errors after upgrade to 0.6

I had some difficulty forcing this update: I'm guessing because the dropbox version has the same version number as the existing 0.7

Oops, I should have incremented the plugin version.

the errors have returned but I'm not seeing any additional debug info?
I wonder if I failed to overwrite the old version somehow (though the timestamp suggests I did..).
there's no additional setting to generate the extra output?

the errors have returned but I'm not seeing any additional debug info?
I wonder if I failed to overwrite the old version somehow (though the timestamp suggests I did..).
there's no additional setting to generate the extra output?

Yeah, something's not right. You should be seeing lot's of logs like below (even when it's working ok).

Code: Select all

 DoorBird Debug                  Doorbird - Current time: 1541486403.01
 DoorBird Debug                  Doorbird - Keep alive: 1541486397
 DoorBird Debug                  Doorbird - Diff: 6.00913095474


I've re-shared the plugin with an incremneted plugin version (0.7.1) https://www.dropbox.com/s/9q2hdjogxctzhbx/DoorBird.indigoPlugin.zip?dl=0. Hopefully this sorts it out

the errors have returned but I'm not seeing any additional debug info?
I wonder if I failed to overwrite the old version somehow (though the timestamp suggests I did..).
there's no additional setting to generate the extra output?

Yeah, something's not right. You should be seeing lot's of logs like below (even when it's working ok).

Code: Select all

 DoorBird Debug                  Doorbird - Current time: 1541486403.01
 DoorBird Debug                  Doorbird - Keep alive: 1541486397
 DoorBird Debug                  Doorbird - Diff: 6.00913095474


I've re-shared the plugin with an incremneted plugin version (0.7.1) https://www.dropbox.com/s/9q2hdjogxctzhbx/DoorBird.indigoPlugin.zip?dl=0. Hopefully this sorts it out

Thanks so much (apologies for unavoidable silence for a few days). Its been running a couple of hours and looks like your example (though curiously only reporting stats for one of the devices ??).
eg

Code: Select all

  DoorBird Debug                  doorbird master - front  - Current time: 1542108031.35
   DoorBird Debug                  doorbird master - front  - Keep alive: 1542108018
   DoorBird Debug                  doorbird master - front  - Diff: 13.349435091
   DoorBird Debug                  doorbird master - front  - Current time: 1542108032.36
   DoorBird Debug                  doorbird master - front  - Keep alive: 1542108018
   DoorBird Debug                  doorbird master - front  - Diff: 14.3555829525
   DoorBird Debug                  doorbird master - front  - Current time: 1542108033.36
   DoorBird Debug                  doorbird master - front  - Keep alive: 1542108018
   DoorBird Debug                  doorbird master - front  - Diff: 15.3606390953
   DoorBird Debug                  doorbird master - front  - Current time: 1542108034.41
   DoorBird Debug                  doorbird master - front  - Keep alive: 1542108032
   DoorBird Debug                  doorbird master - front  - Diff: 2.40977692604
   DoorBird Debug                  doorbird master - front  - Current time: 1542108035.42
   DoorBird Debug                  doorbird master - front  - Keep alive: 1542108032
   DoorBird Debug                  doorbird master - front  - Diff: 3.41543793678
   DoorBird Debug                  doorbird master - front  - Current time: 1542108036.42
   DoorBird Debug                  doorbird master - front  - Keep alive: 1542108025
   DoorBird Debug                  doorbird master - front  - Diff: 11.4239039421
   DoorBird Debug                  doorbird master - front  - Current time: 1542108037.65
   DoorBird Debug                  doorbird master - front  - Keep alive: 1542108025
   DoorBird Debug                  doorbird master - front  - Diff: 12.6526100636
   DoorBird Debug                  doorbird master - front  - Current time: 1542108038.77
   DoorBird Debug                  doorbird master - front  - Keep alive: 1542108025
   DoorBird Debug                  doorbird master - front  - Diff: 13.7700960636


both devices are showing 'green' though. Anyhow the errors were appearing next morning generally so I'll send an update tomoz.

here's the morning update
still only one device active in the logs and both showing 'green' in the main window.
but looking through the logs there are some chunks of this sequence in which that device has started the 'toggling' cycle (does this give you a clue?):

Code: Select all

front  - Diff: 2.89071893692
   DoorBird Debug                  doorbird master - front  - Current time: 1542140850.9
   DoorBird Debug                  doorbird master - front  - Keep alive: 1542140700
   DoorBird Debug                  doorbird master - front  - Diff: 150.898293972
   DoorBird Debug                  Doorbird.primary_device_state_update() called
   DoorBird                        doorbird master - front : Offline
   DoorBird Debug                  doorbird master - front  - Current time: 1542140852.0
   DoorBird Debug                  doorbird master - front  - Keep alive: 1542140700
   DoorBird Debug                  doorbird master - front  - Diff: 152.003359079
   DoorBird Debug                  doorbird master - front  - Current time: 1542140853.01
   DoorBird Debug                  doorbird master - front  - Keep alive: 1542140700
   DoorBird Debug                  doorbird master - front  - Diff: 153.014909983
   DoorBird Debug                  doorbird master - front  - Current time: 1542140854.02
   DoorBird Debug                  doorbird master - front  - Keep alive: 1542140700
   DoorBird Debug                  doorbird master - front  - Diff: 154.023247004
   DoorBird Debug                  doorbird master - front  - Current time: 1542140855.03
   DoorBird Debug                  doorbird master - front  - Keep alive: 1542140700
   DoorBird Debug                  doorbird master - front  - Diff: 155.031037092
   DoorBird Debug                  doorbird master - front  - Current time: 1542140856.04
   DoorBird Debug                  doorbird master - front  - Keep alive: 1542140854
   DoorBird Debug                  doorbird master - front  - Diff: 2.04344391823
   DoorBird Debug                  Doorbird.primary_device_state_update() called
   DoorBird                        doorbird master - front : Online
   DoorBird Debug                  Doorbird.update_status_fields() called
   DoorBird Debug                  Doorbird.check_status() called

I have now re-loaded the plugin and both devices and the logs are active reporting as they should be with both devices. By the end of the day I'm guessing I will be able to post the slab of log you are seeking (with both devices misbehaving).

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

curious!

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?

1/ Yes
2/Yes...but now I'm looking closer at old logs I wonder if its actually just not apparent.

This slab of logs with both running before error messages are being produced (but I think this might be implying that while both are showing green, I'm not seeing an error because they're already over the threshold):

Code: Select all

   DoorBird Debug                  doorbird master - front  - Current time: 1542167022.67
   DoorBird Debug                  doorbird master - front  - Keep alive: 1542166922
   DoorBird Debug                  doorbird master - front  - Diff: 100.669763088
   DoorBird Debug                  doorbird master - laneway - Current time: 1542167022.79
   DoorBird Debug                  doorbird master - laneway - Keep alive: 1542166923
   DoorBird Debug                  doorbird master - laneway - Diff: 99.7857589722
   DoorBird Debug                  doorbird master - front  - Current time: 1542167023.69
   DoorBird Debug                  doorbird master - front  - Keep alive: 1542166922
   DoorBird Debug                  doorbird master - front  - Diff: 101.686386108
   DoorBird Debug                  doorbird master - laneway - Current time: 1542167023.8
   DoorBird Debug                  doorbird master - laneway - Keep alive: 1542166923
   DoorBird Debug                  doorbird master - laneway - Diff: 100.800870895
   DoorBird Debug                  doorbird master - front  - Current time: 1542167024.7
   DoorBird Debug                  doorbird master - front  - Keep alive: 1542166922
   DoorBird Debug                  doorbird master - front  - Diff: 102.696485996
   DoorBird Debug                  doorbird master - laneway - Current time: 1542167024.81
   DoorBird Debug                  doorbird master - laneway - Keep alive: 1542166923
   DoorBird Debug                  doorbird master - laneway - Diff: 101.811903
   DoorBird Debug                  doorbird master - front  - Current time: 1542167025.71
   DoorBird Debug                  doorbird master - front  - Keep alive: 1542166922
   DoorBird Debug                  doorbird master - front  - Diff: 103.708156109
   DoorBird Debug                  doorbird master - laneway - Current time: 1542167025.83
   DoorBird Debug                  doorbird master - laneway - Keep alive: 1542166923
   DoorBird Debug                  doorbird master - laneway - Diff: 102.827073097
   DoorBird Debug                  doorbird master - front  - Current time: 1542167026.72
   DoorBird Debug                  doorbird master - front  - Keep alive: 1542166922
   DoorBird Debug                  doorbird master - front  - Diff: 104.721374989
   DoorBird Debug                  doorbird master - laneway - Current time: 1542167026.83
   DoorBird Debug                  doorbird master - laneway - Keep alive: 1542166923


Here's one from earlier with both toggling:-

Code: Select all

2018-11-14 07:42:13.837   DoorBird Debug   Doorbird.update_credintials() called
2018-11-14 07:42:13.838   DoorBird Debug   Doorbird.check_status() called
2018-11-14 07:42:13.870   DoorBird Debug   Doorbird.primary_device_state_update() called
2018-11-14 07:42:13.876   DoorBird Debug   Doorbird.primary_device_state_update() called
2018-11-14 07:42:13.900   DoorBird Debug   doorbird master - laneway - Current time: 1542141733.87
2018-11-14 07:42:13.902   DoorBird Debug   doorbird master - laneway - Keep alive: 1542141702
2018-11-14 07:42:13.919   DoorBird Debug   doorbird master - laneway - Diff: 31.8713650703
2018-11-14 07:42:13.926   DoorBird Debug   Doorbird.primary_device_state_update() called
2018-11-14 07:42:13.944   DoorBird   doorbird master - laneway: Offline
2018-11-14 07:42:14.840   DoorBird Debug   doorbird master - front  - Current time: 1542141734.84
2018-11-14 07:42:14.842   DoorBird Debug   doorbird master - front  - Keep alive: 1542141702
2018-11-14 07:42:14.843   DoorBird Debug   doorbird master - front  - Diff: 32.8387360573
2018-11-14 07:42:14.949   DoorBird Debug   doorbird master - laneway - Current time: 1542141734.95
2018-11-14 07:42:15.059   DoorBird Debug   doorbird master - laneway - Keep alive: 1542141702
2018-11-14 07:42:15.061   DoorBird Debug   doorbird master - laneway - Diff: 32.9474170208
2018-11-14 07:42:15.847   DoorBird Debug   doorbird master - front  - Current time: 1542141735.85
2018-11-14 07:42:15.849   DoorBird Debug   doorbird master - front  - Keep alive: 1542141702
2018-11-14 07:42:15.850   DoorBird Debug   doorbird master - front  - Diff: 33.8457529545
2018-11-14 07:42:16.067   DoorBird Debug   doorbird master - laneway - Current time: 1542141736.06
...
018-11-14 07:42:17.081   DoorBird Debug   doorbird master - laneway - Keep alive: 1542141702
2018-11-14 07:42:17.083   DoorBird Debug   doorbird master - laneway - Diff: 35.0761289597
2018-11-14 07:42:17.860   DoorBird Debug   doorbird master - front  - Current time: 1542141737.86
2018-11-14 07:42:17.861   DoorBird Debug   doorbird master - front  - Keep alive: 1542141736
2018-11-14 07:42:17.863   DoorBird Debug   doorbird master - front  - Diff: 1.85813808441
2018-11-14 07:42:17.863   DoorBird Debug   Doorbird.primary_device_state_update() called
2018-11-14 07:42:17.888   DoorBird   doorbird master - front : Online
2018-11-14 07:42:17.896   DoorBird Debug   Doorbird.update_status_fields() called
2018-11-14 07:42:17.903   DoorBird Debug   Doorbird.check_status() called
2018-11-14 07:42:18.086   DoorBird Debug   doorbird master - laneway - Current time: 1542141738.08
2018-11-14 07:42:18.089   DoorBird Debug   doorbird master - laneway - Keep alive: 1542141702
2018-11-14 07:42:18.091   DoorBird Debug   doorbird master - laneway - Diff: 36.0844271183
2018-11-14 07:42:18.961   DoorBird Debug   doorbird master - front  - Current time: 1542141738.96
2018-11-14 07:42:19.051   DoorBird Debug   doorbird master - front  - Keep alive: 1542141736
2018-11-14 07:42:19.130   DoorBird Debug   doorbird master - laneway - Current time: 1542141739.13
2018-11-14 07:42:19.133   DoorBird Debug   doorbird master - front  - Diff: 2.95925498009
2018-11-14 07:42:19.251   DoorBird Debug   doorbird master - laneway - Keep alive: 1542141702
2018-11-14 07:42:19.340   DoorBird Debug   doorbird master - laneway - Diff: 37.1283099651
2018-11-14 07:42:20.346   DoorBird Debug   doorbird master - laneway - Current time: 1542141740.34
2018-11-14 07:42:20.408   DoorBird Debug   doorbird master - front  - Current time: 1542141740.41
2018-11-14 07:42:20.518   DoorBird Debug   doorbird master - laneway - Keep alive: 1542141739
2018-11-14 07:42:20.519   DoorBird Debug   doorbird master - front  - Keep alive: 1542141736
2018-11-14 07:42:20.521   DoorBird Debug   doorbird master - laneway - Diff: 1.34414291382
2018-11-14 07:42:20.522   DoorBird Debug   doorbird master - front  - Diff: 4.40591406822
2018-11-14 07:42:20.523   DoorBird Debug   Doorbird.primary_device_state_update() called
2018-11-14 07:42:20.542   DoorBird   doorbird master - laneway: Online


thanks for your help (not at all urgent, as it seems to work still!).
Adam

curious!

It really is! My money is on the Doorbirds having a time skew.

Give this version a try. It uses the actual time that the UDP packet arrived - not the embedded time that the Doorbird's are sending.
https://www.dropbox.com/s/no6uafwppcb1ayj/DoorBird.indigoPlugin.zip?dl=0

Pete

Applied....looking good....but I guess I'll be able to confirm tonight.

Does time run slower in Germany??!


Edit: All working well overnight. Bug fixed!