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.

Sign up for GitHub

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

Jump to bottom

Compile times suddenly extremly high #62567

Closed
fabianvdW opened this issue Jul 10, 2019 · 8 comments
Closed

Compile times suddenly extremly high #62567

fabianvdW opened this issue Jul 10, 2019 · 8 comments
Assignees
@nikic
Labels
A-LLVM Area: Code generation parts specific to LLVM. Both correctness bugs and optimization-related issues. C-bug Category: This is a bug. I-compiletime Issue: Problems and improvements with respect to compile times. T-compiler Relevant to the compiler team, which will review and decide on the PR/issue.

Comments

@fabianvdW
Copy link

fabianvdW commented Jul 10, 2019 •
edited
Loading

Since one of my latest changes to my project, the compile times have been extremly high (jumping to >1min from about 15secs).

I tried compiling the lib of this crate (it is to large to post here):
https://github.com/fabianvdW/ChessInRust
with cargo build--release --lib

Compiler output for release build:

   Compiling FabChess v0.1.0 (D:\SchachReworked)
warning: field is never used: `stm_pieces_without_king`
    --> src\move_generation\movegen.rs:1914:5
     |
1914 |     stm_pieces_without_king: u64,
     |     ^^^^^^^^^^^^^^^^^^^^^^^^^^^^
     |
     = note: #[warn(dead_code)] on by default

warning: field is never used: `all_pieces_without_stmking`
    --> src\move_generation\movegen.rs:1917:5
     |
1917 |     all_pieces_without_stmking: u64,
     |     ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^

warning: field is never used: `enemy_pawns_westattack`
    --> src\move_generation\movegen.rs:1922:5
     |
1922 |     enemy_pawns_westattack: u64,
     |     ^^^^^^^^^^^^^^^^^^^^^^^^^^^

warning: field is never used: `enemy_pawns_eastattack`
    --> src\move_generation\movegen.rs:1923:5
     |
1923 |     enemy_pawns_eastattack: u64,
     |     ^^^^^^^^^^^^^^^^^^^^^^^^^^^

warning: field is never used: `enemy_king_attacks`
    --> src\move_generation\movegen.rs:1926:5
     |
1926 |     enemy_king_attacks: u64,
     |     ^^^^^^^^^^^^^^^^^^^^^^^

    Finished release [optimized] target(s) in 1m 20s

Note that this is with lto=true

Time to investigate with -Ztime-passes in nightly:

   Compiling FabChess v0.1.0 (D:\SchachReworked)
  time: 0.033; rss: 25MB        parsing
  time: 0.000; rss: 26MB        attributes injection
  time: 0.000; rss: 26MB        recursion limit
  time: 0.000; rss: 26MB        crate injection
  time: 0.000; rss: 26MB        plugin loading
  time: 0.000; rss: 26MB        plugin registration
  time: 0.002; rss: 26MB        pre ast expansion lint checks
    time: 0.062; rss: 50MB      expand crate
    time: 0.000; rss: 50MB      check unused macros
  time: 0.062; rss: 50MB        expansion
  time: 0.000; rss: 50MB        maybe building test harness
  time: 0.001; rss: 50MB        AST validation
  time: 0.000; rss: 50MB        maybe creating a macro crate
  time: 0.021; rss: 55MB        name resolution
  time: 0.003; rss: 55MB        complete gated feature checking
  time: 0.016; rss: 63MB        lowering ast -> hir
  time: 0.004; rss: 63MB        early lint checks
    time: 0.004; rss: 66MB      validate hir map
  time: 0.024; rss: 66MB        indexing hir
  time: 0.000; rss: 66MB        load query result cache
  time: 0.000; rss: 66MB        dep graph tcx init
    time: 0.000; rss: 66MB      looking for entry point
    time: 0.000; rss: 67MB      looking for plugin registrar
    time: 0.000; rss: 67MB      looking for derive registrar
  time: 0.007; rss: 67MB        misc checking 1
  time: 0.008; rss: 69MB        type collecting
  time: 0.000; rss: 69MB        impl wf inference
    time: 0.000; rss: 82MB      unsafety checking
    time: 0.000; rss: 82MB      orphan checking
  time: 0.031; rss: 82MB        coherence checking
  time: 0.053; rss: 94MB        wf checking
  time: 0.012; rss: 95MB        item-types checking
  time: 0.442; rss: 113MB       item-bodies checking
    time: 0.035; rss: 114MB     rvalue promotion + match checking
    time: 0.012; rss: 114MB     liveness checking + intrinsic checking
  time: 0.047; rss: 114MB       misc checking 2
  time: 0.000; rss: 114MB       borrow checking
  time: 0.307; rss: 137MB       MIR borrow checking
  time: 0.000; rss: 137MB       dumping chalk-like clauses
  time: 0.000; rss: 137MB       MIR effect checking
  time: 0.000; rss: 137MB       layout testing
    time: 0.005; rss: 137MB     privacy access levels
    time: 0.002; rss: 137MB     private in public
