[Bug 195362] New: Strange behavior of squid during his restart on 10.1 release

bugzilla-noreply at freebsd.org bugzilla-noreply at freebsd.org
Tue Nov 25 08:23:51 UTC 2014


https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=195362

            Bug ID: 195362
           Summary: Strange behavior of squid during his restart on 10.1
                    release
           Product: Base System
           Version: 10.1-RELEASE
          Hardware: amd64
                OS: Any
            Status: New
          Severity: Affects Only Me
          Priority: ---
         Component: misc
          Assignee: freebsd-bugs at FreeBSD.org
          Reporter: df at bloknot.pp.ua

Dear sirs.

I have a bug on the 10.1-RELEASE FreeBSD amd64 installed on my test server.
After I have this bug on my server, I installed FreeBSD 10.1 on my VirtualBox
guest virtual server and got same bug.  
This is a strange behavior of squid during his restart. This affects versions
squid33-3.3.13 and squid-3.4.9 presented in ports now.
To decrease a possible causes of the bug I used a simple squid config and test
this behavior on two FreeBSD 10.1 Release amd64 and FreeBSD 10.0 Release amd64
on VirtualBox guest virtualservers.  Both servers installed on zfs.
I have install а squid from ports using this config options:
#grep _SET /var/db/ports/www_squid/options
OPTIONS_FILE_SET+=AUTH_NIS
OPTIONS_FILE_SET+=DELAY_POOLS
OPTIONS_FILE_SET+=DOCS
OPTIONS_FILE_SET+=EXAMPLES
OPTIONS_FILE_SET+=FS_AUFS
OPTIONS_FILE_SET+=HTCP
OPTIONS_FILE_SET+=IDENT
OPTIONS_FILE_SET+=KQUEUE
OPTIONS_FILE_SET+=SNMP
OPTIONS_FILE_SET+=WCCP
OPTIONS_FILE_SET+=WCCPV2
and use simply config file squid.conf based on squid.sample.conf like this:
#cat /usr/local/etc/squid/squid.conf
acl localnet src 192.168.91.0/24        # RFC1918 possible internal network
acl SSL_ports port 443
acl Safe_ports port 80          # http
acl Safe_ports port 21          # ftp
acl Safe_ports port 443         # https
acl Safe_ports port 70          # gopher
acl Safe_ports port 210         # wais
acl Safe_ports port 1025-65535  # unregistered ports
acl Safe_ports port 280         # http-mgmt
acl Safe_ports port 488         # gss-http
acl Safe_ports port 591         # filemaker
acl Safe_ports port 777         # multiling http
acl CONNECT method CONNECT
http_access deny !Safe_ports
http_access deny CONNECT !SSL_ports
http_access allow localhost manager
http_access deny manager
http_access allow localnet
http_access allow localhost
http_access deny all
http_port 3128
coredump_dir /var/squid/cache/squid
refresh_pattern ^ftp:           1440    20%     10080
refresh_pattern ^gopher:        1440    0%      1440
refresh_pattern -i (/cgi-bin/|\?) 0     0%      0
refresh_pattern .               0       20%     4320

Also I have a file /etc/make.conf on both servers:
#cat /etc/make.conf
OPTIONS_UNSET=X11

And squid starts without errors and it works fine. But if I try to restart or
stop it on 10.1 using '/usr/local/etc/rc.d/squid restart (stop)' then squid
restarts and cotinue works but it have errors and some futures do not works.
More detailed:
After squid starts on FreeBSD 10.1 Release  in /var/log/messages I see
Nov 25 05:47:17 f10_1 squid[527]: Squid Parent: will start 1 kids
Nov 25 05:47:17 f10_1 squid[527]: Squid Parent: (squid-1) process 530 started

in /var/log/squid/cache.log:
2014/11/25 05:47:17 kid1| Accepting HTTP Socket connections at
local=0.0.0.0:3128 remote=[::] FD 10 flags=9

root at f10_1:/usr/home/df # sockstat -l4p 3128
USER     COMMAND    PID   FD PROTO  LOCAL ADDRESS         FOREIGN ADDRESS
squid    squid      530   10 tcp4   *:3128                *:*

