FlushStateToDisk() takes more than 10 minutes #17397

2019-11-06T18:09:57Z [qt-init] Shutdown: In progress...
2019-11-06T18:09:57Z [msghand] msghand thread exit
2019-11-06T18:09:57Z [net] net thread exit
2019-11-06T18:09:57Z [scheduler] scheduler thread interrupt
2019-11-06T18:09:58Z [shutoff] Dumped mempool: 0.016041s to copy, 0.043132s to dump
2019-11-06T18:09:58Z [shutoff] FlushStateToDisk: write coins cache to disk (65649194 coins, 9493571kB) started
2019-11-06T18:23:09Z [shutoff] FlushStateToDisk: write coins cache to disk (65649194 coins, 9493571kB) completed (791.57s)
2019-11-06T18:23:09Z [shutoff] FlushStateToDisk: write coins cache to disk (0 coins, 1027997kB) started
2019-11-06T18:23:09Z [shutoff] FlushStateToDisk: write coins cache to disk (0 coins, 1027997kB) completed (0.07s)
2019-11-06T18:23:09Z [shutoff] Shutdown: done

I understand that cache is about 9.5 GB, nevertheless, is it expected flush duration?

Configuration:

• datadir resides on SSD
• blocksdir resides on HDD
• master (86771d431054efb780a2be4a83a6952530c14875)

To give a clearer idea of the hardware you're using, would you mind installing bitcoinperf, running bitcoinperf-hwinfo, and pasting the output table here? Alternatively could you install fio and run a command like

fio --randrepeat=1 --ioengine=libaio --direct=1 --gtod_reduce=1 \
  --name=test --filename=$PATH_TO_DATADIR/test.io --bs=4k --iodepth=64 \
  --size=180M --time_based=1 --runtime=20 --readwrite=randrw --rwmixread=75

to give us an idea of the IO speed of your disk?

To say something sensible about this we need to know what hardware. What CPU, what OS?

To give a clearer idea of the hardware you're using, would you mind installing bitcoinperf, running bitcoinperf-hwinfo, and pasting the output table here?

$ bitcoinperf-hwinfo
| key                                   | value                                     |
| -----------------------------------   | ---------------------------------------   |
| hostname                              | redcat                                    |
| cpu_model_name                        | Intel(R) Core(TM) i3-7100 CPU @ 3.90GHz   |
| ram_gb                                | 15.579715728759766                        |
| os                                    | ['Linux Mint', '19.2', 'tina']            |
| arch                                  | x86_64                                    |
| kernel                                | 4.15.0-66-generic                         |
| read_iops (/home/hebasto/.bitcoin)    | 3148                                      |
| write_iops (/home/hebasto/.bitcoin)   | 1046                                      |

Alternatively could you install fio...

$ fio --randrepeat=1 --ioengine=libaio --direct=1 --gtod_reduce=1 --name=test --filename=/home/hebasto/.bitcoin/test.io --bs=4k --iodepth=64   --size=180M --time_based=1 --runtime=20 --readwrite=randrw --rwmixread=75
test: (g=0): rw=randrw, bs=(R) 4096B-4096B, (W) 4096B-4096B, (T) 4096B-4096B, ioengine=libaio, iodepth=64
fio-3.1
Starting 1 process
Jobs: 1 (f=1): [m(1)][100.0%][r=13.0MiB/s,w=4440KiB/s][r=3575,w=1110 IOPS][eta 00m:00s]
test: (groupid=0, jobs=1): err= 0: pid=18611: Thu Nov  7 22:49:39 2019
   read: IOPS=3223, BW=12.6MiB/s (13.2MB/s)(252MiB/20015msec)
   bw (  KiB/s): min= 9536, max=15744, per=100.00%, avg=12893.05, stdev=1626.20, samples=40
   iops        : min= 2384, max= 3936, avg=3223.25, stdev=406.57, samples=40
  write: IOPS=1070, BW=4283KiB/s (4386kB/s)(83.7MiB/20015msec)
   bw (  KiB/s): min= 3168, max= 5416, per=100.00%, avg=4283.20, stdev=549.23, samples=40
   iops        : min=  792, max= 1354, avg=1070.80, stdev=137.31, samples=40
  cpu          : usr=2.58%, sys=6.70%, ctx=52091, majf=0, minf=8
  IO depths    : 1=0.1%, 2=0.1%, 4=0.1%, 8=0.1%, 16=0.1%, 32=0.1%, >=64=99.9%
     submit    : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
     complete  : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.1%, >=64=0.0%
     issued rwt: total=64518,21432,0, short=0,0,0, dropped=0,0,0
     latency   : target=0, window=0, percentile=100.00%, depth=64

Run status group 0 (all jobs):
   READ: bw=12.6MiB/s (13.2MB/s), 12.6MiB/s-12.6MiB/s (13.2MB/s-13.2MB/s), io=252MiB (264MB), run=20015-20015msec
  WRITE: bw=4283KiB/s (4386kB/s), 4283KiB/s-4283KiB/s (4386kB/s-4386kB/s), io=83.7MiB (87.8MB), run=20015-20015msec

Disk stats (read/write):
  sda: ios=63291/21314, merge=830/255, ticks=943608/316608, in_queue=1260628, util=99.52%

To say something sensible about this we need to know what hardware. What CPU, what OS?

$ inxi -SCD
System:    Host: redcat Kernel: 4.15.0-66-generic x86_64 bits: 64 Desktop: Cinnamon 4.2.4 Distro: Linux Mint 19.2 Tina 
CPU:       Topology: Dual Core model: Intel Core i3-7100 bits: 64 type: MT MCP L2 cache: 3072 KiB 
           Speed: 3900 MHz min/max: 800/3900 MHz Core speeds (MHz): 1: 3900 2: 3900 3: 3900 4: 3900 
Drives:    Local Storage: total: 875.64 GiB used: 611.86 GiB (69.9%) 
           ID-1: /dev/sda model: SPCC Solid State Disk size: 111.79 GiB 
           ID-2: /dev/sdb vendor: Hitachi model: HCS721050CLA362 size: 298.09 GiB 
           ID-3: /dev/sdc vendor: Western Digital model: WD5003ABYZ-011FA0 size: 465.76 GiB

The other issue with FlushStateToDisk() is that it is run upon shutdown of the process, which if shutting down the OS, means either having to wait the 10 minutes, or forcefully killing the process. Perhaps it could be an option to not FlushStateToDisk() upon shutdown?

@rebroad

The other issue with FlushStateToDisk() is that it is run upon shutdown of the process, which if shutting down the OS, means either having to wait the 10 minutes, or forcefully killing the process.

You may think Bitcoin Core blocking system shutdown is annoying, but as a user (who just wants to sync as fast as possible, rather than worrying about system shutdown) I on the contrary think that FlushStateToDisk should be executed as less frequently as possible, best to not do it at all except shutting down, so that the entire UTXO jobs could be done totally in RAM rather than on hard drive.

I think options with fancy words like "turbo, heavy mode" vs "agile, light mode" can let the user to choose how the cache should behave.

Perhaps it could be an option to not FlushStateToDisk() upon shutdown?

Frankly speaking I don't understand this point - doesn't this mean the sync progress would (partially) lose?

Okay, I'm adding a new issue #19742

Closing as this issue depends on hardware (i.e., SSD) quality.