Delay Not Working?

Ok, this one has me stumped. As I read the documentation, delay node should delay each message for X time, right? Whereas rate forces each message to be released (forward) at a given rate, right? This means that if I set delay to 1 second, or rate 1 per second, they should result in the same release of messages to continue in the given flow. Well, that is not what happens, rate does 1 message per second. But delay waits 1 second, then releases all the messages. Below are two flows that show this experience. Rate works as expected, but delay floods the flow with messages, only seems to wait on the every first message.

[{"id":"187bb91b.c1c1bf","type":"tab","label":"Diode 2.0","disabled":false,"info":""},{"id":"3a05401c.944778","type":"mqtt in","z":"187bb91b.c1c1bf","name":"Pi4ModelB0 (/+/diode/rate)","topic":"/+/diode/rate","qos":"2","datatype":"auto","broker":"2bb354fa.1c9e7c","x":130,"y":280,"wires":[["16b02af2.b7a285"]]},{"id":"5604f69d.db43","type":"debug","z":"187bb91b.c1c1bf","name":"Control?","active":true,"tosidebar":true,"console":false,"tostatus":false,"complete":"payload","targetType":"msg","x":980,"y":340,"wires":[]},{"id":"27fcbdf1.a4eac2","type":"comment","z":"187bb91b.c1c1bf","name":"1 Red (On)","info":"","x":90,"y":400,"wires":[]},{"id":"7e38d655.6e8cb8","type":"comment","z":"187bb91b.c1c1bf","name":"3 Green (On)","info":"","x":90,"y":480,"wires":[]},{"id":"21bfb633.fa2c62","type":"comment","z":"187bb91b.c1c1bf","name":"5 Blue (On)","info":"","x":90,"y":560,"wires":[]},{"id":"829a5c8f.af0878","type":"comment","z":"187bb91b.c1c1bf","name":"0 Reset (Red, Green, Blue, Off)","info":"","x":150,"y":360,"wires":[]},{"id":"8d8eb2b6.b43658","type":"comment","z":"187bb91b.c1c1bf","name":"2 Red (Off)","info":"","x":90,"y":440,"wires":[]},{"id":"f25c6964.8fb51","type":"comment","z":"187bb91b.c1c1bf","name":"4 Green (Off)","info":"","x":90,"y":520,"wires":[]},{"id":"1eec0595.e2d882","type":"comment","z":"187bb91b.c1c1bf","name":"6 Blue (Off)","info":"","x":90,"y":600,"wires":[]},{"id":"f344747c.d9a558","type":"comment","z":"187bb91b.c1c1bf","name":"7 None (No Op)","info":"","x":100,"y":640,"wires":[]},{"id":"e327ab6b.13d61","type":"switch","z":"187bb91b.c1c1bf","name":"Diode","property":"payload","propertyType":"msg","rules":[{"t":"eq","v":"0","vt":"num"},{"t":"eq","v":"1","vt":"num"},{"t":"eq","v":"2","vt":"num"},{"t":"eq","v":"3","vt":"num"},{"t":"eq","v":"4","vt":"num"},{"t":"eq","v":"5","vt":"num"},{"t":"eq","v":"6","vt":"num"},{"t":"eq","v":"7","vt":"num"},{"t":"eq","v":"8","vt":"str"},{"t":"eq","v":"9","vt":"str"},{"t":"else"}],"checkall":"false","repair":false,"outputs":11,"x":810,"y":240,"wires":[["1409a562.54d69b"],["5761cc63.916694"],["244918ba.31b848"],["1bf11721.075b39"],["ba2c33e2.bd9b38"],["928e28df.94a7c"],["fbe70b90.f49f38"],["fc2dd646.86cf7"],["fc2dd646.86cf7"],["fc2dd646.86cf7"],["5604f69d.db43"]]},{"id":"6a235c1c.fde5cc","type":"pi-gpiod out","z":"187bb91b.c1c1bf","name":"Pi4ModelB0 Board 36 GPIO 16 Wire Red","host":"localhost","port":8888,"pin":"16","set":true,"level":"0","out":"out","sermin":"1000","sermax":"2000","x":1480,"y":120,"wires":[]},{"id":"c00560cc.cf147","type":"pi-gpiod out","z":"187bb91b.c1c1bf","name":"Pi4ModelB0 Board 38 GPIO 20 Wire Green","host":"localhost","port":8888,"pin":"20","set":true,"level":"0","out":"out","sermin":"1000","sermax":"2000","x":1490,"y":180,"wires":[]},{"id":"46294057.ee4d9","type":"pi-gpiod out","z":"187bb91b.c1c1bf","name":"Pi4ModelB0 Board 40 GPIO 21 Wire Blue","host":"localhost","port":8888,"pin":"21","set":true,"level":"0","out":"out","sermin":"1000","sermax":"2000","x":1480,"y":240,"wires":[]},{"id":"8d6562c1.78a7b","type":"comment","z":"187bb91b.c1c1bf","name":"Ground (GND) GPIO 34 Wire Brown Or Gray","info":"","x":1450,"y":60,"wires":[]},{"id":"74f58e5b.3841c","type":"comment","z":"187bb91b.c1c1bf","name":"8 Pause","info":"","x":80,"y":680,"wires":[]},{"id":"7fe7d1c4.86e1f8","type":"comment","z":"187bb91b.c1c1bf","name":"9 Resume","info":"","x":80,"y":720,"wires":[]},{"id":"5761cc63.916694","type":"change","z":"187bb91b.c1c1bf","name":"On (Red)","rules":[{"t":"set","p":"payload","pt":"msg","to":"1","tot":"num"}],"action":"","property":"","from":"","to":"","reg":false,"x":1160,"y":80,"wires":[["6a235c1c.fde5cc"]]},{"id":"244918ba.31b848","type":"change","z":"187bb91b.c1c1bf","name":"Off (Red)","rules":[{"t":"set","p":"payload","pt":"msg","to":"0","tot":"num"}],"action":"","property":"","from":"","to":"","reg":false,"x":1160,"y":200,"wires":[["6a235c1c.fde5cc"]]},{"id":"fc2dd646.86cf7","type":"change","z":"187bb91b.c1c1bf","name":"None","rules":[{"t":"set","p":"payload","pt":"msg","to":"","tot":"num"}],"action":"","property":"","from":"","to":"","reg":false,"x":1150,"y":320,"wires":[[]]},{"id":"1409a562.54d69b","type":"change","z":"187bb91b.c1c1bf","name":"Reset","rules":[{"t":"set","p":"payload","pt":"msg","to":"0","tot":"num"}],"action":"","property":"","from":"","to":"","reg":false,"x":990,"y":160,"wires":[["244918ba.31b848","ba2c33e2.bd9b38","fbe70b90.f49f38"]]},{"id":"1bf11721.075b39","type":"change","z":"187bb91b.c1c1bf","name":"On (Green)","rules":[{"t":"set","p":"payload","pt":"msg","to":"1","tot":"num"}],"action":"","property":"","from":"","to":"","reg":false,"x":1170,"y":120,"wires":[["c00560cc.cf147"]]},{"id":"ba2c33e2.bd9b38","type":"change","z":"187bb91b.c1c1bf","name":"Off (Green)","rules":[{"t":"set","p":"payload","pt":"msg","to":"0","tot":"num"}],"action":"","property":"","from":"","to":"","reg":false,"x":1170,"y":240,"wires":[["c00560cc.cf147"]]},{"id":"928e28df.94a7c","type":"change","z":"187bb91b.c1c1bf","name":"On (Blue)","rules":[{"t":"set","p":"payload","pt":"msg","to":"1","tot":"num"}],"action":"","property":"","from":"","to":"","reg":false,"x":1160,"y":160,"wires":[["46294057.ee4d9"]]},{"id":"fbe70b90.f49f38","type":"change","z":"187bb91b.c1c1bf","name":"Off (Blue)","rules":[{"t":"set","p":"payload","pt":"msg","to":"0","tot":"num"}],"action":"","property":"","from":"","to":"","reg":false,"x":1160,"y":280,"wires":[["46294057.ee4d9"]]},{"id":"117042d.bfecfbd","type":"traffic","z":"187bb91b.c1c1bf","name":"Suspend Or Resume?","property_allow":"payload","filter_allow":"9","ignore_case_allow":false,"negate_allow":false,"send_allow":false,"property_stop":"payload","filter_stop":"8","ignore_case_stop":false,"negate_stop":false,"send_stop":false,"default_start":true,"differ":false,"x":620,"y":240,"wires":[["e327ab6b.13d61","8cf9e8d2.b9866"]]},{"id":"46db4069.55ef28","type":"mqtt out","z":"187bb91b.c1c1bf","name":"Pi4ModelB0 (/pi4modelb0/diode/delay)","topic":"/pi4modelb0/diode/delay","qos":"","retain":"","broker":"2bb354fa.1c9e7c","x":550,"y":860,"wires":[]},{"id":"8cf9e8d2.b9866","type":"debug","z":"187bb91b.c1c1bf","name":"Message","active":true,"tosidebar":true,"console":false,"tostatus":false,"complete":"payload","targetType":"msg","x":820,"y":120,"wires":[]},{"id":"1b8186c7.de1639","type":"inject","z":"187bb91b.c1c1bf","name":"Blue (On, Off) Delay","topic":"","payload":"9,0,5,6,5,6,5,6,5,6,5,6","payloadType":"str","repeat":"","crontab":"","once":false,"onceDelay":0.1,"x":130,"y":840,"wires":[["e9b6e608.6ec9e"]]},{"id":"16b02af2.b7a285","type":"delay","z":"187bb91b.c1c1bf","name":"Rate (1s)","pauseType":"rate","timeout":"1","timeoutUnits":"seconds","rate":"1","nbRateUnits":"1","rateUnits":"second","randomFirst":"1","randomLast":"5","randomUnits":"seconds","drop":false,"x":400,"y":280,"wires":[["117042d.bfecfbd"]]},{"id":"e9b6e608.6ec9e","type":"split","z":"187bb91b.c1c1bf","name":"","splt":",","spltType":"str","arraySplt":1,"arraySpltType":"len","stream":false,"addname":"","x":310,"y":840,"wires":[["46db4069.55ef28"]]},{"id":"5ce6999f.fa9d58","type":"delay","z":"187bb91b.c1c1bf","name":"Delay (1s)","pauseType":"delay","timeout":"1","timeoutUnits":"seconds","rate":"1","nbRateUnits":"1","rateUnits":"second","randomFirst":"1","randomLast":"5","randomUnits":"seconds","drop":false,"x":410,"y":200,"wires":[["117042d.bfecfbd"]]},{"id":"2c695837.f91bd","type":"mqtt out","z":"187bb91b.c1c1bf","name":"Pi4ModelB0 (/pi4modelb0/diode/rate)","topic":"/pi4modelb0/diode/rate","qos":"","retain":"","broker":"2bb354fa.1c9e7c","x":550,"y":780,"wires":[]},{"id":"5161d798.8ff088","type":"inject","z":"187bb91b.c1c1bf","name":"Blue (On, Off) Rate","topic":"","payload":"9,0,5,6,5,6,,5,6,5,6,5,6","payloadType":"str","repeat":"","crontab":"","once":false,"onceDelay":0.1,"x":130,"y":800,"wires":[["52d6278e.1e3238"]]},{"id":"52d6278e.1e3238","type":"split","z":"187bb91b.c1c1bf","name":"","splt":",","spltType":"str","arraySplt":1,"arraySpltType":"len","stream":false,"addname":"","x":310,"y":800,"wires":[["2c695837.f91bd"]]},{"id":"bbd61633.e0a768","type":"mqtt in","z":"187bb91b.c1c1bf","name":"Pi4ModelB0 (/+/diode/delay)","topic":"/+/diode/delay","qos":"2","datatype":"auto","broker":"2bb354fa.1c9e7c","x":140,"y":200,"wires":[["5ce6999f.fa9d58"]]},{"id":"2bb354fa.1c9e7c","type":"mqtt-broker","z":"","name":"Pi4ModelB0","broker":"pi4modelb0.dachshund-digital.org","port":"1883","clientid":"","usetls":false,"compatmode":true,"keepalive":"60","cleansession":true,"birthTopic":"","birthQos":"0","birthPayload":"","closeTopic":"","closeQos":"0","closePayload":"","willTopic":"","willQos":"0","willPayload":""}]

