vsl: New Timestamp:Connected for backend tasks

Depending on the settings, a timeout can be ambiguous. It's also
generally useful to be able to tell how long it takes, monitor it
and possibly notice a degradation before errors start manifesting
themselves.

bin/varnishd/cache/cache_backend.c

@@ -168,6 +168,7 @@ vbe_dir_getfd(VRT_CTX, struct worker *wrk, struct backend *bp,
 		return (NULL);
 	}
 
+	VSLb_ts_busyobj(bo, "Connected", W_TIM_real(wrk));
 	fdp = PFD_Fd(pfd);
 	AN(fdp);
 	assert(*fdp >= 0);

bin/varnishtest/tests/c00036.vtc

@@ -20,6 +20,7 @@ varnish v1 -vcl+backend {
 
 logexpect l1 -v v1 -q "vxid == 1004" {
 	expect * 1004 VCL_return      {^fetch}
+	expect 0 1004 Timestamp       {^Connected:}
 	expect 0 1004 BackendOpen     {^\d+ s1}
 	expect 0 1004 Timestamp       {^Bereq:}
 
@@ -27,6 +28,7 @@ logexpect l1 -v v1 -q "vxid == 1004" {
 	# backend goes away on a keepalive TCP connection:
 	expect 0 1004 FetchError      {^HTC eof .-1.}
 	expect 0 1004 BackendClose    {^\d+ s1}
+	expect 0 1004 Timestamp       {^Connected:}
 	expect 0 1004 BackendOpen     {^\d+ s1}
 
 	expect 0 1004 Timestamp       {^Bereq:}

doc/sphinx/reference/vsl.rst

@@ -86,6 +86,9 @@ Backend fetch timestamps
 Start
 	Start of the backend fetch processing.
 
+Connected
+	Successfully established or reused a backend connection.
+
 Bereq
 	Backend request sent.