Quando realizamos testes de performance, é importante contar com depuração para entender o que está acontecendo durante as requisições.
Nesse conteúdo, veremos como utilizar o modo de depuração do K6.
Mão na massa👩💻
Script de exemplo📚
Vamos começar com um script de exemplo, que faz uma requisição a API do K6 para listagem de crocodilos cadastrados:
import http from "k6/http";
export default function() {
http.get("https://test-api.k6.io/public/crocodiles");
}
Execução sem depuração ❌
Executando o script acima utilizando o comando k6 run debbug-request.js , teremos a seguinte saída:
/\ |‾‾| /‾‾/ /‾‾/
/\ / \ | |/ / / /
/ \/ \ | ( / ‾‾\
/ \ | |\ \ | (‾) |
/ __________ \ |__| \__\ \_____/ .io
execution: local
script: .\debbug-request.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 (00m00.8s), 0/1 VUs, 1 complete and 0 interrupted iterations
default ✓ [======================================] 1 VUs 00m00.8s/10m0s 1/1 iters, 1 per VU
data_received..................: 6.5 kB 8.3 kB/s
data_sent......................: 638 B 809 B/s
http_req_blocked...............: avg=235.45ms min=0s med=235.45ms max=470.9ms p(90)=423.81ms p(95)=447.35ms
http_req_connecting............: avg=72.03ms min=0s med=72.03ms max=144.07ms p(90)=129.67ms p(95)=136.87ms
http_req_duration..............: avg=138.38ms min=124.39ms med=138.38ms max=152.37ms p(90)=149.57ms p(95)=150.97ms
{ expected_response:true }...: avg=138.38ms min=124.39ms med=138.38ms max=152.37ms p(90)=149.57ms p(95)=150.97ms
http_req_failed................: 0.00% ✓ 0 ✗ 2
http_req_receiving.............: avg=7.01ms min=5.33ms med=7.01ms max=8.69ms p(90)=8.35ms p(95)=8.52ms
http_req_sending...............: avg=0s min=0s med=0s max=0s p(90)=0s p(95)=0s
http_req_tls_handshaking.......: avg=94.66ms min=0s med=94.66ms max=189.32ms p(90)=170.39ms p(95)=179.85ms
http_req_waiting...............: avg=131.36ms min=119.06ms med=131.36ms max=143.67ms p(90)=141.21ms p(95)=142.44ms
http_reqs......................: 2 2.534658/s
iteration_duration.............: avg=768.07ms min=768.07ms med=768.07ms max=768.07ms p(90)=768.07ms p(95)=768.07ms
iterations.....................: 1 1.267329/s
Execução com depuração🔬
Para habilitar a depuração, adicionamos à execução do script a propriedade --http-debug. Há dois modos possíveis de depuração:
- --http-debug: exibe as solicitações e respostas HTTP, ignorando o corpo.
- --http-debug="full": exibe as solicitações e respostas HTTP, incluindo o corpo inteiro.
Executando o script utilizando o comando k6 run --http-debug debbug-request.js, teremos a seguinte saída:
/\ |‾‾| /‾‾/ /‾‾/
/\ / \ | |/ / / /
/ \/ \ | ( / ‾‾\
/ \ | |\ \ | (‾) |
/ __________ \ |__| \__\ \_____/ .io
execution: local
script: .\debbug-request.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[0001] Request:
GET /public/crocodiles HTTP/1.1
Host: test-api.k6.io
User-Agent: k6/0.38.3 (https://k6.io/)
Accept-Encoding: gzip
group= iter=0 request_id=f6816da2-a76a-4a6f-55ba-7d2af7183f50 scenario=default source=http-debug vu=1
INFO[0001] Response:
HTTP/1.1 301 Moved Permanently
Connection: keep-alive
Content-Type: text/html; charset=utf-8
Date: Sat, 25 Feb 2023 14:57:12 GMT
Location: /public/crocodiles/
X-Frame-Options: SAMEORIGIN
Content-Length: 0
group= iter=0 request_id=f6816da2-a76a-4a6f-55ba-7d2af7183f50 scenario=default source=http-debug vu=1
INFO[0001] Request:
GET /public/crocodiles/ HTTP/1.1
Host: test-api.k6.io
User-Agent: k6/0.38.3 (https://k6.io/)
Referer: https://test-api.k6.io/public/crocodiles
Accept-Encoding: gzip
group= iter=0 request_id=7bc1e20f-7fef-4e88-5b40-d2f718df9529 scenario=default source=http-debug vu=1
INFO[0001] Response:
HTTP/1.1 200 OK
Content-Length: 609
Allow: GET, HEAD, OPTIONS
Connection: keep-alive
Content-Type: application/json
Date: Sat, 25 Feb 2023 14:57:12 GMT
Vary: Accept
X-Frame-Options: SAMEORIGIN
group= iter=0 request_id=7bc1e20f-7fef-4e88-5b40-d2f718df9529 scenario=default source=http-debug vu=1
running (00m00.7s), 0/1 VUs, 1 complete and 0 interrupted iterations
default ✗ [======================================] 1 VUs 00m00.7s/10m0s 1/1 iters, 1 per VU
data_received..................: 6.5 kB 9.3 kB/s
data_sent......................: 638 B 912 B/s
http_req_blocked...............: avg=165.14ms min=514.4µs med=165.14ms max=329.77ms p(90)=296.84ms p(95)=313.3ms
http_req_connecting............: avg=53.29ms min=0s med=53.29ms max=106.58ms p(90)=95.92ms p(95)=101.25ms
http_req_duration..............: avg=157.83ms min=133ms med=157.83ms max=182.67ms p(90)=177.7ms p(95)=180.18ms
{ expected_response:true }...: avg=157.83ms min=133ms med=157.83ms max=182.67ms p(90)=177.7ms p(95)=180.18ms
http_req_failed................: 0.00% ✓ 0 ✗ 2
http_req_receiving.............: avg=45.06ms min=17.38ms med=45.06ms max=72.74ms p(90)=67.21ms p(95)=69.98ms
http_req_sending...............: avg=1.07ms min=0s med=1.07ms max=2.15ms p(90)=1.94ms p(95)=2.05ms
http_req_tls_handshaking.......: avg=92.1ms min=0s med=92.1ms max=184.2ms p(90)=165.78ms p(95)=174.99ms
http_req_waiting...............: avg=111.69ms min=107.76ms med=111.69ms max=115.61ms p(90)=114.83ms p(95)=115.22ms
http_reqs......................: 2 2.857884/s
iteration_duration.............: avg=683.8ms min=683.8ms med=683.8ms max=683.8ms p(90)=683.8ms p(95)=683.8ms
iterations.....................: 1 1.428942/s
Já executando o script com o comandok6 run --http-debug="full" debbug-request.js obtemos o seguinte resultado:
/\ |‾‾| /‾‾/ /‾‾/
/\ / \ | |/ / / /
/ \/ \ | ( / ‾‾\
/ \ | |\ \ | (‾) |
/ __________ \ |__| \__\ \_____/ .io
execution: local
script: .\debbug-request.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[0001] Request:
GET /public/crocodiles HTTP/1.1
Host: test-api.k6.io
User-Agent: k6/0.38.3 (https://k6.io/)
Accept-Encoding: gzip
group= iter=0 request_id=af32a69d-fb1a-42dc-7434-d9de66c964b3 scenario=default source=http-debug vu=1
INFO[0002] Response:
HTTP/1.1 301 Moved Permanently
Connection: keep-alive
Content-Type: text/html; charset=utf-8
Date: Sat, 25 Feb 2023 15:08:14 GMT
Location: /public/crocodiles/
X-Frame-Options: SAMEORIGIN
Content-Length: 0
group= iter=0 request_id=af32a69d-fb1a-42dc-7434-d9de66c964b3 scenario=default source=http-debug vu=1
INFO[0003] Request:
GET /public/crocodiles/ HTTP/1.1
Host: test-api.k6.io
User-Agent: k6/0.38.3 (https://k6.io/)
Referer: https://test-api.k6.io/public/crocodiles
Accept-Encoding: gzip
group= iter=0 request_id=22cbfd7c-4d67-4ca7-5ab2-d12a07dd1ee8 scenario=default source=http-debug vu=1
INFO[0003] Response:
HTTP/1.1 200 OK
Content-Length: 609
Allow: GET, HEAD, OPTIONS
Connection: keep-alive
Content-Type: application/json
Date: Sat, 25 Feb 2023 15:08:14 GMT
Vary: Accept
X-Frame-Options: SAMEORIGIN
[{"id":1,"name":"Bert","sex":"M","date_of_birth":"2010-06-27","age":12},{"id":2,"name":"Ed","sex":"M","date_of_birth":"1995-02-27","age":27},{"id":3,"name":"Lyle the Crocodile","sex":"M","date_of_birth":"1985-03-03","age":37},{"id":4,"name":"Solomon","sex":"M","date_of_birth":"1993-12-25","age":29},{"id":5,"name":"The gharial","sex":"F","date_of_birth":"2004-06-28","age":18},{"id":6,"name":"Sang Buaya","sex":"F","date_of_birth":"2006-01-28","age":17},{"id":7,"name":"Sobek","sex":"F","date_of_birth":"1854-09-02","age":168},{"id":8,"name":"Curious George","sex":"M","date_of_birth":"1981-01-03","age":42}] group= iter=0 request_id=22cbfd7c-4d67-4ca7-5ab2-d12a07dd1ee8 scenario=default source=http-debug vu=1
running (00m01.9s), 0/1 VUs, 1 complete and 0 interrupted iterations
default ✗ [======================================] 1 VUs 00m01.9s/10m0s 1/1 iters, 1 per VU
data_received..................: 6.5 kB 3.4 kB/s
data_sent......................: 638 B 330 B/s
http_req_blocked...............: avg=729ms min=0s med=729ms max=1.45s p(90)=1.31s p(95)=1.38s
http_req_connecting............: avg=567.16ms min=0s med=567.16ms max=1.13s p(90)=1.02s p(95)=1.07s
http_req_duration..............: avg=206.83ms min=177.96ms med=206.83ms max=235.71ms p(90)=229.94ms p(95)=232.82ms
{ expected_response:true }...: avg=206.83ms min=177.96ms med=206.83ms max=235.71ms p(90)=229.94ms p(95)=232.82ms
http_req_failed................: 0.00% ✓ 0 ✗ 2
http_req_receiving.............: avg=86.7ms min=43.21ms med=86.7ms max=130.2ms p(90)=121.5ms p(95)=125.85ms
http_req_sending...............: avg=0s min=0s med=0s max=0s p(90)=0s p(95)=0s
http_req_tls_handshaking.......: avg=102.33ms min=0s med=102.33ms max=204.66ms p(90)=184.19ms p(95)=194.42ms
http_req_waiting...............: avg=120.12ms min=105.51ms med=120.12ms max=134.74ms p(90)=131.82ms p(95)=133.28ms
http_reqs......................: 2 1.03424/s
iteration_duration.............: avg=1.9s min=1.9s med=1.9s max=1.9s p(90)=1.9s p(95)=1.9s
iterations.....................: 1 0.51712/s
vus............................: 1 min=1 max=1
vus_max........................: 1 min=1 max=1
Conclusão💖
O modo de depuração do K6 nos permite verificar melhor os resultados das requisições e entender o que está acontecendo durante os testes de performance. Dessa forma, conseguimos aprimorar nossos resultados.
Gostou do conteúdo e quer saber mais sobre testes de performance com K6? Então não deixe de conferir meu curso na Udemy:
Top comments (0)