search

darold / squidanalyzer

Squid Analyzer parses Squid proxy access log and reports general statistics about hits, bytes, users, networks, top URLs, and top second level domains. Statistic reports are oriented toward user and bandwidth control.
http://squidanalyzer.darold.net/
126 stars 36 forks source link

top denied url not showning squidguard log #117

Closed mrv84 closed 8 years ago

mrv84 commented 8 years ago

Hi Darold unfortunatly i'm here with the same problem as issue #75

I correctly updated to last commit. Everything seems to be ok. Users information, top Urls and top domain. But the top denied menu only shows to me the url blocked by squid, not squidguard.

I make a try using squid-analyzer -d /var/log/squidGuard/squid-bl.log

and that's the result:

squid-analyzer -d /var/log/squidGuard/squid-bl.log

SquidAnalyzer version 6.4 SQUID LOG HISTORY TIME: Tue Jan 12 18:10:02 2016 - HISTORY OFFSET: 1542487 SQUIDGUARD LOG HISTORY TIME: Tue Jan 12 17:01:52 2016 - HISTORY OFFSET: 1427296 Starting to parse logfile /var/log/squidGuard/squid-bl.log. DEBUG: this file will not been parsed: /var/log/squidGuard/squid-bl.log, size lower than expected and 1438700953 is lower than history time 1452618602.428. No new log registered... DEBUG: the log statistics gathering took: 0 wallclock secs ( 0.00 usr + 0.01 sys = 0.01 CPU) Skipping HTML build. DEBUG: generating HTML output took: 0 wallclock secs ( 0.00 usr + 0.00 sys = 0.00 CPU) DEBUG: total execution time: 0 wallclock secs ( 0.00 usr + 0.01 sys = 0.01 CPU)

can you help me? Thank you

darold commented 8 years ago

Can you post here the content of file squidGuard.current and in log file /var/log/squidGuard/squid-bl.log the 3 lines around offset 1427296. To move to that offet in VI just type:

:goto 1427296

Thanks

mrv84 commented 8 years ago

Hi and thanks for the quick reply I can't find the squidGuard.current

Here the output requested 2015-08-04 17:09:13 [2958] Request(desk-/social/-) https://twitter.com/ 10.0.21.76/- - GET REDIRECT

darold commented 8 years ago

The file must be in the output directory, by default /var/www/squidanalyzer/ , you will see *.current file in this repository.

What is this output? Is it the line at offset 1427296 or the first line of the file? I don't understand, squid-analyzer shows that last parsed entry was at Tue Jan 12 17:01:52 2016 en the entry you've posted here is from August 4th last year. There is something wrong, can you check that?

mrv84 commented 8 years ago

Hi @darold here the content of squidguard.current

1452614512.594 1427296

the content at offset 1427296 is:

2016-01-13 11:46:49 [5376] Request(default/news/-) http://www.msn.com/?ocid=iehp 10.0.21.109/- - GET REDIRECT

darold commented 8 years ago

I found a case where SquidAnalyzer is not able to auto detect squidguard log format that can be the source of this issue. Please donwload latest developement code and give it a try, commit b957d75 might solves the issue. There's also more debug information about the parsing detection. Please post here the debug output if the problem is not solved.

mrv84 commented 8 years ago

Hi @darold thanks for your support. Just applied last commit here the debug information

