Thresholds failing, displaying all 0's for response times

I am getting an error “ERRO[0013] some thresholds have failed”. Only one of the thresholds is displaying time and everything looks the same in all the other the calls. I can log the response times for all of the thresholds that failed in each function. Not sure what the problem is and could use some help.

I have set up thresholds:

//Set TLS version, skip cert verification, and response time thresholds
export const options = {
    tlsVersion: 'tls1.2',
    insecureSkipTLSVerify: true,
    thresholds : {
        'http_req_duration{name:"01 Authenticate User"}': ["max>0"],
        'http_req_duration{name:"02 Login"}': ["max>0"],
        'http_req_duration{name:"03 Get1"}': ["max>0"],
        'http_req_duration{name:"04 Post1"}': ["max>0"],
        'http_req_duration{name:"05 Post2"}': ["max>0"],
        'http_req_duration{name:"08 Post3"}': ["max>0"],
        'http_req_duration{name:"07 Post4"}': ["max>0"],
        'http_req_duration{name:"06 Put1"}': ["max>0"],
    }
};

I am getting an ERRO[0013] some thresholds have failed

Response time logged in function from one of the failed thresholds:

console.log(`Authenticate response time = ${response.timings.duration}`);
INFO[0003] Authenticate response time = 170.59           source=console

Get call for one of the failed threshold:

