Syncing block that is already imported

[phahulin]

I'm running:

• Which Parity version?: 1.11.8
• Which operating system?: Linux
• How installed?: via binaries
• Are you fully synchronized?: yes
• Which network are you connected to?: core
• Did you try to restart the node?: yes

Parity would sometime sync blocks that it has already imported (e.g. 4142114)

2018-08-13 03:39:20 UTC Imported #4142113 0xfa38…3c97 (1 txs, 0.02 Mgas, 0 ms, 0.67 KiB)
2018-08-13 03:39:25 UTC Imported #4142114 0x810f…a43e (1 txs, 0.02 Mgas, 0 ms, 0.67 KiB)
2018-08-13 03:39:30 UTC Syncing #4142114 0x810f…a43e     0 blk/s    0 tx/s   0 Mgas/s      0+    0 Qed  #4142084   39/50 peers      3 MiB chain   88 MiB db  0 bytes queu
e    2 MiB sync  RPC:  0 conn, 51 req/s, 140 µs
2018-08-13 03:39:30 UTC Imported #4142115 0xb566…7098 (0 txs, 0.00 Mgas, 0 ms, 0.57 KiB)

We noticed that by increased number of alerts from our monitoring system, since transition to Syncing... results in /api/health endpoint going HTTP 412 Precondition failed.

[Tbaut]

Do I understand well that /api/health answers HTTP 412 Precondition failed every time the node is syncing?

[phahulin]

I guess that it reports HTTP 412 every time api health is not OK, including syncing
https://github.com/paritytech/parity-ethereum/blob/v1.11.8/dapps/src/api/api.rs#L85

What I'm seeing directly is that since upgrade to 1.11.8 from 1.10.6 we have a lot of alerts that node health is not ok. The first thing I see in logs is that nodes periodically go into syncing, esp. strange is when they try to sync a block they've already imported

[phahulin]

Fresh example:

10:26:41 UTC

HTTP/1.1 412 Precondition Failed
{"Ok":{"peers":{"status":"ok","message":"","details":[45,50]},"sync":{"status":"needsAttention","message":"Your node is still syncing, the values you see might be outdated. Wait until it's fully synced.","details":true},"time":{"status":"ok","message":"","details":192}}}

From logs (server is in EDT):

2018-08-13 06:26:40  Imported #4146873 0xa515…3e01 (0 txs, 0.00 Mgas, 0 ms, 0.57 KiB)
2018-08-13 06:26:44  Syncing #4146873 0xa515…3e01     0 blk/s    0 tx/s   0 Mgas/s      0+    0 Qed  #4143623   45/50 peers      6 MiB chain   88 MiB db  0 bytes queue    2 MiB sync  RPC:  0 conn,  1 req/s,  75 µs

[phahulin]

We downgraded nodes from one of public rpc pools to 1.10.6 and both the Syncing message in logs and alerts stopped there. Nodes from another pool running on 1.11.8 still have it.

[phahulin]

Can this be upgraded to something other than "Z1-question"? I opened a few issues in the past week because we actually started to experience problems after transition 1.10.6 -> 1.11.8

[Tbaut]

Not entirely sure if this is a bug. We would need to know why the node is syncing. It could be due to a reorg.

[phahulin]

How do I check for that? Reorg is usually accompanied by a corresponding message in logs:

2018-08-14 09:00:20 UTC Reorg to #4162684 0xd13d…0f56 (0x6f12…c0cc #4162683 0xa6ba…3577 )

And I see those messages still happen occasionally on 1.10.6, but I don't see Syncing messages anymore.

[andresilva]

I think this is a duplicate of #9428 (or the other way around since this one is older). I'm looking into it.

[andresilva]

@phahulin This should be mostly fixed by #9552. It may still happen when ancient block import is running, since it may stall new block import and temporarily cause the node to go into syncing mode.

[jam10o-new]

closing as stale and probably already fixed, @phahulin please let us know if that isn't the case