[root@localhost ~]# squid-analyzer -d /var/log/squid/access.log /var/log/squidGuard/squid-bl.log SquidAnalyzer version 6.5 SQUID LOG HISTORY TIME: Wed Jan 13 16:29:26 2016 - HISTORY OFFSET: 1990768 SQUIDGUARD LOG HISTORY TIME: Tue Jan 12 17:01:52 2016 - HISTORY OFFSET: 1427296 Starting to parse logfile /var/log/squid/access.log. Reading file /var/log/squid/access.log from offset 1990768 to end. Appending data into /var/www/squidanalyzer/2016/01/13 Clearing statistics storage hashes, for 2016-01-13 16:00:00. Appending data into /var/www/squidanalyzer/2016/01/13 Clearing statistics storage hashes, for 2016-01-13 17:00:00. Appending data into /var/www/squidanalyzer/2016/01/13 Starting to parse logfile /var/log/squidGuard/squid-bl.log. DEBUG: this file will not be parsed: /var/log/squidGuard/squid-bl.log, size is lower than expected. DEBUG: exploring /var/log/squidGuard/squid-bl.log, timestamp found at startup, 1438700953, is lower than history time 1452614512.594. SQUID LOG END TIME : Wed Jan 13 18:52:18 2016 SQUIGUARD LOG END TIME : Wed Jan 13 18:52:18 2016 Read 2125 lines, matched 2069 and found 2069 new lines Reordering daily data files now... Saving data into /var/www/squidanalyzer/2016/01/04 Saving data into /var/www/squidanalyzer/2016/01/05 Saving data into /var/www/squidanalyzer/2016/01/06 Saving data into /var/www/squidanalyzer/2016/01/07 Saving data into /var/www/squidanalyzer/2016/01/10 Saving data into /var/www/squidanalyzer/2016/01/11 Saving data into /var/www/squidanalyzer/2016/01/12 Saving data into /var/www/squidanalyzer/2016/01/13 Generating weekly data files now... Compute and dump weekly statistics for week 03 on 2016 Saving data into /var/www/squidanalyzer/2016/week03 Generating monthly data files now... Compute and dump month statistics for 2016/01 Saving data into /var/www/squidanalyzer/2016/01 Generating yearly data files now... Compute and dump year statistics for 2016 Saving data into /var/www/squidanalyzer/2016 DEBUG: the log statistics gathering took: 0 wallclock secs ( 0.44 usr + 0.03 sys = 0.47 CPU) Building HTML output into /var/www/squidanalyzer Generating statistics for day 2016-01-12 User statistics in /var/www/squidanalyzer/2016/01/12... Mime type statistics in /var/www/squidanalyzer/2016/01/12... Network statistics in /var/www/squidanalyzer/2016/01/12... Top URL statistics in /var/www/squidanalyzer/2016/01/12... Top denied URL statistics in /var/www/squidanalyzer/2016/01/12... Top domain statistics in /var/www/squidanalyzer/2016/01/12... Cache statistics in /var/www/squidanalyzer/2016/01/12... Generating statistics for day 2016-01-13 User statistics in /var/www/squidanalyzer/2016/01/13... Mime type statistics in /var/www/squidanalyzer/2016/01/13... Network statistics in /var/www/squidanalyzer/2016/01/13... Top URL statistics in /var/www/squidanalyzer/2016/01/13... Top denied URL statistics in /var/www/squidanalyzer/2016/01/13... Top domain statistics in /var/www/squidanalyzer/2016/01/13... Cache statistics in /var/www/squidanalyzer/2016/01/13... Generating statistics for month 2016-01 User statistics in /var/www/squidanalyzer/2016/01... Mime type statistics in /var/www/squidanalyzer/2016/01... Network statistics in /var/www/squidanalyzer/2016/01... Top URL statistics in /var/www/squidanalyzer/2016/01... Top denied URL statistics in /var/www/squidanalyzer/2016/01... Top domain statistics in /var/www/squidanalyzer/2016/01... Cache statistics in /var/www/squidanalyzer/2016/01... Generating statistics for week 03 on year 2016 User statistics in /var/www/squidanalyzer/2016/week03... Mime type statistics in /var/www/squidanalyzer/2016/week03... Network statistics in /var/www/squidanalyzer/2016/week03... Top URL statistics in /var/www/squidanalyzer/2016/week03... Top denied URL statistics in /var/www/squidanalyzer/2016/week03... Top domain statistics in /var/www/squidanalyzer/2016/week03... Cache statistics in /var/www/squidanalyzer/2016/week03... Generating statistics for year 2016 User statistics in /var/www/squidanalyzer/2016... Mime type statistics in /var/www/squidanalyzer/2016... Network statistics in /var/www/squidanalyzer/2016... Top URL statistics in /var/www/squidanalyzer/2016... Top denied URL statistics in /var/www/squidanalyzer/2016... Top domain statistics in /var/www/squidanalyzer/2016... Cache statistics in /var/www/squidanalyzer/2016... DEBUG: generating HTML output took: 1 wallclock secs ( 0.78 usr + 0.14 sys = 0.92 CPU) DEBUG: total execution time: 1 wallclock secs ( 1.22 usr + 0.17 sys = 1.39 CPU)

