Skip to content

Commit 3a460a3

Browse files
committed
fix: prevent throttling deadlock in cloudwatchlogs output
On a ThrottlingException for CreateLogStream/CreateLogGroup, log-stream creation could wedge for the entire output plugin with nothing logged. LogThrottleRetryer.ShouldRetry performed an unconditional blocking send to a capacity-1 throttle-event channel drained by a single consumer goroutine. The shared TargetManager was bound (via sync.Once) to the first destination's client and retryer; when that destination stopped (e.g. log rotation with auto_removal), its retryer's consumer goroutine exited. The next throttle then filled the buffer and blocked the send forever, and because TargetManager.InitTarget holds a mutex across the create call, all other targets waiting on that mutex stalled as well. Two changes, either of which breaks the deadlock; both applied: - logthrottle.go: make the throttle-event send non-blocking (select with a default) so a full channel or stopped consumer can never block ShouldRetry. The retry decision is unchanged. - cloudwatchlogs.go: give the shared TargetManager its own dedicated retryer and client owned by the plugin, stopped only in Close(), instead of reusing the first destination's client. This decouples the TargetManager lifecycle from any single destination. Tests: - TestShouldRetryDoesNotBlockAfterStop: ShouldRetry returns after the retryer is stopped (fails via timeout on the pre-fix code). - TestSharedRetryerLifecycle: stopping the first destination does not prevent creating additional destinations. - TestInitTargetNoDeadlockUnderThrottling: end-to-end regression driving the real SDK retry loop against an always-throttling endpoint through InitTarget with a stopped retryer consumer; deadlocks on the pre-fix code, passes with the fix.
1 parent 11fef6f commit 3a460a3

5 files changed

Lines changed: 194 additions & 2 deletions

File tree

internal/retryer/logthrottle.go

Lines changed: 5 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -53,7 +53,11 @@ func (r *LogThrottleRetryer) ShouldRetry(req *request.Request) bool {
5353
if req.Operation != nil {
5454
te.Operation = req.Operation.Name
5555
}
56-
r.throttleChan <- te
56+
// Non-blocking: never block ShouldRetry if the consumer has stopped.
57+
select {
58+
case r.throttleChan <- te:
59+
default:
60+
}
5761
}
5862

5963
// Fallback to SDK's built in retry rules

internal/retryer/logthrottle_test.go

Lines changed: 33 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -123,6 +123,39 @@ func TestLogThrottleRetryerLogging(t *testing.T) {
123123
}
124124
}
125125

126+
// TestShouldRetryDoesNotBlockAfterStop verifies ShouldRetry does not block once the
127+
// retryer is stopped (its consumer goroutine no longer drains the throttle channel).
128+
func TestShouldRetryDoesNotBlockAfterStop(t *testing.T) {
129+
l := &testLogger{}
130+
r := NewLogThrottleRetryer(l)
131+
132+
// Stop the retryer, which closes the done channel and exits the consumer goroutine
133+
r.Stop()
134+
time.Sleep(50 * time.Millisecond) // Give the goroutine time to exit
135+
136+
req := &request.Request{
137+
Error: awserr.New("RequestLimitExceeded", "Test AWS Error", nil),
138+
Operation: &request.Operation{Name: "Test"},
139+
}
140+
141+
// Call ShouldRetry in a goroutine and use a timeout to detect blocking
142+
done := make(chan bool, 1)
143+
go func() {
144+
// Call ShouldRetry multiple times to exceed channel capacity (1)
145+
for i := 0; i < 10; i++ {
146+
r.ShouldRetry(req)
147+
}
148+
done <- true
149+
}()
150+
151+
select {
152+
case <-done:
153+
// Success: ShouldRetry did not block
154+
case <-time.After(2 * time.Second):
155+
t.Fatal("ShouldRetry blocked after retryer was stopped - potential deadlock")
156+
}
157+
}
158+
126159
func setup() {
127160
throttleReportTimeout = 400 * time.Millisecond
128161
throttleReportCheckPeriod = 50 * time.Millisecond

plugins/outputs/cloudwatchlogs/cloudwatchlogs.go

Lines changed: 14 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -77,6 +77,11 @@ type CloudWatchLogs struct {
7777
middleware awsmiddleware.Middleware
7878
configurer *awsmiddleware.Configurer
7979
configurerOnce sync.Once
80+
81+
// Dedicated retryer/client for the TargetManager, owned by the plugin so its
82+
// lifecycle is independent of any destination stop.
83+
sharedRetryer *retryer.LogThrottleRetryer
84+
sharedClient *cloudwatchlogs.CloudWatchLogs
8085
}
8186

8287
var _ logs.LogBackend = (*CloudWatchLogs)(nil)
@@ -101,6 +106,11 @@ func (c *CloudWatchLogs) Close() error {
101106
c.workerPool.Stop()
102107
}
103108

109+
// Stop the shared retryer last, after all pushers have drained.
110+
if c.sharedRetryer != nil {
111+
c.sharedRetryer.Stop()
112+
}
113+
104114
return nil
105115
}
106116

