openhab / org.openhab.binding.zigbee

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

Updated to 2.4.0-M5 from 2.3.0 - no longer able to access UART over USB #290

Closed nefilim closed 5 years ago

nefilim commented 5 years ago

This happened after updating as requested in #289

Outline

Replaced the contents of the existing yum repo with the Testing repo and yum update openhab2. Restarted OpenHab2 and rebooted.

[root@nexus ~]# dmesg | grep -i usb
[    0.716193] usbcore: registered new interface driver usbserial
[    0.716203] usbcore: registered new interface driver usbserial_generic
[    0.716212] usbserial: USB Serial support registered for generic
[    1.759921] usbcore: registered new interface driver usbhid
[    1.759924] usbhid: USB HID core driver
[    2.011003] usb 1-4: new full-speed USB device number 2 using xhci_hcd
[    2.177191] usb 1-4: string descriptor 0 read error: -22
[    2.177203] usb 1-4: New USB device found, idVendor=04ca, idProduct=3007
[    2.177207] usb 1-4: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[    2.331977] usb 1-5: new full-speed USB device number 3 using xhci_hcd
[    2.497685] usb 1-5: New USB device found, idVendor=10c4, idProduct=8a2a
[    2.497691] usb 1-5: New USB device strings: Mfr=1, Product=2, SerialNumber=5
[    2.497695] usb 1-5: Product: HubZ Smart Home Controller
[    2.497699] usb 1-5: Manufacturer: Silicon Labs
[    2.497702] usb 1-5: SerialNumber: 61200A2E
[    2.651991] usb 1-6: new full-speed USB device number 4 using xhci_hcd
[    2.817667] usb 1-6: New USB device found, idVendor=10c4, idProduct=8a2a
[    2.817673] usb 1-6: New USB device strings: Mfr=1, Product=2, SerialNumber=5
[    2.817677] usb 1-6: Product: HubZ Smart Home Controller
[    2.817680] usb 1-6: Manufacturer: Silicon Labs
[    2.817683] usb 1-6: SerialNumber: 61200DD8
[    4.433761] usbcore: registered new interface driver cp210x
[    4.433784] usbserial: USB Serial support registered for cp210x
[    4.434777] usb 1-5: cp210x converter now attached to ttyUSB0
[    4.435836] usb 1-5: cp210x converter now attached to ttyUSB1
[    4.436557] usb 1-6: cp210x converter now attached to ttyUSB2
[    4.437380] usb 1-6: cp210x converter now attached to ttyUSB3
[    4.843305] usbcore: registered new interface driver btusb
[    4.939114] usb 1-4: USB disconnect, device number 2
[    4.939489] usbcore: registered new interface driver ath3k
[    5.223830] usb 1-4: new full-speed USB device number 5 using xhci_hcd
[    5.389065] usb 1-4: string descriptor 0 read error: -22
[    5.389077] usb 1-4: New USB device found, idVendor=04ca, idProduct=3007
[    5.389081] usb 1-4: New USB device strings: Mfr=1, Product=2, SerialNumber=3

[root@nexus ~]# lsusb
Bus 002 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub
Bus 001 Device 004: ID 10c4:8a2a Cygnal Integrated Products, Inc. 
Bus 001 Device 003: ID 10c4:8a2a Cygnal Integrated Products, Inc. 
Bus 001 Device 005: ID 04ca:3007 Lite-On Technology Corp. 
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub

[root@nexus ~]# grep -i usb /etc/default/openhab2 
##   EXTRA_JAVA_OPTS="-Dgnu.io.rxtx.SerialPorts=/dev/ttyUSB0:/dev/ttyS0:/dev/ttyS2:/dev/ttyACM0:/dev/ttyAMA0"
EXTRA_JAVA_OPTS="-Dgnu.io.rxtx.SerialPorts=/dev/ttyUSB0:/dev/ttyUSB1:/dev/ttyUSB2:/dev/ttyS0:/dev/ttyS2"

