Bug 195362 - Strange behavior of www/squid during his restart on 10.1 release
Summary: Strange behavior of www/squid during his restart on 10.1 release
Status: Closed FIXED
Alias: None
Product: Ports & Packages
Classification: Unclassified
Component: Individual Port(s) (show other bugs)
Version: Latest
Hardware: amd64 Any
: --- Affects Only Me
Assignee: freebsd-ports-bugs (Nobody)
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2014-11-25 08:23 UTC by df
Modified: 2015-05-17 15:33 UTC (History)
4 users (show)

See Also:


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description df 2014-11-25 08:23:51 UTC
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@f10_1:/usr/home/df # sockstat -l4p 3128
USER     COMMAND    PID   FD PROTO  LOCAL ADDRESS         FOREIGN ADDRESS
squid    squid      530   10 tcp4   *:3128                *:*

root@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@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@f10_1:/usr/home/df # sockstat -l4p 3128
USER     COMMAND    PID   FD PROTO  LOCAL ADDRESS         FOREIGN ADDRESS
squid    squid      730   10 tcp4   *:3128                *:*

root@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@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@f10_1:/usr/home/df # /usr/local/etc/rc.d/squid restart
squid not running? (check /var/run/squid/squid.pid).
Starting squid.

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

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

root@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@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@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.
Comment 1 Mark Linimon freebsd_committer freebsd_triage 2014-11-26 06:50:27 UTC
Fix Summary and make this a ports PR.  Note: squid is currently unmaintained.
Comment 2 pvoigt 2014-12-04 17:59:50 UTC
I can confirm this behavior on 10.1-RELEASE (amd64):
http://lists.freebsd.org/pipermail/freebsd-ports/2014-November/096775.html

Regards,
Peter
Comment 3 Aleksandr 2015-01-23 13:25:49 UTC
I can confirm this behavior on 10.1-RELEASE both i386 and amd64.
squid options 
squid -v
Squid Cache: Version 3.4.9
configure options:  '--with-default-user=squid' '--bindir=/usr/local/sbin' '--sbindir=/usr/local/sbin' '--datadir=/usr/local/etc/squid' '--libexecdir=/usr/local/libexec/squid' '--localstatedir=/var' '--sysconfdir=/usr/local/etc/squid' '--with-logdir=/var/log/squid' '--with-pidfile=/var/run/squid/squid.pid' '--with-swapdir=/var/squid/cache' '--enable-auth' '--enable-build-info' '--enable-loadable-modules' '--enable-removal-policies=lru heap' '--disable-epoll' '--disable-linux-netfilter' '--disable-linux-tproxy' '--disable-translation' '--disable-arch-native' '--enable-eui' '--disable-cache-digests' '--enable-delay-pools' '--disable-ecap' '--disable-esi' '--disable-follow-x-forwarded-for' '--enable-htcp' '--disable-icap-client' '--disable-icmp' '--enable-ident-lookups' '--enable-ipv6' '--enable-kqueue' '--without-large-files' '--disable-http-violations' '--enable-snmp' '--enable-ssl' '--enable-ssl-crtd' '--disable-stacktraces' '--disable-ipf-transparent' '--disable-ipfw-transparent' '--enable-pf-transparent' '--with-nat-devpf' '--disable-forw-via-db' '--enable-wccp' '--enable-wccpv2' '--enable-auth-basic=DB MSNT MSNT-multi-domain NCSA PAM POP3 RADIUS fake getpwnam NIS' '--enable-auth-digest=file' '--enable-external-acl-helpers=file_userip time_quota unix_group' '--enable-auth-negotiate=kerberos wrapper' '--enable-auth-ntlm=fake smb_lm' '--enable-storeio=ufs aufs diskd' '--enable-disk-io=AIO Blocking IpcIo Mmapped DiskThreads DiskDaemon' '--enable-log-daemon-helpers=file' '--enable-url-rewrite-helpers=fake' '--enable-storeid-rewrite-helpers=file' '--with-openssl=/usr/local' '--prefix=/usr/local' '--mandir=/usr/local/man' '--infodir=/usr/local/info/' '--build=i386-portbld-freebsd10.1' 'build_alias=i386-portbld-freebsd10.1' 'CC=cc' 'CFLAGS=-O2 -pipe  -I/usr/local/include -fstack-protector -fno-strict-aliasing' 'LDFLAGS= -pthread -Wl,-rpath,/usr/local/lib -L/usr/local/lib -fstack-protector' 'LIBS=' 'CPPFLAGS=' 'CXX=c++' 'CXXFLAGS=-O2 -pipe -I/usr/local/include -fstack-protector -fno-strict-aliasing  -Wno-unused-private-field' 'CPP=cpp'

