The ESH reintegration started at S1566.
Could you please try a fresh installation to eliminate a potential upgrade issue? But before that, could you verify that there is nothing in your /conf/addons/ directory?
Hello!
It’s too late to do it right now. Hope I’ll catch some free time tomorrow to try with a fresh install. I’ve checked addons folder and, besides readme, there’s no other files in it.
Best regards,
Davor
got last night on openHAB 2.5.0 Build # 1776 update offline / online problem is gone
But I have Openhabian on Raspberry3
1 Like
@davorf I have had similar issues upgrading to M5, but because of travels and lots of thing to do, I had to go back to M4, but hopefully I’ll find some time tomorrow to test newer builds.
Maybe #1776 fixes something if not RC1.
Just to say you are not alone, and that I’m following your progress. 
Edit: I’m on linux, and are using Aeon Gen5 stick.
1 Like
@vespaman Micael thank you for reporting, we are now up to 5 folks with this issue.
Please report your issue in this thread:
Please include details about what operating system and platform you are using, the fact rolling back to M4 fixed it and also any binding you use that also use the serial connection
I would like to ask everyone reporting issues to report exactly what issue THEY have. I want to really be sure that issues are the same and not jump to any conclusions. It’s easy to say that issues people see are the same, and they may have the same or similar appearance, but we need full visibility.
From my perspective, there have not been any code changes that could impact this - there was only one very minor change in this time. Below is a list of changes (excluding database changes) since M4.
From what I’ve seen in the log referenced above by @davorf -:
Error 0x6 at src/windows/termios.c(512): The handle is invalid.
this looks like a problem with serial drivers in the system. I don’t know if there have been any changes to the serial driver - as best as I can tell the last change was in 2018 - or anything else that could impact this.
The error is not quite the same as the following issue on GH, but it’s similar -:
There are other reports of issues in Win10 with these sort of errors.
This is the change I am suspect of Chris where to find more about this change. Do I understand correctly that OpenHAB now uses an ‘embedded’ serial driver and that the zwave binding uses a newer serial driver to access that embedded serial driver??? How can I find more info about this change?
I do remember a conversation on github where Kia asked you about doing something similar and you were reluctant to make that change at that time because you were busy with other stuff. Seems like around the time the IDE wasn’t worling. I’ll try to find thread on github
At the lower levels, the serial driver is the same (I believe) as 2.4 - it’s just the way that the ZWave binding interacts with the driver is now through an openHAB proxy layer.
The change was made in April - so 8 months ago and definately not related to the M4 to M5 that is reported here since M4 was released in late September I believe.
I suspect you are getting this mixed up with something else since the serial change was made in April and the IDE issues were later.
1 Like
For reference (from Jenkins):
September 7 Milestone 3
October 19 Milestone 4
November 17 Milestone 5
December 1 Milestone 6
December 9 Release Candidate 1
OK, so today I finally had some time to test RC1.
I got exactly the same issue with it as M5.
Here’s a log snippet that might help us; It happens afaict about every minute, and makes every node change state.
10:47:08.591 [DEBUG] [nsactionManager$ZWaveTransactionTimer] - NODE 101: TID 355: Timeout at state WAIT_DATA. 3 retries remaining.
10:47:08.591 [DEBUG] [ve.internal.protocol.ZWaveTransaction] - TID 355: Transaction CANCELLED
10:47:08.591 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 101: notifyTransactionResponse TID:355 CANCELLED
10:47:08.591 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
10:47:08.592 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 12 02 87 02 25 CB 9E
10:47:08.591 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 355: Transaction event listener: DONE: CANCELLED ->
10:47:08.592 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 18: Sending REQUEST Message = 01 09 00 13 12 02 87 02 25 CB 9E
10:47:08.592 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT
10:47:08.592 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 356: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 203
10:47:08.592 [DEBUG] [ialization.ZWaveNodeInitStageAdvancer] - NODE 101: Node Init response (4) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@7748ca4e
10:47:08.592 [DEBUG] [ialization.ZWaveNodeInitStageAdvancer] - NODE 101: No data from device, but it was ACK'd. Possibly not supported? (Try 4)
10:47:08.592 [DEBUG] [ialization.ZWaveNodeInitStageAdvancer] - NODE 101: Node Init transaction retries exceeded
10:47:08.592 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 101: SECURITY not supported
10:47:08.592 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 101: Command Class COMMAND_CLASS_METER is NOT required to be secured
10:47:08.593 [DEBUG] [ialization.ZWaveNodeInitStageAdvancer] - NODE 101: ZWaveCommandClassTransactionPayload - send to node
10:47:08.593 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 101: SECURITY not supported
10:47:08.593 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 101: Command Class COMMAND_CLASS_METER is NOT required to be secured
10:47:08.593 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 101: sendTransaction org.openhab.binding.zwave.internal.protocol.transaction.ZWaveCommandClassTransactionPayload@148a93b2
10:47:08.593 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 101: Adding to device queue
10:47:08.593 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 101: Added 359 to queue - size 50
10:47:08.593 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
10:47:10.132 [INFO ] [ding.zwave.handler.ZWaveSerialHandler] - Stopped ZWave serial handler
10:47:10.133 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Interrupted taking message from recvQueue
java.lang.InterruptedException: null
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2014) ~[?:1.8.0_202]
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2048) ~[?:1.8.0_202]
at java.util.concurrent.ArrayBlockingQueue.take(ArrayBlockingQueue.java:403) ~[?:1.8.0_202]
at org.openhab.binding.zwave.internal.protocol.ZWaveTransactionManager$ZWaveReceiveThread.run(ZWaveTransactionManager.java:440) [bundleFile:?]
10:47:10.136 [DEBUG] [zwave.discovery.ZWaveDiscoveryService] - ZWave discovery: Deactivate zwave:serial_zstick:controller
10:47:10.144 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
10:47:10.145 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
10:47:10.147 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'zwave:serial_zstick:controller' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)
10:47:10.164 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'sonyprojector:ethernetconnection:a2ba257e' changed from OFFLINE (COMMUNICATION_ERROR): Opening SDCP connection failed: Ingen väg till värd (Host unreachable) to UNINITIALIZED
10:47:10.167 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'sonyprojector:ethernetconnection:a2ba257e' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)
10:47:10.427 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'sonyprojector:ethernetconnection:a2ba257e' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING
10:47:10.442 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'sonyprojector:ethernetconnection:a2ba257e' changed from INITIALIZING to UNKNOWN
I should perhaps also mention that I had one (in my opinion) very strange issue when going from 2.4 to M4, as reported here.
I know it might be a faulty node, but suggestions around serial drivers made me think it might be related.
From a quick look, this is totally different to what was being discussed earlier which was a USB issue with an exception being thrown in the serial driver.
This is why it’s always best to post information like this, and not just the “I have the same problem” statements.
Please provide the debug log so I can take a look.
To be fair, I said it was a similar problem, and linked back to my issue with M5, which includes debug log etc.
But - here’s the log for RC1
Just to be sure, I’ll switch to another aeon gen5 stick as well.
1 Like
The error is caused when the binding closes - it’s not really an error, but info that the thread was interrupted (as expected). I just wanted to look at the log to see why the binding was closing at this point - otherwise, this would be fine.
There are a number of strange errors saying that the port is closed, but I can’t find the root cause in this log as it’s too short.
Sorry - I just realized that I linked the last log. I meant to put the first log. 
Here’s the first and second files.
Edit: Changing to a new Z-stick did not change anything. (But that was a long shot anyway)
1 Like
The only way that this can happen is if something (ie openHAB core) is disposing of the handler. In the dispose method it closes the serial port and sets the serialPort field to null. We see that this is null in the logs and we see that dispose is being called.
2019-12-15 11:00:09.562 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Stopped ZWave serial handler
Why this is happening, I don’t know. The only thing I can think of is that at some point (prior to any of these logs) the binding was restarted (or more precisely, the handler was restarted). Maybe this hasn’t closed down properly and there is the remnants of a past handler still left.
The fact that you’re still receiving messages indicates that this is likely the case - if the serial port was really null, it would not receive, so my guess is that there are two copies of the serial handler running due to a thread being left open.
None of this code has changed for an awful long time so from a 2.5 perspective I don’t think it’s a regression.
1 Like
Well, first log is from openHAB startup, so I suppose a binding restart would be seen in that log?
Is there any other log that I could enable to give more information?
I have no clue what to look for, but now I think that there’s some kind of watchdog restarting just about every bundle - I tried stop a couple of bundles related to serial, but they are restarted once a minute.
So then I stopped a lot of other bindings, and they are also restarted once a minute, just that they are more silent about it. Or is this intentional nowadays (this auto starting)
Maybe I better put this into 2.5.0.RC1 issues thread!?
I’ll take another look.
I don’t know, but if you are saying that working bindings are restarting, then something strange is happening and I’d be surprised if that is a standard OH feature.
I think that thread is horrible as it’s a real mess of information, but up to you - I don’t follow it though. Also 2.5 is currently about to be released (I think the build has already started).
One point though - as far as I know, you are the only one with this issue?
I don’t see anything in the log that indicates why the handlers are closing, but they are. You see this for all devices a couple of minutes after startup - there’s no indication as to why this is happening that I can see. The binding never calls this dispose method - only the framework does.
2019-12-15 10:48:06.074 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 59: Handler disposed. Unregistering listener.
How are you configuring your system? I wonder if there’s something strange with files being touched that causes the system to think that config files are being updated or something (might explain why bindings restart every minute).
Good Idea! But I can’t think of any problems with time/touched files etc. I looked at all files under conf, and could not find anything very recent.
Maybe I am alone with this, and if 2.5.0 is already on its way, it is anyway too late for a fix for that.
I think next step is to do a clean install. But that is getting too late for today, so I think I’ll go back to M4, and deal with this after Christmas.
Thanks for trying to help!