[Matter] Lightswitch sample when spamming button 2

I have an application that requires invoking multiple commands to the same node in quick succession (multiple times a second).

To evaluate the feasibility of this, I flashed the Matter lightswitch sample on my NRF5340DK+NRF7002EK for a Matter over Wifi setup.

The commands work fine to turn the lightbulb on/off if I press button 2 normally, but if I spam button 2 quickly, after a while, it stops working for a long time, with CHIP_ERROR_NO_MEMORY errors

I: Notify Bounded Cluster | endpoint: 1 cluster: 6
I: 2366227 [DIS]Found an existing secure session to [1:00000000F2DB3567]!
D: 2366234 [DIS]OperationalSessionSetup[1:00000000F2DB3567]: State change 1 --> 5
E: Invoke OnOff Command Request ERROR: Error CHIP:0x0000000B
I: Button has been pressed, keep in this state for at least 500 ms to change light sensitivity of binded lighting devices.
I: 2366427 [IN](S) Sending msg 201809704 on secure session with LSID: 33345
I: Notify Bounded Cluster | endpoint: 1 cluster: 6
I: 2366480 [DIS]Found an existing secure session to [1:00000000F2DB3567]!
D: 2366487 [DIS]OperationalSessionSetup[1:00000000F2DB3567]: State change 1 --> 5
E: Invoke OnOff Command Request ERROR: Error CHIP:0x0000000B
I: 2366500 [IN](S) Sending msg 201809699 on secure session with LSID: 33345
I: 2366525 [IN](S) Sending msg 201809702 on secure session with LSID: 33345
I: Button has been pressed, keep in this state for at least 500 ms to change light sensitivity of binded lighting devices.
I: 2366692 [IN](S) Sending msg 201809705 on secure session with LSID: 33345
I: 2366710 [IN](S) Sending msg 201809700 on secure session with LSID: 33345

Then it fixes itself at a later point (after the session is marked as defunct, but that could be a red herring).

I: 2489896 [SC]SecureSession[0x20004768]: Moving from state 'kActive' --> 'kDefunct'
I: 2489904 [DMG]Time out! failed to receive invoke command response from Exchange: 48681i
E: Binding command was not applied! Reason: 32
I: Button has been pressed, keep in this state for at least 500 ms to change light sensitivity of binded lighting devices.
I: Notify Bounded Cluster | endpoint: 1 cluster: 6
D: 2823110 [DIS]OperationalSessionSetup[1:00000000F2DB3567]: State change 1 --> 2
D: 2823119 [DIS]OperationalSessionSetup[1:17FAB8AF6174CC68]: State change 1 --> 2
I: 2823318 [DIS]Checking node lookup status after 200 ms
I: 2823323 [DIS]Checking node lookup status after 196 ms
I: 2823328 [DIS]Keeping DNSSD lookup active
I: 2824273 [DIS]UDP:[......................]:5540: new best score: 3
D: 2824280 [DIS]Lookup clearing interface for non LL address
I: 2824285 [DIS]UDP:[......................%wlan0]:5540: new best score: 7
I: 2824293 [DIS]Checking node lookup status after 1175 ms
D: 2824298 [DIS]OperationalSessionSetup[1:00000000F2DB3567]: Updating device address to UDP:[......................]:5540 while in state 2
D: 2824312 [DIS]OperationalSessionSetup[1:00000000F2DB3567]: State change 2 --> 3
D: 2824320 [IN]SecureSession[0x20004820]: Allocated Type:2 LSID:33347
I: 2824326 [SC]Initiating session on local FabricIndex 1 from 0x7F0783EE8D41E3BA -> 0x00000000F2DB3567
I: 2824465 [EM]<<< [E:48682i S:0 M:156688477] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:30 (SecureChannel:CASE_Sigma1)
I: 2824478 [IN](U) Sending msg 156688477 to IP address 'UDP:[......................]:5540'
I: 2824489 [SC]Sent Sigma1 msg
D: 2824493 [DIS]OperationalSessionSetup[1:00000000F2DB3567]: State change 3 --> 4

Any thoughts on how to address this issue? I would like to know what specifically is running out of memory from attempting multiple invoke commands in quick succession. What are the limits?

