Updated Home (markdown)

Home.md

@@ -48,6 +48,54 @@ Access Token:\<click to reveal\>
 
 \<room-alias\> - the room alias, eg. #my_room:matrix.org this possibly needs to be URL encoded also, for example  %23my_room%3Amatrix.org
 
+How can I find the lines corresponding to a given HTTP request in my homeserver log?
+---
+
+Synapse tags each log line according to the HTTP request it is processing. When it first receives a request, it logs a line containing the words `Received request: `. For example:
+
+```
+2019-02-14 22:35:08,022 - synapse.access.http.8008 - 233 - INFO - GET-37 - ::1 - 8008 - Received request: GET /_matrix/client/r0/sync
+```
+
+Once it finishes processing the request, it logs another line with the words `Processed request: `. For example:
+
+```
+2019-02-14 22:35:08,196 - synapse.access.http.8008 - 302 - INFO - GET-37 - ::1 - 8008 - {@richvdh:localhost} Processed request: 0.173sec/0.001sec (0.002sec, 0.000sec) (0.027sec/0.026sec/2) 687B 200 "GET /_matrix/client/r0/sync HTTP/1.1" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/69.0.3497.100 Safari/537.36" [0 dbevts]"
+```
 
+Here we can see that the request has been tagged with `GET-37`. (The tag depends on the method of the HTTP request, so might start with `GET-`, `PUT-`, `POST-`, `OPTIONS-` or `DELETE-`.) So to find all lines corresponding to this request, we can do:
 
+```
+grep 'GET-37 ' homeserver.log
+```
+
+If you want to paste that output into a github issue, please remember to surround it with triple-backticks (```) to make it legible (see https://help.github.com/en/articles/basic-writing-and-formatting-syntax#quoting-code).
+
+
+What do all those fields in the 'Processed' line mean?
+---
 
+The log format can vary slightly depending on your log configuration, but here is a breakdown of the example above:
+
+* `2019-02-14 22:35:08,196`: date/time when we finished processing the request
+* `synapse.access.http.8008`: logger name. For 'Received'/'Processed' lines, the logger name is `synapse.access.http.` plus the TCP port that the request came in on
+* `302`: the line number where the request was logged. Useless for 'Received'/'Processed' lines.
+* `INFO`: the log level. Always `INFO` for 'Received'/'Processed' lines. 
+* `GET-37`: the request tag
+* `::1`: the client IP address
+* `8008`: the TCP port where the request came in (again)
+* `{@richvdh:localhost}`: if the request came from an authenticated user or server, their user id or server_name.
+* `Processed request:`
+* `0.173sec/0.001sec`:
+  * time between the request arriving and synapse finishing its processing of it (the "processing time").
+  * time between synapse finishing its processing of the request and the response being sent to the client: ie, the time taken to stream the response to the client. Note that this may be negative if the client dropped the connection before synapse finished processing the request.
+* `(0.002sec, 0.000sec)`: user- and system- cpu time spent processing this request.
+* `(0.027sec/0.026sec/2)`:
+  * time spent waiting for a connection to the database during this request (the "database scheduling time"). (Note that this may be higher than the request processing time, since synapse may make several database requests in parallel, each of which contributes to this scheduling time.)
+  * time spent running database transactions, excluding scheduling time (the "database transaction time"). (Again, may be higher than the request processing time).
+  * the number of database transactions performed.
+* `687B`: the length of the response body (687 bytes, in this case).
+* `200`: the HTTP response code.
+* `"GET /_matrix/client/r0/sync HTTP/1.1"`: the http request line, including the path of the requested url.
+* `"Mozilla/5.0 ..."`: the user-agent of the client. 
+* `[0 dbevts]`: the number of Matrix events which were fetched from the database to fulfil this request.