diff --git a/.env.example b/.env.example index 43bee83..f42a172 100644 --- a/.env.example +++ b/.env.example @@ -24,6 +24,8 @@ REQUESTS_LIMITER_TIMEFRAME=60 QUERY_CHECK_MODE=regex +# Optional: if unset, OTLP export is disabled (console-only logging) +#OTEL_EXPORTER_OTLP_ENDPOINT=http://localhost:4317 ### envars for user-service diff --git a/Cargo.lock b/Cargo.lock index c70bcbc..131de9e 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -63,9 +63,9 @@ dependencies = [ [[package]] name = "arc-swap" -version = "1.8.2" +version = "1.9.0" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "f9f3647c145568cec02c42054e07bdf9a5a698e15b466fb2341bfc393cd24aa5" +checksum = "a07d1f37ff60921c83bdfc7407723bdefe89b44b98a9b772f225c8f9d67141a6" dependencies = [ "rustversion", ] @@ -142,9 +142,9 @@ checksum = "c08606f8c3cbf4ce6ec8e28fb0014a2c086708fe954eaa885384a6165172e7e8" [[package]] name = "aws-lc-rs" -version = "1.16.1" +version = "1.16.2" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "94bffc006df10ac2a68c83692d734a465f8ee6c5b384d8545a636f81d858f4bf" +checksum = "a054912289d18629dc78375ba2c3726a3afe3ff71b4edba9dedfca0e3446d1fc" dependencies = [ "aws-lc-sys", "zeroize", @@ -152,9 +152,9 @@ dependencies = [ [[package]] name = "aws-lc-sys" -version = "0.38.0" +version = "0.39.0" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "4321e568ed89bb5a7d291a7f37997c2c0df89809d7b6d12062c81ddb54aa782e" +checksum = "1fa7e52a4c5c547c741610a2c6f123f3881e409b714cd27e6798ef020c514f0a" dependencies = [ "cc", "cmake", @@ -234,11 +234,30 @@ dependencies = [ "tower-http", ] +[[package]] +name = "axum-tracing-opentelemetry" +version = "0.33.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "4bedd2c385488b22a3a35b664fbc7f8e755d3ec6720848bc106b80cb5ae18fd7" +dependencies = [ + "axum", + "futures-core", + "futures-util", + "http", + "opentelemetry", + "opentelemetry-semantic-conventions", + "pin-project-lite", + "tower", + "tracing", + "tracing-opentelemetry", + "tracing-opentelemetry-instrumentation-sdk", +] + [[package]] name = "base62" -version = "2.2.3" +version = "2.2.4" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "1adf9755786e27479693dedd3271691a92b5e242ab139cacb9fb8e7fb5381111" +checksum = "cd637ac531c60eb7fbc4684dc061c2d7d90d73d758181aa02eeff0464b9eee4b" [[package]] name = "base64" @@ -766,19 +785,6 @@ version = "0.6.1" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "edd0f118536f44f5ccd48bcb8b111bdc3de888b58c74639dfb034a357d0f206d" -[[package]] -name = "env_logger" -version = "0.10.2" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "4cd405aab171cb85d6735e5c8d9db038c17d3ca007a4d2c25f337935c3d90580" -dependencies = [ - "humantime", - "is-terminal", - "log", - "regex", - "termcolor", -] - [[package]] name = "equivalent" version = "1.0.2" @@ -1280,12 +1286,6 @@ version = "1.0.3" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "df3b46402a9d5adb4c86a0cf463f42e19994e3ee891101b1841f30a545cb49a9" -[[package]] -name = "humantime" -version = "2.3.0" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "135b12329e5e3ce057a9f972339ea52bc954fe1e9358ef27f95e89716fbc5424" - [[package]] name = "hyper" version = "1.8.1" @@ -1605,25 +1605,14 @@ checksum = "d98f6fed1fde3f8c21bc40a1abb88dd75e67924f9cffc3ef95607bad8017f8e2" [[package]] name = "iri-string" -version = "0.7.10" +version = "0.7.11" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "c91338f0783edbd6195decb37bae672fd3b165faffb89bf7b9e6942f8b1a731a" +checksum = "d8e7418f59cc01c88316161279a7f665217ae316b388e58a0d10e29f54f1e5eb" dependencies = [ "memchr", "serde", ] -[[package]] -name = "is-terminal" -version = "0.4.17" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "3640c1c38b8e4e43584d8df18be5fc6b0aa314ce6ebf51b53313d4306cca8e46" -dependencies = [ - "hermit-abi", - "libc", - "windows-sys 0.61.2", -] - [[package]] name = "itertools" version = "0.10.5" @@ -1653,9 +1642,9 @@ dependencies = [ [[package]] name = "itoa" -version = "1.0.17" +version = "1.0.18" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "92ecc6618181def0457392ccd0ee51198e065e016d1d527a7ac1b6dc7c1f09d2" +checksum = "8f42a60cbdf9a97f5d2305f08a87dc4e09308d1276d28c869c684d7777685682" [[package]] name = "jni" @@ -1666,7 +1655,7 @@ dependencies = [ "cesu8", "cfg-if", "combine", - "jni-sys", + "jni-sys 0.3.1", "log", "thiserror 1.0.69", "walkdir", @@ -1675,9 +1664,31 @@ dependencies = [ [[package]] name = "jni-sys" -version = "0.3.0" +version = "0.3.1" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "8eaf4bc02d17cbdd7ff4c7438cafcdf7fb9a4613313ad11b4f8fefe7d3fa0130" +checksum = "41a652e1f9b6e0275df1f15b32661cf0d4b78d4d87ddec5e0c3c20f097433258" +dependencies = [ + "jni-sys 0.4.1", +] + +[[package]] +name = "jni-sys" +version = "0.4.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "c6377a88cb3910bee9b0fa88d4f42e1d2da8e79915598f65fb0c7ee14c878af2" +dependencies = [ + "jni-sys-macros", +] + +[[package]] +name = "jni-sys-macros" +version = "0.4.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "38c0b942f458fe50cdac086d2f946512305e5631e720728f2a61aabcd47a6264" +dependencies = [ + "quote", + "syn", +] [[package]] name = "jobserver" @@ -1749,6 +1760,7 @@ dependencies = [ "async-trait", "axum", "axum-prometheus", + "axum-tracing-opentelemetry", "chashmap", "derive_more 2.1.1", "dotenvy", @@ -1763,8 +1775,10 @@ dependencies = [ "mobc", "mobc-redis", "once_cell", + "opentelemetry", + "opentelemetry-otlp", + "opentelemetry_sdk", "postcard", - "pretty_env_logger", "prometheus", "prost", "prost-types", @@ -1785,6 +1799,9 @@ dependencies = [ "tonic", "tonic-prost", "tonic-prost-build", + "tracing", + "tracing-opentelemetry", + "tracing-subscriber", "urlencoding", "uuid", ] @@ -1810,6 +1827,15 @@ version = "0.1.2" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "112b39cec0b298b6c1999fee3e31427f74f676e4cb9879ed1a121b43661a4154" +[[package]] +name = "matchers" +version = "0.2.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "d1525a2a28c7f4fa0fc98bb91ae755d1e2d1505079e05539e35bc876b5d65ae9" +dependencies = [ + "regex-automata", +] + [[package]] name = "matchit" version = "0.8.4" @@ -2058,6 +2084,88 @@ version = "0.2.1" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "7c87def4c32ab89d880effc9e097653c8da5d6ef28e6b539d313baaacfbafcbe" +[[package]] +name = "opentelemetry" +version = "0.31.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "b84bcd6ae87133e903af7ef497404dda70c60d0ea14895fc8a5e6722754fc2a0" +dependencies = [ + "futures-core", + "futures-sink", + "js-sys", + "pin-project-lite", + "thiserror 2.0.18", + "tracing", +] + +[[package]] +name = "opentelemetry-http" +version = "0.31.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "d7a6d09a73194e6b66df7c8f1b680f156d916a1a942abf2de06823dd02b7855d" +dependencies = [ + "async-trait", + "bytes", + "http", + "opentelemetry", + "reqwest 0.12.28", +] + +[[package]] +name = "opentelemetry-otlp" +version = "0.31.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "1f69cd6acbb9af919df949cd1ec9e5e7fdc2ef15d234b6b795aaa525cc02f71f" +dependencies = [ + "http", + "opentelemetry", + "opentelemetry-http", + "opentelemetry-proto", + "opentelemetry_sdk", + "prost", + "reqwest 0.12.28", + "thiserror 2.0.18", + "tokio", + "tonic", + "tracing", +] + +[[package]] +name = "opentelemetry-proto" +version = "0.31.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "a7175df06de5eaee9909d4805a3d07e28bb752c34cab57fa9cff549da596b30f" +dependencies = [ + "opentelemetry", + "opentelemetry_sdk", + "prost", + "tonic", + "tonic-prost", +] + +[[package]] +name = "opentelemetry-semantic-conventions" +version = "0.31.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "e62e29dfe041afb8ed2a6c9737ab57db4907285d999ef8ad3a59092a36bdc846" + +[[package]] +name = "opentelemetry_sdk" +version = "0.31.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "e14ae4f5991976fd48df6d843de219ca6d31b01daaab2dad5af2badeded372bd" +dependencies = [ + "futures-channel", + "futures-executor", + "futures-util", + "opentelemetry", + "percent-encoding", + "rand 0.9.2", + "thiserror 2.0.18", + "tokio", + "tokio-stream", +] + [[package]] name = "owning_ref" version = "0.3.3" @@ -2235,16 +2343,6 @@ dependencies = [ "zerocopy", ] -[[package]] -name = "pretty_env_logger" -version = "0.5.0" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "865724d4dbe39d9f3dd3b52b88d859d66bcb2d6a0acfd5ea68a65fb66d4bdc1c" -dependencies = [ - "env_logger", - "log", -] - [[package]] name = "prettyplease" version = "0.2.37" @@ -2431,9 +2529,9 @@ dependencies = [ [[package]] name = "pulldown-cmark" -version = "0.13.1" +version = "0.13.3" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "83c41efbf8f90ac44de7f3a868f0867851d261b56291732d0cbf7cceaaeb55a6" +checksum = "7c3a14896dfa883796f1cb410461aef38810ea05f2b2c33c5aded3649095fdad" dependencies = [ "bitflags 2.11.0", "memchr", @@ -2799,6 +2897,7 @@ checksum = "eddd3ca559203180a307f12d114c268abf583f59b03cb906fd0b3ff8646c1147" dependencies = [ "base64 0.22.1", "bytes", + "futures-channel", "futures-core", "futures-util", "http", @@ -3060,9 +3159,9 @@ checksum = "f87165f0995f63a9fbeea62b64d10b4d9d8e78ec6d7d51fb2125fda7bb36788f" [[package]] name = "rustls-webpki" -version = "0.103.9" +version = "0.103.10" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "d7df23109aa6c1567d1c575b9952556388da57401e4ace1d15f79eedad0d8f53" +checksum = "df33b2b81ac578cabaf06b89b0631153a3f416b0a886e8a7a1707fb51abbd1ef" dependencies = [ "aws-lc-rs", "ring", @@ -3609,15 +3708,6 @@ dependencies = [ "windows-sys 0.61.2", ] -[[package]] -name = "termcolor" -version = "1.4.1" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "06794f8f6c5c898b3275aebefa6b8a1cb24cd2c6c79397ab15774837a0bc5755" -dependencies = [ - "winapi-util", -] - [[package]] name = "testcontainers" version = "0.27.1" @@ -4018,18 +4108,64 @@ dependencies = [ "tracing-core", ] +[[package]] +name = "tracing-opentelemetry" +version = "0.32.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "1ac28f2d093c6c477eaa76b23525478f38de514fa9aeb1285738d4b97a9552fc" +dependencies = [ + "js-sys", + "opentelemetry", + "smallvec 1.15.1", + "tracing", + "tracing-core", + "tracing-log", + "tracing-subscriber", + "web-time", +] + +[[package]] +name = "tracing-opentelemetry-instrumentation-sdk" +version = "0.32.4" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "bc2a7ad7b8bd011f482d1fdf95be20377cdd19f45aa9d1f9f902d746eddc3cad" +dependencies = [ + "http", + "opentelemetry", + "opentelemetry-semantic-conventions", + "tracing", + "tracing-opentelemetry", +] + +[[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 1.15.1", "thread_local", + "tracing", "tracing-core", "tracing-log", + "tracing-serde", ] [[package]] @@ -4123,9 +4259,9 @@ checksum = "8ecb6da28b8a351d773b68d5825ac39017e680750f980f3a1a85cd8dd28a47c1" [[package]] name = "ureq" -version = "3.2.0" +version = "3.3.0" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "fdc97a28575b85cfedf2a7e7d3cc64b3e11bd8ac766666318003abbacc7a21fc" +checksum = "dea7109cdcd5864d4eeb1b58a1648dc9bf520360d7af16ec26d0a9354bafcfc0" dependencies = [ "base64 0.22.1", "log", @@ -4133,14 +4269,14 @@ dependencies = [ "rustls", "rustls-pki-types", "ureq-proto", - "utf-8", + "utf8-zero", ] [[package]] name = "ureq-proto" -version = "0.5.3" +version = "0.6.0" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "d81f9efa9df032be5934a46a068815a10a042b494b6a58cb0a1a97bb5467ed6f" +checksum = "e994ba84b0bd1b1b0cf92878b7ef898a5c1760108fe7b6010327e274917a808c" dependencies = [ "base64 0.22.1", "http", @@ -4168,10 +4304,10 @@ source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "daf8dba3b7eb870caf1ddeed7bc9d2a049f3cfdfae7cb521b087cc33ae4c49da" [[package]] -name = "utf-8" -version = "0.7.6" +name = "utf8-zero" +version = "0.8.1" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "09cc8ee72d2a9becf2f2febe0205bbed8fc6615b7cb429ad062dc7b7ddd036a9" +checksum = "b8c0a043c9540bae7c578c88f91dda8bd82e59ae27c21baca69c8b191aaf5a6e" [[package]] name = "utf8_iter" @@ -4862,18 +4998,18 @@ dependencies = [ [[package]] name = "zerocopy" -version = "0.8.42" +version = "0.8.47" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "f2578b716f8a7a858b7f02d5bd870c14bf4ddbbcf3a4c05414ba6503640505e3" +checksum = "efbb2a062be311f2ba113ce66f697a4dc589f85e78a4aea276200804cea0ed87" dependencies = [ "zerocopy-derive", ] [[package]] name = "zerocopy-derive" -version = "0.8.42" +version = "0.8.47" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "7e6cc098ea4d3bd6246687de65af3f920c430e236bee1e3bf2e441463f08a02f" +checksum = "0e8bc7269b54418e7aeeef514aa68f8690b8c0489a06b0136e5f57c4c5ccab89" dependencies = [ "proc-macro2", "quote", diff --git a/Cargo.toml b/Cargo.toml index be15e6e..bf57a02 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -17,7 +17,13 @@ prometheus = "0.14.0" hyper = "1.8.1" # Logging and envs log = "0.4.29" -pretty_env_logger = "0.5.0" +tracing = "0.1.44" +tracing-subscriber = { version = "0.3.22", features = ["env-filter", "fmt", "json"] } +tracing-opentelemetry = "0.32.1" +opentelemetry = "0.31.0" +opentelemetry_sdk = { version = "0.31.0", features = ["rt-tokio"] } +opentelemetry-otlp = { version = "0.31.0", features = ["grpc-tonic"] } +axum-tracing-opentelemetry = "0.33.0" dotenvy = "0.15.7" # HTTP client with caching reqwest = { version = "0.13.2", default-features = false, features = ["rustls", "json"] } @@ -59,6 +65,7 @@ async-trait = "0.1.89" [dev-dependencies] testcontainers = "0.27.1" +opentelemetry_sdk = { version = "0.31.0", features = ["testing"] } [build-dependencies] tonic-prost-build = "0.14.5" diff --git a/docker-compose.yaml b/docker-compose.yaml index 0ca4a08..f05b9d2 100644 --- a/docker-compose.yaml +++ b/docker-compose.yaml @@ -26,6 +26,7 @@ services: - CACHE_CLEAN_UP_INTERVAL_SECS - SEARCH_RADIUS_METERS - QUERY_CHECK_MODE + - OTEL_EXPORTER_OTLP_ENDPOINT expose: - 8080 networks: diff --git a/src/handlers/limiter_test.rs b/src/handlers/limiter_test.rs index 657adc1..232acb0 100644 --- a/src/handlers/limiter_test.rs +++ b/src/handlers/limiter_test.rs @@ -4,7 +4,7 @@ use crate::testutils::start_redis; #[tokio::test] async fn test_rate_limiter() { - pretty_env_logger::init(); + let _ = tracing_subscriber::fmt::try_init(); let (_redis_container, redis_client) = start_redis().await; let limiter = RequestsLimiter::new(redis_client, 2, 60); diff --git a/src/handlers/mod.rs b/src/handlers/mod.rs index 4cce7ef..9aca221 100644 --- a/src/handlers/mod.rs +++ b/src/handlers/mod.rs @@ -78,13 +78,14 @@ pub fn preload_env_vars() { let _ = *INLINE_REQUESTS_LIMITER; } +#[tracing::instrument(skip(bot, usr_client), fields(query = %q.query))] pub async fn inline_handler(bot: Bot, q: InlineQuery, usr_client: UserService) -> HandlerResult { if !is_query_correct(&q.query) || rate_limit_exceeded(&q).await { bot.answer_inline_query(q.id, vec![]).await?; return Ok(()); } - log::info!("Got an inline query: {}", q.query); + tracing::info!("Got an inline query: {}", q.query); metrics::INLINE_COUNTER.inc_allowed(); let lang_code = &ensure_lang_code(q.from.id, q.from.language_code.clone(), &usr_client).await; @@ -101,7 +102,7 @@ fn is_query_correct(query: &str) -> bool { *QUERY_CHECK_MODE != QueryCheckMode::Regex ); if !allowed { - log::info!("Invalid query: {}", query); + tracing::info!("Invalid query: {}", query); metrics::INLINE_COUNTER.inc_bad_query(); } allowed @@ -110,7 +111,7 @@ fn is_query_correct(query: &str) -> bool { async fn rate_limit_exceeded(q: &InlineQuery) -> bool { let forbidden = !INLINE_REQUESTS_LIMITER.is_req_allowed(q).await; if forbidden { - log::info!("Requests limit was exceeded for {}", q.from.id); + tracing::info!("Requests limit was exceeded for {}", q.from.id); metrics::INLINE_COUNTER.inc_forbidden(); } forbidden @@ -134,7 +135,7 @@ pub async fn command_handler(bot: Bot, msg: Message, cmd: Command, me: Me, usr_c help::get_start_message(msg.from.as_ref().unwrap(), me, usr_client).await.into() }, Command::Start => { - log::warn!("The /start command was invoked without a FROM field for a message: {msg:?}"); + tracing::warn!("The /start command was invoked without a FROM field for a message: {msg:?}"); let lang_code = &determine_lang_code(&msg, &usr_client).await?; help::get_help_message(me, lang_code).into() } @@ -155,7 +156,7 @@ pub async fn command_handler(bot: Bot, msg: Message, cmd: Command, me: Me, usr_c } _ if usr_client.disabled() => { let lang_code = &determine_lang_code(&msg, &usr_client).await?; - log::error!("user-service is disabled but a command was invoked by {:?}", msg.from); + tracing::error!("user-service is disabled but a command was invoked by {:?}", msg.from); t!("error.service.user.disabled", locale = lang_code).to_string().into() }, _ if msg.from.is_none() => Err(anyhow!("some command was invoked without a FROM field for a message: {msg:?}"))?, @@ -175,7 +176,7 @@ pub async fn message_handler(bot: Bot, msg: Message, usr_client: UserService HandlerResult { - log::info!("Got a callback query for {}: {}", + tracing::info!("Got a callback query for {}: {}", q.from.id, q.data.clone().unwrap_or("".to_string())); @@ -197,6 +198,7 @@ pub async fn callback_handler(bot: Bot, q: CallbackQuery) -> HandlerResult { Ok(()) } +#[tracing::instrument(skip(bot, usr_client))] async fn cmd_loc_handler(bot: Bot, msg: Message, usr_client: UserService) -> HandlerResult { let from = msg.from.as_ref().ok_or("no from")?; let lang_code = &ensure_lang_code(from.id, from.language_code.clone(), &usr_client).await; @@ -205,7 +207,7 @@ async fn cmd_loc_handler(bot: Bot, msg: Message, usr_client: UserService return send_error(bot, msg, "error.query.empty", lang_code).await, Some(text) => text.to_string() }; - log::info!("Got a message query: {}", text); + tracing::info!("Got a message query: {}", text); let location = try_determine_location(from.id, &usr_client).await; let locations = resolve_locations(text, lang_code, location).await?; @@ -213,6 +215,7 @@ async fn cmd_loc_handler(bot: Bot, msg: Message, usr_client: UserService) -> Result, Box> { let query = query.as_str(); let locations = if let Some(coords) = COORDS_REGEXP.captures(query) { diff --git a/src/handlers/test.rs b/src/handlers/test.rs index 450ba2f..bb127d7 100644 --- a/src/handlers/test.rs +++ b/src/handlers/test.rs @@ -1,5 +1,23 @@ use super::{is_query_correct, COORDS_REGEXP, QUERY_REGEX}; +mod otel { + use opentelemetry_sdk::trace::InMemorySpanExporter; + use opentelemetry_sdk::trace::{SdkTracerProvider, SimpleSpanProcessor}; + use tracing::Subscriber; + use tracing_subscriber::{layer::SubscriberExt, Registry}; + + pub fn setup_otel_test() -> (InMemorySpanExporter, SdkTracerProvider, impl Subscriber + Send + Sync) { + let exporter = InMemorySpanExporter::default(); + let provider = SdkTracerProvider::builder() + .with_span_processor(SimpleSpanProcessor::new(exporter.clone())) + .build(); + let tracer = opentelemetry::trace::TracerProvider::tracer(&provider, "test"); + let subscriber = Registry::default() + .with(tracing_opentelemetry::layer().with_tracer(tracer)); + (exporter, provider, subscriber) + } +} + #[test] fn test_coords_regex() { let false_cases = [ @@ -52,7 +70,7 @@ fn test_query_regex() { "中国北京", "دبي مارينا، دبي، الإمارات العربية المتحدة", ]; - + run_test(false_cases, true_cases, |case| QUERY_REGEX.is_match(case)) } @@ -82,10 +100,55 @@ fn test_is_query_correct() { "中国北京", "دبي مارينا، دبي، الإمارات العربية المتحدة", ]; - + run_test(false_cases, true_cases, is_query_correct) } +#[tokio::test] +async fn test_resolve_locations_creates_span() { + let (exporter, _provider, subscriber) = otel::setup_otel_test(); + let _guard = tracing::subscriber::set_default(subscriber); + + let result = super::resolve_locations("55.7 37.6".to_string(), "en", None).await; + assert!(result.is_ok()); + + let spans = exporter.get_finished_spans().unwrap(); + assert!( + spans.iter().any(|s| s.name == "resolve_locations"), + "Expected span 'resolve_locations', got: {:?}", + spans.iter().map(|s| s.name.as_ref()).collect::>() + ); +} + +#[tokio::test] +async fn test_span_hierarchy() { + use tracing::Instrument; + + let (exporter, _provider, subscriber) = otel::setup_otel_test(); + let _guard = tracing::subscriber::set_default(subscriber); + + let root_span = tracing::info_span!("root"); + super::resolve_locations("55.7 37.6".to_string(), "en", None) + .instrument(root_span) + .await + .unwrap(); + + let spans = exporter.get_finished_spans().unwrap(); + let root = spans.iter().find(|s| s.name == "root").expect("root span not found"); + let child = spans.iter().find(|s| s.name == "resolve_locations").expect("child span not found"); + + assert_eq!( + child.span_context.trace_id(), + root.span_context.trace_id(), + "child and root must share the same trace_id" + ); + assert_eq!( + child.parent_span_id, + root.span_context.span_id(), + "child's parent_span_id must equal root's span_id" + ); +} + fn run_test( false_cases: [&str; N1], true_cases: [&str; N2], diff --git a/src/loc/google.rs b/src/loc/google.rs index 7c44919..79599c0 100644 --- a/src/loc/google.rs +++ b/src/loc/google.rs @@ -14,7 +14,7 @@ const FINDER_ENV_API_KEY: &str = "GOOGLE_MAPS_API_KEY"; static GAPI_MODE: Lazy = Lazy::new(|| { let val = std::env::var("GAPI_MODE").expect("GAPI_MODE must be set!"); - log::info!("GAPI_MODE is {val}"); + tracing::info!("GAPI_MODE is {val}"); GoogleAPIMode::from_str(val.as_str()).expect("Invalid value of GAPI_MODE") }); @@ -93,6 +93,7 @@ impl GoogleLocFinder { Self::init(api_key.as_str()) } + #[tracing::instrument(skip(self))] async fn find(&self, address: &str, params: SearchParams<'_>) -> LocResult { let mut results = self.find_geo(address, params).await?; if results.is_empty() { @@ -101,6 +102,7 @@ impl GoogleLocFinder { Ok(results) } + #[tracing::instrument(skip(self))] async fn find_geo(&self, address: &str, params: SearchParams<'_>) -> LocResult { self.geocode_req_counter.inc(); let bounds_part = params.location @@ -114,7 +116,7 @@ impl GoogleLocFinder { self.inc_resp_counter(&resp); let json = resp.json::().await?; - log::info!("Response from Google Maps Geocoding API: {json}"); + tracing::info!("Response from Google Maps Geocoding API: {json}"); let results = iter_over_array(&json["results"]) .filter_map(map_resp_geo) @@ -122,6 +124,7 @@ impl GoogleLocFinder { Ok(results) } + #[tracing::instrument(skip(self))] async fn find_text(&self, address: &str, params: SearchParams<'_>) -> LocResult { self.text_req_counter.inc(); let resp = self.client.post("https://places.googleapis.com/v1/places:searchText") @@ -133,7 +136,7 @@ impl GoogleLocFinder { self.inc_resp_counter(&resp); let json = resp.json::().await?; - log::info!("Response from Google Maps Text Search API: {json}"); + tracing::info!("Response from Google Maps Text Search API: {json}"); let results: Vec = iter_over_array(&json["places"]) .filter_map(map_resp_place) @@ -145,6 +148,7 @@ impl GoogleLocFinder { #[async_trait] impl LocFinder for GoogleLocFinder { + #[tracing::instrument(skip(self))] async fn find(&self, query: &str, lang_code: &str, location: Option<(f64, f64)>) -> LocResult { let params = SearchParams { lang_code, location }; match *GAPI_MODE { diff --git a/src/loc/mod.rs b/src/loc/mod.rs index 8219bcd..3947b7a 100644 --- a/src/loc/mod.rs +++ b/src/loc/mod.rs @@ -18,9 +18,9 @@ const DISABLE_ENV_PREFIX: &str = "DISABLE_FINDER_"; static SEARCH_RADIUS: Lazy = Lazy::new(|| { let val: u32 = std::env::var("SEARCH_RADIUS_METERS") .ok() - .and_then(|v| v.parse().map_err(|e| log::error!("couldn't parse SEARCH_RADIUS_METERS: {e}")).ok()) + .and_then(|v| v.parse().map_err(|e| tracing::error!("couldn't parse SEARCH_RADIUS_METERS: {e}")).ok()) .unwrap_or(1000); - log::info!("SEARCH_RADIUS_METERS is {val}"); + tracing::info!("SEARCH_RADIUS_METERS is {val}"); f64::from(val) / 10_000.0 // 6 digits after a comma have accuracy in 0.1 m, so we need to shift the dot at 5 digits }); @@ -84,6 +84,7 @@ impl SearchChain { self } + #[tracing::instrument(skip(self), fields(query, lang_code))] pub async fn find(&self, query: &str, lang_code: &str, location: Option<(f64, f64)>) -> Vec { let futures = self.regional_finders.get(lang_code) .unwrap_or(&self.global_finders) @@ -94,7 +95,7 @@ impl SearchChain { match fut.await { Ok(res) if !res.is_empty() => return res, Ok(_) => continue, - Err(err) => log::error!("couldn't fetch loc data: {err}"), + Err(err) => tracing::error!("couldn't fetch loc data: {err}"), } }; @@ -125,7 +126,7 @@ impl LocFinderChainWrapper { .map(|v| v == "true" || v == "1" || v == "yes" || v == "y") .unwrap_or(false); if disabled { - log::warn!("The {} finder is disabled!", self.env_suffix); + tracing::warn!("The {} finder is disabled!", self.env_suffix); None } else { Some(self.finder) @@ -133,7 +134,7 @@ impl LocFinderChainWrapper { } } -#[derive(Copy, Clone)] +#[derive(Debug, Copy, Clone)] struct SearchParams<'a> { lang_code: &'a str, location: Option<(f64, f64)> diff --git a/src/loc/osm.rs b/src/loc/osm.rs index 6237940..c64e749 100644 --- a/src/loc/osm.rs +++ b/src/loc/osm.rs @@ -35,6 +35,7 @@ impl OpenStreetMapLocFinder { #[async_trait] impl LocFinder for OpenStreetMapLocFinder { + #[tracing::instrument(skip(self))] async fn find(&self, query: &str, lang_code: &str, location: Option<(f64, f64)>) -> LocResult { self.api_req_counter.inc(); let viewbox_part = location @@ -43,7 +44,7 @@ impl LocFinder for OpenStreetMapLocFinder { .unwrap_or_default(); let query = urlencoding::encode(query); let url = format!("https://nominatim.openstreetmap.org/search?q={query}&format=json{viewbox_part}"); - log::debug!("Request: {url}"); + tracing::debug!("Request: {url}"); let resp = self.client.get(url) .header(USER_AGENT, "kozalosev/LocPlaceBot") .header(ACCEPT_LANGUAGE, lang_code) @@ -51,7 +52,7 @@ impl LocFinder for OpenStreetMapLocFinder { self.inc_resp_counter(&resp); let json = resp.json::().await?; - log::info!("Response from Open Street Map Nominatim API: {json}"); + tracing::info!("Response from Open Street Map Nominatim API: {json}"); let empty = Vec::new(); let results = json.as_array().unwrap_or(&empty).iter() @@ -80,4 +81,4 @@ fn map_resp(v: &serde_json::Value) -> Option { Some(Location { address, latitude, longitude }) -} \ No newline at end of file +} diff --git a/src/loc/yandex.rs b/src/loc/yandex.rs index 48f5f42..8973509 100644 --- a/src/loc/yandex.rs +++ b/src/loc/yandex.rs @@ -14,7 +14,7 @@ const PLACES_ENV_API_KEY: &str = "YANDEX_MAPS_PLACES_API_KEY"; pub static YAPI_MODE: Lazy = Lazy::new(|| { let val = std::env::var("YAPI_MODE").expect("YAPI_MODE must be set!"); - log::info!("YAPI_MODE is {val}"); + tracing::info!("YAPI_MODE is {val}"); YandexAPIMode::from_str(val.as_str()).expect("Invalid value of YAPI_MODE") }); @@ -77,6 +77,7 @@ impl YandexLocFinder { Self::init(geocode_api_key, places_api_key) } + #[tracing::instrument(skip(self))] async fn find_geo_place(&self, address: &str, params: SearchParams<'_>) -> LocResult { let mut results = self.find_geo(address, params).await?; if results.is_empty() { @@ -85,6 +86,7 @@ impl YandexLocFinder { Ok(results) } + #[tracing::instrument(skip(self))] async fn find_geo(&self, address: &str, params: SearchParams<'_>) -> LocResult { self.geocode_req_counter.inc(); @@ -95,7 +97,7 @@ impl YandexLocFinder { self.inc_resp_counter(&resp); let json = resp.json::().await?; - log::info!("Response from Yandex Maps Geocoder: {json}"); + tracing::info!("Response from Yandex Maps Geocoder: {json}"); let empty: Vec = Vec::new(); let result = json["response"]["GeoObjectCollection"]["featureMember"] @@ -107,6 +109,7 @@ impl YandexLocFinder { Ok(result) } + #[tracing::instrument(skip(self))] async fn find_place(&self, address: &str, params: SearchParams<'_>) -> LocResult { self.place_req_counter.inc(); @@ -120,7 +123,7 @@ impl YandexLocFinder { self.inc_resp_counter(&resp); let json = resp.json::().await?; - log::info!("Response from Yandex Maps Places API: {json}"); + tracing::info!("Response from Yandex Maps Places API: {json}"); let empty: Vec = Vec::new(); let result = json["features"] @@ -135,6 +138,7 @@ impl YandexLocFinder { #[async_trait] impl LocFinder for YandexLocFinder { + #[tracing::instrument(skip(self))] async fn find(&self, query: &str, lang_code: &str, location: Option<(f64, f64)>) -> LocResult { let params = SearchParams { lang_code, location }; match *YAPI_MODE { @@ -164,7 +168,7 @@ fn geocode_elem_mapper(v: &serde_json::Value) -> Option { .split(' ') .collect::>(); if pos.len() < 2 { - log::error!("pos length < 2: {pos:?}"); + tracing::error!("pos length < 2: {pos:?}"); return None } let longitude: f64 = pos[0].parse().ok()?; diff --git a/src/main.rs b/src/main.rs index c3e6197..d787aa0 100644 --- a/src/main.rs +++ b/src/main.rs @@ -9,6 +9,7 @@ mod users; mod eula; mod commands; mod redis; +mod observability; #[cfg(test)] mod testutils; @@ -16,6 +17,7 @@ mod testutils; use std::env::VarError; use std::net::SocketAddr; use std::time::Duration; +use axum_tracing_opentelemetry::middleware::{OtelAxumLayer, OtelInResponseLayer}; use futures::future::join_all; use reqwest::Url; use rust_i18n::i18n; @@ -40,8 +42,8 @@ i18n!(fallback = "en"); // load localizations with default parameters async fn main() -> Result<(), Box> { #[cfg(debug_assertions)] dotenvy::dotenv()?; - - pretty_env_logger::init(); + + let tracer_provider = observability::init_tracing()?; handlers::preload_env_vars(); let handler = dptree::entry() @@ -72,7 +74,7 @@ async fn main() -> Result<(), Box> { if set_my_commands_failed { Err("couldn't set the bot's commands")? } else { - log::info!("The commands has been updated successfully!") + tracing::info!("The commands has been updated successfully!") } let webhook_url: Option = match std::env::var(ENV_WEBHOOK_URL) { @@ -102,7 +104,7 @@ async fn main() -> Result<(), Box> { UserService::Connected(grpc) }, Err(e) => { - log::error!("couldn't connect to user-service: {e}"); + tracing::error!("couldn't connect to user-service: {e}"); UserService::Disabled } }; @@ -111,9 +113,9 @@ async fn main() -> Result<(), Box> { RedisStorage::open(&REDIS.connection_url, Json).await? ]; - match webhook_url { + let result = match webhook_url { Some(url) => { - log::info!("Setting a webhook: {url}"); + tracing::info!("Setting a webhook: {url}"); let (mut listener, stop_flag, bot_router) = axum_to_router(bot.clone(), Options::new(addr, url)).await?; let stop_token = listener.stop_token(); @@ -127,13 +129,12 @@ async fn main() -> Result<(), Box> { let srv = tokio::spawn(async move { let tcp_listener = tokio::net::TcpListener::bind(addr) .await - .map_err(|err| { - stop_token.stop(); - err - })?; + .inspect_err(|_| stop_token.stop())?; let app = axum::Router::new() .merge(metrics_router) - .merge(bot_router); + .merge(bot_router) + .layer(OtelInResponseLayer) + .layer(OtelAxumLayer::default()); axum::serve(tcp_listener, app) .with_graceful_shutdown(stop_flag) .await @@ -144,7 +145,7 @@ async fn main() -> Result<(), Box> { res?.map_err(Into::into) } None => { - log::info!("The polling dispatcher is activating..."); + tracing::info!("The polling dispatcher is activating..."); let bot_fut = tokio::spawn(async move { Dispatcher::builder(bot, handler) @@ -157,12 +158,15 @@ async fn main() -> Result<(), Box> { let srv = tokio::spawn(async move { let tcp_listener = tokio::net::TcpListener::bind(addr).await?; - axum::serve(tcp_listener, metrics_router) + let app = metrics_router + .layer(OtelInResponseLayer) + .layer(OtelAxumLayer::default()); + axum::serve(tcp_listener, app) .with_graceful_shutdown(async { tokio::signal::ctrl_c() .await .expect("failed to install CTRL+C signal handler"); - log::info!("Shutdown of the metrics server") + tracing::info!("Shutdown of the metrics server") }) .await }); @@ -170,5 +174,8 @@ async fn main() -> Result<(), Box> { let (res, _) = futures::join!(srv, bot_fut); res?.map_err(Into::into) } - } + }; + + tracer_provider.shutdown()?; + result } diff --git a/src/observability.rs b/src/observability.rs new file mode 100644 index 0000000..ff46d0b --- /dev/null +++ b/src/observability.rs @@ -0,0 +1,58 @@ +use opentelemetry::global; +use opentelemetry::trace::TracerProvider; +use opentelemetry_sdk::Resource; +use opentelemetry_otlp::{SpanExporter, WithExportConfig}; +use opentelemetry_sdk::trace::SdkTracerProvider; +use tracing_subscriber::{Layer, layer::SubscriberExt, util::SubscriberInitExt, EnvFilter}; + +const SERVICE_NAME: &str = env!("CARGO_PKG_NAME"); + +/// Initialize tracing subscriber, optionally with OpenTelemetry OTLP export. +/// +/// Bridges existing `log::*` calls from libraries into the tracing pipeline +/// via `tracing_subscriber`'s built-in `tracing-log` feature (called inside `try_init`). +/// +/// Configuration via environment variables: +/// - `OTEL_EXPORTER_OTLP_ENDPOINT`: OTLP endpoint. If unset, OTLP export is +/// disabled and only console output is produced (useful for local development). +/// - `RUST_LOG`: console log level filter +pub fn init_tracing() -> Result> { + let provider = build_provider()?; + global::set_tracer_provider(provider.clone()); + + // Suppress noisy internals at the OTel level; console verbosity is controlled by RUST_LOG + let otel_filter = EnvFilter::new("trace,h2=off,hyper=off,tower=off,teloxide=off,reqwest=off"); + let telemetry_layer = tracing_opentelemetry::layer() + .with_tracer(provider.tracer(SERVICE_NAME)) + .with_filter(otel_filter); + let fmt_layer = tracing_subscriber::fmt::layer() + .with_target(true) + .with_line_number(true) + .with_filter(EnvFilter::from_default_env()); + tracing_subscriber::registry() + .with(telemetry_layer) + .with(fmt_layer) + .try_init()?; + + tracing::info!(service_name = %SERVICE_NAME, "Tracing initialized"); + Ok(provider) +} + +fn build_provider() -> Result> { + let Some(endpoint) = std::env::var("OTEL_EXPORTER_OTLP_ENDPOINT").ok() else { + tracing::warn!("OTEL_EXPORTER_OTLP_ENDPOINT is not set — OTLP export disabled"); + return Ok(SdkTracerProvider::builder().build()); + }; + + let otlp_exporter = SpanExporter::builder() + .with_tonic() + .with_endpoint(endpoint) + .build()?; + let resource = Resource::builder() + .with_service_name(SERVICE_NAME.to_owned()) + .build(); + Ok(SdkTracerProvider::builder() + .with_batch_exporter(otlp_exporter) + .with_resource(resource) + .build()) +} \ No newline at end of file