mercury-platform-core 4.12.14

Rust port of mercury-composable platform-core — the event-driven foundation layer
Documentation
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
232
233
234
235
236
237
238
239
240
241
242
243
244
245
246
247
248
249
250
251
252
253
254
255
256
257
258
259
260
261
262
263
264
265
266
267
268
269
270
271
272
273
274
275
276
277
278
279
280
281
282
283
284
285
286
287
288
289
290
291
292
293
294
295
296
297
298
299
300
301
302
303
304
305
306
307
308
309
310
311
312
313
314
315
316
317
318
319
320
321
322
323
324
325
326
327
328
329
330
331
332
333
334
335
336
337
338
339
340
341
342
343
344
345
346
347
348
349
350
351
352
353
354
355
356
357
358
359
360
361
362
363
364
365
366
367
368
369
370
371
372
373
374
375
376
377
378
379
380
381
382
383
384
385
386
387
388
389
390
391
392
393
394
395
396
397
398
399
400
401
402
403
404
405
406
407
408
409
410
411
412
413
414
415
416
417
418
419
420
421
422
423
424
425
426
427
428
429
430
431
432
433
434
435
436
437
438
439
440
441
442
443
444
445
446
447
448
449
450
451
452
453
454
455
456
457
458
459
460
461
462
463
464
465
466
467
468
469
470
471
472
473
474
475
476
477
478
479
480
481
482
483
484
485
486
487
488
489
490
491
492
493
494
495
496
497
498
499
500
501
502
503
504
505
506
507
//
// Copyright 2018-2026 Accenture Technology
//
// Licensed under the Apache License, Version 2.0 (the "License");
// you may not use this file except in compliance with the License.
// You may obtain a copy of the License at
//
//     http://www.apache.org/licenses/LICENSE-2.0
//
// Unless required by applicable law or agreed to in writing, software
// distributed under the License is distributed on an "AS IS" BASIS,
// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
// See the License for the specific language governing permissions and
// limitations under the License.
//

//! Structured logging with the **application log context** — Rust port of the
//! Java `LogContextConfig` + `JsonLogger`/`CompactAppender` design
//! (`org.platformlambda.core.logging`).
//!
//! Spans tell you the causal path; application logs tell you what happened
//! inside each step. The log-context feature is **on by default**: the crate
//! ships a built-in `default-log-context.yaml` (embedded at compile time)
//! carrying the standard trace context, so every structured (JSON) log line
//! emitted inside a traced function carries a `context` block — correlation
//! id, trace/span ids, service name, and any business key-values added via
//! `PostOffice::update_context` — with zero setup. An application replaces
//! the template with its own **`app-log-context.yaml`** on the resource path,
//! or opts out entirely with `app.log.context=false` (default `true`).
//!
//! The template maps an output key (your choice) to one of three forms:
//! a reserved **`$token`** (`$cid`, `$traceId`, `$tracePath`, `$spanId`,
//! `$parentSpanId`, `$service`, `$utc` — resolved live per log line), a
//! **`${ENV:default}`** substitution (resolved once at load, via the standard
//! `ConfigReader`), or a **literal**. A key that resolves to nothing is
//! omitted, never printed as null.
//!
//! [`init`] installs the process logger with three formats (the log4j2
//! appender-selection analog): the default **`text`** is a plain console line
//! and — like Java's plain `Console` appender — is unaffected by the log
//! context; **`json`** pretty-prints each record (Java `log4j2-json.xml`);
//! **`compact`** emits single-line jsonl records, no CR/LF (Java
//! `log4j2-compact.xml`). `-Dkey=value` runtime arguments (the JVM `-D`
//! analog) are honored, so `-Dlog.format=json` switches at launch without
//! editing configuration. Deliberate simplifications (doc'd): UTC timestamps,
//! no thread id.

use std::sync::OnceLock;

use crate::trace;
use crate::util::app_config_reader::AppConfigReader;
use crate::util::config_reader::{ConfigError, ConfigReader};

