prometheus / prometheus/node_exporter

caller=collector.go:161 msg="collector failed" <...> err="couldn't get dbus connection: write unix @->/run/dbus/>

Open
#1,970 2 comments 0 reactions 0 assignees View on GitHub

Nobody has claimed this yet.

Dominant language
Go
Stars
13.8k
Forks
2.7k
Avg merge
1d 23h
Merged PRs (30d)
8

Description

Host operating system: output of uname -a
$ uname -a
Linux relay-77c3d3 5.4.0-65-generic #73-Ubuntu SMP Mon Jan 18 17:25:17 UTC 2021 x86_64 x86_64 x86_64 GNU/Linux
node_exporter version: output of node_exporter --version
node_exporter, version 1.0.1 (branch: HEAD, revision: 3715be6ae899f2a9b9dbfd9c39f3e09a7bd4559f)
  build user:       root@1f76dbbcfa55
  build date:       20200616-12:44:12
  go version:       go1.14.4
node_exporter command line flags
     CGroup: /system.slice/node_exporter.service
             └─693 /usr/local/bin/node_exporter --collector.systemd --collector.textfile --collector.textfile.directory=/var/lib/node_exporter --web.listen-address=localhost:9100 --web.telemetry-path=/metrics
Are you running node_exporter in Docker?

No

What did you do that produced an error?

Left the node_exporter running for four days.

What did you expect to see?

Continued operation, no errors or crashes.

What did you see instead?
Feb 15 11:16:52 relay-77c3d3 node_exporter[693]: level=error ts=2021-02-15T00:16:25.113Z caller=collector.go:161 msg="collector failed" name=systemd duration_seconds=43.302483043 err="couldn't get dbus connection: write unix @->/run/dbus/>
Feb 15 11:17:10 relay-77c3d3 node_exporter[693]: level=error ts=2021-02-15T00:16:43.226Z caller=collector.go:161 msg="collector failed" name=systemd duration_seconds=61.324678937 err="couldn't get dbus connection: dbus: connection closed >

Then the system appeared to hang. A jump in the count of go_goroutines was reported by this node_exporter before the hang.
image

Closer:
image

