[Bug]: Write log fail and cc node group leader change at same time cause assert crash

[githubzilla]

• Software version (the version of the software you're running):(required)
  e.g. 0.0.1

• Reproduce steps (describe steps of reproducing the bug):(required)
  Failed CI pipe
  Failed test case: mono_multi.fault_create_drop_index

• Expected result (describe the right result as expected):(required)

• Actual result (describe the incorrect result actually happened):(required)
  eloqsql crashed

• Related issues (references to the related issues, e.g. eloqdb/repository#number):(optional)

[githubzilla]

• TX node logs:
  mysqld.3.log
  mysqld.2.log
  mysqld.1.log

[githubzilla]

Signal 6 (SIGABRT) Crash Analysis: TxLog Group Leader Changes

Issue Summary

A crash occurs due to an assertion failure at tx_index_operation.cpp:466 when node group leader changes happen during an AddIndex transaction operation.

Error from logs:

mariadbd: /home/eloq/workspace/eloqsql/data_substrate/tx_service/src/tx_index_operation.cpp:466: 
virtual void txservice::UpsertTableIndexOp::Forward(txservice::TransactionExecution*): Assertion `false' failed.
260209 19:12:04 [ERROR] mysqld got signal 6 ;

---

Root Cause Analysis

Crash Location

The crash occurs in UpsertTableIndexOp::Forward() at tx_index_operation.cpp:459-472:

else if (op_ == &unlock_cluster_config_op_)
{
    if (unlock_cluster_config_op_.hd_result_.IsError())
    {
        if (txm->CheckLeaderTerm())
        {
            // Releasing a local read lock should never fail
            assert(false);  // <-- Line 466: CRASH HERE
        }
        else
        {
            ForceToFinish(txm);
            return;
        }
    }
    // ... success path ...
}

Underlying Problem: Race Condition Between Term Checks

The assertion is based on a flawed assumption: "Releasing a local read lock should never fail while still being the leader."

However, this assumption doesn't hold during node group leader transitions due to a race condition:

1. Lock Acquisition Phase: When a read lock is acquired, the current leader term is stored in CcEntryAddr.term_

2. Lock Release Phase: PostReadCc::Execute() in template_cc_map.h:1246-1254 checks if the stored term matches the current leader term:

   if (!Sharder::Instance().CheckLeaderTerm(cce_addr.NodeGroupId(),
                                            cce_addr.Term()) &&
       (standby_node_term < 0 || standby_node_term != cce_addr.Term()))
   {
       hd_res->SetError(CcErrorCode::REQUESTED_NODE_NOT_LEADER);
       return true;
   }

3. Error Handling Phase: After the error is returned, txm->CheckLeaderTerm() is called, which checks TxTerm() against the current leader term:

   bool CheckLeaderTerm() const
   {
       NodeGroupId ng_id = TxCcNodeId();
       if (Sharder::Instance().CheckLeaderTerm(ng_id, TxTerm()) || ...)
       {
           return true;
       }
       return false;
   }

The Race Condition:

• Between steps 2 and 3, the leader term may have changed again (recovered or stabilized)
• The cce_addr.Term() (old, stored term) ≠ current leader term → causes error in step 2
• But TxTerm() may still match the new leader term → CheckLeaderTerm() returns true in step 3
• This triggers the assertion even though the lock release legitimately failed due to term mismatch

Evidence from Logs

The logs show rapid, continuous leader updates happening concurrently with the transaction:

[thread 104865] [sharder.cpp:705] update node group ng0 leader to node_id: 0
[thread 104865] [sharder.cpp:705] update node group ng1 leader to node_id: 1
[thread 104865] [sharder.cpp:705] update node group ng2 leader to node_id: 2
[thread 104855] [tx_index_operation.cpp:403] downgrade_all_lock_to_intent_op_ txn: 10285
... (pattern repeats ~40+ times in rapid succession)
[thread 104855] [tx_index_operation.cpp:452] Alter Table Index transaction release cluster config lock, txn: 10285
mariadbd: ... Assertion `false' failed.

The downgrade_all_lock_to_intent_op_ was retrying repeatedly (which is correct behavior), but when it finally succeeded and moved to unlock_cluster_config_op_, the same term mismatch occurred without proper retry handling.

---

Affected Locations

The same flawed pattern exists in 3 locations:

File	Lines	Function	Operation Type
tx_index_operation.cpp	459-472	UpsertTableIndexOp::Forward	AddIndex/DropIndex
tx_operation.cpp	2656-2672	UpsertTableOp::Forward	CreateTable/Update/TruncateTable
tx_operation.cpp	4391-4406	FlushSplitTxOp::Forward	Split/Flush operations

---

Proposed Fix

Strategy

Replace the assert(false) with proper retry logic, similar to how downgrade_all_lock_to_intent_op_ handles errors:

1. Log a warning for monitoring
2. Re-lookup the cluster config entry from the read set (to get updated term)
3. Reset and retry the unlock operation

Fix 1: tx_index_operation.cpp (lines 459-472)

Before:

else if (op_ == &unlock_cluster_config_op_)
{
    if (unlock_cluster_config_op_.hd_result_.IsError())
    {
        if (txm->CheckLeaderTerm())
        {
            // Releasing a local read lock should never fail
            assert(false);
        }
        else
        {
            ForceToFinish(txm);
            return;
        }
    }
    else
    {
        // success path...
    }
}

After:

else if (op_ == &unlock_cluster_config_op_)
{
    if (unlock_cluster_config_op_.hd_result_.IsError())
    {
        if (txm->CheckLeaderTerm())
        {
            // Releasing a local read lock may fail during node group leader
            // transitions when the cce_addr term doesn't match the current
            // leader term. Retry with updated term.
            LOG(WARNING) << "unlock_cluster_config_op_ failed with error: "
                         << unlock_cluster_config_op_.hd_result_.ErrorCode()
                         << ", retrying, txn: " << txm->TxNumber();
            
            // Re-lookup and reset the unlock operation with updated term
            const CcEntryAddr *cluster_config_addr = nullptr;
            const ReadSetEntry *cluster_config_entry = nullptr;
            const auto &meta_rset = txm->rw_set_.MetaDataReadSet();
            for (const auto &[cce_addr, read_entry_pair] : meta_rset)
            {
                if (read_entry_pair.second == cluster_config_ccm_name_sv)
                {
                    cluster_config_addr = &cce_addr;
                    cluster_config_entry = &read_entry_pair.first;
                    break;
                }
            }
            assert(cluster_config_addr && cluster_config_entry);
            unlock_cluster_config_op_.Reset(cluster_config_addr,
                                            cluster_config_entry);
            txm->PushOperation(&unlock_cluster_config_op_);
            txm->Process(unlock_cluster_config_op_);
        }
        else
        {
            ForceToFinish(txm);
            return;
        }
    }
    else
    {
        // success path unchanged...
    }
}

Fix 2: tx_operation.cpp (lines 2656-2672, UpsertTableOp::Forward)

Before:

else if (op_ == &unlock_cluster_config_op_)
{
    assert(op_type_ == OperationType::CreateTable ||
           op_type_ == OperationType::Update ||
           op_type_ == OperationType::TruncateTable);
    if (unlock_cluster_config_op_.hd_result_.IsError())
    {
        if (txm->CheckLeaderTerm())
        {
            // Releasing a local read lock should never fail
            assert(false);
        }
        else
        {
            ForceToFinish(txm);
        }
    }
    // continues to next op...
}

After:

else if (op_ == &unlock_cluster_config_op_)
{
    assert(op_type_ == OperationType::CreateTable ||
           op_type_ == OperationType::Update ||
           op_type_ == OperationType::TruncateTable);
    if (unlock_cluster_config_op_.hd_result_.IsError())
    {
        if (txm->CheckLeaderTerm())
        {
            // Releasing a local read lock may fail during node group leader
            // transitions when the cce_addr term doesn't match the current
            // leader term. Retry with updated term.
            LOG(WARNING) << "unlock_cluster_config_op_ failed with error: "
                         << unlock_cluster_config_op_.hd_result_.ErrorCode()
                         << ", retrying, txn: " << txm->TxNumber();
            
            // Re-lookup and reset the unlock operation with updated term
            const CcEntryAddr *cluster_config_addr = nullptr;
            const ReadSetEntry *cluster_config_entry = nullptr;
            const auto &meta_rset = txm->rw_set_.MetaDataReadSet();
            for (const auto &[cce_addr, read_entry_pair] : meta_rset)
            {
                if (read_entry_pair.second == cluster_config_ccm_name_sv)
                {
                    cluster_config_addr = &cce_addr;
                    cluster_config_entry = &read_entry_pair.first;
                    break;
                }
            }
            assert(cluster_config_addr && cluster_config_entry);
            unlock_cluster_config_op_.Reset(cluster_config_addr,
                                            cluster_config_entry);
            txm->PushOperation(&unlock_cluster_config_op_);
            txm->Process(unlock_cluster_config_op_);
            return;  // Important: return after retry
        }
        else
        {
            ForceToFinish(txm);
            return;
        }
    }
    // success path unchanged...
}

Fix 3: tx_operation.cpp (lines 4391-4406, FlushSplitTxOp::Forward)

Before:

else if (op_ == &unlock_cluster_config_op_)
{
    if (unlock_cluster_config_op_.hd_result_.IsError())
    {
        if (txm->CheckLeaderTerm())
        {
            // Releasing a local read lock should never fail as long as
            // leader is not tranferred away.
            assert(false);
        }
        else
        {
            ForceToFinish(txm);
        }
        return;
    }
    // success path...
}

After:

else if (op_ == &unlock_cluster_config_op_)
{
    if (unlock_cluster_config_op_.hd_result_.IsError())
    {
        if (txm->CheckLeaderTerm())
        {
            // Releasing a local read lock may fail during node group leader
            // transitions when the cce_addr term doesn't match the current
            // leader term. Retry with updated term.
            LOG(WARNING) << "unlock_cluster_config_op_ failed with error: "
                         << unlock_cluster_config_op_.hd_result_.ErrorCode()
                         << ", retrying for FlushSplitTx, range id "
                         << range_info_->PartitionId()
                         << ", txn: " << txm->TxNumber();
            
            // Re-lookup and reset the unlock operation with updated term
            const CcEntryAddr *cluster_config_addr = nullptr;
            const ReadSetEntry *cluster_config_entry = nullptr;
            const auto &meta_rset = txm->rw_set_.MetaDataReadSet();
            for (const auto &[cce_addr, read_entry_pair] : meta_rset)
            {
                if (read_entry_pair.second == cluster_config_ccm_name_sv)
                {
                    cluster_config_addr = &cce_addr;
                    cluster_config_entry = &read_entry_pair.first;
                    break;
                }
            }
            assert(cluster_config_addr && cluster_config_entry);
            unlock_cluster_config_op_.Reset(cluster_config_addr,
                                            cluster_config_entry);
            txm->PushOperation(&unlock_cluster_config_op_);
            txm->Process(unlock_cluster_config_op_);
        }
        else
        {
            ForceToFinish(txm);
        }
        return;
    }
    // success path unchanged...
}

---

Design Considerations

Why Not Add a Retry Limit?

Looking at the existing downgrade_all_lock_to_intent_op_ retry pattern (which was looping ~40+ times in the logs), there is no retry limit. This is intentional because:

1. After the prepare log is flushed, the schema operation is guaranteed to succeed and can only roll forward
2. The transaction must eventually complete once committed
3. Leader transitions are typically transient

However, adding a retry limit with a final assert(false) could be considered for debugging unexpected infinite loops.

Why Re-lookup from ReadSet?

The cluster config entry is stored in txm->rw_set_.MetaDataReadSet(). While the CcEntryAddr stored there should have an updated term (since it's atomic), re-looking it up ensures we get the freshest state and follows the same pattern used when initially setting up the unlock operation.

Alternative: Check for Specific Error Code

A more defensive approach would be to only retry on REQUESTED_NODE_NOT_LEADER error and keep the assertion for truly unexpected errors:

if (unlock_cluster_config_op_.hd_result_.ErrorCode() == 
    CcErrorCode::REQUESTED_NODE_NOT_LEADER)
{
    // Retry logic...
}
else
{
    // Unexpected error - keep the assertion for debugging
    LOG(ERROR) << "Unexpected error in unlock_cluster_config_op_: "
               << unlock_cluster_config_op_.hd_result_.ErrorCode();
    assert(false);
}

---

Testing Recommendations

1. Unit Test: Create a test that simulates leader term changes during the unlock operation
2. Integration Test: Run the existing mono_multi.fault_create_drop_index test that triggered this crash
3. Stress Test: Run concurrent DDL operations with simulated leader elections
4. Regression Test: Ensure the fix doesn't affect normal operation paths

---

Files to Modify

File	Lines to Modify
data_substrate/tx_service/src/tx_index_operation.cpp	459-472
data_substrate/tx_service/src/tx_operation.cpp	2656-2672, 4391-4406

---

Open Questions

1. Should we add a retry limit for safety? If so, what's a reasonable maximum?
2. Should we only retry on REQUESTED_NODE_NOT_LEADER error specifically?
3. Are there other similar patterns in the codebase that should be audited?