Node_exporter: fatal error: runtime.unlock: lock count with Go >= 1.10

[daenney]

Host operating system: output of uname -a

Linux endor 4.13.0-37-generic #42~16.04.1-Ubuntu SMP Wed Mar 7 16:03:28 UTC 2018 x86_64 x86_64 x86_64 GNU/Linux

node_exporter version: output of node_exporter --version

node_exporter, version 0.16.0-rc.0 (branch: HEAD, revision: 002c1ca02917406cbecc457162e2bdb1f29c2f49)
  build user:       root@5ff5455ac873
  build date:       20180309-15:09:26
  go version:       go1.10

Used the release artifact at: https://github.com/prometheus/node_exporter/releases/download/v0.16.0-rc.0/node_exporter-0.16.0-rc.0.linux-amd64.tar.gz

node_exporter command line flags

None, the defaults for 0.16 match my needs

Are you running node_exporter in Docker?

No

What did you do that produced an error?

Just ran it for a couple of days

What did you expect to see?

It not to crash

What did you see instead?

Mar 28 19:47:54 endor node_exporter[18076]: fatal error: runtime·unlock: lock count
Mar 28 19:48:03 endor systemd[1]: node_exporter.service: Main process exited, code=killed, status=11/SEGV

That fatal error line got spewed about a 1000 times, all logged at 19:47:54 according to systemd.

[mschroeder223]

I have the same issue as @daenney

Host operating system: output of uname -a

Linux lb1 4.13.0-26-generic #29~16.04.2-Ubuntu SMP Tue Jan 9 22:00:44 UTC 2018 x86_64 x86_64 x86_64 GNU/Linux

node_exporter version: output of node_exporter --version

node_exporter, version 0.16.0-rc.0 (branch: HEAD, revision: 002c1ca02917406cbecc457162e2bdb1f29c2f49)
  build user:       root@5ff5455ac873
  build date:       20180309-15:09:26
  go version:       go1.10

Observation: I have node_exporter installed on 6 machines at this point. The two machines it keeps failing on are the only two vms I am currently using. The others are bare metal and are running great.

[brian-brazil]

If it's reproducible, could you try bisecting which collectors are enabled to see which it is?

[SuperQ]

Also, running with debug level logs would help identify if there is a specific collector problem.

[daenney]

@mschroeder223 That's interesting. In my case the machine it blows up on is bare metal.

I've set systemd to restart the node_exporter for now, but looking at the logs a new error surfaced too:
Mar 30 09:15:14 endor systemd[1]: node_exporter.service: Main process exited, code=killed, status=5/TRAP. Unsure what that's about.

I've updated my unit file to run with debug logs, I'll check in on it in 24 hours, see what gives.

[mschroeder223]

It took about 4.5hrs for it to crash this morning, this is the output that was captured https://gist.github.com/mschroeder223/16e48f64a8b17888eae0e1d597a83504

I do see several collectors which are running and do not need to be enabled so I am going to disable them and see if it makes any difference.

[grobie]

There is quite a lot going on here. I believe the "lock count" panic is a red herring, and is the result of the go runtime raising a panic while handling another panic (see "panic during panic" in the log).

This issue appears to be highly related to what we see here https://github.com/golang/go/issues/24059 A fix was included in go 1.10.1. As far as I understand, an actual panic is masked by a bug in the panic handling code in the go runtime.

I suggest to build a new release candidate with go 1.10.1 and let @mschroeder223 and @daenney run that release candidate for a while. Hopefully we'll be able to catch the actual panic afterwards.

[SuperQ]

I'll work on building a new RC release.

[mschroeder223]

I don't know if this will help isolate the problem at all, but between the two servers that are continuously crashing, I updated one to exclude some unused collectors:
node_exporter --no-collector.infiniband --no-collector.zfs --no-collector.wifi --no-collector.nfs --no-collector.nfsd

and the other server which continued to crash all weekend:
node_exporter

Also one more crash log from the weekend but with no real trace history
https://gist.github.com/mschroeder223/ca7243393e3c13d619e8ba0f517ca9b9

[SuperQ]

I've published v0.16.0-rc.1. This is now built with Go 1.10.1. Please give it a try and see if it fixes the crash.

[daenney]

Pushed it out today, I'll check back in 24hrs, see if any crashes have shown up. @grobie's line of thought sounds rather plausible though, so lets hope that is it.

[JBauto]

I'm still getting this error even with v0.16.0-rc.1. It runs for a while and then it crashes.

uname -a

Linux node8 4.4.0-116-generic #140-Ubuntu SMP Mon Feb 12 21:23:04 UTC 2018 x86_64 x86_64 x86_64 GNU/Linux

node_exporter --version

node_exporter, version 0.16.0-rc.1 (branch: HEAD, revision: f3ff44fcca5bb20a181cd7b99734afeae553c78e)
  build user:       root@448aa887a7ca
  build date:       20180404-17:47:46
  go version:       go1.10.1

journaltctl -u node_exporter

Apr 09 14:13:47 node8 systemd[1]: Started Node Exporter.
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg="Starting node_exporter (version=0.16.0-rc.1, branch=HEAD, revision=f3ff44fcca5bb20a181cd7b99734afeae553c78e)" source="node_exporter.go:82"
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg="Build context (go=go1.10.1, user=root@448aa887a7ca, date=20180404-17:47:46)" source="node_exporter.go:83"
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg="Enabled collectors:" source="node_exporter.go:90"
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg=" - arp" source="node_exporter.go:97"
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg=" - bcache" source="node_exporter.go:97"
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg=" - bonding" source="node_exporter.go:97"
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg=" - conntrack" source="node_exporter.go:97"
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg=" - cpu" source="node_exporter.go:97"
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg=" - diskstats" source="node_exporter.go:97"
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg=" - edac" source="node_exporter.go:97"
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg=" - entropy" source="node_exporter.go:97"
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg=" - filefd" source="node_exporter.go:97"
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg=" - filesystem" source="node_exporter.go:97"
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg=" - hwmon" source="node_exporter.go:97"
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg=" - infiniband" source="node_exporter.go:97"
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg=" - ipvs" source="node_exporter.go:97"
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg=" - loadavg" source="node_exporter.go:97"
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg=" - mdadm" source="node_exporter.go:97"
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg=" - meminfo" source="node_exporter.go:97"
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg=" - netdev" source="node_exporter.go:97"
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg=" - netstat" source="node_exporter.go:97"
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg=" - nfs" source="node_exporter.go:97"
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg=" - nfsd" source="node_exporter.go:97"
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg=" - sockstat" source="node_exporter.go:97"
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg=" - stat" source="node_exporter.go:97"
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg=" - textfile" source="node_exporter.go:97"
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg=" - time" source="node_exporter.go:97"
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg=" - timex" source="node_exporter.go:97"
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg=" - uname" source="node_exporter.go:97"
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg=" - vmstat" source="node_exporter.go:97"
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg=" - wifi" source="node_exporter.go:97"
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg=" - xfs" source="node_exporter.go:97"
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg=" - zfs" source="node_exporter.go:97"
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg="Listening on :9100" source="node_exporter.go:111"
Apr 10 00:49:26 node8 node_exporter[1576234]: fatal error: runtime·unlock: lock count
Apr 10 00:49:26 node8 node_exporter[1576234]: fatal error: runtime·unlock: lock count
Apr 10 00:49:26 node8 node_exporter[1576234]: fatal error: runtime·unlock: lock count
Apr 10 00:49:26 node8 node_exporter[1576234]: fatal error: runtime·unlock: lock count
Apr 10 00:49:26 node8 node_exporter[1576234]: fatal error: runtime·unlock: lock count
Apr 10 00:49:26 node8 node_exporter[1576234]: fatal error: runtime·unlock: lock count
Apr 10 00:49:26 node8 node_exporter[1576234]: fatal error: runtime·unlock: lock count

[grobie]

We really need a stack trace here to debug that further. Please check your journalctl output at that time without the -u node_exporter filter and paste the output.

[JBauto]

Without the filter, it doesn't show anything more useful I think.