@@ -151,7 +161,10 @@ func (c *CloudWatchLogs) getDest(t pusher.Target, logSrc logs.LogSrc) *cwDest {
151161
if c.Concurrency > 1 {
152162
c.workerPool = pusher.NewWorkerPool(c.Concurrency)
153163
}
154-
c.targetManager = pusher.NewTargetManager(c.Log, client)
164+
// Dedicated retryer/client so the TargetManager isn't tied to the first dest.
165+
c.sharedRetryer = retryer.NewLogThrottleRetryer(c.Log)
166+
c.sharedClient = c.createClient(c.sharedRetryer)
167+
c.targetManager = pusher.NewTargetManager(c.Log, c.sharedClient)
155168
})
156169
p := pusher.NewPusher(c.Log, t, client, c.targetManager, logSrc, c.workerPool, c.ForceFlushInterval.Duration, maxRetryTimeout, &c.pusherWaitGroup)
157170
cwd := &cwDest{

plugins/outputs/cloudwatchlogs/cloudwatchlogs_test.go

Lines changed: 44 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -6,6 +6,7 @@ package cloudwatchlogs
66
import (
77
"sync"
88
"testing"
9+
"time"
910

1011
"github.com/influxdata/telegraf/testutil"
1112
"github.com/stretchr/testify/require"
@@ -100,3 +101,46 @@ func TestDuplicateDestination(t *testing.T) {
100101
// Then the destination for cloudwatchlogs endpoint would be the same
101102
require.Equal(t, d1, d2)
102103
}
104+
105+
// TestSharedRetryerLifecycle verifies that stopping one destination does not affect
106+
// the shared TargetManager's ability to create new targets, and that the shared
107+
// retryer is separate from any destination's retryer.
108+
func TestSharedRetryerLifecycle(t *testing.T) {
109+
c := &CloudWatchLogs{
110+
Log: testutil.Logger{Name: "test"},
111+
AccessKey: "access_key",
112+
SecretKey: "secret_key",
113+
cwDests: sync.Map{},
114+
}
115+
116+
// Create the first destination - this initializes the shared TargetManager
117+
d1 := c.CreateDest("group1", "stream1", -1, "", nil).(*cwDest)
118+
119+
// Verify that the shared retryer was created and is separate from d1's retryer
120+
require.NotNil(t, c.sharedRetryer, "shared retryer should be initialized")
121+
require.NotNil(t, c.sharedClient, "shared client should be initialized")
122+
require.NotSame(t, c.sharedRetryer, d1.retryer, "shared retryer should be separate from destination retryer")
123+
124+
// Stop the first destination (simulates log rotation with auto_removal)
125+
d1.Stop()
126+
127+
// Create a second destination - this should not block or fail
128+
done := make(chan *cwDest, 1)
129+
go func() {
130+
d2 := c.CreateDest("group2", "stream2", -1, "", nil).(*cwDest)
131+
done <- d2
132+
}()
133+
134+
select {
135+
case d2 := <-done:
136+
require.NotNil(t, d2, "second destination should be created successfully")
137+
require.NotSame(t, d1, d2, "second destination should be different from first")
138+
// Clean up
139+
d2.Stop()
140+
case <-time.After(5 * time.Second):
141+
t.Fatal("creating second destination blocked after first destination was stopped - potential deadlock")
142+
}
143+
144+
// Clean up
145+
c.Close()
146+
}
Lines changed: 98 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,98 @@
1+
// Copyright Amazon.com, Inc. or its affiliates. All Rights Reserved.
2+
// SPDX-License-Identifier: MIT
3+
4+
package pusher
5+
6+
import (
7+
"net/http"
8+
"net/http/httptest"
9+
"sync"
10+
"testing"
11+
"time"
12+
13+
"github.com/aws/aws-sdk-go/aws"
14+
"github.com/aws/aws-sdk-go/aws/credentials"
15+
"github.com/aws/aws-sdk-go/aws/session"
16+
17+
"github.com/aws/amazon-cloudwatch-agent/internal/retryer"
18+
"github.com/aws/amazon-cloudwatch-agent/sdk/service/cloudwatchlogs"
19+
"github.com/aws/amazon-cloudwatch-agent/tool/testutil"
20+
)
21+
22+
// newThrottlingClient returns a real CloudWatch Logs client whose endpoint points
23+
// at a local server that always responds with a ThrottlingException, wired with a
24+
// LogThrottleRetryer. The returned retryer is also handed back so the test can stop
25+
// its consumer goroutine to reproduce the dead-consumer condition.
26+
func newThrottlingClient(t *testing.T) (*cloudwatchlogs.CloudWatchLogs, *retryer.LogThrottleRetryer, func()) {
27+
t.Helper()
28+
29+
srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, _ *http.Request) {
30+
// JSON 1.1 protocol: the SDK classifies the error from the error type,
31+
// which it reads from this header / body. ThrottlingException is a
32+
// throttling error, so the SDK will invoke ShouldRetry and retry.
33+
w.Header().Set("X-Amzn-Errortype", "ThrottlingException")
34+
w.Header().Set("Content-Type", "application/x-amz-json-1.1")
35+
w.WriteHeader(http.StatusBadRequest)
36+
_, _ = w.Write([]byte(`{"__type":"ThrottlingException","message":"Rate exceeded"}`))
37+
}))
38+
39+
r := retryer.NewLogThrottleRetryer(testutil.NewNopLogger())
40+
// Bound the retry count: fast, but >1 so a dead consumer fills the capacity-1
41+
// throttle channel and (pre-fix) the next send blocks.
42+
r.NumMaxRetries = 2
43+
44+
sess := session.Must(session.NewSession())
45+
client := cloudwatchlogs.New(sess, &aws.Config{
46+
Region: aws.String("us-east-1"),
47+
Endpoint: aws.String(srv.URL),
48+
DisableSSL: aws.Bool(true),
49+
Credentials: credentials.NewStaticCredentials("ak", "sk", ""),
50+
Retryer: r,
51+
})
52+
53+
return client, r, srv.Close
54+
}
55+
56+
// TestInitTargetNoDeadlockUnderThrottling drives the real SDK retry loop through
57+
// InitTarget while CreateLogStream is throttled and the retryer's consumer has been
58+
// stopped. InitTarget holds a mutex across the create call, so a blocking throttle
59+
// send would wedge every target. Asserts both targets' InitTarget return in time.
60+
func TestInitTargetNoDeadlockUnderThrottling(t *testing.T) {
61+
t.Parallel()
62+
client, r, closeSrv := newThrottlingClient(t)
63+
defer closeSrv()
64+
65+
manager := NewTargetManager(testutil.NewNopLogger(), client)
66+
67+
// Stop the retryer's consumer BEFORE any calls, reproducing the dead-consumer
68+
// condition that arises when the destination owning the retryer stops.
69+
r.Stop()
70+
time.Sleep(50 * time.Millisecond)
71+
72+
var wg sync.WaitGroup
73+
done := make(chan struct{})
74+
for i, target := range []Target{
75+
{Group: "group-A", Stream: "stream-A"},
76+
{Group: "group-B", Stream: "stream-B"},
77+
} {
78+
wg.Add(1)
79+
go func(_ int, tg Target) {
80+
defer wg.Done()
81+
// Returns a throttling error after retries are exhausted; the point is
82+
// that it RETURNS rather than parking forever inside the held mutex.
83+
_ = manager.InitTarget(tg)
84+
}(i, target)
85+
}
86+
87+
go func() {
88+
wg.Wait()
89+
close(done)
90+
}()
91+
92+
select {
93+
case <-done:
94+
// Both InitTarget calls returned: no deadlock.
95+
case <-time.After(60 * time.Second):
96+
t.Fatal("InitTarget deadlocked under throttling with a stopped retryer consumer")
97+
}
98+
}

0 commit comments

Comments
 (0)