Request Failed warnings logged but http_req_failed is 0%

Grafana k6 OSS Support
1

Hi, I’m a bit confused by the output I get from k6.

There is a bunch of Request Failed warnings in the log below but in the results it stated that http_req_failed................: 0.00%. How can it be 0%?

  execution: local
     script: test.js
     output: -

  scenarios: (100.00%) 1 scenario, 500 max VUs, 3m30s max duration (incl. graceful stop):
           * default: Up to 500 looping VUs for 3m0s over 3 stages (gracefulRampDown: 30s, gracefulStop: 30s)

WARN[0141] Request Failed                                error="context deadline exceeded"
WARN[0142] Request Failed                                error="context deadline exceeded"
WARN[0144] Request Failed                                error="context deadline exceeded"
WARN[0146] Request Failed                                error="context deadline exceeded"
WARN[0147] Request Failed                                error="context deadline exceeded"
WARN[0148] Request Failed                                error="context deadline exceeded"
WARN[0148] Request Failed                                error="context deadline exceeded"
WARN[0149] Request Failed                                error="context deadline exceeded"
WARN[0149] Request Failed                                error="context deadline exceeded"
WARN[0149] Request Failed                                error="context deadline exceeded"
WARN[0150] Request Failed                                error="context deadline exceeded"
WARN[0150] Request Failed                                error="context deadline exceeded"
WARN[0152] Request Failed                                error="context deadline exceeded"
WARN[0154] Request Failed                                error="context deadline exceeded"
WARN[0155] Request Failed                                error="context deadline exceeded"
WARN[0155] Request Failed                                error="context deadline exceeded"
WARN[0156] Request Failed                                error="context deadline exceeded"
WARN[0156] Request Failed                                error="context deadline exceeded"
WARN[0156] Request Failed                                error="context deadline exceeded"
WARN[0157] Request Failed                                error="context deadline exceeded"
WARN[0159] Request Failed                                error="context deadline exceeded"
WARN[0159] Request Failed                                error="context deadline exceeded"
WARN[0159] Request Failed                                error="context deadline exceeded"
WARN[0159] Request Failed                                error="context deadline exceeded"
WARN[0162] Request Failed                                error="context deadline exceeded"
WARN[0162] Request Failed                                error="context deadline exceeded"
WARN[0164] Request Failed                                error="context deadline exceeded"
WARN[0164] Request Failed                                error="context deadline exceeded"
WARN[0164] Request Failed                                error="context deadline exceeded"
WARN[0164] Request Failed                                error="context deadline exceeded"
WARN[0164] Request Failed                                error="context deadline exceeded"
WARN[0166] Request Failed                                error="context deadline exceeded"
WARN[0167] Request Failed                                error="context deadline exceeded"
WARN[0167] Request Failed                                error="context deadline exceeded"
WARN[0167] Request Failed                                error="context deadline exceeded"
WARN[0167] Request Failed                                error="context deadline exceeded"
WARN[0168] Request Failed                                error="context deadline exceeded"
WARN[0168] Request Failed                                error="context deadline exceeded"
WARN[0169] Request Failed                                error="context deadline exceeded"
WARN[0172] Request Failed                                error="context deadline exceeded"
WARN[0172] Request Failed                                error="context deadline exceeded"
WARN[0174] Request Failed                                error="context deadline exceeded"
WARN[0174] Request Failed                                error="context deadline exceeded"
WARN[0176] Request Failed                                error="context deadline exceeded"
WARN[0177] Request Failed                                error="context deadline exceeded"
WARN[0191] Request Failed                                error="context deadline exceeded"

running (3m14.1s), 000/500 VUs, 8763 complete and 27 interrupted iterations
default ✓ [======================================] 000/500 VUs  3m0s

     data_received..................: 4.1 GB 21 MB/s
     data_sent......................: 15 MB  78 kB/s
     http_req_blocked...............: avg=186.04ms min=34.57ms  med=165.69ms max=2.71s  p(90)=282.68ms p(95)=331.31ms
     http_req_connecting............: avg=96.47ms  min=15.06ms  med=78.38ms  max=2.23s  p(90)=163.84ms p(95)=196.15ms
     http_req_duration..............: avg=3.48s    min=389.01ms med=1.87s    max=59.92s p(90)=5.89s    p(95)=10.93s
       { expected_response:true }...: avg=3.48s    min=389.01ms med=1.87s    max=59.92s p(90)=5.89s    p(95)=10.93s
     http_req_failed................: 0.00%  ✓ 0     ✗ 8763
     http_req_receiving.............: avg=3s       min=66.27ms  med=1.42s    max=59.57s p(90)=5.41s    p(95)=10.48s
     http_req_sending...............: avg=85.53µs  min=38µs     med=78µs     max=921µs  p(90)=120µs    p(95)=139µs
     http_req_tls_handshaking.......: avg=89.45ms  min=17.86ms  med=69.42ms  max=2.27s  p(90)=155.47ms p(95)=193.75ms
     http_req_waiting...............: avg=481.65ms min=217.45ms med=420.51ms max=12.97s p(90)=754.43ms p(95)=852.12ms
     http_reqs......................: 8763   45.140969/s
     iteration_duration.............: avg=3.66s    min=434.94ms med=2.08s    max=1m0s   p(90)=6.1s     p(95)=11.08s
     iterations.....................: 8763   45.140969/s
     vus............................: 1      min=1   max=500
     vus_max........................: 500    min=500 max=500
2

Hi @alex.fedoseev, welcome to the forum!

Looking at your summary, it seems like you are expecting this ‘Request Failed’ requests possibly by just having responseCallback: http.expectedStatuses(0) in the params of the given requests.

Am I correct in this assumption?

Either way http_req_failed is meant to be a Rate of http_reqs with expected_response:false against those with expected_response:true. So while the log message says that a “request failed” you can (and I guess you did) mark it to expect status code 0.

You can read the original issue that has way too much information and discusses other things. But the gist as explained above is that we wanted a way to mark requests/responses as either doing what is expected of them or not(at the current time limited only based on their status code) and unfortunately the name http_req_failed while short is not as expressive as exptected_response is.

Hope this helps you understand what is happening, and if you haven’t configured the expected statuses please share a script sample reproducing the problem.

3

Looking once more at the output you do have 27 interrupted iterations.

So it is also possible that your request failed due to the iteration taking longer then the gracefulRampDown/gracefulStop, but it seems like it’s too spread out and there to be more than 27 failures, so :man_shrugging: .

4

I actually did one of the very first test runs with config copied from the docs and slightly adjusted stages.

{
  "stages": [
    {
      "duration": "1m",
      "target": 10
    },
    {
      "duration": "1m",
      "target": 500
    },
    {
      "duration": "1m",
      "target": 0
    }
  ],
  "noConnectionReuse": true
}

And in my test file I just do http.get(url).

5

Seems to work for me

image
image1503×637 113 KB

import http from "k6/http";

export let options = {
  "stages": [
    {
      "duration": "1m",
      "target": 10
    },
    {
      "duration": "1m",
      "target": 500
    },
    {
      "duration": "1m",
      "target": 0
    }
  ],
  "noConnectionReuse": true
}

export default function() {
	http.get("https://test.k6.io");
}

I have no idea what is happening in your case, but without a fuller example I am not certain I can help you

6

A post was split to a new topic: Questions around http request