upssched[<pid>]: accept on unix fd failed: Too many open files

[ElioDiNino]

Every ~2-3 days I am getting the following error from NUT, specifically from upssched: upssched[<pid>]: accept on unix fd failed: Too many open files. I have tried Googling, reading the mailing list, and past GitHub issues but found nothing helpful. After around a minute of this error getting repeated a few hundred times it seems to resolve itself and I also receive an email alert because it causes my heartbeat timer to fail.

I am running the version 2.8.0 of nut which is the latest for Proxmox 8.4.0 (Linux 6.8.12-9-pve)
My nut configuration files can be found here: https://github.com/ElioDiNino/Homelab/tree/main/tools/nut

[jimklimov]

Curious, haven't seen that before...

Generally, there's a system ulimit on various constrained resources including the amount of open file descriptors, and those can be inherited from OS hard and soft limits, or set explicitly for systemd units as well as legacy init scripts. Maybe this amount is too constrained on your system somehow, so the limit is easily reached during healthy life-cycle, or something "leaks" in NUT. I think you can monitor the open FD's via ls -la /proc/<pid>/fd on Linux to see how many there are and if the population changes over time or only grows (leak).

Looking at code, there is a conn_add() method called from start_daemon() which implements the main loop. I haven't had much time to discern if this concerns connections from the child processes with timers, from upsmon, or both.

I can't quickly say if the amount of connections is proportional to any settings (timers, notifiers), so at this point can only suggest hints like this.

Guessing from symptoms:

• Given that the problem only happens every few days, I guess this is not a leak but your setup reaching some low-ish threshold when "stars align" in a bad but rare manner. Maybe some combo/amount of alerts is raised that is just right for your setup.
• The "hundred repeats" suggests that the connections are retried (likely with little/no delay), and
• "after around a minute" suggests that something gets restarted, maybe? Or the caller gives up? Are there any log entries suggesting that a process died with error etc. around the end of such minute?

[ElioDiNino]

Thanks for the quick reply @jimklimov

Generally, there's a system ulimit on various constrained resources including the amount of open file descriptors, and those can be inherited from OS hard and soft limits, or set explicitly for systemd units as well as legacy init scripts. Maybe this amount is too constrained on your system somehow, so the limit is easily reached during healthy life-cycle, or something "leaks" in NUT. I think you can monitor the open FD's via ls -la /proc/<pid>/fd on Linux to see how many there are and if the population changes over time or only grows (leak).

I appreciate the FD command suggestion, I will try to monitor that a bit. The last time I got the error (prior to getting it this morning) was 3 days ago and at that time I used ulimit to try increasing the allowable file descriptors from the default 1024 to 10000. Interestingly that seems to have changed back to the default so I will have to look into that (probably happens with Proxmox updates or something).

The current output for the latest PID is here

