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

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


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.


I'd delay any and all formatting until actually needed:

struct log_entry {    struct timeval timestamp;    unsigned int code;    union {        struct param1 p1;        struct param2 p2;    };};

The paramN structures contain the data appropriate for the event in whatever form they were in at that time, but as a copy (so the log data can be analyzed standalone).

Depending on your requirements, you can keep this data in a ring buffer and either constantly overwrite old data, or dump it to disk when a certain percentage is reached.


Edit: Multiple downvoters now. Please leave a comment, so I can address the issues properly. Thanks!

You could reorganize your code so that your logger is reading a date timestamp string from a buffer that is updated N times a second (depending on your desired resolution) by some other thread. For 4 times a second:

struct current_time_stamp {    char timestr_[4][16];    unsigned index_;    unsigned subsecond_;    const char *get () const { return timestr_[index_%4]; }    void update () {        // ... update string in timestr_[(index_+1)%4] ...        // ... if (index_ + 1)%4 is zero, recompute subsecond_        ATOMIC_INCREMENT(index_);        // ... also need a memory barrier for timestr_ update    }};

The sub-second resolution for each log would read from a high performance counter. DeadMG suggests QueryPerformanceTimer on windows, and on Linux (and POSIX) there is clock_gettime. If, however, the overhad of those implementations is still to high for you, you can query the time stamp counter on the processor directly using inline assembly (see rdtsc for x86). The subsecond value is delta'd from the one recorded in the structure to get the proper offset.

If you can get away with logging the time stamp in a binary format, that would get away from the formatting issue.