[Varnish] #1602: Assert error in ESI_DeliverChild(), cache/cache_esi_deliver.c line 530

[Varnish]

#1602: Assert error in ESI_DeliverChild(), cache/cache_esi_deliver.c line 530
-------------------------+--------------------
 Reporter:  cache_layer  |       Owner:
     Type:  defect       |      Status:  new
 Priority:  normal       |   Milestone:
Component:  build        |     Version:  trunk
 Severity:  normal       |  Resolution:
 Keywords:               |
-------------------------+--------------------
Description changed by fgsch:

Old description:

> Hi,
>
> I observed several times at irregular intervals that varnish panics with
> the following error:
>

> {{{
> Last panic at: Tue, 23 Sep 2014 08:05:49 GMT
> Assert error in vbf_fetch_thread(), cache/cache_fetch.c line 838:
>   Condition(uu == bo->fetch_obj->len) not true.
> thread = (cache-worker)
> ident = Linux,3.2.0-55-generic,x86_64,-smalloc,-smalloc,-hcritbit,epoll
> Backtrace:
>   0x432de5: pan_ic+0xc5
>   0x420ee4: vbf_fetch_thread+0x18d4
>   0x435cf0: Pool_Work_Thread+0x370
>   0x448808: wrk_thread_real+0xc8
>   0x7f57bcfcce9a: /lib/x86_64-linux-gnu/libpthread.so.0(+0x7e9a)
> [0x7f57bcfcce9a]
>   0x7f57bccfa31d: /lib/x86_64-linux-gnu/libc.so.6(clone+0x6d)
> [0x7f57bccfa31d]
>   busyobj = 0x7f5758d95e50 {
>     ws = 0x7f5758d95f10 {
>       id = "bo",
>       {s,f,r,e} = {0x7f5758d97e30,+15344,(nil),+57376},
>     },
>   refcnt = 1
>   retries = 0
>   failed = 0
>   state = 3
>     is_do_esi
>     is_uncacheable
>     is_is_gzip
>     is_should_close
>     bodystatus = 4 (eof),
>     },
>     ws = 0x7f5758d96098 {
>       id = "obj",
>       {s,f,r,e} = {0x7f54b84ba678,+920,(nil),+920},
>     },
>   objcore (FETCH) = 0x7f55f8505660 {
>     refcnt = 2
>     flags = 0x4
>     objhead = 0x7f55f86a3450
>   }
>   obj (FETCH) = 0x7f54b84ba450 {
>     vxid = 2186935878,
>     http[obj] = {
>       ws = 0x7f5758d96098[obj]
>         "HTTP/1.0",
>         "200",
>         "OK",
>         "Date: Tue, 23 Sep 2014 08:05:47 GMT",
>         "Vary: Accept-Encoding",
>         "Content-Encoding: gzip",
>         "Content-Type: text/html; charset=UTF-8",
>     },
>     len = 21523,
>     store = {
>     },
>   },
> }
> }}}
>
> Best regards

New description:

 Hi,

 I observed several times at irregular intervals that varnish panics with
 the following error:

 {{{
 Last panic at: Thu, 02 Oct 2014 18:14:24 GMT
 Assert error in ESI_DeliverChild(), cache/cache_esi_deliver.c line 530:
   Condition(start > 0 && start < obj->len * 8) not true.
 thread = (cache-worker)
 ident = Linux,3.2.0-55-generic,x86_64,-smalloc,-smalloc,-hcritbit,epoll
 Backtrace:
   0x432de5: pan_ic+0xc5
   0x419de3: ESI_DeliverChild+0x4a3
   0x43a005: V1D_Deliver+0x245
   0x436e64: CNT_Request+0x394
   0x419386: ESI_Deliver+0x806
   0x43a2e8: V1D_Deliver+0x528
   0x436e64: CNT_Request+0x394
   0x42ce6b: HTTP1_Session+0x3eb
   0x43b418: ses_req_pool_task+0x68
   0x43c3e9: SES_pool_accept_task+0x2a9
 req = 0x3cad750 {
   sp = 0x7f4085c21bd0, vxid = 1579135918,  step = R_STP_DELIVER,
   req_body = R_BODY_NONE,
   err_code = 200, err_reason = (null),
   restarts = 0, esi_level = 1
   sp = 0x7f4085c21bd0 {
     fd = 341, vxid = 505394083,
     client = 10.214.6.19 57913,
     step = S_STP_WORKING,
   },
   worker = 0x7f43dc025c60 {
     ws = 0x7f43dc025e78 {
       id = "wrk",
       {s,f,r,e} = {0x7f43dc025450,+88,+2048,+2048},
     },
   VCL::method = 0x0,
   VCL::return = deliver,
   },
   ws = 0x3cad8e8 {
     id = "req",
     {s,f,r,e} = {0x3caf740,+128,(nil),+57360},
   },
   http[req] = {
     ws = 0x44eea98[req]
       "GET",
       "/esi/sample",
       "HTTP/1.1",
       "Host: domain.com",
       "Accept:
 text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8",
       "Connection: keep-alive",
       "Cookie: cokie",
       "User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_9_5)
 AppleWebKit/600.1.17 (KHTML, like Gecko) Version/7.1 Safari/537.85.10",
       "Accept-Language: nl-nl",
       "Referer: http://domain.com/",
       "X-UA-Device: pc",
       "Accept-Encoding: gzip",
       "grace: none",
       "Surrogate-Capability: abc=ESI/1.0",
       "X-Port: 80",
   },
   http[resp] = {
     ws = 0x3cad8e8[req]
       "HTTP/1.1",
       "200",
       "OK",
       "Cache-Control: max-age=60,public",
       "X-Content-Type-Options: nosniff",
       "Content-Type: text/html;charset=UTF-8",
       "Content-Language: nl-NL",
       "Date: Thu, 02 Oct 2014 18:14:20 GMT",
       "X-Backend: backend",
       "Content-Encoding: gzip",
       "Age: 0",
       "X-Hit: HIT 0",
       "X-Origin: varnish",
       "grace: none",
       "Transfer-Encoding: chunked",
       "Connection: keep-alive",
   },
   vcl = {
     srcname = {
       "input",
       "Builtin",
       "devicedetect.vcl",
     },
   },
   obj (REQ) = 0x7f41d4d9b150 {
     vxid = 2652877743,
     http[obj] = {
       ws = 0x7f42a1224698[obj]
         "HTTP/1.1",
         "200",
         "OK",
         "Cache-Control: max-age=60,public",
         "X-Content-Type-Options: nosniff",
         "Content-Type: text/html;charset=UTF-8",
         "Content-Language: nl-NL",
         "Date: Thu, 02 Oct 2014 18:14:20 GMT",
         "X-Backend: backend",
         "Content-Encoding: gzip",
     },
     len = 10,
     store = {
       10 {
         1f 8b 08 00 00 00 00 00 00 03                   |..........|
       },
     },
   },
 },
 }}}

 Best regards

--

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