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

⚠️ Fix some more races in the delegating logger #1361

Merged
merged 1 commit into from Jan 27, 2021

Conversation

alvaroaleman
Copy link
Member

@alvaroaleman alvaroaleman commented Jan 26, 2021

The delegatingLogger had a logger implementation embedded, calling any
method of that would race with FullFill(), which replaces the embedded
logger.

/cc @charith-elastic
Can you verify this fixes all remaining races?

Fixes #1359

@k8s-ci-robot
Copy link
Contributor

@alvaroaleman: GitHub didn't allow me to request PR reviews from the following users: charith-elastic.

Note that only kubernetes-sigs members and repo collaborators can review this PR, and authors cannot review their own PRs.

In response to this:

The delegatingLogger had a logger implementation embedded, calling any
method of that would race with FullFill(), which replaces the embedded
logger.

/cc @charith-elastic
Can you verify this fixes all remaining races?

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.

@k8s-ci-robot k8s-ci-robot added cncf-cla: yes Indicates the PR's author has signed the CNCF CLA. approved Indicates a PR has been approved by an approver from all required OWNERS files. size/M Denotes a PR that changes 30-99 lines, ignoring generated files. labels Jan 26, 2021
@alvaroaleman alvaroaleman force-pushed the more-racing branch 4 times, most recently from 6970aa9 to 8992715 Compare January 26, 2021 18:00
@k8s-ci-robot k8s-ci-robot added size/L Denotes a PR that changes 100-499 lines, ignoring generated files. and removed size/M Denotes a PR that changes 30-99 lines, ignoring generated files. labels Jan 26, 2021
@charith-elastic
Copy link
Contributor

Seems to work. Thanks @alvaroaleman

If I understand your change correctly, wouldn't it require a lock to be obtained on every logging call even after the promise is fulfilled? Wouldn't that add some overhead?

@alvaroaleman
Copy link
Member Author

If I understand your change correctly, wouldn't it require a lock to be obtained on every logging call even after the promise is fulfilled? Wouldn't that add some overhead?

Good point. I've replaced the Mutex with a RWMutex, that should minimize the overhead. We will always need something to check if the promise was fulfilled, unfortunately.

@alvaroaleman
Copy link
Member Author

/assign @vincepri @estroz

WDYT about including this in 0.8? This change is incompatible in that if anyone ever did a delgatingLogger.Logger.Something, that wouldn't work anymore, but I very much hope no one does that, as it would defeat the purpose of the whole thing. OTOH it is fixing a data race, so that would be good to have in the release IMHO

@vincepri
Copy link
Member

Given that this is a bug that could cause a race condition (and corruption), I'm +1 merging as ⚠️ and open backport PRs as well

The delegatingLogger had a logger implementation embedded, calling any
method of that would race with FullFill(), which replaces the embedded
logger.
@alvaroaleman alvaroaleman changed the title 🐛 Fix some more races in the delegating logger ⚠️ Fix some more races in the delegating logger Jan 27, 2021
@alvaroaleman
Copy link
Member Author

Updated the title to be :warning: (what are our title rules for something that is both breaking and a bugfix?)

@k8s-ci-robot
Copy link
Contributor

@alvaroaleman: The following test failed, say /retest to rerun all failed tests:

Test name Commit Details Rerun command
pull-controller-runtime-apidiff-master ab23736 link /test pull-controller-runtime-apidiff-master

Full PR test history. Your PR dashboard. Please help us cut down on flakes by linking to an open issue when you hit one in your PR.

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. I understand the commands that are listed here.

}

// WithName provides a new Logger with the name appended
Copy link
Contributor

Choose a reason for hiding this comment

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

Removing godocs?

Copy link
Contributor

Choose a reason for hiding this comment

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

I guess it doesn't matter because its an interface method

Copy link
Member Author

Choose a reason for hiding this comment

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

Err yeah sorry, I abused this to check if the linter correctly doesn't care about godocs of exported methods on unexported types (which it does). Since it is only visible from within the package it doesn't matter much IMO

Comment on lines +128 to +129
l.lock.RLock()
defer l.lock.RUnlock()
Copy link
Contributor

@estroz estroz Jan 27, 2021

Choose a reason for hiding this comment

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

Shouldn't these be write locks? Isn't Info writing to the underlying logger here?

Copy link
Member Author

Choose a reason for hiding this comment

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

The Lock protects the reference to the logger, not the method call. The actual logger implementation must also be threadsafe, but that needs to be done in that implementation, not here. Everything except Fullfill only reads the reference (as proven by the included tests not failing with a data race)

Copy link
Member Author

Choose a reason for hiding this comment

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

If we care about that, I can update the PR later to only use the lock to get the logger reference and not around the whole method call, which might improve performance slightly

Copy link
Contributor

Choose a reason for hiding this comment

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

Up to you.

Copy link
Member Author

Choose a reason for hiding this comment

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

Then I'll keep it as-is, only protecting the reference would require to allocate a pointer so it might actually be worse performance-wise and is more complex

Copy link
Contributor

@estroz estroz 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 Jan 27, 2021
@k8s-ci-robot
Copy link
Contributor

[APPROVALNOTIFIER] This PR is APPROVED

This pull-request has been approved by: alvaroaleman, estroz

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

This was referenced Mar 11, 2021
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/L Denotes a PR that changes 100-499 lines, ignoring generated files.
Projects
None yet
Development

Successfully merging this pull request may close these issues.

Data race in the delegating logger
5 participants