Skip to content

Commit 82c4488

Browse files
committed
RUM-16039: Upgrade Mach profiler sampler to sample CPU-time
1 parent c1fbfeb commit 82c4488

17 files changed

Lines changed: 343 additions & 30 deletions

BenchmarkTests/Runner/Scenarios/Profiling/ProfilingScenario.swift

Lines changed: 7 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -32,6 +32,12 @@ struct ProfilingScenario: Scenario {
3232

3333
RUMMonitor.shared().addAttribute(forKey: "scenario", value: "ContinuousProfiling")
3434

35-
Profiling.enable(with: .init(applicationLaunchSampleRate: .maxSampleRate, continuousSampleRate: .maxSampleRate))
35+
Profiling.enable(
36+
with: .init(
37+
applicationLaunchSampleRate: .maxSampleRate,
38+
continuousSampleRate: .maxSampleRate,
39+
featureFlags: [.cpuTimeSamples: true]
40+
)
41+
)
3642
}
3743
}

DatadogProfiling/Mach/dd_pprof.cpp

Lines changed: 5 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -17,8 +17,12 @@
1717
extern "C" {
1818

1919
dd_pprof_t* dd_pprof_create(uint64_t sampling_interval_ns) {
20+
return dd_pprof_create_with_cpu_time(sampling_interval_ns, false);
21+
}
22+
23+
dd_pprof_t* dd_pprof_create_with_cpu_time(uint64_t sampling_interval_ns, bool record_cpu_time) {
2024
try {
21-
auto* profiler = new dd::profiler::profile(sampling_interval_ns);
25+
auto* profiler = new dd::profiler::profile(sampling_interval_ns, record_cpu_time);
2226
return reinterpret_cast<dd_pprof_t*>(profiler);
2327
} catch (...) {
2428
return nullptr;

DatadogProfiling/Mach/dd_profiler.cpp

Lines changed: 24 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -155,6 +155,23 @@ static double read_profiling_sample_rate() {
155155
return sample_rate;
156156
}
157157

158+
static bool read_profiling_record_cpu_time() {
159+
CFStringRef suiteName = CFSTR(DD_PROFILING_USER_DEFAULTS_SUITE_NAME);
160+
CFStringRef key = CFSTR(DD_PROFILING_RECORD_CPU_TIME_KEY);
161+
CFPropertyListRef value = CFPreferencesCopyAppValue(key, suiteName);
162+
163+
bool result = false;
164+
165+
if (value) {
166+
if (CFGetTypeID(value) == CFBooleanGetTypeID()) {
167+
result = CFBooleanGetValue((CFBooleanRef)value);
168+
}
169+
CFRelease(value);
170+
}
171+
172+
return result;
173+
}
174+
158175
/**
159176
* Deletes the DatadogProfiling defaults from the `UserDefaults`
160177
* to be re-evaluated during `Profiling.enable()`.
@@ -163,9 +180,11 @@ void dd_delete_profiling_defaults() {
163180
CFStringRef suiteName = CFSTR(DD_PROFILING_USER_DEFAULTS_SUITE_NAME);
164181
CFStringRef isEnabledKey = CFSTR(DD_PROFILING_IS_ENABLED_KEY);
165182
CFStringRef sampleRateKey = CFSTR(DD_PROFILING_APP_LAUNCH_SAMPLE_RATE_KEY);
183+
CFStringRef recordCPUTimeKey = CFSTR(DD_PROFILING_RECORD_CPU_TIME_KEY);
166184

167185
CFPreferencesSetValue(isEnabledKey, NULL, suiteName, kCFPreferencesCurrentUser, kCFPreferencesAnyHost);
168186
CFPreferencesSetValue(sampleRateKey, NULL, suiteName, kCFPreferencesCurrentUser, kCFPreferencesAnyHost);
187+
CFPreferencesSetValue(recordCPUTimeKey, NULL, suiteName, kCFPreferencesCurrentUser, kCFPreferencesAnyHost);
169188
CFPreferencesSynchronize(suiteName, kCFPreferencesCurrentUser, kCFPreferencesAnyHost);
170189
}
171190

@@ -353,7 +372,9 @@ class dd_profiler {
353372

354373
if (profiler) return true;
355374

356-
profile = new (std::nothrow) dd::profiler::profile(sampling_interval_ns);
375+
record_cpu_time = read_profiling_record_cpu_time();
376+
377+
profile = new (std::nothrow) dd::profiler::profile(sampling_interval_ns, record_cpu_time);
357378
if (!profile) {
358379
status = DD_PROFILER_STATUS_ALLOCATION_FAILED;
359380
return false;
@@ -362,6 +383,7 @@ class dd_profiler {
362383

363384
sampling_config_t config = SAMPLING_CONFIG_DEFAULT;
364385
config.sampling_interval_nanos = sampling_interval_ns;
386+
config.record_cpu_time = record_cpu_time ? 1 : 0;
365387

366388
profiler = new (std::nothrow) mach_sampling_profiler(&config, callback, this, hard_limit_bytes);
367389
if (!profiler) {
@@ -383,6 +405,7 @@ class dd_profiler {
383405
uint64_t hard_limit_bytes = DD_PROFILER_DEFAULT_HARD_LIMIT_BYTES;
384406
uint64_t sampling_interval_ns = SAMPLING_CONFIG_DEFAULT_INTERVAL_NANOS;
385407
int64_t server_time_offset_ns = 0;
408+
bool record_cpu_time = false;
386409

387410
/**
388411
* Mutex protecting the profile pointer.

DatadogProfiling/Mach/include/dd_pprof.h

Lines changed: 9 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -42,6 +42,15 @@ typedef struct profile dd_pprof_t;
4242
*/
4343
dd_pprof_t* dd_pprof_create(uint64_t sampling_interval_ns);
4444

45+
/**
46+
* Create a new pprof profile aggregator with optional CPU-time sample values.
47+
*
48+
* @param sampling_interval_ns The sampling interval in nanoseconds
49+
* @param record_cpu_time Whether samples should include CPU time as a second value
50+
* @return Pointer to the created profile, or NULL on failure
51+
*/
52+
dd_pprof_t* dd_pprof_create_with_cpu_time(uint64_t sampling_interval_ns, bool record_cpu_time);
53+
4554
/**
4655
* Destroy a pprof profile aggregator and free all associated memory
4756
*

DatadogProfiling/Mach/include/dd_profiler.h

Lines changed: 7 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -52,6 +52,8 @@ typedef struct stack_trace {
5252
uint64_t timestamp;
5353
/** Actual sampling interval in nanoseconds for this sample */
5454
uint64_t sampling_interval_nanos;
55+
/** CPU time consumed by this thread since the previous sample */
56+
uint64_t cpu_time_nanos;
5557
/** The stack frames array */
5658
stack_frame_t* frames;
5759
/** Number of frames in the trace */
@@ -74,6 +76,8 @@ typedef struct sampling_config {
7476
uint32_t max_thread_count; // default: 100
7577
/** QoS class for the sampling thread */
7678
qos_class_t qos_class;
79+
/** Whether samples should include a CPU-time value */
80+
uint8_t record_cpu_time;
7781
} sampling_config_t;
7882

7983
/**
@@ -100,7 +104,8 @@ static const sampling_config_t SAMPLING_CONFIG_DEFAULT = {
100104
SAMPLING_CONFIG_DEFAULT_BUFFER_SIZE, // max_buffer_size
101105
SAMPLING_CONFIG_DEFAULT_STACK_DEPTH, // max_stack_depth
102106
SAMPLING_CONFIG_DEFAULT_THREAD_COUNT, // max_thread_count
103-
QOS_CLASS_USER_INTERACTIVE // qos_class
107+
QOS_CLASS_USER_INTERACTIVE, // qos_class
108+
0 // record_cpu_time
104109
};
105110

106111
/**
@@ -122,6 +127,7 @@ typedef void (*stack_trace_callback_t)(stack_trace_t* traces, size_t count, void
122127
#define DD_PROFILING_USER_DEFAULTS_SUITE_NAME "com.datadoghq.ios-sdk.profiling"
123128
#define DD_PROFILING_IS_ENABLED_KEY "is_profiling_enabled"
124129
#define DD_PROFILING_APP_LAUNCH_SAMPLE_RATE_KEY "profiling_app_launch_sample_rate"
130+
#define DD_PROFILING_RECORD_CPU_TIME_KEY "profiling_record_cpu_time"
125131

126132
#ifdef __cplusplus
127133

DatadogProfiling/Mach/include/mach_sampling_profiler.h

Lines changed: 13 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -21,6 +21,7 @@
2121
#include <memory>
2222
#include <mutex>
2323
#include <pthread.h>
24+
#include <unordered_map>
2425
#include <vector>
2526

2627
#ifdef __cplusplus
@@ -165,13 +166,23 @@ class mach_sampling_profiler {
165166
* @param thread The thread to sample
166167
* @param interval_nanos The actual sampling interval in nanoseconds for this sample
167168
*/
168-
void sample_thread(thread_t thread, uint64_t interval_nanos);
169+
void sample_thread(thread_t thread, uint64_t interval_nanos, uint64_t cpu_time_nanos);
169170

170171
/**
171172
* @brief Returns true when the thread is owned by the profiler itself.
172173
*/
173174
bool is_profiler_internal_thread(thread_t thread) const;
174175

176+
/**
177+
* @brief Returns CPU time consumed since the previous observation for this thread.
178+
*/
179+
uint64_t thread_cpu_time_delta_nanos(thread_t thread);
180+
181+
/**
182+
* @brief Removes CPU-time state for threads no longer present in the task.
183+
*/
184+
void prune_thread_cpu_time_state(const thread_t* threads, mach_msg_type_number_t count);
185+
175186
private:
176187
/**
177188
* @brief Static entry point for the sampling thread
@@ -184,6 +195,7 @@ class mach_sampling_profiler {
184195
std::mutex state_mutex;
185196
/// Indicates whether `sampling_thread` currently refers to a live session thread.
186197
std::atomic<bool> has_sampling_thread{false};
198+
std::unordered_map<thread_t, uint64_t> previous_thread_cpu_time_nanos;
187199
};
188200

189201
} // namespace dd::profiler

DatadogProfiling/Mach/include/profile.h

Lines changed: 13 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -147,7 +147,7 @@ class profile {
147147
* @brief Construct a new profile aggregator
148148
* @param sampling_interval_ns Sampling interval in nanoseconds
149149
*/
150-
explicit profile(uint64_t sampling_interval_ns);
150+
explicit profile(uint64_t sampling_interval_ns, bool record_cpu_time = false);
151151
~profile() = default;
152152

153153
profile(const profile&) = delete;
@@ -189,10 +189,16 @@ class profile {
189189

190190
/** @brief Get cached string ID for "wall-time" */
191191
uint32_t wall_time_str_id() const { return _wall_time_str_id; }
192+
193+
/** @brief Get cached string ID for "cpu-time" */
194+
uint32_t cpu_time_str_id() const { return _cpu_time_str_id; }
192195

193196
/** @brief Get cached string ID for "nanoseconds" */
194197
uint32_t nanoseconds_str_id() const { return _nanoseconds_str_id; }
195198

199+
/** @brief Whether samples include a CPU-time value in addition to wall-time */
200+
bool cpu_time_enabled() const { return _record_cpu_time; }
201+
196202
/** @brief Number of labels exported for the sample */
197203
size_t label_count(const sample_t& sample) const { return sample.labels.size() + 1; }
198204

@@ -238,12 +244,18 @@ class profile {
238244

239245
/** @brief Profile sampling interval in nanoseconds */
240246
uint64_t _sampling_interval_ns;
247+
248+
/** @brief Whether samples include CPU time as a second value */
249+
bool _record_cpu_time;
241250

242251
/** @brief Cached string ID for empty string */
243252
uint32_t _empty_str_id;
244253

245254
/** @brief Cached string ID for "wall-time" */
246255
uint32_t _wall_time_str_id;
256+
257+
/** @brief Cached string ID for "cpu-time" */
258+
uint32_t _cpu_time_str_id;
247259

248260
/** @brief Cached string ID for "nanoseconds" */
249261
uint32_t _nanoseconds_str_id;

DatadogProfiling/Mach/mach_sampling_profiler.cpp

Lines changed: 77 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -19,6 +19,7 @@
1919
#include <setjmp.h>
2020
#include <mach/thread_act.h>
2121
#include <mach/thread_status.h>
22+
#include <mach/thread_info.h>
2223
#include <mach/machine/thread_state.h>
2324
#include <new>
2425
#include <utility>
@@ -160,11 +161,32 @@ bool stack_trace_init(stack_trace_t* trace, uint32_t max_depth, uint64_t interva
160161
trace->thread_name = nullptr;
161162
trace->timestamp = 0;
162163
trace->sampling_interval_nanos = interval_nanos;
164+
trace->cpu_time_nanos = 0;
163165
trace->frame_count = 0;
164166
trace->frames = (stack_frame_t*)malloc(max_depth * sizeof(stack_frame_t));
165167
return trace->frames != nullptr;
166168
}
167169

170+
static bool thread_cpu_time_nanos(thread_t thread, uint64_t* cpu_time_nanos) {
171+
if (!cpu_time_nanos) return false;
172+
173+
thread_basic_info_data_t info{};
174+
mach_msg_type_number_t count = THREAD_BASIC_INFO_COUNT;
175+
if (thread_info(thread, THREAD_BASIC_INFO, reinterpret_cast<thread_info_t>(&info), &count) != KERN_SUCCESS) {
176+
return false;
177+
}
178+
179+
const uint64_t user_time_nanos =
180+
(static_cast<uint64_t>(info.user_time.seconds) * 1000000000ULL)
181+
+ (static_cast<uint64_t>(info.user_time.microseconds) * 1000ULL);
182+
const uint64_t system_time_nanos =
183+
(static_cast<uint64_t>(info.system_time.seconds) * 1000000000ULL)
184+
+ (static_cast<uint64_t>(info.system_time.microseconds) * 1000ULL);
185+
186+
*cpu_time_nanos = user_time_nanos + system_time_nanos;
187+
return true;
188+
}
189+
168190
/**
169191
* Destroys a stack trace, freeing the thread name and frames array.
170192
*
@@ -396,6 +418,7 @@ bool mach_sampling_profiler::start_sampling() {
396418

397419
// Clear any leftover data from previous runs
398420
sample_buffer.clear();
421+
previous_thread_cpu_time_nanos.clear();
399422
if (sample_buffer.capacity() < config.max_buffer_size) {
400423
sample_buffer.reserve(config.max_buffer_size);
401424
}
@@ -491,9 +514,10 @@ bool mach_sampling_profiler::is_profiler_internal_thread(thread_t thread) const
491514
* @param thread The thread to sample
492515
* @param interval_nanos The actual sampling interval in nanoseconds for this sample
493516
*/
494-
void mach_sampling_profiler::sample_thread(thread_t thread, uint64_t interval_nanos) {
517+
void mach_sampling_profiler::sample_thread(thread_t thread, uint64_t interval_nanos, uint64_t cpu_time_nanos) {
495518
stack_trace_t trace;
496519
if (!stack_trace_init(&trace, config.max_stack_depth, interval_nanos)) return;
520+
trace.cpu_time_nanos = cpu_time_nanos;
497521

498522
// Get thread info
499523
stack_trace_get_thread_info(&trace, thread);
@@ -519,6 +543,53 @@ void mach_sampling_profiler::sample_thread(thread_t thread, uint64_t interval_na
519543
}
520544
}
521545

546+
uint64_t mach_sampling_profiler::thread_cpu_time_delta_nanos(thread_t thread) {
547+
if (!config.record_cpu_time) {
548+
return 0;
549+
}
550+
551+
uint64_t current_cpu_time_nanos = 0;
552+
if (!thread_cpu_time_nanos(thread, &current_cpu_time_nanos)) {
553+
return 0;
554+
}
555+
556+
auto result = previous_thread_cpu_time_nanos.emplace(thread, current_cpu_time_nanos);
557+
if (result.second) {
558+
return 0;
559+
}
560+
561+
const uint64_t previous_cpu_time_nanos = result.first->second;
562+
result.first->second = current_cpu_time_nanos;
563+
564+
if (current_cpu_time_nanos < previous_cpu_time_nanos) {
565+
return 0;
566+
}
567+
568+
return current_cpu_time_nanos - previous_cpu_time_nanos;
569+
}
570+
571+
void mach_sampling_profiler::prune_thread_cpu_time_state(const thread_t* threads, mach_msg_type_number_t count) {
572+
if (!config.record_cpu_time || previous_thread_cpu_time_nanos.empty()) {
573+
return;
574+
}
575+
576+
for (auto it = previous_thread_cpu_time_nanos.begin(); it != previous_thread_cpu_time_nanos.end();) {
577+
bool is_live_thread = false;
578+
for (mach_msg_type_number_t i = 0; i < count; i++) {
579+
if (threads[i] == it->first) {
580+
is_live_thread = true;
581+
break;
582+
}
583+
}
584+
585+
if (is_live_thread) {
586+
++it;
587+
} else {
588+
it = previous_thread_cpu_time_nanos.erase(it);
589+
}
590+
}
591+
}
592+
522593
/**
523594
* Main sampling loop that collects stack traces from threads.
524595
*/
@@ -535,7 +606,8 @@ void mach_sampling_profiler::main() {
535606
}
536607

537608
if (config.profile_current_thread_only) {
538-
sample_thread(pthread_mach_thread_np(target_thread), interval_nanos);
609+
const thread_t thread = pthread_mach_thread_np(target_thread);
610+
sample_thread(thread, interval_nanos, thread_cpu_time_delta_nanos(thread));
539611
if (sample_buffer.size() >= config.max_buffer_size) {
540612
worker->enqueue_active_buffer(sample_buffer);
541613
}
@@ -557,13 +629,15 @@ void mach_sampling_profiler::main() {
557629
// Skip profiler-owned threads to avoid self-noise in customer profiles.
558630
if (is_profiler_internal_thread(threads[i])) continue;
559631

560-
sample_thread(threads[i], interval_nanos);
632+
sample_thread(threads[i], interval_nanos, thread_cpu_time_delta_nanos(threads[i]));
561633

562634
if (sample_buffer.size() >= config.max_buffer_size) {
563635
worker->enqueue_active_buffer(sample_buffer);
564636
}
565637
}
566638

639+
prune_thread_cpu_time_state(threads, count);
640+
567641
// Clean up thread references
568642
for (mach_msg_type_number_t i = 0; i < count; i++) {
569643
mach_port_deallocate(mach_task_self(), threads[i]);

DatadogProfiling/Mach/profile.cpp

Lines changed: 6 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -81,8 +81,9 @@ std::string uuid_string(const uuid_t uuid) {
8181
*
8282
* @param sampling_interval_ns Sampling interval in nanoseconds
8383
*/
84-
profile::profile(uint64_t sampling_interval_ns)
84+
profile::profile(uint64_t sampling_interval_ns, bool record_cpu_time)
8585
: _sampling_interval_ns(sampling_interval_ns)
86+
, _record_cpu_time(record_cpu_time)
8687
, _epoch_offset(uptime_epoch_offset())
8788
, _server_time_offset_ns(0)
8889
, _start_timestamp(0)
@@ -95,6 +96,7 @@ profile::profile(uint64_t sampling_interval_ns)
9596
// Pre-intern common strings for performance
9697
_empty_str_id = intern_string("");
9798
_wall_time_str_id = intern_string("wall-time");
99+
_cpu_time_str_id = _record_cpu_time ? intern_string("cpu-time") : 0;
98100
_nanoseconds_str_id = intern_string("nanoseconds");
99101
_end_timestamp_ns_str_id = intern_string("end_timestamp_ns");
100102
_thread_id_str_id = intern_string("thread id");
@@ -176,6 +178,9 @@ void profile::add_samples(const stack_trace_t* traces, size_t count, binary_imag
176178
sample.timestamp_uptime_ns = trace.timestamp;
177179
sample.labels = std::move(labels);
178180
sample.values = {static_cast<int64_t>(trace.sampling_interval_nanos)};
181+
if (_record_cpu_time) {
182+
sample.values.push_back(static_cast<int64_t>(trace.cpu_time_nanos));
183+
}
179184

180185
_samples.push_back(std::move(sample));
181186

0 commit comments

Comments
 (0)