From 47f209ec4ef6695e17fc485d0ecdaaa210a63186 Mon Sep 17 00:00:00 2001 From: Brian Botha Date: Fri, 27 Oct 2023 14:41:44 +1100 Subject: [PATCH 1/3] feat: expose more `connectionId` information Changes: * Exposed connection destination ID * Created a common ID that is identical for both sides of the connection. Derived from the source and destination ID. * The `quiche` connection is now the Source Of Truth for these IDs. The destinationId is only know after establishing and is only valid while running. * Added test demonstrating the new Ids and how they relate to each other. Related: https://github.com/MatrixAI/Polykey/pull/609 [ci skip] --- src/QUICConnection.ts | 39 +++++++++++++++++++---- tests/QUICClient.test.ts | 69 +++++++++++++++++++++++++++++++++++++++- 2 files changed, 100 insertions(+), 8 deletions(-) diff --git a/src/QUICConnection.ts b/src/QUICConnection.ts index 76a1fc67..0b50f4f9 100644 --- a/src/QUICConnection.ts +++ b/src/QUICConnection.ts @@ -1,7 +1,6 @@ import type { PromiseCancellable } from '@matrixai/async-cancellable'; import type { ContextTimed, ContextTimedInput } from '@matrixai/contexts'; import type QUICSocket from './QUICSocket'; -import type QUICConnectionId from './QUICConnectionId'; import type { Host, Port, @@ -25,6 +24,7 @@ import { } from '@matrixai/async-init/dist/StartStop'; import { timedCancellable, context } from '@matrixai/contexts/dist/decorators'; import { buildQuicheConfig, minIdleTimeout } from './config'; +import QUICConnectionId from './QUICConnectionId'; import QUICStream from './QUICStream'; import { quiche, ConnectionErrorCode } from './native'; import * as utils from './utils'; @@ -44,11 +44,6 @@ class QUICConnection { */ public readonly type: 'client' | 'server'; - /** - * This is the source connection ID. - */ - public readonly connectionId: QUICConnectionId; - /** * Resolves once the connection has closed. */ @@ -381,7 +376,6 @@ class QUICConnection { } this.type = type; this.conn = conn!; - this.connectionId = scid; this.socket = socket; this.config = config; if (this.config.cert != null) { @@ -413,6 +407,37 @@ class QUICConnection { this.resolveClosedP = resolveClosedP; } + /** + * This is the source connection ID. + */ + public get connectionId() { + return new QUICConnectionId(this.conn.sourceId()); + } + + /** + * This is the destination connection ID. + * This is only fully known after establishing the connection + */ + @ready(new errors.ErrorQUICConnectionNotRunning()) + public get connectionIdPeer() { + return new QUICConnectionId(this.conn.destinationId()); + } + + /** + * A common ID between the client and server connection. + * Used to identify connection pairs more easily. + */ + @ready(new errors.ErrorQUICConnectionNotRunning()) + public get connectionIdShared() { + const sourceId = this.conn.sourceId(); + const destinationId = this.conn.destinationId(); + if (Buffer.compare(sourceId, destinationId) <= 0) { + return new QUICConnectionId(Buffer.concat([sourceId, destinationId])); + } else { + return new QUICConnectionId(Buffer.concat([destinationId, sourceId])); + } + } + public get remoteHost(): Host { return this._remoteHost; } diff --git a/tests/QUICClient.test.ts b/tests/QUICClient.test.ts index 16c57816..0e8af25e 100644 --- a/tests/QUICClient.test.ts +++ b/tests/QUICClient.test.ts @@ -1654,7 +1654,7 @@ describe(QUICClient.name, () => { await server.stop(); }); }); - test('Connections are established and secured quickly', async () => { + test('connections are established and secured quickly', async () => { const tlsConfigServer = await testsUtils.generateTLSConfig(defaultType); const connectionEventProm = promise(); @@ -1808,6 +1808,73 @@ describe(QUICClient.name, () => { errors.ErrorQUICConnectionIdleTimeout, ); + await client.destroy({ force: true }); + await server.stop({ force: true }); + }); + test('connections share the same id information', async () => { + const tlsConfigServer = await testsUtils.generateTLSConfig(defaultType); + + const { p: serverConnectionP, resolveP: serverConnectionResolveP } = + promise(); + const server = new QUICServer({ + crypto: { + key, + ops: serverCryptoOps, + }, + logger: logger.getChild(QUICServer.name), + config: { + key: tlsConfigServer.leafKeyPairPEM.privateKey, + cert: tlsConfigServer.leafCertPEM, + verifyPeer: false, + }, + }); + socketCleanMethods.extractSocket(server); + server.addEventListener( + events.EventQUICServerConnection.name, + (evt: events.EventQUICServerConnection) => { + serverConnectionResolveP(evt.detail); + }, + ); + await server.start({ + host: localhost, + }); + // If the server is slow to respond then this will time out. + // Then main cause of this was the server not processing the initial packet + // that creates the `QUICConnection`, as a result, the whole creation waited + // an extra 1 second for the client to retry the initial packet. + const client = await QUICClient.createQUICClient( + { + host: localhost, + port: server.port, + localHost: localhost, + crypto: { + ops: clientCryptoOps, + }, + logger: logger.getChild(QUICClient.name), + config: { + verifyPeer: false, + }, + }, + { timer: 500 }, + ); + socketCleanMethods.extractSocket(client); + + const clientConn = client.connection; + const serverConn = await serverConnectionP; + + expect( + Buffer.compare(clientConn.connectionId, serverConn.connectionIdPeer), + ).toBe(0); + expect( + Buffer.compare(clientConn.connectionIdPeer, serverConn.connectionId), + ).toBe(0); + expect( + Buffer.compare( + clientConn.connectionIdShared, + serverConn.connectionIdShared, + ), + ).toBe(0); + await client.destroy({ force: true }); await server.stop({ force: true }); }); From 5ac3c3b3f3cd43f4a4e98b1d133da95361932081 Mon Sep 17 00:00:00 2001 From: Brian Botha Date: Fri, 27 Oct 2023 15:34:03 +1100 Subject: [PATCH 2/3] fix: updated logger level when logging errors Errors either bubble up or are handled at some point. Decision to log them out should be made there. IMO we should rarely use `error` level logs because errors are either caught and handled and therefor not exceptional. Or bubble to the top in which case the program crashes. [ci skip] --- src/QUICClient.ts | 15 ++------------- src/QUICConnection.ts | 15 ++------------- src/QUICServer.ts | 3 ++- src/QUICSocket.ts | 3 ++- src/QUICStream.ts | 3 ++- tests/QUICClient.test.ts | 2 +- tests/QUICServer.test.ts | 2 +- tests/QUICSocket.test.ts | 6 +++--- tests/QUICStream.test.ts | 2 +- tests/concurrency.test.ts | 2 +- 10 files changed, 17 insertions(+), 36 deletions(-) diff --git a/src/QUICClient.ts b/src/QUICClient.ts index 7f1a01f1..ccc51a94 100644 --- a/src/QUICClient.ts +++ b/src/QUICClient.ts @@ -315,19 +315,8 @@ class QUICClient { */ protected handleEventQUICClientError = (evt: events.EventQUICClientError) => { const error = evt.detail; - if ( - (error instanceof errors.ErrorQUICConnectionLocal || - error instanceof errors.ErrorQUICConnectionPeer) && - ((!error.data.isApp && - error.data.errorCode === ConnectionErrorCode.NoError) || - (error.data.isApp && error.data.errorCode === 0)) - ) { - // Log out the excpetion as an info when it is graceful - this.logger.info(utils.formatError(error)); - } else { - // Log out the exception as an error when it is not graceful - this.logger.error(utils.formatError(error)); - } + // Log out the error + this.logger.info(utils.formatError(error)); if ( error instanceof errors.ErrorQUICClientInternal || error instanceof errors.ErrorQUICConnectionInternal diff --git a/src/QUICConnection.ts b/src/QUICConnection.ts index 0b50f4f9..590e7892 100644 --- a/src/QUICConnection.ts +++ b/src/QUICConnection.ts @@ -181,19 +181,8 @@ class QUICConnection { ) => { const error = evt.detail; this.errorLast = error; - if ( - (error instanceof errors.ErrorQUICConnectionLocal || - error instanceof errors.ErrorQUICConnectionPeer) && - ((!error.data.isApp && - error.data.errorCode === ConnectionErrorCode.NoError) || - (error.data.isApp && error.data.errorCode === 0)) - ) { - // Log out the excpetion as an info when it is graceful - this.logger.info(utils.formatError(error)); - } else { - // Log out the exception as an error when it is not graceful - this.logger.error(utils.formatError(error)); - } + // Log out error for debugging + this.logger.info(utils.formatError(error)); if (error instanceof errors.ErrorQUICConnectionInternal) { throw error; } diff --git a/src/QUICServer.ts b/src/QUICServer.ts index b295d378..841d47c4 100644 --- a/src/QUICServer.ts +++ b/src/QUICServer.ts @@ -72,7 +72,8 @@ class QUICServer { */ protected handleEventQUICServerError = (evt: events.EventQUICServerError) => { const error = evt.detail; - this.logger.error(utils.formatError(error)); + // Log out error for debugging + this.logger.info(utils.formatError(error)); if (error instanceof errors.ErrorQUICServerInternal) { throw error; } diff --git a/src/QUICSocket.ts b/src/QUICSocket.ts index bdc2989c..adb938d2 100644 --- a/src/QUICSocket.ts +++ b/src/QUICSocket.ts @@ -56,7 +56,8 @@ class QUICSocket { protected handleEventQUICSocketError = (evt: events.EventQUICSocketError) => { const error = evt.detail; - this.logger.error(utils.formatError(error)); + // Log out error for debugging + this.logger.debug(utils.formatError(error)); }; protected handleEventQUICSocketClose = async () => { diff --git a/src/QUICStream.ts b/src/QUICStream.ts index 40d7c671..ef98b783 100644 --- a/src/QUICStream.ts +++ b/src/QUICStream.ts @@ -150,7 +150,8 @@ class QUICStream implements ReadableWritablePair { protected handleEventQUICStreamError = (evt: events.EventQUICStreamError) => { const error = evt.detail; if (error instanceof errors.ErrorQUICStreamInternal) { - this.logger.error(utils.formatError(error)); + // Log out error for debugging + this.logger.debug(utils.formatError(error)); throw error; } if ( diff --git a/tests/QUICClient.test.ts b/tests/QUICClient.test.ts index 0e8af25e..35d18eae 100644 --- a/tests/QUICClient.test.ts +++ b/tests/QUICClient.test.ts @@ -15,7 +15,7 @@ import * as testsUtils from './utils'; import { generateTLSConfig, sleep } from './utils'; describe(QUICClient.name, () => { - const logger = new Logger(`${QUICClient.name} Test`, LogLevel.SILENT, [ + const logger = new Logger(`${QUICClient.name} Test`, LogLevel.WARN, [ new StreamHandler( formatting.format`${formatting.level}:${formatting.keys}:${formatting.msg}`, ), diff --git a/tests/QUICServer.test.ts b/tests/QUICServer.test.ts index 05867fb9..00f74e77 100644 --- a/tests/QUICServer.test.ts +++ b/tests/QUICServer.test.ts @@ -10,7 +10,7 @@ import * as errors from '@/errors'; import * as testsUtils from './utils'; describe(QUICServer.name, () => { - const logger = new Logger(`${QUICServer.name} Test`, LogLevel.SILENT, [ + const logger = new Logger(`${QUICServer.name} Test`, LogLevel.WARN, [ new StreamHandler( formatting.format`${formatting.level}:${formatting.keys}:${formatting.msg}`, ), diff --git a/tests/QUICSocket.test.ts b/tests/QUICSocket.test.ts index 7465ad42..77f80fce 100644 --- a/tests/QUICSocket.test.ts +++ b/tests/QUICSocket.test.ts @@ -13,7 +13,7 @@ import * as events from '@/events'; import * as testsUtils from './utils'; describe(QUICSocket.name, () => { - const logger = new Logger(`${QUICSocket.name} Test`, LogLevel.SILENT, [ + const logger = new Logger(`${QUICSocket.name} Test`, LogLevel.WARN, [ new StreamHandler(), ]); // This has to be setup asynchronously due to key generation @@ -296,7 +296,7 @@ describe(QUICSocket.name, () => { test('error and close event lifecycle', async () => { // We expect error logs const socketLogger = logger.getChild('abc'); - socketLogger.setLevel(LogLevel.SILENT); + socketLogger.setLevel(LogLevel.WARN); const socket = new QUICSocket({ logger: socketLogger, }); @@ -865,7 +865,7 @@ describe(QUICSocket.name, () => { }; // We expect lots of error logs const socketLogger = logger.getChild('abc'); - socketLogger.setLevel(LogLevel.SILENT); + socketLogger.setLevel(LogLevel.WARN); const socket = new QUICSocket({ logger: socketLogger, }); diff --git a/tests/QUICStream.test.ts b/tests/QUICStream.test.ts index 2a6c0cf6..901c9029 100644 --- a/tests/QUICStream.test.ts +++ b/tests/QUICStream.test.ts @@ -10,7 +10,7 @@ import * as testsUtils from './utils'; import { generateTLSConfig } from './utils'; describe(QUICStream.name, () => { - const logger = new Logger(`${QUICStream.name} Test`, LogLevel.SILENT, [ + const logger = new Logger(`${QUICStream.name} Test`, LogLevel.WARN, [ new StreamHandler( formatting.format`${formatting.level}:${formatting.keys}:${formatting.msg}`, ), diff --git a/tests/concurrency.test.ts b/tests/concurrency.test.ts index d508a8ab..bd28aa21 100644 --- a/tests/concurrency.test.ts +++ b/tests/concurrency.test.ts @@ -12,7 +12,7 @@ import { generateTLSConfig, handleStreamProm, sleep } from './utils'; import * as testsUtils from './utils'; describe('Concurrency tests', () => { - const logger = new Logger(`${QUICClient.name} Test`, LogLevel.SILENT, [ + const logger = new Logger(`${QUICClient.name} Test`, LogLevel.WARN, [ new StreamHandler( formatting.format`${formatting.level}:${formatting.keys}:${formatting.msg}`, ), From e4fe8487cb7657c8ad29965bde3ba1973c3c1f7e Mon Sep 17 00:00:00 2001 From: Brian Botha Date: Fri, 27 Oct 2023 16:55:03 +1100 Subject: [PATCH 3/3] fix: zero copy of `connectionId` and `connectionIdPeer` --- src/QUICConnection.ts | 16 ++++++++++++++-- 1 file changed, 14 insertions(+), 2 deletions(-) diff --git a/src/QUICConnection.ts b/src/QUICConnection.ts index 590e7892..919499ef 100644 --- a/src/QUICConnection.ts +++ b/src/QUICConnection.ts @@ -400,7 +400,13 @@ class QUICConnection { * This is the source connection ID. */ public get connectionId() { - return new QUICConnectionId(this.conn.sourceId()); + const sourceId = this.conn.sourceId(); + // Zero copy construction of QUICConnectionId + return new QUICConnectionId( + sourceId.buffer, + sourceId.byteOffset, + sourceId.byteLength, + ); } /** @@ -409,7 +415,13 @@ class QUICConnection { */ @ready(new errors.ErrorQUICConnectionNotRunning()) public get connectionIdPeer() { - return new QUICConnectionId(this.conn.destinationId()); + const destinationId = this.conn.destinationId(); + // Zero copy construction of QUICConnectionId + return new QUICConnectionId( + destinationId.buffer, + destinationId.byteOffset, + destinationId.byteLength, + ); } /**