Also test sub-second resolution timeouts

src/tests/test02.vtc

@@ -1,21 +1,33 @@
 varnishtest "Test data timeout"
 
-server s1 {
+server s1 -repeat 3 {
 	rxreq
 	delay 2
 	txresp -hdr "Foo: bar"
 } -start
 
 varnish v1 -vcl+backend {
 	import curl from "${vmod_topbuild}/src/.libs/libvmod_curl.so";
+	import std;
+
 	sub vcl_recv {
-		curl.set_timeout(1000);
-		curl.set_connect_timeout(1000);
+		if (req.url == "/") {
+			curl.set_timeout(200);
+			curl.set_connect_timeout(200);
+		} else if (req.url == "/other") {
+			curl.set_timeout(1000);
+			curl.set_connect_timeout(1000);
+		} else {
+			curl.set_timeout(1300);
+			curl.set_connect_timeout(1300);
+		}
+		std.timestamp("curl:start");
 		curl.get("http://${s1_addr}:${s1_port}");
 		return (synth(200));
 	}
 
 	sub vcl_synth {
+		std.timestamp("curl:end");
 		set resp.http.x-status = curl.status();
 		set resp.http.x-error = curl.error();
 
@@ -26,9 +38,32 @@ varnish v1 -vcl+backend {
 	}
 } -start
 
+logexpect l1 -v v1 -g request {
+	expect * 1001	Timestamp	{curl:start: \S+ 0\.0\d+ 0\.\d+}
+	expect * =	Timestamp	{curl:end: \S+ 0\.2\d+ 0\.\d+}
+
+	expect * 1002	Timestamp	{curl:start: \S+ 0\.\d+ 0\.\d+}
+	expect * =	Timestamp	{curl:end: \S+ 1\.\d+ 0\.\d+}
+
+	expect * 1003	Timestamp	{curl:start: \S+ 0\.\d+ 0\.\d+}
+	expect * =	Timestamp	{curl:end: \S+ 1\.3\d+ 0\.\d+}
+} -start
+
 client c1 {
 	txreq -url "/"
 	rxresp
 	expect resp.http.x-status == 0
 	expect resp.http.x-error == "Timeout was reached"
+
+	txreq -url "/other"
+	rxresp
+	expect resp.http.x-status == 0
+	expect resp.http.x-error == "Timeout was reached"
+
+	txreq -url "/another"
+	rxresp
+	expect resp.http.x-status == 0
+	expect resp.http.x-error == "Timeout was reached"
 } -run
+
+logexpect l1 -wait