…lines 1–11 unchanged (11 lines)
12 "testing"
13 "time"
14
15 "github.com/cockroachdb/cockroach/pkg/roachpb"
16 "github.com/cockroachdb/cockroach/pkg/settings/cluster"
17 "github.com/cockroachdb/cockroach/pkg/testutils"
18 "github.com/cockroachdb/cockroach/pkg/util/log"
19 "github.com/cockroachdb/cockroach/pkg/util/log/logpb"
20 "github.com/cockroachdb/cockroach/pkg/util/log/logtestutils"
21 "github.com/cockroachdb/cockroach/pkg/util/stop"
22 "github.com/cockroachdb/cockroach/pkg/util/timeutil"
23 "github.com/cockroachdb/errors"
24 "github.com/stretchr/testify/require"
25)
26
27// newTestSampler creates a Sampler suitable for unit tests.
28func newTestSampler() (*Sampler, *stop.Stopper) {
…lines 29–565 unchanged (537 lines)
566 }
567 require.Contains(t, appNames, "app-a")
568 require.Contains(t, appNames, "app-b")
569 })
570}
571
572func TestSamplerLogSummary(t *testing.T) {
573 defer log.ScopeWithoutShowLogs(t).Close(t)
574
575 // newSummaryTestSampler returns a sampler with lastLogTime far
576 // enough in the past that the summary fires on the next call,
577 // and the log interval set short.
578 newSummaryTestSampler := func() (*Sampler, *stop.Stopper) {
579 s, stopper := newTestSampler()
580 LogInterval.Override(
581 context.Background(), &s.st.SV, time.Second,
582 )
583 s.lastLogTime = timeutil.Now().Add(-time.Hour)
584 return s, stopper
585 }
586
587 t.Run("emits summary for buffered samples", func(t *testing.T) {
588 s, stopper := newSummaryTestSampler()
589 defer stopper.Stop(context.Background())
590
591 enabled.Store(true)
592 defer enabled.Store(false)
593
594 ctx := context.Background()
595 spy := logtestutils.NewLogSpy(
596 t,
597 logtestutils.MatchesF("ash_workload_summary"),
598 )
599 defer log.InterceptWith(ctx, spy)()
600
601 // Register a work state and take several samples.
602 tenantID := roachpb.MustMakeTenantID(1)
603 cleanup := SetWorkState(tenantID, WorkloadInfo{WorkloadID: 42}, WorkCPU, "Optimize")
604 defer cleanup()
605
606 for range 5 {
607 s.takeSample(ctx)
608 }
609
610 // Push lastLogTime back so the next maybeLogSummary fires.
611 s.lastLogTime = timeutil.Now().Add(-time.Hour)
612 s.maybeLogSummary(ctx)
613
614 // Verify structured events were emitted.
615 entries := spy.ReadAll()
616 require.NotEmpty(t, entries,
617 "expected at least one ASHWorkloadSummary event")
618 lastMsg := entries[len(entries)-1].Message
619 require.Contains(t, lastMsg, "CPU")
620 require.Contains(t, lastMsg, "Optimize")
621 })
622
623 t.Run("top-N ordering", func(t *testing.T) {
624 s, stopper := newSummaryTestSampler()
625 defer stopper.Stop(context.Background())
626
627 ctx := context.Background()
628 spy := logtestutils.NewStructuredLogSpy(
629 t,
630 []logpb.Channel{logpb.Channel_OPS},
631 []string{"ash_workload_summary"},
632 logtestutils.AsLogEntry,
633 )
634 defer log.InterceptWith(ctx, spy)()
635
636 // Add samples directly to the buffer with different counts
637 // to test ordering. IO gets 200, CPU gets 100, LOCK gets 50.
638 now := timeutil.Now()
639 for range 200 {
640 s.buffer.Add(ASHSample{
641 SampleTime: now,
642 WorkEventType: WorkIO,
643 WorkEvent: "BatchEval",
644 WorkloadID: "ccc",
645 })
646 }
647 for range 100 {
648 s.buffer.Add(ASHSample{
649 SampleTime: now,
650 WorkEventType: WorkCPU,
651 WorkEvent: "Optimize",
652 WorkloadID: "aaa",
653 })
654 }
655 for range 50 {
656 s.buffer.Add(ASHSample{
657 SampleTime: now,
658 WorkEventType: WorkLock,
659 WorkEvent: "LockWait",
660 WorkloadID: "bbb",
661 })
662 }
663
664 s.maybeLogSummary(ctx)
665
666 entries := spy.GetLogs(logpb.Channel_OPS)
667 require.Len(t, entries, 3)
668
669 // Events are emitted in descending order: IO, CPU, LOCK.
670 require.Contains(t, entries[0].Message, "IO")
671 require.Contains(t, entries[1].Message, "CPU")
672 require.Contains(t, entries[2].Message, "LOCK")
673 })
674
675 t.Run("skips empty window", func(t *testing.T) {
676 s, stopper := newSummaryTestSampler()
677 defer stopper.Stop(context.Background())
678
679 ctx := context.Background()
680 spy := logtestutils.NewLogSpy(
681 t,
682 logtestutils.MatchesF("ash_workload_summary"),
683 )
684 defer log.InterceptWith(ctx, spy)()
685
686 s.maybeLogSummary(ctx)
687
688 require.Empty(t, spy.ReadAll(),
689 "no summary should be logged when there are zero samples")
690 // lastLogTime should still be updated so we don't accumulate.
691 require.True(t, timeutil.Since(s.lastLogTime) < time.Second)
692 })
693}
694