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

support/log: decouple logger and unit test concerns #4142

Merged
merged 10 commits into from
Dec 17, 2021

Conversation

sreuland
Copy link
Contributor

@sreuland sreuland commented Dec 14, 2021

PR Checklist

PR Structure

  • This PR has reasonably narrow scope (if not, break it down into smaller PRs).
  • This PR avoids mixing refactoring changes with feature changes (split into two PRs
    otherwise).
  • This PR's title starts with name of package that is most changed in the PR, ex.
    services/friendbot, or all or doc if the changes are broad or impact many
    packages.

Thoroughness

  • This PR adds tests for the most critical parts of the new functionality or fixes.
  • I've updated any docs (developer docs, .md
    files, etc... affected by this change). Take a look in the docs folder for a given service,
    like this one.

Release planning

  • I've updated the relevant CHANGELOG (here for Horizon) if
    needed with deprecations, added features, breaking changes, and DB schema changes.
  • I've decided if this PR requires a new major/minor version according to
    semver, or if it's mainly a patch change. The PR is targeted at the next
    release branch if it's not a patch change.

What

investigation of intermittent failures during 'test race' condition checks on CircleCI jobs led to likely source being unit test hook/unhook state applied on default logger, if any unit tests happen to run in parallel, they would by default be using the same default logger and potentially collide on concurrent access to aspects of hooked state.

Why

First alternative is to add mutex/thread sync around hooked state access in logger, but that seemed to add more complexity and potential brittleness to test infrastructure. Decided to take further step back first and looked at why was unit test and logger so tightly bound, since they should be unrelated. The reason is some unit tests were using the hooked logger to capture log output and then assert on the the logged output. That approach is likely opinionated/subjective, my initial reaction is that logs are code mechanics and don't represent or infer app functionality.

The unit tests that were asserting on log outputs also were asserting on more concrete functional outputs of the system/unit, so I tried an approach here of removing the code that bound unit-test to logger which should remove the intermittent race condition, allow unit tests to be a bit more agnostic, idempotent for different runtime environments.

Closes #4121

Known limitations

If asserting on log outputs is a must, then will need to revert to different approach that applies mutex/thread sync into unit-test/log hooks.

Sorry, something went wrong.

Verified

This commit was signed with the committer’s verified signature.
sreuland shawn
support/log/entry.go Outdated Show resolved Hide resolved

Verified

This commit was signed with the committer’s verified signature.
sreuland shawn

Verified

This commit was signed with the committer’s verified signature.
sreuland shawn
…t logger

Verified

This commit was signed with the committer’s verified signature.
sreuland shawn

Verified

This commit was signed with the committer’s verified signature.
sreuland shawn
Copy link
Member

@leighmcculloch leighmcculloch left a comment

Choose a reason for hiding this comment

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

One comment, see below, non-blocking.

support/http/logging_middleware_test.go Outdated Show resolved Hide resolved

Verified

This commit was signed with the committer’s verified signature.
sreuland shawn
…e services/horizon

Verified

This commit was signed with the committer’s verified signature.
sreuland shawn
Copy link
Member

@leighmcculloch leighmcculloch left a comment

Choose a reason for hiding this comment

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

One non-blocking suggestion, regardless, looks great to me 👏🏻. I'm no Horizon expert, so I defer to @ire-and-curses who had already commented.

services/horizon/internal/test/main.go Outdated Show resolved Hide resolved
sreuland and others added 2 commits December 15, 2021 12:09

Verified

This commit was signed with the committer’s verified signature.
sreuland shawn

Verified

This commit was created on GitHub.com and signed with GitHub’s verified signature. The key has expired.
@sreuland sreuland requested a review from a team December 16, 2021 16:22

Verified

This commit was signed with the committer’s verified signature.
sreuland shawn
…race_cond
@sreuland sreuland merged commit a04fe9e into stellar:master Dec 17, 2021
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.

intermittent CI test failures during 'go test race' condition checks on pull request(PR)
4 participants