aionnetwork / aion

Aion Network - Java Implementation
https://theoan.com/
MIT License
337 stars 112 forks source link

Redundant import attempts #474

Closed AlexandraRoatis closed 4 years ago

AlexandraRoatis commented 6 years ago

I'm running:

  • Which Aion version?: 0.2.6.2f8fdfa
  • Which operating system?: Linux
  • Which distributor and version?: Ubuntu 16.04.4 LTS
  • How installed?: via binaries
  • Are you fully synchronized?: yes
  • Did you try to restart the node?: yes

Issue description: Once fully synced, the sync-ib thread keeps trying to import blocks already imported by the p2p-worker threads leading to many redundant import attempts. Example output shown below:

18-05-10 15:36:21.746 INFO  SYNC [p2p-worker-0]: <import-status: node = c33d5a, hash = 8086ae, number = 136186, txs = 0, result = IMPORTED_BEST, time elapsed = 1 ms>
18-05-10 15:36:22.837 INFO  SYNC [sync-ib]: <import-status: node = 1ab772, hash = 8086ae, number = 136186, txs = 0, result = EXIST, time elapsed = 0 ms>
18-05-10 15:36:26.556 INFO  SYNC [p2p-worker-2]: <import-status: node = e84149, hash = b51022, number = 136187, txs = 2, result = IMPORTED_BEST, time elapsed = 2 ms>
18-05-10 15:36:26.862 INFO  SYNC [sync-ib]: <import-status: node = 47c11b, hash = b51022, number = 136187, txs = 2, result = EXIST, time elapsed = 0 ms>
18-05-10 15:36:38.046 INFO  SYNC [p2p-worker-2]: <import-status: node = 698d14, hash = c5213c, number = 136188, txs = 0, result = IMPORTED_BEST, time elapsed = 1 ms>
18-05-10 15:36:38.848 INFO  SYNC [sync-ib]: <import-status: node = 7e8846, hash = c5213c, number = 136188, txs = 0, result = EXIST, time elapsed = 0 ms>
18-05-10 15:37:19.458 INFO  SYNC [p2p-worker-3]: <import-status: node = e84149, hash = 7a5b41, number = 136189, txs = 0, result = IMPORTED_BEST, time elapsed = 1 ms>
18-05-10 15:37:20.783 INFO  SYNC [sync-ib]: <import-status: node = 588d42, hash = 7a5b41, number = 136189, txs = 0, result = EXIST, time elapsed = 0 ms>
18-05-10 15:37:26.712 INFO  SYNC [p2p-worker-3]: <import-status: node = c33d22, hash = 0b7dd3, number = 136190, txs = 20, result = IMPORTED_BEST, time elapsed = 9 ms>
18-05-10 15:37:27.146 INFO  SYNC [sync-ib]: <import-status: node = 47c11b, hash = 0b7dd3, number = 136190, txs = 20, result = EXIST, time elapsed = 0 ms>
18-05-10 15:37:46.673 INFO  SYNC [p2p-worker-2]: <import-status: node = c33d22, hash = 0fcaa2, number = 136191, txs = 0, result = IMPORTED_BEST, time elapsed = 2 ms>
18-05-10 15:37:46.910 INFO  SYNC [sync-ib]: <import-status: node = 698d14, hash = 0fcaa2, number = 136191, txs = 0, result = EXIST, time elapsed = 0 ms>
AlexandraRoatis commented 5 years ago

As of version 0.3.1.6a9c49e the redundent imports look as below:

