[ICD] Add ICDM 5.1 Automated Test Script (#34817)

* Add ICDM 5.1 Automated Test Script

* fix restyle

* Restyled by prettier-json

* Restyled by isort

* Increase discovery timeout

* Set log to true to debug CI

* Update tests.yaml

* Increase discovery timeout

* Update manualTests.json

* debugging TC_ICDM_5_1.py

* dump ufw for mdns discovery in ci

* Apply fixes for style and dnssd logic

* Remove some debug code

* Undo ufw change

* One more readability update now that I update this file

* Better error message on service not found

* A few more updates for logging and logic when to unlock events

* Restyle

---------

Co-authored-by: Restyled.io <commits@restyled.io>
Co-authored-by: yunhanw-google <yunhanw@google.com>
Co-authored-by: cjandhyala <68604034+cjandhyala@users.noreply.github.com>
Co-authored-by: Andrei Litvin <andreilitvin@google.com>
Co-authored-by: Andrei Litvin <andy314@gmail.com>

Author: 6 people

src/app/tests/suites/certification/Test_TC_ICDM_5_1.yaml

@@ -117,7 +117,7 @@
     "GeneralCommissioning": ["Test_TC_CGEN_2_2"],
     "GeneralDiagnostics": ["Test_TC_DGGEN_2_2"],
     "Identify": ["Test_TC_I_3_2"],
-    "IcdManagement": ["Test_TC_ICDM_4_1", "Test_TC_ICDM_5_1"],
+    "IcdManagement": [],
     "IlluminanceMeasurement": [],
     "InteractionDataModel": [
         "Test_TC_IDM_1_1",

src/app/tests/suites/manualTests.json

@@ -0,0 +1,197 @@
+#
+#    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.
+#
+
+# See https://github.com/project-chip/connectedhomeip/blob/master/docs/testing/python.md#defining-the-ci-test-arguments
+# for details about the block below.
+#
+# === BEGIN CI TEST ARGUMENTS ===
+# test-runner-runs: run1
+# test-runner-run/run1/app: ${LIT_ICD_APP}
+# test-runner-run/run1/factoryreset: True
+# test-runner-run/run1/quiet: True
+# test-runner-run/run1/app-args: --discriminator 1234 --KVS kvs1 --trace-to json:${TRACE_APP}.json
+# test-runner-run/run1/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:${TRACE_TEST_JSON}.json --trace-to perfetto:${TRACE_TEST_PERFETTO}.perfetto
+# === END CI TEST ARGUMENTS ===
+
+import logging
+from dataclasses import dataclass
+
+import chip.clusters as Clusters
+from chip.interaction_model import InteractionModelError, Status
+from matter_testing_support import MatterBaseTest, TestStep, async_test_body, default_matter_test_main
+from mdns_discovery import mdns_discovery
+from mobly import asserts
+
+Cluster = Clusters.Objects.IcdManagement
+Commands = Cluster.Commands
+Attributes = Cluster.Attributes
+OperatingModeEnum = Cluster.Enums.OperatingModeEnum
+ClientTypeEnum = Cluster.Enums.ClientTypeEnum
+
+
+@dataclass
+class Client:
+    checkInNodeID: int
+    subjectId: int
+    key: bytes
+    clientType: ClientTypeEnum
+
+
+logger = logging.getLogger(__name__)
+kRootEndpointId = 0
+
+client1 = Client(
+    checkInNodeID=1,
+    subjectId=1,
+    key=bytes([x for x in range(0x10, 0x20)]),
+    clientType=ClientTypeEnum.kEphemeral
+)
+
+
+class TC_ICDM_5_1(MatterBaseTest):
+
+    #
+    # Class Helper functions
+    #
+
+    async def _read_icdm_attribute_expect_success(self, attribute) -> OperatingModeEnum:
+        return await self.read_single_attribute_check_success(endpoint=kRootEndpointId, cluster=Cluster, attribute=attribute)
+
+    async def _send_single_icdm_command(self, command):
+        return await self.send_single_cmd(command, endpoint=kRootEndpointId)
+
+    async def _get_icd_txt_record(self) -> OperatingModeEnum:
+        discovery = mdns_discovery.MdnsDiscovery(verbose_logging=True)
+        service = await discovery.get_operational_service(
+            node_id=self.dut_node_id,
+            compressed_fabric_id=self.default_controller.GetCompressedFabricId(),
+            log_output=True, discovery_timeout_sec=240)
+
+        asserts.assert_is_not_none(
+            service, f"Failed to get operational node service information for {self.dut_node_id} on {self.default_controller.GetCompressedFabricId()}")
+
+        icdTxtRecord = OperatingModeEnum(int(service.txt_record['ICD']))
+        if icdTxtRecord.value != int(service.txt_record['ICD']):
+            raise AttributeError(f'Not a known ICD type: {service.txt_record["ICD"]}')
+
+        return icdTxtRecord
+
+    #
+    # Test Harness Helpers
+    #
+
+    def desc_TC_ICDM_5_1(self) -> str:
+        """Returns a description of this test"""
+        return "[TC-ICDM-5.1] Operating Mode with DUT as Server"
+
+    def steps_TC_ICDM_5_1(self) -> list[TestStep]:
+        steps = [
+            TestStep(0, "Commissioning, already done", is_commissioning=True),
+            TestStep(1, "TH reads from the DUT the RegisteredClients attribute"),
+            TestStep("2a", "TH reads from the DUT the OperatingMode attribute."),
+            TestStep("2b", "Verify that the ICD DNS-SD TXT key is present."),
+            TestStep("3a", "TH sends RegisterClient command."),
+            TestStep("3b", "TH reads from the DUT the OperatingMode attribute."),
+            TestStep("3c", "Verify that mDNS is advertising ICD key."),
+            TestStep(4, "TH sends UnregisterClient command with CheckInNodeID1."),
+            TestStep("5a", "TH reads from the DUT the OperatingMode attribute."),
+            TestStep("5b", "Verify that the ICD DNS-SD TXT key is present."),
+        ]
+        return steps
+
+    def pics_TC_ICDM_5_1(self) -> list[str]:
+        """ This function returns a list of PICS for this test case that must be True for the test to be run"""
+        pics = [
+            "ICDM.S",
+            "ICDM.S.F02",
+        ]
+        return pics
+
+    #
+    # ICDM 5.1 Test Body
+    #
+
+    @async_test_body
+    async def test_TC_ICDM_5_1(self):
+
+        # Commissioning
+        self.step(0)
+
+        try:
+            self.step(1)
+            registeredClients = await self._read_icdm_attribute_expect_success(
+                Attributes.RegisteredClients)
+
+            for client in registeredClients:
+                try:
+                    await self._send_single_icdm_command(Commands.UnregisterClient(checkInNodeID=client.checkInNodeID))
+                except InteractionModelError as e:
+                    asserts.assert_equal(
+                        e.status, Status.Success, "Unexpected error returned")
+
+            self.step("2a")
+            operatingMode = await self._read_icdm_attribute_expect_success(Attributes.OperatingMode)
+            asserts.assert_equal(operatingMode, OperatingModeEnum.kSit)
+
+            self.step("2b")
+            icdTxtRecord = await self._get_icd_txt_record()
+            asserts.assert_equal(icdTxtRecord, OperatingModeEnum.kSit, "OperatingMode Is not in SIT mode.")
+
+            self.step("3a")
+            try:
+                await self._send_single_icdm_command(Commands.RegisterClient(checkInNodeID=client1.checkInNodeID, monitoredSubject=client1.subjectId, key=client1.key, clientType=client1.clientType))
+            except InteractionModelError as e:
+                asserts.assert_equal(
+                    e.status, Status.Success, "Unexpected error returned")
+
+            self.step("3b")
+            operatingMode = await self._read_icdm_attribute_expect_success(Attributes.OperatingMode)
+            asserts.assert_equal(operatingMode, OperatingModeEnum.kLit)
+
+            self.step("3c")
+            icdTxtRecord = await self._get_icd_txt_record()
+            asserts.assert_equal(icdTxtRecord, OperatingModeEnum.kLit, "OperatingMode Is not in Lit mode.")
+
+            self.step(4)
+            try:
+                await self._send_single_icdm_command(Commands.UnregisterClient(checkInNodeID=client1.checkInNodeID))
+            except InteractionModelError as e:
+                asserts.assert_equal(
+                    e.status, Status.Success, "Unexpected error returned")
+
+            self.step("5a")
+            operatingMode = await self._read_icdm_attribute_expect_success(Attributes.OperatingMode)
+            asserts.assert_equal(operatingMode, OperatingModeEnum.kSit)
+
+            self.step("5b")
+            icdTxtRecord = await self._get_icd_txt_record()
+            asserts.assert_equal(icdTxtRecord, OperatingModeEnum.kSit, "OperatingMode Is not in SIT mode.")
+
+        finally:
+            registeredClients = await self._read_icdm_attribute_expect_success(
+                Attributes.RegisteredClients)
+
+            for client in registeredClients:
+                try:
+                    await self._send_single_icdm_command(Commands.UnregisterClient(checkInNodeID=client.checkInNodeID))
+                except InteractionModelError as e:
+                    asserts.assert_equal(
+                        e.status, Status.Success, "Unexpected error returned")
+
+
+if __name__ == "__main__":
+    default_matter_test_main()

src/python_testing/TC_ICDM_5_1.py

@@ -18,13 +18,16 @@
 
 import asyncio
 import json
+import logging
 from dataclasses import asdict, dataclass
 from enum import Enum
 from typing import Dict, List, Optional
 
 from zeroconf import IPVersion, ServiceStateChange, Zeroconf
 from zeroconf.asyncio import AsyncServiceBrowser, AsyncServiceInfo, AsyncZeroconfServiceTypes
 
+logger = logging.getLogger(__name__)
+
 
 @dataclass
 class MdnsServiceInfo:
@@ -79,7 +82,7 @@ class MdnsDiscovery:
 
     DISCOVERY_TIMEOUT_SEC = 15
 
-    def __init__(self):
+    def __init__(self, verbose_logging: bool = False):
         """
         Initializes the MdnsDiscovery instance.
 
@@ -99,9 +102,15 @@ def __init__(self):
         # A list of service types
         self._service_types = []
 
+        # Filtering to apply for received data items
+        self._name_filter = None
+
         # An asyncio Event to signal when a service has been discovered
         self._event = asyncio.Event()
 
+        # Verbose logging
+        self._verbose_logging = verbose_logging
+
     # Public methods
     async def get_commissioner_service(self, log_output: bool = False,
                                        discovery_timeout_sec: float = DISCOVERY_TIMEOUT_SEC
@@ -116,6 +125,7 @@ async def get_commissioner_service(self, log_output: bool = False,
         Returns:
             Optional[MdnsServiceInfo]: An instance of MdnsServiceInfo or None if timeout reached.
         """
+        self._name_filter = None
         return await self._get_service(MdnsServiceType.COMMISSIONER, log_output, discovery_timeout_sec)
 
     async def get_commissionable_service(self, log_output: bool = False,
@@ -131,10 +141,12 @@ async def get_commissionable_service(self, log_output: bool = False,
         Returns:
             Optional[MdnsServiceInfo]: An instance of MdnsServiceInfo or None if timeout reached.
         """
+        self._name_filter = None
         return await self._get_service(MdnsServiceType.COMMISSIONABLE, log_output, discovery_timeout_sec)
 
-    async def get_operational_service(self, service_name: str = None,
-                                      service_type: str = None,
+    async def get_operational_service(self,
+                                      node_id: Optional[int] = None,
+                                      compressed_fabric_id: Optional[int] = None,
                                       discovery_timeout_sec: float = DISCOVERY_TIMEOUT_SEC,
                                       log_output: bool = False
                                       ) -> Optional[MdnsServiceInfo]:
@@ -144,35 +156,16 @@ async def get_operational_service(self, service_name: str = None,
         Args:
             log_output (bool): Logs the discovered services to the console. Defaults to False.
             discovery_timeout_sec (float): Defaults to 15 seconds.
-            service_name (str): The unique name of the mDNS service. Defaults to None.
-            service_type (str): The service type of the service. Defaults to None.
+            node_id: the node id to create the service name from 
+            compressed_fabric_id: the fabric id to create the service name from 
 
         Returns:
             Optional[MdnsServiceInfo]: An instance of MdnsServiceInfo or None if timeout reached.
         """
         # Validation to ensure both or none of the parameters are provided
-        if (service_name is None) != (service_type is None):
-            raise ValueError("Both service_name and service_type must be provided together or not at all.")
-
-        mdns_service_info = None
-
-        if service_name is None and service_type is None:
-            mdns_service_info = await self._get_service(MdnsServiceType.OPERATIONAL, log_output, discovery_timeout_sec)
-        else:
-            print(f"Looking for MDNS service type '{service_type}',  service name '{service_name}'")
 
-            # Get service info
-            service_info = AsyncServiceInfo(service_type, service_name)
-            is_discovered = await service_info.async_request(self._zc, 3000)
-            if is_discovered:
-                mdns_service_info = self._to_mdns_service_info_class(service_info)
-            self._discovered_services = {}
-            self._discovered_services[service_type] = [mdns_service_info]
-
-            if log_output:
-                self._log_output()
-
-        return mdns_service_info
+        self._name_filter = f'{compressed_fabric_id:016x}-{node_id:016x}.{MdnsServiceType.OPERATIONAL.value}'.upper()
+        return await self._get_service(MdnsServiceType.OPERATIONAL, log_output, discovery_timeout_sec)
 
     async def get_border_router_service(self, log_output: bool = False,
                                         discovery_timeout_sec: float = DISCOVERY_TIMEOUT_SEC
@@ -237,7 +230,7 @@ async def _discover(self,
         if all_services:
             self._service_types = list(await AsyncZeroconfServiceTypes.async_find())
 
-        print(f"Browsing for MDNS service(s) of type: {self._service_types}")
+        logger.info(f"Browsing for MDNS service(s) of type: {self._service_types}")
 
         aiobrowser = AsyncServiceBrowser(zeroconf=self._zc,
                                          type_=self._service_types,
@@ -247,7 +240,7 @@ async def _discover(self,
         try:
             await asyncio.wait_for(self._event.wait(), timeout=discovery_timeout_sec)
         except asyncio.TimeoutError:
-            print(f"MDNS service discovery timed out after {discovery_timeout_sec} seconds.")
+            logger.error("MDNS service discovery timed out after %d seconds.", discovery_timeout_sec)
         finally:
             await aiobrowser.async_cancel()
 
@@ -276,13 +269,25 @@ def _on_service_state_change(
         Returns:
             None: This method does not return any value.
         """
-        if state_change.value == ServiceStateChange.Added.value:
-            self._event.set()
-            asyncio.ensure_future(self._query_service_info(
-                zeroconf,
-                service_type,
-                name)
-            )
+        if self._verbose_logging:
+            logger.info("Service state change: %s on %s/%s", state_change, name, service_type)
+
+        if state_change.value == ServiceStateChange.Removed.value:
+            return
+
+        if self._name_filter is not None and name.upper() != self._name_filter:
+            if self._verbose_logging:
+                logger.info("   Name does NOT match %s", self._name_filter)
+            return
+
+        if self._verbose_logging:
+            logger.info("Received service data. Unlocking service information")
+
+        asyncio.ensure_future(self._query_service_info(
+            zeroconf,
+            service_type,
+            name)
+        )
 
     async def _query_service_info(self, zeroconf: Zeroconf, service_type: str, service_name: str) -> None:
         """
@@ -304,12 +309,19 @@ async def _query_service_info(self, zeroconf: Zeroconf, service_type: str, servi
         service_info.async_clear_cache()
 
         if is_service_discovered:
+            if self._verbose_logging:
+                logger.warning("Service discovered for %s/%s.", service_name, service_type)
+
             mdns_service_info = self._to_mdns_service_info_class(service_info)
 
             if service_type not in self._discovered_services:
                 self._discovered_services[service_type] = [mdns_service_info]
             else:
                 self._discovered_services[service_type].append(mdns_service_info)
+        elif self._verbose_logging:
+            logger.warning("Service information not found.")
+
+        self._event.set()
 
     def _to_mdns_service_info_class(self, service_info: AsyncServiceInfo) -> MdnsServiceInfo:
         """
@@ -355,21 +367,24 @@ async def _get_service(self, service_type: MdnsServiceType,
                                     any. Returns None if no service of the specified type is discovered within
                                     the timeout period.
         """
-        mdns_service_info = None
         self._service_types = [service_type.value]
         await self._discover(discovery_timeout_sec, log_output)
-        if service_type.value in self._discovered_services:
-            mdns_service_info = self._discovered_services[service_type.value][0]
 
-        return mdns_service_info
+        if self._verbose_logging:
+            logger.info("Getting service from discovered services: %s", self._discovered_services)
+
+        if service_type.value in self._discovered_services:
+            return self._discovered_services[service_type.value][0]
+        else:
+            return None
 
     def _log_output(self) -> str:
         """
-        Converts the discovered services to a JSON string and prints it.
+        Converts the discovered services to a JSON string and log it.
 
         The method is intended to be used for debugging or informational purposes, providing a clear and
         comprehensive view of all services discovered during the mDNS service discovery process.
         """
         converted_services = {key: [asdict(item) for item in value] for key, value in self._discovered_services.items()}
         json_str = json.dumps(converted_services, indent=4)
-        print(json_str)
+        logger.info("Discovery data:\n%s", json_str)