storage benchmarking: read results not consistent when writes are benchmarked

[michalkucharczyk]

While working on #10215 I was benchmarking Polkadot Asset Hub database storage read/write to understand the impact of the work I've done in #10215 to the performance.

It seems that benchmarking of writes does not leave the database in consistent state. I noticed that benchmarks using both read and write operations lead to different read timings results than in case of only running read benchmark (--skip-write options).

Here are the results that I got.

This are the results of 10 consecutive executions of read only test for different batches size, results are pretty stable:

batch-size: 100k
weigths_pah_reads_only/00/weigths_pah___100k_read_01.rs:                read: 119_991 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_reads_only/00/weigths_pah___100k_read_02.rs:                read: 119_923 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_reads_only/00/weigths_pah___100k_read_03.rs:                read: 120_301 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_reads_only/00/weigths_pah___100k_read_04.rs:                read: 119_977 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_reads_only/00/weigths_pah___100k_read_05.rs:                read: 120_256 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_reads_only/00/weigths_pah___100k_read_06.rs:                read: 119_823 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_reads_only/00/weigths_pah___100k_read_07.rs:                read: 119_630 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_reads_only/00/weigths_pah___100k_read_08.rs:                read: 120_147 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_reads_only/00/weigths_pah___100k_read_09.rs:                read: 119_909 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_reads_only/00/weigths_pah___100k_read_10.rs:                read: 120_060 * constants::WEIGHT_REF_TIME_PER_NANOS,

batch-size: 10k
weigths_pah_reads_only/00/weigths_pah___10k_read_01.rs:                 read: 118_578 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_reads_only/00/weigths_pah___10k_read_02.rs:                 read: 118_319 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_reads_only/00/weigths_pah___10k_read_03.rs:                 read: 118_847 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_reads_only/00/weigths_pah___10k_read_04.rs:                 read: 119_084 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_reads_only/00/weigths_pah___10k_read_05.rs:                 read: 118_966 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_reads_only/00/weigths_pah___10k_read_06.rs:                 read: 118_750 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_reads_only/00/weigths_pah___10k_read_07.rs:                 read: 118_884 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_reads_only/00/weigths_pah___10k_read_08.rs:                 read: 118_812 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_reads_only/00/weigths_pah___10k_read_09.rs:                 read: 118_392 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_reads_only/00/weigths_pah___10k_read_10.rs:                 read: 119_567 * constants::WEIGHT_REF_TIME_PER_NANOS,

batch-size: 1M
weigths_pah_reads_only/00/weigths_pah___1M_read_01.rs:                  read: 120_442 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_reads_only/00/weigths_pah___1M_read_02.rs:                  read: 120_587 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_reads_only/00/weigths_pah___1M_read_03.rs:                  read: 120_616 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_reads_only/00/weigths_pah___1M_read_04.rs:                  read: 120_668 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_reads_only/00/weigths_pah___1M_read_05.rs:                  read: 120_417 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_reads_only/00/weigths_pah___1M_read_06.rs:                  read: 120_444 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_reads_only/00/weigths_pah___1M_read_07.rs:                  read: 120_503 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_reads_only/00/weigths_pah___1M_read_08.rs:                  read: 120_412 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_reads_only/00/weigths_pah___1M_read_09.rs:                  read: 120_471 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_reads_only/00/weigths_pah___1M_read_10.rs:                  read: 121_295 * constants::WEIGHT_REF_TIME_PER_NANOS,

For read then write benchmark executed in loop over the same db (writes skipped for clarity), read timings are not stable any more:

weigths_pah_rw/00/weigths_pah___100k_rw_01.rs:			read: 130_946 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_rw/00/weigths_pah___100k_rw_02.rs:			read: 119_475 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_rw/00/weigths_pah___100k_rw_03.rs:			read: 134_775 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_rw/00/weigths_pah___100k_rw_04.rs:			read: 136_035 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_rw/00/weigths_pah___100k_rw_05.rs:			read: 130_444 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_rw/00/weigths_pah___100k_rw_06.rs:			read: 170_214 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_rw/00/weigths_pah___100k_rw_07.rs:			read: 130_497 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_rw/00/weigths_pah___100k_rw_08.rs:			read: 181_800 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_rw/00/weigths_pah___100k_rw_09.rs:			read: 182_406 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_rw/00/weigths_pah___100k_rw_10.rs:			read: 137_068 * constants::WEIGHT_REF_TIME_PER_NANOS,

weigths_pah_rw/00/weigths_pah___10k_rw_01.rs:			read: 77_933 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_rw/00/weigths_pah___10k_rw_02.rs:			read: 87_517 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_rw/00/weigths_pah___10k_rw_03.rs:			read: 115_153 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_rw/00/weigths_pah___10k_rw_04.rs:			read: 104_654 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_rw/00/weigths_pah___10k_rw_05.rs:			read: 105_840 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_rw/00/weigths_pah___10k_rw_06.rs:			read: 119_721 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_rw/00/weigths_pah___10k_rw_07.rs:			read: 99_925 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_rw/00/weigths_pah___10k_rw_08.rs:			read: 102_330 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_rw/00/weigths_pah___10k_rw_09.rs:			read: 114_771 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_rw/00/weigths_pah___10k_rw_10.rs:			read: 146_837 * constants::WEIGHT_REF_TIME_PER_NANOS,

weigths_pah_rw/00/weigths_pah___1M_rw_01.rs:			read: 135_741 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_rw/00/weigths_pah___1M_rw_02.rs:			read: 145_561 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_rw/00/weigths_pah___1M_rw_03.rs:			read: 110_653 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_rw/00/weigths_pah___1M_rw_04.rs:			read: 139_268 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_rw/00/weigths_pah___1M_rw_05.rs:			read: 109_138 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_rw/00/weigths_pah___1M_rw_06.rs:			read: 155_584 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_rw/00/weigths_pah___1M_rw_07.rs:			read: 120_767 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_rw/00/weigths_pah___1M_rw_08.rs:			read: 123_224 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_rw/00/weigths_pah___1M_rw_09.rs:			read: 176_991 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_rw/00/weigths_pah___1M_rw_10.rs:			read: 136_337 * constants::WEIGHT_REF_TIME_PER_NANOS,

paritytech/parity-common#949 and #10242 don't help, read numbers are still not stable for read/write benchmarking.

Script for reference

#!/bin/bash -x

export BIN=./polkadot-parachain
export CHAIN="--base-path ./grab-db/pah/"
export COMMON="--state-version 1 --skip-write"
export DIR=weigths_pah_reads_only/00

for i in `seq 1 10`; do
  WEIGTH_FILE=$DIR/`printf "weigths_pah___10k_read_%02d.rs" $i`
  RUST_LOG=info $BIN benchmark storage $CHAIN $COMMON --weight-path $WEIGTH_FILE --batch-size 10000
done

for i in `seq 1 10`; do
  WEIGTH_FILE=$DIR/`printf "weigths_pah___1M_read_%02d.rs" $i`
  RUST_LOG=info $BIN benchmark storage $CHAIN $COMMON --weight-path $WEIGTH_FILE --batch-size 1000000
done

for i in `seq 1 10`; do
  WEIGTH_FILE=$DIR/`printf "weigths_pah___100k_read_%02d.rs" $i`
  RUST_LOG=info $BIN benchmark storage $CHAIN $COMMON --weight-path $WEIGTH_FILE --batch-size 100000
done

[michalkucharczyk]

cc: @skunert @ggwpez @alexggh

[bkchr]

paritytech/parity-common#949 and #10242 don't help, read numbers are still not stable for read/write benchmarking.

Is probably not triggered, as we only compact the DB when we write more than ~64MiB of data. (at once)

[bkchr]

Did you tested it with paritydb?

[alexggh]

First, this are numbers without --enable-trie-cache --trie-cache-size and for parachains the validation mode should be used like in here, that seem to be stable for me.

