Skip to content

Commit 8098ae5

Browse files
committed
[anomalydetection] guard negative flush_interval; preserve log event time
Two fixes from Codex review: 1. NewComponent treated only flush_interval == 0 as needing the default, so a negative value (e.g. user types -1s) flowed through to time.NewTicker, which panics on non-positive durations. Change the guard to <= 0 to match the existing retention guard three lines below. 2. recordingHandle.ObserveLog stamped recorded logs with time.Now().UnixMilli() instead of the LogView's own event time. Replayed, buffered, or delayed logs were recorded with ingestion time rather than the actual event time, breaking chronological reconstruction. Use msg.GetTimestampUnixMilli(), falling back to wall clock only when the message reports zero. Tests (both verified to fail against the unpatched code): - TestRecorderNegativeFlushIntervalFallsBackToDefault — without the fix, the writer goroutine panics in time.NewTicker. - TestRecordingHandle_PreservesLogTimestamp — without the fix, the recorded TimestampMs is wall-clock-now, not the message's event time. Codex flagged a third issue (parquet_log_reader.go reading only chunks[0]). Investigated and confirmed it is not reachable in practice: pqarrow's ReadTable consolidates all row groups into a single Arrow chunk on read in arrow-go v18.4.0 (verified empirically against a parquet file with 8 row groups — produces a 1-chunk table). The chunks[0] pattern is therefore correct for current arrow-go behavior. Not applied.
1 parent 8d12780 commit 8098ae5

2 files changed

Lines changed: 88 additions & 2 deletions

File tree

comp/anomalydetection/recorder/impl/recorder.go

Lines changed: 10 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -51,7 +51,7 @@ func NewComponent(req Requires) Provides {
5151
}
5252

