Debug requests

Kong Gateway admins can debug requests by collecting timing information about a given request, on demand. Request debugging is triggered using a secure token and the resulting data is returned in a response header named X-Kong-Request-Debug-Output.

Request debugging provides the following insights:

  • Time spent in various Kong Gateway components, such as plugins, DNS resolution, and load balancing.
  • Contextual information, such as the domain name tried during these processes.

Note: This feature is meant for live debugging. The JSON schema of the header containing the timing should never be considered static and is always subject to change.

Enable request debugging

Request debugging is enabled by default and has the following configurations in kong.conf:

  1. request_debug = on | off # enable or disable request debugging
  2. request_debug_token <token> # Set debug token explicitly. Otherwise, it will be generated randomly when Kong starts, restarts, and reloads.

The usage of debug token (request-debug-token) prevents abuse of the feature as only authorized personnel are able to issue debug requests.

You can find the debug token in the following locations:

  • Kong Gateway error log: The debug token is logged in the error log (notice level) when Kong Gateway starts, restarts, or reloads. The log line will have the [request-debug] prefix to aid in searching.
  • Filesystem: The debug token is also stored in a file at {prefix}/.request_debug_token and updated when Kong Gateway starts, restarts, or reloads.

Debug request configuration

To debug a request, add the following request headers:

  • At a minimum, you should set the X-Kong-Request-Debug header.
  • If the requests originate from anywhere other than the loopback addresses, the X-Kong-Request-Debug-Token header also needs to be set.

X-Kong-Request-Debug header

If the X-Kong-Request-Debug header is set to *, timing information will be collected and exported for the current request.

In Kong Gateway Enterprise, you can also specify a list of filters, separated by commas, to filter the scope of the time information that is collected. Each filters specifies which phase to collect timing information from. The following filters are supported:

  • rewrite
  • access
  • balancer
  • response
  • header_filter
  • body_filter
  • upstream
  • log

If this header isn’t present or contains an unknown value, timing information will not be collected for the current request.

X-Kong-Request-Debug-Log header

If the X-Kong-Request-Debug-Log header is set to true, timing information will also be logged in the Kong Gateway error log with a log level of notice. By default, the X-Kong-Request-Debug-Log header is set to false. The log line will have the [request-debug] prefix to aid in searching.

X-Kong-Request-Debug-Token header

The X-Kong-Request-Debug-Token is a token for authenticating the client and making the debug request to prevent abuse. Debug requests originating from loopback addresses don’t require this header.

X-Kong-Request-Id header

The X-Kong-Request-Id header contains a unique identifier for each client request. This is enabled by default both upstream and downstream. This unique ID helps in matching specific requests to their corresponding error logs, which is useful for debugging. If Kong Gateway returns an error by calling the PDK kong.response.error, the request ID will also be included in the response body generated by Kong Gateway. In addition, any Kong Gateway error log generated will contain the same request ID, with the format: request_id: xxx.

The log line produced by the debug header as well as the debug response header contains the request ID. You can use this to search for the debug header output using a log viewer UI. This is especially useful when the debug output is too long to fit in the response header. You can see an example log line that includes the Request ID in the Truncation for large debugging output debug request example.

Debug request example

The following is an example debug request:

  1. curl http://localhost:8000/example \
  2.     -H "X-Kong-Request-Debug: *" \
  3.     -H "X-Kong-Request-Debug-Token: xxxxxx"