darold commented 8 years ago

Well I'm a little confused with your installation. SA says:

SQUIDGUARD LOG HISTORY TIME: Tue Jan 12 17:01:52 2016 - HISTORY OFFSET: 1427296

following your previous post, the content of squidguard.current is

1452614512.594 1427296

and the line in your /var/log/squidGuard/squid-bl.log log file at offset 1427296 is :

 2016-01-13 11:46:49 [5376] Request(default/news/-) http://www.msn.com/?ocid=iehp 10.0.21.109/- - GET REDIRECT

The parse give us some relevant debug information:

DEBUG: this file will not be parsed: /var/log/squidGuard/squid-bl.log, size is lower than expected.
DEBUG: exploring /var/log/squidGuard/squid-bl.log, timestamp found at startup, 1438700953, is lower than history time 1452614512.594.

It fisrt says that your log file is smaller or have the same size as 1427296, the offset.

ls -la /var/log/squidGuard/squid-bl.log

must confirm that. In this case, when the size is smaller or equal that the offset, SquidAnalyzer read the first line of the log file to be sure that it is before the last parse date. If timestamp is after the last parsed date it will considere that this is a new file and will process the whole file.

Here this is not the case as we can see in the second line of the debug output, taking the timestamps in the debug report, we can look at more human date using a perl command:

perl -e '$t1=localtime(1438700953); $t2=localtime(1452614512); print "Found: $t1, expected $t2\n";'
Found: Tue Aug  4 17:09:13 2015, expected Tue Jan 12 17:01:52 2016

then August 4th 2015 is before the last parsed date January 12th 2016, so here everything is working as expected.

What I can not explain is why your history file give the right date/offset or at least the same thing that SquidAnalyzer find and the line you'd reported at this offset which have a date in the future of the history timestamps: 2016-01-13 11:46:49

Can you send me the logfile and the history file I will try to reproduce the issue? You can send it to my private email.

mrv84 commented 8 years ago

@darold just sent to you

darold commented 8 years ago

Ok, thanks for the file it save us lot of time. Here is the results of my test.

Last parsed date in SquidGuard.current : 1452707538.747

perl -e '$t=localtime(1452707538); print "$t\n";'
Wed Jan 13 18:52:18 2016

Ok, nothing to say here.

Last parsed offset in SquidGuard.current: 2336616

Log file size:

ls -la squid-bl.log
-rw-rw-r-- 1 gilles gilles 583267 janv. 14 11:32 squid-bl.log

So file size is smaller (583267 bytes) than offset 2336616, SA will read first line of the log file to see if the date is before or after the last parsed date. Here is the first line:

2015-08-04 17:09:13 [2958] Request(desk-user3/social/-) https://twitter.com/ 10.0.21.76/- - GET REDIRECT

So SA behavior is normal and all works as expected. It detect that first line of the log file is older than the history date so this is an old file that must not be parsed.

squid-analyzer -d squid-bl.log
SquidAnalyzer version 6.5
SQUIDGUARD LOG HISTORY TIME: Wed Jan 13 18:52:18 2016 - HISTORY OFFSET: 2336616
Starting to parse logfile squid-bl.log.
DEBUG: this file will not be parsed: squid-bl.log, size is lower than expected.
DEBUG: exploring squid-bl.log, timestamp found at startup, 1438700953, is lower than history time 1452707538.747.
No new log registered...
DEBUG: the log statistics gathering took: 0 wallclock secs ( 0.00 usr +  0.00 sys =  0.00 CPU)
Skipping HTML build.
DEBUG: generating HTML output took: 0 wallclock secs ( 0.00 usr +  0.00 sys =  0.00 CPU)
DEBUG: total execution time: 0 wallclock secs ( 0.00 usr +  0.00 sys =  0.00 CPU)