Apr 09 14:13:47 node8 ansible-command[1576231]: Invoked with warn=True executable=None _uses_shell=True _raw_params=systemctl restart node_exporter removes=None creates=None chdir=None stdin=None
Apr 09 14:13:47 node8 systemd[1]: Stopped Node Exporter.
Apr 09 14:13:47 node8 systemd[1]: Started Node Exporter.
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg="Starting node_exporter (version=0.16.0-rc.1, branch=HEAD, revision=f3ff44fcca5bb20a181cd7b99734afeae553c78e)" source="node_exporter.go:82"
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg="Build context (go=go1.10.1, user=root@448aa887a7ca, date=20180404-17:47:46)" source="node_exporter.go:83"
Apr 09 14:13:47 node8 sudo[1576228]: pam_unix(sudo:session): session closed for user root
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg="Enabled collectors:" source="node_exporter.go:90"
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg=" - arp" source="node_exporter.go:97"
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg=" - bcache" source="node_exporter.go:97"
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg=" - bonding" source="node_exporter.go:97"
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg=" - conntrack" source="node_exporter.go:97"
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg=" - cpu" source="node_exporter.go:97"
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg=" - diskstats" source="node_exporter.go:97"
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg=" - edac" source="node_exporter.go:97"
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg=" - entropy" source="node_exporter.go:97"
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg=" - filefd" source="node_exporter.go:97"
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg=" - filesystem" source="node_exporter.go:97"
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg=" - hwmon" source="node_exporter.go:97"
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg=" - infiniband" source="node_exporter.go:97"
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg=" - ipvs" source="node_exporter.go:97"
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg=" - loadavg" source="node_exporter.go:97"
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg=" - mdadm" source="node_exporter.go:97"
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg=" - meminfo" source="node_exporter.go:97"
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg=" - netdev" source="node_exporter.go:97"
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg=" - netstat" source="node_exporter.go:97"
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg=" - nfs" source="node_exporter.go:97"
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg=" - nfsd" source="node_exporter.go:97"
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg=" - sockstat" source="node_exporter.go:97"
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg=" - stat" source="node_exporter.go:97"
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg=" - textfile" source="node_exporter.go:97"
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg=" - time" source="node_exporter.go:97"
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg=" - timex" source="node_exporter.go:97"
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg=" - uname" source="node_exporter.go:97"
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg=" - vmstat" source="node_exporter.go:97"
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg=" - wifi" source="node_exporter.go:97"
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg=" - xfs" source="node_exporter.go:97"
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg=" - zfs" source="node_exporter.go:97"
Apr 09 14:13:47 node8 node_exporter[1576234]: time="2018-04-09T14:13:47+01:00" level=info msg="Listening on :9100" source="node_exporter.go:111"
Apr 09 14:14:47 node8 sshd[1576083]: Received disconnect from IP_ADDRESS port 43820:11: disconnected by user
Apr 09 14:14:47 node8 sshd[1576083]: Disconnected from IP_ADDRESS port 43820
Apr 09 14:14:47 node8 sshd[1576003]: pam_unix(sshd:session): session closed for user manager
Apr 09 14:14:47 node8 systemd-logind[1082]: Removed session 501.
Apr 09 14:14:47 node8 systemd[1]: Stopping User Manager for UID 1000...
Apr 09 14:14:47 node8 systemd[1576005]: Stopped target Default.
Apr 09 14:14:47 node8 systemd[1576005]: Reached target Shutdown.
Apr 09 14:14:47 node8 systemd[1576005]: Starting Exit the Session...
Apr 09 14:14:47 node8 systemd[1576005]: Stopped target Basic System.
Apr 09 14:14:47 node8 systemd[1576005]: Stopped target Sockets.
Apr 09 14:14:47 node8 systemd[1576005]: Stopped target Paths.
Apr 09 14:14:47 node8 systemd[1576005]: Stopped target Timers.
Apr 09 14:14:47 node8 systemd[1576005]: Received SIGRTMIN+24 from PID 1576309 (kill).
Apr 09 14:14:47 node8 systemd[1576007]: pam_unix(systemd-user:session): session closed for user manager
Apr 09 14:14:47 node8 systemd[1]: Stopped User Manager for UID 1000.
Apr 09 14:14:47 node8 systemd[1]: Removed slice User Slice of manager.
Apr 09 14:17:01 node8 CRON[1576450]: pam_unix(cron:session): session opened for user root by (uid=0)
Apr 09 14:17:01 node8 CRON[1576451]: (root) CMD (   cd / && run-parts --report /etc/cron.hourly)
Apr 09 14:17:01 node8 CRON[1576450]: pam_unix(cron:session): session closed for user root
Apr 09 15:17:01 node8 CRON[1579817]: pam_unix(cron:session): session opened for user root by (uid=0)
Apr 09 15:17:01 node8 CRON[1579818]: (root) CMD (   cd / && run-parts --report /etc/cron.hourly)
Apr 09 15:17:01 node8 CRON[1579817]: pam_unix(cron:session): session closed for user root
Apr 09 16:17:01 node8 CRON[1581532]: pam_unix(cron:session): session opened for user root by (uid=0)
Apr 09 16:17:01 node8 CRON[1581533]: (root) CMD (   cd / && run-parts --report /etc/cron.hourly)
Apr 09 16:17:01 node8 CRON[1581532]: pam_unix(cron:session): session closed for user root
Apr 09 17:17:01 node8 CRON[1583185]: pam_unix(cron:session): session opened for user root by (uid=0)
Apr 09 17:17:01 node8 CRON[1583186]: (root) CMD (   cd / && run-parts --report /etc/cron.hourly)
Apr 09 17:17:01 node8 CRON[1583185]: pam_unix(cron:session): session closed for user root
Apr 09 18:17:01 node8 CRON[1584837]: pam_unix(cron:session): session opened for user root by (uid=0)
Apr 09 18:17:01 node8 CRON[1584838]: (root) CMD (   cd / && run-parts --report /etc/cron.hourly)
Apr 09 18:17:01 node8 CRON[1584837]: pam_unix(cron:session): session closed for user root
Apr 09 18:30:42 node8 dhclient[1269]: DHCPREQUEST of IP_ADDRESS on eno1 to IP_ADDRESS port 67 (xid=0x61fb15b0)
Apr 09 18:30:42 node8 dhclient[1269]: DHCPACK of IP_ADDRESS from IP_ADDRESS
Apr 09 18:30:42 node8 dhclient[1269]: bound to IP_ADDRESS -- renewal in 42306 seconds.
Apr 09 18:44:44 node8 systemd[1]: Starting Cleanup of Temporary Directories...
Apr 09 18:44:44 node8 systemd-tmpfiles[1585610]: [/usr/lib/tmpfiles.d/var.conf:14] Duplicate line for path "/var/log", ignoring.
Apr 09 18:44:44 node8 systemd[1]: Started Cleanup of Temporary Directories.
Apr 09 19:17:01 node8 CRON[1586506]: pam_unix(cron:session): session opened for user root by (uid=0)
Apr 09 19:17:01 node8 CRON[1586507]: (root) CMD (   cd / && run-parts --report /etc/cron.hourly)
Apr 09 19:17:01 node8 CRON[1586506]: pam_unix(cron:session): session closed for user root
Apr 09 20:17:01 node8 CRON[1589398]: pam_unix(cron:session): session opened for user root by (uid=0)
Apr 09 20:17:01 node8 CRON[1589399]: (root) CMD (   cd / && run-parts --report /etc/cron.hourly)
Apr 09 20:17:01 node8 CRON[1589398]: pam_unix(cron:session): session closed for user root
Apr 09 21:17:01 node8 CRON[1593667]: pam_unix(cron:session): session opened for user root by (uid=0)
Apr 09 21:17:01 node8 CRON[1593668]: (root) CMD (   cd / && run-parts --report /etc/cron.hourly)
Apr 09 21:17:01 node8 CRON[1593667]: pam_unix(cron:session): session closed for user root
Apr 09 22:17:01 node8 CRON[1597959]: pam_unix(cron:session): session opened for user root by (uid=0)
Apr 09 22:17:01 node8 CRON[1597960]: (root) CMD (   cd / && run-parts --report /etc/cron.hourly)
Apr 09 22:17:01 node8 CRON[1597959]: pam_unix(cron:session): session closed for user root
Apr 09 23:17:01 node8 CRON[1602223]: pam_unix(cron:session): session opened for user root by (uid=0)
Apr 09 23:17:01 node8 CRON[1602224]: (root) CMD (   cd / && run-parts --report /etc/cron.hourly)
Apr 09 23:17:01 node8 CRON[1602223]: pam_unix(cron:session): session closed for user root
Apr 10 00:17:01 node8 CRON[1606511]: pam_unix(cron:session): session opened for user root by (uid=0)
Apr 10 00:17:01 node8 CRON[1606512]: (root) CMD (   cd / && run-parts --report /etc/cron.hourly)
Apr 10 00:17:01 node8 CRON[1606511]: pam_unix(cron:session): session closed for user root
Apr 10 00:49:26 node8 node_exporter[1576234]: fatal error: runtime·unlock: lock count
Apr 10 00:49:26 node8 node_exporter[1576234]: fatal error: runtime·unlock: lock count
Apr 10 00:49:26 node8 node_exporter[1576234]: fatal error: runtime·unlock: lock count
Apr 10 00:49:26 node8 node_exporter[1576234]: fatal error: runtime·unlock: lock count
Apr 10 00:49:26 node8 node_exporter[1576234]: fatal error: runtime·unlock: lock count
Apr 10 00:49:26 node8 node_exporter[1576234]: fatal error: runtime·unlock: lock count
Apr 10 00:49:26 node8 node_exporter[1576234]: fatal error: runtime·unlock: lock count
Apr 10 00:49:26 node8 node_exporter[1576234]: fatal error: runtime·unlock: lock count
Apr 10 00:49:26 node8 node_exporter[1576234]: fatal error: runtime·unlock: lock count
Apr 10 00:49:26 node8 node_exporter[1576234]: fatal error: runtime·unlock: lock count
Apr 10 00:49:26 node8 node_exporter[1576234]: fatal error: runtime·unlock: lock count

[discordianfish]

I can confirm this is still happening with rc.0:

2018-04-10T16:48:52.441683157Z time="2018-04-10T16:48:52Z" level=info msg="Starting node_exporter (version=0.16.0-rc.1, branch=master, revision=9e485f11578b40915db8668ef9060a014d9cea2f)" source="node_exporter.go:82"
...
2018-04-10T16:48:52.442221476Z time="2018-04-10T16:48:52Z" level=info msg=" - zfs" source="node_exporter.go:97"
2018-04-10T16:48:52.442223509Z time="2018-04-10T16:48:52Z" level=info msg="Listening on :9100" source="node_exporter.go:111"
2018-04-13T10:06:30.639476572Z fatal error: runtime·unlock: lock count
2018-04-13T10:06:30.63951748Z fatal error: runtime·unlock: lock count
2018-04-13T10:06:30.639523112Z fatal error: runtime·unlock: lock count
2018-04-13T10:06:30.639526776Z fatal error: runtime·unlock: lock count
2018-04-13T10:06:30.639530495Z fatal error: runtime·unlock: lock count
2018-04-13T10:06:30.639535581Z fatal error: runtime·unlock: lock count
2018-04-13T10:06:30.639539318Z fatal error: runtime·unlock: lock count
2018-04-13T10:06:30.639542781Z fatal error: runtime·unlock: lock count
2018-04-13T10:06:30.639546352Z fatal error: runtime·unlock: lock count
2018-04-13T10:06:30.639549837Z fatal error: runtime·unlock: lock count
2018-04-13T10:06:30.63955346Z fatal error: runtime·unlock: lock count
2018-04-13T10:06:30.639556917Z fatal error: runtime·unlock: lock count

That happened 95268 times within two seconds. No more details/stacktrace :-/

[discordianfish]

Oh didn't know somebody ran into this long time ago already and filled an upstream issue: https://github.com/golang/go/issues/15438
Suggestions were to check unsafe and cgo code. I don't think we use any unsafe code on linux/amd64 so might be cgo or still an upstream issue.

[discordianfish]

There is also an issue here #228

[daenney]

I can confirm I'm still experiencing this. Node Exporter crashes about once every two days now with that error. Running in debug mode but not getting any stack traces in the journal either.

[daenney]

Actually... this seems to have gotten a bit worse for me. Before once the fatal error: runtime.unlock: lock count happened the node_exporter would crash and systemd would then restart it. However, now it just gets stuck in that mode, so unless I automate checking if the node exporter is still running and if not manually restart it I'm missing metrics.

[discordianfish]

Although we don't make much use of cgo on linux, it would make sense to rule this out.
@daenney: Can you deploy a cgo disabled version of the node-exporter and see if that problem goes away? You can build it yourself by running CGO_ENABLED=0 go build in the repo or you can use my build:

node_exporter.gz

[daenney]

Alright. Built one with Go 1.10.1, with HEAD at 768be139beb1522b092a0ec6ab7b7b3047216577.

$ go get github.com/prometheus/node_exporter
$ cd ~/Development/go/src/github.com/prometheus/node_exporter
$ env CGO_ENABLED=0 go build

It's deployed now, lets see what happens. It might take some time for the bug to manifest though.

[daenney]

So far so good. It's been running for 3 days now roughly, no errors, hasn't been restarted by systemd since I deployed it and no missing data in any graphs (or complaints by Prometheus that the target is unreachable).

This seems to suggest it is indeed related to cgo somehow. What can I do to help narrow this down? Can we do some kind of a build matrix building a node_exporter with only one extension that uses cgo at a time to try and narrow this down? Or build it with cgo, disable all cgo-powered extensions, and then enable one at a time? Would it help to build it with cgo but on an older Go version (say 1.8)?

[discordianfish]

The only collector enabled on linux that use any cgo reference itself is timex, but this only reads some constants and I doubt that's the problem. But you could try running the official release and disable that collector. Though I suspect it's rather related to some stdlib stuff that uses c implementation instead of native go implementation.
Beside that, yeah using an older go version and see if it still happens would help isolate this too.

[SuperQ]

@daenney Let's try Go 1.9.5 + CGO first. Go 1.9 seemed stable enough in node_exporter 0.15.x. So it should be the same with 0.16. If that still crashes, we can narrow it down to code changes in the node_exporter.

[daenney]

Alright. Rebuild one without CGO_ENABLED=0 on Go 1.9.5 at 75561cb1fc3364148b5ca65130a7b7eaead15475. I can rebuild it to the same commit as the 1.10.1 build I did if that's a concern.

[discordianfish]

@daenney Pretty sure that with CGO_ENABLED=0 it will work, the interesting question would be if it this problem is gone with 1.9.5 even with CGO enabled. Can you try this? Running make should do that if go 1.9.5 is installed in the PATH.

[daenney]

I think we're getting our signals crossed. I said "without CGO_ENABLED=0", meaning it's built with CGO as usual. Probably should've formulated that better. I just did a go build.

[daenney]

So far so good though, it's been running for ~2 days with no crashes yet.

[discordianfish]

Ah sorry, misread that. Makes sense!

[daenney]

Still not seeing any crashes. This does seem a bit worrisome though. If it really is a Go 1.10 vs Go 1.9 issue I'm not even sure where to begin to track that down. At least if it manifested on both we could've simply gone with a git bisect of the node_exporter.

[SuperQ]

Yea, this is not the first time the node_exporter has found a golang bug[0]. 🤢

I guess the only thing we can do now is to bisect the collectors and try and narrow it down.

From the original post, it seems like this is causing more issues for this combination

• Ubuntu 16.04 + 4.4 or 4.13
• VMs, rather than bare metal.

Can I ask what VM platform is causing the most issues? I could setup a test instance to see if I can reproduce it.

[daenney]

I got really annoyed with this bug so I decided to try and bruteforce it:

• Spun up an Ubuntu 16.04 instance
• Created the following fs layout:
  
  
  
  • /root/gophers/gopath195
  
  
  • /root/gophers/gopath110
  
  
  • /root/gophers/builds/195
  
  
  • /root/gophers/builds/110
  
  
