diff --git a/.changeset/ckb-tui-v0.1.4.md b/.changeset/ckb-tui-v0.1.4.md new file mode 100644 index 0000000..41a1733 --- /dev/null +++ b/.changeset/ckb-tui-v0.1.4.md @@ -0,0 +1,5 @@ +--- +'@offckb/cli': patch +--- + +Bump the bundled ckb-tui from v0.1.3 to v0.1.4 for `offckb status`. The new release fixes a divide-by-zero panic in ckb-tui's data-sync thread when the connected node has no peers (Officeyutong/ckb-tui#13) — the normal state of a single-node devnet — which permanently froze the Overview, Mempool, Peers, and Blockchain panels within seconds of opening the TUI. SHA-256 digests for the v0.1.4 release assets are pinned in offckb, so the download stays verifiable. diff --git a/.changeset/logs-command-quiet-node.md b/.changeset/logs-command-quiet-node.md new file mode 100644 index 0000000..d50caf5 --- /dev/null +++ b/.changeset/logs-command-quiet-node.md @@ -0,0 +1,5 @@ +--- +'@offckb/cli': minor +--- + +Unify devnet logging around the node's log files and add `offckb logs`. A foreground `offckb node` no longer relays the raw node/miner stdout: the console now shows lifecycle events, live contract script debug output (`debug!` in scripts, streamed over the node's TCP log subscription), submitted transaction hashes, and RPC errors — the full node log stays in `data/logs/run.log` as always, and `--verbose` restores the old firehose. The new `offckb logs [node|script|miner|rpc] [-f] [--grep] [--tail]` command reads those log files (`docker logs` style), so logs are reachable in every run mode — foreground, daemon, or while `offckb status` is attached — and pipe/agent friendly. The RPC proxy is quieter too: per-request lines moved from info to debug, JSON-RPC errors in responses now surface as warnings, and everything the proxy sees is appended to `data/logs/proxy.log` (viewable via `offckb logs rpc`). diff --git a/.changeset/terminal-rpc-version-compat.md b/.changeset/terminal-rpc-version-compat.md new file mode 100644 index 0000000..09fd43d --- /dev/null +++ b/.changeset/terminal-rpc-version-compat.md @@ -0,0 +1,5 @@ +--- +'@offckb/cli': patch +--- + +Fix devnet startup crashing for CKB binaries older than v0.205.0. The devnet ckb.toml template enables the `Terminal` RPC module, which only exists since CKB v0.205.0; older binaries abort at startup with an opaque serde "unknown variant" error, and the legacy-config migration re-added the module on every `offckb node` start even after users removed it by hand. offckb now adapts the devnet config to the CKB version: fresh chains for an old binary are initialized without `Terminal` (the migration also stops re-adding it, while still enabling `tcp_listen_address`), a config that already has `Terminal` paired with an old binary fails fast with an actionable error instead of the serde dump, and an unprobeable custom `--binary-path` that crashes with the tell-tale "unknown variant `Terminal`" message now gets a hint pointing at the cause. The `offckb status` system-metric panels require CKB >= 0.205.0; the README's `status` section says so. diff --git a/CHANGELOG.md b/CHANGELOG.md index 6337a30..668640a 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -4,6 +4,8 @@ ### Patch Changes +- 406415e: Change the default devnet log filter from `warn,ckb-script=debug` to `info,ckb-script=debug` in the `ckb.toml` / `ckb-miner.toml` templates (and the config editor's embedded reference templates). A healthy devnet produces almost no `warn`-level output, which left the `offckb status` Logs panel permanently empty and looked broken; `info` keeps the per-block log stream visible while `ckb-script=debug` still surfaces script execution details. Applies to newly initialized chains — edit `[logger] filter` in your existing devnet `ckb.toml` to opt in. + - 699a850: Fix the `status` command showing missing data on devnet: enable the Terminal RPC module and the TCP listen address in the devnet `ckb.toml` template (and the config editor's embedded reference template), and pass the node's TCP listen address to ckb-tui so the system metrics, mempool, and log panels populate correctly. The devnet RPC now binds to `127.0.0.1` instead of `0.0.0.0` so the unauthenticated RPC (including the new host metrics) is no longer reachable from other machines on the network; edit `rpc.listen_address` in the devnet `ckb.toml` if you rely on remote access. - 45b0e98: Rename `--allow-mainnet-replay-risk` to `--allow-external-key-on-mainnet-fork` (#460) — the old flag remains as a hidden deprecated alias so existing scripts keep working — and apply the fixes left over from the 0.4.9 review (#462): diff --git a/README.md b/README.md index a4b4941..a3eb7a6 100644 --- a/README.md +++ b/README.md @@ -85,6 +85,7 @@ Commands: balance [options] [toAddress] Check account balance, only devnet and testnet debugger Port of the raw CKB Standalone Debugger status [options] Show ckb-tui status interface + logs [options] [target] Show devnet logs: node (default), contract script debug output, miner, or RPC proxy events config [item] [value] do a configuration action devnet config Edit devnet configuration devnet info Show fork metadata and node/indexer readiness @@ -144,6 +145,21 @@ Stop the daemon later with: offckb node stop ``` +**View Logs** + +A foreground `offckb node` stays quiet by default: it prints lifecycle events, contract script debug output (`debug!` in your scripts), submitted transaction hashes, and RPC errors. The node, miner, and RPC proxy always write full logs to files under the devnet data folder, and `offckb logs` reads them in any run mode (foreground, daemon, or while `offckb status` is attached): + +```sh +offckb logs # node log (default) +offckb logs script # contract script debug output only +offckb logs miner # miner log +offckb logs rpc # RPC requests, transaction hashes, RPC errors +offckb logs -f # stream new lines, tail -f style +offckb logs --tail 200 --grep ERROR +``` + +Use `offckb node --verbose` to restore the old behavior of printing the full raw node/miner output to the terminal. + **Agent-Friendly JSON Output** For programmatic consumption or agent integration, add `--json` before or after the command: @@ -188,6 +204,8 @@ offckb status --network mainnet `status` performs a JSON-RPC health check through the proxy before opening the TUI and requires an interactive terminal. +The TUI's system-metric panels are powered by CKB's `Terminal` RPC module, which requires CKB >= 0.205.0. If you run the devnet with an older CKB (e.g. `offckb node 0.120.0` or `--binary-path` pointing at an old build), offckb starts the node without that module and those panels will be unavailable; upgrade CKB to get them. + ### 2. Create a New Contract Project {#create-project} Generate a ready-to-use smart-contract project in JS/TS using templates: @@ -331,7 +349,7 @@ offckb system-scripts --output ### 6. Tweak Devnet Config {#tweak-devnet-config} -By default, OffCKB use a fixed Devnet config. You can customize it, for example by modifying the default log level (`warn,ckb-script=debug`). +By default, OffCKB use a fixed Devnet config. You can customize it, for example by modifying the default log level (`info,ckb-script=debug`). 1. Open the interactive Devnet config editor: diff --git a/ckb/devnet/ckb-miner.toml b/ckb/devnet/ckb-miner.toml index bbc69c7..3482c96 100644 --- a/ckb/devnet/ckb-miner.toml +++ b/ckb/devnet/ckb-miner.toml @@ -10,7 +10,7 @@ data_dir = "data" spec = { file = "specs/dev.toml" } [logger] -filter = "warn,ckb-script=debug" +filter = "info,ckb-script=debug" color = true log_to_file = true log_to_stdout = true diff --git a/ckb/devnet/ckb.toml b/ckb/devnet/ckb.toml index 27ad525..0d70baa 100644 --- a/ckb/devnet/ckb.toml +++ b/ckb/devnet/ckb.toml @@ -10,7 +10,7 @@ data_dir = "data" spec = { file = "specs/dev.toml" } [logger] -filter = "warn,ckb-script=debug" +filter = "info,ckb-script=debug" color = true log_to_file = true log_to_stdout = true diff --git a/src/cfg/setting.ts b/src/cfg/setting.ts index 52aaa51..8c52b3e 100644 --- a/src/cfg/setting.ts +++ b/src/cfg/setting.ts @@ -97,7 +97,7 @@ export const defaultSettings: Settings = { minVersion: '0.200.0', }, ckbTui: { - version: 'v0.1.3', + version: 'v0.1.4', }, }, }; diff --git a/src/cli.ts b/src/cli.ts index 8290832..5015a66 100644 --- a/src/cli.ts +++ b/src/cli.ts @@ -1,5 +1,5 @@ #!/usr/bin/env node -import { Command, CommanderError, Option } from 'commander'; +import { Command, CommanderError, InvalidArgumentError, Option, Argument } from 'commander'; import { startNode, stopNode } from './cmd/node'; import { accounts } from './cmd/accounts'; import { clean } from './cmd/clean'; @@ -15,6 +15,7 @@ import { devnetConfig } from './cmd/devnet-config'; import { devnetFork } from './cmd/devnet-fork'; import { devnetInfo } from './cmd/devnet-info'; import { debugSingleScript, debugTransaction, parseSingleScriptOption } from './cmd/debug'; +import { logsCommand, LogsOptions } from './cmd/logs'; import { printSystemScripts } from './cmd/system-scripts'; import { transferAll } from './cmd/transfer-all'; import { genSystemScriptsJsonFile } from './scripts/gen'; @@ -76,15 +77,47 @@ const nodeCommand = program 'Specify the CKB binary path to use, only for devnet, when set, will ignore version and network', ) .option('--daemon', 'Run the node in the background as a daemon (devnet only)') - .action(async (version: string, options: { network: Network; binaryPath?: string; daemon?: boolean }) => { - return startNode({ version, network: options.network, binaryPath: options.binaryPath, daemon: options.daemon }); - }); + .option( + '--verbose', + 'Print the full raw node/miner output (default shows lifecycle events, script output, tx hashes, and RPC errors)', + ) + .action( + async ( + version: string, + options: { network: Network; binaryPath?: string; daemon?: boolean; verbose?: boolean }, + ) => { + return startNode({ + version, + network: options.network, + binaryPath: options.binaryPath, + daemon: options.daemon, + verbose: options.verbose, + }); + }, + ); nodeCommand .command('stop') .description('Stop the running CKB devnet daemon') .action(async () => stopNode()); +program + .command('logs') + .description('Show devnet logs: node (default), contract script debug output, miner, or RPC proxy events') + .addArgument( + new Argument('[target]', 'Which logs to show').choices(['node', 'script', 'miner', 'rpc']).default('node'), + ) + .option('-f, --follow', 'Stream new log lines as they are written (like tail -f)') + .option('--grep ', 'Only show lines containing the given text') + .option('--tail ', 'Show the last N lines before following', (value: string) => { + const parsed = Number(value); + if (!Number.isInteger(parsed) || parsed < 0) { + throw new InvalidArgumentError('--tail must be a non-negative integer'); + } + return parsed; + }) + .action((target: string, options: LogsOptions) => logsCommand(target, options)); + program .command('create [project-name]') .description('Create a new CKB Smart Contract project in JavaScript.') diff --git a/src/cmd/logs.ts b/src/cmd/logs.ts new file mode 100644 index 0000000..09e0530 --- /dev/null +++ b/src/cmd/logs.ts @@ -0,0 +1,57 @@ +import { + LOG_TARGETS, + LogTarget, + SCRIPT_LOG_TARGET, + filterLinesByTarget, + followLogFile, + grepLines, + parseCkbLogLine, + readLogTail, + resolveLogPath, +} from '../devnet/log-file'; +import { readSettings, Settings } from '../cfg/setting'; +import { logger as defaultLogger, UnifiedLogger } from '../util/logger'; + +export interface LogsOptions { + follow?: boolean; + grep?: string; + tail?: number; +} + +const DEFAULT_TAIL = 100; + +/** + * Print (and optionally follow) a devnet log file. The core is synchronous so + * it can be unit tested with temp files; --follow hands control to + * followLogFile and keeps the process alive until Ctrl-C. + */ +export function showLogs(target: LogTarget, options: LogsOptions, settings: Settings, logger: UnifiedLogger): void { + const filePath = resolveLogPath(target, settings); + const tail = options.tail ?? DEFAULT_TAIL; + + let lines = readLogTail(filePath, tail); + const scriptOnly = target === 'script'; + if (scriptOnly) lines = filterLinesByTarget(lines, SCRIPT_LOG_TARGET); + if (options.grep) lines = grepLines(lines, options.grep); + for (const line of lines) logger.info(line); + + if (!options.follow) return; + + let inScriptEntry = false; + followLogFile(filePath, (line) => { + let show = true; + if (scriptOnly) { + // Unparsable lines are continuations of the previous entry. + const parsed = parseCkbLogLine(line); + if (parsed) inScriptEntry = parsed.target === SCRIPT_LOG_TARGET; + show = inScriptEntry; + } + if (show && options.grep && !line.includes(options.grep)) show = false; + if (show) logger.info(line); + }); +} + +export function logsCommand(target: string | undefined, options: LogsOptions): void { + const resolved: LogTarget = LOG_TARGETS.includes(target as LogTarget) ? (target as LogTarget) : 'node'; + showLogs(resolved, options, readSettings(), defaultLogger); +} diff --git a/src/cmd/node.ts b/src/cmd/node.ts index 146ba7d..23882bb 100644 --- a/src/cmd/node.ts +++ b/src/cmd/node.ts @@ -1,8 +1,13 @@ import { execFile, execFileSync, spawn, ChildProcess } from 'child_process'; import * as fs from 'fs'; import * as path from 'path'; -import { initChainIfNeeded } from '../node/init-chain'; -import { installCKBBinary } from '../node/install'; +import { + initChainIfNeeded, + devnetConfigHasTerminalRpc, + supportsTerminalRpcModule, + TERMINAL_RPC_MIN_CKB_VERSION, +} from '../node/init-chain'; +import { getVersionFromBinary, installCKBBinary } from '../node/install'; import { getCKBBinaryPath, readSettings } from '../cfg/setting'; import { createRPCProxy } from '../tools/rpc-proxy'; import { markForkFirstRunComplete, readForkState } from '../devnet/fork'; @@ -10,12 +15,15 @@ import { callJsonRpc } from '../util/json-rpc'; import { Network } from '../type/base'; import { logger } from '../util/logger'; import { checkNodeReadiness, waitForNodeReady } from '../devnet/readiness'; +import { devnetTcpListenAddress, subscribeToNodeLogs, SubscriptionHandle } from '../devnet/log-subscription'; +import { SCRIPT_LOG_TARGET } from '../devnet/log-file'; export interface NodeProp { version?: string; network?: Network; binaryPath?: string; daemon?: boolean; + verbose?: boolean; } interface PidMetadata { @@ -33,12 +41,18 @@ const NODE_READY_TIMEOUT_MS = 90_000; const FORK_NODE_READY_TIMEOUT_MS = 10 * 60_000; function cleanChildOutput(data: unknown): string { - // CKB colors its output even when it is redirected. Strip ANSI control - // sequences so JSON logs stay machine-readable. - return String(data).replace(/\u001b\[[0-?]*[ -/]*[@-~]/g, ''); + // CKB colors its output even when it is redirected, and log text relayed + // from the node (including contract debug! messages) is untrusted terminal + // input. Strip ANSI CSI/OSC sequences and C0/C1 control characters (keeping + // \n and \t) so JSON logs stay machine-readable and a crafted script log + // cannot inject terminal control sequences. + return String(data) + .replace(/\u001b\[[0-?]*[ -/]*[@-~]/g, '') + .replace(/\u001b\][^\u0007\u001b]*(?:\u0007|\u001b\\)/g, '') + .replace(/[\u0000-\u0008\u000b-\u001f\u007f-\u009f]/g, ''); } -export function startNode({ version, network = Network.devnet, binaryPath, daemon }: NodeProp) { +export function startNode({ version, network = Network.devnet, binaryPath, daemon, verbose }: NodeProp) { if (binaryPath && network !== Network.devnet) { logger.warn('Custom binaryPath is only supported for devnet. The provided binaryPath will be ignored.'); } @@ -48,7 +62,7 @@ export function startNode({ version, network = Network.devnet, binaryPath, daemo switch (network) { case Network.devnet: - return nodeDevnet({ version, binaryPath, daemon }); + return nodeDevnet({ version, binaryPath, daemon, verbose }); case Network.testnet: return nodeTestnet(); case Network.mainnet: @@ -58,7 +72,7 @@ export function startNode({ version, network = Network.devnet, binaryPath, daemo } } -export async function nodeDevnet({ version, binaryPath, daemon }: NodeProp) { +export async function nodeDevnet({ version, binaryPath, daemon, verbose }: NodeProp) { if (daemon) { return startDaemon(); } @@ -66,17 +80,42 @@ export async function nodeDevnet({ version, binaryPath, daemon }: NodeProp) { const settings = readSettings(); const ckbVersion = version || settings.bins.defaultCKBVersion; let ckbBinPath = ''; + // The version the chain config will be validated against. A managed binary + // knows its version by construction; a custom --binary-path is probed, and + // an unprobeable binary stays null (unknown → assume Terminal-capable). + let effectiveCkbVersion: string | null = null; if (binaryPath) { ckbBinPath = binaryPath; logger.info(`Using custom CKB binary path: ${ckbBinPath}`); + effectiveCkbVersion = getVersionFromBinary(ckbBinPath); } else { await installCKBBinary(ckbVersion); ckbBinPath = getCKBBinaryPath(ckbVersion); + effectiveCkbVersion = ckbVersion; } - await initChainIfNeeded(); + await initChainIfNeeded({ ckbVersion: effectiveCkbVersion }); const devnetConfigPath = settings.devnet.configPath; + // A config that enables the Terminal RPC module crashes CKB < 0.205.0 at + // startup with an opaque serde error ("unknown variant `Terminal`"). Catch + // that combination before spawning and say what is actually wrong. The + // version-aware init above never *adds* Terminal for such a binary, so + // hitting this means the config genuinely predates/downgraded past us. + if (!supportsTerminalRpcModule(effectiveCkbVersion) && devnetConfigHasTerminalRpc(devnetConfigPath)) { + throw new Error( + `The devnet config (${path.join(devnetConfigPath, 'ckb.toml')}) enables the "Terminal" RPC module, ` + + `which requires CKB >= ${TERMINAL_RPC_MIN_CKB_VERSION}; the selected binary is ${effectiveCkbVersion}. ` + + `Upgrade the CKB version or remove "Terminal" from rpc.modules in that file.`, + ); + } + if (!supportsTerminalRpcModule(effectiveCkbVersion)) { + logger.info( + `CKB ${effectiveCkbVersion} predates the Terminal RPC module; ` + + `the system-metric panels of \`offckb status\` require CKB >= ${TERMINAL_RPC_MIN_CKB_VERSION}.`, + ); + } + // A forked devnet must boot once with --skip-spec-check --overwrite-spec so // the imported (and patched) spec replaces the source chain's stored spec. const forkState = readForkState(settings.devnet.configPath); @@ -89,8 +128,24 @@ export async function nodeDevnet({ version, binaryPath, daemon }: NodeProp) { const runArgs = ['run', '-C', devnetConfigPath]; if (firstRunFlags) runArgs.push('--skip-spec-check', '--overwrite-spec'); const ckbProcess = spawn(ckbBinPath, runArgs, { stdio: ['ignore', 'pipe', 'pipe'] }); - ckbProcess.stdout?.on('data', (data) => logger.info(['CKB:', cleanChildOutput(data)])); - ckbProcess.stderr?.on('data', (data) => logger.error(['CKB error:', cleanChildOutput(data)])); + // Quiet by default: the node keeps its full log in data/logs/run.log + // (see `offckb logs`), and contract script debug output streams over the + // TCP log subscription below. --verbose restores the raw stdout/stderr relay. + // stdout must be drained either way or the child blocks on a full pipe + // buffer once the OS pipe fills. + if (verbose) { + ckbProcess.stdout?.on('data', (data) => logger.info(['CKB:', cleanChildOutput(data)])); + } else { + ckbProcess.stdout?.on('data', () => {}); + } + // Keep a bounded stderr tail so a startup crash can be translated into an + // actionable error below (CKB's own config errors are notoriously opaque). + let ckbStderrTail = ''; + ckbProcess.stderr?.on('data', (data) => { + const text = cleanChildOutput(data); + ckbStderrTail = (ckbStderrTail + text).slice(-4096); + if (verbose) logger.error(['CKB error:', text]); + }); let ckbExited = false; ckbProcess.once('exit', () => { @@ -104,7 +159,11 @@ export async function nodeDevnet({ version, binaryPath, daemon }: NodeProp) { const readiness = await waitForNodeReady(settings.devnet.rpcUrl, timeoutMs, () => !ckbExited); if (!readiness.ready) { if (!ckbExited) ckbProcess.kill('SIGTERM'); - throw new Error(`CKB devnet failed to become ready: ${readiness.error ?? 'CKB process exited'}`); + const hint = terminalRpcUnknownVariantHint(ckbStderrTail, devnetConfigPath); + throw new Error( + `CKB devnet failed to become ready: ${readiness.error ?? 'CKB process exited'}${hint ?? ''} ` + + 'Check the node log with `offckb logs` or rerun with --verbose for full output.', + ); } if (ckbExited) { throw new Error('CKB devnet exited immediately after its readiness check.'); @@ -126,8 +185,13 @@ export async function nodeDevnet({ version, binaryPath, daemon }: NodeProp) { ckbProcess.kill('SIGTERM'); throw new Error(`CKB miner failed to start: ${(error as Error).message}`); } - minerProcess.stdout?.on('data', (data) => logger.info(['CKB-Miner:', cleanChildOutput(data)])); - minerProcess.stderr?.on('data', (data) => logger.error(['CKB-Miner error:', cleanChildOutput(data)])); + if (verbose) { + minerProcess.stdout?.on('data', (data) => logger.info(['CKB-Miner:', cleanChildOutput(data)])); + minerProcess.stderr?.on('data', (data) => logger.error(['CKB-Miner error:', cleanChildOutput(data)])); + } else { + minerProcess.stdout?.on('data', () => {}); + minerProcess.stderr?.on('data', () => {}); + } try { await waitForChildSpawn(minerProcess, 'CKB miner'); } catch (error) { @@ -141,7 +205,27 @@ export async function nodeDevnet({ version, binaryPath, daemon }: NodeProp) { const proxy = createRPCProxy(Network.devnet, settings.devnet.rpcUrl, settings.devnet.rpcProxyPort); proxy.start(); + + // Contract script debug output (debug! in scripts) streams live over the + // node's TCP log subscription; everything else stays in the log files. + let logSubscription: SubscriptionHandle | null = null; + const tcpAddress = devnetTcpListenAddress(); + if (tcpAddress) { + logSubscription = subscribeToNodeLogs( + tcpAddress, + (entry) => { + if (entry.target === SCRIPT_LOG_TARGET) logger.info(['CKB-Script:', cleanChildOutput(entry.message)]); + }, + (error) => logger.warn(`${error.message} Full logs remain available via: offckb logs -f`), + ); + } else if (!verbose) { + logger.debug('No tcp_listen_address in ckb.toml; script debug output will not stream live.'); + } + logger.success(`CKB devnet is ready at ${settings.devnet.rpcUrl}.`); + if (!verbose) { + logger.info('Follow the full node log with: offckb logs -f'); + } logger.result({ command: 'node', network: Network.devnet, @@ -156,6 +240,7 @@ export async function nodeDevnet({ version, binaryPath, daemon }: NodeProp) { const stopService = (component: 'CKB node' | 'CKB miner', code: number | null, signal: NodeJS.Signals | null) => { if (serviceStopping) return; serviceStopping = true; + logSubscription?.close(); if (component !== 'CKB node' && !ckbProcess.killed) ckbProcess.kill('SIGTERM'); if (component !== 'CKB miner' && !minerProcess.killed) minerProcess.kill('SIGTERM'); proxy.stop(); @@ -167,6 +252,19 @@ export async function nodeDevnet({ version, binaryPath, daemon }: NodeProp) { minerProcess.once('exit', (code, signal) => stopService('CKB miner', code, signal)); } +// CKB < 0.205.0 rejects the Terminal RPC module during config deserialization +// with a serde "unknown variant `Terminal`" error and exits. When startup +// fails with that signature — the realistic case being a custom --binary-path +// whose version could not be probed — point at the actual cause instead of +// leaving the user with the raw serde message. +export function terminalRpcUnknownVariantHint(stderrTail: string, devnetConfigPath: string): string | null { + if (!/unknown variant [`'"]?Terminal/.test(stderrTail)) return null; + return ( + ` The "Terminal" RPC module requires CKB >= ${TERMINAL_RPC_MIN_CKB_VERSION}; ` + + `remove "Terminal" from rpc.modules in ${path.join(devnetConfigPath, 'ckb.toml')} or use a newer CKB binary.` + ); +} + function waitForChildSpawn(child: ChildProcess, label: string): Promise { return new Promise((resolve, reject) => { const onSpawn = () => { diff --git a/src/cmd/status.ts b/src/cmd/status.ts index 3bd331e..fbd2e75 100644 --- a/src/cmd/status.ts +++ b/src/cmd/status.ts @@ -1,10 +1,8 @@ -import fs from 'fs'; -import path from 'path'; -import toml, { JsonMap } from '@iarna/toml'; import { readSettings } from '../cfg/setting'; import { CKBTui } from '../tools/ckb-tui'; import { Network } from '../type/base'; import { checkNodeReadiness } from '../devnet/readiness'; +import { devnetTcpListenAddress } from '../devnet/log-subscription'; export interface StatusOptions { network: Network; @@ -18,28 +16,6 @@ const NETWORK_SETTINGS_KEY: Record = { [Network.mainnet]: 'mainnet', }; -/** - * Best-effort lookup of the devnet node's TCP subscription endpoint from its - * ckb.toml. ckb-tui connects to it directly (the OffCKB proxy is HTTP-only) to - * stream new/rejected transactions and logs; when absent, those dashboards - * simply stay empty, so any failure here is non-fatal. - */ -function devnetTcpListenAddress(): string | undefined { - try { - const settings = readSettings(); - const ckbTomlPath = path.join(settings.devnet.configPath, 'ckb.toml'); - if (!fs.existsSync(ckbTomlPath)) return undefined; - const parsed = toml.parse(fs.readFileSync(ckbTomlPath, 'utf8')); - const rpc = parsed.rpc as JsonMap | undefined; - const address = rpc?.tcp_listen_address; - if (typeof address !== 'string' || address.trim().length === 0) return undefined; - // A wildcard bind is not a dialable address; the node runs on this host. - return address.trim().replace(/^0\.0\.0\.0:/, '127.0.0.1:'); - } catch { - return undefined; - } -} - export async function status({ network }: StatusOptions) { // ckb-tui is an interactive terminal UI. Running it without a TTY // (pipe, redirect, CI) would hang or produce garbage output. diff --git a/src/devnet/log-file.ts b/src/devnet/log-file.ts new file mode 100644 index 0000000..b5bef6e --- /dev/null +++ b/src/devnet/log-file.ts @@ -0,0 +1,159 @@ +import * as fs from 'fs'; +import * as path from 'path'; +import { TextDecoder } from 'util'; +import { Settings } from '../cfg/setting'; +import { Network } from '../type/base'; + +/** + * Shared plumbing for the `offckb logs` command. + * + * CKB always writes its node log to `/logs/run.log` and the miner log to + * `/logs/miner.log` (log_to_file = true in the bundled config), and the + * RPC proxy appends its own events to `/logs/proxy.log`. The files are + * the one log source that exists in every run mode (foreground, daemon, and + * while `offckb status` is attached), so the logs command is a thin reader + * over them instead of a new logging pipeline. + */ + +export type LogTarget = 'node' | 'script' | 'miner' | 'rpc'; +export const LOG_TARGETS: LogTarget[] = ['node', 'script', 'miner', 'rpc']; + +export interface CkbLogLine { + timestamp: string; + thread: string; + level: string; + target: string; + message: string; +} + +// 2026-07-29 11:31:27.149 +00:00 main INFO ckb_bin::subcommand::run ckb version: ... +// The level is NOT padded and the message is separated from the target by +// whitespace (two spaces in practice; be lenient). +const CKB_LOG_LINE = /^(\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}(?:\.\d+)? [+-]\d{2}:\d{2}) (\S+) ([A-Z]+) (\S+)\s+(.*)$/; + +export const SCRIPT_LOG_TARGET = 'ckb-script'; + +export function parseCkbLogLine(line: string): CkbLogLine | null { + const match = line.match(CKB_LOG_LINE); + if (!match) return null; + return { timestamp: match[1], thread: match[2], level: match[3], target: match[4], message: match[5] }; +} + +/** + * Keep lines emitted by the given CKB log target. A line that does not parse + * (stack traces, multi-line contract debug output) belongs to the entry above + * it, so it is kept only when the preceding entry matched. + */ +export function filterLinesByTarget(lines: string[], target: string): string[] { + const kept: string[] = []; + let previousKept = false; + for (const line of lines) { + const parsed = parseCkbLogLine(line); + if (parsed) { + previousKept = parsed.target === target; + if (previousKept) kept.push(line); + } else if (previousKept) { + kept.push(line); + } + } + return kept; +} + +export function tailLines(content: string, count: number): string[] { + const lines = content.split('\n'); + // A trailing newline produces a final empty element that is not a log line. + if (lines.length > 0 && lines[lines.length - 1] === '') lines.pop(); + return count >= lines.length ? lines : lines.slice(lines.length - count); +} + +export function grepLines(lines: string[], pattern: string): string[] { + return lines.filter((line) => line.includes(pattern)); +} + +const LOG_FILE_NAMES: Record, string> = { + node: 'run.log', + script: 'run.log', + miner: 'miner.log', +}; + +/** + * The proxy's event log. Derived from the per-network transactions path + * (`//transactions`) so every network lands in its own data + * folder; for devnet this is `/logs/proxy.log`, next to run.log. + */ +export function proxyLogPathForNetwork(network: Network, settings: Settings): string { + return path.resolve(settings[network].transactionsPath, '..', 'data', 'logs', 'proxy.log'); +} + +export function resolveLogPath(target: LogTarget, settings: Settings): string { + if (target === 'rpc') return proxyLogPathForNetwork(Network.devnet, settings); + return path.join(settings.devnet.dataPath, 'logs', LOG_FILE_NAMES[target]); +} + +export function readLogTail(filePath: string, count: number): string[] { + let content: string; + try { + content = fs.readFileSync(filePath, 'utf8'); + } catch (error) { + const err = error as NodeJS.ErrnoException; + if (err.code === 'ENOENT') { + throw new Error( + `Log file not found at ${filePath}. Start the devnet first (offckb node) and make sure ` + + 'ckb.toml keeps log_to_file = true.', + ); + } + throw error; + } + return tailLines(content, count); +} + +/** + * Stream appended lines from a log file, `tail -f` style. Starts at the + * current end of file; reopen from offset 0 when the file is truncated or + * rotated away. Polling (fs.watchFile) is used instead of fs.watch because it + * behaves consistently across platforms and network filesystems. Returns a + * stop function. + */ +export function followLogFile(filePath: string, onLine: (line: string) => void, intervalMs = 250): () => void { + let offset = fs.existsSync(filePath) ? fs.statSync(filePath).size : 0; + let partial = ''; + // Streaming decoder: a multi-byte UTF-8 character split across two reads + // must not decode into replacement characters. + let decoder = new TextDecoder('utf-8'); + + const onChange = (curr: fs.Stats, prev: fs.Stats) => { + if (curr.size < prev.size || curr.size < offset) { + // Truncated or rotated: restart from the beginning. + offset = 0; + partial = ''; + decoder = new TextDecoder('utf-8'); + } + if (curr.size === offset) return; + + let fd: number; + try { + fd = fs.openSync(filePath, 'r'); + } catch { + return; // briefly missing during rotation; next tick retries + } + try { + const length = curr.size - offset; + const buffer = Buffer.alloc(length); + // readSync may return fewer bytes than requested; only decode what was + // actually read and leave the rest for the next tick. + const bytesRead = fs.readSync(fd, buffer, 0, length, offset); + offset += bytesRead; + const text = partial + decoder.decode(buffer.subarray(0, bytesRead), { stream: true }); + const lines = text.split('\n'); + partial = lines.pop() ?? ''; + for (const line of lines) { + if (line.length > 0) onLine(line); + } + } finally { + fs.closeSync(fd); + } + }; + + fs.watchFile(filePath, { interval: intervalMs }, onChange); + return () => fs.unwatchFile(filePath, onChange); +} diff --git a/src/devnet/log-subscription.ts b/src/devnet/log-subscription.ts new file mode 100644 index 0000000..2e9fd5d --- /dev/null +++ b/src/devnet/log-subscription.ts @@ -0,0 +1,183 @@ +import * as net from 'net'; +import * as fs from 'fs'; +import * as path from 'path'; +import toml, { JsonMap } from '@iarna/toml'; +import { readSettings } from '../cfg/setting'; + +/** + * Client for the CKB node's TCP JSON-RPC log subscription (the same channel + * ckb-tui uses). The node streams every log entry it emits as a structured + * { message, level, target, date } record, which lets the foreground node + * show contract script debug output without relaying raw stdout. + */ + +/** + * Best-effort lookup of the devnet node's TCP subscription endpoint from its + * ckb.toml. Consumers connect to it directly (the OffCKB proxy is HTTP-only) + * to stream log entries; when absent, any failure here is non-fatal. + */ +export function devnetTcpListenAddress(): string | undefined { + try { + const settings = readSettings(); + const ckbTomlPath = path.join(settings.devnet.configPath, 'ckb.toml'); + if (!fs.existsSync(ckbTomlPath)) return undefined; + const parsed = toml.parse(fs.readFileSync(ckbTomlPath, 'utf8')); + const rpc = parsed.rpc as JsonMap | undefined; + const address = rpc?.tcp_listen_address; + if (typeof address !== 'string' || address.trim().length === 0) return undefined; + // A wildcard bind is not a dialable address; the node runs on this host. + return address.trim().replace(/^0\.0\.0\.0:/, '127.0.0.1:'); + } catch { + return undefined; + } +} + +export interface CkbLogEntry { + message: string; + level: string; + target: string; + date: string; +} + +export interface SubscriptionHandle { + close(): void; +} + +export interface SubscribeOptions { + maxAttempts?: number; + retryDelayMs?: number; +} + +export function parseTcpListenAddress(address: string): { host: string; port: number } | null { + const match = address.match(/^(.+):(\d+)$/); + if (!match) return null; + const port = Number(match[2]); + if (!Number.isInteger(port) || port <= 0 || port > 65535) return null; + return { host: match[1], port }; +} + +export function parseSubscriptionMessage(line: string): { subscriptionId?: string; entry?: CkbLogEntry } | null { + let parsed: unknown; + try { + parsed = JSON.parse(line); + } catch { + return null; + } + if (parsed == null || typeof parsed !== 'object') return null; + const message = parsed as Record; + + // Subscribe response: {"jsonrpc":"2.0","result":"","id":1} + if (typeof message.result === 'string' && message.id !== undefined) { + return { subscriptionId: message.result }; + } + + // Notification: {"jsonrpc":"2.0","method":"subscribe","params":{"result":{...entry},"subscription":""}} + if (message.method === 'subscribe' && message.params != null && typeof message.params === 'object') { + const params = message.params as Record; + const result = params.result; + if (result != null && typeof result === 'object') { + const entry = result as Record; + if (typeof entry.message === 'string' && typeof entry.target === 'string') { + return { + entry: { + message: entry.message, + level: typeof entry.level === 'string' ? entry.level : '', + target: entry.target, + date: typeof entry.date === 'string' ? entry.date : '', + }, + }; + } + } + } + + return null; +} + +/** + * Subscribe to the node's "log" topic. The initial connect retries briefly + * because the TCP listener can lag the HTTP RPC readiness check; after + * maxAttempts the failure is reported via onError exactly once and the client + * gives up (the full log remains available through `offckb logs -f`). + */ +export function subscribeToNodeLogs( + tcpAddress: string, + onEntry: (entry: CkbLogEntry) => void, + onError?: (error: Error) => void, + options: SubscribeOptions = {}, +): SubscriptionHandle { + const maxAttempts = options.maxAttempts ?? 10; + const retryDelayMs = options.retryDelayMs ?? 500; + const endpoint = parseTcpListenAddress(tcpAddress); + + let socket: net.Socket | null = null; + let closed = false; + let attempts = 0; + let failedReported = false; + // Retries exist only to bridge the startup window where the TCP listener + // lags HTTP readiness; once a subscription was live, a later drop is + // terminal here (the supervisor tears the whole service down anyway). + let everConnected = false; + let retryTimer: NodeJS.Timeout | null = null; + + const fail = (error: Error) => { + if (failedReported || closed) return; + failedReported = true; + onError?.(error); + }; + + const connect = () => { + if (closed || endpoint == null) return; + retryTimer = null; + attempts += 1; + const conn = net.connect(endpoint.port, endpoint.host); + socket = conn; + let buffer = ''; + + conn.on('connect', () => { + everConnected = true; + conn.write(JSON.stringify({ id: 1, jsonrpc: '2.0', method: 'subscribe', params: ['log'] }) + '\n'); + }); + conn.on('data', (data) => { + buffer += data.toString('utf8'); + const lines = buffer.split('\n'); + buffer = lines.pop() ?? ''; + for (const line of lines) { + if (!line.trim()) continue; + const parsed = parseSubscriptionMessage(line); + if (parsed?.entry) onEntry(parsed.entry); + } + }); + conn.on('error', (error) => { + if (closed) return; + if (everConnected) return; + if (attempts < maxAttempts) { + retryTimer = setTimeout(connect, retryDelayMs); + // A pending retry must not keep the process alive on its own. + retryTimer.unref(); + } else { + fail(new Error(`Log subscription to ${tcpAddress} failed after ${attempts} attempts: ${error.message}`)); + } + }); + conn.on('close', () => { + // The supervisor tears the whole service down when the node dies, so a + // dropped subscription mid-run needs no reconnect of its own. + if (socket === conn) socket = null; + }); + }; + + if (endpoint == null) { + fail(new Error(`Log subscription address ${tcpAddress} is invalid.`)); + } else { + connect(); + } + + return { + close() { + closed = true; + if (retryTimer) clearTimeout(retryTimer); + retryTimer = null; + socket?.destroy(); + socket = null; + }, + }; +} diff --git a/src/node/init-chain.ts b/src/node/init-chain.ts index b030cb7..94f9534 100644 --- a/src/node/init-chain.ts +++ b/src/node/init-chain.ts @@ -1,14 +1,24 @@ import fs from 'fs'; import path from 'path'; +import semver from 'semver'; import toml, { JsonMap } from '@iarna/toml'; import { isFolderExists, copyFilesWithExclusion } from '../util/fs'; import { packageRootPath, readSettings } from '../cfg/setting'; import { logger } from '../util/logger'; -export async function initChainIfNeeded() { +export interface InitChainOptions { + // Version of the CKB binary the chain is being initialized for, when known. + // Drives whether the Terminal RPC module (CKB >= 0.205.0) may appear in the + // resulting ckb.toml. Null/undefined means "unknown" and keeps the + // historical behavior of assuming support. + ckbVersion?: string | null; +} + +export async function initChainIfNeeded(options: InitChainOptions = {}) { const settings = readSettings(); const devnetSourcePath = path.resolve(packageRootPath, './ckb/devnet'); const devnetConfigPath = settings.devnet.configPath; + const ckbTomlPath = path.join(devnetConfigPath, 'ckb.toml'); const requiredConfigFiles = ['ckb.toml', 'ckb-miner.toml', path.join('specs', 'dev.toml')]; const isInitialized = isFolderExists(devnetConfigPath) && @@ -20,6 +30,10 @@ export async function initChainIfNeeded() { // check therefore mistakes a fresh install for an initialized chain. Check // the files CKB actually needs instead, and repair an incomplete directory. if (!isInitialized) { + // Whether the ckb.toml about to be written is the pristine bundled + // template (as opposed to a pre-existing user file being repaired around). + // Only a pristine template may be adapted to the CKB version below. + const ckbTomlWasMissing = !fs.existsSync(ckbTomlPath); await copyFilesWithExclusion(devnetSourcePath, devnetConfigPath, ['data'], false); logger.debug(`init devnet config folder: ${devnetConfigPath}`); @@ -33,14 +47,53 @@ export async function initChainIfNeeded() { // Write the modified content back to the file fs.writeFileSync(minerConfigPath, modifiedData, 'utf8'); } + + // The bundled template enables the Terminal RPC module, which CKB + // versions before 0.205.0 reject at startup (serde "unknown variant"). + // Strip it from a freshly laid-down template when the binary is known to + // be too old. A pre-existing ckb.toml is never edited here — that case is + // reported to the user by the caller instead of silently rewritten. + if (ckbTomlWasMissing && !supportsTerminalRpcModule(options.ckbVersion)) { + removeTerminalRpcModule(ckbTomlPath, options.ckbVersion ?? null); + } } - migrateLegacyDevnetRpcConfig(devnetConfigPath); + migrateLegacyDevnetRpcConfig(devnetConfigPath, options.ckbVersion); } const TERMINAL_RPC_MODULE = 'Terminal'; const DEFAULT_TCP_LISTEN_ADDRESS = '127.0.0.1:18114'; +// The Terminal RPC module (nervosnetwork/ckb#4989) first shipped in CKB +// v0.205.0. Older binaries fail config deserialization on it at startup. +export const TERMINAL_RPC_MIN_CKB_VERSION = '0.205.0'; + +// Unknown (null/undefined/unparseable) versions keep the historical behavior +// of assuming support — a custom binary whose version cannot be probed must +// not lose functionality it may actually have. +export function supportsTerminalRpcModule(ckbVersion: string | null | undefined): boolean { + if (ckbVersion == null || !semver.valid(ckbVersion)) return true; + return semver.gte(ckbVersion, TERMINAL_RPC_MIN_CKB_VERSION); +} + +// Whether the chain's ckb.toml currently enables the Terminal RPC module. +// Unreadable or invalid configs report false and are left for CKB itself to +// complain about. +export function devnetConfigHasTerminalRpc(devnetConfigPath: string): boolean { + try { + const ckbTomlPath = path.join(devnetConfigPath, 'ckb.toml'); + if (!fs.existsSync(ckbTomlPath)) return false; + const parsed = toml.parse(fs.readFileSync(ckbTomlPath, 'utf8')); + const rpc = parsed.rpc as JsonMap | undefined; + const modules = rpc?.modules; + return ( + Array.isArray(modules) && modules.every((m) => typeof m === 'string') && modules.includes(TERMINAL_RPC_MODULE) + ); + } catch { + return false; + } +} + function findRpcSection(lines: string[]): { start: number; end: number } | null { const start = lines.findIndex((line) => /^\s*\[rpc\]\s*$/.test(line)); if (start < 0) return null; @@ -90,6 +143,59 @@ function addTerminalModule(lines: string[], section: { start: number; end: numbe return true; } +// Inverse of addTerminalModule: drops "Terminal" from the rpc.modules array, +// preserving the file's formatting. Handles the single-line template layout +// and hand-formatted multi-line arrays. +function removeTerminalModule(lines: string[], section: { start: number; end: number }): boolean { + const modulesStart = lines.findIndex( + (line, index) => index > section.start && index < section.end && /^\s*modules\s*=\s*\[/.test(line), + ); + if (modulesStart < 0) return false; + + if (lines[modulesStart].includes(']')) { + const line = lines[modulesStart]; + // Terminal last (the bundled template), Terminal first, or Terminal alone. + let updated = line.replace(/,\s*"Terminal"/, ''); + if (updated === line) updated = line.replace(/"Terminal"\s*,\s*/, ''); + if (updated === line) updated = line.replace(/\[\s*"Terminal"\s*\]/, '[]'); + if (updated === line) return false; + lines[modulesStart] = updated; + return true; + } + + // Multi-line array: drop the line holding the Terminal entry. + for (let i = modulesStart + 1; i < section.end; i++) { + if (/^\s*"Terminal",?\s*$/.test(lines[i])) { + lines.splice(i, 1); + return true; + } + if (lines[i].includes(']')) break; + } + return false; +} + +// Removes the Terminal RPC module from a ckb.toml known to be the bundled +// template, for CKB versions too old to support it. Text-based like the +// migration so the template's comments survive; failure is non-fatal and +// simply leaves the template as-is (CKB then reports the config error). +function removeTerminalRpcModule(ckbTomlPath: string, ckbVersion: string | null) { + try { + const source = fs.readFileSync(ckbTomlPath, 'utf8'); + const lines = source.split('\n'); + const section = findRpcSection(lines); + if (section == null) return; + if (!removeTerminalModule(lines, section)) return; + + fs.writeFileSync(ckbTomlPath, lines.join('\n'), 'utf8'); + logger.info( + `CKB ${ckbVersion ?? '< 0.205.0'} does not support the Terminal RPC module; removed it from the new devnet ckb.toml. ` + + `The system-metric panels of \`offckb status\` (ckb-tui) require CKB >= ${TERMINAL_RPC_MIN_CKB_VERSION}.`, + ); + } catch (error) { + logger.debug(`skipping Terminal RPC module removal: ${(error as Error).message}`); + } +} + // Enables rpc.tcp_listen_address. Only the stock loopback default is // uncommented in place — a commented non-loopback value (e.g. 0.0.0.0) stays // disabled and a fresh loopback entry is inserted after the modules array @@ -126,9 +232,14 @@ function enableTcpListenAddress(lines: string[], section: { start: number; end: * fresh config folders, so chains initialized before that change never picked * it up. Edits are text-based to keep user comments/formatting intact, and * any failure is non-fatal — node startup must never break over a migration. - * Returns true when the file was changed. + * + * When ckbVersion is known to predate the Terminal RPC module (< 0.205.0), + * Terminal is NOT added — otherwise every `offckb node` start would re-add + * what the user removed and crash the old binary at startup. The + * tcp_listen_address half predates 0.205.0 by a wide margin and still + * applies. Returns true when the file was changed. */ -export function migrateLegacyDevnetRpcConfig(devnetConfigPath: string): boolean { +export function migrateLegacyDevnetRpcConfig(devnetConfigPath: string, ckbVersion?: string | null): boolean { const ckbTomlPath = path.join(devnetConfigPath, 'ckb.toml'); try { if (!fs.existsSync(ckbTomlPath)) return false; @@ -140,7 +251,10 @@ export function migrateLegacyDevnetRpcConfig(devnetConfigPath: string): boolean const modules = rpc.modules; const needsTerminal = - Array.isArray(modules) && modules.every((m) => typeof m === 'string') && !modules.includes(TERMINAL_RPC_MODULE); + supportsTerminalRpcModule(ckbVersion) && + Array.isArray(modules) && + modules.every((m) => typeof m === 'string') && + !modules.includes(TERMINAL_RPC_MODULE); const tcpAddress = rpc.tcp_listen_address; const needsTcp = typeof tcpAddress !== 'string' || tcpAddress.trim().length === 0; if (!needsTerminal && !needsTcp) return false; diff --git a/src/tools/ckb-tui.ts b/src/tools/ckb-tui.ts index d65602e..f04b33c 100644 --- a/src/tools/ckb-tui.ts +++ b/src/tools/ckb-tui.ts @@ -15,9 +15,14 @@ const EXTRACT_TIMEOUT_MS = 60_000; const STRICT_VERSION_REGEX = /^v(0|[1-9]\d*)\.(0|[1-9]\d*)\.(0|[1-9]\d*)$/; // Independently pinned digests for the default release. Keeping these in -// offckb makes the default installation verifiable even though ckb-tui v0.1.3 +// offckb makes the default installation verifiable even though ckb-tui v0.1.4 // did not upload a checksums-sha256.txt asset. const KNOWN_SHA256: Record> = { + 'v0.1.4': { + 'ckb-tui-with-node-linux-amd64.tar.gz': 'eaed2cfbd55c4ee78493200bf33b5b120ec2625df4e7041b048cd87d51801cbd', + 'ckb-tui-with-node-macos-aarch64.tar.gz': '911aa3f1266fd333d2566e798df888ffb105b35da7d9328d7b715f3be7adc246', + 'ckb-tui-with-node-windows-amd64.zip': 'aab24826e0951188f72ddc1c128148899c54237dc9cc4bd5929038504cdd0dfa', + }, 'v0.1.3': { 'ckb-tui-with-node-linux-amd64.tar.gz': '33455cefe2c016149fa8fa3abde7960b348d4606afef9279d787ac8a8b59956f', 'ckb-tui-with-node-macos-aarch64.tar.gz': 'de18107ec179ced03608da956013e38ae82e6c1fae588f12c17d138ee6ee072c', @@ -25,6 +30,26 @@ const KNOWN_SHA256: Record> = { }, }; +// Digests of the extracted ckb-tui binaries, keyed the same way as +// KNOWN_SHA256. ensureInstalled uses these to recognize a stale or foreign +// binary at the install path: ckb-tui's own `--version` output lags its +// release tag (the v0.1.4 binary still reports 0.1.2), so the on-disk digest +// is the only reliable identity. Versions without a pinned binary digest fall +// back to presence-only detection (install-time archive verification still +// applies). +const KNOWN_BINARY_SHA256: Record> = { + 'v0.1.4': { + 'ckb-tui-with-node-linux-amd64.tar.gz': 'e2c31db99e81ea6ae0455796464a671c10bf8fe74615c40b995c34ff57630b43', + 'ckb-tui-with-node-macos-aarch64.tar.gz': 'a9748cf1581568cf7409193d5cb851ea956a82a84fd69c08513fee351a8ad7fc', + 'ckb-tui-with-node-windows-amd64.zip': '2ed73cd9095b2f9b947377736e8013985f48a8c1e696a3dd78033af658aab612', + }, + 'v0.1.3': { + 'ckb-tui-with-node-linux-amd64.tar.gz': '2daca14ea8eba2a7888d1223c387a8d8e0846dafc424cd66891d4d96f4720005', + 'ckb-tui-with-node-macos-aarch64.tar.gz': 'e21971d59edce7d5d590ac05314d67343fb70187a73a8dd19af87a71e1fe34e0', + 'ckb-tui-with-node-windows-amd64.zip': 'b2fce1c161158e8a2dd5b5c5a796091f3c668e57e57b8dd403053ceef1301716', + }, +}; + export class CKBTui { private static binaryPath: string | null = null; @@ -44,15 +69,22 @@ export class CKBTui { /** * Returns the binary path, downloading and installing if the binary - * does not already exist. + * does not already exist or does not match the configured version's + * pinned digest (e.g. a stale binary from an older default release). */ static ensureInstalled(): string { const binaryPath = this.getBinaryPath(); - if (binaryPath && fs.existsSync(binaryPath)) { + if (binaryPath && this.installedBinaryMatches(binaryPath)) { return binaryPath; } + if (binaryPath && fs.existsSync(binaryPath)) { + logger.info('The installed ckb-tui does not match the configured release; reinstalling...'); + } - // Reset and re-install + // Re-install. The existing binary is deliberately left in place: installSync + // downloads, verifies, and extracts into a temp directory and only then + // publishes with an atomic rename, so a failed reinstall keeps the previous + // binary instead of stranding the user with none. this.binaryPath = null; this.installSync(); return this.binaryPath!; @@ -74,6 +106,37 @@ export class CKBTui { // --- private helpers --- + /** + * Verifies an existing on-disk binary against the configured version's + * pinned binary digest. Returns true when the binary may be kept: either it + * matches the digest, or the configured version has no pinned binary digest + * (presence-only fallback; install-time archive verification still applies). + * Missing, unreadable, or non-regular paths (e.g. a directory or FIFO) count + * as a mismatch so the reinstall flow runs instead of crashing with a raw fs + * error, blocking forever on a special file, or failing later at spawn time. + */ + private static installedBinaryMatches(binaryPath: string): boolean { + const settings = readSettings(); + const expected = KNOWN_BINARY_SHA256[settings.tools.ckbTui.version]?.[this.getAssetName()]; + try { + // Require a regular file first: opening a FIFO or device for reading + // would block indefinitely, before any digest comparison could run. + if (!fs.statSync(binaryPath).isFile()) { + return false; + } + // Metadata alone does not prove readability; an unreadable binary must + // flow into the reinstall path (which republishes with correct modes). + fs.accessSync(binaryPath, fs.constants.R_OK); + if (!expected) { + return true; + } + const actual = crypto.createHash('sha256').update(fs.readFileSync(binaryPath)).digest('hex'); + return actual === expected; + } catch { + return false; + } + } + /** * Resolve and validate that the configured rootFolder is under the * OffCKB data directory. Rejects paths that resolve outside. @@ -96,7 +159,7 @@ export class CKBTui { private static validateVersion(version: string): void { if (!STRICT_VERSION_REGEX.test(version)) { - throw new Error(`Invalid version format: "${version}". Expected format: vX.Y.Z (e.g., v0.1.3)`); + throw new Error(`Invalid version format: "${version}". Expected format: vX.Y.Z (e.g., v0.1.4)`); } } @@ -184,27 +247,11 @@ export class CKBTui { throw new Error(`ckb-tui binary ("${binaryName}") was not found after extraction.`); } - // 5. Move to the final location. renameSync is atomic but throws EXDEV - // when the temp dir and the data path live on different filesystems - // (common in containers). In that case stage the copy inside binDir and - // publish it with a rename, so a concurrent ensureInstalled() never sees - // a partially copied binary at the final path. - try { - fs.renameSync(extractedBinary, this.binaryPath); - } catch (error) { - if ((error as NodeJS.ErrnoException).code === 'EXDEV') { - const stagingPath = path.join(binDir, `.${binaryName}.staging-${process.pid}`); - try { - fs.copyFileSync(extractedBinary, stagingPath); - fs.renameSync(stagingPath, this.binaryPath); - fs.unlinkSync(extractedBinary); - } finally { - fs.rmSync(stagingPath, { force: true }); - } - } else { - throw error; - } - } + // 5. Publish the verified binary. publishExtractedBinary owns the edge + // cases: a directory occupying the install path is set aside (and + // restored on failure), and cross-filesystem temp dirs fall back to a + // staged copy next to the target. + this.publishExtractedBinary(extractedBinary, this.binaryPath); // 6. Make executable on Unix if (process.platform !== 'win32') { @@ -234,6 +281,74 @@ export class CKBTui { } } + /** + * Atomically publish the extracted binary to the install path. + * + * A directory occupying the install path (e.g. from a botched manual + * extraction) cannot be replaced by a file rename — without this handling + * the reinstall would fail on every attempt — so it is first set aside with + * a plain rename (its contents are never deleted) and restored if publishing + * fails. On success the aside directory is left in place and its location + * logged, so nothing the user put there is silently destroyed. + */ + private static publishExtractedBinary(extractedBinary: string, binaryPath: string): void { + let dirBackupPath: string | null = null; + let existing: fs.Stats | null = null; + try { + existing = fs.lstatSync(binaryPath); + } catch { + existing = null; // Nothing at the install path. + } + if (existing?.isDirectory()) { + dirBackupPath = `${binaryPath}.backup-${process.pid}-${Date.now()}`; + fs.renameSync(binaryPath, dirBackupPath); + } + + try { + this.renameIntoPlace(extractedBinary, binaryPath); + } catch (error) { + if (dirBackupPath) { + try { + fs.renameSync(dirBackupPath, binaryPath); + } catch { + // Best effort: the original directory remains at its backup path. + } + } + throw error; + } + + if (dirBackupPath) { + logger.info(`A directory unexpectedly occupied ${binaryPath}; moved it aside to ${dirBackupPath}.`); + } + } + + /** + * renameSync is atomic but throws EXDEV when source and target live on + * different filesystems (common in containers, where os.tmpdir() and the + * data path differ). In that case stage the copy next to the target and + * publish it with a rename, so a concurrent ensureInstalled() never sees a + * partially copied binary at the final path. + */ + private static renameIntoPlace(source: string, target: string): void { + try { + fs.renameSync(source, target); + } catch (error) { + if ((error as NodeJS.ErrnoException).code !== 'EXDEV') { + throw error; + } + const stagingPath = path.join(path.dirname(target), `.${path.basename(target)}.staging-${process.pid}`); + try { + fs.copyFileSync(source, stagingPath); + fs.renameSync(stagingPath, target); + // No cleanup of `source` here: it lives in the temp directory, which + // the caller removes regardless of outcome — don't let a cleanup + // error turn the successful publish above into a reported failure. + } finally { + fs.rmSync(stagingPath, { force: true }); + } + } + } + /** Verify against an independently pinned digest. */ private static verifyChecksum(version: string, assetName: string, archivePath: string): void { const pinnedHash = KNOWN_SHA256[version]?.[assetName]; diff --git a/src/tools/proxy-events.ts b/src/tools/proxy-events.ts new file mode 100644 index 0000000..d84f715 --- /dev/null +++ b/src/tools/proxy-events.ts @@ -0,0 +1,142 @@ +import * as fs from 'fs'; +import * as path from 'path'; + +/** + * Testable core of the RPC proxy's logging behavior. + * + * The proxy keeps the console quiet by default (per-request lines at debug + * level) while surfacing the two signals users actually watch for — + * submitted transaction hashes and JSON-RPC errors — and mirrors everything + * into `/logs/proxy.log` so `offckb logs rpc` can replay it. + */ + +export interface ProxyLogSink { + debug(...args: unknown[]): void; + info(...args: unknown[]): void; + warn(...args: unknown[]): void; + error(...args: unknown[]): void; +} + +export interface ProxyEventLog { + filePath: string; + event(text: string): void; +} + +export interface ProxyEventContext { + sink: ProxyLogSink; + events: ProxyEventLog; + transactionsPath: string; + hashTransaction(tx: unknown): string; +} + +/** + * One event is exactly one line in proxy.log: RPC method names and error + * messages come from the proxied payloads, so embedded newlines or control + * characters would otherwise forge log records or corrupt `offckb logs rpc` + * output. Sanitizing here covers every call site. + */ +function sanitizeEventText(text: string): string { + return text.replace(/[\u0000-\u001f\u007f-\u009f]/g, ' '); +} + +/** Default size cap for proxy.log; past it the file rolls over once to .1. */ +export const PROXY_LOG_MAX_BYTES = 10 * 1024 * 1024; + +/** + * Append-only writer for proxy.log. Directory creation is lazy and cached. + * Growth is bounded: once the file passes maxBytes it is renamed to + * `.1` (single rollover, replacing any previous one) and restarted. + */ +export function createProxyEventLog(filePath: string, maxBytes = PROXY_LOG_MAX_BYTES): ProxyEventLog { + let dirReady = false; + // In-memory size estimate so the cap costs no extra stat per event; + // -1 means "not measured yet" and is re-read lazily. + let size = -1; + return { + filePath, + event(text: string) { + try { + if (!dirReady) { + fs.mkdirSync(path.dirname(filePath), { recursive: true }); + dirReady = true; + } + const line = `${new Date().toISOString()} ${sanitizeEventText(text)}\n`; + if (size < 0) size = fs.existsSync(filePath) ? fs.statSync(filePath).size : 0; + if (size > 0 && size + Buffer.byteLength(line) > maxBytes) { + fs.rmSync(`${filePath}.1`, { force: true }); + fs.renameSync(filePath, `${filePath}.1`); + size = 0; + } + fs.appendFileSync(filePath, line); + size += Buffer.byteLength(line); + } catch { + // Logging must never break request forwarding. + dirReady = false; + size = -1; + } + }, + }; +} + +interface JsonRpcRequestPayload { + method?: unknown; + params?: unknown; +} + +export function handleProxyRequestBody(reqData: string, ctx: ProxyEventContext): void { + if (reqData.length === 0) return; + + try { + const jsonRpcContent = JSON.parse(reqData) as JsonRpcRequestPayload; + const method = jsonRpcContent.method; + const params = jsonRpcContent.params; + ctx.sink.debug('RPC Req: ', method); + if (typeof method === 'string') { + ctx.events.event(`request ${method}`); + } + + if (method === 'send_transaction') { + const tx = (params as unknown[])[0]; + const txHash = ctx.hashTransaction(tx); + if (!fs.existsSync(ctx.transactionsPath)) { + fs.mkdirSync(ctx.transactionsPath, { recursive: true }); + } + const txFile = path.resolve(ctx.transactionsPath, `${txHash}.json`); + fs.writeFileSync(txFile, JSON.stringify(tx, null, 2)); + // The hash line mirrors the RPC method name on purpose: at request time + // the proxy does not yet know whether the node will accept the tx, and + // any rejection surfaces separately as an RPC error line. + ctx.sink.info(`send_transaction: ${txHash}`); + ctx.events.event(`send_transaction ${txHash}`); + } + } catch (err) { + ctx.sink.error('Error parsing JSON-RPC req content:', (err as Error).message); + } +} + +interface JsonRpcErrorPayload { + error?: { code?: unknown; message?: unknown }; +} + +export function handleProxyResponseBody(res: string, contentType: string | undefined, ctx: ProxyEventContext): void { + if (res.length === 0) return; + // Real servers answer with parameters attached (application/json; + // charset=utf-8), so compare the bare media type, not the raw header. + const mediaType = (contentType ?? '').split(';')[0].trim().toLowerCase(); + if (mediaType !== 'application/json') return; + if (!res.trim().startsWith('{') && !res.trim().startsWith('[')) return; + + try { + const parsed = JSON.parse(res) as JsonRpcErrorPayload | JsonRpcErrorPayload[]; + const entries = Array.isArray(parsed) ? parsed : [parsed]; + for (const entry of entries) { + if (entry?.error == null) continue; + const code = entry.error.code ?? 'unknown'; + const message = entry.error.message ?? 'unknown error'; + ctx.sink.warn(`RPC error: [${code}] ${message}`); + ctx.events.event(`error [${code}] ${message}`); + } + } catch (err) { + ctx.sink.error('Error parsing JSON-RPC res content:', (err as Error).message); + } +} diff --git a/src/tools/rpc-proxy.ts b/src/tools/rpc-proxy.ts index 492ec4f..50304fc 100644 --- a/src/tools/rpc-proxy.ts +++ b/src/tools/rpc-proxy.ts @@ -1,15 +1,27 @@ import httpProxy from 'http-proxy'; import http from 'http'; import { Network } from '../type/base'; -import fs from 'fs'; import { readSettings } from '../cfg/setting'; -import path from 'path'; import { logger } from '../util/logger'; +import { proxyLogPathForNetwork } from '../devnet/log-file'; +import { createProxyEventLog, handleProxyRequestBody, handleProxyResponseBody } from './proxy-events'; // todo: if we use import this throws error in tsc building const { cccA } = require('@ckb-ccc/core/advanced'); export function createRPCProxy(network: Network, targetRpcUrl: string, port: number) { + const settings = readSettings(); + const events = createProxyEventLog(proxyLogPathForNetwork(network, settings)); + const ctx = { + sink: logger, + events, + transactionsPath: settings[network].transactionsPath, + hashTransaction: (tx: unknown) => { + const cccTx = cccA.JsonRpcTransformers.transactionTo(tx); + return cccTx.hash() as string; + }, + }; + const proxy = httpProxy.createProxyServer({ target: targetRpcUrl, // Target RPC server changeOrigin: true, // for https target to work @@ -20,33 +32,7 @@ export function createRPCProxy(network: Network, targetRpcUrl: string, port: num req.on('data', (chunk) => { reqData += chunk; }); - req.on('end', () => { - if (reqData.length === 0) return; - - try { - const jsonRpcContent = JSON.parse(reqData); - const method = jsonRpcContent.method; - const params = jsonRpcContent.params; - logger.info('RPC Req: ', method); - logger.debug('RPC Params: ', params); - - if (method === 'send_transaction') { - const tx = params[0]; - - const cccTx = cccA.JsonRpcTransformers.transactionTo(tx); - const txHash = cccTx.hash(); - const settings = readSettings(); - if (!fs.existsSync(settings[network].transactionsPath)) { - fs.mkdirSync(settings[network].transactionsPath); - } - const txFile = path.resolve(settings[network].transactionsPath, `${txHash}.json`); - fs.writeFileSync(txFile, JSON.stringify(tx, null, 2)); - logger.info(`RPC Req: store tx ${txHash}`); - } - } catch (err) { - logger.error('Error parsing JSON-RPC req content:', (err as Error).message); - } - }); + req.on('end', () => handleProxyRequestBody(reqData, ctx)); }); proxy.on('proxyRes', function (proxyRes, _req, _res) { @@ -56,16 +42,7 @@ export function createRPCProxy(network: Network, targetRpcUrl: string, port: num }); proxyRes.on('end', function () { const res = Buffer.concat(body).toString('utf-8'); - if (res.length === 0) return; - if (proxyRes.headers['content-type'] !== 'application/json') return; - if (!res.trim().startsWith('{') && !res.trim().startsWith('[')) return; - - try { - const jsonRpcResponse = JSON.parse(res); - logger.debug('RPC Response: ', jsonRpcResponse); - } catch (err) { - logger.error('Error parsing JSON-RPC res content:', (err as Error).message); - } + handleProxyResponseBody(res, proxyRes.headers['content-type'], ctx); }); }); diff --git a/src/tui/devnet-reference-templates.ts b/src/tui/devnet-reference-templates.ts index fe04fba..478fd8f 100644 --- a/src/tui/devnet-reference-templates.ts +++ b/src/tui/devnet-reference-templates.ts @@ -10,7 +10,7 @@ data_dir = "data" spec = { file = "specs/dev.toml" } [logger] -filter = "warn,ckb-script=debug" +filter = "info,ckb-script=debug" color = true log_to_file = true log_to_stdout = true @@ -193,7 +193,7 @@ data_dir = "data" spec = { file = "specs/dev.toml" } [logger] -filter = "warn,ckb-script=debug" +filter = "info,ckb-script=debug" color = true log_to_file = true log_to_stdout = true diff --git a/tests/ckb-tui-checksum.test.ts b/tests/ckb-tui-checksum.test.ts index e17bbfd..60fe109 100644 --- a/tests/ckb-tui-checksum.test.ts +++ b/tests/ckb-tui-checksum.test.ts @@ -30,7 +30,7 @@ describe('ckb-tui checksum policy', () => { it('enforces the pinned digest for the default release without a network fallback', () => { expect(() => (CKBTui as unknown as { verifyChecksum: (...args: string[]) => void }).verifyChecksum( - 'v0.1.3', + 'v0.1.4', 'ckb-tui-with-node-macos-aarch64.tar.gz', archive, ), diff --git a/tests/ckb-tui-install.test.ts b/tests/ckb-tui-install.test.ts new file mode 100644 index 0000000..4b308c5 --- /dev/null +++ b/tests/ckb-tui-install.test.ts @@ -0,0 +1,238 @@ +import fs from 'fs'; +import os from 'os'; +import path from 'path'; +import crypto from 'crypto'; +import { execFileSync } from 'child_process'; + +jest.mock('child_process', () => ({ + ...jest.requireActual('child_process'), + spawnSync: jest.fn(), +})); +jest.mock('../src/util/logger', () => ({ + logger: { info: jest.fn(), error: jest.fn(), warn: jest.fn() }, +})); + +const mockVersion = { current: 'v0.1.4' }; +const mockDirs = { dataRoot: '', toolsRoot: '' }; + +jest.mock('../src/cfg/setting', () => ({ + get dataPath() { + return mockDirs.dataRoot; + }, + readSettings: () => ({ + tools: { rootFolder: mockDirs.toolsRoot, ckbTui: { version: mockVersion.current } }, + }), +})); + +import { CKBTui } from '../src/tools/ckb-tui'; + +type CKBTuiInternals = { + binaryPath: string | null; + installSync: () => void; + installedBinaryMatches: (binaryPath: string) => boolean; + publishExtractedBinary: (extractedBinary: string, binaryPath: string) => void; +}; + +const binaryName = () => (process.platform === 'win32' ? 'ckb-tui.exe' : 'ckb-tui'); + +// Content the successful install spy publishes, standing in for the verified +// binary the real installSync would atomically rename into place. +const REPLACED_BINARY = 'verified replacement ckb-tui'; + +describe('ckb-tui installed-binary verification', () => { + const internals = CKBTui as unknown as CKBTuiInternals; + let realInstallSync: () => void; + let installSpy: jest.Mock; + let binaryPath: string; + + beforeEach(() => { + jest.clearAllMocks(); + mockDirs.dataRoot = fs.mkdtempSync(path.join(os.tmpdir(), 'offckb-tui-data-')); + mockDirs.toolsRoot = path.join(mockDirs.dataRoot, 'tools'); + fs.mkdirSync(mockDirs.toolsRoot, { recursive: true }); + binaryPath = path.join(mockDirs.toolsRoot, binaryName()); + mockVersion.current = 'v0.1.4'; + internals.binaryPath = null; + realInstallSync = internals.installSync; + // Mimic a successful installSync: publish a real regular replacement file + // at the install path (setting aside a directory that occupies it, like + // the real publish step does). Tests that need a failing install override + // this with a no-publish mockImplementation that throws. + installSpy = jest.fn().mockImplementation(() => { + try { + if (fs.lstatSync(binaryPath).isDirectory()) { + fs.renameSync(binaryPath, `${binaryPath}.set-aside`); + } + } catch { + // Nothing at the install path yet. + } + fs.writeFileSync(binaryPath, REPLACED_BINARY); + internals.binaryPath = binaryPath; + }); + internals.installSync = installSpy; + }); + + afterEach(() => { + internals.installSync = realInstallSync; + internals.binaryPath = null; + fs.rmSync(mockDirs.dataRoot, { recursive: true, force: true }); + jest.restoreAllMocks(); + }); + + const assetName = () => { + if (process.platform === 'darwin') return 'ckb-tui-with-node-macos-aarch64.tar.gz'; + if (process.platform === 'win32') return 'ckb-tui-with-node-windows-amd64.zip'; + return 'ckb-tui-with-node-linux-amd64.tar.gz'; + }; + + // The pinned binary digest for the current platform's v0.1.4 asset, kept in + // sync with KNOWN_BINARY_SHA256 in src/tools/ckb-tui.ts. + const pinnedDigest = () => + ( + ({ + 'ckb-tui-with-node-linux-amd64.tar.gz': 'e2c31db99e81ea6ae0455796464a671c10bf8fe74615c40b995c34ff57630b43', + 'ckb-tui-with-node-macos-aarch64.tar.gz': 'a9748cf1581568cf7409193d5cb851ea956a82a84fd69c08513fee351a8ad7fc', + 'ckb-tui-with-node-windows-amd64.zip': '2ed73cd9095b2f9b947377736e8013985f48a8c1e696a3dd78033af658aab612', + }) as Record + )[assetName()]; + + it('keeps an existing binary whose digest matches the configured release', () => { + fs.writeFileSync(binaryPath, 'installed ckb-tui'); + jest.spyOn(crypto, 'createHash').mockReturnValue({ + update: () => ({ digest: () => pinnedDigest() }), + } as unknown as crypto.Hash); + + expect(CKBTui.ensureInstalled()).toBe(binaryPath); + expect(installSpy).not.toHaveBeenCalled(); + }); + + it('reinstalls when the on-disk binary does not match the pinned digest', () => { + fs.writeFileSync(binaryPath, 'stale ckb-tui from an older release'); + installSpy.mockImplementation(() => { + // The stale binary is NOT deleted up front: it is still in place when + // the reinstall begins and is only replaced once the verified new + // binary is ready to publish. + expect(fs.readFileSync(binaryPath, 'utf8')).toBe('stale ckb-tui from an older release'); + fs.writeFileSync(binaryPath, REPLACED_BINARY); + internals.binaryPath = binaryPath; + }); + + expect(CKBTui.ensureInstalled()).toBe(binaryPath); + expect(installSpy).toHaveBeenCalledTimes(1); + expect(fs.statSync(binaryPath).isFile()).toBe(true); + expect(fs.readFileSync(binaryPath, 'utf8')).toBe(REPLACED_BINARY); + }); + + it('keeps the existing binary when the reinstall fails', () => { + fs.writeFileSync(binaryPath, 'stale ckb-tui from an older release'); + installSpy.mockImplementation(() => { + internals.binaryPath = null; + throw new Error('network down'); + }); + + expect(() => CKBTui.ensureInstalled()).toThrow('network down'); + expect(fs.readFileSync(binaryPath, 'utf8')).toBe('stale ckb-tui from an older release'); + }); + + it('treats a non-regular path at the binary location as a mismatch and reinstalls', () => { + fs.mkdirSync(binaryPath); + + expect(CKBTui.ensureInstalled()).toBe(binaryPath); + expect(installSpy).toHaveBeenCalledTimes(1); + expect(fs.statSync(binaryPath).isFile()).toBe(true); + expect(fs.readFileSync(binaryPath, 'utf8')).toBe(REPLACED_BINARY); + }); + + it('falls back to presence-only detection for a release without a pinned binary digest', () => { + mockVersion.current = 'v9.9.9'; + fs.writeFileSync(binaryPath, 'any content at all'); + + expect(CKBTui.ensureInstalled()).toBe(binaryPath); + expect(installSpy).not.toHaveBeenCalled(); + }); + + it('installs when no binary exists yet', () => { + expect(CKBTui.ensureInstalled()).toBe(binaryPath); + expect(installSpy).toHaveBeenCalledTimes(1); + expect(fs.statSync(binaryPath).isFile()).toBe(true); + expect(fs.readFileSync(binaryPath, 'utf8')).toBe(REPLACED_BINARY); + }); + + const itPosix = process.platform === 'win32' ? it.skip : it; + const itPosixNonRoot = process.platform === 'win32' || (process.getuid && process.getuid() === 0) ? it.skip : it; + + itPosix('does not block on a FIFO at the binary location', () => { + // Pinned digest path: the digest read must not open a FIFO, whose + // blocking read would hang ensureInstalled indefinitely. readFileSync is + // mocked to throw so a regression fails fast instead of hanging the Jest + // worker synchronously (a timer-based timeout cannot fire mid-read). + execFileSync('mkfifo', [binaryPath]); + const readFileSync = jest.spyOn(fs, 'readFileSync').mockImplementation(() => { + throw new Error('A FIFO must not be read'); + }); + + expect(internals.installedBinaryMatches(binaryPath)).toBe(false); + expect(readFileSync).not.toHaveBeenCalled(); + }); + + itPosixNonRoot('treats an unreadable binary as a mismatch', () => { + mockVersion.current = 'v9.9.9'; // Unpinned: presence alone must not suffice. + fs.writeFileSync(binaryPath, 'unreadable ckb-tui', { mode: 0o000 }); + + expect(internals.installedBinaryMatches(binaryPath)).toBe(false); + }); +}); + +describe('ckb-tui binary publishing', () => { + const internals = CKBTui as unknown as CKBTuiInternals; + let binDir: string; + let binaryPath: string; + + beforeEach(() => { + jest.clearAllMocks(); + binDir = fs.mkdtempSync(path.join(os.tmpdir(), 'offckb-tui-publish-')); + binaryPath = path.join(binDir, binaryName()); + }); + + afterEach(() => fs.rmSync(binDir, { recursive: true, force: true })); + + it('replaces an existing file in place', () => { + fs.writeFileSync(binaryPath, 'old binary'); + const extracted = path.join(binDir, 'extracted-ckb-tui'); + fs.writeFileSync(extracted, REPLACED_BINARY); + + internals.publishExtractedBinary(extracted, binaryPath); + + expect(fs.statSync(binaryPath).isFile()).toBe(true); + expect(fs.readFileSync(binaryPath, 'utf8')).toBe(REPLACED_BINARY); + }); + + it('replaces a directory occupying the install path without deleting its contents', () => { + fs.mkdirSync(binaryPath); + fs.writeFileSync(path.join(binaryPath, 'user-file.txt'), 'user data'); + const extracted = path.join(binDir, 'extracted-ckb-tui'); + fs.writeFileSync(extracted, REPLACED_BINARY); + + internals.publishExtractedBinary(extracted, binaryPath); + + expect(fs.statSync(binaryPath).isFile()).toBe(true); + expect(fs.readFileSync(binaryPath, 'utf8')).toBe(REPLACED_BINARY); + // The directory was set aside with a plain rename, not deleted. + const backups = fs.readdirSync(binDir).filter((name) => name.startsWith(`${binaryName()}.backup-`)); + expect(backups).toHaveLength(1); + expect(fs.readFileSync(path.join(binDir, backups[0], 'user-file.txt'), 'utf8')).toBe('user data'); + }); + + it('restores the original directory when publishing fails', () => { + fs.mkdirSync(binaryPath); + fs.writeFileSync(path.join(binaryPath, 'user-file.txt'), 'user data'); + + expect(() => internals.publishExtractedBinary(path.join(binDir, 'missing-binary'), binaryPath)).toThrow(); + + expect(fs.statSync(binaryPath).isDirectory()).toBe(true); + expect(fs.readFileSync(path.join(binaryPath, 'user-file.txt'), 'utf8')).toBe('user data'); + // No set-aside backup is left behind after the successful restore. + const backups = fs.readdirSync(binDir).filter((name) => name.startsWith(`${binaryName()}.backup-`)); + expect(backups).toHaveLength(0); + }); +}); diff --git a/tests/init-chain.test.ts b/tests/init-chain.test.ts index c405f7b..d8e7b63 100644 --- a/tests/init-chain.test.ts +++ b/tests/init-chain.test.ts @@ -16,7 +16,7 @@ jest.mock('../src/util/logger', () => ({ logger: { debug: jest.fn(), info: jest.fn(), warn: jest.fn(), error: jest.fn() }, })); -import { initChainIfNeeded, migrateLegacyDevnetRpcConfig } from '../src/node/init-chain'; +import { initChainIfNeeded, migrateLegacyDevnetRpcConfig, supportsTerminalRpcModule } from '../src/node/init-chain'; const LEGACY_CKB_TOML = `# legacy devnet config from before the ckb-tui fix # a custom comment that must survive migration @@ -206,3 +206,125 @@ describe('migrateLegacyDevnetRpcConfig', () => { expect(migrateLegacyDevnetRpcConfig(mockConfigPath)).toBe(false); }); }); + +describe('Terminal RPC module version gating', () => { + let root: string; + beforeEach(() => { + root = fs.mkdtempSync(path.join(os.tmpdir(), 'offckb-terminal-gate-')); + mockConfigPath = path.join(root, 'devnet'); + }); + afterEach(() => fs.rmSync(root, { recursive: true, force: true })); + + it('treats unknown or unparseable versions as Terminal-capable', () => { + expect(supportsTerminalRpcModule(null)).toBe(true); + expect(supportsTerminalRpcModule(undefined)).toBe(true); + expect(supportsTerminalRpcModule('not-a-version')).toBe(true); + expect(supportsTerminalRpcModule('0.205.0')).toBe(true); + expect(supportsTerminalRpcModule('0.207.0')).toBe(true); + expect(supportsTerminalRpcModule('0.120.0')).toBe(false); + expect(supportsTerminalRpcModule('0.204.9')).toBe(false); + expect(supportsTerminalRpcModule('0.205.0-rc1')).toBe(false); + }); + + it('strips Terminal from a freshly initialized template when the binary is too old', async () => { + await initChainIfNeeded({ ckbVersion: '0.120.0' }); + + const rpc = readCkbToml(mockConfigPath).rpc as JsonMap; + expect(rpc.modules).not.toContain('Terminal'); + expect(rpc.modules).toContain('Indexer'); + // tcp_listen_address predates 0.205.0 and stays enabled. + expect(rpc.tcp_listen_address).toBe('127.0.0.1:18114'); + expect(fs.existsSync(path.join(mockConfigPath, 'ckb-miner.toml'))).toBe(true); + }); + + it('keeps Terminal on fresh init for new or unknown versions', async () => { + await initChainIfNeeded({ ckbVersion: '0.207.0' }); + expect((readCkbToml(mockConfigPath).rpc as JsonMap).modules).toContain('Terminal'); + + const second = fs.mkdtempSync(path.join(os.tmpdir(), 'offckb-terminal-gate-')); + try { + mockConfigPath = path.join(second, 'devnet'); + await initChainIfNeeded(); + expect((readCkbToml(mockConfigPath).rpc as JsonMap).modules).toContain('Terminal'); + } finally { + fs.rmSync(second, { recursive: true, force: true }); + } + }); + + it('never strips a pre-existing ckb.toml, even when the binary is too old', async () => { + const withTerminal = LEGACY_CKB_TOML.replace( + 'modules = ["Net", "Pool", "Miner", "Chain", "Stats", "Subscription", "Experiment", "Debug", "Indexer"]', + 'modules = ["Net", "Chain", "Terminal"]', + ); + fs.mkdirSync(path.join(mockConfigPath, 'specs'), { recursive: true }); + fs.writeFileSync(path.join(mockConfigPath, 'ckb.toml'), withTerminal); + fs.writeFileSync(path.join(mockConfigPath, 'ckb-miner.toml'), 'custom-miner'); + fs.writeFileSync(path.join(mockConfigPath, 'specs', 'dev.toml'), 'custom-spec'); + + await initChainIfNeeded({ ckbVersion: '0.120.0' }); + + expect((readCkbToml(mockConfigPath).rpc as JsonMap).modules).toContain('Terminal'); + }); + + it('migration does not re-add Terminal for an old binary, but still enables tcp', () => { + fs.mkdirSync(mockConfigPath, { recursive: true }); + fs.writeFileSync(path.join(mockConfigPath, 'ckb.toml'), LEGACY_CKB_TOML); + + expect(migrateLegacyDevnetRpcConfig(mockConfigPath, '0.120.0')).toBe(true); + + const rpc = readCkbToml(mockConfigPath).rpc as JsonMap; + expect(rpc.modules).not.toContain('Terminal'); + expect(rpc.tcp_listen_address).toBe('127.0.0.1:18114'); + }); + + it('migration is a no-op for an old binary once tcp is set, breaking the remove/re-add loop', () => { + fs.mkdirSync(mockConfigPath, { recursive: true }); + const tcpOnly = LEGACY_CKB_TOML.replace( + '# tcp_listen_address = "127.0.0.1:18114"', + 'tcp_listen_address = "127.0.0.1:18114"', + ); + fs.writeFileSync(path.join(mockConfigPath, 'ckb.toml'), tcpOnly); + const before = fs.readFileSync(path.join(mockConfigPath, 'ckb.toml'), 'utf8'); + + expect(migrateLegacyDevnetRpcConfig(mockConfigPath, '0.120.0')).toBe(false); + expect(fs.readFileSync(path.join(mockConfigPath, 'ckb.toml'), 'utf8')).toBe(before); + }); + + it('migration still adds Terminal for new and unknown versions', () => { + fs.mkdirSync(mockConfigPath, { recursive: true }); + fs.writeFileSync(path.join(mockConfigPath, 'ckb.toml'), LEGACY_CKB_TOML); + expect(migrateLegacyDevnetRpcConfig(mockConfigPath, '0.207.0')).toBe(true); + expect((readCkbToml(mockConfigPath).rpc as JsonMap).modules).toContain('Terminal'); + + fs.writeFileSync(path.join(mockConfigPath, 'ckb.toml'), LEGACY_CKB_TOML); + expect(migrateLegacyDevnetRpcConfig(mockConfigPath, null)).toBe(true); + expect((readCkbToml(mockConfigPath).rpc as JsonMap).modules).toContain('Terminal'); + }); + + it('preserves a pre-existing hand-formatted multi-line config when the binary is too old', async () => { + // Fresh init strips Terminal from the single-line bundled template... + await initChainIfNeeded({ ckbVersion: '0.120.0' }); + const stripped = readCkbToml(mockConfigPath).rpc as JsonMap; + expect(stripped.modules).not.toContain('Terminal'); + + // ...but once ckb.toml exists — even reformatted by hand — re-init must + // not edit it; reporting Terminal+old-binary is node startup's job. + const second = fs.mkdtempSync(path.join(os.tmpdir(), 'offckb-terminal-gate-')); + try { + mockConfigPath = path.join(second, 'devnet'); + await initChainIfNeeded(); + const ckbTomlPath = path.join(mockConfigPath, 'ckb.toml'); + const singleLine = fs.readFileSync(ckbTomlPath, 'utf8'); + const multiline = singleLine.replace( + /modules = \[[^\]]*\]/, + 'modules = [\n "Net",\n "Chain",\n "Terminal",\n]', + ); + expect(multiline).not.toBe(singleLine); + fs.writeFileSync(ckbTomlPath, multiline); + await initChainIfNeeded({ ckbVersion: '0.120.0' }); + expect((readCkbToml(mockConfigPath).rpc as JsonMap).modules).toContain('Terminal'); + } finally { + fs.rmSync(second, { recursive: true, force: true }); + } + }); +}); diff --git a/tests/log-subscription.test.ts b/tests/log-subscription.test.ts new file mode 100644 index 0000000..9193e23 --- /dev/null +++ b/tests/log-subscription.test.ts @@ -0,0 +1,187 @@ +import * as net from 'net'; +import { EventEmitter } from 'events'; +import { parseTcpListenAddress, parseSubscriptionMessage, subscribeToNodeLogs } from '../src/devnet/log-subscription'; + +// connect is routed through a mock so retry behavior can be driven with a +// fake socket; by default it delegates to the real implementation. +const mockConnect = jest.fn(); +jest.mock('net', () => ({ + ...jest.requireActual('net'), + connect: (...args: unknown[]) => mockConnect(...args), +})); +const realConnect = (jest.requireActual('net') as typeof net).connect; + +class FakeSocket extends EventEmitter { + written: string[] = []; + destroyed = false; + write(data: string): boolean { + this.written.push(data); + return true; + } + destroy(): this { + this.destroyed = true; + return this; + } +} + +describe('parseTcpListenAddress', () => { + it('splits host and port', () => { + expect(parseTcpListenAddress('127.0.0.1:18114')).toEqual({ host: '127.0.0.1', port: 18114 }); + }); + + it('rejects invalid addresses', () => { + expect(parseTcpListenAddress('no-port')).toBeNull(); + expect(parseTcpListenAddress('127.0.0.1:notaport')).toBeNull(); + expect(parseTcpListenAddress('')).toBeNull(); + }); +}); + +describe('parseSubscriptionMessage', () => { + it('parses the subscribe response into a subscription id', () => { + expect(parseSubscriptionMessage('{"jsonrpc":"2.0","result":"0x49af29b770e3502239e4510ff58f8d59","id":1}')).toEqual({ + subscriptionId: '0x49af29b770e3502239e4510ff58f8d59', + }); + }); + + it('parses a log notification into an entry', () => { + const line = JSON.stringify({ + jsonrpc: '2.0', + method: 'subscribe', + params: { + result: { + message: 'script group: 0xabcd DEBUG OUTPUT: hello', + level: 'DEBUG', + target: 'ckb-script', + date: '2026-07-29 11:40:01.500 +00:00', + }, + subscription: '0x49af', + }, + }); + expect(parseSubscriptionMessage(line)).toEqual({ + entry: { + message: 'script group: 0xabcd DEBUG OUTPUT: hello', + level: 'DEBUG', + target: 'ckb-script', + date: '2026-07-29 11:40:01.500 +00:00', + }, + }); + }); + + it('returns null for garbage and unrelated messages', () => { + expect(parseSubscriptionMessage('not json')).toBeNull(); + expect(parseSubscriptionMessage('{"jsonrpc":"2.0","method":"other","params":{}}')).toBeNull(); + }); +}); + +describe('subscribeToNodeLogs', () => { + beforeEach(() => { + mockConnect.mockReset(); + mockConnect.mockImplementation((...args: unknown[]) => + (realConnect as (...a: unknown[]) => net.Socket)(...args), + ); + }); + + it('subscribes over TCP and emits log entries until closed', async () => { + const server = net.createServer((socket) => { + socket.on('data', (data) => { + const request = JSON.parse(data.toString().trim()); + expect(request.method).toBe('subscribe'); + expect(request.params).toEqual(['log']); + socket.write(JSON.stringify({ jsonrpc: '2.0', result: '0xsub', id: request.id }) + '\n'); + socket.write( + JSON.stringify({ + jsonrpc: '2.0', + method: 'subscribe', + params: { + result: { + message: 'hello', + level: 'DEBUG', + target: 'ckb-script', + date: '2026-07-29 11:40:01.500 +00:00', + }, + subscription: '0xsub', + }, + }) + '\n', + ); + }); + }); + await new Promise((resolve) => server.listen(0, '127.0.0.1', resolve)); + const port = (server.address() as net.AddressInfo).port; + + const entries: unknown[] = []; + const errors: Error[] = []; + const sub = subscribeToNodeLogs( + `127.0.0.1:${port}`, + (entry) => entries.push(entry), + (err) => errors.push(err), + ); + + await new Promise((resolve) => setTimeout(resolve, 500)); + sub.close(); + server.close(); + + expect(errors).toEqual([]); + expect(entries).toEqual([ + { message: 'hello', level: 'DEBUG', target: 'ckb-script', date: '2026-07-29 11:40:01.500 +00:00' }, + ]); + }); + + it('retries briefly then reports an error when the node is unreachable', async () => { + const errors: Error[] = []; + const sub = subscribeToNodeLogs( + '127.0.0.1:1', + () => {}, + (err) => errors.push(err), + { + maxAttempts: 2, + retryDelayMs: 50, + }, + ); + await new Promise((resolve) => setTimeout(resolve, 1000)); + sub.close(); + expect(errors).toHaveLength(1); + expect(errors[0].message).toMatch(/log subscription/i); + }); + + it('does not reconnect once an established subscription drops', async () => { + const socket = new FakeSocket(); + mockConnect.mockReturnValue(socket as unknown as net.Socket); + const errors: Error[] = []; + const sub = subscribeToNodeLogs('127.0.0.1:18114', () => {}, (err) => errors.push(err), { + maxAttempts: 3, + retryDelayMs: 30, + }); + + socket.emit('connect'); + expect(socket.written.join('')).toContain('"subscribe"'); + // A mid-run drop is terminal for the subscription (the supervisor tears + // the service down): no reconnect, no failure report. + socket.emit('error', new Error('read ECONNRESET')); + await new Promise((resolve) => setTimeout(resolve, 150)); + expect(mockConnect).toHaveBeenCalledTimes(1); + expect(errors).toEqual([]); + sub.close(); + }); + + it('close() cancels a reconnect pending from the initial connect phase', async () => { + const socket = new FakeSocket(); + mockConnect.mockReturnValue(socket as unknown as net.Socket); + const clearTimeoutSpy = jest.spyOn(global, 'clearTimeout'); + const sub = subscribeToNodeLogs('127.0.0.1:18114', () => {}, () => {}, { + maxAttempts: 5, + retryDelayMs: 50, + }); + + try { + // The first attempt fails before ever connecting, so a retry is pending. + socket.emit('error', new Error('connect ECONNREFUSED')); + sub.close(); + // The pending timer is cancelled, not left to no-op on the closed guard. + expect(clearTimeoutSpy).toHaveBeenCalled(); + await new Promise((resolve) => setTimeout(resolve, 200)); + expect(mockConnect).toHaveBeenCalledTimes(1); + } finally { + clearTimeoutSpy.mockRestore(); + } + }); +}); diff --git a/tests/logs-command.test.ts b/tests/logs-command.test.ts new file mode 100644 index 0000000..e1e308d --- /dev/null +++ b/tests/logs-command.test.ts @@ -0,0 +1,133 @@ +import * as fs from 'fs'; +import * as os from 'os'; +import * as path from 'path'; +import winston from 'winston'; +import { showLogs } from '../src/cmd/logs'; +import { defaultSettings, Settings } from '../src/cfg/setting'; +import { UnifiedLogger } from '../src/util/logger'; + +// Same watcher stub as logs.test.ts: followLogFile's polling cadence belongs +// to libuv, the tests drive change notifications directly. +const mockWatchFile = jest.fn(); +const mockUnwatchFile = jest.fn(); +jest.mock('fs', () => ({ + ...jest.requireActual('fs'), + watchFile: (...args: unknown[]) => mockWatchFile(...args), + unwatchFile: (...args: unknown[]) => mockUnwatchFile(...args), +})); + +const NODE_LINE = + '2026-07-29 11:31:27.149 +00:00 main INFO ckb_bin::subcommand::run ckb version: 0.207.0 (8f6cacf 2026-06-10)'; +const SCRIPT_LINE = + '2026-07-29 11:40:01.500 +00:00 GlobalRt-7 DEBUG ckb-script script group: 0xabcd DEBUG OUTPUT: hello world'; +const ERROR_LINE = + '2026-07-29 11:31:38.636 +00:00 verify_blocks ERROR ckb_chain::verify unverified_block_rx err: channel disconnected'; + +interface WinstonInfo { + [Symbol.for('message')]?: string; +} + +class CapturingTransport extends winston.transports.Console { + logs: string[] = []; + log(info: WinstonInfo, next: () => void) { + this.logs.push(info[Symbol.for('message')] ?? ''); + next(); + } +} + +const tempRoots: string[] = []; +afterEach(() => { + while (tempRoots.length) fs.rmSync(tempRoots.pop() as string, { recursive: true, force: true }); +}); + +function fixture(): { settings: Settings; transport: CapturingTransport } { + const root = fs.mkdtempSync(path.join(os.tmpdir(), 'offckb-logs-cmd-')); + tempRoots.push(root); + const settings = JSON.parse(JSON.stringify(defaultSettings)) as Settings; + settings.devnet.dataPath = path.join(root, 'devnet/data'); + settings.devnet.transactionsPath = path.join(root, 'devnet/transactions'); + const logDir = path.join(settings.devnet.dataPath, 'logs'); + fs.mkdirSync(logDir, { recursive: true }); + fs.writeFileSync(path.join(logDir, 'run.log'), [NODE_LINE, SCRIPT_LINE, ERROR_LINE].join('\n') + '\n'); + fs.writeFileSync(path.join(logDir, 'miner.log'), [ERROR_LINE].join('\n') + '\n'); + fs.writeFileSync(path.join(logDir, 'proxy.log'), 'send_transaction 0xdeadbeef\n'); + const transport = new CapturingTransport(); + return { settings, transport }; +} + +describe('showLogs', () => { + it('prints the node log tail by default', () => { + const { settings, transport } = fixture(); + const log = UnifiedLogger.create({ transports: [transport], showLevel: false }); + showLogs('node', { tail: 100 }, settings, log); + expect(transport.logs).toEqual([NODE_LINE, SCRIPT_LINE, ERROR_LINE]); + }); + + it('prints only ckb-script lines for the script target', () => { + const { settings, transport } = fixture(); + const log = UnifiedLogger.create({ transports: [transport], showLevel: false }); + showLogs('script', { tail: 100 }, settings, log); + expect(transport.logs).toEqual([SCRIPT_LINE]); + }); + + it('reads miner.log for the miner target', () => { + const { settings, transport } = fixture(); + const log = UnifiedLogger.create({ transports: [transport], showLevel: false }); + showLogs('miner', { tail: 100 }, settings, log); + expect(transport.logs).toEqual([ERROR_LINE]); + }); + + it('reads proxy.log for the rpc target', () => { + const { settings, transport } = fixture(); + const log = UnifiedLogger.create({ transports: [transport], showLevel: false }); + showLogs('rpc', { tail: 100 }, settings, log); + expect(transport.logs).toEqual(['send_transaction 0xdeadbeef']); + }); + + it('honors --tail and --grep', () => { + const { settings, transport } = fixture(); + const log = UnifiedLogger.create({ transports: [transport], showLevel: false }); + showLogs('node', { tail: 2, grep: 'ERROR' }, settings, log); + expect(transport.logs).toEqual([ERROR_LINE]); + }); + + it('throws a helpful error when the log file does not exist', () => { + const settings = JSON.parse(JSON.stringify(defaultSettings)) as Settings; + settings.devnet.dataPath = '/nonexistent'; + const log = UnifiedLogger.create({ transports: [new CapturingTransport()] }); + expect(() => showLogs('node', { tail: 100 }, settings, log)).toThrow(/log file not found/i); + }); + + it('in follow mode gates script entries and applies grep to streamed lines', () => { + const { settings, transport } = fixture(); + type StatListener = (curr: fs.Stats, prev: fs.Stats) => void; + const listeners: StatListener[] = []; + mockWatchFile.mockImplementation((_file: unknown, _options: unknown, onChange: StatListener) => { + listeners.push(onChange); + }); + + try { + const log = UnifiedLogger.create({ transports: [transport], showLevel: false }); + showLogs('script', { tail: 100, follow: true, grep: 'hello' }, settings, log); + expect(listeners).toHaveLength(1); + // The tail already printed the one script line (it contains 'hello'). + expect(transport.logs).toEqual([SCRIPT_LINE]); + transport.logs.length = 0; + + const runLog = path.join(settings.devnet.dataPath, 'logs', 'run.log'); + const scriptNoGrep = SCRIPT_LINE.replace('hello world', 'goodbye'); + const scriptWithGrep = SCRIPT_LINE.replace('hello world', 'hello again'); + fs.appendFileSync(runLog, [ERROR_LINE, scriptNoGrep, scriptWithGrep, ' hello continuation'].join('\n') + '\n'); + const stat = fs.statSync(runLog); + listeners[0](stat, stat); + + // ERROR_LINE is not a script entry; scriptNoGrep is filtered by grep; + // the continuation line belongs to the script entry above it and + // matches grep, so both it and scriptWithGrep are shown. + expect(transport.logs).toEqual([scriptWithGrep, ' hello continuation']); + } finally { + mockWatchFile.mockReset(); + mockUnwatchFile.mockReset(); + } + }); +}); diff --git a/tests/logs.test.ts b/tests/logs.test.ts new file mode 100644 index 0000000..ccf90a0 --- /dev/null +++ b/tests/logs.test.ts @@ -0,0 +1,241 @@ +import * as fs from 'fs'; +import * as os from 'os'; +import * as path from 'path'; +import { + parseCkbLogLine, + filterLinesByTarget, + tailLines, + grepLines, + resolveLogPath, + readLogTail, + followLogFile, + LogTarget, +} from '../src/devnet/log-file'; +import { defaultSettings, Settings } from '../src/cfg/setting'; + +// fs.watchFile is a non-configurable property on the fs module, so spyOn +// cannot stub it; route it through a mock factory instead. Everything else +// keeps the real implementation. +const mockWatchFile = jest.fn(); +const mockUnwatchFile = jest.fn(); +jest.mock('fs', () => ({ + ...jest.requireActual('fs'), + watchFile: (...args: unknown[]) => mockWatchFile(...args), + unwatchFile: (...args: unknown[]) => mockUnwatchFile(...args), +})); + +const NODE_LINE = + '2026-07-29 11:31:27.149 +00:00 main INFO ckb_bin::subcommand::run ckb version: 0.207.0 (8f6cacf 2026-06-10)'; +const SCRIPT_LINE = + '2026-07-29 11:40:01.500 +00:00 GlobalRt-7 DEBUG ckb-script script group: 0xabcd DEBUG OUTPUT: hello world'; +const ERROR_LINE = + '2026-07-29 11:31:38.636 +00:00 verify_blocks ERROR ckb_chain::verify unverified_block_rx err: receiving on an empty and disconnected channel'; + +function devnetSettings(root: string): Settings { + const settings = JSON.parse(JSON.stringify(defaultSettings)) as Settings; + settings.devnet.dataPath = path.join(root, 'devnet/data'); + settings.devnet.transactionsPath = path.join(root, 'devnet/transactions'); + return settings; +} + +describe('parseCkbLogLine', () => { + it('parses a standard CKB log line into fields', () => { + expect(parseCkbLogLine(NODE_LINE)).toEqual({ + timestamp: '2026-07-29 11:31:27.149 +00:00', + thread: 'main', + level: 'INFO', + target: 'ckb_bin::subcommand::run', + message: 'ckb version: 0.207.0 (8f6cacf 2026-06-10)', + }); + }); + + it('parses a ckb-script debug line', () => { + const parsed = parseCkbLogLine(SCRIPT_LINE); + expect(parsed?.level).toBe('DEBUG'); + expect(parsed?.target).toBe('ckb-script'); + expect(parsed?.message).toBe('script group: 0xabcd DEBUG OUTPUT: hello world'); + }); + + it('parses lines whose level is not padded', () => { + expect(parseCkbLogLine(ERROR_LINE)?.level).toBe('ERROR'); + expect(parseCkbLogLine(ERROR_LINE)?.target).toBe('ckb_chain::verify'); + }); + + it('returns null for continuation lines and garbage', () => { + expect(parseCkbLogLine(' at ckb_chain::verify (src/verify.rs:42)')).toBeNull(); + expect(parseCkbLogLine('')).toBeNull(); + expect(parseCkbLogLine('some random output')).toBeNull(); + }); +}); + +describe('filterLinesByTarget', () => { + it('keeps only lines from the given target plus their continuation lines', () => { + const lines = [ + NODE_LINE, + SCRIPT_LINE, + ' continuation of the script message', + ERROR_LINE, + SCRIPT_LINE.replace('hello world', 'second'), + ]; + expect(filterLinesByTarget(lines, 'ckb-script')).toEqual([ + SCRIPT_LINE, + ' continuation of the script message', + SCRIPT_LINE.replace('hello world', 'second'), + ]); + }); + + it('drops leading unparsable lines when nothing matched before them', () => { + expect(filterLinesByTarget(['garbage line', SCRIPT_LINE], 'ckb-script')).toEqual([SCRIPT_LINE]); + }); +}); + +describe('tailLines', () => { + it('returns the last N lines', () => { + expect(tailLines('a\nb\nc\nd\n', 2)).toEqual(['c', 'd']); + }); + + it('returns all lines when fewer than N exist', () => { + expect(tailLines('a\nb\n', 10)).toEqual(['a', 'b']); + }); + + it('returns an empty array for empty content', () => { + expect(tailLines('', 5)).toEqual([]); + }); +}); + +describe('grepLines', () => { + it('keeps lines containing the substring', () => { + expect(grepLines([NODE_LINE, SCRIPT_LINE], 'DEBUG OUTPUT')).toEqual([SCRIPT_LINE]); + }); +}); + +describe('resolveLogPath', () => { + const settings = devnetSettings('/data'); + const logsDir = path.join(settings.devnet.dataPath, 'logs'); + const cases: Array<[LogTarget, string]> = [ + ['node', path.join(logsDir, 'run.log')], + ['script', path.join(logsDir, 'run.log')], + ['miner', path.join(logsDir, 'miner.log')], + // proxy.log resolves via transactionsPath and is made absolute. + ['rpc', path.resolve(settings.devnet.transactionsPath, '..', 'data', 'logs', 'proxy.log')], + ]; + it.each(cases)('resolves %s logs to %s', (target, expected) => { + expect(resolveLogPath(target, settings)).toBe(expected); + }); +}); + +describe('readLogTail (file reading)', () => { + it('reads the last N lines of a log file', () => { + const dir = fs.mkdtempSync(path.join(os.tmpdir(), 'offckb-logs-')); + const file = path.join(dir, 'run.log'); + fs.writeFileSync(file, [NODE_LINE, SCRIPT_LINE, ERROR_LINE].join('\n') + '\n'); + expect(readLogTail(file, 2)).toEqual([SCRIPT_LINE, ERROR_LINE]); + fs.rmSync(dir, { recursive: true, force: true }); + }); + + it('throws a helpful error when the file is missing', () => { + expect(() => readLogTail('/nonexistent/run.log', 10)).toThrow(/log file not found/i); + }); +}); + +describe('followLogFile', () => { + // Stub the watcher plumbing: libuv's stat-polling cadence is Node's + // business (and proved flaky on CI runners), what we test is the offset + // tracking and line splitting once a change notification arrives. + type StatListener = (curr: fs.Stats, prev: fs.Stats) => void; + function captureWatchListener(): StatListener[] { + const listeners: StatListener[] = []; + mockWatchFile.mockImplementation((_file: unknown, _options: unknown, onChange: StatListener) => { + listeners.push(onChange); + }); + return listeners; + } + + function tempLog(): { dir: string; file: string } { + const dir = fs.mkdtempSync(path.join(os.tmpdir(), 'offckb-logs-')); + const file = path.join(dir, 'run.log'); + fs.writeFileSync(file, `${NODE_LINE}\n`); + return { dir, file }; + } + + it('emits appended lines until stopped', () => { + const { dir, file } = tempLog(); + const listeners = captureWatchListener(); + + try { + const seen: string[] = []; + const stop = followLogFile(file, (line) => seen.push(line)); + expect(listeners).toHaveLength(1); + + fs.appendFileSync(file, `${SCRIPT_LINE}\n`); + const stat = fs.statSync(file); + listeners[0](stat, stat); + stop(); + + expect(seen).toEqual([SCRIPT_LINE]); + expect(mockUnwatchFile).toHaveBeenCalled(); + } finally { + mockWatchFile.mockReset(); + mockUnwatchFile.mockReset(); + fs.rmSync(dir, { recursive: true, force: true }); + } + }); + + it('re-reads from the beginning when the file is truncated or rotated', () => { + const { dir, file } = tempLog(); + const listeners = captureWatchListener(); + + try { + const seen: string[] = []; + const stop = followLogFile(file, (line) => seen.push(line)); + + fs.appendFileSync(file, `${SCRIPT_LINE}\n`); + const grown = fs.statSync(file); + listeners[0](grown, grown); + expect(seen).toEqual([SCRIPT_LINE]); + + // Rotation replaces the file with a shorter one; the next notification + // must reset the offset instead of seeking past the end. + fs.writeFileSync(file, `${ERROR_LINE}\n`); + listeners[0](fs.statSync(file), grown); + expect(seen).toEqual([SCRIPT_LINE, ERROR_LINE]); + stop(); + } finally { + mockWatchFile.mockReset(); + mockUnwatchFile.mockReset(); + fs.rmSync(dir, { recursive: true, force: true }); + } + }); + + it('reassembles multi-byte UTF-8 characters split across reads', () => { + const { dir, file } = tempLog(); + const listeners = captureWatchListener(); + + try { + const seen: string[] = []; + const stop = followLogFile(file, (line) => seen.push(line)); + + const line = `${SCRIPT_LINE} 调用 🦀`; + const bytes = Buffer.from(`${line}\n`, 'utf8'); + // 🦀 is 4 bytes (f0 9f a6 80); the first chunk ends right after its + // leading byte, so the character straddles two reads. + const cut = bytes.length - 4; + fs.appendFileSync(file, bytes.subarray(0, cut)); + let stat = fs.statSync(file); + listeners[0](stat, stat); + // No newline has arrived yet: nothing is emitted. + expect(seen).toEqual([]); + + fs.appendFileSync(file, bytes.subarray(cut)); + stat = fs.statSync(file); + listeners[0](stat, stat); + // The character arrives intact, not as replacement characters. + expect(seen).toEqual([line]); + stop(); + } finally { + mockWatchFile.mockReset(); + mockUnwatchFile.mockReset(); + fs.rmSync(dir, { recursive: true, force: true }); + } + }); +}); diff --git a/tests/node-quiet-mode.test.ts b/tests/node-quiet-mode.test.ts new file mode 100644 index 0000000..a0bfb5a --- /dev/null +++ b/tests/node-quiet-mode.test.ts @@ -0,0 +1,151 @@ +import { EventEmitter } from 'events'; + +const mockSpawn = jest.fn(); +const mockProxyStart = jest.fn(); +const mockProxyStop = jest.fn(); +const mockSubscribe = jest.fn(); +const mockTcpListenAddress = jest.fn(); +const loggerInfo = jest.fn(); +const loggerWarn = jest.fn(); + +jest.mock('child_process', () => ({ + ...jest.requireActual('child_process'), + spawn: (...args: unknown[]) => mockSpawn(...args), +})); +jest.mock('../src/node/install', () => ({ installCKBBinary: jest.fn().mockResolvedValue(undefined) })); +jest.mock('../src/node/init-chain', () => ({ + initChainIfNeeded: jest.fn().mockResolvedValue(undefined), + supportsTerminalRpcModule: () => true, + devnetConfigHasTerminalRpc: () => false, +})); +jest.mock('../src/cfg/setting', () => ({ + readSettings: () => ({ + bins: { defaultCKBVersion: '0.207.0' }, + devnet: { + configPath: '/tmp/offckb-devnet', + dataPath: '/tmp/offckb-devnet/data', + rpcUrl: 'http://127.0.0.1:8114', + rpcProxyPort: 28114, + transactionsPath: '/tmp/offckb-devnet/transactions', + }, + }), + getCKBBinaryPath: () => '/tmp/ckb', +})); +jest.mock('../src/devnet/fork', () => ({ readForkState: () => null })); +jest.mock('../src/devnet/readiness', () => ({ + checkNodeReadiness: jest.fn(), + waitForNodeReady: jest.fn().mockResolvedValue({ ready: true, rpcUrl: 'http://127.0.0.1:8114' }), +})); +jest.mock('../src/tools/rpc-proxy', () => ({ + createRPCProxy: () => ({ start: mockProxyStart, stop: mockProxyStop }), +})); +jest.mock('../src/devnet/log-subscription', () => ({ + devnetTcpListenAddress: (...args: unknown[]) => mockTcpListenAddress(...args), + subscribeToNodeLogs: (...args: unknown[]) => mockSubscribe(...args), +})); +jest.mock('../src/util/logger', () => ({ + logger: { + success: jest.fn(), + info: (...args: unknown[]) => loggerInfo(...args), + warn: (...args: unknown[]) => loggerWarn(...args), + debug: jest.fn(), + error: jest.fn(), + result: jest.fn(), + }, +})); + +import { nodeDevnet } from '../src/cmd/node'; +import { CkbLogEntry } from '../src/devnet/log-subscription'; + +class FakeChild extends EventEmitter { + stdout = new EventEmitter(); + stderr = new EventEmitter(); + killed = false; + pid = 1234; + kill = jest.fn((_signal?: NodeJS.Signals) => { + this.killed = true; + return true; + }); +} + +describe('foreground node output modes', () => { + let ckb: FakeChild; + let miner: FakeChild; + + beforeEach(() => { + jest.clearAllMocks(); + mockTcpListenAddress.mockReturnValue('127.0.0.1:18114'); + mockSubscribe.mockReturnValue({ close: jest.fn() }); + ckb = new FakeChild(); + miner = new FakeChild(); + mockSpawn.mockReturnValueOnce(ckb).mockImplementationOnce(() => { + process.nextTick(() => miner.emit('spawn')); + return miner; + }); + }); + + it('does not print node/miner output by default', async () => { + await nodeDevnet({}); + loggerInfo.mockClear(); + ckb.stdout.emit('data', 'noisy node line'); + miner.stdout.emit('data', 'noisy miner line'); + const printed = loggerInfo.mock.calls.map((args) => args.map(String).join(' ')).join('\n'); + expect(printed).not.toContain('noisy node line'); + expect(printed).not.toContain('noisy miner line'); + }); + + it('relays node/miner output when --verbose is set', async () => { + await nodeDevnet({ verbose: true }); + loggerInfo.mockClear(); + ckb.stdout.emit('data', 'noisy node line'); + miner.stdout.emit('data', 'noisy miner line'); + const printed = loggerInfo.mock.calls.map((args) => args.map(String).join(' ')).join('\n'); + expect(printed).toContain('noisy node line'); + expect(printed).toContain('noisy miner line'); + }); + + it('streams ckb-script log entries to the console and hides the rest', async () => { + await nodeDevnet({}); + expect(mockSubscribe).toHaveBeenCalledWith('127.0.0.1:18114', expect.any(Function), expect.any(Function)); + const onEntry = mockSubscribe.mock.calls[0][1] as (entry: CkbLogEntry) => void; + + onEntry({ message: 'script group: 0xabcd DEBUG OUTPUT: hello', level: 'DEBUG', target: 'ckb-script', date: '' }); + onEntry({ message: 'block 123', level: 'INFO', target: 'ckb_chain::chain', date: '' }); + + const printed = loggerInfo.mock.calls.map((args) => args.map(String).join(' ')).join('\n'); + expect(printed).toContain('script group: 0xabcd DEBUG OUTPUT: hello'); + expect(printed).not.toContain('block 123'); + }); + + it('strips terminal control sequences from script log entries', async () => { + await nodeDevnet({}); + const onEntry = mockSubscribe.mock.calls[0][1] as (entry: CkbLogEntry) => void; + + const esc = String.fromCharCode(27); + const bel = String.fromCharCode(7); + onEntry({ + message: `${esc}[31mred${esc}[0m ${bel}bell\r`, + level: 'DEBUG', + target: 'ckb-script', + date: '', + }); + + const printed = loggerInfo.mock.calls.map((args) => args.map(String).join(' ')).join('\n'); + expect(printed).toContain('red bell'); + expect(printed).not.toContain(esc); + expect(printed).not.toContain(bel); + expect(printed).not.toContain('\r'); + }); + + it('skips the subscription when the node has no TCP listen address', async () => { + mockTcpListenAddress.mockReturnValue(undefined); + await nodeDevnet({}); + expect(mockSubscribe).not.toHaveBeenCalled(); + }); + + it('points the user at offckb logs once the node is ready', async () => { + await nodeDevnet({}); + const printed = loggerInfo.mock.calls.map((args) => args.map(String).join(' ')).join('\n'); + expect(printed).toMatch(/offckb logs -f/); + }); +}); diff --git a/tests/node-supervisor.test.ts b/tests/node-supervisor.test.ts index f6b8f10..16344b0 100644 --- a/tests/node-supervisor.test.ts +++ b/tests/node-supervisor.test.ts @@ -12,7 +12,10 @@ jest.mock('child_process', () => ({ spawn: (...args: unknown[]) => mockSpawn(...args), })); jest.mock('../src/node/install', () => ({ installCKBBinary: jest.fn().mockResolvedValue(undefined) })); -jest.mock('../src/node/init-chain', () => ({ initChainIfNeeded: jest.fn().mockResolvedValue(undefined) })); +jest.mock('../src/node/init-chain', () => ({ + ...jest.requireActual('../src/node/init-chain'), + initChainIfNeeded: jest.fn().mockResolvedValue(undefined), +})); jest.mock('../src/cfg/setting', () => ({ readSettings: () => ({ bins: { defaultCKBVersion: '0.207.0' }, @@ -42,6 +45,7 @@ jest.mock('../src/util/logger', () => ({ success: jest.fn(), info: jest.fn(), warn: jest.fn(), + debug: jest.fn(), error: jest.fn(), result: jest.fn(), }, @@ -123,7 +127,9 @@ describe('foreground devnet supervisor', () => { await nodeDevnet({}); expect(mockMarkForkFirstRunComplete).toHaveBeenCalledWith('/tmp/offckb-devnet', '100'); - expect(mockMarkForkFirstRunComplete.mock.invocationCallOrder[0]).toBeLessThan(mockSpawn.mock.invocationCallOrder[1]); + expect(mockMarkForkFirstRunComplete.mock.invocationCallOrder[0]).toBeLessThan( + mockSpawn.mock.invocationCallOrder[1], + ); expect(mockProxyStart).toHaveBeenCalled(); }); }); diff --git a/tests/node-terminal-rpc.test.ts b/tests/node-terminal-rpc.test.ts new file mode 100644 index 0000000..1ee5b0f --- /dev/null +++ b/tests/node-terminal-rpc.test.ts @@ -0,0 +1,208 @@ +import { EventEmitter } from 'events'; +import { startNode } from '../src/cmd/node'; +import { Network } from '../src/type/base'; + +const mockSpawn = jest.fn(); +const mockGetVersionFromBinary = jest.fn(); +const mockInstallCKBBinary = jest.fn(); +const mockInitChainIfNeeded = jest.fn(); +const mockDevnetConfigHasTerminalRpc = jest.fn(); +const mockWaitForNodeReady = jest.fn(); + +jest.mock('child_process', () => ({ + ...jest.requireActual('child_process'), + spawn: (...args: unknown[]) => mockSpawn(...args), +})); + +jest.mock('../src/node/install', () => ({ + installCKBBinary: (...args: unknown[]) => mockInstallCKBBinary(...args), + getVersionFromBinary: (...args: unknown[]) => mockGetVersionFromBinary(...args), +})); + +jest.mock('../src/node/init-chain', () => ({ + ...jest.requireActual('../src/node/init-chain'), + initChainIfNeeded: (...args: unknown[]) => mockInitChainIfNeeded(...args), + devnetConfigHasTerminalRpc: (...args: unknown[]) => mockDevnetConfigHasTerminalRpc(...args), +})); + +jest.mock('../src/tools/rpc-proxy', () => ({ + createRPCProxy: jest.fn(() => ({ + start: jest.fn(), + stop: jest.fn(), + })), +})); + +jest.mock('../src/devnet/readiness', () => ({ + checkNodeReadiness: jest.fn().mockResolvedValue({ ready: false, rpcUrl: 'http://127.0.0.1:8114' }), + waitForNodeReady: (...args: unknown[]) => mockWaitForNodeReady(...args), +})); + +jest.mock('../src/devnet/fork', () => ({ + readForkState: jest.fn(() => null), + markForkFirstRunComplete: jest.fn(), +})); + +jest.mock('../src/cfg/setting', () => ({ + readSettings: () => ({ + bins: { defaultCKBVersion: '0.207.0' }, + devnet: { + configPath: '/tmp/offckb-devnet-config', + dataPath: '/tmp/offckb-devnet-data', + rpcUrl: 'http://127.0.0.1:8114', + rpcProxyPort: 28114, + }, + }), + getCKBBinaryPath: (version: string) => `/managed/ckb/${version}/ckb`, +})); + +jest.mock('../src/util/logger', () => ({ + logger: { + success: jest.fn(), + info: jest.fn(), + warn: jest.fn(), + error: jest.fn(), + debug: jest.fn(), + result: jest.fn(), + setJsonMode: jest.fn(), + }, +})); + +import { logger } from '../src/util/logger'; + +// A minimal stand-in for a spawned ChildProcess: event emitter plus piped +// stdio emitters. `once('spawn')` fires on the next tick so waitForChildSpawn +// resolves without the test orchestrating timing. +function makeFakeChild(pid: number) { + const child = new EventEmitter() as EventEmitter & { + stdout: EventEmitter; + stderr: EventEmitter; + pid: number; + killed: boolean; + kill: jest.Mock; + }; + child.stdout = new EventEmitter(); + child.stderr = new EventEmitter(); + child.pid = pid; + child.killed = false; + child.kill = jest.fn(() => { + child.killed = true; + return true; + }); + const originalOnce = child.once.bind(child); + child.once = ((event: string | symbol, listener: (...args: unknown[]) => void) => { + if (event === 'spawn') process.nextTick(listener); + return originalOnce(event, listener); + }) as typeof child.once; + return child; +} + +describe('node devnet Terminal RPC version handling', () => { + let ckbChild: ReturnType; + let minerChild: ReturnType; + + beforeEach(() => { + jest.clearAllMocks(); + ckbChild = makeFakeChild(1111); + minerChild = makeFakeChild(2222); + mockSpawn.mockReset(); + mockSpawn.mockReturnValueOnce(ckbChild).mockReturnValueOnce(minerChild); + mockWaitForNodeReady.mockResolvedValue({ ready: true, rpcUrl: 'http://127.0.0.1:8114', nodeTip: 0n }); + mockInstallCKBBinary.mockResolvedValue(undefined); + mockInitChainIfNeeded.mockResolvedValue(undefined); + mockDevnetConfigHasTerminalRpc.mockReturnValue(false); + mockGetVersionFromBinary.mockReturnValue(null); + }); + + it('passes the managed version to chain init and starts normally', async () => { + await startNode({ network: Network.devnet, version: '0.120.0' }); + + expect(mockInstallCKBBinary).toHaveBeenCalledWith('0.120.0'); + expect(mockInitChainIfNeeded).toHaveBeenCalledWith({ ckbVersion: '0.120.0' }); + expect(mockSpawn).toHaveBeenCalledTimes(2); + expect(logger.info).toHaveBeenCalledWith(expect.stringContaining('predates the Terminal RPC module')); + }); + + it('uses the settings default version when none is given', async () => { + await startNode({ network: Network.devnet }); + + expect(mockInstallCKBBinary).toHaveBeenCalledWith('0.207.0'); + expect(mockInitChainIfNeeded).toHaveBeenCalledWith({ ckbVersion: '0.207.0' }); + }); + + it('probes a custom --binary-path version and forwards it to chain init', async () => { + mockGetVersionFromBinary.mockReturnValue('0.120.0'); + + await startNode({ network: Network.devnet, binaryPath: '/custom/ckb' }); + + expect(mockGetVersionFromBinary).toHaveBeenCalledWith('/custom/ckb'); + expect(mockInstallCKBBinary).not.toHaveBeenCalled(); + expect(mockInitChainIfNeeded).toHaveBeenCalledWith({ ckbVersion: '0.120.0' }); + }); + + it('fails fast with an actionable error when the config has Terminal but the managed binary is too old', async () => { + mockDevnetConfigHasTerminalRpc.mockReturnValue(true); + + await expect(startNode({ network: Network.devnet, version: '0.120.0' })).rejects.toThrow( + /requires CKB >= 0\.205\.0; the selected binary is 0\.120\.0/, + ); + + expect(mockSpawn).not.toHaveBeenCalled(); + }); + + it('fails fast when a probed custom binary is too old for the config', async () => { + mockGetVersionFromBinary.mockReturnValue('0.200.0'); + mockDevnetConfigHasTerminalRpc.mockReturnValue(true); + + await expect(startNode({ network: Network.devnet, binaryPath: '/custom/ckb' })).rejects.toThrow( + /remove "Terminal" from rpc\.modules/, + ); + + expect(mockSpawn).not.toHaveBeenCalled(); + }); + + it('does not fail fast for an unprobeable custom binary (unknown version assumes support)', async () => { + mockGetVersionFromBinary.mockReturnValue(null); + mockDevnetConfigHasTerminalRpc.mockReturnValue(true); + + await startNode({ network: Network.devnet, binaryPath: '/custom/ckb' }); + + expect(mockInitChainIfNeeded).toHaveBeenCalledWith({ ckbVersion: null }); + expect(mockSpawn).toHaveBeenCalledTimes(2); + }); + + it('allows a new-enough binary with a Terminal-enabled config', async () => { + mockDevnetConfigHasTerminalRpc.mockReturnValue(true); + + await startNode({ network: Network.devnet, version: '0.207.0' }); + + expect(mockSpawn).toHaveBeenCalledTimes(2); + expect(logger.info).not.toHaveBeenCalledWith(expect.stringContaining('predates the Terminal RPC module')); + }); + + it('translates an "unknown variant `Terminal`" startup crash into an actionable error', async () => { + mockWaitForNodeReady.mockImplementation(async () => { + ckbChild.stderr.emit( + 'data', + Buffer.from( + 'Error: TOML parse error: unknown variant `Terminal`, expected one of `Net`, `Pool`, `Miner`, `Chain`', + ), + ); + return { ready: false, error: 'CKB process exited' }; + }); + + await expect(startNode({ network: Network.devnet, binaryPath: '/custom/ckb' })).rejects.toThrow( + /The "Terminal" RPC module requires CKB >= 0\.205\.0; remove "Terminal" from rpc\.modules/, + ); + }); + + it('reports a plain startup failure when the stderr tail has no Terminal signature', async () => { + mockWaitForNodeReady.mockImplementation(async () => { + ckbChild.stderr.emit('data', Buffer.from('some unrelated panic')); + return { ready: false, error: 'CKB process exited' }; + }); + + await expect(startNode({ network: Network.devnet, binaryPath: '/custom/ckb' })).rejects.toThrow( + /^CKB devnet failed to become ready: CKB process exited Check the node log with `offckb logs`/, + ); + }); +}); diff --git a/tests/proxy-events.test.ts b/tests/proxy-events.test.ts new file mode 100644 index 0000000..e5e9f6a --- /dev/null +++ b/tests/proxy-events.test.ts @@ -0,0 +1,164 @@ +import * as fs from 'fs'; +import * as os from 'os'; +import * as path from 'path'; +import { createProxyEventLog, handleProxyRequestBody, handleProxyResponseBody } from '../src/tools/proxy-events'; + +function makeSink() { + const sink = { debug: jest.fn(), info: jest.fn(), warn: jest.fn(), error: jest.fn() }; + return sink; +} + +function makeCtx(transactionsPath: string) { + return { + sink: makeSink(), + events: createProxyEventLog(path.join(path.dirname(transactionsPath), 'data', 'logs', 'proxy.log')), + transactionsPath, + hashTransaction: jest.fn(() => '0xhash'), + }; +} + +describe('handleProxyRequestBody', () => { + let dir: string; + let transactionsPath: string; + beforeEach(() => { + dir = fs.mkdtempSync(path.join(os.tmpdir(), 'offckb-proxy-')); + transactionsPath = path.join(dir, 'transactions'); + }); + afterEach(() => fs.rmSync(dir, { recursive: true, force: true })); + + it('logs ordinary requests at debug level, not info', () => { + const ctx = makeCtx(transactionsPath); + handleProxyRequestBody(JSON.stringify({ jsonrpc: '2.0', id: 1, method: 'get_tip_header', params: [] }), ctx); + expect(ctx.sink.debug).toHaveBeenCalledWith('RPC Req: ', 'get_tip_header'); + expect(ctx.sink.info).not.toHaveBeenCalled(); + }); + + it('records every request in the proxy event log', () => { + const ctx = makeCtx(transactionsPath); + handleProxyRequestBody(JSON.stringify({ jsonrpc: '2.0', id: 1, method: 'get_tip_header', params: [] }), ctx); + const content = fs.readFileSync(ctx.events.filePath, 'utf8'); + expect(content).toMatch(/request get_tip_header/); + }); + + it('keeps send_transaction hash visible at info and stores the tx file', () => { + const ctx = makeCtx(transactionsPath); + const tx = { cell_deps: [], inputs: [], outputs: [] }; + handleProxyRequestBody(JSON.stringify({ jsonrpc: '2.0', id: 1, method: 'send_transaction', params: [tx] }), ctx); + expect(ctx.sink.info).toHaveBeenCalledWith(expect.stringContaining('0xhash')); + expect(fs.existsSync(path.join(transactionsPath, '0xhash.json'))).toBe(true); + const content = fs.readFileSync(ctx.events.filePath, 'utf8'); + expect(content).toMatch(/send_transaction 0xhash/); + }); + + it('reports malformed JSON-RPC bodies at error level', () => { + const ctx = makeCtx(transactionsPath); + handleProxyRequestBody('not json', ctx); + expect(ctx.sink.error).toHaveBeenCalled(); + }); + + it('ignores empty bodies', () => { + const ctx = makeCtx(transactionsPath); + handleProxyRequestBody('', ctx); + expect(ctx.sink.debug).not.toHaveBeenCalled(); + expect(ctx.sink.error).not.toHaveBeenCalled(); + }); +}); + +describe('handleProxyResponseBody', () => { + let dir: string; + let transactionsPath: string; + beforeEach(() => { + dir = fs.mkdtempSync(path.join(os.tmpdir(), 'offckb-proxy-')); + transactionsPath = path.join(dir, 'transactions'); + }); + afterEach(() => fs.rmSync(dir, { recursive: true, force: true })); + + it('warns on JSON-RPC errors and records them', () => { + const ctx = makeCtx(transactionsPath); + handleProxyResponseBody( + JSON.stringify({ jsonrpc: '2.0', id: 1, error: { code: -302, message: 'TransactionFailedToVerify' } }), + 'application/json', + ctx, + ); + expect(ctx.sink.warn).toHaveBeenCalledWith(expect.stringContaining('TransactionFailedToVerify')); + const content = fs.readFileSync(ctx.events.filePath, 'utf8'); + expect(content).toMatch(/error .*TransactionFailedToVerify/); + }); + + it('accepts a JSON content type with charset parameters', () => { + const ctx = makeCtx(transactionsPath); + handleProxyResponseBody( + JSON.stringify({ jsonrpc: '2.0', id: 1, error: { code: -302, message: 'TransactionFailedToVerify' } }), + 'application/json; charset=utf-8', + ctx, + ); + expect(ctx.sink.warn).toHaveBeenCalledWith(expect.stringContaining('TransactionFailedToVerify')); + const content = fs.readFileSync(ctx.events.filePath, 'utf8'); + expect(content).toMatch(/error .*TransactionFailedToVerify/); + }); + + it('stays quiet on successful responses', () => { + const ctx = makeCtx(transactionsPath); + handleProxyResponseBody(JSON.stringify({ jsonrpc: '2.0', id: 1, result: '0x0' }), 'application/json', ctx); + expect(ctx.sink.warn).not.toHaveBeenCalled(); + }); + + it('warns for each error entry in a batch response', () => { + const ctx = makeCtx(transactionsPath); + handleProxyResponseBody( + JSON.stringify([ + { jsonrpc: '2.0', id: 1, result: '0x0' }, + { jsonrpc: '2.0', id: 2, error: { code: -1, message: 'boom' } }, + ]), + 'application/json', + ctx, + ); + expect(ctx.sink.warn).toHaveBeenCalledTimes(1); + expect(ctx.sink.warn).toHaveBeenCalledWith(expect.stringContaining('boom')); + }); + + it('ignores non-JSON responses', () => { + const ctx = makeCtx(transactionsPath); + handleProxyResponseBody('not json', 'text/html', ctx); + expect(ctx.sink.warn).not.toHaveBeenCalled(); + expect(ctx.sink.error).not.toHaveBeenCalled(); + }); +}); + +describe('createProxyEventLog', () => { + let dir: string; + beforeEach(() => { + dir = fs.mkdtempSync(path.join(os.tmpdir(), 'offckb-proxy-log-')); + }); + afterEach(() => fs.rmSync(dir, { recursive: true, force: true })); + + it('writes one line per event even when fields contain newlines or control characters', () => { + const file = path.join(dir, 'logs', 'proxy.log'); + const log = createProxyEventLog(file); + const esc = String.fromCharCode(27); + log.event(['request get_tip', 'forged'].join('\n') + '\r' + esc + '[31m'); + const lines = fs.readFileSync(file, 'utf8').trimEnd().split('\n'); + expect(lines).toHaveLength(1); + expect(lines[0]).toContain('request get_tip forged'); + expect(lines[0]).not.toContain(esc); + expect(lines[0]).not.toContain('\r'); + }); + + it('rolls over to a single .1 file once the size cap is exceeded', () => { + const file = path.join(dir, 'logs', 'proxy.log'); + const log = createProxyEventLog(file, 60); + log.event('request get_tip_header'); + log.event('request get_blockchain_info'); + log.event('request get_tip_header'); + + expect(fs.existsSync(`${file}.1`)).toBe(true); + // Single rollover: the .1 holds only the previous generation, the live + // file only what came after the last rollover. + const rolled = fs.readFileSync(`${file}.1`, 'utf8'); + expect(rolled).toMatch(/get_blockchain_info/); + expect(rolled).not.toMatch(/get_tip_header/); + const current = fs.readFileSync(file, 'utf8'); + expect(current).toMatch(/get_tip_header/); + expect(current).not.toMatch(/get_blockchain_info/); + }); +});