Why do I see occasional quick updates?

[sddgit]

I’m trying to use the Blueriiot temperature reading to automate some stuff, in additional to using my own temperature probe. I’d like to always use the most recent of the two. I’m finding that occasionally there are two Blueriiot updates very close together, and that’s upsetting some of my logic. I’m using the last_contact sensor to trigger an automation to copy out some values. Here are some log entries:

[2022-01-01 21:38:38+00:00 INF] [MBW.BlueRiiot2MQTT.Service.PoolUpdater.SingleBlueRiiotPoolWeatherUpdater] Delaying till next check on pool 'Pool', at 01/01/2022 22:38:38, waiting 01:00:30.9999786

[2022-01-01 21:38:38+00:00 INF] [MBW.HassMQTT.HassMqttManager] Pushed 0 discovery documents, 2 values and 4 attribute changes

[2022-01-01 22:15:22+00:00 INF] [MBW.BlueRiiot2MQTT.Service.PoolUpdater.SingleBlueRiiotPoolUpdater] New data ready for pool 'Pool' at 01/01/2022 23:25:49 (interval 01:12:00). Waiting 01:10:33.0946709

[2022-01-01 22:15:22+00:00 INF] [MBW.HassMQTT.HassMqttManager] Pushed 0 discovery documents, 5 values and 10 attribute changes

[2022-01-01 22:39:12+00:00 INF] [MBW.BlueRiiot2MQTT.Service.PoolUpdater.SingleBlueRiiotPoolWeatherUpdater] Delaying till next check on pool 'Pool', at 01/01/2022 23:39:12, waiting 01:00:01.9999852

[2022-01-01 22:39:12+00:00 INF] [MBW.HassMQTT.HassMqttManager] Pushed 0 discovery documents, 2 values and 4 attribute changes

[2022-01-01 23:26:00+00:00 WRN] [MBW.BlueRiiot2MQTT.Service.PoolUpdater.SingleBlueRiiotPoolUpdater] There were 1 consecutive updates without new data for 'Pool', setting next run to be 01/01/2022 23:27:00, waiting 00:01:00

[2022-01-01 23:26:00+00:00 INF] [MBW.HassMQTT.HassMqttManager] Pushed 0 discovery documents, 2 values and 10 attribute changes

[2022-01-01 23:27:03+00:00 INF] [MBW.BlueRiiot2MQTT.Service.PoolUpdater.SingleBlueRiiotPoolUpdater] New data ready for pool 'Pool' at 01/02/2022 00:38:00 (interval 01:12:00). Waiting 01:12:16.0916852

[2022-01-01 23:27:03+00:00 INF] [MBW.HassMQTT.HassMqttManager] Pushed 0 discovery documents, 5 values and 10 attribute changes

You can see there was an update at 23:26. This update retrieved “old” data. The data was the same as that retrieved previously. Then, a minute later, there’s another update that gets fresh data. I would need to ignore the “old” data somehow. Is there a reason this 23:26 update happens?

Thank you.

[LordMike]

What probably happens is the scheduler determines that it needs to update at 23:26, which it then does. As Blueriiot doesn't have any new data yet, the scheduler reschedules for 1 minute later and successfully retrieves new data.

You can follow the logic here: https://github.com/LordMike/MBW.BlueRiiot2MQTT/blob/294dba54255286df3225d21b4a2e02e6d724dcb6/MBW.BlueRiiot2MQTT/Service/PoolUpdater/DelayCalculator.cs#L44-L110

You could try tweaking the UpdateIntervalJitter setting (env var BlueRiiot__UpdateIntervalJitter), and maybe set it to something high, like 00:15:00 (15 minutes). This should place the random jitter at larger values, hopefully pushing past the point where the updates will be available.

If that works for you (most of the time), then I could potentially add some additional time, to raise the chance that data is available.

You will never entirely skip old data though, as BlueRiiot may miss updates from the device for whatever other reason.

Alternatively, you could maybe work of some other sensor, such as last_measurement ?

[sddgit]

Thank you very much for the helpful response. last_measurement sounds like an interesting alternative trigger. In what way exactly does it differ from last_contact?

[LordMike]

If I recall correctly, last_measurement is the actual timestamp from the measurement, be it a device/sigfox or a device/bluetooth measurement.. So to ensure you react when you have data, I would go by that.

There is still at timing risk that the last measurement value comes before any actual values, so you should prob. still wait a few seconds/minutes to ensure HASS has everything before you do your thing.

Last_contact should be when the device contacted BlueRiiot, which should be identical to last_measurement for most purposes, but it may be broken somehow..

[sddgit]

They both seem to trigger at the same time, even with the “bogus” reading. Oh well, I’ll figure out another way of doing what I need. Thanks again for all your help.

[LordMike]

If you enable debug logging we could see what the actual values are. If it's pushing the same value twice, it's a bug that I need to fix.

[sddgit]

Going back to the log I posted above, the values of the sensors at 23:26 are exactly the same as the values an hour and a bit before. Then the values a minute and a bit later are more up to date. But this isn’t a bug is it, just a polling timing issue?

[LordMike]

Checking twice within 10 minutes is unfortunate, but the issue I might see is if I publish the same actual value twice.

I'm thinking that you should only see the update on last_measurement, if it actually changes. And it shouldn't change twice within 10 minutes, only once at most every 1 hour 12 minutes. I've made logic to ensure that unchanged values are not published.

[sddgit]

I’m not sure about publishing the actual value twice. You’re probably not. In my automation, when triggered by either last_measurement or last_contact, I just pick up the current values of all the sensors and copy them out. It doesn’t matter to me whether most of the sensors have values an hour old, but the temperature one is important. I have another temperature probe that updates at most every half a degree. I’m trying to use the most current of the two probes, so getting a value an hour old might override a more current one from the other probe.

I’m trying a 3 minute delay in the automation, with a mode of restart. Then if another update comes in, the automation should restart and pick up the later values.

[LordMike]

Ah, but last_contact should f.ex. only trigger, if the value is updated (by HASS). And HASS doesn't update the value, unless it receives something from MQTT - HASS doesn't care if the value changes or not.

I'll see if I can spot something in the code - may have something to do with the value type (datetimes).

[sddgit]

I think I might be misleading you. last_contact (and last_measurement) do seem to trigger only when the logs show that a poll took place. The only “problem” is that sometimes that poll retrieves data that is still quite old, and that’s something you can’t do much about, I’d say.

In thinking some more, I don’t know why I’ve been so obsessed over doing all this in one automation. I could have another one triggered just by the temperature sensor changing. That should only happen when its value actually changes, as you’ve said. Then I can copy that out if the filter’s been running for at least 5 minutes.

EDIT: but in re-reading your previous responses, maybe you’re saying that last_measurement Itself shouldn’t trigger if there have been no updated values. If that’s how you think it should work, then there might be a problem…

[sddgit]

I’ve set up an automation that’s triggered by the temperature sensor. It looks like that gets triggered twice every time new readings arrive. Wondering whether you see the same thing….