diff --git a/docker-compose-speckle.yml b/docker-compose-speckle.yml index 8cbf2aa8a..af44054ac 100644 --- a/docker-compose-speckle.yml +++ b/docker-compose-speckle.yml @@ -25,7 +25,7 @@ services: SESSION_SECRET: 'TODO:Replace' STRATEGY_LOCAL: 'true' - DEBUG: 'speckle:*' + LOG_LEVEL: 'info' POSTGRES_URL: 'postgres' POSTGRES_USER: 'speckle' @@ -51,7 +51,7 @@ services: mem_limit: '3000m' memswap_limit: '3000m' environment: - DEBUG: 'preview-service:*' + LOG_LEVEL: 'info' PG_CONNECTION_STRING: 'postgres://speckle:speckle@postgres/speckle' webhook-service: @@ -61,7 +61,7 @@ services: image: speckle/speckle-webhook-service:local restart: always environment: - DEBUG: 'webhook-service:*' + LOG_LEVEL: 'info' PG_CONNECTION_STRING: 'postgres://speckle:speckle@postgres/speckle' fileimport-service: @@ -71,6 +71,6 @@ services: image: speckle/speckle-fileimport-service:local restart: always environment: - DEBUG: 'fileimport-service:*' + LOG_LEVEL: 'info' PG_CONNECTION_STRING: 'postgres://speckle:speckle@postgres/speckle' SPECKLE_SERVER_URL: 'http://speckle-server:3000' diff --git a/package.json b/package.json index 5481a005f..ce977519c 100644 --- a/package.json +++ b/package.json @@ -39,6 +39,7 @@ "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 3660d2e95..2c30e9241 100644 --- a/packages/fileimport-service/Dockerfile +++ b/packages/fileimport-service/Dockerfile @@ -1,3 +1,24 @@ +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 && \ @@ -9,6 +30,9 @@ 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 @@ -21,13 +45,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 -COPY packages/fileimport-service/requirements.txt ./ -RUN pip install --no-cache-dir -r requirements.txt - -COPY packages/fileimport-service . - +ENTRYPOINT [ "tini", "--" ] 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 8eb344e90..ea27437c5 100644 --- a/packages/fileimport-service/ifc/import_file.js +++ b/packages/fileimport-service/ifc/import_file.js @@ -1,4 +1,5 @@ const fs = require('fs') +const { logger } = require('../observability/logging') const TMP_RESULTS_PATH = '/tmp/import_result.json' @@ -10,7 +11,7 @@ async function main() { const [filePath, userId, streamId, branchName, commitMessage, fileId] = cmdArgs // eslint-disable-next-line no-console - console.log('ARGV: ', filePath, userId, streamId, branchName, commitMessage) + logger.info('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 b72ef9ae9..a900f21ef 100644 --- a/packages/fileimport-service/ifc/index.js +++ b/packages/fileimport-service/ifc/index.js @@ -2,6 +2,7 @@ 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, @@ -61,8 +62,7 @@ async function parseAndCreateCommit({ }) const json = await response.json() - // eslint-disable-next-line no-console - console.log(json) + logger.info(json) return json.data.commitCreate } diff --git a/packages/fileimport-service/ifc/parser.js b/packages/fileimport-service/ifc/parser.js index 5cc8a4946..d2c6f4d1f 100644 --- a/packages/fileimport-service/ifc/parser.js +++ b/packages/fileimport-service/ifc/parser.js @@ -1,6 +1,7 @@ /* 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 { @@ -29,7 +30,7 @@ module.exports = class IFCParser { // as reference objects in this.productGeo this.productGeo = {} await this.createGeometries() - console.log(`Geometries created: ${Object.keys(this.productGeo).length} meshes.`) + logger.info(`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 @@ -133,7 +134,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. - // console.log( `Traversing element ${element.expressID}; Recurse: ${recursive}; Stack ${depth}` ) + // logger.debug( `Traversing element ${element.expressID}; Recurse: ${recursive}; Stack ${depth}` ) // Traverse all key/value pairs first. for (const key of Object.keys(element)) { @@ -252,7 +253,7 @@ module.exports = class IFCParser { element.propertySets || element.typeProps ) { - console.log( + logger.info( `${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 new file mode 100644 index 000000000..325cc2170 --- /dev/null +++ b/packages/fileimport-service/observability/logging.js @@ -0,0 +1,8 @@ +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 b0503bc32..1e0b874df 100644 --- a/packages/fileimport-service/package.json +++ b/packages/fileimport-service/package.json @@ -23,6 +23,7 @@ "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 0ba7ac3a2..fe67ca21f 100644 --- a/packages/fileimport-service/src/daemon.js +++ b/packages/fileimport-service/src/daemon.js @@ -16,6 +16,7 @@ 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' @@ -56,7 +57,7 @@ async function doTask(task) { const metricDurationEnd = metricDuration.startTimer() try { - console.log('Doing task ', task) + logger.info('Doing task ', task) const info = await FileUploads().where({ id: task.id }).first() if (!info) { throw new Error('Internal error: DB inconsistent') @@ -162,7 +163,7 @@ async function doTask(task) { [commitId, task.id] ) } catch (err) { - console.log('Error: ', err) + logger.error(err) await knex.raw( ` UPDATE file_uploads @@ -189,21 +190,21 @@ async function doTask(task) { function runProcessWithTimeout(cmd, cmdArgs, extraEnv, timeoutMs) { return new Promise((resolve, reject) => { - console.log(`Starting process: ${cmd} ${cmdArgs}`) + logger.info(`Starting process: ${cmd} ${cmdArgs}`) const childProc = spawn(cmd, cmdArgs, { env: { ...process.env, ...extraEnv } }) childProc.stdout.on('data', (data) => { - console.log('Parser: ', data.toString()) + logger.info('Parser: ', data.toString()) }) childProc.stderr.on('data', (data) => { - console.error('Parser: ', data.toString()) + logger.error('Parser: ', data.toString()) }) let timedOut = false const timeout = setTimeout(() => { - console.log('Process timeout. Killing process...') + logger.error('Process timeout. Killing process...') timedOut = true childProc.kill(9) @@ -211,7 +212,7 @@ function runProcessWithTimeout(cmd, cmdArgs, extraEnv, timeoutMs) { }, timeoutMs) childProc.on('close', (code) => { - console.log(`Process exited with code ${code}`) + logger.info(`Process exited with code ${code}`) if (timedOut) return // ignore `close` calls after killing (the promise was already rejected) @@ -247,18 +248,18 @@ async function tick() { setTimeout(tick, 10) } catch (err) { metricOperationErrors.labels('main_loop').inc() - console.log('Error executing task: ', err) + logger.error('Error executing task: ', err) setTimeout(tick, 5000) } } async function main() { - console.log('Starting FileUploads Service...') + logger.info('Starting FileUploads Service...') initPrometheusMetrics() process.on('SIGTERM', () => { shouldExit = true - console.log('Shutting down...') + logger.info('Shutting down...') }) tick() diff --git a/packages/fileimport-service/src/objDependencies.js b/packages/fileimport-service/src/objDependencies.js index 5aea8d7a1..0ab3cc5bd 100644 --- a/packages/fileimport-service/src/objDependencies.js +++ b/packages/fileimport-service/src/objDependencies.js @@ -6,6 +6,7 @@ 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 = [] @@ -25,7 +26,7 @@ const getReferencedMtlFiles = async ({ objFilePath }) => { await events.once(rl, 'close') } catch (err) { - console.error(`Error getting dependencies for file ${objFilePath}: ${err}`) + logger.error(`Error getting dependencies for file ${objFilePath}: ${err}`) } return mtlFiles } @@ -34,17 +35,17 @@ module.exports = { async downloadDependencies({ objFilePath, streamId, destinationDir, token }) { const dependencies = await getReferencedMtlFiles({ objFilePath }) - console.log(`Obj file depends on ${dependencies}`) + logger.info(`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) { - console.log(`OBJ dependency file not found in stream: ${mtlFile}`) + logger.info(`OBJ dependency file not found in stream: ${mtlFile}`) continue } if (!isValidFilename(mtlFile)) { - console.log(`Invalid filename reference in OBJ dependencies: ${mtlFile}`) + logger.warn(`Invalid filename reference in OBJ dependencies: ${mtlFile}`) continue } await downloadFile({ diff --git a/packages/preview-service/Makefile b/packages/preview-service/Makefile index fb81b1091..821eed5b2 100644 --- a/packages/preview-service/Makefile +++ b/packages/preview-service/Makefile @@ -5,17 +5,15 @@ 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 DEBUG="preview-service:*" -e PG_CONNECTION_STRING="postgres://speckle:speckle@localhost/speckle" small-preview-service bash + docker run -it --rm --net=host -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 66a1b4dc0..5af234455 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(logger('dev')) +app.use(LoggingExpressMiddleware) 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 207a1224b..b2b62ceec 100644 --- a/packages/preview-service/bg_service/index.js +++ b/packages/preview-service/bg_service/index.js @@ -6,6 +6,7 @@ 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 @@ -130,22 +131,22 @@ async function tick() { setTimeout(tick, 10) } catch (err) { metrics.metricOperationErrors.labels('main_loop').inc() - console.log('Error executing task: ', err) + logger.error('Error executing task: ', err) setTimeout(tick, 5000) } } async function startPreviewService() { - console.log('ðŸ“ļ Started Preview Service') + logger.info('ðŸ“ļ Started Preview Service') process.on('SIGTERM', () => { shouldExit = true - console.log('Shutting down...') + logger.info('Shutting down...') }) process.on('SIGINT', () => { shouldExit = true - console.log('Shutting down...') + logger.info('Shutting down...') }) metrics.initPrometheusMetrics() diff --git a/packages/preview-service/bin/www b/packages/preview-service/bin/www index 2af055ab1..5d09cea64 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': - console.error(bind + ' requires elevated privileges') + logger.error(bind + ' requires elevated privileges') process.exit(1) break case 'EADDRINUSE': - console.error(bind + ' is already in use') + logger.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 - debug('Listening on ' + bind) + serverLogger.info('Listening on ' + bind) startPreviewService() } diff --git a/packages/preview-service/observability/expressLogging.js b/packages/preview-service/observability/expressLogging.js new file mode 100644 index 000000000..49cd5fac1 --- /dev/null +++ b/packages/preview-service/observability/expressLogging.js @@ -0,0 +1,7 @@ +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 new file mode 100644 index 000000000..0df5dc2c1 --- /dev/null +++ b/packages/preview-service/observability/logging.js @@ -0,0 +1,10 @@ +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 0737ff9b1..4907352c4 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": "DEBUG='preview-service:*' nodemon --trace-deprecation ./bin/www", + "dev": "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 ad52ee7d5..193137377 100644 --- a/packages/preview-service/render_page/src/app.js +++ b/packages/preview-service/render_page/src/app.js @@ -1,9 +1,10 @@ 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 => console.log( args ) ) +// v.on( ViewerEvent.LoadProgress, args => logger.debug( 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 805d38103..f6d0f2688 100644 --- a/packages/preview-service/routes/api.js +++ b/packages/preview-service/routes/api.js @@ -5,6 +5,7 @@ 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() @@ -34,11 +35,11 @@ router.post('/getobjects/:streamId', async (req, res) => { res, (err) => { if (err) { - console.log( + logger.error( `Error streaming objects from stream ${req.params.streamId}: ${err}` ) } else { - console.log( + logger.error( `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 653cac06c..6eb131389 100644 --- a/packages/preview-service/routes/objects.js +++ b/packages/preview-service/routes/objects.js @@ -5,6 +5,7 @@ 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() @@ -44,11 +45,11 @@ router.get('/:streamId/:objectId', async function (req, res) { res, (err) => { if (err) { - console.log( + logger.error( `Error downloading object ${req.params.objectId} from stream ${req.params.streamId}: ${err}` ) } else { - console.log( + logger.info( `Downloaded object ${req.params.objectId} from stream ${ req.params.streamId } (size: ${gzipStream.bytesWritten / 1000000} MB)` @@ -68,7 +69,7 @@ router.get('/:streamId/:objectId/single', async (req, res) => { return res.status(404).send('Failed to find object.') } - console.log( + logger.info( `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 fb050851f..06fd938a4 100644 --- a/packages/preview-service/routes/preview.js +++ b/packages/preview-service/routes/preview.js @@ -4,6 +4,7 @@ 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) => @@ -66,7 +67,7 @@ async function getScreenshot(objectUrl) { const wrapperPromise = (async () => { await page.goto('http://127.0.0.1:3001/render/') - console.log('Page loaded') + logger.info('Page loaded') // Handle page crash (oom?) page.on('error', (err) => { @@ -79,7 +80,7 @@ async function getScreenshot(objectUrl) { try { ret = await wrapperPromise } catch (err) { - console.log(`Error generating preview for ${objectUrl}: ${err}`) + logger.error(`Error generating preview for ${objectUrl}: ${err}`) ret = { error: err } @@ -92,7 +93,7 @@ async function getScreenshot(objectUrl) { return null } - console.log( + logger.info( `Generated preview for ${objectUrl} in ${ret.duration} sec with ${ ret.mem.total / 1000000 } MB of memory` @@ -147,7 +148,7 @@ router.get('/:streamId/:objectId', async function (req, res) { } */ - console.log(objectUrl) + logger.info(objectUrl) const scr = await getScreenshot(objectUrl) diff --git a/packages/server/.vscode/launch.json b/packages/server/.vscode/launch.json index 888db5ced..1604022e0 100644 --- a/packages/server/.vscode/launch.json +++ b/packages/server/.vscode/launch.json @@ -62,10 +62,6 @@ "--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 1a6a61cfd..4ee2666c0 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(logger('speckle', 'dev', {})) + app.use(LoggingExpressMiddleware) } if (process.env.COMPRESSION) { @@ -273,8 +273,8 @@ export async function startHttp( // app.use('/', frontendProxy) app.use(await createFrontendProxy()) - debug('speckle:startup')('âœĻ Proxying frontend (dev mode):') - debug('speckle:startup')(`👉 main application: http://localhost:${port}/`) + startupLogger.info('âœĻ Proxying frontend (dev mode):') + startupLogger.info(`👉 main application: http://localhost:${port}/`) } // Production mode @@ -291,13 +291,13 @@ export async function startHttp( signals: ['SIGTERM', 'SIGINT'], timeout: 5 * 60 * 1000, beforeShutdown: async () => { - debug('speckle:shutdown')('Shutting down (signal received)...') + shutdownLogger.info('Shutting down (signal received)...') }, onSignal: async () => { await shutdown() }, onShutdown: () => { - debug('speckle:shutdown')('Shutdown completed') + shutdownLogger.info('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 - debug('speckle:startup')( + startupLogger.info( `🚀 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 c6f875ee5..06f0759e6 100755 --- a/packages/server/bin/ts-www +++ b/packages/server/bin/ts-www @@ -7,11 +7,11 @@ */ require('ts-node/register') -const debug = require('debug')('speckle:www') +const { logger } = require('../logging/logging') const { init, startHttp } = require('../app') init() .then(({ app, server }) => startHttp(server, app)) - .catch((err) => debug(err)) + .catch((err) => logger.error(err)) // ðŸ’Ĩ diff --git a/packages/server/bin/www b/packages/server/bin/www index 34aa3831a..0df320052 100755 --- a/packages/server/bin/www +++ b/packages/server/bin/www @@ -1,11 +1,11 @@ #!/usr/bin/env node 'use strict' -const debug = require('debug')('speckle:www') +const { logger } = require('../dist/logging/logging') const { init, startHttp } = require('../dist/app') init() .then(({ app, server }) => startHttp(server, app)) - .catch((err) => debug(err)) + .catch((err) => logger.error(err)) // ðŸ’Ĩ diff --git a/packages/server/bootstrap.js b/packages/server/bootstrap.js index a8baa809d..10eaa7857 100644 --- a/packages/server/bootstrap.js +++ b/packages/server/bootstrap.js @@ -24,6 +24,7 @@ const { getApolloServerVersion, getServerVersion } = require('./modules/shared/helpers/envHelper') +const { logger } = require('@/logging/logging') if (isApolloMonitoringEnabled() && !getApolloServerVersion()) { process.env.APOLLO_SERVER_USER_VERSION = getServerVersion() @@ -37,7 +38,7 @@ if (isTestEnv()) { const e = new Error( 'Attempting to run tests without an .env.test file properly set up! Check readme!' ) - console.error(e) + logger.error(e) process.exit(1) } } diff --git a/packages/server/db/knex.js b/packages/server/db/knex.js index be5bb47af..99032d4ac 100644 --- a/packages/server/db/knex.js +++ b/packages/server/db/knex.js @@ -3,6 +3,7 @@ const env = process.env.NODE_ENV || 'development' const configs = require('@/knexfile.js') +const { dbStartupLogger } = require('@/logging/logging') const config = configs[env] config.log = { @@ -15,9 +16,7 @@ config.log = { } } -const debug = require('debug') - -debug('speckle:db-startup')(`Loaded knex conf for ${env}`) +dbStartupLogger.info(`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 021324d3e..218853cb8 100644 --- a/packages/server/logging/apolloPlugin.js +++ b/packages/server/logging/apolloPlugin.js @@ -1,4 +1,5 @@ /* istanbul ignore file */ +// const { logger } = require('@/logging/logging') const Sentry = require('@sentry/node') const { ApolloError } = require('apollo-server-express') const prometheusClient = require('prom-client') @@ -27,7 +28,7 @@ module.exports = { try { const actionName = `${ctx.operation.operation} ${ctx.operation.selectionSet.selections[0].name.value}` metricCallCount.labels(actionName).inc() - // console.log( actionName ) + // logger.debug(actionName) } catch (e) { Sentry.captureException(e) } diff --git a/packages/server/logging/errorLogging.js b/packages/server/logging/errorLogging.js index 06209f90b..a88536f5f 100644 --- a/packages/server/logging/errorLogging.js +++ b/packages/server/logging/errorLogging.js @@ -1,4 +1,5 @@ /* istanbul ignore file */ +const { logger } = require('@/logging/logging') const prometheusClient = require('prom-client') let metricErrorCount = null @@ -13,7 +14,9 @@ module.exports = { }) } - console.log(`Error when handling ${req.originalUrl} from ${req.ip}: ${err.message}`) + logger.error( + `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 new file mode 100644 index 000000000..2f9ae6ba6 --- /dev/null +++ b/packages/server/logging/expressLogging.ts @@ -0,0 +1,7 @@ +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 new file mode 100644 index 000000000..3d529ef1c --- /dev/null +++ b/packages/server/logging/logging.ts @@ -0,0 +1,18 @@ +// 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 0c2775776..ef6ff86f1 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) { - modulesDebug('🔐 Init access request module') + moduleLogger.info('🔐 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 98a77906d..96289f757 100644 --- a/packages/server/modules/activitystream/index.ts +++ b/packages/server/modules/activitystream/index.ts @@ -2,11 +2,9 @@ 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' - -const activitiesDebug = modulesDebug.extend('activities') +import { activitiesLogger, moduleLogger } from '@/logging/logging' let scheduledTask: cron.ScheduledTask | null = null @@ -25,7 +23,7 @@ const scheduleWeeklyActivityNotifications = () => { 'weeklyActivityNotification', //task should be locked for 10 minutes async (now: Date) => { - activitiesDebug('Sending weekly activity digests notifications.') + activitiesLogger.info('Sending weekly activity digests notifications.') const end = now const start = new Date(end.getTime()) start.setDate(start.getDate() - numberOfDays) @@ -37,7 +35,7 @@ const scheduleWeeklyActivityNotifications = () => { const activityModule: SpeckleModule = { init: async (_, isInitial) => { - modulesDebug('ðŸĪš Init activity module') + moduleLogger.info('ðŸĪš 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 77d06cf25..0a01e3fbc 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 debug = require('debug') +const { moduleLogger } = require('@/logging/logging') exports.init = (app) => { - debug('speckle:modules')('💅 Init graphql api explorer module') + moduleLogger.info('💅 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 a86d8c41a..6512ed3de 100644 --- a/packages/server/modules/auth/defaultApps.js +++ b/packages/server/modules/auth/defaultApps.js @@ -1,5 +1,4 @@ 'use strict' -const debug = require('debug') const knex = require('@/db/knex') const Scopes = () => knex('scopes') const Apps = () => knex('server_apps') @@ -8,6 +7,7 @@ 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( '*' ) - // console.log( allScopes.length ) + // logger.debug( 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) { - console.log(e) + logger.error(e) } } @@ -57,7 +57,7 @@ async function updateDefaultApp(app, existingApp) { let affectedTokenIds = [] if (newScopes.length || removedScopes.length) { - debug('speckle:modules')(`🔑 Updating default app ${app.name}`) + moduleLogger.info(`🔑 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 119260e5e..25c84d448 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) => { - debug('speckle:modules')('🔑 Init auth module') + moduleLogger.info('🔑 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 391beb280..a5c1c7e05 100644 --- a/packages/server/modules/auth/rest/index.js +++ b/packages/server/modules/auth/rest/index.js @@ -1,5 +1,4 @@ 'use strict' -const debug = require('debug') const cors = require('cors') const sentry = require(`@/logging/sentryHelper`) @@ -15,6 +14,7 @@ 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 }) - debug('speckle:error')(err) + moduleLogger.error(err) if ( err instanceof InvalidAccessCodeRequestError || @@ -97,6 +97,7 @@ module.exports = (app) => { return res.send(authResponse) } catch (err) { sentry({ err }) + moduleLogger.error(err) return res.status(401).send({ err: err.message }) } }) @@ -117,7 +118,8 @@ module.exports = (app) => { return res.status(200).send({ message: 'You have logged out.' }) } catch (err) { sentry({ err }) - return res.status(400).send({ err: err.message }) + moduleLogger.error(err) + return res.status(400).send('Something went wrong while trying to logout.') } }) } diff --git a/packages/server/modules/auth/services/apps.js b/packages/server/modules/auth/services/apps.js index f4c3bde80..f9b0d707f 100644 --- a/packages/server/modules/auth/services/apps.js +++ b/packages/server/modules/auth/services/apps.js @@ -4,6 +4,7 @@ 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') @@ -129,7 +130,7 @@ module.exports = { await module.exports.revokeExistingAppCredentials({ appId: app.id }) if (app.scopes) { - // console.log( app.scopes, app.id ) + logger.debug(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 324bc0a1b..863f946fa 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 debug = require('debug') +const { logger } = require('@/logging/logging') /** * Wrapper for passport.authenticate that handles success & failure scenarios correctly @@ -11,7 +11,7 @@ const debug = require('debug') function passportAuthenticate(strategy, options = undefined) { return (req, res, next) => passport.authenticate(strategy, options, (err, user, info) => { - if (err) debug('speckle:error')(err) + if (err) logger.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 38d4ddb9f..2a57bebf4 100644 --- a/packages/server/modules/auth/strategies.js +++ b/packages/server/modules/auth/strategies.js @@ -8,6 +8,7 @@ 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 @@ -69,6 +70,7 @@ 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 78e18f7f2..856567d22 100644 --- a/packages/server/modules/auth/strategies/azure-ad.js +++ b/packages/server/modules/auth/strategies/azure-ad.js @@ -4,7 +4,6 @@ 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 { @@ -13,6 +12,7 @@ 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) { - debug('speckle:error')(err) + logger.error(err) return next() } }, diff --git a/packages/server/modules/auth/strategies/github.js b/packages/server/modules/auth/strategies/github.js index 6a9724374..85287abad 100644 --- a/packages/server/modules/auth/strategies/github.js +++ b/packages/server/modules/auth/strategies/github.js @@ -4,7 +4,6 @@ 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 { @@ -13,6 +12,7 @@ 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) { - debug('speckle:error')(err) + logger.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 d35d671e3..d8fa43519 100644 --- a/packages/server/modules/auth/strategies/google.js +++ b/packages/server/modules/auth/strategies/google.js @@ -2,7 +2,6 @@ '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 { @@ -11,6 +10,7 @@ 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) { - debug('speckle:error')(err) + logger.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 058244d1e..453bf2f9f 100644 --- a/packages/server/modules/auth/strategies/local.js +++ b/packages/server/modules/auth/strategies/local.js @@ -1,5 +1,4 @@ 'use strict' -const debug = require('debug') const { createUser, validatePasssword, @@ -18,6 +17,7 @@ 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) { - debug('speckle:error')(err) + logger.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 51f633c9a..b03df3b31 100644 --- a/packages/server/modules/blobstorage/index.js +++ b/packages/server/modules/blobstorage/index.js @@ -1,4 +1,3 @@ -const debug = require('debug') const Busboy = require('busboy') const { streamReadPermissions, @@ -37,18 +36,19 @@ const { ResourceMismatch, BadRequestError } = require('@/modules/shared/errors') +const { moduleLogger, logger } = require('@/logging/logging') const ensureConditions = async () => { if (process.env.DISABLE_FILE_UPLOADS) { - debug('speckle:modules')('ðŸ“Ķ Blob storage is DISABLED') + moduleLogger.info('ðŸ“Ķ Blob storage is DISABLED') return } else { - debug('speckle:modules')('ðŸ“Ķ Init BlobStorage module') + moduleLogger.info('ðŸ“Ķ Init BlobStorage module') await ensureStorageAccess() } if (!process.env.S3_BUCKET) { - debug('speckle:error')( + logger.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 !== '') { - // console.log(`I have a client hash (${clientHash})`) + // logger.debug(`I have a client hash (${clientHash})`) blobId = clientHash } } @@ -148,7 +148,7 @@ exports.init = async (app) => { }) busboy.on('error', async (err) => { - debug('speckle:error')(`File upload error: ${err}`) + logger.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 7b1be8c73..dee6ef0f9 100644 --- a/packages/server/modules/blobstorage/objectStorage.js +++ b/packages/server/modules/blobstorage/objectStorage.js @@ -1,3 +1,4 @@ +const { logger } = require('@/logging/logging') const { NotFoundError } = require('@/modules/shared/errors') const { S3Client, @@ -88,7 +89,7 @@ const storeFileStream = async ({ objectKey, fileStream }) => { }) // parallelUploads3.on('httpUploadProgress', (progress) => { - // console.log(progress) + // logger.debug(progress) // }) const data = await parallelUploads3.done() @@ -114,7 +115,7 @@ const ensureStorageAccess = async () => { try { await client.send(new CreateBucketCommand({ Bucket })) } catch (err) { - console.log(err) + logger.error(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 ae87a34c0..b662a469c 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 { cliDebug } from '@/modules/shared/utils/logger' +import { cliLogger } from '@/logging/logging' 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) - cliDebug('Sent activity notifications') + cliLogger.info('Sent activity notifications') } } diff --git a/packages/server/modules/cli/commands/bull/monitor.ts b/packages/server/modules/cli/commands/bull/monitor.ts index 5bd1e316d..88038692f 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 - cliDebug('Initializing bull queues...') + cliLogger.info('Initializing bull queues...') const queues = [buildNotificationsQueue(NOTIFICATIONS_QUEUE)] if (testQueueId) { - cliDebug('Also initializing queue ' + testQueueId + '...') + cliLogger.info('Also initializing queue %s...', testQueueId) queues.push(buildNotificationsQueue(testQueueId)) } - cliDebug('Initializing monitor...') + cliLogger.info('Initializing monitor...') const app = express() const serverAdapter = new ExpressAdapter() @@ -45,8 +45,8 @@ const command: CommandModule = { app.use(serverAdapter.getRouter()) app.listen(PORT, () => { - cliDebug(`Running on ${PORT}...`) - cliDebug( + cliLogger.info(`Running on ${PORT}...`) + cliLogger.info( `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 adf22e43c..b3d0d18b5 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 () => { - cliDebug('Starting consumption...') + cliLogger.info('Starting consumption...') // Overriding handler for test purposes, we don't want the actual mentions logic to run await initializeConsumption({ - [NotificationType.MentionedInComment]: async (msg, { debug, job }) => { - debug('Received test message with payload', msg, job) + [NotificationType.MentionedInComment]: async (msg, { logger, job }) => { + logger.info('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 09d5d264e..c1f9bbd42 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 }) - cliDebug('Queued a fake notification...') + cliLogger.info('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 6e3ae8406..54116fb5f 100644 --- a/packages/server/modules/cli/commands/db/migrate/create.js +++ b/packages/server/modules/cli/commands/db/migrate/create.js @@ -1,6 +1,7 @@ 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 = { @@ -30,12 +31,12 @@ const command = { ) } - console.log('Creating migration...') + logger.info('Creating migration...') await knex.migrate.make(name, { directory: migrationDir, extension: 'ts' }) - console.log('...done') + logger.info('migration is complete') } } diff --git a/packages/server/modules/cli/commands/db/migrate/down.js b/packages/server/modules/cli/commands/db/migrate/down.js index 37c548967..cd2f65280 100644 --- a/packages/server/modules/cli/commands/db/migrate/down.js +++ b/packages/server/modules/cli/commands/db/migrate/down.js @@ -1,13 +1,14 @@ 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() { - console.log('Undoing last migration...') + logger.info('Undoing last migration...') await knex.migrate.down() - console.log('...done') + logger.info('Completed undoing last migration') } } diff --git a/packages/server/modules/cli/commands/db/migrate/latest.js b/packages/server/modules/cli/commands/db/migrate/latest.js index 07b6f100f..765d8ce98 100644 --- a/packages/server/modules/cli/commands/db/migrate/latest.js +++ b/packages/server/modules/cli/commands/db/migrate/latest.js @@ -1,13 +1,14 @@ 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() { - console.log('Running...') + logger.info('Running latest migration...') await knex.migrate.latest() - console.log('...done') + logger.info('Completed running migration') } } diff --git a/packages/server/modules/cli/commands/db/migrate/rollback.js b/packages/server/modules/cli/commands/db/migrate/rollback.js index f37c5198b..ec101ead8 100644 --- a/packages/server/modules/cli/commands/db/migrate/rollback.js +++ b/packages/server/modules/cli/commands/db/migrate/rollback.js @@ -1,13 +1,14 @@ 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() { - console.log('Rolling back...') + logger.info('Rolling back migrations...') await knex.migrate.rollback(null, true) - console.log('...done') + logger.info('Completed rolling back migrations') } } diff --git a/packages/server/modules/cli/commands/db/migrate/up.js b/packages/server/modules/cli/commands/db/migrate/up.js index f02508fec..04205f2dc 100644 --- a/packages/server/modules/cli/commands/db/migrate/up.js +++ b/packages/server/modules/cli/commands/db/migrate/up.js @@ -1,13 +1,14 @@ 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() { - console.log('Running...') + logger.info('Running next migration...') await knex.migrate.up() - console.log('...done') + logger.info('Completed running next migration') } } diff --git a/packages/server/modules/cli/commands/db/seed/commits.ts b/packages/server/modules/cli/commands/db/seed/commits.ts index 6d02aec1b..a8546ff4c 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< ) } - cliDebug(`Generating ${count} objects & commits for stream ${streamId}...`) + cliLogger.info(`Generating ${count} objects & commits for stream ${streamId}...`) await createTestCommits( times( count, @@ -61,7 +61,7 @@ const command: CommandModule< }) ) ) - cliDebug(`...done`) + cliLogger.info(`...done`) } } diff --git a/packages/server/modules/cli/commands/db/seed/users.js b/packages/server/modules/cli/commands/db/seed/users.js index e92c168e7..2a56dfed4 100644 --- a/packages/server/modules/cli/commands/db/seed/users.js +++ b/packages/server/modules/cli/commands/db/seed/users.js @@ -1,3 +1,4 @@ +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') @@ -45,11 +46,11 @@ async function* batchedOperationGenerator({ batchSize, retryCount = 3 }) { - console.log('Starting batched operation...') + logger.info('Starting batched operation...') let currentItemCount = 0 const batchCount = Math.ceil(itemCount / batchSize) for (let i = 0; i < batchCount; i++) { - console.log(`Processing batch ${i + 1} out of ${batchCount}...`) + logger.info(`Processing batch ${i + 1} out of ${batchCount}...`) const newItemCount = Math.min(currentItemCount + batchSize, itemCount) const insertCount = newItemCount - currentItemCount @@ -59,7 +60,7 @@ async function* batchedOperationGenerator({ const execute = () => Promise.resolve(batchInsertGenerator(insertCount, currentItemCount)) let batchPromise = execute().then((res) => { - console.log(`...processed batch ${i + 1} out of ${batchCount}`) + logger.info(`...processed batch ${i + 1} out of ${batchCount}`) return res }) @@ -70,7 +71,7 @@ async function* batchedOperationGenerator({ }) }) batchPromise = batchPromise.catch((e) => { - console.error('Operation failed all retries: ', e) + logger.error('Operation failed all retries: ', e) }) currentItemCount = newItemCount @@ -110,14 +111,14 @@ const command = { }) for await (const insertedIds of userBatchedInsertionGenerator) { - console.log('Inserting ACL entries for batch...') + logger.info('Inserting ACL entries for batch...') const entries = insertedIds.map((id) => ({ role: Roles.Server.User, userId: id })) await ServerAcl.knex().insert(entries) - console.log('...inserted ACL') + logger.info('...inserted ACL') } } } diff --git a/packages/server/modules/cli/commands/download/commit.ts b/packages/server/modules/cli/commands/download/commit.ts index 79e1b3ee7..33a611e8b 100644 --- a/packages/server/modules/cli/commands/download/commit.ts +++ b/packages/server/modules/cli/commands/download/commit.ts @@ -7,7 +7,6 @@ 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' @@ -20,6 +19,7 @@ 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) { - cliDebug('Encountered falsy object!') + cliLogger.error('Encountered falsy object!') return } @@ -230,7 +230,9 @@ const loadAllObjectsFromParent = async (params: { let processedObjectCount = 1 for await (const obj of objectLoader.getObjectIterator()) { const typedObj = obj as ObjectLoaderObject - cliDebug(`Processing ${obj.id} - ${processedObjectCount++}/${totalObjectCount}`) + cliLogger.info( + `Processing ${obj.id} - ${processedObjectCount++}/${totalObjectCount}` + ) await createNewObject(typedObj, targetStreamId) } } @@ -259,24 +261,24 @@ const command: CommandModule< }, handler: async (argv) => { const { commitUrl, targetStreamId, branchName } = argv - cliDebug(`Process started at: ${new Date().toISOString()}`) + cliLogger.info(`Process started at: ${new Date().toISOString()}`) const localResources = await getLocalResources(targetStreamId, branchName) - cliDebug( + cliLogger.info( `Using local branch ${branchName} of stream ${targetStreamId} to dump the incoming commit` ) const parsedCommitUrl = parseCommitUrl(commitUrl) - cliDebug('Loading the following commit: ', parsedCommitUrl) + cliLogger.info('Loading the following commit: %s', parsedCommitUrl) const client = await createApolloClient(parsedCommitUrl.origin) const commit = await getCommitMetadata(client, parsedCommitUrl) - cliDebug('Loaded commit metadata', commit) + cliLogger.info('Loaded commit metadata: %s', commit) const newCommitId = await saveNewCommit(commit, localResources) - cliDebug(`Created new local commit: ${newCommitId}`) + cliLogger.info(`Created new local commit: ${newCommitId}`) - cliDebug(`Pulling & saving all objects! (${commit.totalChildrenCount})`) + cliLogger.info(`Pulling & saving all objects! (${commit.totalChildrenCount})`) await loadAllObjectsFromParent({ targetStreamId, sourceCommit: commit, @@ -284,7 +286,7 @@ const command: CommandModule< }) const linkToNewCommit = `${getBaseUrl()}/streams/${targetStreamId}/commits/${newCommitId}` - cliDebug(`All done! Find your commit here: ${linkToNewCommit}`) + cliLogger.info(`All done! Find your commit here: ${linkToNewCommit}`) } } diff --git a/packages/server/modules/cli/index.js b/packages/server/modules/cli/index.js index c52da28f6..22d94e771 100644 --- a/packages/server/modules/cli/index.js +++ b/packages/server/modules/cli/index.js @@ -1,3 +1,4 @@ +const { logger } = require('@/logging/logging') const path = require('path') const yargs = require('yargs') require('../../bootstrap') @@ -10,12 +11,12 @@ const execution = yargs .fail((msg, err, yargs) => { if (!err) { // If validation error (no err instance) then just show help and show the message - console.error(yargs.help()) - console.error('\n', msg) + logger.error(yargs.help()) + logger.error('\n', msg) } else { // If actual app error occurred, show the msg, but don't show help info - console.error(err) - console.error('\n', 'Specify --help for available options') + logger.error(err) + logger.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 abceda71a..5b171120b 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) => { - debug('speckle:modules')('ðŸ—Ģ Init comments module') + moduleLogger.info('ðŸ—Ģ 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 5f7d524ff..caddd000e 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) => { - debug('speckle:modules')('ðŸ’Ĩ Init core module') + moduleLogger.info('ðŸ’Ĩ 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 7fdc57de9..29e7d9cff 100644 --- a/packages/server/modules/core/rest/diffDownload.js +++ b/packages/server/modules/core/rest/diffDownload.js @@ -1,6 +1,5 @@ 'use strict' const zlib = require('zlib') -const debug = require('debug') const cors = require('cors') const { validatePermissionsReadStream } = require('./authUtils') @@ -8,6 +7,7 @@ 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) { - debug('speckle:error')( + logger.error( `[User ${ req.context.userId || '-' }] App error streaming objects from stream ${req.params.streamId}: ${err}` ) } else { - debug('speckle:info')( + logger.info( `[User ${req.context.userId || '-'}] Streamed ${ childrenList.length } objects from stream ${req.params.streamId} (size: ${ @@ -73,7 +73,7 @@ module.exports = (app) => { }) } } catch (ex) { - debug('speckle:error')( + logger.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 d9572a1d1..f8c688d25 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) - debug('speckle:info')( + logger.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 }) - // console.log(response) + // logger.debug(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 5eefe9058..da092316c 100644 --- a/packages/server/modules/core/rest/download.js +++ b/packages/server/modules/core/rest/download.js @@ -1,6 +1,5 @@ 'use strict' const zlib = require('zlib') -const debug = require('debug') const cors = require('cors') const { validatePermissionsReadStream } = require('./authUtils') @@ -8,7 +7,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()) @@ -55,13 +54,13 @@ module.exports = (app) => { res, (err) => { if (err) { - debug('speckle:error')( + logger.error( `[User ${req.context.userId || '-'}] Error downloading object ${ req.params.objectId } from stream ${req.params.streamId}: ${err}` ) } else { - debug('speckle:info')( + logger.info( `[User ${req.context.userId || '-'}] Downloaded object ${ req.params.objectId } from stream ${req.params.streamId} (size: ${ @@ -92,7 +91,7 @@ module.exports = (app) => { return res.status(404).send('Failed to find object.') } - debug('speckle:info')( + logger.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 6c5071da2..f6bb6ee0e 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) { - debug('speckle:error')( + logger.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) { - debug('speckle:error')( + logger.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) { - debug('speckle:error')( + logger.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) => { - debug('speckle:error')( + logger.error( `[User ${req.context.userId || '-'}] Upload error: ${e.message}` ) if (!requestDropped) @@ -119,7 +119,7 @@ module.exports = (app) => { await promise - debug('speckle:info')( + logger.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) { - debug('speckle:error')( + logger.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) { - debug('speckle:error')( + logger.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) => { - debug('speckle:error')( + logger.error( `[User ${req.context.userId || '-'}] Upload error: ${e.message}` ) if (!requestDropped) @@ -195,7 +195,7 @@ module.exports = (app) => { promises.push(promise) await promise - debug('speckle:info')( + logger.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 { - debug('speckle:error')( + logger.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 - debug('speckle:upload-endpoint')( + uploadEndpointLogger.info( `[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) => { - debug('speckle:upload-endpoint')( + uploadEndpointLogger.info( `[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 8930cba1c..3ee1489ef 100644 --- a/packages/server/modules/core/services/objects.js +++ b/packages/server/modules/core/services/objects.js @@ -3,9 +3,8 @@ 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') @@ -103,7 +102,7 @@ module.exports = { const q = Objects().insert(batch).toString() + ' on conflict do nothing' await trx.raw(q) }) - debug(`Inserted ${batch.length} objects`) + servicesLogger.info(`Inserted ${batch.length} objects`) } } @@ -117,7 +116,7 @@ module.exports = { const q = Closures().insert(batch).toString() + ' on conflict do nothing' await trx.raw(q) }) - debug(`Inserted ${batch.length} closures`) + servicesLogger.info(`Inserted ${batch.length} closures`) } } return true @@ -190,12 +189,12 @@ module.exports = { } const t1 = performance.now() - debug( + servicesLogger.info( `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.` ) + // logger.debug( `Batch ${index + 1}/${batches.length}: Stored ${closures.length + objsToInsert.length} objects in ${t1-t0}ms.` ) } const promises = batches.map((batch, index) => insertBatch(batch, index)) @@ -433,7 +432,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. - // console.log( cursor ) + // logger.debug( cursor ) if (cursor) { let castType = 'text' if (typeof cursor.value === 'string') castType = 'text' @@ -489,7 +488,7 @@ module.exports = { } mainQuery.limit(limit) - // console.log( mainQuery.toString() ) + // logger.debug( 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 7c0e3cfbc..ab3247b22 100644 --- a/packages/server/modules/core/services/streams.js +++ b/packages/server/modules/core/services/streams.js @@ -1,7 +1,6 @@ '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') @@ -18,6 +17,7 @@ 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 }) { - debug('speckle:db')('Deleting stream ' + streamId) + dbLogger.info('Deleting stream %s', 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 e14640965..791568ce5 100644 --- a/packages/server/modules/core/services/taskScheduler.ts +++ b/packages/server/modules/core/services/taskScheduler.ts @@ -1,11 +1,9 @@ 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' - -const activitiesDebug = modulesDebug.extend('activities') +import { activitiesLogger, logger } from '@/logging/logging' export const scheduledCallbackWrapper = async ( scheduledTime: Date, @@ -23,24 +21,26 @@ export const scheduledCallbackWrapper = async ( // if couldn't acquire it, stop execution if (!lock) { - activitiesDebug( + activitiesLogger.warn( `Could not acquire task lock for ${taskName}, stopping execution.` ) return null } // else continue executing the callback... - activitiesDebug(`Executing scheduled function ${taskName} at ${scheduledTime}`) + activitiesLogger.info( + `Executing scheduled function ${taskName} at ${scheduledTime}` + ) await callback(scheduledTime) // update lock as succeeded const finishDate = new Date() - activitiesDebug( + activitiesLogger.info( `Finished scheduled function ${taskName} execution in ${ (finishDate.getTime() - scheduledTime.getTime()) / 1000 } seconds` ) } catch (error) { - errorDebug( + logger.error( `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 5a863fadd..1fc2ebf93 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 - debug('speckle:db')('Deleting user ' + id) + dbLogger.info('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 074256a7e..c67e71e23 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.stderr.on('data', (data) => { + serverProcess.stdout.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 804ab1819..bce995bc1 100644 --- a/packages/server/modules/emails/index.ts +++ b/packages/server/modules/emails/index.ts @@ -1,17 +1,15 @@ /* 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) => { - modulesDebug('📧 Init emails module') + moduleLogger.info('📧 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 b72b861c4..02dc1cdbf 100644 --- a/packages/server/modules/emails/services/sending.ts +++ b/packages/server/modules/emails/services/sending.ts @@ -1,8 +1,5 @@ +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 @@ -24,7 +21,7 @@ export async function sendEmail({ }: SendEmailParams): Promise { const transporter = getTransporter() if (!transporter) { - errorDebug('No email transport present. Cannot send emails.') + logger.error('No email transport present. Cannot send emails.') return false } try { @@ -37,7 +34,7 @@ export async function sendEmail({ html }) } catch (error) { - errorDebug(error) + logger.error(error) } return false diff --git a/packages/server/modules/emails/utils/transporter.ts b/packages/server/modules/emails/utils/transporter.ts index 4ba6b323b..b62532217 100644 --- a/packages/server/modules/emails/utils/transporter.ts +++ b/packages/server/modules/emails/utils/transporter.ts @@ -1,10 +1,6 @@ -import debug from 'debug' - +import { logger, moduleLogger } from '@/logging/logging' 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 }) @@ -26,7 +22,7 @@ const initSmtpTransporter = async () => { await smtpTransporter.verify() return smtpTransporter } catch (e) { - errorDebug('📧 Email provider is misconfigured, check config variables.', e) + logger.error('📧 Email provider is misconfigured, check config variables.', e) } } @@ -37,7 +33,7 @@ export async function initializeTransporter(): Promise if (process.env.EMAIL === 'true') newTransporter = await initSmtpTransporter() if (!newTransporter) { - modulesDebug( + moduleLogger.warn( '📧 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 d5d9ae217..07442eb16 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) { - debug('speckle:modules')('📄 FileUploads module is DISABLED') + moduleLogger.warn('📄 FileUploads module is DISABLED') return } else { - debug('speckle:modules')('📄 Init FileUploads module') + moduleLogger.info('📄 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) { - debug('speckle:error')(err.message) + logger.error(err) res.status(500).send(err.message) return } diff --git a/packages/server/modules/index.js b/packages/server/modules/index.js index a3b617b41..c8aff7281 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 () => { - modulesDebug('Triggering module shutdown...') + moduleLogger.info('Triggering module shutdown...') const modules = await getSpeckleModules() for (const module of modules) { await module.shutdown?.() } - modulesDebug('...module shutdown finished') + moduleLogger.info('...module shutdown finished') } /** diff --git a/packages/server/modules/notifications/helpers/types.ts b/packages/server/modules/notifications/helpers/types.ts index 198a092b2..f9984a8fe 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 11f388033..4d9c41e26 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 ) { - modulesDebug('📞 Initializing notification queue consumption...') + moduleLogger.info('📞 Initializing notification queue consumption...') const allHandlers: Partial = { [NotificationType.MentionedInComment]: ( @@ -39,14 +39,14 @@ export async function initializeConsumption( initializeQueue() if (shouldDisableNotificationsConsumption()) { - modulesDebug('Skipping notification consumption...') + moduleLogger.info('Skipping notification consumption...') } else { await consumeIncomingNotifications() } } export const init: SpeckleModule['init'] = async (_, isInitial) => { - modulesDebug('📞 Init notifications module') + moduleLogger.info('📞 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 da14d28aa..272bdaaed 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()) { - console.log('Notifications test queue ID: ' + NOTIFICATIONS_QUEUE) - console.log(`Monitor using: 'yarn cli bull monitor ${NOTIFICATIONS_QUEUE}'`) + logger.info('Notifications test queue ID: ' + NOTIFICATIONS_QUEUE) + logger.info(`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 { - notificationsDebug('New notification received...') + notificationsLogger.info('New notification received...') // Parse const payload = job.data @@ -139,17 +139,17 @@ export async function consumeIncomingNotifications() { throw new UnhandledNotificationError(null, { info: { payload, type } }) } - const notificationDebug = notificationsDebug.extend(type) - notificationDebug('Starting processing notification...') - await Promise.resolve(handler(typedPayload, { job, debug: notificationDebug })) - notificationDebug('...successfully processed notification') + const notificationLogger = extendLoggerComponent(notificationsLogger, type) + notificationLogger.info('Starting processing notification...') + await Promise.resolve(handler(typedPayload, { job, logger: notificationLogger })) + notificationLogger.info('...successfully processed notification') return { status: NotificationJobResultsStatus.Success, type } } catch (e: unknown) { - notificationsDebug(e) + notificationsLogger.error(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 d2677b6df..0c983fe90 100644 --- a/packages/server/modules/previews/index.js +++ b/packages/server/modules/previews/index.js @@ -1,8 +1,6 @@ /* istanbul ignore file */ 'use strict' -const debug = require('debug') - const { validateScopes, authorizeResolver } = require('@/modules/shared') const { getStream } = require('../core/services/streams') @@ -19,6 +17,7 @@ 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`) @@ -28,9 +27,9 @@ const previewErrorImage = require.resolve('#/assets/previews/images/preview_erro exports.init = (app) => { if (process.env.DISABLE_PREVIEWS) { - debug('speckle:modules')('ðŸ“ļ Object preview module is DISABLED') + moduleLogger.warn('ðŸ“ļ Object preview module is DISABLED') } else { - debug('speckle:modules')('ðŸ“ļ Init object preview module') + moduleLogger.info('ðŸ“ļ Init object preview module') } const DEFAULT_ANGLE = '0' @@ -64,7 +63,7 @@ exports.init = (app) => { const previewImgId = previewInfo.preview[angle] if (!previewImgId) { - debug('speckle:error')( + logger.error( `Error: Preview angle '${angle}' not found for object ${streamId}:${objectId}` ) return { @@ -75,7 +74,7 @@ exports.init = (app) => { } const previewImg = await getPreviewImage({ previewId: previewImgId }) if (!previewImg) { - debug('speckle:error')(`Error: Preview image not found: ${previewImgId}`) + logger.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 a2365fbd6..04d065494 100644 --- a/packages/server/modules/previews/ogImage.js +++ b/packages/server/modules/previews/ogImage.js @@ -4,6 +4,7 @@ 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) { @@ -22,7 +23,7 @@ module.exports = { } title += '...' } - // console.log( streamName, pixelWidth( title, { font: 'open sans', size: 48 } ), ' / ', imgWidth - 2 * panelPadding - 305 ) + // logger.debug( 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 e41bd4456..933b7b5b7 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) => { - debug('speckle:modules')('â™ŧïļ Init pwd reset module') + moduleLogger.info('â™ŧïļ Init pwd reset module') RestSetup(app) } diff --git a/packages/server/modules/serverinvites/index.js b/packages/server/modules/serverinvites/index.js index 06f154d52..5840c7e0b 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 () => { - debug('speckle:modules')('💌 Init invites module') + moduleLogger.info('💌 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 559c7a068..0e98a0892 100644 --- a/packages/server/modules/shared/services/moduleEventEmitterSetup.ts +++ b/packages/server/modules/shared/services/moduleEventEmitterSetup.ts @@ -1,5 +1,6 @@ +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 = { @@ -26,10 +27,10 @@ export function initializeModuleEventEmitter

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

