New user trying to set up HUSBZB ZigBee

Add-ons Bindings
18

For H102:

dmesg -T|grep tty
[Wed Jan  1 18:03:21 2020] Kernel command line: coherent_pool=1M 8250.nr_uarts=0 bcm2708_fb.fbwidth=656 bcm2708_fb.fbheight=416 bcm2708_fb.fbdepth=16 bcm2708_fb.fbswap=1 vc_mem.mem_base=0x3f000000 vc_mem.mem_size=0x3f600000  dwc_otg.lpm_enable=0 console=ttyS0,115200 console=tty1 root=PARTUUID=f6de938e-02 rootfstype=ext4 elevator=deadline fsck.repair=yes rootwait
[Wed Jan  1 18:03:21 2020] console [tty1] enabled
[Wed Jan  1 18:03:21 2020] 3f201000.serial: ttyAMA0 at MMIO 0x3f201000 (irq = 81, base_baud = 0) is a PL011 rev2
[Wed Jan  1 18:05:11 2020] usb 1-1.2: cp210x converter now attached to ttyUSB0
[Wed Jan  1 18:05:11 2020] usb 1-1.2: cp210x converter now attached to ttyUSB1
[Thu Jan  2 09:18:04 2020] cp210x ttyUSB0: usb_serial_generic_read_bulk_callback - urb stopped: -32
[Thu Jan  2 09:18:04 2020] cp210x ttyUSB0: usb_serial_generic_read_bulk_callback - urb stopped: -32
[Thu Jan  2 09:18:05 2020] cp210x ttyUSB0: failed get req 0x8 size 1 status: -32
[Thu Jan  2 09:18:05 2020] cp210x ttyUSB0: failed set request 0x12 status: -19
[Thu Jan  2 09:18:05 2020] cp210x ttyUSB0: failed set request 0x0 status: -19
[Thu Jan  2 09:18:05 2020] cp210x ttyUSB0: cp210x converter now disconnected from ttyUSB0
[Thu Jan  2 09:18:05 2020] cp210x ttyUSB1: cp210x converter now disconnected from ttyUSB1
[Thu Jan  2 09:30:52 2020] usb 1-1.2: cp210x converter now attached to ttyUSB0
[Thu Jan  2 09:30:52 2020] usb 1-1.2: cp210x converter now attached to ttyUSB1

and chris, I am looking for the binding documentation you mentioned. But here is the log output that Ii have for now, after doing the things H102 suggested.

2020-01-02 09:18:02.030 [hingStatusInfoChangedEvent] - 'zigbee:coordinator_ember:df56b300' changed from UNKNOWN to UNINITIALIZED

==> /var/log/openhab2/openhab.log <==

2020-01-02 09:18:02.058 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - null: networkStateUpdated called with state=SHUTDOWN

2020-01-02 09:18:02.072 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - null: networkStateUpdated called with state=OFFLINE

==> /var/log/openhab2/events.log <==

2020-01-02 09:18:02.085 [hingStatusInfoChangedEvent] - 'zigbee:coordinator_ember:df56b300' changed from UNINITIALIZED to OFFLINE: Failed to open communications port

2020-01-02 09:18:02.097 [hingStatusInfoChangedEvent] - 'zigbee:coordinator_ember:df56b300' changed from OFFLINE: Failed to open communications port to OFFLINE (COMMUNICATION_ERROR)

2020-01-02 09:18:02.175 [vent.ItemStateChangedEvent] - zigbee_coordinator_ember_df56b300_rx_dat changed from NULL to 0

==> /var/log/openhab2/openhab.log <==

2020-01-02 09:18:02.178 [DEBUG] [ding.zigbee.handler.ZigBeeSerialPort] - Serial port '/dev/ttyUSB0' closed.

2020-01-02 09:18:02.185 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - ZigBee network [zigbee:coordinator_ember:df56b300] closed.

==> /var/log/openhab2/events.log <==

2020-01-02 09:18:02.197 [vent.ItemStateChangedEvent] - zigbee_coordinator_ember_df56b300_tx_dat changed from NULL to 0

2020-01-02 09:18:02.200 [vent.ItemStateChangedEvent] - zigbee_coordinator_ember_df56b300_rx_ack changed from NULL to 0

2020-01-02 09:18:02.203 [vent.ItemStateChangedEvent] - zigbee_coordinator_ember_df56b300_tx_ack changed from NULL to 0