18-11-21 09:49:09.606 INFO  SYNC [p2p-worker-28]: <import-status: node = d38ee6, hash = 14355e, number = 1737493, txs = 0, result = IMPORTED_BEST, time elapsed = 1 ms>
18-11-21 09:49:12.413 INFO  SYNC [p2p-worker-9]: <import-status: node = 6e7715, hash = a2b188, number = 1737494, txs = 6, result = IMPORTED_BEST, time elapsed = 3 ms>
18-11-21 09:49:15.602 INFO  SYNC [p2p-worker-8]: <import-status: node = c33d22, hash = 174ee7, number = 1737495, txs = 0, result = IMPORTED_BEST, time elapsed = 1 ms>
18-11-21 09:49:16.675 INFO  SYNC [p2p-worker-18]: <import-status: node = 6e7715, hash = 814682, number = 1737496, txs = 0, result = INVALID_BLOCK, time elapsed = 0 ms>
18-11-21 09:49:23.324 INFO  SYNC [sync-ib]: <import-status: node = 6068a7, hash = 576dc1, number = 1737480, txs = 0, result = EXIST, time elapsed = 0 ms>
18-11-21 09:49:23.324 INFO  SYNC [sync-ib]: <import-status: node = 6068a7, hash = d1c9bf, number = 1737481, txs = 0, result = EXIST, time elapsed = 0 ms>
18-11-21 09:49:23.324 INFO  SYNC [sync-ib]: <import-status: node = 6068a7, hash = 129111, number = 1737482, txs = 0, result = EXIST, time elapsed = 0 ms>
18-11-21 09:49:23.324 INFO  SYNC [sync-ib]: <import-status: node = 6068a7, hash = 52c77a, number = 1737483, txs = 1, result = EXIST, time elapsed = 0 ms>
18-11-21 09:49:23.324 INFO  SYNC [sync-ib]: <import-status: node = 6068a7, hash = cd6343, number = 1737484, txs = 0, result = EXIST, time elapsed = 0 ms>
18-11-21 09:49:23.324 INFO  SYNC [sync-ib]: <import-status: node = 6068a7, hash = 92a76f, number = 1737485, txs = 2, result = EXIST, time elapsed = 0 ms>
18-11-21 09:49:23.324 INFO  SYNC [sync-ib]: <import-status: node = 6068a7, hash = 99e28e, number = 1737486, txs = 1, result = EXIST, time elapsed = 0 ms>
18-11-21 09:49:23.324 INFO  SYNC [sync-ib]: <import-status: node = 6068a7, hash = 1f4151, number = 1737487, txs = 0, result = EXIST, time elapsed = 0 ms>
18-11-21 09:49:23.324 INFO  SYNC [sync-ib]: <import-status: node = 6068a7, hash = 7dd101, number = 1737488, txs = 1, result = EXIST, time elapsed = 0 ms>
18-11-21 09:49:23.325 INFO  SYNC [sync-ib]: <import-status: node = 6068a7, hash = 0f380f, number = 1737489, txs = 0, result = EXIST, time elapsed = 1 ms>
18-11-21 09:49:23.325 INFO  SYNC [sync-ib]: <import-status: node = 6068a7, hash = dbb46e, number = 1737490, txs = 0, result = EXIST, time elapsed = 0 ms>
18-11-21 09:49:23.325 INFO  SYNC [sync-ib]: <import-status: node = 6068a7, hash = e5e699, number = 1737491, txs = 1, result = EXIST, time elapsed = 0 ms>
18-11-21 09:49:23.325 INFO  SYNC [sync-ib]: <import-status: node = 6068a7, hash = 4338b5, number = 1737492, txs = 0, result = EXIST, time elapsed = 0 ms>
18-11-21 09:49:23.325 INFO  SYNC [sync-ib]: <import-status: node = 6068a7, hash = 14355e, number = 1737493, txs = 0, result = EXIST, time elapsed = 0 ms>
18-11-21 09:49:23.325 INFO  SYNC [sync-ib]: <import-status: node = 6068a7, hash = a2b188, number = 1737494, txs = 6, result = EXIST, time elapsed = 0 ms>
18-11-21 09:49:23.325 INFO  SYNC [sync-ib]: <import-status: node = 6068a7, hash = 174ee7, number = 1737495, txs = 0, result = EXIST, time elapsed = 0 ms>
18-11-21 09:49:23.326 INFO  SYNC [sync-ib]: <import-status: node = 6068a7, hash = 814682, number = 1737496, txs = 0, result = IMPORTED_BEST, time elapsed = 1 ms>
18-11-21 09:49:27.338 INFO  SYNC [p2p-worker-19]: <import-status: node = 6068a7, hash = 14356d, number = 1737497, txs = 0, result = IMPORTED_BEST, time elapsed = 4 ms>
18-11-21 09:49:45.159 INFO  SYNC [p2p-worker-6]: <import-status: node = 6e7715, hash = 29127b, number = 1737498, txs = 0, result = IMPORTED_BEST, time elapsed = 1 ms>
18-11-21 09:49:53.059 INFO  SYNC [p2p-worker-27]: <import-status: node = 7901ba, hash = 01fdbc, number = 1737499, txs = 3, result = IMPORTED_BEST, time elapsed = 3 ms>
18-11-21 09:50:05.460 INFO  SYNC [p2p-worker-12]: <import-status: node = 6068a7, hash = 474bda, number = 1737500, txs = 0, result = IMPORTED_BEST, time elapsed = 1 ms>

There seems to be some correlation with the number of active peers. It is present for ~30 peers but not for ~ 10 peers.