Skip to content
This repository has been archived by the owner on Nov 6, 2020. It is now read-only.

Archive node running 1.8.6-unstable from source syncing 3-5x slower relative to 1.7.11-stable #7489

Closed
iostat opened this issue Jan 8, 2018 · 13 comments
Assignees
Labels
F7-optimisation 💊 An enhancement to provide better overall performance in terms of time-to-completion for a task. M4-core ⛓ Core client code / Rust. P2-asap 🌊 No need to stop dead in your tracks, however issue should be addressed as soon as possible.
Milestone

Comments

@iostat
Copy link

iostat commented Jan 8, 2018

I'm running:

  • Which Parity version?: Parity/v1.8.6-unstable-364bf48-20180104/x86_64-linux-gnu/rustc1.22.1 vs. Parity/v1.7.11-stable-a5ed4cf-20171228/x86_64-linux-gnu/rustc1.22.1
  • Which operating system?: Ubuntu Xenial
  • Hardware: EC2 m4.xlarge instance, parity home on io1-class 512GB SSD volume with 3000 IOPS provisioned, XFS formatted, mount point symlinked as ~/.local/share/io.parity.ethereum
  • How installed?: from source (unstable) and official .deb package (stable)
  • Are you fully synchronized?: no
  • Did you try to restart the node?: yes
  • Command line: --db-compaction=ssd --cache-size=1024 --pruning=archive --nat=extip:$EXTIP --unsafe-expose --jsonrpc-interface=all --ws-interface=all --jsonrpc-hosts=all --jsonrpc-cors='*' --jsonrpc-apis=all --jsonrpc-threads=4--jsonrpc-server-threads=4

Hi!

I was initially attempting to sync a full archive node with v1.7.11-stable, and was bitten by with the space amplification issues described in #6280. My node would regularly run out of disk space, and I would have to make a little bit of room so that I can restart Parity wherein RocksDB would run garbage collection on startup and free up 200 or so GB allowing the sync to continue. To this end I actually had created a 1GB dummy file that I could delete when the node inevitably crashed to give it just a bit of breathing room to survive a restart and GC, and then recreated the 1GB dummy file for when RocksDB ate up all the disk space again.

Having noticed that greener pastures may lie ahead in #7348 (and subsequently backported to 1.8 in #7438), I went ahead and compiled what was the latest HEAD (364bf48) of the beta branch last night, using cargo build --release --verbose. Firing up the 1.8.6-unstable binary against my partially synced (around block 3700000) archive node's storage directory (because who wants to relive blocks 2200000-2800000?), it picked it up just fine and continued syncing from where it left off. I immediately noticed it was only hovering around the 1 blk/s mark instead of the usual 3-4, but figured the shiny new RocksDB is compacting stuff behind the scenes and left it to its devices for a few hours. Coming back to it, I noticed absolutely no space amplification (awesome work on that!), but unfortunately saw it's still creeping along at around 1 blk/s and tx/s always within in the high double digits. Switching back to 1.7.11 (again, same working directory), it picked up where the 1.8.6 binary left off but had a significantly peppier 3-4 blk/s and tx/s almost consistently in the triple digits.

Some sample logs:

v1.8.6-unstable

