-
Notifications
You must be signed in to change notification settings - Fork 257
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
Logging (JSON) formatting; span export #1364
Conversation
e5c4b57
to
e45945c
Compare
cb678f6
to
20b711e
Compare
rebase to remove test vendor |
f39ec68
to
94956bd
Compare
rebased to include new CI file |
94956bd
to
1f3ec4b
Compare
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 <hamzaelsaawy@microsoft.com>
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 <hamzaelsaawy@microsoft.com>
// (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.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
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.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
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
|
||
var _ logrus.Hook = &Hook{} | ||
|
||
func NewHook() *Hook { | ||
return &Hook{} | ||
return &Hook{ | ||
EncodeAsJSON: true, |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
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.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
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 <hamzaelsaawy@microsoft.com>
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
LGTM
* 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 <hamzaelsaawy@microsoft.com> * PR: docs, un-exported func, vestigial code Remove unused commented out code and left-over function. Signed-off-by: Hamza El-Saawy <hamzaelsaawy@microsoft.com> * 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 <hamzaelsaawy@microsoft.com> --------- Signed-off-by: Hamza El-Saawy <hamzaelsaawy@microsoft.com>
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 hamzaelsaawy@microsoft.com