Proper chronological ordering of log entries


This issue applies to both the generic Server error log as well as the Payment provider log. I claim this is a nasty bug.

My problem is that a series of quickly happening related log entries are not displayed in correct chronological order if they occurred within the same second. This makes it extremely difficult for my non-tech savvy clients to comprehend the order of events when things go wrong...Telling them that the computer is too stupid to order things properly does not make me look like a rock star.

Often (mostly, but not always? I am not really sure) they appear to be displayed in reverse chronological order - the last entry is display first & the first entry is displayed last. I could be wrong...

A quick check of the underlying table xf_error_log indicates there is an exception_date field which seems to have seconds granularity. Seconds granularity is insufficient for proper ordering of events. Thousands of things can happen each second...


Please be very very careful with this hack workaround...

// hack to make the log entries show up in the proper chronological order...
\XF::$time = time();

Edit: More info provided - I had a payment provider process flow where the "payment initiated" and "payment complete" where significant events that sometimes needed to be examined by the site operations peeps whenever there was a payment issue. Having the "initiated" appear in the log after the "complete" causes huge confusion for the operations team. In this single payment process I resorted to introducing an artificial delay into the payment process after it was "initiated" in order to ensure that the "completion" event (if it actually did happen, but sometimes not) was presented in the proper chronological order in the payment provider log. The penalty was that every user suffered a 2 second pause mid stream in the payment process.
Last edited: