diff --git a/grunt/esbuild/strip-logs.js b/grunt/esbuild/strip-logs.js index 6fc755513..e17b0f941 100644 --- a/grunt/esbuild/strip-logs.js +++ b/grunt/esbuild/strip-logs.js @@ -38,32 +38,32 @@ const stripLogsPlugin = { babel.types.isIdentifier(path.node.callee.object, { name: 'Logger' }) ) { if (babel.types.isIdentifier(path.node.callee.property, { name: 'logAction' })) { - const firstArgument = path.node.arguments[0]; + const secondArgument = path.node.arguments[1]; if ( - babel.types.isMemberExpression(firstArgument) && - babel.types.isIdentifier(firstArgument.object, { name: 'Logger' }) && - firstArgument.property.name.startsWith('LOG_') + babel.types.isMemberExpression(secondArgument) && + babel.types.isIdentifier(secondArgument.object, { name: 'Logger' }) && + secondArgument.property.name.startsWith('LOG_') ) { - if (firstArgument.property.name === 'LOG_ERROR') { - // `path` is a call to `Logger.logAction(Logger.LOG_ERROR, ...)`; preserve it. + if (secondArgument.property.name === 'LOG_ERROR') { + // `path` is a call to `Logger.logAction(arg0, Logger.LOG_ERROR, ...)`; preserve it. foundErrorLog = true; } else { - // `path` is a call to `Logger.logAction(Logger.LOG_*, ...) for some other log level; strip it. + // `path` is a call to `Logger.logAction(arg0, Logger.LOG_*, ...) for some other log level; strip it. foundLogToStrip = true; path.remove(); } } else { - // `path` is a call to `Logger.logAction(...)` with some argument other than a `Logger.LOG_*` expression; raise an error because we can’t determine whether to strip it. + // `path` is a call to `Logger.logAction(arg0, ...)` with some argument other than a `Logger.LOG_*` expression; raise an error because we can’t determine whether to strip it. errors.push({ location: { file: args.path, - column: firstArgument.loc.start.column, - line: firstArgument.loc.start.line, - lineText: lines[firstArgument.loc.start.line - 1], + column: secondArgument.loc.start.column, + line: secondArgument.loc.start.line, + lineText: lines[secondArgument.loc.start.line - 1], }, - text: `First argument passed to Logger.logAction() must be Logger.LOG_*, got \`${ - babel.generator.default(firstArgument).code + text: `Second argument passed to Logger.logAction() must be Logger.LOG_*, got \`${ + babel.generator.default(secondArgument).code }\``, }); } @@ -96,7 +96,7 @@ const stripLogsPlugin = { // accidentally strip all logging calls). if (!foundErrorLog) { - errorMessages.push('Did not find any Logger.logAction(Logger.LOG_ERROR, ...) calls to preserve'); + errorMessages.push('Did not find any Logger.logAction(arg0, Logger.LOG_ERROR, ...) calls to preserve'); } if (!foundNoStripLog) { diff --git a/scripts/moduleReport.ts b/scripts/moduleReport.ts index c933800af..6b0349192 100644 --- a/scripts/moduleReport.ts +++ b/scripts/moduleReport.ts @@ -6,7 +6,7 @@ import { gzip } from 'zlib'; import Table from 'cli-table'; // The maximum size we allow for a minimal useful Realtime bundle (i.e. one that can subscribe to a channel) -const minimalUsefulRealtimeBundleSizeThresholdsKiB = { raw: 95, gzip: 29 }; +const minimalUsefulRealtimeBundleSizeThresholdsKiB = { raw: 96, gzip: 29 }; const baseClientNames = ['BaseRest', 'BaseRealtime']; diff --git a/src/common/lib/client/auth.ts b/src/common/lib/client/auth.ts index 80b4ed253..67e7704f2 100644 --- a/src/common/lib/client/auth.ts +++ b/src/common/lib/client/auth.ts @@ -72,18 +72,18 @@ function c14n(capability?: string | Record>) { return JSON.stringify(c14nCapability); } -function logAndValidateTokenAuthMethod(authOptions: AuthOptions) { +function logAndValidateTokenAuthMethod(authOptions: AuthOptions, logger: Logger) { if (authOptions.authCallback) { - Logger.logAction(Logger.LOG_MINOR, 'Auth()', 'using token auth with authCallback'); + Logger.logAction(logger, Logger.LOG_MINOR, 'Auth()', 'using token auth with authCallback'); } else if (authOptions.authUrl) { - Logger.logAction(Logger.LOG_MINOR, 'Auth()', 'using token auth with authUrl'); + Logger.logAction(logger, Logger.LOG_MINOR, 'Auth()', 'using token auth with authUrl'); } else if (authOptions.key) { - Logger.logAction(Logger.LOG_MINOR, 'Auth()', 'using token auth with client-side signing'); + Logger.logAction(logger, Logger.LOG_MINOR, 'Auth()', 'using token auth with client-side signing'); } else if (authOptions.tokenDetails) { - Logger.logAction(Logger.LOG_MINOR, 'Auth()', 'using token auth with supplied token only'); + Logger.logAction(logger, Logger.LOG_MINOR, 'Auth()', 'using token auth with supplied token only'); } else { const msg = 'authOptions must include valid authentication parameters'; - Logger.logAction(Logger.LOG_ERROR, 'Auth()', msg); + Logger.logAction(logger, Logger.LOG_ERROR, 'Auth()', msg); throw new Error(msg); } } @@ -144,26 +144,31 @@ class Auth { /* Token auth */ if (noWayToRenew(options)) { Logger.logAction( + this.logger, Logger.LOG_ERROR, 'Auth()', 'Warning: library initialized with a token literal without any way to renew the token when it expires (no authUrl, authCallback, or key). See https://help.ably.io/error/40171 for help', ); } this._saveTokenOptions(options.defaultTokenParams as API.TokenDetails, options); - logAndValidateTokenAuthMethod(this.authOptions); + logAndValidateTokenAuthMethod(this.authOptions, this.logger); } else { /* Basic auth */ if (!options.key) { const msg = 'No authentication options provided; need one of: key, authUrl, or authCallback (or for testing only, token or tokenDetails)'; - Logger.logAction(Logger.LOG_ERROR, 'Auth()', msg); + Logger.logAction(this.logger, Logger.LOG_ERROR, 'Auth()', msg); throw new ErrorInfo(msg, 40160, 401); } - Logger.logAction(Logger.LOG_MINOR, 'Auth()', 'anonymous, using basic auth'); + Logger.logAction(this.logger, Logger.LOG_MINOR, 'Auth()', 'anonymous, using basic auth'); this._saveBasicOptions(options); } } + get logger(): Logger { + return this.client.logger; + } + /** * Instructs the library to get a token immediately and ensures Token Auth * is used for all future requests, storing the tokenParams and authOptions @@ -303,7 +308,7 @@ class Auth { * not the passed in ones. */ this._saveTokenOptions(tokenParams, authOptions); - logAndValidateTokenAuthMethod(this.authOptions); + logAndValidateTokenAuthMethod(this.authOptions, this.logger); try { return this._ensureValidAuthCredentials(true); @@ -403,10 +408,10 @@ class Auth { client = this.client; if (resolvedAuthOptions.authCallback) { - Logger.logAction(Logger.LOG_MINOR, 'Auth.requestToken()', 'using token auth with authCallback'); + Logger.logAction(this.logger, Logger.LOG_MINOR, 'Auth.requestToken()', 'using token auth with authCallback'); tokenRequestCallback = resolvedAuthOptions.authCallback; } else if (resolvedAuthOptions.authUrl) { - Logger.logAction(Logger.LOG_MINOR, 'Auth.requestToken()', 'using token auth with authUrl'); + Logger.logAction(this.logger, Logger.LOG_MINOR, 'Auth.requestToken()', 'using token auth with authUrl'); tokenRequestCallback = (params, cb) => { const authHeaders = Utils.mixin( { accept: 'application/json, text/plain' }, @@ -429,12 +434,13 @@ class Auth { } /* RSA8c2 */ const authParams = Utils.mixin({}, resolvedAuthOptions.authParams || {}, params) as RequestParams; - const authUrlRequestCallback = function (result: RequestResult) { + const authUrlRequestCallback = (result: RequestResult) => { let body = (result.body ?? null) as string | Bufferlike | API.TokenDetails | API.TokenRequest | null; let contentType: string | null = null; if (result.error) { Logger.logAction( + this.logger, Logger.LOG_MICRO, 'Auth.requestToken().tokenRequestCallback', 'Received Error: ' + Utils.inspectError(result.error), @@ -448,6 +454,7 @@ class Auth { contentType = contentTypeHeaderOrHeaders; } Logger.logAction( + this.logger, Logger.LOG_MICRO, 'Auth.requestToken().tokenRequestCallback', 'Received; content-type: ' + contentType + '; body: ' + Utils.inspectBody(body), @@ -503,6 +510,7 @@ class Auth { cb(null, body as Exclude, contentType); }; Logger.logAction( + this.logger, Logger.LOG_MICRO, 'Auth.requestToken().tokenRequestCallback', 'Requesting token from ' + @@ -541,7 +549,12 @@ class Auth { } }; } else if (resolvedAuthOptions.key) { - Logger.logAction(Logger.LOG_MINOR, 'Auth.requestToken()', 'using token auth with client-side signing'); + Logger.logAction( + this.logger, + Logger.LOG_MINOR, + 'Auth.requestToken()', + 'using token auth with client-side signing', + ); tokenRequestCallback = (params, cb) => { Utils.whenPromiseSettles(this.createTokenRequest(params, resolvedAuthOptions), (err, result) => cb(err as string | ErrorInfo | null, result ?? null), @@ -551,6 +564,7 @@ class Auth { const msg = 'Need a new token, but authOptions does not include any way to request one (no authUrl, authCallback, or key)'; Logger.logAction( + this.logger, Logger.LOG_ERROR, 'Auth()', 'library initialized with a token literal without any way to renew the token when it expires (no authUrl, authCallback, or key). See https://help.ably.io/error/40171 for help', @@ -577,6 +591,7 @@ class Auth { const requestHeaders = Defaults.defaultPostHeaders(this.client.options); if (resolvedAuthOptions.requestHeaders) Utils.mixin(requestHeaders, resolvedAuthOptions.requestHeaders); Logger.logAction( + this.logger, Logger.LOG_MICRO, 'Auth.requestToken().requestToken', 'Sending POST to ' + path + '; Token params: ' + JSON.stringify(signedTokenParams), @@ -593,19 +608,20 @@ class Auth { return new Promise((resolve, reject) => { let tokenRequestCallbackTimeoutExpired = false, timeoutLength = this.client.options.timeouts.realtimeRequestTimeout, - tokenRequestCallbackTimeout = setTimeout(function () { + tokenRequestCallbackTimeout = setTimeout(() => { tokenRequestCallbackTimeoutExpired = true; const msg = 'Token request callback timed out after ' + timeoutLength / 1000 + ' seconds'; - Logger.logAction(Logger.LOG_ERROR, 'Auth.requestToken()', msg); + Logger.logAction(this.logger, Logger.LOG_ERROR, 'Auth.requestToken()', msg); reject(new ErrorInfo(msg, 40170, 401)); }, timeoutLength); - tokenRequestCallback!(resolvedTokenParams, function (err, tokenRequestOrDetails, contentType) { + tokenRequestCallback!(resolvedTokenParams, (err, tokenRequestOrDetails, contentType) => { if (tokenRequestCallbackTimeoutExpired) return; clearTimeout(tokenRequestCallbackTimeout); if (err) { Logger.logAction( + this.logger, Logger.LOG_ERROR, 'Auth.requestToken()', 'token request signing call returned error; err = ' + Utils.inspectError(err), @@ -648,7 +664,7 @@ class Auth { const msg = 'Expected token request callback to call back with a token string or token request/details object, but got a ' + typeof tokenRequestOrDetails; - Logger.logAction(Logger.LOG_ERROR, 'Auth.requestToken()', msg); + Logger.logAction(this.logger, Logger.LOG_ERROR, 'Auth.requestToken()', msg); reject(new ErrorInfo(msg, 40170, 401)); return; } @@ -671,14 +687,15 @@ class Auth { if (!('keyName' in tokenRequestOrDetails)) { const msg = 'Expected token request callback to call back with a token string, token request object, or token details object'; - Logger.logAction(Logger.LOG_ERROR, 'Auth.requestToken()', msg); + Logger.logAction(this.logger, Logger.LOG_ERROR, 'Auth.requestToken()', msg); reject(new ErrorInfo(msg, 40170, 401)); return; } /* it's a token request, so make the request */ - tokenRequest(tokenRequestOrDetails, function (err, tokenResponse, unpacked) { + tokenRequest(tokenRequestOrDetails, (err, tokenResponse, unpacked) => { if (err) { Logger.logAction( + this.logger, Logger.LOG_ERROR, 'Auth.requestToken()', 'token request API call returned error; err = ' + Utils.inspectError(err), @@ -687,7 +704,7 @@ class Auth { return; } if (!unpacked) tokenResponse = JSON.parse(tokenResponse as string); - Logger.logAction(Logger.LOG_MINOR, 'Auth.getToken()', 'token received'); + Logger.logAction(this.logger, Logger.LOG_MINOR, 'Auth.getToken()', 'token received'); resolve(tokenResponse as API.TokenDetails); }); }); @@ -779,7 +796,7 @@ class Auth { * simply for testing purposes. */ request.mac = request.mac || hmac(signText, keySecret); - Logger.logAction(Logger.LOG_MINOR, 'Auth.getTokenRequest()', 'generated signed request'); + Logger.logAction(this.logger, Logger.LOG_MINOR, 'Auth.getTokenRequest()', 'generated signed request'); return request as API.TokenRequest; } @@ -897,16 +914,21 @@ class Auth { * automatically remove expired tokens. Else just use the cached token. If it is * expired Ably will tell us and we'll discard it then. */ if (!this.isTimeOffsetSet() || !token.expires || token.expires >= this.getTimestampUsingOffset()) { - Logger.logAction(Logger.LOG_MINOR, 'Auth.getToken()', 'using cached token; expires = ' + token.expires); + Logger.logAction( + this.logger, + Logger.LOG_MINOR, + 'Auth.getToken()', + 'using cached token; expires = ' + token.expires, + ); return token; } /* expired, so remove and fallthrough to getting a new one */ - Logger.logAction(Logger.LOG_MINOR, 'Auth.getToken()', 'deleting expired token'); + Logger.logAction(this.logger, Logger.LOG_MINOR, 'Auth.getToken()', 'deleting expired token'); this.tokenDetails = null; } const promise = ( - this.waitingForTokenRequest || (this.waitingForTokenRequest = Multicaster.create()) + this.waitingForTokenRequest || (this.waitingForTokenRequest = Multicaster.create(this.logger)) ).createPromise(); if (this.currentTokenRequestId !== null && !forceSupersede) { return promise; @@ -925,6 +947,7 @@ class Auth { if ((this.currentTokenRequestId as number) > tokenRequestId) { Logger.logAction( + this.logger, Logger.LOG_MINOR, 'Auth._ensureValidAuthCredentials()', 'Discarding token request response; overtaken by newer one', @@ -967,7 +990,7 @@ class Auth { * recognise mismatch and return an error */ const msg = 'Unexpected clientId mismatch: client has ' + this.clientId + ', requested ' + clientId; const err = new ErrorInfo(msg, 40102, 401); - Logger.logAction(Logger.LOG_ERROR, 'Auth._uncheckedSetClientId()', msg); + Logger.logAction(this.logger, Logger.LOG_ERROR, 'Auth._uncheckedSetClientId()', msg); return err; } else { /* RSA7a4: if options.clientId is provided and is not diff --git a/src/common/lib/client/baseclient.ts b/src/common/lib/client/baseclient.ts index f4351902a..98a4720f0 100644 --- a/src/common/lib/client/baseclient.ts +++ b/src/common/lib/client/baseclient.ts @@ -44,26 +44,29 @@ class BaseClient { // Extra HTTP request implementations available to this client, in addition to those in web’s Http.bundledRequestImplementations readonly _additionalHTTPRequestImplementations: HTTPRequestImplementations | null; private readonly __FilteredSubscriptions: typeof FilteredSubscriptions | null; + readonly logger: Logger; constructor(options: ClientOptions) { this._additionalHTTPRequestImplementations = options.plugins ?? null; - Logger.setLog(options.logLevel, options.logHandler); + this.logger = new Logger(); + this.logger.setLog(options.logLevel, options.logHandler); Logger.logAction( + this.logger, Logger.LOG_MICRO, 'BaseClient()', 'initialized with clientOptions ' + Platform.Config.inspect(options), ); this._MsgPack = options.plugins?.MsgPack ?? null; - const normalOptions = (this.options = Defaults.normaliseOptions(options, this._MsgPack)); + const normalOptions = (this.options = Defaults.normaliseOptions(options, this._MsgPack, this.logger)); /* process options */ if (normalOptions.key) { const keyMatch = normalOptions.key.match(/^([^:\s]+):([^:.\s]+)$/); if (!keyMatch) { const msg = 'invalid key parameter'; - Logger.logAction(Logger.LOG_ERROR, 'BaseClient()', msg); + Logger.logAction(this.logger, Logger.LOG_ERROR, 'BaseClient()', msg); throw new ErrorInfo(msg, 40400, 404); } normalOptions.keyName = keyMatch[1]; @@ -81,7 +84,7 @@ class BaseClient { ); } - Logger.logAction(Logger.LOG_MINOR, 'BaseClient()', 'started; version = ' + Defaults.version); + Logger.logAction(this.logger, Logger.LOG_MINOR, 'BaseClient()', 'started; version = ' + Defaults.version); this._currentFallback = null; @@ -150,7 +153,7 @@ class BaseClient { } setLog(logOptions: LoggerOptions): void { - Logger.setLog(logOptions.level, logOptions.handler); + this.logger.setLog(logOptions.level, logOptions.handler); } static Platform = Platform; diff --git a/src/common/lib/client/baserealtime.ts b/src/common/lib/client/baserealtime.ts index 6fe106165..953b850f6 100644 --- a/src/common/lib/client/baserealtime.ts +++ b/src/common/lib/client/baserealtime.ts @@ -33,8 +33,8 @@ class BaseRealtime extends BaseClient { * tell the compiler that these cases are possible so that it forces us to handle them. */ constructor(options?: ClientOptions | string) { - super(Defaults.objectifyOptions(options, false, 'BaseRealtime')); - Logger.logAction(Logger.LOG_MINOR, 'Realtime()', ''); + super(Defaults.objectifyOptions(options, false, 'BaseRealtime', Logger.defaultLogger)); + Logger.logAction(this.logger, Logger.LOG_MINOR, 'Realtime()', ''); // currently we cannot support using Ably.Realtime instances in Vercel Edge runtime. // this error can be removed after fixing https://github.com/ably/ably-js/issues/1731, @@ -78,12 +78,12 @@ class BaseRealtime extends BaseClient { } connect(): void { - Logger.logAction(Logger.LOG_MINOR, 'Realtime.connect()', ''); + Logger.logAction(this.logger, Logger.LOG_MINOR, 'Realtime.connect()', ''); this.connection.connect(); } close(): void { - Logger.logAction(Logger.LOG_MINOR, 'Realtime.close()', ''); + Logger.logAction(this.logger, Logger.LOG_MINOR, 'Realtime.close()', ''); this.connection.close(); } } @@ -93,7 +93,7 @@ class Channels extends EventEmitter { all: Record; constructor(realtime: BaseRealtime) { - super(); + super(realtime.logger); this.realtime = realtime; this.all = Object.create(null); realtime.connection.connectionManager.on('transport.active', () => { @@ -125,6 +125,7 @@ class Channels extends EventEmitter { const channelName = msg.channel; if (channelName === undefined) { Logger.logAction( + this.logger, Logger.LOG_ERROR, 'Channels.processChannelMessage()', 'received event unspecified channel, action = ' + msg.action, @@ -134,6 +135,7 @@ class Channels extends EventEmitter { const channel = this.all[channelName]; if (!channel) { Logger.logAction( + this.logger, Logger.LOG_ERROR, 'Channels.processChannelMessage()', 'received event for non-existent channel: ' + channelName, diff --git a/src/common/lib/client/baserest.ts b/src/common/lib/client/baserest.ts index 46137a08c..255d30bd8 100644 --- a/src/common/lib/client/baserest.ts +++ b/src/common/lib/client/baserest.ts @@ -2,6 +2,7 @@ import BaseClient from './baseclient'; import ClientOptions from '../../types/ClientOptions'; import { Rest } from './rest'; import Defaults from '../util/defaults'; +import Logger from '../util/logger'; /** `BaseRest` is an export of the tree-shakable version of the SDK, and acts as the base class for the `DefaultRest` class exported by the non tree-shakable version. @@ -18,6 +19,6 @@ export class BaseRest extends BaseClient { * tell the compiler that these cases are possible so that it forces us to handle them. */ constructor(options?: ClientOptions | string) { - super(Defaults.objectifyOptions(options, false, 'BaseRest', { Rest })); + super(Defaults.objectifyOptions(options, false, 'BaseRest', Logger.defaultLogger, { Rest })); } } diff --git a/src/common/lib/client/connection.ts b/src/common/lib/client/connection.ts index f8f62ad08..5b7013f28 100644 --- a/src/common/lib/client/connection.ts +++ b/src/common/lib/client/connection.ts @@ -16,7 +16,7 @@ class Connection extends EventEmitter { errorReason: ErrorInfo | null; constructor(ably: BaseRealtime, options: NormalisedClientOptions) { - super(); + super(ably.logger); this.ably = ably; this.connectionManager = new ConnectionManager(ably, options); this.state = this.connectionManager.state.state; @@ -42,24 +42,24 @@ class Connection extends EventEmitter { }) as any; connect(): void { - Logger.logAction(Logger.LOG_MINOR, 'Connection.connect()', ''); + Logger.logAction(this.logger, Logger.LOG_MINOR, 'Connection.connect()', ''); this.connectionManager.requestState({ state: 'connecting' }); } async ping(): Promise { - Logger.logAction(Logger.LOG_MINOR, 'Connection.ping()', ''); + Logger.logAction(this.logger, Logger.LOG_MINOR, 'Connection.ping()', ''); return new Promise((resolve, reject) => { this.connectionManager.ping(null, (err: unknown, result: number) => (err ? reject(err) : resolve(result))); }); } close(): void { - Logger.logAction(Logger.LOG_MINOR, 'Connection.close()', 'connectionKey = ' + this.key); + Logger.logAction(this.logger, Logger.LOG_MINOR, 'Connection.close()', 'connectionKey = ' + this.key); this.connectionManager.requestState({ state: 'closing' }); } get recoveryKey(): string | null { - Logger.deprecationWarning( + this.logger.deprecationWarning( 'The `Connection.recoveryKey` attribute has been replaced by the `Connection.createRecoveryKey()` method. Replace your usage of `recoveryKey` with the return value of `createRecoveryKey()`. `recoveryKey` will be removed in a future version.', ); return this.createRecoveryKey(); diff --git a/src/common/lib/client/defaultrealtime.ts b/src/common/lib/client/defaultrealtime.ts index 866a96302..77e3eca41 100644 --- a/src/common/lib/client/defaultrealtime.ts +++ b/src/common/lib/client/defaultrealtime.ts @@ -17,6 +17,7 @@ import { } from '../types/presencemessage'; import { Http } from 'common/types/http'; import Defaults from '../util/defaults'; +import Logger from '../util/logger'; /** `DefaultRealtime` is the class that the non tree-shakable version of the SDK exports as `Realtime`. It ensures that this version of the SDK includes all of the functionality which is optionally available in the tree-shakable version. @@ -30,7 +31,7 @@ export class DefaultRealtime extends BaseRealtime { } super( - Defaults.objectifyOptions(options, true, 'Realtime', { + Defaults.objectifyOptions(options, true, 'Realtime', Logger.defaultLogger, { ...allCommonModularPlugins, Crypto: DefaultRealtime.Crypto ?? undefined, MsgPack, diff --git a/src/common/lib/client/defaultrest.ts b/src/common/lib/client/defaultrest.ts index 110aef6fa..d6aa8b971 100644 --- a/src/common/lib/client/defaultrest.ts +++ b/src/common/lib/client/defaultrest.ts @@ -7,6 +7,7 @@ import { MsgPack } from 'common/types/msgpack'; import { DefaultPresenceMessage } from '../types/defaultpresencemessage'; import { Http } from 'common/types/http'; import Defaults from '../util/defaults'; +import Logger from '../util/logger'; /** `DefaultRest` is the class that the non tree-shakable version of the SDK exports as `Rest`. It ensures that this version of the SDK includes all of the functionality which is optionally available in the tree-shakable version. @@ -20,7 +21,7 @@ export class DefaultRest extends BaseRest { } super( - Defaults.objectifyOptions(options, true, 'Rest', { + Defaults.objectifyOptions(options, true, 'Rest', Logger.defaultLogger, { ...allCommonModularPlugins, Crypto: DefaultRest.Crypto ?? undefined, MsgPack: DefaultRest._MsgPack ?? undefined, diff --git a/src/common/lib/client/paginatedresource.ts b/src/common/lib/client/paginatedresource.ts index 8c2353009..5602c0dc1 100644 --- a/src/common/lib/client/paginatedresource.ts +++ b/src/common/lib/client/paginatedresource.ts @@ -59,6 +59,10 @@ class PaginatedResource { this.useHttpPaginatedResponse = useHttpPaginatedResponse || false; } + get logger(): Logger { + return this.client.logger; + } + async get(params: Record): Promise> { const result = await Resource.get(this.client, this.path, this.headers, params, this.envelope, false); return this.handlePage(result); @@ -87,6 +91,7 @@ class PaginatedResource { async handlePage(result: ResourceResult): Promise> { if (result.err && returnErrOnly(result.err, result.body, this.useHttpPaginatedResponse)) { Logger.logAction( + this.logger, Logger.LOG_ERROR, 'PaginatedResource.handlePage()', 'Unexpected error getting resource: err = ' + Utils.inspectError(result.err), diff --git a/src/common/lib/client/realtimechannel.ts b/src/common/lib/client/realtimechannel.ts index 637c1c508..e0a561492 100644 --- a/src/common/lib/client/realtimechannel.ts +++ b/src/common/lib/client/realtimechannel.ts @@ -99,15 +99,15 @@ class RealtimeChannel extends EventEmitter { retryCount: number = 0; constructor(client: BaseRealtime, name: string, options?: API.ChannelOptions) { - super(); - Logger.logAction(Logger.LOG_MINOR, 'RealtimeChannel()', 'started; name = ' + name); + super(client.logger); + Logger.logAction(this.logger, Logger.LOG_MINOR, 'RealtimeChannel()', 'started; name = ' + name); this.name = name; - this.channelOptions = normaliseChannelOptions(client._Crypto ?? null, options); + this.channelOptions = normaliseChannelOptions(client._Crypto ?? null, this.logger, options); this.client = client; this._presence = client._RealtimePresence ? new client._RealtimePresence.RealtimePresence(this) : null; this.connectionManager = client.connection.connectionManager; this.state = 'initialized'; - this.subscriptions = new EventEmitter(); + this.subscriptions = new EventEmitter(this.logger); this.syncChannelSerial = undefined; this.properties = { attachSerial: undefined, @@ -130,7 +130,7 @@ class RealtimeChannel extends EventEmitter { }; /* Only differences between this and the public event emitter is that this emits an * update event for all ATTACHEDs, whether resumed or not */ - this._allChannelChanges = new EventEmitter(); + this._allChannelChanges = new EventEmitter(this.logger); } invalidStateError(): ErrorInfo { @@ -157,7 +157,7 @@ class RealtimeChannel extends EventEmitter { if (err) { throw err; } - this.channelOptions = normaliseChannelOptions(this.client._Crypto ?? null, options); + this.channelOptions = normaliseChannelOptions(this.client._Crypto ?? null, this.logger, options); if (this._decodingContext) this._decodingContext.channelOptions = this.channelOptions; if (this._shouldReattachToSetOptions(options, previousChannelOptions)) { /* This does not just do _attach(true, null, callback) because that would put us @@ -253,7 +253,7 @@ class RealtimeChannel extends EventEmitter { } _publish(messages: Array, callback: ErrCallback) { - Logger.logAction(Logger.LOG_MICRO, 'RealtimeChannel.publish()', 'message count = ' + messages.length); + Logger.logAction(this.logger, Logger.LOG_MICRO, 'RealtimeChannel.publish()', 'message count = ' + messages.length); const state = this.state; switch (state) { case 'failed': @@ -261,7 +261,12 @@ class RealtimeChannel extends EventEmitter { callback(ErrorInfo.fromValues(this.invalidStateError())); break; default: { - Logger.logAction(Logger.LOG_MICRO, 'RealtimeChannel.publish()', 'sending message; channel state is ' + state); + Logger.logAction( + this.logger, + Logger.LOG_MICRO, + 'RealtimeChannel.publish()', + 'sending message; channel state is ' + state, + ); const msg = new ProtocolMessage(); msg.action = actions.MESSAGE; msg.channel = this.name; @@ -273,7 +278,7 @@ class RealtimeChannel extends EventEmitter { } onEvent(messages: Array): void { - Logger.logAction(Logger.LOG_MICRO, 'RealtimeChannel.onEvent()', 'received message'); + Logger.logAction(this.logger, Logger.LOG_MICRO, 'RealtimeChannel.onEvent()', 'received message'); const subscriptions = this.subscriptions; for (let i = 0; i < messages.length; i++) { const message = messages[i]; @@ -297,9 +302,14 @@ class RealtimeChannel extends EventEmitter { callback?: StandardCallback, ): void { if (!callback) { - callback = function (err?: ErrorInfo | null) { + callback = (err?: ErrorInfo | null) => { if (err) { - Logger.logAction(Logger.LOG_ERROR, 'RealtimeChannel._attach()', 'Channel attach failed: ' + err.toString()); + Logger.logAction( + this.logger, + Logger.LOG_ERROR, + 'RealtimeChannel._attach()', + 'Channel attach failed: ' + err.toString(), + ); } }; } @@ -336,7 +346,7 @@ class RealtimeChannel extends EventEmitter { } attachImpl(): void { - Logger.logAction(Logger.LOG_MICRO, 'RealtimeChannel.attachImpl()', 'sending ATTACH message'); + Logger.logAction(this.logger, Logger.LOG_MICRO, 'RealtimeChannel.attachImpl()', 'sending ATTACH message'); const attachMsg = protocolMessageFromValues({ action: actions.ATTACH, channel: this.name, @@ -401,7 +411,7 @@ class RealtimeChannel extends EventEmitter { } detachImpl(callback?: ErrCallback): void { - Logger.logAction(Logger.LOG_MICRO, 'RealtimeChannel.detach()', 'sending DETACH message'); + Logger.logAction(this.logger, Logger.LOG_MICRO, 'RealtimeChannel.detach()', 'sending DETACH message'); const msg = protocolMessageFromValues({ action: actions.DETACH, channel: this.name }); this.sendMessage(msg, callback || noop); } @@ -562,7 +572,12 @@ class RealtimeChannel extends EventEmitter { if (!presenceMsg.timestamp) presenceMsg.timestamp = timestamp; if (!presenceMsg.id) presenceMsg.id = id + ':' + i; } catch (e) { - Logger.logAction(Logger.LOG_ERROR, 'RealtimeChannel.processMessage()', (e as Error).toString()); + Logger.logAction( + this.logger, + Logger.LOG_ERROR, + 'RealtimeChannel.processMessage()', + (e as Error).toString(), + ); } } if (this._presence) { @@ -574,6 +589,7 @@ class RealtimeChannel extends EventEmitter { //RTL17 if (this.state !== 'attached') { Logger.logAction( + this.logger, Logger.LOG_MAJOR, 'RealtimeChannel.processMessage()', 'Message "' + @@ -605,7 +621,7 @@ class RealtimeChannel extends EventEmitter { '" on this channel "' + this.name + '".'; - Logger.logAction(Logger.LOG_ERROR, 'RealtimeChannel.processMessage()', msg); + Logger.logAction(this.logger, Logger.LOG_ERROR, 'RealtimeChannel.processMessage()', msg); this._startDecodeFailureRecovery(new ErrorInfo(msg, 40018, 400)); break; } @@ -616,7 +632,12 @@ class RealtimeChannel extends EventEmitter { await decodeMessage(msg, this._decodingContext); } catch (e) { /* decrypt failed .. the most likely cause is that we have the wrong key */ - Logger.logAction(Logger.LOG_ERROR, 'RealtimeChannel.processMessage()', (e as Error).toString()); + Logger.logAction( + this.logger, + Logger.LOG_ERROR, + 'RealtimeChannel.processMessage()', + (e as Error).toString(), + ); switch ((e as ErrorInfo).code) { case 40018: /* decode failure */ @@ -655,6 +676,7 @@ class RealtimeChannel extends EventEmitter { default: Logger.logAction( + this.logger, Logger.LOG_ERROR, 'RealtimeChannel.processMessage()', 'Fatal protocol error: unrecognised action (' + message.action + ')', @@ -666,6 +688,7 @@ class RealtimeChannel extends EventEmitter { _startDecodeFailureRecovery(reason: ErrorInfo): void { if (!this._lastPayload.decodeFailureRecoveryInProgress) { Logger.logAction( + this.logger, Logger.LOG_MAJOR, 'RealtimeChannel.processMessage()', 'Starting decode failure recovery process.', @@ -678,7 +701,12 @@ class RealtimeChannel extends EventEmitter { } onAttached(): void { - Logger.logAction(Logger.LOG_MINOR, 'RealtimeChannel.onAttached', 'activating channel; name = ' + this.name); + Logger.logAction( + this.logger, + Logger.LOG_MINOR, + 'RealtimeChannel.onAttached', + 'activating channel; name = ' + this.name, + ); } notifyState( @@ -689,6 +717,7 @@ class RealtimeChannel extends EventEmitter { hasBacklog?: boolean, ): void { Logger.logAction( + this.logger, Logger.LOG_MICRO, 'RealtimeChannel.notifyState', 'name = ' + this.name + ', current state = ' + this.state + ', notifying state ' + state, @@ -718,9 +747,9 @@ class RealtimeChannel extends EventEmitter { const action = 'Channel state for channel "' + this.name + '"'; const message = state + (reason ? '; reason: ' + reason : ''); if (state === 'failed') { - Logger.logAction(Logger.LOG_ERROR, action, message); + Logger.logAction(this.logger, Logger.LOG_ERROR, action, message); } else { - Logger.logAction(Logger.LOG_MAJOR, action, message); + Logger.logAction(this.logger, Logger.LOG_MAJOR, action, message); } if (state !== 'attaching' && state !== 'suspended') { @@ -744,7 +773,12 @@ class RealtimeChannel extends EventEmitter { } requestState(state: API.ChannelState, reason?: ErrorInfo | null): void { - Logger.logAction(Logger.LOG_MINOR, 'RealtimeChannel.requestState', 'name = ' + this.name + ', state = ' + state); + Logger.logAction( + this.logger, + Logger.LOG_MINOR, + 'RealtimeChannel.requestState', + 'name = ' + this.name + ', state = ' + state, + ); this.notifyState(state, reason); /* send the event and await response */ this.checkPendingState(); @@ -755,6 +789,7 @@ class RealtimeChannel extends EventEmitter { const cmState = this.connectionManager.state; if (!cmState.sendEvents) { Logger.logAction( + this.logger, Logger.LOG_MINOR, 'RealtimeChannel.checkPendingState', 'sendEvents is false; state is ' + this.connectionManager.state.state, @@ -763,6 +798,7 @@ class RealtimeChannel extends EventEmitter { } Logger.logAction( + this.logger, Logger.LOG_MINOR, 'RealtimeChannel.checkPendingState', 'name = ' + this.name + ', state = ' + this.state, @@ -807,7 +843,7 @@ class RealtimeChannel extends EventEmitter { startStateTimerIfNotRunning(): void { if (!this.stateTimer) { this.stateTimer = setTimeout(() => { - Logger.logAction(Logger.LOG_MINOR, 'RealtimeChannel.startStateTimerIfNotRunning', 'timer expired'); + Logger.logAction(this.logger, Logger.LOG_MINOR, 'RealtimeChannel.startStateTimerIfNotRunning', 'timer expired'); this.stateTimer = null; this.timeoutPendingState(); }, this.client.options.timeouts.realtimeRequestTimeout); @@ -833,7 +869,12 @@ class RealtimeChannel extends EventEmitter { * will be triggered once it connects again */ if (this.state === 'suspended' && this.connectionManager.state.sendEvents) { this.retryTimer = null; - Logger.logAction(Logger.LOG_MINOR, 'RealtimeChannel retry timer expired', 'attempting a new attach'); + Logger.logAction( + this.logger, + Logger.LOG_MINOR, + 'RealtimeChannel retry timer expired', + 'attempting a new attach', + ); this.requestState('attaching'); } }, retryDelay); @@ -850,7 +891,7 @@ class RealtimeChannel extends EventEmitter { this: RealtimeChannel, params: RealtimeHistoryParams | null, ): Promise> { - Logger.logAction(Logger.LOG_MICRO, 'RealtimeChannel.history()', 'channel = ' + this.name); + Logger.logAction(this.logger, Logger.LOG_MICRO, 'RealtimeChannel.history()', 'channel = ' + this.name); // We fetch this first so that any plugin-not-provided error takes priority over other errors const restMixin = this.client.rest.channelMixin; @@ -893,6 +934,7 @@ class RealtimeChannel extends EventEmitter { setChannelSerial(channelSerial?: string | null): void { Logger.logAction( + this.logger, Logger.LOG_MICRO, 'RealtimeChannel.setChannelSerial()', 'Updating channel serial; serial = ' + channelSerial + '; previous = ' + this.properties.channelSerial, diff --git a/src/common/lib/client/realtimepresence.ts b/src/common/lib/client/realtimepresence.ts index 612438aab..ef02e8e78 100644 --- a/src/common/lib/client/realtimepresence.ts +++ b/src/common/lib/client/realtimepresence.ts @@ -91,13 +91,13 @@ class RealtimePresence extends EventEmitter { name?: string; constructor(channel: RealtimeChannel) { - super(); + super(channel.logger); this.channel = channel; this.syncComplete = false; this.members = new PresenceMap(this, (item) => item.clientId + ':' + item.connectionId); // RTP17h: Store own members by clientId only. this._myMembers = new PresenceMap(this, (item) => item.clientId!); - this.subscriptions = new EventEmitter(); + this.subscriptions = new EventEmitter(this.logger); this.pendingPresence = []; } @@ -135,6 +135,7 @@ class RealtimePresence extends EventEmitter { } Logger.logAction( + this.logger, Logger.LOG_MICRO, 'RealtimePresence.' + action + 'Client()', 'channel = ' + channel.name + ', id = ' + id + ', client = ' + (clientId || '(implicit) ' + getClientId(this)), @@ -191,6 +192,7 @@ class RealtimePresence extends EventEmitter { } Logger.logAction( + this.logger, Logger.LOG_MICRO, 'RealtimePresence.leaveClient()', 'leaving; channel = ' + this.channel.name + ', client = ' + clientId, @@ -268,7 +270,7 @@ class RealtimePresence extends EventEmitter { } async history(params: RealtimeHistoryParams | null): Promise> { - Logger.logAction(Logger.LOG_MICRO, 'RealtimePresence.history()', 'channel = ' + this.name); + Logger.logAction(this.logger, Logger.LOG_MICRO, 'RealtimePresence.history()', 'channel = ' + this.name); // We fetch this first so that any plugin-not-provided error takes priority over other errors const restMixin = this.channel.client.rest.presenceMixin; @@ -290,6 +292,7 @@ class RealtimePresence extends EventEmitter { setPresence(presenceSet: PresenceMessage[], isSync: boolean, syncChannelSerial?: string): void { Logger.logAction( + this.logger, Logger.LOG_MICRO, 'RealtimePresence.setPresence()', 'received presence for ' + presenceSet.length + ' participants; syncChannelSerial = ' + syncChannelSerial, @@ -345,6 +348,7 @@ class RealtimePresence extends EventEmitter { onAttached(hasPresence?: boolean): void { Logger.logAction( + this.logger, Logger.LOG_MINOR, 'RealtimePresence.onAttached()', 'channel = ' + this.channel.name + ', hasPresence = ' + hasPresence, @@ -367,8 +371,9 @@ class RealtimePresence extends EventEmitter { if (pendingPresCount) { this.pendingPresence = []; const presenceArray = []; - const multicaster = Multicaster.create(); + const multicaster = Multicaster.create(this.logger); Logger.logAction( + this.logger, Logger.LOG_MICRO, 'RealtimePresence.onAttached', 'sending ' + pendingPresCount + ' queued presence messages', @@ -401,6 +406,7 @@ class RealtimePresence extends EventEmitter { failPendingPresence(err?: ErrorInfo | null): void { if (this.pendingPresence.length) { Logger.logAction( + this.logger, Logger.LOG_MINOR, 'RealtimeChannel.failPendingPresence', 'channel; name = ' + this.channel.name + ', err = ' + Utils.inspectError(err), @@ -424,7 +430,7 @@ class RealtimePresence extends EventEmitter { if (err) { const msg = 'Presence auto-re-enter failed: ' + err.toString(); const wrappedErr = new ErrorInfo(msg, 91004, 400); - Logger.logAction(Logger.LOG_ERROR, 'RealtimePresence._ensureMyMembersPresent()', msg); + Logger.logAction(this.logger, Logger.LOG_ERROR, 'RealtimePresence._ensureMyMembersPresent()', msg); const change = new ChannelStateChange(this.channel.state, this.channel.state, true, false, wrappedErr); this.channel.emit('update', change); } @@ -433,6 +439,7 @@ class RealtimePresence extends EventEmitter { for (const memberKey in myMembers.map) { const entry = myMembers.map[memberKey]; Logger.logAction( + this.logger, Logger.LOG_MICRO, 'RealtimePresence._ensureMyMembersPresent()', 'Auto-reentering clientId "' + entry.clientId + '" into the presence set', @@ -488,7 +495,7 @@ class PresenceMap extends EventEmitter { memberKey: (item: PresenceMessage) => string; constructor(presence: RealtimePresence, memberKey: (item: PresenceMessage) => string) { - super(); + super(presence.logger); this.presence = presence; this.map = Object.create(null); this.syncInProgress = false; @@ -580,6 +587,7 @@ class PresenceMap extends EventEmitter { const map = this.map, syncInProgress = this.syncInProgress; Logger.logAction( + this.logger, Logger.LOG_MINOR, 'PresenceMap.startSync()', 'channel = ' + this.presence.channel.name + '; syncInProgress = ' + syncInProgress, @@ -595,6 +603,7 @@ class PresenceMap extends EventEmitter { const map = this.map, syncInProgress = this.syncInProgress; Logger.logAction( + this.logger, Logger.LOG_MINOR, 'PresenceMap.endSync()', 'channel = ' + this.presence.channel.name + '; syncInProgress = ' + syncInProgress, @@ -625,6 +634,7 @@ class PresenceMap extends EventEmitter { waitSync(callback: () => void) { const syncInProgress = this.syncInProgress; Logger.logAction( + this.logger, Logger.LOG_MINOR, 'PresenceMap.waitSync()', 'channel = ' + this.presence.channel.name + '; syncInProgress = ' + syncInProgress, @@ -643,7 +653,7 @@ class PresenceMap extends EventEmitter { } setInProgress(inProgress: boolean) { - Logger.logAction(Logger.LOG_MICRO, 'PresenceMap.setInProgress()', 'inProgress = ' + inProgress); + Logger.logAction(this.logger, Logger.LOG_MICRO, 'PresenceMap.setInProgress()', 'inProgress = ' + inProgress); this.syncInProgress = inProgress; this.presence.syncComplete = !inProgress; } diff --git a/src/common/lib/client/resource.ts b/src/common/lib/client/resource.ts index c5aba126c..186abf1b6 100644 --- a/src/common/lib/client/resource.ts +++ b/src/common/lib/client/resource.ts @@ -75,15 +75,23 @@ function unenvelope( return { err: result.err, body: response, headers: wrappedHeaders, unpacked: true, statusCode: wrappedStatusCode }; } -function logResult(result: ResourceResult, method: HttpMethods, path: string, params: Record) { +function logResult( + result: ResourceResult, + method: HttpMethods, + path: string, + params: Record, + logger: Logger, +) { if (result.err) { Logger.logAction( + logger, Logger.LOG_MICRO, 'Resource.' + method + '()', 'Received Error; ' + urlFromPathAndParams(path, params) + '; Error: ' + Utils.inspectError(result.err), ); } else { Logger.logAction( + logger, Logger.LOG_MICRO, 'Resource.' + method + '()', 'Received; ' + @@ -298,12 +306,14 @@ class Resource { (params = params || {})['envelope'] = envelope; } + const logger = client.logger; + async function doRequest( this: any, headers: Record, params: Record, ): Promise> { - if (Logger.shouldLog(Logger.LOG_MICRO)) { + if (logger.shouldLog(Logger.LOG_MICRO)) { let decodedBody = body; if (headers['content-type']?.indexOf('msgpack') > 0) { try { @@ -313,6 +323,7 @@ class Resource { decodedBody = client._MsgPack.decode(body as Buffer); } catch (decodeErr) { Logger.logAction( + logger, Logger.LOG_MICRO, 'Resource.' + method + '()', 'Sending MsgPack Decoding Error: ' + Utils.inspectError(decodeErr), @@ -320,6 +331,7 @@ class Resource { } } Logger.logAction( + logger, Logger.LOG_MICRO, 'Resource.' + method + '()', 'Sending; ' + urlFromPathAndParams(path, params) + '; Body: ' + decodedBody, @@ -350,8 +362,8 @@ class Resource { result = unenvelope(result, client._MsgPack, envelope); } - if (Logger.shouldLog(Logger.LOG_MICRO)) { - logResult(result, method, path, params); + if (logger.shouldLog(Logger.LOG_MICRO)) { + logResult(result, method, path, params, logger); } if (throwError) { diff --git a/src/common/lib/client/restchannel.ts b/src/common/lib/client/restchannel.ts index 71ac07ea0..ff086a9db 100644 --- a/src/common/lib/client/restchannel.ts +++ b/src/common/lib/client/restchannel.ts @@ -34,19 +34,23 @@ class RestChannel { channelOptions: ChannelOptions; constructor(client: BaseRest, name: string, channelOptions?: ChannelOptions) { - Logger.logAction(Logger.LOG_MINOR, 'RestChannel()', 'started; name = ' + name); + Logger.logAction(client.logger, Logger.LOG_MINOR, 'RestChannel()', 'started; name = ' + name); this.name = name; this.client = client; this.presence = new RestPresence(this); - this.channelOptions = normaliseChannelOptions(client._Crypto ?? null, channelOptions); + this.channelOptions = normaliseChannelOptions(client._Crypto ?? null, this.logger, channelOptions); + } + + get logger(): Logger { + return this.client.logger; } setOptions(options?: ChannelOptions): void { - this.channelOptions = normaliseChannelOptions(this.client._Crypto ?? null, options); + this.channelOptions = normaliseChannelOptions(this.client._Crypto ?? null, this.logger, options); } async history(params: RestHistoryParams | null): Promise> { - Logger.logAction(Logger.LOG_MICRO, 'RestChannel.history()', 'channel = ' + this.name); + Logger.logAction(this.logger, Logger.LOG_MICRO, 'RestChannel.history()', 'channel = ' + this.name); return this.client.rest.channelMixin.history(this, params); } diff --git a/src/common/lib/client/restchannelmixin.ts b/src/common/lib/client/restchannelmixin.ts index 26695c8c1..c104d66be 100644 --- a/src/common/lib/client/restchannelmixin.ts +++ b/src/common/lib/client/restchannelmixin.ts @@ -36,7 +36,13 @@ export class RestChannelMixin { headers, unpacked, ) { - return await messageFromResponseBody(body as Message[], options, client._MsgPack, unpacked ? undefined : format); + return await messageFromResponseBody( + body as Message[], + options, + channel.logger, + client._MsgPack, + unpacked ? undefined : format, + ); }).get(params as Record); } diff --git a/src/common/lib/client/restpresence.ts b/src/common/lib/client/restpresence.ts index 470752443..3ce4e142a 100644 --- a/src/common/lib/client/restpresence.ts +++ b/src/common/lib/client/restpresence.ts @@ -13,8 +13,12 @@ class RestPresence { this.channel = channel; } + get logger(): Logger { + return this.channel.logger; + } + async get(params: any): Promise> { - Logger.logAction(Logger.LOG_MICRO, 'RestPresence.get()', 'channel = ' + this.channel.name); + Logger.logAction(this.logger, Logger.LOG_MICRO, 'RestPresence.get()', 'channel = ' + this.channel.name); const client = this.channel.client, format = client.options.useBinaryProtocol ? Utils.Format.msgpack : Utils.Format.json, envelope = this.channel.client.http.supportsLinkHeaders ? undefined : format, @@ -28,10 +32,11 @@ class RestPresence { this.channel.client.rest.presenceMixin.basePath(this), headers, envelope, - async function (body, headers, unpacked) { + async (body, headers, unpacked) => { return await presenceMessageFromResponseBody( body as Record[], options as CipherOptions, + this.logger, client._MsgPack, unpacked ? undefined : format, ); @@ -40,7 +45,7 @@ class RestPresence { } async history(params: any): Promise> { - Logger.logAction(Logger.LOG_MICRO, 'RestPresence.history()', 'channel = ' + this.channel.name); + Logger.logAction(this.logger, Logger.LOG_MICRO, 'RestPresence.history()', 'channel = ' + this.channel.name); return this.channel.client.rest.presenceMixin.history(this, params); } } diff --git a/src/common/lib/client/restpresencemixin.ts b/src/common/lib/client/restpresencemixin.ts index c42f725a5..f0b2cca37 100644 --- a/src/common/lib/client/restpresencemixin.ts +++ b/src/common/lib/client/restpresencemixin.ts @@ -32,6 +32,7 @@ export class RestPresenceMixin { return await presenceMessageFromResponseBody( body as Record[], options as CipherOptions, + presence.logger, client._MsgPack, unpacked ? undefined : format, ); diff --git a/src/common/lib/transport/comettransport.ts b/src/common/lib/transport/comettransport.ts index 4ecf0d147..ab468b6cc 100644 --- a/src/common/lib/transport/comettransport.ts +++ b/src/common/lib/transport/comettransport.ts @@ -73,7 +73,7 @@ abstract class CometTransport extends Transport { ): IXHRRequest; connect(): void { - Logger.logAction(Logger.LOG_MINOR, 'CometTransport.connect()', 'starting'); + Logger.logAction(this.logger, Logger.LOG_MINOR, 'CometTransport.connect()', 'starting'); Transport.prototype.connect.call(this); const params = this.params; const options = params.options; @@ -83,7 +83,7 @@ abstract class CometTransport extends Transport { this.baseUri = cometScheme + host + ':' + port + '/comet/'; const connectUri = this.baseUri + 'connect'; - Logger.logAction(Logger.LOG_MINOR, 'CometTransport.connect()', 'uri: ' + connectUri); + Logger.logAction(this.logger, Logger.LOG_MINOR, 'CometTransport.connect()', 'uri: ' + connectUri); Utils.whenPromiseSettles(this.auth.getAuthParams(), (err: Error | null, authParams?: Record) => { if (err) { this.disconnect(err); @@ -96,6 +96,7 @@ abstract class CometTransport extends Transport { const connectParams = this.params.getConnectParams(authParams!); if ('stream' in connectParams) this.stream = connectParams.stream; Logger.logAction( + this.logger, Logger.LOG_MINOR, 'CometTransport.connect()', 'connectParams:' + Utils.toQueryString(connectParams), @@ -157,12 +158,12 @@ abstract class CometTransport extends Transport { } requestClose(): void { - Logger.logAction(Logger.LOG_MINOR, 'CometTransport.requestClose()'); + Logger.logAction(this.logger, Logger.LOG_MINOR, 'CometTransport.requestClose()'); this._requestCloseOrDisconnect(true); } requestDisconnect(): void { - Logger.logAction(Logger.LOG_MINOR, 'CometTransport.requestDisconnect()'); + Logger.logAction(this.logger, Logger.LOG_MINOR, 'CometTransport.requestDisconnect()'); this._requestCloseOrDisconnect(false); } @@ -174,6 +175,7 @@ abstract class CometTransport extends Transport { request.on('complete', (err: ErrorInfo) => { if (err) { Logger.logAction( + this.logger, Logger.LOG_ERROR, 'CometTransport.request' + (closing ? 'Close()' : 'Disconnect()'), 'request returned err = ' + Utils.inspectError(err), @@ -186,11 +188,11 @@ abstract class CometTransport extends Transport { } dispose(): void { - Logger.logAction(Logger.LOG_MINOR, 'CometTransport.dispose()', ''); + Logger.logAction(this.logger, Logger.LOG_MINOR, 'CometTransport.dispose()', ''); if (!this.isDisposed) { this.isDisposed = true; if (this.recvRequest) { - Logger.logAction(Logger.LOG_MINOR, 'CometTransport.dispose()', 'aborting recv request'); + Logger.logAction(this.logger, Logger.LOG_MINOR, 'CometTransport.dispose()', 'aborting recv request'); this.recvRequest.abort(); this.recvRequest = null; } @@ -215,7 +217,7 @@ abstract class CometTransport extends Transport { Transport.prototype.onConnect.call(this, message); const baseConnectionUri = (this.baseUri as string) + connectionStr; - Logger.logAction(Logger.LOG_MICRO, 'CometTransport.onConnect()', 'baseUri = ' + baseConnectionUri); + Logger.logAction(this.logger, Logger.LOG_MICRO, 'CometTransport.onConnect()', 'baseUri = ' + baseConnectionUri); this.sendUri = baseConnectionUri + '/send'; this.recvUri = baseConnectionUri + '/recv'; this.closeUri = baseConnectionUri + '/close'; @@ -260,6 +262,7 @@ abstract class CometTransport extends Transport { sendRequest.on('complete', (err: ErrorInfo, data: string) => { if (err) Logger.logAction( + this.logger, Logger.LOG_ERROR, 'CometTransport.sendItems()', 'on complete: err = ' + Utils.inspectError(err), @@ -354,6 +357,7 @@ abstract class CometTransport extends Transport { ); } catch (e) { Logger.logAction( + this.logger, Logger.LOG_ERROR, 'CometTransport.onData()', 'Unexpected exception handing channel event: ' + (e as Error).stack, diff --git a/src/common/lib/transport/connectionmanager.ts b/src/common/lib/transport/connectionmanager.ts index 4403adc46..420fa4e71 100644 --- a/src/common/lib/transport/connectionmanager.ts +++ b/src/common/lib/transport/connectionmanager.ts @@ -211,7 +211,7 @@ class ConnectionManager extends EventEmitter { connectCounter: number; constructor(realtime: BaseRealtime, options: NormalisedClientOptions) { - super(); + super(realtime.logger); this.realtime = realtime; this.initTransports(); this.options = options; @@ -273,7 +273,7 @@ class ConnectionManager extends EventEmitter { this.state = this.states.initialized; this.errorReason = null; - this.queuedMessages = new MessageQueue(); + this.queuedMessages = new MessageQueue(this.logger); this.msgSerial = 0; this.connectionDetails = undefined; this.connectionId = undefined; @@ -306,22 +306,29 @@ class ConnectionManager extends EventEmitter { this.webSocketGiveUpTimer = null; this.abandonedWebSocket = false; - Logger.logAction(Logger.LOG_MINOR, 'Realtime.ConnectionManager()', 'started'); + Logger.logAction(this.logger, Logger.LOG_MINOR, 'Realtime.ConnectionManager()', 'started'); Logger.logAction( + this.logger, Logger.LOG_MICRO, 'Realtime.ConnectionManager()', 'requested transports = [' + (options.transports || Defaults.defaultTransports) + ']', ); Logger.logAction( + this.logger, Logger.LOG_MICRO, 'Realtime.ConnectionManager()', 'available transports = [' + this.transports + ']', ); - Logger.logAction(Logger.LOG_MICRO, 'Realtime.ConnectionManager()', 'http hosts = [' + this.httpHosts + ']'); + Logger.logAction( + this.logger, + Logger.LOG_MICRO, + 'Realtime.ConnectionManager()', + 'http hosts = [' + this.httpHosts + ']', + ); if (!this.transports.length) { const msg = 'no requested transports available'; - Logger.logAction(Logger.LOG_ERROR, 'realtime.ConnectionManager()', msg); + Logger.logAction(this.logger, Logger.LOG_ERROR, 'realtime.ConnectionManager()', msg); throw new Error(msg); } @@ -335,6 +342,7 @@ class ConnectionManager extends EventEmitter { if (options.closeOnUnload === true) { addEventListener('beforeunload', () => { Logger.logAction( + this.logger, Logger.LOG_MAJOR, 'Realtime.ConnectionManager()', 'beforeunload event has triggered the connection to close as closeOnUnload is true', @@ -347,6 +355,7 @@ class ConnectionManager extends EventEmitter { addEventListener('online', () => { if (this.state == this.states.disconnected || this.state == this.states.suspended) { Logger.logAction( + this.logger, Logger.LOG_MINOR, 'ConnectionManager caught browser ‘online’ event', 'reattempting connection', @@ -364,6 +373,7 @@ class ConnectionManager extends EventEmitter { addEventListener('offline', () => { if (this.state == this.states.connected) { Logger.logAction( + this.logger, Logger.LOG_MINOR, 'ConnectionManager caught browser ‘offline’ event', 'disconnecting active transport', @@ -424,6 +434,7 @@ class ConnectionManager extends EventEmitter { sessionRecoveryName = this.sessionRecoveryName(); if (lastSessionData && typeof recoverFn === 'function') { Logger.logAction( + this.logger, Logger.LOG_MINOR, 'ConnectionManager.getTransportParams()', 'Calling clientOptions-provided recover function with last session data (recovery scope: ' + @@ -447,6 +458,7 @@ class ConnectionManager extends EventEmitter { const transportParams = this.createTransportParams(null, mode); if (mode === 'recover') { Logger.logAction( + this.logger, Logger.LOG_MINOR, 'ConnectionManager.getTransportParams()', 'Transport recovery mode = recover; recoveryKey = ' + this.options.recover, @@ -457,6 +469,7 @@ class ConnectionManager extends EventEmitter { } } else { Logger.logAction( + this.logger, Logger.LOG_MINOR, 'ConnectionManager.getTransportParams()', 'Transport params = ' + transportParams.toString(), @@ -473,7 +486,7 @@ class ConnectionManager extends EventEmitter { * @param callback */ tryATransport(transportParams: TransportParams, candidate: TransportName, callback: Function): void { - Logger.logAction(Logger.LOG_MICRO, 'ConnectionManager.tryATransport()', 'trying ' + candidate); + Logger.logAction(this.logger, Logger.LOG_MICRO, 'ConnectionManager.tryATransport()', 'trying ' + candidate); this.proposedTransport = Transport.tryConnect( this.supportedTransports[candidate]!, @@ -485,6 +498,7 @@ class ConnectionManager extends EventEmitter { if (state == this.states.closing || state == this.states.closed || state == this.states.failed) { if (transport) { Logger.logAction( + this.logger, Logger.LOG_MINOR, 'ConnectionManager.tryATransport()', 'connection ' + state.state + ' while we were attempting the transport; closing ' + transport, @@ -497,6 +511,7 @@ class ConnectionManager extends EventEmitter { if (wrappedErr) { Logger.logAction( + this.logger, Logger.LOG_MINOR, 'ConnectionManager.tryATransport()', 'transport ' + candidate + ' ' + wrappedErr.event + ', err: ' + wrappedErr.error.toString(), @@ -536,6 +551,7 @@ class ConnectionManager extends EventEmitter { } Logger.logAction( + this.logger, Logger.LOG_MICRO, 'ConnectionManager.tryATransport()', 'viable transport ' + candidate + '; setting pending', @@ -555,6 +571,7 @@ class ConnectionManager extends EventEmitter { setTransportPending(transport: Transport, transportParams: TransportParams): void { const mode = transportParams.mode; Logger.logAction( + this.logger, Logger.LOG_MINOR, 'ConnectionManager.setTransportPending()', 'transport = ' + transport + '; mode = ' + mode, @@ -598,15 +615,26 @@ class ConnectionManager extends EventEmitter { connectionId: string, connectionDetails: Record, ): boolean { - Logger.logAction(Logger.LOG_MINOR, 'ConnectionManager.activateTransport()', 'transport = ' + transport); + Logger.logAction( + this.logger, + Logger.LOG_MINOR, + 'ConnectionManager.activateTransport()', + 'transport = ' + transport, + ); if (error) { - Logger.logAction(Logger.LOG_ERROR, 'ConnectionManager.activateTransport()', 'error = ' + error); + Logger.logAction(this.logger, Logger.LOG_ERROR, 'ConnectionManager.activateTransport()', 'error = ' + error); } if (connectionId) { - Logger.logAction(Logger.LOG_MICRO, 'ConnectionManager.activateTransport()', 'connectionId = ' + connectionId); + Logger.logAction( + this.logger, + Logger.LOG_MICRO, + 'ConnectionManager.activateTransport()', + 'connectionId = ' + connectionId, + ); } if (connectionDetails) { Logger.logAction( + this.logger, Logger.LOG_MICRO, 'ConnectionManager.activateTransport()', 'connectionDetails = ' + JSON.stringify(connectionDetails), @@ -620,6 +648,7 @@ class ConnectionManager extends EventEmitter { const existingState = this.state, connectedState = this.states.connected.state; Logger.logAction( + this.logger, Logger.LOG_MINOR, 'ConnectionManager.activateTransport()', 'current state = ' + existingState.state, @@ -630,6 +659,7 @@ class ConnectionManager extends EventEmitter { existingState.state == this.states.failed.state ) { Logger.logAction( + this.logger, Logger.LOG_MINOR, 'ConnectionManager.activateTransport()', 'Disconnecting transport and abandoning', @@ -643,6 +673,7 @@ class ConnectionManager extends EventEmitter { /* if the transport is not connected then don't activate it */ if (!transport.isConnected) { Logger.logAction( + this.logger, Logger.LOG_MINOR, 'ConnectionManager.activateTransport()', 'Declining to activate transport ' + transport + ' since it appears to no longer be connected', @@ -701,6 +732,7 @@ class ConnectionManager extends EventEmitter { * from other active transports when upgrading, and upgrading waits for * the old transport to be idle. So log an error. */ Logger.logAction( + this.logger, Logger.LOG_ERROR, 'ConnectionManager.activateTransport()', 'Previous active protocol (for transport ' + @@ -718,7 +750,7 @@ class ConnectionManager extends EventEmitter { transport.shortName + '; stack = ' + new Error().stack; - Logger.logAction(Logger.LOG_ERROR, 'ConnectionManager.activateTransport()', msg); + Logger.logAction(this.logger, Logger.LOG_ERROR, 'ConnectionManager.activateTransport()', msg); } else { existingActiveProtocol.finish(); } @@ -738,8 +770,14 @@ class ConnectionManager extends EventEmitter { wasPending = transport === this.pendingTransport, noTransportsScheduledForActivation = this.noTransportsScheduledForActivation(); - Logger.logAction(Logger.LOG_MINOR, 'ConnectionManager.deactivateTransport()', 'transport = ' + transport); Logger.logAction( + this.logger, + Logger.LOG_MINOR, + 'ConnectionManager.deactivateTransport()', + 'transport = ' + transport, + ); + Logger.logAction( + this.logger, Logger.LOG_MINOR, 'ConnectionManager.deactivateTransport()', 'state = ' + @@ -748,10 +786,16 @@ class ConnectionManager extends EventEmitter { (noTransportsScheduledForActivation ? '' : '; another transport is scheduled for activation'), ); if (error && error.message) - Logger.logAction(Logger.LOG_MICRO, 'ConnectionManager.deactivateTransport()', 'reason = ' + error.message); + Logger.logAction( + this.logger, + Logger.LOG_MICRO, + 'ConnectionManager.deactivateTransport()', + 'reason = ' + error.message, + ); if (wasActive) { Logger.logAction( + this.logger, Logger.LOG_MICRO, 'ConnectionManager.deactivateTransport()', 'Getting, clearing, and requeuing ' + @@ -823,7 +867,7 @@ class ConnectionManager extends EventEmitter { connIdChanged = prevConnId && prevConnId !== connectionId, recoverFailure = !prevConnId && hasConnectionError; if (connIdChanged || recoverFailure) { - Logger.logAction(Logger.LOG_MINOR, 'ConnectionManager.setConnection()', 'Resetting msgSerial'); + Logger.logAction(this.logger, Logger.LOG_MINOR, 'ConnectionManager.setConnection()', 'Resetting msgSerial'); this.msgSerial = 0; // RTN19a2: In the event of a new connectionId, previous msgSerials are // meaningless. @@ -831,6 +875,7 @@ class ConnectionManager extends EventEmitter { } if (this.connectionId !== connectionId) { Logger.logAction( + this.logger, Logger.LOG_MINOR, 'ConnectionManager.setConnection()', 'New connectionId; reattaching any attached channels', @@ -868,6 +913,7 @@ class ConnectionManager extends EventEmitter { const sinceLast = Date.now() - this.lastActivity; if (sinceLast > this.connectionStateTtl + (this.maxIdleInterval as number)) { Logger.logAction( + this.logger, Logger.LOG_MINOR, 'ConnectionManager.checkConnectionStateFreshness()', 'Last known activity from realtime was ' + sinceLast + 'ms ago; discarding connection state', @@ -931,11 +977,12 @@ class ConnectionManager extends EventEmitter { const action = 'Connection state'; const message = stateChange.current + (stateChange.reason ? '; reason: ' + stateChange.reason : ''); if (stateChange.current === 'failed') { - Logger.logAction(Logger.LOG_ERROR, action, message); + Logger.logAction(this.logger, Logger.LOG_ERROR, action, message); } else { - Logger.logAction(Logger.LOG_MAJOR, action, message); + Logger.logAction(this.logger, Logger.LOG_MAJOR, action, message); } Logger.logAction( + this.logger, Logger.LOG_MINOR, 'ConnectionManager.enactStateChange', 'setting new state: ' + @@ -964,13 +1011,19 @@ class ConnectionManager extends EventEmitter { startTransitionTimer(transitionState: ConnectionState): void { Logger.logAction( + this.logger, Logger.LOG_MINOR, 'ConnectionManager.startTransitionTimer()', 'transitionState: ' + transitionState.state, ); if (this.transitionTimer) { - Logger.logAction(Logger.LOG_MINOR, 'ConnectionManager.startTransitionTimer()', 'clearing already-running timer'); + Logger.logAction( + this.logger, + Logger.LOG_MINOR, + 'ConnectionManager.startTransitionTimer()', + 'clearing already-running timer', + ); clearTimeout(this.transitionTimer as number); } @@ -978,6 +1031,7 @@ class ConnectionManager extends EventEmitter { if (this.transitionTimer) { this.transitionTimer = null; Logger.logAction( + this.logger, Logger.LOG_MINOR, 'ConnectionManager ' + transitionState.state + ' timer expired', 'requesting new state: ' + transitionState.failState, @@ -988,7 +1042,7 @@ class ConnectionManager extends EventEmitter { } cancelTransitionTimer(): void { - Logger.logAction(Logger.LOG_MINOR, 'ConnectionManager.cancelTransitionTimer()', ''); + Logger.logAction(this.logger, Logger.LOG_MINOR, 'ConnectionManager.cancelTransitionTimer()', ''); if (this.transitionTimer) { clearTimeout(this.transitionTimer as number); this.transitionTimer = null; @@ -1001,6 +1055,7 @@ class ConnectionManager extends EventEmitter { if (this.suspendTimer) { this.suspendTimer = null; Logger.logAction( + this.logger, Logger.LOG_MINOR, 'ConnectionManager suspend timer expired', 'requesting new state: suspended', @@ -1025,7 +1080,7 @@ class ConnectionManager extends EventEmitter { startRetryTimer(interval: number): void { this.retryTimer = setTimeout(() => { - Logger.logAction(Logger.LOG_MINOR, 'ConnectionManager retry timer expired', 'retrying'); + Logger.logAction(this.logger, Logger.LOG_MINOR, 'ConnectionManager retry timer expired', 'retrying'); this.retryTimer = null; this.requestState({ state: 'connecting' }); }, interval); @@ -1040,11 +1095,17 @@ class ConnectionManager extends EventEmitter { startWebSocketSlowTimer() { this.webSocketSlowTimer = setTimeout(() => { - Logger.logAction(Logger.LOG_MINOR, 'ConnectionManager WebSocket slow timer', 'checking connectivity'); + Logger.logAction( + this.logger, + Logger.LOG_MINOR, + 'ConnectionManager WebSocket slow timer', + 'checking connectivity', + ); if (this.wsCheckResult === null) { this.checkWsConnectivity() .then(() => { Logger.logAction( + this.logger, Logger.LOG_MINOR, 'ConnectionManager WebSocket slow timer', 'ws connectivity check succeeded', @@ -1053,6 +1114,7 @@ class ConnectionManager extends EventEmitter { }) .catch(() => { Logger.logAction( + this.logger, Logger.LOG_MAJOR, 'ConnectionManager WebSocket slow timer', 'ws connectivity check failed', @@ -1064,6 +1126,7 @@ class ConnectionManager extends EventEmitter { Utils.whenPromiseSettles(this.realtime.http.checkConnectivity(), (err, connectivity) => { if (err || !connectivity) { Logger.logAction( + this.logger, Logger.LOG_MAJOR, 'ConnectionManager WebSocket slow timer', 'http connectivity check failed', @@ -1075,6 +1138,7 @@ class ConnectionManager extends EventEmitter { }); } else { Logger.logAction( + this.logger, Logger.LOG_MINOR, 'ConnectionManager WebSocket slow timer', 'http connectivity check succeeded', @@ -1096,6 +1160,7 @@ class ConnectionManager extends EventEmitter { this.webSocketGiveUpTimer = setTimeout(() => { if (!this.wsCheckResult) { Logger.logAction( + this.logger, Logger.LOG_MINOR, 'ConnectionManager WebSocket give up timer', 'websocket connection took more than 10s; ' + (this.baseTransport ? 'trying base transport' : ''), @@ -1108,6 +1173,7 @@ class ConnectionManager extends EventEmitter { } else { // if we don't have a base transport to fallback to, just let the websocket connection attempt time out Logger.logAction( + this.logger, Logger.LOG_MAJOR, 'ConnectionManager WebSocket give up timer', 'websocket connectivity appears to be unavailable but no other transports to try', @@ -1145,6 +1211,7 @@ class ConnectionManager extends EventEmitter { !(this.errorReason && Auth.isTokenErr(this.errorReason as ErrorInfo)))); Logger.logAction( + this.logger, Logger.LOG_MINOR, 'ConnectionManager.notifyState()', 'new state: ' + state + (retryImmediately ? '; will retry connection immediately' : ''), @@ -1193,6 +1260,7 @@ class ConnectionManager extends EventEmitter { const sinceLast = this.lastAutoReconnectAttempt && Date.now() - this.lastAutoReconnectAttempt + 1; if (sinceLast && sinceLast < 1000) { Logger.logAction( + this.logger, Logger.LOG_MICRO, 'ConnectionManager.notifyState()', 'Last reconnect attempt was only ' + @@ -1221,6 +1289,7 @@ class ConnectionManager extends EventEmitter { if (state == 'connected' && !this.activeProtocol) { Logger.logAction( + this.logger, Logger.LOG_ERROR, 'ConnectionManager.notifyState()', 'Broken invariant: attempted to go into connected state, but there is no active protocol', @@ -1240,6 +1309,7 @@ class ConnectionManager extends EventEmitter { requestState(request: any): void { const state = request.state; Logger.logAction( + this.logger, Logger.LOG_MINOR, 'ConnectionManager.requestState()', 'requested state: ' + state + '; current state: ' + this.state.state, @@ -1281,6 +1351,7 @@ class ConnectionManager extends EventEmitter { startConnect(): void { if (this.state !== this.states.connecting) { Logger.logAction( + this.logger, Logger.LOG_MINOR, 'ConnectionManager.startConnect()', 'Must be in connecting state to connect, but was ' + this.state.state, @@ -1315,7 +1386,7 @@ class ConnectionManager extends EventEmitter { }); }; - Logger.logAction(Logger.LOG_MINOR, 'ConnectionManager.startConnect()', 'starting connection'); + Logger.logAction(this.logger, Logger.LOG_MINOR, 'ConnectionManager.startConnect()', 'starting connection'); this.startSuspendTimer(); this.startTransitionTimer(this.states.connecting); @@ -1364,6 +1435,8 @@ class ConnectionManager extends EventEmitter { * for upgrading). Any operation can put us into 'disconnected' to cancel * connection attempts and wait before retrying, or 'failed' to fail. */ Logger.logAction( + this.logger, + Logger.LOG_MINOR, 'ConnectionManager.connectImpl()', 'Must be in connecting state to connect, but was ' + state, @@ -1382,6 +1455,8 @@ class ConnectionManager extends EventEmitter { this.unpersistTransportPreference(); if (this.state === this.states.connecting) { Logger.logAction( + this.logger, + Logger.LOG_MINOR, 'ConnectionManager.connectImpl():', 'web socket connectivity available, cancelling connection attempt with ' + this.baseTransport, @@ -1417,7 +1492,7 @@ class ConnectionManager extends EventEmitter { * with the transport and fallback to base transport. */ connectWs(transportParams: TransportParams, connectCount: number) { - Logger.logAction(Logger.LOG_DEBUG, 'ConnectionManager.connectWs()'); + Logger.logAction(this.logger, Logger.LOG_DEBUG, 'ConnectionManager.connectWs()'); this.startWebSocketSlowTimer(); this.startWebSocketGiveUpTimer(transportParams); @@ -1427,7 +1502,7 @@ class ConnectionManager extends EventEmitter { } connectBase(transportParams: TransportParams, connectCount: number) { - Logger.logAction(Logger.LOG_DEBUG, 'ConnectionManager.connectBase()'); + Logger.logAction(this.logger, Logger.LOG_DEBUG, 'ConnectionManager.connectBase()'); if (this.baseTransport) { this.tryTransportWithFallbacks(this.baseTransport, transportParams, false, connectCount, () => true); } else { @@ -1445,7 +1520,13 @@ class ConnectionManager extends EventEmitter { connectCount: number, shouldContinue: () => boolean, ): void { - Logger.logAction(Logger.LOG_DEBUG, 'ConnectionManager.tryTransportWithFallbacks()', transportName); + Logger.logAction( + this.logger, + + Logger.LOG_DEBUG, + 'ConnectionManager.tryTransportWithFallbacks()', + transportName, + ); const giveUp = (err: IPartialErrorInfo) => { this.notifyState({ state: this.states.connecting.failState as string, error: err }); }; @@ -1527,12 +1608,14 @@ class ConnectionManager extends EventEmitter { } closeImpl(): void { - Logger.logAction(Logger.LOG_MINOR, 'ConnectionManager.closeImpl()', 'closing connection'); + Logger.logAction(this.logger, Logger.LOG_MINOR, 'ConnectionManager.closeImpl()', 'closing connection'); this.cancelSuspendTimer(); this.startTransitionTimer(this.states.closing); if (this.pendingTransport) { Logger.logAction( + this.logger, + Logger.LOG_MICRO, 'ConnectionManager.closeImpl()', 'Closing pending transport: ' + this.pendingTransport, @@ -1542,6 +1625,8 @@ class ConnectionManager extends EventEmitter { if (this.activeProtocol) { Logger.logAction( + this.logger, + Logger.LOG_MICRO, 'ConnectionManager.closeImpl()', 'Closing active transport: ' + this.activeProtocol.getTransport(), @@ -1558,6 +1643,8 @@ class ConnectionManager extends EventEmitter { switch (this.state.state) { case 'connected': { Logger.logAction( + this.logger, + Logger.LOG_MICRO, 'ConnectionManager.onAuthUpdated()', 'Sending AUTH message on active transport', @@ -1598,6 +1685,8 @@ class ConnectionManager extends EventEmitter { case 'connecting': Logger.logAction( + this.logger, + Logger.LOG_MICRO, 'ConnectionManager.onAuthUpdated()', 'Aborting current connection attempts in order to start again with the new auth details', @@ -1607,6 +1696,8 @@ class ConnectionManager extends EventEmitter { default: { Logger.logAction( + this.logger, + Logger.LOG_MICRO, 'ConnectionManager.onAuthUpdated()', 'Connection state is ' + this.state.state + '; waiting until either connected or failed', @@ -1641,13 +1732,21 @@ class ConnectionManager extends EventEmitter { } disconnectAllTransports(): void { - Logger.logAction(Logger.LOG_MINOR, 'ConnectionManager.disconnectAllTransports()', 'Disconnecting all transports'); + Logger.logAction( + this.logger, + + Logger.LOG_MINOR, + 'ConnectionManager.disconnectAllTransports()', + 'Disconnecting all transports', + ); /* This will prevent any connection procedure in an async part of one of its early stages from continuing */ this.connectCounter++; if (this.pendingTransport) { Logger.logAction( + this.logger, + Logger.LOG_MICRO, 'ConnectionManager.disconnectAllTransports()', 'Disconnecting pending transport: ' + this.pendingTransport, @@ -1658,6 +1757,8 @@ class ConnectionManager extends EventEmitter { if (this.proposedTransport) { Logger.logAction( + this.logger, + Logger.LOG_MICRO, 'ConnectionManager.disconnectAllTransports()', 'Disconnecting proposed transport: ' + this.pendingTransport, @@ -1668,6 +1769,8 @@ class ConnectionManager extends EventEmitter { if (this.activeProtocol) { Logger.logAction( + this.logger, + Logger.LOG_MICRO, 'ConnectionManager.disconnectAllTransports()', 'Disconnecting active transport: ' + this.activeProtocol.getTransport(), @@ -1687,19 +1790,21 @@ class ConnectionManager extends EventEmitter { const state = this.state; if (state.sendEvents) { - Logger.logAction(Logger.LOG_MICRO, 'ConnectionManager.send()', 'sending event'); + Logger.logAction(this.logger, Logger.LOG_MICRO, 'ConnectionManager.send()', 'sending event'); this.sendImpl(new PendingMessage(msg, callback)); return; } const shouldQueue = queueEvent && state.queueEvents; if (!shouldQueue) { const err = 'rejecting event, queueEvent was ' + queueEvent + ', state was ' + state.state; - Logger.logAction(Logger.LOG_MICRO, 'ConnectionManager.send()', err); + Logger.logAction(this.logger, Logger.LOG_MICRO, 'ConnectionManager.send()', err); callback(this.errorReason || new ErrorInfo(err, 90000, 400)); return; } - if (Logger.shouldLog(Logger.LOG_MICRO)) { + if (this.logger.shouldLog(Logger.LOG_MICRO)) { Logger.logAction( + this.logger, + Logger.LOG_MICRO, 'ConnectionManager.send()', 'queueing msg; ' + stringifyProtocolMessage(msg, this.realtime._RealtimePresence), @@ -1719,6 +1824,8 @@ class ConnectionManager extends EventEmitter { (this.activeProtocol as Protocol).send(pendingMessage); } catch (e) { Logger.logAction( + this.logger, + Logger.LOG_ERROR, 'ConnectionManager.sendImpl()', 'Unexpected exception in transport.send(): ' + (e as Error).stack, @@ -1727,7 +1834,7 @@ class ConnectionManager extends EventEmitter { } queue(msg: ProtocolMessage, callback: ErrCallback): void { - Logger.logAction(Logger.LOG_MICRO, 'ConnectionManager.queue()', 'queueing event'); + Logger.logAction(this.logger, Logger.LOG_MICRO, 'ConnectionManager.queue()', 'queueing event'); const lastQueued = this.queuedMessages.last(); const maxSize = this.options.maxMessageSize; /* If have already attempted to send a message, don't merge more messages @@ -1735,7 +1842,7 @@ class ConnectionManager extends EventEmitter { * the dup, they'll be lost */ if (lastQueued && !lastQueued.sendAttempted && bundleWith(lastQueued.message, msg, maxSize)) { if (!lastQueued.merged) { - lastQueued.callback = Multicaster.create([lastQueued.callback]); + lastQueued.callback = Multicaster.create(this.logger, [lastQueued.callback]); lastQueued.merged = true; } (lastQueued.callback as MulticasterInstance).push(callback); @@ -1746,6 +1853,8 @@ class ConnectionManager extends EventEmitter { sendQueuedMessages(): void { Logger.logAction( + this.logger, + Logger.LOG_MICRO, 'ConnectionManager.sendQueuedMessages()', 'sending ' + this.queuedMessages.count() + ' queued messages', @@ -1757,6 +1866,8 @@ class ConnectionManager extends EventEmitter { queuePendingMessages(pendingMessages: Array): void { if (pendingMessages && pendingMessages.length) { Logger.logAction( + this.logger, + Logger.LOG_MICRO, 'ConnectionManager.queuePendingMessages()', 'queueing ' + pendingMessages.length + ' pending messages', @@ -1769,6 +1880,8 @@ class ConnectionManager extends EventEmitter { const numQueued = this.queuedMessages.count(); if (numQueued > 0) { Logger.logAction( + this.logger, + Logger.LOG_ERROR, 'ConnectionManager.failQueuedMessages()', 'failing ' + numQueued + ' queued messages, err = ' + Utils.inspectError(err), @@ -1793,6 +1906,8 @@ class ConnectionManager extends EventEmitter { this.processChannelMessage(pendingChannelMessage.message) .catch((err) => { Logger.logAction( + this.logger, + Logger.LOG_ERROR, 'ConnectionManager.processNextPendingChannelMessage() received error ', err, @@ -1812,7 +1927,7 @@ class ConnectionManager extends EventEmitter { ping(transport: Transport | null, callback: Function): void { /* if transport is specified, try that */ if (transport) { - Logger.logAction(Logger.LOG_MINOR, 'ConnectionManager.ping()', 'transport = ' + transport); + Logger.logAction(this.logger, Logger.LOG_MINOR, 'ConnectionManager.ping()', 'transport = ' + transport); const onTimeout = function () { transport.off('heartbeat', onHeartbeat); @@ -1905,11 +2020,11 @@ class ConnectionManager extends EventEmitter { this.notifyState({ state: 'failed', error: err }); } else if (err.statusCode === HttpStatusCodes.Forbidden) { const msg = 'Client configured authentication provider returned 403; failing the connection'; - Logger.logAction(Logger.LOG_ERROR, 'ConnectionManager.actOnErrorFromAuthorize()', msg); + Logger.logAction(this.logger, Logger.LOG_ERROR, 'ConnectionManager.actOnErrorFromAuthorize()', msg); this.notifyState({ state: 'failed', error: new ErrorInfo(msg, 80019, 403, err) }); } else { const msg = 'Client configured authentication provider request failed'; - Logger.logAction(Logger.LOG_MINOR, 'ConnectionManager.actOnErrorFromAuthorize', msg); + Logger.logAction(this.logger, Logger.LOG_MINOR, 'ConnectionManager.actOnErrorFromAuthorize', msg); this.notifyState({ state: this.state.failState as string, error: new ErrorInfo(msg, 80019, 401, err) }); } } @@ -1926,7 +2041,7 @@ class ConnectionManager extends EventEmitter { if (clientId) { const err = this.realtime.auth._uncheckedSetClientId(clientId); if (err) { - Logger.logAction(Logger.LOG_ERROR, 'ConnectionManager.onConnectionDetailsUpdate()', err.message); + Logger.logAction(this.logger, Logger.LOG_ERROR, 'ConnectionManager.onConnectionDetailsUpdate()', err.message); /* Errors setting the clientId are fatal to the connection */ transport.fail(err); return; diff --git a/src/common/lib/transport/messagequeue.ts b/src/common/lib/transport/messagequeue.ts index 3544e9042..a335a585b 100644 --- a/src/common/lib/transport/messagequeue.ts +++ b/src/common/lib/transport/messagequeue.ts @@ -6,8 +6,8 @@ import { PendingMessage } from './protocol'; class MessageQueue extends EventEmitter { messages: Array; - constructor() { - super(); + constructor(logger: Logger) { + super(logger); this.messages = []; } @@ -40,7 +40,12 @@ class MessageQueue extends EventEmitter { } completeMessages(serial: number, count: number, err?: ErrorInfo | null): void { - Logger.logAction(Logger.LOG_MICRO, 'MessageQueue.completeMessages()', 'serial = ' + serial + '; count = ' + count); + Logger.logAction( + this.logger, + Logger.LOG_MICRO, + 'MessageQueue.completeMessages()', + 'serial = ' + serial + '; count = ' + count, + ); err = err || null; const messages = this.messages; if (messages.length === 0) { @@ -71,7 +76,12 @@ class MessageQueue extends EventEmitter { } clear(): void { - Logger.logAction(Logger.LOG_MICRO, 'MessageQueue.clear()', 'clearing ' + this.messages.length + ' messages'); + Logger.logAction( + this.logger, + Logger.LOG_MICRO, + 'MessageQueue.clear()', + 'clearing ' + this.messages.length + ' messages', + ); this.messages = []; this.emit('idle'); } diff --git a/src/common/lib/transport/protocol.ts b/src/common/lib/transport/protocol.ts index ee396767a..cb91a1db2 100644 --- a/src/common/lib/transport/protocol.ts +++ b/src/common/lib/transport/protocol.ts @@ -29,9 +29,9 @@ class Protocol extends EventEmitter { messageQueue: MessageQueue; constructor(transport: Transport) { - super(); + super(transport.logger); this.transport = transport; - this.messageQueue = new MessageQueue(); + this.messageQueue = new MessageQueue(this.logger); transport.on('ack', (serial: number, count: number) => { this.onAck(serial, count); }); @@ -41,12 +41,13 @@ class Protocol extends EventEmitter { } onAck(serial: number, count: number): void { - Logger.logAction(Logger.LOG_MICRO, 'Protocol.onAck()', 'serial = ' + serial + '; count = ' + count); + Logger.logAction(this.logger, Logger.LOG_MICRO, 'Protocol.onAck()', 'serial = ' + serial + '; count = ' + count); this.messageQueue.completeMessages(serial, count); } onNack(serial: number, count: number, err: ErrorInfo): void { Logger.logAction( + this.logger, Logger.LOG_ERROR, 'Protocol.onNack()', 'serial = ' + serial + '; count = ' + count + '; err = ' + Utils.inspectError(err), @@ -70,8 +71,9 @@ class Protocol extends EventEmitter { if (pendingMessage.ackRequired) { this.messageQueue.push(pendingMessage); } - if (Logger.shouldLog(Logger.LOG_MICRO)) { + if (this.logger.shouldLog(Logger.LOG_MICRO)) { Logger.logActionNoStrip( + this.logger, Logger.LOG_MICRO, 'Protocol.send()', 'sending msg; ' + diff --git a/src/common/lib/transport/transport.ts b/src/common/lib/transport/transport.ts index 78a173688..23ad1ec05 100644 --- a/src/common/lib/transport/transport.ts +++ b/src/common/lib/transport/transport.ts @@ -58,7 +58,7 @@ abstract class Transport extends EventEmitter { lastActivity: number | null; constructor(connectionManager: ConnectionManager, auth: Auth, params: TransportParams, forceJsonProtocol?: boolean) { - super(); + super(connectionManager.logger); if (forceJsonProtocol) { params.format = undefined; params.heartbeats = true; @@ -120,8 +120,9 @@ abstract class Transport extends EventEmitter { } onProtocolMessage(message: ProtocolMessage): void { - if (Logger.shouldLog(Logger.LOG_MICRO)) { + if (this.logger.shouldLog(Logger.LOG_MICRO)) { Logger.logActionNoStrip( + this.logger, Logger.LOG_MICRO, 'Transport.onProtocolMessage()', 'received on ' + @@ -137,6 +138,7 @@ abstract class Transport extends EventEmitter { switch (message.action) { case actions.HEARTBEAT: Logger.logActionNoStrip( + this.logger, Logger.LOG_MICRO, 'Transport.onProtocolMessage()', this.shortName + ' heartbeat; connectionId = ' + this.connectionManager.connectionId, @@ -166,9 +168,10 @@ abstract class Transport extends EventEmitter { // Ignored. break; case actions.AUTH: - Utils.whenPromiseSettles(this.auth.authorize(), function (err: ErrorInfo | null) { + Utils.whenPromiseSettles(this.auth.authorize(), (err: ErrorInfo | null) => { if (err) { Logger.logAction( + this.logger, Logger.LOG_ERROR, 'Transport.onProtocolMessage()', 'Ably requested re-authentication, but unable to obtain a new token: ' + Utils.inspectError(err), @@ -178,6 +181,7 @@ abstract class Transport extends EventEmitter { break; case actions.ERROR: Logger.logAction( + this.logger, Logger.LOG_MINOR, 'Transport.onProtocolMessage()', 'received error action; connectionId = ' + @@ -216,7 +220,7 @@ abstract class Transport extends EventEmitter { /* Used for when the server has disconnected the client (usually with a * DISCONNECTED action) */ const err = message && message.error; - Logger.logAction(Logger.LOG_MINOR, 'Transport.onDisconnect()', 'err = ' + Utils.inspectError(err)); + Logger.logAction(this.logger, Logger.LOG_MINOR, 'Transport.onDisconnect()', 'err = ' + Utils.inspectError(err)); this.finish('disconnected', err); } @@ -225,23 +229,23 @@ abstract class Transport extends EventEmitter { * will close the connection and the transport, and do not need to request * a disconnection - RTN15i */ const err = message && message.error; - Logger.logAction(Logger.LOG_MINOR, 'Transport.onFatalError()', 'err = ' + Utils.inspectError(err)); + Logger.logAction(this.logger, Logger.LOG_MINOR, 'Transport.onFatalError()', 'err = ' + Utils.inspectError(err)); this.finish('failed', err); } onClose(message: ProtocolMessage): void { const err = message && message.error; - Logger.logAction(Logger.LOG_MINOR, 'Transport.onClose()', 'err = ' + Utils.inspectError(err)); + Logger.logAction(this.logger, Logger.LOG_MINOR, 'Transport.onClose()', 'err = ' + Utils.inspectError(err)); this.finish('closed', err); } requestClose(): void { - Logger.logAction(Logger.LOG_MINOR, 'Transport.requestClose()', ''); + Logger.logAction(this.logger, Logger.LOG_MINOR, 'Transport.requestClose()', ''); this.send(closeMessage); } requestDisconnect(): void { - Logger.logAction(Logger.LOG_MINOR, 'Transport.requestDisconnect()', ''); + Logger.logAction(this.logger, Logger.LOG_MINOR, 'Transport.requestDisconnect()', ''); this.send(disconnectMessage); } @@ -252,7 +256,7 @@ abstract class Transport extends EventEmitter { } dispose(): void { - Logger.logAction(Logger.LOG_MINOR, 'Transport.dispose()', ''); + Logger.logAction(this.logger, Logger.LOG_MINOR, 'Transport.dispose()', ''); this.isDisposed = true; this.off(); } @@ -282,7 +286,7 @@ abstract class Transport extends EventEmitter { const timeRemaining = this.maxIdleInterval - sinceLast; if (timeRemaining <= 0) { const msg = 'No activity seen from realtime in ' + sinceLast + 'ms; assuming connection has dropped'; - Logger.logAction(Logger.LOG_ERROR, 'Transport.onIdleTimerExpire()', msg); + Logger.logAction(this.logger, Logger.LOG_ERROR, 'Transport.onIdleTimerExpire()', msg); this.disconnect(new ErrorInfo(msg, 80003, 408)); } else { this.setIdleTimer(timeRemaining + 100); @@ -317,7 +321,12 @@ abstract class Transport extends EventEmitter { transport.on(['failed', 'disconnected'], errorCb); transport.on('preconnect', function () { - Logger.logAction(Logger.LOG_MINOR, 'Transport.tryConnect()', 'viable transport ' + transport); + Logger.logAction( + connectionManager.logger, + Logger.LOG_MINOR, + 'Transport.tryConnect()', + 'viable transport ' + transport, + ); clearTimeout(transportAttemptTimer); transport.off(['failed', 'disconnected'], errorCb); callback(null, transport); diff --git a/src/common/lib/transport/websockettransport.ts b/src/common/lib/transport/websockettransport.ts index 0efe0eba0..3e12f1d67 100644 --- a/src/common/lib/transport/websockettransport.ts +++ b/src/common/lib/transport/websockettransport.ts @@ -46,14 +46,14 @@ class WebSocketTransport extends Transport { } connect() { - Logger.logAction(Logger.LOG_MINOR, 'WebSocketTransport.connect()', 'starting'); + Logger.logAction(this.logger, Logger.LOG_MINOR, 'WebSocketTransport.connect()', 'starting'); Transport.prototype.connect.call(this); const self = this, params = this.params, options = params.options; const wsScheme = options.tls ? 'wss://' : 'ws://'; const wsUri = wsScheme + this.wsHost + ':' + Defaults.getPort(options) + '/'; - Logger.logAction(Logger.LOG_MINOR, 'WebSocketTransport.connect()', 'uri: ' + wsUri); + Logger.logAction(this.logger, Logger.LOG_MINOR, 'WebSocketTransport.connect()', 'uri: ' + wsUri); Utils.whenPromiseSettles( this.auth.getAuthParams(), function (err: ErrorInfo | null, authParams?: Record) { @@ -62,7 +62,12 @@ class WebSocketTransport extends Transport { } let paramStr = ''; for (const param in authParams) paramStr += ' ' + param + ': ' + authParams[param] + ';'; - Logger.logAction(Logger.LOG_MINOR, 'WebSocketTransport.connect()', 'authParams:' + paramStr + ' err: ' + err); + Logger.logAction( + self.logger, + Logger.LOG_MINOR, + 'WebSocketTransport.connect()', + 'authParams:' + paramStr + ' err: ' + err, + ); if (err) { self.disconnect(err); return; @@ -92,6 +97,7 @@ class WebSocketTransport extends Transport { } } catch (e) { Logger.logAction( + self.logger, Logger.LOG_ERROR, 'WebSocketTransport.connect()', 'Unexpected exception creating websocket: err = ' + ((e as Error).stack || (e as Error).message), @@ -105,7 +111,7 @@ class WebSocketTransport extends Transport { send(message: ProtocolMessage) { const wsConnection = this.wsConnection; if (!wsConnection) { - Logger.logAction(Logger.LOG_ERROR, 'WebSocketTransport.send()', 'No socket connection'); + Logger.logAction(this.logger, Logger.LOG_ERROR, 'WebSocketTransport.send()', 'No socket connection'); return; } try { @@ -114,7 +120,7 @@ class WebSocketTransport extends Transport { ); } catch (e) { const msg = 'Exception from ws connection when trying to send: ' + Utils.inspectError(e); - Logger.logAction(Logger.LOG_ERROR, 'WebSocketTransport.send()', msg); + Logger.logAction(this.logger, Logger.LOG_ERROR, 'WebSocketTransport.send()', msg); /* Don't try to request a disconnect, that'll just involve sending data * down the websocket again. Just finish the transport. */ this.finish('disconnected', new ErrorInfo(msg, 50000, 500)); @@ -123,6 +129,7 @@ class WebSocketTransport extends Transport { onWsData(data: string) { Logger.logAction( + this.logger, Logger.LOG_MICRO, 'WebSocketTransport.onWsData()', 'data received; length = ' + data.length + '; type = ' + typeof data, @@ -138,6 +145,7 @@ class WebSocketTransport extends Transport { ); } catch (e) { Logger.logAction( + this.logger, Logger.LOG_ERROR, 'WebSocketTransport.onWsData()', 'Unexpected exception handing channel message: ' + (e as Error).stack, @@ -146,7 +154,7 @@ class WebSocketTransport extends Transport { } onWsOpen() { - Logger.logAction(Logger.LOG_MINOR, 'WebSocketTransport.onWsOpen()', 'opened WebSocket'); + Logger.logAction(this.logger, Logger.LOG_MINOR, 'WebSocketTransport.onWsOpen()', 'opened WebSocket'); this.emit('preconnect'); } @@ -164,20 +172,25 @@ class WebSocketTransport extends Transport { } delete this.wsConnection; if (wasClean) { - Logger.logAction(Logger.LOG_MINOR, 'WebSocketTransport.onWsClose()', 'Cleanly closed WebSocket'); + Logger.logAction(this.logger, Logger.LOG_MINOR, 'WebSocketTransport.onWsClose()', 'Cleanly closed WebSocket'); const err = new ErrorInfo('Websocket closed', 80003, 400); this.finish('disconnected', err); } else { const msg = 'Unclean disconnection of WebSocket ; code = ' + code, err = new ErrorInfo(msg, 80003, 400); - Logger.logAction(Logger.LOG_MINOR, 'WebSocketTransport.onWsClose()', msg); + Logger.logAction(this.logger, Logger.LOG_MINOR, 'WebSocketTransport.onWsClose()', msg); this.finish('disconnected', err); } this.emit('disposed'); } onWsError(err: ErrorEvent) { - Logger.logAction(Logger.LOG_MINOR, 'WebSocketTransport.onError()', 'Error from WebSocket: ' + err.message); + Logger.logAction( + this.logger, + Logger.LOG_MINOR, + 'WebSocketTransport.onError()', + 'Error from WebSocket: ' + err.message, + ); /* Wait a tick before aborting: if the websocket was connected, this event * will be immediately followed by an onclose event with a close code. Allow * that to close it (so we see the close code) rather than anticipating it */ @@ -187,7 +200,7 @@ class WebSocketTransport extends Transport { } dispose() { - Logger.logAction(Logger.LOG_MINOR, 'WebSocketTransport.dispose()', ''); + Logger.logAction(this.logger, Logger.LOG_MINOR, 'WebSocketTransport.dispose()', ''); this.isDisposed = true; const wsConnection = this.wsConnection; if (wsConnection) { @@ -198,8 +211,8 @@ class WebSocketTransport extends Transport { delete this.wsConnection; /* defer until the next event loop cycle before closing the socket, * giving some implementations the opportunity to send any outstanding close message */ - Platform.Config.nextTick(function () { - Logger.logAction(Logger.LOG_MICRO, 'WebSocketTransport.dispose()', 'closing websocket'); + Platform.Config.nextTick(() => { + Logger.logAction(this.logger, Logger.LOG_MICRO, 'WebSocketTransport.dispose()', 'closing websocket'); if (!wsConnection) { throw new Error('WebSocketTransport.dispose(): wsConnection is not defined'); } diff --git a/src/common/lib/types/defaultmessage.ts b/src/common/lib/types/defaultmessage.ts index 286ceeef5..dfc4a02b1 100644 --- a/src/common/lib/types/defaultmessage.ts +++ b/src/common/lib/types/defaultmessage.ts @@ -10,17 +10,18 @@ import * as API from '../../../../ably'; import Platform from 'common/platform'; import PresenceMessage from './presencemessage'; import { ChannelOptions } from 'common/types/channel'; +import Logger from '../util/logger'; /** `DefaultMessage` is the class returned by `DefaultRest` and `DefaultRealtime`’s `Message` static property. It introduces the static methods described in the `MessageStatic` interface of the public API of the non tree-shakable version of the library. */ export class DefaultMessage extends Message { static async fromEncoded(encoded: unknown, inputOptions?: API.ChannelOptions): Promise { - return fromEncoded(Platform.Crypto, encoded, inputOptions); + return fromEncoded(Logger.defaultLogger, Platform.Crypto, encoded, inputOptions); } static async fromEncodedArray(encodedArray: Array, options?: API.ChannelOptions): Promise { - return fromEncodedArray(Platform.Crypto, encodedArray, options); + return fromEncodedArray(Logger.defaultLogger, Platform.Crypto, encodedArray, options); } // Used by tests diff --git a/src/common/lib/types/defaultpresencemessage.ts b/src/common/lib/types/defaultpresencemessage.ts index d6639af31..1b8592c3e 100644 --- a/src/common/lib/types/defaultpresencemessage.ts +++ b/src/common/lib/types/defaultpresencemessage.ts @@ -1,4 +1,5 @@ import * as API from '../../../../ably'; +import Logger from '../util/logger'; import PresenceMessage, { fromEncoded, fromEncodedArray, fromValues } from './presencemessage'; /** @@ -6,14 +7,14 @@ import PresenceMessage, { fromEncoded, fromEncodedArray, fromValues } from './pr */ export class DefaultPresenceMessage extends PresenceMessage { static async fromEncoded(encoded: unknown, inputOptions?: API.ChannelOptions): Promise { - return fromEncoded(encoded, inputOptions); + return fromEncoded(Logger.defaultLogger, encoded, inputOptions); } static async fromEncodedArray( encodedArray: Array, options?: API.ChannelOptions, ): Promise { - return fromEncodedArray(encodedArray, options); + return fromEncodedArray(Logger.defaultLogger, encodedArray, options); } static fromValues(values: PresenceMessage | Record, stringifyAction?: boolean): PresenceMessage { diff --git a/src/common/lib/types/message.ts b/src/common/lib/types/message.ts index f1c44cb26..7cc8b80ac 100644 --- a/src/common/lib/types/message.ts +++ b/src/common/lib/types/message.ts @@ -45,11 +45,12 @@ function normaliseContext(context: CipherOptions | EncodingDecodingContext | Cha function normalizeCipherOptions( Crypto: IUntypedCryptoStatic | null, + logger: Logger, options: API.ChannelOptions | null, ): ChannelOptions { if (options && options.cipher) { if (!Crypto) Utils.throwMissingPluginError('Crypto'); - const cipher = Crypto.getCipher(options.cipher); + const cipher = Crypto.getCipher(options.cipher, logger); return { cipher: cipher.cipherParams, channelCipher: cipher.cipher, @@ -76,30 +77,32 @@ function getMessageSize(msg: Message) { } export async function fromEncoded( + logger: Logger, Crypto: IUntypedCryptoStatic | null, encoded: unknown, inputOptions?: API.ChannelOptions, ): Promise { const msg = fromValues(encoded); - const options = normalizeCipherOptions(Crypto, inputOptions ?? null); + const options = normalizeCipherOptions(Crypto, logger, inputOptions ?? null); /* if decoding fails at any point, catch and return the message decoded to * the fullest extent possible */ try { await decode(msg, options); } catch (e) { - Logger.logAction(Logger.LOG_ERROR, 'Message.fromEncoded()', (e as Error).toString()); + Logger.logAction(logger, Logger.LOG_ERROR, 'Message.fromEncoded()', (e as Error).toString()); } return msg; } export async function fromEncodedArray( + logger: Logger, Crypto: IUntypedCryptoStatic | null, encodedArray: Array, options?: API.ChannelOptions, ): Promise { return Promise.all( encodedArray.map(function (encoded) { - return fromEncoded(Crypto, encoded, options); + return fromEncoded(logger, Crypto, encoded, options); }), ); } @@ -248,6 +251,7 @@ export async function decode( export async function fromResponseBody( body: Array, options: ChannelOptions | EncodingDecodingContext, + logger: Logger, MsgPack: MsgPack | null, format?: Utils.Format, ): Promise { @@ -260,7 +264,7 @@ export async function fromResponseBody( try { await decode(msg, options); } catch (e) { - Logger.logAction(Logger.LOG_ERROR, 'Message.fromResponseBody()', (e as Error).toString()); + Logger.logAction(logger, Logger.LOG_ERROR, 'Message.fromResponseBody()', (e as Error).toString()); } } return body; diff --git a/src/common/lib/types/presencemessage.ts b/src/common/lib/types/presencemessage.ts index 5cb1b690c..34e0d2d06 100644 --- a/src/common/lib/types/presencemessage.ts +++ b/src/common/lib/types/presencemessage.ts @@ -11,25 +11,30 @@ function toActionValue(actionString: string) { return actions.indexOf(actionString); } -export async function fromEncoded(encoded: unknown, options?: API.ChannelOptions): Promise { +export async function fromEncoded( + logger: Logger, + encoded: unknown, + options?: API.ChannelOptions, +): Promise { const msg = fromValues(encoded as PresenceMessage | Record, true); /* if decoding fails at any point, catch and return the message decoded to * the fullest extent possible */ try { await decode(msg, options ?? {}); } catch (e) { - Logger.logAction(Logger.LOG_ERROR, 'PresenceMessage.fromEncoded()', (e as Error).toString()); + Logger.logAction(logger, Logger.LOG_ERROR, 'PresenceMessage.fromEncoded()', (e as Error).toString()); } return msg; } export async function fromEncodedArray( + logger: Logger, encodedArray: unknown[], options?: API.ChannelOptions, ): Promise { return Promise.all( encodedArray.map(function (encoded) { - return fromEncoded(encoded, options); + return fromEncoded(logger, encoded, options); }), ); } @@ -50,6 +55,7 @@ export const decode = decodeMessage; export async function fromResponseBody( body: Record[], options: CipherOptions, + logger: Logger, MsgPack: MsgPack | null, format?: Utils.Format, ): Promise { @@ -63,7 +69,7 @@ export async function fromResponseBody( try { await decode(msg, options); } catch (e) { - Logger.logAction(Logger.LOG_ERROR, 'PresenceMessage.fromResponseBody()', (e as Error).toString()); + Logger.logAction(logger, Logger.LOG_ERROR, 'PresenceMessage.fromResponseBody()', (e as Error).toString()); } } return messages; diff --git a/src/common/lib/util/defaults.ts b/src/common/lib/util/defaults.ts index a8b818dbf..1ab3386a2 100644 --- a/src/common/lib/util/defaults.ts +++ b/src/common/lib/util/defaults.ts @@ -48,9 +48,10 @@ type CompleteDefaults = IDefaults & { options: undefined | ClientOptions | string, allowKeyOrToken: boolean, sourceForErrorMessage: string, + logger: Logger, modularPluginsToInclude?: ModularPlugins, ): ClientOptions; - normaliseOptions(options: ClientOptions, MsgPack: MsgPack | null): NormalisedClientOptions; + normaliseOptions(options: ClientOptions, MsgPack: MsgPack | null, logger: Logger | null): NormalisedClientOptions; defaultGetHeaders(options: NormalisedClientOptions, headersOptions?: HeadersOptions): Record; defaultPostHeaders(options: NormalisedClientOptions, headersOptions?: HeadersOptions): Record; }; @@ -151,12 +152,13 @@ function checkHost(host: string): void { } } -function getRealtimeHost(options: ClientOptions, production: boolean, environment: string): string { +function getRealtimeHost(options: ClientOptions, production: boolean, environment: string, logger: Logger): string { if (options.realtimeHost) return options.realtimeHost; /* prefer setting realtimeHost to restHost as a custom restHost typically indicates * a development environment is being used that can't be inferred by the library */ if (options.restHost) { Logger.logAction( + logger, Logger.LOG_MINOR, 'Defaults.normaliseOptions', 'restHost is set to "' + @@ -193,13 +195,14 @@ export function objectifyOptions( options: undefined | ClientOptions | string, allowKeyOrToken: boolean, sourceForErrorMessage: string, + logger: Logger, modularPluginsToInclude?: ModularPlugins, ): ClientOptions { if (options === undefined) { const msg = allowKeyOrToken ? `${sourceForErrorMessage} must be initialized with either a client options object, an Ably API key, or an Ably Token` : `${sourceForErrorMessage} must be initialized with a client options object`; - Logger.logAction(Logger.LOG_ERROR, `${sourceForErrorMessage}()`, msg); + Logger.logAction(logger, Logger.LOG_ERROR, `${sourceForErrorMessage}()`, msg); throw new Error(msg); } @@ -209,7 +212,7 @@ export function objectifyOptions( if (options.indexOf(':') == -1) { if (!allowKeyOrToken) { const msg = `${sourceForErrorMessage} cannot be initialized with just an Ably Token; you must provide a client options object with a \`plugins\` property. (Set this Ably Token as the object’s \`token\` property.)`; - Logger.logAction(Logger.LOG_ERROR, `${sourceForErrorMessage}()`, msg); + Logger.logAction(logger, Logger.LOG_ERROR, `${sourceForErrorMessage}()`, msg); throw new Error(msg); } @@ -217,7 +220,7 @@ export function objectifyOptions( } else { if (!allowKeyOrToken) { const msg = `${sourceForErrorMessage} cannot be initialized with just an Ably API key; you must provide a client options object with a \`plugins\` property. (Set this Ably API key as the object’s \`key\` property.)`; - Logger.logAction(Logger.LOG_ERROR, `${sourceForErrorMessage}()`, msg); + Logger.logAction(logger, Logger.LOG_ERROR, `${sourceForErrorMessage}()`, msg); throw new Error(msg); } @@ -234,9 +237,16 @@ export function objectifyOptions( return optionsObj; } -export function normaliseOptions(options: ClientOptions, MsgPack: MsgPack | null): NormalisedClientOptions { +export function normaliseOptions( + options: ClientOptions, + MsgPack: MsgPack | null, + logger: Logger | null, // should only be omitted by tests +): NormalisedClientOptions { + const loggerToUse = logger ?? Logger.defaultLogger; + if (typeof options.recover === 'function' && options.closeOnUnload === true) { Logger.logAction( + loggerToUse, Logger.LOG_ERROR, 'Defaults.normaliseOptions', 'closeOnUnload was true and a session recovery function was set - these are mutually exclusive, so unsetting the latter', @@ -261,7 +271,7 @@ export function normaliseOptions(options: ClientOptions, MsgPack: MsgPack | null } const restHost = options.restHost || (production ? Defaults.REST_HOST : environment + '-' + Defaults.REST_HOST); - const realtimeHost = getRealtimeHost(options, production, environment); + const realtimeHost = getRealtimeHost(options, production, environment, loggerToUse); (options.fallbackHosts || []).concat(restHost, realtimeHost).forEach(checkHost); @@ -313,11 +323,11 @@ export function normaliseOptions(options: ClientOptions, MsgPack: MsgPack | null }; } -export function normaliseChannelOptions(Crypto: IUntypedCryptoStatic | null, options?: ChannelOptions) { +export function normaliseChannelOptions(Crypto: IUntypedCryptoStatic | null, logger: Logger, options?: ChannelOptions) { const channelOptions = options || {}; if (channelOptions.cipher) { if (!Crypto) Utils.throwMissingPluginError('Crypto'); - const cipher = Crypto.getCipher(channelOptions.cipher); + const cipher = Crypto.getCipher(channelOptions.cipher, logger); channelOptions.cipher = cipher.cipherParams; channelOptions.channelCipher = cipher.cipher; } else if ('cipher' in channelOptions) { diff --git a/src/common/lib/util/eventemitter.ts b/src/common/lib/util/eventemitter.ts index 830962ddd..4c7fef0c9 100644 --- a/src/common/lib/util/eventemitter.ts +++ b/src/common/lib/util/eventemitter.ts @@ -3,11 +3,12 @@ import Logger from './logger'; import Platform from 'common/platform'; /* Call the listener, catch any exceptions and log, but continue operation*/ -function callListener(eventThis: { event: string }, listener: Function, args: unknown[]) { +function callListener(logger: Logger, eventThis: { event: string }, listener: Function, args: unknown[]) { try { listener.apply(eventThis, args); } catch (e) { Logger.logAction( + logger, Logger.LOG_ERROR, 'EventEmitter.emit()', 'Unexpected listener exception: ' + e + '; stack = ' + (e && (e as Error).stack), @@ -58,7 +59,7 @@ class EventEmitter { anyOnce: Array; eventsOnce: Record>; - constructor() { + constructor(readonly logger: Logger) { this.any = []; this.events = Object.create(null); this.anyOnce = []; @@ -215,8 +216,8 @@ class EventEmitter { Array.prototype.push.apply(listeners, eventsListeners); } - listeners.forEach(function (listener) { - callListener(eventThis, listener, args); + listeners.forEach((listener) => { + callListener(this.logger, eventThis, listener, args); }); } diff --git a/src/common/lib/util/logger.ts b/src/common/lib/util/logger.ts index 84b743a67..579e0012b 100644 --- a/src/common/lib/util/logger.ts +++ b/src/common/lib/util/logger.ts @@ -65,9 +65,13 @@ const getDefaultLoggers = (): [Function, Function] => { }; class Logger { - private static logLevel: LogLevels = LogLevels.Error; // default logLevel - private static logHandler: Function; - private static logErrorHandler: Function; + private static defaultLogLevel: LogLevels = LogLevels.Error; + private static defaultLogHandler: Function; + private static defaultLogErrorHandler: Function; + + private logLevel: LogLevels; + private logHandler: Function; + private logErrorHandler: Function; // public constants static readonly LOG_NONE: LogLevels = LogLevels.None; @@ -76,17 +80,24 @@ class Logger { static readonly LOG_MINOR: LogLevels = LogLevels.Minor; static readonly LOG_MICRO: LogLevels = LogLevels.Micro; // aliases - static readonly LOG_DEFAULT: LogLevels = LogLevels.Error; static readonly LOG_DEBUG: LogLevels = LogLevels.Micro; - constructor() { - Logger.logLevel = Logger.LOG_DEFAULT; - } + /** + * This logger instance should only be used when there is no more appropriate logger to use, for example when implementing a public static method or function whose API doesn’t accept any logging configuration. + */ + static defaultLogger: Logger; static initLogHandlers() { const [logHandler, logErrorHandler] = getDefaultLoggers(); - this.logHandler = logHandler; - this.logErrorHandler = logErrorHandler; + this.defaultLogHandler = logHandler; + this.defaultLogErrorHandler = logErrorHandler; + this.defaultLogger = new Logger(); + } + + constructor() { + this.logLevel = Logger.defaultLogLevel; + this.logHandler = Logger.defaultLogHandler; + this.logErrorHandler = Logger.defaultLogErrorHandler; } /* public static functions */ @@ -95,50 +106,54 @@ class Logger { * * The aforementioned plugin expects `level` to be an expression of the form `Logger.LOG_*`; that is, you can’t dynamically specify the log level. */ - static logAction = (level: LogLevels, action: string, message?: string) => { - this.logActionNoStrip(level, action, message); + static logAction = (logger: Logger, level: LogLevels, action: string, message?: string) => { + this.logActionNoStrip(logger, level, action, message); }; /** * Calls to this method are never stripped by the `stripLogs` esbuild plugin. Use it for log statements that you wish to always be included in the modular variant of the SDK. */ - static logActionNoStrip(level: LogLevels, action: string, message?: string) { - if (Logger.shouldLog(level)) { - (level === LogLevels.Error ? Logger.logErrorHandler : Logger.logHandler)('Ably: ' + action + ': ' + message); + static logActionNoStrip(logger: Logger, level: LogLevels, action: string, message?: string) { + logger.logAction(level, action, message); + } + + private logAction(level: LogLevels, action: string, message?: string) { + if (this.shouldLog(level)) { + (level === LogLevels.Error ? this.logErrorHandler : this.logHandler)('Ably: ' + action + ': ' + message); } } - static deprecated = (description: string, msg: string) => { - Logger.deprecationWarning(`${description} is deprecated and will be removed in a future version. ${msg}`); + deprecated = (description: string, msg: string) => { + this.deprecationWarning(`${description} is deprecated and will be removed in a future version. ${msg}`); }; - static renamedClientOption(oldName: string, newName: string) { - Logger.deprecationWarning( + renamedClientOption(oldName: string, newName: string) { + this.deprecationWarning( `The \`${oldName}\` client option has been renamed to \`${newName}\`. Please update your code to use \`${newName}\` instead. \`${oldName}\` will be removed in a future version.`, ); } - static renamedMethod(className: string, oldName: string, newName: string) { - Logger.deprecationWarning( + renamedMethod(className: string, oldName: string, newName: string) { + this.deprecationWarning( `\`${className}\`’s \`${oldName}\` method has been renamed to \`${newName}\`. Please update your code to use \`${newName}\` instead. \`${oldName}\` will be removed in a future version.`, ); } - static deprecationWarning(message: string) { - if (Logger.shouldLog(LogLevels.Error)) { - Logger.logErrorHandler(`Ably: Deprecation warning - ${message}`); + deprecationWarning(message: string) { + if (this.shouldLog(LogLevels.Error)) { + this.logErrorHandler(`Ably: Deprecation warning - ${message}`); } } /* Where a logging operation is expensive, such as serialisation of data, use shouldLog will prevent the object being serialised if the log level will not output the message */ - static shouldLog = (level: LogLevels) => { - return level <= Logger.logLevel; + shouldLog = (level: LogLevels) => { + return level <= this.logLevel; }; - static setLog = (level: LogLevels | undefined, handler: Function | undefined) => { - if (level !== undefined) Logger.logLevel = level; - if (handler !== undefined) Logger.logHandler = Logger.logErrorHandler = handler; + setLog = (level: LogLevels | undefined, handler: Function | undefined) => { + if (level !== undefined) this.logLevel = level; + if (handler !== undefined) this.logHandler = this.logErrorHandler = handler; }; } diff --git a/src/common/lib/util/multicaster.ts b/src/common/lib/util/multicaster.ts index bf5c32c64..494b04d92 100644 --- a/src/common/lib/util/multicaster.ts +++ b/src/common/lib/util/multicaster.ts @@ -23,7 +23,7 @@ class Multicaster { members: Array>; // Private constructor; use static Multicaster.create instead - private constructor(members?: Array | undefined>) { + private constructor(private readonly logger: Logger, members?: Array | undefined>) { this.members = (members as Array>) || []; } @@ -34,6 +34,7 @@ class Multicaster { member(err, result); } catch (e) { Logger.logAction( + this.logger, Logger.LOG_ERROR, 'Multicaster multiple callback handler', 'Unexpected exception: ' + e + '; stack = ' + (e as Error).stack, @@ -63,8 +64,8 @@ class Multicaster { this.call(err); } - static create(members?: Array | undefined>): MulticasterInstance { - const instance = new Multicaster(members); + static create(logger: Logger, members?: Array | undefined>): MulticasterInstance { + const instance = new Multicaster(logger, members); return Object.assign((err?: ErrorInfo | null, result?: T) => instance.call(err, result), { push: (fn: StandardCallback) => instance.push(fn), createPromise: () => instance.createPromise(), diff --git a/src/common/types/ICryptoStatic.ts b/src/common/types/ICryptoStatic.ts index 38648449c..31ff8a369 100644 --- a/src/common/types/ICryptoStatic.ts +++ b/src/common/types/ICryptoStatic.ts @@ -1,5 +1,6 @@ import * as API from '../../../ably'; import ICipher from './ICipher'; +import Logger from '../../common/lib/util/logger'; export type IGetCipherParams = (API.CipherParams | API.CipherParamOptions) & { iv?: IV }; export interface IGetCipherReturnValue { @@ -11,6 +12,7 @@ export default interface ICryptoStatic, + logger: Logger, ): IGetCipherReturnValue>; } @@ -19,5 +21,5 @@ export default interface ICryptoStatic | null) return uri + (params ? '?' : '') + paramString(params); } -function logResult(result: RequestResult, method: HttpMethods, uri: string, params: Record | null) { +function logResult( + result: RequestResult, + method: HttpMethods, + uri: string, + params: Record | null, + logger: Logger, +) { if (result.error) { Logger.logActionNoStrip( + logger, Logger.LOG_MICRO, 'Http.' + method + '()', 'Received Error; ' + appendingParams(uri, params) + '; Error: ' + Utils.inspectError(result.error), ); } else { Logger.logActionNoStrip( + logger, Logger.LOG_MICRO, 'Http.' + method + '()', 'Received; ' + @@ -97,9 +105,10 @@ function logResult(result: RequestResult, method: HttpMethods, uri: string, para } } -function logRequest(method: HttpMethods, uri: string, body: RequestBody | null, params: RequestParams) { - if (Logger.shouldLog(Logger.LOG_MICRO)) { +function logRequest(method: HttpMethods, uri: string, body: RequestBody | null, params: RequestParams, logger: Logger) { + if (logger.shouldLog(Logger.LOG_MICRO)) { Logger.logActionNoStrip( + logger, Logger.LOG_MICRO, 'Http.' + method + '()', 'Sending; ' + @@ -122,6 +131,10 @@ export class Http { : undefined; } + get logger(): Logger { + return this.client?.logger ?? Logger.defaultLogger; + } + get supportsAuthHeaders() { return this.platformHttp.supportsAuthHeaders; } @@ -239,12 +252,12 @@ export class Http { params: RequestParams, ): Promise { try { - logRequest(method, uri, body, params); + logRequest(method, uri, body, params, this.logger); const result = await this.platformHttp.doUri(method, uri, headers, body, params); - if (Logger.shouldLog(Logger.LOG_MICRO)) { - logResult(result, method, uri, params); + if (this.logger.shouldLog(Logger.LOG_MICRO)) { + logResult(result, method, uri, params, this.logger); } return result; diff --git a/src/platform/nodejs/lib/transport/nodecomettransport.js b/src/platform/nodejs/lib/transport/nodecomettransport.js index 9a4eb0a9e..045a2d9f3 100644 --- a/src/platform/nodejs/lib/transport/nodecomettransport.js +++ b/src/platform/nodejs/lib/transport/nodecomettransport.js @@ -96,7 +96,7 @@ class NodeCometTransport extends CometTransport { class Request extends EventEmitter { constructor(uri, headers, params, body, requestMode, format, timeouts, transport) { - super(); + super(transport.logger); if (typeof uri == 'string') uri = url.parse(uri); var tls = uri.protocol == 'https:'; @@ -199,7 +199,7 @@ class Request extends EventEmitter { chunk = JSON.parse(chunk); } catch (e) { var msg = 'Malformed response body from server: ' + e.message; - Logger.logAction(Logger.LOG_ERROR, 'NodeCometTransport.Request.readStream()', msg); + Logger.logAction(self.logger, Logger.LOG_ERROR, 'NodeCometTransport.Request.readStream()', msg); self.complete(new PartialErrorInfo(msg, null, 400)); return; } @@ -256,7 +256,7 @@ class Request extends EventEmitter { body = JSON.parse(String(body)); } catch (e) { var msg = 'Malformed response body from server: ' + e.message; - Logger.logAction(Logger.LOG_ERROR, 'NodeCometTransport.Request.readFully()', msg); + Logger.logAction(self.logger, Logger.LOG_ERROR, 'NodeCometTransport.Request.readFully()', msg); self.complete(new PartialErrorInfo(msg, null, 400)); return; } @@ -301,7 +301,7 @@ class Request extends EventEmitter { } abort() { - Logger.logAction(Logger.LOG_MINOR, 'NodeCometTransport.Request.abort()', ''); + Logger.logAction(this.logger, Logger.LOG_MINOR, 'NodeCometTransport.Request.abort()', ''); var timer = this.timer; if (timer) { clearTimeout(timer); @@ -309,7 +309,7 @@ class Request extends EventEmitter { } var req = this.req; if (req) { - Logger.logAction(Logger.LOG_MINOR, 'NodeCometTransport.Request.abort()', 'aborting request'); + Logger.logAction(this.logger, Logger.LOG_MINOR, 'NodeCometTransport.Request.abort()', 'aborting request'); req.removeListener('error', this.onReqError); req.on('error', noop); req.abort(); diff --git a/src/platform/nodejs/lib/util/crypto.ts b/src/platform/nodejs/lib/util/crypto.ts index 7efe4e43c..1a0854484 100644 --- a/src/platform/nodejs/lib/util/crypto.ts +++ b/src/platform/nodejs/lib/util/crypto.ts @@ -189,12 +189,12 @@ var createCryptoClass = function (bufferUtils: typeof BufferUtils) { * @param params either a CipherParams instance or some subset of its * fields that includes a key */ - static getCipher(params: IGetCipherParams) { + static getCipher(params: IGetCipherParams, logger: Logger) { var cipherParams = isInstCipherParams(params) ? (params as CipherParams) : this.getDefaultParams(params); return { cipherParams: cipherParams, - cipher: new CBCCipher(cipherParams, params.iv ?? null), + cipher: new CBCCipher(cipherParams, params.iv ?? null, logger), }; } } @@ -207,14 +207,14 @@ var createCryptoClass = function (bufferUtils: typeof BufferUtils) { iv: Buffer | null; encryptCipher: NodeCipher | null = null; - constructor(params: CipherParams, iv: Buffer | null) { + constructor(params: CipherParams, iv: Buffer | null, private readonly logger: Logger) { this.algorithm = params.algorithm + '-' + String(params.keyLength) + '-' + params.mode; this.key = params.key; this.iv = iv; } async encrypt(plaintext: InputPlaintext): Promise { - Logger.logAction(Logger.LOG_MICRO, 'CBCCipher.encrypt()', ''); + Logger.logAction(this.logger, Logger.LOG_MICRO, 'CBCCipher.encrypt()', ''); const iv = await this.getIv(); if (!this.encryptCipher) { diff --git a/src/platform/web/lib/http/http.ts b/src/platform/web/lib/http/http.ts index ffe276163..99516cc3b 100644 --- a/src/platform/web/lib/http/http.ts +++ b/src/platform/web/lib/http/http.ts @@ -64,6 +64,7 @@ const Http = class { body, XHRStates.REQ_SEND, (client && client.options.timeouts) ?? null, + this.logger, method, ); req.once( @@ -86,6 +87,7 @@ const Http = class { } else { this.checkConnectivity = async function () { Logger.logAction( + this.logger, Logger.LOG_MICRO, '(XHRRequest)Http.checkConnectivity()', 'Sending; ' + connectivityCheckUrl, @@ -106,7 +108,7 @@ const Http = class { result = !requestResult.error && (requestResult.body as string)?.replace(/\n/, '') == 'yes'; } - Logger.logAction(Logger.LOG_MICRO, '(XHRRequest)Http.checkConnectivity()', 'Result: ' + result); + Logger.logAction(this.logger, Logger.LOG_MICRO, '(XHRRequest)Http.checkConnectivity()', 'Result: ' + result); return result; }; } @@ -116,10 +118,15 @@ const Http = class { return fetchRequestImplementation(method, client ?? null, uri, headers, params, body); }; this.checkConnectivity = async function () { - Logger.logAction(Logger.LOG_MICRO, '(Fetch)Http.checkConnectivity()', 'Sending; ' + connectivityCheckUrl); + Logger.logAction( + this.logger, + Logger.LOG_MICRO, + '(Fetch)Http.checkConnectivity()', + 'Sending; ' + connectivityCheckUrl, + ); const requestResult = await this.doUri(HttpMethods.Get, connectivityCheckUrl, null, null, null); const result = !requestResult.error && (requestResult.body as string)?.replace(/\n/, '') == 'yes'; - Logger.logAction(Logger.LOG_MICRO, '(Fetch)Http.checkConnectivity()', 'Result: ' + result); + Logger.logAction(this.logger, Logger.LOG_MICRO, '(Fetch)Http.checkConnectivity()', 'Result: ' + result); return result; }; } else { @@ -132,6 +139,10 @@ const Http = class { } } + get logger(): Logger { + return this.client?.logger ?? Logger.defaultLogger; + } + async doUri( method: HttpMethods, uri: string, diff --git a/src/platform/web/lib/http/request/xhrrequest.ts b/src/platform/web/lib/http/request/xhrrequest.ts index 942097d26..f390388d7 100644 --- a/src/platform/web/lib/http/request/xhrrequest.ts +++ b/src/platform/web/lib/http/request/xhrrequest.ts @@ -69,9 +69,10 @@ class XHRRequest extends EventEmitter implements IXHRRequest { body: RequestBody | null, requestMode: number, timeouts: Record, + logger: Logger, method?: HttpMethods, ) { - super(); + super(logger); params = params || {}; params.rnd = Utils.cheapRandStr(); this.uri = uri + Utils.toQueryString(params); @@ -93,6 +94,7 @@ class XHRRequest extends EventEmitter implements IXHRRequest { body: RequestBody | null, requestMode: number, timeouts: Record | null, + logger: Logger, method?: HttpMethods, ): XHRRequest { /* XHR requests are used either with the context being a realtime @@ -106,6 +108,7 @@ class XHRRequest extends EventEmitter implements IXHRRequest { body, requestMode, _timeouts, + logger, method, ); } @@ -177,7 +180,7 @@ class XHRRequest extends EventEmitter implements IXHRRequest { ) => { let errorMessage = message + ' (event type: ' + errorEvent.type + ')'; if (this?.xhr?.statusText) errorMessage += ', current statusText is ' + this.xhr.statusText; - Logger.logAction(Logger.LOG_ERROR, 'Request.on' + errorEvent.type + '()', errorMessage); + Logger.logAction(this.logger, Logger.LOG_ERROR, 'Request.on' + errorEvent.type + '()', errorMessage); this.complete(new PartialErrorInfo(errorMessage, code, statusCode)); }; xhr.onerror = function (errorEvent) { diff --git a/src/platform/web/lib/transport/xhrpollingtransport.ts b/src/platform/web/lib/transport/xhrpollingtransport.ts index 12268fed8..0a08b5c3b 100644 --- a/src/platform/web/lib/transport/xhrpollingtransport.ts +++ b/src/platform/web/lib/transport/xhrpollingtransport.ts @@ -30,7 +30,7 @@ class XHRPollingTransport extends CometTransport { body: RequestBody | null, requestMode: number, ) { - return XHRRequest.createRequest(uri, headers, params, body, requestMode, this.timeouts); + return XHRRequest.createRequest(uri, headers, params, body, requestMode, this.timeouts, this.logger); } } diff --git a/src/platform/web/lib/util/crypto.ts b/src/platform/web/lib/util/crypto.ts index b7dab53bf..097e4eef5 100644 --- a/src/platform/web/lib/util/crypto.ts +++ b/src/platform/web/lib/util/crypto.ts @@ -152,12 +152,12 @@ var createCryptoClass = function (config: IPlatformConfig, bufferUtils: typeof B * @param params either a CipherParams instance or some subset of its * fields that includes a key */ - static getCipher(params: IGetCipherParams) { + static getCipher(params: IGetCipherParams, logger: Logger) { var cipherParams = isCipherParams(params) ? (params as CipherParams) : this.getDefaultParams(params); return { cipherParams: cipherParams, - cipher: new CBCCipher(cipherParams, params.iv ?? null), + cipher: new CBCCipher(cipherParams, params.iv ?? null, logger), }; } } @@ -170,7 +170,7 @@ var createCryptoClass = function (config: IPlatformConfig, bufferUtils: typeof B key: ArrayBuffer; iv: ArrayBuffer | null; - constructor(params: CipherParams, iv: IV | null) { + constructor(params: CipherParams, iv: IV | null, private readonly logger: Logger) { if (!crypto.subtle) { if (isSecureContext) { throw new Error( @@ -207,7 +207,7 @@ var createCryptoClass = function (config: IPlatformConfig, bufferUtils: typeof B } async encrypt(plaintext: InputPlaintext): Promise { - Logger.logAction(Logger.LOG_MICRO, 'CBCCipher.encrypt()', ''); + Logger.logAction(this.logger, Logger.LOG_MICRO, 'CBCCipher.encrypt()', ''); const iv = await this.getIv(); const cryptoKey = await crypto.subtle.importKey('raw', this.key, this.webCryptoAlgorithm, false, ['encrypt']); @@ -217,7 +217,7 @@ var createCryptoClass = function (config: IPlatformConfig, bufferUtils: typeof B } async decrypt(ciphertext: InputCiphertext): Promise { - Logger.logAction(Logger.LOG_MICRO, 'CBCCipher.decrypt()', ''); + Logger.logAction(this.logger, Logger.LOG_MICRO, 'CBCCipher.decrypt()', ''); const ciphertextArrayBuffer = bufferUtils.toArrayBuffer(ciphertext); const iv = ciphertextArrayBuffer.slice(0, DEFAULT_BLOCKLENGTH); diff --git a/src/platform/web/modular/message.ts b/src/platform/web/modular/message.ts index 18c5d1396..539a2f782 100644 --- a/src/platform/web/modular/message.ts +++ b/src/platform/web/modular/message.ts @@ -1,21 +1,22 @@ import * as API from '../../../../ably'; import { Crypto } from './crypto'; import { fromEncoded, fromEncodedArray } from '../../../common/lib/types/message'; +import Logger from '../../../common/lib/util/logger'; // The type assertions for the decode* functions below are due to https://github.com/ably/ably-js/issues/1421 export const decodeMessage = ((obj, options) => { - return fromEncoded(null, obj, options); + return fromEncoded(Logger.defaultLogger, null, obj, options); }) as API.MessageStatic['fromEncoded']; export const decodeEncryptedMessage = ((obj, options) => { - return fromEncoded(Crypto, obj, options); + return fromEncoded(Logger.defaultLogger, Crypto, obj, options); }) as API.MessageStatic['fromEncoded']; export const decodeMessages = ((obj, options) => { - return fromEncodedArray(null, obj, options); + return fromEncodedArray(Logger.defaultLogger, null, obj, options); }) as API.MessageStatic['fromEncodedArray']; export const decodeEncryptedMessages = ((obj, options) => { - return fromEncodedArray(Crypto, obj, options); + return fromEncodedArray(Logger.defaultLogger, Crypto, obj, options); }) as API.MessageStatic['fromEncodedArray']; diff --git a/src/platform/web/modular/presencemessage.ts b/src/platform/web/modular/presencemessage.ts index 60e5351e9..6c9b891a0 100644 --- a/src/platform/web/modular/presencemessage.ts +++ b/src/platform/web/modular/presencemessage.ts @@ -1,8 +1,15 @@ import * as API from '../../../../ably'; import { fromEncoded, fromEncodedArray, fromValues } from '../../../common/lib/types/presencemessage'; +import Logger from '../../../common/lib/util/logger'; // The type assertions for the functions below are due to https://github.com/ably/ably-js/issues/1421 -export const decodePresenceMessage = fromEncoded as API.PresenceMessageStatic['fromEncoded']; -export const decodePresenceMessages = fromEncodedArray as API.PresenceMessageStatic['fromEncodedArray']; +export const decodePresenceMessage = ((obj, options) => { + return fromEncoded(Logger.defaultLogger, obj, options); +}) as API.PresenceMessageStatic['fromEncoded']; + +export const decodePresenceMessages = ((obj, options) => { + return fromEncodedArray(Logger.defaultLogger, obj, options); +}) as API.PresenceMessageStatic['fromEncodedArray']; + export const constructPresenceMessage = fromValues as API.PresenceMessageStatic['fromValues']; diff --git a/test/rest/defaults.test.js b/test/rest/defaults.test.js index 99a941a48..212b768a6 100644 --- a/test/rest/defaults.test.js +++ b/test/rest/defaults.test.js @@ -6,7 +6,7 @@ define(['ably', 'chai'], function (Ably, chai) { describe('rest/defaults', function () { it('Init with no endpoint-related options', function () { - var normalisedOptions = Defaults.normaliseOptions({}, null); + var normalisedOptions = Defaults.normaliseOptions({}, null, null); expect(normalisedOptions.restHost).to.equal('rest.ably.io'); expect(normalisedOptions.realtimeHost).to.equal('realtime.ably.io'); @@ -24,7 +24,7 @@ define(['ably', 'chai'], function (Ably, chai) { }); it('Init with production environment', function () { - var normalisedOptions = Defaults.normaliseOptions({ environment: 'production' }, null); + var normalisedOptions = Defaults.normaliseOptions({ environment: 'production' }, null, null); expect(normalisedOptions.restHost).to.equal('rest.ably.io'); expect(normalisedOptions.realtimeHost).to.equal('realtime.ably.io'); @@ -42,7 +42,7 @@ define(['ably', 'chai'], function (Ably, chai) { }); it('Init with given environment', function () { - var normalisedOptions = Defaults.normaliseOptions({ environment: 'sandbox' }, null); + var normalisedOptions = Defaults.normaliseOptions({ environment: 'sandbox' }, null, null); expect(normalisedOptions.restHost).to.equal('sandbox-rest.ably.io'); expect(normalisedOptions.realtimeHost).to.equal('sandbox-realtime.ably.io'); @@ -62,7 +62,11 @@ define(['ably', 'chai'], function (Ably, chai) { }); it('Init with local environment and non-default ports', function () { - var normalisedOptions = Defaults.normaliseOptions({ environment: 'local', port: 8080, tlsPort: 8081 }, null); + var normalisedOptions = Defaults.normaliseOptions( + { environment: 'local', port: 8080, tlsPort: 8081 }, + null, + null, + ); expect(normalisedOptions.restHost).to.equal('local-rest.ably.io'); expect(normalisedOptions.realtimeHost).to.equal('local-realtime.ably.io'); @@ -79,7 +83,7 @@ define(['ably', 'chai'], function (Ably, chai) { }); it('Init with given host', function () { - var normalisedOptions = Defaults.normaliseOptions({ restHost: 'test.org' }, null); + var normalisedOptions = Defaults.normaliseOptions({ restHost: 'test.org' }, null, null); expect(normalisedOptions.restHost).to.equal('test.org'); expect(normalisedOptions.realtimeHost).to.equal('test.org'); @@ -97,7 +101,11 @@ define(['ably', 'chai'], function (Ably, chai) { /* init with given restHost and realtimeHost */ it('Init with given restHost and realtimeHost', function () { - var normalisedOptions = Defaults.normaliseOptions({ restHost: 'test.org', realtimeHost: 'ws.test.org' }, null); + var normalisedOptions = Defaults.normaliseOptions( + { restHost: 'test.org', realtimeHost: 'ws.test.org' }, + null, + null, + ); expect(normalisedOptions.restHost).to.equal('test.org'); expect(normalisedOptions.realtimeHost).to.equal('ws.test.org'); @@ -115,7 +123,7 @@ define(['ably', 'chai'], function (Ably, chai) { it('Init with no endpoint-related options and given default environment', function () { Defaults.ENVIRONMENT = 'sandbox'; - var normalisedOptions = Defaults.normaliseOptions({}, null); + var normalisedOptions = Defaults.normaliseOptions({}, null, null); expect(normalisedOptions.restHost).to.equal('sandbox-rest.ably.io'); expect(normalisedOptions.realtimeHost).to.equal('sandbox-realtime.ably.io'); @@ -141,7 +149,7 @@ define(['ably', 'chai'], function (Ably, chai) { describe('given MsgPack implementation', () => { it('maintains useBinaryProtocol as true', () => { const StubMsgPack = {}; - var normalisedOptions = Defaults.normaliseOptions({ useBinaryProtocol: true }, StubMsgPack); + var normalisedOptions = Defaults.normaliseOptions({ useBinaryProtocol: true }, StubMsgPack, null); expect(normalisedOptions.useBinaryProtocol).to.be.true; }); @@ -150,7 +158,7 @@ define(['ably', 'chai'], function (Ably, chai) { describe('given no MsgPack implementation', () => { it('changes useBinaryProtocol to false', () => { - var normalisedOptions = Defaults.normaliseOptions({ useBinaryProtocol: true }, null); + var normalisedOptions = Defaults.normaliseOptions({ useBinaryProtocol: true }, null, null); expect(normalisedOptions.useBinaryProtocol).to.be.false; }); @@ -161,23 +169,23 @@ define(['ably', 'chai'], function (Ably, chai) { var options; /* Default to true */ - options = Defaults.normaliseOptions({}, null); + options = Defaults.normaliseOptions({}, null, null); expect(options.closeOnUnload).to.equal(true); /* Default to false if using manual recovery */ - options = Defaults.normaliseOptions({ recover: 'someRecoveryKey' }, null); + options = Defaults.normaliseOptions({ recover: 'someRecoveryKey' }, null, null); expect(options.closeOnUnload).to.equal(false); /* Default to false if using autorecovery */ - options = Defaults.normaliseOptions({ recover: function () {} }, null); + options = Defaults.normaliseOptions({ recover: function () {} }, null, null); expect(options.closeOnUnload).to.equal(false); /* can override default with manual recovery */ - options = Defaults.normaliseOptions({ recover: 'someRecoveryKey', closeOnUnload: true }, null); + options = Defaults.normaliseOptions({ recover: 'someRecoveryKey', closeOnUnload: true }, null, null); expect(options.closeOnUnload).to.equal(true); /* can override default with autorecovery only at the cost of unsetting autorecovery */ - options = Defaults.normaliseOptions({ recover: function () {}, closeOnUnload: true }, null); + options = Defaults.normaliseOptions({ recover: function () {}, closeOnUnload: true }, null, null); expect(options.closeOnUnload).to.equal(true); expect(!options.recover).to.be.ok; });