2.5 Milestone 5 Issues

yes Bruce, we are all super appreciative of you helping Chris and your effort
and also some great troubleshooting !!!

Sorry for the not clear answer.

I did the fresh stable version for 2.4. The I did the update to 2.5 m5 from the openhabian-config

Tool.

1 Like

I don’t know if this belongs here on in some zwave thread, but: I get NPEs after upgrading to M5 (from M4).

Exception in thread “ZWaveReceiveProcessorThread” java.lang.NullPointerException
at org.openhab.binding.zwave.internal.protocol.ZWaveTransactionManager$ZWaveReceiveThread.run(ZWaveTransactionManager.java:744)

They arrive within an hour or two. I have restarted a couple of times, but are now back on M4.
@chris Since I haven’t seen anyone else (or search did not find this) having exactly the same, I was going to change my stick to my spare stick tonight, just to rule this out, but seing that it seems to work in M4, I thought I should at least report it here.
Or maybe I need to reset something (I normally clear ‘cache’ and ‘tmp’ on upgrades) extra on this upgrade?

It’s hard to comment with seeing the log. I don’t think there were any significant changes to the ZWave binding from M4 to M5 though.

I had no issues on M4 or M5 with zwave. I tend to clear the cache & tmp directories after upgrade though.

@chris After looking into both event log and openhab log - I wonder if I am not having the same issue as @Gthorsten and maybe @frieso. The NPEs are from the command line, so it is hard to find how they match into the debug logs time wise.

But also I get the same ;

2019-11-25 13:00:16.446 [hingStatusInfoChangedEvent] - ‘zwave:device:controller:node70’ changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (BRIDGE_UNINITIALIZED)

Here are links to snapshot of my issues:
an event.log
and a openhab.log

Unfortunately, the turn around of 8 log files are very quick with these issues, so I don’t have from last startup this morning. If needed I can restart M5 when I am home tonight though!?

But maybe this is not really a zwave issue, but something else, just showing up in zwave?

Yes, this is what I do every upgrade as well! (or are you saying that you clear one extra time after starting the new version? I haven’t done that!)

I upgrade, shutdown, clear cache & tmp. restart.

OK, will test if that makes a difference!
(I normally shutdown old version, clear cache/tmp and then start new version).

1 Like

Not sure if this is new to M5, but i beleive it’s related to changing mqtt client library. I noticed today when I updated mosquitto that openhab doesn’t reconnect when the broker (external) is restarted. I had to manually restart the MQTT Broker Binding bundle to make it work again.

Not sure it’s connected to the problem, but when I restart the bundle i get these errors in the log (one for eact generic mqtt thing):

2019-11-25 16:07:59.983 [ERROR] [nal.common.AbstractInvocationHandler] - An error occurred while calling method 'Runnable.run()' on 'org.eclipse.smarthome.core.thing.internal.ThingManagerImpl$$Lambda$1146/218965510@17eed65b': org.openhab.binding.mqtt.generic.internal.handler.GenericMQTTThingHandler cannot be cast to org.openhab.binding.mqtt.handler.AbstractBrokerHandler
java.lang.ClassCastException: org.openhab.binding.mqtt.generic.internal.handler.GenericMQTTThingHandler cannot be cast to org.openhab.binding.mqtt.handler.AbstractBrokerHandler
	at org.openhab.binding.mqtt.internal.MqttBrokerHandlerFactory.lambda$0(MqttBrokerHandlerFactory.java:83) ~[?:?]
	at java.util.WeakHashMap.forEach(WeakHashMap.java:1025) ~[?:1.8.0_232]
	at java.util.Collections$SynchronizedMap.forEach(Collections.java:2649) ~[?:1.8.0_232]
	at org.openhab.binding.mqtt.internal.MqttBrokerHandlerFactory.removeHandler(MqttBrokerHandlerFactory.java:83) ~[?:?]
	at org.eclipse.smarthome.core.thing.binding.BaseThingHandlerFactory.unregisterHandler(BaseThingHandlerFactory.java:259) ~[?:?]
	at org.eclipse.smarthome.core.thing.internal.ThingManagerImpl.lambda$5(ThingManagerImpl.java:794) ~[?:?]
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:1.8.0_232]
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:1.8.0_232]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_232]
	at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_232]
	at org.eclipse.smarthome.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:152) [bundleFile:?]
	at org.eclipse.smarthome.core.internal.common.Invocation.call(Invocation.java:52) [bundleFile:?]
	at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_232]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_232]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_232]
	at java.lang.Thread.run(Thread.java:748) [?:1.8.0_232]