Warning: Disabling Dapps server because fast RPC server was enabled.
2018-01-08 00:14:30 UTC Starting Parity/v1.8.6-unstable-364bf48-20180104/x86_64-linux-gnu/rustc1.22.1                                                                                                                                                 
2018-01-08 00:14:30 UTC Keys path /home/ubuntu/.local/share/io.parity.ethereum/keys/Foundation
2018-01-08 00:14:30 UTC DB path /home/ubuntu/.local/share/io.parity.ethereum/chains/ethereum/db/906a34e69aec8c0d
2018-01-08 00:14:30 UTC Path to dapps /home/ubuntu/.local/share/io.parity.ethereum/dapps
2018-01-08 00:14:30 UTC State DB configuration: archive
2018-01-08 00:14:30 UTC Operating mode: active
2018-01-08 00:14:30 UTC Warning: Warp Sync is disabled because of non-default pruning mode.
2018-01-08 00:14:30 UTC Configured for Foundation using Ethash engine
2018-01-08 00:14:30 UTC Updated conversion rate to Ξ1 = US$1128.92 (105452660 wei/gas)
2018-01-08 00:14:34 UTC Public node URL: enode://94acab47357d2141b50c53fea5487549c4156e51f5c4ba8b678b6a6d3737e12454f7780c3cc85f45045aaf066e0f455c71d7efdd1e231195f658d0ef4f356b43@52.41.67.76:30303
2018-01-08 00:14:35 UTC Removed existing file '/home/ubuntu/.local/share/io.parity.ethereum/jsonrpc.ipc'.
2018-01-08 00:14:53 UTC Syncing #3880717 ba9a…7ede     0 blk/s    0 tx/s   0 Mgas/s      0+    0 Qed  #3880717    2/25 peers   95 KiB chain 15 KiB db 0 bytes queue 19 KiB sync  RPC:  0 conn,  0 req/s,   0 µs
2018-01-08 00:15:04 UTC Syncing #3880717 ba9a…7ede     0 blk/s    0 tx/s   0 Mgas/s      0+   19 Qed  #3880827    5/25 peers   97 KiB chain 23 KiB db 1 MiB queue 97 KiB sync  RPC:  0 conn,  0 req/s,   0 µs
2018-01-08 00:15:11 UTC Syncing #3880720 f4a8…6101     0 blk/s   16 tx/s   1 Mgas/s      0+  121 Qed  #3880844    5/25 peers   201 KiB chain 221 KiB db 6 MiB queue 182 KiB sync  RPC:  0 conn,  0 req/s,   0 µs
2018-01-08 00:15:20 UTC Syncing #3880731 5712…5c75     1 blk/s   44 tx/s   2 Mgas/s      0+  109 Qed  #3880844    6/25 peers   353 KiB chain 428 KiB db 5 MiB queue 447 KiB sync  RPC:  0 conn,  0 req/s,   0 µs
2018-01-08 00:15:42 UTC Syncing #3880732 f281…64ac     0 blk/s   10 tx/s   0 Mgas/s      0+  184 Qed  #3881052    6/25 peers   354 KiB chain 499 KiB db 10 MiB queue 317 KiB sync  RPC:  0 conn,  0 req/s,   0 µs
2018-01-08 00:15:42 UTC Syncing #3880737 4423…6f15     0 blk/s   30 tx/s   0 Mgas/s      0+  313 Qed  #3881052    6/25 peers   427 KiB chain 646 KiB db 19 MiB queue 317 KiB sync  RPC:  0 conn,  0 req/s,   0 µs
2018-01-08 00:15:51 UTC Syncing #3880742 23e1…b496     0 blk/s   70 tx/s   3 Mgas/s      0+  387 Qed  #3881156    4/25 peers   542 KiB chain 803 KiB db 23 MiB queue 544 KiB sync  RPC:  0 conn,  0 req/s,   0 µs
2018-01-08 00:16:03 UTC Syncing #3880751 c54b…978d     1 blk/s   51 tx/s   2 Mgas/s      0+  470 Qed  #3881225    4/25 peers   775 KiB chain 959 KiB db 27 MiB queue 388 KiB sync  RPC:  0 conn,  0 req/s,   0 µs
2018-01-08 00:16:10 UTC Syncing #3880770 a70d…3673     2 blk/s   80 tx/s   3 Mgas/s      0+  522 Qed  #3881298    4/25 peers   802 KiB chain 1 MiB db 29 MiB queue 422 KiB sync  RPC:  0 conn,  0 req/s,   0 µs
2018-01-08 00:16:20 UTC Syncing #3880785 585b…76b5     1 blk/s   82 tx/s   3 Mgas/s      0+  683 Qed  #3881470    4/25 peers   804 KiB chain 1 MiB db 35 MiB queue 903 KiB sync  RPC:  0 conn,  0 req/s,   0 µs
2018-01-08 00:16:30 UTC Syncing #3880795 54d0…26ae     1 blk/s   73 tx/s   2 Mgas/s      0+  826 Qed  #3881639    5/25 peers   1 MiB chain 1 MiB db 40 MiB queue 622 KiB sync  RPC:  0 conn,  0 req/s,   0 µs
2018-01-08 00:16:41 UTC Syncing #3880815 7010…9532     2 blk/s   96 tx/s   3 Mgas/s      0+  835 Qed  #3881678    5/25 peers   2 MiB chain 2 MiB db 40 MiB queue 1 MiB sync  RPC:  0 conn,  0 req/s,   0 µs
2018-01-08 00:16:50 UTC Syncing #3880831 7d58…edd9     1 blk/s   79 tx/s   3 Mgas/s      0+  843 Qed  #3881678    6/25 peers   2 MiB chain 2 MiB db 40 MiB queue 1 MiB sync  RPC:  0 conn,  0 req/s,   0 µs
2018-01-08 00:17:00 UTC Syncing #3880843 625d…97ac     1 blk/s   82 tx/s   2 Mgas/s      0+  831 Qed  #3881678    7/25 peers   3 MiB chain 2 MiB db 40 MiB queue 1 MiB sync  RPC:  0 conn,  0 req/s,   0 µs
2018-01-08 00:17:06 UTC Syncing #3880845 ab6e…231b     0 blk/s   61 tx/s   1 Mgas/s      0+  831 Qed  #3881678    7/25 peers   3 MiB chain 2 MiB db 40 MiB queue 2 MiB sync  RPC:  0 conn,  0 req/s,   0 µs
2018-01-08 00:17:17 UTC Syncing #3880854 7888…2ec4     1 blk/s   70 tx/s   3 Mgas/s      0+  959 Qed  #3881860    7/25 peers   4 MiB chain 2 MiB db 47 MiB queue 608 KiB sync  RPC:  0 conn,  0 req/s,   0 µs
2018-01-08 00:17:25 UTC Syncing #3880863 b0d1…d257     1 blk/s   79 tx/s   2 Mgas/s      0+  993 Qed  #3881860    7/25 peers   4 MiB chain 2 MiB db 48 MiB queue 608 KiB sync  RPC:  0 conn,  0 req/s,   0 µs
2018-01-08 00:17:30 UTC Syncing #3880870 83ba…2aa8     1 blk/s   84 tx/s   4 Mgas/s      0+  989 Qed  #3881860    7/25 peers   4 MiB chain 3 MiB db 48 MiB queue 608 KiB sync  RPC:  0 conn,  0 req/s,   0 µs
2018-01-08 00:17:40 UTC Syncing #3880876 f289…073b     0 blk/s   75 tx/s   1 Mgas/s      0+  981 Qed  #3881860    9/25 peers   4 MiB chain 3 MiB db 47 MiB queue 608 KiB sync  RPC:  0 conn,  0 req/s,   0 µs
^C2018-01-08 00:17:41 UTC Finishing work, please wait...

