Couldn't get system state: Unknown property #291

drewhemm · 2016-08-25T12:50:03Z

This is appearing frequently in /var/log/messages:

Aug 25 12:46:18 bamboo node_exporter: time="2016-08-25T12:46:18Z" level=error msg="ERROR: systemd collector failed after 0.009243s: couldn't get system state: Unknown property" source="node_exporter.go:91"

Not sure if I should care and/or how to silence it.

drewhemm · 2016-08-25T13:19:04Z

After some initial investigation, it appears that the machines that are not complaining are running a higher version of systemd - 219 vs 208. The higher version outputs systemctl status differently, and the output includes a property 'State'. The question is, is the difference in output solely caused the difference in version (and if so, is the systemd collector only expected to work on machines with a certain version of systemd?) or is it caused by something else?

Working machine:

[ahemming@cms-####### ~]$ systemctl status
● cms-#######
    State: running
     Jobs: 0 queued
   Failed: 0 units
    Since: Wed 2016-08-24 10:36:59 UTC; 1 day 2h ago
...

Machine that complains:

[ahemming@bamboo ~]$ systemctl status
proc-sys-fs-binfmt_misc.automount -> '/org/freedesktop/systemd1/unit/proc_2dsys_2dfs_2dbinfmt_5fmisc_2eautomount'
proc-sys-fs-binfmt_misc.automount - Arbitrary Executable File Formats File System Automount Point
   Loaded: loaded (/usr/lib/systemd/system/proc-sys-fs-binfmt_misc.automount; static)
   Active: active (running) since Thu 2016-04-07 16:13:58 UTC; 4 months 18 days ago
    Where: /proc/sys/fs/binfmt_misc
     Docs: https://www.kernel.org/doc/Documentation/binfmt_misc.txt
           http://www.freedesktop.org/wiki/Software/systemd/APIFileSystems
...

discordianfish · 2017-01-04T12:32:30Z

Which version of the node-exporter are you using?
The collector is not parsing systemctl output but using go-systemd/dbus. The error is returned by conn.GetManagerProperty("SystemState") after successfully connecting to dbus. Maybe that propery doesn't exist in 208?

Can you run this and see what it's reporting?

package main

import (
	"log"

	"github.com/coreos/go-systemd/dbus"
)

func main() {
	conn, err := dbus.New()
	if err != nil {
		log.Fatal(err)
	}
	state, err := conn.GetManagerProperty("SystemState")
	if err != nil {
		log.Fatal(err)
	}
	log.Printf("state: %v", state)
}

If you can't compile it yourself, here is a linux/amd64 binary: https://drive.google.com/file/d/0B5Dqy-L1tbQjeU1jeVZXX3NlT3c/view?usp=sharing

@fabxc You probably have good systemd connections: Any ideas why this might be missing? Maybe it was introduced after 208 but haven't found anything in the changelog.

pengsrc · 2017-05-01T09:11:35Z

@discordianfish Hi, I got Unknown property when executing this code, this should be a bug in go-systemd.

Here's the example of my crond service status.

# systemctl status crond.service
crond.service - Command Scheduler
   Loaded: loaded (/usr/lib/systemd/system/crond.service; enabled)
   Active: active (running) since Mon 2016-08-29 16:14:16 CST; 8 months 1 days ago
 Main PID: 434 (crond)
   CGroup: /system.slice/crond.service
           └─434 /usr/sbin/crond -n

Warning: Journal has been rotated since unit was started. Log output is incomplete or unavailable.

May be the go-systemd package can not parse a service if it has been running for a long time and it's log is not available.

SuperQ · 2018-02-22T19:33:09Z

Is this still an issue with the latest release?

beylisstan · 2018-05-06T09:53:32Z

Same issue here.

Host operating system: output of `uname -a`

Linux xx-xxx-xxxxxx-0 3.12.62-60.62-default #1 SMP Thu Aug 4 09:06:08 UTC 2016 (b0e5a26) x86_64 x86_64 x86_64 GNU/Linux

node_exporter version: output of `node_exporter --version`

node_exporter, version 0.15.2 (branch: HEAD, revision: 98bc649)
build user: root@d5c4792c921f
build date: 20171205-14:50:53
go version: go1.9.2

node_exporter command line flags

./node_exporter --collector.systemd

Are you running node_exporter in Docker?

No

What did you do that produced an error?

./node_exporter --collector.systemd &

What did you expect to see?

Running exporter without errors

What did you see instead?

INFO[0000] INFO[0000] INFO[0000] INFO[0000] Enabled collectors: INFO[0000] - stat INFO[0000] - entropy INFO[0000] - cpu INFO[0000] - loadavg INFO[0000] - netstat INFO[0000] - uname INFO[0000] - arp INFO[0000] - conntrack INFO[0000] - zfs INFO[0000] - filefd INFO[0000] - edac INFO[0000] - filesystem INFO[0000] - infiniband INFO[0000] - diskstats INFO[0000] - meminfo INFO[0000] - bcache INFO[0000] - hwmon INFO[0000] - sockstat INFO[0000] - netdev INFO[0000] - mdadm INFO[0000] - time INFO[0000] - vmstat INFO[0000] - ipvs INFO[0000] - wifi INFO[0000] - systemd INFO[0000] - timex INFO[0000] - textfile INFO[0000] - xfs INFO[0000] Listening on :9100 ERRO[0003] ERRO[0004] Starting node_exporter (version=0.15.2, branch=HEAD, revision=98bc64930d34878b84a0f87dfe6e1a6da61e532d) source="node_exporter.go:43"
Build context (go=go1.9.2, user=root@d5c4792c921f, date=20171205-14:50:53) source="node_exporter.go:44"
No directory specified, see --collector.textfile.directory source="textfile.go:57"
source="node_exporter.go:50"
source="node_exporter.go:52"
source="node_exporter.go:52"
source="node_exporter.go:52"
source="node_exporter.go:52"
source="node_exporter.go:52"
source="node_exporter.go:52"
source="node_exporter.go:52"
source="node_exporter.go:52"
source="node_exporter.go:52"
source="node_exporter.go:52"
source="node_exporter.go:52"
source="node_exporter.go:52"
source="node_exporter.go:52"
source="node_exporter.go:52"
source="node_exporter.go:52"
source="node_exporter.go:52"
source="node_exporter.go:52"
source="node_exporter.go:52"
source="node_exporter.go:52"
source="node_exporter.go:52"
source="node_exporter.go:52"
source="node_exporter.go:52"
source="node_exporter.go:52"
source="node_exporter.go:52"
source="node_exporter.go:52"
source="node_exporter.go:52"
source="node_exporter.go:52"
source="node_exporter.go:52"
source="node_exporter.go:76"
ERROR: systemd collector failed after 0.018945s: couldn't get system state: Unknown property or interface. source="collector.go:123"
ERROR: systemd collector failed after 0.020527s: couldn't get system state: Unknown property or interface. source="collector.go:123"

discordianfish · 2018-08-18T09:30:33Z

@beylisstan Can you try if this still happens with 0.16.0?

discordianfish · 2018-11-05T16:10:52Z

I believe this has been fixed in the meanwhile. If not, please re-open this issue.

tiagoapimenta · 2019-06-07T21:15:01Z

Could you please reopen this bug?

Environment:

uname -a
Linux xxxx 3.10.0-229.el7.x86_64 #1 SMP Thu Jan 29 18:37:38 EST 2015 x86_64 x86_64 x86_64 GNU/Linux

cat /etc/system-release
Red Hat Enterprise Linux Server release 7.1 (Maipo)

node-exporter --version
node_exporter, version 0.18.1 (branch: HEAD, revision: 3db77732e925c08f675d7404a8c46466b2ece83e)
  build user:       root@b50852a1acba
  build date:       20190604-16:41:18
  go version:       go1.12.5

Here is some evidence:

sudo node-exporter --log.level=debug --web.listen-address=":9101" --collector.systemd --collector.textfile.directory=/var/lib/node-porter
...
DEBU[0004] Ignoring unit: dev-disk-by\x2duuid-f6aafd9c\x2d1d30\x2d4d12\x2d9e95\x2d66a23870ac09.device  source="systemd_linux.go:421"
DEBU[0004] Ignoring unit: dev-mapper-vg_app\x2dlv_gemsys.device  source="systemd_linux.go:421"
DEBU[0004] Adding unit: polkit.service                   source="systemd_linux.go:418"
DEBU[0004] Ignoring unit: user-1000.slice                source="systemd_linux.go:421"
DEBU[0004] Ignoring unit: user-0.slice                   source="systemd_linux.go:421"
DEBU[0004] Ignoring unit: session-35.scope               source="systemd_linux.go:421"
DEBU[0004] systemd filterUnits took 0.006092             source="systemd_linux.go:149"
DEBU[0004] systemd collectSystemState took 0.001317      source="systemd_linux.go:200"
DEBU[0004] couldn't get unit 'systemd-readahead-done.timer' LastTriggerUSec: Unknown property  source="systemd_linux.go:342"
DEBU[0004] couldn't get unit 'systemd-tmpfiles-clean.timer' LastTriggerUSec: Unknown property  source="systemd_linux.go:342"
DEBU[0004] systemd collectTimers took 0.004424           source="systemd_linux.go:187"
DEBU[0004] systemd collectSockets took 0.035076          source="systemd_linux.go:195"
DEBU[0004] systemd collectUnitStatusMetrics took 0.088215  source="systemd_linux.go:159"
ERRO[0004] ERROR: systemd collector failed after 0.110036s: couldn't get system state: Unknown property  source="collector.go:132"

sudo systemctl status systemd-readahead-done.timer systemd-tmpfiles-clean.timer
systemd-readahead-done.timer - Stop Read-Ahead Data Collection 10s After Completed Startup
   Loaded: loaded (/usr/lib/systemd/system/systemd-readahead-done.timer; static)
   Active: inactive (dead)
           start condition failed at Sex 2019-06-07 15:00:34 -03; 3h 8min ago
           ConditionVirtualization=no was not met
     Docs: man:systemd-readahead-replay.service(8)

systemd-tmpfiles-clean.timer - Daily Cleanup of Temporary Directories
   Loaded: loaded (/usr/lib/systemd/system/systemd-tmpfiles-clean.timer; static)
   Active: active (waiting) since Sex 2019-06-07 14:58:47 -03; 3h 10min ago
     Docs: man:tmpfiles.d(5)
           man:systemd-tmpfiles(8)

SuperQ · 2019-06-10T11:36:35Z

It looks like this is coming from collectSystemState().

cc: @pgier

pgier · 2019-07-02T22:51:19Z

@tiagoapimenta Can you verify that #1413 fixes this for you?
Also, what do you see for systemctl --version?

tiagoapimenta · 2019-07-03T13:50:30Z

Here it is:

$ systemctl --version
systemd 208
+PAM +LIBWRAP +AUDIT +SELINUX +IMA +SYSVINIT +LIBCRYPTSETUP +GCRYPT +ACL +XZ

Will it still be able to expose systemd metrics?

tiagoapimenta · 2019-07-03T14:26:50Z

I'm unable to build your code, here the steps I tried:

mkdir /tmp/output
docker run -it --rm -v /tmp/output:/go/bin docker.io/golang:alpine
# apk add --no-cache git make
# mkdir -p /go/src/github.com/prometheus
# ln -s ../pgier/node_exporter /go/src/github.com/prometheus/node_exporter
# export CGO_ENABLED=0
# go get github.com/pgier/node_exporter
error here
# cd /go/src/github.com/pgier/node_exporter
# go build -a -ldflags='-s -w -extldflags -static' -o /go/bin/node_exporter .
same error
# make
same error again

the error is the following:

./node_exporter.go:46:25: cannot use nc (type *collector.nodeCollector) as type "github.com/pgier/node_exporter/vendor/github.com/prometheus/client_golang/prometheus".Collector in argument to registry.Register:
        *collector.nodeCollector does not implement "github.com/pgier/node_exporter/vendor/github.com/prometheus/client_golang/prometheus".Collector (wrong type for Collect method)
                have Collect(chan<- "github.com/prometheus/node_exporter/vendor/github.com/prometheus/client_golang/prometheus".Metric)
                want Collect(chan<- "github.com/pgier/node_exporter/vendor/github.com/prometheus/client_golang/prometheus".Metric)
make: *** [Makefile:113: vet] Error 2

pgier · 2019-07-03T15:49:51Z

Will it still be able to expose systemd metrics?

Yes, only the system_running metric will not be available since this comes from the SystemState property which is not available before version 212.

The build error is because the package name is still github.com/prometheus/node_exporter even though it's in my repo. So one way to fix would be to just change the pgier directory to prometheus.

Edit: Another easy way to test is to download the appropriate binary from the CI build https://circleci.com/gh/prometheus/node_exporter/6241#artifacts/containers/0

tiagoapimenta · 2019-07-03T16:40:17Z

Well, the couldn't get unit systemd-tmpfiles-clean.timer message was gone, but it still log an error about systemd-readahead-done.timer, I don't know if it is harmless:

sudo /tmp/node_exporter --log.level=debug --web.listen-address=":9101" --collector.systemd --collector.textfile.directory=/var/lib/node-porter
...
time="2019-07-03T13:37:43-03:00" level=debug msg="Ignoring mount point: /dev/mqueue" source="filesystem_linux.go:42"
time="2019-07-03T13:37:43-03:00" level=debug msg="Ignoring mount point: /sys/kernel/debug" source="filesystem_linux.go:42"
time="2019-07-03T13:37:43-03:00" level=debug msg="Ignoring mount point: /dev/hugepages" source="filesystem_linux.go:42"
time="2019-07-03T13:37:43-03:00" level=debug msg="OK: filesystem collector succeeded after 0.003190s." source="collector.go:139"
time="2019-07-03T13:37:43-03:00" level=debug msg="CPU /sys/bus/cpu/devices/cpu0 is missing cpufreq" source="cpu_linux.go:115"
time="2019-07-03T13:37:43-03:00" level=debug msg="CPU /sys/bus/cpu/devices/cpu0 is missing thermal_throttle" source="cpu_linux.go:136"
time="2019-07-03T13:37:43-03:00" level=debug msg="CPU /sys/bus/cpu/devices/cpu1 is missing cpufreq" source="cpu_linux.go:115"
time="2019-07-03T13:37:43-03:00" level=debug msg="CPU /sys/bus/cpu/devices/cpu1 is missing thermal_throttle" source="cpu_linux.go:136"
time="2019-07-03T13:37:43-03:00" level=debug msg="CPU /sys/bus/cpu/devices/cpu2 is missing cpufreq" source="cpu_linux.go:115"
time="2019-07-03T13:37:43-03:00" level=debug msg="CPU /sys/bus/cpu/devices/cpu2 is missing thermal_throttle" source="cpu_linux.go:136"
time="2019-07-03T13:37:43-03:00" level=debug msg="CPU /sys/bus/cpu/devices/cpu3 is missing cpufreq" source="cpu_linux.go:115"
time="2019-07-03T13:37:43-03:00" level=debug msg="CPU /sys/bus/cpu/devices/cpu3 is missing thermal_throttle" source="cpu_linux.go:136"
time="2019-07-03T13:37:43-03:00" level=debug msg="CPU /sys/bus/cpu/devices/cpu4 is missing cpufreq" source="cpu_linux.go:115"
time="2019-07-03T13:37:43-03:00" level=debug msg="CPU /sys/bus/cpu/devices/cpu4 is missing thermal_throttle" source="cpu_linux.go:136"
time="2019-07-03T13:37:43-03:00" level=debug msg="CPU /sys/bus/cpu/devices/cpu5 is missing cpufreq" source="cpu_linux.go:115"
time="2019-07-03T13:37:43-03:00" level=debug msg="CPU /sys/bus/cpu/devices/cpu5 is missing thermal_throttle" source="cpu_linux.go:136"
time="2019-07-03T13:37:43-03:00" level=debug msg="CPU /sys/bus/cpu/devices/cpu6 is missing cpufreq" source="cpu_linux.go:115"
time="2019-07-03T13:37:43-03:00" level=debug msg="CPU /sys/bus/cpu/devices/cpu6 is missing thermal_throttle" source="cpu_linux.go:136"
time="2019-07-03T13:37:43-03:00" level=debug msg="CPU /sys/bus/cpu/devices/cpu7 is missing cpufreq" source="cpu_linux.go:115"
time="2019-07-03T13:37:43-03:00" level=debug msg="CPU /sys/bus/cpu/devices/cpu7 is missing thermal_throttle" source="cpu_linux.go:136"
time="2019-07-03T13:37:43-03:00" level=debug msg="Node /sys/bus/node/devices/node0 CPU 0 is missing package_throttle" source="cpu_linux.go:185"
time="2019-07-03T13:37:43-03:00" level=debug msg="OK: cpu collector succeeded after 0.004878s." source="collector.go:139"
time="2019-07-03T13:37:43-03:00" level=error msg="ERROR: systemd collector failed after 0.015240s: couldn't get units: couldn't get unit 'systemd-readahead-done.timer' LastTriggerUSec: Unknown property" source="collector.go:136"

The unit systemd-readahead-done.timer is still inactive.

pgier · 2019-07-03T20:49:20Z

Thanks for testing, looks like the LastTriggerUSec property was also added in version 212 of systemd:
systemd/systemd@dedabea
I've updated the PR to also skip the timer metrics for older systemd versions.

tiagoapimenta · 2019-07-04T11:09:47Z

QA done, however for some strange reason go get github.com/pgier/node_exporter lead me to other version, I had to checkout to 14d9b05e in order to make it work, I don't know why, but after that all gone fine...

Evidence:

time="2019-07-04T08:05:32-03:00" level=debug msg="Ignoring unit: dev-rhel-tmp.device" source="systemd_linux.go:442"
time="2019-07-04T08:05:32-03:00" level=debug msg="Ignoring unit: sys-devices-virtual-block-dm\\x2d4.device" source="systemd_linux.go:442"
time="2019-07-04T08:05:32-03:00" level=debug msg="Ignoring unit: dev-dm\\x2d4.device" source="systemd_linux.go:442"
time="2019-07-04T08:05:32-03:00" level=debug msg="Ignoring unit: dev-disk-by\\x2did-dm\\x2dname\\x2drhel\\x2dvar.device" source="systemd_linux.go:442"
time="2019-07-04T08:05:32-03:00" level=debug msg="Ignoring unit: dev-disk-by\\x2did-dm\\x2duuid\\x2dLVM\\x2dhafhyKET4R9jgiC1tuqOmBC4hcAcx5yMhafDS0urtdN5mkp3MoOe2hz8wKpWpwKm.device" source="systemd_linux.go:442"
time="2019-07-04T08:05:32-03:00" level=debug msg="Ignoring unit: dev-disk-by\\x2duuid-97cf5930\\x2d3eb4\\x2d41da\\x2d9548\\x2d0542eeb79dbc.device" source="systemd_linux.go:442"
time="2019-07-04T08:05:32-03:00" level=debug msg="Ignoring unit: dev-rhel-var.device" source="systemd_linux.go:442"
time="2019-07-04T08:05:32-03:00" level=debug msg="Adding unit: polkit.service" source="systemd_linux.go:439"
time="2019-07-04T08:05:32-03:00" level=debug msg="Ignoring unit: user-1000.slice" source="systemd_linux.go:442"
time="2019-07-04T08:05:32-03:00" level=debug msg="Ignoring unit: user-0.slice" source="systemd_linux.go:442"
time="2019-07-04T08:05:32-03:00" level=debug msg="Ignoring unit: session-8990.scope" source="systemd_linux.go:442"
time="2019-07-04T08:05:32-03:00" level=debug msg="systemd filterUnits took 0.006743" source="systemd_linux.go:165"
time="2019-07-04T08:05:32-03:00" level=debug msg="systemd collectSockets took 0.035842" source="systemd_linux.go:213"
time="2019-07-04T08:05:32-03:00" level=debug msg="systemd collectUnitStatusMetrics took 0.081249" source="systemd_linux.go:175"
time="2019-07-04T08:05:32-03:00" level=debug msg="OK: systemd collector succeeded after 0.104952s." source="collector.go:135

The dbus property 'SystemState' and the timer property 'LastTriggerUSec' were added in version 212 of systemd. Check that the version of systemd is higher than 212 before attempting to query these properties systemd/systemd@f755e3b systemd/systemd@dedabea Resolves issue prometheus#291 Signed-off-by: Paul Gier <[email protected]>

The dbus property 'SystemState' and the timer property 'LastTriggerUSec' were added in version 212 of systemd. Check that the version of systemd is higher than 212 before attempting to query these properties systemd/systemd@f755e3b systemd/systemd@dedabea Resolves issue #291 Signed-off-by: Paul Gier <[email protected]>

discordianfish · 2021-03-30T15:26:31Z

I'll consider this to be fixed. Lemme know if someone still runs into this issue.

cokepizza · 2021-12-14T07:36:25Z

The same issue occurred in our vm, and the version of node_exporter is also relatively new.
There's a warning like this "Warning: Journal has been rotated since unit was started. Log output is incomplete or unavailable."

node_exporter, version 1.2.0 (branch: HEAD, revision: 1296894)
build user: root@6b17174de526
build date: 20210715-16:35:54
go version: go1.16.6
platform: linux/amd64

discordianfish · 2021-12-15T09:37:01Z

@cokepizza Do you just get the "Warning: Journal has been rotated since unit was started. Log output is incomplete or unavailable." warning or also "ERROR: systemd collector failed after 0.009243s: couldn't get system state: Unknown property"?

The dbus property 'SystemState' and the timer property 'LastTriggerUSec' were added in version 212 of systemd. Check that the version of systemd is higher than 212 before attempting to query these properties systemd/systemd@f755e3b systemd/systemd@dedabea Resolves issue prometheus#291 Signed-off-by: Paul Gier <[email protected]>

discordianfish added bug require/feedback labels Jan 4, 2017

SuperQ added the pending/close label Feb 22, 2018

discordianfish closed this as completed Nov 5, 2018

SuperQ reopened this Jun 10, 2019

pgier mentioned this issue Jul 2, 2019

systemd: check version for availability of SystemState #1413

Merged

discordianfish closed this as completed Mar 30, 2021

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Couldn't get system state: Unknown property #291

Couldn't get system state: Unknown property #291

drewhemm commented Aug 25, 2016

drewhemm commented Aug 25, 2016

discordianfish commented Jan 4, 2017

pengsrc commented May 1, 2017

SuperQ commented Feb 22, 2018

beylisstan commented May 6, 2018 •

edited

Loading

discordianfish commented Aug 18, 2018

discordianfish commented Nov 5, 2018

tiagoapimenta commented Jun 7, 2019

SuperQ commented Jun 10, 2019

pgier commented Jul 2, 2019 •

edited

Loading

tiagoapimenta commented Jul 3, 2019 •

edited

Loading

tiagoapimenta commented Jul 3, 2019 •

edited

Loading

pgier commented Jul 3, 2019 •

edited

Loading

tiagoapimenta commented Jul 3, 2019 •

edited

Loading

pgier commented Jul 3, 2019

tiagoapimenta commented Jul 4, 2019

discordianfish commented Mar 30, 2021

cokepizza commented Dec 14, 2021

discordianfish commented Dec 15, 2021

Couldn't get system state: Unknown property #291

Couldn't get system state: Unknown property #291

Comments

drewhemm commented Aug 25, 2016

drewhemm commented Aug 25, 2016

discordianfish commented Jan 4, 2017

pengsrc commented May 1, 2017

SuperQ commented Feb 22, 2018

beylisstan commented May 6, 2018 • edited Loading

Host operating system: output of uname -a

node_exporter version: output of node_exporter --version

node_exporter command line flags

Are you running node_exporter in Docker?

What did you do that produced an error?

What did you expect to see?

What did you see instead?

discordianfish commented Aug 18, 2018

discordianfish commented Nov 5, 2018

tiagoapimenta commented Jun 7, 2019

SuperQ commented Jun 10, 2019

pgier commented Jul 2, 2019 • edited Loading

tiagoapimenta commented Jul 3, 2019 • edited Loading

tiagoapimenta commented Jul 3, 2019 • edited Loading

pgier commented Jul 3, 2019 • edited Loading

tiagoapimenta commented Jul 3, 2019 • edited Loading

pgier commented Jul 3, 2019

tiagoapimenta commented Jul 4, 2019

discordianfish commented Mar 30, 2021

cokepizza commented Dec 14, 2021

discordianfish commented Dec 15, 2021

beylisstan commented May 6, 2018 •

edited

Loading

Host operating system: output of `uname -a`

node_exporter version: output of `node_exporter --version`

pgier commented Jul 2, 2019 •

edited

Loading

tiagoapimenta commented Jul 3, 2019 •

edited

Loading

tiagoapimenta commented Jul 3, 2019 •

edited

Loading

pgier commented Jul 3, 2019 •

edited

Loading

tiagoapimenta commented Jul 3, 2019 •

edited

Loading