SmartInspect Logging Performance and Benchmarks
This article provides performance analysis and benchmark results for the SmartInspect .NET library. This information is useful for customers who want to use SmartInspect in highly scalable environments. Even though this article is based on results from the .NET logging library, the results are very similar with the Java and Delphi libraries.
The following performance benchmarks were conducted on a small workgroup server featuring an Intel Core 2 Duo 2.4GHz CPU, 4GB of RAM and a RAID 5 disk array running Windows Server 2003 R2 Standard Edition.
The benchmarks show the performance of the SmartInspect .NET library running under .NET 1.1. The first chart shows statistics about the amount of processed log messages on the particular machine. Please note that the amount of log entries scales with the used hardware.
Analyzing this chart brings some interesting facts to light that have direct implications for production systems using SmartInspect:
The machine that conducted the benchmark could handle about 1,645,000 messages per second when using the memory protocol. This number is a good indication for the actual performance of SmartInspect, as it shows the raw performance of the library without external slowdowns like network or disk access times.
Even when logging to a log file, the machine could handle 139,130 messages per second. The number is even more impressive when considering that SmartInspect does not use any buffering technologies. SmartInspect doesn't use buffers to increase the reliability and to guarantee that all log messages were written to a log file in case of an application crash. This allows analysis of log entries that were sent directly prior to an application failure.
The different log methods have direct implications for the application and logging performance. While basic log methods like LogMessage, LogString, WatchString and so on are very fast, more complex methods like LogException and LogArray consume more resources and need more time to complete.
Compared to log files and the memory protocol, the TCP/IP protocol and the performance hit due to sending messages over the Windows TCP/IP stack and the network can cause problems for very high-performance applications and systems. To guarantee best performance results, logging via TCP/IP is therefore not recommended on production systems. Please note that the TCP/IP benchmarks were performed against the SmartInspect Receiver, a lightweight network server for the SmartInspect libraries.
Based on the previous benchmarks, it is easy to calculate exact execution times for each particular log method and the different protocols. The following chart shows the time the different log methods needed to complete. Just like in the previous chart, the results include storing/sending the log messages to the destinations including the transport over the network or storing the data on the disk. The numbers are given in μs per message (microseconds per message).
As this chart is just another representation of the above data, we see the same implications in this chart. Note that logging a simple string message or logging variable values took only approx. 0.3 - 1.5 μs per message, depending on the actual log method (when logged via the memory protocol).
To calculate the real impact of using SmartInspect in a production environment, we need to figure out the actual distribution of the used log methods. As we have seen above, the used log methods have a direct impact on the actual performance of a production system.
To calculate an average execution time of a log method, we need to know the distribution of the used log methods. Based on observations and direct customer feedback, we believe that the following distribution of log methods is quite common. These numbers can easily be optimized by not using methods like LogArray. Please note that such an optimization is only needed in extreme cases with tens of thousands of log messages per second. Example distribution:
- 60% simple log methods like LogDebug, LogMessage, LogError and so on
- 35% Watch methods to track specific resources (WatchString, WatchDouble etc)
- 5% more complex log methods like LogException and LogArray
This example distribution now lets us calculate the average log method execution time. We can then calculate the complete execution time of an example application. In this scenario, based on the above numbers, the average log method execution time for the memory protocol is 5.4883μs (we will continue with 5.5μs in the next calculation).
Let's take a high-performance ASP.NET application server with 300 page accesses per second. If 20 log messages are generated for each page access, we have the following numbers:
300pages/s * 20log messages/page = 6,000log messages/s 6,000log messages * 5.5μs = 33ms
This calculation means that with the above numbers in this example scenario, about 30ms are spent generating the log messages per second. This results in a performance hit of only 3% on the above described production system for generating the log messages. If needed, the performance can be drastically optimized by changing one or more of the following conditions:
- If only log methods with the best performance are used, the average execution time per log message can be optimized by a factor of 5
- Depending on the application, 20 log messages per page / service access can be reduced as needed
Please note that this calculation is based on the SmartInspect .NET memory protocol. This means that the time for writing the log messages to other logging destinations (a log file, for example) must be added to this equation.
We designed and developed SmartInspect to be reliable and high-performance and we believe that the above results confirm this. Additionally to the above performance benchmarks, one has to keep in mind that SmartInspect contains additional features like the Backlog Queue to further optimize the logging performance for production systems.
When SmartInspect is disabled, on the other hand, there is almost no performance impact of keeping the logging statements in the code. This means that logging can be disabled for most parts of an application, and individual user sessions or application modules can be enabled for logging to identify problems and errors.
This makes SmartInspect very flexible and if you have any questions about the SmartInspect performance or anything else we can assist you with, please contact us at firstname.lastname@example.org.