Ghost button triggering (part 2)

[ristomatti]

Everything ran nicely for some time after #12 was fixed. Now suddenly the problem seems to have come back. I've set up logging to see what happens this time. As there isn't anything else on the state as buttonevent and lastupdate my guess is the fix requires checking the timestamp in some way as suggested by @danpowpow on #12 discussions.

Assuming an old timestamp is returned, comparing it to the server time to decide if a message should be published is not without its issues:

• timestamp sent by the hub does not seem to be timezone adjusted
• using the timestamp as part of the code would assume both the hub and server/computer have time/timezone in sync

A simpler approach would be to only compare if the lastupdated value has changed as the switch seems occasionally trigger two events with different buttonevent values + occasionally some scene cycle events. This will only work though if the lastupdated on the ghost trigger is the same as the previous one. I'll update when I get it caught on the logs. This has been occurring 1-3 times a day during the last week so it should not take too long.

[ristomatti]

I just remembered I've been logging the published events for a longer time and noticed a pattern there. An old event has been triggered multiple times even if there have been newer events in between. Here's an excerpt from the log:

hue/hue_dimmer_switch/lastupdated 2018-04-10T16:49:23
hue/hue_dimmer_switch/buttonevent 1002
hue/hue_dimmer_switch/lastupdated 2018-04-10T16:49:24
hue/hue_dimmer_switch/buttonevent 4002
hue/hue_dimmer_switch/lastupdated 2018-04-10T18:21:37
hue/hue_dimmer_switch/buttonevent 4002
hue/hue_dimmer_switch/lastupdated 2018-04-11T11:07:58
hue/hue_dimmer_switch/buttonevent 4002
hue/hue_dimmer_switch/lastupdated 2018-04-10T18:21:37
hue/hue_dimmer_switch/buttonevent 4002
hue/hue_dimmer_switch/lastupdated 2018-04-11T16:53:37
hue/hue_dimmer_switch/buttonevent 4002
hue/hue_dimmer_switch/lastupdated 2018-04-10T18:21:37
hue/hue_dimmer_switch/buttonevent 3002
hue/hue_dimmer_switch/lastupdated 2018-04-11T19:34:20
hue/hue_dimmer_switch/buttonevent 3002
hue/hue_dimmer_switch/lastupdated 2018-04-11T19:34:23
hue/hue_dimmer_switch/buttonevent 3000
hue/hue_dimmer_switch/lastupdated 2018-04-11T19:34:24
hue/hue_dimmer_switch/buttonevent 3002
hue/hue_dimmer_switch/lastupdated 2018-04-11T19:34:24
hue/hue_dimmer_switch/buttonevent 4002
hue/hue_dimmer_switch/lastupdated 2018-04-12T05:38:57
hue/hue_dimmer_switch/buttonevent 1002
hue/hue_dimmer_switch/lastupdated 2018-04-12T07:34:00
hue/hue_dimmer_switch/buttonevent 1002
hue/hue_dimmer_switch/lastupdated 2018-04-12T14:34:00
hue/hue_dimmer_switch/buttonevent 1002
hue/hue_dimmer_switch/lastupdated 2018-04-12T07:34:00
hue/hue_dimmer_switch/buttonevent 1002
hue/hue_dimmer_switch/lastupdated 2018-04-12T19:16:09
hue/hue_dimmer_switch/buttonevent 1002
hue/hue_dimmer_switch/lastupdated 2018-04-12T07:34:00
hue/hue_dimmer_switch/buttonevent 4002
hue/hue_dimmer_switch/lastupdated 2018-04-13T05:06:54
hue/hue_dimmer_switch/buttonevent 4002
hue/hue_dimmer_switch/lastupdated 2018-04-13T09:26:11
hue/hue_dimmer_switch/buttonevent 4002
hue/hue_dimmer_switch/lastupdated 2018-04-13T05:06:54
hue/hue_dimmer_switch/buttonevent 4002
hue/hue_dimmer_switch/lastupdated 2018-04-13T10:06:54
hue/hue_dimmer_switch/buttonevent 4002
hue/hue_dimmer_switch/lastupdated 2018-04-13T05:06:54

Note for example the timestamp 2018-04-13T05:06:54 appearing 3 times. Based on this it might be enough to just check if the new timestamp is newer than the previous one. I think I'll prototype this.

[ristomatti]

I've implemented the idea. Now I'll just need to wait for enough time to pass. If it happens to work I'll make a pull request.