diff --git a/scripts/e2e/lib/plugins/sweep.sh b/scripts/e2e/lib/plugins/sweep.sh index a79e5cd6cbeb..d673fd1624c1 100644 --- a/scripts/e2e/lib/plugins/sweep.sh +++ b/scripts/e2e/lib/plugins/sweep.sh @@ -17,16 +17,90 @@ export OPENCLAW_PLUGINS_TMP_DIR OPENCLAW_PLUGINS_CLI_TIMEOUT="${OPENCLAW_PLUGINS_CLI_TIMEOUT:-180s}" mkdir -p "$OPENCLAW_PLUGINS_TMP_DIR" +plugins_lifecycle_trace_enabled() { + case "${OPENCLAW_PLUGIN_LIFECYCLE_TRACE:-}" in + 1 | true | TRUE | yes | YES) + return 0 + ;; + *) + return 1 + ;; + esac +} + +# Redact complete stderr before truncation so a split credential can never expose its suffix. +print_plugins_stderr_log() { + local error_file="$1" + local redacted_file + redacted_file="$(mktemp "$OPENCLAW_PLUGINS_TMP_DIR/openclaw-plugin-redacted.XXXXXX")" || return $? + local status=0 + sed -E \ + -e 's/[Bb][Ee][Aa][Rr][Ee][Rr][[:space:]]+[^[:space:]]+/Bearer [REDACTED]/g' \ + -e 's/(^|[^[:alnum:]_])(sk|sess|rk)-[[:alnum:]_-]+/\1[REDACTED]/g' \ + "$error_file" >"$redacted_file" || status=$? + if [[ "$status" -eq 0 ]]; then + docker_e2e_print_log "$redacted_file" >&2 || status=$? + fi + rm -f "$redacted_file" + return "$status" +} + run_plugins_openclaw_logged() { local label="$1" shift - run_logged "$label" openclaw_e2e_maybe_timeout "$OPENCLAW_PLUGINS_CLI_TIMEOUT" node "$OPENCLAW_ENTRY" "$@" + local output_file + output_file="$(mktemp "$OPENCLAW_PLUGINS_TMP_DIR/openclaw-plugin-stdout.XXXXXX")" || return $? + local error_file + error_file="$(mktemp "$OPENCLAW_PLUGINS_TMP_DIR/openclaw-plugin-stderr.XXXXXX")" || { + local create_status=$? + rm -f "$output_file" + return "$create_status" + } + local status=0 + if openclaw_e2e_maybe_timeout "$OPENCLAW_PLUGINS_CLI_TIMEOUT" node "$OPENCLAW_ENTRY" "$@" >"$output_file" 2>"$error_file"; then + if plugins_lifecycle_trace_enabled; then + print_plugins_stderr_log "$error_file" || status=$? + fi + else + status=$? + if ! print_plugins_stderr_log "$error_file"; then + printf 'Plugin sweep stderr redaction failed: %s\n' "$label" >&2 + fi + if [[ "$status" -eq 124 ]]; then + printf 'Plugin sweep command timed out after %s: %s\n' \ + "$OPENCLAW_PLUGINS_CLI_TIMEOUT" "$label" >&2 + else + printf 'Plugin sweep command failed with status %s: %s\n' \ + "$status" "$label" >&2 + fi + fi + rm -f "$error_file" "$output_file" + return "$status" } run_plugins_openclaw_capture() { local output_file="$1" shift - openclaw_e2e_maybe_timeout "$OPENCLAW_PLUGINS_CLI_TIMEOUT" node "$OPENCLAW_ENTRY" "$@" >"$output_file" + local error_file + error_file="$(mktemp "$OPENCLAW_PLUGINS_TMP_DIR/openclaw-plugin-stderr.XXXXXX")" || return $? + local status=0 + if openclaw_e2e_maybe_timeout "$OPENCLAW_PLUGINS_CLI_TIMEOUT" node "$OPENCLAW_ENTRY" "$@" >"$output_file" 2>"$error_file"; then + print_plugins_stderr_log "$error_file" || status=$? + else + status=$? + if ! print_plugins_stderr_log "$error_file"; then + printf 'Plugin sweep stderr redaction failed: %s\n' "${output_file##*/}" >&2 + fi + if [[ "$status" -eq 124 ]]; then + printf 'Plugin sweep capture timed out after %s: %s\n' \ + "$OPENCLAW_PLUGINS_CLI_TIMEOUT" "${output_file##*/}" >&2 + else + printf 'Plugin sweep capture failed with status %s: %s\n' \ + "$status" "${output_file##*/}" >&2 + fi + fi + rm -f "$error_file" + return "$status" } run_plugins_shell_logged() { diff --git a/scripts/e2e/plugins-docker.sh b/scripts/e2e/plugins-docker.sh index 64659992c3ab..9643b46184b3 100755 --- a/scripts/e2e/plugins-docker.sh +++ b/scripts/e2e/plugins-docker.sh @@ -27,6 +27,7 @@ DOCKER_ENV_ARGS=( -e "OPENCLAW_TEST_STATE_SCRIPT_B64=$OPENCLAW_TEST_STATE_SCRIPT_B64" ) for env_name in \ + OPENCLAW_PLUGIN_LIFECYCLE_TRACE \ OPENCLAW_PLUGINS_E2E_CLAWHUB \ OPENCLAW_PLUGINS_E2E_LIVE_CLAWHUB \ OPENCLAW_PLUGINS_E2E_CLAWHUB_SPEC \ diff --git a/test/scripts/docker-build-helper.test.ts b/test/scripts/docker-build-helper.test.ts index d35c5afe8cdb..0007833ee61d 100644 --- a/test/scripts/docker-build-helper.test.ts +++ b/test/scripts/docker-build-helper.test.ts @@ -3914,6 +3914,7 @@ heartbeat_elapsed="\${BASH_REMATCH[1]}" encoding: "utf8", env: { ...process.env, + OPENAI_API_KEY: "", OPENCLAW_OPENWEBUI_FETCH_TIMEOUT_MS: "09000", OPENCLAW_OPENWEBUI_GATEWAY_PORT: "018789", OPENCLAW_OPENWEBUI_PORT: "08080", @@ -4046,16 +4047,18 @@ heartbeat_elapsed="\${BASH_REMATCH[1]}" const client = readFileSync("scripts/e2e/lib/openai-chat-tools/client.mjs", "utf8"); const writer = readFileSync("scripts/e2e/lib/openai-chat-tools/write-config.mjs", "utf8"); const consumed = new Set( - [...`${client}\n${writer}`.matchAll(/["`](OPENCLAW_OPENAI_CHAT_TOOLS_[A-Z0-9_]+)["`]/gu)].map( - (match) => match[1], - ), + [...`${client}\n${writer}`.matchAll(/["`](OPENCLAW_OPENAI_CHAT_TOOLS_[A-Z0-9_]+)["`]/gu)] + .map((match) => match[1]) + .filter((envName): envName is string => envName !== undefined), ); const forwarded = new Set( - [...runner.matchAll(/-e\s+"(OPENCLAW_OPENAI_CHAT_TOOLS_[A-Z0-9_]+)=/gu)].map( - (match) => match[1], - ), + [...runner.matchAll(/-e\s+"(OPENCLAW_OPENAI_CHAT_TOOLS_[A-Z0-9_]+)=/gu)] + .map((match) => match[1]) + .filter((envName): envName is string => envName !== undefined), ); - const missing = [...consumed].filter((envName) => !forwarded.has(envName)).toSorted(); + const missing = [...consumed] + .filter((envName) => !forwarded.has(envName)) + .toSorted((left, right) => left.localeCompare(right)); expect(missing).toEqual([]); }); @@ -4064,14 +4067,18 @@ heartbeat_elapsed="\${BASH_REMATCH[1]}" const runner = readFileSync(KITCHEN_SINK_RPC_DOCKER_E2E_PATH, "utf8"); const walk = readFileSync("scripts/e2e/kitchen-sink-rpc-walk.mjs", "utf8"); const consumed = new Set( - [...walk.matchAll(/\b(?:env|process\.env)\.(OPENCLAW_KITCHEN_SINK_[A-Z0-9_]+)/gu)].map( - (match) => match[1], - ), + [...walk.matchAll(/\b(?:env|process\.env)\.(OPENCLAW_KITCHEN_SINK_[A-Z0-9_]+)/gu)] + .map((match) => match[1]) + .filter((envName): envName is string => envName !== undefined), ); const forwarded = new Set( - [...runner.matchAll(/\b(OPENCLAW_KITCHEN_SINK_[A-Z0-9_]+)\b/gu)].map((match) => match[1]), + [...runner.matchAll(/\b(OPENCLAW_KITCHEN_SINK_[A-Z0-9_]+)\b/gu)] + .map((match) => match[1]) + .filter((envName): envName is string => envName !== undefined), ); - const missing = [...consumed].filter((envName) => !forwarded.has(envName)).toSorted(); + const missing = [...consumed] + .filter((envName) => !forwarded.has(envName)) + .toSorted((left, right) => left.localeCompare(right)); expect(missing).toEqual([]); }); @@ -4878,13 +4885,17 @@ heartbeat_elapsed="\${BASH_REMATCH[1]}" expect(sweep).toContain('OPENCLAW_PLUGINS_CLI_TIMEOUT="${OPENCLAW_PLUGINS_CLI_TIMEOUT:-180s}"'); expect(runner).toContain('PLUGINS_CLI_TIMEOUT="${OPENCLAW_PLUGINS_CLI_TIMEOUT:-180s}"'); expect(runner).toContain('-e "OPENCLAW_PLUGINS_CLI_TIMEOUT=$PLUGINS_CLI_TIMEOUT"'); - expect(sweep).toContain( - 'run_logged "$label" openclaw_e2e_maybe_timeout "$OPENCLAW_PLUGINS_CLI_TIMEOUT" node "$OPENCLAW_ENTRY" "$@"', - ); + expect(runner).toContain("OPENCLAW_PLUGIN_LIFECYCLE_TRACE"); + expect(sweep).toContain("plugins_lifecycle_trace_enabled()"); + expect(sweep).toContain("print_plugins_stderr_log()"); expect(sweep).toContain("run_plugins_openclaw_capture()"); expect(sweep).toContain( - 'openclaw_e2e_maybe_timeout "$OPENCLAW_PLUGINS_CLI_TIMEOUT" node "$OPENCLAW_ENTRY" "$@" >"$output_file"', + 'openclaw_e2e_maybe_timeout "$OPENCLAW_PLUGINS_CLI_TIMEOUT" node "$OPENCLAW_ENTRY" "$@" >"$output_file" 2>"$error_file"', ); + expect(sweep).toContain("Plugin sweep command timed out after %s: %s"); + expect(sweep).toContain("Plugin sweep command failed with status %s: %s"); + expect(sweep).toContain("Plugin sweep capture timed out after %s: %s"); + expect(sweep).toContain("Plugin sweep capture failed with status %s: %s"); expect(sweep).not.toContain('run_logged install-npm node "$OPENCLAW_ENTRY"'); for (const [path, script] of [ [PLUGINS_DOCKER_SWEEP_PATH, sweep], diff --git a/test/scripts/plugins-assertions.test.ts b/test/scripts/plugins-assertions.test.ts index 7597bdc2d9ff..5efea4ce28e1 100644 --- a/test/scripts/plugins-assertions.test.ts +++ b/test/scripts/plugins-assertions.test.ts @@ -5,6 +5,7 @@ import { existsSync, mkdirSync, mkdtempSync, + readdirSync, readFileSync, rmSync, writeFileSync, @@ -154,7 +155,9 @@ async function waitForPortFile(portFile: string): Promise { return port; } } - await new Promise((resolve) => setTimeout(resolve, 5)); + await new Promise((resolve) => { + setTimeout(resolve, 5); + }); } throw new Error(`timed out waiting for ${portFile}`); } @@ -302,6 +305,135 @@ test -d "$OPENCLAW_PLUGINS_TMP_DIR" } }); + it.each( + (["capture", "logged"] as const).flatMap((mode) => + [0, 23, 124].flatMap((status) => + [false, true].map((traceEnabled) => ({ mode, status, traceEnabled })), + ), + ), + )( + "bounds $mode diagnostics with exit $status and lifecycle tracing $traceEnabled", + (testCase) => { + const root = mkdtempSync(path.join(tmpdir(), "openclaw-plugin-sweep-diagnostics-")); + const outputFile = path.join(root, "plugins-git-inspect.json"); + const capturedOutput = `DO_NOT_DUMP_CAPTURED_PLUGIN_OUTPUT\n${"x".repeat(32 * 1024)}\nCAPTURED_PLUGIN_OUTPUT_TAIL`; + const fixtureApiKey = ["sk", "proj", "plugin", "fixture", "secret"].join("-"); + const punctuationApiKey = ["sess", "plugin", "punctuation", "secret"].join("-"); + const startOfLineApiKey = ["rk", "plugin", "start", "secret"].join("-"); + const boundarySecretSuffix = "PLUGIN_BOUNDARY_SECRET_SUFFIX_MUST_NOT_LEAK"; + const boundaryApiKey = ["sk", "proj", "z".repeat(256), boundarySecretSuffix].join("-"); + const capturedError = `DO_NOT_DUMP_PLUGIN_STDERR_PREFIX\n${"y".repeat(32 * 1024)}\n${startOfLineApiKey}\nPLUGIN_STDERR_TAIL_MARKER task-runner risk-score disk-space Authorization: Bearer plugin-fixture-bearer OPENAI_API_KEY=${fixtureApiKey} [${punctuationApiKey}]\n${boundaryApiKey}`; + const command = + testCase.mode === "capture" + ? 'run_plugins_openclaw_capture "$OUTPUT_FILE" plugins inspect demo-plugin --runtime --json' + : 'run_plugins_openclaw_logged install-git plugins install "git:file:///tmp/fixture@revision" --force'; + + try { + const unredactedTail = Buffer.from(`${capturedError}\n`, "utf8") + .subarray(-192) + .toString("utf8"); + expect(unredactedTail).toContain(boundarySecretSuffix); + expect(unredactedTail).not.toContain(["sk", "proj"].join("-")); + + const result = runPluginsSweepShell( + ` +set -euo pipefail +export OPENCLAW_PLUGINS_SWEEP_SOURCE_ONLY=1 +export OPENCLAW_PLUGINS_TMP_DIR="$SCRATCH_ROOT" +export OPENCLAW_PLUGINS_CLI_TIMEOUT=1s +export OPENCLAW_ENTRY=fixture-entry +source scripts/e2e/lib/plugins/sweep.sh +umask 000 +openclaw_e2e_maybe_timeout() { + local raw_stderr_file + local raw_stderr_mode + for raw_stderr_file in "$SCRATCH_ROOT"/openclaw-plugin-stderr.*; do + [[ -f "$raw_stderr_file" ]] || return 86 + if raw_stderr_mode="$(stat -f '%Lp' "$raw_stderr_file" 2>/dev/null)"; then + : + elif raw_stderr_mode="$(stat -c '%a' "$raw_stderr_file" 2>/dev/null)"; then + : + else + return 87 + fi + [[ "$raw_stderr_mode" == "600" ]] || return 88 + done + printf '%s\\n' "$CAPTURED_OUTPUT" + printf '%s\\n' "$CAPTURED_STDERR" >&2 + if [[ "\${OPENCLAW_PLUGIN_LIFECYCLE_TRACE:-}" == "1" ]]; then + printf '%s\\n' '[plugins:lifecycle] shim' >&2 + fi + return "$CAPTURE_STATUS" +} +${command} +`, + { + CAPTURED_OUTPUT: capturedOutput, + CAPTURED_STDERR: capturedError, + CAPTURE_STATUS: String(testCase.status), + OPENCLAW_DOCKER_E2E_LOG_PRINT_BYTES: "192", + OPENCLAW_PLUGIN_LIFECYCLE_TRACE: testCase.traceEnabled ? "1" : "0", + OUTPUT_FILE: outputFile, + SCRATCH_ROOT: root, + }, + ); + + expect(result.status).toBe(testCase.status); + expect(result.stdout).toBe(""); + if (testCase.mode === "capture") { + expect(readFileSync(outputFile, "utf8")).toBe(`${capturedOutput}\n`); + } + expect(result.stderr.length).toBeLessThan(1_024); + expect(result.stderr).not.toContain("DO_NOT_DUMP_CAPTURED_PLUGIN_OUTPUT"); + expect(result.stderr).not.toContain("CAPTURED_PLUGIN_OUTPUT_TAIL"); + expect(result.stderr).not.toContain("DO_NOT_DUMP_PLUGIN_STDERR_PREFIX"); + expect(result.stderr).not.toContain("plugin-fixture-bearer"); + expect(result.stderr).not.toContain(fixtureApiKey); + expect(result.stderr).not.toContain(punctuationApiKey); + expect(result.stderr).not.toContain(startOfLineApiKey); + expect(result.stderr).not.toContain(boundarySecretSuffix); + expect(result.stderr).not.toContain(boundaryApiKey); + expect( + readdirSync(root).filter( + (name) => name.startsWith("openclaw-plugin-") || name.endsWith(".stderr.log"), + ), + ).toEqual([]); + + const printsDiagnostics = + testCase.mode === "capture" || testCase.status !== 0 || testCase.traceEnabled; + if (printsDiagnostics) { + expect(result.stderr).toContain("truncated: showing last 192"); + expect(result.stderr).toContain("PLUGIN_STDERR_TAIL_MARKER"); + expect(result.stderr).toContain("task-runner"); + expect(result.stderr).toContain("risk-score"); + expect(result.stderr).toContain("disk-space"); + expect(result.stderr).toContain("Authorization: Bearer [REDACTED]"); + expect(result.stderr).toContain("OPENAI_API_KEY=[REDACTED]"); + expect(result.stderr).toContain("[[REDACTED]]"); + expect(result.stderr).toContain("[REDACTED]"); + } else { + expect(result.stderr).toBe(""); + } + if (testCase.traceEnabled) { + expect(result.stderr).toContain("[plugins:lifecycle]"); + } else { + expect(result.stderr).not.toContain("[plugins:lifecycle]"); + } + if (testCase.status !== 0) { + const label = testCase.mode === "capture" ? "plugins-git-inspect.json" : "install-git"; + const noun = testCase.mode === "capture" ? "capture" : "command"; + const detail = + testCase.status === 124 + ? `timed out after 1s: ${label}` + : `failed with status ${testCase.status}: ${label}`; + expect(result.stderr).toContain(`Plugin sweep ${noun} ${detail}`); + } + } finally { + rmSync(root, { force: true, recursive: true }); + } + }, + ); + it("scans plugin assertion logs without echoing whole files on failure", async () => { const root = mkdtempSync(path.join(tmpdir(), "openclaw-plugin-update-log-")); try {