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

feat: Refine the Atlantis Info Message Logging #5034

Merged
merged 14 commits into from
Nov 19, 2024

Conversation

X-Guardian
Copy link
Contributor

@X-Guardian X-Guardian commented Oct 23, 2024

what

Refine the Info logging messages that Atlantis produces in the following areas:

  • Add repo and pull annotations on all VCS logs.
  • Replace double quotes in log string with single quotes to avoid JSON escaping.
  • Remove superfluous repo and pull details in log messages where it is annotated.
  • Enhance command runner autoplan logging.
  • Enhance pre/post workflow hook start, end and error logging.
  • Change VCS check status debug messages to info messages
  • Fix 'Supported VCS Hosts' log entry
  • Change web server 'apply lock' entry from info to debug.

why

Improve the logging to help resolve future issues.

tests

Tested locally

Sample Logs

Current
{"level":"info","ts":"2024-11-08T17:32:07.197Z","caller":"vcs/gitlab_client.go:111","msg":"determined GitLab is running version 17.5.0","json":{}}
{"level":"info","ts":"2024-11-08T17:32:07.199Z","caller":"server/server.go:320","msg":"Supported VCS Hosts%!(EXTRA string=hosts, []models.VCSHostType=[Gitlab])","json":{}}
{"level":"info","ts":"2024-11-08T17:32:07.523Z","caller":"server/server.go:473","msg":"Utilizing BoltDB","json":{}}
{"level":"info","ts":"2024-11-08T17:32:07.538Z","caller":"policy/conftest_client.go:167","msg":"failed to get default conftest version. Will attempt request scoped lazy loads DEFAULT_CONFTEST_VERSION not set","json":{}}
{"level":"info","ts":"2024-11-08T17:32:07.538Z","caller":"server/server.go:1043","msg":"Atlantis started - listening on port 4141","json":{}}
{"level":"info","ts":"2024-11-08T17:32:07.539Z","caller":"scheduled/executor_service.go:51","msg":"Scheduled Executor Service started","json":{}}
{"level":"info","ts":"2024-11-08T17:32:26.208Z","caller":"events/events_controller.go:656","msg":"parsed comment as command=\"plan\", verbose=false, dir=\"\", workspace=\"\", project=\"\", policyset=\"\", auto-merge-disabled=false, auto-merge-method=, clear-policy-approval=false, flags=\"\"","json":{"repo":"sheather/test","pull":31}}
{"level":"info","ts":"2024-11-08T17:32:27.269Z","caller":"events/events_controller.go:699","msg":"Running comment command 'plan' on repo 'sheather/test', pull request: 31 for user 'sheather'.","json":{"repo":"sheather/test","pull":31}}
{"level":"info","ts":"2024-11-08T17:32:30.745Z","caller":"runtime/pre_workflow_hook_runner.go:80","msg":"successfully ran \"bash -ce echo \\\"Terraform Version: $ATLANTIS_TERRAFORM_VERSION\\\"\\n\" in \"/root/.atlantis/repos/sheather/test/31/default\"","json":{"repo":"sheather/test","pull":"31"}}
{"level":"warn","ts":"2024-11-08T17:32:33.186Z","caller":"events/plan_command_runner.go:192","msg":"unable to update commit status: POST https://gitlab.lan/api/v4/projects/sheather/test/statuses/a1e2908f540bd9e0b9beb57ace6ebbdecf57bc9b: 400 {message: Cannot transition status via :run from :running (Reason(s): Status cannot transition via \"run\")}","json":{"repo":"sheather/test","pull":"31"},"stacktrace":"github.com/runatlantis/atlantis/server/events.(*PlanCommandRunner).run\n\t/mnt/c/Users/Simon/Documents/GitHub/X-Guardian/atlantis/server/events/plan_command_runner.go:192\ngithub.com/runatlantis/atlantis/server/events.(*PlanCommandRunner).Run\n\t/mnt/c/Users/Simon/Documents/GitHub/X-Guardian/atlantis/server/events/plan_command_runner.go:307\ngithub.com/runatlantis/atlantis/server/events.(*DefaultCommandRunner).RunCommentCommand\n\t/mnt/c/Users/Simon/Documents/GitHub/X-Guardian/atlantis/server/events/command_runner.go:389"}
{"level":"info","ts":"2024-11-08T17:32:33.532Z","caller":"events/project_command_builder.go:496","msg":"found no atlantis.yaml file","json":{"repo":"sheather/test","pull":"31"}}
{"level":"info","ts":"2024-11-08T17:32:33.532Z","caller":"events/project_finder.go:147","msg":"filtered modified files to 1 file(s) in the autoplan file list: [live/aws/123456789012/develop/eu-west-2/stack11/main.tf]","json":{"repo":"sheather/test","pull":"31"}}
{"level":"info","ts":"2024-11-08T17:32:33.533Z","caller":"events/project_finder.go:176","msg":"there are 1 modified project(s) at path(s): live/aws/123456789012/develop/eu-west-2/stack11","json":{"repo":"sheather/test","pull":"31"}}
{"level":"info","ts":"2024-11-08T17:32:33.533Z","caller":"events/project_command_builder.go:518","msg":"automatically determined that there were 1 additional projects modified in this pull request: [repofullname=sheather/test path=live/aws/123456789012/develop/eu-west-2/stack11]","json":{"repo":"sheather/test","pull":"31"}}
{"level":"info","ts":"2024-11-08T17:32:33.533Z","caller":"events/project_finder.go:79","msg":"looking for Terraform Cloud workspace from configuration in \"/root/.atlantis/repos/sheather/test/31/default/live/aws/123456789012/develop/eu-west-2/stack11\"","json":{"repo":"sheather/test","pull":"31"}}
{"level":"info","ts":"2024-11-08T17:32:35.571Z","caller":"events/project_locker.go:86","msg":"acquired lock with id \"sheather/test/live/aws/123456789012/develop/eu-west-2/stack11/default\"","json":{"repo":"sheather/test","pull":"31"}}
{"level":"info","ts":"2024-11-08T17:32:42.478Z","caller":"models/shell_command_runner.go:181","msg":"successfully ran 'sh -c \"/root/.atlantis/bin/terraform1.9.8 init -input=false -upgrade\"' in '/root/.atlantis/repos/sheather/test/31/default/live/aws/123456789012/develop/eu-west-2/stack11'","json":{"repo":"sheather/test","pull":"31","duration":6.8940395}}
{"level":"info","ts":"2024-11-08T17:32:42.518Z","caller":"terraform/terraform_client.go:383","msg":"successfully ran \"/root/.atlantis/bin/terraform1.9.8 workspace show\" in \"/root/.atlantis/repos/sheather/test/31/default/live/aws/123456789012/develop/eu-west-2/stack11\"","json":{"repo":"sheather/test","pull":"31","duration":0.0394347}}
{"level":"info","ts":"2024-11-08T17:32:42.710Z","caller":"models/shell_command_runner.go:181","msg":"successfully ran 'sh -c \"/root/.atlantis/bin/terraform1.9.8 plan -input=false -refresh -out \\\"/root/.atlantis/repos/sheather/test/31/default/live/aws/123456789012/develop/eu-west-2/stack11/default.tfplan\\\"\"' in '/root/.atlantis/repos/sheather/test/31/default/live/aws/123456789012/develop/eu-west-2/stack11'","json":{"repo":"sheather/test","pull":"31","duration":0.1923274}}
{"level":"info","ts":"2024-11-08T17:32:43.259Z","caller":"events/instrumented_project_command_runner.go:88","msg":"plan success. output available at: https://gitlab.lan/sheather/test/-/merge_requests/31","json":{"repo":"sheather/test","pull":"31"}}
{"level":"info","ts":"2024-11-08T17:32:46.932Z","caller":"events/plan_command_runner.go:290","msg":"Running policy check for command=\"plan\", verbose=false, dir=\"\", workspace=\"\", project=\"\", policyset=\"\", auto-merge-disabled=false, auto-merge-method=, clear-policy-approval=false, flags=\"\"","json":{"repo":"sheather/test","pull":"31"}}
{"level":"info","ts":"2024-11-08T17:32:46.932Z","caller":"events/policy_check_command_runner.go:42","msg":"no projects to run policy_check in","json":{"repo":"sheather/test","pull":"31"}}
{"level":"info","ts":"2024-11-08T17:32:51.489Z","caller":"runtime/post_workflow_hook_runner.go:80","msg":"successfully ran \"bash -ce echo \\\"Terraform Version: $ATLANTIS_TERRAFORM_VERSION\\\"\\n\" in \"/root/.atlantis/repos/sheather/test/31/default\"","json":{"repo":"sheather/test","pull":"31"}}
New
{"level":"info","ts":"2024-11-08T17:02:27.858Z","caller":"vcs/gitlab_client.go:111","msg":"GitLab host 'gitlab.lan' is running version 17.5.0","json":{}}
{"level":"info","ts":"2024-11-08T17:02:27.859Z","caller":"server/server.go:325","msg":"Supported VCS Hosts: Gitlab","json":{}}
{"level":"info","ts":"2024-11-08T17:02:28.176Z","caller":"server/server.go:478","msg":"Utilizing BoltDB","json":{}}
{"level":"info","ts":"2024-11-08T17:02:28.192Z","caller":"policy/conftest_client.go:167","msg":"failed to get default conftest version. Will attempt request scoped lazy loads DEFAULT_CONFTEST_VERSION not set","json":{}}
{"level":"info","ts":"2024-11-08T17:02:28.193Z","caller":"server/server.go:1048","msg":"Atlantis started - listening on port 4141","json":{}}
{"level":"info","ts":"2024-11-08T17:02:28.193Z","caller":"scheduled/executor_service.go:51","msg":"Scheduled Executor Service started","json":{}}
{"level":"info","ts":"2024-11-08T17:02:41.173Z","caller":"events/events_controller.go:684","msg":"Handling 'plan' comment","json":{"repo":"sheather/test","pull":31}}
{"level":"info","ts":"2024-11-08T17:02:41.747Z","caller":"events/events_controller.go:728","msg":"Running comment command 'plan' for user 'sheather'.","json":{"repo":"sheather/test","pull":31}}
{"level":"info","ts":"2024-11-08T17:02:42.676Z","caller":"events/pre_workflow_hooks_command_runner.go:53","msg":"Pre-workflow hooks configured, running...","json":{"repo":"sheather/test","pull":"31"}}
{"level":"info","ts":"2024-11-08T17:02:42.683Z","caller":"vcs/gitlab_client.go:408","msg":"Updating GitLab commit status for 'atlantis/plan' to 'running'","json":{"repo":"sheather/test","pull":"31"}}
{"level":"info","ts":"2024-11-08T17:02:43.846Z","caller":"vcs/gitlab_client.go:408","msg":"Updating GitLab commit status for 'atlantis/pre_workflow_hook: Atlantis Setup' to 'running'","json":{"repo":"sheather/test","pull":"31"}}
{"level":"info","ts":"2024-11-08T17:02:45.322Z","caller":"runtime/pre_workflow_hook_runner.go:80","msg":"Successfully ran 'bash -ce echo \"Terraform Version: $ATLANTIS_TERRAFORM_VERSION\"\n' in '/root/.atlantis/repos/sheather/test/31/default'","json":{"repo":"sheather/test","pull":"31"}}
{"level":"info","ts":"2024-11-08T17:02:45.323Z","caller":"vcs/gitlab_client.go:408","msg":"Updating GitLab commit status for 'atlantis/pre_workflow_hook: Atlantis Setup' to 'success'","json":{"repo":"sheather/test","pull":"31"}}
{"level":"info","ts":"2024-11-08T17:02:46.822Z","caller":"events/pre_workflow_hooks_command_runner.go:103","msg":"Pre-workflow hooks completed successfully","json":{"repo":"sheather/test","pull":"31"}}
{"level":"info","ts":"2024-11-08T17:02:47.641Z","caller":"vcs/gitlab_client.go:408","msg":"Updating GitLab commit status for 'atlantis/plan' to 'running'","json":{"repo":"sheather/test","pull":"31"}}
{"level":"warn","ts":"2024-11-08T17:02:48.041Z","caller":"events/plan_command_runner.go:192","msg":"unable to update commit status: POST https://gitlab.lan/api/v4/projects/sheather/test/statuses/a1e2908f540bd9e0b9beb57ace6ebbdecf57bc9b: 400 {message: Cannot transition status via :run from :running (Reason(s): Status cannot transition via \"run\")}","json":{"repo":"sheather/test","pull":"31"},"stacktrace":"github.com/runatlantis/atlantis/server/events.(*PlanCommandRunner).run\n\t/mnt/c/Users/Simon/Documents/GitHub/X-Guardian/atlantis/server/events/plan_command_runner.go:192\ngithub.com/runatlantis/atlantis/server/events.(*PlanCommandRunner).Run\n\t/mnt/c/Users/Simon/Documents/GitHub/X-Guardian/atlantis/server/events/plan_command_runner.go:307\ngithub.com/runatlantis/atlantis/server/events.(*DefaultCommandRunner).RunCommentCommand\n\t/mnt/c/Users/Simon/Documents/GitHub/X-Guardian/atlantis/server/events/command_runner.go:383"}
{"level":"info","ts":"2024-11-08T17:02:48.363Z","caller":"events/project_command_builder.go:496","msg":"found no atlantis.yaml file","json":{"repo":"sheather/test","pull":"31"}}
{"level":"info","ts":"2024-11-08T17:02:48.364Z","caller":"events/project_finder.go:147","msg":"filtered modified files to 1 file(s) in the autoplan file list: [live/aws/123456789012/develop/eu-west-2/stack11/main.tf]","json":{"repo":"sheather/test","pull":"31"}}
{"level":"info","ts":"2024-11-08T17:02:48.364Z","caller":"events/project_finder.go:176","msg":"there are 1 modified project(s) at path(s): live/aws/123456789012/develop/eu-west-2/stack11","json":{"repo":"sheather/test","pull":"31"}}
{"level":"info","ts":"2024-11-08T17:02:48.364Z","caller":"events/project_command_builder.go:518","msg":"automatically determined that there were 1 additional projects modified in this pull request: [repofullname=sheather/test path=live/aws/123456789012/develop/eu-west-2/stack11]","json":{"repo":"sheather/test","pull":"31"}}
{"level":"info","ts":"2024-11-08T17:02:48.364Z","caller":"events/project_finder.go:79","msg":"Looking for Terraform Cloud workspace from configuration in '/root/.atlantis/repos/sheather/test/31/default/live/aws/123456789012/develop/eu-west-2/stack11'","json":{"repo":"sheather/test","pull":"31"}}
{"level":"info","ts":"2024-11-08T17:02:49.517Z","caller":"vcs/gitlab_client.go:408","msg":"Updating GitLab commit status for 'atlantis/plan: live/aws/123456789012/develop/eu-west-2/stack11/default' to 'running'","json":{"repo":"sheather/test","pull":"31"}}
{"level":"info","ts":"2024-11-08T17:02:49.982Z","caller":"events/project_locker.go:86","msg":"Acquired lock with id 'sheather/test/live/aws/123456789012/develop/eu-west-2/stack11/default'","json":{"repo":"sheather/test","pull":"31"}}
{"level":"info","ts":"2024-11-08T17:02:57.738Z","caller":"models/shell_command_runner.go:181","msg":"successfully ran 'sh -c /root/.atlantis/bin/terraform1.9.8 init -input=false -upgrade' in '/root/.atlantis/repos/sheather/test/31/default/live/aws/123456789012/develop/eu-west-2/stack11'","json":{"repo":"sheather/test","pull":"31","duration":7.7429596}}
{"level":"info","ts":"2024-11-08T17:02:57.782Z","caller":"terraform/terraform_client.go:383","msg":"Successfully ran '/root/.atlantis/bin/terraform1.9.8 workspace show' in '/root/.atlantis/repos/sheather/test/31/default/live/aws/123456789012/develop/eu-west-2/stack11'","json":{"repo":"sheather/test","pull":"31","duration":0.0430819}}
{"level":"info","ts":"2024-11-08T17:02:57.965Z","caller":"models/shell_command_runner.go:181","msg":"successfully ran 'sh -c /root/.atlantis/bin/terraform1.9.8 plan -input=false -refresh -out \"/root/.atlantis/repos/sheather/test/31/default/live/aws/123456789012/develop/eu-west-2/stack11/default.tfplan\"' in '/root/.atlantis/repos/sheather/test/31/default/live/aws/123456789012/develop/eu-west-2/stack11'","json":{"repo":"sheather/test","pull":"31","duration":0.1825007}}
{"level":"info","ts":"2024-11-08T17:02:57.965Z","caller":"vcs/gitlab_client.go:408","msg":"Updating GitLab commit status for 'atlantis/plan: live/aws/123456789012/develop/eu-west-2/stack11/default' to 'success'","json":{"repo":"sheather/test","pull":"31"}}
{"level":"info","ts":"2024-11-08T17:02:58.546Z","caller":"events/instrumented_project_command_runner.go:88","msg":"plan success. output available at: https://gitlab.lan/sheather/test/-/merge_requests/31","json":{"repo":"sheather/test","pull":"31"}}
{"level":"info","ts":"2024-11-08T17:03:01.504Z","caller":"vcs/gitlab_client.go:408","msg":"Updating GitLab commit status for 'atlantis/plan' to 'success'","json":{"repo":"sheather/test","pull":"31"}}
{"level":"info","ts":"2024-11-08T17:03:02.623Z","caller":"events/plan_command_runner.go:290","msg":"Running policy check for 'plan'","json":{"repo":"sheather/test","pull":"31"}}
{"level":"info","ts":"2024-11-08T17:03:02.623Z","caller":"events/policy_check_command_runner.go:42","msg":"no projects to run policy_check in","json":{"repo":"sheather/test","pull":"31"}}
{"level":"info","ts":"2024-11-08T17:03:02.623Z","caller":"vcs/gitlab_client.go:408","msg":"Updating GitLab commit status for 'atlantis/policy_check' to 'success'","json":{"repo":"sheather/test","pull":"31"}}
{"level":"info","ts":"2024-11-08T17:03:04.420Z","caller":"events/post_workflow_hooks_command_runner.go:53","msg":"Post-workflow hooks configured, running...","json":{"repo":"sheather/test","pull":"31"}}
{"level":"info","ts":"2024-11-08T17:03:04.434Z","caller":"vcs/gitlab_client.go:408","msg":"Updating GitLab commit status for 'atlantis/post_workflow_hook: Atlantis Cleanup' to 'running'","json":{"repo":"sheather/test","pull":"31"}}
{"level":"info","ts":"2024-11-08T17:03:06.549Z","caller":"runtime/post_workflow_hook_runner.go:80","msg":"Successfully ran 'bash -ce echo \"Terraform Version: $ATLANTIS_TERRAFORM_VERSION\"\n' in '/root/.atlantis/repos/sheather/test/31/default'","json":{"repo":"sheather/test","pull":"31"}}
{"level":"info","ts":"2024-11-08T17:03:06.549Z","caller":"vcs/gitlab_client.go:408","msg":"Updating GitLab commit status for 'atlantis/post_workflow_hook: Atlantis Cleanup' to 'success'","json":{"repo":"sheather/test","pull":"31"}}
{"level":"info","ts":"2024-11-08T17:03:07.997Z","caller":"events/post_workflow_hooks_command_runner.go:151","msg":"Post-workflow hooks completed","json":{"repo":"sheather/test","pull":"31"}}

Signed-off-by: X-Guardian <[email protected]>
@X-Guardian X-Guardian requested review from a team as code owners October 23, 2024 22:09
@X-Guardian X-Guardian requested review from chenrui333, lukemassa and nitrocode and removed request for a team October 23, 2024 22:09
@dosubot dosubot bot added the feature New functionality/enhancement label Oct 23, 2024
lukemassa
lukemassa previously approved these changes Nov 19, 2024
@dosubot dosubot bot added the lgtm This PR has been approved by a maintainer label Nov 19, 2024
@X-Guardian
Copy link
Contributor Author

Hi @lukemassa, can you re-approve, I had to resolve a merge conflict.

@X-Guardian X-Guardian merged commit e468a23 into runatlantis:main Nov 19, 2024
34 checks passed
@X-Guardian X-Guardian deleted the logging-refinement branch November 19, 2024 17:58
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
feature New functionality/enhancement go Pull requests that update Go code lgtm This PR has been approved by a maintainer provider/azuredevops provider/bitbucket provider/github provider/gitlab
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants