[Fryer] master FAIL. 10 of 25 tests succeeded.
fryer at oneiros.varnish-software.com
fryer at oneiros.varnish-software.com
Fri Jun 8 00:14:43 CEST 2012
Tests Failed: httperf-lru-nostream-gzip httperf-lru-nostream-gzip-deflateoff httperf-lru-default httperf-lru-stream-default httperf-hot httperf-lru-nostream-nogzip cold-gzip httperf-lru-stream-gzip httperf-lru-stream-nogzip cold-nogzip siege-test httperf-lru-nostream-default httperf-rapid-expire cold-default purge-fail
Tests OK: streaming memleak 4gpluss-stream 4gpluss basic-fryer 4gpluss-nostream lru-random streaming-grace 4gpluss-nogzip streaming-gzip
2012-06-07 19:32:15 [1,14]: Server pantoum checked out varnish-3.0.0-beta2-1014-ge75cd2e of branch master
2012-06-07 19:32:39 [2,23]: httperf-lru-nostream-gzip(httperf): Starting test
2012-06-07 19:36:08 WARNING [0,208]: httperf-lru-nostream-gzip(httperf): Panic detected. I think!
2012-06-07 19:36:08 WARNING [0, 0]: httperf-lru-nostream-gzip(httperf):
Last panic at: Thu, 07 Jun 2012 19:34:37 GMT
Assert error in cnt_first(), cache/cache_center.c line 943:
Condition(req->sp == sp) not true.
thread = (cache-worker)
ident = Linux,2.6.32-38-generic,x86_64,-smalloc,-smalloc,-hcritbit,epoll
Backtrace:
0x431d88: pan_ic+d8
0x41b021: CNT_Session+781
0x43670d: ses_pool_task+fd
0x433592: Pool_Work_Thread+112
0x441128: wrk_thread_real+c8
0x7fe1d58419ca: _end+7fe1d51bd202
0x7fe1d559ecdd: _end+7fe1d4f1a515
sp = 0x7fe1cbe15e20 {
fd = 24, id = 24, xid = 0,
client = ,
step = STP_FIRST,
handling = deliver,
restarts = 0, esi_level = 0
ws = 0x7fe1c68af158 {
id = "req",
{s,f,r,e} = {0x7fe1c68b0730,0x7fe1c68b0730,(nil),+59632},
},
http[req] = {
ws = (nil)[]
},
worker = 0x7fe1c5e1ac60 {
ws = 0x7fe1c5e1ae20 {
id = "wrk",
{s,f,r,e} = {0x7fe1c5e1a450,0x7fe1c5e1a450,(nil),+2048},
},
},
},
2012-06-07 19:36:08 WARNING [0, 0]: httperf-lru-nostream-gzip(httperf): Varnishstat uptime and measured run-time is too large (measured: 205 stat: 90 diff: 115). Did we crash?
2012-06-07 19:36:08 WARNING [0, 0]: httperf-lru-nostream-gzip(httperf): Out of bounds: n_lru_nuked(0) less than lower boundary 80000
2012-06-07 19:36:08 WARNING [0, 0]: httperf-lru-nostream-gzip(httperf): Out of bounds: client_req(137813) less than lower boundary 1989920
2012-06-07 19:36:08 [1, 0]: httperf-lru-nostream-gzip(httperf): Load: 21:36:08 up 7 days, 7:59, 3 users, load average: 1.23, 1.73, 0.78
2012-06-07 19:36:08 [1, 0]: httperf-lru-nostream-gzip(httperf): Test name: httperf-lru-nostream-gzip
2012-06-07 19:36:08 [1, 0]: httperf-lru-nostream-gzip(httperf): Varnish options:
2012-06-07 19:36:08 [1, 0]: httperf-lru-nostream-gzip(httperf): -t=3600
2012-06-07 19:36:08 [1, 0]: httperf-lru-nostream-gzip(httperf): -s=malloc,30M
2012-06-07 19:36:08 [1, 0]: httperf-lru-nostream-gzip(httperf): Varnish parameters:
2012-06-07 19:36:08 [1, 0]: httperf-lru-nostream-gzip(httperf): thread_stats_rate=1
2012-06-07 19:36:08 [1, 0]: httperf-lru-nostream-gzip(httperf): thread_pool_max=5000
2012-06-07 19:36:08 [1, 0]: httperf-lru-nostream-gzip(httperf): nuke_limit=250
2012-06-07 19:36:08 [1, 0]: httperf-lru-nostream-gzip(httperf): http_gzip_support=on
2012-06-07 19:36:08 [1, 0]: httperf-lru-nostream-gzip(httperf): thread_pool_min=200
2012-06-07 19:36:08 [1, 0]: httperf-lru-nostream-gzip(httperf): Payload size (excludes headers): 10K
2012-06-07 19:36:08 [1, 0]: httperf-lru-nostream-gzip(httperf): Branch: master
2012-06-07 19:36:08 [1, 0]: httperf-lru-nostream-gzip(httperf): Number of clients involved: 24
2012-06-07 19:36:08 [1, 0]: httperf-lru-nostream-gzip(httperf): Type of test: httperf
2012-06-07 19:36:08 [1, 0]: httperf-lru-nostream-gzip(httperf): Test iterations: 1
2012-06-07 19:36:08 [1, 0]: httperf-lru-nostream-gzip(httperf): Runtime: 205 seconds
2012-06-07 19:36:08 [1, 0]: httperf-lru-nostream-gzip(httperf): VCL:
backend foo {
.host = "localhost";
.port = "80";
}
sub vcl_fetch {
set beresp.do_stream = false;
}
2012-06-07 19:36:08 [1, 0]: httperf-lru-nostream-gzip(httperf): Number of total connections: 200000
2012-06-07 19:36:08 [1, 0]: httperf-lru-nostream-gzip(httperf): Note: connections are subject to rounding when divided among clients. Expect slight deviations.
2012-06-07 19:36:08 [1, 0]: httperf-lru-nostream-gzip(httperf): Requests per connection: 10
2012-06-07 19:36:08 [1, 0]: httperf-lru-nostream-gzip(httperf): Extra options to httperf: --wset=1000000,0.1
2012-06-07 19:36:08 [1, 0]: httperf-lru-nostream-gzip(httperf): Httperf command (last client): httperf --hog --timeout 60 --num-calls 10 --num-conns 8333 --port 8080 --burst-length 10 --client 23/24 --server 10.20.100.12 --wset=1000000,0.1
2012-06-07 19:36:15 [2, 6]: httperf-lru-nostream-gzip-deflateoff(httperf): Starting test
2012-06-07 19:39:21 WARNING [0,186]: httperf-lru-nostream-gzip-deflateoff(httperf): Panic detected. I think!
2012-06-07 19:39:21 WARNING [0, 0]: httperf-lru-nostream-gzip-deflateoff(httperf):
Last panic at: Thu, 07 Jun 2012 19:38:15 GMT
Assert error in VCL_recv_method(), ../../include/tbl/vcl_returns.h line 27:
Condition((req->sp) != NULL) not true.
thread = (cache-worker)
ident = Linux,2.6.32-38-generic,x86_64,-smalloc,-smalloc,-hcritbit,epoll
Backtrace:
0x431d88: pan_ic+d8
0x43a3b5: VCL_recv_method+1a5
0x4164c5: cnt_recv+1e5
0x41ae1d: CNT_Session+57d
0x43670d: ses_pool_task+fd
0x433592: Pool_Work_Thread+112
0x441128: wrk_thread_real+c8
0x7f4756ab99ca: _end+7f4756435202
0x7f4756816cdd: _end+7f4756192515
sp = 0x7f474a504820 {
fd = 14, id = 14, xid = 1099976957,
client = 10.20.100.9 13831,
step = STP_RECV,
handling = deliver,
restarts = 0, esi_level = 0
ws = 0x7f4746d13158 {
id = "req",
{s,f,r,e} = {0x7f4746d14730,+248,(nil),+59632},
},
http[req] = {
ws = 0x7f4746d13158[req]
"GET",
"/1/5/4/5/1/4.html",
"HTTP/1.1",
"User-Agent: httperf/0.9.0",
"Host: 10.20.100.12",
},
worker = 0x7f4746aaac60 {
ws = 0x7f4746aaae20 {
id = "wrk",
{s,f,r,e} = {0x7f4746aaa450,0x7f4746aaa450,(nil),+2048},
},
},
vcl = {
srcname = {
"input",
"Default",
},
},
},
2012-06-07 19:39:21 WARNING [0, 0]: httperf-lru-nostream-gzip-deflateoff(httperf): Varnishstat uptime and measured run-time is too large (measured: 182 stat: 65 diff: 117). Did we crash?
2012-06-07 19:39:21 WARNING [0, 0]: httperf-lru-nostream-gzip-deflateoff(httperf): Out of bounds: n_lru_nuked(0) less than lower boundary 80000
2012-06-07 19:39:21 WARNING [0, 0]: httperf-lru-nostream-gzip-deflateoff(httperf): Out of bounds: client_req(133090) less than lower boundary 1989920
2012-06-07 19:39:22 [1, 0]: httperf-lru-nostream-gzip-deflateoff(httperf): Load: 21:39:22 up 7 days, 8:02, 3 users, load average: 0.71, 1.33, 0.80
2012-06-07 19:39:22 [1, 0]: httperf-lru-nostream-gzip-deflateoff(httperf): Test name: httperf-lru-nostream-gzip-deflateoff
2012-06-07 19:39:22 [1, 0]: httperf-lru-nostream-gzip-deflateoff(httperf): Varnish options:
2012-06-07 19:39:22 [1, 0]: httperf-lru-nostream-gzip-deflateoff(httperf): -t=3600
2012-06-07 19:39:22 [1, 0]: httperf-lru-nostream-gzip-deflateoff(httperf): -s=malloc,30M
2012-06-07 19:39:22 [1, 0]: httperf-lru-nostream-gzip-deflateoff(httperf): Varnish parameters:
2012-06-07 19:39:22 [1, 0]: httperf-lru-nostream-gzip-deflateoff(httperf): thread_stats_rate=1
2012-06-07 19:39:22 [1, 0]: httperf-lru-nostream-gzip-deflateoff(httperf): thread_pool_max=5000
2012-06-07 19:39:22 [1, 0]: httperf-lru-nostream-gzip-deflateoff(httperf): nuke_limit=250
2012-06-07 19:39:22 [1, 0]: httperf-lru-nostream-gzip-deflateoff(httperf): http_gzip_support=on
2012-06-07 19:39:22 [1, 0]: httperf-lru-nostream-gzip-deflateoff(httperf): thread_pool_min=200
2012-06-07 19:39:22 [1, 0]: httperf-lru-nostream-gzip-deflateoff(httperf): Payload size (excludes headers): 10K
2012-06-07 19:39:22 [1, 0]: httperf-lru-nostream-gzip-deflateoff(httperf): Branch: master
2012-06-07 19:39:22 [1, 0]: httperf-lru-nostream-gzip-deflateoff(httperf): Number of clients involved: 24
2012-06-07 19:39:22 [1, 0]: httperf-lru-nostream-gzip-deflateoff(httperf): Type of test: httperf
2012-06-07 19:39:22 [1, 0]: httperf-lru-nostream-gzip-deflateoff(httperf): Test iterations: 1
2012-06-07 19:39:22 [1, 0]: httperf-lru-nostream-gzip-deflateoff(httperf): Runtime: 182 seconds
2012-06-07 19:39:22 [1, 0]: httperf-lru-nostream-gzip-deflateoff(httperf): VCL:
backend foo {
.host = "localhost";
.port = "80";
}
sub vcl_fetch {
set beresp.do_stream = false;
set beresp.do_gzip = true;
}
2012-06-07 19:39:22 [1, 0]: httperf-lru-nostream-gzip-deflateoff(httperf): Number of total connections: 200000
2012-06-07 19:39:22 [1, 0]: httperf-lru-nostream-gzip-deflateoff(httperf): Note: connections are subject to rounding when divided among clients. Expect slight deviations.
2012-06-07 19:39:22 [1, 0]: httperf-lru-nostream-gzip-deflateoff(httperf): Requests per connection: 10
2012-06-07 19:39:22 [1, 0]: httperf-lru-nostream-gzip-deflateoff(httperf): Extra options to httperf: --wset=1000000,0.1
2012-06-07 19:39:22 [1, 0]: httperf-lru-nostream-gzip-deflateoff(httperf): Httperf command (last client): httperf --hog --timeout 60 --num-calls 10 --num-conns 8333 --port 8080 --burst-length 10 --client 23/24 --server 10.20.100.12 --wset=1000000,0.1
2012-06-07 19:39:28 [2, 6]: streaming(httperf): Starting test
2012-06-07 19:42:22 [2,173]: httperf-lru-default(httperf): Starting test
2012-06-07 19:46:01 WARNING [0,219]: httperf-lru-default(httperf): Panic detected. I think!
2012-06-07 19:46:01 WARNING [0, 0]: httperf-lru-default(httperf):
Last panic at: Thu, 07 Jun 2012 19:44:43 GMT
Assert error in VCL_recv_method(), ../../include/tbl/vcl_returns.h line 27:
Condition((req->sp) != NULL) not true.
thread = (cache-worker)
ident = Linux,2.6.32-38-generic,x86_64,-smalloc,-smalloc,-hcritbit,epoll
Backtrace:
0x431d88: pan_ic+d8
0x43a3b5: VCL_recv_method+1a5
0x4164c5: cnt_recv+1e5
0x41ae1d: CNT_Session+57d
0x43670d: ses_pool_task+fd
0x433592: Pool_Work_Thread+112
0x441128: wrk_thread_real+c8
0x7ff8832489ca: _end+7ff882bc4202
0x7ff882fa5cdd: _end+7ff882921515
sp = 0x7ff876c0f120 {
fd = 20, id = 20, xid = 477787519,
client = 10.20.100.9 14415,
step = STP_RECV,
handling = deliver,
restarts = 0, esi_level = 0
ws = 0x7ff873202158 {
id = "req",
{s,f,r,e} = {0x7ff873203730,+248,(nil),+59632},
},
http[req] = {
ws = 0x7ff873202158[req]
"GET",
"/1/5/9/1/4/5.html",
"HTTP/1.1",
"User-Agent: httperf/0.9.0",
"Host: 10.20.100.12",
},
worker = 0x7ff872fcac60 {
ws = 0x7ff872fcae20 {
id = "wrk",
{s,f,r,e} = {0x7ff872fca450,0x7ff872fca450,(nil),+2048},
},
},
vcl = {
srcname = {
"input",
"Default",
},
},
},
2012-06-07 19:46:01 WARNING [0, 0]: httperf-lru-default(httperf): Varnishstat uptime and measured run-time is too large (measured: 215 stat: 77 diff: 138). Did we crash?
2012-06-07 19:46:02 WARNING [0, 0]: httperf-lru-default(httperf): Out of bounds: n_lru_nuked(0) less than lower boundary 80000
2012-06-07 19:46:02 WARNING [0, 0]: httperf-lru-default(httperf): Out of bounds: client_req(83640) less than lower boundary 1989920
2012-06-07 19:46:02 [1, 0]: httperf-lru-default(httperf): Load: 21:46:02 up 7 days, 8:08, 3 users, load average: 0.52, 0.90, 0.79
2012-06-07 19:46:02 [1, 0]: httperf-lru-default(httperf): Test name: httperf-lru-default
2012-06-07 19:46:02 [1, 0]: httperf-lru-default(httperf): Varnish options:
2012-06-07 19:46:02 [1, 0]: httperf-lru-default(httperf): -t=3600
2012-06-07 19:46:02 [1, 0]: httperf-lru-default(httperf): -s=malloc,30M
2012-06-07 19:46:02 [1, 0]: httperf-lru-default(httperf): Varnish parameters:
2012-06-07 19:46:02 [1, 0]: httperf-lru-default(httperf): thread_stats_rate=1
2012-06-07 19:46:02 [1, 0]: httperf-lru-default(httperf): thread_pool_max=5000
2012-06-07 19:46:02 [1, 0]: httperf-lru-default(httperf): nuke_limit=250
2012-06-07 19:46:02 [1, 0]: httperf-lru-default(httperf): thread_pool_min=200
2012-06-07 19:46:02 [1, 0]: httperf-lru-default(httperf): Payload size (excludes headers): 10K
2012-06-07 19:46:02 [1, 0]: httperf-lru-default(httperf): Branch: master
2012-06-07 19:46:02 [1, 0]: httperf-lru-default(httperf): Number of clients involved: 24
2012-06-07 19:46:02 [1, 0]: httperf-lru-default(httperf): Type of test: httperf
2012-06-07 19:46:02 [1, 0]: httperf-lru-default(httperf): Test iterations: 1
2012-06-07 19:46:02 [1, 0]: httperf-lru-default(httperf): Runtime: 215 seconds
2012-06-07 19:46:02 [1, 0]: httperf-lru-default(httperf): VCL:
backend foo {
.host = "localhost";
.port = "80";
}
sub vcl_fetch {
set beresp.do_stream = true;
}
2012-06-07 19:46:02 [1, 0]: httperf-lru-default(httperf): Number of total connections: 200000
2012-06-07 19:46:02 [1, 0]: httperf-lru-default(httperf): Note: connections are subject to rounding when divided among clients. Expect slight deviations.
2012-06-07 19:46:02 [1, 0]: httperf-lru-default(httperf): Requests per connection: 10
2012-06-07 19:46:02 [1, 0]: httperf-lru-default(httperf): Extra options to httperf: --wset=1000000,0.1
2012-06-07 19:46:02 [1, 0]: httperf-lru-default(httperf): Httperf command (last client): httperf --hog --timeout 60 --num-calls 10 --num-conns 8333 --port 8080 --burst-length 10 --client 23/24 --server 10.20.100.12 --wset=1000000,0.1
2012-06-07 19:46:09 [2, 6]: memleak(httperf): Starting test
2012-06-07 19:48:32 [2,143]: 4gpluss-stream(httperf): Starting test
2012-06-07 19:48:35 WARNING [0, 2]: Varnish failed to start. Fallback attempts starting
2012-06-07 19:48:35 [1, 0]: Removed (hopefully incompatible) parameter to try to start varnish. Key: thread_stats_rate=1
2012-06-07 19:48:36 [1, 0]: Removed (hopefully incompatible) parameter to try to start varnish. Key: thread_pool_max=300
2012-06-07 19:48:36 [1, 0]: Removed (hopefully incompatible) parameter to try to start varnish. Key: sess_timeout=60000s
2012-06-07 19:48:37 [1, 0]: Fallback worked. Parameter that seemed to cause problems: sess_timeout
2012-06-07 20:08:50 [2,1213]: httperf-lru-stream-default(httperf): Starting test
2012-06-07 20:12:12 WARNING [0,201]: httperf-lru-stream-default(httperf): Panic detected. I think!
2012-06-07 20:12:12 WARNING [0, 0]: httperf-lru-stream-default(httperf):
Last panic at: Thu, 07 Jun 2012 20:10:59 GMT
Assert error in cnt_first(), cache/cache_center.c line 943:
Condition(req->sp == sp) not true.
thread = (cache-worker)
ident = Linux,2.6.32-38-generic,x86_64,-smalloc,-smalloc,-hcritbit,epoll
Backtrace:
0x431d88: pan_ic+d8
0x41b021: CNT_Session+781
0x43670d: ses_pool_task+fd
0x433592: Pool_Work_Thread+112
0x441128: wrk_thread_real+c8
0x7f76e70d59ca: _end+7f76e6a51202
0x7f76e6e32cdd: _end+7f76e67ae515
sp = 0x7f76dce07620 {
fd = 21, id = 21, xid = 0,
client = ,
step = STP_FIRST,
handling = deliver,
restarts = 0, esi_level = 0
ws = 0x7f76d7e13158 {
id = "req",
{s,f,r,e} = {0x7f76d7e14730,0x7f76d7e14730,(nil),+59632},
},
http[req] = {
ws = (nil)[]
},
worker = 0x7f76d6f96c60 {
ws = 0x7f76d6f96e20 {
id = "wrk",
{s,f,r,e} = {0x7f76d6f96450,0x7f76d6f96450,(nil),+2048},
},
},
},
2012-06-07 20:12:12 WARNING [0, 0]: httperf-lru-stream-default(httperf): Varnishstat uptime and measured run-time is too large (measured: 196 stat: 72 diff: 124). Did we crash?
2012-06-07 20:12:12 WARNING [0, 0]: httperf-lru-stream-default(httperf): Out of bounds: n_lru_nuked(0) less than lower boundary 80000
2012-06-07 20:12:12 WARNING [0, 0]: httperf-lru-stream-default(httperf): Out of bounds: client_req(227641) less than lower boundary 1989920
2012-06-07 20:12:12 [1, 0]: httperf-lru-stream-default(httperf): Load: 22:12:12 up 7 days, 8:35, 3 users, load average: 1.90, 2.47, 1.59
2012-06-07 20:12:12 [1, 0]: httperf-lru-stream-default(httperf): Test name: httperf-lru-stream-default
2012-06-07 20:12:12 [1, 0]: httperf-lru-stream-default(httperf): Varnish options:
2012-06-07 20:12:12 [1, 0]: httperf-lru-stream-default(httperf): -t=3600
2012-06-07 20:12:12 [1, 0]: httperf-lru-stream-default(httperf): -s=malloc,30M
2012-06-07 20:12:12 [1, 0]: httperf-lru-stream-default(httperf): Varnish parameters:
2012-06-07 20:12:12 [1, 0]: httperf-lru-stream-default(httperf): thread_stats_rate=1
2012-06-07 20:12:12 [1, 0]: httperf-lru-stream-default(httperf): thread_pool_max=5000
2012-06-07 20:12:12 [1, 0]: httperf-lru-stream-default(httperf): nuke_limit=250
2012-06-07 20:12:12 [1, 0]: httperf-lru-stream-default(httperf): thread_pool_min=200
2012-06-07 20:12:12 [1, 0]: httperf-lru-stream-default(httperf): Payload size (excludes headers): 10K
2012-06-07 20:12:12 [1, 0]: httperf-lru-stream-default(httperf): Branch: master
2012-06-07 20:12:12 [1, 0]: httperf-lru-stream-default(httperf): Number of clients involved: 24
2012-06-07 20:12:12 [1, 0]: httperf-lru-stream-default(httperf): Type of test: httperf
2012-06-07 20:12:12 [1, 0]: httperf-lru-stream-default(httperf): Test iterations: 1
2012-06-07 20:12:12 [1, 0]: httperf-lru-stream-default(httperf): Runtime: 196 seconds
2012-06-07 20:12:12 [1, 0]: httperf-lru-stream-default(httperf): VCL:
backend foo {
.host = "localhost";
.port = "80";
}
sub vcl_fetch {
set beresp.do_stream = true;
}
2012-06-07 20:12:12 [1, 0]: httperf-lru-stream-default(httperf): Number of total connections: 200000
2012-06-07 20:12:12 [1, 0]: httperf-lru-stream-default(httperf): Note: connections are subject to rounding when divided among clients. Expect slight deviations.
2012-06-07 20:12:12 [1, 0]: httperf-lru-stream-default(httperf): Requests per connection: 10
2012-06-07 20:12:12 [1, 0]: httperf-lru-stream-default(httperf): Extra options to httperf: --wset=1000000,0.1
2012-06-07 20:12:12 [1, 0]: httperf-lru-stream-default(httperf): Httperf command (last client): httperf --hog --timeout 60 --num-calls 10 --num-conns 8333 --port 8080 --burst-length 10 --client 23/24 --server 10.20.100.12 --wset=1000000,0.1
2012-06-07 20:12:19 [2, 6]: httperf-hot(httperf): Starting test
2012-06-07 20:13:27 WARNING [0,68]: httperf-hot(httperf): Panic detected. I think!
2012-06-07 20:13:27 WARNING [0, 0]: httperf-hot(httperf):
Last panic at: Thu, 07 Jun 2012 20:13:01 GMT
Assert error in VCL_recv_method(), ../../include/tbl/vcl_returns.h line 27:
Condition((req->sp) != NULL) not true.
thread = (cache-worker)
ident = Linux,2.6.32-38-generic,x86_64,-smalloc,-smalloc,-hcritbit,epoll
Backtrace:
0x431d88: pan_ic+d8
0x43a3b5: VCL_recv_method+1a5
0x4164c5: cnt_recv+1e5
0x41ae1d: CNT_Session+57d
0x43670d: ses_pool_task+fd
0x433592: Pool_Work_Thread+112
0x441128: wrk_thread_real+c8
0x7fa3de2c99ca: _end+7fa3ddc45202
0x7fa3de026cdd: _end+7fa3dd9a2515
sp = 0x7fa3ddc21520 {
fd = 17, id = 17, xid = 242665387,
client = 10.20.100.9 8783,
step = STP_RECV,
handling = deliver,
restarts = 0, esi_level = 0
ws = 0x7fa3d3706158 {
id = "req",
{s,f,r,e} = {0x7fa3d3707730,+232,(nil),+59632},
},
http[req] = {
ws = 0x7fa3d3706158[req]
"GET",
"/2/8/6.html",
"HTTP/1.1",
"User-Agent: httperf/0.9.0",
"Host: 10.20.100.12",
},
worker = 0x7fa3cf1dac60 {
ws = 0x7fa3cf1dae20 {
id = "wrk",
{s,f,r,e} = {0x7fa3cf1da450,0x7fa3cf1da450,(nil),+2048},
},
},
vcl = {
srcname = {
"input",
"Default",
},
},
},
2012-06-07 20:13:27 WARNING [0, 0]: httperf-hot(httperf): Varnishstat uptime and measured run-time is too large (measured: 64 stat: 26 diff: 38). Did we crash?
2012-06-07 20:13:28 WARNING [0, 0]: httperf-hot(httperf): Out of bounds: client_req(82180) less than lower boundary 989840
2012-06-07 20:13:28 [1, 0]: httperf-hot(httperf): Load: 22:13:28 up 7 days, 8:36, 3 users, load average: 0.92, 2.06, 1.51
2012-06-07 20:13:28 [1, 0]: httperf-hot(httperf): Test name: httperf-hot
2012-06-07 20:13:28 [1, 0]: httperf-hot(httperf): Varnish options:
2012-06-07 20:13:28 [1, 0]: httperf-hot(httperf): Varnish parameters:
2012-06-07 20:13:28 [1, 0]: httperf-hot(httperf): thread_stats_rate=1
2012-06-07 20:13:28 [1, 0]: httperf-hot(httperf): Payload size (excludes headers): 256
2012-06-07 20:13:28 [1, 0]: httperf-hot(httperf): Branch: master
2012-06-07 20:13:28 [1, 0]: httperf-hot(httperf): Number of clients involved: 24
2012-06-07 20:13:28 [1, 0]: httperf-hot(httperf): Type of test: httperf
2012-06-07 20:13:28 [1, 0]: httperf-hot(httperf): Test iterations: 1
2012-06-07 20:13:28 [1, 0]: httperf-hot(httperf): Runtime: 64 seconds
2012-06-07 20:13:28 [1, 0]: httperf-hot(httperf): VCL:
backend foo {
.host = "localhost";
.port = "80";
}
sub vcl_fetch {
set beresp.do_stream = true;
}
2012-06-07 20:13:28 [1, 0]: httperf-hot(httperf): Number of total connections: 100000
2012-06-07 20:13:28 [1, 0]: httperf-hot(httperf): Note: connections are subject to rounding when divided among clients. Expect slight deviations.
2012-06-07 20:13:28 [1, 0]: httperf-hot(httperf): Requests per connection: 10
2012-06-07 20:13:28 [1, 0]: httperf-hot(httperf): Extra options to httperf: --wset=1000,0.25
2012-06-07 20:13:28 [1, 0]: httperf-hot(httperf): Httperf command (last client): httperf --hog --timeout 60 --num-calls 10 --num-conns 4166 --port 8080 --burst-length 10 --client 23/24 --server 10.20.100.12 --wset=1000,0.25
2012-06-07 20:13:35 [2, 6]: httperf-lru-nostream-nogzip(httperf): Starting test
2012-06-07 20:16:40 WARNING [0,185]: httperf-lru-nostream-nogzip(httperf): Panic detected. I think!
2012-06-07 20:16:40 WARNING [0, 0]: httperf-lru-nostream-nogzip(httperf):
Last panic at: Thu, 07 Jun 2012 20:15:47 GMT
Assert error in VRT_handling(), cache/cache_vrt.c line 249:
Condition(hand == VCL_RET_OK) not true.
thread = (cache-worker)
ident = Linux,2.6.32-38-generic,x86_64,-smalloc,-smalloc,-hcritbit,epoll
Backtrace:
0x431d88: pan_ic+d8
0x7f12b50fba1a: _end+7f12b4a77252
0x4395ae: VCL_deliver_method+be
0x419729: cnt_prepresp+269
0x41ac6d: CNT_Session+3cd
0x43670d: ses_pool_task+fd
0x433592: Pool_Work_Thread+112
0x441128: wrk_thread_real+c8
0x7f12c33219ca: _end+7f12c2c9d202
0x7f12c307ecdd: _end+7f12c29fa515
sp = 0x7f12b5b10520 {
fd = 24, id = 24, xid = 1521526386,
client = 10.20.100.8 14732,
step = STP_PREPRESP,
handling = deliver,
restarts = 0, esi_level = 0
ws = 0x7f12b2a7a158 {
id = "req",
{s,f,r,e} = {0x7f12b2a7b730,+648,(nil),+59632},
},
http[req] = {
ws = 0x7f12b2a7a158[req]
"GET",
"/1/6/2/5/4/3.html",
"HTTP/1.1",
"User-Agent: httperf/0.9.0",
"Host: 10.20.100.12",
"X-Forwarded-For: 10.20.100.8",
},
http[resp] = {
ws = 0x7f12b2a7a158[req]
"HTTP/1.1",
"OK",
"Server: nginx/0.7.65",
"Content-Type: text/plain",
"Last-Modified: Thu, 07 Jun 2012 20:13:38 GMT",
"Content-Length: 10240",
"Accept-Ranges: bytes",
"Date: Thu, 07 Jun 2012 20:15:47 GMT",
"X-Varnish: 1521526386 1521526307",
"Age: 0",
"Via: 1.1 varnish",
"Connection: keep-alive",
},
worker = 0x7f12b32dec60 {
ws = 0x7f12b32dee20 {
id = "wrk",
{s,f,r,e} = {0x7f12b32de450,0x7f12b32de450,(nil),+2048},
},
},
vcl = {
srcname = {
"input",
"Default",
},
},
obj = 0x7f12b0a5ea00 {
xid = 1521526307,
ws = 0x7f12b0a5ea18 {
id = "obj",
{s,f,r,e} = {0x7f12b0a5ebd8,+192,(nil),+224},
},
http[obj] = {
ws = 0x7f12b0a5ea18[obj]
"HTTP/1.1",
"OK",
"Server: nginx/0.7.65",
"Date: Thu, 07 Jun 2012 20:15:47 GMT",
"Content-Type: text/plain",
"Last-Modified: Thu, 07 Jun 2012 20:13:38 GMT",
"Content-Length: 10240",
},
len = 10240,
store = {
10240 {
4c 6f 72 65 6d 20 69 70 73 75 6d 20 64 6f 6c 6f |Lorem ipsum dolo|
72 20 73 69 74 20 61 6d 65 74 2c 20 63 6f 6e 73 |r sit amet, cons|
65 63 74 65 74 75 72 20 61 64 69 70 69 73 69 63 |ectetur adipisic|
69 6e 67 20 65 6c 69 74 2c 20 73 65 64 20 64 6f |ing elit, sed do|
[10176 more]
},
},
},
},
2012-06-07 20:16:40 WARNING [0, 0]: httperf-lru-nostream-nogzip(httperf): Varnishstat uptime and measured run-time is too large (measured: 181 stat: 53 diff: 128). Did we crash?
2012-06-07 20:16:41 WARNING [0, 0]: httperf-lru-nostream-nogzip(httperf): Out of bounds: n_lru_nuked(6077) less than lower boundary 80000
2012-06-07 20:16:41 WARNING [0, 0]: httperf-lru-nostream-nogzip(httperf): Out of bounds: client_req(89430) less than lower boundary 1989920
2012-06-07 20:16:41 [1, 0]: httperf-lru-nostream-nogzip(httperf): Load: 22:16:41 up 7 days, 8:39, 3 users, load average: 0.71, 1.52, 1.40
2012-06-07 20:16:41 [1, 0]: httperf-lru-nostream-nogzip(httperf): Test name: httperf-lru-nostream-nogzip
2012-06-07 20:16:41 [1, 0]: httperf-lru-nostream-nogzip(httperf): Varnish options:
2012-06-07 20:16:41 [1, 0]: httperf-lru-nostream-nogzip(httperf): -t=3600
2012-06-07 20:16:41 [1, 0]: httperf-lru-nostream-nogzip(httperf): -s=malloc,30M
2012-06-07 20:16:41 [1, 0]: httperf-lru-nostream-nogzip(httperf): Varnish parameters:
2012-06-07 20:16:41 [1, 0]: httperf-lru-nostream-nogzip(httperf): thread_stats_rate=1
2012-06-07 20:16:41 [1, 0]: httperf-lru-nostream-nogzip(httperf): thread_pool_max=5000
2012-06-07 20:16:41 [1, 0]: httperf-lru-nostream-nogzip(httperf): nuke_limit=250
2012-06-07 20:16:41 [1, 0]: httperf-lru-nostream-nogzip(httperf): http_gzip_support=off
2012-06-07 20:16:41 [1, 0]: httperf-lru-nostream-nogzip(httperf): thread_pool_min=200
2012-06-07 20:16:41 [1, 0]: httperf-lru-nostream-nogzip(httperf): Payload size (excludes headers): 10K
2012-06-07 20:16:41 [1, 0]: httperf-lru-nostream-nogzip(httperf): Branch: master
2012-06-07 20:16:41 [1, 0]: httperf-lru-nostream-nogzip(httperf): Number of clients involved: 24
2012-06-07 20:16:41 [1, 0]: httperf-lru-nostream-nogzip(httperf): Type of test: httperf
2012-06-07 20:16:41 [1, 0]: httperf-lru-nostream-nogzip(httperf): Test iterations: 1
2012-06-07 20:16:41 [1, 0]: httperf-lru-nostream-nogzip(httperf): Runtime: 181 seconds
2012-06-07 20:16:41 [1, 0]: httperf-lru-nostream-nogzip(httperf): VCL:
backend foo {
.host = "localhost";
.port = "80";
}
sub vcl_fetch {
set beresp.do_stream = false;
}
2012-06-07 20:16:41 [1, 0]: httperf-lru-nostream-nogzip(httperf): Number of total connections: 200000
2012-06-07 20:16:41 [1, 0]: httperf-lru-nostream-nogzip(httperf): Note: connections are subject to rounding when divided among clients. Expect slight deviations.
2012-06-07 20:16:41 [1, 0]: httperf-lru-nostream-nogzip(httperf): Requests per connection: 10
2012-06-07 20:16:41 [1, 0]: httperf-lru-nostream-nogzip(httperf): Extra options to httperf: --wset=1000000,0.1
2012-06-07 20:16:41 [1, 0]: httperf-lru-nostream-nogzip(httperf): Httperf command (last client): httperf --hog --timeout 60 --num-calls 10 --num-conns 8333 --port 8080 --burst-length 10 --client 23/24 --server 10.20.100.12 --wset=1000000,0.1
2012-06-07 20:16:48 [2, 6]: cold-gzip(httperf): Starting test
2012-06-07 20:20:12 WARNING [0,204]: cold-gzip(httperf): Panic detected. I think!
2012-06-07 20:20:12 WARNING [0, 0]: cold-gzip(httperf):
Last panic at: Thu, 07 Jun 2012 20:17:54 GMT
Assert error in cnt_first(), cache/cache_center.c line 943:
Condition(req->sp == sp) not true.
thread = (cache-worker)
ident = Linux,2.6.32-38-generic,x86_64,-smalloc,-smalloc,-hcritbit,epoll
Backtrace:
0x431d88: pan_ic+d8
0x41b021: CNT_Session+781
0x43670d: ses_pool_task+fd
0x433592: Pool_Work_Thread+112
0x441128: wrk_thread_real+c8
0x7fca4f2809ca: _end+7fca4ebfc202
0x7fca4efddcdd: _end+7fca4e959515
sp = 0x7fca4eb20620 {
fd = 25, id = 25, xid = 0,
client = ,
step = STP_FIRST,
handling = deliver,
restarts = 0, esi_level = 0
ws = 0x7fca42473158 {
id = "req",
{s,f,r,e} = {0x7fca42474730,0x7fca42474730,(nil),+59632},
},
http[req] = {
ws = (nil)[]
},
worker = 0x7fca408b2c60 {
ws = 0x7fca408b2e20 {
id = "wrk",
{s,f,r,e} = {0x7fca408b2450,0x7fca408b2450,(nil),+2048},
},
},
},
2012-06-07 20:20:12 WARNING [0, 0]: cold-gzip(httperf): Varnishstat uptime and measured run-time is too large (measured: 200 stat: 137 diff: 63). Did we crash?
2012-06-07 20:23:37 WARNING [0,205]: cold-gzip(httperf): Panic detected. I think!
2012-06-07 20:23:37 WARNING [0, 0]: cold-gzip(httperf):
Last panic at: Thu, 07 Jun 2012 20:23:00 GMT
Assert error in VCL_recv_method(), ../../include/tbl/vcl_returns.h line 27:
Condition((req->sp) != NULL) not true.
thread = (cache-worker)
ident = Linux,2.6.32-38-generic,x86_64,-smalloc,-smalloc,-hcritbit,epoll
Backtrace:
0x431d88: pan_ic+d8
0x43a3b5: VCL_recv_method+1a5
0x4164c5: cnt_recv+1e5
0x41ae1d: CNT_Session+57d
0x43670d: ses_pool_task+fd
0x433592: Pool_Work_Thread+112
0x441128: wrk_thread_real+c8
0x7fca4f2809ca: _end+7fca4ebfc202
0x7fca4efddcdd: _end+7fca4e959515
sp = 0x7fca3ff03820 {
fd = 18, id = 18, xid = 1269183674,
client = 10.20.100.8 7195,
step = STP_RECV,
handling = deliver,
restarts = 0, esi_level = 0
ws = 0x7fca401e0158 {
id = "req",
{s,f,r,e} = {0x7fca401e1730,+256,(nil),+59632},
},
http[req] = {
ws = 0x7fca401e0158[req]
"GET",
"/0/3/4/4/4/1/0.html",
"HTTP/1.1",
"User-Agent: httperf/0.9.0",
"Host: 10.20.100.12",
},
worker = 0x7fca40e8dc60 {
ws = 0x7fca40e8de20 {
id = "wrk",
{s,f,r,e} = {0x7fca40e8d450,0x7fca40e8d450,(nil),+2048},
},
},
vcl = {
srcname = {
"input",
"Default",
},
},
},
2012-06-07 20:23:37 WARNING [0, 0]: cold-gzip(httperf): Varnishstat uptime and measured run-time is too large (measured: 405 stat: 36 diff: 369). Did we crash?
2012-06-07 20:23:37 WARNING [0, 0]: cold-gzip(httperf): Out of bounds: uptime(36) less than lower boundary 100
2012-06-07 20:23:37 WARNING [0, 0]: cold-gzip(httperf): Out of bounds: client_req(16190) less than lower boundary 1589840
2012-06-07 20:23:37 [1, 0]: cold-gzip(httperf): Load: 22:23:37 up 7 days, 8:46, 3 users, load average: 0.84, 1.00, 1.18
2012-06-07 20:23:37 [1, 0]: cold-gzip(httperf): Test name: cold-gzip
2012-06-07 20:23:37 [1, 0]: cold-gzip(httperf): Varnish options:
2012-06-07 20:23:37 [1, 0]: cold-gzip(httperf): -t=3600
2012-06-07 20:23:37 [1, 0]: cold-gzip(httperf): -s=malloc,10G
2012-06-07 20:23:37 [1, 0]: cold-gzip(httperf): Varnish parameters:
2012-06-07 20:23:37 [1, 0]: cold-gzip(httperf): thread_stats_rate=1
2012-06-07 20:23:37 [1, 0]: cold-gzip(httperf): http_gzip_support=on
2012-06-07 20:23:37 [1, 0]: cold-gzip(httperf): Payload size (excludes headers): 256
2012-06-07 20:23:37 [1, 0]: cold-gzip(httperf): Branch: master
2012-06-07 20:23:37 [1, 0]: cold-gzip(httperf): Number of clients involved: 24
2012-06-07 20:23:37 [1, 0]: cold-gzip(httperf): Type of test: httperf
2012-06-07 20:23:37 [1, 0]: cold-gzip(httperf): Test iterations: 2
2012-06-07 20:23:37 [1, 0]: cold-gzip(httperf): Runtime: 405 seconds
2012-06-07 20:23:37 [1, 0]: cold-gzip(httperf): VCL:
backend foo {
.host = "localhost";
.port = "80";
}
sub vcl_fetch {
set beresp.do_stream = true;
}
2012-06-07 20:23:37 [1, 0]: cold-gzip(httperf): Number of total connections: 80000
2012-06-07 20:23:37 [1, 0]: cold-gzip(httperf): Note: connections are subject to rounding when divided among clients. Expect slight deviations.
2012-06-07 20:23:37 [1, 0]: cold-gzip(httperf): Requests per connection: 10
2012-06-07 20:23:37 [1, 0]: cold-gzip(httperf): Extra options to httperf: --wset=4000000,0.50
2012-06-07 20:23:37 [1, 0]: cold-gzip(httperf): Httperf command (last client): httperf --hog --timeout 60 --num-calls 10 --num-conns 3333 --port 8080 --burst-length 10 --client 23/24 --server 10.20.100.12 --wset=4000000,0.50
2012-06-07 20:23:44 [2, 6]: 4gpluss(httperf): Starting test
2012-06-07 20:23:47 WARNING [0, 2]: Varnish failed to start. Fallback attempts starting
2012-06-07 20:23:47 [1, 0]: Removed (hopefully incompatible) parameter to try to start varnish. Key: thread_stats_rate=1
2012-06-07 20:23:47 [1, 0]: Removed (hopefully incompatible) parameter to try to start varnish. Key: thread_pool_max=300
2012-06-07 20:23:48 [1, 0]: Removed (hopefully incompatible) parameter to try to start varnish. Key: sess_timeout=60000s
2012-06-07 20:23:49 [1, 0]: Fallback worked. Parameter that seemed to cause problems: sess_timeout
2012-06-07 20:45:16 [2,1287]: httperf-lru-stream-gzip(httperf): Starting test
2012-06-07 20:48:52 WARNING [0,216]: httperf-lru-stream-gzip(httperf): Panic detected. I think!
2012-06-07 20:48:52 WARNING [0, 0]: httperf-lru-stream-gzip(httperf):
Last panic at: Thu, 07 Jun 2012 20:47:37 GMT
Assert error in VCL_deliver_method(), ../../include/tbl/vcl_returns.h line 60:
Condition((req->sp) != NULL) not true.
thread = (cache-worker)
ident = Linux,2.6.32-38-generic,x86_64,-smalloc,-smalloc,-hcritbit,epoll
Backtrace:
0x431d88: pan_ic+d8
0x439695: VCL_deliver_method+1a5
0x419729: cnt_prepresp+269
0x41ac6d: CNT_Session+3cd
0x43670d: ses_pool_task+fd
0x433592: Pool_Work_Thread+112
0x441128: wrk_thread_real+c8
0x7f94b619b9ca: _end+7f94b5b17202
0x7f94b5ef8cdd: _end+7f94b5874515
sp = 0x7f94a7503220 {
fd = 16, id = 16, xid = 1027957024,
client = 10.20.100.8 15371,
step = STP_PREPRESP,
handling = deliver,
restarts = 0, esi_level = 0
ws = 0x7f94a6946158 {
id = "req",
{s,f,r,e} = {0x7f94a6947730,+328,(nil),+59632},
},
http[req] = {
ws = 0x7f94a6946158[req]
"GET",
"/1/7/1/7/0/5.html",
"HTTP/1.1",
"User-Agent: httperf/0.9.0",
"Host: 10.20.100.12",
"X-Forwarded-For: 10.20.100.8",
},
http[resp] = {
ws = 0x7f94a6946158[req]
"HTTP/1.1",
"OK",
"Server: nginx/0.7.65",
"Content-Type: text/plain",
"Last-Modified: Thu, 07 Jun 2012 20:45:20 GMT",
"Transfer-Encoding: chunked",
"Date: Thu, 07 Jun 2012 20:47:37 GMT",
"X-Varnish: 1027957024 1027956908",
"Age: 0",
"Via: 1.1 varnish",
"Connection: keep-alive",
},
worker = 0x7f94a650ec60 {
ws = 0x7f94a650ee20 {
id = "wrk",
{s,f,r,e} = {0x7f94a650e450,0x7f94a650e450,(nil),+2048},
},
},
vcl = {
srcname = {
"input",
"Default",
},
},
obj = 0x7f94a8c2e600 {
xid = 1027956908,
ws = 0x7f94a8c2e618 {
id = "obj",
{s,f,r,e} = {0x7f94a8c2e7e8,+216,(nil),+248},
},
http[obj] = {
ws = 0x7f94a8c2e618[obj]
"HTTP/1.1",
"OK",
"Server: nginx/0.7.65",
"Date: Thu, 07 Jun 2012 20:47:37 GMT",
"Content-Type: text/plain",
"Last-Modified: Thu, 07 Jun 2012 20:45:20 GMT",
"Content-Encoding: gzip",
"Content-Length: 249",
},
len = 249,
store = {
249 {
1f 8b 08 00 00 00 00 00 00 03 ed d0 c1 6d 04 21 |.............m.!|
0c 05 d0 94 f2 0b 58 6d 15 7b cc 35 05 38 60 ad |......Xm.{.5.8`.|
2c 61 98 05 b3 4a f9 f1 64 aa 88 f4 39 81 c0 1f |,a...J..d...9...|
fb 7d 8e a9 0e 3b d6 76 d4 d1 c6 c4 b2 80 b8 c6 |.}...;.v........|
[185 more]
},
},
},
},
2012-06-07 20:48:52 WARNING [0, 0]: httperf-lru-stream-gzip(httperf): Varnishstat uptime and measured run-time is too large (measured: 211 stat: 74 diff: 137). Did we crash?
2012-06-07 20:48:53 WARNING [0, 0]: httperf-lru-stream-gzip(httperf): Out of bounds: n_lru_nuked(0) less than lower boundary 80000
2012-06-07 20:48:53 WARNING [0, 0]: httperf-lru-stream-gzip(httperf): Out of bounds: client_req(176670) less than lower boundary 1989920
2012-06-07 20:48:53 [1, 0]: httperf-lru-stream-gzip(httperf): Load: 22:48:53 up 7 days, 9:11, 3 users, load average: 0.81, 0.89, 1.18
2012-06-07 20:48:53 [1, 0]: httperf-lru-stream-gzip(httperf): Test name: httperf-lru-stream-gzip
2012-06-07 20:48:53 [1, 0]: httperf-lru-stream-gzip(httperf): Varnish options:
2012-06-07 20:48:53 [1, 0]: httperf-lru-stream-gzip(httperf): -t=3600
2012-06-07 20:48:53 [1, 0]: httperf-lru-stream-gzip(httperf): -s=malloc,30M
2012-06-07 20:48:53 [1, 0]: httperf-lru-stream-gzip(httperf): Varnish parameters:
2012-06-07 20:48:53 [1, 0]: httperf-lru-stream-gzip(httperf): thread_stats_rate=1
2012-06-07 20:48:53 [1, 0]: httperf-lru-stream-gzip(httperf): thread_pool_max=5000
2012-06-07 20:48:53 [1, 0]: httperf-lru-stream-gzip(httperf): nuke_limit=250
2012-06-07 20:48:53 [1, 0]: httperf-lru-stream-gzip(httperf): http_gzip_support=on
2012-06-07 20:48:53 [1, 0]: httperf-lru-stream-gzip(httperf): thread_pool_min=200
2012-06-07 20:48:53 [1, 0]: httperf-lru-stream-gzip(httperf): Payload size (excludes headers): 10K
2012-06-07 20:48:53 [1, 0]: httperf-lru-stream-gzip(httperf): Branch: master
2012-06-07 20:48:53 [1, 0]: httperf-lru-stream-gzip(httperf): Number of clients involved: 24
2012-06-07 20:48:53 [1, 0]: httperf-lru-stream-gzip(httperf): Type of test: httperf
2012-06-07 20:48:53 [1, 0]: httperf-lru-stream-gzip(httperf): Test iterations: 1
2012-06-07 20:48:53 [1, 0]: httperf-lru-stream-gzip(httperf): Runtime: 211 seconds
2012-06-07 20:48:53 [1, 0]: httperf-lru-stream-gzip(httperf): VCL:
backend foo {
.host = "localhost";
.port = "80";
}
sub vcl_fetch {
set beresp.do_stream = true;
}
2012-06-07 20:48:53 [1, 0]: httperf-lru-stream-gzip(httperf): Number of total connections: 200000
2012-06-07 20:48:53 [1, 0]: httperf-lru-stream-gzip(httperf): Note: connections are subject to rounding when divided among clients. Expect slight deviations.
2012-06-07 20:48:53 [1, 0]: httperf-lru-stream-gzip(httperf): Requests per connection: 10
2012-06-07 20:48:53 [1, 0]: httperf-lru-stream-gzip(httperf): Extra options to httperf: --wset=1000000,0.1
2012-06-07 20:48:53 [1, 0]: httperf-lru-stream-gzip(httperf): Httperf command (last client): httperf --hog --timeout 60 --num-calls 10 --num-conns 8333 --port 8080 --burst-length 10 --client 23/24 --server 10.20.100.12 --wset=1000000,0.1
2012-06-07 20:49:00 [2, 6]: httperf-lru-stream-nogzip(httperf): Starting test
2012-06-07 20:52:35 WARNING [0,214]: httperf-lru-stream-nogzip(httperf): Panic detected. I think!
2012-06-07 20:52:35 WARNING [0, 0]: httperf-lru-stream-nogzip(httperf):
Last panic at: Thu, 07 Jun 2012 20:51:50 GMT
Assert error in VCL_fetch_method(), ../../include/tbl/vcl_returns.h line 56:
Condition((req->sp) != NULL) not true.
thread = (cache-worker)
ident = Linux,2.6.32-38-generic,x86_64,-smalloc,-smalloc,-hcritbit,epoll
Backtrace:
0x431d88: pan_ic+d8
0x439875: VCL_fetch_method+1a5
0x4186a9: cnt_fetch+479
0x41accd: CNT_Session+42d
0x43670d: ses_pool_task+fd
0x433592: Pool_Work_Thread+112
0x441128: wrk_thread_real+c8
0x7f5367c9d9ca: _end+7f5367619202
0x7f53679facdd: _end+7f5367376515
sp = 0x7f535850aa20 {
fd = 22, id = 22, xid = 2134336991,
client = 10.20.100.9 15877,
step = STP_FETCH,
handling = fetch,
err_code = 200, err_reason = (null),
restarts = 0, esi_level = 0
busyobj = 0x7f53583bf020 {
ws = 0x7f53583bf070 {
id = "bo",
{s,f,r,e} = {0x7f53583c0aa0,+248,(nil),+58752},
},
do_stream
bodystatus = 4 (length),
},
http[bereq] = {
ws = 0x7f53583bf070[bo]
"GET",
"/1/7/4/2/8/9.html",
"HTTP/1.1",
"User-Agent: httperf/0.9.0",
"Host: 10.20.100.12",
"X-Forwarded-For: 10.20.100.9",
"X-Varnish: 2134336991",
},
http[beresp] = {
ws = 0x7f53583bf070[bo]
"HTTP/1.1",
"200",
"OK",
"Server: nginx/0.7.65",
"Date: Thu, 07 Jun 2012 20:51:50 GMT",
"Content-Type: text/plain",
"Content-Length: 10240",
"Last-Modified: Thu, 07 Jun 2012 20:49:03 GMT",
"Connection: keep-alive",
"Accept-Ranges: bytes",
},
ws = 0x7f5358f39158 {
id = "req",
{s,f,r,e} = {0x7f5358f3a730,+136,(nil),+59632},
},
http[req] = {
ws = 0x7f5358f39158[req]
"GET",
"/1/7/4/2/8/9.html",
"HTTP/1.1",
"User-Agent: httperf/0.9.0",
"Host: 10.20.100.12",
"X-Forwarded-For: 10.20.100.9",
},
worker = 0x7f5357b4ac60 {
ws = 0x7f5357b4ae20 {
id = "wrk",
{s,f,r,e} = {0x7f5357b4a450,0x7f5357b4a450,(nil),+2048},
},
},
vcl = {
srcname = {
"input",
"Default",
},
},
},
2012-06-07 20:52:35 WARNING [0, 0]: httperf-lru-stream-nogzip(httperf): Varnishstat uptime and measured run-time is too large (measured: 211 stat: 44 diff: 167). Did we crash?
2012-06-07 20:52:35 WARNING [0, 0]: httperf-lru-stream-nogzip(httperf): Out of bounds: n_lru_nuked(135) less than lower boundary 80000
2012-06-07 20:52:35 WARNING [0, 0]: httperf-lru-stream-nogzip(httperf): Out of bounds: client_req(30040) less than lower boundary 1989920
2012-06-07 20:52:35 [1, 0]: httperf-lru-stream-nogzip(httperf): Load: 22:52:35 up 7 days, 9:15, 3 users, load average: 2.62, 4.47, 2.80
2012-06-07 20:52:35 [1, 0]: httperf-lru-stream-nogzip(httperf): Test name: httperf-lru-stream-nogzip
2012-06-07 20:52:35 [1, 0]: httperf-lru-stream-nogzip(httperf): Varnish options:
2012-06-07 20:52:35 [1, 0]: httperf-lru-stream-nogzip(httperf): -t=3600
2012-06-07 20:52:35 [1, 0]: httperf-lru-stream-nogzip(httperf): -s=malloc,30M
2012-06-07 20:52:35 [1, 0]: httperf-lru-stream-nogzip(httperf): Varnish parameters:
2012-06-07 20:52:35 [1, 0]: httperf-lru-stream-nogzip(httperf): thread_stats_rate=1
2012-06-07 20:52:35 [1, 0]: httperf-lru-stream-nogzip(httperf): thread_pool_max=5000
2012-06-07 20:52:35 [1, 0]: httperf-lru-stream-nogzip(httperf): nuke_limit=250
2012-06-07 20:52:35 [1, 0]: httperf-lru-stream-nogzip(httperf): http_gzip_support=off
2012-06-07 20:52:35 [1, 0]: httperf-lru-stream-nogzip(httperf): thread_pool_min=200
2012-06-07 20:52:35 [1, 0]: httperf-lru-stream-nogzip(httperf): Payload size (excludes headers): 10K
2012-06-07 20:52:35 [1, 0]: httperf-lru-stream-nogzip(httperf): Branch: master
2012-06-07 20:52:35 [1, 0]: httperf-lru-stream-nogzip(httperf): Number of clients involved: 24
2012-06-07 20:52:35 [1, 0]: httperf-lru-stream-nogzip(httperf): Type of test: httperf
2012-06-07 20:52:35 [1, 0]: httperf-lru-stream-nogzip(httperf): Test iterations: 1
2012-06-07 20:52:35 [1, 0]: httperf-lru-stream-nogzip(httperf): Runtime: 211 seconds
2012-06-07 20:52:35 [1, 0]: httperf-lru-stream-nogzip(httperf): VCL:
backend foo {
.host = "localhost";
.port = "80";
}
sub vcl_fetch {
set beresp.do_stream = true;
}
2012-06-07 20:52:35 [1, 0]: httperf-lru-stream-nogzip(httperf): Number of total connections: 200000
2012-06-07 20:52:35 [1, 0]: httperf-lru-stream-nogzip(httperf): Note: connections are subject to rounding when divided among clients. Expect slight deviations.
2012-06-07 20:52:35 [1, 0]: httperf-lru-stream-nogzip(httperf): Requests per connection: 10
2012-06-07 20:52:35 [1, 0]: httperf-lru-stream-nogzip(httperf): Extra options to httperf: --wset=1000000,0.1
2012-06-07 20:52:35 [1, 0]: httperf-lru-stream-nogzip(httperf): Httperf command (last client): httperf --hog --timeout 60 --num-calls 10 --num-conns 8333 --port 8080 --burst-length 10 --client 23/24 --server 10.20.100.12 --wset=1000000,0.1
2012-06-07 20:52:42 [2, 6]: basic-fryer(httperf): Starting test
2012-06-07 20:53:04 [2,22]: cold-nogzip(httperf): Starting test
2012-06-07 20:56:30 WARNING [0,205]: cold-nogzip(httperf): Panic detected. I think!
2012-06-07 20:56:30 WARNING [0, 0]: cold-nogzip(httperf):
Last panic at: Thu, 07 Jun 2012 20:54:30 GMT
Assert error in VCL_recv_method(), ../../include/tbl/vcl_returns.h line 27:
Condition((req->sp) != NULL) not true.
thread = (cache-worker)
ident = Linux,2.6.32-38-generic,x86_64,-smalloc,-smalloc,-hcritbit,epoll
Backtrace:
0x431d88: pan_ic+d8
0x43a3b5: VCL_recv_method+1a5
0x4164c5: cnt_recv+1e5
0x41ae1d: CNT_Session+57d
0x43670d: ses_pool_task+fd
0x433592: Pool_Work_Thread+112
0x441128: wrk_thread_real+c8
0x7fb6a56c49ca: _end+7fb6a5040202
0x7fb6a5421cdd: _end+7fb6a4d9d515
sp = 0x7fb696437820 {
fd = 25, id = 25, xid = 1670347141,
client = 10.20.100.8 5271,
step = STP_RECV,
handling = deliver,
restarts = 0, esi_level = 0
ws = 0x7fb696535158 {
id = "req",
{s,f,r,e} = {0x7fb696536730,+256,(nil),+59632},
},
http[req] = {
ws = 0x7fb696535158[req]
"GET",
"/0/2/3/5/6/9/4.html",
"HTTP/1.1",
"User-Agent: httperf/0.9.0",
"Host: 10.20.100.12",
},
worker = 0x7fb6968cec60 {
ws = 0x7fb6968cee20 {
id = "wrk",
{s,f,r,e} = {0x7fb6968ce450,0x7fb6968ce450,(nil),+2048},
},
},
vcl = {
srcname = {
"input",
"Default",
},
},
},
2012-06-07 20:56:30 WARNING [0, 0]: cold-nogzip(httperf): Varnishstat uptime and measured run-time is too large (measured: 201 stat: 119 diff: 82). Did we crash?
2012-06-07 21:00:20 WARNING [0,230]: cold-nogzip(httperf): Panic detected. I think!
2012-06-07 21:00:20 WARNING [0, 0]: cold-nogzip(httperf):
Last panic at: Thu, 07 Jun 2012 20:58:30 GMT
Assert error in VCL_fetch_method(), ../../include/tbl/vcl_returns.h line 56:
Condition((req->sp) != NULL) not true.
thread = (cache-worker)
ident = Linux,2.6.32-38-generic,x86_64,-smalloc,-smalloc,-hcritbit,epoll
Backtrace:
0x431d88: pan_ic+d8
0x439875: VCL_fetch_method+1a5
0x4186a9: cnt_fetch+479
0x41accd: CNT_Session+42d
0x43670d: ses_pool_task+fd
0x433592: Pool_Work_Thread+112
0x441128: wrk_thread_real+c8
0x7fb6a56c49ca: _end+7fb6a5040202
0x7fb6a5421cdd: _end+7fb6a4d9d515
sp = 0x7fb696313120 {
fd = 27, id = 27, xid = 783170211,
client = 10.20.100.7 5698,
step = STP_FETCH,
handling = fetch,
err_code = 200, err_reason = (null),
restarts = 0, esi_level = 0
busyobj = 0x7fb697d2c020 {
ws = 0x7fb697d2c070 {
id = "bo",
{s,f,r,e} = {0x7fb697d2daa0,+504,(nil),+58752},
},
do_stream
bodystatus = 4 (length),
},
http[bereq] = {
ws = 0x7fb697d2c070[bo]
"GET",
"/0/2/7/7/4/8/1.html",
"HTTP/1.1",
"User-Agent: httperf/0.9.0",
"Host: 10.20.100.12",
"X-Forwarded-For: 10.20.100.7",
"X-Varnish: 783170211",
},
http[beresp] = {
ws = 0x7fb697d2c070[bo]
"HTTP/1.1",
"200",
"OK",
"Server: nginx/0.7.65",
"Date: Thu, 07 Jun 2012 20:58:30 GMT",
"Content-Type: text/plain",
"Content-Length: 256",
"Last-Modified: Thu, 07 Jun 2012 20:53:07 GMT",
"Connection: keep-alive",
"Accept-Ranges: bytes",
},
ws = 0x7fb695b13158 {
id = "req",
{s,f,r,e} = {0x7fb695b14730,+216,(nil),+59632},
},
http[req] = {
ws = 0x7fb695b13158[req]
"GET",
"/0/2/7/7/4/8/1.html",
"HTTP/1.1",
"User-Agent: httperf/0.9.0",
"Host: 10.20.100.12",
"X-Forwarded-For: 10.20.100.7",
},
worker = 0x7fb696ae0c60 {
ws = 0x7fb696ae0e20 {
id = "wrk",
{s,f,r,e} = {0x7fb696ae0450,0x7fb696ae0450,(nil),+2048},
},
},
vcl = {
srcname = {
"input",
"Default",
},
},
},
2012-06-07 21:00:20 WARNING [0, 0]: cold-nogzip(httperf): Varnishstat uptime and measured run-time is too large (measured: 432 stat: 109 diff: 323). Did we crash?
2012-06-07 21:00:21 WARNING [0, 0]: cold-nogzip(httperf): Out of bounds: client_req(134420) less than lower boundary 1589840
2012-06-07 21:00:21 [1, 0]: cold-nogzip(httperf): Load: 23:00:21 up 7 days, 9:23, 3 users, load average: 0.32, 1.45, 1.96
2012-06-07 21:00:21 [1, 0]: cold-nogzip(httperf): Test name: cold-nogzip
2012-06-07 21:00:21 [1, 0]: cold-nogzip(httperf): Varnish options:
2012-06-07 21:00:21 [1, 0]: cold-nogzip(httperf): -t=3600
2012-06-07 21:00:21 [1, 0]: cold-nogzip(httperf): -s=malloc,10G
2012-06-07 21:00:21 [1, 0]: cold-nogzip(httperf): Varnish parameters:
2012-06-07 21:00:21 [1, 0]: cold-nogzip(httperf): thread_stats_rate=1
2012-06-07 21:00:21 [1, 0]: cold-nogzip(httperf): http_gzip_support=off
2012-06-07 21:00:21 [1, 0]: cold-nogzip(httperf): Payload size (excludes headers): 256
2012-06-07 21:00:21 [1, 0]: cold-nogzip(httperf): Branch: master
2012-06-07 21:00:21 [1, 0]: cold-nogzip(httperf): Number of clients involved: 24
2012-06-07 21:00:21 [1, 0]: cold-nogzip(httperf): Type of test: httperf
2012-06-07 21:00:21 [1, 0]: cold-nogzip(httperf): Test iterations: 2
2012-06-07 21:00:21 [1, 0]: cold-nogzip(httperf): Runtime: 432 seconds
2012-06-07 21:00:21 [1, 0]: cold-nogzip(httperf): VCL:
backend foo {
.host = "localhost";
.port = "80";
}
sub vcl_fetch {
set beresp.do_stream = true;
}
2012-06-07 21:00:21 [1, 0]: cold-nogzip(httperf): Number of total connections: 80000
2012-06-07 21:00:21 [1, 0]: cold-nogzip(httperf): Note: connections are subject to rounding when divided among clients. Expect slight deviations.
2012-06-07 21:00:21 [1, 0]: cold-nogzip(httperf): Requests per connection: 10
2012-06-07 21:00:21 [1, 0]: cold-nogzip(httperf): Extra options to httperf: --wset=4000000,0.50
2012-06-07 21:00:21 [1, 0]: cold-nogzip(httperf): Httperf command (last client): httperf --hog --timeout 60 --num-calls 10 --num-conns 3333 --port 8080 --burst-length 10 --client 23/24 --server 10.20.100.12 --wset=4000000,0.50
2012-06-07 21:00:33 [2,12]: 4gpluss-nostream(httperf): Starting test
2012-06-07 21:00:36 WARNING [0, 3]: Varnish failed to start. Fallback attempts starting
2012-06-07 21:00:36 [1, 0]: Removed (hopefully incompatible) parameter to try to start varnish. Key: thread_stats_rate=1
2012-06-07 21:00:37 [1, 0]: Removed (hopefully incompatible) parameter to try to start varnish. Key: thread_pool_max=300
2012-06-07 21:00:38 [1, 0]: Removed (hopefully incompatible) parameter to try to start varnish. Key: sess_timeout=60000s
2012-06-07 21:00:38 [1, 0]: Fallback worked. Parameter that seemed to cause problems: sess_timeout
2012-06-07 21:21:05 [2,1227]: lru-random(httperf): Starting test
2012-06-07 21:32:36 [2,690]: siege-test(siege): Starting test
2012-06-07 21:32:54 WARNING [0,18]: siege-test(siege): Panic detected. I think!
2012-06-07 21:32:54 WARNING [0, 0]: siege-test(siege):
Last panic at: Thu, 07 Jun 2012 21:32:40 GMT
Assert error in cnt_first(), cache/cache_center.c line 943:
Condition(req->sp == sp) not true.
thread = (cache-worker)
ident = Linux,2.6.32-38-generic,x86_64,-smalloc,-smalloc,-hcritbit,epoll
Backtrace:
0x431d88: pan_ic+d8
0x41b021: CNT_Session+781
0x43670d: ses_pool_task+fd
0x433592: Pool_Work_Thread+112
0x441128: wrk_thread_real+c8
0x7f0143b679ca: _end+7f01434e3202
0x7f01438c4cdd: _end+7f0143240515
sp = 0x7f0134eb2920 {
fd = 37, id = 37, xid = 0,
client = ,
step = STP_FIRST,
handling = deliver,
restarts = 0, esi_level = 0
ws = 0x7f0134edd158 {
id = "req",
{s,f,r,e} = {0x7f0134ede730,0x7f0134ede730,(nil),+59632},
},
http[req] = {
ws = (nil)[]
},
worker = 0x7f01350c0c60 {
ws = 0x7f01350c0e20 {
id = "wrk",
{s,f,r,e} = {0x7f01350c0450,0x7f01350c0450,(nil),+2048},
},
},
},
2012-06-07 21:32:54 [1, 0]: siege-test(siege): Load: 23:32:54 up 7 days, 9:55, 3 users, load average: 0.30, 0.51, 0.71
2012-06-07 21:32:54 [1, 0]: siege-test(siege): Test name: siege-test
2012-06-07 21:32:54 [1, 0]: siege-test(siege): Varnish options:
2012-06-07 21:32:54 [1, 0]: siege-test(siege): Varnish parameters:
2012-06-07 21:32:54 [1, 0]: siege-test(siege): thread_stats_rate=1
2012-06-07 21:32:54 [1, 0]: siege-test(siege): Payload size (excludes headers): 256
2012-06-07 21:32:54 [1, 0]: siege-test(siege): Branch: master
2012-06-07 21:32:54 [1, 0]: siege-test(siege): Number of clients involved: 0
2012-06-07 21:32:54 [1, 0]: siege-test(siege): Type of test: siege
2012-06-07 21:32:54 [1, 0]: siege-test(siege): Test iterations: 1
2012-06-07 21:32:54 [1, 0]: siege-test(siege): Runtime: 14 seconds
2012-06-07 21:32:54 [1, 0]: siege-test(siege): VCL:
backend foo {
.host = "localhost";
.port = "80";
}
sub vcl_fetch {
set beresp.do_stream = true;
}
2012-06-07 21:33:01 [2, 6]: httperf-lru-nostream-default(httperf): Starting test
2012-06-07 21:36:04 WARNING [0,182]: httperf-lru-nostream-default(httperf): Panic detected. I think!
2012-06-07 21:36:04 WARNING [0, 0]: httperf-lru-nostream-default(httperf):
Last panic at: Thu, 07 Jun 2012 21:35:33 GMT
Assert error in VCL_fetch_method(), ../../include/tbl/vcl_returns.h line 56:
Condition((req->sp) != NULL) not true.
thread = (cache-worker)
ident = Linux,2.6.32-38-generic,x86_64,-smalloc,-smalloc,-hcritbit,epoll
Backtrace:
0x431d88: pan_ic+d8
0x439875: VCL_fetch_method+1a5
0x4186a9: cnt_fetch+479
0x41accd: CNT_Session+42d
0x43670d: ses_pool_task+fd
0x433592: Pool_Work_Thread+112
0x441128: wrk_thread_real+c8
0x7f44049e69ca: _end+7f4404362202
0x7f4404743cdd: _end+7f44040bf515
sp = 0x7f43f5902320 {
fd = 22, id = 22, xid = 566347743,
client = 10.20.100.9 16973,
step = STP_FETCH,
handling = fetch,
err_code = 200, err_reason = (null),
restarts = 0, esi_level = 0
busyobj = 0x7f43f4fd2020 {
ws = 0x7f43f4fd2070 {
id = "bo",
{s,f,r,e} = {0x7f43f4fd3aa0,+512,(nil),+58752},
},
do_stream
bodystatus = 3 (chunked),
},
http[bereq] = {
ws = 0x7f43f4fd2070[bo]
"GET",
"/1/9/1/3/5/5.html",
"HTTP/1.1",
"User-Agent: httperf/0.9.0",
"Host: 10.20.100.12",
"X-Forwarded-For: 10.20.100.9",
"X-Varnish: 566347743",
"Accept-Encoding: gzip",
},
http[beresp] = {
ws = 0x7f43f4fd2070[bo]
"HTTP/1.1",
"200",
"OK",
"Server: nginx/0.7.65",
"Date: Thu, 07 Jun 2012 21:35:33 GMT",
"Content-Type: text/plain",
"Last-Modified: Thu, 07 Jun 2012 21:33:04 GMT",
"Transfer-Encoding: chunked",
"Connection: keep-alive",
"Content-Encoding: gzip",
},
ws = 0x7f43f59c0158 {
id = "req",
{s,f,r,e} = {0x7f43f59c1730,+136,(nil),+59632},
},
http[req] = {
ws = 0x7f43f59c0158[req]
"GET",
"/1/9/1/3/5/5.html",
"HTTP/1.1",
"User-Agent: httperf/0.9.0",
"Host: 10.20.100.12",
"X-Forwarded-For: 10.20.100.9",
},
worker = 0x7f43f475ac60 {
ws = 0x7f43f475ae20 {
id = "wrk",
{s,f,r,e} = {0x7f43f475a450,0x7f43f475a450,(nil),+2048},
},
},
vcl = {
srcname = {
"input",
"Default",
},
},
},
2012-06-07 21:36:04 WARNING [0, 0]: httperf-lru-nostream-default(httperf): Varnishstat uptime and measured run-time is too large (measured: 178 stat: 29 diff: 149). Did we crash?
2012-06-07 21:36:04 WARNING [0, 0]: httperf-lru-nostream-default(httperf): Out of bounds: n_lru_nuked(0) less than lower boundary 80000
2012-06-07 21:36:04 WARNING [0, 0]: httperf-lru-nostream-default(httperf): Out of bounds: client_req(21800) less than lower boundary 1989920
2012-06-07 21:36:04 [1, 0]: httperf-lru-nostream-default(httperf): Load: 23:36:04 up 7 days, 9:58, 3 users, load average: 0.71, 0.73, 0.76
2012-06-07 21:36:04 [1, 0]: httperf-lru-nostream-default(httperf): Test name: httperf-lru-nostream-default
2012-06-07 21:36:04 [1, 0]: httperf-lru-nostream-default(httperf): Varnish options:
2012-06-07 21:36:04 [1, 0]: httperf-lru-nostream-default(httperf): -t=3600
2012-06-07 21:36:04 [1, 0]: httperf-lru-nostream-default(httperf): -s=malloc,30M
2012-06-07 21:36:04 [1, 0]: httperf-lru-nostream-default(httperf): Varnish parameters:
2012-06-07 21:36:04 [1, 0]: httperf-lru-nostream-default(httperf): thread_stats_rate=1
2012-06-07 21:36:04 [1, 0]: httperf-lru-nostream-default(httperf): thread_pool_max=5000
2012-06-07 21:36:04 [1, 0]: httperf-lru-nostream-default(httperf): nuke_limit=250
2012-06-07 21:36:04 [1, 0]: httperf-lru-nostream-default(httperf): thread_pool_min=200
2012-06-07 21:36:04 [1, 0]: httperf-lru-nostream-default(httperf): Payload size (excludes headers): 10K
2012-06-07 21:36:04 [1, 0]: httperf-lru-nostream-default(httperf): Branch: master
2012-06-07 21:36:04 [1, 0]: httperf-lru-nostream-default(httperf): Number of clients involved: 24
2012-06-07 21:36:04 [1, 0]: httperf-lru-nostream-default(httperf): Type of test: httperf
2012-06-07 21:36:04 [1, 0]: httperf-lru-nostream-default(httperf): Test iterations: 1
2012-06-07 21:36:04 [1, 0]: httperf-lru-nostream-default(httperf): Runtime: 178 seconds
2012-06-07 21:36:04 [1, 0]: httperf-lru-nostream-default(httperf): VCL:
backend foo {
.host = "localhost";
.port = "80";
}
sub vcl_fetch {
set beresp.do_stream = false;
}
2012-06-07 21:36:04 [1, 0]: httperf-lru-nostream-default(httperf): Number of total connections: 200000
2012-06-07 21:36:04 [1, 0]: httperf-lru-nostream-default(httperf): Note: connections are subject to rounding when divided among clients. Expect slight deviations.
2012-06-07 21:36:04 [1, 0]: httperf-lru-nostream-default(httperf): Requests per connection: 10
2012-06-07 21:36:04 [1, 0]: httperf-lru-nostream-default(httperf): Extra options to httperf: --wset=1000000,0.1
2012-06-07 21:36:04 [1, 0]: httperf-lru-nostream-default(httperf): Httperf command (last client): httperf --hog --timeout 60 --num-calls 10 --num-conns 8333 --port 8080 --burst-length 10 --client 23/24 --server 10.20.100.12 --wset=1000000,0.1
2012-06-07 21:36:11 [2, 6]: httperf-rapid-expire(httperf): Starting test
2012-06-07 21:37:17 WARNING [0,66]: httperf-rapid-expire(httperf): Panic detected. I think!
2012-06-07 21:37:17 WARNING [0, 0]: httperf-rapid-expire(httperf):
Last panic at: Thu, 07 Jun 2012 21:36:45 GMT
Assert error in cnt_first(), cache/cache_center.c line 943:
Condition(req->sp == sp) not true.
thread = (cache-worker)
ident = Linux,2.6.32-38-generic,x86_64,-smalloc,-smalloc,-hcritbit,epoll
Backtrace:
0x431d88: pan_ic+d8
0x41b021: CNT_Session+781
0x43670d: ses_pool_task+fd
0x433592: Pool_Work_Thread+112
0x441128: wrk_thread_real+c8
0x7f197ddb49ca: _end+7f197d730202
0x7f197db11cdd: _end+7f197d48d515
sp = 0x7f196e806120 {
fd = 20, id = 20, xid = 0,
client = ,
step = STP_FIRST,
handling = deliver,
restarts = 0, esi_level = 0
ws = 0x7f196e66a158 {
id = "req",
{s,f,r,e} = {0x7f196e66b730,0x7f196e66b730,(nil),+59632},
},
http[req] = {
ws = (nil)[]
},
worker = 0x7f196eac1c60 {
ws = 0x7f196eac1e20 {
id = "wrk",
{s,f,r,e} = {0x7f196eac1450,0x7f196eac1450,(nil),+2048},
},
},
},
2012-06-07 21:37:17 WARNING [0, 0]: httperf-rapid-expire(httperf): Varnishstat uptime and measured run-time is too large (measured: 62 stat: 31 diff: 31). Did we crash?
2012-06-07 21:37:17 WARNING [0, 0]: httperf-rapid-expire(httperf): Out of bounds: client_req(74790) less than lower boundary 989840
2012-06-07 21:37:17 [1, 0]: httperf-rapid-expire(httperf): Load: 23:37:17 up 7 days, 10:00, 3 users, load average: 0.84, 0.78, 0.78
2012-06-07 21:37:17 [1, 0]: httperf-rapid-expire(httperf): Test name: httperf-rapid-expire
2012-06-07 21:37:17 [1, 0]: httperf-rapid-expire(httperf): Varnish options:
2012-06-07 21:37:17 [1, 0]: httperf-rapid-expire(httperf): -t=2
2012-06-07 21:37:17 [1, 0]: httperf-rapid-expire(httperf): Varnish parameters:
2012-06-07 21:37:17 [1, 0]: httperf-rapid-expire(httperf): thread_stats_rate=1
2012-06-07 21:37:17 [1, 0]: httperf-rapid-expire(httperf): Payload size (excludes headers): 256
2012-06-07 21:37:17 [1, 0]: httperf-rapid-expire(httperf): Branch: master
2012-06-07 21:37:17 [1, 0]: httperf-rapid-expire(httperf): Number of clients involved: 24
2012-06-07 21:37:17 [1, 0]: httperf-rapid-expire(httperf): Type of test: httperf
2012-06-07 21:37:17 [1, 0]: httperf-rapid-expire(httperf): Test iterations: 1
2012-06-07 21:37:17 [1, 0]: httperf-rapid-expire(httperf): Runtime: 62 seconds
2012-06-07 21:37:17 [1, 0]: httperf-rapid-expire(httperf): VCL:
backend foo {
.host = "localhost";
.port = "80";
}
sub vcl_fetch {
set beresp.do_stream = true;
}
2012-06-07 21:37:17 [1, 0]: httperf-rapid-expire(httperf): Number of total connections: 100000
2012-06-07 21:37:17 [1, 0]: httperf-rapid-expire(httperf): Note: connections are subject to rounding when divided among clients. Expect slight deviations.
2012-06-07 21:37:17 [1, 0]: httperf-rapid-expire(httperf): Requests per connection: 10
2012-06-07 21:37:17 [1, 0]: httperf-rapid-expire(httperf): Extra options to httperf: --wset=100,0.30
2012-06-07 21:37:17 [1, 0]: httperf-rapid-expire(httperf): Httperf command (last client): httperf --hog --timeout 60 --num-calls 10 --num-conns 4166 --port 8080 --burst-length 10 --client 23/24 --server 10.20.100.12 --wset=100,0.30
2012-06-07 21:37:24 [2, 6]: streaming-grace(httperf): Starting test
2012-06-07 21:40:18 [2,173]: cold-default(httperf): Starting test
2012-06-07 21:43:28 WARNING [0,189]: cold-default(httperf): Panic detected. I think!
2012-06-07 21:43:28 WARNING [0, 0]: cold-default(httperf):
Last panic at: Thu, 07 Jun 2012 21:42:16 GMT
Assert error in VCL_recv_method(), ../../include/tbl/vcl_returns.h line 27:
Condition((req->sp) != NULL) not true.
thread = (cache-worker)
ident = Linux,2.6.32-38-generic,x86_64,-smalloc,-smalloc,-hcritbit,epoll
Backtrace:
0x431d88: pan_ic+d8
0x43a3b5: VCL_recv_method+1a5
0x4164c5: cnt_recv+1e5
0x41ae1d: CNT_Session+57d
0x43670d: ses_pool_task+fd
0x433592: Pool_Work_Thread+112
0x441128: wrk_thread_real+c8
0x7f22f563a9ca: _end+7f22f4fb6202
0x7f22f5397cdd: _end+7f22f4d13515
sp = 0x7f22ddef7820 {
fd = 29, id = 29, xid = 1248233599,
client = 10.20.100.9 6152,
step = STP_RECV,
handling = deliver,
restarts = 0, esi_level = 0
ws = 0x7f22e5f64158 {
id = "req",
{s,f,r,e} = {0x7f22e5f65730,+256,(nil),+59632},
},
http[req] = {
ws = 0x7f22e5f64158[req]
"GET",
"/0/2/9/8/2/0/5.html",
"HTTP/1.1",
"User-Agent: httperf/0.9.0",
"Host: 10.20.100.12",
},
worker = 0x7f22e738cc60 {
ws = 0x7f22e738ce20 {
id = "wrk",
{s,f,r,e} = {0x7f22e738c450,0x7f22e738c450,(nil),+2048},
},
},
vcl = {
srcname = {
"input",
"Default",
},
},
},
2012-06-07 21:43:28 WARNING [0, 0]: cold-default(httperf): Varnishstat uptime and measured run-time is too large (measured: 185 stat: 70 diff: 115). Did we crash?
2012-06-07 21:46:55 WARNING [0,207]: cold-default(httperf): Panic detected. I think!
2012-06-07 21:46:55 WARNING [0, 0]: cold-default(httperf):
Last panic at: Thu, 07 Jun 2012 21:45:35 GMT
Assert error in VCL_recv_method(), ../../include/tbl/vcl_returns.h line 27:
Condition((req->sp) != NULL) not true.
thread = (cache-worker)
ident = Linux,2.6.32-38-generic,x86_64,-smalloc,-smalloc,-hcritbit,epoll
Backtrace:
0x431d88: pan_ic+d8
0x43a3b5: VCL_recv_method+1a5
0x4164c5: cnt_recv+1e5
0x41ae1d: CNT_Session+57d
0x43670d: ses_pool_task+fd
0x433592: Pool_Work_Thread+112
0x441128: wrk_thread_real+c8
0x7f22f563a9ca: _end+7f22f4fb6202
0x7f22f5397cdd: _end+7f22f4d13515
sp = 0x7f22d7b77a20 {
fd = 27, id = 27, xid = 1684671673,
client = 10.20.100.9 6490,
step = STP_RECV,
handling = deliver,
restarts = 0, esi_level = 0
ws = 0x7f22e288d158 {
id = "req",
{s,f,r,e} = {0x7f22e288e730,+256,(nil),+59632},
},
http[req] = {
ws = 0x7f22e288d158[req]
"GET",
"/0/3/1/0/5/6/6.html",
"HTTP/1.1",
"User-Agent: httperf/0.9.0",
"Host: 10.20.100.12",
},
worker = 0x7f22e775cc60 {
ws = 0x7f22e775ce20 {
id = "wrk",
{s,f,r,e} = {0x7f22e775c450,0x7f22e775c450,(nil),+2048},
},
},
vcl = {
srcname = {
"input",
"Default",
},
},
},
2012-06-07 21:46:55 WARNING [0, 0]: cold-default(httperf): Varnishstat uptime and measured run-time is too large (measured: 393 stat: 80 diff: 313). Did we crash?
2012-06-07 21:46:56 WARNING [0, 0]: cold-default(httperf): Out of bounds: uptime(80) less than lower boundary 100
2012-06-07 21:46:56 WARNING [0, 0]: cold-default(httperf): Out of bounds: client_req(102010) less than lower boundary 1589840
2012-06-07 21:46:56 [1, 0]: cold-default(httperf): Load: 23:46:56 up 7 days, 10:09, 3 users, load average: 0.67, 0.78, 0.79
2012-06-07 21:46:56 [1, 0]: cold-default(httperf): Test name: cold-default
2012-06-07 21:46:56 [1, 0]: cold-default(httperf): Varnish options:
2012-06-07 21:46:56 [1, 0]: cold-default(httperf): -t=3600
2012-06-07 21:46:56 [1, 0]: cold-default(httperf): -s=malloc,10G
2012-06-07 21:46:56 [1, 0]: cold-default(httperf): Varnish parameters:
2012-06-07 21:46:56 [1, 0]: cold-default(httperf): thread_stats_rate=1
2012-06-07 21:46:56 [1, 0]: cold-default(httperf): Payload size (excludes headers): 256
2012-06-07 21:46:56 [1, 0]: cold-default(httperf): Branch: master
2012-06-07 21:46:56 [1, 0]: cold-default(httperf): Number of clients involved: 24
2012-06-07 21:46:56 [1, 0]: cold-default(httperf): Type of test: httperf
2012-06-07 21:46:56 [1, 0]: cold-default(httperf): Test iterations: 2
2012-06-07 21:46:56 [1, 0]: cold-default(httperf): Runtime: 393 seconds
2012-06-07 21:46:56 [1, 0]: cold-default(httperf): VCL:
backend foo {
.host = "localhost";
.port = "80";
}
sub vcl_fetch {
set beresp.do_stream = true;
}
2012-06-07 21:46:56 [1, 0]: cold-default(httperf): Number of total connections: 80000
2012-06-07 21:46:56 [1, 0]: cold-default(httperf): Note: connections are subject to rounding when divided among clients. Expect slight deviations.
2012-06-07 21:46:56 [1, 0]: cold-default(httperf): Requests per connection: 10
2012-06-07 21:46:56 [1, 0]: cold-default(httperf): Extra options to httperf: --wset=4000000,0.50
2012-06-07 21:46:56 [1, 0]: cold-default(httperf): Httperf command (last client): httperf --hog --timeout 60 --num-calls 10 --num-conns 3333 --port 8080 --burst-length 10 --client 23/24 --server 10.20.100.12 --wset=4000000,0.50
2012-06-07 21:47:03 [2, 6]: 4gpluss-nogzip(httperf): Starting test
2012-06-07 21:47:06 WARNING [0, 2]: Varnish failed to start. Fallback attempts starting
2012-06-07 21:47:06 [1, 0]: Removed (hopefully incompatible) parameter to try to start varnish. Key: thread_stats_rate=1
2012-06-07 21:47:06 [1, 0]: Removed (hopefully incompatible) parameter to try to start varnish. Key: thread_pool_max=300
2012-06-07 21:47:12 [1, 5]: Removed (hopefully incompatible) parameter to try to start varnish. Key: sess_timeout=60000s
2012-06-07 21:47:12 [1, 0]: Fallback worked. Parameter that seemed to cause problems: sess_timeout
2012-06-07 22:08:44 [2,1292]: purge-fail(httperf): Starting test
2012-06-07 22:11:59 WARNING [0,194]: purge-fail(httperf): Panic detected. I think!
2012-06-07 22:11:59 WARNING [0, 0]: purge-fail(httperf):
Last panic at: Thu, 07 Jun 2012 22:11:05 GMT
Assert error in VCL_deliver_method(), ../../include/tbl/vcl_returns.h line 60:
Condition((req->sp) != NULL) not true.
thread = (cache-worker)
ident = Linux,2.6.32-38-generic,x86_64,-smalloc,-smalloc,-hcritbit,epoll
Backtrace:
0x431d88: pan_ic+d8
0x439695: VCL_deliver_method+1a5
0x419729: cnt_prepresp+269
0x41ac6d: CNT_Session+3cd
0x43670d: ses_pool_task+fd
0x433592: Pool_Work_Thread+112
0x441128: wrk_thread_real+c8
0x7f5467c909ca: _end+7f546760c202
0x7f54679edcdd: _end+7f5467369515
sp = 0x7f5459c0cf20 {
fd = 21, id = 21, xid = 1023564448,
client = 10.20.100.7 23874,
step = STP_PREPRESP,
handling = deliver,
restarts = 0, esi_level = 0
ws = 0x7f545ae7a158 {
id = "req",
{s,f,r,e} = {0x7f545ae7b730,+224,(nil),+59632},
},
http[req] = {
ws = 0x7f545ae7a158[req]
"PURGE",
"/foo",
"HTTP/1.1",
"User-Agent: httperf/0.9.0",
"Host: 10.20.100.12",
},
http[resp] = {
ws = 0x7f545ae7a158[req]
"HTTP/1.1",
"Not in cache but not confusing httperf",
"Server: Varnish",
"Content-Type: text/html; charset=utf-8",
"Retry-After: 5",
"Content-Length: 476",
"Accept-Ranges: bytes",
"Date: Thu, 07 Jun 2012 22:11:05 GMT",
"X-Varnish: 1023564448",
"Age: 0",
"Via: 1.1 varnish",
"Connection: close",
},
worker = 0x7f5459090c60 {
ws = 0x7f5459090e20 {
id = "wrk",
{s,f,r,e} = {0x7f5459090450,0x7f5459090450,(nil),+2048},
},
},
vcl = {
srcname = {
"input",
"Default",
},
},
obj = 0x7f545e272000 {
xid = 1023564448,
ws = 0x7f545e272018 {
id = "obj",
{s,f,r,e} = {0x7f545e272548,+176,(nil),+32768},
},
http[obj] = {
ws = 0x7f545e272018[obj]
"HTTP/1.1",
"Not in cache but not confusing httperf",
"Date: Thu, 07 Jun 2012 22:11:05 GMT",
"Server: Varnish",
"Content-Type: text/html; charset=utf-8",
"Retry-After: 5",
"Content-Length: 476",
},
len = 476,
store = {
476 {
0a 3c 3f 78 6d 6c 20 76 65 72 73 69 6f 6e 3d 22 |.<?xml version="|
31 2e 30 22 20 65 6e 63 6f 64 69 6e 67 3d 22 75 |1.0" encoding="u|
74 66 2d 38 22 3f 3e 0a 3c 21 44 4f 43 54 59 50 |tf-8"?>.<!DOCTYP|
45 20 68 74 6d 6c 20 50 55 42 4c 49 43 20 22 2d |E html PUBLIC "-|
[412 more]
},
},
},
},
2012-06-07 22:11:59 WARNING [0, 0]: purge-fail(httperf): Varnishstat uptime and measured run-time is too large (measured: 190 stat: 53 diff: 137). Did we crash?
2012-06-07 22:12:00 WARNING [0, 0]: purge-fail(httperf): Out of bounds: client_req(30053) less than lower boundary 290000
2012-06-07 22:12:00 [1, 0]: purge-fail(httperf): Load: 00:12:00 up 7 days, 10:34, 3 users, load average: 0.38, 0.55, 1.00
2012-06-07 22:12:00 [1, 0]: purge-fail(httperf): Test name: purge-fail
2012-06-07 22:12:00 [1, 0]: purge-fail(httperf): Varnish options:
2012-06-07 22:12:00 [1, 0]: purge-fail(httperf): Varnish parameters:
2012-06-07 22:12:00 [1, 0]: purge-fail(httperf): thread_stats_rate=1
2012-06-07 22:12:00 [1, 0]: purge-fail(httperf): Payload size (excludes headers): 1K
2012-06-07 22:12:00 [1, 0]: purge-fail(httperf): Branch: master
2012-06-07 22:12:00 [1, 0]: purge-fail(httperf): Number of clients involved: 24
2012-06-07 22:12:00 [1, 0]: purge-fail(httperf): Type of test: httperf
2012-06-07 22:12:00 [1, 0]: purge-fail(httperf): Test iterations: 1
2012-06-07 22:12:00 [1, 0]: purge-fail(httperf): Runtime: 190 seconds
2012-06-07 22:12:00 [1, 0]: purge-fail(httperf): VCL:
backend foo {
.host = "localhost";
.port = "80";
}
sub vcl_recv {
if (!req.url ~ "/0/0.html") {
set req.request = "PURGE";
}
set req.url = "/foo";
return (lookup);
}
sub vcl_hit {
if (req.request == "PURGE") {
set obj.ttl = 0s;
error 200 "OK";
}
}
sub vcl_miss {
if (req.request == "PURGE") {
error 200 "Not in cache but not confusing httperf";
}
}
2012-06-07 22:12:00 [1, 0]: purge-fail(httperf): Number of total connections: 300000
2012-06-07 22:12:00 [1, 0]: purge-fail(httperf): Note: connections are subject to rounding when divided among clients. Expect slight deviations.
2012-06-07 22:12:00 [1, 0]: purge-fail(httperf): Requests per connection: 1
2012-06-07 22:12:00 [1, 0]: purge-fail(httperf): Extra options to httperf: --wset=999,0.5 --timeout=5
2012-06-07 22:12:00 [1, 0]: purge-fail(httperf): Httperf command (last client): httperf --hog --timeout 60 --num-calls 1 --num-conns 12500 --port 8080 --burst-length 10 --client 23/24 --server 10.20.100.12 --wset=999,0.5 --timeout=5
2012-06-07 22:12:07 [2, 6]: streaming-gzip(httperf): Starting test
2012-06-07 22:14:43 WARNING [0,155]: Tests finished with problems detected. Failed expectations: 15 Total run time: 9762 seconds
More information about the varnish-test
mailing list