Fibaro Dimmer 2 node not reporting

Landstad · June 23, 2018, 12:34am

I’m on an openhabian-RPi with a USB z-wave dongle.
I have a Fibareo Dimmer 2 that I can’t get to report to the controller (or through association groups to other items).
There is only a single, physical switch connected to the dimmer.

I have lots of Fibaro Dimmer2s around and they work fine. But today I remembered that I have a dimmer behind a wall switch that isn’t in use. So I thought I’d put it to work (controlling lights).

I used triple click to include it (successfully) and created an item.

Then I made a simple rule (where MyItem is the name of the item connected to the channel):

rule “FF_Stue_Ikkelampe changed”
when
Item MyItem received update
then
logInfo(“scenes.rules”,“MyItem.”)
end

Then I walked over and hit the switch. Nothing happens. I check the lifeline - it’s okay (the controller). I try again. I put nodes in Association Group 2 and 3 through HABmin. Still nothing when I try again.

Any suggestions on what can be wrong?

hr3 · June 23, 2018, 6:55am

What versions and have you restarted oH?

mstormi · June 23, 2018, 10:28am

Enable zwave debugging to see if there’s messages arriving at the controller from that device.
If no, you should reset(+reinclude) your device, see device manual for that.
If yes, check the zwave debug logs and XML file created for that node in /var/lib/openhab2/zwave. Eventually use habmin to reinitialize the device (= recreate that XML file).

No need whatsoever to restart OH.

Landstad · June 23, 2018, 6:17pm

Thanks. Nothing in the debug-log.

The resetting process requires one to remove the switch in order to get the dimmer 2 out. I will have to do that another day.

chris · June 23, 2018, 7:15pm

Your reported problem is that it doesn’t report its status - but does it work at all? ie can you control it from the UI, and this works, and it’s just that when you control it from the physical switch it doesn’t update the UI?

Landstad · June 23, 2018, 10:38pm

I took the Dimmer 2 out and restarted it. Then I did a new inclusion.

I now get two Things in the inbox (both Dimmer 2s). Those are both the newly reset + included node. If I do a new exclusion I get a
"[ERROR] [ve.internal.protocol.ZWaveController] - Exception during ZWave thread: Input 2. {}

java.lang.IllegalArgumentException: Illegal status REMOVED. The thing was in state ONLINE and not in REMOVING"

But the node thinks it’s excluded. I delete the Thing from HABmin and do I new inclusion and get a third “Thing” in the inbox.

I have not seen any indication of the node working for anything else than inclusion. (It does get included and in status ONLINE after a little while…).

I have a lot of errors like the one below in my log:
“2018-06-24 00:32:02.717 [ERROR] [e.internal.WriterInterceptorExecutor] - MessageBodyWriter not found for media type=text/plain, type=class java.util.Collections$UnmodifiableCollection, genericType=class java.util.Collections$UnmodifiableCollection.”

chris · June 24, 2018, 7:53am

What version of the binding are you using? This is caused by the framework not allowing the binding to set the state to remove the thing, but I thought that this was changed in the binding a long time ago.

Please provide the debug log.

These don’t appear to be ZWave related are they?

Sorry, but I’m still not sure how this links back to our original question about the status not working? Is that now resolved after excluding and reincluding?

Landstad · June 24, 2018, 3:47pm

In PaperUI under bindings it says 2.3.0 with the option to uninstall. Not sure if that specific version is installed. openHAB 2.3.0-1.

The error in the previous reply is probably unrelated.

Here’s all debug log for the second I did the inlusion. I don’t read what’s relevant or not very well and there’s a LOT of debug code. Let me know if I cut the debug code too short or if the relevant part isn’t there at all.

Node35 appeared after the inclusion. Nothing happens (in the log) when I click the physical switch. I figure a next logical testing step would be to connect a physical lamp to the switch. Could the fact that nothings connected to it matter?