const CONFIG_FILE: &str = "classpath:/app-log-context.yaml";
/// The built-in default template (Java `default-log-context.yaml`), shipped
/// under a DISTINCT file name from the application override. Java keeps the
/// two names apart because same-named classpath resources shadow in
/// classloader order; this port embeds the default at compile time — the
/// same defensive design, enforced by the compiler.
const DEFAULT_TEMPLATE: &str = include_str!("../resources/default-log-context.yaml");
/// Feature switch (Java `app.log.context`), default `true`.
const FEATURE_FLAG: &str = "app.log.context";
const CONTEXT: &str = "context";

/// Parsed log-context template (Java `LogContextConfig`) — the application's
/// `app-log-context.yaml` when present, otherwise the built-in default.
pub struct LogContextConfig {
    enabled: bool,
    /// output key → reserved token name (without the `$`), resolved per line
    tokens: Vec<(String, String)>,
    /// output key → constant (env-resolved or literal), fixed at load
    constants: Vec<(String, String)>,
}

impl LogContextConfig {
    /// The lazily-loaded singleton; touching [`AppConfigReader`] first
    /// guarantees `${ENV:default}` substitution works regardless of timing
    /// (Java parity).
    pub fn instance() -> &'static LogContextConfig {
        static INSTANCE: OnceLock<LogContextConfig> = OnceLock::new();
        INSTANCE.get_or_init(Self::load_config_file)
    }

    /// Resolve the template with the Java `LogContextConfig.loadConfigFile`
    /// order: the `app.log.context` switch (default on) → the application's
    /// own `app-log-context.yaml` (replaces the template entirely) → the
    /// built-in default, so the feature is on out of the box.
    fn load_config_file() -> LogContextConfig {
        let config = AppConfigReader::get_instance();
        if config.get_property_or(FEATURE_FLAG, "true") == "false" {
            log::info!("Application log context disabled by {FEATURE_FLAG}=false");
            return LogContextConfig::disabled();
        }
        match ConfigReader::load(CONFIG_FILE) {
            Ok(reader) => LogContextConfig::from_reader(&reader),
            Err(ConfigError::NotFound(_)) => {
                // no application override — fall back to the built-in default
                match ConfigReader::from_yaml_text(DEFAULT_TEMPLATE) {
                    Ok(reader) => LogContextConfig::from_reader(&reader),
                    Err(e) => {
                        log::warn!("Built-in default-log-context.yaml invalid - {e}");
                        LogContextConfig::disabled()
                    }
                }
            }
            Err(e) => {
                log::error!("Unable to load {CONFIG_FILE} - {e}");
                LogContextConfig::disabled()
            }
        }
    }

    fn disabled() -> Self {
        LogContextConfig {
            enabled: false,
            tokens: Vec::new(),
            constants: Vec::new(),
        }
    }

    /// Build a config from a loaded reader. Public so tests and tooling can
    /// exercise the enabled/disabled paths deterministically (the Java
    /// package-private constructor's analog).
    pub fn from_reader(reader: &ConfigReader) -> Self {
        let mut tokens = Vec::new();
        let mut constants = Vec::new();
        let section: Vec<String> = match reader.get_map().get_element(CONTEXT) {
            Some(crate::ConfigValue::Map(m)) => m.keys().cloned().collect(),
            _ => {
                log::warn!("Log context config has no '{CONTEXT}' section - feature disabled");
                return LogContextConfig::disabled();
            }
        };
        for output_key in section {
            // ConfigReader resolves ${ENV:default} on the leaf value; an unset
            // ${VAR} with no default resolves to nothing and is dropped
            let Some(value) = reader.get_property(&format!("{CONTEXT}.{output_key}")) else {
                continue;
            };
            if let Some(token_name) = value.strip_prefix('$').filter(|_| !value.starts_with("${")) {
                if trace::RESERVED_KEYS.contains(&token_name) {
                    tokens.push((output_key, token_name.to_string()));
                } else {
                    // Java throws here; the Rust port stays advisory —
                    // report and skip (deliberate divergence)
                    log::error!(
                        "Invalid log context token '{value}' for key '{output_key}' - allowed: {:?}",
                        trace::RESERVED_KEYS
                    );
                }
            } else {
                constants.push((output_key, value));
            }
        }
        let enabled = !tokens.is_empty() || !constants.is_empty();
        if enabled {
            // Java 4.12.13: the context block always carries a machine-parseable
            // UTC time - the record's top-level `time` is what the operator's
            // zone renders, and log-to-trace correlation resolves on a time
            // window, so a line parsed in the wrong zone can be correctly
            // correlated and still invisible on its trace. When the template
            // maps `$utc` to no key, insert it as `timestamp` (falling back to
            // `utc` if `timestamp` is taken, and leaving the template alone with
            // a warning if both are)
            if !tokens.iter().any(|(_, token)| token == "utc") {
                let taken = |key: &str| {
                    tokens.iter().any(|(k, _)| k == key) || constants.iter().any(|(k, _)| k == key)
                };
                if !taken("timestamp") {
                    tokens.push(("timestamp".to_string(), "utc".to_string()));
                } else if !taken("utc") {
                    tokens.push(("utc".to_string(), "utc".to_string()));
                } else {
                    log::warn!(
                        "Log context template maps $utc to no key and both 'timestamp' and 'utc' \
                         are taken - no UTC timestamp is added to the context block"
                    );
                }
            }
            log::info!(
                "Application log context enabled with {} context key-value(s)",
                tokens.len() + constants.len()
            );
        }
        LogContextConfig {
            enabled,
            tokens,
            constants,
        }
    }

    pub fn is_enabled(&self) -> bool {
        self.enabled
    }

    /// Build the context block for one log line (Java `render`): reserved
    /// tokens resolved live, constants, then the developer's custom keys.
    /// Keys resolving to nothing are omitted.
    ///
    /// `state` is the current trace bracket — the context block exists ONLY
    /// for a log line emitted inside a traced function execution with a real
    /// request trace (Java parity: the log context is registered per worker
    /// execution in lockstep with the trace bracket; framework, system and
    /// telemetry lines carry no context at all, not even the constants).
    pub fn render(
        &self,
        state: &trace::TraceState,
        log_time: std::time::SystemTime,
    ) -> serde_json::Map<String, serde_json::Value> {
        let mut out = serde_json::Map::new();
        // developer keys render first, so a template key can never be shadowed
        // by `update_context` - the template wins (Java 4.12.13)
        for (key, value) in &state.custom_log_keys {
            if !value.is_null() {
                out.insert(key.clone(), value.clone());
            }
        }
        for (output_key, token_name) in &self.tokens {
            if let Some(value) = state.token(token_name, log_time) {
                out.insert(output_key.clone(), value);
            }
        }
        for (output_key, constant) in &self.constants {
            out.insert(
                output_key.clone(),
                serde_json::Value::String(constant.clone()),
            );
        }
        out
    }
}