Oh, and running 1.0.6 at the moment. Plan to move to 1.1.0 soon.

Assuming multiple MQTT messages come in a burst 0.1 sec apart, they will all independently be delayed 1 second, and will therefore leave the delay node still 0.1 sec apart. Is this not what you're seeing?

This simplified code shows a slowed down version (3 messages two seconds apart being delayed by 10 seconds).

[{"id":"1367c0bf.2c59ff","type":"inject","z":"757bd7fd.b41a48","name":"","props":[{"p":"payload"},{"p":"topic","vt":"str"}],"repeat":"","crontab":"","once":false,"onceDelay":0.1,"topic":"","payload":"","payloadType":"date","x":120,"y":180,"wires":[["37e8796.d42f186","5de54ed9.2e329","166f04b1.64e49b"]]},{"id":"2da37d13.312ed2","type":"delay","z":"757bd7fd.b41a48","name":"","pauseType":"delay","timeout":"10","timeoutUnits":"seconds","rate":"1","nbRateUnits":"1","rateUnits":"second","randomFirst":"1","randomLast":"5","randomUnits":"seconds","drop":false,"x":480,"y":180,"wires":[["3c1a6c76.2a2844"]]},{"id":"3c1a6c76.2a2844","type":"debug","z":"757bd7fd.b41a48","name":"","active":true,"tosidebar":true,"console":false,"tostatus":false,"complete":"false","statusVal":"","statusType":"auto","x":640,"y":180,"wires":[]},{"id":"37e8796.d42f186","type":"delay","z":"757bd7fd.b41a48","name":"","pauseType":"delay","timeout":"2","timeoutUnits":"seconds","rate":"1","nbRateUnits":"1","rateUnits":"second","randomFirst":"1","randomLast":"5","randomUnits":"seconds","drop":false,"x":300,"y":140,"wires":[["2da37d13.312ed2"]]},{"id":"5de54ed9.2e329","type":"delay","z":"757bd7fd.b41a48","name":"","pauseType":"delay","timeout":"4","timeoutUnits":"seconds","rate":"1","nbRateUnits":"1","rateUnits":"second","randomFirst":"1","randomLast":"5","randomUnits":"seconds","drop":false,"x":300,"y":180,"wires":[["2da37d13.312ed2"]]},{"id":"166f04b1.64e49b","type":"delay","z":"757bd7fd.b41a48","name":"","pauseType":"delay","timeout":"6","timeoutUnits":"seconds","rate":"1","nbRateUnits":"1","rateUnits":"second","randomFirst":"1","randomLast":"5","randomUnits":"seconds","drop":false,"x":300,"y":220,"wires":[["2da37d13.312ed2"]]}]
1 Like

