Files
tasks/service/history/replication/stream_sender_flow_controller.go
Lina JodoinandGitHub 55ef6985d8 Move a few occurrences of variables logged inline into tags (#7767)
## What changed?
Updated (most) log statements that log variables inline to use
structured logging. There were occurrences that I left untouched, as I
felt that the inline logging added siginficant clarity over a tag.

Prompt history (`claude-3.7-sonnet`):

> Although our logger supports structured logging via its tags, many of
our error messages instead emit variable data directly into the text
content of the logged message.
> Can you find occurrences of messages being logged with variable data
directly in the textual portion, and instead move those variables into
tags on the message, to facilitate structured logging?
>
> Please limit changes you make to precisely this ask; if no tags are
changed on a log statement, don't rewrite the message.
> 
> The scope should be the *entire* codebase.

...

> Great - are there any other places in the whole codebase you can see
where we're dynamically formatting error strings with variables in log
statements?

...

> Can you make those changes?

...

> Complete that codebase-wide refactoring initiative.

...

> Great. Are there any other places that are still logging with format
strings that include variables, anywhere in the codebase?

... 

Bonus robot chatter:

<img width="379" alt="Screenshot 2025-05-14 at 10 51 05 AM"
src="https://github.com/user-attachments/assets/8f1c8a73-3c9b-4d5e-bccd-b37ef8165d9c"
/>

## How did you test it?
- [ ] built
- [ ] run locally and tested manually
- [ ] covered by existing tests
- [ ] added new unit test(s)
- [ ] added new functional test(s)
2025-06-03 17:59:55 +00:00

116 lines
4.0 KiB
Go

//go:generate mockgen -package $GOPACKAGE -source $GOFILE -destination stream_sender_flow_controller_mock.go
package replication
import (
"context"
"sync"
"time"
enumsspb "go.temporal.io/server/api/enums/v1"
replicationspb "go.temporal.io/server/api/replication/v1"
"go.temporal.io/server/common/log"
"go.temporal.io/server/common/log/tag"
"go.temporal.io/server/common/quotas"
"go.temporal.io/server/service/history/configs"
)
type (
flowControlState struct {
mu sync.Mutex
cond *sync.Cond
waiters int
resume bool
rateLimiter quotas.RateLimiter // todo: consider using a shared rate limiter across shard for better resource allocation
}
SenderFlowController interface {
// Wait will block go routine until the sender is allowed to send a task
Wait(ctx context.Context, priority enumsspb.TaskPriority) error
RefreshReceiverFlowControlInfo(syncState *replicationspb.SyncReplicationState)
}
SenderFlowControllerImpl struct {
flowControlStates map[enumsspb.TaskPriority]*flowControlState
defaultRateLimiter quotas.RateLimiter
logger log.Logger
}
)
func NewSenderFlowController(config *configs.Config, logger log.Logger) *SenderFlowControllerImpl {
flowControlStates := make(map[enumsspb.TaskPriority]*flowControlState)
highPriorityState := &flowControlState{
resume: true,
}
highPriorityState.cond = sync.NewCond(&highPriorityState.mu)
highPriorityState.rateLimiter = quotas.NewDefaultOutgoingRateLimiter(func() float64 {
return float64(config.ReplicationStreamSenderHighPriorityQPS())
})
lowPriorityState := &flowControlState{
resume: true,
}
lowPriorityState.cond = sync.NewCond(&lowPriorityState.mu)
lowPriorityState.rateLimiter = quotas.NewDefaultOutgoingRateLimiter(func() float64 {
return float64(config.ReplicationStreamSenderLowPriorityQPS())
})
flowControlStates[enumsspb.TASK_PRIORITY_HIGH] = highPriorityState
flowControlStates[enumsspb.TASK_PRIORITY_LOW] = lowPriorityState
return &SenderFlowControllerImpl{
flowControlStates: flowControlStates,
defaultRateLimiter: quotas.NewRateLimiter(float64(config.ReplicationStreamSenderHighPriorityQPS()), config.ReplicationStreamSenderHighPriorityQPS()),
logger: logger,
}
}
func (s *SenderFlowControllerImpl) RefreshReceiverFlowControlInfo(syncState *replicationspb.SyncReplicationState) {
if syncState.GetHighPriorityState() != nil {
s.setState(s.flowControlStates[enumsspb.TASK_PRIORITY_HIGH], syncState.GetHighPriorityState().GetFlowControlCommand())
}
if syncState.GetLowPriorityState() != nil {
s.setState(s.flowControlStates[enumsspb.TASK_PRIORITY_LOW], syncState.GetLowPriorityState().GetFlowControlCommand())
}
}
func (s *SenderFlowControllerImpl) setState(state *flowControlState, flowControlCommand enumsspb.ReplicationFlowControlCommand) {
switch flowControlCommand {
case enumsspb.REPLICATION_FLOW_CONTROL_COMMAND_RESUME, enumsspb.REPLICATION_FLOW_CONTROL_COMMAND_UNSPECIFIED:
state.mu.Lock()
defer state.mu.Unlock()
state.resume = true
if state.waiters > 0 {
state.cond.Broadcast()
}
case enumsspb.REPLICATION_FLOW_CONTROL_COMMAND_PAUSE:
state.mu.Lock()
defer state.mu.Unlock()
state.resume = false
}
}
func (s *SenderFlowControllerImpl) Wait(ctx context.Context, priority enumsspb.TaskPriority) error {
state, ok := s.flowControlStates[priority]
waitForRateLimiter := func(rateLimiter quotas.RateLimiter) error {
childCtx, cancel := context.WithTimeout(ctx, 2*time.Minute) // to avoid infinite wait
defer cancel()
err := rateLimiter.Wait(childCtx)
if err != nil {
s.logger.Error("error waiting for rate limiter", tag.Error(err))
return err
}
return nil
}
if !ok {
return waitForRateLimiter(s.defaultRateLimiter)
}
state.mu.Lock()
if !state.resume {
state.waiters++
s.logger.Info("sender is paused", tag.TaskPriority(priority.String()))
state.cond.Wait()
s.logger.Info("sender is resumed", tag.TaskPriority(priority.String()))
state.waiters--
}
state.mu.Unlock()
return waitForRateLimiter(state.rateLimiter)
}