Add some timing info to rustdoc

There are various improvements, but the main one is to time each pass
that rustdoc performs (`rustdoc::passes`).

Before, these were the top five timings for `cargo doc` on the cargo
repository:

```
+---------------------------------+-----------+-----------------+----------+------------+
| Item                            | Self time | % of total time | Time     | Item count |
+---------------------------------+-----------+-----------------+----------+------------+
| <unknown>                       | 854.70ms  | 20.888          | 2.47s    | 744823     |
+---------------------------------+-----------+-----------------+----------+------------+
| expand_crate                    | 795.29ms  | 19.436          | 848.00ms | 1          |
+---------------------------------+-----------+-----------------+----------+------------+
| metadata_decode_entry           | 256.73ms  | 6.274           | 279.49ms | 518344     |
+---------------------------------+-----------+-----------------+----------+------------+
| resolve_crate                   | 240.56ms  | 5.879           | 242.86ms | 1          |
+---------------------------------+-----------+-----------------+----------+------------+
| hir_lowering                    | 146.79ms  | 3.587           | 146.79ms | 1          |
+---------------------------------+-----------+-----------------+----------+------------+
```

Now the timings are:

```
+---------------------------------+-----------+-----------------+----------+------------+
| Item                            | Self time | % of total time | Time     | Item count |
+---------------------------------+-----------+-----------------+----------+------------+
| <unknown>                       | 1.40s     | 22.662          | 3.73s    | 771430     |
+---------------------------------+-----------+-----------------+----------+------------+
| collect-trait-impls             | 1.34s     | 21.672          | 2.87s    | 1          |
+---------------------------------+-----------+-----------------+----------+------------+
| expand_crate                    | 1.21s     | 19.577          | 1.28s    | 1          |
+---------------------------------+-----------+-----------------+----------+------------+
| build extern trait impl         | 704.66ms  | 11.427          | 1.07s    | 21893      |
+---------------------------------+-----------+-----------------+----------+------------+
| metadata_decode_entry           | 354.84ms  | 5.754           | 391.81ms | 544919     |
+---------------------------------+-----------+-----------------+----------+------------+
```
This commit is contained in:
Joshua Nelson 2020-07-16 09:02:41 -04:00
parent 8fdce9bbb9
commit 50a79693e1
2 changed files with 15 additions and 5 deletions

View File

@ -407,7 +407,9 @@ pub fn run_core(options: RustdocOptions) -> (clean::Crate, RenderInfo, RenderOpt
let hir = tcx.hir();
let body = hir.body(hir.body_owned_by(hir.local_def_id_to_hir_id(def_id)));
debug!("visiting body for {:?}", def_id);
tcx.sess.time("emit ignored resolution errors", || {
EmitIgnoredResolutionErrors::new(tcx).visit_body(body);
});
(rustc_interface::DEFAULT_QUERY_PROVIDERS.typeck)(tcx, def_id)
};
}),
@ -430,6 +432,7 @@ pub fn run_core(options: RustdocOptions) -> (clean::Crate, RenderInfo, RenderOpt
// intra-doc-links
resolver.borrow_mut().access(|resolver| {
for extern_name in &extern_names {
sess.time("load extern crate", || {
resolver
.resolve_str_path_error(
DUMMY_SP,
@ -440,6 +443,7 @@ pub fn run_core(options: RustdocOptions) -> (clean::Crate, RenderInfo, RenderOpt
.unwrap_or_else(|()| {
panic!("Unable to resolve external crate {}", extern_name)
});
});
}
});
@ -480,7 +484,9 @@ pub fn run_core(options: RustdocOptions) -> (clean::Crate, RenderInfo, RenderOpt
tcx.ensure().check_mod_attrs(local_def_id);
}
let access_levels = tcx.privacy_access_levels(LOCAL_CRATE);
let access_levels = tcx
.sess
.time("privacy_access_levels", || tcx.privacy_access_levels(LOCAL_CRATE));
// Convert from a HirId set to a DefId set since we don't always have easy access
// to the map from defid -> hirid
let access_levels = AccessLevels {
@ -519,7 +525,7 @@ pub fn run_core(options: RustdocOptions) -> (clean::Crate, RenderInfo, RenderOpt
};
debug!("crate: {:?}", tcx.hir().krate());
let mut krate = clean::krate(&mut ctxt);
let mut krate = tcx.sess.time("clean crate", || clean::krate(&mut ctxt));
if let Some(ref m) = krate.module {
if let None | Some("") = m.doc_value() {
@ -618,7 +624,7 @@ pub fn run_core(options: RustdocOptions) -> (clean::Crate, RenderInfo, RenderOpt
};
if run {
debug!("running pass {}", p.pass.name);
krate = (p.pass.run)(krate, &ctxt);
krate = ctxt.tcx.sess.time(p.pass.name, || (p.pass.run)(krate, &ctxt));
}
}

View File

@ -29,7 +29,9 @@ pub fn collect_trait_impls(krate: Crate, cx: &DocContext<'_>) -> Crate {
for &cnum in cx.tcx.crates().iter() {
for &(did, _) in cx.tcx.all_trait_implementations(cnum).iter() {
cx.tcx.sess.time("build extern trait impl", || {
inline::build_impl(cx, did, None, &mut new_items);
});
}
}
@ -87,7 +89,9 @@ pub fn collect_trait_impls(krate: Crate, cx: &DocContext<'_>) -> Crate {
for &trait_did in cx.tcx.all_traits(LOCAL_CRATE).iter() {
for &impl_node in cx.tcx.hir().trait_impls(trait_did) {
let impl_did = cx.tcx.hir().local_def_id(impl_node);
cx.tcx.sess.time("build local trait impl", || {
inline::build_impl(cx, impl_did.to_def_id(), None, &mut new_items);
});
}
}