Experimental-ims branch tested: [Fryer] FAIL. 22 of 24 tests succeeded.

Thu Sep 1 11:35:12 CEST 2011

The branch mostly survives. No crashes.

However, two tests are failing. A test designed to stress rapid expiry
and one that tests rapid ttl=0s - so in this case it's probably
triggering the same bug.

The default VCL used (err, the fryer-default, not varnish-default) sets
beresp.do_stream = true, so unless a test explicitly disables it or
overrides the VCL, all the tests are run with that set.

I ran the rapid-expiry test with do_stream = false to check if that was
the issue. Disabling do_stream improved the result - the expected amount
of requests were received - but it still gave hitpass. When I
investigated the varnishlog with do_stream=true, it showed Stream
Error's. It also verified hitpass, though there was no reason that this
traffic should cause a hitpass.

As this is also a bit of a test on fryer (the below mail will be sent to
a public list of some sort soon-ish, instead of to myself) I will resist
explaining in detail what every test does - unless asked (do ask -
anyone!).

Grab a hold on me on IRC or mail if you want me to re-test or test with
some specific vcl or parameter, and I'll set it up.

- Kristian
PS: For the record: Master passes all of them, though the 4g-ones are
    not properly measuring the traffic due to s_bodybytes issues.

----- Forwarded message from kristian at oneiros.varnish-software.com -----

Date: Thu,  1 Sep 2011 00:12:45 +0200 (CEST)
From: kristian at oneiros.varnish-software.com
To: kristian at varnish-software.com
Subject: [Fryer] FAIL. 22 of 24 tests succeeded.

Tests Failed: httperf-rapid-expire purge-fail

Tests OK: httperf-lru-default httperf-lru-stream-nogzip 4gpluss-nostream 4gpluss-stream 4gpluss-nogzip cold-default basic-fryer cold-gzip httperf-lru-nostream-gzip streaming cold-nogzip streaming-gzip httperf-lru-nostream-nogzip 4gpluss httperf-hot memleak sky-misc httperf-lru-stream-gzip httperf-lru-nostream-default streaming-grace siege-test httperf-lru-stream-default

2011-08-31 19:15:56 [1,20]: Server tristran checked out varnish-3.0.0-beta2-221-g71ee192 of branch experimental-ims
2011-08-31 19:17:16 [2,80]: httperf-lru-default(httperf): Starting test
2011-08-31 19:20:32 [2,195]: httperf-lru-stream-nogzip(httperf): Starting test
2011-08-31 19:23:47 [2,194]: 4gpluss-nostream(httperf): Starting test
2011-08-31 19:45:16 [2,1289]: 4gpluss-stream(httperf): Starting test
2011-08-31 20:06:37 [2,1280]: 4gpluss-nogzip(httperf): Starting test
2011-08-31 20:50:27 [2,2630]: cold-default(httperf): Starting test
2011-08-31 20:54:40 [2,253]: basic-fryer(httperf): Starting test
2011-08-31 20:55:00 [2,20]: cold-gzip(httperf): Starting test
2011-08-31 20:59:24 [2,263]: httperf-lru-nostream-gzip(httperf): Starting test
2011-08-31 21:02:37 [2,192]: streaming(httperf): Starting test
2011-08-31 21:05:23 [2,166]: cold-nogzip(httperf): Starting test
2011-08-31 21:09:07 [2,223]: streaming-gzip(httperf): Starting test
2011-08-31 21:11:50 [2,162]: httperf-lru-nostream-nogzip(httperf): Starting test
2011-08-31 21:14:50 [2,180]: 4gpluss(httperf): Starting test
2011-08-31 21:35:30 [2,1240]: httperf-hot(httperf): Starting test
2011-08-31 21:37:21 [2,110]: memleak(httperf): Starting test
2011-08-31 21:48:30 [2,669]: sky-misc(httperf): Starting test
2011-08-31 21:54:14 [2,343]: httperf-lru-stream-gzip(httperf): Starting test
2011-08-31 21:57:40 [2,206]: httperf-lru-nostream-default(httperf): Starting test
2011-08-31 22:01:07 [2,206]: httperf-rapid-expire(httperf): Starting test
2011-08-31 22:02:51 WARNING [0,104]: httperf-rapid-expire(httperf): Out of bounds: client_req(123737) less than lower boundary 999640
2011-08-31 22:02:51 WARNING [0, 0]: httperf-rapid-expire(httperf): Out of bounds: cache_hitpass(97376) more than upper boundary 0
2011-08-31 22:02:52 [1, 0]: httperf-rapid-expire(httperf): Load:  00:02:52 up 28 days, 12:18,  2 users,  load average: 2.05, 9.29, 11.92