v1.7.11-stable:

Warning: Disabling Dapps server because fast RPC server was enabled.
2018-01-08 00:17:58 UTC Starting Parity/v1.7.11-stable-a5ed4cf-20171228/x86_64-linux-gnu/rustc1.22.1
2018-01-08 00:17:58 UTC Keys path /home/ubuntu/.local/share/io.parity.ethereum/keys/Foundation
2018-01-08 00:17:58 UTC DB path /home/ubuntu/.local/share/io.parity.ethereum/chains/ethereum/db/906a34e69aec8c0d
2018-01-08 00:17:58 UTC Path to dapps /home/ubuntu/.local/share/io.parity.ethereum/dapps
2018-01-08 00:17:58 UTC State DB configuration: archive
2018-01-08 00:17:58 UTC Operating mode: active
2018-01-08 00:17:58 UTC Warning: Warp Sync is disabled because of non-default pruning mode.
2018-01-08 00:17:58 UTC Configured for Foundation using Ethash engine
2018-01-08 00:17:58 UTC Updated conversion rate to Ξ1 = US$1133.85 (104994150 wei/gas)
2018-01-08 00:18:16 UTC Syncing #3880883 b03b…c78a     0 blk/s    0 tx/s   0 Mgas/s      0+    0 Qed  #3880883    1/25 peers   75 KiB chain 15 KiB db 0 bytes queue 19 KiB sync  RPC:  0 conn,  0 req/s,   0 µs
2018-01-08 00:18:21 UTC Syncing #3880883 b03b…c78a     0 blk/s    0 tx/s   0 Mgas/s      0+    0 Qed  #3880883    2/25 peers   75 KiB chain 15 KiB db 0 bytes queue 1 MiB sync  RPC:  0 conn,  0 req/s,   0 µs
2018-01-08 00:18:26 UTC Syncing #3880888 d318…5309     0 blk/s   54 tx/s   2 Mgas/s      0+  156 Qed  #3881045    3/25 peers   172 KiB chain 257 KiB db 10 MiB queue 1 MiB sync  RPC:  0 conn,  0 req/s,   0 µs
2018-01-08 00:18:32 UTC Syncing #3880912 4ba4…d2df     4 blk/s  371 tx/s  16 Mgas/s     15+  138 Qed  #3881459    3/25 peers   500 KiB chain 1 MiB db 10 MiB queue 1 MiB sync  RPC:  0 conn,  0 req/s,   0 µs
2018-01-08 00:18:42 UTC Syncing #3880950 27c0…3bb9     4 blk/s  296 tx/s  12 Mgas/s    176+  870 Qed  #3882004    4/25 peers   875 KiB chain 2 MiB db 44 MiB queue 980 KiB sync  RPC:  0 conn,  0 req/s,   0 µs
2018-01-08 00:18:51 UTC Syncing #3881009 c648…10bb     5 blk/s  382 tx/s  16 Mgas/s      0+  991 Qed  #3882004    5/25 peers   2 MiB chain 3 MiB db 46 MiB queue 980 KiB sync  RPC:  0 conn,  0 req/s,   0 µs
2018-01-08 00:19:01 UTC Syncing #3881058 81e9…fae8     4 blk/s  425 tx/s  15 Mgas/s      0+  943 Qed  #3882004    6/25 peers   2 MiB chain 4 MiB db 43 MiB queue 980 KiB sync  RPC:  0 conn,  0 req/s,   0 µs
2018-01-08 00:19:06 UTC Syncing #3881087 defc…895c     5 blk/s  405 tx/s  16 Mgas/s      0+  915 Qed  #3882004    6/25 peers   4 MiB chain 4 MiB db 41 MiB queue 980 KiB sync  RPC:  0 conn,  0 req/s,   0 µs
2018-01-08 00:19:11 UTC Syncing #3881118 0b31…8adc     6 blk/s  382 tx/s  16 Mgas/s      0+  883 Qed  #3882004    8/25 peers   4 MiB chain 5 MiB db 39 MiB queue 1 MiB sync  RPC:  0 conn,  0 req/s,   0 µs
2018-01-08 00:19:16 UTC Syncing #3881141 b64b…3f8a     4 blk/s  293 tx/s  13 Mgas/s      0+  950 Qed  #3882095    8/25 peers   4 MiB chain 5 MiB db 42 MiB queue 2 MiB sync  RPC:  0 conn,  0 req/s,   0 µs
2018-01-08 00:19:26 UTC Syncing #3881184 2280…e79a     4 blk/s  189 tx/s   9 Mgas/s      0+  910 Qed  #3882095    8/25 peers   5 MiB chain 6 MiB db 41 MiB queue 2 MiB sync  RPC:  0 conn,  0 req/s,   0 µs
2018-01-08 00:19:36 UTC Syncing #3881209 65e7…0de6     2 blk/s   92 tx/s   5 Mgas/s      0+ 1009 Qed  #3882222    8/25 peers   6 MiB chain 6 MiB db 44 MiB queue 2 MiB sync  RPC:  0 conn,  0 req/s,   0 µs
2018-01-08 00:19:46 UTC Syncing #3881259 d5fd…bcf7     5 blk/s  225 tx/s  11 Mgas/s      0+  961 Qed  #3882222    9/25 peers   7 MiB chain 6 MiB db 42 MiB queue 2 MiB sync  RPC:  0 conn,  0 req/s,   0 µs
2018-01-08 00:19:56 UTC Syncing #3881309 88d9…fa26     5 blk/s  208 tx/s  11 Mgas/s     45+ 1039 Qed  #3882403   10/25 peers   9 MiB chain 7 MiB db 46 MiB queue 421 KiB sync  RPC:  0 conn,  0 req/s,   0 µs
2018-01-08 00:20:06 UTC Syncing #3881343 e427…b694     3 blk/s  133 tx/s   7 Mgas/s      0+ 1058 Qed  #3882403   11/25 peers   12 MiB chain 7 MiB db 47 MiB queue 421 KiB sync  RPC:  0 conn,  0 req/s,   0 µs
2018-01-08 00:20:16 UTC Syncing #3881377 aa7a…bc47     3 blk/s  101 tx/s   5 Mgas/s      0+ 1022 Qed  #3882403   13/25 peers   16 MiB chain 7 MiB db 45 MiB queue 421 KiB sync  RPC:  0 conn,  0 req/s,   0 µs
2018-01-08 00:20:26 UTC Syncing #3881428 c252…3e44     5 blk/s  178 tx/s   7 Mgas/s      0+  974 Qed  #3882403   13/25 peers   19 MiB chain 7 MiB db 44 MiB queue 421 KiB sync  RPC:  0 conn,  0 req/s,   0 µs
2018-01-08 00:20:36 UTC Syncing #3881461 54cb…ee62     3 blk/s  118 tx/s   5 Mgas/s      0+  938 Qed  #3882403   13/25 peers   23 MiB chain 8 MiB db 43 MiB queue 421 KiB sync  RPC:  0 conn,  0 req/s,   0 µs
2018-01-08 00:20:46 UTC Syncing #3881498 039d…3526     3 blk/s  142 tx/s   5 Mgas/s      0+  902 Qed  #3882403   12/25 peers   33 MiB chain 8 MiB db 42 MiB queue 421 KiB sync  RPC:  0 conn,  0 req/s,   0 µs
2018-01-08 00:20:56 UTC Syncing #3881534 0b10…b8c5     3 blk/s  159 tx/s   7 Mgas/s      0+  866 Qed  #3882403   12/25 peers   41 MiB chain 8 MiB db 40 MiB queue 421 KiB sync  RPC:  0 conn,  0 req/s,   0 µs
2018-01-08 00:21:06 UTC Syncing #3881561 a005…893f     2 blk/s  128 tx/s   6 Mgas/s      0+  874 Qed  #3882439   13/25 peers   49 MiB chain 8 MiB db 40 MiB queue 398 KiB sync  RPC:  0 conn,  0 req/s,   0 µs
2018-01-08 00:21:16 UTC Syncing #3881589 7423…e408     2 blk/s  115 tx/s   4 Mgas/s      0+  941 Qed  #3882534   12/25 peers   52 MiB chain 9 MiB db 44 MiB queue 1 MiB sync  RPC:  0 conn,  0 req/s,   0 µs
2018-01-08 00:21:26 UTC Syncing #3881623 bbdf…54d4     3 blk/s  142 tx/s   5 Mgas/s      0+  909 Qed  #3882534   15/25 peers   61 MiB chain 9 MiB db 43 MiB queue 1 MiB sync  RPC:  0 conn,  0 req/s,   0 µs
2018-01-08 00:21:36 UTC Syncing #3881661 2975…d302     3 blk/s  151 tx/s   6 Mgas/s      0+  869 Qed  #3882534   17/25 peers   69 MiB chain 9 MiB db 41 MiB queue 1 MiB sync  RPC:  0 conn,  0 req/s,   0 µs
2018-01-08 00:21:46 UTC Syncing #3881685 7e84…1b36     2 blk/s  137 tx/s   5 Mgas/s      0+  845 Qed  #3882534   17/25 peers   77 MiB chain 9 MiB db 40 MiB queue 1 MiB sync  RPC:  0 conn,  0 req/s,   0 µs
2018-01-08 00:21:56 UTC Syncing #3881710 8164…a2f6     2 blk/s  150 tx/s   5 Mgas/s      0+  854 Qed  #3882567   16/25 peers   85 MiB chain 10 MiB db 40 MiB queue 1 MiB sync  RPC:  0 conn,  0 req/s,   0 µs
2018-01-08 00:22:07 UTC Syncing #3881738 d8a6…c790     2 blk/s  164 tx/s   7 Mgas/s      0+  826 Qed  #3882668   16/25 peers   88 MiB chain 10 MiB db 39 MiB queue 12 MiB sync  RPC:  0 conn,  0 req/s,   0 µs
2018-01-08 00:22:16 UTC Syncing #3881761 3f56…d17b     2 blk/s  123 tx/s   4 Mgas/s      0+  903 Qed  #3882668   18/25 peers   56 MiB chain 10 MiB db 42 MiB queue 12 MiB sync  RPC:  0 conn,  0 req/s,   0 µs

