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

logging.logger and logging.filter: insufficient mutex protection #285

Closed
pohly opened this issue Feb 7, 2022 · 4 comments
Closed

logging.logger and logging.filter: insufficient mutex protection #285

pohly opened this issue Feb 7, 2022 · 4 comments
Labels
kind/bug Categorizes issue or PR as related to a bug.

Comments

@pohly
Copy link

pohly commented Feb 7, 2022

/kind bug

What steps did you take:

Code reading...

What did you expect to happen:

SetLogger/ClearLogger/SetFilter lock logging.mu, which implies that they were meant to be concurrency-safe. However, several other functions access the underlying fields without locking, so that protection is currently useless.

klog/klog.go

Lines 1398 to 1428 in e7e4115

func newVerbose(level Level, b bool) Verbose {
if logging.logr == nil {
return Verbose{b, nil, logging.filter}
}
v := logging.logr.V(int(level))
return Verbose{b, &v, logging.filter}
}
// V reports whether verbosity at the call site is at least the requested level.
// The returned value is a struct of type Verbose, which implements Info, Infoln
// and Infof. These methods will write to the Info log if called.
// Thus, one may write either
// if glog.V(2).Enabled() { klog.Info("log this") }
// or
// klog.V(2).Info("log this")
// The second form is shorter but the first is cheaper if logging is off because it does
// not evaluate its arguments.
//
// Whether an individual call to V generates a log record depends on the setting of
// the -v and -vmodule flags; both are off by default. The V call will log if its level
// is less than or equal to the value of the -v flag, or alternatively if its level is
// less than or equal to the value of the -vmodule pattern matching the source file
// containing the call.
func V(level Level) Verbose {
// This function tries hard to be cheap unless there's work to do.
// The fast path is two atomic loads and compares.
// Here is a cheap but safe test to see if V logging is enabled globally.
if logging.verbosity.get() >= level {
return newVerbose(level, true)
}

klog/klog.go

Line 1550 in e7e4115

logging.print(infoLog, logging.logr, logging.filter, args...)

We can either:

  • add mutex locking to all package-level functions (will cause additional overhead!) or
  • clarify that SetLogger/ClearLogger/SetFilter are meant to be called while it is safe to do so (typically during program init before starting goroutines)
@k8s-ci-robot k8s-ci-robot added the kind/bug Categorizes issue or PR as related to a bug. label Feb 7, 2022
@pohly
Copy link
Author

pohly commented Feb 7, 2022

I'm leaning towards updating the documentation and not adding mutex locking. That seems more useful in practice and in particular will not make klog worse for those who don't use SetLogger or SetFilter.

@serathius
Copy link

I agree with documentation update as it follows original intention of those functions being called once during initial program setup by only one goroutine.

@pohly
Copy link
Author

pohly commented Feb 10, 2022

Resolved via #289

/close

@k8s-ci-robot
Copy link

@pohly: Closing this issue.

In response to this:

Resolved via #289

/close

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the kubernetes/test-infra repository.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
kind/bug Categorizes issue or PR as related to a bug.
Projects
None yet
Development

No branches or pull requests

3 participants