Opened 10 years ago

Closed 6 years ago

#42065 closed defect (wontfix)

Squid runaway child processes at boot, commBind: Cannot bind socket FD NN to *:3128: (48) Address already in use

Reported by: essandess (Steve Smith) Owned by: jmroot (Joshua Root)
Priority: Normal Milestone:
Component: ports Version: 2.2.1
Keywords: Cc:
Port: squid

Description

squid @2.7.STABLE9_3+openssl on OS X 10.9.1 Mac Mini, default squid.conf file. sudo port load squid

On boot, squid launches many (tens or more) child process, consuming all CPU cycles for tens of minutes. On some boots, all but one of the children go away leaving a functioning proxy, other times children proliferate until there are apparently no more file descriptors and the machine crashes.

The following commands kills all squid children, and works to relaunch a working version of squid. However, the macports daemondo that relaunches squid intermittently exhibits the same problem at boot, apparently causing crashes. And even though squid launches normally with a launchctl after boot, the caches.log file often shows the error "commBind: Cannot bind socket FD NN to *:3128: (48) Address already in use". 

# kill runaway squid
sudo launchctl unload -w /Library/LaunchDaemons/org.macports.Squid.plist
sudo killall '(squid)'
sudo killall squid

# relaunch squid successfully after boot
sudo launchctl load -w /Library/LaunchDaemons/org.macports.Squid.plist

The tail of /opt/local/var/squid/logs/cache.log during boot 

