Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

[Test Failed] [TC_DEM_2_7] fails on ESP32 #34960

Closed
jamesharrow opened this issue Aug 13, 2024 · 1 comment · Fixed by #35067
Closed

[Test Failed] [TC_DEM_2_7] fails on ESP32 #34960

jamesharrow opened this issue Aug 13, 2024 · 1 comment · Fixed by #35067
Assignees
@jamesharrow @PeterC1965
Labels
build issue needs triage tests

Comments

@jamesharrow
Copy link
Contributor

Test issue(s)

Having applied a patch to resolve the crash seen on ESP32 - see this issue #34954

When running the TC_DEM_2_7 against the chip-energy-management-app we see that step 5 fails with Invalid Command, but the test script is expecting Constraint Error.

Further investigation is needed to understand why it is returning the wrong error code.

Platform

esp32

Anything else?


INFO       | 2024-08-13 18:15:54.353572 | Executing Test Step: TH reads Forecast attribute.
INFO       | 2024-08-13 18:15:54.625141 | Test Step Completed [PASSED]: TH reads Forecast attribute.
INFO       | 2024-08-13 18:15:54.627048 | --------------------------------------------------------------------------------
INFO       | 2024-08-13 18:15:54.633160 | --------------------------------------------------------------------------------
INFO       | 2024-08-13 18:15:54.634799 | Executing Test Step: TH reads OptOutState attribute.
INFO       | 2024-08-13 18:15:54.749669 | Test Step Completed [PASSED]: TH reads OptOutState attribute.
INFO       | 2024-08-13 18:15:54.751330 | --------------------------------------------------------------------------------
INFO       | 2024-08-13 18:15:54.757734 | --------------------------------------------------------------------------------
INFO       | 2024-08-13 18:15:54.759412 | Executing Test Step: TH sends RequestConstraintBasedPowerForecast with constraints[0].{StartTime=now()-10, Duration=20, NominalPower=Forecast.Slots[0].NominalPower, MaximumEnergy=Forecast.Slots[0].NominalEnergy}, Cause=LocalOptimization.
INFO       | 2024-08-13 18:15:55.174483 | Test Step Completed [PASSED]: TH sends RequestConstraintBasedPowerForecast with constraints[0].{StartTime=now()-10, Duration=20, NominalPower=Forecast.Slots[0].NominalPower, MaximumEnergy=Forecast.Slots[0].NominalEnergy}, Cause=LocalOptimization.
INFO       | 2024-08-13 18:15:55.176136 | --------------------------------------------------------------------------------
INFO       | 2024-08-13 18:15:55.182476 | --------------------------------------------------------------------------------
INFO       | 2024-08-13 18:15:55.184178 | Executing Test Step: TH sends RequestConstraintBasedPowerForecast with constraints[0].{StartTime=now()+10, Duration=20, NominalPower=Forecast.Slots[0].NominalPower, MaximumEnergy=Forecast.Slots[0].NominalEnergy}, constraints[1].{StartTime=now()+20, Duration=20, NominalPower=Forecast.Slots[0].NominalPower, MaximumEnergy=Forecast.Slots[0].NominalEnergy}, constraints[2].{StartTime=now()+40, Duration=20, NominalPower=Forecast.Slots[0].NominalPower, MaximumEnergy=Forecast.Slots[0].NominalEnergy}, Cause=LocalOptimization.
WARNING    | 2024-08-13 18:15:55.668233 | Test Failure: Python test step failure
INFO       | 2024-08-13 18:15:55.671687 | Test Step Completed [FAILED]: TH sends RequestConstraintBasedPowerForecast with constraints[0].{StartTime=now()+10, Duration=20, NominalPower=Forecast.Slots[0].NominalPower, MaximumEnergy=Forecast.Slots[0].NominalEnergy}, constraints[1].{StartTime=now()+20, Duration=20, NominalPower=Forecast.Slots[0].NominalPower, MaximumEnergy=Forecast.Slots[0].NominalEnergy}, constraints[2].{StartTime=now()+40, Duration=20, NominalPower=Forecast.Slots[0].NominalPower, MaximumEnergy=Forecast.Slots[0].NominalEnergy}, Cause=LocalOptimization.
INFO       | 2024-08-13 18:15:55.674015 | --------------------------------------------------------------------------------
INFO       | 2024-08-13 18:15:55.683853 | --------------------------------------------------------------------------------
INFO       | 2024-08-13 18:15:55.685120 | Executing Test Step: Show test logs
INFO       | 2024-08-13 18:15:55.703813 | ---- Start of Python test logs ----
PYTHON_TEST | 2024-08-13 18:15:55.707039 | [MatterTest] 08-13 18:15:51.300 INFO ==========> TC_DEM_2_7 <==========
...

