[CERT-TEST-FAILURE] TC-BRBINFO-4.1 - python script is getting failied with error: "0 new endpoint found"

[KishokG]

Feature Area

Other

Test Case

TC-BRBINFO-4.1

Reproduction steps

TC-BRBINFO-4.1 python script is getting failure at TH server app(lit-icd-app) commissioning by throwing an following error:

[MatterTest] 08-03 06:18:11.353 INFO Starting ICD Server App
[MatterTest] 08-03 06:18:11.353 INFO <<< [E:63838i S:63476 M:144329222 (Ack:171881661)] (S) Msg TX to 1:0000000012344321 [31B4] [UDP:[fe80::e65f:1ff:fe0f:2878%eth0]:5540] --- Type 0000:10 (SecureChannel:StandaloneAck) (B:34)
[MatterTest] 08-03 06:18:11.356 INFO ICD started
/bin/sh: 1: examples/lit-icd-app/linux/out/lit-icd-app/: Permission denied
[MatterTest] 08-03 06:18:14.360 INFO Commissioning of ICD to fabric one (TH)
[MatterTest] 08-03 06:18:14.375 INFO Avahi browse: cache exhausted
[MatterTest] 08-03 06:18:15.376 INFO Avahi browse: all for now
[MatterTest] 08-03 06:18:44.388 ERROR Mdns discovery timed out

• TH: python controller
  commands used to build -

• source scripts/activate.sh && scripts/build_python.sh -m platform -d true -i no

• source no/bin/activate

DUT: Bridge-app

• scripts/examples/gn_build_example.sh examples/bridge-app/linux/ examples/bridge-app/linux/out/bridge-app chip_inet_config_enable_ipv4=false

TH server app: lit-icd-app

• scripts/examples/gn_build_example.sh examples/lit-icd-app/linux/ examples/lit-icd-app/linux/out/lit-icd-app chip_inet_config_enable_ipv4=false chip_enable_icd_server=true

Command used to launch the DUT : ./chip-bridge-app

Command used to run the python script : python3 src/python_testing/TC_BRBINFO_4_1.py --commissioning-method on-network --qr-code MT:-24J042C00KA0648G00 --string-arg th_server_app_path:examples/lit-icd-app/linux/out/lit-icd-app

Bug prevalence

Whenever I do this

GitHub hash of the SDK that was being used

6ba9655

Platform

raspi

Anything else?

Here is the failure logs:
DUT_log: Uploading TC-BRBINFO-4.1(DUT).txt…
CTRL_log: TC-BRBINFO-4.1(CTRL).txt

[KishokG]

Ran using TH image docker(TH image version: v2.11-beta2+fall2024) and the test is failing with below error:

Reproduction steps

TC-BRBINFO-4.1 python script is getting failied due to 0 new endpoint found in FabricSync Admin test app