2020-01-02 09:18:02.205 [vent.ItemStateChangedEvent] - zigbee_coordinator_ember_df56b300_rx_nak changed from NULL to 0

2020-01-02 09:18:02.213 [vent.ItemStateChangedEvent] - zigbee_coordinator_ember_df56b300_tx_nak changed from NULL to 0

2020-01-02 09:18:02.230 [hingStatusInfoChangedEvent] - 'zigbee:coordinator_ember:df56b300' changed from OFFLINE (COMMUNICATION_ERROR) to UNINITIALIZED (HANDLER_MISSING_ERROR)

==> /var/log/openhab2/openhab.log <==

2020-01-02 09:18:03.104 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Initialising ZigBee coordinator

2020-01-02 09:18:03.107 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Mesh Update Period 86400

2020-01-02 09:18:03.110 [DEBUG] [ding.zigbee.handler.ZigBeeSerialPort] - Connecting to serial port [/dev/ttyUSB0] at 57600 baud, flow control FLOWCONTROL_OUT_XONOFF.

2020-01-02 09:18:03.115 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - null: networkStateUpdated called with state=INITIALISING

2020-01-02 09:18:03.141 [DEBUG] [ding.zigbee.handler.ZigBeeSerialPort] - Serial port [/dev/ttyUSB0] is initialized.

==> /var/log/openhab2/events.log <==

2020-01-02 09:18:03.556 [thome.event.ExtensionEvent] - Extension 'binding-zigbee' has been uninstalled.

==> /var/log/openhab2/openhab.log <==

2020-01-02 09:19:19.875 [DEBUG] [ding.serial.internal.SerialActivator] - Serial binding has been stopped.

2020-01-02 09:19:20.142 [INFO ] [basic.internal.servlet.WebAppServlet] - Stopped Basic UI

2020-01-02 09:19:36.519 [INFO ] [assic.internal.servlet.WebAppServlet] - Stopped Classic UI

2020-01-02 09:19:36.580 [INFO ] [ui.habmin.internal.servlet.HABminApp] - Stopped HABmin servlet

==> /var/log/openhab2/events.log <==

2020-01-02 09:19:36.883 [temChannelLinkRemovedEvent] - Link 'zigbee_coordinator_ember_df56b300_rx_ack => zigbee:coordinator_ember:df56b300:rx_ack' has been removed.

2020-01-02 09:19:36.889 [temChannelLinkRemovedEvent] - Link 'zigbee_coordinator_ember_df56b300_tx_nak => zigbee:coordinator_ember:df56b300:tx_nak' has been removed.

2020-01-02 09:19:36.894 [temChannelLinkRemovedEvent] - Link 'zigbee_coordinator_ember_df56b300_tx_dat => zigbee:coordinator_ember:df56b300:tx_dat' has been removed.

2020-01-02 09:19:36.897 [temChannelLinkRemovedEvent] - Link 'zigbee_coordinator_ember_df56b300_tx_ack => zigbee:coordinator_ember:df56b300:tx_ack' has been removed.

2020-01-02 09:19:36.900 [temChannelLinkRemovedEvent] - Link 'zigbee_coordinator_ember_df56b300_rx_dat => zigbee:coordinator_ember:df56b300:rx_dat' has been removed.

2020-01-02 09:19:36.905 [temChannelLinkRemovedEvent] - Link 'zigbee_coordinator_ember_df56b300_rx_nak => zigbee:coordinator_ember:df56b300:rx_nak' has been removed.

==> /var/log/openhab2/openhab.log <==

2020-01-02 09:19:37.157 [INFO ] [panel.internal.HABPanelDashboardTile] - Stopped HABPanel

2020-01-02 09:19:37.202 [INFO ] [openhab.ui.paper.internal.PaperUIApp] - Stopped Paper UI

2020-01-02 09:19:37.238 [INFO ] [.dashboard.internal.DashboardService] - Stopped Dashboard

2020-01-02 09:28:18.549 [INFO ] [thome.model.lsp.internal.ModelServer] - Started Language Server Protocol (LSP) service on port 5007

2020-01-02 09:28:20.672 [INFO ] [.dashboard.internal.DashboardService] - Started Dashboard at http://192.168.1.201:8080

2020-01-02 09:28:20.681 [INFO ] [.dashboard.internal.DashboardService] - Started Dashboard at https://192.168.1.201:8443

2020-01-02 09:28:20.906 [DEBUG] [ding.serial.internal.SerialActivator] - Serial binding has been started.

