From adea7bbbf8982d814d5bf5ed64368cdf5a3a742d Mon Sep 17 00:00:00 2001 From: achingbrain Date: Fri, 17 Nov 2023 15:18:01 +0000 Subject: [PATCH] chore: add trace logs to mss and remove commented perf code --- packages/multistream-select/src/handle.ts | 4 +- packages/multistream-select/src/select.ts | 3 + packages/protocol-perf/src/perf-service.ts | 72 ++++------------------ 3 files changed, 17 insertions(+), 62 deletions(-) diff --git a/packages/multistream-select/src/handle.ts b/packages/multistream-select/src/handle.ts index 8d597d86d5..0ecf2690c6 100644 --- a/packages/multistream-select/src/handle.ts +++ b/packages/multistream-select/src/handle.ts @@ -71,8 +71,8 @@ export async function handle > (stream: Str } if (protocols.includes(protocol)) { - await multistream.write(lp, uint8ArrayFromString(`${protocol}\n`), options) options.log.trace('respond with "%s" for "%s"', protocol, protocol) + await multistream.write(lp, uint8ArrayFromString(`${protocol}\n`), options) return { stream: lp.unwrap(), protocol } } @@ -89,7 +89,7 @@ export async function handle > (stream: Str continue } - await multistream.write(lp, uint8ArrayFromString('na\n'), options) options.log('respond with "na" for "%s"', protocol) + await multistream.write(lp, uint8ArrayFromString('na\n'), options) } } diff --git a/packages/multistream-select/src/select.ts b/packages/multistream-select/src/select.ts index 54f67f8787..c977c7977f 100644 --- a/packages/multistream-select/src/select.ts +++ b/packages/multistream-select/src/select.ts @@ -66,11 +66,13 @@ export async function select > (stream: Str const p2 = uint8ArrayFromString(`${protocol}\n`) await multistream.writeAll(lp, [p1, p2], options) + options?.log.trace('select: reading multistream-select header') let response = await multistream.readString(lp, options) options?.log.trace('select: read "%s"', response) // Read the protocol response if we got the protocolId in return if (response === PROTOCOL_ID) { + options?.log.trace('select: reading protocol response') response = await multistream.readString(lp, options) options?.log.trace('select: read "%s"', response) } @@ -84,6 +86,7 @@ export async function select > (stream: Str for (const protocol of protocols) { options?.log.trace('select: write "%s"', protocol) await multistream.write(lp, uint8ArrayFromString(`${protocol}\n`), options) + options?.log.trace('select: reading protocol response') const response = await multistream.readString(lp, options) options?.log.trace('select: read "%s" for "%s"', response, protocol) diff --git a/packages/protocol-perf/src/perf-service.ts b/packages/protocol-perf/src/perf-service.ts index 1cfc130616..aa1d862f2f 100644 --- a/packages/protocol-perf/src/perf-service.ts +++ b/packages/protocol-perf/src/perf-service.ts @@ -97,16 +97,23 @@ export class Perf implements Startable, PerfInterface { const writeBlockSize = this.writeBlockSize const initialStartTime = Date.now() + let lastReportedTime = Date.now() const connection = await this.components.connectionManager.openConnection(ma, { ...options, force: options.reuseExistingConnection !== true }) + this.log('opened connection after %d ms', Date.now() - lastReportedTime) + lastReportedTime = Date.now() + const stream = await connection.newStream(this.protocol, options) + this.log('opened stream after %d ms', Date.now() - lastReportedTime) + lastReportedTime = Date.now() + let lastAmountOfBytesSent = 0 - let lastReportedTime = Date.now() let totalBytesSent = 0 + const uploadStart = Date.now() // tell the remote how many bytes we will send. Up cast to 64 bit number // as if we send as ui32 we limit total transfer size to 4GB @@ -160,71 +167,14 @@ export class Perf implements Startable, PerfInterface { yield * output - /* - const b = byteStream(stream) - await b.write(uint8Buf.subarray(0, 8), options) - - while (sendBytes > 0) { - let toSend: number = writeBlockSize - - if (toSend > sendBytes) { - toSend = sendBytes - } - - const chunk = uint8Buf.subarray(0, toSend) - - await b.write(chunk, options) - - sendBytes -= toSend - - if (Date.now() - lastReportedTime > 1000) { - yield { - type: 'intermediary', - timeSeconds: (Date.now() - lastReportedTime) / 1000, - uploadBytes: lastAmountOfBytesSent, - downloadBytes: 0 - } - - // record last reported time after `console.log` because it can - // affect benchmark timings - lastReportedTime = Date.now() - lastAmountOfBytesSent = 0 - } - - lastAmountOfBytesSent += toSend - totalBytesSent += toSend - } - - // sent all the bytes, close the write end of the stream - await b.unwrap().closeWrite() + this.log('upload complete after %d ms', Date.now() - uploadStart) -*/ // Read the received bytes let lastAmountOfBytesReceived = 0 lastReportedTime = Date.now() let totalBytesReceived = 0 - /* - while (totalBytesReceived < receiveBytes) { - const buf = await b.read(1024, options) - - if (Date.now() - lastReportedTime > 1000) { - yield { - type: 'intermediary', - timeSeconds: (Date.now() - lastReportedTime) / 1000, - uploadBytes: 0, - downloadBytes: lastAmountOfBytesReceived - } + const downloadStart = Date.now() - // record last reported time after `console.log` because it can - // affect benchmark timings - lastReportedTime = Date.now() - lastAmountOfBytesReceived = 0 - } - - lastAmountOfBytesReceived += buf.byteLength - totalBytesReceived += buf.byteLength - } -*/ for await (const buf of stream.source) { if (Date.now() - lastReportedTime > 1000) { yield { @@ -244,6 +194,8 @@ export class Perf implements Startable, PerfInterface { totalBytesReceived += buf.byteLength } + this.log('download complete after %d ms', Date.now() - downloadStart) + if (totalBytesReceived !== receiveBytes) { throw new Error(`Expected to receive ${receiveBytes} bytes, but received ${totalBytesReceived}`) }