kvserver: add TestFlowControlSendQueueRangeRelocate test #135570

kvoli · 2024-11-18T15:26:14Z

Add a flow control integration test
TestFlowControlSendQueueRangeRelocate. The test has 6 variations, either transferring or not transferring the lease ontop:

We three relocate variations (*=lh,^=send_queue):
- [n1*,n2 ,n3^,n4 ,n5] -> [n2 ,n3^,n4 ,n5 ,n6*] (transfer_lease)
  - The leader and leaseholder is relocated.
- [n1*,n2 ,n3^,n4 ,n5] -> [n1*,n2 ,n4 ,n5 ,n6 ]
  - The replica with a send queue is relocated.
- [n1*,n2 ,n3^,n4 ,n5] -> [n1*,n2 ,n3^,n4 ,n6 ]
  - The replica without a send queue is relocated.

Part of: #132614
Release note: None

blathers-crl · 2024-11-18T15:26:19Z

Your pull request contains more than 1000 changes. It is strongly encouraged to split big PRs into smaller chunks.

_{🦉 Hoot! I am a Blathers, a bot for CockroachDB. My owner is dev-inf.}

cockroach-teamcity · 2024-11-18T15:26:32Z

This change is

kvoli · 2024-11-19T22:53:34Z

I'm missing a variation here that relocates the replica towards a store which the leaseholder has a send queue for, but not for the range (because it doesn't yet have a replica on that store). It doesn't fit too neatly into this test, so I may hack in something to double check it works as expected then defer it to a later PR.

sumeerbhola

haven't finished reading, but pushing some questions about the testdata files.

Reviewed 6 of 7 files at r1.
Reviewable status: complete! 0 of 0 LGTMs obtained (waiting on @kvoli)

pkg/kv/kvserver/testdata/flow_control_integration_v2/send_queue_range_relocate_from_leader_store line 84 at r1 (raw file):
same question as above

After transfer, n6 should initially have a send-queue for n3 with 1 entry. Since no tokens have been consumed, this should be sent and appear in the tracker. And so the send-queue should be empty but 1 entry should be tracked. What am I missing?

pkg/kv/kvserver/testdata/flow_control_integration_v2/send_queue_range_relocate_from_has_token_store_transfer_lease line 79 at r1 (raw file):



-- Observe the total tracked tokens per-stream on new leaseholder n6.

After transfer, n6 should initially have a send-queue for n3 with 1 entry. Since no tokens have been consumed, this should be sent and appear in the tracker. And so the send-queue should be empty but 1 entry should be tracked. What am I missing?

pkg/kv/kvserver/flow_control_integration_test.go line 4923 at r1 (raw file):

// prevention and flushing via selective (logical) admission of entries and token
// return. It also exercises the behavior of the send queue when a range is
// relocated. See the initial comment for an overview of the test structure.

(note to self) stopped here

pkg/kv/kvserver/testdata/flow_control_integration_v2/send_queue_range_relocate_from_leader_store line 62 at r1 (raw file):

--   before=[0 1 2 3 4]
--   after =[5 1 2 3 4]
-- Transferring the lease false.

won't the lease get transferred anyway since the leaseholder is being removed? Just trying to understand -- I'm not saying that we should remove this variant.

pkg/kv/kvserver/testdata/flow_control_integration_v2/send_queue_range_relocate_from_has_token_store line 84 at r1 (raw file):



-- Observe the total tracked tokens per-stream on new leaseholder n1.

new leaseholder? It's the same leaseholder, yes?

kvoli

Reviewable status: complete! 0 of 0 LGTMs obtained (waiting on @sumeerbhola)

pkg/kv/kvserver/testdata/flow_control_integration_v2/send_queue_range_relocate_from_has_token_store line 84 at r1 (raw file):

Previously, sumeerbhola wrote…

new leaseholder? It's the same leaseholder, yes?

It is the same leaseholder, its an artifact of the test structure. I'll push a change to exclude the second print here if the lease didn't move.

pkg/kv/kvserver/testdata/flow_control_integration_v2/send_queue_range_relocate_from_has_token_store_transfer_lease line 79 at r1 (raw file):

Previously, sumeerbhola wrote…

After transfer, n6 should initially have a send-queue for n3 with 1 entry. Since no tokens have been consumed, this should be sent and appear in the tracker. And so the send-queue should be empty but 1 entry should be tracked. What am I missing?

