debugging

2026-05-13 23:03:15 +00:00 · 2026-02-11 23:18:33 +00:00
parent e00e9a77c2
commit 3958e066da
4 changed files with 68 additions and 5 deletions
@@ -90,6 +90,7 @@ export function encryptFileForUpload(source: Uint8Array, fileName: string): Encr
  const encSize = BigInt(chunkSizes.reduce((a, b) => a + b, 0))
  const encData = encryptFile(source, fileHdr, key, nonce, fileSize, encSize)
  const digest = sha512Streaming([encData])
+  console.log(`[AGENT-DBG] encrypt: encData.len=${encData.length} digest=${_dbgHex(digest, 64)} chunkSizes=[${chunkSizes.join(',')}]`)
  return {encData, digest, key, nonce, chunkSizes}
 }

@@ -124,6 +125,7 @@ export async function uploadFile(
    const rcvKp = generateEd25519KeyPair()
    const chunkData = await readChunk(spec.chunkOffset, spec.chunkSize)
    const chunkDigest = getChunkDigest(chunkData)
+    console.log(`[AGENT-DBG] upload chunk=${chunkNo} offset=${spec.chunkOffset} size=${spec.chunkSize} digest=${_dbgHex(chunkDigest, 32)} data[0..8]=${_dbgHex(chunkData)} data[-8..]=${_dbgHex(chunkData.slice(-8))}`)
    const fileInfo: FileInfo = {
      sndKey: encodePubKeyEd25519(sndKp.publicKey),
      size: spec.chunkSize,
@@ -261,7 +263,9 @@ export async function downloadFileRaw(
  const {onProgress, concurrency = 1} = options ?? {}
  // Resolve redirect on main thread (redirect data is small)
  if (fd.redirect !== null) {
+    console.log(`[AGENT-DBG] resolving redirect: outer size=${fd.size} chunks=${fd.chunks.length}`)
    fd = await resolveRedirect(agent, fd)
+    console.log(`[AGENT-DBG] resolved: size=${fd.size} chunks=${fd.chunks.length} digest=${Array.from(fd.digest.slice(0, 16)).map(x => x.toString(16).padStart(2, '0')).join('')}…`)
  }
  const resolvedFd = fd
  // Group chunks by server, sequential within each server, parallel across servers
@@ -280,6 +284,7 @@ export async function downloadFileRaw(
      const seed = decodePrivKeyEd25519(replica.replicaKey)
      const kp = ed25519KeyPairFromSeed(seed)
      const raw = await downloadXFTPChunkRaw(agent, server, kp.privateKey, replica.replicaId)
+      console.log(`[AGENT-DBG] chunk=${chunk.chunkNo} body.len=${raw.body.length} expectedChunkSize=${chunk.chunkSize} digest=${_dbgHex(chunk.digest, 32)} body.byteOffset=${raw.body.byteOffset} body.buffer.byteLength=${raw.body.buffer.byteLength}`)
      await onRawChunk({
        chunkNo: chunk.chunkNo,
        dhSecret: raw.dhSecret,
@@ -355,6 +360,10 @@ export async function deleteFile(agent: XFTPClientAgent, sndDescription: FileDes

 // -- Internal

+function _dbgHex(b: Uint8Array, n = 8): string {
+  return Array.from(b.slice(0, n)).map(x => x.toString(16).padStart(2, '0')).join('')
+}
+
 function digestEqual(a: Uint8Array, b: Uint8Array): boolean {
  if (a.length !== b.length) return false
  let diff = 0
@@ -307,12 +307,14 @@ async function sendXFTPCommandOnce(
  const block = encodeAuthTransmission(client.sessionId, corrId, entityId, cmdBytes, privateKey)
  const reqBody = chunkData ? concatBytes(block, chunkData) : block
  const fullResp = await client.transport.post(reqBody)
+  console.log(`[XFTP-DBG] sendOnce: fullResp.length=${fullResp.length} entityId=${_hex(entityId)} cmdTag=${cmdBytes[0]}`)
  if (fullResp.length < XFTP_BLOCK_SIZE) {
    console.error('[XFTP] Response too short: %d bytes (expected >= %d)', fullResp.length, XFTP_BLOCK_SIZE)
    throw new Error("Server response too short")
  }
  const respBlock = fullResp.subarray(0, XFTP_BLOCK_SIZE)
  const body = fullResp.subarray(XFTP_BLOCK_SIZE)
+  console.log(`[XFTP-DBG] sendOnce: body.length=${body.length} body.byteOffset=${body.byteOffset} body.buffer.byteLength=${body.buffer.byteLength}`)
  // Detect padded error strings (HANDSHAKE, SESSION) before decodeTransmission
  const raw = blockUnpad(respBlock)
  if (raw.length < 20) {
@@ -333,6 +335,10 @@ async function sendXFTPCommandOnce(
  return {response, body}
 }

+function _hex(b: Uint8Array, n = 8): string {
+  return Array.from(b.slice(0, n)).map(x => x.toString(16).padStart(2, '0')).join('')
+}
+
 // -- Send command (with retry + reconnect)

 export async function sendXFTPCommand(
@@ -348,8 +354,10 @@ export async function sendXFTPCommand(
  let client = await clientP
  for (let attempt = 1; attempt <= maxRetries; attempt++) {
    try {
+      if (attempt > 1) console.log(`[XFTP-DBG] sendCmd: retry attempt=${attempt}/${maxRetries}`)
      return await sendXFTPCommandOnce(client, privateKey, entityId, cmdBytes, chunkData)
    } catch (e) {
+      console.log(`[XFTP-DBG] sendCmd: attempt=${attempt} failed: ${e instanceof Error ? e.message : String(e)} retriable=${isRetriable(e)}`)
      if (!isRetriable(e)) {
        throw categorizeError(e)
      }
@@ -404,6 +412,7 @@ export async function downloadXFTPChunkRaw(
  const {response, body} = await sendXFTPCommand(agent, server, rpKey, fId, cmd)
  if (response.type !== "FRFile") throw new Error("unexpected response: " + response.type)
  const dhSecret = dh(response.rcvDhKey, privateKey)
+  console.log(`[XFTP-DBG] dlChunkRaw: body.length=${body.length} nonce=${_hex(response.nonce, 24)} dhSecret=${_hex(dhSecret)} body[0..8]=${_hex(body)} body[-8..]=${_hex(body.slice(-8))}`)
  return {dhSecret, nonce: response.nonce, body}
 }

@@ -88,6 +88,11 @@ class WorkerBackend implements CryptoBackend {
    const nonceCopy = new Uint8Array(nonce)
    const digestCopy = new Uint8Array(digest)
    const buf = this.toTransferable(body)
+    const hex = (b: Uint8Array | ArrayBuffer, n = 8) => {
+      const u = b instanceof ArrayBuffer ? new Uint8Array(b) : b
+      return Array.from(u.slice(0, n)).map(x => x.toString(16).padStart(2, '0')).join('')
+    }
+    console.log(`[BACKEND-DBG] chunk=${chunkNo} body.len=${body.length} body.byteOff=${body.byteOffset} buf.byteLen=${buf.byteLength} nonce=${hex(nonceCopy, 24)} dhSecret=${hex(dhSecretCopy)} digest=${hex(digestCopy, 32)} buf[0..8]=${hex(buf)} body[-8..]=${hex(body.slice(-8))}`)
    await this.send(
      {type: 'decryptAndStoreChunk', dhSecret: dhSecretCopy, nonce: nonceCopy, body: buf, chunkDigest: digestCopy, chunkNo},
      [buf]
@@ -52,6 +52,7 @@ async function handleEncrypt(id: number, data: ArrayBuffer, fileName: string) {
  self.postMessage({id, type: 'progress', done: 50, total: 100})

  const digest = sha512Streaming([encData])
+  console.log(`[WORKER-DBG] encrypt: encData.len=${encData.length} digest=${_whex(digest, 64)} chunkSizes=[${chunkSizes.join(',')}]`)

  self.postMessage({id, type: 'progress', done: 80, total: 100})

@@ -87,7 +88,9 @@ async function handleDecryptAndStore(
  body: ArrayBuffer, chunkDigest: Uint8Array, chunkNo: number
 ) {
  const bodyArr = new Uint8Array(body)
+  console.log(`[WORKER-DBG] store chunk=${chunkNo} body.len=${bodyArr.length} nonce=${_whex(nonce, 24)} dhSecret=${_whex(dhSecret)} digest=${_whex(chunkDigest, 32)} body[0..8]=${_whex(bodyArr)} body[-8..]=${_whex(bodyArr.slice(-8))}`)
  const decrypted = decryptReceivedChunk(dhSecret, nonce, bodyArr, chunkDigest)
+  console.log(`[WORKER-DBG] decrypted chunk=${chunkNo} len=${decrypted.length} [0..8]=${_whex(decrypted)} [-8..]=${_whex(decrypted.slice(-8))}`)

  if (!downloadWriteHandle) {
    const dir = await getSessionDir()
@@ -99,15 +102,24 @@ async function handleDecryptAndStore(
  currentDownloadOffset += decrypted.length
  chunkMeta.set(chunkNo, {offset, size: decrypted.length})
  const written = downloadWriteHandle.write(decrypted, {at: offset})
+  console.log(`[WORKER-DBG] OPFS write chunk=${chunkNo} offset=${offset} size=${decrypted.length} written=${written}`)
  if (written !== decrypted.length) throw new Error(`OPFS download write chunk ${chunkNo}: ${written}/${decrypted.length}`)
  downloadWriteHandle.flush()

+  // Verify: read back and compare first/last 8 bytes
+  const verifyBuf = new Uint8Array(Math.min(8, decrypted.length))
+  downloadWriteHandle.read(verifyBuf, {at: offset})
+  const verifyEnd = new Uint8Array(Math.min(8, decrypted.length))
+  downloadWriteHandle.read(verifyEnd, {at: offset + decrypted.length - verifyEnd.length})
+  console.log(`[WORKER-DBG] OPFS verify chunk=${chunkNo} readBack[0..8]=${_whex(verifyBuf)} readBack[-8..]=${_whex(verifyEnd)} expected[0..8]=${_whex(decrypted)} expected[-8..]=${_whex(decrypted.slice(-8))}`)
+
  self.postMessage({id, type: 'stored'})
 }

 async function handleVerifyAndDecrypt(
  id: number, size: number, digest: Uint8Array, key: Uint8Array, nonce: Uint8Array
 ) {
+  console.log(`[WORKER-DBG] verify: expectedSize=${size} expectedDigest=${_whex(digest, 64)} chunkMeta.size=${chunkMeta.size}`)
  // Close write handle, reopen as read
  if (downloadWriteHandle) {
    downloadWriteHandle.flush()
@@ -118,14 +130,17 @@ async function handleVerifyAndDecrypt(
  const dir = await getSessionDir()
  const fileHandle = await dir.getFileHandle('download.bin')
  const readHandle = await fileHandle.createSyncAccessHandle()
+  const fileSize = readHandle.getSize()
+  console.log(`[WORKER-DBG] verify: OPFS file size=${fileSize}`)

  // Read chunks ordered by chunkNo, verify size and SHA-512 digest (streaming)
  const sortedEntries = [...chunkMeta.entries()].sort((a, b) => a[0] - b[0])
  const chunks: Uint8Array[] = []
  let totalSize = 0
-  for (const [, meta] of sortedEntries) {
+  for (const [chunkNo, meta] of sortedEntries) {
    const buf = new Uint8Array(meta.size)
-    readHandle.read(buf, {at: meta.offset})
+    const bytesRead = readHandle.read(buf, {at: meta.offset})
+    console.log(`[WORKER-DBG] verify read chunk=${chunkNo} offset=${meta.offset} size=${meta.size} bytesRead=${bytesRead} [0..8]=${_whex(buf)} [-8..]=${_whex(buf.slice(-8))}`)
    chunks.push(buf)
    totalSize += meta.size
  }
@@ -136,13 +151,34 @@ async function handleVerifyAndDecrypt(
    return
  }

-  const actualDigest = sha512Streaming(chunks)
+  // Compute per-chunk SHA-512 incrementally to find divergence point
+  const state = sodium.crypto_hash_sha512_init()
+  for (let i = 0; i < chunks.length; i++) {
+    const chunk = chunks[i]
+    const SEG = 4 * 1024 * 1024
+    for (let off = 0; off < chunk.length; off += SEG) {
+      sodium.crypto_hash_sha512_update(state, chunk.subarray(off, Math.min(off + SEG, chunk.length)))
+    }
+  }
+  const actualDigest = sodium.crypto_hash_sha512_final(state)
  if (!digestEqual(actualDigest, digest)) {
-    const hex = (b: Uint8Array) => Array.from(b.slice(0, 16)).map(x => x.toString(16).padStart(2, '0')).join('')
-    console.error(`[WORKER] digest mismatch: expected=${hex(digest)}… actual=${hex(actualDigest)}… chunks=${chunks.length} totalSize=${totalSize}`)
+    console.error(`[WORKER-DBG] DIGEST MISMATCH: expected=${_whex(digest, 64)} actual=${_whex(actualDigest, 64)} chunks=${chunks.length} totalSize=${totalSize}`)
+    // Log per-chunk incremental hash to find divergence
+    const state2 = sodium.crypto_hash_sha512_init()
+    for (let i = 0; i < chunks.length; i++) {
+      const chunk = chunks[i]
+      const SEG = 4 * 1024 * 1024
+      for (let off = 0; off < chunk.length; off += SEG) {
+        sodium.crypto_hash_sha512_update(state2, chunk.subarray(off, Math.min(off + SEG, chunk.length)))
+      }
+      // snapshot incremental hash (create temp copy of state)
+      const chunkDigest = sha512Streaming([chunk])
+      console.error(`[WORKER-DBG] chunk[${i}] size=${chunk.length} sha512=${_whex(chunkDigest, 32)}… [0..8]=${_whex(chunk)} [-8..]=${_whex(chunk.slice(-8))}`)
+    }
    self.postMessage({id, type: 'error', message: 'File digest mismatch'})
    return
  }
+  console.log(`[WORKER-DBG] verify: digest OK`)

  // File-level decrypt
  const result = decryptChunks(BigInt(size), chunks, key, nonce)
@@ -213,6 +249,10 @@ self.onmessage = async (e: MessageEvent) => {

 // ── Helpers ─────────────────────────────────────────────────────

+function _whex(b: Uint8Array, n = 8): string {
+  return Array.from(b.slice(0, n)).map(x => x.toString(16).padStart(2, '0')).join('')
+}
+
 function digestEqual(a: Uint8Array, b: Uint8Array): boolean {
  if (a.length !== b.length) return false
  let diff = 0