Live data from Hacker News

NanoLog – a nanosecond scale logging system for C++

github.com

1–10 of 67 posts

Re: NanoLog – a nanosecond scale logging system for C++

#3
I spent a lot of time trying to build a fast logging system in my last couple of jobs. The basic lesson (and I'm only talking about C/C++/C# here) is that you will spend most of your time formatting strings if you do your file I/O asynchronously.

Since this system has a preprocessor mode, I assume they learnt the same lesson.

The bigger lesson is that it really doesn't matter how many millions of logs you can generate per second if you don't have the infrastructure to store and analyze them easily. No one is going to enjoy digging through these things and the more you generate, the harder it is to extract meaningful information.

In other words, pay a lot more attention to what you'll do with the logs rather than how fast you can spew them out. I have rarely needed more than a few thousand log messages/sec even for a loaded MMO server. I spent way more time creating ways to look at these logs and making them accessible in near real time.

Re: NanoLog – a nanosecond scale logging system for C++

#4

I spent a lot of time trying to build a fast logging system in my last couple of jobs. The basic lesson (and I'm only talking about C/C++/C# here) is that you will spend most of your time formatting strings if you do your file I/O asynchronously. Since this system has a preprocessor mode, I assume they learnt the same lesson. The bigger lesson is that it really doesn't matter how many millions of logs you can generat…

That's why I open comments first.. hypetaker +1

Re: NanoLog – a nanosecond scale logging system for C++

#5
The code overall is pretty clever, but at the core of all this they completely ignore strict aliasing to dump stuff into a char* buffer indiscriminately... Look at this function:

https://github.com/PlatformLab/NanoLog/blob/master/runtime/N...

     T argument = *reinterpret_cast(*in);
     ...
     uint32_t stringBytes = *reinterpret_cast(*in);
A total of 6 reinterpret_casts in that file alone.

I didn't see any indication that you have to turn off strict aliasing to use this library (and would you really want to make all your remaining code slower just so your logging has better benchmark scores?). Which makes all this code UB as far as the C++ standard is concerned (no, their allocator does not magically placement-new the correct object types into the right places).

They could just inspect their T values as char* and/or memcpy them around instead of all this pointer aliasing (well, as long as their values are trivial types - I couldn't figure out whether you can log non-trivial stuff here?) at virtually no additional cost.

Edit: And this right here convinces me that I definitely wouldn't want to use this library in production... Adding a volatile to fix a threading bug is just a big no-no.

https://github.com/PlatformLab/NanoLog/commit/e9691246ede6da...

Re: NanoLog – a nanosecond scale logging system for C++

#6
post #2

Looks interesting but how does one reproduce the comparative benchmarks from the paper? I see the code that benchmarks nanolog but how do I reproduce the baseline for glog?

You can't claim it is faster if you don't provide reproducible benchmarks.

Re: NanoLog – a nanosecond scale logging system for C++

#7

The code overall is pretty clever, but at the core of all this they completely ignore strict aliasing to dump stuff into a char* buffer indiscriminately... Look at this function: https://github.com/PlatformLab/NanoLog/blob/master/runtime/N... T argument = *reinterpret_cast (*in); ... uint32_t stringBytes = *reinterpret_cast (*in); A total of 6 reinterpret_casts in that file alone. I didn't see any indication that you…

You'd think so, but in fact reinterpret_cast from char* (and unsigned char, and std::byte) is explicitly allowed by the type aliasing rules.

Re: NanoLog – a nanosecond scale logging system for C++

#8

The code overall is pretty clever, but at the core of all this they completely ignore strict aliasing to dump stuff into a char* buffer indiscriminately... Look at this function: https://github.com/PlatformLab/NanoLog/blob/master/runtime/N... T argument = *reinterpret_cast (*in); ... uint32_t stringBytes = *reinterpret_cast (*in); A total of 6 reinterpret_casts in that file alone. I didn't see any indication that you…

char* is universal memory format, you could specialize from that into anything you want

Re: NanoLog – a nanosecond scale logging system for C++

#9
post #7

The code overall is pretty clever, but at the core of all this they completely ignore strict aliasing to dump stuff into a char* buffer indiscriminately... Look at this function: https://github.com/PlatformLab/NanoLog/blob/master/runtime/N... T argument = *reinterpret_cast (*in); ... uint32_t stringBytes = *reinterpret_cast (*in); A total of 6 reinterpret_casts in that file alone. I didn't see any indication that you…

You'd think so, but in fact reinterpret_cast from char* (and unsigned char , and std::byte ) is explicitly allowed by the type aliasing rules.

To the best of my knowledge, casting to char* is totally fine (inspecting an object as bytes) under certain constraints.

What is not fine is pretending that an object lives at a position in memory where it does not (i.e. treating bytes of memory as some object through a reinterpret_cast away from char* ).

Edit: To clarify, casting away from char* is of course allowed if you cast to whatever object type actually lives at the pointed-to location.

Re: NanoLog – a nanosecond scale logging system for C++

#10
I built a similar system with a focus on profiling events with extremely low overhead. When taking an timestamp, the processor cycle count register is read, and pushed into a ring buffer with a tiny descriotion including a static string label. A background thread perodically writes that buffer contents to disk. An offline tool visualizes the recorded events and intervals over time and can do a bit of statistics.

This system has served me quite well, but I need to rework the UI because zooming to microsecond resolution on a 30 second trace overflows the range values in the Qt scrollbars.

Post reply on HN