From b6886d222b7f2027d05864b8cd224964aedbd38e Mon Sep 17 00:00:00 2001 From: ykiko Date: Sun, 5 Apr 2026 18:55:22 +0800 Subject: [PATCH] feat: per-session file-based logging with crash capture (#393) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit ## Summary Implement structured file-based logging with per-component separation and crash stacktrace capture. ### Log output structure ``` .clice/logs/2026-04-05_10-30-00_/ master.log SF-0.log SF-1.log SL-0.log ``` ### Changes **Logging infrastructure** (`logging.h`, `logging.cpp`) - `file_logger()` creates a dual-sink logger (file + stderr), so logs go to both the file and terminal - Pre-checks log directory creation and file writability before constructing spdlog sinks; falls back to existing stderr logger on failure - `install_crash_handler()` uses LLVM's `AddSignalHandler` + `PrintStackTraceOnErrorSignal` to write crash stacktraces into the component's log file (and also to stderr) - Fix `LOG_MESSAGE` macro: wrap in `do { } while(0)` to prevent dangling-else - Fix typo: `file_loggger` → `file_logger` **Config** (`config.h`, `config.cpp`) - Add `logging_dir` field to `CliceConfig`, defaulting to `/logs/` - Apply `${workspace}` variable substitution to `logging_dir` **Master server** (`master_server.h`, `master_server.cpp`) - After config loads, create a session directory named `_` under `logging_dir` and switch master to file logging - Pass session log directory to worker pool **Worker pool** (`worker_pool.h`, `worker_pool.cpp`) - Pass `--worker-name` (e.g. `SF-0`, `SL-1`) and `--log-dir` to spawned worker processes - Add `log_dir` to `WorkerPoolOptions` **Workers** (`stateful_worker.h/cpp`, `stateless_worker.h/cpp`) - Accept `worker_name` and `log_dir` parameters; switch to file logging when `log_dir` is provided **CLI cleanup** (`clice.cc`) - Remove `--stateful-worker-count`, `--stateless-worker-count` from CLI (config-file only) - Group internal worker args (`--worker-memory-limit`, `--worker-name`, `--log-dir`) separately **Docs** (`docs/clice.toml`) - Fix `logging_dir` example: `.clice/logging` → `.clice/logs` ## Test plan - [x] `pixi run cmake-build RelWithDebInfo` compiles successfully - [ ] Verify log files created under `.clice/logs/_/` - [ ] Verify each component writes to its own file - [ ] Verify crash stacktrace appears in component log file - [ ] Verify `logging_dir` override in `clice.toml` works - [ ] Verify graceful fallback when log directory is not writable 🤖 Generated with [Claude Code](https://claude.com/claude-code) ## Summary by CodeRabbit * **New Features** * Session-specific logging directories (timestamped) and per-worker log files * CLI options to set worker name and log directory; general log level control * Configurable logging directory with default `/logs/` * **Bug Fixes** * Fixed file-logging name/initialization issues; ensures directory creation and deterministic filenames * Added crash-handler support to append stack traces to logs * **Documentation** * Updated example config to use `${workspace}/.clice/logs` --------- Co-authored-by: Claude Opus 4.6 (1M context) --- docs/clice.toml | 2 +- src/clice.cc | 44 ++++++++++--------- src/server/config.cpp | 5 +++ src/server/config.h | 3 ++ src/server/master_server.cpp | 13 ++++++ src/server/master_server.h | 3 ++ src/server/stateful_worker.cpp | 9 +++- src/server/stateful_worker.h | 5 ++- src/server/stateless_worker.cpp | 7 ++- src/server/stateless_worker.h | 4 +- src/server/worker_pool.cpp | 23 +++++++--- src/server/worker_pool.h | 2 + src/support/logging.cpp | 75 +++++++++++++++++++++++++++------ src/support/logging.h | 15 +++++-- 14 files changed, 158 insertions(+), 52 deletions(-) diff --git a/docs/clice.toml b/docs/clice.toml index 1b423096..ccf06bd5 100644 --- a/docs/clice.toml +++ b/docs/clice.toml @@ -20,7 +20,7 @@ max_active_file = 8 cache_dir = "${workspace}/.clice/cache" # Directory for storing index files. index_dir = "${workspace}/.clice/index" -logging_dir = "${workspace}/.clice/logging" +logging_dir = "${workspace}/.clice/logs" # Compile commands files or directories to search for compile_commands.json files. compile_commands_paths = ["${workspace}/build"] diff --git a/src/clice.cc b/src/clice.cc index 393725e2..5f01a811 100644 --- a/src/clice.cc +++ b/src/clice.cc @@ -29,24 +29,6 @@ struct Options { DecoKV(style = KVStyle::JoinedOrSeparate, help = "Socket mode port", required = false) port = 50051; - DecoKV(style = KVStyle::JoinedOrSeparate, - names = {"--stateful-worker-count", "--stateful-worker-count="}, - help = "Number of stateful workers", - required = false) - stateful_worker_count; - - DecoKV(style = KVStyle::JoinedOrSeparate, - names = {"--stateless-worker-count", "--stateless-worker-count="}, - help = "Number of stateless workers", - required = false) - stateless_worker_count; - - DecoKV(style = KVStyle::JoinedOrSeparate, - names = {"--worker-memory-limit", "--worker-memory-limit="}, - help = "Memory limit per stateful worker (bytes)", - required = false) - worker_memory_limit; - DecoKV(style = KVStyle::JoinedOrSeparate, names = {"--log-level", "--log-level="}, help = "Log level: trace, debug, info, warn, error, off", @@ -58,6 +40,20 @@ struct Options { required = false) record; + // Internal options (passed from master to worker processes) + DecoKV(style = KVStyle::JoinedOrSeparate, + names = {"--worker-memory-limit", "--worker-memory-limit="}, + required = false) + worker_memory_limit; + + DecoKV(style = KVStyle::JoinedOrSeparate, + names = {"--worker-name", "--worker-name="}, + required = false) + worker_name; + + DecoKV(style = KVStyle::JoinedOrSeparate, names = {"--log-dir", "--log-dir="}, required = false) + log_dir; + DecoFlag(names = {"-h", "--help"}, help = "Show help message", required = false) help; @@ -108,13 +104,21 @@ int main(int argc, const char** argv) { auto& mode = *opts.mode; + auto worker_name = opts.worker_name.value_or(""); + auto log_dir = opts.log_dir.value_or(""); + if(mode == "stateless-worker") { - return clice::run_stateless_worker_mode(); + return clice::run_stateless_worker_mode(worker_name.empty() ? "stateless-worker" + : worker_name, + log_dir); } if(mode == "stateful-worker") { auto mem_limit = opts.worker_memory_limit.value_or(4ULL * 1024 * 1024 * 1024); - return clice::run_stateful_worker_mode(mem_limit); + return clice::run_stateful_worker_mode(mem_limit, + worker_name.empty() ? "stateful-worker" + : worker_name, + log_dir); } if(mode == "pipe") { diff --git a/src/server/config.cpp b/src/server/config.cpp index 68078fcc..c9c274c8 100644 --- a/src/server/config.cpp +++ b/src/server/config.cpp @@ -41,10 +41,15 @@ void CliceConfig::apply_defaults(const std::string& workspace_root) { index_dir = path::join(cache_dir, "index"); } + if(logging_dir.empty() && !cache_dir.empty()) { + logging_dir = path::join(cache_dir, "logs"); + } + // Apply variable substitution to string fields substitute_workspace(compile_commands_path, workspace_root); substitute_workspace(cache_dir, workspace_root); substitute_workspace(index_dir, workspace_root); + substitute_workspace(logging_dir, workspace_root); } std::optional CliceConfig::load(const std::string& path, diff --git a/src/server/config.h b/src/server/config.h index 243a319c..0e4df490 100644 --- a/src/server/config.h +++ b/src/server/config.h @@ -22,6 +22,9 @@ struct CliceConfig { // Index storage directory (default: /index/) std::string index_dir; + // Logging directory (default: /logs/) + std::string logging_dir; + // Background indexing bool enable_indexing = true; int idle_timeout_ms = 3000; diff --git a/src/server/master_server.cpp b/src/server/master_server.cpp index 1aa35381..eff67091 100644 --- a/src/server/master_server.cpp +++ b/src/server/master_server.cpp @@ -1,6 +1,7 @@ #include "server/master_server.h" #include +#include #include #include #include @@ -23,6 +24,7 @@ #include "syntax/scan.h" #include "llvm/Support/Chrono.h" +#include "llvm/Support/Process.h" #include "llvm/Support/raw_ostream.h" #include "llvm/Support/xxhash.h" @@ -1552,6 +1554,16 @@ void MasterServer::register_handlers() { // Load configuration from workspace config = CliceConfig::load_from_workspace(workspace_root); + // Switch master to file logging under a session-timestamped directory + if(!config.logging_dir.empty()) { + auto now = std::chrono::system_clock::now(); + auto pid = llvm::sys::Process::getProcessId(); + auto session_dir = + path::join(config.logging_dir, std::format("{:%Y-%m-%d_%H-%M-%S}_{}", now, pid)); + logging::file_logger("master", session_dir, logging::options); + session_log_dir = session_dir; + } + LOG_INFO("Server ready (stateful={}, stateless={}, idle={}ms)", config.stateful_worker_count, config.stateless_worker_count, @@ -1563,6 +1575,7 @@ void MasterServer::register_handlers() { pool_opts.stateful_count = config.stateful_worker_count; pool_opts.stateless_count = config.stateless_worker_count; pool_opts.worker_memory_limit = config.worker_memory_limit; + pool_opts.log_dir = session_log_dir; if(!pool.start(pool_opts)) { LOG_ERROR("Failed to start worker pool"); return; diff --git a/src/server/master_server.h b/src/server/master_server.h index a7cc3dad..6a54cbcb 100644 --- a/src/server/master_server.h +++ b/src/server/master_server.h @@ -146,6 +146,9 @@ private: /// User/project configuration. CliceConfig config; + /// Session-specific log directory (e.g. .clice/logs/2026-04-05_10-30-00/). + std::string session_log_dir; + /// Compilation database (compile_commands.json). CompilationDatabase cdb; diff --git a/src/server/stateful_worker.cpp b/src/server/stateful_worker.cpp index 7ecf69c7..7000cc14 100644 --- a/src/server/stateful_worker.cpp +++ b/src/server/stateful_worker.cpp @@ -320,8 +320,13 @@ void StatefulWorker::register_handlers() { }); } -int run_stateful_worker_mode(std::uint64_t memory_limit) { - logging::stderr_logger("stateful-worker", logging::options); +int run_stateful_worker_mode(std::uint64_t memory_limit, + const std::string& worker_name, + const std::string& log_dir) { + logging::stderr_logger(worker_name, logging::options); + if(!log_dir.empty()) { + logging::file_logger(worker_name, log_dir, logging::options); + } LOG_INFO("Starting stateful worker, memory_limit={}MB", memory_limit / (1024 * 1024)); diff --git a/src/server/stateful_worker.h b/src/server/stateful_worker.h index b5b9c7d4..c3c8c36c 100644 --- a/src/server/stateful_worker.h +++ b/src/server/stateful_worker.h @@ -1,12 +1,15 @@ #pragma once #include +#include namespace clice { /// Run the stateful worker process mode. /// The worker holds compiled ASTs and handles feature requests /// (hover, semantic tokens, etc.) alongside compile requests. -int run_stateful_worker_mode(std::uint64_t memory_limit); +int run_stateful_worker_mode(std::uint64_t memory_limit, + const std::string& worker_name, + const std::string& log_dir); } // namespace clice diff --git a/src/server/stateless_worker.cpp b/src/server/stateless_worker.cpp index 7fe12755..73a543f8 100644 --- a/src/server/stateless_worker.cpp +++ b/src/server/stateless_worker.cpp @@ -47,8 +47,11 @@ static et::serde::RawValue to_raw(const T& value) { return et::serde::RawValue{json ? std::move(*json) : "null"}; } -int run_stateless_worker_mode() { - logging::stderr_logger("stateless-worker", logging::options); +int run_stateless_worker_mode(const std::string& worker_name, const std::string& log_dir) { + logging::stderr_logger(worker_name, logging::options); + if(!log_dir.empty()) { + logging::file_logger(worker_name, log_dir, logging::options); + } LOG_INFO("Starting stateless worker"); diff --git a/src/server/stateless_worker.h b/src/server/stateless_worker.h index 214d930f..991a57d3 100644 --- a/src/server/stateless_worker.h +++ b/src/server/stateless_worker.h @@ -1,11 +1,13 @@ #pragma once +#include + namespace clice { /// Run the stateless worker process mode. /// The worker receives one-shot compilation tasks (BuildPCH, BuildPCM, /// Completion, SignatureHelp, Index) via stdin/stdout bincode IPC, /// executes them on a thread pool, and returns results. -int run_stateless_worker_mode(); +int run_stateless_worker_mode(const std::string& worker_name, const std::string& log_dir); } // namespace clice diff --git a/src/server/worker_pool.cpp b/src/server/worker_pool.cpp index 8f3a7ce5..9e088d22 100644 --- a/src/server/worker_pool.cpp +++ b/src/server/worker_pool.cpp @@ -52,6 +52,10 @@ et::task<> drain_stderr(et::pipe stderr_pipe, std::string prefix) { bool WorkerPool::spawn_worker(const std::string& self_path, bool stateful, std::uint64_t memory_limit) { + auto& workers = stateful ? stateful_workers : stateless_workers; + auto worker_index = workers.size(); + std::string worker_name = std::string(stateful ? "SF-" : "SL-") + std::to_string(worker_index); + et::process::options opts; opts.file = self_path; if(stateful) { @@ -63,6 +67,15 @@ bool WorkerPool::spawn_worker(const std::string& self_path, } else { opts.args = {self_path, "--mode", "stateless-worker"}; } + + opts.args.push_back("--worker-name"); + opts.args.push_back(worker_name); + + if(!log_dir_.empty()) { + opts.args.push_back("--log-dir"); + opts.args.push_back(log_dir_); + } + opts.streams = { et::process::stdio::pipe(true, false), // stdin: child reads et::process::stdio::pipe(false, true), // stdout: child writes @@ -85,14 +98,8 @@ bool WorkerPool::spawn_worker(const std::string& self_path, std::move(spawn.stdin_pipe)); auto peer = std::make_unique(loop, std::move(transport)); - auto& workers = stateful ? stateful_workers : stateless_workers; - auto worker_index = workers.size(); - - // Build log prefix: [SF-0] for stateful, [SL-0] for stateless - std::string prefix = - std::string("[") + (stateful ? "SF-" : "SL-") + std::to_string(worker_index) + "]"; - // Schedule stderr log collection + std::string prefix = "[" + worker_name + "]"; loop.schedule(drain_stderr(std::move(spawn.stderr_pipe), prefix)); workers.push_back(WorkerProcess{ @@ -108,6 +115,8 @@ bool WorkerPool::spawn_worker(const std::string& self_path, } bool WorkerPool::start(const WorkerPoolOptions& options) { + log_dir_ = options.log_dir; + for(std::uint32_t i = 0; i < options.stateless_count; ++i) { if(!spawn_worker(options.self_path, false, 0)) { return false; diff --git a/src/server/worker_pool.h b/src/server/worker_pool.h index ebd3e15c..048212f8 100644 --- a/src/server/worker_pool.h +++ b/src/server/worker_pool.h @@ -26,6 +26,7 @@ struct WorkerPoolOptions { std::uint32_t stateless_count = 2; std::uint32_t stateful_count = 2; std::uint64_t worker_memory_limit = 4ULL * 1024 * 1024 * 1024; // 4GB default + std::string log_dir; }; class WorkerPool { @@ -81,6 +82,7 @@ private: void clear_owner(std::size_t worker_index); std::size_t pick_least_loaded(); + std::string log_dir_; bool spawn_worker(const std::string& self_path, bool stateful, std::uint64_t memory_limit); }; diff --git a/src/support/logging.cpp b/src/support/logging.cpp index 6b6af41c..5e0d3206 100644 --- a/src/support/logging.cpp +++ b/src/support/logging.cpp @@ -11,6 +11,7 @@ #include "spdlog/sinks/ringbuffer_sink.h" #include "spdlog/sinks/stdout_color_sinks.h" #include "spdlog/sinks/stdout_sinks.h" +#include "llvm/Support/Signals.h" namespace clice::logging { @@ -38,27 +39,73 @@ void stderr_logger(std::string_view name, const Options& options) { spdlog::set_default_logger(std::move(logger)); } -void file_loggger(std::string_view name, std::string_view dir, const Options& options) { - auto now = std::chrono::system_clock::now(); - auto filename = std::format("{:%Y-%m-%d_%H-%M-%S}.log", now); - auto sink = std::make_shared(path::join(dir, filename)); +void file_logger(std::string_view name, std::string_view dir, const Options& options) { + if(auto ec = llvm::sys::fs::create_directories(dir)) { + spdlog::error("Failed to create log directory {}: {}", std::string(dir), ec.message()); + return; + } + auto filepath = path::join(dir, std::format("{}.log", name)); + // Verify we can write to the file before constructing the sink. + // (spdlog would throw on failure, but exceptions are disabled in this project.) + { + std::error_code ec; + llvm::raw_fd_ostream test(filepath, ec, llvm::sys::fs::OF_Append); + if(ec) { + spdlog::error("Failed to open log file {}: {}", filepath, ec.message()); + return; + } + } + auto file_sink = std::make_shared(filepath); - if(options.replay_console && ringbuffer_sink) { - sink->set_level(options.level); - sink->set_pattern(pattern); + auto replay_buffer = ringbuffer_sink; - for(auto& log: ringbuffer_sink->last_raw()) { - sink->log(log); + auto console_sink = std::make_shared(options.color); + std::array sinks = {file_sink, console_sink}; + auto logger = std::make_shared(std::string(name), sinks.begin(), sinks.end()); + logger->set_level(options.level); + logger->set_pattern(pattern); + logger->flush_on(Level::trace); + spdlog::set_default_logger(std::move(logger)); + + // Replay buffered logs after swapping the default logger, so no messages + // emitted between the snapshot and the swap are lost. + if(options.replay_console && replay_buffer) { + file_sink->set_level(options.level); + file_sink->set_pattern(pattern); + + for(auto& log: replay_buffer->last_raw()) { + file_sink->log(log); } ringbuffer_sink.reset(); } - auto logger = std::make_shared(std::string(name), std::move(sink)); - logger->set_level(options.level); - logger->set_pattern(pattern); - logger->flush_on(Level::trace); - spdlog::set_default_logger(std::move(logger)); + install_crash_handler(filepath); +} + +static std::unique_ptr crash_log_stream; + +static void crash_handler(void*) { + if(crash_log_stream) { + *crash_log_stream << "\n=== CRASH STACK TRACE ===\n"; + llvm::sys::PrintStackTrace(*crash_log_stream); + crash_log_stream->flush(); + } +} + +void install_crash_handler(std::string_view log_path) { + std::error_code ec; + crash_log_stream = + std::make_unique(llvm::StringRef(log_path.data(), log_path.size()), + ec, + llvm::sys::fs::OF_Append); + if(ec) { + LOG_WARN("Failed to install crash handler for {}: {}", log_path, ec.message()); + crash_log_stream.reset(); + return; + } + llvm::sys::AddSignalHandler(crash_handler, nullptr); + llvm::sys::PrintStackTraceOnErrorSignal("clice"); } } // namespace clice::logging diff --git a/src/support/logging.h b/src/support/logging.h index 06c62b35..9511b833 100644 --- a/src/support/logging.h +++ b/src/support/logging.h @@ -26,7 +26,12 @@ extern Options options; void stderr_logger(std::string_view name, const Options& options); -void file_loggger(std::string_view name, std::string_view dir, const Options& options); +void file_logger(std::string_view name, std::string_view dir, const Options& options); + +/// Install a signal handler that writes crash stacktraces to the given log file. +/// Also enables LLVM's default stderr stacktrace output. +/// Must be called after file_logger so the log file path is known. +void install_crash_handler(std::string_view log_path); template struct logging_rformat { @@ -95,9 +100,11 @@ void critical [[noreturn]] (logging_format fmt, Args&&... args) { } // namespace clice::logging #define LOG_MESSAGE(name, fmt, ...) \ - if(clice::logging::options.level <= clice::logging::Level::name) { \ - clice::logging::name(fmt __VA_OPT__(, ) __VA_ARGS__); \ - } + do { \ + if(clice::logging::options.level <= clice::logging::Level::name) { \ + clice::logging::name(fmt __VA_OPT__(, ) __VA_ARGS__); \ + } \ + } while(0) #define LOG_TRACE(fmt, ...) LOG_MESSAGE(trace, fmt, __VA_ARGS__) #define LOG_DEBUG(fmt, ...) LOG_MESSAGE(debug, fmt, __VA_ARGS__)