# parallel compiler investigation

* sharding hash problems
* hashes are not re-scrambled after sharding
* for a single shard, the 8th-13th bits are always the same
* https://github.com/rust-lang/rust/blob/412f43ac5b4ae8c3599e71c6972112e9be4758fa/src/librustc_data_structures/sharded.rs#L81-L82
* note: we generally likely want to check that our hash is well-distributed in these bits
* Google stores the AND and OR of all hashes for every hashmap (should be all zeroes and all ones)
* Maybe we can get something more fine-grained?

* sharding via hash
* we currently shard by Fx hash for all types
* maybe we can do better?

* too few shards
* 32 shards for all systems may be too few
* increasing shard count seems to do nothing in practice to syscall counts

## too many futex calls

* libstd's Mutex/RwLock/etc all immediately go to futex
* this is a bad default?
* long-term solution is presumably parking_lot in std
* it looks like this is not short-term viable
* may need to try and remove all use of std::sync::* from rustc hot paths?
* rustc_data_structures::sync already uses parking lot
* unclear what the story is more generally

## Investigating system call time (read/write mostly):

export RUSTFLAGS="-Zthreads=28"
sudo rm -rf target
sudo --preserve-env=RUSTFLAGS perf trace --summary -o /tmp/tl-perf timeout 3s ~/.cargo/bin/cargo check -j28

then use https://gist.github.com/Mark-Simulacrum/28d53e4b1ea1d269c32d5b9f6446712d (Alex's tool originally) via `rustc foo.rs && ./foo < /tmp/tl-perf | head -n15`

This gives something like:

   syscall              calls       total       min       avg       max   calls/process
                                    (msec)    (msec)    (msec)    (msec)
   ----------------- -------- ------------ --------- --------- ---------  -------------

   futex                52284  1380466.030     0.000    26.403  2691.245       23
   read                 10558   590776.037     0.000    55.955  1396.433        4
   poll                  7122   419146.809     0.000    58.852  2237.989        3
   munmap                5063     6635.142     0.000     1.311   923.818        2
   clone                 4039     5312.432     0.000     1.315    97.420        1
   sched_yield           8728     4444.073     0.000     0.509   472.982        3
   mmap                 14657     1769.610     0.000     0.121    57.337        6
   write                 8543     1611.345     0.000     0.189    79.488        3
   madvise               1849     1075.505     0.000     0.582   856.632        0
   execve                 136      635.643     0.000     4.674    44.610        0

Concern: lots of time is being spent in `futex`, why? Also, read/poll are spending tons of time in the kernel as well.

Attempted to gather backtraces via `strace -k` -- this failed, we only seem to get ~300 sycalls vs. ~50,000 reported here.

sanity check: does raw strace (without -k) work? yes, `rg '^\d+\s*futex|... futex resumed' /tmp/tl | rg ' = ' | wc -l` reports ~92k syscalls

perf stacktraces also don't really work

trying a different track:

`RUSTFLAGS="-Zthreads=28" perf record -o ~/perf.data timeout 3s ~/.cargo/bin/cargo check -j28`

top data:

* 22.67% in kernel osq_lock
* 5.82% in kernel native_queued_spin_lock_slowpath

Looking around, it seems like there's a kernel patch for osq_lock (https://lore.kernel.org/patchwork/patch/693134/) being high overhead on overcommitted systems... but it seems to be applied in my kernel.

Using `--call-graph fp`, and then `perf report --no-children` (flips the report to "deepest" at the top).

Looks like ~all osq_lock time is coming from __mutex_lock.isra.10, 20% in pipe_wait and 1.3% in pipe_read.

However, even on just t16/j16 (with vCPU=16 Ryzen 1800X), osq_lock is still 8.8% of overall runtime -- so we're still suffering from contention(?) on pipe_wait

Assumption: this is because jobserver is doing a blocking read on the jobserver pipe which is super contentious if there's `28*28` jobserver looking for a token or writing one.

However, though this is bad it's probably *not* the cause of the thousands of `futex` calls since this locking is entirely inside the kernel and so presumably has nothing to do with futexes.

The jobserver pipe has ~300 read/writes in the 3 seconds, with ~3000 "resumed/unfinished" -- I suspect this means that there's definitely some wins to be had.