warning: field is never used: `stm_pieces_without_king`
    --> src\move_generation\movegen.rs:1914:5
     |
1914 |     stm_pieces_without_king: u64,
     |     ^^^^^^^^^^^^^^^^^^^^^^^^^^^^
     |
     = note: #[warn(dead_code)] on by default

warning: field is never used: `all_pieces_without_stmking`
    --> src\move_generation\movegen.rs:1917:5
     |
1917 |     all_pieces_without_stmking: u64,
     |     ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^

warning: field is never used: `enemy_pawns_westattack`
    --> src\move_generation\movegen.rs:1922:5
     |
1922 |     enemy_pawns_westattack: u64,
     |     ^^^^^^^^^^^^^^^^^^^^^^^^^^^

warning: field is never used: `enemy_pawns_eastattack`
    --> src\move_generation\movegen.rs:1923:5
     |
1923 |     enemy_pawns_eastattack: u64,
     |     ^^^^^^^^^^^^^^^^^^^^^^^^^^^

warning: field is never used: `enemy_king_attacks`
    --> src\move_generation\movegen.rs:1926:5
     |
1926 |     enemy_king_attacks: u64,
     |     ^^^^^^^^^^^^^^^^^^^^^^^

    time: 0.019; rss: 137MB     death checking
    time: 0.001; rss: 137MB     unused lib feature checking
      time: 0.013; rss: 138MB   crate lints
      time: 0.006; rss: 138MB   module lints
    time: 0.019; rss: 138MB     lint checking
    time: 0.010; rss: 138MB     privacy checking modules
  time: 0.057; rss: 138MB       misc checking 3
  time: 0.000; rss: 138MB       resolving dependency formats
  time: 0.034; rss: 140MB       metadata encoding and writing
      time: 0.001; rss: 140MB   collecting roots
      time: 0.156; rss: 149MB   collecting mono items
    time: 0.157; rss: 149MB     monomorphization collection
    time: 0.004; rss: 151MB     codegen unit partitioning
    time: 0.014; rss: 159MB     llvm function passes [core.bvutizoj-cgu.0]
    time: 0.019; rss: 168MB     llvm function passes [core.bvutizoj-cgu.13]
    time: 0.014; rss: 172MB     llvm function passes [core.bvutizoj-cgu.7]
    time: 0.013; rss: 179MB     llvm function passes [core.bvutizoj-cgu.8]
    time: 0.304; rss: 184MB     llvm module passes [core.bvutizoj-cgu.13]
    time: 0.213; rss: 184MB     llvm module passes [core.bvutizoj-cgu.8]
    time: 0.011; rss: 184MB     llvm function passes [core.bvutizoj-cgu.15]
    time: 0.335; rss: 185MB     llvm module passes [core.bvutizoj-cgu.7]
    time: 0.011; rss: 186MB     llvm function passes [core.bvutizoj-cgu.1]
    time: 0.012; rss: 186MB     llvm function passes [core.bvutizoj-cgu.4]
    time: 0.229; rss: 187MB     llvm module passes [core.bvutizoj-cgu.15]
    time: 0.200; rss: 187MB     llvm module passes [core.bvutizoj-cgu.1]
    time: 0.012; rss: 185MB     llvm function passes [core.bvutizoj-cgu.3]
    time: 0.218; rss: 186MB     llvm module passes [core.bvutizoj-cgu.4]
    time: 0.010; rss: 186MB     llvm function passes [core.bvutizoj-cgu.11]
    time: 0.698; rss: 186MB     llvm module passes [core.bvutizoj-cgu.0]
    time: 0.008; rss: 186MB     llvm function passes [core.bvutizoj-cgu.5]
    time: 0.008; rss: 183MB     llvm function passes [core.bvutizoj-cgu.14]
    time: 0.133; rss: 183MB     llvm module passes [core.bvutizoj-cgu.3]
    time: 0.006; rss: 184MB     llvm function passes [core.bvutizoj-cgu.6]
    time: 0.096; rss: 184MB     llvm module passes [core.bvutizoj-cgu.5]
    time: 0.006; rss: 184MB     llvm function passes [core.bvutizoj-cgu.9]
    time: 0.228; rss: 184MB     llvm module passes [core.bvutizoj-cgu.11]
    time: 0.005; rss: 185MB     llvm function passes [core.bvutizoj-cgu.2]
    time: 0.122; rss: 185MB     llvm module passes [core.bvutizoj-cgu.9]
    time: 0.308; rss: 185MB     codegen to LLVM IR
    time: 0.000; rss: 185MB     assert dep graph
    time: 0.000; rss: 185MB     serialize dep graph
  time: 1.168; rss: 185MB       codegen
    time: 0.004; rss: 180MB     llvm function passes [core.bvutizoj-cgu.10]
    time: 0.160; rss: 154MB     llvm module passes [core.bvutizoj-cgu.6]
    time: 0.003; rss: 127MB     llvm function passes [core.bvutizoj-cgu.12]
    time: 0.049; rss: 127MB     llvm module passes [core.bvutizoj-cgu.10]
    time: 0.098; rss: 119MB     llvm module passes [core.bvutizoj-cgu.2]
    time: 0.054; rss: 120MB     llvm module passes [core.bvutizoj-cgu.12]
    time: 0.269; rss: 117MB     llvm module passes [core.bvutizoj-cgu.14]
    time: 0.185; rss: 126MB     LTO passes
    time: 0.194; rss: 126MB     LTO passes
    time: 0.330; rss: 137MB     LTO passes
    time: 0.171; rss: 138MB     codegen passes [core.bvutizoj-cgu.8]
    time: 0.190; rss: 138MB     codegen passes [core.bvutizoj-cgu.13]
    time: 0.296; rss: 181MB     codegen passes [core.bvutizoj-cgu.15]
    time: 0.281; rss: 193MB     LTO passes
    time: 0.337; rss: 194MB     LTO passes
    time: 0.202; rss: 200MB     LTO passes
    time: 0.186; rss: 203MB     codegen passes [core.bvutizoj-cgu.4]
    time: 0.136; rss: 201MB     codegen passes [core.bvutizoj-cgu.7]
    time: 0.281; rss: 201MB     codegen passes [core.bvutizoj-cgu.1]
    time: 0.208; rss: 204MB     LTO passes
    time: 0.137; rss: 208MB     LTO passes
    time: 0.123; rss: 221MB     codegen passes [core.bvutizoj-cgu.5]
    time: 0.227; rss: 236MB     codegen passes [core.bvutizoj-cgu.6]
    time: 0.158; rss: 236MB     LTO passes
    time: 0.278; rss: 236MB     LTO passes
    time: 0.100; rss: 236MB     codegen passes [core.bvutizoj-cgu.2]
    time: 0.194; rss: 236MB     codegen passes [core.bvutizoj-cgu.11]
    time: 0.242; rss: 241MB     LTO passes
    time: 0.101; rss: 237MB     LTO passes
    time: 0.943; rss: 237MB     LTO passes
    time: 0.089; rss: 236MB     codegen passes [core.bvutizoj-cgu.10]
    time: 0.080; rss: 236MB     LTO passes
    time: 0.236; rss: 236MB     codegen passes [core.bvutizoj-cgu.9]
    time: 0.079; rss: 238MB     codegen passes [core.bvutizoj-cgu.12]
    time: 0.028; rss: 238MB     LTO passes
    time: 0.033; rss: 238MB     codegen passes [core.bvutizoj-cgu.3]
    time: 1.945; rss: 232MB     codegen passes [core.bvutizoj-cgu.14]
    time: 67.772; rss: 210MB    LTO passes
    time: 10.011; rss: 203MB    codegen passes [core.bvutizoj-cgu.0]
  time: 79.051; rss: 119MB      LLVM passes
  time: 0.000; rss: 116MB       serialize work products
  time: 0.047; rss: 117MB       linking
