Route access logs to stdout (#1315)

Author: lovasoa

CHANGELOG.md

@@ -1,5 +1,9 @@
 # CHANGELOG.md
 
+## unreleased
+
+- **Access logs now go to stdout.** SQLPage now writes the single per-request completion log line to stdout with the target `sqlpage::access`, matching common application-server and container logging conventions. Diagnostic logs, warnings, and internal errors still go to stderr. If your `LOG_LEVEL` or `RUST_LOG` filter is scoped to a specific old target such as `sqlpage::webserver::http=info`, add `sqlpage::access=info` so request-completion logs are still emitted. If your log pipeline only collects stderr, update it to collect stdout too.
+
 ## v0.44.1
 
 An AI-assisted security audit found three vulnerabilities: one authentication bypass that is high severity for affected OIDC deployments, and two lower-severity issues. It also led to three hardening changes. Upgrade now if you use custom OIDC protected paths.

configuration.md

@@ -61,6 +61,9 @@ The environment variable name can optionally be prefixed with `SQLPAGE_`.
 Additionnally, when troubleshooting, you can set the
 [`LOG_LEVEL`](https://docs.rs/tracing-subscriber/latest/tracing_subscriber/filter/struct.EnvFilter.html)
 environment variable to `sqlpage=debug` to get more detailed logs and see exactly what SQLPage is doing.
+Request-completion access logs use the target `sqlpage::access`. Broad filters such as
+`sqlpage=info` include them, but target-specific filters such as `sqlpage::webserver::http=info`
+must also include `sqlpage::access=info` if you want to keep request logs.
 
 SQLPage also supports [OpenTelemetry](https://opentelemetry.io/) tracing via the `OTEL_EXPORTER_OTLP_ENDPOINT` environment variable. See the [SQLPage monitoring example](https://github.com/sqlpage/sqlpage/tree/main/examples/telemetry).
 

examples/official-site/sqlpage/migrations/66_log_component.sql

@@ -8,7 +8,7 @@ Use it to track what happens and troubleshoot issues.
 - Running from a terminal (Linux, macOS, or Windows PowerShell/Command Prompt): they show up in the window.
 - Docker: run `docker logs <container_name>`.
 - Linux service (systemd): run `journalctl -u sqlpage`.
-- Output is written to [standard error (stderr)](https://en.wikipedia.org/wiki/Standard_streams#Standard_error_(stderr)).
+- This component''s output is written to [standard error (stderr)](https://en.wikipedia.org/wiki/Standard_streams#Standard_error_(stderr)). SQLPage request access logs are separate and are written to standard output (stdout).
 ');
 
 INSERT INTO parameter(component, name, description, type, top_level, optional) SELECT 'log', * FROM (VALUES
@@ -58,4 +58,4 @@ select ''log'' as component,
         ''403 - failed for '' || coalesce($username, ''None'') as message,
         ''error'' as level;
 ```
-')
+')

examples/official-site/sqlpage/migrations/73_blog_tracing.sql

@@ -106,7 +106,7 @@ This is much more actionable than a single request duration number.
 
 Tracing is even more useful when logs and traces are connected.
 
-In the example stack, SQLPage writes structured logs to stdout, Promtail forwards them to Loki, and Grafana lets you move from a log line to the matching trace using the trace id. This makes it possible to start from an error log and immediately inspect the full request timeline.
+In the example stack, SQLPage writes request access logs to stdout and diagnostic logs to stderr. The OpenTelemetry Collector forwards both streams to Loki, and Grafana lets you move from a log line to the matching trace using the trace id. This makes it possible to start from an error log and immediately inspect the full request timeline.
 
 That workflow is often the difference between guessing and knowing.
 

examples/telemetry/README.md

@@ -85,9 +85,14 @@ Key attributes on each span:
 SQLPage writes one structured log line per event, for example:
 
 ```text
-ts=2026-03-08T20:56:15.000Z level=info target=sqlpage::webserver::http msg="request completed" http.request.method=GET url.path=/ trace_id=4f2d...
+ts=2026-03-08T20:56:15.000Z level=info target=sqlpage::access msg="200 OK" http.request.method=GET url.path=/ trace_id=4f2d...
 ```
 
+Request-completion access logs use the target `sqlpage::access` and are written to stdout.
+Diagnostic logs, warnings, and internal errors are written to stderr. Docker and most
+container log drivers collect both streams by default, but custom log pipelines that read
+only stderr need to collect stdout as well to keep access logs.
+
 The OpenTelemetry Collector receives these SQLPage container logs through Docker's syslog
 logging driver and forwards them to Loki.
 The homepage dashboard filters to the `sqlpage` service so you can see request logs update
@@ -367,7 +372,7 @@ not specific to SQLPage.
 | `OTEL_SERVICE_NAME`              | No        | Service name shown in traces (default: `unknown_service`) | `sqlpage`                 |
 | `OTEL_EXPORTER_OTLP_HEADERS`    | No        | Comma-separated `key=value` pairs for auth headers | `api-key=abc123`                |
 | `OTEL_EXPORTER_OTLP_PROTOCOL`   | No        | Protocol (default: `http/protobuf`)            | `http/protobuf`                      |
-| `RUST_LOG`                        | No        | Filter which spans/logs are emitted            | `sqlpage=debug,tracing_actix_web=info` |
+| `RUST_LOG` or `LOG_LEVEL`         | No        | Filter which spans/logs are emitted            | `sqlpage=debug,tracing_actix_web=info` |
 
 When `OTEL_EXPORTER_OTLP_ENDPOINT` is **not set**, SQLPage uses plain text
 logging only (same behavior as versions before tracing support was added).
@@ -411,3 +416,10 @@ includes `sqlpage=info`:
 ```bash
 RUST_LOG="sqlpage=info,actix_web=info,tracing_actix_web=info"
 ```
+
+If you filter individual targets instead of the broader `sqlpage` target, include
+the access-log target too:
+
+```bash
+RUST_LOG="sqlpage::access=info,sqlpage::webserver::http=info,actix_web=info,tracing_actix_web=info"
+```

src/telemetry.rs

@@ -20,6 +20,7 @@ static OTLP_HTTP_WORKER_SENDER: OnceLock<
     Result<tokio::sync::mpsc::UnboundedSender<OtlpHttpJob>, String>,
 > = OnceLock::new();
 const DEFAULT_ENV_FILTER_DIRECTIVES: &str = "sqlpage=info,actix_web=info,tracing_actix_web=info,opentelemetry=warn,opentelemetry_sdk=warn,opentelemetry_otlp=warn";
+pub(crate) const ACCESS_LOG_TARGET: &str = "sqlpage::access";
 
 type OtlpHttpResponse = Result<opentelemetry_http::Response<opentelemetry_http::Bytes>, String>;
 
@@ -438,26 +439,29 @@ mod logfmt {
 
     #[derive(Copy, Clone)]
     enum OutputMode {
-        Stderr,
+        StdoutAndStderr,
         TestWriter,
     }
 
     pub(super) struct LogfmtLayer {
-        use_colors: bool,
+        stdout_colors: bool,
+        stderr_colors: bool,
         output_mode: OutputMode,
     }
 
     impl LogfmtLayer {
         pub fn new() -> Self {
             Self {
-                use_colors: io::stderr().is_terminal(),
-                output_mode: OutputMode::Stderr,
+                stdout_colors: io::stdout().is_terminal(),
+                stderr_colors: io::stderr().is_terminal(),
+                output_mode: OutputMode::StdoutAndStderr,
             }
         }
 
         pub fn test_writer() -> Self {
             Self {
-                use_colors: false,
+                stdout_colors: false,
+                stderr_colors: false,
                 output_mode: OutputMode::TestWriter,
             }
         }
@@ -496,12 +500,13 @@ mod logfmt {
 
         fn on_event(&self, event: &tracing::Event<'_>, ctx: Context<'_, S>) {
             let mut buf = String::with_capacity(256);
-            let colors = self.use_colors;
             let level = *event.metadata().level();
             let include_all_span_fields = includes_all_span_fields();
             let mut event_fields = HashMap::new();
             event.record(&mut FieldCollector(&mut event_fields));
             let target = event_target(event, &event_fields);
+            let output_stream = output_stream_for_target(target);
+            let colors = self.use_colors(output_stream);
             let msg = event_fields.get("message");
             let multiline_msg = is_multiline_terminal_message(colors, msg);
             let include_all_event_fields =
@@ -518,16 +523,50 @@ mod logfmt {
             buf.push('\n');
             write_multiline_message(&mut buf, msg, multiline_msg);
             match self.output_mode {
-                OutputMode::Stderr => {
-                    let _ = io::Write::write_all(&mut io::stderr().lock(), buf.as_bytes());
-                }
+                OutputMode::StdoutAndStderr => write_to_output(output_stream, &buf),
                 OutputMode::TestWriter => {
                     eprint!("{buf}");
                 }
             }
         }
     }
 
+    impl LogfmtLayer {
+        fn use_colors(&self, output_stream: OutputStream) -> bool {
+            match output_stream {
+                OutputStream::Stdout => self.stdout_colors,
+                OutputStream::Stderr => self.stderr_colors,
+            }
+        }
+    }
+
+    #[derive(Copy, Clone, Debug, Eq, PartialEq)]
+    enum OutputStream {
+        Stdout,
+        Stderr,
+    }
+
+    fn output_stream_for_target(target: &str) -> OutputStream {
+        if target == super::ACCESS_LOG_TARGET {
+            OutputStream::Stdout
+        } else {
+            OutputStream::Stderr
+        }
+    }
+
+    fn write_to_output(output_stream: OutputStream, buf: &str) {
+        use std::io::Write as _;
+
+        match output_stream {
+            OutputStream::Stdout => {
+                let _ = io::stdout().write_all(buf.as_bytes());
+            }
+            OutputStream::Stderr => {
+                let _ = io::stderr().write_all(buf.as_bytes());
+            }
+        }
+    }
+
     fn event_target<'a>(
         event: &'a tracing::Event<'_>,
         event_fields: &'a HashMap<&'static str, String>,
@@ -819,5 +858,17 @@ mod logfmt {
                 " name=BatchSpanProcessor.ExportFailed reason=\"connection error\""
             );
         }
+
+        #[test]
+        fn access_logs_use_stdout_and_other_logs_use_stderr() {
+            assert_eq!(
+                output_stream_for_target(super::super::ACCESS_LOG_TARGET),
+                OutputStream::Stdout
+            );
+            assert_eq!(
+                output_stream_for_target("sqlpage::webserver::http"),
+                OutputStream::Stderr
+            );
+        }
     }
 }

src/webserver/http.rs

@@ -406,7 +406,7 @@ impl RootSpanBuilder for SqlPageRootSpanBuilder {
             } else {
                 log::Level::Info
             };
-            log::log!(level, "{status}");
+            log::log!(target: crate::telemetry::ACCESS_LOG_TARGET, level, "{status}");
         }
     }
 }