Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Autocomplete performance benchmarks #6633

Closed
georgewfraser opened this issue Nov 25, 2020 · 12 comments
Closed

Autocomplete performance benchmarks #6633

georgewfraser opened this issue Nov 25, 2020 · 12 comments
Labels
A-completion autocompletion A-perf performance issues S-unactionable Issue requires feedback, design decisions or is blocked on other work

Comments

@georgewfraser
Copy link
Contributor

I recently experienced a pretty severe performance regression on autocomplete #6612

I'm interested in implementing some performance benchmarks so we can detect these sorts of regressions. Would such a PR be welcome? Would you like to offer any guidance on how this should be implemented, or should I just put together a proof of concept and we can discuss from there?

@SomeoneToIgnore
Copy link
Contributor

Proof of concept sounds nice, and I don't think PRs are ever unwelcomed here.

I don't know much about the topic, but here's a CLI bench argument logic:
https://github.com/rust-analyzer/rust-analyzer/blob/bf84e4958ee31c59e5b78f60059d69a73ef659bb/crates/rust-analyzer/src/cli/analysis_bench.rs

that looks very related.

@matklad
Copy link
Member

matklad commented Dec 2, 2020

@georgewfraser yeah, as far as micro benches go, the analysis_bench is the thing. We don't run it on CI though, but it should be possible to plug that into our metrics infra:

But, in practice, I think monitoring things as you go would do the trick. I suggest just setting

export RA_PROFILE ='*>150'

in .bashrc and then monitoring the output tab in the editor.

In this particular case (trying to complete stuff in code_model.rs), the picture is pretty clear:

 5333ms - handle_completion
     5289ms - fuzzy_completion
          365ms - render_resolution
              298ms - item::Builder::build
                  296ms - rewrite
                      296ms - rewrite_children
                          296ms - rewrite_self (184 calls)
                            0ms - with_children (1 calls)
                    1ms - diff (1 calls)
                    0ms - insert_use (1 calls)
                    0ms - into_text_edit (1 calls)
                    0ms - mod_path_to_ast (1 calls)
                    0ms - rewrite_root (1 calls)

Looks like rendering a completion item takes a long time, and it really shouldn't. cc @Veykril, you might be curious to look into this.

@kjeremy
Copy link
Contributor

kjeremy commented Dec 2, 2020

Looks like rendering a completion item takes a long time, and it really shouldn't

https://github.com/rust-analyzer/rust-analyzer/blob/0993f9067cfc14cded484906283d1df8e8741e8e/crates/syntax/src/algo.rs#L529

😄

@Veykril
Copy link
Member

Veykril commented Dec 2, 2020

Let's not forget this one here as well 😄 https://github.com/rust-analyzer/rust-analyzer/blob/0993f9067cfc14cded484906283d1df8e8741e8e/crates/syntax/src/algo.rs#L185

I can take a stab at replacing the diffing algo in the (hopefully) near future I think, given the current one is really just not great and partially hacked in such a way that imports don't cause the cursor to jump(which I believe is a big factor to the bad runtime for it due to the lookahead we are doing in there currently). I would imagine that we probably want to go with the same algo/approach that roslyn uses which is according to the comment here TreeComparer.cs#L11-L13:

    // Based on general algorithm described in  
    // "Change Detection in Hierarchically Structured Information"
    // by Sudarshan S. Chawathe, Anand Rajaraman, Hector Garcia-Molina, and Jennifer Widom.

At least from the bit I've seen this algorithm looks promising.

@Veykril
Copy link
Member

Veykril commented Dec 2, 2020

Oh wait I just noticed the 296ms - rewrite part isn't even using the diff algo, well then forget my comment(though we probably want to consider moving to that algorithm at some point). I will take a look at rewrite_self then 👍

@lnicola
Copy link
Member

lnicola commented Dec 2, 2020

I'm not sure what to test this on, but I'd add a profile call to SyntaxRewriter::replacement.

@matklad
Copy link
Member

matklad commented Dec 2, 2020

I'm not sure what to test this on,

I was typing sel<|> on this line

@SomeoneToIgnore
Copy link
Contributor

SomeoneToIgnore commented Dec 2, 2020

I have a branch with the working resolve completions: https://github.com/SomeoneToIgnore/rust-analyzer/tree/resolve-completions

Adding sel to the place specified with that binary gives me

the following trace
 20ms - fuzzy_completion
     13ms - find_similar_imports
         13ms - find_similar_imports
              2ms - get_name_definition
                  2ms - classify_name
                      0ms - SourceBinder::to_module_def (1 calls)
                      0ms - crate_def_map:wait (1 calls)
                      0ms - macro_expand (6 calls)
                      1ms - parse_macro_expansion (6 calls)
                      0ms - ???
                  0ms - ???
              3ms - get_name_definition
                  3ms - classify_name
                      1ms - parse_macro_expansion
                      0ms - SourceBinder::to_module_def (1 calls)
                      0ms - crate_def_map:wait (1 calls)
                      0ms - macro_expand (8 calls)
                      0ms - parse_macro_expansion (7 calls)
                      0ms - ???
                  0ms - ???
              2ms - get_name_definition
                  2ms - classify_name
                      0ms - SourceBinder::to_module_def (1 calls)
                      0ms - crate_def_map:wait (1 calls)
                      1ms - macro_expand (7 calls)
                      0ms - parse_macro_expansion (7 calls)
                      0ms - ???
                  0ms - ???
              0ms - crate_def_map:wait (1 calls)
              0ms - get_name_definition (47 calls)
              0ms - search_dependencies (1 calls)
              4ms - ???
          0ms - ???
      6ms - find_path (45 calls)
      0ms - render_resolution (20 calls)
      0ms - ???