time: 80.495; rss: 67MB         total
    Finished release [optimized] target(s) in 1m 20s

This, to me, suggests turning LTO off.
With LTO off:

   Compiling FabChess v0.1.0 (D:\SchachReworked)
  time: 0.029; rss: 25MB        parsing
  time: 0.000; rss: 26MB        attributes injection
  time: 0.000; rss: 26MB        recursion limit
  time: 0.000; rss: 26MB        crate injection
  time: 0.000; rss: 26MB        plugin loading
  time: 0.000; rss: 26MB        plugin registration
  time: 0.002; rss: 26MB        pre ast expansion lint checks
    time: 0.065; rss: 50MB      expand crate
    time: 0.000; rss: 50MB      check unused macros
  time: 0.066; rss: 50MB        expansion
  time: 0.000; rss: 50MB        maybe building test harness
  time: 0.001; rss: 50MB        AST validation
  time: 0.000; rss: 50MB        maybe creating a macro crate
  time: 0.022; rss: 55MB        name resolution
  time: 0.003; rss: 55MB        complete gated feature checking
  time: 0.017; rss: 63MB        lowering ast -> hir
  time: 0.004; rss: 63MB        early lint checks
    time: 0.003; rss: 66MB      validate hir map
  time: 0.021; rss: 66MB        indexing hir
  time: 0.000; rss: 66MB        load query result cache
  time: 0.000; rss: 66MB        dep graph tcx init
    time: 0.000; rss: 66MB      looking for entry point
    time: 0.000; rss: 66MB      looking for plugin registrar
    time: 0.000; rss: 66MB      looking for derive registrar
  time: 0.006; rss: 67MB        misc checking 1
  time: 0.010; rss: 69MB        type collecting
  time: 0.001; rss: 69MB        impl wf inference
    time: 0.000; rss: 82MB      unsafety checking
    time: 0.000; rss: 82MB      orphan checking
  time: 0.034; rss: 82MB        coherence checking
  time: 0.053; rss: 94MB        wf checking
  time: 0.012; rss: 95MB        item-types checking
  time: 0.436; rss: 113MB       item-bodies checking
    time: 0.038; rss: 114MB     rvalue promotion + match checking
    time: 0.012; rss: 114MB     liveness checking + intrinsic checking
  time: 0.050; rss: 114MB       misc checking 2
  time: 0.000; rss: 114MB       borrow checking
  time: 0.308; rss: 136MB       MIR borrow checking
  time: 0.000; rss: 136MB       dumping chalk-like clauses
  time: 0.000; rss: 136MB       MIR effect checking
  time: 0.000; rss: 136MB       layout testing
    time: 0.005; rss: 137MB     privacy access levels
    time: 0.002; rss: 137MB     private in public