group("Authenticate User", function() {
        const response = http.get('https://#.#.#.#:$/api/auth/v1/authentication/basic', params, {"tags": {"name": "01 Authenticate User"}});
        //Log headers
        for (const p in response.headers) {
            if (response.headers.hasOwnProperty(p)) {
            console.log(p + ' : ' + response.headers[p]);
            }
        };

Terminal output:

     checks..............................: 100.00% ✓ 8        ✗ 0  
     data_received.......................: 202 kB  20 kB/s
     data_sent...........................: 197 kB  20 kB/s
     group_duration......................: avg=385.11ms min=146.72ms med=387.63ms max=682.62ms p(90)=584.32ms p(95)=633.47ms
     http_req_blocked....................: avg=22.27ms  min=2µs      med=3µs      max=178.17ms p(90)=53.45ms  p(95)=115.81ms
     http_req_connecting.................: avg=6.07ms   min=0s       med=0s       max=48.59ms  p(90)=14.57ms  p(95)=31.58ms 
     http_req_duration...................: avg=360.27ms min=137.07ms med=368.91ms max=681.69ms p(90)=583.2ms  p(95)=632.45ms
       { expected_response:true }........: avg=360.27ms min=137.07ms med=368.91ms max=681.69ms p(90)=583.2ms  p(95)=632.45ms
     ✗ { name:"01 Authenticate User" }...: avg=0s       min=0s       med=0s       max=0s       p(90)=0s       p(95)=0s      
     ✓ { name:"02 Login" }...............: avg=423.7ms  min=423.7ms  med=423.7ms  max=423.7ms  p(90)=423.7ms  p(95)=423.7ms 
     ✗ { name:"03 Get1" }................: avg=0s       min=0s       med=0s       max=0s       p(90)=0s       p(95)=0s      
     ✗ { name:"04 Post1" }...............: avg=0s       min=0s       med=0s       max=0s       p(90)=0s       p(95)=0s      
     ✗ { name:"05 Post2" }...............: avg=0s       min=0s       med=0s       max=0s       p(90)=0s       p(95)=0s      
     ✗ { name:"06 Put1" }................: avg=0s       min=0s       med=0s       max=0s       p(90)=0s       p(95)=0s      
     ✗ { name:"07 Post4" }...............: avg=0s       min=0s       med=0s       max=0s       p(90)=0s       p(95)=0s      
     ✗ { name:"08 Post3" }...............: avg=0s       min=0s       med=0s       max=0s       p(90)=0s       p(95)=0s      
     http_req_failed.....................: 0.00%   ✓ 0        ✗ 8  
     http_req_receiving..................: avg=21.41ms  min=182µs    med=308µs    max=168.49ms p(90)=51.29ms  p(95)=109.89ms
     http_req_sending....................: avg=128.25µs min=28µs     med=37µs     max=457µs    p(90)=373µs    p(95)=414.99µs
     http_req_tls_handshaking............: avg=16.17ms  min=0s       med=0s       max=129.39ms p(90)=38.81ms  p(95)=84.1ms  
     http_req_waiting....................: avg=338.73ms min=136.75ms med=305.51ms max=680.95ms p(90)=582.2ms  p(95)=631.58ms
     http_reqs...........................: 8       0.793099/s
     iteration_duration..................: avg=10.08s   min=10.08s   med=10.08s   max=10.08s   p(90)=10.08s   p(95)=10.08s  
     iterations..........................: 1       0.099137/s
     vus.................................: 1       min=1      max=1
     vus_max.............................: 1       min=1      max=1

ERRO[0013] some thresholds have failed     

Call code for successful threshold output:

    group("Session Login", function() {

        const response = http.post('https://#.#.#.#:#/core/app-session?client=app', params, {"tags": {"name": "02 Login"}});
        for (const p in response.headers) {
            if (response.headers.hasOwnProperty(p)) {
                console.log(p + ' : ' + response.headers[p]);
            }
        }

console.log(`Session Login response time = ${response.timings.duration}`);
INFO[0004] Session Login response time = 423.708         source=console

Hi @abooth

Welcome to the community forum :wave:

From the test output you share, and since the thresholds are defined with http_req_duration max>0, I would expect those thresholds to fail. In the output only the 02 Login request seems to have a max (or any) duration > 0.

Why you see a response time in the console for the Authenticate response time, while the metrics in the end are 0, I can’t say yet. Something might be causing failures in the test. Can you share the full (sanitized) script and complete output when running the test?

I tested the test below based on k6’s thresholds on tags example:

import http from 'k6/http';
import { sleep } from 'k6';
import { Rate } from 'k6/metrics';

export const options = {
    thresholds: {
        'http_req_duration{name:"01 Authenticate User"}': ["max>0"],
        'http_req_duration{name:"02 Login"}': ["max>0"],
    },
};

export default function () {
    const res1 = http.get('https://test-api.k6.io/public/crocodiles/1/', { "tags": { "name": "01 Authenticate User" } });
    const res2 = http.get('https://test-api.k6.io/public/crocodiles/2/', { "tags": { "name": "01 Authenticate User" } });

    const responses = http.batch([
        ['GET', 'https://test-api.k6.io/static/favicon.ico', null, { "tags": { "name": "02 Login" } }],
        [
            'GET',
            'https://test-api.k6.io/static/css/site.css',
            null,
            { "tags": { "name": "02 Login" } },
        ],
    ]);

    sleep(1);
}

And it worked for me:


          /\      |‾‾| /‾‾/   /‾‾/   
     /\  /  \     |  |/  /   /  /    
    /  \/    \    |     (   /   ‾‾\  
   /          \   |  |\  \ |  (‾)  | 
  / __________ \  |__| \__\ \_____/ .io

  execution: local
     script: thresholds-on-tags.js
     output: -

  scenarios: (100.00%) 1 scenario, 1 max VUs, 10m30s max duration (incl. graceful stop):
           * default: 1 iterations for each of 1 VUs (maxDuration: 10m0s, gracefulStop: 30s)


running (00m01.7s), 0/1 VUs, 1 complete and 0 interrupted iterations
default ✓ [======================================] 1 VUs  00m01.7s/10m0s  1/1 iters, 1 per VU

     data_received.......................: 18 kB  11 kB/s
     data_sent...........................: 1.2 kB 675 B/s
     http_req_blocked....................: avg=91.03ms  min=9µs      med=53.33ms  max=257.46ms p(90)=212.22ms p(95)=234.84ms
     http_req_connecting.................: avg=26.16ms  min=0s       med=0s       max=104.66ms p(90)=73.26ms  p(95)=88.96ms 
     http_req_duration...................: avg=118.78ms min=106.65ms med=117.32ms max=133.84ms p(90)=130.85ms p(95)=132.35ms
       { expected_response:true }........: avg=118.78ms min=106.65ms med=117.32ms max=133.84ms p(90)=130.85ms p(95)=132.35ms
     ✓ { name:"01 Authenticate User" }...: avg=128.86ms min=123.88ms med=128.86ms max=133.84ms p(90)=132.85ms p(95)=133.34ms
     ✓ { name:"02 Login" }...............: avg=108.71ms min=106.65ms med=108.71ms max=110.77ms p(90)=110.36ms p(95)=110.56ms
     http_req_failed.....................: 0.00%  ✓ 0        ✗ 4  
     http_req_receiving..................: avg=160.25µs min=69µs     med=142.5µs  max=287µs    p(90)=252.8µs  p(95)=269.89µs
     http_req_sending....................: avg=129.25µs min=18µs     med=47.5µs   max=404µs    p(90)=297.5µs  p(95)=350.75µs
     http_req_tls_handshaking............: avg=37.82ms  min=0s       med=0s       max=151.28ms p(90)=105.89ms p(95)=128.58ms
     http_req_waiting....................: avg=118.49ms min=106.46ms med=117.18ms max=133.15ms p(90)=130.32ms p(95)=131.74ms
     http_reqs...........................: 4      2.302862/s
     iteration_duration..................: avg=1.73s    min=1.73s    med=1.73s    max=1.73s    p(90)=1.73s    p(95)=1.73s   
     iterations..........................: 1      0.575716/s
     vus.................................: 1      min=1      max=1
     vus_max.............................: 1      min=1      max=1

So I expect we’ll spot something in your test and full output that can explain what is different in your case, if you can share those.

I would also recommend further debugging to see what is going on with the requests that are failing the thresholds. You’ll find some recommendations in https://github.com/grafana/k6-learn/blob/main/Modules/III-k6-Intermediate/01-How-to-debug-k6-load-testing-scripts.md.

I hope this helps.

Cheers!

Hi Imma,

Thanks so much for the response.

Here is a paired down sanitized script and the output. It shows that even though the Authenticate call succeeds and has a response time of 171.3ms the times are not displayed in the duration output. I do not see any real difference in the calls that would cause only the one to display the durations in the output.

Thanks,
Alan

Script:

import encoding from 'k6/encoding';
import http from 'k6/http'
import {check} from 'k6'

// **** Login *****

// Set username and password
const username = '*****************';
const password = '**************';

//Set TLS version and skip cert verification
export const options = {
  tlsVersion: 'tls1.2',
  insecureSkipTLSVerify: true,
  thresholds : {
    'http_req_duration{name:"01 Authenticate User"}': ["max>0"],
    'http_req_duration{name:"02 Login"}': ["max>0"],
  },
};

// Set credentials in base64
const credentials = `${username}:${password}`;

const encodedCredentials = encoding.b64encode(credentials);

//Set headers
const params = {
    headers: {
        'Content-type':'application/json',
        'Accept-Encoding':'gzip, deflate',
        'Authorization': `Basic ${encodedCredentials}`,
    },
};

export default function () {

	let res = http.get('https://app.loc:44320/api/auth/v1/authentication/basic', params, {"tags": {"name": "01 Authenticate User"}});

    //Log response status
	console.log(`response ${res.status} for VU = ${__VU} ITERA = ${__ITER}`)
    console.log(`Authenticate response time = ${res.timings.duration}\n`);

	check(res, {
		'is res status is 200 :' : (r) => r.status === 200,
	})


// **** Session Login ****

//Set headers
    const params2 = {
        headers: {
            'Content-type':'application/json',
        },
    };

	let res2 = http.post('https://app.loc:44320/core/app-session?client=app', params2, {"tags": {"name": "02 Login"}});

	console.log(`response ${res2.status} for VU = ${__VU} ITERA = ${__ITER}`)
    console.log(`Login response time = ${res2.timings.duration}\n`);

    check(res2, {
        'is res status is 200 :' : (r) => r.status === 200,
    })
}

Output:

          /\      |‾‾| /‾‾/   /‾‾/   
     /\  /  \     |  |/  /   /  /    
    /  \/    \    |     (   /   ‾‾\  
   /          \   |  |\  \ |  (‾)  | 
  / __________ \  |__| \__\ \_____/ .io

WARN[0000] SSLKEYLOGFILE was specified, logging TLS connection keys to '/Users/alan.booth/ssl-key.log'...  test_path="file:///Users/alan.booth/IdeaProjects/K6/debug.js"
  execution: local
     script: debug.js
     output: -

  scenarios: (100.00%) 1 scenario, 1 max VUs, 10m30s max duration (incl. graceful stop):
           * default: 1 iterations for each of 1 VUs (maxDuration: 10m0s, gracefulStop: 30s)

INFO[0000] Request:
GET /api/auth/v1/authentication/basic HTTP/1.1
Host: app.loc:44320
User-Agent: k6/0.40.0 (https://k6.io/)
Accept-Encoding: gzip, deflate
Authorization: Basic ***********************************************************************
Content-Type: application/json

  group= iter=0 request_id=6249ef25-96e8-4d8b-5425-cf35715bf256 scenario=default source=http-debug vu=1
INFO[0000] Response:
HTTP/1.1 200 OK
Transfer-Encoding: chunked
Cache-Control: no-cache, no-store, max-age=0, must-revalidate
Connection: keep-alive
Content-Type: application/json;charset=utf-8
Date: Mon, 23 Jan 2023 17:06:37 GMT
Expires: 0
Pragma: no-cache
Server: openresty/1.15.8.2
Set-Cookie: SESSION=OWFlMGFhNzctODliOS00MGNkLTk2ZTItMzQ4NjQ0YzQ5MGYx; Path=/; Secure; HttpOnly
X-Content-Type-Options: nosniff
X-Frame-Options: DENY
X-Xss-Protection: 1; mode=block

  group= iter=0 request_id=6249ef25-96e8-4d8b-5425-cf35715bf256 scenario=default source=http-debug vu=1
INFO[0000] response 200 for VU = 1 ITERA = 0             source=console
INFO[0000] Authenticate response time = 171.302          source=console
INFO[0000] Request:
POST /core/app-session?client=app HTTP/1.1
Host: app.loc:44320
User-Agent: k6/0.40.0 (https://k6.io/)
Content-Length: 50
Content-Type: application/x-www-form-urlencoded
Cookie: SESSION=OWFlMGFhNzctODliOS00MGNkLTk2ZTItMzQ4NjQ0YzQ5MGYx
Accept-Encoding: gzip

  group= iter=0 name="02 Login" request_id=1b061169-898c-4da5-5558-349834f931f5 scenario=default source=http-debug vu=1
INFO[0001] Response:
HTTP/1.1 200 OK
Transfer-Encoding: chunked
Cache-Control: no-cache, no-store, max-age=0, must-revalidate
Connection: keep-alive
Content-Type: application/json;charset=utf-8
Date: Mon, 23 Jan 2023 17:06:37 GMT
Expires: 0
Pragma: no-cache
Server: openresty/1.15.8.2
X-Content-Type-Options: nosniff
X-Frame-Options: DENY
X-Xss-Protection: 1; mode=block

  group= iter=0 name="02 Login" request_id=1b061169-898c-4da5-5558-349834f931f5 scenario=default source=http-debug vu=1
INFO[0001] response 200 for VU = 1 ITERA = 0             source=console
INFO[0001] Login response time = 510.388                 source=console

running (00m00.9s), 0/1 VUs, 1 complete and 0 interrupted iterations
default ✓ [======================================] 1 VUs  00m00.9s/10m0s  1/1 iters, 1 per VU

     ✓ is res status is 200 :

     checks..............................: 100.00% ✓ 2        ✗ 0
     data_received.......................: 3.7 kB  4.2 kB/s
     data_sent...........................: 916 B   1.0 kB/s
     http_req_blocked....................: avg=101.82ms min=2µs      med=101.82ms max=203.65ms p(90)=183.28ms p(95)=193.46ms
     http_req_connecting.................: avg=36.24ms  min=0s       med=36.24ms  max=72.49ms  p(90)=65.24ms  p(95)=68.86ms 
     http_req_duration...................: avg=340.84ms min=171.3ms  med=340.84ms max=510.38ms p(90)=476.47ms p(95)=493.43ms
       { expected_response:true }........: avg=340.84ms min=171.3ms  med=340.84ms max=510.38ms p(90)=476.47ms p(95)=493.43ms
     ✗ { name:"01 Authenticate User" }...: avg=0s       min=0s       med=0s       max=0s       p(90)=0s       p(95)=0s      
     ✓ { name:"02 Login" }...............: avg=510.38ms min=510.38ms med=510.38ms max=510.38ms p(90)=510.38ms p(95)=510.38ms
     http_req_failed.....................: 0.00%   ✓ 0        ✗ 2
     http_req_receiving..................: avg=499µs    min=358µs    med=499µs    max=640µs    p(90)=611.79µs p(95)=625.9µs 
     http_req_sending....................: avg=75.5µs   min=24µs     med=75.5µs   max=127µs    p(90)=116.7µs  p(95)=121.85µs
     http_req_tls_handshaking............: avg=64.46ms  min=0s       med=64.46ms  max=128.93ms p(90)=116.04ms p(95)=122.49ms
     http_req_waiting....................: avg=340.27ms min=170.81ms med=340.27ms max=509.72ms p(90)=475.83ms p(95)=492.77ms
     http_reqs...........................: 2       2.243435/s
     iteration_duration..................: avg=889.58ms min=889.58ms med=889.58ms max=889.58ms p(90)=889.58ms p(95)=889.58ms
     iterations..........................: 1       1.121718/s

ERRO[0004] some thresholds have failed
1 Like

Hi @abooth

Thanks for sharing the whole script. I’m not sure why yet, but for the http.get() I find you will have to pass the headers in the Params object.

That seems to work for me:

    const params2 = {
        headers: {
            'Content-type':'application/json',
        },
        tags: {
            name: '01 Authenticate User',
        }
    };

    let res2 = http.post('https://app.loc:44320/core/app-session?client=app', params2);

Looking at the logs you share, it seems the get request was not being tagged. In the http debug logs we can see group= iter=0 name="02 Login", but the get() request is not tagged. I do not find name="01 Authenticate User" in the log you shared. That explains the failing threshold even if the request is executed and returns a 200. An alternative that should also work is use http.post() on all requests. Those requests get tagged when you pass the headers as a third argument in the function call.

Let me know if that works for you, and we’ll further investigate why the differences when calling http.get() vs. http.post(). In case it’s something that needs fixing.

Cheers!

Thanks again Imma,

I was able to get all of them working with the move to params except the Login. That one fails for some reason if the tag is declared there. The other calls, (posts and put), worked with the tags in the params.

Output:

 checks..............................: 100.00% ✓ 8        ✗ 0  
 data_received.......................: 202 kB  62 kB/s
 data_sent...........................: 197 kB  61 kB/s
 http_req_blocked....................: avg=24.53ms  min=2µs      med=4.5µs    max=196.23ms p(90)=58.88ms  p(95)=127.55ms
 http_req_connecting.................: avg=8.55ms   min=0s       med=0s       max=68.42ms  p(90)=20.52ms  p(95)=44.47ms 
 http_req_duration...................: avg=375.19ms min=121.16ms med=347.56ms max=827.23ms p(90)=631.32ms p(95)=729.28ms
   { expected_response:true }........: avg=375.19ms min=121.16ms med=347.56ms max=827.23ms p(90)=631.32ms p(95)=729.28ms
 ✓ { name:"01 Authenticate User" }...: avg=173.85ms min=173.85ms med=173.85ms max=173.85ms p(90)=173.85ms p(95)=173.85ms
 ✓ { name:"02 Login" }...............: avg=266.36ms min=266.36ms med=266.36ms max=266.36ms p(90)=266.36ms p(95)=266.36ms
 ✓ { name:"03 Get1" }................: avg=827.23ms min=827.23ms med=827.23ms max=827.23ms p(90)=827.23ms p(95)=827.23ms
 ✓ { name:"04 Post1" }...............: avg=497.53ms min=497.53ms med=497.53ms max=497.53ms p(90)=497.53ms p(95)=497.53ms
 ✓ { name:"05 Post2" }...............: avg=121.16ms min=121.16ms med=121.16ms max=121.16ms p(90)=121.16ms p(95)=121.16ms
 ✓ { name:"06 Put1" }................: avg=139.24ms min=139.24ms med=139.24ms max=139.24ms p(90)=139.24ms p(95)=139.24ms
 ✓ { name:"07 Post3" }...............: avg=428.75ms min=428.75ms med=428.75ms max=428.75ms p(90)=428.75ms p(95)=428.75ms
 ✓ { name:"08 Post4" }...............: avg=547.36ms min=547.36ms med=547.36ms max=547.36ms p(90)=547.36ms p(95)=547.36ms
 http_req_failed.....................: 0.00%   ✓ 0        ✗ 8  
 http_req_receiving..................: avg=81.8ms   min=184µs    med=259µs    max=650.54ms p(90)=196.72ms p(95)=423.63ms
 http_req_sending....................: avg=103.25µs min=10µs     med=15.5µs   max=376µs    p(90)=325.6µs  p(95)=350.79µs
 http_req_tls_handshaking............: avg=15.79ms  min=0s       med=0s       max=126.37ms p(90)=37.91ms  p(95)=82.14ms 
 http_req_waiting....................: avg=293.28ms min=120.64ms med=220.4ms  max=546.75ms p(90)=512.16ms p(95)=529.45ms
 http_reqs...........................: 8       2.479364/s
 iteration_duration..................: avg=3.22s    min=3.22s    med=3.22s    max=3.22s    p(90)=3.22s    p(95)=3.22s   
 iterations..........................: 1       0.30992/s
 vus.................................: 1       min=1      max=1
 vus_max.............................: 1       min=1      max=1
1 Like

Hi @abooth

Good to know that works. It seems that the post command in the login does not accept the tags in the params object. I’ll investigate this a bit more to see if this is expected or something to fix in k6.

Cheers!

Hi Alan,

For the 02 Login tag to work I believe you need to change the code to:

//Set headers
    const params2 = {
        headers: {
            'Content-type': 'application/json',
        },
        tags: {
            name: '02 Login',
        }
    };

    let res2 = http.post('https://app.loc:44320/core/app-session?client=app', null, params2);

The method signatures expect a Params object as second parameter in the get method, and third parameter for post.

If the way you have it in your original script, I understand the post method was interpreting params2 as the body, and taking only the tag as parameters, but not the headers.

Let me know if that make sense.

Cheers!