2025-08-04 16:23:06.345 [DEBUG] [nternal.handler.InsteonDeviceHandler] - channel insteon:device:2a14bf4b5e:5059d1:system-mode received command OFF
2025-08-04 16:23:06.346 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:systemMode handling command StringType:OFF using handler ThermostatSystemModeCommandHandler
2025-08-04 16:23:06.347 [TRACE] [nsteon.internal.device.InsteonDevice] - enqueuing request with delay 0 msec
2025-08-04 16:23:06.347 [TRACE] [steon.internal.device.RequestManager] - scheduling request for 50.59.D1 in 0 msec
2025-08-04 16:23:06.348 [TRACE] [steon.internal.device.RequestManager] - request for 50.59.D1 scheduled in 0 msec
2025-08-04 16:23:06.349 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:systemMode setting query status to: QUERY_SCHEDULED
2025-08-04 16:23:06.349 [TRACE] [steon.internal.device.RequestManager] - handling request for 50.59.D1
2025-08-04 16:23:06.350 [DEBUG] [ternal.device.feature.CommandHandler] - ThermostatSystemModeCommandHandler: sent systemMode 0x09 request to 50.59.D1
2025-08-04 16:23:06.350 [TRACE] [nsteon.internal.device.InsteonDevice] - request taken off direct for systemMode: OUT:Cmd:0x62|toAddress:50.59.D1|messageFlags:0x1F=DIRECT:3:3|command1:0x6B|command2:0x09|userData1:0x00|userData2:0x00|userData3:0x00|userData4:0x00|userData5:0x00|userData6:0x00|userData7:0x00|userData8:0x00|userData9:0x00|userData10:0x00|userData11:0x00|userData12:0x00|userData13:0x00|userData14:0x8C|
2025-08-04 16:23:06.351 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:systemMode setting query status to: QUERY_QUEUED
2025-08-04 16:23:06.352 [TRACE] [ding.insteon.internal.transport.Port] - enqueued msg (1): OUT:Cmd:0x62|toAddress:50.59.D1|messageFlags:0x1F=DIRECT:3:3|command1:0x6B|command2:0x09|userData1:0x00|userData2:0x00|userData3:0x00|userData4:0x00|userData5:0x00|userData6:0x00|userData7:0x00|userData8:0x00|userData9:0x00|userData10:0x00|userData11:0x00|userData12:0x00|userData13:0x00|userData14:0x8C|
2025-08-04 16:23:06.352 [DEBUG] [ding.insteon.internal.transport.Port] - sent msg: OUT:Cmd:0x62|toAddress:50.59.D1|messageFlags:0x1F=DIRECT:3:3|command1:0x6B|command2:0x09|userData1:0x00|userData2:0x00|userData3:0x00|userData4:0x00|userData5:0x00|userData6:0x00|userData7:0x00|userData8:0x00|userData9:0x00|userData10:0x00|userData11:0x00|userData12:0x00|userData13:0x00|userData14:0x8C|
2025-08-04 16:23:06.353 [TRACE] [nsteon.internal.device.InsteonDevice] - next request scheduled in 2000 msec
2025-08-04 16:23:06.353 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:systemMode setting query status to: QUERY_SENT
2025-08-04 16:23:06.354 [TRACE] [steon.internal.device.RequestManager] - scheduling request for 50.59.D1 in 2000 msec
2025-08-04 16:23:06.354 [TRACE] [rnal.transport.stream.IOStreamWriter] - waiting for reply ack
2025-08-04 16:23:06.355 [TRACE] [steon.internal.device.RequestManager] - request for 50.59.D1 scheduled in 2000 msec
2025-08-04 16:23:06.357 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 1 data: 02
2025-08-04 16:23:06.358 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:06.358 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 1 data: 02
2025-08-04 16:23:06.359 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:06.360 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 2 data: 0262
2025-08-04 16:23:06.360 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 6
2025-08-04 16:23:06.361 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:06.361 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 2 data: 0262
2025-08-04 16:23:06.362 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:06.363 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 3 data: 026250
2025-08-04 16:23:06.363 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 6
2025-08-04 16:23:06.364 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:06.365 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 3 data: 026250
2025-08-04 16:23:06.365 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:06.366 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 4 data: 02625059
2025-08-04 16:23:06.366 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 6
2025-08-04 16:23:06.367 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:06.367 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 4 data: 02625059
2025-08-04 16:23:06.368 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:06.369 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 5 data: 02625059D1
2025-08-04 16:23:06.369 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 6
2025-08-04 16:23:06.370 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:06.371 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 5 data: 02625059D1
2025-08-04 16:23:06.371 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:06.373 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 6 data: 02625059D11F
2025-08-04 16:23:06.374 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 6
2025-08-04 16:23:06.374 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 23 extended: true
2025-08-04 16:23:06.375 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:06.375 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 6 data: 02625059D11F
2025-08-04 16:23:06.376 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:06.376 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 7 data: 02625059D11F6B
2025-08-04 16:23:06.377 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 6
2025-08-04 16:23:06.377 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 23 extended: true
2025-08-04 16:23:06.378 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:06.378 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 7 data: 02625059D11F6B
2025-08-04 16:23:06.379 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:06.379 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 8 data: 02625059D11F6B09
2025-08-04 16:23:06.380 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 6
2025-08-04 16:23:06.380 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 23 extended: true
2025-08-04 16:23:06.381 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:06.381 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 8 data: 02625059D11F6B09
2025-08-04 16:23:06.382 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:06.382 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 9 data: 02625059D11F6B0900
2025-08-04 16:23:06.383 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 6
2025-08-04 16:23:06.383 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 23 extended: true
2025-08-04 16:23:06.384 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:06.384 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 9 data: 02625059D11F6B0900
2025-08-04 16:23:06.385 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:06.385 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 10 data: 02625059D11F6B090000
2025-08-04 16:23:06.386 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 6
2025-08-04 16:23:06.386 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 23 extended: true
2025-08-04 16:23:06.387 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:06.387 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 10 data: 02625059D11F6B090000
2025-08-04 16:23:06.388 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:06.388 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 11 data: 02625059D11F6B09000000
2025-08-04 16:23:06.389 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 6
2025-08-04 16:23:06.389 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 23 extended: true
2025-08-04 16:23:06.390 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:06.390 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 11 data: 02625059D11F6B09000000
2025-08-04 16:23:06.391 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:06.391 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 12 data: 02625059D11F6B0900000000
2025-08-04 16:23:06.392 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 6
2025-08-04 16:23:06.392 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 23 extended: true
2025-08-04 16:23:06.393 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:06.393 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 12 data: 02625059D11F6B0900000000
2025-08-04 16:23:06.394 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:06.394 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 13 data: 02625059D11F6B090000000000
2025-08-04 16:23:06.395 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 6
2025-08-04 16:23:06.395 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 23 extended: true
2025-08-04 16:23:06.395 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:06.396 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 13 data: 02625059D11F6B090000000000
2025-08-04 16:23:06.396 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:06.397 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 14 data: 02625059D11F6B09000000000000
2025-08-04 16:23:06.397 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 6
2025-08-04 16:23:06.398 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 23 extended: true
2025-08-04 16:23:06.398 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:06.399 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 14 data: 02625059D11F6B09000000000000
2025-08-04 16:23:06.399 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:06.399 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 15 data: 02625059D11F6B0900000000000000
2025-08-04 16:23:06.400 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 6
2025-08-04 16:23:06.400 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 23 extended: true
2025-08-04 16:23:06.401 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:06.401 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 15 data: 02625059D11F6B0900000000000000
2025-08-04 16:23:06.402 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:06.402 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 16 data: 02625059D11F6B090000000000000000
2025-08-04 16:23:06.403 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 6
2025-08-04 16:23:06.403 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 23 extended: true
2025-08-04 16:23:06.404 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:06.404 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 16 data: 02625059D11F6B090000000000000000
2025-08-04 16:23:06.405 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:06.405 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 17 data: 02625059D11F6B09000000000000000000
2025-08-04 16:23:06.405 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 6
2025-08-04 16:23:06.406 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 23 extended: true
2025-08-04 16:23:06.406 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:06.407 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 17 data: 02625059D11F6B09000000000000000000
2025-08-04 16:23:06.407 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:06.408 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 18 data: 02625059D11F6B0900000000000000000000
2025-08-04 16:23:06.408 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 6
2025-08-04 16:23:06.409 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 23 extended: true
2025-08-04 16:23:06.409 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:06.410 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 18 data: 02625059D11F6B0900000000000000000000
2025-08-04 16:23:06.410 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:06.411 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 19 data: 02625059D11F6B090000000000000000000000
2025-08-04 16:23:06.411 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 6
2025-08-04 16:23:06.412 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 23 extended: true
2025-08-04 16:23:06.412 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:06.413 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 19 data: 02625059D11F6B090000000000000000000000
2025-08-04 16:23:06.413 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:06.414 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 20 data: 02625059D11F6B09000000000000000000000000
2025-08-04 16:23:06.414 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 6
2025-08-04 16:23:06.415 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 23 extended: true
2025-08-04 16:23:06.415 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:06.416 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 20 data: 02625059D11F6B09000000000000000000000000
2025-08-04 16:23:06.416 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:06.417 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 21 data: 02625059D11F6B0900000000000000000000000000
2025-08-04 16:23:06.417 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 6
2025-08-04 16:23:06.418 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 23 extended: true
2025-08-04 16:23:06.418 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:06.418 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 21 data: 02625059D11F6B0900000000000000000000000000
2025-08-04 16:23:06.419 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:06.419 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 22 data: 02625059D11F6B09000000000000000000000000008C
2025-08-04 16:23:06.420 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 6
2025-08-04 16:23:06.420 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 23 extended: true
2025-08-04 16:23:06.421 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:06.421 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 22 data: 02625059D11F6B09000000000000000000000000008C
2025-08-04 16:23:06.422 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:06.422 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 23 data: 02625059D11F6B09000000000000000000000000008C06
2025-08-04 16:23:06.423 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 6
2025-08-04 16:23:06.423 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 23 extended: true
2025-08-04 16:23:06.424 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:06.424 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 0 data: 
2025-08-04 16:23:06.425 [DEBUG] [ding.insteon.internal.transport.Port] - got msg: IN:Cmd:0x62|toAddress:50.59.D1|messageFlags:0x1F=DIRECT:3:3|command1:0x6B|command2:0x09|userData1:0x00|userData2:0x00|userData3:0x00|userData4:0x00|userData5:0x00|userData6:0x00|userData7:0x00|userData8:0x00|userData9:0x00|userData10:0x00|userData11:0x00|userData12:0x00|userData13:0x00|userData14:0x8C|ACK/NACK:0x06|
2025-08-04 16:23:06.426 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:systemMode setting query status to: QUERY_ACKED
2025-08-04 16:23:06.426 [TRACE] [rnal.transport.stream.IOStreamWriter] - signaling receipt of ack: true
2025-08-04 16:23:06.427 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:06.427 [TRACE] [rnal.transport.stream.IOStreamWriter] - got reply ack: true
2025-08-04 16:23:06.428 [TRACE] [rnal.transport.stream.IOStreamWriter] - rate limited for 800 msec
2025-08-04 16:23:06.900 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 1 data: 02
2025-08-04 16:23:06.901 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:06.902 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 1 data: 02
2025-08-04 16:23:06.903 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:06.903 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 2 data: 0250
2025-08-04 16:23:06.904 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 9
2025-08-04 16:23:06.905 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:06.905 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 2 data: 0250
2025-08-04 16:23:06.906 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:06.906 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 3 data: 025050
2025-08-04 16:23:06.907 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 9
2025-08-04 16:23:06.908 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:06.908 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 3 data: 025050
2025-08-04 16:23:06.909 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:06.910 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 4 data: 02505059
2025-08-04 16:23:06.910 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 9
2025-08-04 16:23:06.911 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:06.911 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 4 data: 02505059
2025-08-04 16:23:06.912 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:06.913 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 5 data: 02505059D1
2025-08-04 16:23:06.913 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 9
2025-08-04 16:23:06.914 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:06.914 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 5 data: 02505059D1
2025-08-04 16:23:06.915 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:06.916 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 6 data: 02505059D146
2025-08-04 16:23:06.916 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 9
2025-08-04 16:23:06.917 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:06.918 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 6 data: 02505059D146
2025-08-04 16:23:06.918 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:06.919 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 7 data: 02505059D146C3
2025-08-04 16:23:06.920 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 9
2025-08-04 16:23:06.920 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:06.921 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 7 data: 02505059D146C3
2025-08-04 16:23:06.921 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:06.922 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 8 data: 02505059D146C316
2025-08-04 16:23:06.923 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 9
2025-08-04 16:23:06.923 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:06.924 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 8 data: 02505059D146C316
2025-08-04 16:23:06.925 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:06.925 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 9 data: 02505059D146C3162F
2025-08-04 16:23:06.926 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 9
2025-08-04 16:23:06.927 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 11 extended: false
2025-08-04 16:23:06.927 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:06.928 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 9 data: 02505059D146C3162F
2025-08-04 16:23:06.928 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:06.929 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 10 data: 02505059D146C3162F6B
2025-08-04 16:23:06.930 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 9
2025-08-04 16:23:06.930 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 11 extended: false
2025-08-04 16:23:06.931 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:06.932 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 10 data: 02505059D146C3162F6B
2025-08-04 16:23:06.932 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:06.933 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 11 data: 02505059D146C3162F6B09
2025-08-04 16:23:06.933 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 9
2025-08-04 16:23:06.934 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 11 extended: false
2025-08-04 16:23:06.935 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:06.935 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 0 data: 
2025-08-04 16:23:06.936 [DEBUG] [ding.insteon.internal.transport.Port] - got msg: IN:Cmd:0x50|fromAddress:50.59.D1|toAddress:46.C3.16|messageFlags:0x2F=ACK_OF_DIRECT:3:3|command1:0x6B|command2:0x09|
2025-08-04 16:23:06.937 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:thermostatData2Group handling message using dispatcher PollGroupDispatcher
2025-08-04 16:23:06.938 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:coolSetpoint handling message using dispatcher DefaultDispatcher
2025-08-04 16:23:06.938 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:heatSetpoint handling message using dispatcher DefaultDispatcher
2025-08-04 16:23:06.939 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:systemMode handling message using dispatcher DefaultDispatcher
2025-08-04 16:23:06.940 [DEBUG] [nal.device.feature.MessageDispatcher] - 50.59.D1:systemMode->TriggerPollMsgHandler ACK_OF_DIRECT group:N/A
2025-08-04 16:23:06.940 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:thermostatData2Group making poll msg using handler FlexPollHandler
2025-08-04 16:23:06.941 [TRACE] [nsteon.internal.device.InsteonDevice] - enqueuing request with delay 5000 msec
2025-08-04 16:23:06.942 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:thermostatData2Group setting query status to: QUERY_SCHEDULED
2025-08-04 16:23:06.943 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:systemMode triggered poll on group feature thermostatData2Group
2025-08-04 16:23:06.943 [TRACE] [nsteon.internal.device.InsteonDevice] - handled reply of direct for systemMode
2025-08-04 16:23:06.944 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:systemMode setting query status to: QUERY_ANSWERED
2025-08-04 16:23:06.945 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:lastHeardFrom handling message using dispatcher PassThroughDispatcher
2025-08-04 16:23:06.946 [DEBUG] [nal.device.feature.MessageDispatcher] - 50.59.D1:lastHeardFrom->LastTimeMsgHandler ACK_OF_DIRECT group:N/A
2025-08-04 16:23:06.947 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:lastHeardFrom setting state to: 2025-08-04T16:23:06.935-0400
2025-08-04 16:23:06.947 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:06.947 [TRACE] [rnal.transport.stream.IOStreamWriter] - rate limited for 800 msec
2025-08-04 16:23:07.748 [TRACE] [rnal.transport.stream.IOStreamWriter] - checking message queue
2025-08-04 16:23:08.355 [TRACE] [steon.internal.device.RequestManager] - handling request for 50.59.D1
2025-08-04 16:23:08.356 [TRACE] [steon.internal.device.RequestManager] - scheduling request for 50.59.D1 in 3586 msec
2025-08-04 16:23:08.356 [TRACE] [steon.internal.device.RequestManager] - request for 50.59.D1 scheduled in 3586 msec
2025-08-04 16:23:10.606 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 1 data: 02
2025-08-04 16:23:10.607 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:10.607 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 1 data: 02
2025-08-04 16:23:10.607 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:10.608 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 2 data: 0250
2025-08-04 16:23:10.609 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 9
2025-08-04 16:23:10.609 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:10.609 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 2 data: 0250
2025-08-04 16:23:10.610 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:10.610 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 3 data: 025050
2025-08-04 16:23:10.611 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 9
2025-08-04 16:23:10.611 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:10.612 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 3 data: 025050
2025-08-04 16:23:10.612 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:10.613 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 4 data: 02505059
2025-08-04 16:23:10.613 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 9
2025-08-04 16:23:10.614 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:10.614 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 4 data: 02505059
2025-08-04 16:23:10.615 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:10.615 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 5 data: 02505059D1
2025-08-04 16:23:10.615 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 9
2025-08-04 16:23:10.616 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:10.616 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 5 data: 02505059D1
2025-08-04 16:23:10.617 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:10.617 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 6 data: 02505059D146
2025-08-04 16:23:10.618 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 9
2025-08-04 16:23:10.618 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:10.619 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 6 data: 02505059D146
2025-08-04 16:23:10.619 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:10.619 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 7 data: 02505059D146C3
2025-08-04 16:23:10.620 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 9
2025-08-04 16:23:10.621 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:10.621 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 7 data: 02505059D146C3
2025-08-04 16:23:10.621 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:10.622 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 8 data: 02505059D146C316
2025-08-04 16:23:10.622 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 9
2025-08-04 16:23:10.623 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:10.623 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 8 data: 02505059D146C316
2025-08-04 16:23:10.624 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:10.624 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 9 data: 02505059D146C31605
2025-08-04 16:23:10.625 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 9
2025-08-04 16:23:10.625 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 11 extended: false
2025-08-04 16:23:10.626 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:10.626 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 9 data: 02505059D146C31605
2025-08-04 16:23:10.627 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:10.627 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 10 data: 02505059D146C3160570
2025-08-04 16:23:10.628 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 9
2025-08-04 16:23:10.628 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 11 extended: false
2025-08-04 16:23:10.629 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:10.629 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 10 data: 02505059D146C3160570
2025-08-04 16:23:10.630 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:10.630 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 11 data: 02505059D146C316057000
2025-08-04 16:23:10.631 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 9
2025-08-04 16:23:10.631 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 11 extended: false
2025-08-04 16:23:10.632 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:10.632 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 0 data: 
2025-08-04 16:23:10.633 [DEBUG] [ding.insteon.internal.transport.Port] - got msg: IN:Cmd:0x50|fromAddress:50.59.D1|toAddress:46.C3.16|messageFlags:0x05=DIRECT:1:1|command1:0x70|command2:0x00|
2025-08-04 16:23:10.633 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:thermostatData2Group handling message using dispatcher PollGroupDispatcher
2025-08-04 16:23:10.634 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:coolSetpoint handling message using dispatcher DefaultDispatcher
2025-08-04 16:23:10.634 [DEBUG] [nal.device.feature.MessageDispatcher] - 50.59.D1:coolSetpoint->NoOpMsgHandler DIRECT group:N/A
2025-08-04 16:23:10.635 [TRACE] [ternal.device.feature.MessageHandler] - NoOpMsgHandler: ignoring message with cmd1 0x70
2025-08-04 16:23:10.636 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:heatSetpoint handling message using dispatcher DefaultDispatcher
2025-08-04 16:23:10.636 [DEBUG] [nal.device.feature.MessageDispatcher] - 50.59.D1:heatSetpoint->NoOpMsgHandler DIRECT group:N/A
2025-08-04 16:23:10.637 [TRACE] [ternal.device.feature.MessageHandler] - NoOpMsgHandler: ignoring message with cmd1 0x70
2025-08-04 16:23:10.637 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:systemMode handling message using dispatcher DefaultDispatcher
2025-08-04 16:23:10.638 [DEBUG] [nal.device.feature.MessageDispatcher] - 50.59.D1:systemMode->ThermostatSystemModeMsgHandler DIRECT group:N/A
2025-08-04 16:23:10.638 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:systemMode setting last message value to: 0.0
2025-08-04 16:23:10.639 [DEBUG] [ternal.device.feature.MessageHandler] - ThermostatSystemModeMsgHandler: device 50.59.D1 systemMode is OFF
2025-08-04 16:23:10.639 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:systemMode setting state to: OFF
2025-08-04 16:23:10.640 [DEBUG] [nternal.handler.InsteonDeviceHandler] - publishing state OFF on insteon:device:2a14bf4b5e:5059d1:system-mode
2025-08-04 16:23:10.640 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:systemState handling message using dispatcher DefaultDispatcher
2025-08-04 16:23:10.641 [DEBUG] [nal.device.feature.MessageDispatcher] - 50.59.D1:systemState->ThermostatSystemStateMsgHandler DIRECT group:N/A
2025-08-04 16:23:10.642 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:systemState setting last message value to: 0.0
2025-08-04 16:23:10.642 [DEBUG] [ternal.device.feature.MessageHandler] - ThermostatSystemStateMsgHandler: device 50.59.D1 systemState is OFF
2025-08-04 16:23:10.643 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:systemState setting state to: OFF
2025-08-04 16:23:10.643 [DEBUG] [nternal.handler.InsteonDeviceHandler] - publishing state OFF on insteon:device:2a14bf4b5e:5059d1:system-state
2025-08-04 16:23:10.644 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:energySaving handling message using dispatcher DefaultDispatcher
2025-08-04 16:23:10.645 [DEBUG] [nal.device.feature.MessageDispatcher] - 50.59.D1:energySaving->NoOpMsgHandler DIRECT group:N/A
2025-08-04 16:23:10.645 [TRACE] [ternal.device.feature.MessageHandler] - NoOpMsgHandler: ignoring message with cmd1 0x70
2025-08-04 16:23:10.646 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:fanMode handling message using dispatcher DefaultDispatcher
2025-08-04 16:23:10.646 [DEBUG] [nal.device.feature.MessageDispatcher] - 50.59.D1:fanMode->ThermostatFanModeMsgHandler DIRECT group:N/A
2025-08-04 16:23:10.647 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:fanMode setting last message value to: 0.0
2025-08-04 16:23:10.647 [DEBUG] [ternal.device.feature.MessageHandler] - ThermostatFanModeMsgHandler: device 50.59.D1 fanMode is AUTO
2025-08-04 16:23:10.648 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:fanMode setting state to: AUTO
2025-08-04 16:23:10.648 [DEBUG] [nternal.handler.InsteonDeviceHandler] - publishing state AUTO on insteon:device:2a14bf4b5e:5059d1:fan-mode
2025-08-04 16:23:10.649 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:temperature handling message using dispatcher DefaultDispatcher
2025-08-04 16:23:10.650 [DEBUG] [nal.device.feature.MessageDispatcher] - 50.59.D1:temperature->NoOpMsgHandler DIRECT group:N/A
2025-08-04 16:23:10.650 [TRACE] [ternal.device.feature.MessageHandler] - NoOpMsgHandler: ignoring message with cmd1 0x70
2025-08-04 16:23:10.651 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:humidity handling message using dispatcher DefaultDispatcher
2025-08-04 16:23:10.651 [DEBUG] [nal.device.feature.MessageDispatcher] - 50.59.D1:humidity->NoOpMsgHandler DIRECT group:N/A
2025-08-04 16:23:10.652 [TRACE] [ternal.device.feature.MessageHandler] - NoOpMsgHandler: ignoring message with cmd1 0x70
2025-08-04 16:23:10.652 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:thermostatData1bGroup handling message using dispatcher PollGroupDispatcher
2025-08-04 16:23:10.653 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:dehumidifySetpoint handling message using dispatcher DefaultDispatcher
2025-08-04 16:23:10.653 [DEBUG] [nal.device.feature.MessageDispatcher] - 50.59.D1:dehumidifySetpoint->NoOpMsgHandler DIRECT group:N/A
2025-08-04 16:23:10.654 [TRACE] [ternal.device.feature.MessageHandler] - NoOpMsgHandler: ignoring message with cmd1 0x70
2025-08-04 16:23:10.654 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:humidifySetpoint handling message using dispatcher DefaultDispatcher
2025-08-04 16:23:10.655 [DEBUG] [nal.device.feature.MessageDispatcher] - 50.59.D1:humidifySetpoint->NoOpMsgHandler DIRECT group:N/A
2025-08-04 16:23:10.655 [TRACE] [ternal.device.feature.MessageHandler] - NoOpMsgHandler: ignoring message with cmd1 0x70
2025-08-04 16:23:10.655 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:humidifierState handling message using dispatcher DefaultDispatcher
2025-08-04 16:23:10.656 [DEBUG] [nal.device.feature.MessageDispatcher] - 50.59.D1:humidifierState->NoOpMsgHandler DIRECT group:N/A
2025-08-04 16:23:10.656 [TRACE] [ternal.device.feature.MessageHandler] - NoOpMsgHandler: ignoring message with cmd1 0x70
2025-08-04 16:23:10.657 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:stage1Duration handling message using dispatcher DefaultDispatcher
2025-08-04 16:23:10.657 [DEBUG] [nal.device.feature.MessageDispatcher] - 50.59.D1:stage1Duration->NoOpMsgHandler DIRECT group:N/A
2025-08-04 16:23:10.658 [TRACE] [ternal.device.feature.MessageHandler] - NoOpMsgHandler: ignoring message with cmd1 0x70
2025-08-04 16:23:10.658 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:syncTime handling message using dispatcher DefaultDispatcher
2025-08-04 16:23:10.659 [DEBUG] [nal.device.feature.MessageDispatcher] - 50.59.D1:syncTime->NoOpMsgHandler DIRECT group:N/A
2025-08-04 16:23:10.659 [TRACE] [ternal.device.feature.MessageHandler] - NoOpMsgHandler: ignoring message with cmd1 0x70
2025-08-04 16:23:10.660 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:beep handling message using dispatcher DefaultDispatcher
2025-08-04 16:23:10.660 [DEBUG] [nal.device.feature.MessageDispatcher] - 50.59.D1:beep->NoOpMsgHandler DIRECT group:N/A
2025-08-04 16:23:10.661 [TRACE] [ternal.device.feature.MessageHandler] - NoOpMsgHandler: ignoring message with cmd1 0x70
2025-08-04 16:23:10.661 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:thermostatData1Group handling message using dispatcher PollGroupDispatcher
2025-08-04 16:23:10.662 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:backlightDuration handling message using dispatcher DefaultDispatcher
2025-08-04 16:23:10.662 [DEBUG] [nal.device.feature.MessageDispatcher] - 50.59.D1:backlightDuration->NoOpMsgHandler DIRECT group:N/A
2025-08-04 16:23:10.663 [TRACE] [ternal.device.feature.MessageHandler] - NoOpMsgHandler: ignoring message with cmd1 0x70
2025-08-04 16:23:10.663 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:acDelay handling message using dispatcher DefaultDispatcher
2025-08-04 16:23:10.664 [DEBUG] [nal.device.feature.MessageDispatcher] - 50.59.D1:acDelay->NoOpMsgHandler DIRECT group:N/A
2025-08-04 16:23:10.664 [TRACE] [ternal.device.feature.MessageHandler] - NoOpMsgHandler: ignoring message with cmd1 0x70
2025-08-04 16:23:10.665 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:energyOffset handling message using dispatcher DefaultDispatcher
2025-08-04 16:23:10.665 [DEBUG] [nal.device.feature.MessageDispatcher] - 50.59.D1:energyOffset->NoOpMsgHandler DIRECT group:N/A
2025-08-04 16:23:10.666 [TRACE] [ternal.device.feature.MessageHandler] - NoOpMsgHandler: ignoring message with cmd1 0x70
2025-08-04 16:23:10.666 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:programLock handling message using dispatcher DefaultDispatcher
2025-08-04 16:23:10.667 [DEBUG] [nal.device.feature.MessageDispatcher] - 50.59.D1:programLock->NoOpMsgHandler DIRECT group:N/A
2025-08-04 16:23:10.667 [TRACE] [ternal.device.feature.MessageHandler] - NoOpMsgHandler: ignoring message with cmd1 0x70
2025-08-04 16:23:10.668 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:buttonBeep handling message using dispatcher DefaultDispatcher
2025-08-04 16:23:10.668 [DEBUG] [nal.device.feature.MessageDispatcher] - 50.59.D1:buttonBeep->NoOpMsgHandler DIRECT group:N/A
2025-08-04 16:23:10.669 [TRACE] [ternal.device.feature.MessageHandler] - NoOpMsgHandler: ignoring message with cmd1 0x70
2025-08-04 16:23:10.669 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:buttonLock handling message using dispatcher DefaultDispatcher
2025-08-04 16:23:10.670 [DEBUG] [nal.device.feature.MessageDispatcher] - 50.59.D1:buttonLock->NoOpMsgHandler DIRECT group:N/A
2025-08-04 16:23:10.670 [TRACE] [ternal.device.feature.MessageHandler] - NoOpMsgHandler: ignoring message with cmd1 0x70
2025-08-04 16:23:10.671 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:temperatureScale handling message using dispatcher DefaultDispatcher
2025-08-04 16:23:10.671 [DEBUG] [nal.device.feature.MessageDispatcher] - 50.59.D1:temperatureScale->NoOpMsgHandler DIRECT group:N/A
2025-08-04 16:23:10.672 [TRACE] [ternal.device.feature.MessageHandler] - NoOpMsgHandler: ignoring message with cmd1 0x70
2025-08-04 16:23:10.672 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:timeFormat handling message using dispatcher DefaultDispatcher
2025-08-04 16:23:10.673 [DEBUG] [nal.device.feature.MessageDispatcher] - 50.59.D1:timeFormat->NoOpMsgHandler DIRECT group:N/A
2025-08-04 16:23:10.673 [TRACE] [ternal.device.feature.MessageHandler] - NoOpMsgHandler: ignoring message with cmd1 0x70
2025-08-04 16:23:10.674 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:ledOnOff handling message using dispatcher DefaultDispatcher
2025-08-04 16:23:10.674 [DEBUG] [nal.device.feature.MessageDispatcher] - 50.59.D1:ledOnOff->NoOpMsgHandler DIRECT group:N/A
2025-08-04 16:23:10.675 [TRACE] [ternal.device.feature.MessageHandler] - NoOpMsgHandler: ignoring message with cmd1 0x70
2025-08-04 16:23:10.675 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:reporting handling message using dispatcher DefaultDispatcher
2025-08-04 16:23:10.676 [DEBUG] [nal.device.feature.MessageDispatcher] - 50.59.D1:reporting->NoOpMsgHandler DIRECT group:N/A
2025-08-04 16:23:10.676 [TRACE] [ternal.device.feature.MessageHandler] - NoOpMsgHandler: ignoring message with cmd1 0x70
2025-08-04 16:23:10.677 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:insteonEngine handling message using dispatcher DefaultDispatcher
2025-08-04 16:23:10.677 [DEBUG] [nal.device.feature.MessageDispatcher] - 50.59.D1:insteonEngine->NoOpMsgHandler DIRECT group:N/A
2025-08-04 16:23:10.678 [TRACE] [ternal.device.feature.MessageHandler] - NoOpMsgHandler: ignoring message with cmd1 0x70
2025-08-04 16:23:10.678 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:ping handling message using dispatcher DefaultDispatcher
2025-08-04 16:23:10.679 [DEBUG] [nal.device.feature.MessageDispatcher] - 50.59.D1:ping->NoOpMsgHandler DIRECT group:N/A
2025-08-04 16:23:10.679 [TRACE] [ternal.device.feature.MessageHandler] - NoOpMsgHandler: ignoring message with cmd1 0x70
2025-08-04 16:23:10.680 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:databaseDelta handling message using dispatcher DefaultDispatcher
2025-08-04 16:23:10.680 [DEBUG] [nal.device.feature.MessageDispatcher] - 50.59.D1:databaseDelta->NoOpMsgHandler DIRECT group:N/A
2025-08-04 16:23:10.681 [TRACE] [ternal.device.feature.MessageHandler] - NoOpMsgHandler: ignoring message with cmd1 0x70
2025-08-04 16:23:10.681 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:lastHeardFrom handling message using dispatcher PassThroughDispatcher
2025-08-04 16:23:10.682 [DEBUG] [nal.device.feature.MessageDispatcher] - 50.59.D1:lastHeardFrom->LastTimeMsgHandler DIRECT group:N/A
2025-08-04 16:23:10.683 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:lastHeardFrom setting state to: 2025-08-04T16:23:10.632-0400
2025-08-04 16:23:10.683 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:11.942 [TRACE] [steon.internal.device.RequestManager] - handling request for 50.59.D1
2025-08-04 16:23:11.944 [TRACE] [nsteon.internal.device.InsteonDevice] - request taken off direct for thermostatData2Group: OUT:Cmd:0x62|toAddress:50.59.D1|messageFlags:0x1F=DIRECT:3:3|command1:0x2E|command2:0x02|userData1:0x00|userData2:0x00|userData3:0x00|userData4:0x00|userData5:0x00|userData6:0x00|userData7:0x00|userData8:0x00|userData9:0x00|userData10:0x00|userData11:0x00|userData12:0x00|userData13:0x92|userData14:0x96|
2025-08-04 16:23:11.944 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:thermostatData2Group setting query status to: QUERY_QUEUED
2025-08-04 16:23:11.945 [TRACE] [ding.insteon.internal.transport.Port] - enqueued msg (1): OUT:Cmd:0x62|toAddress:50.59.D1|messageFlags:0x1F=DIRECT:3:3|command1:0x2E|command2:0x02|userData1:0x00|userData2:0x00|userData3:0x00|userData4:0x00|userData5:0x00|userData6:0x00|userData7:0x00|userData8:0x00|userData9:0x00|userData10:0x00|userData11:0x00|userData12:0x00|userData13:0x92|userData14:0x96|
2025-08-04 16:23:11.945 [DEBUG] [ding.insteon.internal.transport.Port] - sent msg: OUT:Cmd:0x62|toAddress:50.59.D1|messageFlags:0x1F=DIRECT:3:3|command1:0x2E|command2:0x02|userData1:0x00|userData2:0x00|userData3:0x00|userData4:0x00|userData5:0x00|userData6:0x00|userData7:0x00|userData8:0x00|userData9:0x00|userData10:0x00|userData11:0x00|userData12:0x00|userData13:0x92|userData14:0x96|
2025-08-04 16:23:11.945 [TRACE] [nsteon.internal.device.InsteonDevice] - next request scheduled in 2000 msec
2025-08-04 16:23:11.946 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:thermostatData2Group setting query status to: QUERY_SENT
2025-08-04 16:23:11.946 [TRACE] [steon.internal.device.RequestManager] - scheduling request for 50.59.D1 in 2000 msec
2025-08-04 16:23:11.946 [TRACE] [rnal.transport.stream.IOStreamWriter] - waiting for reply ack
2025-08-04 16:23:11.947 [TRACE] [steon.internal.device.RequestManager] - request for 50.59.D1 scheduled in 2000 msec
2025-08-04 16:23:11.947 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 1 data: 02
2025-08-04 16:23:11.948 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:11.948 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 1 data: 02
2025-08-04 16:23:11.949 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:11.949 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 2 data: 0262
2025-08-04 16:23:11.950 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 6
2025-08-04 16:23:11.950 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:11.950 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 2 data: 0262
2025-08-04 16:23:11.951 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:11.963 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 3 data: 026250
2025-08-04 16:23:11.964 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 6
2025-08-04 16:23:11.964 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:11.965 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 3 data: 026250
2025-08-04 16:23:11.965 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:11.966 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 4 data: 02625059
2025-08-04 16:23:11.966 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 6
2025-08-04 16:23:11.967 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:11.967 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 4 data: 02625059
2025-08-04 16:23:11.968 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:11.968 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 5 data: 02625059D1
2025-08-04 16:23:11.969 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 6
2025-08-04 16:23:11.969 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:11.970 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 5 data: 02625059D1
2025-08-04 16:23:11.970 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:11.970 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 6 data: 02625059D11F
2025-08-04 16:23:11.971 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 6
2025-08-04 16:23:11.972 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 23 extended: true
2025-08-04 16:23:11.972 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:11.973 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 6 data: 02625059D11F
2025-08-04 16:23:11.973 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:11.974 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 7 data: 02625059D11F2E
2025-08-04 16:23:11.974 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 6
2025-08-04 16:23:11.975 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 23 extended: true
2025-08-04 16:23:11.975 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:11.976 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 7 data: 02625059D11F2E
2025-08-04 16:23:11.976 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:11.976 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 8 data: 02625059D11F2E02
2025-08-04 16:23:11.977 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 6
2025-08-04 16:23:11.978 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 23 extended: true
2025-08-04 16:23:11.978 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:11.979 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 8 data: 02625059D11F2E02
2025-08-04 16:23:11.979 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:11.980 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 9 data: 02625059D11F2E0200
2025-08-04 16:23:11.980 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 6
2025-08-04 16:23:11.981 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 23 extended: true
2025-08-04 16:23:11.981 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:11.982 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 9 data: 02625059D11F2E0200
2025-08-04 16:23:11.982 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:11.983 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 10 data: 02625059D11F2E020000
2025-08-04 16:23:11.983 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 6
2025-08-04 16:23:11.984 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 23 extended: true
2025-08-04 16:23:11.984 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:11.985 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 10 data: 02625059D11F2E020000
2025-08-04 16:23:11.985 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:11.986 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 11 data: 02625059D11F2E02000000
2025-08-04 16:23:11.986 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 6
2025-08-04 16:23:11.987 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 23 extended: true
2025-08-04 16:23:11.987 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:11.987 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 11 data: 02625059D11F2E02000000
2025-08-04 16:23:11.988 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:11.988 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 12 data: 02625059D11F2E0200000000
2025-08-04 16:23:11.989 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 6
2025-08-04 16:23:11.989 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 23 extended: true
2025-08-04 16:23:11.990 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:11.990 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 12 data: 02625059D11F2E0200000000
2025-08-04 16:23:11.991 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:11.991 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 13 data: 02625059D11F2E020000000000
2025-08-04 16:23:11.992 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 6
2025-08-04 16:23:11.992 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 23 extended: true
2025-08-04 16:23:11.993 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:11.993 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 13 data: 02625059D11F2E020000000000
2025-08-04 16:23:11.993 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:11.994 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 14 data: 02625059D11F2E02000000000000
2025-08-04 16:23:11.994 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 6
2025-08-04 16:23:11.995 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 23 extended: true
2025-08-04 16:23:11.995 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:11.996 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 14 data: 02625059D11F2E02000000000000
2025-08-04 16:23:11.996 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:11.997 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 15 data: 02625059D11F2E0200000000000000
2025-08-04 16:23:11.997 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 6
2025-08-04 16:23:11.998 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 23 extended: true
2025-08-04 16:23:11.998 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:11.999 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 15 data: 02625059D11F2E0200000000000000
2025-08-04 16:23:11.999 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:11.999 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 16 data: 02625059D11F2E020000000000000000
2025-08-04 16:23:12.000 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 6
2025-08-04 16:23:12.000 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 23 extended: true
2025-08-04 16:23:12.001 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:12.001 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 16 data: 02625059D11F2E020000000000000000
2025-08-04 16:23:12.002 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:12.002 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 17 data: 02625059D11F2E02000000000000000000
2025-08-04 16:23:12.003 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 6
2025-08-04 16:23:12.003 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 23 extended: true
2025-08-04 16:23:12.004 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:12.004 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 17 data: 02625059D11F2E02000000000000000000
2025-08-04 16:23:12.004 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:12.005 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 18 data: 02625059D11F2E0200000000000000000000
2025-08-04 16:23:12.005 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 6
2025-08-04 16:23:12.006 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 23 extended: true
2025-08-04 16:23:12.006 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:12.007 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 18 data: 02625059D11F2E0200000000000000000000
2025-08-04 16:23:12.007 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:12.007 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 19 data: 02625059D11F2E020000000000000000000000
2025-08-04 16:23:12.008 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 6
2025-08-04 16:23:12.008 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 23 extended: true
2025-08-04 16:23:12.009 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:12.009 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 19 data: 02625059D11F2E020000000000000000000000
2025-08-04 16:23:12.009 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:12.010 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 20 data: 02625059D11F2E02000000000000000000000000
2025-08-04 16:23:12.010 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 6
2025-08-04 16:23:12.011 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 23 extended: true
2025-08-04 16:23:12.011 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:12.011 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 20 data: 02625059D11F2E02000000000000000000000000
2025-08-04 16:23:12.012 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:12.012 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 21 data: 02625059D11F2E0200000000000000000000000092
2025-08-04 16:23:12.013 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 6
2025-08-04 16:23:12.013 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 23 extended: true
2025-08-04 16:23:12.014 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:12.014 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 21 data: 02625059D11F2E0200000000000000000000000092
2025-08-04 16:23:12.014 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:12.015 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 22 data: 02625059D11F2E020000000000000000000000009296
2025-08-04 16:23:12.015 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 6
2025-08-04 16:23:12.016 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 23 extended: true
2025-08-04 16:23:12.016 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:12.017 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 22 data: 02625059D11F2E020000000000000000000000009296
2025-08-04 16:23:12.017 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:12.018 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 23 data: 02625059D11F2E02000000000000000000000000929606
2025-08-04 16:23:12.018 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 6
2025-08-04 16:23:12.019 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 23 extended: true
2025-08-04 16:23:12.019 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:12.020 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 0 data: 
2025-08-04 16:23:12.021 [DEBUG] [ding.insteon.internal.transport.Port] - got msg: IN:Cmd:0x62|toAddress:50.59.D1|messageFlags:0x1F=DIRECT:3:3|command1:0x2E|command2:0x02|userData1:0x00|userData2:0x00|userData3:0x00|userData4:0x00|userData5:0x00|userData6:0x00|userData7:0x00|userData8:0x00|userData9:0x00|userData10:0x00|userData11:0x00|userData12:0x00|userData13:0x92|userData14:0x96|ACK/NACK:0x06|
2025-08-04 16:23:12.021 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:thermostatData2Group setting query status to: QUERY_ACKED
2025-08-04 16:23:12.022 [TRACE] [rnal.transport.stream.IOStreamWriter] - signaling receipt of ack: true
2025-08-04 16:23:12.022 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:12.022 [TRACE] [rnal.transport.stream.IOStreamWriter] - got reply ack: true
2025-08-04 16:23:12.023 [TRACE] [rnal.transport.stream.IOStreamWriter] - rate limited for 800 msec
2025-08-04 16:23:12.490 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 1 data: 02
2025-08-04 16:23:12.491 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:12.492 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 1 data: 02
2025-08-04 16:23:12.492 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:12.493 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 2 data: 0250
2025-08-04 16:23:12.493 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 9
2025-08-04 16:23:12.494 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:12.494 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 2 data: 0250
2025-08-04 16:23:12.495 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:12.495 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 3 data: 025050
2025-08-04 16:23:12.496 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 9
2025-08-04 16:23:12.496 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:12.497 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 3 data: 025050
2025-08-04 16:23:12.497 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:12.498 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 4 data: 02505059
2025-08-04 16:23:12.498 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 9
2025-08-04 16:23:12.499 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:12.499 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 4 data: 02505059
2025-08-04 16:23:12.500 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:12.500 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 5 data: 02505059D1
2025-08-04 16:23:12.501 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 9
2025-08-04 16:23:12.501 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:12.502 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 5 data: 02505059D1
2025-08-04 16:23:12.502 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:12.503 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 6 data: 02505059D146
2025-08-04 16:23:12.504 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 9
2025-08-04 16:23:12.504 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:12.505 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 6 data: 02505059D146
2025-08-04 16:23:12.505 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:12.506 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 7 data: 02505059D146C3
2025-08-04 16:23:12.506 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 9
2025-08-04 16:23:12.507 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:12.507 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 7 data: 02505059D146C3
2025-08-04 16:23:12.508 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:12.508 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 8 data: 02505059D146C316
2025-08-04 16:23:12.509 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 9
2025-08-04 16:23:12.509 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:12.510 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 8 data: 02505059D146C316
2025-08-04 16:23:12.510 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:12.511 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 9 data: 02505059D146C3162F
2025-08-04 16:23:12.511 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 9
2025-08-04 16:23:12.512 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 11 extended: false
2025-08-04 16:23:12.512 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:12.513 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 9 data: 02505059D146C3162F
2025-08-04 16:23:12.513 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:12.514 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 10 data: 02505059D146C3162F2E
2025-08-04 16:23:12.514 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 9
2025-08-04 16:23:12.515 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 11 extended: false
2025-08-04 16:23:12.515 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:12.516 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 10 data: 02505059D146C3162F2E
2025-08-04 16:23:12.517 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:12.517 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 11 data: 02505059D146C3162F2E02
2025-08-04 16:23:12.518 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 9
2025-08-04 16:23:12.518 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 11 extended: false
2025-08-04 16:23:12.519 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:12.519 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 0 data: 
2025-08-04 16:23:12.520 [DEBUG] [ding.insteon.internal.transport.Port] - got msg: IN:Cmd:0x50|fromAddress:50.59.D1|toAddress:46.C3.16|messageFlags:0x2F=ACK_OF_DIRECT:3:3|command1:0x2E|command2:0x02|
2025-08-04 16:23:12.521 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:thermostatData2Group handling message using dispatcher PollGroupDispatcher
2025-08-04 16:23:12.521 [DEBUG] [nal.device.feature.MessageDispatcher] - 50.59.D1:thermostatData2Group got poll ACK_OF_DIRECT
2025-08-04 16:23:12.522 [TRACE] [nsteon.internal.device.InsteonDevice] - handled reply of direct for thermostatData2Group
2025-08-04 16:23:12.522 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:thermostatData2Group setting query status to: QUERY_ANSWERED
2025-08-04 16:23:12.523 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:lastHeardFrom handling message using dispatcher PassThroughDispatcher
2025-08-04 16:23:12.524 [DEBUG] [nal.device.feature.MessageDispatcher] - 50.59.D1:lastHeardFrom->LastTimeMsgHandler ACK_OF_DIRECT group:N/A
2025-08-04 16:23:12.524 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:lastHeardFrom setting state to: 2025-08-04T16:23:12.519-0400
2025-08-04 16:23:12.525 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:12.525 [TRACE] [rnal.transport.stream.IOStreamWriter] - rate limited for 800 msec
2025-08-04 16:23:12.906 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 1 data: 02
2025-08-04 16:23:12.907 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:12.907 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 1 data: 02
2025-08-04 16:23:12.908 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:12.908 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 2 data: 0251
2025-08-04 16:23:12.909 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 9
2025-08-04 16:23:12.909 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:12.910 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 2 data: 0251
2025-08-04 16:23:12.910 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:12.911 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 3 data: 025150
2025-08-04 16:23:12.912 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 9
2025-08-04 16:23:12.912 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:12.913 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 3 data: 025150
2025-08-04 16:23:12.913 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:12.914 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 4 data: 02515059
2025-08-04 16:23:12.914 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 9
2025-08-04 16:23:12.915 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:12.915 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 4 data: 02515059
2025-08-04 16:23:12.916 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:12.916 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 5 data: 02515059D1
2025-08-04 16:23:12.917 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 9
2025-08-04 16:23:12.917 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:12.918 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 5 data: 02515059D1
2025-08-04 16:23:12.918 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:12.919 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 6 data: 02515059D146
2025-08-04 16:23:12.920 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 9
2025-08-04 16:23:12.920 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:12.921 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 6 data: 02515059D146
2025-08-04 16:23:12.921 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:12.922 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 7 data: 02515059D146C3
2025-08-04 16:23:12.922 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 9
2025-08-04 16:23:12.923 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:12.923 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 7 data: 02515059D146C3
2025-08-04 16:23:12.924 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:12.924 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 8 data: 02515059D146C316
2025-08-04 16:23:12.925 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 9
2025-08-04 16:23:12.925 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:12.926 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 8 data: 02515059D146C316
2025-08-04 16:23:12.926 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:12.927 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 9 data: 02515059D146C31615
2025-08-04 16:23:12.927 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 9
2025-08-04 16:23:12.928 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 25 extended: true
2025-08-04 16:23:12.928 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:12.929 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 9 data: 02515059D146C31615
2025-08-04 16:23:12.929 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:12.930 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 10 data: 02515059D146C316152E
2025-08-04 16:23:12.931 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 9
2025-08-04 16:23:12.931 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 25 extended: true
2025-08-04 16:23:12.931 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:12.932 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 10 data: 02515059D146C316152E
2025-08-04 16:23:12.933 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:12.933 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 11 data: 02515059D146C316152E02
2025-08-04 16:23:12.934 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 9
2025-08-04 16:23:12.934 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 25 extended: true
2025-08-04 16:23:12.935 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:12.935 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 11 data: 02515059D146C316152E02
2025-08-04 16:23:12.936 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:12.936 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 12 data: 02515059D146C316152E0201
2025-08-04 16:23:12.937 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 9
2025-08-04 16:23:12.937 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 25 extended: true
2025-08-04 16:23:12.938 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:12.938 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 12 data: 02515059D146C316152E0201
2025-08-04 16:23:12.939 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:12.940 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 13 data: 02515059D146C316152E020104
2025-08-04 16:23:12.940 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 9
2025-08-04 16:23:12.941 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 25 extended: true
2025-08-04 16:23:12.942 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:12.942 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 13 data: 02515059D146C316152E020104
2025-08-04 16:23:12.943 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:12.943 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 14 data: 02515059D146C316152E02010409
2025-08-04 16:23:12.944 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 9
2025-08-04 16:23:12.945 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 25 extended: true
2025-08-04 16:23:12.945 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:12.946 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 14 data: 02515059D146C316152E02010409
2025-08-04 16:23:12.946 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:12.947 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 15 data: 02515059D146C316152E020104093B
2025-08-04 16:23:12.948 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 9
2025-08-04 16:23:12.948 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 25 extended: true
2025-08-04 16:23:12.949 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:12.949 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 15 data: 02515059D146C316152E020104093B
2025-08-04 16:23:12.950 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:12.950 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 16 data: 02515059D146C316152E020104093B0B
2025-08-04 16:23:12.951 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 9
2025-08-04 16:23:12.951 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 25 extended: true
2025-08-04 16:23:12.952 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:12.952 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 16 data: 02515059D146C316152E020104093B0B
2025-08-04 16:23:12.953 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:12.953 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 17 data: 02515059D146C316152E020104093B0B00
2025-08-04 16:23:12.954 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 9
2025-08-04 16:23:12.954 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 25 extended: true
2025-08-04 16:23:12.955 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:12.955 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 17 data: 02515059D146C316152E020104093B0B00
2025-08-04 16:23:12.956 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:12.956 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 18 data: 02515059D146C316152E020104093B0B004B
2025-08-04 16:23:12.957 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 9
2025-08-04 16:23:12.957 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 25 extended: true
2025-08-04 16:23:12.958 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:12.958 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 18 data: 02515059D146C316152E020104093B0B004B
2025-08-04 16:23:12.959 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:12.959 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 19 data: 02515059D146C316152E020104093B0B004B32
2025-08-04 16:23:12.960 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 9
2025-08-04 16:23:12.960 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 25 extended: true
2025-08-04 16:23:12.961 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:12.961 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 19 data: 02515059D146C316152E020104093B0B004B32
2025-08-04 16:23:12.962 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:12.962 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 20 data: 02515059D146C316152E020104093B0B004B3200
2025-08-04 16:23:12.963 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 9
2025-08-04 16:23:12.963 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 25 extended: true
2025-08-04 16:23:12.964 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:12.964 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 20 data: 02515059D146C316152E020104093B0B004B3200
2025-08-04 16:23:12.965 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:12.965 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 21 data: 02515059D146C316152E020104093B0B004B3200EC
2025-08-04 16:23:12.966 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 9
2025-08-04 16:23:12.966 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 25 extended: true
2025-08-04 16:23:12.967 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:12.968 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 21 data: 02515059D146C316152E020104093B0B004B3200EC
2025-08-04 16:23:12.968 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:12.969 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 22 data: 02515059D146C316152E020104093B0B004B3200ECC0
2025-08-04 16:23:12.969 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 9
2025-08-04 16:23:12.970 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 25 extended: true
2025-08-04 16:23:12.970 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:12.971 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 22 data: 02515059D146C316152E020104093B0B004B3200ECC0
2025-08-04 16:23:12.971 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:12.972 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 23 data: 02515059D146C316152E020104093B0B004B3200ECC044
2025-08-04 16:23:12.972 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 9
2025-08-04 16:23:12.973 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 25 extended: true
2025-08-04 16:23:12.973 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:12.974 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 23 data: 02515059D146C316152E020104093B0B004B3200ECC044
2025-08-04 16:23:12.974 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:12.975 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 24 data: 02515059D146C316152E020104093B0B004B3200ECC0443D
2025-08-04 16:23:12.975 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 9
2025-08-04 16:23:12.975 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 25 extended: true
2025-08-04 16:23:12.976 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:12.976 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 24 data: 02515059D146C316152E020104093B0B004B3200ECC0443D
2025-08-04 16:23:12.977 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:12.978 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 25 data: 02515059D146C316152E020104093B0B004B3200ECC0443D06
2025-08-04 16:23:12.978 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 9
2025-08-04 16:23:12.979 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 25 extended: true
2025-08-04 16:23:12.979 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-08-04 16:23:12.980 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 0 data: 
2025-08-04 16:23:12.980 [DEBUG] [ding.insteon.internal.transport.Port] - got msg: IN:Cmd:0x51|fromAddress:50.59.D1|toAddress:46.C3.16|messageFlags:0x15=DIRECT:1:1|command1:0x2E|command2:0x02|userData1:0x01|userData2:0x04|userData3:0x09|userData4:0x3B|userData5:0x0B|userData6:0x00|userData7:0x4B|userData8:0x32|userData9:0x00|userData10:0xEC|userData11:0xC0|userData12:0x44|userData13:0x3D|userData14:0x06|
2025-08-04 16:23:12.981 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:thermostatData2Group handling message using dispatcher PollGroupDispatcher
2025-08-04 16:23:12.981 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:coolSetpoint handling message using dispatcher DefaultDispatcher
2025-08-04 16:23:12.982 [DEBUG] [nal.device.feature.MessageDispatcher] - 50.59.D1:coolSetpoint->CustomTemperatureMsgHandler DIRECT group:N/A
2025-08-04 16:23:12.983 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:coolSetpoint setting last message value to: 75.0
2025-08-04 16:23:12.983 [DEBUG] [ternal.device.feature.MessageHandler] - CustomTemperatureMsgHandler: device 50.59.D1 coolSetpoint is 75 °F
2025-08-04 16:23:12.984 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:coolSetpoint setting state to: 75 °F
2025-08-04 16:23:12.985 [DEBUG] [nternal.handler.InsteonDeviceHandler] - publishing state 75 °F on insteon:device:2a14bf4b5e:5059d1:cool-setpoint
2025-08-04 16:23:12.985 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:heatSetpoint handling message using dispatcher DefaultDispatcher
2025-08-04 16:23:12.986 [DEBUG] [nal.device.feature.MessageDispatcher] - 50.59.D1:heatSetpoint->CustomTemperatureMsgHandler DIRECT group:N/A
2025-08-04 16:23:12.987 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:heatSetpoint setting last message value to: 68.0
2025-08-04 16:23:12.987 [DEBUG] [ternal.device.feature.MessageHandler] - CustomTemperatureMsgHandler: device 50.59.D1 heatSetpoint is 68 °F
2025-08-04 16:23:12.988 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:heatSetpoint setting state to: 68 °F
2025-08-04 16:23:12.989 [DEBUG] [nternal.handler.InsteonDeviceHandler] - publishing state 68 °F on insteon:device:2a14bf4b5e:5059d1:heat-setpoint
2025-08-04 16:23:12.989 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:systemMode handling message using dispatcher DefaultDispatcher
2025-08-04 16:23:12.990 [DEBUG] [nal.device.feature.MessageDispatcher] - 50.59.D1:systemMode->ThermostatSystemModeMsgHandler DIRECT group:N/A
2025-08-04 16:23:12.991 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:systemMode setting last message value to: 0.0
2025-08-04 16:23:12.991 [DEBUG] [ternal.device.feature.MessageHandler] - ThermostatSystemModeMsgHandler: device 50.59.D1 systemMode is OFF
2025-08-04 16:23:12.992 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:systemMode setting state to: OFF
2025-08-04 16:23:12.992 [DEBUG] [nternal.handler.InsteonDeviceHandler] - publishing state OFF on insteon:device:2a14bf4b5e:5059d1:system-mode
2025-08-04 16:23:12.993 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:systemState handling message using dispatcher DefaultDispatcher
2025-08-04 16:23:12.993 [DEBUG] [nal.device.feature.MessageDispatcher] - 50.59.D1:systemState->ThermostatSystemStateMsgHandler DIRECT group:N/A
2025-08-04 16:23:12.994 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:systemState setting last message value to: 0.0
2025-08-04 16:23:12.995 [DEBUG] [ternal.device.feature.MessageHandler] - ThermostatSystemStateMsgHandler: device 50.59.D1 systemState is OFF
2025-08-04 16:23:12.995 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:systemState setting state to: OFF
2025-08-04 16:23:12.996 [DEBUG] [nternal.handler.InsteonDeviceHandler] - publishing state OFF on insteon:device:2a14bf4b5e:5059d1:system-state
2025-08-04 16:23:12.996 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:energySaving handling message using dispatcher DefaultDispatcher
2025-08-04 16:23:12.997 [DEBUG] [nal.device.feature.MessageDispatcher] - 50.59.D1:energySaving->CustomBitmaskMsgHandler DIRECT group:N/A
2025-08-04 16:23:12.998 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:energySaving setting last message value to: 192.0
2025-08-04 16:23:12.998 [DEBUG] [ternal.device.feature.MessageHandler] - CustomBitmaskMsgHandler: device 50.59.D1 energySaving is OFF
2025-08-04 16:23:12.999 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:energySaving setting state to: OFF
2025-08-04 16:23:12.999 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:fanMode handling message using dispatcher DefaultDispatcher
2025-08-04 16:23:13.000 [DEBUG] [nal.device.feature.MessageDispatcher] - 50.59.D1:fanMode->ThermostatFanModeMsgHandler DIRECT group:N/A
2025-08-04 16:23:13.000 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:fanMode setting last message value to: 0.0
2025-08-04 16:23:13.001 [DEBUG] [ternal.device.feature.MessageHandler] - ThermostatFanModeMsgHandler: device 50.59.D1 fanMode is AUTO
2025-08-04 16:23:13.002 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:fanMode setting state to: AUTO
2025-08-04 16:23:13.002 [DEBUG] [nternal.handler.InsteonDeviceHandler] - publishing state AUTO on insteon:device:2a14bf4b5e:5059d1:fan-mode
2025-08-04 16:23:13.003 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:temperature handling message using dispatcher DefaultDispatcher
2025-08-04 16:23:13.004 [DEBUG] [nal.device.feature.MessageDispatcher] - 50.59.D1:temperature->CustomTemperatureMsgHandler DIRECT group:N/A
2025-08-04 16:23:13.005 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:temperature setting last message value to: 23.6
2025-08-04 16:23:13.005 [DEBUG] [ternal.device.feature.MessageHandler] - CustomTemperatureMsgHandler: device 50.59.D1 temperature is 23.6 °C
2025-08-04 16:23:13.006 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:temperature setting state to: 23.6 °C
2025-08-04 16:23:13.006 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:humidity handling message using dispatcher DefaultDispatcher
2025-08-04 16:23:13.007 [DEBUG] [nal.device.feature.MessageDispatcher] - 50.59.D1:humidity->CustomDimensionlessMsgHandler DIRECT group:N/A
2025-08-04 16:23:13.008 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:humidity setting last message value to: 50.0
2025-08-04 16:23:13.008 [DEBUG] [ternal.device.feature.MessageHandler] - CustomDimensionlessMsgHandler: device 50.59.D1 humidity is 50 %
2025-08-04 16:23:13.009 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:humidity setting state to: 50 %
2025-08-04 16:23:13.009 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:thermostatData1bGroup handling message using dispatcher PollGroupDispatcher
2025-08-04 16:23:13.010 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:dehumidifySetpoint handling message using dispatcher DefaultDispatcher
2025-08-04 16:23:13.010 [TRACE] [ternal.device.feature.MessageHandler] - 50.59.D1:dehumidifySetpoint ignoring msg as unmatch filters
2025-08-04 16:23:13.011 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:humidifySetpoint handling message using dispatcher DefaultDispatcher
2025-08-04 16:23:13.012 [TRACE] [ternal.device.feature.MessageHandler] - 50.59.D1:humidifySetpoint ignoring msg as unmatch filters
2025-08-04 16:23:13.012 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:humidifierState handling message using dispatcher DefaultDispatcher
2025-08-04 16:23:13.013 [DEBUG] [nal.device.feature.MessageDispatcher] - 50.59.D1:humidifierState->NoOpMsgHandler DIRECT group:N/A
2025-08-04 16:23:13.013 [TRACE] [ternal.device.feature.MessageHandler] - NoOpMsgHandler: ignoring message with cmd1 0x2E
2025-08-04 16:23:13.014 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:stage1Duration handling message using dispatcher DefaultDispatcher
2025-08-04 16:23:13.014 [TRACE] [ternal.device.feature.MessageHandler] - 50.59.D1:stage1Duration ignoring msg as unmatch filters
2025-08-04 16:23:13.015 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:syncTime handling message using dispatcher DefaultDispatcher
2025-08-04 16:23:13.015 [DEBUG] [nal.device.feature.MessageDispatcher] - 50.59.D1:syncTime->NoOpMsgHandler DIRECT group:N/A
2025-08-04 16:23:13.016 [TRACE] [ternal.device.feature.MessageHandler] - NoOpMsgHandler: ignoring message with cmd1 0x2E
2025-08-04 16:23:13.016 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:beep handling message using dispatcher DefaultDispatcher
2025-08-04 16:23:13.017 [DEBUG] [nal.device.feature.MessageDispatcher] - 50.59.D1:beep->NoOpMsgHandler DIRECT group:N/A
2025-08-04 16:23:13.017 [TRACE] [ternal.device.feature.MessageHandler] - NoOpMsgHandler: ignoring message with cmd1 0x2E
2025-08-04 16:23:13.018 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:thermostatData1Group handling message using dispatcher PollGroupDispatcher
2025-08-04 16:23:13.018 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:backlightDuration handling message using dispatcher DefaultDispatcher
2025-08-04 16:23:13.019 [TRACE] [ternal.device.feature.MessageHandler] - 50.59.D1:backlightDuration ignoring msg as unmatch filters
2025-08-04 16:23:13.019 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:acDelay handling message using dispatcher DefaultDispatcher
2025-08-04 16:23:13.020 [TRACE] [ternal.device.feature.MessageHandler] - 50.59.D1:acDelay ignoring msg as unmatch filters
2025-08-04 16:23:13.021 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:energyOffset handling message using dispatcher DefaultDispatcher
2025-08-04 16:23:13.021 [TRACE] [ternal.device.feature.MessageHandler] - 50.59.D1:energyOffset ignoring msg as unmatch filters
2025-08-04 16:23:13.022 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:programLock handling message using dispatcher DefaultDispatcher
2025-08-04 16:23:13.022 [TRACE] [ternal.device.feature.MessageHandler] - 50.59.D1:programLock ignoring msg as unmatch filters
2025-08-04 16:23:13.023 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:buttonBeep handling message using dispatcher DefaultDispatcher
2025-08-04 16:23:13.023 [TRACE] [ternal.device.feature.MessageHandler] - 50.59.D1:buttonBeep ignoring msg as unmatch filters
2025-08-04 16:23:13.024 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:buttonLock handling message using dispatcher DefaultDispatcher
2025-08-04 16:23:13.024 [TRACE] [ternal.device.feature.MessageHandler] - 50.59.D1:buttonLock ignoring msg as unmatch filters
2025-08-04 16:23:13.025 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:temperatureScale handling message using dispatcher DefaultDispatcher
2025-08-04 16:23:13.025 [TRACE] [ternal.device.feature.MessageHandler] - 50.59.D1:temperatureScale ignoring msg as unmatch filters
2025-08-04 16:23:13.026 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:timeFormat handling message using dispatcher DefaultDispatcher
2025-08-04 16:23:13.026 [TRACE] [ternal.device.feature.MessageHandler] - 50.59.D1:timeFormat ignoring msg as unmatch filters
2025-08-04 16:23:13.027 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:ledOnOff handling message using dispatcher DefaultDispatcher
2025-08-04 16:23:13.028 [TRACE] [ternal.device.feature.MessageHandler] - 50.59.D1:ledOnOff ignoring msg as unmatch filters
2025-08-04 16:23:13.028 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:reporting handling message using dispatcher DefaultDispatcher
2025-08-04 16:23:13.029 [DEBUG] [nal.device.feature.MessageDispatcher] - 50.59.D1:reporting->NoOpMsgHandler DIRECT group:N/A
2025-08-04 16:23:13.029 [TRACE] [ternal.device.feature.MessageHandler] - NoOpMsgHandler: ignoring message with cmd1 0x2E
2025-08-04 16:23:13.030 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:insteonEngine handling message using dispatcher DefaultDispatcher
2025-08-04 16:23:13.030 [DEBUG] [nal.device.feature.MessageDispatcher] - 50.59.D1:insteonEngine->NoOpMsgHandler DIRECT group:N/A
2025-08-04 16:23:13.031 [TRACE] [ternal.device.feature.MessageHandler] - NoOpMsgHandler: ignoring message with cmd1 0x2E
2025-08-04 16:23:13.031 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:ping handling message using dispatcher DefaultDispatcher
2025-08-04 16:23:13.032 [DEBUG] [nal.device.feature.MessageDispatcher] - 50.59.D1:ping->NoOpMsgHandler DIRECT group:N/A
2025-08-04 16:23:13.032 [TRACE] [ternal.device.feature.MessageHandler] - NoOpMsgHandler: ignoring message with cmd1 0x2E
2025-08-04 16:23:13.033 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:databaseDelta handling message using dispatcher DefaultDispatcher
2025-08-04 16:23:13.033 [DEBUG] [nal.device.feature.MessageDispatcher] - 50.59.D1:databaseDelta->NoOpMsgHandler DIRECT group:N/A
2025-08-04 16:23:13.034 [TRACE] [ternal.device.feature.MessageHandler] - NoOpMsgHandler: ignoring message with cmd1 0x2E
2025-08-04 16:23:13.034 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:lastHeardFrom handling message using dispatcher PassThroughDispatcher
2025-08-04 16:23:13.035 [DEBUG] [nal.device.feature.MessageDispatcher] - 50.59.D1:lastHeardFrom->LastTimeMsgHandler DIRECT group:N/A
2025-08-04 16:23:13.036 [TRACE] [nsteon.internal.device.DeviceFeature] - 50.59.D1:lastHeardFrom setting state to: 2025-08-04T16:23:12.979-0400
2025-08-04 16:23:13.036 [TRACE] [rnal.transport.stream.IOStreamReader] - checking for input data
2025-08-04 16:23:13.036 [TRACE] [rnal.transport.stream.IOStreamWriter] - rate limited for 800 msec
2025-08-04 16:23:13.837 [TRACE] [rnal.transport.stream.IOStreamWriter] - checking message queue
2025-08-04 16:23:13.947 [TRACE] [steon.internal.device.RequestManager] - handling request for 50.59.D1
2025-08-04 16:23:13.948 [TRACE] [steon.internal.device.RequestManager] - no more pending requests for 50.59.D1