Make the k6 terminal output more Human Readable

[sniku]

This is a proposal to redefine the k6 terminal output format.

The goal of this proposal is to improve the User Experience of the terminal users by bringing more focus to the important metrics and hiding by default metrics that are not important to a typical k6 user.

Feature Description

The most important standard metric in k6 is called http_req_duration. This metric is currently printed in the middle of minor metrics such as http_req_receiving and http_req_connecting, making it less prominent than it should be.

It seems that metrics are currently printed in alphabetical order, and not in the order of importance.

Suggested Solution

I'm suggesting that the above output should look similar to this:

        /\      |‾‾|  /‾‾/  /‾/   
   /\  /  \     |  |_/  /  / /    
  /  \/    \    |      |  /  ‾‾\  
 /          \   |  |‾\  \ | (_) | 
/ __________ \  |__|  \__\ \___/ .io

  execution: local
   output: -
   script: scripts/load-simple.js

  duration: -,  iterations: -
       vus: 1, max: 10

  done [==========================================================] 4s / 20m0s

  http_reqs..................: 12     2.981276/s
  http_req_duration..........: avg=142.4ms  min=113.73ms med=149.49ms max=176.26ms p(90)=168.28ms p(95)=171.88ms
    http_req_blocked.........: avg=39.31ms  min=747ns    med=1.21µs   max=471.74ms p(90)=1.85µs   p(95)=212.28ms
    http_req_connecting......: avg=8.65ms   min=0s       med=0s       max=103.87ms p(90)=0s       p(95)=46.74ms 
    http_req_tls_handshaking.: avg=26.23ms  min=0s       med=0s       max=314.81ms p(90)=0s       p(95)=141.66ms
    http_req_sending.........: avg=98.25µs  min=27.51µs  med=84.43µs  max=296.81µs p(90)=181.55µs p(95)=236.87µs
    http_req_waiting.........: avg=142.23ms min=113.53ms med=149.33ms max=175.84ms p(90)=168.1ms  p(95)=171.59ms
    http_req_receiving.......: avg=75.83µs  min=15.48µs  med=73.54µs  max=161.66µs p(90)=118.63µs p(95)=139.68µs

  iterations.................: 2      0.496879/s
  iteration_duration.........: avg=1.54s    min=1.28s    med=1.54s    max=1.79s    p(90)=1.74s    p(95)=1.77s   

  vus........................: 1      min=1  max=1 
  vus_max....................: 10     min=10 max=10

  data_sent..................: 947 B  235 B/s
  data_received..............: 8.6 kB 2.1 kB/s

Changes:

1. The minor metrics are nested under the main metric.
2. The minor metrics are printed in the order they are recorded. http_req_blocked -> http_req_connecting -> http_req_tls_handshaking -> http_req_sending -> http_req_waiting -> http_req_receiving.
3. The http_reqs and http_req_duration are next to each other
4. iterations and iteration_duration are next to each other.
5. data_sent and data_received are next to each other, and in correct order.

Better yet, I believe that the minor metrics should not be displayed by default since most users don't need them. I suggest we hide the minor metrics unless user specified an option to view them (--print-minor-metrics configuration option or similar)

The default output could be simplified to:

        /\      |‾‾|  /‾‾/  /‾/   
   /\  /  \     |  |_/  /  / /    
  /  \/    \    |      |  /  ‾‾\  
 /          \   |  |‾\  \ | (_) | 
/ __________ \  |__|  \__\ \___/ .io

  execution: local
   output: -
   script: scripts/load-simple.js

  duration: -,  iterations: -
       vus: 1, max: 10

  done [==========================================================] 4s / 20m0s

  http_reqs..................: 12     2.981276/s
  http_req_duration..........: avg=142.4ms  min=113.73ms med=149.49ms max=176.26ms p(90)=168.28ms p(95)=171.88ms

  iterations.................: 2      0.496879/s
  iteration_duration.........: avg=1.54s    min=1.28s    med=1.54s    max=1.79s    p(90)=1.74s    p(95)=1.77s   

  vus........................: 1      min=1  max=1 
  vus_max....................: 10     min=10 max=10

  data_sent..................: 947 B  235 B/s
  data_received..............: 8.6 kB 2.1 kB/s

