From caea3ec81b8c1f1e690323a00426301dd9c9a05a Mon Sep 17 00:00:00 2001 From: Tennessee Carmel-Veilleux Date: Wed, 10 Jan 2024 16:37:02 -0500 Subject: [PATCH] Fix TimeSnapshot command and add TC-DGGEN-2.4 (#31179) * Implement TimeSnapshot command properly * Add TC-DGGEN-2.4 * Restyled by clang-format * Restyled by isort * Fix lint * Try to fix build * Fix lint some more * Restyled by gn * Address review comments * Restyled by clang-format * Restyled by gn --------- Co-authored-by: tennessee.carmelveilleux@gmail.com Co-authored-by: Restyled.io --- .github/workflows/tests.yaml | 3 +- .../general-diagnostics-server.cpp | 62 +++++- src/python_testing/TC_DGGEN_2_4.py | 192 ++++++++++++++++++ src/python_testing/TC_TIMESYNC_2_2.py | 3 +- src/python_testing/matter_testing_support.py | 26 ++- 5 files changed, 276 insertions(+), 10 deletions(-) create mode 100644 src/python_testing/TC_DGGEN_2_4.py diff --git a/.github/workflows/tests.yaml b/.github/workflows/tests.yaml index e0f60206eb34bc..e02b23c81733de 100644 --- a/.github/workflows/tests.yaml +++ b/.github/workflows/tests.yaml @@ -28,7 +28,7 @@ concurrency: env: CHIP_NO_LOG_TIMESTAMPS: true - + jobs: test_suites_linux: name: Test Suites - Linux @@ -477,6 +477,7 @@ jobs: scripts/run_in_python_env.sh out/venv './scripts/tests/run_python_test.py --script "src/python_testing/TC_TIMESYNC_2_12.py" --app out/linux-x64-all-clusters-ipv6only-no-ble-no-wifi-tsan-clang-test/chip-all-clusters-app --factoryreset --app-args "--discriminator 1234 --KVS kvs1 --trace-to json:out/trace_data/app-{SCRIPT_BASE_NAME}.json" --script-args "--storage-path admin_storage.json --commissioning-method on-network --discriminator 1234 --passcode 20202021 --PICS src/app/tests/suites/certification/ci-pics-values --trace-to json:out/trace_data/test-{SCRIPT_BASE_NAME}.json --trace-to perfetto:out/trace_data/test-{SCRIPT_BASE_NAME}.perfetto"' scripts/run_in_python_env.sh out/venv './scripts/tests/run_python_test.py --script "src/python_testing/TC_TIMESYNC_2_13.py" --app out/linux-x64-all-clusters-ipv6only-no-ble-no-wifi-tsan-clang-test/chip-all-clusters-app --factoryreset --app-args "--discriminator 1234 --KVS kvs1 --trace-to json:out/trace_data/app-{SCRIPT_BASE_NAME}.json" --script-args "--storage-path admin_storage.json --commissioning-method on-network --discriminator 1234 --passcode 20202021 --PICS src/app/tests/suites/certification/ci-pics-values --trace-to json:out/trace_data/test-{SCRIPT_BASE_NAME}.json --trace-to perfetto:out/trace_data/test-{SCRIPT_BASE_NAME}.perfetto"' scripts/run_in_python_env.sh out/venv './scripts/tests/run_python_test.py --script "src/python_testing/TC_TIMESYNC_3_1.py" --app out/linux-x64-all-clusters-ipv6only-no-ble-no-wifi-tsan-clang-test/chip-all-clusters-app --factoryreset --app-args "--discriminator 1234 --KVS kvs1 --trace-to json:out/trace_data/app-{SCRIPT_BASE_NAME}.json" --script-args "--storage-path admin_storage.json --commissioning-method on-network --discriminator 1234 --passcode 20202021 --trace-to json:out/trace_data/test-{SCRIPT_BASE_NAME}.json --trace-to perfetto:out/trace_data/test-{SCRIPT_BASE_NAME}.perfetto"' + scripts/run_in_python_env.sh out/venv './scripts/tests/run_python_test.py --script "src/python_testing/TC_DGGEN_2_4.py" --app out/linux-x64-all-clusters-ipv6only-no-ble-no-wifi-tsan-clang-test/chip-all-clusters-app --factoryreset --app-args "--discriminator 1234 --KVS kvs1 --trace-to json:out/trace_data/app-{SCRIPT_BASE_NAME}.json" --script-args "--storage-path admin_storage.json --commissioning-method on-network --discriminator 1234 --passcode 20202021 --trace-to json:out/trace_data/test-{SCRIPT_BASE_NAME}.json --trace-to perfetto:out/trace_data/test-{SCRIPT_BASE_NAME}.perfetto"' scripts/run_in_python_env.sh out/venv './scripts/tests/run_python_test.py --app out/linux-x64-lit-icd-ipv6only-no-ble-no-wifi-tsan-clang-test/lit-icd-app --factoryreset --app-args "--discriminator 1234 --KVS kvs1 --trace-to json:out/trace_data/app-{SCRIPT_BASE_NAME}.json" --script "src/python_testing/TC_ICDM_2_1.py" --script-args "--storage-path admin_storage.json --commissioning-method on-network --discriminator 1234 --passcode 20202021 --PICS src/app/tests/suites/certification/ci-pics-values --trace-to json:out/trace_data/test-{SCRIPT_BASE_NAME}.json --trace-to perfetto:out/trace_data/test-{SCRIPT_BASE_NAME}.perfetto"' scripts/run_in_python_env.sh out/venv './scripts/tests/run_python_test.py --app out/linux-x64-all-clusters-ipv6only-no-ble-no-wifi-tsan-clang-test/chip-all-clusters-app --factoryreset --app-args "--discriminator 1234 --KVS kvs1 --trace-to json:out/trace_data/app-{SCRIPT_BASE_NAME}.json" --script "src/python_testing/TC_DA_1_5.py" --script-args "--storage-path admin_storage.json --commissioning-method on-network --discriminator 1234 --passcode 20202021 --PICS src/app/tests/suites/certification/ci-pics-values --trace-to json:out/trace_data/test-{SCRIPT_BASE_NAME}.json --trace-to perfetto:out/trace_data/test-{SCRIPT_BASE_NAME}.perfetto"' scripts/run_in_python_env.sh out/venv './scripts/tests/run_python_test.py --app out/linux-x64-all-clusters-ipv6only-no-ble-no-wifi-tsan-clang-test/chip-all-clusters-app --factoryreset --app-args "--discriminator 1234 --KVS kvs1 --trace-to json:out/trace_data/app-{SCRIPT_BASE_NAME}.json" --script "src/python_testing/TC_IDM_1_2.py" --script-args "--storage-path admin_storage.json --commissioning-method on-network --discriminator 1234 --passcode 20202021 --trace-to json:out/trace_data/test-{SCRIPT_BASE_NAME}.json --trace-to perfetto:out/trace_data/test-{SCRIPT_BASE_NAME}.perfetto"' diff --git a/src/app/clusters/general-diagnostics-server/general-diagnostics-server.cpp b/src/app/clusters/general-diagnostics-server/general-diagnostics-server.cpp index 108cc0b7d7357f..ba71b049938f8c 100644 --- a/src/app/clusters/general-diagnostics-server/general-diagnostics-server.cpp +++ b/src/app/clusters/general-diagnostics-server/general-diagnostics-server.cpp @@ -16,6 +16,13 @@ */ #include "general-diagnostics-server.h" + +#ifdef ZCL_USING_TIME_SYNCHRONIZATION_CLUSTER_SERVER +// Need the `nogncheck` because it's inter-cluster dependency and this +// breaks GN deps checks since that doesn't know how to deal with #ifdef'd includes :(. +#include "app/clusters/time-synchronization-server/time-synchronization-server.h" // nogncheck +#endif // ZCL_USING_TIME_SYNCHRONIZATION_CLUSTER_SERVER + #include "app/server/Server.h" #include #include @@ -192,7 +199,9 @@ CHIP_ERROR GeneralDiagosticsAttrAccess::Read(const ConcreteReadAttributePath & a return ReadIfSupported(&DiagnosticDataProvider::GetRebootCount, aEncoder); } case UpTime::Id: { - return ReadIfSupported(&DiagnosticDataProvider::GetUpTime, aEncoder); + System::Clock::Seconds64 system_time_seconds = + std::chrono::duration_cast(Server::GetInstance().TimeSinceInit()); + return aEncoder.Encode(static_cast(system_time_seconds.count())); } case TotalOperationalHours::Id: { return ReadIfSupported(&DiagnosticDataProvider::GetTotalOperationalHours, aEncoder); @@ -385,9 +394,54 @@ bool emberAfGeneralDiagnosticsClusterTestEventTriggerCallback(CommandHandler * c bool emberAfGeneralDiagnosticsClusterTimeSnapshotCallback(CommandHandler * commandObj, ConcreteCommandPath const & commandPath, Commands::TimeSnapshot::DecodableType const & commandData) { - // TODO(#30096): Command needs to be implemented. - ChipLogError(Zcl, "TimeSnapshot not yet supported!"); - commandObj->AddStatus(commandPath, Status::InvalidCommand); + ChipLogError(Zcl, "Received TimeSnapshot command!"); + + Commands::TimeSnapshotResponse::Type response; + + System::Clock::Microseconds64 posix_time_us{ 0 }; + +#ifdef ZCL_USING_TIME_SYNCHRONIZATION_CLUSTER_SERVER + bool time_is_synced = false; + using Clusters::TimeSynchronization::GranularityEnum; + GranularityEnum granularity = Clusters::TimeSynchronization::TimeSynchronizationServer::Instance().GetGranularity(); + switch (granularity) + { + case GranularityEnum::kUnknownEnumValue: + case GranularityEnum::kNoTimeGranularity: + time_is_synced = false; + break; + case GranularityEnum::kMinutesGranularity: + // Minute granularity is not deemed good enough for TimeSnapshot to report PosixTimeMs, by spec. + time_is_synced = false; + break; + case GranularityEnum::kSecondsGranularity: + case GranularityEnum::kMillisecondsGranularity: + case GranularityEnum::kMicrosecondsGranularity: + time_is_synced = true; + break; + } + + if (time_is_synced) + { + CHIP_ERROR posix_time_err = System::SystemClock().GetClock_RealTime(posix_time_us); + if (posix_time_err != CHIP_NO_ERROR) + { + ChipLogError(Zcl, "Failed to get POSIX real time: %" CHIP_ERROR_FORMAT, posix_time_err.Format()); + posix_time_us = System::Clock::Microseconds64{ 0 }; + } + } +#endif // ZCL_USING_TIME_SYNCHRONIZATION_CLUSTER_SERVER + + System::Clock::Milliseconds64 system_time_ms = + std::chrono::duration_cast(Server::GetInstance().TimeSinceInit()); + + response.systemTimeMs = static_cast(system_time_ms.count()); + if (posix_time_us.count() != 0) + { + response.posixTimeMs.SetNonNull( + static_cast(std::chrono::duration_cast(posix_time_us).count())); + } + commandObj->AddResponse(commandPath, response); return true; } diff --git a/src/python_testing/TC_DGGEN_2_4.py b/src/python_testing/TC_DGGEN_2_4.py new file mode 100644 index 00000000000000..b2f599323b5f9f --- /dev/null +++ b/src/python_testing/TC_DGGEN_2_4.py @@ -0,0 +1,192 @@ +# +# Copyright (c) 2023 Project CHIP Authors +# All rights reserved. +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. +# + +import asyncio +import logging + +import chip.clusters as Clusters +from chip.clusters.Types import NullValue +from chip.interaction_model import InteractionModelError +from matter_testing_support import (MatterBaseTest, async_test_body, default_matter_test_main, matter_epoch_us_from_utc_datetime, + utc_datetime_from_matter_epoch_us, utc_datetime_from_posix_time_ms) +from mobly import asserts + +logger = logging.getLogger(__name__) + + +class TC_DGGEN_2_4(MatterBaseTest): + async def read_diags_attribute_expect_success(self, attribute): + cluster = Clusters.Objects.GeneralDiagnostics + return await self.read_single_attribute_check_success(endpoint=0, cluster=cluster, attribute=attribute) + + async def read_timesync_attribute_expect_success(self, attribute): + cluster = Clusters.Objects.TimeSynchronization + return await self.read_single_attribute_check_success(endpoint=0, cluster=cluster, attribute=attribute) + + async def set_time_in_timesync(self, current_time: int): + endpoint = 0 + time_cluster = Clusters.Objects.TimeSynchronization + code = 0 + + try: + await self.send_single_cmd(cmd=time_cluster.Commands.SetUTCTime(UTCTime=current_time, granularity=time_cluster.Enums.GranularityEnum.kSecondsGranularity), endpoint=endpoint) + except InteractionModelError as e: + # The python layer discards the cluster specific portion of the status IB, so for now we just expect a generic FAILURE error + # see #26521 + code = e.status + + asserts.assert_true(code in [0, 1], "Unexpected error while trying to set the UTCTime") + + async def send_time_snapshot_expect_success(self): + endpoint = 0 + diags_cluster = Clusters.Objects.GeneralDiagnostics + code = 0 + + try: + response = await self.send_single_cmd(cmd=diags_cluster.Commands.TimeSnapshot(), endpoint=endpoint) + except InteractionModelError as e: + code = e.status + + asserts.assert_equal(code, 0, "Expected success of TimeSnapshot.") + return response + + @async_test_body + async def test_TC_GEN_2_4(self): + self.print_step(1, "Detect Time Synchronization UTCTime attribute presence") + + root_descriptor = await self.default_controller.ReadAttribute(self.dut_node_id, [(0, Clusters.Descriptor)]) + root_server_list = root_descriptor[0][Clusters.Descriptor][Clusters.Descriptor.Attributes.ServerList] + has_timesync = (Clusters.TimeSynchronization.id in root_server_list) + + testvar_TimeSyncSupported = False + + if has_timesync: + ts_attributes = await self.read_single_attribute(self.default_controller, node_id=self.dut_node_id, endpoint=0, attribute=Clusters.TimeSynchronization.Attributes.AttributeList) + has_utc_time = (Clusters.TimeSynchronization.Attributes.UTCTime.attribute_id in ts_attributes) + + if has_utc_time: + testvar_TimeSyncSupported = True + + self.print_step(2, "Read UpTime attribute, save as UpTime1") + testvar_UpTime1 = await self.read_diags_attribute_expect_success(Clusters.GeneralDiagnostics.Attributes.UpTime) + asserts.assert_greater(testvar_UpTime1, 0, "UpTime1 must be > 0") + + # Step 3 (Time Sync supported) + if testvar_TimeSyncSupported: + self.print_step(3, "Functional verifications when Time Synchronization is supported") + + self.print_step("3a", "Write current time to DUT") + # Get current time in the correct format to set via command. + th_utc = matter_epoch_us_from_utc_datetime(desired_datetime=None) + + await self.set_time_in_timesync(th_utc) + + self.print_step("3b", "Read current time from DUT") + testvar_UTCTime1 = await self.read_timesync_attribute_expect_success(Clusters.TimeSynchronization.Attributes.UTCTime) + asserts.assert_true(testvar_UTCTime1 != NullValue, "UTCTime1 readback must not be null") + + self.print_step("3c", "Wait for 1 second") + await asyncio.sleep(1) + + self.print_step("3d", "Send a first TimeSnapshot command and verify") + response = await self.send_time_snapshot_expect_success() + logging.info(f"Step 3d: {response}") + + # Verify that the DUT sends a TimeSnapshotResponse with the following conditions met: + # - Value of PosixTimeMs field is not null. + # - Value of (SystemTimeMs field / 1000) is greater than or equal to UpTime1 + # - PosixTimeMs field converted to a UTC timestamp is greater than or equal to UTCTime1 converted to a UTC timestamp. + # + # On success of prior verifications: + # - Save the value of the SystemTimeMs field as SystemTimeMs1. + # - Save the value of the PosixTimeMs field as PosixTimeMs1. + asserts.assert_true(response.posixTimeMs != NullValue, "PosixTimeMs field of TimeSnapshotResponse must not be null") + asserts.assert_greater_equal(response.systemTimeMs // 1000, testvar_UpTime1, + "System time in milliseconds must be >= UpTime1") + + utc_from_posix = utc_datetime_from_posix_time_ms(posix_time_ms=response.posixTimeMs) + utc_from_utctime1 = utc_datetime_from_matter_epoch_us(testvar_UTCTime1) + + asserts.assert_greater_equal( + utc_from_posix, utc_from_utctime1, "PosixTimeMs field converted to a UTC timestamp must be >= than UTCTime1 converted to a UTC timestamp") + + testvar_SystemTimeMs1 = response.systemTimeMs + testvar_PosixTimeMs1 = response.posixTimeMs + + self.print_step("3e", "Wait for 1 second") + await asyncio.sleep(1) + + self.print_step("3f", "Send a second TimeSnapshot command and verify") + + response = await self.send_time_snapshot_expect_success() + logging.info(f"Step 3f: {response}") + + # Verify that the DUT sends a TimeSnapshotResponse with the following fields: + # - Value of PosixTimeMs field is not null and greater than PosixTimeMs1. + # - Value of SystemTimeMs field is greater than SystemTimeMs1. + + asserts.assert_true(response.posixTimeMs != NullValue, "PosixTimeMs field of TimeSnapshotResponse must not be null") + asserts.assert_greater(response.posixTimeMs, testvar_PosixTimeMs1, + "POSIX time in milliseconds must be > PosixTimeMs1") + asserts.assert_greater(response.systemTimeMs, testvar_SystemTimeMs1, + "System time in milliseconds must be > SystemTimeMs1") + + self.print_step(4, "Skipped: Functional verifications when Time Synchronization is NOT supported") + + # Step 4 (Time Sync not supported) + else: # if not testvar_TimeSyncSupported: + self.print_step(3, "Skipped: Functional verifications when Time Synchronization is supported") + + self.print_step(4, "Functional verifications when Time Synchronization is NOT supported") + + self.print_step("4a", "Send a first TimeSnapshot command and verify") + response = await self.send_time_snapshot_expect_success() + logging.info(f"Step 4a: {response}") + + # Verify that the DUT sends a TimeSnapshotResponse with the following fields: + # - Value of PosixTimeMs field is null. + # - Value of (SystemTimeMs field / 1000) is greater than UpTime1. + # + # On success of prior verifications, save the value of SystemTimeMs field as SystemTimeMs1. + + asserts.assert_true(response.posixTimeMs == NullValue, "PosixTimeMs field of TimeSnapshotResponse must be null") + asserts.assert_greater_equal(response.systemTimeMs // 1000, testvar_UpTime1, + "System time in milliseconds must be >= UpTime1") + + testvar_SystemTimeMs1 = response.systemTimeMs + + self.print_step("4b", "Wait for 1 second") + await asyncio.sleep(1) + + self.print_step("4c", "Send a second TimeSnapshot command and verify") + + response = await self.send_time_snapshot_expect_success() + logging.info(f"Step 4c: {response}") + + # Verify that the DUT sends a TimeSnapshotResponse with the following fields: + # - Value of PosixTimeMs field is null. + # - Value of SystemTimeMs field is greater than SystemTimeMs1. + # + # On success of prior verifications, save the value of SystemTimeMs field as SystemTimeMs1. + + asserts.assert_true(response.posixTimeMs == NullValue, "PosixTimeMs field of TimeSnapshotResponse must be null") + asserts.assert_greater(response.systemTimeMs, testvar_SystemTimeMs1, + "System time in milliseconds must be > SystemTimeMs1") + + +if __name__ == "__main__": + default_matter_test_main() diff --git a/src/python_testing/TC_TIMESYNC_2_2.py b/src/python_testing/TC_TIMESYNC_2_2.py index 7e63708f358a59..f364c4443b3390 100644 --- a/src/python_testing/TC_TIMESYNC_2_2.py +++ b/src/python_testing/TC_TIMESYNC_2_2.py @@ -43,9 +43,10 @@ async def test_TC_TIMESYNC_2_2(self): self.print_step(2, "Read UTCTime attribute") utc_dut_initial = await self.read_ts_attribute_expect_success(endpoint=endpoint, attribute=attributes.UTCTime) th_utc = utc_time_in_matter_epoch() + + code = 0 try: await self.send_single_cmd(cmd=time_cluster.Commands.SetUTCTime(UTCTime=th_utc, granularity=time_cluster.Enums.GranularityEnum.kMillisecondsGranularity), endpoint=endpoint) - code = 0 except InteractionModelError as e: # The python layer discards the cluster specific portion of the status IB, so for now we just expect a generic FAILURE error # see #26521 diff --git a/src/python_testing/matter_testing_support.py b/src/python_testing/matter_testing_support.py index a0109ea8a2f7f7..b0a3450f47a496 100644 --- a/src/python_testing/matter_testing_support.py +++ b/src/python_testing/matter_testing_support.py @@ -21,7 +21,6 @@ import inspect import json import logging -import math import os import pathlib import queue @@ -183,8 +182,10 @@ def type_matches(received_value, desired_type): else: return isinstance(received_value, desired_type) +# TODO(#31177): Need to add unit tests for all time conversion methods. -def utc_time_in_matter_epoch(desired_datetime: datetime = None): + +def utc_time_in_matter_epoch(desired_datetime: Optional[datetime] = None): """ Returns the time in matter epoch in us. If desired_datetime is None, it will return the current time. @@ -199,19 +200,36 @@ def utc_time_in_matter_epoch(desired_datetime: datetime = None): return utc_th_us +matter_epoch_us_from_utc_datetime = utc_time_in_matter_epoch + + +def utc_datetime_from_matter_epoch_us(matter_epoch_us: int) -> datetime: + """Returns the given Matter epoch time as a usable Python datetime in UTC.""" + delta_from_epoch = timedelta(microseconds=matter_epoch_us) + matter_epoch = datetime(2000, 1, 1, 0, 0, 0, 0, timezone.utc) + + return matter_epoch + delta_from_epoch + + +def utc_datetime_from_posix_time_ms(posix_time_ms: int) -> datetime: + millis = posix_time_ms % 1000 + seconds = posix_time_ms // 1000 + return datetime.fromtimestamp(seconds, timezone.utc) + timedelta(milliseconds=millis) + + def compare_time(received: int, offset: timedelta = timedelta(), utc: int = None, tolerance: timedelta = timedelta(seconds=5)) -> None: if utc is None: utc = utc_time_in_matter_epoch() # total seconds includes fractional for microseconds - expected = utc + offset.total_seconds()*1000000 + expected = utc + offset.total_seconds() * 1000000 delta_us = abs(expected - received) delta = timedelta(microseconds=delta_us) asserts.assert_less_equal(delta, tolerance, "Received time is out of tolerance") def get_wait_seconds_from_set_time(set_time_matter_us: int, wait_seconds: int): - seconds_passed = math.floor((utc_time_in_matter_epoch() - set_time_matter_us)/1000000) + seconds_passed = (utc_time_in_matter_epoch() - set_time_matter_us) // 1000000 return wait_seconds - seconds_passed