Switching out the jobserver crate to use POSIX semaphores instead of the current single byte read/writes:

t28/j28:
   syscall              calls       total       min       avg       max   calls/process
                                    (msec)    (msec)    (msec)    (msec)
   ----------------- -------- ------------ --------- --------- ---------  -------------

   futex                96764  2262843.296     0.000    23.385  2742.920       38
   munmap                6404    14310.071     0.000     2.235  1737.589        2
   madvise               1762     9684.683     0.002     5.496  1069.628        0
   mprotect            157967     6600.101     0.000     0.042   218.601       63
   clone                 4422     3922.891     0.000     0.887    34.297        1
   sched_yield          13068     3540.515     0.000     0.271    39.076        5
   mmap                 11705     2310.119     0.000     0.197    57.416        4
   poll                    11     2306.150     0.000   209.650   326.581        0
   read                  2805      221.704     0.001     0.079    24.106        1
t16/j16:
   syscall              calls       total       min       avg       max   calls/process
                                    (msec)    (msec)    (msec)    (msec)
   ----------------- -------- ------------ --------- --------- ---------  -------------

   futex                85558  1330165.646     0.000    15.547  2801.232       50
   mprotect            159986     8678.207     0.000     0.054   467.317       94
   munmap                4999     7620.045     0.000     1.524   925.214        2
   sched_yield          14404     5692.012     0.000     0.395   281.245        8
   poll                    12     3256.046   205.361   271.337   379.118        0
   madvise               1421     2310.527     0.002     1.626   235.965        0
   clone                 3039     1559.719     0.000     0.513    39.333        1
   mmap                 10095     1215.618     0.000     0.120    49.596        5
   wait4                   14      597.434     0.017    42.674   337.327        0
   read                  3025      505.254     0.000     0.167   231.282        1
   execve                  81      197.252     0.000     2.435    15.086        0

timing:
real 0m3.006s
user 0m28.961s
sys 0m3.792s

vs.

real 0m3.018s
user 0m7.113s
sys 0m8.675s

ideas:
* limit threads reading from jobserver
* jobserver w/o poll (blocking descriptor)
* stop spawning threads if you don't have a token
* use rayon async thread spawning?
* wait to spawn until you have a token
* completely separate jobserver

todo:
* try build with semaphore jobserver
* get -j1 numbers, confirm parallelism
* stop spawning threads if you don't have a token
* cargo/rustc tokens -- communicate to cargo to get token

----

## lock contention

 Performance counter stats for 'timeout 3s /home/mark/Build/cargo/realtarget/release/cargo check -j28':

            94,156      sdt_libpthread:lll_lock_wait
           486,738      syscalls:sys_enter_futex
             2,726      sdt_libpthread:pthread_create
           429,680      sdt_libpthread:mutex_acquired_1
            59,652      sdt_libpthread:mutex_acquired_3

       3.041111192 seconds time elapsed

      17.490127000 seconds user
       6.041626000 seconds sys
       
Samples: 33K of event 'sdt_libpthread:mutex_acquired_1', Event count (approx.): 33732
-   13.54%  (7fa9cd96c969) arg1=94542467499344                                              ◆
     __GI___pthread_mutex_lock (inlined)                                                    ▒
   + cargo::core::interning::InternedString::new                                            ▒
-    8.98%  (7f5f3f46e969) arg1=140047064658184                                             ▒
     __GI___pthread_mutex_lock (inlined)                                                    ▒             
   - std::env::var_os (inlined)                                                             ▒
      - 8.97% std::env::_var                                                                ▒
         - std::env::var (inlined)                                                          ▒
            + 8.83% <rustc::mir::interpret::error::InterpErrorInfo as core::convert::From<ru▒
-    5.65%  (7fa9cd96c969) arg1=94542438954896                                              ▒
   - std::sys::unix::os::env_lock (inlined)                                                 ▒
      - 5.44% std::sys::unix::os::getenv (inlined)                                          ▒
         - std::env::_var_os                                                                ▒
            - 4.52% std::env::var_os (inlined)                                              ▒
               - 4.52% std::env::_var                                                       ▒
                  - 2.36% cargo::util::profile::enabled_level                               ▒