openhab   2049  7.7 23.4 3244568 449616 ?      Ssl  13:53   0:57 /usr/bin/java -Dopenhab.home=/usr/share/openhab2 -Dopenhab.conf=/etc/openhab2 -Dopenhab.runtime=/usr/share/openhab2/runtime -Dopenhab.userdata=/var/lib/openhab2 -Dopenhab.logdir=/var/log/openhab2 -Dfelix.cm.dir=/var/lib/openhab2/config -Djava.library.path=/var/lib/openhab2/tmp/lib -Djetty.host=0.0.0.0 -Djetty.http.compliance=RFC2616 -Dorg.ops4j.pax.web.listening.addresses=0.0.0.0 -Dorg.osgi.service.http.port=8080 -Dorg.osgi.service.http.port.secure=8443 -Djava.awt.headless=true -XX:+UseG1GC -Dgnu.io.rxtx.SerialPorts=/dev/ttyUSB0:/dev/ttyUSB1:/dev/ttyUSB2:/dev/ttyS0:/dev/ttyS2 -Djava.endorsed.dirs=/usr/lib/jvm/zulu-8/jre/lib/endorsed:/usr/lib/jvm/zulu-8/lib/endorsed:/usr/share/openhab2/runtime/lib/endorsed -Djava.ext.dirs=/usr/lib/jvm/zulu-8/jre/lib/ext:/usr/lib/jvm/zulu-8/lib/ext:/usr/share/openhab2/runtime/lib/ext -Dkaraf.instances=/var/lib/openhab2/tmp/instances -Dkaraf.home=/usr/share/openhab2/runtime -Dkaraf.base=/var/lib/openhab2 -Dkaraf.data=/var/lib/openhab2 -Dkaraf.etc=/var/lib/openhab2/etc -Dkaraf.logs=/var/log/openhab2 -Dkaraf.restart.jvm.supported=true -Djava.io.tmpdir=/var/lib/openhab2/tmp -Djava.util.logging.config.file=/var/lib/openhab2/etc/java.util.logging.properties -Dkaraf.startLocalConsole=false -Dkaraf.startRemoteShell=true -classpath /usr/share/openhab2/runtime/lib/boot/activation-1.1.1.jar:/usr/share/openhab2/runtime/lib/boot/jaxb-api-2.3.0.jar:/usr/share/openhab2/runtime/lib/boot/jaxb-core-2.2.11.jar:/usr/share/openhab2/runtime/lib/boot/jaxb-impl-2.2.11.jar:/usr/share/openhab2/runtime/lib/boot/jna-4.5.2.jar:/usr/share/openhab2/runtime/lib/boot/jna-platform-4.5.2.jar:/usr/share/openhab2/runtime/lib/boot/org.apache.karaf.diagnostic.boot-4.2.1.jar:/usr/share/openhab2/runtime/lib/boot/org.apache.karaf.jaas.boot-4.2.1.jar:/usr/share/openhab2/runtime/lib/boot/org.apache.karaf.main-4.2.1.jar:/usr/share/openhab2/runtime/lib/boot/org.osgi.core-6.0.0.jar org.apache.karaf.main.Main

[root@nexus ~]# groups openhab
openhab : openhab tty dialout audio

[root@nexus ~]# ls -l /dev/ttyUSB*
crw-rw---- 1 root dialout 188, 0 Nov  1 13:45 /dev/ttyUSB0
crw-rw---- 1 root dialout 188, 1 Nov  1 13:45 /dev/ttyUSB1
crw-rw---- 1 root dialout 188, 2 Nov  1 13:45 /dev/ttyUSB2
crw-rw---- 1 root dialout 188, 3 Nov  1 13:45 /dev/ttyUSB3

I've also installed the Serial binding but it did not fix the problem.

Configuration

Configuration Description
Coordinator used HUSBZB-1
openHAB version 2.4.0-M5
Hardware Chromebox
Memory 2GB
Java version openjdk version "1.8.0_181", OpenJDK Runtime Environment (Zulu 8.31.0.1-linux64) (build 1.8.0_181-b02), OpenJDK 64-Bit Server VM (Zulu 8.31.0.1-linux64) (build 25.181-b02, mixed mode)
Devices Provide all device types and their addresses

Logs

