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

⚠️ Remove logs from internal controller #1096

Merged
merged 1 commit into from Aug 6, 2020

Conversation

vincepri
Copy link
Member

@vincepri vincepri commented Aug 3, 2020

Reconciliation errors are going to be logged only if V >= 3,
while success reconciliations are set for V >= 5.

Signed-off-by: Vince Prignano vincepri@vmware.com

/assign @alvaroaleman @detiber
Set this as a ⚠️, but we can probably merge in v0.6.2 with a release note for the impact in case we want to.

@k8s-ci-robot k8s-ci-robot added the cncf-cla: yes Indicates the PR's author has signed the CNCF CLA. label Aug 3, 2020
@k8s-ci-robot
Copy link
Contributor

[APPROVALNOTIFIER] This PR is APPROVED

This pull-request has been approved by: vincepri

The full list of commands accepted by this bot can be found here.

The pull request process is described here

Needs approval from an approver in each of these files:

Approvers can indicate their approval by writing /approve in a comment
Approvers can cancel approval by writing /approve cancel in a comment

@k8s-ci-robot k8s-ci-robot added approved Indicates a PR has been approved by an approver from all required OWNERS files. size/XS Denotes a PR that changes 0-9 lines, ignoring generated files. labels Aug 3, 2020
@vincepri vincepri changed the title ⚠️ Increase log levels for controller info and errors ⚠️ Increase log levels for controller info and errors Aug 3, 2020
@detiber
Copy link
Member

detiber commented Aug 3, 2020

lgtm, I don't have any particular preference related to which version to target for this change.

@@ -234,7 +234,9 @@ func (c *Controller) reconcileHandler(obj interface{}) bool {
// resource to be synced.
if result, err := c.Do.Reconcile(req); err != nil {
c.Queue.AddRateLimited(req)
log.Error(err, "Reconciler error")
if log.V(3).Enabled() {
Copy link
Member

Choose a reason for hiding this comment

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

For successes I understand the change but for errors?

Copy link
Member Author

Choose a reason for hiding this comment

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

There was some discussion on the other PR, to have the error only logged on higher verbosity, chances are that folks using loggers are already logging errors on their own.

Copy link
Member

Choose a reason for hiding this comment

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

hances are that folks using loggers are already logging errors on their own.

Maybe? We don't know that and only the ppl that do use their own logger will speak up about this being too noisy. Also, the general direction we are going is to get ppl to use the integrated loggers or not?

IMHO this is pretty much the definition of an error so increasing the verbosity seems wrong to me.

Copy link
Member Author

Choose a reason for hiding this comment

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

I would be in favor of removing these logs altogether in v0.7.x if we're not ok to use verbosity for an error

@ncdc @detiber thoughts here?

Copy link
Member

Choose a reason for hiding this comment

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

Another potential option would be to extend the current use of context w/ logger so that a calling controller can more easily modify the context and have the errors logging here use the logger from the context.

Then we could avoid doing the error logging in the called code (which we currently prefer for the more detailed information it provides), and have the logging here be done with the additional context that is provided by the called reconciler.

That would save having to remember to log errors everywhere on the error path for reconcilers, avoid losing context related to the logging.

Main downside is that it would still potentially log the wrong filename/line number for the error. I'm not sure if there is a better way to handle that generically, though.

Copy link
Member

Choose a reason for hiding this comment

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

I guess my point is that we pretty much don't know if and how ppl use these today and I think if we require debug logging to be enabled to see them, then we can also remove those log statements altogether (but probably for 0.7).

Then we could avoid doing the error logging in the called code (which we currently prefer for the more detailed information it provides), and have the logging here be done with the additional context that is provided by the called reconciler.

So basically tell ppl to put the logger back into the ctx if they add additional fields and then re-use that logger here to get these fields?

Main downside is that it would still potentially log the wrong filename/line number for the error. I'm not sure if there is a better way to handle that generically, though.

Do you have that today? For most (all?) controllers I have worked on there is a function call in the very beginning of the reconciler precicely to be able to log all errors. That log line doesn't really have a useful line number associated.

Copy link
Contributor

Choose a reason for hiding this comment

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

My desire/goal/requirement is that when an error is logged, you have the file name and line number as close to where the error was created as possible. As things currently stand, this log line emits a file and line number that is about as far away from the error's source as possible. I find little to no value in this log message in its current form.

If there is some way for this log invocation to include the error's provenance, then I'm all for keeping it. Otherwise, my vote is to remove it.

Copy link
Member Author

Choose a reason for hiding this comment

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

Removed it, and increased the info log to 5

@vincepri vincepri changed the title ⚠️ Increase log levels for controller info and errors ⚠️ Remove error log in internal controller, set V=5 for Info Aug 4, 2020
@vincepri
Copy link
Member Author

vincepri commented Aug 4, 2020

/milestone v0.7.x

@k8s-ci-robot k8s-ci-robot added this to the v0.7.x milestone Aug 4, 2020
@vincepri
Copy link
Member Author

vincepri commented Aug 5, 2020

@alvaroaleman This should be good to go

@alvaroaleman
Copy link
Member

@vincepri I think we should either remove both of those or keep both, not logging on error but logging on success does not really make sense

@k8s-ci-robot k8s-ci-robot added the needs-rebase Indicates a PR cannot be merged because it has merge conflicts with HEAD. label Aug 5, 2020
@vincepri
Copy link
Member Author

vincepri commented Aug 5, 2020

I'm fine removing both

Signed-off-by: Vince Prignano <vincepri@vmware.com>
@vincepri vincepri changed the title ⚠️ Remove error log in internal controller, set V=5 for Info ⚠️ Remove logs from internal controller Aug 5, 2020
@k8s-ci-robot k8s-ci-robot removed the needs-rebase Indicates a PR cannot be merged because it has merge conflicts with HEAD. label Aug 5, 2020
Copy link
Member

@alvaroaleman alvaroaleman left a comment

Choose a reason for hiding this comment

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

/lgtm

@k8s-ci-robot k8s-ci-robot added the lgtm "Looks good to me", indicates that a PR is ready to be merged. label Aug 6, 2020
@vincepri
Copy link
Member Author

vincepri commented Aug 6, 2020

/test pull-controller-runtime-test-master

@vincepri
Copy link
Member Author

vincepri commented Aug 6, 2020

/retest

@alvaroaleman
Copy link
Member

For posterity, this was re-introduced in #1245

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
approved Indicates a PR has been approved by an approver from all required OWNERS files. cncf-cla: yes Indicates the PR's author has signed the CNCF CLA. lgtm "Looks good to me", indicates that a PR is ready to be merged. size/XS Denotes a PR that changes 0-9 lines, ignoring generated files.
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

5 participants