Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[lutron] LEAP Bridge goes offline and does not return #9178

Closed
morph166955 opened this issue Nov 30, 2020 · 27 comments
Closed

[lutron] LEAP Bridge goes offline and does not return #9178

morph166955 opened this issue Nov 30, 2020 · 27 comments
Labels
bug An unexpected problem or unintended behavior of an add-on

Comments

@morph166955
Copy link
Contributor

morph166955 commented Nov 30, 2020

@bobadair FYI

From https://community.openhab.org/t/lutron-caseta-support/102310/56

LEAP bridges will go offline and not return. Trace logs below do not seem to indicate any specific reason other than "End of input stream detected" and "Message reader thread exiting". No new connection is established after this message.

2020-11-29 19:15:04.599 [INFO ] [me.event.ThingStatusInfoChangedEvent] - Thing 'lutron:leapbridge:bridge2' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): Connection lost
2020-11-29 19:15:04.666 [INFO ] [me.event.ThingStatusInfoChangedEvent] - Thing 'lutron:leapbridge:bridge1' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): Connection lost

2020-11-29 19:11:13.367 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Received message: {"CommuniqueType":"ReadResponse","Header":{"MessageBodyType":"MultipleOccupancyGroupStatus","StatusCode":"200 OK","Url":"/occupancygroup/status"},"Body":{"OccupancyGroupStatuses":[{"href":"/occupancygroup/13/status","OccupancyGroup":{"href":"/occupancygroup/13"},"OccupancyStatus":"Unoccupied"}]}}
2020-11-29 19:11:13.367 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Received CommuniqueType: ReadResponse
2020-11-29 19:11:13.367 [TRACE] [rnal.protocol.leap.LeapMessageParser] - MessageBodyType: MultipleOccupancyGroupStatus
2020-11-29 19:11:13.367 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Parsing occupancy group status list
2020-11-29 19:11:13.367 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - OccupancyGroup: 13 Status: Unoccupied
2020-11-29 19:11:13.367 [TRACE] [n.internal.handler.LeapBridgeHandler] - Group 13 state update: Unoccupied
2020-11-29 19:11:13.389 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Received message: {"CommuniqueType":"ReadResponse","Header":{"MessageBodyType":"OneZoneStatus","StatusCode":"200 OK","Url":"/zone/24/status/level"},"Body":{"ZoneStatus":{"href":"/zone/24/status","Level":0,"SwitchedLevel":"Off","Zone":{"href":"/zone/24"},"StatusAccuracy":"Good"}}}
2020-11-29 19:11:13.389 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Received CommuniqueType: ReadResponse
2020-11-29 19:11:13.389 [TRACE] [rnal.protocol.leap.LeapMessageParser] - MessageBodyType: OneZoneStatus
2020-11-29 19:11:13.389 [TRACE] [n.internal.handler.LeapBridgeHandler] - Zone: 24 level: 0
2020-11-29 19:11:13.389 [TRACE] [n.internal.handler.LeapBridgeHandler] - Zone 24 mapped to device id 32
2020-11-29 19:15:04.599 [DEBUG] [n.internal.handler.LeapBridgeHandler] - End of input stream detected
2020-11-29 19:15:04.600 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 2
2020-11-29 19:15:04.600 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 3
2020-11-29 19:15:04.600 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 5
2020-11-29 19:15:04.600 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 4
2020-11-29 19:15:04.600 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 6
2020-11-29 19:15:04.600 [DEBUG] [n.internal.handler.LeapBridgeHandler] - Message reader thread exiting
2020-11-29 19:15:04.601 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 9
2020-11-29 19:15:04.601 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 10
2020-11-29 19:15:04.601 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 11
2020-11-29 19:15:04.601 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 7
2020-11-29 19:15:04.601 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 8
2020-11-29 19:15:04.601 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 1
2020-11-29 19:15:04.663 [DEBUG] [n.internal.handler.LeapBridgeHandler] - End of input stream detected
2020-11-29 19:15:04.664 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 10
2020-11-29 19:15:04.664 [DEBUG] [n.internal.handler.LeapBridgeHandler] - Message reader thread exiting
2020-11-29 19:15:04.664 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 11
2020-11-29 19:15:04.664 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 40
2020-11-29 19:15:04.664 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 39
2020-11-29 19:15:04.664 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 37
2020-11-29 19:15:04.664 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 16
2020-11-29 19:15:04.664 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 34
2020-11-29 19:15:04.664 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 35
2020-11-29 19:15:04.664 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 41
2020-11-29 19:15:04.664 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 36
2020-11-29 19:15:04.664 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 23
2020-11-29 19:15:04.664 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 29
2020-11-29 19:15:04.664 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 30
2020-11-29 19:15:04.664 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 32
2020-11-29 19:15:04.664 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 31
2020-11-29 19:15:04.664 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 45
2020-11-29 19:15:04.664 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 57
2020-11-29 19:15:04.664 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 47
2020-11-29 19:15:04.664 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 49
2020-11-29 19:15:04.664 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 50
2020-11-29 19:15:04.664 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 51
2020-11-29 19:15:04.664 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 52
2020-11-29 19:15:04.665 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 53
2020-11-29 19:15:04.665 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 54
2020-11-29 19:15:04.665 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 55
2020-11-29 19:15:04.665 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 62
2020-11-29 19:15:04.665 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 64
2020-11-29 19:15:04.665 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 66
2020-11-29 19:15:04.665 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 67
2020-11-29 19:15:04.665 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 65
2020-11-29 19:15:04.665 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 70
2020-11-29 19:15:04.665 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 72
2020-11-29 19:15:04.665 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 74
2020-11-29 19:15:04.665 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 75
2020-11-29 19:15:04.665 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 77
2020-11-29 19:15:04.665 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 76
2020-11-29 19:15:04.665 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 78
2020-11-29 19:15:04.665 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 84
2020-11-29 19:15:04.665 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 85
2020-11-29 19:15:04.665 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 86
2020-11-29 19:15:04.665 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 81
2020-11-29 19:15:04.665 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 80
2020-11-29 19:15:04.665 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 82
2020-11-29 19:15:04.665 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 83
2020-11-29 19:15:04.665 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 87
2020-11-29 19:15:04.665 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 2
2020-11-29 19:15:04.665 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 6
2020-11-29 19:15:04.665 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 12
2020-11-29 19:15:04.665 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 13
2020-11-29 19:15:04.665 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 16
2020-11-29 19:15:04.665 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 22
2020-11-29 19:15:04.665 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 19
2020-11-29 19:15:04.665 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 33
2020-11-29 19:15:04.665 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 20
2020-11-29 19:15:04.665 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 42
2020-11-29 19:15:04.665 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 43
2020-11-29 19:15:04.665 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 60
2020-11-29 19:15:04.665 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 68
2020-11-29 19:15:04.665 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 69
2020-11-29 19:15:04.665 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 71
2020-11-29 19:15:04.666 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 79
2020-11-29 19:15:04.666 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 1
2020-11-29 19:15:04.665 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 73
2020-11-29 19:16:27.503 [ERROR] [org.jupnp.transport.spi.StreamClient] - Request: HttpRequest[GET /capability HTTP/1.1]@629629cf failed
2020-11-29 19:26:24.409 [DEBUG] [ry.LutronMcastBridgeDiscoveryService] - Scanning for Lutron bridge devices using multicast
@morph166955 morph166955 added the bug An unexpected problem or unintended behavior of an add-on label Nov 30, 2020
@bobadair
Copy link
Member

bobadair commented Dec 2, 2020

I don’t see anything unusual in these logs other than that the system lost the connections to two different bridge devices at about the same time. Everything else is the expected behavior when a connection is lost. What happens when it tries to re-connect?

@morph166955
Copy link
Contributor Author

That's it. It never tries to reconnect. I let it sit for 45 minutes that time. It sat overnight once. For some reason it just stays dead.

@bobadair
Copy link
Member

bobadair commented Dec 3, 2020

What do you have the heartbeat and reconnect parameters set to? I was just looking at the code to remember how it works. If the connection is lost, the reader thread just exits and it is up to the heartbeat/reconnect logic to initiate a reconnect. By default, that should happen within 10 minutes.

@morph166955
Copy link
Contributor Author

Everything is default. Definitely didn't kick after an hour of waiting.

@morph166955
Copy link
Contributor Author

morph166955 commented Dec 5, 2020

Happened again today. Both bridges. ~9 minutes apart this time. I waited over an hour, they never came back. At 19:06 (see below) I did "bundle:restart org.openhab.binding.lutron" but that didn't restore the connection either. I attempted to refresh the things file. Also nothing. Restarting OH finally restored the connection.

