Problem SquidGuard + Blacklist updates - Filter Fails after update script
-
Version - Current Full AMD64 2.02 on PC.
I have been having difficultly with my Squidguard where is stops operating every morning. The symptom was that the Squidguard filters seem to be ignored regardless of transparent proxy or regular proxy (port:3128).
What I found was that I am using this short script on cron to update my blacklist from shalla each morning at 4:04am.
–-------------
4 4 * * * /usr/local/bin/squidGuard_blacklist_update.sh#!/usr/local/bin/php -f
$incl = "/usr/local/pkg/squidguard_configurator.inc";
if (file_exists($incl)) {
require_once($incl);
sg_reconfigure_blacklist( "http://www.shallalist.de/Downloads/shallalist.tar.gz", "" );
}
exit;
?>
But, this shows up in the squidguard cache.log when the update runs:
2013/02/22 04:05:34| Reconfiguring Squid Cache (version 2.7.STABLE9)...
2013/02/22 04:05:34| FD 48 Closing HTTP connection
2013/02/22 04:05:34| FD 49 Closing HTTP connection
2013/02/22 04:05:34| FD 50 Closing HTCP socket
2013/02/22 04:05:34| FD 62 Closing SNMP socket
2013/02/22 04:05:34| logfileClose: closing log /var/squid/logs/access.log
2013/02/22 04:05:34| Including Configuration File: /usr/local/etc/squid/squid.conf (depth 0)
2013/02/22 04:05:34| Cache dir '/var/squid/cache' size remains unchanged at 102400000 KB
2013/02/22 04:05:34| WARNING: use of 'override-expire' in 'refresh_pattern' violates HTTP
2013/02/22 04:05:34| WARNING: use of 'override-lastmod' in 'refresh_pattern' violates HTTP
2013/02/22 04:05:34| WARNING: HTTP requires the use of Via
2013/02/22 04:05:34| Initialising SSL.
2013/02/22 04:05:34| logfileOpen: opening log /var/squid/logs/access.log
2013/02/22 04:05:34| Store logging disabled
2013/02/22 04:05:34| Referer logging is disabled.
2013/02/22 04:05:34| DNS Socket created at 0.0.0.0, port 28875, FD 12
2013/02/22 04:05:34| Adding nameserver 10.1.1.49 from squid.conf
2013/02/22 04:05:34| Adding nameserver 10.1.1.48 from squid.conf
2013/02/22 04:05:34| helperOpenServers: Starting 25 'squidGuard' processes
2013-02-22 04:05:36 [12985] (squidGuard): can't write to logfile /var/log/squidGuard.log
2013-02-22 04:05:36 [12985] New setting: logdir: /var/squidGuard/log
2013-02-22 04:05:36 [12985] New setting: dbhome: /var/db/squidGuard
2013-02-22 04:05:36 [12985] init domainlist /var/db/squidGuard/blk_BL_adv/domains
2013-02-22 04:05:36 [12985] loading dbfile /var/db/squidGuard/blk_BL_adv/domains.db
2013-02-22 04:05:36 [12985] Error db_open: Permission denied
2013-02-22 04:05:36 [12985] Going into emergency mode
….
....this is repeated several times before giving up
.....
2013/02/22 04:05:54| Accepting proxy HTTP connections at 10.1.1.5, port 3128, FD 47.
2013/02/22 04:05:54| Accepting transparently proxied HTTP connections at 127.0.0.1, port 3128, FD 48.
2013/02/22 04:05:54| Accepting HTCP messages on port 4827, FD 49.
2013/02/22 04:05:54| Accepting SNMP messages on port 3401, FD 50.
2013/02/22 04:05:54| WCCP Disabled.
2013-02-22 04:05:55 [16800] (squidGuard): can't write to logfile /var/log/squidGuard.log
2013-02-22 04:05:55 [16800] New setting: logdir: /var/squidGuard/log
2013-02-22 04:05:55 [16800] New setting: dbhome: /var/db/squidGuard
2013-02-22 04:05:55 [16800] init domainlist /var/db/squidGuard/blk_BL_adv/domains
2013-02-22 04:05:55 [16800] loading dbfile /var/db/squidGuard/blk_BL_adv/domains.db
2013-02-22 04:05:55 [16800] Error db_open: Permission denied
2013-02-22 04:05:55 [16800] Going into emergency mode
2013/02/22 04:05:54| Loaded Icons.
2013/02/22 04:05:54| Ready to serve requests.
–----------------Until I go into the Proxy filter screen and click "Apply" to get squidguard to try to reload, then squidguard is not filtering anything. Clicking apply is all that is needed and all of the errors seem to be caused by the fact that the update script has deleted the db files in question. It is not a permission issue.... the files are simply not there between the time that the new list completes it's download until the update finishes rebuilding the db's.
So, the question is - what is the best way to "kick" squidguard via the commandline so that I can modify the update script or cron a SG reset for a few minutes after the blacklist update so that it resumes filtering.
On my system (AMD Athlonx64 4400), the download takes about 60-90 seconds and the file rebuild takes another roughly 30 seconds. So, these errors appear to occur only in the last few seconds of the process.
-
I also found this in the system.log
Feb 25 04:04:00 vfw-ka-nat1 php: : The command 'chown -R -v proxy /var/squidGuard/log' returned exit code '127', the output was ''
Feb 25 04:04:00 vfw-ka-nat1 php: : The command 'chown -R -v proxy /var/db/squidGuard' returned exit code '127', the output was ''
Feb 25 04:04:23 vfw-ka-nat1 php: : The command 'umount -f /tmp/squidGuard' returned exit code '127', the output was ''
Feb 25 04:04:24 vfw-ka-nat1 php: : The command 'mdconfig -d -u 15' returned exit code '127', the output was ''
Feb 25 04:04:24 vfw-ka-nat1 php: : The command 'umount -f /tmp/squidGuard' returned exit code '127', the output was ''
Feb 25 04:04:25 vfw-ka-nat1 php: : The command 'mdconfig -d -u 15' returned exit code '127', the output was ''
Feb 25 04:04:25 vfw-ka-nat1 php: : The command '/sbin/mdmfs -s 300M md15 /tmp/squidGuard' returned exit code '1', the output was 'mdmfs: mdconfig (attach) exited with error code 1'
Feb 25 04:04:26 vfw-ka-nat1 php: : The command 'chown -R -v proxy /tmp/squidGuard/unpack' returned exit code '127', the output was ''
Feb 25 04:04:26 vfw-ka-nat1 php: : The command 'chown -R -v proxy /tmp/squidGuard/arcdb' returned exit code '127', the output was ''
Feb 25 04:04:26 vfw-ka-nat1 php: : The command 'chown -R -v proxy /tmp/squidGuard/arcdb/blacklist.files' returned exit code '127', the output was ''
Feb 25 04:04:26 vfw-ka-nat1 php: : The command 'chown -R -v proxy /usr/local/etc/squidGuard/blacklist.files' returned exit code '127', the output was ''
Feb 25 04:04:26 vfw-ka-nat1 php: : The command 'chown -R -v proxy /usr/local/etc/squidGuard/squidGuard_blk_rebuild.conf' returned exit code '127', the output was ''
Feb 25 04:05:27 vfw-ka-nat1 php: : The command 'chown -R -v proxy /tmp/squidGuard/arcdb' returned exit code '127', the output was ''
Feb 25 04:05:32 vfw-ka-nat1 php: : The command 'chown -R -v proxy /var/db/squidGuard' returned exit code '127', the output was ''
Feb 25 04:05:32 vfw-ka-nat1 php: : The command 'umount -f /tmp/squidGuard' returned exit code '127', the output was ''
Feb 25 04:05:33 vfw-ka-nat1 php: : The command 'mdconfig -d -u 15' returned exit code '127', the output was '' -
Ping - still need help on this.
-
I think you missed something or you do a step in the wrong way.
A tutorial:
http://seraphyn.teiko.org/archives/pfsense-squidguard-blacklistupdate-mit-cron.htmlHave an eye on the cron time format!
The easiest way is to install the cron package and configure it under Service - Cron like the attachement:
-
Thank you for the suggestion, but the tutorial shown is EXACTLY the script and method that I am already using.
The problem is that near the end of the process, squidguard dies with these errors:
2013-02-22 04:05:36 [12985] loading dbfile /var/db/squidGuard/blk_BL_adv/domains.db
2013-02-22 04:05:36 [12985] Error db_open: Permission denied
2013-02-22 04:05:36 [12985] Going into emergency modeThere is another issue with timed schedules failing to change, but calling squid -k reconfigure via a cron job will result in the new filter settings taking effect. However, this does NOT fix SquidGuard in emergency mode. I must manually click on "Apply" in the Proxy Filter settings page.
I am not sure why other people do not have this problem. Perhaps, squidguard only retries X number of times and my disk drive is too slow and does not finish quickly enough. It is an older system, (AMD Athlon 4400+ with 5400rpm IDE drive), but it should still be faster than most embedded systems.
-
I have done the tutorial on the post blog-post. Without troubles.
There is also a step that you have to change the access with chmod
Did you do that? -
The chmod line merely makes the script executable by everyone. I am not having a problem with the script running. By looking at the timestamps, it appears that the error happens 10-15 seconds prior to the completion of the script. By watching the files, I see that that first a download starts and completes. Then, a snapshot of the existing blacklist directories are created. Followed by expanding the archive file into the blacklist directories (or maybe into the snapshot, I am not sure which). Finally, the snapshot is released.
I think the error starts during the time that the snapshot is created and mounted. The last parts happen rather quickly and it is hard to manually follow the processes.
-
I am concerned about the "Exit Code 127" errors. I cannot find a definition for that error and I have tried running the commands by hand, but do not get those errors.