search

reinhard-brandstaedter / solarflow-control

A tool to automatically control Zendure's Solarflow hub with more flexibility to match home power demand
67 stars 12 forks source link

"Keep-Alive" for update triggers #190

Closed mavo closed 5 months ago

mavo commented 5 months ago

Hi @reinhard-brandstaedter,

I noticed, that in cases the demand prediction was wrong in one or the other way but then the demand stays stable, it happens that the output does not match whats actually reqiured. Here is an output of the log for the time:

2024-03-31 20:59:24,683:INFO: DTU triggers limit function: 415.6 : 498.5
2024-03-31 20:59:24,683:INFO: HUB: S:0.0W [ 0.0 ], B: 66% (64|68), V:49.0V (49.0|49.0), C:-495W, P:False, F:3.6h, E:39.1h, H:472W, L:800W
2024-03-31 20:59:24,687:INFO: INV: AC:450.8W, AC_Prediction: 391.4W, DC:474.4W, DC_prediction: 415.6W (0.0|0.0|240.4|234.0), L:1043.2W [1600W]
2024-03-31 20:59:24,687:INFO: SMT: T:ShellyEM3 P:3.1W [ -77.0,-77.2,2.7 ] Predict: 2.7W
2024-03-31 20:59:24,689:INFO: Direct connected panels (0.0W) can't cover demand (394.1W), trying to get rest from hub.
2024-03-31 20:59:24,689:INFO: Checking if Solarflow is willing to contribute 394.1W ...
2024-03-31 20:59:24,689:INFO: Based on time, solarpower ( 0.0W) minimum charge power (400W) and bypass state (False), hub could contribute 394.1W - Decision path: 2.1.
2024-03-31 20:59:24,689:INFO: Hub should contribute more (394.0W) than what we currently get from panels (0.0W), we will use the inverter for fast/precise limiting!
2024-03-31 20:59:24,689:INFO: Hub has just recently adjusted limit, need to wait until it is set again! Current limit: 800, new limit: 800
2024-03-31 20:59:24,689:INFO: Setting inverter output limit to 788W (1 min moving average of 197W x 4)
2024-03-31 20:59:24,690:INFO: Sun: 06:44 - 19:41 Demand: 394.1W, Panel DC: (0.0|0.0), Hub DC: (240.4|234.0), Inverter Limit: 788.0W, Hub Limit: 800.0W
2024-03-31 20:59:32,675:INFO: DTU triggers limit function: 376.7 : 415.6
2024-03-31 20:59:32,675:INFO: Rate limit on trigger function, last call was only 8.0s ago!
2024-03-31 20:59:36,563:INFO: Triggering telemetry update: iot/73bkTV/vSU06042/properties/read
2024-03-31 20:59:49,671:INFO: DTU triggers limit function: 407.1 : 376.7
2024-03-31 20:59:49,671:INFO: HUB: S:0.0W [ 0.0,0.0 ], B: 66% (64|68), V:49.0V (49.1|49.0), C:-445W, P:False, F:3.6h, E:39.1h, H:423W, L:800W
2024-03-31 20:59:49,675:INFO: INV: AC:407.5W, AC_Prediction: 386.2W, DC:428.8W, DC_prediction: 407.1W (0.0|0.0|217.3|211.5), L:1043.2W [1600W]
2024-03-31 20:59:49,675:INFO: SMT: T:ShellyEM3 P:47.9W [ -77.2,2.7,42.9,48.6 ] Predict: 48.6W
2024-03-31 20:59:49,676:INFO: Direct connected panels (0.0W) can't cover demand (434.8W), trying to get rest from hub.
2024-03-31 20:59:49,676:INFO: Checking if Solarflow is willing to contribute 434.8W ...
2024-03-31 20:59:49,677:INFO: Based on time, solarpower ( 0.0W) minimum charge power (400W) and bypass state (False), hub could contribute 434.8W - Decision path: 2.1.
2024-03-31 20:59:49,677:INFO: Hub should contribute more (434.0W) than what we currently get from panels (0.0W), we will use the inverter for fast/precise limiting!
2024-03-31 20:59:49,677:INFO: Not setting solarflow output limit to 800.0W as it is identical to current limit!
2024-03-31 20:59:49,677:INFO: Setting inverter output limit to 868W (1 min moving average of 217W x 4)
2024-03-31 20:59:49,677:INFO: Sun: 06:44 - 19:41 Demand: 434.8W, Panel DC: (0.0|0.0), Hub DC: (217.3|211.5), Inverter Limit: 868.0W, Hub Limit: 800.0W
2024-03-31 20:59:51,623:INFO: SMT triggers limit function: 44.879999999999995 -> 128.0
2024-03-31 20:59:51,623:INFO: Rate limit on trigger function, last call was only 2.0s ago!
2024-03-31 20:59:51,627:INFO: SMT triggers limit function: 20.2 -> 103.4
2024-03-31 20:59:51,627:INFO: Rate limit on trigger function, last call was only 2.0s ago!
2024-03-31 20:59:59,672:INFO: DTU triggers limit function: 440.1 : 407.1
2024-03-31 20:59:59,672:INFO: HUB: S:0.0W [ 0.0,0.0 ], B: 66% (64|68), V:49.0V (49.1|49.0), C:-453W, P:False, F:3.6h, E:39.1h, H:433W, L:800W
2024-03-31 20:59:59,675:INFO: INV: AC:434.7W, AC_Prediction: 417.5W, DC:457.6W, DC_prediction: 440.1W (0.0|0.0|231.9|225.7), L:1043.2W [1600W]
2024-03-31 20:59:59,677:INFO: SMT: T:ShellyEM3 P:7.9W [ -77.2,2.7,42.9,48.0,20.2 ] Predict: 103.4W
2024-03-31 20:59:59,680:INFO: Direct connected panels (0.0W) can't cover demand (520.9W), trying to get rest from hub.
2024-03-31 20:59:59,680:INFO: Checking if Solarflow is willing to contribute 520.9W ...
2024-03-31 20:59:59,680:INFO: Based on time, solarpower ( 0.0W) minimum charge power (400W) and bypass state (False), hub could contribute 520.9W - Decision path: 2.1.
2024-03-31 20:59:59,680:INFO: Hub should contribute more (520.0W) than what we currently get from panels (0.0W), we will use the inverter for fast/precise limiting!
2024-03-31 20:59:59,680:INFO: Hub has just recently adjusted limit, need to wait until it is set again! Current limit: 800, new limit: 800
2024-03-31 20:59:59,680:INFO: Not setting inverter output limit as it is identical to current limit!
2024-03-31 20:59:59,681:INFO: Sun: 06:44 - 19:41 Demand: 520.9W, Panel DC: (0.0|0.0), Hub DC: (231.9|225.7), Inverter Limit: 1040.0W, Hub Limit: 800.0W
2024-03-31 21:00:36,564:INFO: Triggering telemetry update: iot/73bkTV/vSU06042/properties/read
2024-03-31 21:01:36,564:INFO: Triggering telemetry update: iot/73bkTV/vSU06042/properties/read
2024-03-31 21:02:36,564:INFO: Triggering telemetry update: iot/73bkTV/vSU06042/properties/read