5353
flushInterval := req.Config.GetDuration("anomaly_detection.recording.flush_interval")
54-
if flushInterval == 0 {
54+
if flushInterval <= 0 {
5555
flushInterval = 60 * time.Second
5656
}
5757

@@ -224,19 +224,27 @@ func (h *recordingHandle) ObserveMetric(sample observer.MetricView) {
224224
}
225225

226226
// ObserveLog forwards the log to the inner handle and records it.
227+
// Uses the LogView's own timestamp (event time) rather than wall-clock now
228+
// so that delayed, buffered, or replayed logs are recorded with their
229+
// original time. Wall-clock falls back only when the message reports no
230+
// timestamp (event time == 0), which would otherwise sort to the epoch.
227231
func (h *recordingHandle) ObserveLog(msg observer.LogView) {
228232
h.inner.ObserveLog(msg)
229233

230234
content := msg.GetContent()
231235
contentCopy := make([]byte, len(content))
232236
copy(contentCopy, content)
233237

238+
timestampMs := msg.GetTimestampUnixMilli()
239+
if timestampMs == 0 {
240+
timestampMs = time.Now().UnixMilli()
241+
}
234242
h.recorder.logParquetWriter.WriteLog(
235243
h.name,
236244
contentCopy,
237245
msg.GetStatus(),
238246
msg.GetHostname(),
239247
msg.GetTags(),
240-
time.Now().UnixMilli(),
248+
timestampMs,
241249
)
242250
}

comp/anomalydetection/recorder/impl/recorder_test.go

Lines changed: 78 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -32,6 +32,22 @@ type fakeHandle struct {
3232
func (h *fakeHandle) ObserveMetric(_ observerdef.MetricView) { h.metricCalls++ }
3333
func (h *fakeHandle) ObserveLog(_ observerdef.LogView) { h.logCalls++ }
3434

35+
// fakeLogView is a minimal observer.LogView with caller-controlled fields,
36+
// used to assert that ObserveLog reads the message's own timestamp.
37+
type fakeLogView struct {
38+
content []byte
39+
status string
40+
tags []string
41+
hostname string
42+
timestampMs int64
43+
}
44+
45+
func (f *fakeLogView) GetContent() []byte { return f.content }
46+
func (f *fakeLogView) GetStatus() string { return f.status }
47+
func (f *fakeLogView) GetTags() []string { return f.tags }
48+
func (f *fakeLogView) GetHostname() string { return f.hostname }
49+
func (f *fakeLogView) GetTimestampUnixMilli() int64 { return f.timestampMs }
50+
3551
// TestRecorderDisabledByDefault locks in the most important contract: when
3652
// anomaly_detection.recording.enabled is false (the default), GetHandle returns
3753
// the inner handle unwrapped and no writer goroutines are started. This is the
@@ -168,3 +184,65 @@ func TestMetricTimestampUnitConsistency(t *testing.T) {
168184
require.Equal(t, tsSec*1000, metrics[0].TimestampMs,
169185
"MetricData.TimestampMs must be in milliseconds (same unit as LogData.TimestampMs); writer received %d seconds, expected %d ms on read", tsSec, tsSec*1000)
170186
}
187+
188+
// TestRecorderNegativeFlushIntervalFallsBackToDefault locks in the Codex #1
189+
// fix: a negative anomaly_detection.recording.flush_interval must not be
190+
// passed through to time.NewTicker (which panics on non-positive durations).
191+
// The recorder should fall back to the 60s default instead.
192+
func TestRecorderNegativeFlushIntervalFallsBackToDefault(t *testing.T) {
193+
cfg := config.NewMockWithOverrides(t, map[string]interface{}{
194+
"anomaly_detection.recording.enabled": true,
195+
"anomaly_detection.recording.output_dir": t.TempDir(),
196+
"anomaly_detection.recording.flush_interval": -1 * time.Second,
197+
"anomaly_detection.recording.retention": time.Hour,
198+
})
199+
lc := compdef.NewTestLifecycle(t)
200+
201+
out := NewComponent(Requires{Lifecycle: lc, Config: cfg})
202+
require.NotNil(t, out.Comp)
203+
204+
impl := out.Comp.(*recorderImpl)
205+
require.NotNil(t, impl.metricParquetWriter, "writer should be constructed (recorder not disabled)")
206+
require.Equal(t, 60*time.Second, impl.metricParquetWriter.flushInterval,
207+
"negative flush_interval must fall back to 60s default")
208+
require.NoError(t, lc.Stop(context.Background()))
209+
}
210+
211+
// TestRecordingHandle_PreservesLogTimestamp locks in the Codex #3 fix:
212+
// ObserveLog must use the message's own GetTimestampUnixMilli() instead of
213+
// wall-clock time, so replayed/delayed/buffered logs are recorded with their
214+
// original event time.
215+
func TestRecordingHandle_PreservesLogTimestamp(t *testing.T) {
216+
tmpDir := t.TempDir()
217+
cfg := config.NewMockWithOverrides(t, map[string]interface{}{
218+
"anomaly_detection.recording.enabled": true,
219+
"anomaly_detection.recording.output_dir": tmpDir,
220+
"anomaly_detection.recording.flush_interval": time.Hour, // only flush on Stop
221+
"anomaly_detection.recording.retention": time.Hour,
222+
})
223+
lc := compdef.NewTestLifecycle(t)
224+
225+
out := NewComponent(Requires{Lifecycle: lc, Config: cfg})
226+
require.NotNil(t, out.Comp)
227+
228+
inner := &fakeHandle{}
229+
handle := out.Comp.GetHandle(func(_ string) observerdef.Handle { return inner })("test-source")
230+
231+
// Pick an event time that is unambiguously not "now".
232+
const eventTimeMs = int64(1_700_000_000_000)
233+
handle.ObserveLog(&fakeLogView{
234+
content: []byte("hello"),
235+
status: "info",
236+
hostname: "host-x",
237+
tags: []string{"env:test"},
238+
timestampMs: eventTimeMs,
239+
})
240+
241+
require.NoError(t, lc.Stop(context.Background()))
242+
243+
logs, err := out.Comp.ReadAllLogs(tmpDir)
244+
require.NoError(t, err)
245+
require.Len(t, logs, 1)
246+
require.Equal(t, eventTimeMs, logs[0].TimestampMs,
247+
"recorded log timestamp must come from LogView.GetTimestampUnixMilli, not wall clock")
248+
}

0 commit comments

Comments
 (0)