iovisor / iovisor/bcc

offcputime/offwake time won't produce stack traces

Open
#4,230 0 comments 0 reactions 0 assignees View on GitHub
Dominant language
C
Stars
22.7k
Forks
4.1k
Avg merge
5d 13h
Merged PRs (30d)
3

Description

Running either offcputime.py or offwaketime.py I get nothing produced. Debugging showed that this is due to the fact that `u32 pid = p->pid`; returns -1 and as a result the following branch is executed:

```
// record previous thread sleep time
if ((THREAD_FILTER) && (STATE_FILTER)) {
bpf_trace_printk("adding %d\\n", pid);
ts = bpf_ktime_get_ns();
start.update(&pid, &ts);
}
```
I'm running upstream 5.19.8 kernel compiled using ubuntu's 22.04's default config, bcc tools have also been compiled from source and the head commit is: c30c4181f800

The following fixes the issue but essentially breaks filtering on the tgid. To me this suggests this is an issue with the way the kprobe is acquiring the argument pointer and doing the followup dereference:

```
# git diff tools/offcputime.py
diff --git a/tools/offcputime.py b/tools/offcputime.py
index 588db942f856..7b15fa00ef81 100755
--- a/tools/offcputime.py
+++ b/tools/offcputime.py
@@ -134,13 +134,16 @@ struct warn_event_t {
};
BPF_PERF_OUTPUT(warn_events);

-int oncpu(struct pt_regs *ctx, struct task_struct *prev) {
- u32 pid = prev->pid;
- u32 tgid = prev->tgid;
+//int oncpu(struct pt_regs *ctx, struct task_struct *prev) {
+TRACEPOINT_PROBE(sched, sched_switch)
+{
+ u32 pid = args->prev_pid;
+ u32 tgid = -1;
u64 ts, *tsp;

// record previous thread sleep time
if ((THREAD_FILTER) && (STATE_FILTER)) {
+bpf_trace_printk("adding %d\\n", pid);
ts = bpf_ktime_get_ns();
start.update(&pid, &ts);
}
@@ -164,7 +167,7 @@ int oncpu(struct pt_regs *ctx, struct task_struct *prev) {
.t_start = t_start,
.t_end = t_end,
};
- warn_events.perf_submit(ctx, &event, sizeof(event));
+ warn_events.perf_submit(args, &event, sizeof(event));
return 0;
}
u64 delta = t_end - t_start;
@@ -224,8 +227,8 @@ bpf_text = bpf_text.replace('MINBLOCK_US_VALUE', str(args.min_block_time))
bpf_text = bpf_text.replace('MAXBLOCK_US_VALUE', str(args.max_block_time))

# handle stack args
-kernel_stack_get = "stack_traces.get_stackid(ctx, 0)"
-user_stack_get = "stack_traces.get_stackid(ctx, BPF_F_USER_STACK)"
+kernel_stack_get = "stack_traces.get_stackid(args, 0)"
+user_stack_get = "stack_traces.get_stackid(args, BPF_F_USER_STACK)"
stack_context = ""
if args.user_stacks_only:
stack_context = "user"
@@ -256,12 +259,12 @@ need_delimiter = args.delimited and not (args.kernel_stacks_only or

# initialize BPF
b = BPF(text=bpf_text)
-b.attach_kprobe(event_re="^finish_task_switch$|^finish_task_switch\.isra\.\d$",
- fn_name="oncpu")
-matched = b.num_open_kprobes()
-if matched == 0:
- print("error: 0 functions traced. Exiting.", file=stderr)
- exit(4)
+#b.attach_kprobe(event_re="^finish_task_switch$|^finish_task_switch\.isra\.\d$",
+# fn_name="oncpu")
+#matched = b.num_open_kprobes()
+#if matched == 0:
+# print("error: 0 functions traced. Exiting.", file=stderr)
+# exit(4)

# header
if not folded:
```

Contributor guide

No contributing guide indexed for this repository

Research direction

Start with tools/offcputime.py and the corresponding offwaketime.py logic, focusing on the finish_task_switch kprobe argument handling and the sched_switch tracepoint alternative shown in the report. Run both tools on the reported kernel configuration and verify that stack traces are produced while thread and tgid filtering still behaves correctly.

Written by the indexing model from the issue text.

Assessment

Tech stack
linux, python
Domain
observability-sre, operating-systems
Issue type
Bug
Difficulty
4/5
Estimated time
3-5 days
Activity status
Stale
Clarity
Mostly clear
Newbie friendliness
35/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.