Chiptool reporting Failed to remove current fabric - Error Domain=CHIPErrorDomain Code=1 "Undefined error:50." even though it seem to succeed

[kean-apple]

Problem

Chiptool reports Failed to remove current fabric
removing-fabric-via-unpair-M5-logs.txt
removing-fabric-via-unpair-chiptool-logs.txt
when it does appear the M5 board is Reset and fabric removed

1. Build iOS chip tool app
2. Pair M5/ESP32 board
3. From chip tool app, select Unpair devices option. Verify that M5 board is reset and Fabric is removed

In step 3, the M5 board does get reset after using unpair option and it seems like the Fabric is removed however CHIPtool does report error:

2022-02-14 17:59:54.416688-0800 localhost CHIPTool[4199]: (CHIP) [com.zigbee.chip:all] � [1644890394416] [4199:133051] CHIP: [EM] Retransmitting MessageCounter:361632 on exchange 21572i Send Cnt 1
2022-02-14 17:59:54.416979-0800 localhost CHIPTool[4199]: (CHIP) [com.zigbee.chip:all] � [1644890394416] [4199:133051] CHIP: [IN] Sending encrypted msg 0x115821468 with MessageCounter:361632 to 0x0000000000000002 (1) at monotonic time: 1644890394416 msec
2022-02-14 17:59:54.716662-0800 localhost CHIPTool[4199]: (CHIP) [com.zigbee.chip:all] � [1644890394716] [4199:135257] CHIP: [EM] Retransmitting MessageCounter:361632 on exchange 21572i Send Cnt 2
2022-02-14 17:59:54.716846-0800 localhost CHIPTool[4199]: (CHIP) [com.zigbee.chip:all] � [1644890394716] [4199:135257] CHIP: [IN] Sending encrypted msg 0x115821468 with MessageCounter:361632 to 0x0000000000000002 (1) at monotonic time: 1644890394716 msec
2022-02-14 17:59:55.016448-0800 localhost CHIPTool[4199]: (CHIP) [com.zigbee.chip:all] � [1644890395016] [4199:135257] CHIP: [EM] Failed to Send CHIP MessageCounter:361632 on exchange 21572i sendCount: 3 max retries: 3
2022-02-14 18:00:01.115348-0800 localhost CHIPTool[4199]: (CHIP) [com.zigbee.chip:all] � [1644890401115] [4199:135257] CHIP: [DMG] Time out! failed to receive invoke command response from Exchange: 21572i
2022-02-14 18:00:01.115673-0800 localhost CHIPTool[4199]: (CoreFoundation) [com.apple.CFBundle:strings] Bundle: CFBundle 0x115204610 </private/var/containers/Bundle/Application/288E3255-8317-4E76-871E-95722091569F/CHIPTool.app> (executable, loaded), key: Undefined error:%u., value: , table: Localizable, localizationName: (null), result: Undefined error:%u.
2022-02-14 18:00:01.115858-0800 localhost CHIPTool[4199]: (CHIP) [com.zigbee.chip:all] � [1644890401115] [4199:135257] CHIP: [DMG] ICR moving to [AwaitingDe]
2022-02-14 18:00:01.115997-0800 localhost CHIPTool[4199]: (CHIP) [com.zigbee.chip:all] � [1644890401115] [4199:133047] CHIP: [CTL] Response Time: PFvPvRKN4chip3app8Clusters22OperationalCredentials8Commands11NOCResponse13DecodableTypeEE+2510527005 12.001841 seconds
2022-02-14 18:00:01.116291-0800 localhost CHIPTool[4199]: Failed to remove current fabric index 1 for device 2. Error Domain=CHIPErrorDomain Code=1 "Undefined error:50." UserInfo={NSLocalizedDescription=Undefined error:50., errorCode=50}

Note: I didn't see the same error when removing fabric via the Fabric management option

[kean-apple]

SHA used: d1c7e85

[bzbarsky-apple]

From the m5stack log:

0x40098916: abort at /Users/keanhinlim/tools/esp-idf/components/newlib/abort.c:46

0x400e34b5: chip::SessionHolder::Get() const at /Users/keanhinlim/connectedhomeip/src/lib/support/CodeUtils.h:477
 (inlined by) chip::Optional<chip::ReferenceCountedHandle<chip::Transport::Session> >::Value() const & at /Users/keanhinlim/connectedhomeip/src/lib/core/Optional.h:170
 (inlined by) chip::SessionHolder::Get() const at /Users/keanhinlim/connectedhomeip/src/transport/SessionHolder.h:54

0x4010435d: chip::Messaging::ExchangeContext::GetSessionHandle() const at /Users/keanhinlim/connectedhomeip/examples/all-clusters-app/esp32/build/esp-idf/chip/../../../../../../config/esp32/third_party/connectedhomeip/src/messaging/ExchangeContext.h:163 (discriminator 3)
 (inlined by) chip::app::ReadHandler::SendReportData(chip::System::PacketBufferHandle&&, bool) at /Users/keanhinlim/connectedhomeip/examples/all-clusters-app/esp32/build/esp-idf/chip/../../../../../../config/esp32/third_party/connectedhomeip/src/app/ReadHandler.cpp:205 (discriminator 3)

0x400e0853: chip::app::reporting::Engine::SendReport(chip::app::ReadHandler*, chip::System::PacketBufferHandle&&, bool) at /Users/keanhinlim/connectedhomeip/examples/all-clusters-app/esp32/build/../third_party/connectedhomeip/src/app/reporting/Engine.cpp:663

0x400e0d69: chip::app::reporting::Engine::BuildAndSendSingleReportData(chip::app::ReadHandler*) at /Users/keanhinlim/connectedhomeip/examples/all-clusters-app/esp32/build/../third_party/connectedhomeip/src/app/reporting/Engine.cpp:451

0x400e0e3b: chip::app::reporting::Engine::Run() at /Users/keanhinlim/connectedhomeip/examples/all-clusters-app/esp32/build/../third_party/connectedhomeip/src/app/reporting/Engine.cpp:528

0x400e0e89: chip::app::reporting::Engine::Run(chip::System::Layer*, void*) at /Users/keanhinlim/connectedhomeip/examples/all-clusters-app/esp32/build/../third_party/connectedhomeip/src/app/reporting/Engine.cpp:483

0x4010d881: chip::System::TimerData::Callback::Invoke() const at /Users/keanhinlim/connectedhomeip/examples/all-clusters-app/esp32/build/esp-idf/chip/../../../../../../config/esp32/third_party/connectedhomeip/src/system/SystemTimer.h:61
 (inlined by) chip::System::TimerPool<chip::System::TimerList::Node>::Invoke(chip::System::TimerList::Node*) at /Users/keanhinlim/connectedhomeip/examples/all-clusters-app/esp32/build/esp-idf/chip/../../../../../../config/esp32/third_party/connectedhomeip/src/system/SystemTimer.h:224

which might be part of the problem here, perhaps...

@yunhanw-google @kghost any idea what's going on with the secure session there?

[kean-apple]

Adding more debug logging on M5
unpair-M5-debug-logging.txt
unpair-m5-chiptool-logging.txt

[kean-apple]

haven't seen this specific crash recently when using unpair option in chiptool

[mrjerryjohns]

Looks like the Session tracked by the ReadHandler somehow ... got torn down, resulting in there being no actual valid session held by the holder, triggering the VerifyOrDie above?

[mrjerryjohns]

@kean-apple is this still an issue?

[kean-apple]

closing. Not seen M5 board crash when removing 1 fabric. Still tracking M5 board crash when removing multiple fabrics #15305