From e2dc5d63723be4dfb61a05be12913dbf3f92528f Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Timo=20K=C3=B6ssler?= Date: Mon, 28 Oct 2024 16:02:41 +0100 Subject: [PATCH 01/11] Add new logger with levels --- library/agent/Agent.test.ts | 4 +- library/agent/Agent.ts | 51 +++++++++--------- library/agent/context/user.test.ts | 20 +++---- library/agent/context/user.ts | 44 ++++++++++------ library/agent/logger/Logger.ts | 5 +- library/agent/logger/LoggerConsole.ts | 15 ++++-- library/agent/logger/LoggerForTesting.ts | 11 +++- library/agent/logger/LoggerNoop.ts | 11 +++- library/agent/logger/getLogLevel.test.ts | 31 +++++++++++ library/agent/logger/getLogLevel.ts | 20 +++++++ library/agent/realtime/pollForChanges.ts | 6 +-- library/helpers/shouldEnableFirewall.ts | 2 +- .../shouldRateLimitRequest.test.ts | 52 +++++++++++-------- .../ratelimiting/shouldRateLimitRequest.ts | 7 ++- library/sinks/Fetch.ts | 24 +++++---- library/sinks/Undici.test.ts | 2 +- library/sinks/Undici.ts | 8 +-- 17 files changed, 205 insertions(+), 108 deletions(-) create mode 100644 library/agent/logger/getLogLevel.test.ts create mode 100644 library/agent/logger/getLogLevel.ts diff --git a/library/agent/Agent.test.ts b/library/agent/Agent.test.ts index b1088d941..bbbecffed 100644 --- a/library/agent/Agent.test.ts +++ b/library/agent/Agent.test.ts @@ -550,9 +550,9 @@ t.test("it logs when failed to report event", async () => { t.same(logger.getMessages(), [ "Starting agent...", "Found token, reporting enabled!", - "Failed to start agent", + "Failed to start agent: Failed to report event", "Heartbeat...", - "Failed to do heartbeat", + "Failed to send heartbeat event", "Failed to report attack", ]); }); diff --git a/library/agent/Agent.ts b/library/agent/Agent.ts index b5bf8e29f..cf035a775 100644 --- a/library/agent/Agent.ts +++ b/library/agent/Agent.ts @@ -82,13 +82,13 @@ export class Agent { list.push(`${pkg}@${incompatiblePackages[pkg]}`); } - this.logger.log( + this.logger.warn( `Unable to prevent prototype pollution, incompatible packages found: ${list.join(" ")}` ); } onPrototypePollutionPrevented() { - this.logger.log("Prevented prototype pollution!"); + this.logger.debug("Prevented prototype pollution!"); // Will be sent in the next heartbeat this.preventedPrototypePollution = true; @@ -123,7 +123,7 @@ export class Agent { module: string; method: string; }) { - this.logger.log( + this.logger.error( `Internal error in module "${module}" in method "${method}"\n${error.stack}` ); } @@ -191,7 +191,7 @@ export class Agent { this.timeoutInMS ) .catch(() => { - this.logger.log("Failed to report attack"); + this.logger.error("Failed to report attack"); }); } } @@ -201,7 +201,7 @@ export class Agent { */ private heartbeat(timeoutInMS = this.timeoutInMS) { this.sendHeartbeat(timeoutInMS).catch(() => { - this.logger.log("Failed to do heartbeat"); + this.logger.warn("Failed to send heartbeat event"); }); } @@ -218,7 +218,7 @@ export class Agent { if (typeof response.block === "boolean") { if (response.block !== this.block) { this.block = response.block; - this.logger.log( + this.logger.debug( `Block mode has been set to ${this.block ? "on" : "off"}` ); } @@ -258,7 +258,7 @@ export class Agent { private async sendHeartbeat(timeoutInMS: number) { if (this.token) { - this.logger.log("Heartbeat..."); + this.logger.debug("Heartbeat..."); const stats = this.statistics.getStats(); const routes = this.routes.asArray(); const outgoingDomains = this.hostnames.asArray(); @@ -296,14 +296,14 @@ export class Agent { */ private startHeartbeats() { if (this.serverless) { - this.logger.log( + this.logger.debug( "Running in serverless environment, not starting heartbeats" ); return; } if (!this.token) { - this.logger.log("No token provided, not starting heartbeats"); + this.logger.debug("No token provided, not starting heartbeats"); return; } @@ -392,21 +392,20 @@ export class Agent { this.started = true; - this.logger.log("Starting agent..."); + this.logger.debug("Starting agent..."); if (!this.block) { - this.logger.log("Dry mode enabled, no requests will be blocked!"); + this.logger.debug("Dry mode enabled, no requests will be blocked!"); } if (this.token) { - this.logger.log("Found token, reporting enabled!"); + this.logger.debug("Found token, reporting enabled!"); } else { - this.logger.log("No token provided, disabling reporting."); + this.logger.debug("No token provided, disabling reporting."); if (!this.block && !isAikidoCI()) { - // eslint-disable-next-line no-console - console.log( - "AIKIDO: Running in monitoring only mode without reporting to Aikido Cloud. Set AIKIDO_BLOCK=true to enable blocking." + this.logger.warn( + "Running in monitoring only mode without reporting to Aikido Cloud. Set AIKIDO_BLOCK=true to enable blocking." ); } } @@ -420,17 +419,17 @@ export class Agent { this.startHeartbeats(); this.startPollingForConfigChanges(); }) - .catch(() => { - this.logger.log("Failed to start agent"); + .catch((err) => { + this.logger.error(`Failed to start agent: ${err.message}`); }); } onFailedToWrapMethod(module: string, name: string) { - this.logger.log(`Failed to wrap method ${name} in module ${module}`); + this.logger.error(`Failed to wrap method ${name} in module ${module}`); } onFailedToWrapModule(module: string, error: Error) { - this.logger.log(`Failed to wrap module ${module}: ${error.message}`); + this.logger.error(`Failed to wrap module ${module}: ${error.message}`); } onPackageWrapped(name: string, details: WrappedPackage) { @@ -442,19 +441,19 @@ export class Agent { if (details.version) { if (details.supported) { - this.logger.log(`${name}@${details.version} is supported!`); + this.logger.info(`${name}@${details.version} is supported!`); } else { - this.logger.log(`${name}@${details.version} is not supported!`); + this.logger.warn(`${name}@${details.version} is not supported!`); } } } onFailedToWrapPackage(module: string) { - this.logger.log(`Failed to wrap package ${module}`); + this.logger.error(`Failed to wrap package ${module}`); } onFailedToWrapFile(module: string, filename: string) { - this.logger.log(`Failed to wrap file ${filename} in module ${module}`); + this.logger.error(`Failed to wrap file ${filename} in module ${module}`); } onConnectHostname(hostname: string, port: number | undefined) { @@ -480,8 +479,8 @@ export class Agent { return this.routes; } - log(message: string) { - this.logger.log(message); + getLogger() { + return this.logger; } async flushStats(timeoutInMS: number) { diff --git a/library/agent/context/user.test.ts b/library/agent/context/user.test.ts index 07649a7c2..2ea4a730f 100644 --- a/library/agent/context/user.test.ts +++ b/library/agent/context/user.test.ts @@ -126,31 +126,23 @@ t.test("it logs when setUser has invalid input", async () => { t.test( "it does not log warning when setUser is called before middleware", async () => { - const logs: string[] = []; - wrap(console, "warn", function warn() { - return function warn(message: string) { - logs.push(message); - }; - }); + const logger = new LoggerForTesting(); + createTestAgent({ logger }); const context = createContext(); runWithContext(context, () => { setUser({ id: "id" }); }); - t.same(logs, []); + t.same(logger.getMessages(), []); } ); t.test( "it logs warning when setUser is called after middleware (once)", async () => { - const logs: string[] = []; - wrap(console, "warn", function warn() { - return function warn(message: string) { - logs.push(message); - }; - }); + const logger = new LoggerForTesting(); + createTestAgent({ logger }); const context = createContext(); runWithContext(context, () => { @@ -159,7 +151,7 @@ t.test( setUser({ id: "id" }); }); - t.same(logs, [ + t.same(logger.getMessages(), [ "setUser(...) must be called before the Zen middleware is executed.", ]); } diff --git a/library/agent/context/user.ts b/library/agent/context/user.ts index 9a50765bc..696c013d2 100644 --- a/library/agent/context/user.ts +++ b/library/agent/context/user.ts @@ -1,5 +1,6 @@ /* eslint-disable max-lines-per-function */ import { isPlainObject } from "../../helpers/isPlainObject"; +import type { Agent } from "../Agent"; import { getInstance } from "../AgentSingleton"; import type { User } from "../Context"; import { ContextStorage } from "./ContextStorage"; @@ -14,33 +15,43 @@ export function setUser(u: { id: string | number; name?: string }) { const user = u as unknown; if (user === null || user === undefined) { - agent.log(`setUser(...) can not be called with null or undefined.`); + agent + .getLogger() + .error(`setUser(...) can not be called with null or undefined.`); return; } if (!isPlainObject(user)) { - agent.log( - `setUser(...) expects an object with 'id' and 'name' properties, found ${typeof user} instead.` - ); + agent + .getLogger() + .error( + `setUser(...) expects an object with 'id' and 'name' properties, found ${typeof user} instead.` + ); return; } if (!("id" in user)) { - agent.log(`setUser(...) expects an object with 'id' property.`); + agent + .getLogger() + .error(`setUser(...) expects an object with 'id' property.`); return; } if (typeof user.id !== "string" && typeof user.id !== "number") { - agent.log( - `setUser(...) expects an object with 'id' property of type string or number, found ${typeof user.id} instead.` - ); + agent + .getLogger() + .error( + `setUser(...) expects an object with 'id' property of type string or number, found ${typeof user.id} instead.` + ); return; } if (typeof user.id === "string" && user.id.length === 0) { - agent.log( - `setUser(...) expects an object with 'id' property non-empty string.` - ); + agent + .getLogger() + .error( + `setUser(...) expects an object with 'id' property non-empty string.` + ); return; } @@ -57,7 +68,7 @@ export function setUser(u: { id: string | number; name?: string }) { } if (context.executedMiddleware) { - logWarningSetUserCalledAfterMiddleware(); + logWarningSetUserCalledAfterMiddleware(agent); } context.user = validatedUser; @@ -73,15 +84,14 @@ export function setUser(u: { id: string | number; name?: string }) { let loggedWarningSetUserCalledAfterMiddleware = false; -function logWarningSetUserCalledAfterMiddleware() { +function logWarningSetUserCalledAfterMiddleware(agent: Agent) { if (loggedWarningSetUserCalledAfterMiddleware) { return; } - // eslint-disable-next-line no-console - console.warn( - `setUser(...) must be called before the Zen middleware is executed.` - ); + agent + .getLogger() + .warn(`setUser(...) must be called before the Zen middleware is executed.`); loggedWarningSetUserCalledAfterMiddleware = true; } diff --git a/library/agent/logger/Logger.ts b/library/agent/logger/Logger.ts index 0e3e4c158..e4a166cca 100644 --- a/library/agent/logger/Logger.ts +++ b/library/agent/logger/Logger.ts @@ -1,3 +1,6 @@ export interface Logger { - log(message: string): void; + debug(message: string): void; + info(message: string): void; + warn(message: string): void; + error(message: string): void; } diff --git a/library/agent/logger/LoggerConsole.ts b/library/agent/logger/LoggerConsole.ts index 1172b794f..981ad06bb 100644 --- a/library/agent/logger/LoggerConsole.ts +++ b/library/agent/logger/LoggerConsole.ts @@ -1,8 +1,17 @@ +/* eslint-disable no-console */ import { Logger } from "./Logger"; export class LoggerConsole implements Logger { - log(message: string) { - // eslint-disable-next-line no-console - console.log(`AIKIDO: ${message}`); + debug(message: string) { + console.debug(`Aikido: ${message}`); + } + info(message: string) { + console.info(`Aikido: ${message}`); + } + warn(message: string) { + console.warn(`Aikido: ${message}`); + } + error(message: string) { + console.error(`Aikido: ${message}`); } } diff --git a/library/agent/logger/LoggerForTesting.ts b/library/agent/logger/LoggerForTesting.ts index f559130e5..eeb98642e 100644 --- a/library/agent/logger/LoggerForTesting.ts +++ b/library/agent/logger/LoggerForTesting.ts @@ -3,7 +3,16 @@ import { Logger } from "./Logger"; export class LoggerForTesting implements Logger { private messages: string[] = []; - log(message: string) { + debug(message: string) { + this.messages.push(message); + } + info(message: string) { + this.messages.push(message); + } + warn(message: string) { + this.messages.push(message); + } + error(message: string) { this.messages.push(message); } diff --git a/library/agent/logger/LoggerNoop.ts b/library/agent/logger/LoggerNoop.ts index 228911f2a..d3e94cc31 100644 --- a/library/agent/logger/LoggerNoop.ts +++ b/library/agent/logger/LoggerNoop.ts @@ -1,7 +1,16 @@ import { Logger } from "./Logger"; export class LoggerNoop implements Logger { - log(message: string) { + debug(message: string) { + // noop + } + info(message: string) { + // noop + } + warn(message: string) { + // noop + } + error(message: string) { // noop } } diff --git a/library/agent/logger/getLogLevel.test.ts b/library/agent/logger/getLogLevel.test.ts new file mode 100644 index 000000000..24c308f93 --- /dev/null +++ b/library/agent/logger/getLogLevel.test.ts @@ -0,0 +1,31 @@ +import * as t from "tap"; +import { getLogLevel } from "./getLogLevel"; + +t.test("it returns the default log level", async (t) => { + t.equal(getLogLevel(), "info"); +}); + +t.test("it returns the log level from the environment variable", async (t) => { + process.env.AIKIDO_LOG_LEVEL = "debug"; + t.equal(getLogLevel(), "debug"); + process.env.AIKIDO_LOG_LEVEL = "info"; + t.equal(getLogLevel(), "info"); + process.env.AIKIDO_LOG_LEVEL = "warn"; + t.equal(getLogLevel(), "warn"); + process.env.AIKIDO_LOG_LEVEL = "error"; + t.equal(getLogLevel(), "error"); + process.env.AIKIDO_LOG_LEVEL = "123456"; + t.equal(getLogLevel(), "info"); + process.env.AIKIDO_LOG_LEVEL = undefined; +}); + +t.test("it respects the AIKIDO_DEBUG environment variable", async (t) => { + t.equal(getLogLevel(), "info"); + process.env.AIKIDO_DEBUG = "1"; + t.equal(getLogLevel(), "debug"); + process.env.AIKIDO_LOG_LEVEL = "warn"; + t.equal(getLogLevel(), "debug"); + process.env.AIKIDO_DEBUG = "0"; + t.equal(getLogLevel(), "warn"); + process.env.AIKIDO_DEBUG = undefined; +}); diff --git a/library/agent/logger/getLogLevel.ts b/library/agent/logger/getLogLevel.ts new file mode 100644 index 000000000..aa5ac1496 --- /dev/null +++ b/library/agent/logger/getLogLevel.ts @@ -0,0 +1,20 @@ +import { isDebugging } from "../../helpers/isDebugging"; + +const logLevels = ["debug", "info", "warn", "error"] as const; +const defaultLogLevel: AikidoLogLevel = "info"; + +type AikidoLogLevel = (typeof logLevels)[number]; + +export function getLogLevel(): AikidoLogLevel { + // Check for AIKIDO_DEBUG environment variable + if (isDebugging()) { + return "debug"; + } + + const envValue = process.env.AIKIDO_LOG_LEVEL; + if (envValue && logLevels.includes(envValue as any)) { + return envValue as AikidoLogLevel; + } + + return defaultLogLevel; +} diff --git a/library/agent/realtime/pollForChanges.ts b/library/agent/realtime/pollForChanges.ts index 75e5f3517..2c03eefb7 100644 --- a/library/agent/realtime/pollForChanges.ts +++ b/library/agent/realtime/pollForChanges.ts @@ -23,12 +23,12 @@ export function pollForChanges({ lastUpdatedAt: number; }) { if (!token) { - logger.log("No token provided, not polling for config updates"); + logger.debug("No token provided, not polling for config updates"); return; } if (serverless) { - logger.log( + logger.debug( "Running in serverless environment, not polling for config updates" ); return; @@ -42,7 +42,7 @@ export function pollForChanges({ interval = setInterval(() => { check(token, onConfigUpdate).catch(() => { - logger.log("Failed to check for config updates"); + logger.error("Failed to check for config updates"); }); }, 60 * 1000); diff --git a/library/helpers/shouldEnableFirewall.ts b/library/helpers/shouldEnableFirewall.ts index 1cf5d6505..67f8a4e34 100644 --- a/library/helpers/shouldEnableFirewall.ts +++ b/library/helpers/shouldEnableFirewall.ts @@ -29,7 +29,7 @@ export default function shouldEnableFirewall() { if (!isAikidoCI()) { // eslint-disable-next-line no-console - console.log( + console.warn( "AIKIDO: Zen is disabled. Configure one of the following environment variables to enable it: AIKIDO_BLOCK, AIKIDO_TOKEN, AIKIDO_DEBUG." ); } diff --git a/library/ratelimiting/shouldRateLimitRequest.test.ts b/library/ratelimiting/shouldRateLimitRequest.test.ts index c7898f96d..9d73dfc33 100644 --- a/library/ratelimiting/shouldRateLimitRequest.test.ts +++ b/library/ratelimiting/shouldRateLimitRequest.test.ts @@ -5,7 +5,7 @@ import { Endpoint } from "../agent/Config"; import type { Context } from "../agent/Context"; import { shouldRateLimitRequest } from "./shouldRateLimitRequest"; import { createTestAgent } from "../helpers/createTestAgent"; -import { wrap } from "../helpers/wrap"; +import { LoggerForTesting } from "../agent/logger/LoggerForTesting"; function createContext( remoteAddress: string | undefined = undefined, @@ -28,16 +28,10 @@ function createContext( }; } -const logs: string[] = []; -wrap(console, "warn", function warn() { - return function warn(message: string) { - logs.push(message); - }; -}); - async function createAgent( endpoints: Endpoint[] = [], - allowedIpAddresses: string[] = [] + allowedIpAddresses: string[] = [], + logger?: LoggerForTesting ) { const agent = createTestAgent({ block: false, @@ -50,6 +44,7 @@ async function createAgent( configUpdatedAt: 0, endpoints: endpoints, }), + logger, }); agent.start([]); @@ -472,20 +467,29 @@ t.test( t.test( "it does not consume rate limit for user a second time (same request)", async (t) => { - const agent = await createAgent([ - { - method: "POST", - route: "/login", - forceProtectionOff: false, - rateLimiting: { - enabled: true, - maxRequests: 3, - windowSizeInMS: 1000, + const logger = new LoggerForTesting(); + const agent = await createAgent( + [ + { + method: "POST", + route: "/login", + forceProtectionOff: false, + rateLimiting: { + enabled: true, + maxRequests: 3, + windowSizeInMS: 1000, + }, }, - }, - ]); + ], + [], + logger + ); - t.same(logs, []); + t.notOk( + logger + .getMessages() + .includes("Zen.addMiddleware(...) should be called only once.") + ); const ctx = createContext("1.2.3.4", "123"); @@ -502,6 +506,10 @@ t.test( block: false, }); - t.same(logs, ["Zen.addMiddleware(...) should be called only once."]); + t.ok( + logger + .getMessages() + .includes("Zen.addMiddleware(...) should be called only once.") + ); } ); diff --git a/library/ratelimiting/shouldRateLimitRequest.ts b/library/ratelimiting/shouldRateLimitRequest.ts index 965f2a766..97a3b30a6 100644 --- a/library/ratelimiting/shouldRateLimitRequest.ts +++ b/library/ratelimiting/shouldRateLimitRequest.ts @@ -24,7 +24,7 @@ export function shouldRateLimitRequest( // Do not consume rate limit for the same request a second time // (Might happen if the user adds the middleware multiple times) if (context.consumedRateLimit) { - logWarningIfMiddlewareExecutedTwice(); + logWarningIfMiddlewareExecutedTwice(agent); return { block: false }; } @@ -93,13 +93,12 @@ export function shouldRateLimitRequest( let loggedWarningIfMiddlewareExecutedTwice = false; -function logWarningIfMiddlewareExecutedTwice(): void { +function logWarningIfMiddlewareExecutedTwice(agent: Agent) { if (loggedWarningIfMiddlewareExecutedTwice) { return; } - // eslint-disable-next-line no-console - console.warn(`Zen.addMiddleware(...) should be called only once.`); + agent.getLogger().warn(`Zen.addMiddleware(...) should be called only once.`); loggedWarningIfMiddlewareExecutedTwice = true; } diff --git a/library/sinks/Fetch.ts b/library/sinks/Fetch.ts index a637060e3..b5bd1ad06 100644 --- a/library/sinks/Fetch.ts +++ b/library/sinks/Fetch.ts @@ -94,16 +94,20 @@ export class Fetch implements Wrapper { const dispatcher = globalThis[undiciGlobalDispatcherSymbol]; if (!dispatcher) { - agent.log( - `global dispatcher not found for fetch, we can't provide protection!` - ); + agent + .getLogger() + .warn( + `Global dispatcher of fetch not found, we can't protect fetch(...) against SSRF attacks!` + ); return; } if (dispatcher.constructor.name !== "Agent") { - agent.log( - `Expected Agent as global dispatcher for fetch but found ${dispatcher.constructor.name}, we can't provide protection!` - ); + agent + .getLogger() + .warn( + `Expected Agent as global dispatcher for fetch but found ${dispatcher.constructor.name}, we can't protect fetch(...) against SSRF attacks!` + ); return; } @@ -122,9 +126,11 @@ export class Fetch implements Wrapper { agent ); } catch (error) { - agent.log( - `Failed to patch global dispatcher for fetch, we can't provide protection!` - ); + agent + .getLogger() + .error( + `Failed to patch global dispatcher for fetch, we can't protect fetch(...) against SSRF attacks!` + ); } } diff --git a/library/sinks/Undici.test.ts b/library/sinks/Undici.test.ts index c1b5bf343..1b2ad224b 100644 --- a/library/sinks/Undici.test.ts +++ b/library/sinks/Undici.test.ts @@ -323,7 +323,7 @@ t.test( logger.clear(); setGlobalDispatcher(new UndiciAgent({})); t.same(logger.getMessages(), [ - "undici.setGlobalDispatcher was called, we can't provide protection!", + "undici.setGlobalDispatcher was called, we can't protect undici against SSRF attacks!", ]); } ); diff --git a/library/sinks/Undici.ts b/library/sinks/Undici.ts index f699ed60e..b9d3055d3 100644 --- a/library/sinks/Undici.ts +++ b/library/sinks/Undici.ts @@ -112,9 +112,11 @@ export class Undici implements Wrapper { wrapExport(exports, "setGlobalDispatcher", pkgInfo, { inspectArgs: (args, agent) => { if (this.patchedGlobalDispatcher) { - agent.log( - `undici.setGlobalDispatcher was called, we can't provide protection!` - ); + agent + .getLogger() + .warn( + `undici.setGlobalDispatcher was called, we can't protect undici against SSRF attacks!` + ); } }, }); From 4d8ea07715d716dabfb4dbc32f5bff540bd22962 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Timo=20K=C3=B6ssler?= Date: Mon, 28 Oct 2024 17:10:19 +0100 Subject: [PATCH 02/11] Check for log level, add additional logs --- library/agent/Agent.ts | 13 +++-- library/agent/context/user.test.ts | 1 - library/agent/hooks/wrapExport.ts | 8 ++- library/agent/hooks/wrapNewInstance.ts | 8 ++- library/agent/logger/LoggerConsole.ts | 17 +++++-- library/agent/logger/getLogLevel.test.ts | 31 ------------ library/agent/logger/getLogLevel.ts | 20 -------- library/agent/logger/logLevel.test.ts | 64 ++++++++++++++++++++++++ library/agent/logger/logLevel.ts | 30 +++++++++++ library/agent/protect.ts | 8 +-- 10 files changed, 131 insertions(+), 69 deletions(-) delete mode 100644 library/agent/logger/getLogLevel.test.ts delete mode 100644 library/agent/logger/getLogLevel.ts create mode 100644 library/agent/logger/logLevel.test.ts create mode 100644 library/agent/logger/logLevel.ts diff --git a/library/agent/Agent.ts b/library/agent/Agent.ts index cf035a775..eb255ac18 100644 --- a/library/agent/Agent.ts +++ b/library/agent/Agent.ts @@ -10,7 +10,7 @@ import { RateLimiter } from "../ratelimiting/RateLimiter"; import { ReportingAPI, ReportingAPIResponse } from "./api/ReportingAPI"; import { AgentInfo } from "./api/Event"; import { Token } from "./api/Token"; -import { Kind } from "./Attack"; +import { attackKindHumanName, Kind } from "./Attack"; import { pollForChanges } from "./realtime/pollForChanges"; import { Context } from "./Context"; import { Hostnames } from "./Hostnames"; @@ -154,6 +154,9 @@ export class Agent { metadata: Record; payload: unknown; }) { + this.logger.info( + `Zen has blocked ${attackKindHumanName(kind)}: kind="${kind}" operation="${operation}(...)" source="${source}${path}" ip="${request.remoteAddress}" blocked=${blocked}` + ); if (this.token) { this.api .report( @@ -424,8 +427,10 @@ export class Agent { }); } - onFailedToWrapMethod(module: string, name: string) { - this.logger.error(`Failed to wrap method ${name} in module ${module}`); + onFailedToWrapMethod(module: string, name: string, error: Error) { + this.logger.error( + `Failed to wrap method ${name} in module ${module}: ${error.message}` + ); } onFailedToWrapModule(module: string, error: Error) { @@ -441,7 +446,7 @@ export class Agent { if (details.version) { if (details.supported) { - this.logger.info(`${name}@${details.version} is supported!`); + this.logger.debug(`${name}@${details.version} is supported!`); } else { this.logger.warn(`${name}@${details.version} is not supported!`); } diff --git a/library/agent/context/user.test.ts b/library/agent/context/user.test.ts index 2ea4a730f..4dce42034 100644 --- a/library/agent/context/user.test.ts +++ b/library/agent/context/user.test.ts @@ -1,5 +1,4 @@ import * as t from "tap"; -import { wrap } from "../../helpers/wrap"; import { type Context, getContext, diff --git a/library/agent/hooks/wrapExport.ts b/library/agent/hooks/wrapExport.ts index 4c9624975..4beca20ab 100644 --- a/library/agent/hooks/wrapExport.ts +++ b/library/agent/hooks/wrapExport.ts @@ -116,7 +116,13 @@ export function wrapExport( } ); } catch (error) { - agent.onFailedToWrapMethod(pkgInfo.name, methodName || "default export"); + if (error instanceof Error) { + agent.onFailedToWrapMethod( + pkgInfo.name, + methodName || "default export", + error + ); + } } } diff --git a/library/agent/hooks/wrapNewInstance.ts b/library/agent/hooks/wrapNewInstance.ts index 3923de4c8..1530ffd82 100644 --- a/library/agent/hooks/wrapNewInstance.ts +++ b/library/agent/hooks/wrapNewInstance.ts @@ -35,6 +35,12 @@ export function wrapNewInstance( } ); } catch (error) { - agent.onFailedToWrapMethod(pkgInfo.name, className || "default export"); + if (error instanceof Error) { + agent.onFailedToWrapMethod( + pkgInfo.name, + className || "default export", + error + ); + } } } diff --git a/library/agent/logger/LoggerConsole.ts b/library/agent/logger/LoggerConsole.ts index 981ad06bb..4e5756180 100644 --- a/library/agent/logger/LoggerConsole.ts +++ b/library/agent/logger/LoggerConsole.ts @@ -1,17 +1,26 @@ /* eslint-disable no-console */ import { Logger } from "./Logger"; +import { AikidoLogLevel, shouldLog } from "./logLevel"; export class LoggerConsole implements Logger { debug(message: string) { - console.debug(`Aikido: ${message}`); + if (shouldLog(AikidoLogLevel.debug)) { + console.debug(`Aikido: ${message}`); + } } info(message: string) { - console.info(`Aikido: ${message}`); + if (shouldLog(AikidoLogLevel.info)) { + console.info(`Aikido: ${message}`); + } } warn(message: string) { - console.warn(`Aikido: ${message}`); + if (shouldLog(AikidoLogLevel.warn)) { + console.warn(`Aikido: ${message}`); + } } error(message: string) { - console.error(`Aikido: ${message}`); + if (shouldLog(AikidoLogLevel.error)) { + console.error(`Aikido: ${message}`); + } } } diff --git a/library/agent/logger/getLogLevel.test.ts b/library/agent/logger/getLogLevel.test.ts deleted file mode 100644 index 24c308f93..000000000 --- a/library/agent/logger/getLogLevel.test.ts +++ /dev/null @@ -1,31 +0,0 @@ -import * as t from "tap"; -import { getLogLevel } from "./getLogLevel"; - -t.test("it returns the default log level", async (t) => { - t.equal(getLogLevel(), "info"); -}); - -t.test("it returns the log level from the environment variable", async (t) => { - process.env.AIKIDO_LOG_LEVEL = "debug"; - t.equal(getLogLevel(), "debug"); - process.env.AIKIDO_LOG_LEVEL = "info"; - t.equal(getLogLevel(), "info"); - process.env.AIKIDO_LOG_LEVEL = "warn"; - t.equal(getLogLevel(), "warn"); - process.env.AIKIDO_LOG_LEVEL = "error"; - t.equal(getLogLevel(), "error"); - process.env.AIKIDO_LOG_LEVEL = "123456"; - t.equal(getLogLevel(), "info"); - process.env.AIKIDO_LOG_LEVEL = undefined; -}); - -t.test("it respects the AIKIDO_DEBUG environment variable", async (t) => { - t.equal(getLogLevel(), "info"); - process.env.AIKIDO_DEBUG = "1"; - t.equal(getLogLevel(), "debug"); - process.env.AIKIDO_LOG_LEVEL = "warn"; - t.equal(getLogLevel(), "debug"); - process.env.AIKIDO_DEBUG = "0"; - t.equal(getLogLevel(), "warn"); - process.env.AIKIDO_DEBUG = undefined; -}); diff --git a/library/agent/logger/getLogLevel.ts b/library/agent/logger/getLogLevel.ts deleted file mode 100644 index aa5ac1496..000000000 --- a/library/agent/logger/getLogLevel.ts +++ /dev/null @@ -1,20 +0,0 @@ -import { isDebugging } from "../../helpers/isDebugging"; - -const logLevels = ["debug", "info", "warn", "error"] as const; -const defaultLogLevel: AikidoLogLevel = "info"; - -type AikidoLogLevel = (typeof logLevels)[number]; - -export function getLogLevel(): AikidoLogLevel { - // Check for AIKIDO_DEBUG environment variable - if (isDebugging()) { - return "debug"; - } - - const envValue = process.env.AIKIDO_LOG_LEVEL; - if (envValue && logLevels.includes(envValue as any)) { - return envValue as AikidoLogLevel; - } - - return defaultLogLevel; -} diff --git a/library/agent/logger/logLevel.test.ts b/library/agent/logger/logLevel.test.ts new file mode 100644 index 000000000..60f1d973c --- /dev/null +++ b/library/agent/logger/logLevel.test.ts @@ -0,0 +1,64 @@ +import * as t from "tap"; +import { getLogLevel, AikidoLogLevel, shouldLog } from "./logLevel"; + +const defaultLogLevel = AikidoLogLevel.info; + +t.test("it returns the default log level", async (t) => { + t.equal(getLogLevel(), defaultLogLevel); +}); + +t.test("it returns the log level from the environment variable", async (t) => { + process.env.AIKIDO_LOG_LEVEL = "debug"; + t.equal(getLogLevel(), AikidoLogLevel.debug); + process.env.AIKIDO_LOG_LEVEL = "info"; + t.equal(getLogLevel(), AikidoLogLevel.info); + process.env.AIKIDO_LOG_LEVEL = "warn"; + t.equal(getLogLevel(), AikidoLogLevel.warn); + process.env.AIKIDO_LOG_LEVEL = "error"; + t.equal(getLogLevel(), AikidoLogLevel.error); + process.env.AIKIDO_LOG_LEVEL = "123456"; + t.equal(getLogLevel(), defaultLogLevel); + process.env.AIKIDO_LOG_LEVEL = undefined; +}); + +t.test("it respects the AIKIDO_DEBUG environment variable", async (t) => { + t.equal(getLogLevel(), defaultLogLevel); + process.env.AIKIDO_DEBUG = "1"; + t.equal(getLogLevel(), AikidoLogLevel.debug); + process.env.AIKIDO_LOG_LEVEL = "warn"; + t.equal(getLogLevel(), AikidoLogLevel.debug); + process.env.AIKIDO_DEBUG = "0"; + t.equal(getLogLevel(), AikidoLogLevel.warn); + process.env.AIKIDO_DEBUG = undefined; +}); + +t.test("test shouldLog", async (t) => { + process.env.AIKIDO_LOG_LEVEL = "debug"; + t.equal(getLogLevel(), AikidoLogLevel.debug); + t.equal(true, shouldLog(AikidoLogLevel.debug)); + t.equal(true, shouldLog(AikidoLogLevel.info)); + t.equal(true, shouldLog(AikidoLogLevel.warn)); + t.equal(true, shouldLog(AikidoLogLevel.error)); + process.env.AIKIDO_LOG_LEVEL = "info"; + t.equal(getLogLevel(), AikidoLogLevel.info); + t.equal(false, shouldLog(AikidoLogLevel.debug)); + t.equal(true, shouldLog(AikidoLogLevel.info)); + t.equal(true, shouldLog(AikidoLogLevel.warn)); + t.equal(true, shouldLog(AikidoLogLevel.error)); + process.env.AIKIDO_LOG_LEVEL = "warn"; + t.equal(getLogLevel(), AikidoLogLevel.warn); + t.equal(false, shouldLog(AikidoLogLevel.debug)); + t.equal(false, shouldLog(AikidoLogLevel.info)); + t.equal(true, shouldLog(AikidoLogLevel.warn)); + t.equal(true, shouldLog(AikidoLogLevel.error)); + process.env.AIKIDO_LOG_LEVEL = "error"; + t.equal(getLogLevel(), AikidoLogLevel.error); + t.equal(false, shouldLog(AikidoLogLevel.debug)); + t.equal(false, shouldLog(AikidoLogLevel.info)); + t.equal(false, shouldLog(AikidoLogLevel.warn)); + t.equal(true, shouldLog(AikidoLogLevel.error)); + process.env.AIKIDO_LOG_LEVEL = undefined; + t.equal(getLogLevel(), defaultLogLevel); + t.equal(false, shouldLog(AikidoLogLevel.debug)); + t.equal(true, shouldLog(AikidoLogLevel.info)); +}); diff --git a/library/agent/logger/logLevel.ts b/library/agent/logger/logLevel.ts new file mode 100644 index 000000000..d329995ee --- /dev/null +++ b/library/agent/logger/logLevel.ts @@ -0,0 +1,30 @@ +import { isDebugging } from "../../helpers/isDebugging"; + +export enum AikidoLogLevel { + debug = 1, + info = 2, + warn = 3, + error = 4, +} + +const logLevelKeys = Object.keys(AikidoLogLevel); +const defaultLogLevel = AikidoLogLevel.info; + +export function getLogLevel(): AikidoLogLevel { + // Check for AIKIDO_DEBUG environment variable + if (isDebugging()) { + return AikidoLogLevel.debug; + } + + const envValue = process.env.AIKIDO_LOG_LEVEL; + if (envValue && logLevelKeys.includes(envValue)) { + return AikidoLogLevel[envValue as keyof typeof AikidoLogLevel]; + } + + return defaultLogLevel; +} + +export function shouldLog(messageLogLevel: AikidoLogLevel) { + const currentLogLevel = getLogLevel(); + return messageLogLevel >= currentLogLevel; +} diff --git a/library/agent/protect.ts b/library/agent/protect.ts index 40c8e8eaf..a4f9c161d 100644 --- a/library/agent/protect.ts +++ b/library/agent/protect.ts @@ -31,7 +31,6 @@ import { Token } from "./api/Token"; import { getAPIURL } from "./getAPIURL"; import { Logger } from "./logger/Logger"; import { LoggerConsole } from "./logger/LoggerConsole"; -import { LoggerNoop } from "./logger/LoggerNoop"; import { GraphQL } from "../sources/GraphQL"; import { Xml2js } from "../sources/Xml2js"; import { FastXmlParser } from "../sources/FastXmlParser"; @@ -41,7 +40,6 @@ import { Hapi } from "../sources/Hapi"; import { Shelljs } from "../sinks/Shelljs"; import { NodeSQLite } from "../sinks/NodeSqlite"; import { BetterSQLite3 } from "../sinks/BetterSQLite3"; -import { isDebugging } from "../helpers/isDebugging"; import { shouldBlock } from "../helpers/shouldBlock"; import { Postgresjs } from "../sinks/Postgresjs"; import { Fastify } from "../sources/Fastify"; @@ -49,11 +47,7 @@ import { Koa } from "../sources/Koa"; import { KoaRouter } from "../sources/KoaRouter"; function getLogger(): Logger { - if (isDebugging()) { - return new LoggerConsole(); - } - - return new LoggerNoop(); + return new LoggerConsole(); } function validatesToken(api: ReportingAPI) { From 6681078b374309d5551a59dda0c8683f80613b65 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Timo=20K=C3=B6ssler?= Date: Mon, 28 Oct 2024 17:29:36 +0100 Subject: [PATCH 03/11] Escape log and fix tests --- end2end/tests/lambda-mongodb.test.js | 4 ++-- library/agent/Agent.test.ts | 1 + library/agent/Agent.ts | 3 ++- library/agent/hooks/wrapNewInstance.test.ts | 2 +- library/helpers/escapeLog.test.ts | 11 +++++++++++ library/helpers/escapeLog.ts | 9 +++++++++ 6 files changed, 26 insertions(+), 4 deletions(-) create mode 100644 library/helpers/escapeLog.test.ts create mode 100644 library/helpers/escapeLog.ts diff --git a/end2end/tests/lambda-mongodb.test.js b/end2end/tests/lambda-mongodb.test.js index bfe00787c..8913126e5 100644 --- a/end2end/tests/lambda-mongodb.test.js +++ b/end2end/tests/lambda-mongodb.test.js @@ -18,7 +18,7 @@ t.before(async () => { t.test("it does not block by default", async (t) => { const { stdout, stderr } = await execAsync( - "npx --node-options='--no-deprecation --preserve-symlinks' --loglevel=error serverless@3.38.0 invoke local --function login --path payloads/nosql-injection-request.json", + "npx --node-options='--no-deprecation --preserve-symlinks' --loglevel=error serverless@3.38.0 invoke local -e AIKIDO_LOG_LEVEL=error --function login --path payloads/nosql-injection-request.json", { cwd: directory, } @@ -39,7 +39,7 @@ t.test("it does not block by default", async (t) => { t.test("it blocks when AIKIDO_BLOCKING is true", async (t) => { const { stdout, stderr } = await execAsync( - "npx --node-options='--no-deprecation --preserve-symlinks' --loglevel=error serverless@3.38.0 invoke local -e AIKIDO_BLOCKING=true --function login --path payloads/nosql-injection-request.json", + "npx --node-options='--no-deprecation --preserve-symlinks' --loglevel=error serverless@3.38.0 invoke local -e AIKIDO_BLOCKING=true -e AIKIDO_LOG_LEVEL=error --function login --path payloads/nosql-injection-request.json", { cwd: directory, } diff --git a/library/agent/Agent.test.ts b/library/agent/Agent.test.ts index bbbecffed..25cf46b3a 100644 --- a/library/agent/Agent.test.ts +++ b/library/agent/Agent.test.ts @@ -553,6 +553,7 @@ t.test("it logs when failed to report event", async () => { "Failed to start agent: Failed to report event", "Heartbeat...", "Failed to send heartbeat event", + 'Zen has blocked a NoSQL injection: kind="nosql_injection" operation="operation(...)" source="body.nested" ip="::1"', "Failed to report attack", ]); }); diff --git a/library/agent/Agent.ts b/library/agent/Agent.ts index eb255ac18..e45f46324 100644 --- a/library/agent/Agent.ts +++ b/library/agent/Agent.ts @@ -23,6 +23,7 @@ import { Users } from "./Users"; import { wrapInstalledPackages } from "./wrapInstalledPackages"; import { Wrapper } from "./Wrapper"; import { isAikidoCI } from "../helpers/isAikidoCI"; +import { escapeLog } from "../helpers/escapeLog"; type WrappedPackage = { version: string | null; supported: boolean }; @@ -155,7 +156,7 @@ export class Agent { payload: unknown; }) { this.logger.info( - `Zen has blocked ${attackKindHumanName(kind)}: kind="${kind}" operation="${operation}(...)" source="${source}${path}" ip="${request.remoteAddress}" blocked=${blocked}` + `Zen has ${blocked ? "blocked" : "detected"} ${attackKindHumanName(kind)}: kind="${kind}" operation="${operation}(...)" source="${source}${escapeLog(path)}" ip="${escapeLog(request.remoteAddress)}"` ); if (this.token) { this.api diff --git a/library/agent/hooks/wrapNewInstance.test.ts b/library/agent/hooks/wrapNewInstance.test.ts index fa22a7201..2a7490c47 100644 --- a/library/agent/hooks/wrapNewInstance.test.ts +++ b/library/agent/hooks/wrapNewInstance.test.ts @@ -66,7 +66,7 @@ t.test("Wrap non existing class", async (t) => { ); t.same(logger.getMessages(), [ - "Failed to wrap method test in module testmod", + "Failed to wrap method test in module testmod: no original function test to wrap", ]); }); diff --git a/library/helpers/escapeLog.test.ts b/library/helpers/escapeLog.test.ts new file mode 100644 index 000000000..9873a3b08 --- /dev/null +++ b/library/helpers/escapeLog.test.ts @@ -0,0 +1,11 @@ +import * as t from "tap"; +import { escapeLog } from "./escapeLog"; + +t.test("it escapes log messages", async (t) => { + t.equal(escapeLog("Hello\nWorld"), "Hello World"); + t.equal(escapeLog("Hello`World"), "Hello'World"); + t.equal(escapeLog("Hello\n`World"), "Hello 'World"); + t.equal(escapeLog("Hello`World\n"), "Hello'World "); + t.equal(escapeLog('Hello "World"'), "Hello 'World'"); + t.equal(escapeLog(undefined), ""); +}); diff --git a/library/helpers/escapeLog.ts b/library/helpers/escapeLog.ts new file mode 100644 index 000000000..aeee7d562 --- /dev/null +++ b/library/helpers/escapeLog.ts @@ -0,0 +1,9 @@ +/** + * Remove new line characters and escape backticks from a log message. + */ +export function escapeLog(log: string | undefined): string { + if (!log || typeof log !== "string") { + return ""; + } + return log.replace(/\n/g, " ").replace(/[`"]/g, "'"); +} From 68497ca357fce6fbad54dc7a0d3d15f73cf806ce Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Timo=20K=C3=B6ssler?= Date: Mon, 16 Dec 2024 17:21:33 +0100 Subject: [PATCH 04/11] Fix logger usage after merge --- library/agent/Agent.ts | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/library/agent/Agent.ts b/library/agent/Agent.ts index 54fb82b5e..5182ec1e3 100644 --- a/library/agent/Agent.ts +++ b/library/agent/Agent.ts @@ -159,7 +159,7 @@ export class Agent { payload: unknown; }) { this.logger.info( - `Zen has ${blocked ? "blocked" : "detected"} ${attackKindHumanName(kind)}: kind="${kind}" operation="${operation}(...)" source="${source}${escapeLog(path)}" ip="${escapeLog(request.remoteAddress)}"` + `Zen has ${blocked ? "blocked" : "detected"} ${attackKindHumanName(kind)}: kind="${kind}" operation="${operation}(...)" source="${source}${escapeLog((paths || []).join())}" ip="${escapeLog(request.remoteAddress)}"` ); if (this.token) { this.api @@ -355,7 +355,7 @@ export class Agent { const blockedIps = await fetchBlockedIPAddresses(this.token); this.serviceConfig.updateBlockedIPAddresses(blockedIps); } catch (error: any) { - this.logger.log( + this.logger.error( `Failed to update blocked IP addresses: ${error.message}` ); } @@ -370,7 +370,7 @@ export class Agent { onConfigUpdate: (config) => { this.updateServiceConfig({ success: true, ...config }); this.updateBlockedIPAddresses().catch((error) => { - this.logger.log( + this.logger.error( `Failed to update blocked IP addresses: ${error.message}` ); }); From 7559a48aa10e842a3e4e879bf5b7e98bce9bc9ca Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Timo=20K=C3=B6ssler?= Date: Fri, 20 Dec 2024 11:15:55 +0100 Subject: [PATCH 05/11] Fix after merge --- library/agent/hooks/wrapNewInstance.test.ts | 6 ++++-- library/agent/hooks/wrapNewInstance.ts | 11 +++++++---- 2 files changed, 11 insertions(+), 6 deletions(-) diff --git a/library/agent/hooks/wrapNewInstance.test.ts b/library/agent/hooks/wrapNewInstance.test.ts index 381b5848e..0afb32fa9 100644 --- a/library/agent/hooks/wrapNewInstance.test.ts +++ b/library/agent/hooks/wrapNewInstance.test.ts @@ -115,7 +115,9 @@ t.test("Errors in interceptor are caught", async (t) => { const instance = new exports.test("input"); t.same(instance.getInput(), "input"); - t.same(logger.getMessages(), ["Failed to wrap method test in module test"]); + t.same(logger.getMessages(), [ + "Failed to wrap method test in module test: test error", + ]); }); t.test("Return value from interceptor is returned", async (t) => { @@ -162,6 +164,6 @@ t.test("Logs error when wrapping default export", async (t) => { const instance = new exports("input"); t.same(instance.getInput(), "input"); t.same(logger.getMessages(), [ - "Failed to wrap method default export in module test", + "Failed to wrap method default export in module test: test error", ]); }); diff --git a/library/agent/hooks/wrapNewInstance.ts b/library/agent/hooks/wrapNewInstance.ts index 114442577..13b575473 100644 --- a/library/agent/hooks/wrapNewInstance.ts +++ b/library/agent/hooks/wrapNewInstance.ts @@ -34,10 +34,13 @@ export function wrapNewInstance( return returnVal; } } catch (error) { - agent.onFailedToWrapMethod( - pkgInfo.name, - className || "default export" - ); + if (error instanceof Error) { + agent.onFailedToWrapMethod( + pkgInfo.name, + className || "default export", + error + ); + } } return newInstance; From 70a6ff2829e24899338a806fdebba7b3d2612bbc Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Timo=20K=C3=B6ssler?= Date: Fri, 20 Dec 2024 13:22:55 +0100 Subject: [PATCH 06/11] Use obj instead of enum --- library/agent/logger/logLevel.ts | 14 ++++++++------ 1 file changed, 8 insertions(+), 6 deletions(-) diff --git a/library/agent/logger/logLevel.ts b/library/agent/logger/logLevel.ts index d329995ee..90ba45a3b 100644 --- a/library/agent/logger/logLevel.ts +++ b/library/agent/logger/logLevel.ts @@ -1,11 +1,13 @@ import { isDebugging } from "../../helpers/isDebugging"; -export enum AikidoLogLevel { - debug = 1, - info = 2, - warn = 3, - error = 4, -} +export const AikidoLogLevel = { + debug: 1, + info: 2, + warn: 3, + error: 4, +} as const; + +type AikidoLogLevel = (typeof AikidoLogLevel)[keyof typeof AikidoLogLevel]; const logLevelKeys = Object.keys(AikidoLogLevel); const defaultLogLevel = AikidoLogLevel.info; From d5fe9a7e3aad6cd87b77db14f6f46d766f42c99b Mon Sep 17 00:00:00 2001 From: BitterPanda <28490560+bitterpanda63@users.noreply.github.com> Date: Tue, 24 Dec 2024 11:09:49 +0000 Subject: [PATCH 07/11] Update library/agent/logger/logLevel.ts --- library/agent/logger/logLevel.ts | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/library/agent/logger/logLevel.ts b/library/agent/logger/logLevel.ts index 90ba45a3b..b09984fa0 100644 --- a/library/agent/logger/logLevel.ts +++ b/library/agent/logger/logLevel.ts @@ -13,7 +13,7 @@ const logLevelKeys = Object.keys(AikidoLogLevel); const defaultLogLevel = AikidoLogLevel.info; export function getLogLevel(): AikidoLogLevel { - // Check for AIKIDO_DEBUG environment variable + // Check for AIKIDO_DEBUG environment variable (backwards compat) if (isDebugging()) { return AikidoLogLevel.debug; } From d592d7411a0d2c5e83339c38c980f824a689a942 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Timo=20K=C3=B6ssler?= Date: Fri, 27 Dec 2024 17:28:43 +0100 Subject: [PATCH 08/11] Change default log level, fix tests --- library/agent/Agent.test.ts | 1 - library/agent/Agent.ts | 2 +- library/agent/logger/logLevel.test.ts | 31 ++++++++++++++++----------- library/agent/logger/logLevel.ts | 12 +++++------ 4 files changed, 26 insertions(+), 20 deletions(-) diff --git a/library/agent/Agent.test.ts b/library/agent/Agent.test.ts index cda2bbecf..bd766b594 100644 --- a/library/agent/Agent.test.ts +++ b/library/agent/Agent.test.ts @@ -669,7 +669,6 @@ t.test("it logs when failed to report event", async () => { "Failed to start agent: Failed to report event", "Heartbeat...", "Failed to send heartbeat event", - 'Zen has blocked a NoSQL injection: kind="nosql_injection" operation="operation(...)" source="body.nested" ip="::1"', "Failed to report attack", ]); }); diff --git a/library/agent/Agent.ts b/library/agent/Agent.ts index 1a071a32f..df0867921 100644 --- a/library/agent/Agent.ts +++ b/library/agent/Agent.ts @@ -194,7 +194,7 @@ export class Agent { if (this.token) { this.api.report(this.token, attack, this.timeoutInMS).catch(() => { - this.logger.log("Failed to report attack"); + this.logger.error("Failed to report attack"); }); } } diff --git a/library/agent/logger/logLevel.test.ts b/library/agent/logger/logLevel.test.ts index 60f1d973c..e79b981cf 100644 --- a/library/agent/logger/logLevel.test.ts +++ b/library/agent/logger/logLevel.test.ts @@ -1,7 +1,7 @@ import * as t from "tap"; import { getLogLevel, AikidoLogLevel, shouldLog } from "./logLevel"; -const defaultLogLevel = AikidoLogLevel.info; +const defaultLogLevel = AikidoLogLevel.warn; t.test("it returns the default log level", async (t) => { t.equal(getLogLevel(), defaultLogLevel); @@ -21,16 +21,23 @@ t.test("it returns the log level from the environment variable", async (t) => { process.env.AIKIDO_LOG_LEVEL = undefined; }); -t.test("it respects the AIKIDO_DEBUG environment variable", async (t) => { - t.equal(getLogLevel(), defaultLogLevel); - process.env.AIKIDO_DEBUG = "1"; - t.equal(getLogLevel(), AikidoLogLevel.debug); - process.env.AIKIDO_LOG_LEVEL = "warn"; - t.equal(getLogLevel(), AikidoLogLevel.debug); - process.env.AIKIDO_DEBUG = "0"; - t.equal(getLogLevel(), AikidoLogLevel.warn); - process.env.AIKIDO_DEBUG = undefined; -}); +t.test( + "it checks the AIKIDO_DEBUG environment variable if AIKIDO_LOG_LEVEL is not set", + async (t) => { + t.equal(getLogLevel(), defaultLogLevel); + process.env.AIKIDO_DEBUG = "1"; + t.equal(getLogLevel(), AikidoLogLevel.debug); + process.env.AIKIDO_LOG_LEVEL = "warn"; + t.equal(getLogLevel(), AikidoLogLevel.warn); + process.env.AIKIDO_LOG_LEVEL = undefined; + t.equal(getLogLevel(), AikidoLogLevel.debug); + process.env.AIKIDO_DEBUG = "0"; + process.env.AIKIDO_LOG_LEVEL = "error"; + t.equal(getLogLevel(), AikidoLogLevel.error); + process.env.AIKIDO_DEBUG = undefined; + process.env.AIKIDO_LOG_LEVEL = undefined; + } +); t.test("test shouldLog", async (t) => { process.env.AIKIDO_LOG_LEVEL = "debug"; @@ -60,5 +67,5 @@ t.test("test shouldLog", async (t) => { process.env.AIKIDO_LOG_LEVEL = undefined; t.equal(getLogLevel(), defaultLogLevel); t.equal(false, shouldLog(AikidoLogLevel.debug)); - t.equal(true, shouldLog(AikidoLogLevel.info)); + t.equal(true, shouldLog(AikidoLogLevel.warn)); }); diff --git a/library/agent/logger/logLevel.ts b/library/agent/logger/logLevel.ts index b09984fa0..9fc4cdb87 100644 --- a/library/agent/logger/logLevel.ts +++ b/library/agent/logger/logLevel.ts @@ -10,19 +10,19 @@ export const AikidoLogLevel = { type AikidoLogLevel = (typeof AikidoLogLevel)[keyof typeof AikidoLogLevel]; const logLevelKeys = Object.keys(AikidoLogLevel); -const defaultLogLevel = AikidoLogLevel.info; +const defaultLogLevel = AikidoLogLevel.warn; export function getLogLevel(): AikidoLogLevel { - // Check for AIKIDO_DEBUG environment variable (backwards compat) - if (isDebugging()) { - return AikidoLogLevel.debug; - } - const envValue = process.env.AIKIDO_LOG_LEVEL; if (envValue && logLevelKeys.includes(envValue)) { return AikidoLogLevel[envValue as keyof typeof AikidoLogLevel]; } + // Check for AIKIDO_DEBUG environment variable (backwards compat) + if (isDebugging()) { + return AikidoLogLevel.debug; + } + return defaultLogLevel; } From 1fddb262a07acaefa1c2a06d5be3245f36d26ed5 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Timo=20K=C3=B6ssler?= Date: Fri, 27 Dec 2024 18:00:09 +0100 Subject: [PATCH 09/11] Fix e2e tests --- end2end/tests/lambda-mongodb.test.js | 7 +++++-- 1 file changed, 5 insertions(+), 2 deletions(-) diff --git a/end2end/tests/lambda-mongodb.test.js b/end2end/tests/lambda-mongodb.test.js index 50c34e663..bd66c4867 100644 --- a/end2end/tests/lambda-mongodb.test.js +++ b/end2end/tests/lambda-mongodb.test.js @@ -25,7 +25,7 @@ t.test("it does not block by default", async (t) => { ); t.same(stderr, ""); - t.same(JSON.parse(stdout.toString()), { + t.same(JSON.parse(stdout.toString().split("\n").slice(2).join("\n")), { statusCode: 200, headers: { "Content-Type": "application/json", @@ -45,7 +45,10 @@ t.test("it blocks when AIKIDO_BLOCKING is true", async (t) => { } ); - t.same(stdout, ""); + t.match( + stdout, + 'Zen has blocked a NoSQL injection: kind="nosql_injection" operation="MongoDB.Collection.findOne(...)" source="body.password" ip="1.2.3.4"' + ); t.match(stderr, /Zen has blocked a NoSQL injection/); }); From 3fad5274f1ccacb1fb123b663ea179fbe30c7147 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Timo=20K=C3=B6ssler?= Date: Fri, 24 Jan 2025 16:05:05 +0100 Subject: [PATCH 10/11] Improve error logs, change logs on startup --- library/agent/Agent.test.ts | 18 +++--- library/agent/Agent.ts | 63 ++++++++++++++----- library/agent/api/fetchBlockedLists.ts | 5 ++ .../agent/realtime/getConfigLastUpdatedAt.ts | 5 ++ library/agent/realtime/pollForChanges.test.ts | 4 +- library/agent/realtime/pollForChanges.ts | 4 +- 6 files changed, 74 insertions(+), 25 deletions(-) diff --git a/library/agent/Agent.test.ts b/library/agent/Agent.test.ts index bd766b594..4c17ad861 100644 --- a/library/agent/Agent.test.ts +++ b/library/agent/Agent.test.ts @@ -98,8 +98,9 @@ t.test("it sends started event", async (t) => { ]); t.same(logger.getMessages(), [ - "Starting agent...", + "Starting agent v0.0.0", "Found token, reporting enabled!", + "Enabled blocking mode, attacks will be blocked!", "mongodb@6.9.0 is supported!", ]); }); @@ -137,8 +138,9 @@ t.test("it logs if package is supported or not", async () => { agent.onPackageWrapped("shell-quote", { version: "1.8.1", supported: false }); t.same(logger.getMessages(), [ - "Starting agent...", + "Starting agent v0.0.0", "Found token, reporting enabled!", + "Enabled blocking mode, attacks will be blocked!", "shell-quote@1.8.1 is not supported!", ]); }); @@ -156,9 +158,9 @@ t.test("it starts in non-blocking mode", async () => { agent.start([]); t.same(logger.getMessages(), [ - "Starting agent...", - "Dry mode enabled, no requests will be blocked!", + "Starting agent v0.0.0", "Found token, reporting enabled!", + "Monitoring mode enabled, no attacks will be blocked!", ]); }); @@ -664,11 +666,12 @@ t.test("it logs when failed to report event", async () => { await setTimeout(0); t.same(logger.getMessages(), [ - "Starting agent...", + "Starting agent v0.0.0", "Found token, reporting enabled!", + "Enabled blocking mode, attacks will be blocked!", "Failed to start agent: Failed to report event", "Heartbeat...", - "Failed to send heartbeat event", + "Failed to send heartbeat event to Aikido platform: Failed to report event", "Failed to report attack", ]); }); @@ -687,8 +690,9 @@ t.test("unable to prevent prototype pollution", async () => { agent.start([]); agent.unableToPreventPrototypePollution({ mongoose: "1.0.0" }); t.same(logger.getMessages(), [ - "Starting agent...", + "Starting agent v0.0.0", "Found token, reporting enabled!", + "Enabled blocking mode, attacks will be blocked!", "Unable to prevent prototype pollution, incompatible packages found: mongoose@1.0.0", ]); diff --git a/library/agent/Agent.ts b/library/agent/Agent.ts index df0867921..a00dd3690 100644 --- a/library/agent/Agent.ts +++ b/library/agent/Agent.ts @@ -11,7 +11,7 @@ import { fetchBlockedLists } from "./api/fetchBlockedLists"; import { ReportingAPI, ReportingAPIResponse } from "./api/ReportingAPI"; import { AgentInfo, DetectedAttack } from "./api/Event"; import { Token } from "./api/Token"; -import { attackKindHumanName, Kind } from "./Attack"; +import { Kind } from "./Attack"; import { pollForChanges } from "./realtime/pollForChanges"; import { Context } from "./Context"; import { Hostnames } from "./Hostnames"; @@ -112,6 +112,17 @@ export class Agent { }, this.timeoutInMS ); + if (!result.success) { + if (result.error === "invalid_token") { + this.logger.error( + "Unable to access the Aikido platform, please check your token." + ); + } else { + this.logger.error( + `Failed to connect to the Aikido platform: ${result.error}` + ); + } + } this.updateServiceConfig(result); @@ -203,8 +214,10 @@ export class Agent { * Sends a heartbeat via the API to the server (only when not in serverless mode) */ private heartbeat(timeoutInMS = this.timeoutInMS) { - this.sendHeartbeat(timeoutInMS).catch(() => { - this.logger.warn("Failed to send heartbeat event"); + this.sendHeartbeat(timeoutInMS).catch((err) => { + this.logger.error( + `Failed to send heartbeat event to Aikido platform: ${err.message}` + ); }); } @@ -221,9 +234,13 @@ export class Agent { if (typeof response.block === "boolean") { if (response.block !== this.block) { this.block = response.block; - this.logger.debug( - `Block mode has been set to ${this.block ? "on" : "off"}` - ); + if (this.block) { + this.logger.info(`Enabled blocking mode, attacks will be blocked!`); + } else { + this.logger.warn( + `Monitoring mode enabled, no attacks will be blocked!` + ); + } } } @@ -291,6 +308,12 @@ export class Agent { timeoutInMS ); + if (!response.success && response.error === "invalid_token") { + this.logger.error( + "Unable to access the Aikido platform, please check your token." + ); + } + this.updateServiceConfig(response); } } @@ -420,24 +443,30 @@ export class Agent { this.started = true; - this.logger.debug("Starting agent..."); - - if (!this.block) { - this.logger.debug("Dry mode enabled, no requests will be blocked!"); - } + this.logger.info(`Starting agent v${getAgentVersion()}`); if (this.token) { - this.logger.debug("Found token, reporting enabled!"); + this.logger.info("Found token, reporting enabled!"); + + if (!this.block) { + this.logger.warn( + "Monitoring mode enabled, no attacks will be blocked!" + ); + } } else { - this.logger.debug("No token provided, disabling reporting."); + this.logger.info("No token found, reporting disabled!"); - if (!this.block && !isAikidoCI()) { + if (!this.block) { this.logger.warn( "Running in monitoring only mode without reporting to Aikido Cloud. Set AIKIDO_BLOCK=true to enable blocking." ); } } + if (this.block) { + this.logger.info("Enabled blocking mode, attacks will be blocked!"); + } + wrapInstalledPackages(wrappers); // Send startup event and wait for config @@ -523,7 +552,11 @@ export class Agent { async flushStats(timeoutInMS: number) { this.statistics.forceCompress(); - await this.sendHeartbeat(timeoutInMS); + await this.sendHeartbeat(timeoutInMS).catch((err) => { + this.logger.error( + `Failed to send heartbeat event to Aikido platform: ${err.message}` + ); + }); } getRateLimiter() { diff --git a/library/agent/api/fetchBlockedLists.ts b/library/agent/api/fetchBlockedLists.ts index 73fcfd390..3e2db2719 100644 --- a/library/agent/api/fetchBlockedLists.ts +++ b/library/agent/api/fetchBlockedLists.ts @@ -25,6 +25,11 @@ export async function fetchBlockedLists(token: Token): Promise<{ }); if (statusCode !== 200) { + if (statusCode === 401) { + throw new Error( + `Unable to access the Aikido platform, please check your token.` + ); + } throw new Error(`Failed to fetch blocked lists: ${statusCode}`); } diff --git a/library/agent/realtime/getConfigLastUpdatedAt.ts b/library/agent/realtime/getConfigLastUpdatedAt.ts index b2c9d4a3b..5da583941 100644 --- a/library/agent/realtime/getConfigLastUpdatedAt.ts +++ b/library/agent/realtime/getConfigLastUpdatedAt.ts @@ -15,6 +15,11 @@ export async function getConfigLastUpdatedAt(token: Token): Promise { }); if (statusCode !== 200) { + if (statusCode === 401) { + throw new Error( + "Unable to access the Aikido platform, please check your token." + ); + } throw new Error(`Invalid response (${statusCode}): ${body}`); } diff --git a/library/agent/realtime/pollForChanges.test.ts b/library/agent/realtime/pollForChanges.test.ts index 7588eb4c9..e44717a43 100644 --- a/library/agent/realtime/pollForChanges.test.ts +++ b/library/agent/realtime/pollForChanges.test.ts @@ -226,7 +226,9 @@ t.test("it deals with API throwing errors", async () => { await clock.nextAsync(); t.same(configUpdates, []); - t.same(logger.getMessages(), ["Failed to check for config updates"]); + t.same(logger.getMessages(), [ + "Failed to check for config updates: Request timed out", + ]); clock.uninstall(); }); diff --git a/library/agent/realtime/pollForChanges.ts b/library/agent/realtime/pollForChanges.ts index 2c03eefb7..06cb02f1e 100644 --- a/library/agent/realtime/pollForChanges.ts +++ b/library/agent/realtime/pollForChanges.ts @@ -41,8 +41,8 @@ export function pollForChanges({ } interval = setInterval(() => { - check(token, onConfigUpdate).catch(() => { - logger.error("Failed to check for config updates"); + check(token, onConfigUpdate).catch((err) => { + logger.error(`Failed to check for config updates: ${err.message}`); }); }, 60 * 1000); From 3d79b597daed5a70e228a13952388a31e29697d8 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Timo=20K=C3=B6ssler?= Date: Fri, 24 Jan 2025 16:41:57 +0100 Subject: [PATCH 11/11] Add comment --- library/helpers/isFirewallSupported.ts | 2 ++ library/helpers/shouldEnableFirewall.ts | 1 + 2 files changed, 3 insertions(+) diff --git a/library/helpers/isFirewallSupported.ts b/library/helpers/isFirewallSupported.ts index 8e1acac31..4b70b3836 100644 --- a/library/helpers/isFirewallSupported.ts +++ b/library/helpers/isFirewallSupported.ts @@ -6,6 +6,7 @@ export default function isFirewallSupported() { if (globalThis.Deno || globalThis.Bun) { // @ts-expect-error Unknown type of globalThis const runtimeName = globalThis.Deno ? "Deno" : "Bun"; + // Not using the logging class because this runs before agent initialization console.error( `Error: Aikido Firewall does not support ${runtimeName}. If you want support for ${runtimeName}, please contact us: hello@aikido.dev` ); @@ -15,6 +16,7 @@ export default function isFirewallSupported() { // Check for unsupported Node.js versions if (getMajorNodeVersion() < 16) { + // Not using the logging class because this runs before agent initialization console.error( "Error: Aikido Firewall requires Node.js 16 or higher to run." ); diff --git a/library/helpers/shouldEnableFirewall.ts b/library/helpers/shouldEnableFirewall.ts index 67f8a4e34..d0ae2c642 100644 --- a/library/helpers/shouldEnableFirewall.ts +++ b/library/helpers/shouldEnableFirewall.ts @@ -28,6 +28,7 @@ export default function shouldEnableFirewall() { } if (!isAikidoCI()) { + // Not using the logging class because this runs before agent initialization // eslint-disable-next-line no-console console.warn( "AIKIDO: Zen is disabled. Configure one of the following environment variables to enable it: AIKIDO_BLOCK, AIKIDO_TOKEN, AIKIDO_DEBUG."