This is interesting.
- Code: Select all
1 DoorBird Debug doorbird master - front - Current time: 1542140850.9
2 DoorBird Debug doorbird master - front - Keep alive: 1542140700
3 DoorBird Debug doorbird master - front - Diff: 150.898293972
4 DoorBird Debug Doorbird.primary_device_state_update() called
5 DoorBird doorbird master - front : Offline
6 DoorBird Debug doorbird master - front - Current time: 1542140852.0
7 DoorBird Debug doorbird master - front - Keep alive: 1542140700
8 DoorBird Debug doorbird master - front - Diff: 152.003359079
9 DoorBird Debug doorbird master - front - Current time: 1542140853.01
10 DoorBird Debug doorbird master - front - Keep alive: 1542140700
11 DoorBird Debug doorbird master - front - Diff: 153.014909983
12 DoorBird Debug doorbird master - front - Current time: 1542140854.02
13 DoorBird Debug doorbird master - front - Keep alive: 1542140700
14 DoorBird Debug doorbird master - front - Diff: 154.023247004
15 DoorBird Debug doorbird master - front - Current time: 1542140855.03
16 DoorBird Debug doorbird master - front - Keep alive: 1542140700
17 DoorBird Debug doorbird master - front - Diff: 155.031037092
18 DoorBird Debug doorbird master - front - Current time: 1542140856.04
19 DoorBird Debug doorbird master - front - Keep alive: 1542140854
20 DoorBird Debug doorbird master - front - Diff: 2.04344391823
21 DoorBird Debug Doorbird.primary_device_state_update() called
22 DoorBird doorbird master - front : Online
23 DoorBird Debug Doorbird.update_status_fields() called
24 DoorBird Debug Doorbird.check_status() called
Lines 1 to 17 show 150 seconds difference between the current time that the plugin (and by extension your Mac) is reporting and the embedded time within the last received Doorbird UDP packet. What's strange is that this is consistently 150 seconds - you would expect this time to grow as more time lapses. This suggests that the time within your Mac and the Doorbird are skewed- but... then at lines 18-20 it switches back to working as expected with a 2 second difference.
If it wasn't for two points I would be thinking that the time within your Doorbird is skewing and then snapping back to being correct. But:
1) You have two Doorbirds that do this at the same time?
2) When you restart the plugin it always corrects the issue?
Are both these points correct?
I think we can fix this either way. Currently the plugin takes the time value embedded with the UDP packet and uses it as a reference as to when it was last online. Instead of doing this I'll change the plugin to reference the actual time that the packet arrived. This should remove any time skew considerations.
Give me a couple of days and I'll knock together a version that does this for you to test
Pete