Hey friends! I’ve found a weird situation when using the pioneerAVR binding 1.x in openhab2 through the compat1x layer:
After the bundle starts it works flawlessly, reads the config, connects to the AVR and even initializes all the items. Everythings completely fine and communication works well. But then, after all the initializations are done, it just closes the connection, gracefully. So it doesn’t look like a problem at all, it just acts like it’s “finished”.
When I try to send commands after that, the event listener fails with a null pointer exception, because the socket is gone, which is correct. Look at my log, my log is amazing:
2017-01-11 00:00:52.149 [DEBUG] [org.openhab.binding.pioneeravr ] - BundleEvent STARTING - org.openhab.binding.pioneeravr
2017-01-11 00:00:52.151 [DEBUG] [neeravr.internal.PioneerAvrActivator] - pioneeravr binding has been started.
2017-01-11 00:00:52.184 [DEBUG] [org.openhab.binding.pioneeravr ] - ServiceEvent REGISTERED - {org.openhab.model.item.binding.BindingConfigReader, org.openhab.binding.pioneeravr.PioneerAvrBindingProvider}={component.name=org.openhab.binding.pioneeravr.genericbindingprovider, component.id=192, service.id=324, service.bundleid=218, service.scope=bundle} - org.openhab.binding.pioneeravr
2017-01-11 00:00:52.194 [DEBUG] [org.openhab.core.compat1x ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.model.item.BindingConfigReader}={service.id=325, service.bundleid=208, service.scope=singleton} - org.openhab.core.compat1x
2017-01-11 00:00:52.211 [DEBUG] [org.openhab.binding.pioneeravr ] - ServiceEvent REGISTERED - {org.osgi.service.event.EventHandler, org.osgi.service.cm.ManagedService}={event.topics=openhab/command/*, service.pid=org.openhab.pioneeravr, component.name=org.openhab.binding.pioneerav, component.id=191, service.id=326, service.bundleid=218, service.scope=bundle} - org.openhab.binding.pioneeravr
2017-01-11 00:00:52.222 [DEBUG] [ioneeravr.internal.PioneerAvrBinding] - Activate
2017-01-11 00:00:52.225 [DEBUG] [ioneeravr.internal.PioneerAvrBinding] - Configuration updated, config true
2017-01-11 00:00:52.230 [DEBUG] [org.openhab.binding.pioneeravr ] - BundleEvent STARTED - org.openhab.binding.pioneeravr
2017-01-11 00:00:52.246 [DEBUG] [internal.ipcontrolprotocol.IpControl] - Connected to AVR on port 23
2017-01-11 00:00:52.249 [DEBUG] [internal.ipcontrolprotocol.IpControl] - conn check disabled, not starting hypervisor
2017-01-11 00:00:52.249 [DEBUG] [internal.ipcontrolprotocol.IpControl] - Data listener started
2017-01-11 00:00:52.250 [DEBUG] [ioneeravr.internal.PioneerAvrBinding] - Initialize item living_avr_source
2017-01-11 00:00:52.252 [TRACE] [internal.ipcontrolprotocol.IpControl] - Waiting status messages
2017-01-11 00:00:52.253 [DEBUG] [internal.ipcontrolprotocol.IpControl] - Send command: ?F
2017-01-11 00:00:52.255 [TRACE] [internal.ipcontrolprotocol.IpControl] - Sending 3 bytes: 3F460D
2017-01-11 00:00:52.257 [DEBUG] [ioneeravr.internal.PioneerAvrBinding] - Initialize item living_avr_display
2017-01-11 00:00:52.259 [DEBUG] [internal.ipcontrolprotocol.IpControl] - Send command: ?FL
2017-01-11 00:00:52.262 [TRACE] [internal.ipcontrolprotocol.IpControl] - Sending 4 bytes: 3F464C0D
2017-01-11 00:00:52.264 [DEBUG] [ioneeravr.internal.PioneerAvrBinding] - Initialize item living_avr_listening_mode
2017-01-11 00:00:52.266 [DEBUG] [internal.ipcontrolprotocol.IpControl] - Send command: ?L
2017-01-11 00:00:52.275 [TRACE] [internal.ipcontrolprotocol.IpControl] - Received 4 bytes: 464E3036
2017-01-11 00:00:52.276 [TRACE] [internal.ipcontrolprotocol.IpControl] - Sending 3 bytes: 3F4C0D
2017-01-11 00:00:52.277 [DEBUG] [ioneeravr.internal.PioneerAvrBinding] - Received status update 'FN06' from device AVR
2017-01-11 00:00:52.277 [DEBUG] [ioneeravr.internal.PioneerAvrBinding] - Initialize item living_avr_power
2017-01-11 00:00:52.279 [DEBUG] [internal.ipcontrolprotocol.IpControl] - Send command: ?P
2017-01-11 00:00:52.280 [TRACE] [internal.ipcontrolprotocol.IpControl] - Sending 3 bytes: 3F500D
2017-01-11 00:00:52.282 [DEBUG] [ioneeravr.internal.PioneerAvrBinding] - Initialize item living_avr_volume
2017-01-11 00:00:52.282 [TRACE] [internal.ipcontrolprotocol.IpControl] - Received 32 bytes: 464C303230303030303030303030303030303030303030303030303030303030
2017-01-11 00:00:52.283 [DEBUG] [internal.ipcontrolprotocol.IpControl] - Send command: ?V
2017-01-11 00:00:52.283 [DEBUG] [ioneeravr.internal.PioneerAvrBinding] - Received status update 'FL020000000000000000000000000000' from device AVR
2017-01-11 00:00:52.285 [TRACE] [internal.ipcontrolprotocol.IpControl] - Sending 3 bytes: 3F560D
2017-01-11 00:00:52.286 [DEBUG] [ioneeravr.internal.PioneerAvrBinding] - Initialize item living_avr_tuner_preset
2017-01-11 00:00:52.285 [DEBUG] [ioneeravr.internal.PioneerAvrBinding] - DisplayInfo: converted value 'FL020000000000000000000000000000' to string '
2017-01-11 00:00:52.289 [DEBUG] [internal.ipcontrolprotocol.IpControl] - Send command: ?TP
2017-01-11 00:00:52.290 [TRACE] [internal.ipcontrolprotocol.IpControl] - Received 6 bytes: 4C4D30343031
2017-01-11 00:00:52.291 [TRACE] [internal.ipcontrolprotocol.IpControl] - Sending 4 bytes: 3F54500D
2017-01-11 00:00:52.291 [DEBUG] [ioneeravr.internal.PioneerAvrBinding] - Received status update 'LM0401' from device AVR
2017-01-11 00:00:52.295 [DEBUG] [ioneeravr.internal.PioneerAvrBinding] - Deactivate
2017-01-11 00:00:52.297 [DEBUG] [internal.ipcontrolprotocol.IpControl] - closed data listener!
2017-01-11 00:00:52.304 [TRACE] [internal.ipcontrolprotocol.IpControl] - Received 4 bytes: 50575231
2017-01-11 00:00:52.306 [DEBUG] [internal.ipcontrolprotocol.IpControl] - closed input stream!
2017-01-11 00:00:52.306 [DEBUG] [ioneeravr.internal.PioneerAvrBinding] - Received status update 'PWR1' from device AVR
2017-01-11 00:00:52.309 [DEBUG] [internal.ipcontrolprotocol.IpControl] - closed output stream!
2017-01-11 00:00:52.310 [DEBUG] [internal.ipcontrolprotocol.IpControl] - closed socket!
2017-01-11 00:00:52.311 [DEBUG] [internal.ipcontrolprotocol.IpControl] - Data listener stopped
Feels like the binding was using some kind of loop which isn’t there in ESH or OH2 anymore. Sadly, the PioneerAVR 2.0 Binding does not have the Listen Mode feature, that I really depend on.
Any ideas?