warning: field is never used: `stm_pieces_without_king`
    --> src\move_generation\movegen.rs:1914:5
     |
1914 |     stm_pieces_without_king: u64,
     |     ^^^^^^^^^^^^^^^^^^^^^^^^^^^^
     |
     = note: #[warn(dead_code)] on by default

warning: field is never used: `all_pieces_without_stmking`
    --> src\move_generation\movegen.rs:1917:5
     |
1917 |     all_pieces_without_stmking: u64,
     |     ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^

warning: field is never used: `enemy_pawns_westattack`
    --> src\move_generation\movegen.rs:1922:5
     |
1922 |     enemy_pawns_westattack: u64,
     |     ^^^^^^^^^^^^^^^^^^^^^^^^^^^

warning: field is never used: `enemy_pawns_eastattack`
    --> src\move_generation\movegen.rs:1923:5
     |
1923 |     enemy_pawns_eastattack: u64,
     |     ^^^^^^^^^^^^^^^^^^^^^^^^^^^

warning: field is never used: `enemy_king_attacks`
    --> src\move_generation\movegen.rs:1926:5
     |
1926 |     enemy_king_attacks: u64,
     |     ^^^^^^^^^^^^^^^^^^^^^^^

    time: 0.018; rss: 137MB     death checking
    time: 0.001; rss: 137MB     unused lib feature checking
      time: 0.012; rss: 138MB   crate lints
      time: 0.006; rss: 138MB   module lints
    time: 0.018; rss: 138MB     lint checking
    time: 0.010; rss: 138MB     privacy checking modules
  time: 0.055; rss: 138MB       misc checking 3
  time: 0.000; rss: 138MB       resolving dependency formats
  time: 0.036; rss: 139MB       metadata encoding and writing
      time: 0.001; rss: 140MB   collecting roots
      time: 0.161; rss: 149MB   collecting mono items
    time: 0.163; rss: 149MB     monomorphization collection
    time: 0.004; rss: 151MB     codegen unit partitioning
    time: 0.013; rss: 159MB     llvm function passes [core.420y0oqy-cgu.0]
    time: 0.019; rss: 168MB     llvm function passes [core.420y0oqy-cgu.13]
    time: 0.014; rss: 173MB     llvm function passes [core.420y0oqy-cgu.7]
    time: 0.013; rss: 179MB     llvm function passes [core.420y0oqy-cgu.8]
    time: 0.290; rss: 184MB     llvm module passes [core.420y0oqy-cgu.13]
    time: 0.205; rss: 184MB     llvm module passes [core.420y0oqy-cgu.8]
    time: 0.011; rss: 185MB     llvm function passes [core.420y0oqy-cgu.15]
    time: 0.012; rss: 185MB     llvm function passes [core.420y0oqy-cgu.4]
    time: 0.338; rss: 185MB     llvm module passes [core.420y0oqy-cgu.7]
    time: 0.011; rss: 185MB     llvm function passes [core.420y0oqy-cgu.1]
    time: 0.225; rss: 186MB     llvm module passes [core.420y0oqy-cgu.15]
    time: 0.217; rss: 186MB     llvm module passes [core.420y0oqy-cgu.4]
    time: 0.012; rss: 186MB     llvm function passes [core.420y0oqy-cgu.3]
    time: 0.201; rss: 186MB     llvm module passes [core.420y0oqy-cgu.1]
    time: 0.010; rss: 186MB     llvm function passes [core.420y0oqy-cgu.11]
    time: 0.689; rss: 186MB     llvm module passes [core.420y0oqy-cgu.0]
    time: 0.007; rss: 184MB     llvm function passes [core.420y0oqy-cgu.5]
    time: 0.008; rss: 182MB     llvm function passes [core.420y0oqy-cgu.14]
    time: 0.129; rss: 182MB     llvm module passes [core.420y0oqy-cgu.3]
    time: 0.092; rss: 182MB     llvm module passes [core.420y0oqy-cgu.5]
    time: 0.006; rss: 183MB     llvm function passes [core.420y0oqy-cgu.6]
    time: 0.006; rss: 183MB     llvm function passes [core.420y0oqy-cgu.9]
    time: 0.218; rss: 184MB     llvm module passes [core.420y0oqy-cgu.11]
    time: 0.004; rss: 184MB     llvm function passes [core.420y0oqy-cgu.2]
    time: 0.137; rss: 184MB     llvm module passes [core.420y0oqy-cgu.9]
    time: 0.299; rss: 184MB     codegen to LLVM IR
    time: 0.000; rss: 184MB     assert dep graph
    time: 0.000; rss: 184MB     serialize dep graph
  time: 1.170; rss: 184MB       codegen
    time: 0.004; rss: 154MB     llvm function passes [core.420y0oqy-cgu.10]
    time: 0.075; rss: 124MB     llvm module passes [core.420y0oqy-cgu.2]
    time: 0.202; rss: 119MB     llvm module passes [core.420y0oqy-cgu.6]
    time: 0.004; rss: 119MB     llvm function passes [core.420y0oqy-cgu.12]
    time: 0.291; rss: 120MB     llvm module passes [core.420y0oqy-cgu.14]
    time: 0.054; rss: 120MB     llvm module passes [core.420y0oqy-cgu.10]
    time: 0.054; rss: 113MB     llvm module passes [core.420y0oqy-cgu.12]
    time: 0.190; rss: 125MB     LTO passes
    time: 0.194; rss: 125MB     LTO passes
    time: 0.330; rss: 136MB     LTO passes
    time: 0.169; rss: 137MB     codegen passes [core.420y0oqy-cgu.8]
    time: 0.200; rss: 136MB     codegen passes [core.420y0oqy-cgu.13]
    time: 0.282; rss: 179MB     codegen passes [core.420y0oqy-cgu.15]
    time: 0.285; rss: 193MB     LTO passes
    time: 0.349; rss: 192MB     LTO passes
    time: 0.201; rss: 192MB     LTO passes
    time: 0.178; rss: 203MB     codegen passes [core.420y0oqy-cgu.4]
    time: 0.136; rss: 200MB     codegen passes [core.420y0oqy-cgu.7]
    time: 0.311; rss: 206MB     codegen passes [core.420y0oqy-cgu.1]
    time: 0.219; rss: 204MB     LTO passes
    time: 0.136; rss: 209MB     LTO passes
    time: 0.131; rss: 236MB     codegen passes [core.420y0oqy-cgu.5]
    time: 0.212; rss: 232MB     codegen passes [core.420y0oqy-cgu.6]
    time: 0.159; rss: 237MB     LTO passes
    time: 0.251; rss: 238MB     LTO passes
    time: 0.104; rss: 238MB     codegen passes [core.420y0oqy-cgu.2]
    time: 0.189; rss: 235MB     codegen passes [core.420y0oqy-cgu.11]
    time: 0.264; rss: 235MB     LTO passes
    time: 0.104; rss: 235MB     LTO passes
    time: 0.921; rss: 235MB     LTO passes
    time: 0.086; rss: 234MB     codegen passes [core.420y0oqy-cgu.10]
    time: 0.079; rss: 235MB     LTO passes
    time: 0.220; rss: 235MB     codegen passes [core.420y0oqy-cgu.9]
    time: 0.091; rss: 237MB     codegen passes [core.420y0oqy-cgu.12]
    time: 0.031; rss: 237MB     LTO passes
    time: 0.034; rss: 237MB     codegen passes [core.420y0oqy-cgu.3]
    time: 1.912; rss: 231MB     codegen passes [core.420y0oqy-cgu.14]
    time: 69.354; rss: 210MB    LTO passes
    time: 11.056; rss: 200MB    codegen passes [core.420y0oqy-cgu.0]
  time: 81.705; rss: 119MB      LLVM passes
  time: 0.000; rss: 117MB       serialize work products
  time: 0.046; rss: 117MB       linking