183ms - handle_resolve_completion
    183ms - add_import_edits
        179ms - rewrite
            179ms - rewrite_children
                  1ms - rewrite_self
                      1ms - rewrite_children
                          1ms - rewrite_self
                              1ms - rewrite_children
                                  1ms - rewrite_self
                                      1ms - rewrite_children
                                          1ms - rewrite_self (111 calls)
                                          0ms - with_children (1 calls)
                                          0ms - ???
                                      0ms - ???
                                  0ms - rewrite_self (2 calls)
                                  0ms - with_children (1 calls)
                                  0ms - ???
                              0ms - ???
                          0ms - rewrite_self (3 calls)
                          0ms - with_children (1 calls)
                          0ms - ???
                      0ms - ???
                  8ms - rewrite_self
                      8ms - rewrite_children
                          8ms - rewrite_self
                              8ms - rewrite_children
                                  1ms - rewrite_self
                                      1ms - rewrite_children
                                          1ms - rewrite_self (10 calls)
                                          0ms - with_children (1 calls)
                                          0ms - ???
                                      0ms - ???
                                  1ms - rewrite_self
                                      1ms - rewrite_children
                                          1ms - rewrite_self
                                              1ms - rewrite_children
                                                  1ms - rewrite_self (7 calls)
                                                  0ms - with_children (1 calls)
                                                  0ms - ???
                                              0ms - ???
                                          0ms - rewrite_self (11 calls)
                                          0ms - with_children (1 calls)
                                          0ms - ???
                                      0ms - ???
                                  1ms - rewrite_self
                                      1ms - rewrite_children
                                          1ms - rewrite_self
                                              1ms - rewrite_children
                                                  1ms - rewrite_self
                                                      1ms - rewrite_children
                                                          1ms - rewrite_self (4 calls)
                                                          0ms - with_children (1 calls)
                                                          0ms - ???
                                                      0ms - ???
                                                  0ms - rewrite_self (4 calls)
                                                  0ms - with_children (1 calls)
                                                  0ms - ???
                                              0ms - ???
                                          0ms - rewrite_self (9 calls)
                                          0ms - with_children (1 calls)
                                          0ms - ???
                                      0ms - ???
                                  2ms - rewrite_self
                                      2ms - rewrite_children
                                          2ms - rewrite_self
                                              2ms - rewrite_children
                                                  1ms - rewrite_self
                                                      1ms - rewrite_children
                                                          1ms - rewrite_self
                                                              1ms - rewrite_children
                                                                  1ms - rewrite_self
                                                                      1ms - rewrite_children
                                                                          1ms - rewrite_self
                                                                              1ms - rewrite_children
                                                                                  1ms - rewrite_self
                                                                                      1ms - rewrite_children
                                                                                          1ms - rewrite_self
                                                                                              1ms - rewrite_children
                                                                                                  1ms - rewrite_self
                                                                                                      1ms - rewrite_children
                                                                                                          1ms - rewrite_self (7 calls)
                                                                                                          0ms - with_children (1 calls)
                                                                                                          0ms - ???
                                                                                                      0ms - ???
                                                                                                  0ms - rewrite_self (2 calls)
                                                                                                  0ms - with_children (1 calls)
                                                                                                  0ms - ???
                                                                                              0ms - ???
                                                                                          0ms - rewrite_self (2 calls)
                                                                                          0ms - with_children (1 calls)
                                                                                          0ms - ???
                                                                                      0ms - ???
                                                                                  0ms - rewrite_self (3 calls)
                                                                                  0ms - with_children (1 calls)
                                                                                  0ms - ???
                                                                              0ms - ???
                                                                          0ms - rewrite_self (3 calls)
                                                                          0ms - with_children (1 calls)
                                                                          0ms - ???
                                                                      0ms - ???
                                                                  0ms - rewrite_self (3 calls)
                                                                  0ms - with_children (1 calls)
                                                                  0ms - ???
                                                              0ms - ???
                                                          0ms - rewrite_self (7 calls)
                                                          0ms - with_children (1 calls)
                                                          0ms - ???
                                                      0ms - ???
                                                  0ms - rewrite_self (14 calls)
                                                  0ms - with_children (1 calls)
                                                  0ms - ???
                                              0ms - ???
                                          0ms - rewrite_self (11 calls)
                                          0ms - with_children (1 calls)
                                          0ms - ???
                                      0ms - ???
                                  1ms - rewrite_self (17 calls)
                                  0ms - with_children (1 calls)
                                  0ms - ???
                              0ms - ???
                          0ms - rewrite_self (4 calls)
                          0ms - with_children (1 calls)
                          0ms - ???
                      0ms - ???
                 11ms - rewrite_self
                     11ms - rewrite_children
                         11ms - rewrite_self
                             11ms - rewrite_children
                                  2ms - rewrite_self
                                      2ms - rewrite_children
                                          1ms - rewrite_self
                                              1ms - rewrite_children
                                                  1ms - rewrite_self
                                                      1ms - rewrite_children
                                                          1ms - rewrite_self
                                                              1ms - rewrite_children
                                                                  1ms - rewrite_self (30 calls)
                                                                  0ms - with_children (1 calls)
                                                                  0ms - ???
                                                              0ms - ???
                                                          0ms - rewrite_self (4 calls)
                                                          0ms - with_children (1 calls)
                                                          0ms - ???
                                                      0ms - ???
                                                  0ms - rewrite_self (4 calls)
                                                  0ms - with_children (1 calls)
                                                  0ms - ???
                                              0ms - ???
                                          0ms - rewrite_self (9 calls)
                                          0ms - with_children (1 calls)
                                          0ms - ???
                                      0ms - ???
                                  1ms - rewrite_self
                                      1ms - rewrite_children
                                          1ms - rewrite_self (10 calls)
                                          0ms - with_children (1 calls)
                                          0ms - ???
                                      0ms - ???
                                  3ms - rewrite_self
                                      3ms - rewrite_children
                                          3ms - rewrite_self
                                              3ms - rewrite_children
                                                  3ms - rewrite_self
                                                      3ms - rewrite_children
                                                          3ms - rewrite_self
                                                              3ms - rewrite_children
                                                                  3ms - rewrite_self
                                                                      3ms - rewrite_children
                                                                          3ms - rewrite_self (29 calls)
                                                                          0ms - with_children (1 calls)
                                                                          0ms - ???
                                                                      0ms - ???
                                                                  0ms - rewrite_self (4 calls)
                                                                  0ms - with_children (1 calls)
                                                                  0ms - ???
                                                              0ms - ???
                                                          0ms - rewrite_self (7 calls)
                                                          0ms - with_children (1 calls)
                                                          0ms - ???
                                                      0ms - ???
                                                  0ms - rewrite_self (6 calls)
                                                  0ms - with_children (1 calls)
                                                  0ms - ???
                                              0ms - ???
                                          0ms - rewrite_self (9 calls)
                                          0ms - with_children (1 calls)
                                          0ms - ???
                                      0ms - ???
                                  2ms - rewrite_self
                                      2ms - rewrite_children
                                          2ms - rewrite_self
                                              2ms - rewrite_children
                                                  2ms - rewrite_self
                                                      2ms - rewrite_children
                                                          2ms - rewrite_self
                                                              2ms - rewrite_children
                                                                  2ms - rewrite_self (30 calls)
                                                                  0ms - with_children (1 calls)
                                                                  0ms - ???
                                                              0ms - ???
                                                          0ms - rewrite_self (4 calls)
                                                          0ms - with_children (1 calls)
                                                          0ms - ???
                                                      0ms - ???
                                                  0ms - rewrite_self (4 calls)
                                                  0ms - with_children (1 calls)
                                                  0ms - ???
                                              0ms - ???
                                          0ms - rewrite_self (9 calls)
                                          0ms - with_children (1 calls)
                                          0ms - ???
                                      0ms - ???
                                  2ms - rewrite_self
                                      2ms - rewrite_children
                                          2ms - rewrite_self
                                              2ms - rewrite_children
                                                  2ms - rewrite_self
                                                      2ms - rewrite_children
                                                          2ms - rewrite_self
                                                              2ms - rewrite_children
                                                                  1ms - rewrite_self
                                                                      1ms - rewrite_children
                                                                          1ms - rewrite_self (27 calls)
                                                                          0ms - with_children (1 calls)
                                                                          0ms - ???
                                                                      0ms - ???
                                                                  0ms - rewrite_self (4 calls)
                                                                  0ms - with_children (1 calls)
                                                                  0ms - ???
                                                              0ms - ???
                                                          0ms - rewrite_self (7 calls)
                                                          0ms - with_children (1 calls)
                                                          0ms - ???
                                                      0ms - ???
                                                  0ms - rewrite_self (6 calls)
                                                  0ms - with_children (1 calls)
                                                  0ms - ???
                                              0ms - ???
                                          0ms - rewrite_self (7 calls)
                                          0ms - with_children (1 calls)
                                          0ms - ???
                                      0ms - ???
                                  0ms - rewrite_self (8 calls)
                                  0ms - with_children (1 calls)
                                  0ms - ???
                              0ms - ???
                          0ms - rewrite_self (4 calls)
                          0ms - with_children (1 calls)
                          0ms - ???
                      0ms - ???
                 13ms - rewrite_self
                     13ms - rewrite_children
                         13ms - rewrite_self
                             13ms - rewrite_children
                                  1ms - rewrite_self
                                      1ms - rewrite_children
                                          1ms - rewrite_self (12 calls)
                                          0ms - with_children (1 calls)
                                          0ms - ???
                                      0ms - ???
                                  2ms - rewrite_self
                                      2ms - rewrite_children
                                          2ms - rewrite_self
                                              2ms - rewrite_children
                                                  2ms - rewrite_self
                                                      2ms - rewrite_children
                                                          2ms - rewrite_self
                                                              2ms - rewrite_children
                                                                  1ms - rewrite_self
                                                                      1ms - rewrite_children
                                                                          1ms - rewrite_self
                                                                              1ms - rewrite_children
                                                                                  1ms - rewrite_self
                                                                                      1ms - rewrite_children
                                                                                          1ms - rewrite_self
                                                                                              1ms - rewrite_children
                                                                                                  1ms - rewrite_self
                                                                                                      1ms - rewrite_children
                                                                                                          1ms - rewrite_self
                                                                                                              1ms - rewrite_children
                                                                                                                  1ms - rewrite_self (7 calls)
                                                                                                                  0ms - with_children (1 calls)
                                                                                                                  0ms - ???
                                                                                                              0ms - ???
                                                                                                          0ms - rewrite_self (8 calls)
                                                                                                          0ms - with_children (1 calls)
                                                                                                          0ms - ???
                                                                                                      0ms - ???
                                                                                                  0ms - rewrite_self (4 calls)
                                                                                                  0ms - with_children (1 calls)
                                                                                                  0ms - ???
                                                                                              0ms - ???
                                                                                          0ms - rewrite_self (2 calls)
                                                                                          0ms - with_children (1 calls)
                                                                                          0ms - ???
                                                                                      0ms - ???
                                                                                  0ms - rewrite_self (2 calls)
                                                                                  0ms - with_children (1 calls)
                                                                                  0ms - ???
                                                                              0ms - ???
                                                                          0ms - rewrite_self (4 calls)
                                                                          0ms - with_children (1 calls)
                                                                          0ms - ???
                                                                      0ms - ???
                                                                  0ms - rewrite_self (4 calls)
                                                                  0ms - with_children (1 calls)
                                                                  0ms - ???
                                                              0ms - ???
                                                          0ms - rewrite_self (4 calls)
                                                          0ms - with_children (1 calls)
                                                          0ms - ???
                                                      0ms - ???
                                                  0ms - rewrite_self (4 calls)
                                                  0ms - with_children (1 calls)
                                                  0ms - ???
                                              0ms - ???
                                          0ms - rewrite_self (11 calls)
                                          0ms - with_children (1 calls)
                                          0ms - ???
                                      0ms - ???
                                  2ms - rewrite_self
                                      2ms - rewrite_children
                                          2ms - rewrite_self
                                              2ms - rewrite_children
                                                  1ms - rewrite_self
                                                      1ms - rewrite_children
                                                          1ms - rewrite_self
                                                              1ms - rewrite_children
                                                                  1ms - rewrite_self
                                                                      1ms - rewrite_children
                                                                          1ms - rewrite_self
                                                                              1ms - rewrite_children
                                                                                  1ms - rewrite_self
                                                                                      1ms - rewrite_children
                                                                                          1ms - rewrite_self (11 calls)
                                                                                          0ms - with_children (1 calls)
                                                                                          0ms - ???
                                                                                      0ms - ???
                                                                                  0ms - rewrite_self (4 calls)
                                                                                  0ms - with_children (1 calls)
                                                                                  0ms - ???
                                                                              0ms - ???
                                                                          0ms - rewrite_self (6 calls)
                                                                          0ms - with_children (1 calls)
                                                                          0ms - ???
                                                                      0ms - ???
                                                                  0ms - rewrite_self (8 calls)
                                                                  0ms - with_children (1 calls)
                                                                  0ms - ???
                                                              0ms - ???
                                                          0ms - with_children (1 calls)
                                                          0ms - ???
                                                      0ms - ???
                                                  1ms - rewrite_self (12 calls)
                                                  0ms - with_children (1 calls)
                                                  0ms - ???
                                              0ms - ???
                                          0ms - rewrite_self (7 calls)
                                          0ms - with_children (1 calls)
                                          0ms - ???
                                      0ms - ???
                                  6ms - rewrite_self (30 calls)
                                  0ms - with_children (1 calls)
                                  0ms - ???
                              0ms - ???
                          0ms - rewrite_self (4 calls)
                          0ms - with_children (1 calls)
                          0ms - ???
                      0ms - ???
                  2ms - rewrite_self
                      2ms - rewrite_children
                          2ms - rewrite_self
                              2ms - rewrite_children
                                  1ms - rewrite_self
                                      1ms - rewrite_children
                                          1ms - rewrite_self
                                              1ms - rewrite_children
                                                  1ms - rewrite_self (13 calls)
                                                  0ms - with_children (1 calls)
                                                  0ms - ???
                                              0ms - ???
                                          0ms - rewrite_self (17 calls)
                                          0ms - with_children (1 calls)
                                          0ms - ???
                                      0ms - ???
                                  0ms - rewrite_self (8 calls)
                                  0ms - with_children (1 calls)
                                  0ms - ???
                              0ms - ???
                          0ms - rewrite_self (4 calls)
                          0ms - with_children (1 calls)
                          0ms - ???
                      0ms - ???
                  3ms - rewrite_self
                      3ms - rewrite_children
                          3ms - rewrite_self
                              3ms - rewrite_children
                                  3ms - rewrite_self (17 calls)
                                  0ms - with_children (1 calls)
                                  0ms - ???
                              0ms - ???
                          0ms - rewrite_self (4 calls)
                          0ms - with_children (1 calls)
                          0ms - ???
                      0ms - ???
                  2ms - rewrite_self
                      2ms - rewrite_children
                          2ms - rewrite_self
                              2ms - rewrite_children
                                  2ms - rewrite_self (13 calls)
                                  0ms - with_children (1 calls)
                                  0ms - ???
                              0ms - ???
                          0ms - rewrite_self (4 calls)
                          0ms - with_children (1 calls)
                          0ms - ???
                      0ms - ???
                  2ms - rewrite_self
                      2ms - rewrite_children
                          2ms - rewrite_self
                              2ms - rewrite_children
                                  2ms - rewrite_self (13 calls)
                                  0ms - with_children (1 calls)
                                  0ms - ???
                              0ms - ???
                          0ms - rewrite_self (4 calls)
                          0ms - with_children (1 calls)
                          0ms - ???
                      0ms - ???
                  2ms - rewrite_self
                      2ms - rewrite_children
                          2ms - rewrite_self
                              2ms - rewrite_children
                                  2ms - rewrite_self (15 calls)
                                  0ms - with_children (1 calls)
                                  0ms - ???
                              0ms - ???
                          0ms - rewrite_self (4 calls)
                          0ms - with_children (1 calls)
                          0ms - ???
                      0ms - ???
                  3ms - rewrite_self
                      3ms - rewrite_children
                          3ms - rewrite_self
                              3ms - rewrite_children
                                  3ms - rewrite_self (13 calls)
                                  0ms - with_children (1 calls)
                                  0ms - ???
                              0ms - ???
                          0ms - rewrite_self (4 calls)
                          0ms - with_children (1 calls)
                          0ms - ???
                      0ms - ???
                  3ms - rewrite_self
                      3ms - rewrite_children
                          3ms - rewrite_self
                              3ms - rewrite_children
                                  3ms - rewrite_self (11 calls)
                                  0ms - with_children (1 calls)
                                  0ms - ???
                              0ms - ???
                          0ms - rewrite_self (4 calls)
                          0ms - with_children (1 calls)
                          0ms - ???
                      0ms - ???
                  1ms - rewrite_self
                      1ms - rewrite_children
                          1ms - rewrite_self
                              1ms - rewrite_children
                                  1ms - rewrite_self
                                      0ms - rewrite_children (1 calls)
                                      0ms - ???
                                  0ms - rewrite_self (6 calls)
                                  0ms - with_children (1 calls)
                                  0ms - ???
                              0ms - ???
                          0ms - rewrite_self (4 calls)
                          0ms - with_children (1 calls)
                          0ms - ???
                      0ms - ???
                  6ms - rewrite_self
                      6ms - rewrite_children
                          6ms - rewrite_self
                              6ms - rewrite_children
                                  2ms - rewrite_self
                                      2ms - rewrite_children
                                          2ms - rewrite_self
                                              2ms - rewrite_children
                                                  1ms - rewrite_self
                                                      1ms - rewrite_children
                                                          1ms - rewrite_self
                                                              1ms - rewrite_children
                                                                  1ms - rewrite_self
                                                                      1ms - rewrite_children
                                                                          1ms - rewrite_self
                                                                              1ms - rewrite_children
                                                                                  1ms - rewrite_self
                                                                                      1ms - rewrite_children
                                                                                          1ms - rewrite_self
                                                                                              1ms - rewrite_children
                                                                                                  1ms - rewrite_self
                                                                                                      1ms - rewrite_children
                                                                                                          1ms - rewrite_self
                                                                                                              1ms - rewrite_children
                                                                                                                  1ms - rewrite_self (9 calls)
                                                                                                                  0ms - with_children (1 calls)
                                                                                                                  0ms - ???
                                                                                                              0ms - ???
                                                                                                          0ms - rewrite_self (2 calls)
                                                                                                          0ms - with_children (1 calls)
                                                                                                          0ms - ???
                                                                                                      0ms - ???
                                                                                                  0ms - rewrite_self (7 calls)
                                                                                                  0ms - with_children (1 calls)
                                                                                                  0ms - ???
                                                                                              0ms - ???
                                                                                          0ms - rewrite_self (6 calls)
                                                                                          0ms - with_children (1 calls)
                                                                                          0ms - ???
                                                                                      0ms - ???
                                                                                  0ms - rewrite_self (2 calls)
                                                                                  0ms - with_children (1 calls)
                                                                                  0ms - ???
                                                                              0ms - ???
                                                                          0ms - rewrite_self (2 calls)
                                                                          0ms - with_children (1 calls)
                                                                          0ms - ???
                                                                      0ms - ???
                                                                  0ms - rewrite_self (4 calls)
                                                                  0ms - with_children (1 calls)
                                                                  0ms - ???
                                                              0ms - ???
                                                          0ms - rewrite_self (4 calls)
                                                          0ms - with_children (1 calls)
                                                          0ms - ???
                                                      0ms - ???
                                                  0ms - rewrite_self (10 calls)
                                                  0ms - with_children (1 calls)
                                                  0ms - ???
                                              0ms - ???
                                          0ms - rewrite_self (9 calls)
                                          0ms - with_children (1 calls)
                                          0ms - ???
                                      0ms - ???
                                  1ms - rewrite_self
                                      1ms - rewrite_children
                                          1ms - rewrite_self (8 calls)
                                          0ms - with_children (1 calls)
                                          0ms - ???
                                      0ms - ???
                                  3ms - rewrite_self (19 calls)
                                  0ms - with_children (1 calls)
                                  0ms - ???
                              0ms - ???
                          0ms - rewrite_self (4 calls)
                          0ms - with_children (1 calls)
                          0ms - ???
                      0ms - ???
                  1ms - rewrite_self
                      1ms - rewrite_children
                          1ms - rewrite_self
                              1ms - rewrite_children
                                  1ms - rewrite_self (9 calls)
                                  0ms - with_children (1 calls)
                                  0ms - ???
                              0ms - ???
                          0ms - rewrite_self (4 calls)
                          0ms - with_children (1 calls)
                          0ms - ???
                      0ms - ???
                  1ms - rewrite_self
                      1ms - rewrite_children
                          1ms - rewrite_self
                              1ms - rewrite_children
                                  1ms - rewrite_self (11 calls)
                                  0ms - with_children (1 calls)
                                  0ms - ???
                              0ms - ???
                          0ms - rewrite_self (4 calls)
                          0ms - with_children (1 calls)
                          0ms - ???
                      0ms - ???
                  1ms - rewrite_self
                      1ms - rewrite_children
                          1ms - rewrite_self
                              1ms - rewrite_children
                                  1ms - rewrite_self (11 calls)
                                  0ms - with_children (1 calls)
                                  0ms - ???
                              0ms - ???
                          0ms - rewrite_self (4 calls)
                          0ms - with_children (1 calls)
                          0ms - ???
                      0ms - ???
                  2ms - rewrite_self
                      2ms - rewrite_children
                          2ms - rewrite_self
                              2ms - rewrite_children
                                  2ms - rewrite_self (15 calls)
                                  0ms - with_children (1 calls)
                                  0ms - ???
                              0ms - ???
                          0ms - rewrite_self (4 calls)
                          0ms - with_children (1 calls)
                          0ms - ???
                      0ms - ???
                  1ms - rewrite_self
                      1ms - rewrite_children
                          1ms - rewrite_self
                              1ms - rewrite_children
                                  1ms - rewrite_self
                                      1ms - rewrite_children
                                          1ms - rewrite_self (16 calls)
                                          0ms - with_children (1 calls)
                                          0ms - ???
                                      0ms - ???
                                  0ms - rewrite_self (10 calls)
                                  0ms - with_children (1 calls)
                                  0ms - ???
                              0ms - ???
                          0ms - rewrite_self (4 calls)
                          0ms - with_children (1 calls)
                          0ms - ???
                      0ms - ???
                  2ms - rewrite_self
                      2ms - rewrite_children
                          2ms - rewrite_self (11 calls)
                          0ms - with_children (1 calls)
                          0ms - ???
                      0ms - ???
                  3ms - rewrite_self
                      3ms - rewrite_children
                          3ms - rewrite_self
                              3ms - rewrite_children
                                  1ms - rewrite_self
                                      1ms - rewrite_children
                                          1ms - rewrite_self (10 calls)
                                          0ms - with_children (1 calls)
                                          0ms - ???
                                      0ms - ???
                                  1ms - rewrite_self
                                      1ms - rewrite_children
                                          1ms - rewrite_self
                                              1ms - rewrite_children
                                                  1ms - rewrite_self (7 calls)
                                                  0ms - with_children (1 calls)
                                                  0ms - ???
                                              0ms - ???
                                          0ms - rewrite_self (9 calls)
                                          0ms - with_children (1 calls)
                                          0ms - ???
                                      0ms - ???
                                  0ms - rewrite_self (7 calls)
                                  0ms - with_children (1 calls)
                                  0ms - ???
                              0ms - ???
                          0ms - rewrite_self (4 calls)
                          0ms - with_children (1 calls)
                          0ms - ???
                      0ms - ???
                  1ms - rewrite_self
                      1ms - rewrite_children
                          1ms - rewrite_self
                              1ms - rewrite_children
                                  1ms - rewrite_self
                                      1ms - rewrite_children
                                          1ms - rewrite_self (10 calls)
                                          0ms - with_children (1 calls)
                                          0ms - ???
                                      0ms - ???
                                  0ms - rewrite_self (4 calls)
                                  0ms - with_children (1 calls)
                                  0ms - ???
                              0ms - ???
                          0ms - rewrite_self (4 calls)
                          0ms - with_children (1 calls)
                          0ms - ???
                      0ms - ???
                  7ms - rewrite_self
                      7ms - rewrite_children
                          7ms - rewrite_self
                              7ms - rewrite_children
                                  1ms - rewrite_self
                                      1ms - rewrite_children
                                          0ms - rewrite_self (10 calls)
                                          0ms - with_children (1 calls)
                                          0ms - ???
                                      0ms - ???
                                  1ms - rewrite_self
                                      1ms - rewrite_children
                                          1ms - rewrite_self (10 calls)
                                          0ms - with_children (1 calls)
                                          0ms - ???
                                      0ms - ???
                                  1ms - rewrite_self
                                      1ms - rewrite_children
                                          1ms - rewrite_self (10 calls)
                                          0ms - with_children (1 calls)
                                          0ms - ???
                                      0ms - ???
                                  1ms - rewrite_self
                                      1ms - rewrite_children
                                          1ms - rewrite_self
                                              1ms - rewrite_children
                                                  1ms - rewrite_self (13 calls)
                                                  0ms - with_children (1 calls)
                                                  0ms - ???
                                              0ms - ???
                                          0ms - rewrite_self (9 calls)
                                          0ms - with_children (1 calls)
                                          0ms - ???
                                      0ms - ???
                                  1ms - rewrite_self (15 calls)
                                  0ms - with_children (1 calls)
                                  0ms - ???
                              0ms - ???
                          0ms - rewrite_self (4 calls)
                          0ms - with_children (1 calls)
                          0ms - ???
                      0ms - ???
                  4ms - rewrite_self
                      4ms - rewrite_children
                          4ms - rewrite_self
                              4ms - rewrite_children
                                  1ms - rewrite_self
                                      1ms - rewrite_children
                                          1ms - rewrite_self (10 calls)
                                          0ms - with_children (1 calls)
                                          0ms - ???
                                      0ms - ???
                                  2ms - rewrite_self
                                      2ms - rewrite_children
                                          2ms - rewrite_self
                                              2ms - rewrite_children
                                                  2ms - rewrite_self (19 calls)
                                                  0ms - with_children (1 calls)
                                                  0ms - ???
                                              0ms - ???
                                          0ms - rewrite_self (9 calls)
                                          0ms - with_children (1 calls)
                                          0ms - ???
                                      0ms - ???
                                  1ms - rewrite_self (9 calls)
                                  0ms - with_children (1 calls)
                                  0ms - ???
                              0ms - ???
                          0ms - rewrite_self (4 calls)
                          0ms - with_children (1 calls)
                          0ms - ???
                      0ms - ???
                  8ms - rewrite_self
                      8ms - rewrite_children
                          8ms - rewrite_self
                              8ms - rewrite_children
                                  1ms - rewrite_self
                                      1ms - rewrite_children
                                          1ms - rewrite_self
                                              1ms - rewrite_children
                                                  1ms - rewrite_self (15 calls)
                                                  0ms - with_children (1 calls)
                                                  0ms - ???
                                              0ms - ???
                                          0ms - rewrite_self (9 calls)
                                          0ms - with_children (1 calls)
                                          0ms - ???
                                      0ms - ???
                                  2ms - rewrite_self
                                      2ms - rewrite_children
                                          2ms - rewrite_self
                                              2ms - rewrite_children
                                                  1ms - rewrite_self
                                                      1ms - rewrite_children
                                                          1ms - rewrite_self
                                                              1ms - rewrite_children
                                                                  1ms - rewrite_self
                                                                      1ms - rewrite_children
                                                                          1ms - rewrite_self
                                                                              1ms - rewrite_children
                                                                                  1ms - rewrite_self
                                                                                      1ms - rewrite_children
                                                                                          0ms - rewrite_self (3 calls)
                                                                                          0ms - with_children (1 calls)
                                                                                          0ms - ???
                                                                                      0ms - ???
                                                                                  0ms - rewrite_self (4 calls)
                                                                                  0ms - with_children (1 calls)
                                                                                  0ms - ???
                                                                              0ms - ???
                                                                          0ms - rewrite_self (4 calls)
                                                                          0ms - with_children (1 calls)
                                                                          0ms - ???
                                                                      0ms - ???
                                                                  0ms - rewrite_self (1 calls)
                                                                  0ms - with_children (1 calls)
                                                                  0ms - ???
                                                              0ms - ???
                                                          0ms - rewrite_self (7 calls)
                                                          0ms - with_children (1 calls)
                                                          0ms - ???
                                                      0ms - ???
                                                  0ms - rewrite_self (12 calls)
                                                  0ms - with_children (1 calls)
                                                  0ms - ???
                                              0ms - ???
                                          0ms - rewrite_self (9 calls)
                                          0ms - with_children (1 calls)
                                          0ms - ???
                                      0ms - ???
                                  4ms - rewrite_self (21 calls)
                                  0ms - with_children (1 calls)
                                  0ms - ???
                              0ms - ???
                          0ms - rewrite_self (4 calls)
                          0ms - with_children (1 calls)
                          0ms - ???
                      0ms - ???
                 50ms - rewrite_self
                     50ms - rewrite_children
                         50ms - rewrite_self
                             50ms - rewrite_children
                                  1ms - rewrite_self
                                      1ms - rewrite_children
                                          1ms - rewrite_self (10 calls)
                                          0ms - with_children (1 calls)
                                          0ms - ???
                                      0ms - ???
                                  1ms - rewrite_self
                                      1ms - rewrite_children
                                          1ms - rewrite_self (8 calls)
                                          0ms - with_children (1 calls)
                                          0ms - ???
                                      0ms - ???
                                  1ms - rewrite_self
                                      1ms - rewrite_children
                                          1ms - rewrite_self (8 calls)
                                          0ms - with_children (1 calls)
                                          0ms - ???
                                      0ms - ???
                                  1ms - rewrite_self
                                      1ms - rewrite_children
                                          1ms - rewrite_self
                                              1ms - rewrite_children
                                                  1ms - rewrite_self (15 calls)
                                                  0ms - with_children (1 calls)
                                                  0ms - ???
                                              0ms - ???
                                          0ms - rewrite_self (13 calls)
                                          0ms - with_children (1 calls)
                                          0ms - ???
                                      0ms - ???
                                  1ms - rewrite_self
                                      1ms - rewrite_children
                                          1ms - rewrite_self
                                              1ms - rewrite_children
                                                  1ms - rewrite_self (11 calls)
                                                  0ms - with_children (1 calls)
                                                  0ms - ???
                                              0ms - ???
                                          0ms - rewrite_self (17 calls)
                                          0ms - with_children (1 calls)
                                          0ms - ???
                                      0ms - ???
                                  2ms - rewrite_self
                                      2ms - rewrite_children
                                          1ms - rewrite_self
                                              1ms - rewrite_children
                                                  1ms - rewrite_self
                                                      1ms - rewrite_children
                                                          1ms - rewrite_self
                                                              1ms - rewrite_children
                                                                  0ms - rewrite_self (3 calls)
                                                                  0ms - with_children (1 calls)
                                                                  0ms - ???
                                                              0ms - ???
                                                          0ms - rewrite_self (7 calls)
                                                          0ms - with_children (1 calls)
                                                          0ms - ???
                                                      0ms - ???
                                                  0ms - rewrite_self (8 calls)
                                                  0ms - with_children (1 calls)
                                                  0ms - ???
                                              0ms - ???
                                          0ms - rewrite_self (9 calls)
                                          0ms - with_children (1 calls)
                                          0ms - ???
                                      0ms - ???
                                  4ms - rewrite_self
                                      4ms - rewrite_children
                                          3ms - rewrite_self
                                              3ms - rewrite_children
                                                  1ms - rewrite_self
                                                      1ms - rewrite_children
                                                          1ms - rewrite_self (5 calls)
                                                          0ms - with_children (1 calls)
                                                          0ms - ???
                                                      0ms - ???
                                                  2ms - rewrite_self (10 calls)
                                                  0ms - with_children (1 calls)
                                                  0ms - ???
                                              0ms - ???
                                          0ms - rewrite_self (9 calls)
                                          0ms - with_children (1 calls)
                                          0ms - ???
                                      0ms - ???
                                  1ms - rewrite_self
                                      1ms - rewrite_children
                                          1ms - rewrite_self (10 calls)
                                          0ms - with_children (1 calls)
                                          0ms - ???
                                      0ms - ???
                                  1ms - rewrite_self
                                      1ms - rewrite_children
                                          1ms - rewrite_self
                                              1ms - rewrite_children
                                                  1ms - rewrite_self (9 calls)
                                                  0ms - with_children (1 calls)
                                                  0ms - ???
                                              0ms - ???
                                          0ms - rewrite_self (9 calls)
                                          0ms - with_children (1 calls)
                                          0ms - ???
                                      0ms - ???
                                  1ms - rewrite_self
                                      1ms - rewrite_children
                                          1ms - rewrite_self (10 calls)
                                          0ms - with_children (1 calls)
                                          0ms - ???
                                      0ms - ???
                                  2ms - rewrite_self
                                      2ms - rewrite_children
                                          2ms - rewrite_self
                                              2ms - rewrite_children
                                                  2ms - rewrite_self
                                                      2ms - rewrite_children
                                                          2ms - rewrite_self
                                                              2ms - rewrite_children
                                                                  2ms - rewrite_self
                                                                      2ms - rewrite_children
                                                                          1ms - rewrite_self
                                                                              1ms - rewrite_children
                                                                                  1ms - rewrite_self
                                                                                      1ms - rewrite_children
                                                                                          1ms - rewrite_self
                                                                                              1ms - rewrite_children
                                                                                                  1ms - rewrite_self
                                                                                                      1ms - rewrite_children
                                                                                                          1ms - rewrite_self
                                                                                                              1ms - rewrite_children
                                                                                                                  1ms - rewrite_self
                                                                                                                      1ms - rewrite_children
                                                                                                                          1ms - rewrite_self (3 calls)
                                                                                                                          0ms - with_children (1 calls)
                                                                                                                          0ms - ???
                                                                                                                      0ms - ???
                                                                                                                  0ms - rewrite_self (2 calls)
                                                                                                                  0ms - with_children (1 calls)
                                                                                                                  0ms - ???
                                                                                                              0ms - ???
                                                                                                          0ms - rewrite_self (4 calls)
                                                                                                          0ms - with_children (1 calls)
                                                                                                          0ms - ???
                                                                                                      0ms - ???
                                                                                                  0ms - rewrite_self (4 calls)
                                                                                                  0ms - with_children (1 calls)
                                                                                                  0ms - ???
                                                                                              0ms - ???
                                                                                          0ms - rewrite_self (2 calls)
                                                                                          0ms - with_children (1 calls)
                                                                                          0ms - ???
                                                                                      0ms - ???
                                                                                  0ms - rewrite_self (1 calls)
                                                                                  0ms - with_children (1 calls)
                                                                                  0ms - ???
                                                                              0ms - ???
                                                                          0ms - rewrite_self (6 calls)
                                                                          0ms - with_children (1 calls)
                                                                          0ms - ???
                                                                      0ms - ???
                                                                  0ms - rewrite_self (4 calls)
                                                                  0ms - with_children (1 calls)
                                                                  0ms - ???
                                                              0ms - ???
                                                          0ms - rewrite_self (1 calls)
                                                          0ms - with_children (1 calls)
                                                          0ms - ???
                                                      0ms - ???
                                                  0ms - rewrite_self (6 calls)
                                                  0ms - with_children (1 calls)
                                                  0ms - ???
                                              0ms - ???
                                          0ms - rewrite_self (9 calls)
                                          0ms - with_children (1 calls)
                                          0ms - ???
                                      0ms - ???
                                  1ms - rewrite_self
                                      1ms - rewrite_children
                                          1ms - rewrite_self
                                              1ms - rewrite_children
                                                  1ms - rewrite_self (9 calls)
                                                  0ms - with_children (1 calls)
                                                  0ms - ???
                                              0ms - ???
                                          0ms - rewrite_self (9 calls)
                                          0ms - with_children (1 calls)
                                          0ms - ???
                                      0ms - ???
                                  1ms - rewrite_self
                                      1ms - rewrite_children
                                          1ms - rewrite_self
                                              1ms - rewrite_children
                                                  1ms - rewrite_self (15 calls)
                                                  0ms - with_children (1 calls)
                                                  0ms - ???
                                              0ms - ???
                                          0ms - rewrite_self (10 calls)
                                          0ms - with_children (1 calls)
                                          0ms - ???
                                      0ms - ???
                                  2ms - rewrite_self
                                      2ms - rewrite_children
                                          1ms - rewrite_self
                                              1ms - rewrite_children
                                                  1ms - rewrite_self
                                                      1ms - rewrite_children
                                                          1ms - rewrite_self
                                                              1ms - rewrite_children
                                                                  1ms - rewrite_self
                                                                      1ms - rewrite_children
                                                                          1ms - rewrite_self
                                                                              1ms - rewrite_children
                                                                                  0ms - rewrite_self (9 calls)
                                                                                  0ms - with_children (1 calls)
                                                                                  0ms - ???
                                                                              0ms - ???
                                                                          0ms - rewrite_self (6 calls)
                                                                          0ms - with_children (1 calls)
                                                                          0ms - ???
                                                                      0ms - ???
                                                                  0ms - rewrite_self (8 calls)
                                                                  0ms - with_children (1 calls)
                                                                  0ms - ???
                                                              0ms - ???
                                                          0ms - with_children (1 calls)
                                                          0ms - ???
                                                      0ms - ???
                                                  0ms - rewrite_self (6 calls)
                                                  0ms - with_children (1 calls)
                                                  0ms - ???
                                              0ms - ???
                                          0ms - rewrite_self (14 calls)
                                          0ms - with_children (1 calls)
                                          0ms - ???
                                      0ms - ???
                                  2ms - rewrite_self
                                      2ms - rewrite_children
                                          1ms - rewrite_self
                                              1ms - rewrite_children
                                                  1ms - rewrite_self (21 calls)
                                                  0ms - with_children (1 calls)
                                                  0ms - ???
                                              0ms - ???
                                          1ms - rewrite_self
                                              1ms - rewrite_children
                                                  1ms - rewrite_self
                                                      1ms - rewrite_children
                                                          1ms - rewrite_self
                                                              1ms - rewrite_children
                                                                  1ms - rewrite_self (27 calls)
                                                                  0ms - with_children (1 calls)
                                                                  0ms - ???
                                                              0ms - ???
                                                          0ms - rewrite_self (1 calls)
                                                          0ms - with_children (1 calls)
                                                          0ms - ???
                                                      0ms - ???
                                                  0ms - rewrite_self (16 calls)
                                                  0ms - with_children (1 calls)
                                                  0ms - ???
                                              0ms - ???
                                          0ms - rewrite_self (9 calls)
                                          0ms - with_children (1 calls)
                                          0ms - ???
                                      0ms - ???
                                  2ms - rewrite_self
                                      2ms - rewrite_children
                                          1ms - rewrite_self
                                              1ms - rewrite_children
                                                  1ms - rewrite_self (21 calls)
                                                  0ms - with_children (1 calls)
                                                  0ms - ???
                                              0ms - ???
                                          1ms - rewrite_self
                                              1ms - rewrite_children
                                                  1ms - rewrite_self (17 calls)
                                                  0ms - with_children (1 calls)
                                                  0ms - ???
                                              0ms - ???
                                          0ms - rewrite_self (9 calls)
                                          0ms - with_children (1 calls)
                                          0ms - ???
                                      0ms - ???
                                  1ms - rewrite_self
                                      1ms - rewrite_children
                                          1ms - rewrite_self
                                              1ms - rewrite_children
                                                  1ms - rewrite_self
                                                      1ms - rewrite_children
                                                          1ms - rewrite_self (4 calls)
                                                          0ms - with_children (1 calls)
                                                          0ms - ???
                                                      0ms - ???
                                                  0ms - rewrite_self (4 calls)
                                                  0ms - with_children (1 calls)
                                                  0ms - ???
                                              0ms - ???
                                          0ms - rewrite_self (9 calls)
                                          0ms - with_children (1 calls)
                                          0ms - ???
                                      0ms - ???
                                  1ms - rewrite_self
                                      1ms - rewrite_children
                                          1ms - rewrite_self
                                              1ms - rewrite_children
                                                  1ms - rewrite_self
                                                      1ms - rewrite_children
                                                          1ms - rewrite_self
                                                              1ms - rewrite_children
                                                                  1ms - rewrite_self
                                                                      1ms - rewrite_children
                                                                          1ms - rewrite_self (5 calls)
                                                                          0ms - with_children (1 calls)
                                                                          0ms - ???
                                                                      0ms - ???
                                                                  0ms - rewrite_self (8 calls)
                                                                  0ms - with_children (1 calls)
                                                                  0ms - ???
                                                              0ms - ???
                                                          0ms - rewrite_self (4 calls)
                                                          0ms - with_children (1 calls)
                                                          0ms - ???
                                                      0ms - ???
                                                  0ms - rewrite_self (4 calls)
                                                  0ms - with_children (1 calls)
                                                  0ms - ???
                                              0ms - ???
                                          0ms - rewrite_self (11 calls)
                                          0ms - with_children (1 calls)
                                          0ms - ???
                                      0ms - ???
                                  9ms - rewrite_self
                                      9ms - rewrite_children
                                          9ms - rewrite_self
                                              9ms - rewrite_children
                                                  1ms - rewrite_self
                                                      1ms - rewrite_children
                                                          1ms - rewrite_self (6 calls)
                                                          0ms - with_children (1 calls)
                                                          0ms - ???
                                                      0ms - ???
                                                  1ms - rewrite_self
                                                      1ms - rewrite_children
                                                          1ms - rewrite_self (6 calls)
                                                          0ms - with_children (1 calls)
                                                          0ms - ???
                                                      0ms - ???
                                                  6ms - rewrite_self
                                                      6ms - rewrite_children
                                                          6ms - rewrite_self
                                                              6ms - rewrite_children
                                                                  6ms - rewrite_self
                                                                      6ms - rewrite_children
                                                                          6ms - rewrite_self
                                                                              6ms - rewrite_children
                                                                                  3ms - rewrite_self
                                                                                      3ms - rewrite_children
                                                                                          2ms - rewrite_self
                                                                                              2ms - rewrite_children
                                                                                                  2ms - rewrite_self
                                                                                                      2ms - rewrite_children
                                                                                                          2ms - rewrite_self
                                                                                                              2ms - rewrite_children
                                                                                                                  2ms - rewrite_self
                                                                                                                      2ms - rewrite_children
                                                                                                                          2ms - rewrite_self (12 calls)
                                                                                                                          0ms - with_children (1 calls)
                                                                                                                          0ms - ???
                                                                                                                      0ms - ???
                                                                                                                  0ms - rewrite_self (4 calls)
                                                                                                                  0ms - with_children (1 calls)
                                                                                                                  0ms - ???
                                                                                                              0ms - ???
                                                                                                          0ms - with_children (1 calls)
                                                                                                          0ms - ???
                                                                                                      0ms - ???
                                                                                                  0ms - rewrite_self (8 calls)
                                                                                                  0ms - with_children (1 calls)
                                                                                                  0ms - ???
                                                                                              0ms - ???
                                                                                          0ms - rewrite_self (4 calls)
                                                                                          0ms - with_children (1 calls)
                                                                                          0ms - ???
                                                                                      0ms - ???
                                                                                  1ms - rewrite_self
                                                                                      1ms - rewrite_children
                                                                                          1ms - rewrite_self
                                                                                              1ms - rewrite_children
                                                                                                  1ms - rewrite_self (7 calls)
                                                                                                  0ms - with_children (1 calls)
                                                                                                  0ms - ???
                                                                                              0ms - ???
                                                                                          0ms - rewrite_self (4 calls)
                                                                                          0ms - with_children (1 calls)
                                                                                          0ms - ???
                                                                                      0ms - ???
                                                                                  1ms - rewrite_self (12 calls)
                                                                                  0ms - with_children (1 calls)
                                                                                  0ms - ???
                                                                              0ms - ???
                                                                          0ms - rewrite_self (4 calls)
                                                                          0ms - with_children (1 calls)
                                                                          0ms - ???
                                                                      0ms - ???
                                                                  0ms - rewrite_self (6 calls)
                                                                  0ms - with_children (1 calls)
                                                                  0ms - ???
                                                              0ms - ???
                                                          0ms - rewrite_self (5 calls)
                                                          0ms - with_children (1 calls)
                                                          0ms - ???
                                                      0ms - ???
                                                  0ms - rewrite_self (12 calls)
                                                  0ms - with_children (1 calls)
                                                  0ms - ???
                                              0ms - ???
                                          0ms - rewrite_self (7 calls)
                                          0ms - with_children (1 calls)
                                          0ms - ???
                                      0ms - ???
                                  6ms - rewrite_self (50 calls)
                                  0ms - with_children (1 calls)
                                  0ms - ???
                              0ms - ???
                          0ms - rewrite_self (4 calls)
                          0ms - with_children (1 calls)
                          0ms - ???
                      0ms - ???
                  7ms - rewrite_self
                      7ms - rewrite_children
                          7ms - rewrite_self
                              7ms - rewrite_children
                                  1ms - rewrite_self
                                      1ms - rewrite_children
                                          1ms - rewrite_self
                                              1ms - rewrite_children
                                                  1ms - rewrite_self
                                                      1ms - rewrite_children
                                                          1ms - rewrite_self
                                                              1ms - rewrite_children
                                                                  1ms - rewrite_self (15 calls)
                                                                  0ms - with_children (1 calls)
                                                                  0ms - ???
                                                              0ms - ???
                                                          0ms - rewrite_self (4 calls)
                                                          0ms - with_children (1 calls)
                                                          0ms - ???
                                                      0ms - ???
                                                  0ms - rewrite_self (4 calls)
                                                  0ms - with_children (1 calls)
                                                  0ms - ???
                                              0ms - ???
                                          0ms - rewrite_self (9 calls)
                                          0ms - with_children (1 calls)
                                          0ms - ???
                                      0ms - ???
                                  1ms - rewrite_self
                                      1ms - rewrite_children
                                          1ms - rewrite_self
                                              1ms - rewrite_children
                                                  1ms - rewrite_self (11 calls)
                                                  0ms - with_children (1 calls)
                                                  0ms - ???
                                              0ms - ???
                                          0ms - rewrite_self (9 calls)
                                          0ms - with_children (1 calls)
                                          0ms - ???
                                      0ms - ???
                                  3ms - rewrite_self
                                      3ms - rewrite_children
                                          2ms - rewrite_self
                                              2ms - rewrite_children
                                                  2ms - rewrite_self
                                                      2ms - rewrite_children
                                                          2ms - rewrite_self
                                                              2ms - rewrite_children
                                                                  2ms - rewrite_self
                                                                      2ms - rewrite_children
                                                                          1ms - rewrite_self
                                                                              1ms - rewrite_children
                                                                                  1ms - rewrite_self
                                                                                      1ms - rewrite_children
                                                                                          1ms - rewrite_self
                                                                                              1ms - rewrite_children
                                                                                                  1ms - rewrite_self
                                                                                                      1ms - rewrite_children
                                                                                                          1ms - rewrite_self
                                                                                                              1ms - rewrite_children
                                                                                                                  1ms - rewrite_self
                                                                                                                      1ms - rewrite_children
                                                                                                                          1ms - rewrite_self
                                                                                                                              1ms - rewrite_children
                                                                                                                                  1ms - rewrite_self (5 calls)
                                                                                                                                  0ms - with_children (1 calls)
                                                                                                                                  0ms - ???
                                                                                                                              0ms - ???
                                                                                                                          0ms - rewrite_self (4 calls)
                                                                                                                          0ms - with_children (1 calls)
                                                                                                                          0ms - ???
                                                                                                                      0ms - ???
                                                                                                                  0ms - rewrite_self (2 calls)
                                                                                                                  0ms - with_children (1 calls)
                                                                                                                  0ms - ???
                                                                                                              0ms - ???
                                                                                                          0ms - rewrite_self (2 calls)
                                                                                                          0ms - with_children (1 calls)
                                                                                                          0ms - ???
                                                                                                      0ms - ???
                                                                                                  0ms - rewrite_self (3 calls)
                                                                                                  0ms - with_children (1 calls)
                                                                                                  0ms - ???
                                                                                              0ms - ???
                                                                                          0ms - rewrite_self (6 calls)
                                                                                          0ms - with_children (1 calls)
                                                                                          0ms - ???
                                                                                      0ms - ???
                                                                                  0ms - rewrite_self (4 calls)
                                                                                  0ms - with_children (1 calls)
                                                                                  0ms - ???
                                                                              0ms - ???
                                                                          0ms - rewrite_self (7 calls)
                                                                          0ms - with_children (1 calls)
                                                                          0ms - ???
                                                                      0ms - ???
                                                                  0ms - rewrite_self (4 calls)
                                                                  0ms - with_children (1 calls)
                                                                  0ms - ???
                                                              0ms - ???
                                                          0ms - rewrite_self (7 calls)
                                                          0ms - with_children (1 calls)
                                                          0ms - ???
                                                      0ms - ???
                                                  0ms - rewrite_self (8 calls)
                                                  0ms - with_children (1 calls)
                                                  0ms - ???
                                              0ms - ???
                                          0ms - rewrite_self (9 calls)
                                          0ms - with_children (1 calls)
                                          0ms - ???
                                      0ms - ???
                                  0ms - rewrite_self (10 calls)
                                  0ms - with_children (1 calls)
                                  0ms - ???
                              0ms - ???
                          0ms - rewrite_self (4 calls)
                          0ms - with_children (1 calls)
                          0ms - ???
                      0ms - ???
                  3ms - rewrite_self
                      3ms - rewrite_children
                          3ms - rewrite_self
                              3ms - rewrite_children
                                  3ms - rewrite_self
                                      3ms - rewrite_children
                                          2ms - rewrite_self
                                              2ms - rewrite_children
                                                  2ms - rewrite_self
                                                      2ms - rewrite_children
                                                          2ms - rewrite_self
                                                              2ms - rewrite_children
                                                                  1ms - rewrite_self
                                                                      1ms - rewrite_children
                                                                          1ms - rewrite_self
                                                                              1ms - rewrite_children
                                                                                  1ms - rewrite_self
                                                                                      1ms - rewrite_children
                                                                                          1ms - rewrite_self
                                                                                              1ms - rewrite_children
                                                                                                  1ms - rewrite_self (9 calls)
                                                                                                  0ms - with_children (1 calls)
                                                                                                  0ms - ???
                                                                                              0ms - ???
                                                                                          0ms - rewrite_self (10 calls)
                                                                                          0ms - with_children (1 calls)
                                                                                          0ms - ???
                                                                                      0ms - ???
                                                                                  0ms - rewrite_self (4 calls)
                                                                                  0ms - with_children (1 calls)
                                                                                  0ms - ???
                                                                              0ms - ???
                                                                          0ms - rewrite_self (12 calls)
                                                                          0ms - with_children (1 calls)
                                                                          0ms - ???
                                                                      0ms - ???
                                                                  0ms - rewrite_self (4 calls)
                                                                  0ms - with_children (1 calls)
                                                                  0ms - ???
                                                              0ms - ???
                                                          0ms - rewrite_self (1 calls)
                                                          0ms - with_children (1 calls)
                                                          0ms - ???
                                                      0ms - ???
                                                  0ms - rewrite_self (12 calls)
                                                  0ms - with_children (1 calls)
                                                  0ms - ???
                                              0ms - ???
                                          0ms - rewrite_self (9 calls)
                                          0ms - with_children (1 calls)
                                          0ms - ???
                                      0ms - ???
                                  0ms - rewrite_self (4 calls)
                                  0ms - with_children (1 calls)
                                  0ms - ???
                              0ms - ???
                          0ms - rewrite_self (4 calls)
                          0ms - with_children (1 calls)
                          0ms - ???
                      0ms - ???
                 17ms - rewrite_self (157 calls)
                  0ms - with_children (1 calls)
                  0ms - ???
              0ms - ???
          1ms - diff
          0ms - insert_use (1 calls)
          0ms - into_text_edit (1 calls)
          0ms - mod_path_to_ast (1 calls)
          0ms - rewrite_root (1 calls)
          3ms - ???
      0ms - ???
 17ms - fuzzy_completion
      9ms - find_similar_imports
          9ms - find_similar_imports
              2ms - get_name_definition
                  2ms - classify_name
                      0ms - SourceBinder::to_module_def (1 calls)
                      0ms - crate_def_map:wait (1 calls)
                      0ms - macro_expand (5 calls)
                      1ms - parse_macro_expansion (6 calls)
                      0ms - ???
                  0ms - ???
              1ms - get_name_definition
                  1ms - classify_name
                      0ms - SourceBinder::to_module_def (1 calls)
                      0ms - crate_def_map:wait (1 calls)
                      0ms - macro_expand (7 calls)
                      0ms - parse_macro_expansion (7 calls)
                      0ms - ???
                  0ms - ???
              0ms - crate_def_map:wait (1 calls)
              0ms - get_name_definition (48 calls)
              0ms - search_dependencies (1 calls)
              4ms - ???
          0ms - ???
      7ms - find_path (51 calls)
      0ms - render_resolution (20 calls)
      0ms - ???
 16ms - fuzzy_completion
      7ms - find_similar_imports
          7ms - find_similar_imports
              2ms - get_name_definition
                  2ms - classify_name
                      0ms - SourceBinder::to_module_def (1 calls)
                      0ms - crate_def_map:wait (1 calls)
                      0ms - macro_expand (5 calls)
                      1ms - parse_macro_expansion (5 calls)
                      0ms - ???
                  0ms - ???
              0ms - crate_def_map:wait (1 calls)
              0ms - get_name_definition (42 calls)
              0ms - search_dependencies (1 calls)
              4ms - ???
          0ms - ???
      8ms - find_path (42 calls)
      0ms - render_resolution (20 calls)
      0ms - ???