In this timeframe, the actual net power consumption (demand - battery discharge) of the house was ~80W lower. But as it was steady, the app did not notice the mismatch.

What I think can help is some sort of the way the app worked before. But maybe trigger only every 30s or so (as it otherwise would be a rollback to previous versions I guess^^).

Or maybe you can have some kind of a stack of a fixed size where the commands go in, so that you can process them in order (fifo) and drop older messages when the size is exceeded so that you have the most recent ones.

Best, MaVo

reinhard-brandstaedter commented 5 months ago

Hi @mavo

the prediction actually is updated on every reading from the smartmeter. There is a time-based stack (1min) of values where values get aggregated into 10s buckets. The predichtion in then based on the last minute and predicts the next 10s value.

In your log however I see only 5 values in the time interval, which could lead to a off prediction. Do you happen to know how often the Shelly3EM reports data?

mavo commented 5 months ago

Hey @reinhard-brandstaedter, the Shelly actually reports quite frequently. At least this is what I can see in home assistant, which uses the data provided. There is no direct setting in the Shelly ui that I could find. Imo it's reporting whenever a change happens.

I am also under the impression, that this also did not happen when I was using the dev build from ~24th of march. But this I cannot really guarantee and have to verify once more.

mavo commented 5 months ago

In this comment from 13days ago you can see, that the Shelly has more values. https://github.com/reinhard-brandstaedter/solarflow-control/issues/167#issuecomment-2005190745

Not quite sure, but didn't you - to have smoother steering work better - introduced something which determines when a change is significant enough to be counted, or do I have fever dreams? Could this interfere here as the changes are too often and therefore all not significant enough to be captured?

Edit: Looks like I indeed had fever dreams. However, I am still having the impression this worked in earlier versions, as the log output from above shows. I will switch to the dev build in question today once again and post some log lines + the image id for verification.

MaVo

mavo commented 5 months ago

So, went back to image from March, cannot confirm what I thought I saw. It's 5 values, sometimes I saw 6 but only very rarely happening.

What I could see, is that when I turn on and off the lights in my room, there is a change triggered in the app but suppressed by the rate limiting. However, the values in the past data of the Shelly are not impacted and stay at usually 5 entries.