time: 83.154; rss: 67MB         total
    Finished release [optimized] target(s) in 1m 23s

This all started happening after this commit where I made some minor changes.
Before this commit, even with lto=true, it looks like this(and is blazingly fast):

   Compiling FabChess v0.1.0 (D:\SchachTest)
  time: 0.028; rss: 25MB        parsing
  time: 0.000; rss: 25MB        attributes injection
  time: 0.000; rss: 25MB        recursion limit
  time: 0.000; rss: 25MB        crate injection
  time: 0.000; rss: 25MB        plugin loading
  time: 0.000; rss: 25MB        plugin registration
  time: 0.002; rss: 25MB        pre ast expansion lint checks
    time: 0.058; rss: 50MB      expand crate
    time: 0.000; rss: 50MB      check unused macros
  time: 0.059; rss: 50MB        expansion
  time: 0.000; rss: 50MB        maybe building test harness
  time: 0.001; rss: 50MB        AST validation
  time: 0.000; rss: 50MB        maybe creating a macro crate
  time: 0.021; rss: 55MB        name resolution
  time: 0.003; rss: 55MB        complete gated feature checking
  time: 0.017; rss: 63MB        lowering ast -> hir
  time: 0.004; rss: 63MB        early lint checks
    time: 0.003; rss: 66MB      validate hir map
  time: 0.021; rss: 66MB        indexing hir
  time: 0.000; rss: 66MB        load query result cache
  time: 0.000; rss: 66MB        dep graph tcx init
    time: 0.000; rss: 66MB      looking for entry point
    time: 0.000; rss: 66MB      looking for plugin registrar
    time: 0.000; rss: 66MB      looking for derive registrar
  time: 0.005; rss: 67MB        misc checking 1
  time: 0.009; rss: 69MB        type collecting
  time: 0.000; rss: 69MB        impl wf inference
    time: 0.000; rss: 82MB      unsafety checking
    time: 0.000; rss: 82MB      orphan checking
  time: 0.032; rss: 82MB        coherence checking
  time: 0.052; rss: 93MB        wf checking
  time: 0.013; rss: 95MB        item-types checking
  time: 0.478; rss: 112MB       item-bodies checking
    time: 0.039; rss: 113MB     rvalue promotion + match checking
    time: 0.012; rss: 113MB     liveness checking + intrinsic checking
  time: 0.052; rss: 113MB       misc checking 2
  time: 0.000; rss: 113MB       borrow checking
  time: 0.342; rss: 136MB       MIR borrow checking
  time: 0.000; rss: 136MB       dumping chalk-like clauses
  time: 0.000; rss: 136MB       MIR effect checking
  time: 0.000; rss: 136MB       layout testing
    time: 0.006; rss: 136MB     privacy access levels
    time: 0.003; rss: 137MB     private in public
