RFXCOM: no messages logged in OpenHAB

Hi all.

I’m using a new RFXCOM on a Synology RS212 NAS running OpenHAB 1.8.1

As far as I can tell the setup is correct, no errors are logged w.r.t. RFXCOM, I know supported sensors are transmitting, yet OpenHAB is not logging any RFXCOM messages.

I’ve set up the USB drivers, permissions of /dev/ttyUSB0 are correct (read/write by all, including the openhab user)

/volume1/homes/openhab $ ls -l /dev/ttyUSB0
crw-rw-rw- 1 root root 188, 0 Mar 1 12:36 /dev/ttyUSB0

And when running as the openhab user, the python rfxcmd tool properly logs my temperature+humidity sensors.

/volume1/homes/openhab $ ./rfxcmd.py -d /dev/ttyUSB0 -lv
RFXCMD Version 0.3 (739)

Received = 0D 01 00 00 02 53 FB 00 04 04 00 01 03 1C
Date/Time = 2016-03-01 12:36:35
Packet Length = 0D
Packettype = Interface Message
Subtype = Interface response
Sequence nbr = 00
Response on cmnd = Get Status, return firmware versions and configuration of the interface.
Transceiver type = 433.92MHz (Transceiver)
Firmware version = 251
Protocols:
Undecoded Disabled
RFU Disabled
Byron SX Disabled
RSL Disabled
Lightning4 Disabled
FineOffset / Viking Disabled
Rubicson Disabled
AE Blyss Disabled
Blinds T1/T2/T3/T4 Disabled
Blinds T0 Disabled
ProGuard Disabled
FS20 Disabled
La Crosse Disabled
Hideki / UPM Enabled
AD Lightwave RF Disabled
Mertik Disabled
Visonic Disabled
ATI Disabled
Oregon Scientific Disabled
Meiantech Disabled
HomeEasy EU Disabled
AC Enabled
ARC Disabled
X10 Disabled

Received = 0A 52 07 00 3C 0E 00 CC 1D 02 89
Date/Time = 2016-03-01 12:37:00
Packet Length = 0A
Packettype = Temperature and humidity sensors
Subtype = TFA TS34C, Cresta
Seqnbr = 00
Id = 3C0E
Temperature = 20.4 C
Humidity = 29%
Humidity Status = Normal
Battery = 9
Signal level = 8

Received = 0A 52 07 01 7B 0E 00 BC 21 02 69
Date/Time = 2016-03-01 12:37:03
Packet Length = 0A
Packettype = Temperature and humidity sensors
Subtype = TFA TS34C, Cresta
Seqnbr = 01
Id = 7B0E
Temperature = 18.8 C
Humidity = 33%
Humidity Status = Normal
Battery = 9
Signal level = 6

Received = 0A 52 07 07 7B 0E 00 BC 21 02 79
Date/Time = 2016-03-01 12:39:24
Packet Length = 0A
Packettype = Temperature and humidity sensors
Subtype = TFA TS34C, Cresta
Seqnbr = 07
Id = 7B0E
Temperature = 18.8 C
Humidity = 33%
Humidity Status = Normal
Battery = 9
Signal level = 7

An exerpt from my logback.xml:

< logger name=“org.openhab.binding.rfxcom” level=“DEBUG” />

Yet no RFXCOM logs with received messages.

RackStation> ./openhab_logs.sh
2016-03-01 15:35:18.404 [INFO ] [.o.core.internal.CoreActivator] - openHAB runtime has been started (v1.8.1).
2016-03-01 15:35:30.201 [INFO ] [o.o.i.s.i.DiscoveryServiceImpl] - mDNS service has been started
2016-03-01 15:35:30.590 [INFO ] [o.o.i.s.i.DiscoveryServiceImpl] - Service Discovery initialization completed.
2016-03-01 15:35:35.040 [INFO ] [c.internal.ModelRepositoryImpl] - Loading model 'rrd4j.persist’
2016-03-01 15:35:38.608 [INFO ] [c.internal.ModelRepositoryImpl] - Loading model 'mysql.persist’
2016-03-01 15:35:38.883 [INFO ] [c.internal.ModelRepositoryImpl] - Loading model 'huis.items’
2016-03-01 15:35:51.056 [INFO ] [c.internal.ModelRepositoryImpl] - Loading model 'default.sitemap’
2016-03-01 15:35:53.408 [INFO ] [c.internal.ModelRepositoryImpl] - Loading model 'alarm.script’
2016-03-01 15:35:59.800 [INFO ] [penhab.io.rest.RESTApplication] - Started REST API at /rest
2016-03-01 15:36:06.496 [INFO ] [.o.u.w.i.servlet.WebAppServlet] - Started Classic UI at /classicui/openhab.app
2016-03-01 15:36:14.606 [INFO ] [c.internal.ModelRepositoryImpl] - Loading model 'allesuit.rules’
2016-03-01 15:36:16.020 [INFO ] [c.internal.ModelRepositoryImpl] - Loading model 'notifications.rules’
2016-03-01 15:36:16.294 [INFO ] [c.internal.ModelRepositoryImpl] - Loading model 'sonos.rules’
2016-03-01 15:36:16.762 [INFO ] [c.internal.ModelRepositoryImpl] - Loading model 'voicecommand.rules’
2016-03-01 15:36:17.230 [DEBUG] [o.b.r.internal.RFXComActivator] - RFXCOM binding has been started.
2016-03-01 15:36:17.878 [DEBUG] [.rfxcom.internal.RFXComBinding] - Activate
2016-03-01 15:36:17.921 [DEBUG] [.rfxcom.internal.RFXComBinding] - Activate
2016-03-01 15:36:18.417 [DEBUG] [.rfxcom.internal.RFXComBinding] - Activate
2016-03-01 15:36:18.597 [INFO ] [.service.AbstractActiveService] - Sonos Refresh Service has been started
2016-03-01 15:36:18.824 [DEBUG] [.rfxcom.internal.RFXComBinding] - Activate
2016-03-01 15:36:21.193 [INFO ] [.b.sonos.internal.SonosBinding] - Querying the network for a predefined Sonos device with UDN uuid:RINCON_000E5873AD0E01400
2016-03-01 15:36:21.293 [INFO ] [.b.sonos.internal.SonosBinding] - Querying the network for a predefined Sonos device with UDN uuid:RINCON_000E583D4D5801400
2016-03-01 15:36:21.316 [INFO ] [.b.sonos.internal.SonosBinding] - Querying the network for any other Sonos device
2016-03-01 15:36:26.836 [INFO ] [.b.sonos.internal.SonosBinding] - Found a Sonos device (S3) with UDN uuid:RINCON_000E5873AD0E01400
2016-03-01 15:36:26.899 [INFO ] [.b.sonos.internal.SonosBinding] - Found a Sonos device (ZP120) with UDN uuid:RINCON_000E583D4D5801400
2016-03-01 15:36:27.861 [WARN ] [.b.sonos.internal.SonosBinding] - Cannot cast class org.openhab.core.library.types.PercentType to an accepted state type for item Sonos_Keuken_volume
2016-03-01 15:36:27.925 [WARN ] [.b.sonos.internal.SonosBinding] - Cannot cast class org.openhab.core.library.types.PercentType to an accepted state type for item Sonos_Slaapkamer_volume
2016-03-01 15:36:30.211 [DEBUG] [.rfxcom.internal.RFXComBinding] - Activate
2016-03-01 15:36:30.310 [INFO ] [runtime.busevents ] - Sonos_Keuken_zone state updated to Keuken
2016-03-01 15:36:30.376 [INFO ] [runtime.busevents ] - Sonos_Slaapkamer_zone state updated to Slaapkamer
2016-03-01 15:36:30.383 [INFO ] [runtime.busevents ] - Sonos_Keuken_status state updated to PLAYING
2016-03-01 15:36:30.519 [DEBUG] [.rfxcom.internal.RFXComBinding] - Activate
2016-03-01 15:36:30.644 [INFO ] [.p.rrd4j.internal.RRD4jService] - Removing invalid defintion component = null heartbeat = 0 min/max = 0.0/0.0 step = 0 0 archives(s) = [] 0 items(s) = []
2016-03-01 15:36:30.648 [INFO ] [runtime.busevents ] - Sonos_Slaapkamer_status state updated to STOPPED
2016-03-01 15:36:30.740 [DEBUG] [.rfxcom.internal.RFXComBinding] - Activate
2016-03-01 15:36:30.873 [DEBUG] [.rfxcom.internal.RFXComBinding] - Activate
2016-03-01 15:36:31.368 [DEBUG] [.rfxcom.internal.RFXComBinding] - Activate
2016-03-01 15:36:37.981 [INFO ] [runtime.busevents ] - Sonos_Keuken_currenttrack state updated to VRT Radio 1 94.2 - Volume 1 - content - 23m remaining
2016-03-01 15:36:38.212 [INFO ] [runtime.busevents ] - Sonos_Slaapkamer_currenttrack state updated to VRT Radio 1 94.2 - Volume 1 - content - 23m remaining
2016-03-01 15:36:39.948 [DEBUG] [.rfxcom.internal.RFXComBinding] - Activate
2016-03-01 15:36:40.093 [DEBUG] [.rfxcom.internal.RFXComBinding] - Activate
2016-03-01 15:36:40.168 [DEBUG] [.rfxcom.internal.RFXComBinding] - Activate
2016-03-01 15:36:40.308 [DEBUG] [org.openhab.model.script.sonos] - Slaapkamer updated
2016-03-01 15:36:40.594 [DEBUG] [.rfxcom.internal.RFXComBinding] - Activate
2016-03-01 15:36:40.628 [DEBUG] [.rfxcom.internal.RFXComBinding] - Activate
2016-03-01 15:36:42.912 [DEBUG] [.rfxcom.internal.RFXComBinding] - Activate
2016-03-01 15:36:43.060 [DEBUG] [.rfxcom.internal.RFXComBinding] - Activate
2016-03-01 15:36:43.174 [DEBUG] [.rfxcom.internal.RFXComBinding] - Activate

What could be wrong?

Have you added the USB device to the Java startup command line?

Didn’t think it was required because the port appears to have been detected. At least it’s not reporting an error.

Tried with -Dgnu.io.rxtx.SerialPorts=/dev/ttyUSB0 added to the cmd line in start_runtime.sh (synology packages).
Still I don’t see RFXCOM messages in the log, only those “[.rfxcom.internal.RFXComBinding] - Activate” messages.

Since I don’t use symlinks, but directly the /dev/ttyUSB0 device node I believe I don’t need to pass the port to the command anyway.

To answer my own question:
I have given up getting RFXCOM to work on the synology and instead switched to a dedicated micro-PC to run openhab. The exact same config I was using on synology worked perfectly on OpenHAB 1.8.3 on the PC.