diff --git a/Cargo.lock b/Cargo.lock index 61e5a40d8..e6041f1db 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -2090,6 +2090,7 @@ dependencies = [ "tower", "tower-http", "tracing", + "tracing-futures", "tracing-log", "tracing-subscriber", "url", @@ -2410,6 +2411,21 @@ dependencies = [ "new_debug_unreachable", ] +[[package]] +name = "futures" +version = "0.3.31" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "65bc07b1a8bc7c85c5f2e110c476c7389b4554ba72af57d8445ea63a576b0876" +dependencies = [ + "futures-channel", + "futures-core", + "futures-executor", + "futures-io", + "futures-sink", + "futures-task", + "futures-util", +] + [[package]] name = "futures-channel" version = "0.3.31" @@ -2483,6 +2499,7 @@ version = "0.3.31" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "9fa08315bb612088cc391249efdc3bc77536f16c91f6cf495e6fbe85b20a4a81" dependencies = [ + "futures-channel", "futures-core", "futures-io", "futures-macro", @@ -8182,6 +8199,18 @@ dependencies = [ "valuable", ] +[[package]] +name = "tracing-futures" +version = "0.2.5" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "97d095ae15e245a057c8e8451bab9b3ee1e1f68e9ba2b4fbc18d0ac5237835f2" +dependencies = [ + "futures", + "futures-task", + "pin-project", + "tracing", +] + [[package]] name = "tracing-log" version = "0.2.0" diff --git a/Cargo.toml b/Cargo.toml index d01b04a9c..84ace9c18 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -66,6 +66,7 @@ derive_builder = "0.20.2" # Async tokio = { version = "1.0", features = ["rt-multi-thread", "signal", "macros"] } tokio-util = { version = "0.7.15", default-features = false, features = ["io"] } +tracing-futures= { version = "0.2.5", features = ["std-future", "futures-03"] } futures-util = "0.3.5" async-stream = "0.3.5" async-compression = { version = "0.4.25", features = ["tokio", "bzip2", "zstd", "gzip"] } diff --git a/src/utils/html.rs b/src/utils/html.rs index 2b55b977a..e0005be8b 100644 --- a/src/utils/html.rs +++ b/src/utils/html.rs @@ -18,7 +18,8 @@ use lol_html::{element, errors::RewritingError}; use std::sync::Arc; use tokio::{io::AsyncRead, task::JoinHandle}; use tokio_util::io::ReaderStream; -use tracing::error; +use tracing::{Span, error, instrument}; +use tracing_futures::Instrument as _; const CHANNEL_SIZE: usize = 64; @@ -36,6 +37,7 @@ pub(crate) enum RustdocRewritingError { /// render the `rustdoc/` templates with the `html`. /// The output is an HTML page which has not yet been UTF-8 validated. /// In practice, the output should always be valid UTF-8. +#[instrument(skip_all, fields(memory_limit = max_allowed_memory_usage))] pub(crate) fn rewrite_rustdoc_html_stream( template_data: Arc, mut reader: R, @@ -46,123 +48,132 @@ pub(crate) fn rewrite_rustdoc_html_stream( where R: AsyncRead + Unpin + Send + 'static, { + let stream_span = Span::current(); + stream!({ let (input_sender, mut input_receiver) = tokio::sync::mpsc::channel::>(CHANNEL_SIZE); let (result_sender, mut result_receiver) = tokio::sync::mpsc::channel::(CHANNEL_SIZE); - let join_handle: JoinHandle> = tokio::spawn(async move { - // we're using the rendering threadpool to limit CPU usage on the server, and to - // offload potentially CPU intensive stuff from the tokio runtime. - // Also this lets us limit the threadpool size and through that the CPU usage. - template_data - .render_in_threadpool(move || { - use lol_html::html_content::{ContentType, Element}; - use lol_html::{HtmlRewriter, MemorySettings, Settings}; + let producer_span = tracing::info_span!("producer_task"); - let head_html = Head::new(&data).render().unwrap(); - let vendored_html = Vendored.render().unwrap(); - let body_html = Body.render().unwrap(); - let topbar_html = data.render().unwrap(); + let join_handle: JoinHandle> = tokio::spawn( + async move { + // we're using the rendering threadpool to limit CPU usage on the server, and to + // offload potentially CPU intensive stuff from the tokio runtime. + // Also this lets us limit the threadpool size and through that the CPU usage. + let render_span = tracing::info_span!("render_task"); + template_data + .render_in_threadpool(move || { + use lol_html::html_content::{ContentType, Element}; + use lol_html::{HtmlRewriter, MemorySettings, Settings}; - // Before: ... rustdoc content ... - // After: - // ```html - //
- // ... rustdoc content ... - //
- // ``` - let body_handler = |rustdoc_body_class: &mut Element| { - // Add the `rustdoc` classes to the html body - let mut tmp; - let klass = if let Some(classes) = rustdoc_body_class.get_attribute("class") - { - tmp = classes; - tmp.push_str(" container-rustdoc"); - &tmp - } else { - "container-rustdoc" - }; - rustdoc_body_class.set_attribute("class", klass)?; - rustdoc_body_class.set_attribute("id", "rustdoc_body_wrapper")?; - rustdoc_body_class.set_attribute("tabindex", "-1")?; - // Change the `body` to a `div` - rustdoc_body_class.set_tag_name("div")?; - // Prepend the askama content - rustdoc_body_class.prepend(&body_html, ContentType::Html); - // Wrap the transformed body and topbar into a element - rustdoc_body_class - .before(r#""#, ContentType::Html); - // Insert the topbar outside of the rustdoc div - rustdoc_body_class.before(&topbar_html, ContentType::Html); - // Finalize body with - rustdoc_body_class.after("", ContentType::Html); + let head_html = Head::new(&data).render().unwrap(); + let vendored_html = Vendored.render().unwrap(); + let body_html = Body.render().unwrap(); + let topbar_html = data.render().unwrap(); - Ok(()) - }; + // Before: ... rustdoc content ... + // After: + // ```html + //
+ // ... rustdoc content ... + //
+ // ``` + let body_handler = |rustdoc_body_class: &mut Element| { + // Add the `rustdoc` classes to the html body + let mut tmp; + let klass = + if let Some(classes) = rustdoc_body_class.get_attribute("class") { + tmp = classes; + tmp.push_str(" container-rustdoc"); + &tmp + } else { + "container-rustdoc" + }; + rustdoc_body_class.set_attribute("class", klass)?; + rustdoc_body_class.set_attribute("id", "rustdoc_body_wrapper")?; + rustdoc_body_class.set_attribute("tabindex", "-1")?; + // Change the `body` to a `div` + rustdoc_body_class.set_tag_name("div")?; + // Prepend the askama content + rustdoc_body_class.prepend(&body_html, ContentType::Html); + // Wrap the transformed body and topbar into a element + rustdoc_body_class + .before(r#""#, ContentType::Html); + // Insert the topbar outside of the rustdoc div + rustdoc_body_class.before(&topbar_html, ContentType::Html); + // Finalize body with + rustdoc_body_class.after("", ContentType::Html); - let settings = Settings { - element_content_handlers: vec![ - // Append `style.css` stylesheet after all head elements. - element!("head", |head: &mut Element| { - head.append(&head_html, ContentType::Html); - Ok(()) - }), - element!("body", body_handler), - // Append `vendored.css` before `rustdoc.css`, so that the duplicate copy of - // `normalize.css` will be overridden by the later version. - // - // Later rustdoc has `#mainThemeStyle` that could be used, but pre-2018 docs - // don't have this: - // - // https://github.com/rust-lang/rust/commit/003b2bc1c65251ec2fc80b78ed91c43fb35402ec - // - // Pre-2018 rustdoc also didn't have the resource suffix, but docs.rs was using a fork - // that had implemented it already then, so we can assume the css files are - // `/rustdoc-.css` and use the `-` to distinguish from the - // `rustdoc.static` path. - element!( - "link[rel='stylesheet'][href*='rustdoc-']", - move |rustdoc_css: &mut Element| { - rustdoc_css.before(&vendored_html, ContentType::Html); + Ok(()) + }; + + let settings = Settings { + element_content_handlers: vec![ + // Append `style.css` stylesheet after all head elements. + element!("head", |head: &mut Element| { + head.append(&head_html, ContentType::Html); Ok(()) - } - ), - ], - memory_settings: MemorySettings { - max_allowed_memory_usage, - ..MemorySettings::default() - }, - ..Settings::default() - }; + }), + element!("body", body_handler), + // Append `vendored.css` before `rustdoc.css`, so that the duplicate copy of + // `normalize.css` will be overridden by the later version. + // + // Later rustdoc has `#mainThemeStyle` that could be used, but pre-2018 docs + // don't have this: + // + // https://github.com/rust-lang/rust/commit/003b2bc1c65251ec2fc80b78ed91c43fb35402ec + // + // Pre-2018 rustdoc also didn't have the resource suffix, but docs.rs was using a fork + // that had implemented it already then, so we can assume the css files are + // `/rustdoc-.css` and use the `-` to distinguish from the + // `rustdoc.static` path. + element!( + "link[rel='stylesheet'][href*='rustdoc-']", + move |rustdoc_css: &mut Element| { + rustdoc_css.before(&vendored_html, ContentType::Html); + Ok(()) + } + ), + ], + memory_settings: MemorySettings { + max_allowed_memory_usage, + ..MemorySettings::default() + }, + ..Settings::default() + }; - let mut rewriter = HtmlRewriter::new(settings, move |chunk: &[u8]| { - // send the result back to the main rewriter when its coming in. - // this can fail only when the receiver is dropped, in which case - // we exit this thread anyways. - let _ = result_sender.blocking_send(Bytes::copy_from_slice(chunk)); - }); - while let Some(chunk) = input_receiver - .blocking_recv() - .ok_or_else(|| anyhow!("couldn't receive from input_receiver"))? - { - // receive data from the input receiver. - // `input_receiver` is a non-async one. - // Since we're in a normal background thread, we can use the blocking `.recv` - // here. - // We will get `None` when the reader is done reading, - // so that's our signal to exit this loop and call `rewriter.end()` below. - rewriter.write(&chunk)?; - } - // finalize everything. Will trigger the output sink (and through that, - // sending data to the `result_sender`). - rewriter.end()?; - Ok(()) - }) - .await?; - Ok(()) - }); + let mut rewriter = HtmlRewriter::new(settings, move |chunk: &[u8]| { + // send the result back to the main rewriter when its coming in. + // this can fail only when the receiver is dropped, in which case + // we exit this thread anyways. + let _ = result_sender.blocking_send(Bytes::copy_from_slice(chunk)); + }); + while let Some(chunk) = input_receiver + .blocking_recv() + .ok_or_else(|| anyhow!("couldn't receive from input_receiver"))? + { + // receive data from the input receiver. + // `input_receiver` is a non-async one. + // Since we're in a normal background thread, we can use the blocking `.recv` + // here. + // We will get `None` when the reader is done reading, + // so that's our signal to exit this loop and call `rewriter.end()` below. + rewriter.write(&chunk)?; + } + // finalize everything. Will trigger the output sink (and through that, + // sending data to the `result_sender`). + rewriter.end()?; + Ok(()) + }) + .instrument(render_span) + .await?; + Ok(()) + } + .instrument(producer_span), + ); let mut reader_stream = ReaderStream::new(&mut reader); while let Some(chunk) = reader_stream.next().await { @@ -221,6 +232,7 @@ where } })?; }) + .instrument(stream_span) } #[cfg(test)] diff --git a/src/web/page/templates.rs b/src/web/page/templates.rs index 21db855ee..77593a8f7 100644 --- a/src/web/page/templates.rs +++ b/src/web/page/templates.rs @@ -69,9 +69,11 @@ impl TemplateData { F: FnOnce() -> Result + Send + 'static, R: Send + 'static, { + let span = tracing::Span::current(); let (send, recv) = tokio::sync::oneshot::channel(); self.rendering_threadpool.spawn({ move || { + let _guard = span.enter(); // the job may have been queued on the thread-pool for a while, // if the request was closed in the meantime the receiver should have // dropped and we don't need to bother rendering the template