ContextQMD
Back to Hurl

Debug Tips

docs/tutorial/debug-tips.md

8.0.117.5 KB
Original Source

Debug Tips

Now that we have many requests in our test file, let's review some tips on how to debug the executed HTTP exchanges.

Verbose Mode

Using --verbose and --very-verbose for all entries

We can run our test with -v/--verbose option. In this mode, each entry is displayed with debugging information like request HTTP headers, response HTTP headers, cookie storage, duration etc...

shell
$ hurl --verbose --no-output basic.hurl
* Options:
*     fail fast: true
*     follow redirect: false
*     insecure: false
*     max redirect: 50
*     retry: 0
* ------------------------------------------------------------------------------
* Executing entry 1
*
* Cookie store:
*
* Request:
* GET http://localhost:3000
*
* Request can be run with the following curl command:
* curl 'http://localhost:3000'
*
> GET / HTTP/1.1
> Host: localhost:3000
> Accept: */*
> User-Agent: hurl/4.0.0
>
* Response: (received 9564 bytes in 11 ms)
*
< HTTP/1.1 200 OK
< Content-Type: text/html; charset=utf-8
< Content-Length: 9564
< Set-Cookie: x-session-id=s%3AEE3wsnrgUPSyAkgJZGa3jMWk7xmOtv4E.kXQpkmNBXnFOqmeSssqXnecF4qqv1D7bKu3rpbEJxmQ; Path=/; HttpOnly; SameSite=Strict
< Date: Wed, 26 Jul 2023 13:16:39 GMT
< Connection: keep-alive
< Keep-Alive: timeout=5
<
*
* ------------------------------------------------------------------------------
* Executing entry 2
*
* Cookie store:
* #HttpOnly_localhost	FALSE	/	FALSE	0	x-session-id	s%3AEE3wsnrgUPSyAkgJZGa3jMWk7xmOtv4E.kXQpkmNBXnFOqmeSssqXnecF4qqv1D7bKu3rpbEJxmQ
*
* Request:
* GET http://localhost:3000/not-found
*
* Request can be run with the following curl command:
* curl --cookie 'x-session-id=s%3AEE3wsnrgUPSyAkgJZGa3jMWk7xmOtv4E.kXQpkmNBXnFOqmeSssqXnecF4qqv1D7bKu3rpbEJxmQ' 'http://localhost:3000/not-found'
*
> GET /not-found HTTP/1.1
> Host: localhost:3000
> Accept: */*
> Cookie: x-session-id=s%3AEE3wsnrgUPSyAkgJZGa3jMWk7xmOtv4E.kXQpkmNBXnFOqmeSssqXnecF4qqv1D7bKu3rpbEJxmQ
> User-Agent: hurl/4.0.0
>
* Response: (received 2217 bytes in 3 ms)
*
< HTTP/1.1 404 Not Found
< Content-Type: text/html; charset=utf-8
< Content-Length: 2217
< Date: Wed, 26 Jul 2023 13:16:39 GMT
< Connection: keep-alive
< Keep-Alive: timeout=5
<
...

Lines beginning with * are debug info, lines that begin with > are HTTP request headers and lines that begin with < are HTTP response headers.

In each run request, we can also see a curl command line to replay this particular request:

shell
...
* Request can be run with the following curl command:
* curl --cookie 'x-session-id=s%3AEE3wsnrgUPSyAkgJZGa3jMWk7xmOtv4E.kXQpkmNBXnFOqmeSssqXnecF4qqv1D7bKu3rpbEJxmQ' 'http://localhost:3000/not-found'
...

In verbose mode, HTTP request and response bodies are not displayed in the debug logs. If you need to inspect the request or response body, you can display more logs with --very-verbose option:

