Friday, January 14, 2011

IIS 7 on SBS 2008 - logging is going haywire

The C: drive on our SBS 2008 server just ran out of space. The culprit appears to be IIS, which is logging an incredible amount of activity in one particular log folder. Most of the IIS log folders look normal, but each of the daily files in C:\inetpub\logs\LogFiles\W3SVC1372222313 is at least 4.4MB, with the largest being yesterday's, at 1.67 GB!

The largest ones I can't even open on the server, but I've examined several of the smaller ones. They all show several dozen entries being made every few minutes that look like this:

2009-07-11 00:00:02 fe80::5558:434c:a610:405a%10 POST /ApiRemoting30/WebService.asmx - 8530 [DOMAINNAME]\[SERVERNAME$] fe80::5558:434c:a610:405a%10 Mozilla/4.0+(compatible;+MSIE+6.0;+MS+Web+Services+Client+Protocol+2.0.50727.4016) 200 0 0 3

Typically 40 or 50 of these entries will be made in the same second, with gaps of 2-5 minutes between each batch of entries. The other 1 percent of the entries in the file appear to involve WSUS.

I'm going to delete most of these files, because I don't really have a choice, but I'd like to know what's causing this out-of-control logging and how to put a lid on it in the future.

UPDATE: Okay, I've been able to examine a few more files. The bloat is apparently being caused by something going wrong when someone (i.e., me or another admin) logs in to WSUS interactively:

  1. The trouble begins with a single log entry with no username (just "-"). It gets an HTTP status of 401.2 and a sc-win32-status code of 5.

  2. This is followed by a long stretch of entries that alternate between no username and my own username. The ones with no username have an HTTP status of 401.1 and a sc-win32-status of 2148074254. The ones with my username are normal HTTP 200 entries.

So as far as I can tell what appears to be happening is that when I log in to administer WSUS via the SBS console, NTLM authentication is not persisting behind the scenes, causing continual reauthentication attempts throughout the session, transparently to me. Hundreds of these entries are being created every second, adding about 70MB per hour to the log file. I have no idea why this is happening.

  • That's IPv6-based access to WSUS that you're seeing there.

    Temporarily disable logging so that you don't fill the drive again:

    • Jump into IIS Manager
    • Locate the WSUS web site (it'll be the one listening on port 8530)
    • Bring up the Logging properties for the root of the site
    • Click "Disable" in the "Actions" pane.

    That'll stop the logs from building up.

    I can't say that I've seen WSUS-related traffic build up logs that big before. 4.4MB in a day isn't unheard of, but the 1.67GB in a day means that something has gone wrong.

    Yesterday's log file is going to tell you lots about what was occurring. I find it hard to believe that it was all WSUS traffic. I wonder if something else didn't start banging on the server computer. Get that larger log file off of the machine and have a look at it.

    Your log looks like it's in the W3C extended format. The format of that log file appears to be:

    Date, Time, source IP address, HTTP request method, URI stem, probably URI query, server port, username, server IP address, user agent, HTTP result, probably Win32 status, and probably time taken

    (The "probably" fields are because I can't be sure without seeing more of the file.) The header on the file will tell you the format for sure.

    You need to get a look at that 1.67GB file-- it's gonna tell you what's up. Logging disabled on the site will prevent the hard drive from filling up again, but you want to know what's happening, behind the scenes, since it's going to be impacting server performance in some manner. Ultimately, you want to get to the bottom of the cause and then get logging enabled again (so that you have an audit trail if you have to track down strangeness again in the future).

  • Is WSUS working ok? You could try running the WSUS diagnostic tool.

    Microsoft Windows Server Update Services Tools and Utilities

    From JS
  • On one side of the equation, you still want to figure out why you are having so much log traffice being generated (no suggestions there...), but I have found that the log folder is a good candidate for NTFS compression. Those text files compress nicely, and since you rarely open the log files, you will likely not even notice that they are compressed.

    phenry : Good idea. I'll try that.
    From Sean Earp
  • Hi,

    I'm experiencing exactly the same issue. Wishful thinking that WSUS SP2 was going to resolve the problem... anyone any further on getting to the root cause of this? I've had a look around IIS and short of turning off logging I'm not sure what else to try...

    Many thanks,

    Mike

  • Same problem here, any solution?

  • On a related note, you may want to consider turning off logging permanently for the WSUS site. Granted it may be useful for troubleshooting WSUS problems, but you can always turn it on as needed.

    Having said that, I would look into the root cause of all the log entries and address that issue, which will then make my previous sentence a moot point. ;)

    From joeqwerty
  • I had the same problem; 20GB of log files in there for me. I noticed that the user listed was an account that I use for our backup program that has to be logged in all the time so backups will run unattended. I have a suspicion it's because the SBS Console is also usually always up as well. Can anyone corroborate this?

  • I'm experiencing exactely the same problem and just stumbled over it because the system partition was filling up. Since the day I started the server this very error is written into the log files multiple times per second in the manner discribed above. The peak was a file with about 270mb.

    I find it very strange that the source AND destiniation IP addresses are always the same. this leads to the thought that the server has a problem talking to itself. I already found an article addressing this issue but it didn't help in my case: http://verbalprocessor.com/2008/06/03/sccm-and-wsus-on-server-2008/

    did anybody find out anything new to this?

0 comments:

Post a Comment