Fix chain tip data race and corrupt rest response (validation)

https://github.com/bitcoin/bitcoin/pull/25077

Host: MarcoFalke  -  PR author: MarcoFalke

Notes

  • It is a data race (undefined behavior) when a thread writes to memory that another thread is reading or writing. std::mutex and std::atomic can be used to guard against data races.

  • Compilers such as gcc and clang can instrument the binary to detect data races with the flag -fsanitize=thread. In Bitcoin Core it can be set via ./configure --with-sanitizers=thread.

  • However, data races may only happen intermittently and detection is not guaranteed, even if the program is fed the same inputs.

  • In Bitcoin Core, validation code is protected by the cs_main global recursive mutex.

Questions

  1. Did you review the PR? Concept ACK, approach ACK, tested ACK, or NACK?

  2. Which two threads cause the data race fixed in this pull request? What is their purpose? Refer to the traceback in the pull request description.

  3. How is the data race fixed in the pull request?

  4. What is the other issue fixed by the change? Why is it impossible to detect that issue with a thread sanitizer that detects data races?

  5. How is the “logical race” fixed in the pull request?

  6. Do you agree with the direction of the change to introduce a GetMutex() alias for the ::cs_main mutex?

  117:00 <MacroFake> #startmeeting
  217:00 <MacroFake> hi everyone and welcome to today's review club
  317:00 <MacroFake> Let's give everyone a chance to say hi
  417:00 <afmencken> hi
  517:00 <paul_c> Hey everybody
  617:00 <svav> Hi
  717:00 <MacroFake> Anyone here for the first time?
  817:01 <michaelfolkson> hi
  917:02 <michaelfolkson> (ld: symbol(s) not found for architecture x86_64
 1017:02 <michaelfolkson> clang: error: linker command failed with exit code 1 (use -v to see invocation))
 1117:02 <michaelfolkson> ignore for now :)
 1217:02 <MacroFake> You also may indicate whether you reviewed the pull request (y/n)
 1317:02 <amirreza97> Hello, y
 1417:03 <paul_c> y
 1517:03 <jojo> hello, n
 1617:03 <MacroFake> Ok, let's jump right in with the first question.
 1717:03 <michaelfolkson> y
 1817:03 <afmencken> y
 1917:03 <Lov3r_Of_Bitcoin> y
 2017:03 <MacroFake> 2. Which two threads cause the data race fixed in this pull request? What is their purpose? Refer to the traceback in the pull request description.
 2117:04 <otech> y
 2217:05 <effexzi> Hi every1
 2317:05 <otech> is b-loadblk one of the threads?
 2417:05 <MacroFake> otech: yest
 2517:05 <MacroFake> *yes
 2617:05 <otech> cs_main is the other?
 2717:06 <MacroFake> cs_main is a Mutex, not a thread
 2817:06 <amirreza97> checking where the tip is null or not. The thread which starts at init.cpp
 2917:06 <amirreza97> whether*
 3017:07 <otech> Just called the "main" thread I guess
 3117:07 <MacroFake> Ok, so one thread is the b-loadblk thread, created at https://github.com/bitcoin/bitcoin/blob/aeab1b42e67cc8146bfc7d127d15633bd652fe60/src/init.cpp#L1671
 3217:07 <MacroFake> Another thread is the "main thread", created by the C++ main() "entry function" at https://github.com/bitcoin/bitcoin/blob/aeab1b42e67cc8146bfc7d127d15633bd652fe60/src/bitcoind.cpp#L259
 3317:07 <MacroFake> What is the purpose of each thread?
 3417:07 <amirreza97> AppInitMain
 3517:08 <otech> Just FYI a list of documented threads can be found here: https://github.com/bitcoin/bitcoin/blob/master/doc/developer-notes.md#threads
 3617:10 <amirreza97> I think the first one is to load blocks from blk???.dat files.
 3717:10 <MacroFake> amirreza97: correct. Also, it loads the mempoo.dat (if one exists)
 3817:11 <MacroFake> The main thread will run during the whole program duration, no fancy answer here :)
 3917:11 <michaelfolkson> "Responsible for starting up and shutting down the application" from otech's link
 4017:12 <MacroFake> 3. How is the data race fixed in the pull request? (Hint: First describe how it happens)
 4117:12 <amirreza97> So why these two starts at the same time? Isn't the first thread (reading from blk???.dat files) precondition for running the main thread?
 4217:13 <amirreza97> I mean reading from files is just at the first time AFAIK. So why not let it be finished and then start the main thread.
 4317:13 <MacroFake> amirreza97: The threads never start at the same time. loadblk is started by the main thread.
 4417:14 <amirreza97> So I mean simultaneously.
 4517:15 <MacroFake> As explained by michaelfolkson, main() will lead the init and shutdown process of the application.
 4617:16 <MacroFake> loading the blocks is one part of the init process. (Other things include loading the wallets and starting the net and p2p interfaces)
 4717:18 <MacroFake> Let's dissect question 3 a bit more. What is the call-stack (functions) for each thread where the race happens
 4817:18 <MacroFake> ?
 4917:19 <MacroFake> Hint: In the traceback in the pull reqeust description, this is included
 5017:20 <MacroFake> It is the first item in each line
 5117:20 <otech> Difficult to parse but something to do with `is_move_assignable` and `is_move_assignable` logic?
 5217:20 <MacroFake> We are looking at the sections "Write of size 8 ..." and "Previous read of size 8"
 5317:21 <otech> `is_move_constructible` *
 5417:21 <MacroFake> otech: Good point. Some function names are increadibly hard to parse as they include the full typenames
 5517:21 <MacroFake> We are only interested in the Bitcoin Core functions, not the std:: ones
 5617:22 <larryruane> modifying the chain tip (correctly, with cs_main): ActivateBestChain calls ActivateBestChainSetp calls ConnectTip calls SetTip ... reading the chain tip (without lock): AppInitMain calls ActiveTip calls Tip
 5717:22 <larryruane> (reading tip is being done to get the argument to RPCNotifyBlockChange)
 5817:23 <MacroFake> larryruane: Correct. The write happens here: "node::ThreadImport -> CChainState::ActivateBestChain -> CChainState::ActivateBestChainStep -> CChainState::ConnectTip -> CChain::SetTip"
 5917:24 <MacroFake> The read happens here: "main -> AppInit -> AppInitMain -> ChainstateManager::ActiveTip() -> CChain::Tip()"
 6017:24 <glozow> so the b-loadblk thread is writing in `SetTip()`while main thread is reading in `Tip()` ?
 6117:24 <MacroFake> glozow: Correct
 6217:25 <MacroFake> (Still with question 3), next step: Which lock is supposed to be held?
 6317:26 <paul_c> could we use a single mutex to remove the data race between the read from and write to?
 6417:26 <afmencken> cs_main is supposed to be held
 6517:26 <MacroFake> paul_c: Yes
 6617:26 <MacroFake> paul_c: The lock already exists, and is supposed to be cs_main
 6717:26 <MacroFake> afmencken: Correct
 6817:27 <MacroFake> (Still q 3), next step: Why is cs_main not held?
 6917:28 <MacroFake> Hint: The implemenation of ActiveTip: https://github.com/bitcoin/bitcoin/blob/aeab1b42e67cc8146bfc7d127d15633bd652fe60/src/validation.h#L914-L918
 7017:29 <MacroFake> And the implementation of ActiveChainState: https://github.com/bitcoin/bitcoin/blob/aeab1b42e67cc8146bfc7d127d15633bd652fe60/src/validation.cpp#L5157
 7117:29 <michaelfolkson> Why was cs_main not held before this PR? Is that the question, sorry
 7217:29 <larryruane> "Why is cs_main not held?" -- is it anything more than that it's an oversight? Ah I think I see, those first 3 methods you linked to don't scquire the lock
 7317:29 <glozow> cs_main is released at the end of `ActiveChainState()` ?
 7417:30 <MacroFake> michaelfolkson: Yes, that is the question
 7517:31 <michaelfolkson> Because it is held by a different thread?
 7617:31 <larryruane> (like `ActiveChainState` does... they should be similar in their locking behavior)
 7717:31 <MacroFake> glozow: Correct. The cs_main Mutex will only be held until the scope is closed. The scope in this case is the function body {...}
 7817:32 <MacroFake> michaelfolkson: If a mutex is acquired by a different thread, it can not be acquired by this thread. However, if the thread *wants* to acquire it, it will wait until it can
 7917:32 <lightlike> is there still a "race", just not one with UB? After the fix, loadblk still does its thing and possible changes the ActiveTip() several times, and at some point the main thread takes the cs_main and calls RPCNotifyBlockChange() with whatever is the current tip at this point - could that vary from run to run?
 8017:32 <MacroFake> michaelfolkson: If the thread does not want to acquire it, it will simply continue
 8117:33 <larryruane> ignore if this is too detailed, but "... it will wait until it can" -- does it spin-wait, or sleep-wait? Or spin for a short time and then "give up" and sleep (let other threads run)?
 8217:33 <MacroFake> lightlike: Good point. I think not, because RPCNotifyBlockChange doesn't care about the exact block, but I should double-check.
 8317:35 <MacroFake> larryruane: I am not familiar with low level primitives, but I'd guess that the thread will be put to sleep and woken when the lock is ready to be picked up
 8417:35 <sipa> larryruane: In Linux these days, locks are implemented using a mechanism called "futexes" (which have their own wikipedia article)
 8517:35 <larryruane> MacroFake: sipa: thanks
 8617:35 <MacroFake> (final part of q 3): How is the data race fixed in the pull request?
 8717:36 <MacroFake> sipa: Thanks!
 8817:36 <sipa> IIRC the basic idea is to use atomic CPU instructions to quickly check if the lock is contended or not, and if it is, make a kernel call that gets woken up when needed
 8917:36 <larryruane> fixed by: https://github.com/bitcoin/bitcoin/pull/25077/files#diff-b1e19192258d83199d8adaa5ac31f067af98f63554bfdd679bd8e8073815e69dR1856
 9017:37 <larryruane> (holding cs_main while calling `ActiveTip`)
 9117:37 <sipa> (re futexes: ha, apparently rusty is listed as one of the inventors)
 9217:37 <michaelfolkson> Were people aware of this data race already (if they built with the thread sanitizer) or did you discover it through doing something specific MacroFake?
 9317:38 ← amirreza79 left (~Amirreza7@2.177.69.171): Leaving
 9417:38 <larryruane> i do see futex often in stack traces for idle threads
 9517:38 <michaelfolkson> sipa: Lol
 9617:39 <MacroFake> michaelfolkson: Data races are had to reproduce, especially if they only happen once per process lifetime (init), so I try to keep an eye on intermittent failures
 9717:39 <MacroFake> This one was found by Cirrus CI on a completely unrelated change: https://cirrus-ci.com/task/5612886578954240?logs=ci#L4868
 9817:40 <MacroFake> *hard to reproduce
 9917:41 <michaelfolkson> Intermittent build error messages or failing to build? (what you keep an eye on?)
