Z-Wave dev null pointer when scanning

I am getting the below exception when trying to scan via paperUI. This means I have to go restart the binding via bundle:restart if I need continued operation. Also, I cannot add any new devices.

Any ideas?

@chris maybe?

17:19:15.041 [ERROR] [internal.DiscoveryServiceRegistryImpl] - Cannot trigger scan for thing types '[zwave:heiman_hs1htz_00_000, zwave:mcohome_mhs512il_00_0 ..... 80_00_000, zwave:somfy_zrtsivnode_00_000]' on 'ZWaveDiscoveryService'!
java.lang.NullPointerException: null
	at org.openhab.binding.zwave.discovery.ZWaveDiscoveryService.startScan(ZWaveDiscoveryService.java:74) [252:org.openhab.binding.zwave:2.4.0.201807152304]
	at org.eclipse.smarthome.config.discovery.AbstractDiscoveryService.startScan(AbstractDiscoveryService.java:208) ....

What version of the binding are you using? I can’t correlate the error at line 74 with a valid line of code in the current master.

I just saw there is a more recent one, will try this in a bit

actually, the link in the testing thread “https://github.com/cdjackson/HABmin2/tree/theme/output” does not seem to point to something atm.

So to be clear - you are not using the master/snapshot binding - you are instead using the development binding?

I have no idea what this link is or where it is used? It’s not where I have (ever, I think) put the development bindings as they are a) nothing to do with HABmin, and b) not hosted on Github anyway :confused:

Thanks for your quick response. Really sorry, I took the link from here: Testing Z-Wave binding on openHAB-2, but was actually looking at the wrong thread, right one is here: OH2 Z-Wave refactoring and testing... and SECURITY

openhab> bundle:list | grep ZWave
252 │ Active   │  80 │ 2.4.0.201807192329     │ ZWave Binding

But yes, I am using the dev binding as I need to use a lock (Danalock V3) which actually works nicely now.

The Error with the most recent binding is the same:

...._ct80_00_000, zwave:somfy_zrtsivnode_00_000]' on 'ZWaveDiscoveryService'!
java.lang.NullPointerException: null
        at org.openhab.binding.zwave.discovery.ZWaveDiscoveryService.startScan(ZWaveDiscoveryService.java:74) [252:org.openhab.binding.zwave:2.4.0.201807192329]
        at org.eclipse.smarthome.config.discovery.AbstractDiscoveryService.startScan(AbstractDiscoveryService.java:208) [97:org.eclipse.smarthome.config.discovery:0.10.0.oh230]
...

Ok, thanks. When I checked the code earlier I thought you were using the master version - I will recheck the dev version.

So I can fix the error, but I’ve no idea why it’s happening. Ultimately, it means that there is no known controller - this code hasn’t changed for over 2 years so it’s a bit strange. Are there any other errors anywhere in your system? It probably indicates there is a problem during initialisation or something like that, and this is an effect of another problem.

Yes, there is a strange thing, that on startup it always resets the serial port to /dev/ttyACM0. I need it to look at /dev/z-wave. As soon as I correct the serial port and save (in paperUI) it works fine. It seems to somehow reset the config on start too, maybe because of an initial scan?

018-07-20 14:12:32.900 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'main.sitemap'
2018-07-20 14:12:33.052 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'test.sitemap'
2018-07-20 14:12:37.316 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Initializing ZWave serial controller.
2018-07-20 14:12:37.324 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Initializing ZWave Controller zwave:serial_zstick:512.
2018-07-20 14:12:37.332 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Scheduling network mesh heal for 12 hours time.
2018-07-20 14:12:37.354 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Connecting to serial port '/dev/z-wave'
2018-07-20 14:12:37.496 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Starting receive thread
2018-07-20 14:12:37.511 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Serial port is initialized
2018-07-20 14:12:37.512 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Starting ZWave thread: Receive
2018-07-20 14:12:37.514 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Initialising ZWave controller
2018-07-20 14:12:37.618 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 14 00 04 00 08 0E 32 02 21 74 00 00 00 00 00 00 00 00 00 00 8C
2018-07-20 14:12:37.646 [INFO ] [ve.internal.protocol.ZWaveController] - Starting ZWave controller