Parents
  • Hi,

    Please upload the full log from the device.

    Best regards,
    Marte

  • Hi there, here are the full logs from the device.

    I have bound the light switch to 2 lightbulbs at endpoint 1 and clusters 6 (onoff) and 8 (levelcontrol)

    I spam button 2 until the Error CHIP:0x0000000B shows up and toggling hangs, then at the end I get a few successful toggles  on one lightbulb, then back to Error CHIP:0x0000000B.

    Logs:

    uart:~$ *** Booting nRF Connect SDK v2.5.2 ***
    I: Init CHIP stack
    I: 328 [DL]BLE address: ????:????:????:????:????:AA
    D: 357 [DL]WiFiManager has been initialized
    D: 362 [DL]Connecting to WiFi network: mywifi�
                                                      � 
    D: 374 [DL]WiFi scanning started...
    I: 378 [SVR]Subscription persistence not supported
    I: 383 [SVR]Server initializing...
    I: 390 [TS]Last Known Good Time: 2024-04-05T06:05:53
    I: 400 [FP]Fabric index 0x1 was retrieved from storage. Compressed FabricId 0x980B6182C720B098, FabricId 0x0000000000000001, NodeId 0x000000006BA9BAD9, VendorId 0xFFF1
    I: 416 [DMG]AccessControl: initializing
    I: 420 [DMG]Examples::AccessControlDelegate::Init
    I: 425 [DMG]AccessControl: setting
    I: 429 [DMG]DefaultAclStorage: initializing
    I: 438 [DMG]DefaultAclStorage: 1 entries loaded
    D: 443 [IN]UDP::Init bind&listen port=5540
    E: 447 [IN]SO_REUSEPORT failed: 109
    D: 460 [IN]UDP::Init bound to port=5540
    D: 463 [IN]BLEBase::Init - setting/overriding transport
    D: 468 [IN]TransportMgr initialized
    I: 476 [ZCL]Using ZAP configuration...
    I: 481 [DMG]AccessControlCluster: initializing
    D: 485 [DL]Boot reason: 1
    I: 488 [ZCL]Initiating Admin Commissioning cluster.
    I: 493 [SVR]Fabric already commissioned. Disabling BLE advertisement
    I: 499 [DIS]Updating services using commissioning mode 0
    I: 504 [DIS]CHIP minimal mDNS started advertising.
    D: 509 [DL]Using wifi MAC for hostname
    I: 512 [DIS]Advertise operational node 980B6182C720B098-000000006BA9BAD9
    D: 519 [DIS]Responding with _matter._tcp.local
    D: 523 [DIS]Responding with 980B6182C720B098-000000006BA9BAD9._matter._tcp.local
    D: 530 [DIS]Responding with 980B6182C720B098-000000006BA9BAD9._matter._tcp.local
    D: 537 [DIS]Responding with F4CE36004FD3.local
    D: 542 [DIS]Responding with F4CE36004FD3.local
    D: 546 [DIS]Responding with _I980B6182C720B098._sub._matter._tcp.local
    I: 552 [DIS]CHIP minimal mDNS configured as 'Operational device'; instance name: 980B6182C720B098-000000006BA9BAD9.
    I: 562 [DIS]mDNS service published: _matter._tcp
    I: 567 [IN]CASE Server enabling CASE session setups
    D: 572 [IN]SecureSession[0x20004318]: Allocated Type:2 LSID:44101
    I: 577 [SVR]Joining Multicast groups
    I: 582 [SVR]Server Listening...
    I: 584 [DL]Device Configuration:
    I: 587 [DL]  Serial Number: 11223344556677889900
    I: 592 [DL]  Vendor Id: 65521 (0xFFF1)
    I: 595 [DL]  Product Id: 32772 (0x8004)
    I: 599 [DL]  Product Name: not-specified
    I: 602 [DL]  Hardware Version: 0
    I: 605 [DL]  Setup Pin Code (0 for UNKNOWN/ERROR): 20202021
    I: 611 [DL]  Setup Discriminator (0xFFFF for UNKNOWN/ERROR): 3840 (0xF00)
    I: 617 [DL]  Manufacturing Date: 2022-01-01
    I: 621 [DL]  Device Type: 65535 (0xFFFF)
    I: 625 [SVR]SetupQRCode: [MT:4CT9142C00KA0648G00]
    I: 629 [SVR]Copy/paste the below URL in a browser to see the QR Code:
    I: 635 [SVR]https://project-chip.github.io/connectedhomeip/qrcode.html?data=MT%3A4CT9142C00KA0648G00
    I: 644 [SVR]Manual pairing code: [34970112332]
    I: 649 [DL]CHIP task running
    I: Initialize binding Handler
    D: 663 [DIS]OperationalSessionSetup[1:000000002A3ACA7D]: State change 1 --> 2
    D: 675 [DIS]OperationalSessionSetup[1:000000002A3ACA7D]: State change 2 --> 1
    E: 682 [SVR]Failed to establish connection to node 0x000000002A3ACA7D
    D: 689 [DIS]OperationalSessionSetup[1:00000000F2DB3567]: State change 1 --> 2
    D: 697 [DIS]OperationalSessionSetup[1:00000000F2DB3567]: State change 2 --> 1
    E: 704 [SVR]Failed to establish connection to node 0x00000000F2DB3567
    D: 712 [DIS]OperationalSessionSetup[1:000000002A3ACA7D]: State change 1 --> 2
    D: 720 [DIS]OperationalSessionSetup[1:000000002A3ACA7D]: State change 2 --> 1
    E: 727 [SVR]Failed to establish connection to node 0x000000002A3ACA7D
    D: 734 [DIS]OperationalSessionSetup[1:00000000F2DB3567]: State change 1 --> 2
    D: 744 [DIS]OperationalSessionSetup[1:00000000F2DB3567]: State change 2 --> 1
    E: 751 [SVR]Failed to establish connection to node 0x00000000F2DB3567
    I: Binding Table size: [4]:
    I: [0] UNICAST:
    I:              + Fabric: 1
                    + LocalEndpoint 1 
                    + ClusterId 6 
                    + RemoteEndpointId 1 
                    + NodeId 708495997
    I: [1] UNICAST:
    I:              + Fabric: 1
                    + LocalEndpoint 1 
                    + ClusterId 6 
                    + RemoteEndpointId 1 
                    + NodeId -220514969
    I: [2] UNICAST:
    I:              + Fabric: 1
                    + LocalEndpoint 1 
                    + ClusterId 8 
                    + RemoteEndpointId 1 
                    + NodeId 708495997
    I: [3] UNICAST:
    I:              + Fabric: 1
                    + LocalEndpoint 1 
                    + ClusterId 8 
                    + RemoteEndpointId 1 
                    + NodeId -220514969
    E: 826 [DL]Long dispatch time: 173 ms, for event type 2
    OK
    I: 5007 [DL]Wi-Fi scan done (0)
    OK
    OK
    OK
    OK
    OK
    OK
    OK
    OK
    OK
    OK
    I: 5034 [DL]Connection to mywifi requested [RSSI=-28]
    I: 16434 [DL]Connected to WiFi network
    I: 16444 [SWU]Stopping the watchdog timer
    I: 16448 [SWU]Starting the periodic query timer, timeout: 86400 seconds
    E: 16454 [SVR]Server initialization complete
    I: 16458 [DIS]Updating services using commissioning mode 0
    E: 16463 [IN]SO_REUSEPORT failed: 109
    I: 16468 [DIS]CHIP minimal mDNS started advertising.
    D: 16485 [DL]Using wifi MAC for hostname
    I: 16489 [DIS]Advertise operational node 980B6182C720B098-000000006BA9BAD9
    D: 16498 [DIS]Responding with _matter._tcp.local
    D: 16503 [DIS]Responding with 980B6182C720B098-000000006BA9BAD9._matter._tcp.local
    D: 16511 [DIS]Responding with 980B6182C720B098-000000006BA9BAD9._matter._tcp.local
    D: 16519 [DIS]Responding with F4CE36004FD3.local
    D: 16524 [DIS]Responding with F4CE36004FD3.local
    D: 16529 [DIS]Responding with _I980B6182C720B098._sub._matter._tcp.local
    I: 16535 [DIS]CHIP minimal mDNS configured as 'Operational device'; instance name: 980B6182C720B098-000000006BA9BAD9.
    I: 16550 [DIS]mDNS service published: _matter._tcp
    E: 16555 [DL]Long dispatch time: 101 ms, for event type 32784
    I: 16561 [DIS]Updating services using commissioning mode 0
    E: 16567 [IN]SO_REUSEPORT failed: 109
    I: 16572 [DIS]CHIP minimal mDNS started advertising.
    D: 16588 [DL]Using wifi MAC for hostname
    I: 16593 [DIS]Advertise operational node 980B6182C720B098-000000006BA9BAD9
    D: 16600 [DIS]Responding with _matter._tcp.local
    D: 16605 [DIS]Responding with 980B6182C720B098-000000006BA9BAD9._matter._tcp.local
    D: 16613 [DIS]Responding with 980B6182C720B098-000000006BA9BAD9._matter._tcp.local
    D: 16621 [DIS]Responding with F4CE36004FD3.local
    D: 16625 [DIS]Responding with F4CE36004FD3.local
    D: 16630 [DIS]Responding with _I980B6182C720B098._sub._matter._tcp.local
    I: 16636 [DIS]CHIP minimal mDNS configured as 'Operational device'; instance name: 980B6182C720B098-000000006BA9BAD9.
    I: 16651 [DIS]mDNS service published: _matter._tcp
    I: 16705 [DIS]Updating services using commissioning mode 0
    E: 16713 [IN]SO_REUSEPORT failed: 109
    I: 16721 [DIS]CHIP minimal mDNS started advertising.
    D: 16756 [DL]Using wifi MAC for hostname
    I: 16760 [DIS]Advertise operational node 980B6182C720B098-000000006BA9BAD9
    D: 16768 [DIS]Responding with _matter._tcp.local
    D: 16772 [DIS]Responding with 980B6182C720B098-000000006BA9BAD9._matter._tcp.local
    D: 16780 [DIS]Responding with 980B6182C720B098-000000006BA9BAD9._matter._tcp.local
    D: 16787 [DIS]Responding with F4CE36004FD3.local
    D: 16791 [DIS]Responding with F4CE36004FD3.local
    D: 16797 [DIS]Responding with _I980B6182C720B098._sub._matter._tcp.local
    I: 16805 [DIS]CHIP minimal mDNS configured as 'Operational device'; instance name: 980B6182C720B098-000000006BA9BAD9.
    I: 16829 [DIS]mDNS service published: _matter._tcp
    E: 16834 [DL]Long dispatch time: 129 ms, for event type 32785
    I: Button has been pressed, keep in this state for at least 500 ms to change light sensitivity of binded lighting devices.
    I: Notify Bounded Cluster | endpoint: 1 cluster: 6
    D: 34417 [DIS]OperationalSessionSetup[1:000000002A3ACA7D]: State change 1 --> 2
    D: 34426 [DIS]OperationalSessionSetup[1:00000000F2DB3567]: State change 1 --> 2
    I: 34536 [DIS]UDP:[fe80::????:????:????:????:????c2fc%wlan0]:5540: new best score: 3
    D: 34544 [DIS]Lookup clearing interface for non LL address
    I: 34550 [DIS]UDP:[????:????:????:????:????:99ff:fe72:c2fc%wlan0]:5540: new best score: 7
    I: 34558 [DIS]Checking node lookup status after 125 ms
    I: 34564 [DIS]Keeping DNSSD lookup active
    I: 34624 [DIS]Checking node lookup status after 200 ms
    I: 34629 [DIS]Checking node lookup status after 196 ms
    I: 34634 [DIS]Keeping DNSSD lookup active
    I: 34638 [DIS]Checking node lookup status after 214 ms
    I: 34642 [DIS]Checking node lookup status after 209 ms
    D: 34647 [DIS]OperationalSessionSetup[1:00000000F2DB3567]: Updating device address to UDP:[????:????:????:????:????:99ff:fe72:c2fc]:5540 while in state 2
    D: 34661 [DIS]OperationalSessionSetup[1:00000000F2DB3567]: State change 2 --> 3
    D: 34669 [IN]SecureSession[0x200043d0]: Allocated Type:2 LSID:44102
    I: 34675 [SC]Initiating session on local FabricIndex 1 from 0x000000006BA9BAD9 -> 0x00000000F2DB3567
    I: 34802 [EM]<<< [E:51703i S:0 M:173326024] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:30 (SecureChannel:CASE_Sigma1)
    I: 34814 [IN](U) Sending msg 173326024 to IP address 'UDP:[????:????:????:????:????:99ff:fe72:c2fc]:5540'
    I: 34824 [SC]Sent Sigma1 msg
    D: 34827 [DIS]OperationalSessionSetup[1:00000000F2DB3567]: State change 3 --> 4
    I: 34914 [EM]>>> [E:51703i S:0 M:110618085 (Ack:173326024)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
    I: 34930 [EM]>>> [E:51703i S:0 M:110618086 (Ack:173326024)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:33 (SecureChannel:CASE_Sigma2Resume)
    I: 34944 [EM]<<< [E:51703i S:0 M:173326025 (Ack:110618086)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
    I: 34957 [IN](U) Sending msg 173326025 to IP address 'UDP:[????:????:????:????:????:99ff:fe72:c2fc]:5540'
    I: 34976 [EM]<<< [E:51703i S:0 M:173326026 (Ack:110618086)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:40 (SecureChannel:StatusReport)
    I: 34989 [IN](U) Sending msg 173326026 to IP address 'UDP:[????:????:????:????:????:99ff:fe72:c2fc]:5540'
    I: 35001 [SC]SecureSession[0x200043d0]: Moving from state 'kEstablishing' --> 'kActive'
    D: 35009 [IN]SecureSession[0x200043d0]: Activated - Type:2 LSID:44102
    D: 35016 [IN]New secure session activated for device <00000000F2DB3567, 1>, LSID:44102 PSID:47564!
    D: 35026 [DIS]OperationalSessionSetup[1:00000000F2DB3567]: State change 4 --> 5
    I: 35035 [EM]<<< [E:51704i S:44102 M:99050] (S) Msg TX to 1:00000000F2DB3567 [B098] --- Type 0001:08 (IM:InvokeCommandRequest)
    I: 35046 [IN](S) Sending msg 99050 on secure session with LSID: 44102
    I: 35237 [EM]>>> [E:51703i S:0 M:110618087 (Ack:173326026)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
    I: 35340 [EM]>>> [E:51704i S:44102 M:262917049 (Ack:99050)] (S) Msg RX from 1:00000000F2DB3567 [B098] --- Type 0001:09 (IM:InvokeCommandResponse)
    I: 35353 [DMG]Received Command Response Status for Endpoint=1 Cluster=0x0000_0006 Command=0x0000_0002 Status=0x0
    D: Binding command applied successfully!
    I: 35367 [EM]<<< [E:51704i S:44102 M:99051 (Ack:262917049)] (S) Msg TX to 1:00000000F2DB3567 [B098] --- Type 0000:10 (SecureChannel:StandaloneAck)
    I: 35380 [IN](S) Sending msg 99051 on secure session with LSID: 44102
    I: 37592 [DIS]UDP:[fe80::????:????:????:????:????a3c8%wlan0]:5540: new best score: 3
    D: 37599 [DIS]Lookup clearing interface for non LL address
    I: 37604 [DIS]UDP:[????:????:????:????:????:99ff:fe71:a3c8%wlan0]:5540: new best score: 7
    I: 37612 [DIS]Checking node lookup status after 3188 ms
    D: 37617 [DIS]OperationalSessionSetup[1:000000002A3ACA7D]: Updating device address to UDP:[????:????:????:????:????:99ff:fe71:a3c8]:5540 while in state 2
    D: 37630 [DIS]OperationalSessionSetup[1:000000002A3ACA7D]: State change 2 --> 3
    D: 37638 [IN]SecureSession[0x20004488]: Allocated Type:2 LSID:44103
    I: 37644 [SC]Initiating session on local FabricIndex 1 from 0x000000006BA9BAD9 -> 0x000000002A3ACA7D
    I: 37772 [EM]<<< [E:51705i S:0 M:173326027] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:30 (SecureChannel:CASE_Sigma1)
    I: 37784 [IN](U) Sending msg 173326027 to IP address 'UDP:[????:????:????:????:????:99ff:fe71:a3c8]:5540'
    I: 37794 [SC]Sent Sigma1 msg
    D: 37797 [DIS]OperationalSessionSetup[1:000000002A3ACA7D]: State change 3 --> 4
    I: 37891 [EM]>>> [E:51705i S:0 M:10471209 (Ack:173326027)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
    I: Button has been pressed, keep in this state for at least 500 ms to change light sensitivity of binded lighting devices.
    I: 37921 [EM]>>> [E:51705i S:0 M:10471210 (Ack:173326027)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:33 (SecureChannel:CASE_Sigma2Resume)
    I: 37934 [EM]<<< [E:51705i S:0 M:173326028 (Ack:10471210)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
    I: 37947 [IN](U) Sending msg 173326028 to IP address 'UDP:[????:????:????:????:????:99ff:fe71:a3c8]:5540'
    I: 37964 [EM]<<< [E:51705i S:0 M:173326029 (Ack:10471210)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:40 (SecureChannel:StatusReport)
    I: 37977 [IN](U) Sending msg 173326029 to IP address 'UDP:[????:????:????:????:????:99ff:fe71:a3c8]:5540'
    I: 37989 [SC]SecureSession[0x20004488]: Moving from state 'kEstablishing' --> 'kActive'
    D: 37998 [IN]SecureSession[0x20004488]: Activated - Type:2 LSID:44103
    D: 38005 [IN]New secure session activated for device <000000002A3ACA7D, 1>, LSID:44103 PSID:51948!
    D: 38014 [DIS]OperationalSessionSetup[1:000000002A3ACA7D]: State change 4 --> 5
    I: 38023 [EM]<<< [E:51706i S:44103 M:255283903] (S) Msg TX to 1:000000002A3ACA7D [B098] --- Type 0001:08 (IM:InvokeCommandRequest)
    I: 38035 [IN](S) Sending msg 255283903 on secure session with LSID: 44103
    I: Notify Bounded Cluster | endpoint: 1 cluster: 6
    I: 38048 [DIS]Found an existing secure session to [1:000000002A3ACA7D]!
    D: 38056 [DIS]OperationalSessionSetup[1:000000002A3ACA7D]: State change 1 --> 5
    I: 38064 [EM]<<< [E:51707i S:44103 M:255283904] (S) Msg TX to 1:000000002A3ACA7D [B098] --- Type 0001:08 (IM:InvokeCommandRequest)
    I: 38076 [IN](S) Sending msg 255283904 on secure session with LSID: 44103
    I: 38083 [DIS]Found an existing secure session to [1:00000000F2DB3567]!
    D: 38090 [DIS]OperationalSessionSetup[1:00000000F2DB3567]: State change 1 --> 5
    I: 38101 [EM]<<< [E:51708i S:44102 M:99052] (S) Msg TX to 1:00000000F2DB3567 [B098] --- Type 0001:08 (IM:InvokeCommandRequest)
    I: 38113 [IN](S) Sending msg 99052 on secure session with LSID: 44102
    I: 38181 [EM]>>> [E:51708i S:44102 M:262917050 (Ack:99052)] (S) Msg RX from 1:00000000F2DB3567 [B098] --- Type 0001:09 (IM:InvokeCommandResponse)
    I: 38195 [DMG]Received Command Response Status for Endpoint=1 Cluster=0x0000_0006 Command=0x0000_0002 Status=0x0
    D: Binding command applied successfully!
    I: 38210 [EM]<<< [E:51708i S:44102 M:99053 (Ack:262917050)] (S) Msg TX to 1:00000000F2DB3567 [B098] --- Type 0000:10 (SecureChannel:StandaloneAck)
    I: 38224 [IN](S) Sending msg 99053 on secure session with LSID: 44102
    I: 38317 [EM]>>> [E:51705i S:0 M:10471211 (Ack:173326029)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
    I: 38337 [EM]>>> [E:51706i S:44103 M:108967118 (Ack:255283903)] (S) Msg RX from 1:000000002A3ACA7D [B098] --- Type 0001:09 (IM:InvokeCommandResponse)
    I: 38351 [DMG]Received Command Response Status for Endpoint=1 Cluster=0x0000_0006 Command=0x0000_0002 Status=0x0
    D: Binding command applied successfully!
    I: 38365 [EM]<<< [E:51706i S:44103 M:255283905 (Ack:108967118)] (S) Msg TX to 1:000000002A3ACA7D [B098] --- Type 0000:10 (SecureChannel:StandaloneAck)
    I: 38379 [IN](S) Sending msg 255283905 on secure session with LSID: 44103
    I: 38388 [EM]>>> [E:51707i S:44103 M:108967119 (Ack:255283904)] (S) Msg RX from 1:000000002A3ACA7D [B098] --- Type 0001:09 (IM:InvokeCommandResponse)
    I: 38402 [DMG]Received Command Response Status for Endpoint=1 Cluster=0x0000_0006 Command=0x0000_0002 Status=0x0
    D: Binding command applied successfully!
    I: 38419 [EM]<<< [E:51707i S:44103 M:255283906 (Ack:108967119)] (S) Msg TX to 1:000000002A3ACA7D [B098] --- Type 0000:10 (SecureChannel:StandaloneAck)
    I: 38433 [IN](S) Sending msg 255283906 on secure session with LSID: 44103
    I: Button has been pressed, keep in this state for at least 500 ms to change light sensitivity of binded lighting devices.
    I: Notify Bounded Cluster | endpoint: 1 cluster: 6
    I: 40219 [DIS]Found an existing secure session to [1:000000002A3ACA7D]!
    D: 40225 [DIS]OperationalSessionSetup[1:000000002A3ACA7D]: State change 1 --> 5
    I: 40233 [EM]<<< [E:51709i S:44103 M:255283907] (S) Msg TX to 1:000000002A3ACA7D [B098] --- Type 0001:08 (IM:InvokeCommandRequest)
    I: 40245 [IN](S) Sending msg 255283907 on secure session with LSID: 44103
    I: 40253 [DIS]Found an existing secure session to [1:00000000F2DB3567]!
    D: 40259 [DIS]OperationalSessionSetup[1:00000000F2DB3567]: State change 1 --> 5
    I: 40268 [EM]<<< [E:51710i S:44102 M:99054] (S) Msg TX to 1:00000000F2DB3567 [B098] --- Type 0001:08 (IM:InvokeCommandRequest)
    I: 40280 [IN](S) Sending msg 99054 on secure session with LSID: 44102
    I: 40330 [EM]>>> [E:51709i S:44103 M:108967120 (Ack:255283907)] (S) Msg RX from 1:000000002A3ACA7D [B098] --- Type 0001:09 (IM:InvokeCommandResponse)
    I: 40344 [DMG]Received Command Response Status for Endpoint=1 Cluster=0x0000_0006 Command=0x0000_0002 Status=0x0
    D: Binding command applied successfully!
    I: 40361 [EM]<<< [E:51709i S:44103 M:255283908 (Ack:108967120)] (S) Msg TX to 1:000000002A3ACA7D [B098] --- Type 0000:10 (SecureChannel:StandaloneAck)
    I: 40375 [IN](S) Sending msg 255283908 on secure session with LSID: 44103
    I: 40396 [EM]>>> [E:51710i S:44102 M:262917051 (Ack:99054)] (S) Msg RX from 1:00000000F2DB3567 [B098] --- Type 0001:09 (IM:InvokeCommandResponse)
    I: 40410 [DMG]Received Command Response Status for Endpoint=1 Cluster=0x0000_0006 Command=0x0000_0002 Status=0x0
    D: Binding command applied successfully!
    I: 40432 [EM]<<< [E:51710i S:44102 M:99055 (Ack:262917051)] (S) Msg TX to 1:00000000F2DB3567 [B098] --- Type 0000:10 (SecureChannel:StandaloneAck)
    I: 40446 [IN](S) Sending msg 99055 on secure session with LSID: 44102
    D: 42100 [IN]Received a duplicate message with MessageCounter:262917051 on exchange 51710i
    I: 42109 [EM]>>> [E:51710i S:44102 M:262917051 (Ack:99054)] (S) Msg RX from 1:00000000F2DB3567 [B098] --- Type 0001:09 (IM:InvokeCommandResponse)
    I: 42123 [EM]<<< [E:51710i S:44102 M:99056 (Ack:262917051)] (S) Msg TX to 1:00000000F2DB3567 [B098] --- Type 0000:10 (SecureChannel:StandaloneAck)
    I: 42136 [IN](S) Sending msg 99056 on secure session with LSID: 44102
    I: Button has been pressed, keep in this state for at least 500 ms to change light sensitivity of binded lighting devices.
    I: Notify Bounded Cluster | endpoint: 1 cluster: 6
    I: 43579 [DIS]Found an existing secure session to [1:000000002A3ACA7D]!
    D: 43586 [DIS]OperationalSessionSetup[1:000000002A3ACA7D]: State change 1 --> 5
    I: 43594 [EM]<<< [E:51711i S:44103 M:255283909] (S) Msg TX to 1:000000002A3ACA7D [B098] --- Type 0001:08 (IM:InvokeCommandRequest)
    I: 43605 [IN](S) Sending msg 255283909 on secure session with LSID: 44103
    I: 43613 [DIS]Found an existing secure session to [1:00000000F2DB3567]!
    D: 43620 [DIS]OperationalSessionSetup[1:00000000F2DB3567]: State change 1 --> 5
    I: 43632 [EM]<<< [E:51712i S:44102 M:99057] (S) Msg TX to 1:00000000F2DB3567 [B098] --- Type 0001:08 (IM:InvokeCommandRequest)
    I: 43643 [IN](S) Sending msg 99057 on secure session with LSID: 44102
    I: 43666 [EM]>>> [E:51711i S:44103 M:108967121 (Ack:255283909)] (S) Msg RX from 1:000000002A3ACA7D [B098] --- Type 0001:09 (IM:InvokeCommandResponse)
    I: 43682 [DMG]Received Command Response Status for Endpoint=1 Cluster=0x0000_0006 Command=0x0000_0002 Status=0x0
    D: Binding command applied successfully!
    I: Button has been pressed, keep in this state for at least 500 ms to change light sensitivity of binded lighting devices.
    I: 43707 [EM]<<< [E:51711i S:44103 M:255283910 (Ack:108967121)] (S) Msg TX to 1:000000002A3ACA7D [B098] --- Type 0000:10 (SecureChannel:StandaloneAck)
    I: 43721 [IN](S) Sending msg 255283910 on secure session with LSID: 44103
    I: Notify Bounded Cluster | endpoint: 1 cluster: 6
    I: 43806 [DIS]Found an existing secure session to [1:000000002A3ACA7D]!
    D: 43813 [DIS]OperationalSessionSetup[1:000000002A3ACA7D]: State change 1 --> 5
    I: 43821 [EM]<<< [E:51713i S:44103 M:255283911] (S) Msg TX to 1:000000002A3ACA7D [B098] --- Type 0001:08 (IM:InvokeCommandRequest)
    I: 43833 [IN](S) Sending msg 255283911 on secure session with LSID: 44103
    I: 43841 [DIS]Found an existing secure session to [1:00000000F2DB3567]!
    D: 43849 [DIS]OperationalSessionSetup[1:00000000F2DB3567]: State change 1 --> 5
    I: 43859 [EM]<<< [E:51714i S:44102 M:99058] (S) Msg TX to 1:00000000F2DB3567 [B098] --- Type 0001:08 (IM:InvokeCommandRequest)
    I: 43870 [IN](S) Sending msg 99058 on secure session with LSID: 44102
    I: Button has been pressed, keep in this state for at least 500 ms to change light sensitivity of binded lighting devices.
    I: 43914 [EM]>>> [E:51713i S:44103 M:108967122 (Ack:255283911)] (S) Msg RX from 1:000000002A3ACA7D [B098] --- Type 0001:09 (IM:InvokeCommandResponse)
    I: 43928 [DMG]Received Command Response Status for Endpoint=1 Cluster=0x0000_0006 Command=0x0000_0002 Status=0x0
    D: Binding command applied successfully!
    I: 43943 [EM]<<< [E:51713i S:44103 M:255283912 (Ack:108967122)] (S) Msg TX to 1:000000002A3ACA7D [B098] --- Type 0000:10 (SecureChannel:StandaloneAck)
    I: 43957 [IN](S) Sending msg 255283912 on secure session with LSID: 44103
    I: Notify Bounded Cluster | endpoint: 1 cluster: 6
    I: 44009 [DIS]Found an existing secure session to [1:000000002A3ACA7D]!
    D: 44015 [DIS]OperationalSessionSetup[1:000000002A3ACA7D]: State change 1 --> 5
    I: 44023 [EM]<<< [E:51715i S:44103 M:255283913] (S) Msg TX to 1:000000002A3ACA7D [B098] --- Type 0001:08 (IM:InvokeCommandRequest)
    I: 44035 [IN](S) Sending msg 255283913 on secure session with LSID: 44103
    I: 44044 [DIS]Found an existing secure session to [1:00000000F2DB3567]!
    D: 44051 [DIS]OperationalSessionSetup[1:00000000F2DB3567]: State change 1 --> 5
    I: 44061 [EM]<<< [E:51716i S:44102 M:99059] (S) Msg TX to 1:00000000F2DB3567 [B098] --- Type 0001:08 (IM:InvokeCommandRequest)
    I: 44072 [IN](S) Sending msg 99059 on secure session with LSID: 44102
    I: Button has been pressed, keep in this state for at least 500 ms to change light sensitivity of binded lighting devices.
    I: 44120 [EM]>>> [E:51715i S:44103 M:108967123 (Ack:255283913)] (S) Msg RX from 1:000000002A3ACA7D [B098] --- Type 0001:09 (IM:InvokeCommandResponse)
    I: 44133 [DMG]Received Command Response Status for Endpoint=1 Cluster=0x0000_0006 Command=0x0000_0002 Status=0x0
    D: Binding command applied successfully!
    I: 44149 [EM]<<< [E:51715i S:44103 M:255283914 (Ack:108967123)] (S) Msg TX to 1:000000002A3ACA7D [B098] --- Type 0000:10 (SecureChannel:StandaloneAck)
    I: 44163 [IN](S) Sending msg 255283914 on secure session with LSID: 44103
    I: Notify Bounded Cluster | endpoint: 1 cluster: 6
    I: 44204 [DIS]Found an existing secure session to [1:000000002A3ACA7D]!
    D: 44211 [DIS]OperationalSessionSetup[1:000000002A3ACA7D]: State change 1 --> 5
    I: 44219 [EM]<<< [E:51717i S:44103 M:255283915] (S) Msg TX to 1:000000002A3ACA7D [B098] --- Type 0001:08 (IM:InvokeCommandRequest)
    I: 44230 [IN](S) Sending msg 255283915 on secure session with LSID: 44103
    I: 44238 [DIS]Found an existing secure session to [1:00000000F2DB3567]!
    D: 44245 [DIS]OperationalSessionSetup[1:00000000F2DB3567]: State change 1 --> 5
    I: 44255 [EM]<<< [E:51718i S:44102 M:99060] (S) Msg TX to 1:00000000F2DB3567 [B098] --- Type 0001:08 (IM:InvokeCommandRequest)
    I: Button has been pressed, keep in this state for at least 500 ms to change light sensitivity of binded lighting devices.
    I: 44278 [IN](S) Sending msg 99060 on secure session with LSID: 44102
    I: 44292 [IN](S) Sending msg 99057 on secure session with LSID: 44102
    I: 44333 [EM]>>> [E:51717i S:44103 M:108967124 (Ack:255283915)] (S) Msg RX from 1:000000002A3ACA7D [B098] --- Type 0001:09 (IM:InvokeCommandResponse)
    I: 44348 [DMG]Received Command Response Status for Endpoint=1 Cluster=0x0000_0006 Command=0x0000_0002 Status=0x0
    D: Binding command applied successfully!
    I: 44364 [EM]<<< [E:51717i S:44103 M:255283916 (Ack:108967124)] (S) Msg TX to 1:000000002A3ACA7D [B098] --- Type 0000:10 (SecureChannel:StandaloneAck)
    I: 44377 [IN](S) Sending msg 255283916 on secure session with LSID: 44103
    I: Notify Bounded Cluster | endpoint: 1 cluster: 6
    I: 44390 [DIS]Found an existing secure session to [1:000000002A3ACA7D]!
    D: 44397 [DIS]OperationalSessionSetup[1:000000002A3ACA7D]: State change 1 --> 5
    I: 44406 [EM]<<< [E:51719i S:44103 M:255283917] (S) Msg TX to 1:000000002A3ACA7D [B098] --- Type 0001:08 (IM:InvokeCommandRequest)
    I: 44417 [IN](S) Sending msg 255283917 on secure session with LSID: 44103
    I: 44425 [DIS]Found an existing secure session to [1:00000000F2DB3567]!
    D: 44432 [DIS]OperationalSessionSetup[1:00000000F2DB3567]: State change 1 --> 5
    I: Button has been pressed, keep in this state for at least 500 ms to change light sensitivity of binded lighting devices.
    I: 44453 [EM]<<< [E:51720i S:44102 M:99061] (S) Msg TX to 1:00000000F2DB3567 [B098] --- Type 0001:08 (IM:InvokeCommandRequest)
    I: 44465 [IN](S) Sending msg 99061 on secure session with LSID: 44102
    I: Notify Bounded Cluster | endpoint: 1 cluster: 6
    I: 44540 [DIS]Found an existing secure session to [1:000000002A3ACA7D]!
    D: 44546 [DIS]OperationalSessionSetup[1:000000002A3ACA7D]: State change 1 --> 5
    I: 44556 [EM]<<< [E:51721i S:44103 M:255283918] (S) Msg TX to 1:000000002A3ACA7D [B098] --- Type 0001:08 (IM:InvokeCommandRequest)
    I: 44568 [IN](S) Sending msg 255283918 on secure session with LSID: 44103
    I: 44577 [DIS]Found an existing secure session to [1:00000000F2DB3567]!
    D: 44584 [DIS]OperationalSessionSetup[1:00000000F2DB3567]: State change 1 --> 5
    I: 44592 [EM]<<< [E:51722i S:44102 M:99062] (S) Msg TX to 1:00000000F2DB3567 [B098] --- Type 0001:08 (IM:InvokeCommandRequest)
    I: 44604 [IN](S) Sending msg 99062 on secure session with LSID: 44102
    I: Button has been pressed, keep in this state for at least 500 ms to change light sensitivity of binded lighting devices.
    I: 44625 [IN](S) Sending msg 99058 on secure session with LSID: 44102
    I: 44645 [EM]>>> [E:51721i S:44103 M:108967125 (Ack:255283918)] (S) Msg RX from 1:000000002A3ACA7D [B098] --- Type 0001:09 (IM:InvokeCommandResponse)
    I: 44661 [DMG]Received Command Response Status for Endpoint=1 Cluster=0x0000_0006 Command=0x0000_0002 Status=0x0
    D: Binding command applied successfully!
    I: 44678 [EM]<<< [E:51721i S:44103 M:255283919 (Ack:108967125)] (S) Msg TX to 1:000000002A3ACA7D [B098] --- Type 0000:10 (SecureChannel:StandaloneAck)
    I: 44692 [IN](S) Sending msg 255283919 on secure session with LSID: 44103
    I: Notify Bounded Cluster | endpoint: 1 cluster: 6
    I: 44727 [DIS]Found an existing secure session to [1:000000002A3ACA7D]!
    D: 44733 [DIS]OperationalSessionSetup[1:000000002A3ACA7D]: State change 1 --> 5
    I: 44742 [EM]<<< [E:51723i S:44103 M:255283920] (S) Msg TX to 1:000000002A3ACA7D [B098] --- Type 0001:08 (IM:InvokeCommandRequest)
    I: 44753 [IN](S) Sending msg 255283920 on secure session with LSID: 44103
    I: 44762 [DIS]Found an existing secure session to [1:00000000F2DB3567]!
    D: 44769 [DIS]OperationalSessionSetup[1:00000000F2DB3567]: State change 1 --> 5
    E: Invoke OnOff Command Request ERROR: Error CHIP:0x0000000B
    I: Button has been pressed, keep in this state for at least 500 ms to change light sensitivity of binded lighting devices.
    I: 44796 [IN](S) Sending msg 99059 on secure session with LSID: 44102
    I: 44838 [EM]>>> [E:51723i S:44103 M:108967126 (Ack:255283920)] (S) Msg RX from 1:000000002A3ACA7D [B098] --- Type 0001:09 (IM:InvokeCommandResponse)
    I: 44852 [DMG]Received Command Response Status for Endpoint=1 Cluster=0x0000_0006 Command=0x0000_0002 Status=0x0
    D: Binding command applied successfully!
    I: 44868 [EM]<<< [E:51723i S:44103 M:255283921 (Ack:108967126)] (S) Msg TX to 1:000000002A3ACA7D [B098] --- Type 0000:10 (SecureChannel:StandaloneAck)
    I: 44881 [IN](S) Sending msg 255283921 on secure session with LSID: 44103
    I: Notify Bounded Cluster | endpoint: 1 cluster: 6
    I: 44903 [DIS]Found an existing secure session to [1:000000002A3ACA7D]!
    D: 44910 [DIS]OperationalSessionSetup[1:000000002A3ACA7D]: State change 1 --> 5
    I: 44918 [EM]<<< [E:51725i S:44103 M:255283922] (S) Msg TX to 1:000000002A3ACA7D [B098] --- Type 0001:08 (IM:InvokeCommandRequest)
    I: 44930 [IN](S) Sending msg 255283922 on secure session with LSID: 44103
    I: 44941 [DIS]Found an existing secure session to [1:00000000F2DB3567]!
    D: 44948 [DIS]OperationalSessionSetup[1:00000000F2DB3567]: State change 1 --> 5
    E: Invoke OnOff Command Request ERROR: Error CHIP:0x0000000B
    I: 44963 [IN](S) Sending msg 99057 on secure session with LSID: 44102
    I: 44973 [IN](S) Sending msg 99060 on secure session with LSID: 44102
    I: Button has been pressed, keep in this state for at least 500 ms to change light sensitivity of binded lighting devices.
    I: 45006 [EM]>>> [E:51725i S:44103 M:108967127 (Ack:255283922)] (S) Msg RX from 1:000000002A3ACA7D [B098] --- Type 0001:09 (IM:InvokeCommandResponse)
    I: 45020 [DMG]Received Command Response Status for Endpoint=1 Cluster=0x0000_0006 Command=0x0000_0002 Status=0x0
    D: Binding command applied successfully!
    I: 45034 [EM]<<< [E:51725i S:44103 M:255283923 (Ack:108967127)] (S) Msg TX to 1:000000002A3ACA7D [B098] --- Type 0000:10 (SecureChannel:StandaloneAck)
    I: 45048 [IN](S) Sending msg 255283923 on secure session with LSID: 44103
    I: Notify Bounded Cluster | endpoint: 1 cluster: 6
    I: 45083 [DIS]Found an existing secure session to [1:000000002A3ACA7D]!
    D: 45089 [DIS]OperationalSessionSetup[1:000000002A3ACA7D]: State change 1 --> 5
    I: 45097 [EM]<<< [E:51727i S:44103 M:255283924] (S) Msg TX to 1:000000002A3ACA7D [B098] --- Type 0001:08 (IM:InvokeCommandRequest)
    I: 45109 [IN](S) Sending msg 255283924 on secure session with LSID: 44103
    I: 45117 [DIS]Found an existing secure session to [1:00000000F2DB3567]!
    D: 45123 [DIS]OperationalSessionSetup[1:00000000F2DB3567]: State change 1 --> 5
    E: Invoke OnOff Command Request ERROR: Error CHIP:0x0000000B
    I: 45138 [IN](S) Sending msg 255283917 on secure session with LSID: 44103
    I: 45146 [IN](S) Sending msg 99061 on secure session with LSID: 44102
    I: 45166 [EM]>>> [E:51727i S:44103 M:108967128 (Ack:255283924)] (S) Msg RX from 1:000000002A3ACA7D [B098] --- Type 0001:09 (IM:InvokeCommandResponse)
    I: Button has been pressed, keep in this state for at least 500 ms to change light sensitivity of binded lighting devices.
    I: 45192 [DMG]Received Command Response Status for Endpoint=1 Cluster=0x0000_0006 Command=0x0000_0002 Status=0x0
    D: Binding command applied successfully!
    I: 45208 [EM]<<< [E:51727i S:44103 M:255283925 (Ack:108967128)] (S) Msg TX to 1:000000002A3ACA7D [B098] --- Type 0000:10 (SecureChannel:StandaloneAck)
    I: 45222 [IN](S) Sending msg 255283925 on secure session with LSID: 44103
    I: 45232 [EM]>>> [E:51719i S:44103 M:108967129 (Ack:255283917)] (S) Msg RX from 1:000000002A3ACA7D [B098] --- Type 0001:09 (IM:InvokeCommandResponse)
    I: 45247 [DMG]Received Command Response Status for Endpoint=1 Cluster=0x0000_0006 Command=0x0000_0002 Status=0x0
    D: Binding command applied successfully!
    I: 45261 [EM]<<< [E:51719i S:44103 M:255283926 (Ack:108967129)] (S) Msg TX to 1:000000002A3ACA7D [B098] --- Type 0000:10 (SecureChannel:StandaloneAck)
    I: 45276 [IN](S) Sending msg 255283926 on secure session with LSID: 44103
    I: Notify Bounded Cluster | endpoint: 1 cluster: 6
    I: 45291 [DIS]Found an existing secure session to [1:000000002A3ACA7D]!
    D: 45297 [DIS]OperationalSessionSetup[1:000000002A3ACA7D]: State change 1 --> 5
    I: 45305 [EM]<<< [E:51729i S:44103 M:255283927] (S) Msg TX to 1:000000002A3ACA7D [B098] --- Type 0001:08 (IM:InvokeCommandRequest)
    I: 45317 [IN](S) Sending msg 255283927 on secure session with LSID: 44103
    I: 45325 [DIS]Found an existing secure session to [1:00000000F2DB3567]!
    D: 45332 [DIS]OperationalSessionSetup[1:00000000F2DB3567]: State change 1 --> 5
    I: 45341 [EM]<<< [E:51730i S:44102 M:99063] (S) Msg TX to 1:00000000F2DB3567 [B098] --- Type 0001:08 (IM:InvokeCommandRequest)
    I: 45352 [IN](S) Sending msg 99063 on secure session with LSID: 44102
    I: 45360 [IN](S) Sending msg 99058 on secure session with LSID: 44102
    I: 45371 [IN](S) Sending msg 99062 on secure session with LSID: 44102
    I: 45386 [EM]>>> [E:51729i S:44103 M:108967130 (Ack:255283927)] (S) Msg RX from 1:000000002A3ACA7D [B098] --- Type 0001:09 (IM:InvokeCommandResponse)
    I: 45400 [DMG]Received Command Response Status for Endpoint=1 Cluster=0x0000_0006 Command=0x0000_0002 Status=0x0
    D: Binding command applied successfully!
    I: 45414 [EM]<<< [E:51729i S:44103 M:255283928 (Ack:108967130)] (S) Msg TX to 1:000000002A3ACA7D [B098] --- Type 0000:10 (SecureChannel:StandaloneAck)
    I: 45427 [IN](S) Sending msg 255283928 on secure session with LSID: 44103
    I: Button has been pressed, keep in this state for at least 500 ms to change light sensitivity of binded lighting devices.
    I: Notify Bounded Cluster | endpoint: 1 cluster: 6
    I: 45500 [DIS]Found an existing secure session to [1:000000002A3ACA7D]!
    D: 45507 [DIS]OperationalSessionSetup[1:000000002A3ACA7D]: State change 1 --> 5
    I: 45515 [EM]<<< [E:51731i S:44103 M:255283929] (S) Msg TX to 1:000000002A3ACA7D [B098] --- Type 0001:08 (IM:InvokeCommandRequest)
    I: 45526 [IN](S) Sending msg 255283929 on secure session with LSID: 44103
    I: 45534 [DIS]Found an existing secure session to [1:00000000F2DB3567]!
    D: 45541 [DIS]OperationalSessionSetup[1:00000000F2DB3567]: State change 1 --> 5
    E: Invoke OnOff Command Request ERROR: Error CHIP:0x0000000B
    I: 45555 [IN](S) Sending msg 99059 on secure session with LSID: 44102
    I: 45581 [EM]>>> [E:51731i S:44103 M:108967131 (Ack:255283929)] (S) Msg RX from 1:000000002A3ACA7D [B098] --- Type 0001:09 (IM:InvokeCommandResponse)
    I: 45595 [DMG]Received Command Response Status for Endpoint=1 Cluster=0x0000_0006 Command=0x0000_0002 Status=0x0
    D: Binding command applied successfully!
    I: Button has been pressed, keep in this state for at least 500 ms to change light sensitivity of binded lighting devices.
    I: 45622 [EM]<<< [E:51731i S:44103 M:255283930 (Ack:108967131)] (S) Msg TX to 1:000000002A3ACA7D [B098] --- Type 0000:10 (SecureChannel:StandaloneAck)
    I: 45636 [IN](S) Sending msg 255283930 on secure session with LSID: 44103
    I: 45648 [IN](S) Sending msg 99060 on secure session with LSID: 44102
    I: Notify Bounded Cluster | endpoint: 1 cluster: 6
    I: 45721 [DIS]Found an existing secure session to [1:000000002A3ACA7D]!
    D: 45728 [DIS]OperationalSessionSetup[1:000000002A3ACA7D]: State change 1 --> 5
    I: 45736 [EM]<<< [E:51733i S:44103 M:255283931] (S) Msg TX to 1:000000002A3ACA7D [B098] --- Type 0001:08 (IM:InvokeCommandRequest)
    I: 45747 [IN](S) Sending msg 255283931 on secure session with LSID: 44103
    I: 45755 [DIS]Found an existing secure session to [1:00000000F2DB3567]!
    D: 45762 [DIS]OperationalSessionSetup[1:00000000F2DB3567]: State change 1 --> 5
    E: Invoke OnOff Command Request ERROR: Error CHIP:0x0000000B
    I: Button has been pressed, keep in this state for at least 500 ms to change light sensitivity of binded lighting devices.
    I: 45821 [IN](S) Sending msg 99061 on secure session with LSID: 44102
    I: 45862 [EM]>>> [E:51733i S:44103 M:108967132 (Ack:255283931)] (S) Msg RX from 1:000000002A3ACA7D [B098] --- Type 0001:09 (IM:InvokeCommandResponse)
    I: 45876 [DMG]Received Command Response Status for Endpoint=1 Cluster=0x0000_0006 Command=0x0000_0002 Status=0x0
    D: Binding command applied successfully!
    I: 45891 [EM]<<< [E:51733i S:44103 M:255283932 (Ack:108967132)] (S) Msg TX to 1:000000002A3ACA7D [B098] --- Type 0000:10 (SecureChannel:StandaloneAck)
    I: 45905 [IN](S) Sending msg 255283932 on secure session with LSID: 44103
    I: Notify Bounded Cluster | endpoint: 1 cluster: 6
    I: 45918 [DIS]Found an existing secure session to [1:000000002A3ACA7D]!
    D: 45925 [DIS]OperationalSessionSetup[1:000000002A3ACA7D]: State change 1 --> 5
    I: 45935 [EM]<<< [E:51735i S:44103 M:255283933] (S) Msg TX to 1:000000002A3ACA7D [B098] --- Type 0001:08 (IM:InvokeCommandRequest)
    I: 45947 [IN](S) Sending msg 255283933 on secure session with LSID: 44103
    I: 45955 [DIS]Found an existing secure session to [1:00000000F2DB3567]!
    D: 45961 [DIS]OperationalSessionSetup[1:00000000F2DB3567]: State change 1 --> 5
    E: Invoke OnOff Command Request ERROR: Error CHIP:0x0000000B
    I: 45975 [IN](S) Sending msg 99057 on secure session with LSID: 44102
    I: 45996 [EM]>>> [E:51735i S:44103 M:108967133 (Ack:255283933)] (S) Msg RX from 1:000000002A3ACA7D [B098] --- Type 0001:09 (IM:InvokeCommandResponse)
    I: 46010 [DMG]Received Command Response Status for Endpoint=1 Cluster=0x0000_0006 Command=0x0000_0002 Status=0x0
    D: Binding command applied successfully!
    I: Button has been pressed, keep in this state for at least 500 ms to change light sensitivity of binded lighting devices.
    I: 46036 [EM]<<< [E:51735i S:44103 M:255283934 (Ack:108967133)] (S) Msg TX to 1:000000002A3ACA7D [B098] --- Type 0000:10 (SecureChannel:StandaloneAck)
    I: 46049 [IN](S) Sending msg 255283934 on secure session with LSID: 44103
    I: 46057 [IN](S) Sending msg 99063 on secure session with LSID: 44102
    I: 46075 [IN](S) Sending msg 99062 on secure session with LSID: 44102
    I: Notify Bounded Cluster | endpoint: 1 cluster: 6
    I: 46119 [DIS]Found an existing secure session to [1:000000002A3ACA7D]!
    D: 46125 [DIS]OperationalSessionSetup[1:000000002A3ACA7D]: State change 1 --> 5
    I: 46133 [EM]<<< [E:51737i S:44103 M:255283935] (S) Msg TX to 1:000000002A3ACA7D [B098] --- Type 0001:08 (IM:InvokeCommandRequest)
    I: 46144 [IN](S) Sending msg 255283935 on secure session with LSID: 44103
    I: 46152 [DIS]Found an existing secure session to [1:00000000F2DB3567]!
    D: 46159 [DIS]OperationalSessionSetup[1:00000000F2DB3567]: State change 1 --> 5
    E: Invoke OnOff Command Request ERROR: Error CHIP:0x0000000B
    I: 46197 [EM]>>> [E:51737i S:44103 M:108967134 (Ack:255283935)] (S) Msg RX from 1:000000002A3ACA7D [B098] --- Type 0001:09 (IM:InvokeCommandResponse)
    I: 46211 [DMG]Received Command Response Status for Endpoint=1 Cluster=0x0000_0006 Command=0x0000_0002 Status=0x0
    I: Button has been pressed, keep in this state for at least 500 ms to change light sensitivity of binded lighting devices.
    D: Binding command applied successfully!
    I: 46236 [EM]<<< [E:51737i S:44103 M:255283936 (Ack:108967134)] (S) Msg TX to 1:000000002A3ACA7D [B098] --- Type 0000:10 (SecureChannel:StandaloneAck)
    I: 46250 [IN](S) Sending msg 255283936 on secure session with LSID: 44103
    I: 46263 [IN](S) Sending msg 99058 on secure session with LSID: 44102
    I: Notify Bounded Cluster | endpoint: 1 cluster: 6
    I: 46296 [DIS]Found an existing secure session to [1:000000002A3ACA7D]!
    D: 46303 [DIS]OperationalSessionSetup[1:000000002A3ACA7D]: State change 1 --> 5
    I: 46311 [EM]<<< [E:51739i S:44103 M:255283937] (S) Msg TX to 1:000000002A3ACA7D [B098] --- Type 0001:08 (IM:InvokeCommandRequest)
    I: 46322 [IN](S) Sending msg 255283937 on secure session with LSID: 44103
    I: 46330 [DIS]Found an existing secure session to [1:00000000F2DB3567]!
    D: 46337 [DIS]OperationalSessionSetup[1:00000000F2DB3567]: State change 1 --> 5
    E: Invoke OnOff Command Request ERROR: Error CHIP:0x0000000B
    I: 46379 [EM]>>> [E:51739i S:44103 M:108967135 (Ack:255283937)] (S) Msg RX from 1:000000002A3ACA7D [B098] --- Type 0001:09 (IM:InvokeCommandResponse)
    I: 46393 [DMG]Received Command Response Status for Endpoint=1 Cluster=0x0000_0006 Command=0x0000_0002 Status=0x0
    D: Binding command applied successfully!
    I: 46410 [EM]<<< [E:51739i S:44103 M:255283938 (Ack:108967135)] (S) Msg TX to 1:000000002A3ACA7D [B098] --- Type 0000:10 (SecureChannel:StandaloneAck)
    I: 46423 [IN](S) Sending msg 255283938 on secure session with LSID: 44103
    I: Button has been pressed, keep in this state for at least 500 ms to change light sensitivity of binded lighting devices.
    I: 46473 [IN](S) Sending msg 99059 on secure session with LSID: 44102
    I: Notify Bounded Cluster | endpoint: 1 cluster: 6
    I: 46487 [DIS]Found an existing secure session to [1:000000002A3ACA7D]!
    D: 46494 [DIS]OperationalSessionSetup[1:000000002A3ACA7D]: State change 1 --> 5
    I: 46504 [EM]<<< [E:51741i S:44103 M:255283939] (S) Msg TX to 1:000000002A3ACA7D [B098] --- Type 0001:08 (IM:InvokeCommandRequest)
    I: 46516 [IN](S) Sending msg 255283939 on secure session with LSID: 44103
    I: 46524 [DIS]Found an existing secure session to [1:00000000F2DB3567]!
    D: 46531 [DIS]OperationalSessionSetup[1:00000000F2DB3567]: State change 1 --> 5
    E: Invoke OnOff Command Request ERROR: Error CHIP:0x0000000B
    I: 46576 [IN](S) Sending msg 99060 on secure session with LSID: 44102
    I: 46591 [EM]>>> [E:51741i S:44103 M:108967136 (Ack:255283939)] (S) Msg RX from 1:000000002A3ACA7D [B098] --- Type 0001:09 (IM:InvokeCommandResponse)
    I: 46605 [DMG]Received Command Response Status for Endpoint=1 Cluster=0x0000_0006 Command=0x0000_0002 Status=0x0
    D: Binding command applied successfully!
    I: Button has been pressed, keep in this state for at least 500 ms to change light sensitivity of binded lighting devices.
    I: 46636 [EM]<<< [E:51741i S:44103 M:255283940 (Ack:108967136)] (S) Msg TX to 1:000000002A3ACA7D [B098] --- Type 0000:10 (SecureChannel:StandaloneAck)
    I: 46650 [IN](S) Sending msg 255283940 on secure session with LSID: 44103
    I: 46664 [IN](S) Sending msg 99061 on secure session with LSID: 44102
    I: Notify Bounded Cluster | endpoint: 1 cluster: 6
    I: 46696 [DIS]Found an existing secure session to [1:000000002A3ACA7D]!
    D: 46703 [DIS]OperationalSessionSetup[1:000000002A3ACA7D]: State change 1 --> 5
    I: 46713 [EM]<<< [E:51743i S:44103 M:255283941] (S) Msg TX to 1:000000002A3ACA7D [B098] --- Type 0001:08 (IM:InvokeCommandRequest)
    I: 46724 [IN](S) Sending msg 255283941 on secure session with LSID: 44103
    I: 46732 [DIS]Found an existing secure session to [1:00000000F2DB3567]!
    D: 46739 [DIS]OperationalSessionSetup[1:00000000F2DB3567]: State change 1 --> 5
    E: Invoke OnOff Command Request ERROR: Error CHIP:0x0000000B
    I: 46767 [IN](S) Sending msg 99063 on secure session with LSID: 44102
    I: Button has been pressed, keep in this state for at least 500 ms to change light sensitivity of binded lighting devices.
    I: Notify Bounded Cluster | endpoint: 1 cluster: 6
    I: 46875 [DIS]Found an existing secure session to [1:000000002A3ACA7D]!
    D: 46881 [DIS]OperationalSessionSetup[1:000000002A3ACA7D]: State change 1 --> 5
    E: Invoke OnOff Command Request ERROR: Error CHIP:0x0000000B
    I: 46894 [DIS]Found an existing secure session to [1:00000000F2DB3567]!
    D: 46900 [DIS]OperationalSessionSetup[1:00000000F2DB3567]: State change 1 --> 5
    E: Invoke OnOff Command Request ERROR: Error CHIP:0x0000000B
    I: 46935 [IN](S) Sending msg 99062 on secure session with LSID: 44102
    I: Button has been pressed, keep in this state for at least 500 ms to change light sensitivity of binded lighting devices.
    I: Notify Bounded Cluster | endpoint: 1 cluster: 6
    I: 47065 [DIS]Found an existing secure session to [1:000000002A3ACA7D]!
    D: 47072 [DIS]OperationalSessionSetup[1:000000002A3ACA7D]: State change 1 --> 5
    E: Invoke OnOff Command Request ERROR: Error CHIP:0x0000000B
    I: 47085 [DIS]Found an existing secure session to [1:00000000F2DB3567]!
    D: 47091 [DIS]OperationalSessionSetup[1:00000000F2DB3567]: State change 1 --> 5
    E: Invoke OnOff Command Request ERROR: Error CHIP:0x0000000B
    I: Button has been pressed, keep in this state for at least 500 ms to change light sensitivity of binded lighting devices.
    I: 47260 [IN](S) Sending msg 99057 on secure session with LSID: 44102
    I: Notify Bounded Cluster | endpoint: 1 cluster: 6
    I: 47285 [DIS]Found an existing secure session to [1:000000002A3ACA7D]!
    D: 47291 [DIS]OperationalSessionSetup[1:000000002A3ACA7D]: State change 1 --> 5
    E: Invoke OnOff Command Request ERROR: Error CHIP:0x0000000B
    I: 47304 [DIS]Found an existing secure session to [1:00000000F2DB3567]!
    D: 47310 [DIS]OperationalSessionSetup[1:00000000F2DB3567]: State change 1 --> 5
    E: Invoke OnOff Command Request ERROR: Error CHIP:0x0000000B
    I: 47366 [IN](S) Sending msg 255283941 on secure session with LSID: 44103
    I: Button has been pressed, keep in this state for at least 500 ms to change light sensitivity of binded lighting devices.
    I: Notify Bounded Cluster | endpoint: 1 cluster: 6
    I: 47709 [DIS]Found an existing secure session to [1:000000002A3ACA7D]!
    D: 47715 [DIS]OperationalSessionSetup[1:000000002A3ACA7D]: State change 1 --> 5
    E: Invoke OnOff Command Request ERROR: Error CHIP:0x0000000B
    I: 47730 [DIS]Found an existing secure session to [1:00000000F2DB3567]!
    D: 47737 [DIS]OperationalSessionSetup[1:00000000F2DB3567]: State change 1 --> 5
    E: Invoke OnOff Command Request ERROR: Error CHIP:0x0000000B
    I: Button has been pressed, keep in this state for at least 500 ms to change light sensitivity of binded lighting devices.
    I: Notify Bounded Cluster | endpoint: 1 cluster: 6
    I: 47924 [DIS]Found an existing secure session to [1:000000002A3ACA7D]!
    D: 47931 [DIS]OperationalSessionSetup[1:000000002A3ACA7D]: State change 1 --> 5
    E: Invoke OnOff Command Request ERROR: Error CHIP:0x0000000B
    I: 47945 [DIS]Found an existing secure session to [1:00000000F2DB3567]!
    D: 47952 [DIS]OperationalSessionSetup[1:00000000F2DB3567]: State change 1 --> 5
    E: Invoke OnOff Command Request ERROR: Error CHIP:0x0000000B
    I: 48012 [IN](S) Sending msg 255283941 on secure session with LSID: 44103
    I: Button has been pressed, keep in this state for at least 500 ms to change light sensitivity of binded lighting devices.
    I: Notify Bounded Cluster | endpoint: 1 cluster: 6
    I: 48353 [DIS]Found an existing secure session to [1:000000002A3ACA7D]!
    D: 48359 [DIS]OperationalSessionSetup[1:000000002A3ACA7D]: State change 1 --> 5
    E: Invoke OnOff Command Request ERROR: Error CHIP:0x0000000B
    I: 48372 [DIS]Found an existing secure session to [1:00000000F2DB3567]!
    D: 48378 [DIS]OperationalSessionSetup[1:00000000F2DB3567]: State change 1 --> 5
    E: Invoke OnOff Command Request ERROR: Error CHIP:0x0000000B
    I: Button has been pressed, keep in this state for at least 500 ms to change light sensitivity of binded lighting devices.
    I: Notify Bounded Cluster | endpoint: 1 cluster: 6
    I: 48539 [DIS]Found an existing secure session to [1:000000002A3ACA7D]!
    D: 48546 [DIS]OperationalSessionSetup[1:000000002A3ACA7D]: State change 1 --> 5
    E: Invoke OnOff Command Request ERROR: Error CHIP:0x0000000B
    I: 48560 [DIS]Found an existing secure session to [1:00000000F2DB3567]!
    D: 48567 [DIS]OperationalSessionSetup[1:00000000F2DB3567]: State change 1 --> 5
    E: Invoke OnOff Command Request ERROR: Error CHIP:0x0000000B
    I: Button has been pressed, keep in this state for at least 500 ms to change light sensitivity of binded lighting devices.
    I: Notify Bounded Cluster | endpoint: 1 cluster: 6
    I: 48775 [DIS]Found an existing secure session to [1:000000002A3ACA7D]!
    D: 48781 [DIS]OperationalSessionSetup[1:000000002A3ACA7D]: State change 1 --> 5
    E: Invoke OnOff Command Request ERROR: Error CHIP:0x0000000B
    I: 48794 [DIS]Found an existing secure session to [1:00000000F2DB3567]!
    D: 48800 [DIS]OperationalSessionSetup[1:00000000F2DB3567]: State change 1 --> 5
    E: Invoke OnOff Command Request ERROR: Error CHIP:0x0000000B
    I: Button has been pressed, keep in this state for at least 500 ms to change light sensitivity of binded lighting devices.
    I: 48924 [IN](S) Sending msg 255283941 on secure session with LSID: 44103
    I: Notify Bounded Cluster | endpoint: 1 cluster: 6
    I: 49006 [DIS]Found an existing secure session to [1:000000002A3ACA7D]!
    D: 49012 [DIS]OperationalSessionSetup[1:000000002A3ACA7D]: State change 1 --> 5
    E: Invoke OnOff Command Request ERROR: Error CHIP:0x0000000B
    I: 49025 [DIS]Found an existing secure session to [1:00000000F2DB3567]!
    D: 49032 [DIS]OperationalSessionSetup[1:00000000F2DB3567]: State change 1 --> 5
    E: Invoke OnOff Command Request ERROR: Error CHIP:0x0000000B
    I: Button has been pressed, keep in this state for at least 500 ms to change light sensitivity of binded lighting devices.
    I: Notify Bounded Cluster | endpoint: 1 cluster: 6
    I: 49244 [DIS]Found an existing secure session to [1:000000002A3ACA7D]!
    D: 49250 [DIS]OperationalSessionSetup[1:000000002A3ACA7D]: State change 1 --> 5
    E: Invoke OnOff Command Request ERROR: Error CHIP:0x0000000B
    I: 49263 [DIS]Found an existing secure session to [1:00000000F2DB3567]!
    D: 49269 [DIS]OperationalSessionSetup[1:00000000F2DB3567]: State change 1 --> 5
    E: Invoke OnOff Command Request ERROR: Error CHIP:0x0000000B
    I: Button has been pressed, keep in this state for at least 500 ms to change light sensitivity of binded lighting devices.
    I: Notify Bounded Cluster | endpoint: 1 cluster: 6
    I: 49432 [DIS]Found an existing secure session to [1:000000002A3ACA7D]!
    D: 49438 [DIS]OperationalSessionSetup[1:000000002A3ACA7D]: State change 1 --> 5
    E: Invoke OnOff Command Request ERROR: Error CHIP:0x0000000B
    I: 49451 [DIS]Found an existing secure session to [1:00000000F2DB3567]!
    D: 49458 [DIS]OperationalSessionSetup[1:00000000F2DB3567]: State change 1 --> 5
    E: Invoke OnOff Command Request ERROR: Error CHIP:0x0000000B
    I: Button has been pressed, keep in this state for at least 500 ms to change light sensitivity of binded lighting devices.
    I: Notify Bounded Cluster | endpoint: 1 cluster: 6
    I: 49658 [DIS]Found an existing secure session to [1:000000002A3ACA7D]!
    D: 49664 [DIS]OperationalSessionSetup[1:000000002A3ACA7D]: State change 1 --> 5
    E: Invoke OnOff Command Request ERROR: Error CHIP:0x0000000B
    I: 49682 [DIS]Found an existing secure session to [1:00000000F2DB3567]!
    D: 49689 [DIS]OperationalSessionSetup[1:00000000F2DB3567]: State change 1 --> 5
    E: Invoke OnOff Command Request ERROR: Error CHIP:0x0000000B
    I: Button has been pressed, keep in this state for at least 500 ms to change light sensitivity of binded lighting devices.
    I: Notify Bounded Cluster | endpoint: 1 cluster: 6
    I: 49868 [DIS]Found an existing secure session to [1:000000002A3ACA7D]!
    D: 49876 [DIS]OperationalSessionSetup[1:000000002A3ACA7D]: State change 1 --> 5
    E: Invoke OnOff Command Request ERROR: Error CHIP:0x0000000B
    I: 49889 [DIS]Found an existing secure session to [1:00000000F2DB3567]!
    D: 49896 [DIS]OperationalSessionSetup[1:00000000F2DB3567]: State change 1 --> 5
    E: Invoke OnOff Command Request ERROR: Error CHIP:0x0000000B
    I: Button has been pressed, keep in this state for at least 500 ms to change light sensitivity of binded lighting devices.
    I: Notify Bounded Cluster | endpoint: 1 cluster: 6
    I: 50069 [DIS]Found an existing secure session to [1:000000002A3ACA7D]!
    D: 50075 [DIS]OperationalSessionSetup[1:000000002A3ACA7D]: State change 1 --> 5
    E: Invoke OnOff Command Request ERROR: Error CHIP:0x0000000B
    I: 50088 [DIS]Found an existing secure session to [1:00000000F2DB3567]!
    D: 50094 [DIS]OperationalSessionSetup[1:00000000F2DB3567]: State change 1 --> 5
    E: Invoke OnOff Command Request ERROR: Error CHIP:0x0000000B
    I: 50218 [IN](S) Sending msg 255283941 on secure session with LSID: 44103
    I: Button has been pressed, keep in this state for at least 500 ms to change light sensitivity of binded lighting devices.
    I: Notify Bounded Cluster | endpoint: 1 cluster: 6
    I: 50704 [DIS]Found an existing secure session to [1:000000002A3ACA7D]!
    D: 50712 [DIS]OperationalSessionSetup[1:000000002A3ACA7D]: State change 1 --> 5
    E: Invoke OnOff Command Request ERROR: Error CHIP:0x0000000B
    I: 50728 [DIS]Found an existing secure session to [1:00000000F2DB3567]!
    D: 50735 [DIS]OperationalSessionSetup[1:00000000F2DB3567]: State change 1 --> 5
    E: Invoke OnOff Command Request ERROR: Error CHIP:0x0000000B
    I: Button has been pressed, keep in this state for at least 500 ms to change light sensitivity of binded lighting devices.
    I: Notify Bounded Cluster | endpoint: 1 cluster: 6
    I: 50937 [DIS]Found an existing secure session to [1:000000002A3ACA7D]!
    D: 50943 [DIS]OperationalSessionSetup[1:000000002A3ACA7D]: State change 1 --> 5
    E: Invoke OnOff Command Request ERROR: Error CHIP:0x0000000B
    I: 50956 [DIS]Found an existing secure session to [1:00000000F2DB3567]!
    D: 50962 [DIS]OperationalSessionSetup[1:00000000F2DB3567]: State change 1 --> 5
    E: Invoke OnOff Command Request ERROR: Error CHIP:0x0000000B
    I: Button has been pressed, keep in this state for at least 500 ms to change light sensitivity of binded lighting devices.
    I: Notify Bounded Cluster | endpoint: 1 cluster: 6
    I: 51124 [DIS]Found an existing secure session to [1:000000002A3ACA7D]!
    D: 51131 [DIS]OperationalSessionSetup[1:000000002A3ACA7D]: State change 1 --> 5
    E: Invoke OnOff Command Request ERROR: Error CHIP:0x0000000B
    I: 51144 [DIS]Found an existing secure session to [1:00000000F2DB3567]!
    D: 51150 [DIS]OperationalSessionSetup[1:00000000F2DB3567]: State change 1 --> 5
    E: Invoke OnOff Command Request ERROR: Error CHIP:0x0000000B
    E: 52148 [EM]Failed to Send CHIP MessageCounter:255283941 on exchange 51743i sendCount: 4 max retries: 4
    D: 54436 [IN]SecureSession[0x20004488]: MarkAsDefunct Type:2 LSID:44103
    I: 54442 [SC]SecureSession[0x20004488]: Moving from state 'kActive' --> 'kDefunct'
    I: 54449 [DMG]Time out! failed to receive invoke command response from Exchange: 51743i
    I: Response timeout for invoked command, trying to recover CASE session.
    D: 54463 [DIS]OperationalSessionSetup[1:000000002A3ACA7D]: State change 1 --> 2
    I: 54472 [DIS]Found an existing secure session to [1:00000000F2DB3567]!
    D: 54479 [DIS]OperationalSessionSetup[1:00000000F2DB3567]: State change 1 --> 5
    E: Invoke OnOff Command Request ERROR: Error CHIP:0x0000000B
    I: 54670 [DIS]Checking node lookup status after 200 ms
    I: 55614 [DIS]UDP:[fe80::????:????:????:????:????a3c8%wlan0]:5540: new best score: 3
    D: 55621 [DIS]Lookup clearing interface for non LL address
    I: 55627 [DIS]UDP:[????:????:????:????:????:99ff:fe71:a3c8%wlan0]:5540: new best score: 7
    I: 55634 [DIS]Checking node lookup status after 1164 ms
    D: 55640 [DIS]OperationalSessionSetup[1:000000002A3ACA7D]: Updating device address to UDP:[????:????:????:????:????:99ff:fe71:a3c8]:5540 while in state 2
    D: 55653 [DIS]OperationalSessionSetup[1:000000002A3ACA7D]: State change 2 --> 3
    D: 55661 [IN]SecureSession[0x20004540]: Allocated Type:2 LSID:44104
    I: 55667 [SC]Initiating session on local FabricIndex 1 from 0x000000006BA9BAD9 -> 0x000000002A3ACA7D
    I: 55807 [EM]<<< [E:51780i S:0 M:173326030] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:30 (SecureChannel:CASE_Sigma1)
    I: 55820 [IN](U) Sending msg 173326030 to IP address 'UDP:[????:????:????:????:????:99ff:fe71:a3c8]:5540'
    I: 55831 [SC]Sent Sigma1 msg
    D: 55834 [DIS]OperationalSessionSetup[1:000000002A3ACA7D]: State change 3 --> 4
    I: 57039 [IN](S) Sending msg 99063 on secure session with LSID: 44102
    I: 61090 [IN](S) Sending msg 99061 on secure session with LSID: 44102
    I: 62054 [IN](S) Sending msg 99059 on secure session with LSID: 44102
    I: 62225 [IN](U) Sending msg 173326030 to IP address 'UDP:[????:????:????:????:????:99ff:fe71:a3c8]:5540'
    I: 62598 [IN](S) Sending msg 99060 on secure session with LSID: 44102
    I: 62605 [IN](S) Sending msg 99058 on secure session with LSID: 44102
    I: 62888 [IN](S) Sending msg 99062 on secure session with LSID: 44102
    I: Button has been pressed, keep in this state for at least 500 ms to change light sensitivity of binded lighting devices.
    I: Notify Bounded Cluster | endpoint: 1 cluster: 6
    I: 67808 [DIS]Found an existing secure session to [1:00000000F2DB3567]!
    D: 67814 [DIS]OperationalSessionSetup[1:00000000F2DB3567]: State change 1 --> 5
    E: Invoke OnOff Command Request ERROR: Error CHIP:0x0000000B
    I: 68146 [IN](U) Sending msg 173326030 to IP address 'UDP:[????:????:????:????:????:99ff:fe71:a3c8]:5540'
    E: 72780 [EM]Failed to Send CHIP MessageCounter:99057 on exchange 51712i sendCount: 4 max retries: 4
    I: 72924 [IN](S) Sending msg 99063 on secure session with LSID: 44102
    D: 77813 [IN]SecureSession[0x200043d0]: MarkAsDefunct Type:2 LSID:44102
    I: 77819 [SC]SecureSession[0x200043d0]: Moving from state 'kActive' --> 'kDefunct'
    I: 77827 [DMG]Time out! failed to receive invoke command response from Exchange: 51712i
    E: Binding command was not applied! Reason: 32
    I: 78167 [IN](U) Sending msg 173326030 to IP address 'UDP:[????:????:????:????:????:99ff:fe71:a3c8]:5540'
    I: Button has been pressed, keep in this state for at least 500 ms to change light sensitivity of binded lighting devices.
    I: Notify Bounded Cluster | endpoint: 1 cluster: 6
    D: 81912 [DIS]OperationalSessionSetup[1:00000000F2DB3567]: State change 1 --> 2
    I: 82119 [DIS]Checking node lookup status after 200 ms
    I: 83058 [DIS]UDP:[fe80::????:????:????:????:????c2fc%wlan0]:5540: new best score: 3
    D: 83065 [DIS]Lookup clearing interface for non LL address
    I: 83070 [DIS]UDP:[????:????:????:????:????:99ff:fe72:c2fc%wlan0]:5540: new best score: 7
    I: 83078 [DIS]Checking node lookup status after 1159 ms
    D: 83083 [DIS]OperationalSessionSetup[1:00000000F2DB3567]: Updating device address to UDP:[????:????:????:????:????:99ff:fe72:c2fc]:5540 while in state 2
    D: 83096 [DIS]OperationalSessionSetup[1:00000000F2DB3567]: State change 2 --> 3
    D: 83104 [IN]SecureSession[0x200045f8]: Allocated Type:2 LSID:44105
    I: 83110 [SC]Initiating session on local FabricIndex 1 from 0x000000006BA9BAD9 -> 0x00000000F2DB3567
    I: 83248 [EM]<<< [E:51782i S:0 M:173326031] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:30 (SecureChannel:CASE_Sigma1)
    I: 83261 [IN](U) Sending msg 173326031 to IP address 'UDP:[????:????:????:????:????:99ff:fe72:c2fc]:5540'
    I: 83272 [SC]Sent Sigma1 msg
    D: 83275 [DIS]OperationalSessionSetup[1:00000000F2DB3567]: State change 3 --> 4
    I: 83328 [EM]>>> [E:51782i S:0 M:110618088 (Ack:173326031)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
    I: 83346 [EM]>>> [E:51782i S:0 M:110618089 (Ack:173326031)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:33 (SecureChannel:CASE_Sigma2Resume)
    I: 83360 [EM]<<< [E:51782i S:0 M:173326032 (Ack:110618089)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
    I: 83374 [IN](U) Sending msg 173326032 to IP address 'UDP:[????:????:????:????:????:99ff:fe72:c2fc]:5540'
    I: 83510 [EM]<<< [E:51782i S:0 M:173326033 (Ack:110618089)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:40 (SecureChannel:StatusReport)
    I: 83523 [IN](U) Sending msg 173326033 to IP address 'UDP:[????:????:????:????:????:99ff:fe72:c2fc]:5540'
    I: 83535 [SC]SecureSession[0x200045f8]: Moving from state 'kEstablishing' --> 'kActive'
    D: 83543 [IN]SecureSession[0x200045f8]: Activated - Type:2 LSID:44105
    D: 83550 [IN]New secure session activated for device <00000000F2DB3567, 1>, LSID:44105 PSID:47565!
    D: 83559 [DIS]OperationalSessionSetup[1:00000000F2DB3567]: State change 4 --> 5
    E: Invoke OnOff Command Request ERROR: Error CHIP:0x0000000B
    I: 83672 [EM]>>> [E:51782i S:0 M:110618090 (Ack:173326033)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
    I: Button has been pressed, keep in this state for at least 500 ms to change light sensitivity of binded lighting devices.
    I: Notify Bounded Cluster | endpoint: 1 cluster: 6
    I: 85429 [DIS]Found an existing secure session to [1:00000000F2DB3567]!
    D: 85436 [DIS]OperationalSessionSetup[1:00000000F2DB3567]: State change 1 --> 5
    I: 85444 [EM]<<< [E:51784i S:44105 M:1227097] (S) Msg TX to 1:00000000F2DB3567 [B098] --- Type 0001:08 (IM:InvokeCommandRequest)
    I: 85455 [IN](S) Sending msg 1227097 on secure session with LSID: 44105
    I: 86171 [IN](S) Sending msg 1227097 on secure session with LSID: 44105
    I: 86335 [EM]>>> [E:51784i S:44105 M:119856713 (Ack:1227097)] (S) Msg RX from 1:00000000F2DB3567 [B098] --- Type 0001:09 (IM:InvokeCommandResponse)
    I: 86349 [DMG]Received Command Response Status for Endpoint=1 Cluster=0x0000_0006 Command=0x0000_0002 Status=0x0
    D: Binding command applied successfully!
    I: 86364 [EM]<<< [E:51784i S:44105 M:1227098 (Ack:119856713)] (S) Msg TX to 1:00000000F2DB3567 [B098] --- Type 0000:10 (SecureChannel:StandaloneAck)
    I: 86377 [IN](S) Sending msg 1227098 on secure session with LSID: 44105
    E: 86824 [EM]Failed to Send CHIP MessageCounter:99062 on exchange 51722i sendCount: 4 max retries: 4
    E: 86893 [EM]Failed to Send CHIP MessageCounter:99059 on exchange 51716i sendCount: 4 max retries: 4
    E: 87205 [EM]Failed to Send CHIP MessageCounter:99061 on exchange 51720i sendCount: 4 max retries: 4
    I: Button has been pressed, keep in this state for at least 500 ms to change light sensitivity of binded lighting devices.
    I: Notify Bounded Cluster | endpoint: 1 cluster: 6
    I: 87581 [DIS]Found an existing secure session to [1:00000000F2DB3567]!
    D: 87587 [DIS]OperationalSessionSetup[1:00000000F2DB3567]: State change 1 --> 5
    I: 87595 [EM]<<< [E:51785i S:44105 M:1227099] (S) Msg TX to 1:00000000F2DB3567 [B098] --- Type 0001:08 (IM:InvokeCommandRequest)
    I: 87607 [IN](S) Sending msg 1227099 on secure session with LSID: 44105
    I: 88275 [IN](S) Sending msg 1227099 on secure session with LSID: 44105
    I: 88981 [IN](S) Sending msg 1227099 on secure session with LSID: 44105
    I: Button has been pressed, keep in this state for at least 500 ms to change light sensitivity of binded lighting devices.
    I: Notify Bounded Cluster | endpoint: 1 cluster: 6
    I: 89575 [DIS]Found an existing secure session to [1:00000000F2DB3567]!
    D: 89581 [DIS]OperationalSessionSetup[1:00000000F2DB3567]: State change 1 --> 5
    E: Invoke OnOff Command Request ERROR: Error CHIP:0x0000000B
    I: 89926 [IN](S) Sending msg 1227099 on secure session with LSID: 44105
    E: 90231 [EM]Failed to Send CHIP MessageCounter:99060 on exchange 51718i sendCount: 4 max retries: 4
    E: 90744 [EM]Failed to Send CHIP MessageCounter:99058 on exchange 51714i sendCount: 4 max retries: 4
    I: Button has been pressed, keep in this state for at least 500 ms to change light sensitivity of binded lighting devices.
    I: 91161 [IN](S) Sending msg 1227099 on secure session with LSID: 44105
    I: Notify Bounded Cluster | endpoint: 1 cluster: 6
    I: 91202 [DIS]Found an existing secure session to [1:00000000F2DB3567]!
    D: 91209 [DIS]OperationalSessionSetup[1:00000000F2DB3567]: State change 1 --> 5
    E: Invoke OnOff Command Request ERROR: Error CHIP:0x0000000B
    I: 93144 [IN](U) Sending msg 173326030 to IP address 'UDP:[????:????:????:????:????:99ff:fe71:a3c8]:5540'
    D: 94579 [IN]SecureSession[0x200043d0]: MarkAsDefunct Type:2 LSID:44102
    I: 94585 [DMG]Time out! failed to receive invoke command response from Exchange: 51714i
    I: Response timeout for invoked command, trying to recover CASE session.
    I: 94600 [DIS]Found an existing secure session to [1:00000000F2DB3567]!
    D: 94606 [DIS]OperationalSessionSetup[1:00000000F2DB3567]: State change 1 --> 5
    E: Invoke OnOff Command Request ERROR: Error CHIP:0x0000000B
    D: 94781 [IN]SecureSession[0x200043d0]: MarkAsDefunct Type:2 LSID:44102
    I: 94787 [DMG]Time out! failed to receive invoke command response from Exchange: 51716i
    E: Binding command was not applied! Reason: 32
    D: 94976 [IN]SecureSession[0x200043d0]: MarkAsDefunct Type:2 LSID:44102
    I: 94983 [DMG]Time out! failed to receive invoke command response from Exchange: 51718i
    E: Binding command was not applied! Reason: 32
    D: 95173 [IN]SecureSession[0x200043d0]: MarkAsDefunct Type:2 LSID:44102
    I: 95179 [DMG]Time out! failed to receive invoke command response from Exchange: 51720i
    E: Binding command was not applied! Reason: 32
    D: 95315 [IN]SecureSession[0x200043d0]: MarkAsDefunct Type:2 LSID:44102
    I: 95321 [DMG]Time out! failed to receive invoke command response from Exchange: 51722i
    E: Binding command was not applied! Reason: 32
    E: 99281 [EM]Failed to Send CHIP MessageCounter:99063 on exchange 51730i sendCount: 4 max retries: 4
    D: 106397 [IN]SecureSession[0x200043d0]: MarkAsDefunct Type:2 LSID:44102
    I: 106404 [DMG]Time out! failed to receive invoke command response from Exchange: 51730i
    E: Binding command was not applied! Reason: 32
    E: 117672 [EM]Failed to Send CHIP MessageCounter:1227099 on exchange 51785i sendCount: 4 max retries: 4
    E: 119061 [EM]Failed to Send CHIP MessageCounter:173326030 on exchange 51780i sendCount: 4 max retries: 4
    D: 121778 [IN]SecureSession[0x200045f8]: MarkAsDefunct Type:2 LSID:44105
    I: 121785 [SC]SecureSession[0x200045f8]: Moving from state 'kActive' --> 'kDefunct'

  • Hi,

    Thank you for the logs.

    The developers are investigating this issue. I will update this ticket with their findings.

    Best regards,

    Maria

  • Hello,

    Thank you for checking in. Our developers has not been able to reproduce this behaviour with this method:

    1. Connect Light Bulb (any board)

    2. Connect Light Switch (nRF7002DK)

    3. Bind both devices together

    4. click the light switch button to change the LED state on the Light Bulb multiple times rapidly (a few times per second)

    If you have another method for reproducing this, please share it.

    Also, can you describe your use-case where you need to send rapid commands to the same node?

    Edit: Increasing these defines could be of some help:

    #define CHIP_SYSTEM_CONFIG_PACKETBUFFER_POOL_SIZE

    #define CHIP_CONFIG_MAX_EXCHANGE_CONTEXTS

    Best regards,

    Maria

Reply Children
No Data
Related