mirror of
https://github.com/hanzoai/tasks.git
synced 2026-10-04 02:04:03 +00:00
Lina JodoinandGitHub
a646b2d5ef
I'm sending the review for the mechanism (and an example callsite), and I'll send out a review that makes use of it throughout the scheduler code afterwards. ## What changed? - CHASM scheduler components each parent a new EventLog component, which we'll use to record decision logic details that are normally too spammy for logs. - No plan to expose this through any APIs just yet; it isn't meant to be customer-facing (though, I am thinking about how we can make it easy for dev success to get at) ## Why? - V1 debugging was often done through use of the workflow's event history; without an analogue for V2, it's difficult to get a clear picture of how the logic arrived at a certain output state. - Info logging in the same capacity would likely be too spammy for our observability system. - It's difficult to trace a complete picture for an individual schedule *over time* using just Loki. Schedules are often long-lived, with state transitions taking place in short blips over periods of days or weeks. Being able to get a complete list on demand for a relevant scheduler will greatly improve debugging time. ## How did you test it? - [ ] built - [ ] run locally and tested manually - [ ] covered by existing tests - [x] added new unit test(s) - [ ] added new functional test(s) ## Potential risks - This could increase scheduler state size, however: - V2 already measures notably lighter on storage than V1 (not to mention, no event history data whatsoever) - Log is bounded to max 30 messages per component (usually scheduler, generator, invoker) of max 1000 characters each (e.g., ~100KB), as a safety mechanism - Most messages logged will be small and informational, not large state dumps (e.g., "scheduler unpaused", "generator scheduled for ..."). - Backfillers each get their own log, which shares a Backfiller's lifecycle.
94 lines
3.1 KiB
Go
94 lines
3.1 KiB
Go
package scheduler_test
|
|
|
|
import (
|
|
"fmt"
|
|
"strings"
|
|
"testing"
|
|
"time"
|
|
|
|
"github.com/stretchr/testify/require"
|
|
enumspb "go.temporal.io/api/enums/v1"
|
|
schedulepb "go.temporal.io/api/schedule/v1"
|
|
"google.golang.org/protobuf/types/known/timestamppb"
|
|
)
|
|
|
|
const (
|
|
testEventLogMaxEntries = 30
|
|
testEventLogMaxMessageLen = 1000
|
|
)
|
|
|
|
func TestEventLog_Accumulates(t *testing.T) {
|
|
sched, ctx, _ := setupSchedulerForTest(t)
|
|
eventLog := sched.EventLog.Get(ctx)
|
|
eventLog.Events = nil
|
|
|
|
messages := []string{"first", "second", "third"}
|
|
for _, m := range messages {
|
|
eventLog.LogEvent(ctx, m, testEventLogMaxEntries, testEventLogMaxMessageLen)
|
|
}
|
|
|
|
require.Len(t, eventLog.Events, len(messages))
|
|
for i, m := range messages {
|
|
require.Equal(t, m, eventLog.Events[i].Message)
|
|
require.NotNil(t, eventLog.Events[i].Time)
|
|
}
|
|
}
|
|
|
|
func TestEventLog_TruncatesLongMessages(t *testing.T) {
|
|
sched, ctx, _ := setupSchedulerForTest(t)
|
|
eventLog := sched.EventLog.Get(ctx)
|
|
eventLog.Events = nil
|
|
|
|
long := strings.Repeat("x", testEventLogMaxMessageLen+50)
|
|
eventLog.LogEvent(ctx, long, testEventLogMaxEntries, testEventLogMaxMessageLen)
|
|
|
|
require.Len(t, eventLog.Events, 1)
|
|
require.Len(t, eventLog.Events[0].Message, testEventLogMaxMessageLen)
|
|
require.Equal(t, long[:testEventLogMaxMessageLen], eventLog.Events[0].Message)
|
|
}
|
|
|
|
func TestEventLog_DropsEarliestWhenFull(t *testing.T) {
|
|
sched, ctx, _ := setupSchedulerForTest(t)
|
|
eventLog := sched.EventLog.Get(ctx)
|
|
eventLog.Events = nil
|
|
|
|
const overflow = 5
|
|
total := testEventLogMaxEntries + overflow
|
|
for i := range total {
|
|
eventLog.LogEvent(ctx, fmt.Sprintf("event-%d", i), testEventLogMaxEntries, testEventLogMaxMessageLen)
|
|
}
|
|
|
|
require.Len(t, eventLog.Events, testEventLogMaxEntries)
|
|
// The earliest `overflow` entries should have been dropped; the retained
|
|
// window starts at event-`overflow` and ends at the most recent event.
|
|
require.Equal(t, fmt.Sprintf("event-%d", overflow), eventLog.Events[0].Message)
|
|
require.Equal(t, fmt.Sprintf("event-%d", total-1), eventLog.Events[len(eventLog.Events)-1].Message)
|
|
}
|
|
|
|
func TestEventLog_EachComponentHasOwn(t *testing.T) {
|
|
sched, ctx, _ := setupSchedulerForTest(t)
|
|
|
|
// Create a backfiller so we can exercise its EventLog too.
|
|
backfiller := sched.NewRangeBackfiller(ctx, &schedulepb.BackfillRequest{
|
|
StartTime: timestamppb.New(time.Now().Add(-time.Hour)),
|
|
EndTime: timestamppb.New(time.Now()),
|
|
OverlapPolicy: enumspb.SCHEDULE_OVERLAP_POLICY_ALLOW_ALL,
|
|
})
|
|
|
|
// Each host component gets its own EventLog instance.
|
|
require.NotNil(t, sched.EventLog.Get(ctx))
|
|
require.NotNil(t, sched.Generator.Get(ctx).EventLog.Get(ctx))
|
|
require.NotNil(t, sched.Invoker.Get(ctx).EventLog.Get(ctx))
|
|
require.NotNil(t, backfiller.EventLog.Get(ctx))
|
|
|
|
// EventLogs on different hosts are independent.
|
|
sched.EventLog.Get(ctx).Events = nil
|
|
sched.Generator.Get(ctx).EventLog.Get(ctx).Events = nil
|
|
backfiller.EventLog.Get(ctx).Events = nil
|
|
|
|
sched.EventLog.Get(ctx).LogEvent(ctx, "scheduler-event", testEventLogMaxEntries, testEventLogMaxMessageLen)
|
|
require.Len(t, sched.EventLog.Get(ctx).Events, 1)
|
|
require.Empty(t, sched.Generator.Get(ctx).EventLog.Get(ctx).Events)
|
|
require.Empty(t, backfiller.EventLog.Get(ctx).Events)
|
|
}
|