fdcdb30d28
* Initial plan * feat: add concurrency-aware buffer sizing and hot object caching for GetObject - Implement adaptive buffer sizing based on concurrent request load - Add per-request tracking with automatic cleanup using RAII guards - Implement hot object cache (LRU) for frequently accessed small files (<= 10MB) - Add disk I/O semaphore to prevent saturation under extreme load - Integrate concurrency module into GetObject implementation - Buffer sizes now adapt: low concurrency uses large buffers for throughput, high concurrency uses smaller buffers for fairness and memory efficiency - Add comprehensive metrics collection for monitoring performance Co-authored-by: houseme <[email protected]> * docs: add comprehensive documentation and tests for concurrent GetObject optimization - Add detailed technical documentation explaining the solution - Document root cause analysis and solution architecture - Include performance expectations and testing recommendations - Add integration tests for concurrency tracking and buffer sizing - Add cache behavior tests - Include benchmark tests for concurrent request handling Co-authored-by: houseme <[email protected]> * fix: address code review issues in concurrency module - Fix race condition in cache size tracking by using consistent atomic operations within lock - Correct buffer sizing logic: 1-2 requests use 100%, 3-4 use 75%, 5-8 use 50%, >8 use 40% - Improve error message for semaphore acquire failure - Document limitation of streaming cache implementation (not yet implemented) - Add TODO for proper streaming cache with suggested approaches - Update tests to match corrected buffer sizing thresholds Co-authored-by: houseme <[email protected]> * docs: add comprehensive implementation summary for concurrent GetObject optimization - Executive summary of problem and solution - Detailed architecture documentation for each optimization - Integration points and code examples - Complete testing strategy and performance validation steps - Monitoring and observability guidelines with Prometheus queries - Deployment considerations and rollout strategy - Future enhancement roadmap - Success criteria and quantitative metrics Co-authored-by: houseme <[email protected]> * fix * fix * refactor: optimize cache with lru 0.16.2 read-first pattern and add advanced features - Implement optimized read-first cache access using peek() to reduce write lock contention - Add batch cache operations: get_cached_batch() for efficient multi-object retrieval - Add cache utility methods: is_cached(), remove_cached(), get_hot_keys() - Implement warm_cache() for pre-populating cache on startup - Add get_advanced_buffer_size() with file size and sequential read optimization - Enhance test suite with 8 new comprehensive tests covering: - Batch operations and cache warming - Hot keys tracking and analysis - Cache removal and LRU behavior verification - Concurrent cache access performance - Advanced buffer sizing strategies - Improve documentation and code comments in English throughout Co-authored-by: houseme <[email protected]> * docs: add final comprehensive optimization summary - Complete technical documentation of all optimizations - Detailed performance analysis and metrics - Production deployment guide with examples - Comprehensive API reference and usage patterns - Migration guide and future enhancement roadmap - All documentation in professional English Co-authored-by: houseme <[email protected]> * fix * fix * add moka crate for cache * feat: replace LRU with Moka cache and add comprehensive metrics - Replace lru crate with moka 0.12.11 for superior concurrent performance - Implement lock-free cache with automatic TTL/TTI expiration - Add size-based eviction using Moka's weigher function - Integrate comprehensive metrics collection throughout GetObject flow: * Cache hit/miss tracking with per-key access counts * Request concurrency gauges * Disk permit wait time histograms * Total request duration tracking * Response size and buffer size histograms - Deep integration with ecfs.rs GetObject operation - Add hit rate calculation method - Enhanced CacheStats with hit/miss counters - Lock-free concurrent reads for better scalability Moka advantages over LRU: - True lock-free concurrent access - Built-in TTL and TTI support - Automatic size-based eviction - Better performance under high concurrency - Native async support Co-authored-by: houseme <[email protected]> * docs: add comprehensive Moka cache migration and metrics documentation - Complete technical documentation of LRU to Moka migration - Detailed performance comparison and benchmarks - Comprehensive metrics catalog with 15+ Prometheus metrics - Prometheus query examples for monitoring - Dashboard and alerting recommendations - Migration guide with code examples - Troubleshooting guide for common issues - Future enhancement roadmap Co-authored-by: houseme <[email protected]> * fix * fix * refactor: update tests for Moka cache implementation - Completely refactor test suite to align with Moka-based concurrency.rs - Add Clone derive to ConcurrencyManager for test convenience - Update all tests to handle Moka's async behavior with proper delays - Add new tests: * test_cache_hit_rate - validate hit rate calculation * test_ttl_expiration - verify TTL configuration * test_is_cached_no_side_effects - ensure contains doesn't affect LRU * bench_concurrent_cache_performance - benchmark concurrent access - Updated existing tests: * test_moka_cache_operations - renamed and updated for Moka API * test_moka_cache_eviction - validate automatic eviction * test_hot_keys_tracking - improved assertions for sorted results * test_concurrent_cache_access - validate lock-free performance - All tests now include appropriate sleep delays for Moka's async processing - Enhanced documentation and assertions for better test clarity - Total: 18 comprehensive integration tests Co-authored-by: houseme <[email protected]> * docs: add comprehensive Moka test suite documentation - Complete test suite documentation for all 18 tests - Detailed test patterns and best practices for Moka - Debugging guide for common test failures - Performance expectations and CI integration - 100% API coverage validation - Future enhancement roadmap Co-authored-by: houseme <[email protected]> * fix * fmt * docs: enhance code comments and test documentation throughout - Significantly improve module-level documentation in concurrency.rs - Add detailed explanations of performance characteristics and expected improvements - Document the solution to issue #911 with before/after metrics - Enhance constant documentation with purpose and impact explanations - Add comprehensive RAII guard documentation with thread safety notes - Improve test documentation with detailed test strategy and rationale - Add Moka-specific test patterns and timing guidance - Include performance expectations for each test category - Document why each test matters for solving the original issue - All documentation written in professional English - Follow Rust documentation best practices with examples Co-authored-by: houseme <[email protected]> * remove lru crate * upgrade version * fix: resolve test errors by correcting module structure and test assertions - Fix test import paths to use crate:: instead of rustfs:: (binary-only crate) - Keep test file in src/storage/ instead of tests/ (no lib.rs exists) - Add #[cfg(test)] guard to mod declaration in storage/mod.rs - Fix Arc type annotations for Moka's ConcurrencyManager in concurrent tests - Correct test_buffer_size_bounds assertions to match actual implementation: * Minimum buffer is 32KB for files <100KB, 64KB otherwise * Maximum buffer respects base_buffer_size when concurrency is low * Buffer sizing doesn't cap at file size, only at min/max constraints - All 17 integration tests now pass successfully Co-authored-by: houseme <[email protected]> * fix: modify `TimeoutLayer::new` to `TimeoutLayer::with_status_code` and improve docker health check * fix * feat: implement cache writeback for small objects in GetObject - Add cache writeback logic for objects meeting caching criteria: * No range/part request (full object retrieval) * Object size known and <= 10MB (max_object_size threshold) * Not encrypted (SSE-C or managed encryption) - Read eligible objects into memory and cache via background task - Serve response from in-memory data for immediate client response - Add metrics counter for cache writeback operations - Add 3 new tests for cache writeback functionality: * test_cache_writeback_flow - validates round-trip caching * test_cache_writeback_size_limit - ensures large objects aren't cached * test_cache_writeback_concurrent - validates thread-safe concurrent writes - Update test suite documentation (now 20 comprehensive tests) Co-authored-by: houseme <[email protected]> * improve code for const * cargo clippy * feat: add cache enable/disable configuration via environment variable - Add is_cache_enabled() method to ConcurrencyManager - Read RUSTFS_OBJECT_CACHE_ENABLE env var (default: false) at startup - Update ecfs.rs to check is_cache_enabled() before cache lookup and writeback - Cache lookup and writeback now respect the enable flag - Add test_cache_enable_configuration test - Constants already exist in rustfs_config: * ENV_OBJECT_CACHE_ENABLE = "RUSTFS_OBJECT_CACHE_ENABLE" * DEFAULT_OBJECT_CACHE_ENABLE = false - Total: 21 comprehensive tests passing Co-authored-by: houseme <[email protected]> * fix * fmt * fix * fix * feat: implement comprehensive CachedGetObject response cache with metadata - Add CachedGetObject struct with full response metadata fields: * body, content_length, content_type, e_tag, last_modified * expires, cache_control, content_disposition, content_encoding * storage_class, version_id, delete_marker, tag_count, etc. - Add dual cache architecture in HotObjectCache: * Legacy simple byte cache for backward compatibility * New response cache for complete GetObject responses - Add ConcurrencyManager methods for response caching: * get_cached_object() - retrieve cached response with metadata * put_cached_object() - store complete response * invalidate_cache() - invalidate on write operations * invalidate_cache_versioned() - invalidate both version and latest * make_cache_key() - generate cache keys with version support * max_object_size() - get cache threshold - Add builder pattern for CachedGetObject construction - Add 6 new tests for response cache functionality (27 total): * test_cached_get_object_basic - basic operations * test_cached_get_object_versioned - version key handling * test_cache_invalidation - write operation invalidation * test_cache_invalidation_versioned - versioned invalidation * test_cached_get_object_size_limit - size enforcement * test_max_object_size - threshold accessor All 27 tests pass successfully. Co-authored-by: houseme <[email protected]> * feat: integrate CachedGetObject cache in ecfs.rs with full metadata and cache invalidation Integration of CachedGetObject response cache in ecfs.rs: 1. get_object: Cache lookup uses get_cached_object() with full metadata - Returns complete response with e_tag, last_modified, content_type, etc. - Parses last_modified from RFC3339 string - Supports versioned cache keys via make_cache_key() 2. get_object: Cache writeback uses put_cached_object() with metadata - Stores content_type, e_tag, last_modified in CachedGetObject - Background writeback via tokio::spawn() 3. Cache invalidation added to write operations: - put_object: invalidate_cache_versioned() after store.put_object() - put_object_extract: invalidate_cache_versioned() after each file extraction - copy_object: invalidate_cache_versioned() after store.copy_object() - delete_object: invalidate_cache_versioned() after store.delete_object() - delete_objects: invalidate_cache_versioned() for each deleted object - complete_multipart_upload: invalidate_cache_versioned() after completion 4. Fixed test_adaptive_buffer_sizing to be more robust with parallel tests All 27 tests pass. Co-authored-by: houseme <[email protected]> * fix: add error logging for time parsing in cache lookup and writeback - Add warning log when RFC3339 parsing fails in cache lookup - Add warning log when time formatting fails in cache writeback - Improves debugging for cache-related issues Co-authored-by: houseme <[email protected]> * fix * fix * upgrade version * fmt * add http: 4138 and add max_object_size key * fix * fix * fix * modify metrics key * add * upgrade crates version and improve docker observability * feat: implement adaptive I/O strategy based on disk permit wait time Implements adaptive I/O strategy for GetObject operations based on disk permit wait times, as requested in issue #911. Key changes: 1. New types in concurrency.rs: - IoLoadLevel enum: Low (<10ms), Medium (10-50ms), High (50-200ms), Critical (>200ms) - IoStrategy struct: contains optimized I/O parameters based on load level - IoLoadMetrics: rolling window metrics for load tracking 2. New ConcurrencyManager methods: - calculate_io_strategy(): calculates adaptive strategy from permit wait duration - record_permit_wait(): records observation for load tracking - smoothed_load_level(): returns averaged load level for stability - io_load_stats(): returns (avg_wait, p95_wait, max_wait, count) for monitoring - adaptive_buffer_size(): convenience method for buffer sizing 3. Integration in ecfs.rs get_object: - Calculate IoStrategy after acquiring disk permit - Use strategy buffer_size instead of static sizing - Consider strategy.cache_writeback_enabled in cache decision - Record new metrics: io.load.level gauge, io.buffer.multiplier gauge, io.strategy.selected counter by load level 4. New tests (4 added, 31 total): - test_io_load_level_classification: validates load level thresholds - test_io_strategy_buffer_sizing: validates buffer multipliers - test_calculate_io_strategy: validates manager strategy calculation - test_io_load_stats: validates stats tracking All 31 tests pass. Clippy clean. Formatted. Co-authored-by: houseme <[email protected]> * fix * fix * docs: add comprehensive architecture design and fix cache hit event notification 1. Added CONCURRENCY_ARCHITECTURE.md with complete design documentation: - Executive summary and problem statement - Architecture overview with request flow diagram - Detailed module analysis for concurrency.rs and ecfs.rs - Critical analysis of helper.complete() for cache hits - Adaptive I/O strategy design with algorithm - Cache architecture with CachedGetObject structure - Metrics and monitoring with Prometheus queries - Performance characteristics and future enhancements 2. Fixed critical issue: Cache hit path now calls helper.complete() - S3 bucket notifications (s3:GetObject events) now trigger for cache hits - Event-driven workflows (Lambda, SNS) work correctly for all object access - Maintains audit trail for both cache hits and misses All 31 tests pass. Co-authored-by: houseme <[email protected]> * fix: set object info and version_id on helper before complete() for cache hits When serving from cache, properly configure the OperationHelper before calling complete() to ensure S3 bucket notifications include complete object metadata: 1. Build ObjectInfo from cached metadata: - bucket, name, size, actual_size - etag, mod_time, version_id, delete_marker - storage_class, content_type, content_encoding - user_metadata (user_defined) 2. Set helper.object(event_info).version_id(version_id_str) before complete() 3. Updated CONCURRENCY_ARCHITECTURE.md with: - Complete code example for cache hit event notification - Explanation of why ObjectInfo is required - Documentation of version_id handling This ensures: - Lambda triggers receive proper object metadata for cache hits - SNS/SQS notifications include complete information - Audit logs contain accurate object details - Version-specific event routing works correctly All 31 tests pass. Co-authored-by: houseme <[email protected]> * fix * improve code * fmt --------- Co-authored-by: copilot-swe-agent[bot] <[email protected]> Co-authored-by: houseme <[email protected]> Co-authored-by: houseme <[email protected]>
706 lines
27 KiB
Rust
706 lines
27 KiB
Rust
// Copyright 2024 RustFS Team
|
||
//
|
||
// 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.
|
||
|
||
use crate::config::OtelConfig;
|
||
use crate::global::OBSERVABILITY_METRIC_ENABLED;
|
||
use crate::{Recorder, TelemetryError};
|
||
use flexi_logger::{DeferredNow, Record, WriteMode, WriteMode::AsyncWith, style};
|
||
use metrics::counter;
|
||
use nu_ansi_term::Color;
|
||
use opentelemetry::{KeyValue, global, trace::TracerProvider};
|
||
use opentelemetry_appender_tracing::layer::OpenTelemetryTracingBridge;
|
||
use opentelemetry_otlp::{Compression, Protocol, WithExportConfig, WithHttpConfig};
|
||
use opentelemetry_sdk::{
|
||
Resource,
|
||
logs::SdkLoggerProvider,
|
||
metrics::{PeriodicReader, SdkMeterProvider},
|
||
trace::{RandomIdGenerator, Sampler, SdkTracerProvider},
|
||
};
|
||
use opentelemetry_semantic_conventions::{
|
||
SCHEMA_URL,
|
||
attribute::{DEPLOYMENT_ENVIRONMENT_NAME, NETWORK_LOCAL_ADDRESS, SERVICE_VERSION as OTEL_SERVICE_VERSION},
|
||
};
|
||
use rustfs_config::{
|
||
APP_NAME, DEFAULT_LOG_KEEP_FILES, DEFAULT_LOG_LEVEL, DEFAULT_OBS_LOG_STDOUT_ENABLED, ENVIRONMENT, METER_INTERVAL,
|
||
SAMPLE_RATIO, SERVICE_VERSION,
|
||
observability::{
|
||
DEFAULT_OBS_ENVIRONMENT_PRODUCTION, DEFAULT_OBS_LOG_FLUSH_MS, DEFAULT_OBS_LOG_MESSAGE_CAPA, DEFAULT_OBS_LOG_POOL_CAPA,
|
||
ENV_OBS_LOG_DIRECTORY, ENV_OBS_LOG_FLUSH_MS, ENV_OBS_LOG_MESSAGE_CAPA, ENV_OBS_LOG_POOL_CAPA,
|
||
},
|
||
};
|
||
use rustfs_utils::{get_env_u64, get_env_usize, get_local_ip_with_default};
|
||
use smallvec::SmallVec;
|
||
use std::{borrow::Cow, env, fs, io::IsTerminal, time::Duration};
|
||
use tracing::info;
|
||
use tracing_error::ErrorLayer;
|
||
use tracing_opentelemetry::{MetricsLayer, OpenTelemetryLayer};
|
||
use tracing_subscriber::{
|
||
EnvFilter, Layer,
|
||
fmt::{format::FmtSpan, time::LocalTime},
|
||
layer::SubscriberExt,
|
||
util::SubscriberInitExt,
|
||
};
|
||
|
||
/// A guard object that manages the lifecycle of OpenTelemetry components.
|
||
///
|
||
/// This struct holds references to the created OpenTelemetry providers and ensures
|
||
/// they are properly shut down when the guard is dropped. It implements the RAII
|
||
/// (Resource Acquisition Is Initialization) pattern for managing telemetry resources.
|
||
///
|
||
/// When this guard goes out of scope, it will automatically shut down:
|
||
/// - The tracer provider (for distributed tracing)
|
||
/// - The meter provider (for metrics collection)
|
||
/// - The logger provider (for structured logging)
|
||
///
|
||
/// Implement Debug trait correctly, rather than using derive, as some fields may not have implemented Debug
|
||
pub struct OtelGuard {
|
||
tracer_provider: Option<SdkTracerProvider>,
|
||
meter_provider: Option<SdkMeterProvider>,
|
||
logger_provider: Option<SdkLoggerProvider>,
|
||
flexi_logger_handles: Option<flexi_logger::LoggerHandle>,
|
||
tracing_guard: Option<tracing_appender::non_blocking::WorkerGuard>,
|
||
}
|
||
|
||
impl std::fmt::Debug for OtelGuard {
|
||
fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
|
||
f.debug_struct("OtelGuard")
|
||
.field("tracer_provider", &self.tracer_provider.is_some())
|
||
.field("meter_provider", &self.meter_provider.is_some())
|
||
.field("logger_provider", &self.logger_provider.is_some())
|
||
.field("flexi_logger_handles", &self.flexi_logger_handles.is_some())
|
||
.field("tracing_guard", &self.tracing_guard.is_some())
|
||
.finish()
|
||
}
|
||
}
|
||
|
||
impl Drop for OtelGuard {
|
||
fn drop(&mut self) {
|
||
if let Some(provider) = self.tracer_provider.take() {
|
||
if let Err(err) = provider.shutdown() {
|
||
eprintln!("Tracer shutdown error: {err:?}");
|
||
}
|
||
}
|
||
|
||
if let Some(provider) = self.meter_provider.take() {
|
||
if let Err(err) = provider.shutdown() {
|
||
eprintln!("Meter shutdown error: {err:?}");
|
||
}
|
||
}
|
||
if let Some(provider) = self.logger_provider.take() {
|
||
if let Err(err) = provider.shutdown() {
|
||
eprintln!("Logger shutdown error: {err:?}");
|
||
}
|
||
}
|
||
|
||
if let Some(handle) = self.flexi_logger_handles.take() {
|
||
handle.shutdown();
|
||
println!("flexi_logger shutdown completed");
|
||
}
|
||
|
||
if let Some(guard) = self.tracing_guard.take() {
|
||
drop(guard);
|
||
println!("Tracing guard dropped, flushing logs.");
|
||
}
|
||
}
|
||
}
|
||
|
||
/// create OpenTelemetry Resource
|
||
fn resource(config: &OtelConfig) -> Resource {
|
||
Resource::builder()
|
||
.with_service_name(Cow::Borrowed(config.service_name.as_deref().unwrap_or(APP_NAME)).to_string())
|
||
.with_schema_url(
|
||
[
|
||
KeyValue::new(
|
||
OTEL_SERVICE_VERSION,
|
||
Cow::Borrowed(config.service_version.as_deref().unwrap_or(SERVICE_VERSION)).to_string(),
|
||
),
|
||
KeyValue::new(
|
||
DEPLOYMENT_ENVIRONMENT_NAME,
|
||
Cow::Borrowed(config.environment.as_deref().unwrap_or(ENVIRONMENT)).to_string(),
|
||
),
|
||
KeyValue::new(NETWORK_LOCAL_ADDRESS, get_local_ip_with_default()),
|
||
],
|
||
SCHEMA_URL,
|
||
)
|
||
.build()
|
||
}
|
||
|
||
/// Creates a periodic reader for stdout metrics
|
||
fn create_periodic_reader(interval: u64) -> PeriodicReader<opentelemetry_stdout::MetricExporter> {
|
||
PeriodicReader::builder(opentelemetry_stdout::MetricExporter::default())
|
||
.with_interval(Duration::from_secs(interval))
|
||
.build()
|
||
}
|
||
|
||
// Read the AsyncWith parameter from the environment variable
|
||
fn get_env_async_with() -> WriteMode {
|
||
let pool_capa = get_env_usize(ENV_OBS_LOG_POOL_CAPA, DEFAULT_OBS_LOG_POOL_CAPA);
|
||
let message_capa = get_env_usize(ENV_OBS_LOG_MESSAGE_CAPA, DEFAULT_OBS_LOG_MESSAGE_CAPA);
|
||
let flush_ms = get_env_u64(ENV_OBS_LOG_FLUSH_MS, DEFAULT_OBS_LOG_FLUSH_MS);
|
||
|
||
AsyncWith {
|
||
pool_capa,
|
||
message_capa,
|
||
flush_interval: Duration::from_millis(flush_ms),
|
||
}
|
||
}
|
||
|
||
fn build_env_filter(logger_level: &str, default_level: Option<&str>) -> EnvFilter {
|
||
let level = default_level.unwrap_or(logger_level);
|
||
let mut filter = EnvFilter::try_from_default_env().unwrap_or_else(|_| EnvFilter::new(level));
|
||
if !matches!(logger_level, "trace" | "debug") {
|
||
let directives: SmallVec<[&str; 5]> = smallvec::smallvec!["hyper", "tonic", "h2", "reqwest", "tower"];
|
||
for directive in directives {
|
||
filter = filter.add_directive(format!("{directive}=off").parse().unwrap());
|
||
}
|
||
}
|
||
|
||
filter
|
||
}
|
||
|
||
/// Custom Log Formatter Function - Terminal Output (with Color)
|
||
#[inline(never)]
|
||
fn format_with_color(w: &mut dyn std::io::Write, now: &mut DeferredNow, record: &Record) -> Result<(), std::io::Error> {
|
||
let level = record.level();
|
||
let level_style = style(level);
|
||
let binding = std::thread::current();
|
||
let thread_name = binding.name().unwrap_or("unnamed");
|
||
let thread_id = format!("{:?}", std::thread::current().id());
|
||
writeln!(
|
||
w,
|
||
"[{}] {} [{}] [{}:{}] [{}:{}] {}",
|
||
now.now().format(flexi_logger::TS_DASHES_BLANK_COLONS_DOT_BLANK),
|
||
level_style.paint(level.to_string()),
|
||
Color::Magenta.paint(record.target()),
|
||
Color::Blue.paint(record.file().unwrap_or("unknown")),
|
||
Color::Blue.paint(record.line().unwrap_or(0).to_string()),
|
||
Color::Green.paint(thread_name),
|
||
Color::Green.paint(thread_id),
|
||
record.args()
|
||
)
|
||
}
|
||
|
||
/// Custom Log Formatter - File Output (No Color)
|
||
#[inline(never)]
|
||
fn format_for_file(w: &mut dyn std::io::Write, now: &mut DeferredNow, record: &Record) -> Result<(), std::io::Error> {
|
||
let level = record.level();
|
||
let binding = std::thread::current();
|
||
let thread_name = binding.name().unwrap_or("unnamed");
|
||
let thread_id = format!("{:?}", std::thread::current().id());
|
||
writeln!(
|
||
w,
|
||
"[{}] {} [{}] [{}:{}] [{}:{}] {}",
|
||
now.now().format(flexi_logger::TS_DASHES_BLANK_COLONS_DOT_BLANK),
|
||
level,
|
||
record.target(),
|
||
record.file().unwrap_or("unknown"),
|
||
record.line().unwrap_or(0),
|
||
thread_name,
|
||
thread_id,
|
||
record.args()
|
||
)
|
||
}
|
||
|
||
/// stdout + span information (fix: retain WorkerGuard to avoid releasing after initialization)
|
||
fn init_stdout_logging(_config: &OtelConfig, logger_level: &str, is_production: bool) -> OtelGuard {
|
||
let env_filter = build_env_filter(logger_level, None);
|
||
let (nb, guard) = tracing_appender::non_blocking(std::io::stdout());
|
||
let enable_color = std::io::stdout().is_terminal();
|
||
let fmt_layer = tracing_subscriber::fmt::layer()
|
||
.with_timer(LocalTime::rfc_3339())
|
||
.with_target(true)
|
||
.with_ansi(enable_color)
|
||
.with_thread_names(true)
|
||
.with_thread_ids(true)
|
||
.with_file(true)
|
||
.with_line_number(true)
|
||
.with_writer(nb)
|
||
.json()
|
||
.with_current_span(true)
|
||
.with_span_list(true)
|
||
.with_span_events(if is_production { FmtSpan::CLOSE } else { FmtSpan::FULL });
|
||
tracing_subscriber::registry()
|
||
.with(env_filter)
|
||
.with(ErrorLayer::default())
|
||
.with(fmt_layer)
|
||
.init();
|
||
|
||
OBSERVABILITY_METRIC_ENABLED.set(false).ok();
|
||
counter!("rustfs.start.total").increment(1);
|
||
info!("Init stdout logging (level: {})", logger_level);
|
||
OtelGuard {
|
||
tracer_provider: None,
|
||
meter_provider: None,
|
||
logger_provider: None,
|
||
flexi_logger_handles: None,
|
||
tracing_guard: Some(guard),
|
||
}
|
||
}
|
||
|
||
/// File rolling log (size switching + number retained)
|
||
fn init_file_logging(config: &OtelConfig, logger_level: &str, is_production: bool) -> Result<OtelGuard, TelemetryError> {
|
||
use flexi_logger::{Age, Cleanup, Criterion, FileSpec, LogSpecification, Naming};
|
||
|
||
let service_name = config.service_name.as_deref().unwrap_or(APP_NAME);
|
||
let default_log_directory = rustfs_utils::dirs::get_log_directory_to_string(ENV_OBS_LOG_DIRECTORY);
|
||
let log_directory = config.log_directory.as_deref().unwrap_or(default_log_directory.as_str());
|
||
let log_filename = config.log_filename.as_deref().unwrap_or(service_name);
|
||
let keep_files = config.log_keep_files.unwrap_or(DEFAULT_LOG_KEEP_FILES);
|
||
if let Err(e) = fs::create_dir_all(log_directory) {
|
||
return Err(TelemetryError::Io(e.to_string()));
|
||
}
|
||
#[cfg(unix)]
|
||
{
|
||
use std::fs::Permissions;
|
||
use std::os::unix::fs::PermissionsExt;
|
||
let desired: u32 = 0o755;
|
||
match fs::metadata(log_directory) {
|
||
Ok(meta) => {
|
||
let current = meta.permissions().mode() & 0o777;
|
||
// Only tighten to 0755 if existing permissions are looser than target, avoid loosening
|
||
if (current & !desired) != 0 {
|
||
if let Err(e) = fs::set_permissions(log_directory, Permissions::from_mode(desired)) {
|
||
return Err(TelemetryError::SetPermissions(format!(
|
||
"dir='{log_directory}', want={desired:#o}, have={current:#o}, err={e}"
|
||
)));
|
||
}
|
||
// Second verification
|
||
if let Ok(meta2) = fs::metadata(log_directory) {
|
||
let after = meta2.permissions().mode() & 0o777;
|
||
if after != desired {
|
||
return Err(TelemetryError::SetPermissions(format!(
|
||
"dir='{log_directory}', want={desired:#o}, after={after:#o}"
|
||
)));
|
||
}
|
||
}
|
||
}
|
||
}
|
||
Err(e) => {
|
||
return Err(TelemetryError::Io(format!("stat '{log_directory}' failed: {e}")));
|
||
}
|
||
}
|
||
}
|
||
|
||
// parsing level
|
||
let log_spec = LogSpecification::parse(logger_level)
|
||
.unwrap_or_else(|_| LogSpecification::parse(DEFAULT_LOG_LEVEL).unwrap_or(LogSpecification::error()));
|
||
|
||
// Switch by size (MB), Build log cutting conditions
|
||
let rotation_criterion = match (config.log_rotation_time.as_deref(), config.log_rotation_size_mb) {
|
||
// Cut by time and size at the same time
|
||
(Some(time), Some(size)) => {
|
||
let age = match time.to_lowercase().as_str() {
|
||
"hour" => Age::Hour,
|
||
"day" => Age::Day,
|
||
"minute" => Age::Minute,
|
||
"second" => Age::Second,
|
||
_ => Age::Day, // The default is by day
|
||
};
|
||
Criterion::AgeOrSize(age, size * 1024 * 1024) // Convert to bytes
|
||
}
|
||
// Cut by time only
|
||
(Some(time), None) => {
|
||
let age = match time.to_lowercase().as_str() {
|
||
"hour" => Age::Hour,
|
||
"day" => Age::Day,
|
||
"minute" => Age::Minute,
|
||
"second" => Age::Second,
|
||
_ => Age::Day, // The default is by day
|
||
};
|
||
Criterion::Age(age)
|
||
}
|
||
// Cut by size only
|
||
(None, Some(size)) => {
|
||
Criterion::Size(size * 1024 * 1024) // Convert to bytes
|
||
}
|
||
// By default, it is cut by the day
|
||
_ => Criterion::Age(Age::Day),
|
||
};
|
||
|
||
// write mode
|
||
let write_mode = get_env_async_with();
|
||
// Build
|
||
let mut builder = flexi_logger::Logger::try_with_env_or_str(logger_level)
|
||
.unwrap_or(flexi_logger::Logger::with(log_spec.clone()))
|
||
.format_for_stderr(format_with_color)
|
||
.format_for_stdout(format_with_color)
|
||
.format_for_files(format_for_file)
|
||
.log_to_file(
|
||
FileSpec::default()
|
||
.directory(log_directory)
|
||
.basename(log_filename)
|
||
.suppress_timestamp(),
|
||
)
|
||
.rotate(rotation_criterion, Naming::TimestampsDirect, Cleanup::KeepLogFiles(keep_files))
|
||
.write_mode(write_mode)
|
||
.append()
|
||
.use_utc();
|
||
|
||
// Optional copy to stdout (for local observation)
|
||
if config.log_stdout_enabled.unwrap_or(DEFAULT_OBS_LOG_STDOUT_ENABLED) || !is_production {
|
||
builder = builder.duplicate_to_stdout(flexi_logger::Duplicate::All);
|
||
} else {
|
||
builder = builder.duplicate_to_stdout(flexi_logger::Duplicate::None);
|
||
}
|
||
|
||
let handle = match builder.start() {
|
||
Ok(h) => Some(h),
|
||
Err(e) => {
|
||
eprintln!("ERROR: start flexi_logger failed: {e}");
|
||
None
|
||
}
|
||
};
|
||
|
||
OBSERVABILITY_METRIC_ENABLED.set(false).ok();
|
||
info!(
|
||
"Init file logging at '{}', roll size {:?}MB, keep {}",
|
||
log_directory, config.log_rotation_size_mb, keep_files
|
||
);
|
||
|
||
Ok(OtelGuard {
|
||
tracer_provider: None,
|
||
meter_provider: None,
|
||
logger_provider: None,
|
||
flexi_logger_handles: handle,
|
||
tracing_guard: None,
|
||
})
|
||
}
|
||
|
||
/// Observability (HTTP export, supports three sub-endpoints; if not, fallback to unified endpoint)
|
||
fn init_observability_http(config: &OtelConfig, logger_level: &str, is_production: bool) -> Result<OtelGuard, TelemetryError> {
|
||
// Resources and sampling
|
||
let res = resource(config);
|
||
let service_name = config.service_name.as_deref().unwrap_or(APP_NAME).to_owned();
|
||
let use_stdout = config.use_stdout.unwrap_or(!is_production);
|
||
let sample_ratio = config.sample_ratio.unwrap_or(SAMPLE_RATIO);
|
||
let sampler = if (0.0..1.0).contains(&sample_ratio) {
|
||
Sampler::TraceIdRatioBased(sample_ratio)
|
||
} else {
|
||
Sampler::AlwaysOn
|
||
};
|
||
|
||
// Endpoint
|
||
let root_ep = config.endpoint.clone(); // owned String
|
||
|
||
let trace_ep: String = config
|
||
.trace_endpoint
|
||
.as_deref()
|
||
.filter(|s| !s.is_empty())
|
||
.map(|s| s.to_string())
|
||
.unwrap_or_else(|| format!("{root_ep}/v1/traces"));
|
||
|
||
let metric_ep: String = config
|
||
.metric_endpoint
|
||
.as_deref()
|
||
.filter(|s| !s.is_empty())
|
||
.map(|s| s.to_string())
|
||
.unwrap_or_else(|| format!("{root_ep}/v1/metrics"));
|
||
|
||
let log_ep: String = config
|
||
.log_endpoint
|
||
.as_deref()
|
||
.filter(|s| !s.is_empty())
|
||
.map(|s| s.to_string())
|
||
.unwrap_or_else(|| format!("{root_ep}/v1/logs"));
|
||
|
||
// Tracer(HTTP)
|
||
let tracer_provider = {
|
||
let exporter = opentelemetry_otlp::SpanExporter::builder()
|
||
.with_http()
|
||
.with_endpoint(trace_ep.as_str())
|
||
.with_protocol(Protocol::HttpBinary)
|
||
.with_compression(Compression::Gzip)
|
||
.build()
|
||
.map_err(|e| TelemetryError::BuildSpanExporter(e.to_string()))?;
|
||
|
||
let mut builder = SdkTracerProvider::builder()
|
||
.with_sampler(sampler)
|
||
.with_id_generator(RandomIdGenerator::default())
|
||
.with_resource(res.clone())
|
||
.with_batch_exporter(exporter);
|
||
|
||
if use_stdout {
|
||
builder = builder.with_batch_exporter(opentelemetry_stdout::SpanExporter::default());
|
||
}
|
||
|
||
let provider = builder.build();
|
||
global::set_tracer_provider(provider.clone());
|
||
provider
|
||
};
|
||
|
||
// Meter(HTTP)
|
||
let meter_provider = {
|
||
let exporter = opentelemetry_otlp::MetricExporter::builder()
|
||
.with_http()
|
||
.with_endpoint(metric_ep.as_str())
|
||
.with_temporality(opentelemetry_sdk::metrics::Temporality::default())
|
||
.with_protocol(Protocol::HttpBinary)
|
||
.with_compression(Compression::Gzip)
|
||
.build()
|
||
.map_err(|e| TelemetryError::BuildMetricExporter(e.to_string()))?;
|
||
let meter_interval = config.meter_interval.unwrap_or(METER_INTERVAL);
|
||
|
||
let (provider, recorder) = Recorder::builder(service_name.clone())
|
||
.with_meter_provider(|b| {
|
||
let b = b.with_resource(res.clone()).with_reader(
|
||
PeriodicReader::builder(exporter)
|
||
.with_interval(Duration::from_secs(meter_interval))
|
||
.build(),
|
||
);
|
||
if use_stdout {
|
||
b.with_reader(create_periodic_reader(meter_interval))
|
||
} else {
|
||
b
|
||
}
|
||
})
|
||
.build();
|
||
global::set_meter_provider(provider.clone());
|
||
metrics::set_global_recorder(recorder).map_err(|e| TelemetryError::InstallMetricsRecorder(e.to_string()))?;
|
||
provider
|
||
};
|
||
|
||
// Logger(HTTP)
|
||
let logger_provider = {
|
||
let exporter = opentelemetry_otlp::LogExporter::builder()
|
||
.with_http()
|
||
.with_endpoint(log_ep.as_str())
|
||
.with_protocol(Protocol::HttpBinary)
|
||
.with_compression(Compression::Gzip)
|
||
.build()
|
||
.map_err(|e| TelemetryError::BuildLogExporter(e.to_string()))?;
|
||
|
||
let mut builder = SdkLoggerProvider::builder().with_resource(res);
|
||
builder = builder.with_batch_exporter(exporter);
|
||
if use_stdout {
|
||
builder = builder.with_batch_exporter(opentelemetry_stdout::LogExporter::default());
|
||
}
|
||
builder.build()
|
||
};
|
||
|
||
// Tracing layer
|
||
let fmt_layer_opt = {
|
||
if config.log_stdout_enabled.unwrap_or(DEFAULT_OBS_LOG_STDOUT_ENABLED) {
|
||
let enable_color = std::io::stdout().is_terminal();
|
||
let mut layer = tracing_subscriber::fmt::layer()
|
||
.with_timer(LocalTime::rfc_3339())
|
||
.with_target(true)
|
||
.with_ansi(enable_color)
|
||
.with_thread_names(true)
|
||
.with_thread_ids(true)
|
||
.with_file(true)
|
||
.with_line_number(true)
|
||
.json()
|
||
.with_current_span(true)
|
||
.with_span_list(true);
|
||
let span_event = if is_production { FmtSpan::CLOSE } else { FmtSpan::FULL };
|
||
layer = layer.with_span_events(span_event);
|
||
Some(layer.with_filter(build_env_filter(logger_level, None)))
|
||
} else {
|
||
None
|
||
}
|
||
};
|
||
|
||
let filter = build_env_filter(logger_level, None);
|
||
let otel_bridge = OpenTelemetryTracingBridge::new(&logger_provider).with_filter(build_env_filter(logger_level, None));
|
||
let tracer = tracer_provider.tracer(service_name.to_string());
|
||
|
||
tracing_subscriber::registry()
|
||
.with(filter)
|
||
.with(ErrorLayer::default())
|
||
.with(fmt_layer_opt)
|
||
.with(OpenTelemetryLayer::new(tracer))
|
||
.with(otel_bridge)
|
||
.with(MetricsLayer::new(meter_provider.clone()))
|
||
.init();
|
||
|
||
OBSERVABILITY_METRIC_ENABLED.set(true).ok();
|
||
counter!("rustfs.start.total").increment(1);
|
||
info!(
|
||
"Init observability (HTTP): trace='{}', metric='{}', log='{}'",
|
||
trace_ep, metric_ep, log_ep
|
||
);
|
||
|
||
Ok(OtelGuard {
|
||
tracer_provider: Some(tracer_provider),
|
||
meter_provider: Some(meter_provider),
|
||
logger_provider: Some(logger_provider),
|
||
flexi_logger_handles: None,
|
||
tracing_guard: None,
|
||
})
|
||
}
|
||
|
||
/// Initialize Telemetry,Entrance: three rules
|
||
pub(crate) fn init_telemetry(config: &OtelConfig) -> Result<OtelGuard, TelemetryError> {
|
||
let environment = config.environment.as_deref().unwrap_or(ENVIRONMENT);
|
||
let is_production = environment.eq_ignore_ascii_case(DEFAULT_OBS_ENVIRONMENT_PRODUCTION);
|
||
let logger_level = config.logger_level.as_deref().unwrap_or(DEFAULT_LOG_LEVEL);
|
||
|
||
// Rule 3: Observability (any endpoint is enabled if it is not empty)
|
||
let has_obs = !config.endpoint.is_empty()
|
||
|| config.trace_endpoint.as_deref().map(|s| !s.is_empty()).unwrap_or(false)
|
||
|| config.metric_endpoint.as_deref().map(|s| !s.is_empty()).unwrap_or(false)
|
||
|| config.log_endpoint.as_deref().map(|s| !s.is_empty()).unwrap_or(false);
|
||
|
||
if has_obs {
|
||
return init_observability_http(config, logger_level, is_production);
|
||
}
|
||
|
||
// Rule 2: The user has explicitly customized the log directory (determined by whether ENV_OBS_LOG_DIRECTORY is set)
|
||
let user_set_log_dir = env::var(ENV_OBS_LOG_DIRECTORY).is_ok();
|
||
if user_set_log_dir {
|
||
return init_file_logging(config, logger_level, is_production);
|
||
}
|
||
|
||
// Rule 1: Default stdout (error level)
|
||
Ok(init_stdout_logging(config, DEFAULT_LOG_LEVEL, is_production))
|
||
}
|
||
|
||
#[cfg(test)]
|
||
mod tests {
|
||
use super::*;
|
||
use rustfs_config::USE_STDOUT;
|
||
|
||
#[test]
|
||
fn test_production_environment_detection() {
|
||
// Test production environment logic
|
||
let production_envs = vec!["production", "PRODUCTION", "Production"];
|
||
|
||
for env_value in production_envs {
|
||
let is_production = env_value.to_lowercase() == "production";
|
||
assert!(is_production, "Should detect '{env_value}' as production environment");
|
||
}
|
||
}
|
||
|
||
#[test]
|
||
fn test_non_production_environment_detection() {
|
||
// Test non-production environment logic
|
||
let non_production_envs = vec!["development", "test", "staging", "dev", "local"];
|
||
|
||
for env_value in non_production_envs {
|
||
let is_production = env_value.to_lowercase() == "production";
|
||
assert!(!is_production, "Should not detect '{env_value}' as production environment");
|
||
}
|
||
}
|
||
|
||
#[test]
|
||
fn test_stdout_behavior_logic() {
|
||
// Test the stdout behavior logic without environment manipulation
|
||
struct TestCase {
|
||
is_production: bool,
|
||
config_use_stdout: Option<bool>,
|
||
expected_use_stdout: bool,
|
||
description: &'static str,
|
||
}
|
||
|
||
let test_cases = vec![
|
||
TestCase {
|
||
is_production: true,
|
||
config_use_stdout: None,
|
||
expected_use_stdout: false,
|
||
description: "Production with no config should disable stdout",
|
||
},
|
||
TestCase {
|
||
is_production: false,
|
||
config_use_stdout: None,
|
||
expected_use_stdout: USE_STDOUT,
|
||
description: "Non-production with no config should use default",
|
||
},
|
||
TestCase {
|
||
is_production: true,
|
||
config_use_stdout: Some(true),
|
||
expected_use_stdout: true,
|
||
description: "Production with explicit true should enable stdout",
|
||
},
|
||
TestCase {
|
||
is_production: true,
|
||
config_use_stdout: Some(false),
|
||
expected_use_stdout: false,
|
||
description: "Production with explicit false should disable stdout",
|
||
},
|
||
TestCase {
|
||
is_production: false,
|
||
config_use_stdout: Some(true),
|
||
expected_use_stdout: true,
|
||
description: "Non-production with explicit true should enable stdout",
|
||
},
|
||
];
|
||
|
||
for case in test_cases {
|
||
let default_use_stdout = if case.is_production { false } else { USE_STDOUT };
|
||
|
||
let actual_use_stdout = case.config_use_stdout.unwrap_or(default_use_stdout);
|
||
|
||
assert_eq!(actual_use_stdout, case.expected_use_stdout, "Test case failed: {}", case.description);
|
||
}
|
||
}
|
||
|
||
#[test]
|
||
fn test_log_level_filter_mapping_logic() {
|
||
// Test the log level mapping logic used in the real implementation
|
||
let test_cases = vec![
|
||
("trace", "Trace"),
|
||
("debug", "Debug"),
|
||
("info", "Info"),
|
||
("warn", "Warn"),
|
||
("warning", "Warn"),
|
||
("error", "Error"),
|
||
("off", "None"),
|
||
("invalid_level", "Info"), // Should default to Info
|
||
];
|
||
|
||
for (input_level, expected_variant) in test_cases {
|
||
let filter_variant = match input_level.to_lowercase().as_str() {
|
||
"trace" => "Trace",
|
||
"debug" => "Debug",
|
||
"info" => "Info",
|
||
"warn" | "warning" => "Warn",
|
||
"error" => "Error",
|
||
"off" => "None",
|
||
_ => "Info", // default case
|
||
};
|
||
|
||
assert_eq!(
|
||
filter_variant, expected_variant,
|
||
"Log level '{input_level}' should map to '{expected_variant}'"
|
||
);
|
||
}
|
||
}
|
||
|
||
#[test]
|
||
fn test_otel_config_environment_defaults() {
|
||
// Test that OtelConfig properly handles environment detection logic
|
||
let config = OtelConfig {
|
||
endpoint: "".to_string(),
|
||
use_stdout: None,
|
||
environment: Some("production".to_string()),
|
||
..Default::default()
|
||
};
|
||
|
||
// Simulate the logic from init_telemetry
|
||
let environment = config.environment.as_deref().unwrap_or(ENVIRONMENT);
|
||
assert_eq!(environment, "production");
|
||
|
||
// Test with development environment
|
||
let dev_config = OtelConfig {
|
||
endpoint: "".to_string(),
|
||
use_stdout: None,
|
||
environment: Some("development".to_string()),
|
||
..Default::default()
|
||
};
|
||
|
||
let dev_environment = dev_config.environment.as_deref().unwrap_or(ENVIRONMENT);
|
||
assert_eq!(dev_environment, "development");
|
||
}
|
||
}
|