From bae394d2770afbeaa971335483d60f5b80f9c3d2 Mon Sep 17 00:00:00 2001
From: maziggy <mz@v8w.de>
Date: Wed, 25 Mar 2026 13:21:27 +0100
Subject: [PATCH]   Add debug logging to NTAG write/verify path

  Temporary diagnostics to identify which step of the NTAG write
  fails: per-page ACK status, reactivation, read-back, or data
  mismatch. Enable DEBUG level for pn5180 module.
---
 spoolbuddy/daemon/main.py   |  1 +
 spoolbuddy/daemon/pn5180.py | 23 +++++++++++++++++++++--
 2 files changed, 22 insertions(+), 2 deletions(-)

diff --git a/spoolbuddy/daemon/main.py b/spoolbuddy/daemon/main.py
index d98710c96..1a64d1c00 100644
--- a/spoolbuddy/daemon/main.py
+++ b/spoolbuddy/daemon/main.py
@@ -23,6 +23,7 @@ logging.basicConfig(
     datefmt="%H:%M:%S",
 )
 logger = logging.getLogger("spoolbuddy")
+logging.getLogger("daemon.pn5180").setLevel(logging.DEBUG)
 
 
 def _spoolbuddy_env_path() -> Path:
diff --git a/spoolbuddy/daemon/pn5180.py b/spoolbuddy/daemon/pn5180.py
index bdbd793ad..206b8c5ae 100644
--- a/spoolbuddy/daemon/pn5180.py
+++ b/spoolbuddy/daemon/pn5180.py
@@ -498,10 +498,15 @@ class PN5180:
         rx_status = self.read_reg(0x13)
         rx_bytes = rx_status & 0x1FF
         rx_bits = (rx_status >> 9) & 0x1FF
+        logger.debug(
+            "NTAG write page %d: rx_status=0x%08X, rx_bytes=%d, rx_bits=%d", page, rx_status, rx_bytes, rx_bits
+        )
         if rx_bytes == 0 and rx_bits == 0:
+            logger.warning("NTAG write page %d: no ACK received", page)
             return False
 
         ack = self.read_data(1)
+        logger.debug("NTAG write page %d: ACK byte=0x%02X", page, ack[0])
         return ack[0] == 0x0A
 
     def ntag_write_pages(self, start_page: int, data: bytes) -> bool:
@@ -516,25 +521,39 @@ class PN5180:
             padded.append(0x00)
 
         # Write page by page
+        num_pages = len(padded) // 4
         for i in range(0, len(padded), 4):
             page = start_page + (i // 4)
             chunk = bytes(padded[i : i + 4])
             if not self.ntag_write_page(page, chunk):
+                logger.warning("NTAG write failed at page %d (of %d pages)", page, num_pages)
                 return False
             time.sleep(0.002)
 
+        logger.info("NTAG write complete (%d pages), verifying...", num_pages)
+
         # Reactivate card for verification read
         result = self.reactivate_card()
         if result is None:
+            logger.warning("NTAG verify: reactivate_card() failed")
             return False
 
         # Read back and verify
-        num_pages = len(padded) // 4
         readback = self.ntag_read_pages(start_page, num_pages)
         if readback is None:
+            logger.warning("NTAG verify: ntag_read_pages() returned None")
             return False
 
-        return readback[: len(data)] == data
+        if readback[: len(data)] != data:
+            logger.warning(
+                "NTAG verify: data mismatch (wrote %d bytes, read back %d bytes, first diff at byte %d)",
+                len(data),
+                len(readback),
+                next((i for i in range(min(len(data), len(readback))) if readback[i] != data[i]), -1),
+            )
+            return False
+
+        return True
 
     def read_ntag(self, uid: bytes) -> bytes | None:
         """Read NTAG pages 4-20 (NDEF data area, 68 bytes). No auth needed.