warning: field is never used: `stm_pieces_without_king`
    --> src\move_generation\movegen.rs:1913:5
     |
1913 |     stm_pieces_without_king: u64,
     |     ^^^^^^^^^^^^^^^^^^^^^^^^^^^^
     |
     = note: #[warn(dead_code)] on by default

warning: field is never used: `all_pieces_without_stmking`
    --> src\move_generation\movegen.rs:1916:5
     |
1916 |     all_pieces_without_stmking: u64,
     |     ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^

warning: field is never used: `enemy_pawns_westattack`
    --> src\move_generation\movegen.rs:1921:5
     |
1921 |     enemy_pawns_westattack: u64,
     |     ^^^^^^^^^^^^^^^^^^^^^^^^^^^

warning: field is never used: `enemy_pawns_eastattack`
    --> src\move_generation\movegen.rs:1922:5
     |
1922 |     enemy_pawns_eastattack: u64,
     |     ^^^^^^^^^^^^^^^^^^^^^^^^^^^

warning: field is never used: `enemy_king_attacks`
    --> src\move_generation\movegen.rs:1925:5
     |
1925 |     enemy_king_attacks: u64,
     |     ^^^^^^^^^^^^^^^^^^^^^^^

warning: field is never used: `stm_incheck`
    --> src\move_generation\movegen.rs:2097:5
     |
2097 |     stm_incheck: bool,
     |     ^^^^^^^^^^^^^^^^^

warning: field is never used: `stm_haslegalmove`
    --> src\move_generation\movegen.rs:2098:5
     |
2098 |     stm_haslegalmove: bool,
     |     ^^^^^^^^^^^^^^^^^^^^^^

warning: field is never used: `additional_bitboards`
    --> src\move_generation\movegen.rs:2099:5
     |
