Multiple outputs at the same change

[Pauge26]

My Power saver Best save-node sends more outputs when the node should send on or off.

Here is a picture from my sensor output this night; At 3- and 5 the node sends both on and off, and this seems a bit randomely.

I had the same experience yesterday when I got 6 ouput messages with false from "off" and 1 with true from "on". (The false messages came before the on message, but the clock for sending was the same xx.59.59.

Is this the right behaviour?

I use version 3.0.10 in NodeRED and my flow is under here: https://pastebin.com/uya2s7vr I appreciate your work with the nodes!

[Pauge26]

Here is data from the debug node from the "off"-output now. Seems like the "Best save" node sends a lot of outputs.

29.12.2021, 20:00:00node: OFF
msg.payload : boolean
false
29.12.2021, 20:00:00node: OFF
msg.payload : boolean
false
29.12.2021, 20:00:01node: OFF
msg.payload : boolean
false
29.12.2021, 20:00:02node: OFF
msg.payload : boolean
false
29.12.2021, 20:00:03node: OFF
msg.payload : boolean
false
29.12.2021, 20:00:04node: OFF
msg.payload : boolean
false
29.12.2021, 20:00:05node: OFF
msg.payload : boolean
false
29.12.2021, 20:00:06node: OFF
msg.payload : boolean
false
29.12.2021, 20:00:07node: OFF
msg.payload : boolean
false
29.12.2021, 20:00:08node: OFF
msg.payload : boolean
false
29.12.2021, 20:00:09node: OFF
msg.payload : boolean
false
29.12.2021, 20:00:10node: OFF
msg.payload : boolean
false
29.12.2021, 20:00:11node: OFF
msg.payload : boolean
false
29.12.2021, 20:00:12node: OFF
msg.payload : boolean
false
29.12.2021, 20:00:13node: OFF
msg.payload : boolean
false
29.12.2021, 20:00:13node: OFF
msg.payload : boolean
false
29.12.2021, 20:00:13node: OFF
msg.payload : boolean
false

Schedule from 19.00

{
    "schedule": [
        {
            "time": "2021-12-29T20:00:00+01:00",
            "value": false
        },
        {
            "time": "2021-12-29T22:00:00+01:00",
            "value": true
        },
        {
            "time": "2021-12-30T00:00:00+01:00",
            "value": false
        },
        {
            "time": "2021-12-30T02:00:00+01:00",
            "value": true
        },
        {
            "time": "2021-12-30T18:00:00+01:00",
            "value": false
        },
        {
            "time": "2021-12-30T20:00:00+01:00",
            "value": true
        },
        {
            "time": "2021-12-30T21:00:00+01:00",
            "value": false
        },
        {
            "time": "2021-12-30T23:00:00+01:00",
            "value": true
        }
    ],

[ottopaulsen]

Jeg kan ikke umiddelbart se hvorfor dette skjer. Har du krysset av for at Best Save skal sende data ved rescheduling? Du kan evt. sjekke om det er en sammenheng der ved å debugge også når den mottar data inn.

[Pauge26]

Mystisk.. Har fulgt med litt de siste timene;

Klokken 20: Config Best-save node: (Send When Rescheduling = true)

maxHoursToSaveInSequence: "2"
minHoursOnAfterMaxSequenceSaved: "1"
minSaving: 0.02
sendCurrentValueWhenRescheduling: true
outputIfNoSchedule: true
scheduleOnlyFromCurrentTime: true

Usikker på antallet meldinger som gikk inn, men antar det var samme antall som test kl. 22, altså 1 melding inn til best-save node. Her gikk det fra sparing på (off), til sparing av (on). På dette tidspunktet ble det sendt 24 "false"-beskjeder fra "off"-outputen.

Klokken 22: Config Best-save node: (Send When Rescheduling = false)

maxHoursToSaveInSequence: "2"
minHoursOnAfterMaxSequenceSaved: "1"
minSaving: 0.02
sendCurrentValueWhenRescheduling: false
outputIfNoSchedule: true
scheduleOnlyFromCurrentTime: true

I denne sekvensen kom det en melding fra state node (Nordpool sensor) til Price reciever. Fra price reciever gikk det en melding inn til best-save node, og denne sendte 6 "false"-beskjeder fra "off"-outputen.

Har logg på output fra schedule og antall sendte true/false-beskjeder som kan oversendes dersom det er av interesse :)

[ottopaulsen]

Do you by any chance have a time property in the payload sent to the Best Save node? (There is not supposed to be one, but I use it for testing purposes, and that could cause such issues.)

[pittbull]

Jeg har også tilsvarende problem med "best save"-noden. Hørte en innfernalsk lyd fra vaskerommet og det viste seg at Aeotec switchen på VVB slo seg av og på en haug med ganger. Jeg har også satt en notify til telefonen nå i starten så jeg kan følge med og det rant inn med meldinger.

Kjører standard konfig fra deg og kun lagt add-tariff mellom price og save noden.

Noen tips til feilsøkning?

[ottopaulsen]

Prøv å finn ut om dette skjer når det kommer priser og planen oppdateres, eller om det skjer til andre tidspunkt, når den bare skal endre planen. Jeg vil tippe at det er når den replanlegger, men greit å være sikker på det.

Også, prøv å ta vare på input til Best Save-noden, og output på utg 3 når dette skjer. Kanskje hvis jeg får riktig input og output, at jeg kan klare å gjenskape det.

[pittbull]

Tror det er under replanlegging men skal koble på noen debug noder og så ser vi i morgen 👍🏼

[ottopaulsen]

In the latest version there is a time property in the output. Please verify that it is equal to the time that the planning is actually happening.

[ottopaulsen]

Please try version 3.2.1. I found a bug that may actually have caused these problems. Looking forward to hearing from you.

[pittbull]

Will update and report.

[pittbull]

Updated, and next change scheduled for 10 am in the morning. Will update after that.

[pittbull]

At 10 am I recieved 14 notifications on my phone suggesting the best node executed 14 times. I checked the VVB and it was only turned off once according to the history in HA.

[pittbull]

Not sure what debug logs you want but here's most of them:

From price receiver:

{"priceData":[{"value":1.86,"start":"2022-01-08T00:00:00+01:00"},{"value":1.83,"start":"2022-01-08T01:00:00+01:00"},{"value":1.81,"start":"2022-01-08T02:00:00+01:00"},{"value":1.83,"start":"2022-01-08T03:00:00+01:00"},{"value":1.84,"start":"2022-01-08T04:00:00+01:00"},{"value":1.84,"start":"2022-01-08T05:00:00+01:00"},{"value":1.84,"start":"2022-01-08T06:00:00+01:00"},{"value":1.84,"start":"2022-01-08T07:00:00+01:00"},{"value":1.87,"start":"2022-01-08T08:00:00+01:00"},{"value":1.9,"start":"2022-01-08T09:00:00+01:00"},{"value":1.94,"start":"2022-01-08T10:00:00+01:00"},{"value":1.93,"start":"2022-01-08T11:00:00+01:00"},{"value":1.93,"start":"2022-01-08T12:00:00+01:00"},{"value":1.9,"start":"2022-01-08T13:00:00+01:00"},{"value":1.9,"start":"2022-01-08T14:00:00+01:00"},{"value":1.93,"start":"2022-01-08T15:00:00+01:00"},{"value":1.96,"start":"2022-01-08T16:00:00+01:00"},{"value":1.9,"start":"2022-01-08T17:00:00+01:00"},{"value":1.86,"start":"2022-01-08T18:00:00+01:00"},{"value":1.76,"start":"2022-01-08T19:00:00+01:00"},{"value":1.6,"start":"2022-01-08T20:00:00+01:00"},{"value":1.59,"start":"2022-01-08T21:00:00+01:00"},{"value":1.54,"start":"2022-01-08T22:00:00+01:00"},{"value":1.53,"start":"2022-01-08T23:00:00+01:00"}],"source":"Nordpool"}

From Best save: [{"time":"2022-01-08T11:00:00+01:00","value":true},{"time":"2022-01-08T16:00:00+01:00","value":false},{"time":"2022-01-08T20:00:00+01:00","value":true},{"time":"2022-01-08T21:00:00+01:00","value":false},{"time":"2022-01-08T23:00:00+01:00","value":true}]

[{"price":1.93,"onOff":true,"start":"2022-01-08T11:00:00+01:00","saving":null},{"price":1.93,"onOff":true,"start":"2022-01-08T12:00:00+01:00","saving":null},{"price":1.9,"onOff":true,"start":"2022-01-08T13:00:00+01:00","saving":null},{"price":1.9,"onOff":true,"start":"2022-01-08T14:00:00+01:00","saving":null},{"price":1.93,"onOff":true,"start":"2022-01-08T15:00:00+01:00","saving":null},{"price":1.96,"onOff":false,"start":"2022-01-08T16:00:00+01:00","saving":0.36},{"price":1.9,"onOff":false,"start":"2022-01-08T17:00:00+01:00","saving":0.3},{"price":1.86,"onOff":false,"start":"2022-01-08T18:00:00+01:00","saving":0.26},{"price":1.76,"onOff":false,"start":"2022-01-08T19:00:00+01:00","saving":0.16},{"price":1.6,"onOff":true,"start":"2022-01-08T20:00:00+01:00","saving":null},{"price":1.59,"onOff":false,"start":"2022-01-08T21:00:00+01:00","saving":0.06},{"price":1.54,"onOff":false,"start":"2022-01-08T22:00:00+01:00","saving":0.01},{"price":1.53,"onOff":true,"start":"2022-01-08T23:00:00+01:00","saving":null}]

{"maxHoursToSaveInSequence":"4","minHoursOnAfterMaxSequenceSaved":"1","minSaving":0.03,"sendCurrentValueWhenRescheduling":true,"outputIfNoSchedule":true,"scheduleOnlyFromCurrentTime":true}

[ottopaulsen]

I prefer to get the complete payload of output 3 on the best save node. Then I can verify what version that is actually running. You did restart Node-RED after installing version 3.2.1, right?

[ottopaulsen]

Ok, new attempt. Thank you for being so patient :-) I found another detail that may have caused the problems. Please try version 3.2.2.

