Handler for GET /system/df returned error: context canceled - Error every 60 seconds

I’m getting this error exactly every 60 seconds: Been trying to diagnose it for some hours now and it’s driving me nuts!

This is what I’ve tested:

Disabled zabbix-agent, netdata, telegraf or any tool that could be pulling stats from docker: No change

Stopped every single container running: No change

Stopped docker altogether: Obviously, the issue gets solved.

The reason I point the last test out, although obvious, is because I noticed this issue by external factors.

See, docker is installed inside a VM, on an Intel NUC and every 60 seconds, exactly at the same timestamp the errors are being logged, the CPU fan revs up for like 15 seconds, then stops again.

$ docker info
Client:
 Context:    default
 Debug Mode: false
 Plugins:
  app: Docker App (Docker Inc., v0.9.1-beta3)
  buildx: Build with BuildKit (Docker Inc., v0.5.1-tp-docker)

Server:
 Containers: 12
  Running: 9
  Paused: 0
  Stopped: 3
 Images: 25
 Server Version: 20.10.6
 Storage Driver: btrfs
  Build Version: Btrfs v5.11.1
  Library Version: 102
 Logging Driver: json-file
 Cgroup Driver: systemd
 Cgroup Version: 2
 Plugins:
  Volume: local
  Network: bridge host ipvlan macvlan null overlay
  Log: awslogs fluentd gcplogs gelf journald json-file local logentries splunk syslog
 Swarm: inactive
 Runtimes: io.containerd.runtime.v1.linux runc io.containerd.runc.v2
 Default Runtime: runc
 Init Binary: docker-init
 containerd version: 05f951a3781f4f2c1911b05e61c160e9c30eaa8e.m
 runc version: 12644e614e25b05da6fd08a38ffa0cfe1903fdec
 init version: de40ad0
 Security Options:
  seccomp
   Profile: default
  cgroupns
 Kernel Version: 5.11.16-arch1-1
 Operating System: Arch Linux
 OSType: linux
 Architecture: x86_64
 CPUs: 4
 Total Memory: 3.836GiB
 Name: jarvis
 ID: xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx (redacted)
 Docker Root Dir: /var/lib/docker
 Debug Mode: false
 Registry: https://index.docker.io/v1/
 Labels:
 Experimental: false
 Insecure Registries:
  127.0.0.0/8
 Live Restore Enabled: false

WARNING: No kernel memory limit support
WARNING: No oom kill disable support




Apr 25 00:44:08 jarvis dockerd[704]: time="2021-04-25T00:44:08.017963744+02:00" level=error msg="Handler for GET /system/df returned error: context canceled"
Apr 25 00:45:08 jarvis dockerd[704]: time="2021-04-25T00:45:08.380682351+02:00" level=error msg="Handler for GET /system/df returned error: context canceled"
Apr 25 00:46:08 jarvis dockerd[704]: time="2021-04-25T00:46:08.702935067+02:00" level=error msg="Handler for GET /system/df returned error: context canceled"
Apr 25 00:47:08 jarvis dockerd[704]: time="2021-04-25T00:47:08.375923516+02:00" level=error msg="Handler for GET /system/df returned error: context canceled"
Apr 25 00:48:07 jarvis dockerd[704]: time="2021-04-25T00:48:07.936722382+02:00" level=error msg="Handler for GET /system/df returned error: context canceled"
Apr 25 00:49:08 jarvis dockerd[704]: time="2021-04-25T00:49:08.416427201+02:00" level=error msg="Handler for GET /system/df returned error: context canceled"
Apr 25 00:50:08 jarvis dockerd[704]: time="2021-04-25T00:50:08.455649087+02:00" level=error msg="Handler for GET /system/df returned error: context canceled"
Apr 25 00:51:08 jarvis dockerd[704]: time="2021-04-25T00:51:08.526290031+02:00" level=error msg="Handler for GET /system/df returned error: context canceled"
Apr 25 00:52:08 jarvis dockerd[704]: time="2021-04-25T00:52:08.359336232+02:00" level=error msg="Handler for GET /system/df returned error: context canceled"
Apr 25 00:53:08 jarvis dockerd[704]: time="2021-04-25T00:53:08.344667458+02:00" level=error msg="Handler for GET /system/df returned error: context canceled"
Apr 25 00:54:07 jarvis dockerd[704]: time="2021-04-25T00:54:07.874002859+02:00" level=error msg="Handler for GET /system/df returned error: context canceled"
Apr 25 00:55:08 jarvis dockerd[704]: time="2021-04-25T00:55:08.131910242+02:00" level=error msg="Handler for GET /system/df returned error: context canceled"
Apr 25 00:56:08 jarvis dockerd[704]: time="2021-04-25T00:56:08.414118329+02:00" level=error msg="Handler for GET /system/df returned error: context canceled"
Apr 25 00:57:08 jarvis dockerd[704]: time="2021-04-25T00:57:08.609506884+02:00" level=error msg="Handler for GET /system/df returned error: context canceled"
Apr 25 00:58:07 jarvis dockerd[704]: time="2021-04-25T00:58:07.899771968+02:00" level=error msg="Handler for GET /system/df returned error: context canceled"
Apr 25 00:59:08 jarvis dockerd[704]: time="2021-04-25T00:59:08.311113352+02:00" level=error msg="Handler for GET /system/df returned error: context canceled"
Apr 25 01:00:08 jarvis dockerd[704]: time="2021-04-25T01:00:08.479744869+02:00" level=error msg="Handler for GET /system/df returned error: context canceled"
Apr 25 01:01:08 jarvis dockerd[704]: time="2021-04-25T01:01:08.446439268+02:00" level=error msg="Handler for GET /system/df returned error: context canceled"
Apr 25 01:02:08 jarvis dockerd[704]: time="2021-04-25T01:02:08.439946388+02:00" level=error msg="Handler for GET /system/df returned error: context canceled"
Apr 25 01:03:08 jarvis dockerd[704]: time="2021-04-25T01:03:08.305311938+02:00" level=error msg="Handler for GET /system/df returned error: context canceled"