First of all, thanks for catching this. I don't actually know why this is happening, it appears that the replica gets the queued entry sent to it without any corresponding token deduction or return from the new leaseholder/leader n6, prior to n6 creating a replica send stream towards s3.

Relevant logs:

# 1 MiB write to develop send queue.
I241125 21:46:12.124574 72 kv/kvserver_test/flow_control_integration_test.go:5614 ⋮ [-] 818  ‹(Sending 1 MiB put request to develop a send queue)›
I241125 21:46:12.124779 72 kv/kvserver/kvflowcontrol/rac2/range_controller.go:850 ⋮ [T1,Vsystem,n1] 819  r74/1 admitted request (pri=‹normal-pri› wait-duration=1.75µs wait-for-all=false)

# Corresponding token deductions and tracking on n1.
I241125 21:46:12.125196 935 kv/kvserver/replica_proposal_buf.go:926 ⋮ [T1,Vsystem,n1,s1,r74/1:‹/{Table/Max-Max}›,raft] 820  bound index/log terms for proposal entry: ‹6/33 EntryNormal <omitted>›
I241125 21:46:12.125250 935 kv/kvserver/kvflowcontrol/rac2/token_tracker.go:87 ⋮ [T1,Vsystem,n1,s1,r74/1:‹/{Table/Max-Max}›,raft] 821  tracking ‹+1.0 MiB› flow control tokens for pri=NormalPri stream=t‹1›/s‹1› log-position=6/33
I241125 21:46:12.125293 935 kv/kvserver/kvflowcontrol/rac2/token_counter.go:630 ⋮ [T1,Vsystem,n1,s1,r74/1:‹/{Table/Max-Max}›,raft] 822  adjusted send flow tokens (wc=regular stream=t‹1›/s‹1› delta=‹-1.0 MiB› flag=‹normal›): regular=‹+3.0 MiB› elastic=‹+1.0 MiB›
I241125 21:46:12.125337 935 kv/kvserver/kvflowcontrol/rac2/token_counter.go:630 ⋮ [T1,Vsystem,n1,s1,r74/1:‹/{Table/Max-Max}›,raft] 823  adjusted eval flow tokens (wc=regular stream=t‹1›/s‹1› delta=‹-1.0 MiB› flag=‹normal›): regular=‹+3.0 MiB› elastic=‹+1.0 MiB›
I241125 21:46:12.125375 935 kv/kvserver/kvflowcontrol/rac2/token_tracker.go:87 ⋮ [T1,Vsystem,n1,s1,r74/1:‹/{Table/Max-Max}›,raft] 824  tracking ‹+1.0 MiB› flow control tokens for pri=NormalPri stream=t‹1›/s‹2› log-position=6/33
I241125 21:46:12.125407 935 kv/kvserver/kvflowcontrol/rac2/token_counter.go:630 ⋮ [T1,Vsystem,n1,s1,r74/1:‹/{Table/Max-Max}›,raft] 825  adjusted send flow tokens (wc=regular stream=t‹1›/s‹2› delta=‹-1.0 MiB› flag=‹normal›): regular=‹+3.0 MiB› elastic=‹+1.0 MiB›
I241125 21:46:12.125448 935 kv/kvserver/kvflowcontrol/rac2/token_counter.go:630 ⋮ [T1,Vsystem,n1,s1,r74/1:‹/{Table/Max-Max}›,raft] 826  adjusted eval flow tokens (wc=regular stream=t‹1›/s‹2› delta=‹-1.0 MiB› flag=‹normal›): regular=‹+3.0 MiB› elastic=‹+1.0 MiB›
I241125 21:46:12.125501 935 kv/kvserver/kvflowcontrol/rac2/token_counter.go:630 ⋮ [T1,Vsystem,n1,s1,r74/1:‹/{Table/Max-Max}›,raft] 827  adjusted eval flow tokens (wc=elastic stream=t‹1›/s‹3› delta=‹-1.0 MiB› flag=‹normal›): regular=‹+0 B› elastic=‹-3.0 MiB›
I241125 21:46:12.125563 935 kv/kvserver/kvflowcontrol/rac2/token_tracker.go:87 ⋮ [T1,Vsystem,n1,s1,r74/1:‹/{Table/Max-Max}›,raft] 828  tracking ‹+1.0 MiB› flow control tokens for pri=NormalPri stream=t‹1›/s‹4› log-position=6/33
I241125 21:46:12.125595 935 kv/kvserver/kvflowcontrol/rac2/token_counter.go:630 ⋮ [T1,Vsystem,n1,s1,r74/1:‹/{Table/Max-Max}›,raft] 829  adjusted send flow tokens (wc=regular stream=t‹1›/s‹4› delta=‹-1.0 MiB› flag=‹normal›): regular=‹+3.0 MiB› elastic=‹+1.0 MiB›
I241125 21:46:12.125629 935 kv/kvserver/kvflowcontrol/rac2/token_counter.go:630 ⋮ [T1,Vsystem,n1,s1,r74/1:‹/{Table/Max-Max}›,raft] 830  adjusted eval flow tokens (wc=regular stream=t‹1›/s‹4› delta=‹-1.0 MiB› flag=‹normal›): regular=‹+3.0 MiB› elastic=‹+1.0 MiB›
I241125 21:46:12.125691 935 kv/kvserver/kvflowcontrol/rac2/token_tracker.go:87 ⋮ [T1,Vsystem,n1,s1,r74/1:‹/{Table/Max-Max}›,raft] 831  tracking ‹+1.0 MiB› flow control tokens for pri=NormalPri stream=t‹1›/s‹5› log-position=6/33
I241125 21:46:12.125719 935 kv/kvserver/kvflowcontrol/rac2/token_counter.go:630 ⋮ [T1,Vsystem,n1,s1,r74/1:‹/{Table/Max-Max}›,raft] 832  adjusted send flow tokens (wc=regular stream=t‹1›/s‹5› delta=‹-1.0 MiB› flag=‹normal›): regular=‹+3.0 MiB› elastic=‹+1.0 MiB›
I241125 21:46:12.125805 935 kv/kvserver/kvflowcontrol/rac2/token_counter.go:630 ⋮ [T1,Vsystem,n1,s1,r74/1:‹/{Table/Max-Max}›,raft] 833  adjusted eval flow tokens (wc=regular stream=t‹1›/s‹5› delta=‹-1.0 MiB› flag=‹normal›): regular=‹+3.0 MiB› elastic=‹+1.0 MiB›

