ocre/
log.rs

1//! Structured logging to Workers Logs: levels, request-scoped fields, JSON lines (Rails' `Rails.logger` and tagged logging).
2//!
3//! Every [`Ctx`](crate::Ctx) carries a [`Logger`]: in a request it is tagged
4//! with the request's `request_id`, `method` and `path`, so each line of a
5//! request can be found together in the Workers Logs dashboard. Add fields
6//! with [`Logger::with`] (Rails' `logger.tagged`):
7//!
8//! ```no_run
9//! use axum::extract::{Path, State};
10//! use ocre::{Ctx, Result};
11//!
12//! async fn pay(State(ctx): State<Ctx>, Path(order_id): Path<i64>) -> Result<&'static str> {
13//!     let log = ctx.log().with("order_id", order_id);
14//!     log.info("payment started");
15//!     log.debug(format_args!("cart: {:?}", vec![1, 2])); // formatted only when debug is on
16//!     Ok("OK")
17//! }
18//! # let _ = pay;
19//! ```
20//!
21//! # Levels and formats
22//!
23//! Two Worker variables configure logging; they are read on every request,
24//! job batch and cron run (no binding call):
25//!
26//! | Variable | Values | Default in `ocre dev` (debug build) | Default after `ocre deploy` (release build) |
27//! |---|---|---|---|
28//! | [`LOG_LEVEL`] | `debug`, `info`, `warn`, `error`, `off` (`warning`, `fatal` accepted) | `debug` | `info` |
29//! | [`LOG_FORMAT`] | `json`, `text` | `text` | `json` |
30//!
31//! `json` writes each line as a JavaScript object (`{"level": "info",
32//! "message": "...", "request_id": "...", ...}`): Workers Logs indexes every
33//! field, so the dashboard can filter on `$metadata.request_id` or your own
34//! fields. `text` writes `INFO payment started order_id=42 request_id=...`,
35//! easier to read in the `ocre dev` terminal. Lines go to `console.debug`,
36//! `console.info`, `console.warn` or `console.error`, so the level also shows
37//! in the dashboard and in `ocre logs`.
38//!
39//! Field names matching [`FILTERED_PARAMETERS`](crate::security::FILTERED_PARAMETERS)
40//! (`password`, `email`, `token`...) are written as `[FILTERED]`, at any depth.
41//!
42//! # Free plan
43//!
44//! Workers Logs keeps 200,000 events a day for 3 days on the free plan
45//! (September 2026); each request is one event plus one per line logged.
46//! Above that, events are sampled, never billed. `info` in production logs
47//! only what the app asks for; Ocre's own per-request and SQL lines are
48//! `debug`, so they cost nothing after `ocre deploy`. Messages passed as
49//! `format_args!(...)` are only formatted when their level is on.
50
51use std::{
52    fmt::{Display, Write as _},
53    sync::atomic::{AtomicU8, Ordering},
54};
55
56use serde::Serialize;
57use serde_json::{Map, Value};
58
59/// Worker variable setting the lowest level logged: `debug`, `info`, `warn`, `error` or `off`.
60///
61/// Set it in cloudflare.config.ts (`LOG_LEVEL: bindings.text("debug"),`)
62/// or in `.dev.vars`. Unset: `debug` in debug builds (`ocre dev`), `info` in
63/// release builds (`ocre deploy`).
64///
65/// # Examples
66///
67/// ```
68/// assert_eq!(ocre::log::LOG_LEVEL, "LOG_LEVEL");
69/// ```
70pub const LOG_LEVEL: &str = "LOG_LEVEL";
71
72/// Worker variable choosing the line format: `json` or `text`.
73///
74/// Unset: `text` in debug builds (`ocre dev`), `json` in release builds.
75///
76/// # Examples
77///
78/// ```
79/// assert_eq!(ocre::log::LOG_FORMAT, "LOG_FORMAT");
80/// ```
81pub const LOG_FORMAT: &str = "LOG_FORMAT";
82
83/// Severity of a log line (Rails' `:debug`, `:info`, `:warn`, `:error`).
84///
85/// Rails' `:fatal` and `:unknown` are [`Error`](Self::Error) here.
86///
87/// # Examples
88///
89/// ```
90/// use ocre::log::Level;
91///
92/// assert!(Level::Debug < Level::Error);
93/// assert_eq!(Level::parse("WARNING"), Some(Level::Warn));
94/// assert_eq!(Level::Info.as_str(), "info");
95/// ```
96#[derive(Debug, Clone, Copy, PartialEq, Eq, PartialOrd, Ord, Hash)]
97pub enum Level {
98    /// Details for development: SQL statements, request summaries.
99    Debug,
100    /// Normal events worth keeping in production.
101    Info,
102    /// Something unexpected that the app handled.
103    Warn,
104    /// A failure: internal errors, failed jobs.
105    Error,
106}
107
108impl Level {
109    /// Reads a level name, case-insensitively: `debug`, `info`, `warn` (`warning`), `error` (`fatal`, `unknown`).
110    ///
111    /// # Examples
112    ///
113    /// ```
114    /// use ocre::log::Level;
115    ///
116    /// assert_eq!(Level::parse("fatal"), Some(Level::Error));
117    /// assert_eq!(Level::parse("loud"), None);
118    /// ```
119    pub fn parse(name: &str) -> Option<Self> {
120        match name.trim().to_ascii_lowercase().as_str() {
121            "debug" => Some(Self::Debug),
122            "info" => Some(Self::Info),
123            "warn" | "warning" => Some(Self::Warn),
124            "error" | "fatal" | "unknown" => Some(Self::Error),
125            _ => None,
126        }
127    }
128
129    /// The lowercase name written in log lines: `debug`, `info`, `warn`, `error`.
130    ///
131    /// # Examples
132    ///
133    /// ```
134    /// assert_eq!(ocre::log::Level::Warn.as_str(), "warn");
135    /// ```
136    pub fn as_str(self) -> &'static str {
137        match self {
138            Self::Debug => "debug",
139            Self::Info => "info",
140            Self::Warn => "warn",
141            Self::Error => "error",
142        }
143    }
144}
145
146/// How log lines are written: see the [module documentation](self).
147///
148/// # Examples
149///
150/// ```
151/// use ocre::log::Format;
152///
153/// assert_eq!(Format::parse("JSON"), Some(Format::Json));
154/// assert_eq!(Format::parse("pretty"), Some(Format::Text));
155/// ```
156#[derive(Debug, Clone, Copy, PartialEq, Eq)]
157pub enum Format {
158    /// One JavaScript object per line, indexed by Workers Logs.
159    Json,
160    /// `LEVEL message key=value ...`, for the terminal.
161    Text,
162}
163
164impl Format {
165    /// Reads a format name: `json`, or `text` (`pretty` and `compact` accepted, like Loco).
166    ///
167    /// # Examples
168    ///
169    /// ```
170    /// assert_eq!(ocre::log::Format::parse("yaml"), None);
171    /// ```
172    pub fn parse(name: &str) -> Option<Self> {
173        match name.trim().to_ascii_lowercase().as_str() {
174            "json" => Some(Self::Json),
175            "text" | "pretty" | "compact" => Some(Self::Text),
176            _ => None,
177        }
178    }
179}
180
181/// Current settings: 0 = not configured yet; else `1 + threshold * 2 + json`,
182/// where threshold 4 means `off`.
183static SETTINGS: AtomicU8 = AtomicU8::new(0);
184const OFF: u8 = 4;
185
186/// Applies the [`LOG_LEVEL`] and [`LOG_FORMAT`] values of the Worker
187/// (`None` or an unknown value: the build's default). Called by `Ctx::new`.
188pub(crate) fn configure(level: Option<&str>, format: Option<&str>) {
189    let threshold = match level.map(|name| name.trim().to_ascii_lowercase()) {
190        Some(name) if name == "off" || name == "none" => OFF,
191        Some(name) => Level::parse(&name).unwrap_or_else(default_level) as u8,
192        None => default_level() as u8,
193    };
194    let json = format.and_then(Format::parse).unwrap_or_else(default_format) == Format::Json;
195    SETTINGS.store(1 + threshold * 2 + u8::from(json), Ordering::Relaxed);
196}
197
198fn default_level() -> Level {
199    if cfg!(debug_assertions) { Level::Debug } else { Level::Info }
200}
201
202fn default_format() -> Format {
203    if cfg!(debug_assertions) { Format::Text } else { Format::Json }
204}
205
206fn settings() -> (u8, Format) {
207    match SETTINGS.load(Ordering::Relaxed) {
208        0 => (default_level() as u8, default_format()),
209        packed => ((packed - 1) / 2, if (packed - 1) % 2 == 1 { Format::Json } else { Format::Text }),
210    }
211}
212
213/// Writes log lines with a set of fields; cheap to clone (see the [module documentation](self)).
214///
215/// [`Ctx::log`](crate::Ctx::log) gives the request's logger; code without a
216/// `Ctx` uses [`Logger::new`].
217///
218/// # Examples
219///
220/// ```
221/// use ocre::log::{Format, Level, Logger};
222///
223/// let log = Logger::new().with("order_id", 42).with("password", "hunter2");
224/// log.info("paid"); // written to the Worker logs
225/// assert_eq!(
226///     log.line(Level::Info, "paid", Format::Json),
227///     r#"{"level":"info","message":"paid","order_id":42,"password":"[FILTERED]"}"#
228/// );
229/// assert_eq!(log.line(Level::Warn, "slow", Format::Text), "WARN slow order_id=42 password=[FILTERED]");
230/// ```
231#[derive(Debug, Clone, Default)]
232pub struct Logger {
233    fields: Map<String, Value>,
234}
235
236impl Logger {
237    /// A logger without fields.
238    ///
239    /// # Examples
240    ///
241    /// ```
242    /// ocre::log::Logger::new().warn("cache miss");
243    /// ```
244    pub fn new() -> Self {
245        Self::default()
246    }
247
248    /// A copy of this logger with one more field on every line (Rails' `logger.tagged`).
249    ///
250    /// Any serializable value; a value that does not serialize is written
251    /// as `null`. A field with the same name is replaced.
252    ///
253    /// # Examples
254    ///
255    /// ```
256    /// let log = ocre::log::Logger::new().with("user_id", 7);
257    /// assert_eq!(log.field("user_id"), Some(&serde_json::json!(7)));
258    /// ```
259    pub fn with(&self, key: &str, value: impl Serialize) -> Self {
260        let mut logger = self.clone();
261        logger.fields.insert(key.to_owned(), serde_json::to_value(value).unwrap_or(Value::Null));
262        logger
263    }
264
265    /// The value of a field, e.g. `request_id`.
266    ///
267    /// # Examples
268    ///
269    /// ```
270    /// assert_eq!(ocre::log::Logger::new().field("request_id"), None);
271    /// ```
272    pub fn field(&self, key: &str) -> Option<&Value> {
273        self.fields.get(key)
274    }
275
276    /// Whether lines of `level` are written, under the current [`LOG_LEVEL`].
277    ///
278    /// Check it before building an expensive message that is not
279    /// `format_args!(...)` (Rails' block form of `logger.debug { ... }`).
280    ///
281    /// # Examples
282    ///
283    /// ```
284    /// let log = ocre::log::Logger::new();
285    /// if log.enabled(ocre::log::Level::Debug) {
286    ///     log.debug(serde_json::json!({"big": [1, 2, 3]}));
287    /// }
288    /// ```
289    pub fn enabled(&self, level: Level) -> bool {
290        level as u8 >= settings().0
291    }
292
293    /// Writes a `debug` line.
294    ///
295    /// # Examples
296    ///
297    /// ```
298    /// let rows = 3;
299    /// ocre::log::Logger::new().debug(format_args!("{rows} rows"));
300    /// ```
301    pub fn debug(&self, message: impl Display) {
302        self.log(Level::Debug, &message);
303    }
304
305    /// Writes an `info` line.
306    ///
307    /// # Examples
308    ///
309    /// ```
310    /// ocre::log::Logger::new().info("signed up");
311    /// ```
312    pub fn info(&self, message: impl Display) {
313        self.log(Level::Info, &message);
314    }
315
316    /// Writes a `warn` line.
317    ///
318    /// # Examples
319    ///
320    /// ```
321    /// ocre::log::Logger::new().warn("retrying");
322    /// ```
323    pub fn warn(&self, message: impl Display) {
324        self.log(Level::Warn, &message);
325    }
326
327    /// Writes an `error` line.
328    ///
329    /// # Examples
330    ///
331    /// ```
332    /// ocre::log::Logger::new().error("payment provider down");
333    /// ```
334    pub fn error(&self, message: impl Display) {
335        self.log(Level::Error, &message);
336    }
337
338    /// Writes a line of `level` when it is enabled; the message is formatted only then.
339    ///
340    /// # Examples
341    ///
342    /// ```
343    /// ocre::log::Logger::new().log(ocre::log::Level::Info, &"hello");
344    /// ```
345    pub fn log(&self, level: Level, message: &dyn Display) {
346        if !self.enabled(level) {
347            return;
348        }
349        let format = settings().1;
350        emit(level, format, &self.line(level, &message.to_string(), format));
351    }
352
353    /// The line [`log`](Self::log) writes, whatever the current level: JSON or text.
354    ///
355    /// # Examples
356    ///
357    /// ```
358    /// use ocre::log::{Format, Level, Logger};
359    ///
360    /// let line = Logger::new().with("path", "/a b").line(Level::Error, "boom", Format::Text);
361    /// assert_eq!(line, r#"ERROR boom path="/a b""#);
362    /// ```
363    pub fn line(&self, level: Level, message: &str, format: Format) -> String {
364        let fields = crate::security::filter_json(&Value::Object(self.fields.clone()));
365        let Value::Object(fields) = fields else { unreachable!("filtering keeps an object") };
366        match format {
367            Format::Json => {
368                let mut line = Map::with_capacity(fields.len() + 2);
369                line.insert("level".to_owned(), level.as_str().into());
370                line.insert("message".to_owned(), message.into());
371                line.extend(fields);
372                Value::Object(line).to_string()
373            }
374            Format::Text => {
375                let mut line = format!("{} {message}", level.as_str().to_ascii_uppercase());
376                for (key, value) in fields {
377                    let _ = write!(line, " {key}={}", text_value(&value));
378                }
379                line
380            }
381        }
382    }
383}
384
385/// Strings bare unless they contain spaces, quotes or `=`; other values as JSON.
386fn text_value(value: &Value) -> String {
387    match value {
388        Value::String(text) if !text.is_empty() && !text.contains([' ', '"', '=']) => text.clone(),
389        other => other.to_string(),
390    }
391}
392
393/// `panicked at src/lib.rs:12:5: <message>`: the line the panic hook logs.
394pub(crate) fn panic_line(message: &str, location: Option<(&str, u32, u32)>) -> String {
395    match location {
396        Some((file, line, column)) => format!("panicked at {file}:{line}:{column}: {message}"),
397        None => format!("panicked: {message}"),
398    }
399}
400
401/// Worker logs: `console.<level>` with a JavaScript object for JSON lines;
402/// stderr in native builds (unit tests).
403fn emit(level: Level, format: Format, line: &str) {
404    #[cfg(target_arch = "wasm32")]
405    {
406        use worker::wasm_bindgen::JsValue;
407        let value = match format {
408            Format::Json => js_sys::JSON::parse(line).unwrap_or_else(|_| JsValue::from_str(line)),
409            Format::Text => JsValue::from_str(line),
410        };
411        let console = match level {
412            Level::Debug => worker::web_sys::console::debug_1,
413            Level::Info => worker::web_sys::console::info_1,
414            Level::Warn => worker::web_sys::console::warn_1,
415            Level::Error => worker::web_sys::console::error_1,
416        };
417        console(&value);
418    }
419    #[cfg(not(target_arch = "wasm32"))]
420    {
421        let _ = (level, format);
422        eprintln!("{line}");
423    }
424}
425
426#[cfg(test)]
427#[path = "../tests/log.rs"]
428mod tests;
ocre/log.rs

ocre/
log.rs
