<div dir="ltr"><div>So... determining that FD is to be reaped proved hard. Internet lore suggests fcntl() and poll() on the FD, but it just seems valid to them. The errno is also usually not raised (once I saw a "111: Connection refused" though).</div><div>So the best dumb idea so far is to bail out if we spent the whole loop (128 attempts) and only got zero-sized read replies and no errors.</div><div><br></div><div><a href="https://github.com/networkupstools/nut/pull/1965">https://github.com/networkupstools/nut/pull/1965</a></div><div><br></div><div>Jim<br></div></div><br><div class="gmail_quote"><div dir="ltr" class="gmail_attr">On Tue, Jun 13, 2023 at 4:06 PM Jim Klimov <<a href="mailto:jimklimov%2Bnut@gmail.com">jimklimov+nut@gmail.com</a>> wrote:<br></div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex"><div dir="ltr"><div>After launching the command several times, with debug (posted by new code in a new branch for the investigation) confirming that the same daemon handles operations from the new client instances, its strace now has numerous FDs to report after select() - so I guess it is a problem of detecting an exit of the counterpart.</div><div><br><br><br></div><div>   0.000000     [D2] parse_at: is 'heartbeat@localhost' in AT command the 'heartbeat@localhost' we were launched to process?<br>   0.000034     [D1] parse_at: 'heartbeat@localhost' in AT command matched the 'heartbeat@localhost' UPSNAME we were launched to process<br>   0.000041     [D1] parse_at: processing CANCEL-TIMER<br>   0.000054     [D2] parse_at: is 'heartbeat@localhost' in AT command the 'heartbeat@localhost' we were launched to process?<br>   0.000057     [D1] parse_at: 'heartbeat@localhost' in AT command matched the 'heartbeat@localhost' UPSNAME we were launched to process<br>   0.000060     [D1] parse_at: processing START-TIMER<br>   0.000151     [D1] Keeping stderr open due to debug verbosity 8<br>   0.000195     Timer daemon started<br>   0.000204     [D2] Timer daemon waiting for connections on pipefd 10<br>   0.250325     [D3] new connection on fd 7<br>   0.250377     New timer: heartbeat-failure-timer (660 seconds)<br>   0.250423     [D1] Exiting upssched (CLI process)<br></div><div><br></div><div>   0.000000     [D2] parse_at: is 'heartbeat@localhost' in AT command the 'heartbeat@localhost' we were launched to process?<br>   0.000039     [D1] parse_at: 'heartbeat@localhost' in AT command matched the 'heartbeat@localhost' UPSNAME we were launched to process<br>   0.000047     [D1] parse_at: processing CANCEL-TIMER<br>  14.745773     [D3] new connection on fd 8<br>  14.745829     Cancelling timer: heartbeat-failure-timer<br>   0.000153     [D2] parse_at: is 'heartbeat@localhost' in AT command the 'heartbeat@localhost' we were launched to process?<br>   0.000159     [D1] parse_at: 'heartbeat@localhost' in AT command matched the 'heartbeat@localhost' UPSNAME we were launched to process<br>   0.000163     [D1] parse_at: processing START-TIMER<br>  14.745890     [D3] new connection on fd 9<br>  14.745969     New timer: heartbeat-failure-timer (660 seconds)<br>   0.000293     [D1] Exiting upssched (CLI process)<br></div><div><br></div><div>   0.000001     [D2] parse_at: is 'heartbeat@localhost' in AT command the 'heartbeat@localhost' we were launched to process?<br>   0.000042     [D1] parse_at: 'heartbeat@localhost' in AT command matched the 'heartbeat@localhost' UPSNAME we were launched to process<br>   0.000050     [D1] parse_at: processing CANCEL-TIMER<br>  47.674032     [D3] new connection on fd 11<br>  47.674160     Cancelling timer: heartbeat-failure-timer<br>   0.000266     [D2] parse_at: is 'heartbeat@localhost' in AT command the 'heartbeat@localhost' we were launched to process?<br>   0.000277     [D1] parse_at: 'heartbeat@localhost' in AT command matched the 'heartbeat@localhost' UPSNAME we were launched to process<br>   0.000284     [D1] parse_at: processing START-TIMER<br>  47.674235     [D3] new connection on fd 12<br>  47.674388     New timer: heartbeat-failure-timer (660 seconds)<br>   0.000487     [D1] Exiting upssched (CLI process)<br></div><div><br></div><div>
<div>Note that `select` only lists remnants of "new connection" but not the FD#10 (pipefd):<br></div><div><br></div>

    select(13, [7 8 9 10 11 12], NULL, NULL, {tv_sec=1, tv_usec=0}) = 5 (in [7 8 9 11 12], left {tv_sec=0, tv_usec=999997})</div><div><br></div><div>Jim</div><div><br></div><div><br></div></div><br><div class="gmail_quote"><div dir="ltr" class="gmail_attr">On Tue, Jun 13, 2023 at 3:41 PM Jim Klimov <<a href="mailto:jimklimov%2Bnut@gmail.com" target="_blank">jimklimov+nut@gmail.com</a>> wrote:<br></div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex"><div dir="ltr"><div>So, got some good news: I hear(*) I managed to reproduce the problem with current NUT master and an adapted copy of your posted configs and script :D</div><div>Experimental debugging now sounds possible.<br></div><div><br></div><div>(*) PC under the desk wails with all its cooling fans as soon as I started the client which spawned a daemon and itself had exited:<br></div><div><br></div><div>$ UPSNAME=heartbeat@localhost NOTIFYTYPE=ONBATT NUT_STATEPATH=/dev/shm NUT_CONFPATH=`pwd`/tests/NIT/tmp/etc ./clients/upssched -DDDDDDDD<br>   0.000000     [D2] parse_at: is 'heartbeat@localhost' in AT command the 'heartbeat@localhost' we were launched to process?<br>   0.000053     [D1] parse_at: 'heartbeat@localhost' in AT command matched the 'heartbeat@localhost' UPSNAME we were launched to process<br>   0.000066     [D1] parse_at: processing CANCEL-TIMER<br>   0.000089     [D2] parse_at: is 'heartbeat@localhost' in AT command the 'heartbeat@localhost' we were launched to process?<br>   0.000096     [D1] parse_at: 'heartbeat@localhost' in AT command matched the 'heartbeat@localhost' UPSNAME we were launched to process<br>   0.000104     [D1] parse_at: processing START-TIMER<br></div><div><br></div><div>$<br></div><div><br></div><div>Jim</div><div><br></div></div><br><div class="gmail_quote"><div dir="ltr" class="gmail_attr">On Tue, Jun 13, 2023 at 1:58 PM Kari Lempiäinen <<a href="mailto:kari.lempiainen@summerday.net" target="_blank">kari.lempiainen@summerday.net</a>> wrote:<br></div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex"><div>




