diff options
| author | Paul Buetow <paul@buetow.org> | 2026-05-20 14:37:41 +0300 |
|---|---|---|
| committer | Paul Buetow <paul@buetow.org> | 2026-05-20 14:37:41 +0300 |
| commit | 96355c79a38032ab4bd880b3b3ff4192ae709795 (patch) | |
| tree | 7a395706e3db680f6e695c8602501741eed6ad45 | |
| parent | f063e626a28339735da583142e5af864a60c2111 (diff) | |
task 27: add KindSleep and requested sleep metric
27 files changed, 607 insertions, 29 deletions
diff --git a/cmd/ioworkload/scenario_sleep.go b/cmd/ioworkload/scenario_sleep.go new file mode 100644 index 0000000..bb6c5a4 --- /dev/null +++ b/cmd/ioworkload/scenario_sleep.go @@ -0,0 +1,45 @@ +package main + +import ( + "fmt" + "runtime" + "syscall" + "time" + "unsafe" + + "golang.org/x/sys/unix" +) + +const sleepSyscallsEmitFor = 2 * time.Second + +func sleepSyscalls() error { + deadline := time.Now().Add(sleepSyscallsEmitFor) + for time.Now().Before(deadline) { + if err := syscall.Nanosleep(&syscall.Timespec{Sec: 0, Nsec: 2_000_000}, nil); err != nil && err != syscall.EINTR { + return fmt.Errorf("nanosleep: %w", err) + } + if err := callClockNanosleep(3_000_000); err != nil { + return err + } + } + return nil +} + +func callClockNanosleep(requestedNs int64) error { + req := unix.Timespec{Sec: requestedNs / 1_000_000_000, Nsec: requestedNs % 1_000_000_000} + _, _, errno := syscall.RawSyscall6( + unix.SYS_CLOCK_NANOSLEEP, + uintptr(unix.CLOCK_MONOTONIC), + 0, + uintptr(unsafe.Pointer(&req)), + 0, + 0, + 0, + ) + runtime.KeepAlive(req) + if errno != 0 && errno != syscall.EINTR { + return fmt.Errorf("clock_nanosleep: %w", errno) + } + return nil +} + diff --git a/cmd/ioworkload/scenarios.go b/cmd/ioworkload/scenarios.go index 8f4eef2..e0827a5 100644 --- a/cmd/ioworkload/scenarios.go +++ b/cmd/ioworkload/scenarios.go @@ -35,6 +35,7 @@ var scenarios = map[string]func() error{ "eventfd-basic": eventfdBasic, "eventfd2-basic": eventfd2Basic, "polling-epoll": pollingEpoll, + "sleep-syscalls": sleepSyscalls, "family-mixed": familyMixed, "close-basic": closeBasic, "close-range": closeRange, diff --git a/integrationtests/sleep_test.go b/integrationtests/sleep_test.go new file mode 100644 index 0000000..a465420 --- /dev/null +++ b/integrationtests/sleep_test.go @@ -0,0 +1,67 @@ +package integrationtests + +import "testing" + +const ( + sleepParquetDuration = 6 + sleepWorkloadStartupEnv = "IOR_WORKLOAD_STARTUP_DELAY_MS=1000" +) + +func TestSleepTracepoints(t *testing.T) { + h := newTestHarness(t) + h.WorkloadEnv = []string{sleepWorkloadStartupEnv} + result, pid, err := h.Run("sleep-syscalls", defaultDuration) + if err != nil { + t.Fatalf("run scenario sleep-syscalls: %v", err) + } + + AssertNoUnexpectedPID(t, result, pid) + AssertNoUnexpectedComm(t, result, "ioworkload") + AssertEventsPresent(t, result, []ExpectedEvent{ + {Tracepoint: "enter_nanosleep", Comm: "ioworkload", MinCount: 1}, + {Tracepoint: "enter_clock_nanosleep", Comm: "ioworkload", MinCount: 1}, + }) +} + +func TestSleepRequestedTimespecInParquet(t *testing.T) { + h := newTestHarness(t) + h.WorkloadEnv = []string{sleepWorkloadStartupEnv} + path, pid, err := h.RunParquet("sleep-syscalls", sleepParquetDuration) + if err != nil { + t.Fatalf("run sleep-syscalls parquet scenario: %v", err) + } + + rows := filterRecordsByPID(readParquetRecords(t, path), uint32(pid)) + if len(rows) == 0 { + t.Fatalf("expected parquet rows for workload PID %d", pid) + } + + var sawNanosleep bool + var sawClockNanosleep bool + for _, row := range rows { + switch row.Syscall { + case "nanosleep": + if row.RequestedSleepNS == 2_000_000 { + sawNanosleep = true + } + if row.Bytes != 0 { + t.Fatalf("nanosleep bytes = %d, want 0", row.Bytes) + } + case "clock_nanosleep": + if row.RequestedSleepNS == 3_000_000 { + sawClockNanosleep = true + } + if row.Bytes != 0 { + t.Fatalf("clock_nanosleep bytes = %d, want 0", row.Bytes) + } + } + } + + if !sawNanosleep { + t.Fatal("expected nanosleep row with RequestedSleepNS=2000000") + } + if !sawClockNanosleep { + t.Fatal("expected clock_nanosleep row with RequestedSleepNS=3000000") + } +} + diff --git a/internal/c/generated_tracepoints.c b/internal/c/generated_tracepoints.c index 68aa8a7..55164d5 100644 --- a/internal/c/generated_tracepoints.c +++ b/internal/c/generated_tracepoints.c @@ -14261,7 +14261,7 @@ int handle_sys_exit_clock_getres(struct syscall_trace_exit *ctx) { return 0; } -/// sys_enter_clock_nanosleep is a struct null_event +/// sys_enter_clock_nanosleep is a struct sleep_event SEC("tracepoint/syscalls/sys_enter_clock_nanosleep") int handle_sys_enter_clock_nanosleep(struct syscall_trace_enter *ctx) { __u32 pid, tid; @@ -14271,15 +14271,25 @@ int handle_sys_enter_clock_nanosleep(struct syscall_trace_enter *ctx) { if (!ior_on_syscall_enter(tid, SYS_ENTER_CLOCK_NANOSLEEP)) return 0; - struct null_event *ev = bpf_ringbuf_reserve(&event_map, sizeof(struct null_event), 0); + struct sleep_event *ev = bpf_ringbuf_reserve(&event_map, sizeof(struct sleep_event), 0); if (!ev) return 0; - ev->event_type = ENTER_NULL_EVENT; + ev->event_type = ENTER_SLEEP_EVENT; ev->trace_id = SYS_ENTER_CLOCK_NANOSLEEP; ev->pid = pid; ev->tid = tid; ev->time = bpf_ktime_get_boot_ns(); + ev->requested_ns = -1; + if (ctx->args[2] != 0) { + struct __ior_timespec { + __s64 tv_sec; + __s64 tv_nsec; + } ts = {}; + if (bpf_probe_read_user(&ts, sizeof(ts), (void *)ctx->args[2]) == 0) { + ev->requested_ns = ts.tv_sec * 1000000000LL + ts.tv_nsec; + } + } bpf_ringbuf_submit(ev, 0); return 0; @@ -14311,7 +14321,7 @@ int handle_sys_exit_clock_nanosleep(struct syscall_trace_exit *ctx) { return 0; } -/// sys_enter_nanosleep is a struct null_event +/// sys_enter_nanosleep is a struct sleep_event SEC("tracepoint/syscalls/sys_enter_nanosleep") int handle_sys_enter_nanosleep(struct syscall_trace_enter *ctx) { __u32 pid, tid; @@ -14321,15 +14331,25 @@ int handle_sys_enter_nanosleep(struct syscall_trace_enter *ctx) { if (!ior_on_syscall_enter(tid, SYS_ENTER_NANOSLEEP)) return 0; - struct null_event *ev = bpf_ringbuf_reserve(&event_map, sizeof(struct null_event), 0); + struct sleep_event *ev = bpf_ringbuf_reserve(&event_map, sizeof(struct sleep_event), 0); if (!ev) return 0; - ev->event_type = ENTER_NULL_EVENT; + ev->event_type = ENTER_SLEEP_EVENT; ev->trace_id = SYS_ENTER_NANOSLEEP; ev->pid = pid; ev->tid = tid; ev->time = bpf_ktime_get_boot_ns(); + ev->requested_ns = -1; + if (ctx->args[0] != 0) { + struct __ior_timespec { + __s64 tv_sec; + __s64 tv_nsec; + } ts = {}; + if (bpf_probe_read_user(&ts, sizeof(ts), (void *)ctx->args[0]) == 0) { + ev->requested_ns = ts.tv_sec * 1000000000LL + ts.tv_nsec; + } + } bpf_ringbuf_submit(ev, 0); return 0; diff --git a/internal/c/generated_tracepoints_result.txt b/internal/c/generated_tracepoints_result.txt index 77339f5..6319861 100644 --- a/internal/c/generated_tracepoints_result.txt +++ b/internal/c/generated_tracepoints_result.txt @@ -19,7 +19,7 @@ sys_enter_chroot is a struct path_event sys_enter_clock_adjtime is a struct null_event sys_enter_clock_getres is a struct null_event sys_enter_clock_gettime is a struct null_event -sys_enter_clock_nanosleep is a struct null_event +sys_enter_clock_nanosleep is a struct sleep_event sys_enter_clock_settime is a struct null_event sys_enter_clone is a struct null_event sys_enter_clone3 is a struct null_event @@ -192,7 +192,7 @@ sys_enter_munlock is a struct null_event sys_enter_munlockall is a struct null_event sys_enter_munmap is a struct mem_event sys_enter_name_to_handle_at is a struct path_event -sys_enter_nanosleep is a struct null_event +sys_enter_nanosleep is a struct sleep_event sys_enter_newfstat is a struct fd_event sys_enter_newfstatat is a struct path_event sys_enter_newlstat is a struct path_event diff --git a/internal/c/types.h b/internal/c/types.h index a496c1a..6c22b90 100644 --- a/internal/c/types.h +++ b/internal/c/types.h @@ -37,6 +37,8 @@ #define EXIT_POLL_EVENT 32 #define ENTER_MEM_EVENT 33 #define EXIT_MEM_EVENT 34 +#define ENTER_SLEEP_EVENT 35 +#define EXIT_SLEEP_EVENT 36 #define UNCLASSIFIED 0 #define READ_CLASSIFIED 1 @@ -221,3 +223,12 @@ struct mem_event { __u64 length2; __u64 flags; }; + +struct sleep_event { + __u32 event_type; + __u32 trace_id; + __u64 time; + __u32 pid; + __u32 tid; + __s64 requested_ns; +}; diff --git a/internal/event/interface_assertions.go b/internal/event/interface_assertions.go index 97a198f..ebe1d9f 100644 --- a/internal/event/interface_assertions.go +++ b/internal/event/interface_assertions.go @@ -65,4 +65,7 @@ var ( // *types.MemEvent carries memory-operation metadata (addr/length/flags). _ Event = (*types.MemEvent)(nil) + + // *types.SleepEvent carries requested sleep duration metadata. + _ Event = (*types.SleepEvent)(nil) ) diff --git a/internal/event/pair.go b/internal/event/pair.go index 115323b..523f961 100644 --- a/internal/event/pair.go +++ b/internal/event/pair.go @@ -29,6 +29,8 @@ type Pair struct { // AddressSpaceBytes tracks memory-region extent for memory syscalls // (e.g. munmap/mremap) and is intentionally separate from I/O bytes. AddressSpaceBytes uint64 + // RequestedSleepNs tracks requested sleep duration for nanosleep-style syscalls. + RequestedSleepNs int64 } func NewPair(enterEv Event) *Pair { diff --git a/internal/eventloop_bytes_test.go b/internal/eventloop_bytes_test.go index 636f80f..54c25d0 100644 --- a/internal/eventloop_bytes_test.go +++ b/internal/eventloop_bytes_test.go @@ -147,3 +147,25 @@ func TestApplyAddressSpaceBytes(t *testing.T) { t.Fatalf("pair.Bytes = %d, want 0 (IO bytes must stay separate)", pair.Bytes) } } + +func TestApplyRequestedSleepNs(t *testing.T) { + pair := &event.Pair{ + EnterEv: &types.SleepEvent{ + TraceId: types.SYS_ENTER_NANOSLEEP, + RequestedNs: 7_500_000, + EventType: types.ENTER_SLEEP_EVENT, + Time: 10, + Pid: 1, + Tid: 2, + }, + ExitEv: &types.RetEvent{ + TraceId: types.SYS_EXIT_NANOSLEEP, + Ret: 0, + }, + } + + applyRequestedSleepNs(pair) + if pair.RequestedSleepNs != 7_500_000 { + t.Fatalf("pair.RequestedSleepNs = %d, want 7500000", pair.RequestedSleepNs) + } +} diff --git a/internal/eventloop_exit.go b/internal/eventloop_exit.go index 7e26cb0..7a69774 100644 --- a/internal/eventloop_exit.go +++ b/internal/eventloop_exit.go @@ -42,6 +42,8 @@ func (e *eventLoop) handleTracepointExit(ep *event.Pair) bool { return e.handlePollExit(ep, ev) case *types.MemEvent: return e.handleMemExit(ep, ev) + case *types.SleepEvent: + return e.handleSleepExit(ep, ev) case *types.NullEvent: return e.handleNullExit(ep, ev) case *types.FcntlEvent: @@ -417,6 +419,15 @@ func (e *eventLoop) handleMemExit(ep *event.Pair, memEv *types.MemEvent) bool { return true } +func (e *eventLoop) handleSleepExit(ep *event.Pair, sleepEv *types.SleepEvent) bool { + ep.Comm = e.comm(sleepEv.GetTid()) + if !e.Filter().MatchPair(ep) { + ep.Recycle() + return false + } + return true +} + func pipeDescriptorName(flags, fd0, fd1 int32) string { return fmt.Sprintf("pipe:%d:%d:%d", flags, fd0, fd1) } @@ -544,6 +555,17 @@ func applyAddressSpaceBytes(ep *event.Pair) { ep.AddressSpaceBytes = addressSpaceBytesFromMem(memEv) } +func applyRequestedSleepNs(ep *event.Pair) { + if ep == nil { + return + } + sleepEv, ok := ep.EnterEv.(*types.SleepEvent) + if !ok { + return + } + ep.RequestedSleepNs = sleepEv.RequestedNs +} + // dropMalformedRawEvent records a warning when a raw BPF event cannot be // decoded, keeping the error visible without crashing the event loop. func (e *eventLoop) dropMalformedRawEvent(evType types.EventType, raw []byte) { diff --git a/internal/eventloop_runtime.go b/internal/eventloop_runtime.go index 697de07..8ef3abf 100644 --- a/internal/eventloop_runtime.go +++ b/internal/eventloop_runtime.go @@ -248,6 +248,7 @@ func (e *eventLoop) initRawHandlers() { e.registerIPCHandlers() e.registerPollingHandlers() e.registerMemoryHandlers() + e.registerSleepHandlers() } // registerOpenHandlers wires enter/exit handlers for open-family events. @@ -460,6 +461,16 @@ func (e *eventLoop) registerMemoryHandlers() { } } +func (e *eventLoop) registerSleepHandlers() { + e.rawHandlers[types.ENTER_SLEEP_EVENT] = func(raw []byte, _ chan<- *event.Pair) { + sleepEv, ok := decodeRawEvent(e, types.ENTER_SLEEP_EVENT, raw, types.NewSleepEventFast) + if !ok { + return + } + e.tracepointEntered(sleepEv) + } +} + func decodeRawEvent[T any](e *eventLoop, eventType types.EventType, raw []byte, decode func([]byte) *T) (*T, bool) { decoded := decode(raw) if decoded == nil { @@ -514,6 +525,7 @@ func (e *eventLoop) tracepointExited(exitEv event.Event, ch chan<- *event.Pair) } applyRetBytes(ep) applyAddressSpaceBytes(ep) + applyRequestedSleepNs(ep) tid := ep.EnterEv.GetTid() ep.CalculateDurations(e.pairs.prevTime(tid)) e.pairs.setPrevTime(tid, ep.ExitEv.GetTime()) diff --git a/internal/eventloop_sleep_test.go b/internal/eventloop_sleep_test.go new file mode 100644 index 0000000..2edf276 --- /dev/null +++ b/internal/eventloop_sleep_test.go @@ -0,0 +1,76 @@ +package internal + +import ( + "testing" + + "ior/internal/event" + "ior/internal/globalfilter" + "ior/internal/types" +) + +func TestHandleSleepExitCarriesCommAndAppliesFilter(t *testing.T) { + t.Run("accepted", func(t *testing.T) { + el := mustNewEventLoop(t, eventLoopConfig{}) + enter := &types.SleepEvent{ + EventType: types.ENTER_SLEEP_EVENT, + TraceId: types.SYS_ENTER_NANOSLEEP, + Time: 100, + Pid: 10, + Tid: 11, + RequestedNs: 2_000_000, + } + exit := &types.RetEvent{ + EventType: types.EXIT_RET_EVENT, + TraceId: types.SYS_EXIT_NANOSLEEP, + Time: 120, + Ret: 0, + Pid: 10, + Tid: 11, + } + ep := &event.Pair{EnterEv: enter, ExitEv: exit} + + if ok := el.handleSleepExit(ep, enter); !ok { + t.Fatal("handleSleepExit returned false") + } + if ep.Comm != "" { + t.Fatalf("expected empty comm for unresolved tid, got %q", ep.Comm) + } + }) + + t.Run("filtered", func(t *testing.T) { + el := mustNewEventLoop(t, eventLoopConfig{ + filter: globalfilter.Filter{ + Syscall: &globalfilter.StringFilter{Pattern: "openat"}, + }, + }) + enter := &types.SleepEvent{ + EventType: types.ENTER_SLEEP_EVENT, + TraceId: types.SYS_ENTER_CLOCK_NANOSLEEP, + Time: 100, + Pid: 10, + Tid: 11, + RequestedNs: 3_000_000, + } + exit := &types.RetEvent{ + EventType: types.EXIT_RET_EVENT, + TraceId: types.SYS_EXIT_CLOCK_NANOSLEEP, + Time: 120, + Ret: 0, + Pid: 10, + Tid: 11, + } + ep := &event.Pair{EnterEv: enter, ExitEv: exit} + + if ok := el.handleSleepExit(ep, enter); ok { + t.Fatal("handleSleepExit should reject pair due to filter mismatch") + } + }) +} + +func TestInitRawHandlersRegistersSleepEvents(t *testing.T) { + el := mustNewEventLoop(t, eventLoopConfig{}) + if _, ok := el.rawHandlers[types.ENTER_SLEEP_EVENT]; !ok { + t.Fatal("ENTER_SLEEP_EVENT handler is not registered") + } +} + diff --git a/internal/generate/bpfhandler.go b/internal/generate/bpfhandler.go index 9e6f5d7..5c42464 100644 --- a/internal/generate/bpfhandler.go +++ b/internal/generate/bpfhandler.go @@ -97,6 +97,8 @@ func generateExtra(tp GeneratedTracepoint, isEnter bool) string { return generateExtraPoll(f.Name) case KindMem: return generateExtraMem(f.Name) + case KindSleep: + return generateExtraSleep(f.Name) case KindOpen: return generateExtraOpen(f) case KindPathname: @@ -243,6 +245,17 @@ func generateExtraMem(name string) string { } } +func generateExtraSleep(name string) string { + ptrExpr := "0" + switch name { + case "sys_enter_nanosleep": + ptrExpr = "ctx->args[0]" + case "sys_enter_clock_nanosleep": + ptrExpr = "ctx->args[2]" + } + return " ev->requested_ns = -1;\n if (" + ptrExpr + " != 0) {\n struct __ior_timespec {\n __s64 tv_sec;\n __s64 tv_nsec;\n } ts = {};\n if (bpf_probe_read_user(&ts, sizeof(ts), (void *)" + ptrExpr + ") == 0) {\n ev->requested_ns = ts.tv_sec * 1000000000LL + ts.tv_nsec;\n }\n }\n" +} + // eventStructName returns the C struct name for a TracepointKind. The mapping // is driven by kindRegistry so adding a new kind only requires a registry entry. func eventStructName(kind TracepointKind) string { diff --git a/internal/generate/classify.go b/internal/generate/classify.go index a2da47d..2bb2b81 100644 --- a/internal/generate/classify.go +++ b/internal/generate/classify.go @@ -23,6 +23,7 @@ const ( KindEpollCtl KindPoll KindMem + KindSleep ) type RetClassification string @@ -153,6 +154,10 @@ func classifyNameOnly(name string) (ClassificationResult, bool) { return ClassificationResult{Kind: KindMem}, true case "sys_enter_mremap": return ClassificationResult{Kind: KindMem}, true + case "sys_enter_nanosleep": + return ClassificationResult{Kind: KindSleep}, true + case "sys_enter_clock_nanosleep": + return ClassificationResult{Kind: KindSleep}, true } if strings.HasPrefix(name, "sys_enter_io_") { return ClassificationResult{Kind: KindNull}, true diff --git a/internal/generate/classify_test.go b/internal/generate/classify_test.go index 2bc0e88..daf008a 100644 --- a/internal/generate/classify_test.go +++ b/internal/generate/classify_test.go @@ -439,6 +439,20 @@ func TestClassifyMremap(t *testing.T) { } } +func TestClassifyNanosleep(t *testing.T) { + r := classifyFromData(t, FormatNanosleep) + if r.Kind != KindSleep { + t.Errorf("nanosleep: got kind %d, want KindSleep", r.Kind) + } +} + +func TestClassifyClockNanosleep(t *testing.T) { + r := classifyFromData(t, FormatClockNanosleep) + if r.Kind != KindSleep { + t.Errorf("clock_nanosleep: got kind %d, want KindSleep", r.Kind) + } +} + func TestClassifyKillRequiresGenerationFallback(t *testing.T) { r := classifyFromData(t, FormatKill) if r.Kind != KindNone { @@ -493,6 +507,8 @@ func TestClassifySyscallPairAccepted(t *testing.T) { {"pselect6", FormatPselect6, FormatExitPselect6, KindPoll}, {"munmap", FormatMunmap, FormatExitMunmap, KindMem}, {"mremap", FormatMremap, FormatExitMremap, KindMem}, + {"nanosleep", FormatNanosleep, FormatExitNanosleep, KindSleep}, + {"clock_nanosleep", FormatClockNanosleep, FormatExitClockNanosleep, KindSleep}, {"kill", FormatKill, FormatExitKill, KindNull}, } @@ -532,6 +548,8 @@ func TestClassifySyscallPairEmitsAllFamilies(t *testing.T) { {"pselect6", FormatPselect6, FormatExitPselect6, FamilyPolling}, {"munmap", FormatMunmap, FormatExitMunmap, FamilyMemory}, {"mremap", FormatMremap, FormatExitMremap, FamilyMemory}, + {"nanosleep", FormatNanosleep, FormatExitNanosleep, FamilyTime}, + {"clock_nanosleep", FormatClockNanosleep, FormatExitClockNanosleep, FamilyTime}, {"kill", FormatKill, FormatExitKill, FamilySignals}, } diff --git a/internal/generate/codegen_test.go b/internal/generate/codegen_test.go index 3ec8d72..bc4ec3a 100644 --- a/internal/generate/codegen_test.go +++ b/internal/generate/codegen_test.go @@ -310,6 +310,25 @@ func TestGeneratePselect6HandlerCapturesTimeoutPointer(t *testing.T) { requireContains(t, output, "ev->timeout_ns = ts.tv_sec * 1000000000LL + ts.tv_nsec;") } +func TestGenerateSleepHandlerCapturesRequestedTimespec(t *testing.T) { + output := generateFromPair(t, FormatNanosleep, FormatExitNanosleep) + + requireContains(t, output, "struct sleep_event *ev") + requireContains(t, output, "ev->event_type = ENTER_SLEEP_EVENT;") + requireContains(t, output, "ev->requested_ns = -1;") + requireContains(t, output, "if (ctx->args[0] != 0) {") + requireContains(t, output, "ev->requested_ns = ts.tv_sec * 1000000000LL + ts.tv_nsec;") +} + +func TestGenerateClockNanosleepHandlerCapturesRequestedTimespec(t *testing.T) { + output := generateFromPair(t, FormatClockNanosleep, FormatExitClockNanosleep) + + requireContains(t, output, "struct sleep_event *ev") + requireContains(t, output, "ev->event_type = ENTER_SLEEP_EVENT;") + requireContains(t, output, "if (ctx->args[2] != 0) {") + requireContains(t, output, "ev->requested_ns = ts.tv_sec * 1000000000LL + ts.tv_nsec;") +} + func TestGenerateNameToHandleAtHandler(t *testing.T) { output := generateFromPair(t, FormatNameToHandleAt, FormatExitNameToHandleAt) @@ -425,6 +444,7 @@ func TestGenerateAllEventTypes(t *testing.T) { {KindEpollCtl, "ENTER_EPOLL_CTL_EVENT", "EXIT_EPOLL_CTL_EVENT"}, {KindPoll, "ENTER_POLL_EVENT", "EXIT_POLL_EVENT"}, {KindMem, "ENTER_MEM_EVENT", "EXIT_MEM_EVENT"}, + {KindSleep, "ENTER_SLEEP_EVENT", "EXIT_SLEEP_EVENT"}, } for _, tt := range tests { @@ -459,6 +479,7 @@ func TestEventStructNames(t *testing.T) { {KindEpollCtl, "epoll_ctl_event"}, {KindPoll, "poll_event"}, {KindMem, "mem_event"}, + {KindSleep, "sleep_event"}, } for _, tt := range tests { @@ -477,7 +498,7 @@ func TestEnterReject(t *testing.T) { t.Error("KindNone should be enter-rejected") } - accepted := []TracepointKind{KindFd, KindOpen, KindPathname, KindName, KindFcntl, KindNull, KindDup3, KindOpenByHandleAt, KindSocket, KindSocketpair, KindAccept, KindPipe, KindEventfd, KindEpollCtl, KindPoll, KindMem} + accepted := []TracepointKind{KindFd, KindOpen, KindPathname, KindName, KindFcntl, KindNull, KindDup3, KindOpenByHandleAt, KindSocket, KindSocketpair, KindAccept, KindPipe, KindEventfd, KindEpollCtl, KindPoll, KindMem, KindSleep} for _, k := range accepted { if isEnterRejected(k) { t.Errorf("kind %d should NOT be enter-rejected", k) diff --git a/internal/generate/kindregistry.go b/internal/generate/kindregistry.go index 756ed17..96d98d8 100644 --- a/internal/generate/kindregistry.go +++ b/internal/generate/kindregistry.go @@ -33,6 +33,7 @@ var kindRegistry = map[TracepointKind]kindMeta{ KindEpollCtl: {structName: "epoll_ctl_event", enterAccepted: true}, KindPoll: {structName: "poll_event", enterAccepted: true}, KindMem: {structName: "mem_event", enterAccepted: true}, + KindSleep: {structName: "sleep_event", enterAccepted: true}, // KindNone is intentionally absent: it represents "unclassified" and is // never enter-accepted. lookupKind returns the zero kindMeta (enterAccepted=false) // for any unregistered kind, so KindNone is implicitly rejected. diff --git a/internal/generate/testdata.go b/internal/generate/testdata.go index 6b08f98..d88a1b9 100644 --- a/internal/generate/testdata.go +++ b/internal/generate/testdata.go @@ -1358,3 +1358,55 @@ format: field:int __syscall_nr; offset:8; size:4; signed:1; field:long ret; offset:16; size:8; signed:1; ` + +const FormatNanosleep = `name: sys_enter_nanosleep +ID: 441 +format: + field:unsigned short common_type; offset:0; size:2; signed:0; + field:unsigned char common_flags; offset:2; size:1; signed:0; + field:unsigned char common_preempt_count; offset:3; size:1; signed:0; + field:int common_pid; offset:4; size:4; signed:1; + + field:int __syscall_nr; offset:8; size:4; signed:1; + field:struct __kernel_timespec * rqtp; offset:16; size:8; signed:0; + field:struct __kernel_timespec * rmtp; offset:24; size:8; signed:0; +` + +const FormatExitNanosleep = `name: sys_exit_nanosleep +ID: 440 +format: + field:unsigned short common_type; offset:0; size:2; signed:0; + field:unsigned char common_flags; offset:2; size:1; signed:0; + field:unsigned char common_preempt_count; offset:3; size:1; signed:0; + field:int common_pid; offset:4; size:4; signed:1; + + field:int __syscall_nr; offset:8; size:4; signed:1; + field:long ret; offset:16; size:8; signed:1; +` + +const FormatClockNanosleep = `name: sys_enter_clock_nanosleep +ID: 447 +format: + field:unsigned short common_type; offset:0; size:2; signed:0; + field:unsigned char common_flags; offset:2; size:1; signed:0; + field:unsigned char common_preempt_count; offset:3; size:1; signed:0; + field:int common_pid; offset:4; size:4; signed:1; + + field:int __syscall_nr; offset:8; size:4; signed:1; + field:clockid_t which_clock; offset:16; size:8; signed:0; + field:int flags; offset:24; size:8; signed:0; + field:const struct __kernel_timespec * rqtp; offset:32; size:8; signed:0; + field:struct __kernel_timespec * rmtp; offset:40; size:8; signed:0; +` + +const FormatExitClockNanosleep = `name: sys_exit_clock_nanosleep +ID: 446 +format: + field:unsigned short common_type; offset:0; size:2; signed:0; + field:unsigned char common_flags; offset:2; size:1; signed:0; + field:unsigned char common_preempt_count; offset:3; size:1; signed:0; + field:int common_pid; offset:4; size:4; signed:1; + + field:int __syscall_nr; offset:8; size:4; signed:1; + field:long ret; offset:16; size:8; signed:1; +` diff --git a/internal/parquet/schema.go b/internal/parquet/schema.go index 87d4e2f..f39361c 100644 --- a/internal/parquet/schema.go +++ b/internal/parquet/schema.go @@ -26,6 +26,7 @@ type Record struct { Ret int64 `parquet:"ret"` Bytes uint64 `parquet:"bytes"` AddressSpaceBytes uint64 `parquet:"address_space_bytes"` + RequestedSleepNS int64 `parquet:"requested_sleep_ns"` File string `parquet:"file"` IsError bool `parquet:"is_error"` FilterEpoch uint64 `parquet:"filter_epoch"` @@ -69,6 +70,7 @@ func RecordFromStream(row streamrow.Row, filterEpoch uint64) Record { Ret: row.RetVal, Bytes: row.Bytes, AddressSpaceBytes: row.AddressSpaceBytes, + RequestedSleepNS: row.RequestedSleepNs, File: row.FileName, IsError: row.IsError, FilterEpoch: filterEpoch, diff --git a/internal/streamrow/row.go b/internal/streamrow/row.go index 7497583..a6ccdf7 100644 --- a/internal/streamrow/row.go +++ b/internal/streamrow/row.go @@ -25,9 +25,11 @@ type Row struct { Bytes uint64 // AddressSpaceBytes tracks memory-region extent for memory-management syscalls. AddressSpaceBytes uint64 - RetVal int64 - IsError bool - FD int32 + // RequestedSleepNs stores requested sleep duration metadata for sleep syscalls. + RequestedSleepNs int64 + RetVal int64 + IsError bool + FD int32 } func (r Row) SyscallValue() string { @@ -113,6 +115,7 @@ func New(seq uint64, pair *event.Pair) Row { GapNs: pair.DurationToPrev, Bytes: pair.Bytes, AddressSpaceBytes: pair.AddressSpaceBytes, + RequestedSleepNs: pair.RequestedSleepNs, FD: UnknownFD, } if fd, ok := pair.FileDescriptor(); ok { diff --git a/internal/streamrow/row_test.go b/internal/streamrow/row_test.go index 7573f43..9757722 100644 --- a/internal/streamrow/row_test.go +++ b/internal/streamrow/row_test.go @@ -62,6 +62,7 @@ func TestNewPopulatesFieldsFromPair(t *testing.T) { pair.DurationToPrev = 19 pair.Bytes = 512 pair.AddressSpaceBytes = 2048 + pair.RequestedSleepNs = 987_654 got := New(9, pair) if got.Seq != 9 || got.TimeNs != 1234 { @@ -82,6 +83,9 @@ func TestNewPopulatesFieldsFromPair(t *testing.T) { if got.AddressSpaceBytes != 2048 { t.Fatalf("AddressSpaceBytes = %d, want 2048", got.AddressSpaceBytes) } + if got.RequestedSleepNs != 987_654 { + t.Fatalf("RequestedSleepNs = %d, want 987654", got.RequestedSleepNs) + } if got.RetVal != -2 || !got.IsError { t.Fatalf("RetVal/IsError = %d/%v, want -2/true", got.RetVal, got.IsError) } @@ -140,6 +144,25 @@ func TestNewCarriesReadyCountForPoll(t *testing.T) { } } +func TestNewCarriesRequestedSleepNs(t *testing.T) { + enter := &types.SleepEvent{TraceId: types.SYS_ENTER_NANOSLEEP, Time: 3200, Pid: 31, Tid: 32, RequestedNs: 5_000_000} + exit := &types.RetEvent{TraceId: types.SYS_EXIT_NANOSLEEP, Time: 3300, Ret: 0, Pid: 31, Tid: 32} + pair := event.NewPair(enter) + pair.ExitEv = exit + pair.RequestedSleepNs = enter.RequestedNs + + got := New(25, pair) + if got.Syscall != "nanosleep" || got.FD != UnknownFD { + t.Fatalf("Syscall/FD = %q/%d, want nanosleep/%d", got.Syscall, got.FD, UnknownFD) + } + if got.RequestedSleepNs != 5_000_000 { + t.Fatalf("RequestedSleepNs = %d, want 5000000", got.RequestedSleepNs) + } + if got.Bytes != 0 { + t.Fatalf("Bytes = %d, want 0 for sleep events", got.Bytes) + } +} + // TestRowValueAccessors verifies that all typed accessor methods return the // underlying field values set on a Row. func TestRowValueAccessors(t *testing.T) { diff --git a/internal/tui/eventstream/export.go b/internal/tui/eventstream/export.go index 73bc1fa..8a28d85 100644 --- a/internal/tui/eventstream/export.go +++ b/internal/tui/eventstream/export.go @@ -182,7 +182,7 @@ func exportRowsToCSV(rows []StreamEvent, exportDir, filename string) (string, er // writeStreamCSV writes the CSV header and all event rows to w, calling fail // on the first write error to close the underlying file before returning. func writeStreamCSV(w *csv.Writer, rows []StreamEvent, fail func(error) (string, error)) error { - header := []string{"seq", "time_ns", "gap_ns", "latency_ns", "comm", "pid", "tid", "syscall", "fd", "ret", "bytes", "file", "error", "family"} + header := []string{"seq", "time_ns", "gap_ns", "latency_ns", "comm", "pid", "tid", "syscall", "fd", "ret", "bytes", "file", "error", "family", "requested_sleep_ns"} if err := w.Write(header); err != nil { _, err = fail(err) return err @@ -204,6 +204,7 @@ func writeStreamCSV(w *csv.Writer, rows []StreamEvent, fail func(error) (string, ev.FileName, fmt.Sprintf("%t", ev.IsError), ev.Family, + fmt.Sprintf("%d", ev.RequestedSleepNs), } if err := w.Write(record); err != nil { _, err = fail(err) diff --git a/internal/tui/eventstream/export_test.go b/internal/tui/eventstream/export_test.go index 6cea2b1..68fae70 100644 --- a/internal/tui/eventstream/export_test.go +++ b/internal/tui/eventstream/export_test.go @@ -201,20 +201,21 @@ func TestExportRowsToCSVPathTraversal(t *testing.T) { func TestWriteStreamCSVAppendsFamilyColumn(t *testing.T) { var buf bytes.Buffer rows := []StreamEvent{{ - Seq: 7, - TimeNs: 100, - GapNs: 3, - DurationNs: 5, - Comm: "worker", - PID: 10, - TID: 11, - Syscall: "socketpair", - FD: 4, - RetVal: 0, - Bytes: 0, - FileName: "/tmp/sock", - IsError: false, - Family: "Network", + Seq: 7, + TimeNs: 100, + GapNs: 3, + DurationNs: 5, + Comm: "worker", + PID: 10, + TID: 11, + Syscall: "socketpair", + FD: 4, + RetVal: 0, + Bytes: 0, + FileName: "/tmp/sock", + IsError: false, + Family: "Network", + RequestedSleepNs: 0, }} fail := func(err error) (string, error) { return "", err } @@ -226,11 +227,11 @@ func TestWriteStreamCSVAppendsFamilyColumn(t *testing.T) { if err != nil { t.Fatalf("read CSV: %v", err) } - wantHeader := []string{"seq", "time_ns", "gap_ns", "latency_ns", "comm", "pid", "tid", "syscall", "fd", "ret", "bytes", "file", "error", "family"} + wantHeader := []string{"seq", "time_ns", "gap_ns", "latency_ns", "comm", "pid", "tid", "syscall", "fd", "ret", "bytes", "file", "error", "family", "requested_sleep_ns"} if !reflect.DeepEqual(records[0], wantHeader) { t.Fatalf("header = %#v, want %#v", records[0], wantHeader) } - if records[1][8] != "4" || records[1][12] != "false" || records[1][13] != "Network" { + if records[1][8] != "4" || records[1][12] != "false" || records[1][13] != "Network" || records[1][14] != "0" { t.Fatalf("family should be appended without shifting legacy columns, got %#v", records[1]) } } diff --git a/internal/types/fastdecode.go b/internal/types/fastdecode.go index 1f89ee4..6e35093 100644 --- a/internal/types/fastdecode.go +++ b/internal/types/fastdecode.go @@ -25,6 +25,7 @@ const ( pollEventSize = 40 pollEventSizeV1 = 36 memEventSize = 56 + sleepEventSize = 32 ) func NewOpenEventFast(raw []byte) *OpenEvent { @@ -360,3 +361,20 @@ func NewMemEventFast(raw []byte) *MemEvent { m.Flags = binary.LittleEndian.Uint64(raw[48:56]) return m } + +func NewSleepEventFast(raw []byte) *SleepEvent { + if len(raw) < sleepEventSize { + return nil + } + if len(raw) != sleepEventSize { + return NewSleepEvent(raw) + } + s := poolOfSleepEvents.Get().(*SleepEvent) + s.EventType = EventType(binary.LittleEndian.Uint32(raw[0:4])) + s.TraceId = TraceId(binary.LittleEndian.Uint32(raw[4:8])) + s.Time = binary.LittleEndian.Uint64(raw[8:16]) + s.Pid = binary.LittleEndian.Uint32(raw[16:20]) + s.Tid = binary.LittleEndian.Uint32(raw[20:24]) + s.RequestedNs = int64(binary.LittleEndian.Uint64(raw[24:32])) + return s +} diff --git a/internal/types/fastdecode_test.go b/internal/types/fastdecode_test.go index 8bb4b34..f17c7a9 100644 --- a/internal/types/fastdecode_test.go +++ b/internal/types/fastdecode_test.go @@ -241,6 +241,26 @@ func TestFastDecodersMatchGeneratedDecoders(t *testing.T) { t.Fatalf("mem decode mismatch") } }) + + t.Run("SleepEvent", func(t *testing.T) { + ev := &SleepEvent{ + EventType: ENTER_SLEEP_EVENT, + TraceId: SYS_ENTER_NANOSLEEP, + Time: 1, + Pid: 2, + Tid: 3, + RequestedNs: 9_000_000, + } + raw, _ := ev.Bytes() + + slow := NewSleepEvent(raw) + fast := NewSleepEventFast(raw) + defer slow.Recycle() + defer fast.Recycle() + if !slow.Equals(fast) { + t.Fatalf("sleep decode mismatch") + } + }) } func TestNewSocketpairEventFastKernelLayout(t *testing.T) { @@ -390,6 +410,31 @@ func TestNewPollEventFastKernelLayout(t *testing.T) { } } +func TestNewSleepEventFastKernelLayout(t *testing.T) { + raw := make([]byte, sleepEventSize) + binary.LittleEndian.PutUint32(raw[0:4], uint32(ENTER_SLEEP_EVENT)) + binary.LittleEndian.PutUint32(raw[4:8], uint32(SYS_ENTER_CLOCK_NANOSLEEP)) + binary.LittleEndian.PutUint64(raw[8:16], 1) + binary.LittleEndian.PutUint32(raw[16:20], 2) + binary.LittleEndian.PutUint32(raw[20:24], 3) + binary.LittleEndian.PutUint64(raw[24:32], uint64(125_000_000)) + + fast := NewSleepEventFast(raw) + if fast == nil { + t.Fatalf("expected decoded sleep event for kernel layout payload") + } + defer fast.Recycle() + + if fast.EventType != ENTER_SLEEP_EVENT || + fast.TraceId != SYS_ENTER_CLOCK_NANOSLEEP || + fast.Time != 1 || + fast.Pid != 2 || + fast.Tid != 3 || + fast.RequestedNs != 125_000_000 { + t.Fatalf("unexpected sleep decode: %#v", fast) + } +} + func TestFastDecodersReturnNilOnShortPayload(t *testing.T) { cases := []struct { name string @@ -411,6 +456,7 @@ func TestFastDecodersReturnNilOnShortPayload(t *testing.T) { {name: "EventfdEvent", decode: func(raw []byte) bool { return NewEventfdEventFast(raw) == nil }}, {name: "EpollCtlEvent", decode: func(raw []byte) bool { return NewEpollCtlEventFast(raw) == nil }}, {name: "PollEvent", decode: func(raw []byte) bool { return NewPollEventFast(raw) == nil }}, + {name: "SleepEvent", decode: func(raw []byte) bool { return NewSleepEventFast(raw) == nil }}, } for _, tc := range cases { diff --git a/internal/types/generated_types.go b/internal/types/generated_types.go index 63cb28c..bd5518a 100644 --- a/internal/types/generated_types.go +++ b/internal/types/generated_types.go @@ -102,6 +102,8 @@ const ENTER_POLL_EVENT = 31 const EXIT_POLL_EVENT = 32 const ENTER_MEM_EVENT = 33 const EXIT_MEM_EVENT = 34 +const ENTER_SLEEP_EVENT = 35 +const EXIT_SLEEP_EVENT = 36 const UNCLASSIFIED = 0 const READ_CLASSIFIED = 1 const WRITE_CLASSIFIED = 2 @@ -2021,3 +2023,71 @@ func (m *MemEvent) Bytes() ([]byte, error) { func (m *MemEvent) Recycle() { poolOfMemEvents.Put(m) } + +type SleepEvent struct { + EventType EventType + TraceId TraceId + Time uint64 + Pid uint32 + Tid uint32 + RequestedNs int64 +} + +func (s SleepEvent) String() string { + return fmt.Sprintf("EventType:%v TraceId:%v Time:%v Pid:%v Tid:%v RequestedNs:%v", s.EventType, s.TraceId, s.Time, s.Pid, s.Tid, s.RequestedNs) +} + +func (s SleepEvent) Equals(other any) bool { + otherConcrete, ok := other.(*SleepEvent) + if !ok { + return false + } + return s.EventType == otherConcrete.EventType && s.TraceId == otherConcrete.TraceId && s.Time == otherConcrete.Time && s.Pid == otherConcrete.Pid && s.Tid == otherConcrete.Tid && s.RequestedNs == otherConcrete.RequestedNs +} + +func (s *SleepEvent) GetEventType() EventType { + return s.EventType +} + +func (s *SleepEvent) GetTraceId() TraceId { + return s.TraceId +} + +func (s *SleepEvent) GetPid() uint32 { + return s.Pid +} + +func (s *SleepEvent) GetTid() uint32 { + return s.Tid +} + +func (s *SleepEvent) GetTime() uint64 { + return s.Time +} + +var poolOfSleepEvents = sync.Pool{ + New: func() any { return &SleepEvent{} }, +} + +func NewSleepEvent(raw []byte) *SleepEvent { + s := poolOfSleepEvents.Get().(*SleepEvent) + if err := binary.Read(bytes.NewReader(raw), binary.LittleEndian, s); err != nil { + *s = SleepEvent{} + poolOfSleepEvents.Put(s) + return nil + } + return s +} + +func (s *SleepEvent) Bytes() ([]byte, error) { + buf := new(bytes.Buffer) + err := binary.Write(buf, binary.LittleEndian, s) + if err != nil { + return nil, err + } + return buf.Bytes(), nil +} + +func (s *SleepEvent) Recycle() { + poolOfSleepEvents.Put(s) +} diff --git a/internal/types/types_test.go b/internal/types/types_test.go index 0134ea0..df321ac 100644 --- a/internal/types/types_test.go +++ b/internal/types/types_test.go @@ -323,6 +323,29 @@ func TestPollEventSerialization(t *testing.T) { assertEquals(t, pollEv1.TimeoutNs, pollEv2.TimeoutNs) } +func TestSleepEventSerialization(t *testing.T) { + sleepEv1 := SleepEvent{ + EventType: ENTER_SLEEP_EVENT, + TraceId: SYS_ENTER_CLOCK_NANOSLEEP, + Time: 7901, + Pid: 44, + Tid: 45, + RequestedNs: 150_000_000, + } + bytes, err := sleepEv1.Bytes() + if err != nil { + t.Error(err) + } + sleepEv2 := NewSleepEvent(bytes) + + assertEquals(t, sleepEv1.EventType, sleepEv2.EventType) + assertEquals(t, sleepEv1.TraceId, sleepEv2.TraceId) + assertEquals(t, sleepEv1.Time, sleepEv2.Time) + assertEquals(t, sleepEv1.Pid, sleepEv2.Pid) + assertEquals(t, sleepEv1.Tid, sleepEv2.Tid) + assertEquals(t, sleepEv1.RequestedNs, sleepEv2.RequestedNs) +} + func TestEqualsDifferentTypes(t *testing.T) { openEv := OpenEvent{EventType: ENTER_OPEN_EVENT, TraceId: SYS_ENTER_OPENAT, Time: 1, Pid: 1, Tid: 1} nullEv := NullEvent{EventType: ENTER_NULL_EVENT, TraceId: SYS_ENTER_SYNC, Time: 1, Pid: 1, Tid: 1} |