• Downloaded and extracted Go 1.10.1 and Go 1.9.5 in /root/gophers/<version>
• Fetched node exporter:
  
  
  
  • GOPATH=/root/gophers/gopath110 /root/gophers/go110/bin/go get github.com/prometheus/node_exporter
  
  
  • GOPATH=/root/gophers/gopath195 /root/gophers/go195/bin/go get github.com/prometheus/node_exporter
  
  
• Found all the commit hashes of any commit between 0.15.2 and 0.16.0-rc.2 that touches
  a .go file: git log --pretty=format:%H v0.15.2..v0.16.0-rc.2 --no-merges -- '*.go' > /root/gophers/commits.txt

• Build a node exporter for every commit for both versions of Go:

  #!/usr/bin/env bash
  
  filename="/root/gophers/commits.txt"
  declare -i offset
  offset=0
  
  while read commit; do
        cd /root/gophers/gopath195/src/github.com/prometheus/node_exporter
        git checkout $commit
        echo "Building $commit with Go 1.9.5"
        GOPATH=/root/gophers/gopath195 /root/gophers/go195/bin/go get ./...
        GOPATH=/root/gophers/gopath195 /root/gophers/go195/bin/go build -o "/root/gophers/builds/195/node_exporter_195_$(printf "%02d" $offset)_$commit"
        offset+=1
        echo "Done building $commit with Go 1.9.5"
  done < $filename
  

• Repeat above for Go 1.10.1

