Don't print thread ids and names in `tracing` logs #78933

jyn514 · 2020-11-10T22:33:37Z

Before:

2:rustc INFO rustc_interface::passes Pre-codegen
2:rustcTy interner             total           ty lt ct all
2:rustc    Adt               :   1078 81.3%,  0.0%   0.0%  0.0%  0.0%
2:rustc    Array             :      1  0.1%,  0.0%   0.0%  0.0%  0.0%
2:rustc    Slice             :      1  0.1%,  0.0%   0.0%  0.0%  0.0%
2:rustc    RawPtr            :      2  0.2%,  0.0%   0.0%  0.0%  0.0%
2:rustc    Ref               :      4  0.3%,  0.1%   0.1%  0.0%  0.0%
2:rustc    FnDef             :      0  0.0%,  0.0%   0.0%  0.0%  0.0%
2:rustc    FnPtr             :     76  5.7%,  0.0%   0.0%  0.0%  0.0%
2:rustc    Placeholder       :      0  0.0%,  0.0%   0.0%  0.0%  0.0%
2:rustc    Generator         :      0  0.0%,  0.0%   0.0%  0.0%  0.0%
2:rustc    GeneratorWitness  :      0  0.0%,  0.0%   0.0%  0.0%  0.0%
2:rustc    Dynamic           :      3  0.2%,  0.0%   0.0%  0.0%  0.0%
2:rustc    Closure           :      0  0.0%,  0.0%   0.0%  0.0%  0.0%
2:rustc    Tuple             :     13  1.0%,  0.0%   0.0%  0.0%  0.0%
2:rustc    Bound             :      0  0.0%,  0.0%   0.0%  0.0%  0.0%
2:rustc    Param             :    146 11.0%,  0.0%   0.0%  0.0%  0.0%
2:rustc    Infer             :      2  0.2%,  0.1%   0.0%  0.0%  0.0%
2:rustc    Projection        :      0  0.0%,  0.0%   0.0%  0.0%  0.0%
2:rustc    Opaque            :      0  0.0%,  0.0%   0.0%  0.0%  0.0%
2:rustc    Foreign           :      0  0.0%,  0.0%   0.0%  0.0%  0.0%
2:rustc                  total   1326         0.2%   0.1%  0.0%  0.0%
2:rustcInternalSubsts interner: #437
2:rustcRegion interner: #355
2:rustcStability interner: #1
2:rustcConst Stability interner: #0
2:rustcAllocation interner: #0
2:rustcLayout interner: #0

After:

 INFO rustc_interface::passes Post-codegen
Ty interner             total           ty lt ct all
    Adt               :   1078 81.3%,  0.0%   0.0%  0.0%  0.0%
    Array             :      1  0.1%,  0.0%   0.0%  0.0%  0.0%
    Slice             :      1  0.1%,  0.0%   0.0%  0.0%  0.0%
    RawPtr            :      2  0.2%,  0.0%   0.0%  0.0%  0.0%
    Ref               :      4  0.3%,  0.1%   0.1%  0.0%  0.0%
    FnDef             :      0  0.0%,  0.0%   0.0%  0.0%  0.0%
    FnPtr             :     76  5.7%,  0.0%   0.0%  0.0%  0.0%
    Placeholder       :      0  0.0%,  0.0%   0.0%  0.0%  0.0%
    Generator         :      0  0.0%,  0.0%   0.0%  0.0%  0.0%
    GeneratorWitness  :      0  0.0%,  0.0%   0.0%  0.0%  0.0%
    Dynamic           :      3  0.2%,  0.0%   0.0%  0.0%  0.0%
    Closure           :      0  0.0%,  0.0%   0.0%  0.0%  0.0%
    Tuple             :     13  1.0%,  0.0%   0.0%  0.0%  0.0%
    Bound             :      0  0.0%,  0.0%   0.0%  0.0%  0.0%
    Param             :    146 11.0%,  0.0%   0.0%  0.0%  0.0%
    Infer             :      2  0.2%,  0.1%   0.0%  0.0%  0.0%
    Projection        :      0  0.0%,  0.0%   0.0%  0.0%  0.0%
    Opaque            :      0  0.0%,  0.0%   0.0%  0.0%  0.0%
    Foreign           :      0  0.0%,  0.0%   0.0%  0.0%  0.0%
                  total   1326         0.2%   0.1%  0.0%  0.0%
