Skip to content

chore(logging): trim default log volume — reclassify routine info→debug, add trace tier #3994

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
Yeraze merged 2 commits into from
Jul 8, 2026
Merged

chore(logging): trim default log volume — reclassify routine info→debug, add trace tier #3994

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
2 commits
Select commit Hold shift + click to select a range
c5d8553
chore(logging): trim default log volume — reclassify routine info→deb…
Yeraze Jul 7, 2026
3d0ddb7
address review: document trace unknown[] rationale + module-load leve…
Yeraze Jul 7, 2026
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
1 change: 1 addition & 0 deletions CHANGELOG.md
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -7,6 +7,7 @@ The format is based on [Keep a Changelog](https://keepachangelog.com/en/1.0.0/),
## [Unreleased]

### Changed
- **Container logs are far quieter at the default level.** Routine per-packet, per-request, and periodic-scheduler activity — plus the ~60-line environment dump printed on every boot — was logged at `info`, which is the production default, making Docker logs hard to use for support. That activity is now logged at `debug`; `info` is reserved for genuinely important, low-frequency events (startup/shutdown, source connect/disconnect, backups/restores/migrations, and deliberate actions taken), so an idle container is near-silent. A new `trace` level captures the full per-packet firehose. Raise verbosity for troubleshooting with `LOG_LEVEL=debug` (or `trace`) — no `NODE_ENV` change needed. As a side benefit, MeshCore message **bodies** are no longer written to logs (only sender/channel metadata and a length).
- **BREAKING (deployments behind a reverse proxy): `TRUST_PROXY` now defaults to `false`.** Previously, production builds trusted the first proxy hop when `TRUST_PROXY` was unset, which let a direct-connected client spoof `X-Forwarded-For` to bypass the auth brute-force limiter and poison audit attribution. Proxied deployments must now set `TRUST_PROXY` explicitly (`TRUST_PROXY=1` for a single proxy). Direct (non-proxied) deployments need no change.

## [4.12.5] - 2026-07-06
Expand Down
6 changes: 6 additions & 0 deletions docker-compose.yml
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -27,6 +27,12 @@ services:
- TZ=America/New_York
- ALLOWED_ORIGINS=http://localhost:8080 # Required for CORS

# Log verbosity: trace | debug | info | warn | error
# Defaults to `info` in production / `debug` in development. `info` is
# deliberately quiet (startup + connect/disconnect + errors). Raise to
# `debug` (or `trace` for the per-packet firehose) when troubleshooting.
# - LOG_LEVEL=debug

# OPTIONAL: Uncomment and configure for production deployments
# See docs/configuration/production.md for full production setup guide

Expand Down
17 changes: 11 additions & 6 deletions docs/configuration/index.md
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -190,7 +190,7 @@ See the [Push Notifications guide](/features/notifications) for setup instructio

| Variable | Description | Default |
|----------|-------------|---------|
| `LOG_LEVEL` | Log verbosity: `debug`, `info`, `warn`, `error` | `debug` in development, `info` in production |
| `LOG_LEVEL` | Log verbosity: `trace`, `debug`, `info`, `warn`, `error` | `debug` in development, `info` in production |

**Note**: `LOG_LEVEL` controls log output independently of `NODE_ENV`. This lets you enable debug logging in production Docker deployments without changing rate limits, cookie warnings, or other `NODE_ENV`-dependent behavior.

Expand Down Expand Up @@ -320,12 +320,14 @@ MeshMonitor logs to stdout/stderr by default. Log output uses level prefixes: `[

### Log Levels

Control verbosity with the `LOG_LEVEL` environment variable:
Control verbosity with the `LOG_LEVEL` environment variable. Levels are
cumulative — each includes everything above it in this table:

| Level | What is logged |
|-------|---------------|
| `debug` | Everything — verbose diagnostics, state changes, data inspection |
| `info` | Informational messages, warnings, and errors |
| `trace` | Firehose — per-packet / per-loop diagnostics. Only enable for a short capture window; far too noisy for steady use. |
| `debug` | Verbose but bounded — routine per-event activity, periodic scheduler cycles, connection handshake steps, state inspection. |
| `info` | **Default in production.** Important, low-frequency events: startup/shutdown, source connect/disconnect, backups/restores/migrations, and deliberate actions taken. An idle container is near-silent at this level. |
| `warn` | Warnings and errors only |
| `error` | Errors only |

Expand All @@ -334,11 +336,14 @@ If `LOG_LEVEL` is not set, the default depends on `NODE_ENV`:
- `production` → `info`

::: tip Troubleshooting in Production
Set `LOG_LEVEL=debug` to get verbose logging without changing `NODE_ENV`. This avoids side effects like altered rate limits or cookie warnings:
The default `info` level is deliberately quiet — routine per-packet, per-request,
and periodic-scheduler activity is logged at `debug`. To investigate an issue,
raise the level without changing `NODE_ENV` (this avoids side effects like
altered rate limits or cookie warnings):
```yaml
environment:
- NODE_ENV=production
- LOG_LEVEL=debug
- LOG_LEVEL=debug # or `trace` for the full per-packet firehose
```
:::

Expand Down
6 changes: 3 additions & 3 deletions src/server/auth/authMiddleware.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -45,7 +45,7 @@ export function optionalAuth() {
if (!user) {
// Auto-provision if enabled
if (config.proxyAuthAutoProvision) {
logger.info(`🔐 Auto-provisioning proxy user: ${proxyUser.email}`);
logger.debug(`🔐 Auto-provisioning proxy user: ${proxyUser.email}`);

const isAdmin = isAdminUser(proxyUser.email, proxyUser.groups);
const username = proxyUser.email.split('@')[0]; // Use email prefix as username
Expand Down Expand Up @@ -105,7 +105,7 @@ export function optionalAuth() {

// Check if we need to migrate local user to proxy
if (user && user.authProvider === 'local') {
logger.info(`🔄 Migrating local user '${user.username}' to proxy auth`);
logger.debug(`🔄 Migrating local user '${user.username}' to proxy auth`);

const isAdmin = isAdminUser(proxyUser.email, proxyUser.groups);

Expand Down Expand Up @@ -143,7 +143,7 @@ export function optionalAuth() {
const currentIsAdmin = isAdminUser(proxyUser.email, proxyUser.groups);

if (currentIsAdmin !== user.isAdmin) {
logger.info(`🔄 Updating admin status for ${user.username}: ${user.isAdmin} → ${currentIsAdmin}`);
logger.debug(`🔄 Updating admin status for ${user.username}: ${user.isAdmin} → ${currentIsAdmin}`);

await databaseService.auth.updateUser(user.id, {
isAdmin: currentIsAdmin,
Expand Down
110 changes: 55 additions & 55 deletions src/server/config/environment.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -309,7 +309,7 @@ export interface EnvironmentConfig {
accessLogFormatProvided: boolean;

// Logging
logLevel: 'debug' | 'info' | 'warn' | 'error';
logLevel: 'trace' | 'debug' | 'info' | 'warn' | 'error';
logLevelProvided: boolean;

// Branding (login page customization)
Expand Down Expand Up @@ -696,8 +696,8 @@ export function loadEnvironmentConfig(): EnvironmentConfig {
const accessLogFormat = parseEnum('ACCESS_LOG_FORMAT', process.env.ACCESS_LOG_FORMAT, ['combined', 'common', 'tiny'] as const, 'combined');

// Logging
const logLevelDefault: 'debug' | 'info' | 'warn' | 'error' = nodeEnv.value === 'development' ? 'debug' : 'info';
const logLevel = parseEnum('LOG_LEVEL', process.env.LOG_LEVEL?.toLowerCase(), ['debug', 'info', 'warn', 'error'] as const, logLevelDefault);
const logLevelDefault: 'trace' | 'debug' | 'info' | 'warn' | 'error' = nodeEnv.value === 'development' ? 'debug' : 'info';
const logLevel = parseEnum('LOG_LEVEL', process.env.LOG_LEVEL?.toLowerCase(), ['trace', 'debug', 'info', 'warn', 'error'] as const, logLevelDefault);

// Branding (login page customization)
// CUSTOM_TITLE overrides the "MeshMonitor" heading on the login page.
Expand Down Expand Up @@ -736,79 +736,79 @@ export function loadEnvironmentConfig(): EnvironmentConfig {
logger.info(` BASE_URL: ${baseUrl || '/'} (${src(baseUrlProvided)})`);
logger.info(` LOG_LEVEL: ${logLevel.value} (${src(logLevel.wasProvided)})`);
logger.info(` TZ: ${timezone.value} (${src(timezone.wasProvided)})`);
logger.info(` ALLOWED_ORIGINS: ${allowedOrigins.value || '*'} (${src(allowedOrigins.wasProvided)})`);
logger.info(` IFRAME_ALLOWED_ORIGINS: ${iframeAllowedOrigins.value.length > 0 ? iframeAllowedOrigins.value.join(',') : '(not set - iframe embedding blocked)'} (${src(iframeAllowedOrigins.wasProvided)})`);
logger.info(` TRUST_PROXY: ${trustProxy.value} (${src(trustProxy.wasProvided)})`);
logger.debug(` ALLOWED_ORIGINS: ${allowedOrigins.value || '*'} (${src(allowedOrigins.wasProvided)})`);
logger.debug(` IFRAME_ALLOWED_ORIGINS: ${iframeAllowedOrigins.value.length > 0 ? iframeAllowedOrigins.value.join(',') : '(not set - iframe embedding blocked)'} (${src(iframeAllowedOrigins.wasProvided)})`);
logger.debug(` TRUST_PROXY: ${trustProxy.value} (${src(trustProxy.wasProvided)})`);
logger.info(` VERSION_CHECK_DISABLED: ${versionCheckDisabled}`);
logger.info(' --- Session/Security ---');
logger.info(` SESSION_SECRET: ${sessionSecretProvided ? '***provided***' : '(auto-generated)'}`);
logger.info(` SESSION_COOKIE_NAME: ${sessionCookieName.value} (${src(sessionCookieName.wasProvided)})`);
logger.info(` SESSION_MAX_AGE: ${sessionMaxAge.value}ms (${src(sessionMaxAge.wasProvided)})`);
logger.info(` SESSION_ROLLING: ${sessionRolling.value} (${src(sessionRolling.wasProvided)})`);
logger.info(` COOKIE_SECURE: ${cookieSecure.value} (${src(cookieSecure.wasProvided)})`);
logger.info(` COOKIE_SAMESITE: ${cookieSameSite.value} (${src(cookieSameSite.wasProvided)})`);
logger.info(' --- Database ---');
logger.debug(' --- Session/Security ---');
logger.debug(` SESSION_SECRET: ${sessionSecretProvided ? '***provided***' : '(auto-generated)'}`);
logger.debug(` SESSION_COOKIE_NAME: ${sessionCookieName.value} (${src(sessionCookieName.wasProvided)})`);
logger.debug(` SESSION_MAX_AGE: ${sessionMaxAge.value}ms (${src(sessionMaxAge.wasProvided)})`);
logger.debug(` SESSION_ROLLING: ${sessionRolling.value} (${src(sessionRolling.wasProvided)})`);
logger.debug(` COOKIE_SECURE: ${cookieSecure.value} (${src(cookieSecure.wasProvided)})`);
logger.debug(` COOKIE_SAMESITE: ${cookieSameSite.value} (${src(cookieSameSite.wasProvided)})`);
logger.debug(' --- Database ---');
logger.info(` DATABASE_TYPE: ${databaseType}`);
if (databaseUrl.wasProvided) {
logger.info(` DATABASE_URL: ***provided*** (${databaseType})`);
} else {
logger.info(` DATABASE_PATH: ${databasePath.value} (${src(databasePath.wasProvided)})`);
}
logger.info(` TRACEROUTE_HISTORY_LIMIT: ${tracerouteHistoryLimit.value} (${src(tracerouteHistoryLimit.wasProvided)})`);
logger.info(' --- Meshtastic ---');
logger.debug(` TRACEROUTE_HISTORY_LIMIT: ${tracerouteHistoryLimit.value} (${src(tracerouteHistoryLimit.wasProvided)})`);
logger.debug(' --- Meshtastic ---');
logger.info(` MESHTASTIC_NODE_IP: ${meshtasticNodeIp.value} (${src(meshtasticNodeIp.wasProvided)})`);
logger.info(` MESHTASTIC_NODE_PORT / MESHTASTIC_TCP_PORT: ${meshtasticTcpPort.value} (${src(meshtasticTcpPort.wasProvided)})`);
logger.info(` MESHTASTIC_STALE_CONNECTION_TIMEOUT: ${meshtasticStaleConnectionTimeout.value}ms (${src(meshtasticStaleConnectionTimeout.wasProvided)})`);
logger.info(` MESHTASTIC_CONNECT_TIMEOUT_MS: ${meshtasticConnectTimeoutMs.value}ms (${src(meshtasticConnectTimeoutMs.wasProvided)})`);
logger.info(` MESHTASTIC_RECONNECT_INITIAL_DELAY_MS: ${meshtasticReconnectInitialDelayMs.value}ms (${src(meshtasticReconnectInitialDelayMs.wasProvided)})`);
logger.info(` MESHTASTIC_RECONNECT_MAX_DELAY_MS: ${meshtasticReconnectMaxDelayMs.value}ms (${src(meshtasticReconnectMaxDelayMs.wasProvided)})`);
logger.info(` MESHTASTIC_MODULE_CONFIG_DELAY_MS: ${meshtasticModuleConfigDelayMs.value}ms (${src(meshtasticModuleConfigDelayMs.wasProvided)})`);
logger.debug(` MESHTASTIC_STALE_CONNECTION_TIMEOUT: ${meshtasticStaleConnectionTimeout.value}ms (${src(meshtasticStaleConnectionTimeout.wasProvided)})`);
logger.debug(` MESHTASTIC_CONNECT_TIMEOUT_MS: ${meshtasticConnectTimeoutMs.value}ms (${src(meshtasticConnectTimeoutMs.wasProvided)})`);
logger.debug(` MESHTASTIC_RECONNECT_INITIAL_DELAY_MS: ${meshtasticReconnectInitialDelayMs.value}ms (${src(meshtasticReconnectInitialDelayMs.wasProvided)})`);
logger.debug(` MESHTASTIC_RECONNECT_MAX_DELAY_MS: ${meshtasticReconnectMaxDelayMs.value}ms (${src(meshtasticReconnectMaxDelayMs.wasProvided)})`);
logger.debug(` MESHTASTIC_MODULE_CONFIG_DELAY_MS: ${meshtasticModuleConfigDelayMs.value}ms (${src(meshtasticModuleConfigDelayMs.wasProvided)})`);
if (oidcEnabled) {
logger.info(' --- OIDC ---');
logger.info(` OIDC_ISSUER: ${oidcIssuer.value ? '***provided***' : 'not set'}`);
logger.info(` OIDC_CLIENT_ID: ${oidcClientId.value ? '***provided***' : 'not set'}`);
logger.info(` OIDC_AUTO_CREATE_USERS: ${oidcAutoCreateUsers.value} (${src(oidcAutoCreateUsers.wasProvided)})`);
logger.info(` OIDC_GROUPS_CLAIM: ${oidcGroupsClaim.value} (${src(oidcGroupsClaim.wasProvided)})`);
logger.info(` OIDC_ADMIN_GROUPS: ${oidcAdminGroups.length > 0 ? oidcAdminGroups.join(', ') : 'not set (group→admin mapping disabled; first-login bootstrap applies)'}`);
logger.info(` OIDC_ALLOWED_GROUPS: ${oidcAllowedGroups.length > 0 ? oidcAllowedGroups.join(', ') : 'not set (all OIDC users allowed)'}`);
}
logger.info(' --- Authentication ---');
logger.info(` DISABLE_ANONYMOUS: ${disableAnonymous.value} (${src(disableAnonymous.wasProvided)})`);
logger.info(` DISABLE_LOCAL_AUTH: ${disableLocalAuth.value} (${src(disableLocalAuth.wasProvided)})`);
logger.debug(' --- OIDC ---');
logger.debug(` OIDC_ISSUER: ${oidcIssuer.value ? '***provided***' : 'not set'}`);
logger.debug(` OIDC_CLIENT_ID: ${oidcClientId.value ? '***provided***' : 'not set'}`);
logger.debug(` OIDC_AUTO_CREATE_USERS: ${oidcAutoCreateUsers.value} (${src(oidcAutoCreateUsers.wasProvided)})`);
logger.debug(` OIDC_GROUPS_CLAIM: ${oidcGroupsClaim.value} (${src(oidcGroupsClaim.wasProvided)})`);
logger.debug(` OIDC_ADMIN_GROUPS: ${oidcAdminGroups.length > 0 ? oidcAdminGroups.join(', ') : 'not set (group→admin mapping disabled; first-login bootstrap applies)'}`);
logger.debug(` OIDC_ALLOWED_GROUPS: ${oidcAllowedGroups.length > 0 ? oidcAllowedGroups.join(', ') : 'not set (all OIDC users allowed)'}`);
}
logger.debug(' --- Authentication ---');
logger.debug(` DISABLE_ANONYMOUS: ${disableAnonymous.value} (${src(disableAnonymous.wasProvided)})`);
logger.debug(` DISABLE_LOCAL_AUTH: ${disableLocalAuth.value} (${src(disableLocalAuth.wasProvided)})`);
if (adminUsername.wasProvided) {
logger.info(` ADMIN_USERNAME: ${adminUsername.value} (env)`);
logger.debug(` ADMIN_USERNAME: ${adminUsername.value} (env)`);
}
if (proxyAuthEnabled.value) {
logger.info(' --- Proxy Authentication ---');
logger.info(` PROXY_AUTH_ENABLED: ${proxyAuthEnabled.value}`);
logger.info(` PROXY_AUTH_AUTO_PROVISION: ${proxyAuthAutoProvision.value}`);
logger.info(` PROXY_AUTH_ADMIN_GROUPS: ${proxyAuthAdminGroups.length > 0 ? proxyAuthAdminGroups.join(', ') : 'not set'}`);
logger.info(` PROXY_AUTH_ADMIN_EMAILS: ${proxyAuthAdminEmails.length > 0 ? '***configured***' : 'not set'}`);
logger.info(` PROXY_AUTH_NORMAL_USER_GROUPS: ${proxyAuthNormalUserGroups.length > 0 ? proxyAuthNormalUserGroups.join(', ') : 'not set (all proxy users allowed)'}`);
logger.info(` PROXY_AUTH_JWT_GROUPS_CLAIM: ${proxyAuthJwtGroupsClaim}`);
logger.info(` PROXY_AUTH_AUDIT_LOGGING: ${proxyAuthAuditLogging.value}`);
logger.debug(' --- Proxy Authentication ---');
logger.debug(` PROXY_AUTH_ENABLED: ${proxyAuthEnabled.value}`);
logger.debug(` PROXY_AUTH_AUTO_PROVISION: ${proxyAuthAutoProvision.value}`);
logger.debug(` PROXY_AUTH_ADMIN_GROUPS: ${proxyAuthAdminGroups.length > 0 ? proxyAuthAdminGroups.join(', ') : 'not set'}`);
logger.debug(` PROXY_AUTH_ADMIN_EMAILS: ${proxyAuthAdminEmails.length > 0 ? '***configured***' : 'not set'}`);
logger.debug(` PROXY_AUTH_NORMAL_USER_GROUPS: ${proxyAuthNormalUserGroups.length > 0 ? proxyAuthNormalUserGroups.join(', ') : 'not set (all proxy users allowed)'}`);
logger.debug(` PROXY_AUTH_JWT_GROUPS_CLAIM: ${proxyAuthJwtGroupsClaim}`);
logger.debug(` PROXY_AUTH_AUDIT_LOGGING: ${proxyAuthAuditLogging.value}`);
if (proxyAuthLogoutUrl) {
logger.info(` PROXY_AUTH_LOGOUT_URL: ${proxyAuthLogoutUrl}`);
logger.debug(` PROXY_AUTH_LOGOUT_URL: ${proxyAuthLogoutUrl}`);
}
}
logger.info(' --- Rate Limiting ---');
logger.info(` RATE_LIMIT_API: ${rateLimitApi.value} req/min (${src(rateLimitApi.wasProvided)})`);
logger.info(` RATE_LIMIT_AUTH: ${rateLimitAuth.value} req/min (${src(rateLimitAuth.wasProvided)})`);
logger.info(` RATE_LIMIT_MESSAGES: ${rateLimitMessages.value} req/min (${src(rateLimitMessages.wasProvided)})`);
logger.debug(' --- Rate Limiting ---');
logger.debug(` RATE_LIMIT_API: ${rateLimitApi.value} req/min (${src(rateLimitApi.wasProvided)})`);
logger.debug(` RATE_LIMIT_AUTH: ${rateLimitAuth.value} req/min (${src(rateLimitAuth.wasProvided)})`);
logger.debug(` RATE_LIMIT_MESSAGES: ${rateLimitMessages.value} req/min (${src(rateLimitMessages.wasProvided)})`);
if (vapidPublicKey.wasProvided) {
logger.info(' --- Push Notifications ---');
logger.info(` VAPID keys: ***provided***`);
logger.info(` PUSH_NOTIFICATION_TTL: ${pushNotificationTtl.value}s (${src(pushNotificationTtl.wasProvided)})`);
logger.debug(' --- Push Notifications ---');
logger.debug(` VAPID keys: ***provided***`);
logger.debug(` PUSH_NOTIFICATION_TTL: ${pushNotificationTtl.value}s (${src(pushNotificationTtl.wasProvided)})`);
}
if (accessLogEnabled.value) {
logger.info(' --- Access Logging ---');
logger.info(` ACCESS_LOG_PATH: ${accessLogPath.value} (${src(accessLogPath.wasProvided)})`);
logger.info(` ACCESS_LOG_FORMAT: ${accessLogFormat.value} (${src(accessLogFormat.wasProvided)})`);
logger.debug(' --- Access Logging ---');
logger.debug(` ACCESS_LOG_PATH: ${accessLogPath.value} (${src(accessLogPath.wasProvided)})`);
logger.debug(` ACCESS_LOG_FORMAT: ${accessLogFormat.value} (${src(accessLogFormat.wasProvided)})`);
}
if (customTitle.wasProvided || customLogoUrl.wasProvided) {
logger.info(' --- Branding ---');
if (customTitle.wasProvided) logger.info(` CUSTOM_TITLE: ${customTitle.value}`);
if (customLogoUrl.wasProvided) logger.info(` CUSTOM_LOGO_URL: ${customLogoUrl.value}`);
logger.debug(' --- Branding ---');
if (customTitle.wasProvided) logger.debug(` CUSTOM_TITLE: ${customTitle.value}`);
if (customLogoUrl.wasProvided) logger.debug(` CUSTOM_LOGO_URL: ${customLogoUrl.value}`);
}

return {
Expand Down
Loading
Loading