2020-01-02 09:28:22.845 [INFO ] [ui.habmin.internal.servlet.HABminApp] - Started HABmin servlet at /habmin

2020-01-02 09:28:23.110 [INFO ] [openhab.ui.paper.internal.PaperUIApp] - Started Paper UI at /paperui

2020-01-02 09:28:23.329 [INFO ] [panel.internal.HABPanelDashboardTile] - Started HABPanel at /habpanel

2020-01-02 09:31:30.417 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - Starting ZigBeeDiscoveryService

==> /var/log/openhab2/events.log <==

2020-01-02 09:31:30.852 [thome.event.ExtensionEvent] - Extension 'binding-zigbee' has been installed.

2020-01-02 09:31:31.188 [hingStatusInfoChangedEvent] - 'zigbee:coordinator_ember:df56b300' changed from UNINITIALIZED to INITIALIZING

==> /var/log/openhab2/openhab.log <==

2020-01-02 09:31:31.216 [DEBUG] [ng.zigbee.ember.handler.EmberHandler] - Initializing ZigBee Ember serial bridge handler.

2020-01-02 09:31:31.218 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Initializing ZigBee network [zigbee:coordinator_ember:df56b300].

2020-01-02 09:31:31.220 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Channel 11

2020-01-02 09:31:31.222 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - PANID 35112

2020-01-02 09:31:31.224 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - EPANID CF5AB932B32CE585

2020-01-02 09:31:31.228 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Network Key 4A0BB91BD9CDC704E6D023CA43BB4F28

2020-01-02 09:31:31.230 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Link Key 5A6967426565416C6C69616E63653039

2020-01-02 09:31:31.232 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Config: zigbee_initialise found, initializeNetwork=false

2020-01-02 09:31:31.234 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Network Key String 4A0BB91BD9CDC704E6D023CA43BB4F28

2020-01-02 09:31:31.238 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Network key final array 4A0BB91BD9CDC704E6D023CA43BB4F28

2020-01-02 09:31:31.240 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Link Key String 5A6967426565416C6C69616E63653039

2020-01-02 09:31:31.243 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Link key final array 5A6967426565416C6C69616E63653039

2020-01-02 09:31:31.340 [DEBUG] [ng.zigbee.ember.handler.EmberHandler] - ZigBee Ember Coordinator opening Port:'/dev/ttyUSB0' PAN:8928, EPAN:CF5AB932B32CE585, Channel:11

2020-01-02 09:31:31.343 [DEBUG] [ng.zigbee.ember.handler.EmberHandler] - Ember end device poll timout set to (169 * 2^9) = 86528 seconds

2020-01-02 09:31:31.365 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Scheduling ZigBee start

==> /var/log/openhab2/events.log <==

2020-01-02 09:31:31.376 [hingStatusInfoChangedEvent] - 'zigbee:coordinator_ember:df56b300' changed from INITIALIZING to UNKNOWN

==> /var/log/openhab2/openhab.log <==

2020-01-02 09:31:32.372 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - ZigBee network starting

2020-01-02 09:31:32.375 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Initialising ZigBee coordinator

2020-01-02 09:31:32.453 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Mesh Update Period 86400

2020-01-02 09:31:32.490 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - null: networkStateUpdated called with state=INITIALISING

2020-01-02 09:31:32.495 [DEBUG] [ding.zigbee.handler.ZigBeeSerialPort] - Connecting to serial port [/dev/ttyUSB0] at 57600 baud, flow control FLOWCONTROL_OUT_XONOFF.

2020-01-02 09:31:32.533 [DEBUG] [ding.zigbee.handler.ZigBeeSerialPort] - Serial port [/dev/ttyUSB0] is initialized.

==> /var/log/openhab2/events.log <==

2020-01-02 09:31:39.393 [nt.FirmwareStatusInfoEvent] - Firmware status of thing zigbee:coordinator_ember:df56b300 changed to UNKNOWN.

Thank you both

19

What serial port did you select in PaperUI drop down?

20

It would help in pretty much every case - the only time it won’t help is if there is only ever one USB serial dongle on a machine, and even in that case, it would not hurt :slight_smile:

1 Like
21

This all looks the same - nearly the last thing in the log shows that the port opened ok. I think we need more log information to see what is happening.

22

H102:
/dev/ttyUSB0

chris:
I think I set the logs as you suggested; and this is output:

020-01-02 09:47:20.078 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst []

2020-01-02 09:47:21.683 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst []

2020-01-02 09:47:23.286 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst []

2020-01-02 09:47:24.891 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst []

2020-01-02 09:47:26.495 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst []

2020-01-02 09:47:28.099 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst []

2020-01-02 09:47:29.704 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst []

2020-01-02 09:47:31.308 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst []

2020-01-02 09:47:32.912 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst []

2020-01-02 09:47:34.517 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst []

2020-01-02 09:47:36.121 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst []

2020-01-02 09:47:37.725 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst []

2020-01-02 09:47:39.330 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst []

2020-01-02 09:47:40.933 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst []

2020-01-02 09:47:42.537 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst []

2020-01-02 09:47:44.140 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst []

2020-01-02 09:47:45.745 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst []

2020-01-02 09:47:47.348 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst []

2020-01-02 09:47:48.952 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst []

2020-01-02 09:47:50.555 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst []

2020-01-02 09:47:52.166 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst []

2020-01-02 09:47:53.769 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst []

2020-01-02 09:47:55.372 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst []

2020-01-02 09:47:56.975 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst []

2020-01-02 09:47:58.579 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst []

2020-01-02 09:48:00.182 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst []

2020-01-02 09:48:01.786 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst []

2020-01-02 09:48:03.390 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst []

2020-01-02 09:48:04.993 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst []

2020-01-02 09:48:06.597 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst []

2020-01-02 09:48:08.199 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst []

2020-01-02 09:48:09.802 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst []

2020-01-02 09:48:11.411 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst []

2020-01-02 09:48:13.014 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst []

2020-01-02 09:48:14.617 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst []

2020-01-02 09:48:16.221 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst []

2020-01-02 09:48:17.824 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst []

2020-01-02 09:48:19.427 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst []

2020-01-02 09:48:21.030 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst []

2020-01-02 09:48:22.633 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst []

2020-01-02 09:48:24.236 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst []

2020-01-02 09:48:25.840 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst []

2020-01-02 09:48:27.443 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst []

2020-01-02 09:48:29.046 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst []

2020-01-02 09:48:30.650 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst []

2020-01-02 09:48:32.253 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst []

2020-01-02 09:48:33.856 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst []

2020-01-02 09:48:35.459 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst []

2020-01-02 09:48:37.063 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst []

2020-01-02 09:48:38.666 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst []
23

Try setting up a UDEV rule on your Pi and see if that helps. Something like in this post Linear HUSBZB-1

24

Thanks, a UDEV rule is another new thing for me to research/learn so it may take a while till I post a report.

1 Like
25

Yep - looks “better”…

What this tells me is that the port is opening, but the dongle is not communicating. The binding is sending the reset command repeatedly.

Are you sure you have the right port? The HUSBZB should provide both ZWave and ZigBee, so there should be two ports showing up in your system. I’m not sure which way around the ports arbitrate, but I seem to recall someone saying they always appear is a specific order (@Bruce_Osborne you might know the answer to this?). I’m just wondering if you’re connected to the ZWave side of the dongle?

26

I have that dongle on my test system but I do not have any Zigbee devices.
I can set up the Zigbee coordinator on it this evening to check, if that would help.

27

I think Zigbee is the second, if I remember correctly.:thinking:

28

the HUSBZB presents itself as 2 serial interfaces in the OS. (1 for Z-Wave & 1 for Zigbee)

29

H102
I added the two lines of code you pointed me to in a file /etc/udev/rules.d/999-HUSBZB.rules.
Interesting thing now in addition to the ttyUSB0 and ttyUSB1 port options that I had in the PaperUI setup for the stick I also have a new ttyUSB-5. I have tried all three with same results.

30

Do you have anything else plugged into the USB ports? My stick shows up as ttyUSB0 and ttyUSB1 but I have no other devices attached.

31

No, nothing else. I did have just ttyUSB0 and ttyUSB1 before I did the UDEV rule H102 and chris suggested (if I did that correctly)

32

I will try and look further this evening. I am in the eastern US.

33

@Dave55 Try using the USB-5 and see what happens you may be able to try USB-55 as well.

Here is an old article but you may find it useful https://github.com/openhab/openhab1-addons/wiki/symlinks

34

@H102 Too impatient or just do not need my testing?
Like I stated I have that stick currently connected to a Raspberry Pi 3B+.

35

@Bruce_Osborne :laughing: I’m just impatient.:laughing:

1 Like
36

Getting ready to leave for home now.

37

@Bruce_Osborne but It’s only 4:30, who’s the impatient one again?:rofl: