[Tigron]: Testing logs user experience

[apostasie]

<!> Blocked by <!>:

• [Tigron]: expect.JSON comparator and updated volume test #4079

---

This PR focuses specifically on enhancing the human experience of looking at this:

I do spend a lot of time debugging on the CI, or locally, and here are my issues with this:

It is all packed, and very hard to distinguish one line from the other - everything visually stands at the same level - headers, context information, failure, file and line numbers.

This here is actually a simple failure - for more complex ones, it literally takes minutes of squinting to figure out where is the command that was run, and more time to figure out what is the "failure".

More often than not, the failure is really cryptic, as in false is not true.
Yeah, no shit Sherlock.
So, you do have to context switch to an IDE, find the file, go to that line number, try to understand the test, read the tea leaves, etc.
Also, since the filename is shown as basename only, I regularly open the wrong (identically named) one.

Context is hard to figure out too.

There are empty sections ("Setup") - did anything run in there? or not? if nothing ran, why show the section?
If something ran, what was it so that I can reproduce the context before trying to debug the command.

Env is a can of worms on its own - useful, but also very loud.

This PR would like to propose we address all these issues:

• separate things so that they are easier to visually spot
• hide what is not necessary, show what is
• show full lifecycle context to ease manual reproduction
• use indentation, tables, colors, borders, arrows, emoji, kitchen sink if necessary, in order to make this thing easier to visually grok and navigate fast
• hyperlinks where feasible to quickly open the right file in your IDE instead of searching around
• clear failure information, what was actual, what was expected, what did it all mean?
• clear sections emphasizing lifecycle

I do appreciate that everyone has their own tastes and preferences when it comes to visual things, so, I do not expect that we are going to agree on every detail, and we will have to settle on something.

The important part here is to come up with something that objectively addresses these issues - then we can bikeshed all we want on pink vs. green :-) (or I will make the output configurable so that different projects can pick their poison).

I truly believe very few people engage with the CI failures not because they are lazy, but because it looks like a train accident.

PLEASE NOTE THAT THIS PR CODE IS NOT READY FOR REVIEW.
What is ready for review and discussion right now is the visual end-result (see next comment).

[apostasie]

The current proposal of this PR is:

[apostasie]

Here is the text version of that same failure, copy-pasted from my terminal.

   volume_inspect_test.go:193:
        ⤵️️ "TestVolumeInspect": into subtests prep
    volume_inspect_test.go:193:
        ↩️️ "TestVolumeInspect": done with subtests prep
    --- FAIL: TestVolumeInspect/inspect_labels (0.09s)
        volume_inspect_test.go:193:

            +============================================================================================================+
            | 🚀       | "TestVolumeInspect/inspect_labels": starting test!                                               |
            +============================================================================================================+

        volume_inspect_test.go:193:

            +------------------------------------------------------------------------------------------------------------+
            | Command | /usr/local/bin/nerdctl volume inspect testvolumeinspect-second-744d9160                          |
            +------------------------------------------------------------------------------------------------------------+
            | Stdout  | [                                                                                                |
            |         |     {                                                                                            |
            |         |         "Name": "testvolumeinspect-second-744d9160",                                             |
            |         |         "Mountpoint": "/home/dmp.linux/.local/share/nerdctl/1935db59/volumes/nerdctl-test/testvo |
            |         | lumeinspect-second-744d9160/_data",                                                              |
            |         |         "Labels": {                                                                              |
            |         |             "bar": "barval",                                                                     |
            |         |             "foo": "fooval"                                                                      |
            |         |         }                                                                                        |
            |         |     }                                                                                            |
            |         | ]                                                                                                |
            |         |                                                                                                  |
            |         |                                                                                                  |
            +------------------------------------------------------------------------------------------------------------+

        volume_inspect_test.go:193:

            <<<<<<<<<<<<<<<<<<<<
            	🖊️ Inspecting output (contains)
            	👀 testing:		`[
                {
                    "Name": "testvolumeinspect-second-744d9160",
                    "Mountpoint": "/home/dmp.linux/.local/share/nerdctl/1935db59/volumes/nerdctl-test/testvolumeinspect-second-744d9160/_data",
                    "Labels": {
                        "bar": "barval",
                        "foo": "fooval"
                    }
                }
            ]

            `
            	❌ FAILED!		~= `testvolumeinspect-second-744d9160XXXXXXXXXX`
            >>>>>>>>>>>>>>>>>>>>

        volume_inspect_test.go:193:

            <<<<<<<<<<<<<<<<<<<<
            	🖊️ Unmarshalling JSON from stdout must succeed
            	👀 testing:		`<nil>`
            	✅️ does verify:		is `<nil>`
            >>>>>>>>>>>>>>>>>>>>

    volume_inspect_test.go:193:

        +============================================================================================================+
        | 🧽️      | "TestVolumeInspect": post-cleanup                                                                |
        +============================================================================================================+

    volume_inspect_test.go:72:

        +------------------------------------------------------------------------------------------------------------+
        | Command | /usr/local/bin/nerdctl volume rm -f testvolumeinspect-first-15e4b5b2                             |
        +------------------------------------------------------------------------------------------------------------+
        | Stdout  | testvolumeinspect-first-15e4b5b2                                                                 |
        |         |                                                                                                  |
        +------------------------------------------------------------------------------------------------------------+

    volume_inspect_test.go:73:

        +------------------------------------------------------------------------------------------------------------+
        | Command | /usr/local/bin/nerdctl volume rm -f testvolumeinspect-second-744d9160                            |
        +------------------------------------------------------------------------------------------------------------+
        | Stdout  | testvolumeinspect-second-744d9160                                                                |
        |         |                                                                                                  |
        +------------------------------------------------------------------------------------------------------------+

FAIL
FAIL	github.com/containerd/nerdctl/v2/cmd/nerdctl/volume	0.667s
FAIL

[AkihiroSuda]

Thanks, the output looks better now

[apostasie]

NOTE
The last commit voluntarily introduces a test breakage so that people can review the UX on an actual failure.

Once we are ready to merge, I will yank out that last commit.

[apostasie]

go mod tidy seem to have brought the update in (maybe because of x/text).
Anyhow, this is fine.

[AkihiroSuda]

Thanks

[apostasie]

Thanks @AkihiroSuda
Rebased and yanked out test commit.

I think this might require minor adjustments in the future as we debug more with this in, but let's see about that later on.

[apostasie]

Kube failure I have seen quite a few times.
Looks like (again) some race.
Commit does work, but somehow the committed image is not yet available when we try to save it.

Rootless failure is again #4046
Intuition is that the recent changes in command implementation make things a lot faster, and more likely to surface timing issues with stdin attachment.