I recognize that this may simply be due to the fact that the DBs were created with v1.7.11 RocksDB tuning parameters, but I'm inclined to believe that since v1.8.6 doesn't hit space-amplification issues that that's not entirely what's at play here. Would love to see if anyone else is experiencing such behavior or if it's just me, and I'd be glad to help prod this further any way I can!

@5chdn 5chdn self-assigned this Jan 8, 2018
@5chdn 5chdn added F7-optimisation 💊 An enhancement to provide better overall performance in terms of time-to-completion for a task. M4-core ⛓ Core client code / Rust. P2-asap 🌊 No need to stop dead in your tracks, however issue should be addressed as soon as possible. labels Jan 8, 2018
@5chdn 5chdn added this to the 1.9 milestone Jan 8, 2018
@5chdn
Copy link
Contributor

5chdn commented Jan 8, 2018

Thanks for your report. cc @andresilva

I noticed something similar with the latest master 1.9.0-unstable versus 1.8.5 which does not include #7348 - will do some benchmarks today.

@andresilva
Copy link
Contributor

andresilva commented Jan 8, 2018

It could be the initial compaction from the updated RocksDB settings which takes a bit longer. We should check if this also happens on a fresh db. If indeed it is the compaction then performance should go back to normal if you let it run long enough.

@iostat
Copy link
Author