2024-04-01 09:42:09,429:INFO: SMT triggers limit function: 211.3 -> 306.3
2024-04-01 09:42:09,429:INFO: HUB: S:221.3W [ 221.0,220.0,220.3,222.9 ], B: 97% (96|99), V:49.8V (49.8|49.8), C: 211W, P:False, F:16.3h, E:51.8h, H: 0W, L: 0W
2024-04-01 09:42:09,432:INFO: INV: AC:202.3W, AC_Prediction: 200.9W, DC:212.9W, DC_prediction: 211.4W (107.9|105.2|0.0|0.0), L:756.8W [1600W]
2024-04-01 09:42:09,434:INFO: SMT: T:ShellyEM3 P:211.6W [ 69.3,126.9,187.9,207.3,211.3 ] Predict: 306.3W
2024-04-01 09:42:09,437:INFO: Direct connected panels (213.1W) can't cover demand (507.2W), trying to get rest from hub.
2024-04-01 09:42:09,437:INFO: Checking if Solarflow is willing to contribute 294.1W ...
2024-04-01 09:42:09,437:INFO: Based on time, solarpower (221.3W) minimum charge power (400W) and bypass state (False), hub could contribute  0.0W - Decision path: 2.2.
2024-04-01 09:42:09,437:INFO: Hub has just recently adjusted limit, need to wait until it is set again! Current limit: 0, new limit: 0
2024-04-01 09:42:09,437:INFO: Solarflow is willing to contribute 0.0W!
2024-04-01 09:42:09,437:INFO: Adjusting inverter limit from 107.9W to 193.0W
2024-04-01 09:42:09,437:INFO: Direct connected panel limit is 192W.
2024-04-01 09:42:09,437:INFO: Setting inverter output limit to 764W (1 min moving average of 192W x 4)
2024-04-01 09:42:09,438:INFO: Sun: 06:41 - 19:42 Demand: 507.2W, Panel DC: (107.9|105.2), Hub DC: (0.0|0.0), Inverter Limit: 764.0W, Hub Limit: 0.0W
2024-04-01 09:42:09,441:INFO: SMT triggers limit function: 241.12 -> 287.1
2024-04-01 09:42:09,441:INFO: Rate limit on trigger function, last call was only 0.0s ago!
2024-04-01 09:42:09,445:INFO: SMT triggers limit function: 240.9 -> 287.0
2024-04-01 09:42:09,445:INFO: Rate limit on trigger function, last call was only 0.0s ago!
2024-04-01 09:42:13,427:INFO: SMT triggers limit function: 240.8 -> 286.9
2024-04-01 09:42:13,427:INFO: Rate limit on trigger function, last call was only 4.0s ago!
2024-04-01 09:42:13,431:INFO: SMT triggers limit function: 225.5 -> 276.7
2024-04-01 09:42:13,431:INFO: Rate limit on trigger function, last call was only 4.0s ago!
2024-04-01 09:42:13,435:INFO: SMT triggers limit function: 222.4 -> 274.7
2024-04-01 09:42:13,436:INFO: Rate limit on trigger function, last call was only 4.0s ago!
2024-04-01 09:42:14,430:INFO: SMT triggers limit function: 221.4 -> 274.0
2024-04-01 09:42:14,430:INFO: Rate limit on trigger function, last call was only 5.0s ago!
2024-04-01 09:42:14,433:INFO: SMT triggers limit function: 235.9 -> 283.7
2024-04-01 09:42:14,433:INFO: Rate limit on trigger function, last call was only 5.0s ago!
2024-04-01 09:42:14,437:INFO: SMT triggers limit function: 242.7 -> 288.2
2024-04-01 09:42:14,437:INFO: Rate limit on trigger function, last call was only 5.0s ago!
2024-04-01 09:42:18,424:INFO: SMT triggers limit function: 245.1 -> 299.6
2024-04-01 09:42:18,424:INFO: Rate limit on trigger function, last call was only 9.0s ago!
2024-04-01 09:42:18,427:INFO: SMT triggers limit function: 230.2 -> 284.7
2024-04-01 09:42:18,427:INFO: Rate limit on trigger function, last call was only 9.0s ago!
2024-04-01 09:42:18,431:INFO: SMT triggers limit function: 222.3 -> 276.8
2024-04-01 09:42:18,431:INFO: Rate limit on trigger function, last call was only 9.0s ago!
2024-04-01 09:42:20,435:INFO: SMT triggers limit function: 219.4 -> 273.9
2024-04-01 09:42:20,435:INFO: HUB: S:221.3W [ 221.0,220.0,220.3,222.9 ], B: 97% (96|99), V:49.8V (49.8|49.8), C: 211W, P:False, F:16.3h, E:51.8h, H: 0W, L: 0W
2024-04-01 09:42:20,438:INFO: INV: AC:202.3W, AC_Prediction: 200.9W, DC:212.9W, DC_prediction: 211.4W (107.9|105.2|0.0|0.0), L:763.2W [1600W]
2024-04-01 09:42:20,440:INFO: SMT: T:ShellyEM3 P:217.9W [ 126.9,187.9,207.3,211.3,219.4 ] Predict: 273.9W
2024-04-01 09:42:20,443:INFO: Direct connected panels (213.1W) can't cover demand (474.8W), trying to get rest from hub.
2024-04-01 09:42:20,443:INFO: Checking if Solarflow is willing to contribute 261.7W ...
2024-04-01 09:42:20,443:INFO: Based on time, solarpower (221.3W) minimum charge power (400W) and bypass state (False), hub could contribute  0.0W - Decision path: 2.2.
2024-04-01 09:42:20,443:INFO: Hub has just recently adjusted limit, need to wait until it is set again! Current limit: 0, new limit: 0
2024-04-01 09:42:20,443:INFO: Solarflow is willing to contribute 0.0W!
2024-04-01 09:42:20,443:INFO: Adjusting inverter limit from 107.9W to 193.0W
2024-04-01 09:42:20,443:INFO: Direct connected panel limit is 192W.
2024-04-01 09:42:20,443:INFO: Setting inverter output limit to 768W (1 min moving average of 192W x 4)
2024-04-01 09:42:20,444:INFO: Sun: 06:41 - 19:42 Demand: 474.8W, Panel DC: (107.9|105.2), Hub DC: (0.0|0.0), Inverter Limit: 768.0W, Hub Limit: 0.0W
2024-04-01 09:42:20,448:INFO: SMT triggers limit function: 233.39000000000001 -> 260.8
2024-04-01 09:42:20,448:INFO: Rate limit on trigger function, last call was only 0.0s ago!
2024-04-01 09:42:20,452:INFO: SMT triggers limit function: 235.6 -> 262.3
2024-04-01 09:42:20,452:INFO: Rate limit on trigger function, last call was only 0.0s ago!
2024-04-01 09:42:22,436:INFO: SMT triggers limit function: 236.7 -> 263.0
2024-04-01 09:42:22,436:INFO: Rate limit on trigger function, last call was only 2.0s ago!
2024-04-01 09:42:22,439:INFO: SMT triggers limit function: 247.0 -> 269.9
2024-04-01 09:42:22,440:INFO: Rate limit on trigger function, last call was only 2.0s ago!
2024-04-01 09:42:22,443:INFO: SMT triggers limit function: 251.5 -> 272.9
2024-04-01 09:42:22,444:INFO: Rate limit on trigger function, last call was only 2.0s ago!
2024-04-01 09:42:30,418:INFO: SMT triggers limit function: 252.6 -> 272.3
2024-04-01 09:42:30,418:INFO: Rate limit on trigger function, last call was only 10.0s ago!
2024-04-01 09:42:30,421:INFO: SMT triggers limit function: 233.5 -> 253.2
2024-04-01 09:42:30,421:INFO: Rate limit on trigger function, last call was only 10.0s ago!
2024-04-01 09:42:30,425:INFO: SMT triggers limit function: 228.7 -> 248.4
2024-04-01 09:42:30,425:INFO: Rate limit on trigger function, last call was only 10.0s ago!
2024-04-01 09:42:32,417:INFO: SMT triggers limit function: 227.1 -> 246.8
2024-04-01 09:42:32,417:INFO: HUB: S:220.8W [ 220.0,220.3,222.9,222.0,218.8 ], B: 97% (96|99), V:49.8V (49.8|49.8), C: 206W, P:False, F:16.3h, E:51.8h, H: 0W, L: 0W
2024-04-01 09:42:32,420:INFO: INV: AC:202.3W, AC_Prediction: 200.9W, DC:212.9W, DC_prediction: 211.4W (107.9|105.2|0.0|0.0), L:766.4W [1600W]
2024-04-01 09:42:32,422:INFO: SMT: T:ShellyEM3 P:226.3W [ 187.9,207.3,211.3,219.4,227.1 ] Predict: 246.8W
2024-04-01 09:42:32,425:INFO: Direct connected panels (213.1W) can't cover demand (447.7W), trying to get rest from hub.
2024-04-01 09:42:32,425:INFO: Checking if Solarflow is willing to contribute 234.6W ...
2024-04-01 09:42:32,425:INFO: Based on time, solarpower (220.8W) minimum charge power (400W) and bypass state (False), hub could contribute  0.0W - Decision path: 2.2.
2024-04-01 09:42:32,425:INFO: Hub has just recently adjusted limit, need to wait until it is set again! Current limit: 0, new limit: 0
2024-04-01 09:42:32,425:INFO: Solarflow is willing to contribute 0.0W!
2024-04-01 09:42:32,425:INFO: Adjusting inverter limit from 107.9W to 193.0W
2024-04-01 09:42:32,425:INFO: Direct connected panel limit is 192W.
2024-04-01 09:42:32,426:INFO: Setting inverter output limit to 768W (1 min moving average of 192W x 4)
2024-04-01 09:42:32,426:INFO: Sun: 06:41 - 19:42 Demand: 447.7W, Panel DC: (107.9|105.2), Hub DC: (0.0|0.0), Inverter Limit: 768.0W, Hub Limit: 0.0W
reinhard-brandstaedter commented 5 months ago

