Question about access_log timestamp 1

[Einstein47]

This isn't an error, just a question.

I noticed in my access_log today that I have an entry that is out of time with the related log entries. Here is what I'm talking about:

192.168.9.106 - - [22/Jan/2008:14:58:20 -0700] "GET /Brio/img/btn_er_msg_critical.gif HTTP/1.1" 200 357
192.168.9.106 - - [[red]22/Jan/2008:14:58:20 -0700[/red]] "GET /Brio/img/closer.gif HTTP/1.1" 200 94
192.168.9.106 - - [[red]22/Jan/2008:14:24:47 -0700[/red]] "POST /Brio/dataaccess/Browse?REQUEST_TYPE=53805057 HTTP/1.1" 200 145857057

The POST has a timestamp of 34 minutes earlier than the line before it, however it is later in the access_log file.

[blue]Why would that happen?[/blue]

Any ideas or suggestions would be appreciated - thanks in advance.

Einstein47 (Starbase47.com)
“Never put both feet in your mouth at the same time.
Because then you won't have a leg to stand on.“
- Unknown

 

[colorplane]

I'm guessing that /Brio/dataaccess allows file upload?

The content-length on that entry is 145,857,057 bytes, or 139MB. It simply took the user 34 minutes to upload the file. The timestamp relates to when the upload began, and its position in the logs corresponds to when it ended.

34 minutes to upload 139MB is about 4MB/s which is very fast but not surprising since this connection was from a computer on your local network 192.168.9.*

I hope this is still relevant a couple weeks after you posted the mystery!

 

[colorplane]

Ha, I guess "dataaccess" would more likely mean that they were downloading, either way it's the same concept =)

 

[Einstein47]

This box creates reports, and it pulls a lot of data to crunch on. 139MB is large, but it isn't the biggest. So I guess it was just a timing issue.

Thanks for the heads up - STAR for you.

Einstein47 (Starbase47.com)
“Never put both feet in your mouth at the same time.
Because then you won't have a leg to stand on.“
- Unknown