10017:41 <lightlike> Does the previous change in "AppInitMain" by this PR (before loadblk is started) also fix something, or is it a precautionary measure?
10117:41 <MacroFake> michaelfolkson: The functional test fails
10217:41 <michaelfolkson> Gotcha
10317:41 <MacroFake> michaelfolkson: I copied the traceback from the Cirrus CI log
10417:42 <MacroFake> ( Unrelated: A similar find was https://github.com/bitcoin/bitcoin/pull/18742 )
10517:42 <MacroFake> lightlike: Good question. I don't think it fixes anything as no other threads are running at this point
10617:42 <MacroFake> (I think)
10717:43 <MacroFake> Yes, you'll see that ThreadImport starts only 30 lines *later*
10817:43 <MacroFake> However, I added annotations to the Active* function to force cs_main at every call site
10917:43 <MacroFake> as belt-and-suspenders
11017:44 <larryruane> it would be nice if there was a "race" or "thread-safety" PR label
11117:44 <MacroFake> Ok, next question
11217:44 <MacroFake> 4. What is the other issue fixed by the change? Why is it impossible to detect that issue with a thread sanitizer that detects data races?
11317:45 <MacroFake> (hint: It is described in the pull request description)
11417:45 <michaelfolkson> The corrupt REST response. Not sure how you found that either :)
11517:45 <larryruane> maybe found by static analysis (annotations)?
11617:45 <larryruane> it's not possible because that rest code is part of the client and it's single-threaded (?)
11717:45 <larryruane> it's a separate executable
11817:46 <MacroFake> michaelfolkson: I think it can only be found manually, unless there is a test that specifically checks this and for some reason fails
11917:46 <michaelfolkson> So you just spotted it through your own eyes?
12017:46 <MacroFake> larryruane: Nope. rest is delivered by the same bitcoind process
12117:46 <larryruane> can we assert lock is held?
12217:46 <larryruane> oh okay thanks
12317:46 <MacroFake> michaelfolkson: Yes
12417:47 <michaelfolkson> Wow ok
12517:47 <larryruane> oh i was thinking of bitcoin-chainstate, that's a separate exe I think
12617:47 <MacroFake> larryruane: Correct
12717:47 <MacroFake> Anyone knows the answer to q 4? :)
12817:48 <afmencken> In the case of the corrupt REST response, there is no data race to detect, is that correct?
12917:48 <MacroFake> afmencken: Yes
13017:49 <MacroFake> Hint: The REST interface calls chainman.ActiveChain().Height() and then chainman.ActiveChain().Tip()->GetBlockHash() separately
13117:50 <MacroFake> Hint: Is the cs_main lock held over both calls?
13217:50 <afmencken> The problem is not that the lock isn't held, but that different pieces of data that the lock is guarding are read during different reads.
13317:50 <afmencken> i.e. different "holdings" of the lock.
13417:50 <afmencken> So the reads are inconsistent with eachother.
13517:50 <MacroFake> afmencken: Correct
13617:51 <paul_c> Is it impossible to detect that issue with a thread sanitizer that detects data races because it can't automatically find bugs in the program or suggest ways to fix the data-races found?
13717:51 <MacroFake> paul_c: Hmmm. Think a bit more about what exactly a thread sanitizer detects
13817:52 <MacroFake> Surely it detects "bugs in the program", but of what kind?
13917:53 <larryruane> UBs, (undefined), like 2 threads reading and writing the same memory at the same time?
14017:54 <larryruane> (or also, 2 threads writing) ... so not really locking? (but the fix is usually locking)
14117:54 <MacroFake> larryruane: Yes, so getting the lock and getting thing_1, then releasing the lock, then taking it again and getting thing_2 is not UB (a data-race detectable by a sanitizer)
14217:54 <lightlike> I think in this case there would be no UB, just a rest response that would consist of parts that don't fit together (because the parts correspond to different chain tips)
14317:55 <MacroFake> lightlike: Yes
14417:55 <MacroFake> I am not sure if a word exists for that. I just called it "logical" race
14517:55 <MacroFake> 5. How is the “logical race” fixed in the pull request?
14617:55 <larryruane> yes higher-level race, maybe
14717:56 <larryruane> get the height and tip hash from within the lamba, while `cs_main` is held?
14817:56 <afmencken> The logical race is fixed by moving all of the reads into a single critical section.
14917:56 <MacroFake> larryruane: afmencken: Correct
15017:56 <MacroFake> 4 minutes left for the last question and any of your questions
15117:56 <larryruane> MacroFake: I was wondering if you considered returning those two values from the lambda?
15217:56 <MacroFake> 6. Do you agree with the direction of the change to introduce a GetMutex() alias for the ::cs_main mutex?
15317:57 <paul_c> y
15417:57 <larryruane> yes! it paves the way for finer-grain locking (chainman level) instead of using cs_main for so much
15517:57 <MacroFake> larryruane: Yes, but that would mean more code
15617:58 <MacroFake> larryruane: The lambda is called in two different places, but if the variables are set via capturing, then only one location would need to change
15717:59 <larryruane> MacroFake: can you tell us why `::cs_main` instead of just `cs_main`? I know the double-colon means global scope, but is there a danger that some class will implement a `cs_main` variable? (Or do they already?)
15817:59 <afmencken> I'm not sure I understand what is gained from adding GetMutex
15917:59 <larryruane> is it just to emphasize that it's a global? (make it slightly uglier so we have more motivation to get rid of it? :) )
16017:59 <MacroFake> larryruane: It doesn't matter fro ::cs_main, but for other globals that do not start with our g_ prefix (style guide), it could cause issues
16118:00 <MacroFake> *for
16218:00 <MacroFake> #endmeeting