From owner-freebsd-bugs@FreeBSD.ORG Tue Nov 25 08:23:51 2014 Return-Path: Delivered-To: freebsd-bugs@FreeBSD.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:1900:2254:206a::19:1]) (using TLSv1.2 with cipher AECDH-AES256-SHA (256/256 bits)) (No client certificate requested) by hub.freebsd.org (Postfix) with ESMTPS id 816A5876 for ; Tue, 25 Nov 2014 08:23:51 +0000 (UTC) Received: from kenobi.freebsd.org (kenobi.freebsd.org [IPv6:2001:1900:2254:206a::16:76]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (Client did not present a certificate) by mx1.freebsd.org (Postfix) with ESMTPS id 688B3169 for ; Tue, 25 Nov 2014 08:23:51 +0000 (UTC) Received: from bugs.freebsd.org ([127.0.1.118]) by kenobi.freebsd.org (8.14.9/8.14.9) with ESMTP id sAP8NpBQ065252 for ; Tue, 25 Nov 2014 08:23:51 GMT (envelope-from bugzilla-noreply@freebsd.org) From: bugzilla-noreply@freebsd.org To: freebsd-bugs@FreeBSD.org Subject: [Bug 195362] New: Strange behavior of squid during his restart on 10.1 release Date: Tue, 25 Nov 2014 08:23:51 +0000 X-Bugzilla-Reason: AssignedTo X-Bugzilla-Type: new X-Bugzilla-Watch-Reason: None X-Bugzilla-Product: Base System X-Bugzilla-Component: misc X-Bugzilla-Version: 10.1-RELEASE X-Bugzilla-Keywords: X-Bugzilla-Severity: Affects Only Me X-Bugzilla-Who: df@bloknot.pp.ua X-Bugzilla-Status: New X-Bugzilla-Priority: --- X-Bugzilla-Assigned-To: freebsd-bugs@FreeBSD.org X-Bugzilla-Target-Milestone: --- X-Bugzilla-Flags: X-Bugzilla-Changed-Fields: bug_id short_desc product version rep_platform op_sys bug_status bug_severity priority component assigned_to reporter Message-ID: Content-Type: text/plain; charset="UTF-8" Content-Transfer-Encoding: quoted-printable X-Bugzilla-URL: https://bugs.freebsd.org/bugzilla/ Auto-Submitted: auto-generated MIME-Version: 1.0 X-BeenThere: freebsd-bugs@freebsd.org X-Mailman-Version: 2.1.18-1 Precedence: list List-Id: Bug reports List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Tue, 25 Nov 2014 08:23:51 -0000 https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=3D195362 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@FreeBSD.org Reporter: df@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 VirtualB= ox guest virtual server and got same bug.=20=20 This is a strange behavior of squid during his restart. This affects versio= ns 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 t= est this behavior on two FreeBSD 10.1 Release amd64 and FreeBSD 10.0 Release am= d64 on VirtualBox guest virtualservers. Both servers installed on zfs. I have install =D0=B0 squid from ports using this config options: #grep _SET /var/db/ports/www_squid/options OPTIONS_FILE_SET+=3DAUTH_NIS OPTIONS_FILE_SET+=3DDELAY_POOLS OPTIONS_FILE_SET+=3DDOCS OPTIONS_FILE_SET+=3DEXAMPLES OPTIONS_FILE_SET+=3DFS_AUFS OPTIONS_FILE_SET+=3DHTCP OPTIONS_FILE_SET+=3DIDENT OPTIONS_FILE_SET+=3DKQUEUE OPTIONS_FILE_SET+=3DSNMP OPTIONS_FILE_SET+=3DWCCP OPTIONS_FILE_SET+=3DWCCPV2 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=3DX11 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 start= ed in /var/log/squid/cache.log: 2014/11/25 05:47:17 kid1| Accepting HTTP Socket connections at local=3D0.0.0.0:3128 remote=3D[::] FD 10 flags=3D9 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/messa= ges 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 start= ed Nov 25 05:54:41 f10_1 squid[527]: Squid Parent: (squid-1) process 733 start= ed 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 start= ed 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 start= ed 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 start= ed 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 start= ed 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 objec= ts 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:312= 8: (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 =3D 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 tr= y 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 th= is bug. If need then I can present more information about this. Thanks, Fedor Konstantinov. --=20 You are receiving this mail because: You are the assignee for the bug.=