From 4c451c639bdb0f5b4fff6e9206f2c2fa22c8f0c7 Mon Sep 17 00:00:00 2001 From: euzu Date: Fri, 18 Sep 2026 15:47:02 +0200 Subject: [PATCH] runtime liveness watchdog --- .github/workflows/docker-build.yml | 15 +- CHANGELOG.md | 13 + Cargo.lock | 177 +++++++++ Makefile | 6 + backend/app/Cargo.toml | 8 +- backend/app/src/api/main_api.rs | 5 + backend/app/src/main.rs | 19 + backend/core/src/model/healthcheck.rs | 24 ++ backend/core/src/utils/mod.rs | 1 + backend/core/src/utils/runtime_liveness.rs | 442 +++++++++++++++++++++ bin/build_docker.sh | 30 +- docker/Dockerfile.manual | 18 + docs/src/build-and-deploy.md | 17 + docs/src/operations-debugging.md | 90 +++++ docs/src/troubleshooting.md | 32 ++ 15 files changed, 882 insertions(+), 15 deletions(-) create mode 100644 backend/core/src/utils/runtime_liveness.rs diff --git a/.github/workflows/docker-build.yml b/.github/workflows/docker-build.yml index 4af27091d..2bfa82aeb 100644 --- a/.github/workflows/docker-build.yml +++ b/.github/workflows/docker-build.yml @@ -66,13 +66,14 @@ jobs: chmod +x ./bin/inc_version.sh if [[ "${{ github.event_name }}" == "push" ]]; then case "${{ github.ref_name }}" in - develop|experimental) ./bin/inc_version.sh ;; + develop) ./bin/inc_version.sh ;; + experimental) echo "🔬 Experimental builds do not bump versions; keeping version from develop." ;; master) echo "Master builds use the version already committed in the merged PR; skipping version bump." ;; *) echo "Unsupported push branch: ${{ github.ref_name }}" >&2; exit 1 ;; esac else - if [[ "${{ github.event.inputs.branch }}" == "master" ]]; then - echo "Manual master builds use the version already committed on master; skipping version bump." + if [[ "${{ github.event.inputs.branch }}" == "master" || "${{ github.event.inputs.branch }}" == "experimental" ]]; then + echo "Manual ${{ github.event.inputs.branch }} builds skip version bump." else case "${{ github.event.inputs.choice }}" in major) ./bin/inc_version.sh m ;; @@ -146,8 +147,8 @@ jobs: done - name: Commit version bump if: >- - (github.event_name == 'push' && (github.ref == 'refs/heads/develop' || github.ref == 'refs/heads/experimental')) || - (github.event_name == 'workflow_dispatch' && github.event.inputs.branch != 'master') + (github.event_name == 'push' && github.ref == 'refs/heads/develop') || + (github.event_name == 'workflow_dispatch' && github.event.inputs.branch == 'develop' && github.event.inputs.choice != 'none') id: version_commit run: | git config user.name "euzu" @@ -219,8 +220,8 @@ jobs: if: >- success() && ( - (github.event_name == 'push' && (github.ref == 'refs/heads/develop' || github.ref == 'refs/heads/experimental')) || - (github.event_name == 'workflow_dispatch' && github.event.inputs.branch != 'master') + (github.event_name == 'push' && github.ref == 'refs/heads/develop') || + (github.event_name == 'workflow_dispatch' && github.event.inputs.branch == 'develop') ) && steps.version_commit.outputs.did_commit == 'true' run: | diff --git a/CHANGELOG.md b/CHANGELOG.md index d1f592d60..b1990a9d2 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -110,6 +110,13 @@ ## 🌟 New Features +- **Runtime liveness watchdog and a tokio-console diagnostic build.** An optional heartbeat/watchdog detects a wedged + async runtime (process alive, scheduler no longer making progress, logs stop) and logs a diagnostic snapshot with + runtime metrics and a per-thread `/proc/self/task` inventory. It is opt-in and off by default (`TULIPROX_WATCHDOG=1`), + never restarts the process, and exposes its state through the `/healthcheck` `runtime` object. For deeper task and lock + inspection, `make build-diagnostic` produces a separate `tokio-console` binary; normal release images contain neither + the subscriber nor `tokio_unstable`. + - **`.env` file support for secrets and environment variables:** Tuliprox now automatically loads environment variables from a `.env` file at startup. - **Discovery order:** searches `--env-file ` (or `-e`), `TULIPROX_ENV_FILE`, then `/.env` @@ -1330,6 +1337,12 @@ ## ⚙️ New Settings +- **Runtime diagnostics (environment variables)**: + - `TULIPROX_WATCHDOG` (default unset = disabled): set to `1`/`true`/`on`/`yes`/`enabled` to start the liveness watchdog. + - `TULIPROX_WATCHDOG_HEARTBEAT_MS` (default `1000`), `TULIPROX_WATCHDOG_STALL_MS` (default `10000`) and + `TULIPROX_WATCHDOG_RELOG_MS` (default `30000`): heartbeat cadence, stall threshold and re-log interval. + - `TULIPROX_TOKIO_CONSOLE` (default unset): set to `1` to start the console subscriber in a `tokio-console` build. + - **source.yml (target `options`)**: - Added optional `clear_invalid_epg_ids` (`bool`, default `false`) to clear unresolved live-channel EPG IDs after EPG matching and final mappings without removing playlist entries. The legacy name `required_epg` is accepted while diff --git a/Cargo.lock b/Cargo.lock index c47091847..0fe3b1564 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -472,6 +472,12 @@ version = "3.20.2" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "5d20789868f4b01b2f2caec9f5c4e0213b41e3e5702a50157d699ae31ced2fcb" +[[package]] +name = "byteorder" +version = "1.5.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "1fd0f2584146f6f2ef48085050886acf353beff7305ebd1ae69500e27c67f64b" + [[package]] name = "bytes" version = "1.12.1" @@ -676,6 +682,46 @@ version = "0.4.32" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "cc14f565cf027a105f7a44ccf9e5b424348421a1d8952a8fc9d499d313107789" +[[package]] +name = "console-api" +version = "0.9.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "e8599749b6667e2f0c910c1d0dff6901163ff698a52d5a39720f61b5be4b20d3" +dependencies = [ + "futures-core", + "prost", + "prost-types", + "tonic", + "tonic-prost", + "tracing-core", +] + +[[package]] +name = "console-subscriber" +version = "0.5.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "fb4915b7d8dd960457a1b6c380114c2944f728e7c65294ab247ae6b6f1f37592" +dependencies = [ + "console-api", + "crossbeam-channel", + "crossbeam-utils", + "futures-task", + "hdrhistogram", + "humantime", + "hyper-util", + "prost", + "prost-types", + "serde", + "serde_json", + "thread_local", + "tokio", + "tokio-stream", + "tonic", + "tracing", + "tracing-core", + "tracing-subscriber", +] + [[package]] name = "console_error_panic_hook" version = "0.1.7" @@ -763,6 +809,15 @@ dependencies = [ "winnow 0.7.15", ] +[[package]] +name = "crossbeam-channel" +version = "0.5.17" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "98b0cc327b5bc766e7fda9c9260cc0fa81b43a8e240440422dff70788e3f9ef1" +dependencies = [ + "crossbeam-utils", +] + [[package]] name = "crossbeam-utils" version = "0.8.21" @@ -1795,6 +1850,19 @@ dependencies = [ "foldhash", ] +[[package]] +name = "hdrhistogram" +version = "7.6.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "f49d1053f4708f0af3cf9fc5bffc7e68a914a3c45becb231c80068c9c3f78bea" +dependencies = [ + "base64 0.22.1", + "byteorder", + "flate2", + "nom 8.0.0", + "num-traits", +] + [[package]] name = "heck" version = "0.5.0" @@ -1884,6 +1952,12 @@ version = "1.0.3" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "df3b46402a9d5adb4c86a0cf463f42e19994e3ee891101b1841f30a545cb49a9" +[[package]] +name = "humantime" +version = "2.4.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "15cdd26707701c53297e2fa6afb323d55fbc1d0810c3aec078ae3ef0424c3c15" + [[package]] name = "hybrid-array" version = "0.4.10" @@ -2183,6 +2257,15 @@ version = "1.70.2" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "a6cb138bb79a146c1bd460005623e142ef0181e3d0219cb493e02f7d08a35695" +[[package]] +name = "itertools" +version = "0.14.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "2b192c782037fadd9cfa75548310488aabdbf3d2da73885b31bd0abd03351285" +dependencies = [ + "either", +] + [[package]] name = "itoa" version = "1.0.18" @@ -2398,6 +2481,15 @@ dependencies = [ "twox-hash", ] +[[package]] +name = "matchers" +version = "0.2.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "d1525a2a28c7f4fa0fc98bb91ae755d1e2d1505079e05539e35bc876b5d65ae9" +dependencies = [ + "regex-automata", +] + [[package]] name = "matchit" version = "0.8.4" @@ -3051,6 +3143,38 @@ dependencies = [ "unicode-ident", ] +[[package]] +name = "prost" +version = "0.14.4" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "528ac67416ff8646872a3c02cad9cc4ee5dc9f9540c9b10771855c95cb2e5ae1" +dependencies = [ + "bytes", + "prost-derive", +] + +[[package]] +name = "prost-derive" +version = "0.14.4" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "b570b25f7617e43d59005d0990ccb79e950a423952cea19671b7a876da390adf" +dependencies = [ + "anyhow", + "itertools", + "proc-macro2", + "quote", + "syn 2.0.119", +] + +[[package]] +name = "prost-types" +version = "0.14.4" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "f94967dc7688f3054c7fac87473ffae4cc4c3904800e2d9f5b857246d8963b0a" +dependencies = [ + "prost", +] + [[package]] name = "quanta" version = "0.12.6" @@ -3780,6 +3904,15 @@ dependencies = [ "digest 0.11.3", ] +[[package]] +name = "sharded-slab" +version = "0.1.7" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "f40ca3c46823713e0d4209592e8d6e826aa57e928f09752619fc696c499637f6" +dependencies = [ + "lazy_static", +] + [[package]] name = "shared" version = "3.3.113" @@ -4069,6 +4202,15 @@ dependencies = [ "syn 3.0.4", ] +[[package]] +name = "thread_local" +version = "1.1.10" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "1ad99c4c6d32803332c548b1af0540b357b3f5fc0be8f6c6bfe8b2e6ae784070" +dependencies = [ + "cfg-if", +] + [[package]] name = "time" version = "0.3.55" @@ -4140,6 +4282,7 @@ dependencies = [ "signal-hook-registry", "socket2", "tokio-macros", + "tracing", "windows-sys 0.61.2", ] @@ -4265,6 +4408,17 @@ dependencies = [ "tracing", ] +[[package]] +name = "tonic-prost" +version = "0.14.5" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "a55376a0bbaa4975a3f10d009ad763d8f4108f067c7c2e74f3001fb49778d309" +dependencies = [ + "bytes", + "prost", + "tonic", +] + [[package]] name = "tower" version = "0.5.3" @@ -4373,6 +4527,22 @@ source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "db97caf9d906fbde555dd62fa95ddba9eecfd14cb388e4f491a66d74cd5fb79a" dependencies = [ "once_cell", + "valuable", +] + +[[package]] +name = "tracing-subscriber" +version = "0.3.23" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "cb7f578e5945fb242538965c2d0b04418d38ec25c79d160cd279bf0731c8d319" +dependencies = [ + "matchers", + "once_cell", + "regex-automata", + "sharded-slab", + "thread_local", + "tracing", + "tracing-core", ] [[package]] @@ -4396,6 +4566,7 @@ dependencies = [ "chrono", "chrono-tz", "clap", + "console-subscriber", "crc32fast", "cron", "dashmap", @@ -5035,6 +5206,12 @@ dependencies = [ "wasm-bindgen", ] +[[package]] +name = "valuable" +version = "0.1.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "ba73ea9cf16a25df0c8caa16c51acb937d5712a8429db78a3ee29d5dcacd3a65" + [[package]] name = "vergen" version = "10.0.3" diff --git a/Makefile b/Makefile index b173a43aa..ea362a24e 100644 --- a/Makefile +++ b/Makefile @@ -215,6 +215,12 @@ build: ## Build the entire workspace in parallel using detected CPU count @echo "==> Building workspace with $(CARGO_BUILD_JOBS) jobs" @TMPDIR="$${TMPDIR:-/tmp}" $(CARGO_STABLE) build -j$(CARGO_BUILD_JOBS) --workspace +.PHONY: build-diagnostic +build-diagnostic: ## Build tuliprox with tokio-console (diagnostic only; requires tokio_unstable) + @echo "==> Building diagnostic binary (tokio-console, RUSTFLAGS=--cfg tokio_unstable)" + @RUSTFLAGS="--cfg tokio_unstable" TMPDIR="$${TMPDIR:-/tmp}" $(CARGO_STABLE) build -j$(CARGO_BUILD_JOBS) --package tuliprox --features tokio-console + @echo "==> Run with TULIPROX_TOKIO_CONSOLE=1, then connect with: tokio-console" + .PHONY: serve serve: ## Run tuliprox server with settings folder: make serve @if [ -z "$(SETTINGS_FOLDER)" ]; then \ diff --git a/backend/app/Cargo.toml b/backend/app/Cargo.toml index 900455cea..40bb9d895 100644 --- a/backend/app/Cargo.toml +++ b/backend/app/Cargo.toml @@ -63,9 +63,8 @@ blake3.workspace = true bytes.workspace = true tokio-stream = { version = "0.1.19", features = ["sync"] } tokio = { workspace = true, features = ["rt-multi-thread", "parking_lot", "fs", "process", "signal", "time", "macros"] } -#console-subscriber = "0" -#tracing = "0.1" -#tracing-subscriber = { version = "0.3", features = ["fmt", "env-filter"] } +# Diagnostic-only: built solely under the `tokio-console` feature. +console-subscriber = { version = "0.5", optional = true } tokio-util = { version = "0.7.19", features = ["io", "io-util"] } tempfile = "3.27.0" base64.workspace = true @@ -119,6 +118,9 @@ tokio-rustls = "0.26.4" [features] proxy-auth-regression = [] +# Diagnostic build. Requires RUSTFLAGS="--cfg tokio_unstable" at compile time; +# see `make build-diagnostic`. Inactive unless TULIPROX_TOKIO_CONSOLE=1. +tokio-console = ["dep:console-subscriber"] [[bin]] diff --git a/backend/app/src/api/main_api.rs b/backend/app/src/api/main_api.rs index 70431235f..bf973ce9f 100644 --- a/backend/app/src/api/main_api.rs +++ b/backend/app/src/api/main_api.rs @@ -281,11 +281,16 @@ fn get_web_dir_path(web_ui_enabled: bool, web_root: &str) -> Result Healthcheck { + // `status` stays `ok` for as long as the server answers requests: the + // container healthcheck restarts on a non-ok body, and a wedged runtime is + // reported by the watchdog thread instead of by killing the process. + // Liveness is exposed separately in `runtime`. Healthcheck { status: "ok".to_string(), version: VERSION.to_string(), build_time: get_build_time(), server_time: get_server_time(), + runtime: tuliprox_core::utils::runtime_liveness::health_snapshot(), } } diff --git a/backend/app/src/main.rs b/backend/app/src/main.rs index 19173cf3f..f3b33fd8e 100644 --- a/backend/app/src/main.rs +++ b/backend/app/src/main.rs @@ -277,8 +277,26 @@ fn handle_migrate_db(db_path: &Path, db_type: Option<&str>, no_backup: bool) { } } +/// Installs the tokio-console subscriber when the diagnostic build is used and +/// explicitly requested at runtime. +/// +/// The subscriber is expensive: it records every task poll. It is therefore +/// compiled in only under the `tokio-console` feature and stays inactive unless +/// `TULIPROX_TOKIO_CONSOLE=1`. A production binary does not contain the code. +#[cfg(feature = "tokio-console")] +fn init_tokio_console() { + if std::env::var("TULIPROX_TOKIO_CONSOLE").is_ok_and(|value| value == "1") { + console_subscriber::init(); + info!("tokio-console subscriber enabled (connect with `tokio-console`)"); + } +} + +#[cfg(not(feature = "tokio-console"))] +const fn init_tokio_console() {} + #[tokio::main] async fn main() { + init_tokio_console(); api::api_utils::init_uptime_clock(); let args = Args::parse(); @@ -531,6 +549,7 @@ async fn start_in_cli_mode(cfg: Arc, targets: Arc) { } async fn start_in_server_mode(cfg: Arc, targets: Arc) { + tuliprox_core::utils::runtime_liveness::start(&tokio::runtime::Handle::current()); if let Err(err) = api::main_api::start_server(cfg, targets).await { exit!("Can't start server: {err}"); } diff --git a/backend/core/src/model/healthcheck.rs b/backend/core/src/model/healthcheck.rs index 46b5534c3..7190d0353 100644 --- a/backend/core/src/model/healthcheck.rs +++ b/backend/core/src/model/healthcheck.rs @@ -8,4 +8,28 @@ pub struct Healthcheck { #[serde(default, skip_serializing_if = "is_blank_optional_string")] pub build_time: Option, pub server_time: String, + /// Runtime liveness as observed by the scheduler heartbeat. Absent before + /// the watchdog is installed (for example in setup mode). + #[serde(default, skip_serializing_if = "Option::is_none")] + pub runtime: Option, +} + +/// Liveness snapshot produced by the scheduler heartbeat. +/// +/// `status` is `alive` while the heartbeat is within its stall threshold and +/// `stalled` otherwise. This field is informational: the enclosing +/// [`Healthcheck::status`] stays `ok` for as long as the HTTP server answers, +/// so an orchestrator does not restart a process that still serves requests. +#[derive(Debug, Clone, Serialize, Deserialize)] +pub struct RuntimeHealth { + pub status: String, + pub heartbeat_age_ms: u64, + pub heartbeat_interval_ms: u64, + pub stall_threshold_ms: u64, + #[serde(default, skip_serializing_if = "Option::is_none")] + pub stalled_for_ms: Option, + pub ticks: u64, + pub stall_episodes: u64, + pub max_schedule_delay_ms: u64, + pub uptime_ms: u64, } diff --git a/backend/core/src/utils/mod.rs b/backend/core/src/utils/mod.rs index 981790d0f..8b281ac23 100644 --- a/backend/core/src/utils/mod.rs +++ b/backend/core/src/utils/mod.rs @@ -18,6 +18,7 @@ mod provider_resolve_token; mod recording_paths; pub mod request_headers; pub mod response_compression; +pub mod runtime_liveness; mod step_measure; mod sys_utils; mod telegram; diff --git a/backend/core/src/utils/runtime_liveness.rs b/backend/core/src/utils/runtime_liveness.rs new file mode 100644 index 000000000..0d5d5c611 --- /dev/null +++ b/backend/core/src/utils/runtime_liveness.rs @@ -0,0 +1,442 @@ +//! Scheduler heartbeat and an independent watchdog thread. +//! +//! A wedged Tokio runtime parks every worker on a futex and leaves the I/O +//! driver in `epoll_wait`; at the OS level that is indistinguishable from an +//! idle runtime. No task inside the runtime can report that state, so the +//! detection is split in two: +//! +//! * a heartbeat task records monotonic progress only while the scheduler +//! still runs, and +//! * a plain `std::thread`, outside the runtime, watches the heartbeat age and +//! logs a diagnostic snapshot when progress stops. +//! +//! The watchdog never restarts or interrupts anything. It only reports. + +use crate::model::RuntimeHealth; +use log::{debug, info, warn}; +use std::{ + sync::{ + atomic::{AtomicU64, Ordering}, + Arc, OnceLock, + }, + time::{Duration, Instant}, +}; + +pub const DEFAULT_HEARTBEAT_INTERVAL_MS: u64 = 1_000; +pub const DEFAULT_STALL_THRESHOLD_MS: u64 = 10_000; +pub const DEFAULT_STALL_RELOG_MS: u64 = 30_000; +pub const DEFAULT_WATCHDOG_POLL_MS: u64 = 1_000; + +/// The watchdog only sleeps and reads atomics outside a stall, so it does not +/// need the default thread stack. +const WATCHDOG_STACK_SIZE: usize = 256 * 1024; + +fn monotonic_origin() -> Instant { + static ORIGIN: OnceLock = OnceLock::new(); + *ORIGIN.get_or_init(Instant::now) +} + +/// Monotonic milliseconds since the process first read the liveness clock. +/// +/// Wall-clock reads can jump backwards on NTP adjustments, which would make a +/// heartbeat age meaningless; the watchdog therefore never uses `SystemTime`. +#[must_use] +pub fn monotonic_now_ms() -> u64 { u64::try_from(monotonic_origin().elapsed().as_millis()).unwrap_or(u64::MAX) } + +fn read_env_ms(name: &str, default_ms: u64) -> u64 { + std::env::var(name) + .ok() + .and_then(|value| value.trim().parse::().ok()) + .filter(|value| *value > 0) + .unwrap_or(default_ms) +} + +fn watchdog_flag_enabled(value: Option<&str>) -> bool { + value.is_some_and(|value| { + matches!(value.trim().to_ascii_lowercase().as_str(), "1" | "true" | "on" | "yes" | "enabled") + }) +} + +/// The watchdog is opt-in: without `TULIPROX_WATCHDOG=1` (or `true`/`on`/`yes`/ +/// `enabled`) no heartbeat task and no watchdog thread are started. +fn watchdog_enabled() -> bool { watchdog_flag_enabled(std::env::var("TULIPROX_WATCHDOG").ok().as_deref()) } + +/// Progress shared between the in-runtime heartbeat and the watchdog thread. +/// +/// Every accessor takes the current monotonic instant instead of reading a +/// clock, so the stall decision is testable without threads or time. +pub struct RuntimeLiveness { + started_ms: u64, + heartbeat_interval_ms: u64, + stall_threshold_ms: u64, + last_tick_ms: AtomicU64, + ticks: AtomicU64, + stall_episodes: AtomicU64, + max_schedule_delay_ms: AtomicU64, +} + +impl RuntimeLiveness { + #[must_use] + pub fn new(started_ms: u64, heartbeat_interval_ms: u64, stall_threshold_ms: u64) -> Self { + Self { + started_ms, + heartbeat_interval_ms: heartbeat_interval_ms.max(1), + stall_threshold_ms: stall_threshold_ms.max(1), + last_tick_ms: AtomicU64::new(started_ms), + ticks: AtomicU64::new(0), + stall_episodes: AtomicU64::new(0), + max_schedule_delay_ms: AtomicU64::new(0), + } + } + + #[must_use] + pub const fn heartbeat_interval_ms(&self) -> u64 { self.heartbeat_interval_ms } + + #[must_use] + pub const fn stall_threshold_ms(&self) -> u64 { self.stall_threshold_ms } + + /// Records progress. `schedule_delay_ms` is how late the heartbeat was + /// scheduled relative to its deadline and surfaces scheduler pressure even + /// when the threshold is never crossed. + pub fn tick(&self, now_ms: u64, schedule_delay_ms: u64) { + self.last_tick_ms.store(now_ms, Ordering::Release); + self.ticks.fetch_add(1, Ordering::Relaxed); + self.max_schedule_delay_ms.fetch_max(schedule_delay_ms, Ordering::Relaxed); + } + + /// Saturation covers a heartbeat timestamp that is somehow ahead of `now`. + #[must_use] + pub fn age_ms(&self, now_ms: u64) -> u64 { now_ms.saturating_sub(self.last_tick_ms.load(Ordering::Acquire)) } + + #[must_use] + pub fn is_stalled(&self, now_ms: u64) -> bool { self.age_ms(now_ms) > self.stall_threshold_ms } + + pub fn note_stall(&self) { self.stall_episodes.fetch_add(1, Ordering::Relaxed); } + + #[must_use] + pub fn snapshot(&self, now_ms: u64) -> RuntimeHealth { + let age = self.age_ms(now_ms); + let stalled = age > self.stall_threshold_ms; + RuntimeHealth { + status: if stalled { "stalled".to_string() } else { "alive".to_string() }, + heartbeat_age_ms: age, + heartbeat_interval_ms: self.heartbeat_interval_ms, + stall_threshold_ms: self.stall_threshold_ms, + stalled_for_ms: stalled.then(|| age.saturating_sub(self.stall_threshold_ms)), + ticks: self.ticks.load(Ordering::Relaxed), + stall_episodes: self.stall_episodes.load(Ordering::Relaxed), + max_schedule_delay_ms: self.max_schedule_delay_ms.load(Ordering::Relaxed), + uptime_ms: now_ms.saturating_sub(self.started_ms), + } + } +} + +static INSTANCE: OnceLock> = OnceLock::new(); + +/// Installs the process-wide liveness state once. Later calls are ignored. +pub fn install(liveness: Arc) -> bool { INSTANCE.set(liveness).is_ok() } + +#[must_use] +pub fn installed() -> Option<&'static Arc> { INSTANCE.get() } + +/// Current liveness snapshot, or `None` when the watchdog is not installed. +#[must_use] +pub fn health_snapshot() -> Option { + INSTANCE.get().map(|liveness| liveness.snapshot(monotonic_now_ms())) +} + +/// Starts the heartbeat task and the watchdog thread, unless already started. +/// +/// Returns the shared state on success. The watchdog is opt-in; without +/// `TULIPROX_WATCHDOG=1` nothing is started. The interval and threshold can be +/// overridden with `TULIPROX_WATCHDOG_HEARTBEAT_MS` and +/// `TULIPROX_WATCHDOG_STALL_MS`; the relog interval with +/// `TULIPROX_WATCHDOG_RELOG_MS`. +pub fn start(runtime: &tokio::runtime::Handle) -> Option> { + if !watchdog_enabled() { + debug!("Runtime liveness watchdog disabled (set TULIPROX_WATCHDOG=1 to enable)"); + return None; + } + + let heartbeat_interval_ms = read_env_ms("TULIPROX_WATCHDOG_HEARTBEAT_MS", DEFAULT_HEARTBEAT_INTERVAL_MS); + let stall_threshold_ms = read_env_ms("TULIPROX_WATCHDOG_STALL_MS", DEFAULT_STALL_THRESHOLD_MS); + let relog_ms = read_env_ms("TULIPROX_WATCHDOG_RELOG_MS", DEFAULT_STALL_RELOG_MS); + + let liveness = Arc::new(RuntimeLiveness::new(monotonic_now_ms(), heartbeat_interval_ms, stall_threshold_ms)); + if !install(Arc::clone(&liveness)) { + return None; + } + + spawn_heartbeat(Arc::clone(&liveness)); + match spawn_watchdog(Arc::clone(&liveness), runtime.clone(), relog_ms) { + Ok(_) => info!( + "Runtime liveness watchdog started: heartbeat {heartbeat_interval_ms} ms, stall threshold {stall_threshold_ms} ms" + ), + Err(err) => warn!("Failed to start runtime liveness watchdog thread: {err}"), + } + Some(liveness) +} + +/// Spawns the in-runtime heartbeat task. +fn spawn_heartbeat(liveness: Arc) { + let interval = Duration::from_millis(liveness.heartbeat_interval_ms()); + tokio::spawn(async move { + let mut expected = Instant::now() + interval; + loop { + tokio::time::sleep_until(tokio::time::Instant::from_std(expected)).await; + let now = Instant::now(); + let delay_ms = u64::try_from(now.saturating_duration_since(expected).as_millis()).unwrap_or(u64::MAX); + liveness.tick(monotonic_now_ms(), delay_ms); + expected += interval; + // After a long stall, sleep_until would return immediately until it + // catches up; resync so recovery does not become a tight loop. + if expected < now { + expected = now + interval; + } + } + }); +} + +/// Spawns the watchdog thread that lives outside the Tokio runtime. +fn spawn_watchdog( + liveness: Arc, + runtime: tokio::runtime::Handle, + relog_ms: u64, +) -> std::io::Result> { + std::thread::Builder::new().name("tuliprox-watchdog".to_string()).stack_size(WATCHDOG_STACK_SIZE).spawn(move || { + run_watchdog(&liveness, &runtime, relog_ms); + }) +} + +/// The decision the watchdog makes on each poll. +#[derive(Debug, Clone, Copy, PartialEq, Eq)] +enum WatchdogVerdict { + /// Within the threshold and not in a stall, or still inside an episode but + /// before the relog interval is due. + Quiet, + /// Above the threshold and it is time to (re)log the stall. + LogStall, + /// The heartbeat is fresh again after an episode. + Recovered, +} + +fn watchdog_verdict( + age_ms: u64, + stall_threshold_ms: u64, + in_stall: bool, + since_last_log_ms: u64, + relog_ms: u64, +) -> WatchdogVerdict { + if age_ms > stall_threshold_ms { + if in_stall && since_last_log_ms < relog_ms { + WatchdogVerdict::Quiet + } else { + WatchdogVerdict::LogStall + } + } else if in_stall { + WatchdogVerdict::Recovered + } else { + WatchdogVerdict::Quiet + } +} + +fn run_watchdog(liveness: &RuntimeLiveness, runtime: &tokio::runtime::Handle, relog_ms: u64) { + let poll = Duration::from_millis(DEFAULT_WATCHDOG_POLL_MS); + let threshold_ms = liveness.stall_threshold_ms(); + let mut in_stall = false; + let mut last_log_ms = 0_u64; + + loop { + std::thread::sleep(poll); + let now = monotonic_now_ms(); + let age = liveness.age_ms(now); + let since_last_log = now.saturating_sub(last_log_ms); + match watchdog_verdict(age, threshold_ms, in_stall, since_last_log, relog_ms) { + WatchdogVerdict::Quiet => {} + WatchdogVerdict::LogStall => { + if !in_stall { + liveness.note_stall(); + } + let snapshot = liveness.snapshot(now); + warn!( + "Runtime liveness stall: heartbeat silent for {age} ms (threshold {threshold_ms} ms, episode {})", + snapshot.stall_episodes + ); + log_runtime_diagnostics(&snapshot, runtime, age); + last_log_ms = now; + in_stall = true; + } + WatchdogVerdict::Recovered => { + info!("Runtime liveness recovered: heartbeat resumed after {age} ms of silence"); + in_stall = false; + } + } + } +} + +fn log_runtime_diagnostics(snapshot: &RuntimeHealth, runtime: &tokio::runtime::Handle, age_ms: u64) { + let metrics = runtime.metrics(); + warn!( + "Runtime diagnostics: heartbeat_age_ms={age_ms}, heartbeat_interval_ms={}, stall_threshold_ms={}, ticks={}, max_schedule_delay_ms={}, uptime_ms={}, workers={}, alive_tasks={}, global_queue_depth={}", + snapshot.heartbeat_interval_ms, + snapshot.stall_threshold_ms, + snapshot.ticks, + snapshot.max_schedule_delay_ms, + snapshot.uptime_ms, + metrics.num_workers(), + metrics.num_alive_tasks(), + metrics.global_queue_depth(), + ); + + #[cfg(target_has_atomic = "64")] + log_worker_diagnostics(&metrics); + + #[cfg(target_os = "linux")] + log_thread_inventory(); +} + +// Only metrics that are stable without `tokio_unstable` may be used here: the +// same source must compile in the default build. `worker_poll_count`, +// `worker_local_queue_depth` and the blocking-pool counters are behind +// `tokio_unstable` and are deliberately omitted. +#[cfg(target_has_atomic = "64")] +fn log_worker_diagnostics(metrics: &tokio::runtime::RuntimeMetrics) { + for worker in 0..metrics.num_workers() { + warn!( + "Runtime worker {worker}: park_count={}, total_busy={:?}", + metrics.worker_park_count(worker), + metrics.worker_total_busy_duration(worker), + ); + } +} + +/// Logs what every thread in this process is doing, mirroring the manual +/// `/proc//task/*/stack` inspection used to diagnose a hang. +#[cfg(target_os = "linux")] +fn log_thread_inventory() { + let Ok(entries) = std::fs::read_dir("/proc/self/task") else { return }; + + let mut threads: Vec = Vec::new(); + for entry in entries.flatten() { + let Some(tid) = entry.file_name().into_string().ok() else { continue }; + let base = entry.path(); + let comm = + std::fs::read_to_string(base.join("comm")).map_or_else(|_| "?".to_string(), |name| name.trim().to_string()); + let state = read_proc_state(&base.join("stat")); + let wchan = std::fs::read_to_string(base.join("wchan")) + .map_or_else(|_| "?".to_string(), |value| value.trim().to_string()); + threads.push(format!("tid={tid} name={comm} state={state} wchan={wchan}")); + } + threads.sort(); + warn!("Runtime thread inventory ({} threads):\n{}", threads.len(), threads.join("\n")); +} + +/// Reads the state field from `/proc//stat`. +/// +/// The command name in the second field is wrapped in parentheses and may +/// itself contain spaces and parentheses, so the state is the token following +/// the *last* `)`. +#[cfg(target_os = "linux")] +fn read_proc_state(stat_path: &std::path::Path) -> String { + let Ok(stat) = std::fs::read_to_string(stat_path) else { return "?".to_string() }; + stat.rfind(')') + .and_then(|closing| stat[closing + 1..].split_whitespace().next()) + .map_or_else(|| "?".to_string(), ToString::to_string) +} + +#[cfg(test)] +mod tests { + use super::{ + monotonic_now_ms, spawn_heartbeat, watchdog_flag_enabled, watchdog_verdict, RuntimeLiveness, WatchdogVerdict, + }; + use std::{ + sync::Arc, + time::{Duration, Instant}, + }; + + #[test] + fn watchdog_flag_is_off_by_default_and_accepts_conventional_on_values() { + assert!(!watchdog_flag_enabled(None)); + for value in ["0", "false", "FALSE", " off ", "no", "disabled", ""] { + assert!(!watchdog_flag_enabled(Some(value)), "expected {value:?} to keep the watchdog off"); + } + for value in ["1", "true", "TRUE", " on ", "yes", "enabled"] { + assert!(watchdog_flag_enabled(Some(value)), "expected {value:?} to enable the watchdog"); + } + } + + #[tokio::test] + async fn heartbeat_task_records_progress() { + let liveness = Arc::new(RuntimeLiveness::new(monotonic_now_ms(), 5, 5_000)); + spawn_heartbeat(Arc::clone(&liveness)); + let deadline = Instant::now() + Duration::from_secs(5); + while liveness.snapshot(monotonic_now_ms()).ticks == 0 { + assert!(Instant::now() < deadline, "heartbeat task never ticked"); + tokio::time::sleep(Duration::from_millis(10)).await; + } + assert!(!liveness.is_stalled(monotonic_now_ms())); + } + + #[test] + fn fresh_heartbeat_reports_alive() { + let liveness = RuntimeLiveness::new(1_000, 1_000, 5_000); + liveness.tick(2_000, 3); + let snapshot = liveness.snapshot(2_500); + assert_eq!(snapshot.status, "alive"); + assert_eq!(snapshot.heartbeat_age_ms, 500); + assert_eq!(snapshot.stalled_for_ms, None); + assert_eq!(snapshot.ticks, 1); + assert_eq!(snapshot.max_schedule_delay_ms, 3); + assert_eq!(snapshot.uptime_ms, 1_500); + } + + #[test] + fn silent_heartbeat_reports_stalled_with_overflow_age() { + let liveness = RuntimeLiveness::new(0, 1_000, 5_000); + liveness.tick(1_000, 0); + let snapshot = liveness.snapshot(9_000); + assert_eq!(snapshot.status, "stalled"); + assert_eq!(snapshot.heartbeat_age_ms, 8_000); + assert_eq!(snapshot.stalled_for_ms, Some(3_000)); + assert!(liveness.is_stalled(9_000)); + assert!(!liveness.is_stalled(5_500)); + } + + #[test] + fn heartbeat_age_saturates_when_clock_moves_backwards() { + let liveness = RuntimeLiveness::new(10_000, 1_000, 5_000); + assert_eq!(liveness.age_ms(1_000), 0); + } + + #[test] + fn max_schedule_delay_keeps_the_worst_observation() { + let liveness = RuntimeLiveness::new(0, 1_000, 5_000); + liveness.tick(1_000, 10); + liveness.tick(2_000, 4); + liveness.tick(3_000, 25); + assert_eq!(liveness.snapshot(3_000).max_schedule_delay_ms, 25); + } + + #[test] + fn stall_episodes_are_counted_once_per_episode() { + let liveness = RuntimeLiveness::new(0, 1_000, 5_000); + assert_eq!(liveness.snapshot(0).stall_episodes, 0); + liveness.note_stall(); + liveness.note_stall(); + assert_eq!(liveness.snapshot(0).stall_episodes, 2); + } + + #[test] + fn verdict_logs_on_entry_then_respects_relog_interval() { + assert_eq!(watchdog_verdict(1_000, 5_000, false, 0, 30_000), WatchdogVerdict::Quiet); + assert_eq!(watchdog_verdict(6_000, 5_000, false, 0, 30_000), WatchdogVerdict::LogStall); + assert_eq!(watchdog_verdict(6_000, 5_000, true, 1_000, 30_000), WatchdogVerdict::Quiet); + assert_eq!(watchdog_verdict(6_000, 5_000, true, 30_000, 30_000), WatchdogVerdict::LogStall); + } + + #[test] + fn verdict_reports_recovery_only_after_an_episode() { + assert_eq!(watchdog_verdict(100, 5_000, false, 0, 30_000), WatchdogVerdict::Quiet); + assert_eq!(watchdog_verdict(100, 5_000, true, 0, 30_000), WatchdogVerdict::Recovered); + } +} diff --git a/bin/build_docker.sh b/bin/build_docker.sh index 19b477666..efab248cb 100755 --- a/bin/build_docker.sh +++ b/bin/build_docker.sh @@ -30,6 +30,20 @@ esac echo "🚀 Building for branch: $BRANCH (tag: $TAG_SUFFIX)" +# The experimental image is the diagnostic build: tokio-console is compiled in +# and switched on inside the image. develop and master must stay uninstrumented, +# so both the cargo feature and tokio_unstable are confined to this branch. +CARGO_FEATURES=() +DOCKER_BUILD_ARGS=() +if [ "$BRANCH" = "experimental" ]; then + export RUSTFLAGS="${RUSTFLAGS} --cfg tokio_unstable" + CARGO_FEATURES=(--features tokio-console) + # 0.0.0.0 is required so a host-published port can reach the in-container + # gRPC server; publish it as 127.0.0.1:6669:6669 to keep it host-local. + DOCKER_BUILD_ARGS=(--build-arg TULIPROX_TOKIO_CONSOLE=1 --build-arg TOKIO_CONSOLE_BIND=0.0.0.0:6669) + echo "🔬 Experimental diagnostic build: tokio_unstable + --features tokio-console" +fi + # Directories WORKING_DIR=$(pwd) DOCKER_DIR="${WORKING_DIR}/docker" @@ -104,7 +118,7 @@ for PLATFORM in "${!ARCHITECTURES[@]}"; do echo "🔨 Building for $ARCHITECTURE" # Using cross for compilation - cross build -p tuliprox --release --target "$ARCHITECTURE" --locked + cross build -p tuliprox --release --target "$ARCHITECTURE" --locked ${CARGO_FEATURES[@]+"${CARGO_FEATURES[@]}"} SOURCE_BIN_PATH="target/${ARCHITECTURE}/release/tuliprox" cp "${SOURCE_BIN_PATH}" "${DOCKER_DIR}/binaries/tuliprox-${ARCHITECTURE}" @@ -131,20 +145,26 @@ REPO_OWNER_LC="${REPO_OWNER,,}" for IMAGE_NAME in "${!MULTI_PLATFORM_IMAGES[@]}"; do BUILD_TARGET="${MULTI_PLATFORM_IMAGES[$IMAGE_NAME]}" - TAG_VERSION="ghcr.io/${REPO_OWNER_LC}/${IMAGE_NAME}:${VERSION}" TAG_BRANCH="ghcr.io/${REPO_OWNER_LC}/${IMAGE_NAME}:${TAG_SUFFIX}" + if [ "$BRANCH" = "experimental" ]; then + # Experimental images must not overwrite official release version tags + TAG_VERSION="ghcr.io/${REPO_OWNER_LC}/${IMAGE_NAME}:experimental-${VERSION}" + else + TAG_VERSION="ghcr.io/${REPO_OWNER_LC}/${IMAGE_NAME}:${VERSION}" + fi echo "🎯 Building multi-platform image: ${IMAGE_NAME}" # THE FIX: Using type=gha for automatic GitHub Actions cache management. - # No more local files, no more leftover artifacts. + # Scoped per branch/tag_suffix to avoid cache pollution between develop and experimental. docker buildx build -f Dockerfile.manual \ -t "${TAG_VERSION}" \ -t "${TAG_BRANCH}" \ --target "$BUILD_TARGET" \ --platform "linux/amd64,linux/arm64" \ - --cache-from "type=gha,scope=${IMAGE_NAME}" \ - --cache-to "type=gha,mode=max,scope=${IMAGE_NAME}" \ + --cache-from "type=gha,scope=${IMAGE_NAME}-${TAG_SUFFIX}" \ + --cache-to "type=gha,mode=max,scope=${IMAGE_NAME}-${TAG_SUFFIX}" \ + ${DOCKER_BUILD_ARGS[@]+"${DOCKER_BUILD_ARGS[@]}"} \ --push \ . done diff --git a/docker/Dockerfile.manual b/docker/Dockerfile.manual index 73be5990e..32b0fede4 100644 --- a/docker/Dockerfile.manual +++ b/docker/Dockerfile.manual @@ -37,6 +37,15 @@ FROM scratch AS scratch-final ARG TZ=UTC ENV TZ=${TZ} +# Non-zero only in the experimental diagnostic image; the binary ignores any +# other value, and develop/master images do not contain the subscriber at all. +ARG TULIPROX_TOKIO_CONSOLE=0 +ENV TULIPROX_TOKIO_CONSOLE=${TULIPROX_TOKIO_CONSOLE} +# console-subscriber binds this address. Loopback by default; the experimental +# image widens it to 0.0.0.0 so a published host port can reach the gRPC server. +ARG TOKIO_CONSOLE_BIND=127.0.0.1:6669 +ENV TOKIO_CONSOLE_BIND=${TOKIO_CONSOLE_BIND} + # Copy timezone data and localtime from tz-prep COPY --from=tz-prep /output/usr/share/zoneinfo /usr/share/zoneinfo COPY --from=tz-prep /output/etc/localtime /etc/localtime @@ -63,6 +72,15 @@ FROM alpine:latest AS alpine-final ARG TZ=UTC ENV TZ=${TZ} +# Non-zero only in the experimental diagnostic image; the binary ignores any +# other value, and develop/master images do not contain the subscriber at all. +ARG TULIPROX_TOKIO_CONSOLE=0 +ENV TULIPROX_TOKIO_CONSOLE=${TULIPROX_TOKIO_CONSOLE} +# console-subscriber binds this address. Loopback by default; the experimental +# image widens it to 0.0.0.0 so a published host port can reach the gRPC server. +ARG TOKIO_CONSOLE_BIND=127.0.0.1:6669 +ENV TOKIO_CONSOLE_BIND=${TOKIO_CONSOLE_BIND} + # Install dependencies including ffmpeg RUN apk add --no-cache bash curl strace tcpdump bind-tools nano ca-certificates tini ffmpeg diff --git a/docs/src/build-and-deploy.md b/docs/src/build-and-deploy.md index ddc6b352e..36438f374 100644 --- a/docs/src/build-and-deploy.md +++ b/docs/src/build-and-deploy.md @@ -41,6 +41,7 @@ environment across different machines. * `make test`: Runs all workspace tests using the Stable toolchain. * `make lint`: Runs clippy to find common mistakes and improve code quality. * `make lint-fix`: Automatically applies clippy suggestions (where possible). +* `make build-diagnostic`: Builds the backend with `tokio-console` support (diagnostic only, not part of normal releases). * `make markdown-lint`: Checks all .md files for formatting consistency. **Formatting**: @@ -128,6 +129,22 @@ rustup target add x86_64-unknown-linux-musl cargo build -p tuliprox --target x86_64-unknown-linux-musl --release ``` +### Diagnostic Build (tokio-console) + +To diagnose async hangs (tasks that never complete, locks held across `.await`), build the diagnostic binary: + +```bash +make build-diagnostic +TULIPROX_TOKIO_CONSOLE=1 ./target/release/tuliprox -s -p ./config +tokio-console # defaults to http://127.0.0.1:6669 +``` + +This build compiles `tokio` with `--cfg tokio_unstable` and enables the optional `console-subscriber`. It is a separate +binary and normal release builds are unaffected. The experimental Docker image +(`ghcr.io/euzu/tuliprox:experimental`) is built this way and enables the subscriber by default. See +[Runtime Liveness Watchdog](./operations-debugging.md#8-runtime-liveness-watchdog) for the always-available (opt-in) +watchdog that does not require a special build. + ### Cross-Compilation (ARM / Windows) To compile for architectures other than your host, use the `cross` tool or native mingw packages. diff --git a/docs/src/operations-debugging.md b/docs/src/operations-debugging.md index 4dfc74240..874890a06 100644 --- a/docs/src/operations-debugging.md +++ b/docs/src/operations-debugging.md @@ -417,3 +417,93 @@ If hot-reload fails to trigger, a container restart (`docker restart tuliprox`) is the safest fallback. --- + +## 8. Runtime Liveness Watchdog + +A reverse proxy can wedge without crashing: the process is still alive, but the async scheduler stops making progress and +the logs simply stop. At the OS level this looks like an idle process, so `docker stats` and `ps` cannot tell it apart +from a healthy one. + +The watchdog detects exactly that. It is **opt-in and off by default**. + +### What it does + +* **Heartbeat (inside the runtime):** a small task records a monotonic timestamp every second and measures how late it + was scheduled. +* **Watchdog thread (outside the runtime):** a separate `std::thread` watches the heartbeat age. If the scheduler is + wedged, the heartbeat stops advancing and the thread logs a diagnostic snapshot. +* **On a stall** it logs (once, then every 30 s while it continues) the heartbeat age, runtime metrics (worker count, + alive tasks, global queue depth, per-worker park counts) and, on Linux, a `/proc/self/task` inventory with each + thread's id, name, state and waiting channel. +* **On recovery** it logs that the heartbeat is back. + +The watchdog never restarts or interrupts the process. It only reports. + +### Enabling + +| Variable | Default | Purpose | +|:---------------------------------|:----------------|:-------------------------------------------------------| +| `TULIPROX_WATCHDOG` | *(unset = off)* | Set to `1` (or `true`/`on`/`yes`/`enabled`) to enable. | +| `TULIPROX_WATCHDOG_HEARTBEAT_MS` | `1000` | Heartbeat interval. | +| `TULIPROX_WATCHDOG_STALL_MS` | `10000` | Heartbeat age above which a stall is reported. | +| `TULIPROX_WATCHDOG_RELOG_MS` | `30000` | Re-log interval while a stall continues. | + +Docker example: + +```yaml +services: + tuliprox: + environment: + - TULIPROX_WATCHDOG=1 +``` + +### Healthcheck + +While the watchdog runs, `GET /healthcheck` gains a `runtime` object: + +```json +{ + "status": "ok", + "runtime": { + "status": "alive", + "heartbeat_age_ms": 12, + "heartbeat_interval_ms": 1000, + "stall_threshold_ms": 10000, + "ticks": 8401, + "stall_episodes": 0, + "max_schedule_delay_ms": 3, + "uptime_ms": 8401000 + } +} +``` + +`runtime.status` is `stalled` once the heartbeat stops. The top-level `status` intentionally stays `ok` for as long as the +HTTP server answers, so no orchestrator restarts the process. If the whole runtime is wedged, the endpoint cannot answer +at all — in that case the watchdog log is the signal. + +--- + +## 9. tokio-console Diagnostic Build + +`tokio-console` shows live which tasks exist, where each one is waiting, and which lock it holds. It is the tool to +identify an async deadlock. It needs a special build and is never part of the standard production image. + +```bash +# Build the diagnostic binary (requires RUSTFLAGS="--cfg tokio_unstable" internally) +make build-diagnostic + +# Run it with the subscriber enabled and attach the console +TULIPROX_TOKIO_CONSOLE=1 ./target/release/tuliprox -s -p ./config +tokio-console # defaults to http://127.0.0.1:6669 +``` + +The experimental Docker image (`ghcr.io/euzu/tuliprox:experimental`) already carries this build and enables it by default. + +Notes: + +* The default release build compiles none of this: no `tokio_unstable`, no `console-subscriber`. There is no runtime cost + in normal images. +* The console gRPC server has no authentication. Keep it on loopback (the default) or, if you must publish a port, + publish it only on the host loopback (`-p 127.0.0.1:6669:6669`). + +--- diff --git a/docs/src/troubleshooting.md b/docs/src/troubleshooting.md index c8229102a..6602dc185 100644 --- a/docs/src/troubleshooting.md +++ b/docs/src/troubleshooting.md @@ -205,3 +205,35 @@ any operation requiring a new descriptor (such as opening a file or creating a s ``` --- + +## 5. Server Stops Responding While the Container Keeps Running + +**The Problem:** After running normally for a while (often hours), Tuliprox stops processing and logging. The container +still shows `running` with `ExitCode: 0` and low CPU/memory; there is no panic, no shutdown message and no final log +entry. Only a manual restart recovers it. + +**Root Cause:** A wedged async runtime. Every Tokio worker is parked on a futex and the I/O driver sits in `epoll_wait`, +which the OS cannot distinguish from an idle process. This is consistent with a task holding a shared lock while waiting +forever on a network operation that has no timeout (for example an upstream that accepts the connection but never sends a +response). + +**How to confirm:** Enable the runtime liveness watchdog (off by default): + +```yaml +services: + tuliprox: + environment: + - TULIPROX_WATCHDOG=1 +``` + +When the runtime stops making progress, the watchdog logs a `Runtime liveness stall` line with runtime metrics and a +per-thread `/proc/self/task` inventory, and `GET /healthcheck` reports `runtime.status: stalled`. The watchdog never +restarts the process. + +**How to find the exact task and lock:** use the `tokio-console` diagnostic build (see +[Runtime Liveness Watchdog](./operations-debugging.md#8-runtime-liveness-watchdog)) or run the experimental image. + +**Immediate mitigation:** restart the container. The watchdog log is what tells you the stall happened on its own and +captures what every thread was doing at that moment. + +---