Re: [squid-users] sigsegv again :-(

From: Henrik Nordstrom <hno@dont-contact.us>
Date: Thu, 13 Nov 2003 10:04:58 +0100 (CET)

Please file a bug report for this issue.

Regards
Henrik

On Thu, 13 Nov 2003, oleg wrote:

>
> hello.
> i'm facing strange situation.
> from the users' point of view squid works as normal, BUT
> in my cache.log i have the following
> ===========================================
> 2003/11/13 09:16:08| Starting Squid Cache version 2.5.STABLE4 for i686-pc-linux-gnu...
> 2003/11/13 09:16:08| Process ID 22150
> 2003/11/13 09:16:08| With 1024 file descriptors available
> 2003/11/13 09:16:08| DNS Socket created at 0.0.0.0, port 32796, FD 4
> 2003/11/13 09:16:08| Adding nameserver 192.168.7.5 from squid.conf
> 2003/11/13 09:16:08| helperOpenServers: Starting 10 'squidGuard' processes
> 2003/11/13 09:16:09| helperOpenServers: Starting 7 'auth_md5_wo_ip' processes
> 2003/11/13 09:16:10| helperOpenServers: Starting 8 'ip_acl' processes
> 2003/11/13 09:16:11| Unlinkd pipe opened on FD 35
> 2003/11/13 09:16:11| Swap maxSize 2682880 KB, estimated 206375 objects
> 2003/11/13 09:16:11| Target number of buckets: 10318
> 2003/11/13 09:16:11| Using 16384 Store buckets
> 2003/11/13 09:16:11| Max Mem size: 49152 KB
> 2003/11/13 09:16:11| Max Swap size: 2682880 KB
> 2003/11/13 09:16:11| Store logging disabled
> 2003/11/13 09:16:11| Rebuilding storage in /cache (CLEAN)
> 2003/11/13 09:16:11| Using Least Load store dir selection
> 2003/11/13 09:16:11| Set Current Directory to /cache/
> 2003/11/13 09:16:11| Loaded Icons.
> 2003/11/13 09:16:13| Accepting HTTP connections at 192.168.7.1, port 3128, FD 36.
> 2003/11/13 09:16:13| Ready to serve requests.
> 2003/11/13 09:16:13| Store rebuilding is 5.2% complete
> 2003/11/13 09:16:16| Done reading /cache swaplog (78778 entries)
> 2003/11/13 09:16:16| Finished rebuilding storage from disk.
> 2003/11/13 09:16:16| 78778 Entries scanned
> 2003/11/13 09:16:16| 0 Invalid entries.
> 2003/11/13 09:16:16| 0 With invalid flags.
> 2003/11/13 09:16:16| 78776 Objects loaded.
> 2003/11/13 09:16:16| 0 Objects expired.
> 2003/11/13 09:16:16| 0 Objects cancelled.
> 2003/11/13 09:16:16| 1 Duplicate URLs purged.
> 2003/11/13 09:16:16| 1 Swapfile clashes avoided.
> 2003/11/13 09:16:16| Took 4.5 seconds (17586.1 objects/sec).
> 2003/11/13 09:16:16| Beginning Validation Procedure
> 2003/11/13 09:16:16| Completed Validation Procedure
> 2003/11/13 09:16:16| Validated 78776 Entries
> 2003/11/13 09:16:16| store_swap_size = 869504k
> 2003/11/13 09:16:16| storeLateRelease: released 0 objects
> (squid)[0x80996a9]
> /lib/libc.so.6[0x400bb4f8]
> (squid)[0x80a9515]
> (squid)[0x8076db8]
> (squid)[0x8064839]
> (squid)[0x808410f]
> /lib/libc.so.6(__libc_start_main+0xc7)[0x400a8917]
> (squid)(log+0xa1)[0x804a6fd]
> FATAL: Received Segment Violation...dying.
> 2003/11/13 09:52:04| storeDirWriteCleanLogs: Starting...
> 2003/11/13 09:52:04| WARNING: Closing open FD 36
> 2003/11/13 09:52:04| 65536 entries written so far.
> 2003/11/13 09:52:04| Finished. Wrote 79389 entries.
> 2003/11/13 09:52:04| Took 0.1 seconds (1173300.0 entries/sec).
> CPU Usage: 9.990 seconds = 6.880 user + 3.110 sys
> Maximum Resident Size: 0 KB
> Page faults with physical i/o: 362
> Memory usage for squid via mallinfo():
> total space in arena: 13152 KB
> Ordinary blocks: 13133 KB 16 blks
> Small blocks: 0 KB 6 blks
> Holding blocks: 1164 KB 4 blks
> Free Small blocks: 0 KB
> Free Ordinary blocks: 18 KB
> Total in use: 14297 KB 109%
> Total free: 18 KB 0%
> 2003/11/13 09:52:07| Starting Squid Cache version 2.5.STABLE4 for i686-pc-linux-gnu...
> 2003/11/13 09:52:07| Process ID 22321
> 2003/11/13 09:52:07| With 1024 file descriptors available
> 2003/11/13 09:52:07| DNS Socket created at 0.0.0.0, port 32797, FD 4
> 2003/11/13 09:52:07| Adding nameserver 192.168.7.5 from squid.conf
> 2003/11/13 09:52:07| helperOpenServers: Starting 10 'squidGuard' processes
> 2003/11/13 09:52:08| helperOpenServers: Starting 7 'auth_md5_wo_ip' processes
> 2003/11/13 09:52:09| helperOpenServers: Starting 8 'ip_acl' processes
> 2003/11/13 09:52:10| Unlinkd pipe opened on FD 35
> 2003/11/13 09:52:10| Swap maxSize 2682880 KB, estimated 206375 objects
> 2003/11/13 09:52:10| Target number of buckets: 10318
> 2003/11/13 09:52:10| Using 16384 Store buckets
> 2003/11/13 09:52:10| Max Mem size: 49152 KB
> 2003/11/13 09:52:10| Max Swap size: 2682880 KB
> 2003/11/13 09:52:10| Store logging disabled
> 2003/11/13 09:52:10| Rebuilding storage in /cache (CLEAN)
> 2003/11/13 09:52:10| Using Least Load store dir selection
> 2003/11/13 09:52:10| Set Current Directory to /cache/
> 2003/11/13 09:52:10| Loaded Icons.
> 2003/11/13 09:52:12| Accepting HTTP connections at 192.168.7.1, port 3128, FD 36.
> 2003/11/13 09:52:12| Ready to serve requests.
> 2003/11/13 09:52:12| Store rebuilding is 5.2% complete
> 2003/11/13 09:52:12| Done reading /cache swaplog (79389 entries)
> 2003/11/13 09:52:12| Finished rebuilding storage from disk.
> 2003/11/13 09:52:12| 79389 Entries scanned
> 2003/11/13 09:52:12| 0 Invalid entries.
> 2003/11/13 09:52:12| 0 With invalid flags.
> 2003/11/13 09:52:12| 79389 Objects loaded.
> 2003/11/13 09:52:12| 0 Objects expired.
> 2003/11/13 09:52:12| 0 Objects cancelled.
> 2003/11/13 09:52:12| 0 Duplicate URLs purged.
> 2003/11/13 09:52:12| 0 Swapfile clashes avoided.
> 2003/11/13 09:52:12| Took 1.9 seconds (40905.7 objects/sec).
> 2003/11/13 09:52:12| Beginning Validation Procedure
> 2003/11/13 09:52:12| Completed Validation Procedure
> 2003/11/13 09:52:12| Validated 79389 Entries
> 2003/11/13 09:52:12| store_swap_size = 874492k
> 2003/11/13 09:52:13| storeLateRelease: released 0 objects
> (squid)[0x80996a9]
> /lib/libc.so.6[0x400bb4f8]
> (squid)[0x80a9515]
> (squid)[0x8076db8]
> (squid)[0x8064839]
> (squid)[0x808410f]
> /lib/libc.so.6(__libc_start_main+0xc7)[0x400a8917]
> (squid)(log+0xa1)[0x804a6fd]
> FATAL: Received Segment Violation...dying.
> 2003/11/13 09:52:14| storeDirWriteCleanLogs: Starting...
> 2003/11/13 09:52:14| WARNING: Closing open FD 36
> 2003/11/13 09:52:14| 65536 entries written so far.
> 2003/11/13 09:52:14| Finished. Wrote 79389 entries.
> 2003/11/13 09:52:14| Took 0.1 seconds (1149316.0 entries/sec).
> CPU Usage: 0.900 seconds = 0.700 user + 0.200 sys
> Maximum Resident Size: 0 KB
> Page faults with physical i/o: 329
> Memory usage for squid via mallinfo():
> total space in arena: 9672 KB
> Ordinary blocks: 9655 KB 2 blks
> Small blocks: 0 KB 5 blks
> Holding blocks: 1164 KB 4 blks
> Free Small blocks: 0 KB
> Free Ordinary blocks: 17 KB
> Total in use: 10819 KB 112%
> Total free: 17 KB 0%
> 2003/11/13 09:52:17| Starting Squid Cache version 2.5.STABLE4 for i686-pc-linux-gnu...
> 2003/11/13 09:52:17| Process ID 22367
> 2003/11/13 09:52:17| With 1024 file descriptors available
> 2003/11/13 09:52:17| DNS Socket created at 0.0.0.0, port 32797, FD 4
> 2003/11/13 09:52:17| Adding nameserver 192.168.7.5 from squid.conf
> 2003/11/13 09:52:17| helperOpenServers: Starting 10 'squidGuard' processes
> 2003/11/13 09:52:18| helperOpenServers: Starting 7 'auth_md5_wo_ip' processes
> 2003/11/13 09:52:19| helperOpenServers: Starting 8 'ip_acl' processes
> 2003/11/13 09:52:21| Unlinkd pipe opened on FD 35
> 2003/11/13 09:52:21| Swap maxSize 2682880 KB, estimated 206375 objects
> 2003/11/13 09:52:21| Target number of buckets: 10318
> 2003/11/13 09:52:21| Using 16384 Store buckets
> 2003/11/13 09:52:21| Max Mem size: 49152 KB
> 2003/11/13 09:52:21| Max Swap size: 2682880 KB
> 2003/11/13 09:52:21| tore logging disabled
> 2003/11/13 09:52:21| Rebuilding storage in /cache (CLEAN)
> 2003/11/13 09:52:21| Using Least Load store dir selection
> 2003/11/13 09:52:21| Set Current Directory to /cache/
> 2003/11/13 09:52:21| Loaded Icons.
> 2003/11/13 09:52:22| Accepting HTTP connections at 192.168.7.1, port 3128, FD 36.
> 2003/11/13 09:52:22| Ready to serve requests.
> 2003/11/13 09:52:22| Store rebuilding is 5.2% complete
> 2003/11/13 09:52:23| Done reading /cache swaplog (79389 entries)
> 2003/11/13 09:52:23| Finished rebuilding storage from disk.
> 2003/11/13 09:52:23| 79389 Entries scanned
> 2003/11/13 09:52:23| 0 Invalid entries.
> 2003/11/13 09:52:23| 0 With invalid flags.
> 2003/11/13 09:52:23| 79389 Objects loaded.
> 2003/11/13 09:52:23| 0 Objects expired.
> 2003/11/13 09:52:23| 0 Objects cancelled.
> 2003/11/13 09:52:23| 0 Duplicate URLs purged.
> 2003/11/13 09:52:23| 0 Swapfile clashes avoided.
> 2003/11/13 09:52:23| Took 2.1 seconds (37022.0 objects/sec).
> 2003/11/13 09:52:23| Beginning Validation Procedure
> 2003/11/13 09:52:23| Completed Validation Procedure
> 2003/11/13 09:52:23| Validated 79389 Entries
> 2003/11/13 09:52:23| store_swap_size = 874492k
> 2003/11/13 09:52:23| storeLateRelease: released 0 objects
> =======================================================================================
>
> gdb backtrace of stack
> ========================================================
> This GDB was configured as "i386-redhat-linux-gnu"...
> (gdb) list *0x80996a9
> 0x80996a9 is in death (tools.c:281).
> 276 #endif /* _SQUID_SOLARIS_ */
> 277 #if HAVE_BACKTRACE_SYMBOLS_FD
> 278 {
> 279 static void *(callarray[8192]);
> 280 int n;
> 281 n = backtrace(callarray, 8192);
> 282 backtrace_symbols_fd(callarray, n, fileno(debug_log));
> 283 }
> 284 #endif
> 285 #endif /* PRINT_STACK_TRACE */
> (gdb) list *0x80a9515
> 0x80a9515 is in authenticateDigestHandleReply (digest/auth_digest.c:899).
> 894 digest_user = auth_user_request->auth_user->scheme_data;
> 895 if (reply && (strncasecmp(reply, "ERR", 3) == 0))
> 896 digest_request->flags.credentials_ok = 3;
> 897 else {
> 898 CvtBin(reply, digest_user->HA1);
> 899 digest_user->HA1created = 1;
> 900 }
> 901 valid = cbdataValid(r->data);
> 902 if (valid)
> 903 r->handler(r->data, NULL);
> (gdb) list *0x8076db8
> 0x8076db8 is in helperHandleRead (helper.c:751).
> 746 } else if ((t = strchr(srv->buf, '\n'))) {
> 747 /* end of reply found */
> 748 debug(84, 3) ("helperHandleRead: end of reply found\n");
> 749 *t = '\0';
> 750 if (cbdataValid(r->data))
> 751 r->callback(r->data, srv->buf);
> 752 srv->flags.busy = 0;
> 753 srv->offset = 0;
> 754 helperRequestFree(r);
> 755 srv->request = NULL;
> (gdb) list *0x8064839
> 0x8064839 is in comm_poll (comm_select.c:447).
> 442 #endif
> 443 else {
> 444 F->read_handler = NULL;
> 445 hdl(fd, F->read_data);
> 446 statCounter.select_fds++;
> 447 if (commCheckICPIncoming)
> 448 comm_poll_icp_incoming();
> 449 if (commCheckDNSIncoming)
> 450 comm_poll_dns_incoming();
> 451 if (commCheckHTTPIncoming)
> (gdb) list *0x808410f
> 0x808410f is in main (main.c:743).
> 738 }
> 739 eventRun();
> 740 if ((loop_delay = eventNextTime()) < 0)
> 741 loop_delay = 0;
> 742 #if HAVE_POLL
> 743 switch (comm_poll(loop_delay)) {
> 744 #else
> 745 switch (comm_select(loop_delay)) {
> 746 #endif
> 747 case COMM_OK:
> ===============================================================================
>
> my build options were
> =========================================
> ./configure \
> --enable-storeio="ufs diskd" \
> --enable-removal-policies="lru heap" \
> --enable-delay-pools \
> --disable-icmp \
> --disable-wccp \
> --disable-snmp \
> --enable-arp-acl \
> --disable-htcp \
> --enable-err-languages="English Russian-1251 Russian-koi8-r" \
> --enable-default-err-language="Russian-koi8-r" \
> --enable-poll \
> --disable-ident-lookups \
> --enable-truncate \
> --enable-auth="basic digest" \
> --enable-stacktraces
> =====================================================
>
> AFAICS squid does not exit, it just starts new child instead of one that died.
> and no core files at coredump_dir
>
> this is squid 2.5.STABLE4 with all availible patches applied (except some
> latest cosmetic)
> Red Hat 9.0
> 2.4.22 kernel from kernel.org
>
> can someone tell something on this?
>
> oleg
>
Received on Thu Nov 13 2003 - 02:05:02 MST

This archive was generated by hypermail pre-2.1.9 : Tue Dec 09 2003 - 17:21:16 MST