Fixed Proper chronological ordering of log entries

[keithg]

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...

 

[keithg]

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

// hack to make the log entries show up in the proper chronological order...
sleep(2);
\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.

 

[keithg]

upon reflection an extremely simple core solution would be to add an auto-increment field to the xf_error_log table and then always sort on that.

the upgrade script may be a bit knarly? That is a problem left to the core developers...

Cheers!

 

[XF Bug Bot]

Thank you for reporting this issue. It has now been resolved and we are aiming to include it in a future XF release (2.1.3).

Change log:

Allow error and payment provider logs to be sorted by their primary key in order to have more accurate chronological sorting for logs that can happen quickly.

Any changes made as a result of this issue being resolved may not be rolled out here until later.