root at f10_1:/usr/home/df # ps -wauxd | grep squid
squid 527   0.0  0.8 61276  8488  -  Is    5:47AM 0:00.01 |--
/usr/local/sbin/squid -f /usr/local/etc/squid/squid.conf
squid 530   0.0  1.6 81756 16456  -  S     5:47AM 0:00.32 | `-- (squid-1) -f
/usr/local/etc/squid/squid.conf (squid)
squid 531   0.0  0.3 23876  2952  -  I     5:47AM 0:00.06 |   `--
(logfile-daemon) /var/log/squid/access.log (log_file_daemon)

root at f10_1:/usr/home/df # cat /var/run/squid/squid.pid
530

After I run the command /usr/local/etc/rc.d/squid restart in /var/log/messages
I see:

Nov 25 05:54:38 f10_1 squid[527]: Squid Parent: (squid-1) process 530 exited
due to signal 6 with status 0
Nov 25 05:54:38 f10_1 kernel: pid 530 (squid), uid 100: exited on signal 6
Nov 25 05:54:38 f10_1 squid[727]: Squid Parent: will start 1 kids
Nov 25 05:54:38 f10_1 squid[727]: Squid Parent: (squid-1) process 730 started
Nov 25 05:54:41 f10_1 squid[527]: Squid Parent: (squid-1) process 733 started
Nov 25 05:54:41 f10_1 (squid-1): Unable to open HTTP Socket
Nov 25 05:54:41 f10_1 squid[527]: Squid Parent: (squid-1) process 733 exited
with status 1
Nov 25 05:54:44 f10_1 squid[527]: Squid Parent: (squid-1) process 736 started
Nov 25 05:54:44 f10_1 (squid-1): Unable to open HTTP Socket
Nov 25 05:54:44 f10_1 squid[527]: Squid Parent: (squid-1) process 736 exited
with status 1
Nov 25 05:54:47 f10_1 squid[527]: Squid Parent: (squid-1) process 739 started
Nov 25 05:54:47 f10_1 (squid-1): Unable to open HTTP Socket
Nov 25 05:54:47 f10_1 squid[527]: Squid Parent: (squid-1) process 739 exited
with status 1
Nov 25 05:54:50 f10_1 squid[527]: Squid Parent: (squid-1) process 742 started
Nov 25 05:54:51 f10_1 (squid-1): Unable to open HTTP Socket
Nov 25 05:54:51 f10_1 squid[527]: Squid Parent: (squid-1) process 742 exited
with status 1
Nov 25 05:54:54 f10_1 squid[527]: Squid Parent: (squid-1) process 745 started
Nov 25 05:54:54 f10_1 (squid-1): Unable to open HTTP Socket
Nov 25 05:54:54 f10_1 squid[527]: Squid Parent: (squid-1) process 745 exited
with status 1
Nov 25 05:54:54 f10_1 squid[527]: Squid Parent: (squid-1) process 745 will not
be restarted due to repeated, frequent failures
Nov 25 05:54:54 f10_1 squid[527]: Exiting due to repeated, frequent failures