2018-11-01 13:53:31.698 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - F0D1B8000002B04B: Initializing ZigBee thing handler zigbee:device:5b077569:f0d1b8000002b04b
2018-11-01 13:53:31.699 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - F0D1B8000002B04B: Coordinator status changed to UNKNOWN.
2018-11-01 13:53:31.702 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - F0D1B8000002B04B: Coordinator is unknown or not online.
2018-11-01 13:53:31.921 [WARN ] [e.jetty.util.thread.ThreadPoolBudget] - Low configured threads: (max=8 - required=1)=7 < warnAt=8 for QueuedThreadPool[ServletModel-19]@49d775{STARTING,8<=0<=8,i=0,q=0}[ReservedThreadExecutor@4a5363c2{s=0/1,p=0}]
2018-11-01 13:53:32.127 [DEBUG] [com.zsmartsystems.zigbee            ] - BundleEvent STARTING - com.zsmartsystems.zigbee
2018-11-01 13:53:32.132 [DEBUG] [com.zsmartsystems.zigbee            ] - BundleEvent STARTED - com.zsmartsystems.zigbee
2018-11-01 13:53:32.137 [DEBUG] [m.zsmartsystems.zigbee.dongle.cc2531] - BundleEvent STARTING - com.zsmartsystems.zigbee.dongle.cc2531
2018-11-01 13:53:32.152 [DEBUG] [m.zsmartsystems.zigbee.dongle.cc2531] - BundleEvent STARTED - com.zsmartsystems.zigbee.dongle.cc2531
2018-11-01 13:53:32.160 [DEBUG] [om.zsmartsystems.zigbee.dongle.ember] - BundleEvent STARTING - com.zsmartsystems.zigbee.dongle.ember
2018-11-01 13:53:32.167 [DEBUG] [om.zsmartsystems.zigbee.dongle.ember] - BundleEvent STARTED - com.zsmartsystems.zigbee.dongle.ember
2018-11-01 13:53:32.170 [DEBUG] [smartsystems.zigbee.dongle.telegesis] - BundleEvent STARTING - com.zsmartsystems.zigbee.dongle.telegesis
2018-11-01 13:53:32.174 [DEBUG] [smartsystems.zigbee.dongle.telegesis] - BundleEvent STARTED - com.zsmartsystems.zigbee.dongle.telegesis
2018-11-01 13:53:32.182 [DEBUG] [com.zsmartsystems.zigbee.dongle.xbee] - BundleEvent STARTING - com.zsmartsystems.zigbee.dongle.xbee
2018-11-01 13:53:32.184 [DEBUG] [com.zsmartsystems.zigbee.dongle.xbee] - BundleEvent STARTED - com.zsmartsystems.zigbee.dongle.xbee
2018-11-01 13:53:32.346 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - ZigBee network starting
2018-11-01 13:53:32.347 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Initialising ZigBee coordinator
2018-11-01 13:53:32.376 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Adding supported cluster 1280
2018-11-01 13:53:32.378 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode ] - ClusterMatcher starting
2018-11-01 13:53:32.461 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode ] - ClusterMatcher adding cluster IAS_ZONE
2018-11-01 13:53:32.471 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Adding supported cluster 25
2018-11-01 13:53:32.472 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode ] - ClusterMatcher adding cluster OTA_UPGRADE
2018-11-01 13:53:32.477 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EZSP dongle initialize with protocol ASH2.
2018-11-01 13:53:32.484 [DEBUG] [ding.zigbee.handler.ZigBeeSerialPort] - Connecting to serial port [/dev/ttyUSB1] at 57600 baud, flow control FLOWCONTROL_OUT_XONOFF.
2018-11-01 13:53:32.494 [ERROR] [ding.zigbee.handler.ZigBeeSerialPort] - Serial Error: Port /dev/ttyUSB1 does not exist.
2018-11-01 13:53:32.504 [ERROR] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unable to open Ember serial port
2018-11-01 13:53:32.507 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Loading ZigBee network state: Start.
2018-11-01 13:53:32.879 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 000D6F001200CEBE: Node 0 added to the network
2018-11-01 13:53:33.134 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - F0D1B8000002AC4F: Node 13783 added to the network
2018-11-01 13:53:33.137 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - F0D1B8000002ADC8: Node 61453 added to the network
2018-11-01 13:53:33.138 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - F0D1B8000002B04B: Node 28675 added to the network
2018-11-01 13:53:33.151 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - F0D1B8000002B3E6: Node 57464 added to the network
2018-11-01 13:53:33.153 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Loading ZigBee network state: Done.
2018-11-01 13:53:33.154 [DEBUG] [bee.internal.ZigBeeNetworkDiscoverer] - Network discovery task starting
2018-11-01 13:53:33.170 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - F0D1B8000002B3E6: Coordinator status changed to OFFLINE.
2018-11-01 13:53:33.175 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - F0D1B8000002B3E6: Coordinator is unknown or not online.
2018-11-01 13:53:33.171 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - F0D1B8000002B04B: Coordinator status changed to OFFLINE.
2018-11-01 13:53:33.176 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - F0D1B8000002B04B: Coordinator is unknown or not online.
2018-11-01 13:53:33.187 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - B0CE181403182CDE: Coordinator status changed to OFFLINE.
2018-11-01 13:53:33.189 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - B0CE181403182CDE: Coordinator is unknown or not online.
2018-11-01 13:53:33.187 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - F0D1B8000002ADC8: Coordinator status changed to OFFLINE.
2018-11-01 13:53:33.190 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - F0D1B8000002ADC8: Coordinator is unknown or not online.
2018-11-01 13:53:33.188 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - F0D1B8000002AC4F: Coordinator status changed to OFFLINE.
2018-11-01 13:53:33.191 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - F0D1B8000002AC4F: Coordinator is unknown or not online.
2018-11-01 13:53:33.234 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - F0D1B8000002B3E6: Channel zigbee:device:5b077569:f0d1b8000002b3e6:F0D1B8000002B3E6_1_switch_level linked - polling started.
2018-11-01 13:53:33.254 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - B0CE181403182CDE: Channel zigbee:device:5b077569:b0ce181403182cde:B0CE181403182CDE_1_switch_level linked - polling started.
2018-11-01 13:53:33.267 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - F0D1B8000002ADC8: Channel zigbee:device:5b077569:f0d1b8000002adc8:F0D1B8000002ADC8_1_switch_level linked - polling started.
2018-11-01 13:53:33.279 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - F0D1B8000002B04B: Channel zigbee:device:5b077569:f0d1b8000002b04b:F0D1B8000002B04B_1_switch_level linked - polling started.
2018-11-01 13:53:33.286 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - F0D1B8000002ADC8: Channel zigbee:device:5b077569:f0d1b8000002adc8:F0D1B8000002ADC8_1_color_temperature linked - polling started.
2018-11-01 13:53:33.297 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - F0D1B8000002AC4F: Channel zigbee:device:5b077569:f0d1b8000002ac4f:F0D1B8000002AC4F_1_color_temperature linked - polling started.
2018-11-01 13:53:33.321 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - F0D1B8000002B04B: Channel zigbee:device:5b077569:f0d1b8000002b04b:F0D1B8000002B04B_1_color_temperature linked - polling started.
2018-11-01 13:53:33.333 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - F0D1B8000002AC4F: Channel zigbee:device:5b077569:f0d1b8000002ac4f:F0D1B8000002AC4F_1_switch_level linked - polling started.
2018-11-01 13:53:33.333 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - F0D1B8000002B3E6: Channel zigbee:device:5b077569:f0d1b8000002b3e6:F0D1B8000002B3E6_1_color_temperature linked - polling started.
2018-11-01 13:53:33.634 [INFO ] [arthome.ui.paper.internal.PaperUIApp] - Started Paper UI at /paperui
2018-11-01 13:54:01.354 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception: 
java.lang.NullPointerException: null
    at org.openhab.binding.zigbee.ember.handler.EmberHandler$1.run(EmberHandler.java:107) ~[?:?]
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) ~[?:?]
    at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) ~[?:?]
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) ~[?:?]
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) ~[?:?]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
    at java.lang.Thread.run(Thread.java:748) [?:?]
