Logrus logs #423

DavidGOrtega · 2022-03-03T15:45:39Z

The purpose is to offer an insight digest report on refresh of Task status and script logs.

Logrus' log level is aligned with terraform. Terraform is reading the [LOG_LEVEL] from the given log. Our formatter parses the desired logrus level from the call and sets the logs initial level. I.E.
- logrus.Debug("here") => [DEBUG] TPI here
- logrus.Info("here") => [INFO] TPI here
Colors and eye candy is used to make the less effort to read our logs.
We add a small refresh report creating a tpiFormatter that receives the d schemaData and uses it to signal the logs.

Usage

export TF_LOG_PROVIDER=INFO or export TF_LOG_PROVIDER=DEBUG prior to use terraform

Closes

closes UX: improve log formatting & info (on refresh & show) #392

Co-authored-by: Restyled.io <[email protected]>

…der-iterative into logrus

0x2b3bfa0 · 2022-03-03T17:24:55Z

Sample — `b56e1cd` snapshot

resource "iterative_task" "sample" {
  cloud  = "az"
  script = <<-END
    #!/bin/bash
    echo "Hello World"
  END
}

$ TF_LOG_PROVIDER=INFO terraform refresh
2022-03-03T17:22:19.387Z [INFO]  provider: configuring client automatic mTLS
2022-03-03T17:22:19.423Z [INFO]  provider.terraform-provider-iterative: configuring server automatic mTLS: timestamp=2022-03-03T17:22:19.423Z
2022-03-03T17:22:19.450Z [INFO]  provider: configuring client automatic mTLS
2022-03-03T17:22:19.485Z [INFO]  provider.terraform-provider-iterative: configuring server automatic mTLS: timestamp=2022-03-03T17:22:19.485Z
2022-03-03T17:22:19.512Z [INFO]  provider: configuring client automatic mTLS
2022-03-03T17:22:19.549Z [INFO]  provider.terraform-provider-iterative: configuring server automatic mTLS: timestamp=2022-03-03T17:22:19.549Z
iterative_task.task: Refreshing state... [id=tpi-1mb61lbbee8oj-27liktpn-6bfaepcv]
2022-03-03T17:22:19.581Z [INFO]  provider.terraform-provider-iterative: 2022/03/03 17:22:19 [INFO] Reading ResourceGroup...: timestamp=2022-03-03T17:22:19.581Z
2022-03-03T17:22:20.244Z [INFO]  provider.terraform-provider-iterative: 2022/03/03 17:22:20 [INFO] Reading StorageAccount...: timestamp=2022-03-03T17:22:20.244Z
2022-03-03T17:22:20.599Z [INFO]  provider.terraform-provider-iterative: 2022/03/03 17:22:20 [INFO] Reading BlobContainer...: timestamp=2022-03-03T17:22:20.599Z
2022-03-03T17:22:20.807Z [INFO]  provider.terraform-provider-iterative: 2022/03/03 17:22:20 [INFO] Reading Credentials...: timestamp=2022-03-03T17:22:20.807Z
2022-03-03T17:22:20.807Z [INFO]  provider.terraform-provider-iterative: 2022/03/03 17:22:20 [INFO] Reading VirtualNetwork...: timestamp=2022-03-03T17:22:20.807Z
2022-03-03T17:22:21.418Z [INFO]  provider.terraform-provider-iterative: 2022/03/03 17:22:21 [INFO] Reading SecurityGroup...: timestamp=2022-03-03T17:22:21.418Z
2022-03-03T17:22:21.588Z [INFO]  provider.terraform-provider-iterative: 2022/03/03 17:22:21 [INFO] Reading Subnet...: timestamp=2022-03-03T17:22:21.588Z
2022-03-03T17:22:21.769Z [INFO]  provider.terraform-provider-iterative: 2022/03/03 17:22:21 [INFO] Reading VirtualMachineScaleSet...: timestamp=2022-03-03T17:22:21.769Z
2022-03-03T17:22:22.719Z [INFO]  provider.terraform-provider-iterative: 2022/03/03 17:22:22 [INFO] Done!: timestamp=2022-03-03T17:22:22.719Z
2022-03-03T17:22:25.799Z [INFO]  provider.terraform-provider-iterative: 2022/03/03 17:22:25 [INFO] Reading ResourceGroup...: timestamp=2022-03-03T17:22:25.799Z
2022-03-03T17:22:25.835Z [INFO]  provider.terraform-provider-iterative: 2022/03/03 17:22:25 [INFO] Reading StorageAccount...: timestamp=2022-03-03T17:22:25.835Z
2022-03-03T17:22:26.231Z [INFO]  provider.terraform-provider-iterative: 2022/03/03 17:22:26 [INFO] Reading BlobContainer...: timestamp=2022-03-03T17:22:26.231Z
2022-03-03T17:22:26.413Z [INFO]  provider.terraform-provider-iterative: 2022/03/03 17:22:26 [INFO] Reading Credentials...: timestamp=2022-03-03T17:22:26.413Z
2022-03-03T17:22:26.413Z [INFO]  provider.terraform-provider-iterative: 2022/03/03 17:22:26 [INFO] Reading VirtualNetwork...: timestamp=2022-03-03T17:22:26.413Z
2022-03-03T17:22:27.039Z [INFO]  provider.terraform-provider-iterative: 2022/03/03 17:22:27 [INFO] Reading SecurityGroup...: timestamp=2022-03-03T17:22:27.039Z
2022-03-03T17:22:27.229Z [INFO]  provider.terraform-provider-iterative: 2022/03/03 17:22:27 [INFO] Reading Subnet...: timestamp=2022-03-03T17:22:27.229Z
2022-03-03T17:22:27.403Z [INFO]  provider.terraform-provider-iterative: 2022/03/03 17:22:27 [INFO] Reading VirtualMachineScaleSet...: timestamp=2022-03-03T17:22:27.403Z
2022-03-03T17:22:27.939Z [INFO]  provider.terraform-provider-iterative: 2022/03/03 17:22:27 [INFO] Done!: timestamp=2022-03-03T17:22:27.939Z
2022-03-03T17:22:28.982Z [INFO]  provider.terraform-provider-iterative: 2022/03/03 17:22:28 [INFO] Reading ResourceGroup...: timestamp=2022-03-03T17:22:28.981Z
2022-03-03T17:22:28.994Z [INFO]  provider.terraform-provider-iterative: 2022/03/03 17:22:28 [INFO] Reading StorageAccount...: timestamp=2022-03-03T17:22:28.994Z
2022-03-03T17:22:29.376Z [INFO]  provider.terraform-provider-iterative: 2022/03/03 17:22:29 [INFO] Reading BlobContainer...: timestamp=2022-03-03T17:22:29.376Z
2022-03-03T17:22:29.570Z [INFO]  provider.terraform-provider-iterative: 2022/03/03 17:22:29 [INFO] Reading Credentials...: timestamp=2022-03-03T17:22:29.570Z
2022-03-03T17:22:29.570Z [INFO]  provider.terraform-provider-iterative: 2022/03/03 17:22:29 [INFO] Reading VirtualNetwork...: timestamp=2022-03-03T17:22:29.570Z
2022-03-03T17:22:29.743Z [INFO]  provider.terraform-provider-iterative: 2022/03/03 17:22:29 [INFO] Reading SecurityGroup...: timestamp=2022-03-03T17:22:29.743Z
2022-03-03T17:22:29.915Z [INFO]  provider.terraform-provider-iterative: 2022/03/03 17:22:29 [INFO] Reading Subnet...: timestamp=2022-03-03T17:22:29.915Z
2022-03-03T17:22:30.086Z [INFO]  provider.terraform-provider-iterative: 2022/03/03 17:22:30 [INFO] Reading VirtualMachineScaleSet...: timestamp=2022-03-03T17:22:30.086Z
2022-03-03T17:22:30.583Z [INFO]  provider.terraform-provider-iterative: 2022/03/03 17:22:30 [INFO] Done!: timestamp=2022-03-03T17:22:30.583Z
2022-03-03T17:22:31.220Z [INFO]  provider.terraform-provider-iterative: [INFO] tpi-1mb61lbbee8oj-27liktpn-6bfaepcv [0011] 🚀 az m at us-west                            
2022-03-03T17:22:31.220Z [INFO]  provider.terraform-provider-iterative: [INFO] tpi-1mb61lbbee8oj-27liktpn-6bfaepcv [0011] Task logs:-- Logs begin at Thu 2022-03-03 17:18:51 UTC, end at Thu 2022-03-03 17:22:22 UTC. --
2022-03-03T17:22:31.220Z [INFO]  provider.terraform-provider-iterative: [INFO] Mar 03 17:19:48 tpi000000 systemd[1]: Started tpi-task.service.
2022-03-03T17:22:31.220Z [INFO]  provider.terraform-provider-iterative: [INFO] Mar 03 17:19:48 tpi000000 tpi-task[1803]: Hello World
2022-03-03T17:22:31.220Z [INFO]  provider.terraform-provider-iterative: [INFO] Mar 03 17:19:48 tpi000000 bash[1804]: NOTICE: Config file "/root/.config/rclone/rclone.conf" not found - using defaults
2022-03-03T17:22:31.220Z [INFO]  provider.terraform-provider-iterative: [INFO] Mar 03 17:20:08 tpi000000 tpi-task-shutdown[1915]: 2022/03/03 17:20:08 [INFO] Stopping task tpi-1mb61lbbee8oj-27liktpn-6bfaepcv...
2022-03-03T17:22:31.220Z [INFO]  provider.terraform-provider-iterative: [INFO]  
2022-03-03T17:22:31.220Z [INFO]  provider.terraform-provider-iterative: [INFO] tpi-1mb61lbbee8oj-27liktpn-6bfaepcv [0011] Task is terminated succesfully 🟢