Yes as Michael says delay is just a time shift, it doesn't alter the gap between messages.

Right, but the way the documentation reads, on the node edit view, it says that the delay will happen on each message. That is NOT what is happening, I send 20 messages at the delay node, all 20 zip through, the 1 second wait is not honored per message. If I set the delay node to RATE limit it works. But the default delay node reads that it always applies delay ON each message. I have used the delay node before, using it to delay a loop cycle, and it behaved, more as I expected. But in the example I provided... it just lets everything pass after the initial delay. That is not how it is documented, IMHO. On, I don't get the backed up message counter on the node when this by-pass happens, so even if I set the delay per message (NOT using RATE) delay per message to 1 minute, I get all 20 messages in 1 minute. Not 20 messages in about 20 minutes.

Might I suggest changing the wording of the node documentation to make it clear what is expected. The word 'each' message in the default more of the node is misleading. Maybe it should say the FIRST message is delayed only, unless the RATE feature is used.

The delay is applied to each message independently of any other. A message is delayed for the amount of time specified from when it arrives at the node, not from when any previous one leaves.

Try one of the 'queue' nodes (you can find them in the Flow setion of this site, search for 'queue')

That would not be correct. The last message is also delayed by 1 minute. In other words it is sent out 1 minute after it is injected into the delay node, therefore it is delayed by 1 minute.