Here’s an example of the output of the response header:

  1. {
  2.     "child": {
  3.         "rewrite": {
  4.             "total_time": 0
  5.         },
  6.         "access": {
  7.             "child": {
  8.                 "dns": {
  9.                     "child": {
  10.                         "example.com": {
  11.                             "child": {
  12.                                 "resolve": {
  13.                                     "total_time": 0,
  14.                                     "cache_hit": true
  15.                                 }
  16.                             },
  17.                             "total_time": 0
  18.                         }
  19.                     },
  20.                     "total_time": 0
  21.                 },
  22.                 "plugins": {
  23.                     "child": {
  24.                         "rate-limiting": {
  25.                             "child": {
  26.                                 "176928d4-0949-47c8-8114-19cac8f86aab": {
  27.                                     "child": {
  28.                                         "redis": {
  29.                                             "total_time": 1,
  30.                                             "child": {
  31.                                                 "connections": {
  32.                                                     "child": {
  33.                                                         "tcp://localhost:6379": {
  34.                                                             "child": {
  35.                                                                 "connect": {
  36.                                                                     "child": {
  37.                                                                         "dns": {
  38.                                                                             "child": {
  39.                                                                                 "localhost": {
  40.                                                                                     "child": {
  41.                                                                                         "resolve": {
  42.                                                                                             "total_time": 0,
  43.                                                                                             "cache_hit": true
  44.                                                                                         }
  45.                                                                                     },
  46.                                                                                     "total_time": 0
  47.                                                                                 }
  48.                                                                             },
  49.                                                                             "total_time": 0
  50.                                                                         }
  51.                                                                     },
  52.                                                                     "total_time": 0
  53.                                                                 }
  54.                                                             },
  55.                                                             "total_time": 0
  56.                                                         }
  57.                                                     },
  58.                                                     "total_time": 0
  59.                                                 }
  60.                                             }
  61.                                         }
  62.                                     },
  63.                                     "total_time": 2
  64.                                 }
  65.                             },
  66.                             "total_time": 2
  67.                         },
  68.                         "request-transformer": {
  69.                             "child": {
  70.                                 "cfd2d953-ad82-453c-9979-b7573f52c226": {
  71.                                     "total_time": 0
  72.                                 }
  73.                             },
  74.                             "total_time": 0
  75.                         }
  76.                     },
  77.                     "total_time": 2
  78.                 }
  79.             },
  80.             "total_time": 3
  81.         },
  82.         "log": {
  83.             "child": {
  84.                 "plugins": {
  85.                     "child": {
  86.                         "http-log": {
  87.                             "child": {
  88.                                 "22906259-2963-4c6d-96a1-6d36d21714e3": {
  89.                                     "total_time": 4
  90.                                 }
  91.                             },
  92.                             "total_time": 4
  93.                         }
  94.                     },
  95.                     "total_time": 4
  96.                 }
  97.             },
  98.             "total_time": 4
  99.         },
  100.         "header_filter": {
  101.             "child": {
  102.                 "plugins": {
  103.                     "child": {
  104.                         "response-transformer": {
  105.                             "child": {
  106.                                 "dee98076-a58f-490d-8f7b-8523506bf96d": {
  107.                                     "total_time": 1
  108.                                 }
  109.                             },
  110.                             "total_time": 1
  111.                         }
  112.                     },
  113.                     "total_time": 1
  114.                 }
  115.             },
  116.             "total_time": 1
  117.         },
  118.         "body_filter": {
  119.             "child": {
  120.                 "plugins": {
  121.                     "child": {
  122.                         "response-transformer": {
  123.                             "child": {
  124.                                 "dee98076-a58f-490d-8f7b-8523506bf96d": {
  125.                                     "total_time": 0
  126.                                 }
  127.                             },
  128.                             "total_time": 1
  129.                         }
  130.                     },
  131.                     "total_time": 1
  132.                 }
  133.             },
  134.             "total_time": 1
  135.         },
  136.         "balancer": {
  137.             "total_time": 0
  138.         },
  139.         "upstream": {
  140.             "total_time": 152,
  141.             "child": {
  142.                 "time_to_first_byte": {
  143.                     "total_time": 151
  144.                 },
  145.                 "streaming": {
  146.                     "total_time": 1
  147.                 }
  148.             }
  149.         }
  150.     },
  151.     "request_id": "0208903e83001d216bee5435dbc5ed25"
  152. }

If you analyze the example debug output, you can see that:

  • The unit of total_time is millisecond.
  • The DNS resolution for example.host was cached, which is why it’s so fast in the example.
  • The upstream took 100ms in this request.
    • The elapsed time from Kong Gateway sending the request to the upstream to Kong Gateway receiving the first byte is 20ms.
    • The elapsed time from the first byte to the last byte from the upstream is 80ms.

You can also filter the debug output:

  1. curl http://localhost:8000/example \
  2.     -H "X-Kong-Request-Debug: upstream" \
  3.     -H "X-Kong-Request-Debug-Token: xxxxxx"

This will return something like the following:

  1. {
  2.   "request_id": "a1a1530f8ddb6f6f2462916ae002b715",
  3.   "child": {
  4.     "upstream": {
  5.       "total_time": 363,
  6.       "child": {
  7.         "time_to_first_byte": {
  8.           "total_time": 363
  9.         }
  10.       }
  11.     }
  12.   }
  13. }

Truncation for large debugging output

The downstream system may impose a size restriction on response headers, leading Kong Gateway to truncate the X-Kong-Request-Output if it exceeds 2KB. This truncated output will be unconditionally logged in the error_log.

  1. curl http://localhost:8000/large_debugging_output \
  2.     -H "X-Kong-Request-Debug: *" \
  3.     -H "X-Kong-Request-Debug-Token: xxxxxx"

This will return something like the following:

  1. {
  2.   "request_id": "60ca0a4f8e5e936c43692f49b27d2932",
  3.   "truncated": true,
  4.   "message": "Output is truncated, please check the error_log for full output by filtering with the request_id."
  5. }

Debug request outputs that exceed 3KB are split into multiple parts with the request_id as an identifier.

Note: The debug output doesn’t have a consistent pattern and may change in the future. It wasn’t designed to be processed by automated tools. Rather, it was intended for human readability.