Out of curiosity… is this a rule sending lots of commands to trvs
Did the temp actually change? No, it died before that happened
Is that trv further away from hub than others? It’s not the furthest away
is this a rule sending lots of commands to trvs? no this was me changing manually from HABPanel, I do have rules that will change a few at a time, but this wasn’t that
error should be handled (ill improve next week)
also slowed the message queue down to 500ms from 100ms just in case flooded.
test version: LightwaveRF-Jars/org.openhab.binding.lightwaverf-2.5.13-SNAPSHOT_alextest.jar at main · delid4ve/LightwaveRF-Jars · GitHub
that seemed to report all transactions as failures
19:21:51.528 [DEBUG] [ternal.LightwaverfSmartCommandManager] - Message received: {"version":1,"senderId":1,"transactionId":7120479,"direction":"notification","class":"feature","operation":"event","items":[{"payload":{"time":1617992511515,"featureId":"5df8b6728522075debd21ad8-99-3157346060+1","deviceId":8,"type":"power","channel":0,"writable":false,"stateless":false,"virtual":false,"value":1370,"status":"ok","_feature":{"deviceId":"5df8b6728522075debd21ad8-8-3157346060+1","productCode":"LW600","featureId":"5df8b6728522075debd21ad8-99-3157346060+1","featureType":"power"}},"success":true,"itemId":62}]}
19:21:51.531 [DEBUG] [ternal.LightwaverfSmartCommandManager] - Processing device notification
19:21:51.533 [DEBUG] [ternal.LightwaverfSmartCommandManager] - Transaction 7120479 is for 8 and contains 1 updates
19:21:51.534 [ERROR] [ternal.LightwaverfSmartCommandManager] - Transaction 62 wasnt a success
19:21:51.537 [DEBUG] [handler.LightwaverfSmartDeviceHandler] - Device 8 Updated Channel 1#power
19:21:51.539 [DEBUG] [handler.LightwaverfSmartDeviceHandler] - Device 8 Updated Channel 1#powerCost
And I updated a TRV from the app and if bombed out again
19:22:06.796 [DEBUG] [ternal.LightwaverfSmartCommandManager] - Message received: {"version":1,"senderId":1,"transactionId":7121638,"direction":"notification","class":"user","operation":"update","items":[{"payload":{"time":1617992526766,"email":"my@email","rootGroupIds":["5df8b6728522075debd21ad8-5df8b6728522075debd21ad9"],"settings":{"geofencing":false},"consent":{"data":{"consented":true,"updated":"2019-12-06T16:13:28.717Z"},"marketing":{"hubspotId":"15909051"}},"utility":{"electricity":{"tariff":0.11593,"country":"GB","currency":"GBP"}},"userId":"7aa9ada8-9914-4f8f-9bd4-80f85593a54b","givenName":"Alex","familyName":"Surname","platformToken":null,"firebaseToken":"token","platform":"ios","notificationTypes":{"firmware":true,"automations":true}},"success":true,"itemId":67}]}
19:22:06.799 [DEBUG] [ternal.LightwaverfSmartCommandManager] - Processing device notification
19:22:06.801 [WARN ] [connections.LightwaverfSmartWebsocket] - LightwaveRF - Closing a WebSocket due to null
19:22:06.803 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'lightwaverf:lightwaverfaccount:alex' changed from ONLINE to OFFLINE
19:22:06.803 [DEBUG] [handler.LightwaverfSmartDeviceHandler] - bridgeStatusChanged OFFLINE for thing lightwaverf:d21:alex:OfficeDimmer
19:22:06.803 [DEBUG] [handler.LightwaverfSmartDeviceHandler] - bridgeStatusChanged OFFLINE for thing lightwaverf:d22:alex:LivingroomDimmer
19:22:06.805 [DEBUG] [handler.LightwaverfSmartDeviceHandler] - bridgeStatusChanged OFFLINE for thing lightwaverf:d21:alex:KeiraDimmer
19:22:06.805 [WARN ] [connections.LightwaverfSmartWebsocket] - LightwaveRF - WebSocket connection closed
19:22:06.805 [DEBUG] [handler.LightwaverfSmartDeviceHandler] - bridgeStatusChanged OFFLINE for thing lightwaverf:d21:alex:BedroomDimmer
19:22:06.804 [DEBUG] [handler.LightwaverfSmartDeviceHandler] - bridgeStatusChanged OFFLINE for thing lightwaverf:h21:alex:LightwaveHub
19:22:06.804 [DEBUG] [handler.LightwaverfSmartDeviceHandler] - bridgeStatusChanged OFFLINE for thing lightwaverf:d21:alex:RyanDimmer
19:22:06.809 [DEBUG] [handler.LightwaverfSmartDeviceHandler] - bridgeStatusChanged OFFLINE for thing lightwaverf:e11:alex:Monitor
19:22:06.809 [DEBUG] [handler.LightwaverfSmartDeviceHandler] - bridgeStatusChanged OFFLINE for thing lightwaverf:t11:alex:OfficeTRV
19:22:06.808 [WARN ] [connections.LightwaverfSmartWebsocket] - LightwaveRF - Closing a WebSocket due to NullPointerException
19:22:06.807 [DEBUG] [handler.LightwaverfSmartDeviceHandler] - bridgeStatusChanged OFFLINE for thing lightwaverf:t11:alex:Heating
19:22:06.806 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'lightwaverf:d22:alex:LivingroomDimmer' changed from ONLINE to OFFLINE (BRIDGE_OFFLINE)
19:22:06.806 [DEBUG] [handler.LightwaverfSmartDeviceHandler] - bridgeStatusChanged OFFLINE for thing lightwaverf:s22:alex:ConservatorySocket
19:22:06.814 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'lightwaverf:d21:alex:OfficeDimmer' changed from ONLINE to OFFLINE (BRIDGE_OFFLINE)
19:22:06.814 [DEBUG] [handler.LightwaverfSmartDeviceHandler] - bridgeStatusChanged OFFLINE for thing lightwaverf:t11:alex:BedroomTRV
19:22:06.813 [WARN ] [connections.LightwaverfSmartWebsocket] - LightwaveRF - WebSocket connection closed
19:22:06.812 [DEBUG] [handler.LightwaverfSmartDeviceHandler] - bridgeStatusChanged OFFLINE for thing lightwaverf:t11:alex:RyanTRV
19:22:06.811 [DEBUG] [handler.LightwaverfSmartDeviceHandler] - bridgeStatusChanged OFFLINE for thing lightwaverf:t11:alex:LivingroomTRV2
19:22:06.810 [DEBUG] [handler.LightwaverfSmartDeviceHandler] - bridgeStatusChanged OFFLINE for thing lightwaverf:t11:alex:LivingroomTRV1
19:22:06.820 [DEBUG] [handler.LightwaverfSmartDeviceHandler] - bridgeStatusChanged OFFLINE for thing lightwaverf:d21:alex:DownstairsDimmer
19:22:06.819 [DEBUG] [handler.LightwaverfSmartDeviceHandler] - bridgeStatusChanged OFFLINE for thing lightwaverf:t11:alex:EnSuiteTRV
19:22:06.818 [WARN ] [connections.LightwaverfSmartWebsocket] - LightwaveRF - Closing a WebSocket due to Disconnected
19:22:06.817 [DEBUG] [handler.LightwaverfSmartDeviceHandler] - bridgeStatusChanged OFFLINE for thing lightwaverf:t11:alex:KeiraTRV
19:22:06.824 [WARN ] [connections.LightwaverfSmartWebsocket] - LightwaveRF - WebSocket connection closed
19:22:06.816 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'lightwaverf:d21:alex:KeiraDimmer' changed from ONLINE to OFFLINE (BRIDGE_OFFLINE)
19:22:06.816 [DEBUG] [handler.Lightwaver
I’ll have a look over weekend. Did it quick so prob in wrong place. 
Will test it when you’re ready 
Forgot to wrap the rest of the code, concentrating on the tv instead 
Not sure if normal notification changes have a success field so may have to adapt slightly. LightwaveRF-Jars/org.openhab.binding.lightwaverf-2.5.13-SNAPSHOT_alextest.jar at main · delid4ve/LightwaveRF-Jars · GitHub
I’ll have a play tomorrow see if I can get my sockets to fail… is it just trv’s you have @xela? If not seems to be a localised trv issue so will help me track it down.
Ignore that just see dimmer in the log
Hmm… also just see that top line in the log… that’s a new message I’ve not seen before…
That’s gonna crash it too (as it did).
Like the look of the new token fields aswell in there… maybe the local api being worked on
I’ll get that one sorted over weekend, had enough of screens for one day 
I have the TRVs, sockets, switches and a monitor. I’ve only seen it with the TRVs, but I don’t overly interact with the lights etc
Yeah, the new message came up after I opened the app, will see if I can trigger it again at some point, I redacted some of it, I’ll pm you the full version
Seems to get stuck
20:11:16.434 [DEBUG] [andler.LightwaverfSmartAccountHandler] - Running the message queue
20:11:16.434 [DEBUG] [andler.LightwaverfSmartAccountHandler] - Starting the websocket
20:11:16.435 [DEBUG] [andler.LightwaverfSmartAccountHandler] - Creating scheduled tasks
20:11:16.557 [DEBUG] [ternal.LightwaverfSmartCommandManager] - Sending Login Command
20:11:16.557 [DEBUG] [ternal.LightwaverfSmartCommandManager] - Adding login command to the top of the queue
20:11:16.558 [DEBUG] [connections.LightwaverfSmartWebsocket] - LightwaveRF - WebSocket Socket successfully connected to v1-linkplus-app.lightwaverf.com/54.246.140.139
Go back to working version for now while I look into it.
Might be a cache problem it getting stuck, may just need a restart of openhab.
Have done for now, no rush, I was only testing them because you were releasing them 
Was bound to be bugs moving over to the websocket. Works a lot better in general without the polling just new messages/errors to sort out
Oh it’s a million times better than the polling, can’t wait for local api access too
Try this one @xela.
- unsupported messages should now be logged at info level so I can add if needed.
- unsuccessful commands from openhab will now re-queue (need to see how this goes as if its always unsucessful it will just keep trying) - should be able to find how long it takes for your trv to actually receive now though and whether an error in a transformation somewhere (something the hub doesnt like)
- some logging changed to trace
can you also let me know how you got that top log message from the app, what you did. i cant get it to happen
can you also let me know how you got that top log message from the app, what you did. i cant get it to happen
I’m not 100% sure, I opened the app and changed the temperature on one of the TRVs, but it was the first time I opened in a while, so maybe it was re-authing
Still seems to be crashing if I send commands from HABPanel:
11:17:33.860 [INFO ] [smarthome.event.ItemCommandEvent ] - Item 'lw_LR2Heating_callForHeat' received command ON
11:17:33.861 [INFO ] [arthome.event.ItemStatePredictedEvent] - lw_LR2Heating_callForHeat predicted to become ON
11:17:33.869 [INFO ] [clipse.smarthome.model.script.Heating] - Turning Heating on due to lw_LR2Heating_callForHeat
11:17:33.870 [INFO ] [smarthome.event.ItemStateChangedEvent] - lw_LR2Heating_callForHeat changed from OFF to ON
11:17:33.872 [INFO ] [home.event.GroupItemStateChangedEvent] - Lightwave_TRV_CallforHeat changed from OFF to UNDEF through lw_LR2Heating_callForHeat
11:17:33.873 [DEBUG] [connections.LightwaverfSmartWebsocket] - Sending message: {"version":1,"class":"feature","operation":"write","direction":"request","senderId":"c5f3b12b-75ca-4863-8c93-488d86796f83","items":[{"itemId":"127","payload":{"featureId":"5df8b6728522075debd21ad8-166-3157346060+1","value":1}}],"transactionId":127}
11:17:33.876 [DEBUG] [connections.LightwaverfSmartWebsocket] - LightwaveRF - Websocket message sending completed: {"version":1,"class":"feature","operation":"write","direction":"request","senderId":"c5f3b12b-75ca-4863-8c93-488d86796f83","items":[{"itemId":"127","payload":{"featureId":"5df8b6728522075debd21ad8-166-3157346060+1","value":1}}],"transactionId":127}
11:17:33.934 [WARN ] [connections.LightwaverfSmartWebsocket] - LightwaveRF - Closing a WebSocket due to null
11:17:33.938 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'lightwaverf:lightwaverfaccount:alex' changed from ONLINE to OFFLINE
11:17:33.939 [WARN ] [connections.LightwaverfSmartWebsocket] - LightwaveRF - WebSocket connection closed
11:17:33.939 [DEBUG] [handler.LightwaverfSmartDeviceHandler] - bridgeStatusChanged OFFLINE for thing lightwaverf:d22:alex:LivingroomDimmer
11:17:33.941 [WARN ] [connections.LightwaverfSmartWebsocket] - LightwaveRF - Closing a WebSocket due to NullPointerException
11:17:33.939 [DEBUG] [handler.LightwaverfSmartDeviceHandler] - bridgeStatusChanged OFFLINE for thing lightwaverf:h21:alex:LightwaveHub
11:17:33.942 [WARN ] [connections.LightwaverfSmartWebsocket] - LightwaveRF - WebSocket connection closed
11:17:33.939 [DEBUG] [handler.LightwaverfSmartDeviceHandler] - bridgeStatusChanged OFFLINE for thing lightwaverf:d21:alex:KeiraDimmer
11:17:33.943 [DEBUG] [handler.LightwaverfSmartDeviceHandler] - bridgeStatusChanged OFFLINE for thing lightwaverf:s22:alex:ConservatorySocket
11:17:33.938 [DEBUG] [handler.LightwaverfSmartDeviceHandler] - bridgeStatusChanged OFFLINE for thing lightwaverf:d21:alex:OfficeDimmer
11:17:33.938 [DEBUG] [handler.LightwaverfSmartDeviceHandler] - bridgeStatusChanged OFFLINE for thing lightwaverf:d21:alex:RyanDimmer
11:17:33.945 [DEBUG] [handler.LightwaverfSmartDeviceHandler] - bridgeStatusChanged OFFLINE for thing lightwaverf:e11:alex:Monitor
11:17:33.945 [DEBUG] [handler.LightwaverfSmartDeviceHandler] - bridgeStatusChanged OFFLINE for thing lightwaverf:d21:alex:BedroomDimmer
11:17:33.944 [DEBUG] [handler.LightwaverfSmartDeviceHandler] - bridgeStatusChanged OFFLINE for thing lightwaverf:t11:alex:OfficeTRV
11:17:33.943 [WARN ] [connections.LightwaverfSmartWebsocket] - LightwaveRF - Closing a WebSocket due to Disconnected
11:17:33.942 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'lightwaverf:d22:alex:LivingroomDimmer' changed from ONLINE to OFFLINE (BRIDGE_OFFLINE)
11:17:33.942 [DEBUG] [handler.LightwaverfSmartDeviceHandler] - bridgeStatusChanged OFFLINE for thing lightwaverf:t11:alex:Heating
11:17:33.948 [WARN ] [connections.LightwaverfSmartWebsocket] - LightwaveRF - WebSocket connection closed
Edit: Just opened again and got the same:
11:19:40.799 [INFO ] [ternal.LightwaverfSmartCommandManager] - Unhandled websocket message {"version":1,"senderId":1,"transactionId":9653059,"direction":"notification","class":"user","operation":"update","items":[{"payload":{"time":1618049980779,"email":"alex@co.uk","rootGroupIds":["5df8b6728522075debd21ad8-5df8b6728522075debd21ad9"],"settings":{"geofencing":false},"consent":{"data":{"consented":true,"updated":"2019-12-06T16:13:28.717Z"},"marketing":{"hubspotId":"15909051"}},"utility":{"electricity":{"tariff":0.11593,"country":"GB","currency":"GBP"}},"userId":"7aa9ada8-9914-4f8f-9bd4-80f85593a54b","givenName":"Alex","familyName":"","platformToken":null,"firebaseToken":"f9DV6BG8eUepiMNH6fvpY8:APA91bEL4Mto-YuQqFKhuzBnTollq2STRRi2","platform":"ios","notificationTypes":{"firmware":true,"automations":true}},"success":true,"itemId":15}]}
can you try again with trace logging enabled (the message causing it will then show)
Just clearing cache and tmp, will try after its started again
1 Like
11:28:29.386 [INFO ] [smarthome.event.ItemCommandEvent ] - Item ‘lw_LR2Heating_callForHeat’ received command ON
11:28:29.389 [INFO ] [arthome.event.ItemStatePredictedEvent] - lw_LR2Heating_callForHeat predicted to become ON
11:28:29.472 [INFO ] [smarthome.event.ItemStateChangedEvent] - lw_LR2Heating_callForHeat changed from OFF to ON
11:28:29.473 [INFO ] [home.event.GroupItemStateChangedEvent] - Lightwave_TRV_CallforHeat changed from OFF to UNDEF through lw_LR2Heating_callForHeat
11:28:29.478 [TRACE] [ternal.LightwaverfSmartCommandManager] - Adding command to the queue
11:28:29.480 [INFO ] [clipse.smarthome.model.script.Heating] - Turning Heating on due to lw_LR2Heating_callForHeat
11:28:29.481 [DEBUG] [connections.LightwaverfSmartWebsocket] - Sending message: {“version”:1,“class”:“feature”,“operation”:“write”,“direction”:“request”,“senderId”:“dc0c2a1b-e2c5-47c1-b969-7af85f7473c9”,“items”:[{“itemId”:“127”,“payload”:{“featureId”:“5df8b6728522075debd21ad8-166-3157346060+1”,“value”:1}}],“transactionId”:127}
11:28:29.484 [DEBUG] [connections.LightwaverfSmartWebsocket] - LightwaveRF - Websocket message sending completed: {“version”:1,“class”:“feature”,“operation”:“write”,“direction”:“request”,“senderId”:“dc0c2a1b-e2c5-47c1-b969-7af85f7473c9”,“items”:[{“itemId”:“127”,“payload”:{“featureId”:“5df8b6728522075debd21ad8-166-3157346060+1”,“value”:1}}],“transactionId”:127}
11:28:29.541 [TRACE] [ternal.LightwaverfSmartCommandManager] - Message received: {“version”:1,“senderId”:1,“direction”:“response”,“items”:[{“itemId”:“127”,“success”:false,“error”:{“code”:6,“group”:3,“source”:“linkPlus”}}],“class”:“feature”,“operation”:“write”,“transactionId”:46577354}
11:28:29.547 [WARN ] [connections.LightwaverfSmartWebsocket] - LightwaveRF - Closing a WebSocket due to null
11:28:29.550 [DEBUG] [handler.LightwaverfSmartDeviceHandler] - bridgeStatusChanged OFFLINE for thing lightwaverf:d21:alex:KeiraDimmer
11:28:29.551 [DEBUG] [handler.LightwaverfSmartDeviceHandler] - bridgeStatusChanged OFFLINE for thing lightwaverf:d21:alex:OfficeDimmer
11:28:29.551 [WARN ] [connections.LightwaverfSmartWebsocket] - LightwaveRF - WebSocket connection closed
5 mins see why it’s failing to process so I’ll change
Different error code to before…