K6 timings seem (very slow)

Grafana k6
1

newly trying out k6, and there’s something i am not getting. if i run the following “test”:

gdate +%s.%N ; curl <demo-url>/clients ;echo "" ; gdate +%s.%N

on my mac, i get a result:

1730735650.745561000
[{"id":1,"name":"Zasu Pitts","email":"pitts@silents.com"},{"id":2,"name":"Theda Bara","email":"bara@silents.com"},{"id":3,"name":"Lon Chaney","email":"chaney@silents.com"},{"id":4,"name":"Clara Bow","email":"clarabow@silents.com"},{"id":5,"name":"Rudolph Valentino","email":"valentino@silents.com"},{"id":6,"name":"Lillian Gish","email":"gish@silents.com"},{"id":7,"name":"John Garfield","email":"garfield@silents.com"},{"id":8,"name":"Douglas Fairbanks","email":"fairbanks@ss.com"},{"id":9,"name":"Buster Keaton","email":"keaton@silents.com"},{"id":10,"name":"Mary Pickford","email":"pickford@silents.com"}]
1730735650.819227000

which looks to me like it took all of 0.07 seconds.

if i run the same as a k6 invocation:

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

export default function () {
  http.get('http://<demo-url>/clients');
  sleep(1);
}

i get results that seem to me to indicate it took almost a second for the api call:

 k6 run single-test.js

         /\      Grafana   /‾‾/
    /\  /  \     |\  __   /  /
   /  \/    \    | |/ /  /   ‾‾\
  /          \   |   (  |  (‾)  |
 / __________ \  |_|\_\  \_____/

     execution: local
        script: single-test.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)


     data_received..................: 944 B 902 B/s
     data_sent......................: 132 B 126 B/s
     http_req_blocked...............: avg=18.32ms min=18.32ms med=18.32ms max=18.32ms p(90)=18.32ms p(95)=18.32ms
     http_req_connecting............: avg=16.24ms min=16.24ms med=16.24ms max=16.24ms p(90)=16.24ms p(95)=16.24ms
     http_req_duration..............: avg=22.91ms min=22.91ms med=22.91ms max=22.91ms p(90)=22.91ms p(95)=22.91ms
       { expected_response:true }...: avg=22.91ms min=22.91ms med=22.91ms max=22.91ms p(90)=22.91ms p(95)=22.91ms
     http_req_failed................: 0.00% 0 out of 1
     http_req_receiving.............: avg=165µs   min=165µs   med=165µs   max=165µs   p(90)=165µs   p(95)=165µs
     http_req_sending...............: avg=102µs   min=102µs   med=102µs   max=102µs   p(90)=102µs   p(95)=102µs
     http_req_tls_handshaking.......: avg=0s      min=0s      med=0s      max=0s      p(90)=0s      p(95)=0s
     http_req_waiting...............: avg=22.64ms min=22.64ms med=22.64ms max=22.64ms p(90)=22.64ms p(95)=22.64ms
     http_reqs......................: 1     0.955789/s
     iteration_duration.............: avg=1.04s   min=1.04s   med=1.04s   max=1.04s   p(90)=1.04s   p(95)=1.04s
     iterations.....................: 1     0.955789/s
     vus............................: 1     min=1      max=1
     vus_max........................: 1     min=1      max=1


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

which, if i am reading correctly, says it took 1.04 seconds. i’ve tried a few different configurations, and that 1 second result is pretty consistent.

so, i assume i am either reading this wrong or implementing it wrong. any help appreciated, thanks

2

Hi @grafpoo , welcome to the community forum!

It looks like you are looking at how long the whole execution took which also include the sleep of 1 second that is at the end of the script.

  sleep(1);

If you look at the http_req* metrics - likely mostly interested in http_req_duration you will notice that it obviously takes way less time.

Adding sleep is fairly common (which is why it is in most of the examples) as it is good idea to pace requests or to make it more realistic in how users do requests.

Hope this helps you!

3

ha, that’s embarrassing, of course you’re correct. thanks!