InternalSubsts interner: #437
Region interner: #355
Stability interner: #1
Const Stability interner: #0
Allocation interner: #0
Layout interner: #0

Closes #78931
r? @oli-obk

Before: ``` 2:rustc INFO rustc_interface::passes Pre-codegen 2:rustcTy interner total ty lt ct all 2:rustc Adt : 1078 81.3%, 0.0% 0.0% 0.0% 0.0% 2:rustc Array : 1 0.1%, 0.0% 0.0% 0.0% 0.0% 2:rustc Slice : 1 0.1%, 0.0% 0.0% 0.0% 0.0% 2:rustc RawPtr : 2 0.2%, 0.0% 0.0% 0.0% 0.0% 2:rustc Ref : 4 0.3%, 0.1% 0.1% 0.0% 0.0% 2:rustc FnDef : 0 0.0%, 0.0% 0.0% 0.0% 0.0% 2:rustc FnPtr : 76 5.7%, 0.0% 0.0% 0.0% 0.0% 2:rustc Placeholder : 0 0.0%, 0.0% 0.0% 0.0% 0.0% 2:rustc Generator : 0 0.0%, 0.0% 0.0% 0.0% 0.0% 2:rustc GeneratorWitness : 0 0.0%, 0.0% 0.0% 0.0% 0.0% 2:rustc Dynamic : 3 0.2%, 0.0% 0.0% 0.0% 0.0% 2:rustc Closure : 0 0.0%, 0.0% 0.0% 0.0% 0.0% 2:rustc Tuple : 13 1.0%, 0.0% 0.0% 0.0% 0.0% 2:rustc Bound : 0 0.0%, 0.0% 0.0% 0.0% 0.0% 2:rustc Param : 146 11.0%, 0.0% 0.0% 0.0% 0.0% 2:rustc Infer : 2 0.2%, 0.1% 0.0% 0.0% 0.0% 2:rustc Projection : 0 0.0%, 0.0% 0.0% 0.0% 0.0% 2:rustc Opaque : 0 0.0%, 0.0% 0.0% 0.0% 0.0% 2:rustc Foreign : 0 0.0%, 0.0% 0.0% 0.0% 0.0% 2:rustc total 1326 0.2% 0.1% 0.0% 0.0% 2:rustcInternalSubsts interner: rust-lang#437 2:rustcRegion interner: rust-lang#355 2:rustcStability interner: #1 2:rustcConst Stability interner: #0 2:rustcAllocation interner: #0 2:rustcLayout interner: #0 ``` After: ``` INFO rustc_interface::passes Post-codegen Ty interner total ty lt ct all Adt : 1078 81.3%, 0.0% 0.0% 0.0% 0.0% Array : 1 0.1%, 0.0% 0.0% 0.0% 0.0% Slice : 1 0.1%, 0.0% 0.0% 0.0% 0.0% RawPtr : 2 0.2%, 0.0% 0.0% 0.0% 0.0% Ref : 4 0.3%, 0.1% 0.1% 0.0% 0.0% FnDef : 0 0.0%, 0.0% 0.0% 0.0% 0.0% FnPtr : 76 5.7%, 0.0% 0.0% 0.0% 0.0% Placeholder : 0 0.0%, 0.0% 0.0% 0.0% 0.0% Generator : 0 0.0%, 0.0% 0.0% 0.0% 0.0% GeneratorWitness : 0 0.0%, 0.0% 0.0% 0.0% 0.0% Dynamic : 3 0.2%, 0.0% 0.0% 0.0% 0.0% Closure : 0 0.0%, 0.0% 0.0% 0.0% 0.0% Tuple : 13 1.0%, 0.0% 0.0% 0.0% 0.0% Bound : 0 0.0%, 0.0% 0.0% 0.0% 0.0% Param : 146 11.0%, 0.0% 0.0% 0.0% 0.0% Infer : 2 0.2%, 0.1% 0.0% 0.0% 0.0% Projection : 0 0.0%, 0.0% 0.0% 0.0% 0.0% Opaque : 0 0.0%, 0.0% 0.0% 0.0% 0.0% Foreign : 0 0.0%, 0.0% 0.0% 0.0% 0.0% total 1326 0.2% 0.1% 0.0% 0.0% InternalSubsts interner: rust-lang#437 Region interner: rust-lang#355 Stability interner: #1 Const Stability interner: #0 Allocation interner: #0 Layout interner: #0 ```

oli-obk · 2020-11-11T09:08:47Z

compiler/rustc_driver/src/lib.rs