The problem is to know where do this offset comes from? I don't know, probably it is related to the bug fixes by commit b957d75, but I'm not sure at all.

To solve your current issue you have to replace the offset in the SquidGuard.current with 581712, so the content of the file should be:

1452707538.747  581712

Note that there must be a tabulation between the two numbers.

Here are the parser result after this change:

squid-analyzer -d squid-bl.log
SquidAnalyzer version 6.5
SQUIDGUARD LOG HISTORY TIME: Wed Jan 13 18:52:18 2016 - HISTORY OFFSET: 581712
Starting to parse logfile squid-bl.log.
Reading file squid-bl.log from offset 581712 to end.
Appending data into /var/www/squidanalyzer/2016/01/14
SQUIGUARD LOG END TIME  : Thu Jan 14 09:44:16 2016
Read 15 lines, matched 14 and found 14 new lines
Reordering daily data files now...
Saving data into /var/www/squidanalyzer/2016/01/14
...

We need to know if commit b957d75 has solves this issue, so please warn me if the issue appears again.

Regards,

mrv84 commented 8 years ago

HI @darold and thanks for your support edited the file .current as indicated

but same problem here , squid-bl.log not parsed

[root@localhost ~]# squid-analyzer -d /var/log/squid/access.log /var/log/squidGuard/squid-bl.log SquidAnalyzer version 6.5 SQUID LOG HISTORY TIME: Thu Jan 14 15:13:20 2016 - HISTORY OFFSET: 2833367 SQUIDGUARD LOG HISTORY TIME: Thu Jan 14 15:13:20 2016 - HISTORY OFFSET: 2833367 Starting to parse logfile /var/log/squid/access.log. Reading file /var/log/squid/access.log from offset 2833367 to end. Appending data into /var/www/squidanalyzer/2016/01/14 Starting to parse logfile /var/log/squidGuard/squid-bl.log. DEBUG: this file will not be parsed: /var/log/squidGuard/squid-bl.log, size is lower than expected. DEBUG: exploring /var/log/squidGuard/squid-bl.log, timestamp found at startup, 1438700953, is lower than history time 1452780800.489. SQUID LOG END TIME : Thu Jan 14 15:18:31 2016 SQUIGUARD LOG END TIME : Thu Jan 14 15:18:31 2016 Read 60 lines, matched 58 and found 58 new lines Reordering daily data files now... Saving data into /var/www/squidanalyzer/2016/01/04 Saving data into /var/www/squidanalyzer/2016/01/05 Saving data into /var/www/squidanalyzer/2016/01/06 Saving data into /var/www/squidanalyzer/2016/01/07 Saving data into /var/www/squidanalyzer/2016/01/10 Saving data into /var/www/squidanalyzer/2016/01/11 Saving data into /var/www/squidanalyzer/2016/01/12 Saving data into /var/www/squidanalyzer/2016/01/13 Saving data into /var/www/squidanalyzer/2016/01/14 Generating weekly data files now... Compute and dump weekly statistics for week 03 on 2016 Saving data into /var/www/squidanalyzer/2016/week03 Generating monthly data files now... Compute and dump month statistics for 2016/01 Saving data into /var/www/squidanalyzer/2016/01 Generating yearly data files now... Compute and dump year statistics for 2016 Saving data into /var/www/squidanalyzer/2016 DEBUG: the log statistics gathering took: 0 wallclock secs ( 0.22 usr + 0.02 sys = 0.24 CPU) Building HTML output into /var/www/squidanalyzer Generating statistics for day 2016-01-14 User statistics in /var/www/squidanalyzer/2016/01/14... Mime type statistics in /var/www/squidanalyzer/2016/01/14... Network statistics in /var/www/squidanalyzer/2016/01/14... Top URL statistics in /var/www/squidanalyzer/2016/01/14... Top denied URL statistics in /var/www/squidanalyzer/2016/01/14... Top domain statistics in /var/www/squidanalyzer/2016/01/14... Cache statistics in /var/www/squidanalyzer/2016/01/14... Generating statistics for month 2016-01 User statistics in /var/www/squidanalyzer/2016/01... Mime type statistics in /var/www/squidanalyzer/2016/01... Network statistics in /var/www/squidanalyzer/2016/01... Top URL statistics in /var/www/squidanalyzer/2016/01... Top denied URL statistics in /var/www/squidanalyzer/2016/01... Top domain statistics in /var/www/squidanalyzer/2016/01... Cache statistics in /var/www/squidanalyzer/2016/01... Generating statistics for week 03 on year 2016 User statistics in /var/www/squidanalyzer/2016/week03... Mime type statistics in /var/www/squidanalyzer/2016/week03... Network statistics in /var/www/squidanalyzer/2016/week03... Top URL statistics in /var/www/squidanalyzer/2016/week03... Top denied URL statistics in /var/www/squidanalyzer/2016/week03... Top domain statistics in /var/www/squidanalyzer/2016/week03... Cache statistics in /var/www/squidanalyzer/2016/week03... Generating statistics for year 2016 User statistics in /var/www/squidanalyzer/2016... Mime type statistics in /var/www/squidanalyzer/2016... Network statistics in /var/www/squidanalyzer/2016... Top URL statistics in /var/www/squidanalyzer/2016... Top denied URL statistics in /var/www/squidanalyzer/2016... Top domain statistics in /var/www/squidanalyzer/2016... Cache statistics in /var/www/squidanalyzer/2016... DEBUG: generating HTML output took: 1 wallclock secs ( 0.63 usr + 0.11 sys = 0.74 CPU) DEBUG: total execution time: 1 wallclock secs ( 0.85 usr + 0.13 sys = 0.98 CPU)