iostat commented Jan 8, 2018

Is there some way I can export the raw block RLPs from parity and import them back into a clean database? I'd like to get an empirical test going between the two versions, but it's a bit difficult to get it consistent due to the fact that the two clean DBs might not necessarily have the same peer set and block availability characteristics.

@andresilva
Copy link
Contributor

andresilva commented Jan 8, 2018

parity export blocks <filename> and then to import parity import <filename>. You can pass a --to flag to export to specify until which block to export.

@iostat
Copy link
Author

iostat commented Jan 8, 2018

Thanks @andresilva!. Already noticed something interesting while exporting, the block export in 1.8.6 is S L O W! The block DB is RocksDB as well I presume? Check this out (this is using the DB originally created with 1.7.11 as well):

$ parity-1.8.6 export blocks --to 1000000 /mnt/ssd/perf/first-million.rlp
2018-01-08 14:35:28 UTC Configured for Foundation using Ethash engine
2018-01-08 14:42:02 UTC #10000
^C

I didn't even bother going past 10k, because doing the same with with 1.7.11:

$ parity-1.7.11 export blocks --to 1000000 /mnt/ssd/perf/first-million-2.rlp
2018-01-08 14:42:37 UTC Configured for Foundation using Ethash engine
2018-01-08 14:42:44 UTC #10000
2018-01-08 14:43:00 UTC #20000
2018-01-08 14:43:15 UTC #30000
2018-01-08 14:43:29 UTC #40000
2018-01-08 14:43:40 UTC #50000
2018-01-08 14:43:50 UTC #60000
2018-01-08 14:44:00 UTC #70000
2018-01-08 14:44:09 UTC #80000
2018-01-08 14:44:17 UTC #90000
2018-01-08 14:44:25 UTC #100000
2018-01-08 14:44:32 UTC #110000
2018-01-08 14:44:39 UTC #120000
2018-01-08 14:44:45 UTC #130000
2018-01-08 14:44:52 UTC #140000
2018-01-08 14:44:58 UTC #150000
2018-01-08 14:45:03 UTC #160000
2018-01-08 14:45:09 UTC #170000
2018-01-08 14:45:14 UTC #180000
2018-01-08 14:45:19 UTC #190000
...
2018-01-08 14:47:58 UTC Export completed.

