abracadaniel / cardano-pool-docker

Docker container for setting up and running a Cardano Stake Pool
164 stars 62 forks source link

Extremely slow syncing with blockchain #14

Closed robinboening closed 3 years ago

robinboening commented 3 years ago

Hey there!

Thank you for dockerizing and open sourcing your work!

I set up the block producing node and the relay on two VPS and started the registration container locally.

The blockchain sync in the registration container seems very slow to me. I don't know if thats normal, but I wouldn't think so.

Not only that the sync itself is really slow but it also interrupts every ~10min and I need to wait for it to continue for about ~10min. I am waiting for 1.5h just to get to 2%.

This might not be related to the dockerization, but I just wanted to bring it up because I know file access in mounted volumes are very slow (on Mac).

Do you know anything about that or have an idea/advice?

Thanks

robinboening commented 3 years ago

The node logs this

[309d7be5:cardano.node.ChainDB:Info:5] [2021-02-15 17:55:22.22 UTC] block replay progress (%) = 92.3
[309d7be5:cardano.node.ChainDB:Info:5] [2021-02-15 17:55:22.39 UTC] block replay progress (%) = 92.5
[309d7be5:cardano.node.ChainDB:Info:5] [2021-02-15 17:55:22.57 UTC] block replay progress (%) = 92.7
[309d7be5:cardano.node.ChainDB:Info:5] [2021-02-15 17:55:22.74 UTC] block replay progress (%) = 92.9
[309d7be5:cardano.node.ChainDB:Info:5] [2021-02-15 17:55:22.92 UTC] block replay progress (%) = 93.2
[309d7be5:cardano.node.ChainDB:Info:5] [2021-02-15 17:55:23.03 UTC] before next, messages elided = 388799
[309d7be5:cardano.node.ChainDB:Info:5] [2021-02-15 17:55:23.03 UTC] Replayed block: slot SlotNo 410398 of At (SlotNo 439830)
[309d7be5:cardano.node.ChainDB:Info:5] [2021-02-15 17:55:23.09 UTC] Replayed block: slot SlotNo 410399 of At (SlotNo 439830)
[309d7be5:cardano.node.ChainDB:Info:5] [2021-02-15 17:55:23.10 UTC] block replay progress (%) = 93.3
[309d7be5:cardano.node.ChainDB:Info:5] [2021-02-15 17:55:23.29 UTC] block replay progress (%) = 93.5
[309d7be5:cardano.node.ChainDB:Info:5] [2021-02-15 17:55:23.48 UTC] block replay progress (%) = 93.8
[309d7be5:cardano.node.ChainDB:Info:5] [2021-02-15 17:55:23.66 UTC] block replay progress (%) = 94.0
[309d7be5:cardano.node.ChainDB:Info:5] [2021-02-15 17:55:23.85 UTC] block replay progress (%) = 94.2
[309d7be5:cardano.node.ChainDB:Info:5] [2021-02-15 17:55:24.04 UTC] block replay progress (%) = 94.4
[309d7be5:cardano.node.ChainDB:Info:5] [2021-02-15 17:55:24.23 UTC] block replay progress (%) = 94.7
[309d7be5:cardano.node.ChainDB:Info:5] [2021-02-15 17:55:24.42 UTC] block replay progress (%) = 94.9
[309d7be5:cardano.node.ChainDB:Info:5] [2021-02-15 17:55:24.66 UTC] block replay progress (%) = 95.1
[309d7be5:cardano.node.ChainDB:Info:5] [2021-02-15 17:55:24.86 UTC] block replay progress (%) = 95.4
[309d7be5:cardano.node.ChainDB:Info:5] [2021-02-15 17:55:25.12 UTC] block replay progress (%) = 95.6
[309d7be5:cardano.node.ChainDB:Info:5] [2021-02-15 17:55:25.34 UTC] block replay progress (%) = 95.8
[309d7be5:cardano.node.ChainDB:Info:5] [2021-02-15 17:55:25.54 UTC] block replay progress (%) = 96.0
[309d7be5:cardano.node.ChainDB:Info:5] [2021-02-15 17:55:25.74 UTC] block replay progress (%) = 96.3
[309d7be5:cardano.node.ChainDB:Info:5] [2021-02-15 17:55:25.91 UTC] block replay progress (%) = 96.5
[309d7be5:cardano.node.ChainDB:Info:5] [2021-02-15 17:55:26.08 UTC] block replay progress (%) = 96.7
[309d7be5:cardano.node.ChainDB:Info:5] [2021-02-15 17:55:26.21 UTC] block replay progress (%) = 96.9
[309d7be5:cardano.node.ChainDB:Info:5] [2021-02-15 17:55:26.37 UTC] block replay progress (%) = 97.2
[309d7be5:cardano.node.ChainDB:Info:5] [2021-02-15 17:55:26.54 UTC] block replay progress (%) = 97.4
[309d7be5:cardano.node.ChainDB:Info:5] [2021-02-15 17:55:26.71 UTC] block replay progress (%) = 97.6
[309d7be5:cardano.node.ChainDB:Info:5] [2021-02-15 17:55:26.87 UTC] block replay progress (%) = 97.9
[309d7be5:cardano.node.ChainDB:Info:5] [2021-02-15 17:55:27.04 UTC] block replay progress (%) = 98.1
[309d7be5:cardano.node.ChainDB:Info:5] [2021-02-15 17:55:27.19 UTC] before next, messages elided = 410399
[309d7be5:cardano.node.ChainDB:Info:5] [2021-02-15 17:55:27.19 UTC] Replayed block: slot SlotNo 431998 of At (SlotNo 439830)
[309d7be5:cardano.node.ChainDB:Info:5] [2021-02-15 17:55:27.19 UTC] Replayed block: slot SlotNo 431999 of At (SlotNo 439830)
[309d7be5:cardano.node.ChainDB:Info:5] [2021-02-15 17:55:27.21 UTC] block replay progress (%) = 98.2
[309d7be5:cardano.node.ChainDB:Info:5] [2021-02-15 17:55:27.44 UTC] block replay progress (%) = 98.4
[309d7be5:cardano.node.ChainDB:Info:5] [2021-02-15 17:55:27.66 UTC] block replay progress (%) = 98.7
[309d7be5:cardano.node.ChainDB:Info:5] [2021-02-15 17:55:28.13 UTC] block replay progress (%) = 98.9
[309d7be5:cardano.node.ChainDB:Info:5] [2021-02-15 17:55:28.31 UTC] block replay progress (%) = 99.1
[309d7be5:cardano.node.ChainDB:Info:5] [2021-02-15 17:55:28.48 UTC] block replay progress (%) = 99.4
[309d7be5:cardano.node.ChainDB:Info:5] [2021-02-15 17:55:28.74 UTC] block replay progress (%) = 99.6
[309d7be5:cardano.node.ChainDB:Info:5] [2021-02-15 17:55:28.92 UTC] block replay progress (%) = 99.8
[309d7be5:cardano.node.ChainDB:Info:5] [2021-02-15 17:55:29.11 UTC] before next, messages elided = 431999
[309d7be5:cardano.node.ChainDB:Info:5] [2021-02-15 17:55:29.11 UTC] Replayed block: slot SlotNo 439830 of At (SlotNo 439830)
[309d7be5:cardano.node.ChainDB:Info:5] [2021-02-15 17:55:29.11 UTC] Opened lgr db

and the cli log shows this

Socket to node is functional.
slot 568436/21845295 2.60%

cardano-cli: Network.Socket.connect: <socket: 11>: does not exist (No such file or directory)
cardano-cli: Network.Socket.connect: <socket: 11>: does not exist (No such file or directory)
cardano-cli: Network.Socket.connect: <socket: 11>: does not exist (No such file or directory)
cardano-cli: Network.Socket.connect: <socket: 11>: does not exist (No such file or directory)
cardano-cli: Network.Socket.connect: <socket: 11>: does not exist (No such file or directory)
cardano-cli: Network.Socket.connect: <socket: 10>: does not exist (No such file or directory)
...

until it continues, around 10 or 20min later.

robinboening commented 3 years ago

I'll close the issue now as I think I found the issue causing this.

In case anyone is interested:

When I closed the right pane of the split tmux screen was getting faster. At least for a while but slowed down again... Then I noticed my docker engine was limited to 2 GB of memory. I increased to 8 GB and it seems to be working much better now.