and

squid -v
Squid Cache: Version 3.4.11
configure options:  '--with-default-user=squid' '--bindir=/usr/local/sbin' '--sbindir=/usr/local/sbin' '--datadir=/usr/local/etc/squid' '--libexecdir=/usr/local/libexec/squid' '--localstatedir=/var' '--sysconfdir=/usr/local/etc/squid' '--with-logdir=/var/log/squid' '--with-pidfile=/var/run/squid/squid.pid' '--with-swapdir=/var/squid/cache' '--enable-auth' '--enable-build-info' '--enable-loadable-modules' '--enable-removal-policies=lru heap' '--disable-epoll' '--disable-linux-netfilter' '--disable-linux-tproxy' '--disable-translation' '--disable-arch-native' '--enable-eui' '--disable-cache-digests' '--enable-delay-pools' '--disable-ecap' '--disable-esi' '--disable-follow-x-forwarded-for' '--enable-htcp' '--disable-icap-client' '--disable-icmp' '--enable-ident-lookups' '--enable-ipv6' '--enable-kqueue' '--without-large-files' '--disable-http-violations' '--without-nettle' '--enable-snmp' '--enable-ssl' '--enable-ssl-crtd' '--disable-stacktraces' '--disable-ipf-transparent' '--disable-ipfw-transparent' '--enable-pf-transparent' '--with-nat-devpf' '--disable-forw-via-db' '--enable-wccp' '--enable-wccpv2' '--enable-auth-basic=DB MSNT MSNT-multi-domain NCSA PAM POP3 RADIUS fake getpwnam NIS' '--enable-auth-digest=file' '--enable-external-acl-helpers=file_userip time_quota unix_group' '--enable-auth-negotiate=kerberos wrapper' '--enable-auth-ntlm=fake smb_lm' '--enable-storeio=ufs aufs diskd' '--enable-disk-io=AIO Blocking IpcIo Mmapped DiskThreads DiskDaemon' '--enable-log-daemon-helpers=file' '--enable-url-rewrite-helpers=fake' '--enable-storeid-rewrite-helpers=file' '--with-openssl=/usr/local' '--prefix=/usr/local' '--mandir=/usr/local/man' '--infodir=/usr/local/info/' '--build=amd64-portbld-freebsd10.1' 'build_alias=amd64-portbld-freebsd10.1' 'CC=cc' 'CFLAGS=-O2 -pipe  -I/usr/local/include -fstack-protector -fno-strict-aliasing' 'LDFLAGS= -pthread -Wl,-rpath,/usr/local/lib -L/usr/local/lib -fstack-protector' 'LIBS=' 'CPPFLAGS=' 'CXX=c++' 'CXXFLAGS=-O2 -pipe -I/usr/local/include -fstack-protector -fno-strict-aliasing  -Wno-unused-private-field' 'CPP=cpp' --enable-ltdl-convenience


Everything works fine on FreeBSD 10.0
Comment 4 pvoigt 2015-02-22 21:54:41 UTC
OK, my issue is covered with bug 195802: https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=195802

Regards,
Peter
Comment 5 John Marino freebsd_committer 2015-05-17 15:33:32 UTC
known issue and described by bug 195802.