[Varnish] #1397: Assert error in vbf_stp_condfetch(), cache/cache_fetch.c line 635: Condition(obj->len == al) not true.

[Varnish]

#1397: Assert error in vbf_stp_condfetch(), cache/cache_fetch.c line 635:
Condition(obj->len == al) not true.
--------------------+----------------------
 Reporter:  scoof   |       Owner:
     Type:  defect  |      Status:  new
 Priority:  normal  |   Milestone:
Component:  build   |     Version:  unknown
 Severity:  normal  |  Resolution:
 Keywords:          |
--------------------+----------------------

Comment (by scoof):

 I was able to reproduce on my laptop. 100M malloc, 1s TTL, 1d grace on all
 objects.

 I then fetch a 10M object, and then fill the cache with 20k objects until
 <10MB are left. I make sure that nuke_limit is sufficiently high, and
 fetch the 10M object again. This triggers this assert.

 syncvsl varnishlog, running 3d50d453ad6cd2b9d4da72d970b3051862757123

 {{{
 *   << Request  >> 68562
 -   Begin          req 68561
 -   ReqMethod      GET
 -   ReqURL         /10MB
 -   ReqProtocol    HTTP/1.1
 -   ReqHeader      User-Agent: curl/7.30.0
 -   ReqHeader      Host: localhost
 -   ReqHeader      Accept: */*
 -   ReqStart       127.0.0.1 58823
 -   VCL_call       RECV
 -   VCL_return     hash
 -   VCL_call       HASH
 -   VCL_return     lookup
 -   Hit            2147483651
 -   VCL_call       HIT
 -   VCL_return     deliver
 -   Link           bereq 68563
 -   VCL_call       DELIVER
 -   VCL_return     deliver
 -   Debug          "RES_MODE 2%00"
 -   RespProtocol   HTTP/1.1
 -   RespStatus     200
 -   RespResponse   OK
 -   RespHeader     Server: Apache/2.4.6 (Debian)
 -   RespHeader     Last-Modified: Mon, 24 Oct 2011 13:29:00 GMT
 -   RespHeader     ETag: "989680-4b00b67d84216"
 -   RespHeader     Date: Mon, 06 Jan 2014 19:32:32 GMT
 -   RespHeader     Content-Length: 10000000
 -   RespHeader     Connection: keep-alive
 -   RespHeader     Accept-Ranges: bytes
 -   Debug          "XXX REF 3%00"
 -   Length         0
 -   ReqEnd         1389036752.007915258 1389036752.005141497 -0.002975702
 0.000201941 -0.002975702
 -   End

 *   << Session  >> 68561
 -   Begin          sess
 -   SessOpen       127.0.0.1 58823 :80 127.0.0.1 80 1389036752.005141 17
 -   Link           req 68562
 -   SessClose      REM_CLOSE 0.009 1 0 0 0 1 1
 -   End

 *   << BeReq    >> 68563
 -   Begin          bereq 68562
 -   Debug          "MKBEREQ -> STARTFETCH%00"
 -   VCL_call       BACKEND_FETCH
 -   VCL_return     fetch
 -   Debug          "STARTFETCH -> FETCHHDR%00"
 -   BereqMethod    GET
 -   BereqURL       /10MB
 -   BereqProtocol  HTTP/1.1
 -   BereqHeader    User-Agent: curl/7.30.0
 -   BereqHeader    Host: localhost
 -   BereqHeader    Accept: */*
 -   BereqHeader    X-Forwarded-For: 127.0.0.1
 -   BereqHeader    Accept-Encoding: gzip
 -   BereqHeader    If-Modified-Since: Mon, 24 Oct 2011 13:29:00 GMT
 -   BereqHeader    X-Varnish: 68563
 -   Debug          "XXX BOS: 0 -> 1%00"
 -   BackendClose   21 default(127.0.0.1,,8081) toolate
 -   BackendOpen    21 default(127.0.0.1,,8081) 127.0.0.1 44593
 -   Backend        21 default default(127.0.0.1,,8081)
 -   BereqMethod    GET
 -   BereqURL       /10MB
 -   BereqProtocol  HTTP/1.1
 -   BereqHeader    User-Agent: curl/7.30.0
 -   BereqHeader    Host: localhost
 -   BereqHeader    Accept: */*
 -   BereqHeader    X-Forwarded-For: 127.0.0.1
 -   BereqHeader    Accept-Encoding: gzip
 -   BereqHeader    If-Modified-Since: Mon, 24 Oct 2011 13:29:00 GMT
 -   BereqHeader    X-Varnish: 68563
 -   BerespProtocol HTTP/1.1
 -   BerespStatus   304
 -   BerespResponse Not Modified
 -   BerespHeader   Date: Mon, 06 Jan 2014 19:32:32 GMT
 -   BerespHeader   Server: Apache/2.4.6 (Debian)
 -   BerespHeader   ETag: "989680-4b00b67d84216"
 -   TTL            RFC -1 -1 -1 1389036752 1389036752 1389036752 0 0
 -   VCL_call       BACKEND_RESPONSE
 -   TTL            VCL 1 10 0 1389036752 0
 -   TTL            VCL 1 86400 0 1389036752 0
 -   VCL_return     deliver
 -   Debug          "FETCHHDR -> CONDFETCH%00"
 -   Storage        malloc s0
 -   ObjProtocol    HTTP/1.1
 -   ObjStatus      200
 -   ObjResponse    OK
 -   ObjHeader      Date: Mon, 06 Jan 2014 19:31:52 GMT
 -   ObjHeader      Server: Apache/2.4.6 (Debian)
 -   ObjHeader      Last-Modified: Mon, 24 Oct 2011 13:29:00 GMT
 -   ObjHeader      ETag: "989680-4b00b67d84216"
 -   Debug          "XXX BOS: 1 -> 2%00"
 -   VSL            flush
 -   End            synth
 }}}

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