@@ -1288,8 +1288,6 @@ pub fn init_env_logger(env: &str) {
        .with_indent_lines(true)
        .with_ansi(true)
        .with_targets(true)
-        .with_thread_ids(true)


I did turn these on on purpose, because in a parallel rustc we'll be unable to pick apart the tracing messages otherwise. One alternative would be to only turn them on if there's a RUSTC_LOG_THREADS env var set. So by default we would not emit these for now. What do you think?

Is there a way to tell if the parallel compiler is enabled? Maybe with a cfg? It would be nice for this to be enabled/disabled automatically.

it's a command line flag, which we don't have access to at this stage. I think we can cross that bridge when parallel compiling and debugging parallel compilers becomes more common.

@oli-obk are you sure? I see a lot of cfg(parallel_compiler) around the code base - do you have to both build the parallel compiler and opt into it with a command line flag?

There's two bits of parallel compiler: query-level support in compiled code (e.g. using a mutex), and separately how many threads we actually end up using (-Zthreads). The latter only has any effect if the first is enabled, which is indeed cfg paralllel_compiler.

Ok, it sounds like a) the question only matters when parallel_compiler is set, and then separately b) it might be nice to disable thread-based logging when cfg(parallel_compiler) is set but -Z threads isn't passed. I implemented a) and I think I'll leave b) for when parallel_compiler is better maintained - how does that sound?

oli-obk · 2020-11-12T08:57:36Z

@bors r+ rollup

bors · 2020-11-12T08:57:38Z

📌 Commit 6e9ed8b has been approved by oli-obk

Don't print thread ids and names in `tracing` logs Before: ``` 2:rustc INFO rustc_interface::passes Pre-codegen 2:rustcTy interner total ty lt ct all 2:rustc Adt : 1078 81.3%, 0.0% 0.0% 0.0% 0.0% 2:rustc Array : 1 0.1%, 0.0% 0.0% 0.0% 0.0% 2:rustc Slice : 1 0.1%, 0.0% 0.0% 0.0% 0.0% 2:rustc RawPtr : 2 0.2%, 0.0% 0.0% 0.0% 0.0% 2:rustc Ref : 4 0.3%, 0.1% 0.1% 0.0% 0.0% 2:rustc FnDef : 0 0.0%, 0.0% 0.0% 0.0% 0.0% 2:rustc FnPtr : 76 5.7%, 0.0% 0.0% 0.0% 0.0% 2:rustc Placeholder : 0 0.0%, 0.0% 0.0% 0.0% 0.0% 2:rustc Generator : 0 0.0%, 0.0% 0.0% 0.0% 0.0% 2:rustc GeneratorWitness : 0 0.0%, 0.0% 0.0% 0.0% 0.0% 2:rustc Dynamic : 3 0.2%, 0.0% 0.0% 0.0% 0.0% 2:rustc Closure : 0 0.0%, 0.0% 0.0% 0.0% 0.0% 2:rustc Tuple : 13 1.0%, 0.0% 0.0% 0.0% 0.0% 2:rustc Bound : 0 0.0%, 0.0% 0.0% 0.0% 0.0% 2:rustc Param : 146 11.0%, 0.0% 0.0% 0.0% 0.0% 2:rustc Infer : 2 0.2%, 0.1% 0.0% 0.0% 0.0% 2:rustc Projection : 0 0.0%, 0.0% 0.0% 0.0% 0.0% 2:rustc Opaque : 0 0.0%, 0.0% 0.0% 0.0% 0.0% 2:rustc Foreign : 0 0.0%, 0.0% 0.0% 0.0% 0.0% 2:rustc total 1326 0.2% 0.1% 0.0% 0.0% 2:rustcInternalSubsts interner: rust-lang#437 2:rustcRegion interner: rust-lang#355 2:rustcStability interner: #1 2:rustcConst Stability interner: #0 2:rustcAllocation interner: #0 2:rustcLayout interner: #0 ``` After: ``` INFO rustc_interface::passes Post-codegen Ty interner total ty lt ct all Adt : 1078 81.3%, 0.0% 0.0% 0.0% 0.0% Array : 1 0.1%, 0.0% 0.0% 0.0% 0.0% Slice : 1 0.1%, 0.0% 0.0% 0.0% 0.0% RawPtr : 2 0.2%, 0.0% 0.0% 0.0% 0.0% Ref : 4 0.3%, 0.1% 0.1% 0.0% 0.0% FnDef : 0 0.0%, 0.0% 0.0% 0.0% 0.0% FnPtr : 76 5.7%, 0.0% 0.0% 0.0% 0.0% Placeholder : 0 0.0%, 0.0% 0.0% 0.0% 0.0% Generator : 0 0.0%, 0.0% 0.0% 0.0% 0.0% GeneratorWitness : 0 0.0%, 0.0% 0.0% 0.0% 0.0% Dynamic : 3 0.2%, 0.0% 0.0% 0.0% 0.0% Closure : 0 0.0%, 0.0% 0.0% 0.0% 0.0% Tuple : 13 1.0%, 0.0% 0.0% 0.0% 0.0% Bound : 0 0.0%, 0.0% 0.0% 0.0% 0.0% Param : 146 11.0%, 0.0% 0.0% 0.0% 0.0% Infer : 2 0.2%, 0.1% 0.0% 0.0% 0.0% Projection : 0 0.0%, 0.0% 0.0% 0.0% 0.0% Opaque : 0 0.0%, 0.0% 0.0% 0.0% 0.0% Foreign : 0 0.0%, 0.0% 0.0% 0.0% 0.0% total 1326 0.2% 0.1% 0.0% 0.0% InternalSubsts interner: rust-lang#437 Region interner: rust-lang#355 Stability interner: #1 Const Stability interner: #0 Allocation interner: #0 Layout interner: #0 ``` Closes rust-lang#78931 r? `@oli-obk`