2020-12-04 17:56:00.729 [TRACE] [n.internal.handler.LeapBridgeHandler] - Zone: 22 level: 50
2020-12-04 17:56:00.729 [TRACE] [n.internal.handler.LeapBridgeHandler] - Zone 22 mapped to device id 30
2020-12-04 17:56:00.730 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Received message: {"CommuniqueType":"CreateResponse","Header":{"MessageBodyType":"OneZoneStatus","StatusCode":"201 Created","Url":"/zone/
22/commandprocessor"},"Body":{"ZoneStatus":{"href":"/zone/22/status","Level":50,"Zone":{"href":"/zone/22"}}}}
2020-12-04 17:56:00.730 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Received CommuniqueType: CreateResponse
2020-12-04 17:56:00.806 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "CreateRequest","Header": {"Url": "/zone/30/commandprocessor"},"Body": {"Command": {"CommandType": "Go
ToDimmedLevel","DimmedLevelParameters": {"Level": 50, "FadeTime": "00:00:01", "DelayTime": "00:00:00"}}}}
2020-12-04 17:56:00.828 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Received message: {"CommuniqueType":"ReadResponse","Header":{"MessageBodyType":"OneZoneStatus","StatusCode":"200 OK","Url":"/zone/30/stat
us/level"},"Body":{"ZoneStatus":{"href":"/zone/30/status","Level":50,"Zone":{"href":"/zone/30"},"StatusAccuracy":"Good"}}}
2020-12-04 17:56:00.828 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Received CommuniqueType: ReadResponse
2020-12-04 17:56:00.828 [TRACE] [rnal.protocol.leap.LeapMessageParser] - MessageBodyType: OneZoneStatus
2020-12-04 17:56:00.828 [TRACE] [n.internal.handler.LeapBridgeHandler] - Zone: 30 level: 50
2020-12-04 17:56:00.828 [TRACE] [n.internal.handler.LeapBridgeHandler] - Zone 30 mapped to device id 39
2020-12-04 17:56:00.831 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Received message: {"CommuniqueType":"CreateResponse","Header":{"MessageBodyType":"OneZoneStatus","StatusCode":"201 Created","Url":"/zone/
30/commandprocessor"},"Body":{"ZoneStatus":{"href":"/zone/30/status","Level":50,"Zone":{"href":"/zone/30"}}}}
2020-12-04 17:56:00.831 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Received CommuniqueType: CreateResponse
2020-12-04 17:56:00.906 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "CreateRequest","Header": {"Url": "/zone/31/commandprocessor"},"Body": {"Command": {"CommandType": "Go
ToDimmedLevel","DimmedLevelParameters": {"Level": 50, "FadeTime": "00:00:01", "DelayTime": "00:00:00"}}}}
2020-12-04 17:56:00.930 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Received message: {"CommuniqueType":"ReadResponse","Header":{"MessageBodyType":"OneZoneStatus","StatusCode":"200 OK","Url":"/zone/31/stat
us/level"},"Body":{"ZoneStatus":{"href":"/zone/31/status","Level":50,"Zone":{"href":"/zone/31"},"StatusAccuracy":"Good"}}}
2020-12-04 17:56:00.930 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Received CommuniqueType: ReadResponse
2020-12-04 17:56:00.930 [TRACE] [rnal.protocol.leap.LeapMessageParser] - MessageBodyType: OneZoneStatus
2020-12-04 17:56:00.931 [TRACE] [n.internal.handler.LeapBridgeHandler] - Zone: 31 level: 50
2020-12-04 17:56:00.931 [TRACE] [n.internal.handler.LeapBridgeHandler] - Zone 31 mapped to device id 40
2020-12-04 17:56:00.932 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Received message: {"CommuniqueType":"CreateResponse","Header":{"MessageBodyType":"OneZoneStatus","StatusCode":"201 Created","Url":"/zone/
31/commandprocessor"},"Body":{"ZoneStatus":{"href":"/zone/31/status","Level":50,"Zone":{"href":"/zone/31"}}}}
2020-12-04 17:56:00.932 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Received CommuniqueType: CreateResponse
2020-12-04 17:58:58.454 [DEBUG] [n.internal.handler.LeapBridgeHandler] - End of input stream detected
2020-12-04 17:58:58.454 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 2
2020-12-04 17:58:58.454 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 3
2020-12-04 17:58:58.455 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 4
2020-12-04 17:58:58.455 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 5
2020-12-04 17:58:58.455 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 6
2020-12-04 17:58:58.455 [DEBUG] [n.internal.handler.LeapBridgeHandler] - Message reader thread exiting
2020-12-04 17:58:58.456 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 9
2020-12-04 17:58:58.456 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 10
2020-12-04 17:58:58.456 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 11
2020-12-04 17:58:58.456 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 7
2020-12-04 17:58:58.456 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 8
2020-12-04 17:58:58.456 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 1
2020-12-04 17:59:10.826 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Received message: {"CommuniqueType":"ReadResponse","Header":{"MessageBodyType":"MultipleOccupancyGroupStatus","StatusCode":"200 OK","Url"
:"/occupancygroup/status"},"Body":{"OccupancyGroupStatuses":[{"href":"/occupancygroup/2/status","OccupancyGroup":{"href":"/occupancygroup/2"},"OccupancyStatus":"Unoccupied"}]}}
2020-12-04 17:59:10.826 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Received CommuniqueType: ReadResponse
2020-12-04 17:59:10.826 [TRACE] [rnal.protocol.leap.LeapMessageParser] - MessageBodyType: MultipleOccupancyGroupStatus
2020-12-04 17:59:10.826 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Parsing occupancy group status list
2020-12-04 17:59:10.826 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - OccupancyGroup: 2 Status: Unoccupied
2020-12-04 17:59:10.826 [TRACE] [n.internal.handler.LeapBridgeHandler] - Group 2 state update: Unoccupied
2020-12-04 17:59:10.848 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Received message: {"CommuniqueType":"ReadResponse","Header":{"MessageBodyType":"OneZoneStatus","StatusCode":"200 OK","Url":"/zone/53/stat
us/level"},"Body":{"ZoneStatus":{"href":"/zone/53/status","Level":0,"SwitchedLevel":"Off","Zone":{"href":"/zone/53"},"StatusAccuracy":"Good"}}}
2020-12-04 17:59:10.848 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Received CommuniqueType: ReadResponse
2020-12-04 17:59:10.848 [TRACE] [rnal.protocol.leap.LeapMessageParser] - MessageBodyType: OneZoneStatus
2020-12-04 17:59:10.848 [TRACE] [n.internal.handler.LeapBridgeHandler] - Zone: 53 level: 0
2020-12-04 17:59:10.848 [TRACE] [n.internal.handler.LeapBridgeHandler] - Zone 53 mapped to device id 70
2020-12-04 18:00:06.398 [DEBUG] [ry.LutronMcastBridgeDiscoveryService] - Scanning for Lutron bridge devices using multicast
2020-12-04 18:00:09.400 [TRACE] [ry.LutronMcastBridgeDiscoveryService] - Timed out waiting for multicast response. Presumably all bridge devices have already responded.
2020-12-04 18:06:00.935 [DEBUG] [n.internal.handler.LeapBridgeHandler] - End of input stream detected
2020-12-04 18:06:00.936 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 10
2020-12-04 18:06:00.936 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 11
2020-12-04 18:06:00.936 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 40
2020-12-04 18:06:00.936 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 39
2020-12-04 18:06:00.936 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 37
2020-12-04 18:06:00.936 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 16
2020-12-04 18:06:00.936 [DEBUG] [n.internal.handler.LeapBridgeHandler] - Message reader thread exiting
2020-12-04 18:06:00.936 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 34
2020-12-04 18:06:00.936 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 35
2020-12-04 18:06:00.936 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 41
2020-12-04 18:06:00.936 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 36
2020-12-04 18:06:00.936 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 23
2020-12-04 18:06:00.936 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 29
2020-12-04 18:06:00.936 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 30
2020-12-04 18:06:00.936 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 31
2020-12-04 18:06:00.936 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 32
2020-12-04 18:06:00.936 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 45
2020-12-04 18:06:00.936 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 57
2020-12-04 18:06:00.936 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 47
2020-12-04 18:06:00.936 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 49
2020-12-04 18:06:00.936 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 50
2020-12-04 18:06:00.936 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 51
2020-12-04 18:06:00.936 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 52
2020-12-04 18:06:00.937 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 53
2020-12-04 18:06:00.937 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 54
2020-12-04 18:06:00.937 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 55
2020-12-04 18:06:00.937 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 62
2020-12-04 18:06:00.937 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 64
2020-12-04 18:06:00.937 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 66
2020-12-04 18:06:00.937 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 67
2020-12-04 18:06:00.937 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 65
2020-12-04 18:06:00.937 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 70
2020-12-04 18:06:00.937 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 72
2020-12-04 18:06:00.937 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 74
2020-12-04 18:06:00.937 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 75
2020-12-04 18:06:00.937 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 77
2020-12-04 18:06:00.937 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 76
2020-12-04 18:06:00.937 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 78
2020-12-04 18:06:00.937 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 84
2020-12-04 18:06:00.937 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 85
2020-12-04 18:06:00.937 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 86
2020-12-04 18:06:00.937 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 81
2020-12-04 18:06:00.937 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 80
2020-12-04 18:06:00.937 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 82
2020-12-04 18:06:00.937 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 83
2020-12-04 18:06:00.937 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 87
2020-12-04 18:06:00.937 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 2
2020-12-04 18:06:00.937 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 6
2020-12-04 18:06:00.937 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 12
2020-12-04 18:06:00.937 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 13
2020-12-04 18:06:00.937 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 16
2020-12-04 18:06:00.937 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 20
2020-12-04 18:06:00.937 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 22
2020-12-04 18:06:00.937 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 19
2020-12-04 18:06:00.937 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 33
2020-12-04 18:06:00.937 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 42
2020-12-04 18:06:00.937 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 43
2020-12-04 18:06:00.937 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 60
2020-12-04 18:06:00.937 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 68
2020-12-04 18:06:00.937 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 69
2020-12-04 18:06:00.937 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 71
2020-12-04 18:06:00.937 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 73
2020-12-04 18:06:00.937 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 79
2020-12-04 18:06:00.937 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 1
2020-12-04 18:30:09.401 [DEBUG] [ry.LutronMcastBridgeDiscoveryService] - Scanning for Lutron bridge devices using multicast
2020-12-04 18:30:12.403 [TRACE] [ry.LutronMcastBridgeDiscoveryService] - Timed out waiting for multicast response. Presumably all bridge devices have already responded.
2020-12-04 19:00:12.403 [DEBUG] [ry.LutronMcastBridgeDiscoveryService] - Scanning for Lutron bridge devices using multicast
2020-12-04 19:00:15.405 [TRACE] [ry.LutronMcastBridgeDiscoveryService] - Timed out waiting for multicast response. Presumably all bridge devices have already responded.
2020-12-04 19:06:21.525 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 62
2020-12-04 19:06:21.527 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered group handler for ID 2
2020-12-04 19:06:21.530 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 53
2020-12-04 19:06:21.532 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered group handler for ID 16
2020-12-04 19:06:21.534 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 3
2020-12-04 19:06:21.536 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered group handler for ID 13
2020-12-04 19:06:21.537 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered group handler for ID 12
2020-12-04 19:06:21.539 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 51
2020-12-04 19:06:21.541 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 87
2020-12-04 19:06:21.543 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 5
2020-12-04 19:06:21.545 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 43
2020-12-04 19:06:21.546 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 47
2020-12-04 19:06:21.548 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 23
2020-12-04 19:06:21.552 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 29
2020-12-04 19:06:21.557 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 72
2020-12-04 19:06:21.559 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 79
2020-12-04 19:06:21.561 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 10
2020-12-04 19:06:21.563 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 8
2020-12-04 19:06:21.565 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 32
2020-12-04 19:06:21.566 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 11
2020-12-04 19:06:21.568 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 70
2020-12-04 19:06:21.570 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 50
2020-12-04 19:06:21.571 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 52
2020-12-04 19:06:21.573 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 77
2020-12-04 19:06:21.575 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 73
2020-12-04 19:06:21.577 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered group handler for ID 20
2020-12-04 19:06:21.579 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 64
2020-12-04 19:06:21.585 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 10
2020-12-04 19:06:21.588 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 11
2020-12-04 19:06:21.591 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 40
2020-12-04 19:06:21.593 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 39
2020-12-04 19:06:21.595 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 37
2020-12-04 19:06:21.597 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 16
2020-12-04 19:06:21.599 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 34
2020-12-04 19:06:21.602 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 35
2020-12-04 19:06:21.604 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 41
2020-12-04 19:06:21.608 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 36
2020-12-04 19:06:21.611 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 30
2020-12-04 19:06:21.616 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 31
2020-12-04 19:06:21.619 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 45
2020-12-04 19:06:21.622 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 57
2020-12-04 19:06:21.625 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 49
2020-12-04 19:06:21.627 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 54
2020-12-04 19:06:21.630 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 55
2020-12-04 19:06:21.632 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 66
2020-12-04 19:06:21.634 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 67
2020-12-04 19:06:21.637 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 65
2020-12-04 19:06:21.639 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 74
2020-12-04 19:06:21.641 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 75
2020-12-04 19:06:21.643 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 76
2020-12-04 19:06:21.646 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 78
2020-12-04 19:06:21.649 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 84
2020-12-04 19:06:21.651 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 85
2020-12-04 19:06:21.655 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 81
2020-12-04 19:06:21.655 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 86
2020-12-04 19:06:21.657 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 80
2020-12-04 19:06:21.660 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 82
2020-12-04 19:06:21.662 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 83
2020-12-04 19:06:21.664 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered group handler for ID 6
2020-12-04 19:06:21.665 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered group handler for ID 22
2020-12-04 19:06:21.667 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 19
2020-12-04 19:06:21.669 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 33
2020-12-04 19:06:21.670 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 42
2020-12-04 19:06:21.672 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 60
2020-12-04 19:06:21.673 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 68
2020-12-04 19:06:21.675 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 69
2020-12-04 19:06:21.677 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 71
2020-12-04 19:06:21.678 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 1
2020-12-04 19:06:21.680 [DEBUG] [n.internal.handler.LeapBridgeHandler] - Disconnecting
2020-12-04 19:06:21.680 [DEBUG] [n.internal.handler.LeapBridgeHandler] - Command sender thread exiting
2020-12-04 19:06:21.685 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 2
2020-12-04 19:06:21.687 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 4
2020-12-04 19:06:21.688 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 6
2020-12-04 19:06:21.690 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 9
2020-12-04 19:06:21.692 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 7
2020-12-04 19:06:21.693 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 1
2020-12-04 19:06:21.695 [DEBUG] [n.internal.handler.LeapBridgeHandler] - Disconnecting
2020-12-04 19:06:21.695 [DEBUG] [n.internal.handler.LeapBridgeHandler] - Command sender thread exiting
2020-12-04 19:06:21.771 [TRACE] [n.internal.handler.LeapBridgeHandler] - Initializing keystore
2020-12-04 19:06:21.771 [TRACE] [n.internal.handler.LeapBridgeHandler] - Initializing SSL Context
2020-12-04 19:06:21.772 [TRACE] [lutron.internal.action.DimmerActions] - Lutron Dimmer actions service created
2020-12-04 19:06:21.772 [TRACE] [lutron.internal.action.DimmerActions] - Lutron Dimmer actions service created
2020-12-04 19:06:21.772 [TRACE] [lutron.internal.action.DimmerActions] - Lutron Dimmer actions service created
2020-12-04 19:06:21.772 [TRACE] [lutron.internal.action.DimmerActions] - Lutron Dimmer actions service created
2020-12-04 19:06:21.772 [TRACE] [lutron.internal.action.DimmerActions] - Lutron Dimmer actions service created
2020-12-04 19:06:21.774 [DEBUG] [utron.internal.handler.DimmerHandler] - Initializing Dimmer handler for integration ID 39
2020-12-04 19:06:21.774 [DEBUG] [utron.internal.handler.DimmerHandler] - Initializing device state for Dimmer 39
2020-12-04 19:06:21.776 [DEBUG] [utron.internal.handler.SwitchHandler] - Initializing Switch handler for integration ID 16
2020-12-04 19:06:21.776 [DEBUG] [utron.internal.handler.DimmerHandler] - Initializing Dimmer handler for integration ID 11
2020-12-04 19:06:21.776 [DEBUG] [utron.internal.handler.SwitchHandler] - Initializing device state for Switch 16
2020-12-04 19:06:21.776 [DEBUG] [utron.internal.handler.DimmerHandler] - Initializing device state for Dimmer 11
2020-12-04 19:06:21.776 [TRACE] [lutron.internal.action.DimmerActions] - Lutron Dimmer actions service created
2020-12-04 19:06:21.776 [TRACE] [lutron.internal.action.DimmerActions] - Lutron Dimmer actions service created
2020-12-04 19:06:21.778 [DEBUG] [utron.internal.handler.DimmerHandler] - Initializing Dimmer handler for integration ID 10
2020-12-04 19:06:21.778 [DEBUG] [utron.internal.handler.DimmerHandler] - Initializing device state for Dimmer 10
2020-12-04 19:06:21.778 [DEBUG] [utron.internal.handler.DimmerHandler] - Initializing Dimmer handler for integration ID 37
2020-12-04 19:06:21.778 [DEBUG] [utron.internal.handler.DimmerHandler] - Initializing device state for Dimmer 37
2020-12-04 19:06:21.778 [TRACE] [lutron.internal.action.DimmerActions] - Lutron Dimmer actions service created
2020-12-04 19:06:21.778 [TRACE] [lutron.internal.action.DimmerActions] - Lutron Dimmer actions service created
2020-12-04 19:06:21.780 [DEBUG] [utron.internal.handler.DimmerHandler] - Initializing Dimmer handler for integration ID 34
2020-12-04 19:06:21.780 [DEBUG] [utron.internal.handler.DimmerHandler] - Initializing device state for Dimmer 34
2020-12-04 19:06:21.780 [TRACE] [lutron.internal.action.DimmerActions] - Lutron Dimmer actions service created
2020-12-04 19:06:21.780 [DEBUG] [utron.internal.handler.DimmerHandler] - Initializing Dimmer handler for integration ID 36
2020-12-04 19:06:21.780 [DEBUG] [utron.internal.handler.DimmerHandler] - Initializing device state for Dimmer 36
2020-12-04 19:06:21.781 [DEBUG] [utron.internal.handler.DimmerHandler] - Initializing Dimmer handler for integration ID 40
2020-12-04 19:06:21.781 [DEBUG] [utron.internal.handler.DimmerHandler] - Initializing device state for Dimmer 40
2020-12-04 19:06:21.781 [TRACE] [lutron.internal.action.DimmerActions] - Lutron Dimmer actions service created
2020-12-04 19:06:21.783 [DEBUG] [utron.internal.handler.DimmerHandler] - Initializing Dimmer handler for integration ID 23
2020-12-04 19:06:21.783 [DEBUG] [utron.internal.handler.DimmerHandler] - Initializing device state for Dimmer 23
2020-12-04 19:06:21.783 [TRACE] [lutron.internal.action.DimmerActions] - Lutron Dimmer actions service created
2020-12-04 19:06:21.783 [TRACE] [lutron.internal.action.DimmerActions] - Lutron Dimmer actions service created
2020-12-04 19:06:21.785 [DEBUG] [utron.internal.handler.DimmerHandler] - Initializing Dimmer handler for integration ID 31
2020-12-04 19:06:21.785 [DEBUG] [utron.internal.handler.DimmerHandler] - Initializing Dimmer handler for integration ID 35
2020-12-04 19:06:21.785 [DEBUG] [utron.internal.handler.DimmerHandler] - Initializing device state for Dimmer 31
2020-12-04 19:06:21.785 [DEBUG] [utron.internal.handler.DimmerHandler] - Initializing device state for Dimmer 35
2020-12-04 19:06:21.785 [DEBUG] [utron.internal.handler.DimmerHandler] - Initializing Dimmer handler for integration ID 29
2020-12-04 19:06:21.785 [DEBUG] [utron.internal.handler.DimmerHandler] - Initializing Dimmer handler for integration ID 41
2020-12-04 19:06:21.785 [DEBUG] [utron.internal.handler.DimmerHandler] - Initializing device state for Dimmer 29
2020-12-04 19:06:21.785 [DEBUG] [utron.internal.handler.DimmerHandler] - Initializing device state for Dimmer 41
2020-12-04 19:06:21.785 [TRACE] [lutron.internal.action.DimmerActions] - Lutron Dimmer actions service created
2020-12-04 19:06:21.786 [TRACE] [n.internal.handler.LeapBridgeHandler] - Initializing keystore
2020-12-04 19:06:21.786 [DEBUG] [utron.internal.handler.DimmerHandler] - Initializing Dimmer handler for integration ID 30
2020-12-04 19:06:21.786 [DEBUG] [utron.internal.handler.DimmerHandler] - Initializing device state for Dimmer 30
2020-12-04 19:06:21.786 [TRACE] [n.internal.handler.LeapBridgeHandler] - Initializing SSL Context
2020-12-04 19:06:21.787 [TRACE] [lutron.internal.action.DimmerActions] - Lutron Dimmer actions service created
2020-12-04 19:06:21.787 [DEBUG] [utron.internal.handler.SwitchHandler] - Initializing Switch handler for integration ID 47
2020-12-04 19:06:21.787 [DEBUG] [utron.internal.handler.SwitchHandler] - Initializing device state for Switch 47
2020-12-04 19:06:21.788 [DEBUG] [utron.internal.handler.SwitchHandler] - Initializing Switch handler for integration ID 32
2020-12-04 19:06:21.788 [DEBUG] [utron.internal.handler.SwitchHandler] - Initializing device state for Switch 32
2020-12-04 19:06:21.789 [DEBUG] [utron.internal.handler.SwitchHandler] - Initializing Switch handler for integration ID 49
2020-12-04 19:06:21.790 [DEBUG] [utron.internal.handler.SwitchHandler] - Initializing device state for Switch 49
2020-12-04 19:06:21.790 [DEBUG] [utron.internal.handler.DimmerHandler] - Initializing Dimmer handler for integration ID 57
2020-12-04 19:06:21.790 [DEBUG] [utron.internal.handler.DimmerHandler] - Initializing device state for Dimmer 57
2020-12-04 19:06:21.790 [DEBUG] [utron.internal.handler.SwitchHandler] - Initializing Switch handler for integration ID 51
2020-12-04 19:06:21.790 [DEBUG] [utron.internal.handler.SwitchHandler] - Initializing device state for Switch 51
2020-12-04 19:06:21.791 [DEBUG] [utron.internal.handler.SwitchHandler] - Initializing Switch handler for integration ID 52
2020-12-04 19:06:21.791 [DEBUG] [utron.internal.handler.DimmerHandler] - Initializing Dimmer handler for integration ID 45
2020-12-04 19:06:21.791 [DEBUG] [utron.internal.handler.DimmerHandler] - Initializing device state for Dimmer 45
2020-12-04 19:06:21.791 [DEBUG] [utron.internal.handler.SwitchHandler] - Initializing device state for Switch 52
2020-12-04 19:06:21.791 [DEBUG] [utron.internal.handler.SwitchHandler] - Initializing Switch handler for integration ID 50
2020-12-04 19:06:21.791 [DEBUG] [utron.internal.handler.SwitchHandler] - Initializing device state for Switch 50
2020-12-04 19:06:21.793 [DEBUG] [utron.internal.handler.SwitchHandler] - Initializing Switch handler for integration ID 54
2020-12-04 19:06:21.793 [DEBUG] [utron.internal.handler.SwitchHandler] - Initializing device state for Switch 54
2020-12-04 19:06:21.793 [DEBUG] [utron.internal.handler.SwitchHandler] - Initializing Switch handler for integration ID 55
2020-12-04 19:06:21.793 [DEBUG] [utron.internal.handler.SwitchHandler] - Initializing device state for Switch 55
2020-12-04 19:06:21.793 [DEBUG] [utron.internal.handler.SwitchHandler] - Initializing Switch handler for integration ID 62
2020-12-04 19:06:21.793 [DEBUG] [utron.internal.handler.SwitchHandler] - Initializing device state for Switch 62
2020-12-04 19:06:21.794 [DEBUG] [utron.internal.handler.SwitchHandler] - Initializing Switch handler for integration ID 53
2020-12-04 19:06:21.794 [DEBUG] [utron.internal.handler.SwitchHandler] - Initializing device state for Switch 53
2020-12-04 19:06:21.794 [DEBUG] [utron.internal.handler.SwitchHandler] - Initializing Switch handler for integration ID 64
2020-12-04 19:06:21.794 [DEBUG] [utron.internal.handler.SwitchHandler] - Initializing device state for Switch 64
2020-12-04 19:06:21.794 [TRACE] [lutron.internal.action.DimmerActions] - Lutron Dimmer actions service created
2020-12-04 19:06:21.794 [DEBUG] [utron.internal.handler.SwitchHandler] - Initializing Switch handler for integration ID 66
2020-12-04 19:06:21.794 [DEBUG] [utron.internal.handler.SwitchHandler] - Initializing device state for Switch 66
2020-12-04 19:06:21.795 [DEBUG] [utron.internal.handler.SwitchHandler] - Initializing Switch handler for integration ID 65
2020-12-04 19:06:21.795 [DEBUG] [utron.internal.handler.SwitchHandler] - Initializing device state for Switch 65
2020-12-04 19:06:21.795 [DEBUG] [utron.internal.handler.SwitchHandler] - Initializing Switch handler for integration ID 70
2020-12-04 19:06:21.795 [DEBUG] [utron.internal.handler.SwitchHandler] - Initializing device state for Switch 70
2020-12-04 19:06:21.796 [TRACE] [lutron.internal.action.DimmerActions] - Lutron Dimmer actions service created
2020-12-04 19:06:21.796 [DEBUG] [utron.internal.handler.SwitchHandler] - Initializing Switch handler for integration ID 74
2020-12-04 19:06:21.796 [DEBUG] [utron.internal.handler.SwitchHandler] - Initializing device state for Switch 74
2020-12-04 19:06:21.796 [TRACE] [lutron.internal.action.DimmerActions] - Lutron Dimmer actions service created
2020-12-04 19:06:21.797 [DEBUG] [utron.internal.handler.SwitchHandler] - Initializing Switch handler for integration ID 67
2020-12-04 19:06:21.797 [DEBUG] [utron.internal.handler.SwitchHandler] - Initializing device state for Switch 67
2020-12-04 19:06:21.797 [DEBUG] [utron.internal.handler.SwitchHandler] - Initializing Switch handler for integration ID 75
2020-12-04 19:06:21.797 [DEBUG] [utron.internal.handler.SwitchHandler] - Initializing device state for Switch 75
2020-12-04 19:06:21.798 [TRACE] [lutron.internal.action.DimmerActions] - Lutron Dimmer actions service created
2020-12-04 19:06:21.798 [DEBUG] [utron.internal.handler.DimmerHandler] - Initializing Dimmer handler for integration ID 72
2020-12-04 19:06:21.798 [DEBUG] [utron.internal.handler.DimmerHandler] - Initializing device state for Dimmer 72
2020-12-04 19:06:21.799 [DEBUG] [lutron.internal.handler.ShadeHandler] - Initializing Shade handler for integration ID 78
2020-12-04 19:06:21.799 [DEBUG] [lutron.internal.handler.ShadeHandler] - Initializing device state for Shade 78
2020-12-04 19:06:21.803 [DEBUG] [utron.internal.handler.DimmerHandler] - Initializing Dimmer handler for integration ID 76
2020-12-04 19:06:21.803 [DEBUG] [utron.internal.handler.DimmerHandler] - Initializing device state for Dimmer 76
2020-12-04 19:06:21.804 [TRACE] [lutron.internal.action.DimmerActions] - Lutron Dimmer actions service created
2020-12-04 19:06:21.808 [DEBUG] [utron.internal.handler.DimmerHandler] - Initializing Dimmer handler for integration ID 77
2020-12-04 19:06:21.808 [DEBUG] [utron.internal.handler.DimmerHandler] - Initializing device state for Dimmer 77
2020-12-04 19:06:21.808 [DEBUG] [utron.internal.handler.DimmerHandler] - Initializing Dimmer handler for integration ID 81
2020-12-04 19:06:21.808 [DEBUG] [utron.internal.handler.DimmerHandler] - Initializing device state for Dimmer 81
2020-12-04 19:06:21.808 [DEBUG] [utron.internal.handler.SwitchHandler] - Initializing Switch handler for integration ID 86
2020-12-04 19:06:21.808 [DEBUG] [utron.internal.handler.SwitchHandler] - Initializing device state for Switch 86
2020-12-04 19:06:21.808 [TRACE] [lutron.internal.action.DimmerActions] - Lutron Dimmer actions service created
2020-12-04 19:06:21.809 [DEBUG] [utron.internal.handler.SwitchHandler] - Initializing Switch handler for integration ID 82
2020-12-04 19:06:21.809 [DEBUG] [utron.internal.handler.SwitchHandler] - Initializing device state for Switch 82
2020-12-04 19:06:21.809 [DEBUG] [utron.internal.handler.SwitchHandler] - Initializing Switch handler for integration ID 85
2020-12-04 19:06:21.809 [DEBUG] [utron.internal.handler.SwitchHandler] - Initializing device state for Switch 85
2020-12-04 19:06:21.811 [DEBUG] [utron.internal.handler.SwitchHandler] - Initializing Switch handler for integration ID 83
2020-12-04 19:06:21.811 [DEBUG] [utron.internal.handler.SwitchHandler] - Initializing device state for Switch 83
2020-12-04 19:06:21.813 [DEBUG] [utron.internal.handler.DimmerHandler] - Initializing Dimmer handler for integration ID 80
2020-12-04 19:06:21.813 [DEBUG] [utron.internal.handler.DimmerHandler] - Initializing device state for Dimmer 80
2020-12-04 19:06:21.816 [DEBUG] [utron.internal.handler.SwitchHandler] - Initializing Switch handler for integration ID 87
2020-12-04 19:06:21.816 [DEBUG] [utron.internal.handler.SwitchHandler] - Initializing device state for Switch 87
2020-12-04 19:06:21.816 [DEBUG] [utron.internal.handler.OGroupHandler] - Initializing Occupancy Group handler for integration ID 2
2020-12-04 19:06:21.816 [DEBUG] [utron.internal.handler.OGroupHandler] - Initializing device state for Occupancy Group 2
2020-12-04 19:06:21.818 [DEBUG] [utron.internal.handler.OGroupHandler] - Initializing Occupancy Group handler for integration ID 6
2020-12-04 19:06:21.818 [DEBUG] [utron.internal.handler.OGroupHandler] - Initializing device state for Occupancy Group 6
2020-12-04 19:06:21.819 [DEBUG] [utron.internal.handler.OGroupHandler] - Initializing Occupancy Group handler for integration ID 12
2020-12-04 19:06:21.819 [DEBUG] [utron.internal.handler.OGroupHandler] - Initializing device state for Occupancy Group 12
2020-12-04 19:06:21.819 [DEBUG] [utron.internal.handler.DimmerHandler] - Initializing Dimmer handler for integration ID 84
2020-12-04 19:06:21.819 [DEBUG] [utron.internal.handler.DimmerHandler] - Initializing device state for Dimmer 84
2020-12-04 19:06:21.821 [DEBUG] [utron.internal.handler.OGroupHandler] - Initializing Occupancy Group handler for integration ID 22
2020-12-04 19:06:21.821 [DEBUG] [utron.internal.handler.OGroupHandler] - Initializing device state for Occupancy Group 22
2020-12-04 19:06:21.821 [DEBUG] [utron.internal.handler.OGroupHandler] - Initializing Occupancy Group handler for integration ID 20
2020-12-04 19:06:21.821 [DEBUG] [utron.internal.handler.OGroupHandler] - Initializing device state for Occupancy Group 20
2020-12-04 19:06:21.822 [DEBUG] [utron.internal.handler.OGroupHandler] - Initializing Occupancy Group handler for integration ID 13
2020-12-04 19:06:21.822 [DEBUG] [utron.internal.handler.OGroupHandler] - Initializing device state for Occupancy Group 13
2020-12-04 19:06:21.822 [DEBUG] [n.internal.handler.BaseKeypadHandler] - Initializing Keypad Handler for integration ID 19
2020-12-04 19:06:21.823 [DEBUG] [n.internal.handler.BaseKeypadHandler] - Initializing Keypad Handler for integration ID 33
2020-12-04 19:06:21.824 [DEBUG] [n.internal.handler.BaseKeypadHandler] - Initializing Keypad Handler for integration ID 68
2020-12-04 19:06:21.825 [DEBUG] [n.internal.handler.BaseKeypadHandler] - Initializing Keypad Handler for integration ID 42
2020-12-04 19:06:21.830 [DEBUG] [n.internal.handler.BaseKeypadHandler] - Initializing Keypad Handler for integration ID 60
2020-12-04 19:06:21.832 [DEBUG] [n.internal.handler.BaseKeypadHandler] - Initializing Keypad Handler for integration ID 71
2020-12-04 19:06:21.833 [DEBUG] [utron.internal.handler.OGroupHandler] - Initializing Occupancy Group handler for integration ID 16
2020-12-04 19:06:21.833 [DEBUG] [utron.internal.handler.OGroupHandler] - Initializing device state for Occupancy Group 16
2020-12-04 19:06:21.833 [DEBUG] [n.internal.handler.BaseKeypadHandler] - Initializing Keypad Handler for integration ID 43
2020-12-04 19:06:21.834 [TRACE] [n.internal.handler.LeapBridgeHandler] - Registered child handler for ID 39
2020-12-04 19:06:21.834 [TRACE] [n.internal.handler.LeapBridgeHandler] - Registered child handler for ID 11
2020-12-04 19:06:21.834 [TRACE] [n.internal.handler.LeapBridgeHandler] - Registered child handler for ID 16
2020-12-04 19:06:21.834 [TRACE] [n.internal.handler.LeapBridgeHandler] - Registered child handler for ID 10
2020-12-04 19:06:21.834 [TRACE] [n.internal.handler.LeapBridgeHandler] - Registered child handler for ID 37
2020-12-04 19:06:21.834 [TRACE] [n.internal.handler.LeapBridgeHandler] - Registered child handler for ID 34
2020-12-04 19:06:21.835 [TRACE] [n.internal.handler.LeapBridgeHandler] - Registered child handler for ID 36
2020-12-04 19:06:21.835 [TRACE] [n.internal.handler.LeapBridgeHandler] - Registered child handler for ID 40
2020-12-04 19:06:21.835 [TRACE] [n.internal.handler.LeapBridgeHandler] - Registered child handler for ID 23
2020-12-04 19:06:21.835 [TRACE] [n.internal.handler.LeapBridgeHandler] - Registered child handler for ID 31
2020-12-04 19:06:21.835 [TRACE] [n.internal.handler.LeapBridgeHandler] - Registered child handler for ID 35
2020-12-04 19:06:21.835 [TRACE] [n.internal.handler.LeapBridgeHandler] - Registered child handler for ID 29
2020-12-04 19:06:21.835 [TRACE] [n.internal.handler.LeapBridgeHandler] - Registered child handler for ID 41
2020-12-04 19:06:21.835 [TRACE] [n.internal.handler.LeapBridgeHandler] - Registered child handler for ID 30
2020-12-04 19:06:21.835 [DEBUG] [n.internal.handler.BaseKeypadHandler] - Initializing Keypad Handler for integration ID 69
2020-12-04 19:06:21.836 [DEBUG] [n.internal.handler.BaseKeypadHandler] - Initializing Keypad Handler for integration ID 79
2020-12-04 19:06:21.838 [DEBUG] [g.lutron.internal.handler.FanHandler] - Initializing Fan handler for integration ID 3
2020-12-04 19:06:21.838 [DEBUG] [g.lutron.internal.handler.FanHandler] - Initializing device state for Fan 3
2020-12-04 19:06:21.839 [DEBUG] [g.lutron.internal.handler.FanHandler] - Initializing Fan handler for integration ID 2
2020-12-04 19:06:21.839 [DEBUG] [g.lutron.internal.handler.FanHandler] - Initializing device state for Fan 2
2020-12-04 19:06:21.839 [DEBUG] [g.lutron.internal.handler.FanHandler] - Initializing Fan handler for integration ID 4
2020-12-04 19:06:21.839 [DEBUG] [g.lutron.internal.handler.FanHandler] - Initializing device state for Fan 4
2020-12-04 19:06:21.840 [DEBUG] [utron.internal.handler.SwitchHandler] - Initializing Switch handler for integration ID 5
2020-12-04 19:06:21.840 [DEBUG] [n.internal.handler.BaseKeypadHandler] - Initializing Keypad Handler for integration ID 1
2020-12-04 19:06:21.840 [DEBUG] [utron.internal.handler.SwitchHandler] - Initializing device state for Switch 5
2020-12-04 19:06:21.842 [DEBUG] [g.lutron.internal.handler.FanHandler] - Initializing Fan handler for integration ID 9
2020-12-04 19:06:21.842 [DEBUG] [g.lutron.internal.handler.FanHandler] - Initializing device state for Fan 9
2020-12-04 19:06:21.842 [DEBUG] [utron.internal.handler.SwitchHandler] - Initializing Switch handler for integration ID 6
2020-12-04 19:06:21.842 [DEBUG] [utron.internal.handler.SwitchHandler] - Initializing device state for Switch 6
2020-12-04 19:06:21.843 [DEBUG] [n.internal.handler.BaseKeypadHandler] - Initializing Keypad Handler for integration ID 73
2020-12-04 19:06:21.844 [DEBUG] [n.internal.handler.BaseKeypadHandler] - Initializing Keypad Handler for integration ID 7
2020-12-04 19:06:21.844 [TRACE] [n.internal.handler.LeapBridgeHandler] - Registered child handler for ID 47
2020-12-04 19:06:21.844 [TRACE] [n.internal.handler.LeapBridgeHandler] - Registered child handler for ID 32
2020-12-04 19:06:21.844 [TRACE] [n.internal.handler.LeapBridgeHandler] - Registered child handler for ID 49
2020-12-04 19:06:21.844 [TRACE] [n.internal.handler.LeapBridgeHandler] - Registered child handler for ID 57
2020-12-04 19:06:21.844 [DEBUG] [g.lutron.internal.handler.FanHandler] - Initializing Fan handler for integration ID 10
2020-12-04 19:06:21.844 [DEBUG] [g.lutron.internal.handler.FanHandler] - Initializing device state for Fan 10
2020-12-04 19:06:21.844 [TRACE] [n.internal.handler.LeapBridgeHandler] - Registered child handler for ID 51
2020-12-04 19:06:21.844 [TRACE] [n.internal.handler.LeapBridgeHandler] - Registered child handler for ID 45
2020-12-04 19:06:21.844 [TRACE] [n.internal.handler.LeapBridgeHandler] - Registered child handler for ID 50
2020-12-04 19:06:21.844 [TRACE] [n.internal.handler.LeapBridgeHandler] - Registered child handler for ID 54
2020-12-04 19:06:21.844 [TRACE] [n.internal.handler.LeapBridgeHandler] - Registered child handler for ID 55
2020-12-04 19:06:21.844 [TRACE] [n.internal.handler.LeapBridgeHandler] - Registered child handler for ID 62
2020-12-04 19:06:21.844 [TRACE] [n.internal.handler.LeapBridgeHandler] - Registered child handler for ID 53
2020-12-04 19:06:21.844 [TRACE] [n.internal.handler.LeapBridgeHandler] - Registered child handler for ID 64
2020-12-04 19:06:21.844 [TRACE] [n.internal.handler.LeapBridgeHandler] - Registered child handler for ID 66
2020-12-04 19:06:21.845 [TRACE] [n.internal.handler.LeapBridgeHandler] - Registered child handler for ID 65
2020-12-04 19:06:21.845 [TRACE] [n.internal.handler.LeapBridgeHandler] - Registered child handler for ID 70
2020-12-04 19:06:21.845 [TRACE] [n.internal.handler.LeapBridgeHandler] - Registered child handler for ID 74
2020-12-04 19:06:21.845 [TRACE] [n.internal.handler.LeapBridgeHandler] - Registered child handler for ID 67
2020-12-04 19:06:21.845 [TRACE] [n.internal.handler.LeapBridgeHandler] - Registered child handler for ID 75
2020-12-04 19:06:21.845 [TRACE] [n.internal.handler.LeapBridgeHandler] - Registered child handler for ID 72
2020-12-04 19:06:21.845 [TRACE] [n.internal.handler.LeapBridgeHandler] - Registered child handler for ID 78
2020-12-04 19:06:21.845 [TRACE] [n.internal.handler.LeapBridgeHandler] - Registered child handler for ID 76
2020-12-04 19:06:21.845 [TRACE] [n.internal.handler.LeapBridgeHandler] - Registered child handler for ID 77
2020-12-04 19:06:21.845 [TRACE] [n.internal.handler.LeapBridgeHandler] - Registered child handler for ID 52
2020-12-04 19:06:21.845 [TRACE] [n.internal.handler.LeapBridgeHandler] - Registered child handler for ID 81
2020-12-04 19:06:21.845 [TRACE] [n.internal.handler.LeapBridgeHandler] - Registered child handler for ID 86
2020-12-04 19:06:21.845 [TRACE] [n.internal.handler.LeapBridgeHandler] - Registered child handler for ID 82
2020-12-04 19:06:21.845 [TRACE] [n.internal.handler.LeapBridgeHandler] - Registered child handler for ID 85
2020-12-04 19:06:21.845 [TRACE] [n.internal.handler.LeapBridgeHandler] - Registered child handler for ID 83
2020-12-04 19:06:21.845 [TRACE] [n.internal.handler.LeapBridgeHandler] - Registered child handler for ID 80
2020-12-04 19:06:21.845 [TRACE] [n.internal.handler.LeapBridgeHandler] - Registered child handler for ID 87
2020-12-04 19:06:21.845 [TRACE] [n.internal.handler.LeapBridgeHandler] - Registered group handler for ID 2
2020-12-04 19:06:21.845 [DEBUG] [g.lutron.internal.handler.FanHandler] - Initializing Fan handler for integration ID 11
2020-12-04 19:06:21.845 [TRACE] [n.internal.handler.LeapBridgeHandler] - Registered group handler for ID 6
2020-12-04 19:06:21.845 [DEBUG] [g.lutron.internal.handler.FanHandler] - Initializing device state for Fan 11
2020-12-04 19:06:21.845 [TRACE] [n.internal.handler.LeapBridgeHandler] - Registered group handler for ID 12
2020-12-04 19:06:21.845 [TRACE] [n.internal.handler.LeapBridgeHandler] - Registered group handler for ID 22
2020-12-04 19:06:21.845 [TRACE] [n.internal.handler.LeapBridgeHandler] - Registered child handler for ID 84
2020-12-04 19:06:21.845 [TRACE] [n.internal.handler.LeapBridgeHandler] - Registered group handler for ID 20
2020-12-04 19:06:21.845 [TRACE] [n.internal.handler.LeapBridgeHandler] - Registered group handler for ID 13
2020-12-04 19:06:21.845 [TRACE] [n.internal.handler.LeapBridgeHandler] - Registered group handler for ID 16
2020-12-04 19:06:21.845 [TRACE] [n.internal.handler.LeapBridgeHandler] - Registered child handler for ID 3
2020-12-04 19:06:21.845 [TRACE] [n.internal.handler.LeapBridgeHandler] - Registered child handler for ID 2
2020-12-04 19:06:21.845 [TRACE] [n.internal.handler.LeapBridgeHandler] - Registered child handler for ID 4
2020-12-04 19:06:21.845 [TRACE] [n.internal.handler.LeapBridgeHandler] - Registered child handler for ID 5
2020-12-04 19:06:21.845 [TRACE] [n.internal.handler.LeapBridgeHandler] - Registered child handler for ID 9
2020-12-04 19:06:21.845 [TRACE] [n.internal.handler.LeapBridgeHandler] - Registered child handler for ID 6
2020-12-04 19:06:21.845 [TRACE] [n.internal.handler.LeapBridgeHandler] - Registered child handler for ID 10
2020-12-04 19:06:21.845 [TRACE] [n.internal.handler.LeapBridgeHandler] - Registered child handler for ID 11
2020-12-04 19:06:21.846 [DEBUG] [n.internal.handler.BaseKeypadHandler] - Initializing Keypad Handler for integration ID 1
2020-12-04 19:06:21.846 [DEBUG] [n.internal.handler.BaseKeypadHandler] - Initializing Keypad Handler for integration ID 8

After bundle restart, all things did:
2020-12-04 19:06:21.524 [INFO ] [me.event.ThingStatusInfoChangedEvent] - Thing 'lutron:switch:bridge1:pantry' changed from OFFLINE (BRIDGE_OFFLINE) to UNINITIALIZED
2020-12-04 19:06:21.526 [INFO ] [me.event.ThingStatusInfoChangedEvent] - Thing 'lutron:switch:bridge1:pantry' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)

Touching the things file minutes later did:
2020-12-04 19:10:30.506 [INFO ] [me.event.ThingStatusInfoChangedEvent] - Thing 'lutron:switch:bridge1:pantry' changed from OFFLINE (BRIDGE_OFFLINE) to UNINITIALIZED
2020-12-04 19:10:30.507 [INFO ] [me.event.ThingStatusInfoChangedEvent] - Thing 'lutron:switch:bridge1:pantry' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)
2020-12-04 19:10:30.831 [INFO ] [me.event.ThingStatusInfoChangedEvent] - Thing 'lutron:switch:bridge1:pantry' changed from UNINITIALIZED to INITIALIZING
2020-12-04 19:10:30.833 [INFO ] [me.event.ThingStatusInfoChangedEvent] - Thing 'lutron:switch:bridge1:pantry' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE)

@bobadair
Copy link
Member

bobadair commented Dec 5, 2020

Do you see messages like these every 5 minutes in your log file? You should be seeing them as a result of the keepalive job running.

17:05:35.816 TRACE o.o.b.l.i.handler.LeapBridgeHandler:731 - Sending keepalive query
17:05:35.816 TRACE o.o.b.l.i.handler.LeapBridgeHandler:405 - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/server/1/status/ping"}}
17:05:35.832 TRACE o.o.b.l.i.p.leap.LeapMessageParser:76 - Received message: {"CommuniqueType":"ReadResponse","Header":{"MessageBodyType":"OnePingResponse","StatusCode":"200 OK","Url":"/server/1/status/ping"},"Body":{"PingResponse":{"LEAPVersion":1.113}}}
17:05:35.832 DEBUG o.o.b.l.i.p.leap.LeapMessageParser:88 - Received CommuniqueType: ReadResponse
17:05:35.832 TRACE o.o.b.l.i.handler.LeapBridgeHandler:747 - Canceling scheduled reconnect job.
17:05:35.832 TRACE o.o.b.l.i.p.leap.LeapMessageParser:169 - MessageBodyType: OnePingResponse
17:05:35.832 DEBUG o.o.b.l.i.p.leap.LeapMessageParser:253 - Ping response received

@morph166955
Copy link
Contributor Author

morph166955 commented Dec 6, 2020

I think I grepped this correctly for what you're looking for. This is everything from 1700 until 1959 from the event I just posted.

Notice this massive gap:

2020-12-04 17:48:58.453 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Ping response received
2020-12-04 19:16:34.349 [DEBUG] [n.internal.handler.LeapBridgeHandler] - Starting keepalive job with interval 5
$ grep -i "2020-12-04" lutron.log | grep -i " 17:\| 18:\| 19:" | grep -i "ping\|keepalive"
2020-12-04 17:03:56.326 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending keepalive query
2020-12-04 17:03:56.326 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/server/1/status/ping"}}
2020-12-04 17:03:56.329 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Received message: {"CommuniqueType":"ReadResponse","Header":{"MessageBodyType":"OnePingResponse","StatusCode":"200 OK","Url":"/server/1/status/ping"},"Body":{"PingResponse":{"LEAPVersion":1.113}}}
2020-12-04 17:03:56.329 [TRACE] [rnal.protocol.leap.LeapMessageParser] - MessageBodyType: OnePingResponse
2020-12-04 17:03:56.329 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Ping response received
2020-12-04 17:03:58.449 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending keepalive query
2020-12-04 17:03:58.449 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/server/1/status/ping"}}
2020-12-04 17:03:58.451 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Received message: {"CommuniqueType":"ReadResponse","Header":{"MessageBodyType":"OnePingResponse","StatusCode":"200 OK","Url":"/server/1/status/ping"},"Body":{"PingResponse":{"LEAPVersion":1.113}}}
2020-12-04 17:03:58.451 [TRACE] [rnal.protocol.leap.LeapMessageParser] - MessageBodyType: OnePingResponse
2020-12-04 17:03:58.451 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Ping response received
2020-12-04 17:08:56.326 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending keepalive query
2020-12-04 17:08:56.326 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/server/1/status/ping"}}
2020-12-04 17:08:56.329 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Received message: {"CommuniqueType":"ReadResponse","Header":{"MessageBodyType":"OnePingResponse","StatusCode":"200 OK","Url":"/server/1/status/ping"},"Body":{"PingResponse":{"LEAPVersion":1.113}}}
2020-12-04 17:08:56.329 [TRACE] [rnal.protocol.leap.LeapMessageParser] - MessageBodyType: OnePingResponse
2020-12-04 17:08:56.329 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Ping response received
2020-12-04 17:08:58.449 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending keepalive query
2020-12-04 17:08:58.449 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/server/1/status/ping"}}
2020-12-04 17:08:58.451 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Received message: {"CommuniqueType":"ReadResponse","Header":{"MessageBodyType":"OnePingResponse","StatusCode":"200 OK","Url":"/server/1/status/ping"},"Body":{"PingResponse":{"LEAPVersion":1.113}}}
2020-12-04 17:08:58.451 [TRACE] [rnal.protocol.leap.LeapMessageParser] - MessageBodyType: OnePingResponse
2020-12-04 17:08:58.451 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Ping response received
2020-12-04 17:13:56.326 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending keepalive query
2020-12-04 17:13:56.326 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/server/1/status/ping"}}
2020-12-04 17:13:56.329 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Received message: {"CommuniqueType":"ReadResponse","Header":{"MessageBodyType":"OnePingResponse","StatusCode":"200 OK","Url":"/server/1/status/ping"},"Body":{"PingResponse":{"LEAPVersion":1.113}}}
2020-12-04 17:13:56.329 [TRACE] [rnal.protocol.leap.LeapMessageParser] - MessageBodyType: OnePingResponse
2020-12-04 17:13:56.329 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Ping response received
2020-12-04 17:13:58.449 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending keepalive query
2020-12-04 17:13:58.450 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/server/1/status/ping"}}
2020-12-04 17:13:58.451 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Received message: {"CommuniqueType":"ReadResponse","Header":{"MessageBodyType":"OnePingResponse","StatusCode":"200 OK","Url":"/server/1/status/ping"},"Body":{"PingResponse":{"LEAPVersion":1.113}}}
2020-12-04 17:13:58.451 [TRACE] [rnal.protocol.leap.LeapMessageParser] - MessageBodyType: OnePingResponse
2020-12-04 17:13:58.451 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Ping response received
2020-12-04 17:18:56.327 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending keepalive query
2020-12-04 17:18:56.327 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/server/1/status/ping"}}
2020-12-04 17:18:56.329 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Received message: {"CommuniqueType":"ReadResponse","Header":{"MessageBodyType":"OnePingResponse","StatusCode":"200 OK","Url":"/server/1/status/ping"},"Body":{"PingResponse":{"LEAPVersion":1.113}}}
2020-12-04 17:18:56.329 [TRACE] [rnal.protocol.leap.LeapMessageParser] - MessageBodyType: OnePingResponse
2020-12-04 17:18:56.329 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Ping response received
2020-12-04 17:18:58.450 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending keepalive query
2020-12-04 17:18:58.450 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/server/1/status/ping"}}
2020-12-04 17:18:58.451 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Received message: {"CommuniqueType":"ReadResponse","Header":{"MessageBodyType":"OnePingResponse","StatusCode":"200 OK","Url":"/server/1/status/ping"},"Body":{"PingResponse":{"LEAPVersion":1.113}}}
2020-12-04 17:18:58.452 [TRACE] [rnal.protocol.leap.LeapMessageParser] - MessageBodyType: OnePingResponse
2020-12-04 17:18:58.452 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Ping response received
2020-12-04 17:23:56.327 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending keepalive query
2020-12-04 17:23:56.327 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/server/1/status/ping"}}
2020-12-04 17:23:56.329 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Received message: {"CommuniqueType":"ReadResponse","Header":{"MessageBodyType":"OnePingResponse","StatusCode":"200 OK","Url":"/server/1/status/ping"},"Body":{"PingResponse":{"LEAPVersion":1.113}}}
2020-12-04 17:23:56.330 [TRACE] [rnal.protocol.leap.LeapMessageParser] - MessageBodyType: OnePingResponse
2020-12-04 17:23:56.330 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Ping response received
2020-12-04 17:23:58.450 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending keepalive query
2020-12-04 17:23:58.450 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/server/1/status/ping"}}
2020-12-04 17:23:58.452 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Received message: {"CommuniqueType":"ReadResponse","Header":{"MessageBodyType":"OnePingResponse","StatusCode":"200 OK","Url":"/server/1/status/ping"},"Body":{"PingResponse":{"LEAPVersion":1.113}}}
2020-12-04 17:23:58.452 [TRACE] [rnal.protocol.leap.LeapMessageParser] - MessageBodyType: OnePingResponse
2020-12-04 17:23:58.452 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Ping response received
2020-12-04 17:28:56.327 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending keepalive query
2020-12-04 17:28:56.327 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/server/1/status/ping"}}
2020-12-04 17:28:56.330 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Received message: {"CommuniqueType":"ReadResponse","Header":{"MessageBodyType":"OnePingResponse","StatusCode":"200 OK","Url":"/server/1/status/ping"},"Body":{"PingResponse":{"LEAPVersion":1.113}}}
2020-12-04 17:28:56.330 [TRACE] [rnal.protocol.leap.LeapMessageParser] - MessageBodyType: OnePingResponse
2020-12-04 17:28:56.330 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Ping response received
2020-12-04 17:28:58.450 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending keepalive query
2020-12-04 17:28:58.450 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/server/1/status/ping"}}
2020-12-04 17:28:58.452 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Received message: {"CommuniqueType":"ReadResponse","Header":{"MessageBodyType":"OnePingResponse","StatusCode":"200 OK","Url":"/server/1/status/ping"},"Body":{"PingResponse":{"LEAPVersion":1.113}}}
2020-12-04 17:28:58.452 [TRACE] [rnal.protocol.leap.LeapMessageParser] - MessageBodyType: OnePingResponse
2020-12-04 17:28:58.452 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Ping response received
2020-12-04 17:33:56.327 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending keepalive query
2020-12-04 17:33:56.327 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/server/1/status/ping"}}
2020-12-04 17:33:56.330 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Received message: {"CommuniqueType":"ReadResponse","Header":{"MessageBodyType":"OnePingResponse","StatusCode":"200 OK","Url":"/server/1/status/ping"},"Body":{"PingResponse":{"LEAPVersion":1.113}}}
2020-12-04 17:33:56.330 [TRACE] [rnal.protocol.leap.LeapMessageParser] - MessageBodyType: OnePingResponse
2020-12-04 17:33:56.330 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Ping response received
2020-12-04 17:33:58.450 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending keepalive query
2020-12-04 17:33:58.451 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/server/1/status/ping"}}
2020-12-04 17:33:58.452 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Received message: {"CommuniqueType":"ReadResponse","Header":{"MessageBodyType":"OnePingResponse","StatusCode":"200 OK","Url":"/server/1/status/ping"},"Body":{"PingResponse":{"LEAPVersion":1.113}}}
2020-12-04 17:33:58.452 [TRACE] [rnal.protocol.leap.LeapMessageParser] - MessageBodyType: OnePingResponse
2020-12-04 17:33:58.452 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Ping response received
2020-12-04 17:38:56.327 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending keepalive query
2020-12-04 17:38:56.328 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/server/1/status/ping"}}
2020-12-04 17:38:56.330 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Received message: {"CommuniqueType":"ReadResponse","Header":{"MessageBodyType":"OnePingResponse","StatusCode":"200 OK","Url":"/server/1/status/ping"},"Body":{"PingResponse":{"LEAPVersion":1.113}}}
2020-12-04 17:38:56.330 [TRACE] [rnal.protocol.leap.LeapMessageParser] - MessageBodyType: OnePingResponse
2020-12-04 17:38:56.330 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Ping response received
2020-12-04 17:38:58.451 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending keepalive query
2020-12-04 17:38:58.451 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/server/1/status/ping"}}
2020-12-04 17:38:58.453 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Received message: {"CommuniqueType":"ReadResponse","Header":{"MessageBodyType":"OnePingResponse","StatusCode":"200 OK","Url":"/server/1/status/ping"},"Body":{"PingResponse":{"LEAPVersion":1.113}}}
2020-12-04 17:38:58.453 [TRACE] [rnal.protocol.leap.LeapMessageParser] - MessageBodyType: OnePingResponse
2020-12-04 17:38:58.453 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Ping response received
2020-12-04 17:43:56.328 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending keepalive query
2020-12-04 17:43:56.328 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/server/1/status/ping"}}
2020-12-04 17:43:56.330 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Received message: {"CommuniqueType":"ReadResponse","Header":{"MessageBodyType":"OnePingResponse","StatusCode":"200 OK","Url":"/server/1/status/ping"},"Body":{"PingResponse":{"LEAPVersion":1.113}}}
2020-12-04 17:43:56.330 [TRACE] [rnal.protocol.leap.LeapMessageParser] - MessageBodyType: OnePingResponse
2020-12-04 17:43:56.330 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Ping response received
2020-12-04 17:43:58.451 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending keepalive query
2020-12-04 17:43:58.451 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/server/1/status/ping"}}
2020-12-04 17:43:58.453 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Received message: {"CommuniqueType":"ReadResponse","Header":{"MessageBodyType":"OnePingResponse","StatusCode":"200 OK","Url":"/server/1/status/ping"},"Body":{"PingResponse":{"LEAPVersion":1.113}}}
2020-12-04 17:43:58.453 [TRACE] [rnal.protocol.leap.LeapMessageParser] - MessageBodyType: OnePingResponse
2020-12-04 17:43:58.453 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Ping response received
2020-12-04 17:48:56.328 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending keepalive query
2020-12-04 17:48:56.328 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/server/1/status/ping"}}
2020-12-04 17:48:56.330 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Received message: {"CommuniqueType":"ReadResponse","Header":{"MessageBodyType":"OnePingResponse","StatusCode":"200 OK","Url":"/server/1/status/ping"},"Body":{"PingResponse":{"LEAPVersion":1.113}}}
2020-12-04 17:48:56.330 [TRACE] [rnal.protocol.leap.LeapMessageParser] - MessageBodyType: OnePingResponse
2020-12-04 17:48:56.330 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Ping response received
2020-12-04 17:48:58.451 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending keepalive query
2020-12-04 17:48:58.451 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/server/1/status/ping"}}
2020-12-04 17:48:58.453 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Received message: {"CommuniqueType":"ReadResponse","Header":{"MessageBodyType":"OnePingResponse","StatusCode":"200 OK","Url":"/server/1/status/ping"},"Body":{"PingResponse":{"LEAPVersion":1.113}}}
2020-12-04 17:48:58.453 [TRACE] [rnal.protocol.leap.LeapMessageParser] - MessageBodyType: OnePingResponse
2020-12-04 17:48:58.453 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Ping response received
2020-12-04 19:16:34.349 [DEBUG] [n.internal.handler.LeapBridgeHandler] - Starting keepalive job with interval 5
2020-12-04 19:16:34.423 [DEBUG] [n.internal.handler.LeapBridgeHandler] - Starting keepalive job with interval 5
2020-12-04 19:21:34.349 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending keepalive query
2020-12-04 19:21:34.349 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/server/1/status/ping"}}
2020-12-04 19:21:34.351 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Received message: {"CommuniqueType":"ReadResponse","Header":{"MessageBodyType":"OnePingResponse","StatusCode":"200 OK","Url":"/server/1/status/ping"},"Body":{"PingResponse":{"LEAPVersion":1.113}}}
2020-12-04 19:21:34.351 [TRACE] [rnal.protocol.leap.LeapMessageParser] - MessageBodyType: OnePingResponse
2020-12-04 19:21:34.351 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Ping response received
2020-12-04 19:21:34.424 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending keepalive query
2020-12-04 19:21:34.424 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/server/1/status/ping"}}
2020-12-04 19:21:34.426 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Received message: {"CommuniqueType":"ReadResponse","Header":{"MessageBodyType":"OnePingResponse","StatusCode":"200 OK","Url":"/server/1/status/ping"},"Body":{"PingResponse":{"LEAPVersion":1.113}}}
2020-12-04 19:21:34.426 [TRACE] [rnal.protocol.leap.LeapMessageParser] - MessageBodyType: OnePingResponse
2020-12-04 19:21:34.426 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Ping response received
2020-12-04 19:26:34.349 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending keepalive query
2020-12-04 19:26:34.350 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/server/1/status/ping"}}
2020-12-04 19:26:34.351 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Received message: {"CommuniqueType":"ReadResponse","Header":{"MessageBodyType":"OnePingResponse","StatusCode":"200 OK","Url":"/server/1/status/ping"},"Body":{"PingResponse":{"LEAPVersion":1.113}}}
2020-12-04 19:26:34.352 [TRACE] [rnal.protocol.leap.LeapMessageParser] - MessageBodyType: OnePingResponse
2020-12-04 19:26:34.352 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Ping response received
2020-12-04 19:26:34.424 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending keepalive query
2020-12-04 19:26:34.424 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/server/1/status/ping"}}
2020-12-04 19:26:34.427 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Received message: {"CommuniqueType":"ReadResponse","Header":{"MessageBodyType":"OnePingResponse","StatusCode":"200 OK","Url":"/server/1/status/ping"},"Body":{"PingResponse":{"LEAPVersion":1.113}}}
2020-12-04 19:26:34.427 [TRACE] [rnal.protocol.leap.LeapMessageParser] - MessageBodyType: OnePingResponse
2020-12-04 19:26:34.427 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Ping response received
2020-12-04 19:31:34.350 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending keepalive query
2020-12-04 19:31:34.350 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/server/1/status/ping"}}
2020-12-04 19:31:34.352 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Received message: {"CommuniqueType":"ReadResponse","Header":{"MessageBodyType":"OnePingResponse","StatusCode":"200 OK","Url":"/server/1/status/ping"},"Body":{"PingResponse":{"LEAPVersion":1.113}}}
2020-12-04 19:31:34.352 [TRACE] [rnal.protocol.leap.LeapMessageParser] - MessageBodyType: OnePingResponse
2020-12-04 19:31:34.352 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Ping response received
2020-12-04 19:31:34.424 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending keepalive query
2020-12-04 19:31:34.424 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/server/1/status/ping"}}
2020-12-04 19:31:34.427 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Received message: {"CommuniqueType":"ReadResponse","Header":{"MessageBodyType":"OnePingResponse","StatusCode":"200 OK","Url":"/server/1/status/ping"},"Body":{"PingResponse":{"LEAPVersion":1.113}}}
2020-12-04 19:31:34.427 [TRACE] [rnal.protocol.leap.LeapMessageParser] - MessageBodyType: OnePingResponse
2020-12-04 19:31:34.427 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Ping response received
2020-12-04 19:36:34.350 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending keepalive query
2020-12-04 19:36:34.350 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/server/1/status/ping"}}
2020-12-04 19:36:34.352 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Received message: {"CommuniqueType":"ReadResponse","Header":{"MessageBodyType":"OnePingResponse","StatusCode":"200 OK","Url":"/server/1/status/ping"},"Body":{"PingResponse":{"LEAPVersion":1.113}}}
2020-12-04 19:36:34.352 [TRACE] [rnal.protocol.leap.LeapMessageParser] - MessageBodyType: OnePingResponse
2020-12-04 19:36:34.352 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Ping response received
2020-12-04 19:36:34.424 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending keepalive query
2020-12-04 19:36:34.424 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/server/1/status/ping"}}
2020-12-04 19:36:34.427 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Received message: {"CommuniqueType":"ReadResponse","Header":{"MessageBodyType":"OnePingResponse","StatusCode":"200 OK","Url":"/server/1/status/ping"},"Body":{"PingResponse":{"LEAPVersion":1.113}}}
2020-12-04 19:36:34.427 [TRACE] [rnal.protocol.leap.LeapMessageParser] - MessageBodyType: OnePingResponse
2020-12-04 19:36:34.427 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Ping response received
2020-12-04 19:41:34.350 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending keepalive query
2020-12-04 19:41:34.350 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/server/1/status/ping"}}
2020-12-04 19:41:34.352 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Received message: {"CommuniqueType":"ReadResponse","Header":{"MessageBodyType":"OnePingResponse","StatusCode":"200 OK","Url":"/server/1/status/ping"},"Body":{"PingResponse":{"LEAPVersion":1.113}}}
2020-12-04 19:41:34.352 [TRACE] [rnal.protocol.leap.LeapMessageParser] - MessageBodyType: OnePingResponse
2020-12-04 19:41:34.352 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Ping response received
2020-12-04 19:41:34.424 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending keepalive query
2020-12-04 19:41:34.425 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/server/1/status/ping"}}
2020-12-04 19:41:34.427 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Received message: {"CommuniqueType":"ReadResponse","Header":{"MessageBodyType":"OnePingResponse","StatusCode":"200 OK","Url":"/server/1/status/ping"},"Body":{"PingResponse":{"LEAPVersion":1.113}}}
2020-12-04 19:41:34.427 [TRACE] [rnal.protocol.leap.LeapMessageParser] - MessageBodyType: OnePingResponse
2020-12-04 19:41:34.427 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Ping response received
2020-12-04 19:46:34.350 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending keepalive query
2020-12-04 19:46:34.350 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/server/1/status/ping"}}
2020-12-04 19:46:34.352 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Received message: {"CommuniqueType":"ReadResponse","Header":{"MessageBodyType":"OnePingResponse","StatusCode":"200 OK","Url":"/server/1/status/ping"},"Body":{"PingResponse":{"LEAPVersion":1.113}}}
2020-12-04 19:46:34.352 [TRACE] [rnal.protocol.leap.LeapMessageParser] - MessageBodyType: OnePingResponse
2020-12-04 19:46:34.352 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Ping response received
2020-12-04 19:46:34.425 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending keepalive query
2020-12-04 19:46:34.425 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/server/1/status/ping"}}
2020-12-04 19:46:34.427 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Received message: {"CommuniqueType":"ReadResponse","Header":{"MessageBodyType":"OnePingResponse","StatusCode":"200 OK","Url":"/server/1/status/ping"},"Body":{"PingResponse":{"LEAPVersion":1.113}}}
2020-12-04 19:46:34.427 [TRACE] [rnal.protocol.leap.LeapMessageParser] - MessageBodyType: OnePingResponse
2020-12-04 19:46:34.427 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Ping response received
2020-12-04 19:51:34.350 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending keepalive query
2020-12-04 19:51:34.351 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/server/1/status/ping"}}
2020-12-04 19:51:34.352 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Received message: {"CommuniqueType":"ReadResponse","Header":{"MessageBodyType":"OnePingResponse","StatusCode":"200 OK","Url":"/server/1/status/ping"},"Body":{"PingResponse":{"LEAPVersion":1.113}}}
2020-12-04 19:51:34.352 [TRACE] [rnal.protocol.leap.LeapMessageParser] - MessageBodyType: OnePingResponse
2020-12-04 19:51:34.352 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Ping response received
2020-12-04 19:51:34.425 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending keepalive query
2020-12-04 19:51:34.425 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/server/1/status/ping"}}
2020-12-04 19:51:34.427 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Received message: {"CommuniqueType":"ReadResponse","Header":{"MessageBodyType":"OnePingResponse","StatusCode":"200 OK","Url":"/server/1/status/ping"},"Body":{"PingResponse":{"LEAPVersion":1.113}}}
2020-12-04 19:51:34.427 [TRACE] [rnal.protocol.leap.LeapMessageParser] - MessageBodyType: OnePingResponse
2020-12-04 19:51:34.427 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Ping response received
2020-12-04 19:56:34.351 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending keepalive query
2020-12-04 19:56:34.351 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/server/1/status/ping"}}
2020-12-04 19:56:34.353 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Received message: {"CommuniqueType":"ReadResponse","Header":{"MessageBodyType":"OnePingResponse","StatusCode":"200 OK","Url":"/server/1/status/ping"},"Body":{"PingResponse":{"LEAPVersion":1.113}}}
2020-12-04 19:56:34.353 [TRACE] [rnal.protocol.leap.LeapMessageParser] - MessageBodyType: OnePingResponse
2020-12-04 19:56:34.353 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Ping response received
2020-12-04 19:56:34.425 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending keepalive query
2020-12-04 19:56:34.425 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/server/1/status/ping"}}
2020-12-04 19:56:34.428 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Received message: {"CommuniqueType":"ReadResponse","Header":{"MessageBodyType":"OnePingResponse","StatusCode":"200 OK","Url":"/server/1/status/ping"},"Body":{"PingResponse":{"LEAPVersion":1.113}}}
2020-12-04 19:56:34.428 [TRACE] [rnal.protocol.leap.LeapMessageParser] - MessageBodyType: OnePingResponse
2020-12-04 19:56:34.428 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Ping response received

@bobadair
Copy link
Member

bobadair commented Dec 6, 2020

Matching the messages up by time, it looks like the keepalive job stopped running for both bridge things about 10 minutes before one connection was lost and 18 minutes before the other was lost. So the handlers would have been unable to restart the connections. Can you also grep for the "Canceling scheduled reconnect job" message and see what the last times were that it was logged?

Are you sure you're not having some sort of more general problem with the system like running out of threads in a pool or some other resource?

2020-12-04 17:48:56.328 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending keepalive query
2020-12-04 17:48:56.328 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/server/1/status/ping"}}
2020-12-04 17:48:56.330 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Received message: {"CommuniqueType":"ReadResponse","Header":{"MessageBodyType":"OnePingResponse","StatusCode":"200 OK","Url":"/server/1/status/ping"},"Body":{"PingResponse":{"LEAPVersion":1.113}}}
2020-12-04 17:48:56.330 [TRACE] [rnal.protocol.leap.LeapMessageParser] - MessageBodyType: OnePingResponse
2020-12-04 17:48:56.330 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Ping response received
2020-12-04 17:48:58.451 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending keepalive query
2020-12-04 17:48:58.451 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/server/1/status/ping"}}
2020-12-04 17:48:58.453 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Received message: {"CommuniqueType":"ReadResponse","Header":{"MessageBodyType":"OnePingResponse","StatusCode":"200 OK","Url":"/server/1/status/ping"},"Body":{"PingResponse":{"LEAPVersion":1.113}}}
2020-12-04 17:48:58.453 [TRACE] [rnal.protocol.leap.LeapMessageParser] - MessageBodyType: OnePingResponse
2020-12-04 17:48:58.453 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Ping response received

 2020-12-04 17:58:58.454 [DEBUG] [n.internal.handler.LeapBridgeHandler] - End of input stream detected
 2020-12-04 17:58:58.455 [DEBUG] [n.internal.handler.LeapBridgeHandler] - Message reader thread exiting

 2020-12-04 18:06:00.935 [DEBUG] [n.internal.handler.LeapBridgeHandler] - End of input stream detected
 2020-12-04 18:06:00.936 [DEBUG] [n.internal.handler.LeapBridgeHandler] - Message reader thread exiting

@morph166955
Copy link
Contributor Author

morph166955 commented Dec 6, 2020

Ignore previous. Was looking at the wrong file. Apparently my logs rolled.

2020-12-04 17:03:56.329 [TRACE] [n.internal.handler.LeapBridgeHandler] - Canceling scheduled reconnect job.
2020-12-04 17:03:58.451 [TRACE] [n.internal.handler.LeapBridgeHandler] - Canceling scheduled reconnect job.
2020-12-04 17:08:56.329 [TRACE] [n.internal.handler.LeapBridgeHandler] - Canceling scheduled reconnect job.
2020-12-04 17:08:58.451 [TRACE] [n.internal.handler.LeapBridgeHandler] - Canceling scheduled reconnect job.
2020-12-04 17:13:56.329 [TRACE] [n.internal.handler.LeapBridgeHandler] - Canceling scheduled reconnect job.
2020-12-04 17:13:58.451 [TRACE] [n.internal.handler.LeapBridgeHandler] - Canceling scheduled reconnect job.
2020-12-04 17:18:56.329 [TRACE] [n.internal.handler.LeapBridgeHandler] - Canceling scheduled reconnect job.
2020-12-04 17:18:58.452 [TRACE] [n.internal.handler.LeapBridgeHandler] - Canceling scheduled reconnect job.
2020-12-04 17:23:56.330 [TRACE] [n.internal.handler.LeapBridgeHandler] - Canceling scheduled reconnect job.
2020-12-04 17:23:58.452 [TRACE] [n.internal.handler.LeapBridgeHandler] - Canceling scheduled reconnect job.
2020-12-04 17:28:56.330 [TRACE] [n.internal.handler.LeapBridgeHandler] - Canceling scheduled reconnect job.
2020-12-04 17:28:58.452 [TRACE] [n.internal.handler.LeapBridgeHandler] - Canceling scheduled reconnect job.
2020-12-04 17:33:56.330 [TRACE] [n.internal.handler.LeapBridgeHandler] - Canceling scheduled reconnect job.
2020-12-04 17:33:58.452 [TRACE] [n.internal.handler.LeapBridgeHandler] - Canceling scheduled reconnect job.
2020-12-04 17:38:56.330 [TRACE] [n.internal.handler.LeapBridgeHandler] - Canceling scheduled reconnect job.
2020-12-04 17:38:58.453 [TRACE] [n.internal.handler.LeapBridgeHandler] - Canceling scheduled reconnect job.
2020-12-04 17:43:56.330 [TRACE] [n.internal.handler.LeapBridgeHandler] - Canceling scheduled reconnect job.
2020-12-04 17:43:58.453 [TRACE] [n.internal.handler.LeapBridgeHandler] - Canceling scheduled reconnect job.
2020-12-04 17:48:56.330 [TRACE] [n.internal.handler.LeapBridgeHandler] - Canceling scheduled reconnect job.
2020-12-04 17:48:58.453 [TRACE] [n.internal.handler.LeapBridgeHandler] - Canceling scheduled reconnect job.
2020-12-04 19:21:34.351 [TRACE] [n.internal.handler.LeapBridgeHandler] - Canceling scheduled reconnect job.
2020-12-04 19:21:34.426 [TRACE] [n.internal.handler.LeapBridgeHandler] - Canceling scheduled reconnect job.
2020-12-04 19:26:34.351 [TRACE] [n.internal.handler.LeapBridgeHandler] - Canceling scheduled reconnect job.
2020-12-04 19:26:34.427 [TRACE] [n.internal.handler.LeapBridgeHandler] - Canceling scheduled reconnect job.
2020-12-04 19:31:34.352 [TRACE] [n.internal.handler.LeapBridgeHandler] - Canceling scheduled reconnect job.
2020-12-04 19:31:34.427 [TRACE] [n.internal.handler.LeapBridgeHandler] - Canceling scheduled reconnect job.
2020-12-04 19:36:34.352 [TRACE] [n.internal.handler.LeapBridgeHandler] - Canceling scheduled reconnect job.
2020-12-04 19:36:34.427 [TRACE] [n.internal.handler.LeapBridgeHandler] - Canceling scheduled reconnect job.
2020-12-04 19:41:34.352 [TRACE] [n.internal.handler.LeapBridgeHandler] - Canceling scheduled reconnect job.
2020-12-04 19:41:34.427 [TRACE] [n.internal.handler.LeapBridgeHandler] - Canceling scheduled reconnect job.
2020-12-04 19:46:34.352 [TRACE] [n.internal.handler.LeapBridgeHandler] - Canceling scheduled reconnect job.
2020-12-04 19:46:34.427 [TRACE] [n.internal.handler.LeapBridgeHandler] - Canceling scheduled reconnect job.
2020-12-04 19:51:34.352 [TRACE] [n.internal.handler.LeapBridgeHandler] - Canceling scheduled reconnect job.
2020-12-04 19:51:34.427 [TRACE] [n.internal.handler.LeapBridgeHandler] - Canceling scheduled reconnect job.
2020-12-04 19:56:34.353 [TRACE] [n.internal.handler.LeapBridgeHandler] - Canceling scheduled reconnect job.
2020-12-04 19:56:34.428 [TRACE] [n.internal.handler.LeapBridgeHandler] - Canceling scheduled reconnect job.

I'm not tracking any thread issues right now. Just moved up to M5 and things have been pretty solid.

@bobadair
Copy link
Member

bobadair commented Dec 9, 2020

Ok. So the heartbeat logic was behaving as expected until it stopped running.

@bobadair
Copy link
Member

I've built a new OH3 version of the binding that includes some extra debug logging. This may help determine what is going wrong.

https://github.com/bobadair/openhab-addons/releases/tag/9178-1

@morph166955
Copy link
Contributor Author

I can probably drop this in tomorrow morning and just let it run until things break again.

@morph166955
Copy link
Contributor Author

My caseta just failed...

2020-12-13 13:06:01.405 [DEBUG] [n.internal.handler.LeapBridgeHandler] - End of input stream detected
2020-12-13 13:06:01.405 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 10
2020-12-13 13:06:01.405 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 40
2020-12-13 13:06:01.405 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 11
2020-12-13 13:06:01.405 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 39
2020-12-13 13:06:01.405 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 37
2020-12-13 13:06:01.406 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 16
2020-12-13 13:06:01.406 [DEBUG] [n.internal.handler.LeapBridgeHandler] - Message reader thread exiting
2020-12-13 13:06:01.406 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 34
2020-12-13 13:06:01.406 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 35
2020-12-13 13:06:01.406 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 41
2020-12-13 13:06:01.406 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 36
2020-12-13 13:06:01.407 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 23
2020-12-13 13:06:01.407 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 29
2020-12-13 13:06:01.407 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 30
2020-12-13 13:06:01.407 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 31
2020-12-13 13:06:01.407 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 32
2020-12-13 13:06:01.407 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 45
2020-12-13 13:06:01.407 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 57
2020-12-13 13:06:01.407 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 47
2020-12-13 13:06:01.407 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 49
2020-12-13 13:06:01.407 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 50
2020-12-13 13:06:01.407 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 51
2020-12-13 13:06:01.407 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 53
2020-12-13 13:06:01.407 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 54
2020-12-13 13:06:01.407 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 62
2020-12-13 13:06:01.407 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 64
2020-12-13 13:06:01.407 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 66
2020-12-13 13:06:01.407 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 67
2020-12-13 13:06:01.407 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 65
2020-12-13 13:06:01.407 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 70
2020-12-13 13:06:01.407 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 72
2020-12-13 13:06:01.407 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 74
2020-12-13 13:06:01.407 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 75
2020-12-13 13:06:01.407 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 77
2020-12-13 13:06:01.407 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 76
2020-12-13 13:06:01.407 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 78
2020-12-13 13:06:01.407 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 84
2020-12-13 13:06:01.407 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 86
2020-12-13 13:06:01.407 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 85
2020-12-13 13:06:01.407 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 55
2020-12-13 13:06:01.407 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 80
2020-12-13 13:06:01.407 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 82
2020-12-13 13:06:01.407 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 83
2020-12-13 13:06:01.407 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 87
2020-12-13 13:06:01.407 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 2
2020-12-13 13:06:01.407 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 6
2020-12-13 13:06:01.408 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 12
2020-12-13 13:06:01.408 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 13
2020-12-13 13:06:01.408 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 16
2020-12-13 13:06:01.408 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 20
2020-12-13 13:06:01.408 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 22
2020-12-13 13:06:01.408 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 60
2020-12-13 13:06:01.408 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 19
2020-12-13 13:06:01.408 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 43
2020-12-13 13:06:01.408 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 68
2020-12-13 13:06:01.408 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 69
2020-12-13 13:06:01.408 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 71
2020-12-13 13:06:01.408 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 79
2020-12-13 13:06:01.408 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 33
2020-12-13 13:06:01.408 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 73
2020-12-13 13:06:01.408 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 1
2020-12-13 13:06:01.408 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 52
2020-12-13 13:06:01.407 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 81
2020-12-13 13:06:01.408 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 42

@morph166955
Copy link
Contributor Author

Both bridges died this time. I let them sit for almost 45 minutes before I restarted OH

2020-12-13 21:14:07.250 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Received CommuniqueType: ReadResponse
2020-12-13 21:14:07.250 [TRACE] [rnal.protocol.leap.LeapMessageParser] - MessageBodyType: OneZoneStatus
2020-12-13 21:14:07.250 [TRACE] [n.internal.handler.LeapBridgeHandler] - Zone: 53 level: 100
2020-12-13 21:14:07.250 [TRACE] [n.internal.handler.LeapBridgeHandler] - Zone 53 mapped to device id 70
2020-12-13 21:18:04.835 [DEBUG] [n.internal.handler.LeapBridgeHandler] - End of input stream detected
2020-12-13 21:18:04.836 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 11
2020-12-13 21:18:04.836 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 40
2020-12-13 21:18:04.836 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 39
2020-12-13 21:18:04.836 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 37
2020-12-13 21:18:04.836 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 10
2020-12-13 21:18:04.837 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 16
2020-12-13 21:18:04.837 [DEBUG] [n.internal.handler.LeapBridgeHandler] - Message reader thread exiting
2020-12-13 21:18:04.837 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 35
2020-12-13 21:18:04.837 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 41
2020-12-13 21:18:04.837 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 36
2020-12-13 21:18:04.837 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 23
2020-12-13 21:18:04.837 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 29
2020-12-13 21:18:04.837 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 30
2020-12-13 21:18:04.837 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 31
2020-12-13 21:18:04.837 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 32
2020-12-13 21:18:04.837 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 45
2020-12-13 21:18:04.837 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 57
2020-12-13 21:18:04.837 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 47
2020-12-13 21:18:04.838 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 49
2020-12-13 21:18:04.838 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 50
2020-12-13 21:18:04.838 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 51
2020-12-13 21:18:04.838 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 52
2020-12-13 21:18:04.838 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 53
2020-12-13 21:18:04.838 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 54
2020-12-13 21:18:04.838 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 55
2020-12-13 21:18:04.838 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 62
2020-12-13 21:18:04.838 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 64
2020-12-13 21:18:04.838 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 66
2020-12-13 21:18:04.838 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 67
2020-12-13 21:18:04.838 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 65
2020-12-13 21:18:04.838 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 70
2020-12-13 21:18:04.838 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 72
2020-12-13 21:18:04.838 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 74
2020-12-13 21:18:04.838 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 75
2020-12-13 21:18:04.838 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 77
2020-12-13 21:18:04.838 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 76
2020-12-13 21:18:04.838 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 78
2020-12-13 21:18:04.838 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 84
2020-12-13 21:18:04.838 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 85
2020-12-13 21:18:04.838 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 86
2020-12-13 21:18:04.838 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 81
2020-12-13 21:18:04.838 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 80
2020-12-13 21:18:04.838 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 82
2020-12-13 21:18:04.838 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 83
2020-12-13 21:18:04.838 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 87
2020-12-13 21:18:04.838 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 2
2020-12-13 21:18:04.838 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 6
2020-12-13 21:18:04.838 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 12
2020-12-13 21:18:04.838 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 13
2020-12-13 21:18:04.838 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 16
2020-12-13 21:18:04.838 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 20
2020-12-13 21:18:04.838 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 22
2020-12-13 21:18:04.838 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 19
2020-12-13 21:18:04.838 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 33
2020-12-13 21:18:04.838 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 42
2020-12-13 21:18:04.838 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 43
2020-12-13 21:18:04.838 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 60
2020-12-13 21:18:04.838 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 68
2020-12-13 21:18:04.838 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 69
2020-12-13 21:18:04.838 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 71
2020-12-13 21:18:04.838 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 73
2020-12-13 21:18:04.839 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 79
2020-12-13 21:18:04.839 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 1
2020-12-13 21:18:04.839 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 34
2020-12-13 21:18:05.052 [DEBUG] [n.internal.handler.LeapBridgeHandler] - End of input stream detected
2020-12-13 21:18:05.052 [DEBUG] [n.internal.handler.LeapBridgeHandler] - Message reader thread exiting
2020-12-13 21:18:05.052 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 2
2020-12-13 21:18:05.052 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 3
2020-12-13 21:18:05.052 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 4
2020-12-13 21:18:05.052 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 5
2020-12-13 21:18:05.052 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 6
2020-12-13 21:18:05.052 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 9
2020-12-13 21:18:05.052 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 11
2020-12-13 21:18:05.052 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 7
2020-12-13 21:18:05.052 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 8
2020-12-13 21:18:05.052 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 1
2020-12-13 21:18:05.052 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 10
2020-12-13 21:29:17.154 [DEBUG] [ry.LutronMcastBridgeDiscoveryService] - Scanning for Lutron bridge devices using multicast
2020-12-13 21:29:20.156 [TRACE] [ry.LutronMcastBridgeDiscoveryService] - Timed out waiting for multicast response. Presumably all bridge devices have already responded.
2020-12-13 21:59:20.157 [DEBUG] [ry.LutronMcastBridgeDiscoveryService] - Scanning for Lutron bridge devices using multicast
2020-12-13 21:59:23.157 [TRACE] [ry.LutronMcastBridgeDiscoveryService] - Timed out waiting for multicast response. Presumably all bridge devices have already responded.

@bobadair
Copy link
Member

bobadair commented Dec 16, 2020

So it doesn't look like the handler is shutting the connection down, or you would see it with the new debug messages. It seems it is being killed by something external. When is the last time the keepalive job (the one that logs "Sending keepalive query") runs before the connections are lost?

@morph166955
Copy link
Contributor Author

I just noticed when upgrading to RC1 and then S2086 that the "stock" binding also loaded. I'm not 100% sure if that happened above with those logs. I've got the bindings squared away so let's see what happens next time this happens.

@morph166955
Copy link
Contributor Author

Apparently that didn't take very long. The logs at the end are me shutting OH down for a restart. I clipped everything that wasn't a zone doing something.

$grep -iv zone /var/log/openhab/lutron.log
2020-12-18 15:26:19.304 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending keepalive query
2020-12-18 15:26:19.304 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/server/1/status/ping"}}
2020-12-18 15:26:19.307 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Received message: {"CommuniqueType":"ReadResponse","Header":{"MessageBodyType":"OnePingResponse","StatusCode":"200 OK","Url":"/server/1/status/ping"},"Body":{"PingResponse":{"LEAPVersion":1.113}}}
2020-12-18 15:26:19.307 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Received CommuniqueType: ReadResponse
2020-12-18 15:26:19.307 [TRACE] [n.internal.handler.LeapBridgeHandler] - Canceling scheduled reconnect job.
2020-12-18 15:26:19.307 [TRACE] [rnal.protocol.leap.LeapMessageParser] - MessageBodyType: OnePingResponse
2020-12-18 15:26:19.307 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Ping response received
2020-12-18 15:26:19.321 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending keepalive query
2020-12-18 15:26:19.321 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/server/1/status/ping"}}
2020-12-18 15:26:19.323 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Received message: {"CommuniqueType":"ReadResponse","Header":{"MessageBodyType":"OnePingResponse","StatusCode":"200 OK","Url":"/server/1/status/ping"},"Body":{"PingResponse":{"LEAPVersion":1.113}}}
2020-12-18 15:26:19.323 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Received CommuniqueType: ReadResponse
2020-12-18 15:26:19.323 [TRACE] [n.internal.handler.LeapBridgeHandler] - Canceling scheduled reconnect job.
2020-12-18 15:26:19.323 [TRACE] [rnal.protocol.leap.LeapMessageParser] - MessageBodyType: OnePingResponse
2020-12-18 15:26:19.323 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Ping response received
2020-12-18 15:26:34.852 [TRACE] [n.internal.handler.LeapBridgeHandler] - Received request to send Lutron command: #OUTPUT,10,1,0,0.25
2020-12-18 15:26:34.855 [TRACE] [n.internal.handler.LeapBridgeHandler] - Received request to send Lutron command: #OUTPUT,11,1,0,0.25
2020-12-18 15:26:34.857 [TRACE] [n.internal.handler.LeapBridgeHandler] - Received request to send Lutron command: #OUTPUT,67,1,0
2020-12-18 15:26:34.870 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Received CommuniqueType: ReadResponse
2020-12-18 15:26:34.879 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Received CommuniqueType: CreateResponse
2020-12-18 15:26:34.985 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Received CommuniqueType: CreateResponse
2020-12-18 15:26:34.989 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Received CommuniqueType: ReadResponse
2020-12-18 15:26:35.076 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Received CommuniqueType: CreateResponse
2020-12-18 15:26:35.083 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Received CommuniqueType: ReadResponse
2020-12-18 15:27:18.960 [DEBUG] [ry.LutronMcastBridgeDiscoveryService] - Scanning for Lutron bridge devices using multicast
2020-12-18 15:27:21.962 [TRACE] [ry.LutronMcastBridgeDiscoveryService] - Timed out waiting for multicast response. Presumably all bridge devices have already responded.
2020-12-18 15:28:35.014 [TRACE] [n.internal.handler.LeapBridgeHandler] - Received request to send Lutron command: #OUTPUT,10,1,0,0.25
2020-12-18 15:28:35.015 [TRACE] [n.internal.handler.LeapBridgeHandler] - Received request to send Lutron command: #OUTPUT,11,1,0,0.25
2020-12-18 15:28:35.017 [TRACE] [n.internal.handler.LeapBridgeHandler] - Received request to send Lutron command: #OUTPUT,67,1,0
2020-12-18 15:28:35.033 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Received CommuniqueType: ReadResponse
2020-12-18 15:28:35.040 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Received CommuniqueType: CreateResponse
2020-12-18 15:28:35.145 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Received CommuniqueType: ReadResponse
2020-12-18 15:28:35.147 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Received CommuniqueType: CreateResponse
2020-12-18 15:28:35.231 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Received CommuniqueType: ReadResponse
2020-12-18 15:28:35.236 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Received CommuniqueType: CreateResponse
2020-12-18 15:30:35.200 [TRACE] [n.internal.handler.LeapBridgeHandler] - Received request to send Lutron command: #OUTPUT,10,1,0,0.25
2020-12-18 15:30:35.201 [TRACE] [n.internal.handler.LeapBridgeHandler] - Received request to send Lutron command: #OUTPUT,11,1,0,0.25
2020-12-18 15:30:35.202 [TRACE] [n.internal.handler.LeapBridgeHandler] - Received request to send Lutron command: #OUTPUT,67,1,0
2020-12-18 15:30:35.230 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Received CommuniqueType: CreateResponse
2020-12-18 15:30:35.237 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Received CommuniqueType: ReadResponse
2020-12-18 15:30:35.328 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Received CommuniqueType: ReadResponse
2020-12-18 15:30:35.334 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Received CommuniqueType: CreateResponse
2020-12-18 15:30:35.419 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Received CommuniqueType: ReadResponse
2020-12-18 15:30:35.426 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Received CommuniqueType: CreateResponse
2020-12-18 15:31:19.304 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending keepalive query
2020-12-18 15:31:19.304 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/server/1/status/ping"}}
2020-12-18 15:31:19.307 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Received message: {"CommuniqueType":"ReadResponse","Header":{"MessageBodyType":"OnePingResponse","StatusCode":"200 OK","Url":"/server/1/status/ping"},"Body":{"PingResponse":{"LEAPVersion":1.113}}}
2020-12-18 15:31:19.307 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Received CommuniqueType: ReadResponse
2020-12-18 15:31:19.307 [TRACE] [n.internal.handler.LeapBridgeHandler] - Canceling scheduled reconnect job.
2020-12-18 15:31:19.307 [TRACE] [rnal.protocol.leap.LeapMessageParser] - MessageBodyType: OnePingResponse
2020-12-18 15:31:19.307 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Ping response received
2020-12-18 15:31:19.321 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending keepalive query
2020-12-18 15:31:19.321 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/server/1/status/ping"}}
2020-12-18 15:31:19.323 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Received message: {"CommuniqueType":"ReadResponse","Header":{"MessageBodyType":"OnePingResponse","StatusCode":"200 OK","Url":"/server/1/status/ping"},"Body":{"PingResponse":{"LEAPVersion":1.113}}}
2020-12-18 15:31:19.323 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Received CommuniqueType: ReadResponse
2020-12-18 15:31:19.323 [TRACE] [n.internal.handler.LeapBridgeHandler] - Canceling scheduled reconnect job.
2020-12-18 15:31:19.323 [TRACE] [rnal.protocol.leap.LeapMessageParser] - MessageBodyType: OnePingResponse
2020-12-18 15:31:19.323 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Ping response received
2020-12-18 15:32:35.371 [TRACE] [n.internal.handler.LeapBridgeHandler] - Received request to send Lutron command: #OUTPUT,10,1,0,0.25
2020-12-18 15:32:35.371 [TRACE] [n.internal.handler.LeapBridgeHandler] - Received request to send Lutron command: #OUTPUT,11,1,0,0.25
2020-12-18 15:32:35.373 [TRACE] [n.internal.handler.LeapBridgeHandler] - Received request to send Lutron command: #OUTPUT,67,1,0
2020-12-18 15:32:35.399 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Received CommuniqueType: ReadResponse
2020-12-18 15:32:35.403 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Received CommuniqueType: CreateResponse
2020-12-18 15:32:35.498 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Received CommuniqueType: ReadResponse
2020-12-18 15:32:35.502 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Received CommuniqueType: CreateResponse
2020-12-18 15:32:35.601 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Received CommuniqueType: ReadResponse
2020-12-18 15:32:35.604 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Received CommuniqueType: CreateResponse
2020-12-18 15:41:19.325 [DEBUG] [n.internal.handler.LeapBridgeHandler] - End of input stream detected
2020-12-18 15:41:19.326 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 2
2020-12-18 15:41:19.326 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 3
2020-12-18 15:41:19.327 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 5
2020-12-18 15:41:19.327 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 4
2020-12-18 15:41:19.327 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 6
2020-12-18 15:41:19.328 [DEBUG] [n.internal.handler.LeapBridgeHandler] - Message reader thread exiting
2020-12-18 15:41:19.328 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 9
2020-12-18 15:41:19.328 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 10
2020-12-18 15:41:19.328 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 11
2020-12-18 15:41:19.328 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 7
2020-12-18 15:41:19.329 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 8
2020-12-18 15:41:19.329 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 1
2020-12-18 15:42:35.607 [DEBUG] [n.internal.handler.LeapBridgeHandler] - End of input stream detected
2020-12-18 15:42:35.608 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 10
2020-12-18 15:42:35.608 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 11
2020-12-18 15:42:35.608 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 39
2020-12-18 15:42:35.608 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 40
2020-12-18 15:42:35.629 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 37
2020-12-18 15:42:35.631 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 34
2020-12-18 15:42:35.631 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 41
2020-12-18 15:42:35.631 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 36
2020-12-18 15:42:35.631 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 23
2020-12-18 15:42:35.631 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 29
2020-12-18 15:42:35.631 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 30
2020-12-18 15:42:35.631 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 31
2020-12-18 15:42:35.631 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 32
2020-12-18 15:42:35.631 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 45
2020-12-18 15:42:35.631 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 16
2020-12-18 15:42:35.631 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 47
2020-12-18 15:42:35.631 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 57
2020-12-18 15:42:35.631 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 49
2020-12-18 15:42:35.631 [DEBUG] [n.internal.handler.LeapBridgeHandler] - Message reader thread exiting
2020-12-18 15:42:35.631 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 50
2020-12-18 15:42:35.631 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 51
2020-12-18 15:42:35.631 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 52
2020-12-18 15:42:35.631 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 53
2020-12-18 15:42:35.631 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 55
2020-12-18 15:42:35.631 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 54
2020-12-18 15:42:35.631 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 62
2020-12-18 15:42:35.631 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 64
2020-12-18 15:42:35.631 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 66
2020-12-18 15:42:35.631 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 67
2020-12-18 15:42:35.631 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 65
2020-12-18 15:42:35.631 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 72
2020-12-18 15:42:35.631 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 70
2020-12-18 15:42:35.631 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 74
2020-12-18 15:42:35.631 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 75
2020-12-18 15:42:35.631 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 77
2020-12-18 15:42:35.631 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 76
2020-12-18 15:42:35.631 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 78
2020-12-18 15:42:35.631 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 84
2020-12-18 15:42:35.631 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 85
2020-12-18 15:42:35.631 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 86
2020-12-18 15:42:35.631 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 81
2020-12-18 15:42:35.631 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 80
2020-12-18 15:42:35.631 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 82
2020-12-18 15:42:35.631 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 83
2020-12-18 15:42:35.631 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 87
2020-12-18 15:42:35.631 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 2
2020-12-18 15:42:35.631 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 6
2020-12-18 15:42:35.631 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 12
2020-12-18 15:42:35.631 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 13
2020-12-18 15:42:35.631 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 20
2020-12-18 15:42:35.631 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 22
2020-12-18 15:42:35.631 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 19
2020-12-18 15:42:35.631 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 33
2020-12-18 15:42:35.632 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 42
2020-12-18 15:42:35.632 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 60
2020-12-18 15:42:35.632 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 43
2020-12-18 15:42:35.632 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 68
2020-12-18 15:42:35.632 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 69
2020-12-18 15:42:35.632 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 71
2020-12-18 15:42:35.632 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 16
2020-12-18 15:42:35.632 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 73
2020-12-18 15:42:35.632 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 79
2020-12-18 15:42:35.632 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 1
2020-12-18 15:42:35.631 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 35
2020-12-18 15:49:04.818 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 50
2020-12-18 15:49:04.820 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 19
2020-12-18 15:49:04.822 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 68
2020-12-18 15:49:04.829 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 10
2020-12-18 15:49:04.835 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 30
2020-12-18 15:49:04.839 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 66
2020-12-18 15:49:04.840 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 2
2020-12-18 15:49:04.843 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 37
2020-12-18 15:49:04.845 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 76
2020-12-18 15:49:04.848 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 64
2020-12-18 15:49:04.850 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 43
2020-12-18 15:49:04.851 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 1
2020-12-18 15:49:04.853 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 32
2020-12-18 15:49:04.855 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 31
2020-12-18 15:49:04.858 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 11
2020-12-18 15:49:04.861 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 33
2020-12-18 15:49:04.863 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 49
2020-12-18 15:49:04.865 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 4
2020-12-18 15:49:04.867 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 77
2020-12-18 15:49:04.869 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 62
2020-12-18 15:49:04.871 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 54
2020-12-18 15:49:04.873 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 47
2020-12-18 15:49:04.875 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 78
2020-12-18 15:49:04.877 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 73
2020-12-18 15:49:04.879 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered group handler for ID 20
2020-12-18 15:49:04.881 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 41
2020-12-18 15:49:04.884 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 8
2020-12-18 15:49:04.886 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 9
2020-12-18 15:49:04.888 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 6
2020-12-18 15:49:04.890 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 16
2020-12-18 15:49:04.891 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 57
2020-12-18 15:49:04.893 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 87
2020-12-18 15:49:04.895 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered group handler for ID 6
2020-12-18 15:49:04.897 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 7
2020-12-18 15:49:04.899 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 11
2020-12-18 15:49:04.902 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 36
2020-12-18 15:49:04.904 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 82
2020-12-18 15:49:04.906 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 52
2020-12-18 15:49:04.908 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 10
2020-12-18 15:49:04.910 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 53
2020-12-18 15:49:04.912 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 29
2020-12-18 15:49:04.915 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 71
2020-12-18 15:49:04.916 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 40
2020-12-18 15:49:04.919 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered group handler for ID 13
2020-12-18 15:49:04.921 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 69
2020-12-18 15:49:04.923 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 65
2020-12-18 15:49:04.925 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 55
2020-12-18 15:49:04.927 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered group handler for ID 12
2020-12-18 15:49:04.928 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered group handler for ID 22
2020-12-18 15:49:04.930 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 75
2020-12-18 15:49:04.932 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 74
2020-12-18 15:49:04.934 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 3
2020-12-18 15:49:04.937 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 39
2020-12-18 15:49:04.940 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 34
2020-12-18 15:49:04.944 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 35
2020-12-18 15:49:04.947 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 23
2020-12-18 15:49:04.951 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 45
2020-12-18 15:49:04.954 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 51
2020-12-18 15:49:04.956 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 67
2020-12-18 15:49:04.958 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 70
2020-12-18 15:49:04.959 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 72
2020-12-18 15:49:04.962 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 84
2020-12-18 15:49:04.964 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 85
2020-12-18 15:49:04.966 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 86
2020-12-18 15:49:04.968 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 81
2020-12-18 15:49:04.972 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 80
2020-12-18 15:49:04.975 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 83
2020-12-18 15:49:04.977 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered group handler for ID 2
2020-12-18 15:49:04.979 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered group handler for ID 16
2020-12-18 15:49:04.981 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 42
2020-12-18 15:49:04.982 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 60
2020-12-18 15:49:04.985 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 79
2020-12-18 15:49:04.988 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 1
2020-12-18 15:49:04.991 [DEBUG] [n.internal.handler.LeapBridgeHandler] - Disconnecting
2020-12-18 15:49:04.992 [DEBUG] [n.internal.handler.LeapBridgeHandler] - Command sender thread exiting
2020-12-18 15:49:04.995 [TRACE] [n.internal.handler.LeapBridgeHandler] - Unregistered child handler for ID 5
2020-12-18 15:49:04.999 [DEBUG] [n.internal.handler.LeapBridgeHandler] - Disconnecting
2020-12-18 15:49:04.999 [DEBUG] [n.internal.handler.LeapBridgeHandler] - Command sender thread exiting

@bobadair
Copy link
Member

It seems suspicious to me that the connection closes exactly 10 minutes after the last keepalive query. I thought I saw that in a previous log, also. Can you post all of the log messages from the binding from 2020-12-18 15:31:19 until the line:
2020-12-18 15:41:19.325 [DEBUG] [n.internal.handler.LeapBridgeHandler] - End of input stream detected

@morph166955
Copy link
Contributor Author

Here ya go

2020-12-18 15:30:35.419 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Received CommuniqueType: ReadResponse
2020-12-18 15:30:35.419 [TRACE] [rnal.protocol.leap.LeapMessageParser] - MessageBodyType: OneZoneStatus
2020-12-18 15:30:35.419 [TRACE] [n.internal.handler.LeapBridgeHandler] - Zone: 52 level: 0
2020-12-18 15:30:35.419 [TRACE] [n.internal.handler.LeapBridgeHandler] - Zone 52 mapped to device id 67
2020-12-18 15:30:35.426 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Received message: {"CommuniqueType":"CreateResponse","Header":{"MessageBodyType":"OneZoneStatus","StatusCode":"201 Created","Url":"/zone/
52/commandprocessor"},"Body":{"ZoneStatus":{"href":"/zone/52/status","Level":0,"SwitchedLevel":"Off","Zone":{"href":"/zone/52"}}}}
2020-12-18 15:30:35.426 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Received CommuniqueType: CreateResponse
2020-12-18 15:31:19.304 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending keepalive query
2020-12-18 15:31:19.304 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/server/1/status/ping"}}
2020-12-18 15:31:19.307 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Received message: {"CommuniqueType":"ReadResponse","Header":{"MessageBodyType":"OnePingResponse","StatusCode":"200 OK","Url":"/server/1/s
tatus/ping"},"Body":{"PingResponse":{"LEAPVersion":1.113}}}
2020-12-18 15:31:19.307 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Received CommuniqueType: ReadResponse
2020-12-18 15:31:19.307 [TRACE] [n.internal.handler.LeapBridgeHandler] - Canceling scheduled reconnect job.
2020-12-18 15:31:19.307 [TRACE] [rnal.protocol.leap.LeapMessageParser] - MessageBodyType: OnePingResponse
2020-12-18 15:31:19.307 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Ping response received
2020-12-18 15:31:19.321 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending keepalive query
2020-12-18 15:31:19.321 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/server/1/status/ping"}}
2020-12-18 15:31:19.323 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Received message: {"CommuniqueType":"ReadResponse","Header":{"MessageBodyType":"OnePingResponse","StatusCode":"200 OK","Url":"/server/1/s
tatus/ping"},"Body":{"PingResponse":{"LEAPVersion":1.113}}}
2020-12-18 15:31:19.323 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Received CommuniqueType: ReadResponse
2020-12-18 15:31:19.323 [TRACE] [n.internal.handler.LeapBridgeHandler] - Canceling scheduled reconnect job.
2020-12-18 15:31:19.323 [TRACE] [rnal.protocol.leap.LeapMessageParser] - MessageBodyType: OnePingResponse
2020-12-18 15:31:19.323 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Ping response received
2020-12-18 15:32:35.371 [TRACE] [n.internal.handler.LeapBridgeHandler] - Received request to send Lutron command: #OUTPUT,10,1,0,0.25
2020-12-18 15:32:35.371 [TRACE] [n.internal.handler.LeapBridgeHandler] - Received request to send Lutron command: #OUTPUT,11,1,0,0.25
2020-12-18 15:32:35.371 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "CreateRequest","Header": {"Url": "/zone/7/commandprocessor"},"Body": {"Command": {"CommandType": "GoT
oDimmedLevel","DimmedLevelParameters": {"Level": 0, "FadeTime": "00:00:01", "DelayTime": "00:00:00"}}}}
2020-12-18 15:32:35.373 [TRACE] [n.internal.handler.LeapBridgeHandler] - Received request to send Lutron command: #OUTPUT,67,1,0
2020-12-18 15:32:35.399 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Received message: {"CommuniqueType":"ReadResponse","Header":{"MessageBodyType":"OneZoneStatus","StatusCode":"200 OK","Url":"/zone/7/statu
s/level"},"Body":{"ZoneStatus":{"href":"/zone/7/status","Level":0,"Zone":{"href":"/zone/7"},"StatusAccuracy":"Good"}}}
2020-12-18 15:32:35.399 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Received CommuniqueType: ReadResponse
2020-12-18 15:32:35.399 [TRACE] [rnal.protocol.leap.LeapMessageParser] - MessageBodyType: OneZoneStatus
2020-12-18 15:32:35.399 [TRACE] [n.internal.handler.LeapBridgeHandler] - Zone: 7 level: 0
2020-12-18 15:32:35.399 [TRACE] [n.internal.handler.LeapBridgeHandler] - Zone 7 mapped to device id 10
2020-12-18 15:32:35.403 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Received message: {"CommuniqueType":"CreateResponse","Header":{"MessageBodyType":"OneZoneStatus","StatusCode":"201 Created","Url":"/zone/
7/commandprocessor"},"Body":{"ZoneStatus":{"href":"/zone/7/status","Level":0,"Zone":{"href":"/zone/7"}}}}
2020-12-18 15:32:35.403 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Received CommuniqueType: CreateResponse
2020-12-18 15:32:35.471 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "CreateRequest","Header": {"Url": "/zone/8/commandprocessor"},"Body": {"Command": {"CommandType": "GoT
oDimmedLevel","DimmedLevelParameters": {"Level": 0, "FadeTime": "00:00:01", "DelayTime": "00:00:00"}}}}
2020-12-18 15:32:35.498 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Received message: {"CommuniqueType":"ReadResponse","Header":{"MessageBodyType":"OneZoneStatus","StatusCode":"200 OK","Url":"/zone/8/statu
s/level"},"Body":{"ZoneStatus":{"href":"/zone/8/status","Level":0,"Zone":{"href":"/zone/8"},"StatusAccuracy":"Good"}}}
2020-12-18 15:32:35.498 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Received CommuniqueType: ReadResponse
2020-12-18 15:32:35.498 [TRACE] [rnal.protocol.leap.LeapMessageParser] - MessageBodyType: OneZoneStatus
2020-12-18 15:32:35.498 [TRACE] [n.internal.handler.LeapBridgeHandler] - Zone: 8 level: 0
2020-12-18 15:32:35.498 [TRACE] [n.internal.handler.LeapBridgeHandler] - Zone 8 mapped to device id 11
2020-12-18 15:32:35.502 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Received message: {"CommuniqueType":"CreateResponse","Header":{"MessageBodyType":"OneZoneStatus","StatusCode":"201 Created","Url":"/zone/
8/commandprocessor"},"Body":{"ZoneStatus":{"href":"/zone/8/status","Level":0,"Zone":{"href":"/zone/8"}}}}
2020-12-18 15:32:35.502 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Received CommuniqueType: CreateResponse
2020-12-18 15:32:35.572 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "CreateRequest","Header": {"Url": "/zone/52/commandprocessor"},"Body": {"Command": {"CommandType": "Go
ToLevel","Parameter": [{"Type": "Level", "Value": 0}]}}}
2020-12-18 15:32:35.601 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Received message: {"CommuniqueType":"ReadResponse","Header":{"MessageBodyType":"OneZoneStatus","StatusCode":"200 OK","Url":"/zone/52/stat
us/level"},"Body":{"ZoneStatus":{"href":"/zone/52/status","Level":0,"SwitchedLevel":"Off","Zone":{"href":"/zone/52"},"StatusAccuracy":"Good"}}}
2020-12-18 15:32:35.601 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Received CommuniqueType: ReadResponse
2020-12-18 15:32:35.601 [TRACE] [rnal.protocol.leap.LeapMessageParser] - MessageBodyType: OneZoneStatus
2020-12-18 15:32:35.601 [TRACE] [n.internal.handler.LeapBridgeHandler] - Zone: 52 level: 0
2020-12-18 15:32:35.601 [TRACE] [n.internal.handler.LeapBridgeHandler] - Zone 52 mapped to device id 67
2020-12-18 15:32:35.604 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Received message: {"CommuniqueType":"CreateResponse","Header":{"MessageBodyType":"OneZoneStatus","StatusCode":"201 Created","Url":"/zone/
52/commandprocessor"},"Body":{"ZoneStatus":{"href":"/zone/52/status","Level":0,"SwitchedLevel":"Off","Zone":{"href":"/zone/52"}}}}
2020-12-18 15:32:35.604 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Received CommuniqueType: CreateResponse
2020-12-18 15:41:19.325 [DEBUG] [n.internal.handler.LeapBridgeHandler] - End of input stream detected
2020-12-18 15:41:19.326 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 2
2020-12-18 15:41:19.326 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 3
2020-12-18 15:41:19.327 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 5
2020-12-18 15:41:19.327 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 4
2020-12-18 15:41:19.327 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 6
2020-12-18 15:41:19.328 [DEBUG] [n.internal.handler.LeapBridgeHandler] - Message reader thread exiting
2020-12-18 15:41:19.328 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 9
2020-12-18 15:41:19.328 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 10
2020-12-18 15:41:19.328 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 11
2020-12-18 15:41:19.328 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 7
2020-12-18 15:41:19.329 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 8
2020-12-18 15:41:19.329 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 1
2020-12-18 15:42:35.607 [DEBUG] [n.internal.handler.LeapBridgeHandler] - End of input stream detected
2020-12-18 15:42:35.608 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 10
2020-12-18 15:42:35.608 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 11
2020-12-18 15:42:35.608 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 39
2020-12-18 15:42:35.608 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 40
2020-12-18 15:42:35.629 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 37
2020-12-18 15:42:35.631 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 34
2020-12-18 15:42:35.631 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 41
2020-12-18 15:42:35.631 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 36
2020-12-18 15:42:35.631 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 23
2020-12-18 15:42:35.631 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 29
2020-12-18 15:42:35.631 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 30
2020-12-18 15:42:35.631 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 31
2020-12-18 15:42:35.631 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 32

@morph166955
Copy link
Contributor Author

Here's an odd one. Bridge went offline. 20 minutes later something triggered the bridge to send a command to one of my lights (which it shouldn't have done with the bridge offline). That caused some kind of reconnect however the bridge was effectively unresponsive. Despite showing as online, I couldn't send any commands. In the end it kept trying to send "#OUTPUT,72,1,0,0.25"

2020-12-19 18:38:49.755 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 79
2020-12-19 18:54:39.248 [TRACE] [n.internal.handler.LeapBridgeHandler] - Received request to send Lutron command: #OUTPUT,72,1,50,0.25
2020-12-19 18:54:39.249 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "CreateRequest","Header": {"Url": "/zone/54/commandprocessor"},"Body": {"Command": {"CommandType": "Go
ToDimmedLevel","DimmedLevelParameters": {"Level": 50, "FadeTime": "00:00:01", "DelayTime": "00:00:00"}}}}
2020-12-19 18:54:39.249 [WARN ] [n.internal.handler.LeapBridgeHandler] - Communication error, will try to reconnect. Error: Connection or outbound has closed
2020-12-19 18:54:39.249 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 10
2020-12-19 18:54:39.249 [DEBUG] [n.internal.handler.LeapBridgeHandler] - Attempting to reconnect to the bridge
2020-12-19 18:54:39.249 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 39
2020-12-19 18:54:39.250 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 29
2020-12-19 18:54:39.250 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 23
2020-12-19 18:54:39.250 [DEBUG] [n.internal.handler.LeapBridgeHandler] - Disconnecting
2020-12-19 18:54:39.250 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 41
2020-12-19 18:54:39.250 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 30
...
2020-12-19 18:54:39.255 [DEBUG] [n.internal.handler.LeapBridgeHandler] - Opening SSL connection to REDACTED:8081
2020-12-19 18:54:39.255 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 72
2020-12-19 18:54:39.423 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 40
2020-12-19 18:54:39.423 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 39
2020-12-19 18:54:39.424 [DEBUG] [n.internal.handler.LeapBridgeHandler] - Starting keepalive job with interval 5
2020-12-19 18:54:39.424 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 37
2020-12-19 18:54:39.424 [DEBUG] [n.internal.handler.LeapBridgeHandler] - Command sender thread exiting
2020-12-19 18:54:39.424 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 16
2020-12-19 18:54:39.424 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 34
2020-12-19 18:54:39.424 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 35
2020-12-19 18:54:39.424 [DEBUG] [n.internal.handler.LeapBridgeHandler] - Command sender thread started
2020-12-19 18:54:39.424 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 41
2020-12-19 18:54:39.424 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 36
2020-12-19 18:54:39.424 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 23
2020-12-19 18:54:39.424 [DEBUG] [n.internal.handler.LeapBridgeHandler] - Message reader thread started
2020-12-19 18:54:39.424 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 29
2020-12-19 18:54:39.424 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "CreateRequest","Header": {"Url": "/zone/54/commandprocessor"},"Body": {"Command": {"CommandType": "Go
ToDimmedLevel","DimmedLevelParameters": {"Level": 50, "FadeTime": "00:00:01", "DelayTime": "00:00:00"}}}}
2020-12-19 18:54:39.426 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 30
2020-12-19 18:54:39.426 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 32
2020-12-19 18:54:39.426 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 45
2020-12-19 18:54:39.426 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to OFFLINE for lutron device handler 47
...
2020-12-19 18:54:39.428 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Received message: {"CommuniqueType":"SubscribeResponse","Header":{"StatusCode":"204 NoContent","Url":"/device/status/deviceheard"}}
2020-12-19 18:54:39.429 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Received CommuniqueType: SubscribeResponse
2020-12-19 18:54:39.429 [TRACE] [rnal.protocol.leap.LeapMessageParser] - No MessageBodyType in header
2020-12-19 18:54:39.446 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Received message: {"CommuniqueType":"CreateResponse","Header":{"MessageBodyType":"OneZoneStatus","StatusCode":"201 Created","Url":"/zone/
54/commandprocessor"},"Body":{"ZoneStatus":{"href":"/zone/54/status","Level":50,"Zone":{"href":"/zone/54"}}}}
2020-12-19 18:54:39.446 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Received CommuniqueType: CreateResponse
2020-12-19 18:54:39.448 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Received message: {"CommuniqueType":"SubscribeResponse","Header":{"StatusCode":"204 NoContent","Url":"/zone/status/deprecated/level"}}
2020-12-19 18:54:39.448 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Received CommuniqueType: SubscribeResponse
2020-12-19 18:54:39.448 [TRACE] [rnal.protocol.leap.LeapMessageParser] - No MessageBodyType in header
2020-12-19 18:54:39.453 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Received message: {"CommuniqueType":"ReadResponse","Header":{"MessageBodyType":"OneZoneStatus","StatusCode":"200 OK","Url":"/zone/54/stat
us/level"},"Body":{"ZoneStatus":{"href":"/zone/54/status","Level":50,"Zone":{"href":"/zone/54"},"StatusAccuracy":"Good"}}}
2020-12-19 18:54:39.453 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Received CommuniqueType: ReadResponse
2020-12-19 18:54:39.453 [TRACE] [rnal.protocol.leap.LeapMessageParser] - MessageBodyType: OneZoneStatus
2020-12-19 18:54:39.453 [TRACE] [n.internal.handler.LeapBridgeHandler] - Zone: 54 level: 50
2020-12-19 18:54:39.453 [TRACE] [n.internal.handler.LeapBridgeHandler] - Zone 54 mapped to device id 72
2020-12-19 18:54:39.527 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/buttongroup"}}
2020-12-19 18:54:39.624 [TRACE] [rnal.protocol.leap.LeapMessageParser] - Received message: {"CommuniqueType":"ReadResponse","Header":{"MessageBodyType":"MultipleButtonGroupDefinition","StatusCode":"200 OK","Url
":"/buttongroup"},"Body":{"ButtonGroups":[{"href":"/buttongroup/9","Buttons":[{"href":"/button/117"},{"href":"/button/118"}],"AffectedZones":[{"href":"/buttongroup/9/affectedzone/67","Zone":{"href":"/zone/67"}}
2020-12-19 18:54:39.624 [DEBUG] [rnal.protocol.leap.LeapMessageParser] - Received CommuniqueType: ReadResponse
2020-12-19 18:54:39.624 [TRACE] [rnal.protocol.leap.LeapMessageParser] - MessageBodyType: MultipleButtonGroupDefinition
2020-12-19 18:54:39.624 [TRACE] [n.internal.handler.LeapBridgeHandler] - Found ButtonGroup: 9 parent device: 33
2020-12-19 18:54:39.624 [TRACE] [n.internal.handler.LeapBridgeHandler] - Found ButtonGroup: 10 parent device: 42
2020-12-19 18:54:39.624 [TRACE] [n.internal.handler.LeapBridgeHandler] - Found ButtonGroup: 14 parent device: 60
2020-12-19 18:54:39.624 [TRACE] [n.internal.handler.LeapBridgeHandler] - Found ButtonGroup: 16 parent device: 68
2020-12-19 18:54:39.624 [TRACE] [n.internal.handler.LeapBridgeHandler] - Found ButtonGroup: 18 parent device: 71
2020-12-19 18:54:39.624 [TRACE] [n.internal.handler.LeapBridgeHandler] - Found ButtonGroup: 19 parent device: 73
2020-12-19 18:54:39.625 [TRACE] [n.internal.handler.LeapBridgeHandler] - Found ButtonGroup: 5 parent device: 19
2020-12-19 18:54:39.625 [TRACE] [n.internal.handler.LeapBridgeHandler] - Found ButtonGroup: 11 parent device: 43
2020-12-19 18:54:39.625 [TRACE] [n.internal.handler.LeapBridgeHandler] - Found ButtonGroup: 17 parent device: 69
2020-12-19 18:54:39.625 [TRACE] [n.internal.handler.LeapBridgeHandler] - Found ButtonGroup: 20 parent device: 79
2020-12-19 18:54:39.627 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/device"}}
2020-12-19 18:54:39.727 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/area"}}
2020-12-19 18:54:39.828 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/occupancygroup"}}
2020-12-19 18:54:39.841 [DEBUG] [utron.internal.handler.OGroupHandler] - Initializing device state for Occupancy Group 22
2020-12-19 18:54:39.841 [TRACE] [n.internal.handler.LeapBridgeHandler] - Received request to send Lutron command: ?GROUP,22,3
2020-12-19 18:54:39.841 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to ONLINE for lutron device handler 19
2020-12-19 18:54:39.841 [DEBUG] [n.internal.handler.BaseKeypadHandler] - Initializing device state for Keypad 19
2020-12-19 18:54:39.841 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to ONLINE for lutron device handler 33
2020-12-19 18:54:39.841 [DEBUG] [n.internal.handler.BaseKeypadHandler] - Initializing device state for Keypad 33
2020-12-19 18:54:39.841 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to ONLINE for lutron device handler 42
2020-12-19 18:54:39.841 [DEBUG] [n.internal.handler.BaseKeypadHandler] - Initializing device state for Keypad 42
2020-12-19 18:54:39.841 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to ONLINE for lutron device handler 43
2020-12-19 18:54:39.841 [DEBUG] [n.internal.handler.BaseKeypadHandler] - Initializing device state for Keypad 43
2020-12-19 18:54:39.841 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to ONLINE for lutron device handler 60
2020-12-19 18:54:39.841 [DEBUG] [n.internal.handler.BaseKeypadHandler] - Initializing device state for Keypad 60
2020-12-19 18:54:39.841 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to ONLINE for lutron device handler 68
2020-12-19 18:54:39.841 [DEBUG] [n.internal.handler.BaseKeypadHandler] - Initializing device state for Keypad 68
2020-12-19 18:54:39.841 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to ONLINE for lutron device handler 69
2020-12-19 18:54:39.841 [DEBUG] [n.internal.handler.BaseKeypadHandler] - Initializing device state for Keypad 69
2020-12-19 18:54:39.841 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to ONLINE for lutron device handler 71
2020-12-19 18:54:39.841 [DEBUG] [n.internal.handler.BaseKeypadHandler] - Initializing device state for Keypad 71
2020-12-19 18:54:39.841 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to ONLINE for lutron device handler 73
2020-12-19 18:54:39.841 [DEBUG] [n.internal.handler.BaseKeypadHandler] - Initializing device state for Keypad 73
2020-12-19 18:54:39.841 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to ONLINE for lutron device handler 79
2020-12-19 18:54:39.841 [DEBUG] [n.internal.handler.BaseKeypadHandler] - Initializing device state for Keypad 79
2020-12-19 18:54:39.841 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to ONLINE for lutron device handler 1
2020-12-19 18:54:39.841 [DEBUG] [n.internal.handler.BaseKeypadHandler] - Initializing device state for Keypad 1
2020-12-19 18:54:39.837 [DEBUG] [utron.internal.handler.DimmerHandler] - Initializing device state for Dimmer 11
2020-12-19 18:54:39.838 [DEBUG] [utron.internal.handler.LutronHandler] - Bridge status changed to ONLINE for lutron device handler 34
2020-12-19 18:54:39.837 [DEBUG] [utron.internal.handler.DimmerHandler] - Initializing device state for Dimmer 39
2020-12-19 18:54:39.841 [TRACE] [n.internal.handler.LeapBridgeHandler] - Received request to send Lutron command: ?OUTPUT,11,1
2020-12-19 18:54:39.841 [DEBUG] [utron.internal.handler.DimmerHandler] - Initializing device state for Dimmer 34
2020-12-19 18:54:39.841 [TRACE] [n.internal.handler.LeapBridgeHandler] - Received request to send Lutron command: ?OUTPUT,39,1
2020-12-19 18:54:39.838 [TRACE] [n.internal.handler.LeapBridgeHandler] - Received request to send Lutron command: ?OUTPUT,37,1
2020-12-19 18:54:39.841 [TRACE] [n.internal.handler.LeapBridgeHandler] - Received request to send Lutron command: ?OUTPUT,34,1
2020-12-19 18:54:39.928 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "SubscribeRequest","Header": {"Url": "/occupancygroup/status"}}
2020-12-19 18:54:40.028 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/zone/7/status"}}
2020-12-19 18:54:40.128 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/zone/31/status"}}
2020-12-19 18:54:40.229 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/zone/12/status"}}
2020-12-19 18:54:40.329 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/zone/26/status"}}
2020-12-19 18:54:40.429 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/zone/32/status"}}
2020-12-19 18:54:40.529 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/zone/27/status"}}
2020-12-19 18:54:40.629 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/zone/17/status"}}
2020-12-19 18:54:40.730 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/zone/21/status"}}
2020-12-19 18:54:40.830 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/zone/22/status"}}
2020-12-19 18:54:40.930 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/zone/23/status"}}
2020-12-19 18:54:41.030 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/zone/24/status"}}
2020-12-19 18:54:41.130 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/zone/33/status"}}
2020-12-19 18:54:41.231 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/zone/44/status"}}
2020-12-19 18:54:41.331 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/zone/35/status"}}
2020-12-19 18:54:41.431 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/zone/36/status"}}
2020-12-19 18:54:41.531 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/zone/37/status"}}
2020-12-19 18:54:41.631 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/zone/38/status"}}
2020-12-19 18:54:41.732 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/zone/39/status"}}
2020-12-19 18:54:41.832 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/zone/40/status"}}
2020-12-19 18:54:41.932 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/zone/41/status"}}
2020-12-19 18:54:42.032 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/zone/42/status"}}
2020-12-19 18:54:42.132 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/zone/47/status"}}
2020-12-19 18:54:42.233 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/zone/49/status"}}
2020-12-19 18:54:42.333 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/zone/51/status"}}
2020-12-19 18:54:42.433 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/zone/52/status"}}
2020-12-19 18:54:42.533 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/zone/50/status"}}
2020-12-19 18:54:42.633 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/zone/53/status"}}
2020-12-19 18:54:42.734 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/zone/54/status"}}
2020-12-19 18:54:42.834 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/zone/55/status"}}
2020-12-19 18:54:42.934 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/zone/56/status"}}
2020-12-19 18:54:43.034 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/zone/58/status"}}
2020-12-19 18:54:43.135 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/zone/57/status"}}
2020-12-19 18:54:43.235 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/zone/59/status"}}
2020-12-19 18:54:43.335 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/zone/64/status"}}
2020-12-19 18:54:43.435 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/zone/65/status"}}
2020-12-19 18:54:43.535 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/zone/66/status"}}
2020-12-19 18:54:43.636 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/zone/61/status"}}
2020-12-19 18:54:43.736 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/zone/60/status"}}
2020-12-19 18:54:43.836 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/zone/62/status"}}
2020-12-19 18:54:43.936 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/zone/63/status"}}
2020-12-19 18:54:44.037 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/zone/67/status"}}
2020-12-19 18:54:44.137 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/occupancygroup/status"}}
2020-12-19 18:54:44.237 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/occupancygroup/status"}}
2020-12-19 18:54:44.337 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/occupancygroup/status"}}
2020-12-19 18:54:44.437 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/occupancygroup/status"}}
2020-12-19 18:54:44.538 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/occupancygroup/status"}}
2020-12-19 18:54:44.638 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/occupancygroup/status"}}
2020-12-19 18:54:44.738 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/occupancygroup/status"}}
2020-12-19 18:54:44.838 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/zone/8/status"}}
2020-12-19 18:54:44.939 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/zone/30/status"}}
2020-12-19 18:54:45.039 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/zone/28/status"}}
2020-12-19 18:54:45.139 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "ReadRequest","Header": {"Url": "/zone/25/status"}}
...
2020-12-19 18:55:31.132 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "CreateRequest","Header": {"Url": "/zone/54/commandprocessor"},"Body": {"Command": {"CommandType": "Go
ToDimmedLevel","DimmedLevelParameters": {"Level": 50, "FadeTime": "00:00:01", "DelayTime": "00:00:00"}}}}
2020-12-19 18:56:02.872 [TRACE] [n.internal.handler.LeapBridgeHandler] - Received request to send Lutron command: #OUTPUT,72,1,50,0.25
2020-12-19 18:56:02.872 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "CreateRequest","Header": {"Url": "/zone/54/commandprocessor"},"Body": {"Command": {"CommandType": "Go
ToDimmedLevel","DimmedLevelParameters": {"Level": 50, "FadeTime": "00:00:01", "DelayTime": "00:00:00"}}}}
2020-12-19 18:58:00.890 [TRACE] [n.internal.handler.LeapBridgeHandler] - Received request to send Lutron command: #OUTPUT,72,1,0,0.25
2020-12-19 18:58:00.890 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "CreateRequest","Header": {"Url": "/zone/54/commandprocessor"},"Body": {"Command": {"CommandType": "Go
ToDimmedLevel","DimmedLevelParameters": {"Level": 0, "FadeTime": "00:00:01", "DelayTime": "00:00:00"}}}}
2020-12-19 18:58:01.889 [TRACE] [n.internal.handler.LeapBridgeHandler] - Received request to send Lutron command: #OUTPUT,72,1,0,0.25
2020-12-19 18:58:01.889 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "CreateRequest","Header": {"Url": "/zone/54/commandprocessor"},"Body": {"Command": {"CommandType": "Go
ToDimmedLevel","DimmedLevelParameters": {"Level": 0, "FadeTime": "00:00:01", "DelayTime": "00:00:00"}}}}
2020-12-19 18:58:02.888 [TRACE] [n.internal.handler.LeapBridgeHandler] - Received request to send Lutron command: #OUTPUT,72,1,0,0.25
2020-12-19 18:58:02.889 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "CreateRequest","Header": {"Url": "/zone/54/commandprocessor"},"Body": {"Command": {"CommandType": "Go
ToDimmedLevel","DimmedLevelParameters": {"Level": 0, "FadeTime": "00:00:01", "DelayTime": "00:00:00"}}}}
2020-12-19 18:58:03.889 [TRACE] [n.internal.handler.LeapBridgeHandler] - Received request to send Lutron command: #OUTPUT,72,1,0,0.25
2020-12-19 18:58:03.889 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "CreateRequest","Header": {"Url": "/zone/54/commandprocessor"},"Body": {"Command": {"CommandType": "Go
ToDimmedLevel","DimmedLevelParameters": {"Level": 0, "FadeTime": "00:00:01", "DelayTime": "00:00:00"}}}}
2020-12-19 18:58:04.889 [TRACE] [n.internal.handler.LeapBridgeHandler] - Received request to send Lutron command: #OUTPUT,72,1,0,0.25
2020-12-19 18:58:04.889 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "CreateRequest","Header": {"Url": "/zone/54/commandprocessor"},"Body": {"Command": {"CommandType": "Go
ToDimmedLevel","DimmedLevelParameters": {"Level": 0, "FadeTime": "00:00:01", "DelayTime": "00:00:00"}}}}
2020-12-19 18:58:05.891 [TRACE] [n.internal.handler.LeapBridgeHandler] - Received request to send Lutron command: #OUTPUT,72,1,0,0.25
2020-12-19 18:58:05.891 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "CreateRequest","Header": {"Url": "/zone/54/commandprocessor"},"Body": {"Command": {"CommandType": "Go
ToDimmedLevel","DimmedLevelParameters": {"Level": 0, "FadeTime": "00:00:01", "DelayTime": "00:00:00"}}}}
2020-12-19 18:58:06.891 [TRACE] [n.internal.handler.LeapBridgeHandler] - Received request to send Lutron command: #OUTPUT,72,1,0,0.25
2020-12-19 18:58:06.891 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "CreateRequest","Header": {"Url": "/zone/54/commandprocessor"},"Body": {"Command": {"CommandType": "Go
ToDimmedLevel","DimmedLevelParameters": {"Level": 0, "FadeTime": "00:00:01", "DelayTime": "00:00:00"}}}}
2020-12-19 18:58:07.891 [TRACE] [n.internal.handler.LeapBridgeHandler] - Received request to send Lutron command: #OUTPUT,72,1,0,0.25
2020-12-19 18:58:07.891 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "CreateRequest","Header": {"Url": "/zone/54/commandprocessor"},"Body": {"Command": {"CommandType": "Go
ToDimmedLevel","DimmedLevelParameters": {"Level": 0, "FadeTime": "00:00:01", "DelayTime": "00:00:00"}}}}
2020-12-19 18:58:08.889 [TRACE] [n.internal.handler.LeapBridgeHandler] - Received request to send Lutron command: #OUTPUT,72,1,0,0.25
2020-12-19 18:58:08.889 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "CreateRequest","Header": {"Url": "/zone/54/commandprocessor"},"Body": {"Command": {"CommandType": "Go
ToDimmedLevel","DimmedLevelParameters": {"Level": 0, "FadeTime": "00:00:01", "DelayTime": "00:00:00"}}}}
2020-12-19 18:58:09.889 [TRACE] [n.internal.handler.LeapBridgeHandler] - Received request to send Lutron command: #OUTPUT,72,1,0,0.25
2020-12-19 18:58:09.889 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "CreateRequest","Header": {"Url": "/zone/54/commandprocessor"},"Body": {"Command": {"CommandType": "Go
ToDimmedLevel","DimmedLevelParameters": {"Level": 0, "FadeTime": "00:00:01", "DelayTime": "00:00:00"}}}}
2020-12-19 18:58:10.889 [TRACE] [n.internal.handler.LeapBridgeHandler] - Received request to send Lutron command: #OUTPUT,72,1,0,0.25
2020-12-19 18:58:10.889 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "CreateRequest","Header": {"Url": "/zone/54/commandprocessor"},"Body": {"Command": {"CommandType": "Go
ToDimmedLevel","DimmedLevelParameters": {"Level": 0, "FadeTime": "00:00:01", "DelayTime": "00:00:00"}}}}
2020-12-19 18:58:11.889 [TRACE] [n.internal.handler.LeapBridgeHandler] - Received request to send Lutron command: #OUTPUT,72,1,0,0.25
2020-12-19 18:58:11.889 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "CreateRequest","Header": {"Url": "/zone/54/commandprocessor"},"Body": {"Command": {"CommandType": "Go
ToDimmedLevel","DimmedLevelParameters": {"Level": 0, "FadeTime": "00:00:01", "DelayTime": "00:00:00"}}}}
2020-12-19 18:58:12.890 [TRACE] [n.internal.handler.LeapBridgeHandler] - Received request to send Lutron command: #OUTPUT,72,1,0,0.25
2020-12-19 18:58:12.890 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "CreateRequest","Header": {"Url": "/zone/54/commandprocessor"},"Body": {"Command": {"CommandType": "Go
ToDimmedLevel","DimmedLevelParameters": {"Level": 0, "FadeTime": "00:00:01", "DelayTime": "00:00:00"}}}}
2020-12-19 18:58:13.890 [TRACE] [n.internal.handler.LeapBridgeHandler] - Received request to send Lutron command: #OUTPUT,72,1,0,0.25
2020-12-19 18:58:13.890 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "CreateRequest","Header": {"Url": "/zone/54/commandprocessor"},"Body": {"Command": {"CommandType": "Go
ToDimmedLevel","DimmedLevelParameters": {"Level": 0, "FadeTime": "00:00:01", "DelayTime": "00:00:00"}}}}
2020-12-19 18:58:14.890 [TRACE] [n.internal.handler.LeapBridgeHandler] - Received request to send Lutron command: #OUTPUT,72,1,0,0.25
2020-12-19 18:58:14.890 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "CreateRequest","Header": {"Url": "/zone/54/commandprocessor"},"Body": {"Command": {"CommandType": "Go
ToDimmedLevel","DimmedLevelParameters": {"Level": 0, "FadeTime": "00:00:01", "DelayTime": "00:00:00"}}}}
2020-12-19 18:58:15.890 [TRACE] [n.internal.handler.LeapBridgeHandler] - Received request to send Lutron command: #OUTPUT,72,1,0,0.25
2020-12-19 18:58:15.890 [TRACE] [n.internal.handler.LeapBridgeHandler] - Sending command {"CommuniqueType": "CreateRequest","Header": {"Url": "/zone/54/commandprocessor"},"Body": {"Command": {"CommandType": "Go

@morph166955
Copy link
Contributor Author

As a test, to see if this is the leap code or the move to OH3, I've added IP bridges for my two bridges in parallel to the LEAP bridges. Let's see if one goes offline and the other doesn't.

@morph166955
Copy link
Contributor Author

So I'm starting to wonder if you were right about the thread exhaustion question a while ago on this. My bridges went offline again this morning. Oddly enough, my ecobee binding also broke at almost the same time and didn't come back. Also at the same time, the rule that I have which runs periodic speedtests (every 15 minutes) stopped working. Given that the threading system was changed in OH3, we may need to look there.

@bobadair
Copy link
Member

I was just reading through 1998. It sounds like that could be the issue. I hope it is, because I'm starting to run out of things to check in the Lutron binding. :-)

@morph166955
Copy link
Contributor Author

Yeah I'd say hold until that Samsung binding is fixed up. It may fix a few things.

@bobadair
Copy link
Member

I've submitted PR #9554 for the debug logging change.

@morph166955
Copy link
Contributor Author

Cool. I had an interesting event today I've been watching. I loaded both the ecobee and denon changed bindings that resolved their thread issues. This time, instead of the things just going offline, one stayed up and the other flapped up and down. I just compiled and loaded the Samsung TV changes Kai submitted about an hour ago. Lets see if this calms everything down.

@morph166955
Copy link
Contributor Author

This has been completely stable with the updated samsung, denon, and ecobee bindings in place. I'm going to close this for now as it looks like the lutron binding was just being impacted by the threading issues on those bindings.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug An unexpected problem or unintended behavior of an add-on
Projects
None yet
Development

No branches or pull requests

2 participants