DavidGOrtega · 2022-03-03T22:31:03Z

@0x2b3bfa0 Update to your comment. Your original logs now use Logrus

DavidGOrtega · 2022-03-03T22:31:46Z

I wonder why your logs are repeated three times. Is the refresh operation running it several times?

Co-authored-by: Restyled.io <[email protected]>

casperdcl

🚀

iterative/utils/logger.go

task/aws/task.go

0x2b3bfa0 · 2022-03-04T00:03:48Z

I wonder why your logs are repeated three times. Is the refresh operation running it several times?

Yes, it's running several times and can be optimized to run only once. See #290 for context.

0x2b3bfa0 · 2022-03-07T00:43:05Z

Side topic: we already were duplicating the functionality of official providers, reinventing the Terraform planner, but after this pull request we're also bypassing Terraform Core to print our own logs.

I'd prefer not to divert this thread towards the discussion of the advantages and disadvantages of these choices, but it feels like it's something we should be aware of.

DavidGOrtega · 2022-03-07T05:45:00Z

The ability of custom logs is something that Terraform know and indeed they are willing to fix

Terraform performs as many operations in parallel as possible,

Having parallel logs are normal. However for the refresh "report" they should be all them together. I have found after several trial that the logs were always fine. I mean the report stayed together without having applied any parallelism constrain.
In any case I did add the tpi id always to identify.

