diff --git a/keyserver/package.json b/keyserver/package.json index 9bf56c810..e923bf972 100644 --- a/keyserver/package.json +++ b/keyserver/package.json @@ -1,115 +1,116 @@ { "name": "keyserver", "version": "0.0.1", "type": "module", "private": true, "license": "BSD-3-Clause", "main": "dist/keyserver", "scripts": { "clean": "rm -rf dist/ && rm -rf node_modules/ && mkdir dist", "babel-build-comm-config": ". bash/source-nvm.sh && yarn --silent babel src/lib/utils/comm-config.js --out-dir dist/lib/utils/ --config-file ./babel.config.cjs", "babel-build": ". bash/source-nvm.sh && yarn --silent babel src/ --out-dir dist/ --config-file ./babel.config.cjs --verbose --ignore 'src/landing/flow-typed','src/landing/node_modules','src/landing/package.json','src/lib/flow-typed','src/lib/node_modules','src/lib/package.json','src/web/flow-typed','src/web/node_modules','src/web/package.json','src/web/dist','src/web/webpack.config.js','src/web/account-bar.react.js','src/web/app.react.js','src/web/calendar','src/web/chat','src/web/flow','src/web/loading-indicator.react.js','src/web/modals','src/web/root.js','src/web/router-history.js','src/web/script.js','src/web/selectors/chat-selectors.js','src/web/selectors/entry-selectors.js','src/web/splash','src/web/vector-utils.js','src/web/vectors.react.js'", "rsync": "rsync -rLpmuv --exclude '*/package.json' --exclude '*/node_modules/*' --include '*.json' --include '*.cjs' --include '*.node' --exclude '*.*' src/ dist/", "prod-build": "yarn babel-build && yarn rsync", "prod": "KEYSERVER=true node --trace-warnings --loader=./loader.mjs dist/keyserver", "profile-prod": "KEYSERVER=true KEYSERVER_CPU_PROFILING_ENABLED=true 0x --output-dir cpu_profiling_logs/{pid}.0x -o -- node --trace-warnings --loader=./loader.mjs dist/keyserver", "clear-profile-logs": "rm -rf cpu_profiling_logs/", "dev-rsync": "yarn --silent chokidar --initial --silent -s 'src/**/*.json' 'src/**/*.cjs' -c 'yarn rsync > /dev/null 2>&1'", "dev": ". bash/source-nvm.sh && yarn concurrently --names=\"BABEL,RSYNC,NODEM\" -c \"bgBlue.bold,bgMagenta.bold,bgGreen.bold\" \"yarn babel-build --source-maps --watch\" \"yarn dev-rsync\" \". bash/source-nvm.sh && KEYSERVER=true NODE_ENV=development nodemon -e js,json,cjs --watch dist --no-warnings=ExperimentalWarning --loader=./loader.mjs dist/keyserver\"", + "dev-log-metrics": "KEYSERVER_ENDPOINT_METRICS_ENABLED=true yarn dev", "script": ". bash/source-nvm.sh && NODE_ENV=development node --loader=./loader.mjs", "test": "jest" }, "devDependencies": { "@babel/cli": "^7.13.14", "@babel/core": "^7.13.14", "@babel/node": "^7.13.13", "@babel/plugin-proposal-class-properties": "^7.13.0", "@babel/plugin-proposal-nullish-coalescing-operator": "^7.13.8", "@babel/plugin-proposal-object-rest-spread": "^7.13.8", "@babel/plugin-proposal-optional-chaining": "^7.13.12", "@babel/plugin-syntax-dynamic-import": "^7.8.3", "@babel/plugin-transform-runtime": "^7.13.10", "@babel/preset-env": "^7.13.12", "@babel/preset-flow": "^7.13.13", "@babel/preset-react": "^7.13.13", "babel-jest": "^26.6.3", "babel-plugin-transform-import-meta": "2.2.0", "chokidar-cli": "^2.1.0", "concurrently": "^5.3.0", "flow-bin": "^0.182.0", "flow-typed": "^3.2.1", "internal-ip": "4.3.0", "jest": "^26.6.3", "nodemon": "^2.0.4", "0x": "^5.7.0" }, "dependencies": { "@babel/runtime": "^7.13.10", "@commapp/olm": "0.0.10", "@parse/node-apn": "^3.2.0", "@vingle/bmp-js": "^0.2.5", "JSONStream": "^1.3.5", "bad-words": "^3.0.4", "common-tags": "^1.7.2", "compression": "^1.7.4", "cookie-parser": "^1.4.3", "dateformat": "^3.0.3", "detect-browser": "^4.0.4", "ethers": "^5.7.2", "express": "^4.17.3", "express-ws": "^4.0.0", "firebase-admin": "^10.1.0", "geoip-lite": "^1.4.5", "invariant": "^2.2.4", "landing": "0.0.1", "lib": "0.0.1", "lodash": "^4.17.21", "multer": "^1.4.1", "mysql2": "^2.3.3", "natural": "^6.2.0", "node-schedule": "^2.1.0", "nodemailer": "^6.6.1", "qrcode": "^1.5.3", "react": "18.1.0", "react-dom": "18.1.0", "react-html-email": "^3.0.0", "react-redux": "^7.1.1", "react-router": "^5.2.0", "redis": "^3.1.1", "redux": "^4.0.4", "replacestream": "^4.0.3", "rereadable-stream": "^1.4.5", "rust-node-addon": "0.0.1", "sharp": "^0.30.5", "siwe": "^1.1.6", "sql-template-strings": "^2.2.2", "stream-combiner": "^0.2.2", "tcomb": "^3.2.29", "twin-bcrypt": "^2.1.1", "uuid": "^3.4.0", "web": "0.0.1", "web-push": "^3.5.0", "ws": "^8.13.0" }, "optionalDependencies": { "bufferutil": "^4.0.5", "utf-8-validate": "^5.0.7" }, "nodemonConfig": { "delay": "200" }, "jest": { "roots": [ "/src" ], "transform": { "\\.js$": "babel-jest" }, "transformIgnorePatterns": [ "/node_modules/(?!@babel/runtime)" ], "setupFiles": [ "/jest-setup.js" ] } } diff --git a/keyserver/src/keyserver.js b/keyserver/src/keyserver.js index cec304ddf..b9f81876b 100644 --- a/keyserver/src/keyserver.js +++ b/keyserver/src/keyserver.js @@ -1,237 +1,243 @@ // @flow import olm from '@commapp/olm'; import cluster from 'cluster'; import compression from 'compression'; import cookieParser from 'cookie-parser'; import crypto from 'crypto'; import express from 'express'; import expressWs from 'express-ws'; import os from 'os'; import qrcode from 'qrcode'; import './cron/cron.js'; import { qrCodeLinkURL } from 'lib/facts/links.js'; import { migrate } from './database/migrations.js'; import { jsonEndpoints } from './endpoints.js'; +import { logEndpointMetrics } from './middleware/endpoint_profiling.js'; import { emailSubscriptionResponder } from './responders/comm-landing-responders.js'; import { jsonHandler, downloadHandler, handleAsyncPromise, htmlHandler, uploadHandler, } from './responders/handlers.js'; import landingHandler from './responders/landing-handler.js'; import { errorReportDownloadResponder } from './responders/report-responders.js'; import { inviteResponder, websiteResponder, } from './responders/website-responders.js'; import { webWorkerResponder } from './responders/webworker-responders.js'; import { onConnection } from './socket/socket.js'; import { createAndMaintainTunnelbrokerWebsocket } from './socket/tunnelbroker.js'; import { multerProcessor, multimediaUploadResponder, uploadDownloadResponder, } from './uploads/uploads.js'; import { verifyUserLoggedIn } from './user/login.js'; import { initENSCache } from './utils/ens-cache.js'; import { getContentSigningKey } from './utils/olm-utils.js'; import { prefetchAllURLFacts, getSquadCalURLFacts, getLandingURLFacts, getCommAppURLFacts, } from './utils/urls.js'; const shouldDisplayQRCodeInTerminal = false; (async () => { await Promise.all([olm.init(), prefetchAllURLFacts(), initENSCache()]); const squadCalBaseRoutePath = getSquadCalURLFacts()?.baseRoutePath; const landingBaseRoutePath = getLandingURLFacts()?.baseRoutePath; const commAppBaseRoutePath = getCommAppURLFacts()?.baseRoutePath; const compiledFolderOptions = process.env.NODE_ENV === 'development' ? undefined : { maxAge: '1y', immutable: true }; const isCPUProfilingEnabled = process.env.KEYSERVER_CPU_PROFILING_ENABLED; + const areEndpointMetricsEnabled = + process.env.KEYSERVER_ENDPOINT_METRICS_ENABLED; if (cluster.isMaster) { const didMigrationsSucceed: boolean = await migrate(); if (!didMigrationsSucceed) { // The following line uses exit code 2 to ensure nodemon exits // in a dev environment, instead of restarting. Context provided // in https://github.com/remy/nodemon/issues/751 process.exit(2); } // Allow login to be optional until staging environment is available try { // We await here to ensure that the keyserver has been provisioned a // commServicesAccessToken. In the future, this will be necessary for // many keyserver operations. const identityInfo = await verifyUserLoggedIn(); // We don't await here, as Tunnelbroker communication is not needed for // normal keyserver behavior yet. In addition, this doesn't return // information useful for other keyserver functions. handleAsyncPromise(createAndMaintainTunnelbrokerWebsocket(identityInfo)); } catch (e) { console.warn('failed_identity_login'); } if (shouldDisplayQRCodeInTerminal) { try { const aes256Key = crypto.randomBytes(32).toString('hex'); const ed25519Key = await getContentSigningKey(); console.log( '\nOpen the Comm app on your phone and scan the QR code below\n', ); console.log('How to find the scanner:\n'); console.log('Go to \x1b[1mProfile\x1b[0m'); console.log('Select \x1b[1mLinked devices\x1b[0m'); console.log('Click \x1b[1mAdd\x1b[0m on the top right'); const url = qrCodeLinkURL(aes256Key, ed25519Key); qrcode.toString(url, (error, encodedURL) => console.log(encodedURL)); } catch (e) { console.log('Error generating QR code', e); } } if (!isCPUProfilingEnabled) { const cpuCount = os.cpus().length; for (let i = 0; i < cpuCount; i++) { cluster.fork(); } cluster.on('exit', () => cluster.fork()); } } if (!cluster.isMaster || isCPUProfilingEnabled) { const server = express(); server.use(compression()); expressWs(server); server.use(express.json({ limit: '250mb' })); server.use(cookieParser()); const setupAppRouter = router => { + if (areEndpointMetricsEnabled) { + router.use(logEndpointMetrics); + } router.use('/images', express.static('images')); router.use('/fonts', express.static('fonts')); router.use('/misc', express.static('misc')); router.use( '/.well-known', express.static( '.well-known', // Necessary for apple-app-site-association file { setHeaders: res => res.setHeader('Content-Type', 'application/json'), }, ), ); router.use( '/compiled', express.static('app_compiled', compiledFolderOptions), ); router.use('/', express.static('icons')); for (const endpoint in jsonEndpoints) { // $FlowFixMe Flow thinks endpoint is string const responder = jsonEndpoints[endpoint]; const expectCookieInvalidation = endpoint === 'log_out'; router.post( `/${endpoint}`, jsonHandler(responder, expectCookieInvalidation), ); } router.get( '/download_error_report/:reportID', downloadHandler(errorReportDownloadResponder), ); router.get( '/upload/:uploadID/:secret', downloadHandler(uploadDownloadResponder), ); router.get('/invite/:secret', inviteResponder); // $FlowFixMe express-ws has side effects that can't be typed router.ws('/ws', onConnection); router.get('/worker/:worker', webWorkerResponder); router.get('*', htmlHandler(websiteResponder)); router.post( '/upload_multimedia', multerProcessor, uploadHandler(multimediaUploadResponder), ); }; // Note - the order of router declarations matters. On prod we have // squadCalBaseRoutePath configured to '/', which means it's a catch-all. If // we call server.use on squadCalRouter first, it will catch all requests // and prevent commAppRouter and landingRouter from working correctly. So we // make sure that squadCalRouter goes last server.get('/invite/:secret', inviteResponder); if (landingBaseRoutePath) { const landingRouter = express.Router(); landingRouter.get('/invite/:secret', inviteResponder); landingRouter.use( '/.well-known', express.static( '.well-known', // Necessary for apple-app-site-association file { setHeaders: res => res.setHeader('Content-Type', 'application/json'), }, ), ); landingRouter.use('/images', express.static('images')); landingRouter.use('/fonts', express.static('fonts')); landingRouter.use( '/compiled', express.static('landing_compiled', compiledFolderOptions), ); landingRouter.use('/', express.static('landing_icons')); landingRouter.post('/subscribe_email', emailSubscriptionResponder); landingRouter.get('*', landingHandler); server.use(landingBaseRoutePath, landingRouter); } if (commAppBaseRoutePath) { const commAppRouter = express.Router(); setupAppRouter(commAppRouter); server.use(commAppBaseRoutePath, commAppRouter); } if (squadCalBaseRoutePath) { const squadCalRouter = express.Router(); setupAppRouter(squadCalRouter); server.use(squadCalBaseRoutePath, squadCalRouter); } const listenAddress = (() => { if (process.env.COMM_LISTEN_ADDR) { return process.env.COMM_LISTEN_ADDR; } else if (process.env.NODE_ENV === 'development') { return undefined; } else { return 'localhost'; } })(); server.listen(parseInt(process.env.PORT, 10) || 3000, listenAddress); } })(); diff --git a/keyserver/src/middleware/endpoint_profiling.js b/keyserver/src/middleware/endpoint_profiling.js new file mode 100644 index 000000000..7cdd4b29d --- /dev/null +++ b/keyserver/src/middleware/endpoint_profiling.js @@ -0,0 +1,27 @@ +// @flow + +import type { $Request, $Response, NextFunction } from 'express'; + +function logEndpointMetrics( + req: $Request, + res: $Response, + next: NextFunction, +): void { + const endpointName = req.url; + const requestTime = Date.now(); + + const onCompletion = () => { + const responseTime = Date.now(); + const endpointDuration = responseTime - requestTime; + const contentSize = res.get('Content-Length') ?? 'NaN'; + console.log( + `${endpointName}, ${endpointDuration.toFixed(2)}ms, ${contentSize} bytes`, + ); + }; + + res.on('finish', onCompletion); + + next(); +} + +export { logEndpointMetrics };