+972 52-548-6969
Robustness fixes are hard
The following is a fix we did to resolve a production crash of RavenDB. Take a look at the code, and consider what kind of error we are trying to handle here.
Hint: The logger class can never throw.
The underlying issue was simple. We run out of memory, which is an expected occurrence, and is handled by the very function that we are looking at above.
However, under low memory conditions, allocations can fail. In the code above, the allocation of the log string statement failed, which threw an error. This caused an exception to escape a thread boundary and kill the entire process.
Moving the log statement to the inside of the try statement allows us to recover from it, attempt to report the error, and release any currently held memory and attempt to reduce our memory utilization.
This particular error is annoying. A string allocation will always allocate, but even if you run out of actual memory, such allocations will often succeed because it can be served out of the already existing GC heap,without the need to trigger actual allocation from the OS. This is just a reminder that anything that can go wrong will, and with just the right set of circumstances to cause us pain.
I’ll use this opportunity to recommend, once again, reading How Complex Systems Fail. Even in this small example, you can see that it takes multiple separate things to align just right for an error to actually happen. You have to have low memory and the GC heap should be empty and only then you’ll get the actual issue. Low memory without the GC heap being full, and the code works as intended. GC heap being full and no low memory, no problemo. 
Comments
So, how does one log out-of-memory errors?
@peter: You first have to deallocate a "safety" chunk of memory to be able to construct strings, open files and generally log anything.
cheers, </wqw>
Peter, Typically, you allocate a string at the start of the application and use that as the log string.That assumes that your actual logging isn't doing any allocations, of course.
I'm not familiar with the logger that you use, but have you considered introducing overloads with data parameters, so that you'd be able to call log with the template and the
Namewithout interpolating the string?Scooletz, I am aware of this, but I decided not to go that route. That is why all my log statements are inside an if clause.Having data parameters like that will actually _ also_ allocate, usually (because of
params).And that gives me the ability to use formatted strings.Comment preview