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

Self Profiling Causes ICE With Parallel rustc #54141

Closed
TheDarkula opened this issue Sep 11, 2018 · 3 comments
Closed

Self Profiling Causes ICE With Parallel rustc #54141

TheDarkula opened this issue Sep 11, 2018 · 3 comments
Labels
A-parallel-queries Area: Parallel query execution I-ICE Issue: The compiler panicked, giving an Internal Compilation Error (ICE) ❄️

Comments

@TheDarkula
Copy link
Contributor

I parallelised check_crate() in src/librustc_passes/rvalue_promotion.rs. Then ran a test compile on the regex crate with cargo rustc -- -Z time-passes -Z query-threads=4.

This caused an ICE saying:

thread '<unnamed>' panicked at 'end_activity() was called but a different activity was running', librustc/util/profiling.rs:179:17

cc @wesleywiser @Zoxc

@wesleywiser
Copy link
Member

The self profiler isn't compatible with parallel queries yet. Right now, there's just a singleton instance of the profiler but with parallel queries we probably need one per worker thread stored in TLS or something. At the end, we'll aggregate all the info together and display it.

For now, it's probably a good idea to disable the self profiler if you are using parallel queries.

@TheDarkula
Copy link
Contributor Author

Ah, that explains rustc yelling at me.
Thanks for the info

@memoryruins memoryruins added I-ICE Issue: The compiler panicked, giving an Internal Compilation Error (ICE) ❄️ A-parallel-queries Area: Parallel query execution labels Sep 15, 2018
bors added a commit that referenced this issue Feb 10, 2019
Implement more detailed self profiling

Timing data and cache hits/misses are now recorded at the query level.
This allows us to show detailed per query information such as total time
for each query.

To see detailed query information in the summary pass the `-Z verbose`
flag. For example:

```
rustc -Z self-profile -Z verbose hello_world.rs
```

results in something like:

```md
Self profiling results:

| Phase                                     | Time (ms)      | Time (%) | Queries        | Hits (%)
| ----------------------------------------- | -------------- | -------- | -------------- | --------
| Other                                     |            177 |    54.97 |           8094 |    45.47
| - {time spent not running queries}        |            113 |    35.09 |              0 |     0.00
| - const_eval                              |             16 |     4.97 |             26 |    11.54
| - type_of                                 |              9 |     2.80 |            627 |    27.75
| - const_eval_raw                          |              8 |     2.48 |             22 |     0.00
| - adt_def                                 |              7 |     2.17 |            381 |    11.55
| - visible_parent_map                      |              7 |     2.17 |             99 |    98.99
| - item_attrs                              |              6 |     1.86 |            698 |    50.14
| - item_children                           |              5 |     1.55 |           2815 |     0.00
| - adt_dtorck_constraint                   |              4 |     1.24 |              2 |     0.00
| - adt_destructor                          |              2 |     0.62 |             15 |    86.67
| TypeChecking                              |             53 |    16.46 |           2834 |    79.89
| - trait_impls_of                          |              9 |     2.80 |             65 |    86.15
| - evaluate_obligation                     |              7 |     2.17 |             80 |     2.50
| - const_is_rvalue_promotable_to_static    |              6 |     1.86 |              1 |     0.00
| - is_copy_raw                             |              6 |     1.86 |             29 |    58.62
| - rvalue_promotable_map                   |              6 |     1.86 |              2 |    50.00
| - {time spent not running queries}        |              6 |     1.86 |              0 |     0.00
| - typeck_item_bodies                      |              5 |     1.55 |              1 |     0.00
| - typeck_tables_of                        |              5 |     1.55 |             19 |    94.74
| - dropck_outlives                         |              2 |     0.62 |              1 |     0.00
| - layout_raw                              |              1 |     0.31 |            668 |    87.87
| Linking                                   |             48 |    14.91 |             43 |    46.51
| - {time spent not running queries}        |             48 |    14.91 |              0 |     0.00
| Codegen                                   |             29 |     9.01 |            420 |    61.90
| - {time spent not running queries}        |             16 |     4.97 |              0 |     0.00
| - collect_and_partition_mono_items        |             11 |     3.42 |             13 |    92.31
| - mir_const                               |              1 |     0.31 |              1 |     0.00
| - mir_validated                           |              1 |     0.31 |              3 |    66.67
| Expansion                                 |             14 |     4.35 |              0 |     0.00
| - {time spent not running queries}        |             14 |     4.35 |              0 |     0.00
| BorrowChecking                            |              1 |     0.31 |             12 |    41.67
| - borrowck                                |              1 |     0.31 |              2 |    50.00
| Parsing                                   |              0 |     0.00 |              0 |     0.00

Optimization level: No
Incremental: off
```

