Re: [squid-users] FATAL: Unable to open HTTP Socket

On 3/10/2012 7:56 p.m., shahab bohlooli wrote:
> Dear All,
>
> Recently, I chose to install and run Squid 3.2.1 on Debain Weezy/SID
> (64 bit) with 4 workers
> At the beginning every thing went well, but when the system goes under
> loads of 20 users (more or less) I lose workers sequentially until
> there went no kids to process the requests.

Which appears to be the real problem. Question is how is it happening?
what else is happening when the kids disappear?

> In this time I have to
> restart the squid to solve the problem temporarily.
>
>
> The cache log shows following error (part of the log):
>
> 2012/10/03 09:45:02 kid1| Loaded Icons.
> 2012/10/03 09:45:02 kid1| Reconfiguring Squid Cache (version 3.2.1)...

Um, you said "Restart" ? not "reconfigure". The above is the result of
"squid -k reconfigure"

> 2012/10/03 09:45:02 kid1| Closing HTTP port 192.168.10.3:8080
> 2012/10/03 09:45:02 kid1| Logfile: closing log stdio:/var/log/squid3/store.log
> 2012/10/03 09:45:02 kid1| Logfile: closing log stdio:/var/log/squid3/access.log
> 2012/10/03 09:45:02 kid1| Startup: Initializing Authentication Schemes ...
> 2012/10/03 09:45:02 kid1| Startup: Initialized Authentication Scheme 'basic'
> 2012/10/03 09:45:02 kid1| Startup: Initialized Authentication Scheme 'digest'
> 2012/10/03 09:45:02 kid1| Startup: Initialized Authentication Scheme 'negotiate'
> 2012/10/03 09:45:02 kid1| Startup: Initialized Authentication Scheme 'ntlm'
> 2012/10/03 09:45:02 kid1| Startup: Initialized Authentication.
> 2012/10/03 09:45:02 kid1| Processing Configuration File:
> /opt/squid3/etc/squid.conf (depth 0)
> 2012/10/03 09:45:02 kid1| Initializing https proxy context
> 2012/10/03 09:45:02 kid1| Logfile: opening log stdio:/var/log/squid3/access.log
> 2012/10/03 09:45:02 kid1| Squid plugin modules loaded: 0
> 2012/10/03 09:45:02 kid1| Adaptation support is off.
> 2012/10/03 09:45:02 kid1| Logfile: opening log stdio:/var/log/squid3/store.log
> 2012/10/03 09:45:02 kid1| DNS Socket created at [::], FD 9
> 2012/10/03 09:45:02 kid1| DNS Socket created at 0.0.0.0, FD 11
> 2012/10/03 09:45:02 kid1| Adding domain arums.ac.ir from /etc/resolv.conf
> 2012/10/03 09:45:02 kid1| Adding nameserver 78.38.27.3 from /etc/resolv.conf
> 2012/10/03 09:45:02 kid1| Adding nameserver 78.38.27.4 from /etc/resolv.conf
> 2012/10/03 09:45:02 kid1| helperOpenServers: Starting 0/20
> 'basic_ldap_auth' processes
> 2012/10/03 09:45:02 kid1| helperOpenServers: No 'basic_ldap_auth'
> processes needed.
> 2012/10/03 09:45:02 kid1| HTCP Disabled.
> 2012/10/03 09:45:02 kid2| Loaded Icons.
> 2012/10/03 09:45:02 kid2| Reconfiguring Squid Cache (version 3.2.1)...
> 2012/10/03 09:45:02 kid2| Closing HTTP port 192.168.10.3:8080
> 2012/10/03 09:45:02 kid2| Logfile: closing log stdio:/var/log/squid3/store.log
> 2012/10/03 09:45:02 kid2| Logfile: closing log stdio:/var/log/squid3/access.log
> 2012/10/03 09:45:02 kid2| Startup: Initializing Authentication Schemes ...
> 2012/10/03 09:45:02 kid2| Startup: Initialized Authentication Scheme 'basic'
> 2012/10/03 09:45:02 kid2| Startup: Initialized Authentication Scheme 'digest'
> 2012/10/03 09:45:02 kid2| Startup: Initialized Authentication Scheme 'negotiate'
> 2012/10/03 09:45:02 kid2| Startup: Initialized Authentication Scheme 'ntlm'
> 2012/10/03 09:45:02 kid2| Startup: Initialized Authentication.
> 2012/10/03 09:45:02 kid2| Processing Configuration File:
> /opt/squid3/etc/squid.conf (depth 0)
> 2012/10/03 09:45:02 kid2| Initializing https proxy context
> 2012/10/03 09:45:02 kid2| Logfile: opening log stdio:/var/log/squid3/access.log
> 2012/10/03 09:45:02 kid2| Squid plugin modules loaded: 0
> 2012/10/03 09:45:02 kid2| Adaptation support is off.
> 2012/10/03 09:45:02 kid2| Logfile: opening log stdio:/var/log/squid3/store.log
> 2012/10/03 09:45:02 kid2| DNS Socket created at [::], FD 9
> 2012/10/03 09:45:02 kid2| DNS Socket created at 0.0.0.0, FD 11
> 2012/10/03 09:45:02 kid2| Adding domain arums.ac.ir from /etc/resolv.conf
> 2012/10/03 09:45:02 kid2| Adding nameserver 78.38.27.3 from /etc/resolv.conf
> 2012/10/03 09:45:02 kid2| Adding nameserver 78.38.27.4 from /etc/resolv.conf
> 2012/10/03 09:45:02 kid2| helperOpenServers: Starting 0/20
> 'basic_ldap_auth' processes
> 2012/10/03 09:45:02 kid2| helperOpenServers: No 'basic_ldap_auth'
> processes needed.
> 2012/10/03 09:45:02 kid2| HTCP Disabled.
> 2012/10/03 09:45:02 kid4| Loaded Icons.
> 2012/10/03 09:45:02 kid6| Loaded Icons.
> 2012/10/03 09:45:02 kid3| Loaded Icons.
> 2012/10/03 09:45:02 kid3| Reconfiguring Squid Cache (version 3.2.1)...
> 2012/10/03 09:45:02 kid3| Closing HTTP port 192.168.10.3:8080
> 2012/10/03 09:45:02 kid3| Logfile: closing log stdio:/var/log/squid3/store.log
> 2012/10/03 09:45:02 kid3| Logfile: closing log stdio:/var/log/squid3/access.log
> 2012/10/03 09:45:02 kid3| Startup: Initializing Authentication Schemes ...
> 2012/10/03 09:45:02 kid3| Startup: Initialized Authentication Scheme 'basic'
> 2012/10/03 09:45:02 kid3| Startup: Initialized Authentication Scheme 'digest'
> 2012/10/03 09:45:02 kid3| Startup: Initialized Authentication Scheme 'negotiate'
> 2012/10/03 09:45:02 kid3| Startup: Initialized Authentication Scheme 'ntlm'
> 2012/10/03 09:45:02 kid3| Startup: Initialized Authentication.
> 2012/10/03 09:45:02 kid3| Processing Configuration File:
> /opt/squid3/etc/squid.conf (depth 0)
> 2012/10/03 09:45:02 kid3| Initializing https proxy context
> 2012/10/03 09:45:02 kid4| Accepting HTTP Socket connections at
> local=192.168.10.3:8080 remote=[::] FD 17 flags=1
> 2012/10/03 09:45:02 kid1| Loaded Icons.
> 2012/10/03 09:45:02 kid5| Loaded Icons.
> 2012/10/03 09:45:02 kid5| Reconfiguring Squid Cache (version 3.2.1)...
> 2012/10/03 09:45:02 kid5| Logfile: closing log stdio:/var/log/squid3/store.log
> 2012/10/03 09:45:02 kid5| Logfile: closing log stdio:/var/log/squid3/access.log
> 2012/10/03 09:45:02 kid5| Startup: Initializing Authentication Schemes ...
> 2012/10/03 09:45:02 kid5| Startup: Initialized Authentication Scheme 'basic'
> 2012/10/03 09:45:02 kid5| Startup: Initialized Authentication Scheme 'digest'
> 2012/10/03 09:45:02 kid5| Startup: Initialized Authentication Scheme 'negotiate'
> 2012/10/03 09:45:02 kid5| Startup: Initialized Authentication Scheme 'ntlm'
> 2012/10/03 09:45:02 kid5| Startup: Initialized Authentication.
> 2012/10/03 09:45:02 kid1| Closing HTTP port 192.168.10.3:8080
> 2012/10/03 09:45:02 kid1| storeDirWriteCleanLogs: Starting...
> 2012/10/03 09:45:02 kid1| Finished. Wrote 0 entries.
> 2012/10/03 09:45:02 kid1| Took 0.00 seconds ( 0.00 entries/sec).
> FATAL: Unable to open HTTP Socket

Something else is still using the particular port.... probably kid4 above.

Sadly we do not print out the process which is reporting FATAL for a
better trace. That is another bug which needs to be fixed.

> Squid Cache (Version 3.2.1): Terminated abnormally.
> 2012/10/03 09:45:02 kid5| Processing Configuration File:
> /opt/squid3/etc/squid.conf (depth 0)
> CPU Usage: 7.488 seconds = 4.860 user + 2.628 sys
> Maximum Resident Size: 80480 KB
> Page faults with physical i/o: 0
> Memory usage for squid via mallinfo():
> total space in arena: 6148 KB
> Ordinary blocks: 5672 KB 41 blks
> Small blocks: 0 KB 1 blks
> Holding blocks: 2096 KB 5 blks
> Free Small blocks: 0 KB
> Free Ordinary blocks: 475 KB
> Total in use: 7768 KB 126%
> Total free: 475 KB 8%
>
>
> Any help on this appreciated
>
> Regards, Bohlooli

Amos
Received on Wed Oct 03 2012 - 09:37:31 MDT