No notifications and multiple "Couldn't find JvmType" log entries

DaveL · October 3, 2020, 2:04pm

OS: Ubuntu 18.04.4 LTS
JRE: OpenJDK 1.8.0_265
OpenHAB 2.5.9

Noticed that my messages have stopped, went to look in the logs and I’m seeing hundreds (+!) of messages such as:

2020-10-03 08:53:45.378 [INFO ] [ext.common.types.util.TypeReferences] - Couldn't find JvmType for name 'org.openhab.binding.network.internal.action.NetworkActions' in context org.eclipse.xtext.xbase.resource.BatchLinkableResource@57b7672 uri='hvac.rules'
java.lang.NullPointerException: null
2020-10-03 08:53:46.617 [INFO ] [ext.common.types.util.TypeReferences] - Couldn't find JvmType for name 'org.openhab.binding.astro.internal.action.AstroActions' in context org.eclipse.xtext.xbase.resource.BatchLinkableResource@15755f5 uri='Chicken_Coop.rules'
java.lang.NullPointerException: null

I’m receiving these referencing Network, SendMail, Astro, and MQTT Actions. Not sure where to start with this one, thoughts?

DaveL · October 3, 2020, 2:26pm

Just opened my events log and a whole number of curious entries in there as well. Some examples:

2020-10-03 09:23:50.472 [vent.ItemStateChangedEvent] - zwave_serial_zstick_c57535c9_serial_nak changed from NULL to 0
2020-10-03 09:23:50.473 [vent.ItemStateChangedEvent] - zwave_serial_zstick_c57535c9_serial_can changed from NULL to 17
2020-10-03 09:23:50.473 [vent.ItemStateChangedEvent] - zwave_serial_zstick_c57535c9_serial_oof changed from NULL to 0
2020-10-03 09:23:50.473 [vent.ItemStateChangedEvent] - zwave_serial_zstick_c57535c9_serial_cse changed from NULL to 0
2020-10-03 09:23:53.663 [hingStatusInfoChangedEvent] - 'zwave:serial_zstick:c57535c9' changed from OFFLINE (COMMUNICATION_ERROR): Serial Error: Port /dev/ttyACM0 does not exist to ONLINE
2020-10-03 09:23:53.664 [hingStatusInfoChangedEvent] - 'zwave:device:c57535c9:node23' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE
2020-10-03 09:23:53.664 [hingStatusInfoChangedEvent] - 'zwave:device:c57535c9:node24' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE
2020-10-03 09:23:53.664 [hingStatusInfoChangedEvent] - 'zwave:device:c57535c9:node26' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE
2020-10-03 09:23:53.664 [hingStatusInfoChangedEvent] - 'zwave:device:c57535c9:node29' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE
2020-10-03 09:23:53.683 [hingStatusInfoChangedEvent] - 'zwave:device:c57535c9:node20' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE
2020-10-03 09:23:53.683 [hingStatusInfoChangedEvent] - 'zwave:device:c57535c9:node21' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE
2020-10-03 09:23:53.684 [hingStatusInfoChangedEvent] - 'zwave:device:c57535c9:node34' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE
2020-10-03 09:23:53.684 [hingStatusInfoChangedEvent] - 'zwave:device:c57535c9:node22' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE
2020-10-03 09:23:53.685 [hingStatusInfoChangedEvent] - 'zwave:device:c57535c9:node9' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE
2020-10-03 09:23:53.685 [hingStatusInfoChangedEvent] - 'zwave:device:c57535c9:node31' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE
2020-10-03 09:23:53.685 [hingStatusInfoChangedEvent] - 'zwave:device:c57535c9:node32' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE
2020-10-03 09:23:53.685 [hingStatusInfoChangedEvent] - 'zwave:device:c57535c9:node8' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE
2020-10-03 09:23:53.686 [hingStatusInfoChangedEvent] - 'zwave:device:c57535c9:node33' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE
2020-10-03 09:23:53.686 [hingStatusInfoChangedEvent] - 'zwave:device:c57535c9:node2' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE
2020-10-03 09:23:53.686 [hingStatusInfoChangedEvent] - 'zwave:device:c57535c9:node17' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE
2020-10-03 09:23:53.686 [hingStatusInfoChangedEvent] - 'zwave:device:c57535c9:node19' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE
2020-10-03 09:23:53.686 [hingStatusInfoChangedEvent] - 'zwave:device:c57535c9:node10' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE
2020-10-03 09:23:53.686 [hingStatusInfoChangedEvent] - 'zwave:device:c57535c9:node15' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE
2020-10-03 09:23:53.687 [hingStatusInfoChangedEvent] - 'zwave:device:c57535c9:node11' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE
2020-10-03 09:23:53.687 [hingStatusInfoChangedEvent] - 'zwave:device:c57535c9:node14' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE
2020-10-03 09:23:53.687 [hingStatusInfoChangedEvent] - 'zwave:device:c57535c9:node12' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE
2020-10-03 09:23:53.688 [hingStatusInfoChangedEvent] - 'zwave:device:c57535c9:node13' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE
2020-10-03 09:23:53.688 [hingStatusInfoChangedEvent] - 'zwave:device:c57535c9:node25' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE
2020-10-03 09:23:53.688 [hingStatusInfoChangedEvent] - 'zwave:device:c57535c9:node4' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE
2020-10-03 09:23:53.688 [hingStatusInfoChangedEvent] - 'zwave:device:c57535c9:node7' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE
2020-10-03 09:23:53.689 [hingStatusInfoChangedEvent] - 'zwave:device:c57535c9:node3' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE
2020-10-03 09:23:53.689 [hingStatusInfoChangedEvent] - 'zwave:device:c57535c9:node5' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE
2020-10-03 09:23:53.689 [me.event.ThingUpdatedEvent] - Thing 'zwave:serial_zstick:c57535c9' has been updated.
2020-10-03 09:23:53.689 [me.event.ThingUpdatedEvent] - Thing 'zwave:device:c57535c9:node7' has been updated.

