Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Off CPU profiling #196

Open
wants to merge 8 commits into
base: main
Choose a base branch
from
Open

Off CPU profiling #196

wants to merge 8 commits into from

Conversation

florianl
Copy link
Contributor

@florianl florianl commented Oct 20, 2024

This is the code that backs
#144. It can be reused to add features like requested in #33 and therefore can be an alternative to
#192.

The idea that enables off CPU profiling is, that perf event and kprobe eBPF programs are quite similar and can be converted. This allows, with the dynamic rewrite of tail call maps, the reuse of existing eBPF programs and concepts.

This proposal adds the new flag '-off-cpu-threshold' that enables off CPU profiling and attaches the two additional hooks, as discussed in Option B in #144.

@@ -4,14 +4,6 @@
#include "tracemgmt.h"
#include "stackdeltatypes.h"

#ifndef __USER32_CS
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This got moved to tracemgmt.h to make it available to other entry points.

@@ -602,151 +594,6 @@ static ErrorCode unwind_one_frame(u64 pid, u32 frame_idx, struct UnwindState *st
#error unsupported architecture
#endif

// Initialize state from pt_regs
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This got moved to tracemgmt.h to make it available to other entry points.

#endif // TESTING_COREDUMP

static inline
int collect_trace(struct pt_regs *ctx, TraceOrigin origin, u32 pid, u32 tid, u64 off_cpu_time) {
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

With moving collect_trace() to tracemgmt.h its arguments changed. origin was added to further keep track what triggered the stack unwinding. pid and tid also got added as argument, as the entry point for off CPU profiling does some filtering on these parameters, so it didn't make sense to call the helper for this information multiple times. And finally off_cpu_time got added as argument, to forward the information for how long a trace was off CPU and store the information in the Trace struct.

func initializeMapsAndPrograms(includeTracers types.IncludedTracers,
kernelSymbols *libpf.SymbolMap, filterErrorFrames bool, mapScaleFactor int,
kernelVersionCheck bool, debugTracer bool, bpfVerifierLogLevel uint32) (
func initializeMapsAndPrograms(kernelSymbols *libpf.SymbolMap, cfg *Config) (
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

With adding an additional argument from *Config to initializeMapsAndPrograms() it made sense to just pass *Config rather than every single argument by itself.

tracer/tracer.go Outdated Show resolved Hide resolved
Copy link
Contributor

@umanwizard umanwizard left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'll give my thought despite not being a maintainer.

Comment on lines +39 to +41
if (bpf_get_prandom_u32()%OFF_CPU_THRESHOLD_MAX > syscfg->off_cpu_threshold) {
return 0;
}
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm not sure the numbers will be statistically valid given this check. Shouldn't the probability of sampling be based on the amount of time spent? (Similar to how e.g. the probability of heap allocation samplers recording a stack is determined by the amount of bytes allocated).

Imagine if the off-CPU time of some process is dominated by one call to read that hangs forever (e.g. due to networking misconfiguration). Unless you get lucky enough that you hit this threshold on that call, you will not see it reflected in the profile.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Imagine if the off-CPU time of some process is dominated by one call to read that hangs forever (e.g. due to networking misconfiguration). Unless you get lucky enough that you hit this threshold on that call, you will not see it reflected in the profile.

I think you describe a good example of the general risk of a sampling approach. In #144 a sampling approach is proposed, as handling every scheduling event in both hooks is a too high risk to overload the system. If the sampling should be done on the off-CPU time, then there is also a management overhead to correctly size the eBPF map that communicates the start of the off-CPU time to the end of the off-CPU time. So yes, using a sampling approach to drop some events in the first hook will miss out on some events.
But similar to regular sampling based on-CPU profiling, if something is misconfigured, then there will be not a single event but multiple ones and so the issue will be visible to the profiler. The same applies to off-CPU profiling, I think. Overall, sampling based profiling provides valuable insights into the hot paths of the system for (expected or unexpected) things that happen often. Sampling is not an approach that catches every event, otherwise it would qualify as debugging or security utility - but sampling does not satisfy this requirements.

Copy link
Contributor

@umanwizard umanwizard Oct 24, 2024

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I completely agree that the feature must use sampling. However the strategy used for sampling makes a difference.

E.g., see here where a similar analysis was done for jemalloc: https://github.com/jemalloc/jemalloc/blob/2a693b83d2d1631b6a856d178125e1c47c12add9/doc_internal/PROFILING_INTERNALS.md#L4

The authors concluded that they needed to sample per-byte, rather than per-allocation, because sampling per-allocation increases the variance significantly in a scenario where the allocations can have significantly different sizes.

The corresponding approach here would be to sample per-nanosecond, rather than per-event.

The downside is then you would have to call bpf_ktime_get_ns on the begin and end unconditionally (to know how long the task was parked for and then do your sampling logic), whereas now we skip calling bpf_ktime_get_ns when the sampling doesn't hit. I'm not sure what the overhead of that would be.

I will try to put together a test based on your code to see how much this affects profiling variance in the real world.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks for the link to the research that got into the sampling strategy for jemalloc.

From my perspective, there are major differences in the purpose of sampling off CPU profiling vs jemalloc that lead to the differences in the sampling strategies.
jemalloc considers small allocations as “cheaper” whereas larger allocations result in more effort. For off CPU profiling the effort to take computing resources from a task and later reassign computing resources are always the same and the time a task is off CPU does not make a difference. So the sampling strategy of jemalloc takes the effort into account while for off CPU profiling the effort is constant.

The general event based sampling approach also comes with the advantage that it lets users predict the direct storage impact that off CPU profiling will have. The storage requirements are linearly correlated to configuration of the CLI flag -off-cpu-threshold. Changing the sampling strategy will make the storage predictions more complex and harder.

We can also not make assumptions about the environment, where off CPU profiling will be used. Will the environment be dominated by short interrupts, with small off CPU times for tasks, or will there be more larger off CPU times, e.g. if spinning disks are used instead of other faster memory solutions. The general event based sampling approach does not make a difference between these two kinds.

Switching to sampling on the off CPU time will also introduce a management overhead. First eBPF maps need to be scaled larger, resulting in a larger memory requirement for the eBPF Profiling agent and secondly there will be more computing overhead. To make a fair sampling decision on the off CPU time we need to make sure, that every tasked that is handled by the scheduler fits into the eBPF maps. The additional computing overhead will be on calling bpf_ktime_get_ns twice to get the off CPU time for each task before making a sampling decision on it, and more eBPF map updates and lookups to forward the off CPU time information from the first to the second hook.

With #144 a general sampling approach was accepted, which is implemented in this current state of code proposal.
Maybe @open-telemetry/profiling-maintainers can provide their views on the different kinds of sampling strategies and provide guidance moving on on this topic.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks for the detailed response. Your points about the differences in constraints between jemalloc and opentelemetry-ebpf-profiler are compelling.

I still think in the future it is worth testing with different sampling strategies to see how much it affects variance in common scenarios and then making a call whether that's worth the downsides (e.g. less predictable storage usage).

But you've convinced me that this is a good enough default that it's worth starting with this.

Copy link
Member

@christos68k christos68k Oct 31, 2024

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@umanwizard You bring up a valid point, in some tests I did for an unrelated project, calling bpf_ktime_get_ns too much can add up to significant overhead but that was at frequencies far higher than 500-1000Hz which I would assume is the worst-case of what we'd be dealing with here. It also seems simple enough implementation-wise to experiment with and compare. If that's something you'd still like to pursue, I would definitely be interested in the output.

Copy link
Member

@felixge felixge Nov 1, 2024

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

jemalloc considers small allocations as “cheaper” whereas larger allocations result in more effort.

I'll admit that I need to find some more time to fully digest the highly interesting jemalloc doc. But my initial impression is that this aspect was not the deciding factor for their choice of sampling strategy and more of a "nice to have". I could be wrong tho.

The storage requirements are linearly correlated to configuration of the CLI flag -off-cpu-threshold. Changing the sampling strategy will make the storage predictions more complex and harder.

Will it? Assuming we want to sample from N events that are produced of some time period t, a Bernoulli strategy using a time rate R will produce data at a rate of t/R (independent of N)

A strategy that relies on sampling 1 event for every R events will produce data at a rate of N/R (independent of t).

In both cases the choice of R allows linear control over the data rate, but the second strategy requires the user to know N in order to pick an initial rate R and predict the data volume it will produce. But N might change over time, so this strategy doesn't really allow a predictable data rate from a user perspective as far as I can tell.

Sorry I was interrupted by having to drop my daughter off to daycare, so I submitted this too hastily this morning. The analysis above only works when there is a only a single thread involved. For multiple threads the data rate for the Bernoulli strategy increases with the number of threads. I think this could be handled by dividing the event durations by the number of threads, but I need to think about this a bit more. But my point about the unpredictable data volumes for the strategy in this PR remains valid I think.

With #144 a general sampling approach was accepted, which is implemented in this current state of code proposal.

I think the merging of that PR signaled high-level consensus on implementing Off-CPU, but not necessary any consensus on the sampling strategy. I explicitly called that out in my comment here.

Switching to sampling on the off CPU time will also introduce a management overhead.

I don't have immediate comments on this. It definitely needs to be considered. But I think there is also some value in thinking about the strategy we would like if implementation issues were not prohibitive.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I thought I replied to this thread at the beginning of the week. But it looks like I didn’t. So, sorry for the late reply.

With #144 a general sampling approach was accepted, which is implemented in this current state of code proposal.

I think the merging of that PR signaled high-level consensus on implementing Off-CPU, but not necessary any consensus on the sampling strategy. I explicitly called that out in my comment here.

You are right, #144 did not focus on a sampling strategy. My motivation of #144 was to introduce the general idea of off-CPU profiling and keeping its overhead minimal, so that there is no performance impact.

I think there is a major difference between the sampling strategies, per-allocation and per-byte, as used for jemalloc and the strategies, event based and off-CPU-time based, discussed here for off-CPU profiling.
The sampling strategy for jemalloc comes with the major advantage that at the time of decision the number of requested bytes are known. So there is no management overhead in changing the sampling strategy.
Whereas for off-CPU profiling, the time a task will be off-CPU is not known at the point when a scheduler decides to take computing resources from a task. To guarantee a fair sampling strategy based on off-CPU-time, it needs to be guaranteed that all tasks are tracked. Which will result in significantly more eBPF map updates/lookups but also the eBPF maps need to be scaled (significantly larger and) correctly. Besides this, there will also be some additional overhead in calling helpers like bpf_ktime_get_ns more often than required.

[..] But my point about the unpredictable data volumes for the strategy in this PR remains valid I think.

Can you elaborate a bit more on this? With the suggested event based sampling strategy, the storage requirement should be linear in-/decreasing depending on the following major components

  • Number of CPU cores
  • CPU frequency
  • off-CPU threshold

As the number of CPU cores should be known, as well their CPU frequency, the required storage is depending directly on the configured off-CPU threshold and will increase and decrease accordingly. Of course, this is a simplified view as environments change, CPU cores use a dynamic frequency and power management can take down CPU cores. But these environmental beneficial features should only reduce the required storage and the configuration with the most impact should be the configured off-CPU threshold.

tracer/tracer.go Outdated
Comment on lines 678 to 694
// All the tail call targets are perf event programs. To be able to tail call them
// from a kprobe, adjust their specification.
if !unwindProg.noTailCallTarget {
// Adjust program type
progSpec.Type = cebpf.Kprobe

// Adjust program name for easier debugging
progSpec.Name = "kp_" + progSpec.Name
}
if err := tailcallMap.Update(unsafe.Pointer(&unwindProg.progID), unsafe.Pointer(&fd),
cebpf.UpdateAny); err != nil {
// Every eBPF program that is loaded within loadUnwinders can be the
// destination of a tail call of another eBPF program. If we can not update
// the eBPF map that manages these destinations our unwinding will fail.
return fmt.Errorf("failed to update tailcall map: %v", err)
if err := loadProgram(ebpfProgs, tailcallMap, unwindProg.progID, progSpec,
programOptions, unwindProg.noTailCallTarget); err != nil {
return err
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

While this is clever, and avoids some function declarations. I think this might have some maintenance overhead. Especially if anything in the ebpf binary becomes more function type specific. And this also prevents to have differing probe context usage for perf_event vs. kprobe. Perhaps in future we would like the perf_event probe to also record perf event specific data from the context?

I would prefer a solution to do this in the eBPF C code instead. Just separate is tracepoint to main function that gets called from each ebpf helper entry point separately. This would be future proof without maintenance fear. Even if it likely doubles the eBPF ELF binary size.

Copy link
Contributor Author

@florianl florianl Nov 1, 2024

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

For the moment, I will keep the proposed solution. Currently there is a high demand to also check in the debug eBPF blobs - which would add binary blobs of 1.4M (amd64) + 1.4M (arm64) to the respository.

With a macro like the following it is possible to generate perf event and kprobe programs from the same source, avoiding code duplication:

#define MULTI_USE_FUNC(func_name) \
    SEC("perf_event/"#func_name) \
    int func_name##_perf(struct pt_regs *ctx) { \
        return func_name(ctx); \
    } \
    \
    SEC("kprobe/"#func_name) \
    int func_name##_kprobe(struct pt_regs *ctx) { \
        return func_name(ctx); \
    }

If it is decided to also check in debug eBPF blobs, then the checked in binary blobs will be the sum of 1.4M (amd64/perf events) + 1.4M (arm64/perf events) + 1.4M (amd64/kprobe) + 1.4M (arm64/kprobe) just for the debug binary eBPF blobs.
Without the discussion around also keeping the debug binary eBPF blobs checked into the repository, switching to the marco for code generation sounds like a viable option. But with this discussion, I would like to defer this implementation detail for a moment and wait for the discussion result.

While using a macro to generate these two different kinds of eBPF programs from the same code is possible and avoid relabeling the eBPF programs, the more significant part is updating the tail call. I didn't find a way to rewrite the tail call maps when generating code with the above marco. So dynamic rewriting of the tail call map would stay anyway.

Independent of the way it is done in the end, the relabeling or program generation using a macro only affects the programs that are tail call destinations and are used for unwinding the stack. The entry hooks, no matter whether it is a perf event type of program of kprobe, will stay native eBPF program types and not touched. This allows to do eBPF program type specific tasks - only the tail call destinations are generic and not eBPF program type specific. So there is no limitation in fetching and handling eBPF program type specific information.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

opened #225 to bring this discussion forward.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

With c1724aa I have rewritten the approach to generate perf event and kprobe programs at compile time as requested.
With this change the new size of tracer.ebpf.release.amd64 is 570 KBytes (before 291 KBytes) and for tracer.ebpf.release.arm64 it becomes 554 KBytes (before 283 KBytes).

Let me know what you think - @fabled @christos68k

trace->pid = pid;
trace->tid = tid;
trace->ktime = ktime;
trace->offtime = off_cpu_time;
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I didn't find any handling of offtime by the reporter. If it still follows the previous method (merely counting the number of traceEvents), it won't accurately reflect how long a process has been scheduled out of the CPU. Some samples have a long duration of being scheduled out of the CPU, while others have a short duration, yet they are counted as the same count, which is incorrect.

It is suggested that count=offtime/sampling-interval, so that it can maintain the same meaning of samples as on-CPU.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Handling of off-CPU traces in the user space part is still named as outstanding work to be done in #196 (comment).

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The current OTel Profiling signal is not well suited for data like off-CPU traces. This is a known problem and the OTel Profiling SIG is working on improvements for the OTel Profiling signal.
This fact is one reason, why the user space part for off-CPU profiling is not yet implemented (as mentioned in #196 (comment)) , as there are major changes coming up.

cli_flags.go Outdated Show resolved Hide resolved
@florianl
Copy link
Contributor Author

Rebased proposed changes on current main and resolved merge conflicts.

cli_flags.go Outdated Show resolved Hide resolved
cli_flags.go Outdated Show resolved Hide resolved
libpf/symbol.go Outdated Show resolved Hide resolved
support/ebpf/off_cpu.ebpf.c Outdated Show resolved Hide resolved
support/ebpf/off_cpu.ebpf.c Outdated Show resolved Hide resolved
Comment on lines +629 to +671
if (pid == 0) {
return 0;
}
Copy link
Member

@christos68k christos68k Oct 31, 2024

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think this doesn't belong here and is better placed at the source (we're already checking against pid == 0 in one of the call sites so can also restore the pid == 0 check in the other).

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I did place this check here on purpose as safe guard. While this check is also done in

if (pid == 0 || tid == 0) {
it is not done in
int native_tracer_entry(struct bpf_perf_event_data *ctx) {
. In the former kprobe/finish_task_switch checks are performed based on the PID. While the later perf_event/native_tracer_entry is just adapted to the changes of collect_trace(). The idea is, that collect_trace() serves as entry point for stack unwinding for any kind of eBPF program and therefore it should do the basic checks to not run into stack unwinding issues.
Also moving this check to the caller of collect_trace() will duplicate code in the current situation, which I tried to avoid.

support/ebpf/tracemgmt.h Outdated Show resolved Hide resolved
} TraceOrigin;

// OFF_CPU_THRESHOLD_MAX defines the maximum threshold.
#define OFF_CPU_THRESHOLD_MAX 1000
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This should probably be 100 which is intuitive percentage-wise and also consistent with the probabilistic profiling setting:

Suggested change
#define OFF_CPU_THRESHOLD_MAX 1000
#define OFF_CPU_THRESHOLD_MAX 100

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

1000 is chosen over 100 to provide a more fine grained possibility to configure the off-CPU threshold. On a single core system, using regular percentages makes sense, I think. But the more cores are in use, the more data will be generated. And so I think it makes sense to provide the option to reduce the storage and do off-CPU profiling only for a smaller amount than 1% of all scheduler task switches.
Let me know, if 1% of all scheduler task switches is the minimum that should be allowed to configure.

support/ebpf/types.h Outdated Show resolved Hide resolved
@florianl
Copy link
Contributor Author

florianl commented Nov 1, 2024

With d4a09ad the propagation of off CPU profiles in user space and reporting was added. The PR was rebased to resolve recent API changes in the reporter package.

@florianl florianl marked this pull request as ready for review November 1, 2024 12:51
@florianl florianl requested review from a team as code owners November 1, 2024 12:51
@@ -226,20 +240,25 @@ func (r *OTLPReporter) ReportTraceEvent(trace *libpf.Trace, meta *TraceEventMeta
containerID: containerID,
}

if events, exists := (*traceEventsMap)[key]; exists {
traceEventsMap := r.traceEvents.WLock()
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

No need to hold the lock while looking up the Cgroupv2 ID and creating the key. So I moved fetching the lock to this later point.

// This is to ensure that AttributeTable does not contain duplicates.
attributeMap := make(map[string]uint64)
// getProfile returns an OTLP profile containing all collected traces up to this moment.
func (r *OTLPReporter) getProfile(origin int) (profile *profiles.Profile, startTS, endTS uint64) {
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

getProfile() used to be +200 LOC. I did split it into multiple logical independent functions. So most of the code just shifted and was not changed.

florianl and others added 7 commits November 18, 2024 14:53
This is the code that backs
open-telemetry#144.
It can be reused to add features like requested in
open-telemetry#33 and
therefore can be an alternative to
open-telemetry#192.

The idea that enables off CPU profiling is, that perf event and kprobe eBPF
programs are quite similar and can be converted. This allows, with the
dynamic rewrite of tail call maps, the reuse of existing eBPF programs and
concepts.

This proposal adds the new flag '-off-cpu-threshold' that enables off CPU
profiling and attaches the two additional hooks, as discussed in Option B
in open-telemetry#144.

Outstanding work:
- [ ] Handle off CPU traces in the reporter package
- [ ] Handle off CPU traces in the user space side

Signed-off-by: Florian Lehner <[email protected]>
Signed-off-by: Florian Lehner <[email protected]>
Signed-off-by: Florian Lehner <[email protected]>
@florianl
Copy link
Contributor Author

Needed to force-push to the branch to resolve merge conflicts. Looking forward on getting feedback.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

8 participants