[master] 7b5ee1a Timestamp documentation

[Martin Blix Grydeland]

commit 7b5ee1a64c41dbe0044a74a6a9ea562309a28f04
Author: Martin Blix Grydeland <martin at varnish-software.com>
Date:   Tue Mar 25 16:28:58 2014 +0100

    Timestamp documentation

diff --git a/doc/sphinx/reference/vsl.rst b/doc/sphinx/reference/vsl.rst
index 78c3456..36d51bd 100644
--- a/doc/sphinx/reference/vsl.rst
+++ b/doc/sphinx/reference/vsl.rst
@@ -20,6 +20,83 @@ VSL tags
 
 .. include:: ../../../lib/libvarnishapi/vsl-tags.rst
 
+TIMESTAMPS
+==========
+
+Timestamps are inserted in the log on completing certain events during
+the worker thread's task handling. The timestamps has a label showing
+which event was completed. The reported fields show the absolute time
+of the event, the time spent since the start of the task and the time
+spent since the last timestamp was logged.
+
+The timestamps logged automatically by Varnish are inserted after
+completing events that are expected to have delays (e.g. network IO or
+spending time on a waitinglist). Timestamps can also be inserted from
+VCL using the std.timestamp() method. If one is doing time consuming
+tasks in the VCL configuration, it's a good idea to log a timestamp
+after completing that task. This keeps the timing information in
+subsequent timestamps from including the time spent on the VCL event.
+
+Request handling timestamps
+~~~~~~~~~~~~~~~~~~~~~~~~~~~
+
+Start
+	The start of request processing (first byte received or
+	restart).
+
+Req
+	Complete client request received.
+
+ReqBody
+	Client request body processed (discarded, cached or passed to
+	the backend).
+
+Waitinglist
+	Came off waitinglist.
+
+Fetch
+	Fetch processing finished (completely fetched or ready for
+	streaming).
+
+Process
+	Processing finished, ready to deliver the client response.
+
+Resp
+	Delivery of response to the client finished.
+
+Restart
+	Client request is being restarted.
+
+Pipe handling timestamps
+~~~~~~~~~~~~~~~~~~~~~~~~
+
+Pipe
+	Opened a pipe to the backend and forwarded the request.
+
+PipeSess
+	The pipe session has finished.
+
+Backend fetch timestamps
+~~~~~~~~~~~~~~~~~~~~~~~~
+
+Start
+	Start of the backend fetch processing.
+
+Bereq
+	Backend request sent.
+
+Beresp
+	Backend response headers received.
+
+BerespBody
+	Backend response body received.
+
+Retry
+	Backend request is being retried.
+
+Error
+	Backend request failed to vcl_error.
+
 
 HISTORY
 =======
diff --git a/include/tbl/vsl_tags.h b/include/tbl/vsl_tags.h
index 34c5c13..0f50a48 100644
--- a/include/tbl/vsl_tags.h
+++ b/include/tbl/vsl_tags.h
@@ -468,7 +468,8 @@ SLTM(Timestamp, 0, "Timing information",
 	"Time stamps are issued by Varnish on certain events,"
 	" and show the absolute time of the event, the time spent since the"
 	" start of the work unit, and the time spent since the last timestamp"
-	" was logged.\n\n"
+	" was logged. See vsl(7) for information about the individual"
+	" timestamps.\n\n"
 	"The format is::\n\n"
 	"\t%s: %f %f %f\n"
 	"\t|   |  |  |\n"