Running valgrind and some asserts against squid-3.0-cvs

From: Reuben Farrelly <reuben-squid-dev@dont-contact.us>
Date: Sat, 09 Nov 2002 22:08:48 +1100

Hi,

Have just spent a bit of time running valgrind 1.0.4 against squid-3.0 and
here are some findings/observations/outputs...looks like some may be comms
related (Adri?)

Running valgrind --error-limit=no -v --gdb-attach=yes
/usr/sbin/squid-3.0 -NCd1 I had problems with gdb attaching to the
process when launching as root, however seems to be ok when launch under
user 'squid'. I'm testing against 3.0-cvs (as of a few hours ago) and
2.5-cvs (before the latest commits in the last hour or two)

1. Appears in 2.5 also, possibly harmless (Henrik?) on boot:

==19169== Conditional jump or move depends on uninitialised value(s)
==19169== at 0x420BACDB: (within /lib/i686/libc-2.3.1.so)
==19169== by 0x420BA3E5: (within /lib/i686/libc-2.3.1.so)
==19169== by 0x808C507: mimeGetEntry(char const*, int) (mime.cc:214)
==19169== by 0x808C711: mimeGetContentType (mime.cc:289)
(valgrind summary shows 1939 times at completion)

2,3,4 Appear when first object retrieved from the cache however valgrind
reports these ones as occurring 245868, 281859 and 380243 times respectively :

==18835== Conditional jump or move depends on uninitialised value(s)
==18835== at 0x420BACDB: (within /lib/i686/libc-2.3.1.so)
==18835== by 0x420BA3E5: (within /lib/i686/libc-2.3.1.so)
==18835== by 0x804E00A: aclMatchRegex (acl.cc:1066)
==18835== by 0x804EC19: aclMatchAcl(_acl*, _aclCheck_t*) (acl.cc:1565)

==18835== Conditional jump or move depends on uninitialised value(s)
==18835== at 0x420BACDB: (within /lib/i686/libc-2.3.1.so)
==18835== by 0x420BA3E5: (within /lib/i686/libc-2.3.1.so)
==18835== by 0x809180B: refreshLimits(char const*) (refresh.cc:115)
==18835== by 0x8092094: getMaxAge (refresh.cc:407)

==18835== Conditional jump or move depends on uninitialised value(s)
==18835== at 0x420BACDB: (within /lib/i686/libc-2.3.1.so)
==18835== by 0x420BA3E5: (within /lib/i686/libc-2.3.1.so)
==18835== by 0x809180B: refreshLimits(char const*) (refresh.cc:115)
==18835== by 0x8091AE8: refreshCheck(_StoreEntry const*, _request_t*,
long) (refresh.cc:230)

5. Going to http://windowsupdate.microsoft.com/ has a few times today
triggered an assert which kills off valgrind as well as squid (ugh):

2002/11/09 19:47:17| clientReplyContext::saveState: saving store context
2002/11/09 19:47:48| assertion failed: ssl.cc:228: "len ==
(size_t)sslState->client.len"
Aborted
[root@tornado squid]#

Yep, back at a shell so no chance to run gdb or anything. This one only
seems to occur when run under valgrind though - haven't see this one ever
before when running with gdb only or standalone.

6. Just got this one come through as well running valgrind, dropping
into gdb:

==19169==
==19169== Syscall param write(buf) contains uninitialised or unaddressable
byte(s)
==19169== at 0x420CACE4: (within /lib/i686/libc-2.3.1.so)
==19169== by 0x8066403: comm_write_try(int, void*) (comm.cc:661)
==19169== by 0x8069892: comm_select (comm_poll.cc:474)
==19169== by 0x808A211: main (main.cc:724)
==19169== Address 0x4817187E is 726 bytes inside a block of size 87380
alloc'd
==19169== at 0x4003CDDA: malloc (vg_clientfuncs.c:100)
==19169== by 0x80BFF8E: xmalloc (util.c:463)
==19169== by 0x8096DC4: sslStart (ssl.cc:491)
==19169== by 0x8065192: clientProcessRequest(_clientHttpRequest*)
(client_side_request.cc:577)
==19169==
==19169== ---- Attach to GDB ? --- [Return/N/n/Y/y/C/c] ---- y
==19169== starting GDB with cmd: /usr/bin/gdb -nw /proc/19169/exe 19169
<loads lots of symbols>
Loaded symbols for /lib/libnss_dns.so.2
vg_do_syscall3 (syscallno=4294966784, arg1=19177, arg2=0, arg3=0)
     at vg_mylibc.c:92