2011-08-31 22:02:52 [1, 0]: httperf-rapid-expire(httperf): Test name: httperf-rapid-expire
2011-08-31 22:02:52 [1, 0]: httperf-rapid-expire(httperf): Varnish options: 
2011-08-31 22:02:52 [1, 0]: httperf-rapid-expire(httperf): -t=2
2011-08-31 22:02:52 [1, 0]: httperf-rapid-expire(httperf): Varnish parameters: 
2011-08-31 22:02:52 [1, 0]: httperf-rapid-expire(httperf): Payload size (excludes headers): 256
2011-08-31 22:02:52 [1, 0]: httperf-rapid-expire(httperf): Branch: experimental-ims
2011-08-31 22:02:52 [1, 0]: httperf-rapid-expire(httperf): Number of clients involved: 24
2011-08-31 22:02:52 [1, 0]: httperf-rapid-expire(httperf): Type of test: httperf
2011-08-31 22:02:52 [1, 0]: httperf-rapid-expire(httperf): Test iterations: 1
2011-08-31 22:02:52 [1, 0]: httperf-rapid-expire(httperf): Runtime: 98 seconds
2011-08-31 22:02:52 [1, 0]: httperf-rapid-expire(httperf): VCL: 
backend foo {
	.host = "localhost";
	.port = "80";
}

sub vcl_fetch {
	set beresp.do_stream = true;
}

2011-08-31 22:02:52 [1, 0]: httperf-rapid-expire(httperf): Number of total connections: 100000
2011-08-31 22:02:52 [1, 0]: httperf-rapid-expire(httperf): Note: connections are subject to rounding when divided among clients. Expect slight deviations.
2011-08-31 22:02:52 [1, 0]: httperf-rapid-expire(httperf): Requests per connection: 10
2011-08-31 22:02:52 [1, 0]: httperf-rapid-expire(httperf): Extra options to httperf: --wset=100,0.30
2011-08-31 22:02:52 [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.4 --wset=100,0.30
2011-08-31 22:02:59 [2, 7]: purge-fail(httperf): Starting test
2011-08-31 22:05:22 WARNING [0,142]: purge-fail(httperf): Out of bounds: cache_hitpass(243398) more than upper boundary 0
2011-08-31 22:05:23 [1, 0]: purge-fail(httperf): Load:  00:05:23 up 28 days, 12:21,  2 users,  load average: 2.00, 6.68, 10.56

2011-08-31 22:05:23 [1, 0]: purge-fail(httperf): Test name: purge-fail
2011-08-31 22:05:23 [1, 0]: purge-fail(httperf): Varnish options: 
2011-08-31 22:05:23 [1, 0]: purge-fail(httperf): -w=5,100
2011-08-31 22:05:23 [1, 0]: purge-fail(httperf): Varnish parameters: 
2011-08-31 22:05:23 [1, 0]: purge-fail(httperf): Payload size (excludes headers): 1K
2011-08-31 22:05:23 [1, 0]: purge-fail(httperf): Branch: experimental-ims
2011-08-31 22:05:23 [1, 0]: purge-fail(httperf): Number of clients involved: 24
2011-08-31 22:05:23 [1, 0]: purge-fail(httperf): Type of test: httperf
2011-08-31 22:05:23 [1, 0]: purge-fail(httperf): Test iterations: 1
2011-08-31 22:05:23 [1, 0]: purge-fail(httperf): Runtime: 136 seconds
2011-08-31 22:05:23 [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";
	}
}

2011-08-31 22:05:23 [1, 0]: purge-fail(httperf): Number of total connections: 300000
2011-08-31 22:05:23 [1, 0]: purge-fail(httperf): Note: connections are subject to rounding when divided among clients. Expect slight deviations.
2011-08-31 22:05:23 [1, 0]: purge-fail(httperf): Requests per connection: 1
2011-08-31 22:05:23 [1, 0]: purge-fail(httperf): Extra options to httperf: --wset=999,0.5 --timeout=5
2011-08-31 22:05:23 [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.4 --wset=999,0.5 --timeout=5
2011-08-31 22:05:30 [2, 7]: streaming-grace(httperf): Starting test
2011-08-31 22:08:16 [2,166]: siege-test(siege): Starting test
2011-08-31 22:09:31 [2,74]: httperf-lru-stream-default(httperf): Starting test
2011-08-31 22:12:45 WARNING [0,193]: Tests finished with problems detected. Failed expectations: 2 Total run time: 10630 seconds

----- End forwarded message -----
-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 490 bytes
Desc: Digital signature
URL: <https://www.varnish-cache.org/lists/pipermail/varnish-dev/attachments/20110901/3d8aa107/attachment-0003.pgp>