<details>
<summary>Rendered</summary>

Self profiling results:

| Phase                                     | Time (ms)      | Time (%) | Queries        | Hits (%)
| ----------------------------------------- | -------------- | -------- | -------------- | --------
| **Other**                                     |           **177** |   **54.97** |   **8094** |  **45.47**
| - {time spent not running queries}        |            113 |    35.09 |              0 |     0.00
| - const_eval                              |             16 |     4.97 |             26 |    11.54
| - type_of                                 |              9 |     2.80 |            627 |    27.75
| - const_eval_raw                          |              8 |     2.48 |             22 |     0.00
| - adt_def                                 |              7 |     2.17 |            381 |    11.55
| - visible_parent_map                      |              7 |     2.17 |             99 |    98.99
| - item_attrs                              |              6 |     1.86 |            698 |    50.14
| - item_children                           |              5 |     1.55 |           2815 |     0.00
| - adt_dtorck_constraint                   |              4 |     1.24 |              2 |     0.00
| - adt_destructor                          |              2 |     0.62 |             15 |    86.67
| TypeChecking                              |             53 |    16.46 |           2834 |    79.89
| - trait_impls_of                          |              9 |     2.80 |             65 |    86.15
| - evaluate_obligation                     |              7 |     2.17 |             80 |     2.50
| - const_is_rvalue_promotable_to_static    |              6 |     1.86 |              1 |     0.00
| - is_copy_raw                             |              6 |     1.86 |             29 |    58.62
| - rvalue_promotable_map                   |              6 |     1.86 |              2 |    50.00
| - {time spent not running queries}        |              6 |     1.86 |              0 |     0.00
| - typeck_item_bodies                      |              5 |     1.55 |              1 |     0.00
| - typeck_tables_of                        |              5 |     1.55 |             19 |    94.74
| - dropck_outlives                         |              2 |     0.62 |              1 |     0.00
| - layout_raw                              |              1 |     0.31 |            668 |    87.87
| Linking                                   |             48 |    14.91 |             43 |    46.51
| - {time spent not running queries}        |             48 |    14.91 |              0 |     0.00
| Codegen                                   |             29 |     9.01 |            420 |    61.90
| - {time spent not running queries}        |             16 |     4.97 |              0 |     0.00
| - collect_and_partition_mono_items        |             11 |     3.42 |             13 |    92.31
| - mir_const                               |              1 |     0.31 |              1 |     0.00
| - mir_validated                           |              1 |     0.31 |              3 |    66.67
| Expansion                                 |             14 |     4.35 |              0 |     0.00
| - {time spent not running queries}        |             14 |     4.35 |              0 |     0.00
| BorrowChecking                            |              1 |     0.31 |             12 |    41.67
| - borrowck                                |              1 |     0.31 |              2 |    50.00
| Parsing                                   |              0 |     0.00 |              0 |     0.00

Optimization level: No
Incremental: off

</details>
cc @nikomatsakis @michaelwoerister @Zoxc

Fixes #54141
@TheDarkula
Copy link
Contributor Author

@wesleywiser Awesome! Thanks so much for this.
Now I can get back to work on parallelism :)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
A-parallel-queries Area: Parallel query execution I-ICE Issue: The compiler panicked, giving an Internal Compilation Error (ICE) ❄️
Projects
None yet
Development

No branches or pull requests

3 participants