Generally the steering function is triggered like this: smartmeter values are taken as they come in. To accommodate for the different reporting intervals - some poste every second, some in 10s or more - these values are put into 10s buckets of a totsl buffer of 1 minute, where a weight is put on the last reported value in a 10s bucket. Then the prediction (linear regression) is calculated based on these values. So if there is significant change on the predicted value and the last smartmeter bucket, the limit function is called. If the limit function is called too often it is rate limited and only the last one is executed outside the rate limit.

So in theory this can lead to some initial false (over/under) prediction, which should then flatten out to the real usage (if usage is rather constant)

mavo commented 5 months ago

Mhhh, but then I don't get where it "fails" for me atm. Based on what I found in the great www is that the values are reported from the shellyem3 when they change. But if they do not change there is nothing new reported apparently.

How many values do you see on your log output?

I had a look at the night, and I actually fed in more than 10% of my battery to the grid last night. I never saw it like this before :-/

mavo commented 5 months ago

New Data, maybe helps to understand.

2024-04-01 20:42:17,783:INFO: SMT triggers limit function: -16.230000000000075 -> -44.1
2024-04-01 20:42:17,783:INFO: HUB: S:0.0W [ 0.0,0.0 ], B: 63% (61|66), V:47.8V (47.8|47.8), C:-520W, P:False, F:27.3h, E:62.8h, H:496W, L:800W
2024-04-01 20:42:17,786:INFO: INV: AC:478.9W, AC_Prediction: 486.6W, DC:504.0W, DC_prediction: 512.0W (0.0|0.0|255.5|248.5), L:968.0W [1600W]
2024-04-01 20:42:17,787:INFO: SMT: T:ShellyEM3 P:-16.2W [ -0.9,4.0,-22.1,-38.7,-16.2 ] Predict: -44.1W
2024-04-01 20:42:17,790:INFO: Direct connected panels (0.0W) can't cover demand (442.5W), trying to get rest from hub.
2024-04-01 20:42:17,791:INFO: Checking if Solarflow is willing to contribute 442.5W ...
2024-04-01 20:42:17,791:INFO: Based on time, solarpower ( 0.0W) minimum charge power (400W) and bypass state (False), hub could contribute 442.5W - Decision path: 2.1.
2024-04-01 20:42:17,791:INFO: Hub should contribute more (442.0W) than what we currently get from panels (0.0W), we will use the inverter for fast/precise limiting!
2024-04-01 20:42:17,791:INFO: Hub has just recently adjusted limit, need to wait until it is set again! Current limit: 800, new limit: 800
2024-04-01 20:42:17,791:INFO: Setting inverter output limit to 884W (1 min moving average of 221W x 4)
2024-04-01 20:42:17,791:INFO: Sun: 06:41 - 19:42 Demand: 442.5W, Panel DC: (0.0|0.0), Hub DC: (255.5|248.5), Inverter Limit: 884.0W, Hub Limit: 800.0W
2024-04-01 20:42:17,795:INFO: SMT triggers limit function: -1.2 -> -29.1
2024-04-01 20:42:17,795:INFO: Rate limit on trigger function, last call was only 0.0s ago!
2024-04-01 20:42:22,611:INFO: DTU triggers limit function: 501.9 : 538.7
2024-04-01 20:42:22,611:INFO: Rate limit on trigger function, last call was only 4.8s ago!
2024-04-01 20:42:37,609:INFO: DTU triggers limit function: 471.3 : 501.9
2024-04-01 20:42:37,609:INFO: HUB: S:0.0W [ 0.0,0.0 ], B: 63% (61|66), V:47.8V (47.8|47.8), C:-486W, P:False, F:27.3h, E:62.8h, H:463W, L:800W
2024-04-01 20:42:37,613:INFO: INV: AC:442.6W, AC_Prediction: 430.4W, DC:465.8W, DC_prediction: 471.3W (0.0|0.0|236.1|229.7), L:968.0W [1600W]
2024-04-01 20:42:37,613:INFO: SMT: T:ShellyEM3 P:39.7W [ 4.0,-22.1,-38.7,40.1 ] Predict: 40.1W
2024-04-01 20:42:37,614:INFO: Direct connected panels (0.0W) can't cover demand (470.5W), trying to get rest from hub.
2024-04-01 20:42:37,615:INFO: Checking if Solarflow is willing to contribute 470.5W ...
2024-04-01 20:42:37,615:INFO: Based on time, solarpower ( 0.0W) minimum charge power (400W) and bypass state (False), hub could contribute 470.5W - Decision path: 2.1.
2024-04-01 20:42:37,615:INFO: Hub should contribute more (470.0W) than what we currently get from panels (0.0W), we will use the inverter for fast/precise limiting!
2024-04-01 20:42:37,615:INFO: Not setting solarflow output limit to 800.0W as it is identical to current limit!
2024-04-01 20:42:37,615:INFO: Setting inverter output limit to 940W (1 min moving average of 235W x 4)
2024-04-01 20:42:37,615:INFO: Sun: 06:41 - 19:42 Demand: 470.5W, Panel DC: (0.0|0.0), Hub DC: (236.1|229.7), Inverter Limit: 940.0W, Hub Limit: 800.0W
2024-04-01 20:42:41,347:INFO: Triggering telemetry update: iot/73bkTV/vSU06042/properties/read
2024-04-01 20:43:41,347:INFO: Triggering telemetry update: iot/73bkTV/vSU06042/properties/read
2024-04-01 20:44:36,618:INFO: DTU triggers limit function: 502.3 : 471.3
2024-04-01 20:44:36,618:INFO: HUB: S:0.0W [ 0.0,0.0 ], B: 63% (61|65), V:47.8V (47.8|47.8), C:-508W, P:False, F:27.4h, E:62.9h, H:484W, L:800W
2024-04-01 20:44:36,622:INFO: INV: AC:474.8W, AC_Prediction: 477.2W, DC:499.7W, DC_prediction: 502.3W (0.0|0.0|253.3|246.4), L:939.2W [1600W]
2024-04-01 20:44:36,622:INFO: SMT: T:ShellyEM3 P:-12.7W [ -17.8,-2.4,-14.3 ] Predict: -14.3W
2024-04-01 20:44:36,623:INFO: Direct connected panels (0.0W) can't cover demand (462.9W), trying to get rest from hub.
2024-04-01 20:44:36,623:INFO: Checking if Solarflow is willing to contribute 462.9W ...
2024-04-01 20:44:36,624:INFO: Based on time, solarpower ( 0.0W) minimum charge power (400W) and bypass state (False), hub could contribute 462.9W - Decision path: 2.1.
2024-04-01 20:44:36,624:INFO: Hub should contribute more (462.0W) than what we currently get from panels (0.0W), we will use the inverter for fast/precise limiting!
2024-04-01 20:44:36,624:INFO: Not setting solarflow output limit to 800.0W as it is identical to current limit!
2024-04-01 20:44:36,624:INFO: Setting inverter output limit to 924W (1 min moving average of 231W x 4)
2024-04-01 20:44:36,624:INFO: Sun: 06:41 - 19:42 Demand: 462.9W, Panel DC: (0.0|0.0), Hub DC: (253.3|246.4), Inverter Limit: 924.0W, Hub Limit: 800.0W
2024-04-01 20:44:41,347:INFO: Triggering telemetry update: iot/73bkTV/vSU06042/properties/read
2024-04-01 20:45:41,348:INFO: Triggering telemetry update: iot/73bkTV/vSU06042/properties/read
2024-04-01 20:46:41,348:INFO: Triggering telemetry update: iot/73bkTV/vSU06042/properties/read
2024-04-01 20:47:41,348:INFO: Triggering telemetry update: iot/73bkTV/vSU06042/properties/read
2024-04-01 20:48:41,349:INFO: Triggering telemetry update: iot/73bkTV/vSU06042/properties/read
2024-04-01 20:49:41,349:INFO: Triggering telemetry update: iot/73bkTV/vSU06042/properties/read
2024-04-01 20:50:41,349:INFO: Triggering telemetry update: iot/73bkTV/vSU06042/properties/read
2024-04-01 20:51:41,350:INFO: Triggering telemetry update: iot/73bkTV/vSU06042/properties/read
2024-04-01 20:52:41,350:INFO: Triggering telemetry update: iot/73bkTV/vSU06042/properties/read
2024-04-01 20:53:41,350:INFO: Triggering telemetry update: iot/73bkTV/vSU06042/properties/read
2024-04-01 20:54:41,350:INFO: Triggering telemetry update: iot/73bkTV/vSU06042/properties/read
2024-04-01 20:55:41,351:INFO: Triggering telemetry update: iot/73bkTV/vSU06042/properties/read
2024-04-01 20:56:41,351:INFO: Triggering telemetry update: iot/73bkTV/vSU06042/properties/read
2024-04-01 20:57:41,351:INFO: Triggering telemetry update: iot/73bkTV/vSU06042/properties/read
2024-04-01 20:58:41,352:INFO: Triggering telemetry update: iot/73bkTV/vSU06042/properties/read
2024-04-01 20:58:45,462:INFO: SMT triggers limit function: -17.649999999999977 -> -61.1
2024-04-01 20:58:45,462:INFO: HUB: S:0.0W [ 0.0,0.0 ], B: 60% (57|62), V:47.6V (47.6|47.6), C:-500W, P:False, F:27.6h, E:63.1h, H:477W, L:800W
2024-04-01 20:58:45,465:INFO: INV: AC:462.8W, AC_Prediction: 462.9W, DC:487.1W, DC_prediction: 487.1W (0.0|0.0|246.9|240.2), L:923.2W [1600W]
2024-04-01 20:58:45,467:INFO: SMT: T:ShellyEM3 P:-17.6W [ -3.6,139.1,-21.9,-22.3,-17.6 ] Predict: -61.1W
2024-04-01 20:58:45,470:INFO: Direct connected panels (0.0W) can't cover demand (401.8W), trying to get rest from hub.
2024-04-01 20:58:45,470:INFO: Checking if Solarflow is willing to contribute 401.8W ...
2024-04-01 20:58:45,470:INFO: Based on time, solarpower ( 0.0W) minimum charge power (400W) and bypass state (False), hub could contribute 401.8W - Decision path: 2.1.
2024-04-01 20:58:45,470:INFO: Hub should contribute more (401.0W) than what we currently get from panels (0.0W), we will use the inverter for fast/precise limiting!
2024-04-01 20:58:45,470:INFO: Not setting solarflow output limit to 800.0W as it is identical to current limit!
2024-04-01 20:58:45,471:INFO: Setting inverter output limit to 800W (1 min moving average of 200W x 4)
2024-04-01 20:58:45,471:INFO: Sun: 06:41 - 19:42 Demand: 401.8W, Panel DC: (0.0|0.0), Hub DC: (246.9|240.2), Inverter Limit: 800.0W, Hub Limit: 800.0W
2024-04-01 20:58:45,475:INFO: SMT triggers limit function: -14.3 -> -57.7
2024-04-01 20:58:45,475:INFO: Rate limit on trigger function, last call was only 0.0s ago!
2024-04-01 20:58:47,463:INFO: SMT triggers limit function: -15.1 -> -58.5
2024-04-01 20:58:47,463:INFO: Rate limit on trigger function, last call was only 2.0s ago!
2024-04-01 20:58:47,467:INFO: SMT triggers limit function: -8.0 -> -51.4
2024-04-01 20:58:47,467:INFO: Rate limit on trigger function, last call was only 2.0s ago!
2024-04-01 20:58:47,470:INFO: SMT triggers limit function: 22.5 -> -20.9
2024-04-01 20:58:47,470:INFO: Rate limit on trigger function, last call was only 2.0s ago!
2024-04-01 20:58:48,463:INFO: SMT triggers limit function: 32.6 -> -10.8
2024-04-01 20:58:48,463:INFO: Rate limit on trigger function, last call was only 3.0s ago!
2024-04-01 20:58:48,467:INFO: SMT triggers limit function: 35.9 -> -7.5
2024-04-01 20:58:48,467:INFO: Rate limit on trigger function, last call was only 3.0s ago!
2024-04-01 20:58:52,607:INFO: DTU triggers limit function: 461.9 : 502.3
2024-04-01 20:58:52,607:INFO: Rate limit on trigger function, last call was only 7.1s ago!
2024-04-01 20:59:02,607:INFO: DTU triggers limit function: 425.0 : 461.9
2024-04-01 20:59:02,608:INFO: HUB: S:0.0W [ 0.0,0.0 ], B: 60% (57|62), V:47.6V (47.6|47.6), C:-457W, P:False, F:27.6h, E:63.1h, H:436W, L:800W
2024-04-01 20:59:02,611:INFO: INV: AC:409.5W, AC_Prediction: 408.9W, DC:431.1W, DC_prediction: 425.0W (0.0|0.0|218.0|212.1), L:923.2W [1600W]
2024-04-01 20:59:02,611:INFO: SMT: T:ShellyEM3 P:51.1W [ 139.1,-21.9,-22.3,51.0 ] Predict: 51.0W
2024-04-01 20:59:02,613:INFO: Direct connected panels (0.0W) can't cover demand (459.9W), trying to get rest from hub.
2024-04-01 20:59:02,613:INFO: Checking if Solarflow is willing to contribute 459.9W ...
2024-04-01 20:59:02,613:INFO: Based on time, solarpower ( 0.0W) minimum charge power (400W) and bypass state (False), hub could contribute 459.9W - Decision path: 2.1.
2024-04-01 20:59:02,613:INFO: Hub should contribute more (459.0W) than what we currently get from panels (0.0W), we will use the inverter for fast/precise limiting!
2024-04-01 20:59:02,613:INFO: Hub has just recently adjusted limit, need to wait until it is set again! Current limit: 800, new limit: 800
2024-04-01 20:59:02,613:INFO: Setting inverter output limit to 916W (1 min moving average of 229W x 4)
2024-04-01 20:59:02,614:INFO: Sun: 06:41 - 19:42 Demand: 459.9W, Panel DC: (0.0|0.0), Hub DC: (218.0|212.1), Inverter Limit: 916.0W, Hub Limit: 800.0W
2024-04-01 20:59:04,464:INFO: SMT triggers limit function: 49.75999999999999 -> -3.1
2024-04-01 20:59:04,465:INFO: Rate limit on trigger function, last call was only 1.9s ago!
2024-04-01 20:59:04,468:INFO: SMT triggers limit function: 11.4 -> -41.5
2024-04-01 20:59:04,468:INFO: Rate limit on trigger function, last call was only 1.9s ago!
2024-04-01 20:59:15,468:INFO: SMT triggers limit function: 3.640000000000043 -> 35.8
2024-04-01 20:59:15,468:INFO: HUB: S:0.0W [ 0.0,0.0 ], B: 60% (57|62), V:47.6V (47.6|47.6), C:-475W, P:False, F:27.6h, E:63.1h, H:453W, L:800W
2024-04-01 20:59:15,471:INFO: INV: AC:458.7W, AC_Prediction: 440.3W, DC:482.8W, DC_prediction: 443.5W (0.0|0.0|244.7|238.1), L:923.2W [1600W]
2024-04-01 20:59:15,473:INFO: SMT: T:ShellyEM3 P:3.6W [ -21.9,-22.3,51.1,7.3,3.6 ] Predict: 35.8W
2024-04-01 20:59:15,476:INFO: Direct connected panels (0.0W) can't cover demand (476.1W), trying to get rest from hub.
2024-04-01 20:59:15,476:INFO: Checking if Solarflow is willing to contribute 476.1W ...
2024-04-01 20:59:15,476:INFO: Based on time, solarpower ( 0.0W) minimum charge power (400W) and bypass state (False), hub could contribute 476.1W - Decision path: 2.1.
2024-04-01 20:59:15,476:INFO: Hub should contribute more (476.0W) than what we currently get from panels (0.0W), we will use the inverter for fast/precise limiting!
2024-04-01 20:59:15,476:INFO: Hub has just recently adjusted limit, need to wait until it is set again! Current limit: 800, new limit: 800
2024-04-01 20:59:15,476:INFO: Setting inverter output limit to 952W (1 min moving average of 238W x 4)
2024-04-01 20:59:15,477:INFO: Sun: 06:41 - 19:42 Demand: 476.1W, Panel DC: (0.0|0.0), Hub DC: (244.7|238.1), Inverter Limit: 952.0W, Hub Limit: 800.0W
2024-04-01 20:59:15,480:INFO: SMT triggers limit function: 13.7 -> 45.9
2024-04-01 20:59:15,480:INFO: Rate limit on trigger function, last call was only 0.0s ago!
2024-04-01 20:59:16,480:INFO: SMT triggers limit function: 13.7 -> 45.9
2024-04-01 20:59:16,481:INFO: Rate limit on trigger function, last call was only 1.0s ago!
2024-04-01 20:59:16,486:INFO: SMT triggers limit function: 14.8 -> 47.0
2024-04-01 20:59:16,486:INFO: Rate limit on trigger function, last call was only 1.0s ago!
2024-04-01 20:59:16,491:INFO: SMT triggers limit function: -4.4 -> 27.8
2024-04-01 20:59:16,491:INFO: Rate limit on trigger function, last call was only 1.0s ago!
2024-04-01 20:59:17,606:INFO: DTU triggers limit function: 461.8 : 425.0
2024-04-01 20:59:17,606:INFO: Rate limit on trigger function, last call was only 2.1s ago!

