Understanding output generated by azure k6 task

Grafana k6 Extensions
1

Hi. I’m having hard times understanding what the output from test run means.
Text output is follows similar format as the command-line, however there are all sorts of characters added rendering it useless

image
image1818×473 34 KB

Below is the text copy-paste

2022-04-20T23:04:00.7631530Z e[31m     ✗ status is 200
2022-04-20T23:04:00.7631849Z       ↳  0% — ✓ 0 / ✗ 2391e[0m
2022-04-20T23:04:00.7632156Z e[31m     ✗ res body contains items
2022-04-20T23:04:00.7632394Z       ↳  0% — ✓ 0 / ✗ 2391e[0m
2022-04-20T23:04:00.7632493Z 
2022-04-20T23:04:00.7632684Z      █ setup
2022-04-20T23:04:00.7632768Z 
2022-04-20T23:04:00.7632964Z e[32m       ✓ status is 200e[0m
2022-04-20T23:04:00.7633310Z e[32m       ✓ res body contains accessTokene[0m
2022-04-20T23:04:00.7633492Z 
2022-04-20T23:04:00.7634279Z    e[31m✗e[0m GetMenus_Duratione[2m..............:e[0m avg=e[36m909.002426e[0m min=e[36m76.8148e[0m  med=e[36m761.8644e[0m max=e[36m2914.4075e[0m p(90)=e[36m1692.4524e[0m p(95)=e[36m2007.45595e[0m p(99)=e[36m2559.98371e[0m count=e[36m2391e[0m
2022-04-20T23:04:00.7635003Z    e[31m✗e[0m GetMenus_Requestse[2m..............:e[0m e[36m0.00%e[0m  e[36;2m✓ 0e[0m         e[36;2m✗ 2391e[0m 
2022-04-20T23:04:00.7635444Z      checkse[2m.........................:e[0m e[36m0.04%e[0m  e[36;2m✓ 2e[0m         e[36;2m✗ 4782e[0m 
2022-04-20T23:04:00.7635833Z      data_receivede[2m..................:e[0m e[36m1.2 MBe[0m e[36;2m19 kB/se[0m
2022-04-20T23:04:00.7636225Z      data_sente[2m......................:e[0m e[36m405 kBe[0m e[36;2m6.8 kB/se[0m
2022-04-20T23:04:00.7636799Z      http_req_blockede[2m...............:e[0m avg=e[36m6.33mse[0m     min=e[36m0se[0m       med=e[36m0se[0m       max=e[36m121.84mse[0m  p(90)=e[36m0se[0m        p(95)=e[36m76.76mse[0m    p(99)=e[36m82.52mse[0m    count=e[36m2392e[0m
2022-04-20T23:04:00.7637611Z      http_req_connectinge[2m............:e[0m avg=e[36m2.12mse[0m     min=e[36m0se[0m       med=e[36m0se[0m       max=e[36m68.69mse[0m   p(90)=e[36m0se[0m        p(95)=e[36m25.17mse[0m    p(99)=e[36m27.64mse[0m    count=e[36m2392e[0m
2022-04-20T23:04:00.7638384Z      http_req_duratione[2m..............:e[0m avg=e[36m908.67mse[0m   min=e[36m76.81mse[0m  med=e[36m761.72mse[0m max=e[36m2.91se[0m     p(90)=e[36m1.69se[0m     p(95)=e[36m2se[0m         p(99)=e[36m2.55se[0m      count=e[36m2392e[0m
2022-04-20T23:04:00.7639216Z        { expected_response:true }e[2m...:e[0m avg=e[36m131.27mse[0m   min=e[36m131.27mse[0m med=e[36m131.27mse[0m max=e[36m131.27mse[0m  p(90)=e[36m131.27mse[0m  p(95)=e[36m131.27mse[0m   p(99)=e[36m131.27mse[0m   count=e[36m1e[0m   
2022-04-20T23:04:00.7639849Z      http_req_failede[2m................:e[0m e[36m99.95%e[0m e[36;2m✓ 2391e[0m      e[36;2m✗ 1e[0m    
2022-04-20T23:04:00.7640586Z      http_req_receivinge[2m.............:e[0m avg=e[36m157.84µse[0m   min=e[36m0se[0m       med=e[36m0se[0m       max=e[36m2.11mse[0m    p(90)=e[36m670.62µse[0m  p(95)=e[36m916.35µse[0m   p(99)=e[36m1.02mse[0m     count=e[36m2392e[0m
2022-04-20T23:04:00.7641454Z      http_req_sendinge[2m...............:e[0m avg=e[36m34.17µse[0m    min=e[36m0se[0m       med=e[36m0se[0m       max=e[36m1.95mse[0m    p(90)=e[36m160.11µse[0m  p(95)=e[36m232.26µse[0m   p(99)=e[36m533.68µse[0m   count=e[36m2392e[0m
2022-04-20T23:04:00.7642252Z      http_req_tls_handshakinge[2m.......:e[0m avg=e[36m4.19mse[0m     min=e[36m0se[0m       med=e[36m0se[0m       max=e[36m86.24mse[0m   p(90)=e[36m0se[0m        p(95)=e[36m51.13mse[0m    p(99)=e[36m54.69mse[0m    count=e[36m2392e[0m
2022-04-20T23:04:00.7643025Z      http_req_waitinge[2m...............:e[0m avg=e[36m908.48mse[0m   min=e[36m76.59mse[0m  med=e[36m760.93mse[0m max=e[36m2.91se[0m     p(90)=e[36m1.69se[0m     p(95)=e[36m2se[0m         p(99)=e[36m2.55se[0m      count=e[36m2392e[0m
2022-04-20T23:04:00.7644529Z      http_reqse[2m......................:e[0m e[36m2392e[0m   e[36;2m39.862158/se[0m
2022-04-20T23:04:00.7645114Z      iteration_duratione[2m.............:e[0m avg=e[36m2.39se[0m      min=e[36m304.94mse[0m med=e[36m2.32se[0m    max=e[36m4.75se[0m     p(90)=e[36m3.19se[0m     p(95)=e[36m3.52se[0m      p(99)=e[36m4.07se[0m      count=e[36m2322e[0m
2022-04-20T23:04:00.7645705Z      iterationse[2m.....................:e[0m e[36m2321e[0m   e[36;2m38.678958/se[0m
2022-04-20T23:04:00.7646105Z      vuse[2m............................:e[0m e[36m198e[0m    e[36;2mmin=3e[0m       e[36;2mmax=198e[0m
2022-04-20T23:04:01.1067725Z      vus_maxe[2m........................:e[0m e[36m300e[0m    e[36;2mmin=300e[0m     e[36;2mmax=300e[0mtime="2022-04-20T23:04:01Z" level=error msg="some thresholds have failed"
2

Hi @RobertD

It seems like the color formatting is broken.

Could you please try to run the k6 with --no-color option.

Let me know if that helps!

Cheers

3

Hi @olegbespalov
Additional option made little difference.

Here is azure devops task setup:

image
image1037×474 13.1 KB

Here is output from test:

image
image1906×600 101 KB

Can you advise?

4

Hi @RobertD !

Thank you for your patience.

Well, it seems like it an issue with the Azure, I found a tread where people report about same behavior for different tools Strip or honor ASCII color coding · Issue #1569 · microsoft/azure-pipelines-agent · GitHub.

As the alternative, maybe it’s possible to consider an alternative output?

5

As much as i would prefer moving away from azure, this is the setup used where i work.
Thank you for your input Oleg.

6

As much as i would prefer moving away from azure, this is the setup used where i work.

To be honest, I wasn’t suggested to move away from the azure :see_no_evil: What I meant is instead of the standard k6’s output use some alternative (an external one) if that’s possible.

See that Results output

7

Hi Oleg,

Apologies for long delay - have been swamped at work.

How would i go about using a non-standard output? Do you suggest using idk powershell script to execute tests?
Is this known issue within the extension development team? Do you have a timeframe when this might be fixed?

Note: Linked issue appears to be closed by MS