1use std::{
2 env, fmt,
3 io::{self, BufWriter, Write},
4 panic::{self, PanicHookInfo},
5 process,
6 sync::{
7 Arc, Once, OnceLock,
8 atomic::{AtomicBool, AtomicU64, Ordering},
9 },
10 thread,
11 time::{Duration, Instant, SystemTime, UNIX_EPOCH},
12};
13
14use crossbeam_channel::{Receiver, Sender, TrySendError};
15use tracing::{
16 Event, Level, Metadata, Subscriber,
17 field::{Field, Visit},
18};
19use tracing_subscriber::{
20 fmt::{FmtContext, FormatEvent, FormatFields, MakeWriter, format::Writer},
21 registry::LookupSpan,
22};
23
24use crate::{Controller, HttpException, Module, RouteDef};
25
26const RESET: &str = "\x1b[0m";
27const BRAND: &str = "\x1b[38;5;45m";
28const PID: &str = "\x1b[38;5;141m";
29const TIME: &str = "\x1b[38;5;245m";
30const CONTEXT: &str = "\x1b[38;5;111m";
31const INFO: &str = "\x1b[38;5;39m";
32const WARN: &str = "\x1b[38;5;214m";
33const ERROR: &str = "\x1b[38;5;203m";
34const DEBUG: &str = "\x1b[38;5;177m";
35const OK_STATUS: &str = "\x1b[38;5;82m";
36const ACCESS_LOG_QUEUE_CAPACITY: usize = 65_536;
37const ACCESS_LOG_BATCH_SIZE: usize = 1_024;
38const ACCESS_LOG_FLUSH_INTERVAL: Duration = Duration::from_millis(100);
39const ACCESS_LOG_DROP_REPORT_INTERVAL: Duration = Duration::from_secs(1);
40
41static TRACING_INIT: Once = Once::new();
42static PANIC_HOOK_INIT: Once = Once::new();
43static LOG_PRIORITY: OnceLock<u8> = OnceLock::new();
44static HTTP_REQUEST_LOGGING: OnceLock<bool> = OnceLock::new();
45static CAELIX_TRACING_SUBSCRIBER: AtomicBool = AtomicBool::new(false);
46static ACCESS_LOG_WRITER: OnceLock<AccessLogWriter> = OnceLock::new();
47
48#[derive(Clone, Copy, Debug, Eq, PartialEq)]
49pub enum LogLevel {
50 Info,
51 Log,
52 Warn,
53 Error,
54 Debug,
55}
56
57impl LogLevel {
58 fn label(self) -> &'static str {
59 match self {
60 Self::Info | Self::Log => "INFO",
61 Self::Warn => "WARN",
62 Self::Error => "ERROR",
63 Self::Debug => "DEBUG",
64 }
65 }
66
67 fn color(self) -> &'static str {
68 match self {
69 Self::Info | Self::Log => INFO,
70 Self::Warn => WARN,
71 Self::Error => ERROR,
72 Self::Debug => DEBUG,
73 }
74 }
75
76 fn priority(self) -> u8 {
77 match self {
78 Self::Error => 1,
79 Self::Warn => 2,
80 Self::Info | Self::Log => 3,
81 Self::Debug => 4,
82 }
83 }
84}
85
86#[derive(Clone, Debug)]
87pub struct Logger {
88 context: String,
89}
90
91impl Logger {
92 pub fn new(context: impl Into<String>) -> Self {
93 Self {
94 context: short_type_name(&context.into()).to_string(),
95 }
96 }
97
98 pub fn for_type<T: ?Sized>() -> Self {
99 Self::new(std::any::type_name::<T>())
100 }
101
102 pub fn context(&self) -> &str {
103 &self.context
104 }
105
106 pub fn info(&self, message: impl AsRef<str>) {
107 self.write(LogLevel::Info, message, None);
108 }
109
110 pub fn warn(&self, message: impl AsRef<str>) {
111 self.write(LogLevel::Warn, message, None);
112 }
113
114 pub fn error(&self, message: impl AsRef<str>) {
115 self.write(LogLevel::Error, message, None);
116 }
117
118 pub fn debug(&self, message: impl AsRef<str>) {
119 self.write(LogLevel::Debug, message, None);
120 }
121
122 pub(crate) fn write(
123 &self,
124 level: LogLevel,
125 message: impl AsRef<str>,
126 elapsed: Option<Duration>,
127 ) {
128 self.write_inner(level, message, elapsed, false);
129 }
130
131 fn write_forced(&self, level: LogLevel, message: impl AsRef<str>) {
132 self.write_inner(level, message, None, true);
133 }
134
135 fn write_inner(
136 &self,
137 level: LogLevel,
138 message: impl AsRef<str>,
139 elapsed: Option<Duration>,
140 force: bool,
141 ) {
142 if !force && !log_level_enabled(level) {
143 return;
144 }
145
146 init_logging();
147
148 let line = format_log_line(&self.context, level, message.as_ref(), elapsed);
149
150 match level {
151 LogLevel::Info | LogLevel::Log => {
152 tracing::info!(target: "caelix", message = line.as_str())
153 }
154 LogLevel::Warn => tracing::warn!(target: "caelix", message = line.as_str()),
155 LogLevel::Error => tracing::error!(target: "caelix", message = line.as_str()),
156 LogLevel::Debug => tracing::debug!(target: "caelix", message = line.as_str()),
157 }
158 }
159}
160
161fn format_log_line(
162 context: &str,
163 level: LogLevel,
164 message: &str,
165 elapsed: Option<Duration>,
166) -> String {
167 let pid = process::id();
168 let timestamp = current_timestamp();
169 let level_label = format!("{:>5}", level.label());
170 let elapsed = elapsed
171 .map(|duration| format!(" {}", format_elapsed(duration)))
172 .unwrap_or_default();
173 let message = match level {
174 LogLevel::Error => format!("{}{}{}", ERROR, message, RESET),
175 _ => message.to_string(),
176 };
177
178 format!(
179 "{}[Caelix]{} {}{}{} - {}{}{} {}{}{} {}[{}]{} {}{}",
180 BRAND,
181 RESET,
182 PID,
183 pid,
184 RESET,
185 TIME,
186 timestamp,
187 RESET,
188 level.color(),
189 level_label,
190 RESET,
191 CONTEXT,
192 context,
193 RESET,
194 message,
195 elapsed
196 )
197}
198
199fn format_elapsed(duration: Duration) -> String {
200 let milliseconds = duration.as_millis();
201
202 if milliseconds > 0 {
203 format!("+{milliseconds}ms")
204 } else {
205 format!("+{}µs", duration.as_micros())
206 }
207}
208
209fn current_timestamp() -> String {
210 let duration = SystemTime::now()
211 .duration_since(UNIX_EPOCH)
212 .unwrap_or(Duration::ZERO);
213 let total_seconds = duration.as_secs();
214 let days = (total_seconds / 86_400) as i64;
215 let seconds_of_day = total_seconds % 86_400;
216 let (year, month, day) = civil_from_days(days);
217 let hour_24 = seconds_of_day / 3_600;
218 let minute = (seconds_of_day % 3_600) / 60;
219 let second = seconds_of_day % 60;
220 let period = if hour_24 < 12 { "AM" } else { "PM" };
221 let hour_12 = match hour_24 % 12 {
222 0 => 12,
223 hour => hour,
224 };
225
226 format!("{month:02}/{day:02}/{year:04}, {hour_12:02}:{minute:02}:{second:02} {period}")
227}
228
229fn civil_from_days(days_since_epoch: i64) -> (i64, u32, u32) {
230 let z = days_since_epoch + 719_468;
231 let era = if z >= 0 { z } else { z - 146_096 } / 146_097;
232 let doe = z - era * 146_097;
233 let yoe = (doe - doe / 1_460 + doe / 36_524 - doe / 146_096) / 365;
234 let year = yoe + era * 400;
235 let doy = doe - (365 * yoe + yoe / 4 - yoe / 100);
236 let mp = (5 * doy + 2) / 153;
237 let day = doy - (153 * mp + 2) / 5 + 1;
238 let month = mp + if mp < 10 { 3 } else { -9 };
239 let year = year + if month <= 2 { 1 } else { 0 };
240
241 (year, month as u32, day as u32)
242}
243
244impl crate::Injectable for Logger {
245 fn dependencies() -> Vec<crate::ProviderDependency> {
246 crate::provider_dependencies![]
247 }
248
249 fn create(_container: &crate::Container) -> crate::BoxFuture<'_, crate::Result<Self>> {
250 Box::pin(async move { Ok(Self::new("Application")) })
251 }
252}
253
254pub fn log(context: &str, level: LogLevel, message: impl AsRef<str>, elapsed: Option<Duration>) {
255 Logger::new(context).write(level, message, elapsed);
256}
257
258pub fn log_http_exception(exception: &HttpException) {
259 if !exception.status.is_server_error() {
260 return;
261 }
262
263 let message = match &exception.source {
264 Some(source) => format!(
265 "{} {}: {} | source: {source:#}",
266 exception.status.as_u16(),
267 exception.error,
268 exception.message
269 ),
270 None => format!(
271 "{} {}: {}",
272 exception.status.as_u16(),
273 exception.error,
274 exception.message
275 ),
276 };
277
278 Logger::new("ExceptionHandler").error(message);
279}
280
281pub(crate) fn init_logging() {
282 install_panic_hook();
283 init_tracing();
284}
285
286fn init_tracing() {
287 TRACING_INIT.call_once(|| {
288 let subscriber = tracing_subscriber::fmt()
289 .without_time()
290 .with_level(false)
291 .with_target(false)
292 .with_ansi(false)
293 .with_writer(CaelixMakeWriter)
294 .event_format(CaelixFormatter)
295 .finish();
296
297 if tracing::subscriber::set_global_default(subscriber).is_ok() {
298 CAELIX_TRACING_SUBSCRIBER.store(true, Ordering::Release);
299 }
300 });
301}
302
303fn install_panic_hook() {
304 PANIC_HOOK_INIT.call_once(|| {
305 panic::set_hook(Box::new(|info| {
306 Logger::new("ExceptionHandler").write_forced(LogLevel::Error, panic_message(info));
307 }));
308 });
309}
310
311fn panic_message(info: &PanicHookInfo<'_>) -> String {
312 let payload = if let Some(message) = info.payload().downcast_ref::<&str>() {
313 *message
314 } else if let Some(message) = info.payload().downcast_ref::<String>() {
315 message.as_str()
316 } else {
317 "panic occurred"
318 };
319
320 if let Some(location) = info.location() {
321 format!(
322 "panic: {} (at {}:{}:{})",
323 payload,
324 location.file(),
325 location.line(),
326 location.column()
327 )
328 } else {
329 format!("panic: {}", payload)
330 }
331}
332
333struct CaelixFormatter;
334
335impl<S, N> FormatEvent<S, N> for CaelixFormatter
336where
337 S: Subscriber + for<'span> LookupSpan<'span>,
338 N: for<'writer> FormatFields<'writer> + 'static,
339{
340 fn format_event(
341 &self,
342 _ctx: &FmtContext<'_, S, N>,
343 mut writer: Writer<'_>,
344 event: &Event<'_>,
345 ) -> fmt::Result {
346 if event.metadata().target() != "caelix" {
347 return Ok(());
348 }
349
350 let mut visitor = MessageVisitor::default();
351 event.record(&mut visitor);
352
353 writeln!(writer, "{}", visitor.message)
354 }
355}
356
357struct CaelixMakeWriter;
358
359impl<'a> MakeWriter<'a> for CaelixMakeWriter {
360 type Writer = CaelixStreamWriter;
361
362 fn make_writer(&'a self) -> Self::Writer {
363 CaelixStreamWriter::Stdout(io::stdout())
364 }
365
366 fn make_writer_for(&'a self, meta: &Metadata<'_>) -> Self::Writer {
367 if *meta.level() == Level::ERROR {
368 CaelixStreamWriter::Stderr(io::stderr())
369 } else {
370 CaelixStreamWriter::Stdout(io::stdout())
371 }
372 }
373}
374
375enum CaelixStreamWriter {
376 Stdout(io::Stdout),
377 Stderr(io::Stderr),
378}
379
380impl Write for CaelixStreamWriter {
381 fn write(&mut self, buf: &[u8]) -> io::Result<usize> {
382 match self {
383 Self::Stdout(writer) => writer.write(buf),
384 Self::Stderr(writer) => writer.write(buf),
385 }
386 }
387
388 fn flush(&mut self) -> io::Result<()> {
389 match self {
390 Self::Stdout(writer) => writer.flush(),
391 Self::Stderr(writer) => writer.flush(),
392 }
393 }
394}
395
396#[derive(Default)]
397struct MessageVisitor {
398 message: String,
399}
400
401impl Visit for MessageVisitor {
402 fn record_str(&mut self, field: &Field, value: &str) {
403 if field.name() == "message" {
404 self.message = value.to_string();
405 }
406 }
407
408 fn record_debug(&mut self, field: &Field, value: &dyn fmt::Debug) {
409 if field.name() == "message" && self.message.is_empty() {
410 self.message = format!("{value:?}");
411 }
412 }
413}
414
415pub fn log_application_starting() {
416 log(
417 "Application",
418 LogLevel::Info,
419 "Starting Caelix application...",
420 None,
421 );
422}
423
424pub fn log_application_started(elapsed: Duration) {
425 log(
426 "Application",
427 LogLevel::Info,
428 "Caelix application successfully started",
429 Some(elapsed),
430 );
431}
432
433pub fn log_listening(addr: &str) {
434 log(
435 "Application",
436 LogLevel::Info,
437 format!("Caelix application listening on {}", addr),
438 None,
439 );
440}
441
442pub fn log_module_initialized(module: &str, elapsed: Duration) {
443 log(
444 "InstanceLoader",
445 LogLevel::Info,
446 format!("{} dependencies initialized", short_type_name(module)),
447 Some(elapsed),
448 );
449}
450
451pub fn log_provider_initialized(provider: &str, elapsed: Duration) {
452 log(
453 "ProviderLoader",
454 LogLevel::Info,
455 format!("{} initialized", short_type_name(provider)),
456 Some(elapsed),
457 );
458}
459
460pub fn log_controller_routes<C: Controller>() {
461 let routes = C::routes();
462
463 if routes.is_empty() {
464 return;
465 }
466
467 log(
468 "RoutesResolver",
469 LogLevel::Info,
470 format!(
471 "{} {{{}}}:",
472 short_type_name(std::any::type_name::<C>()),
473 C::base_path()
474 ),
475 Some(Duration::ZERO),
476 );
477
478 for route in routes {
479 log_route_mapped(route);
480 }
481}
482
483pub fn log_route_mapped(route: &RouteDef) {
484 log(
485 "RouterExplorer",
486 LogLevel::Info,
487 format!(
488 "Mapped {{{}, {}}} route",
489 route.path,
490 route.method.to_uppercase()
491 ),
492 Some(Duration::ZERO),
493 );
494}
495
496pub fn log_http_request(method: &str, path: &str, status: u16, elapsed: Duration) {
497 let level = match status {
498 500..=599 => LogLevel::Error,
499 _ => LogLevel::Info,
500 };
501 if !log_level_enabled(level) {
502 return;
503 }
504
505 init_logging();
506
507 if CAELIX_TRACING_SUBSCRIBER.load(Ordering::Acquire) {
508 access_log_writer().write(method, path, status, elapsed);
509 } else {
510 let status = color_status(status);
511 log(
512 "HTTP",
513 level,
514 format!("{} {} {}", method, path, status),
515 Some(elapsed),
516 );
517 }
518}
519
520#[doc(hidden)]
524#[allow(clippy::too_many_arguments)]
525pub fn log_http_request_info(
526 client_address: &str,
527 method: &str,
528 path_and_query: &str,
529 protocol: &str,
530 status: u16,
531 response_size: Option<u64>,
532 referrer: &str,
533 user_agent: &str,
534 elapsed: Duration,
535) {
536 let level = match status {
537 500..=599 => LogLevel::Error,
538 _ => LogLevel::Info,
539 };
540 if !log_level_enabled(level) {
541 return;
542 }
543
544 init_logging();
545
546 if CAELIX_TRACING_SUBSCRIBER.load(Ordering::Acquire) {
547 access_log_writer().write_info(HttpAccessLogInfo::new(
548 client_address,
549 method,
550 path_and_query,
551 protocol,
552 status,
553 response_size,
554 referrer,
555 user_agent,
556 elapsed,
557 ));
558 } else {
559 log(
560 "HTTP",
561 level,
562 format_http_request_info(
563 client_address,
564 method,
565 path_and_query,
566 protocol,
567 status,
568 response_size,
569 referrer,
570 user_agent,
571 elapsed,
572 ),
573 None,
574 );
575 }
576}
577
578pub fn dropped_http_request_logs() -> u64 {
581 ACCESS_LOG_WRITER
582 .get()
583 .map(|writer| writer.dropped.load(Ordering::Relaxed))
584 .unwrap_or(0)
585}
586
587struct AccessLogWriter {
588 sender: Sender<AccessLogEvent>,
589 dropped: Arc<AtomicU64>,
590 pending_drop_report: Arc<AtomicU64>,
591}
592
593enum AccessLogEvent {
594 Compact {
595 request: String,
596 status: u16,
597 elapsed: Duration,
598 },
599 Info(HttpAccessLogInfo),
600}
601
602struct HttpAccessLogInfo {
603 client_address: String,
604 method: String,
605 path_and_query: String,
606 protocol: String,
607 status: u16,
608 response_size: Option<u64>,
609 referrer: String,
610 user_agent: String,
611 elapsed: Duration,
612}
613
614impl HttpAccessLogInfo {
615 #[allow(clippy::too_many_arguments)]
616 fn new(
617 client_address: &str,
618 method: &str,
619 path_and_query: &str,
620 protocol: &str,
621 status: u16,
622 response_size: Option<u64>,
623 referrer: &str,
624 user_agent: &str,
625 elapsed: Duration,
626 ) -> Self {
627 Self {
628 client_address: client_address.to_string(),
629 method: method.to_string(),
630 path_and_query: path_and_query.to_string(),
631 protocol: protocol.to_string(),
632 status,
633 response_size,
634 referrer: referrer.to_string(),
635 user_agent: user_agent.to_string(),
636 elapsed,
637 }
638 }
639}
640
641impl AccessLogWriter {
642 fn new() -> Self {
643 let (sender, receiver) = crossbeam_channel::bounded(ACCESS_LOG_QUEUE_CAPACITY);
644 let dropped = Arc::new(AtomicU64::new(0));
645 let pending_drop_report = Arc::new(AtomicU64::new(0));
646 let worker_drop_report = Arc::clone(&pending_drop_report);
647
648 thread::Builder::new()
649 .name("caelix-access-log".to_string())
650 .spawn(move || write_access_logs(receiver, worker_drop_report))
651 .expect("failed to start the Caelix access-log writer");
652
653 Self {
654 sender,
655 dropped,
656 pending_drop_report,
657 }
658 }
659
660 fn write(&self, method: &str, path: &str, status: u16, elapsed: Duration) {
661 if self.sender.is_full() {
662 self.record_drop();
663 return;
664 }
665
666 let mut request = String::with_capacity(method.len() + path.len() + 1);
667 request.push_str(method);
668 request.push(' ');
669 request.push_str(path);
670
671 let event = AccessLogEvent::Compact {
672 request,
673 status,
674 elapsed,
675 };
676
677 if matches!(self.sender.try_send(event), Err(TrySendError::Full(_))) {
678 self.record_drop();
679 }
680 }
681
682 fn write_info(&self, event: HttpAccessLogInfo) {
683 if self.sender.is_full() {
684 self.record_drop();
685 return;
686 }
687
688 if matches!(
689 self.sender.try_send(AccessLogEvent::Info(event)),
690 Err(TrySendError::Full(_))
691 ) {
692 self.record_drop();
693 }
694 }
695
696 fn record_drop(&self) {
697 self.dropped.fetch_add(1, Ordering::Relaxed);
698 self.pending_drop_report.fetch_add(1, Ordering::Relaxed);
699 }
700}
701
702fn access_log_writer() -> &'static AccessLogWriter {
703 ACCESS_LOG_WRITER.get_or_init(AccessLogWriter::new)
704}
705
706fn write_access_logs(receiver: Receiver<AccessLogEvent>, dropped: Arc<AtomicU64>) {
707 let stdout = io::stdout();
708 let stderr = io::stderr();
709 let mut stdout = BufWriter::with_capacity(256 * 1024, stdout.lock());
710 let mut stderr = BufWriter::with_capacity(16 * 1024, stderr.lock());
711 let mut last_drop_report = Instant::now();
712
713 loop {
714 match receiver.recv_timeout(ACCESS_LOG_FLUSH_INTERVAL) {
715 Ok(event) => {
716 write_access_log(&mut stdout, &mut stderr, event);
717
718 for event in receiver.try_iter().take(ACCESS_LOG_BATCH_SIZE - 1) {
719 write_access_log(&mut stdout, &mut stderr, event);
720 }
721 }
722 Err(crossbeam_channel::RecvTimeoutError::Timeout) => {}
723 Err(crossbeam_channel::RecvTimeoutError::Disconnected) => break,
724 }
725
726 if last_drop_report.elapsed() >= ACCESS_LOG_DROP_REPORT_INTERVAL {
727 report_dropped_access_logs(&mut stderr, &dropped);
728 last_drop_report = Instant::now();
729 }
730
731 let _ = stdout.flush();
732 let _ = stderr.flush();
733 }
734
735 report_dropped_access_logs(&mut stderr, &dropped);
736 let _ = stdout.flush();
737 let _ = stderr.flush();
738}
739
740fn write_access_log(
741 stdout: &mut BufWriter<io::StdoutLock<'_>>,
742 stderr: &mut BufWriter<io::StderrLock<'_>>,
743 event: AccessLogEvent,
744) {
745 let (level, message, elapsed) = match event {
746 AccessLogEvent::Compact {
747 request,
748 status,
749 elapsed,
750 } => {
751 let level = log_level_for_status(status);
752 (
753 level,
754 format!("{} {}", request, color_status(status)),
755 Some(elapsed),
756 )
757 }
758 AccessLogEvent::Info(info) => {
759 let level = log_level_for_status(info.status);
760 (
761 level,
762 format_http_request_info(
763 &info.client_address,
764 &info.method,
765 &info.path_and_query,
766 &info.protocol,
767 info.status,
768 info.response_size,
769 &info.referrer,
770 &info.user_agent,
771 info.elapsed,
772 ),
773 None,
774 )
775 }
776 };
777 let line = format_log_line("HTTP", level, &message, elapsed);
778
779 if level == LogLevel::Error {
780 let _ = writeln!(stderr, "{line}");
781 } else {
782 let _ = writeln!(stdout, "{line}");
783 }
784}
785
786fn log_level_for_status(status: u16) -> LogLevel {
787 match status {
788 500..=599 => LogLevel::Error,
789 _ => LogLevel::Info,
790 }
791}
792
793#[allow(clippy::too_many_arguments)]
794fn format_http_request_info(
795 client_address: &str,
796 method: &str,
797 path_and_query: &str,
798 protocol: &str,
799 status: u16,
800 response_size: Option<u64>,
801 referrer: &str,
802 user_agent: &str,
803 elapsed: Duration,
804) -> String {
805 let request = if path_and_query.is_empty() {
806 method.to_string()
807 } else {
808 format!("{method} {path_and_query}")
809 };
810 let response_size = response_size
811 .map(|size| size.to_string())
812 .unwrap_or_else(|| "-".to_string());
813
814 format!(
815 "{client_address} \"{request} {protocol}\" {} {response_size} \"{referrer}\" \"{user_agent}\" {:.6}",
816 color_status(status),
817 elapsed.as_secs_f64(),
818 )
819}
820
821fn report_dropped_access_logs(stderr: &mut BufWriter<io::StderrLock<'_>>, dropped: &AtomicU64) {
822 let dropped = dropped.swap(0, Ordering::Relaxed);
823
824 if dropped > 0 {
825 let _ = writeln!(
826 stderr,
827 "[Caelix] access-log writer queue was full; dropped {dropped} entries"
828 );
829 }
830}
831
832pub fn http_request_logging_enabled() -> bool {
833 *HTTP_REQUEST_LOGGING.get_or_init(|| {
834 env::var("CAELIX_HTTP_LOG")
835 .or_else(|_| env::var("CAELIX_ACCESS_LOG"))
836 .ok()
837 .and_then(|value| parse_bool(&value))
838 .unwrap_or(false)
839 })
840}
841
842pub fn log_module_routes<M: Module>() {
843 let metadata = M::register();
844
845 for import in &metadata.imports {
846 (import.route_log_fn)();
847 }
848
849 for controller in &metadata.controllers {
850 (controller.route_log_fn)();
851 }
852}
853
854fn short_type_name(name: &str) -> &str {
855 name.rsplit("::").next().unwrap_or(name)
856}
857
858fn color_status(status: u16) -> String {
859 let color = match status {
860 500..=599 => ERROR,
861 400..=499 => WARN,
862 _ => OK_STATUS,
863 };
864
865 format!("{}{}{}", color, status, RESET)
866}
867
868fn log_level_enabled(level: LogLevel) -> bool {
869 level.priority() <= configured_log_priority()
870}
871
872fn configured_log_priority() -> u8 {
873 *LOG_PRIORITY.get_or_init(|| {
874 env::var("CAELIX_LOG")
875 .ok()
876 .and_then(|value| parse_log_level(&value))
877 .or_else(|| {
878 env::var("RUST_LOG")
879 .ok()
880 .and_then(|value| parse_rust_log_level(&value))
881 })
882 .unwrap_or(LogLevel::Info.priority())
883 })
884}
885
886fn parse_rust_log_level(value: &str) -> Option<u8> {
887 value.split(',').find_map(|directive| {
888 let directive = directive.trim();
889
890 if let Some((target, level)) = directive.split_once('=') {
891 let target = target.trim();
892 if matches!(target, "caelix" | "caelix_core" | "caelix-core") {
893 return parse_log_level(level);
894 }
895
896 return None;
897 }
898
899 parse_log_level(directive)
900 })
901}
902
903fn parse_log_level(value: &str) -> Option<u8> {
904 match value.trim().to_ascii_lowercase().as_str() {
905 "debug" | "trace" => Some(LogLevel::Debug.priority()),
906 "info" | "log" => Some(LogLevel::Info.priority()),
907 "warn" | "warning" => Some(LogLevel::Warn.priority()),
908 "error" => Some(LogLevel::Error.priority()),
909 "off" => Some(0),
910 _ => None,
911 }
912}
913
914fn parse_bool(value: &str) -> Option<bool> {
915 match value.trim().to_ascii_lowercase().as_str() {
916 "1" | "true" | "yes" | "y" | "on" => Some(true),
917 "0" | "false" | "no" | "n" | "off" => Some(false),
918 _ => None,
919 }
920}
921
922#[cfg(test)]
923mod tests {
924 use super::*;
925
926 #[test]
927 fn elapsed_format_preserves_sub_millisecond_detail() {
928 assert_eq!(format_elapsed(Duration::ZERO), "+0µs");
929 assert_eq!(format_elapsed(Duration::from_micros(742)), "+742µs");
930 assert_eq!(format_elapsed(Duration::from_micros(1_200)), "+1ms");
931 assert_eq!(format_elapsed(Duration::from_millis(42)), "+42ms");
932 }
933
934 #[test]
935 fn parse_bool_accepts_common_env_values() {
936 assert_eq!(parse_bool("1"), Some(true));
937 assert_eq!(parse_bool("on"), Some(true));
938 assert_eq!(parse_bool("false"), Some(false));
939 assert_eq!(parse_bool("off"), Some(false));
940 assert_eq!(parse_bool("sometimes"), None);
941 }
942
943 #[test]
944 fn detailed_http_log_includes_actix_default_fields() {
945 let line = format_http_request_info(
946 "127.0.0.1:43120",
947 "GET",
948 "/hello?name=Caelix",
949 "HTTP/1.1",
950 200,
951 Some(42),
952 "https://example.com",
953 "CaelixTest/1.0",
954 Duration::from_micros(1_250),
955 );
956
957 assert!(line.starts_with("127.0.0.1:43120 \"GET /hello?name=Caelix HTTP/1.1\""));
958 assert!(line.contains(" 42 \"https://example.com\" \"CaelixTest/1.0\" 0.001250"));
959 }
960}