[MatterTest] 08-06 04:45:42.568 ERROR Exception occurred in test_TC_BRBINFO_4_1.
Traceback (most recent call last):
File "/usr/local/lib/python3.12/dist-packages/mobly/base_test.py", line 818, in exec_one_test
test_method()
File "/root/python_testing/scripts/sdk/matter_testing_support.py", line 1671, in async_runner
return _async_runner(body, self, *args, **kwargs)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/root/python_testing/scripts/sdk/matter_testing_support.py", line 1659, in _async_runner
return asyncio.run(runner_with_timeout)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/lib/python3.12/asyncio/runners.py", line 194, in run
return runner.run(main)
^^^^^^^^^^^^^^^^
File "/usr/lib/python3.12/asyncio/runners.py", line 118, in run
return self._loop.run_until_complete(task)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/lib/python3.12/asyncio/base_events.py", line 687, in run_until_complete
return future.result()
^^^^^^^^^^^^^^^
File "/usr/lib/python3.12/asyncio/tasks.py", line 520, in wait_for
return await fut
^^^^^^^^^
File "/root/python_testing/scripts/sdk/TC_BRBINFO_4_1.py", line 157, in test_TC_BRBINFO_4_1
dynamic_endpoint_id = await self._get_dynamic_endpoint()
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/root/python_testing/scripts/sdk/TC_BRBINFO_4_1.py", line 98, in _get_dynamic_endpoint
asserts.assert_equal(len(unique_endpoints_set), 1, "Expected only one new endpoint")
File "/usr/local/lib/python3.12/dist-packages/mobly/asserts.py", line 66, in assert_equal
_call_unittest_assertion(
File "/usr/local/lib/python3.12/dist-packages/mobly/asserts.py", line 50, in _call_unittest_assertion
raise signals.TestFailure(my_msg, extras=extras)
mobly.signals.TestFailure: Details=0 != 1 Expected only one new endpoint, Extras=None

TH: TH image docker(TH image version: v2.11-beta2+fall2024)

DUT: Bridge-app

TH server app: lit-icd-app

Command used to launch the DUT : ./chip-bridge-app

Command used to run the python script : python TC_BRBINFO_4_1.py --commissioning-method on-network --discriminator 3840 --passcode 20202021 --paa-trust-store-path /credentials/development/paa-root-certs/ --storage-path admin_storage.json --string-arg th_server_app_path:/root/lit-icd-app

Bug prevalence
Whenever I do this

GitHub hash of the SDK that was being used
d0d9127

Platform
raspi

Here is the failure logs:

tc-brbinfo-4-1-dut.txt
tc-brbinfo-4-1.txt

[rochaferraz]

@KishokG please try following these steps. I think the most important issue is that it seems you are using the bridge app, while we need to have both the FabricSync Bridge and FabricSync Administrator apps.

Build python wheels and activated the environment

$ ./scripts/build_python.sh -i py
$ source py/bin/activate

Build & run the FabricSync Bridge and Administrator app with RPC support. Do not the regular bridge app, which seems to be used in your setup.

$ ./scripts/build/build_examples.py --target linux-x64-fabric-admin-rpc build
$ ./scripts/build/build_examples.py --target linux-x64-fabric-bridge-rpc build
$ ./out/linux-x64-fabric-admin-rpc/fabric-admin # (in terminal screen 2)
$ ./out/linux-x64-fabric-bridge-rpc/fabric-bridge-app --KVS fs.kvs # (in terminal screen 3) 

Build ICD

$ ./scripts/build/build_examples.py --target linux-x64-lit-icd build

Run Test

$ python3 src/python_testing/TC_BRBINFO_4_1.py --commissioning-method on-network --qr-code MT:-24J042C00KA0648G00 --string-arg th_server_app_path:out/linux-x64-lit-icd/lit-icd-app

after ICD is commissioned to TH, follow the step prompted the user entering ICD<->DUT commissioning information into the FabricAdmin terminal. Similar to:

>>>  pairing onnetwork 111 34659557

Then hit on the DUT test script terminal.

At the end of that step, ICD is commissioned both to DUT and to TH.

The current DUT sample app eventually fails with a Timeout on event ActiveChanged error, but that needs to be fixed and it is unrelated to this issue.

[rochaferraz]

fyi @tehampson @cletnick

[KishokG]

@rochaferraz Build is failed due to wrong target name in RPI platform:

ubuntu@ubuntu:~/connectedhomeip$ ./scripts/build/build_examples.py --target linux-x64-fabric-admin-rpc build
Usage: build_examples.py [OPTIONS] COMMAND1 [ARGS]... [COMMAND2 [ARGS]...]...
Try 'build_examples.py --help' for help.

Error: Invalid value for '--target': 'linux-x64-fabric-admin-rpc' is not a valid target name.
ubuntu@ubuntu:~/connectedhomeip$

[rochaferraz]

@KishokG sorry for the delay, I'm back today from OOO. What branch/tag are you using?

[KishokG]

@KishokG sorry for the delay, I'm back today from OOO. What branch/tag are you using?

@rochaferraz I've tried to build with TE2 commit: d0d91272068f267cf880f9d56787ca28da885673

[cjandhyala]

@rochaferraz @KishokG could you pls get together offline in slack tomorrow and resolve this issue. this seem to be more of a build issue than a script issue at this point.

[tehampson]

./scripts/build/build_examples.py --target linux-arm64-lit-icd-clang-no-ble build is the command needed to build the raspi version of the lit-icd app that we are using.

There is already a lit-icd-app that I think should be use-able https://github.com/project-chip/connectedhomeip/blob/master/integrations/docker/images/chip-cert-bins/Dockerfile#L256 on the TH

I will keep this issue open add assigned to myself to confirm this app does in fact exist already on TH and will work for passing the test

[cjandhyala]

@KishokG Could you pls try this ASAP

[KishokG]

@KishokG Could you pls try this ASAP

Sure @cjandhyala

[KishokG]

@tehampson and @cjandhyala I've tried to execute the test but it's failing in commissioning.

Steps followed:

Commands used to build the Sample app:

./scripts/build/build_examples.py --target linux-arm64-fabric-admin-rpc build
./scripts/build/build_examples.py --target linux-arm64-fabric-bridge-rpc build
./scripts/build/build_examples.py --target linux-arm64-lit-icd-clang-no-ble build

Command used to launch the DUT:
./fabric-admin
./fabric-bridge-app --KVS fs.kvs

Command used to run the python script:
python3 TC_BRBINFO_4_1.py --commissioning-method on-network --qr-code MT:-24J042C00KA0648G00 --string-arg th_server_app_path:out/linux-arm64-lit-icd-clang-no-ble/lit-icd-app

Here is the logs:
TC-BRBINFO-4.1_Fabric_admin_rpc_logs.txt
TC-BRBINFO-4.1_Fabric_bridge_rpc_logs.txt
TC-BRBINFO-4.1_TH_logs.txt

[tehampson]

Did you compile the example from latest master or TE2 branch?

I think we would benefit from a remote debug session. I might be available Friday I will be in Central European Time (CET), so we might have more overlapping hours. I will message tomorrow with my avaiablity on Friday. If that doesn't work, I am free next Tuesday, and will be back in EST timezone

Assuming we can figure out why you are stuck on commissioning the "DUT" I also want to mention that you need to use the latest version in master for TC_BRBINFO_4_1.py. For TE2 we know that these failed and we have since updated both app and test script and plan to fix some issues that were encountered, which is why using latest is very important

Also this test currently takes over 60 mins to run. We also noticed a corner case we should test for which means this test would increase to over 2 hours. We are working on a spec changes that will help reduce length of time this test should take.

[KishokG]

Did you compile the example from latest master or TE2 branch?

Yes @tehampson I've tried in latest Master TOT.

[KishokG]

I think we would benefit from a remote debug session. I might be available Friday I will be in Central European Time (CET), so we might have more overlapping hours. I will message tomorrow with my avaiablity on Friday. If that doesn't work, I am free next Tuesday, and will be back in EST timezone

Sure @tehampson

[KishokG]

@tehampson Could you please let me know, When you are available for the remote debug session.

[tehampson]

Arranging time over slack

[tehampson]

We had a call it seems like Kishok is up and running. To summarize some additional comments made during our call I would recommend holding off on running BRBINFO_4_1 until the following PRs land that bring in spec change to greatly reduce length of time required for test to run (From over 60 mins to under 5 mins)

TimeoutMs is being added in spec text in https://github.com/CHIP-Specifications/connectedhomeip-spec/pull/10298

Codegen is happening in #35154
Update to example app #35174
Update to test plan is #35160

[KishokG]

@tehampson Here is the code that we changed during the debug session:

    logging.info("Starting ICD Server App")
    cmd = [app]
    cmd.extend(['--secured-device-port', str(self.port)])
    cmd.extend(['--discriminator', str(discriminator)])
    cmd.extend(['--passcode', str(passcode)])
    cmd.extend(['--KVS', self.kvs])
    self.app_process = subprocess.Popen(cmd)
    ## self.app_process = subprocess.Popen(cmd, bufsize=0, shell=False)
    logging.info("ICD started")
    time.sleep(3)