errors after upgrade to 0.6

[agame]

I upgraded the plugin to version 0.6 a couple of days ago and have since been seeing experiencing some odd problems.

The two master devices invariably show themselves as offline after a period (state binding is set to 'device status', so I assume these should still be showing green indefinitely?). They will come back green after reloading the plugin. The door birds are operating correctly in other respects (visible in Security Spy, and on the Doorbird App), and are actually still reporting motion and button presses, so I assume this is just a UI issue (?). A status request generates this:

Code: Select all

8 Oct 2018 at 8:08:19 am
   DoorBird                        sent "DoorBird Front (master device status)" status request
   DoorBird Debug                  Dorbird.update_status_fields() called
   DoorBird Debug                  Doorbird.check_status() called
   DoorBird                        DoorBird Front (master device status): Connected
   DoorBird                            Firmware    : 000112
   DoorBird                            Build Number: 15337269
   DoorBird                            MAC Address : 1CCAE37xxxx
   DoorBird                            Model       : DoorBird D2101BV

There are also bursts of dense error messages in the logs: a slab of which looks like this:

Code: Select all

DoorBird Debug                  Doorbird.primary_device_state_update() called
   DoorBird                        DoorBird Laneway (master device status): Online
   DoorBird Debug                  Dorbird.update_status_fields() called
   DoorBird Debug                  Doorbird.check_status() called
   DoorBird Debug                  Doorbird.primary_device_state_update() called
   DoorBird                        DoorBird Laneway (master device status): Offline
   DoorBird Debug                  Doorbird.primary_device_state_update() called
   DoorBird                        DoorBird Front (master device status): Offline
   DoorBird Debug                  Doorbird.primary_device_state_update() called
   Schedule                        update old humidity variables ensuite
   DoorBird                        DoorBird Laneway (master device status): Online
   DoorBird Debug                  Dorbird.update_status_fields() called
   DoorBird Debug                  Doorbird.check_status() called
   DoorBird Debug                  Doorbird.primary_device_state_update() called
   DoorBird                        DoorBird Front (master device status): Online
   DoorBird Debug                  Doorbird.primary_device_state_update() called
   DoorBird Debug                  Dorbird.update_status_fields() called
   DoorBird                        DoorBird Laneway (master device status): Offline
   DoorBird Debug                  Doorbird.check_status() called
   DoorBird Debug                  Doorbird.primary_device_state_update() called
   DoorBird                        DoorBird Laneway (master device status): Online
   DoorBird Debug                  Dorbird.update_status_fields() called
   DoorBird Debug                  Doorbird.check_status() called
   DoorBird Debug                  Doorbird.primary_device_state_update() called
   DoorBird                        DoorBird Front (master device status): Offline
   DoorBird Debug                  Doorbird.primary_device_state_update() called
   DoorBird                        DoorBird Laneway (master device status): Offline
   DoorBird Debug                  Doorbird.primary_device_state_update() called
   DoorBird                        DoorBird Front (master device status): Online
   DoorBird Debug                  Dorbird.update_status_fields() called
   DoorBird Debug                  Doorbird.check_status() called
   DoorBird Debug                  Doorbird.primary_device_state_update() called
   DoorBird                        DoorBird Laneway (master device status): Online
   DoorBird Debug                  Doorbird.primary_device_state_update() called
   DoorBird Debug                  Dorbird.update_status_fields() called
   DoorBird                        DoorBird Front (master device status): Offline
   DoorBird Debug                  Doorbird.check_status() called
   DoorBird Debug                  Doorbird.primary_device_state_update() called
   DoorBird Debug                  Doorbird.primary_device_state_update() called
   DoorBird                        DoorBird Front (master device status): Online
   DoorBird                        DoorBird Laneway (master device status): Offline
   DoorBird Debug                  Dorbird.update_status_fields() called
   DoorBird Debug                  Doorbird.check_status() called
   DoorBird Debug                  Doorbird.primary_device_state_update() called
   DoorBird                        DoorBird Laneway (master device status): Online
   DoorBird Debug                  Doorbird.primary_device_state_update() called
   DoorBird Debug                  Dorbird.update_status_fields() called
   DoorBird                        DoorBird Front (master device status): Offline
   DoorBird Debug                  Doorbird.check_status() called            