[pittbull]

My pleasure. These nodes will solve many of my issues so thank YOU for taking your time.

How would I go about giving you the proper debug data?

And yes, I did restart Node-red.

[ottopaulsen]

A debug node on output 3, and copy the complete output (payload) of this, not just some of the properties, as you did above. Maybe easier if you log the complete msg object in the debug node, not only the payload.

But I am more curious on the result of the latest change :-)

[pittbull]

I was unable to copy the entite msg object that's why I did it in pieces, but will recheck.

Next schedule is at 4 pm - fingers crossed.

[pittbull]

Worked like a charm - One notification, one action! Perfect 😊

Thank you kindly for assisting.

[ottopaulsen]

Nice! Thank you for helping finding the bug. @Pauge26 , does it work for you to? (Make sure you use version 3.2.2)

[pittbull]

No worries - that's just fun.

Now on to trying to learn how to get an entity into HA which visualises the scheduler with on/off 😄.

[pittbull]

Not sure if I should continue on this or start a new one, but woke up today and my VVB had been off since 1 am. According to the debug log it should've been turned on at 4 am (power saver disabled), but the best node sent an "on" command.

Something is not correct now as it seem to never disable power saving mode.

I have restarted NR and the best node reported 4 changes: "on" at 11 am. I was watching the flow and it did not execute the "on" at 11. I have disconnected the switches from the but have kept the notifications.

