Bug: electrs stuck on 100%/IO usage due to rocksdb:low

[dpc]

Describe the bug

I'm running electrs, just to have it around. Today I've noticed that my secondary desktop CPU fan constantly spins, and turns out electrs's rocksdb:low thread just does something that seems not caused by any requests or any new blocks. After a couple of minutes, I restarted it, didn't help, then after few more minutes I shut it down.

It seems like some strange rocksdb behavior to me, which worries me because we're using rocksdb in Fedimint as well.

Electrs version

0.10.8

To Reproduce

No idea. On my primary desktop I have an instance of electrs and that one is idle. Same version, same config.

Expected behavior
NA

Configuration
It's a rather vanilla electrs from nix-bitcoin, electrs.toml contains only auth.

No error messages.

System running electrs
NixOS

Electrum client
No clients are using it.

Additional context
Add any other context about the problem here.

[romanz]

Thanks for reporting this issue!

IIUC, it is possible that electrs is running background RocksDB compaction:
https://github.com/facebook/rocksdb/wiki/RocksDB-Tuning-Guide#parallelism-options
https://github.com/facebook/rocksdb/wiki/Thread-Pool

Could you please watch the RocksDB directory (e.g. using watch ls -lt db/bitcoin/)?
If it is compacting, you should see new SST files created while the rocksdb:low thread is running.

[romanz]

BTW, if you are using a SSD for RocksDB storage, I would suggest trying latest electrs with db_parallelism set to >1 (introduced in #1138).

[Kixunil]

Also for completeness, electrs is not intended as a public server so if you happen to have its port exposed it might have gotten some nasty packet. Though I think it's unlikely.

[dpc]

Could you please watch the RocksDB directory (e.g. using watch ls -lt db/bitcoin/)?
If it is compacting, you should see new SST files created while the rocksdb:low thread is running.

It does produce new ssts rapidly:

total 57933612
-rw-r--r-- 1 electrs electrs  29335255 Feb  7 09:53 356671.sst
-rw-r--r-- 1 electrs electrs 270752513 Feb  7 09:53 356670.sst
-rw-r--r-- 1 electrs electrs    176374 Feb  7 09:53 LOG
-rw-r--r-- 1 electrs electrs 270754847 Feb  7 09:53 356669.sst
-rw-r--r-- 1 electrs electrs 270754920 Feb  7 09:52 356668.sst
-rw-r--r-- 1 electrs electrs 270750428 Feb  7 09:52 356667.sst
-rw-r--r-- 1 electrs electrs 270752016 Feb  7 09:52 356666.sst
-rw-r--r-- 1 electrs electrs 270756682 Feb  7 09:52 356665.sst
-rw-r--r-- 1 electrs electrs 270754840 Feb  7 09:51 356664.sst
-rw-r--r-- 1 electrs electrs 270751564 Feb  7 09:51 356663.sst
-rw-r--r-- 1 electrs electrs 270750340 Feb  7 09:51 356662.sst
-rw-r--r-- 1 electrs electrs 270753578 Feb  7 09:51 356661.sst
-rw-r--r-- 1 electrs electrs 270754827 Feb  7 09:50 356660.sst
-rw-r--r-- 1 electrs electrs 270757112 Feb  7 09:50 356659.sst
-rw-r--r-- 1 electrs electrs 270752416 Feb  7 09:50 356658.sst
-rw-r--r-- 1 electrs electrs 270753716 Feb  7 09:50 356657.sst
-rw-r--r-- 1 electrs electrs 270753187 Feb  7 09:49 356656.sst
-rw-r--r-- 1 electrs electrs 270754195 Feb  7 09:49 356655.sst
-rw-r--r-- 1 electrs electrs 270756131 Feb  7 09:49 356654.sst
-rw-r--r-- 1 electrs electrs 270753855 Feb  7 09:48 356653.sst
-rw-r--r-- 1 electrs electrs 270752396 Feb  7 09:48 356652.sst
-rw-r--r-- 1 electrs electrs 270751543 Feb  7 09:48 356651.sst
-rw-r--r-- 1 electrs electrs 270757401 Feb  7 09:48 356650.sst
-rw-r--r-- 1 electrs electrs 270752947 Feb  7 09:47 356643.sst
-rw-r--r-- 1 electrs electrs     23904 Feb  7 09:47 MANIFEST-356630

The whole dataset is around 55G, and in 5 minutes since it was started it rewrote like 6GB.Yesterday it must have been sitting there like that for 15 minutes while I was waiting, and I walked into this room after a whole day of not being there. So either I was extremely (un)lucky, or it seems like it might be doing this ... a little too much?

I'm going to give it some time now see if it wraps it up.

[dpc]

Ok... Around 15 minutes later it was done, rewriting 78 270MB files total (plus the ones it did yesterday, which judging by the timestamps was another 70).

I guess that's what rocksdb does. I learned something. I guess I was expecting some more ... lazy approach for some reason.