From b960a321daba5bd0b43a5c2879ba7ee8bbe1263f Mon Sep 17 00:00:00 2001 From: Alex <94073946+Alex-NRCan@users.noreply.github.com> Date: Wed, 28 Feb 2024 13:25:53 -0500 Subject: [PATCH] New log methods to track objects (#1871) --- docs/programming/logging.md | 9 +- .../geoview-core/src/core/utils/logger.ts | 232 ++++++++++++------ 2 files changed, 160 insertions(+), 81 deletions(-) diff --git a/docs/programming/logging.md b/docs/programming/logging.md index bd58e3e8a7d..0acf7791adb 100644 --- a/docs/programming/logging.md +++ b/docs/programming/logging.md @@ -51,7 +51,14 @@ The `LOG_TRACE` functions are used when the developer wants to view the call sta Typically, to debug an application, the developer should use `logger.logDebug()` and when they are done, they should remove the line after some time. The line can be committed and remain in the code for a while, but they aren't meant to stay forever. -A neat feature of the `logger` is also the possibility to log using timing markers. Call `logMarkerStart` to start a timer using a key and then call `logMarkerCheck` and provide the same key to log the time span between 'now' and the 'start' time. +A neat feature of the `logger` is the possibility to log using timing markers. Call `logMarkerStart` to start a timer using a key and then call `logMarkerCheck` and provide the same key to log the time span between 'now' and the 'start' time. + +Another neat feature of the `logger` is the possibility to track an object and log when they changed or whenever we want. Call `logTrackerStart` to start an interval timer which constantly checks object value. Below is an example of how to call it.: +```ts + let toto = 1; + logger.logTrackerStart('test', () => toto); +``` +Remember to call `logTrackerStop` to stop tracking. ## Characteristics to know when using `useWhatChanged` ## diff --git a/packages/geoview-core/src/core/utils/logger.ts b/packages/geoview-core/src/core/utils/logger.ts index 4345b048008..f89581ac45a 100644 --- a/packages/geoview-core/src/core/utils/logger.ts +++ b/packages/geoview-core/src/core/utils/logger.ts @@ -42,8 +42,8 @@ const LOG_LEVEL = getItemAsNumberOrNumberArraySetValue(LOCAL_STORAGE_KEY_LEVEL, /** * Helper function to format a time for logging. - * @param date {Date} The date to format - * @returns The formatted date + * @param {Date} date The date to format + * @returns {string} The formatted date */ const formatTime = (date: Date): string => { const options: Intl.DateTimeFormatOptions = { @@ -78,16 +78,24 @@ type ColorCode = { dodgerblue: string; darkorange: string; yellowgreen: string; + goldenrod: string; green: string; }; /** - * A Log marker with various keys, used to track various timings + * A Log marker with various keys, used to log various specific execution timings */ type LogMarker = { [key: string]: Date; }; +/** + * A Log tracker with various keys, used to log and track object modifications accross execution timings + */ +type LogTracker = { + [key: string]: NodeJS.Timeout; +}; + /** * A Console Logger to help out logging information with levels of details. */ @@ -95,12 +103,18 @@ export class ConsoleLogger { // The logging level. The higher the number, the more detailed the log. loggingLevel: number | number[]; - // The active markers for the logger. + // The active timing markers for the logger. markers: LogMarker = {}; + // The active object(s) trackers for the logger. + trackers: LogTracker = {}; + + // The interval in ms for the object trackers + trackerInterval = 100; + /** * Constructor - * @param logLevel? number Indicate the level of detail for the ConsoleLogger. The higher the number, the more detailed the log. + * @param {number | number[]} logLevel Indicate the level of detail for the ConsoleLogger. The higher the number, the more detailed the log. */ constructor(logLevel: number | number[]) { // Set the level for the logger so that it logs what we really want to see. @@ -110,133 +124,133 @@ export class ConsoleLogger { /** * Logs tracing calls at the highest level of detail. * Only shows if LOG_ACTIVE is true. - * @param message unknown[] the messages to log + * @param {unknown[]} messages the messages to log */ - logTraceDetailed = (...message: unknown[]): void => { + logTraceDetailed = (...messages: unknown[]): void => { // Validate log active if (!LOG_ACTIVE) return; // Redirect - this.logLevel(LOG_TRACE_DETAILED, 'DETAL', 'turquoise', ...message); // Not a typo, 5 characters for alignment + this.logLevel(LOG_TRACE_DETAILED, 'DETAL', 'turquoise', ...messages); // Not a typo, 5 characters for alignment }; /** - * Logging function commonly used in the useEffects to track when a component is being unmounted. + * Logging function commonly used in the useEffects to log when a component is being unmounted. * Only shows if LOG_ACTIVE is true. - * @param message string useEffectFunction the useEffect function identifier - * @param message unknown[] the messages to log + * @param {string} useEffectFunction the useEffect function identifier + * @param {unknown[]} messages the messages to log */ - logTraceUseEffectUnmount = (useEffectFunction: string, ...message: unknown[]): void => { + logTraceUseEffectUnmount = (useEffectFunction: string, ...messages: unknown[]): void => { // Validate log active if (!LOG_ACTIVE) return; // Redirect - this.logLevel(LOG_TRACE_USE_EFFECT_UNMOUNT, 'U_UMT', 'grey', useEffectFunction, ...message); + this.logLevel(LOG_TRACE_USE_EFFECT_UNMOUNT, 'U_UMT', 'grey', useEffectFunction, ...messages); }; /** - * Logging function commonly used in the rendering to track when a component is being rendered. + * Logging function commonly used in the rendering to log when a component is being rendered. * Only shows if LOG_ACTIVE is true. - * @param message string component the component being rendered - * @param message unknown[] the messages to log + * @param {string} component the component being rendered + * @param {unknown[]} messages the messages to log */ - logTraceRender = (component: string, ...message: unknown[]): void => { + logTraceRender = (component: string, ...messages: unknown[]): void => { // Validate log active if (!LOG_ACTIVE) return; // Redirect - this.logLevel(LOG_TRACE_RENDER, 'RENDR', 'plum', component, ...message); // Not a typo, 5 characters for alignment + this.logLevel(LOG_TRACE_RENDER, 'RENDR', 'plum', component, ...messages); // Not a typo, 5 characters for alignment }; /** - * Logging function commonly used in the useMemo to track when a value is being memoized. + * Logging function commonly used in the useMemo to log when a value is being memoized. * Only shows if LOG_ACTIVE is true. - * @param message string useCallbackFunction the useCallback function identifier - * @param message unknown[] the messages to log + * @param {string} useMemoFunction the useCallback function identifier + * @param {unknown[]} messages the messages to log */ - logTraceUseMemo = (useMemoFunction: string, ...message: unknown[]): void => { + logTraceUseMemo = (useMemoFunction: string, ...messages: unknown[]): void => { // Validate log active if (!LOG_ACTIVE) return; // Redirect - this.logLevel(LOG_TRACE_USE_MEMO, 'U_MEM', 'orchid', useMemoFunction, ...message); + this.logLevel(LOG_TRACE_USE_MEMO, 'U_MEM', 'orchid', useMemoFunction, ...messages); }; /** - * Logging function commonly used in the useCallback to track when a callback is being memoized. + * Logging function commonly used in the useCallback to log when a callback is being memoized. * Only shows if LOG_ACTIVE is true. - * @param message string useCallbackFunction the useCallback function identifier - * @param message unknown[] the messages to log + * @param {string} useCallbackFunction the useCallback function identifier + * @param {unknown[]} messages the messages to log */ - logTraceUseCallback = (useCallbackFunction: string, ...message: unknown[]): void => { + logTraceUseCallback = (useCallbackFunction: string, ...messages: unknown[]): void => { // Validate log active if (!LOG_ACTIVE) return; // Redirect - this.logLevel(LOG_TRACE_USE_CALLBACK, 'U_CLB', 'darkorchid', useCallbackFunction, ...message); + this.logLevel(LOG_TRACE_USE_CALLBACK, 'U_CLB', 'darkorchid', useCallbackFunction, ...messages); }; /** - * Logging function commonly used in the useEffects to track when a component is being mounted. + * Logging function commonly used in the useEffects to log when a component is being mounted. * Only shows if LOG_ACTIVE is true. - * @param message string useEffectFunction the useEffect function identifier - * @param message unknown[] the messages to log + * @param {string} message useEffectFunction the useEffect function identifier + * @param {unknown[]} messages the messages to log */ - logTraceUseEffect = (useEffectFunction: string, ...message: unknown[]): void => { + logTraceUseEffect = (useEffectFunction: string, ...messages: unknown[]): void => { // Validate log active if (!LOG_ACTIVE) return; // Redirect - this.logLevel(LOG_TRACE_USE_EFFECT, 'U_EFF', 'mediumorchid', useEffectFunction, ...message); + this.logLevel(LOG_TRACE_USE_EFFECT, 'U_EFF', 'mediumorchid', useEffectFunction, ...messages); }; /** - * Logging function commonly used in the store subscriptions to track when a store has triggered a subscription. + * Logging function commonly used in the store subscriptions to log when a store has triggered a subscription. * Only shows if LOG_ACTIVE is true. - * @param message string storeSubscription the store subscription event that was raised - * @param message unknown[] the messages to log + * @param {string} message storeSubscription the store subscription event that was raised + * @param {unknown[]} messages the messages to log */ - logTraceCoreStoreSubscription = (storeSubscription: string, ...message: unknown[]): void => { + logTraceCoreStoreSubscription = (storeSubscription: string, ...messages: unknown[]): void => { // Validate log active if (!LOG_ACTIVE) return; // Redirect - this.logLevel(LOG_TRACE_CORE_STORE_SUBSCRIPTION, 'E_STO', 'royalblue', storeSubscription, ...message); + this.logLevel(LOG_TRACE_CORE_STORE_SUBSCRIPTION, 'E_STO', 'royalblue', storeSubscription, ...messages); }; /** - * Logging function commonly used in the API event handlers to track when the API has triggered an event. + * Logging function commonly used in the API event handlers to log when the API has triggered an event. * Only shows if LOG_ACTIVE is true. - * @param message string apiEvent the api event that was raised - * @param message unknown[] the messages to log + * @param {string} apiEvent the api event that was raised + * @param {unknown[]} messages the messages to log */ - logTraceCoreAPIEvent = (apiEvent: string, ...message: unknown[]): void => { + logTraceCoreAPIEvent = (apiEvent: string, ...messages: unknown[]): void => { // Validate log active if (!LOG_ACTIVE) return; // Redirect - this.logLevel(LOG_TRACE_CORE_API_EVENT, 'E_API', 'cornflowerblue', apiEvent, ...message); + this.logLevel(LOG_TRACE_CORE_API_EVENT, 'E_API', 'cornflowerblue', apiEvent, ...messages); }; /** * Logs trace information for core processing. * Only shows if LOG_ACTIVE is true. - * @param message unknown[] the messages to log + * @param {unknown[]} messages the messages to log */ - logTraceCore = (...message: unknown[]): void => { + logTraceCore = (...messages: unknown[]): void => { // Validate log active if (!LOG_ACTIVE) return; // Redirect - this.logLevel(LOG_TRACE_CORE, 'TRACE', 'dodgerblue', ...message); + this.logLevel(LOG_TRACE_CORE, 'TRACE', 'dodgerblue', ...messages); }; /** * Logs debug information. * Only shows if LOG_ACTIVE is true. - * @param message unknown[] the messages to log + * @param {unknown[]} messages the messages to log */ - logDebug = (...message: unknown[]): void => { + logDebug = (...messages: unknown[]): void => { // Validate log active if (!LOG_ACTIVE) return; // Redirect - this.logLevel(LOG_DEBUG, 'DEBUG', 'darkorange', ...message); + this.logLevel(LOG_DEBUG, 'DEBUG', 'darkorange', ...messages); }; /** - * Start a time marker using the given marker key. Used to track timings. - * @param markerKey {string} the unique key for this marker tracker + * Starts a time marker using the given marker key. Used to log various specific execution timings. + * @param {string} markerKey the unique key for this time marker */ logMarkerStart = (markerKey: string): void => { // Store the current date in the markers using the marker key @@ -247,10 +261,10 @@ export class ConsoleLogger { * Logs the time difference between 'now' and the original marker start. * Only shows if LOG_ACTIVE is true. * Priority level is the same as LOG_DEBUG. - * @param markerKey {string} the unique key for this marker tracker - * @param message unknown[] the messages to log + * @param {string} markerKey the unique key for this execution timing marker + * @param {unknown[]} messages the timing marker messages to log */ - logMarkerCheck = (markerKey: string, ...message: unknown[]): void => { + logMarkerCheck = (markerKey: string, ...messages: unknown[]): void => { // Validate log active and existing marker if (!LOG_ACTIVE) return; if (!this.markers[markerKey]) return; @@ -276,43 +290,99 @@ export class ConsoleLogger { if (hours) logMsg = `${hours} hours, ${mins} minutes, ${seconds} seconds, and ${timeSpan} ms`; // Redirect - this.logLevel(LOG_DEBUG, 'MARKR', 'yellowgreen', logMsg, ...message, `(${markerKey})`); // Not a typo, 5 characters for alignment + this.logLevel(LOG_DEBUG, 'MARKR', 'yellowgreen', logMsg, ...messages, `(${markerKey})`); // Not a typo, 5 characters for alignment + }; + + /** + * Starts logging object(s) at every `trackerInterval`ms. Used to track object(s) modification timings. + * Only shows if LOG_ACTIVE is true. + * Priority level is the same as LOG_DEBUG. + * @param {string} trackerKey the unique key for this object(s) tracker + * @param {() => T} callbackObject the callback executed to retrieve the object + * @param {(prevObject: T, newObject: T) => boolean} callbackCheck? optionally specify how the equality comparison should happen to decide if we want to log + * @param {number} interval? optionally specify an interval to call the callback for + */ + logTrackerStart = ( + trackerKey: string, + callbackObject: () => T, + callbackCheck?: (prevObject: T, newObject: T) => boolean, + interval?: number + ): void => { + // Validate log active and existing tracker clearing + if (!LOG_ACTIVE) return; + if (this.trackers[trackerKey]) this.logTrackerStop(trackerKey); + + // Calback right away to get the object on start + let object = callbackObject(); + + // Log right away for the first tracker to happen immediately + this.logLevel(LOG_DEBUG, 'TRAKR', 'goldenrod', object, `(${trackerKey})`); // Not a typo, 5 characters for alignment + + // Start the interval to check every few ms + this.trackers[trackerKey] = setInterval(() => { + // Calback to retrieve the object again + const newObject = callbackObject(); + + // Check if changed + let hasChanged = false; + if (callbackCheck) hasChanged = callbackCheck(object, newObject); // Use callback to know + else hasChanged = newObject !== object; // Use straight equality comparator + + // If has changed + if (hasChanged) { + // Redirect + this.logLevel(LOG_DEBUG, 'TRAKR', 'goldenrod', newObject, `(${trackerKey})`); // Not a typo, 5 characters for alignment + } + + // Update reference + object = newObject; + }, interval || this.trackerInterval); + }; + + /** + * Stops the object(s) tracker for the given tracker key + * @param {string} trackerKey the unique key for this object(s) tracker + */ + logTrackerStop = (trackerKey: string): void => { + if (this.trackers[trackerKey]) { + clearInterval(this.trackers[trackerKey]); + } }; /** * Logs general flow of the application. * Shows all the time. - * @param message unknown[] the messages to log + * @param {unknown[]} messages the messages to log */ - logInfo = (...message: unknown[]): void => { + logInfo = (...messages: unknown[]): void => { // Redirect - this.logLevel(LOG_INFO, 'INFO ', 'green', ...message); // Not a typo, 5 characters for alignment + this.logLevel(LOG_INFO, 'INFO ', 'green', ...messages); // Not a typo, 5 characters for alignment }; /** * Logs warnings coming from the application. * Shows all the time. - * @param message unknown[] the messages to log + * @param {unknown[]} messages the messages to log */ - logWarning = (...message: unknown[]): void => { + logWarning = (...messages: unknown[]): void => { // Redirect - this.warnLevel(LOG_WARNING, ...message); + this.warnLevel(LOG_WARNING, ...messages); }; /** * Logs errors coming from the application. * Shows all the time. - * @param message unknown[] the messages to log + * @param {unknown[]} messages the messages to log */ - logError = (...message: unknown[]): void => { + logError = (...messages: unknown[]): void => { // Redirect - this.errorLevel(LOG_ERROR, ...message); + this.errorLevel(LOG_ERROR, ...messages); }; /** * Compares the provided level (number) with the logging level (number | number[]) to know if the log should appear or not. - * @param level number the level associated with the message to be logged. - * @returns boolean true if the log level indicates that it should appear + * @param {number} level the level associated with the message to be logged. + * @returns {boolean} true if the log level indicates that it should appear */ checkLevel = (level: number): boolean => { // If regular number @@ -324,34 +394,34 @@ export class ConsoleLogger { /** * Checks that the level is greater or equal to the application logging level. * If level is valid, logs using console.log(). - * @param level number the level associated with the message to be logged. - * @param message unknown[] the messages to log + * @param {number} level the level associated with the message to be logged. + * @param {unknown[]} messages the messages to log */ - logLevel = (level: number, header: string, color: keyof ColorCode, ...message: unknown[]): void => { + logLevel = (level: number, header: string, color: keyof ColorCode, ...messages: unknown[]): void => { // If the configured logging level accepts to log the given level - if (this.checkLevel(level)) console.log(`%c${formatTime(new Date())} ${header}`, `color: ${color}`, ...message); + if (this.checkLevel(level)) console.log(`%c${formatTime(new Date())} ${header}`, `color: ${color}`, ...messages); }; /** * Checks that the level is greater or equal to the application logging level. * If level is valid, logs using console.warn(). - * @param level number the level associated with the message to be logged. - * @param message unknown[] the messages to log + * @param {number} level the level associated with the message to be logged. + * @param {unknown[]} messages the messages to log */ - warnLevel = (level: number, ...message: unknown[]): void => { + warnLevel = (level: number, ...messages: unknown[]): void => { // If the configured logging level accepts to log the given level - if (this.checkLevel(level)) console.warn(`${formatTime(new Date())}`, ...message); + if (this.checkLevel(level)) console.warn(`${formatTime(new Date())}`, ...messages); }; /** * Checks that the level is greater or equal to the application logging level. * If level is valid, logs using console.error(). - * @param level number the level associated with the message to be logged. - * @param message unknown[] the messages to log + * @param {number} level the level associated with the message to be logged. + * @param {unknown[]} messages the messages to log */ - errorLevel = (level: number, ...message: unknown[]): void => { + errorLevel = (level: number, ...messages: unknown[]): void => { // If the configured logging level accepts to log the given level - if (this.checkLevel(level)) console.error(`${formatTime(new Date())}`, ...message); + if (this.checkLevel(level)) console.error(`${formatTime(new Date())}`, ...messages); }; } @@ -370,8 +440,10 @@ logger.logInfo('Logger initialized'); // logger.logTraceCoreAPIEvent('trace api event'); // logger.logTraceCore('trace core'); // logger.logDebug('debug'); -// logger.logMarkerStart('test'); -// logger.logMarkerCheck('test'); +// logger.logMarkerStart('test time marker'); +// logger.logMarkerCheck('test time marker'); +// logger.logTrackerStart('test object tracker', () => undefined); +// logger.logTrackerStop('test object tracker'); // logger.logInfo('info'); // logger.logWarning('warning'); // logger.logError('error');