From 8bf45938ea1c749c7577823f32e11f53d7738b11 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Mateusz=20Gruszczy=C5=84ski?= Date: Wed, 22 Jul 2026 11:15:01 +0200 Subject: [PATCH] logging --- .env.example | 4 +++- Cargo.toml | 2 +- README.md | 16 ++++++++++++++-- docker-compose.yml | 3 ++- src/app.rs | 23 ++++++++++++++++------- src/auth.rs | 35 +++++++++++++++++++++++++++++------ src/config.rs | 10 ++++++++++ src/database.rs | 4 ++++ src/main.rs | 34 ++++++++++++++++++++++++++++++++-- src/state.rs | 5 +++-- src/websocket.rs | 20 +++++++++++++------- static/js/api.js | 13 +++++++++++-- static/js/home.js | 3 +++ static/js/logger.js | 32 ++++++++++++++++++++++++++++++++ static/js/note.js | 3 +++ static/js/pad.js | 3 +++ static/js/public.js | 3 +++ static/js/socket.js | 6 ++++-- static/js/workspace.js | 3 +++ 19 files changed, 189 insertions(+), 33 deletions(-) create mode 100644 static/js/logger.js diff --git a/.env.example b/.env.example index bb9a4ea..673d674 100644 --- a/.env.example +++ b/.env.example @@ -20,7 +20,9 @@ DATABASE_MAX_CONNECTIONS=8 # Logging -RUST_LOG=rustpad=debug,tower_http=info +# available: warn, debug, info +FRONTEND_DEBUG=false +RUST_LOG=rustpad=info,tower_http=warn # Maximum upload size UPLOAD_MAX_SIZE_MB=20 diff --git a/Cargo.toml b/Cargo.toml index 9c55874..1278b50 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -1,6 +1,6 @@ [package] name = "rustpad" -version = "0.0.3" +version = "0.0.4" edition = "2024" rust-version = "1.94" description = "Collaborative Markdown notepad built with Axum, WebSockets and SQLite, PostgreSQL and MySQL" diff --git a/README.md b/README.md index 46ff677..e12ad83 100644 --- a/README.md +++ b/README.md @@ -39,7 +39,7 @@ The maximum size of a single file is configured with `UPLOAD_MAX_SIZE_MB` w `.en ## Wybór bazy danych -RustPad wybiera silnik na podstawie `DATABASE_URL`: +RustPad use db engine via `DATABASE_URL`: - SQLite: `sqlite:///data/db/rustpad.db?mode=rwc&journal_mode=WAL&busy_timeout=5000` - PostgreSQL: `postgres://rustpad:rustpad@postgres:5432/rustpad` @@ -47,7 +47,7 @@ RustPad wybiera silnik na podstawie `DATABASE_URL`: SQLite pozostaje domyślną bazą dla developmentu i małych instalacji. Tryb WAL pozwala czytać podczas zapisu, ale SQLite nadal wykonuje tylko jeden zapis naraz. `busy_timeout=5000` powoduje krótkie oczekiwanie zamiast natychmiastowego błędu `database is locked`. Przy wielu równoczesnych edytorach lub wielu instancjach aplikacji zalecany jest PostgreSQL albo MySQL. -Opcjonalne bazy w Docker Compose: +Opcjonalne db inDocker Compose: ```bash # PostgreSQL @@ -70,3 +70,15 @@ Nicknames can still be used anonymously while they remain unregistered. Register All runtime SQL statements are centralized in `src/queries.rs`. Backend modules reference named constants, which keeps database-specific debugging and query review in one place. + +## Diagnostics and logging + +Server logs use `tracing`. Configure verbosity with `RUST_LOG`, for example: + +```env +RUST_LOG=rustpad=debug,tower_http=info +``` + +Important lifecycle, database, authentication, password-reset and WebSocket events are logged. Passwords, session tokens, reset tokens, SMTP credentials and authorization headers are never logged. + +Browser diagnostics are configured separately from backend logs with `FRONTEND_LOG_LEVEL`. Supported values are `off`, `error`, `warn`, `info`, and `debug`; the default is `warn`. URL parameters cannot enable diagnostics. Use `debug` only in trusted development environments. Production should normally use `warn` or `error`. diff --git a/docker-compose.yml b/docker-compose.yml index f822abf..4ff8ebf 100644 --- a/docker-compose.yml +++ b/docker-compose.yml @@ -15,7 +15,8 @@ services: UPLOAD_MAX_SIZE_MB: ${UPLOAD_MAX_SIZE_MB:-20} ASSET_VERSION: ${ASSET_VERSION:-dev} REGISTRATION_ENABLED: ${REGISTRATION_ENABLED:-false} - RUST_LOG: ${RUST_LOG:-rustpad=info,tower_http=info} + RUST_LOG: ${RUST_LOG:-rustpad=info,tower_http=warn} + FRONTEND_LOG_LEVEL: ${FRONTEND_LOG_LEVEL:-warn} PUBLIC_URL: ${PUBLIC_URL:-http://localhost:3000} SMTP_HOST: ${SMTP_HOST:-} SMTP_PORT: ${SMTP_PORT:-587} diff --git a/src/app.rs b/src/app.rs index 76b2941..7bab803 100644 --- a/src/app.rs +++ b/src/app.rs @@ -91,7 +91,7 @@ async fn health() -> &'static str { } async fn home(State(state): State) -> Response { - versioned_html(include_str!("../static/home.html"), &state.asset_version, state.registration_enabled) + versioned_html(include_str!("../static/home.html"), &state.asset_version, state.registration_enabled, &state.frontend_log_level) } async fn pad( @@ -102,7 +102,7 @@ async fn pad( Ok(Some(pad)) => { let html = include_str!("../static/pad.html") .replace("__PAD_TITLE__", &escape_html(&pad.title)); - versioned_html(&html, &state.asset_version, state.registration_enabled) + versioned_html(&html, &state.asset_version, state.registration_enabled, &state.frontend_log_level) }, Ok(None) => error_response( StatusCode::NOT_FOUND, @@ -125,7 +125,7 @@ async fn public_page( Path(token): Path, ) -> Response { match db::find_published_page(&state.db, &token).await { - Ok(Some(_)) => versioned_html(include_str!("../static/public.html"), &state.asset_version, state.registration_enabled), + Ok(Some(_)) => versioned_html(include_str!("../static/public.html"), &state.asset_version, state.registration_enabled, &state.frontend_log_level), Ok(None) => error_response( StatusCode::NOT_FOUND, "404", @@ -150,7 +150,7 @@ async fn workspace( Ok(Some(workspace)) => { let html = include_str!("../static/workspace.html") .replace("__WORKSPACE_TITLE__", &escape_html(&workspace.title)); - versioned_html(&html, &state.asset_version, state.registration_enabled) + versioned_html(&html, &state.asset_version, state.registration_enabled, &state.frontend_log_level) }, Ok(None) => error_response( StatusCode::NOT_FOUND, @@ -197,7 +197,7 @@ async fn note( .replace("__NOTE_TITLE__", &escape_html(¬e.title)) .replace("__WORKSPACE_TITLE__", &escape_html(&workspace.title)) .replace("__WORKSPACE_SLUG__", &escape_html(&workspace_slug)); - versioned_html(&html, &state.asset_version, state.registration_enabled) + versioned_html(&html, &state.asset_version, state.registration_enabled, &state.frontend_log_level) }, Ok(None) => error_response( StatusCode::NOT_FOUND, @@ -285,15 +285,24 @@ fn error_response( response } -fn versioned_html(template: &str, asset_version: &str, registration_enabled: bool) -> Response { +fn versioned_html(template: &str, asset_version: &str, registration_enabled: bool, frontend_log_level: &str) -> Response { + let frontend_config = format!( + r#""#, + escape_js_string(frontend_log_level), + ); let html = template .replace("__ASSET_VERSION__", asset_version) - .replace("__REGISTRATION_ENABLED__", if registration_enabled { "true" } else { "false" }); + .replace("__REGISTRATION_ENABLED__", if registration_enabled { "true" } else { "false" }) + .replace("", &format!("{frontend_config}")); let mut response = Html(html).into_response(); no_store(&mut response); response } +fn escape_js_string(value: &str) -> String { + value.replace('\\', "\\\\").replace('"', "\\\"").replace('<', "\\u003c") +} + fn no_store(response: &mut Response) { response.headers_mut().insert( header::CACHE_CONTROL, diff --git a/src/auth.rs b/src/auth.rs index 4fb6c91..7479e67 100644 --- a/src/auth.rs +++ b/src/auth.rs @@ -6,6 +6,7 @@ use rand_core::{OsRng, RngCore}; use serde::{Deserialize, Serialize}; use sha2::{Digest, Sha256}; use sqlx::FromRow; +use tracing::{debug, info, warn}; use crate::{queries, state::{SharedState, SmtpConfig}}; @@ -26,21 +27,24 @@ pub struct User { pub id: i64, pub nickname: String, pub email: String, pub pass pub async fn identity(State(state): State, Json(req): Json) -> Result, AuthError> { let nickname = validate_nickname(&req.nickname)?; + debug!(nickname = %nickname, has_session = req.session_token.is_some(), "identity check requested"); match find_user_by_nickname(&state, &nickname).await? { - None => Ok(Json(IdentityResponse { nickname, registered: false })), + None => { debug!(nickname = %nickname, "nickname is available for guest use"); Ok(Json(IdentityResponse { nickname, registered: false })) }, Some(user) => { let token = req.session_token.as_deref().ok_or_else(|| AuthError::unauthorized("This nickname is registered. Log in to use it."))?; let current = user_from_token(&state, token).await?.ok_or_else(|| AuthError::unauthorized("Your session has expired. Log in again."))?; if current.id != user.id { return Err(AuthError::unauthorized("This nickname belongs to another account.")); } + info!(user_id = user.id, nickname = %user.nickname, "registered identity authorized"); Ok(Json(IdentityResponse { nickname: user.nickname, registered: true })) } } } pub async fn register(State(state): State, Json(req): Json) -> Result<(StatusCode, Json), AuthError> { - if !state.registration_enabled { return Err(AuthError::forbidden("Registration is disabled.")); } + if !state.registration_enabled { warn!("registration attempt rejected because registration is disabled"); return Err(AuthError::forbidden("Registration is disabled.")); } let nickname = validate_nickname(&req.nickname)?; let email = validate_email(&req.email)?; + info!(nickname = %nickname, email_domain = %email_domain(&email), "registration requested"); validate_password(&req.password)?; let nickname_key = normalize(&nickname); let email_key = normalize(&email); @@ -51,31 +55,41 @@ pub async fn register(State(state): State, Json(req): Json, Json(req): Json) -> Result, AuthError> { let email = validate_email(&req.email)?; + debug!(email_domain = %email_domain(&email), "login requested"); let user = find_user_by_email(&state, &email).await?.ok_or_else(|| AuthError::unauthorized("Invalid e-mail address or password."))?; - if !verify_password(&user.password_hash, &req.password) { return Err(AuthError::unauthorized("Invalid e-mail address or password.")); } - Ok(Json(create_session(&state, &user).await?)) + if !verify_password(&user.password_hash, &req.password) { warn!(user_id = user.id, "login rejected: invalid password"); return Err(AuthError::unauthorized("Invalid e-mail address or password.")); } + let session = create_session(&state, &user).await?; + info!(user_id = user.id, nickname = %user.nickname, "login successful"); + Ok(Json(session)) } pub async fn me(State(state): State, headers: HeaderMap) -> Result, AuthError> { let token = bearer(&headers).ok_or_else(|| AuthError::unauthorized("Not logged in."))?; let user = user_from_token(&state, token).await?.ok_or_else(|| AuthError::unauthorized("Your session has expired."))?; + debug!(user_id = user.id, "session validation successful"); let expires_at: String = sqlx::query_scalar(queries::get(state.db.kind(), queries::AUTH_SESSION_EXPIRES_AT)) .bind(token).fetch_one(state.db.pool()).await.map_err(AuthError::database)?; Ok(Json(SessionResponse { token: token.into(), nickname: user.nickname, email: user.email, expires_at })) } pub async fn logout(State(state): State, headers: HeaderMap) -> Result, AuthError> { - if let Some(token) = bearer(&headers) { sqlx::query(queries::get(state.db.kind(), queries::AUTH_DELETE_SESSION_BY_TOKEN)).bind(token).execute(state.db.pool()).await.map_err(AuthError::database)?; } + if let Some(token) = bearer(&headers) { + let result = sqlx::query(queries::get(state.db.kind(), queries::AUTH_DELETE_SESSION_BY_TOKEN)).bind(token).execute(state.db.pool()).await.map_err(AuthError::database)?; + info!(rows_affected = result.rows_affected(), "logout processed"); + } else { debug!("logout requested without an active session"); } Ok(Json(serde_json::json!({"ok": true}))) } pub async fn request_reset(State(state): State, Json(req): Json) -> Result, AuthError> { let email = validate_email(&req.email)?; + info!(email_domain = %email_domain(&email), "password reset requested"); let smtp = state.smtp.as_ref().ok_or_else(|| AuthError::service_unavailable("Password reset is not configured on this server."))?; if let Some(user) = find_user_by_email(&state, &email).await? { let token = random_token(); @@ -84,12 +98,16 @@ pub async fn request_reset(State(state): State, Json(req): Json, Json(req): Json) -> Result, AuthError> { validate_password(&req.password)?; + info!("password reset confirmation requested"); let now_time = Utc::now(); let now = now_time.to_rfc3339(); let token_hash = hash_token(req.token.trim()); @@ -100,6 +118,7 @@ pub async fn confirm_reset(State(state): State, Json(req): Json, Json(req): Json Result Result, AuthError> { @@ -185,4 +206,6 @@ async fn send_reset(smtp:&SmtpConfig,user:&User,token:&str)->Result<(),AuthError pub struct AuthError { status: StatusCode, pub message: String } impl AuthError { fn bad_request(m:&str)->Self{Self{status:StatusCode::BAD_REQUEST,message:m.into()}} fn unauthorized(m:&str)->Self{Self{status:StatusCode::UNAUTHORIZED,message:m.into()}} fn forbidden(m:&str)->Self{Self{status:StatusCode::FORBIDDEN,message:m.into()}} fn conflict(m:&str)->Self{Self{status:StatusCode::CONFLICT,message:m.into()}} fn internal(m:&str)->Self{Self{status:StatusCode::INTERNAL_SERVER_ERROR,message:m.into()}} fn service_unavailable(m:&str)->Self{Self{status:StatusCode::SERVICE_UNAVAILABLE,message:m.into()}} fn database(e:sqlx::Error)->Self{tracing::error!(error=%e,"authentication database error");Self::internal("Database error.")} } + +fn email_domain(email: &str) -> &str { email.rsplit_once('@').map(|(_, domain)| domain).unwrap_or("invalid") } impl axum::response::IntoResponse for AuthError { fn into_response(self)->axum::response::Response{(self.status,Json(serde_json::json!({"error":self.message}))).into_response()} } diff --git a/src/config.rs b/src/config.rs index 3b9a222..d2e116a 100644 --- a/src/config.rs +++ b/src/config.rs @@ -12,6 +12,7 @@ pub struct Config { pub asset_version: String, pub smtp: Option, pub registration_enabled: bool, + pub frontend_log_level: String, } impl Config { @@ -56,6 +57,7 @@ impl Config { asset_version: env_var("ASSET_VERSION", env!("CARGO_PKG_VERSION")), smtp, registration_enabled: env_bool("REGISTRATION_ENABLED", false)?, + frontend_log_level: env_log_level("FRONTEND_LOG_LEVEL", "warn")?, }) } } @@ -74,3 +76,11 @@ fn env_bool(name: &str, default: bool) -> Result Ok(default), } } + +fn env_log_level(name: &str, default: &str) -> Result> { + let value = env_var(name, default).trim().to_ascii_lowercase(); + match value.as_str() { + "off" | "error" | "warn" | "info" | "debug" => Ok(value), + _ => Err(format!("{name} must be one of: off, error, warn, info, debug").into()), + } +} diff --git a/src/database.rs b/src/database.rs index 3f13825..7351644 100644 --- a/src/database.rs +++ b/src/database.rs @@ -1,5 +1,6 @@ use crate::queries; use sqlx::{any::AnyPoolOptions, AnyPool}; +use tracing::{debug, info}; #[derive(Debug, Clone, Copy, PartialEq, Eq)] pub enum DatabaseKind { @@ -18,15 +19,18 @@ impl Database { pub async fn connect(url: &str, max_connections: u32) -> Result { sqlx::any::install_default_drivers(); let kind = DatabaseKind::from_url(url)?; + debug!(?kind, max_connections, "initializing database pool"); let pool = AnyPoolOptions::new() .max_connections(max_connections) .connect(url) .await?; if kind == DatabaseKind::Sqlite { + debug!("applying SQLite connection pragmas"); sqlx::query(queries::SQLITE_FOREIGN_KEYS_ON).execute(&pool).await?; sqlx::query(queries::SQLITE_JOURNAL_WAL).execute(&pool).await?; sqlx::query(queries::SQLITE_BUSY_TIMEOUT).execute(&pool).await?; } + info!(?kind, max_connections, "database pool ready"); Ok(Self { pool, kind }) } diff --git a/src/main.rs b/src/main.rs index 2fa836d..f48c734 100644 --- a/src/main.rs +++ b/src/main.rs @@ -14,7 +14,7 @@ use config::Config; use database::{Database, DatabaseKind}; use state::AppState; use tokio::net::TcpListener; -use tracing::info; +use tracing::{info, warn}; use tracing_subscriber::{layer::SubscriberExt, util::SubscriberInitExt}; #[tokio::main] @@ -23,13 +23,31 @@ async fn main() -> Result<(), Box> { init_tracing(); let config = Config::from_env()?; + info!( + host = %config.host, + port = config.port, + database_kind = %database_kind_label(&config.database_url), + database_max_connections = config.database_max_connections, + static_dir = %config.static_dir, + files_dir = %config.files_dir, + upload_max_size_bytes = config.upload_max_size_bytes, + registration_enabled = config.registration_enabled, + frontend_log_level = %config.frontend_log_level, + smtp_configured = config.smtp.is_some(), + asset_version = %config.asset_version, + "configuration loaded" + ); if let Some(path) = config.database_url.strip_prefix("sqlite://").and_then(|v| v.split('?').next()) { if let Some(parent) = std::path::Path::new(path).parent() { std::fs::create_dir_all(parent)?; } } + info!("connecting to database"); let db = Database::connect(&config.database_url, config.database_max_connections).await?; + info!(database_kind = ?db.kind(), "database connection established"); run_migrations(&db).await?; + info!(database_kind = ?db.kind(), "database migrations completed"); std::fs::create_dir_all(&config.files_dir)?; + info!(files_dir = %config.files_dir, "file storage ready"); let state = Arc::new(AppState::new( db, config.asset_version.clone(), @@ -37,6 +55,7 @@ async fn main() -> Result<(), Box> { config.upload_max_size_bytes, config.smtp.clone(), config.registration_enabled, + config.frontend_log_level.clone(), )); let app = app::router( state, @@ -50,6 +69,7 @@ async fn main() -> Result<(), Box> { axum::serve(listener, app) .with_graceful_shutdown(shutdown_signal()) .await?; + info!("RustPad stopped cleanly"); Ok(()) } @@ -78,7 +98,10 @@ async fn shutdown_signal() { }; #[cfg(not(unix))] let terminate = std::future::pending::<()>(); - tokio::select! { () = ctrl_c => {}, () = terminate => {} } + tokio::select! { + () = ctrl_c => warn!("shutdown requested by Ctrl+C"), + () = terminate => warn!("shutdown requested by SIGTERM"), + } } async fn run_migrations(db: &Database) -> Result<(), sqlx::migrate::MigrateError> { @@ -89,3 +112,10 @@ async fn run_migrations(db: &Database) -> Result<(), sqlx::migrate::MigrateError }; sqlx::migrate::Migrator::new(path).await?.run(db.pool()).await } + +fn database_kind_label(url: &str) -> &'static str { + if url.starts_with("sqlite:") { "sqlite" } + else if url.starts_with("postgres:") || url.starts_with("postgresql:") { "postgres" } + else if url.starts_with("mysql:") { "mysql" } + else { "unknown" } +} diff --git a/src/state.rs b/src/state.rs index fde8609..be487b3 100644 --- a/src/state.rs +++ b/src/state.rs @@ -24,12 +24,13 @@ pub struct AppState { pub upload_max_size_bytes: usize, pub smtp: Option, pub registration_enabled: bool, + pub frontend_log_level: String, channels: RwLock>>, } impl AppState { - pub fn new(db: Database, asset_version: String, files_dir: String, upload_max_size_bytes: usize, smtp: Option, registration_enabled: bool) -> Self { - Self { db, asset_version, files_dir, upload_max_size_bytes, smtp, registration_enabled, channels: RwLock::new(HashMap::new()) } + pub fn new(db: Database, asset_version: String, files_dir: String, upload_max_size_bytes: usize, smtp: Option, registration_enabled: bool, frontend_log_level: String) -> Self { + Self { db, asset_version, files_dir, upload_max_size_bytes, smtp, registration_enabled, frontend_log_level, channels: RwLock::new(HashMap::new()) } } async fn channel_for_key(&self, key: String) -> broadcast::Sender { if let Some(sender) = self.channels.read().await.get(&key) { return sender.clone(); } diff --git a/src/websocket.rs b/src/websocket.rs index a410742..6894c9e 100644 --- a/src/websocket.rs +++ b/src/websocket.rs @@ -1,7 +1,7 @@ use axum::{extract::{ws::{Message, WebSocket}, Path, State, WebSocketUpgrade}, response::Response}; use futures_util::{SinkExt, StreamExt}; use serde::{Deserialize, Serialize}; -use tracing::{debug, warn}; +use tracing::{debug, info, warn}; use crate::{auth, db, state::{NoteUpdate, SharedState}}; #[derive(Debug, Deserialize)] @@ -24,8 +24,9 @@ pub async fn upgrade(ws: WebSocketUpgrade, Path((workspace_slug, note_slug)): Pa } async fn handle_socket(mut socket: WebSocket, state: SharedState, workspace_slug: String, note_slug: String) { - let Some(workspace) = db::find_workspace(&state.db, &workspace_slug).await.ok().flatten() else { let _=send_error(&mut socket,"Workspace not found").await; return; }; - let Some(note) = db::find_note(&state.db, workspace.id, ¬e_slug).await.ok().flatten() else { let _=send_error(&mut socket,"Note not found").await; return; }; + info!(%workspace_slug, %note_slug, "note websocket connected"); + let Some(workspace) = db::find_workspace(&state.db, &workspace_slug).await.ok().flatten() else { warn!(%workspace_slug, %note_slug, "note websocket rejected: workspace not found"); let _=send_error(&mut socket,"Workspace not found").await; return; }; + let Some(note) = db::find_note(&state.db, workspace.id, ¬e_slug).await.ok().flatten() else { warn!(%workspace_slug, %note_slug, "note websocket rejected: note not found"); let _=send_error(&mut socket,"Note not found").await; return; }; let (password, nickname, session_token) = match socket.recv().await { Some(Ok(Message::Text(text))) => match serde_json::from_str::(&text) { Ok(ClientMessage::Authenticate { password, nickname, session_token }) => (password, clean_nickname(nickname), session_token), @@ -33,7 +34,8 @@ async fn handle_socket(mut socket: WebSocket, state: SharedState, workspace_slug }, _ => return }; let nickname = match auth::authorize_nickname(&state, nickname, session_token).await { Ok(value) => value, Err(message) => { let _=send_error(&mut socket,&message).await; return; } }; - if !db::verify_workspace_password(&workspace, password.as_deref()) { let _=send_error(&mut socket,"Invalid password").await; return; } + if !db::verify_workspace_password(&workspace, password.as_deref()) { warn!(workspace_id = workspace.id, note_id = note.id, "note websocket rejected: invalid workspace password"); let _=send_error(&mut socket,"Invalid password").await; return; } + info!(workspace_id = workspace.id, note_id = note.id, nickname = ?nickname, "note websocket authenticated"); if send(&mut socket,&ServerMessage::Authenticated { workspace_title:workspace.title.clone(), note_title:note.title.clone(), content:note.content.clone(), owner_map:note.owner_map.clone() }).await.is_err(){return;} let channel=state.note_channel(&workspace_slug,¬e_slug).await; let mut updates=channel.subscribe(); @@ -46,7 +48,7 @@ async fn handle_socket(mut socket: WebSocket, state: SharedState, workspace_slug let owner_map=owner_map.unwrap_or_else(||"[]".into()); match db::save_revision(&state.db,note.id,workspace.id,&content,nickname.as_deref(),&owner_map).await { Ok((revision_id,updated_at))=>{let _=channel.send(NoteUpdate{content,revision_id,updated_at,author:nickname.clone(),owner_map});} - Err(error)=>warn!(%error,"failed to save revision"), + Err(error)=>warn!(%error, workspace_id = workspace.id, note_id = note.id, "failed to save revision"), } } Ok(ClientMessage::Authenticate{..})=>{}, Err(error)=>warn!(%error,"invalid websocket message"), @@ -59,6 +61,7 @@ async fn handle_socket(mut socket: WebSocket, state: SharedState, workspace_slug Err(tokio::sync::broadcast::error::RecvError::Closed)=>break, } }} + info!(workspace_id = workspace.id, note_id = note.id, "note websocket disconnected"); } fn clean_nickname(value: Option)->Option{value.map(|v|v.trim().chars().take(40).collect::()).filter(|v|!v.is_empty())} async fn send_error(socket:&mut WebSocket,message:&str)->Result<(),axum::Error>{send(socket,&ServerMessage::Error{message:message.into()}).await} @@ -76,7 +79,8 @@ pub async fn upgrade_pad(ws:WebSocketUpgrade,Path(slug):Path,State(state ws.on_upgrade(move|socket|handle_pad_socket(socket,state,slug)) } async fn handle_pad_socket(mut socket:WebSocket,state:SharedState,slug:String){ - let Some(pad)=db::find_pad(&state.db,&slug).await.ok().flatten() else {let _=send_pad(&mut socket,&PadServerMessage::Error{message:"Note not found".into()}).await;return;}; + info!(%slug, "pad websocket connected"); + let Some(pad)=db::find_pad(&state.db,&slug).await.ok().flatten() else {warn!(%slug, "pad websocket rejected: pad not found");let _=send_pad(&mut socket,&PadServerMessage::Error{message:"Note not found".into()}).await;return;}; let (password,nickname,session_token)=match socket.recv().await{ Some(Ok(Message::Text(text)))=>match serde_json::from_str::(&text){ Ok(ClientMessage::Authenticate{password,nickname,session_token})=>(password,clean_nickname(nickname),session_token), @@ -84,7 +88,8 @@ async fn handle_pad_socket(mut socket:WebSocket,state:SharedState,slug:String){ },_=>return }; let nickname=match auth::authorize_nickname(&state,nickname,session_token).await{Ok(value)=>value,Err(message)=>{let _=send_pad(&mut socket,&PadServerMessage::Error{message}).await;return;}}; - if !db::verify_pad_password(&pad,password.as_deref()){let _=send_pad(&mut socket,&PadServerMessage::Error{message:"Invalid password".into()}).await;return;} + if !db::verify_pad_password(&pad,password.as_deref()){warn!(pad_id = pad.id, "pad websocket rejected: invalid password");let _=send_pad(&mut socket,&PadServerMessage::Error{message:"Invalid password".into()}).await;return;} + info!(pad_id = pad.id, nickname = ?nickname, "pad websocket authenticated"); if send_pad(&mut socket,&PadServerMessage::Authenticated{title:pad.title.clone(),content:pad.content.clone(),owner_map:pad.owner_map.clone()}).await.is_err(){return;} let channel=state.pad_channel(&slug).await; let mut updates=channel.subscribe(); @@ -112,6 +117,7 @@ async fn handle_pad_socket(mut socket:WebSocket,state:SharedState,slug:String){ Err(tokio::sync::broadcast::error::RecvError::Closed)=>break, } }} + info!(pad_id = pad.id, "pad websocket disconnected"); } async fn send_pad(socket:&mut WebSocket,message:&PadServerMessage)->Result<(),axum::Error>{socket.send(Message::Text(serde_json::to_string(message).unwrap().into())).await} async fn send_pad_split(sender:&mut futures_util::stream::SplitSink,message:&PadServerMessage)->Result<(),axum::Error>{sender.send(Message::Text(serde_json::to_string(message).unwrap().into())).await} diff --git a/static/js/api.js b/static/js/api.js index ff28dda..854160a 100644 --- a/static/js/api.js +++ b/static/js/api.js @@ -1,19 +1,28 @@ +import { logDebug, logError, logWarn } from "./logger.js"; + export async function api(path, options = {}) { const controller = new AbortController(); const timeout = setTimeout(() => controller.abort(), 12000); try { const headers = new Headers(options.headers || {}); if (!(options.body instanceof FormData) && !headers.has("content-type")) headers.set("content-type", "application/json"); + const started = performance.now(); + logDebug("api.request", { method: options.method || "GET", path }); const response = await fetch(path, { ...options, headers, signal: controller.signal }); + const durationMs = Math.round(performance.now() - started); + logDebug("api.response", { method: options.method || "GET", path, status: response.status, durationMs }); const contentType = response.headers.get("content-type") || ""; const data = contentType.includes("application/json") ? await response.json().catch(() => ({})) : {}; if (!response.ok) { const defaults = { 400: "Invalid request.", 401: "Authentication required.", 403: "Access denied.", 404: "The requested resource was not found.", 405: "This operation is not allowed.", 409: "The requested change conflicts with existing data.", 413: "The uploaded data is too large.", 429: "Too many requests. Try again later.", 500: "Server error. Try again later.", 503: "Service temporarily unavailable." }; - throw new Error(data.error || defaults[response.status] || `Request failed (${response.status}).`); + const requestError = new Error(data.error || defaults[response.status] || `Request failed (${response.status}).`); + logWarn("api.failed", { method: options.method || "GET", path, status: response.status, message: requestError.message }); + throw requestError; } return data; } catch (error) { - if (error.name === "AbortError") throw new Error("Timed out"); + if (error.name === "AbortError") { logWarn("api.timeout", { method: options.method || "GET", path }); throw new Error("Timed out"); } + logError("api.network_error", error, { method: options.method || "GET", path }); throw error; } finally { clearTimeout(timeout); } } diff --git a/static/js/home.js b/static/js/home.js index 2c54c98..7fb2e9b 100644 --- a/static/js/home.js +++ b/static/js/home.js @@ -1,3 +1,6 @@ +import { installGlobalDiagnostics, logInfo } from "./logger.js"; +installGlobalDiagnostics(); + import { bindIdentityDialog, handleResetToken, logoutCurrentSession, validateCurrentSession } from "./auth-ui.js"; import { api } from "@rustpad/api"; diff --git a/static/js/logger.js b/static/js/logger.js new file mode 100644 index 0000000..e8ce3fd --- /dev/null +++ b/static/js/logger.js @@ -0,0 +1,32 @@ +const PREFIX = "[RustPad]"; +const LEVELS = Object.freeze({ off: 0, error: 1, warn: 2, info: 3, debug: 4 }); + +function configuredLevel() { + const configured = window.__RUSTPAD_CONFIG__?.frontendLogLevel; + return Object.prototype.hasOwnProperty.call(LEVELS, configured) ? configured : "warn"; +} + +function enabled(level) { + return LEVELS[configuredLevel()] >= LEVELS[level]; +} + +function safeDetails(details) { + if (!details || typeof details !== "object") return details; + const blocked = /password|token|secret|authorization|cookie|email|content/i; + return Object.fromEntries(Object.entries(details).map(([key, value]) => [key, blocked.test(key) ? "[redacted]" : value])); +} + +export function logInfo(event, details = {}) { if (enabled("info")) console.info(PREFIX, event, safeDetails(details)); } +export function logWarn(event, details = {}) { if (enabled("warn")) console.warn(PREFIX, event, safeDetails(details)); } +export function logError(event, error, details = {}) { + if (enabled("error")) console.error(PREFIX, event, { ...safeDetails(details), error: error instanceof Error ? error.message : String(error) }); +} +export function logDebug(event, details = {}) { if (enabled("debug")) console.debug(PREFIX, event, safeDetails(details)); } + +export function installGlobalDiagnostics() { + logInfo("frontend.initialized", { path: location.pathname, assetVersion: document.body?.dataset.assetVersion || "unknown", logLevel: configuredLevel() }); + window.addEventListener("error", (event) => logError("frontend.uncaught_error", event.error || event.message, { file: event.filename, line: event.lineno, column: event.colno })); + window.addEventListener("unhandledrejection", (event) => logError("frontend.unhandled_rejection", event.reason)); + window.addEventListener("online", () => logInfo("network.online")); + window.addEventListener("offline", () => logWarn("network.offline")); +} diff --git a/static/js/note.js b/static/js/note.js index cd298cd..03f7d2c 100644 --- a/static/js/note.js +++ b/static/js/note.js @@ -1,3 +1,6 @@ +import { installGlobalDiagnostics, logInfo } from "./logger.js"; +installGlobalDiagnostics(); + import { api } from "@rustpad/api"; import { copyText } from "@rustpad/clipboard"; import { applyFormat, bindFormatShortcuts } from "@rustpad/editor-format"; diff --git a/static/js/pad.js b/static/js/pad.js index 74dbece..8c0daae 100644 --- a/static/js/pad.js +++ b/static/js/pad.js @@ -1,3 +1,6 @@ +import { installGlobalDiagnostics, logInfo } from "./logger.js"; +installGlobalDiagnostics(); + import { api } from "@rustpad/api"; import { copyText } from "@rustpad/clipboard"; import { applyFormat, bindFormatShortcuts } from "@rustpad/editor-format"; diff --git a/static/js/public.js b/static/js/public.js index 7228242..0bbb79b 100644 --- a/static/js/public.js +++ b/static/js/public.js @@ -1,3 +1,6 @@ +import { installGlobalDiagnostics, logInfo } from "./logger.js"; +installGlobalDiagnostics(); + import { api } from "@rustpad/api"; import { copyText } from "@rustpad/clipboard"; import { renderMarkdown } from "@rustpad/markdown"; diff --git a/static/js/socket.js b/static/js/socket.js index 0bf589e..8a595dc 100644 --- a/static/js/socket.js +++ b/static/js/socket.js @@ -1,11 +1,13 @@ +import { logDebug, logError, logInfo, logWarn } from "./logger.js"; + export class NoteSocket { constructor({ workspaceSlug, noteSlug, password, nickname, sessionToken, onStatus, onAuthenticated, onDocument, onError }) { Object.assign(this, { workspaceSlug, noteSlug, password, nickname, sessionToken, onStatus, onAuthenticated, onDocument, onError }); this.socket=null; this.timer=null; this.closed=false; } - connect() { clearTimeout(this.timer); this.closed=false; this.onStatus?.("connecting"); const protocol=location.protocol==="https:"?"wss:":"ws:"; this.socket=new WebSocket(`${protocol}//${location.host}/ws/${encodeURIComponent(this.workspaceSlug)}/${encodeURIComponent(this.noteSlug)}`); this.socket.addEventListener("open",()=>this.socket.send(JSON.stringify({type:"authenticate",password:this.password||null,nickname:this.nickname||null,session_token:this.sessionToken||null}))); this.socket.addEventListener("message",event=>{const m=JSON.parse(event.data); if(m.type==="error"){this.onError?.(m.message);this.closed=true;this.socket.close();} if(m.type==="authenticated"){this.onStatus?.("online");this.onAuthenticated?.(m);} if(m.type==="document")this.onDocument?.(m);}); this.socket.addEventListener("close",()=>{if(!this.closed){this.onStatus?.("offline");this.timer=setTimeout(()=>this.connect(),1500);}}); this.socket.addEventListener("error",()=>{this.onError?.("Failed to connect to the WebSocket server");this.socket.close();}); } + connect() { clearTimeout(this.timer); this.closed=false; this.onStatus?.("connecting"); const protocol=location.protocol==="https:"?"wss:":"ws:"; this.socket=new WebSocket(`${protocol}//${location.host}/ws/${encodeURIComponent(this.workspaceSlug)}/${encodeURIComponent(this.noteSlug)}`); this.socket.addEventListener("open",()=>{logInfo("websocket.open",{kind:"note",workspace:this.workspaceSlug,note:this.noteSlug});this.socket.send(JSON.stringify({type:"authenticate",password:this.password||null,nickname:this.nickname||null,session_token:this.sessionToken||null}));}); this.socket.addEventListener("message",event=>{const m=JSON.parse(event.data); if(m.type==="error"){this.onError?.(m.message);this.closed=true;this.socket.close();} if(m.type==="authenticated"){logInfo("websocket.authenticated",{kind:"note",workspace:this.workspaceSlug,note:this.noteSlug});this.onStatus?.("online");this.onAuthenticated?.(m);} if(m.type==="document")this.onDocument?.(m);}); this.socket.addEventListener("close",event=>{logWarn("websocket.close",{kind:"note",code:event.code,reason:event.reason||"",intentional:this.closed});if(!this.closed){this.onStatus?.("offline");this.timer=setTimeout(()=>this.connect(),1500);}}); this.socket.addEventListener("error",event=>{logError("websocket.error",event,{kind:"note"});this.onError?.("Failed to connect to the WebSocket server");this.socket.close();}); } update(content, ownerMap="[]") { if(this.socket?.readyState===WebSocket.OPEN)this.socket.send(JSON.stringify({type:"update",content,owner_map:ownerMap})); } stop(){this.closed=true;clearTimeout(this.timer);this.socket?.close();} } export class PadSocket { constructor({slug,password,nickname,sessionToken,onStatus,onAuthenticated,onDocument,onError}){Object.assign(this,{slug,password,nickname,sessionToken,onStatus,onAuthenticated,onDocument,onError});this.socket=null;this.timer=null;this.closed=false;} - connect(){clearTimeout(this.timer);this.closed=false;this.onStatus?.("connecting");const protocol=location.protocol==="https:"?"wss:":"ws:";this.socket=new WebSocket(`${protocol}//${location.host}/ws/p/${encodeURIComponent(this.slug)}`);this.socket.addEventListener("open",()=>this.socket.send(JSON.stringify({type:"authenticate",password:this.password||null,nickname:this.nickname||null,session_token:this.sessionToken||null})));this.socket.addEventListener("message",e=>{const m=JSON.parse(e.data);if(m.type==="error"){this.onError?.(m.message);this.closed=true;this.socket.close();}if(m.type==="authenticated"){this.onStatus?.("online");this.onAuthenticated?.(m);}if(m.type==="document")this.onDocument?.(m);});this.socket.addEventListener("close",()=>{if(!this.closed){this.onStatus?.("offline");this.timer=setTimeout(()=>this.connect(),1500);}});this.socket.addEventListener("error",()=>{this.onError?.("Failed to connect to the WebSocket server");this.socket.close();});} + connect(){clearTimeout(this.timer);this.closed=false;this.onStatus?.("connecting");const protocol=location.protocol==="https:"?"wss:":"ws:";this.socket=new WebSocket(`${protocol}//${location.host}/ws/p/${encodeURIComponent(this.slug)}`);this.socket.addEventListener("open",()=>{logInfo("websocket.open",{kind:"note",workspace:this.workspaceSlug,note:this.noteSlug});this.socket.send(JSON.stringify({type:"authenticate",password:this.password||null,nickname:this.nickname||null,session_token:this.sessionToken||null}));});this.socket.addEventListener("message",e=>{const m=JSON.parse(e.data);if(m.type==="error"){this.onError?.(m.message);this.closed=true;this.socket.close();}if(m.type==="authenticated"){logInfo("websocket.authenticated",{kind:"note",workspace:this.workspaceSlug,note:this.noteSlug});this.onStatus?.("online");this.onAuthenticated?.(m);}if(m.type==="document")this.onDocument?.(m);});this.socket.addEventListener("close",event=>{logWarn("websocket.close",{kind:"note",code:event.code,reason:event.reason||"",intentional:this.closed});if(!this.closed){this.onStatus?.("offline");this.timer=setTimeout(()=>this.connect(),1500);}});this.socket.addEventListener("error",event=>{logError("websocket.error",event,{kind:"note"});this.onError?.("Failed to connect to the WebSocket server");this.socket.close();});} update(content,ownerMap="[]"){if(this.socket?.readyState===WebSocket.OPEN)this.socket.send(JSON.stringify({type:"update",content,owner_map:ownerMap}));} stop(){this.closed=true;clearTimeout(this.timer);this.socket?.close();} } diff --git a/static/js/workspace.js b/static/js/workspace.js index ad9c6a3..6d25968 100644 --- a/static/js/workspace.js +++ b/static/js/workspace.js @@ -1,3 +1,6 @@ +import { installGlobalDiagnostics, logInfo } from "./logger.js"; +installGlobalDiagnostics(); + import { api } from "@rustpad/api"; import { copyText } from "@rustpad/clipboard"; import { getNickname, getPassword, setPassword } from "@rustpad/session";