Parity stops syncing at certain block with tracing on and pruning archive

[luchenyuxx]

I'm running:

• Which Parity version?: version Parity-Ethereum/v2.0.0-beta-6eae372-20180717/x86_64-linux-gnu/rustc1.27.1
• Which operating system?: Linux
• How installed?: One-line Binary Installer
• Are you fully synchronized?: no
• Which network are you connected to?: ethereum / ropsten
• Did you try to restart the node?: yes

I started to sync from scratch the ropsten net with option --pruning archive --tracing on. The synchronisation stops at number 599252. I also tried sync the main net, it also stops at some block.

2018-07-23 12:34:39 UTC Syncing  #599252 0x6f98…1552     0.00 blk/s    0.0 tx/s    0 Mgas/s      0+    0 Qed    #70021    6/25 peers    660 MiB chain  365 MiB db  0 bytes queue   12 MiB sync  RPC:  0 conn,    0 req/s,    0 µs
2018-07-23 12:34:49 UTC Syncing  #599252 0x6f98…1552     0.00 blk/s    0.0 tx/s    0 Mgas/s      0+    0 Qed    #92760    6/25 peers    660 MiB chain  365 MiB db  0 bytes queue   13 MiB sync  RPC:  0 conn,    0 req/s,    0 µs
2018-07-23 12:34:59 UTC Syncing  #599252 0x6f98…1552     0.00 blk/s    0.0 tx/s    0 Mgas/s      0+    0 Qed   #113141    6/25 peers    660 MiB chain  365 MiB db  0 bytes queue   12 MiB sync  RPC:  0 conn,    0 req/s,    0 µs
2018-07-23 12:35:09 UTC Syncing  #599252 0x6f98…1552     0.00 blk/s    0.0 tx/s    0 Mgas/s      0+    0 Qed    #95488    6/25 peers    660 MiB chain  365 MiB db  0 bytes queue   12 MiB sync  RPC:  0 conn,    0 req/s,    0 µs
2018-07-23 12:35:19 UTC Syncing  #599252 0x6f98…1552     0.00 blk/s    0.0 tx/s    0 Mgas/s      0+    0 Qed   #118094    6/25 peers    660 MiB chain  365 MiB db  0 bytes queue   12 MiB sync  RPC:  0 conn,    0 req/s,    0 µs
2018-07-23 12:35:29 UTC Syncing  #599252 0x6f98…1552     0.00 blk/s    0.0 tx/s    0 Mgas/s      0+    0 Qed   #135861    6/25 peers    660 MiB chain  365 MiB db  0 bytes queue   12 MiB sync  RPC:  0 conn,    0 req/s,    0 µs
2018-07-23 12:35:39 UTC Syncing  #599252 0x6f98…1552     0.00 blk/s    0.0 tx/s    0 Mgas/s      0+    0 Qed   #158845    6/25 peers    660 MiB chain  365 MiB db  0 bytes queue   13 MiB sync  RPC:  0 conn,    0 req/s,    0 µs
2018-07-23 12:35:49 UTC Syncing  #599252 0x6f98…1552     0.00 blk/s    0.0 tx/s    0 Mgas/s      0+    0 Qed   #148638    6/25 peers    660 MiB chain  365 MiB db  0 bytes queue   13 MiB sync  RPC:  0 conn,    0 req/s,    0 µs
2018-07-23 12:35:59 UTC Syncing  #599252 0x6f98…1552     0.00 blk/s    0.0 tx/s    0 Mgas/s      0+    0 Qed    #15244    6/25 peers    660 MiB chain  365 MiB db  0 bytes queue   13 MiB sync  RPC:  0 conn,    0 req/s,    0 µs
2018-07-23 12:36:09 UTC Syncing  #599252 0x6f98…1552     0.00 blk/s    0.0 tx/s    0 Mgas/s      0+    0 Qed    #42903    6/25 peers    660 MiB chain  365 MiB db  0 bytes queue   13 MiB sync  RPC:  0 conn,    0 req/s,    0 µs
2018-07-23 12:36:19 UTC Syncing  #599252 0x6f98…1552     0.00 blk/s    0.0 tx/s    0 Mgas/s      0+    0 Qed    #24321    5/25 peers    660 MiB chain  365 MiB db  0 bytes queue   12 MiB sync  RPC:  0 conn,    0 req/s,    0 µs
2018-07-23 12:36:29 UTC Syncing  #599252 0x6f98…1552     0.00 blk/s    0.0 tx/s    0 Mgas/s      0+    0 Qed    #83130    6/25 peers    660 MiB chain  365 MiB db  0 bytes queue   13 MiB sync  RPC:  0 conn,    0 req/s,    0 µs
2018-07-23 12:36:39 UTC Syncing  #599252 0x6f98…1552     0.00 blk/s    0.0 tx/s    0 Mgas/s      0+    0 Qed    #57728    6/25 peers    660 MiB chain  365 MiB db  0 bytes queue   12 MiB sync  RPC:  0 conn,    0 req/s,    0 µs
2018-07-23 12:36:49 UTC Syncing  #599252 0x6f98…1552     0.00 blk/s    0.0 tx/s    0 Mgas/s      0+    0 Qed    #80588    6/25 peers    660 MiB chain  365 MiB db  0 bytes queue   13 MiB sync  RPC:  0 conn,    0 req/s,    0 µs
2018-07-23 12:36:59 UTC Syncing  #599252 0x6f98…1552     0.00 blk/s    0.0 tx/s    0 Mgas/s      0+    0 Qed   #103703    6/25 peers    660 MiB chain  365 MiB db  0 bytes queue   12 MiB sync  RPC:  0 conn,    0 req/s,    0 µs
2018-07-23 12:37:09 UTC Syncing  #599252 0x6f98…1552     0.00 blk/s    0.0 tx/s    0 Mgas/s      0+    0 Qed    #90862    6/25 peers    660 MiB chain  365 MiB db  0 bytes queue   12 MiB sync  RPC:  0 conn,    0 req/s,    0 µs
2018-07-23 12:37:19 UTC Syncing  #599252 0x6f98…1552     0.00 blk/s    0.0 tx/s    0 Mgas/s      0+    0 Qed    #67636    6/25 peers    660 MiB chain  365 MiB db  0 bytes queue   13 MiB sync  RPC:  0 conn,    0 req/s,    0 µs

