[Varnish] #1335: Assert error in cnt_miss(), cache/cache_req_fsm.c (fryer)

[Varnish]

#1335: Assert error in cnt_miss(), cache/cache_req_fsm.c (fryer)
----------------------+--------------------
 Reporter:  lkarsten  |       Owner:
     Type:  defect    |      Status:  new
 Priority:  normal    |   Milestone:
Component:  varnishd  |     Version:  trunk
 Severity:  normal    |  Resolution:
 Keywords:            |
----------------------+--------------------
Description changed by lkarsten:

Old description:

> Found a Varnishd child panic on master (209f797) with fryer.
>
> Should be pretty simple to reproduce. A single siege process, 15
> concurrent connections with keepalive. 1 single 1K object hit repeatedly.
>
> Child crashes in vcl_miss after 120 seconds.
>
> startargs:
> 2013-09-04 11:06:54,021 - fry - INFO - run[fryer1]:
> /opt/varnish/sbin/varnishd -T localhost:6082 -a :6081 -f
> /opt/varnish/etc/testsuite.vcl -smalloc,20M -p thread_pool_max=3000 -p
> thread_pool_min=1000 -P /opt/varnish/var/varnishd.pid
>

> {{{
> Last panic at: Wed, 04 Sep 2013 09:14:48 GMT
> Assert error in cnt_miss(), cache/cache_req_fsm.c line 561:
>   Condition((req->objcore) != NULL) not true.
> thread = (cache-worker)
> ident = Linux,3.2.0-51-generic,x86_64,-smalloc,-smalloc,-hcritbit,epoll
> Backtrace:
>   0x42e6b7: ObjIterEnd+5d7
>   0x433a02: CNT_Request+21a2
>   0x429ca8: HTTP1_Session+4b8
>   0x4352b8: RFC2616_Do_Cond+148
>   0x4364e5: SES_pool_accept_task+1f5
>   0x430af3: Pool_Work_Thread+c3
>   0x443a38: WRK_SumStat+108
>   0x7f0e0bb7be9a: _end+7f0e0b4f8702
>   0x7f0e0b8a8ccd: _end+7f0e0b225535
> req = 0x7f0dc4060a00 {
>   sp = 0x7f0dc80008e0, vxid = 1079740951,  step = R_STP_MISS,
>   req_body = R_BODY_NONE,
>   restarts = 0, esi_level = 0
>   sp = 0x7f0dc80008e0 {
>     fd = 24, vxid = 262145,
>     client = 194.31.39.161 57623,
>     step = S_STP_WORKING,
>   },
>   worker = 0x7f0df3e12c80 {
>     ws = 0x7f0df3e12e78 {
>       id = "wrk",
>       {s,f,r,e} = {0x7f0df3e12470,0x7f0df3e12470,(nil),+2048},
>     },
>   VCL::method = 0x0,
>   VCL::return = fetch,
>   },
>   ws = 0x7f0dc4060ba8 {
>     id = "req",
>     {s,f,r,e} = {0x7f0dc40621b0,+256,(nil),+59472},
>   },
>   http[req] = {
>     ws = 0x7f0dc4060ba8[req]
>       "GET",
>       "/cacheabledata/set_hot1/index.html",
>       "HTTP/1.1",
>       "Host: fryer1.varnish-software.com:6081",
>       "Accept: */*",
>       "User-Agent: JoeDog/1.00 [en] (X11; I; Siege 2.70)",
>       "Connection: keep-alive",
>       "X-Forwarded-For: 194.31.39.161",
>       "Accept-Encoding: gzip",
>   },
>   vcl = {
>     srcname = {
>       "input",
>       "Default",
>     },
>   },
> },
> }}}
>
> testsuite.vcl:
> {{{
> backend default {
>         .host = "localhost";
>         .port = "80";
> }
> }}}

New description:

 Found a Varnishd child panic on master (209f797) with fryer.

 Should be pretty simple to reproduce. A single siege process, 15
 concurrent connections with keepalive. 1 single 1K object hit repeatedly.

 Child crashes after 120 seconds.

 startargs:
 2013-09-04 11:06:54,021 - fry - INFO - run[fryer1]:
 /opt/varnish/sbin/varnishd -T localhost:6082 -a :6081 -f
 /opt/varnish/etc/testsuite.vcl -smalloc,20M -p thread_pool_max=3000 -p
 thread_pool_min=1000 -P /opt/varnish/var/varnishd.pid


 {{{
 Last panic at: Wed, 04 Sep 2013 09:14:48 GMT
 Assert error in cnt_miss(), cache/cache_req_fsm.c line 561:
   Condition((req->objcore) != NULL) not true.
 thread = (cache-worker)
 ident = Linux,3.2.0-51-generic,x86_64,-smalloc,-smalloc,-hcritbit,epoll
 Backtrace:
   0x42e6b7: ObjIterEnd+5d7
   0x433a02: CNT_Request+21a2
   0x429ca8: HTTP1_Session+4b8
   0x4352b8: RFC2616_Do_Cond+148
   0x4364e5: SES_pool_accept_task+1f5
   0x430af3: Pool_Work_Thread+c3
   0x443a38: WRK_SumStat+108
   0x7f0e0bb7be9a: _end+7f0e0b4f8702
   0x7f0e0b8a8ccd: _end+7f0e0b225535
 req = 0x7f0dc4060a00 {
   sp = 0x7f0dc80008e0, vxid = 1079740951,  step = R_STP_MISS,
   req_body = R_BODY_NONE,
   restarts = 0, esi_level = 0
   sp = 0x7f0dc80008e0 {
     fd = 24, vxid = 262145,
     client = 194.31.39.161 57623,
     step = S_STP_WORKING,
   },
   worker = 0x7f0df3e12c80 {
     ws = 0x7f0df3e12e78 {
       id = "wrk",
       {s,f,r,e} = {0x7f0df3e12470,0x7f0df3e12470,(nil),+2048},
     },
   VCL::method = 0x0,
   VCL::return = fetch,
   },
   ws = 0x7f0dc4060ba8 {
     id = "req",
     {s,f,r,e} = {0x7f0dc40621b0,+256,(nil),+59472},
   },
   http[req] = {
     ws = 0x7f0dc4060ba8[req]
       "GET",
       "/cacheabledata/set_hot1/index.html",
       "HTTP/1.1",
       "Host: fryer1.varnish-software.com:6081",
       "Accept: */*",
       "User-Agent: JoeDog/1.00 [en] (X11; I; Siege 2.70)",
       "Connection: keep-alive",
       "X-Forwarded-For: 194.31.39.161",
       "Accept-Encoding: gzip",
   },
   vcl = {
     srcname = {
       "input",
       "Default",
     },
   },
 },
 }}}

 testsuite.vcl:
 {{{
 backend default {
         .host = "localhost";
         .port = "80";
 }
 }}}

--

-- 
Ticket URL: <https://www.varnish-cache.org/trac/ticket/1335#comment:2>
Varnish <https://varnish-cache.org/>
The Varnish HTTP Accelerator