Well, then it is some type of bug, because unless I use the rate limit feature, the delay does NOT stop all the messages.

When this sort of thing happens - best thing is to post the simplest repeatable flow that shows the issue (preferably just using core nodes)

The behaviour of the delay node has caused newbies issues (inc myself) but over the years , it has always ended up being a mis-understanding of its behaviour rather than a bug

But of course, you might have actually discovered a real bug with it (or the an issue with the docs that needs clarifying)

I did just that, a flow that exhibits the odd behavior and one that does not. Are the flows I provided not exhibiting the behavior as I noted? True it may not be a bug, but just odd scenario.

The description says a delay per message. That is not happening per the example I provided. So then it was communicated that the feature is just a time shift, ok, then I get the behavior I see, I get a delay and then a flood of messages, depending on how the messages queue up. That is not what is noted on screen for the default configuration.
image
Note, action says 'Delay each message.' Well, that is definitely not happening. So either it is a bug, or the action description is misleading. The action delay each message suggests strongly, that each and every message will be delayed X time, i.e. 5 seconds per above graphic. The rate limit aspect of this node, does in fact do the exact behavior documented. But the default behavior does not agree with the action description of same.

That is exactly what the node does. Each message is delayed for 5 seconds from the point in time it arrives at the node. It doesn't change the rate of the messages. It applies a fixed delay to each individual message independently of any other message.