DavidGOrtega · 2022-03-07T10:28:14Z

Command–line tools with emoji were awesome in 2015, but they look a bit kitsch in retrospective

icons are better than text and easy to be followed within a bunch of text. Its not about emojis it's about icons

0x2b3bfa0 · 2022-03-07T11:00:41Z

easy to be followed within a bunch of text

Sounds like an x–y problem: polished command–line tools usually don't bury useful information behind “a bunch of text” unless users explicitly ask for the latter.

it's not about emojis, it's about icons

💯 See gh and poetry for some elegant Unicode alternatives to emoji.

0x2b3bfa0 · 2022-03-07T11:02:05Z

The ability of custom logs is something that Terraform know and indeed they hashicorp/terraform-plugin-sdk#145 (comment)

I don't see any signs of enthusiasm there. Especially after hashicorp/terraform#17267 (comment). 🤔

0x2b3bfa0 · 2022-03-07T11:04:17Z

Having parallel logs are normal. However for the refresh "report" they should be all them together. I have found after several trial that the logs were always fine. I mean the report stayed together without having applied any parallelism constrain.
In any case I did add the tpi id always to identify.

Yes, if you print all the logs at once and the process takes a split second, it would be moderately hard to hit this condition. Still, rest assured that it will happen. 🙃 Anyway.

