transitionTime of MoveToLeve and StepSaturation doesn't take effect

Problem Description:
transitionTime of MoveToLeve and StepSaturation doesn't take effect

expected behavior

DUT dimming level goes from 0 to 254, cost 6553.5s
DUT saturation goes from 120 to 130, cost 30s

actual behavior
transitionTime doesn't take effect,

DUT dimming level from 0 to 254, cost about 2s
DUT saturation from 120 to 130, cost about 5s

steps to reproduce
MoveToLeve:

Check DUT CurrentLevel is 0
Send the cmd to DUT successfully: zcl LevelControl MoveToLevel 12344321 1 0 level=254 transitionTime=65535 optionMask=0 optionOverride=0
Check the DUT CurrentLevel

ColorControl:

Send the cmd to DUT successfully: zcl ColorControl StepSaturation 12344321 1 0 stepMode=1 stepSize=10 transitionTime=300 optionsMask=0 optionsOverride=0
Check the DUT CurrentSaturation

system configuration
commit 6db59aa066599f9e5967e900c809a85037a56e8b (HEAD -> test_event_5, origin/test_event_5)

logs:

chip-device-ctrl > zclread LevelControl CurrentLevel 12344321 1 0
[1631509027.056155][2526:2535] CHIP:DMG: SendReadRequest: Client[0] [ INIT]
[1631509027.056465][2526:2535] CHIP:IN: Secure message was encrypted: Msg ID 66
[1631509027.056540][2526:2535] CHIP:IN: Encrypted message 0xd84ab98 to 0x0000000000BC5C01 of type 2 and protocolId 5 on exchange 39057.
[1631509027.056684][2526:2535] CHIP:IN: Sending msg 0xd84ab98 to 0x0000000000BC5C01 at utc time: 8661878 msec
[1631509027.056740][2526:2535] CHIP:IN: Sending secure msg on generic transport
[1631509027.056937][2526:2535] CHIP:IN: Secure msg send status ../../src/inet/IPEndPointBasis.cpp:915: Success
[1631509027.057033][2526:2535] CHIP:DMG: Client[0] moving to [AwaitingResponse]
[1631509027.220014][2526:2535] CHIP:EM: Received message of type 0x05 with vendorId 0x0000 and protocolId 0x0005 on exchange 39057
[1631509027.220164][2526:2535] CHIP:EM: Rxd Ack; Removing MsgId:00000042 from Retrans Table
[1631509027.220225][2526:2535] CHIP:EM: Removed CHIP MsgId:00000042 from RetransTable
[1631509027.220340][2526:2535] CHIP:DMG: ReportData =
[1631509027.220406][2526:2535] CHIP:DMG: {
[1631509027.220455][2526:2535] CHIP:DMG:        AttributeDataList =
[1631509027.220512][2526:2535] CHIP:DMG:        [
[1631509027.220569][2526:2535] CHIP:DMG:                AttributeDataElement =
[1631509027.220641][2526:2535] CHIP:DMG:                {
[1631509027.220695][2526:2535] CHIP:DMG:                        AttributePath =
[1631509027.220812][2526:2535] CHIP:DMG:                        {
[1631509027.220884][2526:2535] CHIP:DMG:                                NodeId = 0xbc5c01,
[1631509027.220955][2526:2535] CHIP:DMG:                                EndpointId = 0x1,
[1631509027.221038][2526:2535] CHIP:DMG:                                ClusterId = 0x8,
[1631509027.221121][2526:2535] CHIP:DMG:                                FieldTag = 0x0,
[1631509027.221199][2526:2535] CHIP:DMG:                        }
[1631509027.221281][2526:2535] CHIP:DMG:
[1631509027.221367][2526:2535] CHIP:DMG:                        Data = 0,
[1631509027.221446][2526:2535] CHIP:DMG:                        DataElementVersion = 0x0,
[1631509027.221515][2526:2535] CHIP:DMG:                },
[1631509027.221592][2526:2535] CHIP:DMG:
[1631509027.221652][2526:2535] CHIP:DMG:        ],
[1631509027.221725][2526:2535] CHIP:DMG:
[1631509027.221776][2526:2535] CHIP:DMG: }
[1631509027.222493][2526:2535] CHIP:ZCL: ReadAttributesResponse:
[1631509027.222563][2526:2535] CHIP:ZCL:   ClusterId: 0x0000_0008
[1631509027.222621][2526:2535] CHIP:ZCL:   attributeId: 0x0000_0000
[1631509027.222669][2526:2535] CHIP:ZCL:   status: Success                (0x0000)
[1631509027.222715][2526:2535] CHIP:ZCL:   attribute TLV Type: 0x04
[1631509027.222769][2526:2535] CHIP:ZCL:   attributeValue: 0
[1631509027.222953][2526:2535] CHIP:DMG: Client[0] moving to [INIT]
[1631509027.223013][2526:2535] CHIP:DMG: Client[0] moving to [UNINIT]
AttributeReadResult(path=AttributePath(nodeId=12344321, endpointId=1, clusterId=8, attributeId=0), status=0, value=0)
[1631509027.223074][2526:2535] CHIP:EM: Sending Standalone Ack for MsgId:00000022
[1631509027.223283][2526:2535] CHIP:IN: Secure message was encrypted: Msg ID 67
[1631509027.223358][2526:2535] CHIP:IN: Encrypted message 0xffff97ffdaf8 to 0x0000000000BC5C01 of type 16 and protocolId 0 on exchange 39057.
[1631509027.223432][2526:2535] CHIP:IN: Sending msg 0xffff97ffdaf8 to 0x0000000000BC5C01 at utc time: 8662045 msec
[1631509027.223575][2526:2535] CHIP:IN: chip-device-ctrl > Sending secure msg on generic transport
[1631509027.223823][2526:2535] CHIP:IN: Secure msg send status ../../src/inet/IPEndPointBasis.cpp:915: Success
[1631509027.223903][2526:2535] CHIP:EM: Flushed pending ack for MsgId:00000022

chip-device-ctrl >
chip-device-ctrl > zcl LevelControl MoveToLevel 12344321 1 0 level=254 transitionTime=65535 optionMask=0 optionOverride=0
[1631509032.902667][2526:2535] CHIP:DMG: ICR moving to [Initialize]
[1631509032.902769][2526:2535] CHIP:DMG: ICR moving to [AddCommand]
[1631509032.902961][2526:2535] CHIP:IN: Secure message was encrypted: Msg ID 68
[1631509032.903016][2526:2535] CHIP:IN: Encrypted message 0xd84ab98 to 0x0000000000BC5C01 of type 8 and protocolId 5 on exchange 39058.
[1631509032.903072][2526:2535] CHIP:IN: Sending msg 0xd84ab98 to 0x0000000000BC5C01 at utc time: 8667724 msec
[1631509032.903116][2526:2535] CHIP:IN: Sending secure msg on generic transport
[1631509032.903269][2526:2535] CHIP:IN: Secure msg send status ../../src/inet/IPEndPointBasis.cpp:915: Success
[1631509032.903343][2526:2535] CHIP:DMG: ICR moving to [   Sending]
[1631509033.048389][2526:2535] CHIP:EM: Received message of type 0x09 with vendorId 0x0000 and protocolId 0x0005 on exchange 39058
[1631509033.048532][2526:2535] CHIP:EM: Rxd Ack; Removing MsgId:00000044 from Retrans Table
[1631509033.048588][2526:2535] CHIP:EM: Removed CHIP MsgId:00000044 from RetransTable
[1631509033.048696][2526:2535] CHIP:DMG: InvokeCommand =
[1631509033.048759][2526:2535] CHIP:DMG: {
[1631509033.048803][2526:2535] CHIP:DMG:        CommandList =
[1631509033.048859][2526:2535] CHIP:DMG:        [
[1631509033.048914][2526:2535] CHIP:DMG:                CommandDataElement =
[1631509033.048985][2526:2535] CHIP:DMG:                {
[1631509033.049054][2526:2535] CHIP:DMG:                        CommandPath =
[1631509033.049122][2526:2535] CHIP:DMG:                        {
[1631509033.049192][2526:2535] CHIP:DMG:                                EndpointId = 0x1,
[1631509033.049283][2526:2535] CHIP:DMG:                                ClusterId = 0x8,
[1631509033.049372][2526:2535] CHIP:DMG:                                CommandId = 0x0,
[1631509033.049455][2526:2535] CHIP:DMG:                        },
[1631509033.049548][2526:2535] CHIP:DMG:
[1631509033.049615][2526:2535] CHIP:DMG:                        StatusElement =
[1631509033.049687][2526:2535] CHIP:DMG:                        {
[1631509033.049762][2526:2535] CHIP:DMG:                                GeneralCode = 0x0,
[1631509033.049840][2526:2535] CHIP:DMG:                                ProtocolId = 0x5,
[1631509033.049923][2526:2535] CHIP:DMG:                                protocolCode = 0x0,
[1631509033.049995][2526:2535] CHIP:DMG:                        },
[1631509033.050078][2526:2535] CHIP:DMG:
[1631509033.050187][2526:2535] CHIP:DMG:                },
[1631509033.050269][2526:2535] CHIP:DMG:
[1631509033.050324][2526:2535] CHIP:DMG:        ],
[1631509033.050394][2526:2535] CHIP:DMG:
[1631509033.050444][2526:2535] CHIP:DMG: }
SetCommandIndexStatus commandHandle=1 commandIndex=1
[1631509033.051052][2526:2535] CHIP:ZCL: DefaultResponse:
[1631509033.051108][2526:2535] CHIP:ZCL:   Transaction: 0xffffa7ca74a0
[1631509033.051155][2526:2535] CHIP:ZCL:   status: EMBER_ZCL_STATUS_SUCCESS (0x00)
[1631509033.051205][2526:2535] CHIP:ZCL: IMDefaultResponseCallback: Missing success callback
[1631509033.051250][2526:2535] CHIP:ZCL: IMDefaultResponseCallback: Missing failure callback
[1631509033.051413][2526:2535] CHIP:DMG: ICR moving to [Uninitiali]
[1631509033.051486][2526:2535] CHIP:EM: Sending Standalone Ack for MsgId:00000023
Received command status response:
[1631509033.051634][2526:2535] CHIP:IN: Secure message was encrypted: Msg ID 69
[1631509033.051703][2526:2535] CHIP:IN: Encrypted message 0xffff97ffdaf8 to 0x0000000000BC5C01 of type 16 and protocolId 0 on exchange 39058.
[1631509033.051778][2526:2535] CHIP:IN: Sending msg 0xffff97ffdaf8 to 0x0000000000BC5C01 at utc time: 8667873 msec
Container:
    ProtocolId = 5
    ProtocolCode = 0
    EndpointId = 1
    ClusterId = 8
    CommandId = 0
    CommandIndex = 1[1631509033.051831][2526:2535] CHIP:IN: Sending secure msg on generic transport

[1631509033.052146][2526:2535] CHIP:IN: Secure msg send status ../../src/inet/IPEndPointBasis.cpp:915: Success
[1631509033.052226][2526:2535] CHIP:EM: Flushed pending ack for MsgId:00000023
chip-device-ctrl > zclread LevelControl CurrentLevel 12344321 1 0
[1631509035.024731][2526:2535] CHIP:DMG: SendReadRequest: Client[0] [ INIT]
[1631509035.024993][2526:2535] CHIP:IN: Secure message was encrypted: Msg ID 70
[1631509035.025052][2526:2535] CHIP:IN: Encrypted message 0xd84ab98 to 0x0000000000BC5C01 of type 2 and protocolId 5 on exchange 39059.
[1631509035.025109][2526:2535] CHIP:IN: Sending msg 0xd84ab98 to 0x0000000000BC5C01 at utc time: 8669846 msec
[1631509035.025149][2526:2535] CHIP:IN: Sending secure msg on generic transport
[1631509035.025308][2526:2535] CHIP:IN: Secure msg send status ../../src/inet/IPEndPointBasis.cpp:915: Success
[1631509035.025376][2526:2535] CHIP:DMG: Client[0] moving to [AwaitingResponse]
[1631509035.197096][2526:2535] CHIP:EM: Received message of type 0x05 with vendorId 0x0000 and protocolId 0x0005 on exchange 39059
[1631509035.197219][2526:2535] CHIP:EM: Rxd Ack; Removing MsgId:00000046 from Retrans Table
[1631509035.197262][2526:2535] CHIP:EM: Removed CHIP MsgId:00000046 from RetransTable
[1631509035.197352][2526:2535] CHIP:DMG: ReportData =
[1631509035.197400][2526:2535] CHIP:DMG: {
[1631509035.197438][2526:2535] CHIP:DMG:        AttributeDataList =
[1631509035.197486][2526:2535] CHIP:DMG:        [
[1631509035.197528][2526:2535] CHIP:DMG:                AttributeDataElement =
[1631509035.197578][2526:2535] CHIP:DMG:                {
[1631509035.197625][2526:2535] CHIP:DMG:                        AttributePath =
[1631509035.197691][2526:2535] CHIP:DMG:                        {
[1631509035.197749][2526:2535] CHIP:DMG:                                NodeId = 0xbc5c01,
[1631509035.197809][2526:2535] CHIP:DMG:                                EndpointId = 0x1,
[1631509035.197871][2526:2535] CHIP:DMG:                                ClusterId = 0x8,
[1631509035.197933][2526:2535] CHIP:DMG:                                FieldTag = 0x0,
[1631509035.197984][2526:2535] CHIP:DMG:                        }
[1631509035.198052][2526:2535] CHIP:DMG:
[1631509035.198112][2526:2535] CHIP:DMG:                        Data = 254,
[1631509035.198190][2526:2535] CHIP:DMG:                        DataElementVersion = 0x0,
[1631509035.198245][2526:2535] CHIP:DMG:                },
[1631509035.198302][2526:2535] CHIP:DMG:
[1631509035.198346][2526:2535] CHIP:DMG:        ],
[1631509035.198397][2526:2535] CHIP:DMG:
[1631509035.198434][2526:2535] CHIP:DMG: }
[1631509035.198983][2526:2535] CHIP:ZCL: ReadAttributesResponse:
[1631509035.199037][2526:2535] CHIP:ZCL:   ClusterId: 0x0000_0008
[1631509035.199080][2526:2535] CHIP:ZCL:   attributeId: 0x0000_0000
[1631509035.199116][2526:2535] CHIP:ZCL:   status: Success                (0x0000)
[1631509035.199150][2526:2535] CHIP:ZCL:   attribute TLV Type: 0x04
[1631509035.199192][2526:2535] CHIP:ZCL:   attributeValue: 254
[1631509035.199333][2526:2535] CHIP:DMG: Client[0] moving to [INIT]
[1631509035.199379][2526:2535] CHIP:DMG: Client[0] moving to [UNINIT]
[1631509035.199427][2526:2535] CHIP:EM: Sending Standalone Ack for MsgId:00000024
AttributeReadResult(path=AttributePath(nodeId=12344321, endpointId=1, clusterId=8, attributeId=0), status=0, value=254)
[1631509035.199566][2526:2535] CHIP:IN: Secure message was encrypted: Msg ID 71
[1631509035.199620][2526:2535] CHIP:IN: Encrypted message 0xffff97ffdaf8 to 0x0000000000BC5C01 of type 16 and protocolId 0 on exchange 39059.
[1631509035.199674][2526:2535] CHIP:IN: Sending msg 0xffff97ffdaf8 to 0x0000000000BC5C01 at utc time: 8670021 msec
[1631509035.199713][2526:2535] CHIP:IN: Sending secure msg on generic transport
chip-device-ctrl > [1631509035.199893][2526:2535] CHIP:IN: Secure msg send status ../../src/inet/IPEndPointBasis.cpp:915: Success
[1631509035.199951][2526:2535] CHIP:EM: Flushed pending ack for MsgId:00000024