/// The three output formats (the log4j2 appender-selection analog):
/// `text` = the default plain console line (context-free, like Java's plain
/// `Console` appender); `json` = pretty-print JSON (Java `log4j2-json.xml`);
/// `compact` = single-line jsonl, no CR/LF within a record (Java
/// `log4j2-compact.xml`). Both JSON forms carry the `context` block.
#[derive(Clone, Copy, PartialEq)]
enum LogFormat {
    Text,
    Json,
    Compact,
}

impl LogFormat {
    fn resolve(name: &str) -> LogFormat {
        match name.to_ascii_lowercase().as_str() {
            "json" => LogFormat::Json,
            "compact" => LogFormat::Compact,
            _ => LogFormat::Text,
        }
    }
}

/// The process logger (the log4j2 appenders' analog).
struct PlatformLogger {
    format: LogFormat,
    level: log::LevelFilter,
}

impl log::Log for PlatformLogger {
    fn enabled(&self, metadata: &log::Metadata) -> bool {
        metadata.level() <= self.level
    }

    fn log(&self, record: &log::Record) {
        if !self.enabled(record.metadata()) {
            return;
        }
        let now = std::time::SystemTime::now();
        let time = trace::iso8601_utc(now);
        if self.format == LogFormat::Text {
            println!(
                "{time} {:<5} [{}] {}",
                record.level(),
                record.module_path().unwrap_or("unknown"),
                record.args()
            );
            return;
        }
        let mut line = serde_json::Map::new();
        line.insert("time".into(), serde_json::Value::String(time));
        line.insert(
            "level".into(),
            serde_json::Value::String(record.level().to_string()),
        );
        line.insert(
            "source".into(),
            serde_json::Value::String(format!(
                "{}({}:{})",
                record.module_path().unwrap_or("unknown"),
                record.file().unwrap_or("?"),
                record.line().unwrap_or(0)
            )),
        );
        let message = record.args().to_string();
        // a message that is itself JSON embeds as a structured object
        // (Java JsonLogger's ObjectMessage handling — the telemetry
        // dataset renders structured, not as an escaped string)
        let message_value = if message.starts_with('{') {
            serde_json::from_str::<serde_json::Value>(&message)
                .unwrap_or(serde_json::Value::String(message))
        } else {
            serde_json::Value::String(message)
        };
        line.insert("message".into(), message_value);
        // the application log context: ONLY inside a traced worker with a
        // real request trace (Java parity — the context registers per worker
        // execution in lockstep with the trace bracket; a zero-traced route
        // registers none). Framework/system/telemetry lines carry no context
        // block at all — constants never leak onto context-less lines.
        let config = LogContextConfig::instance();
        if config.is_enabled() {
            let context = trace::with_current(|state| {
                if state.zero_traced {
                    None
                } else {
                    Some(config.render(state, now))
                }
            })
            .flatten();
            if let Some(context) = context {
                if !context.is_empty() {
                    line.insert("context".into(), serde_json::Value::Object(context));
                }
            }
        }
        let line = serde_json::Value::Object(line);
        match self.format {
            // pretty-print JSON, one record over multiple lines
            LogFormat::Json => println!(
                "{}",
                serde_json::to_string_pretty(&line).unwrap_or_else(|_| line.to_string())
            ),
            // compact jsonl: one record per line, no CR/LF within a record
            _ => println!("{line}"),
        }
    }

