Skip to content

Conversation

@gauravkghildiyal
Copy link

Previously, the stub package used a global logger instance, making it difficult for applications using the stub as a library to customize logging behavior, by using nrilog.Set():

nri/pkg/log/log.go

Lines 37 to 40 in 9b8befa

// Set the logger used by NRI.
func Set(l Logger) {
log = l
}

@chrishenzie
Copy link
Contributor

chrishenzie commented Oct 10, 2025

Could you expand on your use case here? How would you like to customize logging behavior in a way that is unsupported by the existing logger?

Edit: I see the dranet PR mentioned above. CC @klihub what are your thoughts?

@gauravkghildiyal
Copy link
Author

(Feel free to point out if there's an already existing way on how this can be achieved, but I'll share what I interpret here)

My understanding is that it likely has always been the intention to let logger be customizable, given NRI package exposes this Set function:

nri/pkg/log/log.go

Lines 37 to 40 in 9b8befa

// Set the logger used by NRI.
func Set(l Logger) {
log = l
}

But unfortunately the "stub" package already builds it's own logger at a global scope, thereby not allowing the library users an opportunity to even make use of the Set function

nri/pkg/stub/stub.go

Lines 190 to 192 in 9b8befa

var (
// Logger for messages generated internally by the stub itself.
log = nrilog.Get()

The logs that are generated currently by this library have this format (derived from logrus):

time="2025-10-10T16:44:12Z" level=info msg="Created plugin 00-dra.net (dranet, handles RunPodSandbox,StopPodSandbox,RemovePodSandbox,CreateContainer)"
time="2025-10-10T16:44:12Z" level=info msg="Registering plugin 00-dra.net..."
time="2025-10-10T16:44:12Z" level=info msg="Configuring plugin 00-dra.net for runtime containerd/2.0.6..."
time="2025-10-10T16:44:12Z" level=info msg="Started plugin 00-dra.net..."

Application using klog as their logger have this default format, as an example.

I1010 16:44:11.053616  156918 app.go:80] FLAG: --logtostderr="true"
I1010 16:44:11.053618  156918 app.go:80] FLAG: --one_output="false"
I1010 16:44:11.053619  156918 app.go:80] FLAG: --skip_headers="false"

This difference in the log format causes implications on how things like log severity are interpreted.

@klihub
Copy link
Member

klihub commented Oct 10, 2025

@gauravkghildiyal Wouldn't it be simpler to allow setting the package global logger in the stub from the outside? That would also have the benefit that if we ever add logging to stub package functions which don't have a receiver (IOW, are not stub.Stub 'member' functions) these would log consistently with the rest, including Stub instances.

So something like this:

// SetLogger sets the logger used to log messages internally generated by the stub package.
func SetLogger(l nrilog.Logger) nrilog.Logger {
    old := log
    log = l
    return old
}

// GetLogger returns the current logger user by the stub package.
func GetLogger() nrilog.Logger {
    return log
}

@klihub
Copy link
Member

klihub commented Oct 10, 2025

Could you expand on your use case here? How would you like to customize logging behavior in a way that is unsupported by the existing logger?

Edit: I see the dranet PR mentioned above. CC @klihub what are your thoughts?

@chrishenzie My comment (although not related to dranet in any way) is that in most cases when I used such a (type-scoped) logger as proposed in this PR, I regretted it later and eventually changed it to package-scoped instead, because sooner or later I ended up in a situation where I wanted/needed to log from a non-type-scoped function but had no logger, and in some cases the context was such that this could not be worked around by turning the functions into an artificially type-scoped one just to have access to the logger. Hence my comment for the alternative approach above.

@klihub klihub requested review from chrishenzie and klihub October 10, 2025 20:01
@aojea
Copy link
Contributor

aojea commented Oct 10, 2025

@pohly had to go through this recently with all the changes in klog and context logging in kubernetes, I think his experience can be very valuable, Patrick can you give us your opinion on this matter? what is the best way to plumb a custom logger in a library?

@pohly
Copy link

pohly commented Oct 15, 2025

because sooner or later I ended up in a situation where I wanted/needed to log from a non-type-scoped function but had no logger

This is tempting, but it is better to resist the temptation. It makes the assumption that there's only going to be a single log output stream for the entire package in a program at any given time. This prevents running unit tests in parallel with per-test log output. I don't know about this stub that is being discussed here, but is it really safe to assume that no downstream consumer of the package has a need to run two instances at the same time in their program?

It is very unfortunate that klog by design has a global per-program logger. I wish we hadn't. kubernetes/enhancements#3077 is about reducing it's usage.


registrationTimeout: DefaultRegistrationTimeout,
requestTimeout: DefaultRequestTimeout,
logger: nrilog.Get(),
Copy link
Member

@klihub klihub Oct 15, 2025

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@gauravkghildiyal I think it would also make sense to add a WithLogger(nrilog.Logger) Option option which would allow setting the used logger with a stub.Option.

@klihub
Copy link
Member

klihub commented Oct 15, 2025

because sooner or later I ended up in a situation where I wanted/needed to log from a non-type-scoped function but had no logger

This is tempting, but it is better to resist the temptation. It makes the assumption that there's only going to be a single log output stream for the entire package in a program at any given time. This prevents running unit tests in parallel with per-test log output. I don't know about this stub that is being discussed here, but is it really safe to assume that no downstream consumer of the package has a need to run two instances at the same time in their program?

That's true and is a valid point. IOW... no, it wouldn't be safe to assume that there would be only ever a single instance in a single program. Plus, right now we only ever internally generate log messages from a type-instance context, never from a package global context. And if we ever need to start doing that, we can always add a functions for setting that logger, too.

@pohly
Copy link

pohly commented Oct 15, 2025

And if we ever need to start doing that, we can always add a functions for setting that logger, too.

Or design those functions so that the caller can pass in a logger. It's more explicit that way.

This works best for functions which accept a ctx context.Context, but then you need to decide whether you want to use logr.FromContext (https://pkg.go.dev/github.com/go-logr/logr#FromContext) or slog-context.FromContext (https://pkg.go.dev/github.com/veqryn/slog-context#FromCtx) and the corresponding logger APIs.

@pohly
Copy link

pohly commented Oct 15, 2025

The two are interoperable: apps can pass a logr.Logger and your package can use slog, and vice-versa.

@klihub klihub self-requested a review October 16, 2025 14:27
Previously, the stub package used a global logger instance, making it
difficult for applications using the stub as a library to customize
logging behavior.

Co-authored-by: Krisztian Litkey <krisztian.litkey@intel.com>
Signed-off-by: Gaurav Ghildiyal <gauravkg@google.com>
Signed-off-by: Krisztian Litkey <krisztian.litkey@intel.com>
@klihub klihub force-pushed the configurable-logger branch from c679937 to 08a891a Compare October 29, 2025 08:01
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

5 participants