Proposal: change verbosity

[knutov]

Verbosity now looks irrational in some cases: (as for spot v1.10.1-9aab799-2023-07-27T15:02:00Z)

without -v / --dry / --dbg:

more logical here seems to me is just good exit code and output with echo: commands.

there is missing level (and I'm not sure it should be added, but it could be like info level without debug info) where

run task "uptime0", commands: 2
completed command "first command"
completed command "second command"
completed task "uptime0", commands: 2

is expected, with timings but without script: /bin/sh -c /tmp/.spot-7004577479215170560/spot-script1302878036 part (mostly always useless data)

With -v now is:

And here is "run task" message, result first, then 'completed' mesage, then source code of executed task.

Other order seems to be more logical to me:

• "start message" - the name of task to run
• source code of task
• result of task
• "finish message" - "completed task..." with timings

"script: /bin/bash -c /tmp/.spot-3848016599666591744/spot-script2179626406" still looks useless here, but shell and vars could be good to see here.

At the same time, --dbg is logical and seems to print things in order as they happen:

spot v1.10.1-9aab799-2023-07-27T15:02:00Z
2023/08/09 01:08:17.578 [DEBUG] request to load playbook "test.yml"
2023/08/09 01:08:17.579 [INFO]  playbook loaded with 10 tasks
2023/08/09 01:08:17.579 [DEBUG] load command "print" (task: print)
2023/08/09 01:08:17.579 [DEBUG] load command "first command" (task: uptime0)
2023/08/09 01:08:17.579 [DEBUG] load command "second command" (task: uptime0)
...
2023/08/09 01:08:17.579 [DEBUG] inventory location "inventory.yml"
2023/08/09 01:08:17.580 [INFO]  inventory loaded with 20 hosts
...
2023/08/09 01:08:17.580 [DEBUG] runner created: concurrency:1, connector: ssh connector with private key /home/ko.., timeout 30s, agent false, ssh_shell:"/bin/sh", verbose:false, dry:false, only:[], skip:[]
2023/08/09 01:08:17.580 [DEBUG] task "uptime0" has 2 commands
...
[localhost] run task "uptime0", commands: 2 (local)
2023/08/09 01:08:17.580 [INFO]  run command "first command" on local host
2023/08/09 01:08:17.580 [DEBUG] run local command "first command"
2023/08/09 01:08:17.580 [DEBUG] execute script "first command" on localhost
2023/08/09 01:08:17.580 [DEBUG] command "first command" is multiline, using script file
2023/08/09 01:08:17.582 [DEBUG] > /tmp/.spot-5221253505732668416/spot-script30046284
2023/08/09 01:08:17.585 [DEBUG] > setvar FILE_NAME=/tmp/file1
2023/08/09 01:08:17.585 [DEBUG] set 1 variables from command "first command": map[FILE_NAME:/tmp/file1]
[localhost] completed command "first command" {script: /bin/bash -c /tmp/.spot-5221253505732668416/spot-script30046284} (4ms)
2023/08/09 01:08:17.585 [INFO]  run command "second command" on local host
2023/08/09 01:08:17.585 [DEBUG] run local command "second command"
2023/08/09 01:08:17.585 [DEBUG] execute script "second command" on localhost
2023/08/09 01:08:17.585 [DEBUG] command "second command" is multiline, using script file
2023/08/09 01:08:17.588 [DEBUG] > /tmp/.spot-3997384446221292544/spot-script2795792527
2023/08/09 01:08:17.590 [DEBUG] > File name is /tmp/file1, var is
[localhost] completed command "second command" {script: /bin/bash -c /tmp/.spot-3997384446221292544/spot-script2795792527} (5ms)
[localhost] completed task "uptime0", commands: 2 (10ms)
2023/08/09 01:08:17.590 [INFO]  completed: hosts:1, commands:2 in 0s
2023/08/09 01:08:17.590 [INFO]  completed all 1 targets in 0s

[umputun]

I have changed the order and it shows the script after the useless script: blah like this

[localhost] run task "uptime0", commands: 2 (local)
[localhost]  > /tmp/.spot-4749518492390856704/spot-script3291037774
[localhost]  > setvar FILE_NAME=/tmp/file1
[localhost] script: /tmp/.spot-4749518492390856704/spot-script3291037774
[localhost]  + #!/bin/zsh
[localhost]  + set -e
[localhost]  + export FILE_NAME=/tmp/file1
[localhost]  + touch $FILE_NAME ; ANOTHER_VAR=foo
[localhost]  + echo setvar FILE_NAME=${FILE_NAME}
[localhost] completed command "first command" {script: /bin/zsh -c /tmp/.spot-4749518492390856704/spot-script3291037774} (58ms)

I think it is logical to show the source right after script: /tmp/.spot-4749518492390856704/spot-script3291037774 . This change on master

[knutov]

Still strange to me to see what we did after results, not before we doing it. But it's not critical.

More important thing is now there is no echo output in case spot was run without -v but, but having output with useless "{script: /bin/bash -c /tmp/.spot-9109533436149929984/spot-script387946043}" without requesting any debug info.

[knutov]

  - name: print
    commands:
      - name: print
        echo: "hello world"
        options:
          local: true

this will produce (without -v):

[localhost] run task "print", commands: 1 (local)
[localhost] completed command "print" {echo: hello world} (2ms)
[localhost] completed task "print", commands: 1 (2ms)

"info" messages are not expected without -v or --dbg, but this is clearly some "info" messages. But important info (result of echo: command) is hard to see in all this text.

[knutov]

well, not sure how can it be better, just think echo output here is really not easy to find by human eye.

[umputun]

ok, you confused me for real ;) You said before, "More important thing is now there is no echo output in case spot was run without -v" but in fact, there is one, just not where you expect it to see?

[knutov]

Yeah, sorry, I thought about next case but I looked to the old output form previous test task

[knutov]

to clarify, what I think is easy to read from screen and what is logical to understand during reading:

• printing in exact order as it happens (first what will be run, then result, then status and timings, OR what, status, result)
• minimal debug/info messages if not requested: names of executed tasks, echo: output from new line, errors (but only if they happen, without confirmation task was run successful), no timings without -v too.
• may be some -v levels, like -vv, -vvv. With additional timings, confirmations, etc. (not critical at all, just one -v is fine)