<div dir="ltr"><div>So, I've done some experiments, also integrating upssched into NIT (NUT Integration Testing) suite, to help automate the setup and debugging - that aspect can be seen in <a href="https://github.com/jimklimov/nut/tree/issue-2890">https://github.com/jimklimov/nut/tree/issue-2890</a> (also investigating for <a href="https://github.com/networkupstools/nut/issues/2890">https://github.com/networkupstools/nut/issues/2890</a> that also touches on upssched).</div><div><br></div><div>My current conclusion is that `setenv("NOTIFYTYPE")` only happens when `upsmon` calls whatever it has as the `NOTIFYCMD` handler. It is a new process every time it is called, and when the handler is a script or other short-lived program, it indeed sees the current unique value of NOTIFYTYPE (and UPSNAME, and "other CLI args" that convey the message for notification).</div><div><br></div><div>However in case of upssched, the first call to create/cancel timers launches a daemon (to track timer states and execute `CMDSCRIPT` when timers elapse). Subsequent calls to `upssched` as a CLI program talk to this daemon via pipe, to inform it of state changes for `START-TIMER` and `CANCEL-TIMER` matches, e.g.:</div><div><br></div><div>UPS dummy@localhost:12345 on battery<br>Fri Apr 11 13:40:09 UTC 2025: /home/jim/nut/scripts/misc/notifyme-debug ONBATT [dummy@localhost:12345]: args: UPS dummy@localhost:12345 on battery (1 arg tokens)<br>Defaulting debug verbosity to NUT_DEBUG_LEVEL=3 since none was requested by command-line options<br> 0.000081 [D2:7688] parse_at: is '*' in AT command the 'dummy@localhost:12345' we were launched to process?<br> 0.000129 [D1:7688] parse_at: this AT command is for a wildcard: matched<br> 0.000171 [D1:7688] parse_at: SKIP: 'ONLINE' in AT command did not match the 'ONBATT' NOTIFYTYPE we were launched to process<br>...</div><div> 0.001165 [D1:7688] parse_at: this AT command is for a wildcard: matched<br> 0.001172 [D1:7688] parse_at: processing EXECUTE<br> 0.001193 Executing command: ONBATT<br>Fri Apr 11 13:40:09 UTC 2025: /home/jim/nut/clients/upssched-cmd: THIS IS A SAMPLE SCRIPT, PLEASE TAILOR IT FOR YOUR DEPLOYMENT OF NUT!<br>Fri Apr 11 13:40:09 UTC 2025: UPSNAME='dummy@localhost:12345' NOTIFYTYPE='ONBATT' args=ONBATT<br> 0.009687 [D2:7688] parse_at: is '*' in AT command the 'dummy@localhost:12345' we were launched to process?<br> 0.009719 [D1:7688] parse_at: this AT command is for a wildcard: matched<br> 0.009751 [D1:7688] parse_at: processing CANCEL-TIMER<br> 25.037157 [D3:7373] new connection on fd 16<br> 25.037214 [D3:7373] Ending sock_read() on a good note: try to use command:<br> 25.037238 [D3:7373] arg 0: CANCEL<br> 25.037243 [D3:7373] arg 1: LINE-STATUS-1s</div><div>...</div><div> 0.019160 [D2:7688] parse_at: is '*' in AT command the 'dummy@localhost:12345' we were launched to process?<br> 0.019190 [D1:7688] parse_at: this AT command is for a wildcard: matched<br> 0.019196 [D1:7688] parse_at: processing START-TIMER<br> 25.046606 [D3:7373] closing connection on fd 16<br> 25.046647 [D3:7373] new connection on fd 16<br> 25.046706 [D3:7373] Ending sock_read() on a good note: try to use command:<br> 25.046729 [D3:7373] arg 0: START<br> 25.046734 [D3:7373] arg 1: BATT-STATUS-60<br> 25.046757 [D3:7373] arg 2: 3600<br> 25.046780 New timer: BATT-STATUS-60 (3600 seconds)<br> 0.019597 [D2:7688] parse_at: is '*' in AT command the 'dummy@localhost:12345' we were launched to process?<br> 0.019622 [D1:7688] parse_at: this AT command is for a wildcard: matched<br> 0.019627 [D1:7688] parse_at: SKIP: 'REPLBATT' in AT command did not match the 'ONBATT' NOTIFYTYPE we were launched to process</div><div><br></div><div>Note the 25-sec timestamps of the daemon, and 0.x sec timestamps of the client that reacts to a new ONBATT event.</div><div><br></div><div>The `upssched` code, its infinite-looping daemon included, never calls `setenv()`. So all runs of a `CMDSCRIPT` inherit the environment exported for the first run of `upssched` when it created the daemon, including the original and static value of `NOTIFYTYPE`.</div><div><br></div><div>The `upssched` CLI program directly runs the `CMDSCRIPT` when an `AT ... EXECUTE ...` line is matched, however -- including the `NOTIFYTYPE` relevant at this moment, as seen in the third report from `
upssched-cmd`
script below:</div><div><br></div><div> 25.047059 [D3:7373] closing connection on fd 16<br> 0.019795 [D2:7688] parse_at: is '*' in AT command the 'dummy@localhost:12345' we were launched to process?<br> 0.019818 [D1:7688] parse_at: this AT command is for a wildcard: matched<br> 0.019842 [D1:7688] parse_at: SKIP: 'COMMBAD' in AT command did not match the 'ONBATT' NOTIFYTYPE we were launched to process<br> 0.019858 [D1:7688] Exiting upssched (CLI process)<br> 26.048227 Event: BATT-STATUS-1s<br>Fri Apr 11 13:40:10 UTC 2025: /home/jim/nut/clients/upssched-cmd: THIS IS A SAMPLE SCRIPT, PLEASE TAILOR IT FOR YOUR DEPLOYMENT OF NUT!<br>Fri Apr 11 13:40:10 UTC 2025: UPSNAME='dummy@localhost:12345' NOTIFYTYPE='ONBATT' args=BATT-STATUS-1s<br> 27.061667 Event: BATT-STATUS-2s<br>Fri Apr 11 13:40:11 UTC 2025: /home/jim/nut/clients/upssched-cmd: THIS IS A SAMPLE SCRIPT, PLEASE TAILOR IT FOR YOUR DEPLOYMENT OF NUT!<br>Fri Apr 11 13:40:11 UTC 2025: UPSNAME='dummy@localhost:12345' NOTIFYTYPE='ONBATT' args=BATT-STATUS-2s<br>UPS dummy@localhost:12345 on line power<br>Fri Apr 11 13:40:14 UTC 2025: /home/jim/nut/scripts/misc/notifyme-debug ONLINE [dummy@localhost:12345]: args: UPS dummy@localhost:12345 on line power (1 arg tokens)<br>Defaulting debug verbosity to NUT_DEBUG_LEVEL=3 since none was requested by command-line options<br> 0.000068 [D2:7720] parse_at: is '*' in AT command the 'dummy@localhost:12345' we were launched to process?<br> 0.000109 [D1:7720] parse_at: this AT command is for a wildcard: matched<br> 0.000138 [D1:7720] parse_at: processing EXECUTE<br> 0.000143 Executing command: ONLINE<br>Fri Apr 11 13:40:14 UTC 2025: /home/jim/nut/clients/upssched-cmd: THIS IS A SAMPLE SCRIPT, PLEASE TAILOR IT FOR YOUR DEPLOYMENT OF NUT!<br>Fri Apr 11 13:40:14 UTC 2025: UPSNAME='dummy@localhost:12345' NOTIFYTYPE='ONLINE' args=ONLINE<br> 0.011340 [D2:7720] parse_at: is '*' in AT command the 'dummy@localhost:12345' we were launched to process?<br> 0.011389 [D1:7720] parse_at: this AT command is for a wildcard: matched<br> 0.011398 [D1:7720] parse_at: processing CANCEL-TIMER<br> 30.042455 [D3:7373] new connection on fd 16<br> 30.042490 Event: BATT-STATUS-5s<br>Fri Apr 11 13:40:14 UTC 2025: /home/jim/nut/clients/upssched-cmd: THIS IS A SAMPLE SCRIPT, PLEASE TAILOR IT FOR YOUR DEPLOYMENT OF NUT!<br>Fri Apr 11 13:40:14 UTC 2025: UPSNAME='dummy@localhost:12345' NOTIFYTYPE='ONBATT' args=BATT-STATUS-5s<br> 30.051445 [D3:7373] Ending sock_read() on a good note: try to use command:<br> 30.051489 [D3:7373] arg 0: CANCEL<br> 30.051496 [D3:7373] arg 1: BATT-STATUS-1s</div><div><br></div><div>It seems that sometimes timer calls can happen before they get the cancel signal (processing the list and calling the commands can take a while), note the jump from 27.x to 30.x seconds and call to handle
BATT-STATUS-5s
even though we are already processing cancellation of
BATT-STATUS-1s and would likely get to cancel 5s in a moment.</div><div><br></div><div>...</div><div> 0.020701 [D2:7720] parse_at: is '*' in AT command the 'dummy@localhost:12345' we were launched to process?<br> 0.020727 [D1:7720] parse_at: this AT command is for a wildcard: matched<br> 0.020733 [D1:7720] parse_at: processing CANCEL-TIMER<br> 30.051843 [D3:7373] closing connection on fd 16<br> 30.051897 [D3:7373] new connection on fd 16<br> 30.051963 [D3:7373] Ending sock_read() on a good note: try to use command:<br> 30.051992 [D3:7373] arg 0: CANCEL<br> 30.052021 [D3:7373] arg 1: BATT-STATUS-2s<br> 0.021220 [D2:7720] parse_at: is '*' in AT command the 'dummy@localhost:12345' we were launched to process?<br> 0.021250 [D1:7720] parse_at: this AT command is for a wildcard: matched<br> 0.021290 [D1:7720] parse_at: processing CANCEL-TIMER<br> 30.052299 [D3:7373] closing connection on fd 16<br> 30.052340 [D3:7373] new connection on fd 16<br> 30.052392 [D3:7373] Ending sock_read() on a good note: try to use command:<br> 30.052415 [D3:7373] arg 0: CANCEL<br> 30.052420 [D3:7373] arg 1: BATT-STATUS-5s<br> 0.021601 [D2:7720] parse_at: is '*' in AT command the 'dummy@localhost:12345' we were launched to process?<br> 0.021626 [D1:7720] parse_at: this AT command is for a wildcard: matched<br> 0.021631 [D1:7720] parse_at: processing CANCEL-TIMER<br> 30.052685 [D3:7373] closing connection on fd 16<br> 30.052727 [D3:7373] new connection on fd 16<br> 30.052781 [D3:7373] Ending sock_read() on a good note: try to use command:<br> 30.052804 [D3:7373] arg 0: CANCEL<br> 30.052810 [D3:7373] arg 1: BATT-STATUS-15s<br> 30.052831 Cancelling timer: BATT-STATUS-15s</div><div>...</div><div><br></div><div>Ultimately, what should matter for the `CMDSCRIPT` are its command-line arguments (technically, the first and only one). That alone dictates the operation it should run, regardless of the UPSNAME or NOTIFYTYPE values. It would probably be correct to unset those variables in the loop at least, or in the tool overall (to not imply any guarantees of anything related to those strings).</div><div><br></div><div>If timers or executions relate to a particular UPS, name it in the `AT` line spec (instead of the asterisk) and track as an uniquely named timer to start or cancel.</div><div><br></div><div>That was a fun exploration, thanks for the nudge!</div><div><br></div><div>Jim Klimov</div><div><br></div><div><br></div></div><br><div class="gmail_quote gmail_quote_container"><div dir="ltr" class="gmail_attr">On Tue, Apr 8, 2025 at 10:59 AM RemiG <<a href="mailto:mailing-nut@dbmtechnologies.com">mailing-nut@dbmtechnologies.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>
<p><font face="monospace">Hi for all<br>
<br>
an other one with same wrong NOTIFYTYPE (my supposition) (</font><font face="monospace"><span style="font-family:monospace"><span style="color:rgb(0,0,0);background-color:rgb(255,255,255)">ups.mfr:
EATON, </span>ups.model: Ellipse PRO 1600)<br>
</span><br>
upsmon says NOTIFYTYPE = ONBATT</font></p>
<p><font face="monospace">upssched create a time associated to this
Event => BATT-STATUS-5 (but Power return before 5 minutes ;-)
so ... )<br>
upsmon says NOTIFYTYPE = ONLINE</font></p>
<p>
</p>
<p><font face="monospace">upssched.conf delete this Event =>
BATT-STATUS-5, </font><font face="monospace"><font face="monospace">BATT-STATUS-10</font></font></p>
<p><font face="monospace">upssched create a TIMER associated to this
Event => LINE-STATUS-5 and so on<br>
<br>
</font></p>
<p><font face="monospace">and after all other timers created by
ONLINE => LINE-STATUS-5, LINE-STATUS-10</font></p>
<p><font face="monospace">sent ENV var NOTIFYTYPE to
/bin/upssched-cmd bash script => ONBATT (but upsc
UPS@localhost read ups.status : OL CHRG )</font></p>
<p><font face="monospace"><br>
</font></p>
<p><font face="monospace">Isn't it strange ONBATT / OL CHGR<br>
</font></p>
<p><font face="monospace"><span style="color:rgb(0,0,0);background-color:rgb(255,255,255)">root@greg:~#
grep " ups" /var/log/syslog
</span><br>
Apr 8 10:07:33 greg upsmon[32507]: Onduleur UPS1@localhost en
mode Secours sur batterie
<br>
Apr 8 10:07:33 greg upssched[17464]: Executing command: ONBATT
<br>
Apr 8 10:07:34 greg upssched-cmd-received-NOTIFYTYPE: ONBATT
<br>
Apr 8 10:07:34 greg upssched-cmd-read-Upsc_ups_status: OB
DISCHRG
<br>
Apr 8 10:07:34 greg upssched[17497]: Timer daemon started
<br>
Apr 8 10:07:34 greg upssched[17497]: New timer: BATT-STATUS-5
(300 seconds)
<br>
Apr 8 10:07:34 greg upssched[17497]: New timer: BATT-STATUS-10
(600 seconds)
<br>
Apr 8 10:08:03 greg upsmon[32507]: Onduleur UPS1@localhost en
mode Secteur : recharge batterie en cours
<br>
Apr 8 10:08:03 greg upssched[17516]: Executing command: ONLINE
<br>
Apr 8 10:08:03 greg upssched-cmd-received-NOTIFYTYPE: ONLINE
<br>
Apr 8 10:08:03 greg upssched-cmd-read-Upsc_ups_status: OL CHRG
<br>
Apr 8 10:08:04 greg upssched[17497]: Cancelling timer:
BATT-STATUS-5
<br>
Apr 8 10:08:04 greg upssched[17497]: Cancelling timer:
BATT-STATUS-10
<br>
Apr 8 10:08:04 greg upssched[17497]: New timer: LINE-STATUS-5
(300 seconds)
<br>
Apr 8 10:08:04 greg upssched[17497]: New timer: LINE-STATUS-10
(600 seconds)
<br>
</font><span style="font-family:monospace"><span style="font-family:monospace"><span style="color:rgb(0,0,0);background-color:rgb(255,255,255)">Apr 8
10:13:04 greg upssched[17497]: Event: LINE-STATUS-5
</span><br>
Apr 8 10:13:04 greg upssched-cmd-received-NOTIFYTYPE: ONBATT
<br>
Apr 8 10:13:04 greg upssched-cmd-read-Upsc_ups_status: OL
CHRG
<br>
Apr 8 10:18:04 greg upssched[17497]: Event: LINE-STATUS-10
<br>
Apr 8 10:18:05 greg upssched-cmd-received-NOTIFYTYPE: ONBATT
<br>
Apr 8 10:18:05 greg upssched-cmd-read-Upsc_ups_status: OL
CHRG<br>
</span></span>-- </p>
<blockquote type="cite">
<div class="gmail_quote">
<blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex">
<div>
<pre cols="72"># admin linux only ;-)</pre>
</div>
_______________________________________________<br>
Nut-upsuser mailing list<br>
<a href="mailto:Nut-upsuser@alioth-lists.debian.net" target="_blank">Nut-upsuser@alioth-lists.debian.net</a><br>
<a href="https://alioth-lists.debian.net/cgi-bin/mailman/listinfo/nut-upsuser" rel="noreferrer" target="_blank">https://alioth-lists.debian.net/cgi-bin/mailman/listinfo/nut-upsuser</a><br>
</blockquote>
</div>
</blockquote>
<pre cols="72">--
# admin linux only ;-)</pre>
</div>
</blockquote></div>