[Pauge26]

Nice! Thank you for helping finding the bug. @Pauge26 , does it work for you to? (Make sure you use version 3.2.2)

Yes, works like a charm here too. Thanks for fixing this @ottopaulsen and for helping to find the bug @pittbull! 😃

I have not experienced any problems like mentioned over, yet.. Anyway I reccomend to open a new issue on this one @pittbull. Closing this case!

[ottopaulsen]

Ok, @pittbull, let us keep this open for a while. Please report any more findings. I will see if I can find anything.

[pittbull]

Update: Having restarted and updated the flow the new schedule is: on from 11-16, and off from 16-20. It executed an "on" both at 11 and 12 so fingers crossed.

I have a feeling that something happens when working in NR and doing multiple updates and price retriveals - but I have no concrete evidence.

[ottopaulsen]

The latest bug I fixed was related to what you suspect. There is a timeout waiting for the next switch. When prices was received, a new timeout was generated without clearing the old, so both would turn the switch. Next time price was received there would be three, and so on. But I hope I managed to fix that in 3.2.2.

[pittbull]

According to the schedule mentioned above it should've enabled the power saver from 4 pm - that didn't happen.

Could a new schedule have been received in the mean time?

Edit: and to answer my own question - of course, since the flow is initiated every 60 minutes. :)