❯ ls -la /proc/2556240/fd
total 0
dr-x------ 2 root root 201 Apr  9 07:40 .
dr-xr-xr-x 9 root root   0 Apr  8 21:25 ..
lrwx------ 1 root root  64 Apr  9 07:40 0 -> /dev/null
lrwx------ 1 root root  64 Apr  9 07:40 1 -> /dev/null
lrwx------ 1 root root  64 Apr  9 07:40 10 -> 'socket:[16709349]'
lrwx------ 1 root root  64 Apr  9 07:40 100 -> 'socket:[17057188]'
lrwx------ 1 root root  64 Apr  9 07:40 101 -> 'socket:[17057189]'
lrwx------ 1 root root  64 Apr  9 07:40 102 -> 'socket:[17073934]'
lrwx------ 1 root root  64 Apr  9 07:40 103 -> 'socket:[17075126]'
lrwx------ 1 root root  64 Apr  9 07:40 104 -> 'socket:[17075127]'
lrwx------ 1 root root  64 Apr  9 07:40 105 -> 'socket:[17095790]'
lrwx------ 1 root root  64 Apr  9 07:40 106 -> 'socket:[17098153]'
lrwx------ 1 root root  64 Apr  9 07:40 107 -> 'socket:[17098154]'
lrwx------ 1 root root  64 Apr  9 07:40 108 -> 'socket:[17098165]'
lrwx------ 1 root root  64 Apr  9 07:40 109 -> 'socket:[17113152]'
lrwx------ 1 root root  64 Apr  9 07:40 11 -> 'socket:[16715045]'
lrwx------ 1 root root  64 Apr  9 07:40 110 -> 'socket:[17113153]'
lrwx------ 1 root root  64 Apr  9 07:40 111 -> 'socket:[17098205]'
lrwx------ 1 root root  64 Apr  9 07:40 112 -> 'socket:[17113253]'
lrwx------ 1 root root  64 Apr  9 07:40 113 -> 'socket:[17113254]'
lrwx------ 1 root root  64 Apr  9 07:40 114 -> 'socket:[17098206]'
lrwx------ 1 root root  64 Apr  9 07:40 115 -> 'socket:[17135204]'
lrwx------ 1 root root  64 Apr  9 07:40 116 -> 'socket:[17135205]'
lrwx------ 1 root root  64 Apr  9 07:40 117 -> 'socket:[17140754]'
lrwx------ 1 root root  64 Apr  9 07:40 118 -> 'socket:[17140766]'
lrwx------ 1 root root  64 Apr  9 07:40 119 -> 'socket:[17140767]'
lrwx------ 1 root root  64 Apr  9 07:40 12 -> 'socket:[16715046]'
lrwx------ 1 root root  64 Apr  9 07:40 120 -> 'socket:[17139095]'
lrwx------ 1 root root  64 Apr  9 07:40 121 -> 'socket:[17139120]'
lrwx------ 1 root root  64 Apr  9 07:40 122 -> 'socket:[17139121]'
lrwx------ 1 root root  64 Apr  9 07:40 123 -> 'socket:[17141006]'
lrwx------ 1 root root  64 Apr  9 07:40 124 -> 'socket:[17139499]'
lrwx------ 1 root root  64 Apr  9 07:40 125 -> 'socket:[17139500]'
lrwx------ 1 root root  64 Apr  9 07:40 126 -> 'socket:[17139584]'
lrwx------ 1 root root  64 Apr  9 07:40 127 -> 'socket:[17141017]'
lrwx------ 1 root root  64 Apr  9 07:40 128 -> 'socket:[17141018]'
lrwx------ 1 root root  64 Apr  9 07:40 129 -> 'socket:[17189660]'
lrwx------ 1 root root  64 Apr  9 07:40 13 -> 'socket:[16715057]'
lrwx------ 1 root root  64 Apr  9 07:40 130 -> 'socket:[17191899]'
lrwx------ 1 root root  64 Apr  9 07:40 131 -> 'socket:[17191900]'
lrwx------ 1 root root  64 Apr  9 07:40 132 -> 'socket:[17193204]'
lrwx------ 1 root root  64 Apr  9 07:40 133 -> 'socket:[17193205]'
lrwx------ 1 root root  64 Apr  9 07:40 134 -> 'socket:[17193206]'
lrwx------ 1 root root  64 Apr  9 07:40 135 -> 'socket:[17193241]'
lrwx------ 1 root root  64 Apr  9 07:40 136 -> 'socket:[17221689]'
lrwx------ 1 root root  64 Apr  9 07:40 137 -> 'socket:[17221690]'
lrwx------ 1 root root  64 Apr  9 07:40 138 -> 'socket:[17220310]'
lrwx------ 1 root root  64 Apr  9 07:40 139 -> 'socket:[17228461]'
lrwx------ 1 root root  64 Apr  9 07:40 14 -> 'socket:[16715058]'
lrwx------ 1 root root  64 Apr  9 07:40 140 -> 'socket:[17228462]'
lrwx------ 1 root root  64 Apr  9 07:40 141 -> 'socket:[17228468]'
lrwx------ 1 root root  64 Apr  9 07:40 142 -> 'socket:[17240275]'
lrwx------ 1 root root  64 Apr  9 07:40 143 -> 'socket:[17240276]'
lrwx------ 1 root root  64 Apr  9 07:40 144 -> 'socket:[17240293]'
lrwx------ 1 root root  64 Apr  9 07:40 145 -> 'socket:[17240308]'
lrwx------ 1 root root  64 Apr  9 07:40 146 -> 'socket:[17240309]'
lrwx------ 1 root root  64 Apr  9 07:40 147 -> 'socket:[17258551]'
lrwx------ 1 root root  64 Apr  9 07:40 148 -> 'socket:[17240331]'
lrwx------ 1 root root  64 Apr  9 07:40 149 -> 'socket:[17240332]'
lrwx------ 1 root root  64 Apr  9 07:40 15 -> 'socket:[16715067]'
lrwx------ 1 root root  64 Apr  9 07:40 150 -> 'socket:[17272778]'
lrwx------ 1 root root  64 Apr  9 07:40 151 -> 'socket:[17272794]'
lrwx------ 1 root root  64 Apr  9 07:40 152 -> 'socket:[17272795]'
lrwx------ 1 root root  64 Apr  9 07:40 153 -> 'socket:[17272804]'
lrwx------ 1 root root  64 Apr  9 07:40 154 -> 'socket:[17273324]'
lrwx------ 1 root root  64 Apr  9 07:40 155 -> 'socket:[17273325]'
lrwx------ 1 root root  64 Apr  9 07:40 156 -> 'socket:[17294176]'
lrwx------ 1 root root  64 Apr  9 07:40 157 -> 'socket:[17297816]'
lrwx------ 1 root root  64 Apr  9 07:40 158 -> 'socket:[17297817]'
lrwx------ 1 root root  64 Apr  9 07:40 159 -> 'socket:[17297850]'
lrwx------ 1 root root  64 Apr  9 07:40 16 -> 'socket:[16718845]'
lrwx------ 1 root root  64 Apr  9 07:40 160 -> 'socket:[17297851]'
lrwx------ 1 root root  64 Apr  9 07:40 161 -> 'socket:[17297852]'
lrwx------ 1 root root  64 Apr  9 07:40 162 -> 'socket:[17318582]'
lrwx------ 1 root root  64 Apr  9 07:40 163 -> 'socket:[17298385]'
lrwx------ 1 root root  64 Apr  9 07:40 164 -> 'socket:[17298386]'
lrwx------ 1 root root  64 Apr  9 07:40 165 -> 'socket:[17298404]'
lrwx------ 1 root root  64 Apr  9 07:40 166 -> 'socket:[17298415]'
lrwx------ 1 root root  64 Apr  9 07:40 167 -> 'socket:[17298416]'
lrwx------ 1 root root  64 Apr  9 07:40 168 -> 'socket:[17345589]'
lrwx------ 1 root root  64 Apr  9 07:40 169 -> 'socket:[17345609]'
lrwx------ 1 root root  64 Apr  9 07:40 17 -> 'socket:[16718846]'
lrwx------ 1 root root  64 Apr  9 07:40 170 -> 'socket:[17345610]'
lrwx------ 1 root root  64 Apr  9 07:40 171 -> 'socket:[17331417]'
lrwx------ 1 root root  64 Apr  9 07:40 172 -> 'socket:[17364642]'
lrwx------ 1 root root  64 Apr  9 07:40 173 -> 'socket:[17364643]'
lrwx------ 1 root root  64 Apr  9 07:40 174 -> 'socket:[17363380]'
lrwx------ 1 root root  64 Apr  9 07:40 175 -> 'socket:[17363393]'
lrwx------ 1 root root  64 Apr  9 07:40 176 -> 'socket:[17363394]'
lrwx------ 1 root root  64 Apr  9 07:40 177 -> 'socket:[17363417]'
lrwx------ 1 root root  64 Apr  9 07:40 178 -> 'socket:[17363431]'
lrwx------ 1 root root  64 Apr  9 07:40 179 -> 'socket:[17363432]'
lrwx------ 1 root root  64 Apr  9 07:40 18 -> 'socket:[16715102]'
lrwx------ 1 root root  64 Apr  9 07:40 180 -> 'socket:[17365761]'
lrwx------ 1 root root  64 Apr  9 07:40 181 -> 'socket:[17363535]'
lrwx------ 1 root root  64 Apr  9 07:40 182 -> 'socket:[17363536]'
lrwx------ 1 root root  64 Apr  9 07:40 183 -> 'socket:[17405278]'
lrwx------ 1 root root  64 Apr  9 07:40 184 -> 'socket:[17405824]'
lrwx------ 1 root root  64 Apr  9 07:40 185 -> 'socket:[17405825]'
lrwx------ 1 root root  64 Apr  9 07:40 186 -> 'socket:[17417079]'
lrwx------ 1 root root  64 Apr  9 07:40 187 -> 'socket:[17430861]'
lrwx------ 1 root root  64 Apr  9 07:40 188 -> 'socket:[17430862]'
lrwx------ 1 root root  64 Apr  9 07:40 189 -> 'socket:[17432701]'
lrwx------ 1 root root  64 Apr  9 07:40 19 -> 'socket:[16756882]'
lrwx------ 1 root root  64 Apr  9 07:40 190 -> 'socket:[17430935]'
lrwx------ 1 root root  64 Apr  9 07:40 191 -> 'socket:[17430936]'
lrwx------ 1 root root  64 Apr  9 07:41 192 -> 'socket:[17455208]'
lrwx------ 1 root root  64 Apr  9 07:46 193 -> 'socket:[17455231]'
lrwx------ 1 root root  64 Apr  9 07:46 194 -> 'socket:[17455232]'
lrwx------ 1 root root  64 Apr  9 07:51 195 -> 'socket:[17455234]'
lrwx------ 1 root root  64 Apr  9 07:56 196 -> 'socket:[17464906]'
lrwx------ 1 root root  64 Apr  9 07:56 197 -> 'socket:[17464907]'
lrwx------ 1 root root  64 Apr  9 08:02 198 -> 'socket:[17455243]'
lrwx------ 1 root root  64 Apr  9 08:06 199 -> 'socket:[17490185]'
lrwx------ 1 root root  64 Apr  9 07:40 2 -> /dev/null
lrwx------ 1 root root  64 Apr  9 07:40 20 -> 'socket:[16756883]'
lrwx------ 1 root root  64 Apr  9 08:06 200 -> 'socket:[17490186]'
lrwx------ 1 root root  64 Apr  9 07:40 21 -> 'socket:[16760432]'
lrwx------ 1 root root  64 Apr  9 07:40 22 -> 'socket:[16760449]'
lrwx------ 1 root root  64 Apr  9 07:40 23 -> 'socket:[16760450]'
lrwx------ 1 root root  64 Apr  9 07:40 24 -> 'socket:[16760461]'
lrwx------ 1 root root  64 Apr  9 07:40 25 -> 'socket:[16760468]'
lrwx------ 1 root root  64 Apr  9 07:40 26 -> 'socket:[16760469]'
lrwx------ 1 root root  64 Apr  9 07:40 27 -> 'socket:[16760519]'
lrwx------ 1 root root  64 Apr  9 07:40 28 -> 'socket:[16789199]'
lrwx------ 1 root root  64 Apr  9 07:40 29 -> 'socket:[16789200]'
lrwx------ 1 root root  64 Apr  9 07:40 3 -> 'socket:[16709078]'
lrwx------ 1 root root  64 Apr  9 07:40 30 -> 'socket:[16792843]'
lrwx------ 1 root root  64 Apr  9 07:40 31 -> 'socket:[16802556]'
lrwx------ 1 root root  64 Apr  9 07:40 32 -> 'socket:[16802557]'
lrwx------ 1 root root  64 Apr  9 07:40 33 -> 'socket:[16805981]'
lrwx------ 1 root root  64 Apr  9 07:40 34 -> 'socket:[16802746]'
lrwx------ 1 root root  64 Apr  9 07:40 35 -> 'socket:[16802747]'
lrwx------ 1 root root  64 Apr  9 07:40 36 -> 'socket:[16819463]'
lrwx------ 1 root root  64 Apr  9 07:40 37 -> 'socket:[16826866]'
lrwx------ 1 root root  64 Apr  9 07:40 38 -> 'socket:[16826867]'
lrwx------ 1 root root  64 Apr  9 07:40 39 -> 'socket:[16831861]'
lr-x------ 1 root root  64 Apr  9 07:40 4 -> /etc/nut/upssched.conf
lrwx------ 1 root root  64 Apr  9 07:40 40 -> 'socket:[16831874]'
lrwx------ 1 root root  64 Apr  9 07:40 41 -> 'socket:[16831875]'
lrwx------ 1 root root  64 Apr  9 07:40 42 -> 'socket:[16831876]'
lrwx------ 1 root root  64 Apr  9 07:40 43 -> 'socket:[16831877]'
lrwx------ 1 root root  64 Apr  9 07:40 44 -> 'socket:[16831878]'
lrwx------ 1 root root  64 Apr  9 07:40 45 -> 'socket:[16831879]'
lrwx------ 1 root root  64 Apr  9 07:40 46 -> 'socket:[16862422]'
lrwx------ 1 root root  64 Apr  9 07:40 47 -> 'socket:[16862423]'
lrwx------ 1 root root  64 Apr  9 07:40 48 -> 'socket:[16865407]'
lrwx------ 1 root root  64 Apr  9 07:40 49 -> 'socket:[16865410]'
lrwx------ 1 root root  64 Apr  9 07:40 5 -> 'socket:[16711711]'
lrwx------ 1 root root  64 Apr  9 07:40 50 -> 'socket:[16865411]'
lrwx------ 1 root root  64 Apr  9 07:40 51 -> 'socket:[16879447]'
lrwx------ 1 root root  64 Apr  9 07:40 52 -> 'socket:[16865867]'
lrwx------ 1 root root  64 Apr  9 07:40 53 -> 'socket:[16865868]'
lrwx------ 1 root root  64 Apr  9 07:40 54 -> 'socket:[16865887]'
lrwx------ 1 root root  64 Apr  9 07:40 55 -> 'socket:[16896422]'
lrwx------ 1 root root  64 Apr  9 07:40 56 -> 'socket:[16896423]'
lrwx------ 1 root root  64 Apr  9 07:40 57 -> 'socket:[16898479]'
lrwx------ 1 root root  64 Apr  9 07:40 58 -> 'socket:[16905762]'
lrwx------ 1 root root  64 Apr  9 07:40 59 -> 'socket:[16905763]'
lrwx------ 1 root root  64 Apr  9 07:40 6 -> 'socket:[16711712]'
lrwx------ 1 root root  64 Apr  9 07:40 60 -> 'socket:[16908279]'
lrwx------ 1 root root  64 Apr  9 07:40 61 -> 'socket:[16918880]'
lrwx------ 1 root root  64 Apr  9 07:40 62 -> 'socket:[16918881]'
lrwx------ 1 root root  64 Apr  9 07:40 63 -> 'socket:[16918887]'
lrwx------ 1 root root  64 Apr  9 07:40 64 -> 'socket:[16923474]'
lrwx------ 1 root root  64 Apr  9 07:40 65 -> 'socket:[16923475]'
lrwx------ 1 root root  64 Apr  9 07:40 66 -> 'socket:[16919243]'
lrwx------ 1 root root  64 Apr  9 07:40 67 -> 'socket:[16919253]'
lrwx------ 1 root root  64 Apr  9 07:40 68 -> 'socket:[16919254]'
lrwx------ 1 root root  64 Apr  9 07:40 69 -> 'socket:[16952339]'
lrwx------ 1 root root  64 Apr  9 07:40 7 -> 'socket:[16709350]'
lrwx------ 1 root root  64 Apr  9 07:40 70 -> 'socket:[16952351]'
lrwx------ 1 root root  64 Apr  9 07:40 71 -> 'socket:[16952352]'
lrwx------ 1 root root  64 Apr  9 07:40 72 -> 'socket:[16966673]'
lrwx------ 1 root root  64 Apr  9 07:40 73 -> 'socket:[16966689]'
lrwx------ 1 root root  64 Apr  9 07:40 74 -> 'socket:[16966690]'
lrwx------ 1 root root  64 Apr  9 07:40 75 -> 'socket:[16962478]'
lrwx------ 1 root root  64 Apr  9 07:40 76 -> 'socket:[16980163]'
lrwx------ 1 root root  64 Apr  9 07:40 77 -> 'socket:[16980164]'
lrwx------ 1 root root  64 Apr  9 07:40 78 -> 'socket:[16980190]'
lrwx------ 1 root root  64 Apr  9 07:40 79 -> 'socket:[16980547]'
lrwx------ 1 root root  64 Apr  9 07:40 8 -> 'socket:[16712720]'
lrwx------ 1 root root  64 Apr  9 07:40 80 -> 'socket:[16980548]'
lrwx------ 1 root root  64 Apr  9 07:40 81 -> 'socket:[16980572]'
lrwx------ 1 root root  64 Apr  9 07:40 82 -> 'socket:[16980573]'
lrwx------ 1 root root  64 Apr  9 07:40 83 -> 'socket:[16980574]'
lrwx------ 1 root root  64 Apr  9 07:40 84 -> 'socket:[17008766]'
lrwx------ 1 root root  64 Apr  9 07:40 85 -> 'socket:[17016416]'
lrwx------ 1 root root  64 Apr  9 07:40 86 -> 'socket:[17016417]'
lrwx------ 1 root root  64 Apr  9 07:40 87 -> 'socket:[17022203]'
lrwx------ 1 root root  64 Apr  9 07:40 88 -> 'socket:[17007385]'
lrwx------ 1 root root  64 Apr  9 07:40 89 -> 'socket:[17007386]'
lrwx------ 1 root root  64 Apr  9 07:40 9 -> 'socket:[16715044]'
lrwx------ 1 root root  64 Apr  9 07:40 90 -> 'socket:[17007398]'
lrwx------ 1 root root  64 Apr  9 07:40 91 -> 'socket:[17022335]'
lrwx------ 1 root root  64 Apr  9 07:40 92 -> 'socket:[17022336]'
lrwx------ 1 root root  64 Apr  9 07:40 93 -> 'socket:[17007422]'
lrwx------ 1 root root  64 Apr  9 07:40 94 -> 'socket:[17007441]'
lrwx------ 1 root root  64 Apr  9 07:40 95 -> 'socket:[17007442]'
lrwx------ 1 root root  64 Apr  9 07:40 96 -> 'socket:[17022485]'
lrwx------ 1 root root  64 Apr  9 07:40 97 -> 'socket:[17057171]'
lrwx------ 1 root root  64 Apr  9 07:40 98 -> 'socket:[17057172]'
lrwx------ 1 root root  64 Apr  9 07:40 99 -> 'socket:[17057179]'