Secondly, even with this, it is really weird that runs of write benchmark would impact read, my guess here is that probably you get some noise from a cache either the DB cache or the OS one, could you try before each run to try to clear all OS cache and see if it impacts anything, some like:

 sudo bash -c 'echo 1 > /proc/sys/vm/drop_caches' ; sudo bash -c 'echo 2 > /proc/sys/vm/drop_caches' ;  sudo bash -c 'echo 3 > /proc/sys/vm/drop_caches'  ;

[michalkucharczyk]

Without write, the reads are stable - so I think OS caches are excluded, (yeah but I will give it a try). Measurments are done the dedicated machine to reduce OS noise.

The write test first modifies the db and then commits and reverts - here. We had problems with performance drop on badly compacted rocksdb (paritytech/parity-common#949), this is why I think write can impact read.

[michalkucharczyk]

Forgot to mention: I don't see this fluctuations for the DB with 1M keys in state trie (PAH now has 8.5M).

Did you tested it with paritydb?

No.

[michalkucharczyk]

`script` with trie-cache-enabled and OS cache invalidation

#!/bin/bash -x

# RUST_LOG=info ../target/release/polkadot-parachain  benchmark storage --state-version 1  --base-path ./grab-db/pah/ --batch-size 100000 --estimation-batch-size 10
# RUST_LOG=info ../target/release/polkadot-parachain  benchmark storage --state-version 1  --base-path ./grab-db/pah/ --batch-size 1000000 --estimation-batch-size 100
# RUST_LOG=info ../target/release/polkadot-parachain  benchmark storage --state-version 1



export BIN=./polkadot-parachain
export CHAIN="--base-path ./grab-db/pah/"
export COMMON="--state-version 1 --enable-trie-cache"
#export COMMON="--state-version 1"
export DIR=weigths_pah_rw_with_tc/00

for i in `seq 1 4`; do
  sudo bash -c 'echo 1 > /proc/sys/vm/drop_caches' ; sudo bash -c 'echo 2 > /proc/sys/vm/drop_caches' ;  sudo bash -c 'echo 3 > /proc/sys/vm/drop_caches';
  WEIGTH_FILE=$DIR/`printf "weigths_pah___10k_rw_%02d.rs" $i`
  RUST_LOG=info $BIN benchmark storage $CHAIN $COMMON --weight-path $WEIGTH_FILE --batch-size 10000
done

for i in `seq 1 4`; do
  sudo bash -c 'echo 1 > /proc/sys/vm/drop_caches' ; sudo bash -c 'echo 2 > /proc/sys/vm/drop_caches' ;  sudo bash -c 'echo 3 > /proc/sys/vm/drop_caches';
  WEIGTH_FILE=$DIR/`printf "weigths_pah___1M_rw_%02d.rs" $i`
  RUST_LOG=info $BIN benchmark storage $CHAIN $COMMON --weight-path $WEIGTH_FILE --batch-size 1000000
done

for i in `seq 1 4`; do
  sudo bash -c 'echo 1 > /proc/sys/vm/drop_caches' ; sudo bash -c 'echo 2 > /proc/sys/vm/drop_caches' ;  sudo bash -c 'echo 3 > /proc/sys/vm/drop_caches';
  WEIGTH_FILE=$DIR/`printf "weigths_pah___100k_rw_%02d.rs" $i`
  RUST_LOG=info $BIN benchmark storage $CHAIN $COMMON --weight-path $WEIGTH_FILE --batch-size 100000
done

read results are still not consistent (maybe default cache size is too small). writes numbers look good.

weigths_pah_rw_with_tc/00/weigths_pah___100k_rw_01.rs:                  read: 164_896 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_rw_with_tc/00/weigths_pah___100k_rw_01.rs:                  write: 72_831 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_rw_with_tc/00/weigths_pah___100k_rw_02.rs:                  read: 112_615 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_rw_with_tc/00/weigths_pah___100k_rw_02.rs:                  write: 72_839 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_rw_with_tc/00/weigths_pah___100k_rw_03.rs:                  read: 101_978 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_rw_with_tc/00/weigths_pah___100k_rw_03.rs:                  write: 72_813 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_rw_with_tc/00/weigths_pah___100k_rw_04.rs:                  read: 65_159 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_rw_with_tc/00/weigths_pah___100k_rw_04.rs:                  write: 72_987 * constants::WEIGHT_REF_TIME_PER_NANOS,

weigths_pah_rw_with_tc/00/weigths_pah___10k_rw_01.rs:                   read: 50_042 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_rw_with_tc/00/weigths_pah___10k_rw_01.rs:                   write: 92_819 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_rw_with_tc/00/weigths_pah___10k_rw_02.rs:                   read: 54_707 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_rw_with_tc/00/weigths_pah___10k_rw_02.rs:                   write: 95_400 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_rw_with_tc/00/weigths_pah___10k_rw_03.rs:                   read: 75_901 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_rw_with_tc/00/weigths_pah___10k_rw_03.rs:                   write: 97_294 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_rw_with_tc/00/weigths_pah___10k_rw_04.rs:                   read: 77_217 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_rw_with_tc/00/weigths_pah___10k_rw_04.rs:                   write: 97_291 * constants::WEIGHT_REF_TIME_PER_NANOS,

weigths_pah_rw_with_tc/00/weigths_pah___1M_rw_01.rs:                    read: 89_868 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_rw_with_tc/00/weigths_pah___1M_rw_01.rs:                    write: 48_634 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_rw_with_tc/00/weigths_pah___1M_rw_02.rs:                    read: 90_867 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_rw_with_tc/00/weigths_pah___1M_rw_02.rs:                    write: 48_940 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_rw_with_tc/00/weigths_pah___1M_rw_03.rs:                    read: 108_424 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_rw_with_tc/00/weigths_pah___1M_rw_03.rs:                    write: 48_587 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_rw_with_tc/00/weigths_pah___1M_rw_04.rs:                    read: 147_366 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah_rw_with_tc/00/weigths_pah___1M_rw_04.rs:                    write: 49_054 * constants::WEIGHT_REF_TIME_PER_NANOS,

[alexggh]

--trie-cache-enabled runs with only 64MiB cache which is too small to see notice results, for example running on my machine on cache big enough to make sure fits in it --trie-cache-size 14737418240.

So probably the variantion you see are coming from the rocks-db cache, but still weird it happens only if you ran a write benchmark before.

weigths_pah___10k_rw_02.rs:			read: 5_878 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah___10k_rw_02.rs:			write: 30_886 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah___10k_rw_04.rs:			read: 5_875 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah___10k_rw_04.rs:			write: 30_949 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah___10k_rw_03.rs:			read: 5_965 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah___10k_rw_03.rs:			write: 30_927 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah___10k_rw_01.rs:			read: 5_873 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah___10k_rw_01.rs:			write: 30_842 * constants::WEIGHT_REF_TIME_PER_NANOS,


weigths_pah___100k_rw_02.rs:			read: 5_824 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah___100k_rw_02.rs:			write: 24_174 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah___100k_rw_01.rs:			read: 5_811 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah___100k_rw_01.rs:			write: 24_187 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah___100k_rw_04.rs:			read: 5_860 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah___100k_rw_04.rs:			write: 24_219 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah___100k_rw_03.rs:			read: 6_029 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah___100k_rw_03.rs:			write: 24_143 * constants::WEIGHT_REF_TIME_PER_NANOS,

weigths_pah___1M_rw_03.rs:			read: 5_655 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah___1M_rw_03.rs:			write: 16_903 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah___1M_rw_02.rs:			read: 5_673 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah___1M_rw_02.rs:			write: 16_852 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah___1M_rw_04.rs:			read: 5_675 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah___1M_rw_04.rs:			write: 16_929 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah___1M_rw_01.rs:			read: 5_700 * constants::WEIGHT_REF_TIME_PER_NANOS,
weigths_pah___1M_rw_01.rs:			write: 16_891 * constants::WEIGHT_REF_TIME_PER_NANOS,

[michalkucharczyk]

Btw, enabling cache is hiding the real problem. The results shall be consistent.

[alexggh]

Btw, enabling cache is hiding the real problem. The results shall be consistent.

I was just trying to isolate where the variation might come from, I agree results should be consistent.

[michalkucharczyk]

Yeah, increasing trie cache to --trie-cache-size 8589934592 helped:

./weigths_pah___100k_rw_01.rs:                  read: 11_624 * constants::WEIGHT_REF_TIME_PER_NANOS,
./weigths_pah___100k_rw_01.rs:                  write: 63_222 * constants::WEIGHT_REF_TIME_PER_NANOS,
./weigths_pah___100k_rw_02.rs:                  read: 11_677 * constants::WEIGHT_REF_TIME_PER_NANOS,
./weigths_pah___100k_rw_02.rs:                  write: 62_700 * constants::WEIGHT_REF_TIME_PER_NANOS,
./weigths_pah___100k_rw_03.rs:                  read: 11_688 * constants::WEIGHT_REF_TIME_PER_NANOS,
./weigths_pah___100k_rw_03.rs:                  write: 62_567 * constants::WEIGHT_REF_TIME_PER_NANOS,
./weigths_pah___100k_rw_04.rs:                  read: 11_635 * constants::WEIGHT_REF_TIME_PER_NANOS,
./weigths_pah___100k_rw_04.rs:                  write: 62_626 * constants::WEIGHT_REF_TIME_PER_NANOS,

./weigths_pah___10k_rw_01.rs:                   read: 11_767 * constants::WEIGHT_REF_TIME_PER_NANOS,
./weigths_pah___10k_rw_01.rs:                   write: 78_332 * constants::WEIGHT_REF_TIME_PER_NANOS,
./weigths_pah___10k_rw_02.rs:                   read: 11_772 * constants::WEIGHT_REF_TIME_PER_NANOS,
./weigths_pah___10k_rw_02.rs:                   write: 78_109 * constants::WEIGHT_REF_TIME_PER_NANOS,
./weigths_pah___10k_rw_03.rs:                   read: 11_820 * constants::WEIGHT_REF_TIME_PER_NANOS,
./weigths_pah___10k_rw_03.rs:                   write: 78_189 * constants::WEIGHT_REF_TIME_PER_NANOS,
./weigths_pah___10k_rw_04.rs:                   read: 11_755 * constants::WEIGHT_REF_TIME_PER_NANOS,
./weigths_pah___10k_rw_04.rs:                   write: 78_327 * constants::WEIGHT_REF_TIME_PER_NANOS,

./weigths_pah___1M_rw_01.rs:                    read: 11_741 * constants::WEIGHT_REF_TIME_PER_NANOS,
./weigths_pah___1M_rw_01.rs:                    write: 45_351 * constants::WEIGHT_REF_TIME_PER_NANOS,
./weigths_pah___1M_rw_02.rs:                    read: 11_840 * constants::WEIGHT_REF_TIME_PER_NANOS,
./weigths_pah___1M_rw_02.rs:                    write: 44_415 * constants::WEIGHT_REF_TIME_PER_NANOS,
./weigths_pah___1M_rw_03.rs:                    read: 11_834 * constants::WEIGHT_REF_TIME_PER_NANOS,
./weigths_pah___1M_rw_03.rs:                    write: 44_785 * constants::WEIGHT_REF_TIME_PER_NANOS,
./weigths_pah___1M_rw_04.rs:                    read: 11_731 * constants::WEIGHT_REF_TIME_PER_NANOS,
./weigths_pah___1M_rw_04.rs:                    write: 44_597 * constants::WEIGHT_REF_TIME_PER_NANOS,

Assuming that we want to use reasonable size of trie-cache during benchmark, issue is probably not that important. (@alexggh thanks for help).