[squid-users] ncsa_auth crashes squid

From: Tri H Trinh <trinhhoaitri@dont-contact.us>
Date: Fri, 9 Sep 2005 14:53:57 +0700

Summary:

My squid-2.5.STABLE9-8 running on FC4 (kernel 2.6.12-1.1447) and have
no problem until I introduce ncsa authentication, following the
instruction found at
http://www.linuxhomenetworking.com/linux-adv/squid.htm

Error message "WARNING: Cannot run '/usr/lib/squid/ncsa_auth' process"
found in cache.log when squid starts with /etc/rc.d/init.d/squid
script. Client browsers still see authentication screen, but squid
crashes and restarts after the client provides userid / password and
hit Enter key. In addition, many pids are assigned to squid. After
crashing and restart, some more pids are added to this list.

Squid starts and authenticates normally if we start squid from command
line instead, i.e. type #squid. No error message found in cache.log,
and client can access internet if proper id and password provided.

Details:

- Start squid using /etc/rc.d/init.d/squid script and see this warning
in the cache.log

       -|- /var/log/squid/cache.log

2005/09/09 14:24:43| Starting Squid Cache version 2.5.STABLE9 for
i386-redhat-linux-gnu...
2005/09/09 14:24:43| Process ID 2284
2005/09/09 14:24:43| With 1024 file descriptors available
2005/09/09 14:24:43| DNS Socket created at 0.0.0.0, port 32771, FD 5
2005/09/09 14:24:43| Adding nameserver 192.168.1.10 from squid.conf
2005/09/09 14:24:43| Adding nameserver 203.113.131.1 from squid.conf
2005/09/09 14:24:43| Adding nameserver 203.113.131.2 from squid.conf
2005/09/09 14:24:43| helperOpenServers: Starting 5 'ncsa_auth' processes
2005/09/09 14:24:43| WARNING: Cannot run '/usr/lib/squid/ncsa_auth' process.
2005/09/09 14:24:43| WARNING: Cannot run '/usr/lib/squid/ncsa_auth' process.
2005/09/09 14:24:43| WARNING: Cannot run '/usr/lib/squid/ncsa_auth' process.
2005/09/09 14:24:43| WARNING: Cannot run '/usr/lib/squid/ncsa_auth' process.
2005/09/09 14:24:43| WARNING: Cannot run '/usr/lib/squid/ncsa_auth' process.
2005/09/09 14:24:43| User-Agent logging is disabled.
2005/09/09 14:24:43| Referer logging is disabled.
2005/09/09 14:24:43| Unlinkd pipe opened on FD 10
2005/09/09 14:24:43| Swap maxSize 7372800 KB, estimated 567138 objects
2005/09/09 14:24:43| Target number of buckets: 28356
2005/09/09 14:24:43| Using 32768 Store buckets
2005/09/09 14:24:43| Max Mem size: 8192 KB
2005/09/09 14:24:43| Max Swap size: 7372800 KB
2005/09/09 14:24:43| Rebuilding storage in /var/spool/squid (DIRTY)
2005/09/09 14:24:43| Using Least Load store dir selection
2005/09/09 14:24:43| Set Current Directory to /var/spool/squid
2005/09/09 14:24:43| Loaded Icons.
2005/09/09 14:24:43| Accepting HTTP connections at 0.0.0.0, port 3128, FD 12.
2005/09/09 14:24:43| Accepting HTTP connections at 0.0.0.0, port 8080, FD 13.
2005/09/09 14:24:43| Accepting ICP messages at 0.0.0.0, port 3130, FD 14.
2005/09/09 14:24:43| WCCP Disabled.
2005/09/09 14:24:43| Ready to serve requests.
2005/09/09 14:24:44| Done reading /var/spool/squid swaplog (700 entries)
2005/09/09 14:24:44| Finished rebuilding storage from disk.
2005/09/09 14:24:44| 700 Entries scanned
2005/09/09 14:24:44| 0 Invalid entries.
2005/09/09 14:24:44| 0 With invalid flags.
2005/09/09 14:24:44| 700 Objects loaded.
2005/09/09 14:24:44| 0 Objects expired.
2005/09/09 14:24:44| 0 Objects cancelled.
2005/09/09 14:24:44| 0 Duplicate URLs purged.
2005/09/09 14:24:44| 0 Swapfile clashes avoided.
2005/09/09 14:24:44| Took 0.5 seconds (1362.7 objects/sec).
2005/09/09 14:24:44| Beginning Validation Procedure
2005/09/09 14:24:44| Completed Validation Procedure
2005/09/09 14:24:44| Validated 700 Entries
2005/09/09 14:24:44| store_swap_size = 5528k
2005/09/09 14:24:44| storeLateRelease: released 0 objects

       -|- Many process id are assigned for squid:

