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

Update Logrus to fix logging in tests #9712

Closed
wants to merge 5 commits into from
Closed

Conversation

jakule
Copy link
Contributor

@jakule jakule commented Jan 8, 2022

After removing vendor/ folder caller in our unit tests prints internal logger location instead of the real one where log was called, example:

Step #1 - "run-tests": 2022-01-07T21:06:35Z DEBU [BUFFER]    Removing watcher 0xc002d80300 via external close. logrus@v1.4.4-0.20210817004754-047e20245621/entry.go:289
Step #1 - "run-tests": 2022-01-07T21:06:35Z DEBU [BUFFER]    Removing watcher 0xc001774480 via external close. logrus@v1.4.4-0.20210817004754-047e20245621/entry.go:289
Step #1 - "run-tests": 2022-01-07T21:06:35Z DEBU [PROXY:SER] Context is closing. cluster:localhost logrus@v1.4.4-0.20210817004754-047e20245621/entry.go:289
Step #1 - "run-tests": 2022-01-07T21:06:35Z DEBU [BUFFER]    Removing watcher 0xc002d80840 via external close. logrus@v1.4.4-0.20210817004754-047e20245621/entry.go:289

This bug was fixed upstream.

Until now we were using our own fork of logrus because of a race condition, but looks like this problem also has been fixed upstream: https://github.com/sirupsen/logrus/blame/v1.7.0/entry.go#L268-L279
I also updated the version in our API module as we're using there upstream version anyways.

@zmb3
Copy link
Collaborator

zmb3 commented Jan 8, 2022

What's wrong with logrus 1.8.1?

@jakule
Copy link
Contributor Author

jakule commented Jan 8, 2022

@zmb3 This sirupsen/logrus@ac6e35b
It reverts the patch that we need (reverted in 1.7.1). I'm thinking now about adding 1.7.0 to replace section in our go.mod so we know that we always use the same version.

@zmb3
Copy link
Collaborator

zmb3 commented Jan 9, 2022

I'm not sure I understand. So logrus had a race condition, they fixed it in 1.7.0, and then they rolled back the fix and the bug is present again?

@jakule
Copy link
Contributor Author

jakule commented Jan 9, 2022

@zmb3 Pretty much. The one thing that can be not clear here is when the race happen. In order to trigger that behavior you need to call SetFormatter() and then try to print a log message at the same time. This is what causes race in our tests as we call SetFormatter() every time we load config:

logger.SetFormatter(formatter)

This is our internal fix gravitational/logrus@047e202 which matches code in 1.7.0.
I checked the logrus history and they introduced the same fix around 1.6 I think and changed/reverted back to old form in 1.7.1 as a part of another fix.

Probably the second option would be to not call SetFormatter() multiple times and use the latest version, but this more work that just version update.
Third option would be to update our fork and re-apply our fix once again.

@zmb3
Copy link
Collaborator

zmb3 commented Jan 10, 2022

Got it. I'm fine with this fix, was just trying to understand.

Using the replace directive to pin the version is something I haven't seen before. Is that necessary?

@espadolini
Copy link
Contributor

How does this relate to #9689?

@jakule
Copy link
Contributor Author

jakule commented Jan 10, 2022

@zmb3 I don't think pinning in this way is very common, but AFAIK this is the only way to pin some dependency in Go to a particular version. On thing that is not clear about Go modules is what version of a modules is used when you build something, as GO doesn't allow a multiple version of the same library. For example, if we depend on logrus 1.7 then Go will use 1.7, unless one of our dependencies depends on logrus in a never version. Go will include a never version of logrus in our build (as or dependency require it), which we don't want to. Here is the documentation describing that https://go.dev/ref/mod#minimal-version-selection
I'd assume that go.mod is updated if that happens, but I don't think everyone would remember to check the version of our logger after calling go get or similar. With replace and a comment I think makes it clearer of what version we want to use and why.

@espadolini I checked and I don't think that gravitational is no longer needed after upgrading the logger. Looks like logrus 1.5 had some fixes in this area (previously we were using 1.4.x). I reverted your patch and with upgraded logger the caller location is correct.
Are you ok with reverting #9689 or you see any potential problems with that?

@espadolini
Copy link
Contributor

If we end up using the upstream logrus then the check on formatter should be cleaned up, I'm on board with that.

@@ -342,7 +342,7 @@ func formatCallerWithPathAndLine() (path string) {
return ""
}

var frameIgnorePattern = regexp.MustCompile(`github\.com/(gravitational|(S|s)irupsen)/logrus`)
var frameIgnorePattern = regexp.MustCompile(`github\.com/((S|s)irupsen)/logrus`)
Copy link
Contributor

Choose a reason for hiding this comment

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

Maybe we could drop the weird (S|s) and do a case-insensitive match instead?

Copy link
Contributor Author

Choose a reason for hiding this comment

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

I don't think that case-insensitive compare is a good fit as it's slower that the current one. But I also think we can drop S at all. Currently the logrus package is called "github.com/sirupsen/logrus" and I don't think that anyone uses the old one anymore (I checked our current dependencies and I don't see it).

@jakule
Copy link
Contributor Author

jakule commented Jan 11, 2022

After talking with Roman I'm closing this PR in favor of #9738

@jakule jakule closed this Jan 11, 2022
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.

None yet

4 participants