2099 |     additional_bitboards: AdditionalBitBoards,
     |     ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^

    time: 0.027; rss: 137MB     death checking
    time: 0.001; rss: 137MB     unused lib feature checking
      time: 0.015; rss: 137MB   crate lints
      time: 0.007; rss: 138MB   module lints
    time: 0.022; rss: 138MB     lint checking
    time: 0.011; rss: 138MB     privacy checking modules
  time: 0.071; rss: 138MB       misc checking 3
  time: 0.000; rss: 138MB       resolving dependency formats
  time: 0.034; rss: 139MB       metadata encoding and writing
      time: 0.001; rss: 139MB   collecting roots
      time: 0.157; rss: 149MB   collecting mono items
    time: 0.158; rss: 149MB     monomorphization collection
    time: 0.004; rss: 150MB     codegen unit partitioning
    time: 0.014; rss: 159MB     llvm function passes [core.bvutizoj-cgu.0]
    time: 0.020; rss: 167MB     llvm function passes [core.bvutizoj-cgu.13]
    time: 0.016; rss: 171MB     llvm function passes [core.bvutizoj-cgu.4]
    time: 0.012; rss: 177MB     llvm function passes [core.bvutizoj-cgu.15]
    time: 0.402; rss: 183MB     llvm module passes [core.bvutizoj-cgu.0]
    time: 0.350; rss: 183MB     llvm module passes [core.bvutizoj-cgu.13]
    time: 0.258; rss: 181MB     llvm module passes [core.bvutizoj-cgu.15]
    time: 0.012; rss: 181MB     llvm function passes [core.bvutizoj-cgu.1]
    time: 0.014; rss: 183MB     llvm function passes [core.bvutizoj-cgu.3]
    time: 0.378; rss: 183MB     llvm module passes [core.bvutizoj-cgu.4]
    time: 0.013; rss: 183MB     llvm function passes [core.bvutizoj-cgu.8]
    time: 0.013; rss: 184MB     llvm function passes [core.bvutizoj-cgu.5]
    time: 0.145; rss: 184MB     llvm module passes [core.bvutizoj-cgu.3]
    time: 0.010; rss: 184MB     llvm function passes [core.bvutizoj-cgu.11]
    time: 0.206; rss: 184MB     llvm module passes [core.bvutizoj-cgu.1]
    time: 0.007; rss: 184MB     llvm function passes [core.bvutizoj-cgu.7]
    time: 0.214; rss: 184MB     llvm module passes [core.bvutizoj-cgu.8]
    time: 0.008; rss: 184MB     llvm function passes [core.bvutizoj-cgu.14]
    time: 0.231; rss: 184MB     llvm module passes [core.bvutizoj-cgu.5]
    time: 0.085; rss: 185MB     llvm module passes [core.bvutizoj-cgu.7]
    time: 0.006; rss: 185MB     llvm function passes [core.bvutizoj-cgu.6]
    time: 0.006; rss: 185MB     llvm function passes [core.bvutizoj-cgu.9]
    time: 0.230; rss: 185MB     llvm module passes [core.bvutizoj-cgu.11]
    time: 0.005; rss: 182MB     llvm function passes [core.bvutizoj-cgu.2]
    time: 0.128; rss: 182MB     llvm module passes [core.bvutizoj-cgu.9]
    time: 0.343; rss: 183MB     codegen to LLVM IR
    time: 0.000; rss: 183MB     assert dep graph
    time: 0.000; rss: 183MB     serialize dep graph
  time: 1.147; rss: 183MB       codegen
    time: 0.003; rss: 178MB     llvm function passes [core.bvutizoj-cgu.10]
    time: 0.166; rss: 170MB     llvm module passes [core.bvutizoj-cgu.6]
    time: 0.003; rss: 124MB     llvm function passes [core.bvutizoj-cgu.12]
    time: 0.094; rss: 124MB     llvm module passes [core.bvutizoj-cgu.2]
    time: 0.052; rss: 120MB     llvm module passes [core.bvutizoj-cgu.10]
    time: 0.055; rss: 121MB     llvm module passes [core.bvutizoj-cgu.12]
    time: 0.287; rss: 118MB     llvm module passes [core.bvutizoj-cgu.14]
    time: 0.184; rss: 125MB     LTO passes
    time: 0.195; rss: 127MB     LTO passes
    time: 0.337; rss: 134MB     LTO passes
    time: 0.354; rss: 135MB     LTO passes
    time: 0.163; rss: 135MB     codegen passes [core.bvutizoj-cgu.8]
    time: 0.180; rss: 134MB     codegen passes [core.bvutizoj-cgu.13]
    time: 0.274; rss: 146MB     codegen passes [core.bvutizoj-cgu.1]
    time: 0.273; rss: 142MB     codegen passes [core.bvutizoj-cgu.15]
    time: 0.286; rss: 139MB     LTO passes
    time: 0.202; rss: 142MB     LTO passes
    time: 0.220; rss: 142MB     LTO passes
    time: 0.172; rss: 143MB     codegen passes [core.bvutizoj-cgu.5]
    time: 0.118; rss: 140MB     LTO passes
    time: 0.147; rss: 140MB     codegen passes [core.bvutizoj-cgu.4]
    time: 0.201; rss: 141MB     codegen passes [core.bvutizoj-cgu.6]
    time: 0.713; rss: 141MB     LTO passes
    time: 0.105; rss: 146MB     codegen passes [core.bvutizoj-cgu.7]
    time: 0.160; rss: 152MB     LTO passes
    time: 0.286; rss: 153MB     LTO passes
    time: 0.099; rss: 153MB     codegen passes [core.bvutizoj-cgu.2]
    time: 0.188; rss: 166MB     codegen passes [core.bvutizoj-cgu.11]
    time: 0.100; rss: 162MB     LTO passes
    time: 0.306; rss: 162MB     LTO passes
    time: 0.085; rss: 154MB     codegen passes [core.bvutizoj-cgu.10]
    time: 0.727; rss: 150MB     codegen passes [core.bvutizoj-cgu.0]
    time: 0.082; rss: 151MB     LTO passes
    time: 0.030; rss: 151MB     LTO passes
    time: 0.033; rss: 152MB     codegen passes [core.bvutizoj-cgu.3]
    time: 0.906; rss: 152MB     LTO passes
    time: 0.075; rss: 144MB     codegen passes [core.bvutizoj-cgu.12]
    time: 0.218; rss: 139MB     codegen passes [core.bvutizoj-cgu.9]
    time: 1.798; rss: 136MB     codegen passes [core.bvutizoj-cgu.14]
  time: 4.836; rss: 117MB       LLVM passes
  time: 0.000; rss: 115MB       serialize work products
  time: 0.024; rss: 115MB       linking