darold commented 8 years ago

I think you have not saved the change:

SQUIDGUARD LOG HISTORY TIME: Thu Jan 14 15:13:20 2016 - HISTORY OFFSET: 2833367

as you see history offset is the same, it should be 581712. Like in my test you must have a debug output as follow:

SQUIDGUARD LOG HISTORY TIME: Wed Jan 13 18:52:18 2016 - HISTORY OFFSET: 581712

Regards,

darold commented 8 years ago

Take care that the timestamp has changed in your history file, so you must fix it too.

mrv84 commented 8 years ago

OK @darold edited timestamp and offset and finally i got my top denied menu populated.

but there's many missing data as you can see fron the squid-bl.log i sent to you there are many site reported Now i'll show you what i can see on the squid analyzer top denied menu:

topdenied-error

darold commented 8 years ago

I was thinking that it start to fail on Wed Jan 13 18:52:18 2016, if this is not the case what was the last entry from squid-bl.log that was not imported?

mrv84 commented 8 years ago

squid-bl.log has a first entry on 2015-08-04 17:09:13

seems that were imported only the last 16 entry started from 2016-01-14 09:01:38 ( +3 entry that comes from a test denied specified on squid configuration)

But all the others entry are missing

darold commented 8 years ago

Ok, here how to proceed to recover.

0) make a backup of your /var/www/squidanalyzer/ directory if possible, "shit can happen" 1) copy your squid-bl.log log file: cp /var/log/squidGuard/squid-bl.log /var/log/squidGuard/squid-bl.log.tmp 2) Edit the copy /var/log/squidGuard/squid-bl.log.tmp and remove the line after offset 581712, those starting from January 14th untill now and save the changes. 3) rename your current history file: mv /var/www/squidanalyzer/SquidGuard.current /var/www/squidanalyzer/SquidGuard.current.old 4) run squid-analyzer on the temporary file as follow: squid-analyzer -d /var/log/squidGuard/squid-bl.log.tmp 5) Remove this temporay file rm /var/log/squidGuard/squid-bl.log.tmp 6) Restore your current history file: mv /var/www/squidanalyzer/SquidGuard.current.old /var/www/squidanalyzer/SquidGuard.current