>( /** * Debugger scoped to this module event emitter */ - debug + logger } } diff --git a/packages/server/modules/shared/utils/logger.ts b/packages/server/modules/shared/utils/logger.ts deleted file mode 100644 index d81368816..000000000 --- a/packages/server/modules/shared/utils/logger.ts +++ /dev/null @@ -1,8 +0,0 @@ -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 1648c4c12..115c115bf 100644 --- a/packages/server/modules/stats/index.js +++ b/packages/server/modules/stats/index.js @@ -1,8 +1,8 @@ 'use strict' -const debug = require('debug') +const { moduleLogger } = require('@/logging/logging') exports.init = async () => { - debug('speckle:modules')('📊 Init stats module') + moduleLogger.info('📊 Init stats module') // TODO } diff --git a/packages/server/modules/webhooks/index.ts b/packages/server/modules/webhooks/index.ts index 396eda435..5eb432d18 100644 --- a/packages/server/modules/webhooks/index.ts +++ b/packages/server/modules/webhooks/index.ts @@ -1,24 +1,22 @@ 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' - -const webhooksDebug = modulesDebug.extend('activities') +import { activitiesLogger, moduleLogger } from '@/logging/logging' const scheduleWebhookCleanup = () => { const cronExpression = '0 4 * * 1' return scheduleExecution(cronExpression, 'weeklyWebhookCleanup', async () => { - webhooksDebug('Starting weekly webhooks cleanup') + activitiesLogger.info('Starting weekly webhooks cleanup') await cleanOrphanedWebhookConfigs() - webhooksDebug('Finished cleanup') + activitiesLogger.info('Finished cleanup') }) } let scheduledTask: cron.ScheduledTask | null = null export const init: SpeckleModule['init'] = () => { - modulesDebug('ðŸŽĢ Init webhooks module') + moduleLogger.info('ðŸŽĢ Init webhooks module') scheduledTask = scheduleWebhookCleanup() } diff --git a/packages/server/package.json b/packages/server/package.json index e2b19d45f..cc39241e2 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 DEBUG='speckle:*' nodemon ./bin/www --watch ./dist --watch ./assets --watch ./bin/www -e js,ts,graphql,env,gql", + "run:watch": "cross-env NODE_ENV=development 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 DEBUG='speckle:*' node ./bin/ts-www", + "dev:server:test": "cross-env DISABLE_NOTIFICATIONS_CONSUMPTION=true NODE_ENV=test 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 DEBUG='speckle:*' ts-node ./modules/cli/index.js", + "cli": "cross-env NODE_ENV=development ts-node ./modules/cli/index.js", "migrate": "yarn cli db migrate", - "migrate:test": "cross-env NODE_ENV=test DEBUG='speckle:*' ts-node ./modules/cli/index.js db migrate", + "migrate:test": "cross-env NODE_ENV=test ts-node ./modules/cli/index.js db migrate", "gqlgen": "graphql-codegen --config codegen.yml" }, "dependencies": { @@ -38,6 +38,7 @@ "@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", @@ -48,7 +49,6 @@ "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,8 +64,6 @@ "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", @@ -76,6 +74,8 @@ "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 e0c1ce5f4..c18946e37 100644 --- a/packages/server/scripts/duplicateUserMigration.js +++ b/packages/server/scripts/duplicateUserMigration.js @@ -1,4 +1,5 @@ const knex = require('@/db/knex') +const { logger } = require('@/logging/logging') const roles = require('@/modules/core/roles.js') const Users = () => knex('users') @@ -24,10 +25,10 @@ const migrateColumnValue = async (tableName, columnName, oldUser, newUser) => { const query = knex(tableName) .where({ [columnName]: oldUser.id }) .update({ [columnName]: newUser.id }) - console.log(`${query}`) + logger.info(`${query}`) await query } catch (err) { - console.log(err) + logger.error(err) } } @@ -106,7 +107,7 @@ const getDuplicateUsers = async () => { const runMigrations = async () => { const duplicateUsers = await getDuplicateUsers() - console.log(duplicateUsers) + logger.info(duplicateUsers) await Promise.all( duplicateUsers.map(async (userDouble) => { const migrations = createMigrations(userDouble) @@ -125,7 +126,7 @@ const runMigrations = async () => { // await createData() await runMigrations() } catch (err) { - console.log(err) + logger.error(err) } finally { process.exit() } diff --git a/packages/server/scripts/seedUsers.js b/packages/server/scripts/seedUsers.js index 66ed5962b..174b6258e 100644 --- a/packages/server/scripts/seedUsers.js +++ b/packages/server/scripts/seedUsers.js @@ -1,4 +1,5 @@ require('../bootstrap') +const { logger } = require('@/logging/logging') const { createUser } = require('@/modules/core/services/users') const axios = require('axios').default @@ -15,4 +16,4 @@ const main = async () => { await Promise.all(userInputs.map((userInput) => createUser(userInput))) } -main().then(console.log('created')).catch(console.log('failed')) +main().then(logger.info('created')).catch(logger.error('failed')) diff --git a/packages/server/scripts/streamObjects.js b/packages/server/scripts/streamObjects.js index 0272b8f4e..9d651a976 100644 --- a/packages/server/scripts/streamObjects.js +++ b/packages/server/scripts/streamObjects.js @@ -8,6 +8,7 @@ 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 = { @@ -53,7 +54,7 @@ const main = async () => { .set('Content-type', 'multipart/form-data') .attach('batch1', Buffer.from(JSON.stringify(objBatch), 'utf8')) - console.log(uploadRes.status) + logger.info(uploadRes.status) const objectIds = objBatch.map((obj) => obj.id) const res = await fetch(`http://localhost:3000/api/getobjects/${testStream.id}`, { @@ -66,8 +67,8 @@ const main = async () => { body: JSON.stringify({ objects: JSON.stringify(objectIds) }) }) const data = await res.body.getReader().read() - console.log(data) + logger.info(data) exit(0) } -main().then(console.log('created')).catch(console.log('failed')) +main().then(logger.info('created')).catch(logger.error('failed')) diff --git a/packages/server/test/helpers.js b/packages/server/test/helpers.js index f370e0420..dc7bfc646 100644 --- a/packages/server/test/helpers.js +++ b/packages/server/test/helpers.js @@ -1,4 +1,5 @@ /* istanbul ignore file */ +// const { logger } = require('@/logging/logging') const crypto = require('crypto') function generateManyObjects(shitTon, noise) { @@ -68,7 +69,7 @@ exports.generateManyObjects = generateManyObjects exports.getAnIdForThisOnePlease = getAnIdForThisOnePlease exports.sleep = (ms) => { - // console.log( `\t Sleeping ${ms}ms ` ) + // logger.debug( `\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 b10343aeb..ea0f8ac5c 100644 --- a/packages/server/test/hooks.js +++ b/packages/server/test/hooks.js @@ -9,6 +9,7 @@ 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) @@ -72,14 +73,14 @@ const initializeTestServer = async (server, app) => { exports.mochaHooks = { beforeAll: async () => { - console.log('running before all') + logger.info('running before all') await unlock() await knex.migrate.rollback() await knex.migrate.latest() await init() }, afterAll: async () => { - console.log('running after all') + logger.info('running after all') await unlock() await shutdown() } diff --git a/packages/server/test/notificationsHelper.ts b/packages/server/test/notificationsHelper.ts index 5da56f694..7dc56aef3 100644 --- a/packages/server/test/notificationsHelper.ts +++ b/packages/server/test/notificationsHelper.ts @@ -2,6 +2,7 @@ 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 @@ -142,13 +143,13 @@ export async function debugJobs() { { items: failed, display: 'Failed' } ] - console.log('------------- START debugJobs() --------------') + logger.debug('------------- START debugJobs() --------------') for (const { items, display } of jobCollections) { - console.log(`${display}: ` + waiting.length) - console.log(`${display} jobs: `) + logger.debug(`${display}: ` + waiting.length) + logger.debug(`${display} jobs: `) for (const job of items) { - console.log( + logger.debug( ` - ${JSON.stringify( pick(job, [ 'timestamp', @@ -162,6 +163,6 @@ export async function debugJobs() { ) } } - console.log({ workers }) - console.log('------------- END debugJobs() --------------') + logger.debug({ workers }) + logger.debug('------------- END debugJobs() --------------') } diff --git a/packages/server/type-augmentations/morgan-debug.d.ts b/packages/server/type-augmentations/morgan-debug.d.ts deleted file mode 100644 index b70007c5b..000000000 --- a/packages/server/type-augmentations/morgan-debug.d.ts +++ /dev/null @@ -1,9 +0,0 @@ -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 627884f48..4b10aacef 100644 --- a/packages/shared/package.json +++ b/packages/shared/package.json @@ -31,7 +31,8 @@ "3d" ], "dependencies": { - "lodash": "^4.17.0" + "lodash": "^4.17.0", + "pino": "^8.7.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 49d97ee06..196258d0c 100644 --- a/packages/shared/src/core/index.ts +++ b/packages/shared/src/core/index.ts @@ -3,4 +3,5 @@ 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 new file mode 100644 index 000000000..219e2751f --- /dev/null +++ b/packages/shared/src/core/observability/logging.ts @@ -0,0 +1,23 @@ +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 acac81781..03942c495 100644 --- a/packages/webhook-service/Dockerfile +++ b/packages/webhook-service/Dockerfile @@ -1,3 +1,24 @@ +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 && \ @@ -19,10 +40,13 @@ COPY .yarnrc.yml . COPY .yarn ./.yarn COPY package.json yarn.lock ./ -WORKDIR /speckle-server/packages/webhook-service -COPY packages/webhook-service/package.json . +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/ RUN yarn workspaces focus --production -COPY packages/webhook-service/src . - +ENTRYPOINT [ "tini", "--" ] CMD ["yarn", "node", "main.js"] diff --git a/packages/webhook-service/package.json b/packages/webhook-service/package.json index 3632a8de1..3be08af07 100644 --- a/packages/webhook-service/package.json +++ b/packages/webhook-service/package.json @@ -21,6 +21,7 @@ "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 2441c8a04..10f6788b7 100644 --- a/packages/webhook-service/src/main.js +++ b/packages/webhook-service/src/main.js @@ -3,7 +3,8 @@ const crypto = require('crypto') const knex = require('./knex') const fs = require('fs') -const metrics = require('./prometheusMetrics') +const metrics = require('./observability/prometheusMetrics') +const { logger } = require('./observability/logging') let shouldExit = false const HEALTHCHECK_FILE_PATH = '/tmp/last_successful_query' @@ -57,7 +58,7 @@ async function doTask(task) { .digest('hex') const postHeaders = { 'X-WEBHOOK-SIGNATURE': signature } - console.log( + logger.info( `Callin webhook ${fullPayload.streamId} : ${fullPayload.event.event_name} at ${fullPayload.webhook.url}...` ) const result = await makeNetworkRequest({ @@ -66,7 +67,7 @@ async function doTask(task) { headersData: postHeaders }) - console.log(` Result: ${JSON.stringify(result)}`) + logger.info(` Result: ${JSON.stringify(result)}`) if (!result.success) { throw new Error(result.error) @@ -124,17 +125,17 @@ async function tick() { setTimeout(tick, 10) } catch (err) { metrics.metricOperationErrors.labels('main_loop').inc() - console.log('Error executing task: ', err) + logger.error('Error executing task: ', err) setTimeout(tick, 5000) } } async function main() { - console.log('Starting Webhook Service...') + logger.info('Starting Webhook Service...') process.on('SIGTERM', () => { shouldExit = true - console.log('Shutting down...') + logger.info('Shutting down...') }) metrics.initPrometheusMetrics() diff --git a/packages/webhook-service/src/observability/logging.js b/packages/webhook-service/src/observability/logging.js new file mode 100644 index 000000000..dd1fccbed --- /dev/null +++ b/packages/webhook-service/src/observability/logging.js @@ -0,0 +1,7 @@ +const { logger: baseLogger, extendLoggerComponent } = require('@speckle/shared') + +const logger = extendLoggerComponent(baseLogger, 'webhook-service') + +module.exports = { + logger +} diff --git a/packages/webhook-service/src/prometheusMetrics.js b/packages/webhook-service/src/observability/prometheusMetrics.js similarity index 99% rename from packages/webhook-service/src/prometheusMetrics.js rename to packages/webhook-service/src/observability/prometheusMetrics.js index 8b340125d..553540e2a 100644 --- a/packages/webhook-service/src/prometheusMetrics.js +++ b/packages/webhook-service/src/observability/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 9e866499b..57846fe09 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 debug = require('debug')('speckle') +const { logger } = require('./observability/logging') 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] - debug('POST request to:', url) + logger.info('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() })) - //console.log( 'Server response:', response ) + // logger.debug( '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 ba1ad01c4..6ef99cd37 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' - DEBUG: 'speckle:*' + LOG_LEVEL: 'info' POSTGRES_URL: 'postgres' POSTGRES_USER: 'speckle' @@ -91,7 +91,7 @@ services: command: ['bash', '-c', '/wait && node bin/www'] environment: - DEBUG: 'preview-service:*' + LOG_LEVEL: 'info' 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: - DEBUG: 'webhook-service:*' + LOG_LEVEL: 'info' 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: - DEBUG: 'fileimport-service:*' + LOG_LEVEL: 'info' 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 581500383..ed334408b 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: DEBUG - value: "fileimport-service:*" + - name: LOG_LEVEL + value: {{ .Values.fileimport_service.logLevel | quote }} {{- 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 94f0e75f7..c2008c5c9 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: DEBUG - value: "preview-service:*" + - name: LOG_LEVEL + value: {{ .Values.preview_service.logLevel | quote }} {{- 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 f34f5e465..2520d03d9 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: DEBUG - value: "speckle:*" + - name: LOG_LEVEL + value: {{ .Values.server.logLevel }} - 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 28c44d6c1..327786389 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: DEBUG - value: "webhook-service:*" + - name: LOG_LEVEL + value: {{ .Values.webhook_service.logLevel }} {{- 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 bef4a9b45..b51f45c53 100644 --- a/utils/helm/speckle-server/values.yaml +++ b/utils/helm/speckle-server/values.yaml @@ -361,6 +361,9 @@ 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 ## @@ -591,6 +594,9 @@ 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/ @@ -651,6 +657,9 @@ 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/ @@ -711,6 +720,9 @@ 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/ @@ -771,6 +783,9 @@ 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/ @@ -837,6 +852,9 @@ 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/ @@ -899,6 +917,9 @@ 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 22ce16f27..ac2670f7a 100644 --- a/yarn.lock +++ b/yarn.lock @@ -4821,6 +4821,7 @@ __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 @@ -4955,12 +4956,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 @@ -4969,11 +4970,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 @@ -5020,6 +5021,7 @@ __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 @@ -5043,7 +5045,6 @@ __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 @@ -5066,8 +5067,6 @@ __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 @@ -5081,6 +5080,8 @@ __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 @@ -5116,6 +5117,7 @@ __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 @@ -5181,6 +5183,7 @@ __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 @@ -6059,6 +6062,46 @@ __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" @@ -7718,6 +7761,13 @@ __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" @@ -7920,7 +7970,7 @@ __metadata: languageName: node linkType: hard -"basic-auth@npm:^2.0.1, basic-auth@npm:~2.0.0, basic-auth@npm:~2.0.1": +"basic-auth@npm:^2.0.1": version: 2.0.1 resolution: "basic-auth@npm:2.0.1" dependencies: @@ -8916,6 +8966,13 @@ __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" @@ -9654,6 +9711,13 @@ __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" @@ -9675,7 +9739,7 @@ __metadata: languageName: node linkType: hard -"debug@npm:2.6.9, debug@npm:^2.2.0, debug@npm:~2.6.9": +"debug@npm:2.6.9, debug@npm:^2.2.0": version: 2.6.9 resolution: "debug@npm:2.6.9" dependencies: @@ -11107,7 +11171,7 @@ __metadata: languageName: node linkType: hard -"events@npm:3.3.0, events@npm:^3.2.0": +"events@npm:3.3.0, events@npm:^3.2.0, events@npm:^3.3.0": version: 3.3.0 resolution: "events@npm:3.3.0" checksum: f6f487ad2198aa41d878fa31452f1a3c00958f46e9019286ff4787c84aac329332ab45c9cdc8c445928fc6d7ded294b9e005a7fce9426488518017831b272780 @@ -11361,6 +11425,13 @@ __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" @@ -11395,6 +11466,29 @@ __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" @@ -12116,6 +12210,19 @@ __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" @@ -12130,19 +12237,6 @@ __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" @@ -12541,6 +12635,16 @@ __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" @@ -13739,6 +13843,13 @@ __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" @@ -15453,44 +15564,6 @@ __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" @@ -16100,6 +16173,13 @@ __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" @@ -16831,6 +16911,81 @@ __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" @@ -17086,6 +17241,13 @@ __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" @@ -17290,6 +17452,13 @@ __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" @@ -17386,6 +17555,13 @@ __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" @@ -17489,7 +17665,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.3.6": +"readable-stream@npm:^2.0.1, readable-stream@npm:^2.0.6, readable-stream@npm:^2.3.5": version: 2.3.7 resolution: "readable-stream@npm:2.3.7" dependencies: @@ -17515,6 +17691,18 @@ __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" @@ -17533,6 +17721,13 @@ __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" @@ -18183,6 +18378,7 @@ __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 @@ -18251,6 +18447,13 @@ __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" @@ -18345,6 +18548,13 @@ __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" @@ -18818,6 +19028,24 @@ __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" @@ -18927,7 +19155,7 @@ __metadata: languageName: node linkType: hard -"split2@npm:^4.1.0": +"split2@npm:^4.0.0, split2@npm:^4.1.0": version: 4.1.0 resolution: "split2@npm:4.1.0" checksum: ec581597cb74c13cdfb5e2047543dd40cb1e8e9803c7b1e0c29ede05f2b4f049b2d6e7f2788a225d544549375719658b8f38e9366364dec35dc7a12edfda5ee5 @@ -19531,6 +19759,15 @@ __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" @@ -19554,16 +19791,6 @@ __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" @@ -21220,7 +21447,7 @@ __metadata: languageName: node linkType: hard -"xtend@npm:^4.0.0, xtend@npm:~4.0.1": +"xtend@npm:^4.0.0": version: 4.0.2 resolution: "xtend@npm:4.0.2" checksum: ac5dfa738b21f6e7f0dd6e65e1b3155036d68104e67e5d5d1bde74892e327d7e5636a076f625599dc394330a731861e87343ff184b0047fef1360a7ec0a5a36a