The configuration is

[parity]
chain="ropsten"

[network]
bootnodes = ["enode://51e5befb0984036fcab8d14908ac2afa75febe9f1d45a9496c8257afc032ad6125918933c80de5901bd9333e1bcd9fe9ff3d91d1f89ce9d15c0508fdf73b2287@54.37.84.104:30303","enode://30b7ab30a01c124a6cceca36863ece12c4f5fa68e3ba9b0b51407ccc002eeed3b3102d20a88f1c1d3c3154e2449317b8ef95090e77b312d5cc39354f86d5d606@52.176.7.10:30303"]

[rpc]
interface = "all"

[footprint]
tracing = "on"
pruning = "archive"
pruning_memory = 8000
pruning_history = 4000
cache_size_db = 4000
cache_size_blocks = 4000
cache_size_queue = 4000
cache_size_state = 4000
db_compaction = "ssd"
scale_verifiers = true
num_verifiers = 64
cache_size = 32000

The detailed log with -l sync is here

[luchenyuxx]

This won't happen in latest stable version Parity/v1.11.7-stable-085035f-20180717/x86_64-linux-gnu/rustc1.27.1

[Tbaut]

I believe that the following do not apply in archive mode

pruning_memory = 8000
pruning_history = 4000

How did you determine the other config params? Is your bootnode online (you can verify it with reserved-peers and reserved-only) ?

Could you relaunch the node with -l sync and post some logs here?

[luchenyuxx]

@Tbaut
I didn't use reserved-peers or reserved-only.
Other params are used to increase the performance. I make it use a lot of memory since I have very powerful machine with 64G memory.
The log with -l sync is provided. Look at the last line.

The detailed log with -l sync is here

[Tbaut]

Thanks for the logs, I missed them. It looks like the peers you have are not sufficient. I was asking you to test your bootnode, to see if it was up and running and could provide you with the blocks you need. Alternatively, I'd suggest to add the bootnodes we use:

	"nodes": [
		"enode://6332792c4a00e3e4ee0926ed89e0d27ef985424d97b6a45bf0f23e51f0dcb5e66b875777506458aea7af6f9e4ffb69f43f3778ee73c81ed9d34c51c4b16b0b0f@52.232.243.152:30303",
		"enode://94c15d1b9e2fe7ce56e458b9a3b672ef11894ddedd0c6f247e0f1d3487f52b66208fb4aeb8179fce6e3a749ea93ed147c37976d67af557508d199d9594c35f09@192.81.208.223:30303",
		"enode://30b7ab30a01c124a6cceca36863ece12c4f5fa68e3ba9b0b51407ccc002eeed3b3102d20a88f1c1d3c3154e2449317b8ef95090e77b312d5cc39354f86d5d606@52.176.7.10:30303",
		"enode://865a63255b3bb68023b6bffd5095118fcc13e79dcf014fe4e47e065c350c7cc72af2e53eff895f11ba1bbb6a2b33271c1116ee870f266618eadfc2e78aa7349c@52.176.100.77:30303"
],

[luchenyuxx]

@Tbaut Thank you for the response. For the boot nodes, I actually used the ones I found in go-ethereum repository, the same as you provided.
Please note that it works on stable version with the same configuration.

[Tbaut]

@5chdn do you have any spare node to try to reproduce this?

[5chdn]

This is ugly if true.

@Tbaut I fully synced no-warp nodes 2.0 and 2.1 without any issue. Might be related to the archive?

[Tbaut]

I can reproduce.. I'm blocked at 599180 (edit 599196 now after a couple hours).
launched with: --chain ropsten --tracing on --pruning archive --log-file ~/parity.log

2018-07-27 09:59:26 UTC Syncing  #599180 0x1de5…7605     0.00 blk/s    0.0 tx/s    0 Mgas/s      0+    0 Qed   #599178    5/1024 peers    776 MiB chain  365 MiB db  0 bytes queue  114 MiB sync  RPC:  0 conn,    2 req/s, 2869 µs

[5chdn]

escalating

[Tbaut]

From Riot Support channel by @ansermino
Reproduced on Mainnet using the following configuration: https://gist.github.com/ansermino/4557597c167e81d63638eff1f7bcbcb0

Logs: https://gist.github.com/ansermino/b0ed2105b8e404dbeee6189810dca99a

[luchenyuxx]

By the way, it also happened to me on main net, with the same configuration.

[computerality]

An assert happens at a nearby block number on mainnet when running with --fast-db as reported in #9180

[clowestab]

Just wanted to check in on the status/cause of this issue. Are there any updates to share?

[cheme]

I started a sync with @Tbaut last configuration, and as @computerality said, I ran into #9180 near your just before your stuck block, with paritytech/parity-common#38 build it goes past those blocks and continue syncing.

[andresilva]

Should be fixed in #9525.

[5chdn]

and related to #9549 #9526