TE#6 Mac Chip tool testing: TC-MF-1.23 - Mac Chip tool giving 0x01 error response instead of 0x02

[Garik098]

Testcase: TC-MF-1.23 step 5

When Mac chip tool opens a commissioning window using BCM giving max+1 timeout (901 seconds), it is expected to get 0x02 response code while we are seeing 0x01 (Busy) response code.

"ubuntu@matter-te-6:~$ chip-tool administratorcommissioning open-basic-commissioning-window 901 0 [1634245410.473728][4230:4230] CHIP:CTL: Read local id 0x000000000001B669, remote id 0x58EF6937C7559F28 [1634245410.476264][4230:4230] CHIP:CTL: Generating NOC [1634245410.476596][4230:4230] CHIP:CTL: Generating ICAC [1634245410.482200][4230:4230] CHIP:IN: UDP::Init bind&listen port=5541 [1634245410.482340][4230:4230] CHIP:IN: UDP::Init bound to port=5541 [1634245410.482369][4230:4230] CHIP:IN: UDP::Init bind&listen port=5541 [1634245410.482462][4230:4230] CHIP:IN: UDP::Init bound to port=5541 [1634245410.482488][4230:4230] CHIP:IN: TransportMgr initialized [1634245410.482510][4230:4230] CHIP:DIS: Init fabric pairing table with server storage [1634245410.490837][4230:4230] CHIP:DL: MDNS failed to join multicast group on veth1ab88fa for address type IPv4: ../../third_party/connectedhomeip/src/inet/IPEndPointBasis.cpp:259: Inet Error 0x00000110: Address not found [1634245410.492621][4230:4230] CHIP:DL: MDNS failed to join multicast group on vethc72637a for address type IPv4: ../../third_party/connectedhomeip/src/inet/IPEndPointBasis.cpp:259: Inet Error 0x00000110: Address not found [1634245410.494344][4230:4230] CHIP:DL: MDNS failed to join multicast group on veth280f827 for address type IPv4: ../../third_party/connectedhomeip/src/inet/IPEndPointBasis.cpp:259: Inet Error 0x00000110: Address not found [1634245410.496013][4230:4230] CHIP:DL: MDNS failed to join multicast group on veth09ab52b for address type IPv4: ../../third_party/connectedhomeip/src/inet/IPEndPointBasis.cpp:259: Inet Error 0x00000110: Address not found [1634245410.497775][4230:4230] CHIP:DL: MDNS failed to join multicast group on vethc0cbd1a for address type IPv4: ../../third_party/connectedhomeip/src/inet/IPEndPointBasis.cpp:259: Inet Error 0x00000110: Address not found [1634245410.497949][4230:4230] CHIP:ZCL: Using ZAP configuration... [1634245410.498028][4230:4230] CHIP:ZCL: deactivate report event [1634245410.498630][4230:4230] CHIP:DIS: Verifying the received credentials [1634245410.500551][4230:4230] CHIP:DIS: Added new fabric at index: 1, Initialized: 1 [1634245410.500589][4230:4230] CHIP:DIS: Assigned compressed fabric ID: 0xFF77B9A4FF1DBD83, node ID: 0x000000000001B669 [1634245410.500616][4230:4230] CHIP:CTL: Joined the fabric at index 1. Compressed fabric ID is: 0xFF77B9A4FF1DBD83 [1634245410.501015][4230:4235] CHIP:DL: CHIP task running [1634245410.501905][4230:4235] CHIP:IN: Build plaintext message 0xaaaad1f05f58 to 0x0000000000000000 of type 48 and protocolId 0 on exchange 42359r with MessageCounter 4244046383. [1634245410.501964][4230:4235] CHIP:IN: Sending plaintext msg 0xaaaad1f05f58 to 0x0000000000000000 at utc time: 14474089 msec [1634245410.501992][4230:4235] CHIP:IN: Sending msg on generic transport [1634245410.502124][4230:4235] CHIP:SC: Sent SigmaR1 msg [1634245410.504772][4230:4235] CHIP:EM: Received message of type 0x31 with vendorId 0x0000 and protocolId 0x0000 on exchange 42359i [1634245410.504819][4230:4235] CHIP:EM: Rxd Ack; Removing MessageCounter:FCF7022F from Retrans Table [1634245410.504844][4230:4235] CHIP:EM: Removed CHIP MessageCounter:FCF7022F from RetransTable [1634245410.504899][4230:4235] CHIP:SC: Received SigmaR2 msg [1634245410.504931][4230:4235] CHIP:SC: Peer assigned session key ID 3 [1634245410.507948][4230:4235] CHIP:SC: Sending SigmaR3 [1634245410.508417][4230:4235] CHIP:EM: Piggybacking Ack for MessageCounter:2ECD92CC on exchange: 42359i [1634245410.508465][4230:4235] CHIP:IN: Build plaintext message 0xaaaad1f05f58 to 0x0000000000000000 of type 50 and protocolId 0 on exchange 42359r with MessageCounter 4244046384. [1634245410.508499][4230:4235] CHIP:IN: Sending plaintext msg 0xaaaad1f05f58 to 0x0000000000000000 at utc time: 14474095 msec [1634245410.508556][4230:4235] CHIP:IN: Sending msg on generic transport [1634245410.508652][4230:4235] CHIP:SC: Sent SigmaR3 msg [1634245410.508685][4230:4235] CHIP:IN: New secure session created for device 0x58EF6937C7559F28, key 3!! [1634245410.508747][4230:4235] CHIP:TOO: Sending cluster (0x003C) command (0x01) on endpoint 0 [1634245410.508781][4230:4235] CHIP:DMG: ICR moving to [Initialize] [1634245410.508816][4230:4235] CHIP:DMG: ICR moving to [AddCommand] [1634245410.508908][4230:4235] CHIP:IN: Secure message was encrypted: Msg ID 0 [1634245410.508936][4230:4235] CHIP:IN: Build encrypted message 0xaaaad1f05f70 to 0x58EF6937C7559F28 of type 8 and protocolId 1 on exchange 42360r with MessageCounter 0. [1634245410.508964][4230:4235] CHIP:IN: Sending encrypted msg 0xaaaad1f05f70 to 0x58EF6937C7559F28 at utc time: 14474096 msec [1634245410.508989][4230:4235] CHIP:IN: Sending msg on generic transport [1634245410.509052][4230:4235] CHIP:DMG: ICR moving to [ Sending] [1634245410.512103][4230:4235] CHIP:EM: Received message of type 0x10 with vendorId 0x0000 and protocolId 0x0000 on exchange 42359i [1634245410.512146][4230:4235] CHIP:EM: Rxd Ack; Removing MessageCounter:FCF70230 from Retrans Table [1634245410.512171][4230:4235] CHIP:EM: Removed CHIP MessageCounter:FCF70230 from RetransTable [1634245410.513191][4230:4235] CHIP:EM: Received message of type 0x09 with vendorId 0x0000 and protocolId 0x0001 on exchange 42360i [1634245410.513231][4230:4235] CHIP:EM: Rxd Ack; Removing MessageCounter:00000000 from Retrans Table [1634245410.513255][4230:4235] CHIP:EM: Removed CHIP MessageCounter:00000000 from RetransTable [1634245410.513294][4230:4235] CHIP:DMG: InvokeCommand = [1634245410.513321][4230:4235] CHIP:DMG: { [1634245410.513344][4230:4235] CHIP:DMG: CommandList = [1634245410.513370][4230:4235] CHIP:DMG: [ [1634245410.513395][4230:4235] CHIP:DMG: CommandDataElement = [1634245410.513442][4230:4235] CHIP:DMG: { [1634245410.513480][4230:4235] CHIP:DMG: CommandPath = [1634245410.513592][4230:4235] CHIP:DMG: { [1634245410.513639][4230:4235] CHIP:DMG: EndpointId = 0x0, [1634245410.513686][4230:4235] CHIP:DMG: ClusterId = 0x3c, [1634245410.513731][4230:4235] CHIP:DMG: CommandId = 0x1, [1634245410.513778][4230:4235] CHIP:DMG: }, [1634245410.513830][4230:4235] CHIP:DMG:
[1634245410.513869][4230:4235] CHIP:DMG: StatusElement = [1634245410.513914][4230:4235] CHIP:DMG: { [1634245410.513959][4230:4235] CHIP:DMG: GeneralCode = 0x1, [1634245410.514008][4230:4235] CHIP:DMG: ProtocolId = 0x1, [1634245410.514053][4230:4235] CHIP:DMG: protocolCode = 0x1, [1634245410.514096][4230:4235] CHIP:DMG: }, [1634245410.514144][4230:4235] CHIP:DMG:
[1634245410.514182][4230:4235] CHIP:DMG: }, [1634245410.514226][4230:4235] CHIP:DMG:
[1634245410.514259][4230:4235] CHIP:DMG: ], [1634245410.514299][4230:4235] CHIP:DMG:
[1634245410.514330][4230:4235] CHIP:DMG: } [1634245410.514387][4230:4235] CHIP:ZCL: DefaultResponse: [1634245410.514417][4230:4235] CHIP:ZCL: Transaction: 0xaaaab0e6ae38 [1634245410.514446][4230:4235] CHIP:ZCL: status: EMBER_ZCL_STATUS_FAILURE (0x01) [1634245410.514480][4230:4235] CHIP:TOO: Default Failure Response: 0x01 [1634245410.514536][4230:4235] CHIP:DMG: ICR moving to [Uninitiali] [1634245410.514570][4230:4235] CHIP:EM: Sending Standalone Ack for MessageCounter:00000001 [1634245410.514662][4230:4235] CHIP:IN: Secure message was encrypted: Msg ID 1 [1634245410.514699][4230:4235] CHIP:IN: Build encrypted message 0xffff8dda19c0 to 0x58EF6937C7559F28 of type 16 and protocolId 0 on exchange 42360r with MessageCounter 1. [1634245410.514738][4230:4235] CHIP:IN: Sending encrypted msg 0xffff8dda19c0 to 0x58EF6937C7559F28 at utc time: 14474101 msec [1634245410.514772][4230:4235] CHIP:IN: Sending msg on generic transport [1634245410.514869][4230:4235] CHIP:EM: Flushed pending ack for MessageCounter:00000001 [1634245410.515063][4230:4230] CHIP:TOO: Run command failure: ../../third_party/connectedhomeip/zzz_generated/chip-tool/zap-generated/cluster/Commands.h:43: CHIP Error 0x000000AC: Internal error [1634245410.515160][4230:4230] CHIP:CTL: Shutting down the commissioner [1634245410.515198][4230:4230] CHIP:CTL: Shutting down the controller [1634245410.518170][4230:4230] CHIP:DL: Inet Layer shutdown [1634245410.518296][4230:4230] CHIP:DL: BLE layer shutdown [1634245410.518330][4230:4230] CHIP:DL: System Layer shutdown"

[franck-apple]

This requires changes in the Interaction Model layer to support custom error code, which is currently expected to land in TE7.5, so moving this to TE7.5 as well.

[Garik098]

TE7 update: Observing the same issue on ECM as well as on BCM (TC-MF-1.23 and TC-MF-1.24)

[pan-apple]

Fixed by #11883