Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
4 changes: 4 additions & 0 deletions CHANGELOG.md
Original file line number Diff line number Diff line change
@@ -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.
Expand Down
3 changes: 3 additions & 0 deletions configuration.md
Original file line number Diff line number Diff line change
Expand Up @@ -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).

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand Down Expand Up @@ -58,4 +58,4 @@ select ''log'' as component,
''403 - failed for '' || coalesce($username, ''None'') as message,
''error'' as level;
```
')
')
Original file line number Diff line number Diff line change
Expand Up @@ -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.
Expand Down
16 changes: 14 additions & 2 deletions examples/telemetry/README.md
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand Down Expand Up @@ -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).
Expand Down Expand Up @@ -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"
```
69 changes: 60 additions & 9 deletions src/telemetry.rs
Original file line number Diff line number Diff line change
Expand Up @@ -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>;

Expand Down Expand Up @@ -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,
}
}
Expand Down Expand Up @@ -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 =
Expand All @@ -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>,
Expand Down Expand Up @@ -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
);
}
}
}
2 changes: 1 addition & 1 deletion src/webserver/http.rs
Original file line number Diff line number Diff line change
Expand Up @@ -405,7 +405,7 @@ impl RootSpanBuilder for SqlPageRootSpanBuilder {
} else {
log::Level::Info
};
log::log!(level, "{status}");
log::log!(target: crate::telemetry::ACCESS_LOG_TARGET, level, "{status}");
Comment thread
lovasoa marked this conversation as resolved.
}
}
}
Expand Down
Loading