note that with this, fuzzy_completions are down to 20ms, yet handle_resolve_completion operation is now close to 200ms (and results with the "overly long loop turn")
I have a feeling (not sure if true though), that rewrite_children can get another small fix somewhere, since all I do is insert an import, yet the change trace is massive.

This isn't the final version of the feature, but the fuzzy completion and resolve completion code will most probably stay the same for the first iteration, so we might want to try and optimise this case.

Yet 5333ms is something dreadful, I've never seen my readings spiking over 300ms.

@Veykril
Copy link
Member

Veykril commented Dec 2, 2020

Yet 5333ms is something dreadful, I've never seen my readings spinning over 300ms.

Same applies for me, never saw it go above 300ms either.

So SyntaxRewriter seems to always traverse all the descendants of the root node until it hits either a replacement or a token, so even if we were to only replace a single node in the tree we would still visit all the descendants of all its siblings which sounds very wasteful. This also means we kind of always do a deep clone of the tree(minus the replacements/deletions) due to how rewrite_children works if I am not mistaken.

@matklad
Copy link
Member

matklad commented Dec 2, 2020

I've just tried to re-reproduce on the latest master, it reproduced easily:

image

bors bot added a commit that referenced this issue Dec 8, 2020
6706: Move import text edit calculation into a completion resolve request r=matklad a=SomeoneToIgnore