<div dir="ltr">
<div style="font-family:Calibri,Arial,Helvetica,sans-serif;font-size:12pt;color:rgb(0,0,0)">
Hi,</div>
<div style="font-family:Calibri,Arial,Helvetica,sans-serif;font-size:12pt;color:rgb(0,0,0)">
<br>
</div>
<div style="font-family:Calibri,Arial,Helvetica,sans-serif;font-size:12pt;color:rgb(0,0,0)">
Thanks Jim! Here is more system information from the commands you mentioned.</div>
<div style="font-family:Calibri,Arial,Helvetica,sans-serif;font-size:12pt;color:rgb(0,0,0)">
<br>
</div>
<div style="font-family:Calibri,Arial,Helvetica,sans-serif;font-size:12pt;color:rgb(0,0,0)">
Kari</div>
<div style="font-family:Calibri,Arial,Helvetica,sans-serif;font-size:12pt;color:rgb(0,0,0)">
<br>
</div>
<div style="font-family:Calibri,Arial,Helvetica,sans-serif;font-size:12pt;color:rgb(0,0,0)">
root@fricka:~# lsof -p 1716171
<div>lsof: WARNING: can't stat() fuse.gvfsd-fuse file system /run/user/1002/gvfs</div>
<div>      Output information may be incomplete.</div>
<div>COMMAND      PID USER   FD   TYPE             DEVICE SIZE/OFF     NODE NAME</div>
<div>upssched 1716171 root  cwd    DIR                8,2     4096        2 /</div>
<div>upssched 1716171 root  rtd    DIR                8,2     4096        2 /</div>
<div>upssched 1716171 root  txt    REG                8,2    39240 21762148 /usr/sbin/upssched</div>
<div>upssched 1716171 root  mem    REG                8,2  1922136 21764230 /usr/lib/x86_64-linux-gnu/libc.so.6</div>
<div>upssched 1716171 root  mem    REG                8,2   210968 21764476 /usr/lib/x86_64-linux-gnu/ld-linux-x86-64.so.2</div>
<div>upssched 1716171 root    0u   CHR                1,3      0t0        4 /dev/null</div>
<div>upssched 1716171 root    1u   CHR                1,3      0t0        4 /dev/null</div>
<div>upssched 1716171 root    2u   CHR                1,3      0t0        4 /dev/null</div>
<div>upssched 1716171 root    3u  unix 0x00000000eeb52825      0t0 16427010 type=DGRAM (CONNECTED)</div>
<div>upssched 1716171 root    4r   REG                8,2      545 39847858 /etc/nut/upssched.conf</div>
<div>upssched 1716171 root    5u  unix 0x00000000a035b466      0t0 16426351 type=STREAM (UNCONNECTED)</div>
<div>upssched 1716171 root    6u  unix 0x0000000050820b2b      0t0 16426352 type=STREAM (UNCONNECTED)</div>
<div>upssched 1716171 root    7u  unix 0x00000000447aac0e      0t0 16424724 /var/run/nut/upssched.pipe type=STREAM (CONNECTED)</div>
<div>upssched 1716171 root   10u  unix 0x00000000d7bd8088      0t0 16424722 /var/run/nut/upssched.pipe type=STREAM (LISTEN)</div>
<div><br>
</div>
<div><br>
</div>
<div>root@fricka:~# ps -ef|grep ups</div>
<div>root        1425       1  0 Jun11 ?        00:00:00 sshd: /usr/sbin/sshd -D [listener] 0 of 10-100 startups</div>
<div>root     1156722       1  0 00:00 ?        00:00:00 /usr/sbin/cupsd -l</div>
<div>root     1156723       1  0 00:00 ?        00:00:00 /usr/sbin/cups-browsed</div>
<div>lp       1156748 1156722  0 00:00 ?        00:00:00 /usr/lib/cups/notifier/dbus dbus://</div>
<div>nut      1713117       1  0 14:30 ?        00:00:00 /lib/nut/dummy-ups -a heartbeat</div>
<div>nut      1713154       1  0 14:30 ?        00:00:00 /lib/nut/usbhid-ups -a eaton5s</div>
<div>nut      1713155       1  0 14:30 ?        00:00:00 /lib/nut/upsd -F</div>
<div>root     1713156       1  0 14:30 ?        00:00:00 /lib/nut/upsmon -F</div>
<div>root     1713157 1713156  0 14:30 ?        00:00:00 /lib/nut/upsmon -F</div>
<div>root     1716171       1 99 14:35 ?        00:05:10 /sbin/upssched UPS heartbeat@localhost: On battery.</div>
<div>root     1719510 1550505  0 14:40 pts/2    00:00:00 grep ups</div>
<div><br>
</div>
<div><br>
</div>
<div><br>
</div>
<div><br>
</div>
<div>root@fricka:~# fuser /var/run/nut/upssched.pipe</div>
<div>/run/nut/upssched.pipe: 1716171</div>
<div><br>
</div>
<div><br>
</div>
<div>root@fricka:/proc/1716171/fd# ls -la</div>
<div>total 0</div>
<div>dr-x------ 2 root root  0 Jun 13 14:36 .</div>
<div>dr-xr-xr-x 9 root root  0 Jun 13 14:35 ..</div>
<div>lrwx------ 1 root root 64 Jun 13 14:36 0 -> /dev/null</div>
<div>lrwx------ 1 root root 64 Jun 13 14:36 1 -> /dev/null</div>
<div>lrwx------ 1 root root 64 Jun 13 14:36 10 -> 'socket:[16424722]'</div>
<div>lrwx------ 1 root root 64 Jun 13 14:36 2 -> /dev/null</div>
<div>lrwx------ 1 root root 64 Jun 13 14:36 3 -> 'socket:[16427010]'</div>
<div>lr-x------ 1 root root 64 Jun 13 14:36 4 -> /etc/nut/upssched.conf</div>
<div>lrwx------ 1 root root 64 Jun 13 14:36 5 -> 'socket:[16426351]'</div>
<div>lrwx------ 1 root root 64 Jun 13 14:36 6 -> 'socket:[16426352]'</div>
<div>lrwx------ 1 root root 64 Jun 13 14:36 7 -> 'socket:[16424724]'</div>
<div><br>
</div>
<br>
</div>
<div id="m_3863736705357785274m_-8937715224875115372m_-3595996456645787348appendonsend"></div>
<div style="font-family:Calibri,Arial,Helvetica,sans-serif;font-size:12pt;color:rgb(0,0,0)">
<br>
</div>
<hr style="display:inline-block;width:98%">
<div id="m_3863736705357785274m_-8937715224875115372m_-3595996456645787348divRplyFwdMsg" dir="ltr"><font style="font-size:11pt;color:rgb(0,0,0)" face="Calibri, sans-serif"><b>From:</b> Jim Klimov <<a href="mailto:jimklimov%2Bnut@gmail.com" target="_blank">jimklimov+nut@gmail.com</a>><br>
<b>Sent:</b> Tuesday, June 13, 2023 14:17<br>
<b>To:</b> Kari Lempiäinen <<a href="mailto:kari.lempiainen@summerday.net" target="_blank">kari.lempiainen@summerday.net</a>><br>
<b>Cc:</b> Arnaud Quette via Nut-upsuser <<a href="mailto:nut-upsuser@alioth-lists.debian.net" target="_blank">nut-upsuser@alioth-lists.debian.net</a>>; nut-upsdev <<a href="mailto:nut-upsdev@alioth-lists.debian.net" target="_blank">nut-upsdev@alioth-lists.debian.net</a>>; Dimitris Economou <<a href="mailto:dimitris.s.economou@gmail.com" target="_blank">dimitris.s.economou@gmail.com</a>><br>
<b>Subject:</b> Re: [Nut-upsuser] Upssched 100% CPU after updating Debian 12</font>
<div> </div>
</div>
<div>
<div dir="ltr">
<div>FWIW, cross-posted the issue to NUT GitHub tracker: <a href="https://github.com/networkupstools/nut/issues/1964" target="_blank">
https://github.com/networkupstools/nut/issues/1964</a></div>
<div><br>
</div>
<div>Jim<br>
</div>
</div>
</div>
</div>

</div></blockquote></div>
</blockquote></div>
</blockquote></div>