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

Improve logging #1171

Merged
merged 9 commits into from
Jun 17, 2022
Merged

Improve logging #1171

merged 9 commits into from
Jun 17, 2022

Conversation

ZauberNerd
Copy link
Contributor

Replace more of the global logger call sites with contextualized job/step loggers and add job/step id and results as fields to the JSON logger output.

This causes most debug logs to be printed with the job logger, which means they are now correctly prefixed with the job they belong to.
Also, having the ids and results in the JSON output helps in cases where the log is read by machines, because we now can attribute each line to a job/step.

@github-actions
Copy link
Contributor

github-actions bot commented May 17, 2022

MegaLinter status: ✅ SUCCESS

Descriptor Linter Files Fixed Errors Elapsed time
✅ CREDENTIALS secretlint yes no 1.18s
✅ EDITORCONFIG editorconfig-checker 33 0 0.1s
✅ GIT git_diff yes no 0.01s

See errors details in artifact MegaLinter reports on CI Job page
Set VALIDATE_ALL_CODEBASE: true in mega-linter.yml to validate all sources, not only the diff

@codecov
Copy link

codecov bot commented May 18, 2022

Codecov Report

Merging #1171 (a08496c) into master (4f8da0a) will increase coverage by 4.89%.
The diff coverage is 76.62%.

@@            Coverage Diff             @@
##           master    #1171      +/-   ##
==========================================
+ Coverage   57.50%   62.40%   +4.89%     
==========================================
  Files          32       40       +8     
  Lines        4594     5402     +808     
==========================================
+ Hits         2642     3371     +729     
- Misses       1729     1769      +40     
- Partials      223      262      +39     
Impacted Files Coverage Δ
pkg/model/action.go 0.00% <0.00%> (ø)
pkg/model/step_result.go 0.00% <ø> (ø)
pkg/model/workflow.go 54.29% <0.00%> (+3.38%) ⬆️
pkg/container/docker_run.go 15.18% <21.73%> (+9.64%) ⬆️
pkg/container/docker_pull.go 33.33% <33.33%> (ø)
pkg/container/file_collector.go 44.85% <44.85%> (ø)
pkg/common/git/git.go 50.00% <47.91%> (ø)
pkg/container/docker_auth.go 47.61% <50.00%> (+2.61%) ⬆️
pkg/exprparser/interpreter.go 73.37% <53.48%> (-0.02%) ⬇️
pkg/artifacts/server.go 67.53% <60.00%> (+0.21%) ⬆️
... and 30 more

📣 Codecov can now indicate which changes are the most critical in Pull Requests. Learn more

@ZauberNerd ZauberNerd marked this pull request as ready for review May 18, 2022 08:43
@ZauberNerd ZauberNerd requested a review from a team as a code owner May 18, 2022 08:43
KnisterPeter
KnisterPeter previously approved these changes May 18, 2022
@ZauberNerd ZauberNerd marked this pull request as draft May 18, 2022 12:54
@ZauberNerd ZauberNerd changed the base branch from master to implement-pre-and-post-steps May 18, 2022 12:55
@ZauberNerd
Copy link
Contributor Author

Rebased this PR against the pre-post PR #1089 and marked it as draft.
Let's get #1089 merged first.

@ZauberNerd ZauberNerd force-pushed the improve-logging branch 3 times, most recently from 8292684 to 53cceb7 Compare May 19, 2022 15:30
Base automatically changed from implement-pre-and-post-steps to master May 24, 2022 13:36
@mergify mergify bot requested a review from a team May 24, 2022 15:13
KnisterPeter
KnisterPeter previously approved these changes May 25, 2022
@mergify
Copy link
Contributor

mergify bot commented Jun 8, 2022

@ZauberNerd this pull request is now in conflict 😩

@mergify mergify bot added the conflict PR has conflicts label Jun 8, 2022
@mergify mergify bot removed the conflict PR has conflicts label Jun 8, 2022
@mergify
Copy link
Contributor

mergify bot commented Jun 8, 2022

@ZauberNerd this pull request has failed checks 🛠

@mergify mergify bot added the needs-work Extra attention is needed label Jun 8, 2022
@mergify mergify bot removed the needs-work Extra attention is needed label Jun 8, 2022
@mergify mergify bot requested a review from a team June 8, 2022 16:24
@mergify
Copy link
Contributor

mergify bot commented Jun 10, 2022

@ZauberNerd this pull request is now in conflict 😩

@mergify mergify bot added the conflict PR has conflicts label Jun 10, 2022
ZauberNerd and others added 8 commits June 13, 2022 13:31
Co-authored-by: Markus Wolf <markus.wolf@new-work.se>
Co-authored-by: Markus Wolf <markus.wolf@new-work.se>
Co-authored-by: Markus Wolf <markus.wolf@new-work.se>
Co-authored-by: Markus Wolf <markus.wolf@new-work.se>
Co-authored-by: Markus Wolf <markus.wolf@new-work.se>
The container gets injected a job logger, but during the time that steps
are run, we want to use the step logger.
This commit wraps pre/main/post steps in an executor that replaces the
job logger with a step logger.

Co-authored-by: Markus Wolf <markus.wolf@new-work.se>
Co-authored-by: Markus Wolf <markus.wolf@new-work.se>
Co-authored-by: Markus Wolf <markus.wolf@new-work.se>
@mergify mergify bot removed the conflict PR has conflicts label Jun 13, 2022
} else {
err := info.stopContainer()(ctx)
if err != nil {
return err
}
info.result("success")
logger.WithField("jobResult", "success").Infof("\U0001F3C1 Job succeeded")
Copy link
Contributor

Choose a reason for hiding this comment

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

I get a misleading logging message, this job doesn't succeed. I cancelled it.

🚀  Start image=ghcr.io/catthehacker/ubuntu:act-latest
  🐳  docker pull image=ghcr.io/catthehacker/ubuntu:act-latest platform= username= forcePull=false
🏁  Job succeeded
Warning: unable to get git repo: unable to find git repo
Error: context canceled

Probably a bug, which hasn't surfaced earlier.

I'm testing this change against my selfhosted runner code

I cancelled while it was downloading the docker image for the job

@mergify mergify bot requested a review from a team June 16, 2022 18:32
Copy link
Contributor

@ChristopherHX ChristopherHX left a comment

Choose a reason for hiding this comment

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

Seems to work fine.
I wonder why this single warning bypassed my logger, both global and context logger have an custom formatter. The later warnings of the same kind are working as expected and call my formatter.

time="2022-06-16T21:19:42+02:00" level=warning msg="unable to get git repo: unable to find git repo"

Copy link
Contributor

@cplee cplee left a comment

Choose a reason for hiding this comment

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

Thanks for this @ZauberNerd - sorry for delays in review

@mergify mergify bot merged commit 4391a10 into master Jun 17, 2022
@mergify mergify bot deleted the improve-logging branch June 17, 2022 15:55
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

4 participants