perf(cmpp): instrument inbound flow and unbatch submit worker

This commit is contained in:
hectorzhao
2026-08-20 11:27:35 +08:00
parent c4f36fc50d
commit b9a71fe0b9
23 changed files with 760 additions and 138 deletions
+1
View File
@@ -11,6 +11,7 @@
- 维护 `messageId -> sequenceId -> gatewayMessageId` 映射。
- 支持断线重连和后续消息继续消费。
- 暴露健康检查和最小指标。
- Redis Stream Submit Worker 使用持续补位的有界工作池并逐条 ACK;默认并发64,可用`GATEWAY_SUBMIT_WORKER_CONCURRENCY`调整,最大1024。供应商通道的真实上限仍由TPS限速、连接数和CMPP窗口共同决定。
## 建议骨架
+13
View File
@@ -67,6 +67,7 @@ func main() {
worker.Stream = getenv("GATEWAY_SUBMIT_STREAM", "gateway.submit.commands")
worker.Group = getenv("GATEWAY_SUBMIT_GROUP", "cmpp-gateway")
worker.Consumer = getenv("GATEWAY_SUBMIT_CONSUMER", "gateway-1")
worker.Concurrency = positiveEnvInt("GATEWAY_SUBMIT_WORKER_CONCURRENCY", 64)
worker.APIBaseURL = apiBaseURL
go func() {
log.Printf("cmpp gateway submit worker consuming stream=%s group=%s consumer=%s", worker.Stream, worker.Group, worker.Consumer)
@@ -85,6 +86,10 @@ func main() {
UpstreamDesired: desired, UpstreamConnected: connected,
DownstreamConnected: inbound.ActiveConnectionCount(), SubmitWorkerUp: worker != nil,
}
if worker != nil {
snapshot.SubmitWorkerConcurrency = worker.ConfiguredConcurrency()
snapshot.SubmitWorkerInFlight = worker.InFlight()
}
if worker == nil || worker.Redis == nil {
return snapshot
}
@@ -141,6 +146,14 @@ func getenv(key string, fallback string) string {
return value
}
func positiveEnvInt(key string, fallback int) int {
value, err := strconv.Atoi(os.Getenv(key))
if err != nil || value <= 0 {
return fallback
}
return value
}
func hostname() string {
name, err := os.Hostname()
if err != nil || name == "" {
+28 -7
View File
@@ -1,6 +1,7 @@
package inbound
import (
"cmpp-platform/gateway/internal/metrics"
"context"
"crypto/md5"
"errors"
@@ -56,6 +57,7 @@ func (s Server) handleSubmit(response *cmpp.Response, packet *cmpp.Packet, logge
if !ok {
return true, nil
}
handlerStartedAt := time.Now()
session := findSessionByConn(packet.Conn)
if session == nil || strings.TrimSpace(session.account) == "" {
logger.Printf(
@@ -63,7 +65,8 @@ func (s Server) handleSubmit(response *cmpp.Response, packet *cmpp.Packet, logge
req.protocol, req.protocol, packet.Conn.Conn.RemoteAddr(), req.sequenceID, "authenticated connection session not found",
)
setInboundSubmitResponse(response.Packer, 0, 9)
response.AfterSend = s.submitResponseProtocolLogger("", req.protocol, req.sequenceID, "", "", 0, 9)
responseReadyAt := time.Now()
response.AfterSend = observeInboundSubmitResponse(handlerStartedAt, responseReadyAt, false, s.submitResponseProtocolLogger("", req.protocol, req.sequenceID, "", "", 0, 9))
return false, nil
}
account := session.account
@@ -75,7 +78,8 @@ func (s Server) handleSubmit(response *cmpp.Response, packet *cmpp.Packet, logge
fmt.Sprintf("enterprise code mismatch: expected %s", session.enterpriseCode),
)
setInboundSubmitResponse(response.Packer, 0, 9)
response.AfterSend = s.submitResponseProtocolLogger(account, defaultString(session.protocol, req.protocol), req.sequenceID, "", "", 0, 9)
responseReadyAt := time.Now()
response.AfterSend = observeInboundSubmitResponse(handlerStartedAt, responseReadyAt, false, s.submitResponseProtocolLogger(account, defaultString(session.protocol, req.protocol), req.sequenceID, "", "", 0, 9))
return false, nil
}
phones := make([]string, len(req.destTerminalIDs))
@@ -93,19 +97,23 @@ func (s Server) handleSubmit(response *cmpp.Response, packet *cmpp.Packet, logge
clientProtocol, req.protocol, account, enterpriseCode, remote, req.sequenceID, phone, strings.TrimSpace(req.srcID), req.msgFmt,
req.pkNumber, req.pkTotal, len(req.destTerminalIDs), len(req.msgContent),
)
decodeStartedAt := time.Now()
content, longMessage, err := decodeInboundSubmitContent(req)
metrics.ObserveInboundStage("decode", err == nil, time.Since(decodeStartedAt))
if err != nil {
logger.Printf(
"cmpp inbound event=submit_rejected protocol=%s packet_type=%s account=%s remote=%s seq=%d phone=%s result=9 stage=decode reason=%q",
clientProtocol, req.protocol, account, remote, req.sequenceID, phone, err,
)
setInboundSubmitResponse(response.Packer, 0, 9)
response.AfterSend = s.submitResponseProtocolLogger(account, clientProtocol, req.sequenceID, phone, "", 0, 9)
responseReadyAt := time.Now()
response.AfterSend = observeInboundSubmitResponse(handlerStartedAt, responseReadyAt, false, s.submitResponseProtocolLogger(account, clientProtocol, req.sequenceID, phone, "", 0, 9))
return false, nil
}
contentHash := fmt.Sprintf("%x", md5.Sum([]byte(content)))
startedAt := time.Now()
releaseSubmitBarrier := beginDownstreamSubmitBarrier(packet.Conn)
apiStartedAt := time.Now()
result, err := s.submit(remote, submitRequest{
Account: account,
PhoneNumber: phone,
@@ -118,6 +126,7 @@ func (s Server) handleSubmit(response *cmpp.Response, packet *cmpp.Packet, logge
RemoteIP: remoteIP(remote),
LongMessage: longMessage,
})
metrics.ObserveInboundStage("api_roundtrip", err == nil, time.Since(apiStartedAt))
if err != nil || !result.Accepted {
reason := "api returned accepted=false"
if err != nil {
@@ -133,10 +142,11 @@ func (s Server) handleSubmit(response *cmpp.Response, packet *cmpp.Packet, logge
)
setInboundSubmitResponse(response.Packer, 0, responseResult)
protocolLogger := s.submitResponseProtocolLogger(account, clientProtocol, req.sequenceID, phone, result.MessageID, 0, responseResult)
response.AfterSend = func(sendErr error) {
responseReadyAt := time.Now()
response.AfterSend = observeInboundSubmitResponse(handlerStartedAt, responseReadyAt, false, func(sendErr error) {
releaseSubmitBarrier()
protocolLogger(sendErr)
}
})
return false, nil
}
gatewayMsgID := messageIDFrom(result.MessageID, req.sequenceID)
@@ -175,7 +185,8 @@ func (s Server) handleSubmit(response *cmpp.Response, packet *cmpp.Packet, logge
if current := findSessionByConn(packet.Conn); current != nil && current.report != nil {
go current.report(current, "submit", "")
}
response.AfterSend = func(sendErr error) {
responseReadyAt := time.Now()
response.AfterSend = observeInboundSubmitResponse(handlerStartedAt, responseReadyAt, true, func(sendErr error) {
releaseSubmitBarrier()
s.emitProtocolLog(protocolLogEvent{
Protocol: "cmpp",
@@ -199,7 +210,7 @@ func (s Server) handleSubmit(response *cmpp.Response, packet *cmpp.Packet, logge
logger.Printf("cmpp inbound event=post_submit_pending_flush_failed account=%s message_id=%s error=%q", account, result.MessageID, err.Error())
}
}()
}
})
logger.Printf(
"cmpp inbound event=submit_accepted protocol=%s packet_type=%s account=%s remote=%s seq=%d phone=%s dest_count=%d accepted_count=%d result=0 message_id=%s gateway_message_id=%d duration_ms=%d content_chars=%d content_hash=%s",
clientProtocol, req.protocol, account, remote, req.sequenceID, phone, len(phones), len(responseMessages), result.MessageID, gatewayMsgID, time.Since(startedAt).Milliseconds(), len([]rune(content)), contentHash,
@@ -207,6 +218,16 @@ func (s Server) handleSubmit(response *cmpp.Response, packet *cmpp.Packet, logge
return false, nil
}
func observeInboundSubmitResponse(handlerStartedAt time.Time, responseReadyAt time.Time, accepted bool, next func(error)) func(error) {
return func(sendErr error) {
metrics.ObserveInboundStage("response_write", sendErr == nil, time.Since(responseReadyAt))
metrics.ObserveInboundStage("handler_total", accepted && sendErr == nil, time.Since(handlerStartedAt))
if next != nil {
next(sendErr)
}
}
}
type inboundSubmitPacket struct {
protocol string
pkTotal uint8
+130 -8
View File
@@ -14,15 +14,39 @@ var submitAccepted atomic.Uint64
var submitFailed atomic.Uint64
var submitDurationNanoseconds atomic.Uint64
var durationBuckets = [...]time.Duration{
5 * time.Millisecond,
10 * time.Millisecond,
25 * time.Millisecond,
50 * time.Millisecond,
100 * time.Millisecond,
250 * time.Millisecond,
500 * time.Millisecond,
time.Second,
3 * time.Second,
10 * time.Second,
}
type durationHistogram struct {
count atomic.Uint64
sumNano atomic.Uint64
buckets [len(durationBuckets)]atomic.Uint64
}
var inboundStageHistograms [4][2]durationHistogram
var submitStageHistograms [5][2]durationHistogram
type Snapshot struct {
UpstreamDesired int
UpstreamConnected int
DownstreamConnected int
SubmitWorkerUp bool
QueueAvailable bool
QueuePending int64
QueueLag int64
QueueOldestAgeSeconds float64
UpstreamDesired int
UpstreamConnected int
DownstreamConnected int
SubmitWorkerUp bool
SubmitWorkerConcurrency int
SubmitWorkerInFlight int64
QueueAvailable bool
QueuePending int64
QueueLag int64
QueueOldestAgeSeconds float64
}
type SnapshotFunc func(context.Context) Snapshot
@@ -36,6 +60,25 @@ func ObserveSubmit(accepted bool, duration time.Duration) {
submitDurationNanoseconds.Add(uint64(max(duration, 0)))
}
// ObserveInboundStage deliberately accepts only a fixed stage/result vocabulary.
// Entity identifiers would create unbounded Prometheus series during high-volume traffic.
func ObserveInboundStage(stage string, success bool, duration time.Duration) {
stageIndex := inboundStageIndex(stage)
if stageIndex < 0 {
return
}
observeDuration(&inboundStageHistograms[stageIndex][boolIndex(success)], duration)
}
// ObserveSubmitStage separates queueing, limiting, connection-window, supplier and API callback time.
func ObserveSubmitStage(stage string, success bool, duration time.Duration) {
stageIndex := submitStageIndex(stage)
if stageIndex < 0 {
return
}
observeDuration(&submitStageHistograms[stageIndex][boolIndex(success)], duration)
}
func Handler(load SnapshotFunc) http.Handler {
return http.HandlerFunc(func(response http.ResponseWriter, request *http.Request) {
if request.Method != http.MethodGet || request.URL.Path != "/metrics" {
@@ -61,9 +104,18 @@ func Handler(load SnapshotFunc) http.Handler {
fmt.Fprintf(response, "# HELP cmpp_gateway_submit_total Upstream submit attempts by bounded result.\n# TYPE cmpp_gateway_submit_total counter\ncmpp_gateway_submit_total{result=\"accepted\"} %d\ncmpp_gateway_submit_total{result=\"failed\"} %d\n", accepted, failed)
fmt.Fprintf(response, "# HELP cmpp_gateway_submit_duration_seconds_sum Total upstream submit duration.\n# TYPE cmpp_gateway_submit_duration_seconds_sum counter\ncmpp_gateway_submit_duration_seconds_sum %f\n", float64(submitDurationNanoseconds.Load())/float64(time.Second))
fmt.Fprintf(response, "# HELP cmpp_gateway_submit_duration_seconds_count Total measured upstream submits.\n# TYPE cmpp_gateway_submit_duration_seconds_count counter\ncmpp_gateway_submit_duration_seconds_count %d\n", count)
fmt.Fprint(response, "# HELP cmpp_gateway_inbound_stage_duration_seconds CMPP inbound handler duration by bounded stage and result.\n# TYPE cmpp_gateway_inbound_stage_duration_seconds histogram\n")
for index, stage := range []string{"decode", "api_roundtrip", "response_write", "handler_total"} {
writeDurationHistogram(response, "cmpp_gateway_inbound_stage_duration_seconds", stage, &inboundStageHistograms[index])
}
fmt.Fprint(response, "# HELP cmpp_gateway_submit_stage_duration_seconds Gateway submit duration by bounded stage and result.\n# TYPE cmpp_gateway_submit_stage_duration_seconds histogram\n")
for index, stage := range []string{"stream_wait", "rate_limit_wait", "connection_wait", "supplier_rtt", "api_callback"} {
writeDurationHistogram(response, "cmpp_gateway_submit_stage_duration_seconds", stage, &submitStageHistograms[index])
}
fmt.Fprintf(response, "# HELP cmpp_gateway_upstream_connections Desired and live supplier connections.\n# TYPE cmpp_gateway_upstream_connections gauge\ncmpp_gateway_upstream_connections{state=\"desired\"} %d\ncmpp_gateway_upstream_connections{state=\"connected\"} %d\n", snapshot.UpstreamDesired, snapshot.UpstreamConnected)
fmt.Fprintf(response, "# HELP cmpp_gateway_downstream_connections Authenticated client connections.\n# TYPE cmpp_gateway_downstream_connections gauge\ncmpp_gateway_downstream_connections %d\n", snapshot.DownstreamConnected)
fmt.Fprintf(response, "# HELP cmpp_gateway_submit_worker_up Whether the submit worker was initialized.\n# TYPE cmpp_gateway_submit_worker_up gauge\ncmpp_gateway_submit_worker_up %d\n", boolNumber(snapshot.SubmitWorkerUp))
fmt.Fprintf(response, "# HELP cmpp_gateway_submit_worker_slots Configured and active bounded submit worker slots.\n# TYPE cmpp_gateway_submit_worker_slots gauge\ncmpp_gateway_submit_worker_slots{state=\"configured\"} %d\ncmpp_gateway_submit_worker_slots{state=\"in_flight\"} %d\n", snapshot.SubmitWorkerConcurrency, snapshot.SubmitWorkerInFlight)
if snapshot.QueueAvailable {
fmt.Fprintf(response, "# HELP cmpp_gateway_submit_queue_pending Pending entries owned by the consumer group.\n# TYPE cmpp_gateway_submit_queue_pending gauge\ncmpp_gateway_submit_queue_pending %d\n", snapshot.QueuePending)
fmt.Fprintf(response, "# HELP cmpp_gateway_submit_queue_lag Undelivered entries for the consumer group.\n# TYPE cmpp_gateway_submit_queue_lag gauge\ncmpp_gateway_submit_queue_lag %d\n", snapshot.QueueLag)
@@ -72,6 +124,76 @@ func Handler(load SnapshotFunc) http.Handler {
})
}
func observeDuration(histogram *durationHistogram, duration time.Duration) {
duration = max(duration, 0)
histogram.count.Add(1)
histogram.sumNano.Add(uint64(duration))
for index, bucket := range durationBuckets {
if duration <= bucket {
histogram.buckets[index].Add(1)
}
}
}
func writeDurationHistogram(response http.ResponseWriter, metricName string, stage string, histograms *[2]durationHistogram) {
for resultIndex, result := range []string{"failed", "success"} {
histogram := &histograms[resultIndex]
count := histogram.count.Load()
if count == 0 {
continue
}
for index, bucket := range durationBuckets {
fmt.Fprintf(response, "%s_bucket{stage=%q,result=%q,le=%q} %d\n", metricName, stage, result, durationBucketLabel(bucket), histogram.buckets[index].Load())
}
fmt.Fprintf(response, "%s_bucket{stage=%q,result=%q,le=\"+Inf\"} %d\n", metricName, stage, result, count)
fmt.Fprintf(response, "%s_sum{stage=%q,result=%q} %f\n", metricName, stage, result, float64(histogram.sumNano.Load())/float64(time.Second))
fmt.Fprintf(response, "%s_count{stage=%q,result=%q} %d\n", metricName, stage, result, count)
}
}
func durationBucketLabel(bucket time.Duration) string {
return fmt.Sprintf("%g", bucket.Seconds())
}
func boolIndex(value bool) int {
if value {
return 1
}
return 0
}
func inboundStageIndex(stage string) int {
switch stage {
case "decode":
return 0
case "api_roundtrip":
return 1
case "response_write":
return 2
case "handler_total":
return 3
default:
return -1
}
}
func submitStageIndex(stage string) int {
switch stage {
case "stream_wait":
return 0
case "rate_limit_wait":
return 1
case "connection_wait":
return 2
case "supplier_rtt":
return 3
case "api_callback":
return 4
default:
return -1
}
}
func boolNumber(value bool) int {
if value {
return 1
+13 -1
View File
@@ -11,16 +11,28 @@ import (
func TestMetricsHandlerExportsOnlyAggregateGatewayState(t *testing.T) {
ObserveSubmit(true, 20*time.Millisecond)
ObserveInboundStage("api_roundtrip", true, 30*time.Millisecond)
ObserveSubmitStage("rate_limit_wait", true, 15*time.Millisecond)
request := httptest.NewRequest(http.MethodGet, "/metrics", nil)
response := httptest.NewRecorder()
Handler(func(context.Context) Snapshot {
return Snapshot{UpstreamDesired: 2, UpstreamConnected: 1, DownstreamConnected: 3, SubmitWorkerUp: true, QueueAvailable: true, QueuePending: 4, QueueLag: 5, QueueOldestAgeSeconds: 12}
return Snapshot{UpstreamDesired: 2, UpstreamConnected: 1, DownstreamConnected: 3, SubmitWorkerUp: true, SubmitWorkerConcurrency: 64, SubmitWorkerInFlight: 7, QueueAvailable: true, QueuePending: 4, QueueLag: 5, QueueOldestAgeSeconds: 12}
}).ServeHTTP(response, request)
body := response.Body.String()
if response.Code != http.StatusOK || !strings.Contains(body, "cmpp_gateway_submit_queue_pending 4") || !strings.Contains(body, "cmpp_gateway_upstream_connections{state=\"connected\"} 1") {
t.Fatalf("unexpected metrics response: code=%d body=%s", response.Code, body)
}
for _, expected := range []string{
`cmpp_gateway_inbound_stage_duration_seconds_count{stage="api_roundtrip",result="success"} 1`,
`cmpp_gateway_submit_stage_duration_seconds_count{stage="rate_limit_wait",result="success"} 1`,
`cmpp_gateway_submit_worker_slots{state="configured"} 64`,
`cmpp_gateway_submit_worker_slots{state="in_flight"} 7`,
} {
if !strings.Contains(body, expected) {
t.Fatalf("metrics response is missing %q: %s", expected, body)
}
}
for _, forbidden := range []string{"phone_number", "message_id", "channel_id"} {
if strings.Contains(body, forbidden) {
t.Fatalf("metrics expose forbidden label %q", forbidden)
+150 -27
View File
@@ -10,6 +10,7 @@ import (
"net/http"
"strings"
"sync"
"sync/atomic"
"time"
"cmpp-platform/gateway/internal/metrics"
@@ -21,11 +22,12 @@ import (
)
const (
defaultStream = "gateway.submit.commands"
defaultGroup = "cmpp-gateway"
defaultConsumer = "gateway-1"
defaultMinIdle = 30 * time.Second
defaultMaxFails = 3
defaultStream = "gateway.submit.commands"
defaultGroup = "cmpp-gateway"
defaultConsumer = "gateway-1"
defaultMinIdle = 30 * time.Second
defaultMaxFails = 3
defaultConcurrency = 64
)
type Worker struct {
@@ -39,11 +41,13 @@ type Worker struct {
Consumer string
Block time.Duration
Count int64
Concurrency int
MinIdle time.Duration
MaxFailures int
APIBaseURL string
HTTPClient *http.Client
Logger *log.Logger
inFlight atomic.Int64
}
type DeadLetterEvent struct {
@@ -78,6 +82,8 @@ func (w *Worker) Run(ctx context.Context) error {
if w.Upstream == nil {
return fmt.Errorf("upstream manager is required")
}
pool := newMessageWorkPool(ctx, w, w.concurrency())
defer pool.wait()
for {
if err := w.ensureGroup(ctx); err != nil {
if ctx.Err() != nil {
@@ -87,7 +93,7 @@ func (w *Worker) Run(ctx context.Context) error {
sleep(ctx, 3*time.Second)
continue
}
if err := w.recoverPending(ctx); err != nil {
if err := w.recoverPending(ctx, pool); err != nil {
if ctx.Err() != nil {
return ctx.Err()
}
@@ -95,7 +101,7 @@ func (w *Worker) Run(ctx context.Context) error {
sleep(ctx, time.Second)
continue
}
if err := w.consumeOnce(ctx); err != nil {
if err := w.consumeOnce(ctx, pool); err != nil {
if ctx.Err() != nil {
return ctx.Err()
}
@@ -113,12 +119,16 @@ func (w *Worker) ensureGroup(ctx context.Context) error {
return err
}
func (w *Worker) consumeOnce(ctx context.Context) error {
func (w *Worker) consumeOnce(ctx context.Context, pool *messageWorkPool) error {
available, err := pool.waitForCapacity(ctx)
if err != nil {
return err
}
streams, err := w.Redis.XReadGroup(ctx, &redis.XReadGroupArgs{
Group: w.group(),
Consumer: w.consumer(),
Streams: []string{w.stream(), ">"},
Count: w.count(),
Count: min(w.count(), int64(available)),
Block: w.block(),
}).Result()
if errors.Is(err, redis.Nil) {
@@ -128,23 +138,29 @@ func (w *Worker) consumeOnce(ctx context.Context) error {
return err
}
for _, stream := range streams {
if err := w.processMessages(ctx, stream.Messages); err != nil {
return err
for _, message := range stream.Messages {
if !pool.dispatch(message) {
return fmt.Errorf("gateway submit worker capacity accounting mismatch")
}
}
}
return nil
}
func (w *Worker) recoverPending(ctx context.Context) error {
func (w *Worker) recoverPending(ctx context.Context, pool *messageWorkPool) error {
start := "0-0"
for {
available := pool.available()
if available == 0 {
return nil
}
messages, next, err := w.Redis.XAutoClaim(ctx, &redis.XAutoClaimArgs{
Stream: w.stream(),
Group: w.group(),
Consumer: w.consumer(),
MinIdle: w.minIdle(),
Start: start,
Count: w.count(),
Count: min(w.count(), int64(available)),
}).Result()
if errors.Is(err, redis.Nil) {
return nil
@@ -156,8 +172,13 @@ func (w *Worker) recoverPending(ctx context.Context) error {
return nil
}
w.logf("gateway submit worker reclaimed %d pending message(s)", len(messages))
if err := w.processMessages(ctx, messages); err != nil {
return err
for _, message := range messages {
// An in-flight command can legitimately exceed MinIdle while waiting on a supplier.
// Rechecking both the local active set and Redis PEL closes the race where the
// original attempt ACKs between XAUTOCLAIM returning and local dispatch.
if err := pool.dispatchRecovered(ctx, message); err != nil {
return err
}
}
start = next
if next == "0-0" {
@@ -166,27 +187,111 @@ func (w *Worker) recoverPending(ctx context.Context) error {
}
}
func (w *Worker) processMessages(ctx context.Context, messages []redis.XMessage) error {
var group sync.WaitGroup
for _, message := range messages {
message := message
group.Add(1)
go func() {
defer group.Done()
if err := w.processMessage(ctx, message); err != nil {
w.logf("gateway submit worker message %s failed: %v", message.ID, err)
}
}()
type messageWorkPool struct {
ctx context.Context
worker *Worker
slots chan struct{}
completed chan struct{}
group sync.WaitGroup
mu sync.Mutex
active map[string]struct{}
}
func newMessageWorkPool(ctx context.Context, worker *Worker, concurrency int) *messageWorkPool {
return &messageWorkPool{
ctx: ctx, worker: worker, slots: make(chan struct{}, concurrency),
completed: make(chan struct{}, concurrency), active: make(map[string]struct{}),
}
}
func (p *messageWorkPool) available() int {
return cap(p.slots) - len(p.slots)
}
func (p *messageWorkPool) waitForCapacity(ctx context.Context) (int, error) {
for p.available() == 0 {
select {
case <-ctx.Done():
return 0, ctx.Err()
case <-p.completed:
}
}
return p.available(), nil
}
func (p *messageWorkPool) dispatch(message redis.XMessage) bool {
p.mu.Lock()
if _, exists := p.active[message.ID]; exists {
p.mu.Unlock()
return true
}
select {
case p.slots <- struct{}{}:
p.active[message.ID] = struct{}{}
p.worker.inFlight.Add(1)
p.group.Add(1)
p.mu.Unlock()
case <-p.ctx.Done():
p.mu.Unlock()
return false
default:
p.mu.Unlock()
return false
}
go func() {
defer func() {
p.mu.Lock()
delete(p.active, message.ID)
p.mu.Unlock()
<-p.slots
p.worker.inFlight.Add(-1)
select {
case p.completed <- struct{}{}:
default:
}
p.group.Done()
}()
if err := p.worker.processMessage(p.ctx, message); err != nil {
p.worker.logf("gateway submit worker message %s failed: %v", message.ID, err)
}
}()
return true
}
func (p *messageWorkPool) dispatchRecovered(ctx context.Context, message redis.XMessage) error {
p.mu.Lock()
_, active := p.active[message.ID]
p.mu.Unlock()
if active {
return nil
}
pending, err := p.worker.Redis.XPendingExt(ctx, &redis.XPendingExtArgs{
Stream: p.worker.stream(), Group: p.worker.group(), Start: message.ID, End: message.ID, Count: 1,
}).Result()
if err != nil && !errors.Is(err, redis.Nil) {
return err
}
if len(pending) == 0 {
return nil
}
if !p.dispatch(message) {
return fmt.Errorf("gateway submit worker recovery capacity accounting mismatch")
}
group.Wait()
return nil
}
func (p *messageWorkPool) wait() {
p.group.Wait()
}
func (w *Worker) processMessage(ctx context.Context, message redis.XMessage) error {
command, err := CommandFromStreamValues(message.Values)
if err != nil {
return w.deadLetterMalformedMessage(ctx, message, err)
}
if !command.CreatedAt.IsZero() {
metrics.ObserveSubmitStage("stream_wait", true, time.Since(command.CreatedAt))
}
if err := w.handleCommand(ctx, command); err != nil {
if ctx.Err() != nil {
return ctx.Err()
@@ -208,11 +313,14 @@ func (w *Worker) processMessage(ctx context.Context, message redis.XMessage) err
func (w *Worker) handleCommand(ctx context.Context, command queue.SubmitCommand) error {
startedAt := time.Now()
limitStartedAt := time.Now()
if w.Limiter != nil {
if _, err := w.Limiter.Wait(ctx, command.ChannelID, command.Route.RateLimitPerSecond); err != nil {
metrics.ObserveSubmitStage("rate_limit_wait", false, time.Since(limitStartedAt))
return err
}
}
metrics.ObserveSubmitStage("rate_limit_wait", true, time.Since(limitStartedAt))
submit := w.Submit
if submit == nil {
if w.Upstream == nil {
@@ -389,6 +497,21 @@ func (w *Worker) count() int64 {
return 10
}
func (w *Worker) concurrency() int {
if w.Concurrency > 0 {
return min(w.Concurrency, 1024)
}
return defaultConcurrency
}
func (w *Worker) ConfiguredConcurrency() int {
return w.concurrency()
}
func (w *Worker) InFlight() int64 {
return w.inFlight.Load()
}
func (w *Worker) minIdle() time.Duration {
if w.MinIdle > 0 {
return w.MinIdle
+136 -13
View File
@@ -2,6 +2,7 @@ package submitworker
import (
"context"
"sync/atomic"
"testing"
"time"
@@ -121,11 +122,21 @@ func TestMinIdleDefaultsToThirtySeconds(t *testing.T) {
}
}
func TestProcessMessagesDoesNotLetOneChannelBlockAnother(t *testing.T) {
func TestConcurrencyUsesBoundedDefaultAndMaximum(t *testing.T) {
if got := (&Worker{}).ConfiguredConcurrency(); got != defaultConcurrency {
t.Fatalf("default concurrency = %d, want %d", got, defaultConcurrency)
}
if got := (&Worker{Concurrency: 2048}).ConfiguredConcurrency(); got != 1024 {
t.Fatalf("capped concurrency = %d, want 1024", got)
}
}
func TestMessageWorkPoolContinuouslyRefillsWithoutWaitingForSlowSibling(t *testing.T) {
mr := miniredis.RunT(t)
client := redis.NewClient(&redis.Options{Addr: mr.Addr()})
startedA := make(chan struct{})
startedB := make(chan struct{})
startedC := make(chan struct{})
releaseA := make(chan struct{})
worker := &Worker{
Redis: client,
@@ -136,19 +147,17 @@ func TestProcessMessagesDoesNotLetOneChannelBlockAnother(t *testing.T) {
<-releaseA
case "channel-b":
close(startedB)
case "channel-c":
close(startedC)
}
return queue.SubmitResult{SubmitStatus: "accepted"}, nil
},
}
messages := []redis.XMessage{
{ID: "1-0", Values: submitCommandValues("message-a", "channel-a")},
{ID: "2-0", Values: submitCommandValues("message-b", "channel-b")},
pool := newMessageWorkPool(context.Background(), worker, 2)
if !pool.dispatch(redis.XMessage{ID: "1-0", Values: submitCommandValues("message-a", "channel-a")}) ||
!pool.dispatch(redis.XMessage{ID: "2-0", Values: submitCommandValues("message-b", "channel-b")}) {
t.Fatal("initial messages were not dispatched")
}
done := make(chan struct{})
go func() {
_ = worker.processMessages(context.Background(), messages)
close(done)
}()
select {
case <-startedA:
case <-time.After(time.Second):
@@ -159,11 +168,125 @@ func TestProcessMessagesDoesNotLetOneChannelBlockAnother(t *testing.T) {
case <-time.After(200 * time.Millisecond):
t.Fatal("channel-b was blocked by channel-a")
}
close(releaseA)
ctx, cancel := context.WithTimeout(context.Background(), time.Second)
defer cancel()
if _, err := pool.waitForCapacity(ctx); err != nil {
t.Fatalf("wait for refill capacity: %v", err)
}
if !pool.dispatch(redis.XMessage{ID: "3-0", Values: submitCommandValues("message-c", "channel-c")}) {
t.Fatal("refill message was not dispatched")
}
select {
case <-done:
case <-time.After(time.Second):
t.Fatal("message batch did not complete")
case <-startedC:
case <-time.After(200 * time.Millisecond):
t.Fatal("pool waited for the slow sibling instead of refilling its free slot")
}
close(releaseA)
pool.wait()
}
func TestMessageWorkPoolAcknowledgesFastMessageBeforeSlowSiblingCompletes(t *testing.T) {
mr := miniredis.RunT(t)
client := redis.NewClient(&redis.Options{Addr: mr.Addr()})
worker := &Worker{Redis: client, Stream: "gateway.submit.commands", Group: "cmpp-gateway"}
ctx := context.Background()
if err := worker.ensureGroup(ctx); err != nil {
t.Fatalf("ensureGroup: %v", err)
}
for _, entry := range []struct{ id, messageID, channelID string }{
{"1-0", "message-slow", "channel-slow"},
{"2-0", "message-fast", "channel-fast"},
} {
if err := client.XAdd(ctx, &redis.XAddArgs{Stream: worker.stream(), ID: entry.id, Values: submitCommandValues(entry.messageID, entry.channelID)}).Err(); err != nil {
t.Fatalf("xadd %s: %v", entry.id, err)
}
}
streams, err := client.XReadGroup(ctx, &redis.XReadGroupArgs{Group: worker.group(), Consumer: worker.consumer(), Streams: []string{worker.stream(), ">"}, Count: 2}).Result()
if err != nil || len(streams) != 1 || len(streams[0].Messages) != 2 {
t.Fatalf("xreadgroup: streams=%+v err=%v", streams, err)
}
slowStarted := make(chan struct{})
fastReturned := make(chan struct{})
releaseSlow := make(chan struct{})
worker.Submit = func(_ context.Context, command queue.SubmitCommand) (queue.SubmitResult, error) {
if command.ChannelID == "channel-slow" {
close(slowStarted)
<-releaseSlow
} else {
close(fastReturned)
}
return queue.SubmitResult{SubmitStatus: "accepted"}, nil
}
pool := newMessageWorkPool(ctx, worker, 2)
for _, message := range streams[0].Messages {
if !pool.dispatch(message) {
t.Fatalf("message %s was not dispatched", message.ID)
}
}
<-slowStarted
<-fastReturned
deadline := time.Now().Add(time.Second)
for {
pending, pendingErr := client.XPending(ctx, worker.stream(), worker.group()).Result()
if pendingErr != nil {
t.Fatalf("xpending: %v", pendingErr)
}
if pending.Count == 1 {
break
}
if time.Now().After(deadline) {
t.Fatalf("pending count = %d, want 1 while slow sibling is still running", pending.Count)
}
time.Sleep(10 * time.Millisecond)
}
close(releaseSlow)
pool.wait()
}
func TestPendingRecoveryDoesNotDuplicateAnActiveOrAlreadyAcknowledgedMessage(t *testing.T) {
mr := miniredis.RunT(t)
client := redis.NewClient(&redis.Options{Addr: mr.Addr()})
worker := &Worker{Redis: client, Stream: "gateway.submit.commands", Group: "cmpp-gateway", MinIdle: time.Millisecond}
ctx := context.Background()
if err := worker.ensureGroup(ctx); err != nil {
t.Fatalf("ensureGroup: %v", err)
}
if err := client.XAdd(ctx, &redis.XAddArgs{Stream: worker.stream(), ID: "3-0", Values: submitCommandValues("message-active", "channel-active")}).Err(); err != nil {
t.Fatalf("xadd: %v", err)
}
streams, err := client.XReadGroup(ctx, &redis.XReadGroupArgs{Group: worker.group(), Consumer: worker.consumer(), Streams: []string{worker.stream(), ">"}, Count: 1}).Result()
if err != nil || len(streams) != 1 || len(streams[0].Messages) != 1 {
t.Fatalf("xreadgroup: streams=%+v err=%v", streams, err)
}
message := streams[0].Messages[0]
started := make(chan struct{})
release := make(chan struct{})
var submits atomic.Int32
worker.Submit = func(_ context.Context, _ queue.SubmitCommand) (queue.SubmitResult, error) {
submits.Add(1)
close(started)
<-release
return queue.SubmitResult{SubmitStatus: "accepted"}, nil
}
pool := newMessageWorkPool(ctx, worker, 2)
if !pool.dispatch(message) {
t.Fatal("active message was not dispatched")
}
<-started
time.Sleep(5 * time.Millisecond)
if err := worker.recoverPending(ctx, pool); err != nil {
t.Fatalf("recoverPending: %v", err)
}
if got := submits.Load(); got != 1 {
t.Fatalf("active message submit count = %d, want 1", got)
}
close(release)
pool.wait()
if err := pool.dispatchRecovered(ctx, message); err != nil {
t.Fatalf("dispatch acknowledged recovery: %v", err)
}
if got := submits.Load(); got != 1 {
t.Fatalf("acknowledged message submit count = %d, want 1", got)
}
}
+17 -5
View File
@@ -1,6 +1,7 @@
package upstream
import (
"cmpp-platform/gateway/internal/metrics"
"cmpp-platform/gateway/internal/queue"
"context"
"fmt"
@@ -17,7 +18,7 @@ import (
func (m *Manager) Submit(ctx context.Context, cmd queue.SubmitCommand) (queue.SubmitResult, error) {
if err := validateSubmitCommand(cmd); err != nil {
result := submitResult(cmd, 0, "", "rejected", "INVALID_COMMAND", err.Error())
if postErr := m.post(ctx, "/gateway/events/submit-result", result); postErr != nil {
if postErr := m.postSubmitCallback(ctx, "/gateway/events/submit-result", result); postErr != nil {
return result, postErr
}
return result, err
@@ -26,7 +27,7 @@ func (m *Manager) Submit(ctx context.Context, cmd queue.SubmitCommand) (queue.Su
pool, err := m.connectionFor(cmd)
if err != nil {
result := submitResult(cmd, 0, "", "rejected", "CONNECT_FAILED", err.Error())
if postErr := m.post(ctx, "/gateway/events/submit-result", result); postErr != nil {
if postErr := m.postSubmitCallback(ctx, "/gateway/events/submit-result", result); postErr != nil {
return result, postErr
}
return result, err
@@ -43,7 +44,7 @@ func (m *Manager) Submit(ctx context.Context, cmd queue.SubmitCommand) (queue.Su
SubmitSegmentResult: segment,
}
callbackCtx, cancel := context.WithTimeout(context.Background(), 2*time.Second)
postErr := m.post(callbackCtx, "/gateway/events/submit-segment-result", payload)
postErr := m.postSubmitCallback(callbackCtx, "/gateway/events/submit-segment-result", payload)
cancel()
if postErr != nil {
log.Printf(
@@ -53,12 +54,12 @@ func (m *Manager) Submit(ctx context.Context, cmd queue.SubmitCommand) (queue.Su
}
})
if err != nil {
if postErr := m.post(ctx, "/gateway/events/submit-result", result); postErr != nil {
if postErr := m.postSubmitCallback(ctx, "/gateway/events/submit-result", result); postErr != nil {
return result, postErr
}
return result, err
}
if err := m.post(ctx, "/gateway/events/submit-result", result); err != nil {
if err := m.postSubmitCallback(ctx, "/gateway/events/submit-result", result); err != nil {
return result, err
}
return result, nil
@@ -79,13 +80,17 @@ func (p *connectionPool) submit(
var firstGatewayMessageID string
segments := make([]queue.SubmitSegmentResult, 0, len(parts))
for _, part := range parts {
connectionStartedAt := time.Now()
conn, release, err := p.acquireConnection(ctx)
metrics.ObserveSubmitStage("connection_wait", err == nil, time.Since(connectionStartedAt))
if err != nil {
result := submitResult(cmd, 0, "", "timeout", "WINDOW_TIMEOUT", err.Error())
result.Segments = segments
return result, err
}
supplierStartedAt := time.Now()
seq, gatewayMessageID, result, err := conn.submitPart(ctx, cmd, part)
metrics.ObserveSubmitStage("supplier_rtt", err == nil, time.Since(supplierStartedAt))
release()
segment := submitSegmentResult(part, seq, gatewayMessageID, result)
segments = append(segments, segment)
@@ -113,6 +118,13 @@ func (p *connectionPool) submit(
return result, nil
}
func (m *Manager) postSubmitCallback(ctx context.Context, path string, payload any) error {
startedAt := time.Now()
err := m.post(ctx, path, payload)
metrics.ObserveSubmitStage("api_callback", err == nil, time.Since(startedAt))
return err
}
func (c *connection) submitPart(ctx context.Context, cmd queue.SubmitCommand, part submitPart) (uint32, string, queue.SubmitResult, error) {
rspCh := make(chan submitPartResponse, 1)
pkt := c.submitRequestPacket(cmd, part)