The above log extract was from last night and I haven't been able to replicate this morning, so can't be certain this wasn't transitory. But the status is still drifting from green to grey after a few hours. [assume the inconsistent spelling of 'Dorbird' up there is just a feature of the code...].

[kwijibo007]

Strange. My DoorBird shows green (on) as expected. After how long do they show as off? Do they both turn off at the same time?

[agame]

they both seem to be thrashing themselves on/off tens of times per minute (but show as continually grey on the UI once entering that mode). I just tested movement and it was detected successfully but with a longer than expected lag (presumably waiting for one of the brief 'connected' periods. This didn't occur in the previous versions - and given its affecting both devices similarly seems likely to be the plugin rather than a device glitch.

I wonder if I should try rolling back?

here's about a minute's worth of my log just now

Code: Select all

DoorBird Debug                  Doorbird.primary_device_state_update() called
   DoorBird                        DoorBird Laneway (master device status): Online
   DoorBird Debug                  Dorbird.update_status_fields() called
   DoorBird Debug                  Doorbird.check_status() called
   DoorBird Debug                  Doorbird.primary_device_state_update() called
   DoorBird                        DoorBird Laneway (master device status): Offline
   DoorBird Debug                  Doorbird.primary_device_state_update() called
   DoorBird                        DoorBird Front (master device status): Offline
   DoorBird Debug                  Doorbird.primary_device_state_update() called
   Schedule                        update old humidity variables ensuite
   DoorBird                        DoorBird Laneway (master device status): Online
   DoorBird Debug                  Dorbird.update_status_fields() called
   DoorBird Debug                  Doorbird.check_status() called
   DoorBird Debug                  Doorbird.primary_device_state_update() called
   DoorBird                        DoorBird Front (master device status): Online
   DoorBird Debug                  Doorbird.primary_device_state_update() called
   DoorBird Debug                  Dorbird.update_status_fields() called
   DoorBird                        DoorBird Laneway (master device status): Offline
   DoorBird Debug                  Doorbird.check_status() called
   DoorBird Debug                  Doorbird.primary_device_state_update() called
   DoorBird                        DoorBird Laneway (master device status): Online
   DoorBird Debug                  Dorbird.update_status_fields() called
   DoorBird Debug                  Doorbird.check_status() called
   DoorBird Debug                  Doorbird.primary_device_state_update() called
   DoorBird                        DoorBird Front (master device status): Offline
   DoorBird Debug                  Doorbird.primary_device_state_update() called
   DoorBird                        DoorBird Laneway (master device status): Offline
   DoorBird Debug                  Doorbird.primary_device_state_update() called
   DoorBird                        DoorBird Front (master device status): Online
   DoorBird Debug                  Dorbird.update_status_fields() called
   DoorBird Debug                  Doorbird.check_status() called
   DoorBird Debug                  Doorbird.primary_device_state_update() called
   DoorBird                        DoorBird Laneway (master device status): Online
   DoorBird Debug                  Doorbird.primary_device_state_update() called
   DoorBird Debug                  Dorbird.update_status_fields() called
   DoorBird                        DoorBird Front (master device status): Offline
   DoorBird Debug                  Doorbird.check_status() called
   DoorBird Debug                  Doorbird.primary_device_state_update() called
   DoorBird Debug                  Doorbird.primary_device_state_update() called
   DoorBird                        DoorBird Front (master device status): Online
   DoorBird                        DoorBird Laneway (master device status): Offline
   DoorBird Debug                  Dorbird.update_status_fields() called
   DoorBird Debug                  Doorbird.check_status() called
   DoorBird Debug                  Doorbird.primary_device_state_update() called
   DoorBird                        DoorBird Laneway (master device status): Online
   DoorBird Debug                  Doorbird.primary_device_state_update() called
   DoorBird Debug                  Dorbird.update_status_fields() called
   DoorBird                        DoorBird Front (master device status): Offline
   DoorBird Debug                  Doorbird.check_status() called
   Error             

every few minutes there's a red 'DoorBird Error' stating 'Unable to update Doorbird details'.

[agame]

UPDATE:

looking for a version to try rolling back to, I came across your note on release 0.4.1 on re-saving the master device settings. I was travelling so had skipped from 0.4 to 0.6 and therefore hadn't done that since installing 4.0. So I tried doing that anyhow (still on 0.6) and my log is now clear and status is a nice green - at least it has been for 10 mins.

So fingers crossed problem is solved!

[kwijibo007]

Great news. Let me know if anything weird shoes up again. There were some fairly substantial changes made between 0.5 and 0.6... I was surprised at the lack of issues raised

[kwijibo007]

Oh... and I'll fix those "Dorbird" typos in the next update.

Pete

[agame]

ha! thanks. still stable overnight so clearly that was it.

[agame]

hmmm... have been away for a period and on return it appears problems have recurred - but only with one of the doorbrid devices. It is toggling on and off every couple of seconds. The logs are full of this cycle of messages:

Code: Select all

31 Oct 2018 at 10:53:26 am
   DoorBird Debug                  Doorbird.primary_device_state_update() called
   DoorBird                        DoorBird Front (master device status): Online
   DoorBird Debug                  Dorbird.update_status_fields() called
   DoorBird Debug                  Doorbird.check_status() called
   DoorBird Debug                  Doorbird.primary_device_state_update() called
   DoorBird                        DoorBird Front (master device status): Offline
   DoorBird Debug                  Doorbird.primary_device_state_update() called
   DoorBird                        DoorBird Front (master device status): Online
   DoorBird Debug                  Dorbird.update_status_fields() called
   DoorBird Debug                  Doorbird.check_status() called
   DoorBird Debug                  Doorbird.primary_device_state_update() called
   DoorBird                        DoorBird Front (master device status): Offline
   DoorBird Debug                  Doorbird.primary_device_state_update() called
   DoorBird                        DoorBird Front (master device status): Online
   DoorBird Debug                  Dorbird.update_status_fields() called
   DoorBird Debug                  Doorbird.check_status() called
   DoorBird Debug                  Doorbird.primary_device_state_update() called
   DoorBird                        DoorBird Front (master device status): Offline

less frequently, the following error appears:

Code: Select all

 DoorBird Error                  DoorBird Front (master device status): Unable to update Doorbird details

in all other respects, the device seems to be working as per normal ( both in indigo and natively).

I've done the obvious things such as reloading the plugin, re-saving the config on the master device, rebooting the DoorBird. It was working fine before the upgrade (from .04 to .06).. Reloading the plugin is the only thing that has any impact: the errors go away for a few hours.



Edit: Tried another plugin restart. Now the cycle of error messages is running on both my door bird devices.

[berkinet]

I am also seeing odd issues. I have not reported them earlier because I was also troubleshooting other issues with DoorBird and could not be sure of the problem.

Here is what I am getting. I see the following in my log:

Code: Select all

2018-11-01 10:09:43.853	DoorBird Debug	Doorbird.doorbell_event() called
2018-11-01 10:09:43.898	DoorBird Debug	Doorbird.primary_device_state_update() called
2018-11-01 10:09:47.458	DoorBird Debug	Doorbird.primary_device_state_update() called
2018-11-01 10:09:47.497	DoorBird Debug	Dorbird.update_status_fields() called
2018-11-01 10:09:47.501	DoorBird Debug	Doorbird.check_status() called
2018-11-01 10:09:48.477	DoorBird Debug	Doorbird.doorbell_off() called
2018-11-01 10:09:48.479	DoorBird Debug	Doorbird.primary_device_state_update() called
2018-11-01 10:09:51.528	DoorBird Debug	Doorbird.primary_device_state_update() called

I have a trigger that is keyed to a Doorbell type device's On/Off State. That trigger fires on the events noted above.
However, in fact, the doorbell button has not been pressed! So, I am getting a phantom event.
Any ideas on how to trouble shoot this?

Note, I still get doorbell events after a reset. But, in those cases the DoorBird actually behaves as though the button had been pressed (and rings the attached physical doorbell).

Finally, does anyone know how to see the DoorBird's last reset time?

[kwijibo007]

hmmm... have been away for a period and on return it appears problems have recurred - but only with one of the doorbrid devices. It is toggling on and off every couple of seconds. The logs are full of this cycle of messages...

I've done the obvious things such as reloading the plugin, re-saving the config on the master device, rebooting the DoorBird. It was working fine before the upgrade (from .04 to .06).. Reloading the plugin is the only thing that has any impact: the errors go away for a few hours.

Edit: Tried another plugin restart. Now the cycle of error messages is running on both my door bird devices.

Obviously a plugin bug. I wonder if this has something to do with having two Doorbirds? Would it be possible to delete one of the Doorbird devices from Indigo to see if the issue stops on the other? If the error continues could you delete the other device as well? Then re-create them both? Apologies in advance, I know this could be very inconvenient if you have control pages and triggers configured...

I made a lot of changes between 0.4 and 0.6 and I deleted devices multiple times in testing. I wonder if a gremlin exists that might be removed after deleting?

Any ideas on how to trouble shoot this?

Note, I still get doorbell events after a reset. But, in those cases the DoorBird actually behaves as though the button had been pressed (and rings the attached physical doorbell).

With this issue I think the only way to understand what's happening is to print the decrypted UDP packet to the log so we can see if your Doorbird is really sending the bell press event or if the plugin is triggering by mistake.

Give me a couple of days and I'll get a new version out that allows printing of the decrypted UDP packet.

@berkinet and @agame, could you both please confirm that your firmware is still 000112? I'm sure it is... just want to tick that one off.

Pete

[berkinet]

@berkinet and @agame, could you both please confirm that your firmware is still 000112? I'm sure it is... just want to tick that one off.

Confirmed.

[berkinet]

The only three ways I could tell when the reset time was:
1) The logging on my switch timestamped the interface flap
2) The plugin would show the DoorBird go offline and then online
3) BlueIris

