ceos/opencode
1
0
Fork 0
Code Issues Pull requests Projects Releases Packages Wiki Activity Actions

feat(core): write logs as state jsonl

Browse source
This commit is contained in:
opencode-agent[bot] 2026-06-05 14:07:45 +00:00
commit ce69ddb88e
6 changed files with 226 additions and 105 deletions
Download patch file Download diff file Expand all files Collapse all files

2
packages/core/src/global.ts
View file

@ -19,7 +19,7 @@ const paths = {
},
data,
bin: path.join(cache, "bin"),
log: path.join(data, "log"),
log: state,
repos: path.join(data, "repos"),
cache,
config,

173
packages/core/src/util/log.ts
View file

@ -2,10 +2,10 @@ export * as Log from "./log"
import path from "path"
import fs from "fs/promises"
import { createWriteStream } from "fs"
import { appendFileSync } from "fs"
import * as Global from "../global"
import { Schema } from "effect"
import { Glob } from "./glob"
import { ensureProcessMetadata } from "./opencode-process"
export const Level = Schema.Literals(["DEBUG", "INFO", "WARN", "ERROR"]).annotate({
identifier: "LogLevel",
@ -19,9 +19,6 @@ const levelPriority: Record<Level, number> = {
WARN: 2,
ERROR: 3,
}
const keep = 10
const initializedRunID = "OPENCODE_LOG_INITIALIZED_RUN_ID"
let level: Level = "INFO"
function shouldLog(input: Level): boolean {
@ -49,59 +46,42 @@ const loggers = new Map<string, Logger>()
export const Default = create({ service: "default" })
export interface Options {
print: boolean
print?: boolean
dev?: boolean
level?: Level
file?: string | false
}
let logpath = ""
export function file() {
return logpath
}
let write = (msg: any) => {
process.stderr.write(msg)
return msg.length
type LogEntry = {
json: string
pretty: string
}
let write = (entry: LogEntry) => {
process.stderr.write(entry.pretty)
}
export async function init(options: Options) {
if (options.level) level = options.level
void cleanup(Global.Path.log)
if (options.print) return
logpath = path.join(
Global.Path.log,
options.dev ? "dev.log" : new Date().toISOString().split(".")[0].replace(/:/g, "") + ".log",
)
const runID = process.env.OPENCODE_RUN_ID
const shouldTruncate = !options.dev || !runID || process.env[initializedRunID] !== runID
if (shouldTruncate) await fs.truncate(logpath).catch(() => {})
if (options.dev && runID) process.env[initializedRunID] = runID
const stream = createWriteStream(logpath, { flags: "a" })
write = async (msg: any) => {
return new Promise((resolve, reject) => {
stream.write(msg, (err) => {
if (err) reject(err)
else resolve(msg.length)
})
})
level = options.level ?? parseLevel(process.env.OPENCODE_LOG_LEVEL) ?? level
const print = options.print ?? truthy(process.env.OPENCODE_PRINT_LOGS)
const configured = options.file ?? process.env.OPENCODE_LOG_FILE
logpath = configured === false || disabled(configured) ? "" : configured || path.join(Global.Path.log, "log.jsonl")
if (logpath) await fs.mkdir(path.dirname(logpath), { recursive: true })
write = (entry) => {
if (logpath) {
try {
appendFileSync(logpath, entry.json)
} catch {}
}
if (print) process.stderr.write(entry.pretty)
}
}
async function cleanup(dir: string) {
const files = (
await Glob.scan("????-??-??T??????.log", {
cwd: dir,
absolute: false,
include: "file",
}).catch(() => [])
)
.filter((file) => path.basename(file) === file)
.sort()
if (files.length <= keep) return
const doomed = files.slice(0, -keep)
await Promise.all(doomed.map((file) => fs.unlink(path.join(dir, file)).catch(() => {})))
}
function formatError(error: Error, depth = 0): string {
const result = error.message
return error.cause instanceof Error && depth < 10
@ -121,43 +101,63 @@ export function create(tags?: Record<string, any>) {
}
}
function build(message: any, extra?: Record<string, any>) {
const prefix = Object.entries({
...tags,
...extra,
})
.filter(([_, value]) => value !== undefined && value !== null)
.map(([key, value]) => {
const prefix = `${key}=`
if (value instanceof Error) return prefix + formatError(value)
if (typeof value === "object") return prefix + JSON.stringify(value)
return prefix + value
function build(inputLevel: Level, message: any, extra?: Record<string, any>): LogEntry {
const ts = new Date()
const metadata = ensureProcessMetadata("main")
const fields = Object.fromEntries(
Object.entries({
...tags,
...extra,
})
.filter((entry) => entry[1] !== undefined && entry[1] !== null)
.map(([key, value]) => [key, normalize(value)]),
)
const service = typeof fields.service === "string" ? fields.service : undefined
if (service) delete fields.service
const text = stringifyMessage(message)
const record = {
ts: ts.toISOString(),
level: inputLevel,
message: text,
run_id: metadata.runID,
process_role: metadata.processRole,
pid: process.pid,
service,
fields,
}
const diff = ts.getTime() - last
last = ts.getTime()
const prefix = Object.entries({ service, ...fields })
.filter((entry) => entry[1] !== undefined && entry[1] !== null)
.map(([key, value]) => `${key}=${typeof value === "object" ? safeStringify(value) : value}`)
.join(" ")
const next = new Date()
const diff = next.getTime() - last
last = next.getTime()
return [next.toISOString().split(".")[0], "+" + diff + "ms", prefix, message].filter(Boolean).join(" ") + "\n"
return {
json: safeStringify(record) + "\n",
pretty:
[inputLevel.padEnd(5), ts.toISOString().split(".")[0], "+" + diff + "ms", prefix, text]
.filter(Boolean)
.join(" ") + "\n",
}
}
const result: Logger = {
debug(message?: any, extra?: Record<string, any>) {
if (shouldLog("DEBUG")) {
write("DEBUG " + build(message, extra))
write(build("DEBUG", message, extra))
}
},
info(message?: any, extra?: Record<string, any>) {
if (shouldLog("INFO")) {
write("INFO " + build(message, extra))
write(build("INFO", message, extra))
}
},
error(message?: any, extra?: Record<string, any>) {
if (shouldLog("ERROR")) {
write("ERROR " + build(message, extra))
write(build("ERROR", message, extra))
}
},
warn(message?: any, extra?: Record<string, any>) {
if (shouldLog("WARN")) {
write("WARN " + build(message, extra))
write(build("WARN", message, extra))
}
},
tag(key: string, value: string) {
@ -192,3 +192,50 @@ export function create(tags?: Record<string, any>) {
return result
}
function truthy(value: string | undefined) {
return value?.toLowerCase() === "1" || value?.toLowerCase() === "true"
}
function disabled(value: string | undefined) {
const lower = value?.toLowerCase()
return lower === "0" || lower === "false" || lower === "off"
}
function parseLevel(value: string | undefined): Level | undefined {
if (value === "DEBUG" || value === "INFO" || value === "WARN" || value === "ERROR") return value
return undefined
}
function stringifyMessage(message: any): string {
if (message instanceof Error) return formatError(message)
if (message === undefined) return ""
if (typeof message === "string") return message
if (typeof message === "object") return safeStringify(message)
return String(message)
}
function normalize(value: any): any {
if (value instanceof Error) {
return {
name: value.name,
message: formatError(value),
stack: value.stack,
}
}
if (typeof value === "bigint") return value.toString()
return value
}
function safeStringify(value: any) {
const seen = new WeakSet<object>()
return JSON.stringify(value, (_, item) => {
if (typeof item === "bigint") return item.toString()
if (item instanceof Error) return normalize(item)
if (typeof item === "object" && item !== null) {
if (seen.has(item)) return "[Circular]"
seen.add(item)
}
return item
})
}

2
packages/opencode/src/cli/cmd/run/trace.ts
View file

@ -1,7 +1,7 @@
// Dev-only JSONL event trace for direct interactive mode.
//
// Enable with OPENCODE_DIRECT_TRACE=1. Writes one JSON line per event to
// ~/.local/share/opencode/log/direct/<timestamp>-<pid>.jsonl. Also writes
// ~/.local/state/opencode/direct/<timestamp>-<pid>.jsonl. Also writes
// a latest.json pointer so you can quickly find the most recent trace.
//
// The trace captures the full closed loop: outbound prompts, inbound SDK

14
packages/opencode/src/index.ts
View file

@ -67,6 +67,11 @@ function show(out: string) {
process.stderr.write(out)
}
function parseLogLevel(value: string | undefined): Log.Level | undefined {
if (value === "DEBUG" || value === "INFO" || value === "WARN" || value === "ERROR") return value
return undefined
}
const cli = yargs(args)
.parserConfiguration({ "populate--": true })
.scriptName("opencode")
@ -79,6 +84,10 @@ const cli = yargs(args)
describe: "print logs to stderr",
type: "boolean",
})
.option("log-file", {
describe: "path to JSONL log file",
type: "string",
})
.option("log-level", {
describe: "log level",
type: "string",
@ -94,10 +103,13 @@ const cli = yargs(args)
}
await Log.init({
print: process.argv.includes("--print-logs"),
print: opts.printLogs,
file: opts.logFile,
dev: Installation.isLocal(),
level: (() => {
if (opts.logLevel) return opts.logLevel as Log.Level
const envLevel = parseLogLevel(process.env.OPENCODE_LOG_LEVEL)
if (envLevel) return envLevel
if (Installation.isLocal()) return "DEBUG"
return "INFO"
})(),

24
packages/opencode/src/temporary.ts
View file

@ -4,11 +4,27 @@ import { InstallationVersion } from "@opencode-ai/core/installation/version"
import { hideBin } from "yargs/helpers"
import { Log } from "./node"
const args = hideBin(process.argv)
function flag(name: string) {
const index = args.indexOf(name)
if (index >= 0) return args[index + 1]
const value = args.find((arg) => arg.startsWith(name + "="))
return value?.slice(name.length + 1)
}
function parseLogLevel(value: string | undefined): Log.Level | undefined {
if (value === "DEBUG" || value === "INFO" || value === "WARN" || value === "ERROR") return value
return undefined
}
Log.init({
print: false,
print: args.includes("--print-logs"),
file: flag("--log-file"),
level: parseLogLevel(flag("--log-level")),
})
const cli = yargs(hideBin(process.argv))
const cli = yargs(args)
.parserConfiguration({ "populate--": true })
.scriptName("opencode")
.wrap(100)
@ -20,6 +36,10 @@ const cli = yargs(hideBin(process.argv))
describe: "print logs to stderr",
type: "boolean",
})
.option("log-file", {
describe: "path to JSONL log file",
type: "string",
})
.option("log-level", {
describe: "log level",
type: "string",

120
packages/opencode/test/util/log.test.ts
View file

@ -3,6 +3,7 @@ import { Effect } from "effect"
import fs from "fs/promises"
import path from "path"
import { CrossSpawnSpawner } from "@opencode-ai/core/cross-spawn-spawner"
import * as EffectLogger from "@opencode-ai/core/effect/logger"
import { Global } from "@opencode-ai/core/global"
import * as Log from "@opencode-ai/core/util/log"
import { tmpdirScoped } from "../fixture/fixture"
@ -10,68 +11,109 @@ import { testEffect } from "../lib/effect"
const it = testEffect(CrossSpawnSpawner.defaultLayer)
function files(dir: string) {
return Effect.gen(function* () {
let last = ""
let same = 0
for (let i = 0; i < 50; i++) {
const list = yield* Effect.promise(() => fs.readdir(dir).then((files) => files.sort()))
const next = JSON.stringify(list)
same = next === last ? same + 1 : 0
if (same >= 2 && list.length === 11) return list
last = next
yield* Effect.sleep("10 millis")
}
return yield* Effect.promise(() => fs.readdir(dir).then((files) => files.sort()))
})
function restoreEnv(key: string, value: string | undefined) {
if (value === undefined) delete process.env[key]
else process.env[key] = value
}
it.live("init cleanup keeps the newest timestamped logs", () =>
it.live("init writes JSONL to the default state log file", () =>
Effect.gen(function* () {
const log = Global.Path.log
const file = process.env.OPENCODE_LOG_FILE
const level = process.env.OPENCODE_LOG_LEVEL
const print = process.env.OPENCODE_PRINT_LOGS
yield* Effect.addFinalizer(() => Effect.sync(() => (Global.Path.log = log)))
const dir = yield* tmpdirScoped()
Global.Path.log = dir
restoreEnv("OPENCODE_LOG_FILE", undefined)
restoreEnv("OPENCODE_LOG_LEVEL", undefined)
restoreEnv("OPENCODE_PRINT_LOGS", undefined)
yield* Effect.addFinalizer(() =>
Effect.promise(async () => {
Global.Path.log = log
restoreEnv("OPENCODE_LOG_FILE", file)
restoreEnv("OPENCODE_LOG_LEVEL", level)
restoreEnv("OPENCODE_PRINT_LOGS", print)
await Log.init({ print: false, level: "DEBUG" })
}),
)
const list = Array.from({ length: 12 }, (_, i) => `2000-01-${String(i + 1).padStart(2, "0")}T000000.log`)
yield* Effect.promise(() => Log.init({ print: false, level: "DEBUG" }))
Log.create({ service: "log.test.default" }).info("hello", { answer: 42 })
yield* Effect.all(list.map((file) => Effect.promise(() => fs.writeFile(path.join(dir, file), file))))
const record = JSON.parse(yield* Effect.promise(() => fs.readFile(path.join(dir, "log.jsonl"), "utf8")))
yield* Effect.promise(() => Log.init({ print: false, dev: false }))
const next = yield* files(dir)
expect(next).not.toContain(list[0]!)
expect(next).toContain(list.at(-1)!)
expect(Log.file()).toBe(path.join(dir, "log.jsonl"))
expect(record.level).toBe("INFO")
expect(record.message).toBe("hello")
expect(record.service).toBe("log.test.default")
expect(record.pid).toBe(process.pid)
expect(record.fields.answer).toBe(42)
expect(typeof record.run_id).toBe("string")
expect(typeof record.process_role).toBe("string")
}),
)
it.live("local dev log is not truncated twice for the same run", () =>
it.live("env can override file path and log level", () =>
Effect.gen(function* () {
const log = Global.Path.log
const runID = process.env.OPENCODE_RUN_ID
const initialized = process.env.OPENCODE_LOG_INITIALIZED_RUN_ID
const file = process.env.OPENCODE_LOG_FILE
const level = process.env.OPENCODE_LOG_LEVEL
yield* Effect.addFinalizer(() =>
Effect.sync(() => {
Effect.promise(async () => {
Global.Path.log = log
if (runID === undefined) delete process.env.OPENCODE_RUN_ID
else process.env.OPENCODE_RUN_ID = runID
if (initialized === undefined) delete process.env.OPENCODE_LOG_INITIALIZED_RUN_ID
else process.env.OPENCODE_LOG_INITIALIZED_RUN_ID = initialized
restoreEnv("OPENCODE_LOG_FILE", file)
restoreEnv("OPENCODE_LOG_LEVEL", level)
await Log.init({ print: false, level: "DEBUG" })
}),
)
const dir = yield* tmpdirScoped()
Global.Path.log = dir
process.env.OPENCODE_RUN_ID = "run-1"
delete process.env.OPENCODE_LOG_INITIALIZED_RUN_ID
process.env.OPENCODE_LOG_FILE = path.join(dir, "custom.jsonl")
process.env.OPENCODE_LOG_LEVEL = "WARN"
yield* Effect.promise(() => Log.init({ print: false, dev: true }))
yield* Effect.promise(() => fs.writeFile(path.join(dir, "dev.log"), "main startup\n"))
yield* Effect.promise(() => Log.init({ print: false, dev: true }))
yield* Effect.promise(() => Log.init({ print: false }))
const logger = Log.create({ service: "log.test.env" })
logger.info("hidden")
logger.warn("visible")
expect(yield* Effect.promise(() => fs.readFile(path.join(dir, "dev.log"), "utf8"))).toContain("main startup")
const records = (yield* Effect.promise(() => fs.readFile(path.join(dir, "custom.jsonl"), "utf8")))
.trim()
.split("\n")
.map((line) => JSON.parse(line))
expect(Log.file()).toBe(path.join(dir, "custom.jsonl"))
expect(records).toHaveLength(1)
expect(records[0].level).toBe("WARN")
expect(records[0].message).toBe("visible")
}),
)
it.live("Effect logger writes annotations into JSONL fields", () =>
Effect.gen(function* () {
const log = Global.Path.log
yield* Effect.addFinalizer(() =>
Effect.promise(async () => {
Global.Path.log = log
await Log.init({ print: false, level: "DEBUG" })
}),
)
const dir = yield* tmpdirScoped()
Global.Path.log = dir
yield* Effect.promise(() => Log.init({ print: false, level: "DEBUG" }))
yield* Effect.logInfo("effect hello").pipe(
Effect.annotateLogs({ service: "log.test.effect", "session.id": "session-1" }),
Effect.provide(EffectLogger.layer),
)
const record = JSON.parse(yield* Effect.promise(() => fs.readFile(path.join(dir, "log.jsonl"), "utf8")))
expect(record.level).toBe("INFO")
expect(record.message).toBe("effect hello")
expect(record.service).toBe("log.test.effect")
expect(record.fields["session.id"]).toBe("session-1")
}),
)