Skip to content

stork-agent bind exporter frequently errors on POST to /json/v1

Describe the bug

We have added the stork-agent to standard ISC bind containers (internetsystemsconsortium/bind9:9.18) and run them side by side with the named process. While testing we found that every minute following error messages get created:

time="2022-07-04 06:57:24" level="error" msg="Problem getting stats from BIND 9: Post \"http://127.0.0.1:80/json/v1\": EOF\nproblem sending POST to http://127.0.0.1:80/json/v1\nisc.org/stork/agent.(*HTTPClient).Call\n\t/builds/isc-projects/stork/backend/agent/caclient.go:101\nisc.org/stork/agent.(*PromBind9Exporter).collectStats\n\t/builds/isc-projects/stork/backend/agent/prombind9exporter.go:1187\nisc.org/stork/agent.(*PromBind9Exporter).Collect\n\t/builds/isc-projects/stork/backend/agent/prombind9exporter.go:556\ngithub.com/prometheus/client_golang/prometheus.(*Registry).Gather.func1\n\t/builds/isc-projects/stork/tools/golang/gopath/pkg/mod/github.com/prometheus/client_golang@v1.7.0/prometheus/registry.go:444\nruntime.goexit\n\t/builds/isc-projects/stork/tools/golang/go/src/runtime/asm_amd64.s:1581" file="prombind9exporter.go:1190 "
time="2022-07-04 06:57:24" level="error" msg="Some errors were encountered while collecting stats from BIND 9: Post \"http://127.0.0.1:80/json/v1\": EOF\nproblem sending POST to http://127.0.0.1:80/json/v1\nisc.org/stork/agent.(*HTTPClient).Call\n\t/builds/isc-projects/stork/backend/agent/caclient.go:101\nisc.org/stork/agent.(*PromBind9Exporter).collectStats\n\t/builds/isc-projects/stork/backend/agent/prombind9exporter.go:1187\nisc.org/stork/agent.(*PromBind9Exporter).Collect\n\t/builds/isc-projects/stork/backend/agent/prombind9exporter.go:556\ngithub.com/prometheus/client_golang/prometheus.(*Registry).Gather.func1\n\t/builds/isc-projects/stork/tools/golang/gopath/pkg/mod/github.com/prometheus/client_golang@v1.7.0/prometheus/registry.go:444\nruntime.goexit\n\t/builds/isc-projects/stork/tools/golang/go/src/runtime/asm_amd64.s:1581" file="prombind9exporter.go:565  "

While debugging we found that the bind exporter runs following POST request to the JSON API of bind:

POST /json/v1 HTTP/1.1
Host: 127.0.0.1:80
User-Agent: Go-http-client/1.1
Content-Length: 2
Content-Type: application/json
Accept-Encoding: gzip

{}

To Reproduce

In tcpdump we can see that every second request (on the keep-alived connection) gets FINed by the bind httpd server. The reason seems to be that the bind httpd is not properly handling this (and all?) POST requests with data. This can easily reproduced with curl:

# curl -v -d '{}' -o/dev/null http://127.0.0.1:80/json/v1 -o/dev/null http://127.0.0.1:80/json/v1
*   Trying 127.0.0.1:80...
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
  0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0* Connected to 127.0.0.1 (127.0.0.1) port 80 (#0)
> POST /json/v1 HTTP/1.1
> Host: 127.0.0.1
> User-Agent: curl/7.81.0
> Accept: */*
> Content-Length: 2
> Content-Type: application/x-www-form-urlencoded
> 
} [2 bytes data]
* Mark bundle as not supporting multiuse
< HTTP/1.1 200 OK
< Content-Type: application/json
< Date: Mon, 04 Jul 2022 07:09:27 GMT
< Expires: Mon, 04 Jul 2022 07:09:27 GMT
< Last-Modified: Mon, 04 Jul 2022 07:09:27 GMT
< Pragma: no-cache
< Cache-Control: no-cache
< Server: libisc
< Content-Length: 58431
< 
{ [11824 bytes data]
100 58433  100 58431  100     2  21.7M    782 --:--:-- --:--:-- --:--:-- 27.8M
* Connection #0 to host 127.0.0.1 left intact
* Found bundle for host 127.0.0.1: 0x5568a154fec0 [serially]
* Can not multiplex, even if we wanted to!
* Re-using existing connection! (#0) with host 127.0.0.1
* Connected to 127.0.0.1 (127.0.0.1) port 80 (#0)
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
  0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0> POST /json/v1 HTTP/1.1
> Host: 127.0.0.1
> User-Agent: curl/7.81.0
> Accept: */*
> Content-Length: 2
> Content-Type: application/x-www-form-urlencoded
> 
} [2 bytes data]
* Connection died, retrying a fresh connect (retry count: 1)

^^^^^^^^^^^^^^^^^^^^^ SECOND REQUEST DIES ^^^^^^^^^^^^^^^^^^^^^

100     2    0     0  100     2      0   1282 --:--:-- --:--:-- --:--:--  2000
* Closing connection 0
* Issue another request to this URL: 'http://127.0.0.1:80/json/v1'
* Hostname 127.0.0.1 was found in DNS cache
*   Trying 127.0.0.1:80...
* Connected to 127.0.0.1 (127.0.0.1) port 80 (#1)
> POST /json/v1 HTTP/1.1
> Host: 127.0.0.1
> User-Agent: curl/7.81.0
> Accept: */*
> Content-Length: 2
> Content-Type: application/x-www-form-urlencoded
> 
} [2 bytes data]
* Mark bundle as not supporting multiuse
< HTTP/1.1 200 OK
< Content-Type: application/json
< Date: Mon, 04 Jul 2022 07:09:27 GMT
< Expires: Mon, 04 Jul 2022 07:09:27 GMT
< Last-Modified: Mon, 04 Jul 2022 07:09:27 GMT
< Pragma: no-cache
< Cache-Control: no-cache
< Server: libisc
< Content-Length: 58431
< 
{ [35984 bytes data]
100 58433  100 58431  100     2  11.4M    409 --:--:-- --:--:-- --:--:-- 11.4M
* Connection #1 to host 127.0.0.1 left intact

Expected behavior

No error message gets logged.

Additional Information

The problem does not occur when doing a GET to the endpoint or even an empty POST. I tried to find if POST is allowed for the statistics-channel in bind but did not find anything in the docs. Fixing is easily possible by using GET requests, though - although caclient.go is missing a function to do a simple GET request and probably this is the reason why an empty POST is currently sent in https://github.com/isc-projects/stork/blob/master/backend/agent/prombind9exporter.go#L1164-L1187

Environment:

  • BIND9 version: 9.18.4-1+ubuntu22.04.1+isc+1
  • Stork: 1.4.0
  • OS: Ubuntu 22.04 LTS (docker container internetsystemsconsortium/bind9:9.18)