WatchPoint
Is it possible to printf in 1ns? Ultra-high performance logging for debugging concurrency issues in C and C++ programs.
In today’s video, we dive deep into printf debugging and we answer the question: can we get a printf in as low as 1 nanosecond? Printf debugging is often plagued by issues like the elusive “Heisenbug,” where adding print statements causes the problem to disappear due to timing and race conditions. We explore a variety of printf, sprintf functions, logging libraries, performance benchmarks, and techniques to improve performance, especially when debugging multithreaded applications. We begin by testing the performance of a simple printf function. Results are not great. Look at how it scales: as I add threads it gets worse and worse. When we look at the implementation inside libc, it’s taking a mutex when it does the write; so other threads are blocking. That mutex is the real problem, because it’s going to cause the thing that does the printf to block while the other thread has the mutex; and that’s going to change the scheduling order. No wonder the race condition is going to go away. spdlog is a C++ logging library that promises fast logging, but struggles with performance as it also relies on mutexes for multithreaded environments. It’s actually worse than fprintf. sprintf scales much better because we’re not taking that mutex; it’s much less intrusive. But if we zoom in by taking out fprintf and spdlog from the chart, we can see we’re still at nearly 200 nanoseconds – even single-threaded. And we were aiming for 1 nanosecond. What’s getting in the way here are all the string manipulations. So can we do better? To further improve performance, we introduce L3, a lightweight logging library that eliminates string manipulation. Look at how much better it performs: we’re down to 1 nanosecond for single-threaded cases, with decent scalability for multithreading. No threads blocking there. This solution is much more efficient than using traditional printf, sprintf, spdlog. Watch the video above for full explanation on how we got it down to 1 nanosecond. And give L3 a try at https://github.com/undoio/l3 Printf debugging
spdlog
sprintf debugging
L3 logging library
Want GDB pro tips directly in your inbox?
Share this tutorial