Thousands of message sent from Time Node

[nabahr]

Describe the bug

I have suspected that my Time nodes are sending multiple messages for a while. I use Time Nodes in a few places. One is to start automations each morning for our alarms to wake up in the morning, and every single morning my Node red instance goes crazy with disconnects from Home Assistant but the automation itself seemed to work ok, but with weird behavior sometimes.
Some other uses trigger TTS messages to play at a certain time and I always get the message played multiple times.

So I set up a test, a time node using an input_datetime from home assistant, which has just a time set, and set to repeat everyday.
It triggered fine at first, I only got one message, so I tried changing the time of the input_datetime a few times to trigger it again and each time I only got one message. So I left the time set to "organically" have it trigger each day. The first day it was still fine, only one message. The second day, this morning, my log is filled with 1105 messages logged from the same Time node.

To Reproduce

Create a input_datetime entity in home assistant, set to just the time.
Create a Time Node in NR to trigger everyday based on the input_datetime.
Wire that to a debug node.
Wait a few days and see the log fill with extra messages.

Expected behavior

Only one message should be sent when the time is reached.

Screenshots

No response

Example Flow

No response

Environment Information

Version: 0.67.2

Home Assistant version: 2024.8.2
Companion version: 4.0.2

Node-RED version: 4.0.2
Docker: no
Add-on: no

Node.js version: v20.5.1 x64 linux
OS: Linux 5.15.143-1-pve x64

Additional context

No response

[nabahr]

This morning the same Time Node with the same input_datetime, completely unchanged, logged 1112 messages. There may have been even more because the last debug log has only half the message logged.

Also to add, each message is the same except for the _msgid, each id is unique.

[zachowj]

I set this up about four days ago, and since then, only one message has been logged each day.

[nabahr]

Yeah, I am not sure how to really continue digging into this one. Over the days I have made unrelated changes to my flows, etc. and it went back to sending just one message. That kept up for about 2 or 3 days but just this morning it did log 2 messages. I tried to do a little research in the cron library used to see if there are any known issues there but didn't find anything too conclusive. Closest I found was this closed issue

I run in proxmox and also did an upgrade and reboot this morning, so I suspect that I won't get multiples tomorrow morning when the next time node is supposed to trigger. If you have anything you want me to try just let me know.

[zachowj]

I've added logging for the creation and destruction of the cron job, as I suspected that something might not be getting cleaned up properly during node deployment. In my testing, everything appears to be functioning correctly.

This logging will be included in the next release. To view it, simply set the Node-RED log level to debug.

[nabahr]

Sounds good, I will keep an eye out for the update and let you know what I find.

[nabahr]

Well, I've kept my plugin up to date and in the meantime I've updated the host and node red and I haven't seen this issue again. Not sure what fixed it or if it was just a fluke but I think this can be closed.

[nabahr]

And of course, as soon as I close it then it happens again....this time it fired twice for every time node I have, starting a few days ago up until now. Unfortunately, I didn't have the debug logging enabled, so I will add that now and hopefully get it to happen again.

[nabahr]

Ok, I noticed after it happened again that it seemed to be tied to losing connection to home assistant....so I started just rebooting my HA VM and restarting HA a bunch until it happened that I see it create the cronjob twice. No indication that I can tell in the log for why so I included everything in the log starting at the previous reconnect, where the cronjob is only added once per time node, then another disconnect/reconnect where it gets added twice.
FYI, there are 6 total time nodes in my flows, 4 of which are named Alarm Clock, but they all have a different input_datetime entity.
ha-time-debug.txt

[zachowj]

It seems like this issue is caused by a race condition due to multiple events (e.g., HA ready, state changed, and HA running) triggering the cron job creation. I'll implement a safeguard to ensure that only one instance of the cron job can run at any given time.