• Create systemd files for all builds, write out targets for vegeta and start them:

  #!/usr/bin/env bash
  
  declare -i port
  port=9100
  
  for n in /root/gophers/builds/195/* ; do
        short=$(echo $n | cut -d '/' -f6 | cut -d '_' -f1-4)
        cat <<-EOF > /etc/systemd/system/$short.service
  [Unit]
  Description=Prometheus Node Exporter $port
  
  [Service]
  User=root
  ExecStart=$n --log.level="debug" --web.listen-address="127.0.0.1:$port"
  Restart=never
  EOF
        echo "GET http://127.0.0.1:$port/metrics" >> /root/gophers/targets.txt
        port+=1
  done
  
  systemctl daemon-reload
  
  for n in /etc/systemd/system/node_exporter_195_*; do
  systemctl start $(basename $n)
  done
  

• Repeat above for Go 1.10.1
• Launch vegeta against them: ./vegeta attack -targets=targets.txt -rate=68 > results.bin

And now we wait.

[daenney]

I think I have bad news... None of my Go 1.9.5 exporters have crashed, but on Go 1.10.1 they have, and it's at random commits, there's no logical progression. There's 5 out of the 68 that are dead. Weirdly not all of them have died with that same error, some of them appeared to have just choked and called it quits.

[SuperQ]

@daenney Thanks a ton for doing this research. For now I'm proposing we cut the release binaries with Go 1.9.5 (https://github.com/prometheus/node_exporter/pull/922). I also saw one instance of rc.2 locking up in production yesterday.

[daenney]

Glad to help. I think it would be prudent to build against 1.9.5 for now, yes.

This begs the question, is it a bug around CGO introduced in 1.10.x, or is there an actual bug in the node_exporter which due to bugfixes/changes related to 1.10.x somehow now manifests?

If someone finds it useful, I can upload all the artifacts somewhere so you can run your own tests (though it's not hard to build it yourself).

[SuperQ]

@daenney It looks like Go 1.10.2 is out, want to give that a try?

[daenney]

@SuperQ I would, except looking at the 1.10.2 milestone I can't see anything that could relate to this bug, except maybe golang/go#24935? However even that bug, I can't really see that triggering this error.

What do you think?

[LaurentDumont]

Hey everyone,

I was wondering why my Grafana dashboards we're empty and it seems I've hit the issue mentioned in this thread.

Two QEMU VMs - Debian 9
Same node-exporter version on both servers.

sysadmin@srv1:/opt/prometheus-node-exporter$ ./node_exporter --version
node_exporter, version 0.16.0-rc.1 (branch: HEAD, revision: f3ff44fcca5bb20a181cd7b99734afeae553c78e)
  build user:       root@448aa887a7ca
  build date:       20180404-17:47:46
  go version:       go1.10.1

sysadmin@srv1:~$ sudo systemctl status prometheus-node.service 
● prometheus-node.service - Prometheus node exporter
   Loaded: loaded (/etc/systemd/system/prometheus-node.service; enabled; vendor preset: enabled)
   Active: failed (Result: signal) since Sat 2018-05-05 22:47:02 EDT; 14h ago
  Process: 17352 ExecStart=/opt/prometheus-node-exporter/node_exporter (code=killed, signal=TRAP)
 Main PID: 17352 (code=killed, signal=TRAP)
      CPU: 25.315s

May 05 22:47:02 srv1 node_exporter[17352]: fatal error: runtime·unlock: lock count
May 05 22:47:02 srv1 node_exporter[17352]: fatal error: runtime·unlock: lock count
May 05 22:47:02 srv1 node_exporter[17352]: fatal error: runtime·unlock: lock count
May 05 22:47:02 srv1 node_exporter[17352]: fatal error: runtime·unlock: lock count
May 05 22:47:02 srv1 node_exporter[17352]: fatal error: runtime·unlock: lock count
May 05 22:47:02 srv1 node_exporter[17352]: fatal error: runtime·unlock: lock count
May 05 22:47:02 srv1 node_exporter[17352]: fatal error: runtime·unlock: lock count
May 05 22:47:02 srv1 node_exporter[17352]: fatal error: runtime·unlock: lock count
May 05 22:47:02 srv1 node_exporter[17352]: fatal error: runtime·unlock: lock count
May 05 22:47:02 srv1 node_exporter[17352]: fatal error: runtime·unlock: lock countfatal: morestack on g0

sysadmin@monitoring:~$ sudo systemctl status prometheus-node.service 
● prometheus-node.service - Prometheus node exporter
   Loaded: loaded (/etc/systemd/system/prometheus-node.service; enabled; vendor preset: enabled)
   Active: failed (Result: signal) since Sun 2018-05-06 11:52:26 UTC; 5h 30min ago
  Process: 27491 ExecStart=/opt/prometheus-node-exporter/node_exporter (code=killed, signal=SEGV)
 Main PID: 27491 (code=killed, signal=SEGV)
      CPU: 44.285s

May 06 11:52:26 monitoring node_exporter[27491]: fatal error: runtime·unlock: lock count
May 06 11:52:26 monitoring node_exporter[27491]: fatal error: runtime·unlock: lock count
May 06 11:52:26 monitoring node_exporter[27491]: fatal error: runtime·unlock: lock count
May 06 11:52:26 monitoring node_exporter[27491]: fatal error: runtime·unlock: lock count
May 06 11:52:26 monitoring node_exporter[27491]: fatal error: runtime·unlock: lock count
May 06 11:52:26 monitoring node_exporter[27491]: fatal error: runtime·unlock: lock count
May 06 11:52:26 monitoring node_exporter[27491]: fatal error: runtime·unlock: lock count
May 06 11:52:26 monitoring node_exporter[27491]: fatal error: runtime·unlock: lock count
May 06 11:52:26 monitoring node_exporter[27491]: fatal error: runtime·unlock: lock count
May 06 11:52:26 monitoring node_exporter[27491]: fatal error: runtime·unlock: lock count

Anything else I can provide to help?

[SuperQ]

@LaurentDumont Please give rc.3 a try, it's built with Go 1.9.5, which should be more stable.

[LaurentDumont]

Awesome, thank you. I've redeployed with rc.3. I'll monitor over the next few days.

[SuperQ]

@daenney I've started up 3 test binaries on my laptop to see if I can narrow it down the issue.

1. 0.16.0-rc.3 + Go 1.9.5
2. master + Go 1.10.2
3. master -tags notimex + Go 1.10.2

I'm hitting them with ~3 QPS each.

[SuperQ]

Well, that didn't help.. the notimex variation crashed.

fatal error: runtime·unlock: lock count
fatal error: fatal: morestack on g0

And again, no other useful stack log.

[LaurentDumont]

Looks good on my side with 0.16.0-rc.3 - no crash for 24+ hours. I'll monitor over the next few days just to make sure.

[MorphBonehunter]

Last thursday i've updated my node-exporters from:

node_exporter, version 0.15.2 (branch: master, revision: 0e4cae5e4fc9a0cabc881e2bc4022236c8a81099)
  build user:       archpkg@43415cb6bbf2
  build date:       20180412-07:14:31
  go version:       go1.10.1

to

node_exporter, version 0.16.0 (branch: master, revision: c695dc38f7c6bba165fff1057f94a8a1329eeecd)
  build user:       archpkg@9488af9336e0
  build date:       20180516-13:53:11
  go version:       go1.10.2

After that i had one crash yesterday:

Mai 21 15:45:00 pandora prometheus-node-exporter[538]: fatal error: runtime·unlock: lock count
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: fatal error: runtime·unlock: lock count
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: fatal error: runtime·unlock: lock count
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: fatal error: runtime·unlock: lock count
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: fatal error: runtime·unlock: lock count
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: fatal error: runtime·unlock: lock count
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: fatal error: runtime·unlock: lock count
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: fatal error: runtime·unlock: lock count
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: fatal error: runtime·unlock: lock count
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: fatal error: runtime·unlock: lock count
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: fatal error: runtime·unlock: lock count
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: fatal error: runtime·unlock: lock count
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: fatal error: runtime·unlock: lock count
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: fatal error: runtime·unlock: lock count
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: fatal error: runtime·unlock: lock count
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: fatal error: runtime·unlock: lock count
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: fatal error: runtime·unlock: lock count
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: fatal error: runtime·unlock: lock count
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: fatal error: runtime·unlock: lock count
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: fatal error: runtime·unlock: lock count
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: fatal error: runtime·unlock: lock count
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: fatal error: runtime·unlock: lock count
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: fatal error: runtime·unlock: lock count
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: fatal error: runtime·unlock: lock count
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: fatal error: runtime·unlock: lock count
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: fatal error: runtime·unlock: lock count
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: fatal error: runtime·unlock: lock count
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: fatal error: runtime·unlock: lock count
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: fatal error: runtime·unlock: lock count
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: fatal error: runtime·unlock: lock count
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: fatal error: runtime·unlock: lock count
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: fatal error: runtime·unlock: lock count
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: fatal error: runtime·unlock: lock count
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: fatal error: runtime·unlock: lock count
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: fatal error: runtime·unlock: lock count
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: fatal error: runtime·unlock: lock count
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: fatal error: runtime·unlock: lock count
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: fatal error: runtime·unlock: lock count
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: fatal error: runtime·unlock: lock count
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: fatal error: runtime·unlock: lock count
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: fatal error: runtime·unlock: lock count
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: fatal error: runtime·unlock: lock count
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: fatal error: runtime·unlock: lock count
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: fatal error: runtime·unlock: lock count
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: fatal error: runtime·unlock: lock count
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: fatal error: runtime·unlock: lock count
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: fatal error: runtime·unlock: lock count
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: fatal error: runtime·unlock: lock count
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: fatal error: runtime·unlock: lock count
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: fatal error: runtime·unlock: lock count
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: fatal error: runtime·unlock: lock count
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: fatal error: runtime·unlock: lock count
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: fatal error: runtime·unlock: lock count
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: fatal error: runtime·unlock: lock count
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: fatal error: runtime·unlock: lock count
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: fatal error: runtime·unlock: lock count
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: fatal error: malloc deadlock
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: panic during panic
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime stack:
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime stack:
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.startpanic_mruntime.throw(0xaa9662, 0x1b)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/panic.go:616 +0x81
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.unlock(0x10496c0)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/lock_futex.go:118 +0xa0
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.printunlock()
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/print.go:80 +0x59
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.throw(0xaa9662, 0x1b)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/panic.go:610 +0x4e
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.unlock(0x10496c0)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/lock_futex.go:118 +0xa0
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.printunlock()
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/print.go:80 +0x59
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.throw(0xaa9662, 0x1b)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/panic.go:610 +0x4e
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.unlock(0x10496c0)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/lock_futex.go:118 +0xa0
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.printunlock()
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/print.go:80 +0x59
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.throw(()
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: 0xaa9662, 0x1b)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/panic.go:610 +0x4e
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.unlock(0x10496c0)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/lock_futex.go:118 +0xa0
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.printunlock()
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/print.go:80 +0x59
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.throw(0xaa9662, 0x1b)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/panic.go:610 +0x4e
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.unlock(0x10496c0)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/lock_futex.go:118 +0xa0
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.printunlock()
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/print.go:80 +0x59
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.throw(0xaa9662, 0x1b)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/panic.go:610 +0x4e
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.unlock(0x10496c0)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/lock_futex.go:118 +0xa0
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.printunlock()
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/print.go:80 +0x59
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.throw(0xaa9662, 0x1b)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/panic.go:610 +0x4e
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.unlock(0x10496c0)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/lock_futex.go:118 +0xa0
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.printunlock()
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/print.go:80 +0x59
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.throw(0xaa9662, 0x1b)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/panic.go:610 +0x4e
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.unlock(0x10496c0)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/lock_futex.go:118 +0xa0
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.printunlock()
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/print.go:80 +0x59
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.throw(0xaa9662, 0x1b)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/panic.go:610 +0x4e
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.unlock(0x10496c0)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/lock_futex.go:118 +0xa0
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.printunlock()
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/print.go:80 +0x59
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.throw(0xaa9662, 0x1b)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/panic.go:610 +0x4e
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.unlock(0x10496c0)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/lock_futex.go:118 +0xa0
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.printunlock()
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/print.go:80 +0x59
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.throw(0xaa9662, 0x1b)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/panic.go:610 +0x4e
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.unlock(0x10496c0)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/lock_futex.go:118 +0xa0
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.printunlock()
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/print.go:80 +0x59
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.throw(0xaa9662, 0x1b)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/panic.go:610 +0x4e
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.unlock(0x10496c0)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/lock_futex.go:118 +0xa0
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.printunlock()
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/print.go:80 +0x59
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.throw(0xaa9662, 0x1b)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/panic.go:610 +0x4e
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.unlock(0x10496c0)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/lock_futex.go:118 +0xa0
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.printunlock()
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/print.go:80 +0x59
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.throw(0xaa9662, 0x1b)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/panic.go:610 +0x4e
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.unlock(0x10496c0)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/lock_futex.go:118 +0xa0
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.printunlock()
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/print.go:80 +0x59
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.throw(0xaa9662, 0x1b)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/panic.go:610 +0x4e
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.unlock(0x10496c0)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/lock_futex.go:118 +0xa0
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.printunlock()
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/print.go:80 +0x59
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.throw(0xaa9662, 0x1b)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/panic.go:610 +0x4e
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.unlock(0x10496c0)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/lock_futex.go:118 +0xa0
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.printunlock()
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/print.go:80 +0x59
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.throw(0xaa9662, 0x1b)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/panic.go:610 +0x4e
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.unlock(0x10496c0)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/lock_futex.go:118 +0xa0
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.printunlock()
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/print.go:80 +0x59
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.throw(0xaa9662, 0x1b)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/panic.go:610 +0x4e
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.unlock(0x10496c0)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/lock_futex.go:118 +0xa0
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.printunlock()
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/print.go:80 +0x59
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.throw(0xaa9662, 0x1b)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/panic.go:610 +0x4e
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.unlock(0x10496c0)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/lock_futex.go:118 +0xa0
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.printunlock()
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/print.go:80 +0x59
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.throw(0xaa9662, 0x1b)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/panic.go:610 +0x4e
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.unlock(0x10496c0)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/lock_futex.go:118 +0xa0
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.printunlock()
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/print.go:80 +0x59
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.throw(0xaa9662, 0x1b)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/panic.go:610 +0x4e
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.unlock(0x10496c0)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/lock_futex.go:118 +0xa0
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.printunlock()
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/print.go:80 +0x59
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.throw(0xaa9662, 0x1b)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/panic.go:610 +0x4e
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.unlock(0x10496c0)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/lock_futex.go:118 +0xa0
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.printunlock()
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/print.go:80 +0x59
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.throw(0xaa9662, 0x1b)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/panic.go:610 +0x4e
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.unlock(0x10496c0)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/lock_futex.go:118 +0xa0
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.printunlock()
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/print.go:80 +0x59
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.throw(0xaa9662, 0x1b)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/panic.go:610 +0x4e
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.unlock(0x10496c0)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/lock_futex.go:118 +0xa0
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.printunlock()
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/print.go:80 +0x59
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.throw(0xaa9662, 0x1b)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/panic.go:610 +0x4e
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.unlock(0x10496c0)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/lock_futex.go:118 +0xa0
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.printunlock()
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/print.go:80 +0x59
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.throw(0xaa9662, 0x1b)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/panic.go:610 +0x4e
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.unlock(0x10496c0)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/lock_futex.go:118 +0xa0
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.printunlock()
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/print.go:80 +0x59
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.throw(0xaa9662, 0x1b)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/panic.go:610 +0x4e
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.unlock(0x10496c0)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/lock_futex.go:118 +0xa0
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.printunlock()
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/print.go:80 +0x59
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.throw(0xaa9662, 0x1b)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/panic.go:610 +0x4e
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.unlock(0x10496c0)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/lock_futex.go:118 +0xa0
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.printunlock()
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/print.go:80 +0x59
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.throw(0xaa9662, 0x1b)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/panic.go:610 +0x4e
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.unlock(0x10496c0)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/lock_futex.go:118 +0xa0
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.printunlock()
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/print.go:80 +0x59
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.throw(0xaa9662, 0x1b)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/panic.go:610 +0x4e
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.unlock(0x10496c0)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/lock_futex.go:118 +0xa0
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.printunlock()
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/print.go:80 +0x59
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.throw(0xaa9662, 0x1b)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/panic.go:610 +0x4e
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.unlock(0x10496c0)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/lock_futex.go:118 +0xa0
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.printunlock()
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/print.go:80 +0x59
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.throw(0xaa9662, 0x1b)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/panic.go:610 +0x4e
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.unlock(0x10496c0)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/lock_futex.go:118 +0xa0
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.printunlock()
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/print.go:80 +0x59
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.throw(0xaa9662, 0x1b)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/panic.go:610 +0x4e
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.unlock(0x10496c0)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/lock_futex.go:118 +0xa0
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.printunlock()
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/print.go:80 +0x59
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.throw(0xaa9662, 0x1b)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/panic.go:610 +0x4e
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: ...additional frames elided...
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: goroutine 352590 [running]:
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.systemstack_switch()
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/asm_amd64.s:363 fp=0xc4203cd5b8 sp=0xc4203cd5b0 pc=0x457f30
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.startpanic()
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/panic.go:589 +0x1e fp=0xc4203cd5d0 sp=0xc4203cd5b8 pc=0x42c0ae
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.throw(0xaa0b0a, 0xf)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/panic.go:615 +0x74 fp=0xc4203cd5f0 sp=0xc4203cd5d0 pc=0x42c1d4
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.mallocgc(0x1, 0x9bb820, 0xc4201da001, 0xc420440564)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/malloc.go:621 +0x99d fp=0xc4203cd690 sp=0xc4203cd5f0 pc=0x411c5d
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.newobject(0x9bb820, 0x9bb820)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/malloc.go:839 +0x38 fp=0xc4203cd6c0 sp=0xc4203cd690 pc=0x411e08
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: reflect.unsafe_New(0x9bb820, 0x9bb820)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/malloc.go:844 +0x2b fp=0xc4203cd6e0 sp=0xc4203cd6c0 pc=0x411e5b
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: reflect.makeInt(0x0, 0x1, 0xb18380, 0x9bb820, 0xc420440564, 0x1, 0x88)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/reflect/value.go:2339 +0x4b fp=0xc4203cd708 sp=0xc4203cd6e0 pc=0x4b4cab
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: reflect.cvtUint(0x9bb820, 0xffac21, 0x88, 0xb18380, 0x9bb820, 0x401f7c, 0xc4203cd7e8, 0xc4203cd7f0)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/reflect/value.go:2414 +0x85 fp=0xc4203cd758 sp=0xc4203cd708 pc=0x4b5325
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: reflect.Value.Convert(0x9bb820, 0xffac21, 0x88, 0xb18380, 0x9bb820, 0x88, 0xc420440564, 0x88)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/reflect/value.go:2249 +0xe9 fp=0xc4203cd7e0 sp=0xc4203cd758 pc=0x4b45b9
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: github.com/prometheus/node_exporter/vendor/github.com/godbus/dbus.setDest(0x9bb820, 0xc42044053d, 0x188, 0x9bb820, 0xffac21, 0x88, 0x0, 0x0)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /arch-packages/prometheus-node-exporter/src/src/github.com/prometheus/node_exporter/vendor/github.com/godbus/dbus/dbus.go:96 +0x2ea fp=0xc4203cd880 sp=0xc4203cd7e0 pc=0x7e3bda
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: github.com/prometheus/node_exporter/vendor/github.com/godbus/dbus.storeBase(0x9bb820, 0xc42044053d, 0x188, 0x9bb820, 0xffac21, 0x88, 0x0, 0x0)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /arch-packages/prometheus-node-exporter/src/src/github.com/prometheus/node_exporter/vendor/github.com/godbus/dbus/dbus.go:79 +0x5d fp=0xc4203cd8d0 sp=0xc4203cd880 pc=0x7e38bd
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: github.com/prometheus/node_exporter/vendor/github.com/godbus/dbus.store(0x9bb820, 0xc42044053d, 0x188, 0x9bb820, 0xffac21, 0x88, 0x9bb820, 0xffac21)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /arch-packages/prometheus-node-exporter/src/src/github.com/prometheus/node_exporter/vendor/github.com/godbus/dbus/dbus.go:74 +0xe3 fp=0xc4203cd920 sp=0xc4203cd8d0 pc=0x7e3753
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: github.com/prometheus/node_exporter/vendor/github.com/godbus/dbus.store(0x9ab660, 0xc42044053d, 0x16, 0x9bb820, 0xffac21, 0x88, 0x0, 0x0)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /arch-packages/prometheus-node-exporter/src/src/github.com/prometheus/node_exporter/vendor/github.com/godbus/dbus/dbus.go:66 +0x1be fp=0xc4203cd970 sp=0xc4203cd920 pc=0x7e382e
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: github.com/prometheus/node_exporter/vendor/github.com/godbus/dbus.storeInterfaces(0x9bb820, 0xffac21, 0x9ab660, 0xc42044053d, 0x0, 0x0)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /arch-packages/prometheus-node-exporter/src/src/github.com/prometheus/node_exporter/vendor/github.com/godbus/dbus/dbus.go:61 +0xb2 fp=0xc4203cd9d8 sp=0xc4203cd970 pc=0x7e3642
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: github.com/prometheus/node_exporter/vendor/github.com/godbus/dbus.Store(0xc420020c80, 0x5, 0x8, 0xc4203cdc28, 0x5, 0x5, 0x0, 0x0)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /arch-packages/prometheus-node-exporter/src/src/github.com/prometheus/node_exporter/vendor/github.com/godbus/dbus/dbus.go:53 +0x99 fp=0xc4203cda20 sp=0xc4203cd9d8 pc=0x7e34e9
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: github.com/prometheus/node_exporter/vendor/github.com/godbus/dbus.DecodeMessage(0xb0b580, 0xc42014d2d0, 0xc420028168, 0xd, 0xd)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /arch-packages/prometheus-node-exporter/src/src/github.com/prometheus/node_exporter/vendor/github.com/godbus/dbus/message.go:153 +0x32f fp=0xc4203cdc88 sp=0xc4203cda20 pc=0x7f087f
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: github.com/prometheus/node_exporter/vendor/github.com/godbus/dbus.(*unixTransport).ReadMessage(0xc4202b8250, 0xc4204299b0, 0x1, 0xc42014c878)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /arch-packages/prometheus-node-exporter/src/src/github.com/prometheus/node_exporter/vendor/github.com/godbus/dbus/transport_unix.go:160 +0xb1f fp=0xc4203cde08 sp=0xc4203cdc88 pc=0x7f71cf
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: github.com/prometheus/node_exporter/vendor/github.com/godbus/dbus.(*Conn).inWorker(0xc42016c000)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /arch-packages/prometheus-node-exporter/src/src/github.com/prometheus/node_exporter/vendor/github.com/godbus/dbus/conn.go:285 +0x4b fp=0xc4203cdfd8 sp=0xc4203cde08 pc=0x7e05ab
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: runtime.goexit()
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/asm_amd64.s:2361 +0x1 fp=0xc4203cdfe0 sp=0xc4203cdfd8 pc=0x45aaa1
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: created by github.com/prometheus/node_exporter/vendor/github.com/godbus/dbus.(*Conn).Auth
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /arch-packages/prometheus-node-exporter/src/src/github.com/prometheus/node_exporter/vendor/github.com/godbus/dbus/auth.go:118 +0x6c9
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: goroutine 1 [IO wait, 4458 minutes]:
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: internal/poll.runtime_pollWait(0x7fbe224b0f00, 0x72, 0x0)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/netpoll.go:173 +0x57
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: internal/poll.(*pollDesc).wait(0xc42017a598, 0x72, 0xc42006c000, 0x0, 0x0)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/internal/poll/fd_poll_runtime.go:85 +0x9b
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: internal/poll.(*pollDesc).waitRead(0xc42017a598, 0xffffffffffffff00, 0x0, 0x0)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/internal/poll/fd_poll_runtime.go:90 +0x3d
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: internal/poll.(*FD).Accept(0xc42017a580, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/internal/poll/fd_unix.go:372 +0x1a8
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: net.(*netFD).accept(0xc42017a580, 0xc4201604e0, 0xc420061be0, 0x4022a8)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/net/fd_unix.go:238 +0x42
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: net.(*TCPListener).accept(0xc420178108, 0xc420061c10, 0x401207, 0xc4201604e0)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/net/tcpsock_posix.go:136 +0x2e
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: net.(*TCPListener).AcceptTCP(0xc420178108, 0xc420061c58, 0xc420061c60, 0x18)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/net/tcpsock.go:246 +0x49
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: net/http.tcpKeepAliveListener.Accept(0xc420178108, 0xac6960, 0xc420160460, 0xb11b60, 0xc420175830)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/net/http/server.go:3216 +0x2f
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: net/http.(*Server).Serve(0xc4201b8a90, 0xb11820, 0xc420178108, 0x0, 0x0)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/net/http/server.go:2770 +0x1a5
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: net/http.(*Server).ListenAndServe(0xc4201b8a90, 0xc4201b8a90, 0x2)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/net/http/server.go:2711 +0xa9
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: net/http.ListenAndServe(0xa98e57, 0x5, 0x0, 0x0, 0x1, 0xc4201d6200)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/net/http/server.go:2969 +0x7a
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: main.main()
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /arch-packages/prometheus-node-exporter/src/src/github.com/prometheus/node_exporter/node_exporter.go:112 +0x9cf
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: goroutine 352571 [runnable]:
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: github.com/prometheus/node_exporter/vendor/github.com/godbus/dbus.(*Object).Call(0xc420429a10, 0xaa88b4, 0x1a, 0x0, 0x0, 0x0, 0x0, 0xc42016c000)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /arch-packages/prometheus-node-exporter/src/src/github.com/prometheus/node_exporter/vendor/github.com/godbus/dbus/object.go:27 +0xbb
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: github.com/prometheus/node_exporter/vendor/github.com/godbus/dbus.(*Conn).Hello(0xc42016c000, 0xc42016c000, 0x0)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /arch-packages/prometheus-node-exporter/src/src/github.com/prometheus/node_exporter/vendor/github.com/godbus/dbus/conn.go:270 +0x7d
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: github.com/prometheus/node_exporter/vendor/github.com/coreos/go-systemd/dbus.dbusAuthHelloConnection(0xac5f70, 0x120, 0x110, 0xa33220)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /arch-packages/prometheus-node-exporter/src/src/github.com/prometheus/node_exporter/vendor/github.com/coreos/go-systemd/dbus/dbus.go:230 +0x51
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: github.com/prometheus/node_exporter/vendor/github.com/coreos/go-systemd/dbus.NewSystemConnection.func1(0x110, 0x110, 0xc4202b6240)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /arch-packages/prometheus-node-exporter/src/src/github.com/prometheus/node_exporter/vendor/github.com/coreos/go-systemd/dbus/dbus.go:127 +0x2d
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: github.com/prometheus/node_exporter/vendor/github.com/coreos/go-systemd/dbus.NewConnection(0xac5f00, 0x7fbe245106c8, 0x0, 0xffffffffffffffff)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /arch-packages/prometheus-node-exporter/src/src/github.com/prometheus/node_exporter/vendor/github.com/coreos/go-systemd/dbus/dbus.go:164 +0x3c
Mai 21 15:45:00 pandora systemd[1]: prometheus-node-exporter.service: Main process exited, code=exited, status=2/INVALIDARGUMENT
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: github.com/prometheus/node_exporter/vendor/github.com/coreos/go-systemd/dbus.NewSystemConnection(0xc420052c38, 0xc420052ab0, 0x411e08)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /arch-packages/prometheus-node-exporter/src/src/github.com/prometheus/node_exporter/vendor/github.com/coreos/go-systemd/dbus/dbus.go:126 +0x2d
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: github.com/prometheus/node_exporter/vendor/github.com/coreos/go-systemd/dbus.New(0x7830bb, 0xa52ce0, 0xc420d7e190)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /arch-packages/prometheus-node-exporter/src/src/github.com/prometheus/node_exporter/vendor/github.com/coreos/go-systemd/dbus/dbus.go:116 +0x26
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: github.com/prometheus/node_exporter/collector.(*systemdCollector).newDbus(0xc420432bd0, 0xdc48ed, 0x9bb5a0, 0xc4202b8180)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /arch-packages/prometheus-node-exporter/src/src/github.com/prometheus/node_exporter/collector/systemd_linux.go:150 +0x5c
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: github.com/prometheus/node_exporter/collector.(*systemdCollector).getAllUnits(0xc420432bd0, 0x0, 0x0, 0x0, 0x0, 0x0)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /arch-packages/prometheus-node-exporter/src/src/github.com/prometheus/node_exporter/collector/systemd_linux.go:159 +0x80
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: github.com/prometheus/node_exporter/collector.(*systemdCollector).Update(0xc420432bd0, 0xc420471aa0, 0x1025740, 0xc42003fea0)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /arch-packages/prometheus-node-exporter/src/src/github.com/prometheus/node_exporter/collector/systemd_linux.go:83 +0x40
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: github.com/prometheus/node_exporter/collector.execute(0xa9bcaa, 0x7, 0xb0bcc0, 0xc420432bd0, 0xc420471aa0)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /arch-packages/prometheus-node-exporter/src/src/github.com/prometheus/node_exporter/collector/collector.go:127 +0x7e
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: github.com/prometheus/node_exporter/collector.nodeCollector.Collect.func1(0xc420471aa0, 0xc4203edfb0, 0xa9bcaa, 0x7, 0xb0bcc0, 0xc420432bd0)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /arch-packages/prometheus-node-exporter/src/src/github.com/prometheus/node_exporter/collector/collector.go:118 +0x53
Mai 21 15:45:00 pandora systemd[1]: prometheus-node-exporter.service: Failed with result 'exit-code'.
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: created by github.com/prometheus/node_exporter/collector.nodeCollector.Collect
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /arch-packages/prometheus-node-exporter/src/src/github.com/prometheus/node_exporter/collector/collector.go:117 +0x109
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: goroutine 352529 [IO wait]:
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: internal/poll.runtime_pollWait(0x7fbe224b0880, 0x72, 0xc42003ae58)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/netpoll.go:173 +0x57
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: internal/poll.(*pollDesc).wait(0xc420020218, 0x72, 0xffffffffffffff00, 0xb0d6a0, 0xff54c8)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/internal/poll/fd_poll_runtime.go:85 +0x9b
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: internal/poll.(*pollDesc).waitRead(0xc420020218, 0xc420df6100, 0x1, 0x1)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/internal/poll/fd_poll_runtime.go:90 +0x3d
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: internal/poll.(*FD).Read(0xc420020200, 0xc420df61c1, 0x1, 0x1, 0x0, 0x0, 0x0)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/internal/poll/fd_unix.go:157 +0x17d
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: net.(*netFD).Read(0xc420020200, 0xc420df61c1, 0x1, 0x1, 0xc4204f01e0, 0xc42003afa0, 0xc42003af01)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/net/fd_unix.go:202 +0x4f
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: net.(*conn).Read(0xc420178048, 0xc420df61c1, 0x1, 0x1, 0x0, 0x0, 0x0)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/net/net.go:176 +0x6a
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: net/http.(*connReader).backgroundRead(0xc420df61b0)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/net/http/server.go:668 +0x5a
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: created by net/http.(*connReader).startBackgroundRead
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/net/http/server.go:664 +0xce
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: goroutine 97129 [chan receive]:
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: github.com/prometheus/node_exporter/vendor/github.com/prometheus/client_golang/prometheus.(*Registry).Gather(0xc4201a8680, 0x0, 0x0, 0x0, 0x0, 0x0)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /arch-packages/prometheus-node-exporter/src/src/github.com/prometheus/node_exporter/vendor/github.com/prometheus/client_golang/prometheus/registry.go:444 +0x851
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: github.com/prometheus/node_exporter/vendor/github.com/prometheus/client_golang/prometheus.Gatherers.Gather(0xc42023ca20, 0x2, 0x2, 0x0, 0x0, 0x0, 0x0, 0x0)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /arch-packages/prometheus-node-exporter/src/src/github.com/prometheus/node_exporter/vendor/github.com/prometheus/client_golang/prometheus/registry.go:591 +0xe2e
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: github.com/prometheus/node_exporter/vendor/github.com/prometheus/client_golang/prometheus/promhttp.HandlerFor.func1(0x7fbe22474458, 0xc4200897c0, 0xc420130800)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /arch-packages/prometheus-node-exporter/src/src/github.com/prometheus/node_exporter/vendor/github.com/prometheus/client_golang/prometheus/promhttp/http.go:116 +0x59
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: net/http.HandlerFunc.ServeHTTP(0xc420089680, 0x7fbe22474458, 0xc4200897c0, 0xc420130800)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/net/http/server.go:1947 +0x44
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: github.com/prometheus/node_exporter/vendor/github.com/prometheus/client_golang/prometheus/promhttp.InstrumentHandlerInFlight.func1(0x7fbe22474458, 0xc4200897c0, 0xc420130800)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /arch-packages/prometheus-node-exporter/src/src/github.com/prometheus/node_exporter/vendor/github.com/prometheus/client_golang/prometheus/promhttp/instrument_server.go:40 +0xa9
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: net/http.HandlerFunc.ServeHTTP(0xc42050e420, 0x7fbe22474458, 0xc4200897c0, 0xc420130800)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/net/http/server.go:1947 +0x44
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: github.com/prometheus/node_exporter/vendor/github.com/prometheus/client_golang/prometheus/promhttp.InstrumentHandlerCounter.func1(0xb11320, 0xc4202380e0, 0xc420130800)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /arch-packages/prometheus-node-exporter/src/src/github.com/prometheus/node_exporter/vendor/github.com/prometheus/client_golang/prometheus/promhttp/instrument_server.go:100 +0xda
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: net/http.HandlerFunc.ServeHTTP(0xc42050e660, 0xb11320, 0xc4202380e0, 0xc420130800)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/net/http/server.go:1947 +0x44
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: main.handler(0xb11320, 0xc4202380e0, 0xc420130800)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /arch-packages/prometheus-node-exporter/src/src/github.com/prometheus/node_exporter/node_exporter.go:68 +0x718
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: net/http.HandlerFunc.ServeHTTP(0xac6790, 0xb11320, 0xc4202380e0, 0xc420130800)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/net/http/server.go:1947 +0x44
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: net/http.(*ServeMux).ServeHTTP(0x1025280, 0xb11320, 0xc4202380e0, 0xc420130800)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/net/http/server.go:2337 +0x130
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: net/http.serverHandler.ServeHTTP(0xc4201b8a90, 0xb11320, 0xc4202380e0, 0xc420130800)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/net/http/server.go:2694 +0xbc
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: net/http.(*conn).serve(0xc420160460, 0xb11aa0, 0xc4201a8040)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/net/http/server.go:1830 +0x651
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: created by net/http.(*Server).Serve
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/net/http/server.go:2795 +0x27b
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: goroutine 352591 [chan receive]:
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: github.com/prometheus/node_exporter/vendor/github.com/godbus/dbus.(*Conn).outWorker(0xc42016c000)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /arch-packages/prometheus-node-exporter/src/src/github.com/prometheus/node_exporter/vendor/github.com/godbus/dbus/conn.go:427 +0x63
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: created by github.com/prometheus/node_exporter/vendor/github.com/godbus/dbus.(*Conn).Auth
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /arch-packages/prometheus-node-exporter/src/src/github.com/prometheus/node_exporter/vendor/github.com/godbus/dbus/auth.go:119 +0x6ee
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: goroutine 352575 [runnable]:
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: syscall.Syscall(0x0, 0x8, 0xc4203d7900, 0x1200, 0x8, 0x1200, 0x0)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/syscall/asm_linux_amd64.s:18 +0x5
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: syscall.read(0x8, 0xc4203d7900, 0x1200, 0x1200, 0xc4201a8201, 0x0, 0x0)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/syscall/zsyscall_linux_amd64.go:749 +0x5f
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: syscall.Read(0x8, 0xc4203d7900, 0x1200, 0x1200, 0x0, 0xc42002c058, 0xc42002c000)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/syscall/syscall_unix.go:162 +0x49
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: internal/poll.(*FD).Read(0xc420276730, 0xc4203d7900, 0x1200, 0x1200, 0x0, 0x0, 0x0)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/internal/poll/fd_unix.go:153 +0x118
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: os.(*File).read(0xc42042e450, 0xc4203d7900, 0x1200, 0x1200, 0x4e9081, 0x9bb820, 0x1200)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/os/file_unix.go:226 +0x4e
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: os.(*File).Read(0xc42042e450, 0xc4203d7900, 0x1200, 0x1200, 0x1200, 0x1200, 0xc4203d7900)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/os/file.go:107 +0x6a
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: bytes.(*Buffer).ReadFrom(0xc4205880e0, 0xb0c780, 0xc42042e450, 0x0, 0xc42005d778, 0x18)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/bytes/buffer.go:205 +0xa0
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: io/ioutil.readAll(0xb0c780, 0xc42042e450, 0x1200, 0x0, 0x0, 0x0, 0x0, 0x0)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/io/ioutil/ioutil.go:36 +0xb5
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: io/ioutil.ReadFile(0xc4202d8e40, 0x35, 0x0, 0x0, 0x0, 0x0, 0x0)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/io/ioutil/ioutil.go:73 +0xd5
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: github.com/prometheus/node_exporter/collector.readUintFromFile(0xc4202d8e40, 0x35, 0x3, 0xc4202d8e40, 0x35)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /arch-packages/prometheus-node-exporter/src/src/github.com/prometheus/node_exporter/collector/helper.go:23 +0x39
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: github.com/prometheus/node_exporter/collector.(*cpuCollector).updateCPUfreq(0xc4201a8500, 0xc420471aa0, 0x0, 0x0)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /arch-packages/prometheus-node-exporter/src/src/github.com/prometheus/node_exporter/collector/cpu_linux.go:113 +0xa4f
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: github.com/prometheus/node_exporter/collector.(*cpuCollector).Update(0xc4201a8500, 0xc420471aa0, 0x1025740, 0xc4202a0e80)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /arch-packages/prometheus-node-exporter/src/src/github.com/prometheus/node_exporter/collector/cpu_linux.go:86 +0x60
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: github.com/prometheus/node_exporter/collector.execute(0xa98291, 0x3, 0xb0b940, 0xc4201a8500, 0xc420471aa0)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /arch-packages/prometheus-node-exporter/src/src/github.com/prometheus/node_exporter/collector/collector.go:127 +0x7e
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: github.com/prometheus/node_exporter/collector.nodeCollector.Collect.func1(0xc420471aa0, 0xc4203edfb0, 0xa98291, 0x3, 0xb0b940, 0xc4201a8500)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /arch-packages/prometheus-node-exporter/src/src/github.com/prometheus/node_exporter/collector/collector.go:118 +0x53
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: created by github.com/prometheus/node_exporter/collector.nodeCollector.Collect
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /arch-packages/prometheus-node-exporter/src/src/github.com/prometheus/node_exporter/collector/collector.go:117 +0x109
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: goroutine 352542 [semacquire]:
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: sync.runtime_Semacquire(0xc4203edfbc)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/sema.go:56 +0x39
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: sync.(*WaitGroup).Wait(0xc4203edfb0)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/sync/waitgroup.go:129 +0x72
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: github.com/prometheus/node_exporter/collector.nodeCollector.Collect(0xc420436270, 0xc420471aa0)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /arch-packages/prometheus-node-exporter/src/src/github.com/prometheus/node_exporter/collector/collector.go:122 +0x12f
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: github.com/prometheus/node_exporter/vendor/github.com/prometheus/client_golang/prometheus.(*Registry).Gather.func1()
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /arch-packages/prometheus-node-exporter/src/src/github.com/prometheus/node_exporter/vendor/github.com/prometheus/client_golang/prometheus/registry.go:401 +0x5c
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: created by github.com/prometheus/node_exporter/vendor/github.com/prometheus/client_golang/prometheus.(*Registry).Gather
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /arch-packages/prometheus-node-exporter/src/src/github.com/prometheus/node_exporter/vendor/github.com/prometheus/client_golang/prometheus/registry.go:454 +0x816
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: goroutine 352541 [semacquire]:
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: sync.runtime_Semacquire(0xc4203edfac)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/runtime/sema.go:56 +0x39
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: sync.(*WaitGroup).Wait(0xc4203edfa0)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /usr/lib/go/src/sync/waitgroup.go:129 +0x72
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: github.com/prometheus/node_exporter/vendor/github.com/prometheus/client_golang/prometheus.(*Registry).Gather.func2(0xc4203edfa0, 0xc420471aa0)
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /arch-packages/prometheus-node-exporter/src/src/github.com/prometheus/node_exporter/vendor/github.com/prometheus/client_golang/prometheus/registry.go:415 +0x2b
Mai 21 15:45:00 pandora prometheus-node-exporter[538]: created by github.com/prometheus/node_exporter/vendor/github.com/prometheus/client_golang/prometheus.(*Registry).Gather
Mai 21 15:45:00 pandora prometheus-node-exporter[538]:         /arch-packages/prometheus-node-exporter/src/src/github.com/prometheus/node_exporter/vendor/github.com/prometheus/client_golang/prometheus/registry.go:414 +0x537

so 0.15.2 runs stable on go1.10.1 and 0.16.0 seems to have an problem on go1.10.2.

[SuperQ]

@MorphBonehunter, Thanks for the report. Are you running with the systemd collector enabled? It looks like the crash may have been in the dbus code.

[MorphBonehunter]

Yes, thats right. I've running the exporter with the following options:
--log.level warn --collector.systemd --collector.netdev.ignored-devices="^br-.*|^docker.*|^veth.*" --collector.textfile.directory=/var/lib/prometheus-node-exporter

[grobie]

I'd be careful to not read too much into the last executed collector before the crash, given all the experiments around cgo and go versions.

IIRC you mentioned you had reported this to the go team @SuperQ, did anything come out of it?

[SuperQ]

@grobie True, we've seen the crash with default flags. I think we need to do some more bisecting of the collectors to see which one triggers the problem. I'm going to try spinning up a number of exporters with various flag differences.

There has been no progress in the upstream bug. We need a reproducible test case in order to convince them to investigate.

[daenney]

Interestingly, this is the first bug report that actually has a stack trace. So far every reported instance of this bug ended at fatal error: runtime.unlock: lock count.

Fwiw I wasn't explicitly running with the systemd collector enabled, so unless that happens by default I think that aspect is more of a coincidence than anything else.

[austin987]

I was able to get a stacktrace today (attached) when load testing with vegeta.

This is on an OpenRC system (Gentoo), so systemd is not the culprit.
node_exporter.log

[daenney]

@austin987 You seem to be getting a different error though: fatal error: schedule: holding locks.

[austin987]

@daenney ah, so it is; I didn't read closely enough. Should I file a new issue for that?

[daenney]

@austin987 I'm not sure. Might be good for visibility though, so we don't forget about tracking that one down too, we risk it getting burried in the rest of this issue. They feel related to me.

[mschroeder223]

I posted this previously on April 2nd, I had disabled infiniband, zfs, wifi, nfs and nfsd and I've had rc.1 running on multiple servers with no issues since then. Which would lead me to believe the issue lies in one of those collectors.

[daenney]

Those collectors are active on my system but aren't actually doing anything since I don't have any infiniband, ZFS, nfs(d) active. It bails out in the first check in Update() of each collector which at least in my case would make them unlikely to be involved in that crash.

I do have WiFi since there's a built-in WiFi thing in this box. The only metric collected is node_wifi_interface_frequency_hertz, it's not actually active or scanning or connected to any network. Looking at that code I'm having a hard time seeing how it itself would cause such an error. The one stack trace we do seem to have from @MorphBonehunter doesn't mention anything related to the wifi collector in the crash which I would expect to see if it was somehow involved.

[kielfriedt]

any progress on this? Any temporary fix?

[SuperQ]

The temporary fix is to build with Go 1.9.x.

[daenney]

I'm honestly a bit stumped though. I'm not sure where to go from here and golang/go#25128 kinda feels dead in the water (though I suppose that have to do with things ramping up to Go 1.11).

If anyone has suggestion on what to try, I'm all ears. I can build/run whatever and try and crash it, but it would help if we had osme kind of strategy to narrow it down.

I guess we could run a bisect between Go 1.9.x and 1.10 and see when the crash starts to appear?

[discordianfish]

@daenney Yes, bisect between 1.9.x and 1.10 would be what I would suggest to. Would be awesome if you could look into this!

[daenney]

Alright, looks like something started moving in golang/go#25128 and with golang/go@4991bc6257a9e9d922f7b6e29e393d764c4e4295 we might be able to get a proper error trace out of it. I'll see about giving that a try first before I dive into bisecting Go 1.9 to 1.10, as that'll probably take a long time to narrow down given that it takes some time to trigger the error.

[egonelbre]

I stumbled into this issue by accident and took a quick look around in the code, so ignore when I say something completely stupid, since I have no in-depth understanding.

When VM and/or heisenbug with varying timing, I usually suspect time drift problems. There are ways to force time problems e.g. ntpdsim, but I didn't get to that. Anyways, this suspicion led me into https://github.com/prometheus/node_exporter/blob/b62c7bc0ad37373b911fa45937348f3c594ce19d/collector/ntp.go#L148... but, shouldn't leapMidnight be protected somehow? Because, as far as I can understand Update may be called concurrently.

[SuperQ]

@egonelbre Good catch, yes, that does appear to need a mutex on it. Probably unrelated to this specific crash, as we're pretty sure it's in the CGO code, and that collector is pure go. I'll file a separate issue for that.

[daenney]

Has anyone tried building this with Go 1.11? I'm short on time right now to try and do a full bisect between Go 1.9 and 1.10, but if it happens to be gone with 1.11 I'd be good with that :smile:.

[chrj]

I will try running under under the Go 1.11 beta and put our node_exporters up for the test. We have had 1-2 crashes per week on ~70 instances. I'll report back in a week.

[marcan]

Oh hey, you might remember me from that other time node_exporter found a Golang bug. I just hit this one too:

fatal error: runtime·unlock: lock count
fatal error: runtime·unlock: lock count
fatal error: runtime·unlock: lock count
fatal error: runtime·unlock: lock count
fatal error: runtime·unlock: lock count
fatal error: runtime·unlock: lock count
fatal error: runtime·unlock: lock count
fatal error: runtime·unlock: lock count
fatal error: runtime·unlock: lock count
fatal error: runtime·unlock: lock count
fatal error: runtime·unlock: lock count
fatal error: runtime·unlock: lock count
fatal error: fatal error: runtime·unlock: lock countruntime·lock: lock count

panic during panic
stack trace unavailable

runtime stack:

This is Gentoo again, versions:

node_exporter, version 0.16.0 (branch: non-git, revision: d42bd70)
  build user:       portage@binhost
  build date:       20180619-21:57:10
  go version:       go1.10.1

Unfortunately this just happened on a VM with many siblings running on the same hardware, after days of uptime, and I will only have access to this hardware for a couple more days, so it's not looking good for reproducibility. However, I'll be running these VM images at home and see if I can get it to repro on other hardware.

[SuperQ]

@marcan Welcome back! :joy:

It's reasonably easy to reproduce. Slamming the node_exporter with vegeta with like 3QPS will crash it in ~30min.

But nobody's been able to bisect enough things or get enough trace info to figure out so far. :(

[marcan]

Just in case hardware is related to reproducibility, I'll dump my stack info here:

(32-thread host)

• Linux vmhost04 4.17.2-gentoo #1 SMP Mon Jul 23 16:11:24 CEST 2018 x86_64 Intel(R) Xeon(R) CPU E5-2667 v3 @ 3.20GHz GenuineIntel GNU/Linux
• QEMU emulator version 2.12.0

(16-CPU guest)

• Linux csgo06 4.17.2-gentoo #4 SMP Thu Jun 28 19:00:28 CEST 2018 x86_64 Intel(R) Xeon(R) CPU E5-2667 v3 @ 3.20GHz GenuineIntel GNU/Linux
• sys-libs/glibc-2.26-r7

I'll be testing the same exact guest VM image again later, but I won't be able to get ahold of identical server hardware (but I can try on a bunch of different hosts I do have access to). Hopefully I can spend some time tracking it down. Unfortunately it's less likely I'll be able to find time to do it on the original hardware where I saw the crash, before I lose access.

[SuperQ]

So far, it doesn't seem hardware related, only CGO issue with 1.10

[chrj]

Unfortunately, I'm also seeing the issue with Go 1.11beta2.

[marcan]

Well, this just happened on another server of mine, so reproducibility won't be an issue. This time it spat out >95000 lines (!) of "fatal error: runtime·unlock: lock count" into the log.

node_exporter, version 0.16.0 (branch: non-git, revision: d42bd70)
  build user:       portage@binhost
  build date:       20180717-22:35:36
  go version:       go1.10.3

Will debug later when I get a chance.

[hoffie]

The most minimal example which still crashes for me is running with only the wifi collector enabled.

None of the node_exporters with the wifi collector disabled have crashed for me so far (but it's hard to tell if it just takes longer or eliminates the problem entirely). Do we have any reports of crashes with the wifi collector disabled? I only see suspicions of the wifi being possibly the culprit:
https://github.com/prometheus/node_exporter/issues/870#issuecomment-397692373
https://github.com/prometheus/node_exporter/issues/870#issuecomment-397692373

Also note: Sometimes it crashes within seconds, sometimes it takes >90min. Linux localhost 4.17.5-1-ARCH #1 SMP PREEMPT Sun Jul 8 17:27:31 UTC 2018 x86_64 GNU/Linux, go version go1.10.3 linux/amd64, node_exporter master @ 80a5712b97cd649b6bf2f9f60cf5c497043ef187. Also, the crash messages have been totally different (e.g. systemstack called from unexpected goroutine, fatal error: malloc deadlock). All contained the lock count error somewhere. Sometimes, crashes manifest in a few lines, sometimes in thousands, sometimes with "clean" stack traces, sometimes with stack traces mixed with other error messages.

Will try further tracking it down by trying different go versions and/or bisecting the wifi collector code, as time permits.

$ ./node_exporter $(for coll in arp bcache bonding conntrack cpu diskstats edac entropy filefd filesystem hwmon infiniband ipvs loadavg mdadm meminfo netdev netstat nfs nfsd sockstat stat textfile time timex uname vmstat netclass xfs zfs; do echo --no-collector.$coll; done) --web.listen-address=:9101
INFO[0000] Starting node_exporter (version=0.16.0, branch=fix-staticcheck, revision=80a5712b97cd649b6bf2f9f60cf5c497043ef187)  source="node_exporter.go:82"
INFO[0000] Build context (go=go1.10.3, user=christian@wuechoo, date=20180729-18:47:59)  source="node_exporter.go:83"
INFO[0000] Enabled collectors:                           source="node_exporter.go:90"
INFO[0000]  - wifi                                       source="node_exporter.go:97"
INFO[0000] Listening on :9101                            source="node_exporter.go:111"
[...]
fatal error: runtime·unlock: lock count
fatal: morestack on g0

[SuperQ]

@hoffie Interesting, with the wifi collector on, do you get goroutine leaks like was reported in https://github.com/prometheus/node_exporter/issues/1008?

Wifi collector is the only one using netlink, which does use syscall.

/cc @mdlayher I don't think this is your fault, but thought you might want to be aware.

[hoffie]

@SuperQ: No goroutine leaks that I would have spotted (no increased memory usage or anything). go_goroutines metric seems to be in line with all my other node_exporter instances with other enabled collectors (8-14 routines) while being hammered with vegeta with 50qps.

Please also note that my results / suggested conclusion could still be bad luck -- i.e. it could still be that "node_exporter without any collectors" or "node_exporter with at least one collector" would crash as well. For me, they haven't. The only certain information is that "node_exporter with wifi collector crashes".
I should also say that my machine does not have wifi devices at all, so node_exporter's output is limited to (as expected):

node_scrape_collector_duration_seconds{collector="wifi"} 0.000785804
node_scrape_collector_success{collector="wifi"} 1

Edit: Just noticed that the netlink package also contains ASM code for setsockopt. I have no knowledge about ASM, but it seems to be possible to implement this using the more-standard maybe less-unsafe Syscall6 call. There also seem to be wrappers for that. From a quick glance it doesn't seem like this code path is hit at all though.

[mdlayher]

I have a couple of ideas I can try to investigate tomorrow, but in the mean time, disabling the WiFi collector seems reasonable.

[mdlayher]

At its core, the WiFi collector is more or less doing something like this on every scrape cycle:

package main

import (
    "fmt"
    "runtime"
    "sync"

    "github.com/mdlayher/genetlink"
)

func main() {
    workers := runtime.NumCPU()

    var wg sync.WaitGroup
    wg.Add(workers)

    for i := 0; i < workers; i++ {
        go func() {
            defer wg.Done()

            for {
                work()
            }
        }()
    }

    wg.Wait()
}

func work() {
    c, err := genetlink.Dial(nil)
    if err != nil {
        panicf("failed to dial: %v", err)
    }
    defer c.Close()

    if _, err := c.GetFamily("nl80211"); err != nil {
        panicf("failed to dial: %v", err)
    }
}

func panicf(format string, a ...interface{}) {
    panic(fmt.Sprintf(format, a...))
}

So I'm running this program to see if I can trigger a crash on my machine:

matt@nerr-2:~$ uname -a
Linux nerr-2 4.15.0-29-generic #31-Ubuntu SMP Tue Jul 17 15:39:52 UTC 2018 x86_64 x86_64 x86_64 GNU/Linux
matt@nerr-2:~$ go version
go version go1.10.3 linux/amd64

No luck so far though.

The only thing that comes to mind with that "lock count" message would be a behavior I am using in Go 1.10+: https://golang.org/doc/go1.10#runtime.

As far as I know, this is being done correctly: https://github.com/mdlayher/netlink/blob/master/conn_linux.go#L316-L328.

Hence, if there's an issue, I would think that my minimal program could reproduce it without the need to pull in node_exporter.

[mdlayher]

I've run my stress test on a beefy VM today and didn't run into any problems. At first I wondered if it was because I was on Go 1.10.3, but it appears above that 0.16.0 is also based on Go 1.10.3.

I'll try with node_exporter itself tomorrow.

[hoffie]

@mdlayher: Your example code runs stable for me, too. I also tried extracting more of node_exporter into a standalone binary and testing it in a similar way -- no crash so far.

I built a node_exporter with LockOSThread usage disabled (see diff below). It has been running stable for 150 minutes+.

In my tests, crashes happened faster when I set GOMAXPROCS=2. This may be just luck, though.

Overall, these results make me believe that it may be some runtime.LockOSThread interaction with go scheduling (go routines, channels).

Will try building Go with the relevant 1.10 change reverted and will test with unchanged node_exporter source code/deps again.

During today's crashes I've seen some more variations in error messages/stack traces. Sometimes the lock count one is not contained at all.

fatal error: runtime·unlock: lock count
fatal: morestack on g0

INFO[0000] Listening on :9101                            source="node_exporter.go:111"
 fatal error: schedule: holding locks

runtime stack:
runtime.throw(0xa0c651, 0x17)
    /usr/lib/go/src/runtime/panic.go:616 +0x81
runtime.schedule()
    /usr/lib/go/src/runtime/proc.go:2489 +0x351
runtime.goschedImpl(0xc420162300)
    /usr/lib/go/src/runtime/proc.go:2619 +0xf7
runtime.gosched_m(0xc420162300)
    /usr/lib/go/src/runtime/proc.go:2627 +0x36
runtime.mcall(0x1007f66f4ff8a4e)
    /usr/lib/go/src/runtime/asm_amd64.s:351 +0x5b

goroutine 1 [IO wait, 19 minutes]:
internal/poll.runtime_pollWait(0x7f66fd609f00, 0x72, 0x0)
    /usr/lib/go/src/runtime/netpoll.go:173 +0x57
internal/poll.(*pollDesc).wait(0xc4202e8518, 0x72, 0xc42019e000, 0x0, 0x0)
    /usr/lib/go/src/internal/poll/fd_poll_runtime.go:85 +0x9b
internal/poll.(*pollDesc).waitRead(0xc4202e8518, 0xffffffffffffff00, 0x0, 0x0)
    /usr/lib/go/src/internal/poll/fd_poll_runtime.go:90 +0x3d
internal/poll.(*FD).Accept(0xc4202e8500, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
    /usr/lib/go/src/internal/poll/fd_unix.go:372 +0x1a8
net.(*netFD).accept(0xc4202e8500, 0xc420282300, 0xc4205a1be0, 0x402ee8)
    /usr/lib/go/src/net/fd_unix.go:238 +0x42
net.(*TCPListener).accept(0xc420192370, 0xc4205a1c10, 0x401e47, 0xc420282300)
    /usr/lib/go/src/net/tcpsock_posix.go:136 +0x2e
net.(*TCPListener).AcceptTCP(0xc420192370, 0xc4205a1c58, 0xc4205a1c60, 0x18)
    /usr/lib/go/src/net/tcpsock.go:246 +0x49
net/http.tcpKeepAliveListener.Accept(0xc420192370, 0xa2cd30, 0xc420282280, 0xa78400, 0xc42030e990)
    /usr/lib/go/src/net/http/server.go:3216 +0x2f
net/http.(*Server).Serve(0xc420314270, 0xa780c0, 0xc420192370, 0x0, 0x0)
    /usr/lib/go/src/net/http/server.go:2770 +0x1a5
net/http.(*Server).ListenAndServe(0xc420314270, 0xc420314270, 0x2)
    /usr/lib/go/src/net/http/server.go:2711 +0xa9
net/http.ListenAndServe(0x7fffbd1df4a5, 0x5, 0x0, 0x0, 0x1, 0xc42030a7e0)
    /usr/lib/go/src/net/http/server.go:2969 +0x7a
main.main()
    /home/christian/go/src/github.com/prometheus/node_exporter/node_exporter.go:112 +0x9cf

goroutine 38 [IO wait, 12 minutes]:
internal/poll.runtime_pollWait(0x7f66fd609e30, 0x72, 0xc4205a3868)
    /usr/lib/go/src/runtime/netpoll.go:173 +0x57
internal/poll.(*pollDesc).wait(0xc4202e8598, 0x72, 0xffffffffffffff00, 0xa73f40, 0xf2c9a8)
    /usr/lib/go/src/internal/poll/fd_poll_runtime.go:85 +0x9b
internal/poll.(*pollDesc).waitRead(0xc4202e8598, 0xc420320000, 0x1000, 0x1000)
    /usr/lib/go/src/internal/poll/fd_poll_runtime.go:90 +0x3d
internal/poll.(*FD).Read(0xc4202e8580, 0xc420320000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
    /usr/lib/go/src/internal/poll/fd_unix.go:157 +0x17d
net.(*netFD).Read(0xc4202e8580, 0xc420320000, 0x1000, 0x1000, 0xc4205a3978, 0x66a47a, 0xc42030ea88)
    /usr/lib/go/src/net/fd_unix.go:202 +0x4f
net.(*conn).Read(0xc420192380, 0xc420320000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
    /usr/lib/go/src/net/net.go:176 +0x6a
net/http.(*connReader).Read(0xc42030ea80, 0xc420320000, 0x1000, 0x1000, 0x2, 0x0, 0x0)
    /usr/lib/go/src/net/http/server.go:764 +0xf8
bufio.(*Reader).fill(0xc4202286c0)
    /usr/lib/go/src/bufio/bufio.go:100 +0x11e
bufio.(*Reader).ReadSlice(0xc4202286c0, 0xc42017640a, 0xc4205a3ad8, 0x411d66, 0x7f66fd610458, 0x3, 0xc4205a3ac0)
    /usr/lib/go/src/bufio/bufio.go:341 +0x2c
bufio.(*Reader).ReadLine(0xc4202286c0, 0xc4202c2300, 0x100, 0xf8, 0x9eb2c0, 0xa2cb01, 0x100c4205a3b58)
    /usr/lib/go/src/bufio/bufio.go:370 +0x34
net/textproto.(*Reader).readLineSlice(0xc42036e240, 0xc4205b4c00, 0xc4205a3ba8, 0x412a48, 0x100, 0x9eb2c0)
    /usr/lib/go/src/net/textproto/reader.go:55 +0x70
net/textproto.(*Reader).ReadLine(0xc42036e240, 0xc4202c2300, 0x0, 0x0, 0x72)
    /usr/lib/go/src/net/textproto/reader.go:36 +0x2b
net/http.readRequest(0xc4202286c0, 0x0, 0xc4202c2300, 0x0, 0x0)
    /usr/lib/go/src/net/http/request.go:929 +0x8c
net/http.(*conn).readRequest(0xc4201abf40, 0xa78340, 0xc42019eb00, 0x0, 0x0, 0x0)
    /usr/lib/go/src/net/http/server.go:944 +0x16f
net/http.(*conn).serve(0xc4201abf40, 0xa78340, 0xc42019eb00)
    /usr/lib/go/src/net/http/server.go:1768 +0x4dc
created by net/http.(*Server).Serve
    /usr/lib/go/src/net/http/server.go:2795 +0x27b

goroutine 50907 [IO wait]:
internal/poll.runtime_pollWait(0x7f66fd609d60, 0x72, 0xc420390868)
    /usr/lib/go/src/runtime/netpoll.go:173 +0x57
internal/poll.(*pollDesc).wait(0xc420262118, 0x72, 0xffffffffffffff00, 0xa73f40, 0xf2c9a8)
    /usr/lib/go/src/internal/poll/fd_poll_runtime.go:85 +0x9b
internal/poll.(*pollDesc).waitRead(0xc420262118, 0xc4201ef000, 0x1000, 0x1000)
    /usr/lib/go/src/internal/poll/fd_poll_runtime.go:90 +0x3d
internal/poll.(*FD).Read(0xc420262100, 0xc4201ef000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
    /usr/lib/go/src/internal/poll/fd_unix.go:157 +0x17d
net.(*netFD).Read(0xc420262100, 0xc4201ef000, 0x1000, 0x1000, 0xc420390978, 0x66a47a, 0xc420266a88)
    /usr/lib/go/src/net/fd_unix.go:202 +0x4f
net.(*conn).Read(0xc4201925c8, 0xc4201ef000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
    /usr/lib/go/src/net/net.go:176 +0x6a
net/http.(*connReader).Read(0xc420266a80, 0xc4201ef000, 0x1000, 0x1000, 0x1, 0x17f66fd6736c8, 0x3)
    /usr/lib/go/src/net/http/server.go:764 +0xf8
bufio.(*Reader).fill(0xc4204694a0)
    /usr/lib/go/src/bufio/bufio.go:100 +0x11e
bufio.(*Reader).ReadSlice(0xc4204694a0, 0xc420390a0a, 0xc420390ad8, 0x411d66, 0x7f66fd60e908, 0x3, 0x7f66fd6736c8)
    /usr/lib/go/src/bufio/bufio.go:341 +0x2c
bufio.(*Reader).ReadLine(0xc4204694a0, 0xc420256300, 0x100, 0xf8, 0x9eb2c0, 0x1, 0x100c42012b000)
    /usr/lib/go/src/bufio/bufio.go:370 +0x34
net/textproto.(*Reader).readLineSlice(0xc4201be030, 0xc420341501, 0xc420390ba8, 0x412a48, 0x100, 0x9eb2c0)
    /usr/lib/go/src/net/textproto/reader.go:55 +0x70
net/textproto.(*Reader).ReadLine(0xc4201be030, 0xc420256300, 0x0, 0x0, 0x72)
    /usr/lib/go/src/net/textproto/reader.go:36 +0x2b
net/http.readRequest(0xc4204694a0, 0x0, 0xc420256300, 0x0, 0x0)
    /usr/lib/go/src/net/http/request.go:929 +0x8c
net/http.(*conn).readRequest(0xc420282280, 0xa78340, 0xc4205de2c0, 0x0, 0x0, 0x0)
    /usr/lib/go/src/net/http/server.go:944 +0x16f
net/http.(*conn).serve(0xc420282280, 0xa78340, 0xc4205de2c0)
    /usr/lib/go/src/net/http/server.go:1768 +0x4dc
created by net/http.(*Server).Serve
    /usr/lib/go/src/net/http/server.go:2795 +0x27b

Disabling LockOSThread for debugging (don't think it's a valid fix as it seems to break correctness guarantees in netlink API usage):

diff --git a/vendor/github.com/mdlayher/wifi/client_linux.go b/vendor/github.com/mdlayher/wifi/client_linux.go
index 4edb9bc..e9c93c6 100644
--- a/vendor/github.com/mdlayher/wifi/client_linux.go
+++ b/vendor/github.com/mdlayher/wifi/client_linux.go
@@ -36,7 +36,10 @@ type client struct {
 // newClient dials a generic netlink connection and verifies that nl80211
 // is available for use by this package.
 func newClient() (*client, error) {
-       c, err := genetlink.Dial(nil)
+       cfg := &netlink.Config{
+               NoLockThread: true,
+       }
+       c, err := genetlink.Dial(cfg)
        if err != nil {
                return nil, err
        }

[mdlayher]

Thanks for all the debugging work you've done so far. I was curious about NoLockThread as well but didn't give it a try yet. It does seem like it's possible that we're causing some unexpected state in the runtime which could cause a crash.

[hoffie]

Just found a very similar looking Go issue (which is about Plan 9): https://github.com/golang/go/issues/22227

I have run the following tests:

1. node_exporter (vanilla) built with go1.10.3 (vanilla, built from source). First crash after 5 minutes. Second crash after 3 minutes. Even more afterwards.
2. node_exporter with the below diff built with go1.10.3 (vanilla, built from source). Ran stable for an hour.
3. node_exporter (vanilla) built with go at revision 555c16d8cbd8372c1f57beb059a23b56bf1e909f (last commit before the LockOSThread changes). Ran stable for an hour.

(1) is supposed to confirm the problem (again)
(2) could be an attempt regarding a workaround from the node_exporter (or rather mdlayher/netlink) perspective
(3) should help in tracking down the relevant go change.

@mdlayher: Can you provide some comments around (2)? As I understand your netlink code, you have to guarentee that the netlink calls from one (node_exporter) request always originate from the OS thread, right? It would be safe to return this thread into the normal Go thread pool after netlink usage, right? Is the position I suggest in the diff the proper place to do that?

Next steps:

• Confirm with @mdlayher whether the workaround could/should be implemented. This should be given some more testing regarding stability and correctness, though.
• Bisect the actual breaking go change (will do that in the coming days)
• Provide an update in the upstream issue https://github.com/golang/go/issues/25128 (will do that in a moment)
• Condense node_exporter + wifi collector to some very minimal reproducer which can be handed to the Go developers (the other way round -- extracting the netlink part -- did not work as mentioned above).

diff --git a/vendor/github.com/mdlayher/netlink/conn_linux.go b/vendor/github.com/mdlayher/netlink/conn_linux.go
index 2c9e38a..39363ca 100644
--- a/vendor/github.com/mdlayher/netlink/conn_linux.go
+++ b/vendor/github.com/mdlayher/netlink/conn_linux.go
@@ -251,6 +251,7 @@ func newSysSocket(lockThread bool) *sysSocket {
                        // the goroutine exits starting in Go 1.10:
                        // https://go-review.googlesource.com/c/go/+/46038.
                        runtime.LockOSThread()
+                       defer runtime.UnlockOSThread()
                }

                defer wg.Done()

[mdlayher]

That patch seems reasonable to me because I'm not mucking with network namespaces or anything at the moment. If it provides stability, that's excellent, but I think there may still be something wrong on the runtime end if the documented Go 1.10+ behavior causes a fatal runtime error after some time.

[hoffie]

Alright. Yes, I also think this is a Go bug, but it might make sense to provide some intermediate workaround until the bug is properly solved.

Bisecting Go lead to https://github.com/golang/go/commit/4f34a5291317fe959074fb40b85d9be242b8a2fc as the problematic change. Will see where this leads us.

[mdlayher]

A note from our conversation on that thread:

Keep in mind that just because bisect points at a commit does not mean the commit is bad. It could be a perfectly correct commit that is just exposing an issue that already existed. I could certainly see how thrashing OS threads more often by forcing termination when a locked goroutine exits could expose other issues (e.g. memory corruption) elsewhere.

I am curious if we have a Cgo bug somewhere in one of the collectors and the interaction with the WiFi collector is causing it all to explode.

[marcan]

The fact that it crashes with just the wifi collector suggests this isn't an issue with another collector. Does the node_exporter core rely on Cgo for anything?

[daenney]

Kind of an aside here, but given the node exporter seems to primarly target backend systems, should we consider disabling the WiFi collector by default, at least until it the issue is resolved?

[SuperQ]

While I would like to turn it off, I think it would make too many eyes stop looking into it and it would never get fixed.

I'll consider it.

[daenney]

Reading up on golang/go#25128 it seems @mdlayher has applied a fix to to netlink in the form of https://github.com/mdlayher/netlink/commit/3d8cc9af89458b8b6a9ce675d4dfa50a724e9025 that causes the error to disappear.

Even though the WiFi collector is now disabled by default it seems worthwhile to upgrade to at least that commit so that those that do need the WiFi collector and enable it can have a more stable experience.

[discordianfish]

@daenney Now that we isolated this issue a bit further, maybe it makes sense to update the title and description of this issue since it seems like it might take a while to get this fixed upstream and released.

[daenney]

@discordianfish Mmm, indeed. I updated it to "when WiFi collector is enabled" only to realise that this is no longer the case as with the changes @mdlayher has done the issue appears resolved.

Since there is an upstream issue about the particulars of this bug, should we consider closing this? Is there anything left to do from a Prometheus/node_exporter side of things?

[discordianfish]

@daenney Agree, probably is fine to close this.