Improve log message when receiving an invalid or corrupt packet

bdraco · bdraco · commit eb84c8e8d9df · 2021-09-22T23:07:41.000-05:00
- The choked wording makes it seems like there is a problem in zeroconf when
  the usual case was an invalid packet send or corrupt wire data.
diff --git a/tests/test_protocol.py b/tests/test_protocol.py
@@ -822,16 +822,18 @@ def test_dns_compression_invalid_skips_bad_name_compress_in_question():
     assert len(parsed.questions) == 4
 
 
-def test_dns_compression_all_invalid():
+def test_dns_compression_all_invalid(caplog):
     """Test our wire parser can skip all invalid data."""
     packet = (
         b'\x00\x00\x84\x00\x00\x00\x00\x01\x00\x00\x00\x00!roborock-vacuum-s5e_miio416'
         b'112328\x00\x00/\x80\x01\x00\x00\x00x\x00\t\xc0P\x00\x05@\x00\x00\x00\x00'
     )
-    parsed = r.DNSIncoming(packet)
+    parsed = r.DNSIncoming(packet, ("2.4.5.4", 5353))
     assert len(parsed.questions) == 0
     assert len(parsed.answers) == 0
 
+    assert " Unable to parse; skipping record" in caplog.text
+
 
 def test_invalid_next_name_ignored():
     """Test our wire parser does not throw an an invalid next name.
@@ -918,15 +920,16 @@ def test_dns_compression_points_beyond_packet():
     assert len(parsed.answers) == 1
 
 
-def test_dns_compression_generic_failure():
+def test_dns_compression_generic_failure(caplog):
     """Test our wire parser does not loop forever when dns compression is corrupt."""
     packet = (
         b'\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x02\x06domain\x05local\x00\x00\x01'
         b'\x80\x01\x00\x00\x00\x01\x00\x04\xc0\xa8\xd0\x05-\x0c\x00\x01\x80\x01\x00\x00'
         b'\x00\x01\x00\x04\xc0\xa8\xd0\x06'
     )
-    parsed = r.DNSIncoming(packet)
+    parsed = r.DNSIncoming(packet, ("1.2.3.4", 5353))
     assert len(parsed.answers) == 1
+    assert "Received invalid packet from ('1.2.3.4', 5353)" in caplog.text
 
 
 def test_label_length_attack():
diff --git a/zeroconf/_core.py b/zeroconf/_core.py
@@ -274,7 +274,7 @@ def datagram_received(
             )
             return
 
-        msg = DNSIncoming(data, scope, now)
+        msg = DNSIncoming(data, (addr, port), scope, now)
         if msg.valid:
             log.debug(
                 'Received from %r:%r [socket %s]: %r (%d bytes) as [%r]',
diff --git a/zeroconf/_protocol/incoming.py b/zeroconf/_protocol/incoming.py
@@ -21,7 +21,7 @@
 """
 
 import struct
-from typing import Callable, Dict, List, Optional, Set, cast
+from typing import Callable, Dict, List, Optional, Set, Tuple, cast
 
 from . import DNSMessage
 from .._dns import DNSAddress, DNSHinfo, DNSNsec, DNSPointer, DNSQuestion, DNSRecord, DNSService, DNSText
@@ -67,9 +67,16 @@ class DNSIncoming(DNSMessage, QuietLogger):
         'valid',
         'now',
         'scope_id',
+        'source',
     )
 
-    def __init__(self, data: bytes, scope_id: Optional[int] = None, now: Optional[float] = None) -> None:
+    def __init__(
+        self,
+        data: bytes,
+        source: Optional[Tuple[str, int]] = None,
+        scope_id: Optional[int] = None,
+        now: Optional[float] = None,
+    ) -> None:
         """Constructor from string holding bytes of packet"""
         super().__init__(0)
         self.offset = 0
@@ -86,6 +93,7 @@ def __init__(self, data: bytes, scope_id: Optional[int] = None, now: Optional[fl
         self.valid = False
         self._read_others = False
         self.now = now or current_time_millis()
+        self.source = source
         self.scope_id = scope_id
         self._parse_data(self._initial_parse)
 
@@ -102,7 +110,12 @@ def _parse_data(self, parser_call: Callable) -> None:
         try:
             parser_call()
         except DECODE_EXCEPTIONS:
-            self.log_exception_warning('Choked at offset %d while unpacking %r', self.offset, self.data)
+            self.log_exception_warning(
+                'Received invalid packet from %s at offset %d while unpacking %r',
+                self.source,
+                self.offset,
+                self.data,
+            )
 
     @property
     def answers(self) -> List[DNSRecord]:

Original file line number	Diff line number	Diff line change
`@@ -274,7 +274,7 @@ def datagram_received(`
`274`	`274`	`)`
`275`	`275`	`return`
`276`	`276`
`277`		`- msg = DNSIncoming(data, scope, now)`
	`277`	`+ msg = DNSIncoming(data, (addr, port), scope, now)`
`278`	`278`	`if msg.valid:`
`279`	`279`	`log.debug(`
`280`	`280`	`'Received from %r:%r [socket %s]: %r (%d bytes) as [%r]',`