How to mis-configure your production to dead crawl

time to read 2 min | 322 words

One of the things that I avidly subscribe to is that when you are building server applications, visibility into what the application is doing is key. If you don’t have visibility into the application, you are left in the dark, stumbling and alone.

NH Prof is a good example of how you make things much more visible to developers, but I am doing this in many other places, Rhino Service Bus is another example of how important it is to have visibility into what your servers are doing. Being able to see what is actually going on in your apps is priceless!

However, that does come at a cost. And a pretty steep one at that.

Logging is expensive. It is expensive to gather the data to log, it is expensive to actually log the data, in order to produce coherent logs in multi threaded environment, you need to perform synchronization, etc.

One of the most common performance problems that people run into is when they push their debug logging configuration to production. If we will look into NHibernate as a good example, if you set the log level to debug, you are going to get tens of thousands of messages just for the startup! And you are going to get hundreds and thousands of log messages for routine operations.

That is going to slow things down, considerably.

Production configuration management is a big topic, and it deserves its own post, but the impact of setting the log level too low in production cannot be stressed strongly enough.

Pay attention to this, or it will make you pay attention to it.

In one notable case, several years ago, we re-implemented a whole module in the application (significantly optimizing it) to get exactly zero benefit (well, negative benefit, actually) from the exercise, since the actual problem was slow logging database.

In another, we improved performance by over 60% by simply raising the log level from DEBUG to ERROR.