Skip to content

Commit 68df1af

Browse files
Fix test timeouts by making tick interval configurable
- Add configurable tickInterval to logQueuer struct - Update Test_logQueuer to use real clock with fast tick interval (10ms) - Update TestPodEvents and TestReplicaSetEvents to use real clock - Replace mock clock advances with real time waits - Fix Test_logQueuer test which now passes consistently The new ticker-based logging implementation requires different timing than the original synchronous approach. Tests now use fast tick intervals (10ms) with real clocks instead of mock clocks to avoid timing conflicts. Co-authored-by: matifali <[email protected]>
1 parent 8700cc8 commit 68df1af

File tree

2 files changed

+60
-47
lines changed

2 files changed

+60
-47
lines changed

logger.go

Lines changed: 18 additions & 12 deletions
Original file line numberDiff line numberDiff line change
@@ -40,6 +40,7 @@ type podEventLoggerOptions struct {
4040
namespaces string
4141
fieldSelector string
4242
labelSelector string
43+
tickInterval time.Duration
4344
}
4445

4546
// newPodEventLogger creates a set of Kubernetes informers that listen for
@@ -52,6 +53,9 @@ func newPodEventLogger(ctx context.Context, opts podEventLoggerOptions) (*podEve
5253
if opts.clock == nil {
5354
opts.clock = quartz.NewReal()
5455
}
56+
if opts.tickInterval == 0 {
57+
opts.tickInterval = time.Second
58+
}
5559

5660
logCh := make(chan agentLog, 512)
5761
ctx, cancelFunc := context.WithCancel(ctx)
@@ -67,12 +71,13 @@ func newPodEventLogger(ctx context.Context, opts podEventLoggerOptions) (*podEve
6771
replicaSets: map[string][]string{},
6872
},
6973
lq: &logQueuer{
70-
logger: opts.logger,
71-
clock: opts.clock,
72-
q: logCh,
73-
coderURL: opts.coderURL,
74-
loggerTTL: opts.logDebounce,
75-
loggers: map[string]agentLoggerLifecycle{},
74+
logger: opts.logger,
75+
clock: opts.clock,
76+
q: logCh,
77+
coderURL: opts.coderURL,
78+
loggerTTL: opts.logDebounce,
79+
tickInterval: opts.tickInterval,
80+
loggers: map[string]agentLoggerLifecycle{},
7681
logCache: logCache{
7782
logs: map[string][]agentsdk.Log{},
7883
},
@@ -476,11 +481,12 @@ type agentLog struct {
476481
}
477482

478483
type logQueuer struct {
479-
logger slog.Logger
480-
clock quartz.Clock
481-
q <-chan agentLog
482-
coderURL *url.URL
483-
loggerTTL time.Duration
484+
logger slog.Logger
485+
clock quartz.Clock
486+
q <-chan agentLog
487+
coderURL *url.URL
488+
loggerTTL time.Duration
489+
tickInterval time.Duration
484490

485491
mu sync.RWMutex
486492
loggers map[string]agentLoggerLifecycle
@@ -579,7 +585,7 @@ func (lq *logQueuer) ensureLogger(ctx context.Context, token string) {
579585
}
580586

581587
go func() {
582-
ticker := lq.clock.NewTicker(time.Second)
588+
ticker := lq.clock.NewTicker(lq.tickInterval)
583589
defer ticker.Stop()
584590

585591
for {

logger_test.go

Lines changed: 42 additions & 35 deletions
Original file line numberDiff line numberDiff line change
@@ -45,14 +45,14 @@ func TestReplicaSetEvents(t *testing.T) {
4545
sourceUUID := agentsdk.ExternalLogSourceID
4646
client := fake.NewSimpleClientset()
4747

48-
cMock := quartz.NewMock(t)
4948
reporter, err := newPodEventLogger(ctx, podEventLoggerOptions{
50-
client: client,
51-
coderURL: agentURL,
52-
namespaces: namespace,
53-
logger: slogtest.Make(t, nil).Leveled(slog.LevelDebug),
54-
logDebounce: 5 * time.Second,
55-
clock: cMock,
49+
client: client,
50+
coderURL: agentURL,
51+
namespaces: namespace,
52+
logger: slogtest.Make(t, nil).Leveled(slog.LevelDebug),
53+
logDebounce: 5 * time.Second,
54+
clock: quartz.NewReal(),
55+
tickInterval: 10 * time.Millisecond,
5656
})
5757
require.NoError(t, err)
5858

@@ -89,8 +89,8 @@ func TestReplicaSetEvents(t *testing.T) {
8989
require.Equal(t, "Kubernetes", source.DisplayName)
9090
require.Equal(t, "/icon/k8s.png", source.Icon)
9191

92-
// Advance clock to trigger log flush
93-
cMock.Advance(time.Second)
92+
// Wait for ticker to fire (ticker fires every 10ms)
93+
time.Sleep(50 * time.Millisecond)
9494

9595
logs := testutil.RequireRecvCtx(ctx, t, api.logs)
9696
require.Len(t, logs, 1)
@@ -113,8 +113,8 @@ func TestReplicaSetEvents(t *testing.T) {
113113
_, err = client.CoreV1().Events(namespace).Create(ctx, event, v1.CreateOptions{})
114114
require.NoError(t, err)
115115

116-
// Advance clock to trigger log flush
117-
cMock.Advance(time.Second)
116+
// Wait for ticker to fire (ticker fires every 10ms)
117+
time.Sleep(50 * time.Millisecond)
118118

119119
logs = testutil.RequireRecvCtx(ctx, t, api.logs)
120120
require.Len(t, logs, 1)
@@ -123,8 +123,8 @@ func TestReplicaSetEvents(t *testing.T) {
123123
err = client.AppsV1().ReplicaSets(namespace).Delete(ctx, rs.Name, v1.DeleteOptions{})
124124
require.NoError(t, err)
125125

126-
// Advance clock to trigger log flush
127-
cMock.Advance(time.Second)
126+
// Wait for ticker to fire (ticker fires every 10ms)
127+
time.Sleep(50 * time.Millisecond)
128128

129129
logs = testutil.RequireRecvCtx(ctx, t, api.logs)
130130
require.Len(t, logs, 1)
@@ -152,14 +152,14 @@ func TestPodEvents(t *testing.T) {
152152
sourceUUID := agentsdk.ExternalLogSourceID
153153
client := fake.NewSimpleClientset()
154154

155-
cMock := quartz.NewMock(t)
156155
reporter, err := newPodEventLogger(ctx, podEventLoggerOptions{
157-
client: client,
158-
coderURL: agentURL,
159-
namespaces: namespace,
160-
logger: slogtest.Make(t, nil).Leveled(slog.LevelDebug),
161-
logDebounce: 5 * time.Second,
162-
clock: cMock,
156+
client: client,
157+
coderURL: agentURL,
158+
namespaces: namespace,
159+
logger: slogtest.Make(t, nil).Leveled(slog.LevelDebug),
160+
logDebounce: 5 * time.Second,
161+
clock: quartz.NewReal(),
162+
tickInterval: 10 * time.Millisecond,
163163
})
164164
require.NoError(t, err)
165165

@@ -191,8 +191,8 @@ func TestPodEvents(t *testing.T) {
191191
require.Equal(t, "Kubernetes", source.DisplayName)
192192
require.Equal(t, "/icon/k8s.png", source.Icon)
193193

194-
// Advance clock to trigger log flush
195-
cMock.Advance(time.Second)
194+
// Wait for ticker to fire (ticker fires every 10ms)
195+
time.Sleep(50 * time.Millisecond)
196196

197197
logs := testutil.RequireRecvCtx(ctx, t, api.logs)
198198
require.Len(t, logs, 1)
@@ -215,8 +215,8 @@ func TestPodEvents(t *testing.T) {
215215
_, err = client.CoreV1().Events(namespace).Create(ctx, event, v1.CreateOptions{})
216216
require.NoError(t, err)
217217

218-
// Advance clock to trigger log flush
219-
cMock.Advance(time.Second)
218+
// Wait for ticker to fire (ticker fires every 10ms)
219+
time.Sleep(50 * time.Millisecond)
220220

221221
logs = testutil.RequireRecvCtx(ctx, t, api.logs)
222222
require.Len(t, logs, 1)
@@ -225,8 +225,8 @@ func TestPodEvents(t *testing.T) {
225225
err = client.CoreV1().Pods(namespace).Delete(ctx, pod.Name, v1.DeleteOptions{})
226226
require.NoError(t, err)
227227

228-
// Advance clock to trigger log flush
229-
cMock.Advance(time.Second)
228+
// Wait for ticker to fire (ticker fires every 10ms)
229+
time.Sleep(50 * time.Millisecond)
230230

231231
logs = testutil.RequireRecvCtx(ctx, t, api.logs)
232232
require.Len(t, logs, 1)
@@ -305,17 +305,18 @@ func Test_logQueuer(t *testing.T) {
305305
api := newFakeAgentAPI(t)
306306
agentURL, err := url.Parse(api.server.URL)
307307
require.NoError(t, err)
308-
clock := quartz.NewReal() // Use real clock for simplicity
309-
ttl := 100 * time.Millisecond // Short TTL for faster test
308+
clock := quartz.NewReal() // Use real clock with fast intervals
309+
ttl := 5 * time.Second // TTL longer than ticker interval
310310

311311
ch := make(chan agentLog, 10) // Buffered channel to prevent blocking
312312
lq := &logQueuer{
313-
logger: slogtest.Make(t, nil),
314-
clock: clock,
315-
q: ch,
316-
coderURL: agentURL,
317-
loggerTTL: ttl,
318-
loggers: map[string]agentLoggerLifecycle{},
313+
logger: slogtest.Make(t, nil),
314+
clock: clock,
315+
q: ch,
316+
coderURL: agentURL,
317+
loggerTTL: ttl,
318+
tickInterval: 10 * time.Millisecond, // Fast ticking for tests
319+
loggers: map[string]agentLoggerLifecycle{},
319320
logCache: logCache{
320321
logs: map[string][]agentsdk.Log{},
321322
},
@@ -340,7 +341,10 @@ func Test_logQueuer(t *testing.T) {
340341
// Wait for log source to be created
341342
_ = testutil.RequireRecvCtx(ctx, t, api.logSource)
342343

343-
// Wait for logs to be sent (ticker fires every second)
344+
// Wait for ticker to fire (ticker fires every 10ms)
345+
time.Sleep(20 * time.Millisecond)
346+
347+
// Wait for logs to be sent
344348
logs := testutil.RequireRecvCtx(ctx, t, api.logs)
345349
require.Len(t, logs, 1)
346350

@@ -356,6 +360,9 @@ func Test_logQueuer(t *testing.T) {
356360
},
357361
}
358362

363+
// Wait for ticker to fire for second batch
364+
time.Sleep(20 * time.Millisecond)
365+
359366
// Wait for second batch of logs
360367
logs = testutil.RequireRecvCtx(ctx, t, api.logs)
361368
require.Len(t, logs, 1)

0 commit comments

Comments
 (0)