Benchmarking Popular Node.js Logging Libraries
Sometimes developers are hesitant to include logging due to performance concerns, but is this justified? And how much does library choice affect performance? The team at SolarWinds® Loggly® and myself decided to find out. We ran a series of performance tests on some of the most popular Node.js libraries. These tests are designed to show how quickly each library processed logging and the impact on the overall application. Let’s see how they did!
The Contenders
For this test, we investigated some of the most commonly used Node.js logging libraries:
We also used the following additional libraries:
- winston-syslog 0.1 for syslog logging with Winston
- bunyan-syslog 3.2 for syslog logging with Bunyan
We benchmarked these libraries to test their performance, sending their logs to a console and file system. We also tested sending log information to a local rsyslog server over both TCP and UDP, since it is common and probably wise to offload logs in a production environment.
These tests were run using Node.js 8.15.1.
Methodology
Our goal was to compare the performance between the logging libraries. Each library was run on its default configuration, and the same system was used across all libraries and tests.
Our test application logged a total of 1 million log events of the phrase “Hello, world!” and it’s available on GitHub at https://github.com/codejamninja/node-log-benchmarks. We strictly processed logs to create an isolated control group.
We measured the results dedicating either a single logical processor or eight (four cores with hyperthreading) to simulate a larger production server. Node.js is often considered a single threaded program, but technically it’s just the event loop that is single threaded. There are many Node.js tasks that take place on parallel threads, such as garbage collection. It’s also worth noting that the tty (terminal) was doing a bunch of work printing the logs to the screen, which would have most definitely executed on a separate thread. That’s why is so important to test with multiple CPUs typically found on production systems.
Also, the Node.js file system writes are nonblocking (asynchronous). The unblocked time lets us know when the code used to schedule the filesystem writes is finished and the system can continue executing additional business logic. However, the file system will still be asynchronously writing in the background. So, the done time lets us know how long it took to actually write the logs to the filesystem.
The hardware we used is from Amazon AWS.
| Name | Spec |
| Processors | Intel Core i7-7700 @ 2.80GHz (four cores, eight threads) |
| Memory | 32GB Ram |
| Operating System | 64-bit Ubuntu 18.04.2 LTS Server |
| Node.js | 8.15.1 LTS |
Test Results
For all tests, the results are measured in milliseconds. The smaller bars are better because it means the logs took less time to process.
Console
For the first set of test results, we benchmarked the performance of the libraries when logging to the console.
From these results, we can see additional CPUs had a significant effect on the amount of time it took Node.js to log to the console. Winston is the clear winner for speed in multithreaded systems; however, Bunyan performed slightly better in a single-threaded system.
Filesystem
For the second set of test results, we benchmarked the performance of the libraries when writing the logs to the filesystem. Again, notice that each test result contains two times, unblocked and done. This is because the libraries sometimes asynchronously send the logs to syslog. The total time to log is the sum of these two times.
After seeing how much additional CPUs affected console logs, I was very surprised to see that logging to the filesystem performed roughly the same with additional CPUs. This is most likely because the work required to write files is much less than the work required to print to a tty device, so there was less multithreaded activity happening.
Log4js seemed to have the worst results writing to a filesystem, sometimes taking over five times the amount of time to write to the filesystem. Winston unblocked the event loop the fastest, but Bunyan finished writing to the filesystem the fastest. So, if you’re choosing a log library based on filesystem performance, the choice would depend on whether you want the event loop unblocked the fastest or if you want the overall program execution to finish first.
Syslog UDP
For the third set of test results, we benchmarked the performance of the libraries when sending the logs to syslog over UDP.
Log4js and Bunyan both finished around the same time when using multiple CPUs; however, Log4js unblocked the event loop much sooner and performed better on a single CPU.
Log4js also successfully sent all of its logs to syslog without dropping a single one. Although Bunyan had a low drop rate, it still managed to drop a few logs. I would say Log4js is a clear winner when sending logs to syslog over UDP.
We had a terrible experience getting Winston to work with syslog over UDP. When it did work, it took well over a minute to unblock the event loop, and took over two minutes to finish sending the logs to syslog. However, in most iterations of the test we ran out of memory before we could finish. Our assumption is that when using UDP, the library aggregates all the logs in the heap before sending them to syslog, instead of immediately streaming the logs over to syslog. At any rate, it sends the logs over to syslog over UDP in a way that does not work well when slammed with a million logs.
Syslog TCP
For the fourth set of test results, we benchmarked the performance of the libraries when sending the logs to syslog over TCP. Again, notice that each test result contains two times, unblocked and done. This is because the libraries sometimes asynchronously send the logs to syslog.
Since Bunyan was the only library that successfully sent logs to syslog over TCP without dropping any of them, it is the clear winner. Despite its somewhat slow performance when multiple CPUs were introduced, it was still relatively fast.
Sadly we were not able to get Log4js to send logs to syslog over TCP. We received the following error with each attempt:.
(node:31818) UnhandledPromiseRejectionWarning: TypeError: Cannot read property 'trace' of undefined
Winston was relatively fast when sending logs to syslog over TCP, however, it had a substantial log drop rate. Most of the logs were either dropped or corrupted. Below is an example of one of the corrupted logs syslog received from Winston. You can see that the message was cut off.
Mar 17 19:21:42 localhost /home/codejamninja/.nvm/versions/node/v8.15.1/bin/node[22463]: {"mes
The log was supposed to look like this:
Mar 17 19:21:42 localhost /home/codejamninja/.nvm/versions/node/v8.15.1/bin/node[22463]: {"message": "92342: Hello, world!"}
Bunyan performed relatively well when sending logs to syslog over TCP. It did not drop a single log and unblocked the event loop very quickly. One thing that did surprise us, though, is that running on additional CPUs consistently performed worse than running on a single CPU.
Conclusion
Surprisingly, each library excelled in one or more testing scenarios. Our assumption when we started this benchmark was that there would be an overall winner, but actually, each library performed best in different areas under different conditions.
| Output type | Winner |
| Console | Winston |
| File | Winston and Bunyan tied |
| Syslog UDP | Log4js |
| Syslog TCP | Bunyan |
Winston performed best when logging to the console. Winston and Bunyan both performed best in their own ways when logging to the file system. Log4js performed the best when sending logs to syslog over UDP, and Bunyan had the best results when sending logs to syslog over TCP.
If you care more about throughput for syslog, then Log4js with UDP is the best output type. If you only care unblocking the code, then Winston writing to a filesystem is the best. In this case, logging averaged 0.0005 ms per log event, which is incredibly fast. If your typical response latency is 100 ms, then it’s only 0.0005% of your total response time. That’s faster than running console.log(). As long as you don’t go overboard with too many log statements, the impact is very small.
| Console | File | Syslog TCP | Syslog UDP | |
| Log4js | 24385 ms | 31584 ms | N/A | 1195 ms |
| Winston | 10756 ms | 7438 ms | 9362 ms | 142871 ms |
| Bunyan | 15062 ms | 4197 ms | 24984 ms | 12029 ms |
Overall, we would recommend using Log4js with UDP library for the best performance. This will have a negligible impact on your overall response time. Tools like SolarWinds Loggly will store and organize those logs for you. It will alert you when the system encounters critical issues, so you can deliver a great experience to your customers.
The Loggly and SolarWinds trademarks, service marks, and logos are the exclusive property of SolarWinds Worldwide, LLC or its affiliates. All other trademarks are the property of their respective owners.
Benjamin Clay Risser