chip-device-ctrl > zcl ColorControl StepSaturation 12344321 1 0 stepMode=1 stepSize=10 transitionTime=300 optionsMask=0 optionsOverride=0
[1631516470.842392][2301:2309] CHIP:DMG: ICR moving to [Initialize]
[1631516470.842511][2301:2309] CHIP:DMG: ICR moving to [AddCommand]
[1631516470.842743][2301:2309] CHIP:IN: Secure message was encrypted: Msg ID 448
[1631516470.842816][2301:2309] CHIP:IN: Encrypted message 0x1ff9eab8 to 0x0000000000BC5C01 of type 8 and protocolId 5 on exchange 39248.
[1631516470.842940][2301:2309] CHIP:IN: Sending msg 0x1ff9eab8 to 0x0000000000BC5C01 at utc time: 6274306 msec
[1631516470.842995][2301:2309] CHIP:IN: Sending secure msg on generic transport
[1631516470.843229][2301:2309] CHIP:IN: Secure msg send status ../../src/inet/IPEndPointBasis.cpp:915: Success
[1631516470.843380][2301:2309] CHIP:DMG: ICR moving to [   Sending]
[1631516471.056854][2301:2309] CHIP:EM: Received message of type 0x09 with vendorId 0x0000 and protocolId 0x0005 on exchange 39248
[1631516471.056985][2301:2309] CHIP:EM: Rxd Ack; Removing MsgId:000001C0 from Retrans Table
[1631516471.057042][2301:2309] CHIP:EM: Removed CHIP MsgId:000001C0 from RetransTable
[1631516471.057148][2301:2309] CHIP:DMG: InvokeCommand =
[1631516471.057212][2301:2309] CHIP:DMG: {
[1631516471.057254][2301:2309] CHIP:DMG:        CommandList =
[1631516471.057362][2301:2309] CHIP:DMG:        [
[1631516471.057420][2301:2309] CHIP:DMG:                CommandDataElement =
[1631516471.057659][2301:2309] CHIP:DMG:                {
[1631516471.057781][2301:2309] CHIP:DMG:                        CommandPath =
[1631516471.057908][2301:2309] CHIP:DMG:                        {
[1631516471.058064][2301:2309] CHIP:DMG:                                EndpointId = 0x1,
[1631516471.058197][2301:2309] CHIP:DMG:                                ClusterId = 0x300,
[1631516471.058279][2301:2309] CHIP:DMG:                                CommandId = 0x5,
[1631516471.058388][2301:2309] CHIP:DMG:                        },
[1631516471.058522][2301:2309] CHIP:DMG:
[1631516471.058584][2301:2309] CHIP:DMG:                        StatusElement =
[1631516471.058696][2301:2309] CHIP:DMG:                        {
[1631516471.058758][2301:2309] CHIP:DMG:                                GeneralCode = 0x0,
[1631516471.058878][2301:2309] CHIP:DMG:                                ProtocolId = 0x5,
[1631516471.059003][2301:2309] CHIP:DMG:                                protocolCode = 0x0,
[1631516471.059089][2301:2309] CHIP:DMG:                        },
[1631516471.059250][2301:2309] CHIP:DMG:
[1631516471.059317][2301:2309] CHIP:DMG:                },
[1631516471.059433][2301:2309] CHIP:DMG:
[1631516471.059526][2301:2309] CHIP:DMG:        ],
[1631516471.059599][2301:2309] CHIP:DMG:
[1631516471.059691][2301:2309] CHIP:DMG: }
SetCommandIndexStatus commandHandle=1 commandIndex=1
[1631516471.060302][2301:2309] CHIP:ZCL: DefaultResponse:
[1631516471.060357][2301:2309] CHIP:ZCL:   Transaction: 0xffffa5e974a0
[1631516471.060403][2301:2309] CHIP:ZCL:   status: EMBER_ZCL_STATUS_SUCCESS (0x00)
[1631516471.060454][2301:2309] CHIP:ZCL: IMDefaultResponseCallback: Missing success callback
[1631516471.060499][2301:2309] CHIP:ZCL: IMDefaultResponseCallback: Missing failure callback
[1631516471.060701][2301:2309] CHIP:DMG: ICR moving to [Uninitiali]
[1631516471.060779][2301:2309] CHIP:EM: Sending Standalone Ack for MsgId:000000E1
Received command status response:
[1631516471.060932][2301:2309] CHIP:IN: Secure message was encrypted: Msg ID 449
[1631516471.061001][2301:2309] CHIP:IN: Encrypted message 0xffff9e77aaf8 to 0x0000000000BC5C01 of type 16 and protocolId 0 on exchange 39248.
[1631516471.061071][2301:2309] CHIP:IN: Sending msg 0xffff9e77aaf8 to 0x0000000000BC5C01 at utc time: 6274524 msec
Container:
    ProtocolId = 5
    ProtocolCode = 0
    EndpointId = 1
    ClusterId = 768
    CommandId = 5
    CommandIndex = 1[1631516471.061124][2301:2309] CHIP:IN: Sending secure msg on generic transport

[1631516471.061418][2301:2309] CHIP:IN: Secure msg send status ../../src/inet/IPEndPointBasis.cpp:915: Success
[1631516471.061555][2301:2309] CHIP:EM: Flushed pending ack for MsgId:000000E1

chip-device-ctrl > zclread ColorControl CurrentSaturation 12344321 1 0
[1631516473.601819][2301:2309] CHIP:DMG: SendReadRequest: Client[0] [ INIT]
[1631516473.602081][2301:2309] CHIP:IN: Secure message was encrypted: Msg ID 450
[1631516473.602137][2301:2309] CHIP:IN: Encrypted message 0x1ff9eab8 to 0x0000000000BC5C01 of type 2 and protocolId 5 on exchange 39249.
[1631516473.602189][2301:2309] CHIP:IN: Sending msg 0x1ff9eab8 to 0x0000000000BC5C01 at utc time: 6277065 msec
[1631516473.602272][2301:2309] CHIP:IN: Sending secure msg on generic transport
[1631516473.602464][2301:2309] CHIP:IN: Secure msg send status ../../src/inet/IPEndPointBasis.cpp:915: Success
[1631516473.602578][2301:2309] CHIP:DMG: Client[0] moving to [AwaitingResponse]
[1631516473.840044][2301:2309] CHIP:EM: Received message of type 0x05 with vendorId 0x0000 and protocolId 0x0005 on exchange 39249
[1631516473.840192][2301:2309] CHIP:EM: Rxd Ack; Removing MsgId:000001C2 from Retrans Table
[1631516473.840248][2301:2309] CHIP:EM: Removed CHIP MsgId:000001C2 from RetransTable
[1631516473.840360][2301:2309] CHIP:DMG: ReportData =
[1631516473.840424][2301:2309] CHIP:DMG: {
[1631516473.840472][2301:2309] CHIP:DMG:        AttributeDataList =
[1631516473.840637][2301:2309] CHIP:DMG:        [
[1631516473.840696][2301:2309] CHIP:DMG:                AttributeDataElement =
[1631516473.840808][2301:2309] CHIP:DMG:                {
[1631516473.840878][2301:2309] CHIP:DMG:                        AttributePath =
[1631516473.840994][2301:2309] CHIP:DMG:                        {
[1631516473.841059][2301:2309] CHIP:DMG:                                NodeId = 0xbc5c01,
[1631516473.841178][2301:2309] CHIP:DMG:                                EndpointId = 0x1,
[1631516473.841263][2301:2309] CHIP:DMG:                                ClusterId = 0x300,
[1631516473.841436][2301:2309] CHIP:DMG:                                FieldTag = 0x1,
[1631516473.841520][2301:2309] CHIP:DMG:                        }
[1631516473.841685][2301:2309] CHIP:DMG:
[1631516473.841773][2301:2309] CHIP:DMG:                        Data = 125,
[1631516473.841931][2301:2309] CHIP:DMG:                        DataElementVersion = 0x0,
[1631516473.842001][2301:2309] CHIP:DMG:                },
[1631516473.842077][2301:2309] CHIP:DMG:
[1631516473.842133][2301:2309] CHIP:DMG:        ],
[1631516473.842202][2301:2309] CHIP:DMG:
[1631516473.842253][2301:2309] CHIP:DMG: }
[1631516473.842933][2301:2309] CHIP:ZCL: ReadAttributesResponse:
[1631516473.843003][2301:2309] CHIP:ZCL:   ClusterId: 0x0000_0300
[1631516473.843060][2301:2309] CHIP:ZCL:   attributeId: 0x0000_0001
[1631516473.843108][2301:2309] CHIP:ZCL:   status: Success                (0x0000)
[1631516473.843156][2301:2309] CHIP:ZCL:   attribute TLV Type: 0x04
[1631516473.843212][2301:2309] CHIP:ZCL:   attributeValue: 125
[1631516473.843389][2301:2309] CHIP:DMG: Client[0] moving to [INIT]
[1631516473.843454][2301:2309] CHIP:DMG: Client[0] moving to [UNINIT]
AttributeReadResult(path=AttributePath(nodeId=12344321, endpointId=1, clusterId=768, attributeId=1), status=0, value=125)
[1631516473.843519][2301:2309] CHIP:EM: Sending Standalone Ack for MsgId:000000E2
[1631516473.843718][2301:2309] CHIP:IN: Secure message was encrypted: Msg ID 451
[1631516473.843791][2301:2309] CHIP:IN: Encrypted message 0xffff9e77aaf8 to 0x0000000000BC5C01 of type 16 and protocolId 0 on exchange 39249.
[1631516473.843863][2301:2309] CHIP:IN: Sending msg 0xffff9e77aaf8 to 0x0000000000BC5C01 at utc time: 6277307 msec
[1631516473.843935][2301:2309] CHIP:IN: Sending secure msg on generic transport
chip-device-ctrl > [1631516473.844171][2301:2309] CHIP:IN: Secure msg send status ../../src/inet/IPEndPointBasis.cpp:915: Success
[1631516473.844304][2301:2309] CHIP:EM: Flushed pending ack for MsgId:000000E2

chip-device-ctrl > zclread ColorControl CurrentSaturation 12344321 1 0
[1631516476.286327][2301:2309] CHIP:DMG: SendReadRequest: Client[0] [ INIT]
[1631516476.286583][2301:2309] CHIP:IN: Secure message was encrypted: Msg ID 452
[1631516476.286817][2301:2309] CHIP:IN: Encrypted message 0x1ff9eab8 to 0x0000000000BC5C01 of type 2 and protocolId 5 on exchange 39250.
[1631516476.286911][2301:2309] CHIP:IN: Sending msg 0x1ff9eab8 to 0x0000000000BC5C01 at utc time: 6279750 msec
[1631516476.286952][2301:2309] CHIP:IN: Sending secure msg on generic transport
[1631516476.287140][2301:2309] CHIP:IN: Secure msg send status ../../src/inet/IPEndPointBasis.cpp:915: Success
[1631516476.287256][2301:2309] CHIP:DMG: Client[0] moving to [AwaitingResponse]
[1631516476.484816][2301:2309] CHIP:EM: Received message of type 0x05 with vendorId 0x0000 and protocolId 0x0005 on exchange 39250
[1631516476.484968][2301:2309] CHIP:EM: Rxd Ack; Removing MsgId:000001C4 from Retrans Table
[1631516476.485024][2301:2309] CHIP:EM: Removed CHIP MsgId:000001C4 from RetransTable
[1631516476.485136][2301:2309] CHIP:DMG: ReportData =
[1631516476.485200][2301:2309] CHIP:DMG: {
[1631516476.485249][2301:2309] CHIP:DMG:        AttributeDataList =
[1631516476.485410][2301:2309] CHIP:DMG:        [
[1631516476.485465][2301:2309] CHIP:DMG:                AttributeDataElement =
[1631516476.485581][2301:2309] CHIP:DMG:                {
[1631516476.485636][2301:2309] CHIP:DMG:                        AttributePath =
[1631516476.485754][2301:2309] CHIP:DMG:                        {
[1631516476.485841][2301:2309] CHIP:DMG:                                NodeId = 0xbc5c01,
[1631516476.485972][2301:2309] CHIP:DMG:                                EndpointId = 0x1,
[1631516476.486092][2301:2309] CHIP:DMG:                                ClusterId = 0x300,
[1631516476.486164][2301:2309] CHIP:DMG:                                FieldTag = 0x1,
[1631516476.486286][2301:2309] CHIP:DMG:                        }
[1631516476.486409][2301:2309] CHIP:DMG:
[1631516476.486473][2301:2309] CHIP:DMG:                        Data = 130,
[1631516476.486589][2301:2309] CHIP:DMG:                        DataElementVersion = 0x0,
[1631516476.486648][2301:2309] CHIP:DMG:                },
[1631516476.486762][2301:2309] CHIP:DMG:
[1631516476.486811][2301:2309] CHIP:DMG:        ],
[1631516476.486924][2301:2309] CHIP:DMG:
[1631516476.486976][2301:2309] CHIP:DMG: }
[1631516476.487780][2301:2309] CHIP:ZCL: ReadAttributesResponse:
[1631516476.487847][2301:2309] CHIP:ZCL:   ClusterId: 0x0000_0300
[1631516476.487901][2301:2309] CHIP:ZCL:   attributeId: 0x0000_0001
[1631516476.487948][2301:2309] CHIP:ZCL:   status: Success                (0x0000)
[1631516476.487995][2301:2309] CHIP:ZCL:   attribute TLV Type: 0x04
[1631516476.488050][2301:2309] CHIP:ZCL:   attributeValue: 130
[1631516476.488306][2301:2309] CHIP:DMG: Client[0] moving to [INIT]
[1631516476.488414][2301:2309] CHIP:DMG: Client[0] moving to [UNINIT]
[1631516476.488474][2301:2309] CHIP:EM: Sending Standalone Ack for MsgId:000000E3
AttributeReadResult(path=AttributePath(nodeId=12344321, endpointId=1, clusterId=768, attributeId=1), status=0, value=130)
[1631516476.488724][2301:2309] CHIP:IN: Secure message was encrypted: Msg ID 453
[1631516476.488798][2301:2309] CHIP:IN: Encrypted message 0xffff9e77aaf8 to 0x0000000000BC5C01 of type 16 and protocolId 0 on exchange 39250.
[1631516476.488876][2301:2309] CHIP:IN: Sending msg 0xffff9e77aaf8 to 0x0000000000BC5C01 at utc time: 6279952 msec
[1631516476.488995][2301:2309] CHIP:IN: Sending secure msg on generic transport
chip-device-ctrl > [1631516476.489218][2301:2309] CHIP:IN: Secure msg send status ../../src/inet/IPEndPointBasis.cpp:915: Success
[1631516476.489338][2301:2309] CHIP:EM: Flushed pending ack for MsgId:000000E3
zclread ColorControl CurrentSaturation 12344321 1 0
[1631516478.807126][2301:2309] CHIP:DMG: SendReadRequest: Client[0] [ INIT]
[1631516478.807436][2301:2309] CHIP:IN: Secure message was encrypted: Msg ID 454
[1631516478.807509][2301:2309] CHIP:IN: Encrypted message 0x1ff9eab8 to 0x0000000000BC5C01 of type 2 and protocolId 5 on exchange 39251.
[1631516478.807570][2301:2309] CHIP:IN: Sending msg 0x1ff9eab8 to 0x0000000000BC5C01 at utc time: 6282271 msec
[1631516478.807674][2301:2309] CHIP:IN: Sending secure msg on generic transport
[1631516478.807918][2301:2309] CHIP:IN: Secure msg send status ../../src/inet/IPEndPointBasis.cpp:915: Success
[1631516478.808059][2301:2309] CHIP:DMG: Client[0] moving to [AwaitingResponse]
[1631516478.940399][2301:2309] CHIP:EM: Received message of type 0x05 with vendorId 0x0000 and protocolId 0x0005 on exchange 39251
[1631516478.940580][2301:2309] CHIP:EM: Rxd Ack; Removing MsgId:000001C6 from Retrans Table
[1631516478.940637][2301:2309] CHIP:EM: Removed CHIP MsgId:000001C6 from RetransTable
[1631516478.940749][2301:2309] CHIP:DMG: ReportData =
[1631516478.940814][2301:2309] CHIP:DMG: {
[1631516478.940857][2301:2309] CHIP:DMG:        AttributeDataList =
[1631516478.940986][2301:2309] CHIP:DMG:        [
[1631516478.941041][2301:2309] CHIP:DMG:                AttributeDataElement =
[1631516478.941159][2301:2309] CHIP:DMG:                {
[1631516478.941216][2301:2309] CHIP:DMG:                        AttributePath =
[1631516478.941329][2301:2309] CHIP:DMG:                        {
[1631516478.941408][2301:2309] CHIP:DMG:                                NodeId = 0xbc5c01,
[1631516478.941529][2301:2309] CHIP:DMG:                                EndpointId = 0x1,
[1631516478.941653][2301:2309] CHIP:DMG:                                ClusterId = 0x300,
[1631516478.941725][2301:2309] CHIP:DMG:                                FieldTag = 0x1,
[1631516478.941841][2301:2309] CHIP:DMG:                        }
[1631516478.941965][2301:2309] CHIP:DMG:
[1631516478.942032][2301:2309] CHIP:DMG:                        Data = 130,
[1631516478.942140][2301:2309] CHIP:DMG:                        DataElementVersion = 0x0,
[1631516478.942220][2301:2309] CHIP:DMG:                },
[1631516478.942338][2301:2309] CHIP:DMG:
[1631516478.942428][2301:2309] CHIP:DMG:        ],
[1631516478.942538][2301:2309] CHIP:DMG:
[1631516478.942590][2301:2309] CHIP:DMG: }
[1631516478.943391][2301:2309] CHIP:ZCL: ReadAttributesResponse:
[1631516478.943456][2301:2309] CHIP:ZCL:   ClusterId: 0x0000_0300
[1631516478.943510][2301:2309] CHIP:ZCL:   attributeId: 0x0000_0001
[1631516478.943558][2301:2309] CHIP:ZCL:   status: Success                (0x0000)
[1631516478.943604][2301:2309] CHIP:ZCL:   attribute TLV Type: 0x04
[1631516478.943659][2301:2309] CHIP:ZCL:   attributeValue: 130
[1631516478.943910][2301:2309] CHIP:DMG: Client[0] moving to [INIT]
AttributeReadResult(path=AttributePath(nodeId=12344321, endpointId=1, clusterId=768, attributeId=1), status=0, value=130)
[1631516478.944079][2301:2309] CHIP:DMG: Client[0] moving to [UNINIT]
[1631516478.944161][2301:2309] CHIP:EM: Sending Standalone Ack for MsgId:000000E4
[1631516478.944323][2301:2309] CHIP:IN: Secure message was encrypted: Msg ID 455
[1631516478.944393][2301:2309] CHIP:IN: Encrypted message 0xffff9e77aaf8 to 0x0000000000BC5C01 of type 16 and protocolId 0 on exchange 39251.
[1631516478.944476][2301:2309] CHIP:IN: Sending msg 0xffff9e77aaf8 to 0x0000000000BC5C01 at utc time: 6282407 msec
[1631516478.944588][2301:2309] CHIP:IN: Sending secure msg on generic transport
chip-device-ctrl > [1631516478.944814][2301:2309] CHIP:IN: Secure msg send status ../../src/inet/IPEndPointBasis.cpp:915: Success
[1631516478.944941][2301:2309] CHIP:EM: Flushed pending ack for MsgId:000000E4
zclread ColorControl CurrentSaturation 12344321 1 0
[1631516482.331450][2301:2309] CHIP:DMG: SendReadRequest: Client[0] [ INIT]
[1631516482.331735][2301:2309] CHIP:IN: Secure message was encrypted: Msg ID 456
[1631516482.331799][2301:2309] CHIP:IN: Encrypted message 0x1ff9eab8 to 0x0000000000BC5C01 of type 2 and protocolId 5 on exchange 39252.
[1631516482.331861][2301:2309] CHIP:IN: Sending msg 0x1ff9eab8 to 0x0000000000BC5C01 at utc time: 6285795 msec
[1631516482.331953][2301:2309] CHIP:IN: Sending secure msg on generic transport
[1631516482.332125][2301:2309] CHIP:IN: Secure msg send status ../../src/inet/IPEndPointBasis.cpp:915: Success
[1631516482.332251][2301:2309] CHIP:DMG: Client[0] moving to [AwaitingResponse]
[1631516482.518024][2301:2309] CHIP:EM: Received message of type 0x05 with vendorId 0x0000 and protocolId 0x0005 on exchange 39252
[1631516482.518171][2301:2309] CHIP:EM: Rxd Ack; Removing MsgId:000001C8 from Retrans Table
[1631516482.518227][2301:2309] CHIP:EM: Removed CHIP MsgId:000001C8 from RetransTable
[1631516482.518340][2301:2309] CHIP:DMG: ReportData =
[1631516482.518404][2301:2309] CHIP:DMG: {
[1631516482.518451][2301:2309] CHIP:DMG:        AttributeDataList =
[1631516482.518516][2301:2309] CHIP:DMG:        [
[1631516482.518625][2301:2309] CHIP:DMG:                AttributeDataElement =
[1631516482.518687][2301:2309] CHIP:DMG:                {
[1631516482.518787][2301:2309] CHIP:DMG:                        AttributePath =
[1631516482.518854][2301:2309] CHIP:DMG:                        {
[1631516482.518967][2301:2309] CHIP:DMG:                                NodeId = 0xbc5c01,
[1631516482.519032][2301:2309] CHIP:DMG:                                EndpointId = 0x1,
[1631516482.519155][2301:2309] CHIP:DMG:                                ClusterId = 0x300,
[1631516482.519221][2301:2309] CHIP:DMG:                                FieldTag = 0x1,
[1631516482.519343][2301:2309] CHIP:DMG:                        }
[1631516482.519466][2301:2309] CHIP:DMG:
[1631516482.519531][2301:2309] CHIP:DMG:                        Data = 130,
[1631516482.519647][2301:2309] CHIP:DMG:                        DataElementVersion = 0x0,
[1631516482.519704][2301:2309] CHIP:DMG:                },
[1631516482.519819][2301:2309] CHIP:DMG:
[1631516482.519868][2301:2309] CHIP:DMG:        ],
[1631516482.519981][2301:2309] CHIP:DMG:
[1631516482.520034][2301:2309] CHIP:DMG: }
[1631516482.520979][2301:2309] CHIP:ZCL: ReadAttributesResponse:
[1631516482.521050][2301:2309] CHIP:ZCL:   ClusterId: 0x0000_0300
[1631516482.521105][2301:2309] CHIP:ZCL:   attributeId: 0x0000_0001
[1631516482.521153][2301:2309] CHIP:ZCL:   status: Success                (0x0000)
[1631516482.521199][2301:2309] CHIP:ZCL:   attribute TLV Type: 0x04
[1631516482.521254][2301:2309] CHIP:ZCL:   attributeValue: 130
[1631516482.521496][2301:2309] CHIP:DMG: Client[0] moving to [INIT]
[1631516482.521601][2301:2309] CHIP:DMG: Client[0] moving to [UNINIT]
[1631516482.521670][2301:2309] CHIP:EM: Sending Standalone Ack for MsgId:000000E5
AttributeReadResult(path=AttributePath(nodeId=12344321, endpointId=1, clusterId=768, attributeId=1), status=0, value=130)
[1631516482.521897][2301:2309] CHIP:IN: Secure message was encrypted: Msg ID 457
[1631516482.521970][2301:2309] CHIP:IN: Encrypted message 0xffff9e77aaf8 to 0x0000000000BC5C01 of type 16 and protocolId 0 on exchange 39252.
[1631516482.522041][2301:2309] CHIP:IN: Sending msg 0xffff9e77aaf8 to 0x0000000000BC5C01 at utc time: 6285985 msec
[1631516482.522093][2301:2309] CHIP:IN: Sending secure msg on generic transport
chip-device-ctrl > [1631516482.522312][2301:2309] CHIP:IN: Secure msg send status ../../src/inet/IPEndPointBasis.cpp:915: Success
[1631516482.522434][2301:2309] CHIP:EM: Flushed pending ack for MsgId:000000E5