I can't quickly say if the amount of connections is proportional to any settings (timers, notifiers), so at this point can only suggest hints like this.

Guessing from symptoms:

• Given that the problem only happens every few days, I guess this is not a leak but your setup reaching some low-ish threshold when "stars align" in a bad but rare manner. Maybe some combo/amount of alerts is raised that is just right for your setup.

That's possible, I am not running much on my system right now though and nothing notable (at least based on system logs) is occurring at the same time.

• The "hundred repeats" suggests that the connections are retried (likely with little/no delay), and

Yeah, there seems to be 0 delay, see logs below.

• "after around a minute" suggests that something gets restarted, maybe? Or the caller gives up? Are there any log entries suggesting that a process died with error etc. around the end of such minute?

Yeah, the service is definitely getting restarted since the PID changes when it starts working again.

Logs

Start of the errors

Apr 08 20:44:04 pve upssched[1921612]: Cancelling timer: heartbeat-failure-timer
Apr 08 20:44:04 pve upssched[1921612]: New timer: heartbeat-failure-timer (660 seconds)
Apr 08 20:44:04 pve nut-monitor[2548613]: Network UPS Tools upsmon 2.8.0
Apr 08 20:49:06 pve nut-monitor[2549543]: Network UPS Tools upsmon 2.8.0
Apr 08 20:49:06 pve tailscaled[924]: magicsock: endpoints changed: 192.168.0.17:41641 (portmap), 24.85.226.112:41641 (stun), 192.168.50.132:41641 (local)
Apr 08 20:54:06 pve upssched[1921612]: Cancelling timer: heartbeat-failure-timer
Apr 08 20:54:06 pve upssched[1921612]: New timer: heartbeat-failure-timer (660 seconds)
Apr 08 20:54:06 pve nut-monitor[2550467]: Network UPS Tools upsmon 2.8.0
Apr 08 20:59:08 pve nut-monitor[2551397]: Network UPS Tools upsmon 2.8.0
Apr 08 21:04:08 pve upssched[1921612]: Cancelling timer: heartbeat-failure-timer
Apr 08 21:04:08 pve upssched[1921612]: New timer: heartbeat-failure-timer (660 seconds)
Apr 08 21:04:08 pve nut-monitor[2552322]: Network UPS Tools upsmon 2.8.0
Apr 08 21:09:10 pve nut-monitor[2553237]: Network UPS Tools upsmon 2.8.0
Apr 08 21:14:10 pve upssched[1921612]: Cancelling timer: heartbeat-failure-timer
Apr 08 21:14:10 pve upssched[1921612]: New timer: heartbeat-failure-timer (660 seconds)
Apr 08 21:14:10 pve nut-monitor[2554141]: Network UPS Tools upsmon 2.8.0
Apr 08 21:17:01 pve CRON[2554687]: pam_unix(cron:session): session opened for user root(uid=0) by (uid=0)
Apr 08 21:17:01 pve CRON[2554688]: (root) CMD (cd / && run-parts --report /etc/cron.hourly)
Apr 08 21:17:01 pve CRON[2554687]: pam_unix(cron:session): session closed for user root
Apr 08 21:19:12 pve nut-monitor[2555081]: Network UPS Tools upsmon 2.8.0
Apr 08 21:24:12 pve upssched[1921612]: accept on unix fd failed: Too many open files
Apr 08 21:24:12 pve upssched[1921612]: accept on unix fd failed: Too many open files
Apr 08 21:24:12 pve upssched[1921612]: accept on unix fd failed: Too many open files
Apr 08 21:24:12 pve upssched[1921612]: accept on unix fd failed: Too many open files
Apr 08 21:24:12 pve upssched[1921612]: accept on unix fd failed: Too many open files
Apr 08 21:24:12 pve upssched[1921612]: accept on unix fd failed: Too many open files
Apr 08 21:24:12 pve upssched[1921612]: accept on unix fd failed: Too many open files
Apr 08 21:24:12 pve upssched[1921612]: accept on unix fd failed: Too many open files
Apr 08 21:24:12 pve upssched[1921612]: accept on unix fd failed: Too many open files
Apr 08 21:24:12 pve upssched[1921612]: accept on unix fd failed: Too many open files
Apr 08 21:24:12 pve upssched[1921612]: accept on unix fd failed: Too many open files
Apr 08 21:24:12 pve upssched[1921612]: accept on unix fd failed: Too many open files
Apr 08 21:24:12 pve upssched[1921612]: accept on unix fd failed: Too many open files
Apr 08 21:24:12 pve upssched[1921612]: accept on unix fd failed: Too many open files
Apr 08 21:24:12 pve upssched[1921612]: accept on unix fd failed: Too many open files
Apr 08 21:24:12 pve upssched[1921612]: accept on unix fd failed: Too many open files
Apr 08 21:24:12 pve upssched[1921612]: accept on unix fd failed: Too many open files
Apr 08 21:24:12 pve upssched[1921612]: accept on unix fd failed: Too many open files
Apr 08 21:24:12 pve upssched[1921612]: accept on unix fd failed: Too many open files
Apr 08 21:24:12 pve upssched[1921612]: accept on unix fd failed: Too many open files
Apr 08 21:24:12 pve upssched[1921612]: accept on unix fd failed: Too many open files
Apr 08 21:24:12 pve upssched[1921612]: accept on unix fd failed: Too many open files
Apr 08 21:24:12 pve upssched[1921612]: accept on unix fd failed: Too many open files
Apr 08 21:24:12 pve upssched[1921612]: accept on unix fd failed: Too many open files
Apr 08 21:24:12 pve upssched[1921612]: accept on unix fd failed: Too many open files
Apr 08 21:24:12 pve upssched[1921612]: accept on unix fd failed: Too many open files
Apr 08 21:24:12 pve upssched[1921612]: accept on unix fd failed: Too many open files
Apr 08 21:24:12 pve upssched[1921612]: accept on unix fd failed: Too many open files
Apr 08 21:24:12 pve upssched[1921612]: accept on unix fd failed: Too many open files
...

