From a1928f7ada5d949555fffbafa4742ae7799123e7 Mon Sep 17 00:00:00 2001 From: Denis Cornehl Date: Wed, 6 Mar 2024 16:48:06 +0100 Subject: [PATCH] drop rendering times recording in favor of sentry performance tracing --- src/metrics/mod.rs | 4 ---- src/storage/mod.rs | 32 +++++------------------------ src/web/metrics.rs | 51 +--------------------------------------------- src/web/rustdoc.rs | 31 ---------------------------- 4 files changed, 6 insertions(+), 112 deletions(-) diff --git a/src/metrics/mod.rs b/src/metrics/mod.rs index b08d731f6..ccddd35cb 100644 --- a/src/metrics/mod.rs +++ b/src/metrics/mod.rs @@ -87,10 +87,6 @@ metrics! { pub(crate) routes_visited: IntCounterVec["route"], /// The response times of various docs.rs routes pub(crate) response_time: HistogramVec["route"], - /// The time it takes to render a rustdoc page - pub(crate) rustdoc_rendering_times: HistogramVec["step"], - /// The time it takes to render a rustdoc redirect page - pub(crate) rustdoc_redirect_rendering_times: HistogramVec["step"], /// Count of recently accessed crates pub(crate) recent_crates: IntGaugeVec["duration"], diff --git a/src/storage/mod.rs b/src/storage/mod.rs index f8efc8662..e2dd14eba 100644 --- a/src/storage/mod.rs +++ b/src/storage/mod.rs @@ -6,10 +6,7 @@ mod s3; pub use self::compression::{compress, decompress, CompressionAlgorithm, CompressionAlgorithms}; use self::database::DatabaseBackend; use self::s3::S3Backend; -use crate::{ - db::Pool, error::Result, utils::spawn_blocking, web::metrics::RenderingTimesRecorder, Config, - InstanceMetrics, -}; +use crate::{db::Pool, error::Result, utils::spawn_blocking, Config, InstanceMetrics}; use anyhow::{anyhow, ensure}; use chrono::{DateTime, Utc}; use fn_error_context::context; @@ -175,8 +172,7 @@ impl AsyncStorage { /// * `path` - the wanted path inside the documentation. /// * `archive_storage` - if `true`, we will assume we have a remove ZIP archive and an index /// where we can fetch the requested path from inside the ZIP file. - /// * `fetch_time` - used to collect metrics when using the storage inside web server handlers. - #[instrument(skip(fetch_time))] + #[instrument] pub(crate) async fn fetch_rustdoc_file( &self, name: &str, @@ -184,7 +180,6 @@ impl AsyncStorage { latest_build_id: i32, path: &str, archive_storage: bool, - fetch_time: Option<&mut RenderingTimesRecorder<'_>>, ) -> Result { trace!("fetch rustdoc file"); Ok(if archive_storage { @@ -193,13 +188,9 @@ impl AsyncStorage { latest_build_id, path, self.max_file_size_for(path), - fetch_time, ) .await? } else { - if let Some(fetch_time) = fetch_time { - fetch_time.step("fetch from storage"); - } // Add rustdoc prefix, name and version to the path for accessing the file stored in the database let remote_path = format!("rustdoc/{name}/{version}/{path}"); self.get(&remote_path, self.max_file_size_for(path)).await? @@ -221,7 +212,6 @@ impl AsyncStorage { latest_build_id, path, self.max_file_size_for(path), - None, ) .await? } else { @@ -349,18 +339,14 @@ impl AsyncStorage { Ok(local_index_path) } - #[instrument(skip(fetch_time))] + #[instrument] pub(crate) async fn get_from_archive( &self, archive_path: &str, latest_build_id: i32, path: &str, max_size: usize, - mut fetch_time: Option<&mut RenderingTimesRecorder<'_>>, ) -> Result { - if let Some(ref mut t) = fetch_time { - t.step("find path in index"); - } let index_filename = self .download_archive_index(archive_path, latest_build_id) .await?; @@ -371,9 +357,6 @@ impl AsyncStorage { }? .ok_or(PathNotFoundError)?; - if let Some(t) = fetch_time { - t.step("range request"); - } let blob = self .get_range( archive_path, @@ -640,7 +623,6 @@ impl Storage { latest_build_id: i32, path: &str, archive_storage: bool, - fetch_time: Option<&mut RenderingTimesRecorder<'_>>, ) -> Result { self.runtime.block_on(self.inner.fetch_rustdoc_file( name, @@ -648,7 +630,6 @@ impl Storage { latest_build_id, path, archive_storage, - fetch_time, )) } @@ -730,14 +711,12 @@ impl Storage { latest_build_id: i32, path: &str, max_size: usize, - fetch_time: Option<&mut RenderingTimesRecorder<'_>>, ) -> Result { self.runtime.block_on(self.inner.get_from_archive( archive_path, latest_build_id, path, max_size, - fetch_time, )) } @@ -1172,14 +1151,13 @@ mod backend_tests { assert!(local_index_location.exists()); assert!(storage.exists_in_archive("folder/test.zip", 0, "src/main.rs",)?); - let file = - storage.get_from_archive("folder/test.zip", 0, "Cargo.toml", std::usize::MAX, None)?; + let file = storage.get_from_archive("folder/test.zip", 0, "Cargo.toml", std::usize::MAX)?; assert_eq!(file.content, b"data"); assert_eq!(file.mime, "text/toml"); assert_eq!(file.path, "folder/test.zip/Cargo.toml"); let file = - storage.get_from_archive("folder/test.zip", 0, "src/main.rs", std::usize::MAX, None)?; + storage.get_from_archive("folder/test.zip", 0, "src/main.rs", std::usize::MAX)?; assert_eq!(file.content, b"data"); assert_eq!(file.mime, "text/rust"); assert_eq!(file.path, "folder/test.zip/src/main.rs"); diff --git a/src/web/metrics.rs b/src/web/metrics.rs index f767e9fe6..b5157b2d1 100644 --- a/src/web/metrics.rs +++ b/src/web/metrics.rs @@ -9,10 +9,8 @@ use axum::{ middleware::Next, response::IntoResponse, }; -use prometheus::{proto::MetricFamily, Encoder, HistogramVec, TextEncoder}; +use prometheus::{proto::MetricFamily, Encoder, TextEncoder}; use std::{borrow::Cow, sync::Arc, time::Instant}; -#[cfg(test)] -use tracing::debug; async fn fetch_and_render_metrics( fetch_metrics: impl Fn() -> Result> + Send + 'static, @@ -112,53 +110,6 @@ pub(crate) async fn request_recorder( result } -struct RenderingTime { - start: Instant, - step: &'static str, -} - -pub(crate) struct RenderingTimesRecorder<'a> { - metric: &'a HistogramVec, - current: Option, -} - -impl<'a> RenderingTimesRecorder<'a> { - pub(crate) fn new(metric: &'a HistogramVec) -> Self { - Self { - metric, - current: None, - } - } - - pub(crate) fn step(&mut self, step: &'static str) { - self.record_current(); - self.current = Some(RenderingTime { - start: Instant::now(), - step, - }); - } - - fn record_current(&mut self) { - if let Some(current) = self.current.take() { - #[cfg(test)] - debug!( - "rendering time - {}: {:?}", - current.step, - current.start.elapsed() - ); - self.metric - .with_label_values(&[current.step]) - .observe(duration_to_seconds(current.start.elapsed())); - } - } -} - -impl Drop for RenderingTimesRecorder<'_> { - fn drop(&mut self) { - self.record_current(); - } -} - #[cfg(test)] mod tests { use crate::test::wrapper; diff --git a/src/web/rustdoc.rs b/src/web/rustdoc.rs index b44b55ae1..c7a8c0d31 100644 --- a/src/web/rustdoc.rs +++ b/src/web/rustdoc.rs @@ -14,7 +14,6 @@ use crate::{ extractors::{DbConnection, Path}, file::File, match_version, - metrics::RenderingTimesRecorder, page::TemplateData, MetaData, ReqVersion, }, @@ -90,7 +89,6 @@ async fn try_serve_legacy_toolchain_asset( #[instrument(skip_all)] pub(crate) async fn rustdoc_redirector_handler( Path(params): Path, - Extension(metrics): Extension>, Extension(storage): Extension>, Extension(config): Extension>, mut conn: DbConnection, @@ -116,8 +114,6 @@ pub(crate) async fn rustdoc_redirector_handler( )?) } - let mut rendering_time = RenderingTimesRecorder::new(&metrics.rustdoc_redirect_rendering_times); - // global static assets for older builds are served from the root, which ends up // in this handler as `params.name`. if let Some((_, extension)) = params.name.rsplit_once('.') { @@ -125,7 +121,6 @@ pub(crate) async fn rustdoc_redirector_handler( .binary_search(&extension) .is_ok() { - rendering_time.step("serve static asset"); return try_serve_legacy_toolchain_asset(storage, config, params.name) .instrument(info_span!("serve static asset")) .await; @@ -162,7 +157,6 @@ pub(crate) async fn rustdoc_redirector_handler( // it doesn't matter if the version that was given was exact or not, since we're redirecting // anyway - rendering_time.step("match version"); let matched_release = match_version( &mut conn, &crate_name, @@ -177,13 +171,9 @@ pub(crate) async fn rustdoc_redirector_handler( if let Some(ref target) = params.target { if target.ends_with(".js") { // this URL is actually from a crate-internal path, serve it there instead - rendering_time.step("serve JS for crate"); - return async { let krate = CrateDetails::from_matched_release(&mut conn, matched_release).await?; - rendering_time.step("fetch from storage"); - match storage .fetch_rustdoc_file( &crate_name, @@ -191,7 +181,6 @@ pub(crate) async fn rustdoc_redirector_handler( krate.latest_build_id.unwrap_or(0), target, krate.archive_storage, - Some(&mut rendering_time), ) .await { @@ -231,8 +220,6 @@ pub(crate) async fn rustdoc_redirector_handler( } if matched_release.rustdoc_status() { - rendering_time.step("redirect to doc"); - let url_str = if let Some(target) = target { format!( "/{crate_name}/{}/{target}/{}/", @@ -261,7 +248,6 @@ pub(crate) async fn rustdoc_redirector_handler( )? .into_response()) } else { - rendering_time.step("redirect to crate"); Ok(axum_cached_redirect( format!("/crate/{crate_name}/{}", matched_release.req_version), CachePolicy::ForeverInCdn, @@ -361,8 +347,6 @@ pub(crate) async fn rustdoc_html_server_handler( Extension(csp): Extension>, uri: Uri, ) -> AxumResult { - let mut rendering_time = RenderingTimesRecorder::new(&metrics.rustdoc_rendering_times); - // since we directly use the Uri-path and not the extracted params from the router, // we have to percent-decode the string here. let original_path = percent_encoding::percent_decode(uri.path().as_bytes()) @@ -394,8 +378,6 @@ pub(crate) async fn rustdoc_html_server_handler( } trace!("match version"); - rendering_time.step("match version"); - let mut conn = pool.get_async().await?; // Check the database for releases with the requested version while doing the following: @@ -430,13 +412,10 @@ pub(crate) async fn rustdoc_html_server_handler( })?; trace!("crate details"); - rendering_time.step("crate details"); - // Get the crate's details from the database let krate = CrateDetails::from_matched_release(&mut conn, matched_release).await?; if !krate.rustdoc_status { - rendering_time.step("redirect to crate"); return Ok(axum_cached_redirect( format!("/crate/{}/{}", params.name, params.version), CachePolicy::ForeverInCdn, @@ -465,10 +444,6 @@ pub(crate) async fn rustdoc_html_server_handler( trace!(?storage_path, ?req_path, "try fetching from storage"); - // record the data-fetch step - // until we re-add it below inside `fetch_rustdoc_file` - rendering_time.step("fetch from storage"); - // Attempt to load the file from the database let blob = match storage .fetch_rustdoc_file( @@ -477,7 +452,6 @@ pub(crate) async fn rustdoc_html_server_handler( krate.latest_build_id.unwrap_or(0), &storage_path, krate.archive_storage, - Some(&mut rendering_time), ) .await { @@ -541,7 +515,6 @@ pub(crate) async fn rustdoc_html_server_handler( // Serve non-html files directly if !storage_path.ends_with(".html") { trace!(?storage_path, "serve asset"); - rendering_time.step("serve asset"); // default asset caching behaviour is `Cache::ForeverInCdnAndBrowser`. // This is an edge-case when we serve invocation specific static assets under `/latest/`: @@ -549,8 +522,6 @@ pub(crate) async fn rustdoc_html_server_handler( return Ok(File(blob).into_response()); } - rendering_time.step("find latest path"); - let latest_release = krate.latest_release()?; // Get the latest version of the crate @@ -618,8 +589,6 @@ pub(crate) async fn rustdoc_html_server_handler( format!("{target}/") }; - rendering_time.step("rewrite html"); - // Build the page of documentation, templates .render_in_threadpool({