Something's definitely fishy here! I'd understand if it slower if it were writing to rocks as it has to use a different strategy to avoid space amp, but reading as well? I'm wondering if this performance hit is actually a read bottleneck! Anyway, will be back with import logs as soon as those run!

@andresilva
Copy link
Contributor

@iostat I'm not sure if the compaction is triggered when you open RocksDB (even if you're just reading). Could you let it export completely and then do the import into a fresh database and compare results? This was actually one of the benchmarks I used when tuning RocksDB (block import and snapshot restore).

@iostat
Copy link
Author

iostat commented Jan 8, 2018

I should probably clarify that in the original post by compaction I really meant "cleaning up the 200+ GB wasted space due to amp." I guess garbage collection would be more appropriate, I'll update the OP accordingly.

As far as full export/restore -- I'm only synced up to ~3800000, and I know that even with 1.7.11 it took several days to clear the state bloat attacks with my hardware. Is there a more limited test we can do to get a viable result? I'm trying first 1M blocks at the moment.

@andresilva
Copy link
Contributor

Yes, by compaction I mean RocksDB's garbage collection mechanism. For my benchmarks I used the first 2M blocks, as far as time taken to import I didn't see a lot of variability between the different versions (assuming a fresh database).

@iostat
Copy link
Author

iostat commented Jan 8, 2018

