Textfile Log Error Message Noise - v0.15.0

[michaeljoy]

Host operating system: output of uname -a

4.4.0-1035-aws #44-Ubuntu SMP Tue Sep 12 17:27:47 UTC 2017 x86_64 x86_64 x86_64 GNU/Linux

node_exporter version: output of node_exporter --version

version=0.15.0, branch=master, revision=f3a70226025bf81e55eaf9d7386f9f7b3a267694

node_exporter command line flags

--path.procfs='/host/proc' --path.sysfs='/host/sys' --collector.filesystem.ignored-mount-points='^/(sys|proc|dev|host|etc)($|/)' --collector.filesystem.ignored-fs-types='^(aufs|cgroup|devpts|mqueue|nsfs|sysfs|proc|tmpfs|shm|none)$' --web.listen-address=10.something:9100

Are you running node_exporter in Docker?

Docker version 17.07.0-ce, build 8784753

/usr/bin/docker run \
        --net host -m 0b -v /proc:/host/proc:ro \
 -v /sys:/host/sys:ro \
 -v /:/rootfs:ro,rslave \
 -v /etc/node-exporter:/etc/node-exporter \
  \
        --name node_exporter \
        docker.io/prom/node-exporter:master \
         --path.procfs='/host/proc' --path.sysfs='/host/sys' --collector.filesystem.ignored-mount-points='^/(sys|proc|dev|host|etc)($|/)' --collector.filesystem.ignored-fs-types='^(aufs|cgroup|devpts|mqueue|nsfs|sysfs|proc|tmpfs|shm|none)$' --web.listen-address=10.something:9100

What did you do that produced an error?

Started the docker container with the --collector.textfile.directory='/etc/node-exporter' directory specified with no files, or a file with a static value

What did you expect to see?

No errors

What did you see instead?

Continuously stacking error messages in docker logs, incrementing until the log messages are enormous and make the logs nearly unreadable on every poll interval. It's seriously noisy, and seems broken to error on an empty directory, especially when it spams every polling interval if you don't specify a directory! If you don't specify a directory, the logs are spammed with this :

time="2017-10-16T22:08:56Z" level=info msg="No directory specified, see --collector.textfile.directory" source="textfile.go:57"

If you do specify a directory, even if it's empty, you end up with enormous log spam that looks like this :

time="2017-10-16T21:56:26Z" level=error msg="error gathering metrics: [from Gatherer #1] collected metric node_textfile_scrape_error gauge:<value:0 >  was collected before with the same name and label values\n" source="<autogenerated>:1"
time="2017-10-16T21:56:41Z" level=error msg="error gathering metrics: 2 error(s) occurred:\n* [from Gatherer #1] [from Gatherer #1] collected metric node_textfile_scrape_error gauge:<value:0 >  was collected before with the same name and label values\n* [from Gatherer #1] collected metric node_textfile_scrape_error gauge:<value:0 >  was collected before with the same name and label values\n" source="<autogenerated>:1"
time="2017-10-16T21:56:56Z" level=error msg="error gathering metrics: 3 error(s) occurred:\n* [from Gatherer #1] [from Gatherer #1] [from Gatherer #1] collected metric node_textfile_scrape_error gauge:<value:0 >  was collected before with the same name and label values\n* [from Gatherer #1] [from Gatherer #1] collected metric node_textfile_scrape_error gauge:<value:0 >  was collected before with the same name and label values\n* [from Gatherer #1] collected metric node_textfile_scrape_error gauge:<value:0 >  was collected before with the same name and label values\n" source="<autogenerated>:1"
time="2017-10-16T21:57:11Z" level=error msg="error gathering metrics: 4 error(s) occurred:\n* [from Gatherer #1] [from Gatherer #1] [from Gatherer #1] [from Gatherer #1] collected metric node_textfile_scrape_error gauge:<value:0 >  was collected before with the same name and label values\n* [from Gatherer #1] [from Gatherer #1] [from Gatherer #1] collected metric node_textfile_scrape_error gauge:<value:0 >  was collected before with the same name and label values\n* [from Gatherer #1] [from Gatherer #1] collected metric node_textfile_scrape_error gauge:<value:0 >  was collected before with the same name and label values\n* [from Gatherer #1] collected metric node_textfile_scrape_error gauge:<value:0 >  was collected before with the same name and label values\n" source="<autogenerated>:1"
time="2017-10-16T21:57:26Z" level=error msg="error gathering metrics: 5 error(s) occurred:\n* [from Gatherer #1] [from Gatherer #1] [from Gatherer #1] [from Gatherer #1] [from Gatherer #1] collected metric node_textfile_scrape_error gauge:<value:0 >  was collected before with the same name and label values\n* [from Gatherer #1] [from Gatherer #1] [from Gatherer #1] [from Gatherer #1] collected metric node_textfile_scrape_error gauge:<value:0 >  was collected before with the same name and label values\n* [from Gatherer #1] [from Gatherer #1] [from Gatherer #1] collected metric node_textfile_scrape_error gauge:<value:0 >  was collected before with the same name and label values\n* [from Gatherer #1] [from Gatherer #1] collected metric node_textfile_scrape_error gauge:<value:0 >  was collected before with the same name and label values\n* [from Gatherer #1] collected metric node_textfile_scrape_error gauge:<value:0 >  was collected before with the same name and label values\n" source="<autogenerated>:1"
time="2017-10-16T21:57:41Z" level=error msg="error gathering metrics: 6 error(s) occurred:\n* [from Gatherer #1] [from Gatherer #1] [from Gatherer #1] [from Gatherer #1] [from Gatherer #1] [from Gatherer #1] collected metric node_textfile_scrape_error gauge:<value:0 >  was collected before with the same name and label values\n* [from Gatherer #1] [from Gatherer #1] [from Gatherer #1] [from Gatherer #1] [from Gatherer #1] collected metric node_textfile_scrape_error gauge:<value:0 >  was collected before with the same name and label values\n* [from Gatherer #1] [from Gatherer #1] [from Gatherer #1] [from Gatherer #1] collected metric node_textfile_scrape_error gauge:<value:0 >  was collected before with the same name and label values\n* [from Gatherer #1] [from Gatherer #1] [from Gatherer #1] collected metric node_textfile_scrape_error gauge:<value:0 >  was collected before with the same name and label values\n* [from Gatherer #1] [from Gatherer #1] collected metric node_textfile_scrape_error gauge:<value:0 >  was collected before with the same name and label values\n* [from Gatherer #1] collected metric node_textfile_scrape_error gauge:<value:0 >  was collected before with the same name and label values\n" source="<autogenerated>:1"

