diff --git a/README.md b/README.md index e385ec4..05ea2a4 100644 --- a/README.md +++ b/README.md @@ -82,11 +82,19 @@ You can control the output from Aikido Safe Chain using the `--safe-chain-loggin - `--safe-chain-logging=silent` - Suppresses all Aikido Safe Chain output except when malware is blocked. The package manager output is written to stdout as normal, and Safe Chain only writes a short message if it has blocked malware and causes the process to exit. -Example usage: + Example usage: -```shell -npm install express --safe-chain-logging=silent -``` + ```shell + npm install express --safe-chain-logging=silent + ``` + +- `--safe-chain-logging=verbose` - Enables detailed diagnostic output from Aikido Safe Chain. Useful for troubleshooting issues or understanding what Safe Chain is doing behind the scenes. + + Example usage: + + ```shell + npm install express --safe-chain-logging=verbose + ``` # Usage in CI/CD diff --git a/package.json b/package.json index 0193a82..6a5dec3 100644 --- a/package.json +++ b/package.json @@ -9,7 +9,8 @@ "scripts": { "test": "npm run test --workspace=packages/safe-chain --workspace=packages/safe-chain-bun", "test:e2e": "npm run test --workspace=test/e2e", - "lint": "npm run lint --workspace=packages/safe-chain" + "lint": "npm run lint --workspace=packages/safe-chain", + "typecheck": "npm run typecheck --workspace=packages/safe-chain" }, "repository": { "type": "git", diff --git a/packages/safe-chain/src/config/settings.js b/packages/safe-chain/src/config/settings.js index ad150b2..7f932a7 100644 --- a/packages/safe-chain/src/config/settings.js +++ b/packages/safe-chain/src/config/settings.js @@ -7,8 +7,13 @@ export function getLoggingLevel() { return LOGGING_SILENT; } + if (level === LOGGING_VERBOSE) { + return LOGGING_VERBOSE; + } + return LOGGING_NORMAL; } export const LOGGING_SILENT = "silent"; export const LOGGING_NORMAL = "normal"; +export const LOGGING_VERBOSE = "verbose"; diff --git a/packages/safe-chain/src/environment/userInteraction.js b/packages/safe-chain/src/environment/userInteraction.js index 3f690fb..3222874 100644 --- a/packages/safe-chain/src/environment/userInteraction.js +++ b/packages/safe-chain/src/environment/userInteraction.js @@ -2,12 +2,28 @@ import chalk from "chalk"; import ora from "ora"; import { isCi } from "./environment.js"; -import { getLoggingLevel, LOGGING_SILENT } from "../config/settings.js"; +import { + getLoggingLevel, + LOGGING_SILENT, + LOGGING_VERBOSE, +} from "../config/settings.js"; + +/** + * @type {{ bufferOutput: boolean, bufferedMessages:(() => void)[]}} + */ +const state = { + bufferOutput: false, + bufferedMessages: [], +}; function isSilentMode() { return getLoggingLevel() === LOGGING_SILENT; } +function isVerboseMode() { + return getLoggingLevel() === LOGGING_VERBOSE; +} + function emptyLine() { if (isSilentMode()) return; @@ -22,7 +38,7 @@ function emptyLine() { function writeInformation(message, ...optionalParams) { if (isSilentMode()) return; - console.log(message, ...optionalParams); + writeOrBuffer(() => console.log(message, ...optionalParams)); } /** @@ -36,7 +52,7 @@ function writeWarning(message, ...optionalParams) { if (!isCi()) { message = chalk.yellow(message); } - console.warn(message, ...optionalParams); + writeOrBuffer(() => console.warn(message, ...optionalParams)); } /** @@ -48,7 +64,7 @@ function writeError(message, ...optionalParams) { if (!isCi()) { message = chalk.red(message); } - console.error(message, ...optionalParams); + writeOrBuffer(() => console.error(message, ...optionalParams)); } function writeExitWithoutInstallingMaliciousPackages() { @@ -56,7 +72,30 @@ function writeExitWithoutInstallingMaliciousPackages() { if (!isCi()) { message = chalk.red(message); } - console.error(message); + writeOrBuffer(() => console.error(message)); +} + +/** + * @param {string} message + * @param {...any} optionalParams + * @returns {void} + */ +function writeVerbose(message, ...optionalParams) { + if (!isVerboseMode()) return; + + writeOrBuffer(() => console.log(message, ...optionalParams)); +} + +/** + * + * @param {() => void} messageFunction + */ +function writeOrBuffer(messageFunction) { + if (state.bufferOutput) { + state.bufferedMessages.push(messageFunction); + } else { + messageFunction(); + } } /** @@ -114,11 +153,27 @@ function startProcess(message) { } } +function startBufferingLogs() { + state.bufferOutput = true; + state.bufferedMessages = []; +} + +function writeBufferedLogsAndStopBuffering() { + state.bufferOutput = false; + for (const log of state.bufferedMessages) { + log(); + } + state.bufferedMessages = []; +} + export const ui = { + writeVerbose, writeInformation, writeWarning, writeError, writeExitWithoutInstallingMaliciousPackages, emptyLine, startProcess, + startBufferingLogs, + writeBufferedLogsAndStopBuffering, }; diff --git a/packages/safe-chain/src/main.js b/packages/safe-chain/src/main.js index fca1218..eea9257 100644 --- a/packages/safe-chain/src/main.js +++ b/packages/safe-chain/src/main.js @@ -12,13 +12,15 @@ import chalk from "chalk"; * @returns {Promise} */ export async function main(args) { + process.on("SIGINT", handleProcessTermination); + process.on("SIGTERM", handleProcessTermination); + const proxy = createSafeChainProxy(); await proxy.startServer(); // Global error handlers to log unhandled errors process.on("uncaughtException", (error) => { ui.writeError(`Safe-chain: Uncaught exception: ${error.message}`); - // @ts-expect-error writeVerbose will be added in a future PR ui.writeVerbose(`Stack trace: ${error.stack}`); process.exit(1); }); @@ -26,7 +28,6 @@ export async function main(args) { process.on("unhandledRejection", (reason) => { ui.writeError(`Safe-chain: Unhandled promise rejection: ${reason}`); if (reason instanceof Error) { - // @ts-expect-error writeVerbose will be added in a future PR ui.writeVerbose(`Stack trace: ${reason.stack}`); } process.exit(1); @@ -46,8 +47,16 @@ export async function main(args) { } } + // Buffer logs during package manager execution, this avoids interleaving + // of logs from the package manager and safe-chain + // Not doing this could cause bugs to disappear when cursor movement codes + // are written by the package manager while safe-chain is writing logs + ui.startBufferingLogs(); const packageManagerResult = await getPackageManager().runCommand(args); + // Write all buffered logs + ui.writeBufferedLogsAndStopBuffering(); + if (!proxy.verifyNoMaliciousPackages()) { return 1; } @@ -72,3 +81,7 @@ export async function main(args) { await proxy.stopServer(); } } + +function handleProcessTermination() { + ui.writeBufferedLogsAndStopBuffering(); +} diff --git a/packages/safe-chain/src/registryProxy/mitmRequestHandler.js b/packages/safe-chain/src/registryProxy/mitmRequestHandler.js index 5bbf38a..c990a98 100644 --- a/packages/safe-chain/src/registryProxy/mitmRequestHandler.js +++ b/packages/safe-chain/src/registryProxy/mitmRequestHandler.js @@ -9,9 +9,13 @@ import { ui } from "../environment/userInteraction.js"; * @param {(target: string) => Promise} isAllowed */ export function mitmConnect(req, clientSocket, isAllowed) { + ui.writeVerbose(`Safe-chain: Set up MITM tunnel for ${req.url}`); const { hostname } = new URL(`http://${req.url}`); - clientSocket.on("error", () => { + clientSocket.on("error", (err) => { + ui.writeVerbose( + `Safe-chain: Client socket error for ${req.url}: ${err.message}` + ); // NO-OP // This can happen if the client TCP socket sends RST instead of FIN. // Not subscribing to 'close' event will cause node to throw and crash. @@ -56,6 +60,7 @@ function createHttpsServer(hostname, isAllowed) { const targetUrl = `https://${hostname}${pathAndQuery}`; if (!(await isAllowed(targetUrl))) { + ui.writeVerbose(`Safe-chain: Blocking request to ${targetUrl}`); res.writeHead(403, "Forbidden - blocked by safe-chain"); res.end("Blocked by safe-chain"); return; @@ -96,7 +101,10 @@ function getRequestPathAndQuery(url) { function forwardRequest(req, hostname, res) { const proxyReq = createProxyRequest(hostname, req, res); - proxyReq.on("error", () => { + proxyReq.on("error", (err) => { + ui.writeVerbose( + `Safe-chain: Error occurred while proxying request: ${err.message}` + ); res.writeHead(502); res.end("Bad Gateway"); }); @@ -111,6 +119,9 @@ function forwardRequest(req, hostname, res) { }); req.on("end", () => { + ui.writeVerbose( + `Safe-chain: Finished proxying request to ${req.url} for ${hostname}` + ); proxyReq.end(); }); } diff --git a/packages/safe-chain/src/registryProxy/registryProxy.js b/packages/safe-chain/src/registryProxy/registryProxy.js index bd98ff5..ed103b2 100644 --- a/packages/safe-chain/src/registryProxy/registryProxy.js +++ b/packages/safe-chain/src/registryProxy/registryProxy.js @@ -138,6 +138,7 @@ function handleConnect(req, clientSocket, head) { mitmConnect(req, clientSocket, isAllowedUrl); } else { // For other hosts, just tunnel the request to the destination tcp socket + ui.writeVerbose(`Safe-chain: Tunneling request to ${req.url}`); tunnelRequest(req, clientSocket, head); } } diff --git a/packages/safe-chain/src/scanning/audit/index.js b/packages/safe-chain/src/scanning/audit/index.js index b6dfcc5..784b95f 100644 --- a/packages/safe-chain/src/scanning/audit/index.js +++ b/packages/safe-chain/src/scanning/audit/index.js @@ -1,3 +1,4 @@ +import { ui } from "../../environment/userInteraction.js"; import { MALWARE_STATUS_MALWARE, openMalwareDatabase, @@ -38,8 +39,14 @@ export async function auditChanges(changes) { ); if (malwarePackage) { + ui.writeVerbose( + `Safe-chain: Package ${change.name}@${change.version} is marked as malware: ${malwarePackage.status}` + ); disallowedChanges.push({ ...change, reason: malwarePackage.status }); } else { + ui.writeVerbose( + `Safe-chain: Package ${change.name}@${change.version} is clean` + ); allowedChanges.push(change); } }