After many more of the same message

Apr 08 21:25:09 pve upssched[1921612]: accept on unix fd failed: Too many open files
Apr 08 21:25:09 pve upssched[1921612]: accept on unix fd failed: Too many open files
Apr 08 21:25:09 pve upssched[1921612]: accept on unix fd failed: Too many open files
Apr 08 21:25:09 pve upssched[1921612]: accept on unix fd failed: Too many open files
Apr 08 21:25:09 pve upssched[1921612]: accept on unix fd failed: Too many open files
Apr 08 21:25:09 pve upssched[1921612]: accept on unix fd failed: Too many open files
Apr 08 21:25:09 pve upssched[1921612]: accept on unix fd failed: Too many open files
Apr 08 21:25:09 pve upssched[1921612]: accept on unix fd failed: Too many open files
Apr 08 21:25:09 pve upssched[1921612]: accept on unix fd failed: Too many open files
Apr 08 21:25:09 pve upssched[1921612]: accept on unix fd failed: Too many open files
Apr 08 21:25:09 pve upssched[1921612]: accept on unix fd failed: Too many open files
Apr 08 21:25:09 pve upssched[1921612]: accept on unix fd failed: Too many open files
Apr 08 21:25:09 pve upssched[1921612]: accept on unix fd failed: Too many open files
Apr 08 21:25:09 pve upssched[1921612]: accept on unix fd failed: Too many open files
Apr 08 21:25:09 pve upssched[1921612]: accept on unix fd failed: Too many open files
Apr 08 21:25:09 pve upssched[1921612]: accept on unix fd failed: Too many open files
Apr 08 21:25:09 pve upssched[1921612]: accept on unix fd failed: Too many open files
Apr 08 21:25:10 pve upssched[1921612]: Event: heartbeat-failure-timer
Apr 08 21:25:10 pve upssched-cmd[2556237]: UPS heartbeat failed! Check NUT configurations.
Apr 08 21:25:10 pve upssched[1921612]: accept on unix fd failed: Too many open files
Apr 08 21:25:10 pve postfix/pickup[2545856]: 0BB8DA061B: uid=0 from=<root>
Apr 08 21:25:10 pve postfix/cleanup[2556236]: 0BB8DA061B: message-id=<20250409042510.0BB8DA061B@redacted_email>
Apr 08 21:25:10 pve postfix/qmgr[14964]: 0BB8DA061B: from=<redacted_email>, size=484, nrcpt=1 (queue active)
Apr 08 21:25:10 pve upssched[1921612]: accept on unix fd failed: Too many open files
Apr 08 21:25:10 pve upssched[1921612]: accept on unix fd failed: Too many open files
Apr 08 21:25:10 pve upssched[1921612]: accept on unix fd failed: Too many open files
Apr 08 21:25:10 pve upssched[1921612]: accept on unix fd failed: Too many open files
Apr 08 21:25:10 pve upssched[1921612]: accept on unix fd failed: Too many open files
Apr 08 21:25:10 pve upssched[1921612]: accept on unix fd failed: Too many open files
Apr 08 21:25:10 pve upssched[1921612]: accept on unix fd failed: Too many open files
Apr 08 21:25:10 pve upssched[1921612]: accept on unix fd failed: Too many open files
Apr 08 21:25:10 pve upssched[1921612]: accept on unix fd failed: Too many open files
Apr 08 21:25:10 pve upssched[1921612]: accept on unix fd failed: Too many open files
Apr 08 21:25:10 pve upssched[1921612]: accept on unix fd failed: Too many open files
Apr 08 21:25:10 pve upssched[1921612]: accept on unix fd failed: Too many open files
Apr 08 21:25:10 pve upssched[1921612]: accept on unix fd failed: Too many open files
Apr 08 21:25:10 pve upssched[1921612]: accept on unix fd failed: Too many open files
Apr 08 21:25:10 pve upssched[1921612]: Timer queue empty, exiting
Apr 08 21:25:10 pve nut-monitor[2556006]: read confirmation failed, trying again
Apr 08 21:25:10 pve upssched[2556006]: read confirmation failed, trying again
Apr 08 21:25:10 pve upssched[2556240]: Timer daemon started
Apr 08 21:25:10 pve upssched[2556240]: New timer: heartbeat-failure-timer (660 seconds)
Apr 08 21:25:10 pve nut-monitor[2556004]: Network UPS Tools upsmon 2.8.0
Apr 08 21:25:11 pve postfix/smtp[2556239]: 0BB8DA061B: replace: header From: root <redacted_email>: From: Proxmox <redacted_email>
Apr 08 21:25:11 pve postfix/smtp[2556239]: 0BB8DA061B: to=<redacted_email>, relay=smtp.forwardemail.net[149.28.215.223]:465, delay=1.6, delays=0.03/0.02/0.91/0.61, dsn=2.0.0, status=sent (250 OK: message queued)
Apr 08 21:25:11 pve postfix/qmgr[14964]: 0BB8DA061B: removed
Apr 08 21:29:14 pve nut-monitor[2556975]: Network UPS Tools upsmon 2.8.0
Apr 08 21:34:19 pve upssched[2556240]: Cancelling timer: heartbeat-failure-timer
Apr 08 21:34:19 pve upssched[2556240]: New timer: heartbeat-failure-timer (660 seconds)
Apr 08 21:34:19 pve nut-monitor[2557905]: Network UPS Tools upsmon 2.8.0
Apr 08 21:39:17 pve nut-monitor[2558832]: Network UPS Tools upsmon 2.8.0
Apr 08 21:44:17 pve upssched[2556240]: Cancelling timer: heartbeat-failure-timer
Apr 08 21:44:17 pve upssched[2556240]: New timer: heartbeat-failure-timer (660 seconds)
Apr 08 21:44:17 pve nut-monitor[2559770]: Network UPS Tools upsmon 2.8.0
Apr 08 21:49:19 pve nut-monitor[2560699]: Network UPS Tools upsmon 2.8.0
Apr 08 21:54:19 pve upssched[2556240]: Cancelling timer: heartbeat-failure-timer
Apr 08 21:54:19 pve upssched[2556240]: New timer: heartbeat-failure-timer (660 seconds)
Apr 08 21:54:19 pve nut-monitor[2561632]: Network UPS Tools upsmon 2.8.0
...