In /var/log/squid/cache.log I see some repeating bloks like this:
2014/11/25 05:54:50 kid1| Starting Squid Cache version 3.3.13 for
amd64-portbld-freebsd10.1...
2014/11/25 05:54:50 kid1| Process ID 742
2014/11/25 05:54:50 kid1| Process Roles: worker
2014/11/25 05:54:50 kid1| With 28728 file descriptors available
2014/11/25 05:54:50 kid1| Initializing IP Cache...
2014/11/25 05:54:50 kid1| DNS Socket created at 0.0.0.0, FD 7
2014/11/25 05:54:50 kid1| Adding nameserver 8.8.8.8 from /etc/resolv.conf
2014/11/25 05:54:50 kid1| Logfile: opening log daemon:/var/log/squid/access.log
2014/11/25 05:54:50 kid1| Logfile Daemon: opening log /var/log/squid/access.log
2014/11/25 05:54:50 kid1| Store logging disabled
2014/11/25 05:54:50 kid1| Swap maxSize 0 + 262144 KB, estimated 20164 objects
2014/11/25 05:54:50 kid1| Target number of buckets: 1008
2014/11/25 05:54:50 kid1| Using 8192 Store buckets
2014/11/25 05:54:50 kid1| Max Mem  size: 262144 KB
2014/11/25 05:54:50 kid1| Max Swap size: 0 KB
2014/11/25 05:54:50 kid1| Using Least Load store dir selection
2014/11/25 05:54:50 kid1| Set Current Directory to /var/squid/cache/squid
2014/11/25 05:54:51 kid1| Loaded Icons.
2014/11/25 05:54:51 kid1| commBind: Cannot bind socket FD 10 to 0.0.0.0:3128:
(48) Address already in use
2014/11/25 05:54:51 kid1| HTCP Disabled.
2014/11/25 05:54:51 kid1| Squid plugin modules loaded: 0
2014/11/25 05:54:51 kid1| Closing HTTP port 0.0.0.0:3128
2014/11/25 05:54:51 kid1| storeDirWriteCleanLogs: Starting...
2014/11/25 05:54:51 kid1|   Finished.  Wrote 0 entries.
2014/11/25 05:54:51 kid1|   Took 0.00 seconds (  0.00 entries/sec).
FATAL: Unable to open HTTP Socket
Squid Cache (Version 3.3.13): Terminated abnormally.
CPU Usage: 0.177 seconds = 0.131 user + 0.046 sys
Maximum Resident Size: 69888 KB
Page faults with physical i/o: 0

root at f10_1:/usr/home/df # sockstat -l4p 3128
USER     COMMAND    PID   FD PROTO  LOCAL ADDRESS         FOREIGN ADDRESS
squid    squid      730   10 tcp4   *:3128                *:*

root at f10_1:/usr/home/df # ps -wauxd | grep squid
squid 727   0.0  0.9 61276  9700  -  Is    5:54AM  0:00.00 |--
/usr/local/sbin/squid -f /usr/local/etc/squid/squid.conf
squid 730   0.0  1.7 81756 17484  -  S     5:54AM  0:00.20 | `-- (squid-1) -f
/usr/local/etc/squid/squid.conf (squid)
squid 731   0.0  0.3 23876  2964  -  I     5:54AM  0:00.04 |   `--
(logfile-daemon) /var/log/squid/access.log (log_file_daemon)

root at f10_1:/usr/home/df # cat /var/run/squid/squid.pid
745

As you see, the pid of squid process, writen on /var/run/squid/squid.pid do not
match with realy pid of squid process. But squid running and works. If I try to
run the following commands then I see:

root at f10_1:/usr/home/df # /usr/local/etc/rc.d/squid restart
squid not running? (check /var/run/squid/squid.pid).
Starting squid.

root at f10_1:/usr/home/df # squid -k check
squid: ERROR: Could not send signal 0 to process 861: (3) No such process

root at f10_1:/usr/home/df # squid -k rotate
squid: ERROR: Could not send signal 30 to process 865: (3) No such process

root at f10_1:/usr/home/df # sockstat -l4p 3128
USER     COMMAND    PID   FD PROTO  LOCAL ADDRESS         FOREIGN ADDRESS
squid    squid      730   10 tcp4   *:3128                *:*
And squid process is running.

root at f10_1:/usr/home/df # /usr/local/etc/rc.d/squid stop
squid not running? (check /var/run/squid/squid.pid). After some pause

root at f10_1:/usr/home/df # sockstat -4lp3128
USER     COMMAND    PID   FD PROTO  LOCAL ADDRESS         FOREIGN ADDRESS
squid    squid      730   10 tcp4   *:3128                *:*

I made same action with two versions of squid on FreeBSD10.0 Release amd64
which I have installed on my virtual server and squid works fine without this
bug.
If need then I can present more information about this.

Thanks, Fedor Konstantinov.

-- 
You are receiving this mail because:
You are the assignee for the bug.


More information about the freebsd-bugs mailing list