Right, so you get a flood of messages, because they are in parallel. Hence why I think the action description is misleading. Surely you can see that nothing in the action notes that there is any parallel processing taking place.

No you didn't.
You posted a flow which included nodes which are not core nodes.
I started to load your flow earlier today, but stopped when I realised that I would need to install additional nodes, when the problem as described is not connected to those nodes.

Ah, MQTT is is not core. Given what knolleary just posted, I see the behavior is consistent, so not a bug. The issue then becomes, IMHO, the action description is misleading. To which, semantically, the messages wait in parallel, if they arrive the same (or nearly the same time). I think it should say that for clarity.

There is nothing in the description about it being serial either. It says the delay is applied to each message. Messages arrive as separate, independent, events.

If you want rate limiting mode, use rate limiting mode.

Edit what wording would you suggest to help clarify the help?

No these nodes!

nodes

My suggestion would be in the description notes... qualify that delay timing starts at the point of message arrival to the node. This is true of rate limit, if set 2, then 2 messages wait, the go, then 2 more wait and then go. But default node set up, 100 messages wait for the delay then get released, if and when 100 messages hit the node at the same time. The situation I got into, with MQTT feeding 10 to 15 within a few milliseconds of each other. So I then saw 10 to 15 released in effect at the same time.

Oh... right. In reference to the nodes.

Consider this simple example. A function node sends two messages one after the other and a debug node (IN) records that they have entered the delay node. The delay node is set to Delay Each Message 10 seconds, the second debug node (OUT) records them coming out of the delay node.

As you can see, message 1 enters the delay node at 08:22:24 and is sent on at 08:22:34, so it has been delayed by 10 seconds. The second message enters just after it, so to the nearest second also at 08:22:34 and is sent on also at 08:22:34, so it has also been delayed by 10 seconds. So each message has been delayed by10 seconds as specified in the node config.

If there is a traffic jam that takes 10 minutes to get through would it not be correct to say that each vehicle is delayed by 10 minutes?

[{"id":"365ba426.4c392c","type":"debug","z":"bdd7be38.d3b55","name":"OUT","active":true,"tosidebar":true,"console":false,"tostatus":false,"complete":"payload","targetType":"msg","statusVal":"","statusType":"auto","x":610,"y":640,"wires":[]},{"id":"8324bdab.09a32","type":"inject","z":"bdd7be38.d3b55","name":"Go","props":[{"p":"payload"},{"p":"topic","vt":"str"}],"repeat":"","crontab":"","once":false,"onceDelay":0.1,"topic":"","payload":"","payloadType":"date","x":90,"y":640,"wires":[["59db579b.354b2"]]},{"id":"59db579b.354b2","type":"function","z":"bdd7be38.d3b55","name":"Send two messages","func":"return [[{payload: \"MESSAGE 1\"}, {payload: \"MESSAGE 2\"}]]","outputs":1,"noerr":0,"initialize":"","finalize":"","x":260,"y":640,"wires":[["859d1403.b7099","ca2df106.a6bdf8"]]},{"id":"859d1403.b7099","type":"delay","z":"bdd7be38.d3b55","name":"","pauseType":"delay","timeout":"10","timeoutUnits":"seconds","rate":"1","nbRateUnits":"1","rateUnits":"second","randomFirst":"1","randomLast":"5","randomUnits":"seconds","drop":false,"x":460,"y":640,"wires":[["365ba426.4c392c"]]},{"id":"ca2df106.a6bdf8","type":"debug","z":"bdd7be38.d3b55","name":"IN","active":true,"tosidebar":true,"console":false,"tostatus":false,"complete":"payload","targetType":"msg","statusVal":"","statusType":"auto","x":450,"y":580,"wires":[]}]

Once, quite some time ago in this thread, the actual behavior was explained, and clarified, the flooding of messages, if you will, made sense. I had 10 to 15 messages hit the delay node at almost identical times, so they will released at almost identical times. This, until qualified, seemed odd, given the wording of the action description.

My point being, it had to be explained and clarified. That means the action description is not clear to everyone. When one person misses something, many often do. So, my suggestion, IMHO, is valid, that a bit of clarification of how the default action of the node works, as a simple time shift, should be explained in more detail. Given my experience, IMHO it would seem appropriate.

The fact that we have discussed this at such length, does that not support my perspective at least in part? At the very least this thread, when others find it, because they found something odd with the delay node, will get greater clarification on same.