[jimklimov]

Can't help but wonder if this is under the hood an issue similar to https://alioth-lists.debian.net/pipermail/nut-upsuser/2025-April/013928.html - at least, these are two upssched weirdness discussions within a week.

at that time I used ulimit to try increasing...

Did you do it from shell? This only impacts processes spawned by it (or its descendants), but not e.g. systemd units (independence from current shell circumstances was one of selling points for service management frameworks vs. init-scripts). The kernel-wide soft/hard defaults I think can be set via sysctl (e.g. in /etc/sysctl.conf somewhere), but for systemd units there's a LimitNOFILE setting. The nut-server.service has some detailed comments from my older experience:

# A busy server can be monitoring a lot of devices as well as replying
# to many clients. The "infinity" definition is actually capped by OS
# settings and hard-coded defaults; typically can be 65535+ nowadays.
# On 64-bit distros this can well be set into hundreds of thousands
# as well (though note each connection has a CPU and RAM overhead
# so one can strike physical limits upon deployment and/or bring the
# poorly sized system to a crawl, or worse). On a running system you
# can check /proc/$MAINPID/limits for active ulimits of the process.
# From my experiments, up to 1048576 can be set, but any larger value
# falls back to 65536. The systemd definition of "infinity" is 65536
# too (or maybe it falls back to that); though this may be OS/distro
# limitation and not systemd fault specifically.
#LimitNOFILE=infinity
#LimitNOFILE=65535
LimitNOFILE=1048576

