Debugging restarts/crashes?
Cloude Porteus
cloude at instructables.com
Thu May 14 18:26:27 CEST 2009
I was able to find this entry in /var/log/messages, but it's hard to tell if
it's going to be helpful or not for debugging. I can't seem to find a
daemon.log in /var/log.
May 13 13:06:48 squid03 varnishd[14993]: Child (14994) not responding to
ping, killing it.
May 13 13:06:48 squid03 varnishd[14993]: Child (14994) died signal=6
May 13 13:06:48 squid03 varnishd[14993]: Child (14994) Panic message: Assert
error in Tcheck(), cache.h line 648: Condition((t.e) != 0) not true.
thread = (cache-worker)sp = 0x2ab733984008 { fd = 19, id = 19, xid =
2173533104, client = 10.0.0.1:58322, step = STP_FETCH, handling =
fetch, ws = 0x2ab733984078 { id = "sess", {s,f,r,e} =
{0x2ab733984808,,+1162,(nil),+262144}, }, worker = 0x2ab7b4a46bd0 {
}, vcl = { srcname = { "input", "Default",
}, }, obj = 0x2aaddddaf000 { refcnt = 1, xid = 2173533104, ws
= 0x2aaddddaf028 { id = "obj", {s,f,r,e} =
{0x2aaddddaf358,,0x2aaddddaf358,(nil),+3240}, }, http = { ws =
0x2aaddddaf028 { id = "obj", {s,f,r,e} =
{0x2aaddddaf358,,0x2aaddddaf358,(nil),+3240}, }, }, len = 0,
store = { }, }, },
May 13 13:06:48 squid03 varnishd[14993]: child (32738) Started
May 13 13:06:48 squid03 varnishd[14993]: Child (32738) said Closed fds: 4 5
6 10 11 13 14
May 13 13:06:48 squid03 varnishd[14993]: Child (32738) said Child starts
May 13 13:06:48 squid03 varnishd[14993]: Child (32738) said managed to mmap
53687091200 bytes of 53687091200
May 13 13:06:48 squid03 varnishd[14993]: Child (32738) said Ready
May 13 13:06:50 squid03 varnishd[14993]: Child (32738) died signal=6
May 13 13:06:50 squid03 varnishd[14993]: Child (32738) Panic message: Assert
error in Tcheck(), cache.h line 648: Condition((t.e) != 0) not true.
thread = (cache-worker)sp = 0x2ab736402008 { fd = 267, id = 267, xid =
1961344622, client = 10.0.0.1:59424, step = STP_FETCH, handling =
fetch, ws = 0x2ab736402078 { id = "sess", {s,f,r,e} =
{0x2ab736402808,,+1162,(nil),+262144}, }, worker = 0x2ab7432ffbd0 {
}, vcl = { srcname = { "input", "Default",
}, }, obj = 0x2aaab0ce0000 { refcnt = 1, xid = 1961344622, ws
= 0x2aaab0ce0028 { id = "obj", {s,f,r,e} =
{0x2aaab0ce0358,,0x2aaab0ce0358,(nil),+3240}, }, http = { ws =
0x2aaab0ce0028 { id = "obj", {s,f,r,e} =
{0x2aaab0ce0358,,0x2aaab0ce0358,(nil),+3240}, }, }, len = 0,
store = { }, }, },
May 13 13:06:50 squid03 varnishd[14993]: child (390) Started
May 13 13:06:50 squid03 varnishd[14993]: Child (390) said Closed fds: 4 5 6
10 11 13 14
May 13 13:06:50 squid03 varnishd[14993]: Child (390) said Child starts
May 13 13:06:50 squid03 varnishd[14993]: Child (390) said managed to mmap
53687091200 bytes of 53687091200
May 13 13:06:50 squid03 varnishd[14993]: Child (390) said Ready
On Wed, May 13, 2009 at 5:57 PM, John Adams <jna at twitter.com> wrote:
> Go look in /var/log/daemon.log, and find out why the children are dying. If
> you're getting SEGVs, that's going to be listed in your syslog.
> A big reason for crashing is running out of session workspace
> (sess_workspace). Find out if that's happening, and if it is, increase it.
> (say, to 512k)
>
>
> -j
>
> On May 13, 2009, at 5:17 PM, Cloude Porteus wrote:
>
> Varnish seems to restart itself every so often, usually after a few days.
> We finally installed some SSD's, which made all the difference and our
> system load came down to the .02 - .2 range.
>
> I don't currently have any logging turned on. If I did, would it have any
> useful information for me?
>
> We typically don't have more that 700k objects cached. I also never see the
> worker threads go above 400. We are running on CentOS 5.
>
> Our config:
>
> NFILES=131072
> MEMLOCK=90000
> DAEMON_COREFILE_LIMIT="unlimited"
> VARNISH_VCL_CONF=/etc/varnish/instructables.vcl
> VARNISH_LISTEN_ADDRESS=
> VARNISH_LISTEN_PORT=80
> VARNISH_ADMIN_LISTEN_ADDRESS=127.0.0.1
> VARNISH_ADMIN_LISTEN_PORT=82
> VARNISH_MIN_THREADS=400
> VARNISH_MAX_THREADS=4000
> VARNISH_THREAD_TIMEOUT=60
> VARNISH_STORAGE_FILE=/var/lib/varnish/mmap
> VARNISH_STORAGE_SIZE=50G
> VARNISH_STORAGE="file,${VARNISH_STORAGE_FILE},${VARNISH_STORAGE_SIZE}"
> VARNISH_TTL=1800
>
> DAEMON_OPTS="-a ${VARNISH_LISTEN_ADDRESS}:${VARNISH_LISTEN_PORT} \
> -f ${VARNISH_VCL_CONF} \
> -T
> ${VARNISH_ADMIN_LISTEN_ADDRESS}:${VARNISH_ADMIN_LISTEN_PORT} \
> -t ${VARNISH_TTL} \
> -w
> ${VARNISH_MIN_THREADS},${VARNISH_MAX_THREADS},${VARNISH_THREAD_TIMEOUT} \
> -u varnish -g varnish \
> -s ${VARNISH_STORAGE} \
> -p obj_workspace=4096 \
> -p sess_workspace=262144 \
> -p lru_interval=3600 \
> -p listen_depth=8192 \
> -p log_hashstring=off \
> -p sess_timeout=10 \
> -p shm_workspace=32768 \
> -p ping_interval=1 \
> -p thread_pools=4 \
> -p thread_pool_min=100 \
> -p thread_pool_max=4000 \
> -p srcaddr_ttl=0 \
> -p esi_syntax=1 "
>
> I don't think out load is all that heavy and we have a high hitrate ratio.
> Our varnishstat output.
>
> 0+11:02:14
>
> Hitrate ratio: 10 100 133
> Hitrate avg: 0.9875 0.9833 0.9832
>
> 15370527 325.94 386.84 Client connections accepted
> 15370517 325.94 386.84 Client requests received
> 14604988 320.94 367.57 Cache hits
> 182795 4.00 4.60 Cache hits for pass
> 581426 1.00 14.63 Cache misses
> 765513 5.00 19.27 Backend connections success
> 1 0.00 0.00 Backend connections failures
> 119 . . N struct sess_mem
> 10 . . N struct sess
> 447866 . . N struct object
> 440545 . . N struct objecthead
> 913238 . . N struct smf
> 4490 . . N small free smf
> 2 . . N large free smf
> 0 . . N struct vbe_conn
> 112 . . N struct bereq
> 400 . . N worker threads
> 400 0.00 0.01 N worker threads created
> 313048 0.00 7.88 N worker threads limited
> 1 . . N backends
> 126326 . . N expired objects
> 1250255 . . N LRU moved objects
> 18 0.00 0.00 HTTP header overflows
> 13645614 292.95 343.42 Objects sent with write
> 15370518 327.94 386.84 Total Sessions
> 15370510 327.94 386.84 Total Requests
> 7 0.00 0.00 Total pipe
> 191394 5.00 4.82 Total pass
> 765481 9.00 19.27 Total fetch
> 7252376430 156332.93 182523.19 Total header bytes
> 74103505138 772233.39 1864989.81 Total body bytes
> 15370160 327.94 386.83 Session Closed
> 365 0.00 0.01 Session herd
> 758091326 15625.09 19079.16 SHM records
> 62365137 1317.75 1569.57 SHM writes
> 468 0.00 0.01 SHM flushes due to overflow
> 589 0.00 0.01 SHM MTX contention
> 307 0.00 0.01 SHM cycles through buffer
> 1573886 15.00 39.61 allocator requests
> 908746 . . outstanding allocations
> 7766196224 . . bytes allocated
> 45920894976 . . bytes free
>
>
> --
> VP of Product Development
> Instructables.com
>
> http://www.instructables.com/member/lebowski
> _______________________________________________
> varnish-dev mailing list
> varnish-dev at projects.linpro.no
> http://projects.linpro.no/mailman/listinfo/varnish-dev
>
>
> ---
> John Adams
> Twitter Operations
> jna at twitter.com
> http://twitter.com/netik
>
>
>
>
>
--
VP of Product Development
Instructables.com
http://www.instructables.com/member/lebowski
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://www.varnish-cache.org/lists/pipermail/varnish-dev/attachments/20090514/6ed28191/attachment-0001.html>
More information about the varnish-dev
mailing list