Thread Info
  • State Verified Answer
  • Locked Locked
  • Replies 1 reply
  • Subscribers 3 subscribers
  • Views 1139 views
  • Users 0 members are here
Options
Suggested
This discussion has been locked.
You can no longer post new replies to this discussion. If you have a question you can start a new discussion

Web filtering (http) log not in chronological order

asc_

Hey everyone,

sieving through a bunch of http logfiles searching for connectivity problems we have, i realized that log entries sometimes are not in chronological order. My logfile then looks like this:

2020:05:15-12:23:11 m-2 httpproxy[7283]: id="0001" severity="info" sys="SecureWeb" sub="http" name="http access" action="pass" method="CONNECT" srcip="***2" dstip="35.206.134.202" user="" group="" ad_domain="" statuscode="200" cached="0" profile="REF_DefaultHTTPProfile (Default Web Filter Profile)" filteraction="REF_DefaultHTTPCFFAction (Default content filter action)" size="13068" request="0x47410a00" url="https://***/" referer="" error="" authtime="0" dnstime="3" aptptime="98" cattime="33" avscantime="0" fullreqtime="2307922" device="0" auth="0" ua="Mozilla/5.0 (Windows NT 6.1; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/81.0.4044.138 Safari/537.36" exceptions="" category="136" reputation="neutral" categoryname="Online Shopping"
2020:05:15-12:23:12 m-2 httpproxy[7283]: id="0001" severity="info" sys="SecureWeb" sub="http" name="http access" action="pass" method="CONNECT" srcip="***" dstip="185.64.189.112" user="" group="" ad_domain="" statuscode="200" cached="0" profile="REF_DefaultHTTPProfile (Default Web Filter Profile)" filteraction="REF_DefaultHTTPCFFAction (Default content filter action)" size="5105" request="0x49cc4300" url="https://***/" referer="" error="" authtime="0" dnstime="10" aptptime="68" cattime="26" avscantime="0" fullreqtime="2305663" device="0" auth="0" ua="Mozilla/5.0 (Windows NT 6.1; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/81.0.4044.138 Safari/537.36" exceptions="" category="178" reputation="neutral" categoryname="Internet Services" application="pubmatic" app-id="996"
2020:05:15-12:23:11 m-2 httpproxy[7283]: id="0001" severity="info" sys="SecureWeb" sub="http" name="http access" action="pass" method="CONNECT" srcip="***" dstip="178.250.2.131" user="" group="" ad_domain="" statuscode="200" cached="0" profile="REF_DefaultHTTPProfile (Default Web Filter Profile)" filteraction="REF_DefaultHTTPCFFAction (Default content filter action)" size="6299" request="0x5732c700" url="https://***/" referer="" error="" authtime="0" dnstime="5" aptptime="113" cattime="53" avscantime="0" fullreqtime="2308332" device="0" auth="0" ua="Mozilla/5.0 (Windows NT 6.1; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/81.0.4044.138 Safari/537.36" exceptions="" category="105" reputation="neutral" categoryname="Business" application="criteo" app-id="922"

Can I happily ignore this or is something odd going on here? Looks like normal multithreaded proxying going on but with a single log writer process. Right?

Regards

Alex



This thread was automatically locked due to age.
  • 0

    I think you can happily ignore these.   The example entries are from three different sessions (different request numbers, different destinations, probably different source IP if those had not been obscured).   I think it is an anomaly of the write-to-disk process that some entries arrive ahead of others.  A difference of one second in the log may represent a very small difference in the actual real-time sequence of events, since many of these can happen per second.

    After loading my log data into a SQL database, I sort first on source IP, then on file sequence number (which I apply during the load process).   Sometimes I have tried to reorder based on SourceIP and request number, but that has proven to be a lot of complexity for little incremental value.

     

Unfiltered HTML