[SERVER-38660] fuzzer can cause tests to timeout when executing secondary reads with transactions Created: 14/Dec/18  Updated: 23/Jan/19  Resolved: 23/Jan/19

Status: Closed
Project: Core Server
Component/s: None
Affects Version/s: 4.1.6
Fix Version/s: None

Type: Bug Priority: Major - P3
Reporter: Randolph Tan Assignee: Tess Avitabile (Inactive)
Resolution: Duplicate Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Issue Links:
Duplicate
duplicates SERVER-39139 Remove testing support for secondary ... Closed
Related
is related to SERVER-39139 Remove testing support for secondary ... Closed
Operating System: ALL
Sprint: Repl 2019-01-28
Participants:

 Description   

Once a secondary read only transaction starts and gets stashed, the applier trying to get the global X will block (like trying to replicate create collection command). And once the X lock is queued, new requests to secondary will queue behind the X lock until it is satisfied/abandoned. This can cause a deadlock scenario like this:

1. Txn1 starts, do ops, stash locks.
2. Repl applier request global X, conflicts with stashed locks, and lock request gets queued.
3. Txn1 continues, checks out session, tries to satisfy read concern, which involves checking if oplog collection exists that requires global IS, so it gets queued behind #2 (note: this is before locks gets unstashed).
4. Periodic Txn Killer sees that Txn1 is already expired, tries to kill it by checking out the session, but it is blocked waiting for step#3 to check the session back in.

More notes:
Periodic Txn Killer actually kills the opCtx of session before trying to check it out, but step#3 is also blocked on pbwm resource mutex while trying to grab GlobalLock. And this operation doesn't use opCtx so it cannot be interrupted by killOp.



 Comments   
Comment by Tess Avitabile (Inactive) [ 23/Jan/19 ]

Closing as a duplicate of SERVER-39139, since we will remove support for secondary transactions entirely.

Comment by Tess Avitabile (Inactive) [ 19/Jan/19 ]

Sure, I can make a separate ticket to disable secondary transactions in the fuzzer. I'll wait to see what happens with SERVER-39096 first.

I don't think it is worthwhile to test secondary transactions in the fuzzer. Since they are not a supported feature, if they deadlock or crash in a new way, I don't want us to have to take the time to investigate it.

Comment by Max Hirschhorn [ 19/Jan/19 ]

Would it be acceptable to repurpose this ticket to say that the fuzzer must not run transactions on secondaries? An alternative is to wait and see if we need to disable transactions on secondaries entirely due to SERVER-39096.

In terms of JIRA process, I'd prefer we make a separate TIG ticket for the changes to the fuzzer. (We can close this ticket as "Won't fix" or Backlog it until transactions on secondaries are a thing.)

tess.avitabile, would it be possible for the fuzzer to continue to run transactions on secondaries so long as none of the statements include a readConcern with afterCluster? It wasn't clear to me what the actual steps to reproduce the problem were, but we generally try to make the blacklisting as narrow as possible.

Comment by Tess Avitabile (Inactive) [ 18/Jan/19 ]

max.hirschhorn, I think the best way to resolve this is for the fuzzer to not run transactions on secondaries. Secondary read-only transactions are not supported outside of tests, and we do not require that they do not cause deadlocks. A background dbhash check would never encounter this scenario, since it (correctly) does not send readConcern after the first command in a transaction.

Would it be acceptable to repurpose this ticket to say that the fuzzer must not run transactions on secondaries? An alternative is to wait and see if we need to disable transactions on secondaries entirely due to SERVER-39096.

Comment by Max Hirschhorn [ 07/Jan/19 ]

Is the secondary read only transaction that's occurring here a dbhash? If we don't use background dbhash checks in the fuzzer, we can ban secondary read only transactions in the fuzzer.

If it is a background dbhash check, this might be fixed by SERVER-38341, which will remove the pbwm lock.

Just to clarify - We don't run the CheckReplDBHashInBackground hook during the jstestfuzz* test suites. I'd say (1) it's unlikely for the fuzzer to do a large enough volume of writes to exercise timestamping in a particularly interesting way to make the check worthwhile, and (2) the manipulation of the transactionLifetimeLimitSeconds server parameter to be 1e9 could be inherited by concurrent fuzzer operations and would lead to Evergreen timeouts since the fuzzer isn't guaranteed to abort the transactions it starts.

Comment by Randolph Tan [ 07/Jan/19 ]

greg.mckeon I don't think so. The fuzzer had a read pref of secondary only and it can run arbitrary commands (since it's the fuzzer test). In the build failure, if I remember correctly, was just a plain find on the secondary. If I also remember correctly, the failure is easy to reproduce, I had a lot of success reproducing the hang running the generated test file locally.

Comment by Judah Schvimer [ 07/Jan/19 ]

The PBWM is not interruptible because it uses the lock function that is not interruptible. Should we audit all users of this and remove any that are problematic or unnecessary? Any instance of ResourceLock falls into this category. CC geert.bosch

Comment by Siyuan Zhou [ 07/Jan/19 ]

We are also wondering why the second operation in the transaction need to wait for read concern. Does the second transactional operation come with a read concern?

As discussed with milkie weeks ago, another possible fix is to compare lastApplied from the replication coordinator, rather than the top of the oplog, with the timestamp from the storage, when waiting for all earlier writes to commit. We always maintain lastApplied on both primary and secondaries.

Comment by Gregory McKeon (Inactive) [ 07/Jan/19 ]

renctan or max.hirschhorn
Is the secondary read only transaction that's occurring here a dbhash? If we don't use background dbhash checks in the fuzzer, we can ban secondary read only transactions in the fuzzer.

If it is a background dbhash check, this might be fixed by SERVER-38341, which will remove the pbwm lock.

Comment by Randolph Tan [ 21/Dec/18 ]

max.hirschhorn I think I know what is going on. It looks like the session killer is running but there's a deadlock that made it stuck. Updated the description.

Comment by Randolph Tan [ 20/Dec/18 ]

I haven't looked at the exact operation, but I believe they were read only transactions since I think the transaction participant didn't have any ops stashed, but has the locks held. My initial though was it should have expired as well, but it was not getting killed (I can semi-reliably repro this on my local machine). Then I saw the 3hr transaction lifetime limits. After looking at then again today, they appear to just be TestData variables. I'll try to look again tomorrow.

Comment by Max Hirschhorn [ 18/Dec/18 ]

Setup: Fuzzer is currently set to have a transaction lifetime of 3hrs.

renctan, the jstestfuzz* test suites set a transaction lifetime of 1 second. What transaction were you expecting to be aborted by the reaper that wasn't?

Generated at Thu Feb 08 04:49:36 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.