Design a Log Format and Split Out Errors

Goal

Design the four parts of an access log — format, shape, sink and filter — one after another, and confirm how each shows up in the actual log file.

Why it matters

The access log is the only part of the observability configuration that is irreversible. Even if you realize after an incident "I should have recorded the upstream address too", it is not in the log of that incident. So the criterion for choosing a format is not taste but a question — at three in the morning, can you narrow down the cause from this one line alone. On top of that, the fact that a file sink gathers in a buffer and then empties it, what is printed in the slot where there is no value, and which level you have to write the filter at do not stick from reading documentation and only stay once you have been through them.

Steps

Start two upstreams — 8091 is ok and 8092 is fail. In /root/envd-log/log-text.yaml, put three routes, /ping (direct_response pong), /bad (cluster bad) and / (cluster good), and a file access log sink — the path is /root/envd-log/access.log and the format is %RESPONSE_CODE%|%REQ(:PATH)%|%UPSTREAM_HOST%. Start it with --file-flush-interval-msec 200 attached, request /hello once, and wait until the log is written to confirm.
Create /root/envd-log/log-wide.yaml — the log path is /root/envd-log/wide.log and the format is eight fields: %RESPONSE_CODE%|%REQ(:METHOD)%|%REQ(:PATH)%|%PROTOCOL%|%DURATION%|%UPSTREAM_HOST%|%RESPONSE_FLAGS%|%BYTES_SENT%. After you start it with that configuration, request /hello, /ping and /bad/x once each and confirm that three lines are written.
Create /root/envd-log/log-miss.yaml — the path is /root/envd-log/miss.log and the format is %RESPONSE_CODE%|%REQ(:PATH)%|%UPSTREAM_HOST%|%REQ(X-TENANT)% (the last field is the request header x-tenant). After you start it, request /ping and /hello once each without the header, and in /root/envd-log/03-missing.txt write three lines: ping_upstream= (the third field of the /ping line), ping_tenant= (the fourth field) and hello_tenant=.
Create /root/envd-log/log-json.yaml — the path is /root/envd-log/access.json, the format is json_format, and there are five keys: code, path, upstream, flags and duration_ms. After you start it, request /hello and /bad/x once each and confirm that it can be read with jq.
Create /root/envd-log/log-err.yaml — put just one sink, keep only 500 and above with filter.status_code_filter (comparison operator GE, value 500), with the path /root/envd-log/errors.json and the keys code, path, upstream and flags. After you start it, request /hello twice and /bad/x once, and in /root/envd-log/05-filter.txt write two lines: lines= (the number of lines in errors.json) and codes= (the code values of those lines, separated by spaces).
Create /root/envd-log/log-two.yaml — there are two sinks. One records all requests as text to /root/envd-log/all.log (format %RESPONSE_CODE%|%REQ(:PATH)%|%UPSTREAM_HOST%), and the other records only 500 and above as JSON to /root/envd-log/only5xx.json. After you start it, request /hello three times and /bad/x twice, and in /root/envd-log/06-two.txt write three lines: all=, err= and ratio_ok= (the difference between all and err).
Create /root/envd-log/log-reqid.yaml — the path is /root/envd-log/reqid.log and the format is %RESPONSE_CODE%|%REQ(:PATH)%|%REQ(X-REQUEST-ID)%. After you start it, request /given with the header x-request-id: envd-777 attached and /none with no header. In /root/envd-log/07-reqid.txt, write three lines: given= (the third field of the first request's line), none_len= (the number of characters in the third field of the second request's line) and none_is_given= (yes if that value equals envd-777, otherwise no).
In /root/envd-log/08-report.md, write four lines — fields= (the number of fields in the step 2 format), missing_marker= (the character printed when there was no value in step 3), and all_lines= and error_lines= (the two values from step 6) — and below them write what you learned in at least four lines.

Notes

When you start Envoy, also give --file-flush-interval-msec 200. The default is 10 seconds, so right after a request the log looks empty.
Even so, do not use a fixed sleep. Wait with a loop that runs 줄 수가 N 이상이 될 때까지 (the Korean text means "until the line count is N or more").
Before you start it again, clean up with pkill -x envoy, and wait for startup with a loop that runs until /ready returns LIVE.
To count or extract fields, use awk -F'|', and to check JSON, use jq -c ..
Envoy appends to the log file. Delete that file before you change the format and start it again — otherwise lines in the old format and lines in the new format get mixed in one file.
Common mistake — writing the sink's filter inside typed_config. There is no such field there, so the whole configuration is rejected. Write it at the same level as name.

Keep the log in a file, and know why it comes out late

Start two upstreams — 8091 is ok and 8092 is fail. In /root/envd-log/log-text.yaml, put three routes, /ping (direct_response pong), /bad (cluster bad) and / (cluster good), and a file access log sink — the path is /root/envd-log/access.log and the format is %RESPONSE_CODE%|%REQ(:PATH)%|%UPSTREAM_HOST%. Start it with --file-flush-interval-msec 200 attached, request /hello once, and wait until the log is written to confirm.

