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

It would help a lot if you too could get a strack trace.

Are you too using the diskd store?

--
Henrik Nordstrom
Squid hacker
Sonny Franslay wrote:
> 
> 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