Every thing should be ok in the reports, otherwise try to run squid-analyzer --rebuild to force SquidAnalyzer to reconstruct all reports (it can take a very long time).

darold commented 8 years ago

Sorry i've reedited the previous post because some command was wrong.

mrv84 commented 8 years ago

No problem and always many thanks to you for your support

Executed correctly , we've almost done

summary

The content of top denied

top-denied-ok

but, after some minutes the summary remain the same but the content of top denied were blank. and i need to re execute squid-analyzer -d /var/log/squid/access.log /var/log/squidGuard/squid-bl.log

after that the page content were normally showed

Last anomaly: for the yer 2015 only mime type and network were populated.

2015-mimetype

the Users, top denied, top url, top denied are blank 2015-blankuser

darold commented 8 years ago

Have you executed squid-analyzer with the --rebuild option?

mrv84 commented 8 years ago

yes sure

darold commented 8 years ago

Please send to my private email the result of command:

find /var/www/squidanalyzer/2015/ -name '*.dat
mrv84 commented 8 years ago

update : as indicated before, i made the rebuild at 17.10 now i opended the proxy analyzer that indicated to me a new report generated at 18.05.01 and only summary information were visible. the other content now are blank.

mrv84 commented 8 years ago

@darold
no result for the command that you indicate

[root@localhost www]# find /var/www/squidanalyzer/2015/ -name '*.dat

darold commented 8 years ago

you need to close the quote at the end of the command, sorry for the typo

darold commented 8 years ago

Ok I was afraid that dat files was removed using --preserve option. I'm not able to reproduce the issue, can you run the following command and send me log file result.log

squid-analyzer -d --rebuild > result.log 2>&1

Thanks

darold commented 8 years ago

Last commit df7b0a4 might now solves the issue. There was a major bug that makes SquidGuard.current history file overridden by the content of the main SquidAnalyzer.current history file. Please upgrade.

mrv84 commented 8 years ago

hi @darold i upgraded to the last commit anyway i still have the problem mentioned by mail:

on squid-bl.log i got many many entrys that indicate to me mutiple tentative to :

2016-01-18 15:50:54 [890] Request(default/remote-control/-) http://rl.ammyy.com/ 10.0.21.105/- - POST REDIRECT 2016-01-18 15:51:14 [890] Request(default/remote-control/-) http://rl.ammyy.com/ 10.0.21.105/- - POST REDIRECT 2016-01-18 15:51:34 [890] Request(default/remote-control/-) http://rl.ammyy.com/ 10.0.21.105/- - POST REDIRECT 2016-01-18 15:51:54 [890] Request(default/remote-control/-) http://rl.ammyy.com/ 10.0.21.105/- - POST REDIRECT 2016-01-18 15:52:14 [890] Request(default/remote-control/-) http://rl.ammyy.com/ 10.0.21.105/- - POST REDIRECT 2016-01-18 15:52:34 [890] Request(default/remote-control/-) http://rl.ammyy.com/ 10.0.21.105/- - POST REDIRECT 2016-01-18 15:52:54 [890] Request(default/remote-control/-) http://rl.ammyy.com/ 10.0.21.105/- - POST REDIRECT

that entrys still continue from 18/01 to the current date.

but on proxyanalyzer i can see only

topdenied-ammy

darold commented 8 years ago

I think this is because the content of the denied.dat file contained only one entry. You need to change the content of the SquidGuard.current file to match the line:

2016-01-18 15:51:14 [890] Request(default/remote-control/-) http://rl.ammyy.com/ 10.0.21.105/- - POST REDIRECT

I don't know the offset in your file (edit the file with VI, type g and ctrl+g to obtain the offset then substact 1), for the timestamp, use: 1453128674

Then execute: squid-analyzer squid-bl.log

that should fix the issue.

mrv84 commented 8 years ago

Sorry man i didn't understand what i have to do i have no denied.dat file

darold commented 8 years ago

Sorry I have to be more precise, the name of the file is stat_denied_url.dat

mrv84 commented 8 years ago

@darold for me you can close the issues, everything now is working correctly thanks for your support