diff --git a/.changeset/add-structured-logging.md b/.changeset/add-structured-logging.md new file mode 100644 index 00000000..a8b2db3f --- /dev/null +++ b/.changeset/add-structured-logging.md @@ -0,0 +1,11 @@ +--- +"@googleworkspace/cli": minor +--- + +Add opt-in structured HTTP request logging via `tracing` + +New environment variables: +- `GOOGLE_WORKSPACE_CLI_LOG`: stderr log filter (e.g., `gws=debug`) +- `GOOGLE_WORKSPACE_CLI_LOG_FILE`: directory for JSON log files with daily rotation + +Logging is completely silent by default (zero overhead). Only PII-free metadata is logged: API method ID, HTTP method, status code, latency, and content-type. diff --git a/AGENTS.md b/AGENTS.md index 5b138897..77a852e7 100644 --- a/AGENTS.md +++ b/AGENTS.md @@ -56,6 +56,7 @@ The CLI uses a **two-phase argument parsing** strategy: | `src/executor.rs` | HTTP request construction, response handling, schema validation | | `src/schema.rs` | `gws schema` command — introspect API method schemas | | `src/error.rs` | Structured JSON error output | +| `src/logging.rs` | Opt-in structured logging (stderr + file) via `tracing` | ## Demo Videos @@ -202,4 +203,11 @@ Use these labels to categorize pull requests and issues: |---|---| | `GOOGLE_WORKSPACE_PROJECT_ID` | GCP project ID override for quota/billing and fallback for helper commands (overridden by `--project` flag) | +### Logging + +| Variable | Description | +|---|---| +| `GOOGLE_WORKSPACE_CLI_LOG` | Log level filter for stderr output (e.g., `gws=debug`). Off by default. | +| `GOOGLE_WORKSPACE_CLI_LOG_FILE` | Directory for JSON-line log files with daily rotation. Off by default. | + All variables can also live in a `.env` file (loaded via `dotenvy`). diff --git a/Cargo.lock b/Cargo.lock index 198e3212..52f735fd 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -373,6 +373,21 @@ dependencies = [ "libc", ] +[[package]] +name = "crossbeam-channel" +version = "0.5.15" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "82b8f8f868b36967f9606790d1903570de9ceaf870a7bf9fbbd3016d636a2cb2" +dependencies = [ + "crossbeam-utils", +] + +[[package]] +name = "crossbeam-utils" +version = "0.8.21" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "d0a5c400df2834b80a4c3327b3aad3a4c4cd4de0629063962b03235697506a28" + [[package]] name = "crossterm" version = "0.29.0" @@ -890,6 +905,9 @@ dependencies = [ "thiserror 2.0.18", "tokio", "tokio-util", + "tracing", + "tracing-appender", + "tracing-subscriber", "yup-oauth2", "zeroize", ] @@ -1417,6 +1435,15 @@ dependencies = [ "winapi", ] +[[package]] +name = "matchers" +version = "0.2.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "d1525a2a28c7f4fa0fc98bb91ae755d1e2d1505079e05539e35bc876b5d65ae9" +dependencies = [ + "regex-automata", +] + [[package]] name = "memchr" version = "2.8.0" @@ -1479,6 +1506,15 @@ dependencies = [ "minimal-lexical", ] +[[package]] +name = "nu-ansi-term" +version = "0.50.3" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "7957b9740744892f114936ab4a57b3f487491bbeafaf8083688b16841a4240e5" +dependencies = [ + "windows-sys 0.61.2", +] + [[package]] name = "num-conv" version = "0.2.0" @@ -2344,6 +2380,15 @@ dependencies = [ "digest", ] +[[package]] +name = "sharded-slab" +version = "0.1.7" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "f40ca3c46823713e0d4209592e8d6e826aa57e928f09752619fc696c499637f6" +dependencies = [ + "lazy_static", +] + [[package]] name = "shlex" version = "1.3.0" @@ -2612,6 +2657,15 @@ dependencies = [ "syn 2.0.117", ] +[[package]] +name = "thread_local" +version = "1.1.9" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "f60246a4944f24f6e018aa17cdeffb7818b76356965d03b07d6a9886e8962185" +dependencies = [ + "cfg-if", +] + [[package]] name = "time" version = "0.3.47" @@ -2619,6 +2673,7 @@ source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "743bd48c283afc0388f9b8827b976905fb217ad9e647fae3a379a9283c4def2c" dependencies = [ "deranged", + "itoa", "libc", "num-conv", "num_threads", @@ -2772,9 +2827,33 @@ source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "63e71662fa4b2a2c3a26f570f037eb95bb1f85397f3cd8076caed2f026a6d100" dependencies = [ "pin-project-lite", + "tracing-attributes", "tracing-core", ] +[[package]] +name = "tracing-appender" +version = "0.2.4" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "786d480bce6247ab75f005b14ae1624ad978d3029d9113f0a22fa1ac773faeaf" +dependencies = [ + "crossbeam-channel", + "thiserror 2.0.18", + "time", + "tracing-subscriber", +] + +[[package]] +name = "tracing-attributes" +version = "0.1.31" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "7490cfa5ec963746568740651ac6781f701c9c5ea257c58e057f3ba8cf69e8da" +dependencies = [ + "proc-macro2", + "quote", + "syn 2.0.117", +] + [[package]] name = "tracing-core" version = "0.1.36" @@ -2782,6 +2861,49 @@ source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "db97caf9d906fbde555dd62fa95ddba9eecfd14cb388e4f491a66d74cd5fb79a" dependencies = [ "once_cell", + "valuable", +] + +[[package]] +name = "tracing-log" +version = "0.2.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "ee855f1f400bd0e5c02d150ae5de3840039a3f54b025156404e34c23c03f47c3" +dependencies = [ + "log", + "once_cell", + "tracing-core", +] + +[[package]] +name = "tracing-serde" +version = "0.2.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "704b1aeb7be0d0a84fc9828cae51dab5970fee5088f83d1dd7ee6f6246fc6ff1" +dependencies = [ + "serde", + "tracing-core", +] + +[[package]] +name = "tracing-subscriber" +version = "0.3.23" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "cb7f578e5945fb242538965c2d0b04418d38ec25c79d160cd279bf0731c8d319" +dependencies = [ + "matchers", + "nu-ansi-term", + "once_cell", + "regex-automata", + "serde", + "serde_json", + "sharded-slab", + "smallvec", + "thread_local", + "tracing", + "tracing-core", + "tracing-log", + "tracing-serde", ] [[package]] @@ -2895,6 +3017,12 @@ dependencies = [ "wasm-bindgen", ] +[[package]] +name = "valuable" +version = "0.1.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "ba73ea9cf16a25df0c8caa16c51acb937d5712a8429db78a3ee29d5dcacd3a65" + [[package]] name = "version_check" version = "0.9.5" diff --git a/Cargo.toml b/Cargo.toml index 8aa0db22..d04399b0 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -58,6 +58,9 @@ async-trait = "0.1.89" serde_yaml = "0.9.34" percent-encoding = "2.3.2" zeroize = { version = "1.8.2", features = ["derive"] } +tracing = "0.1" +tracing-subscriber = { version = "0.3", features = ["env-filter", "json"] } +tracing-appender = "0.2" [target.'cfg(target_os = "macos")'.dependencies] keyring = { version = "3.6.3", features = ["apple-native"] } diff --git a/README.md b/README.md index bd7de02c..e098a036 100644 --- a/README.md +++ b/README.md @@ -383,6 +383,8 @@ All variables are optional. See [`.env.example`](.env.example) for a copy-paste | `GOOGLE_WORKSPACE_CLI_CONFIG_DIR` | Override config directory (default: `~/.config/gws`) | | `GOOGLE_WORKSPACE_CLI_SANITIZE_TEMPLATE` | Default Model Armor template | | `GOOGLE_WORKSPACE_CLI_SANITIZE_MODE` | `warn` (default) or `block` | +| `GOOGLE_WORKSPACE_CLI_LOG` | Log level for stderr (e.g., `gws=debug`). Off by default. | +| `GOOGLE_WORKSPACE_CLI_LOG_FILE` | Directory for JSON log files with daily rotation. Off by default. | | `GOOGLE_WORKSPACE_PROJECT_ID` | GCP project ID override for quota/billing and fallback for helper commands | Environment variables can also be set in a `.env` file (loaded via [dotenvy](https://crates.io/crates/dotenvy)). diff --git a/src/client.rs b/src/client.rs index eb838852..6c08318d 100644 --- a/src/client.rs +++ b/src/client.rs @@ -41,6 +41,13 @@ pub async fn send_with_retry( .and_then(|s| s.parse::().ok()) .unwrap_or(1 << attempt); // 1, 2, 4 seconds + tracing::debug!( + attempt = attempt + 1, + max_retries = MAX_RETRIES, + retry_after_secs = retry_after, + "Rate limited, retrying" + ); + tokio::time::sleep(std::time::Duration::from_secs(retry_after)).await; } diff --git a/src/discovery.rs b/src/discovery.rs index b4fa9ff1..2af4a669 100644 --- a/src/discovery.rs +++ b/src/discovery.rs @@ -207,6 +207,7 @@ pub async fn fetch_discovery_document( if modified.elapsed().unwrap_or_default() < std::time::Duration::from_secs(86400) { let data = std::fs::read_to_string(&cache_file)?; let doc: RestDescription = serde_json::from_str(&data)?; + tracing::debug!(service = %service, version = %version, "Discovery cache hit"); return Ok(doc); } } @@ -219,6 +220,7 @@ pub async fn fetch_discovery_document( crate::validate::encode_path_segment(version), ); + tracing::debug!(service = %service, version = %version, "Fetching discovery document"); let client = crate::client::build_client()?; let resp = client.get(&url).send().await?; diff --git a/src/executor.rs b/src/executor.rs index ab08ea0d..73fd772f 100644 --- a/src/executor.rs +++ b/src/executor.rs @@ -422,7 +422,10 @@ pub async fn execute_method( ) .await?; + let method_id = method.id.as_deref().unwrap_or("unknown"); + let start = std::time::Instant::now(); let response = request.send().await.context("HTTP request failed")?; + let latency_ms = start.elapsed().as_millis() as u64; let status = response.status(); let content_type = response @@ -434,9 +437,27 @@ pub async fn execute_method( if !status.is_success() { let error_body = response.text().await.unwrap_or_default(); + tracing::warn!( + api_method = method_id, + http_method = %method.http_method, + status = status.as_u16(), + latency_ms = latency_ms, + "API error" + ); return handle_error_response(status, &error_body, &auth_method); } + tracing::debug!( + api_method = method_id, + http_method = %method.http_method, + status = status.as_u16(), + latency_ms = latency_ms, + content_type = %content_type, + is_upload = input.is_upload, + page = pages_fetched, + "API request" + ); + let is_json = content_type.contains("application/json") || content_type.contains("text/json"); diff --git a/src/logging.rs b/src/logging.rs new file mode 100644 index 00000000..434ce9e0 --- /dev/null +++ b/src/logging.rs @@ -0,0 +1,112 @@ +// Copyright 2026 Google LLC +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +//! Structured Logging +//! +//! Provides opt-in, PII-free logging for HTTP requests and CLI operations. +//! All output goes to stderr or a log file — stdout remains clean for +//! machine-consumable JSON output. +//! +//! ## Environment Variables +//! +//! - `GOOGLE_WORKSPACE_CLI_LOG`: Filter directive for stderr logging +//! (e.g., `gws=debug`, `gws=trace`). If unset, no stderr logging. +//! +//! - `GOOGLE_WORKSPACE_CLI_LOG_FILE`: Directory path for JSON-line log +//! files with daily rotation. If unset, no file logging. + +use tracing_subscriber::prelude::*; + +/// Environment variable controlling stderr log output. +const ENV_LOG: &str = "GOOGLE_WORKSPACE_CLI_LOG"; + +/// Environment variable controlling file log output. +const ENV_LOG_FILE: &str = "GOOGLE_WORKSPACE_CLI_LOG_FILE"; + +/// Initialize the tracing subscriber based on environment variables. +/// +/// If neither `GOOGLE_WORKSPACE_CLI_LOG` nor `GOOGLE_WORKSPACE_CLI_LOG_FILE` +/// is set, this is a no-op and logging adds zero overhead. +/// +/// This function must be called at most once (typically in `main()`). +/// Subsequent calls will silently fail (tracing only allows one global +/// subscriber). +pub fn init_logging() { + let stderr_filter = std::env::var(ENV_LOG).ok(); + let log_file_dir = std::env::var(ENV_LOG_FILE).ok(); + + // If neither env var is set, skip initialization entirely for zero overhead. + if stderr_filter.is_none() && log_file_dir.is_none() { + return; + } + + let registry = tracing_subscriber::registry(); + + // Stderr layer: human-readable, filtered by GOOGLE_WORKSPACE_CLI_LOG + let stderr_layer = stderr_filter.map(|filter| { + let env_filter = tracing_subscriber::EnvFilter::new(filter); + tracing_subscriber::fmt::layer() + .with_writer(std::io::stderr) + .with_target(false) + .compact() + .with_filter(env_filter) + }); + + // File layer: JSON-line output with daily rotation + let (file_layer, _guard) = if let Some(ref dir) = log_file_dir { + let file_appender = tracing_appender::rolling::daily(dir, "gws.log"); + let (non_blocking, guard) = tracing_appender::non_blocking(file_appender); + let layer = tracing_subscriber::fmt::layer() + .json() + .with_writer(non_blocking) + .with_target(true) + .with_filter(tracing_subscriber::EnvFilter::new("gws=debug")); + (Some(layer), Some(guard)) + } else { + (None, None) + }; + + // Compose layers and set as global subscriber. + // The guard is leaked intentionally so the non-blocking writer stays + // alive for the lifetime of the process. + let subscriber = registry.with(stderr_layer).with(file_layer); + if tracing::subscriber::set_global_default(subscriber).is_ok() { + if let Some(guard) = _guard { + // Leak the guard so the non-blocking writer lives for the process lifetime. + // This is the recommended pattern from tracing-appender docs. + std::mem::forget(guard); + } + } +} + +#[cfg(test)] +mod tests { + use super::*; + + #[test] + fn test_init_logging_default_no_panic() { + // With no env vars set, init_logging should be a no-op and not panic. + // We can't truly test the global subscriber in unit tests (it's global state), + // but we can verify the early-return path doesn't panic. + std::env::remove_var(ENV_LOG); + std::env::remove_var(ENV_LOG_FILE); + init_logging(); + } + + #[test] + fn test_env_var_names() { + assert_eq!(ENV_LOG, "GOOGLE_WORKSPACE_CLI_LOG"); + assert_eq!(ENV_LOG_FILE, "GOOGLE_WORKSPACE_CLI_LOG_FILE"); + } +} diff --git a/src/main.rs b/src/main.rs index 4090a280..17849f7b 100644 --- a/src/main.rs +++ b/src/main.rs @@ -31,6 +31,7 @@ mod formatter; mod fs_util; mod generate_skills; mod helpers; +mod logging; mod oauth_config; mod schema; mod services; @@ -47,6 +48,9 @@ async fn main() { // Load .env file if present (silently ignored if missing) let _ = dotenvy::dotenv(); + // Initialize structured logging (no-op if env vars are unset) + logging::init_logging(); + if let Err(err) = run().await { print_error_json(&err); std::process::exit(err.exit_code()); @@ -466,6 +470,10 @@ fn print_usage() { println!( " GOOGLE_WORKSPACE_PROJECT_ID Override the GCP project ID for quota and billing" ); + println!(" GOOGLE_WORKSPACE_CLI_LOG Log level for stderr (e.g., gws=debug)"); + println!( + " GOOGLE_WORKSPACE_CLI_LOG_FILE Directory for JSON log files (daily rotation)" + ); println!(); println!("EXIT CODES:"); for (code, description) in crate::error::EXIT_CODE_DOCUMENTATION {