Repository: XKNX/xknx (python)

Issue:
Unhandled management telegram warnings in HA log
**Description of problem:**

When programming a device from ETS and using the "Physikalische Adresse & Applikationsprogram" button, I receive these warnings in my HA log:

```plain
2023-02-21 13:27:30.393 WARNING (MainThread) [xknx.management] Unhandled management telegram: Telegram(destination_address=0/0/0, direction=TelegramDirection.INCOMING, payload=<IndividualAddressRead />, source_address=1.0.1, tpci=TDataBroadcast())
2023-02-21 13:27:30.396 WARNING (MainThread) [xknx.management] Unhandled management telegram: Telegram(destination_address=0/0/0, direction=TelegramDirection.INCOMING, payload=<IndividualAddressRead />, source_address=1.0.1, tpci=TDataBroadcast())
2023-02-21 13:27:33.398 WARNING (MainThread) [xknx.management] Unhandled management telegram: Telegram(destination_address=0/0/0, direction=TelegramDirection.INCOMING, payload=<IndividualAddressRead />, source_address=1.0.1, tpci=TDataBroadcast())
2023-02-21 13:27:33.401 WARNING (MainThread) [xknx.management] Unhandled management telegram: Telegram(destination_address=0/0/0, direction=TelegramDirection.INCOMING, payload=<IndividualAddressRead />, source_address=1.0.1, tpci=TDataBroadcast())
2023-02-21 13:27:36.409 WARNING (MainThread) [xknx.management] Unhandled management telegram: Telegram(destination_address=0/0/0, direction=TelegramDirection.INCOMING, payload=<IndividualAddressRead />, source_address=1.0.1, tpci=TDataBroadcast())
2023-02-21 13:27:36.412 WARNING (MainThread) [xknx.management] Unhandled management telegram: Telegram(destination_address=0/0/0, direction=TelegramDirection.INCOMING, payload=<IndividualAddressRead />, source_address=1.0.1, tpci=TDataBroadcast())
2023-02-21 13:27:39.420 WARNING (MainThread) [xknx.management] Unhandled management telegram: Telegram(destination_address=0/0/0, direction=TelegramDirection.INCOMING, payload=<IndividualAddressRead />, source_address=1.0.1, tpci=TDataBroadcast())
2023-02-21 13:27:39.423 WARNING (MainThread) [xknx.management] Unhandled management telegram: Telegram(destination_address=0/0/0, direction=TelegramDirection.INCOMING, payload=<IndividualAddressRead />, source_address=1.0.1, tpci=TDataBroadcast())
2023-02-21 13:27:42.431 WARNING (MainThread) [xknx.management] Unhandled management telegram: Telegram(destination_address=0/0/0, direction=TelegramDirection.INCOMING, payload=<IndividualAddressRead />, source_address=1.0.1, tpci=TDataBroadcast())
2023-02-21 13:27:42.434 WARNING (MainThread) [xknx.management] Unhandled management telegram: Telegram(destination_address=0/0/0, direction=TelegramDirection.INCOMING, payload=<IndividualAddressRead />, source_address=1.0.1, tpci=TDataBroadcast())
2023-02-21 13:27:45.443 WARNING (MainThread) [xknx.management] Unhandled management telegram: Telegram(destination_address=0/0/0, direction=TelegramDirection.INCOMING, payload=<IndividualAddressRead />, source_address=1.0.1, tpci=TDataBroadcast())
2023-02-21 13:27:45.446 WARNING (MainThread) [xknx.management] Unhandled management telegram: Telegram(destination_address=0/0/0, direction=TelegramDirection.INCOMING, payload=<IndividualAddressRead />, source_address=1.0.1, tpci=TDataBroadcast())
2023-02-21 13:27:48.454 WARNING (MainThread) [xknx.management] Unhandled management telegram: Telegram(destination_address=0/0/0, direction=TelegramDirection.INCOMING, payload=<IndividualAddressRead />, source_address=1.0.1, tpci=TDataBroadcast())
2023-02-21 13:27:48.457 WARNING (MainThread) [xknx.management] Unhandled management telegram: Telegram(destination_address=0/0/0, direction=TelegramDirection.INCOMING, payload=<IndividualAddressRead />, source_address=1.0.1, tpci=TDataBroadcast())
2023-02-21 13:27:51.467 WARNING (MainThread) [xknx.management] Unhandled management telegram: Telegram(destination_address=0/0/0, direction=TelegramDirection.INCOMING, payload=<IndividualAddressRead />, source_address=1.0.1, tpci=TDataBroadcast())
2023-02-21 13:27:51.469 WARNING (MainThread) [xknx.management] Unhandled management telegram: Telegram(destination_address=0/0/0, direction=TelegramDirection.INCOMING, payload=<IndividualAddressRead />, source_address=1.0.1, tpci=TDataBroadcast())
2023-02-21 13:27:51.515 WARNING (MainThread) [xknx.management] Unhandled management telegram: Telegram(destination_address=0/0/0, direction=TelegramDirection.INCOMING, payload=<IndividualAddressResponse />, source_address=1.0.5, tpci=TDataBroadcast())
2023-02-21 13:27:51.518 WARNING (MainThread) [xknx.management] Unhandled management telegram: Telegram(destination_address=0/0/0, direction=TelegramDirection.INCOMING, payload=<IndividualAddressResponse />, source_address=1.0.5, tpci=TDataBroadcast())
2023-02-21 13:27:54.852 WARNING (MainThread) [xknx.management] Unhandled management telegram: Telegram(destination_address=0/0/0, direction=TelegramDirection.INCOMING, payload=<IndividualAddressRead />, source_address=1.0.1, tpci=TDataBroadcast())
2023-02-21 13:27:54.854 WARNING (MainThread) [xknx.management] Unhandled management telegram: Telegram(destination_address=0/0/0, direction=TelegramDirection.INCOMING, payload=<IndividualAddressRead />, source_address=1.0.1, tpci=TDataBroadcast())

```

