mirror of
https://github.com/simplex-chat/simplexmq.git
synced 2026-09-01 20:18:26 +00:00
debug logging in web page and server
This commit is contained in:
Evgeny @ SimpleX Chat
@@ -75,7 +75,7 @@ import Simplex.Messaging.Version
|
||||
import System.Environment (lookupEnv)
|
||||
import System.Exit (exitFailure)
|
||||
import System.FilePath ((</>))
|
||||
import System.IO (hPrint, hPutStrLn, universalNewlineMode)
|
||||
import System.IO (hPrint, hPutStrLn, stderr, universalNewlineMode)
|
||||
#ifdef slow_servers
|
||||
import System.Random (getStdRandom, randomR)
|
||||
#endif
|
||||
@@ -179,12 +179,18 @@ xftpServer cfg@XFTPServerConfig {xftpPort, transportConfig, inactiveClientExpira
|
||||
webHello = sniUsed && any (\(t, _) -> tokenKey t == "xftp-web-hello") (fst $ H.requestHeaders request)
|
||||
webHandshake = sniUsed && any (\(t, _) -> tokenKey t == "xftp-handshake") (fst $ H.requestHeaders request)
|
||||
processHello pk_ = do
|
||||
liftIO $ hPutStrLn stderr $ "DEBUG processHello: bodyHead.len=" <> show (B.length bodyHead) <> " sniUsed=" <> show sniUsed <> " webHello=" <> show webHello
|
||||
liftIO $ hPutStrLn stderr $ "DEBUG processHello: bodyHead first20=" <> show (B.take 20 bodyHead)
|
||||
challenge_ <-
|
||||
if
|
||||
| B.null bodyHead -> pure Nothing
|
||||
| sniUsed -> do
|
||||
body <- liftHS $ C.unPad bodyHead
|
||||
XFTPClientHello {webChallenge} <- liftHS $ smpDecode body
|
||||
let unpadResult = C.unPad bodyHead
|
||||
liftIO $ hPutStrLn stderr $ "DEBUG processHello: unPad result=" <> show (either show (\b -> "OK len=" <> show (B.length b) <> " bytes=" <> show (B.take 20 b)) unpadResult)
|
||||
body <- liftHS unpadResult
|
||||
let decodeResult = smpDecode body :: Either String XFTPClientHello
|
||||
liftIO $ hPutStrLn stderr $ "DEBUG processHello: smpDecode result=" <> show (either id (\(XFTPClientHello wc) -> "OK challenge=" <> show (fmap B.length wc)) decodeResult)
|
||||
XFTPClientHello {webChallenge} <- liftHS $ first show decodeResult
|
||||
pure webChallenge
|
||||
| otherwise -> throwE HANDSHAKE
|
||||
rng <- asks random
|
||||
|
||||
+26
-2
@@ -79,15 +79,21 @@ function createBrowserTransport(baseUrl: string): Transport {
|
||||
const effectiveUrl = typeof __XFTP_PROXY_PORT__ !== 'undefined' && __XFTP_PROXY_PORT__
|
||||
? '/xftp-proxy'
|
||||
: baseUrl
|
||||
console.log('[DEBUG transport] baseUrl=%s effectiveUrl=%s proxy=%s', baseUrl, effectiveUrl, __XFTP_PROXY_PORT__)
|
||||
return {
|
||||
async post(body: Uint8Array, headers?: Record<string, string>): Promise<Uint8Array> {
|
||||
console.log('[DEBUG transport.post] url=%s bodyLen=%d headers=%o', effectiveUrl, body.length, headers)
|
||||
const resp = await fetch(effectiveUrl, {
|
||||
method: "POST",
|
||||
headers,
|
||||
body,
|
||||
})
|
||||
console.log('[DEBUG transport.post] status=%d statusText=%s', resp.status, resp.statusText)
|
||||
console.log('[DEBUG transport.post] response headers:', Object.fromEntries(resp.headers.entries()))
|
||||
if (!resp.ok) throw new Error(`fetch failed: ${resp.status}`)
|
||||
return new Uint8Array(await resp.arrayBuffer())
|
||||
const buf = new Uint8Array(await resp.arrayBuffer())
|
||||
console.log('[DEBUG transport.post] responseLen=%d first16=%s', buf.length, Array.from(buf.subarray(0, 16)).map(b => b.toString(16).padStart(2,'0')).join(' '))
|
||||
return buf
|
||||
},
|
||||
close() {}
|
||||
}
|
||||
@@ -135,13 +141,19 @@ export async function connectXFTP(server: XFTPServer): Promise<XFTPClient> {
|
||||
|
||||
try {
|
||||
// Step 1: send client hello with web challenge
|
||||
console.log('[DEBUG connectXFTP] Step 1: sending client hello')
|
||||
const challenge = new Uint8Array(32)
|
||||
crypto.getRandomValues(challenge)
|
||||
const clientHelloBytes = encodeClientHello({webChallenge: challenge})
|
||||
console.log('[DEBUG connectXFTP] clientHelloBytes.length=%d', clientHelloBytes.length)
|
||||
const shsBody = await transport.post(clientHelloBytes, {"xftp-web-hello": "1"})
|
||||
console.log('[DEBUG connectXFTP] Step 1 done: shsBody.length=%d', shsBody.length)
|
||||
|
||||
// Step 2: decode + verify server handshake
|
||||
console.log('[DEBUG connectXFTP] Step 2: decoding server handshake')
|
||||
const hs = decodeServerHandshake(shsBody)
|
||||
console.log('[DEBUG connectXFTP] Step 2 decoded: sessionId.length=%d certChain.length=%d signedKey.length=%d webProof=%s',
|
||||
hs.sessionId.length, hs.certChainDer.length, hs.signedKeyDer.length, hs.webIdentityProof ? hs.webIdentityProof.length : 'null')
|
||||
if (!hs.webIdentityProof) throw new Error("connectXFTP: no web identity proof")
|
||||
const idOk = verifyIdentityProof({
|
||||
certChainDer: hs.certChainDer,
|
||||
@@ -151,17 +163,22 @@ export async function connectXFTP(server: XFTPServer): Promise<XFTPClient> {
|
||||
sessionId: hs.sessionId,
|
||||
keyHash: server.keyHash
|
||||
})
|
||||
console.log('[DEBUG connectXFTP] Step 2 identity verified=%s', idOk)
|
||||
if (!idOk) throw new Error("connectXFTP: identity verification failed")
|
||||
|
||||
// Step 3: version negotiation
|
||||
const vr = compatibleVRange(hs.xftpVersionRange, {minVersion: initialXFTPVersion, maxVersion: currentXFTPVersion})
|
||||
console.log('[DEBUG connectXFTP] Step 3: version range=%o negotiated=%o', hs.xftpVersionRange, vr)
|
||||
if (!vr) throw new Error("connectXFTP: incompatible version")
|
||||
const xftpVersion = vr.maxVersion
|
||||
|
||||
// Step 4: send client handshake
|
||||
console.log('[DEBUG connectXFTP] Step 4: sending client handshake v=%d', xftpVersion)
|
||||
const ack = await transport.post(encodeClientHandshake({xftpVersion, keyHash: server.keyHash}), {"xftp-handshake": "1"})
|
||||
console.log('[DEBUG connectXFTP] Step 4 done: ack.length=%d', ack.length)
|
||||
if (ack.length !== 0) throw new Error("connectXFTP: non-empty handshake ack")
|
||||
|
||||
console.log('[DEBUG connectXFTP] handshake complete, sessionId=%s', Array.from(hs.sessionId.subarray(0, 8)).map(b => b.toString(16).padStart(2,'0')).join(''))
|
||||
return {baseUrl, sessionId: hs.sessionId, xftpVersion, transport}
|
||||
} catch (e) {
|
||||
transport.close()
|
||||
@@ -178,15 +195,22 @@ async function sendXFTPCommand(
|
||||
cmdBytes: Uint8Array,
|
||||
chunkData?: Uint8Array
|
||||
): Promise<{response: FileResponse, body: Uint8Array}> {
|
||||
const cmdTag = String.fromCharCode(...cmdBytes.subarray(0, 4))
|
||||
console.log('[DEBUG sendXFTPCommand] cmd=%s entityId.len=%d chunkData=%s', cmdTag, entityId.length, chunkData ? chunkData.length : 'none')
|
||||
const corrId = new Uint8Array(0)
|
||||
const block = encodeAuthTransmission(client.sessionId, corrId, entityId, cmdBytes, privateKey)
|
||||
const reqBody = chunkData ? concatBytes(block, chunkData) : block
|
||||
console.log('[DEBUG sendXFTPCommand] reqBody.length=%d (block=%d + chunk=%d)', reqBody.length, block.length, chunkData?.length ?? 0)
|
||||
const fullResp = await client.transport.post(reqBody)
|
||||
if (fullResp.length < XFTP_BLOCK_SIZE) throw new Error("sendXFTPCommand: response too short")
|
||||
console.log('[DEBUG sendXFTPCommand] fullResp.length=%d', fullResp.length)
|
||||
if (fullResp.length < XFTP_BLOCK_SIZE) throw new Error("sendXFTPCommand: response too short (" + fullResp.length + " < " + XFTP_BLOCK_SIZE + ")")
|
||||
const respBlock = fullResp.subarray(0, XFTP_BLOCK_SIZE)
|
||||
const body = fullResp.subarray(XFTP_BLOCK_SIZE)
|
||||
console.log('[DEBUG sendXFTPCommand] respBlock first4: %s', Array.from(respBlock.subarray(0, 4)).map(b => b.toString(16).padStart(2,'0')).join(' '))
|
||||
const {command} = decodeTransmission(client.sessionId, respBlock)
|
||||
console.log('[DEBUG sendXFTPCommand] decoded command=%s', String.fromCharCode(...command.subarray(0, Math.min(20, command.length))))
|
||||
const response = decodeResponse(command)
|
||||
console.log('[DEBUG sendXFTPCommand] response.type=%s', response.type)
|
||||
if (response.type === "FRErr") throw new Error("XFTP error: " + response.err.type)
|
||||
return {response, body}
|
||||
}
|
||||
|
||||
@@ -85,18 +85,34 @@ export interface XFTPServerHandshake {
|
||||
// sigBytes = ByteString (1-byte len prefix, empty for Nothing)
|
||||
// Trailing bytes (Tail) are ignored for forward compatibility.
|
||||
export function decodeServerHandshake(block: Uint8Array): XFTPServerHandshake {
|
||||
console.log('[DEBUG decodeServerHandshake] block.length=%d', block.length)
|
||||
const raw = blockUnpad(block)
|
||||
console.log('[DEBUG decodeServerHandshake] unpadded.length=%d content=%s', raw.length, String.fromCharCode(...raw.subarray(0, Math.min(40, raw.length))))
|
||||
// Detect error responses (server sends padded error string like "HANDSHAKE")
|
||||
if (raw.length < 20) {
|
||||
const text = String.fromCharCode(...raw)
|
||||
if (/^[A-Z_]+$/.test(text)) {
|
||||
throw new Error("server handshake error: " + text)
|
||||
}
|
||||
}
|
||||
const d = new Decoder(raw)
|
||||
const xftpVersionRange = decodeVersionRange(d)
|
||||
console.log('[DEBUG decodeServerHandshake] versionRange=%o offset=%d', xftpVersionRange, d.offset())
|
||||
const sessionId = decodeBytes(d)
|
||||
console.log('[DEBUG decodeServerHandshake] sessionId.length=%d offset=%d', sessionId.length, d.offset())
|
||||
// CertChainPubKey: smpEncode (encodeCertChain certChain, SignedObject signedPubKey)
|
||||
const certChainDer = decodeNonEmpty(decodeLarge, d)
|
||||
console.log('[DEBUG decodeServerHandshake] certChain.length=%d offset=%d', certChainDer.length, d.offset())
|
||||
const signedKeyDer = decodeLarge(d)
|
||||
console.log('[DEBUG decodeServerHandshake] signedKey.length=%d offset=%d remaining=%d', signedKeyDer.length, d.offset(), d.remaining())
|
||||
// webIdentityProof: 1-byte length-prefixed ByteString (empty = Nothing)
|
||||
let webIdentityProof: Uint8Array | null = null
|
||||
if (d.remaining() > 0) {
|
||||
const sigBytes = decodeBytes(d)
|
||||
console.log('[DEBUG decodeServerHandshake] webProof.length=%d', sigBytes.length)
|
||||
webIdentityProof = sigBytes.length === 0 ? null : sigBytes
|
||||
} else {
|
||||
console.log('[DEBUG decodeServerHandshake] no webIdentityProof (remaining=0)')
|
||||
}
|
||||
// Remaining bytes are Tail (ignored for forward compatibility)
|
||||
return {xftpVersionRange, sessionId, certChainDer, signedKeyDer, webIdentityProof}
|
||||
|
||||
@@ -92,21 +92,32 @@ export interface DecodedTransmission {
|
||||
// Call decodeResponse(command) from commands.ts to parse the response.
|
||||
// Matches xftpDecodeTClient with implySessId = False: reads and verifies sessionId from wire.
|
||||
export function decodeTransmission(sessionId: Uint8Array, block: Uint8Array): DecodedTransmission {
|
||||
console.log('[DEBUG decodeTransmission] block.length=%d', block.length)
|
||||
const raw = blockUnpad(block)
|
||||
console.log('[DEBUG decodeTransmission] unpadded.length=%d first8=%s', raw.length, Array.from(raw.subarray(0, 8)).map(b => b.toString(16).padStart(2,'0')).join(' '))
|
||||
const d = new Decoder(raw)
|
||||
const count = d.anyByte()
|
||||
console.log('[DEBUG decodeTransmission] batch count=%d', count)
|
||||
if (count !== 1) throw new Error("decodeTransmission: expected batch count 1, got " + count)
|
||||
const transmission = decodeLarge(d)
|
||||
console.log('[DEBUG decodeTransmission] transmission.length=%d', transmission.length)
|
||||
const td = new Decoder(transmission)
|
||||
// Skip authenticator (server responses have empty auth)
|
||||
decodeBytes(td)
|
||||
const auth = decodeBytes(td)
|
||||
console.log('[DEBUG decodeTransmission] auth.length=%d', auth.length)
|
||||
// implySessId = False: read sessionId from wire and verify
|
||||
const sessId = decodeBytes(td)
|
||||
console.log('[DEBUG decodeTransmission] sessId.length=%d', sessId.length)
|
||||
if (sessId.length !== sessionId.length || !sessId.every((b, i) => b === sessionId[i])) {
|
||||
console.log('[DEBUG decodeTransmission] SESSION MISMATCH expected=%s got=%s',
|
||||
Array.from(sessionId.subarray(0, 8)).map(b => b.toString(16).padStart(2,'0')).join(''),
|
||||
Array.from(sessId.subarray(0, 8)).map(b => b.toString(16).padStart(2,'0')).join(''))
|
||||
throw new Error("decodeTransmission: session ID mismatch")
|
||||
}
|
||||
const corrId = decodeBytes(td)
|
||||
const entityId = decodeBytes(td)
|
||||
const command = td.takeAll()
|
||||
console.log('[DEBUG decodeTransmission] corrId.len=%d entityId.len=%d command.len=%d cmd=%s',
|
||||
corrId.length, entityId.length, command.length, String.fromCharCode(...command.subarray(0, Math.min(10, command.length))))
|
||||
return {corrId, entityId, command}
|
||||
}
|
||||
|
||||
Reference in New Issue
Block a user