# Admitted on all nodes except 3
I241125 21:46:12.129688 938 kv/kvserver/kvflowcontrol/rac2/range_controller.go:2123 ⋮ [T1,Vsystem,n1] 856  r74:(n2,s2):2 stream t‹1›/s‹2› admit term:6, admitted:[LowPri:33,NormalPri:33,AboveNormalPri:33,HighPri:33] returned send:NormalPri:+1.0 MiB eval:NormalPri:+1.0 MiB
I241125 21:46:12.353456 940 kv/kvserver/kvflowcontrol/rac2/range_controller.go:2123 ⋮ [T1,Vsystem,n1,s1,r74/1:‹/{Table/Max-Max}›,raft] 862  r74:(n1,s1):1 stream t‹1›/s‹1› admit term:6, admitted:[LowPri:33,NormalPri:33,AboveNormalPri:33,HighPri:33] returned send:NormalPri:+1.0 MiB eval:NormalPri:+1.0 MiB
I241125 21:46:12.650124 930 kv/kvserver/kvflowcontrol/rac2/range_controller.go:2123 ⋮ [T1,Vsystem,n1] 865  r74:(n5,s5):5 stream t‹1›/s‹5› admit term:6, admitted:[LowPri:33,NormalPri:33,AboveNormalPri:33,HighPri:33] returned send:NormalPri:+1.0 MiB eval:NormalPri:+1.0 MiB
I241125 21:46:12.805797 931 kv/kvserver/kvflowcontrol/rac2/range_controller.go:2123 ⋮ [T1,Vsystem,n1] 868  r74:(n4,s4):4 stream t‹1›/s‹4› admit term:6, admitted:[LowPri:33,NormalPri:33,AboveNormalPri:33,HighPri:33] returned send:NormalPri:+1.0 MiB eval:NormalPri:+1.0 MiB