I don't think they should be there

- [ ] using xknx standalone
- [x] using Home-Assistant knx integration

**Version information:**
- xknx / Home-Assistant release with the issue: 2023.2.1 (I know .5 exists but according to the changelog, no xknx updates are in these releases)
- last working xknx / Home-Assistant release (if known): N/A

**KNX installation:**
<!--
Please provide details about your installation.
- Manufacturer and model of relevant actors, sensors or interfaces.
- if you have access to ETS:
  - provide relevant group address parameters (DPT, Flags)
  - if applicable: excerpt of bus monitor output
-->

1.0.1 is the tunnel address ETS used
1.0.5 is a MDT BE-16000.02


**Problem-relevant `configuration.yaml` entries (fill out even if it seems unimportant):**

**Diagnostic data of the config entry (only when Home Assistant is used)**

[config_entry-knx-45c5f69670ca8326b6d870984a44f938.json.txt](https://github.com/XKNX/xknx/files/10793589/config_entry-knx-45c5f69670ca8326b6d870984a44f938.json.txt)

**Traceback (if applicable):**


Pull request description:
Lower log levels for unsupported Telegrams
<!--
  You are awesome! Thanks for contributing to our project!
  Please, DO NOT DELETE ANY TEXT from this template!.
-->
## Description
<!--
Please include a summary of the change and which issue is fixed.
Please also include relevant motivation and context.
List any dependencies that are required for this change.
-->


Fixes #1203

## Type of change
<!--
Please tick the applicable options.
NOTE: Ticking multiple options most likely indicates
that your change is to big and it is suggested to split it into several smaller PRs.
-->

- [ ] Bug fix (non-breaking change which fixes an issue)
- [ ] New feature (non-breaking change which adds functionality)
- [ ] Breaking change (fix or feature that would cause existing functionality to not work as expected)
- [x] Code quality improvements to existing code or addition of tests

## Checklist

- [ ] The documentation has been adjusted accordingly
- [ ] Tests have been added that prove the fix is effective or that the feature works
- [x] The changes are documented in the changelog (docs/changelog.md)

Patch:
diff --git a/docs/changelog.md b/docs/changelog.md
index 1277fa0c..5ba70d87 100644
--- a/docs/changelog.md
+++ b/docs/changelog.md
@@ -12,6 +12,10 @@ nav_order: 2
 
 - When `ConnectionConfig.individual_address` is set and a Keyring is given `ConnectionType.AUTOMATIC` will try to connect to the host of this address. If not found (in keyfile or discovery) it will raise.
 
+### Internals
+
+- Lower log levels for unsupported Telegrams and add more information.
+
 # 2.5.0 Request IA 2023-02-14
 
 ### Connection
diff --git a/xknx/cemi/cemi_frame.py b/xknx/cemi/cemi_frame.py
index 2f6795f4..f6592636 100644
--- a/xknx/cemi/cemi_frame.py
+++ b/xknx/cemi/cemi_frame.py
@@ -155,7 +155,8 @@ class CEMIFrame:
         _apdu = bytes([_tpdu[0] & 0b11]) + _tpdu[1:]  # clear TPCI bits
         if len(_apdu) != (_npdu_len + 1):  # TCPI octet not included in NPDU length
             raise UnsupportedCEMIMessage(
-                f"APDU LEN should be {_npdu_len} but is {len(_apdu) - 1} in CEMI: {cemi.hex()}"
+                f"APDU LEN should be {_npdu_len} but is {len(_apdu) - 1} "
+                f"from {src_addr} in CEMI: {cemi.hex()}"
             )
 
         # TPCI (transport layer control information)
@@ -170,13 +171,15 @@ class CEMIFrame:
             )
         except ConversionError as err:
             raise UnsupportedCEMIMessage(
-                f"TPCI not supported: {_tpdu[0]:#10b}"
+                f"TPCI not supported: {_tpdu[0]:#10b} "
+                f"from {src_addr} in CEMI: {cemi.hex()}"
             ) from err
 
         if tpci.control:
             if _npdu_len:
                 raise UnsupportedCEMIMessage(
                     f"Invalid length for control TPDU {tpci}: {_npdu_len}"
+                    f" from {src_addr} in CEMI: {cemi.hex()}"
                 )
             return CEMIFrame(
                 code=code,
@@ -190,7 +193,10 @@ class CEMIFrame:
         try:
             payload = APCI.from_knx(_apdu)
         except ConversionError as err:
-            raise UnsupportedCEMIMessage("APDU not supported") from err
+            raise UnsupportedCEMIMessage(
+                f"APDU not supported from {src_addr} "
+                f"from {src_addr} in CEMI: {cemi.hex()}"
+            ) from err
 
         return CEMIFrame(
             code=code,
diff --git a/xknx/cemi/cemi_handler.py b/xknx/cemi/cemi_handler.py
index 71ca7623..b3e37969 100644
--- a/xknx/cemi/cemi_handler.py
+++ b/xknx/cemi/cemi_handler.py
@@ -98,7 +98,11 @@ class CEMIHandler:
             try:
                 cemi = self.data_secure.received_cemi(cemi=cemi)
             except DataSecureError as err:
-                data_secure_logger.warning("Could not decrypt CEMI frame: %s", err)
+                data_secure_logger.log(
+                    err.log_level,
+                    "Could not decrypt CEMI frame: %s",
+                    err,
+                )
                 return
         # TODO: remove telegram init from CEMIFrame class and move it here?
         telegram = cemi.telegram
diff --git a/xknx/exceptions/exception.py b/xknx/exceptions/exception.py
index 87a09cb1..35080e4b 100644
--- a/xknx/exceptions/exception.py
+++ b/xknx/exceptions/exception.py
@@ -1,6 +1,7 @@
 """Module for XKXN Exceptions."""
 from __future__ import annotations
 
+import logging
 from typing import Any
 
 
@@ -158,6 +159,11 @@ class DeviceIllegalValue(XKNXException):
 class DataSecureError(XKNXException):
     """Exception class for KNX Data Secure handling."""
 
+    def __init__(self, message: str, log_level: int = logging.WARNING) -> None:
+        """Instantiate exception."""
+        super().__init__(message)
+        self.log_level = log_level
+
 
 class SecureException(XKNXException):
     """Exception class for IP secure handling."""
diff --git a/xknx/io/routing.py b/xknx/io/routing.py
index 6d2a0ab5..bf8dd7a1 100644
--- a/xknx/io/routing.py
+++ b/xknx/io/routing.py
@@ -260,7 +260,7 @@ class Routing(Interface):
         try:
             cemi = CEMIFrame.from_knx(routing_indication.raw_cemi)
         except UnsupportedCEMIMessage as unsupported_cemi_err:
-            logger.warning("CEMI not supported: %s", unsupported_cemi_err)
+            logger.info("CEMI not supported: %s", unsupported_cemi_err)
             return
         if cemi.src_addr == self.individual_address:
             logger.debug("Ignoring own packet %s", cemi)
diff --git a/xknx/io/tunnel.py b/xknx/io/tunnel.py
index 83e98841..1739da36 100644
--- a/xknx/io/tunnel.py
+++ b/xknx/io/tunnel.py
@@ -316,7 +316,7 @@ class _Tunnel(Interface):
         try:
             cemi = CEMIFrame.from_knx(tunneling_request.raw_cemi)
         except UnsupportedCEMIMessage as unsupported_cemi_err:
-            logger.warning("CEMI not supported: %s", unsupported_cemi_err)
+            logger.info("CEMI not supported: %s", unsupported_cemi_err)
             return
         self.cemi_received_callback(cemi)
 
diff --git a/xknx/management/management.py b/xknx/management/management.py
index dc237762..43c125e3 100644
--- a/xknx/management/management.py
+++ b/xknx/management/management.py
@@ -64,7 +64,7 @@ class Management:
                 self.xknx.cemi_handler.send_telegram(disconnect)
             )
             return
-        logger.warning("Unhandled management telegram: %r", telegram)
+        logger.debug("Unhandled management telegram: %r", telegram)
         return
 
     async def connect(self, address: IndividualAddress) -> P2PConnection:
@@ -244,7 +244,7 @@ class P2PConnection:
             await self.xknx.cemi_handler.send_telegram(telegram)
             ack = await asyncio.wait_for(self._ack_waiter, MANAGAMENT_ACK_TIMEOUT)
         except asyncio.TimeoutError:
-            logger.debug(
+            logger.info(
                 "%s: timeout while waiting for ACK. Resending Telegram.", self.address
             )
             # resend once after 3 seconds without ACK
diff --git a/xknx/secure/data_secure.py b/xknx/secure/data_secure.py
index 2b723b5a..ac44b0c0 100644
--- a/xknx/secure/data_secure.py
+++ b/xknx/secure/data_secure.py
@@ -114,13 +114,15 @@ class DataSecure:
             last_valid_sequence_number = self._individual_address_table[source_address]
         except KeyError:
             raise DataSecureError(
-                f"Source address not found in Security Individual Address Table: {source_address}"
+                f"Source address not found in Security Individual Address Table: {source_address}",
+                log_level=logging.INFO,
             )
         if not received_sequence_number > last_valid_sequence_number:
             # TODO: implement and increment Security Failure Log counter (not when equal)
             raise DataSecureError(
                 f"Sequence number too low for {source_address}: "
-                f"{received_sequence_number} received, {last_valid_sequence_number} last valid"
+                f"{received_sequence_number} received, {last_valid_sequence_number} last valid",
+                log_level=logging.WARNING,
             )
 
         yield
@@ -136,7 +138,8 @@ class DataSecure:
         if isinstance(cemi.dst_addr, GroupAddress):
             if cemi.dst_addr in self._group_key_table:
                 raise DataSecureError(
-                    f"Discarding frame with plain APDU for secure group address: {cemi}"
+                    f"Discarding frame with plain APDU for secure group address: {cemi}",
+                    log_level=logging.WARNING,
                 )
             return cemi
         # Plain point-to-point frame
@@ -148,25 +151,31 @@ class DataSecure:
     def _received_secure_cemi(self, cemi: CEMIFrame, s_apdu: SecureAPDU) -> CEMIFrame:
         """Handle received secured CEMI frame."""
         if s_apdu.scf.service is not SecurityALService.S_A_DATA:
-            raise DataSecureError(f"Only SecurityALService.S_A_DATA supported {cemi}")
+            raise DataSecureError(
+                f"Only SecurityALService.S_A_DATA supported {cemi}",
+                log_level=logging.DEBUG,
+            )
         if s_apdu.scf.system_broadcast or s_apdu.scf.tool_access:
             # TODO: handle incoming responses with tool key of sending device
             # when we can send with tool key
             raise DataSecureError(
-                f"System broadcast and tool access not supported {cemi}"
+                f"System broadcast and tool access not supported {cemi}",
+                log_level=logging.DEBUG,
             )
 
         # Secure group communication frame
         if isinstance(cemi.dst_addr, GroupAddress):
             if not (key := self._group_key_table.get(cemi.dst_addr)):
                 raise DataSecureError(
-                    f"No key found for group address {cemi.dst_addr} from {cemi.src_addr}"
+                    f"No key found for group address {cemi.dst_addr} from {cemi.src_addr}",
+                    log_level=logging.INFO,
                 )
         # Secure point-to-point frame
         else:
             # TODO: maybe possible to implement this over tool key
             raise DataSecureError(
-                f"Secure Point-to-Point communication not supported {cemi}"
+                f"Secure Point-to-Point communication not supported {cemi}",
+                log_level=logging.DEBUG,
             )
 
         with self.check_sequence_number(


Test patch:
diff --git a/test/io_tests/routing_test.py b/test/io_tests/routing_test.py
index 9f404ca4..eadb84ea 100644
--- a/test/io_tests/routing_test.py
+++ b/test/io_tests/routing_test.py
@@ -64,7 +64,7 @@ class TestRouting:
         ]
         await asyncio.sleep(0)  # await local L_Data.con
 
-    @patch("logging.Logger.warning")
+    @patch("logging.Logger.info")
     async def test_routing_indication_received_apci_unsupported(self, logging_mock):
         """Test Tunnel sending ACK for unsupported frames."""
         routing = Routing(