[MatterTest] 08-13 18:15:55.377 INFO <<< [E:42497i S:56886 M:131054175 (Ack:153280628)] (S) Msg TX to 1:0000000012344321 [B1F2] [UDP:172.24.0.102:5540] --- Type 0001:08 (IM:InvokeCommandRequest) (B:126)
[MatterTest] 08-13 18:15:55.541 INFO {
[MatterTest] 08-13 18:15:55.542 INFO 	"event" : "MessageReceived",
[MatterTest] 08-13 18:15:55.542 INFO 	"messageType" : "Secure",
[MatterTest] 08-13 18:15:55.543 INFO 	"packetHeader" : 
[MatterTest] 08-13 18:15:55.544 INFO 	{
[MatterTest] 08-13 18:15:55.544 INFO 		"flags" : 0,
[MatterTest] 08-13 18:15:55.545 INFO 		"msgCounter" : 153280629,
[MatterTest] 08-13 18:15:55.545 INFO 		"securityFlags" : 0,
[MatterTest] 08-13 18:15:55.546 INFO 		"sessionId" : 56886
[MatterTest] 08-13 18:15:55.547 INFO 	},
[MatterTest] 08-13 18:15:55.547 INFO 	"payload" : 
[MatterTest] 08-13 18:15:55.548 INFO 	{
[MatterTest] 08-13 18:15:55.548 INFO 		"decoded" : 
[MatterTest] 08-13 18:15:55.549 INFO 		{
[MatterTest] 08-13 18:15:55.549 INFO 			"invoke_response" : 
[MatterTest] 08-13 18:15:55.550 INFO 			{
[MatterTest] 08-13 18:15:55.550 INFO 				"interaction_model_revison" : "11",
[MatterTest] 08-13 18:15:55.551 INFO 				"invoke_responses" : 
[MatterTest] 08-13 18:15:55.551 INFO 				{
[MatterTest] 08-13 18:15:55.552 INFO 					"Anonymous<0>" : 
[MatterTest] 08-13 18:15:55.552 INFO 					{
[MatterTest] 08-13 18:15:55.553 INFO 						"status" : 
[MatterTest] 08-13 18:15:55.554 INFO 						{
[MatterTest] 08-13 18:15:55.554 INFO 							"path" : 
[MatterTest] 08-13 18:15:55.555 INFO 							{
[MatterTest] 08-13 18:15:55.555 INFO 								"cluster_id" : "152 == 'DeviceEnergyManagement'",
[MatterTest] 08-13 18:15:55.556 INFO 								"command_id" : "6 == 'RequestConstraintBasedForecast'",
[MatterTest] 08-13 18:15:55.556 INFO 								"endpoint_id" : "1"
[MatterTest] 08-13 18:15:55.557 INFO 							},
[MatterTest] 08-13 18:15:55.557 INFO 							"status" : 
[MatterTest] 08-13 18:15:55.558 INFO 							{
[MatterTest] 08-13 18:15:55.558 INFO 								"status" : "133 == kInvalidCommand"
[MatterTest] 08-13 18:15:55.559 INFO 							}
[MatterTest] 08-13 18:15:55.559 INFO 						}
[MatterTest] 08-13 18:15:55.560 INFO 					}
[MatterTest] 08-13 18:15:55.560 INFO 				},
[MatterTest] 08-13 18:15:55.561 INFO 				"suppress_response" : "false"
[MatterTest] 08-13 18:15:55.561 INFO 			}
[MatterTest] 08-13 18:15:55.562 INFO 		},
[MatterTest] 08-13 18:15:55.562 INFO 		"hex" : "152800360115350137002400012401982402061835012400851818181824FF0B18",
[MatterTest] 08-13 18:15:55.563 INFO 		"size" : 33
[MatterTest] 08-13 18:15:55.563 INFO 	},
[MatterTest] 08-13 18:15:55.564 INFO 	"payloadHeader" : 
[MatterTest] 08-13 18:15:55.564 INFO 	{
[MatterTest] 08-13 18:15:55.565 INFO 		"ackMessageCounter" : 131054175,
[MatterTest] 08-13 18:15:55.565 INFO 		"exchangeFlags" : 6,
[MatterTest] 08-13 18:15:55.566 INFO 		"exchangeId" : 42497,
[MatterTest] 08-13 18:15:55.566 INFO 		"initiator" : false,
[MatterTest] 08-13 18:15:55.566 INFO 		"messageType" : 9,
[MatterTest] 08-13 18:15:55.567 INFO 		"needsAck" : true,
[MatterTest] 08-13 18:15:55.567 INFO 		"protocolId" : 1
[MatterTest] 08-13 18:15:55.568 INFO 	}
[MatterTest] 08-13 18:15:55.568 INFO }
[MatterTest] 08-13 18:15:55.569 INFO >>> [E:42497i S:56886 M:153280629 (Ack:131054175)] (S) Msg RX from 1:0000000012344321 [B1F2] --- Type 0001:09 (IM:InvokeCommandResponse) (B:67)
[MatterTest] 08-13 18:15:55.582 INFO Received Command Response Status for Endpoint=1 Cluster=0x0000_0098 Command=0x0000_0006 Status=0x85
[MatterTest] 08-13 18:15:55.585 ERROR Exception occurred in test_TC_DEM_2_7.
Traceback (most recent call last):
  File "/root/python_testing/scripts/sdk/TC_DEMTestBase.py", line 162, in send_request_constraint_based_forecast
    await self.send_single_cmd(cmd=Clusters.DeviceEnergyManagement.Commands.RequestConstraintBasedForecast(constraints=constraintList,
  File "/root/python_testing/scripts/sdk/matter_testing_support.py", line 992, in send_single_cmd
    result = await dev_ctrl.SendCommand(nodeid=node_id, endpoint=endpoint, payload=cmd, timedRequestTimeoutMs=timedRequestTimeoutMs,
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/dist-packages/chip/ChipDeviceCtrl.py", line 1213, in SendCommand
    return await future
           ^^^^^^^^^^^^
chip.interaction_model.InteractionModelError: InteractionModelError: InvalidCommand (0x85)

During handling of the above exception, another exception occurred:

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_DEM_2_7.py", line 194, in test_TC_DEM_2_7
    await self.send_request_constraint_based_forecast(constraintList, cause=Clusters.DeviceEnergyManagement.Enums.AdjustmentCauseEnum.kLocalOptimization, expected_status=Status.ConstraintError)
  File "/root/python_testing/scripts/sdk/TC_DEMTestBase.py", line 170, in send_request_constraint_based_forecast
    asserts.assert_equal(e.status, expected_status, "Unexpected error returned")
  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=<Status.InvalidCommand: 133> != <Status.ConstraintError: 135> Unexpected error returned, Extras=None
@jamesharrow jamesharrow mentioned this issue Aug 13, 2024
Closed
@PeterC1965
Copy link
Contributor

Test 2.7 might being run on the ESP32 with both kPowerForecastReporting and kStateForecastReporting set when it should only be run with kStateForecastReporting (they are mutually exclusive flags). When I run the Linux test with both of these set, I see the same fail in test step 5.

I'll update the test plan + scripts to check for this and fail straightaway if they see this.

@PeterC1965 PeterC1965 mentioned this issue Aug 19, 2024
Merged
@jamesharrow jamesharrow moved this from Todo to In Progress in [Grouping] Energy Management Aug 23, 2024
@mergify mergify bot closed this as completed in #35067 Aug 29, 2024
@github-project-automation github-project-automation bot moved this from In Progress to Done in [Grouping] Energy Management Aug 29, 2024
@github-project-automation github-project-automation bot moved this from Todo to Done in [Build] Build Issues Aug 29, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@jamesharrow jamesharrow

@PeterC1965 PeterC1965

Labels
build issue needs triage tests
Projects
[Build] Build Issues
Archived in project
[Grouping] Energy Management
Archived in project
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

Address various DEM testing issues PeterC1965/connectedhomeip
2 participants
@jamesharrow @PeterC1965