klog icon indicating copy to clipboard operation
klog copied to clipboard

stderrthreshold not honored when logtostderr is set

Open aramase opened this issue 4 years ago • 49 comments

/kind bug

What steps did you take and what happened: [A clear and concise description of what the bug is.] We're using the klog logging framework in Secrets Store CSI Driver. When trying to set -stderrthreshold=ERROR with -logtostderr=true, we're seeing all the logs are being printed. Is this the expected behavior?

Users want to only log the ERROR but that doesn't seem like an option today? Is there any configuration that we're missing.

cc @tam7t

What did you expect to happen:

Anything else you would like to add: [Miscellaneous information that will assist in solving the issue.]

aramase avatar Feb 11 '21 18:02 aramase

Found this PR (https://github.com/kubernetes/klog/pull/31) which adds the severity check when logtostderr is set. This was however reverted https://github.com/kubernetes/klog/pull/50

aramase avatar Feb 11 '21 18:02 aramase

@pohly @dims could you please take a look?

pierluigilenoci avatar Feb 24 '21 15:02 pierluigilenoci

@DirectXMan12 @justinsb @neolit123 @mtaufen could you please take a look?

pierluigilenoci avatar Feb 25 '21 11:02 pierluigilenoci

@pohly @yuzhiquan @munnerz could you please take a look?

pierluigilenoci avatar Mar 04 '21 16:03 pierluigilenoci

Who needs to be tagged to get feedback?

@jayunit100 @hoegaarden @andyxning @yagonobre @vincepri @detiber @thockin @tallclair @piosz @brancz @lavalamp

pierluigilenoci avatar Mar 04 '21 17:03 pierluigilenoci

Everyone is extremely overloaded. This looks like it may be much more important to you than perhaps to some other people.

The description of the reversion PR is pretty clear about what went wrong. I recommend sending a PR that adds what you need while not triggering the problems mentioned there.

lavalamp avatar Mar 04 '21 17:03 lavalamp

@lavalamp I can understand that you are all loaded with work but this seems a pretty big bug for a logging library and it seems incredible to me that in two years no one has been able to fix it.

pierluigilenoci avatar Mar 09 '21 16:03 pierluigilenoci

@pierluigilenoci please re-read exactly what @lavalamp said. that's what you will hear from any one of us. good luck!

dims avatar Mar 09 '21 16:03 dims

Issues go stale after 90d of inactivity. Mark the issue as fresh with /remove-lifecycle stale. Stale issues rot after an additional 30d of inactivity and eventually close.

If this issue is safe to close now please do so with /close.

Send feedback to sig-contributor-experience at kubernetes/community. /lifecycle stale

fejta-bot avatar Jun 07 '21 17:06 fejta-bot

/remove-lifecycle stale

pierluigilenoci avatar Jun 08 '21 07:06 pierluigilenoci

@lavalamp @dims any chance to get the PR of @pierluigilenoci approved? Sorry for jumping in, but I am affected by a pod for Azure AKS which is using this library and generating high log storage costs per month ...

deyanp avatar Jul 28 '21 06:07 deyanp

@deyanp this is configurable from the command line as well as programatically, so sorry i don't see why the application developer using this library is unable to set this in one of those ways? can you please explain more?

dims avatar Jul 28 '21 10:07 dims

@dims , I cannot explain more, as I am not a contributor to the client library/application in question (using klog) - https://github.com/Azure/secrets-store-csi-driver-provider-azure ... My understanding is that the contributors of (e.g. @aramase ) are stating the bug is in klog ...

deyanp avatar Aug 04 '21 07:08 deyanp

I came across this same issue today when using the cluster-autoscaler. I concur with what others have stated here about the fact that stderrthreshold was not honored when logtostderr was set to true. However, it is honored when logtostderr is set to false. In addition, if you want to log to stderr then you can set logtostderr to false and then set stderrthreshold to a value that is less than ERROR (ex: INFO) and the logs will show up in stderr.

      - command:
        - ./cluster-autoscaler
        - --v=4
        - --stderrthreshold=info
        - --logtostderr=false

The code that is responsible for this logic can be found at https://github.com/kubernetes/klog/blob/main/klog.go#L938

This may not fulfill all use cases for individuals who have posted here, but I hope others find this information helpful.

jwmajors81 avatar Sep 28 '21 17:09 jwmajors81

The Kubernetes project currently lacks enough contributors to adequately respond to all issues and PRs.

This bot triages issues and PRs according to the following rules:

  • After 90d of inactivity, lifecycle/stale is applied
  • After 30d of inactivity since lifecycle/stale was applied, lifecycle/rotten is applied
  • After 30d of inactivity since lifecycle/rotten was applied, the issue is closed

You can:

  • Mark this issue or PR as fresh with /remove-lifecycle stale
  • Mark this issue or PR as rotten with /lifecycle rotten
  • Close this issue or PR with /close
  • Offer to help out with Issue Triage

Please send feedback to sig-contributor-experience at kubernetes/community.

/lifecycle stale

k8s-triage-robot avatar Dec 27 '21 18:12 k8s-triage-robot

/remove-lifecycle stale

pierluigilenoci avatar Jan 03 '22 17:01 pierluigilenoci

The Kubernetes project currently lacks enough contributors to adequately respond to all issues and PRs.

This bot triages issues and PRs according to the following rules:

  • After 90d of inactivity, lifecycle/stale is applied
  • After 30d of inactivity since lifecycle/stale was applied, lifecycle/rotten is applied
  • After 30d of inactivity since lifecycle/rotten was applied, the issue is closed

You can:

  • Mark this issue or PR as fresh with /remove-lifecycle stale
  • Mark this issue or PR as rotten with /lifecycle rotten
  • Close this issue or PR with /close
  • Offer to help out with Issue Triage

Please send feedback to sig-contributor-experience at kubernetes/community.

/lifecycle stale

k8s-triage-robot avatar Apr 03 '22 17:04 k8s-triage-robot

/remove-lifecycle stale

pierluigilenoci avatar Apr 04 '22 07:04 pierluigilenoci

This is a really big bug, I'm amazed that nobody cares. 🙌🏻

pierluigilenoci avatar Apr 04 '22 07:04 pierluigilenoci

@pierluigilenoci I'd refer you again to the comment above - based on responses to this issue, it seems like it is far more important of an issue for you than it is for others. This is a community, collaborative project which means you are equally able to work on a patch and fix this 😊 changing lifecycle labels alone won't drive this issue closer to completion.

Everyone is extremely overloaded. This looks like it may be much more important to you than perhaps to some other people.

The description of the reversion PR is pretty clear about what went wrong. I recommend sending a PR that adds what you need while not triggering the problems mentioned there.

munnerz avatar Apr 04 '22 08:04 munnerz

Ah, I see your draft PR open too - my bad 😊 are you able to work on this and drive it to a non-draft state?

munnerz avatar Apr 04 '22 08:04 munnerz

And do it without breaking compatibility with existing users of klog?

pohly avatar Apr 04 '22 08:04 pohly

@munnerz my PR needs to be fixed and I still haven't found the time to do it. I also have little drive to do it because I know it wouldn't be particularly appreciated anyway. @pohly for me, a fix for this bug may not be backward compatible.

pierluigilenoci avatar Apr 04 '22 08:04 pierluigilenoci

for me, a fix for this bug may not be backward compatible.

That's the key problem then: we cannot break existing users unless it is a clear bug fix that everyone wants, and in this case it just seems about confusing behavior. The issue descriptions asks "Is this the expected behavior?" and the answer is "probably, because that is what the current implementation does".

pohly avatar Apr 04 '22 09:04 pohly

@pohly the answer to "Is this the expected behavior?" is certainly: "Absolutely not but changing it breaks things so we keep it broken". 😉

pierluigilenoci avatar Apr 04 '22 10:04 pierluigilenoci

From Klog docs

-logtostderr=true
	Logs are written to standard error instead of to files.
-alsologtostderr=false
	Logs are written to standard error as well as to files.
-stderrthreshold=ERROR
	Log events at or above this severity are logged to standard
	error as well as to files.

pierluigilenoci avatar Apr 04 '22 10:04 pierluigilenoci

According to this, -stderrthreshold only applies when writing to files and stderr ("Log events at or above this severity are logged to standard error as well as to files." - emphasis mine).

The name could be clearer, but that ship has sailed.

A bug fix would be to say:

-logtostderr=true
	Logs are written to standard error instead of to files. -alsologtostderr and -stderrthreshold have no effect when enabled.

pohly avatar Apr 04 '22 10:04 pohly

What you want is:

-stderrthreshold=ERROR
	Only log events at or above this severity are logged to standard error, regardless
        of the settings for -logtostderr and -alsologtostderr-alsologtostderr.

That is a change of existing functionality.

In this case, "intended behavior" = "what was implemented and users started to rely upon", not "how command line flags might be understood".

pohly avatar Apr 04 '22 10:04 pohly

What users "rely upon" is a side effect of a "bad" implementation or "poor" documentation writing. For me, it is the first since I find the second interpretation a stretch.

In my opinion, there is little to interpret in the docs.

  • logtostderr is pretty clear: errors only go to stderr. No doubt.
  • alsologtostderr says that the logs go to both sides, stderr and file. No doubt. The only room for interpretation is if both are configured, which of the two has "priority" since they are in contrast.

Another thing is stderrthreshold. This flag creates a "filter" for the level of logs pushed to stderr. It is used to configure another aspect.

On one side "where" (logtostderr and alsologtostderr) on the other "what" (stderrthreshold). For me, therefore, the intended behavior is quite clear.

Regardless of log philosophy dissertations, one thing remains clear. There is currently no way to configure Klog to send log to stderr with only the ERROR level.

pierluigilenoci avatar Apr 04 '22 11:04 pierluigilenoci

In fact, in a pragmatic way, I had added, in my PR, a new flag called alsologtostderrthreshold that acts exactly on what you say. To put a filter for alsologtostderr.

I got stuck when I saw that I couldn't find a way not to break the current behavior given the current implementation.

pierluigilenoci avatar Apr 04 '22 11:04 pierluigilenoci