On-demand Request Tracing
Gerrit supports on-demand tracing of single requests that results in
additional logs with debug information that are written to the
error_log. The logs that correspond to a traced request are
associated with a unique trace ID. This trace ID is returned with the
response and can be used by an administrator to find the matching log
How tracing is enabled and how the trace ID is returned depends on the request type:
REST API: For REST calls tracing can be enabled by setting the
tracerequest parameter or the
X-Gerrit-Traceheader, the trace ID is returned as
X-Gerrit-Traceheader. More information about this can be found in the Request Tracing section of the REST API documentation.
SSH API: For SSH calls tracing can be enabled by setting the
--traceoption. More information about this can be found in the Trace section of the SSH command documentation.
Git Push (requires usage of git protocol v2): For Git pushes tracing can be enabled by setting the
tracepush option, the trace ID is returned in the command output. More information about this can be found in the Trace section of the upload documentation.
Git Clone/Fetch/Ls-Remote (requires usage of git protocol v2): For Git clone/fetch/ls-remote tracing can be enabled by setting the
traceserver option. Use '-o trace=<TRACE-ID>' for
git ls-remote, and '--server-option trace=<TRACE-ID>' for
git clone. If the
traceserver option is set without a value (without trace ID) a trace ID is generated but the generated trace ID is not returned to the client (hence a trace ID should always be set).
When request tracing is enabled it is possible to provide an ID that should be used as trace ID. If a trace ID is not provided a trace ID is automatically generated. The trace ID must be provided to the support team (administrator of the server) so that they can find the trace.
When doing traces it is recommended to specify the ID of the issue that is being investigated as trace ID so that the traces of the issue can be found more easily. When the issue ID is used as trace ID there is no need to find the generated trace ID and report it in the issue.
Since tracing consumes additional server resources tracing should only be enabled for single requests if there is a concrete need for debugging. In particular bots should never enable tracing for all their requests by default.
Automatic Request Tracing
Gerrit can be configured to automatically retry requests on non-recoverable failures with tracing enabled. This allows to automatically captures traces of these failures for further analysis by the Gerrit administrators.
The auto-retry on failure behaves the same way as if the calling user would retry the failed operation with tracing enabled.
It is expected that the auto-retry fails with the same exception that triggered the auto-retry, however this is not guaranteed:
Not all Gerrit operations are fully atomic and it can happen that some parts of the operation have been successfully performed before the failure happened. In this case the auto-retry may fail with a different exception.
Some exceptions may mistakenly be considered as non-recoverable and the auto-retry actually succeeds.
If an auto-retry succeeds you may consider filing this as Gerrit issue so that the Gerrit developers can fix this and treat this exception as recoverable.
The trace IDs for auto-retries are generated and start with
retry-on-failure-. For REST requests they are returned to the client
The best way to search for auto-retries in logs is to do a grep by
AutoRetry. For each auto-retry that happened this should match 1 or 2
FINElog entry with the exception that triggered the auto-retry
FINElog entry with the exception that happened on auto-retry (if this log entry is not present the operation succeeded on auto-retry)
To inspect single auto-retry occurrences in detail you can do a
grep by the trace ID. The trace ID is part of the log
entries which have been found by the previous grep (watch out for
|Auto-retrying on failures is only supported by some of the REST endpoints (change REST endpoints that perform updates).|
If auto-retry is enabled the following metrics are reported:
action/auto_retry_count: Number of automatic retries with tracing
action/failures_on_auto_retry_count: Number of failures on auto retry
By comparing the values of these counters one can see how often the auto-retry succeeds. As explained above if auto-retries succeed that’s an issue with Gerrit that you may want to report.
Find log entries for a trace ID
If tracing is enabled all log messages that correspond to the traced
request have a
TRACE_ID tag set, e.g.:
[2018-08-13 15:28:08,913] [HTTP-76] TRACE com.google.gerrit.httpd.restapi.RestApiServlet : Received REST request: GET /a/accounts/self (parameters: [trace]) [CONTEXT forced=true TRACE_ID="1534166888910-3985dfba" ] [2018-08-13 15:28:08,914] [HTTP-76] TRACE com.google.gerrit.httpd.restapi.RestApiServlet : Calling user: admin [CONTEXT forced=true TRACE_ID="1534166888910-3985dfba" ] [2018-08-13 15:28:08,942] [HTTP-76] TRACE com.google.gerrit.httpd.restapi.RestApiServlet : REST call succeeded: 200 [CONTEXT forced=true TRACE_ID="1534166888910-3985dfba" ]
By doing a grep with the trace ID over the error log the log entries that correspond to the request can be found.
|Usually only server administrators have access to the logs.|
Which information is captured in a trace?
REST API: request URL, request parameter names, calling user, response code, response body on errors
SSH API: parameter names
Git API: push options, magic branch parameter names
cache misses, cache evictions
reads from NoteDb, writes to NoteDb
reads of meta data files, writes of meta data files
index queries (with parameters and matches)
permission checks (e.g. which rule is responsible for a deny)
all other logs
Part of Gerrit Code Review