errors after upgrade to 0.6

Posted on
Fri Nov 02, 2018 8:46 am
berkinet offline
User avatar
Posts: 3114
Joined: Nov 18, 2008
Location: Berkeley, CA, USA & Mougins, France

Re: errors after upgrade to 0.6

berkinet wrote:
... I have the old button, time to open it up and see if there are any electronics inside, or just a switch.
Definitely more than just a switch. The photo below is actually the back side of the board. When the button is pressed, the two onboard-switches are pushed against two matching plastic posts inside the case.

doorBird-Soft-Touch_button.png
doorBird-Soft-Touch_button.png (315.89 KiB) Viewed 323 times

Posted on
Fri Nov 02, 2018 2:48 pm
agame offline
Posts: 197
Joined: Jul 13, 2017
Location: Melbourne, Australia

Re: errors after upgrade to 0.6

Now about 12 hours later and the cycle of errors has returned to both devices :(

I also have a 2101 (2101V) and the nightly reboot does not send me an alert nor ring the doorbell via the IP Chime. I do not use any of the other contacts, relays, etc.


I also have, with the soft-touch button (the backlight on the original button pad failed so they sent me the soft-touch), and I have no phantom rings. I have the IP chime device.

Posted on
Fri Nov 02, 2018 2:59 pm
lanbrown offline
Posts: 675
Joined: Sep 26, 2017

Re: errors after upgrade to 0.6

berkinet wrote:
berkinet wrote:
... I have the old button, time to open it up and see if there are any electronics inside, or just a switch.
Definitely more than just a switch. The photo below is actually the back side of the board. When the button is pressed, the two onboard-switches are pushed against two matching plastic posts inside the case.

doorBird-Soft-Touch_button.png


They really made that complicated for what it does. I think they made things too complex where they should be simple. They need to learn about K.I.S.S.

Posted on
Sat Nov 03, 2018 3:22 pm
agame offline
Posts: 197
Joined: Jul 13, 2017
Location: Melbourne, Australia

Re: errors after upgrade to 0.6

I've upgraded to 0.7.
As per usual, the logs were quiet for a few hours but became noisy again overnight with the usual cycle of error messages.

Posted on
Sat Nov 03, 2018 3:53 pm
kwijibo007 offline
Posts: 258
Joined: Sep 27, 2013
Location: Melbourne, Australia

Re: errors after upgrade to 0.6

agame wrote:
I've upgraded to 0.7.
As per usual, the logs were quiet for a few hours but became noisy again overnight with the usual cycle of error messages.



Hi Adam,

Would you mind running a custom version of the plugin so we can do some troubleshooting? You can download it here: https://www.dropbox.com/s/wb9vritf782lcfz/DoorBird.indigoPlugin.zip?dl=0

To determine if the Doorbrid device is "off" the plugin detects that the Doorbird has not sent a UDP "keep alive packet" in x seconds. X being the amount set in your plugin devices preferences "Keep Alive Timeout". The default is 30 seconds. The theory being that if your Doorbird does not send a keep alive packet within 30 seconds it must be offline. If the Doorbird is offline and a packet is recived, it turns back on. I think for some reason the variable that holds the timestamp of the last time your Doorbirds checked in is not updating or is invalid. And therefore the device gets caught in a toggle loop.

This version of the plugin prints the values of the current time (as reported by the plugin), the variable holding the value of the perceived last check in and the difference between the two in seconds. The times are printed in unix time (not human readable). This is going to cause a lot logs to be written. When the Doorbirds start toggling on / off in a loop could you please post a few of the log entires so I can see what's happening?

Pete

Posted on
Sat Nov 03, 2018 9:01 pm
agame offline
Posts: 197
Joined: Jul 13, 2017
Location: Melbourne, Australia

Re: errors after upgrade to 0.6

Thanks for that!
the explanation makes sense [except why does it take a few hours to commence? ]

I had some difficulty forcing this update: I'm guessing because the dropbox version has the same version number as the existing 0.7 [is dropbox pointing at the intended version?] So have since deleted the existing plugin file and manually replaced the file rather than using the 'double-click' process.
The plugin reload of course has stopped the noisy logs for now so lets see what is happening tomorrow morning!

Posted on
Sun Nov 04, 2018 4:03 am
kwijibo007 offline
Posts: 258
Joined: Sep 27, 2013
Location: Melbourne, Australia

Re: errors after upgrade to 0.6

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.

Posted on
Mon Nov 05, 2018 7:20 pm
agame offline
Posts: 197
Joined: Jul 13, 2017
Location: Melbourne, Australia

Re: errors after upgrade to 0.6

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?

Posted on
Tue Nov 06, 2018 12:42 am
kwijibo007 offline
Posts: 258
Joined: Sep 27, 2013
Location: Melbourne, Australia

Re: errors after upgrade to 0.6

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/9q2hdjogxctzhbx/DoorBird.indigoPlugin.zip?dl=0. Hopefully this sorts it out :D

Posted on
Tue Nov 13, 2018 5:22 am
agame offline
Posts: 197
Joined: Jul 13, 2017
Location: Melbourne, Australia

Re: errors after upgrade to 0.6

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/9q2hdjogxctzhbx/DoorBird.indigoPlugin.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.

Posted on
Tue Nov 13, 2018 2:56 pm
agame offline
Posts: 197
Joined: Jul 13, 2017
Location: Melbourne, Australia

Re: errors after upgrade to 0.6

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).

Posted on
Tue Nov 13, 2018 4:35 pm
kwijibo007 offline
Posts: 258
Joined: Sep 27, 2013
Location: Melbourne, Australia

Re: errors after upgrade to 0.6

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

Posted on
Tue Nov 13, 2018 10:32 pm
agame offline
Posts: 197
Joined: Jul 13, 2017
Location: Melbourne, Australia

Re: errors after upgrade to 0.6

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

Posted on
Wed Nov 14, 2018 4:27 am
kwijibo007 offline
Posts: 258
Joined: Sep 27, 2013
Location: Melbourne, Australia

Re: errors after upgrade to 0.6

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/no6uafwppcb1ayj/DoorBird.indigoPlugin.zip?dl=0

Pete

Posted on
Wed Nov 14, 2018 9:49 am
lanbrown offline
Posts: 675
Joined: Sep 26, 2017

Re: errors after upgrade to 0.6

I think we know that they have a time skew. If you don't use the API to reboot daily; when it does it itself it is slightly more than 24 hours. Most likely their internal code says to reboot every 24 hours and not a little over 24 hours.

The IP Chime and I/O Controller are even worse as they are 25.5 hours between automatic reboots.

Who is online

Users browsing this forum: No registered users and 1 guest