Thanks!!

1) Unmanaged switch. No go.
2) Unfortunately, I get similar events at other times, when the DoorBird did not "think" there was a button press.
3) BINGO I looked at the Security Spy log and there I found

Code: Select all

2018/11/01 09:34:06: Error communicating with the network device "DoorBird". 4.2.9,70900,800 Failed to obtain video frame from network device. The operation timed out. 

[berkinet]

I do use the plugin to perform a night reset via the API at midnight.

Very odd. After I did the button replacement, the problem actually went away for a couple of weeks. That is, I still had the 24 hourly resets, but no phantom button presses. Then, three days ago it mysteriously started again. There may be something about the button that defies the imagination. But, the problem came back right after a very heavy rain!

Anyway, I guess it is time for the nightly reboot.

[berkinet]

...Anyway, I guess it is time for the nightly reboot.

And... guess what. When I perform the restart via the API, the DoorBird generates a phantom button event, just like when rebooting on the daily restart. But, at least I can now report a repeatable bug.

[agame]

Obviously a plugin bug. I wonder if this has something to do with having two Doorbirds? Would it be possible to delete one of the Doorbird devices from Indigo to see if the issue stops on the other? If the error continues could you delete the other device as well? Then re-create them both? Apologies in advance, I know this could be very inconvenient if you have control pages and triggers configured...

I made a lot of changes between 0.4 and 0.6 and I deleted devices multiple times in testing. I wonder if a gremlin exists that might be removed after deleting?


@berkinet and @agame, could you both please confirm that your firmware is still 000112? I'm sure it is... just want to tick that one off.

Pete

I deleted one device but sadly the cycle continued on the other DoorBird. I've now reloaded the plugin and the logs are quiet (but that's the usual outcome for an hour or two - I'll need to confirm later if it returns or not).

And yes, still on 112.

Adam