Messaging: Avoid deadlocks related to 0 receiver behavior

[mattlord]

Description

There's conditional behavior and code paths in the message manager when the number of receivers is 0. The main mutex and the stream mutex locks are used to ensure overall consistency. But:

1. The order that those locks are taken in was not enforced or consistent
2. There was a gap in the poller between when the 0 receiver code path was checked — specifically that it was NOT 0 — and the main mutex lock was taken to ensure that this invariant holds during the polling run here:

   vitess/go/vt/vttablet/tabletserver/messager/message_manager.go

   Lines 752 to 787 in c985379

   	// Fast-path. Skip all the work.
   	if mm.receiverCount() == 0 {
   	return
   	}
   	mm.streamMu.Lock()
   	defer mm.streamMu.Unlock()
   	ctx, cancel := context.WithTimeout(tabletenv.LocalContext(), mm.pollerTicks.Interval())
   	defer func() {
   	mm.tsv.LogError()
   	cancel()
   	}()
   	size := mm.cache.Size()
   	bindVars := map[string]*querypb.BindVariable{
   	"time_next": sqltypes.Int64BindVariable(time.Now().UnixNano()),
   	"max": sqltypes.Int64BindVariable(int64(size)),
   	}
   	qr, err := mm.readPending(ctx, bindVars)
   	if err != nil {
   	return
   	}
   	// Obtain mu lock to verify and preserve that len(receivers) != 0.
   	mm.mu.Lock()
   	defer mm.mu.Unlock()
   	mm.messagesPending = false
   	if len(qr.Rows) >= size {
   	// There are probably more messages to be sent.
   	mm.messagesPending = true
   	}
   	if len(mm.receivers) == 0 {
   	// Almost never reachable because we just checked this.
   	return
   	}

These two factors can lead to deadlocks when the receiver count goes to/from 0 while the the poller runs:

In unsubscribe() we have the main mutex, and while holding it we then call stopVStream() if the subscriber/receiver count is at 0. Then stopVStream() tries to get the stream mutex.

Concurrently, runPoller() — which by default, or more accurately when using the documented message table structure here via the vt_poller_interval comment directive, runs on a 30 second ticker — gets the stream mutex first, then it later tries to get the main mutex.

Now we are deadlocked. They're both waiting on each other.

This then in turn causes things like PlannedReparentShard to hang because during the transition from primary serving we stop/close the message service, which in turn will wait trying to get the main mutex.

Changes

1. We clean up the mutex usage. In order to ensure that the cache stays in sync with the database and we are moving forward linearly though the logical GTID stream — updated by the poller and its results streamer, and the binlog streamer — we now use the cacheManagementMu lock. The explicit usage of this new mutex allows us to avoid the deadlocks seen before because it's taken immediately when the poller or binlog streamer process data coming from the database (which is used to update the cache), and we no longer need to take this lock when starting or stopping the binlog streamer itself.
   • After the initial changes made in the PR I could see that we were still prone to deadlocks in various places due to checking the receiver count all the time (I could see this in the race test stack traces, see Notes below), which required the main mutex, while holding the stream mutex. Anywhere we were holding the stream mutex, and checking receiver count — which we did A LOT, for example when processing every row event from the binlog stream via processRowEvent()->Add() — we were at risk of a deadlock. The main mutex became VERY hot because we were checking the receiver count all the time to ensure the fast path (do nothing when there's no receivers).
2. We add an important predicate to the poller query — time_acked is null — to try and limit the size of scans done on the underlying message table to try and ensure that the poller runs quickly. This aspect is important because the binlog event processing is blocked during this time. It also prevents us from doing unnecessary work as InnoDB does most of the work — all query (WHERE) predicates become index condition pushdowns and the new poller_idx index can be used for the ordering to apply the LIMIT as well — and passes the minimum amount of potentially useful data up the stack InnoDB->MySQL->MessageManager->Cache.
3. We update the tests so that we're using the new recommended/documented (see docs ticket below) message table structure and thus we're testing behavior with the structure we tell users to use.

Notes

This is able to complete on vitessio/main:

$ make build; failed=0; for i in {1..100}; do if ! go test -race -v -failfast -timeout 1m vitess.io/vitess/go/vt/vttablet/tabletserver/messager; then echo -e '\nUh oh! We have a problem...\n'; failed=1; break; fi; go clean -testcache; done; if [[ ${failed} -eq 0 ]]; then echo -e '\nWe made it! All good...\n'; fi

Whatever changes are made here we should continue to pass that test (it does). It's even more reliable now — you can run it 1,000 times and no flakiness.

Related Issue(s)

• Fixes: Bug Report: vttablet hanging when running PlannedReparentShard #9936

Checklist

• "Backport me!" label has been added if this change should be backported
• Tests are not required (the existing unit and e2e tests cover the behavior)
• Documentation: Update message table schema for efficient poller and w/o potential message loss website#1015

[derekperkins]

Looks like the majority of tests are failing on

--- FAIL: TestMessageStreamingPlan (0.00s)
    plan_test.go:239: 
        	Error Trace:	plan_test.go:239
        	Error:      	Received unexpected error:
        	            	Code: FAILED_PRECONDITION
        	            	'msg' is not a message table
        	Test:       	TestMessageStreamingPlan

[derekperkins]

@mattlord you really rolled through quite a few iterations, thanks again for digging in so deep. I don't think I have enough context around vstream to provide much feedback on the latest design. Once @rohit-nayak-ps approves it, I'm ready to roll it out in prod to test it out.

[mattlord]

Note that the Cluster (20) -> backup_xtrabackup test failure is due to: #10146

[derekperkins]

@mattlord is this still waiting on @rohit-nayak-ps, or was pairing with @sougou sufficient review?

[derekperkins]

🎉 Thanks so much for tracking this down!! I'll be rolling it out later today

[mattlord]

🎉 Thanks so much for tracking this down!! I'll be rolling it out later today

Excellent! Please let me know how things go.