errors after upgrade to 0.6

Post Reply
kwijibo007
Posts: 331
Joined: Fri Sep 27, 2013 4:58 pm
Location: Melbourne, Australia

Re: errors after upgrade to 0.6

Post by kwijibo007 »

agame wrote: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.
Top
agame
Posts: 514
Joined: Thu Jul 13, 2017 10:29 pm
Location: Melbourne, Australia

Re: errors after upgrade to 0.6

Post by agame »

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?
Top
kwijibo007
Posts: 331
Joined: Fri Sep 27, 2013 4:58 pm
Location: Melbourne, Australia

Re: errors after upgrade to 0.6

Post by kwijibo007 »

agame wrote: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/9q2hdjogxctzh ... n.zip?dl=0. Hopefully this sorts it out :D
Top
agame
Posts: 514
Joined: Thu Jul 13, 2017 10:29 pm
Location: Melbourne, Australia

Re: errors after upgrade to 0.6

Post by agame »

kwijibo007 wrote:
agame wrote: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/9q2hdjogxctzh ... n.zip?dl=0. Hopefully this sorts it out :D
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.
Top
agame
Posts: 514
Joined: Thu Jul 13, 2017 10:29 pm
Location: Melbourne, Australia

Re: errors after upgrade to 0.6

Post by agame »

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).
Top
kwijibo007
Posts: 331
Joined: Fri Sep 27, 2013 4:58 pm
Location: Melbourne, Australia

Re: errors after upgrade to 0.6

Post by kwijibo007 »

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 :D

Pete
Top
agame
Posts: 514
Joined: Thu Jul 13, 2017 10:29 pm
Location: Melbourne, Australia

Re: errors after upgrade to 0.6

Post by agame »

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
Top
kwijibo007
Posts: 331
Joined: Fri Sep 27, 2013 4:58 pm
Location: Melbourne, Australia

Re: errors after upgrade to 0.6

Post by kwijibo007 »

agame wrote: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/no6uafwppcb1a ... n.zip?dl=0

Pete
Top
agame
Posts: 514
Joined: Thu Jul 13, 2017 10:29 pm
Location: Melbourne, Australia

Re: errors after upgrade to 0.6

Post by agame »

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!
Top
Post Reply

Return to “Doorbird”