prometheus1 running out of disk space
Date: Fri, 10 Feb 2023 00:03:34 +0000
From: nagios@hetzner-hel1-01.torproject.org
To: anarcat+rapports@orangeseeds.org
Subject: ** PROBLEM Service Alert: hetzner-nbg1-01/disk usage - all is CRITICAL **
***** Icinga *****
Notification Type: PROBLEM
Service: disk usage - all
Host: hetzner-nbg1-01
Address: 195.201.139.202
State: CRITICAL
Date/Time: Fri Feb 10 00:03:34 UTC 2023
Additional Info:
DISK CRITICAL - free space: / 9098 MB (5% inode=99%): /dev 3864 MB (100% inode=99%): /dev/shm 3883 MB (99% inode=99%): /run 776 MB (99% inode=99%): /run/lock 5 MB (100% inode=99%): /tmp 3883 MB (100% inode=99%): /run/credentials 776 MB (99% inode=99%): /var/tmp 9098 MB (5% inode=99%):
disk space was fairly constant until june, and then it started increasing semi-linearly. we gained 30G since then with ~8GB left. we lose about 2GB at each compaction run, and those run roughly every day, so it's unlikely we'll have room until monday.
last time this happened (#40840 (closed)) we just silenced the warning, we can't get away with that this time...
Activity
assigned to @kez
added Doing label
at the very least we can give it another 20 gigs of space if we want to wait until tuesday (monday is a holiday) to brainstorm in the TPA sync.
disk space was fairly constant until june, and then it started increasing semi-linearly
do we know why? is that space being taken up by the archives of old data? in that case, i'd suggest we start archiving data that's older than 6 months to a year
marked this issue as related to #40840 (closed)
marked this issue as related to #40330
do we know why? is that space being taken up by the archives of old data? in that case, i'd suggest we start archiving data that's older than 6 months to a year
i don't know. i'm not sure how to tell. but worse, i am not sure there's a way to "archive" data in prometheus... there are complex multi-server setups where one server downsamples from the first, but we're not there yet. see also #40330.
-
here's one interesting, if confusing fact:
this is a picture of the prometheus dashboard showing specifically the disk space used by the prometheus directory itself. you'll notice there's a correlation between the time it starts going up linearly and some disturbance in the graph. two, in fact: first the color changes in the graph, which means the internal labels on the data series changed. but then another line showed up, and that one is stable at 106GB.
they don't correlate exactly with the beginning of the rise, that said. it seems the rise started at the end of May and the new line showed up in early May. and the color change is even before that.
one thing though: we do have more servers than we had before. 12 months ago, we had 86 instances according to prometheus. now we have 96:
https://grafana.torproject.org/d/wUmZB05Zk/tpo-overview?orgId=1&viewPanel=2&from=now-1y&to=nowyou can also see that we started the bullseye upgrades around April (when the colors changed) and there was a big batch done in May as well (when the new line appeared). the server itself was upgraded in April (#40690 (comment 2793604)).
so it could be some metric that has a cardinal explosion since the bullseye upgrade, that is the only theory i have so far, and it's a hard one to track down...
-
but then another line showed up, and that one is stable at 106GB.
i think the reason this is happening is most likely because a cron job that's supposed to update it is not running. that line is the
/var/lib/prometheusdisk usage on the server, and it's definitely not at a steady 106GB:root@hetzner-nbg1-01:~# du -sh /var/lib/prometheus/ 137G /var/lib/prometheus/so ignore that line.
-
ha, i think i found something:
https://prometheus.torproject.org/classic/graph?g0.range_input=1h&g0.expr=topk(10%2C%20count%20by%20(name)(%7B__name__%3D~%22.%2B%22%7D))&g0.tab=1
that's the
topk(10, count by (__name__)({__name__=~".+"}))query which shows:Element Value node_systemd_unit_state{} 55235 node_logind_sessions{} 13020 node_cpu_seconds_total{} 6408 node_scrape_collector_success{} 3889 node_scrape_collector_duration_seconds{} 3889 onion_service_descriptor_fetch_attempts{} 3244 onion_service_descriptor_reachable{} 3241 onion_service_introduction_points_number{} 2978 onion_service_descriptor_latency{} 2978 onion_service_reachable{} 2813 ie. the systemd and logind collectors generate a lot of entries. we should probably disable those to stop those metrics from accumulating.
-
i didn't invent those queries btw, they come from:
https://alexandre-vazquez.com/how-it-optimize-the-disk-usage-in-the-prometheus-database/
here's the usage per job:
that's
topk(10, count by (job)({__name__=~".+"}))and it is:Element Value {job="node"} 172664 {job="onionprobe"} 24396 {job="gitaly"} 6967 {job="gitlab-workhorse"} 4684 {job="gitlab"} 3410 {job="process"} 3088 {job="apache"} 2207 {job="bind"} 1625 {job="postgres"} 1260 {job="grafana"} 1094 i.e. mostly the node exporter, but note that onionprobe is also in there, which is surprising. probably another thing to fix.
-
at 2023-02-10 19:14:06UTC, i deployed a tweak in puppet to disable the logind and systemd collectors. this should reduce the disk usage of those as puppet runs everywhere.
@kez could you force-run puppet everywhere?
another thing to try is https://prometheus.io/docs/prometheus/1.8/storage/#settings-for-very-long-retention-time i.e. "increase the flag value
storage.local.series-file-shrink-ratio"finally, also note that the above queries are also available, pre-cooked, in https://prometheus.torproject.org/classic/status
-
disk space was fairly constant until june, and then it started increasing semi-linearly. we gained 30G since then with ~8GB left. we lose about 2GB at each compaction run, and those run roughly every day, so it's unlikely we'll have room until monday.
another important point: we don't have a compaction every day. that was me misreading the graph. compactions happen over weeks. the last one was on 2023-01-23 and before that on 2023-01-02, so about three weeks. it that is right, we should be compacting in a few days and since we gain 8GB between compaction cycles, it's unlikely we'll eat the remaining 8GB of disk by then.
so we at least have the weekend to process this.
-
looking at the disk usage graphs since the puppet deployment (2023-02-10 19:14:06UTC +4-6h (so until 23:14UTC or 2023-02-11 01:14UTC), we see disk usage has stopped growing:
in the above graph, between 2023-02-11 12:00UTC and 2023-02-12 01:00UTC, we seem to be going upwards, gaining more free space as time goes forward. then we have this huge cliff that's the ~monthly compaction, and then disk space is more or less steady.
it's still on a downward trend, however. it's hard to tell, but it seems we're still going downwards:
it's still a little early to tell however. i looked at the prometheus status page and the biggest metrics are now:
Highest Cardinality Labels
Name Count updated_at 50736 hsdir 1703 name 1594 relname 1018 name 659 address 411 device 326 instance 165 grpc_method 151 endpoint 149 Highest Cardinality Metric Names
Name Count onion_service_descriptor_fetch_attempts 6826 onion_service_descriptor_reachable 6798 node_cpu_seconds_total 6424 onion_service_descriptor_latency 6350 onion_service_introduction_points_number 6350 onion_service_connection_attempts 5984 onion_service_reachable 5984 onion_service_status_code 5864 onion_service_latency 5864 node_scrape_collector_success 3744 Label Names With Highest Cumulative Label Value Length
Name Length updated_at 856780 hsdir 88423 name 52941 relname 26462 name 19333 filename 11764 address 9867 instance 4997 endpoint 4923 device 3186 Most Common Label Pairs
Name Count job=node 98023 alias=hetzner-nbg1-01.torproject.org 52030 job=onionprobe 51473 instance=hetzner-nbg1-01.torproject.org:9935 51473 classes=role::undefined 27916 classes=role::ganeti::chi 24791 protocol=http 24176 port=80 24176 classes=role::ganeti::fsn 22911 reachable=1 12214 So the next target for optimization would be the onionprobe exporter, i think. In particular, the
updated_atlabel seems to see a lot of churn...I think i'll open a ticket for @rhatto to see if that can be improved and otherwise call this one resolved.
mentioned in issue #41072 (closed)
marked this issue as related to #41072 (closed)
mentioned in commit wiki-replica@a88c640f
mentioned in issue #41639 (closed)
mentioned in issue #41807 (closed)
