diff --git a/src/logged.ts b/src/logged.ts deleted file mode 100644 index f0995ee..0000000 --- a/src/logged.ts +++ /dev/null @@ -1,767 +0,0 @@ -import { - Logger, - LogLevel, - Injectable, - Controller, - ControllerOptions, - ScopeOptions, - ExecutionContext, -} from "@nestjs/common"; -import { ScopedLogger } from "./logger"; -import { - LoggedParamReflectData, - ReturnsReflectData, - returns, - nestLoggedMetadata, - loggedParam, - scopedLogger, -} from "./reflected"; -import { objectContainedLogSync, getItemByPathSync } from "./internals/utils"; -import { createRouteParamDecorator } from "./internals/nest"; -import { RequestMethod } from "@nestjs/common"; - -const RevRequestMethod = [ - "GET", - "POST", - "PUT", - "DELETE", - "PATCH", - "ALL", - "OPTIONS", - "HEAD", - "SEARCH", -]; - -function loggerInit(_target: any) { - if (!Object.getOwnPropertyNames(_target).includes("logger")) { - const newTargetLogger = new Logger(_target.constructor.name); - newTargetLogger.log("Logger Initialized."); - Object.defineProperty(_target, "logger", { - writable: false, - enumerable: false, - configurable: false, - value: newTargetLogger, - }); - } -} - -export function LoggedInjectable( - options?: ScopeOptions & { verbose?: boolean } -) { - return (target: any) => { - loggerInit(target.prototype); - - const logger = target.prototype.logger; - - const methods = Object.getOwnPropertyNames(target.prototype); - - methods.forEach((method) => { - if ( - method !== "constructor" && - typeof target.prototype[method] === "function" - ) { - if (options && options.verbose) - logger.log(`LoggedFunction applied to ${method}`); - LoggedFunction()(target.prototype, method, { - value: target.prototype[method], - }); - } - }); - - Injectable(options)(target); - }; -} - -export function LoggedController(): (target: any) => void; -export function LoggedController( - prefix: string | string[] -): (target: any) => void; -export function LoggedController( - options: ControllerOptions & { verbose?: boolean } -): (target: any) => void; - -export function LoggedController(param?: any): (target: any) => void { - return (target: any) => { - loggerInit(target.prototype); - - const logger = target.prototype.logger; - - const methods = Object.getOwnPropertyNames(target.prototype); - - let verbose = - typeof param === "object" && Object.keys(param).includes("verbose") - ? param.verbose - : false; - - methods.forEach((method) => { - if ( - method !== "constructor" && - typeof target.prototype[method] === "function" - ) { - if (verbose) { - const path = Reflect.getMetadata("path", target.prototype[method]); - const httpMethod = Reflect.getMetadata( - "method", - target.prototype[method] - ); - logger.log( - `LoggedRoute applied to ${method} (${RevRequestMethod[httpMethod]} ${path})` - ); - } - LoggedRoute()(target.prototype, method, { - value: target.prototype[method], - }); - } - }); - - Controller(param)(target); - }; -} - -interface FunctionMetadata { - scopedLoggerInjectableParam?: number; - loggedParams?: LoggedParamReflectData[]; -} - -interface OverrideBuildOptions { - callLogLevel: LogLevel | 'skip'; - returnLogLevel: LogLevel | 'skip'; - errorLogLevel: LogLevel | 'skip'; - /** @deprecated use `callLogLevel: 'skip'` instead */ - skipCallLog: boolean; - /** @deprecated use `returnLogLevel: 'skip'` instead */ - skipReturnLog: boolean; - /** @deprecated use `errorLogLevel: 'skip'` instead */ - skipErrorLog: boolean; -} - -const defaultOverrideBuildOptions: OverrideBuildOptions = { - callLogLevel: 'log', - returnLogLevel: 'log', - errorLogLevel: 'error', - skipCallLog: false, - skipReturnLog: false, - skipErrorLog: false, -} - -class LoggedMetadata { - options: OverrideBuildOptions - - constructor(options?: Partial) { - this.options = { - ...defaultOverrideBuildOptions, - ...(options ?? {}), - } - } - - updateOption(options: Partial) { - this.options = { - ...this.options, - ...options - } - } -} - -type BuildType = 'route' | 'function' | 'guard' | 'interceptor' | 'middleware'; - -const callLogIdentifyMessageDictionary: Record = { - route: 'ENDPOINT', - function: 'FUNCTION', - guard: 'GUARD', - interceptor: 'INTERCEPTOR', - middleware: 'MIDDLEWARE', -} - -function createCallLogIdentifyMessage(message: 'HIT' | 'RETURNED' | 'ERROR', type: BuildType, key?: string, route?: string) { - if (message === 'ERROR') - return `ERROR WHILE ${callLogIdentifyMessageDictionary[type]} ${key} (${route}): `; - - if (type === 'guard' || type === 'interceptor' || type === 'middleware' || type === 'route') - return `${message} ${callLogIdentifyMessageDictionary[type]} ${key} (${route})` - if (type === 'function') - return `${message} ${callLogIdentifyMessageDictionary[type]} ${key}`; - - return `${message} ${callLogIdentifyMessageDictionary[type]}`; -} - -export const REQUEST_LOG_ID = '__nestlogged_request_log_id__'; - -function overrideBuild, R>( - type: 'route', - originalFunction: (...args: F) => R, - baseLogger: Logger, - metadatas: FunctionMetadata, - key: string, - returnsData: ReturnsReflectData[] | string | true, - logged: LoggedMetadata, - route: string, -): (...args: F) => R; -function overrideBuild, R>( - type: 'function' | 'guard' | 'interceptor' | 'middleware', - originalFunction: (...args: F) => R, - baseLogger: Logger, - metadatas: FunctionMetadata, - key: string, - returnsData: ReturnsReflectData[] | string | true, - logged: LoggedMetadata, -): (...args: F) => R; -function overrideBuild, R>( - type: BuildType, - originalFunction: (...args: F) => R, - baseLogger: Logger, - metadatas: FunctionMetadata, - key: string, - returnsData: ReturnsReflectData[] | string | true, - logged: LoggedMetadata, - route?: string, -): (...args: F) => R { - return function (...args: F): R { - // Creating ScopedLogger - let injectedLogger: Logger = baseLogger; - if (typeof metadatas.scopedLoggerInjectableParam !== "undefined") { - if (type === 'function') { - if ( - args.length <= metadatas.scopedLoggerInjectableParam || - !(args[metadatas.scopedLoggerInjectableParam] instanceof ScopedLogger) - ) { - args[metadatas.scopedLoggerInjectableParam] = ScopedLogger.fromRoot(baseLogger, key); - } else { - args[metadatas.scopedLoggerInjectableParam] = ScopedLogger.fromSuper(baseLogger, args[metadatas.scopedLoggerInjectableParam], key); - } - } else { - // special, can access to request object - if (type === 'guard' || type === 'interceptor') { - // args[0] == ExecutionContext - const ctx = (args[0] as ExecutionContext); - if (ctx.getType() !== 'http') { - injectedLogger.error('Cannot inject logger: Request type is not http'); - } else { - let req = ctx.switchToHttp().getRequest(); - if (req[REQUEST_LOG_ID] === undefined) { - req[REQUEST_LOG_ID] = ScopedLogger.createScopeId(); - } - args[metadatas.scopedLoggerInjectableParam] = ScopedLogger.fromRoot(baseLogger, key, req[REQUEST_LOG_ID]); - } - } else if (type === 'middleware') { - let req = args[0]; - if (req[REQUEST_LOG_ID] === undefined) { - req[REQUEST_LOG_ID] = ScopedLogger.createScopeId(); - } - args[metadatas.scopedLoggerInjectableParam] = ScopedLogger.fromRoot(baseLogger, key, req[REQUEST_LOG_ID]); - } else if (type === 'route') { - // args[metadatas.scopedLoggerInjectableParam] is now Request object, thanks to code in @LoggedRoute!!!! - let req = args[metadatas.scopedLoggerInjectableParam]; - if (req[REQUEST_LOG_ID] === undefined) { - req[REQUEST_LOG_ID] = ScopedLogger.createScopeId(); - } - args[metadatas.scopedLoggerInjectableParam] = ScopedLogger.fromRoot(baseLogger, key, req[REQUEST_LOG_ID]); - } - } - - injectedLogger = args[metadatas.scopedLoggerInjectableParam]; - } - - // If this is ExecutionContext based function (e.g. Guard, Interceptor) get Request from Context - if (type === 'guard' || type === 'interceptor') { - const context = args[0] as ExecutionContext; - if (context.getType() === 'http') { - const req = context.switchToHttp().getRequest(); - route = /* supporting FastifyRequest */ req.raw ? req.raw.url : req.url; - } - } - - // Start Log - if (logged.options.callLogLevel !== 'skip') { - const callLogIdentifyMessage = - type === 'middleware' || type === 'guard' || type === 'interceptor' || type === 'route' - ? createCallLogIdentifyMessage('HIT', type, key, route) - : createCallLogIdentifyMessage('HIT', type, key); - injectedLogger[logged.options.callLogLevel]( - `${callLogIdentifyMessage} ${metadatas.loggedParams && metadatas.loggedParams.length > 0 - ? "WITH " + - metadatas.loggedParams.map( - ({ name, index, include, exclude }) => - name + - "=" + - objectContainedLogSync(args[index], { - include, - exclude, - }) - ).join(", ") - : "" - }` - ); - } - - try { - const r: R = originalFunction.call(this, ...args); // Try to call original function - - // Return Log - if (logged.options.returnLogLevel !== 'skip') { - if ( - originalFunction.constructor.name === 'AsyncFunction' || - (r && typeof r === 'object' && typeof r['then'] === 'function') - ) { - return r['then']((r: any) => { - const resultLogged = Array.isArray(returnsData) - ? typeof r === "object" && r !== null - ? "WITH " + - returnsData.map(({ name, path }) => { - const value = getItemByPathSync(r, path); - - return value !== undefined ? `${name}=${value}` : ""; - }) - .filter((v) => v.length > 0) - .join(", ") - : "" - : typeof returnsData === 'string' - ? "WITH " + returnsData + "=" + typeof r === "object" ? JSON.stringify(r) : r - : returnsData - ? typeof r === "object" - ? "WITH " + JSON.stringify(r) - : "WITH " + r - : ""; - - injectedLogger[logged.options.returnLogLevel](`${createCallLogIdentifyMessage('RETURNED', type, key, route)} ${resultLogged}`); - return r; - }) - } else { - const resultLogged = Array.isArray(returnsData) - ? typeof r === "object" && r !== null - ? "WITH " + - returnsData.map(({ name, path }) => { - const value = getItemByPathSync(r, path); - - return value !== undefined ? `${name}=${value}` : ""; - }) - .filter((v) => v.length > 0) - .join(", ") - : "" - : typeof returnsData === 'string' - ? "WITH " + returnsData + "=" + typeof r === "object" ? JSON.stringify(r) : r - : returnsData - ? typeof r === "object" - ? "WITH " + JSON.stringify(r) - : "WITH " + r - : ""; - - injectedLogger[logged.options.returnLogLevel](`${createCallLogIdentifyMessage('RETURNED', type, key, route)} ${resultLogged}`); - return r; - } - } else { - return r; - } - } catch (e) { - // Error Log - if (logged.options.errorLogLevel !== 'skip') { - injectedLogger[logged.options.errorLogLevel](`${createCallLogIdentifyMessage('ERROR', type, key, route)} ${e}`); - } - throw e; - } - } -} - -export function LoggedFunction, R>( - options?: Partial -) { - return ( - _target: any, - key: string, - descriptor: TypedPropertyDescriptor<(...args: F) => R | Promise> - ) => { - loggerInit(_target); - - const logger: Logger = _target.logger; - - const fn = descriptor.value; - - if (!fn || typeof fn !== "function") { - logger.warn( - `LoggedFunction decorator applied to non-function property: ${key}` - ); - return; - } - - const logMetadata: LoggedMetadata | undefined = Reflect.getOwnMetadata( - nestLoggedMetadata, - _target, - key - ) - if (logMetadata) { - // already applied, override instead - logMetadata.updateOption(options) - return - } - const newMetadata = new LoggedMetadata(options); - - const all = Reflect.getMetadataKeys(fn).map((k) => [ - k, - Reflect.getMetadata(k, fn), - ]); - - const scopedLoggerInjectableParam: number = Reflect.getOwnMetadata( - scopedLogger, - _target, - key - ); - - const loggedParams: LoggedParamReflectData[] = Reflect.getOwnMetadata( - loggedParam, - _target, - key - ); - - const returnsData: ReturnsReflectData[] | true = Reflect.getOwnMetadata( - returns, - fn - ); - - const overrideFunction = overrideBuild( - 'function', - fn, - logger, - { - scopedLoggerInjectableParam, - loggedParams, - }, - key, - returnsData, - newMetadata, - ); - - _target[key] = overrideFunction; - descriptor.value = overrideFunction; - - Reflect.defineMetadata( - nestLoggedMetadata, - newMetadata, - _target, - key - ) - all.forEach(([k, v]) => { - Reflect.defineMetadata(k, v, _target[key]); - Reflect.defineMetadata(k, v, descriptor.value); - }); - } -} - -export function LoggedRoute, R>(route?: string, options?: Partial) { - return ( - _target: any, - key: string, - descriptor: TypedPropertyDescriptor<(...args: F) => R> - ) => { - loggerInit(_target); - - const logger = _target.logger; - - const fn = descriptor.value; - - if (!fn || typeof fn !== "function") { - logger.warn( - `LoggedRoute decorator applied to non-function property: ${key}` - ); - return; - } - - const logMetadata: LoggedMetadata | undefined = Reflect.getOwnMetadata( - nestLoggedMetadata, - _target, - key - ) - if (logMetadata) { - // already applied, override instead - logMetadata.updateOption(options) - return - } - const newMetadata = new LoggedMetadata(options); - - const all = Reflect.getMetadataKeys(fn).map((k) => [ - k, - Reflect.getMetadata(k, fn), - ]); - - const httpPath: string = Reflect.getMetadata("path", fn); - const httpMethod: RequestMethod = Reflect.getMetadata("method", fn); - - const fullRoute = `${_target.constructor.name}::${route ?? httpPath}[${RevRequestMethod[httpMethod] - }]`; - - const scopedLoggerInjectableParam: number = Reflect.getOwnMetadata( - scopedLogger, - _target, - key - ); - // if @InjectLogger exists, fake nestjs as it is @Req() - if (scopedLoggerInjectableParam !== undefined) { - createRouteParamDecorator(0)()(_target, key, scopedLoggerInjectableParam); - } - - const loggedParams: LoggedParamReflectData[] = Reflect.getOwnMetadata( - loggedParam, - _target, - key - ); - - const returnsData: ReturnsReflectData[] | true = Reflect.getOwnMetadata( - returns, - fn - ); - - const overrideFunction = overrideBuild( - 'route', - fn, - logger, - { - scopedLoggerInjectableParam, - loggedParams, - }, - key, - returnsData, - newMetadata, - fullRoute, - ); - - _target[key] = overrideFunction; - descriptor.value = overrideFunction; - - Reflect.defineMetadata( - nestLoggedMetadata, - newMetadata, - _target, - key - ) - all.forEach(([k, v]) => { - Reflect.defineMetadata(k, v, _target[key]); - Reflect.defineMetadata(k, v, descriptor.value); - }); - }; -} - -export function LoggedGuard, R>(options?: Partial) { - return ( - _target: any, - key: string, - descriptor: TypedPropertyDescriptor<(context: ExecutionContext, ...args: F) => R> - ) => { - loggerInit(_target); - - const logger: Logger = _target.logger; - - const fn = descriptor.value; - - if (!fn || typeof fn!== "function") { - logger.warn( - `LoggedGuard decorator applied to non-function property: ${key}` - ); - return; - } - - const logMetadata: LoggedMetadata | undefined = Reflect.getOwnMetadata( - nestLoggedMetadata, - _target, - key - ) - if (logMetadata) { - // already applied, override instead - logMetadata.updateOption(options) - return - } - const newMetadata = new LoggedMetadata(options); - - const all = Reflect.getMetadataKeys(fn).map((k) => [ - k, - Reflect.getMetadata(k, fn), - ]); - - const scopedLoggerInjectableParam: number = Reflect.getOwnMetadata( - scopedLogger, - _target, - key - ); - - const returnsData: ReturnsReflectData[] | true = Reflect.getOwnMetadata( - returns, - fn - ); - - const overrideFunction = overrideBuild( - 'guard', - fn, - logger, - { - scopedLoggerInjectableParam, - loggedParams: [], - }, - _target.constructor.name, - returnsData, - newMetadata, - ); - - _target[key] = overrideFunction; - descriptor.value = overrideFunction; - - Reflect.defineMetadata( - nestLoggedMetadata, - newMetadata, - _target, - key - ) - all.forEach(([k, v]) => { - Reflect.defineMetadata(k, v, _target[key]); - Reflect.defineMetadata(k, v, descriptor.value); - }); - } -} - -export function LoggedInterceptor, R>(options?: Partial) { - return ( - _target: any, - key: string, - descriptor: TypedPropertyDescriptor<(context: ExecutionContext, ...args: F) => R> - ) => { - loggerInit(_target); - - const logger: Logger = _target.logger; - - const fn = descriptor.value; - - if (!fn || typeof fn!== "function") { - logger.warn( - `LoggedInterceptor decorator applied to non-function property: ${key}` - ); - return; - } - - const logMetadata: LoggedMetadata | undefined = Reflect.getOwnMetadata( - nestLoggedMetadata, - _target, - key - ) - if (logMetadata) { - // already applied, override instead - logMetadata.updateOption(options) - return - } - const newMetadata = new LoggedMetadata(options); - - const all = Reflect.getMetadataKeys(fn).map((k) => [ - k, - Reflect.getMetadata(k, fn), - ]); - - const scopedLoggerInjectableParam: number = Reflect.getOwnMetadata( - scopedLogger, - _target, - key - ); - - const returnsData: ReturnsReflectData[] | true = Reflect.getOwnMetadata( - returns, - fn - ); - - const overrideFunction = overrideBuild( - 'interceptor', - fn, - logger, - { - scopedLoggerInjectableParam, - loggedParams: [], - }, - _target.constructor.name, - returnsData, - newMetadata, - ); - - _target[key] = overrideFunction; - descriptor.value = overrideFunction; - - Reflect.defineMetadata( - nestLoggedMetadata, - newMetadata, - _target, - key - ) - all.forEach(([k, v]) => { - Reflect.defineMetadata(k, v, _target[key]); - Reflect.defineMetadata(k, v, descriptor.value); - }); - } -} - -export function LoggedMiddleware, R>(options?: Partial) { - return ( - _target: any, - key: string, - descriptor: TypedPropertyDescriptor<(context: ExecutionContext, ...args: F) => R> - ) => { - loggerInit(_target); - - const logger: Logger = _target.logger; - - const fn = descriptor.value; - - if (!fn || typeof fn!== "function") { - logger.warn( - `LoggedMiddleware decorator applied to non-function property: ${key}` - ); - return; - } - - const logMetadata: LoggedMetadata | undefined = Reflect.getOwnMetadata( - nestLoggedMetadata, - _target, - key - ) - if (logMetadata) { - // already applied, override instead - logMetadata.updateOption(options) - return - } - const newMetadata = new LoggedMetadata(options); - - const all = Reflect.getMetadataKeys(fn).map((k) => [ - k, - Reflect.getMetadata(k, fn), - ]); - - const scopedLoggerInjectableParam: number = Reflect.getOwnMetadata( - scopedLogger, - _target, - key - ); - - const returnsData: ReturnsReflectData[] | true = Reflect.getOwnMetadata( - returns, - fn - ); - - const overrideFunction = overrideBuild( - 'middleware', - fn, - logger, - { - scopedLoggerInjectableParam, - loggedParams: [], - }, - _target.constructor.name, - returnsData, - newMetadata, - ); - - _target[key] = overrideFunction; - descriptor.value = overrideFunction; - - Reflect.defineMetadata( - nestLoggedMetadata, - newMetadata, - _target, - key - ) - all.forEach(([k, v]) => { - Reflect.defineMetadata(k, v, _target[key]); - Reflect.defineMetadata(k, v, descriptor.value); - }); - } -} \ No newline at end of file diff --git a/src/logged/class.ts b/src/logged/class.ts new file mode 100644 index 0000000..b8b47dc --- /dev/null +++ b/src/logged/class.ts @@ -0,0 +1,87 @@ +import { + Injectable, + Controller, + ControllerOptions, + ScopeOptions, +} from "@nestjs/common"; +import { + loggerInit, + RevRequestMethod +} from './utils'; +import { + LoggedRoute, + LoggedFunction +} from "./methods"; + +export function LoggedInjectable( + options?: ScopeOptions & { verbose?: boolean } +) { + return (target: any) => { + loggerInit(target.prototype); + + const logger = target.prototype.logger; + + const methods = Object.getOwnPropertyNames(target.prototype); + + methods.forEach((method) => { + if ( + method !== "constructor" && + typeof target.prototype[method] === "function" + ) { + if (options && options.verbose) + logger.log(`LoggedFunction applied to ${method}`); + LoggedFunction()(target.prototype, method, { + value: target.prototype[method], + }); + } + }); + + Injectable(options)(target); + }; +} + + export function LoggedController(): (target: any) => void; + export function LoggedController( + prefix: string | string[] + ): (target: any) => void; + export function LoggedController( + options: ControllerOptions & { verbose?: boolean } + ): (target: any) => void; + + export function LoggedController(param?: any): (target: any) => void { + return (target: any) => { + loggerInit(target.prototype); + + const logger = target.prototype.logger; + + const methods = Object.getOwnPropertyNames(target.prototype); + + let verbose = + typeof param === "object" && Object.keys(param).includes("verbose") + ? param.verbose + : false; + + methods.forEach((method) => { + if ( + method !== "constructor" && + typeof target.prototype[method] === "function" + ) { + if (verbose) { + const path = Reflect.getMetadata("path", target.prototype[method]); + const httpMethod = Reflect.getMetadata( + "method", + target.prototype[method] + ); + logger.log( + `LoggedRoute applied to ${method} (${RevRequestMethod[httpMethod]} ${path})` + ); + } + LoggedRoute()(target.prototype, method, { + value: target.prototype[method], + }); + } + }); + + Controller(param)(target); + }; + } \ No newline at end of file diff --git a/src/logged/index.ts b/src/logged/index.ts new file mode 100644 index 0000000..d6e5803 --- /dev/null +++ b/src/logged/index.ts @@ -0,0 +1,2 @@ +export * from "./methods"; +export { LoggedController, LoggedInjectable } from "./class" \ No newline at end of file diff --git a/src/logged/metadata.ts b/src/logged/metadata.ts new file mode 100644 index 0000000..a48d753 --- /dev/null +++ b/src/logged/metadata.ts @@ -0,0 +1,21 @@ +import { OverrideBuildOptions, defaultOverrideBuildOptions } from './utils'; + +export const nestLoggedMetadata = Symbol("nlogdec-metadata"); + +export class LoggedMetadata { + options: OverrideBuildOptions + + constructor(options?: Partial) { + this.options = { + ...defaultOverrideBuildOptions, + ...(options ?? {}), + } + } + + updateOption(options: Partial) { + this.options = { + ...this.options, + ...options + } + } +} \ No newline at end of file diff --git a/src/logged/methods/function.ts b/src/logged/methods/function.ts new file mode 100644 index 0000000..75110e1 --- /dev/null +++ b/src/logged/methods/function.ts @@ -0,0 +1,89 @@ +import { Logger } from "@nestjs/common"; +import { OverrideBuildOptions, loggerInit } from "../utils"; +import { LoggedMetadata, nestLoggedMetadata } from "../metadata"; +import { loggedParam, scopedLogger, returns, ReturnsReflectData, LoggedParamReflectData } from "../../reflected"; +import { overrideBuild } from "../override"; + +export function LoggedFunction, R>( + options?: Partial +) { + return ( + _target: any, + key: string, + descriptor: TypedPropertyDescriptor<(...args: F) => R | Promise> + ) => { + loggerInit(_target); + + const logger: Logger = _target.logger; + + const fn = descriptor.value; + + if (!fn || typeof fn !== "function") { + logger.warn( + `LoggedFunction decorator applied to non-function property: ${key}` + ); + return; + } + + const logMetadata: LoggedMetadata | undefined = Reflect.getOwnMetadata( + nestLoggedMetadata, + _target, + key + ) + if (logMetadata) { + // already applied, override instead + logMetadata.updateOption(options) + return + } + const newMetadata = new LoggedMetadata(options); + + const all = Reflect.getMetadataKeys(fn).map((k) => [ + k, + Reflect.getMetadata(k, fn), + ]); + + const scopedLoggerInjectableParam: number = Reflect.getOwnMetadata( + scopedLogger, + _target, + key + ); + + const loggedParams: LoggedParamReflectData[] = Reflect.getOwnMetadata( + loggedParam, + _target, + key + ); + + const returnsData: ReturnsReflectData[] | true = Reflect.getOwnMetadata( + returns, + fn + ); + + const overrideFunction = overrideBuild( + 'function', + fn, + logger, + { + scopedLoggerInjectableParam, + loggedParams, + }, + key, + returnsData, + newMetadata, + ); + + _target[key] = overrideFunction; + descriptor.value = overrideFunction; + + Reflect.defineMetadata( + nestLoggedMetadata, + newMetadata, + _target, + key + ) + all.forEach(([k, v]) => { + Reflect.defineMetadata(k, v, _target[key]); + Reflect.defineMetadata(k, v, descriptor.value); + }); + } +} \ No newline at end of file diff --git a/src/logged/methods/guard.ts b/src/logged/methods/guard.ts new file mode 100644 index 0000000..8f8d0e6 --- /dev/null +++ b/src/logged/methods/guard.ts @@ -0,0 +1,81 @@ +import { ExecutionContext, Logger } from "@nestjs/common"; +import { OverrideBuildOptions, loggerInit } from "../utils"; +import { LoggedMetadata, nestLoggedMetadata } from "../metadata"; +import { scopedLogger, returns, ReturnsReflectData } from "../../reflected"; +import { overrideBuild } from "../override"; + +export function LoggedGuard, R>(options?: Partial) { + return ( + _target: any, + key: string, + descriptor: TypedPropertyDescriptor<(context: ExecutionContext, ...args: F) => R> + ) => { + loggerInit(_target); + + const logger: Logger = _target.logger; + + const fn = descriptor.value; + + if (!fn || typeof fn!== "function") { + logger.warn( + `LoggedGuard decorator applied to non-function property: ${key}` + ); + return; + } + + const logMetadata: LoggedMetadata | undefined = Reflect.getOwnMetadata( + nestLoggedMetadata, + _target, + key + ) + if (logMetadata) { + // already applied, override instead + logMetadata.updateOption(options) + return + } + const newMetadata = new LoggedMetadata(options); + + const all = Reflect.getMetadataKeys(fn).map((k) => [ + k, + Reflect.getMetadata(k, fn), + ]); + + const scopedLoggerInjectableParam: number = Reflect.getOwnMetadata( + scopedLogger, + _target, + key + ); + + const returnsData: ReturnsReflectData[] | true = Reflect.getOwnMetadata( + returns, + fn + ); + + const overrideFunction = overrideBuild( + 'guard', + fn, + logger, + { + scopedLoggerInjectableParam, + loggedParams: [], + }, + _target.constructor.name, + returnsData, + newMetadata, + ); + + _target[key] = overrideFunction; + descriptor.value = overrideFunction; + + Reflect.defineMetadata( + nestLoggedMetadata, + newMetadata, + _target, + key + ) + all.forEach(([k, v]) => { + Reflect.defineMetadata(k, v, _target[key]); + Reflect.defineMetadata(k, v, descriptor.value); + }); + } +} \ No newline at end of file diff --git a/src/logged/methods/index.ts b/src/logged/methods/index.ts new file mode 100644 index 0000000..48548ea --- /dev/null +++ b/src/logged/methods/index.ts @@ -0,0 +1,5 @@ +export { LoggedFunction } from "./function"; +export { LoggedRoute } from "./route"; +export { LoggedGuard } from "./guard"; +export { LoggedInterceptor } from "./interceptor"; +export { LoggedMiddleware } from "./middleware"; \ No newline at end of file diff --git a/src/logged/methods/interceptor.ts b/src/logged/methods/interceptor.ts new file mode 100644 index 0000000..b3e29af --- /dev/null +++ b/src/logged/methods/interceptor.ts @@ -0,0 +1,82 @@ +import { OverrideBuildOptions } from "../utils"; +import { ExecutionContext, Logger } from "@nestjs/common"; +import { loggerInit } from "../utils"; +import { LoggedMetadata, nestLoggedMetadata } from '../metadata'; +import { scopedLogger, returns, ReturnsReflectData } from "../../reflected"; +import { overrideBuild } from "../override"; + +export function LoggedInterceptor, R>(options?: Partial) { + return ( + _target: any, + key: string, + descriptor: TypedPropertyDescriptor<(context: ExecutionContext, ...args: F) => R> + ) => { + loggerInit(_target); + + const logger: Logger = _target.logger; + + const fn = descriptor.value; + + if (!fn || typeof fn!== "function") { + logger.warn( + `LoggedInterceptor decorator applied to non-function property: ${key}` + ); + return; + } + + const logMetadata: LoggedMetadata | undefined = Reflect.getOwnMetadata( + nestLoggedMetadata, + _target, + key + ) + if (logMetadata) { + // already applied, override instead + logMetadata.updateOption(options) + return + } + const newMetadata = new LoggedMetadata(options); + + const all = Reflect.getMetadataKeys(fn).map((k) => [ + k, + Reflect.getMetadata(k, fn), + ]); + + const scopedLoggerInjectableParam: number = Reflect.getOwnMetadata( + scopedLogger, + _target, + key + ); + + const returnsData: ReturnsReflectData[] | true = Reflect.getOwnMetadata( + returns, + fn + ); + + const overrideFunction = overrideBuild( + 'interceptor', + fn, + logger, + { + scopedLoggerInjectableParam, + loggedParams: [], + }, + _target.constructor.name, + returnsData, + newMetadata, + ); + + _target[key] = overrideFunction; + descriptor.value = overrideFunction; + + Reflect.defineMetadata( + nestLoggedMetadata, + newMetadata, + _target, + key + ) + all.forEach(([k, v]) => { + Reflect.defineMetadata(k, v, _target[key]); + Reflect.defineMetadata(k, v, descriptor.value); + }); + } +} \ No newline at end of file diff --git a/src/logged/methods/middleware.ts b/src/logged/methods/middleware.ts new file mode 100644 index 0000000..613cbd5 --- /dev/null +++ b/src/logged/methods/middleware.ts @@ -0,0 +1,82 @@ +import { OverrideBuildOptions } from "../utils"; +import { ExecutionContext, Logger } from "@nestjs/common"; +import { loggerInit } from "../utils"; +import { LoggedMetadata, nestLoggedMetadata } from '../metadata'; +import { scopedLogger, returns, ReturnsReflectData } from "../../reflected"; +import { overrideBuild } from "../override"; + +export function LoggedMiddleware, R>(options?: Partial) { + return ( + _target: any, + key: string, + descriptor: TypedPropertyDescriptor<(context: ExecutionContext, ...args: F) => R> + ) => { + loggerInit(_target); + + const logger: Logger = _target.logger; + + const fn = descriptor.value; + + if (!fn || typeof fn!== "function") { + logger.warn( + `LoggedMiddleware decorator applied to non-function property: ${key}` + ); + return; + } + + const logMetadata: LoggedMetadata | undefined = Reflect.getOwnMetadata( + nestLoggedMetadata, + _target, + key + ) + if (logMetadata) { + // already applied, override instead + logMetadata.updateOption(options) + return + } + const newMetadata = new LoggedMetadata(options); + + const all = Reflect.getMetadataKeys(fn).map((k) => [ + k, + Reflect.getMetadata(k, fn), + ]); + + const scopedLoggerInjectableParam: number = Reflect.getOwnMetadata( + scopedLogger, + _target, + key + ); + + const returnsData: ReturnsReflectData[] | true = Reflect.getOwnMetadata( + returns, + fn + ); + + const overrideFunction = overrideBuild( + 'middleware', + fn, + logger, + { + scopedLoggerInjectableParam, + loggedParams: [], + }, + _target.constructor.name, + returnsData, + newMetadata, + ); + + _target[key] = overrideFunction; + descriptor.value = overrideFunction; + + Reflect.defineMetadata( + nestLoggedMetadata, + newMetadata, + _target, + key + ) + all.forEach(([k, v]) => { + Reflect.defineMetadata(k, v, _target[key]); + Reflect.defineMetadata(k, v, descriptor.value); + }); + } +} \ No newline at end of file diff --git a/src/logged/methods/route.ts b/src/logged/methods/route.ts new file mode 100644 index 0000000..164fea9 --- /dev/null +++ b/src/logged/methods/route.ts @@ -0,0 +1,99 @@ +import { RequestMethod } from "@nestjs/common"; +import { OverrideBuildOptions, loggerInit, RevRequestMethod } from "../utils"; +import { LoggedMetadata, nestLoggedMetadata } from "../metadata"; +import { loggedParam, scopedLogger, returns, ReturnsReflectData, LoggedParamReflectData } from "../../reflected"; +import { overrideBuild } from "../override"; +import { createRouteParamDecorator } from "../../internals/nest"; + +export function LoggedRoute, R>(route?: string, options?: Partial) { + return ( + _target: any, + key: string, + descriptor: TypedPropertyDescriptor<(...args: F) => R> + ) => { + loggerInit(_target); + + const logger = _target.logger; + + const fn = descriptor.value; + + if (!fn || typeof fn !== "function") { + logger.warn( + `LoggedRoute decorator applied to non-function property: ${key}` + ); + return; + } + + const logMetadata: LoggedMetadata | undefined = Reflect.getOwnMetadata( + nestLoggedMetadata, + _target, + key + ) + if (logMetadata) { + // already applied, override instead + logMetadata.updateOption(options) + return + } + const newMetadata = new LoggedMetadata(options); + + const all = Reflect.getMetadataKeys(fn).map((k) => [ + k, + Reflect.getMetadata(k, fn), + ]); + + const httpPath: string = Reflect.getMetadata("path", fn); + const httpMethod: RequestMethod = Reflect.getMetadata("method", fn); + + const fullRoute = `${_target.constructor.name}::${route ?? httpPath}[${RevRequestMethod[httpMethod] + }]`; + + const scopedLoggerInjectableParam: number = Reflect.getOwnMetadata( + scopedLogger, + _target, + key + ); + // if @InjectLogger exists, fake nestjs as it is @Req() + if (scopedLoggerInjectableParam !== undefined) { + createRouteParamDecorator(0)()(_target, key, scopedLoggerInjectableParam); + } + + const loggedParams: LoggedParamReflectData[] = Reflect.getOwnMetadata( + loggedParam, + _target, + key + ); + + const returnsData: ReturnsReflectData[] | true = Reflect.getOwnMetadata( + returns, + fn + ); + + const overrideFunction = overrideBuild( + 'route', + fn, + logger, + { + scopedLoggerInjectableParam, + loggedParams, + }, + key, + returnsData, + newMetadata, + fullRoute, + ); + + _target[key] = overrideFunction; + descriptor.value = overrideFunction; + + Reflect.defineMetadata( + nestLoggedMetadata, + newMetadata, + _target, + key + ) + all.forEach(([k, v]) => { + Reflect.defineMetadata(k, v, _target[key]); + Reflect.defineMetadata(k, v, descriptor.value); + }); + }; +} \ No newline at end of file diff --git a/src/logged/override.ts b/src/logged/override.ts new file mode 100644 index 0000000..922bfcf --- /dev/null +++ b/src/logged/override.ts @@ -0,0 +1,186 @@ +import { Logger, ExecutionContext } from "@nestjs/common"; +import { LoggedParamReflectData, ReturnsReflectData } from "../reflected"; +import { LoggedMetadata } from './metadata'; +import { BuildType, REQUEST_LOG_ID, createCallLogIdentifyMessage } from "./utils"; +import { objectContainedLogSync, getItemByPathSync } from "../internals/utils"; +import { ScopedLogger } from "../logger"; + +interface FunctionMetadata { + scopedLoggerInjectableParam?: number; + loggedParams?: LoggedParamReflectData[]; +} + +export function overrideBuild, R>( + type: 'route', + originalFunction: (...args: F) => R, + baseLogger: Logger, + metadatas: FunctionMetadata, + key: string, + returnsData: ReturnsReflectData[] | string | true, + logged: LoggedMetadata, + route: string, +): (...args: F) => R; +export function overrideBuild, R>( + type: 'function' | 'guard' | 'interceptor' | 'middleware', + originalFunction: (...args: F) => R, + baseLogger: Logger, + metadatas: FunctionMetadata, + key: string, + returnsData: ReturnsReflectData[] | string | true, + logged: LoggedMetadata, +): (...args: F) => R; +export function overrideBuild, R>( + type: BuildType, + originalFunction: (...args: F) => R, + baseLogger: Logger, + metadatas: FunctionMetadata, + key: string, + returnsData: ReturnsReflectData[] | string | true, + logged: LoggedMetadata, + route?: string, +): (...args: F) => R { + return function (...args: F): R { + // Creating ScopedLogger + let injectedLogger: Logger = baseLogger; + if (typeof metadatas.scopedLoggerInjectableParam !== "undefined") { + if (type === 'function') { + if ( + args.length <= metadatas.scopedLoggerInjectableParam || + !(args[metadatas.scopedLoggerInjectableParam] instanceof ScopedLogger) + ) { + args[metadatas.scopedLoggerInjectableParam] = ScopedLogger.fromRoot(baseLogger, key); + } else { + args[metadatas.scopedLoggerInjectableParam] = ScopedLogger.fromSuper(baseLogger, args[metadatas.scopedLoggerInjectableParam], key); + } + } else { + // special, can access to request object + if (type === 'guard' || type === 'interceptor') { + // args[0] == ExecutionContext + const ctx = (args[0] as ExecutionContext); + if (ctx.getType() !== 'http') { + injectedLogger.error('Cannot inject logger: Request type is not http'); + } else { + let req = ctx.switchToHttp().getRequest(); + if (req[REQUEST_LOG_ID] === undefined) { + req[REQUEST_LOG_ID] = ScopedLogger.createScopeId(); + } + args[metadatas.scopedLoggerInjectableParam] = ScopedLogger.fromRoot(baseLogger, key, req[REQUEST_LOG_ID]); + } + } else if (type === 'middleware') { + let req = args[0]; + if (req[REQUEST_LOG_ID] === undefined) { + req[REQUEST_LOG_ID] = ScopedLogger.createScopeId(); + } + args[metadatas.scopedLoggerInjectableParam] = ScopedLogger.fromRoot(baseLogger, key, req[REQUEST_LOG_ID]); + } else if (type === 'route') { + // args[metadatas.scopedLoggerInjectableParam] is now Request object, thanks to code in @LoggedRoute!!!! + let req = args[metadatas.scopedLoggerInjectableParam]; + if (req[REQUEST_LOG_ID] === undefined) { + req[REQUEST_LOG_ID] = ScopedLogger.createScopeId(); + } + args[metadatas.scopedLoggerInjectableParam] = ScopedLogger.fromRoot(baseLogger, key, req[REQUEST_LOG_ID]); + } + } + + injectedLogger = args[metadatas.scopedLoggerInjectableParam]; + } + + // If this is ExecutionContext based function (e.g. Guard, Interceptor) get Request from Context + if (type === 'guard' || type === 'interceptor') { + const context = args[0] as ExecutionContext; + if (context.getType() === 'http') { + const req = context.switchToHttp().getRequest(); + route = /* supporting FastifyRequest */ req.raw ? req.raw.url : req.url; + } + } + + // Start Log + if (logged.options.callLogLevel !== 'skip') { + const callLogIdentifyMessage = + type === 'middleware' || type === 'guard' || type === 'interceptor' || type === 'route' + ? createCallLogIdentifyMessage('HIT', type, key, route) + : createCallLogIdentifyMessage('HIT', type, key); + injectedLogger[logged.options.callLogLevel]( + `${callLogIdentifyMessage} ${metadatas.loggedParams && metadatas.loggedParams.length > 0 + ? "WITH " + + metadatas.loggedParams.map( + ({ name, index, include, exclude }) => + name + + "=" + + objectContainedLogSync(args[index], { + include, + exclude, + }) + ).join(", ") + : "" + }` + ); + } + + try { + const r: R = originalFunction.call(this, ...args); // Try to call original function + + // Return Log + if (logged.options.returnLogLevel !== 'skip') { + if ( + originalFunction.constructor.name === 'AsyncFunction' || + (r && typeof r === 'object' && typeof r['then'] === 'function') + ) { + return r['then']((r: any) => { + const resultLogged = Array.isArray(returnsData) + ? typeof r === "object" && r !== null + ? "WITH " + + returnsData.map(({ name, path }) => { + const value = getItemByPathSync(r, path); + + return value !== undefined ? `${name}=${value}` : ""; + }) + .filter((v) => v.length > 0) + .join(", ") + : "" + : typeof returnsData === 'string' + ? "WITH " + returnsData + "=" + typeof r === "object" ? JSON.stringify(r) : r + : returnsData + ? typeof r === "object" + ? "WITH " + JSON.stringify(r) + : "WITH " + r + : ""; + + injectedLogger[logged.options.returnLogLevel](`${createCallLogIdentifyMessage('RETURNED', type, key, route)} ${resultLogged}`); + return r; + }) + } else { + const resultLogged = Array.isArray(returnsData) + ? typeof r === "object" && r !== null + ? "WITH " + + returnsData.map(({ name, path }) => { + const value = getItemByPathSync(r, path); + + return value !== undefined ? `${name}=${value}` : ""; + }) + .filter((v) => v.length > 0) + .join(", ") + : "" + : typeof returnsData === 'string' + ? "WITH " + returnsData + "=" + typeof r === "object" ? JSON.stringify(r) : r + : returnsData + ? typeof r === "object" + ? "WITH " + JSON.stringify(r) + : "WITH " + r + : ""; + + injectedLogger[logged.options.returnLogLevel](`${createCallLogIdentifyMessage('RETURNED', type, key, route)} ${resultLogged}`); + return r; + } + } else { + return r; + } + } catch (e) { + // Error Log + if (logged.options.errorLogLevel !== 'skip') { + injectedLogger[logged.options.errorLogLevel](`${createCallLogIdentifyMessage('ERROR', type, key, route)} ${e}`); + } + throw e; + } + } +} \ No newline at end of file diff --git a/src/logged/utils.ts b/src/logged/utils.ts new file mode 100644 index 0000000..2545ea2 --- /dev/null +++ b/src/logged/utils.ts @@ -0,0 +1,71 @@ +import { Logger, LogLevel } from "@nestjs/common"; + +export const RevRequestMethod = [ + "GET", + "POST", + "PUT", + "DELETE", + "PATCH", + "ALL", + "OPTIONS", + "HEAD", + "SEARCH", +]; + +export function loggerInit(_target: any) { + if (!Object.getOwnPropertyNames(_target).includes("logger")) { + const newTargetLogger = new Logger(_target.constructor.name); + newTargetLogger.log("Logger Initialized."); + Object.defineProperty(_target, "logger", { + writable: false, + enumerable: false, + configurable: false, + value: newTargetLogger, + }); + } +} + +export type BuildType = 'route' | 'function' | 'guard' | 'interceptor' | 'middleware'; + +const callLogIdentifyMessageDictionary: Record = { + route: 'ENDPOINT', + function: 'FUNCTION', + guard: 'GUARD', + interceptor: 'INTERCEPTOR', + middleware: 'MIDDLEWARE', +} + +export function createCallLogIdentifyMessage(message: 'HIT' | 'RETURNED' | 'ERROR', type: BuildType, key?: string, route?: string) { + if (message === 'ERROR') + return `ERROR WHILE ${callLogIdentifyMessageDictionary[type]} ${key} (${route}): `; + + if (type === 'guard' || type === 'interceptor' || type === 'middleware' || type === 'route') + return `${message} ${callLogIdentifyMessageDictionary[type]} ${key} (${route})` + if (type === 'function') + return `${message} ${callLogIdentifyMessageDictionary[type]} ${key}`; + + return `${message} ${callLogIdentifyMessageDictionary[type]}`; +} + +export const REQUEST_LOG_ID = '__nestlogged_request_log_id__'; + +export interface OverrideBuildOptions { + callLogLevel: LogLevel | 'skip'; + returnLogLevel: LogLevel | 'skip'; + errorLogLevel: LogLevel | 'skip'; + /** @deprecated use `callLogLevel: 'skip'` instead */ + skipCallLog: boolean; + /** @deprecated use `returnLogLevel: 'skip'` instead */ + skipReturnLog: boolean; + /** @deprecated use `errorLogLevel: 'skip'` instead */ + skipErrorLog: boolean; +} + +export const defaultOverrideBuildOptions: OverrideBuildOptions = { + callLogLevel: 'log', + returnLogLevel: 'log', + errorLogLevel: 'error', + skipCallLog: false, + skipReturnLog: false, + skipErrorLog: false, +} \ No newline at end of file diff --git a/src/reflected.ts b/src/reflected.ts index 080fefa..7ab6047 100644 --- a/src/reflected.ts +++ b/src/reflected.ts @@ -31,8 +31,6 @@ export const scopedLogger = Symbol("nlogdec-scopedLogger"); export const loggedParam = Symbol("nlogdec-loggedParam"); export const returns = Symbol("nlogdec-returns"); -export const nestLoggedMetadata = Symbol("nlogdec-metadata"); - export function InjectLogger( target: any, propertyKey: string | symbol, diff --git a/src/utils.ts b/src/utils.ts index f93e595..7908b99 100644 --- a/src/utils.ts +++ b/src/utils.ts @@ -1,6 +1,6 @@ import { Logger } from "@nestjs/common"; import { ScopedLogger } from "./logger"; -import { REQUEST_LOG_ID } from "./logged"; +import { REQUEST_LOG_ID } from "./logged/utils"; const logger = new Logger();