I believe the above format is more useful for the majority of k6 users than the current verbose, alphabetical format.

Complex scripts

More complex scripts that define sub metrics such as http_req_duration{name:PublicCrocs}, and groups should be considered.

Example

Suggested output

        /\      |‾‾|  /‾‾/  /‾/   
   /\  /  \     |  |_/  /  / /    
  /  \/    \    |      |  /  ‾‾\  
 /          \   |  |‾\  \ | (_) | 
/ __________ \  |__|  \__\ \___/ .io

  execution: local
   output: -
   script: scripts/test-api.js

  duration: -,  iterations: -
       vus: 1, max: 70

  done [==========================================================] 2.8s / 30s

  █ Public endpoints
    ✓ Crocs are older than 5 years of age

  █ Create and modify crocs
    ✓ Croc was deleted correctly

    █ Create crocs
      ✓ Croc created correctly

    █ Update croc
      ✓ Update worked
      ✓ Updated name is correct

  checks.....................: 100.00% ✓ 40   ✗ 0   

  http_reqs..................: 60      20.904866/s
✓ http_req_duration..........: avg=127.64ms min=114.66ms med=122.02ms max=321.28ms p(90)=127.1ms  p(95)=137.83ms
  ✓ { name:Create }..........: avg=123.39ms min=121.58ms med=123.03ms max=125.93ms p(90)=125.59ms p(95)=125.76ms
  ✓ { name:PublicCrocs }.....: avg=121.41ms min=114.66ms med=120.6ms  max=136.97ms p(90)=126.52ms p(95)=128.07ms

  data_received..............: 76 kB   26 kB/s
  data_sent..................: 8.7 kB  3.0 kB/s

  iterations.................: 3       1.045243/s
  iteration_duration.........: avg=1.73s    min=1.22s    med=1.84s    max=2s       p(90)=1.95s    p(95)=1.97s   

  vus........................: 7       min=1  max=7 
  vus_max....................: 70      min=70 max=70

[na--]

I like most of the ideas here in general, though because of the way metrics are implemented in k6, the end-of-test summary is currently generated very organically, so it might be a bit tricky to handle all of the corner cases of us adding some rigid structure to it. For example, run a script that doesn't make any HTTP requests, but adds a custom metric...

That said, it's definitely not impossible to add structure, we just have to evaluate the effort and prioritize accordingly.

The thing I dislike most about the current proposal is the indentation of the so-called "minor" metrics. This has 2 big issues:

1. It somehow suggests that these metrics are a subset of the http_req_duration metric, which is not the case for all of them. http_req_blocked, http_req_connecting, and http_req_tls_handshaking don't have anything in common with http_req_duration...
2. It would actually conflict with the currently-indented actual sub-metrics (i.e. the { name:Create }, { name:PublicCrocs }, etc.), which are actually a subset of the parent metric.

That said, I like pretty much everything else you suggested 🎉. I've written my ideas about filtering/whitelisting metrics in #1321. I think hiding the "minor" metrics by default isn't only a cosmetic/UX issue, but also a very important performance one, so it should be handled in a more fundamental way.

And over Slack you suggested a very good solution for the summary layout flexibility - to have the end-of-test summary as a template file. We can ship k6 with a default one that we think is good for the majority of users. But we can also give the option to advanced users to specify specify their own alternative template for k6 run, if they have specific needs or preferences. I think this is something we can do relatively easily with the built-in Go text templates. We just need to expose a well thought-out data structure to that template, so that you could show the known metrics in a structured way, but also show any extra custom metrics below. Basically, the data structure should have "getter" methods that remember which metrics were already displayed and have a way of iterating over the rest at the end...

[sniku]

The thing I dislike most about the current proposal is the indentation of the so-called "minor" metrics. This has 2 big issues:

1. It somehow suggests that these metrics are a subset of the http_req_duration metric, which is not the case for all of them. http_req_blocked, http_req_connecting, and http_req_tls_handshaking don't have anything in common with http_req_duration...

I agree with this. http_req_blocked, http_req_connecting and http_req_tls_handshaking should not be nested under http_req_duration. It's clear to me now that those metrics don't have anything to do with http_req_duration 👍