Right now it seems like the node only creates log items during exclusion and inclusion.

2018-06-24 17:24:44.507 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - sendResponse info=null content=DirectByteBuffer@883b2f[p=0,l=200,c=32768,r=200]={<<<event: message\nda...usInfoEvent"}\n\n>>>1 Wall Switch\\",\\...WdVsL+xokX6hp4b} complete=false committing=false callback=Blocker@1f12879{null}

2018-06-24 17:24:44.512 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@f7496f[PROCESSING][i=null,cb=Blocker@1f12879{null}] generate: FLUSH (null,[p=0,l=200,c=32768,r=200],false)@COMMITTED

2018-06-24 17:24:44.515 [DEBUG] [io.socket.client.Manager            ] - writing packet io.socket.parser.Packet@eeb9ce

2018-06-24 17:24:44.520 [DEBUG] [io.socket.parser.Parser             ] - encoding packet io.socket.parser.Packet@eeb9ce

2018-06-24 17:24:44.519 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - write: WriteFlusher@40f1bf{IDLE} [HeapByteBuffer@8d85b5[p=0,l=6,c=1024,r=6]={<<<\r\nC8\r\n>>>\n\n\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00...\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00},DirectByteBuffer@883b2f[p=0,l=200,c=32768,r=200]={<<<event: message\nda...usInfoEvent"}\n\n>>>1 Wall Switch\\",\\...WdVsL+xokX6hp4b}]

2018-06-24 17:24:44.523 [DEBUG] [io.socket.parser.Parser             ] - encoded io.socket.parser.Packet@eeb9ce as 2["itemupdate",{"itemName":"FF_Kitchen_CC_Idle","itemStatus":"ON"}]

2018-06-24 17:24:44.526 [DEBUG] [io.socket.engineio.client.Socket    ] - flushing 1 packets in socket

2018-06-24 17:24:44.529 [DEBUG] [io.socket.client.Manager            ] - writing packet io.socket.parser.Packet@294a23

2018-06-24 17:24:44.531 [DEBUG] [io.socket.parser.Parser             ] - encoding packet io.socket.parser.Packet@294a23

2018-06-24 17:24:44.530 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - update WriteFlusher@40f1bf{WRITING}:IDLE-->WRITING

2018-06-24 17:24:44.534 [DEBUG] [io.socket.parser.Parser             ] - encoded io.socket.parser.Packet@294a23 as 2["itemupdate",{"itemName":"FF_Kitchen_CC_Volum","itemStatus":"1"}]

2018-06-24 17:24:44.537 [DEBUG] [io.socket.engineio.client.Socket    ] - flushing 1 packets in socket

2018-06-24 17:24:44.541 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - flushed 206 SelectChannelEndPoint@1205f5e{/192.168.0.8:53712<->8080,Open,in,out,-,W,7067/30000,HttpConnection@d70d76}{io=0/0,kio=0,kro=1}

2018-06-24 17:24:44.544 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - Flushed=true 6/6+1 WriteFlusher@40f1bf{WRITING}

2018-06-24 17:24:44.546 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - update WriteFlusher@40f1bf{IDLE}:WRITING-->IDLE

2018-06-24 17:24:44.549 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@f7496f[PROCESSING][i=null,cb=Blocker@1f12879{null}] generate: DONE (null,[p=200,l=200,c=32768,r=0],false)@COMMITTED