Well, usually the whole node crashes once disk space limit is hit, so it's possible the GC I observed is part of crash recovery or something :/. Running the clean import on 1M I'm actually seeing significantly increased performance in 1.8.6!

https://gist.github.com/iostat/c655f3cc7127f5ed9811d7c724436786

I took a closer look at my original issue while running htop and iostat, and I noticed I always have one of my cores maxed out with 1.8.6, but nowhere near the same amount of IOPS saturation (3-400 w/ 1.8.6 as opposed to ~2500 with 1.7.11). I'm assuming that's RocksDB's doing, maybe it's slowly chugging its compaction/optimization along? Perhaps I should let it crawl for a day or two and see if performance recovers?

@andresilva
Copy link
Contributor

Yes, this is what I observed on my benchmarks too, a marginal performance increase (I didn't see that big a difference though). If you could let it keep running it would be great, so we can check if eventually performance goes back to normal (assuming it's caused by RocksDB compaction) and how long it takes to do it (I wasn't able to test this migration on archive nodes).

@5chdn
Copy link
Contributor

5chdn commented Jan 8, 2018

The following plots show sync performance on a fresh database.

screenshot at 2018-01-08 22-24-20
screenshot at 2018-01-08 22-27-36
screenshot at 2018-01-08 22-29-54
screenshot at 2018-01-08 22-51-06

Can't really see huge differences.

@5chdn
Copy link
Contributor

5chdn commented Jan 9, 2018

Can't really see huge differences.

Actually, I do see huge differences, and it turns out 1.8.6 is much faster than 1.8.5.

screenshot at 2018-01-09 21-19-16
screenshot at 2018-01-09 21-25-37
screenshot at 2018-01-09 21-34-08
screenshot at 2018-01-09 21-40-10

@5chdn
Copy link
Contributor

5chdn commented Jan 9, 2018

Closing. The obvious workaround would be killing the DB.

It looks like resyncing an archive node with 1.8.6 would only take a couple of days. I'm already at block 4.2 million after 24 hours on HDD with my fresh (non-archive) no-warp node.

@5chdn 5chdn closed this as completed Jan 9, 2018
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
F7-optimisation 💊 An enhancement to provide better overall performance in terms of time-to-completion for a task. M4-core ⛓ Core client code / Rust. P2-asap 🌊 No need to stop dead in your tracks, however issue should be addressed as soon as possible.
Projects
None yet
Development

No branches or pull requests

3 participants