-
Notifications
You must be signed in to change notification settings - Fork 177
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
contextual logging #2121
contextual logging #2121
Conversation
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.
Thanks for the PR @darkdarkdragon . I skimmed through the code, I think it solves the problem. Added 2 comments.
My main concern is that we overuse the context object, meaning that we pass it now everywhere just for the logging purpose, but not every place actually respects what context is designed for.
That's why I'd recommend creating a separate struct like clog
like this.
struct clog {
manifestID string,
sessionID string,
...
}
And then store this struct in the context. In that case, we could pass context only to the functions that respect the context contract (cancellation, timeouts, etc.) and to the others, pass just clog
struct. Wdyt?
core/lb.go
Outdated
@@ -147,8 +146,9 @@ func (lb *LoadBalancingTranscoder) leastLoaded() string { | |||
} | |||
|
|||
type transcoderParams struct { | |||
md *SegTranscodingMetadata | |||
res chan struct { | |||
logCtx context.Context |
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.
This looks fishy. In general Go doc does not recommend storing context in any structs.
Do not store Contexts inside a struct type; instead, pass a Context explicitly to each function that needs it. The Context should be the first parameter, typically named ctx
I understand that transcoderParams
are actually for us the request params, but still...
It makes me think that we should maybe have an abstraction like clog
struct which we store inside the context. Then, pass only this struct into transcoderParams
(and to all other places that do not respect the context
(i.e. does not stop working when the context is canceled) ).
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.
Yes, it is looks not ideal, but I think it's better than the other option. Introducing separate structure for logging data will lead to a lot of wrapping/unwrapping code, and for what? To satisfy one sentence in context package's documentation?
Context is useful because it is a black box, and functions can pass it around without knowing what's inside.
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.
In general Go doc does not recommend storing context in any structs.
@leszko I think that's a rule that needs to be interpreted with a grain of salt as well. At least I interpret it as not storing ctxs in a long-living struct that will be shared among multiple short-lived operations, each of these operations (naturally) with their own respective ctxs.
I think in the case of a struct only used to pass parameters around it is very much an exception of that, as it is mostly a syntax sugar for not repeating the parameters multiple times in several places, but all of those within one of those short-live operations with the same ctx. (I am assuming that this is the use case for this params struct, since it is also so short with only 3 fields). An example of that is go's own http.Request
object which can hold a ctx for that specific request to be made: https://pkg.go.dev/net/http#NewRequestWithContext
Another exception for that rule I think are "background jobs" which should be cancellable with a context passed on creation of the job. In that case, you could in theory pass the context around in every internal struct that needs access to it, but I think it's also valid to store the job context in the struct that represents the job itself, and access it anywhere you need it. One example of those is the RabbitMQ Streams consumer here (it has an internal done
channel instead, but could just as well be an external context.Context
for the same result).
Also an example for storing "application" (contextual) data in a context is julienschmidt/httprouter. It is an HTTP router which you can defined path routes with params, and it stores those params in the ctx in case you wanna use it with a raw http.Handler
and not their specialized interface.
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.
That's ok. Maybe we should just call it ctx
or context
then? If we pass it a context for the request. logCtx
looks misleading, you receive this struct and you're not sure if you can depend on this context timeout/cancellation...
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.
Yeah makes sense! I agree that having a separate context that is used for nothing but logging would be an anti-patttern. IMO, there should be only one ctx
passed around [1], which in some places is used only for cancellation in case no logging is done, in others is used only for logging in case cancellation is not supported, and in the ideal cases are used for both. With that in mind, this should be renamed to just ctx
and if it's built out of thin air just for logging it should be from a context.TODO()
to be fixed later with a real context, not a context.Background()
(not sure if that's happening anywhere right now).
[1] The only exception case I've found for this rule is when you do actually have multiple hierarchical cancellation contexts for the current code. For example if you have a server, which has it's own ctx
for shutting down, while each request also has it's own ctx
. You might use both, or better yet "merge" them into a single ctx
that you pass around further down, using the same example as before, like this: https://github.com/livepeer/livepeer-data/blob/ed2b74fc9a2124032c05b11addfa4ebb6c013aab/pkg/event/stream_consumer.go#L199
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.
Yeah, agree 🤝
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.
@leszko @victorges
I've renamed logCtx to ctx
in most places, now it's ready for review.
I think context was designed for passing around data, not just for timeouts/cancellation ( |
core/lb.go
Outdated
@@ -147,8 +146,9 @@ func (lb *LoadBalancingTranscoder) leastLoaded() string { | |||
} | |||
|
|||
type transcoderParams struct { | |||
md *SegTranscodingMetadata | |||
res chan struct { | |||
logCtx context.Context |
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.
In general Go doc does not recommend storing context in any structs.
@leszko I think that's a rule that needs to be interpreted with a grain of salt as well. At least I interpret it as not storing ctxs in a long-living struct that will be shared among multiple short-lived operations, each of these operations (naturally) with their own respective ctxs.
I think in the case of a struct only used to pass parameters around it is very much an exception of that, as it is mostly a syntax sugar for not repeating the parameters multiple times in several places, but all of those within one of those short-live operations with the same ctx. (I am assuming that this is the use case for this params struct, since it is also so short with only 3 fields). An example of that is go's own http.Request
object which can hold a ctx for that specific request to be made: https://pkg.go.dev/net/http#NewRequestWithContext
Another exception for that rule I think are "background jobs" which should be cancellable with a context passed on creation of the job. In that case, you could in theory pass the context around in every internal struct that needs access to it, but I think it's also valid to store the job context in the struct that represents the job itself, and access it anywhere you need it. One example of those is the RabbitMQ Streams consumer here (it has an internal done
channel instead, but could just as well be an external context.Context
for the same result).
Also an example for storing "application" (contextual) data in a context is julienschmidt/httprouter. It is an HTTP router which you can defined path routes with params, and it stores those params in the ctx in case you wanna use it with a raw http.Handler
and not their specialized interface.
9dc806d
to
121fba4
Compare
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 added my comments.
In general, it looks good and I really like the improvement. Most of the comments are minor and some of them might be just because of my lack of the livepeer domain and codebase.
var clogContextKey = clogContextKeyT{} | ||
|
||
const ( | ||
// standard keys |
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.
What is the meaning of a standard key? Why orchSessionID
is not a standard key?
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.
What is the meaning of a standard key?
These constants exists only for one reason - to be able to print them in sorted order.
Why orchSessionID is not a standard key?
It is. I just forgot to add it to the stdKeysOrder
array.
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.
ahh, I see, then I think you can remove this comment // standard keys
and maybe rename stdKeys
, because this std
has apparently no meaning, which can be confusing.
You can just call them clogKeys
or keys
.
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.
They are 'standard' because we define them in the package, and have separate AddXXX
methods for them - as opposed to general AddVal
method which allows user to add any key.
clog/clog.go
Outdated
} | ||
|
||
func V(level glog.Level) Verbose { | ||
return Verbose(bool(glog.V(level))) |
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.
return Verbose(bool(glog.V(level))) | |
return Verbose(glog.V(level)) |
Nit: You don't need bool()
type conversion here.
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.
thanks, fixed
clog/clog.go
Outdated
} | ||
|
||
func infof(ctx context.Context, lastErr bool, format string, args ...interface{}) { | ||
glog.InfoDepth(2, formatMessage(ctx, lastErr, format, args...)) |
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.
Why is the depth 2
here (while everywhere else it's 1
)?
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.
Where it is 1
?
clog/clog.go
Outdated
} | ||
|
||
// Infofe if last argument is not nil it will be printed as " err=%q" | ||
func Infofe(ctx context.Context, format string, args ...interface{}) { |
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.
Is there any known convention with this e
at the end logging functions? If not, then maybe we don't need this Infofe()
and (v Verbose) Infofe()
at all? I see they are not used in many places and maybe we can add err=%v
there in the string message. What do you think? To me, this looks confusing.
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.
It is convention that I've just invented 😄
This exists to avoid having err=<nil>
in the logs. We will get it if we're doing Infof("err=%v", err)
in case err
could be nil
.
So to avoid this I need to write
if err != nil {
glog.Infof("message var1=%s err=%v", var1, err)
} else {
glog.Infof("message var1=%s", var1)
}`
Infofe
helps to avoid this duplication.
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.
ok, I see. I'd probably prefer having err=<nil>
since it's kind-of magic behavior of the library you create. In other words, as a user of clog
you can be confused that suddenly err=
is automatically added at the end. Anyway, it's minor and probably opinion-based, so I leave it up to you (and @victorges) to decide.
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.
You would prefer not to have err=<nil>
in the logs once you will start digging through actual logs 😄
When searching through logs using err=
as a query it's much better to see lines with actual errors 😄
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.
When searching through logs using err= as a query it's much better to see lines with actual errors 😄
This will be so much less insane now that we have an actual tool for querying logs by their actual fields and not just text search 😄
But I think it's nice to avoid the err=<nil>
lines anyway :)
It is convention that I've just invented 😄
Since it is a new convetion and thus not something that is self-explanatory, WDYT of using a more explicit name for the function? I like Infoferr
for example.
And another approach is providing an AddErr
function that only adds the error to the log if it is not nil
. On your example, it could be:
ctx = clog.AddErr(ctx, err)
clog.Infof(ctx, "message var1=%s", var1)
or with the chaining idea in the other comment:
clog.Fields(ctx).AddErr(err)
.Infof("message var1=%s", var1)
} | ||
for key, val := range cmap.vals { | ||
if _, ok := stdKeys[key]; !ok { | ||
sb.WriteString(key) |
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.
Nit: Consider extracting to a function, these 4 lines are the same as in line 166.
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 could, but I don't see much value in it.
} | ||
cmap.mu.RLock() | ||
for _, key := range stdKeysOrder { | ||
if val, ok := cmap.vals[key]; ok { |
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 see you print the standard keys in some predefined order. However, not standard keys are printed in random order. Is that intended?
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.
Is that intended?
It is consequence of go
's map being random. I could overcome it by different ways, but I've decided that it's not worth it. And anyway, right now only standard keys are used.
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.
If we prepare the clog
only for standard keys now, then let's maybe print only them? And skip printing the random keys? I think we should make it clear if the user of clog
is allowed to create custom keys or not. If yes, then be consistent and print them in some order (i.e. alphabetic) if not, then just do not log the custom keys.
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.
- It is allowed to create custom keys.
- I don't think it's worth it. To do that we will need to write more code and suffer runtime efficiency. We can change it later if we will decide that this is a problem.
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.
- It is allowed to create custom keys.
Do we use it anywhere? Why do we need it?
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 it will be quite annoying to go through logs where the keys have a random order on every line. Especially when for example going through a stream of the same log type, I normally get used to find the data I want on the same position on the line (cause fields generally have have the same length) and just move around.
Totally something that we can change in implementation later without breaking compatibility, so not necessary now, but giving my +1 here that we probably want to do some deterministic key order here soon. We could create an auxiliary keys
slice, sort that, and then print the fields the same way we do for the stdKeysOrder
above. That's exactly how logrus
does it (src) and I'd guess how json
package does it too for serialization.
0c74034
to
18935e4
Compare
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.
Added comments.
I also played with it and everything seems to work fine :)
One more thing came to my mind, I see that in the GH issue #2102, @iameli mentioned that two fields should be printed in the logs manifestId
and sessionId
. I see a lot of other fields printed, but sessionId
was not printed (at least in my case).
Could you maybe confirm with @iameli that what we print is ok?
/* | ||
Package clog provides Conext with logging information. | ||
*/ | ||
package clog |
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 it should at least:
- Create this context
- Use your functions to update it (
AddManifestID()
,AddOrchSessionID()
) - Execute
messageFromContext()
and assert the result
You can think if something else can be tested.
var clogContextKey = clogContextKeyT{} | ||
|
||
const ( | ||
// standard keys |
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.
ahh, I see, then I think you can remove this comment // standard keys
and maybe rename stdKeys
, because this std
has apparently no meaning, which can be confusing.
You can just call them clogKeys
or keys
.
return AddVal(ctx, orchSessionID, val) | ||
} | ||
|
||
func AddSessionID(ctx context.Context, val string) context.Context { |
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.
👍
clog/clog.go
Outdated
} | ||
|
||
// Infofe if last argument is not nil it will be printed as " err=%q" | ||
func Infofe(ctx context.Context, format string, args ...interface{}) { |
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.
ok, I see. I'd probably prefer having err=<nil>
since it's kind-of magic behavior of the library you create. In other words, as a user of clog
you can be confused that suddenly err=
is automatically added at the end. Anyway, it's minor and probably opinion-based, so I leave it up to you (and @victorges) to decide.
} | ||
cmap.mu.RLock() | ||
for _, key := range stdKeysOrder { | ||
if val, ok := cmap.vals[key]; ok { |
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.
If we prepare the clog
only for standard keys now, then let's maybe print only them? And skip printing the random keys? I think we should make it clear if the user of clog
is allowed to create custom keys or not. If yes, then be consistent and print them in some order (i.e. alphabetic) if not, then just do not log the custom keys.
clog/clog.go
Outdated
} | ||
|
||
func infof(ctx context.Context, lastErr bool, format string, args ...interface{}) { | ||
glog.InfoDepth(2, formatMessage(ctx, lastErr, format, args...)) |
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 already asked about it, but it gets lost somewhere during the refactor ;) Why is the depth here 2
while in Warningf
, Fatalf
and Infof
you use 1
?
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.
For Warningf
call stack looks like this: calling code->clog.Warningf->glog.WarningDepth
For Infof
: calling code->clog.Infof->infof->glog.InfoDepth
As you can see there is one more function in the chain, so call stack is deeper by one.
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.
Ahh, I see. Consider adding a comment to the code to explain it.
18935e4
to
d4f43fe
Compare
@victorges could you give it another review? |
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.
@darkdarkdragon , the PR looks good from my end. Last two things are:
-
Non-standard keys, I still don't get why we have them if we don't use them at all. I think we should not "just have them in case" but rather either remove them for now (if we don't need them), make their printing deterministic (if we need them).
-
Confirm if the format we print is ok with @iameli , because GH Issue mentioned something slightly different.
/* | ||
Package clog provides Conext with logging information. | ||
*/ | ||
package clog |
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.
Great, thanks!
2e7a517
to
da72130
Compare
1f129c1
to
cbbf55c
Compare
cbbf55c
to
5046c59
Compare
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 with a few suggestions, but feel free to merge as is! Also thanks for migrating so much of the codebase to the new lib already!
At some point I started mostly skimming on the changes to use the new lib tho, since it looked mostly straightforward/automatic. Let me know if there are any files that need a more thorough review.
func AddVal(ctx context.Context, key, val string) context.Context { | ||
cmap, _ := ctx.Value(clogContextKey).(*values) | ||
if cmap == nil { | ||
cmap = newValues() | ||
ctx = context.WithValue(ctx, clogContextKey, cmap) | ||
} |
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.
One thing that bothers me about the "lazy init" approach is that every interface we give needs to receive & return a context.Context
instance. I'm not 100% which is my preference, but have you considered/WDYT of a separate function to initialize the context like
ctx = clog.InitFields(ctx)
and then it can just be used to add fields without worrying about re-setting the ctx
value like
clog.AddVal(ctx, "a", "b")
or
clog.Fields(ctx).Add("a", "b")
or even ⛓️
clog.Fields(ctx)
.Add("a", "b")
.Add("c", "d")
In which clog.Fields
would panic if the fields have not been initialized. Also maybe InitFields
could even be the same function as "clone": if there are already fields there, it would create new ones and clone the values, for a "sub-log-context".
Note that we could also allow both interfaces to be used, with the disclaimer that, if you use Fields
you must know that your ctx
has already been initalized.
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.
Right now, after context is initialised, you can just do clog.AddVal(ctx, "a", "b")
- this will work just fine because anyway it will return same context. I didn't want explicit initialisation because I didn't want to have accidental panic in production.
cmap.mu.Lock() | ||
cmap.vals[key] = val | ||
cmap.mu.Unlock() |
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.
Would be great if we could avoid this lock somehow, as logging ideally shouldn't be something you need to be too cautious about performance issues. I wonder if no lock at all wouldn't be sufficient here, since that also considering the current interface which returns a context.Context
on every added field, doesn't look like something that we would/should be calling concurrently.
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.
doesn't look like something that we would/should be calling concurrently.
I thought so, but was forced to add lock after panics 😄 Turned out we do use same context from different go-routines.
Anyway, when I've first created this package, I didn't know how much information will end up in the logging context.
Turned out not much - right now I'm using only one non-standard key, and probably we will not add many more.
So I think we can get rid of map completely and just use pre-allocated array containing key/value pairs.
Or keep map and locks, but pre-format message on every AddXXX call. Or something else - but it is discussion for the next issue/PR 😄
clog/clog.go
Outdated
} | ||
|
||
// Infofe if last argument is not nil it will be printed as " err=%q" | ||
func Infofe(ctx context.Context, format string, args ...interface{}) { |
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.
When searching through logs using err= as a query it's much better to see lines with actual errors 😄
This will be so much less insane now that we have an actual tool for querying logs by their actual fields and not just text search 😄
But I think it's nice to avoid the err=<nil>
lines anyway :)
It is convention that I've just invented 😄
Since it is a new convetion and thus not something that is self-explanatory, WDYT of using a more explicit name for the function? I like Infoferr
for example.
And another approach is providing an AddErr
function that only adds the error to the log if it is not nil
. On your example, it could be:
ctx = clog.AddErr(ctx, err)
clog.Infof(ctx, "message var1=%s", var1)
or with the chaining idea in the other comment:
clog.Fields(ctx).AddErr(err)
.Infof("message var1=%s", var1)
} | ||
cmap.mu.RLock() | ||
for _, key := range stdKeysOrder { | ||
if val, ok := cmap.vals[key]; ok { |
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 it will be quite annoying to go through logs where the keys have a random order on every line. Especially when for example going through a stream of the same log type, I normally get used to find the data I want on the same position on the line (cause fields generally have have the same length) and just move around.
Totally something that we can change in implementation later without breaking compatibility, so not necessary now, but giving my +1 here that we probably want to do some deterministic key order here soon. We could create an auxiliary keys
slice, sort that, and then print the fields the same way we do for the stdKeysOrder
above. That's exactly how logrus
does it (src) and I'd guess how json
package does it too for serialization.
return | ||
case params := <-sess.sender: | ||
cancel() | ||
res, err := | ||
sess.transcoder.Transcode(params.md) | ||
sess.transcoder.Transcode(params.ctx, params.md) |
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.
Hum, I think I understood the need but it's quite confusing to have 2 (3?) contexts here. Seems like this context passed here should be logCtx
instead? Since it's a function that did not receive a ctx before so it's likely only used for logging.
Is there any way of getting rid of the duplication or maybe sticking to only 1 context in the implementation here? Havent read the whole logic so not sure if I follow it, but if we need params.ctx
for cancellation and logCtx
for logging, shouldn't clog.Clone(params.ctx, logCtx)
or sth like that be the only ctx we need here?
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.
Infofe
made for the cases when we don't know if err
is nil or not. But here we already checked, so no point of using Infofe
Either way came to my mind that Infofe will be logging errors as info, not as errors, right? Sth we'd like to change somehow?
Fixed in 4d312d6
Also, while at it, mind adding any text here to say something about what is this error?
This concrete error already has verbose description added (like errors.Wrapf(err, "Could not get orchestrator orch=%v", orchestratorServer)
)
@@ -114,7 +115,7 @@ func (o *orchestratorPool) GetOrchestrators(numOrchestrators int, suspender comm | |||
return | |||
} | |||
if err != nil && !errors.Is(err, context.Canceled) { | |||
glog.Error(err) | |||
clog.Errorf(ctx, "err=%q", err) |
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.
Hmm, isn't Infof
(err) a good candidate here? Either way came to my mind that Infofe
will be logging errors as info, not as errors, right? Sth we'd like to change somehow?
Also, while at it, mind adding any text here to say something about what is this error?
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.
because ctx
is captured in the closure, and will be the same for subsequent calls to function that is returned from createRTMPStreamIDHandler
@@ -238,21 +239,27 @@ func createRTMPStreamIDHandler(s *LivepeerServer) func(url *url.URL) (strmID str | |||
profiles := []ffmpeg.VideoProfile{} | |||
detectionConfig := core.DetectionConfig{} | |||
var VerificationFreq uint | |||
nonce := rand.Uint64() | |||
|
|||
ctx := clog.AddNonce(_ctx, nonce) |
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.
What's the reason for declaring a new variable here instead of replacing?
@@ -1424,26 +1440,26 @@ func (s *LivepeerServer) HandleRecordings(w http.ResponseWriter, r *http.Request | |||
return | |||
default: | |||
} | |||
glog.V(common.VERBOSE).Infof("Playlist generation for manifestID=%s took=%s", manifestID, time.Since(now1)) | |||
clog.V(common.VERBOSE).Infof(ctx, "Playlist generation for took=%s", time.Since(now1)) |
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.
clog.V(common.VERBOSE).Infof(ctx, "Playlist generation for took=%s", time.Since(now1)) | |
clog.V(common.VERBOSE).Infof(ctx, "Playlist generation took=%q", time.Since(now1)) |
return errSecret | ||
} | ||
if req.Capacity <= 0 { | ||
glog.Info(errZeroCapacity.Error()) | ||
glog.Errorf("err=%q", errZeroCapacity.Error()) |
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.
Same for some info on the logs about what this means / where it comes from.
And it has option to disable sorting 😄 I would prefer not to call sort for every log line. |
4d312d6
to
b6630c7
Compare
ce9e07a
to
5f5e23b
Compare
What does this pull request do? Explain your changes. (required)
Passes request specific information (manifestId, seqNo, etc) around and logs everywhere.
Specific updates (required)
Adds requests specific info (manfiestId, etc) to Context object, passes this context around.
Adds 'clog' module that must be used for logging instead of
glog
. This module takes provided context and logs info from the context along the message.How did you test each of these updates (required)
Manual
Does this pull request close any open issues?
Fixes #2102
Checklist:
make
runs successfully./test.sh
pass