From 8243db4fbf13b8760c7287c2b48457d85f252e91 Mon Sep 17 00:00:00 2001 From: maslow Date: Thu, 2 Nov 2023 17:55:55 +0800 Subject: [PATCH] feat(runtime): beautify runtime log format (#1637) --- runtimes/nodejs/package-lock.json | 1 + runtimes/nodejs/package.json | 3 +- runtimes/nodejs/src/handler/invoke.ts | 50 ++++------ runtimes/nodejs/src/support/engine/console.ts | 98 +++++++++++++------ .../nodejs/src/support/engine/function.ts | 3 - .../ingress/runtime-ingress.service.ts | 2 + 6 files changed, 92 insertions(+), 65 deletions(-) diff --git a/runtimes/nodejs/package-lock.json b/runtimes/nodejs/package-lock.json index 8df98a068b..36edc72a63 100644 --- a/runtimes/nodejs/package-lock.json +++ b/runtimes/nodejs/package-lock.json @@ -14,6 +14,7 @@ "@kubernetes/client-node": "^0.18.0", "@lafjs/cloud": "^1.0.0-beta.12", "axios": "^1.4.0", + "chalk": "^4.1.2", "chatgpt": "^5.2.5", "cors": "^2.8.5", "database-proxy": "^1.0.0-beta.12", diff --git a/runtimes/nodejs/package.json b/runtimes/nodejs/package.json index c8644dd861..3d2b3bd3ff 100644 --- a/runtimes/nodejs/package.json +++ b/runtimes/nodejs/package.json @@ -31,6 +31,7 @@ "@kubernetes/client-node": "^0.18.0", "@lafjs/cloud": "^1.0.0-beta.12", "axios": "^1.4.0", + "chalk": "^4.1.2", "chatgpt": "^5.2.5", "cors": "^2.8.5", "database-proxy": "^1.0.0-beta.12", @@ -77,4 +78,4 @@ ], "delay": 1000 } -} \ No newline at end of file +} diff --git a/runtimes/nodejs/src/handler/invoke.ts b/runtimes/nodejs/src/handler/invoke.ts index 70c7d76927..1a76f937d1 100644 --- a/runtimes/nodejs/src/handler/invoke.ts +++ b/runtimes/nodejs/src/handler/invoke.ts @@ -2,9 +2,9 @@ import { Response } from 'express' import { IRequest } from '../support/types' import { DEFAULT_FUNCTION_NAME, INTERCEPTOR_FUNCTION_NAME } from '../constants' import { parseToken } from '../support/token' -import { logger } from '../support/logger' import { CloudFunction, + Console, DebugConsole, FunctionCache, FunctionContext, @@ -72,40 +72,27 @@ async function invokeFunction( return ctx.response.status(405).send('Method Not Allowed') } + const logger = new Console(func.data.name) try { // execute the func ctx.__function_name = func.data.name const result = await func.execute(ctx, useInterceptor) - // return false to reject request if interceptor got error if (result.error) { - logger.error( - requestId, - `invoke function ${ctx.__function_name} invoke error: `, - result, - ) - - ctx.response.status(400).send({ - error: `invoke ${ctx.__function_name} function got error, please check the function logs`, + logger.error(result.error) + return ctx.response.status(500).send({ + error: 'Internal Server Error', requestId, }) - return false } - logger.trace( - requestId, - `invoke function ${ctx.__function_name} invoke success: `, - result, - ) - - // return false to reject request if interceptor return false + // reject request if interceptor return false if ( typeof result.data === 'object' && result.data.__type__ === '__interceptor__' && result.data.__res__ == false ) { - ctx.response.status(403).send({ error: 'Forbidden', requestId }) - return false + return ctx.response.status(403).send({ error: 'Forbidden', requestId }) } if (ctx.response.writableEnded === false) { @@ -166,7 +153,6 @@ async function invokeDebug( } const func = new CloudFunction(funcData) - const debugConsole = new DebugConsole(funcName) try { @@ -174,29 +160,29 @@ async function invokeDebug( ctx.__function_name = funcName const result = await func.execute(ctx, useInterceptor, debugConsole) + // set logs to response header - ctx.response.set('x-laf-func-logs', debugConsole.getLogs()) + if (result.error) { + debugConsole.error(result.error) + } + const logs = encodeURIComponent(debugConsole.getLogs()) + ctx.response.set('x-laf-func-logs', logs) ctx.response.set('x-laf-func-time-usage', result.time_usage.toString()) if (result.error) { - logger.error(requestId, `debug function ${funcName} error: `, result) - return ctx.response.send({ - error: 'invoke function got error: ' + result.error.toString(), - time_usage: result.time_usage, + return ctx.response.status(500).send({ + error: 'Internal Server Error', requestId, }) } - logger.trace(requestId, `invoke ${funcName} invoke success: `, result) - - // return false to reject request if interceptor return false + // reject request if interceptor return false if ( typeof result.data === 'object' && result.data.__type__ === '__interceptor__' && result.data.__res__ == false ) { - ctx.response.status(403).send({ error: 'Forbidden', requestId }) - return false + return ctx.response.status(403).send({ error: 'Forbidden', requestId }) } if (ctx.response.writableEnded === false) { @@ -207,7 +193,7 @@ async function invokeDebug( return ctx.response.send(data) } } catch (error) { - logger.error(requestId, 'failed to invoke error', error) + debugConsole.error(requestId, 'failed to invoke error', error) return ctx.response.status(500).send('Internal Server Error') } } diff --git a/runtimes/nodejs/src/support/engine/console.ts b/runtimes/nodejs/src/support/engine/console.ts index 6b38c1df42..7ca73adbda 100644 --- a/runtimes/nodejs/src/support/engine/console.ts +++ b/runtimes/nodejs/src/support/engine/console.ts @@ -1,60 +1,100 @@ import * as util from 'util' import dayjs from 'dayjs' +import chalk from 'chalk' +import { padStart} from 'lodash' + +enum LogLevel { + DEBUG = 'DEBUG', + INFO = 'INFO', + WARN = 'WARN', + ERROR = 'ERROR', +} export class Console { - functionName: string - constructor(functionName: string) { - this.functionName = functionName + category: string + + constructor(category: string) { + this.category = category } - _log(...params: any[]): void { - const now = dayjs().format('YYYY-MM-DD HH:mm:ss.SSS') - const content = params - .map((param) => { - return util.inspect(param, { depth: 1 }) - }) - .join(' ') - - const data = `[${now}] [${this.functionName}] ${content}` - console.log(data) + protected _format(level: LogLevel, ...params: any[]): string { + const time = chalk.gray(dayjs().format('YYYY-MM-DD HH:mm:ss.SSS')) + const levelStr = this._colorize(level, padStart(level, 5, ' ')) + const fn = chalk.blue(`[${this.category}]`) + + let content = params + .map((param) => { + if (typeof param === 'string') return this._colorize(level, param) + return this._colorize(level, util.inspect(param, { depth: 1, colors: true })) + }) + .join(' ') + + // content = this._colorize(level, content) + const data = `${time} ${levelStr} ${fn} ${content}` + return data } debug(...params: any[]) { - this._log(...params) + const data = this._format(LogLevel.DEBUG, ...params) + console.debug(data) } info(...params: any[]) { - this._log(...params) + const data = this._format(LogLevel.INFO, ...params) + console.info(data) } log(...params: any[]) { - this._log(...params) + const data = this._format(LogLevel.INFO, ...params) + console.log(data) } warn(...params: any[]) { - this._log(...params) + const data = this._format(LogLevel.WARN, ...params) + console.warn(data) } + + error(...params: any[]) { + const data = this._format(LogLevel.ERROR, ...params) + console.error(data) + } + + protected _colorize(level: LogLevel, data: any) { + let result = data + switch (level) { + case LogLevel.DEBUG: + result = chalk.gray(data) + break + case LogLevel.INFO: + result = chalk.green(data) + break + case LogLevel.WARN: + result = chalk.yellow(data) + break + case LogLevel.ERROR: + result = chalk.red(data) + break + default: + result = data + break + } + return result + } + } export class DebugConsole extends Console { - constructor(functionName: string) { - super(functionName) + constructor(category: string) { + super(category) } private _logs: string[] = [] - _log(...params: any[]): void { - const now = dayjs().format('YYYY-MM-DD HH:mm:ss.SSS') - const content = params - .map((param) => { - return util.inspect(param, { depth: 1 }) - }) - .join(' ') - - const data = `[${now}] [${this.functionName}] ${content}` + protected _format(level: LogLevel, ...params: any[]): string { + const data = super._format(level, ...params) this._logs.push(data) - console.log(data) + return data } getLogs() { diff --git a/runtimes/nodejs/src/support/engine/function.ts b/runtimes/nodejs/src/support/engine/function.ts index cd86ca3925..b2fbec0b5c 100644 --- a/runtimes/nodejs/src/support/engine/function.ts +++ b/runtimes/nodejs/src/support/engine/function.ts @@ -58,7 +58,6 @@ export class CloudFunction { code = this.wrap(this.data.source.compiled) } const script = createScript(code, {}) - const fconsole = sandbox.console const options: RunningScriptOptions = { filename: `CloudFunction.${this.data.name}`, timeout: this.timeout, @@ -83,8 +82,6 @@ export class CloudFunction { time_usage, } } catch (error) { - fconsole.log(error.message, error.stack) - const _end_time = process.hrtime.bigint() const time_usage = nanosecond2ms(_end_time - _start_time) diff --git a/server/src/gateway/ingress/runtime-ingress.service.ts b/server/src/gateway/ingress/runtime-ingress.service.ts index b87dbde587..12219cd48e 100644 --- a/server/src/gateway/ingress/runtime-ingress.service.ts +++ b/server/src/gateway/ingress/runtime-ingress.service.ts @@ -86,6 +86,8 @@ export class RuntimeGatewayService { // k8s nginx ingress annotations // websocket is enabled by default in k8s nginx ingress + 'nginx.ingress.kubernetes.io/proxy-read-timeout': '300', + 'nginx.ingress.kubernetes.io/proxy-send-timeout': '300', 'nginx.ingress.kubernetes.io/proxy-body-size': '0', 'nginx.ingress.kubernetes.io/proxy-buffer-size': '8192k', 'nginx.ingress.kubernetes.io/server-snippet':