feat(request-id): add a request ID to logs and error templates

[samugi]

Closed in favor of #11624

Summary

Add a request ID (which matches the trace_id or correlation_id when available) to error templates and logs.

Description

Error logs are populated with a unique identifier for the request (random generated 16 Bytes hex), using a format similar to the following:

2023/07/31 18:21:23 [error] 1773198#0: *2966 [lua] some_file.lua:58: rewrite(): some log, client: 127.0.0.1, server: kong, request: "GET / HTTP/1.1", host: "localhost:8000", request_id: "c48604ca1518bcb38bb2661a155d5fff"

The ID is stored in the Nginx variable $kong_request_id and can be used in the access_log directive.

Trace ID

When available, the request ID is replaced by the current request's trace ID. Trace IDs in Kong are generated during the rewrite phase, for each request, which means that when tracing is enabled the same request may log different IDs before and after the value is updated during the rewrite phase. In addition to that, in case of distributed tracing (requests incoming to Kong contain headers with tracing information, including the trace ID), the trace ID is updated by the Opentelemetry plugin during the access phase. Whenever the Request ID is updated, a line is printed in the logs to notify about the update event, e.g.:

setting request_id to: [new_id] for the current request, request_id: "[old_id]"

Example:

Request that provides the 4bf92f3577b34da6a3ce929d0e0e4736 trace ID via a tracing header:

http :8000 traceparent:00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01

Logs:

some_file.lua:58: access(): some log (before OTEL), client: 127.0.0.1, server: kong, request: "GET / HTTP/1.1", host: "0.0.0.0:9000", request_id: "c48604ca1518bcb38bb2661a155d5fff"

request_id.lua:83 setting request_id to: '4bf92f3577b34da6a3ce929d0e0e4736' for the current request, client: 127.0.0.1, server: kong, request: "GET / HTTP/1.1", host: "0.0.0.0:9000", request_id: "c48604ca1518bcb38bb2661a155d5fff"

handler.lua:118: access(): test log after Opentelemetry, client: 127.0.0.1, server: kong, request: "GET / HTTP/1.1", host: "0.0.0.0:9000", request_id: "4bf92f3577b34da6a3ce929d0e0e4736"

Error templates always display the updated Request ID.

Testing

Error templates & logs

Start Kong using an error template that includes two placeholders for parameters, the first will be populated with the error message, the second with the request ID. The builtin fixtures can be used to test this, similarly to the following example:

KONG_ERROR_TEMPLATE_JSON=spec/fixtures/error_templates/error_template.json kong start

Request:

http :8000

Response:

{
    "custom_template_message": "no Route matched with those values",
    "request_id": "26751e2f52415e17c847e4bfb764cb66"
}

Access log

Example output:

[4bf92f3577b34da6a3ce929d0e0e4736] 127.0.0.1 - - [31/Jul/2023:18:21:24 +0200] "GET / HTTP/1.1" 200 648 "-" "HTTPie/3.2.1"

Checklist

• The Pull Request has tests
• There's an entry in the CHANGELOG
• There is a user-facing docs PR against https://github.com/Kong/docs.konghq.com - PUT DOCS PR HERE

Full changelog

• Add a request ID (which matches the trace_id or correlation_id when available) to error templates, access logs and error logs.
• Bump lua-kong-nginx-module to version 0.7.0 (needed to use the custom error log handler)
• Include request ID in log serializer output

Issue reference

KAG-2034

FTI-4837