Efficiently computing date/time stamp for logging purposes on unix/win32

Question

I'm in a situation where after having profiled and analyzed our system, come to the conclusion that the logging component of the system is one of the many bottle necks taking up about ~17% of total running time - a lot of things are logged.

Of this, about 5% of the time the logger consumes is related to producing a date/time stamp in ascii in the following format: YYYYMMDD HHMMSS.fff - we roughly log about 700k lines per second. (roughly 700K x (localtime and gettimeofday) calls per second)

I was wondering what techniques fellow SOers have for producing time-stamps efficiently.

Cross platform solutions would be welcomed.

Note1: we looked into Boost.datetime - it's great, but a bit too slow for our needs, std::chrono is a perfect solution, however we unfortunately have to support pre c++11 compilers.

Note2: We've implemented a simple optimisation that only computes the date part (yyyymmdd) one per 24hrs hence only having 1 gettimeofday call per line - didn't help much though.

Answer 1

If you have the option of using C++11, you should check out std::chrono.

Failing that, the optimisation would depend on the resolution you need. I would ask if you absolutely need timestamps on the logging or if occassional timestamps with sequence information might be useful?

Example:

<timestamp1> <seq_num_0> ...
<timestamp1> <seq_num_1> ...
....
<timestamp1> <seq_num_n-1> ...
<timestamp2> <seq_num_0> ...

The way I see it, you have two problems:

1. Synchronizing the timestamps with other systems
2. Getting an accurate timestamp on a single system

I would use a timer based system to update the timestamp twice every millisecond and re-use it between updates. I would then make sure that the systems your code runs on have their clocks synchronized to an atomic clock. You generate the timestamp twice to try and compensate for the flakiness of the underlying OS's timer mechanisms.

I don't think you could get much better than that.

EDIT: Actually, you can. Make sure you only format the timestamp string when it changes. You also don't need a sequence number, if you can guarantee that entries get logged in the order they come in. Given those two assumptions, your logging problem now reduces to how fast you can concatenate and write out two strings.

UPDATE 2: If BOOST isn't suitable and if you can't use C++11, it boils down to this:

1. Use a timer to set and format the timestamp twice every millisecond - you can do this via OS level APIs.
2. Make sure that events are logged in the order they come in.

Assuming I/O isn't your bottleneck, your problem is then nothing but one of fast string concatenation.