Feb 15 11:19:43 relay-77c3d3 node_exporter[693]: level=error ts=2021-02-15T00:19:30.050Z caller=collector.go:161 msg="collector failed" name=systemd duration_seconds=212.803465432 err="couldn't get dbus connection: write unix @->/run/dbus>
Feb 15 11:25:19 relay-77c3d3 node_exporter[693]: level=error ts=2021-02-15T00:21:52.326Z caller=collector.go:161 msg="collector failed" name=systemd duration_seconds=117.599559737 err="couldn't get dbus connection: write unix @: sendmsg: >
Feb 15 11:26:02 relay-77c3d3 node_exporter[693]: level=error ts=2021-02-15T00:26:02.471Z caller=collector.go:161 msg="collector failed" name=systemd duration_seconds=152.451322805 err="couldn't get dbus connection: write unix @: sendmsg: >
Feb 15 11:31:14 relay-77c3d3 node_exporter[693]: level=error ts=2021-02-15T00:28:43.803Z caller=collector.go:161 msg="collector failed" name=systemd duration_seconds=248.305289209 err="couldn't get dbus connection: write unix @: sendmsg: >
Feb 15 11:31:29 relay-77c3d3 node_exporter[693]: level=error ts=2021-02-15T00:29:00.829Z caller=collector.go:161 msg="collector failed" name=systemd duration_seconds=317.861842938 err="couldn't get dbus connection: write unix @: sendmsg: >
Feb 15 11:31:31 relay-77c3d3 node_exporter[693]: level=error ts=2021-02-15T00:28:38.707Z caller=collector.go:161 msg="collector failed" name=systemd duration_seconds=265.530885084 err="couldn't get dbus connection: write unix @: sendmsg: >
Feb 15 11:31:55 relay-77c3d3 node_exporter[693]: level=error ts=2021-02-15T00:29:04.703Z caller=collector.go:161 msg="collector failed" name=systemd duration_seconds=274.001391161 err="couldn't get dbus connection: write unix @: sendmsg: >
Feb 15 11:33:19 relay-77c3d3 node_exporter[693]: level=warn ts=2021-02-15T00:32:04.979Z caller=cpu_linux.go:247 collector=cpu msg="CPU Idle counter jumped backwards, possible hotplug event, resetting CPU stats" cpu=0 old_value=233602.62 n>
Feb 15 11:36:15 relay-77c3d3 node_exporter[693]: level=warn ts=2021-02-15T00:33:38.687Z caller=cpu_linux.go:247 collector=cpu msg="CPU Idle counter jumped backwards, possible hotplug event, resetting CPU stats" cpu=1 old_value=233653.46 n>
Feb 15 11:41:45 relay-77c3d3 node_exporter[693]: level=error ts=2021-02-15T00:41:45.243Z caller=collector.go:161 msg="collector failed" name=systemd duration_seconds=199.064034172 err="couldn't get dbus connection: write unix @: sendmsg: >
Feb 15 11:41:45 relay-77c3d3 node_exporter[693]: level=warn ts=2021-02-15T00:41:45.468Z caller=cpu_linux.go:247 collector=cpu msg="CPU Idle counter jumped backwards, possible hotplug event, resetting CPU stats" cpu=0 old_value=233602.63 n>
Feb 15 11:41:45 relay-77c3d3 node_exporter[693]: level=warn ts=2021-02-15T00:41:45.595Z caller=cpu_linux.go:247 collector=cpu msg="CPU Idle counter jumped backwards, possible hotplug event, resetting CPU stats" cpu=1 old_value=233653.47 n>
Feb 15 11:41:45 relay-77c3d3 node_exporter[693]: level=warn ts=2021-02-15T00:41:45.597Z caller=cpu_linux.go:247 collector=cpu msg="CPU Idle counter jumped backwards, possible hotplug event, resetting CPU stats" cpu=0 old_value=233603.01 n>
Feb 15 11:41:45 relay-77c3d3 node_exporter[693]: level=warn ts=2021-02-15T00:41:45.597Z caller=cpu_linux.go:247 collector=cpu msg="CPU Idle counter jumped backwards, possible hotplug event, resetting CPU stats" cpu=1 old_value=233653.74 n>
Feb 15 11:41:45 relay-77c3d3 node_exporter[693]: level=warn ts=2021-02-15T00:41:45.597Z caller=cpu_linux.go:247 collector=cpu msg="CPU Idle counter jumped backwards, possible hotplug event, resetting CPU stats" cpu=0 old_value=233603.01 n>
Feb 15 11:41:45 relay-77c3d3 node_exporter[693]: level=warn ts=2021-02-15T00:41:45.597Z caller=cpu_linux.go:247 collector=cpu msg="CPU Idle counter jumped backwards, possible hotplug event, resetting CPU stats" cpu=1 old_value=233653.74 n>
Feb 15 11:41:45 relay-77c3d3 node_exporter[693]: level=warn ts=2021-02-15T00:41:45.877Z caller=cpu_linux.go:255 collector=cpu msg="CPU User counter jumped backwards" cpu=0 old_value=71977.62 new_value=71977.58
Feb 15 11:41:45 relay-77c3d3 node_exporter[693]: level=warn ts=2021-02-15T00:41:45.877Z caller=cpu_linux.go:267 collector=cpu msg="CPU System counter jumped backwards" cpu=0 old_value=13458.96 new_value=13458.91
Feb 15 11:41:45 relay-77c3d3 node_exporter[693]: level=warn ts=2021-02-15T00:41:45.877Z caller=cpu_linux.go:255 collector=cpu msg="CPU User counter jumped backwards" cpu=1 old_value=72021.78 new_value=72021.69

The system unhung at 11:41 when the process was reaped by oom-killer.

Contributor guide

Open the contributing guide

First steps

  1. Read the whole issue, then the project's contributing guide.
  2. Comment on the issue to say you are picking it up — it saves two people doing the same work.
  3. Fork the repository and make your change on a branch.
  4. Open a pull request that references the issue number.

Research direction

Start with the systemd collector errors reported at collector.go:161 and inspect the systemd collector entry point, then compare the CPU warnings around cpu_linux.go:247. Reproduce the DBus failure and the rising goroutine count described in the logs. Done means identifying and addressing the behavior that leaves node_exporter hanging until the OOM killer reaps it.

Written by the indexing model from the issue text.

Assessment

Tech stack
go
Domain
observability, operating-systems
Issue type
Bug
Difficulty
4/5
Estimated time
3-5 days
Activity status
Stale
Clarity
Needs clarification
Newbie friendliness
35/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.