When Apache2 log file entries have timestamps that are out of order, do you trust the timestamp or the order?10.1.10.250 - - [20/May/2015:00:43:53 -0600] GET /foo/bar_1234.jpg HTTP/1.1 200 738542 http://www.example.com/foo/bar/jbcore/full.html some UA10.1.10.250 - - [20/May/2015:00:43:55 -0600] GET /foo/bar_2345.jpg HTTP/1.1 200 824394 http://www.example.com/foo/bar/jbcore/full.html some UA10.1.10.250 - - [20/May/2015:00:43:57 -0600] GET /foo/bar_3456.jpg HTTP/1.1 200 15680 http://www.example.com/foo/bar/jbcore/full.html some UA10.1.10.250 - - [20/May/2015:00:43:53 -0600] GET /foo/bar_4567.jpg HTTP/1.1 200 822449 http://www.example.com/foo/bar/jbcore/full.html some UA10.1.10.250 - - [20/May/2015:00:43:57 -0600] GET /foo/bar_5678.jpg HTTP/1.1 200 15062 http://www.example.com/foo/bar/jbcore/full.html some UA10.1.10.250 - - [20/May/2015:00:43:56 -0600] GET /foo/bar_6789.jpg HTTP/1.1 200 798119 http://www.example.com/foo/bar/jbcore/full.html some UA10.1.10.250 - - [20/May/2015:00:43:54 -0600] GET /foo/bar_7890.jpg HTTP/1.1 200 836622 http://www.example.com/foo/bar/jbcore/full.html some UA10.1.10.250 - - [20/May/2015:00:44:20 -0600] GET /foo/bar_8901.jpg HTTP/1.1 200 763120 http://www.example.com/foo/bar/jbcore/full.html some UA
Do you trust timestamps when they are out of order?
apache2;apache log files
This may seem odd, however, there may be a valid explanation.Apache can log either the access (start) time or the completion time. At one point, when the feature to select access or completion time was new, Apache changed the default from access to completion, but when the inevitable backlash came, quickly changed the default back to access time. However what did not change as a result of the new feature is that regardless of which log time you select, it is always written to the log file at completion rather than when first accessed. Prior to this, all accesses were logged immediately even if they never really completed. The new method results in a cleaner log file.So what happens now is that if a request takes a while to complete, it is written to the log file when it is completed which can be several seconds after it was started- hence the access times being out of order slightly. This is not that unusual since sometimes requests can take a few seconds to complete from time to time. However, if this is consistent throughout your log file, I would be looking into whether your server is taking too long to process requests or if there are specific requests that take too long. Otherwise, I would not worry about it at all.