views:

72

answers:

4

Update: After looking in the event log at around the time this occurred, I get the message: "The server was unable to allocate from the system nonpaged pool because the pool was empty." repeated continually throughout the log, until it was rebooted.

I am writing a class that writes debugging information to a file, up until now the class has worked fine, however I am now starting to stress-test my application (by running it at 1000x times faster than normal) and this has caused an unusual error to occur.

The problem I am seeing is that after a long period of time (4 hours+) my application crashes and seems to take out Windows with it; I can no longer open up Windows Explorer or any other application. A system reboot seems to solve the issue, however when I do the file I am writing to is blank.

This makes me think that perhaps the issue is related to open file handles; perhaps Windows is reaching it's limit of open file handles somehow?

So, here comes the related question; here is the main function that writes data to the file. As you can see, FileStream and BinaryWriter objects are created with each call to this function, wrapped in using statements to ensure they are properly Closed/Disposed.

/// <summary>
/// This is called after changing any
/// stats data, or on initial startup.
/// It saves the current stats to file.
/// </summary>
public void UpdateStatsData()
{
    lock (this.lockObject)
    {
        using (FileStream fileStream = new FileStream(Constants.StatsFile, FileMode.Create, FileAccess.Write, FileShare.None, 128, FileOptions.WriteThrough))
        {
            using (BinaryWriter binWriter = new BinaryWriter(fileStream))
            {
                binWriter.Write(this.serverStats.APM);
                binWriter.Write(this.serverStats.AverageJackpotWin);
                binWriter.Write(this.serverStats.AverageWinnings);
                binWriter.Write(this.serverStats.NumberOfGamesPlayed);
                binWriter.Write(this.serverStats.NumberOfJackpots);
                binWriter.Write(this.serverStats.RunningPercentage);
                binWriter.Write(this.serverStats.SiteID);
                binWriter.Write(this.serverStats.TotalJackpotsValue);
                binWriter.Write(this.serverStats.TotalStaked);
                binWriter.Write(this.serverStats.TotalWinnings);
            }
        }
    }
}
  1. Is it possible that this function, when called very rapidly, could cause file handles to slowly build up and eventually exceed Windows' maximum?

  2. A possible solution involves making the FileStream and BinaryWriter objects private member variables of the class, creating them in the constructor, and then overwriting the data with each call.

.

/// <summary>
/// This should be called after changing any
/// stats data, or on initial startup.
/// It saves the current stats to a serialized file.
/// </summary>
public void UpdateStatsData()
{
    lock (this.lockObject)
    {
        // Seek to the beginning of the file.
        this.binWriter.BaseStream.Seek(0, SeekOrigin.Begin);

        // Write the stats data over the existing data.
        this.binWriter.Write(this.serverStats.APM);
        this.binWriter.Write(this.serverStats.AverageJackpotWin);
        this.binWriter.Write(this.serverStats.AverageWinnings);
        this.binWriter.Write(this.serverStats.NumberOfGamesPlayed);
        this.binWriter.Write(this.serverStats.NumberOfJackpots);
        this.binWriter.Write(this.serverStats.RunningPercentage);
        this.binWriter.Write(this.serverStats.SiteID);
        this.binWriter.Write(this.serverStats.TotalJackpotsValue);
        this.binWriter.Write(this.serverStats.TotalStaked);
        this.binWriter.Write(this.serverStats.TotalWinnings);
    }
}

However, while it may be quicker and only mean using one FileStream, how do I ensure that the FileStream and BinaryWriter are Closed/Disposed properly on application shutdown?

+1  A: 

Most of this code looks fine to me -- you should have no problem re-creating the FileStreams like you are.

The only thing that jumps out at me is that your lockObject is not static. That's potentially a big problem -- multiple instances of the class will cause blocking not to occur, which means you might be running into some strange condition caused by multiple threads running the same code at the same time. Who knows, under load you could be creating thousands of open file handles all at the same time.

Dave Markle
I should have probably mentioned that there is only ever one instance of this class. Although you're right, it's a fault! Also, how do I ensure that the FileStream object is properly flushed/closed when using the 2nd example code? Will the GC do it for me when it's disposed?
Siyfion
Are you running this in a single thread?
Dave Markle
No, the application is multi-threaded.
Siyfion
+1  A: 

I see nothing wrong with the first in terms of handle closure. I do with the second; specifically the very issues you ask about. You could make your class disposable and then ideally close it during a "controlled" shut-down, while depending on the file object's finaliser to take care of matters during exceptional shut-down, but I'm not sure you're fixing the right issue.

What measurements of open file handles confirm your suspicion that this is the issue? It's reasonable to suspect open file handles when you are indeed opening lots of files, but it's foolish to "fix" that unless either A) examining the code shows it will obviously have this problem (not the case here) or B) you've shown that such file handles are indeed too high.

Does the app leave an exception in the event viewer on crashing?

Jon Hanna
Interestingly the event log has the following error events listed continually around the time the application crashed: "The server was unable to allocate from the system nonpaged pool because the pool was empty."
Siyfion
Jon Hanna
Thanks, will do.
Siyfion
Keep us posted on what you find out... This could be interesting...
Dave Markle
Turns out it was related to dkackman's answer.
Siyfion
+1  A: 

The combination of parameters to the FileStream constructor look suspect to me (assuming that all threads log to the same file (Constants.StatsFile):

  • FileMode.Create = Always create the file. overwrite if it exists. you are deleting all previous logs with each entry into this method (might try OpenOrCreate or Append)
  • FileOptions.WriteThrough = no caching - force the disk to spin and force the thread to wait for the disk - slow

My guess: you are calling this method much more quickly than it can complete. Each call backs up on the lock statement waiting for the previous call to delete the file, write to it, and completely flush it to disk. After awhile you just run out of memory.

Assuming you didn't intend to delete the log file each time try this combination and see if things get better and at a minimum get rid of WriteThrough as that will make this method much faster:

using (FileStream fileStream = new FileStream(Constants.StatsFile, FileMode.Append, 
        FileAccess.Write, FileShare.None, 128, FileOptions.SequentialScan))
dkackman
After changing all of the FileStream constructors in the program so that they no longer use FileOptions.WriteThrough and use the FileMode.OpenOrCreate mode when they can, I have yet to see the same problem occur.
Siyfion
+2  A: 

Running out of non-paged pool memory is a very serious mishap in Windows. Nothing good happens after that, drivers will fail to do their job, a reboot is required to recover from this.

Of course, it isn't normal for a user mode program (a managed one at that) to cause this to happen. Windows protects itself against this by giving a process a limited quota of the available system resources. There are many of them, a limit of 10,000 handles is an obvious one that strikes pretty often if a program leaks handles.

Memory from the non-paged pool is exclusively allocated by drivers. They need that kind of precious memory because they use memory at device interrupt time. A critical time where it isn't possible to map memory from the paging file. The pool is small, it needs to be because it permanently occupies RAM. It depends on the amount of RAM your machine has, typically 256 MB max for a machine with 1 GB of RAM. You can see its current size in TaskMgr.exe, Performance tab. I'm giving it a decent workaround right now, it is currently showing 61 MB.

Clearly your program is making a driver on your machine consume too much non-page pool memory. Or it is leaking, possibly induced by the heavy workout you give it. Windows is powerless to prevent this, quotas are associated with processes, not drivers. You'll have to find the driver that misbehaves. It would be one that's associated with the file system or the disk. A very common one that causes trouble like this is, you probably guessed it by now, your virus scanner.

Hans Passant