fix(iroh-dns-server): Backwards compatibility for packets stored with iroh-dns-server v0.34 or lower (#3295)

## Description

#3186 introduced a backwards-incompatible change to the iroh-dns-server
database that went uncaught so far.
The serialization format for SignedPackets changed between pkarr v2 and
pkarr v3: pkarr v3 prepends a `last_seen` timestamp (8 bytes) to the
serialized representation of a SignedPacket. Therefore, parsing packets
stored in the the database with pkarr v2 (iroh-dns-server v0.34 and
lower) fails with an error. The error also stops the store actor, and
thus all subsequent requests will fail as well.

This PR changes this by attempting to parse the packet in the pkarr v2
format if parsing as pkarr v3 packet fails. Parsing as pkarr v2 is
achieved by prepending 8 zero bytes to the payload (an empty last_seen
timestamp).

The PR also improves the tracing logging at various places.

## Breaking Changes

<!-- Optional, if there are any breaking changes document them,
including how to migrate older code. -->

## Notes & open questions

There's no test yet. I tested manually by launching iroh-dns-server
v0.34, inserting some packets with the `publish` example. When
restarting the server from `main`, retrieving packets leads to errors.
When applying this PR, retrieving the old packets work.

If we want / need a test, how should we do it? We can either add a dev
dependency to `[email protected]` (which would recursively pull in
all of `[email protected]`), or somehow insert a packet as it would be created
by `[email protected]` manually into the database. Not sure if it's
worth it, but maybe it is?

## Change checklist
<!-- Remove any that are not relevant. -->
- [x] Self-review.
- [x] Documentation updates following the [style
guide](https://rust-lang.github.io/rfcs/1574-more-api-documentation-conventions.html#appendix-a-full-conventions-text),
if relevant.
- [ ] Tests if relevant.

Author: Frando

iroh-dns-server/src/store.rs

@@ -7,7 +7,7 @@ use hickory_server::proto::rr::{Name, RecordSet, RecordType, RrKey};
 use lru::LruCache;
 use pkarr::{Client as PkarrClient, SignedPacket};
 use tokio::sync::Mutex;
-use tracing::{debug, trace};
+use tracing::{debug, trace, warn};
 use ttl_cache::TtlCache;
 
 use self::signed_packets::SignedPacketStore;
@@ -92,24 +92,46 @@ impl ZoneStore {
     }
 
     /// Resolve a DNS query.
-    #[allow(clippy::unused_async)]
+    #[tracing::instrument("resolve", skip_all, fields(pubkey=%pubkey,name=%name,typ=%record_type))]
     pub async fn resolve(
         &self,
         pubkey: &PublicKeyBytes,
         name: &Name,
         record_type: RecordType,
     ) -> Result<Option<Arc<RecordSet>>> {
-        tracing::info!("{} {}", name, record_type);
+        trace!("store resolve");
         if let Some(rset) = self.cache.lock().await.resolve(pubkey, name, record_type) {
+            debug!(
+                len = rset.records_without_rrsigs().count(),
+                "resolved from cache"
+            );
             return Ok(Some(rset));
         }
 
         if let Some(packet) = self.store.get(pubkey).await? {
-            return self
+            trace!(packet_timestamp = ?packet.timestamp(), "store hit");
+            return match self
                 .cache
                 .lock()
                 .await
-                .insert_and_resolve(&packet, name, record_type);
+                .insert_and_resolve(&packet, name, record_type)
+            {
+                Ok(Some(rset)) => {
+                    debug!(
+                        len = rset.records_without_rrsigs().count(),
+                        "resolved from store"
+                    );
+                    Ok(Some(rset))
+                }
+                Ok(None) => {
+                    debug!("resolved to zone, but no matching records in zone");
+                    Ok(None)
+                }
+                Err(err) => {
+                    warn!("failed to retrieve zone after inserting in cache: {err:#?}");
+                    Err(err)
+                }
+            };
         };
 
         if let Some(pkarr) = self.pkarr.as_ref() {
@@ -226,11 +248,14 @@ impl ZoneCache {
             .map(|old| old.is_newer_than(signed_packet))
             .unwrap_or(false)
         {
-            return Ok(());
+            trace!("insert skip: cached is newer");
+            Ok(())
+        } else {
+            self.cache
+                .put(pubkey, CachedZone::from_signed_packet(signed_packet)?);
+            trace!("inserted into cache");
+            Ok(())
         }
-        self.cache
-            .put(pubkey, CachedZone::from_signed_packet(signed_packet)?);
-        Ok(())
     }
 
     fn remove(&mut self, pubkey: &PublicKeyBytes) {
@@ -260,10 +285,8 @@ impl CachedZone {
     }
 
     fn resolve(&self, name: &Name, record_type: RecordType) -> Option<Arc<RecordSet>> {
+        trace!(name=%name, typ=%record_type, "resolve in zone");
         let key = RrKey::new(name.into(), record_type);
-        for record in self.records.keys() {
-            tracing::info!("record {:?}", record);
-        }
         self.records.get(&key).cloned()
     }
 }

iroh-dns-server/src/store/signed_packets.rs

@@ -7,7 +7,7 @@ use redb::{
 };
 use tokio::sync::{mpsc, oneshot};
 use tokio_util::sync::CancellationToken;
-use tracing::{debug, error, info, trace};
+use tracing::{debug, error, info, trace, warn};
 
 use crate::{metrics::Metrics, util::PublicKeyBytes};
 
@@ -132,9 +132,16 @@ impl Actor {
                     Some(msg) = self.recv.recv() => {
                         match msg {
                             Message::Get { key, res } => {
-                                trace!("get {}", key);
-                                let packet = get_packet(&tables.signed_packets, &key).context("get packet failed")?;
-                                res.send(packet).ok();
+                                match get_packet(&tables.signed_packets, &key) {
+                                    Ok(packet) => {
+                                        trace!("get {key}: {}", packet.is_some());
+                                        res.send(packet).ok();
+                                    },
+                                    Err(err) => {
+                                        warn!("get {key} failed: {err:#}");
+                                        return Err(err).with_context(|| format!("get packet for {key} failed"))
+                                    }
+                                }
                             }
                             Message::Upsert { packet, res } => {
                                 let key = PublicKeyBytes::from_signed_packet(&packet);
@@ -317,8 +324,23 @@ fn get_packet(
     let Some(row) = table.get(key.as_ref()).context("database fetch failed")? else {
         return Ok(None);
     };
-    let packet = SignedPacket::deserialize(row.value()).context("parsing signed packet failed")?;
-    Ok(Some(packet))
+    match SignedPacket::deserialize(row.value()) {
+        Ok(packet) => Ok(Some(packet)),
+        Err(err) => {
+            // Prior to iroh-dns-server v0.35, we stored packets in the default `SignedPacket::as_bytes` serialization from pkarr v2,
+            // which did not include the `last_seen` timestamp added as a prefix in `SignedPacket::serialize` from pkarr v3.
+            // If decoding the packet as a serialized pkarr v3 packet fails, we assume it was stored with iroh-dns-server before v0.35,
+            // and prepend an empty timestamp.
+            let data = row.value();
+            let mut buf = Vec::with_capacity(data.len() + 8);
+            buf.extend(&[0u8; 8]);
+            buf.extend(data);
+            match SignedPacket::deserialize(&buf) {
+                Ok(packet) => Ok(Some(packet)),
+                Err(err2) => Err(anyhow::anyhow!("Failed to decode as pkarr v3: {err:#}. Also failed to decode as pkarr v2: {err2:#}"))
+            }
+        }
+    }
 }
 
 async fn evict_task(send: mpsc::Sender<Message>, options: Options, cancel: CancellationToken) {

iroh/src/discovery/pkarr.rs

@@ -392,10 +392,15 @@ impl PkarrRelayClient {
             .send()
             .await?;
 
-        if !response.status().is_success() {
+        let status = response.status();
+        if !status.is_success() {
+            let text = if let Ok(text) = response.text().await {
+                text
+            } else {
+                "(no details provided)".to_string()
+            };
             bail!(format!(
-                "Publish request failed with status {}",
-                response.status()
+                "Publish request failed with status {status}: {text}",
             ))
         }