[SuperQ]

Strange, I am not able to reproduce this error with no textfile directory or an empty textfile directory. I will have to look over the code to see if I can trace what's going on.

[emalyi]

The same issue with a package installation:

root@prom:~# node_exporter --version
node_exporter, version 0.15.0 (branch: HEAD, revision: 6ecd8780d9f91a7378fabb80837c88a97c6ca321)
  build user:       root@maya
  build date:       20171020-03:15:42
  go version:       go1.8

root@prom:~# uname -a
Linux prom 4.4.0-97-generic #120-Ubuntu SMP Tue Sep 19 17:28:18 UTC 2017 x86_64 x86_64 x86_64 GNU/Linux

And if execute:

root@prom:~# /usr/sbin/node_exporter --collector.textfile.directory /var/lib/node_exporter/textfile_collector
INFO[0000] Starting node_exporter (version=0.15.0, branch=HEAD, revision=6ecd8780d9f91a7378fabb80837c88a97c6ca321)  source="node_exporter.go:78"
INFO[0000] Build context (go=go1.8, user=root@maya, date=20171020-03:15:42)  source="node_exporter.go:79"
INFO[0000] Enabled collectors:                           source="node_exporter.go:86"
INFO[0000]  - xfs                                        source="node_exporter.go:88"
INFO[0000]  - diskstats                                  source="node_exporter.go:88"
INFO[0000]  - stat                                       source="node_exporter.go:88"
INFO[0000]  - cpu                                        source="node_exporter.go:88"
INFO[0000]  - meminfo                                    source="node_exporter.go:88"
INFO[0000]  - edac                                       source="node_exporter.go:88"
INFO[0000]  - wifi                                       source="node_exporter.go:88"
INFO[0000]  - arp                                        source="node_exporter.go:88"
INFO[0000]  - loadavg                                    source="node_exporter.go:88"
INFO[0000]  - time                                       source="node_exporter.go:88"
INFO[0000]  - sockstat                                   source="node_exporter.go:88"
INFO[0000]  - entropy                                    source="node_exporter.go:88"
INFO[0000]  - hwmon                                      source="node_exporter.go:88"
INFO[0000]  - vmstat                                     source="node_exporter.go:88"
INFO[0000]  - zfs                                        source="node_exporter.go:88"
INFO[0000]  - uname                                      source="node_exporter.go:88"
INFO[0000]  - conntrack                                  source="node_exporter.go:88"
INFO[0000]  - infiniband                                 source="node_exporter.go:88"
INFO[0000]  - netstat                                    source="node_exporter.go:88"
INFO[0000]  - ipvs                                       source="node_exporter.go:88"
INFO[0000]  - textfile                                   source="node_exporter.go:88"
INFO[0000]  - filefd                                     source="node_exporter.go:88"
INFO[0000]  - mdadm                                      source="node_exporter.go:88"
INFO[0000]  - timex                                      source="node_exporter.go:88"
INFO[0000]  - netdev                                     source="node_exporter.go:88"
INFO[0000]  - filesystem                                 source="node_exporter.go:88"
INFO[0000]  - bcache                                     source="node_exporter.go:88"
INFO[0000] Listening on :9100                            source="node_exporter.go:103"
ERRO[0007] error gathering metrics: [from Gatherer #1] collected metric node_textfile_scrape_error gauge:<value:0 >  was collected before with the same name and label values
  source="<autogenerated>:38"
ERRO[0017] error gathering metrics: 2 error(s) occurred:
* [from Gatherer #1] [from Gatherer #1] collected metric node_textfile_scrape_error gauge:<value:0 >  was collected before with the same name and label values
* [from Gatherer #1] collected metric node_textfile_scrape_error gauge:<value:0 >  was collected before with the same name and label values
  source="<autogenerated>:38"
ERRO[0027] error gathering metrics: 3 error(s) occurred:
* [from Gatherer #1] [from Gatherer #1] [from Gatherer #1] collected metric node_textfile_scrape_error gauge:<value:0 >  was collected before with the same name and label values
* [from Gatherer #1] [from Gatherer #1] collected metric node_textfile_scrape_error gauge:<value:0 >  was collected before with the same name and label values
* [from Gatherer #1] collected metric node_textfile_scrape_error gauge:<value:0 >  was collected before with the same name and label values
  source="<autogenerated>:38

[frateralexander]

Solved it ?