92 }
(gdb) bt
#0 vg_do_syscall3 (syscallno=4294966784, arg1=19177, arg2=0, arg3=0)
     at vg_mylibc.c:92
#1 0x00004ae9 in ?? ()
#2 0x420cace4 in write () from /lib/i686/libc.so.6
#3 0x08066403 in comm_write_try (fd=1096779496, data=0x0) at comm.cc:660
#4 0x08069892 in comm_select (msec=10) at comm_poll.cc:471
#5 0x0808a211 in main (argc=2, argv=0x141) at main.cc:724
#6 0x42015a54 in __libc_start_main () from /lib/i686/libc.so.6
Current language: auto; currently c
(gdb)
(gdb) info locals
__res = 4294966784
(gdb) frame 1
#1 0x00004ae9 in ?? ()
(gdb) frame 2
#2 0x420cace4 in write () from /lib/i686/libc.so.6
(gdb) frame 3
#3 0x08066403 in comm_write_try (fd=1096779496, data=0x0) at comm.cc:660
660 retval = FD_WRITE_METHOD(fd, Fc->write.buf +
Fc->write.curofs, Fc->write.size - Fc->write.curofs);
Current language: auto; currently c++
(gdb) frame 4
#4 0x08069892 in comm_select (msec=10) at comm_poll.cc:471
471 hdl(fd, F->write_data);
(gdb) frame 5
#5 0x0808a211 in main (argc=2, argv=0x141) at main.cc:724
724 switch (comm_select(loop_delay)) {
(gdb) frame 6
#6 0x42015a54 in __libc_start_main () from /lib/i686/libc.so.6
(gdb)

I have a core file from this one (ran cmd: gcore while under
gdb). Valgrind reports 5 times this one was hit.

7. I have gotten this a few times upon sending a TERM signal to
squid. I haven't seen this one before...this seems to be
reproduceable(ish) on shutdown as squid sits for possibly about 30s before
this error comes up.

2002/11/09 20:18:09| FD 15 Closing SNMP socket
2002/11/09 20:18:09| assertion failed: comm.cc:1342: "fdc_table[fd].active
== 1"
2002/11/09 20:18:09| Closing unlinkd pipe on FD 10
2002/11/09 20:18:09| aioSync: flushing pending I/O operations
2002/11/09 20:18:09| aioSync: done
2002/11/09 20:18:09| aioSync: flushing pending I/O operations
2002/11/09 20:18:09| aioSync: done
2002/11/09 20:18:09| storeDirWriteCleanLogs: Starting...
2002/11/09 20:18:09| 65536 entries written so far.
2002/11/09 20:18:09| Finished. Wrote 127241 entries.
2002/11/09 20:18:09| Took 0.3 seconds (412190.0 entries/sec).
2002/11/09 20:18:09| aioSync: flushing pending I/O operations
2002/11/09 20:18:09| aioSync: done
2002/11/09 20:18:09| aioSync: flushing pending I/O operations
2002/11/09 20:18:09| aioSync: done
2002/11/09 20:18:09| aioSync: flushing pending I/O operations
2002/11/09 20:18:09| aioSync: done
2002/11/09 20:18:09| aioSync: flushing pending I/O operations
2002/11/09 20:18:09| aioSync: done
2002/11/09 20:18:09| assertion failed: disk.cc:92: "F->flags.open"
2002/11/09 20:18:09| assertion failed: comm_poll.cc:134: "F->flags.open"
2002/11/09 20:18:09| assertion failed: comm_poll.cc:134: "F->flags.open"

Program exited normally.
(gdb) bt
No stack.

---
Hope this is handy.  If anyone can suggest better ways to test or more 
appropriate options to gdb or valgrind then I'd be interested to know
Reuben
-------------------------------------------------------------
Reuben Farrelly          West Ryde, NSW 2114,       Australia 
Received on Sat Nov 09 2002 - 04:08:41 MST

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