Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Default to Key, Value based Access Logging to STDOUT #1446

Closed
arkodg opened this issue May 24, 2023 · 14 comments · Fixed by #1800
Closed

Default to Key, Value based Access Logging to STDOUT #1446

arkodg opened this issue May 24, 2023 · 14 comments · Fixed by #1800
Assignees
Labels
kind/enhancement New feature or request
Milestone

Comments

@arkodg
Copy link
Contributor

arkodg commented May 24, 2023

Description:

Default to the JSON format for Access Logs written to STDOUT
https://www.envoyproxy.io/docs/envoy/latest/configuration/observability/access_log/usage#format-dictionaries

this reduces the burden on the end user to parse the text based access logs enabled by default today which dont have the field name printed beside it
https://www.envoyproxy.io/docs/envoy/latest/configuration/observability/access_log/usage#default-format-string
which was enabled with #704

@arkodg arkodg added the kind/enhancement New feature or request label May 24, 2023
@arkodg
Copy link
Contributor Author

arkodg commented May 24, 2023

thoughts @envoyproxy/gateway-maintainers ?

@arkodg arkodg added the kind/decision A record of a decision made by the community. label May 24, 2023
@tmsnan
Copy link
Contributor

tmsnan commented May 26, 2023

In our gateway, we use the format type to directly output the json type to replace the json_format type, because when we actually use the json_format type, the performance is very poor. Here is an example of using

                  - name: envoy.access_loggers.file
                    typed_config:
                      "@type": type.googleapis.com/envoy.extensions.access_loggers.file.v3.FileAccessLog
                      path: /dev/stdout
                      format: "{\"start_time\":\"%START_TIME%\",\"method\":\"%REQ(:METHOD)%\",\"x-envoy-origin-path\":\"%REQ(X-ENVOY-ORIGINAL-PATH?:PATH)%\",\"protocol\":\"%PROTOCOL%\",\"response_code\":\"%RESPONSE_CODE%\",\"response_flags\":\"%RESPONSE_FLAGS%\",\"response_code_details\":\"%RESPONSE_CODE_DETAILS%\",\"connection_termination_details\":\"%CONNECTION_TERMINATION_DETAILS%\",\"upstream_transport_failure_reason\":\"%UPSTREAM_TRANSPORT_FAILURE_REASON%\",\"bytes_received\":\"%BYTES_RECEIVED%\",\"bytes_sent\":\"%BYTES_SENT%\",\"duration\":\"%DURATION%\",\"x-envoy-upstream-service-time\":\"%RESP(X-ENVOY-UPSTREAM-SERVICE-TIME)%\",\"x-forwarded-for\":\"%REQ(X-FORWARDED-FOR)%\",\"user-agent\":\"%REQ(USER-AGENT)%\",\"x-request-id\":\"%REQ(X-REQUEST-ID)%\",\":authority\":\"%REQ(:AUTHORITY)%\",\"upstream_host\":\"%UPSTREAM_HOST%\",\"upstream_cluster\":\"%UPSTREAM_CLUSTER%\",\"upstream_local_address\":\"%UPSTREAM_LOCAL_ADDRESS%\",\"downstream_local_address\":\"%DOWNSTREAM_LOCAL_ADDRESS%\",\"downstream_remote_address\":\"%DOWNSTREAM_REMOTE_ADDRESS%\",\"requested_server_name\":\"%REQUESTED_SERVER_NAME%\",\"route_name\":\"%ROUTE_NAME%\"}\n"

@arkodg
Copy link
Contributor Author

arkodg commented May 26, 2023

haha @tmsnan, nice workaround :) , can you share any relevant upstream link that highlights the poor performance

@tmsnan
Copy link
Contributor

tmsnan commented May 26, 2023

@arkodg ,field data was not saved at the time. But this scene is easy to compare. If necessary, I will try to compare it locally. The reason is that the json format output needs to be serialized, while the text only needs to be simply spliced ​​according to the format

@haq204
Copy link
Contributor

haq204 commented May 26, 2023

I would prefer keeping the default to text due to the serialization cost @tmsnan mentioned. I don't think I've ever seen json format set as the default for logs in other places and probably for good reason. logs can be voluminous so the serialization can add a lot of extra CPU cycles/memory util and I'm not sure that's a cost I want to enable by default to users.

@arkodg
Copy link
Contributor Author

arkodg commented May 26, 2023

related upstream issue envoyproxy/envoy#10415

@arkodg
Copy link
Contributor Author

arkodg commented Jun 16, 2023

chatted with @cpakulski who confirmed the extra cost for serialization when using json format, so I'm a
+1 to @tmsnan's approach of using text format, but representing the text as a json string as shown here.
which can be used to update the defaults set here

// EnvoyTextLogFormat is the default log format for Envoy.

wdyt @AliceProxy @zirain @Xunzhuo ?

@zirain
Copy link
Member

zirain commented Jun 16, 2023

I will be -1 to use it as default.
AFAIK, fluent-bit/istio use a plain text as default, prefer to same thing.

@arkodg
Copy link
Contributor Author

arkodg commented Jun 16, 2023

im personally tired of staring at

[2016-04-15T20:17:00.310Z] "POST /api/v1/locations HTTP/2" 204 - 154 0 226 100 "10.0.35.28"
"nsq2http" "cc21d9b0-cf5c-432b-8c7e-98aeb7988cd2" "locations" "tcp://10.0.2.1:80"

and figuring out which field maps to which attribute.
Offline tooling for parsing these logs and creating the attribute mappings exist, and so does the ability to change the format, but sometimes its faster to get to the root cause by directly looking at the pod logs, which might be useful for most imo

@zirain
Copy link
Member

zirain commented Jun 16, 2023

That's why EG offer the ability to customize

@tmsnan
Copy link
Contributor

tmsnan commented Jun 19, 2023

I think changing to json string type by default is more friendly to novices.

@github-actions
Copy link

This issue has been automatically marked as stale because it has not had activity in the last 30 days.

@github-actions github-actions bot added the stale label Jul 19, 2023
@arkodg arkodg removed the stale label Aug 4, 2023
@arkodg arkodg changed the title Default to JSON format for Access Logging to STDOUT Default to Key, Value based Access Logging to STDOUT Aug 4, 2023
@arkodg
Copy link
Contributor Author

arkodg commented Aug 4, 2023

had a chat with @zirain who is not completely opposed to this :), but worries about perf .
I'd prefer if we tried this out sooner than later and can always revert if perf drops significantly.

Hoping we can get @tmsnan's suggestion in #1446 (comment)
@tmsnan can you help with this one :)

@arkodg arkodg added help wanted Extra attention is needed and removed kind/decision A record of a decision made by the community. labels Aug 4, 2023
@arkodg arkodg added this to the 0.6.0-rc1 milestone Aug 4, 2023
@arkodg arkodg self-assigned this Aug 18, 2023
@arkodg arkodg removed the help wanted Extra attention is needed label Aug 18, 2023
@arkodg
Copy link
Contributor Author

arkodg commented Aug 18, 2023

assigning this to myself

arkodg added a commit to arkodg/gateway that referenced this issue Aug 18, 2023
Before
```
[2023-08-18T22:15:14.085Z] "GET /get HTTP/1.1" 200 - 0 509 1 0 "10.1.3.156" "curl/7.86.0" "ec7ca022-80c8-4e7c-8271-167b260bd190" "www.example.com" "10.102.226.25:3000"
```

