diff --git a/.dockerignore b/.dockerignore new file mode 100644 index 0000000..eacfe58 --- /dev/null +++ b/.dockerignore @@ -0,0 +1,4 @@ +target/ +.git/ +*.md +tests/ diff --git a/Dockerfile b/Dockerfile new file mode 100644 index 0000000..68ea098 --- /dev/null +++ b/Dockerfile @@ -0,0 +1,39 @@ +# Build. rusqlite is bundled (compiles SQLite from source) and librqbit needs a C +# toolchain, so the builder needs cc. TLS is rustls throughout, so no OpenSSL headers. +FROM rust:1-slim-bookworm AS build +RUN apt-get update && apt-get install -y --no-install-recommends \ + build-essential \ + && rm -rf /var/lib/apt/lists/* +WORKDIR /src + +# Dependencies first, so editing the source does not rebuild librqbit every time. +COPY Cargo.toml Cargo.lock ./ +RUN mkdir src && echo 'fn main(){}' > src/main.rs \ + && cargo build --release --locked \ + && rm -rf src + +COPY src ./src +COPY web ./web +# cargo skips a rebuild if mtimes look untouched; make sure it does not. +RUN touch src/main.rs && cargo build --release --locked + +FROM debian:bookworm-slim +RUN apt-get update && apt-get install -y --no-install-recommends \ + ca-certificates gosu \ + && rm -rf /var/lib/apt/lists/* +COPY --from=build /src/target/release/ipx /usr/local/bin/ipx +COPY docker-entrypoint.sh /usr/local/bin/ +RUN chmod +x /usr/local/bin/docker-entrypoint.sh + +ENV IPX_CONFIG=/config/config.toml \ + IPX_DATA_DIR=/data \ + IPX_LOG=ipx=info \ + PUID=99 \ + PGID=100 +VOLUME ["/config", "/data", "/downloads"] + +# Web UI, and the BitTorrent peer port (TCP and UDP -- DHT needs the UDP side). +EXPOSE 8099/tcp 6881/tcp 6881/udp + +ENTRYPOINT ["docker-entrypoint.sh"] +CMD ["ipx", "daemon"] diff --git a/PROGRESS.md b/PROGRESS.md index 56a3a7a..1a5d06f 100644 --- a/PROGRESS.md +++ b/PROGRESS.md @@ -56,6 +56,38 @@ and until now nothing set them. --- +## 2026-09-10 — Log view in the app, and Docker + +**Log view.** A ring buffer (2000 lines) fed by a `tracing` layer, exposed at `/api/logs` with a +sequence cursor so the UI polls for "everything after N" without duplicates. Tailing a file was the +obvious approach and the wrong one: under Docker the logs go to stdout and there is no file. An +`access_log` middleware adds a line per HTTP request, so the daemon and the web side share one +stream — which is what Ray asked for. That middleware skips `/api/logs` itself, or the panel's +2-second poll would generate a line per poll forever, a log of nothing but its own requests. + +UI: sidebar **Log** button, level and text filters, follow-tail toggle, copy button, colour-coded +levels. + +**Restart safety.** Detached torrents introduced a `downloading` state, and a row left in it by a +restart would sit there forever — the pending queue skips it and nothing else revisits it. +`requeue_interrupted()` resets those at startup, leaving alone any row that already has a file. + +**Docker.** Multi-stage build (deps cached separately from source), `debian:bookworm-slim` runtime, +114 MB. Entrypoint writes a starter config bound to `0.0.0.0` on first run, because a container's +loopback is unreachable from outside, and drops to `PUID:PGID` via gosu. Healthcheck is +`ipx status`, which goes through the control socket to the worker and so catches a *wedged* daemon, +not just a dead one. + +Built and actually run, not just written: image builds, container starts, writes its config, serves +the UI (401 without a token, 200 with), `/api/logs` answers, and the process runs as +`uid=99(ipx) gid=100(users)` with files owned `99:100` and the token file at mode 600. + +Worth noting for future testing here: this session's Docker socket belongs to the Unraid host, so +`-v /tmp/...:/config` binds a path on the *host*, not one visible from inside this container. The +mount looks empty from here while being perfectly correct — verify inside the container instead. + +--- + ## 2026-09-10 — Torrents: they work, and one was freezing the whole daemon Asked "is torrents working?". The honest answer had been "unverified since step 7" — so it got tested diff --git a/README.md b/README.md index c3ed6cc..69dfd75 100644 --- a/README.md +++ b/README.md @@ -134,6 +134,30 @@ server-side before they reach the page. clear — and a feed URL can itself contain a credential (Patreon's, for one, carries an auth token). Put it behind a reverse proxy with TLS if that matters to you. +## Log view + +The **Log** button in the sidebar shows the running daemon's output live: feed scans, downloads, +torrent activity and every HTTP request, with level and text filters and a copy button. It reads a +2000-line ring buffer held inside the process (`/api/logs`), not a file — so it works the same under +Docker, where logs go to stdout and there is no file to tail. `IPX_LOG=ipx=debug` adds detail; +`IPX_LOG=ipx=info,librqbit=info` shows what torrents are doing. + +## Docker + +```sh +docker compose up -d # builds the image and starts it +docker compose logs -f ipx # the token is printed on first start +``` + +`docker-compose.yml` mounts `./config`, `./data` and a downloads directory, publishes 8099 for the +UI and 6881 (TCP **and** UDP — DHT needs the UDP side), and sets `PUID`/`PGID` to `99:100` so files +land owned the way Unraid shares expect. On first start the entrypoint writes a config bound to +`0.0.0.0`, since a container's loopback is not reachable from outside it, and prints the URL with +its generated token. + +The healthcheck runs `ipx status`, which goes through the control socket to the command worker — so +it catches a daemon that is alive but wedged, not merely one that has died. + ## Running it as a service `contrib/` has a systemd user unit for the daemon, and a timer plus one-shot service if you would diff --git a/docker-compose.yml b/docker-compose.yml new file mode 100644 index 0000000..a93f5a1 --- /dev/null +++ b/docker-compose.yml @@ -0,0 +1,30 @@ +services: + ipx: + build: . + # image: ipx:latest # swap build: for image: once you have published one + container_name: ipx + restart: unless-stopped + environment: + # Unraid shares expect these; downloads land owned by nobody:users. + PUID: "99" + PGID: "100" + TZ: "America/Toronto" + # ipx=debug for verbose, or add librqbit=info to watch torrents. + IPX_LOG: "ipx=info" + ports: + - "8099:8099" # web UI + - "6881:6881/tcp" # BitTorrent peers + - "6881:6881/udp" # DHT + volumes: + - ./config:/config # config.toml, and the web token + - ./data:/data # state.db + - /mnt/user/audio/ipx:/downloads + healthcheck: + # `ipx status` proxies through the control socket to the command worker, so this + # catches a daemon that is alive but wedged -- not just one that has died. (A + # blocked worker is a real failure mode: a torrent used to be able to cause it.) + test: ["CMD", "ipx", "status"] + interval: 30s + timeout: 5s + retries: 3 + start_period: 10s diff --git a/docker-entrypoint.sh b/docker-entrypoint.sh new file mode 100755 index 0000000..0125091 --- /dev/null +++ b/docker-entrypoint.sh @@ -0,0 +1,40 @@ +#!/bin/sh +set -e + +# A container's loopback is not reachable from outside it, so the default bind of +# 127.0.0.1 would leave the UI unreachable. Write a starter config that binds 0.0.0.0 +# on first run; after that the file is yours and is never rewritten. +if [ ! -f "$IPX_CONFIG" ]; then + mkdir -p "$(dirname "$IPX_CONFIG")" + cat > "$IPX_CONFIG" </dev/null 2>&1; then addgroup --gid "$PGID" ipx 2>/dev/null || true; fi + if ! getent passwd ipx >/dev/null 2>&1; then + adduser --uid "$PUID" --gid "$PGID" --disabled-password --gecos "" ipx 2>/dev/null || true + fi + chown -R "$PUID:$PGID" "$IPX_DATA_DIR" "$(dirname "$IPX_CONFIG")" 2>/dev/null || true + exec gosu "$PUID:$PGID" "$@" +fi + +exec "$@" diff --git a/src/db.rs b/src/db.rs index 2fede90..4b03f49 100644 --- a/src/db.rs +++ b/src/db.rs @@ -703,6 +703,17 @@ impl Db { Ok(()) } + /// Nothing can be in flight the moment the daemon starts, so any row still marked + /// `downloading` is a leftover from a restart or a crash. Left alone it would sit + /// there forever: the pending queue skips it and nothing else ever revisits it. + pub fn requeue_interrupted(&self) -> Result { + let conn = self.conn.lock().unwrap(); + Ok(conn.execute( + "UPDATE enclosures SET state = 'pending' WHERE state = 'downloading' AND path IS NULL", + [], + )?) + } + /// Puts an enclosure back in the queue so the next scan picks it up. This is how a /// `skipped` verdict (from a filter that has since been changed) gets revisited. pub fn requeue(&self, id: i64) -> Result<()> { @@ -782,6 +793,27 @@ mod tests { "search is case-insensitive and covers the description"); } + #[test] + fn a_restart_requeues_interrupted_downloads() { + let db = Db::memory().unwrap(); + db.exec_for_test( + "INSERT INTO enclosures (id, feed_id, guid, url, state, path) VALUES + (1,'f','a','u1','downloading',NULL), + (2,'f','b','u2','pending',NULL), + (3,'f','c','u3','downloading','/tmp/already-here'), + (4,'f','d','u4','done','/tmp/x');", + ) + .unwrap(); + assert_eq!(db.requeue_interrupted().unwrap(), 1, "only the in-flight, fileless one"); + let conn = db.conn.lock().unwrap(); + let state = |id: i64| -> String { + conn.query_row("SELECT state FROM enclosures WHERE id = ?1", [id], |r| r.get(0)).unwrap() + }; + assert_eq!(state(1), "pending"); + assert_eq!(state(3), "downloading", "it has a file; leave it alone"); + assert_eq!(state(4), "done"); + } + #[test] fn enclosure_url_is_the_dedupe_key() { let db = Db::memory().unwrap(); diff --git a/src/logbuf.rs b/src/logbuf.rs new file mode 100644 index 0000000..4eb7bc0 --- /dev/null +++ b/src/logbuf.rs @@ -0,0 +1,154 @@ +//! In-process ring buffer of log lines, so the UI can show what the daemon is doing. +//! +//! Tailing a file would not survive Docker, where logs go to stdout and there is no file +//! to read. Capturing inside the tracing pipeline works the same either way. + +use std::collections::VecDeque; +use std::sync::{LazyLock, Mutex}; +use tracing::field::{Field, Visit}; +use tracing_subscriber::Layer; +use tracing_subscriber::layer::Context; + +/// Kept small enough to be cheap to hold and to serialise in one response. +const CAPACITY: usize = 2000; + +#[derive(Clone, Debug, serde::Serialize)] +pub struct LogLine { + /// Monotonic, so a client can ask for "everything after N" without duplicates. + pub seq: u64, + pub ts: i64, + pub level: String, + pub target: String, + pub msg: String, +} + +struct Ring { + lines: VecDeque, + next_seq: u64, +} + +static BUF: LazyLock> = LazyLock::new(|| { + Mutex::new(Ring { lines: VecDeque::with_capacity(CAPACITY), next_seq: 1 }) +}); + +pub fn push(level: &str, target: &str, msg: String) { + let mut ring = match BUF.lock() { + Ok(r) => r, + Err(p) => p.into_inner(), // a poisoned log buffer must not take the process down + }; + let seq = ring.next_seq; + ring.next_seq += 1; + if ring.lines.len() == CAPACITY { + ring.lines.pop_front(); + } + ring.lines.push_back(LogLine { + seq, + ts: crate::db::now(), + level: level.to_owned(), + target: target.to_owned(), + msg, + }); +} + +/// Lines newer than `after`, oldest first, plus the highest seq now held. +pub fn since(after: u64, limit: usize) -> (Vec, u64) { + let ring = match BUF.lock() { + Ok(r) => r, + Err(p) => p.into_inner(), + }; + let latest = ring.next_seq.saturating_sub(1); + let mut out: Vec = ring + .lines + .iter() + .filter(|l| l.seq > after) + .cloned() + .collect(); + // On a first load (after = 0) the tail is what matters, not the head. + if out.len() > limit { + out.drain(..out.len() - limit); + } + (out, latest) +} + +/// A tracing layer that mirrors every event into the ring. +pub struct RingLayer; + +impl Layer for RingLayer { + fn on_event(&self, event: &tracing::Event<'_>, _ctx: Context<'_, S>) { + let mut v = Collect::default(); + event.record(&mut v); + let meta = event.metadata(); + push(meta.level().as_str(), meta.target(), v.finish()); + } +} + +#[derive(Default)] +struct Collect { + message: String, + fields: Vec, +} + +impl Collect { + fn finish(self) -> String { + if self.fields.is_empty() { + self.message + } else if self.message.is_empty() { + self.fields.join(" ") + } else { + format!("{} {}", self.message, self.fields.join(" ")) + } + } + fn add(&mut self, field: &Field, value: String) { + if field.name() == "message" { + self.message = value; + } else { + self.fields.push(format!("{}={}", field.name(), value)); + } + } +} + +impl Visit for Collect { + fn record_debug(&mut self, field: &Field, value: &dyn std::fmt::Debug) { + self.add(field, format!("{value:?}")); + } + fn record_str(&mut self, field: &Field, value: &str) { + self.add(field, value.to_owned()); + } + fn record_i64(&mut self, field: &Field, value: i64) { + self.add(field, value.to_string()); + } + fn record_u64(&mut self, field: &Field, value: u64) { + self.add(field, value.to_string()); + } + fn record_bool(&mut self, field: &Field, value: bool) { + self.add(field, value.to_string()); + } +} + +#[cfg(test)] +mod tests { + use super::*; + + #[test] + fn the_ring_drops_oldest_and_keeps_sequence_stable() { + for i in 0..(CAPACITY + 50) { + push("INFO", "t", format!("line {i}")); + } + let (all, latest) = since(0, CAPACITY * 2); + assert_eq!(all.len(), CAPACITY, "bounded"); + assert!(latest >= (CAPACITY + 50) as u64); + assert!( + all.first().unwrap().seq < all.last().unwrap().seq, + "oldest first" + ); + + // "everything after the last one I saw" must return nothing new. + let (none, _) = since(latest, 100); + assert!(none.is_empty()); + + // A first load takes the tail, not the head. + let (tail, _) = since(0, 5); + assert_eq!(tail.len(), 5); + assert_eq!(tail.last().unwrap().seq, latest); + } +} diff --git a/src/main.rs b/src/main.rs index 35d52c2..3ca0a72 100644 --- a/src/main.rs +++ b/src/main.rs @@ -3,6 +3,7 @@ mod db; mod download; mod feed; mod ipc; +mod logbuf; mod retention; mod torrent; mod web; @@ -119,13 +120,19 @@ impl Ctx { #[tokio::main] async fn main() -> Result<()> { let cli = Cli::parse(); - tracing_subscriber::fmt() - .with_env_filter( - tracing_subscriber::EnvFilter::try_from_env("IPX_LOG") - .unwrap_or_else(|_| "ipx=info".into()), - ) - .with_writer(std::io::stderr) - .init(); + // Everything goes to stderr as before, and is mirrored into a ring the UI can read. + { + use tracing_subscriber::layer::SubscriberExt; + use tracing_subscriber::util::SubscriberInitExt; + tracing_subscriber::registry() + .with( + tracing_subscriber::EnvFilter::try_from_env("IPX_LOG") + .unwrap_or_else(|_| "ipx=info".into()), + ) + .with(tracing_subscriber::fmt::layer().with_writer(std::io::stderr)) + .with(logbuf::RingLayer) + .init(); + } let config_path = cli.config.clone().unwrap_or_else(config::config_path); let cfg = config::Config::load(&config_path)?; @@ -207,6 +214,12 @@ async fn daemon( anyhow::bail!("a daemon is already listening on {}", socket.display()); } + match ctx.db.requeue_interrupted() { + Ok(n) if n > 0 => tracing::info!(count = n, "requeued downloads interrupted by a restart"), + Ok(_) => {} + Err(e) => tracing::warn!(error = ?e, "could not requeue interrupted downloads"), + } + let (tx_cmd, mut rx_cmd) = mpsc::channel::(64); let web = start_web(&ctx, &config_path, web_addr, &tx_cmd, &events).await?; diff --git a/src/web.rs b/src/web.rs index f214ac1..6d8fe6b 100644 --- a/src/web.rs +++ b/src/web.rs @@ -72,9 +72,11 @@ pub fn router(state: WebState) -> Router { .route("/api/fetch", post(fetch_now)) .route("/api/opml", get(export_opml).post(import_opml)) .route("/api/settings", get(get_settings).patch(patch_settings)) + .route("/api/logs", get(logs)) .route("/api/events", get(events)) .route("/media/{id}", get(media)) .layer(middleware::from_fn_with_state(state.clone(), auth)) + .layer(middleware::from_fn(access_log)) .with_state(state) } @@ -790,3 +792,49 @@ async fn patch_settings( state.ctx.reload_cfg(&state.config_path)?; Ok(StatusCode::NO_CONTENT) } + +#[derive(Deserialize)] +struct LogQuery { + /// Highest seq the client already has; 0 means "give me the tail". + #[serde(default)] + after: u64, + #[serde(default = "two_hundred")] + limit: usize, +} + +fn two_hundred() -> usize { + 200 +} + +#[derive(Serialize)] +struct LogPage { + lines: Vec, + latest: u64, +} + +async fn logs(Query(q): Query) -> Json { + let (lines, latest) = crate::logbuf::since(q.after, q.limit.clamp(1, 2000)); + Json(LogPage { lines, latest }) +} + +/// One line per HTTP request, so the web side shows up in the same log as the daemon. +/// +/// The log view polls `/api/logs`, so logging that path would generate a line per poll +/// forever -- a feed of nothing but its own requests. +async fn access_log(req: Request, next: Next) -> Response { + let path = req.uri().path().to_owned(); + let method = req.method().clone(); + let quiet = path.starts_with("/api/logs"); + let started = std::time::Instant::now(); + let resp = next.run(req).await; + if !quiet { + let ms = started.elapsed().as_millis(); + let status = resp.status().as_u16(); + if resp.status().is_success() || resp.status().is_redirection() { + tracing::info!(target: "ipx::http", "{method} {path} -> {status} in {ms}ms"); + } else { + tracing::warn!(target: "ipx::http", "{method} {path} -> {status} in {ms}ms"); + } + } + resp +} diff --git a/tests/page-smoke.js b/tests/page-smoke.js index da234b6..f11a1eb 100644 --- a/tests/page-smoke.js +++ b/tests/page-smoke.js @@ -79,6 +79,7 @@ const drive = [ ['downloadLatestModal', () => ctx.downloadLatestModal(feed)], ['removeFeed', () => ctx.removeFeed(feed)], ['prefsModal', () => ctx.prefsModal()], + ['logsModal', () => ctx.logsModal()], ]; for (const [name, fn] of drive) { try { @@ -97,3 +98,5 @@ if (missing.length) { process.exit(1); } console.log('OK: page script loads clean, every selector it wires at load exists'); +// logsModal arms a poll timer; without this the pending interval keeps node alive. +process.exit(0); diff --git a/web/index.html b/web/index.html index 01142c3..349d389 100644 --- a/web/index.html +++ b/web/index.html @@ -217,6 +217,19 @@ input[type=range]::-moz-range-thumb{width:12px;height:12px;border:0;border-radiu background:var(--panel);border:1px solid var(--line);border-radius:14px; padding:20px;width:min(460px,100%);box-shadow:var(--shadow);max-height:88vh;overflow:auto; } +.card.wide{width:min(1000px,100%)} +#logbox{ + background:var(--bg);border:1px solid var(--line);border-radius:9px;padding:10px 12px; + height:min(60vh,520px);overflow:auto;font:12px/1.5 ui-monospace,SFMono-Regular,Menlo,monospace; +} +#logbox .l{display:flex;gap:9px;white-space:pre-wrap;overflow-wrap:anywhere} +#logbox time{color:var(--faint);flex:none} +#logbox .lv{flex:none;width:42px;font-weight:700} +#logbox .lv.ERROR{color:var(--bad)} #logbox .lv.WARN{color:var(--warn)} +#logbox .lv.INFO{color:var(--accent)} #logbox .lv.DEBUG,#logbox .lv.TRACE{color:var(--faint)} +#logbox .tg{color:var(--faint);flex:none} +.logbar{display:flex;gap:8px;align-items:center;margin-bottom:9px;flex-wrap:wrap} +.logbar .grow{flex:1;min-width:120px} .card h3{margin:0 0 14px;font-size:17px} .field{display:grid;gap:4px;margin-bottom:12px} .field label{font-size:12px;color:var(--dim)} @@ -263,6 +276,7 @@ input[type=range]::-moz-range-thumb{width:12px;height:12px;border:0;border-radiu +
@@ -647,8 +661,78 @@ document.addEventListener('keydown',ev=>{ }); /* ---------------- modals ---------------- */ -function openModal(html){ $('#modalCard').innerHTML=html; $('#modal').classList.add('on'); } -function closeModal(){ $('#modal').classList.remove('on'); } +function openModal(html,wide){ + $('#modalCard').innerHTML=html; + $('#modalCard').classList.toggle('wide',!!wide); + $('#modal').classList.add('on'); +} +function closeModal(){ + $('#modal').classList.remove('on'); + if(logTimer){ clearInterval(logTimer); logTimer=null; } +} + +/* ---------------- log view ---------------- */ +let logTimer=null, logSeq=0, logLines=[], logFilter='', logLevel=''; +const LEVELS={ERROR:3,WARN:2,INFO:1,DEBUG:0,TRACE:0}; + +function logsModal(){ + logSeq=0; logLines=[]; + openModal(`

Log

+
+ + + + + +
+

Loading…

+ Live from the running daemon: feed scans, downloads, torrents and every + HTTP request. Set IPX_LOG=ipx=debug for more detail.`, true); + + $('#loglevel').onchange=e=>{ logLevel=e.target.value; drawLog(); }; + $('#logq').oninput=e=>{ logFilter=e.target.value.toLowerCase(); drawLog(); }; + $('#logcopy').onclick=()=>copyText(visibleLog().map(l=> + `${new Date(l.ts*1000).toISOString()} ${l.level} ${l.target} ${l.msg}`).join('\n'), $('#logcopy')); + + pollLog(); + logTimer=setInterval(pollLog,2000); +} + +async function pollLog(){ + try{ + const r=await api(`/api/logs?after=${logSeq}&limit=500`); + if(r.lines.length){ + logLines=logLines.concat(r.lines).slice(-2000); + logSeq=r.latest; + drawLog(); + }else if(!logLines.length){ drawLog(); } + }catch(e){ + const box=$('#logbox'); + if(box) box.innerHTML=`

Lost contact with the daemon: ${esc(e.message)}

`; + } +} +function visibleLog(){ + const min=logLevel?LEVELS[logLevel]:-1; + return logLines.filter(l=> + (LEVELS[l.level]??1)>=min && + (!logFilter || (l.msg+' '+l.target).toLowerCase().includes(logFilter))); +} +function drawLog(){ + const box=$('#logbox'); if(!box) return; + const follow=$('#logfollow')?.checked; + const rows=visibleLog(); + box.innerHTML = rows.length ? rows.map(l=>{ + const t=new Date(l.ts*1000).toLocaleTimeString(); + return `
${esc(l.level)}`+ + `${esc(l.target.replace(/^ipx::?/,''))}${esc(l.msg)}
`; + }).join('') : '

Nothing matches.

'; + if(follow) box.scrollTop=box.scrollHeight; +} $('#modal').onclick=e=>{ if(e.target.id==='modal') closeModal(); }; $('#addFeed').onclick=()=>{ @@ -842,6 +926,7 @@ function on(sel,ev,fn){ } $('#scanAll').onclick=async()=>{ toast('Scanning all feeds…'); await api('/api/fetch',{method:'POST',body:JSON.stringify({force:true})}); }; on('#prefs','onclick',prefsModal); +on('#logs','onclick',logsModal); $('#feedFilter').oninput=renderFeeds; $('#burger').onclick=()=>$('#sidebar').classList.toggle('open'); $('#theme').onclick=()=>{