cdjackson commented 5 years ago

I guess you need to address why the serial port is not opening - it says it’s not available and the normal reason for this is security access rights.

On 1 Nov 2018, at 20:01, Peter vR notifications@github.com wrote:

This happened after updating as requested in #289 https://github.com/openhab/org.openhab.binding.zigbee/issues/289 Outline

Replaced the contents of the existing yum repo with the Testing repo and yum update openhab2. Restarted OpenHab2 and rebooted.

[root@nexus ~]# dmesg | grep -i usb [ 0.716193] usbcore: registered new interface driver usbserial [ 0.716203] usbcore: registered new interface driver usbserial_generic [ 0.716212] usbserial: USB Serial support registered for generic [ 1.759921] usbcore: registered new interface driver usbhid [ 1.759924] usbhid: USB HID core driver [ 2.011003] usb 1-4: new full-speed USB device number 2 using xhci_hcd [ 2.177191] usb 1-4: string descriptor 0 read error: -22 [ 2.177203] usb 1-4: New USB device found, idVendor=04ca, idProduct=3007 [ 2.177207] usb 1-4: New USB device strings: Mfr=1, Product=2, SerialNumber=3 [ 2.331977] usb 1-5: new full-speed USB device number 3 using xhci_hcd [ 2.497685] usb 1-5: New USB device found, idVendor=10c4, idProduct=8a2a [ 2.497691] usb 1-5: New USB device strings: Mfr=1, Product=2, SerialNumber=5 [ 2.497695] usb 1-5: Product: HubZ Smart Home Controller [ 2.497699] usb 1-5: Manufacturer: Silicon Labs [ 2.497702] usb 1-5: SerialNumber: 61200A2E [ 2.651991] usb 1-6: new full-speed USB device number 4 using xhci_hcd [ 2.817667] usb 1-6: New USB device found, idVendor=10c4, idProduct=8a2a [ 2.817673] usb 1-6: New USB device strings: Mfr=1, Product=2, SerialNumber=5 [ 2.817677] usb 1-6: Product: HubZ Smart Home Controller [ 2.817680] usb 1-6: Manufacturer: Silicon Labs [ 2.817683] usb 1-6: SerialNumber: 61200DD8 [ 4.433761] usbcore: registered new interface driver cp210x [ 4.433784] usbserial: USB Serial support registered for cp210x [ 4.434777] usb 1-5: cp210x converter now attached to ttyUSB0 [ 4.435836] usb 1-5: cp210x converter now attached to ttyUSB1 [ 4.436557] usb 1-6: cp210x converter now attached to ttyUSB2 [ 4.437380] usb 1-6: cp210x converter now attached to ttyUSB3 [ 4.843305] usbcore: registered new interface driver btusb [ 4.939114] usb 1-4: USB disconnect, device number 2 [ 4.939489] usbcore: registered new interface driver ath3k [ 5.223830] usb 1-4: new full-speed USB device number 5 using xhci_hcd [ 5.389065] usb 1-4: string descriptor 0 read error: -22 [ 5.389077] usb 1-4: New USB device found, idVendor=04ca, idProduct=3007 [ 5.389081] usb 1-4: New USB device strings: Mfr=1, Product=2, SerialNumber=3 [root@nexus ~]# lsusb Bus 002 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub Bus 001 Device 004: ID 10c4:8a2a Cygnal Integrated Products, Inc. Bus 001 Device 003: ID 10c4:8a2a Cygnal Integrated Products, Inc. Bus 001 Device 005: ID 04ca:3007 Lite-On Technology Corp. Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub Configuration