After
```
"start_time":"2023-08-18T22:01:23.901Z","method":"GET","x-envoy-origin-path":"/get","protocol":"HTTP/1.1","response_code":"200","response_flags":"-","response_code_details":"via_upstream","connection_termination_details":"-","upstream_transport_failure_reason":"-","bytes_received":"0","bytes_sent":"511","duration":"0","x-envoy-upstream-service-time":"0","x-forwarded-for":"192.168.65.4","user-agent":"curl/7.86.0","x-request-id":"000985ce-a62d-4899-95f8-c60fa9e5f246",":authority":"www.example.com","upstream_host":"10.104.223.83:3000","upstream_cluster":"default/backend/rule/0/match/0-www.example.com","upstream_local_address":"10.1.3.145:55664","downstream_local_address":"10.1.3.145:10080","downstream_remote_address":"192.168.65.4:50042","requested_server_name":"-","route_name":"default/backend/rule/0/match/0-www.example.com"
```

Fixes: envoyproxy#1446

Signed-off-by: Arko Dasgupta <[email protected]>
arkodg added a commit to arkodg/gateway that referenced this issue Aug 30, 2023
Before
```
[2023-08-18T22:15:14.085Z] "GET /get HTTP/1.1" 200 - 0 509 1 0 "10.1.3.156" "curl/7.86.0" "ec7ca022-80c8-4e7c-8271-167b260bd190" "www.example.com" "10.102.226.25:3000"
```

After
```
"start_time":"2023-08-18T22:01:23.901Z","method":"GET","x-envoy-origin-path":"/get","protocol":"HTTP/1.1","response_code":"200","response_flags":"-","response_code_details":"via_upstream","connection_termination_details":"-","upstream_transport_failure_reason":"-","bytes_received":"0","bytes_sent":"511","duration":"0","x-envoy-upstream-service-time":"0","x-forwarded-for":"192.168.65.4","user-agent":"curl/7.86.0","x-request-id":"000985ce-a62d-4899-95f8-c60fa9e5f246",":authority":"www.example.com","upstream_host":"10.104.223.83:3000","upstream_cluster":"default/backend/rule/0/match/0-www.example.com","upstream_local_address":"10.1.3.145:55664","downstream_local_address":"10.1.3.145:10080","downstream_remote_address":"192.168.65.4:50042","requested_server_name":"-","route_name":"default/backend/rule/0/match/0-www.example.com"
```

Fixes: envoyproxy#1446

Signed-off-by: Arko Dasgupta <[email protected]>
arkodg added a commit that referenced this issue Aug 31, 2023
* Add a key to the access default log text format

Before
```
[2023-08-18T22:15:14.085Z] "GET /get HTTP/1.1" 200 - 0 509 1 0 "10.1.3.156" "curl/7.86.0" "ec7ca022-80c8-4e7c-8271-167b260bd190" "www.example.com" "10.102.226.25:3000"
```

After
```
{"start_time":"2023-08-30T19:39:16.694Z","method":"GET","x-envoy-origin-path":"/get","protocol":"HTTP/1.1","response_code":"200","response_flags":"-","response_code_details":"via_upstream","connection_termination_details":"-","upstream_transport_failure_reason":"-","bytes_received":"0","bytes_sent":"508","duration":"1","x-envoy-upstream-service-time":"0","x-forwarded-for":"10.1.4.12","user-agent":"curl/7.86.0","x-request-id":"df9cc5ed-8f92-4376-b045-34669dde0ea1",":authority":"www.example.com","upstream_host":"10.110.21.140:3000","upstream_cluster":"httproute/default/backend/rule/0","upstream_local_address":"10.1.4.12:36496","downstream_local_address":"127.0.0.1:10080","downstream_remote_address":"127.0.0.1:53826","requested_server_name":"-","route_name":"httproute/default/backend/rule/0/match/0/www_example_com"}
```

Fixes: #1446

Signed-off-by: Arko Dasgupta <[email protected]>

* use space instead of ,

Signed-off-by: Arko Dasgupta <[email protected]>

* use json format

Signed-off-by: Arko Dasgupta <[email protected]>

* fix json

Signed-off-by: Arko Dasgupta <[email protected]>

---------

Signed-off-by: Arko Dasgupta <[email protected]>
Co-authored-by: zirain <[email protected]>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
kind/enhancement New feature or request
Projects
None yet
Development

Successfully merging a pull request may close this issue.

4 participants