Test on te6, still failed , set 30sec, but was 45~50sec, for test log:
'''
3.2.2. [TC-CC-3.1] Hue MoveTo functionality with server as DUT
************step1
chip-device-ctrl > zclread ColorControl CurrentHue 12344321 1 0
[1634191083.950794][4649:4656] CHIP:DMG: SendReadRequest: Client[0] [ INIT]
[1634191083.951116][4649:4656] CHIP:IN: Secure message was encrypted: Msg ID 58
[1634191083.951189][4649:4656] CHIP:IN: Build encrypted message 0x7062258 to 0x0000000000BC5C01 of type 2 and protocolId 1 on exchange 11550r with MessageCounter 58.
[1634191083.951273][4649:4656] CHIP:IN: Sending encrypted msg 0x7062258 to 0x0000000000BC5C01 at utc time: 5977097 msec
[1634191083.951338][4649:4656] CHIP:IN: Sending msg on generic transport
[1634191083.951614][4649:4656] CHIP:DMG: Client[0] moving to [AwaitingInitialReport]
[1634191084.104240][4649:4656] CHIP:EM: Received message of type 0x05 with vendorId 0x0000 and protocolId 0x0001 on exchange 11550i
[1634191084.104390][4649:4656] CHIP:EM: Rxd Ack; Removing MessageCounter:0000003A from Retrans Table
[1634191084.104445][4649:4656] CHIP:EM: Removed CHIP MessageCounter:0000003A from RetransTable
[1634191084.104546][4649:4656] CHIP:DMG: ReportData =
[1634191084.104606][4649:4656] CHIP:DMG: {
[1634191084.104653][4649:4656] CHIP:DMG:        AttributeDataList =
[1634191084.104709][4649:4656] CHIP:DMG:        [
[1634191084.104764][4649:4656] CHIP:DMG:                AttributeDataElement =
[1634191084.104827][4649:4656] CHIP:DMG:                {
[1634191084.104883][4649:4656] CHIP:DMG:                        AttributePath =
[1634191084.104994][4649:4656] CHIP:DMG:                        {
[1634191084.105061][4649:4656] CHIP:DMG:                                NodeId = 0xbc5c01,
[1634191084.105146][4649:4656] CHIP:DMG:                                EndpointId = 0x1,
[1634191084.105225][4649:4656] CHIP:DMG:                                ClusterId = 0x300,
[1634191084.105310][4649:4656] CHIP:DMG:                                FieldTag = 0x0,
[1634191084.105382][4649:4656] CHIP:DMG:                        }
[1634191084.105471][4649:4656] CHIP:DMG:
[1634191084.105557][4649:4656] CHIP:DMG:                        Data = 0,
[1634191084.105632][4649:4656] CHIP:DMG:                        DataElementVersion = 0x0,
[1634191084.105693][4649:4656] CHIP:DMG:                },
[1634191084.105771][4649:4656] CHIP:DMG:
[1634191084.105833][4649:4656] CHIP:DMG:        ],
[1634191084.105909][4649:4656] CHIP:DMG:
[1634191084.105968][4649:4656] CHIP:DMG: }
[1634191084.106759][4649:4656] CHIP:ZCL: ReadAttributesResponse:
[1634191084.106838][4649:4656] CHIP:ZCL:   ClusterId: 0x0000_0300
[1634191084.106901][4649:4656] CHIP:ZCL:   attributeId: 0x0000_0000
[1634191084.106956][4649:4656] CHIP:ZCL:   status: Success                (0x0000)
[1634191084.107010][4649:4656] CHIP:ZCL:   attribute TLV Type: 0x04
[1634191084.107077][4649:4656] CHIP:ZCL:   attributeValue: 0
[1634191084.107338][4649:4656] CHIP:EM: Piggybacking Ack for MessageCounter:00000038 on exchange: 11550i
AttributeReadResult(path=AttributePath(nodeId=12344321, endpointId=1, clusterId=768, attributeId=0), status=0, value=0)
[1634191084.107529][4649:4656] CHIP:IN: Secure message was encrypted: Msg ID 59
[1634191084.107603][4649:4656] CHIP:IN: Build encrypted message 0x7062258 to 0x0000000000BC5C01 of type 1 and protocolId 1 on exchange 11550r with MessageCounter 59.
[1634191084.107690][4649:4656] CHIP:IN: Sending encrypted msg 0x7062258 to 0x0000000000BC5C01 at utc time: 5977253 msec
[1634191084.107754][4649:4656] CHIP:IN: Sending msg on generic transport
chip-device-ctrl > [1634191084.108071][4649:4656] CHIP:DMG: Client[0] moving to [UNINIT]
[1634191084.200575][4649:4656] CHIP:EM: Received message of type 0x10 with vendorId 0x0000 and protocolId 0x0000 on exchange 11550i
[1634191084.200736][4649:4656] CHIP:EM: Rxd Ack; Removing MessageCounter:0000003B from Retrans Table
[1634191084.200801][4649:4656] CHIP:EM: Removed CHIP MessageCounter:0000003B from RetransTable
************step2a
chip-device-ctrl > zcl ColorControl MoveToHue 12344321 1 0 hue=1 direction=0 transitionTime=300 optionsMask=1 optionsOverride=1
[1634191838.361651][4649:4656] CHIP:DMG: ICR moving to [Initialize]
[1634191838.361761][4649:4656] CHIP:DMG: ICR moving to [AddCommand]
[1634191838.361991][4649:4656] CHIP:IN: Secure message was encrypted: Msg ID 60
[1634191838.362054][4649:4656] CHIP:IN: Build encrypted message 0x7062258 to 0x0000000000BC5C01 of type 8 and protocolId 1 on exchange 11551r with MessageCounter 60.
[1634191838.362123][4649:4656] CHIP:IN: Sending encrypted msg 0x7062258 to 0x0000000000BC5C01 at utc time: 6731507 msec
[1634191838.362223][4649:4656] CHIP:IN: Sending msg on generic transport
[1634191838.362497][4649:4656] CHIP:DMG: ICR moving to [   Sending]
[1634191838.726122][4649:4656] CHIP:EM: Received message of type 0x09 with vendorId 0x0000 and protocolId 0x0001 on exchange 11551i
[1634191838.726321][4649:4656] CHIP:EM: Rxd Ack; Removing MessageCounter:0000003C from Retrans Table
[1634191838.726388][4649:4656] CHIP:EM: Removed CHIP MessageCounter:0000003C from RetransTable
[1634191838.726500][4649:4656] CHIP:DMG: InvokeCommand =
[1634191838.726570][4649:4656] CHIP:DMG: {
[1634191838.726626][4649:4656] CHIP:DMG:        CommandList =
[1634191838.726690][4649:4656] CHIP:DMG:        [
[1634191838.726752][4649:4656] CHIP:DMG:                CommandDataElement =
[1634191838.726828][4649:4656] CHIP:DMG:                {
[1634191838.726898][4649:4656] CHIP:DMG:                        CommandPath =
[1634191838.726997][4649:4656] CHIP:DMG:                        {
[1634191838.727076][4649:4656] CHIP:DMG:                                EndpointId = 0x1,
[1634191838.727161][4649:4656] CHIP:DMG:                                ClusterId = 0x300,
[1634191838.727249][4649:4656] CHIP:DMG:                                CommandId = 0x0,
[1634191838.727340][4649:4656] CHIP:DMG:                        },
[1634191838.727424][4649:4656] CHIP:DMG:
[1634191838.727499][4649:4656] CHIP:DMG:                        StatusElement =
[1634191838.727580][4649:4656] CHIP:DMG:                        {
[1634191838.727646][4649:4656] CHIP:DMG:                                GeneralCode = 0x0,
[1634191838.727736][4649:4656] CHIP:DMG:                                ProtocolId = 0x1,
[1634191838.727828][4649:4656] CHIP:DMG:                                protocolCode = 0x0,
[1634191838.727916][4649:4656] CHIP:DMG:                        },
[1634191838.727998][4649:4656] CHIP:DMG:
[1634191838.728064][4649:4656] CHIP:DMG:                },
[1634191838.728149][4649:4656] CHIP:DMG:
[1634191838.728214][4649:4656] CHIP:DMG:        ],
[1634191838.728291][4649:4656] CHIP:DMG:
[1634191838.728348][4649:4656] CHIP:DMG: }
SetCommandIndexStatus commandHandle=1 commandIndex=1
[1634191838.728985][4649:4656] CHIP:ZCL: DefaultResponse:
[1634191838.729047][4649:4656] CHIP:ZCL:   Transaction: 0xffffbb796240
[1634191838.729102][4649:4656] CHIP:ZCL:   status: EMBER_ZCL_STATUS_SUCCESS (0x00)
[1634191838.729161][4649:4656] CHIP:ZCL: IMDefaultResponseCallback: Missing success callback
[1634191838.729214][4649:4656] CHIP:ZCL: IMDefaultResponseCallback: Missing failure callback
[1634191838.729391][4649:4656] CHIP:DMG: ICR moving to [Uninitiali]
Received command status response:
[1634191838.729475][4649:4656] CHIP:EM: Sending Standalone Ack for MessageCounter:0000003A
[1634191838.729678][4649:4656] CHIP:IN: Secure message was encrypted: Msg ID 61
Container:
ProtocolId = 1
ProtocolCode = 0
EndpointId = 1
ClusterId = 768
CommandId = 0
CommandIndex = 1[1634191838.729746][4649:4656] CHIP:IN: Build encrypted message 0xffffabf7dad0 to 0x0000000000BC5C01 of type 16 and protocolId 0 on exchange 11551r with MessageCounter 61.
[1634191838.729922][4649:4656] CHIP:IN: Sending encrypted msg 0xffffabf7dad0 to 0x0000000000BC5C01 at utc time: 6731875 msec
[1634191838.729993][4649:4656] CHIP:IN: Sending msg on generic transport
[1634191838.730279][4649:4656] CHIP:EM: Flushed pending ack for MessageCounter:0000003A
chip-device-ctrl > zclread ColorControl CurrentHue 12344321 1 0
[1634191844.103113][4649:4656] CHIP:DMG: SendReadRequest: Client[0] [ INIT]
[1634191844.103432][4649:4656] CHIP:IN: Secure message was encrypted: Msg ID 62
[1634191844.103507][4649:4656] CHIP:IN: Build encrypted message 0x7062258 to 0x0000000000BC5C01 of type 2 and protocolId 1 on exchange 11552r with MessageCounter 62.
[1634191844.103585][4649:4656] CHIP:IN: Sending encrypted msg 0x7062258 to 0x0000000000BC5C01 at utc time: 6737249 msec
[1634191844.103638][4649:4656] CHIP:IN: Sending msg on generic transport
[1634191844.103890][4649:4656] CHIP:DMG: Client[0] moving to [AwaitingInitialReport]
[1634191844.251689][4649:4656] CHIP:EM: Received message of type 0x05 with vendorId 0x0000 and protocolId 0x0001 on exchange 11552i
[1634191844.251829][4649:4656] CHIP:EM: Rxd Ack; Removing MessageCounter:0000003E from Retrans Table
[1634191844.251880][4649:4656] CHIP:EM: Removed CHIP MessageCounter:0000003E from RetransTable
[1634191844.251976][4649:4656] CHIP:DMG: ReportData =
[1634191844.252032][4649:4656] CHIP:DMG: {
[1634191844.252076][4649:4656] CHIP:DMG:        AttributeDataList =
[1634191844.252223][4649:4656] CHIP:DMG:        [
[1634191844.252272][4649:4656] CHIP:DMG:                AttributeDataElement =
[1634191844.252361][4649:4656] CHIP:DMG:                {
[1634191844.252413][4649:4656] CHIP:DMG:                        AttributePath =
[1634191844.252479][4649:4656] CHIP:DMG:                        {
[1634191844.252562][4649:4656] CHIP:DMG:                                NodeId = 0xbc5c01,
[1634191844.252623][4649:4656] CHIP:DMG:                                EndpointId = 0x1,
[1634191844.252722][4649:4656] CHIP:DMG:                                ClusterId = 0x300,
[1634191844.252776][4649:4656] CHIP:DMG:                                FieldTag = 0x0,
[1634191844.252867][4649:4656] CHIP:DMG:                        }
[1634191844.252968][4649:4656] CHIP:DMG:
[1634191844.253025][4649:4656] CHIP:DMG:                        Data = 1,
[1634191844.253114][4649:4656] CHIP:DMG:                        DataElementVersion = 0x0,
[1634191844.253160][4649:4656] CHIP:DMG:                },
[1634191844.253252][4649:4656] CHIP:DMG:
[1634191844.253300][4649:4656] CHIP:DMG:        ],
[1634191844.253357][4649:4656] CHIP:DMG:
[1634191844.253400][4649:4656] CHIP:DMG: }
[1634191844.253982][4649:4656] CHIP:ZCL: ReadAttributesResponse:
[1634191844.254048][4649:4656] CHIP:ZCL:   ClusterId: 0x0000_0300
[1634191844.254099][4649:4656] CHIP:ZCL:   attributeId: 0x0000_0000
[1634191844.254140][4649:4656] CHIP:ZCL:   status: Success                (0x0000)
[1634191844.254218][4649:4656] CHIP:ZCL:   attribute TLV Type: 0x04
[1634191844.254276][4649:4656] CHIP:ZCL:   attributeValue: 1
[1634191844.254523][4649:4656] CHIP:EM: Piggybacking Ack for MessageCounter:0000003B on exchange: 11552i
AttributeReadResult(path=AttributePath(nodeId=12344321, endpointId=1, clusterId=768, attributeId=0), status=0, value=1)
[1634191844.254680][4649:4656] CHIP:IN: Secure message was encrypted: Msg ID 63
[1634191844.254748][4649:4656] CHIP:IN: Build encrypted message 0x7062258 to 0x0000000000BC5C01 of type 1 and protocolId 1 on exchange 11552r with MessageCounter 63.
[1634191844.254822][4649:4656] CHIP:IN: Sending encrypted msg 0x7062258 to 0x0000000000BC5C01 at utc time: 6737400 msec
[1634191844.254872][4649:4656] CHIP:IN: Sending msg on generic transport
chip-device-ctrl > [1634191844.255187][4649:4656] CHIP:DMG: Client[0] moving to [UNINIT]
[1634191844.339969][4649:4656] CHIP:EM: Received message of type 0x10 with vendorId 0x0000 and protocolId 0x0000 on exchange 11552i
[1634191844.340126][4649:4656] CHIP:EM: Rxd Ack; Removing MessageCounter:0000003F from Retrans Table
[1634191844.340192][4649:4656] CHIP:EM: Removed CHIP MessageCounter:0000003F from RetransTable
************step2b
chip-device-ctrl > zclread ColorControl CurrentHue 12344321 1 0
[1634191869.038763][4649:4656] CHIP:DMG: SendReadRequest: Client[0] [ INIT]
[1634191869.039017][4649:4656] CHIP:IN: Secure message was encrypted: Msg ID 64
[1634191869.039070][4649:4656] CHIP:IN: Build encrypted message 0x7062258 to 0x0000000000BC5C01 of type 2 and protocolId 1 on exchange 11553r with MessageCounter 64.
[1634191869.039174][4649:4656] CHIP:IN: Sending encrypted msg 0x7062258 to 0x0000000000BC5C01 at utc time: 6762184 msec
[1634191869.039218][4649:4656] CHIP:IN: Sending msg on generic transport
[1634191869.039459][4649:4656] CHIP:DMG: Client[0] moving to [AwaitingInitialReport]
[1634191869.221573][4649:4656] CHIP:EM: Received message of type 0x05 with vendorId 0x0000 and protocolId 0x0001 on exchange 11553i
[1634191869.221709][4649:4656] CHIP:EM: Rxd Ack; Removing MessageCounter:00000040 from Retrans Table
[1634191869.221758][4649:4656] CHIP:EM: Removed CHIP MessageCounter:00000040 from RetransTable
[1634191869.221850][4649:4656] CHIP:DMG: ReportData =
[1634191869.221903][4649:4656] CHIP:DMG: {
[1634191869.221945][4649:4656] CHIP:DMG:        AttributeDataList =
[1634191869.222017][4649:4656] CHIP:DMG:        [
[1634191869.222087][4649:4656] CHIP:DMG:                AttributeDataElement =
[1634191869.222137][4649:4656] CHIP:DMG:                {
[1634191869.222241][4649:4656] CHIP:DMG:                        AttributePath =
[1634191869.222301][4649:4656] CHIP:DMG:                        {
[1634191869.222397][4649:4656] CHIP:DMG:                                NodeId = 0xbc5c01,
[1634191869.222473][4649:4656] CHIP:DMG:                                EndpointId = 0x1,
[1634191869.222748][4649:4656] CHIP:DMG:                                ClusterId = 0x300,
[1634191869.222898][4649:4656] CHIP:DMG:                                FieldTag = 0x0,
[1634191869.222971][4649:4656] CHIP:DMG:                        }
[1634191869.223103][4649:4656] CHIP:DMG:
[1634191869.223228][4649:4656] CHIP:DMG:                        Data = 1,
[1634191869.223302][4649:4656] CHIP:DMG:                        DataElementVersion = 0x0,
[1634191869.223415][4649:4656] CHIP:DMG:                },
[1634191869.223495][4649:4656] CHIP:DMG:
[1634191869.223592][4649:4656] CHIP:DMG:        ],
[1634191869.223669][4649:4656] CHIP:DMG:
[1634191869.223728][4649:4656] CHIP:DMG: }
[1634191869.224427][4649:4656] CHIP:ZCL: ReadAttributesResponse:
[1634191869.224506][4649:4656] CHIP:ZCL:   ClusterId: 0x0000_0300
[1634191869.224570][4649:4656] CHIP:ZCL:   attributeId: 0x0000_0000
[1634191869.224626][4649:4656] CHIP:ZCL:   status: Success                (0x0000)
[1634191869.224679][4649:4656] CHIP:ZCL:   attribute TLV Type: 0x04
[1634191869.224746][4649:4656] CHIP:ZCL:   attributeValue: 1
[1634191869.225007][4649:4656] CHIP:EM: Piggybacking Ack for MessageCounter:0000003D on exchange: 11553i
AttributeReadResult(path=AttributePath(nodeId=12344321, endpointId=1, clusterId=768, attributeId=0), status=0, value=1)
[1634191869.225183][4649:4656] CHIP:IN: Secure message was encrypted: Msg ID 65
[1634191869.225259][4649:4656] CHIP:IN: Build encrypted message 0x7062258 to 0x0000000000BC5C01 of type 1 and protocolId 1 on exchange 11553r with MessageCounter 65.
[1634191869.225347][4649:4656] CHIP:IN: Sending encrypted msg 0x7062258 to 0x0000000000BC5C01 at utc time: 6762371 msec
[1634191869.225413][4649:4656] CHIP:IN: Sending msg on generic transport
chip-device-ctrl > [1634191869.225771][4649:4656] CHIP:DMG: Client[0] moving to [UNINIT]
[1634191869.307756][4649:4656] CHIP:EM: Received message of type 0x10 with vendorId 0x0000 and protocolId 0x0000 on exchange 11553i
[1634191869.307878][4649:4656] CHIP:EM: Rxd Ack; Removing MessageCounter:00000041 from Retrans Table
[1634191869.307922][4649:4656] CHIP:EM: Removed CHIP MessageCounter:00000041 from RetransTable
[1634191883.434875][4649:4653] CHIP:DL: Got IP address on interface: wlan0 IP: <IP_ADDRESS>
[1634191883.435334][4649:4656] CHIP:DL: HandlePlatformSpecificBLEEvent 32770
************step3a
chip-device-ctrl > zcl ColorControl MoveToHue 12344321 1 0 hue=150 direction=1 transitionTime=300 optionsMask=1 optionsOverride=1
[1634191922.300592][4649:4656] CHIP:DMG: ICR moving to [Initialize]
[1634191922.300717][4649:4656] CHIP:DMG: ICR moving to [AddCommand]
[1634191922.300970][4649:4656] CHIP:IN: Secure message was encrypted: Msg ID 66
[1634191922.301043][4649:4656] CHIP:IN: Build encrypted message 0x7062258 to 0x0000000000BC5C01 of type 8 and protocolId 1 on exchange 11554r with MessageCounter 66.
[1634191922.301131][4649:4656] CHIP:IN: Sending encrypted msg 0x7062258 to 0x0000000000BC5C01 at utc time: 6815446 msec
[1634191922.301196][4649:4656] CHIP:IN: Sending msg on generic transport
[1634191922.301466][4649:4656] CHIP:DMG: ICR moving to [   Sending]
[1634191922.522899][4649:4656] CHIP:EM: Received message of type 0x09 with vendorId 0x0000 and protocolId 0x0001 on exchange 11554i
[1634191922.523003][4649:4656] CHIP:EM: Rxd Ack; Removing MessageCounter:00000042 from Retrans Table
[1634191922.523035][4649:4656] CHIP:EM: Removed CHIP MessageCounter:00000042 from RetransTable
[1634191922.523100][4649:4656] CHIP:DMG: InvokeCommand =
[1634191922.523134][4649:4656] CHIP:DMG: {
[1634191922.523160][4649:4656] CHIP:DMG:        CommandList =
[1634191922.523189][4649:4656] CHIP:DMG:        [
[1634191922.523218][4649:4656] CHIP:DMG:                CommandDataElement =
[1634191922.523258][4649:4656] CHIP:DMG:                {
[1634191922.523292][4649:4656] CHIP:DMG:                        CommandPath =
[1634191922.523324][4649:4656] CHIP:DMG:                        {
[1634191922.523369][4649:4656] CHIP:DMG:                                EndpointId = 0x1,
[1634191922.523412][4649:4656] CHIP:DMG:                                ClusterId = 0x300,
[1634191922.523454][4649:4656] CHIP:DMG:                                CommandId = 0x0,
[1634191922.523490][4649:4656] CHIP:DMG:                        },
[1634191922.523536][4649:4656] CHIP:DMG:
[1634191922.523571][4649:4656] CHIP:DMG:                        StatusElement =
[1634191922.523609][4649:4656] CHIP:DMG:                        {
[1634191922.523646][4649:4656] CHIP:DMG:                                GeneralCode = 0x0,
[1634191922.523691][4649:4656] CHIP:DMG:                                ProtocolId = 0x1,
[1634191922.523731][4649:4656] CHIP:DMG:                                protocolCode = 0x0,
[1634191922.523772][4649:4656] CHIP:DMG:                        },
[1634191922.523805][4649:4656] CHIP:DMG:
[1634191922.523838][4649:4656] CHIP:DMG:                },
[1634191922.523877][4649:4656] CHIP:DMG:
[1634191922.523905][4649:4656] CHIP:DMG:        ],
[1634191922.523941][4649:4656] CHIP:DMG:
[1634191922.523967][4649:4656] CHIP:DMG: }
SetCommandIndexStatus commandHandle=1 commandIndex=1
[1634191922.524351][4649:4656] CHIP:ZCL: DefaultResponse:
[1634191922.524382][4649:4656] CHIP:ZCL:   Transaction: 0xffffbb796240
[1634191922.524407][4649:4656] CHIP:ZCL:   status: EMBER_ZCL_STATUS_SUCCESS (0x00)
[1634191922.524435][4649:4656] CHIP:ZCL: IMDefaultResponseCallback: Missing success callback
[1634191922.524459][4649:4656] CHIP:ZCL: IMDefaultResponseCallback: Missing failure callback
[1634191922.524558][4649:4656] CHIP:DMG: ICR moving to [Uninitiali]
[1634191922.524602][4649:4656] CHIP:EM: Sending Standalone Ack for MessageCounter:0000003F
Received command status response:
[1634191922.524707][4649:4656] CHIP:IN: Secure message was encrypted: Msg ID 67
[1634191922.524740][4649:4656] CHIP:IN: Build encrypted message 0xffffabf7dad0 to 0x0000000000BC5C01 of type 16 and protocolId 0 on exchange 11554r with MessageCounter 67.
Container:
ProtocolId = 1
ProtocolCode = 0
EndpointId = 1
ClusterId = 768
CommandId = 0
CommandIndex = 1[1634191922.524784][4649:4656] CHIP:IN: Sending encrypted msg 0xffffabf7dad0 to 0x0000000000BC5C01 at utc time: 6815670 msec
[1634191922.524846][4649:4656] CHIP:IN: Sending msg on generic transport
[1634191922.525012][4649:4656] CHIP:EM: Flushed pending ack for MessageCounter:0000003F
************step3b
chip-device-ctrl > zclread ColorControl CurrentHue 12344321 1 0
[1634191928.813428][4649:4656] CHIP:DMG: SendReadRequest: Client[0] [ INIT]
[1634191928.813698][4649:4656] CHIP:IN: Secure message was encrypted: Msg ID 68
[1634191928.813754][4649:4656] CHIP:IN: Build encrypted message 0x7062258 to 0x0000000000BC5C01 of type 2 and protocolId 1 on exchange 11555r with MessageCounter 68.
[1634191928.813817][4649:4656] CHIP:IN: Sending encrypted msg 0x7062258 to 0x0000000000BC5C01 at utc time: 6821959 msec
[1634191928.813865][4649:4656] CHIP:IN: Sending msg on generic transport
[1634191928.814098][4649:4656] CHIP:DMG: Client[0] moving to [AwaitingInitialReport]
[1634191929.100961][4649:4656] CHIP:EM: Received message of type 0x05 with vendorId 0x0000 and protocolId 0x0001 on exchange 11555i
[1634191929.101097][4649:4656] CHIP:EM: Rxd Ack; Removing MessageCounter:00000044 from Retrans Table
[1634191929.101147][4649:4656] CHIP:EM: Removed CHIP MessageCounter:00000044 from RetransTable
[1634191929.101238][4649:4656] CHIP:DMG: ReportData =
[1634191929.101292][4649:4656] CHIP:DMG: {
[1634191929.101335][4649:4656] CHIP:DMG:        AttributeDataList =
[1634191929.101381][4649:4656] CHIP:DMG:        [
[1634191929.101428][4649:4656] CHIP:DMG:                AttributeDataElement =
[1634191929.101493][4649:4656] CHIP:DMG:                {
[1634191929.101543][4649:4656] CHIP:DMG:                        AttributePath =
[1634191929.101606][4649:4656] CHIP:DMG:                        {
[1634191929.101669][4649:4656] CHIP:DMG:                                NodeId = 0xbc5c01,
[1634191929.101743][4649:4656] CHIP:DMG:                                EndpointId = 0x1,
[1634191929.101816][4649:4656] CHIP:DMG:                                ClusterId = 0x300,
[1634191929.101886][4649:4656] CHIP:DMG:                                FieldTag = 0x0,
[1634191929.101953][4649:4656] CHIP:DMG:                        }
[1634191929.102021][4649:4656] CHIP:DMG:
[1634191929.102086][4649:4656] CHIP:DMG:                        Data = 26,
[1634191929.102156][4649:4656] CHIP:DMG:                        DataElementVersion = 0x0,
[1634191929.102285][4649:4656] CHIP:DMG:                },
[1634191929.102371][4649:4656] CHIP:DMG:
[1634191929.102430][4649:4656] CHIP:DMG:        ],
[1634191929.102505][4649:4656] CHIP:DMG:
[1634191929.102563][4649:4656] CHIP:DMG: }
[1634191929.103268][4649:4656] CHIP:ZCL: ReadAttributesResponse:
[1634191929.103348][4649:4656] CHIP:ZCL:   ClusterId: 0x0000_0300
[1634191929.103411][4649:4656] CHIP:ZCL:   attributeId: 0x0000_0000
[1634191929.103466][4649:4656] CHIP:ZCL:   status: Success                (0x0000)
[1634191929.103520][4649:4656] CHIP:ZCL:   attribute TLV Type: 0x04
[1634191929.103588][4649:4656] CHIP:ZCL:   attributeValue: 26
[1634191929.103856][4649:4656] CHIP:EM: Piggybacking Ack for MessageCounter:00000040 on exchange: 11555i
AttributeReadResult(path=AttributePath(nodeId=12344321, endpointId=1, clusterId=768, attributeId=0), status=0, value=26)
[1634191929.104043][4649:4656] CHIP:IN: Secure message was encrypted: Msg ID 69
[1634191929.104117][4649:4656] CHIP:IN: Build encrypted message 0x7062258 to 0x0000000000BC5C01 of type 1 and protocolId 1 on exchange 11555r with MessageCounter 69.
[1634191929.104202][4649:4656] CHIP:IN: Sending encrypted msg 0x7062258 to 0x0000000000BC5C01 at utc time: 6822250 msec
[1634191929.104267][4649:4656] CHIP:IN: Sending msg on generic transport
chip-device-ctrl > [1634191929.104573][4649:4656] CHIP:DMG: Client[0] moving to [UNINIT]
[1634191929.296455][4649:4656] CHIP:EM: Received message of type 0x10 with vendorId 0x0000 and protocolId 0x0000 on exchange 11555i
[1634191929.296621][4649:4656] CHIP:EM: Rxd Ack; Removing MessageCounter:00000045 from Retrans Table
[1634191929.296687][4649:4656] CHIP:EM: Removed CHIP MessageCounter:00000045 from RetransTable
chip-device-ctrl > zclread ColorControl CurrentHue 12344321 1 0
[1634191939.202463][4649:4656] CHIP:DMG: SendReadRequest: Client[0] [ INIT]
[1634191939.202782][4649:4656] CHIP:IN: Secure message was encrypted: Msg ID 70
[1634191939.202856][4649:4656] CHIP:IN: Build encrypted message 0x7062258 to 0x0000000000BC5C01 of type 2 and protocolId 1 on exchange 11556r with MessageCounter 70.
[1634191939.202937][4649:4656] CHIP:IN: Sending encrypted msg 0x7062258 to 0x0000000000BC5C01 at utc time: 6832348 msec
[1634191939.203001][4649:4656] CHIP:IN: Sending msg on generic transport
[1634191939.203240][4649:4656] CHIP:DMG: Client[0] moving to [AwaitingInitialReport]
[1634191939.418414][4649:4656] CHIP:EM: Received message of type 0x05 with vendorId 0x0000 and protocolId 0x0001 on exchange 11556i
[1634191939.418582][4649:4656] CHIP:EM: Rxd Ack; Removing MessageCounter:00000046 from Retrans Table
[1634191939.418648][4649:4656] CHIP:EM: Removed CHIP MessageCounter:00000046 from RetransTable
[1634191939.418763][4649:4656] CHIP:DMG: ReportData =
[1634191939.418834][4649:4656] CHIP:DMG: {
[1634191939.418890][4649:4656] CHIP:DMG:        AttributeDataList =
[1634191939.418955][4649:4656] CHIP:DMG:        [
[1634191939.419017][4649:4656] CHIP:DMG:                AttributeDataElement =
[1634191939.419092][4649:4656] CHIP:DMG:                {
[1634191939.419163][4649:4656] CHIP:DMG:                        AttributePath =
[1634191939.419251][4649:4656] CHIP:DMG:                        {
[1634191939.419339][4649:4656] CHIP:DMG:                                NodeId = 0xbc5c01,
[1634191939.419424][4649:4656] CHIP:DMG:                                EndpointId = 0x1,
[1634191939.419509][4649:4656] CHIP:DMG:                                ClusterId = 0x300,
[1634191939.419606][4649:4656] CHIP:DMG:                                FieldTag = 0x0,
[1634191939.419679][4649:4656] CHIP:DMG:                        }
[1634191939.419777][4649:4656] CHIP:DMG:
[1634191939.419861][4649:4656] CHIP:DMG:                        Data = 66,
[1634191939.419942][4649:4656] CHIP:DMG:                        DataElementVersion = 0x0,
[1634191939.420028][4649:4656] CHIP:DMG:                },
[1634191939.420108][4649:4656] CHIP:DMG:
[1634191939.420172][4649:4656] CHIP:DMG:        ],
[1634191939.420248][4649:4656] CHIP:DMG:
[1634191939.420305][4649:4656] CHIP:DMG: }
[1634191939.420996][4649:4656] CHIP:ZCL: ReadAttributesResponse:
[1634191939.421073][4649:4656] CHIP:ZCL:   ClusterId: 0x0000_0300
[1634191939.421136][4649:4656] CHIP:ZCL:   attributeId: 0x0000_0000
[1634191939.421191][4649:4656] CHIP:ZCL:   status: Success                (0x0000)
[1634191939.421245][4649:4656] CHIP:ZCL:   attribute TLV Type: 0x04
[1634191939.421314][4649:4656] CHIP:ZCL:   attributeValue: 66
[1634191939.421592][4649:4656] CHIP:EM: Piggybacking Ack for MessageCounter:00000042 on exchange: 11556i
AttributeReadResult(path=AttributePath(nodeId=12344321, endpointId=1, clusterId=768, attributeId=0), status=0, value=66)
[1634191939.421788][4649:4656] CHIP:IN: Secure message was encrypted: Msg ID 71
[1634191939.421858][4649:4656] CHIP:IN: Build encrypted message 0x7062258 to 0x0000000000BC5C01 of type 1 and protocolId 1 on exchange 11556r with MessageCounter 71.
[1634191939.421944][4649:4656] CHIP:IN: Sending encrypted msg 0x7062258 to 0x0000000000BC5C01 at utc time: 6832567 msec
[1634191939.422008][4649:4656] CHIP:IN: Sending msg on generic transport
chip-device-ctrl > [1634191939.422369][4649:4656] CHIP:DMG: Client[0] moving to [UNINIT]
[1634191939.624590][4649:4656] CHIP:EM: Received message of type 0x10 with vendorId 0x0000 and protocolId 0x0000 on exchange 11556i
[1634191939.624760][4649:4656] CHIP:EM: Rxd Ack; Removing MessageCounter:00000047 from Retrans Table
[1634191939.624826][4649:4656] CHIP:EM: Removed CHIP MessageCounter:00000047 from RetransTable
chip-device-ctrl > zclread ColorControl CurrentHue 12344321 1 0
[1634191953.101050][4649:4656] CHIP:DMG: SendReadRequest: Client[0] [ INIT]
[1634191953.101261][4649:4656] CHIP:IN: Secure message was encrypted: Msg ID 72
[1634191953.101299][4649:4656] CHIP:IN: Build encrypted message 0x7062258 to 0x0000000000BC5C01 of type 2 and protocolId 1 on exchange 11557r with MessageCounter 72.
[1634191953.101380][4649:4656] CHIP:IN: Sending encrypted msg 0x7062258 to 0x0000000000BC5C01 at utc time: 6846247 msec
[1634191953.101408][4649:4656] CHIP:IN: Sending msg on generic transport
[1634191953.101623][4649:4656] CHIP:DMG: Client[0] moving to [AwaitingInitialReport]
[1634191953.221059][4649:4656] CHIP:EM: Received message of type 0x05 with vendorId 0x0000 and protocolId 0x0001 on exchange 11557i
[1634191953.221199][4649:4656] CHIP:EM: Rxd Ack; Removing MessageCounter:00000048 from Retrans Table
[1634191953.221249][4649:4656] CHIP:EM: Removed CHIP MessageCounter:00000048 from RetransTable
[1634191953.221342][4649:4656] CHIP:DMG: ReportData =
[1634191953.221397][4649:4656] CHIP:DMG: {
[1634191953.221439][4649:4656] CHIP:DMG:        AttributeDataList =
[1634191953.221487][4649:4656] CHIP:DMG:        [
[1634191953.221534][4649:4656] CHIP:DMG:                AttributeDataElement =
[1634191953.221598][4649:4656] CHIP:DMG:                {
[1634191953.221651][4649:4656] CHIP:DMG:                        AttributePath =
[1634191953.221722][4649:4656] CHIP:DMG:                        {
[1634191953.221794][4649:4656] CHIP:DMG:                                NodeId = 0xbc5c01,
[1634191953.221861][4649:4656] CHIP:DMG:                                EndpointId = 0x1,
[1634191953.221929][4649:4656] CHIP:DMG:                                ClusterId = 0x300,
[1634191953.221999][4649:4656] CHIP:DMG:                                FieldTag = 0x0,
[1634191953.222048][4649:4656] CHIP:DMG:                        }
[1634191953.222116][4649:4656] CHIP:DMG:
[1634191953.222248][4649:4656] CHIP:DMG:                        Data = 118,
[1634191953.222317][4649:4656] CHIP:DMG:                        DataElementVersion = 0x0,
[1634191953.222374][4649:4656] CHIP:DMG:                },
[1634191953.222435][4649:4656] CHIP:DMG:
[1634191953.222482][4649:4656] CHIP:DMG:        ],
[1634191953.222539][4649:4656] CHIP:DMG:
[1634191953.222582][4649:4656] CHIP:DMG: }
[1634191953.223206][4649:4656] CHIP:ZCL: ReadAttributesResponse:
[1634191953.223267][4649:4656] CHIP:ZCL:   ClusterId: 0x0000_0300
[1634191953.223316][4649:4656] CHIP:ZCL:   attributeId: 0x0000_0000
[1634191953.223358][4649:4656] CHIP:ZCL:   status: Success                (0x0000)
[1634191953.223399][4649:4656] CHIP:ZCL:   attribute TLV Type: 0x04
[1634191953.223453][4649:4656] CHIP:ZCL:   attributeValue: 118
[1634191953.223674][4649:4656] CHIP:EM: Piggybacking Ack for MessageCounter:00000044 on exchange: 11557i
AttributeReadResult(path=AttributePath(nodeId=12344321, endpointId=1, clusterId=768, attributeId=0), status=0, value=118)
[1634191953.223825][4649:4656] CHIP:IN: Secure message was encrypted: Msg ID 73
[1634191953.223882][4649:4656] CHIP:IN: Build encrypted message 0x7062258 to 0x0000000000BC5C01 of type 1 and protocolId 1 on exchange 11557r with MessageCounter 73.
[1634191953.223947][4649:4656] CHIP:IN: Sending encrypted msg 0x7062258 to 0x0000000000BC5C01 at utc time: 6846369 msec
[1634191953.223994][4649:4656] CHIP:IN: Sending msg on generic transport
chip-device-ctrl > [1634191953.224238][4649:4656] CHIP:DMG: Client[0] moving to [UNINIT]
[1634191953.438903][4649:4656] CHIP:EM: Received message of type 0x10 with vendorId 0x0000 and protocolId 0x0000 on exchange 11557i
[1634191953.439039][4649:4656] CHIP:EM: Rxd Ack; Removing MessageCounter:00000049 from Retrans Table
[1634191953.439088][4649:4656] CHIP:EM: Removed CHIP MessageCounter:00000049 from RetransTable
zclread ColorControl CurrentHue 12344321 1 0
[1634191956.065784][4649:4656] CHIP:DMG: SendReadRequest: Client[0] [ INIT]
[1634191956.066072][4649:4656] CHIP:IN: Secure message was encrypted: Msg ID 74
[1634191956.066137][4649:4656] CHIP:IN: Build encrypted message 0x7062258 to 0x0000000000BC5C01 of type 2 and protocolId 1 on exchange 11558r with MessageCounter 74.
[1634191956.066296][4649:4656] CHIP:IN: Sending encrypted msg 0x7062258 to 0x0000000000BC5C01 at utc time: 6849212 msec
[1634191956.066352][4649:4656] CHIP:IN: Sending msg on generic transport
[1634191956.066558][4649:4656] CHIP:DMG: Client[0] moving to [AwaitingInitialReport]
[1634191956.286476][4649:4656] CHIP:EM: Received message of type 0x05 with vendorId 0x0000 and protocolId 0x0001 on exchange 11558i
[1634191956.286630][4649:4656] CHIP:EM: Rxd Ack; Removing MessageCounter:0000004A from Retrans Table
[1634191956.286686][4649:4656] CHIP:EM: Removed CHIP MessageCounter:0000004A from RetransTable
[1634191956.286792][4649:4656] CHIP:DMG: ReportData =
[1634191956.286854][4649:4656] CHIP:DMG: {
[1634191956.286902][4649:4656] CHIP:DMG:        AttributeDataList =
[1634191956.286955][4649:4656] CHIP:DMG:        [
[1634191956.287024][4649:4656] CHIP:DMG:                AttributeDataElement =
[1634191956.287121][4649:4656] CHIP:DMG:                {
[1634191956.287171][4649:4656] CHIP:DMG:                        AttributePath =
[1634191956.287292][4649:4656] CHIP:DMG:                        {
[1634191956.287368][4649:4656] CHIP:DMG:                                NodeId = 0xbc5c01,
[1634191956.287457][4649:4656] CHIP:DMG:                                EndpointId = 0x1,
[1634191956.287566][4649:4656] CHIP:DMG:                                ClusterId = 0x300,
[1634191956.287641][4649:4656] CHIP:DMG:                                FieldTag = 0x0,
[1634191956.287752][4649:4656] CHIP:DMG:                        }
[1634191956.287821][4649:4656] CHIP:DMG:
[1634191956.287929][4649:4656] CHIP:DMG:                        Data = 129,
[1634191956.288008][4649:4656] CHIP:DMG:                        DataElementVersion = 0x0,
[1634191956.288103][4649:4656] CHIP:DMG:                },
[1634191956.288209][4649:4656] CHIP:DMG:
[1634191956.288260][4649:4656] CHIP:DMG:        ],
[1634191956.288355][4649:4656] CHIP:DMG:
[1634191956.288406][4649:4656] CHIP:DMG: }
[1634191956.288982][4649:4656] CHIP:ZCL: ReadAttributesResponse:
[1634191956.289023][4649:4656] CHIP:ZCL:   ClusterId: 0x0000_0300
[1634191956.289052][4649:4656] CHIP:ZCL:   attributeId: 0x0000_0000
[1634191956.289075][4649:4656] CHIP:ZCL:   status: Success                (0x0000)
[1634191956.289096][4649:4656] CHIP:ZCL:   attribute TLV Type: 0x04
[1634191956.289128][4649:4656] CHIP:ZCL:   attributeValue: 129
[1634191956.289304][4649:4656] CHIP:EM: Piggybacking Ack for MessageCounter:00000046 on exchange: 11558i
AttributeReadResult(path=AttributePath(nodeId=12344321, endpointId=1, clusterId=768, attributeId=0), status=0, value=129)
[1634191956.289428][4649:4656] CHIP:IN: Secure message was encrypted: Msg ID 75
[1634191956.289463][4649:4656] CHIP:IN: Build encrypted message 0x7062258 to 0x0000000000BC5C01 of type 1 and protocolId 1 on exchange 11558r with MessageCounter 75.
[1634191956.289505][4649:4656] CHIP:IN: Sending encrypted msg 0x7062258 to 0x0000000000BC5C01 at utc time: 6849435 msec
[1634191956.289531][4649:4656] CHIP:IN: Sending msg on generic transport
chip-device-ctrl > [1634191956.289754][4649:4656] CHIP:DMG: Client[0] moving to [UNINIT]
[1634191956.496059][4649:4656] CHIP:EM: Received message of type 0x10 with vendorId 0x0000 and protocolId 0x0000 on exchange 11558i
[1634191956.496227][4649:4656] CHIP:EM: Rxd Ack; Removing MessageCounter:0000004B from Retrans Table
[1634191956.496293][4649:4656] CHIP:EM: Removed CHIP MessageCounter:0000004B from RetransTable
zclread ColorControl CurrentHue 12344321 1 0
[1634191961.435649][4649:4656] CHIP:DMG: SendReadRequest: Client[0] [ INIT]
[1634191961.435943][4649:4656] CHIP:IN: Secure message was encrypted: Msg ID 76
[1634191961.436008][4649:4656] CHIP:IN: Build encrypted message 0x7062258 to 0x0000000000BC5C01 of type 2 and protocolId 1 on exchange 11559r with MessageCounter 76.
[1634191961.436077][4649:4656] CHIP:IN: Sending encrypted msg 0x7062258 to 0x0000000000BC5C01 at utc time: 6854581 msec
[1634191961.436182][4649:4656] CHIP:IN: Sending msg on generic transport
[1634191961.436400][4649:4656] CHIP:DMG: Client[0] moving to [AwaitingInitialReport]
[1634191961.714134][4649:4656] CHIP:EM: Received message of type 0x05 with vendorId 0x0000 and protocolId 0x0001 on exchange 11559i
[1634191961.714299][4649:4656] CHIP:EM: Rxd Ack; Removing MessageCounter:0000004C from Retrans Table
[1634191961.714348][4649:4656] CHIP:EM: Removed CHIP MessageCounter:0000004C from RetransTable
[1634191961.714441][4649:4656] CHIP:DMG: ReportData =
[1634191961.714495][4649:4656] CHIP:DMG: {
[1634191961.714537][4649:4656] CHIP:DMG:        AttributeDataList =
[1634191961.714583][4649:4656] CHIP:DMG:        [
[1634191961.714674][4649:4656] CHIP:DMG:                AttributeDataElement =
[1634191961.714732][4649:4656] CHIP:DMG:                {
[1634191961.714818][4649:4656] CHIP:DMG:                        AttributePath =
[1634191961.714871][4649:4656] CHIP:DMG:                        {
[1634191961.714966][4649:4656] CHIP:DMG:                                NodeId = 0xbc5c01,
[1634191961.715042][4649:4656] CHIP:DMG:                                EndpointId = 0x1,
[1634191961.715136][4649:4656] CHIP:DMG:                                ClusterId = 0x300,
[1634191961.715231][4649:4656] CHIP:DMG:                                FieldTag = 0x0,
[1634191961.715320][4649:4656] CHIP:DMG:                        }
[1634191961.715415][4649:4656] CHIP:DMG:
[1634191961.715512][4649:4656] CHIP:DMG:                        Data = 150,
[1634191961.715568][4649:4656] CHIP:DMG:                        DataElementVersion = 0x0,
[1634191961.715662][4649:4656] CHIP:DMG:                },
[1634191961.715742][4649:4656] CHIP:DMG:
[1634191961.715788][4649:4656] CHIP:DMG:        ],
[1634191961.715845][4649:4656] CHIP:DMG:
[1634191961.715888][4649:4656] CHIP:DMG: }
[1634191961.716455][4649:4656] CHIP:ZCL: ReadAttributesResponse:
[1634191961.716516][4649:4656] CHIP:ZCL:   ClusterId: 0x0000_0300
[1634191961.716566][4649:4656] CHIP:ZCL:   attributeId: 0x0000_0000
[1634191961.716608][4649:4656] CHIP:ZCL:   status: Success                (0x0000)
[1634191961.716649][4649:4656] CHIP:ZCL:   attribute TLV Type: 0x04
[1634191961.716702][4649:4656] CHIP:ZCL:   attributeValue: 150
[1634191961.716915][4649:4656] CHIP:EM: Piggybacking Ack for MessageCounter:00000048 on exchange: 11559i
AttributeReadResult(path=AttributePath(nodeId=12344321, endpointId=1, clusterId=768, attributeId=0), status=0, value=150)
[1634191961.717063][4649:4656] CHIP:IN: Secure message was encrypted: Msg ID 77
[1634191961.717122][4649:4656] CHIP:IN: Build encrypted message 0x7062258 to 0x0000000000BC5C01 of type 1 and protocolId 1 on exchange 11559r with MessageCounter 77.
[1634191961.717188][4649:4656] CHIP:IN: Sending encrypted msg 0x7062258 to 0x0000000000BC5C01 at utc time: 6854863 msec
[1634191961.717237][4649:4656] CHIP:IN: Sending msg on generic transport
chip-device-ctrl > [1634191961.717537][4649:4656] CHIP:DMG: Client[0] moving to [UNINIT]
[1634191961.914836][4649:4656] CHIP:EM: Received message of type 0x10 with vendorId 0x0000 and protocolId 0x0000 on exchange 11559i
[1634191961.915007][4649:4656] CHIP:EM: Rxd Ack; Removing MessageCounter:0000004D from Retrans Table
[1634191961.915074][4649:4656] CHIP:EM: Removed CHIP MessageCounter:0000004D from RetransTable
chip-device-ctrl > zclread ColorControl CurrentHue 12344321 1 0
[1634191969.535262][4649:4656] CHIP:DMG: SendReadRequest: Client[0] [ INIT]
[1634191969.535588][4649:4656] CHIP:IN: Secure message was encrypted: Msg ID 78
[1634191969.535661][4649:4656] CHIP:IN: Build encrypted message 0x7062258 to 0x0000000000BC5C01 of type 2 and protocolId 1 on exchange 11560r with MessageCounter 78.
[1634191969.535775][4649:4656] CHIP:IN: Sending encrypted msg 0x7062258 to 0x0000000000BC5C01 at utc time: 6862681 msec
[1634191969.535869][4649:4656] CHIP:IN: Sending msg on generic transport
[1634191969.536094][4649:4656] CHIP:DMG: Client[0] moving to [AwaitingInitialReport]
[1634191969.901132][4649:4656] CHIP:EM: Received message of type 0x05 with vendorId 0x0000 and protocolId 0x0001 on exchange 11560i
[1634191969.901301][4649:4656] CHIP:EM: Rxd Ack; Removing MessageCounter:0000004E from Retrans Table
[1634191969.901366][4649:4656] CHIP:EM: Removed CHIP MessageCounter:0000004E from RetransTable
[1634191969.901482][4649:4656] CHIP:DMG: ReportData =
[1634191969.901553][4649:4656] CHIP:DMG: {
[1634191969.901609][4649:4656] CHIP:DMG:        AttributeDataList =
[1634191969.901783][4649:4656] CHIP:DMG:        [
[1634191969.901851][4649:4656] CHIP:DMG:                AttributeDataElement =
[1634191969.901973][4649:4656] CHIP:DMG:                {
[1634191969.902041][4649:4656] CHIP:DMG:                        AttributePath =
[1634191969.902163][4649:4656] CHIP:DMG:                        {
[1634191969.902298][4649:4656] CHIP:DMG:                                NodeId = 0xbc5c01,
[1634191969.902437][4649:4656] CHIP:DMG:                                EndpointId = 0x1,
[1634191969.902566][4649:4656] CHIP:DMG:                                ClusterId = 0x300,
[1634191969.902702][4649:4656] CHIP:DMG:                                FieldTag = 0x0,
[1634191969.902822][4649:4656] CHIP:DMG:                        }
[1634191969.902899][4649:4656] CHIP:DMG:
[1634191969.903018][4649:4656] CHIP:DMG:                        Data = 150,
[1634191969.903149][4649:4656] CHIP:DMG:                        DataElementVersion = 0x0,
[1634191969.903224][4649:4656] CHIP:DMG:                },
[1634191969.903358][4649:4656] CHIP:DMG:
[1634191969.903421][4649:4656] CHIP:DMG:        ],
[1634191969.903496][4649:4656] CHIP:DMG:
[1634191969.903554][4649:4656] CHIP:DMG: }
[1634191969.904297][4649:4656] CHIP:ZCL: ReadAttributesResponse:
[1634191969.904370][4649:4656] CHIP:ZCL:   ClusterId: 0x0000_0300
[1634191969.904436][4649:4656] CHIP:ZCL:   attributeId: 0x0000_0000
[1634191969.904492][4649:4656] CHIP:ZCL:   status: Success                (0x0000)
[1634191969.904547][4649:4656] CHIP:ZCL:   attribute TLV Type: 0x04
[1634191969.904617][4649:4656] CHIP:ZCL:   attributeValue: 150
[1634191969.905049][4649:4656] CHIP:EM: Piggybacking Ack for MessageCounter:0000004A on exchange: 11560i
[1634191969.905313][4649:4656] CHIP:IN: Secure message was encrypted: Msg ID 79
[1634191969.905388][4649:4656] CHIP:IN: Build encrypted message 0x7062258 to 0x0000000000BC5C01 of type 1 and protocolId 1 on exchange 11560r with MessageCounter 79.
[1634191969.905475][4649:4656] CHIP:IN: Sending encrypted msg 0x7062258 to 0x0000000000BC5C01 at utc time: 6863051 msec
[1634191969.905539][4649:4656] CHIP:IN: Sending msg on generic transport
[1634191969.905845][4649:4656] CHIP:DMG: Client[0] moving to [UNINIT]
AttributeReadResult(path=AttributePath(nodeId=12344321, endpointId=1, clusterId=768, attributeId=0), status=0, value=150)
chip-device-ctrl > [1634191970.008927][4649:4656] CHIP:EM: Received message of type 0x10 with vendorId 0x0000 and protocolId 0x0000 on exchange 11560i
[1634191970.009101][4649:4656] CHIP:EM: Rxd Ack; Removing MessageCounter:0000004F from Retrans Table
[1634191970.009172][4649:4656] CHIP:EM: Removed CHIP MessageCounter:0000004F from RetransTable
************step4a
chip-device-ctrl > zcl ColorControl MoveToHue 12344321 1 0 hue=160 direction=2 transitionTime=300 optionsMask=1 optionsOverride=1
[1634192310.890797][4649:4656] CHIP:DMG: ICR moving to [Initialize]
[1634192310.890891][4649:4656] CHIP:DMG: ICR moving to [AddCommand]
[1634192310.891089][4649:4656] CHIP:IN: Secure message was encrypted: Msg ID 80
[1634192310.891140][4649:4656] CHIP:IN: Build encrypted message 0x7062258 to 0x0000000000BC5C01 of type 8 and protocolId 1 on exchange 11561r with MessageCounter 80.
[1634192310.891242][4649:4656] CHIP:IN: Sending encrypted msg 0x7062258 to 0x0000000000BC5C01 at utc time: 7204037 msec
[1634192310.891286][4649:4656] CHIP:IN: Sending msg on generic transport
[1634192310.891563][4649:4656] CHIP:DMG: ICR moving to [   Sending]
[1634192311.185669][4649:4656] CHIP:EM: Received message of type 0x09 with vendorId 0x0000 and protocolId 0x0001 on exchange 11561i
[1634192311.185836][4649:4656] CHIP:EM: Rxd Ack; Removing MessageCounter:00000050 from Retrans Table
[1634192311.185902][4649:4656] CHIP:EM: Removed CHIP MessageCounter:00000050 from RetransTable
[1634192311.186017][4649:4656] CHIP:DMG: InvokeCommand =
[1634192311.186087][4649:4656] CHIP:DMG: {
[1634192311.186142][4649:4656] CHIP:DMG:        CommandList =
[1634192311.186242][4649:4656] CHIP:DMG:        [
[1634192311.186368][4649:4656] CHIP:DMG:                CommandDataElement =
[1634192311.186453][4649:4656] CHIP:DMG:                {
[1634192311.186577][4649:4656] CHIP:DMG:                        CommandPath =
[1634192311.186717][4649:4656] CHIP:DMG:                        {
[1634192311.186840][4649:4656] CHIP:DMG:                                EndpointId = 0x1,
[1634192311.186942][4649:4656] CHIP:DMG:                                ClusterId = 0x300,
[1634192311.187113][4649:4656] CHIP:DMG:                                CommandId = 0x0,
[1634192311.187204][4649:4656] CHIP:DMG:                        },
[1634192311.187377][4649:4656] CHIP:DMG:
[1634192311.187446][4649:4656] CHIP:DMG:                        StatusElement =
[1634192311.187511][4649:4656] CHIP:DMG:                        {
[1634192311.187630][4649:4656] CHIP:DMG:                                GeneralCode = 0x0,
[1634192311.187720][4649:4656] CHIP:DMG:                                ProtocolId = 0x1,
[1634192311.187851][4649:4656] CHIP:DMG:                                protocolCode = 0x0,
[1634192311.187934][4649:4656] CHIP:DMG:                        },
[1634192311.188015][4649:4656] CHIP:DMG:
[1634192311.188084][4649:4656] CHIP:DMG:                },
[1634192311.188171][4649:4656] CHIP:DMG:
[1634192311.188232][4649:4656] CHIP:DMG:        ],
[1634192311.188308][4649:4656] CHIP:DMG:
[1634192311.188365][4649:4656] CHIP:DMG: }
SetCommandIndexStatus commandHandle=1 commandIndex=1
[1634192311.188995][4649:4656] CHIP:ZCL: DefaultResponse:
[1634192311.189056][4649:4656] CHIP:ZCL:   Transaction: 0xffffbb796240
[1634192311.189110][4649:4656] CHIP:ZCL:   status: EMBER_ZCL_STATUS_SUCCESS (0x00)
[1634192311.189168][4649:4656] CHIP:ZCL: IMDefaultResponseCallback: Missing success callback
[1634192311.189221][4649:4656] CHIP:ZCL: IMDefaultResponseCallback: Missing failure callback
[1634192311.189394][4649:4656] CHIP:DMG: ICR moving to [Uninitiali]
[1634192311.189473][4649:4656] CHIP:EM: Sending Standalone Ack for MessageCounter:0000004C
Received command status response:
[1634192311.189645][4649:4656] CHIP:IN: Secure message was encrypted: Msg ID 81
[1634192311.189714][4649:4656] CHIP:IN: Build encrypted message 0xffffabf7dad0 to 0x0000000000BC5C01 of type 16 and protocolId 0 on exchange 11561r with MessageCounter 81.
Container:
ProtocolId = 1
ProtocolCode = 0
EndpointId = 1
ClusterId = 768
CommandId = 0
CommandIndex = 1
[1634192311.189802][4649:4656] CHIP:IN: Sending encrypted msg 0xffffabf7dad0 to 0x0000000000BC5C01 at utc time: 7204335 msec
[1634192311.190046][4649:4656] CHIP:IN: Sending msg on generic transport
[1634192311.190354][4649:4656] CHIP:EM: Flushed pending ack for MessageCounter:0000004C
************step4b
chip-device-ctrl > zclread ColorControl CurrentHue 12344321 1 0
[1634192313.571066][4649:4656] CHIP:DMG: SendReadRequest: Client[0] [ INIT]
[1634192313.571388][4649:4656] CHIP:IN: Secure message was encrypted: Msg ID 82
[1634192313.571462][4649:4656] CHIP:IN: Build encrypted message 0x7062258 to 0x0000000000BC5C01 of type 2 and protocolId 1 on exchange 11562r with MessageCounter 82.
[1634192313.571556][4649:4656] CHIP:IN: Sending encrypted msg 0x7062258 to 0x0000000000BC5C01 at utc time: 7206717 msec
[1634192313.571621][4649:4656] CHIP:IN: Sending msg on generic transport
[1634192313.571849][4649:4656] CHIP:DMG: Client[0] moving to [AwaitingInitialReport]
[1634192313.971094][4649:4656] CHIP:EM: Received message of type 0x05 with vendorId 0x0000 and protocolId 0x0001 on exchange 11562i
[1634192313.971263][4649:4656] CHIP:EM: Rxd Ack; Removing MessageCounter:00000052 from Retrans Table
[1634192313.971328][4649:4656] CHIP:EM: Removed CHIP MessageCounter:00000052 from RetransTable
[1634192313.971446][4649:4656] CHIP:DMG: ReportData =
[1634192313.971516][4649:4656] CHIP:DMG: {
[1634192313.971572][4649:4656] CHIP:DMG:        AttributeDataList =
[1634192313.971634][4649:4656] CHIP:DMG:        [
[1634192313.971695][4649:4656] CHIP:DMG:                AttributeDataElement =
[1634192313.971807][4649:4656] CHIP:DMG:                {
[1634192313.971877][4649:4656] CHIP:DMG:                        AttributePath =
[1634192313.971960][4649:4656] CHIP:DMG:                        {
[1634192313.972040][4649:4656] CHIP:DMG:                                NodeId = 0xbc5c01,
[1634192313.972120][4649:4656] CHIP:DMG:                                EndpointId = 0x1,
[1634192313.972211][4649:4656] CHIP:DMG:                                ClusterId = 0x300,
[1634192313.972297][4649:4656] CHIP:DMG:                                FieldTag = 0x0,
[1634192313.972377][4649:4656] CHIP:DMG:                        }
[1634192313.972459][4649:4656] CHIP:DMG:
[1634192313.972543][4649:4656] CHIP:DMG:                        Data = 151,
[1634192313.972611][4649:4656] CHIP:DMG:                        DataElementVersion = 0x0,
[1634192313.972688][4649:4656] CHIP:DMG:                },
[1634192313.972766][4649:4656] CHIP:DMG:
[1634192313.972828][4649:4656] CHIP:DMG:        ],
[1634192313.972904][4649:4656] CHIP:DMG:
[1634192313.972961][4649:4656] CHIP:DMG: }
[1634192313.973676][4649:4656] CHIP:ZCL: ReadAttributesResponse:
[1634192313.973754][4649:4656] CHIP:ZCL:   ClusterId: 0x0000_0300
[1634192313.973819][4649:4656] CHIP:ZCL:   attributeId: 0x0000_0000
[1634192313.973873][4649:4656] CHIP:ZCL:   status: Success                (0x0000)
[1634192313.973926][4649:4656] CHIP:ZCL:   attribute TLV Type: 0x04
[1634192313.973994][4649:4656] CHIP:ZCL:   attributeValue: 151
[1634192313.974314][4649:4656] CHIP:EM: Piggybacking Ack for MessageCounter:0000004D on exchange: 11562i
AttributeReadResult(path=AttributePath(nodeId=12344321, endpointId=1, clusterId=768, attributeId=0), status=0, value=151)
[1634192313.974515][4649:4656] CHIP:IN: Secure message was encrypted: Msg ID 83
[1634192313.974589][4649:4656] CHIP:IN: Build encrypted message 0x7062258 to 0x0000000000BC5C01 of type 1 and protocolId 1 on exchange 11562r with MessageCounter 83.
[1634192313.974675][4649:4656] CHIP:IN: Sending encrypted msg 0x7062258 to 0x0000000000BC5C01 at utc time: 7207120 msec
[1634192313.974740][4649:4656] CHIP:IN: Sending msg on generic transport
chip-device-ctrl > [1634192313.975055][4649:4656] CHIP:DMG: Client[0] moving to [UNINIT]
[1634192314.154490][4649:4656] CHIP:EM: Received message of type 0x10 with vendorId 0x0000 and protocolId 0x0000 on exchange 11562i
[1634192314.154657][4649:4656] CHIP:EM: Rxd Ack; Removing MessageCounter:00000053 from Retrans Table
[1634192314.154725][4649:4656] CHIP:EM: Removed CHIP MessageCounter:00000053 from RetransTable
chip-device-ctrl > zclread ColorControl CurrentHue 12344321 1 0
[1634192329.143658][4649:4656] CHIP:DMG: SendReadRequest: Client[0] [ INIT]
[1634192329.143985][4649:4656] CHIP:IN: Secure message was encrypted: Msg ID 86
[1634192329.144059][4649:4656] CHIP:IN: Build encrypted message 0x7062258 to 0x0000000000BC5C01 of type 2 and protocolId 1 on exchange 11564r with MessageCounter 86.
[1634192329.144139][4649:4656] CHIP:IN: Sending encrypted msg 0x7062258 to 0x0000000000BC5C01 at utc time: 7222289 msec
[1634192329.144204][4649:4656] CHIP:IN: Sending msg on generic transport
[1634192329.144473][4649:4656] CHIP:DMG: Client[0] moving to [AwaitingInitialReport]
[1634192329.392857][4649:4656] CHIP:EM: Received message of type 0x05 with vendorId 0x0000 and protocolId 0x0001 on exchange 11564i
[1634192329.392994][4649:4656] CHIP:EM: Rxd Ack; Removing MessageCounter:00000056 from Retrans Table
[1634192329.393044][4649:4656] CHIP:EM: Removed CHIP MessageCounter:00000056 from RetransTable
[1634192329.393136][4649:4656] CHIP:DMG: ReportData =
[1634192329.393189][4649:4656] CHIP:DMG: {
[1634192329.393231][4649:4656] CHIP:DMG:        AttributeDataList =
[1634192329.393289][4649:4656] CHIP:DMG:        [
[1634192329.393336][4649:4656] CHIP:DMG:                AttributeDataElement =
[1634192329.393397][4649:4656] CHIP:DMG:                {
[1634192329.393446][4649:4656] CHIP:DMG:                        AttributePath =
[1634192329.393517][4649:4656] CHIP:DMG:                        {
[1634192329.393581][4649:4656] CHIP:DMG:                                NodeId = 0xbc5c01,
[1634192329.393642][4649:4656] CHIP:DMG:                                EndpointId = 0x1,
[1634192329.393709][4649:4656] CHIP:DMG:                                ClusterId = 0x300,
[1634192329.393774][4649:4656] CHIP:DMG:                                FieldTag = 0x0,
[1634192329.393823][4649:4656] CHIP:DMG:                        }
[1634192329.393897][4649:4656] CHIP:DMG:
[1634192329.393960][4649:4656] CHIP:DMG:                        Data = 155,
[1634192329.394021][4649:4656] CHIP:DMG:                        DataElementVersion = 0x0,
[1634192329.394086][4649:4656] CHIP:DMG:                },
[1634192329.394145][4649:4656] CHIP:DMG:
[1634192329.394226][4649:4656] CHIP:DMG:        ],
[1634192329.394287][4649:4656] CHIP:DMG:
[1634192329.394330][4649:4656] CHIP:DMG: }
[1634192329.394983][4649:4656] CHIP:ZCL: ReadAttributesResponse:
[1634192329.395048][4649:4656] CHIP:ZCL:   ClusterId: 0x0000_0300
[1634192329.395098][4649:4656] CHIP:ZCL:   attributeId: 0x0000_0000
[1634192329.395139][4649:4656] CHIP:ZCL:   status: Success                (0x0000)
[1634192329.395180][4649:4656] CHIP:ZCL:   attribute TLV Type: 0x04
[1634192329.395234][4649:4656] CHIP:ZCL:   attributeValue: 155
[1634192329.395465][4649:4656] CHIP:EM: Piggybacking Ack for MessageCounter:00000051 on exchange: 11564i
AttributeReadResult(path=AttributePath(nodeId=12344321, endpointId=1, clusterId=768, attributeId=0), status=0, value=155)
[1634192329.395611][4649:4656] CHIP:IN: Secure message was encrypted: Msg ID 87
[1634192329.395674][4649:4656] CHIP:IN: Build encrypted message 0x7062258 to 0x0000000000BC5C01 of type 1 and protocolId 1 on exchange 11564r with MessageCounter 87.
[1634192329.395744][4649:4656] CHIP:IN: Sending encrypted msg 0x7062258 to 0x0000000000BC5C01 at utc time: 7222541 msec
[1634192329.395794][4649:4656] CHIP:IN: Sending msg on generic transport
chip-device-ctrl > [1634192329.396033][4649:4656] CHIP:DMG: Client[0] moving to [UNINIT]
[1634192329.599385][4649:4656] CHIP:EM: Received message of type 0x10 with vendorId 0x0000 and protocolId 0x0000 on exchange 11564i
[1634192329.599558][4649:4656] CHIP:EM: Rxd Ack; Removing MessageCounter:00000057 from Retrans Table
[1634192329.599625][4649:4656] CHIP:EM: Removed CHIP MessageCounter:00000057 from RetransTable
chip-device-ctrl > zclread ColorControl CurrentHue 12344321 1 0
[1634192345.316286][4649:4656] CHIP:DMG: SendReadRequest: Client[0] [ INIT]
[1634192345.316602][4649:4656] CHIP:IN: Secure message was encrypted: Msg ID 88
[1634192345.316677][4649:4656] CHIP:IN: Build encrypted message 0x7062258 to 0x0000000000BC5C01 of type 2 and protocolId 1 on exchange 11565r with MessageCounter 88.
[1634192345.316823][4649:4656] CHIP:IN: Sending encrypted msg 0x7062258 to 0x0000000000BC5C01 at utc time: 7238462 msec
[1634192345.316886][4649:4656] CHIP:IN: Sending msg on generic transport
[1634192345.317159][4649:4656] CHIP:DMG: Client[0] moving to [AwaitingInitialReport]
[1634192345.590045][4649:4656] CHIP:EM: Received message of type 0x05 with vendorId 0x0000 and protocolId 0x0001 on exchange 11565i
[1634192345.590250][4649:4656] CHIP:EM: Rxd Ack; Removing MessageCounter:00000058 from Retrans Table
[1634192345.590316][4649:4656] CHIP:EM: Removed CHIP MessageCounter:00000058 from RetransTable
[1634192345.590433][4649:4656] CHIP:DMG: ReportData =
[1634192345.590505][4649:4656] CHIP:DMG: {
[1634192345.590561][4649:4656] CHIP:DMG:        AttributeDataList =
[1634192345.590629][4649:4656] CHIP:DMG:        [
[1634192345.590691][4649:4656] CHIP:DMG:                AttributeDataElement =
[1634192345.590768][4649:4656] CHIP:DMG:                {
[1634192345.590834][4649:4656] CHIP:DMG:                        AttributePath =
[1634192345.590961][4649:4656] CHIP:DMG:                        {
[1634192345.591037][4649:4656] CHIP:DMG:                                NodeId = 0xbc5c01,
[1634192345.591134][4649:4656] CHIP:DMG:                                EndpointId = 0x1,
[1634192345.591225][4649:4656] CHIP:DMG:                                ClusterId = 0x300,
[1634192345.591318][4649:4656] CHIP:DMG:                                FieldTag = 0x0,
[1634192345.591399][4649:4656] CHIP:DMG:                        }
[1634192345.591493][4649:4656] CHIP:DMG:
[1634192345.591587][4649:4656] CHIP:DMG:                        Data = 159,
[1634192345.591677][4649:4656] CHIP:DMG:                        DataElementVersion = 0x0,
[1634192345.591763][4649:4656] CHIP:DMG:                },
[1634192345.591847][4649:4656] CHIP:DMG:
[1634192345.591909][4649:4656] CHIP:DMG:        ],
[1634192345.591985][4649:4656] CHIP:DMG:
[1634192345.592042][4649:4656] CHIP:DMG: }
[1634192345.592740][4649:4656] CHIP:ZCL: ReadAttributesResponse:
[1634192345.592819][4649:4656] CHIP:ZCL:   ClusterId: 0x0000_0300
[1634192345.592882][4649:4656] CHIP:ZCL:   attributeId: 0x0000_0000
[1634192345.592938][4649:4656] CHIP:ZCL:   status: Success                (0x0000)
[1634192345.592992][4649:4656] CHIP:ZCL:   attribute TLV Type: 0x04
[1634192345.593062][4649:4656] CHIP:ZCL:   attributeValue: 159
[1634192345.593321][4649:4656] CHIP:EM: Piggybacking Ack for MessageCounter:00000053 on exchange: 11565i
AttributeReadResult(path=AttributePath(nodeId=12344321, endpointId=1, clusterId=768, attributeId=0), status=0, value=159)
[1634192345.593510][4649:4656] CHIP:IN: Secure message was encrypted: Msg ID 89
[1634192345.593582][4649:4656] CHIP:IN: Build encrypted message 0x7062258 to 0x0000000000BC5C01 of type 1 and protocolId 1 on exchange 11565r with MessageCounter 89.
[1634192345.593668][4649:4656] CHIP:IN: Sending encrypted msg 0x7062258 to 0x0000000000BC5C01 at utc time: 7238739 msec
[1634192345.593731][4649:4656] CHIP:IN: Sending msg on generic transport
chip-device-ctrl > [1634192345.593994][4649:4656] CHIP:DMG: Client[0] moving to [UNINIT]
[1634192345.810529][4649:4656] CHIP:EM: Received message of type 0x10 with vendorId 0x0000 and protocolId 0x0000 on exchange 11565i
[1634192345.810694][4649:4656] CHIP:EM: Rxd Ack; Removing MessageCounter:00000059 from Retrans Table
[1634192345.810758][4649:4656] CHIP:EM: Removed CHIP MessageCounter:00000059 from RetransTable
zclread ColorControl CurrentHue 12344321 1 0
[1634192348.157342][4649:4656] CHIP:DMG: SendReadRequest: Client[0] [ INIT]
[1634192348.157611][4649:4656] CHIP:IN: Secure message was encrypted: Msg ID 90
[1634192348.157667][4649:4656] CHIP:IN: Build encrypted message 0x7062258 to 0x0000000000BC5C01 of type 2 and protocolId 1 on exchange 11566r with MessageCounter 90.
[1634192348.157732][4649:4656] CHIP:IN: Sending encrypted msg 0x7062258 to 0x0000000000BC5C01 at utc time: 7241303 msec
[1634192348.157780][4649:4656] CHIP:IN: Sending msg on generic transport
[1634192348.157973][4649:4656] CHIP:DMG: Client[0] moving to [AwaitingInitialReport]
[1634192348.461018][4649:4656] CHIP:EM: Received message of type 0x05 with vendorId 0x0000 and protocolId 0x0001 on exchange 11566i
[1634192348.461188][4649:4656] CHIP:EM: Rxd Ack; Removing MessageCounter:0000005A from Retrans Table
[1634192348.461253][4649:4656] CHIP:EM: Removed CHIP MessageCounter:0000005A from RetransTable
[1634192348.461368][4649:4656] CHIP:DMG: ReportData =
[1634192348.461440][4649:4656] CHIP:DMG: {
[1634192348.461496][4649:4656] CHIP:DMG:        AttributeDataList =
[1634192348.461621][4649:4656] CHIP:DMG:        [
[1634192348.461834][4649:4656] CHIP:DMG:                AttributeDataElement =
[1634192348.461913][4649:4656] CHIP:DMG:                {
[1634192348.461981][4649:4656] CHIP:DMG:                        AttributePath =
[1634192348.462055][4649:4656] CHIP:DMG:                        {
[1634192348.462138][4649:4656] CHIP:DMG:                                NodeId = 0xbc5c01,
[1634192348.462322][4649:4656] CHIP:DMG:                                EndpointId = 0x1,
[1634192348.462405][4649:4656] CHIP:DMG:                                ClusterId = 0x300,
[1634192348.462489][4649:4656] CHIP:DMG:                                FieldTag = 0x0,
[1634192348.462578][4649:4656] CHIP:DMG:                        }
[1634192348.462667][4649:4656] CHIP:DMG:
[1634192348.462745][4649:4656] CHIP:DMG:                        Data = 160,
[1634192348.462823][4649:4656] CHIP:DMG:                        DataElementVersion = 0x0,
[1634192348.462909][4649:4656] CHIP:DMG:                },
[1634192348.462991][4649:4656] CHIP:DMG:
[1634192348.463052][4649:4656] CHIP:DMG:        ],
[1634192348.463128][4649:4656] CHIP:DMG:
[1634192348.463188][4649:4656] CHIP:DMG: }
[1634192348.463927][4649:4656] CHIP:ZCL: ReadAttributesResponse:
[1634192348.464008][4649:4656] CHIP:ZCL:   ClusterId: 0x0000_0300
[1634192348.464065][4649:4656] CHIP:ZCL:   attributeId: 0x0000_0000
[1634192348.464113][4649:4656] CHIP:ZCL:   status: Success                (0x0000)
[1634192348.464159][4649:4656] CHIP:ZCL:   attribute TLV Type: 0x04
[1634192348.464220][4649:4656] CHIP:ZCL:   attributeValue: 160
[1634192348.464479][4649:4656] CHIP:EM: Piggybacking Ack for MessageCounter:00000055 on exchange: 11566i
AttributeReadResult(path=AttributePath(nodeId=12344321, endpointId=1, clusterId=768, attributeId=0), status=0, value=160)
[1634192348.464654][4649:4656] CHIP:IN: Secure message was encrypted: Msg ID 91
[1634192348.464716][4649:4656] CHIP:IN: Build encrypted message 0x7062258 to 0x0000000000BC5C01 of type 1 and protocolId 1 on exchange 11566r with MessageCounter 91.
[1634192348.464792][4649:4656] CHIP:IN: Sending encrypted msg 0x7062258 to 0x0000000000BC5C01 at utc time: 7241610 msec
[1634192348.464847][4649:4656] CHIP:IN: Sending msg on generic transport
chip-device-ctrl > [1634192348.465203][4649:4656] CHIP:DMG: Client[0] moving to [UNINIT]
[1634192348.666317][4649:4656] CHIP:EM: Received message of type 0x10 with vendorId 0x0000 and protocolId 0x0000 on exchange 11566i
[1634192348.666486][4649:4656] CHIP:EM: Rxd Ack; Removing MessageCounter:0000005B from Retrans Table
[1634192348.666550][4649:4656] CHIP:EM: Removed CHIP MessageCounter:0000005B from RetransTable
zclread ColorControl CurrentHue 12344321 1 0
[1634192352.004154][4649:4656] CHIP:DMG: SendReadRequest: Client[0] [ INIT]
[1634192352.004477][4649:4656] CHIP:IN: Secure message was encrypted: Msg ID 92
[1634192352.004553][4649:4656] CHIP:IN: Build encrypted message 0x7062258 to 0x0000000000BC5C01 of type 2 and protocolId 1 on exchange 11567r with MessageCounter 92.
[1634192352.004639][4649:4656] CHIP:IN: Sending encrypted msg 0x7062258 to 0x0000000000BC5C01 at utc time: 7245150 msec
[1634192352.004703][4649:4656] CHIP:IN: Sending msg on generic transport
[1634192352.004946][4649:4656] CHIP:DMG: Client[0] moving to [AwaitingInitialReport]
[1634192352.215662][4649:4656] CHIP:EM: Received message of type 0x05 with vendorId 0x0000 and protocolId 0x0001 on exchange 11567i
[1634192352.215844][4649:4656] CHIP:EM: Rxd Ack; Removing MessageCounter:0000005C from Retrans Table
[1634192352.215911][4649:4656] CHIP:EM: Removed CHIP MessageCounter:0000005C from RetransTable
[1634192352.216034][4649:4656] CHIP:DMG: ReportData =
[1634192352.216112][4649:4656] CHIP:DMG: {
[1634192352.216168][4649:4656] CHIP:DMG:        AttributeDataList =
[1634192352.216229][4649:4656] CHIP:DMG:        [
[1634192352.216282][4649:4656] CHIP:DMG:                AttributeDataElement =
[1634192352.216344][4649:4656] CHIP:DMG:                {
[1634192352.216402][4649:4656] CHIP:DMG:                        AttributePath =
[1634192352.216524][4649:4656] CHIP:DMG:                        {
[1634192352.216605][4649:4656] CHIP:DMG:                                NodeId = 0xbc5c01,
[1634192352.216678][4649:4656] CHIP:DMG:                                EndpointId = 0x1,
[1634192352.216769][4649:4656] CHIP:DMG:                                ClusterId = 0x300,
[1634192352.217113][4649:4656] CHIP:DMG:                                FieldTag = 0x0,
[1634192352.217253][4649:4656] CHIP:DMG:                        }
[1634192352.217354][4649:4656] CHIP:DMG:
[1634192352.217436][4649:4656] CHIP:DMG:                        Data = 160,
[1634192352.217519][4649:4656] CHIP:DMG:                        DataElementVersion = 0x0,
[1634192352.217597][4649:4656] CHIP:DMG:                },
[1634192352.217669][4649:4656] CHIP:DMG:
[1634192352.217732][4649:4656] CHIP:DMG:        ],
[1634192352.217809][4649:4656] CHIP:DMG:
[1634192352.217870][4649:4656] CHIP:DMG: }
[1634192352.218640][4649:4656] CHIP:ZCL: ReadAttributesResponse:
[1634192352.218719][4649:4656] CHIP:ZCL:   ClusterId: 0x0000_0300
[1634192352.218794][4649:4656] CHIP:ZCL:   attributeId: 0x0000_0000
[1634192352.218853][4649:4656] CHIP:ZCL:   status: Success                (0x0000)
[1634192352.218899][4649:4656] CHIP:ZCL:   attribute TLV Type: 0x04
[1634192352.218968][4649:4656] CHIP:ZCL:   attributeValue: 160
AttributeReadResult(path=AttributePath(nodeId=12344321, endpointId=1, clusterId=768, attributeId=0), status=0, value=160)
[1634192352.219542][4649:4656] CHIP:EM: Piggybacking Ack for MessageCounter:00000057 on exchange: 11567i
[1634192352.219791][4649:4656] CHIP:IN: Secure message was encrypted: Msg ID 93
[1634192352.219863][4649:4656] CHIP:IN: Build encrypted message 0x7062258 to 0x0000000000BC5C01 of type 1 and protocolId 1 on exchange 11567r with MessageCounter 93.
[1634192352.219950][4649:4656] CHIP:IN: Sending encrypted msg 0x7062258 to 0x0000000000BC5C01 at utc time: 7245365 msec
[1634192352.220033][4649:4656] CHIP:IN: cSending msg on generic transport
hip-device-ctrl > [1634192352.220383][4649:4656] CHIP:DMG: Client[0] moving to [UNINIT]
[1634192352.317753][4649:4656] CHIP:EM: Received message of type 0x10 with vendorId 0x0000 and protocolId 0x0000 on exchange 11567i
[1634192352.317845][4649:4656] CHIP:EM: Rxd Ack; Removing MessageCounter:0000005D from Retrans Table
[1634192352.317873][4649:4656] CHIP:EM: Removed CHIP MessageCounter:0000005D from RetransTable
************step5a
chip-device-ctrl > zcl ColorControl MoveToHue 12344321 1 0 hue=155 direction=3 transitionTime=300 optionsMask=1 optionsOverride=1
[1634192521.362458][4649:4656] CHIP:DMG: ICR moving to [Initialize]
[1634192521.362561][4649:4656] CHIP:DMG: ICR moving to [AddCommand]
[1634192521.362778][4649:4656] CHIP:IN: Secure message was encrypted: Msg ID 94
[1634192521.362833][4649:4656] CHIP:IN: Build encrypted message 0x7062258 to 0x0000000000BC5C01 of type 8 and protocolId 1 on exchange 11568r with MessageCounter 94.
[1634192521.362900][4649:4656] CHIP:IN: Sending encrypted msg 0x7062258 to 0x0000000000BC5C01 at utc time: 7414508 msec
[1634192521.362948][4649:4656] CHIP:IN: Sending msg on generic transport
[1634192521.363188][4649:4656] CHIP:DMG: ICR moving to [   Sending]
[1634192521.583629][4649:4656] CHIP:EM: Received message of type 0x09 with vendorId 0x0000 and protocolId 0x0001 on exchange 11568i
[1634192521.583726][4649:4656] CHIP:EM: Rxd Ack; Removing MessageCounter:0000005E from Retrans Table
[1634192521.583753][4649:4656] CHIP:EM: Removed CHIP MessageCounter:0000005E from RetransTable
[1634192521.583812][4649:4656] CHIP:DMG: InvokeCommand =
[1634192521.583841][4649:4656] CHIP:DMG: {
[1634192521.583864][4649:4656] CHIP:DMG:        CommandList =
[1634192521.583889][4649:4656] CHIP:DMG:        [
[1634192521.583914][4649:4656] CHIP:DMG:                CommandDataElement =
[1634192521.583952][4649:4656] CHIP:DMG:                {
[1634192521.583980][4649:4656] CHIP:DMG:                        CommandPath =
[1634192521.584018][4649:4656] CHIP:DMG:                        {
[1634192521.584053][4649:4656] CHIP:DMG:                                EndpointId = 0x1,
[1634192521.584092][4649:4656] CHIP:DMG:                                ClusterId = 0x300,
[1634192521.584125][4649:4656] CHIP:DMG:                                CommandId = 0x0,
[1634192521.584158][4649:4656] CHIP:DMG:                        },
[1634192521.584195][4649:4656] CHIP:DMG:
[1634192521.584223][4649:4656] CHIP:DMG:                        StatusElement =
[1634192521.584250][4649:4656] CHIP:DMG:                        {
[1634192521.584285][4649:4656] CHIP:DMG:                                GeneralCode = 0x0,
[1634192521.584322][4649:4656] CHIP:DMG:                                ProtocolId = 0x1,
[1634192521.584357][4649:4656] CHIP:DMG:                                protocolCode = 0x0,
[1634192521.584388][4649:4656] CHIP:DMG:                        },
[1634192521.584421][4649:4656] CHIP:DMG:
[1634192521.584450][4649:4656] CHIP:DMG:                },
[1634192521.584482][4649:4656] CHIP:DMG:
[1634192521.584505][4649:4656] CHIP:DMG:        ],
[1634192521.584535][4649:4656] CHIP:DMG:
[1634192521.584557][4649:4656] CHIP:DMG: }
SetCommandIndexStatus commandHandle=1 commandIndex=1
[1634192521.584913][4649:4656] CHIP:ZCL: DefaultResponse:
[1634192521.584940][4649:4656] CHIP:ZCL:   Transaction: 0xffffbb796240
[1634192521.584962][4649:4656] CHIP:ZCL:   status: EMBER_ZCL_STATUS_SUCCESS (0x00)
[1634192521.584986][4649:4656] CHIP:ZCL: IMDefaultResponseCallback: Missing success callback
[1634192521.585008][4649:4656] CHIP:ZCL: IMDefaultResponseCallback: Missing failure callback
[1634192521.585099][4649:4656] CHIP:DMG: ICR moving to [Uninitiali]
[1634192521.585136][4649:4656] CHIP:EM: Sending Standalone Ack for MessageCounter:00000059
Received command status response:
[1634192521.585231][4649:4656] CHIP:IN: Secure message was encrypted: Msg ID 95
[1634192521.585259][4649:4656] CHIP:IN: Build encrypted message 0xffffabf7dad0 to 0x0000000000BC5C01 of type 16 and protocolId 0 on exchange 11568r with MessageCounter 95.
Container:
ProtocolId = 1
ProtocolCode = 0
EndpointId = 1
ClusterId = 768
CommandId = 0
CommandIndex = 1[1634192521.585300][4649:4656] CHIP:IN: Sending encrypted msg 0xffffabf7dad0 to 0x0000000000BC5C01 at utc time: 7414731 msec
[1634192521.585392][4649:4656] CHIP:IN: Sending msg on generic transport
[1634192521.585525][4649:4656] CHIP:EM: Flushed pending ack for MessageCounter:00000059
************step5b
chip-device-ctrl > zclread ColorControl CurrentHue 12344321 1 0
[1634192523.633228][4649:4656] CHIP:DMG: SendReadRequest: Client[0] [ INIT]
[1634192523.633543][4649:4656] CHIP:IN: Secure message was encrypted: Msg ID 96
[1634192523.633617][4649:4656] CHIP:IN: Build encrypted message 0x7062258 to 0x0000000000BC5C01 of type 2 and protocolId 1 on exchange 11569r with MessageCounter 96.
[1634192523.633708][4649:4656] CHIP:IN: Sending encrypted msg 0x7062258 to 0x0000000000BC5C01 at utc time: 7416779 msec
[1634192523.633772][4649:4656] CHIP:IN: Sending msg on generic transport
[1634192523.633999][4649:4656] CHIP:DMG: Client[0] moving to [AwaitingInitialReport]
[1634192523.931726][4649:4656] CHIP:EM: Received message of type 0x05 with vendorId 0x0000 and protocolId 0x0001 on exchange 11569i
[1634192523.931865][4649:4656] CHIP:EM: Rxd Ack; Removing MessageCounter:00000060 from Retrans Table
[1634192523.931914][4649:4656] CHIP:EM: Removed CHIP MessageCounter:00000060 from RetransTable
[1634192523.932006][4649:4656] CHIP:DMG: ReportData =
[1634192523.932060][4649:4656] CHIP:DMG: {
[1634192523.932102][4649:4656] CHIP:DMG:        AttributeDataList =
[1634192523.932149][4649:4656] CHIP:DMG:        [
[1634192523.932196][4649:4656] CHIP:DMG:                AttributeDataElement =
[1634192523.932260][4649:4656] CHIP:DMG:                {
[1634192523.932304][4649:4656] CHIP:DMG:                        AttributePath =
[1634192523.932360][4649:4656] CHIP:DMG:                        {
[1634192523.932424][4649:4656] CHIP:DMG:                                NodeId = 0xbc5c01,
[1634192523.932485][4649:4656] CHIP:DMG:                                EndpointId = 0x1,
[1634192523.932548][4649:4656] CHIP:DMG:                                ClusterId = 0x300,
[1634192523.932643][4649:4656] CHIP:DMG:                                FieldTag = 0x0,
[1634192523.932714][4649:4656] CHIP:DMG:                        }
[1634192523.932783][4649:4656] CHIP:DMG:
[1634192523.932847][4649:4656] CHIP:DMG:                        Data = 159,
[1634192523.932914][4649:4656] CHIP:DMG:                        DataElementVersion = 0x0,
[1634192523.932970][4649:4656] CHIP:DMG:                },
[1634192523.933035][4649:4656] CHIP:DMG:
[1634192523.933081][4649:4656] CHIP:DMG:        ],
[1634192523.933140][4649:4656] CHIP:DMG:
[1634192523.933183][4649:4656] CHIP:DMG: }
[1634192523.933752][4649:4656] CHIP:ZCL: ReadAttributesResponse:
[1634192523.933815][4649:4656] CHIP:ZCL:   ClusterId: 0x0000_0300
[1634192523.933864][4649:4656] CHIP:ZCL:   attributeId: 0x0000_0000
[1634192523.933906][4649:4656] CHIP:ZCL:   status: Success                (0x0000)
[1634192523.933947][4649:4656] CHIP:ZCL:   attribute TLV Type: 0x04
[1634192523.934000][4649:4656] CHIP:ZCL:   attributeValue: 159
[1634192523.934248][4649:4656] CHIP:EM: Piggybacking Ack for MessageCounter:0000005A on exchange: 11569i
AttributeReadResult(path=AttributePath(nodeId=12344321, endpointId=1, clusterId=768, attributeId=0), status=0, value=159)
[1634192523.934393][4649:4656] CHIP:IN: Secure message was encrypted: Msg ID 97
[1634192523.934451][4649:4656] CHIP:IN: Build encrypted message 0x7062258 to 0x0000000000BC5C01 of type 1 and protocolId 1 on exchange 11569r with MessageCounter 97.
[1634192523.934518][4649:4656] CHIP:IN: Sending encrypted msg 0x7062258 to 0x0000000000BC5C01 at utc time: 7417080 msec
[1634192523.934567][4649:4656] CHIP:IN: Sending msg on generic transport
chip-device-ctrl > [1634192523.934818][4649:4656] CHIP:DMG: Client[0] moving to [UNINIT]
[1634192524.137597][4649:4656] CHIP:EM: Received message of type 0x10 with vendorId 0x0000 and protocolId 0x0000 on exchange 11569i
[1634192524.137776][4649:4656] CHIP:EM: Rxd Ack; Removing MessageCounter:00000061 from Retrans Table
[1634192524.137843][4649:4656] CHIP:EM: Removed CHIP MessageCounter:00000061 from RetransTable
zclread ColorControl CurrentHue 12344321 1 0
[1634192552.762432][4649:4656] CHIP:DMG: SendReadRequest: Client[0] [ INIT]
[1634192552.762757][4649:4656] CHIP:IN: Secure message was encrypted: Msg ID 104
[1634192552.762831][4649:4656] CHIP:IN: Build encrypted message 0x7062258 to 0x0000000000BC5C01 of type 2 and protocolId 1 on exchange 11573r with MessageCounter 104.
[1634192552.762911][4649:4656] CHIP:IN: Sending encrypted msg 0x7062258 to 0x0000000000BC5C01 at utc time: 7445908 msec
[1634192552.762975][4649:4656] CHIP:IN: Sending msg on generic transport
[1634192552.763208][4649:4656] CHIP:DMG: Client[0] moving to [AwaitingInitialReport]
[1634192552.909510][4649:4656] CHIP:EM: Received message of type 0x05 with vendorId 0x0000 and protocolId 0x0001 on exchange 11573i
[1634192552.909661][4649:4656] CHIP:EM: Rxd Ack; Removing MessageCounter:00000068 from Retrans Table
[1634192552.909717][4649:4656] CHIP:EM: Removed CHIP MessageCounter:00000068 from RetransTable
[1634192552.909821][4649:4656] CHIP:DMG: ReportData =
[1634192552.909882][4649:4656] CHIP:DMG: {
[1634192552.909931][4649:4656] CHIP:DMG:        AttributeDataList =
[1634192552.909994][4649:4656] CHIP:DMG:        [
[1634192552.910048][4649:4656] CHIP:DMG:                AttributeDataElement =
[1634192552.910114][4649:4656] CHIP:DMG:                {
[1634192552.910170][4649:4656] CHIP:DMG:                        AttributePath =
[1634192552.910292][4649:4656] CHIP:DMG:                        {
[1634192552.910366][4649:4656] CHIP:DMG:                                NodeId = 0xbc5c01,
[1634192552.910435][4649:4656] CHIP:DMG:                                EndpointId = 0x1,
[1634192552.910517][4649:4656] CHIP:DMG:                                ClusterId = 0x300,
[1634192552.910591][4649:4656] CHIP:DMG:                                FieldTag = 0x0,
[1634192552.910662][4649:4656] CHIP:DMG:                        }
[1634192552.910740][4649:4656] CHIP:DMG:
[1634192552.910814][4649:4656] CHIP:DMG:                        Data = 156,
[1634192552.910891][4649:4656] CHIP:DMG:                        DataElementVersion = 0x0,
[1634192552.910959][4649:4656] CHIP:DMG:                },
[1634192552.911021][4649:4656] CHIP:DMG:
[1634192552.911073][4649:4656] CHIP:DMG:        ],
[1634192552.911144][4649:4656] CHIP:DMG:
[1634192552.911194][4649:4656] CHIP:DMG: }
[1634192552.911819][4649:4656] CHIP:ZCL: ReadAttributesResponse:
[1634192552.911889][4649:4656] CHIP:ZCL:   ClusterId: 0x0000_0300
[1634192552.911946][4649:4656] CHIP:ZCL:   attributeId: 0x0000_0000
[1634192552.911994][4649:4656] CHIP:ZCL:   status: Success                (0x0000)
[1634192552.912040][4649:4656] CHIP:ZCL:   attribute TLV Type: 0x04
[1634192552.912100][4649:4656] CHIP:ZCL:   attributeValue: 156
[1634192552.912344][4649:4656] CHIP:EM: Piggybacking Ack for MessageCounter:00000062 on exchange: 11573i
AttributeReadResult(path=AttributePath(nodeId=12344321, endpointId=1, clusterId=768, attributeId=0), status=0, value=156)
[1634192552.912513][4649:4656] CHIP:IN: Secure message was encrypted: Msg ID 105
[1634192552.912575][4649:4656] CHIP:IN: Build encrypted message 0x7062258 to 0x0000000000BC5C01 of type 1 and protocolId 1 on exchange 11573r with MessageCounter 105.
[1634192552.912650][4649:4656] CHIP:IN: Sending encrypted msg 0x7062258 to 0x0000000000BC5C01 at utc time: 7446058 msec
[1634192552.912704][4649:4656] CHIP:IN: Sending msg on generic transport
chip-device-ctrl > [1634192552.912981][4649:4656] CHIP:DMG: Client[0] moving to [UNINIT]
[1634192553.117622][4649:4656] CHIP:EM: Received message of type 0x10 with vendorId 0x0000 and protocolId 0x0000 on exchange 11573i
[1634192553.117790][4649:4656] CHIP:EM: Rxd Ack; Removing MessageCounter:00000069 from Retrans Table
[1634192553.117856][4649:4656] CHIP:EM: Removed CHIP MessageCounter:00000069 from RetransTable
zclread ColorControl CurrentHue 12344321 1 0
[1634192557.330216][4649:4656] CHIP:DMG: SendReadRequest: Client[0] [ INIT]
[1634192557.330485][4649:4656] CHIP:IN: Secure message was encrypted: Msg ID 106
[1634192557.330541][4649:4656] CHIP:IN: Build encrypted message 0x7062258 to 0x0000000000BC5C01 of type 2 and protocolId 1 on exchange 11574r with MessageCounter 106.
[1634192557.330612][4649:4656] CHIP:IN: Sending encrypted msg 0x7062258 to 0x0000000000BC5C01 at utc time: 7450476 msec
[1634192557.330660][4649:4656] CHIP:IN: Sending msg on generic transport
[1634192557.330844][4649:4656] CHIP:DMG: Client[0] moving to [AwaitingInitialReport]
[1634192557.598809][4649:4656] CHIP:EM: Received message of type 0x05 with vendorId 0x0000 and protocolId 0x0001 on exchange 11574i
[1634192557.598978][4649:4656] CHIP:EM: Rxd Ack; Removing MessageCounter:0000006A from Retrans Table
[1634192557.599044][4649:4656] CHIP:EM: Removed CHIP MessageCounter:0000006A from RetransTable
[1634192557.599159][4649:4656] CHIP:DMG: ReportData =
[1634192557.599231][4649:4656] CHIP:DMG: {
[1634192557.599287][4649:4656] CHIP:DMG:        AttributeDataList =
[1634192557.599347][4649:4656] CHIP:DMG:        [
[1634192557.599401][4649:4656] CHIP:DMG:                AttributeDataElement =
[1634192557.599483][4649:4656] CHIP:DMG:                {
[1634192557.599561][4649:4656] CHIP:DMG:                        AttributePath =
[1634192557.599640][4649:4656] CHIP:DMG:                        {
[1634192557.599727][4649:4656] CHIP:DMG:                                NodeId = 0xbc5c01,
[1634192557.599819][4649:4656] CHIP:DMG:                                EndpointId = 0x1,
[1634192557.599908][4649:4656] CHIP:DMG:                                ClusterId = 0x300,
[1634192557.599999][4649:4656] CHIP:DMG:                                FieldTag = 0x0,
[1634192557.600080][4649:4656] CHIP:DMG:                        }
[1634192557.600181][4649:4656] CHIP:DMG:
[1634192557.600259][4649:4656] CHIP:DMG:                        Data = 155,
[1634192557.600344][4649:4656] CHIP:DMG:                        DataElementVersion = 0x0,
[1634192557.600425][4649:4656] CHIP:DMG:                },
[1634192557.600510][4649:4656] CHIP:DMG:
[1634192557.600572][4649:4656] CHIP:DMG:        ],
[1634192557.600649][4649:4656] CHIP:DMG:
[1634192557.600708][4649:4656] CHIP:DMG: }
[1634192557.601400][4649:4656] CHIP:ZCL: ReadAttributesResponse:
[1634192557.601481][4649:4656] CHIP:ZCL:   ClusterId: 0x0000_0300
[1634192557.601545][4649:4656] CHIP:ZCL:   attributeId: 0x0000_0000
[1634192557.601602][4649:4656] CHIP:ZCL:   status: Success                (0x0000)
[1634192557.601656][4649:4656] CHIP:ZCL:   attribute TLV Type: 0x04
[1634192557.601724][4649:4656] CHIP:ZCL:   attributeValue: 155
[1634192557.601983][4649:4656] CHIP:EM: Piggybacking Ack for MessageCounter:00000064 on exchange: 11574i
AttributeReadResult(path=AttributePath(nodeId=12344321, endpointId=1, clusterId=768, attributeId=0), status=0, value=155)
[1634192557.602161][4649:4656] CHIP:IN: Secure message was encrypted: Msg ID 107
[1634192557.602350][4649:4656] CHIP:IN: Build encrypted message 0x7062258 to 0x0000000000BC5C01 of type 1 and protocolId 1 on exchange 11574r with MessageCounter 107.
[1634192557.602443][4649:4656] CHIP:IN: Sending encrypted msg 0x7062258 to 0x0000000000BC5C01 at utc time: 7450748 msec
[1634192557.602667][4649:4656] CHIP:IN: Sending msg on generic transport
chip-device-ctrl > [1634192557.603071][4649:4656] CHIP:DMG: Client[0] moving to [UNINIT]
[1634192557.803003][4649:4656] CHIP:EM: Received message of type 0x10 with vendorId 0x0000 and protocolId 0x0000 on exchange 11574i
[1634192557.803102][4649:4656] CHIP:EM: Rxd Ack; Removing MessageCounter:0000006B from Retrans Table
[1634192557.803129][4649:4656] CHIP:EM: Removed CHIP MessageCounter:0000006B from RetransTable
zclread ColorControl CurrentHue 12344321 1 0
[1634192559.718517][4649:4656] CHIP:DMG: SendReadRequest: Client[0] [ INIT]
[1634192559.718838][4649:4656] CHIP:IN: Secure message was encrypted: Msg ID 108
[1634192559.718912][4649:4656] CHIP:IN: Build encrypted message 0x7062258 to 0x0000000000BC5C01 of type 2 and protocolId 1 on exchange 11575r with MessageCounter 108.
[1634192559.718993][4649:4656] CHIP:IN: Sending encrypted msg 0x7062258 to 0x0000000000BC5C01 at utc time: 7452864 msec
[1634192559.719058][4649:4656] CHIP:IN: Sending msg on generic transport
[1634192559.719345][4649:4656] CHIP:DMG: Client[0] moving to [AwaitingInitialReport]
[1634192559.975382][4649:4656] CHIP:EM: Received message of type 0x05 with vendorId 0x0000 and protocolId 0x0001 on exchange 11575i
[1634192559.975533][4649:4656] CHIP:EM: Rxd Ack; Removing MessageCounter:0000006C from Retrans Table
[1634192559.975589][4649:4656] CHIP:EM: Removed CHIP MessageCounter:0000006C from RetransTable
[1634192559.975690][4649:4656] CHIP:DMG: ReportData =
[1634192559.975751][4649:4656] CHIP:DMG: {
[1634192559.975799][4649:4656] CHIP:DMG:        AttributeDataList =
[1634192559.975852][4649:4656] CHIP:DMG:        [
[1634192559.975905][4649:4656] CHIP:DMG:                AttributeDataElement =
[1634192559.975979][4649:4656] CHIP:DMG:                {
[1634192559.976029][4649:4656] CHIP:DMG:                        AttributePath =
[1634192559.976102][4649:4656] CHIP:DMG:                        {
[1634192559.976174][4649:4656] CHIP:DMG:                                NodeId = 0xbc5c01,
[1634192559.976258][4649:4656] CHIP:DMG:                                EndpointId = 0x1,
[1634192559.976326][4649:4656] CHIP:DMG:                                ClusterId = 0x300,
[1634192559.976409][4649:4656] CHIP:DMG:                                FieldTag = 0x0,
[1634192559.976489][4649:4656] CHIP:DMG:                        }
[1634192559.976575][4649:4656] CHIP:DMG:
[1634192559.976648][4649:4656] CHIP:DMG:                        Data = 155,
[1634192559.976724][4649:4656] CHIP:DMG:                        DataElementVersion = 0x0,
[1634192559.976797][4649:4656] CHIP:DMG:                },
[1634192559.976869][4649:4656] CHIP:DMG:
[1634192559.976922][4649:4656] CHIP:DMG:        ],
[1634192559.976987][4649:4656] CHIP:DMG:
[1634192559.977036][4649:4656] CHIP:DMG: }
[1634192559.977659][4649:4656] CHIP:ZCL: ReadAttributesResponse:
[1634192559.977728][4649:4656] CHIP:ZCL:   ClusterId: 0x0000_0300
[1634192559.977784][4649:4656] CHIP:ZCL:   attributeId: 0x0000_0000
[1634192559.977831][4649:4656] CHIP:ZCL:   status: Success                (0x0000)
[1634192559.977877][4649:4656] CHIP:ZCL:   attribute TLV Type: 0x04
[1634192559.977935][4649:4656] CHIP:ZCL:   attributeValue: 155
[1634192559.978172][4649:4656] CHIP:EM: Piggybacking Ack for MessageCounter:00000066 on exchange: 11575i
AttributeReadResult(path=AttributePath(nodeId=12344321, endpointId=1, clusterId=768, attributeId=0), status=0, value=155)
[1634192559.978397][4649:4656] CHIP:IN: Secure message was encrypted: Msg ID 109
[1634192559.978461][4649:4656] CHIP:IN: Build encrypted message 0x7062258 to 0x0000000000BC5C01 of type 1 and protocolId 1 on exchange 11575r with MessageCounter 109.
[1634192559.978537][4649:4656] CHIP:IN: Sending encrypted msg 0x7062258 to 0x0000000000BC5C01 at utc time: 7453124 msec
[1634192559.978593][4649:4656] CHIP:IN: Sending msg on generic transport
chip-device-ctrl > [1634192559.978916][4649:4656] CHIP:DMG: Client[0] moving to [UNINIT]
[1634192560.156871][4649:4656] CHIP:EM: Received message of type 0x10 with vendorId 0x0000 and protocolId 0x0000 on exchange 11575i
[1634192560.157003][4649:4656] CHIP:EM: Rxd Ack; Removing MessageCounter:0000006D from Retrans Table
[1634192560.157051][4649:4656] CHIP:EM: Removed CHIP MessageCounter:0000006D from RetransTable
'''

@lucyShi0116 Can you please re-verify this on a more recent matter?