From 78ecaeffcb3c1f1d80e3bf2391988f10125c20ed Mon Sep 17 00:00:00 2001 From: Iain Sproat <68657+iainsproat@users.noreply.github.com> Date: Mon, 5 Dec 2022 15:46:09 +0000 Subject: [PATCH] Revert structured logging 2 (#1240) * Revert "'@' shortcut must come after it is configured in bootstrap (#1239)" This reverts commit 967329473f1fd7d38e5608ecd65754e48e8db7d0. * Revert "Structured logging (attempt 2) (#1234)" This reverts commit 444d2ca7ddfa0766a3fc0d5592e3e778a6806aaa. --- docker-compose-speckle.yml | 8 +- package.json | 1 - packages/fileimport-service/Dockerfile | 36 +- .../fileimport-service/ifc/import_file.js | 3 +- packages/fileimport-service/ifc/index.js | 4 +- packages/fileimport-service/ifc/parser.js | 7 +- .../observability/logging.js | 8 - packages/fileimport-service/package.json | 1 - packages/fileimport-service/src/daemon.js | 21 +- .../fileimport-service/src/objDependencies.js | 9 +- packages/preview-service/Makefile | 4 +- packages/preview-service/app.js | 4 +- packages/preview-service/bg_service/index.js | 9 +- packages/preview-service/bin/www | 8 +- .../observability/expressLogging.js | 7 - .../preview-service/observability/logging.js | 10 - packages/preview-service/package.json | 6 +- .../preview-service/render_page/src/app.js | 3 +- packages/preview-service/routes/api.js | 5 +- packages/preview-service/routes/objects.js | 7 +- packages/preview-service/routes/preview.js | 9 +- packages/server/.vscode/launch.json | 4 + packages/server/app.ts | 16 +- packages/server/bin/ts-www | 4 +- packages/server/bin/www | 4 +- packages/server/bootstrap.js | 3 +- packages/server/db/knex.js | 5 +- packages/server/logging/apolloPlugin.js | 3 +- packages/server/logging/errorLogging.js | 5 +- packages/server/logging/expressLogging.ts | 7 - packages/server/logging/logging.ts | 18 - .../server/modules/accessrequests/index.ts | 4 +- .../server/modules/activitystream/index.ts | 8 +- packages/server/modules/apiexplorer/index.js | 4 +- packages/server/modules/auth/defaultApps.js | 8 +- packages/server/modules/auth/index.js | 4 +- packages/server/modules/auth/rest/index.js | 8 +- packages/server/modules/auth/services/apps.js | 3 +- .../modules/auth/services/passportService.js | 4 +- packages/server/modules/auth/strategies.js | 2 - .../modules/auth/strategies/azure-ad.js | 4 +- .../server/modules/auth/strategies/github.js | 4 +- .../server/modules/auth/strategies/google.js | 4 +- .../server/modules/auth/strategies/local.js | 4 +- packages/server/modules/blobstorage/index.js | 12 +- .../modules/blobstorage/objectStorage.js | 5 +- .../modules/cli/commands/activities/send.ts | 4 +- .../modules/cli/commands/bull/monitor.ts | 12 +- .../modules/cli/commands/bull/test-consume.ts | 8 +- .../modules/cli/commands/bull/test-push.ts | 4 +- .../modules/cli/commands/db/migrate/create.js | 5 +- .../modules/cli/commands/db/migrate/down.js | 5 +- .../modules/cli/commands/db/migrate/latest.js | 5 +- .../cli/commands/db/migrate/rollback.js | 5 +- .../modules/cli/commands/db/migrate/up.js | 5 +- .../modules/cli/commands/db/seed/commits.ts | 6 +- .../modules/cli/commands/db/seed/users.js | 13 +- .../modules/cli/commands/download/commit.ts | 22 +- packages/server/modules/cli/index.js | 9 +- packages/server/modules/comments/index.js | 4 +- packages/server/modules/core/index.js | 4 +- .../server/modules/core/rest/diffDownload.js | 8 +- .../server/modules/core/rest/diffUpload.js | 6 +- packages/server/modules/core/rest/download.js | 9 +- packages/server/modules/core/rest/upload.js | 26 +- .../server/modules/core/services/objects.js | 15 +- .../server/modules/core/services/streams.js | 4 +- .../modules/core/services/taskScheduler.ts | 14 +- .../server/modules/core/services/users.js | 4 +- .../modules/core/tests/graphSubs.spec.js | 2 +- packages/server/modules/emails/index.ts | 6 +- .../server/modules/emails/services/sending.ts | 9 +- .../modules/emails/utils/transporter.ts | 10 +- packages/server/modules/fileuploads/index.js | 8 +- packages/server/modules/index.js | 6 +- .../modules/notifications/helpers/types.ts | 4 +- .../server/modules/notifications/index.ts | 8 +- .../modules/notifications/services/queue.ts | 18 +- packages/server/modules/previews/index.js | 11 +- packages/server/modules/previews/ogImage.js | 3 +- packages/server/modules/pwdreset/index.ts | 4 +- .../server/modules/serverinvites/index.js | 4 +- .../services/moduleEventEmitterSetup.ts | 9 +- .../server/modules/shared/utils/logger.ts | 8 + packages/server/modules/stats/index.js | 4 +- packages/server/modules/webhooks/index.ts | 10 +- packages/server/package.json | 14 +- .../server/scripts/duplicateUserMigration.js | 9 +- packages/server/scripts/seedUsers.js | 3 +- packages/server/scripts/streamObjects.js | 7 +- packages/server/test/helpers.js | 3 +- packages/server/test/hooks.js | 5 +- packages/server/test/notificationsHelper.ts | 13 +- .../type-augmentations/morgan-debug.d.ts | 9 + packages/shared/package.json | 3 +- packages/shared/src/core/index.ts | 1 - .../shared/src/core/observability/logging.ts | 23 -- packages/webhook-service/Dockerfile | 32 +- packages/webhook-service/package.json | 1 - packages/webhook-service/src/main.js | 13 +- .../src/observability/logging.js | 7 - .../{observability => }/prometheusMetrics.js | 2 +- packages/webhook-service/src/webhookCaller.js | 6 +- .../template-docker-compose.yml | 8 +- .../fileimport_service/deployment.yml | 4 +- .../templates/preview_service/deployment.yml | 4 +- .../templates/server/deployment.yml | 4 +- .../templates/webhook_service/deployment.yml | 4 +- utils/helm/speckle-server/values.yaml | 21 - yarn.lock | 371 ++++-------------- 110 files changed, 413 insertions(+), 792 deletions(-) delete mode 100644 packages/fileimport-service/observability/logging.js delete mode 100644 packages/preview-service/observability/expressLogging.js delete mode 100644 packages/preview-service/observability/logging.js delete mode 100644 packages/server/logging/expressLogging.ts delete mode 100644 packages/server/logging/logging.ts create mode 100644 packages/server/modules/shared/utils/logger.ts create mode 100644 packages/server/type-augmentations/morgan-debug.d.ts delete mode 100644 packages/shared/src/core/observability/logging.ts delete mode 100644 packages/webhook-service/src/observability/logging.js rename packages/webhook-service/src/{observability => }/prometheusMetrics.js (99%) diff --git a/docker-compose-speckle.yml b/docker-compose-speckle.yml index af44054ac..8cbf2aa8a 100644 --- a/docker-compose-speckle.yml +++ b/docker-compose-speckle.yml @@ -25,7 +25,7 @@ services: SESSION_SECRET: 'TODO:Replace' STRATEGY_LOCAL: 'true' - LOG_LEVEL: 'info' + DEBUG: 'speckle:*' POSTGRES_URL: 'postgres' POSTGRES_USER: 'speckle' @@ -51,7 +51,7 @@ services: mem_limit: '3000m' memswap_limit: '3000m' environment: - LOG_LEVEL: 'info' + DEBUG: 'preview-service:*' PG_CONNECTION_STRING: 'postgres://speckle:speckle@postgres/speckle' webhook-service: @@ -61,7 +61,7 @@ services: image: speckle/speckle-webhook-service:local restart: always environment: - LOG_LEVEL: 'info' + DEBUG: 'webhook-service:*' PG_CONNECTION_STRING: 'postgres://speckle:speckle@postgres/speckle' fileimport-service: @@ -71,6 +71,6 @@ services: image: speckle/speckle-fileimport-service:local restart: always environment: - LOG_LEVEL: 'info' + DEBUG: 'fileimport-service:*' PG_CONNECTION_STRING: 'postgres://speckle:speckle@postgres/speckle' SPECKLE_SERVER_URL: 'http://speckle-server:3000' diff --git a/package.json b/package.json index ce977519c..5481a005f 100644 --- a/package.json +++ b/package.json @@ -39,7 +39,6 @@ "eslint-config-prettier": "^8.5.0", "husky": "^7.0.4", "lint-staged": "^12.3.7", - "pino-pretty": "^9.1.1", "prettier": "^2.5.1", "ts-node": "^10.9.1", "tsconfig-paths": "^4.0.0" diff --git a/packages/fileimport-service/Dockerfile b/packages/fileimport-service/Dockerfile index 2c30e9241..3660d2e95 100644 --- a/packages/fileimport-service/Dockerfile +++ b/packages/fileimport-service/Dockerfile @@ -1,24 +1,3 @@ -FROM node:16.18.0-bullseye-slim as build-stage - -ARG NODE_ENV=production -ENV NODE_ENV=${NODE_ENV} - -WORKDIR /speckle-server - -COPY .yarnrc.yml . -COPY .yarn ./.yarn -COPY package.json yarn.lock ./ - -COPY packages/fileimport-service/package.json ./packages/fileimport-service/ -COPY packages/shared/package.json ./packages/shared/ - -RUN yarn workspaces focus -A && yarn - -COPY packages/shared ./packages/shared/ -COPY packages/fileimport-service ./packages/fileimport-service/ - -RUN yarn workspaces foreach run build - FROM node:16.18.0-bullseye-slim as node RUN apt-get update && \ @@ -30,9 +9,6 @@ RUN apt-get update && \ && apt-get clean \ && rm -rf /var/lib/apt/lists/* -COPY packages/fileimport-service/requirements.txt /speckle-server/ -RUN pip install --no-cache-dir -r /speckle-server/requirements.txt - ADD https://github.com/ufoscout/docker-compose-wait/releases/download/2.8.0/wait /wait RUN chmod +x /wait @@ -45,13 +21,13 @@ COPY .yarnrc.yml . COPY .yarn ./.yarn COPY package.json yarn.lock ./ -COPY packages/fileimport-service/package.json ./packages/fileimport-service/ - -COPY --from=build-stage /speckle-server/packages/shared ./packages/shared -COPY --from=build-stage /speckle-server/packages/fileimport-service ./packages/fileimport-service - WORKDIR /speckle-server/packages/fileimport-service +COPY packages/fileimport-service/package.json ./ RUN yarn workspaces focus --production -ENTRYPOINT [ "tini", "--" ] +COPY packages/fileimport-service/requirements.txt ./ +RUN pip install --no-cache-dir -r requirements.txt + +COPY packages/fileimport-service . + CMD ["yarn", "node", "src/daemon.js"] diff --git a/packages/fileimport-service/ifc/import_file.js b/packages/fileimport-service/ifc/import_file.js index ea27437c5..8eb344e90 100644 --- a/packages/fileimport-service/ifc/import_file.js +++ b/packages/fileimport-service/ifc/import_file.js @@ -1,5 +1,4 @@ const fs = require('fs') -const { logger } = require('../observability/logging') const TMP_RESULTS_PATH = '/tmp/import_result.json' @@ -11,7 +10,7 @@ async function main() { const [filePath, userId, streamId, branchName, commitMessage, fileId] = cmdArgs // eslint-disable-next-line no-console - logger.info('ARGV: ', filePath, userId, streamId, branchName, commitMessage) + console.log('ARGV: ', filePath, userId, streamId, branchName, commitMessage) const data = fs.readFileSync(filePath) diff --git a/packages/fileimport-service/ifc/index.js b/packages/fileimport-service/ifc/index.js index a900f21ef..b72ef9ae9 100644 --- a/packages/fileimport-service/ifc/index.js +++ b/packages/fileimport-service/ifc/index.js @@ -2,7 +2,6 @@ const { performance } = require('perf_hooks') const { fetch } = require('undici') const Parser = require('./parser_v2') const ServerAPI = require('./api.js') -const { logger } = require('../observability/logging') async function parseAndCreateCommit({ data, @@ -62,7 +61,8 @@ async function parseAndCreateCommit({ }) const json = await response.json() - logger.info(json) + // eslint-disable-next-line no-console + console.log(json) return json.data.commitCreate } diff --git a/packages/fileimport-service/ifc/parser.js b/packages/fileimport-service/ifc/parser.js index d2c6f4d1f..5cc8a4946 100644 --- a/packages/fileimport-service/ifc/parser.js +++ b/packages/fileimport-service/ifc/parser.js @@ -1,7 +1,6 @@ /* eslint-disable no-console */ /* eslint-disable camelcase */ const WebIFC = require('web-ifc/web-ifc-api-node') -const { logger } = require('../observability/logging.js') const ServerAPI = require('./api.js') module.exports = class IFCParser { @@ -30,7 +29,7 @@ module.exports = class IFCParser { // as reference objects in this.productGeo this.productGeo = {} await this.createGeometries() - logger.info(`Geometries created: ${Object.keys(this.productGeo).length} meshes.`) + console.log(`Geometries created: ${Object.keys(this.productGeo).length} meshes.`) // Lastly, traverse the ifc project object and parse it into something friendly; as well as // replace all its geometries with actual references to speckle meshes from the productGeo map @@ -134,7 +133,7 @@ module.exports = class IFCParser { if (this.cache[element.expressID.toString()]) return this.cache[element.expressID.toString()] // If you got here -> It's an IFC Element: create base object, upload and return ref. - // logger.debug( `Traversing element ${element.expressID}; Recurse: ${recursive}; Stack ${depth}` ) + // console.log( `Traversing element ${element.expressID}; Recurse: ${recursive}; Stack ${depth}` ) // Traverse all key/value pairs first. for (const key of Object.keys(element)) { @@ -253,7 +252,7 @@ module.exports = class IFCParser { element.propertySets || element.typeProps ) { - logger.info( + console.log( `${element.constructor.name} ${element.GlobalId}:\n\tchildren count: ${ element.children ? element.children.length : '0' };\n\tspatial children count: ${ diff --git a/packages/fileimport-service/observability/logging.js b/packages/fileimport-service/observability/logging.js deleted file mode 100644 index 325cc2170..000000000 --- a/packages/fileimport-service/observability/logging.js +++ /dev/null @@ -1,8 +0,0 @@ -const { logger: baseLogger, extendLoggerComponent } = require('@speckle/shared') - -// loggers for specific components within normal operation -const logger = extendLoggerComponent(baseLogger, 'fileimport-service') - -module.exports = { - logger -} diff --git a/packages/fileimport-service/package.json b/packages/fileimport-service/package.json index 1e0b874df..b0503bc32 100644 --- a/packages/fileimport-service/package.json +++ b/packages/fileimport-service/package.json @@ -23,7 +23,6 @@ "url": "https://github.com/specklesystems/speckle-server/issues" }, "dependencies": { - "@speckle/shared": "workspace:^", "aws-sdk": "^2.1075.0", "bcrypt": "^5.0.1", "crypto-random-string": "^3.3.1", diff --git a/packages/fileimport-service/src/daemon.js b/packages/fileimport-service/src/daemon.js index fe67ca21f..0ba7ac3a2 100644 --- a/packages/fileimport-service/src/daemon.js +++ b/packages/fileimport-service/src/daemon.js @@ -16,7 +16,6 @@ const { spawn } = require('child_process') const ServerAPI = require('../ifc/api') const objDependencies = require('./objDependencies') -const { logger } = require('../observability/logging') const HEALTHCHECK_FILE_PATH = '/tmp/last_successful_query' @@ -57,7 +56,7 @@ async function doTask(task) { const metricDurationEnd = metricDuration.startTimer() try { - logger.info('Doing task ', task) + console.log('Doing task ', task) const info = await FileUploads().where({ id: task.id }).first() if (!info) { throw new Error('Internal error: DB inconsistent') @@ -163,7 +162,7 @@ async function doTask(task) { [commitId, task.id] ) } catch (err) { - logger.error(err) + console.log('Error: ', err) await knex.raw( ` UPDATE file_uploads @@ -190,21 +189,21 @@ async function doTask(task) { function runProcessWithTimeout(cmd, cmdArgs, extraEnv, timeoutMs) { return new Promise((resolve, reject) => { - logger.info(`Starting process: ${cmd} ${cmdArgs}`) + console.log(`Starting process: ${cmd} ${cmdArgs}`) const childProc = spawn(cmd, cmdArgs, { env: { ...process.env, ...extraEnv } }) childProc.stdout.on('data', (data) => { - logger.info('Parser: ', data.toString()) + console.log('Parser: ', data.toString()) }) childProc.stderr.on('data', (data) => { - logger.error('Parser: ', data.toString()) + console.error('Parser: ', data.toString()) }) let timedOut = false const timeout = setTimeout(() => { - logger.error('Process timeout. Killing process...') + console.log('Process timeout. Killing process...') timedOut = true childProc.kill(9) @@ -212,7 +211,7 @@ function runProcessWithTimeout(cmd, cmdArgs, extraEnv, timeoutMs) { }, timeoutMs) childProc.on('close', (code) => { - logger.info(`Process exited with code ${code}`) + console.log(`Process exited with code ${code}`) if (timedOut) return // ignore `close` calls after killing (the promise was already rejected) @@ -248,18 +247,18 @@ async function tick() { setTimeout(tick, 10) } catch (err) { metricOperationErrors.labels('main_loop').inc() - logger.error('Error executing task: ', err) + console.log('Error executing task: ', err) setTimeout(tick, 5000) } } async function main() { - logger.info('Starting FileUploads Service...') + console.log('Starting FileUploads Service...') initPrometheusMetrics() process.on('SIGTERM', () => { shouldExit = true - logger.info('Shutting down...') + console.log('Shutting down...') }) tick() diff --git a/packages/fileimport-service/src/objDependencies.js b/packages/fileimport-service/src/objDependencies.js index 0ab3cc5bd..5aea8d7a1 100644 --- a/packages/fileimport-service/src/objDependencies.js +++ b/packages/fileimport-service/src/objDependencies.js @@ -6,7 +6,6 @@ const path = require('path') const { downloadFile, getFileInfoByName } = require('./filesApi') const isValidFilename = require('valid-filename') -const { logger } = require('../observability/logging') const getReferencedMtlFiles = async ({ objFilePath }) => { const mtlFiles = [] @@ -26,7 +25,7 @@ const getReferencedMtlFiles = async ({ objFilePath }) => { await events.once(rl, 'close') } catch (err) { - logger.error(`Error getting dependencies for file ${objFilePath}: ${err}`) + console.error(`Error getting dependencies for file ${objFilePath}: ${err}`) } return mtlFiles } @@ -35,17 +34,17 @@ module.exports = { async downloadDependencies({ objFilePath, streamId, destinationDir, token }) { const dependencies = await getReferencedMtlFiles({ objFilePath }) - logger.info(`Obj file depends on ${dependencies}`) + console.log(`Obj file depends on ${dependencies}`) for (const mtlFile of dependencies) { // there might be multiple files named with the same name, take the first... const [file] = (await getFileInfoByName({ fileName: mtlFile, streamId, token })) .blobs if (!file) { - logger.info(`OBJ dependency file not found in stream: ${mtlFile}`) + console.log(`OBJ dependency file not found in stream: ${mtlFile}`) continue } if (!isValidFilename(mtlFile)) { - logger.warn(`Invalid filename reference in OBJ dependencies: ${mtlFile}`) + console.log(`Invalid filename reference in OBJ dependencies: ${mtlFile}`) continue } await downloadFile({ diff --git a/packages/preview-service/Makefile b/packages/preview-service/Makefile index 821eed5b2..fb81b1091 100644 --- a/packages/preview-service/Makefile +++ b/packages/preview-service/Makefile @@ -5,15 +5,17 @@ build: run: docker run -it --rm --net=host \ + -e DEBUG="preview-service:*" \ -e PG_CONNECTION_STRING="postgres://speckle:speckle@localhost/speckle" \ preview-service run-release: docker run -it --rm --net=host \ + -e DEBUG="preview-service:*" \ -e PG_CONNECTION_STRING="postgres://speckle:speckle@localhost/speckle" \ speckle/speckle-preview-service:v2.3.3 small: docker build -t small-preview-service ../.. -f Dockerfile.small - docker run -it --rm --net=host -e PG_CONNECTION_STRING="postgres://speckle:speckle@localhost/speckle" small-preview-service bash + docker run -it --rm --net=host -e DEBUG="preview-service:*" -e PG_CONNECTION_STRING="postgres://speckle:speckle@localhost/speckle" small-preview-service bash diff --git a/packages/preview-service/app.js b/packages/preview-service/app.js index 5af234455..66a1b4dc0 100644 --- a/packages/preview-service/app.js +++ b/packages/preview-service/app.js @@ -4,16 +4,16 @@ const createError = require('http-errors') const express = require('express') const path = require('path') const cookieParser = require('cookie-parser') +const logger = require('morgan') const indexRouter = require('./routes/index') const previewRouter = require('./routes/preview') const objectsRouter = require('./routes/objects') const apiRouter = require('./routes/api') -const { LoggingExpressMiddleware } = require('./observability/expressLogging') const app = express() -app.use(LoggingExpressMiddleware) +app.use(logger('dev')) app.use(express.json({ limit: '100mb' })) app.use(express.urlencoded({ limit: '100mb', extended: false })) diff --git a/packages/preview-service/bg_service/index.js b/packages/preview-service/bg_service/index.js index b2b62ceec..207a1224b 100644 --- a/packages/preview-service/bg_service/index.js +++ b/packages/preview-service/bg_service/index.js @@ -6,7 +6,6 @@ const fetch = require('node-fetch') const fs = require('fs') const metrics = require('./prometheusMetrics') const joinImages = require('join-images') -const { logger } = require('../observability/logging') let shouldExit = false @@ -131,22 +130,22 @@ async function tick() { setTimeout(tick, 10) } catch (err) { metrics.metricOperationErrors.labels('main_loop').inc() - logger.error('Error executing task: ', err) + console.log('Error executing task: ', err) setTimeout(tick, 5000) } } async function startPreviewService() { - logger.info('ðŸ“ļ Started Preview Service') + console.log('ðŸ“ļ Started Preview Service') process.on('SIGTERM', () => { shouldExit = true - logger.info('Shutting down...') + console.log('Shutting down...') }) process.on('SIGINT', () => { shouldExit = true - logger.info('Shutting down...') + console.log('Shutting down...') }) metrics.initPrometheusMetrics() diff --git a/packages/preview-service/bin/www b/packages/preview-service/bin/www index 5d09cea64..2af055ab1 100755 --- a/packages/preview-service/bin/www +++ b/packages/preview-service/bin/www @@ -5,9 +5,9 @@ */ const app = require('../app') +const debug = require('debug')('preview-service:server') const http = require('http') const { startPreviewService } = require('../bg_service') -const { serverLogger, logger } = require('../observability/logging') /** * Get port from environment and store in Express. @@ -64,11 +64,11 @@ function onError(error) { // handle specific listen errors with friendly messages switch (error.code) { case 'EACCES': - logger.error(bind + ' requires elevated privileges') + console.error(bind + ' requires elevated privileges') process.exit(1) break case 'EADDRINUSE': - logger.error(bind + ' is already in use') + console.error(bind + ' is already in use') process.exit(1) break default: @@ -83,7 +83,7 @@ function onError(error) { function onListening() { const addr = server.address() const bind = typeof addr === 'string' ? 'pipe ' + addr : 'port ' + addr.port - serverLogger.info('Listening on ' + bind) + debug('Listening on ' + bind) startPreviewService() } diff --git a/packages/preview-service/observability/expressLogging.js b/packages/preview-service/observability/expressLogging.js deleted file mode 100644 index 49cd5fac1..000000000 --- a/packages/preview-service/observability/expressLogging.js +++ /dev/null @@ -1,7 +0,0 @@ -const { logger } = require('./logging') -const HttpLogger = require('pino-http') - -module.exports.LoggingExpressMiddleware = HttpLogger({ - logger, - autoLogging: false -}) diff --git a/packages/preview-service/observability/logging.js b/packages/preview-service/observability/logging.js deleted file mode 100644 index 0df5dc2c1..000000000 --- a/packages/preview-service/observability/logging.js +++ /dev/null @@ -1,10 +0,0 @@ -const { logger: baseLogger, extendLoggerComponent } = require('@speckle/shared') - -// loggers for specific components within normal operation -const logger = extendLoggerComponent(baseLogger, 'preview-service') -const serverLogger = extendLoggerComponent(logger, 'server') - -module.exports = { - logger, - serverLogger -} diff --git a/packages/preview-service/package.json b/packages/preview-service/package.json index 4907352c4..0737ff9b1 100644 --- a/packages/preview-service/package.json +++ b/packages/preview-service/package.json @@ -14,25 +14,25 @@ "node": ">=14.0.0 <17.0.0" }, "scripts": { - "dev": "nodemon --trace-deprecation ./bin/www", + "dev": "DEBUG='preview-service:*' nodemon --trace-deprecation ./bin/www", "build": "webpack --env dev --config webpack.config.render_page.js && webpack --env build --config webpack.config.render_page.js", "lint": "eslint . --ext .js,.ts" }, "dependencies": { "@speckle/objectloader": "workspace:^", - "@speckle/shared": "workspace:^", "@speckle/viewer": "workspace:^", "cookie-parser": "~1.4.4", "crypto": "^1.0.1", + "debug": "~2.6.9", "express": "~4.16.1", "file-type": "^16.5.4", "http-errors": "~1.6.3", "join-images": "^1.1.3", "knex": "^2.0.0", + "morgan": "~1.9.1", "node-fetch": "^2.6.1", "pg": "^8.7.3", "pg-query-stream": "^4.2.3", - "pino-http": "^8.2.1", "prom-client": "^14.0.1", "puppeteer": "^13.3.2", "sharp": "^0.30.5", diff --git a/packages/preview-service/render_page/src/app.js b/packages/preview-service/render_page/src/app.js index 193137377..ad52ee7d5 100644 --- a/packages/preview-service/render_page/src/app.js +++ b/packages/preview-service/render_page/src/app.js @@ -1,10 +1,9 @@ import { DebugViewer, DefaultViewerParams } from '@speckle/viewer' -// import { logger } from '../../observability/logging' const v = new DebugViewer(document.getElementById('renderer'), DefaultViewerParams) window.v = v -// v.on( ViewerEvent.LoadProgress, args => logger.debug( args ) ) +// v.on( ViewerEvent.LoadProgress, args => console.log( args ) ) window.LoadData = async function LoadData(url) { // token is not used in this context, since the preview service talks directly to the DB diff --git a/packages/preview-service/routes/api.js b/packages/preview-service/routes/api.js index f6d0f2688..805d38103 100644 --- a/packages/preview-service/routes/api.js +++ b/packages/preview-service/routes/api.js @@ -5,7 +5,6 @@ const express = require('express') const { getObjectsStream } = require('./services/objects_utils') const { SpeckleObjectsStream } = require('./speckleObjectsStream') const { pipeline, PassThrough } = require('stream') -const { logger } = require('../observability/logging') const router = express.Router() @@ -35,11 +34,11 @@ router.post('/getobjects/:streamId', async (req, res) => { res, (err) => { if (err) { - logger.error( + console.log( `Error streaming objects from stream ${req.params.streamId}: ${err}` ) } else { - logger.error( + console.log( `Streamed ${childrenList.length} objects from stream ${ req.params.streamId } (size: ${gzipStream.bytesWritten / 1000000} MB)` diff --git a/packages/preview-service/routes/objects.js b/packages/preview-service/routes/objects.js index 6eb131389..653cac06c 100644 --- a/packages/preview-service/routes/objects.js +++ b/packages/preview-service/routes/objects.js @@ -5,7 +5,6 @@ const express = require('express') const { getObject, getObjectChildrenStream } = require('./services/objects_utils') const { SpeckleObjectsStream } = require('./speckleObjectsStream') const { pipeline, PassThrough } = require('stream') -const { logger } = require('../observability/logging') const router = express.Router() @@ -45,11 +44,11 @@ router.get('/:streamId/:objectId', async function (req, res) { res, (err) => { if (err) { - logger.error( + console.log( `Error downloading object ${req.params.objectId} from stream ${req.params.streamId}: ${err}` ) } else { - logger.info( + console.log( `Downloaded object ${req.params.objectId} from stream ${ req.params.streamId } (size: ${gzipStream.bytesWritten / 1000000} MB)` @@ -69,7 +68,7 @@ router.get('/:streamId/:objectId/single', async (req, res) => { return res.status(404).send('Failed to find object.') } - logger.info( + console.log( `Downloaded single object ${req.params.objectId} from stream ${req.params.streamId}` ) diff --git a/packages/preview-service/routes/preview.js b/packages/preview-service/routes/preview.js index 06fd938a4..fb050851f 100644 --- a/packages/preview-service/routes/preview.js +++ b/packages/preview-service/routes/preview.js @@ -4,7 +4,6 @@ const express = require('express') const router = express.Router() const puppeteer = require('puppeteer') -const { logger } = require('../observability/logging') async function pageFunction(objectUrl) { waitForAnimation = async (ms = 70) => @@ -67,7 +66,7 @@ async function getScreenshot(objectUrl) { const wrapperPromise = (async () => { await page.goto('http://127.0.0.1:3001/render/') - logger.info('Page loaded') + console.log('Page loaded') // Handle page crash (oom?) page.on('error', (err) => { @@ -80,7 +79,7 @@ async function getScreenshot(objectUrl) { try { ret = await wrapperPromise } catch (err) { - logger.error(`Error generating preview for ${objectUrl}: ${err}`) + console.log(`Error generating preview for ${objectUrl}: ${err}`) ret = { error: err } @@ -93,7 +92,7 @@ async function getScreenshot(objectUrl) { return null } - logger.info( + console.log( `Generated preview for ${objectUrl} in ${ret.duration} sec with ${ ret.mem.total / 1000000 } MB of memory` @@ -148,7 +147,7 @@ router.get('/:streamId/:objectId', async function (req, res) { } */ - logger.info(objectUrl) + console.log(objectUrl) const scr = await getScreenshot(objectUrl) diff --git a/packages/server/.vscode/launch.json b/packages/server/.vscode/launch.json index 1604022e0..888db5ced 100644 --- a/packages/server/.vscode/launch.json +++ b/packages/server/.vscode/launch.json @@ -62,6 +62,10 @@ "--timeout=0" ], "console": "integratedTerminal", + "env": { + // "POSTGRES_URL": "postgres://speckle:speckle@localhost/speckle2_test", + "DEBUG": "server:*" + }, // "envFile": "${workspaceFolder}/.env", "runtimeExecutable": "npm", "skipFiles": ["/**"], diff --git a/packages/server/app.ts b/packages/server/app.ts index 4ee2666c0..1a6a61cfd 100644 --- a/packages/server/app.ts +++ b/packages/server/app.ts @@ -6,12 +6,12 @@ import express, { Express } from 'express' // `express-async-errors` patches express to catch errors in async handlers. no variable needed import 'express-async-errors' import compression from 'compression' +import logger from 'morgan-debug' +import debug from 'debug' import { createTerminus } from '@godaddy/terminus' import * as Sentry from '@sentry/node' import Logging from '@/logging' -import { startupLogger, shutdownLogger } from '@/logging/logging' -import { LoggingExpressMiddleware } from '@/logging/expressLogging' import { errorLoggingMiddleware } from '@/logging/errorLogging' import prometheusClient from 'prom-client' @@ -184,7 +184,7 @@ export async function init() { await knex.migrate.latest() if (process.env.NODE_ENV !== 'test') { - app.use(LoggingExpressMiddleware) + app.use(logger('speckle', 'dev', {})) } if (process.env.COMPRESSION) { @@ -273,8 +273,8 @@ export async function startHttp( // app.use('/', frontendProxy) app.use(await createFrontendProxy()) - startupLogger.info('âœĻ Proxying frontend (dev mode):') - startupLogger.info(`👉 main application: http://localhost:${port}/`) + debug('speckle:startup')('âœĻ Proxying frontend (dev mode):') + debug('speckle:startup')(`👉 main application: http://localhost:${port}/`) } // Production mode @@ -291,13 +291,13 @@ export async function startHttp( signals: ['SIGTERM', 'SIGINT'], timeout: 5 * 60 * 1000, beforeShutdown: async () => { - shutdownLogger.info('Shutting down (signal received)...') + debug('speckle:shutdown')('Shutting down (signal received)...') }, onSignal: async () => { await shutdown() }, onShutdown: () => { - shutdownLogger.info('Shutdown completed') + debug('speckle:shutdown')('Shutdown completed') process.exit(0) } }) @@ -307,7 +307,7 @@ export async function startHttp( const addressString = isString(address) ? address : address?.address const port = isString(address) ? null : address?.port - startupLogger.info( + debug('speckle:startup')( `🚀 My name is Speckle Server, and I'm running at ${addressString}:${port}` ) app.emit('appStarted') diff --git a/packages/server/bin/ts-www b/packages/server/bin/ts-www index 06f0759e6..c6f875ee5 100755 --- a/packages/server/bin/ts-www +++ b/packages/server/bin/ts-www @@ -7,11 +7,11 @@ */ require('ts-node/register') -const { logger } = require('../logging/logging') +const debug = require('debug')('speckle:www') const { init, startHttp } = require('../app') init() .then(({ app, server }) => startHttp(server, app)) - .catch((err) => logger.error(err)) + .catch((err) => debug(err)) // ðŸ’Ĩ diff --git a/packages/server/bin/www b/packages/server/bin/www index 0df320052..34aa3831a 100755 --- a/packages/server/bin/www +++ b/packages/server/bin/www @@ -1,11 +1,11 @@ #!/usr/bin/env node 'use strict' -const { logger } = require('../dist/logging/logging') +const debug = require('debug')('speckle:www') const { init, startHttp } = require('../dist/app') init() .then(({ app, server }) => startHttp(server, app)) - .catch((err) => logger.error(err)) + .catch((err) => debug(err)) // ðŸ’Ĩ diff --git a/packages/server/bootstrap.js b/packages/server/bootstrap.js index 10eaa7857..a8baa809d 100644 --- a/packages/server/bootstrap.js +++ b/packages/server/bootstrap.js @@ -24,7 +24,6 @@ const { getApolloServerVersion, getServerVersion } = require('./modules/shared/helpers/envHelper') -const { logger } = require('@/logging/logging') if (isApolloMonitoringEnabled() && !getApolloServerVersion()) { process.env.APOLLO_SERVER_USER_VERSION = getServerVersion() @@ -38,7 +37,7 @@ if (isTestEnv()) { const e = new Error( 'Attempting to run tests without an .env.test file properly set up! Check readme!' ) - logger.error(e) + console.error(e) process.exit(1) } } diff --git a/packages/server/db/knex.js b/packages/server/db/knex.js index 99032d4ac..be5bb47af 100644 --- a/packages/server/db/knex.js +++ b/packages/server/db/knex.js @@ -3,7 +3,6 @@ const env = process.env.NODE_ENV || 'development' const configs = require('@/knexfile.js') -const { dbStartupLogger } = require('@/logging/logging') const config = configs[env] config.log = { @@ -16,7 +15,9 @@ config.log = { } } -dbStartupLogger.info(`Loaded knex conf for ${env}`) +const debug = require('debug') + +debug('speckle:db-startup')(`Loaded knex conf for ${env}`) /** * Need to override type because type def file incorrectly uses ES6 diff --git a/packages/server/logging/apolloPlugin.js b/packages/server/logging/apolloPlugin.js index 218853cb8..021324d3e 100644 --- a/packages/server/logging/apolloPlugin.js +++ b/packages/server/logging/apolloPlugin.js @@ -1,5 +1,4 @@ /* istanbul ignore file */ -// const { logger } = require('@/logging/logging') const Sentry = require('@sentry/node') const { ApolloError } = require('apollo-server-express') const prometheusClient = require('prom-client') @@ -28,7 +27,7 @@ module.exports = { try { const actionName = `${ctx.operation.operation} ${ctx.operation.selectionSet.selections[0].name.value}` metricCallCount.labels(actionName).inc() - // logger.debug(actionName) + // console.log( actionName ) } catch (e) { Sentry.captureException(e) } diff --git a/packages/server/logging/errorLogging.js b/packages/server/logging/errorLogging.js index a88536f5f..06209f90b 100644 --- a/packages/server/logging/errorLogging.js +++ b/packages/server/logging/errorLogging.js @@ -1,5 +1,4 @@ /* istanbul ignore file */ -const { logger } = require('@/logging/logging') const prometheusClient = require('prom-client') let metricErrorCount = null @@ -14,9 +13,7 @@ module.exports = { }) } - logger.error( - `Error when handling ${req.originalUrl} from ${req.ip}: ${err.message}` - ) + console.log(`Error when handling ${req.originalUrl} from ${req.ip}: ${err.message}`) let route = 'unknown' if (req.route && req.route.path) route = req.route.path metricErrorCount.labels(route).inc() diff --git a/packages/server/logging/expressLogging.ts b/packages/server/logging/expressLogging.ts deleted file mode 100644 index 2f9ae6ba6..000000000 --- a/packages/server/logging/expressLogging.ts +++ /dev/null @@ -1,7 +0,0 @@ -import { logger } from './logging' -import HttpLogger from 'pino-http' - -export const LoggingExpressMiddleware = HttpLogger({ - logger, - autoLogging: false -}) diff --git a/packages/server/logging/logging.ts b/packages/server/logging/logging.ts deleted file mode 100644 index 3d529ef1c..000000000 --- a/packages/server/logging/logging.ts +++ /dev/null @@ -1,18 +0,0 @@ -// Note logging is imported by www & ts-www, prior to init() being called -// so we can't use local imports with '@' etc., as they aren't yet defined. -import { logger, extendLoggerComponent } from '@speckle/shared' -export { logger, extendLoggerComponent } from '@speckle/shared' - -// loggers for phases of operation -export const startupLogger = logger.child({ phase: 'startup' }) -export const dbStartupLogger = logger.child({ phase: 'db-startup' }) -export const shutdownLogger = logger.child({ phase: 'shutdown' }) - -// loggers for specific components within normal operation -export const moduleLogger = extendLoggerComponent(logger, 'modules') -export const activitiesLogger = extendLoggerComponent(moduleLogger, 'activities') -export const cliLogger = extendLoggerComponent(logger, 'cli') -export const notificationsLogger = extendLoggerComponent(logger, 'notifications') -export const uploadEndpointLogger = extendLoggerComponent(logger, 'upload-endpoint') -export const dbLogger = extendLoggerComponent(logger, 'db') -export const servicesLogger = extendLoggerComponent(logger, 'services') diff --git a/packages/server/modules/accessrequests/index.ts b/packages/server/modules/accessrequests/index.ts index ef6ff86f1..0c2775776 100644 --- a/packages/server/modules/accessrequests/index.ts +++ b/packages/server/modules/accessrequests/index.ts @@ -1,12 +1,12 @@ -import { moduleLogger } from '@/logging/logging' import { initializeEventListener } from '@/modules/accessrequests/services/eventListener' import { Optional, SpeckleModule } from '@/modules/shared/helpers/typeHelper' +import { modulesDebug } from '@/modules/shared/utils/logger' let quitListeners: Optional<() => void> = undefined const ServerAccessRequestsModule: SpeckleModule = { init(_, isInitial) { - moduleLogger.info('🔐 Init access request module') + modulesDebug('🔐 Init access request module') if (isInitial) { quitListeners = initializeEventListener() diff --git a/packages/server/modules/activitystream/index.ts b/packages/server/modules/activitystream/index.ts index 96289f757..98a77906d 100644 --- a/packages/server/modules/activitystream/index.ts +++ b/packages/server/modules/activitystream/index.ts @@ -2,9 +2,11 @@ import { SpeckleModule } from '@/modules/shared/helpers/typeHelper' import cron from 'node-cron' import { sendActivityNotifications } from '@/modules/activitystream/services/summary' import { initializeEventListener } from '@/modules/activitystream/services/eventListener' +import { modulesDebug } from '@/modules/shared/utils/logger' import { publishNotification } from '@/modules/notifications/services/publication' import { scheduleExecution } from '@/modules/core/services/taskScheduler' -import { activitiesLogger, moduleLogger } from '@/logging/logging' + +const activitiesDebug = modulesDebug.extend('activities') let scheduledTask: cron.ScheduledTask | null = null @@ -23,7 +25,7 @@ const scheduleWeeklyActivityNotifications = () => { 'weeklyActivityNotification', //task should be locked for 10 minutes async (now: Date) => { - activitiesLogger.info('Sending weekly activity digests notifications.') + activitiesDebug('Sending weekly activity digests notifications.') const end = now const start = new Date(end.getTime()) start.setDate(start.getDate() - numberOfDays) @@ -35,7 +37,7 @@ const scheduleWeeklyActivityNotifications = () => { const activityModule: SpeckleModule = { init: async (_, isInitial) => { - moduleLogger.info('ðŸĪš Init activity module') + modulesDebug('ðŸĪš Init activity module') if (isInitial) { initializeEventListener() scheduledTask = scheduleWeeklyActivityNotifications() diff --git a/packages/server/modules/apiexplorer/index.js b/packages/server/modules/apiexplorer/index.js index 0a01e3fbc..77d06cf25 100644 --- a/packages/server/modules/apiexplorer/index.js +++ b/packages/server/modules/apiexplorer/index.js @@ -1,9 +1,9 @@ /* istanbul ignore file */ 'use strict' -const { moduleLogger } = require('@/logging/logging') +const debug = require('debug') exports.init = (app) => { - moduleLogger.info('💅 Init graphql api explorer module') + debug('speckle:modules')('💅 Init graphql api explorer module') // sweet and simple app.get('/explorer', (req, res) => { diff --git a/packages/server/modules/auth/defaultApps.js b/packages/server/modules/auth/defaultApps.js index 6512ed3de..a86d8c41a 100644 --- a/packages/server/modules/auth/defaultApps.js +++ b/packages/server/modules/auth/defaultApps.js @@ -1,4 +1,5 @@ 'use strict' +const debug = require('debug') const knex = require('@/db/knex') const Scopes = () => knex('scopes') const Apps = () => knex('server_apps') @@ -7,7 +8,6 @@ const AppScopes = () => knex('server_apps_scopes') const { getApp } = require('@/modules/auth/services/apps') const { Scopes: ScopesConst } = require('@/modules/core/helpers/mainConstants') const { difference } = require('lodash') -const { moduleLogger, logger } = require('@/logging/logging') let allScopes = [] @@ -25,7 +25,7 @@ module.exports = async () => { async function registerOrUpdateApp(app) { if (app.scopes && app.scopes === 'all') { // let scopes = await Scopes( ).select( '*' ) - // logger.debug( allScopes.length ) + // console.log( allScopes.length ) app.scopes = allScopes.map((s) => s.name) } @@ -44,7 +44,7 @@ async function registerDefaultApp(app) { await Apps().insert(app) await AppScopes().insert(scopes) } catch (e) { - logger.error(e) + console.log(e) } } @@ -57,7 +57,7 @@ async function updateDefaultApp(app, existingApp) { let affectedTokenIds = [] if (newScopes.length || removedScopes.length) { - moduleLogger.info(`🔑 Updating default app ${app.name}`) + debug('speckle:modules')(`🔑 Updating default app ${app.name}`) affectedTokenIds = await knex('user_server_app_tokens') .where({ appId: app.id }) .pluck('tokenId') diff --git a/packages/server/modules/auth/index.js b/packages/server/modules/auth/index.js index 25c84d448..119260e5e 100644 --- a/packages/server/modules/auth/index.js +++ b/packages/server/modules/auth/index.js @@ -1,9 +1,9 @@ 'use strict' +const debug = require('debug') const { registerOrUpdateScope } = require('@/modules/shared') -const { moduleLogger } = require('@/logging/logging') exports.init = async (app) => { - moduleLogger.info('🔑 Init auth module') + debug('speckle:modules')('🔑 Init auth module') // Initialize authn strategies exports.authStrategies = await require('./strategies')(app) diff --git a/packages/server/modules/auth/rest/index.js b/packages/server/modules/auth/rest/index.js index a5c1c7e05..391beb280 100644 --- a/packages/server/modules/auth/rest/index.js +++ b/packages/server/modules/auth/rest/index.js @@ -1,4 +1,5 @@ 'use strict' +const debug = require('debug') const cors = require('cors') const sentry = require(`@/logging/sentryHelper`) @@ -14,7 +15,6 @@ const { revokeRefreshToken } = require(`@/modules/auth/services/apps`) const { validateScopes } = require(`@/modules/shared`) const { InvalidAccessCodeRequestError } = require('@/modules/auth/errors') const { ForbiddenError } = require('apollo-server-errors') -const { moduleLogger } = require('@/logging/logging') // TODO: Secure these endpoints! module.exports = (app) => { @@ -45,7 +45,7 @@ module.exports = (app) => { return res.redirect(`${app.redirectUrl}?access_code=${ac}`) } catch (err) { sentry({ err }) - moduleLogger.error(err) + debug('speckle:error')(err) if ( err instanceof InvalidAccessCodeRequestError || @@ -97,7 +97,6 @@ module.exports = (app) => { return res.send(authResponse) } catch (err) { sentry({ err }) - moduleLogger.error(err) return res.status(401).send({ err: err.message }) } }) @@ -118,8 +117,7 @@ module.exports = (app) => { return res.status(200).send({ message: 'You have logged out.' }) } catch (err) { sentry({ err }) - moduleLogger.error(err) - return res.status(400).send('Something went wrong while trying to logout.') + return res.status(400).send({ err: err.message }) } }) } diff --git a/packages/server/modules/auth/services/apps.js b/packages/server/modules/auth/services/apps.js index f9b0d707f..f4c3bde80 100644 --- a/packages/server/modules/auth/services/apps.js +++ b/packages/server/modules/auth/services/apps.js @@ -4,7 +4,6 @@ const crs = require('crypto-random-string') const knex = require(`@/db/knex`) const { createToken, createBareToken } = require(`@/modules/core/services/tokens`) -const { logger } = require('@/logging/logging') const Users = () => knex('users') const ApiTokens = () => knex('api_tokens') const ServerApps = () => knex('server_apps') @@ -130,7 +129,7 @@ module.exports = { await module.exports.revokeExistingAppCredentials({ appId: app.id }) if (app.scopes) { - logger.debug(app.scopes, app.id) + // console.log( app.scopes, app.id ) // Flush existing app scopes await ServerAppsScopes().where({ appId: app.id }).del() // Update new scopes diff --git a/packages/server/modules/auth/services/passportService.js b/packages/server/modules/auth/services/passportService.js index 863f946fa..324bc0a1b 100644 --- a/packages/server/modules/auth/services/passportService.js +++ b/packages/server/modules/auth/services/passportService.js @@ -1,5 +1,5 @@ const passport = require('passport') -const { logger } = require('@/logging/logging') +const debug = require('debug') /** * Wrapper for passport.authenticate that handles success & failure scenarios correctly @@ -11,7 +11,7 @@ const { logger } = require('@/logging/logging') function passportAuthenticate(strategy, options = undefined) { return (req, res, next) => passport.authenticate(strategy, options, (err, user, info) => { - if (err) logger.error(err) + if (err) debug('speckle:error')(err) if (!user) { const errMsg = info?.message || 'Failed to authenticate, contact server admins' return res.redirect(`/error?message=${errMsg}`) diff --git a/packages/server/modules/auth/strategies.js b/packages/server/modules/auth/strategies.js index 2a57bebf4..38d4ddb9f 100644 --- a/packages/server/modules/auth/strategies.js +++ b/packages/server/modules/auth/strategies.js @@ -8,7 +8,6 @@ const passport = require('passport') const sentry = require('@/logging/sentryHelper') const { createAuthorizationCode } = require('./services/apps') const { isSSLServer } = require('@/modules/shared/helpers/envHelper') -const { moduleLogger } = require('@/logging/logging') /** * TODO: Get rid of session entirely, we don't use it for the app and it's not really necessary for the auth flow, so it only complicates things @@ -70,7 +69,6 @@ module.exports = async (app) => { return res.redirect(redirectUrl) } catch (err) { sentry({ err }) - moduleLogger.error(err) if (req.session) req.session.destroy() return res.status(401).send({ err: err.message }) } diff --git a/packages/server/modules/auth/strategies/azure-ad.js b/packages/server/modules/auth/strategies/azure-ad.js index 856567d22..78e18f7f2 100644 --- a/packages/server/modules/auth/strategies/azure-ad.js +++ b/packages/server/modules/auth/strategies/azure-ad.js @@ -4,6 +4,7 @@ const passport = require('passport') const OIDCStrategy = require('passport-azure-ad').OIDCStrategy const URL = require('url').URL +const debug = require('debug') const { findOrCreateUser, getUserByEmail } = require('@/modules/core/services/users') const { getServerInfo } = require('@/modules/core/services/generic') const { @@ -12,7 +13,6 @@ const { resolveAuthRedirectPath } = require('@/modules/serverinvites/services/inviteProcessingService') const { passportAuthenticate } = require('@/modules/auth/services/passportService') -const { logger } = require('@/logging/logging') module.exports = async (app, session, sessionStorage, finalizeAuth) => { const strategy = new OIDCStrategy( @@ -120,7 +120,7 @@ module.exports = async (app, session, sessionStorage, finalizeAuth) => { // return to the auth flow return next() } catch (err) { - logger.error(err) + debug('speckle:error')(err) return next() } }, diff --git a/packages/server/modules/auth/strategies/github.js b/packages/server/modules/auth/strategies/github.js index 85287abad..6a9724374 100644 --- a/packages/server/modules/auth/strategies/github.js +++ b/packages/server/modules/auth/strategies/github.js @@ -4,6 +4,7 @@ const passport = require('passport') const GithubStrategy = require('passport-github2') const URL = require('url').URL +const debug = require('debug') const { findOrCreateUser, getUserByEmail } = require('@/modules/core/services/users') const { getServerInfo } = require('@/modules/core/services/generic') const { @@ -12,7 +13,6 @@ const { resolveAuthRedirectPath } = require('@/modules/serverinvites/services/inviteProcessingService') const { passportAuthenticate } = require('@/modules/auth/services/passportService') -const { logger } = require('@/logging/logging') module.exports = async (app, session, sessionStorage, finalizeAuth) => { const strategy = { @@ -91,7 +91,7 @@ module.exports = async (app, session, sessionStorage, finalizeAuth) => { // return to the auth flow return done(null, myUser) } catch (err) { - logger.error(err) + debug('speckle:error')(err) return done(null, false, { message: err.message }) } } diff --git a/packages/server/modules/auth/strategies/google.js b/packages/server/modules/auth/strategies/google.js index d8fa43519..d35d671e3 100644 --- a/packages/server/modules/auth/strategies/google.js +++ b/packages/server/modules/auth/strategies/google.js @@ -2,6 +2,7 @@ 'use strict' const passport = require('passport') const GoogleStrategy = require('passport-google-oauth20').Strategy +const debug = require('debug') const { findOrCreateUser, getUserByEmail } = require('@/modules/core/services/users') const { getServerInfo } = require('@/modules/core/services/generic') const { @@ -10,7 +11,6 @@ const { resolveAuthRedirectPath } = require('@/modules/serverinvites/services/inviteProcessingService') const { passportAuthenticate } = require('@/modules/auth/services/passportService') -const { logger } = require('@/logging/logging') module.exports = async (app, session, sessionStorage, finalizeAuth) => { const strategy = { @@ -88,7 +88,7 @@ module.exports = async (app, session, sessionStorage, finalizeAuth) => { // return to the auth flow return done(null, myUser) } catch (err) { - logger.error(err) + debug('speckle:error')(err) return done(null, false, { message: err.message }) } } diff --git a/packages/server/modules/auth/strategies/local.js b/packages/server/modules/auth/strategies/local.js index 453bf2f9f..058244d1e 100644 --- a/packages/server/modules/auth/strategies/local.js +++ b/packages/server/modules/auth/strategies/local.js @@ -1,4 +1,5 @@ 'use strict' +const debug = require('debug') const { createUser, validatePasssword, @@ -17,7 +18,6 @@ const { resolveAuthRedirectPath } = require('@/modules/serverinvites/services/inviteProcessingService') const { getIpFromRequest } = require('@/modules/shared/utils/ip') -const { logger } = require('@/logging/logging') module.exports = async (app, session, sessionAppId, finalizeAuth) => { const strategy = { @@ -101,7 +101,7 @@ module.exports = async (app, session, sessionAppId, finalizeAuth) => { return next() } catch (err) { - logger.error(err) + debug('speckle:error')(err) return res.status(400).send({ err: err.message }) } }, diff --git a/packages/server/modules/blobstorage/index.js b/packages/server/modules/blobstorage/index.js index b03df3b31..51f633c9a 100644 --- a/packages/server/modules/blobstorage/index.js +++ b/packages/server/modules/blobstorage/index.js @@ -1,3 +1,4 @@ +const debug = require('debug') const Busboy = require('busboy') const { streamReadPermissions, @@ -36,19 +37,18 @@ const { ResourceMismatch, BadRequestError } = require('@/modules/shared/errors') -const { moduleLogger, logger } = require('@/logging/logging') const ensureConditions = async () => { if (process.env.DISABLE_FILE_UPLOADS) { - moduleLogger.info('ðŸ“Ķ Blob storage is DISABLED') + debug('speckle:modules')('ðŸ“Ķ Blob storage is DISABLED') return } else { - moduleLogger.info('ðŸ“Ķ Init BlobStorage module') + debug('speckle:modules')('ðŸ“Ķ Init BlobStorage module') await ensureStorageAccess() } if (!process.env.S3_BUCKET) { - logger.error( + debug('speckle:error')( 'S3_BUCKET env variable was not specified. ðŸ“Ķ BlobStorage will be DISABLED.' ) return @@ -104,7 +104,7 @@ exports.init = async (app) => { if (formKey.includes('hash:')) { clientHash = formKey.split(':')[1] if (clientHash && clientHash !== '') { - // logger.debug(`I have a client hash (${clientHash})`) + // console.log(`I have a client hash (${clientHash})`) blobId = clientHash } } @@ -148,7 +148,7 @@ exports.init = async (app) => { }) busboy.on('error', async (err) => { - logger.error(`File upload error: ${err}`) + debug('speckle:error')(`File upload error: ${err}`) //delete all started uploads await Promise.all( Object.keys(uploadOperations).map((blobId) => diff --git a/packages/server/modules/blobstorage/objectStorage.js b/packages/server/modules/blobstorage/objectStorage.js index dee6ef0f9..7b1be8c73 100644 --- a/packages/server/modules/blobstorage/objectStorage.js +++ b/packages/server/modules/blobstorage/objectStorage.js @@ -1,4 +1,3 @@ -const { logger } = require('@/logging/logging') const { NotFoundError } = require('@/modules/shared/errors') const { S3Client, @@ -89,7 +88,7 @@ const storeFileStream = async ({ objectKey, fileStream }) => { }) // parallelUploads3.on('httpUploadProgress', (progress) => { - // logger.debug(progress) + // console.log(progress) // }) const data = await parallelUploads3.done() @@ -115,7 +114,7 @@ const ensureStorageAccess = async () => { try { await client.send(new CreateBucketCommand({ Bucket })) } catch (err) { - logger.error(err) + console.log(err) } } else { throw new Error(`Can't open S3 bucket '${Bucket}': ${err.toString()}`) diff --git a/packages/server/modules/cli/commands/activities/send.ts b/packages/server/modules/cli/commands/activities/send.ts index b662a469c..ae87a34c0 100644 --- a/packages/server/modules/cli/commands/activities/send.ts +++ b/packages/server/modules/cli/commands/activities/send.ts @@ -2,7 +2,7 @@ import { CommandModule } from 'yargs' import { initializeQueue } from '@/modules/notifications/services/queue' import { sendActivityNotifications } from '@/modules/activitystream/services/summary' import { publishNotification } from '@/modules/notifications/services/publication' -import { cliLogger } from '@/logging/logging' +import { cliDebug } from '@/modules/shared/utils/logger' const command: CommandModule = { command: 'send [days]', @@ -22,7 +22,7 @@ const command: CommandModule = { const start = new Date(end.getTime()) start.setDate(start.getDate() - numberOfDays) await sendActivityNotifications(start, end, publishNotification) - cliLogger.info('Sent activity notifications') + cliDebug('Sent activity notifications') } } diff --git a/packages/server/modules/cli/commands/bull/monitor.ts b/packages/server/modules/cli/commands/bull/monitor.ts index 88038692f..5bd1e316d 100644 --- a/packages/server/modules/cli/commands/bull/monitor.ts +++ b/packages/server/modules/cli/commands/bull/monitor.ts @@ -7,8 +7,8 @@ import { NOTIFICATIONS_QUEUE, buildNotificationsQueue } from '@/modules/notifications/services/queue' +import { cliDebug } from '@/modules/shared/utils/logger' import { noop } from 'lodash' -import { cliLogger } from '@/logging/logging' const PORT = 3032 @@ -25,15 +25,15 @@ const command: CommandModule = { handler: async (argv) => { const testQueueId = argv.testQueueId - cliLogger.info('Initializing bull queues...') + cliDebug('Initializing bull queues...') const queues = [buildNotificationsQueue(NOTIFICATIONS_QUEUE)] if (testQueueId) { - cliLogger.info('Also initializing queue %s...', testQueueId) + cliDebug('Also initializing queue ' + testQueueId + '...') queues.push(buildNotificationsQueue(testQueueId)) } - cliLogger.info('Initializing monitor...') + cliDebug('Initializing monitor...') const app = express() const serverAdapter = new ExpressAdapter() @@ -45,8 +45,8 @@ const command: CommandModule = { app.use(serverAdapter.getRouter()) app.listen(PORT, () => { - cliLogger.info(`Running on ${PORT}...`) - cliLogger.info( + cliDebug(`Running on ${PORT}...`) + cliDebug( `For the UI, open http://localhost:${PORT}/, and make sure Redis is running` ) }) diff --git a/packages/server/modules/cli/commands/bull/test-consume.ts b/packages/server/modules/cli/commands/bull/test-consume.ts index b3d0d18b5..adf22e43c 100644 --- a/packages/server/modules/cli/commands/bull/test-consume.ts +++ b/packages/server/modules/cli/commands/bull/test-consume.ts @@ -1,6 +1,6 @@ -import { cliLogger } from '@/logging/logging' import { NotificationType } from '@/modules/notifications/helpers/types' import { initializeConsumption } from '@/modules/notifications/index' +import { cliDebug } from '@/modules/shared/utils/logger' import { get, noop } from 'lodash' import { CommandModule } from 'yargs' @@ -8,12 +8,12 @@ const command: CommandModule = { command: 'test-consume', describe: 'Consume incoming messages inserted through test-push', handler: async () => { - cliLogger.info('Starting consumption...') + cliDebug('Starting consumption...') // Overriding handler for test purposes, we don't want the actual mentions logic to run await initializeConsumption({ - [NotificationType.MentionedInComment]: async (msg, { logger, job }) => { - logger.info('Received test message with payload', msg, job) + [NotificationType.MentionedInComment]: async (msg, { debug, job }) => { + debug('Received test message with payload', msg, job) if (get(msg.data, 'error')) { throw new Error('Forced to throw error!') diff --git a/packages/server/modules/cli/commands/bull/test-push.ts b/packages/server/modules/cli/commands/bull/test-push.ts index c1f9bbd42..09d5d264e 100644 --- a/packages/server/modules/cli/commands/bull/test-push.ts +++ b/packages/server/modules/cli/commands/bull/test-push.ts @@ -1,10 +1,10 @@ -import { cliLogger } from '@/logging/logging' import { MentionedInCommentData, NotificationType } from '@/modules/notifications/helpers/types' import { publishNotification } from '@/modules/notifications/services/publication' import { initializeQueue } from '@/modules/notifications/services/queue' +import { cliDebug } from '@/modules/shared/utils/logger' import { CommandModule } from 'yargs' const command: CommandModule = { @@ -36,7 +36,7 @@ const command: CommandModule = { } as unknown as MentionedInCommentData }) - cliLogger.info('Queued a fake notification...') + cliDebug('Queued a fake notification...') } } diff --git a/packages/server/modules/cli/commands/db/migrate/create.js b/packages/server/modules/cli/commands/db/migrate/create.js index 54116fb5f..6e3ae8406 100644 --- a/packages/server/modules/cli/commands/db/migrate/create.js +++ b/packages/server/modules/cli/commands/db/migrate/create.js @@ -1,7 +1,6 @@ const knex = require('@/db/knex') const { appRoot } = require('@/bootstrap') const fs = require('fs/promises') -const { logger } = require('@/logging/logging') /** @type {import('yargs').CommandModule} */ const command = { @@ -31,12 +30,12 @@ const command = { ) } - logger.info('Creating migration...') + console.log('Creating migration...') await knex.migrate.make(name, { directory: migrationDir, extension: 'ts' }) - logger.info('migration is complete') + console.log('...done') } } diff --git a/packages/server/modules/cli/commands/db/migrate/down.js b/packages/server/modules/cli/commands/db/migrate/down.js index cd2f65280..37c548967 100644 --- a/packages/server/modules/cli/commands/db/migrate/down.js +++ b/packages/server/modules/cli/commands/db/migrate/down.js @@ -1,14 +1,13 @@ const knex = require('@/db/knex') -const { logger } = require('@/logging/logging') /** @type {import('yargs').CommandModule} */ const command = { command: 'down', describe: 'Undo last run migration', async handler() { - logger.info('Undoing last migration...') + console.log('Undoing last migration...') await knex.migrate.down() - logger.info('Completed undoing last migration') + console.log('...done') } } diff --git a/packages/server/modules/cli/commands/db/migrate/latest.js b/packages/server/modules/cli/commands/db/migrate/latest.js index 765d8ce98..07b6f100f 100644 --- a/packages/server/modules/cli/commands/db/migrate/latest.js +++ b/packages/server/modules/cli/commands/db/migrate/latest.js @@ -1,14 +1,13 @@ const knex = require('@/db/knex') -const { logger } = require('@/logging/logging') /** @type {import('yargs').CommandModule} */ const command = { command: 'latest', describe: 'Run all migrations that have not yet been run', async handler() { - logger.info('Running latest migration...') + console.log('Running...') await knex.migrate.latest() - logger.info('Completed running migration') + console.log('...done') } } diff --git a/packages/server/modules/cli/commands/db/migrate/rollback.js b/packages/server/modules/cli/commands/db/migrate/rollback.js index ec101ead8..f37c5198b 100644 --- a/packages/server/modules/cli/commands/db/migrate/rollback.js +++ b/packages/server/modules/cli/commands/db/migrate/rollback.js @@ -1,14 +1,13 @@ const knex = require('@/db/knex') -const { logger } = require('@/logging/logging') /** @type {import('yargs').CommandModule} */ const command = { command: 'rollback', describe: 'Roll back all migrations', async handler() { - logger.info('Rolling back migrations...') + console.log('Rolling back...') await knex.migrate.rollback(null, true) - logger.info('Completed rolling back migrations') + console.log('...done') } } diff --git a/packages/server/modules/cli/commands/db/migrate/up.js b/packages/server/modules/cli/commands/db/migrate/up.js index 04205f2dc..f02508fec 100644 --- a/packages/server/modules/cli/commands/db/migrate/up.js +++ b/packages/server/modules/cli/commands/db/migrate/up.js @@ -1,14 +1,13 @@ const knex = require('@/db/knex') -const { logger } = require('@/logging/logging') /** @type {import('yargs').CommandModule} */ const command = { command: 'up', describe: 'Run next migration that has not yet been run', async handler() { - logger.info('Running next migration...') + console.log('Running...') await knex.migrate.up() - logger.info('Completed running next migration') + console.log('...done') } } diff --git a/packages/server/modules/cli/commands/db/seed/commits.ts b/packages/server/modules/cli/commands/db/seed/commits.ts index a8546ff4c..6d02aec1b 100644 --- a/packages/server/modules/cli/commands/db/seed/commits.ts +++ b/packages/server/modules/cli/commands/db/seed/commits.ts @@ -1,6 +1,6 @@ -import { cliLogger } from '@/logging/logging' import { getStream } from '@/modules/core/repositories/streams' import { getUser } from '@/modules/core/repositories/users' +import { cliDebug } from '@/modules/shared/utils/logger' import { BasicTestCommit, createTestCommits } from '@/test/speckle-helpers/commitHelper' import dayjs from 'dayjs' import { times } from 'lodash' @@ -48,7 +48,7 @@ const command: CommandModule< ) } - cliLogger.info(`Generating ${count} objects & commits for stream ${streamId}...`) + cliDebug(`Generating ${count} objects & commits for stream ${streamId}...`) await createTestCommits( times( count, @@ -61,7 +61,7 @@ const command: CommandModule< }) ) ) - cliLogger.info(`...done`) + cliDebug(`...done`) } } diff --git a/packages/server/modules/cli/commands/db/seed/users.js b/packages/server/modules/cli/commands/db/seed/users.js index 2a56dfed4..e92c168e7 100644 --- a/packages/server/modules/cli/commands/db/seed/users.js +++ b/packages/server/modules/cli/commands/db/seed/users.js @@ -1,4 +1,3 @@ -const { logger } = require('@/logging/logging') const { Users, ServerAcl } = require('@/modules/core/dbSchema') const { Roles } = require('@/modules/core/helpers/mainConstants') const { faker } = require('@faker-js/faker') @@ -46,11 +45,11 @@ async function* batchedOperationGenerator({ batchSize, retryCount = 3 }) { - logger.info('Starting batched operation...') + console.log('Starting batched operation...') let currentItemCount = 0 const batchCount = Math.ceil(itemCount / batchSize) for (let i = 0; i < batchCount; i++) { - logger.info(`Processing batch ${i + 1} out of ${batchCount}...`) + console.log(`Processing batch ${i + 1} out of ${batchCount}...`) const newItemCount = Math.min(currentItemCount + batchSize, itemCount) const insertCount = newItemCount - currentItemCount @@ -60,7 +59,7 @@ async function* batchedOperationGenerator({ const execute = () => Promise.resolve(batchInsertGenerator(insertCount, currentItemCount)) let batchPromise = execute().then((res) => { - logger.info(`...processed batch ${i + 1} out of ${batchCount}`) + console.log(`...processed batch ${i + 1} out of ${batchCount}`) return res }) @@ -71,7 +70,7 @@ async function* batchedOperationGenerator({ }) }) batchPromise = batchPromise.catch((e) => { - logger.error('Operation failed all retries: ', e) + console.error('Operation failed all retries: ', e) }) currentItemCount = newItemCount @@ -111,14 +110,14 @@ const command = { }) for await (const insertedIds of userBatchedInsertionGenerator) { - logger.info('Inserting ACL entries for batch...') + console.log('Inserting ACL entries for batch...') const entries = insertedIds.map((id) => ({ role: Roles.Server.User, userId: id })) await ServerAcl.knex().insert(entries) - logger.info('...inserted ACL') + console.log('...inserted ACL') } } } diff --git a/packages/server/modules/cli/commands/download/commit.ts b/packages/server/modules/cli/commands/download/commit.ts index 33a611e8b..79e1b3ee7 100644 --- a/packages/server/modules/cli/commands/download/commit.ts +++ b/packages/server/modules/cli/commands/download/commit.ts @@ -7,6 +7,7 @@ import { HttpLink, ApolloQueryResult } from '@apollo/client/core' +import { cliDebug } from '@/modules/shared/utils/logger' import { CommandModule } from 'yargs' import { getBaseUrl, getServerVersion } from '@/modules/shared/helpers/envHelper' import { Commit } from '@/test/graphql/generated/graphql' @@ -19,7 +20,6 @@ import { createObject } from '@/modules/core/services/objects' import { getObject } from '@/modules/core/repositories/objects' import ObjectLoader from '@speckle/objectloader' import { noop } from 'lodash' -import { cliLogger } from '@/logging/logging' type LocalResources = Awaited> type ParsedCommitUrl = ReturnType @@ -188,7 +188,7 @@ const createNewObject = async ( targetStreamId: string ) => { if (!newObject) { - cliLogger.error('Encountered falsy object!') + cliDebug('Encountered falsy object!') return } @@ -230,9 +230,7 @@ const loadAllObjectsFromParent = async (params: { let processedObjectCount = 1 for await (const obj of objectLoader.getObjectIterator()) { const typedObj = obj as ObjectLoaderObject - cliLogger.info( - `Processing ${obj.id} - ${processedObjectCount++}/${totalObjectCount}` - ) + cliDebug(`Processing ${obj.id} - ${processedObjectCount++}/${totalObjectCount}`) await createNewObject(typedObj, targetStreamId) } } @@ -261,24 +259,24 @@ const command: CommandModule< }, handler: async (argv) => { const { commitUrl, targetStreamId, branchName } = argv - cliLogger.info(`Process started at: ${new Date().toISOString()}`) + cliDebug(`Process started at: ${new Date().toISOString()}`) const localResources = await getLocalResources(targetStreamId, branchName) - cliLogger.info( + cliDebug( `Using local branch ${branchName} of stream ${targetStreamId} to dump the incoming commit` ) const parsedCommitUrl = parseCommitUrl(commitUrl) - cliLogger.info('Loading the following commit: %s', parsedCommitUrl) + cliDebug('Loading the following commit: ', parsedCommitUrl) const client = await createApolloClient(parsedCommitUrl.origin) const commit = await getCommitMetadata(client, parsedCommitUrl) - cliLogger.info('Loaded commit metadata: %s', commit) + cliDebug('Loaded commit metadata', commit) const newCommitId = await saveNewCommit(commit, localResources) - cliLogger.info(`Created new local commit: ${newCommitId}`) + cliDebug(`Created new local commit: ${newCommitId}`) - cliLogger.info(`Pulling & saving all objects! (${commit.totalChildrenCount})`) + cliDebug(`Pulling & saving all objects! (${commit.totalChildrenCount})`) await loadAllObjectsFromParent({ targetStreamId, sourceCommit: commit, @@ -286,7 +284,7 @@ const command: CommandModule< }) const linkToNewCommit = `${getBaseUrl()}/streams/${targetStreamId}/commits/${newCommitId}` - cliLogger.info(`All done! Find your commit here: ${linkToNewCommit}`) + cliDebug(`All done! Find your commit here: ${linkToNewCommit}`) } } diff --git a/packages/server/modules/cli/index.js b/packages/server/modules/cli/index.js index f953188d5..c52da28f6 100644 --- a/packages/server/modules/cli/index.js +++ b/packages/server/modules/cli/index.js @@ -1,7 +1,6 @@ const path = require('path') const yargs = require('yargs') require('../../bootstrap') -const { logger } = require('@/logging/logging') const execution = yargs .scriptName('yarn cli') @@ -11,12 +10,12 @@ const execution = yargs .fail((msg, err, yargs) => { if (!err) { // If validation error (no err instance) then just show help and show the message - logger.error(yargs.help()) - logger.error('\n', msg) + console.error(yargs.help()) + console.error('\n', msg) } else { // If actual app error occurred, show the msg, but don't show help info - logger.error(err) - logger.error('\n', 'Specify --help for available options') + console.error(err) + console.error('\n', 'Specify --help for available options') } process.exit(1) diff --git a/packages/server/modules/comments/index.js b/packages/server/modules/comments/index.js index 5b171120b..abceda71a 100644 --- a/packages/server/modules/comments/index.js +++ b/packages/server/modules/comments/index.js @@ -1,12 +1,12 @@ -const { moduleLogger } = require('@/logging/logging') const { notifyUsersOnCommentEvents } = require('@/modules/comments/services/notifications') +const debug = require('debug') let unsubFromEvents exports.init = async (_, isInitial) => { - moduleLogger.info('ðŸ—Ģ Init comments module') + debug('speckle:modules')('ðŸ—Ģ Init comments module') if (isInitial) { unsubFromEvents = await notifyUsersOnCommentEvents() diff --git a/packages/server/modules/core/index.js b/packages/server/modules/core/index.js index caddd000e..5f7d524ff 100644 --- a/packages/server/modules/core/index.js +++ b/packages/server/modules/core/index.js @@ -1,9 +1,9 @@ 'use strict' +const debug = require('debug') const { registerOrUpdateScope, registerOrUpdateRole } = require('@/modules/shared') -const { moduleLogger } = require('@/logging/logging') exports.init = async (app) => { - moduleLogger.info('ðŸ’Ĩ Init core module') + debug('speckle:modules')('ðŸ’Ĩ Init core module') // Initialize the static route require('./rest/static')(app) diff --git a/packages/server/modules/core/rest/diffDownload.js b/packages/server/modules/core/rest/diffDownload.js index 29e7d9cff..7fdc57de9 100644 --- a/packages/server/modules/core/rest/diffDownload.js +++ b/packages/server/modules/core/rest/diffDownload.js @@ -1,5 +1,6 @@ 'use strict' const zlib = require('zlib') +const debug = require('debug') const cors = require('cors') const { validatePermissionsReadStream } = require('./authUtils') @@ -7,7 +8,6 @@ const { SpeckleObjectsStream } = require('./speckleObjectsStream') const { getObjectsStream } = require('../services/objects') const { pipeline, PassThrough } = require('stream') -const { logger } = require('@/logging/logging') module.exports = (app) => { app.options('/api/getobjects/:streamId', cors()) @@ -40,13 +40,13 @@ module.exports = (app) => { res, (err) => { if (err) { - logger.error( + debug('speckle:error')( `[User ${ req.context.userId || '-' }] App error streaming objects from stream ${req.params.streamId}: ${err}` ) } else { - logger.info( + debug('speckle:info')( `[User ${req.context.userId || '-'}] Streamed ${ childrenList.length } objects from stream ${req.params.streamId} (size: ${ @@ -73,7 +73,7 @@ module.exports = (app) => { }) } } catch (ex) { - logger.error( + debug('speckle:error')( `[User ${req.context.userId || '-'}] DB Error streaming objects from stream ${ req.params.streamId }: ${ex}` diff --git a/packages/server/modules/core/rest/diffUpload.js b/packages/server/modules/core/rest/diffUpload.js index f8c688d25..d9572a1d1 100644 --- a/packages/server/modules/core/rest/diffUpload.js +++ b/packages/server/modules/core/rest/diffUpload.js @@ -1,11 +1,11 @@ 'use strict' const zlib = require('zlib') const cors = require('cors') +const debug = require('debug') const { validatePermissionsWriteStream } = require('./authUtils') const { hasObjects } = require('../services/objects') -const { logger } = require('@/logging/logging') module.exports = (app) => { app.options('/api/diff/:streamId', cors()) @@ -21,7 +21,7 @@ module.exports = (app) => { const objectList = JSON.parse(req.body.objects) - logger.info( + debug('speckle:info')( `[User ${req.context.userId || '-'}] Diffing ${ objectList.length } objects for stream ${req.params.streamId}` @@ -31,7 +31,7 @@ module.exports = (app) => { streamId: req.params.streamId, objectIds: objectList }) - // logger.debug(response) + // console.log(response) res.writeHead(200, { 'Content-Encoding': 'gzip', 'Content-Type': 'application/json' diff --git a/packages/server/modules/core/rest/download.js b/packages/server/modules/core/rest/download.js index da092316c..5eefe9058 100644 --- a/packages/server/modules/core/rest/download.js +++ b/packages/server/modules/core/rest/download.js @@ -1,5 +1,6 @@ 'use strict' const zlib = require('zlib') +const debug = require('debug') const cors = require('cors') const { validatePermissionsReadStream } = require('./authUtils') @@ -7,7 +8,7 @@ const { validatePermissionsReadStream } = require('./authUtils') const { getObject, getObjectChildrenStream } = require('../services/objects') const { SpeckleObjectsStream } = require('./speckleObjectsStream') const { pipeline, PassThrough } = require('stream') -const { logger } = require('@/logging/logging') + module.exports = (app) => { app.options('/objects/:streamId/:objectId', cors()) @@ -54,13 +55,13 @@ module.exports = (app) => { res, (err) => { if (err) { - logger.error( + debug('speckle:error')( `[User ${req.context.userId || '-'}] Error downloading object ${ req.params.objectId } from stream ${req.params.streamId}: ${err}` ) } else { - logger.info( + debug('speckle:info')( `[User ${req.context.userId || '-'}] Downloaded object ${ req.params.objectId } from stream ${req.params.streamId} (size: ${ @@ -91,7 +92,7 @@ module.exports = (app) => { return res.status(404).send('Failed to find object.') } - logger.info( + debug('speckle:info')( `[User ${req.context.userId || '-'}] Downloaded single object ${ req.params.objectId } from stream ${req.params.streamId}` diff --git a/packages/server/modules/core/rest/upload.js b/packages/server/modules/core/rest/upload.js index f6bb6ee0e..6c5071da2 100644 --- a/packages/server/modules/core/rest/upload.js +++ b/packages/server/modules/core/rest/upload.js @@ -2,11 +2,11 @@ const zlib = require('zlib') const cors = require('cors') const Busboy = require('busboy') +const debug = require('debug') const { validatePermissionsWriteStream } = require('./authUtils') const { createObjectsBatched } = require('../services/objects') -const { logger, uploadEndpointLogger } = require('@/logging/logging') const MAX_FILE_SIZE = 50 * 1024 * 1024 @@ -48,7 +48,7 @@ module.exports = (app) => { const gzippedBuffer = Buffer.concat(buffer) if (gzippedBuffer.length > MAX_FILE_SIZE) { - logger.error( + debug('speckle:error')( `[User ${ req.context.userId || '-' }] Upload error: Batch size too large (${ @@ -66,7 +66,7 @@ module.exports = (app) => { const gunzippedBuffer = zlib.gunzipSync(gzippedBuffer).toString() if (gunzippedBuffer.length > MAX_FILE_SIZE) { - logger.error( + debug('speckle:error')( `[User ${ req.context.userId || '-' }] Upload error: Batch size too large (${ @@ -85,7 +85,7 @@ module.exports = (app) => { try { objs = JSON.parse(gunzippedBuffer) } catch (e) { - logger.error( + debug('speckle:error')( `[User ${ req.context.userId || '-' }] Upload error: Batch not in JSON format` @@ -104,7 +104,7 @@ module.exports = (app) => { } const promise = createObjectsBatched(req.params.streamId, objs).catch((e) => { - logger.error( + debug('speckle:error')( `[User ${req.context.userId || '-'}] Upload error: ${e.message}` ) if (!requestDropped) @@ -119,7 +119,7 @@ module.exports = (app) => { await promise - logger.info( + debug('speckle:info')( `[User ${req.context.userId || '-'}] Uploaded batch of ${ objs.length } objects to stream ${req.params.streamId} (size: ${ @@ -146,7 +146,7 @@ module.exports = (app) => { let objs = [] if (buffer.length > MAX_FILE_SIZE) { - logger.error( + debug('speckle:error')( `[User ${ req.context.userId || '-' }] Upload error: Batch size too large (${ @@ -163,7 +163,7 @@ module.exports = (app) => { try { objs = JSON.parse(buffer) } catch (e) { - logger.error( + debug('speckle:error')( `[User ${ req.context.userId || '-' }] Upload error: Batch not in JSON format` @@ -181,7 +181,7 @@ module.exports = (app) => { } const promise = createObjectsBatched(req.params.streamId, objs).catch((e) => { - logger.error( + debug('speckle:error')( `[User ${req.context.userId || '-'}] Upload error: ${e.message}` ) if (!requestDropped) @@ -195,7 +195,7 @@ module.exports = (app) => { promises.push(promise) await promise - logger.info( + debug('speckle:info')( `[User ${req.context.userId || '-'}] Uploaded batch of ${ objs.length } objects to stream ${req.params.streamId} (size: ${ @@ -206,7 +206,7 @@ module.exports = (app) => { ) }) } else { - logger.error( + debug('speckle:error')( `[User ${req.context.userId || '-'}] Invalid ContentType header: ${mimeType}` ) if (!requestDropped) @@ -222,7 +222,7 @@ module.exports = (app) => { busboy.on('finish', async () => { if (requestDropped) return - uploadEndpointLogger.info( + debug('speckle:upload-endpoint')( `[User ${req.context.userId || '-'}] Upload finished: ${totalProcessed} objs, ${ process.memoryUsage().heapUsed / 1024 / 1024 } MB mem` @@ -238,7 +238,7 @@ module.exports = (app) => { }) busboy.on('error', async (err) => { - uploadEndpointLogger.info( + debug('speckle:upload-endpoint')( `[User ${req.context.userId || '-'}] Upload error: ${err}` ) if (!requestDropped) diff --git a/packages/server/modules/core/services/objects.js b/packages/server/modules/core/services/objects.js index 3ee1489ef..8930cba1c 100644 --- a/packages/server/modules/core/services/objects.js +++ b/packages/server/modules/core/services/objects.js @@ -3,8 +3,9 @@ const { performance } = require('perf_hooks') const crypto = require('crypto') const { set, get, chunk } = require('lodash') +const debug = require('debug')('speckle:services') + const knex = require(`@/db/knex`) -const { servicesLogger } = require('@/logging/logging') const Objects = () => knex('objects') const Closures = () => knex('object_children_closure') @@ -102,7 +103,7 @@ module.exports = { const q = Objects().insert(batch).toString() + ' on conflict do nothing' await trx.raw(q) }) - servicesLogger.info(`Inserted ${batch.length} objects`) + debug(`Inserted ${batch.length} objects`) } } @@ -116,7 +117,7 @@ module.exports = { const q = Closures().insert(batch).toString() + ' on conflict do nothing' await trx.raw(q) }) - servicesLogger.info(`Inserted ${batch.length} closures`) + debug(`Inserted ${batch.length} closures`) } } return true @@ -189,12 +190,12 @@ module.exports = { } const t1 = performance.now() - servicesLogger.info( + debug( `Batch ${index + 1}/${batches.length}: Stored ${ closures.length + objsToInsert.length } objects in ${t1 - t0}ms.` ) - // logger.debug( `Batch ${index + 1}/${batches.length}: Stored ${closures.length + objsToInsert.length} objects in ${t1-t0}ms.` ) + // console.log( `Batch ${index + 1}/${batches.length}: Stored ${closures.length + objsToInsert.length} objects in ${t1-t0}ms.` ) } const promises = batches.map((batch, index) => insertBatch(batch, index)) @@ -432,7 +433,7 @@ module.exports = { // Set cursor clause, if present. If it's not present, it's an entry query; this method will return a cursor based on its given query. // We have implemented keyset pagination for more efficient searches on larger sets. This approach depends on an order by value provided by the user and a (hidden) primary key. - // logger.debug( cursor ) + // console.log( cursor ) if (cursor) { let castType = 'text' if (typeof cursor.value === 'string') castType = 'text' @@ -488,7 +489,7 @@ module.exports = { } mainQuery.limit(limit) - // logger.debug( mainQuery.toString() ) + // console.log( mainQuery.toString() ) // Finally, execute the query const rows = await mainQuery const totalCount = rows && rows.length > 0 ? parseInt(rows[0].total_count) : 0 diff --git a/packages/server/modules/core/services/streams.js b/packages/server/modules/core/services/streams.js index ab3247b22..7c0e3cfbc 100644 --- a/packages/server/modules/core/services/streams.js +++ b/packages/server/modules/core/services/streams.js @@ -1,6 +1,7 @@ 'use strict' const _ = require('lodash') const crs = require('crypto-random-string') +const debug = require('debug') const { createBranch } = require('@/modules/core/services/branches') const { Streams, StreamAcl, knex } = require('@/modules/core/dbSchema') @@ -17,7 +18,6 @@ const { inviteUsersToStream } = require('@/modules/serverinvites/services/inviteCreationService') const { omitBy, isNull, isUndefined, has } = require('lodash') -const { dbLogger } = require('@/logging/logging') module.exports = { /** @@ -165,7 +165,7 @@ module.exports = { }, async deleteStream({ streamId }) { - dbLogger.info('Deleting stream %s', streamId) + debug('speckle:db')('Deleting stream ' + streamId) // Delete stream commits (not automatically cascaded) await knex.raw( diff --git a/packages/server/modules/core/services/taskScheduler.ts b/packages/server/modules/core/services/taskScheduler.ts index 791568ce5..e14640965 100644 --- a/packages/server/modules/core/services/taskScheduler.ts +++ b/packages/server/modules/core/services/taskScheduler.ts @@ -1,9 +1,11 @@ import cron from 'node-cron' import { InvalidArgumentError } from '@/modules/shared/errors' +import { modulesDebug, errorDebug } from '@/modules/shared/utils/logger' import { ensureError } from '@/modules/shared/helpers/errorHelper' import { acquireTaskLock } from '@/modules/core/repositories/scheduledTasks' import { ScheduledTaskRecord } from '@/modules/core/helpers/types' -import { activitiesLogger, logger } from '@/logging/logging' + +const activitiesDebug = modulesDebug.extend('activities') export const scheduledCallbackWrapper = async ( scheduledTime: Date, @@ -21,26 +23,24 @@ export const scheduledCallbackWrapper = async ( // if couldn't acquire it, stop execution if (!lock) { - activitiesLogger.warn( + activitiesDebug( `Could not acquire task lock for ${taskName}, stopping execution.` ) return null } // else continue executing the callback... - activitiesLogger.info( - `Executing scheduled function ${taskName} at ${scheduledTime}` - ) + activitiesDebug(`Executing scheduled function ${taskName} at ${scheduledTime}`) await callback(scheduledTime) // update lock as succeeded const finishDate = new Date() - activitiesLogger.info( + activitiesDebug( `Finished scheduled function ${taskName} execution in ${ (finishDate.getTime() - scheduledTime.getTime()) / 1000 } seconds` ) } catch (error) { - logger.error( + errorDebug( `The triggered task execution ${taskName} failed at ${scheduledTime}, with error ${ ensureError(error, 'unknown reason').message }` diff --git a/packages/server/modules/core/services/users.js b/packages/server/modules/core/services/users.js index 1fc2ebf93..5a863fadd 100644 --- a/packages/server/modules/core/services/users.js +++ b/packages/server/modules/core/services/users.js @@ -10,11 +10,11 @@ const { const Users = () => UsersSchema.knex() const Acl = () => ServerAclSchema.knex() +const debug = require('debug') const { deleteStream } = require('./streams') const { LIMITED_USER_FIELDS } = require('@/modules/core/helpers/userHelper') const { deleteAllUserInvites } = require('@/modules/serverinvites/repositories') const { UsersEmitter, UsersEvents } = require('@/modules/core/events/usersEmitter') -const { dbLogger } = require('@/logging/logging') const changeUserRole = async ({ userId, role }) => await Acl().where({ userId }).update({ role }) @@ -176,7 +176,7 @@ module.exports = { async deleteUser(id) { //TODO: check for the last admin user to survive - dbLogger.info('Deleting user ' + id) + debug('speckle:db')('Deleting user ' + id) await _ensureAtleastOneAdminRemains(id) const streams = await knex.raw( ` diff --git a/packages/server/modules/core/tests/graphSubs.spec.js b/packages/server/modules/core/tests/graphSubs.spec.js index c67e71e23..074256a7e 100644 --- a/packages/server/modules/core/tests/graphSubs.spec.js +++ b/packages/server/modules/core/tests/graphSubs.spec.js @@ -77,7 +77,7 @@ describe('GraphQL API Subscriptions @gql-subscriptions', () => { ) const reg = /running at 0.0.0.0:([0-9]*)/ - serverProcess.stdout.on('data', (data) => { + serverProcess.stderr.on('data', (data) => { // uncomment this line to understand a bit more what's happening... // console.error( `stderr: ${data}` ) // ok this is going to be a dirt hack, but I have no better idea ATM diff --git a/packages/server/modules/emails/index.ts b/packages/server/modules/emails/index.ts index bce995bc1..804ab1819 100644 --- a/packages/server/modules/emails/index.ts +++ b/packages/server/modules/emails/index.ts @@ -1,15 +1,17 @@ /* istanbul ignore file */ -import { moduleLogger } from '@/logging/logging' import * as SendingService from '@/modules/emails/services/sending' import { initializeVerificationOnRegistration } from '@/modules/emails/services/verification/request' import { initializeTransporter } from '@/modules/emails/utils/transporter' import { Optional, SpeckleModule } from '@/modules/shared/helpers/typeHelper' +import dbg from 'debug' +const debug = dbg('speckle') +const modulesDebug = debug.extend('modules') let quitVerificationListeners: Optional<() => void> = undefined const emailsModule: SpeckleModule = { init: async (app, isInitial) => { - moduleLogger.info('📧 Init emails module') + modulesDebug('📧 Init emails module') // init transporter await initializeTransporter() diff --git a/packages/server/modules/emails/services/sending.ts b/packages/server/modules/emails/services/sending.ts index 02dc1cdbf..b72b861c4 100644 --- a/packages/server/modules/emails/services/sending.ts +++ b/packages/server/modules/emails/services/sending.ts @@ -1,5 +1,8 @@ -import { logger } from '@/logging/logging' import { getTransporter } from '@/modules/emails/utils/transporter' +import dbg from 'debug' + +const debug = dbg('speckle') +const errorDebug = debug.extend('errors') export type SendEmailParams = { from?: string @@ -21,7 +24,7 @@ export async function sendEmail({ }: SendEmailParams): Promise { const transporter = getTransporter() if (!transporter) { - logger.error('No email transport present. Cannot send emails.') + errorDebug('No email transport present. Cannot send emails.') return false } try { @@ -34,7 +37,7 @@ export async function sendEmail({ html }) } catch (error) { - logger.error(error) + errorDebug(error) } return false diff --git a/packages/server/modules/emails/utils/transporter.ts b/packages/server/modules/emails/utils/transporter.ts index b62532217..4ba6b323b 100644 --- a/packages/server/modules/emails/utils/transporter.ts +++ b/packages/server/modules/emails/utils/transporter.ts @@ -1,6 +1,10 @@ -import { logger, moduleLogger } from '@/logging/logging' +import debug from 'debug' + import { createTransport, Transporter } from 'nodemailer' +const modulesDebug = debug('speckle').extend('modules') +const errorDebug = debug('speckle').extend('errors') + let transporter: Transporter | undefined = undefined const createJsonEchoTransporter = () => createTransport({ jsonTransport: true }) @@ -22,7 +26,7 @@ const initSmtpTransporter = async () => { await smtpTransporter.verify() return smtpTransporter } catch (e) { - logger.error('📧 Email provider is misconfigured, check config variables.', e) + errorDebug('📧 Email provider is misconfigured, check config variables.', e) } } @@ -33,7 +37,7 @@ export async function initializeTransporter(): Promise if (process.env.EMAIL === 'true') newTransporter = await initSmtpTransporter() if (!newTransporter) { - moduleLogger.warn( + modulesDebug( '📧 Email provider is not configured. Server functionality will be limited.' ) } diff --git a/packages/server/modules/fileuploads/index.js b/packages/server/modules/fileuploads/index.js index 07442eb16..d5d9ae217 100644 --- a/packages/server/modules/fileuploads/index.js +++ b/packages/server/modules/fileuploads/index.js @@ -1,11 +1,11 @@ /* istanbul ignore file */ 'use strict' +const debug = require('debug') const { saveUploadFile } = require('./services/fileuploads') const request = require('request') const { streamWritePermissions } = require('@/modules/shared/authz') const { authMiddlewareCreator } = require('@/modules/shared/middleware') -const { moduleLogger, logger } = require('@/logging/logging') const saveFileUploads = async ({ userId, streamId, branchName, uploadResults }) => { await Promise.all( @@ -25,10 +25,10 @@ const saveFileUploads = async ({ userId, streamId, branchName, uploadResults }) exports.init = async (app) => { if (process.env.DISABLE_FILE_UPLOADS) { - moduleLogger.warn('📄 FileUploads module is DISABLED') + debug('speckle:modules')('📄 FileUploads module is DISABLED') return } else { - moduleLogger.info('📄 Init FileUploads module') + debug('speckle:modules')('📄 Init FileUploads module') } app.post( @@ -40,7 +40,7 @@ exports.init = async (app) => { `${process.env.CANONICAL_URL}/api/stream/${req.params.streamId}/blob`, async (err, response, body) => { if (err) { - logger.error(err) + debug('speckle:error')(err.message) res.status(500).send(err.message) return } diff --git a/packages/server/modules/index.js b/packages/server/modules/index.js index c8aff7281..a3b617b41 100644 --- a/packages/server/modules/index.js +++ b/packages/server/modules/index.js @@ -5,8 +5,8 @@ const { appRoot, packageRoot } = require('@/bootstrap') const { values, merge, camelCase } = require('lodash') const baseTypeDefs = require('@/modules/core/graph/schema/baseTypeDefs') const { scalarResolvers } = require('./core/graph/scalars') +const { modulesDebug } = require('@/modules/shared/utils/logger') const { makeExecutableSchema } = require('@graphql-tools/schema') -const { moduleLogger } = require('@/logging/logging') /** * Cached speckle module requires @@ -84,13 +84,13 @@ exports.init = async (app) => { } exports.shutdown = async () => { - moduleLogger.info('Triggering module shutdown...') + modulesDebug('Triggering module shutdown...') const modules = await getSpeckleModules() for (const module of modules) { await module.shutdown?.() } - moduleLogger.info('...module shutdown finished') + modulesDebug('...module shutdown finished') } /** diff --git a/packages/server/modules/notifications/helpers/types.ts b/packages/server/modules/notifications/helpers/types.ts index f9984a8fe..198a092b2 100644 --- a/packages/server/modules/notifications/helpers/types.ts +++ b/packages/server/modules/notifications/helpers/types.ts @@ -2,8 +2,8 @@ import { StreamAccessRequestRecord } from '@/modules/accessrequests/repositories' import { MaybeAsync, Optional } from '@/modules/shared/helpers/typeHelper' import { Job } from 'bull' +import debug from 'debug' import { isObject, has } from 'lodash' -import { Logger } from 'pino' export enum NotificationType { ActivityDigest = 'activityDigest', @@ -41,7 +41,7 @@ export type NotificationHandler MaybeAsync diff --git a/packages/server/modules/notifications/index.ts b/packages/server/modules/notifications/index.ts index 4d9c41e26..11f388033 100644 --- a/packages/server/modules/notifications/index.ts +++ b/packages/server/modules/notifications/index.ts @@ -8,14 +8,14 @@ import { NotificationType, NotificationTypeHandlers } from '@/modules/notifications/helpers/types' +import { modulesDebug } from '@/modules/shared/utils/logger' import { SpeckleModule } from '@/modules/shared/helpers/typeHelper' import { shouldDisableNotificationsConsumption } from '@/modules/shared/helpers/envHelper' -import { moduleLogger } from '@/logging/logging' export async function initializeConsumption( customHandlers?: Partial ) { - moduleLogger.info('📞 Initializing notification queue consumption...') + modulesDebug('📞 Initializing notification queue consumption...') const allHandlers: Partial = { [NotificationType.MentionedInComment]: ( @@ -39,14 +39,14 @@ export async function initializeConsumption( initializeQueue() if (shouldDisableNotificationsConsumption()) { - moduleLogger.info('Skipping notification consumption...') + modulesDebug('Skipping notification consumption...') } else { await consumeIncomingNotifications() } } export const init: SpeckleModule['init'] = async (_, isInitial) => { - moduleLogger.info('📞 Init notifications module') + modulesDebug('📞 Init notifications module') if (isInitial) { await initializeConsumption() } diff --git a/packages/server/modules/notifications/services/queue.ts b/packages/server/modules/notifications/services/queue.ts index 272bdaaed..da14d28aa 100644 --- a/packages/server/modules/notifications/services/queue.ts +++ b/packages/server/modules/notifications/services/queue.ts @@ -12,11 +12,11 @@ import { NotificationType, NotificationTypeHandlers } from '@/modules/notifications/helpers/types' +import { notificationsDebug } from '@/modules/shared/utils/logger' import { isProdEnv, isTestEnv } from '@/modules/shared/helpers/envHelper' import Bull from 'bull' import { buildBaseQueueOptions } from '@/modules/shared/helpers/bullHelper' import cryptoRandomString from 'crypto-random-string' -import { logger, notificationsLogger, extendLoggerComponent } from '@/logging/logging' export type NotificationJobResult = { status: NotificationJobResultsStatus @@ -39,8 +39,8 @@ export const NOTIFICATIONS_QUEUE = isTestEnv() : NOTIFICATIONS_QUEUE_MAIN_BASE if (isTestEnv()) { - logger.info('Notifications test queue ID: ' + NOTIFICATIONS_QUEUE) - logger.info(`Monitor using: 'yarn cli bull monitor ${NOTIFICATIONS_QUEUE}'`) + console.log('Notifications test queue ID: ' + NOTIFICATIONS_QUEUE) + console.log(`Monitor using: 'yarn cli bull monitor ${NOTIFICATIONS_QUEUE}'`) } let queue: Optional @@ -117,7 +117,7 @@ export async function consumeIncomingNotifications() { queue.process(async (job): Promise => { let notificationType: Optional try { - notificationsLogger.info('New notification received...') + notificationsDebug('New notification received...') // Parse const payload = job.data @@ -139,17 +139,17 @@ export async function consumeIncomingNotifications() { throw new UnhandledNotificationError(null, { info: { payload, type } }) } - const notificationLogger = extendLoggerComponent(notificationsLogger, type) - notificationLogger.info('Starting processing notification...') - await Promise.resolve(handler(typedPayload, { job, logger: notificationLogger })) - notificationLogger.info('...successfully processed notification') + const notificationDebug = notificationsDebug.extend(type) + notificationDebug('Starting processing notification...') + await Promise.resolve(handler(typedPayload, { job, debug: notificationDebug })) + notificationDebug('...successfully processed notification') return { status: NotificationJobResultsStatus.Success, type } } catch (e: unknown) { - notificationsLogger.error(e) + notificationsDebug(e) const err = e instanceof Error ? e : new Error('Unexpected notification consumption error') diff --git a/packages/server/modules/previews/index.js b/packages/server/modules/previews/index.js index 0c983fe90..d2677b6df 100644 --- a/packages/server/modules/previews/index.js +++ b/packages/server/modules/previews/index.js @@ -1,6 +1,8 @@ /* istanbul ignore file */ 'use strict' +const debug = require('debug') + const { validateScopes, authorizeResolver } = require('@/modules/shared') const { getStream } = require('../core/services/streams') @@ -17,7 +19,6 @@ const { } = require('./services/previews') const { makeOgImage } = require('./ogImage') -const { moduleLogger, logger } = require('@/logging/logging') const httpErrorImage = (httpErrorCode) => require.resolve(`#/assets/previews/images/preview_${httpErrorCode}.png`) @@ -27,9 +28,9 @@ const previewErrorImage = require.resolve('#/assets/previews/images/preview_erro exports.init = (app) => { if (process.env.DISABLE_PREVIEWS) { - moduleLogger.warn('ðŸ“ļ Object preview module is DISABLED') + debug('speckle:modules')('ðŸ“ļ Object preview module is DISABLED') } else { - moduleLogger.info('ðŸ“ļ Init object preview module') + debug('speckle:modules')('ðŸ“ļ Init object preview module') } const DEFAULT_ANGLE = '0' @@ -63,7 +64,7 @@ exports.init = (app) => { const previewImgId = previewInfo.preview[angle] if (!previewImgId) { - logger.error( + debug('speckle:error')( `Error: Preview angle '${angle}' not found for object ${streamId}:${objectId}` ) return { @@ -74,7 +75,7 @@ exports.init = (app) => { } const previewImg = await getPreviewImage({ previewId: previewImgId }) if (!previewImg) { - logger.error(`Error: Preview image not found: ${previewImgId}`) + debug('speckle:error')(`Error: Preview image not found: ${previewImgId}`) return { type: 'file', file: previewErrorImage diff --git a/packages/server/modules/previews/ogImage.js b/packages/server/modules/previews/ogImage.js index 04d065494..a2365fbd6 100644 --- a/packages/server/modules/previews/ogImage.js +++ b/packages/server/modules/previews/ogImage.js @@ -4,7 +4,6 @@ const sharp = require('sharp') const xmlescape = require('xml-escape') const pixelWidth = require('string-pixel-width') -// const { logger } = require('@/logging/logging') module.exports = { async makeOgImage(previewBufferOrFilename, streamName) { @@ -23,7 +22,7 @@ module.exports = { } title += '...' } - // logger.debug( streamName, pixelWidth( title, { font: 'open sans', size: 48 } ), ' / ', imgWidth - 2 * panelPadding - 305 ) + // console.log( streamName, pixelWidth( title, { font: 'open sans', size: 48 } ), ' / ', imgWidth - 2 * panelPadding - 305 ) const logo = await sharp( require.resolve('#/assets/previews/images/speckle_logo_and_text.png') diff --git a/packages/server/modules/pwdreset/index.ts b/packages/server/modules/pwdreset/index.ts index 933b7b5b7..e41bd4456 100644 --- a/packages/server/modules/pwdreset/index.ts +++ b/packages/server/modules/pwdreset/index.ts @@ -1,10 +1,10 @@ -import { moduleLogger } from '@/logging/logging' import RestSetup from '@/modules/pwdreset/rest' import { SpeckleModule } from '@/modules/shared/helpers/typeHelper' +import debug from 'debug' import { noop } from 'lodash' export const init: SpeckleModule['init'] = (app) => { - moduleLogger.info('â™ŧïļ Init pwd reset module') + debug('speckle:modules')('â™ŧïļ Init pwd reset module') RestSetup(app) } diff --git a/packages/server/modules/serverinvites/index.js b/packages/server/modules/serverinvites/index.js index 5840c7e0b..06f154d52 100644 --- a/packages/server/modules/serverinvites/index.js +++ b/packages/server/modules/serverinvites/index.js @@ -1,9 +1,9 @@ 'use strict' +const debug = require('debug') const { registerOrUpdateScope } = require('@/modules/shared') -const { moduleLogger } = require('@/logging/logging') exports.init = async () => { - moduleLogger.info('💌 Init invites module') + debug('speckle:modules')('💌 Init invites module') const scopes = require('./scopes.js') for (const scope of scopes) { diff --git a/packages/server/modules/shared/services/moduleEventEmitterSetup.ts b/packages/server/modules/shared/services/moduleEventEmitterSetup.ts index 0e98a0892..559c7a068 100644 --- a/packages/server/modules/shared/services/moduleEventEmitterSetup.ts +++ b/packages/server/modules/shared/services/moduleEventEmitterSetup.ts @@ -1,6 +1,5 @@ -import { moduleLogger } from '@/logging/logging' -import { extendLoggerComponent } from '@speckle/shared' import { MaybeAsync } from '@/modules/shared/helpers/typeHelper' +import { modulesDebug } from '@/modules/shared/utils/logger' import EventEmitter from 'eventemitter2' export type ModuleEventEmitterParams = { @@ -27,10 +26,10 @@ export function initializeModuleEventEmitter

>( const { moduleName, namespace } = params const identifier = namespace ? `${moduleName}-${namespace}` : moduleName - const logger = extendLoggerComponent(moduleLogger, identifier, 'events') + const debug = modulesDebug.extend(identifier).extend('events') const errHandler = (e: unknown) => { - logger.error(`Unhandled ${identifier} event emitter error`, e) + debug(`Unhandled ${identifier} event emitter error`, e) } const emitter = new EventEmitter() @@ -77,6 +76,6 @@ export function initializeModuleEventEmitter

>( /** * Debugger scoped to this module event emitter */ - logger + debug } } diff --git a/packages/server/modules/shared/utils/logger.ts b/packages/server/modules/shared/utils/logger.ts new file mode 100644 index 000000000..d81368816 --- /dev/null +++ b/packages/server/modules/shared/utils/logger.ts @@ -0,0 +1,8 @@ +import dbg from 'debug' + +const debug = dbg('speckle') + +export const modulesDebug = debug.extend('modules') +export const notificationsDebug = debug.extend('notifications') +export const cliDebug = debug.extend('cli') +export const errorDebug = debug.extend('error') diff --git a/packages/server/modules/stats/index.js b/packages/server/modules/stats/index.js index 115c115bf..1648c4c12 100644 --- a/packages/server/modules/stats/index.js +++ b/packages/server/modules/stats/index.js @@ -1,8 +1,8 @@ 'use strict' -const { moduleLogger } = require('@/logging/logging') +const debug = require('debug') exports.init = async () => { - moduleLogger.info('📊 Init stats module') + debug('speckle:modules')('📊 Init stats module') // TODO } diff --git a/packages/server/modules/webhooks/index.ts b/packages/server/modules/webhooks/index.ts index 5eb432d18..396eda435 100644 --- a/packages/server/modules/webhooks/index.ts +++ b/packages/server/modules/webhooks/index.ts @@ -1,22 +1,24 @@ import cron from 'node-cron' import { SpeckleModule } from '@/modules/shared/helpers/typeHelper' +import { modulesDebug } from '@/modules/shared/utils/logger' import { scheduleExecution } from '@/modules/core/services/taskScheduler' import { cleanOrphanedWebhookConfigs } from '@/modules/webhooks/services/cleanup' -import { activitiesLogger, moduleLogger } from '@/logging/logging' + +const webhooksDebug = modulesDebug.extend('activities') const scheduleWebhookCleanup = () => { const cronExpression = '0 4 * * 1' return scheduleExecution(cronExpression, 'weeklyWebhookCleanup', async () => { - activitiesLogger.info('Starting weekly webhooks cleanup') + webhooksDebug('Starting weekly webhooks cleanup') await cleanOrphanedWebhookConfigs() - activitiesLogger.info('Finished cleanup') + webhooksDebug('Finished cleanup') }) } let scheduledTask: cron.ScheduledTask | null = null export const init: SpeckleModule['init'] = () => { - moduleLogger.info('ðŸŽĢ Init webhooks module') + modulesDebug('ðŸŽĢ Init webhooks module') scheduledTask = scheduleWebhookCleanup() } diff --git a/packages/server/package.json b/packages/server/package.json index cc39241e2..e2b19d45f 100644 --- a/packages/server/package.json +++ b/packages/server/package.json @@ -17,17 +17,17 @@ "scripts": { "build": "tsc -p ./tsconfig.build.json", "build:watch": "tsc -p ./tsconfig.build.json -w", - "run:watch": "cross-env NODE_ENV=development nodemon ./bin/www --watch ./dist --watch ./assets --watch ./bin/www -e js,ts,graphql,env,gql", + "run:watch": "cross-env NODE_ENV=development DEBUG='speckle:*' nodemon ./bin/www --watch ./dist --watch ./assets --watch ./bin/www -e js,ts,graphql,env,gql", "dev": "concurrently -r \"npm:build:watch\" \"npm:run:watch\"", - "dev:server:test": "cross-env DISABLE_NOTIFICATIONS_CONSUMPTION=true NODE_ENV=test node ./bin/ts-www", + "dev:server:test": "cross-env DISABLE_NOTIFICATIONS_CONSUMPTION=true NODE_ENV=test DEBUG='speckle:*' node ./bin/ts-www", "test": "cross-env NODE_ENV=test mocha", "test:coverage": "cross-env NODE_ENV=test nyc --reporter lcov mocha", "test:report": "yarn test:coverage -- --reporter mocha-junit-reporter --reporter-options mochaFile=reports/test-results.xml", "lint": "eslint . --ext .js,.ts", "lint:tsc": "tsc --noEmit", - "cli": "cross-env NODE_ENV=development ts-node ./modules/cli/index.js", + "cli": "cross-env NODE_ENV=development DEBUG='speckle:*' ts-node ./modules/cli/index.js", "migrate": "yarn cli db migrate", - "migrate:test": "cross-env NODE_ENV=test ts-node ./modules/cli/index.js db migrate", + "migrate:test": "cross-env NODE_ENV=test DEBUG='speckle:*' ts-node ./modules/cli/index.js db migrate", "gqlgen": "graphql-codegen --config codegen.yml" }, "dependencies": { @@ -38,7 +38,6 @@ "@sentry/node": "^6.17.9", "@sentry/tracing": "^6.17.9", "@speckle/shared": "workspace:^", - "@types/pino-http": "^5.8.1", "apollo-server-express": "^3.10.2", "bcrypt": "^5.0.0", "bull": "^4.8.5", @@ -49,6 +48,7 @@ "crypto-random-string": "^3.2.0", "dataloader": "^2.0.0", "dayjs": "^1.11.5", + "debug": "^4.3.1", "dotenv": "^8.2.0", "ejs": "^3.1.8", "eventemitter2": "^6.4.7", @@ -64,6 +64,8 @@ "lodash": "^4.17.21", "mjml": "^4.13.0", "module-alias": "^2.2.2", + "morgan": "^1.10.0", + "morgan-debug": "^2.0.0", "node-cron": "^3.0.2", "node-machine-id": "^1.1.12", "nodemailer": "^6.5.0", @@ -74,8 +76,6 @@ "passport-google-oauth20": "^2.0.0", "pg": "^8.7.3", "pg-query-stream": "^4.2.3", - "pino": "^8.7.0", - "pino-http": "^8.2.1", "prom-client": "^14.0.1", "rate-limiter-flexible": "^2.4.1", "redis": "^3.1.1", diff --git a/packages/server/scripts/duplicateUserMigration.js b/packages/server/scripts/duplicateUserMigration.js index c18946e37..e0c1ce5f4 100644 --- a/packages/server/scripts/duplicateUserMigration.js +++ b/packages/server/scripts/duplicateUserMigration.js @@ -1,5 +1,4 @@ const knex = require('@/db/knex') -const { logger } = require('@/logging/logging') const roles = require('@/modules/core/roles.js') const Users = () => knex('users') @@ -25,10 +24,10 @@ const migrateColumnValue = async (tableName, columnName, oldUser, newUser) => { const query = knex(tableName) .where({ [columnName]: oldUser.id }) .update({ [columnName]: newUser.id }) - logger.info(`${query}`) + console.log(`${query}`) await query } catch (err) { - logger.error(err) + console.log(err) } } @@ -107,7 +106,7 @@ const getDuplicateUsers = async () => { const runMigrations = async () => { const duplicateUsers = await getDuplicateUsers() - logger.info(duplicateUsers) + console.log(duplicateUsers) await Promise.all( duplicateUsers.map(async (userDouble) => { const migrations = createMigrations(userDouble) @@ -126,7 +125,7 @@ const runMigrations = async () => { // await createData() await runMigrations() } catch (err) { - logger.error(err) + console.log(err) } finally { process.exit() } diff --git a/packages/server/scripts/seedUsers.js b/packages/server/scripts/seedUsers.js index 174b6258e..66ed5962b 100644 --- a/packages/server/scripts/seedUsers.js +++ b/packages/server/scripts/seedUsers.js @@ -1,5 +1,4 @@ require('../bootstrap') -const { logger } = require('@/logging/logging') const { createUser } = require('@/modules/core/services/users') const axios = require('axios').default @@ -16,4 +15,4 @@ const main = async () => { await Promise.all(userInputs.map((userInput) => createUser(userInput))) } -main().then(logger.info('created')).catch(logger.error('failed')) +main().then(console.log('created')).catch(console.log('failed')) diff --git a/packages/server/scripts/streamObjects.js b/packages/server/scripts/streamObjects.js index 9d651a976..0272b8f4e 100644 --- a/packages/server/scripts/streamObjects.js +++ b/packages/server/scripts/streamObjects.js @@ -8,7 +8,6 @@ const { fetch } = require('undici') const { init } = require(`@/app`) const request = require('supertest') const { exit } = require('yargs') -const { logger } = require('@/logging/logging') const main = async () => { const testStream = { @@ -54,7 +53,7 @@ const main = async () => { .set('Content-type', 'multipart/form-data') .attach('batch1', Buffer.from(JSON.stringify(objBatch), 'utf8')) - logger.info(uploadRes.status) + console.log(uploadRes.status) const objectIds = objBatch.map((obj) => obj.id) const res = await fetch(`http://localhost:3000/api/getobjects/${testStream.id}`, { @@ -67,8 +66,8 @@ const main = async () => { body: JSON.stringify({ objects: JSON.stringify(objectIds) }) }) const data = await res.body.getReader().read() - logger.info(data) + console.log(data) exit(0) } -main().then(logger.info('created')).catch(logger.error('failed')) +main().then(console.log('created')).catch(console.log('failed')) diff --git a/packages/server/test/helpers.js b/packages/server/test/helpers.js index dc7bfc646..f370e0420 100644 --- a/packages/server/test/helpers.js +++ b/packages/server/test/helpers.js @@ -1,5 +1,4 @@ /* istanbul ignore file */ -// const { logger } = require('@/logging/logging') const crypto = require('crypto') function generateManyObjects(shitTon, noise) { @@ -69,7 +68,7 @@ exports.generateManyObjects = generateManyObjects exports.getAnIdForThisOnePlease = getAnIdForThisOnePlease exports.sleep = (ms) => { - // logger.debug( `\t Sleeping ${ms}ms ` ) + // console.log( `\t Sleeping ${ms}ms ` ) return new Promise((resolve) => { setTimeout(resolve, ms) }) diff --git a/packages/server/test/hooks.js b/packages/server/test/hooks.js index ea0f8ac5c..b10343aeb 100644 --- a/packages/server/test/hooks.js +++ b/packages/server/test/hooks.js @@ -9,7 +9,6 @@ const deepEqualInAnyOrder = require('deep-equal-in-any-order') const knex = require(`@/db/knex`) const { init, startHttp, shutdown } = require(`@/app`) const { default: graphqlChaiPlugin } = require('@/test/plugins/graphql') -const { logger } = require('@/logging/logging') // Register chai plugins chai.use(chaiHttp) @@ -73,14 +72,14 @@ const initializeTestServer = async (server, app) => { exports.mochaHooks = { beforeAll: async () => { - logger.info('running before all') + console.log('running before all') await unlock() await knex.migrate.rollback() await knex.migrate.latest() await init() }, afterAll: async () => { - logger.info('running after all') + console.log('running after all') await unlock() await shutdown() } diff --git a/packages/server/test/notificationsHelper.ts b/packages/server/test/notificationsHelper.ts index 7dc56aef3..5da56f694 100644 --- a/packages/server/test/notificationsHelper.ts +++ b/packages/server/test/notificationsHelper.ts @@ -2,7 +2,6 @@ import { getQueue, NotificationJobResult } from '@/modules/notifications/service import { EventEmitter } from 'events' import { CompletedEventCallback, FailedEventCallback, JobId } from 'bull' import { pick } from 'lodash' -import { logger } from '@/logging/logging' type AckEvent = { result?: NotificationJobResult @@ -143,13 +142,13 @@ export async function debugJobs() { { items: failed, display: 'Failed' } ] - logger.debug('------------- START debugJobs() --------------') + console.log('------------- START debugJobs() --------------') for (const { items, display } of jobCollections) { - logger.debug(`${display}: ` + waiting.length) - logger.debug(`${display} jobs: `) + console.log(`${display}: ` + waiting.length) + console.log(`${display} jobs: `) for (const job of items) { - logger.debug( + console.log( ` - ${JSON.stringify( pick(job, [ 'timestamp', @@ -163,6 +162,6 @@ export async function debugJobs() { ) } } - logger.debug({ workers }) - logger.debug('------------- END debugJobs() --------------') + console.log({ workers }) + console.log('------------- END debugJobs() --------------') } diff --git a/packages/server/type-augmentations/morgan-debug.d.ts b/packages/server/type-augmentations/morgan-debug.d.ts new file mode 100644 index 000000000..b70007c5b --- /dev/null +++ b/packages/server/type-augmentations/morgan-debug.d.ts @@ -0,0 +1,9 @@ +declare module 'morgan-debug' { + declare const func: ( + namespace: string, + format: string, + options: Record + ) => import('express').Handler + + export default func +} diff --git a/packages/shared/package.json b/packages/shared/package.json index 4b10aacef..627884f48 100644 --- a/packages/shared/package.json +++ b/packages/shared/package.json @@ -31,8 +31,7 @@ "3d" ], "dependencies": { - "lodash": "^4.17.0", - "pino": "^8.7.0" + "lodash": "^4.17.0" }, "peerDependencies": { "@tiptap/core": "^2.0.0-beta.176" diff --git a/packages/shared/src/core/index.ts b/packages/shared/src/core/index.ts index 196258d0c..49d97ee06 100644 --- a/packages/shared/src/core/index.ts +++ b/packages/shared/src/core/index.ts @@ -3,5 +3,4 @@ export * from './helpers/batch' export * from './helpers/timeConstants' export * from './helpers/utility' export * from './helpers/utilityTypes' -export * from './observability/logging' export * from './utils/localStorage' diff --git a/packages/shared/src/core/observability/logging.ts b/packages/shared/src/core/observability/logging.ts deleted file mode 100644 index 219e2751f..000000000 --- a/packages/shared/src/core/observability/logging.ts +++ /dev/null @@ -1,23 +0,0 @@ -import pino from 'pino' - -export const logger = pino({ - base: undefined, // Set to undefined to avoid adding pid, hostname properties to each log. - formatters: { - level: (label) => { - return { level: label } - } - }, - level: process.env.LOG_LEVEL || 'info', - timestamp: pino.stdTimeFunctions.isoTime -}) - -export function extendLoggerComponent( - otherChild: pino.Logger, - ...subComponent: string[] -): pino.Logger { - const otherChildBindings = otherChild.bindings() - otherChildBindings.component = [otherChildBindings.component, ...subComponent] - .filter(Boolean) - .join('/') - return otherChild.child(otherChildBindings) -} diff --git a/packages/webhook-service/Dockerfile b/packages/webhook-service/Dockerfile index 03942c495..acac81781 100644 --- a/packages/webhook-service/Dockerfile +++ b/packages/webhook-service/Dockerfile @@ -1,24 +1,3 @@ -FROM node:16.18.0-bullseye-slim as build-stage - -ARG NODE_ENV=production -ENV NODE_ENV=${NODE_ENV} - -WORKDIR /speckle-server - -COPY .yarnrc.yml . -COPY .yarn ./.yarn -COPY package.json yarn.lock ./ - -COPY packages/webhook-service/package.json ./packages/webhook-service/ -COPY packages/shared/package.json ./packages/shared/ - -RUN yarn workspaces focus -A && yarn - -COPY packages/shared ./packages/shared/ -COPY packages/webhook-service/src ./packages/webhook-service/ - -RUN yarn workspaces foreach run build - FROM node:16.18.0-bullseye-slim as node RUN apt-get update && \ @@ -40,13 +19,10 @@ COPY .yarnrc.yml . COPY .yarn ./.yarn COPY package.json yarn.lock ./ -COPY packages/webhook-service/package.json ./packages/webhook-service/ - -COPY --from=build-stage /speckle-server/packages/shared ./packages/shared -COPY --from=build-stage /speckle-server/packages/webhook-service ./packages/webhook-service - -WORKDIR /speckle-server/packages/webhook-service/ +WORKDIR /speckle-server/packages/webhook-service +COPY packages/webhook-service/package.json . RUN yarn workspaces focus --production -ENTRYPOINT [ "tini", "--" ] +COPY packages/webhook-service/src . + CMD ["yarn", "node", "main.js"] diff --git a/packages/webhook-service/package.json b/packages/webhook-service/package.json index 3be08af07..3632a8de1 100644 --- a/packages/webhook-service/package.json +++ b/packages/webhook-service/package.json @@ -21,7 +21,6 @@ "lint": "eslint . --ext .js,.ts" }, "dependencies": { - "@speckle/shared": "workspace:^", "knex": "^2.0.0", "node-fetch": "^2.6.1", "pg": "^8.7.3", diff --git a/packages/webhook-service/src/main.js b/packages/webhook-service/src/main.js index 10f6788b7..2441c8a04 100644 --- a/packages/webhook-service/src/main.js +++ b/packages/webhook-service/src/main.js @@ -3,8 +3,7 @@ const crypto = require('crypto') const knex = require('./knex') const fs = require('fs') -const metrics = require('./observability/prometheusMetrics') -const { logger } = require('./observability/logging') +const metrics = require('./prometheusMetrics') let shouldExit = false const HEALTHCHECK_FILE_PATH = '/tmp/last_successful_query' @@ -58,7 +57,7 @@ async function doTask(task) { .digest('hex') const postHeaders = { 'X-WEBHOOK-SIGNATURE': signature } - logger.info( + console.log( `Callin webhook ${fullPayload.streamId} : ${fullPayload.event.event_name} at ${fullPayload.webhook.url}...` ) const result = await makeNetworkRequest({ @@ -67,7 +66,7 @@ async function doTask(task) { headersData: postHeaders }) - logger.info(` Result: ${JSON.stringify(result)}`) + console.log(` Result: ${JSON.stringify(result)}`) if (!result.success) { throw new Error(result.error) @@ -125,17 +124,17 @@ async function tick() { setTimeout(tick, 10) } catch (err) { metrics.metricOperationErrors.labels('main_loop').inc() - logger.error('Error executing task: ', err) + console.log('Error executing task: ', err) setTimeout(tick, 5000) } } async function main() { - logger.info('Starting Webhook Service...') + console.log('Starting Webhook Service...') process.on('SIGTERM', () => { shouldExit = true - logger.info('Shutting down...') + console.log('Shutting down...') }) metrics.initPrometheusMetrics() diff --git a/packages/webhook-service/src/observability/logging.js b/packages/webhook-service/src/observability/logging.js deleted file mode 100644 index dd1fccbed..000000000 --- a/packages/webhook-service/src/observability/logging.js +++ /dev/null @@ -1,7 +0,0 @@ -const { logger: baseLogger, extendLoggerComponent } = require('@speckle/shared') - -const logger = extendLoggerComponent(baseLogger, 'webhook-service') - -module.exports = { - logger -} diff --git a/packages/webhook-service/src/observability/prometheusMetrics.js b/packages/webhook-service/src/prometheusMetrics.js similarity index 99% rename from packages/webhook-service/src/observability/prometheusMetrics.js rename to packages/webhook-service/src/prometheusMetrics.js index 553540e2a..8b340125d 100644 --- a/packages/webhook-service/src/observability/prometheusMetrics.js +++ b/packages/webhook-service/src/prometheusMetrics.js @@ -3,7 +3,7 @@ const http = require('http') const prometheusClient = require('prom-client') -const knex = require('../knex') +const knex = require('./knex') let metricFree = null let metricUsed = null diff --git a/packages/webhook-service/src/webhookCaller.js b/packages/webhook-service/src/webhookCaller.js index 57846fe09..9e866499b 100644 --- a/packages/webhook-service/src/webhookCaller.js +++ b/packages/webhook-service/src/webhookCaller.js @@ -4,7 +4,7 @@ const dns = require('dns') const isIpPrivate = require('private-ip') const fetch = require('node-fetch') -const { logger } = require('./observability/logging') +const debug = require('debug')('speckle') async function isLocalNetworkUrl(url) { const parsedUrl = new URL(url) @@ -38,7 +38,7 @@ async function makeNetworkRequest({ url, data, headersData }) { const headers = { 'Content-Type': 'application/json' } for (const k in headersData) headers[k] = headersData[k] - logger.info('POST request to:', url) + debug('POST request to:', url) const t0 = Date.now() try { @@ -51,7 +51,7 @@ async function makeNetworkRequest({ url, data, headersData }) { size: 500 * 1000 // 500kb max response size, to accommodate various error responses (defaults to no limit) }).then(async (res) => ({ status: res.status, body: await res.text() })) - // logger.debug( 'Server response:', response ) + //console.log( 'Server response:', response ) const error = httpSuccessCodes.indexOf(response.status) === -1 ? `HTTP response code: ${response.status}` diff --git a/utils/1click_image_scripts/template-docker-compose.yml b/utils/1click_image_scripts/template-docker-compose.yml index 6ef99cd37..ba1ad01c4 100644 --- a/utils/1click_image_scripts/template-docker-compose.yml +++ b/utils/1click_image_scripts/template-docker-compose.yml @@ -55,7 +55,7 @@ services: SESSION_SECRET: 'TODO: change' STRATEGY_LOCAL: 'true' - LOG_LEVEL: 'info' + DEBUG: 'speckle:*' POSTGRES_URL: 'postgres' POSTGRES_USER: 'speckle' @@ -91,7 +91,7 @@ services: command: ['bash', '-c', '/wait && node bin/www'] environment: - LOG_LEVEL: 'info' + DEBUG: 'preview-service:*' PG_CONNECTION_STRING: 'postgres://speckle:speckle@postgres/speckle' WAIT_HOSTS: 'postgres:5432' @@ -100,7 +100,7 @@ services: restart: always command: ['bash', '-c', '/wait && node main.js'] environment: - LOG_LEVEL: 'info' + DEBUG: 'webhook-service:*' PG_CONNECTION_STRING: 'postgres://speckle:speckle@postgres/speckle' WAIT_HOSTS: 'postgres:5432' @@ -109,7 +109,7 @@ services: restart: always command: ['bash', '-c', '/wait && node src/daemon.js'] environment: - LOG_LEVEL: 'info' + DEBUG: 'fileimport-service:*' PG_CONNECTION_STRING: 'postgres://speckle:speckle@postgres/speckle' WAIT_HOSTS: 'postgres:5432' SPECKLE_SERVER_URL: 'http://speckle-server:3000' diff --git a/utils/helm/speckle-server/templates/fileimport_service/deployment.yml b/utils/helm/speckle-server/templates/fileimport_service/deployment.yml index ed334408b..581500383 100644 --- a/utils/helm/speckle-server/templates/fileimport_service/deployment.yml +++ b/utils/helm/speckle-server/templates/fileimport_service/deployment.yml @@ -74,8 +74,8 @@ spec: name: {{ default .Values.secretName .Values.db.connectionString.secretName }} key: {{ default "postgres_url" .Values.db.connectionString.secretKey }} - - name: LOG_LEVEL - value: {{ .Values.fileimport_service.logLevel | quote }} + - name: DEBUG + value: "fileimport-service:*" {{- if .Values.db.useCertificate }} - name: NODE_EXTRA_CA_CERTS diff --git a/utils/helm/speckle-server/templates/preview_service/deployment.yml b/utils/helm/speckle-server/templates/preview_service/deployment.yml index c2008c5c9..94f0e75f7 100644 --- a/utils/helm/speckle-server/templates/preview_service/deployment.yml +++ b/utils/helm/speckle-server/templates/preview_service/deployment.yml @@ -70,8 +70,8 @@ spec: name: {{ default .Values.secretName .Values.db.connectionString.secretName }} key: {{ default "postgres_url" .Values.db.connectionString.secretKey }} - - name: LOG_LEVEL - value: {{ .Values.preview_service.logLevel | quote }} + - name: DEBUG + value: "preview-service:*" {{- if .Values.db.useCertificate }} - name: NODE_EXTRA_CA_CERTS diff --git a/utils/helm/speckle-server/templates/server/deployment.yml b/utils/helm/speckle-server/templates/server/deployment.yml index 2520d03d9..f34f5e465 100644 --- a/utils/helm/speckle-server/templates/server/deployment.yml +++ b/utils/helm/speckle-server/templates/server/deployment.yml @@ -92,8 +92,8 @@ spec: - name: PORT value: {{ include "server.port" $ | quote }} - - name: LOG_LEVEL - value: {{ .Values.server.logLevel }} + - name: DEBUG + value: "speckle:*" - name: SESSION_SECRET valueFrom: diff --git a/utils/helm/speckle-server/templates/webhook_service/deployment.yml b/utils/helm/speckle-server/templates/webhook_service/deployment.yml index 327786389..28c44d6c1 100644 --- a/utils/helm/speckle-server/templates/webhook_service/deployment.yml +++ b/utils/helm/speckle-server/templates/webhook_service/deployment.yml @@ -70,8 +70,8 @@ spec: name: {{ default .Values.secretName .Values.db.connectionString.secretName }} key: {{ default "postgres_url" .Values.db.connectionString.secretKey }} - - name: LOG_LEVEL - value: {{ .Values.webhook_service.logLevel }} + - name: DEBUG + value: "webhook-service:*" {{- if .Values.db.useCertificate }} - name: NODE_EXTRA_CA_CERTS diff --git a/utils/helm/speckle-server/values.yaml b/utils/helm/speckle-server/values.yaml index b51f45c53..bef4a9b45 100644 --- a/utils/helm/speckle-server/values.yaml +++ b/utils/helm/speckle-server/values.yaml @@ -361,9 +361,6 @@ server: ## @param server.replicas The number of instances of the Server pod to be deployed within the cluster. ## replicas: 1 - ## @param server.logLevel The minimum level of logs which will be output. Suitable values are trace, debug, info, warn, error, fatal, or silent - ## - logLevel: 'info' sessionSecret: ## @param server.sessionSecret.secretName The name of the Kubernetes Secret containing the Session secret. This is a unique value (can be generated randomly). This is expected to be provided within the Kubernetes cluster as an opaque Kubernetes Secret. Ref: https://kubernetes.io/docs/concepts/configuration/secret/#opaque-secrets ## @@ -594,9 +591,6 @@ frontend: ## @param frontend.replicas The number of instances of the Frontend pod to be deployed within the cluster. ## replicas: 1 - ## @param frontend.logLevel The minimum level of logs which will be output. Suitable values are trace, debug, info, warn, error, fatal, or silent - ## - logLevel: 'info' requests: ## @param frontend.requests.cpu The CPU that should be available on a node when scheduling this pod. ## ref: https://kubernetes.io/docs/concepts/configuration/manage-resources-containers/ @@ -657,9 +651,6 @@ preview_service: ## @param preview_service.replicas The number of instances of the Preview Service pod to be deployed within the cluster. ## replicas: 1 - ## @param preview_service.logLevel The minimum level of logs which will be output. Suitable values are trace, debug, info, warn, error, fatal, or silent - ## - logLevel: 'info' requests: ## @param preview_service.requests.cpu The CPU that should be available on a node when scheduling this pod. ## ref: https://kubernetes.io/docs/concepts/configuration/manage-resources-containers/ @@ -720,9 +711,6 @@ webhook_service: ## @param webhook_service.replicas The number of instances of the Webhook Service pod to be deployed within the cluster. ## replicas: 1 - ## @param webhook_service.logLevel The minimum level of logs which will be output. Suitable values are trace, debug, info, warn, error, fatal, or silent - ## - logLevel: 'info' requests: ## @param webhook_service.requests.cpu The CPU that should be available on a node when scheduling this pod. ## ref: https://kubernetes.io/docs/concepts/configuration/manage-resources-containers/ @@ -783,9 +771,6 @@ fileimport_service: ## @param fileimport_service.replicas The number of instances of the FileImport Service pod to be deployed within the cluster. ## replicas: 1 - ## @param fileimport_service.logLevel The minimum level of logs which will be output. Suitable values are trace, debug, info, warn, error, fatal, or silent - ## - logLevel: 'info' requests: ## @param fileimport_service.requests.cpu The CPU that should be available on a node when scheduling this pod. ## ref: https://kubernetes.io/docs/concepts/configuration/manage-resources-containers/ @@ -852,9 +837,6 @@ monitoring: ## @param monitoring.replicas The number of instances of the Monitoring pod to be deployed within the cluster. ## replicas: 1 - ## @param monitoring.logLevel The minimum level of logs which will be output. Suitable values are trace, debug, info, warn, error, fatal, or silent - ## - logLevel: 'info' requests: ## @param monitoring.requests.cpu The CPU that should be available on a node when scheduling this pod. ## ref: https://kubernetes.io/docs/concepts/configuration/manage-resources-containers/ @@ -917,9 +899,6 @@ monitoring: helm_test_enabled: true test: - ## @param test.logLevel The minimum level of logs which will be output. Suitable values are trace, debug, info, warn, error, fatal, or silent - ## - logLevel: 'info' requests: ## @param test.requests.cpu The CPU that should be available on a node when scheduling this pod. ## ref: https://kubernetes.io/docs/concepts/configuration/manage-resources-containers/ diff --git a/yarn.lock b/yarn.lock index ac2670f7a..22ce16f27 100644 --- a/yarn.lock +++ b/yarn.lock @@ -4821,7 +4821,6 @@ __metadata: version: 0.0.0-use.local resolution: "@speckle/fileimport-service@workspace:packages/fileimport-service" dependencies: - "@speckle/shared": "workspace:^" aws-sdk: ^2.1075.0 bcrypt: ^5.0.1 cross-env: ^7.0.3 @@ -4956,12 +4955,12 @@ __metadata: dependencies: "@babel/core": ^7.17.5 "@speckle/objectloader": "workspace:^" - "@speckle/shared": "workspace:^" "@speckle/viewer": "workspace:^" babel-loader: ^8.2.2 clean-webpack-plugin: ^4.0.0-alpha.0 cookie-parser: ~1.4.4 crypto: ^1.0.1 + debug: ~2.6.9 eslint: ^8.11.0 eslint-config-prettier: ^8.5.0 express: ~4.16.1 @@ -4970,11 +4969,11 @@ __metadata: http-errors: ~1.6.3 join-images: ^1.1.3 knex: ^2.0.0 + morgan: ~1.9.1 node-fetch: ^2.6.1 nodemon: ^2.0.7 pg: ^8.7.3 pg-query-stream: ^4.2.3 - pino-http: ^8.2.1 prettier: ^2.5.1 prom-client: ^14.0.1 puppeteer: ^13.3.2 @@ -5021,7 +5020,6 @@ __metadata: "@types/module-alias": ^2.0.1 "@types/node-cron": ^3.0.2 "@types/nodemailer": ^6.4.5 - "@types/pino-http": ^5.8.1 "@types/sanitize-html": ^2.6.2 "@types/supertest": ^2.0.12 "@types/verror": ^1.10.6 @@ -5045,6 +5043,7 @@ __metadata: crypto-random-string: ^3.2.0 dataloader: ^2.0.0 dayjs: ^1.11.5 + debug: ^4.3.1 deep-equal-in-any-order: ^1.1.15 dotenv: ^8.2.0 ejs: ^3.1.8 @@ -5067,6 +5066,8 @@ __metadata: mocha-junit-reporter: ^2.0.2 mock-require: ^3.0.3 module-alias: ^2.2.2 + morgan: ^1.10.0 + morgan-debug: ^2.0.0 node-cron: ^3.0.2 node-machine-id: ^1.1.12 node-mocks-http: ^1.12.1 @@ -5080,8 +5081,6 @@ __metadata: passport-google-oauth20: ^2.0.0 pg: ^8.7.3 pg-query-stream: ^4.2.3 - pino: ^8.7.0 - pino-http: ^8.2.1 prettier: ^2.5.1 prom-client: ^14.0.1 rate-limiter-flexible: ^2.4.1 @@ -5117,7 +5116,6 @@ __metadata: eslint: ^8.11.0 eslint-config-prettier: ^8.5.0 lodash: ^4.17.0 - pino: ^8.7.0 rollup: ^2.79.1 rollup-plugin-delete: ^2.0.0 rollup-plugin-typescript2: ^0.34.1 @@ -5183,7 +5181,6 @@ __metadata: version: 0.0.0-use.local resolution: "@speckle/webhook-service@workspace:packages/webhook-service" dependencies: - "@speckle/shared": "workspace:^" cross-env: ^7.0.3 eslint: ^8.11.0 eslint-config-prettier: ^8.5.0 @@ -6062,46 +6059,6 @@ __metadata: languageName: node linkType: hard -"@types/pino-http@npm:^5.8.1": - version: 5.8.1 - resolution: "@types/pino-http@npm:5.8.1" - dependencies: - "@types/pino": 6.3 - checksum: c01bd5fa927218844337c3ba2c9d6c1c5d9f9da7d45368018a5fd404d5b3dd6489f903c33093a722e52f272b5642e41e660812ed7f50e738f2c5465580f43b27 - languageName: node - linkType: hard - -"@types/pino-pretty@npm:*": - version: 4.7.5 - resolution: "@types/pino-pretty@npm:4.7.5" - dependencies: - "@types/node": "*" - "@types/pino": 6.3 - checksum: 80b3e80d1d9b52f015382bbd544206228d0c35eed1a0e1443245568eee01191b5fe916e7821de2922846f267e5d0693f4796562d3bcf24266156d1abc9e2e673 - languageName: node - linkType: hard - -"@types/pino-std-serializers@npm:*": - version: 2.4.1 - resolution: "@types/pino-std-serializers@npm:2.4.1" - dependencies: - "@types/node": "*" - checksum: a156e25882db9aade2576dbe6414379efcdd4fad24211d3f22f20e0cd4bee569215799ee5cd9b2b15282f18461a8a54573ff42bf6bee5d35b72513be2f78bdec - languageName: node - linkType: hard - -"@types/pino@npm:6.3": - version: 6.3.12 - resolution: "@types/pino@npm:6.3.12" - dependencies: - "@types/node": "*" - "@types/pino-pretty": "*" - "@types/pino-std-serializers": "*" - sonic-boom: ^2.1.0 - checksum: 801735146669312d02459781e5180220630eaef643da36dc5a9a97520e7ecc3da7270f31a86fcdcb1dc835073c9143fc628024ba5e3a0ea7cbb86aada4897709 - languageName: node - linkType: hard - "@types/prosemirror-commands@npm:*, @types/prosemirror-commands@npm:^1.0.4": version: 1.0.4 resolution: "@types/prosemirror-commands@npm:1.0.4" @@ -7761,13 +7718,6 @@ __metadata: languageName: node linkType: hard -"atomic-sleep@npm:^1.0.0": - version: 1.0.0 - resolution: "atomic-sleep@npm:1.0.0" - checksum: b95275afb2f80732f22f43a60178430c468906a415a7ff18bcd0feeebc8eec3930b51250aeda91a476062a90e07132b43a1794e8d8ffcf9b650e8139be75fa36 - languageName: node - linkType: hard - "auto-bind@npm:~4.0.0": version: 4.0.0 resolution: "auto-bind@npm:4.0.0" @@ -7970,7 +7920,7 @@ __metadata: languageName: node linkType: hard -"basic-auth@npm:^2.0.1": +"basic-auth@npm:^2.0.1, basic-auth@npm:~2.0.0, basic-auth@npm:~2.0.1": version: 2.0.1 resolution: "basic-auth@npm:2.0.1" dependencies: @@ -8966,13 +8916,6 @@ __metadata: languageName: node linkType: hard -"colorette@npm:^2.0.7": - version: 2.0.19 - resolution: "colorette@npm:2.0.19" - checksum: 888cf5493f781e5fcf54ce4d49e9d7d698f96ea2b2ef67906834bb319a392c667f9ec69f4a10e268d2946d13a9503d2d19b3abaaaf174e3451bfe91fb9d82427 - languageName: node - linkType: hard - "colornames@npm:^1.1.1": version: 1.1.1 resolution: "colornames@npm:1.1.1" @@ -9711,13 +9654,6 @@ __metadata: languageName: node linkType: hard -"dateformat@npm:^4.6.3": - version: 4.6.3 - resolution: "dateformat@npm:4.6.3" - checksum: c3aa0617c0a5b30595122bc8d1bee6276a9221e4d392087b41cbbdf175d9662ae0e50d0d6dcdf45caeac5153c4b5b0844265f8cd2b2245451e3da19e39e3b65d - languageName: node - linkType: hard - "dayjs@npm:^1.11.5": version: 1.11.5 resolution: "dayjs@npm:1.11.5" @@ -9739,7 +9675,7 @@ __metadata: languageName: node linkType: hard -"debug@npm:2.6.9, debug@npm:^2.2.0": +"debug@npm:2.6.9, debug@npm:^2.2.0, debug@npm:~2.6.9": version: 2.6.9 resolution: "debug@npm:2.6.9" dependencies: @@ -11171,7 +11107,7 @@ __metadata: languageName: node linkType: hard -"events@npm:3.3.0, events@npm:^3.2.0, events@npm:^3.3.0": +"events@npm:3.3.0, events@npm:^3.2.0": version: 3.3.0 resolution: "events@npm:3.3.0" checksum: f6f487ad2198aa41d878fa31452f1a3c00958f46e9019286ff4787c84aac329332ab45c9cdc8c445928fc6d7ded294b9e005a7fce9426488518017831b272780 @@ -11425,13 +11361,6 @@ __metadata: languageName: node linkType: hard -"fast-copy@npm:^3.0.0": - version: 3.0.0 - resolution: "fast-copy@npm:3.0.0" - checksum: 58edbc2dcc10e948f5a67fb278dc3d696a65ac68036c3f872fc6c839522b071d3151c7bcea779946f96e01f9a1fdd9b76621532ee32f51000b1403ee673e14ba - languageName: node - linkType: hard - "fast-deep-equal@npm:^3.1.1, fast-deep-equal@npm:^3.1.3": version: 3.1.3 resolution: "fast-deep-equal@npm:3.1.3" @@ -11466,29 +11395,6 @@ __metadata: languageName: node linkType: hard -"fast-redact@npm:^3.1.1": - version: 3.1.2 - resolution: "fast-redact@npm:3.1.2" - checksum: a30eb6b6830333ab213e0def55f46453ca777544dbd3a883016cb590a0eeb95e6fdf546553c1a13d509896bfba889b789991160a6d0996ceb19fce0a02e8b753 - languageName: node - linkType: hard - -"fast-safe-stringify@npm:^2.1.1": - version: 2.1.1 - resolution: "fast-safe-stringify@npm:2.1.1" - checksum: a851cbddc451745662f8f00ddb622d6766f9bd97642dabfd9a405fb0d646d69fc0b9a1243cbf67f5f18a39f40f6fa821737651ff1bceeba06c9992ca2dc5bd3d - languageName: node - linkType: hard - -"fast-url-parser@npm:^1.1.3": - version: 1.1.3 - resolution: "fast-url-parser@npm:1.1.3" - dependencies: - punycode: ^1.3.2 - checksum: 5043d0c4a8d775ff58504d56c096563c11b113e4cb8a2668c6f824a1cd4fb3812e2fdf76537eb24a7ce4ae7def6bd9747da630c617cf2a4b6ce0c42514e4f21c - languageName: node - linkType: hard - "fast-xml-parser@npm:3.19.0": version: 3.19.0 resolution: "fast-xml-parser@npm:3.19.0" @@ -12210,19 +12116,6 @@ __metadata: languageName: node linkType: hard -"glob@npm:^8.0.0, glob@npm:^8.0.3": - version: 8.0.3 - resolution: "glob@npm:8.0.3" - dependencies: - fs.realpath: ^1.0.0 - inflight: ^1.0.4 - inherits: 2 - minimatch: ^5.0.1 - once: ^1.3.0 - checksum: 50bcdea19d8e79d8de5f460b1939ffc2b3299eac28deb502093fdca22a78efebc03e66bf54f0abc3d3d07d8134d19a32850288b7440d77e072aa55f9d33b18c5 - languageName: node - linkType: hard - "glob@npm:^8.0.1": version: 8.0.1 resolution: "glob@npm:8.0.1" @@ -12237,6 +12130,19 @@ __metadata: languageName: node linkType: hard +"glob@npm:^8.0.3": + version: 8.0.3 + resolution: "glob@npm:8.0.3" + dependencies: + fs.realpath: ^1.0.0 + inflight: ^1.0.4 + inherits: 2 + minimatch: ^5.0.1 + once: ^1.3.0 + checksum: 50bcdea19d8e79d8de5f460b1939ffc2b3299eac28deb502093fdca22a78efebc03e66bf54f0abc3d3d07d8134d19a32850288b7440d77e072aa55f9d33b18c5 + languageName: node + linkType: hard + "global-dirs@npm:^0.1.1": version: 0.1.1 resolution: "global-dirs@npm:0.1.1" @@ -12635,16 +12541,6 @@ __metadata: languageName: node linkType: hard -"help-me@npm:^4.0.1": - version: 4.1.0 - resolution: "help-me@npm:4.1.0" - dependencies: - glob: ^8.0.0 - readable-stream: ^3.6.0 - checksum: 521b1b3f8cef500eff7b22fdeb7c5315c93001026dd3dac2450e8f85bfeba5512d51c14e3654fa03527a996130a372e903e3bf88a0e0fea1ec089c947212477e - languageName: node - linkType: hard - "hex-rgb@npm:^4.1.0": version: 4.3.0 resolution: "hex-rgb@npm:4.3.0" @@ -13843,13 +13739,6 @@ __metadata: languageName: node linkType: hard -"joycon@npm:^3.1.1": - version: 3.1.1 - resolution: "joycon@npm:3.1.1" - checksum: 8003c9c3fc79c5c7602b1c7e9f7a2df2e9916f046b0dbad862aa589be78c15734d11beb9fe846f5e06138df22cb2ad29961b6a986ba81c4920ce2b15a7f11067 - languageName: node - linkType: hard - "jquery@npm:3.5": version: 3.5.1 resolution: "jquery@npm:3.5.1" @@ -15564,6 +15453,44 @@ __metadata: languageName: node linkType: hard +"morgan-debug@npm:^2.0.0": + version: 2.0.0 + resolution: "morgan-debug@npm:2.0.0" + dependencies: + through2: ~2.0.1 + peerDependencies: + debug: "*" + morgan: 1.x + checksum: 3519f2a61dfede9c89c31c906da4fc9459ad49664cd562cf5dd3d6c7ce4f4d335064034a843597552a95f9fdfdcc998d365817e30086b84872aa69b151a50ab2 + languageName: node + linkType: hard + +"morgan@npm:^1.10.0": + version: 1.10.0 + resolution: "morgan@npm:1.10.0" + dependencies: + basic-auth: ~2.0.1 + debug: 2.6.9 + depd: ~2.0.0 + on-finished: ~2.3.0 + on-headers: ~1.0.2 + checksum: fb41e226ab5a1abf7e8909e486b387076534716d60207e361acfb5df78b84d703a7b7ea58f3046a9fd0b83d3c94bfabde32323341a1f1b26ce50680abd2ea5dd + languageName: node + linkType: hard + +"morgan@npm:~1.9.1": + version: 1.9.1 + resolution: "morgan@npm:1.9.1" + dependencies: + basic-auth: ~2.0.0 + debug: 2.6.9 + depd: ~1.1.2 + on-finished: ~2.3.0 + on-headers: ~1.0.1 + checksum: 69584328686c2cb2b7b8e69000cdf8f4d02218b6539870dae9266239506a9f1cd212635441899d6c446716462976bdd594251b598ba5cb494ef65420aff1399a + languageName: node + linkType: hard + "ms@npm:2.0.0": version: 2.0.0 resolution: "ms@npm:2.0.0" @@ -16173,13 +16100,6 @@ __metadata: languageName: node linkType: hard -"on-exit-leak-free@npm:^2.1.0": - version: 2.1.0 - resolution: "on-exit-leak-free@npm:2.1.0" - checksum: 7334d98b87b0c89c9b69c747760b21196ff35afdedc4eaf1a0a3a02964463d7f6802481b120e4c8298967c74773ca7b914ab2eb3d9b279010eb7f67ac4960eed - languageName: node - linkType: hard - "on-finished@npm:2.4.1": version: 2.4.1 resolution: "on-finished@npm:2.4.1" @@ -16911,81 +16831,6 @@ __metadata: languageName: node linkType: hard -"pino-abstract-transport@npm:^1.0.0, pino-abstract-transport@npm:v1.0.0": - version: 1.0.0 - resolution: "pino-abstract-transport@npm:1.0.0" - dependencies: - readable-stream: ^4.0.0 - split2: ^4.0.0 - checksum: 05dd0eda52dd99fd204b39fe7b62656744b63e863bc052cdd5105d25f226a236966d0a46e39a1ace4838f6e988c608837ff946d2d0bc92835ca7baa0a3bff8d8 - languageName: node - linkType: hard - -"pino-http@npm:^8.2.1": - version: 8.2.1 - resolution: "pino-http@npm:8.2.1" - dependencies: - fast-url-parser: ^1.1.3 - get-caller-file: ^2.0.5 - pino: ^8.0.0 - pino-std-serializers: ^6.0.0 - process-warning: ^2.0.0 - checksum: 7eb0d72a1986c16ab7ca22f193f9a5d1b26dc6614fddd4f7859065a410d86ab9cbb96a70a5758fa432dd1dd01c02a6e5774bba90f9a2e08ea0c1ac242af7ea0d - languageName: node - linkType: hard - -"pino-pretty@npm:^9.1.1": - version: 9.1.1 - resolution: "pino-pretty@npm:9.1.1" - dependencies: - colorette: ^2.0.7 - dateformat: ^4.6.3 - fast-copy: ^3.0.0 - fast-safe-stringify: ^2.1.1 - help-me: ^4.0.1 - joycon: ^3.1.1 - minimist: ^1.2.6 - on-exit-leak-free: ^2.1.0 - pino-abstract-transport: ^1.0.0 - pump: ^3.0.0 - readable-stream: ^4.0.0 - secure-json-parse: ^2.4.0 - sonic-boom: ^3.0.0 - strip-json-comments: ^3.1.1 - bin: - pino-pretty: bin.js - checksum: c1d148aa0c5f2d1034cf76c0b397cf9725923d16343e9dff78d56b564090c1c86208aae94f1208f0fb936f456eece7eab6264095337540f42d91aaa13e5b8935 - languageName: node - linkType: hard - -"pino-std-serializers@npm:^6.0.0": - version: 6.0.0 - resolution: "pino-std-serializers@npm:6.0.0" - checksum: d9dc1779b3870cdbe00dc2dff15e3931eb126bb144bc9f746d83a2c1174a28e366ed0abe63379dee2fee474e6018a088bfbb2c4b57c1e206601918f5a61e276f - languageName: node - linkType: hard - -"pino@npm:^8.0.0, pino@npm:^8.7.0": - version: 8.7.0 - resolution: "pino@npm:8.7.0" - dependencies: - atomic-sleep: ^1.0.0 - fast-redact: ^3.1.1 - on-exit-leak-free: ^2.1.0 - pino-abstract-transport: v1.0.0 - pino-std-serializers: ^6.0.0 - process-warning: ^2.0.0 - quick-format-unescaped: ^4.0.3 - real-require: ^0.2.0 - safe-stable-stringify: ^2.3.1 - sonic-boom: ^3.1.0 - thread-stream: ^2.0.0 - bin: - pino: bin.js - checksum: 4aa2e320aa88f4a90fd25884ee4e3b9ef7963b3c59c514f3693b5a5c987b112cf3ab4e39a8c51efe32c861f5c058d7cfa7fcda59d964ed878f842fdbc6ab2876 - languageName: node - linkType: hard - "pkg-dir@npm:4.2.0, pkg-dir@npm:^4.1.0, pkg-dir@npm:^4.2.0": version: 4.2.0 resolution: "pkg-dir@npm:4.2.0" @@ -17241,13 +17086,6 @@ __metadata: languageName: node linkType: hard -"process-warning@npm:^2.0.0": - version: 2.0.0 - resolution: "process-warning@npm:2.0.0" - checksum: a2bb299835bced58e63cbe06a8fd6e048a648d3649e81b62c442b63112a3f0a86912e7b1a9c557daca30652232d3b0a7f1972fb87c36334e2a5a6f3d5c4a76c9 - languageName: node - linkType: hard - "process@npm:^0.11.10": version: 0.11.10 resolution: "process@npm:0.11.10" @@ -17452,13 +17290,6 @@ __metadata: languageName: node linkType: hard -"punycode@npm:^1.3.2": - version: 1.4.1 - resolution: "punycode@npm:1.4.1" - checksum: fa6e698cb53db45e4628559e557ddaf554103d2a96a1d62892c8f4032cd3bc8871796cae9eabc1bc700e2b6677611521ce5bb1d9a27700086039965d0cf34518 - languageName: node - linkType: hard - "punycode@npm:^2.1.0, punycode@npm:^2.1.1": version: 2.1.1 resolution: "punycode@npm:2.1.1" @@ -17555,13 +17386,6 @@ __metadata: languageName: node linkType: hard -"quick-format-unescaped@npm:^4.0.3": - version: 4.0.4 - resolution: "quick-format-unescaped@npm:4.0.4" - checksum: 7bc32b99354a1aa46c089d2a82b63489961002bb1d654cee3e6d2d8778197b68c2d854fd23d8422436ee1fdfd0abaddc4d4da120afe700ade68bd357815b26fd - languageName: node - linkType: hard - "rainbowvis.js@npm:^1.0.1": version: 1.0.1 resolution: "rainbowvis.js@npm:1.0.1" @@ -17665,7 +17489,7 @@ __metadata: languageName: node linkType: hard -"readable-stream@npm:^2.0.1, readable-stream@npm:^2.0.6, readable-stream@npm:^2.3.5": +"readable-stream@npm:^2.0.1, readable-stream@npm:^2.0.6, readable-stream@npm:^2.3.5, readable-stream@npm:~2.3.6": version: 2.3.7 resolution: "readable-stream@npm:2.3.7" dependencies: @@ -17691,18 +17515,6 @@ __metadata: languageName: node linkType: hard -"readable-stream@npm:^4.0.0": - version: 4.2.0 - resolution: "readable-stream@npm:4.2.0" - dependencies: - abort-controller: ^3.0.0 - buffer: ^6.0.3 - events: ^3.3.0 - process: ^0.11.10 - checksum: aa8447f781e6df90af78f6b0b9b9a77da2816dcf6c8220e7021c4de36e04f8129fed7ead81eac0baad2f42098209f9e7d7cd43169e1c156efcd2613828a37439 - languageName: node - linkType: hard - "readable-web-to-node-stream@npm:^3.0.0": version: 3.0.2 resolution: "readable-web-to-node-stream@npm:3.0.2" @@ -17721,13 +17533,6 @@ __metadata: languageName: node linkType: hard -"real-require@npm:^0.2.0": - version: 0.2.0 - resolution: "real-require@npm:0.2.0" - checksum: fa060f19f2f447adf678d1376928c76379dce5f72bd334da301685ca6cdcb7b11356813332cc243c88470796bc2e2b1e2917fc10df9143dd93c2ea608694971d - languageName: node - linkType: hard - "rechoir@npm:^0.7.0": version: 0.7.1 resolution: "rechoir@npm:0.7.1" @@ -18378,7 +18183,6 @@ __metadata: eslint-config-prettier: ^8.5.0 husky: ^7.0.4 lint-staged: ^12.3.7 - pino-pretty: ^9.1.1 prettier: ^2.5.1 ts-node: ^10.9.1 tsconfig-paths: ^4.0.0 @@ -18447,13 +18251,6 @@ __metadata: languageName: node linkType: hard -"safe-stable-stringify@npm:^2.3.1": - version: 2.4.1 - resolution: "safe-stable-stringify@npm:2.4.1" - checksum: d8e505c462031301040605a4836ca25b52a1744eff01b0939b4d43136638fb8e88e0cec3d3ab6ab8e26f501086e6ba6bf34b228f57bf2ac56cb8d4061355d723 - languageName: node - linkType: hard - "safer-buffer@npm:>= 2.1.2 < 3, safer-buffer@npm:>= 2.1.2 < 3.0.0, safer-buffer@npm:^2.0.2, safer-buffer@npm:^2.1.0, safer-buffer@npm:~2.1.0": version: 2.1.2 resolution: "safer-buffer@npm:2.1.2" @@ -18548,13 +18345,6 @@ __metadata: languageName: node linkType: hard -"secure-json-parse@npm:^2.4.0": - version: 2.5.0 - resolution: "secure-json-parse@npm:2.5.0" - checksum: 84147a32615ce0d93d2fbba60cde85ae362f45cc948ea134e4d6d1e678bb4b7f3a5ce9b9692ed052baefeb2e1c8ba183b34920390e6a089925b97b0d8f7ab064 - languageName: node - linkType: hard - "select-hose@npm:^2.0.0": version: 2.0.0 resolution: "select-hose@npm:2.0.0" @@ -19028,24 +18818,6 @@ __metadata: languageName: node linkType: hard -"sonic-boom@npm:^2.1.0": - version: 2.8.0 - resolution: "sonic-boom@npm:2.8.0" - dependencies: - atomic-sleep: ^1.0.0 - checksum: c7f9c89f931d7f60f8e0741551a729f0d81e6dc407a99420fc847a9a4c25af048a615b1188ab3c4f1fb3708fe4904973ddab6ebcc8ed5b78b50ab81a99045910 - languageName: node - linkType: hard - -"sonic-boom@npm:^3.0.0, sonic-boom@npm:^3.1.0": - version: 3.2.0 - resolution: "sonic-boom@npm:3.2.0" - dependencies: - atomic-sleep: ^1.0.0 - checksum: 526669b78e0ac3bcbe2a53e5ac8960d3b25e61d8e6a46eaed5a0c46d7212c5f638bb136236870babedfcb626063711ba8f81e538f88b79e6a90a5b2ff71943b4 - languageName: node - linkType: hard - "sort-any@npm:^2.0.0": version: 2.0.0 resolution: "sort-any@npm:2.0.0" @@ -19155,7 +18927,7 @@ __metadata: languageName: node linkType: hard -"split2@npm:^4.0.0, split2@npm:^4.1.0": +"split2@npm:^4.1.0": version: 4.1.0 resolution: "split2@npm:4.1.0" checksum: ec581597cb74c13cdfb5e2047543dd40cb1e8e9803c7b1e0c29ede05f2b4f049b2d6e7f2788a225d544549375719658b8f38e9366364dec35dc7a12edfda5ee5 @@ -19759,15 +19531,6 @@ __metadata: languageName: node linkType: hard -"thread-stream@npm:^2.0.0": - version: 2.2.0 - resolution: "thread-stream@npm:2.2.0" - dependencies: - real-require: ^0.2.0 - checksum: b7f0ee166ed17ac54700a0b6fc291967c97785b458ff54efe5431a7281bb52d1163e6ec550a614f2a47f0f02de5b35a342bd5acd215af23030938c64859152b2 - languageName: node - linkType: hard - "three-mesh-bvh@npm:0.5.17": version: 0.5.17 resolution: "three-mesh-bvh@npm:0.5.17" @@ -19791,6 +19554,16 @@ __metadata: languageName: node linkType: hard +"through2@npm:~2.0.1": + version: 2.0.5 + resolution: "through2@npm:2.0.5" + dependencies: + readable-stream: ~2.3.6 + xtend: ~4.0.1 + checksum: beb0f338aa2931e5660ec7bf3ad949e6d2e068c31f4737b9525e5201b824ac40cac6a337224856b56bd1ddd866334bbfb92a9f57cd6f66bc3f18d3d86fc0fe50 + languageName: node + linkType: hard + "through@npm:^2.3.6, through@npm:^2.3.8": version: 2.3.8 resolution: "through@npm:2.3.8" @@ -21447,7 +21220,7 @@ __metadata: languageName: node linkType: hard -"xtend@npm:^4.0.0": +"xtend@npm:^4.0.0, xtend@npm:~4.0.1": version: 4.0.2 resolution: "xtend@npm:4.0.2" checksum: ac5dfa738b21f6e7f0dd6e65e1b3155036d68104e67e5d5d1bde74892e327d7e5636a076f625599dc394330a731861e87343ff184b0047fef1360a7ec0a5a36a