I’m seeing the exact same behavior, but only on one of my machines. I’m having some challenges getting the binding into debug logging though and haven’t had time to generate logs. Does your Binding Thing still show as Online when this happens?

I actually don’t get any errors in the logs so I can’t say if it’s related or not.

The broker Thing shows online all the time, but my Generig MQTT Things go offline (Offline - Communication Error) if they try to publish anything. The ones I have that just listens don’t go offline.

I don’t get any errors either, (except the ones when restarting the binding), so it took a while to localize the issue. Will try to enable debug logging.

That’s the same behavior I’m seeing. I don’t have any other MQTT Things on this instance of OH, it only uses the publishMQTT Action which does log errors when I try to publish a message. But I bet if I did have any Generic MQTT Things it would behave similarly to what you describe.
two ista
Now that I know it’s not just me I’ll also try to find some time today to gather some logs.

What is odd is I have two instances of OH, one running 2.5 M5 and the other running a snapshot from a couple of days later, so essentially the same as I don’t think there were any MQTT changes in those two days,. Only one of these is showing this behavior.

Is the other one reconnecting when the connection is lost?

Yes, the other one reconnects without missing a beat. What I suspect is happening is that the remote one is not detecting that the connection was lost in the first place so it doesn’t go into the loop to retry connecting. Restarting the bundle causes it to try to reconnect and everything is fine after that, at least until the connection between it and the broker is broken again.

The one that does reconnect without problem is located on the same machine as the broker, so that might be a difference between the two.

Well, mine is also on the same machine as the broker, but still doesn’t reconnect. Also got this in the log with debug enabled:

2019-11-25 17:50:10.018 [DEBUG] [qtt.generic.AbstractMQTTThingHandler] - Successfully published value { "externalId": 0, 
						 "name": "Övervåning", 
						 "actualTemp": 204, 
						 "targetTemp": 190, 
						 "climateSystems": [1] } to topic Nibeuplink/Set/Thermostats
2019-11-25 17:50:10.020 [hingStatusInfoChangedEvent] - 'mqtt:topic:NibeUplink' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): MQTT client is not connected.


Even though I stopped mosquitto completely. Subsequent publishes also says successful, but mosquitto is not running and the thing now shows as offline.

Hi Micael,

my problem was, that I had to many “old” serial features loaded. I had to remove all bindings that depend on serial (Davis1 was the troublesooting one) then I reinstalled zwave and the other bindings. Check what features you have active. My working config uses the following features (see post: 2.5 Milestone 5 Issues ) hope this helps?

Why would you do that? (shut down old version first). There is no reason to, unless you want to make a backup first or something simular.
As Bruce say, just update. I believe the update progress will clear the cache and tmp, as well as restart the system when done upgrading.
My experiences is, make another reboot after the first start, when things has settled. Cause the first start would normally show tons of errors and warnings. Second start should go alot faster and with a less more warnings/errors, if any.

1 Like

Frieso, thanks for letting me know how you solved your issue! I’ll see if there’s any extra serial dependent bundles that has arrived with M5 in my setup. (I haven’t installed any, but who knows, every rock needs to be turned over!).

I’m off for a business trip tomorrow, so I let my system stay at M4 so I know my home looks occupied while I’m gone. But in the end of the week, I’ll have a new go at M5.

Well, I am running the whole oh environment usermode in my home dir, so basically I have ~/oh on my server, which is the current version. When I up/downgrade, I stop it, and make a copy to e.g. ~/oh_2.4.0 and then clears the oh/userdata/tmp + cache as well as removing runtime, copy the new version on top of it all and start it up.

This way, I can go back in about a minute by renaming the dirs.
I have done it like this since I started with oh (some early version of 2.0), has worked fine. Maybe this is not the way to do it nowadays?