DaveL · October 3, 2020, 2:31pm

Just pulled down my zwave binding debug logs. Something very not good is going on here:

2020-10-03 09:29:51.836 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 22: Node Init response (0) null
2020-10-03 09:29:51.833 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 227: Node Init response (0) null
2020-10-03 09:29:51.832 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 9: Skipping initialization thread, process stopped by controller
2020-10-03 09:29:51.832 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 14: Node Init response (0) null
2020-10-03 09:29:51.831 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 15: Node Init response (0) null
2020-10-03 09:29:51.829 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node Init response (0) null
2020-10-03 09:29:51.828 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 13: Node Init response (0) null
2020-10-03 09:29:51.826 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node Init response (0) null
2020-10-03 09:29:51.836 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node Init transaction completed with response null
2020-10-03 09:29:51.836 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Skipping initialization thread, process stopped by controller
2020-10-03 09:29:51.825 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 11: Node Init response (0) null
2020-10-03 09:29:51.824 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 29: Node Init response (0) null
2020-10-03 09:29:51.837 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 11: Node Init transaction completed with response null
2020-10-03 09:29:51.837 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 11: Skipping initialization thread, process stopped by controller
2020-10-03 09:29:51.822 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 31: Node Init response (0) null
2020-10-03 09:29:51.837 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node Init transaction completed with response null
2020-10-03 09:29:51.821 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node Init response (0) null
2020-10-03 09:29:51.820 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 26: Node Init response (0) null
2020-10-03 09:29:51.837 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Skipping initialization thread, process stopped by controller
2020-10-03 09:29:51.837 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 13: Node Init transaction completed with response null
2020-10-03 09:29:51.838 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 13: Skipping initialization thread, process stopped by controller
2020-10-03 09:29:51.838 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 14: Node Init transaction completed with response null
2020-10-03 09:29:51.838 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 14: Skipping initialization thread, process stopped by controller
2020-10-03 09:29:51.838 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 15: Node Init transaction completed with response null
2020-10-03 09:29:51.838 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 15: Skipping initialization thread, process stopped by controller
2020-10-03 09:29:51.839 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 22: Node Init transaction completed with response null
2020-10-03 09:29:51.839 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 22: Skipping initialization thread, process stopped by controller
2020-10-03 09:29:51.839 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 23: Node Init transaction completed with response null
2020-10-03 09:29:51.839 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 23: Skipping initialization thread, process stopped by controller
2020-10-03 09:29:51.839 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node Init transaction completed with response null
2020-10-03 09:29:51.839 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Skipping initialization thread, process stopped by controller
2020-10-03 09:29:51.839 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 26: Node Init transaction completed with response null
2020-10-03 09:29:51.840 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 26: Skipping initialization thread, process stopped by controller
2020-10-03 09:29:51.840 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 29: Node Init transaction completed with response null
2020-10-03 09:29:51.840 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 29: Skipping initialization thread, process stopped by controller
2020-10-03 09:29:51.840 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 31: Node Init transaction completed with response null
2020-10-03 09:29:51.840 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 31: Skipping initialization thread, process stopped by controller
2020-10-03 09:29:51.840 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 227: Node Init transaction completed with response null
2020-10-03 09:29:51.840 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 227: Skipping initialization thread, process stopped by controller
2020-10-03 09:29:51.841 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWave controller shutdown
2020-10-03 09:29:51.841 [DEBUG] [zwave.handler.ZWaveControllerHandler] - ZWave network stopped
2020-10-03 09:29:51.841 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Disposing receive thread
2020-10-03 09:29:51.866 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Stopped ZWave thread: Receive
2020-10-03 09:29:51.866 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Receive thread dispose
2020-10-03 09:29:51.866 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Disposing serial connection
2020-10-03 09:29:51.886 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Serial connection disposed