time: 6.335; rss: 64MB          total
    Finished release [optimized] target(s) in 6.60s

My stable version:
rustc --version --verbose:

rustc 1.36.0 (a53f9df32 2019-07-03)
binary: rustc
commit-hash: a53f9df32fbb0b5f4382caaad8f1a46f36ea887c
commit-date: 2019-07-03
host: x86_64-pc-windows-gnu
release: 1.36.0
LLVM version: 8.0

My nightly version:
rustc --version --verbose:

rustc 1.38.0-nightly (0b680cfce 2019-07-09)
binary: rustc
commit-hash: 0b680cfce544ff9a59d720020e397c4bf3346650
commit-date: 2019-07-09
host: x86_64-pc-windows-gnu
release: 1.38.0-nightly
LLVM version: 8.0
@jonas-schievink jonas-schievink added A-LLVM Area: Code generation parts specific to LLVM. Both correctness bugs and optimization-related issues. C-bug Category: This is a bug. I-compiletime Issue: Problems and improvements with respect to compile times. T-compiler Relevant to the compiler team, which will review and decide on the PR/issue. labels Jul 10, 2019
@cramertj
Copy link
Member

Since one of my latest changes to my project, the compile times have been extremly high

What was the change that caused the increase?

@fabianvdW
Copy link
Author

fabianvdW commented Jul 10, 2019 •
edited
Loading

Since one of my latest changes to my project, the compile times have been extremly high

What was the change that caused the increase?

I don't know. I can't pinpoint what exactly causes the compile time spikes, but it definitely was this commit.

There is nothing really happening, just a new Struct and some some changes to old structs and arguments of functions. I am a newbie, so I don't know what could potentially be dangerous, but the one thing I would say is that I am allocating a lot of memory on the stack and in this commit this will also increase by 150KB

@nikic
Copy link
Contributor

nikic commented Jul 10, 2019

Perf shows 50% spent in DSE with 25% in PointerMayBeCaptured. Sounds like https://bugs.llvm.org/show_bug.cgi?id=37588. There's a few sources of quadratic behavior in DSE that don't seems to have any simple solution. In the meantime, try to avoid doing a huge amount of stack allocations...

@nikic
Copy link
Contributor

nikic commented Jul 10, 2019

Good news! Your case is fixed in LLVM 9, likely by https://reviews.llvm.org/rL357257. So this issue will resolve itself when the LLVM 9 update lands.

@nikic nikic self-assigned this Jul 10, 2019
@fabianvdW
Copy link
Author

Perf shows 50% spent in DSE with 25% in PointerMayBeCaptured. Sounds like https://bugs.llvm.org/show_bug.cgi?id=37588. There's a few sources of quadratic behavior in DSE that don't seems to have any simple solution. In the meantime, try to avoid doing a huge amount of stack allocations...

Dropping the stack allocations would be a major performance drop :/

@fabianvdW
Copy link
Author

Good news! Your case is fixed in LLVM 9, likely by https://reviews.llvm.org/rL357257. So this issue will resolve itself when the LLVM 9 update lands.

Great! :D When will it land? Is it in the next offical release? :D

@mati865
Copy link
Contributor

mati865 commented Jul 18, 2019

It's in the nightly: #62592
If nothing goes wrong it will be available in release 1.38.0.

@nikic
Copy link
Contributor

nikic commented Jul 18, 2019

Verified that the build is fast with the current nightly, so closing this issue.

@nikic nikic closed this as completed Jul 18, 2019
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@nikic nikic

Labels
A-LLVM Area: Code generation parts specific to LLVM. Both correctness bugs and optimization-related issues. C-bug Category: This is a bug. I-compiletime Issue: Problems and improvements with respect to compile times. T-compiler Relevant to the compiler team, which will review and decide on the PR/issue.
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
5 participants
@nikic @mati865 @jonas-schievink @cramertj @fabianvdW