[root@tigger ~]# service squid status
squid (pid 2122 2121 2120 2119 2118 2116 2114) is running...

       -|- Start client browser, authentication prompt pops, but when
type in id and passwd wil make squid crash.

2005/09/09 14:28:33| WARNING: All basicauthenticator processes are busy.
2005/09/09 14:28:33| WARNING: up to 1 pending requests queued
2005/09/09 14:28:33| storeDirWriteCleanLogs: Starting...
2005/09/09 14:28:33| WARNING: Closing open FD 12
2005/09/09 14:28:33| Finished. Wrote 700 entries.
2005/09/09 14:28:33| Took 0.0 seconds (291909.9 entries/sec).
FATAL: Too many queued basicauthenticator requests (1 on 0)
Squid Cache (Version 2.5.STABLE9): Terminated abnormally.
CPU Usage: 0.119 seconds = 0.051 user + 0.068 sys
Maximum Resident Size: 0 KB
Page faults with physical i/o: 2
Memory usage for squid via mallinfo():
        total space in arena: 2112 KB
        Ordinary blocks: 2052 KB 4 blks
        Small blocks: 0 KB 0 blks
        Holding blocks: 340 KB 2 blks
        Free Small blocks: 0 KB
        Free Ordinary blocks: 59 KB
        Total in use: 2392 KB 113%
        Total free: 59 KB 3%
2005/09/09 14:28:36| Starting Squid Cache version 2.5.STABLE9 for
i386-redhat-linux-gnu...
2005/09/09 14:28:36| Process ID 2356
2005/09/09 14:28:36| With 1024 file descriptors available
2005/09/09 14:28:36| DNS Socket created at 0.0.0.0, port 32772, FD 5
2005/09/09 14:28:36| Adding nameserver 192.168.1.10 from squid.conf
2005/09/09 14:28:36| Adding nameserver 203.113.131.1 from squid.conf
2005/09/09 14:28:36| Adding nameserver 203.113.131.2 from squid.conf
2005/09/09 14:28:36| helperOpenServers: Starting 5 'ncsa_auth' processes
2005/09/09 14:28:36| WARNING: Cannot run '/usr/lib/squid/ncsa_auth' process.
2005/09/09 14:28:36| WARNING: Cannot run '/usr/lib/squid/ncsa_auth' process.
2005/09/09 14:28:36| WARNING: Cannot run '/usr/lib/squid/ncsa_auth' process.
2005/09/09 14:28:36| WARNING: Cannot run '/usr/lib/squid/ncsa_auth' process.
2005/09/09 14:28:36| WARNING: Cannot run '/usr/lib/squid/ncsa_auth' process.
2005/09/09 14:28:36| User-Agent logging is disabled.
2005/09/09 14:28:36| Referer logging is disabled.
2005/09/09 14:28:36| Unlinkd pipe opened on FD 10
2005/09/09 14:28:36| Swap maxSize 7372800 KB, estimated 567138 objects
2005/09/09 14:28:36| Target number of buckets: 28356
2005/09/09 14:28:36| Using 32768 Store buckets
2005/09/09 14:28:36| Max Mem size: 8192 KB
2005/09/09 14:28:36| Max Swap size: 7372800 KB
2005/09/09 14:28:36| Rebuilding storage in /var/spool/squid (CLEAN)
2005/09/09 14:28:36| Using Least Load store dir selection
2005/09/09 14:28:36| Set Current Directory to /var/spool/squid
2005/09/09 14:28:36| Loaded Icons.
2005/09/09 14:28:36| Accepting HTTP connections at 0.0.0.0, port 3128, FD 12.
2005/09/09 14:28:36| Accepting HTTP connections at 0.0.0.0, port 8080, FD 13.
2005/09/09 14:28:36| Accepting ICP messages at 0.0.0.0, port 3130, FD 14.
2005/09/09 14:28:36| WCCP Disabled.
2005/09/09 14:28:36| Ready to serve requests.
2005/09/09 14:28:36| Done reading /var/spool/squid swaplog (700 entries)
2005/09/09 14:28:36| Finished rebuilding storage from disk.
2005/09/09 14:28:36| 700 Entries scanned
2005/09/09 14:28:36| 0 Invalid entries.
2005/09/09 14:28:36| 0 With invalid flags.
2005/09/09 14:28:36| 700 Objects loaded.
2005/09/09 14:28:36| 0 Objects expired.
2005/09/09 14:28:36| 0 Objects cancelled.
2005/09/09 14:28:36| 0 Duplicate URLs purged.
2005/09/09 14:28:36| 0 Swapfile clashes avoided.
2005/09/09 14:28:36| Took 0.3 seconds (2223.5 objects/sec).
2005/09/09 14:28:36| Beginning Validation Procedure
2005/09/09 14:28:36| Completed Validation Procedure
2005/09/09 14:28:36| Validated 700 Entries
2005/09/09 14:28:36| store_swap_size = 5528k
2005/09/09 14:28:37| storeLateRelease: released 0 objects

       -|- After squid's crash & auto restart, even more pids are
assigned to squid:

[root@tigger ~]# service squid status
squid (pid 2361 2360 2359 2358 2357 2356 2290 2289 2288 2287 2286
2282) is running...

- Start squid using command line, (i.e. type #squid) no warning found
in cache.log. Client browser can authenticate normally.

2005/09/09 14:38:21| Starting Squid Cache version 2.5.STABLE9 for
i386-redhat-linux-gnu...
2005/09/09 14:38:21| Process ID 2211
2005/09/09 14:38:21| With 1024 file descriptors available
2005/09/09 14:38:21| Performing DNS Tests...
2005/09/09 14:38:21| Successful DNS name lookup tests...
2005/09/09 14:38:21| DNS Socket created at 0.0.0.0, port 32771, FD 5
2005/09/09 14:38:21| Adding nameserver 192.168.1.10 from squid.conf
2005/09/09 14:38:21| Adding nameserver 203.113.131.1 from squid.conf
2005/09/09 14:38:21| Adding nameserver 203.113.131.2 from squid.conf
2005/09/09 14:38:21| helperOpenServers: Starting 5 'ncsa_auth' processes
2005/09/09 14:38:22| User-Agent logging is disabled.
2005/09/09 14:38:22| Referer logging is disabled.
2005/09/09 14:38:22| Unlinkd pipe opened on FD 15
2005/09/09 14:38:22| Swap maxSize 7372800 KB, estimated 567138 objects
2005/09/09 14:38:22| Target number of buckets: 28356
2005/09/09 14:38:22| Using 32768 Store buckets
2005/09/09 14:38:22| Max Mem size: 8192 KB
2005/09/09 14:38:22| Max Swap size: 7372800 KB
2005/09/09 14:38:22| Rebuilding storage in /var/spool/squid (CLEAN)
2005/09/09 14:38:22| Using Least Load store dir selection
2005/09/09 14:38:22| Set Current Directory to /var/spool/squid
2005/09/09 14:38:22| Loaded Icons.
2005/09/09 14:38:23| Accepting HTTP connections at 0.0.0.0, port 3128, FD 17.
2005/09/09 14:38:23| Accepting HTTP connections at 0.0.0.0, port 8080, FD 18.
2005/09/09 14:38:23| Accepting ICP messages at 0.0.0.0, port 3130, FD 19.
2005/09/09 14:38:23| WCCP Disabled.
2005/09/09 14:38:23| Ready to serve requests.
2005/09/09 14:38:23| Done reading /var/spool/squid swaplog (700 entries)
2005/09/09 14:38:23| Finished rebuilding storage from disk.
2005/09/09 14:38:23| 700 Entries scanned
2005/09/09 14:38:23| 0 Invalid entries.
2005/09/09 14:38:23| 0 With invalid flags.
2005/09/09 14:38:23| 700 Objects loaded.
2005/09/09 14:38:23| 0 Objects expired.
2005/09/09 14:38:23| 0 Objects cancelled.
2005/09/09 14:38:23| 0 Duplicate URLs purged.
2005/09/09 14:38:23| 0 Swapfile clashes avoided.
2005/09/09 14:38:23| Took 0.5 seconds (1288.7 objects/sec).
2005/09/09 14:38:23| Beginning Validation Procedure
2005/09/09 14:38:23| Completed Validation Procedure
2005/09/09 14:38:23| Validated 700 Entries
2005/09/09 14:38:23| store_swap_size = 5528k
2005/09/09 14:38:23| storeLateRelease: released 0 objects

       -|- Squid's pid

[root@tigger ~]# service squid status
squid (pid 2211 2209) is running...

-- 
Tri H. Trinh
--------------------------------------------------------
The Linux philosophy is 'Laugh in the face 
of danger'. Oops. Wrong One. 'Do it yourself'. 
Yes, that's it.
                                          Linus Torvalds
Received on Fri Sep 09 2005 - 01:53:58 MDT

This archive was generated by hypermail pre-2.1.9 : Sat Oct 01 2005 - 12:00:03 MDT