Part of #6612 (presumably fixing it)
Part of #6366 (does not cover all possible resolve capabilities we can do)
Closes #6594

Further improves imports on completion performance by deferring the computations for import inserts.

To use the new mode, you have to have the experimental completions enabled and use the LSP 3.16-compliant client that reports `additionalTextEdits` in its `CompletionItemCapabilityResolveSupport` field in the client capabilities.
rust-analyzer VSCode extension does this already hence picks up the changes completely.

Performance implications are descrbed in: #6633 (comment)

Co-authored-by: Kirill Bulatov <mail4score@gmail.com>
@matklad
Copy link
Member

matklad commented Dec 10, 2020

I've just tried to re-reproduce on the latest master, it reproduced easily:

Found it!

#6805

still slow after this change, but already much faster.

@lnicola lnicola added S-unactionable Issue requires feedback, design decisions or is blocked on other work A-completion autocompletion A-perf performance issues labels Dec 20, 2020
bors bot added a commit that referenced this issue Apr 2, 2021
8302: Allow multiple modules from the same crate in fixtures r=SomeoneToIgnore a=SomeoneToIgnore

A tiny step towards #6633

As discussed in [Zulip](https://rust-lang.zulipchat.com/#narrow/stream/185405-t-compiler.2Fwg-rls-2.2E0/topic/Completion.20benchmarks), we would need to have a generated code for the completions benchmark.
To better represent a real project, we'd better allow to specify multiple modules in a crate within a single fixture.

Co-authored-by: Kirill Bulatov <mail4score@gmail.com>
@matklad
Copy link
Member

matklad commented May 21, 2021

We now have an actually usable bench here:

https://github.com/rust-analyzer/rust-analyzer/blob/eb08a27f1bd31cc15db4893dded60663effaf3f9/crates/rust-analyzer/src/integrated_benchmarks.rs#L80

it works fine for debugging and and investigation.

We don’t use it to capture regressions. I wish we had infra for perf regression tests, but I don’t know an easy way to do it reliably.

@matklad matklad closed this as completed May 21, 2021
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
A-completion autocompletion A-perf performance issues S-unactionable Issue requires feedback, design decisions or is blocked on other work
Projects
None yet
Development

No branches or pull requests

6 participants