Example app conformance failed: chip-tv-casting-app

[HNaftalin]

Reproduction steps

Need to find and address conformance issues on the example app "chip-tv-casting-app"
NOTE: we should remove the door lock and media clusters completely to match the all-clusters

Bug prevalence

always

GitHub hash of the SDK that was being used

tot

Platform

core

Platform Version(s)

No response

Anything else?

No response

References:

#29812
#37267

Test Command:

run_python_test.py --app ./out/linux-x64-tv-casting-app-no-ble/chip-tv-casting-app --factory-reset --app-args "--trace-to json:log" --script src/python_testing/TC_DeviceConformance.py --script-args "--qr-code MT:-24J0AFN00KA0648G00"

Error Summary:

Test didn't complete. Possible timeout or crash. Last log lines:
[2025-01-28 09:41:41.446423][�[32mTEST�[0m][�[33mSTDOUT�[0m][67939:67939] CHIP:DL: Got Ethernet interface: ens4

[2025-01-28 09:41:41.446489][�[32mTEST�[0m][�[33mSTDOUT�[0m][67939:67939] CHIP:DL: Found the primary Ethernet interface:ens4

[2025-01-28 09:41:41.446568][�[32mTEST�[0m][�[33mSTDOUT�[0m][67939:67939] CHIP:DL: Failed to get WiFi interface

[2025-01-28 09:41:41.446572][�[32mTEST�[0m][�[33mSTDOUT�[0m][67939:67939] CHIP:DL: Failed to reset WiFi statistic counts

[2025-01-28 09:41:41.447248][�[32mTEST�[0m][�[33mSTDOUT�[0m][67939:67939] CHIP:TS: Last Known Good Time: 2023-10-14T01:16:48

[2025-01-28 09:41:41.447518][�[32mTEST�[0m][�[33mSTDOUT�[0m][67939:67939] CHIP:FP: Fabric index 0x1 was retrieved from storage. Compressed FabricId 0xFC175BF08C8DD684, FabricId 0x0000000000000001, NodeId 0x000000000001B669, VendorId 0xFFF1

[2025-01-28 09:41:41.448370][�[32mTEST�[0m][�[33mSTDOUT�[0m][67939:67939] CHIP:DMG: Ember attribute persistence requires setting up

[2025-01-28 09:41:41.448384][�[32mTEST�[0m][�[33mSTDOUT�[0m][67939:67939] CHIP:ZCL: Using ZAP configuration...

[2025-01-28 09:41:41.448722][�[32mTEST�[0m][�[33mSTDOUT�[0m][67939:67939] CHIP:IN: CASE Server enabling CASE session setups

[2025-01-28 09:41:41.573742][�[32mTEST�[0m][�[33mSTDOUT�[0m][MatterTest] 01-28 09:41:41.573 INFO Starting test set, running 1 tests

[2025-01-28 09:41:41.575197][�[32mTEST�[0m][�[33mSTDOUT�[0m][MatterTest] 01-28 09:41:41.575 INFO ==========> TC_DeviceConformance <==========

[2025-01-28 09:41:41.576823][�[32mTEST�[0m][�[33mSTDOUT�[0m][MatterTest] 01-28 09:41:41.576 INFO Starting commissioning discovery over DNS-SD

[2025-01-28 09:41:41.577425][�[32mTEST�[0m][�[33mSTDOUT�[0m][MatterTest] 01-28 09:41:41.577 INFO Lookup started for FC175BF08C8DD684-0000000012344321

[2025-01-28 09:41:41.778387][�[32mTEST�[0m][�[33mSTDOUT�[0m][MatterTest] 01-28 09:41:41.778 INFO Checking node lookup status for FC175BF08C8DD684-0000000012344321 after 200 ms

[2025-01-28 09:42:11.592746][�[32mTEST�[0m][�[33mSTDOUT�[0m][MatterTest] 01-28 09:42:11.592 ERROR Discovery timed out

[2025-01-28 09:42:11.592882][�[32mTEST�[0m][�[33mSTDOUT�[0m][MatterTest] 01-28 09:42:11.592 ERROR Secure Pairing Failed

[2025-01-28 09:42:11.593232][�[32mTEST�[0m][�[33mSTDOUT�[0m][MatterTest] 01-28 09:42:11.593 WARNING Failed to establish secure session to device: src/controller/python/ChipDeviceController-ScriptDevicePairingDelegate.cpp:96: CHIP Error 0x00000003: Incorrect state

[2025-01-28 09:42:12.593406][�[32mTEST�[0m][�[33mSTDOUT�[0m][MatterTest] 01-28 09:42:12.593 ERROR Timeout waiting for mDNS resolution.

[2025-01-28 09:42:26.592041][�[32mTEST�[0m][�[33mSTDOUT�[0m][MatterTest] 01-28 09:42:26.591 INFO Checking node lookup status for FC175BF08C8DD684-0000000012344321 after 45014 ms

[2025-01-28 09:42:26.592261][�[32mTEST�[0m][�[33mSTDOUT�[0m][MatterTest] 01-28 09:42:26.591 ERROR OperationalSessionSetup[1:0000000012344321]: operational discovery failed: src/lib/address_resolve/AddressResolve_DefaultImpl.cpp:124: CHIP Error 0x00000032: Timeout

[2025-01-28 09:42:26.596878][�[32mTEST�[0m][�[33mSTDOUT�[0m][MatterTest] 01-28 09:42:26.592 ERROR Error in TC_DeviceConformance#setup_class.

[2025-01-28 09:42:26.596981][�[32mTEST�[0m][�[33mSTDOUT�[0m]Traceback (most recent call last):

[2025-01-28 09:42:26.597074][�[32mTEST�[0m][�[33mSTDOUT�[0m] File "/tmp/connectedhomeip/out/python_env/lib/python3.11/site-packages/mobly/base_test.py", line 428, in _setup_class

[2025-01-28 09:42:26.597097][�[32mTEST�[0m][�[33mSTDOUT�[0m] self.setup_class()

[2025-01-28 09:42:26.597207][�[32mTEST�[0m][�[33mSTDOUT�[0m] File "/tmp/connectedhomeip/out/python_env/lib/python3.11/site-packages/chip/testing/matter_testing.py", line 2107, in async_runner

[2025-01-28 09:42:26.597251][�[32mTEST�[0m][�[33mSTDOUT�[0m] return _async_runner(body, self, *args, **kwargs)

[2025-01-28 09:42:26.597293][�[32mTEST�[0m][�[33mSTDOUT�[0m] ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^

[2025-01-28 09:42:26.597387][�[32mTEST�[0m][�[33mSTDOUT�[0m] File "/tmp/connectedhomeip/out/python_env/lib/python3.11/site-packages/chip/testing/matter_testing.py", line 2095, in _async_runner

[2025-01-28 09:42:26.597465][�[32mTEST�[0m][�[33mSTDOUT�[0m] return self.event_loop.run_until_complete(asyncio.wait_for(body(self, *args, **kwargs), timeout=timeout))

[2025-01-28 09:42:26.597545][�[32mTEST�[0m][�[33mSTDOUT�[0m] ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^

[2025-01-28 09:42:26.597609][�[32mTEST�[0m][�[33mSTDOUT�[0m] File "/usr/lib/python3.11/asyncio/base_events.py", line 650, in run_until_complete

[2025-01-28 09:42:26.597633][�[32mTEST�[0m][�[33mSTDOUT�[0m] return future.result()

[2025-01-28 09:42:26.597657][�[32mTEST�[0m][�[33mSTDOUT�[0m] ^^^^^^^^^^^^^^^

[2025-01-28 09:42:26.597711][�[32mTEST�[0m][�[33mSTDOUT�[0m] File "/usr/lib/python3.11/asyncio/tasks.py", line 484, in wait_for

[2025-01-28 09:42:26.597732][�[32mTEST�[0m][�[33mSTDOUT�[0m] return fut.result()

[2025-01-28 09:42:26.597754][�[32mTEST�[0m][�[33mSTDOUT�[0m] ^^^^^^^^^^^^

[2025-01-28 09:42:26.597825][�[32mTEST�[0m][�[33mSTDOUT�[0m] File "/tmp/connectedhomeip/src/python_testing/TC_DeviceConformance.py", line 383, in setup_class

[2025-01-28 09:42:26.597855][�[32mTEST�[0m][�[33mSTDOUT�[0m] await self.setup_class_helper()

[2025-01-28 09:42:26.597949][�[32mTEST�[0m][�[33mSTDOUT�[0m] File "/tmp/connectedhomeip/src/python_testing/TC_DeviceConformance.py", line 56, in setup_class_helper

[2025-01-28 09:42:26.597984][�[32mTEST�[0m][�[33mSTDOUT�[0m] await super().setup_class_helper()

[2025-01-28 09:42:26.598083][�[32mTEST�[0m][�[33mSTDOUT�[0m] File "/tmp/connectedhomeip/out/python_env/lib/python3.11/site-packages/chip/testing/basic_composition.py", line 182, in setup_class_helper

[2025-01-28 09:42:26.598127][�[32mTEST�[0m][�[33mSTDOUT�[0m] wildcard_read = (await dev_ctrl.Read(node_id, [()]))

[2025-01-28 09:42:26.598169][�[32mTEST�[0m][�[33mSTDOUT�[0m] ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^

[2025-01-28 09:42:26.598257][�[32mTEST�[0m][�[33mSTDOUT�[0m] File "/tmp/connectedhomeip/out/python_env/lib/python3.11/site-packages/chip/ChipDeviceCtrl.py", line 1564, in Read

[2025-01-28 09:42:26.598339][�[32mTEST�[0m][�[33mSTDOUT�[0m] device = await self.GetConnectedDevice(nodeid, payloadCapability=payloadCapability)

[2025-01-28 09:42:26.598403][�[32mTEST�[0m][�[33mSTDOUT�[0m] ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^

[2025-01-28 09:42:26.598494][�[32mTEST�[0m][�[33mSTDOUT�[0m] File "/tmp/connectedhomeip/out/python_env/lib/python3.11/site-packages/chip/ChipDeviceCtrl.py", line 1091, in GetConnectedDevice

[2025-01-28 09:42:26.598509][�[32mTEST�[0m][�[33mSTDOUT�[0m] await future

[2025-01-28 09:42:26.598596][�[32mTEST�[0m][�[33mSTDOUT�[0m]chip.exceptions.ChipStackError: src/lib/address_resolve/AddressResolve_DefaultImpl.cpp:124: CHIP Error 0x00000032: Timeout

[2025-01-28 09:42:26.598640][�[32mTEST�[0m][�[33mSTDOUT�[0m][MatterTest] 01-28 09:42:26.597 INFO ***** Test Failure :

[2025-01-28 09:42:26.598683][�[32mTEST�[0m][�[33mSTDOUT�[0m][MatterTest] 01-28 09:42:26.597 INFO Finished test in 0ms

[2025-01-28 09:42:26.598713][�[32mTEST�[0m][�[33mSTDOUT�[0m][MatterTest] 01-28 09:42:26.597 ERROR

[2025-01-28 09:42:26.598717][�[32mTEST�[0m][�[33mSTDOUT�[0m]

[2025-01-28 09:42:26.598766][�[32mTEST�[0m][�[33mSTDOUT�[0m]******************************************************************

[2025-01-28 09:42:26.598771][�[32mTEST�[0m][�[33mSTDOUT�[0m]*

[2025-01-28 09:42:26.598809][�[32mTEST�[0m][�[33mSTDOUT�[0m]* Test setup_class failed for the following reason:

[2025-01-28 09:42:26.598875][�[32mTEST�[0m][�[33mSTDOUT�[0m]* src/lib/address_resolve/AddressResolve_DefaultImpl.cpp:124: CHIP Error 0x00000032: Timeout

[2025-01-28 09:42:26.598880][�[32mTEST�[0m][�[33mSTDOUT�[0m]*

[2025-01-28 09:42:26.598982][�[32mTEST�[0m][�[33mSTDOUT�[0m]* File "/tmp/connectedhomeip/out/python_env/lib/python3.11/site-packages/chip/ChipDeviceCtrl.py", line 1091, in GetConnectedDevice

[2025-01-28 09:42:26.599073][�[32mTEST�[0m][�[33mSTDOUT�[0m]* chip.exceptions.ChipStackError: src/lib/address_resolve/AddressResolve_DefaultImpl.cpp:124: CHIP Error 0x00000032: Timeout

[2025-01-28 09:42:26.599078][�[32mTEST�[0m][�[33mSTDOUT�[0m]*

[2025-01-28 09:42:26.599090][�[32mTEST�[0m][�[33mSTDOUT�[0m]* Test step:

[2025-01-28 09:42:26.599130][�[32mTEST�[0m][�[33mSTDOUT�[0m]* UNKNOWN - no test steps provided in test script

[2025-01-28 09:42:26.599135][�[32mTEST�[0m][�[33mSTDOUT�[0m]*

[2025-01-28 09:42:26.599150][�[32mTEST�[0m][�[33mSTDOUT�[0m]* Endpoint: None

[2025-01-28 09:42:26.599155][�[32mTEST�[0m][�[33mSTDOUT�[0m]*

[2025-01-28 09:42:26.599213][�[32mTEST�[0m][�[33mSTDOUT�[0m]*******************************************************************

[2025-01-28 09:42:26.599218][�[32mTEST�[0m][�[33mSTDOUT�[0m]

[2025-01-28 09:42:26.611558][�[32mTEST�[0m][�[33mSTDOUT�[0m][MatterTest] 01-28 09:42:26.611 INFO Summary for test class TC_DeviceConformance: Error 1, Executed 0, Failed 0, Passed 0, Requested 4, Skipped 4

[2025-01-28 09:42:26.611956][�[32mTEST�[0m][�[33mSTDOUT�[0m][MatterTest] 01-28 09:42:26.611 INFO Summary for test run MatterTest@01-28-2025_09-41-41-572:

[2025-01-28 09:42:26.612072][�[32mTEST�[0m][�[33mSTDOUT�[0m]Total time elapsed 45.03794970400031s

[2025-01-28 09:42:26.612236][�[32mTEST�[0m][�[33mSTDOUT�[0m]Artifacts are saved in "/tmp/matter_testing/logs/MatterTest/01-28-2025_09-41-41-572"

[2025-01-28 09:42:26.612326][�[32mTEST�[0m][�[31mSTDERR�[0m]INFO:root:Finished test set, ran for 45038274.0ms

[2025-01-28 09:42:26.612452][�[32mTEST�[0m][�[33mSTDOUT�[0m]Test summary saved in "/tmp/matter_testing/logs/MatterTest/01-28-2025_09-41-41-572/test_summary.yaml"

[2025-01-28 09:42:26.612534][�[32mTEST�[0m][�[33mSTDOUT�[0m]Test results: Error 1, Executed 0, Failed 0, Passed 0, Requested 4, Skipped 4

[2025-01-28 09:42:26.612754][�[32mTEST�[0m][�[31mSTDERR�[0m]INFO:chip.native.FP:Forgetting fabric 0x1

[2025-01-28 09:42:26.612815][�[32mTEST�[0m][�[31mSTDERR�[0m]INFO:chip.native.TS:Pending Last Known Good Time: 2023-10-14T01:16:48

[2025-01-28 09:42:26.612914][�[32mTEST�[0m][�[31mSTDERR�[0m]INFO:chip.native.TS:Previous Last Known Good Time: 2023-10-14T01:16:48

[2025-01-28 09:42:26.613053][�[32mTEST�[0m][�[31mSTDERR�[0m]INFO:chip.native.TS:Reverted Last Known Good Time to previous value

[2025-01-28 09:42:26.613369][�[32mTEST�[0m][�[31mSTDERR�[0m]ERROR:chip.native.CTL:Shutting down the stack...

[2025-01-28 09:42:26.614748][�[32mTEST�[0m][�[31mSTDERR�[0m]ERROR:chip.native.-:src/messaging/ExchangeMgr.cpp:185: CHIP Error 0x00000007: No unsolicited message handler at src/protocols/bdx/BdxTransferServer.cpp:55

[2025-01-28 09:42:26.614842][�[32mTEST�[0m][�[31mSTDERR�[0m]INFO:chip.native.FP:Shutting down FabricTable

[2025-01-28 09:42:26.614898][�[32mTEST�[0m][�[31mSTDERR�[0m]INFO:chip.native.TS:Pending Last Known Good Time: 2023-10-14T01:16:48

[2025-01-28 09:42:26.614969][�[32mTEST�[0m][�[31mSTDERR�[0m]INFO:chip.native.TS:Previous Last Known Good Time: 2023-10-14T01:16:48

[2025-01-28 09:42:26.615022][�[32mTEST�[0m][�[31mSTDERR�[0m]INFO:chip.native.TS:Reverted Last Known Good Time to previous value

[2025-01-28 09:42:26.618549][�[32mTEST�[0m][�[31mSTDERR�[0m]INFO:chip.native.DL:NVS set: chip-counters/total-operational-hours = 0 (0x0)

[2025-01-28 09:42:26.618620][�[32mTEST�[0m][�[31mSTDERR�[0m]INFO:chip.native.DL:Inet Layer shutdown

[2025-01-28 09:42:26.618654][�[32mTEST�[0m][�[31mSTDERR�[0m]INFO:chip.native.DL:BLE Layer shutdown

[2025-01-28 09:42:26.618686][�[32mTEST�[0m][�[31mSTDERR�[0m]INFO:chip.native.DL:System Layer shutdown

[2025-01-28 09:42:26.618860][�[32mTEST�[0m][�[31mSTDERR�[0m]ERROR:root:Final result: FAIL !

[2025-01-28 09:42:26.686774][�[32mTEST�[0m][�[31mSTDERR�[0m]ERROR:asyncio:Task exception was never retrieved

[2025-01-28 09:42:26.687116][�[32mTEST�[0m][�[31mSTDERR�[0m]future: exception=ChipStackError(3, 'src/controller/python/ChipDeviceController-ScriptDevicePairingDelegate.cpp:96: CHIP Error 0x00000003: Incorrect state')>

[2025-01-28 09:42:26.687152][�[32mTEST�[0m][�[31mSTDERR�[0m]Traceback (most recent call last):

[2025-01-28 09:42:26.687256][�[32mTEST�[0m][�[31mSTDERR�[0m] File "/tmp/connectedhomeip/out/python_env/lib/python3.11/site-packages/chip/ChipDeviceCtrl.py", line 731, in EstablishPASESession

[2025-01-28 09:42:26.687287][�[32mTEST�[0m][�[31mSTDERR�[0m] await self._establishPASESession(

[2025-01-28 09:42:26.687379][�[32mTEST�[0m][�[31mSTDERR�[0m] File "/tmp/connectedhomeip/out/python_env/lib/python3.11/site-packages/chip/ChipDeviceCtrl.py", line 716, in _establishPASESession

[2025-01-28 09:42:26.687416][�[32mTEST�[0m][�[31mSTDERR�[0m] await asyncio.futures.wrap_future(ctx.future)

[2025-01-28 09:42:26.687520][�[32mTEST�[0m][�[31mSTDERR�[0m]chip.exceptions.ChipStackError: src/controller/python/ChipDeviceController-ScriptDevicePairingDelegate.cpp:96: CHIP Error 0x00000003: Incorrect state

2025-01-28 09:42:26 matter-build-coverage root[67933] ERROR Test script exited with returncode 1

2025-01-28 09:42:26 matter-build-coverage root[67933] INFO Stopping app with SIGTERM