Configuration Description Coordinator used HUSBZB-1 openHAB version 2.4.0-M5 Hardware Chromebox Memory 2GB Java version openjdk version "1.8.0_181", OpenJDK Runtime Environment (Zulu 8.31.0.1-linux64) (build 1.8.0_181-b02), OpenJDK 64-Bit Server VM (Zulu 8.31.0.1-linux64) (build 25.181-b02, mixed mode) Devices Provide all device types and their addresses Logs

2018-11-01 13:53:31.698 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - F0D1B8000002B04B: Initializing ZigBee thing handler zigbee:device:5b077569:f0d1b8000002b04b 2018-11-01 13:53:31.699 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - F0D1B8000002B04B: Coordinator status changed to UNKNOWN. 2018-11-01 13:53:31.702 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - F0D1B8000002B04B: Coordinator is unknown or not online. 2018-11-01 13:53:31.921 [WARN ] [e.jetty.util.thread.ThreadPoolBudget] - Low configured threads: (max=8 - required=1)=7 < warnAt=8 for QueuedThreadPool[ServletModel-19]@49d775{STARTING,8<=0<=8,i=0,q=0}[ReservedThreadExecutor@4a5363c2{s=0/1,p=0}] 2018-11-01 13:53:32.127 [DEBUG] [com.zsmartsystems.zigbee ] - BundleEvent STARTING - com.zsmartsystems.zigbee 2018-11-01 13:53:32.132 [DEBUG] [com.zsmartsystems.zigbee ] - BundleEvent STARTED - com.zsmartsystems.zigbee 2018-11-01 13:53:32.137 [DEBUG] [m.zsmartsystems.zigbee.dongle.cc2531] - BundleEvent STARTING - com.zsmartsystems.zigbee.dongle.cc2531 2018-11-01 13:53:32.152 [DEBUG] [m.zsmartsystems.zigbee.dongle.cc2531] - BundleEvent STARTED - com.zsmartsystems.zigbee.dongle.cc2531 2018-11-01 13:53:32.160 [DEBUG] [om.zsmartsystems.zigbee.dongle.ember] - BundleEvent STARTING - com.zsmartsystems.zigbee.dongle.ember 2018-11-01 13:53:32.167 [DEBUG] [om.zsmartsystems.zigbee.dongle.ember] - BundleEvent STARTED - com.zsmartsystems.zigbee.dongle.ember 2018-11-01 13:53:32.170 [DEBUG] [smartsystems.zigbee.dongle.telegesis] - BundleEvent STARTING - com.zsmartsystems.zigbee.dongle.telegesis 2018-11-01 13:53:32.174 [DEBUG] [smartsystems.zigbee.dongle.telegesis] - BundleEvent STARTED - com.zsmartsystems.zigbee.dongle.telegesis 2018-11-01 13:53:32.182 [DEBUG] [com.zsmartsystems.zigbee.dongle.xbee] - BundleEvent STARTING - com.zsmartsystems.zigbee.dongle.xbee 2018-11-01 13:53:32.184 [DEBUG] [com.zsmartsystems.zigbee.dongle.xbee] - BundleEvent STARTED - com.zsmartsystems.zigbee.dongle.xbee 2018-11-01 13:53:32.346 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - ZigBee network starting 2018-11-01 13:53:32.347 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Initialising ZigBee coordinator 2018-11-01 13:53:32.376 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Adding supported cluster 1280 2018-11-01 13:53:32.378 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode ] - ClusterMatcher starting 2018-11-01 13:53:32.461 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode ] - ClusterMatcher adding cluster IAS_ZONE 2018-11-01 13:53:32.471 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Adding supported cluster 25 2018-11-01 13:53:32.472 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode ] - ClusterMatcher adding cluster OTA_UPGRADE 2018-11-01 13:53:32.477 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EZSP dongle initialize with protocol ASH2. 2018-11-01 13:53:32.484 [DEBUG] [ding.zigbee.handler.ZigBeeSerialPort] - Connecting to serial port [/dev/ttyUSB1] at 57600 baud, flow control FLOWCONTROL_OUT_XONOFF. 2018-11-01 13:53:32.494 [ERROR] [ding.zigbee.handler.ZigBeeSerialPort] - Serial Error: Port /dev/ttyUSB1 does not exist. 2018-11-01 13:53:32.504 [ERROR] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unable to open Ember serial port 2018-11-01 13:53:32.507 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Loading ZigBee network state: Start. 2018-11-01 13:53:32.879 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 000D6F001200CEBE: Node 0 added to the network 2018-11-01 13:53:33.134 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - F0D1B8000002AC4F: Node 13783 added to the network 2018-11-01 13:53:33.137 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - F0D1B8000002ADC8: Node 61453 added to the network 2018-11-01 13:53:33.138 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - F0D1B8000002B04B: Node 28675 added to the network 2018-11-01 13:53:33.151 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - F0D1B8000002B3E6: Node 57464 added to the network 2018-11-01 13:53:33.153 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Loading ZigBee network state: Done. 2018-11-01 13:53:33.154 [DEBUG] [bee.internal.ZigBeeNetworkDiscoverer] - Network discovery task starting 2018-11-01 13:53:33.170 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - F0D1B8000002B3E6: Coordinator status changed to OFFLINE. 2018-11-01 13:53:33.175 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - F0D1B8000002B3E6: Coordinator is unknown or not online. 2018-11-01 13:53:33.171 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - F0D1B8000002B04B: Coordinator status changed to OFFLINE. 2018-11-01 13:53:33.176 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - F0D1B8000002B04B: Coordinator is unknown or not online. 2018-11-01 13:53:33.187 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - B0CE181403182CDE: Coordinator status changed to OFFLINE. 2018-11-01 13:53:33.189 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - B0CE181403182CDE: Coordinator is unknown or not online. 2018-11-01 13:53:33.187 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - F0D1B8000002ADC8: Coordinator status changed to OFFLINE. 2018-11-01 13:53:33.190 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - F0D1B8000002ADC8: Coordinator is unknown or not online. 2018-11-01 13:53:33.188 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - F0D1B8000002AC4F: Coordinator status changed to OFFLINE. 2018-11-01 13:53:33.191 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - F0D1B8000002AC4F: Coordinator is unknown or not online. 2018-11-01 13:53:33.234 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - F0D1B8000002B3E6: Channel zigbee:device:5b077569:f0d1b8000002b3e6:F0D1B8000002B3E6_1_switch_level linked - polling started. 2018-11-01 13:53:33.254 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - B0CE181403182CDE: Channel zigbee:device:5b077569:b0ce181403182cde:B0CE181403182CDE_1_switch_level linked - polling started. 2018-11-01 13:53:33.267 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - F0D1B8000002ADC8: Channel zigbee:device:5b077569:f0d1b8000002adc8:F0D1B8000002ADC8_1_switch_level linked - polling started. 2018-11-01 13:53:33.279 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - F0D1B8000002B04B: Channel zigbee:device:5b077569:f0d1b8000002b04b:F0D1B8000002B04B_1_switch_level linked - polling started. 2018-11-01 13:53:33.286 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - F0D1B8000002ADC8: Channel zigbee:device:5b077569:f0d1b8000002adc8:F0D1B8000002ADC8_1_color_temperature linked - polling started. 2018-11-01 13:53:33.297 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - F0D1B8000002AC4F: Channel zigbee:device:5b077569:f0d1b8000002ac4f:F0D1B8000002AC4F_1_color_temperature linked - polling started. 2018-11-01 13:53:33.321 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - F0D1B8000002B04B: Channel zigbee:device:5b077569:f0d1b8000002b04b:F0D1B8000002B04B_1_color_temperature linked - polling started. 2018-11-01 13:53:33.333 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - F0D1B8000002AC4F: Channel zigbee:device:5b077569:f0d1b8000002ac4f:F0D1B8000002AC4F_1_switch_level linked - polling started. 2018-11-01 13:53:33.333 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - F0D1B8000002B3E6: Channel zigbee:device:5b077569:f0d1b8000002b3e6:F0D1B8000002B3E6_1_color_temperature linked - polling started. 2018-11-01 13:53:33.634 [INFO ] [arthome.ui.paper.internal.PaperUIApp] - Started Paper UI at /paperui 2018-11-01 13:54:01.354 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception: java.lang.NullPointerException: null at org.openhab.binding.zigbee.ember.handler.EmberHandler$1.run(EmberHandler.java:107) ~[?:?] at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) ~[?:?] at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) ~[?:?] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) ~[?:?] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) ~[?:?] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?] at java.lang.Thread.run(Thread.java:748) [?:?] — You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub https://github.com/openhab/org.openhab.binding.zigbee/issues/290, or mute the thread https://github.com/notifications/unsubscribe-auth/AA_kQ1qSmLT1LhhoMx28Ab7UyVR3jRh0ks5uq1MUgaJpZM4YIylH.

nefilim commented 5 years ago

@cdjackson - not sure what else to check? It was working, upgraded with yum and now it's not working, would it suggest something with the upgrade process is awry?

I've updated the original post a few times, checked everything I could think of. Also, selinux has been disabled since before I started playing with OpenHab

nefilim commented 5 years ago
-bash-4.2$ whoami
openhab
-bash-4.2$ cat /dev/ttyUSB1 
^C

if there was a permissions problem it would show cat: /dev/ttyUSB1: Permission denied

cdjackson commented 5 years ago

I’m not sure - serial port issues are a common problem unfortunately. Normally it’s related to security, but I’m not really an expert with the low level stuff. I don’t think it’s likely to be related to the binding and I don’t know if the update removed some serial options or security settings maybe?

cdjackson commented 5 years ago

I would suggest to discuss the serial port access issues on the community forum as it's not a binding bug.