I'm not convinced about the remaining minor metrics: http_req_sending, http_req_waiting and http_req_receiving - I think those perhaps should still be nested under the "parent" metric, but I don't have strong feelings about this any more. 😄

The template solution is very flexible, but after some thinking, I'm a little concerned that it might not be so easy for users to make changes to it.

1. Where would the end-of-test-summary-template be stored? Should it be a part of the script, and included in the options object or should it live externally somewhere in the k6 config?
2. Should users need to copy, edit, and save our default template to skip seeing metric they don't want? (there are many steps to accomplish something that seems simple).
3. Is it going to be easy for users to understand and edit the "Golang text template" to include the minor metrics? I imagine it's going to be somewhat finicky unless we provide copy-pasteable examples.
4. Would it be possible for us to provide several templates out of the box? If we provide few different templates I think most users won't need to create their own in the end. Something like this: --template=default or --template=full or --template=minimal ?

[na--]

I'm not convinced about the remaining minor metrics: http_req_sending, http_req_waiting and http_req_receiving - I think those perhaps should still be nested under the "parent" metric, but I don't have strong feelings about this any more. smile

If we didn't have sub-metrics, I wouldn't mind, but since we do, I think this would only add confusion. After all sub-metrics contain subsets of the values from the "parent" metric, so their stats would be somewhat similar. Whereas http_req_duration is the sum of sending + waiting + receiving, so it has wildly different values - you're not going to gain any clarity by putting these next to each other.

1. Where would the end-of-test-summary-template be stored? Should it be a part of the script, and included in the options object or should it live externally somewhere in the k6 config?

I was thinking that users can specify their custom templates in a file, and they can pass the path to that file as a CLI flag. Since the end-of-test summary is only applicable for local execution (i.e. k6 run), we don't need to concern ourselves with storing this path (or the template contents) in the options.

2. Should users need to copy, edit, and save our default template to skip seeing metric they don't want? (there are many steps to accomplish something that seems simple).

The metric skipping would probably be better handled by #1321

3. Is it going to be easy for users to understand and edit the "Golang text template" to include the minor metrics? I imagine it's going to be somewhat finicky unless we provide copy-pasteable examples.

True, though I'd consider this a feature for advanced users, I assume we're going to spend some time properly documenting the default template, and maybe even offer a few alternatives ourselves. And I assume that we'd have to answer the occasional support question...

4. Would it be possible for us to provide several templates out of the box? If we provide few different templates I think most users won't need to create their own in the end. Something like this: --template=default or --template=full or --template=minimal ?

Yes, that might work. Though the flag should probably be --sumary-template, to have the same prefix as the other related flags. We can offer a variety of templates OR the option to specify a completely custom one.

[na--]

Just a random thought, but if we have support for text templates of the end-of-test CLI summary, it's a very small amount of work to also support HTML templates... This would allow us to very easily produce well-formatted executive reports at the end of a test run! 🎉 I thought we had an open issue about something like this, but I couldn't find it, so I'm posting this here.

[na--]

Another somewhat random though - after considering #1120 and #1366, if we can make HTML reports, we should be easily able to make XML reports as well, which is essentially what JUnit (and other similar) results are...

[mostafa]

@na-- and @sniku,

how about implementing the TAP standard?
https://testanything.org/

[na--]

@mostafa, maybe I don't understand what TAP is about from the examples on that page, but I don't think it will be in any way useful in solving the problems presented in this issue? 😕

[mostafa]

It's a output formatting standard for test suites. It can be used for checks to show a better output, for example.
https://en.wikipedia.org/wiki/Test_Anything_Protocol

[na--]

@sniku, now that we have handleSummary() (#1768) and k6-summary in jslib, I think we should close this.

Instead, can you please open several issues/PRs in the jslib repo, one for each specific suggestion and issue you've found in the current text summary? For example, having a new option for generateTextSummary() called hiddenMetrics (or something like that) to reduce the noise... Alternatively, instead of overburdening the current summary with a bunch of options, we can have completely new helpers function that generate tailored summaries for different k6 use cases (e.g. functional tests). No idea what the best approach should be, but the k6 repo is no longer the place for these issues, unless the helper functions need more data than we currently expose.