[ElioDiNino]

Did you do it from shell? This only impacts processes spawned by it (or its descendants), but not e.g. systemd units (independence from current shell circumstances was one of selling points for service management frameworks vs. init-scripts). The kernel-wide soft/hard defaults I think can be set via sysctl (e.g. in /etc/sysctl.conf somewhere), but for systemd units there's a LimitNOFILE setting. The nut-server.service has some detailed comments from my older experience:

# A busy server can be monitoring a lot of devices as well as replying
# to many clients. The "infinity" definition is actually capped by OS
# settings and hard-coded defaults; typically can be 65535+ nowadays.
# On 64-bit distros this can well be set into hundreds of thousands
# as well (though note each connection has a CPU and RAM overhead
# so one can strike physical limits upon deployment and/or bring the
# poorly sized system to a crawl, or worse). On a running system you
# can check /proc/$MAINPID/limits for active ulimits of the process.
# From my experiments, up to 1048576 can be set, but any larger value
# falls back to 65536. The systemd definition of "infinity" is 65536
# too (or maybe it falls back to that); though this may be OS/distro
# limitation and not systemd fault specifically.
#LimitNOFILE=infinity
#LimitNOFILE=65535
LimitNOFILE=1048576

Ah yeah I did, whoops. Thanks for the pointer, I have now adjusted the limit there (as well as for nut-monitor.service) and see the expected limits reflected in /proc/<pid>/limits. Hopefully that will help with my issue, time to wait a few days :)