From 295d5ad44ff8ba21fbfddcb4971e0c1677597338 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?I=C3=B1aki=20Baz=20Castillo?= Date: Thu, 29 Aug 2024 18:05:36 +0200 Subject: [PATCH] Node: New setLogEventListeners() utility to get log events ### Details - Instead of relying on `DEBUG` variable and stdout/stderr logs, an application may want to collect mediasoup generated logs and post them somewhere. - This PR exposed a new `setLogEventListeners()` function at mediasoup root module level. ### Usage example ```ts mediasoup.setLogEventListeners({ ondebug: undefined, onwarn: (namespace: string, log: string) => { MyEnterpriseLogger.warn(`${namespace} ${log}`); }, onerror: (namespace: string, log: string, error?: Error) => { if (error) { MyEnterpriseLogger.error(`${namespace} ${log}: ${error}`); } else { MyEnterpriseLogger.error(`${namespace} ${log}`); } } }); ``` --- CHANGELOG.md | 1 + node/src/ActiveSpeakerObserver.ts | 2 +- node/src/AudioLevelObserver.ts | 2 +- node/src/Consumer.ts | 2 +- node/src/DataConsumer.ts | 7 ++-- node/src/DirectTransport.ts | 2 +- node/src/Logger.ts | 46 ++++++++++++++++++++---- node/src/PipeTransport.ts | 2 +- node/src/PlainTransport.ts | 2 +- node/src/Producer.ts | 2 +- node/src/Router.ts | 17 ++++----- node/src/Transport.ts | 6 ++-- node/src/WebRtcTransport.ts | 2 +- node/src/Worker.ts | 34 +++++------------- node/src/enhancedEvents.ts | 5 ++- node/src/index.ts | 60 ++++++++++++++++++++++++++++++- node/src/test/test-mediasoup.ts | 22 ++++++++++++ node/src/types.ts | 41 ++++++++++----------- 18 files changed, 173 insertions(+), 82 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 9acd0a5a6e..b910b208c2 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -4,6 +4,7 @@ - `Worker`: Fix `io_uring` support detection ([PR #1445](https://github.com/versatica/mediasoup/pull/1445)). - Mitigate libsrtp wraparound with loss decryption failure ([PR #1438](https://github.com/versatica/mediasoup/pull/1438)). +- Node: New `setLogEventListeners()` utility to get log events ([PR #XXXX](https://github.com/versatica/mediasoup/pull/XXXX)). ### 3.14.11 diff --git a/node/src/ActiveSpeakerObserver.ts b/node/src/ActiveSpeakerObserver.ts index 9187175115..609e6581e5 100644 --- a/node/src/ActiveSpeakerObserver.ts +++ b/node/src/ActiveSpeakerObserver.ts @@ -103,7 +103,7 @@ export class ActiveSpeakerObserver< } default: { - logger.error('ignoring unknown event "%s"', event); + logger.error(`ignoring unknown event "${event}"`); } } } diff --git a/node/src/AudioLevelObserver.ts b/node/src/AudioLevelObserver.ts index e0a91e408d..d429933954 100644 --- a/node/src/AudioLevelObserver.ts +++ b/node/src/AudioLevelObserver.ts @@ -147,7 +147,7 @@ export class AudioLevelObserver< } default: { - logger.error('ignoring unknown event "%s"', event); + logger.error(`ignoring unknown event "${event}"`); } } } diff --git a/node/src/Consumer.ts b/node/src/Consumer.ts index cb6314eea2..5945f8993b 100644 --- a/node/src/Consumer.ts +++ b/node/src/Consumer.ts @@ -899,7 +899,7 @@ export class Consumer< } default: { - logger.error('ignoring unknown event "%s"', event); + logger.error(`ignoring unknown event "${event}"`); } } } diff --git a/node/src/DataConsumer.ts b/node/src/DataConsumer.ts index 19e66b5267..f05b998d17 100644 --- a/node/src/DataConsumer.ts +++ b/node/src/DataConsumer.ts @@ -430,7 +430,7 @@ export class DataConsumer< * Set buffered amount low threshold. */ async setBufferedAmountLowThreshold(threshold: number): Promise { - logger.debug('setBufferedAmountLowThreshold() [threshold:%s]', threshold); + logger.debug(`setBufferedAmountLowThreshold() [threshold:${threshold}]`); /* Build Request. */ const requestOffset = @@ -714,10 +714,7 @@ export class DataConsumer< } default: { - logger.error( - 'ignoring unknown event "%s" in channel listener', - event - ); + logger.error(`ignoring unknown event "${event}"`); } } } diff --git a/node/src/DirectTransport.ts b/node/src/DirectTransport.ts index ea5f2b8684..0774a088f7 100644 --- a/node/src/DirectTransport.ts +++ b/node/src/DirectTransport.ts @@ -276,7 +276,7 @@ export class DirectTransport< } default: { - logger.error('ignoring unknown event "%s"', event); + logger.error(`ignoring unknown event "${event}"`); } } } diff --git a/node/src/Logger.ts b/node/src/Logger.ts index 96f5054b75..66b5456c0c 100644 --- a/node/src/Logger.ts +++ b/node/src/Logger.ts @@ -1,12 +1,35 @@ import debug from 'debug'; +import { EnhancedEventEmitter } from './enhancedEvents'; const APP_NAME = 'mediasoup'; +export type LoggerEmitterEvents = { + debuglog: [string, string]; + warnlog: [string, string]; + errorlog: [string, string, Error?]; +}; + +export type LoggerEmitter = EnhancedEventEmitter; + export class Logger { + private static debugLogEmitter?: LoggerEmitter; + private static warnLogEmitter?: LoggerEmitter; + private static errorLogEmitter?: LoggerEmitter; + readonly #debug: debug.Debugger; readonly #warn: debug.Debugger; readonly #error: debug.Debugger; + static setEmitters( + debugLogEmitter?: LoggerEmitter, + warnLogEmitter?: LoggerEmitter, + errorLogEmitter?: LoggerEmitter + ): void { + Logger.debugLogEmitter = debugLogEmitter; + Logger.warnLogEmitter = warnLogEmitter; + Logger.errorLogEmitter = errorLogEmitter; + } + constructor(prefix?: string) { if (prefix) { this.#debug = debug(`${APP_NAME}:${prefix}`); @@ -25,15 +48,26 @@ export class Logger { /* eslint-enable no-console */ } - get debug(): debug.Debugger { - return this.#debug; + debug(log: string): void { + this.#debug(log); + + Logger.debugLogEmitter?.safeEmit('debuglog', this.#debug.namespace, log); } - get warn(): debug.Debugger { - return this.#warn; + warn(log: string): void { + this.#warn(log); + + Logger.warnLogEmitter?.safeEmit('warnlog', this.#warn.namespace, log); } - get error(): debug.Debugger { - return this.#error; + error(log: string, error?: Error): void { + this.#error(log, error); + + Logger.errorLogEmitter?.safeEmit( + 'errorlog', + this.#error.namespace, + log, + error + ); } } diff --git a/node/src/PipeTransport.ts b/node/src/PipeTransport.ts index 61a30bbf07..d15dd5025a 100644 --- a/node/src/PipeTransport.ts +++ b/node/src/PipeTransport.ts @@ -450,7 +450,7 @@ export class PipeTransport< } default: { - logger.error('ignoring unknown event "%s"', event); + logger.error(`ignoring unknown event "${event}"`); } } } diff --git a/node/src/PlainTransport.ts b/node/src/PlainTransport.ts index c4202eec7e..e1eabcac62 100644 --- a/node/src/PlainTransport.ts +++ b/node/src/PlainTransport.ts @@ -451,7 +451,7 @@ export class PlainTransport< } default: { - logger.error('ignoring unknown event "%s"', event); + logger.error(`ignoring unknown event "${event}"`); } } } diff --git a/node/src/Producer.ts b/node/src/Producer.ts index 4ab4b64620..c9c05b2aec 100644 --- a/node/src/Producer.ts +++ b/node/src/Producer.ts @@ -586,7 +586,7 @@ export class Producer< } default: { - logger.error('ignoring unknown event "%s"', event); + logger.error(`ignoring unknown event "${event}"`); } } } diff --git a/node/src/Router.ts b/node/src/Router.ts index 70fc9ffb27..755d579f72 100644 --- a/node/src/Router.ts +++ b/node/src/Router.ts @@ -1212,7 +1212,7 @@ export class Router< }) .catch(error => { logger.error( - 'pipeToRouter() | error creating PipeTransport pair:%o', + 'pipeToRouter() | error creating PipeTransport pair:', error ); @@ -1281,8 +1281,8 @@ export class Router< return { pipeConsumer, pipeProducer }; } catch (error) { logger.error( - 'pipeToRouter() | error creating pipe Consumer/Producer pair:%o', - error + 'pipeToRouter() | error creating pipe Consumer/Producer pair:', + error as Error ); if (pipeConsumer) { @@ -1326,8 +1326,8 @@ export class Router< return { pipeDataConsumer, pipeDataProducer }; } catch (error) { logger.error( - 'pipeToRouter() | error creating pipe DataConsumer/DataProducer pair:%o', - error + 'pipeToRouter() | error creating pipe DataConsumer/DataProducer pair:', + error as Error ); pipeDataConsumer?.close(); @@ -1526,10 +1526,7 @@ export class Router< const producer = this.#producers.get(producerId); if (!producer) { - logger.error( - 'canConsume() | Producer with id "%s" not found', - producerId - ); + logger.error(`canConsume() | Producer with id "${producerId}" not found`); return false; } @@ -1543,7 +1540,7 @@ export class Router< clonedRtpCapabilities ); } catch (error) { - logger.error('canConsume() | unexpected error: %s', String(error)); + logger.error(`canConsume() | unexpected error: ${error}`); return false; } diff --git a/node/src/Transport.ts b/node/src/Transport.ts index 8559b5961e..7448e8a438 100644 --- a/node/src/Transport.ts +++ b/node/src/Transport.ts @@ -667,7 +667,7 @@ export abstract class Transport< * Set maximum incoming bitrate for receiving media. */ async setMaxIncomingBitrate(bitrate: number): Promise { - logger.debug('setMaxIncomingBitrate() [bitrate:%s]', bitrate); + logger.debug(`setMaxIncomingBitrate() [bitrate:${bitrate}]`); /* Build Request. */ const requestOffset = @@ -688,7 +688,7 @@ export abstract class Transport< * Set maximum outgoing bitrate for sending media. */ async setMaxOutgoingBitrate(bitrate: number): Promise { - logger.debug('setMaxOutgoingBitrate() [bitrate:%s]', bitrate); + logger.debug(`setMaxOutgoingBitrate() [bitrate:${bitrate}]`); /* Build Request. */ const requestOffset = new FbsTransport.SetMaxOutgoingBitrateRequestT( @@ -707,7 +707,7 @@ export abstract class Transport< * Set minimum outgoing bitrate for sending media. */ async setMinOutgoingBitrate(bitrate: number): Promise { - logger.debug('setMinOutgoingBitrate() [bitrate:%s]', bitrate); + logger.debug(`setMinOutgoingBitrate() [bitrate:${bitrate}]`); /* Build Request. */ const requestOffset = new FbsTransport.SetMinOutgoingBitrateRequestT( diff --git a/node/src/WebRtcTransport.ts b/node/src/WebRtcTransport.ts index 34ca5014a3..9f908ec19c 100644 --- a/node/src/WebRtcTransport.ts +++ b/node/src/WebRtcTransport.ts @@ -644,7 +644,7 @@ export class WebRtcTransport< } default: { - logger.error('ignoring unknown event "%s"', event); + logger.error(`ignoring unknown event "${event}"`); } } } diff --git a/node/src/Worker.ts b/node/src/Worker.ts index 73480a406d..c1d2e20f7c 100644 --- a/node/src/Worker.ts +++ b/node/src/Worker.ts @@ -348,11 +348,7 @@ export class Worker< spawnArgs.push(`--disableLiburing=true`); } - logger.debug( - 'spawning worker process: %s %s', - spawnBin, - spawnArgs.join(' ') - ); + logger.debug(`spawning worker process: ${spawnBin} ${spawnArgs.join(' ')}`); this.#child = spawn( // command @@ -398,7 +394,7 @@ export class Worker< if (!spawnDone && event === Event.WORKER_RUNNING) { spawnDone = true; - logger.debug('worker process running [pid:%s]', this.#pid); + logger.debug(`worker process running [pid:${this.#pid}]`); this.emit('@success'); } @@ -415,18 +411,14 @@ export class Worker< if (code === 42) { logger.error( - 'worker process failed due to wrong settings [pid:%s]', - this.#pid + `worker process failed due to wrong settings [pid:${this.#pid}]` ); this.close(); this.emit('@failure', new TypeError('wrong settings')); } else { logger.error( - 'worker process failed unexpectedly [pid:%s, code:%s, signal:%s]', - this.#pid, - code, - signal + `worker process failed unexpectedly [pid:${this.#pid}, code:${code}, signal:${signal}]` ); this.close(); @@ -437,10 +429,7 @@ export class Worker< } } else { logger.error( - 'worker process died unexpectedly [pid:%s, code:%s, signal:%s]', - this.#pid, - code, - signal + `worker process died unexpectedly [pid:${this.#pid}, code:${code}, signal:${signal}]` ); this.workerDied( @@ -459,18 +448,14 @@ export class Worker< spawnDone = true; logger.error( - 'worker process failed [pid:%s]: %s', - this.#pid, - error.message + `worker process failed [pid:${this.#pid}]: ${error.message}` ); this.close(); this.emit('@failure', error); } else { logger.error( - 'worker process error [pid:%s]: %s', - this.#pid, - error.message + `worker process error [pid:${this.#pid}]: ${error.message}` ); this.workerDied(error); @@ -479,10 +464,7 @@ export class Worker< this.#child.on('close', (code, signal) => { logger.debug( - 'worker subprocess closed [pid:%s, code:%s, signal:%s]', - this.#pid, - code, - signal + `worker subprocess closed [pid:${this.#pid}, code:${code}, signal:${signal}]` ); this.#subprocessClosed = true; diff --git a/node/src/enhancedEvents.ts b/node/src/enhancedEvents.ts index e2ef6a34fb..a0fbfba558 100644 --- a/node/src/enhancedEvents.ts +++ b/node/src/enhancedEvents.ts @@ -25,9 +25,8 @@ export class EnhancedEventEmitter< return super.emit(eventName, ...args); } catch (error) { enhancedEventEmitterLogger.error( - 'safeEmit() | event listener threw an error [eventName:%s]:%o', - eventName, - error + `safeEmit() | event listener threw an error [eventName:${eventName}]:`, + error as Error ); try { diff --git a/node/src/index.ts b/node/src/index.ts index 1c02f63c23..9239dc77ac 100644 --- a/node/src/index.ts +++ b/node/src/index.ts @@ -1,4 +1,4 @@ -import { Logger } from './Logger'; +import { Logger, LoggerEmitter } from './Logger'; import { EnhancedEventEmitter } from './enhancedEvents'; import { workerBin, Worker, WorkerSettings } from './Worker'; import * as utils from './utils'; @@ -43,6 +43,64 @@ export { workerBin }; const logger = new Logger(); +/** + * Event listeners for mediasoup generated logs. + */ +export type LogEventListeners = { + ondebug?: (namespace: string, log: string) => void; + onwarn?: (namespace: string, log: string) => void; + onerror?: (namespace: string, log: string, error?: Error) => void; +}; + +/** + * Set event listeners for mediasoup generated logs. If called with no arguments + * then no events will be emitted. + * + * @example + * ```ts + * mediasoup.setLogEventListeners({ + * ondebug: undefined, + * onwarn: (namespace: string, log: string) => { + * MyEnterpriseLogger.warn(`${namespace} ${log}`); + * }, + * onerror: (namespace: string, log: string, error?: Error) => { + * if (error) { + * MyEnterpriseLogger.error(`${namespace} ${log}: ${error}`); + * } else { + * MyEnterpriseLogger.error(`${namespace} ${log}`); + * } + * } + * }); + * ``` + */ +export function setLogEventListeners(listeners?: LogEventListeners): void { + logger.debug('setLogEventListeners()'); + + let debugLogEmitter: LoggerEmitter | undefined; + let warnLogEmitter: LoggerEmitter | undefined; + let errorLogEmitter: LoggerEmitter | undefined; + + if (listeners?.ondebug) { + debugLogEmitter = new EnhancedEventEmitter(); + + debugLogEmitter.on('debuglog', listeners.ondebug); + } + + if (listeners?.onwarn) { + warnLogEmitter = new EnhancedEventEmitter(); + + warnLogEmitter.on('warnlog', listeners.onwarn); + } + + if (listeners?.onerror) { + errorLogEmitter = new EnhancedEventEmitter(); + + errorLogEmitter.on('errorlog', listeners.onerror); + } + + Logger.setEmitters(debugLogEmitter, warnLogEmitter, errorLogEmitter); +} + /** * Create a Worker. */ diff --git a/node/src/test/test-mediasoup.ts b/node/src/test/test-mediasoup.ts index 4fa6db110a..bfafad5f7f 100644 --- a/node/src/test/test-mediasoup.ts +++ b/node/src/test/test-mediasoup.ts @@ -1,6 +1,8 @@ import * as fs from 'node:fs'; import * as path from 'node:path'; +import { enhancedOnce } from '../enhancedEvents'; import * as mediasoup from '../'; +import { WorkerEvents } from '../types'; const PKG = JSON.parse( fs.readFileSync(path.join(__dirname, '..', '..', '..', 'package.json'), { @@ -15,6 +17,26 @@ test('mediasoup.version matches version field in package.json', () => { expect(version).toBe(PKG.version); }); +test('setLoggerEventListeners() works', async () => { + const onDebug = jest.fn(); + + mediasoup.setLogEventListeners({ + ondebug: onDebug, + onwarn: undefined, + onerror: undefined, + }); + + const worker = await mediasoup.createWorker(); + + worker.close(); + + expect(onDebug).toHaveBeenCalled(); + + if (worker.subprocessClosed === false) { + await enhancedOnce(worker, 'subprocessclose'); + } +}, 2000); + test('mediasoup.getSupportedRtpCapabilities() returns the mediasoup RTP capabilities', () => { const rtpCapabilities = getSupportedRtpCapabilities(); diff --git a/node/src/types.ts b/node/src/types.ts index 45ef78af89..7f5ca140fa 100644 --- a/node/src/types.ts +++ b/node/src/types.ts @@ -1,23 +1,24 @@ -export * from './Worker'; -export * from './WebRtcServer'; -export * from './Router'; -export * from './Transport'; -export * from './WebRtcTransport'; -export * from './PlainTransport'; -export * from './PipeTransport'; -export * from './DirectTransport'; -export * from './Producer'; -export * from './Consumer'; -export * from './DataProducer'; -export * from './DataConsumer'; -export * from './RtpObserver'; -export * from './ActiveSpeakerObserver'; -export * from './AudioLevelObserver'; -export * from './RtpParameters'; -export * from './SctpParameters'; -export * from './SrtpParameters'; -export * from './errors'; -export type { ScalabilityMode } from './scalabilityModes'; +export type * from './index'; +export type * from './Worker'; +export type * from './WebRtcServer'; +export type * from './Router'; +export type * from './Transport'; +export type * from './WebRtcTransport'; +export type * from './PlainTransport'; +export type * from './PipeTransport'; +export type * from './DirectTransport'; +export type * from './Producer'; +export type * from './Consumer'; +export type * from './DataProducer'; +export type * from './DataConsumer'; +export type * from './RtpObserver'; +export type * from './ActiveSpeakerObserver'; +export type * from './AudioLevelObserver'; +export type * from './RtpParameters'; +export type * from './SctpParameters'; +export type * from './SrtpParameters'; +export type * from './scalabilityModes'; +export type * from './errors'; export type AppData = { [key: string]: unknown;