[Varnish] #986: Stream-related Assert error in AssertObjCorePassOrBusy(), cache.h line 1011:

[Varnish]

#986: Stream-related Assert error in AssertObjCorePassOrBusy(), cache.h line
1011:
----------------------+-----------------------------------------------------
 Reporter:  kristian  |       Owner:       
     Type:  defect    |      Status:  new  
 Priority:  normal    |   Milestone:       
Component:  varnishd  |     Version:  trunk
 Severity:  normal    |    Keywords:       
----------------------+-----------------------------------------------------
 Discovered during testing of the streaming code.

 {{{

 debug: 2 (6s) Executing tests
 log: 1 (25s) Server tristran checked out varnish-3.0.0-beta2-155-g555735f
 warning: 0 (233s) httperf TEST (streaming): Panic detected. I think!
 warning: 0 (0s) httperf TEST (streaming):
 Last panic at: Wed, 24 Aug 2011 11:30:16 GMT
 Assert error in AssertObjCorePassOrBusy(), cache.h line 1011:
   Condition((oc->flags & (1<<1)) != 0) not true.
 thread = (cache-worker)
 ident = Linux,2.6.32-33-server,x86_64,-smalloc,-smalloc,-hcritbit,epoll
 Backtrace:
   0x42e368: pan_ic+d8
   0x41872b: cnt_prepresp+3bb
   0x418cbd: CNT_Session+3cd
   0x42fb58: wrk_do_cnt_sess+b8
   0x42ffe1: wrk_thread_real+411
   0x7f44249779ca: _end+7f44242fe712
   0x7f44246d470d: _end+7f442405b455
 sp = 0x7f43dfd13008 {
   fd = 157, id = 157, xid = 1969712598,
   client = 10.20.100.9 6936,
   step = STP_PREPRESP,
   handling = deliver,
   restarts = 0, esi_level = 0
   ws = 0x7f43dfd13080 {
     id = "sess",
     {s,f,r,e} = {0x7f43dfd13cc8,+152,(nil),+65536},
   },
   http[req] = {
     ws = 0x7f43dfd13080[sess]
       "GET",
       "/9/1/3.html",
       "HTTP/1.1",
       "User-Agent: httperf/0.9.0",
       "Host: 10.20.100.4",
       "X-Forwarded-For: 10.20.100.9",
   },
   worker = 0x7f4400af9b60 {
     ws = 0x7f4400af9d08 {
       id = "wrk",
       {s,f,r,e} = {0x7f4400ae7af0,0x7f4400ae7af0,(nil),+65536},
     },
     },
     vcl = {
       srcname = {
         "input",
         "Default",
       },
     },
   obj = 0x7f4418f4c300 {
     xid = 1969712501,
     ws = 0x7f4418f4c318 {
       id = "obj",
       {s,f,r,e} = {0x7f4418f4c4d0,+192,(nil),+224},
     },
     http[obj] = {
       ws = 0x7f4418f4c318[obj]
         "HTTP/1.1",
         "OK",
         "Server: nginx/0.7.65",
         "Date: Wed, 24 Aug 2011 11:30:01 GMT",
         "Content-Type: text/plain",
         "Last-Modified: Wed, 24 Aug 2011 11:27:50 GMT",
         "Content-Length: 1048576",
     },
     len = 1048576,
     store = {
       1048576 {
         00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 |................|
         00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 |................|
         00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 |................|
         00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 |................|
         [1048512 more]
       },
     },
   },
 },




 log: 1 (0s) httperf TEST (streaming): Varnishstat uptime and measured run-
 time is too large (measured: 145 stat: 0 diff: 145). Did we crash?
 warning: 0 (0s) httperf TEST (streaming): Out of bounds: client_conn(0)
 less than lower boundary 9900
 warning: 0 (0s) httperf TEST (streaming): Out of bounds: client_req(0)
 less than lower boundary 9800
 log: 1 (0s) httperf TEST (streaming): Test name: streaming
 log: 1 (0s) httperf TEST (streaming): Varnish options:
 log: 1 (0s) httperf TEST (streaming): -t=1
 log: 1 (0s) httperf TEST (streaming): Varnish parameters:
 log: 1 (0s) httperf TEST (streaming): thread_pool_add_delay=1
 log: 1 (0s) httperf TEST (streaming): http_gzip_support=off
 log: 1 (0s) httperf TEST (streaming): default_grace=0
 log: 1 (0s) httperf TEST (streaming): Payload size (excludes headers): 1M
 log: 1 (0s) httperf TEST (streaming): Branch: master
 log: 1 (0s) httperf TEST (streaming): Number of clients involved: 24
 log: 1 (0s) httperf TEST (streaming): Type of test: httperf
 log: 1 (0s) httperf TEST (streaming): Test iterations: 1
 log: 1 (0s) httperf TEST (streaming): Runtime: 145 seconds
 log: 1 (0s) httperf TEST (streaming): VCL:
 backend foo {
         .host = "localhost";
         .port = "80";
         .connect_timeout = 10s;
 }

 sub vcl_fetch {
         set beresp.do_stream = true;
         set beresp.grace = 0s;
         set beresp.ttl = 15s;
 }

 sub vcl_deliver {
         set resp.http.x-fryer = "some test";
 }

 log: 1 (0s) httperf TEST (streaming): Number of total connections: 10000
 log: 1 (0s) httperf TEST (streaming): Note: connections are subject to
 rounding when divided among clients. Expect slight deviations.
 log: 1 (0s) httperf TEST (streaming): Requests per connection: 1
 log: 1 (0s) httperf TEST (streaming): Extra options to httperf:
 --wset=1000,0.1 --rate 3
 log: 1 (0s) httperf TEST (streaming): Httperf command (last client):
 httperf --hog --timeout 60 --num-calls 1 --num-conns 416 --port 8080
 --burst-length 1 --client 23/24 --server 10.20.100.4 --wset=1000,0.1
 --rate 3
 warning: 0 (0s) Tests finished with problems detected. Failed
 expectations: 4 Total run time: 265 seconds
 debug: 2 (0s) Sending mail
 }}}

 As discussed on IRC already.

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