New performance timings (#3096)

Co-authored-by: Laurenz <laurmaedje@gmail.com>

7 files changed, 8 insertions, 17 deletions

diff --git a/crates/typst-pdf/Cargo.toml b/crates/typst-pdf/Cargo.toml
index ae838f3b..3dcddbb0 100644
--- a/crates/typst-pdf/Cargo.toml
+++ b/crates/typst-pdf/Cargo.toml
@@ -17,6 +17,8 @@ bench = false
 
 [dependencies]
 typst = { workspace = true }
+typst-macros = { workspace = true }
+typst-timing = { workspace = true }
 base64 = { workspace = true }
 bytemuck = { workspace = true }
 comemo = { workspace = true }
@@ -27,7 +29,6 @@ once_cell = { workspace = true }
 pdf-writer = { workspace = true }
 subsetter = { workspace = true }
 svg2pdf = { workspace = true }
-tracing = { workspace = true }
 ttf-parser = { workspace = true }
 unicode-properties = { workspace = true }
 unscanny = { workspace = true }
diff --git a/crates/typst-pdf/src/extg.rs b/crates/typst-pdf/src/extg.rs
index d95b91c4..f3ad3815 100644
--- a/crates/typst-pdf/src/extg.rs
+++ b/crates/typst-pdf/src/extg.rs
@@ -22,7 +22,6 @@ impl ExtGState {
 }
 
 /// Embed all used external graphics states into the PDF.
-#[tracing::instrument(skip_all)]
 pub(crate) fn write_external_graphics_states(ctx: &mut PdfContext) {
     for external_gs in ctx.extg_map.items() {
         let id = ctx.alloc.bump();
diff --git a/crates/typst-pdf/src/font.rs b/crates/typst-pdf/src/font.rs
index ce3913f7..cc116613 100644
--- a/crates/typst-pdf/src/font.rs
+++ b/crates/typst-pdf/src/font.rs
@@ -21,7 +21,7 @@ const SYSTEM_INFO: SystemInfo = SystemInfo {
 };
 
 /// Embed all used fonts into the PDF.
-#[tracing::instrument(skip_all)]
+#[typst_macros::time(name = "write fonts")]
 pub(crate) fn write_fonts(ctx: &mut PdfContext) {
     for font in ctx.font_map.items() {
         let type0_ref = ctx.alloc.bump();
@@ -168,6 +168,7 @@ pub(crate) fn write_fonts(ctx: &mut PdfContext) {
 /// - For a font with TrueType outlines, this returns the whole OpenType font.
 /// - For a font with CFF outlines, this returns just the CFF font program.
 #[comemo::memoize]
+#[typst_macros::time(name = "subset font")]
 fn subset_font(font: &Font, glyphs: &[u16]) -> Arc<Vec<u8>> {
     let data = font.data();
     let profile = subsetter::Profile::pdf(glyphs);
diff --git a/crates/typst-pdf/src/image.rs b/crates/typst-pdf/src/image.rs
index 2e99eef5..3857e68f 100644
--- a/crates/typst-pdf/src/image.rs
+++ b/crates/typst-pdf/src/image.rs
@@ -32,7 +32,7 @@ pub fn deferred_image(image: Image) -> Deferred<EncodedImage> {
 }
 
 /// Embed all used images into the PDF.
-#[tracing::instrument(skip_all)]
+#[typst_macros::time(name = "write images")]
 pub(crate) fn write_images(ctx: &mut PdfContext) {
     for (i, _) in ctx.image_map.items().enumerate() {
         let handle = ctx.image_deferred_map.get(&i).unwrap();
@@ -111,7 +111,6 @@ pub(crate) fn write_images(ctx: &mut PdfContext) {
 /// whether the image has color.
 ///
 /// Skips the alpha channel as that's encoded separately.
-#[tracing::instrument(skip_all)]
 fn encode_raster_image(image: &RasterImage) -> (Vec<u8>, Filter, bool) {
     let dynamic = image.dynamic();
     match (image.format(), dynamic) {
@@ -154,7 +153,6 @@ fn encode_raster_image(image: &RasterImage) -> (Vec<u8>, Filter, bool) {
 }
 
 /// Encode an image's alpha channel if present.
-#[tracing::instrument(skip_all)]
 fn encode_alpha(raster: &RasterImage) -> (Vec<u8>, Filter) {
     let pixels: Vec<_> = raster
         .dynamic()
@@ -167,7 +165,6 @@ fn encode_alpha(raster: &RasterImage) -> (Vec<u8>, Filter) {
 /// Encode an SVG into a chunk of PDF objects.
 ///
 /// The main XObject will have ID 1.
-#[tracing::instrument(skip_all)]
 fn encode_svg(svg: &SvgImage) -> Chunk {
     let mut chunk = Chunk::new();
 
diff --git a/crates/typst-pdf/src/lib.rs b/crates/typst-pdf/src/lib.rs
index dba4e3dc..63a9dd97 100644
--- a/crates/typst-pdf/src/lib.rs
+++ b/crates/typst-pdf/src/lib.rs
@@ -47,7 +47,7 @@ use crate::pattern::PdfPattern;
 /// The `timestamp`, if given, is expected to be the creation date of the
 /// document as a UTC datetime. It will only be used if `set document(date: ..)`
 /// is `auto`.
-#[tracing::instrument(skip_all)]
+#[typst_macros::time(name = "pdf")]
 pub fn pdf(
     document: &Document,
     ident: Option<&str>,
@@ -147,7 +147,6 @@ impl<'a> PdfContext<'a> {
 }
 
 /// Write the document catalog.
-#[tracing::instrument(skip_all)]
 fn write_catalog(ctx: &mut PdfContext, ident: Option<&str>, timestamp: Option<Datetime>) {
     let lang = ctx
         .languages
@@ -278,7 +277,6 @@ fn write_catalog(ctx: &mut PdfContext, ident: Option<&str>, timestamp: Option<Da
 }
 
 /// Compress data with the DEFLATE algorithm.
-#[tracing::instrument(skip_all)]
 fn deflate(data: &[u8]) -> Vec<u8> {
     const COMPRESSION_LEVEL: u8 = 6;
     miniz_oxide::deflate::compress_to_vec_zlib(data, COMPRESSION_LEVEL)
diff --git a/crates/typst-pdf/src/outline.rs b/crates/typst-pdf/src/outline.rs
index 9c9ef413..78698cf8 100644
--- a/crates/typst-pdf/src/outline.rs
+++ b/crates/typst-pdf/src/outline.rs
@@ -8,7 +8,6 @@ use typst::model::HeadingElem;
 use crate::{AbsExt, PdfContext};
 
 /// Construct the outline for the document.
-#[tracing::instrument(skip_all)]
 pub(crate) fn write_outline(ctx: &mut PdfContext) -> Option<Ref> {
     let mut tree: Vec<HeadingNode> = vec![];
 
@@ -130,7 +129,6 @@ impl HeadingNode {
 }
 
 /// Write an outline item and all its children.
-#[tracing::instrument(skip_all)]
 fn write_outline_item(
     ctx: &mut PdfContext,
     node: &HeadingNode,
diff --git a/crates/typst-pdf/src/page.rs b/crates/typst-pdf/src/page.rs
index 89b0ba5f..d3bbcb74 100644
--- a/crates/typst-pdf/src/page.rs
+++ b/crates/typst-pdf/src/page.rs
@@ -26,7 +26,7 @@ use crate::image::deferred_image;
 use crate::{deflate_deferred, AbsExt, EmExt, PdfContext};
 
 /// Construct page objects.
-#[tracing::instrument(skip_all)]
+#[typst_macros::time(name = "construct pages")]
 pub(crate) fn construct_pages(ctx: &mut PdfContext, frames: &[Frame]) {
     for frame in frames {
         let (page_ref, page) = construct_page(ctx, frame);
@@ -36,7 +36,7 @@ pub(crate) fn construct_pages(ctx: &mut PdfContext, frames: &[Frame]) {
 }
 
 /// Construct a page object.
-#[tracing::instrument(skip_all)]
+#[typst_macros::time(name = "construct page")]
 pub(crate) fn construct_page(ctx: &mut PdfContext, frame: &Frame) -> (Ref, Page) {
     let page_ref = ctx.alloc.bump();
 
@@ -83,7 +83,6 @@ pub(crate) fn construct_page(ctx: &mut PdfContext, frame: &Frame) -> (Ref, Page)
 }
 
 /// Write the page tree.
-#[tracing::instrument(skip_all)]
 pub(crate) fn write_page_tree(ctx: &mut PdfContext) {
     for i in 0..ctx.pages.len() {
         write_page(ctx, i);
@@ -142,7 +141,6 @@ pub(crate) fn write_page_tree(ctx: &mut PdfContext) {
 }
 
 /// Write a page tree node.
-#[tracing::instrument(skip_all)]
 fn write_page(ctx: &mut PdfContext, i: usize) {
     let page = &ctx.pages[i];
     let content_id = ctx.alloc.bump();
@@ -204,7 +202,6 @@ fn write_page(ctx: &mut PdfContext, i: usize) {
 }
 
 /// Write the page labels.
-#[tracing::instrument(skip_all)]
 pub(crate) fn write_page_labels(ctx: &mut PdfContext) -> Vec<(NonZeroUsize, Ref)> {
     let mut result = vec![];
     let mut prev: Option<&PdfPageLabel> = None;