Logging (JSON) formatting; span export #1364
Conversation
helsaawy
force-pushed
the
he/trace-base
branch
3 times, most recently
from
e5c4b57 to
e45945c
Compare
helsaawy
force-pushed
the
he/trace-base
branch
7 times, most recently
from
cb678f6 to
20b711e
Compare
helsaawy
changed the title
|
rebase to remove test vendor |
helsaawy
force-pushed
the
he/trace-base
branch
from
f39ec68 to
94956bd
Compare
|
rebased to include new CI file |
helsaawy
force-pushed
the
he/trace-base
branch
from
94956bd to
1f3ec4b
Compare
helsaawy
force-pushed
the
he/trace-base
branch
from
e951f8e to
ef1b206
Compare
Added formatting for logrus export hook to marshal structs as JSON strings, as well as format other known types (eg, time.Time). Updated span export to: * include span kind * include status code * log if span attributes were dropped Added helper `log.Format*` functions to format Time and other structs to JSON. This is already done by the logging hook, but allows spans format their attributes consistently, since they must be converted to strings before being exported. Signed-off-by: Hamza El-Saawy <[email protected]>
helsaawy
force-pushed
the
he/trace-base
branch
from
ef1b206 to
375041a
Compare
|
rebase to resolve merge conflicts with dependent PR, #1379 |
Remove unused commented out code and left-over function. Signed-off-by: Hamza El-Saawy <[email protected]>
| // (OC) Span attributes are guaranteed to be strings, bools, or int64s, so we can | ||
| // can skip overhead in entry.WithFields() and add them directly to entry.Data. | ||
| // Preallocate ahead of time, since we should add, at most, 10 additional entries | ||
| data := make(logrus.Fields, len(entry.Data)+len(s.Attributes)+10) |
There was a problem hiding this comment.
Don't necessarily need this changed, but it does seem like we're effectively copying any data items on log.L twice, once when we call Dup, and once below. Would it be better to just call Dup and then directly add any span attributes and other fields onto that entry directly? Assuming map resizes when they run out of space add a reasonable amount of extra space, I imagine we're not getting much value out of pre-creating an empty map with the final size.
There was a problem hiding this comment.
Every call to .WithFields() duplicates the Data map and does additional overhead (src), but making a dedicated map and sizing it felt cleaner than modifying entry.Data directly.
I can switch if if you feel strongly about it though
|
Given how old this PR is, I'm not going to ask you to do this now, but in the future I want our team to try to split up PRs more into smaller chunks. For instance, it looks like this one would really easily split between Smaller PRs should hopefully reduce the cognitive overhead with review, which will help get them in faster. It also makes it easier if we need to revert an old change, or bisect to determine what change caused an issue. |
|
Have we thought through the implications of JSON-encoding event data by default in a bunch of cases? For instance, do we or others (Howard?) have log processing that depends on the current format? |
internal/log/hook.go
Outdated
| func NewHook() *Hook { | ||
| return &Hook{} | ||
| return &Hook{ | ||
| EncodeAsJSON: true, |
There was a problem hiding this comment.
I think this would be a good place to consider splitting PRs in general: Adding new functionality vs turning on that functionality by default.
It's a lot easier to get in changes to add new JSON-encoding support, and keep it off by default, and then make a single, small, obvious change to turn it on by default, rather than mixing that in with the mechanism implementation.
In this case, I'm not too worried about the time or duration formatting, but especially turning on JSON encoding by default seems riskier to me.
There was a problem hiding this comment.
I can split that part out in a new PR
I discussed with Howard a while back and am re-discussing with him now, but we make no guarantees about log format stability, and we change logs and their fields all the time.
Plus, currently relying on fmt.Sprintf("%v",...) is also not stable, since go makes no guarantees about what the verbose format for structs will be, and any field or struct update will impact that as well
Clarified documentation. Disable JSON encoding by default. Bug: `AddSpanContext` wasn't checked when adding span information. Bug: `EncodeError` was unneeded. Signed-off-by: Hamza El-Saawy <[email protected]>
* Log (JSON) formatting hook; span export Added formatting for logrus export hook to marshal structs as JSON strings, as well as format other known types (eg, time.Time). Updated span export to: * include span kind * include status code * log if span attributes were dropped Added helper `log.Format*` functions to format Time and other structs to JSON. This is already done by the logging hook, but allows spans format their attributes consistently, since they must be converted to strings before being exported. Signed-off-by: Hamza El-Saawy <[email protected]> * PR: docs, un-exported func, vestigial code Remove unused commented out code and left-over function. Signed-off-by: Hamza El-Saawy <[email protected]> * PR: docs, defaults, AddSpanContext/EncodeError bug Clarified documentation. Disable JSON encoding by default. Bug: `AddSpanContext` wasn't checked when adding span information. Bug: `EncodeError` was unneeded. Signed-off-by: Hamza El-Saawy <[email protected]> --------- Signed-off-by: Hamza El-Saawy <[email protected]>
3 participants
Updated logrus hook to marshal structs and other type (eg,
time.Time,time.Duration,[]byte) as JSONstrings.
Updated span export to:
Additionally, added conversion that checks from common error types
(including those in
containerd/containerd/errdefs) to the trace statuscode (which, via convention, is a GRPC error code).
Added helper
log.Format*functions to format Time and other structsto JSON. This is already done by the logging hook, but allows spans
format their attributes consistently, since they must be converted to
strings before being exported.
Signed-off-by: Hamza El-Saawy [email protected]