# Relocate happens here
I241125 21:46:13.241297 72 kv/kvserver_test/flow_control_integration_test.go:5614 ⋮ [-] 882  ‹-- Issuing RelocateRange:›
I241125 21:46:13.241297 72 kv/kvserver_test/flow_control_integration_test.go:5614 ⋮ [-] 882 +‹--   before=[0 1 2 3 4]›
I241125 21:46:13.241297 72 kv/kvserver_test/flow_control_integration_test.go:5614 ⋮ [-] 882 +‹--   after =[5 0 1 2 3]›
I241125 21:46:13.241297 72 kv/kvserver_test/flow_control_integration_test.go:5614 ⋮ [-] 882 +‹-- Transferring the lease: true.›
I241125 21:46:13.247153 935 kv/kvserver/kvflowcontrol/rac2/range_controller.go:2158 ⋮ [T1,Vsystem,n1,s1,r74/1:‹/{Table/Max-Max}›,raft] 914  creating send stream t‹1›/s‹6› for replica (n6,s6):6LEARNER
I241125 21:46:13.261469 940 kv/kvserver/kvflowcontrol/rac2/range_controller.go:2526 ⋮ [T1,Vsystem,n1,s1,r74/1:‹/{Table/Max-Max}›,raft] 1013  closing send stream t‹1›/s‹5› for replica (n5,s5):5LEARNER
I241125 21:46:13.262111 936 kv/kvserver/kvflowcontrol/rac2/range_controller.go:1502 ⋮ [T1,Vsystem,n1,s1,r74/1:‹/{Table/Max-Max}›,raft] 1026  r74 closing range controller
I241125 21:46:13.262122 936 kv/kvserver/kvflowcontrol/rac2/range_controller.go:2526 ⋮ [T1,Vsystem,n1,s1,r74/1:‹/{Table/Max-Max}›,raft] 1027  closing send stream t‹1›/s‹2› for replica (n2,s2):2
I241125 21:46:13.262133 936 kv/kvserver/kvflowcontrol/rac2/range_controller.go:2526 ⋮ [T1,Vsystem,n1,s1,r74/1:‹/{Table/Max-Max}›,raft] 1030  closing send stream t‹1›/s‹3› for replica (n3,s3):3
I241125 21:46:13.262145 936 kv/kvserver/kvflowcontrol/rac2/token_counter.go:630 ⋮ [T1,Vsystem,n1,s1,r74/1:‹/{Table/Max-
I241125 21:46:13.262202 936 kv/kvserver/kvflowcontrol/rac2/range_controller.go:2526 ⋮ [T1,Vsystem,n1,s1,r74/1:‹/{Table/Max-Max}›,raft] 1035  closing send stream t‹1›/s‹4› for replica (n4,s4):4
I241125 21:46:13.262211 936 kv/kvserver/kvflowcontrol/rac2/range_controller.go:2526 ⋮ [T1,Vsystem,n1,s1,r74/1:‹/{Table/Max-Max}›,raft] 1036  closing send stream t‹1›/s‹6› for replica (n6,s6):6
I241125 21:46:13.262220 936 kv/kvserver/kvflowcontrol/rac2/range_controller.go:2526 ⋮ [T1,Vsystem,n1,s1,r74/1:‹/{Table/Max-Max}›,raft] 1037  closing send stream t‹1›/s‹1› for replica (n1,s1):1

# Raft messages between the relocate start and here that involve n3.
I241125 21:46:13.268683 8952 kv/kvserver_test/client_raft_helpers_test.go:104 ⋮ [T1,Vsystem,n3] 1045   [raft] r74 Raft message ‹6->3 MsgVote Term:7 Log:6/42›
I241125 21:46:13.273685 9058 kv/kvserver_test/client_raft_helpers_test.go:104 ⋮ [T1,Vsystem,n6] 1051   [raft] r74 Raft message ‹3->6 MsgVoteResp Term:7 Log:0/0›


# n6 creates range controller after being given the lead (and lease via a joint cfg).
# Note here that n6 is sending messages to n3 without tracking/deducting tokens for them. Later, when the put
# request is sent to the post-relocated range, it does track the entries.
I241125 21:46:13.273739 5970 kv/kvserver/kvflowcontrol/rac2/range_controller.go:673 ⋮ [T1,Vsystem,n6,s6,r74/6:‹/{Table/Max-Max}›,raft] 1052  r74 creating range controller
I241125 21:46:13.273765 5970 kv/kvserver/kvflowcontrol/rac2/range_controller.go:2158 ⋮ [T1,Vsystem,n6,s6,r74/6:‹/{Table/Max-Max}›,raft] 1053  creating send stream t‹1›/s‹6› for replica (n6,s6):6
I241125 21:46:13.273928 8952 kv/kvserver_test/client_raft_helpers_test.go:104 ⋮ [T1,Vsystem,n3] 1055   [raft] r74 Raft message ‹6->3 MsgApp Term:7 Log:6/42 Commit:42 Entries:[7/43 EntryNormal <omitted>]›
I241125 21:46:13.274028 9058 kv/kvserver_test/client_raft_helpers_test.go:104 ⋮ [T1,Vsystem,n6] 1058   [raft] r74 Raft message ‹3->6 MsgAppResp Term:7 Log:6/42 Rejected (Hint: 32) Commit:32›
I241125 21:46:13.274143 5971 kv/kvserver/kvflowcontrol/rac2/range_controller.go:2158 ⋮ [T1,Vsystem,n6,s6,r74/6:‹/{Table/Max-Max}›,raft] 1060  creating send stream t‹1›/s‹1› for replica (n1,s1):1
I241125 21:46:13.275635 9058 kv/kvserver_test/client_raft_helpers_test.go:104 ⋮ [T1,Vsystem,n6] 1065   [raft] r74 Raft message ‹3->6 MsgAppResp Term:7 Log:0/42 Commit:42›
I241125 21:46:13.275658 5976 kv/kvserver/kvflowcontrol/rac2/range_controller.go:2158 ⋮ [T1,Vsystem,n6,s6,r74/6:‹/{Table/Max-Max}›,raft] 1066  creating send stream t‹1›/s‹3› for replica (n3,s3):3
I241125 21:46:13.275893 8952 kv/kvserver_test/client_raft_helpers_test.go:104 ⋮ [T1,Vsystem,n3] 1067   [raft] r74 Raft message ‹6->3 MsgApp Term:7 Log:6/42 Commit:42›
I241125 21:46:13.275911 8952 kv/kvserver_test/client_raft_helpers_test.go:104 ⋮ [T1,Vsystem,n3] 1068   [raft] r74 Raft message ‹6->3 MsgApp Term:7 Log:6/42 Commit:42 Entries:[›
I241125 21:46:13.275911 8952 kv/kvserver_test/client_raft_helpers_test.go:104 ⋮ [T1,Vsystem,n3] 1068 +‹  7/43 EntryNormal <omitted>›
I241125 21:46:13.275911 8952 kv/kvserver_test/client_raft_helpers_test.go:104 ⋮ [T1,Vsystem,n3] 1068 +‹  7/44 EntryNormal <omitted>›
I241125 21:46:13.275911 8952 kv/kvserver_test/client_raft_helpers_test.go:104 ⋮ [T1,Vsystem,n3] 1068 +‹]›
I241125 21:46:13.276180 9058 kv/kvserver_test/client_raft_helpers_test.go:104 ⋮ [T1,Vsystem,n6] 1069   [raft] r74 Raft message ‹3->6 MsgAppResp Term:7 Log:0/44 Commit:42›
I241125 21:46:13.276180 9058 kv/kvserver_test/client_raft_helpers_test.go:104 ⋮ [T1,Vsystem,n6] 1069   [raft] r74 Raft message ‹3->6 MsgAppResp Term:7 Log:0/44 Commit:42›
I241125 21:46:13.276315 8952 kv/kvserver_test/client_raft_helpers_test.go:104 ⋮ [T1,Vsystem,n3] 1072   [raft] r74 Raft message ‹6->3 MsgApp Term:7 Log:7/44 Commit:44›
I241125 21:46:13.276424 5973 kv/kvserver/kvflowcontrol/rac2/range_controller.go:2158 ⋮ [T1,Vsystem,n6,s6,r74/6:‹/{Table/Max-Max}›,raft] 1078  creating send stream t‹1›/s‹4› for replica (n4,s4):4
I241125 21:46:13.276446 9058 kv/kvserver_test/client_raft_helpers_test.go:104 ⋮ [T1,Vsystem,n6] 1079   [raft] r74 Raft message ‹3->6 MsgAppResp Term:7 Log:0/44 Commit:44›
I241125 21:46:13.276456 8914 kv/kvserver_test/client_raft_helpers_test.go:104 ⋮ [T1,Vsystem,n6] 1080   [raft] r74 Raft message ‹1->6 MsgAppResp Term:7 Log:0/44 Commit:44›
I241125 21:46:13.276468 5973 kv/kvserver/kvflowcontrol/rac2/range_controller.go:2158 ⋮ [T1,Vsystem,n6,s6,r74/6:‹/{Table/Max-Max}›,raft] 1081  creating send stream t‹1›/s‹2› for replica (n2,s2):2

# Issuing post-relocate put at n6 the new leaseholder.
I241125 21:46:13.277437 72 kv/kvserver_test/flow_control_integration_test.go:5614 ⋮ [-] 1094  ‹(Sending 1 MiB put request to the relocated range)›
I241125 21:46:13.277854 72 kv/kvserver/kvflowcontrol/rac2/range_controller.go:850 ⋮ [T1,Vsystem,n6] 1095  r74/6 admitted request (pri=‹normal-pri› wait-duration=541ns wait-for-all=false)
I241125 21:46:13.277966 5980 kv/kvserver/kvflowcontrol/rac2/token_tracker.go:87 ⋮ [T1,Vsystem,n6,s6,r74/6:‹/{Table/Max-Max}›,raft] 1097  tracking ‹+1.0 MiB› flow control tokens for pri=NormalPri stream=t‹1›/s‹1› log-position=7/45
I241125 21:46:13.277979 5980 kv/kvserver/kvflowcontrol/rac2/token_counter.go:630 ⋮ [T1,Vsystem,n6,s6,r74/6:‹/{Table/Max-Max}›,raft] 1098  adjusted send flow tokens (wc=regular stream=t‹1›/s‹1› delta=‹-1.0 MiB› flag=‹normal›): regular=‹+3.0 MiB› elastic=‹+1.0 MiB›
I241125 21:46:13.277992 5980 kv/kvserver/kvflowcontrol/rac2/token_counter.go:630 ⋮ [T1,Vsystem,n6,s6,r74/6:‹/{Table/Max-Max}›,raft] 1099  adjusted eval flow tokens (wc=regular stream=t‹1›/s‹1› delta=‹-1.0 MiB› flag=‹normal›): regular=‹+3.0 MiB› elastic=‹+1.0 MiB›
I241125 21:46:13.278009 5980 kv/kvserver/kvflowcontrol/rac2/token_tracker.go:87 ⋮ [T1,Vsystem,n6,s6,r74/6:‹/{Table/Max-Max}›,raft] 1100  tracking ‹+1.0 MiB› flow control tokens for pri=NormalPri stream=t‹1›/s‹2› log-position=7/45
I241125 21:46:13.278022 5980 kv/kvserver/kvflowcontrol/rac2/token_counter.go:630 ⋮ [T1,Vsystem,n6,s6,r74/6:‹/{Table/Max-Max}›,raft] 1101  adjusted send flow tokens (wc=regular stream=t‹1›/s‹2› delta=‹-1.0 MiB› flag=‹normal›): regular=‹+3.0 MiB› elastic=‹+1.0 MiB›
I241125 21:46:13.278036 5980 kv/kvserver/kvflowcontrol/rac2/token_counter.go:630 ⋮ [T1,Vsystem,n6,s6,r74/6:‹/{Table/Max-Max}›,raft] 1102  adjusted eval flow tokens (wc=regular stream=t‹1›/s‹2› delta=‹-1.0 MiB› flag=‹normal›): regular=‹+3.0 MiB› elastic=‹+1.0 MiB›
I241125 21:46:13.278055 5980 kv/kvserver/kvflowcontrol/rac2/token_tracker.go:87 ⋮ [T1,Vsystem,n6,s6,r74/6:‹/{Table/Max-Max}›,raft] 1103  tracking ‹+1.0 MiB› flow control tokens for pri=NormalPri stream=t‹1›/s‹3› log-position=7/45
I241125 21:46:13.278065 5980 kv/kvserver/kvflowcontrol/rac2/token_counter.go:630 ⋮ [T1,Vsystem,n6,s6,r74/6:‹/{Table/Max-Max}›,raft] 1104  adjusted send flow tokens (wc=regular stream=t‹1›/s‹3› delta=‹-1.0 MiB› flag=‹normal›): regular=‹+3.0 MiB› elastic=‹+1.0 MiB›
I241125 21:46:13.278077 5980 kv/kvserver/kvflowcontrol/rac2/token_counter.go:630 ⋮ [T1,Vsystem,n6,s6,r74/6:‹/{Table/Max-Max}›,raft] 1105  adjusted eval flow tokens (wc=regular stream=t‹1›/s‹3› delta=‹-1.0 MiB› flag=‹normal›): regular=‹+3.0 MiB› elastic=‹+1.0 MiB›
I241125 21:46:13.278101 5980 kv/kvserver/kvflowcontrol/rac2/token_tracker.go:87 ⋮ [T1,Vsystem,n6,s6,r74/6:‹/{Table/Max-Max}›,raft] 1106  tracking ‹+1.0 MiB› flow control tokens for pri=NormalPri stream=t‹1›/s‹4› log-position=7/45
I241125 21:46:13.278112 5980 kv/kvserver/kvflowcontrol/rac2/token_counter.go:630 ⋮ [T1,Vsystem,n6,s6,r74/6:‹/{Table/Max-Max}›,raft] 1108  adjusted send flow tokens (wc=regular stream=t‹1›/s‹4› delta=‹-1.0 MiB› flag=‹normal›): regular=‹+3.0 MiB› elastic=‹+1.0 MiB›
I241125 21:46:13.278126 5980 kv/kvserver/kvflowcontrol/rac2/token_counter.go:630 ⋮ [T1,Vsystem,n6,s6,r74/6:‹/{Table/Max-Max}›,raft] 1110  adjusted eval flow tokens (wc=regular stream=t‹1›/s‹4› delta=‹-1.0 MiB› flag=‹normal›): regular=‹+3.0 MiB› elastic=‹+1.0 MiB›
I241125 21:46:13.278142 5980 kv/kvserver/kvflowcontrol/rac2/token_tracker.go:87 ⋮ [T1,Vsystem,n6,s6,r74/6:‹/{Table/Max-Max}›,raft] 1111  tracking ‹+1.0 MiB› flow control tokens for pri=NormalPri stream=t‹1›/s‹6› log-position=7/45
I241125 21:46:13.278154 5980 kv/kvserver/kvflowcontrol/rac2/token_counter.go:630 ⋮ [T1,Vsystem,n6,s6,r74/6:‹/{Table/Max-Max}›,raft] 1114  adjusted send flow tokens (wc=regular stream=t‹1›/s‹6› delta=‹-1.0 MiB› flag=‹normal›): regular=‹+3.0 MiB› elastic=‹+1.0 MiB›

pkg/kv/kvserver/testdata/flow_control_integration_v2/send_queue_range_relocate_from_leader_store line 62 at r1 (raw file):

Previously, sumeerbhola wrote…

won't the lease get transferred anyway since the leaseholder is being removed? Just trying to understand -- I'm not saying that we should remove this variant.

Yeah it will, its just whether it transfers the lease explicitly via an AdminTransferLease. The relocate logic slightly changes, mostly the the timing of the lease transfer -- whether its to a voter incoming, or to a full voter also.

kvoli · 2024-11-25T22:33:47Z

For whatever reason, I'm no longer able to comment on reviewable without it wiping my text (probably the long code comment).

After transfer, n6 should initially have a send-queue for n3 with 1 entry. Since no tokens have been consumed, this should be sent and appear in the tracker. And so the send-queue should be empty but 1 entry should be tracked. What am I missing?
First of all, thanks for catching this. I don't actually know why this is happening, it appears that the replica gets the queued entry sent to it without any corresponding token deduction or return from the new leaseholder/leader n6, prior to n6 creating a replica send stream towards s3.

s3 enters StateSnapshot iiuc, this is how it sidesteps tracking the entry:

I241125 22:27:38.893185 6008 kv/kvserver/kvflowcontrol/rac2/range_controller.go:1057 ⋮ [T1,Vsystem,n6,s6,r74/6:‹/{Table/Max-Max}›,raft] 1270  r74 handling raft event: term=0 snap=‹<nil>› entries=[] msgApps=map[] replicaStateInfo=map[1:{StateProbe 0 44} 2:{StateReplicate 44 45} 3:{StateSnapshot 0 44} 4:{StateProbe 0 44} 6:{StateReplicate 44 45}] msgAppMode=‹1›
...
I241125 22:27:38.895093 9150 kv/kvserver/replica_raftstorage.go:521 ⋮ [T1,Vsystem,n3,s3,r74/3:‹/{Table/Max-Max}›] 1288  applied snapshot d816383e from (n6,s6):6 at applied index 44 (total=1ms data=1.9 KiB excise=true ingestion=6@0ms)

sumeerbhola · 2024-11-25T23:17:09Z

s3 enters StateSnapshot iiuc, this is how it sidesteps tracking the entry

Ah yes, this makes sense. Since s6 is a new replica it doesn't have the raft log entries from the previous put -- it was created using a snapshot after the put. So a replica with a send-queue can only be caught up with a snapshot. I wonder if we will start seeing more snapshotting due to this behavior. It would be nice to have the ability to delegate the sending of entries, akin to delegated snapshots. Should I create an issue?

sumeerbhola

Reviewed 1 of 7 files at r1.
Reviewable status: complete! 1 of 0 LGTMs obtained (waiting on @kvoli)

pkg/kv/kvserver/testdata/flow_control_integration_v2/send_queue_range_relocate_from_has_token_store line 84 at r1 (raw file):

Previously, kvoli (Austen) wrote…

It is the same leaseholder, its an artifact of the test structure. I'll push a change to exclude the second print here if the lease didn't move.

sounds good

pkg/kv/kvserver/flow_control_integration_test.go line 4923 at r1 (raw file):

Previously, sumeerbhola wrote…

(note to self) stopped here

done

Add a flow control integration test `TestFlowControlSendQueueRangeRelocate`. The test has 6 variations, either transferring or not transferring the lease on-top: ``` We use three relocate variations (*=lh,^=send_queue): - [n1*,n2 ,n3^,n4 ,n5] -> [n2 ,n3^,n4 ,n5 ,n6*] (transfer_lease) - The leader and leaseholder is relocated. - [n1*,n2 ,n3^,n4 ,n5] -> [n1*,n2 ,n4 ,n5 ,n6 ] - The replica with a send queue is relocated. - [n1*,n2 ,n3^,n4 ,n5] -> [n1*,n2 ,n3^,n4 ,n6 ] - The replica without a send queue is relocated. ``` Part of: cockroachdb#132614 Release note: None

kvoli · 2024-11-26T16:21:38Z

Rebased to resolve merge conflicts.

kvoli · 2024-11-26T18:52:44Z

Extended CI failure is on bench. TYFTR!

bors r=sumeerbhola

craig · 2024-11-26T19:25:00Z

Build succeeded:

kvoli self-assigned this Nov 18, 2024

kvoli added the backport-24.3.x Flags PRs that need to be backported to 24.3 label Nov 18, 2024

kvoli mentioned this pull request Nov 18, 2024

kvserver: [dnm] add RACv2 failing split/merge/migrate repros #135339

Closed

kvoli force-pushed the 241118.rac-send-queue-relocate-test branch 2 times, most recently from 160b25e to 19a8a6a Compare November 19, 2024 22:51

kvoli requested a review from sumeerbhola November 19, 2024 23:01

kvoli marked this pull request as ready for review November 19, 2024 23:01

kvoli requested a review from a team as a code owner November 19, 2024 23:01

sumeerbhola requested changes Nov 21, 2024

View reviewed changes

kvoli requested a review from sumeerbhola November 25, 2024 22:08

kvoli commented Nov 25, 2024

View reviewed changes

sumeerbhola approved these changes Nov 25, 2024

View reviewed changes

kvoli force-pushed the 241118.rac-send-queue-relocate-test branch from 19a8a6a to 2fd7fdd Compare November 26, 2024 14:14

kvoli force-pushed the 241118.rac-send-queue-relocate-test branch from 2fd7fdd to 07ce9fd Compare November 26, 2024 16:21

kvoli removed the backport-24.3.x Flags PRs that need to be backported to 24.3 label Nov 26, 2024

craig bot merged commit aded21f into cockroachdb:master Nov 26, 2024
22 of 23 checks passed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

kvserver: add TestFlowControlSendQueueRangeRelocate test #135570

kvserver: add TestFlowControlSendQueueRangeRelocate test #135570

kvoli commented Nov 18, 2024

blathers-crl bot commented Nov 18, 2024

cockroach-teamcity commented Nov 18, 2024

kvoli commented Nov 19, 2024

sumeerbhola left a comment

kvoli left a comment •

edited

Loading

kvoli commented Nov 25, 2024

sumeerbhola commented Nov 25, 2024

sumeerbhola left a comment

kvoli commented Nov 26, 2024

kvoli commented Nov 26, 2024

craig bot commented Nov 26, 2024

kvserver: add TestFlowControlSendQueueRangeRelocate test #135570

kvserver: add TestFlowControlSendQueueRangeRelocate test #135570

Conversation

kvoli commented Nov 18, 2024

blathers-crl bot commented Nov 18, 2024

cockroach-teamcity commented Nov 18, 2024

kvoli commented Nov 19, 2024

sumeerbhola left a comment

Choose a reason for hiding this comment

kvoli left a comment • edited Loading

Choose a reason for hiding this comment

kvoli commented Nov 25, 2024

sumeerbhola commented Nov 25, 2024

sumeerbhola left a comment

Choose a reason for hiding this comment

kvoli commented Nov 26, 2024

kvoli commented Nov 26, 2024

craig bot commented Nov 26, 2024

kvoli left a comment •

edited

Loading