Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

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

Closed
joerg1985 opened this issue Jan 11, 2022 · 25 comments · Fixed by #760
Closed

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

joerg1985 opened this issue Jan 11, 2022 · 25 comments · Fixed by #760
Labels
Milestone

Comments

@joerg1985
Copy link

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
Copy link
Contributor

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
Copy link
Author

logs.txt

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

@cdjackson
Copy link
Contributor

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

@joerg1985
Copy link
Author

joerg1985 commented Jan 12, 2022

@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
Copy link
Contributor

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
Copy link
Member

wborn commented Jan 16, 2022

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

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
Copy link
Contributor

cdjackson commented Jan 16, 2022 via email

@wborn
Copy link
Member

wborn commented Jan 16, 2022

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 eclipse-archived/smarthome#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
Copy link
Contributor

cdjackson commented Jan 16, 2022 via email

@cdjackson
Copy link
Contributor

@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
Copy link
Member

wborn commented Jan 17, 2022

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 eclipse-archived/smarthome#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
Copy link
Collaborator

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
Copy link
Member

wborn commented Jan 17, 2022

I also read in eclipse-archived/smarthome#3975 (comment) that new discovery results are used for updating the locations in existing astro/weather binding things.

@wborn
Copy link
Member

wborn commented Jan 17, 2022

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
Copy link

obones commented Jan 17, 2022

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
Copy link
Contributor

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
Copy link
Contributor

nailyk-fr commented Feb 16, 2022

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 22f4e89

openhab-cli info

Version:     3.2.0 (Build)

@dhelleberg
Copy link

I face unfortunately the same issue on 3.3.0.M1

@openhab-bot
Copy link
Collaborator

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
Copy link

flozano commented May 22, 2022

I'm being hit heavily by this bug also

@ZeiP
Copy link

ZeiP commented May 24, 2022

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

@ZeiP
Copy link

ZeiP commented May 24, 2022

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
Copy link
Collaborator

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
Copy link

flozano commented May 25, 2022

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
Copy link
Contributor

I will remove discovery from the binding to resolve this.

@cdjackson cdjackson added the bug label May 29, 2022
@cdjackson cdjackson added this to the 3.3 milestone May 29, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

Successfully merging a pull request may close this issue.

9 participants