Between 20:44 and 20:58 just nothing was triggered, but as you can see in the screenshot, the SMT did report data. Also, when I triggered the blinds to go down, the demand significantly changed for about 30s, but nothing was triggered in the app. You can see this happening in the graph on 20:57:48 (UTC) and ended 20:58:13. Something another 30s later also used some energy and this somehow got the trigger to be activated. image

reinhard-brandstaedter commented 5 months ago

From the graph the shelly really just seems to update 5 times per minute. I also found this discussion where people also see this with some firmware change (https://community.home-assistant.io/t/shelly-reporting-frequency/615831). Some even complain that the new update ingluences their solar steering….hmm. Wondering how this could be worked around. Maybe a longer time window or a smaller trigger difference… In my case I get current power usage updates every 2s

reinhard-brandstaedter commented 5 months ago

Hi @mavo ,

can you try pushing regular updates, e.g. every 2 seconds by following this example: https://shelly-api-docs.shelly.cloud/gen2/ComponentsAndServices/Mqtt/#step-10-generate-periodic-updates-over-mqtt-using-shelly-script

mavo commented 5 months ago

From the graph the shelly really just seems to update 5 times per minute. I also found this discussion where people also see this with some firmware change (https://community.home-assistant.io/t/shelly-reporting-frequency/615831). Some even complain that the new update ingluences their solar steering….hmm. Wondering how this could be worked around. Maybe a longer time window or a smaller trigger difference… In my case I get current power usage updates every 2s

Yeah, I found the same. But they are talking about shellyem3 pro. Whereas I am using the non-pro shelly3.

image

This is a picture of the current values reported from shelly. There are indeed phases of reports only every 15s (between 9:00:30 and 9:00:55. However, at ~9:01 there are values reported every second, if they change.

reinhard-brandstaedter commented 5 months ago

I don't think that the behavior is different on the Shelly Pro vs Non-Pro. At least from the changelog of the firmware it seems shared between all devices. Any detected change of 10W difference should try to trigger a adaption of limits (in case it's within a rate limit). So I'd still like to try a constant time-based reporting of the shelly. The SMT buffer should always be filled with 5-7 values. Maybe what happens on your side is that the buffer gets emptied due to low amount of data coming in.

Mine typically looks like this:

2024-04-02 10:04:33,904:INFO: SMT triggers limit function: 85.0 -> 98.0
2024-04-02 10:04:33,904:INFO: HUB: S:453.3W [ 474.7,476.5,409.7,448.5,477.4,455.7,445.8 ], B: 12% (13|11|12), V:48.6V (48.6|48.7|48.6), C: 190W, P:False, F:65.1h, E:1.7h, H:245W, L:700W
2024-04-02 10:04:33,906:INFO: INV: AC:242.2W, AC_Prediction: 231.2W, DC:254.9W, DC_prediction: 241.2W (0.0|0.0|254.9|0.0), L:948.0W [2000.0W]
2024-04-02 10:04:33,907:INFO: SMT: T:Smartmeter P:80.0W [ 74.6,81.4,19.9,97.6,110.1,99.5,85.0 ] Predict: 98.0W
2024-04-02 10:04:33,910:INFO: Direct connected panels (0.0W) can't cover demand (329.2W), trying to get rest from hub.
2024-04-02 10:04:33,910:INFO: Checking if Solarflow is willing to contribute 329.2W ...
2024-04-02 10:04:33,910:INFO: Based on time, solarpower (453.3W) minimum charge power (225W) and bypass state (False), hub could contribute 228.3W - Decision path: 2.2.
2024-04-02 10:04:33,910:INFO: Hub should contribute more (228.0W) than what we currently get from panels (0.0W), we will use the inverter for fast/precise limiting!
2024-04-02 10:04:33,910:INFO: Not setting solarflow output limit to 700.0W as it is identical to current limit!
2024-04-02 10:04:33,910:INFO: Setting inverter output limit to 912W (1 min moving average of 228W x 4)
2024-04-02 10:04:33,910:INFO: Sun: 06:49 - 19:45 Demand: 329.2W, Panel DC: (0.0|0.0|0.0), Hub DC: (254.9), Inverter Limit: 912.0W, Hub Limit: 700.0W
2024-04-02 10:04:34,901:INFO: SMT triggers limit function: 82.3 -> 107.4
2024-04-02 10:04:34,902:INFO: Rate limit on trigger function, last call was only 1.0s ago!
2024-04-02 10:04:35,904:INFO: SMT triggers limit function: 79.4 -> 105.4
2024-04-02 10:04:35,904:INFO: Rate limit on trigger function, last call was only 2.0s ago!
2024-04-02 10:04:36,906:INFO: SMT triggers limit function: 75.8 -> 103.0
2024-04-02 10:04:36,906:INFO: Rate limit on trigger function, last call was only 3.0s ago!
2024-04-02 10:04:37,899:INFO: SMT triggers limit function: 83.0 -> 93.7
2024-04-02 10:04:37,899:INFO: Rate limit on trigger function, last call was only 4.0s ago!
2024-04-02 10:04:38,899:INFO: SMT triggers limit function: 83.0 -> 93.7
2024-04-02 10:04:38,899:INFO: Rate limit on trigger function, last call was only 5.0s ago!
2024-04-02 10:04:39,264:INFO: SMT triggers limit function: 83.0 -> 93.7
2024-04-02 10:04:39,264:INFO: Rate limit on trigger function, last call was only 5.4s ago!
2024-04-02 10:04:44,903:INFO: SMT triggers limit function: 85.6 -> 106.7
2024-04-02 10:04:44,903:INFO: HUB: S:463.4W [ 476.5,409.7,448.5,477.4,455.7,466.7,477.9 ], B: 12% (13|11|12), V:48.6V (48.6|48.7|48.6), C: 219W, P:False, F:65.1h, E:1.7h, H:248W, L:700W
2024-04-02 10:04:44,905:INFO: INV: AC:234.5W, AC_Prediction: 231.3W, DC:246.9W, DC_prediction: 243.5W (0.0|0.0|246.9|0.0), L:912.0W [2000.0W]
2024-04-02 10:04:44,907:INFO: SMT: T:Smartmeter P:86.0W [ 19.9,97.6,110.1,99.5,75.8,85.6 ] Predict: 106.7W
2024-04-02 10:04:44,910:INFO: Direct connected panels (0.0W) can't cover demand (338.0W), trying to get rest from hub.
2024-04-02 10:04:44,910:INFO: Checking if Solarflow is willing to contribute 338.0W ...
2024-04-02 10:04:44,910:INFO: Based on time, solarpower (463.4W) minimum charge power (225W) and bypass state (False), hub could contribute 238.4W - Decision path: 2.2.
2024-04-02 10:04:44,910:INFO: Hub should contribute more (238.0W) than what we currently get from panels (0.0W), we will use the inverter for fast/precise limiting!
2024-04-02 10:04:44,910:INFO: Hub has just recently adjusted limit, need to wait until it is set again! Current limit: 700, new limit: 700
2024-04-02 10:04:44,910:INFO: Setting inverter output limit to 952W (1 min moving average of 238W x 4)
2024-04-02 10:04:44,910:INFO: Sun: 06:49 - 19:45 Demand: 338.0W, Panel DC: (0.0|0.0|0.0), Hub DC: (246.9), Inverter Limit: 952.0W, Hub Limit: 700.0W
2024-04-02 10:04:45,903:INFO: SMT triggers limit function: 78.5 -> 101.9
2024-04-02 10:04:45,903:INFO: Rate limit on trigger function, last call was only 1.0s ago!
2024-04-02 10:04:46,899:INFO: SMT triggers limit function: 77.5 -> 101.3
2024-04-02 10:04:46,900:INFO: Rate limit on trigger function, last call was only 2.0s ago!
2024-04-02 10:04:47,963:INFO: SMT triggers limit function: 82.5 -> 104.6
2024-04-02 10:04:47,963:INFO: Rate limit on trigger function, last call was only 3.1s ago!
2024-04-02 10:04:48,905:INFO: SMT triggers limit function: 68.0 -> 87.6
2024-04-02 10:04:48,905:INFO: Rate limit on trigger function, last call was only 4.0s ago!
2024-04-02 10:04:49,221:INFO: SMT triggers limit function: 68.0 -> 87.6
2024-04-02 10:04:49,221:INFO: Rate limit on trigger function, last call was only 4.3s ago!
2024-04-02 10:04:49,905:INFO: SMT triggers limit function: 79.3 -> 92.9
2024-04-02 10:04:49,905:INFO: Rate limit on trigger function, last call was only 5.0s ago!
2024-04-02 10:04:50,899:INFO: SMT triggers limit function: 70.4 -> 88.7
2024-04-02 10:04:50,899:INFO: Rate limit on trigger function, last call was only 6.0s ago!
2024-04-02 10:04:51,904:INFO: SMT triggers limit function: 66.1 -> 86.7
2024-04-02 10:04:51,904:INFO: Rate limit on trigger function, last call was only 7.0s ago!
2024-04-02 10:04:52,899:INFO: SMT triggers limit function: 67.4 -> 87.3
2024-04-02 10:04:52,899:INFO: Rate limit on trigger function, last call was only 8.0s ago!
2024-04-02 10:04:53,900:INFO: SMT triggers limit function: 32.5 -> 71.1
2024-04-02 10:04:53,900:INFO: Rate limit on trigger function, last call was only 9.0s ago!
2024-04-02 10:04:54,603:INFO: Triggering telemetry update: iot/73bkTV/5ak8yGU7/properties/read
2024-04-02 10:04:54,903:INFO: SMT triggers limit function: 16.8 -> 63.8
mavo commented 5 months ago

I checked the great WWW a bit more - in order to get the "force update" work. However, what I found is that my shelly3em is a Gen1 device, where I cannot use the RPC commands to trigger updates. What I found is that I can set "update_periodic" via an http call to the settings, which I did and set it to 2. I can now see that there is a new msg every 2s in mqtt explorer visible. Just for cross linking if anyone needs this in the future as well -> https://community.home-assistant.io/t/shelly-i3-mqtt-events/266669/3

Lets see if this will fix it. At least I now saw sometimes more than 5 values. However, as its currently april and the weather is behaving exactly as you expect it this time of the year, it changes from sun to could very often, therefore triggering more values to be publish naturally.

reinhard-brandstaedter commented 5 months ago

OK, great! Thanks for documenting this here! Let's observe this a bit. Agree on the weather. Today is a very good testing day ;-) Sun goes on/off and the control script is trying to keep up with the changes.

mavo commented 5 months ago

Seems to work much better now. image

The values are adjusted fairly well, although please notice, that the HA dashboard seem to still have some less frequent updates. But it does trigger in the app and its not just stuck on wrong values as it used to be.

Thanks alot for the support!🙇