    fn flush(&self) {}
}

/// Install the process logger, reading `log.format` (`text` | `json` |
/// `compact`, default `text`) and `log.level` (default `info`; `RUST_LOG` env
/// wins) from the application configuration. `-Dkey=value` runtime arguments
/// (the JVM `-D` analog) are loaded into the override registry first, so
/// `hello_world -- -Dlog.format=json` switches format at launch. Idempotent —
/// a second call is a no-op (the `log` crate accepts one logger per process).
pub fn init() {
    // runtime -D overrides win over configuration files (System.getProperty parity)
    crate::util::overrides::load_runtime_args();
    let config = AppConfigReader::get_instance();
    let format = LogFormat::resolve(&config.get_property_or("log.format", "text"));
    let level_text = std::env::var("RUST_LOG")
        .ok()
        .unwrap_or_else(|| config.get_property_or("log.level", "info"));
    let level = match level_text.to_ascii_lowercase().as_str() {
        "error" => log::LevelFilter::Error,
        "warn" => log::LevelFilter::Warn,
        "debug" => log::LevelFilter::Debug,
        "trace" => log::LevelFilter::Trace,
        "off" => log::LevelFilter::Off,
        _ => log::LevelFilter::Info,
    };
    // initialize the log-context template BEFORE installing the logger: the
    // JSON logger consults it on every line, and letting the first log line
    // trigger the lazy init would re-enter the OnceLock from inside its own
    // initializer (the config logs while loading) — a deadlock
    let context = LogContextConfig::instance();
    if log::set_boxed_logger(Box::new(PlatformLogger { format, level })).is_ok() {
        log::set_max_level(level);
        if context.is_enabled() {
            log::info!(
                "Application log context enabled with {} context key-value(s)",
                context.tokens.len() + context.constants.len()
            );
        }
    }
}

#[cfg(test)]
mod tests {
    use super::*;

    #[test]
    fn format_resolution() {
        assert!(matches!(LogFormat::resolve("json"), LogFormat::Json));
        assert!(matches!(LogFormat::resolve("JSON"), LogFormat::Json));
        assert!(matches!(LogFormat::resolve("compact"), LogFormat::Compact));
        assert!(matches!(LogFormat::resolve("text"), LogFormat::Text));
        assert!(matches!(LogFormat::resolve("unknown"), LogFormat::Text)); // safe default
    }

    /// One sequential test for the three `load_config_file` outcomes — the
    /// resolution reads process-global state (overrides, resource roots), so
    /// the cases must not run as parallel tests.
    #[test]
    fn log_context_is_on_by_default_overridable_and_can_opt_out() {
        // 1. DEFAULT-ON: no app-log-context.yaml on the resource path (this
        // crate's own resources/ has none) → the built-in default template
        // enables the feature with the standard trace-context keys
        let config = LogContextConfig::load_config_file();
        assert!(config.is_enabled(), "log context must be ON by default");
        let token_keys: Vec<&str> = config.tokens.iter().map(|(k, _)| k.as_str()).collect();
        for expected in [
            "cid",
            "trace_id",
            "trace_path",
            "span_id",
            "parent_span_id",
            "service",
            "timestamp",
        ] {
            assert!(
                token_keys.contains(&expected),
                "built-in template must carry '{expected}'"
            );
        }
        assert!(
            config.constants.is_empty(),
            "built-in default has no constants"
        );

        // 2. OPT-OUT: app.log.context=false disables the feature entirely
        crate::util::overrides::set(FEATURE_FLAG, "false");
        let config = LogContextConfig::load_config_file();
        crate::util::overrides::clear(FEATURE_FLAG);
        assert!(!config.is_enabled(), "app.log.context=false must opt out");

        // 3. APP FILE OVERRIDES: an app-log-context.yaml on the resource path
        // REPLACES the built-in template entirely (no merge)
        let dir = std::env::temp_dir().join(format!("pc-logctx-default-{}", std::process::id()));
        std::fs::create_dir_all(&dir).unwrap();
        std::fs::write(
            dir.join("app-log-context.yaml"),
            "context:\n  onlyKey: $service\n",
        )
        .unwrap();
        crate::util::resources::prepend_resource_root(&dir);
        let config = LogContextConfig::load_config_file();
        assert!(config.is_enabled());
        assert_eq!(
            config.tokens,
            vec![
                ("onlyKey".to_string(), "service".to_string()),
                // the engine supplies the UTC timestamp when the template maps $utc to no key
                ("timestamp".to_string(), "utc".to_string()),
            ],
            "the application template must replace the built-in default entirely"
        );
        std::fs::remove_dir_all(&dir).ok();
    }

    /// The automatic UTC timestamp: inserted as `timestamp`, falling back to
    /// `utc` when `timestamp` is taken, and left out with a warning when both
    /// are; an explicit `$utc` mapping is kept as authored (no duplicate).
    #[test]
    fn utc_timestamp_is_supplied_when_the_template_omits_it() {
        let reader = |text: &str| ConfigReader::from_yaml_text(text).expect("yaml");
        let inserted = LogContextConfig::from_reader(&reader("context:\n  svc: $service\n"));
        assert!(inserted
            .tokens
            .contains(&("timestamp".to_string(), "utc".to_string())));
        let explicit =
            LogContextConfig::from_reader(&reader("context:\n  when: $utc\n  svc: $service\n"));
        assert_eq!(
            1,
            explicit.tokens.iter().filter(|(_, t)| t == "utc").count()
        );
        assert!(explicit
            .tokens
            .contains(&("when".to_string(), "utc".to_string())));
        let fallback = LogContextConfig::from_reader(&reader("context:\n  timestamp: $service\n"));
        assert!(fallback
            .tokens
            .contains(&("utc".to_string(), "utc".to_string())));
        let both_taken = LogContextConfig::from_reader(&reader(
            "context:\n  timestamp: $service\n  utc: hello\n",
        ));
        assert!(!both_taken.tokens.iter().any(|(_, t)| t == "utc"));
    }

    /// Developer keys render first and the template wins, so a business key
    /// can never shadow a template key.
    #[test]
    fn template_keys_win_over_developer_keys() {
        let config = LogContextConfig::from_reader(
            &ConfigReader::from_yaml_text("context:\n  service: $service\n  env: dev\n")
                .expect("yaml"),
        );
        let mut state = trace::TraceState::new("greeting.demo", "t1", "GET /x", None, None);
        state
            .custom_log_keys
            .insert("service".to_string(), serde_json::json!("shadow"));
        state
            .custom_log_keys
            .insert("env".to_string(), serde_json::json!("shadow"));
        state
            .custom_log_keys
            .insert("user".to_string(), serde_json::json!("eric"));
        let out = config.render(&state, std::time::SystemTime::now());
        assert_eq!("greeting.demo", out["service"]);
        assert_eq!("dev", out["env"]);
        assert_eq!("eric", out["user"]);
        assert!(out.contains_key("timestamp"), "the automatic UTC timestamp");
    }
}