Squid and SquidGuard does not start after reboot
-
Here is some more info…
As stated in my previous post my 2 pfsense machines are configured identically. One requires manual restart of squid the other does not.
Here are the system logs at boot for the system that requires the manual restart of squid.
Jun 22 08:25:36 kernel: ppc0: parallel port not found.
Jun 22 08:25:36 kernel: sio0 at port 0x3f8-0x3ff irq 4 flags 0x10 on isa0
Jun 22 08:25:36 kernel: sio0: type 16550A, console
Jun 22 08:25:36 kernel: sio0: [FILTER]
Jun 22 08:25:36 kernel: sio1 at port 0x2f8-0x2ff irq 3 on isa0
Jun 22 08:25:36 kernel: sio1: type 16550A
Jun 22 08:25:36 kernel: sio1: [FILTER]
Jun 22 08:25:36 kernel: Timecounter "TSC" frequency 498054562 Hz quality 800
Jun 22 08:25:36 kernel: Timecounters tick every 10.000 msec
Jun 22 08:25:36 kernel: IPsec: Initialized Security Association Processing.
Jun 22 08:25:36 kernel: ad0: 152627MB <samsung hm160hc="" lq100-10="">at ata0-master PIO4
Jun 22 08:25:36 kernel: Trying to mount root from ufs:/dev/ad0s1a
Jun 22 08:25:36 kernel: glxsb0: <amd geode="" lx="" security="" block="" (aes-128-cbc,="" rng)="">mem 0xefff4000-0xefff7fff irq 9 at
device 1.2 on pci0
Jun 22 08:25:37 kernel: pflog0: promiscuous mode enabled
Jun 22 08:25:46 php: : SQUID is installed but not started. Not installing redirect rules.
Jun 22 08:25:46 php: : SQUID is installed but not started. Not installing redirect rules.
Jun 22 08:25:47 pftpx[481]: listening on 127.0.0.1 port 8021
Jun 22 08:25:47 pftpx[481]: listening on 127.0.0.1 port 8021
Jun 22 08:25:50 dhcpd: Internet Systems Consortium DHCP Server V3.0.7
Jun 22 08:25:50 dhcpd: Copyright 2004-2008 Internet Systems Consortium.
Jun 22 08:25:50 dhcpd: All rights reserved.
Jun 22 08:25:50 dhcpd: For info, please visit http://www.isc.org/sw/dhcp/
Jun 22 08:25:50 dnsmasq[580]: started, version 2.45 cachesize 150
Jun 22 08:25:50 dnsmasq[580]: compile time options: IPv6 GNU-getopt BSD-bridge ISC-leasefile no-DBus no-I18N TFTP
Jun 22 08:25:50 dnsmasq[580]: reading /etc/resolv.conf
Jun 22 08:25:50 dnsmasq[580]: using nameserver 192.168.0.1#53
Jun 22 08:25:50 dnsmasq[580]: read /etc/hosts - 2 addresses
Jun 22 08:25:50 kernel: ipfw2 (+ipv6) initialized, divert loadable, nat loadable, rule-based forwarding enabled,
default to accept, logging disabled
Jun 22 08:25:55 php: : SQUID is installed but not started. Not installing redirect rules.
Jun 22 08:25:55 php: : SQUID is installed but not started. Not installing redirect rules.
Jun 22 08:25:57 php: : Creating rrd update script
Jun 22 08:25:57 dhcpd: Internet Systems Consortium DHCP Server V3.0.7
Jun 22 08:25:57 dhcpd: Copyright 2004-2008 Internet Systems Consortium.
Jun 22 08:25:57 dhcpd: All rights reserved.
Jun 22 08:25:57 dhcpd: For info, please visit http://www.isc.org/sw/dhcp/
Jun 22 08:26:00 php: : Resyncing configuration for all packages.
Jun 22 08:26:02 php: : Reloading Squid for configuration sync
Jun 22 08:26:05 last message repeated 2 times
Jun 22 08:26:06 php: : Starting Squid
Jun 22 08:26:06 squid[1034]: Squid Parent: child process 1037 started
Jun 22 08:26:08 php: : Reloading Squid for configuration sync
Jun 22 08:26:10 last message repeated 2 times
Jun 22 08:26:11 check_reload_status: check_reload_status is starting
Jun 22 08:26:11 check_reload_status: rc.newwanip starting
Jun 22 08:26:14 login: login on console as root
Jun 22 08:26:18 php: : Informational: rc.newwanip is starting vr1.
Jun 22 08:26:18 php: : rc.newwanip working with (IP address: 192.168.0.4) (interface: wan) (interface real: vr1).
Jun 22 08:29:32 sshd[1633]: Accepted keyboard-interactive/pam for admin from 192.168.10.199 port 59703 ssh2
Jun 22 08:30:31 php[530]: /pkg_edit.php: Reloading Squid for configuration sync
Jun 22 08:30:34 check_reload_status: reloading filterHere are the logs for the system that works automatically…
Jun 22 08:02:50 kernel: acpi_throttle0: <acpi cpu="" throttling="">on cpu0
Jun 22 08:02:50 kernel: pmtimer0 on isa0
Jun 22 08:02:50 kernel: orm0: <isa option="" roms="">at iomem 0xc0000-0xc7fff,0xc8000-0xc8fff,0xc9000-0xc9fff,0xdc000-0xdffff,0xe0000-0xe3fff pnpid ORM0000 on isa0
Jun 22 08:02:50 kernel: sc0: <system console="">at flags 0x100 on isa0
Jun 22 08:02:50 kernel: sc0: VGA <16 virtual consoles, flags=0x300>
Jun 22 08:02:50 kernel: vga0: <generic isa="" vga="">at port 0x3c0-0x3df iomem 0xa0000-0xbffff on isa0
Jun 22 08:02:50 kernel: Timecounter "TSC" frequency 2659711266 Hz quality 800
Jun 22 08:02:50 kernel: Timecounters tick every 10.000 msec
Jun 22 08:02:50 kernel: IPsec: Initialized Security Association Processing.
Jun 22 08:02:50 kernel: ad0: 8192MB <vmware virtual="" ide="" hard="" drive="" 00000001="">at ata0-master UDMA33
Jun 22 08:02:50 kernel: acd0: CDROM <vmware virtual="" ide="" cdrom="" drive="" 00000001="">at ata1-master UDMA33
Jun 22 08:02:50 kernel: Waiting 5 seconds for SCSI devices to settle
Jun 22 08:02:50 kernel: Trying to mount root from ufs:/dev/ad0s1a
Jun 22 08:02:50 kernel: pflog0: promiscuous mode enabled
Jun 22 08:02:50 php: : SQUID is installed but not started. Not installing redirect rules.
Jun 22 08:02:50 php: : SQUID is installed but not started. Not installing redirect rules.
Jun 22 08:02:50 pftpx[478]: listening on 127.0.0.1 port 8021
Jun 22 08:02:50 pftpx[478]: listening on 127.0.0.1 port 8021
Jun 22 08:02:52 dhcpd: Internet Systems Consortium DHCP Server V3.0.7
Jun 22 08:02:52 dhcpd: Copyright 2004-2008 Internet Systems Consortium.
Jun 22 08:02:52 dhcpd: All rights reserved.
Jun 22 08:02:52 dhcpd: For info, please visit http://www.isc.org/sw/dhcp/
Jun 22 08:02:52 dnsmasq[573]: started, version 2.45 cachesize 150
Jun 22 08:02:52 dnsmasq[573]: compile time options: IPv6 GNU-getopt BSD-bridge ISC-leasefile no-DBus no-I18N TFTP
Jun 22 08:02:52 dnsmasq[573]: reading /etc/resolv.conf
Jun 22 08:02:52 dnsmasq[573]: using nameserver 192.168.0.1#53
Jun 22 08:02:52 dnsmasq[573]: read /etc/hosts - 2 addresses
Jun 22 08:02:52 kernel: ipfw2 (+ipv6) initialized, divert loadable, nat loadable, rule-based forwarding enabled, default to accept, logging disabled
Jun 22 08:02:54 php: : SQUID is installed but not started. Not installing redirect rules.
Jun 22 08:02:54 php: : SQUID is installed but not started. Not installing redirect rules.
Jun 22 08:02:55 php: : Creating rrd update script
Jun 22 08:02:55 dhcpd: Internet Systems Consortium DHCP Server V3.0.7
Jun 22 08:02:55 dhcpd: Copyright 2004-2008 Internet Systems Consortium.
Jun 22 08:02:55 dhcpd: All rights reserved.
Jun 22 08:02:55 dhcpd: For info, please visit http://www.isc.org/sw/dhcp/
Jun 22 08:02:55 php: : Resyncing configuration for all packages.
Jun 22 08:02:56 php: : Reloading Squid for configuration sync
Jun 22 08:02:57 last message repeated 6 times
Jun 22 08:02:57 check_reload_status: check_reload_status is starting
Jun 22 08:02:57 squid[968]: Squid Parent: child process 971 started
Jun 22 08:02:57 check_reload_status: rc.newwanip starting
Jun 22 08:02:58 login: login on ttyv0 as root
Jun 22 08:02:58 php: : Informational: rc.newwanip is starting em0.
Jun 22 08:02:59 php: : rc.newwanip working with (IP address: 192.168.0.9) (interface: wan) (interface real: em0).
Jun 22 08:03:02 Squid_Alarm[1101]: Squid has exited. Reconfiguring filter.
Jun 22 08:03:02 Squid_Alarm[1103]: Attempting restart…
Jun 22 08:03:02 squid[1110]: Squid Parent: child process 1113 started
Jun 22 08:03:05 Squid_Alarm[1117]: Reconfiguring filter…
Jun 22 08:03:06 Squid_Alarm[1194]: Squid has resumed. Reconfiguring filter.
Jun 22 08:04:48 sshd[1383]: Accepted keyboard-interactive/pam for admin from 192.168.0.101 port 60639 ssh2so notice the following… in the system that works late in the boot process we see that when rc.newwanip runs Squid has an alarm which causes it to restart...
Jun 22 08:02:59 php: : rc.newwanip working with (IP address: 192.168.0.9) (interface: wan) (interface real: em0).
Jun 22 08:03:02 Squid_Alarm[1101]: Squid has exited. Reconfiguring filter.
Jun 22 08:03:02 Squid_Alarm[1103]: Attempting restart…the system that requires the manual restart does not exhibit this behavior.
Jun 22 08:26:18 php: : rc.newwanip working with (IP address: 192.168.0.4) (interface: wan) (interface real: vr1).
Jun 22 08:29:32 sshd[1633]: Accepted keyboard-interactive/pam for admin from 192.168.10.199 port 59703 ssh2
Jun 22 08:30:31 php[530]: /pkg_edit.php: Reloading Squid for configuration sync
Jun 22 08:30:34 check_reload_status: reloading filterSo maybe what should happen after rc.newwanip runs is that squid should be restarted and ** NOT ** reload from a configuration sync that was done prior to assignment of the wan IP ???!??!?
I don't currently know enough about squid and its startup sequence to know if the above observation is related or not to the problem. I will see if I can figure out how to restart squid after rc.newwanip to see if that makes any difference.
comments anyone?
–luis</vmware></vmware></generic></system></isa></acpi></amd></samsung>
-
It may be a timing issue somehow. I setup squid on my ALIX on 1.2.3 and it works - but I am using a wireless WAN, which is slower to get an IP than DHCP or PPPoE would be.
During boot, I also get:
Jun 22 17:23:49 pfSense php: : SQUID is installed but not started. Not installing redirect rules. Jun 22 17:23:49 pfSense php: : SQUID is installed but not started. Not installing redirect rules.
but a few moments after rc.newwanip is run, the redirect rule is present and the proxy works.
I do not see squid restart anywhere near rc.newwanip, either.
It would be interesting to know one more thing: You said squid was running, but I'd like to know if the NAT redirect rule is actually there.
Just after a reboot, drop to a shell prompt and then run the following:
# pfctl -sn | grep http
If squid's redirect rule is present, you should get a line like this:
rdr on vr0 inet proto tcp from any to ! (vr0) port = http -> 127.0.0.1 port 80
If that line is not there, it would explain why the proxy appears to be non-functional.
-
Probably this is a HAVP package message. If squid not running - HAVP giu not use redirect rules (rdr to squid).
Jun 22 17:23:49 pfSense php: : SQUID is installed but not started. Not installing redirect rules.
-
Probably this is a HAVP package message. If squid not running - HAVP giu not use redirect rules (rdr to squid).
Jun 22 17:23:49 pfSense php: : SQUID is installed but not started. Not installing redirect rules.
No, it's from squid, it's just that the filter.inc reload tries to grab the rules before squid is running on ALIX. It's ok, it happens a few seconds later and it's fine. Nothing to worry about in most cases. HAVP is not involved.
-
Putting squidguard into this mix on ALIX definitely isn't quite right at boot time though. I've got some fixes I just committed to squidguard which makes that combination work OK for me on reboot.
Try to reinstall squid and squidguard, double check your settings, and then try again.
If you are running on CF in that ALIX, under squid's cache management, be sure to choose the null type for the cache, that way it won't fill up your /var memory disk with cache data and bomb out, too.
-
It may be a timing issue somehow. I setup squid on my ALIX on 1.2.3 and it works - but I am using a wireless WAN, which is slower to get an IP than DHCP or PPPoE would be.
Just after a reboot, drop to a shell prompt and then run the following:
# pfctl -sn | grep http
If squid's redirect rule is present, you should get a line like this:
rdr on vr0 inet proto tcp from any to ! (vr0) port = http -> 127.0.0.1 port 80
If that line is not there, it would explain why the proxy appears to be non-functional.
OK. so here is a clean sequence.
1. uninstalled squid (and all squid packages)
2. installed squid and configured it. (it is currently the only package installed. squidGuard is not installed.)
3. made sure squid worked correctly.
4. rebooted the system and go the following in syslogJun 22 20:11:29 webxaccelerator php: : SQUID is installed but not started. Not installing redirect rules.
Jun 22 20:11:29 webxaccelerator php: : SQUID is installed but not started. Not installing redirect rules.Jun 22 20:11:34 webxaccelerator kernel: ipfw2 (+ipv6) initialized, divert loadable, nat loadable, rule-based forwarding enabled, default to accept, logging disabled
Jun 22 20:11:38 webxaccelerator php: : SQUID is installed but not started. Not installing redirect rules.
Jun 22 20:11:38 webxaccelerator php: : SQUID is installed but not started. Not installing redirect rules.Jun 22 20:11:43 webxaccelerator php: : Resyncing configuration for all packages.
Jun 22 20:11:45 webxaccelerator php: : Reloading Squid for configuration sync
Jun 22 20:11:48 webxaccelerator last message repeated 2 times
Jun 22 20:11:49 webxaccelerator php: : Starting Squid
Jun 22 20:11:49 webxaccelerator squid[1017]: Squid Parent: child process 1019 started
Jun 22 20:11:50 webxaccelerator php: : Reloading Squid for configuration sync
Jun 22 20:11:52 webxaccelerator last message repeated 2 times
Jun 22 20:12:00 webxaccelerator php: : Informational: rc.newwanip is starting vr1.
Jun 22 20:12:00 webxaccelerator php: : rc.newwanip working with (IP address: 192.168.0.4) (interface: wan) (interface real: vr1).the rc.newwanip is the last thing in the log file…
5. here is the output for
pfctl -sn | grep http
i.e. nada.. zip... no rule!
6. then i do a
killall -TERM squid
ps aux | grep squid
7. we now wait for proxy_monitor.sh to span a new squid... and here it is
ps aux | grep squid
root 1687 0.0 1.5 7196 3700 ?? Ss 8:16PM 0:00.00 /usr/local/sbin/squid -D
proxy 1690 0.0 3.9 15388 9772 ?? S 8:16PM 0:00.17 (squid) -D (squid)
root 1847 0.0 0.1 376 256 p0 R+ 8:16PM 0:00.00 grep squid8. the output of pfctl now shows...
pfctl -sn | grep http
rdr on vr0 inet proto tcp from any to ! (vr0) port = http -> 127.0.0.1 port 80
9. we confirm that indeed the proxy service is now working as it should be looking at /var/squid/log/access
so the pf rule is not getting installed which is why the proxy service is not working.
I currently have WAN IP set to DHCP so it takes a bit of time to get the IP address of the WAN.
does anyone know how to control the order of execution of the startup scripts? i have been looking but no luck.
so the $64,000 question is.... why is the rule not getting created?
I look forward to your response.
-
In your boot log, it did try to add the NAT rule – twice.
Jun 22 20:11:29 webxaccelerator php: : SQUID is installed but not started. Not installing redirect rules. Jun 22 20:11:29 webxaccelerator php: : SQUID is installed but not started. Not installing redirect rules. [...] Jun 22 20:11:38 webxaccelerator php: : SQUID is installed but not started. Not installing redirect rules. Jun 22 20:11:38 webxaccelerator php: : SQUID is installed but not started. Not installing redirect rules.
There is one each for the NAT and firewall rules. So it tried twice but since at the time that was run, the squid process was not running, it didn't add the rule. I looked at my boot log again and I also see the same two sets of two lines. For me, it shows up shortly after the rc.newwanip run finishes. Not sure why that might be different in your case, except that my WAN is wireless which would be even slower than DHCP alone.
However, the missing NAT rule is the real problem, and should be easier to fix or patch around.
-
OK. so what I think you are telling me is that squid is starting up too late. In other words there is no squid process running when the NAT rules was going to be installed… However, squid is spawned later on but for some reason the redirect rule was not installed then.
Later on when squid is manually killed with "killall -TERM squid" followed by a /usr/local/etc/rc.d/squid.sh start (executed by the proxy_monitor) then rule is reinstalled. the rule is probably installed by /etc/rc.filter_configure_sync executed from within the body of the proxy_monitor.
if [ $NUM_PROCS -lt 1 ]; then
# squid is down
echo "Squid has exited. Reconfiguring filter." |
logger -p daemon.info -i -t Squid_Alarm
echo "Attempting restart…" | logger -p daemon.info -i -t Squid_Alarm
/usr/local/etc/rc.d/squid.sh start
sleep 3
echo "Reconfiguring filter..." | logger -p daemon.info -i -t Squid_Alarm
/etc/rc.filter_configure_sync
touch /var/run/squid_alarm
fiso maybe the solution is as simple as running /etc/rc.filter_configure_sync after boot? let me reboot and try that manually.
so... that works!
pfctl -sn| grep http
/etc/rc.filter_configure_sync
!p
pfctl -sn | grep http
rdr on vr0 inet proto tcp from any to ! (vr0) port = http -> 127.0.0.1 port 80how would I arrange to have /etc/rc.filter_configure_sync executed as the last thing in the boot sequence?
--luis
-
That's the thing – it should be run there already, and again in rc.newwanip. But I may need to make the equivalent PHP code run at the end of the squid package sync routine.
I'm working on getting that updated.It's already run there. Maybe it just needs to sleep a little first.Can you open /usr/local/pkg/squid.inc, go to line 1128 or so, and find this line:
filter_configure();
And make it this:
// Sleep for a couple seconds to give squid a chance to fire up fully. sleep(5); filter_configure();
-
OK. I will give that a try right away…
in the mean time I have fixed the issue by adding following ugly hack to /etc/rc.newwanip
line 65: exec("/etc/rc.filter_configure_sync");
so the code now looks like
log_error("rc.newwanip working with (IP address: {$curwanip}) (interface: {$interface}) (interface real: {$interface_real}).");
if($curwanip == "0.0.0.0") {
log_error("Failed to update WAN IP, restarting dhclient.");
exec("dhclient $interface_real");
exit;
}exec("/etc/rc.filter_configure_sync");
and the nat rule is in place after reboot
pfctl -sn | grep http
rdr on vr0 inet proto tcp from any to ! (vr0) port = http -> 127.0.0.1 port 80
Your solution is ** MUCH NICER **... let me try it....
Nope... that did not work.
pfctl -sn | grep http
here is the full system log
Jun 22 21:12:05 webxaccelerator kernel: cpu0 on motherboard
Jun 22 21:12:05 webxaccelerator kernel: orm0: <isa option="" rom="">at iomem 0xe0000-0xea7ff pnpid ORM0000 on isa0
Jun 22 21:12:05 webxaccelerator kernel: ppc0: parallel port not found.
Jun 22 21:12:05 webxaccelerator kernel: sio0 at port 0x3f8-0x3ff irq 4 flags 0x10 on isa0
Jun 22 21:12:05 webxaccelerator kernel: sio0: type 16550A, console
Jun 22 21:12:05 webxaccelerator kernel: sio0: [FILTER]
Jun 22 21:12:05 webxaccelerator kernel: sio1 at port 0x2f8-0x2ff irq 3 on isa0
Jun 22 21:12:05 webxaccelerator kernel: sio1: type 16550A
Jun 22 21:12:05 webxaccelerator kernel: sio1: [FILTER]
Jun 22 21:12:05 webxaccelerator kernel: Timecounter "TSC" frequency 498054727 Hz quality 800
Jun 22 21:12:05 webxaccelerator kernel: Timecounters tick every 10.000 msec
Jun 22 21:12:05 webxaccelerator kernel: IPsec: Initialized Security Association Processing.
Jun 22 21:12:05 webxaccelerator kernel: ad0: 152627MB <samsung hm160hc="" lq100-10="">at ata0-master PIO4
Jun 22 21:12:05 webxaccelerator kernel: Trying to mount root from ufs:/dev/ad0s1a
Jun 22 21:12:05 webxaccelerator kernel: glxsb0: <amd geode="" lx="" security="" block="" (aes-128-cbc,="" rng)="">mem 0xefff4000-0xefff7fff irq 9 at device 1.2 on pci0
Jun 22 21:12:06 webxaccelerator kernel: pflog0: promiscuous mode enabled
Jun 22 21:12:15 webxaccelerator php: : SQUID is installed but not started. Not installing redirect rules.
Jun 22 21:12:15 webxaccelerator php: : SQUID is installed but not started. Not installing redirect rules.
Jun 22 21:12:16 webxaccelerator pftpx[481]: listening on 127.0.0.1 port 8021
Jun 22 21:12:16 webxaccelerator pftpx[481]: listening on 127.0.0.1 port 8021
Jun 22 21:12:19 webxaccelerator dhcpd: Internet Systems Consortium DHCP Server V3.0.7
Jun 22 21:12:19 webxaccelerator dhcpd: Copyright 2004-2008 Internet Systems Consortium.
Jun 22 21:12:19 webxaccelerator dhcpd: All rights reserved.
Jun 22 21:12:19 webxaccelerator dhcpd: For info, please visit http://www.isc.org/sw/dhcp/
Jun 22 21:12:19 webxaccelerator dnsmasq[580]: started, version 2.45 cachesize 150
Jun 22 21:12:19 webxaccelerator dnsmasq[580]: compile time options: IPv6 GNU-getopt BSD-bridge ISC-leasefile no-DBus no-I18N TFTP
Jun 22 21:12:19 webxaccelerator dnsmasq[580]: reading /etc/resolv.conf
Jun 22 21:12:19 webxaccelerator dnsmasq[580]: using nameserver 192.168.0.1#53
Jun 22 21:12:19 webxaccelerator dnsmasq[580]: read /etc/hosts - 2 addresses
Jun 22 21:12:19 webxaccelerator kernel: ipfw2 (+ipv6) initialized, divert loadable, nat loadable, rule-based forwarding enabled, default to accept, logging disabled
Jun 22 21:12:24 webxaccelerator php: : SQUID is installed but not started. Not installing redirect rules.
Jun 22 21:12:24 webxaccelerator php: : SQUID is installed but not started. Not installing redirect rules.
Jun 22 21:12:25 webxaccelerator php: : Creating rrd update script
Jun 22 21:12:26 webxaccelerator dhcpd: Internet Systems Consortium DHCP Server V3.0.7
Jun 22 21:12:26 webxaccelerator dhcpd: Copyright 2004-2008 Internet Systems Consortium.
Jun 22 21:12:26 webxaccelerator dhcpd: All rights reserved.
Jun 22 21:12:26 webxaccelerator dhcpd: For info, please visit http://www.isc.org/sw/dhcp/
Jun 22 21:12:28 webxaccelerator php: : Resyncing configuration for all packages.
Jun 22 21:12:31 webxaccelerator php: : Reloading Squid for configuration sync
Jun 22 21:12:38 webxaccelerator php: : Starting Squid
Jun 22 21:12:38 webxaccelerator squid[958]: Squid Parent: child process 960 started
Jun 22 21:12:44 webxaccelerator php: : Reloading Squid for configuration sync
Jun 22 21:13:09 webxaccelerator last message repeated 4 times
Jun 22 21:13:15 webxaccelerator check_reload_status: check_reload_status is starting
Jun 22 21:13:15 webxaccelerator check_reload_status: rc.newwanip starting
Jun 22 21:13:18 webxaccelerator login: login on console as root
Jun 22 21:13:24 webxaccelerator php: : Informational: rc.newwanip is starting vr1.
Jun 22 21:13:25 webxaccelerator php: : rc.newwanip working with (IP address: 192.168.0.4) (interface: wan) (interface real: vr1).and here is the mod to squid.inc
sleep(5);
filter_configure();What else could be happening?
–luis</amd></samsung></isa>
-
I'll have to run some more tests tomorrow to see if I can figure out what is going wrong. You could experiment with different sleep values, maybe up to 30 seconds or so, as a test. I went ahead and committed the 5 second sleep to the package just in case it worked.
-
hm… shouldn't line 1128 of /usr/local/pkg/squid.inc be calling
filter_configure_sync() instead of filter_configure()?
i just looked at the code or filter_configure in /etc/inc/filter.inc and it doesn't look like does much... It basically touches /tmp/filter_dirty and then exits...
when does filter_configure_sync() get called?
I just replaced the call to filter_configure() with filter_configure_sync() in squid.inc and guess what... that seems to work.
pfctl -sn | grep http
rdr on vr0 inet proto tcp from any to ! (vr0) port = http -> 127.0.0.1 port 80
Does this work for you?
--luis
-
Not sure offhand, but if it works, I'll commit it.I was informed that is a Very Bad Thing to do, since it can get you stuck in a loop.I'll investigate it further tomorrow, but at least there is a lead.
-
well it works for me… i assume it will work for you as well since it seems to be a fairly innocuous function. I just cant see how filter_configure() ever worked since the all the work is done in filter_configure_sync(). It seems that filter_configure() just flags the fact that changes to the filter rules need to be synced and then expects some other process to detect this and then do the job.
Anyway, am not familiar with the code enough to know if there are other repercussions to making the change. You would be a better judge of this. On the surface, however, it looks like the right thing to do.
Thanks for all your help. Unless I hear from you I assume that this issue is now closed.
take care.
--luis
-
That is the difference. filter_configure_sync() is synchronous - it does it right then and there and you wait on it. The other method waits on a periodic process to pick up the flag file and run with it.
-
Not sure offhand, but if it works, I'll commit it.I was informed that is a Very Bad Thing to do, since it can get you stuck in a loop.I'll investigate it further tomorrow, but at least there is a lead.
OK. let me know if you need help. I certainly have a system here that can reproduce the problem very reliably.
Is the "VERY BAD THING" caused by the possibility of having two filter_configure_syn() happening at the same time?
–luis
-
That seemed to be the case, but I don't know the specifics in detail.
I'll work on it more tomorrow and see what I can come up with.
-
Now to make things even more strange, I cannot reproduce the problem at all.
I uninstalled and reinstalled both squid and squidguard last night, and now when I reboot the rule is there, and I'm not using any locally modified code. I even switched slices and tried it again, and it came up with the rule intact.
Does it still happen for you if you uninstall and reinstall squid now?
I made a couple changes to the pkg last night but nothing that should have affected this.
Jim
-
Now to make things even more strange, I cannot reproduce the problem at all.
I uninstalled and reinstalled both squid and squidguard last night, and now when I reboot the rule is there, and I'm not using any locally modified code. I even switched slices and tried it again, and it came up with the rule intact.
Does it still happen for you if you uninstall and reinstall squid now?
I made a couple changes to the pkg last night but nothing that should have affected this.
Jim
i booted my system with the manually modified /usr/local/pkg/squid.inc with the change where filter_configure() was replaced with filter_configure_sync() and confirmed that the http redirect rule was in place.
then i uninstalled squid (So there are 0 packages on the system now) and rebooted.
then i checked for the rule… its not there.
pfctl -sn | grep http
the system logs look clean and the boot console shows no errors.
next I installed squid and started the service and noticed that the rule was in place.
pfctl -sn | grep http
rdr on vr0 inet proto tcp from any to ! (vr0) port = http -> 127.0.0.1 port 80
after reboot i get
pfctl -sn | grep http
rdr on vr0 inet proto tcp from any to ! (vr0) port = http -> 127.0.0.1 port 80
so... the rule is in place.
i did notice that the boot sequence now takes a lot longer than it did before. During the Syncing packages line each squid module takes a long time... Here is what I have
Syncing packges: squid squidcache squidmac squid squidtraffic squidupstream squidauth squidusers
So is the delay caused by a full filter_configure_sync for each one? ah... i see that you have the sleep(5) in there. let me take that out to see what happens...
so... when the sleep(5) is removed the boot up sequence is much faster.. as expected.
** BUT **
pfctl -sn | grep http
the rule is gone.
I really don't like the sleep solution.... there is obviously some race condition happening here which is being addressed by slowing down the config process. Having a random sleep is just asking for problems down the road.
anyway, replacing filter_configure() with filter_configure_sync()works for me. Are you sure this is not the answer? the book sequence is fast (maybe a little slower than using filter_configure() but not noticeably so) and it works...
pfctl -sn | grep http
rdr on vr0 inet proto tcp from any to ! (vr0) port = http -> 127.0.0.1 port 80
I look forward to your thoughts.
--luis
-
Given the warnings I was given about not using filter_configure_sync() in that way, the sleep() solution is better. The reason the rule isn't present was because they were trying to add the rules too quickly after squid was told to start up.
If you look in the code, the squid launch process is done using mwexec_bg() which will fork a background process, which will cause a race with whatever code is next, the sleep induces a delay before reconfiguring the filter, which seems to make it work.
Though I swear I tried it yesterday with that sleep() and it didn't make a difference.
I have a couple more ideas, though:
- Remove the sleep, and change mwexec_bg() for squid to mwexec() on line 1123 which may avoid the race.
- Loop a couple times and only sleep for a second or two if squid is not running. That way it doesn't proceed until the process is found, or breaks out if it's not running after a few seconds (5, 10, whatever).