Re: [SQU] Squid 2.4 Head FATAL: Received Segment Violation...dying

From: Sonny Franslay <sonnyfranslay@dont-contact.us>
Date: Wed, 14 Feb 2001 16:10:40 +0800 (Singapore Standard Time)

Hi,

I am also experiencing the same kind of problem with Squid2.4
Pre-Stable. However, this problem does not occur just after we run
squid but much later after that.

What I notice however is that this Segment Violation error occurs when
there are numerous Forwarding loop. This error is kinda weird as we did
not used to have such warning with 2.4Dev4. Below is an extract for such
error:

->2001/02/13 23:04:03| WARNING: Forwarding loop detected for:
->GET
->/scripts/cms/CmsInit.ASP?ID=1&D2=l?OACC@??????&AW=167&LV=2045&CU=51312796
->HTTP/1.0
->User-Agent: Mozilla/4.01 [en] (WinNT; I)
->Pragma: no-cache
->Accept: image/gif, image/x-xbitmap, image/jpeg, image/pjpeg, */*
->Accept-Language: en
->Accept-Charset: iso-8859-1,*,utf-8
->Via: 1.0 proxy1.foo.com:8080 (Squid/2.4.PRE-STABLE), 1.0
->proxy11.foo.com:8080 (Squid/2.4.PRE-STABLE
->), 1.0 proxy2.foo.com:8080 (Squid/2.4.PRE-STABLE), 1.0
->prpxy12.foo.com:8080 (Squid/2.4.PRE-STABLE)
->X-Forwarded-For: 192.168.41.38, 192.168.41.43, 192.168.41.34
->Host: proxy.foo.com:8080
->Cache-Control: max-age=0
->Connection: keep-alive

then squid will die:

->FATAL: Received Segment Violation...dying.
->2001/02/13 23:04:06| Not currently OK to rewrite swap log.
->001/02/13 23:04:06| storeDirWriteCleanLogs: Operation aborted.

Another thing I notice also is that such forwarding loop error only with
WinNT client (not sure if it is true WinNT or Win2k).

  User-Agent: Mozilla/4.01 [en] (WinNT; I)

Currently, one way to end the segmentation fault error is to stop
squid, remove all the swap.state file under squid/swap directory and start
squid. This somehow helps but I am not very comfortable with such measure.

Have been losing sleep over this, I really hope someone can enlighten me
on this.

thanks in advance.

Sonny I. Franslay
--------------------

On Tue, 13 Feb 2001, Alejandro A. Ramirez wrote:

> Hi Henrik,
>
> Im testing the squid-2.4-200102120000 version, and it seems that I have
> hitted a bug, below you will find the backtrace, Im using FreeBSD 4.2 with 2
> PIII 600 Mhz processors, and 1 Gig of Ram, it was serving 18.7 kreq/min with
> a very good performance, the configuration options are as follows:
>
> setenv PREFIX /usr/local
>
> ./configure --prefix=${PREFIX} \
> --with-layout=GNU \
> --bindir=${PREFIX}/sbin \
> --sysconfdir=${PREFIX}/etc/squid \
> --localstatedir=${PREFIX}/squid \
> --enable-snmp \
> --disable-ident-lookups \
> --enable-underscores \
> --disable-icp \
> --enable-truncate \
> --enable-storeio=ufs,diskd
>
> And in the squid.conf I have all the cache_dirīs like this one :
>
> cache_dir diskd -1 /cache0/0 6000 16 256 64 72
>
> The kernel is compiled with the following options:
>
> options NMBCLUSTERS=32768 #Support for 32M for MBufs
> options MAXDSIZ="(1024*1024*1024)"
> options DFLDSIZ="(1024*1024*1024)"
> options PQ_LARGECACHE
> options SYSVMSG
> options MAXFILES=32768
> options MSGMNB=16384
> options MSGMNI=41
> options MSGSEG=2049
> options MSGSSZ=64
> options MSGTQL=1024
> options SYSVSHM
> options SHMSEG=16
> options SHMMNI=32
> options SHMMAX=2097152
> options SHMALL=8192
>
> The system log file it showed this:
>
> Feb 13 12:35:22 cache /kernel: pid 214 (squid), uid 80: exited on signal 11
>
> cache# netstat -mb
> 68/16352/131072 mbufs in use (current/peak/max):
> 66 mbufs allocated to data
> 2 mbufs allocated to packet headers
> 64/5632/32768 mbuf clusters in use (current/peak/max)
> 15352 Kbytes allocated to network (15% of mb_map in use)
> 0 requests for memory denied
> 0 requests for memory delayed
> 0 calls to protocol drain routines
>
> cache# df
> Filesystem 1K-blocks Used Avail Capacity Mounted on
> /dev/idad0s1a 254063 43537 190201 19% /
> /dev/idad0s1h 60521954 619863 55060335 1% /cache0
> /dev/da0s1e 17235871 577908 15279094 4% /cache1/0
> /dev/da1s1e 17235871 567513 15289489 4% /cache1/1
> /dev/da2s1e 17235871 629858 15227144 4% /cache1/2
> /dev/da3s1e 17235871 619487 15237515 4% /cache1/3
> /dev/da4s1e 17235871 586776 15270226 4% /cache1/4
> /dev/da5s1e 17235871 577241 15279761 4% /cache1/5
> /dev/idad0s1e 1016303 11 934988 0% /tmp
> /dev/idad0s1g 4065262 544458 3195584 15% /usr
> /dev/idad0s1f 2032623 599 1869415 0% /var
> procfs 4 4 0 100% /proc
>
> The filesystems are mounted with softupdates & noatime option.
>
> Here are the first two errors that I got before I used GDB for getting a
> backtrace:
>
> 2001/02/13 11:26:33| clientReadRequest: FD 672 Invalid Request
> 2001/02/13 11:26:33| clientSendMoreData: Deferring error:invalid-request
> FATAL: Received Segment Violation...dying.
> 2001/02/13 11:26:38| storeDirWriteCleanLogs: Starting...
> 2001/02/13 11:26:38| WARNING: Closing open FD 22
> 2001/02/13 11:26:38| 65536 entries written so far.
> 2001/02/13 11:26:38| 131072 entries written so far.
> 2001/02/13 11:26:38| Finished. Wrote 156863 entries.
> 2001/02/13 11:26:38| Took 0.5 seconds (325129.6 entries/sec).
> CPU Usage: 2526.218 seconds = 1370.164 user + 1156.054 sys
> Maximum Resident Size: 245556 KB
> Page faults with physical i/o: 0
>
> 2001/02/13 11:30:34| clientReadRequest: FD 4339 Invalid Request
> 2001/02/13 11:30:34| clientSendMoreData: Deferring error:invalid-request
> FATAL: Received Bus Error...dying.
> 2001/02/13 11:30:36| storeDirWriteCleanLogs: Starting...
> 2001/02/13 11:30:36| WARNING: Closing open FD 28
> 2001/02/13 11:30:36| 65536 entries written so far.
> 2001/02/13 11:30:36| 131072 entries written so far.
> 2001/02/13 11:30:36| Finished. Wrote 168271 entries.
> 2001/02/13 11:30:36| Took 0.4 seconds (384771.6 entries/sec).
> CPU Usage: 183.611 seconds = 97.945 user + 85.666 sys
> Maximum Resident Size: 154836 KB
> Page faults with physical i/o: 2
>
> Here it is the GDB Backtrace:
>
> Script started on Tue Feb 13 12:01:17 2001
> GNU gdb 4.18
> Copyright 1998 Free Software Foundation, Inc.
> GDB is free software, covered by the GNU General Public License, and you are
> welcome to change it and/or distribute copies of it under certain
> conditions.
> Type "show copying" to see the conditions.
> There is absolutely no warranty for GDB. Type "show warranty" for details.
> This GDB was configured as "i386-unknown-freebsd"...
> (gdb) handle SIGPIPE noprint nostop passhandle SIGPIPE noprint nostop pass
> Signal Stop Print Pass to program Description
> SIGPIPE No No Yes Broken pipe
> (gdb) r -CNd1r -CNd1
> Starting program: /usr/local/sbin/squid -CNd1
> 2001/02/13 12:01:28| Starting Squid Cache version 2.4.PRE-STABLE for
> i386-unknown-freebsd4.2...
> 2001/02/13 12:01:28| Process ID 214
> 2001/02/13 12:01:28| With 32768 file descriptors available
> 2001/02/13 12:01:28| Performing DNS Tests...
> 2001/02/13 12:01:28| Successful DNS name lookup tests...
> 2001/02/13 12:01:28| DNS Socket created on FD 7
> 2001/02/13 12:01:28| Adding nameserver 127.0.0.1 from /etc/resolv.conf
> 2001/02/13 12:01:28| Unlinkd pipe opened on FD 12
> 2001/02/13 12:01:28| Swap maxSize 43008000 KB, estimated 3308307 objects
> 2001/02/13 12:01:28| Target number of buckets: 165415
> 2001/02/13 12:01:28| Using 262144 Store buckets
> 2001/02/13 12:01:28| Max Mem size: 131072 KB
> 2001/02/13 12:01:28| Max Swap size: 43008000 KB
> 2001/02/13 12:01:28| Store logging disabled
> 2001/02/13 12:01:28| Rebuilding storage in /cache0/0 (DIRTY)
> 2001/02/13 12:01:28| Rebuilding storage in /cache1/0/0 (DIRTY)
> 2001/02/13 12:01:28| Rebuilding storage in /cache1/1/0 (DIRTY)
> 2001/02/13 12:01:28| Rebuilding storage in /cache1/2/0 (DIRTY)
> 2001/02/13 12:01:28| Rebuilding storage in /cache1/3/0 (DIRTY)
> 2001/02/13 12:01:28| Rebuilding storage in /cache1/4/0 (DIRTY)
> 2001/02/13 12:01:28| Rebuilding storage in /cache1/5/0 (DIRTY)
> 2001/02/13 12:01:28| Using Round Robin store dir selection
> 2001/02/13 12:01:28| Set Current Directory to /cache0/0
> 2001/02/13 12:01:28| Loaded Icons.
> 2001/02/13 12:01:28| Accepting HTTP connections at 0.0.0.0, port 80, FD 31.
> 2001/02/13 12:01:28| Accepting SNMP messages on port 1610, FD 33.
> 2001/02/13 12:01:28| Accepting WCCP messages on port 2048, FD 34.
> 2001/02/13 12:01:28| Ready to serve requests.
> 2001/02/13 12:01:30| Store rebuilding is 17.0% complete
> 2001/02/13 12:01:37| Done reading /cache1/1/0 swaplog (24037 entries)
> 2001/02/13 12:01:37| Done reading /cache1/0/0 swaplog (24078 entries)
> 2001/02/13 12:01:37| Done reading /cache1/2/0 swaplog (24075 entries)
> 2001/02/13 12:01:37| Done reading /cache1/3/0 swaplog (24077 entries)
> 2001/02/13 12:01:37| Done reading /cache1/5/0 swaplog (24077 entries)
> 2001/02/13 12:01:37| Done reading /cache0/0 swaplog (24114 entries)
> 2001/02/13 12:01:37| Done reading /cache1/4/0 swaplog (24142 entries)
> 2001/02/13 12:01:37| Finished rebuilding storage from disk.
> 2001/02/13 12:01:37| 168360 Entries scanned
> 2001/02/13 12:01:37| 0 Invalid entries.
> 2001/02/13 12:01:37| 0 With invalid flags.
> 2001/02/13 12:01:37| 168117 Objects loaded.
> 2001/02/13 12:01:37| 0 Objects expired.
> 2001/02/13 12:01:37| 240 Objects cancelled.
> 2001/02/13 12:01:37| 4 Duplicate URLs purged.
> 2001/02/13 12:01:37| 2 Swapfile clashes avoided.
> 2001/02/13 12:01:37| Took 8.4 seconds (19971.4 objects/sec).
> 2001/02/13 12:01:37| Beginning Validation Procedure
> 2001/02/13 12:01:37| Completed Validation Procedure
> 2001/02/13 12:01:37| Validated 168114 Entries
> 2001/02/13 12:01:37| store_swap_size = 1619718k
> 2001/02/13 12:01:37| storeLateRelease: released 0 objects
> 2001/02/13 12:01:48| parseHttpRequest: Unsupported method 'HA'
> 2001/02/13 12:01:48| clientReadRequest: FD 150 Invalid Request
> 2001/02/13 12:01:58| parseHttpRequest: Requestheader contains NULL
> characters
> ...
> ...
> ...
> 2001/02/13 12:27:54| parseHttpRequest: Requestheader contains NULL
> characters
> 2001/02/13 12:27:54| clientReadRequest: FD 794 Invalid Request
> 2001/02/13 12:27:54| clientSendMoreData: Deferring error:invalid-request
>
> Program received signal SIGSEGV, Segmentation fault.
> 0x80aa847 in linklistPush (L=0x132843, p=0x50137000) at tools.c:873
> 873 while (*L)
> (gdb) bt
> #0 0x80aa847 in linklistPush (L=0x132843, p=0x50137000) at tools.c:873
> #1 0x80b7a20 in storeDiskdShmPut (sd=0x820d948, offset=192512) at
> store_dir_diskd.c:1643
> #2 0x80b482c in storeDiskdDirCallback (SD=0x820d948) at
> store_dir_diskd.c:532
> #3 0x80a6ac3 in storeDirCallback () at store_dir.c:463
> #4 0x8065f0a in comm_poll (msec=0) at comm_select.c:330
> #5 0x80882ed in main (argc=2, argv=0xbfbffc24) at main.c:720
> #6 0x804a529 in _start ()
> (gdb) c
> Continuing.
>
> Program terminated with signal SIGSEGV, Segmentation fault.
> The program no longer exists.
> Script done on Tue Feb 13 12:35:41 2001
>
> I Hope this can help you to debug this, if there is anything else that I can
> do to help, just let me know.
>
> Greetings
> Ales
>
>
>
> --
> To unsubscribe, see http://www.squid-cache.org/mailing-lists.html
>

--
To unsubscribe, see http://www.squid-cache.org/mailing-lists.html
Received on Wed Feb 14 2001 - 01:12:59 MST

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