That does make it a bit problematic to keep track as I was expecting something to happen which have been rescheduled. I also wonder about the logic behind why a saving schedule would be moved if already planned? Wouldn't this mean that we will miss a saving opportunity?

[ottopaulsen]

Are you talking about the Power Saver node or the ps-strategy-best-save node? I assume the latter. If the prices received are the same, the plan should be the same. However, if you just received tomorrows prices, that may in theory affect the schedule now, but that depends on your settings. But if you look at the schedule on output 3, you can see what it should have done at 16:00.

[pittbull]

Are you talking about the Power Saver node or the ps-strategy-best-save node?

I assume the latter.

Indeed I refer to the best-save node.

If the prices received are the same, the plan should be the same. However, if you just received tomorrows prices, that may in theory affect the schedule now, but that depends on your settings.

That's what I find strange because having debugged a few times now I can see it rescheduling when I manually update the flow.

But if you look at the schedule on output 3, you can see what it should have done at 16:00.

The schedule I looked at arround 1200 today, were supposed to turn off VVB at 4, but the schdule changed some time inbetween resulting in an on at 4.

So - for my understanding - should the flow be left to itself and reschedule on it's own without any human interruption? 😊

[pittbull]

I think the issue with rescheduling is that at the top of the hour, that last hour moves out of the array and a new hour enters at the top of the array: Now before 1900 the best-node reported "6 changes, on at 1900", and then "6 changes off at 2300". Then I forced an update and it rescheduled to "8 changes, off at 2100". This must be due to the values of the one hour moving out and the new hour coming in resulting in different math and hence schedules.

Just a thought, but maybe a consistent schedule pr. 24 hours would be better?

[ottopaulsen]

The schedule is created for the timeframe you receive prices for, normally one or two days. I assume you received prices for tomorrow around 13:00, so that could affect the schedule.

[pittbull]

Agreed - but the schedules continue to change through out the afternoon and evening as well indicating that something else is contributing.

[pittbull]

I have switched to 'schedule for': whole data set to see if this keeps it more stable.

[ottopaulsen]

That is interesting. Please let me know what you find.

[pittbull]

My observations are these:

if running with schedule: 'whole data set' the schedule only change when tomorrows prices are retrieved.

if running with schedule: 'from current hour' the schedules will change more often.

I say 'more often' because I have not had time to debug exactly how often.

My thinking: If 'whole data set' means from 00:00 today until 23:59 tomorrow the hours remains constant. And if 'from current hour' means from now and 48 hours ahead, then the schedules will have to change because the data set will change more frequently. Not sure if this makes sense though.

[pittbull]

I have been running very consistent the last week using whole data set scheduling, so on my part this issue can be closed.

[ottopaulsen]

schedule: 'from current hour' is removed in version 3.3.0 Please verify that this works ok now.

[pittbull]

Confirming that 3.3.0 works on my part.