From 5eba7ea8e2927fd61408d6f23ccdabc471dd2aef Mon Sep 17 00:00:00 2001 From: Eason <30045503+Eason0729@users.noreply.github.com> Date: Sat, 20 Jul 2024 05:30:54 +0000 Subject: [PATCH] refactor(backend): impl telemetry in announcement resource(and it's related endpoints) --- Cargo.lock | 11 +++ backend/Cargo.toml | 1 + backend/src/controller/crypto.rs | 5 -- backend/src/endpoint/announcement.rs | 119 ++++++++++++++++++++------- backend/src/endpoint/mod.rs | 1 + backend/src/entity/announcement.rs | 4 +- backend/src/entity/mod.rs | 1 + backend/src/entity/util/with.rs | 2 + backend/src/util/bound.rs | 3 + backend/src/util/rate_limit.rs | 1 + 10 files changed, 109 insertions(+), 39 deletions(-) diff --git a/Cargo.lock b/Cargo.lock index e487673..7d03a43 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -712,6 +712,7 @@ dependencies = [ "tower-http", "tracing", "tracing-core", + "tracing-futures", "tracing-opentelemetry", "tracing-subscriber", "uuid", @@ -6225,6 +6226,16 @@ dependencies = [ "valuable", ] +[[package]] +name = "tracing-futures" +version = "0.2.5" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "97d095ae15e245a057c8e8451bab9b3ee1e1f68e9ba2b4fbc18d0ac5237835f2" +dependencies = [ + "pin-project", + "tracing", +] + [[package]] name = "tracing-log" version = "0.2.0" diff --git a/backend/Cargo.toml b/backend/Cargo.toml index e945579..abd2cfb 100644 --- a/backend/Cargo.toml +++ b/backend/Cargo.toml @@ -41,6 +41,7 @@ governor = "0.6.0" http = "^0.2" lazy_static = "1.5.0" prost-wkt-types = { workspace = true } +tracing-futures = "0.2.5" [dependencies.grpc] path = "../grpc" diff --git a/backend/src/controller/crypto.rs b/backend/src/controller/crypto.rs index 4e7d2ac..216107f 100644 --- a/backend/src/controller/crypto.rs +++ b/backend/src/controller/crypto.rs @@ -32,7 +32,6 @@ pub struct CryptoController { } impl CryptoController { - #[tracing::instrument(parent=span,name="crypto_construct",level = "info",skip_all)] pub fn new(span: &Span) -> Self { let salt = CONFIG.database.salt.as_bytes().to_vec(); Self { @@ -41,7 +40,6 @@ impl CryptoController { } } /// hash `src` and compare hash value with `hashed` - #[tracing::instrument(name = "crypto_hasheq_controller", level = "debug", skip_all)] pub fn hash_eq(&self, src: &str, hashed: &[u8]) -> bool { let src_hashed: Vec = self.hash(src); let mut result = true; @@ -53,7 +51,6 @@ impl CryptoController { result } /// get BLAKE2b-512 hashed bytes with salt - #[tracing::instrument(name = "crypto_hash_controller", level = "debug", skip_all)] pub fn hash(&self, src: &str) -> Vec { let mut hasher = Blake2b512::new(); hasher.update([src.as_bytes(), self.salt.as_slice()].concat()); @@ -64,7 +61,6 @@ impl CryptoController { /// Serialize and calculate checksum and return /// /// Note that it shouldn't be an security measurement - #[tracing::instrument(level = "debug", skip_all, name = "encode")] pub fn encode(&self, obj: M) -> Result { let mut raw = postcard::to_allocvec(&obj)?; @@ -80,7 +76,6 @@ impl CryptoController { /// check signature and return the object /// /// Error if signature invaild - #[tracing::instrument(level = "debug", skip_all, name = "decode")] pub fn decode(&self, raw: String) -> Result { let mut raw = URL_SAFE_NO_PAD.decode(raw)?; diff --git a/backend/src/endpoint/announcement.rs b/backend/src/endpoint/announcement.rs index 21b952a..9173e54 100644 --- a/backend/src/endpoint/announcement.rs +++ b/backend/src/endpoint/announcement.rs @@ -1,4 +1,5 @@ use super::tools::*; +use opentelemetry::trace::FutureExt; use grpc::backend::announcement_server::*; @@ -51,7 +52,12 @@ impl From for AnnouncementInfo { #[async_trait] impl Announcement for ArcServer { - #[instrument(skip_all, level = "debug")] + #[instrument( + skip_all, + level = "info", + name = "Announcement.list", + err(level = "debug", Display) + )] async fn list( &self, req: Request, @@ -92,7 +98,12 @@ impl Announcement for ArcServer { remain, })) } - #[instrument(skip_all, level = "debug")] + #[instrument( + skip_all, + level = "info", + name = "Announcement.full_info", + err(level = "debug", Display) + )] async fn full_info(&self, req: Request) -> Result, Status> { let (auth, req) = self.rate_limit(req).in_current_span().await?; @@ -108,7 +119,40 @@ impl Announcement for ArcServer { Ok(Response::new(model.with_auth(&auth).into())) } - #[instrument(skip_all, level = "debug")] + #[instrument( + skip_all, + level = "info", + name = "Announcement.full_info_by_contest", + err(level = "debug", Display) + )] + async fn full_info_by_contest( + &self, + req: Request, + ) -> Result, Status> { + let (auth, req) = self.rate_limit(req).in_current_span().await?; + + let parent: contest::IdModel = + contest::Entity::related_read_by_id(&auth, Into::::into(req.contest_id), &self.db) + .in_current_span() + .await?; + let model = parent + .upgrade() + .find_related(Entity) + .filter(Column::Id.eq(Into::::into(req.announcement_id))) + .one(self.db.deref()) + .instrument(info_span!("fetch").or_current()) + .await + .map_err(Into::::into)? + .ok_or(Error::NotInDB)?; + + Ok(Response::new(model.with_auth(&auth).into())) + } + #[instrument( + skip_all, + level = "info", + name = "Announcement.create", + err(level = "debug", Display) + )] async fn create( &self, req: Request, @@ -143,9 +187,16 @@ impl Announcement for ArcServer { self.dup.store(user_id, uuid, id.clone()); tracing::debug!(id = id.id, "announcement_created"); + tracing::info!(count.announcement = 1); + Ok(Response::new(id)) } - #[instrument(skip_all, level = "debug")] + #[instrument( + skip_all, + level = "info", + name = "Announcement.update", + err(level = "debug", Display) + )] async fn update( &self, req: Request, @@ -182,7 +233,12 @@ impl Announcement for ArcServer { Ok(Response::new(())) } - #[instrument(skip_all, level = "debug")] + #[instrument( + skip_all, + level = "info", + name = "Announcement.remove", + err(level = "debug", Display) + )] async fn remove(&self, req: Request) -> Result, Status> { let (auth, req) = self.rate_limit(req).in_current_span().await?; @@ -198,9 +254,16 @@ impl Announcement for ArcServer { tracing::debug!(id = req.id); + tracing::info!(counter.announcement = -1); + Ok(Response::new(())) } - #[instrument(skip_all, level = "debug")] + #[instrument( + skip_all, + level = "info", + name = "Announcement.add_to_contest", + err(level = "debug", Display) + )] async fn add_to_contest( &self, req: Request, @@ -244,7 +307,12 @@ impl Announcement for ArcServer { Ok(Response::new(())) } - #[instrument(skip_all, level = "debug")] + #[instrument( + skip_all, + level = "info", + name = "Announcement.remove_from_contest", + err(level = "debug", Display) + )] async fn remove_from_contest( &self, req: Request, @@ -269,7 +337,12 @@ impl Announcement for ArcServer { Ok(Response::new(())) } - #[instrument(skip_all, level = "debug")] + #[instrument( + skip_all, + level = "info", + name = "Announcement.publish", + err(level = "debug", Display) + )] async fn publish(&self, req: Request) -> Result, Status> { let (auth, req) = self.rate_limit(req).in_current_span().await?; let perm = auth.user_perm(); @@ -299,7 +372,12 @@ impl Announcement for ArcServer { Ok(Response::new(())) } - #[instrument(skip_all, level = "debug")] + #[instrument( + skip_all, + level = "info", + name = "Announcement.unpublish", + err(level = "debug", Display) + )] async fn unpublish(&self, req: Request) -> Result, Status> { let (auth, req) = self.rate_limit(req).in_current_span().await?; let perm = auth.user_perm(); @@ -329,27 +407,4 @@ impl Announcement for ArcServer { Ok(Response::new(())) } - #[instrument(skip_all, level = "debug")] - async fn full_info_by_contest( - &self, - req: Request, - ) -> Result, Status> { - let (auth, req) = self.rate_limit(req).in_current_span().await?; - - let parent: contest::IdModel = - contest::Entity::related_read_by_id(&auth, Into::::into(req.contest_id), &self.db) - .in_current_span() - .await?; - let model = parent - .upgrade() - .find_related(Entity) - .filter(Column::Id.eq(Into::::into(req.announcement_id))) - .one(self.db.deref()) - .instrument(info_span!("fetch").or_current()) - .await - .map_err(Into::::into)? - .ok_or(Error::NotInDB)?; - - Ok(Response::new(model.with_auth(&auth).into())) - } } diff --git a/backend/src/endpoint/mod.rs b/backend/src/endpoint/mod.rs index fe416d0..db47722 100644 --- a/backend/src/endpoint/mod.rs +++ b/backend/src/endpoint/mod.rs @@ -36,6 +36,7 @@ mod tools { time::*, }; pub use crate::{fill_active_model, fill_exist_active_model, server::ArcServer, TonicStream}; + pub use tracing::{Instrument, Level}; } // FIXME: currently we report transaction error as internal error, diff --git a/backend/src/entity/announcement.rs b/backend/src/entity/announcement.rs index c9a0730..c62e453 100644 --- a/backend/src/entity/announcement.rs +++ b/backend/src/entity/announcement.rs @@ -1,6 +1,5 @@ use super::*; use grpc::backend::list_announcement_request::Sort; -use tracing::instrument; pub static NAME: &str = "announcement"; @@ -252,7 +251,6 @@ impl WithAuthTrait for Paginator {} impl Paginator { pub fn new_text(text: String, start_from_end: bool) -> Self { - // FIXME: check dup text Self::Text(TextPaginator::new(text, start_from_end)) } pub fn new_sort(sort: Sort, start_from_end: bool) -> Self { @@ -273,6 +271,7 @@ impl Paginator { } impl<'a, 'b> WithDB<'a, WithAuth<'b, Paginator>> { + #[instrument(skip_all, err(level = "debug", Display))] pub async fn fetch(&mut self, size: u64, offset: i64) -> Result, Error> { let db = self.0; let auth = self.1 .0; @@ -283,6 +282,7 @@ impl<'a, 'b> WithDB<'a, WithAuth<'b, Paginator>> { Paginator::Default(ref mut x) => x.fetch(size, offset, auth, db).await, } } + #[instrument(skip_all, err(level = "debug", Display))] pub async fn remain(&self) -> Result { let db = self.0; let auth = self.1 .0; diff --git a/backend/src/entity/mod.rs b/backend/src/entity/mod.rs index 37bd73e..73ff80b 100644 --- a/backend/src/entity/mod.rs +++ b/backend/src/entity/mod.rs @@ -17,6 +17,7 @@ pub mod util; use sea_orm::{ entity::prelude::*, EntityTrait, FromQueryResult, PrimaryKeyTrait, QueryFilter, Select, }; +use tracing::{instrument, Level}; use crate::util::{auth::Auth, error::Error}; use tonic::async_trait; diff --git a/backend/src/entity/util/with.rs b/backend/src/entity/util/with.rs index fd8043a..fe7e5b4 100644 --- a/backend/src/entity/util/with.rs +++ b/backend/src/entity/util/with.rs @@ -1,7 +1,9 @@ use crate::util::auth::Auth; use sea_orm::DatabaseConnection; +#[derive(Debug)] pub struct WithAuth<'a, T>(pub &'a Auth, pub T); +#[derive(Debug)] pub struct WithDB<'a, T>(pub &'a DatabaseConnection, pub T); pub trait WithAuthTrait diff --git a/backend/src/util/bound.rs b/backend/src/util/bound.rs index 3dce728..d530cc2 100644 --- a/backend/src/util/bound.rs +++ b/backend/src/util/bound.rs @@ -1,11 +1,14 @@ use super::error::Error; use grpc::backend::*; +use tracing::instrument; pub trait BoundCheck { /// return true if fail fn check(&self) -> bool; + #[instrument(skip_all, level = "info")] fn bound_check(&self) -> Result<(), tonic::Status> { if self.check() { + tracing::warn!(msg = "bound check fail"); Err(Error::NumberTooLarge.into()) } else { Ok(()) diff --git a/backend/src/util/rate_limit.rs b/backend/src/util/rate_limit.rs index 3479522..16f6ecb 100644 --- a/backend/src/util/rate_limit.rs +++ b/backend/src/util/rate_limit.rs @@ -80,6 +80,7 @@ impl Server { Ok((auth, req)) } + #[instrument(skip_all, level = "info")] pub async fn rate_limit( &self, req: tonic::Request,