rpc/rest/zmq: reduce LOCK(cs_main) scope: ~6 times as many requests per second #26308

pull andrewtoth wants to merge 6 commits into bitcoin:master from andrewtoth:no-lock-for-read-block changing 4 files +29 −28
  1. andrewtoth commented at 7:50 pm on October 13, 2022: contributor

    Picking up from #21006.

    After commit https://github.com/bitcoin/bitcoin/commit/ccd8ef65f93ed82a87cee634660bed3ac17d9eb5 it is no longer required to hold cs_main when calling ReadBlockFromDisk. This can be verified in master at https://github.com/bitcoin/bitcoin/blob/master/src/node/blockstorage.cpp#L755. Same can be seen for UndoReadFromDisk https://github.com/bitcoin/bitcoin/blob/master/src/node/blockstorage.cpp#L485.

    The first commit moves ReadBlockFromDisk outside the lock scope in rest_block, where we can see a huge performance improvement when fetching blocks with multiple threads.

    My test setup, on an Intel i7 with 8 cores (16 threads):

    1. Start a fully synced bitcoind, with this bitcoin.conf:
    0    rest=1
    1    rpcthreads=16
    2    rpcworkqueue=64
    3    rpcuser=user
    4    rpcpassword=password
    
    1. Run ApacheBench: 10000 requests, 16 parallel threads, fetching block nr. 750000 in binary:
    0    ab -n 10000 -c 16 "http://127.0.0.1:8332/rest/block/0000000000000000000592a974b1b9f087cb77628bb4a097d5c2c11b3476a58e.bin"
    

    Time per request (mean) 183 ms on master 30 ms this branch

    So this can process 6.1 times as many requests, and saturates all the cores instead of keeping them partly idle waiting in the lock. With 8 threads the mean times were 90 ms on master and 19 ms on this branch, a speedup of 4.7x.

    Big thanks to martinus for finding this and the original PR.

    The second commit is from a suggestion on the original PR by jonatack to remove the unnecessary LOCK(cs_main) in the zmq notifier’s NotifyBlock.

    I also found that this approach could be applied to rpcs getblock (including verbosity=3), getblockstats, and gettxoutproof with similar very good results. The above benchmarks steps need to be modified slightly for RPC. Run the following ApacheBench command with different request data in a file named data.json:

    0ab -p data.json -n 10000 -c 16 -A user:password "http://127.0.0.1:8332/"
    

    For getblock, use the following in data.json:

    0{"jsonrpc": "1.0", "id": "curltest", "method": "getblock", "params": ["0000000000000000000592a974b1b9f087cb77628bb4a097d5c2c11b3476a58e"]}
    

    master - 184 ms mean request time branch - 28 ms mean request time

    For getblock with verbosity level 3, use the following in data.json:

    0{"jsonrpc": "1.0", "id": "curltest", "method": "getblock", "params": ["0000000000000000000592a974b1b9f087cb77628bb4a097d5c2c11b3476a58e", 3]}
    

    This verbosity level fetches an undo file from disk, so it benefits from this approach as well. However, a lot of time is spent serializing to JSON so the performance gain is not as severe. master - 818 ms mean request time branch - 505 ms mean request time

    For getblockstats, use the following in data.json:

    0{"jsonrpc": "1.0", "id": "curltest", "method": "getblockstats", "params": ["0000000000000000000592a974b1b9f087cb77628bb4a097d5c2c11b3476a58e", ["minfeerate","avgfeerate"]]}
    

    This request used a lock on reading both a block and undo file, so the results are very good. master - 244 ms mean request time branch - 28 ms mean request time

  2. DrahtBot added the label RPC/REST/ZMQ on Oct 13, 2022
  3. andrewtoth force-pushed on Oct 14, 2022
  4. aureleoules approved
  5. aureleoules commented at 10:49 am on October 14, 2022: member

    ACK 77de778de07349c191f47c1e80e484519101f446

     0hey -n 1000 -c 16 "http://127.0.0.1:8332/rest/block/0000000000000000000592a974b1b9f087cb77628bb4a097d5c2c11b3476a58e.bin"
     1
     2Summary:
     3  Total:	16.1675 secs
     4  Slowest:	0.5310 secs
     5  Fastest:	0.0372 secs
     6  Average:	0.2569 secs
     7  Requests/sec:	61.3578
     8  
     9  Total data:	1285175680 bytes
    10  Size/request:	1295540 bytes
    11
    12Response time histogram:
    13  0.037 [1]	|
    14  0.087 [6]	|
    15  0.136 [6]	|
    16  0.185 [7]	|
    17  0.235 [168]	|■■■■■■■■■■
    18  0.284 [685]	|■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■
    19  0.333 [92]	|■■■■■
    20  0.383 [3]	|
    21  0.432 [10]	|■
    22  0.482 [13]	|■
    23  0.531 [1]	|
    24
    25
    26Latency distribution:
    27  10% in 0.2290 secs
    28  25% in 0.2390 secs
    29  50% in 0.2520 secs
    30  75% in 0.2671 secs
    31  90% in 0.2880 secs
    32  95% in 0.3055 secs
    33  99% in 0.4610 secs
    34
    35Details (average, fastest, slowest):
    36  DNS+dialup:	0.0000 secs, 0.0372 secs, 0.5310 secs
    37  DNS-lookup:	0.0000 secs, 0.0000 secs, 0.0000 secs
    38  req write:	0.0000 secs, 0.0000 secs, 0.0003 secs
    39  resp wait:	0.2172 secs, 0.0197 secs, 0.4897 secs
    40  resp read:	0.0396 secs, 0.0005 secs, 0.0429 secs
    41
    42Status code distribution:
    43  [200]	992 responses
    
     0hey -n 1000 -c 16 "http://127.0.0.1:8332/rest/block/0000000000000000000592a974b1b9f087cb77628bb4a097d5c2c11b3476a58e.bin"
     1
     2Summary:
     3  Total:	5.5089 secs
     4  Slowest:	0.3319 secs
     5  Fastest:	0.0221 secs
     6  Average:	0.0856 secs
     7  Requests/sec:	180.0725
     8  
     9  Total data:	1285175680 bytes
    10  Size/request:	1295540 bytes
    11
    12Response time histogram:
    13  0.022 [1]	|
    14  0.053 [109]	|■■■■■■■■■■
    15  0.084 [397]	|■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■
    16  0.115 [420]	|■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■
    17  0.146 [41]	|■■■■
    18  0.177 [3]	|
    19  0.208 [4]	|
    20  0.239 [1]	|
    21  0.270 [7]	|■
    22  0.301 [3]	|
    23  0.332 [6]	|■
    24
    25
    26Latency distribution:
    27  10% in 0.0508 secs
    28  25% in 0.0690 secs
    29  50% in 0.0831 secs
    30  75% in 0.0979 secs
    31  90% in 0.1090 secs
    32  95% in 0.1220 secs
    33  99% in 0.2890 secs
    34
    35Details (average, fastest, slowest):
    36  DNS+dialup:	0.0000 secs, 0.0221 secs, 0.3319 secs
    37  DNS-lookup:	0.0000 secs, 0.0000 secs, 0.0000 secs
    38  req write:	0.0000 secs, 0.0000 secs, 0.0004 secs
    39  resp wait:	0.0486 secs, 0.0126 secs, 0.2870 secs
    40  resp read:	0.0369 secs, 0.0004 secs, 0.0731 secs
    41
    42Status code distribution:
    43  [200]	992 responses
    

    The results are consistent. The speed improvement seems to be seen only with large blocks, which is great for mainnet. I didn’t notice any gains on testnet since blocks are almost empty.

  6. andrewtoth commented at 8:47 pm on October 14, 2022: contributor

    After reading this comment #17161 (comment) it appears it is unsafe to call ReadBlockFromDisk without holding cs_main. The block could be removed while the file is open which can cause issues on Windows.

    I proposed a fix in #26316. That or another fix should be merged first before this would be safe for use with pruning I believe.

  7. andrewtoth marked this as a draft on Oct 15, 2022
  8. andrewtoth renamed this:
    rest: reduce LOCK(cs_main) scope in rest_block: ~6 times as many requests per second
    rpc/rest/zmq: reduce LOCK(cs_main) scope: ~6 times as many requests per second
    on Oct 17, 2022
  9. andrewtoth force-pushed on Oct 17, 2022
  10. andrewtoth force-pushed on Oct 17, 2022
  11. andrewtoth force-pushed on Oct 17, 2022
  12. DrahtBot commented at 1:37 am on October 17, 2022: contributor

    The following sections might be updated with supplementary metadata relevant to reviewers and maintainers.

    Reviews

    See the guideline for information on the review process.

    Type Reviewers
    ACK MarcoFalke, hebasto
    Stale ACK aureleoules, ryanofsky

    If your review is incorrectly listed, please react with 👎 to this comment and the bot will ignore it on the next update.

    Conflicts

    Reviewers, this pull request conflicts with the following ones:

    • #26415 (rpc,rest: faster getblock and rest_block by reading raw block by andrewtoth)
    • #25232 (rpc: Faster getblock API by AaronDewes)
    • #23507 (Refactor: Improve API design of ScriptToUniv, TxToUniv etc to return the UniValue instead of mutating a parameter/reference by mjdietzx)
    • #21319 (RPC/Blockchain: Optimise getblock for simple disk->hex case by luke-jr)
    • #19888 (rpc, test: Improve getblockstats for unspendables by fjahr)

    If you consider this pull request important, please also help to review the conflicting pull requests. Ideally, start with the one that should be merged first.

  13. andrewtoth marked this as ready for review on Oct 17, 2022
  14. andrewtoth force-pushed on Oct 17, 2022
  15. andrewtoth marked this as a draft on Oct 19, 2022
  16. ryanofsky approved
  17. ryanofsky commented at 8:53 pm on November 17, 2022: contributor

    Code review ACK d7f358ba64a620417d80c6402f51669f23a503eb, and I think I disagree with (or don’t understand) the comment that this change should require #26316. In all of the cases here, the ReadBlock or UndoRead return value is checked so if reading data fails on windows, the RPC and rest requests should still do the right thing.

    Or is the concern not that this change would cause RPC and rest calls to do the wrong thing, but that this change would cause unlink calls to fail on windows and result in a wasted disk space? If that is the bug, and I think a more minimal and elegant fix might just be to make the pruning code resilient to files temporarily being unlinkable because they are in-use, and to just retry and delete them later on the next round of pruning.

  18. andrewtoth commented at 4:06 pm on November 18, 2022: contributor

    Or is the concern not that this change would cause RPC and rest calls to do the wrong thing, but that this change would cause unlink calls to fail on windows and result in a wasted disk space? If that is the bug, and I think a more minimal and elegant fix might just be to make the pruning code resilient to files temporarily being unlinkable because they are in-use, and to just retry and delete them later on the next round of pruning. @ryanofsky yes, thank you for the suggestion. I’ve implemented that in #26533. I think that’s a better/less invasive solution than what I have proposed in #26316.

  19. andrewtoth marked this as ready for review on Nov 18, 2022
  20. DrahtBot added the label Needs rebase on Dec 6, 2022
  21. andrewtoth force-pushed on Dec 6, 2022
  22. andrewtoth commented at 2:28 pm on December 6, 2022: contributor
    Rebased
  23. in src/zmq/zmqpublishnotifier.cpp:252 in 2cd94daf18 outdated
    257-            return false;
    258-        }
    259-
    260-        ss << block;
    261+    CBlock block;
    262+    if(!ReadBlockFromDisk(block, pindex, consensusParams)) {
    


    maflcko commented at 2:34 pm on December 6, 2022:
    0    if (!ReadBlockFromDisk(block, pindex, consensusParams)) {
    

    nit in a2403f4b2cb07acc2b00db8a8be6c8c0dedf09f3 (for new code)

  24. DrahtBot removed the label Needs rebase on Dec 6, 2022
  25. maflcko commented at 7:51 pm on December 6, 2022: member

    Happy to re-ACK for the nit

    review ACK 2cd94daf18aa4ce124142d7f41e6a6b627580acb 🔗

    Signature:

     0-----BEGIN PGP SIGNED MESSAGE-----
     1Hash: SHA512
     2
     3review ACK 2cd94daf18aa4ce124142d7f41e6a6b627580acb 🔗
     4-----BEGIN PGP SIGNATURE-----
     5
     6iQGzBAEBCgAdFiEE+rVPoUahrI9sLGYTzit1aX5ppUgFAlwqrYAACgkQzit1aX5p
     7pUjc5Av/RSFb/nqSUF7w9OmGQfGhal9C56bH/LMj9shwqYn3Ic9hW/CruW5tWAlJ
     8Gq97INRqPxt+t9wnsgUYXEahBWkpmfUvNo/0sXJQnwE86fbBm+yWDEZnmeAiYQ/f
     9wPkXkLSXqcnyrGCaEN5t4lwU7qTAMw0MCqOKCXZJwdMoKEUtvxt+BEGmy9ZlXNtg
    10Vyu0+aUvjysxdpGjScdDC7GRbjlIAWG10kXs3en3zKEHK4Q4bG/Cv0pmxYxrBhXa
    117HROxcpJcl94HcwePF7xr1NstEBkw4Hc+GhjSasw1aJHs84clRyQj7Jg/1Q+Y2Qq
    12klCiYa6rK3WytxyWzBc3eETCuXLOhugGIFFu6mjOHx5zcmcwGRiRQIunOwOtHb4G
    13H2izSoJigG1WESg4fyC/4YKemx/lUDgui+4mcqzVqvedgWB1cCFC8xZ+mdJB1qld
    147AUPRhrAQPTOAi1+5gg/KQbcX9YIuJADB8onzaU/wP0/guEusTJGvOKHoynOKm8a
    15QbGZaOzx
    16=yYXw
    17-----END PGP SIGNATURE-----
    
  26. rest: reduce LOCK(cs_main) scope in rest_block c75e3d2772
  27. zmq: remove LOCK(cs_main) from NotifyBlock 7d253c943f
  28. rpc: reduce LOCK(cs_main) scope in GetBlockChecked and getblock f00808e932
  29. rpc: reduce LOCK(cs_main) scope in blockToJSON efd82aec8a
  30. rpc: reduce LOCK(cs_main) scope in GetUndoChecked and getblockstats 4d92b5aaba
  31. rpc: reduce LOCK(cs_main) scope in gettxoutproof d7f61e7d59
  32. andrewtoth force-pushed on Dec 6, 2022
  33. andrewtoth commented at 8:07 pm on December 6, 2022: contributor
    @MarcoFalke addressed the nit.
  34. maflcko commented at 8:48 am on December 7, 2022: member

    re-ACK d7f61e7d5909da7227c9e34be06ce9eb872ba074 💫

    Signature:

     0-----BEGIN PGP SIGNED MESSAGE-----
     1Hash: SHA512
     2
     3re-ACK d7f61e7d5909da7227c9e34be06ce9eb872ba074 💫
     4-----BEGIN PGP SIGNATURE-----
     5
     6iQGzBAEBCgAdFiEE+rVPoUahrI9sLGYTzit1aX5ppUgFAlwqrYAACgkQzit1aX5p
     7pUh4tQwAvbdeO4ZW0zETPMGCO0+JGfkDLQdWqhYC1Tm+LpGUS5otVF64KqbI5xid
     8wuXSbuHEQhc4nXHrfLdnuuJ9WQFcfIbZu5XE2pybBAMj1yoCtUH9j1mr4WlVvbxi
     9f7wn2bSwO5gcJX0XrMU/TvwQT8AMbbell6gXqs8Llt08yddoeQq2GH8WYZhUPF8W
    10q8NloGBUB4EENXH8PeFwq1qXpmBMaGA9b0QCgzCK4X7Vfd6eVlbreTyWNO3hgRDr
    11kl3LbJDaiFzP8LR2x3xg9qjf0GyRFg6VAZGm0RA+Cf2FySUj4GH4RvaqyGbBKBCq
    12pKqKpqKxywN245uzAVBRW8SYyDrP6ibB/KyEB2G4CUkzGypeRGFsULaprG9n0brA
    13YM0z4Sgl30W+A64iJOm4cnHVUoyfFpH+ez6NQpxx9WxZ7xhXNDUU6oVQ91FcIr0Q
    14Hct5tsAyR5GTfsfzbqbgokuUn210xMvPkoorZuW5SCFZ33rYw3M1CNNumBrX7vXx
    15sWjO8zXh
    16=lJz/
    17-----END PGP SIGNATURE-----
    
  35. hebasto commented at 10:52 am on December 7, 2022: member
    Concept ACK.
  36. in src/rpc/blockchain.cpp:596 in d7f61e7d59
    596 
    597     if (!ReadBlockFromDisk(block, pblockindex, Params().GetConsensus())) {
    598         // Block not found on disk. This could be because we have the block
    599         // header in our index but not yet have the block or did not accept the
    600-        // block.
    601+        // block. Or if the block was pruned right after we released the lock above.
    


    hebasto commented at 11:18 am on December 7, 2022:
    Do we have a test for such a case?

    maflcko commented at 11:21 am on December 7, 2022:

    I don’t think it it possible to write a test for this deletion race, unless you want to modify the source code as well?

    It might be easier to write a functional test for lack of deletion (on Windows) in #26533 by holding a open file handle to the block file


    andrewtoth commented at 1:42 pm on December 7, 2022:
    The way I could see a test for this case would be to have a long sleep above the if statement, then call PruneBlockFilesManual in the test and it should fail here, but that would require modifying the source as pointed out by MarcoFalke. Is there another way to introduce an arbitrary delay or block the thread in tests?
  37. in src/rpc/blockchain.cpp:185 in d7f61e7d59
    180@@ -181,7 +181,8 @@ UniValue blockToJSON(BlockManager& blockman, const CBlock& block, const CBlockIn
    181         case TxVerbosity::SHOW_DETAILS:
    182         case TxVerbosity::SHOW_DETAILS_AND_PREVOUT:
    183             CBlockUndo blockUndo;
    184-            const bool have_undo{WITH_LOCK(::cs_main, return !blockman.IsBlockPruned(blockindex) && UndoReadFromDisk(blockUndo, blockindex))};
    185+            const bool is_not_pruned{WITH_LOCK(::cs_main, return !blockman.IsBlockPruned(blockindex))};
    186+            const bool have_undo{is_not_pruned && UndoReadFromDisk(blockUndo, blockindex)};
    


    hebasto commented at 11:59 am on December 7, 2022:

    efd82aec8a2dd0fca8f2597c3f84cefe057d1243

    nit: Less negations:

    0            const bool is_pruned{WITH_LOCK(::cs_main, return blockman.IsBlockPruned(blockindex))};
    1            const bool have_undo{!is_pruned && UndoReadFromDisk(blockUndo, blockindex)};
    

    ?


    fanquake commented at 12:03 pm on December 7, 2022:
    How is this less negations? You’re swapping a negation on one line, for a negation on a different line.

    hebasto commented at 12:06 pm on December 7, 2022:

    How is this less negations?

    line 184: is_not_pruned line 184: !blockman.IsBlockPruned(blockindex) line 185: is_not_pruned total = 3 cases

    in suggestion line 185: !is_pruned total =1 case


    fanquake commented at 12:08 pm on December 7, 2022:
    I wouldn’t consider variable names describing a state “negations”, and I’m not sure why there is a need to avoid them.

    maflcko commented at 12:10 pm on December 7, 2022:

    Can also keep everything in one line as-is, and reduce the diff to a one-char diff.

    0const bool have_undo{WITH_LOCK(::cs_main, return !blockman.IsBlockPruned(blockindex)) && UndoReadFromDisk(blockUndo, blockindex)};
    

    hebasto commented at 12:14 pm on December 7, 2022:

    I wouldn’t consider variable names describing a state “negations”, and I’m not sure why there is a need to avoid them.

    nm, I agree with the current code.

  38. hebasto approved
  39. hebasto commented at 11:59 am on December 7, 2022: member
    ACK d7f61e7d5909da7227c9e34be06ce9eb872ba074, I have reviewed the code and it looks OK. Did not make benchmarking though.
  40. maflcko merged this on Dec 8, 2022
  41. maflcko closed this on Dec 8, 2022

  42. sidhujag referenced this in commit ef0b52a124 on Dec 8, 2022
  43. andrewtoth deleted the branch on Dec 8, 2022
  44. Fabcien referenced this in commit ae8564750e on Jan 25, 2023
  45. Fabcien referenced this in commit 3bac4c6a23 on Jan 25, 2023
  46. Fabcien referenced this in commit 60cd1c8b0d on Jan 25, 2023
  47. Fabcien referenced this in commit da006fdac2 on Jan 25, 2023
  48. Fabcien referenced this in commit e2648cf69d on Jan 25, 2023
  49. Fabcien referenced this in commit ee739b76a6 on Jan 25, 2023
  50. bitcoin locked this on Dec 8, 2023

github-metadata-mirror

This is a metadata mirror of the GitHub repository bitcoin/bitcoin. This site is not affiliated with GitHub. Content is generated from a GitHub metadata backup.
generated: 2024-10-04 22:12 UTC

This site is hosted by @0xB10C
More mirrored repositories can be found on mirror.b10c.me