[Varnish] #924: Missing errorhandling code in cnt_error(), cache_center.c line 418:

Varnish varnish-bugs at varnish-cache.org
Thu May 26 10:31:51 CEST 2011


#924: Missing errorhandling code in cnt_error(), cache_center.c line 418:
--------------------+-------------------------------------------------------
 Reporter:  kdajka  |        Type:  defect  
   Status:  new     |    Priority:  normal  
Milestone:          |   Component:  varnishd
  Version:  trunk   |    Severity:  major   
 Keywords:          |  
--------------------+-------------------------------------------------------
 Hi, I'm seeing child restarts in newest trunk
 bbc2f9194c45c94b4c7348a3fd3b4f1bc9574398. I have 3 backtraces all were
 triggered
 by PURGE (the squid way), after few hours after start. This varnish
 instance is getting about 10 PURGE requests and ~2 bans per hour. Crashes
 happend after malloc fulled up.

 My system: Linux varnishic06 2.6.26-2-amd64 #1 SMP Thu Nov 25 04:30:55 UTC
 2010
 x86_64 GNU/Linux

 {{{
 /usr/local/inp/varnish/sbin/varnishd -P /var/tmp/foo.bar.pl_varnishd.pid
 -a :8084 \
 -i foo.bar_varnishic06 -n foo.bar_varnishic06 -f
 /exp/confvarnish/foo.bar.pl/foo.bar.pl.vcl \
 -T :2084 -h classic,20011 -p thread_pools 4 -p ban_lurker_sleep 0.1 -w
 200,4000,2 \
 -t 0 -s malloc,9G
 }}}

 {{{
 panic.show
 200
 Last panic at: Wed, 25 May 2011 19:52:55 GMT
 Missing errorhandling code in cnt_error(), cache_center.c line 418:
   Condition((sp->obj) != 0) not true.thread = (cache-worker)
 ident = Linux,2.6.26-2-amd64,x86_64,-smalloc,-smalloc,-hclassic,epoll
 Backtrace:
   0x434d81: pan_backtrace+16
   0x434fea: pan_ic+164
   0x41864a: cnt_error+12d
   0x41c36a: CNT_Session+67a
   0x436c0d: wrk_do_cnt_sess+12a
   0x436478: wrk_thread_real+851
   0x436879: wrk_thread+e5
   0x7fd9a2252fc7: _end+7fd9a1bc398f
   0x7fd9a1fc864d: _end+7fd9a1939015
 sp = 0x7fd8414de008 {
   fd = 654, id = 654, xid = 909745151,
   client = 172.20.26.107 43629,
   step = STP_ERROR,
   handling = error,
   err_code = 404, err_reason = Not in cache.,
   restarts = 0, esi_level = 0
   ws = 0x7fd8414de080 {
     id = "sess",
     {s,f,r,e} = {0x7fd8414decf0,+144,(nil),+65536},
   },
   http[req] = {
     ws = 0x7fd8414de080[sess]
       "PURGE",
       "/resource/IMG_0127.jpg",
       "HTTP/1.1",
       "Host: foo.bar.pl",
       "x-real-forwarded-for: 172.20.26.107",
   },
   worker = 0x7fd84ab51e10 {
     ws = 0x7fd84ab51fb0 {
       id = "wrk",
       {s,f,r,e} = {0x7fd84ab3fd20,+48,(nil),+65536},
     },
     http[bereq] = {
       ws = 0x7fd84ab51fb0[wrk]
         "GET",
         "/resource/IMG_0127.jpg",
         "HTTP/1.1",
         "Host: foo.bar.pl",
         "x-real-forwarded-for: 172.20.26.107",
         "X-Varnish: 909745151",
         "Accept-Encoding: gzip",
     },
     },
     vcl = {
       srcname = {
         "input",
         "Default",
         "/exp/confvarnish/foo.bar.pl/backends_foo.bar.pl.vcl",
         "/exp/confvarnish/global/500.vcl",
       },
     },
 },
 }}}

 {{{
 $ gdb -c
 varnish_bbc2f9194c45c94b4c7348a3fd3b4f1bc9574398/var/varnish/foo.bar_varnishic06/
 core.3297 varnish_bbc2f9194c45c94b4c7348a3fd3b4f1bc9574398/sbin/varnishd
 [...]
 Core was generated by `/usr/local/inp/varnish/sbin/varnishd -P
 /var/tmp/foo.bar.pl_varnishd.pid -a 19'.
 Program terminated with signal 6, Aborted.
 [...]
 (gdb) bt
 #0  0x00007fd9a1f2aed5 in raise () from /lib/libc.so.6
 #1  0x00007fd9a1f2c3f3 in abort () from /lib/libc.so.6
 #2  0x0000000000435097 in pan_ic (func=0x46d3ef "cnt_error", file=0x46d226
 "cache_center.c", line=418, cond=0x46d3f9 "(sp->obj) != 0", err=0, xxx=1)
     at cache_panic.c:358
 #3  0x000000000041864a in cnt_error (sp=0x7fd8414de008) at
 cache_center.c:418
 #4  0x000000000041c36a in CNT_Session (sp=0x7fd8414de008) at steps.h:46
 #5  0x0000000000436c0d in wrk_do_cnt_sess (w=0x7fd84ab51e10,
 priv=0x7fd8414de008) at cache_pool.c:300
 #6  0x0000000000436478 in wrk_thread_real (qp=0x7fd9a1b0f2e0,
 shm_workspace=8192, sess_workspace=65536, nhttp=64, http_space=1160,
 siov=128)
 at cache_pool.c:184
 #7  0x0000000000436879 in wrk_thread (priv=0x7fd9a1b0f2e0) at
 cache_pool.c:230
 #8  0x00007fd9a2252fc7 in start_thread () from /lib/libpthread.so.0
 #9  0x00007fd9a1fc864d in clone () from /lib/libc.so.6
 #10 0x0000000000000000 in ?? ()
 (gdb) frame 2
 #2  0x0000000000435097 in pan_ic (func=0x46d3ef "cnt_error", file=0x46d226
 "cache_center.c", line=418, cond=0x46d3f9 "(sp->obj) != 0", err=0, xxx=1)
     at cache_panic.c:358
 358     cache_panic.c: No such file or directory.
         in cache_panic.c
 (gdb) print *sp
 $1 = {magic = 741317722, fd = 654, id = 654, xid = 909745151, restarts =
 0,
 esi_level = 0, disable_esi = 0, hash_ignore_busy = 0 '\0',
 hash_always_miss = 0
 '\0',
   wrk = 0x7fd84ab51e10, sockaddrlen = 16, mysockaddrlen = 128, sockaddr =
 0x7fd8414de2e0, mysockaddr = 0x7fd8414de360, mylsock = 0x7fd9a1b20550,
   addr = 0x7fd8414decf0 "172.20.26.107", port = 0x7fd8414ded00 "43629",
 client_identity = 0x0, doclose = 0x0, http = 0x7fd8414de3e0, http0 =
 0x7fd8414de868, ws = {{
       magic = 905626964, id = 0x47286e "sess", s = 0x7fd8414decf0
 "172.20.26.107", f = 0x7fd8414ded80 "0100101 Firefox/4.0.1", r = 0x0, e =
 0x7fd8414eecf0 "",
       overflow = 0}}, ws_ses = 0x7fd8414ded08 "PURGE", ws_req =
 0x7fd8414ded48
 "172.20.26.107",
   digest =
 "e&\237:yB�\212;\017\216\016�j��\204��\223��\"\025��\f\227�\232�k",
 htc = {{magic = 1041886673, fd = 654, maxbytes = 32768, maxhdr = 2048,
       ws = 0x7fd8414de080, rxbuf = {b = 0x7fd8414ded08 "PURGE", e =
 0x7fd8414ded48 "172.20.26.107"}, pipeline = {b = 0x0, e = 0x0}}}, t_open =
 1306352754.8537035,
   t_req = 1306352754.8537273, t_resp = nan(0x8000000000000), t_end =
 1306352754.8537035, exp = {ttl = -1, grace = 30, keep = -1}, step =
 STP_ERROR,
 cur_method = 0,
   handling = 1, sendbody = 0 '\0', wantbody = 1 '\001', err_code = 404,
 err_reason = 0x7fd99adf70c7 <Address 0x7fd99adf70c7 out of bounds>, list =
 {vtqe_next = 0x0,
     vtqe_prev = 0x0}, director = 0x7fd9a1b0fa68, vbc = 0x0, obj = 0x0,
 objcore =
 0x0, vcl = 0x7fd9a1b26428, hash_objhead = 0x0, mem = 0x7fd8414de000,
 workreq = {
     list = {vtqe_next = 0x0, vtqe_prev = 0x0}, func = 0x436ae3
 <wrk_do_cnt_sess>, priv = 0x7fd8414de008}, acct_tmp = {first = 0, sess =
 1, req
 = 1, pipe = 0,
     pass = 0, fetch = 0, hdrbytes = 0, bodybytes = 0}, acct_req = {first =
 0,
 sess = 0, req = 0, pipe = 0, pass = 0, fetch = 0, hdrbytes = 0, bodybytes
 = 0},
   acct_ses = {first = 1306352754.8537035, sess = 0, req = 0, pipe = 0,
 pass = 0,
 fetch = 0, hdrbytes = 0, bodybytes = 0}, ev = {events = 0, data = {ptr =
 0x0, fd
 = 0,
       u32 = 0, u64 = 0}}}
 }}}

-- 
Ticket URL: <http://www.varnish-cache.org/trac/ticket/924>
Varnish <http://varnish-cache.org/>
The Varnish HTTP Accelerator




More information about the varnish-bugs mailing list