Wrong data from e2guardian access.log

[waltertakashi]

Hi! We're having some problems with the report generated by SquidAnalyzer. We're using e2guardian v5.3.2 and SquidAnalyzer 6.6 (last commit).

Our current date/time in our server is Sex Abr 19 23:16:01 AMT 2019, but when we run SquidAnalyzer, it shows the following message on debug:

SQUID LOG HISTORY TIME: Sat Apr 20 18:51:37 2019 - HISTORY OFFSET: 1421

The head of access.log is as follows:

1555708547.543      1 192.168.1.56 TCP_DENIED/403 0 GET http://clientservices.googleapis.com/chrome-variations/seed?osname=win&channel=stable&milestone=73 - DEFAULT_PARENT/192.168.1.1 -
1555710929.169    204 192.168.1.56 TCP_MISS/301 0 GET http://officecdn.microsoft.com/db/492350f6-3a01-4f97-b9c0-c7c6ddf67d60/Office/Data/v64_16.0.11425.20204.cab - DEFAULT_PARENT/192.168.1.1 -
1555710934.315     97 192.168.1.56 TCP_MISS/301 0 GET http://officecdn.microsoft.com/sg/492350f6-3a01-4f97-b9c0-c7c6ddf67d60/Office/Data/v64_16.0.11425.20204.cab - DEFAULT_PARENT/192.168.1.1 -
1555715941.108 120095 192.168.1.231 TCP_DENIED/403 0 HEAD http://download.microsoft.com/v11/2/windowsupdate/redir/v6-win7sp1-wuredir.cab?1904192316 - DEFAULT_PARENT/192.168.1.1 -

The report is also giving wrong date/time values. Any ideas?

Thanks in advance!

[darold]

Hi,

Please post the result of the following command:

LANG=C perl -e 'use POSIX qw/ strftime/; print strftime("%a %b %e %H:%M:%S %Y (%z)", CORE::localtime(1555710929.169)), "\n";'

Regards

[waltertakashi]

Hi Darold,

Here is the output:

root@ubnt-server:~# LANG=C perl -e 'use POSIX qw/ strftime/; print strftime("%a %b %e %H:%M:%S %Y (%z)", CORE::localtime(1555710929.169)), "\n";'
Fri Apr 19 17:55:29 2019 (-0400)

Thanks!

[darold]

Actually SquidAnalyzer use the localtime but if you use the -t option or the TimeZone configuration directive the specified value is added to the timestamp. Do you use this configuration?

[waltertakashi]

No, I'm not using this option. It is really strange. Now I'm getting the following output:

SQUID LOG SET START TIME: Fri Apr 19 13:15:47 2019
.....
SQUID LOG END TIME  : Mon Apr 22 05:43:12 2019

I checked these timestamps using the command you provided in your last reply and got the following outputs (from the first and last entries on access.log):

LANG=C perl -e 'use POSIX qw/ strftime/; print strftime("%a %b %e %H:%M:%S %Y (%z)", CORE::localtime(1555708547.543)), "\n";'
Fri Apr 19 17:15:47 2019 (-0400)

LANG=C perl -e 'use POSIX qw/ strftime/; print strftime("%a %b %e %H:%M:%S %Y (%z)", CORE::localtime(1555940592.864)), "\n";'
Mon Apr 22 09:43:12 2019 (-0400)

4 hours of difference between the logs and the report from SquidAnalyzer.

[waltertakashi]

Well, I think I fixed it. I uncommented the TimeZone option and set it to +00, rebuilt it and voilá, worked like a charm :)

Thank you!

BTW: thank you for this awesome project :D

[darold]

Commit 1bfd73c fix auto detection and handling of timezone. You should not have to use the TimeZone +00 workaround.