DavidGOrtega · 2022-03-07T11:05:24Z

I don't see any signs of enthusiasm there. Especially after hashicorp/terraform#17267 (comment). 🤔

"...Instead, any output from providers will need to be designed with a suitable structure that it can be translated to both a terminal-based UI and to other UI contexts such as Terraform Cloud's web UI,..."

What distil is that they are not willing to support any output but be able to specify a closed JSON format to be displayed on the UI and or the Cloud's UI. It's pretty clear. They are not telling they are not supporting it.

DavidGOrtega · 2022-03-07T11:06:50Z

Still, rest assured that it will happen. 🙃 Anyway.

bikeshedding?
WE still have the task id to be able to follow up in that hard condition 🙂

DavidGOrtega · 2022-03-07T11:16:22Z

💯 See gh and poetry for some elegant Unicode alternatives to emoji.

In any case I imagine that you are referring to 🚀
I see the statuses 🔴 🟡 perfectly valid as icons

0x2b3bfa0 · 2022-03-07T11:26:17Z

In any case I imagine that you are referring to 🚀
I see the statuses 🔴 🟡 perfectly valid as icons

Definitely bikeshedding, but if we had full control of the terminal and outputted less text, I would prefer alternatives like \e[31;1m•\e[0m and \e[33;1m•\e[0m as in poetry 🤷🏼‍♂️ Let's postpone this discussion until this level of detail becomes part of our priorities.

0x2b3bfa0 · 2022-03-07T11:29:52Z

What distil is that they are not willing to support any output but be able to specify a closed JSON format to be displayed on the UI and or the Cloud's UI.

And that format will be oriented towards sane, officially supported use cases, not printing thousands of log lines to the console.

casperdcl · 2022-03-07T11:32:52Z

The ability of custom logs is something that Terraform know and indeed they are willing to fix

I don't think they're closing that issue any time soon.

All the log lines have a lengthy 72 character prefix that can't be easily disabled

So they can be disabled? How?

Command–line tools with emoji [...] look a bit kitsch

and

icons are better than text and easy to be followed

💯 I see the value in visual cues, however the different colours are enough for this (no need to have emoji).

DavidGOrtega · 2022-03-07T11:34:37Z

So they can be disabled? How?

unfortunately they can't

0x2b3bfa0 · 2022-03-07T11:36:54Z

So they can be disabled? How?

Either:

Forking Terraform Core (missing troll face emoji), or
Piping the output to awk (ditto)

casperdcl

i hate everything about this 😅

logs fix

36caeed

restyled-io bot mentioned this pull request Mar 3, 2022

Restyle Logrus logs #424

Merged

restyled-io bot and others added 3 commits March 3, 2022 17:19

Restyled by gofmt (#424)

b56e1cd

Co-authored-by: Restyled.io <[email protected]>

DEBUG level

02c109c

Merge branch 'logrus' of https://github.com/iterative/terraform-provi…

af08e91

…der-iterative into logrus

DavidGOrtega temporarily deployed to automatic March 3, 2022 17:17 Inactive

DavidGOrtega had a problem deploying to automatic March 3, 2022 17:18 Error

basicFormatter

cb5d9ec

DavidGOrtega temporarily deployed to automatic March 3, 2022 22:17 Inactive

restyled-io bot mentioned this pull request Mar 3, 2022

Restyle Logrus logs #431

Merged

DavidGOrtega had a problem deploying to automatic March 3, 2022 22:17 Error

DavidGOrtega requested a review from 0x2b3bfa0 March 3, 2022 22:32

Restyled by gofmt (#431)

30129f9

Co-authored-by: Restyled.io <[email protected]>

DavidGOrtega temporarily deployed to automatic March 3, 2022 22:35 Inactive

DavidGOrtega had a problem deploying to automatic March 3, 2022 22:35 Failure

casperdcl suggested changes Mar 3, 2022

View reviewed changes

improvements

c59c950

0x2b3bfa0 temporarily deployed to automatic March 7, 2022 05:46 Inactive

0x2b3bfa0 temporarily deployed to automatic March 7, 2022 05:47 Inactive

0x2b3bfa0 requested a review from casperdcl March 7, 2022 10:33

casperdcl approved these changes Mar 7, 2022

View reviewed changes

DavidGOrtega merged commit 9fc440f into master Mar 7, 2022

DavidGOrtega deleted the logrus branch March 7, 2022 13:28

0x2b3bfa0 mentioned this pull request Mar 7, 2022

Optimize task creation/deletion times #290

Open

This was referenced Mar 31, 2022

Improve TF_LOG_PROVIDER logs #471

Merged

Display real-time progress while transferring data #467

Merged

task: log experience & verbosity #481

Closed

0x2b3bfa0 mentioned this pull request May 6, 2022

Minor readme suggestion: remove or modify TF_LOG_PROVIDER=INFO #556

Closed

0x2b3bfa0 mentioned this pull request Jun 27, 2022

Provide a standalone command-line tool #610

Merged

0x2b3bfa0 mentioned this pull request Nov 12, 2022

Use logrusctx instead of logrus on task #716

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Logrus logs #423

Logrus logs #423

DavidGOrtega commented Mar 3, 2022 •

edited

Loading

0x2b3bfa0 commented Mar 3, 2022 •

edited

Loading

DavidGOrtega commented Mar 3, 2022

DavidGOrtega commented Mar 3, 2022

casperdcl left a comment

0x2b3bfa0 commented Mar 4, 2022

0x2b3bfa0 commented Mar 7, 2022 •

edited

Loading

DavidGOrtega commented Mar 7, 2022 •

edited

Loading

DavidGOrtega commented Mar 7, 2022

0x2b3bfa0 commented Mar 7, 2022

0x2b3bfa0 commented Mar 7, 2022

0x2b3bfa0 commented Mar 7, 2022

DavidGOrtega commented Mar 7, 2022

DavidGOrtega commented Mar 7, 2022 •

edited

Loading

DavidGOrtega commented Mar 7, 2022

0x2b3bfa0 commented Mar 7, 2022 •

edited

Loading

0x2b3bfa0 commented Mar 7, 2022

casperdcl commented Mar 7, 2022 •

edited

Loading

DavidGOrtega commented Mar 7, 2022

0x2b3bfa0 commented Mar 7, 2022

casperdcl left a comment

Logrus logs #423

Logrus logs #423

Conversation

DavidGOrtega commented Mar 3, 2022 • edited Loading

Usage

Closes

0x2b3bfa0 commented Mar 3, 2022 • edited Loading

Sample — b56e1cd snapshot

DavidGOrtega commented Mar 3, 2022

DavidGOrtega commented Mar 3, 2022

casperdcl left a comment

Choose a reason for hiding this comment

0x2b3bfa0 commented Mar 4, 2022

0x2b3bfa0 commented Mar 7, 2022 • edited Loading

DavidGOrtega commented Mar 7, 2022 • edited Loading

DavidGOrtega commented Mar 7, 2022

0x2b3bfa0 commented Mar 7, 2022

0x2b3bfa0 commented Mar 7, 2022

0x2b3bfa0 commented Mar 7, 2022

DavidGOrtega commented Mar 7, 2022

DavidGOrtega commented Mar 7, 2022 • edited Loading

DavidGOrtega commented Mar 7, 2022

0x2b3bfa0 commented Mar 7, 2022 • edited Loading

0x2b3bfa0 commented Mar 7, 2022

casperdcl commented Mar 7, 2022 • edited Loading

DavidGOrtega commented Mar 7, 2022

0x2b3bfa0 commented Mar 7, 2022

casperdcl left a comment

Choose a reason for hiding this comment

DavidGOrtega commented Mar 3, 2022 •

edited

Loading

0x2b3bfa0 commented Mar 3, 2022 •

edited

Loading

Sample — `b56e1cd` snapshot

0x2b3bfa0 commented Mar 7, 2022 •

edited

Loading

DavidGOrtega commented Mar 7, 2022 •

edited

Loading

DavidGOrtega commented Mar 7, 2022 •

edited

Loading

0x2b3bfa0 commented Mar 7, 2022 •

edited

Loading

casperdcl commented Mar 7, 2022 •

edited

Loading