...

se
2018-07-20 14:12:59.252 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 00 41 15 AF
2018-07-20 14:12:59.253 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 9: Transaction event listener: DONE: CANCELLED ->
2018-07-20 14:12:59.256 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: -- To notify -- TIMEOUT_WAITING_FOR_CONTROLLE
R
2018-07-20 14:12:59.256 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 04 00 41 15 AF
2018-07-20 14:12:59.258 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ********* Transaction Response Complete -- 9 --
2018-07-20 14:12:59.263 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2018-07-20 14:12:59.263 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 14: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@3a41036a
2018-07-20 14:12:59.267 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 10: Transaction Start type IdentifyNode
2018-07-20 14:12:59.823 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: sendTransaction org.openhab.binding.zwave.internal.protocol.ZWaveSerialPayload@30b9681a
2018-07-20 14:12:59.825 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false
2018-07-20 14:13:00.190 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Stopped ZWave serial handler
2018-07-20 14:13:00.192 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - Deactivating ZWave discovery service for zwave:serial_zstick:512
2018-07-20 14:13:00.195 [DEBUG] [org.openhab.binding.zwave           ] - ServiceEvent UNREGISTERING - {org.eclipse.smarthome.config.discovery.DiscoveryService}={service.id=293, service.bundleid=252, service.scope=singleton} - org.openhab.binding.zwave
2018-07-20 14:13:00.201 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Initializing ZWave serial controller.
2018-07-20 14:13:00.202 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Initializing ZWave Controller zwave:serial_zstick:512.
2018-07-20 14:13:00.204 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Scheduling network mesh heal for 12 hours time.
2018-07-20 14:13:00.209 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Connecting to serial port '/dev/ttyACM0'
2018-07-20 14:13:00.209 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 21: Controller status changed to OFFLINE.
2018-07-20 14:13:00.211 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Controller status changed to OFFLINE.

I don’t think it should do an initial scan, and it shouldn’t reset the config. There aren’t some sort of duplicate definitions of the thing anywhere are there? I’m not sure really why it would change serial port.

Can you provide the full log please so I can see what happened in the missing 20 seconds?

Sure:
log: https://drive.google.com/open?id=1eOTwYZTTNEBaiXpo-qwadpAg4fJiN2bl
jsondb things: https://drive.google.com/open?id=11lZ6seVYbulOaak4Am_VQhGE9Qbtak51

Everything was configured via paperUI. When switching to the dev binding, I deleted the old z-stick and added the new one that was discovered via paperui.

A grep -ir ttyACM0 on /var/lib/openhab2 and /etc/openhab2/ did not reveal anything

I do have EXTRA_JAVA_OPTS="-Dgnu.io.rxtx.SerialPorts=/dev/zigbee:/dev/z-wave" in defaults. Anyway, this was working fine with the prod 2.3 binding (but not z-wave security naturally)

Also, while I do not think it has anything to do with this, my ST814 is somehow not sending any temperature updates anymore. I set it to have a 1min wakeup period, which works, but setting the timed updates to 1min still results in no sensor updates whatsoever. Just so you know why NODE 3 changes are a bit strange. I then tried to reset it, but can now not include it anymore without a scan.

There’s a lot of strange stuff in your log. Have you tried to restart the system?

Yep. Does not change anything sadly…

I think the bottom line is for some reason (and I don’t know why) the configuration on startup seems to be wrong. It then doesn’t open the serial port and after that it’s game over.

Unfortunately, I don’t know why the configuration would be incorrect to start with.

I did not find the reason for this not to work (and work if started manually), but somehow it starts working fine if I directly use /dev/ttyACM0 (and also add it to the default/openhab2 file) instead of a symbolic link from /dev/z-wave. There seems to be some problem in symbolic link handling which was not there in the 2.3 production binding.