-
-
Notifications
You must be signed in to change notification settings - Fork 357
Expand file tree
/
Copy pathasync_test.go
More file actions
282 lines (250 loc) · 9.89 KB
/
Copy pathasync_test.go
File metadata and controls
282 lines (250 loc) · 9.89 KB
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
232
233
234
235
236
237
238
239
240
241
242
243
244
245
246
247
248
249
250
251
252
253
254
255
256
257
258
259
260
261
262
263
264
265
266
267
268
269
270
271
272
273
274
275
276
277
278
279
280
281
282
package certmagic
import (
"context"
"errors"
"fmt"
"io"
stdlog "log"
"sync/atomic"
"testing"
"time"
"go.uber.org/zap"
)
// TestJobManagerCleansUpAfterJobPanic verifies that when a submitted job
// panics, the worker still releases the in-flight name and decrements its
// active-worker counter. Without these cleanups, a single panic would
// silently strand all future renewals for that name (and, after enough
// panics, every name) until process restart. See certmagic issue for
// caddyserver/caddy#7366.
func TestJobManagerCleansUpAfterJobPanic(t *testing.T) {
// Suppress the worker's "panic: certificate worker: ..." message so it
// doesn't pollute test output. We're intentionally triggering a panic.
stdlog.SetOutput(io.Discard)
t.Cleanup(func() { stdlog.SetOutput(io.Discard) })
jm := &jobManager{maxConcurrentJobs: 10}
logger := zap.NewNop()
jm.Submit(logger, "renewal_X", func() error {
panic("simulated panic from acme library")
})
// Cleanup happens in deferred handlers inside worker(), so we cannot
// synchronize on it from inside the job itself. Poll until state settles.
if !waitUntil(time.Second, func() bool {
jm.mu.Lock()
defer jm.mu.Unlock()
_, nameStillTracked := jm.names["renewal_X"]
return !nameStillTracked && jm.activeWorkers == 0
}) {
jm.mu.Lock()
_, nameStillTracked := jm.names["renewal_X"]
active := jm.activeWorkers
jm.mu.Unlock()
t.Fatalf("worker did not clean up after panic: name still tracked=%v, activeWorkers=%d (want false, 0)",
nameStillTracked, active)
}
// A subsequent submission with the same name must actually run.
// If the names leak regressed, this Submit would be silently dropped.
var ran int32
jm.Submit(logger, "renewal_X", func() error {
atomic.StoreInt32(&ran, 1)
return nil
})
if !waitUntil(time.Second, func() bool {
return atomic.LoadInt32(&ran) == 1
}) {
t.Fatal("second Submit with the same name was silently dropped after panic")
}
}
// TestDoWithRetryReturnsErrorOnSuccess verifies that doWithRetry returns nil
// when the operation succeeds on the first attempt.
func TestDoWithRetryReturnsNilOnSuccess(t *testing.T) {
logger := zap.NewNop()
ctx := context.Background()
err := doWithRetry(ctx, logger, func(ctx context.Context) error {
return nil
})
if err != nil {
t.Fatalf("expected nil error on success, got: %v", err)
}
}
// TestDoWithRetryReturnsErrorOnErrNoRetry verifies that doWithRetry returns
// the error immediately (without retrying) when the function returns an
// ErrNoRetry error.
func TestDoWithRetryReturnsErrorOnErrNoRetry(t *testing.T) {
logger := zap.NewNop()
ctx := context.Background()
expectedErr := fmt.Errorf("permanent failure")
callCount := 0
err := doWithRetry(ctx, logger, func(ctx context.Context) error {
callCount++
return ErrNoRetry{expectedErr}
})
if !errors.Is(err, expectedErr) {
t.Fatalf("expected ErrNoRetry's wrapped error %v, got: %v", expectedErr, err)
}
if callCount != 1 {
t.Fatalf("expected function to be called exactly once (no retry), got %d calls", callCount)
}
}
// TestDoWithRetryReturnsErrorOnContextCancellation verifies that doWithRetry
// returns context.Canceled when the context is cancelled during a retry wait.
func TestDoWithRetryReturnsErrorOnContextCancellation(t *testing.T) {
logger := zap.NewNop()
ctx, cancel := context.WithCancel(context.Background())
// Cancel after a short delay to trigger cancellation during the first retry wait
go func() {
time.Sleep(50 * time.Millisecond)
cancel()
}()
err := doWithRetry(ctx, logger, func(ctx context.Context) error {
return fmt.Errorf("transient error to trigger retry")
})
if !errors.Is(err, context.Canceled) {
t.Fatalf("expected context.Canceled, got: %v", err)
}
}
// TestDoWithRetryRetriesAndSucceeds verifies that doWithRetry actually retries
// the function when it fails, and succeeds when a subsequent attempt works.
func TestDoWithRetryRetriesAndSucceeds(t *testing.T) {
logger := zap.NewNop()
ctx := context.Background()
// We need to make the retry intervals short for this test.
// Save and restore the original intervals.
originalIntervals := retryIntervals
retryIntervals = []time.Duration{10 * time.Millisecond}
t.Cleanup(func() { retryIntervals = originalIntervals })
attempt := 0
err := doWithRetry(ctx, logger, func(ctx context.Context) error {
attempt++
if attempt < 3 {
return fmt.Errorf("transient error on attempt %d", attempt)
}
return nil
})
if err != nil {
t.Fatalf("expected nil error after successful retry, got: %v", err)
}
if attempt != 3 {
t.Fatalf("expected 3 attempts, got %d", attempt)
}
}
// TestDoWithRetryReturnsLastErrorOnExhaustion verifies the critical fix for
// the bug where doWithRetry returned nil instead of the last error when all
// retries were exhausted. This is the silent-renewal-failure bug that caused
// expired certificates to be served indefinitely.
//
// Since maxRetryDuration is 30 days, we cannot test the natural exhaustion
// path directly. Instead, we verify that the last error from f() is always
// propagated: we make f() fail once, then force the loop to exit by having
// f() cancel the context (which triggers the ctx.Done() path). This confirms
// that doWithRetry never returns nil when f() has returned a non-nil error.
func TestDoWithRetryReturnsLastErrorOnExhaustion(t *testing.T) {
logger := zap.NewNop()
// Use short intervals for testing
originalIntervals := retryIntervals
retryIntervals = []time.Duration{10 * time.Millisecond}
t.Cleanup(func() { retryIntervals = originalIntervals })
ctx, cancel := context.WithCancel(context.Background())
defer cancel()
lastErr := fmt.Errorf("persistent ACME failure")
var attempts int
err := doWithRetry(ctx, logger, func(ctx context.Context) error {
attempts++
// After the first failure, cancel the context so the next loop
// iteration hits ctx.Done() and returns context.Canceled instead
// of nil. This proves the error path is taken, not the success path.
if attempts >= 1 {
cancel()
}
return lastErr
})
// The function should NOT return nil — that was the bug.
// It should return either the last error (via the exhaustion path)
// or context.Canceled (via the ctx.Done() path). Either way, it
// must be non-nil.
if err == nil {
t.Fatal("doWithRetry returned nil after failures — this is the silent renewal bug (see #7843)")
}
}
func waitUntil(timeout time.Duration, cond func() bool) bool {
deadline := time.Now().Add(timeout)
for time.Now().Before(deadline) {
if cond() {
return true
}
time.Sleep(5 * time.Millisecond)
}
return cond()
}
// TestRenewalBackoffSchedule verifies the scheduling primitive that lets
// queueRenewalTask pace retries itself instead of relying on a single
// long-lived jm job sleeping between attempts (see caddyserver/caddy#7843:
// after a transient DNS outage cleared, renewal did not happen again until
// the process was restarted, because the in-flight job's own multi-hour
// internal sleep -- not the periodic maintenance tick -- was governing
// retries, and jm.Submit silently dropped every duplicate submission from
// the maintenance tick in the meantime).
//
// It uses a fresh *renewalBackoff (not the shared package-level
// renewalRetrySchedule) and a synthetic clock so it doesn't need to sleep
// for real minutes/hours/days.
func TestRenewalBackoffSchedule(t *testing.T) {
rb := &renewalBackoff{}
const name = "renew_example.com"
now := time.Date(2026, 1, 1, 0, 0, 0, 0, time.UTC)
// No recorded failures yet: always ready.
if !rb.readyFor(name) {
t.Fatal("expected a name with no recorded failure to be ready immediately")
}
// First failure: schedules the first retry interval out.
if exhausted := rb.recordFailure(name, now); exhausted {
t.Fatal("did not expect the retry budget to be exhausted after a single failure")
}
if rb.readyForAsOf(name, now) {
t.Fatal("expected name to not be ready for a retry immediately after recording a failure")
}
// Not ready right up until (but not including) the first retry interval.
almostThere := now.Add(retryIntervals[0] - time.Millisecond)
if rb.readyForAsOf(name, almostThere) {
t.Fatal("expected name to still not be ready just before its scheduled retry time")
}
// Ready once the first retry interval has elapsed.
dueTime := now.Add(retryIntervals[0])
if !rb.readyForAsOf(name, dueTime) {
t.Fatal("expected name to be ready once its scheduled retry time has passed")
}
// A second consecutive failure advances to the next (longer) interval,
// counted from when this second attempt happened.
if exhausted := rb.recordFailure(name, dueTime); exhausted {
t.Fatal("did not expect the retry budget to be exhausted after a second failure")
}
secondDue := dueTime.Add(retryIntervals[1])
if rb.readyForAsOf(name, secondDue.Add(-time.Millisecond)) {
t.Fatal("expected name to still be backing off before the second scheduled retry time")
}
if !rb.readyForAsOf(name, secondDue) {
t.Fatal("expected name to be ready once the second scheduled retry time has passed")
}
// clear() makes the name immediately ready again, as happens after a
// successful renewal.
rb.recordFailure(name, secondDue)
if rb.readyForAsOf(name, secondDue) {
t.Fatal("expected name to be backing off before calling clear")
}
rb.clear(name)
if !rb.readyForAsOf(name, secondDue) {
t.Fatal("expected name to be immediately ready after clear")
}
// Once the cumulative failure window reaches maxRetryDuration, the
// caller is told the budget is exhausted and the schedule resets, so a
// fresh maintenance tick is not throttled indefinitely (mirroring
// doWithRetry's own give-up-and-return behavior).
start := now
rb.recordFailure(name, start)
exhausted := rb.recordFailure(name, start.Add(maxRetryDuration))
if !exhausted {
t.Fatal("expected the retry budget to be reported exhausted once maxRetryDuration has elapsed")
}
if !rb.readyForAsOf(name, start.Add(maxRetryDuration)) {
t.Fatal("expected name to be immediately ready again after the retry budget was exhausted")
}
}