I have activated debug and found something that might point us in the right direction, but can’t wrap my head around it:

Apr 26 17:34:06 jarvis dockerd[702]: time="2021-04-26T17:34:06.015042342+02:00" level=debug msg="Health check for container 9a1a3d40b49a27cfa81beaa6ec09b151732995bf2ead1e1b86b5e743cf9fd5b9 done (exitCode=0)"
Apr 26 17:34:06 jarvis dockerd[702]: time="2021-04-26T17:34:06.116170303+02:00" level=debug msg="Calling GET /_ping"
Apr 26 17:34:06 jarvis dockerd[702]: time="2021-04-26T17:34:06.938163882+02:00" level=debug msg="Calling GET /v1.41/containers/json?limit=-1&all=0&size=0&trunc_cmd=0"
Apr 26 17:34:06 jarvis dockerd[702]: time="2021-04-26T17:34:06.942352125+02:00" level=debug msg="Calling GET /v1.41/containers/json?limit=-1&all=0&size=0&trunc_cmd=0&filters=%7B%22health%22%3A+%5B%22healthy%22%5D%7D"
Apr 26 17:34:06 jarvis dockerd[702]: time="2021-04-26T17:34:06.944575123+02:00" level=debug msg="Calling GET /v1.41/containers/json?limit=-1&all=0&size=0&trunc_cmd=0&filters=%7B%22health%22%3A+%5B%22unhealthy%22%5D%7D"
Apr 26 17:34:07 jarvis dockerd[702]: time="2021-04-26T17:34:07.938523040+02:00" level=debug msg="Calling GET /v1.41/containers/json?limit=-1&all=0&size=0&trunc_cmd=0"
Apr 26 17:34:07 jarvis dockerd[702]: time="2021-04-26T17:34:07.951599558+02:00" level=debug msg="Calling GET /v1.41/containers/json?limit=-1&all=0&size=0&trunc_cmd=0&filters=%7B%22health%22%3A+%5B%22healthy%22%5D%7D"
Apr 26 17:34:07 jarvis dockerd[702]: time="2021-04-26T17:34:07.953429065+02:00" level=debug msg="Calling GET /v1.41/containers/json?limit=-1&all=0&size=0&trunc_cmd=0&filters=%7B%22health%22%3A+%5B%22unhealthy%22%5D%7D"
Apr 26 17:34:08 jarvis dockerd[702]: time="2021-04-26T17:34:08.016566871+02:00" level=debug msg=VolumeStore.Find ByType=service.andCombinator ByValue="[[local] 0x55e14a9957a0]"
Apr 26 17:34:08 jarvis dockerd[702]: time="2021-04-26T17:34:08.019595155+02:00" level=debug msg="FIXME: Got an API for which error does not match any expected type!!!: context canceled" error_type="*errors.errorString" module=api
Apr 26 17:34:08 jarvis dockerd[702]: time="2021-04-26T17:34:08.019612353+02:00" level=error msg="Handler for GET /system/df returned error: context canceled"
Apr 26 17:34:08 jarvis dockerd[702]: time="2021-04-26T17:34:08.019621221+02:00" level=debug msg="FIXME: Got an API for which error does not match any expected type!!!: context canceled" error_type="*errors.errorString" module=api

Specially this part: “FIXME: Got an API for which error does not match any expected type!!!: context canceled”

I thought it had something to do with the btrfs driver but shifted to overlay2 and got the same issue.
Some of my containers have nfs volumes, could this be related?

Do you guys need any more logs to look into this?