search

openhab / org.openhab.binding.zigbee

openHAB binding for ZigBee
Eclipse Public License 2.0
73 stars 111 forks source link

discovery of new thing will reset the baudrate of the BV2010/10 #726

Closed joerg1985 closed 2 years ago

joerg1985 commented 2 years ago

Outline

I am using the BV2010/10 zigbee coordinator with a custom firmware. The stock firmware was to old to work with newer devices (https://www.openhab.org/addons/bindings/zigbee/). The custom firmware is configured to use a baud rate of 115200 with software flow control. It is possible to change the baud rate in the configuration of the ember coordinator. This makes the 'thing' to go into 'online' mode and the known things are going into 'online' mode.

As soon as the the discovery of a new 'thing' is started, the baud rate of the coordinator is reset to the default value of 57600. This makes the coordinator go into 'error' mode and the discovery of the thing fails.

Configuration

Configuration Description
Coordinator used BV2010/10 (ember)
openHAB version 3.2.0
Hardware raspi
Memory 512 mb
Java version 11
Devices

Logs

cdjackson commented 2 years ago

Logs

?????

Please provide the logs as this is not a problem that I personally have, and others do not report this issue so I can only guess what is wrong with your system without the logs.

joerg1985 commented 2 years ago

logs.txt

These are the logs scanning for new things without adding a new thing and the baudrate is reset to 57600

cdjackson commented 2 years ago

Nothing here is changing the baud rate. The dongle stays working throughout this process so clearly nothing changed.

joerg1985 commented 2 years ago

@cdjackson thanks for looking into this, here is a new log file with extended logging settings. again scanning for a new device without a new device in range, this time the device went offline again: 2022-01-12 19:03:10.585 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'zigbee:coordinator_ember:01381021' changed from ONLINE to UNKNOWN short after the configuration was changed: 2022-01-12 19:03:09.977 [DEBUG] [g.discovery.internal.PersistentInbox] - The configuration for thing 'zigbee:coordinator_ember:01381021' is updated...

here is the full log file: logs2.txt sorry for the first log file, i must have make a mistake taking the logs.

cdjackson commented 2 years ago

There is a discovery of USB devices that was added by German Telekom a few years ago, but my understanding is that this should not update the configuration of an existing thing. That said, it does seem to be based on your report.

@wborn I'm wondering if this is a bug in the core? The discovery provides configuration for the thing, but if the user has instantiated the thing, and changed the configuration, the core shouldn't update this config. I thought the core was meant to use the representation property to stop this happening - this is set as the port name, so assuming the port is not changing, I would have expected the core not to update the configuration of an instantiated thing?

Or am I missing something?

wborn commented 2 years ago

I had a look at the discovery code and it could be that the PersistentInbox always updates existing things based on new discovery results. See: PersistentInbox.java#L254-L264

You can enable debug logging on org.openhab.core.config.discovery.internal.PersistentInbox to check my hypothesis. :slightly_smiling_face:

For network based things I can imagine it could be useful to also update existing things e.g. to update IPs or ports etc.

cdjackson commented 2 years ago

In the past the binding was able to check to see if a thing existed and not update, but that function caused an issue (I forget what - circular dependencies or something I think) and was removed, so now the binding has no way to know if the thing exists and just has to rely on the core to manage this…

On 16/01/2022, at 11:40 PM, Wouter Born @.***> wrote:

I had a look at the discovery code and it could be that the PersistentInbox always updates existing things based on new discovery results. See: PersistentInbox.java#L254-L264 https://github.com/openhab/openhab-core/blob/0dbc2b2ef428d1691907b0c7a85dce9c2f4a9b67/bundles/org.openhab.core.config.discovery/src/main/java/org/openhab/core/config/discovery/internal/PersistentInbox.java#L254-L264 You can enable debug logging on org.openhab.core.config.discovery.internal.PersistentInbox to check my hypothesis. 🙂

— Reply to this email directly, view it on GitHub https://github.com/openhab/org.openhab.binding.zigbee/issues/726#issuecomment-1013851262, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAH6IQY7V5B7Y667223RWW3UWKODPANCNFSM5LXKR42A. Triage notifications on the go with GitHub Mobile for iOS https://apps.apple.com/app/apple-store/id1477376905?ct=notification-email&mt=8&pt=524675 or Android https://play.google.com/store/apps/details?id=com.github.android&referrer=utm_campaign%3Dnotification-email%26utm_medium%3Demail%26utm_source%3Dgithub. You are receiving this because you were mentioned.

wborn commented 2 years ago

Yes it was a bit easier to only create discovery results for new things in the past using the DiscoveryServiceCallback when implementing an ExtendedDiscoveryService. Those implementations got removed with https://github.com/eclipse-archived/smarthome/pull/6237.

But it is still possible to track the created existing things in your binding whenever createHandler is called to create existing things by the ThingHandlerFactory. Then you can use this info to skip creating discovery results for any existing things in the DiscoveryService.

cdjackson commented 2 years ago

Interesting point - not something I’d considered but I see there are calls in the factory class when a thing is removed. To ensure this works, the core would need to guarantee that all things are instantiated before the discovery service is started - is that the case? If notches will still be a problem if background discovery starts before the things are created as the handler factory will not be able to build the list of things.

I’ll take a look to see if I can link the factory and discovery handler anyway.

cdjackson commented 2 years ago

@wborn - thinking about this some more, doesn't it make more sense to do this in the core than in every binding. I personally can't see the case when the discovery system should ever override the configuration that a user has set when they instantiated the thing.

Or maybe there is there a case where discovery can update IP addresses or something like that? In my bindings where I have devices that can change address I manage this in the thing handler, but maybe it's a valid use case? In the "old days" of OH2, the discovery service was only meant to discover the existence of a thing and add it to the inbox - if that's still the case, then I don't see a use case for discovery services updating the configuration of existing things....

I'm not necessarily against adding the internal check in the binding - it looks easy enough with a static method and I already track the creation/removal - but I personally think unless there's a use case for the discovery changing an instantiated things configuration it might be better placed in the core.

wborn commented 2 years ago

In the "old days" of OH2, the discovery service was only meant to discover the existence of a thing and add it to the inbox - if that's still the case, then I don't see a use case for discovery services updating the configuration of existing things....

This code for updating existing things using discovery results seems to go back to 2014, as it was first introduced in https://github.com/eclipse-archived/smarthome/pull/52

So it will probably introduce other issues if we'd remove it today. A reusable solution that can be used by all bindings would make sense to me.

Another workaround could be to make it possible to disable the discovery service using configuration.

openhab-bot commented 2 years ago

This issue has been mentioned on openHAB Community. There might be relevant details there:

https://community.openhab.org/t/firmware-upgrade-the-bitronvideo-bv-2010-10-zigbee-usb-dongle/128879/13

wborn commented 2 years ago

I also read in https://github.com/eclipse-archived/smarthome/issues/3975#issuecomment-320892193 that new discovery results are used for updating the locations in existing astro/weather binding things.

wborn commented 2 years ago

The custom firmware is configured to use a baud rate of 115200 with software flow control.

Maybe it is possible to detect this custom firmware somehow and then create a discovery result with the right configuration in the discovery service?

obones commented 2 years ago

Maybe it is possible to detect this custom firmware somehow and then create a discovery result with the right configuration in the discovery service?

I'm also facing this issue, but it's not just the baud rate that is overwritten, pretty much all settings are reverted back to their defaults: baud rate, high/low ram, join type.

I worked around it by manually creating the bridge in the interface and placing the discovered one in the ignore list

cdjackson commented 2 years ago

Maybe it is possible to detect this custom firmware somehow and then create a discovery result with the right configuration in the discovery service?

I'm not keen on this. When we first implemented this discovery I was keen not to open the serial port to try and perform more detection. To do this means (obviously) opening ports - this can conflict with other operations. Eg if the thing is already instantiated, then it will prevent the thing starting (ok, it could be retried, but with all the problems around nrjavaserial I prefer not to continually open the port trying different speed options). 56k and 115k are not the only speeds in use so it's just not (IMHO) a very elegant solution.

nailyk-fr commented 2 years ago

I am having big troubles with my current OpenHab 3 + Zigbee setup. After a lot of trials and failure I decided to upgrade the firmware of my Bitron video stick ( https://github.com/grobasoz/zigbee-firmware/blob/master/EM3587/NCP_USW_EM3587-LR_678-115k2.ebl )

After upgrade stop/start of openhab then changing controller with 115200 bauds put the controller back online. After a reboot of the host, the controller is back to 57k : 

2022-02-16 13:18:05.173 [DEBUG] [ng.zigbee.ember.handler.EmberHandler] - ZigBee Ember Coordinator opening Port:'/dev/ttyUSB0' PAN:7b07, EPAN:1511CFED5E90A32F, Channel:11
2022-02-16 13:18:07.576 [DEBUG] [nding.zigbee.serial.ZigBeeSerialPort] - Connecting to serial port [/dev/ttyUSB0] at 57600 baud, flow control FLOWCONTROL_OUT_XONOFF.
2022-02-16 13:18:07.723 [DEBUG] [nding.zigbee.serial.ZigBeeSerialPort] - Serial port [/dev/ttyUSB0] is initialized.
2022-02-16 13:18:19.406 [DEBUG] [nding.zigbee.serial.ZigBeeSerialPort] - Serial port '/dev/ttyUSB0' closed.

I did not identify yet if this value is coming back from backup.

Switching back the value to 115200 bauds brings the controller back online.

I tried to change the baud value in /var/lib/openhab/jsondb/org.openhab.core.thing.Thing.json after removing the /var/lib/openhab/jsondb/bakcup folder (while open hab is stopped of course), still coming back at 57600 bauds.

And, same behavior as @joerg1985 a click on 'scan' button of the webUI reset the speed value : 

2043 2022-02-16 13:39:52.066 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EZSP Dongle: Initialize with protocol ASH2.     
2044 2022-02-16 13:39:52.067 [DEBUG] [nding.zigbee.serial.ZigBeeSerialPort] - Connecting to serial port [/dev/ttyUSB0] at 115200 baud, flow control FLOWCONTROL_OUT_XONOFF.
2045 2022-02-16 13:39:52.096 [DEBUG] [nding.zigbee.serial.ZigBeeSerialPort] - Serial port [/dev/ttyUSB0] is initialized.      
2046 2022-02-16 13:39:54.800 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Ember: Link State change to true, initialised=false, networkStateUp=false
2047 2022-02-16 13:39:54.802 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Ember: Link State change to true ignored.       
2048 2022-02-16 13:39:54.817 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspVersionResponse [networkId=0, protocolVersion=8, stackType=2, stackVersion=67A0]
2049 2022-02-16 13:39:54.818 [DEBUG] [systems.zigbee.dongle.ember.EmberNcp] - EzspVersionResponse [networkId=0, protocolVersion=8, stackType=2, stackVersion=67A0]
2050 2022-02-16 13:39:54.832 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspVersionResponse [networkId=0, protocolVersion=8, stackType=2, stackVersion=67A0]
2051 2022-02-16 13:39:54.832 [DEBUG] [systems.zigbee.dongle.ember.EmberNcp] - EzspVersionResponse [networkId=0, protocolVersion=8, stackType=2, stackVersion=67A0]
2052 2022-02-16 13:39:54.833 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspVersionResponse [networkId=0, protocolVersion=8, stackType=2, stackVersion=67A0]
2053 2022-02-16 13:39:54.849 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspGetStandaloneBootloaderVersionPlatMicroPhyResponse [networkId=0, bootloaderVersion=5800, nodePlat=4, nodeMicro=14, nodePhy=3]
[...] // pressed 'scan' button
7969 2022-02-16 13:42:50.419 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - ZigBeeNetworkManager shutdown: networkState=ONLINE
7970 2022-02-16 13:42:50.420 [DEBUG] [atabase.ZigBeeNetworkDatabaseManager] - Data store: Deferred Write Time set to 0ms      
7971 2022-02-16 13:42:50.420 [DEBUG] [atabase.ZigBeeNetworkDatabaseManager] - Data store: Deferred Write Time set less than Max Deferred Write Time
7972 2022-02-16 13:42:50.421 [DEBUG] [atabase.ZigBeeNetworkDatabaseManager] - Data store: Max Deferred Write Time set to 0ms  
7973 2022-02-16 13:42:50.421 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Network state is updated to SHUTDOWN            
[...]
9004 2022-02-16 13:42:52.168 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EZSP Dongle: Initialize with protocol ASH2.     
9005 2022-02-16 13:42:52.169 [DEBUG] [nding.zigbee.serial.ZigBeeSerialPort] - Connecting to serial port [/dev/ttyUSB0] at 57600 baud, flow control FLOWCONTROL_OUT_XONOFF.
9006 2022-02-16 13:42:52.197 [DEBUG] [nding.zigbee.serial.ZigBeeSerialPort] - Serial port [/dev/ttyUSB0] is initialized.      
9007 2022-02-16 13:42:55.930 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - Starting ZigBee scan for zigbee:coordinator_ember:4dae9b1149
9008 2022-02-16 13:42:55.931 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - ZigBee coordinator is offline - aborted scan for zigbee:coordinator_ember:4dae9b1149
9009 2022-02-16 13:42:55.934 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - CC86ECFFFE937ADA: Discovery: Starting discovery for existing device
9010 2022-02-16 13:42:55.936 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - Starting ZigBee scan for zigbee:coordinator_ember:0137236D
9011 2022-02-16 13:42:55.936 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - ZigBee coordinator is offline - aborted scan for zigbee:coordinator_ember:0137236D
9012 2022-02-16 13:42:55.945 [INFO ] [bee.discovery.ZigBeeDiscoveryService] - CC86ECFFFE937ADA: Starting ZigBee device discovery
9013 2022-02-16 13:42:55.946 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - CC86ECFFFE937ADA: Creating ZigBee device zigbee:device with bridge zigbee:coordinator_ember:0137236D
9014 2022-02-16 13:42:55.950 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - CC86ECFFFE937ADA: Node discovery not complete   
[...]
9015 2022-02-16 13:43:02.208 [DEBUG] [systems.zigbee.dongle.ember.EmberNcp] - No response from ezspVersion command            
9016 2022-02-16 13:43:02.208 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EZSP Dongle: Version returned null. ASH/EZSP not initialised.
9017 2022-02-16 13:43:02.209 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Network state is updated to OFFLINE

Openhab 3.2.0 currently running, so I assume it includes https://github.com/openhab/org.openhab.binding.zigbee/commit/22f4e89c97982433f2b56e62febdf268424a8d32

openhab-cli info

Version:     3.2.0 (Build)
dhelleberg commented 2 years ago

I face unfortunately the same issue on 3.3.0.M1

openhab-bot commented 2 years ago

This issue has been mentioned on openHAB Community. There might be relevant details there:

https://community.openhab.org/t/firmware-upgrade-the-bitronvideo-bv-2010-10-zigbee-usb-dongle/128879/1

flozano commented 2 years ago

I'm being hit heavily by this bug also

ZeiP commented 2 years ago

Me too. This is something there should be at least a workaround for.

ZeiP commented 2 years ago

I actually managed to work around this by:

  1. Disabling the existing controller through the UI
  2. Adding the controller again manually with the correct settings
  3. Changing the bridgeUID parameter from the Code tab of each Thing to point to the new controller. Most of my devices returned back to online status after this, but I had to manually re-add some of my devices, at least the Aqara door switches.
openhab-bot commented 2 years ago

This issue has been mentioned on openHAB Community. There might be relevant details there:

https://community.openhab.org/t/ledvance-smart-outdoor-zigbee-pairing-but-not-working/135974/3

flozano commented 2 years ago

I actually managed to work around this by:

  1. Disabling the existing controller through the UI
  2. Adding the controller again manually with the correct settings
  3. Changing the bridgeUID parameter from the Code tab of each Thing to point to the new controller. Most of my devices returned back to online status after this, but I had to manually re-add some of my devices, at least the Aqara door switches.

I tried this way and the USB device actually comes as online immediately, but when changing the bridge for the devices they get GONE status immediately...

cdjackson commented 2 years ago

I will remove discovery from the binding to resolve this.