shell
$ hurl --very-verbose --no-output basic.hurl
* Options:
*     fail fast: true
*     follow redirect: false
*     insecure: false
*     max redirect: 50
*     retry: 0
* ------------------------------------------------------------------------------
* Executing entry 1
*
* Cookie store:
*
* Request:
* GET http://localhost:3000
*
* Request can be run with the following curl command:
* curl 'http://localhost:3000'
*
** WARNING: failed to open cookie file ""
**   Trying 127.0.0.1:3000...
** Connected to localhost (127.0.0.1) port 3000 (#0)
> GET / HTTP/1.1
> Host: localhost:3000
> Accept: */*
> User-Agent: hurl/4.0.0
>
* Request body:
*
** Added cookie x-session-id="s%3A_l88C6GKbPeC5YuDLraWARY32NB3bP-l.T%2BViEW%2BqMrmLZDqwzDxtEbdtW67lCKt0jGvvlfqls%2FI" for domain localhost, path /, expire 0
** Connection #0 to host localhost left intact
* Response: (received 9564 bytes in 9 ms)
*
< HTTP/1.1 200 OK
< Content-Type: text/html; charset=utf-8
< Content-Length: 9564
< Set-Cookie: x-session-id=s%3A_l88C6GKbPeC5YuDLraWARY32NB3bP-l.T%2BViEW%2BqMrmLZDqwzDxtEbdtW67lCKt0jGvvlfqls%2FI; Path=/; HttpOnly; SameSite=Strict
< Date: Wed, 26 Jul 2023 13:19:45 GMT
< Connection: keep-alive
< Keep-Alive: timeout=5
<
* Response body:
* <!doctype html>
* <html lang="en">
*     <head>
*         <meta charset="UTF-8" />
*         <title>Movies Box</title>
*         <link rel="icon" type="image/png" href="/img/favicon.png" />
*         <link rel="stylesheet" href="/css/style.css" />
*     </head>
*     <body>
...
*     </body>
* </html>
*
* Timings:
* begin: 2023-07-26 13:19:45.378037 UTC
* end: 2023-07-26 13:19:45.387332 UTC
* namelookup: 4182 µs
* connect: 4798 µs
* app_connect: 0 µs
* pre_transfer: 4912 µs
* start_transfer: 9126 µs
* total: 9171 µs
*
* ------------------------------------------------------------------------------
* Executing entry 2
*
* Cookie store:
* #HttpOnly_localhost	FALSE	/	FALSE	0	x-session-id	s%3A_l88C6GKbPeC5YuDLraWARY32NB3bP-l.T%2BViEW%2BqMrmLZDqwzDxtEbdtW67lCKt0jGvvlfqls%2FI
*
* Request:
* GET http://localhost:3000/not-found
*
* Request can be run with the following curl command:
* curl --cookie 'x-session-id=s%3A_l88C6GKbPeC5YuDLraWARY32NB3bP-l.T%2BViEW%2BqMrmLZDqwzDxtEbdtW67lCKt0jGvvlfqls%2FI' 'http://localhost:3000/not-found'
*
** Found bundle for host: 0x60000340c930 [serially]
** Can not multiplex, even if we wanted to
** Re-using existing connection #0 with host localhost
> GET /not-found HTTP/1.1
> Host: localhost:3000
> Accept: */*
> Cookie: x-session-id=s%3A_l88C6GKbPeC5YuDLraWARY32NB3bP-l.T%2BViEW%2BqMrmLZDqwzDxtEbdtW67lCKt0jGvvlfqls%2FI
> User-Agent: hurl/4.0.0
>
* Request body:
*
** Connection #0 to host localhost left intact
* Response: (received 2217 bytes in 5 ms)
*
< HTTP/1.1 404 Not Found
< Content-Type: text/html; charset=utf-8
< Content-Length: 2217
< Date: Wed, 26 Jul 2023 13:19:45 GMT
< Connection: keep-alive
< Keep-Alive: timeout=5
<
* Response body:
* <!doctype html>
* <html lang="en">
...
* <h3>Not Found</h3>
* <h4>404</h4>
...
* </html>
*
* Timings:
* begin: 2023-07-26 13:19:45.390823 UTC
* end: 2023-07-26 13:19:45.395983 UTC
* namelookup: 44 µs
* connect: 0 µs
* app_connect: 0 µs
* pre_transfer: 126 µs
* start_transfer: 5100 µs
* total: 5124 µs
*
...

--very-verbose output is much more verbose; with body request and response, libcurl logs and response timings are displayed.

Debugging a specific entry

If you have a lot of entries (request / response pairs) in your Hurl file, using --verbose or --very-verbose can produce a lot of logs and can be difficult to analyse. Instead of passing options to the command line, you can use an [Options] section that will activate logs only for the specified entry:

hurl
# Checking our home page:
# ...

# Check that we have a 404 response for broken links:
# ...

# Check our health API:
# ...

# Check search API:
GET http://localhost:3000/api/search
[Options]
verbose: true
[Query]
q: 1982
sort: name

HTTP 200
# ...

And run it without --verbose option:

shell
$ hurl --no-output basic.hurl
* ------------------------------------------------------------------------------
* Executing entry 4
*
* Entry options:
* verbose: true
*
* Cookie store:
* #HttpOnly_localhost	FALSE	/	FALSE	0	x-session-id	s%3Aq_5wf1l2wBQ_96y6kpLeR0J4zLJF34EZ.n%2Bu1UJPqK0Ih2tz3Dd6w2kXAuufueT6HQDekBPtHhbc
*
* Request:
* GET http://localhost:3000/api/search
* [Query]
* q: 1982
* sort: name
*
* Request can be run with the following curl command:
* curl --cookie 'x-session-id=s%3Aq_5wf1l2wBQ_96y6kpLeR0J4zLJF34EZ.n%2Bu1UJPqK0Ih2tz3Dd6w2kXAuufueT6HQDekBPtHhbc' 'http://localhost:3000/api/search?q=1982&sort=name'
*
> GET /api/search?q=1982&sort=name HTTP/1.1
> Host: localhost:3000
> Accept: */*
> Cookie: x-session-id=s%3Aq_5wf1l2wBQ_96y6kpLeR0J4zLJF34EZ.n%2Bu1UJPqK0Ih2tz3Dd6w2kXAuufueT6HQDekBPtHhbc
> User-Agent: hurl/4.0.0
>
* Response: (received 1447 bytes in 0 ms)
*
< HTTP/1.1 200 OK
< Cache-control: no-store
< Content-Type: application/json; charset=utf-8
< Content-Length: 1447
< Date: Wed, 26 Jul 2023 13:29:39 GMT
< Connection: keep-alive
< Keep-Alive: timeout=5
<
*

Use Error Format

When you’ve asserts errors, the analysis can be difficult because you don’t have a lot of information apart of the expected values:

shell
$ hurl --test basic.hurl
basic.hurl: Running [1/1]
error: Assert failure
  --> basic.hurl:47:0
   |
47 | jsonpath "$[0].name" == "Robocop"
   |   actual:   string <Blade Runner>
   |   expected: string <Robocop>
   |

basic.hurl: Failure (4 request(s) in 16 ms)
--------------------------------------------------------------------------------
Executed files:  1
Succeeded files: 0 (0.0%)
Failed files:    1 (100.0%)
Duration:        17 ms

With --error-format option, you can opt in for a longer error description in case of error assert. On any error, we'll get the response headers and body. This is useful to see the expected values, especially in CI/CD context when you've to analyse past executed tests.

shell
$ hurl --error-format long --test basic.hurl
basic.hurl: Running [1/1]
HTTP/1.1 200
Cache-control: no-store
Content-Type: application/json; charset=utf-8
Content-Length: 1447
Date: Wed, 26 Jul 2023 14:14:00 GMT
Connection: keep-alive
Keep-Alive: timeout=5

[{"name":"Blade Runner","url":"/movies/blade-runner","director":"Ridley Scott","release_date":"1982-06-25","actors":["Harrison Ford","Rutger Hauer","Sean Young","Edward James Olmos"],"artwork":"/img/blade-runner-800x1200.webp","artwork_128":"/img/blade-runner-128x192.webp"},{"name":"Conan the Barbarian","url":"/movies/conan-the-barbarian","director":"John Milius","release_date":"1982-05-14","actors":["Arnold Schwarzenegger","James Earl Jones","Sandahl Bergman","Ben Davidson","Cassandra Gaviola","Gerry Lopez","Mako","Valerie Quennessen","William Smith","Max von Sydow"],"artwork":"/img/conan-the-barbarian-800x1200.webp","artwork_128":"/img/conan-the-barbarian-128x192.webp"},{"name":"The Dark Crystal","url":"/movies/the-dark-crystal","director":"Jim Henson","release_date":"1982-12-17","actors":["Stephen Garlick","Lisa Maxwell","Billie Whitelaw","Percy Edwards"],"artwork":"/img/the-dark-crystal-800x1200.webp","artwork_128":"/img/the-dark-crystal-128x192.webp"},{"name":"The Thing","url":"/movies/the-thing","director":"John Carpenter","release_date":"1982-06-25","actors":["Kurt Russell"],"artwork":"/img/the-thing-800x1200.webp","artwork_128":"/img/the-thing-128x192.webp"},{"name":"Tron","url":"/movies/tron","director":"Steven Lisberger","release_date":"1982-07-09","actors":["Jeff Bridges","Bruce Boxleitner","David Warner","Cindy Morgan","Barnard Hughes"],"artwork":"/img/tron-800x1200.webp","artwork_128":"/img/tron-128x192.webp"}]

error: Assert failure
  --> basic.hurl:47:0
   |
47 | jsonpath "$[0].name" == "Robocop"
   |   actual:   string <Blade Runner>
   |   expected: string <Robocop>
   |

basic.hurl: Failure (4 request(s) in 23 ms)

Get Response Body

When there are errors (HTTP runtimes or asserts errors), Hurl doesn't output HTTP response body. But sometimes the response body is necessary to explain failures. To do so, either:

  • use --very-verbose globally or per-request to get the full body response
hurl
GET https://foo.com/success
HTTP 200

GET https://foo.com/failure
[Options]
very-verbose: true
HTTP 200

GET https://foo.com/success
HTTP 200
  • use --output per-request and --ignore-asserts: --ignore-asserts will disable any check, while --output can be used to output any particular response body. With this file, the response of https://foo.com/failure will be outputted on standard output:
hurl
GET https://foo.com/success
HTTP 200

GET https://foo.com/failure
[Options]
# use - to output on standard output, foo.bin to save on disk 
output: -
HTTP 200

GET https://foo.com/success
HTTP 200

To get more information, one can also used a JSON report with --report-json. This option produces a structured export of all run datas (request headers, response headers, response body, curl debug command line etc...)

shell
$ hurl --report-json /tmp/report *.hurl

Include Headers Like curl

We can also run our file to only output HTTP headers, with -i/--include option. In this mode, headers of the last entry are displayed:

shell
$ hurl -i basic.hurl
HTTP/1.1 200
Cache-control: no-store
Content-Type: application/json; charset=utf-8
Content-Length: 1447
Date: Wed, 26 Jul 2023 14:58:27 GMT
Connection: keep-alive
Keep-Alive: timeout=5

[{"name":"Blade Runner","url":"/movies/blade-runner","director":"Ridley Scott","release_date":"1982-06-25",...

If you want to inspect any entry other than the last one, you can run your test to a given entry with the --to-entry option, starting at index 1:

shell
$ hurl -i --to-entry 2 basic.hurl
HTTP/1.1 404
Content-Type: text/html; charset=utf-8
Content-Length: 2217
Date: Wed, 26 Jul 2023 14:59:57 GMT
Connection: keep-alive
Keep-Alive: timeout=5

<!doctype html>
<html lang="en">
    <head>
        <meta charset="UTF-8" />
        <title></title>
...
    </body>
</html>

Export curl Commands

--curl command line option can be used to produce a file of curl commands of a run. This is equivalent of running Hurl in verbose and grepping the standard error for the debug curl command. The produced file is just a text list of curl debug commands, one line per entry (retry command are not written).

shell
$ echo 'HEAD https://example.org' | hurl --repeat 3 --curl /tmp/curl.txt
$ cat /tmp/curl.txt
curl --head 'https://example.org'
curl --head 'https://example.org'
curl --head 'https://example.org'

Using a Proxy

Finally, you can use a proxy between Hurl and your server to inspect requests and responses.

For instance, with mitmproxy:

  1. First, launch mitmproxy, it will listen to connections on 8888 port

    shell

$ mitmweb -p 8888 --web-port 8889 --web-open-browser Web server listening at http://127.0.0.1:8889/ Proxy server listening at http://*:8888 ```

  1. Then, run Hurl with -x/--proxy option

    shell

$ hurl --proxy localhost:8888 basic.hurl ```

The web interface of mitmproxy allows you to inspect, intercept any requests run by Hurl, and see the returned response to Hurl.