…laumeGomez Rollup of 5 pull requests Successful merges: - rust-lang#78916 (extend const generics test suite) - rust-lang#78921 (Improve the page title switch handling between search and doc) - rust-lang#78933 (Don't print thread ids and names in `tracing` logs) - rust-lang#78960 (Test default values for const parameters.) - rust-lang#78971 (Update books) Failed merges: r? `@ghost` `@rustbot` modify labels: rollup

rust-highfive assigned oli-obk Nov 10, 2020

rust-highfive added the S-waiting-on-review Status: Awaiting review from the assignee but also interested parties. label Nov 10, 2020

jyn514 added A-contributor-roadblock Area: Makes things more difficult for new or seasoned contributors to Rust T-compiler Relevant to the compiler team, which will review and decide on the PR/issue. labels Nov 10, 2020

oli-obk reviewed Nov 11, 2020

View reviewed changes

Enable thread names in debug logging only for parallel_compiler

6e9ed8b

bors added S-waiting-on-bors Status: Waiting on bors to run and complete tests. Bors will change the label on completion. and removed S-waiting-on-review Status: Awaiting review from the assignee but also interested parties. labels Nov 12, 2020

GuillaumeGomez mentioned this pull request Nov 12, 2020

Rollup of 7 pull requests #78974

Closed

GuillaumeGomez mentioned this pull request Nov 12, 2020

Rollup of 5 pull requests #78976

Merged

bors merged commit d3244df into rust-lang:master Nov 12, 2020

rustbot added this to the 1.49.0 milestone Nov 12, 2020

jyn514 deleted the tracing-output branch November 12, 2020 15:42

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Don't print thread ids and names in `tracing` logs #78933

Don't print thread ids and names in `tracing` logs #78933

jyn514 commented Nov 10, 2020

oli-obk Nov 11, 2020

jyn514 Nov 11, 2020

oli-obk Nov 11, 2020 •

edited

Loading

jyn514 Nov 11, 2020

Mark-Simulacrum Nov 11, 2020

jyn514 Nov 11, 2020

oli-obk commented Nov 12, 2020

bors commented Nov 12, 2020

Don't print thread ids and names in tracing logs #78933

Don't print thread ids and names in tracing logs #78933

Conversation

jyn514 commented Nov 10, 2020

oli-obk Nov 11, 2020

Choose a reason for hiding this comment

jyn514 Nov 11, 2020

Choose a reason for hiding this comment

oli-obk Nov 11, 2020 • edited Loading

Choose a reason for hiding this comment

jyn514 Nov 11, 2020

Choose a reason for hiding this comment

Mark-Simulacrum Nov 11, 2020

Choose a reason for hiding this comment

jyn514 Nov 11, 2020

Choose a reason for hiding this comment

oli-obk commented Nov 12, 2020

bors commented Nov 12, 2020

Don't print thread ids and names in `tracing` logs #78933

Don't print thread ids and names in `tracing` logs #78933

oli-obk Nov 11, 2020 •

edited

Loading