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

Inconsistent debug logging of line payloads from TCP listener #497

Closed
matthiasr opened this issue May 16, 2023 · 1 comment · Fixed by #510
Closed

Inconsistent debug logging of line payloads from TCP listener #497

matthiasr opened this issue May 16, 2023 · 1 comment · Fixed by #510
Labels
bug good first issue help wanted PRs for this issue are especially welcome

Comments

@matthiasr
Copy link
Contributor

We log raw packets in different places. Sometimes, we pass it to the logger as a string, sometimes as a byte slice. Specifically, this affects the TCP ingestion path.

This leads to confusing log output, especially in the JSON format, because the "binary" data is Base64-encoded by the log library.

We should consistently convert the lines to strings for logging, since we know that it's mostly-ASCII data.

@matthiasr matthiasr added bug good first issue help wanted PRs for this issue are especially welcome labels May 16, 2023
@matthiasr
Copy link
Contributor Author

In the standard log output, this shows as line="…" vs. line=…:

level=debug ts=2023-05-16T11:59:48.597Z caller=listener.go:136 msg="Incoming line" proto=tcp line=ratelimit.go.nextGC:43558224|g
level=debug ts=2023-05-16T11:59:48.597Z caller=relay.go:150 msg="Relaying line" line=ratelimit.go.nextGC:43558224|g
level=debug ts=2023-05-16T11:59:48.598Z caller=relay.go:119 msg="Adding line to buffer" line="ratelimit.go.nextGC:43558224|g\n"
level=debug ts=2023-05-16T11:59:49.569Z caller=relay.go:132 msg="Sending packet" length=597 data="ratelimit.go.numGC:1|c\nratelimit.go.totalAlloc:9974800|c\nratelimit.go.mallocs:131674|c\nratelimit.go.frees:312509|c\nratelimit.go.pauseTotalNs:99290|c\nratelimit.go.lastGC:1684238384274161217|g\nratelimit.go.gcCPUPercent:0|g\nratelimit.go.heapObjects:128909|g\nruntime.num_values:1|g\nratelimit.redis_pool.cx_active:10|g\nratelimit.go.sys:0|g\nratelimit.go.heapSys:51544064|g\nratelimit.go.heapIdle:20365312|g\nratelimit.go.nextGC:43558224|g\nratelimit.go.heapReleased:5029888|g\nratelimit.go.numGoroutine:464|g\nratelimit.go.alloc:27489712|g\nratelimit.go.heapAlloc:27489712|g\nratelimit.go.heapInuse:31178752|g\n"

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug good first issue help wanted PRs for this issue are especially welcome
Projects
None yet
Development

Successfully merging a pull request may close this issue.

1 participant