Provide better feedback for syncing and operations

[WhoSoup]

Just wanted to see how long it would take to sync from the open node. The status report of syncing happens every 50 blocks, but the time it takes to process a single block from the open node is between ~3 and ~10 seconds. It didn't give me the first status update until 4:30 minutes were elapsed:

time="2019-10-06T09:28:33+02:00" level=info msg="Listening on :8070..."
time="2019-10-06T09:28:42+02:00" level=debug msg=synced height=206422 took=8.8035035s
time="2019-10-06T09:28:49+02:00" level=debug msg=synced height=206423 took=6.7853881s
time="2019-10-06T09:28:53+02:00" level=debug msg=synced height=206424 took=3.7572149s
time="2019-10-06T09:28:57+02:00" level=debug msg=synced height=206425 took=4.5542605s
time="2019-10-06T09:29:18+02:00" level=debug msg=synced height=206426 took=3.7092121s
time="2019-10-06T09:29:22+02:00" level=debug msg=synced height=206427 took=3.8902225s
time="2019-10-06T09:29:26+02:00" level=debug msg=synced height=206428 took=4.0652325s
time="2019-10-06T09:29:29+02:00" level=debug msg=synced height=206429 took=3.4901997s
time="2019-10-06T09:29:33+02:00" level=debug msg=synced height=206430 took=3.5952056s
time="2019-10-06T09:29:36+02:00" level=debug msg=synced height=206431 took=3.4221957s
time="2019-10-06T09:29:40+02:00" level=debug msg=synced height=206432 took=3.9762274s
time="2019-10-06T09:29:44+02:00" level=debug msg=synced height=206433 took=3.1281789s
time="2019-10-06T09:29:47+02:00" level=debug msg=synced height=206434 took=3.198183s
time="2019-10-06T09:29:51+02:00" level=debug msg=synced height=206435 took=3.9082235s
time="2019-10-06T09:29:55+02:00" level=debug msg=synced height=206436 took=4.3762503s
time="2019-10-06T09:29:59+02:00" level=debug msg=synced height=206437 took=3.8482201s
time="2019-10-06T09:30:09+02:00" level=debug msg=synced height=206438 took=10.5626042s
time="2019-10-06T09:30:14+02:00" level=debug msg=synced height=206439 took=4.2612437s
time="2019-10-06T09:30:18+02:00" level=debug msg=synced height=206440 took=3.9982287s
time="2019-10-06T09:30:23+02:00" level=debug msg=synced height=206441 took=4.8192757s
time="2019-10-06T09:30:27+02:00" level=debug msg=synced height=206442 took=4.2992459s
time="2019-10-06T09:30:30+02:00" level=debug msg=synced height=206443 took=3.2961886s
time="2019-10-06T09:30:34+02:00" level=debug msg=synced height=206444 took=3.9352251s
time="2019-10-06T09:30:38+02:00" level=debug msg=synced height=206445 took=4.3222472s
time="2019-10-06T09:30:42+02:00" level=debug msg=synced height=206446 took=3.741214s
time="2019-10-06T09:31:13+02:00" level=debug msg=synced height=206447 took=4.4012518s
time="2019-10-06T09:31:17+02:00" level=debug msg=synced height=206448 took=3.8692214s
time="2019-10-06T09:31:21+02:00" level=debug msg=synced height=206449 took=4.0612322s
time="2019-10-06T09:31:25+02:00" level=debug msg=synced height=206450 took=4.6522661s
time="2019-10-06T09:31:29+02:00" level=debug msg=synced height=206451 took=3.724213s
time="2019-10-06T09:31:32+02:00" level=debug msg=synced height=206452 took=2.7751587s
time="2019-10-06T09:31:35+02:00" level=debug msg=synced height=206453 took=3.3431912s
time="2019-10-06T09:31:39+02:00" level=debug msg=synced height=206454 took=3.5502031s
time="2019-10-06T09:31:43+02:00" level=debug msg=synced height=206455 took=4.0952343s
time="2019-10-06T09:31:46+02:00" level=debug msg=synced height=206456 took=3.7292133s
time="2019-10-06T09:31:51+02:00" level=debug msg=synced height=206457 took=4.3242474s
time="2019-10-06T09:31:55+02:00" level=debug msg=synced height=206458 took=4.3192471s
time="2019-10-06T09:31:59+02:00" level=debug msg=synced height=206459 took=3.9082235s
time="2019-10-06T09:32:08+02:00" level=debug msg=synced height=206460 took=9.2275278s
time="2019-10-06T09:32:13+02:00" level=debug msg=synced height=206461 took=4.6022632s
time="2019-10-06T09:32:18+02:00" level=debug msg=synced height=206462 took=5.2933028s
time="2019-10-06T09:32:22+02:00" level=debug msg=synced height=206463 took=3.8262188s
time="2019-10-06T09:32:28+02:00" level=debug msg=synced height=206464 took=5.9693415s
time="2019-10-06T09:32:33+02:00" level=debug msg=synced height=206465 took=4.5802619s
time="2019-10-06T09:32:37+02:00" level=debug msg=synced height=206466 took=4.8542776s
time="2019-10-06T09:32:42+02:00" level=debug msg=synced height=206467 took=4.6242645s
time="2019-10-06T09:32:46+02:00" level=debug msg=synced height=206468 took=4.4832564s
time="2019-10-06T09:32:51+02:00" level=debug msg=synced height=206469 took=4.510258s
time="2019-10-06T09:32:55+02:00" level=debug msg=synced height=206470 took=4.2022404s
time="2019-10-06T09:33:00+02:00" level=debug msg=synced height=206471 took=4.7092693s
time="2019-10-06T09:33:00+02:00" level=info msg="sync stats" avg=4.467575534s elapsed=4m26.5082434s height=206471 left=8h12m46.414884012s syncing-to=213089

I think we should make it time based rather than block based or at least caution people that it's going to take a while for the first message to show up if they're syncing from the open node.

[Emyrk]

I was thinking about this too. I put this in real quick to have something, but we should improve it. The other downside is that the sync routine doesn't check the new factomd height. So after 8h, you still have 8hr worth of blocks to sync.

[WhoSoup]

We should also provide a message when the node finished syncing and enters normal operation, possibly a few status updates here and there during normal operations. The question "is my node finished syncing" pops up frequently in the #support channel

[Emyrk]

That is a good idea yea.

[WhoSoup]

fix for this in #69