A file sink does not write to disk on every request — it gathers in a buffer and empties it periodically. The default period is 10 seconds, so if you cat right after a request, it looks like there is nothing. A large share of "the log is not being written" reports is this. In the lab, you shorten it with --file-flush-interval-msec 200 to remove the waiting time. Even so, use a loop that runs until a line appears instead of a fixed sleep.

Decide ahead of time the values you will need after an incident

Create /root/envd-log/log-wide.yaml — the log path is /root/envd-log/wide.log and the format is eight fields: %RESPONSE_CODE%|%REQ(:METHOD)%|%REQ(:PATH)%|%PROTOCOL%|%DURATION%|%UPSTREAM_HOST%|%RESPONSE_FLAGS%|%BYTES_SENT%. After you start it with that configuration, request /hello, /ping and /bad/x once each and confirm that three lines are written.

The %...% in the format string is a command operator. A request header is %REQ(이름)% and a response header is %RESP(이름)% (the placeholder is the header name), and things that start with a colon, like :METHOD and :PATH, are HTTP/2 pseudo-headers. There is one criterion for choosing what to put here — at three in the morning, can you narrow down the cause from this line alone. The status code alone does not narrow it; you need which upstream received it, how many milliseconds it took and which flags were attached.

Know what is printed when there is no value

Create /root/envd-log/log-miss.yaml — the path is /root/envd-log/miss.log and the format is %RESPONSE_CODE%|%REQ(:PATH)%|%UPSTREAM_HOST%|%REQ(X-TENANT)% (the last field is the request header x-tenant). After you start it, request /ping and /hello once each without the header, and in /root/envd-log/03-missing.txt write three lines: ping_upstream= (the third field of the /ping line), ping_tenant= (the fourth field) and hello_tenant=.

/ping is a direct_response, so it does not go to an upstream — then there is no value to put in %UPSTREAM_HOST%. The same goes for a header that was not sent. Envoy does not leave such spots empty and fills them with a one-character mark. If you do not learn what that mark is, when you read the log by machine you will take that value for a real value and store it as it is. awk -F'|' is handy for counting fields.

Switch to a format a machine can read

Create /root/envd-log/log-json.yaml — the path is /root/envd-log/access.json, the format is json_format, and there are five keys: code, path, upstream, flags and duration_ms. After you start it, request /hello and /bad/x once each and confirm that it can be read with jq.

A text format cut by a separator is easy for people to read, but the moment the separator appears inside a value (as when a question mark and a value are attached to the path), the fields shift. If you plan to send logs to a collector and query them, it is better to use json_format from the start. You can name the keys freely, and you use the same command operators in the value slots. Check with jq -c . 파일 — if even one line is broken, jq fails on the spot.

Collect only the errors separately

Create /root/envd-log/log-err.yaml — put just one sink, keep only 500 and above with filter.status_code_filter (comparison operator GE, value 500), with the path /root/envd-log/errors.json and the keys code, path, upstream and flags. After you start it, request /hello twice and /bad/x once, and in /root/envd-log/05-filter.txt write two lines: lines= (the number of lines in errors.json) and codes= (the code values of those lines, separated by spaces).

You can attach a filter to each sink. Write filter not inside typed_config but at the same level as name — if you write it inside, the configuration is rejected with "there is no such field". Besides status code, filters include duration (duration_filter), response flags and header conditions. If you collect only the errors separately, the capacity stays manageable even if you set a long retention period.

Use two sinks together

Create /root/envd-log/log-two.yaml — there are two sinks. One records all requests as text to /root/envd-log/all.log (format %RESPONSE_CODE%|%REQ(:PATH)%|%UPSTREAM_HOST%), and the other records only 500 and above as JSON to /root/envd-log/only5xx.json. After you start it, request /hello three times and /bad/x twice, and in /root/envd-log/06-two.txt write three lines: all=, err= and ratio_ok= (the difference between all and err).

Sinks are a list, so you can have several, and each has its own format and its own filter. This is exactly the common setup in practice — keep the full log short in a short format for a short time, and keep the error log in a detailed format for a long time. If you mix the two in one file, you cannot set the retention period separately.

Who creates the request ID

Create /root/envd-log/log-reqid.yaml — the path is /root/envd-log/reqid.log and the format is %RESPONSE_CODE%|%REQ(:PATH)%|%REQ(X-REQUEST-ID)%. After you start it, request /given with the header x-request-id: envd-777 attached and /none with no header. In /root/envd-log/07-reqid.txt, write three lines: given= (the third field of the first request's line), none_len= (the number of characters in the third field of the second request's line) and none_is_given= (yes if that value equals envd-777, otherwise no).

The request ID is the thread that ties together one request passing through several services, so the proxy at the very front creates one if there is none and passes it along as it is if there is one. Using the value the client gave as it is is the default behavior, so also remember that anyone outside can send in any value (there is a separate setting to delete values that came from outside the trust boundary). Count characters with awk '{print length($0)}' or wc -c.

Leave a log design memo

In /root/envd-log/08-report.md, write four lines — fields= (the number of fields in the step 2 format), missing_marker= (the character printed when there was no value in step 3), and all_lines= and error_lines= (the two values from step 6) — and below them write what you learned in at least four lines.

This memo is something you will read yourself the next time you decide the log format of a service. Write "why I decided to include it" rather than "what I included". Take the values from the files you made in the earlier steps.