2018-06-24 17:24:44.553 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - sendResponse info=null content=DirectByteBuffer@151b781[p=0,l=200,c=32768,r=200]={<<<event: message\nda...usInfoEvent"}\n\n>>>1 Wall Switch\\",\\..."zwave_class_sp} complete=false committing=false callback=Blocker@19b5d29{null}

2018-06-24 17:24:44.556 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@1632f71[PROCESSING][i=null,cb=Blocker@19b5d29{null}] generate: FLUSH (null,[p=0,l=200,c=32768,r=200],false)@COMMITTED

2018-06-24 17:24:44.558 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - write: WriteFlusher@8d500c{IDLE} [HeapByteBuffer@692140[p=0,l=6,c=1024,r=6]={<<<\r\nC8\r\n>>>\n\n\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00...\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00},DirectByteBuffer@151b781[p=0,l=200,c=32768,r=200]={<<<event: message\nda...usInfoEvent"}\n\n>>>1 Wall Switch\\",\\..."zwave_class_sp}]

2018-06-24 17:24:44.561 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - update WriteFlusher@8d500c{WRITING}:IDLE-->WRITING

2018-06-24 17:24:44.564 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - flushed 206 SelectChannelEndPoint@1dfc61{/192.168.0.8:53989<->8080,Open,in,out,-,W,7070/30000,HttpConnection@1d73ad8}{io=0/0,kio=0,kro=1}

2018-06-24 17:24:44.567 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - Flushed=true 6/6+1 WriteFlusher@8d500c{WRITING}

2018-06-24 17:24:44.569 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - update WriteFlusher@8d500c{IDLE}:WRITING-->IDLE

2018-06-24 17:24:44.572 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@1632f71[PROCESSING][i=null,cb=Blocker@19b5d29{null}] generate: DONE (null,[p=200,l=200,c=32768,r=0],false)@COMMITTED

2018-06-24 17:24:44.576 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - sendResponse info=null content=DirectByteBuffer@883b2f[p=0,l=149,c=32768,r=149]={<<<event: message\nda...mStateEvent"}\n\n>>>etail\\":\\"NONE\\"}...WdVsL+xokX6hp4b} complete=false committing=false callback=Blocker@1f12879{null}

2018-06-24 17:24:44.578 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@f7496f[PROCESSING][i=null,cb=Blocker@1f12879{null}] generate: FLUSH (null,[p=0,l=149,c=32768,r=149],false)@COMMITTED

2018-06-24 17:24:44.581 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - write: WriteFlusher@40f1bf{IDLE} [HeapByteBuffer@8d85b5[p=0,l=6,c=1024,r=6]={<<<\r\n95\r\n>>>\n\n\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00...\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00},DirectByteBuffer@883b2f[p=0,l=149,c=32768,r=149]={<<<event: message\nda...mStateEvent"}\n\n>>>etail\\":\\"NONE\\"}...WdVsL+xokX6hp4b}]

2018-06-24 17:24:44.583 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - update WriteFlusher@40f1bf{WRITING}:IDLE-->WRITING

2018-06-24 17:24:44.585 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - flushed 155 SelectChannelEndPoint@1205f5e{/192.168.0.8:53712<->8080,Open,in,out,-,W,42/30000,HttpConnection@d70d76}{io=0/0,kio=0,kro=1}

2018-06-24 17:24:44.587 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - Flushed=true 6/6+1 WriteFlusher@40f1bf{WRITING}

2018-06-24 17:24:44.588 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - update WriteFlusher@40f1bf{IDLE}:WRITING-->IDLE

2018-06-24 17:24:44.590 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@f7496f[PROCESSING][i=null,cb=Blocker@1f12879{null}] generate: DONE (null,[p=149,l=149,c=32768,r=0],false)@COMMITTED

2018-06-24 17:24:44.591 [DEBUG] [org.eclipse.jetty.io.IdleTimeout    ] - SelectChannelEndPoint@1205f5e{/192.168.0.8:53712<->8080,Open,in,out,-,-,4/30000,HttpConnection@d70d76}{io=0/0,kio=0,kro=1} idle timeout check, elapsed: 4 ms, remaining: 29996 ms

2018-06-24 17:24:44.593 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - sendResponse info=null content=DirectByteBuffer@151b781[p=0,l=149,c=32768,r=149]={<<<event: message\nda...mStateEvent"}\n\n>>>etail\\":\\"NONE\\"}..."zwave_class_sp} complete=false committing=false callback=Blocker@19b5d29{null}

2018-06-24 17:24:44.594 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@1632f71[PROCESSING][i=null,cb=Blocker@19b5d29{null}] generate: FLUSH (null,[p=0,l=149,c=32768,r=149],false)@COMMITTED

2018-06-24 17:24:44.596 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - write: WriteFlusher@8d500c{IDLE} [HeapByteBuffer@692140[p=0,l=6,c=1024,r=6]={<<<\r\n95\r\n>>>\n\n\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00...\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00},DirectByteBuffer@151b781[p=0,l=149,c=32768,r=149]={<<<event: message\nda...mStateEvent"}\n\n>>>etail\\":\\"NONE\\"}..."zwave_class_sp}]

2018-06-24 17:24:44.598 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - update WriteFlusher@8d500c{WRITING}:IDLE-->WRITING

2018-06-24 17:24:44.600 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - flushed 155 SelectChannelEndPoint@1dfc61{/192.168.0.8:53989<->8080,Open,in,out,-,W,33/30000,HttpConnection@1d73ad8}{io=0/0,kio=0,kro=1}

2018-06-24 17:24:44.601 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - Flushed=true 6/6+1 WriteFlusher@8d500c{WRITING}

2018-06-24 17:24:44.603 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - update WriteFlusher@8d500c{IDLE}:WRITING-->IDLE

2018-06-24 17:24:44.605 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@1632f71[PROCESSING][i=null,cb=Blocker@19b5d29{null}] generate: DONE (null,[p=149,l=149,c=32768,r=0],false)@COMMITTED

2018-06-24 17:24:44.608 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - sendResponse info=null content=DirectByteBuffer@883b2f[p=0,l=151,c=32768,r=151]={<<<event: message\nda...mStateEvent"}\n\n>>>ail\\":\\"NONE\\"}",...WdVsL+xokX6hp4b} complete=false committing=false callback=Blocker@1f12879{null}

2018-06-24 17:24:44.609 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@f7496f[PROCESSING][i=null,cb=Blocker@1f12879{null}] generate: FLUSH (null,[p=0,l=151,c=32768,r=151],false)@COMMITTED

2018-06-24 17:24:44.611 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - write: WriteFlusher@40f1bf{IDLE} [HeapByteBuffer@8d85b5[p=0,l=6,c=1024,r=6]={<<<\r\n97\r\n>>>\n\n\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00...\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00},DirectByteBuffer@883b2f[p=0,l=151,c=32768,r=151]={<<<event: message\nda...mStateEvent"}\n\n>>>ail\\":\\"NONE\\"}",...WdVsL+xokX6hp4b}]

2018-06-24 17:24:44.612 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - update WriteFlusher@40f1bf{WRITING}:IDLE-->WRITING

2018-06-24 17:24:44.614 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - flushed 157 SelectChannelEndPoint@1205f5e{/192.168.0.8:53712<->8080,Open,in,out,-,W,27/30000,HttpConnection@d70d76}{io=0/0,kio=0,kro=1}

2018-06-24 17:24:44.616 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - Flushed=true 6/6+1 WriteFlusher@40f1bf{WRITING}

2018-06-24 17:24:44.617 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - update WriteFlusher@40f1bf{IDLE}:WRITING-->IDLE

2018-06-24 17:24:44.619 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@f7496f[PROCESSING][i=null,cb=Blocker@1f12879{null}] generate: DONE (null,[p=151,l=151,c=32768,r=0],false)@COMMITTED

2018-06-24 17:24:44.621 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - sendResponse info=null content=DirectByteBuffer@151b781[p=0,l=151,c=32768,r=151]={<<<event: message\nda...mStateEvent"}\n\n>>>ail\\":\\"NONE\\"}",..."zwave_class_sp} complete=false committing=false callback=Blocker@19b5d29{null}

2018-06-24 17:24:44.623 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@1632f71[PROCESSING][i=null,cb=Blocker@19b5d29{null}] generate: FLUSH (null,[p=0,l=151,c=32768,r=151],false)@COMMITTED

2018-06-24 17:24:44.624 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - write: WriteFlusher@8d500c{IDLE} [HeapByteBuffer@692140[p=0,l=6,c=1024,r=6]={<<<\r\n97\r\n>>>\n\n\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00...\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00},DirectByteBuffer@151b781[p=0,l=151,c=32768,r=151]={<<<event: message\nda...mStateEvent"}\n\n>>>ail\\":\\"NONE\\"}",..."zwave_class_sp}]

2018-06-24 17:24:44.626 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - update WriteFlusher@8d500c{WRITING}:IDLE-->WRITING

2018-06-24 17:24:44.628 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - flushed 157 SelectChannelEndPoint@1dfc61{/192.168.0.8:53989<->8080,Open,in,out,-,W,27/30000,HttpConnection@1d73ad8}{io=0/0,kio=0,kro=1}

2018-06-24 17:24:44.629 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - Flushed=true 6/6+1 WriteFlusher@8d500c{WRITING}

2018-06-24 17:24:44.631 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - update WriteFlusher@8d500c{IDLE}:WRITING-->IDLE

2018-06-24 17:24:44.633 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@1632f71[PROCESSING][i=null,cb=Blocker@19b5d29{null}] generate: DONE (null,[p=151,l=151,c=32768,r=0],false)@COMMITTED

2018-06-24 17:24:44.803 [DEBUG] [su.litvak.chromecast.api.v2.Channel ] -  --> {"type":"GET_STATUS","requestId":172}

2018-06-24 17:24:44.892 [DEBUG] [su.litvak.chromecast.api.v2.Channel ] -  <-- {"requestId":172,"status":{"volume":{"controlType":"attenuation","level":1.0,"muted":false,"stepInterval":0.05000000074505806}},"type":"RECEIVER_STATUS"}

2018-06-24 17:24:44.903 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - sendResponse info=null content=DirectByteBuffer@883b2f[p=0,l=200,c=32768,r=200]={<<<event: message\nda...usInfoEvent"}\n\n>>>1 Wall Switch\\",\\...WdVsL+xokX6hp4b} complete=false committing=false callback=Blocker@1f12879{null}

2018-06-24 17:24:44.906 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@f7496f[PROCESSING][i=null,cb=Blocker@1f12879{null}] generate: FLUSH (null,[p=0,l=200,c=32768,r=200],false)@COMMITTED

2018-06-24 17:24:44.909 [DEBUG] [io.socket.client.Manager            ] - writing packet io.socket.parser.Packet@55931d

2018-06-24 17:24:44.912 [DEBUG] [io.socket.parser.Parser             ] - encoding packet io.socket.parser.Packet@55931d

2018-06-24 17:24:44.909 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - write: WriteFlusher@40f1bf{IDLE} [HeapByteBuffer@8d85b5[p=0,l=6,c=1024,r=6]={<<<\r\nC8\r\n>>>\n\n\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00...\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00},DirectByteBuffer@883b2f[p=0,l=200,c=32768,r=200]={<<<event: message\nda...usInfoEvent"}\n\n>>>1 Wall Switch\\",\\...WdVsL+xokX6hp4b}]

2018-06-24 17:24:44.914 [DEBUG] [io.socket.parser.Parser             ] - encoded io.socket.parser.Packet@55931d as 2["itemupdate",{"itemName":"FF_Stue_CC_Idle","itemStatus":"ON"}]

2018-06-24 17:24:44.916 [DEBUG] [io.socket.engineio.client.Socket    ] - flushing 1 packets in socket

2018-06-24 17:24:44.916 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - update WriteFlusher@40f1bf{WRITING}:IDLE-->WRITING

2018-06-24 17:24:44.919 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - flushed 206 SelectChannelEndPoint@1205f5e{/192.168.0.8:53712<->8080,Open,in,out,-,W,304/30000,HttpConnection@d70d76}{io=0/0,kio=0,kro=1}

2018-06-24 17:24:44.922 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - Flushed=true 6/6+1 WriteFlusher@40f1bf{WRITING}

2018-06-24 17:24:44.923 [DEBUG] [io.socket.client.Manager            ] - writing packet io.socket.parser.Packet@927227

2018-06-24 17:24:44.925 [DEBUG] [io.socket.parser.Parser             ] - encoding packet io.socket.parser.Packet@927227

2018-06-24 17:24:44.925 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - update WriteFlusher@40f1bf{IDLE}:WRITING-->IDLE

2018-06-24 17:24:44.927 [DEBUG] [io.socket.parser.Parser             ] - encoded io.socket.parser.Packet@927227 as 2["itemupdate",{"itemName":"FF_Stue_CC_Volum","itemStatus":"100"}]

2018-06-24 17:24:44.929 [DEBUG] [io.socket.engineio.client.Socket    ] - flushing 1 packets in socket

2018-06-24 17:24:44.930 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@f7496f[PROCESSING][i=null,cb=Blocker@1f12879{null}] generate: DONE (null,[p=200,l=200,c=32768,r=0],false)@COMMITTED

2018-06-24 17:24:44.932 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - sendResponse info=null content=DirectByteBuffer@151b781[p=0,l=200,c=32768,r=200]={<<<event: message\nda...usInfoEvent"}\n\n>>>1 Wall Switch\\",\\..."zwave_class_sp} complete=false committing=false callback=Blocker@19b5d29{null}

2018-06-24 17:24:44.933 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@1632f71[PROCESSING][i=null,cb=Blocker@19b5d29{null}] generate: FLUSH (null,[p=0,l=200,c=32768,r=200],false)@COMMITTED

2018-06-24 17:24:44.935 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - write: WriteFlusher@8d500c{IDLE} [HeapByteBuffer@692140[p=0,l=6,c=1024,r=6]={<<<\r\nC8\r\n>>>\n\n\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00...\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00},DirectByteBuffer@151b781[p=0,l=200,c=32768,r=200]={<<<event: message\nda...usInfoEvent"}\n\n>>>1 Wall Switch\\",\\..."zwave_class_sp}]

2018-06-24 17:24:44.937 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - update WriteFlusher@8d500c{WRITING}:IDLE-->WRITING

2018-06-24 17:24:44.939 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - flushed 206 SelectChannelEndPoint@1dfc61{/192.168.0.8:53989<->8080,Open,in,out,-,W,309/30000,HttpConnection@1d73ad8}{io=0/0,kio=0,kro=1}

2018-06-24 17:24:44.940 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - Flushed=true 6/6+1 WriteFlusher@8d500c{WRITING}

2018-06-24 17:24:44.942 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - update WriteFlusher@8d500c{IDLE}:WRITING-->IDLE

2018-06-24 17:24:44.943 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@1632f71[PROCESSING][i=null,cb=Blocker@19b5d29{null}] generate: DONE (null,[p=200,l=200,c=32768,r=0],false)@COMMITTED

2018-06-24 17:24:44.946 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - sendResponse info=null content=DirectByteBuffer@883b2f[p=0,l=146,c=32768,r=146]={<<<event: message\nda...mStateEvent"}\n\n>>>usDetail\\":\\"NONE...WdVsL+xokX6hp4b} complete=false committing=false callback=Blocker@1f12879{null}

2018-06-24 17:24:44.947 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@f7496f[PROCESSING][i=null,cb=Blocker@1f12879{null}] generate: FLUSH (null,[p=0,l=146,c=32768,r=146],false)@COMMITTED

2018-06-24 17:24:44.949 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - write: WriteFlusher@40f1bf{IDLE} [HeapByteBuffer@8d85b5[p=0,l=6,c=1024,r=6]={<<<\r\n92\r\n>>>\n\n\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00...\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00},DirectByteBuffer@883b2f[p=0,l=146,c=32768,r=146]={<<<event: message\nda...mStateEvent"}\n\n>>>usDetail\\":\\"NONE...WdVsL+xokX6hp4b}]

2018-06-24 17:24:44.951 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - update WriteFlusher@40f1bf{WRITING}:IDLE-->WRITING

2018-06-24 17:24:44.952 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - flushed 152 SelectChannelEndPoint@1205f5e{/192.168.0.8:53712<->8080,Open,in,out,-,W,31/30000,HttpConnection@d70d76}{io=0/0,kio=0,kro=1}

2018-06-24 17:24:44.954 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - Flushed=true 6/6+1 WriteFlusher@40f1bf{WRITING}

2018-06-24 17:24:44.955 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - update WriteFlusher@40f1bf{IDLE}:WRITING-->IDLE

2018-06-24 17:24:44.957 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@f7496f[PROCESSING][i=null,cb=Blocker@1f12879{null}] generate: DONE (null,[p=146,l=146,c=32768,r=0],false)@COMMITTED

2018-06-24 17:24:44.960 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - sendResponse info=null content=DirectByteBuffer@151b781[p=0,l=146,c=32768,r=146]={<<<event: message\nda...mStateEvent"}\n\n>>>usDetail\\":\\"NONE..."zwave_class_sp} complete=false committing=false callback=Blocker@19b5d29{null}

2018-06-24 17:24:44.961 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@1632f71[PROCESSING][i=null,cb=Blocker@19b5d29{null}] generate: FLUSH (null,[p=0,l=146,c=32768,r=146],false)@COMMITTED

2018-06-24 17:24:44.963 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - write: WriteFlusher@8d500c{IDLE} [HeapByteBuffer@692140[p=0,l=6,c=1024,r=6]={<<<\r\n92\r\n>>>\n\n\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00...\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00},DirectByteBuffer@151b781[p=0,l=146,c=32768,r=146]={<<<event: message\nda...mStateEvent"}\n\n>>>usDetail\\":\\"NONE..."zwave_class_sp}]

2018-06-24 17:24:44.964 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - update WriteFlusher@8d500c{WRITING}:IDLE-->WRITING

2018-06-24 17:24:44.966 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - flushed 152 SelectChannelEndPoint@1dfc61{/192.168.0.8:53989<->8080,Open,in,out,-,W,26/30000,HttpConnection@1d73ad8}{io=0/0,kio=0,kro=1}

2018-06-24 17:24:44.968 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - Flushed=true 6/6+1 WriteFlusher@8d500c{WRITING}

2018-06-24 17:24:44.969 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - update WriteFlusher@8d500c{IDLE}:WRITING-->IDLE

2018-06-24 17:24:44.971 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@1632f71[PROCESSING][i=null,cb=Blocker@19b5d29{null}] generate: DONE (null,[p=146,l=146,c=32768,r=0],false)@COMMITTED

2018-06-24 17:24:44.973 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - sendResponse info=null content=DirectByteBuffer@883b2f[p=0,l=150,c=32768,r=150]={<<<event: message\nda...mStateEvent"}\n\n>>>tail\\":\\"NONE\\"}"...WdVsL+xokX6hp4b} complete=false committing=false callback=Blocker@1f12879{null}

2018-06-24 17:24:44.975 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@f7496f[PROCESSING][i=null,cb=Blocker@1f12879{null}] generate: FLUSH (null,[p=0,l=150,c=32768,r=150],false)@COMMITTED

2018-06-24 17:24:44.977 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - write: WriteFlusher@40f1bf{IDLE} [HeapByteBuffer@8d85b5[p=0,l=6,c=1024,r=6]={<<<\r\n96\r\n>>>\n\n\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00...\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00},DirectByteBuffer@883b2f[p=0,l=150,c=32768,r=150]={<<<event: message\nda...mStateEvent"}\n\n>>>tail\\":\\"NONE\\"}"...WdVsL+xokX6hp4b}]

2018-06-24 17:24:44.978 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - update WriteFlusher@40f1bf{WRITING}:IDLE-->WRITING

2018-06-24 17:24:44.980 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - flushed 156 SelectChannelEndPoint@1205f5e{/192.168.0.8:53712<->8080,Open,in,out,-,W,26/30000,HttpConnection@d70d76}{io=0/0,kio=0,kro=1}

2018-06-24 17:24:44.981 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - Flushed=true 6/6+1 WriteFlusher@40f1bf{WRITING}

2018-06-24 17:24:44.983 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - update WriteFlusher@40f1bf{IDLE}:WRITING-->IDLE

2018-06-24 17:24:44.985 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@f7496f[PROCESSING][i=null,cb=Blocker@1f12879{null}] generate: DONE (null,[p=150,l=150,c=32768,r=0],false)@COMMITTED

2018-06-24 17:24:44.987 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - sendResponse info=null content=DirectByteBuffer@151b781[p=0,l=150,c=32768,r=150]={<<<event: message\nda...mStateEvent"}\n\n>>>tail\\":\\"NONE\\"}"..."zwave_class_sp} complete=false committing=false callback=Blocker@19b5d29{null}

2018-06-24 17:24:44.989 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@1632f71[PROCESSING][i=null,cb=Blocker@19b5d29{null}] generate: FLUSH (null,[p=0,l=150,c=32768,r=150],false)@COMMITTED

2018-06-24 17:24:44.990 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - write: WriteFlusher@8d500c{IDLE} [HeapByteBuffer@692140[p=0,l=6,c=1024,r=6]={<<<\r\n96\r\n>>>\n\n\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00...\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00},DirectByteBuffer@151b781[p=0,l=150,c=32768,r=150]={<<<event: message\nda...mStateEvent"}\n\n>>>tail\\":\\"NONE\\"}"..."zwave_class_sp}]

2018-06-24 17:24:44.992 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - update WriteFlusher@8d500c{WRITING}:IDLE-->WRITING

2018-06-24 17:24:44.994 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - flushed 156 SelectChannelEndPoint@1dfc61{/192.168.0.8:53989<->8080,Open,in,out,-,W,26/30000,HttpConnection@1d73ad8}{io=0/0,kio=0,kro=1}

2018-06-24 17:24:44.995 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - Flushed=true 6/6+1 WriteFlusher@8d500c{WRITING}

2018-06-24 17:24:44.997 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - update WriteFlusher@8d500c{IDLE}:WRITING-->IDLE

2018-06-24 17:24:44.999 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@1632f71[PROCESSING][i=null,cb=Blocker@19b5d29{null}] generate: DONE (null,[p=150,l=150,c=32768,r=0],false)@COMMITTED

chris · June 24, 2018, 4:37pm

None of this is related to ZWave. I need to see the initialisation of the device - this will be quite a lot of logging and will take maybe 30 seconds to complete.

So it’s now only showing as an unknown device?

Landstad · June 24, 2018, 7:48pm

No, sorry. It initializes too and comes up as ONLINE with lifeline in both paperUI and HABmin.

Thanks for your interest in this issue @chris. I will not have time to generate new logs until after a short vacation, but will reply with more logs and tag you then.

yhd · February 20, 2019, 7:50pm

Hi @Landstad,

Have you found a solution for your issues?
I ran into similar problems with the same device. The only difference is, that I am definitely just missing the status information from the physical button push sent to openhab. I can control the device as expected via openhab and physical button.

Any hint would be appreciated. I will check the logs as mentioned above when I find the time.

Cheers