project-chip / certification-tool

A test harness and tooling designed to simplify development, testing, and certification for devices, guided by the Connectivity Standards Alliance.
https://csa-iot.org/
Apache License 2.0
42 stars 24 forks source link

[BUG] [Matter1.4 TE#2] TC-OPSTATE-2.5 test failure with python script in step 2 #408

Open OliverFan1 opened 3 months ago

OliverFan1 commented 3 months ago

Reproduction steps

For TC-OPSTATE-2.5, UI-python test seems not work right, and if I run test in Python inside docker mode, test failed quite early at step2. Test commands and parameters are as follows (found from _Matter_V_1_4TestPlanVerification document in Python Script Command sheet): python3 TC_OPSTATE_2_5.py --commissioning-method ble-wifi --wifi-ssid ORBI32 --wifi-passphrase slowballoon575 --discriminator 3840 --passcode 20202021 --storage-path admin_storage.json --PICS /var/tmp/ --int-arg PIXIT_ENDPOINT:1 PIXIT.WAITTIME.REBOOT:100 --paa-trust-store-path /credentials/development/paa-root-certs/

Bug prevalence

everytime

GitHub hash of the SDK that was being used

304df86c9300ecfdfb1e6424565867d9dc6ad359

Platform

freeRTOS, other

Platform Version(s)

No response

Anything else?

This issue was found during Matter 1.4 TE#2, see attached the test log failed-TC-OPSTATE-2.5.log

robszewczyk commented 2 months ago

Relevant stack trace:

[MatterTest] 08-16 09:53:41.640 INFO <<< [E:23629i S:977 M:114168724 (Ack:138563668)] (S) Msg TX to 1:0000000012344321 [CE33] [UDP:192.168.1.23:5540] --- Type 0001:01 (IM:StatusResponse) (B:42)
[MatterTest] 08-16 09:53:41.644 ERROR Exception occurred in test_TC_OPSTATE_2_5.
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 1744, in async_runner
    return _async_runner(body, self, *args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/root/python_testing/scripts/sdk/matter_testing_support.py", line 1732, 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_OPSTATE_2_5.py", line 57, in test_TC_OPSTATE_2_5
    await self.TEST_TC_OPSTATE_BASE_2_5(endpoint=endpoint)
  File "/root/python_testing/scripts/sdk/TC_OpstateCommon.py", line 1046, in TEST_TC_OPSTATE_BASE_2_5
    await events_callback.start(self.default_controller,
  File "/root/python_testing/scripts/sdk/TC_OpstateCommon.py", line 63, in start
    self._subscription = await dev_ctrl.ReadEvent(node_id,
                         ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/dist-packages/chip/ChipDeviceCtrl.py", line 1680, in ReadEvent
    res = await self.Read(nodeid=nodeid, events=events, eventNumberFilter=eventNumberFilter,
          ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/dist-packages/chip/ChipDeviceCtrl.py", line 1534, in Read
    return await future
           ^^^^^^^^^^^^
chip.exceptions.ChipStackError: IM Error 0x00000580: General error: 0x80 (INVALID_ACTION)
[MatterTest] 08-16 09:53:41.660 ERROR Exception happened when executing on_fail for test_TC_OPSTATE_2_5.
Traceback (most recent call last):
  File "/usr/local/lib/python3.12/dist-packages/mobly/base_test.py", line 665, in _exec_procedure_func
    func(copy.deepcopy(tr_record))
         ^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/copy.py", line 162, in deepcopy
    y = _reconstruct(x, memo, *rv)
        ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/copy.py", line 259, in _reconstruct
    state = deepcopy(state, memo)
            ^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/copy.py", line 136, in deepcopy
    y = copier(x, memo)
        ^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/copy.py", line 221, in _deepcopy_dict
    y[deepcopy(key, memo)] = deepcopy(value, memo)
                             ^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/copy.py", line 143, in deepcopy
    y = copier(memo)
        ^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/dist-packages/mobly/records.py", line 290, in __deepcopy__
    exception = copy.deepcopy(self.exception)
                ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/copy.py", line 162, in deepcopy
    y = _reconstruct(x, memo, *rv)
        ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/copy.py", line 253, in _reconstruct
    y = func(*args)
        ^^^^^^^^^^^
  File "/usr/lib/python3.12/copy.py", line 252, in <genexpr>
    args = (deepcopy(arg, memo) for arg in args)
            ^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/copy.py", line 151, in deepcopy
    rv = reductor(4)
         ^^^^^^^^^^^
ValueError: ctypes objects containing pointers cannot be pickled
cjandhyala commented 2 months ago

@OliverFan1 Looks like this issue on your product side. Could you verify from your side ?

OliverFan1 commented 2 months ago

Hi @cjandhyala, I'm not sure this issue is on my dut side. I did more tests and found that one more parameter needs to be added to test parameters: "endpoint": "1" to pass step 2.

However after that, further test still failed at:

File "/root/python_testing/scripts/sdk/TC_OpstateCommon.py", line 1105, in TEST_TC_OPSTATE_BASE_2_5
    asserts.assert_less_equal(initial_countdown_time, event_data.totalOperationalTime,
File "/usr/local/lib/python3.12/dist-packages/mobly/asserts.py", line 198, in assert_less_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=30 not less than or equal to 0 The total operation time shall be at least 30.0, Extras=None

While in the same log, script already got a subscription report in which totalOperationalTime=30 (line 1677)

I also did step by step manual test according to the Verification Steps Document and test passed.

Find attached the new UI-Python failure log and my manual test passed log. manual-test-pass-OPSTATE-2_5_0904.log still-failed-UI_Python-OPSTATE-2_5_0904.log

Thanks