2014/01/08 21:54:13| Starting Squid Cache version 2.7.STABLE9 for i686-apple-darwin13.0.0...
2014/01/08 21:54:13| Process ID 602
2014/01/08 21:54:13| With 2560 file descriptors available
2014/01/08 21:54:13| Using kqueue for the IO loop
2014/01/08 21:54:13| Performing DNS Tests...
2014/01/08 21:54:13| Successful DNS name lookup tests...
2014/01/08 21:54:13| ipcacheAddEntryFromHosts: Bad IP address 'fe80::1%lo0'
2014/01/08 21:54:25| Starting Squid Cache version 2.7.STABLE9 for i686-apple-darwin13.0.0...
2014/01/08 21:54:25| Process ID 690
2014/01/08 21:54:25| With 2560 file descriptors available
2014/01/08 21:54:25| Using kqueue for the IO loop
2014/01/08 21:54:25| Performing DNS Tests...
2014/01/08 21:54:25| Successful DNS name lookup tests...
2014/01/08 21:54:25| ipcacheAddEntryFromHosts: Bad IP address 'fe80::1%lo0'
2014/01/08 21:54:55| Starting Squid Cache version 2.7.STABLE9 for i686-apple-darwin13.0.0...
2014/01/08 21:54:55| Process ID 746
2014/01/08 21:54:55| With 2560 file descriptors available
2014/01/08 21:54:55| Using kqueue for the IO loop
2014/01/08 21:54:55| Performing DNS Tests...
2014/01/08 21:54:55| Successful DNS name lookup tests...
2014/01/08 21:54:55| ipcacheAddEntryFromHosts: Bad IP address 'fe80::1%lo0'
2014/01/08 21:55:31| Starting Squid Cache version 2.7.STABLE9 for i686-apple-darwin13.0.0...
2014/01/08 21:55:31| Process ID 908
2014/01/08 21:55:31| With 2560 file descriptors available
2014/01/08 21:55:31| Using kqueue for the IO loop
2014/01/08 21:55:31| Performing DNS Tests...
2014/01/08 21:55:31| Successful DNS name lookup tests...
2014/01/08 21:55:31| ipcacheAddEntryFromHosts: Bad IP address 'fe80::1%lo0'
2014/01/08 21:56:01| Starting Squid Cache version 2.7.STABLE9 for i686-apple-darwin13.0.0...
2014/01/08 21:56:01| Process ID 1002
2014/01/08 21:56:01| With 2560 file descriptors available
2014/01/08 21:56:01| Using kqueue for the IO loop
2014/01/08 21:56:01| Performing DNS Tests...
2014/01/08 21:56:01| Successful DNS name lookup tests...
2014/01/08 21:56:01| ipcacheAddEntryFromHosts: Bad IP address 'fe80::1%lo0'
2014/01/08 21:56:31| Starting Squid Cache version 2.7.STABLE9 for i686-apple-darwin13.0.0...
2014/01/08 21:56:31| Process ID 1136
2014/01/08 21:56:31| With 2560 file descriptors available
2014/01/08 21:56:31| Using kqueue for the IO loop
2014/01/08 21:56:31| Performing DNS Tests...
2014/01/08 21:56:31| Successful DNS name lookup tests...
2014/01/08 21:56:31| ipcacheAddEntryFromHosts: Bad IP address 'fe80::1%lo0'
2014/01/08 21:57:02| Starting Squid Cache version 2.7.STABLE9 for i686-apple-darwin13.0.0...
2014/01/08 21:57:02| Process ID 1275
2014/01/08 21:57:02| With 2560 file descriptors available
2014/01/08 21:57:02| Using kqueue for the IO loop
2014/01/08 21:57:02| Performing DNS Tests...
2014/01/08 21:57:02| Successful DNS name lookup tests...
2014/01/08 21:57:02| ipcacheAddEntryFromHosts: Bad IP address 'fe80::1%lo0'
2014/01/08 21:57:33| Starting Squid Cache version 2.7.STABLE9 for i686-apple-darwin13.0.0...
2014/01/08 21:57:33| Process ID 1353
2014/01/08 21:57:33| With 2560 file descriptors available
2014/01/08 21:57:33| Using kqueue for the IO loop
2014/01/08 21:57:33| Performing DNS Tests...
2014/01/08 21:57:33| Successful DNS name lookup tests...
2014/01/08 21:57:33| ipcacheAddEntryFromHosts: Bad IP address 'fe80::1%lo0'
2014/01/08 21:58:04| Starting Squid Cache version 2.7.STABLE9 for i686-apple-darwin13.0.0...
2014/01/08 21:58:04| Process ID 1436
2014/01/08 21:58:04| With 2560 file descriptors available
2014/01/08 21:58:04| Using kqueue for the IO loop
2014/01/08 21:58:04| Performing DNS Tests...
2014/01/08 21:58:04| Successful DNS name lookup tests...
2014/01/08 21:58:04| ipcacheAddEntryFromHosts: Bad IP address 'fe80::1%lo0'
2014/01/08 21:54:13| DNS Socket created at 0.0.0.0, port 56204, FD 8
2014/01/08 21:54:13| Adding domain mydomain.com. from /etc/resolv.conf
2014/01/08 21:54:13| Adding nameserver 10.0.1.3 from /etc/resolv.conf
2014/01/08 21:54:13| Adding nameserver 10.0.1.1 from /etc/resolv.conf
2014/01/08 21:54:13| logfileOpen: opening log /opt/local/var/squid/logs/access.log
2014/01/08 21:54:13| Unlinkd pipe opened on FD 13
2014/01/08 21:54:13| Swap maxSize 102400 + 8192 KB, estimated 8507 objects
2014/01/08 21:54:13| Target number of buckets: 425
2014/01/08 21:54:13| Using 8192 Store buckets
2014/01/08 21:54:13| Max Mem  size: 8192 KB
2014/01/08 21:54:13| Max Swap size: 102400 KB
2014/01/08 21:54:13| logfileOpen: opening log /opt/local/var/squid/logs/store.log
2014/01/08 21:54:13| Rebuilding storage in /opt/local/var/squid/cache (DIRTY)
2014/01/08 21:54:13| Using Least Load store dir selection
2014/01/08 21:54:13| Set Current Directory to /opt/local/var/squid/cache
2014/01/08 21:54:13| Loaded Icons.
2014/01/08 21:58:23| Accepting proxy HTTP connections at 0.0.0.0, port 3128, FD 15.
2014/01/08 21:58:23| Accepting ICP messages at 0.0.0.0, port 3130, FD 16.
2014/01/08 21:58:23| WCCP Disabled.
2014/01/08 21:58:23| Ready to serve requests.
2014/01/08 21:58:23| Done reading /opt/local/var/squid/cache swaplog (3315 entries)
2014/01/08 21:58:23| Finished rebuilding storage from disk.
2014/01/08 21:58:23|      3315 Entries scanned
2014/01/08 21:58:23|         0 Invalid entries.
2014/01/08 21:58:23|         0 With invalid flags.
2014/01/08 21:58:23|      3315 Objects loaded.
2014/01/08 21:58:23|         0 Objects expired.
2014/01/08 21:58:23|         0 Objects cancelled.
2014/01/08 21:58:23|         0 Duplicate URLs purged.
2014/01/08 21:58:23|         0 Swapfile clashes avoided.
2014/01/08 21:58:23|   Took 250.2 seconds (  13.3 objects/sec).
2014/01/08 21:58:23| Beginning Validation Procedure
2014/01/08 21:58:23|   Completed Validation Procedure
2014/01/08 21:58:23|   Validated 3315 Entries
2014/01/08 21:58:23|   store_swap_size = 92004k
2014/01/08 21:58:24| storeLateRelease: released 0 objects
2014/01/08 21:54:25| DNS Socket created at 0.0.0.0, port 59575, FD 8
2014/01/08 21:54:25| Adding domain mydomain.com. from /etc/resolv.conf
2014/01/08 21:54:25| Adding nameserver 10.0.1.3 from /etc/resolv.conf
2014/01/08 21:54:25| Adding nameserver 10.0.1.1 from /etc/resolv.conf
2014/01/08 21:54:25| logfileOpen: opening log /opt/local/var/squid/logs/access.log
2014/01/08 21:54:25| Unlinkd pipe opened on FD 13
2014/01/08 21:54:25| Swap maxSize 102400 + 8192 KB, estimated 8507 objects
2014/01/08 21:54:25| Target number of buckets: 425
2014/01/08 21:54:25| Using 8192 Store buckets
2014/01/08 21:54:25| Max Mem  size: 8192 KB
2014/01/08 21:54:25| Max Swap size: 102400 KB
2014/01/08 21:54:25| logfileOpen: opening log /opt/local/var/squid/logs/store.log
2014/01/08 21:54:25| Rebuilding storage in /opt/local/var/squid/cache (DIRTY)
2014/01/08 21:54:25| Using Least Load store dir selection
2014/01/08 21:54:25| Set Current Directory to /opt/local/var/squid/cache
2014/01/08 21:54:25| Loaded Icons.
2014/01/08 21:58:30| commBind: Cannot bind socket FD 15 to *:3128: (48) Address already in use
FATAL: Cannot open HTTP Port
Squid Cache (Version 2.7.STABLE9): Terminated abnormally.
CPU Usage: 42.186 seconds = 41.535 user + 0.651 sys
Maximum Resident Size: 78389248 KB
Page faults with physical i/o: 0
2014/01/08 21:59:06| Preparing for mydomaindown after 0 requests
2014/01/08 21:59:06| Waiting 30 seconds for active connections to finish
2014/01/08 21:59:06| FD 15 Closing HTTP connection
2014/01/08 21:54:55| DNS Socket created at 0.0.0.0, port 54188, FD 8
2014/01/08 21:54:55| Adding domain mydomain.com. from /etc/resolv.conf
2014/01/08 21:54:55| Adding nameserver 10.0.1.3 from /etc/resolv.conf
2014/01/08 21:54:55| Adding nameserver 10.0.1.1 from /etc/resolv.conf
2014/01/08 21:54:55| logfileOpen: opening log /opt/local/var/squid/logs/access.log
2014/01/08 21:54:55| Unlinkd pipe opened on FD 13
2014/01/08 21:54:55| Swap maxSize 102400 + 8192 KB, estimated 8507 objects
2014/01/08 21:54:55| Target number of buckets: 425
2014/01/08 21:54:55| Using 8192 Store buckets
2014/01/08 21:54:55| Max Mem  size: 8192 KB
2014/01/08 21:54:55| Max Swap size: 102400 KB
2014/01/08 21:54:55| logfileOpen: opening log /opt/local/var/squid/logs/store.log
2014/01/08 21:54:55| Rebuilding storage in /opt/local/var/squid/cache (DIRTY)
2014/01/08 21:54:55| Using Least Load store dir selection
2014/01/08 21:54:55| Set Current Directory to /opt/local/var/squid/cache
2014/01/08 21:54:55| Loaded Icons.
2014/01/08 21:59:29| Accepting proxy HTTP connections at 0.0.0.0, port 3128, FD 15.
2014/01/08 21:59:29| commBind: Cannot bind socket FD 16 to *:3130: (48) Address already in use
FATAL: Cannot open ICP Port
Squid Cache (Version 2.7.STABLE9): Terminated abnormally.
CPU Usage: 42.179 seconds = 41.549 user + 0.630 sys
Maximum Resident Size: 78401536 KB
Page faults with physical i/o: 0
2014/01/08 21:59:37| mydomainting down...
2014/01/08 21:59:37| FD 16 Closing ICP connection
2014/01/08 21:59:37| Closing unlinkd pipe on FD 13
2014/01/08 21:59:37| storeDirWriteCleanLogs: Starting...
2014/01/08 21:59:37|   Finished.  Wrote 3315 entries.
2014/01/08 21:59:37|   Took 0.0 seconds (3035714.3 entries/sec).
CPU Usage: 42.185 seconds = 41.528 user + 0.658 sys
Maximum Resident Size: 79011840 KB
Page faults with physical i/o: 64
2014/01/08 21:59:37| logfileClose: closing log /opt/local/var/squid/logs/store.log
2014/01/08 21:59:37| logfileClose: closing log /opt/local/var/squid/logs/access.log
2014/01/08 21:59:37| Squid Cache (Version 2.7.STABLE9): Exiting normally.
2014/01/08 21:59:38| Starting Squid Cache version 2.7.STABLE9 for i686-apple-darwin13.0.0...
2014/01/08 21:59:38| Process ID 1656
2014/01/08 21:59:38| With 2560 file descriptors available
2014/01/08 21:59:38| Using kqueue for the IO loop
2014/01/08 21:59:38| Performing DNS Tests...
2014/01/08 21:59:38| Successful DNS name lookup tests...
2014/01/08 21:59:38| ipcacheAddEntryFromHosts: Bad IP address 'fe80::1%lo0'
2014/01/08 21:55:31| DNS Socket created at 0.0.0.0, port 55820, FD 8
2014/01/08 21:55:31| Adding domain mydomain.com. from /etc/resolv.conf
2014/01/08 21:55:31| Adding nameserver 10.0.1.3 from /etc/resolv.conf
2014/01/08 21:55:31| Adding nameserver 10.0.1.1 from /etc/resolv.conf
2014/01/08 21:55:31| logfileOpen: opening log /opt/local/var/squid/logs/access.log
2014/01/08 21:55:31| Unlinkd pipe opened on FD 13
2014/01/08 21:55:31| Swap maxSize 102400 + 8192 KB, estimated 8507 objects
2014/01/08 21:55:31| Target number of buckets: 425
2014/01/08 21:55:31| Using 8192 Store buckets
2014/01/08 21:55:31| Max Mem  size: 8192 KB
2014/01/08 21:55:31| Max Swap size: 102400 KB
2014/01/08 21:55:31| logfileOpen: opening log /opt/local/var/squid/logs/store.log
2014/01/08 21:55:31| Rebuilding storage in /opt/local/var/squid/cache (CLEAN)
2014/01/08 21:55:31| Using Least Load store dir selection
2014/01/08 21:55:31| Set Current Directory to /opt/local/var/squid/cache
2014/01/08 21:55:31| Loaded Icons.
2014/01/08 21:59:57| Accepting proxy HTTP connections at 0.0.0.0, port 3128, FD 15.
2014/01/08 21:59:57| Accepting ICP messages at 0.0.0.0, port 3130, FD 16.
2014/01/08 21:59:57| WCCP Disabled.
2014/01/08 21:59:57| Ready to serve requests.
2014/01/08 21:59:57| Done reading /opt/local/var/squid/cache swaplog (3315 entries)
2014/01/08 21:59:57| Finished rebuilding storage from disk.
2014/01/08 21:59:57|      3315 Entries scanned
2014/01/08 21:59:57|         0 Invalid entries.
2014/01/08 21:59:57|         0 With invalid flags.
2014/01/08 21:59:57|      3315 Objects loaded.
2014/01/08 21:59:57|         0 Objects expired.
2014/01/08 21:59:57|         0 Objects cancelled.
2014/01/08 21:59:57|         0 Duplicate URLs purged.
2014/01/08 21:59:57|         0 Swapfile clashes avoided.
2014/01/08 21:59:57|   Took 266.5 seconds (  12.4 objects/sec).
2014/01/08 21:59:57| Beginning Validation Procedure
2014/01/08 21:59:57|   Completed Validation Procedure
2014/01/08 21:59:57|   Validated 3315 Entries
2014/01/08 21:59:57|   store_swap_size = 92004k
2014/01/08 21:59:58| storeLateRelease: released 0 objects
2014/01/08 22:00:05| Preparing for mydomaindown after 0 requests
2014/01/08 22:00:05| Waiting 30 seconds for active connections to finish
2014/01/08 22:00:05| FD 15 Closing HTTP connection

Change History (2)

comment:1 Changed 10 years ago by mf2k (Frank Schima)

Cc: jmr@… removed
Owner: changed from macports-tickets@… to jmr@…

comment:2 Changed 6 years ago by jmroot (Joshua Root)

Resolution: → wontfix
Status: new → closed

Bugs in 2.7 are probably there to stay at this point.

Note: See TracTickets for help on using tickets.