Branch data Line data Source code
1 : : // SPDX-License-Identifier: MIT OR LGPL-2.0-or-later
2 : : // SPDX-FileCopyrightText: 2016 Christian Hergert <christian@hergert.me>
3 : :
4 : : #include <config.h> // for ENABLE_PROFILER, HAVE_SYS_SYSCALL_H, HAVE_UNISTD_H
5 : :
6 : : #ifdef HAVE_SIGNAL_H
7 : : # include <signal.h> // for siginfo_t, sigevent, sigaction, SIGPROF, ...
8 : : #endif
9 : :
10 : : #ifdef ENABLE_PROFILER
11 : : // IWYU has a weird loop where if this is present, it asks for it to be removed,
12 : : // and if absent, asks for it to be added
13 : : # include <alloca.h> // IWYU pragma: keep
14 : : # include <errno.h>
15 : : # include <stdint.h>
16 : : # include <stdio.h> // for sscanf
17 : : # include <string.h> // for memcpy, strlen
18 : : # include <sys/syscall.h> // for __NR_gettid
19 : : # include <sys/types.h> // for timer_t
20 : : # include <time.h> // for size_t, CLOCK_MONOTONIC, itimerspec, ...
21 : : # ifdef HAVE_UNISTD_H
22 : : # include <unistd.h> // for getpid, syscall
23 : : # endif
24 : : # include <array>
25 : : #endif
26 : :
27 : : #include <chrono>
28 : :
29 : : #ifdef ENABLE_PROFILER
30 : : # include <algorithm> // for min
31 : : # include <format>
32 : : # include <string>
33 : : # include <string_view>
34 : : #endif
35 : :
36 : : #include <glib-object.h>
37 : : #include <glib.h>
38 : :
39 : : #ifdef ENABLE_PROFILER
40 : : # ifdef G_OS_UNIX
41 : : # include <glib-unix.h>
42 : : # endif
43 : : # include <sysprof-capture.h>
44 : : #endif
45 : :
46 : : #include <js/GCAPI.h> // for JSFinalizeStatus, JSGCStatus, GCReason
47 : : #include <js/ProfilingStack.h> // for EnableContextProfilingStack, ...
48 : : #include <js/TypeDecls.h>
49 : : #include <mozilla/Atomics.h> // for ProfilingStack operators
50 : : #include <mozilla/Maybe.h>
51 : :
52 : : #include "gjs/auto.h"
53 : : #include "gjs/context.h"
54 : : #include "gjs/jsapi-util.h" // for gjs_explain_gc_reason
55 : : #include "gjs/mem-private.h"
56 : : #include "gjs/profiler-private.h" // IWYU pragma: associated
57 : : #include "gjs/profiler.h"
58 : : #include "util/log.h"
59 : : #include "util/misc.h"
60 : :
61 : : using mozilla::Maybe, mozilla::Nothing, mozilla::Some,
62 : : std::chrono_literals::operator""s, std::chrono_literals::operator""ms;
63 : :
64 : : /*
65 : : * This is mostly non-exciting code wrapping the builtin Profiler in mozjs. In
66 : : * particular, the profiler consumer is required to "bring your own sampler".
67 : : * We do the very non-surprising thing of using POSIX timers to deliver SIGPROF
68 : : * to the thread containing the JSContext.
69 : : *
70 : : * However, we do use a Linux'ism that allows us to deliver the signal to only a
71 : : * single thread. Doing this in a generic fashion would require
72 : : * thread-registration so that we can mask SIGPROF from all threads except the
73 : : * JS thread. The gecko engine uses tgkill() to do this with a secondary thread
74 : : * instead of using POSIX timers. We could do this too, but it would still be
75 : : * Linux-only.
76 : : *
77 : : * Another option might be to use pthread_kill() and a secondary thread to
78 : : * perform the notification.
79 : : *
80 : : * From within the signal handler, we process the current stack as delivered to
81 : : * us from the JSContext. Any pointer data that comes from the runtime has to be
82 : : * copied, so we keep our own dedup'd string pointers for JavaScript file/line
83 : : * information. Non-JS instruction pointers are just fine, as they can be
84 : : * resolved by parsing the ELF for the file mapped on disk containing that
85 : : * address.
86 : : *
87 : : * As much of this code has to run from signal handlers, it is very important
88 : : * that we don't use anything that can malloc() or lock, or deadlocks are very
89 : : * likely. Most of GjsProfilerCapture is signal-safe.
90 : : */
91 : :
92 : : static const std::chrono::seconds FLUSH_DELAY = 3s;
93 : : static const std::chrono::milliseconds SAMPLING_PERIOD = 1ms;
94 : :
95 : : // Custom packing for Maybe<ProfilerTimePoint>. We assume that 0 is not a value
96 : : // that comes out of the monotonic clock and so can be used to indicate Nothing
97 : : namespace mozilla::detail {
98 : : template <>
99 : : struct MaybeStorage<ProfilerTimePoint> {
100 : : protected:
101 : : union {
102 : : struct {
103 : : ProfilerTimePoint val;
104 : : } mStorage;
105 : : ProfilerTimePoint::rep mIsSome;
106 : : };
107 : :
108 : 0 : explicit MaybeStorage(ProfilerTimePoint some) : mStorage({some}) {
109 : 0 : g_assert(some.time_since_epoch().count() != 0 &&
110 : : "0 is not a valid value for Maybe<ProfilerTimePoint>");
111 : 0 : }
112 : : MaybeStorage() : mIsSome(0) {}
113 : : };
114 : :
115 : : static_assert(sizeof(Maybe<ProfilerTimePoint>) == sizeof(ProfilerTimePoint),
116 : : "Maybe<ProfilerTimePoint> should pack");
117 : :
118 : : } // namespace mozilla::detail
119 : :
120 [ # # # # : 0 : G_DEFINE_POINTER_TYPE(GjsProfiler, gjs_profiler)
# # ]
121 : :
122 : : struct _GjsProfiler {
123 : : #ifdef ENABLE_PROFILER
124 : : /* The stack for the JSContext profiler to use for current stack information
125 : : * while executing. We will look into this during our SIGPROF handler.
126 : : */
127 : : ProfilingStack stack;
128 : :
129 : : // The context being profiled
130 : : JSContext* cx;
131 : :
132 : : // Buffers and writes our sampled stacks
133 : : SysprofCaptureWriter* capture;
134 : : GSource* periodic_flush;
135 : :
136 : : SysprofCaptureWriter* target_capture;
137 : :
138 : : // Cache previous values of counters so that we don't overrun the output
139 : : // with counters that don't change very often
140 : : uint64_t last_counter_values[GJS_N_COUNTERS];
141 : : #endif // ENABLE_PROFILER
142 : :
143 : : // The filename to write to
144 : : char* filename;
145 : :
146 : : // An FD to capture to
147 : : int fd;
148 : :
149 : : #ifdef ENABLE_PROFILER
150 : : // Our POSIX timer to wakeup SIGPROF
151 : : timer_t timer;
152 : :
153 : : // Cached copy of our pid
154 : : GPid pid;
155 : :
156 : : // Timing information
157 : : Maybe<ProfilerTimePoint> gc_begin_time;
158 : : Maybe<ProfilerTimePoint> sweep_begin_time;
159 : : Maybe<ProfilerTimePoint> group_sweep_begin_time;
160 : : const char* gc_reason; // statically allocated
161 : :
162 : : // GLib signal handler ID for SIGUSR2
163 : : unsigned sigusr2_id;
164 : : unsigned counter_base; // index of first GObject memory counter
165 : : unsigned gc_counter_base; // index of first GC stats counter
166 : : #endif // ENABLE_PROFILER
167 : :
168 : : // If we are currently sampling
169 : : unsigned running : 1;
170 : : };
171 : :
172 : : static GjsContext* profiling_context;
173 : :
174 : : #ifdef ENABLE_PROFILER
175 : :
176 : : [[nodiscard]]
177 : 31 : static inline ProfilerTimePoint profiler_timestamp() {
178 : 31 : return std::chrono::time_point_cast<std::chrono::nanoseconds>(
179 : 62 : GLib::MonotonicClock::now());
180 : : }
181 : :
182 : : /**
183 : : * gjs_profiler_extract_maps:
184 : : *
185 : : * This function will write the mapped section information to the capture file
186 : : * so that the callgraph builder can generate symbols from the stack addresses
187 : : * provided.
188 : : *
189 : : * Returns: true if successful; otherwise false and the profile should abort.
190 : : */
191 : : [[nodiscard]]
192 : 6 : static bool gjs_profiler_extract_maps(GjsProfiler* self) {
193 : 6 : ProfilerTimePoint now = profiler_timestamp();
194 : :
195 : 6 : g_assert(self && "Profiler must be set up before extracting maps");
196 : :
197 : 6 : std::string path = std::format("/proc/{}/maps", self->pid);
198 : :
199 : 6 : Gjs::AutoChar content;
200 : : size_t len;
201 [ - + ]: 6 : if (!g_file_get_contents(path.c_str(), content.out(), &len, nullptr))
202 : 0 : return false;
203 : :
204 : 6 : Gjs::AutoStrv lines{g_strsplit(content, "\n", 0)};
205 : :
206 [ + + ]: 1416 : for (size_t ix = 0; lines[ix]; ix++) {
207 : : char file[256];
208 : : unsigned long start;
209 : : unsigned long end;
210 : : unsigned long offset;
211 : : unsigned long inode;
212 : :
213 : 1410 : file[sizeof file - 1] = '\0';
214 : :
215 : 1410 : int r = sscanf(lines[ix], "%lx-%lx %*15s %lx %*x:%*x %lu %255s",
216 : : &start, &end, &offset, &inode, file);
217 [ + + ]: 1410 : if (r != 5)
218 : 370 : continue;
219 : :
220 [ + + ]: 1040 : if (strcmp("[vdso]", file) == 0) {
221 : 6 : offset = 0;
222 : 6 : inode = 0;
223 : : }
224 : :
225 : 1040 : if (!sysprof_capture_writer_add_map(
226 [ - + ]: 2080 : self->capture, now.time_since_epoch().count(), -1, self->pid,
227 : : start, end, offset, inode, file))
228 : 0 : return false;
229 : : }
230 : :
231 : 6 : return true;
232 : 6 : }
233 : :
234 : : // Assumes the last byte of the SysprofCaptureCounter buffer must be a zero byte
235 : : template <size_t N>
236 : 324 : static void copy_counter_string(char (&dest)[N], std::string_view src) {
237 : 324 : g_assert(src.size() < N && "string too long for Sysprof counter field");
238 : 324 : size_t copied = src.copy(dest, N - 1);
239 : 324 : std::fill(dest + copied, dest + N, '\0');
240 : 324 : }
241 : :
242 : 96 : static void setup_counter_helper(SysprofCaptureCounter* counter,
243 : : std::string_view counter_name,
244 : : unsigned counter_base, size_t ix) {
245 : 96 : copy_counter_string(counter->category, "GJS");
246 : 96 : copy_counter_string(counter->name, counter_name);
247 : 96 : copy_counter_string(counter->description, GJS_COUNTER_DESCRIPTIONS[ix]);
248 : 96 : counter->id = static_cast<uint32_t>(counter_base + ix);
249 : 96 : counter->type = SYSPROF_CAPTURE_COUNTER_INT64;
250 : 96 : counter->value.v64 = 0;
251 : 96 : }
252 : :
253 : : [[nodiscard]]
254 : 6 : static bool gjs_profiler_define_counters(GjsProfiler* self) {
255 : 6 : ProfilerTimePoint now = profiler_timestamp();
256 : :
257 : 6 : g_assert(self && "Profiler must be set up before defining counters");
258 : :
259 : : std::array<SysprofCaptureCounter, GJS_N_COUNTERS> counters;
260 : 6 : self->counter_base =
261 : 6 : sysprof_capture_writer_request_counter(self->capture, GJS_N_COUNTERS);
262 : :
263 : : # define SETUP_COUNTER(counter_name, ix) \
264 : : setup_counter_helper(counters.data() + (ix), #counter_name, \
265 : : self->counter_base, ix);
266 : 102 : GJS_FOR_EACH_COUNTER(SETUP_COUNTER);
267 : : # undef SETUP_COUNTER
268 : :
269 : 6 : if (!sysprof_capture_writer_define_counters(
270 [ - + ]: 6 : self->capture, now.time_since_epoch().count(), -1, self->pid,
271 : 6 : counters.data(), GJS_N_COUNTERS))
272 : 0 : return false;
273 : :
274 : : std::array<SysprofCaptureCounter, Gjs::GCCounters::N_COUNTERS> gc_counters;
275 : 6 : self->gc_counter_base = sysprof_capture_writer_request_counter(
276 : : self->capture, Gjs::GCCounters::N_COUNTERS);
277 : :
278 [ + + ]: 18 : for (size_t ix = 0; ix < Gjs::GCCounters::N_COUNTERS; ix++) {
279 : 12 : copy_counter_string(gc_counters[ix].category, "GJS");
280 : 12 : gc_counters[ix].id = static_cast<uint32_t>(self->gc_counter_base + ix);
281 : 12 : gc_counters[ix].type = SYSPROF_CAPTURE_COUNTER_INT64;
282 : 12 : gc_counters[ix].value.v64 = 0;
283 : : }
284 : 6 : copy_counter_string(gc_counters[Gjs::GCCounters::GC_HEAP_BYTES].name,
285 : 6 : "GC bytes");
286 : 6 : copy_counter_string(gc_counters[Gjs::GCCounters::GC_HEAP_BYTES].description,
287 : 6 : "Bytes used in GC heap");
288 : 6 : copy_counter_string(gc_counters[Gjs::GCCounters::MALLOC_HEAP_BYTES].name,
289 : 6 : "Malloc bytes");
290 : 6 : copy_counter_string(
291 : 6 : gc_counters[Gjs::GCCounters::MALLOC_HEAP_BYTES].description,
292 : 6 : "Malloc bytes owned by tenured GC things");
293 : :
294 : 6 : return sysprof_capture_writer_define_counters(
295 : 6 : self->capture, now.time_since_epoch().count(), -1, self->pid,
296 : 12 : gc_counters.data(), Gjs::GCCounters::N_COUNTERS);
297 : : }
298 : :
299 : : #endif /* ENABLE_PROFILER */
300 : :
301 : : /**
302 : : * _gjs_profiler_new:
303 : : * @gjs_context: The #GjsContext to profile
304 : : *
305 : : * This creates a new profiler for the #JSContext. It is important that this
306 : : * instance is freed with _gjs_profiler_free() before the context is destroyed.
307 : : *
308 : : * Call gjs_profiler_start() to enable the profiler, and gjs_profiler_stop()
309 : : * when you have finished.
310 : : *
311 : : * The profiler works by enabling the JS profiler in spidermonkey so that sample
312 : : * information is available. A POSIX timer is used to signal SIGPROF to the
313 : : * process on a regular interval to collect the most recent profile sample and
314 : : * stash it away. It is a programming error to mask SIGPROF from the thread
315 : : * controlling the JS context.
316 : : *
317 : : * If another #GjsContext already has a profiler, or @context already has one,
318 : : * then returns %NULL instead.
319 : : *
320 : : * Returns: (transfer full) (nullable): A newly allocated #GjsProfiler
321 : : */
322 : 6 : GjsProfiler* gjs_profiler_new(GjsContext* gjs_context) {
323 : 6 : g_return_val_if_fail(gjs_context, nullptr);
324 : :
325 [ - + ]: 6 : if (profiling_context == gjs_context) {
326 : 0 : gjs_critical("You can only create one profiler at a time");
327 : 0 : return nullptr;
328 : : }
329 : :
330 [ - + ]: 6 : if (profiling_context) {
331 : 0 : gjs_message(
332 : : "Not going to profile GjsContext {}; you can only profile one "
333 : : "context at a time",
334 : : static_cast<void*>(gjs_context));
335 : 0 : return nullptr;
336 : : }
337 : :
338 : 6 : auto* self = g_new0(GjsProfiler, 1);
339 : :
340 : : #ifdef ENABLE_PROFILER
341 : 6 : self->cx =
342 : 6 : static_cast<JSContext*>(gjs_context_get_native_context(gjs_context));
343 : 6 : self->pid = getpid();
344 : : #endif
345 : 6 : self->fd = -1;
346 : :
347 : 6 : profiling_context = gjs_context;
348 : :
349 : 6 : return self;
350 : : }
351 : :
352 : : /**
353 : : * _gjs_profiler_free:
354 : : * @self: A #GjsProfiler
355 : : *
356 : : * Frees a profiler instance and cleans up any allocated data.
357 : : *
358 : : * If the profiler is running, it will be stopped. This may result in blocking
359 : : * to write the contents of the buffer to the underlying file-descriptor.
360 : : */
361 : 6 : void gjs_profiler_free(GjsProfiler* self) {
362 [ - + ]: 6 : if (!self)
363 : 0 : return;
364 : :
365 [ - + ]: 6 : if (self->running)
366 : 0 : gjs_profiler_stop(self);
367 : :
368 : 6 : profiling_context = nullptr;
369 : :
370 [ + + ]: 6 : g_clear_pointer(&self->filename, g_free);
371 : : #ifdef ENABLE_PROFILER
372 [ - + ]: 6 : g_clear_pointer(&self->capture, sysprof_capture_writer_unref);
373 [ - + ]: 6 : g_clear_pointer(&self->periodic_flush, g_source_destroy);
374 [ - + ]: 6 : g_clear_pointer(&self->target_capture, sysprof_capture_writer_unref);
375 : :
376 [ - + ]: 6 : if (self->fd != -1)
377 : 0 : close(self->fd);
378 : :
379 : 6 : self->stack.~ProfilingStack();
380 : : #endif
381 [ - + ]: 6 : g_free(self);
382 : : }
383 : :
384 : : /**
385 : : * gjs_profiler_is_running:
386 : : * @self: A #GjsProfiler
387 : : *
388 : : * Checks if the profiler is currently running. This means that the JS
389 : : * profiler is enabled and POSIX signal timers are registered.
390 : : *
391 : : * Returns: true if the profiler is active.
392 : : */
393 : 105 : bool gjs_profiler_is_running(GjsProfiler* self) {
394 : 105 : g_return_val_if_fail(self, false);
395 : :
396 : 105 : return self->running;
397 : : }
398 : :
399 : : #ifdef ENABLE_PROFILER
400 : :
401 : 18 : static void gjs_profiler_sigprof(int signum [[maybe_unused]], siginfo_t* info,
402 : : void*) {
403 : 18 : GjsProfiler* self = gjs_context_get_profiler(profiling_context);
404 : :
405 : 18 : g_assert(info && "SIGPROF handler called with invalid signal info");
406 : 18 : g_assert(info->si_signo == SIGPROF &&
407 : : "SIGPROF handler called with other signal");
408 : :
409 : : /*
410 : : * NOTE:
411 : : *
412 : : * This is the SIGPROF signal handler. Everything done in this thread
413 : : * needs to be things that are safe to do in a signal handler. One thing
414 : : * that is not okay to do, is *malloc*.
415 : : */
416 : :
417 [ + - - + ]: 18 : if (!self || info->si_code != SI_TIMER)
418 : 5 : return;
419 : :
420 : 18 : uint32_t depth = self->stack.stackSize();
421 [ + + ]: 18 : if (depth == 0)
422 : 5 : return;
423 : :
424 : 13 : ProfilerTimePoint now = profiler_timestamp();
425 : :
426 : : auto* addrs = static_cast<SysprofCaptureAddress*>(
427 : 13 : alloca(sizeof(SysprofCaptureAddress) * depth));
428 : :
429 [ + + ]: 45 : for (uint32_t ix = 0; ix < depth; ix++) {
430 : 32 : js::ProfilingStackFrame& entry = self->stack.frames[ix];
431 : 32 : const char* label = entry.label();
432 : 32 : const char* dynamic_string = entry.dynamicString();
433 : 32 : uint32_t flipped = depth - 1 - ix;
434 : 32 : size_t label_length = strlen(label);
435 : :
436 : : /* 512 is an arbitrarily large size, very likely to be enough to hold
437 : : * the final string.
438 : : */
439 : : char final_string[512];
440 : 32 : char* position = final_string;
441 : 32 : size_t available_length = sizeof (final_string) - 1;
442 : :
443 [ + + ]: 32 : if (label_length > 0) {
444 : 18 : label_length = std::min(label_length, available_length);
445 : :
446 : : // Start copying the label to the final string
447 : 18 : memcpy(position, label, label_length);
448 : 18 : available_length -= label_length;
449 : 18 : position += label_length;
450 : :
451 : : /* Add a space in between the label and the dynamic string, if there
452 : : * is one.
453 : : */
454 [ - + - - ]: 18 : if (dynamic_string && available_length > 0) {
455 : 0 : *position++ = ' ';
456 : 0 : available_length--;
457 : : }
458 : : }
459 : :
460 : : /* Now append the dynamic string at the end of the final string.
461 : : * The string is cut in case it doesn't fit the remaining space.
462 : : */
463 [ - + ]: 32 : if (dynamic_string) {
464 : 0 : size_t dynamic_string_length = strlen(dynamic_string);
465 : :
466 [ # # ]: 0 : if (dynamic_string_length > 0) {
467 : : size_t remaining_length =
468 : 0 : std::min(available_length, dynamic_string_length);
469 : 0 : memcpy(position, dynamic_string, remaining_length);
470 : 0 : position += remaining_length;
471 : : }
472 : : }
473 : :
474 : 32 : *position = 0;
475 : :
476 : : /* GeckoProfiler will put "js::RunScript" on the stack, but it has a
477 : : * stack address of "this", which is not terribly useful since
478 : : * everything will show up as [stack] when building callgraphs.
479 : : */
480 [ + + ]: 32 : if (final_string[0] != '\0')
481 : 18 : addrs[flipped] =
482 : 18 : sysprof_capture_writer_add_jitmap(self->capture, final_string);
483 : : else
484 : 14 : addrs[flipped] =
485 : 14 : reinterpret_cast<SysprofCaptureAddress>(entry.stackAddress());
486 : : }
487 : :
488 : 13 : if (!sysprof_capture_writer_add_sample(self->capture,
489 [ - + ]: 13 : now.time_since_epoch().count(), -1,
490 : 13 : self->pid, -1, addrs, depth)) {
491 : 0 : gjs_profiler_stop(self);
492 : 0 : return;
493 : : }
494 : :
495 : : unsigned ids[GJS_N_COUNTERS];
496 : : SysprofCaptureCounterValue values[GJS_N_COUNTERS];
497 : 13 : size_t new_counts = 0;
498 : :
499 : : # define FETCH_COUNTERS(name, ix) \
500 : : { \
501 : : uint64_t count = GJS_GET_COUNTER(name); \
502 : : if (count != self->last_counter_values[ix]) { \
503 : : ids[new_counts] = self->counter_base + (ix); \
504 : : values[new_counts].v64 = count; \
505 : : new_counts++; \
506 : : } \
507 : : self->last_counter_values[ix] = count; \
508 : : }
509 [ - + - + : 208 : GJS_FOR_EACH_COUNTER(FETCH_COUNTERS);
- + - + -
+ - + - +
- + - + -
+ - + - +
- + - + -
+ - + ]
510 : : # undef FETCH_COUNTERS
511 : :
512 [ - + - - ]: 13 : if (new_counts > 0 && !sysprof_capture_writer_set_counters(
513 [ - + ]: 13 : self->capture, now.time_since_epoch().count(), -1,
514 : 0 : self->pid, ids, values, new_counts))
515 : 0 : gjs_profiler_stop(self);
516 : : }
517 : :
518 : 0 : static gboolean profiler_auto_flush_cb(void* user_data) {
519 : 0 : auto* self = static_cast<GjsProfiler*>(user_data);
520 : :
521 [ # # ]: 0 : if (!self->running)
522 : 0 : return G_SOURCE_REMOVE;
523 : :
524 : 0 : sysprof_capture_writer_flush(self->capture);
525 : :
526 : 0 : return G_SOURCE_CONTINUE;
527 : : }
528 : :
529 : : #endif // ENABLE_PROFILER
530 : :
531 : : /**
532 : : * gjs_profiler_start:
533 : : * @self: A #GjsProfiler
534 : : *
535 : : * As expected, this starts the GjsProfiler.
536 : : *
537 : : * This will enable the underlying JS profiler and register a POSIX timer to
538 : : * deliver SIGPROF on the configured sampling frequency.
539 : : *
540 : : * To reduce sampling overhead, #GjsProfiler stashes information about the
541 : : * profile to be calculated once the profiler has been disabled. Calling
542 : : * gjs_profiler_stop() will result in that delayed work to be completed.
543 : : *
544 : : * You should call gjs_profiler_stop() when the profiler is no longer needed.
545 : : */
546 : 6 : void gjs_profiler_start(GjsProfiler* self) {
547 : 6 : g_return_if_fail(self);
548 [ - + ]: 6 : if (self->running)
549 : 0 : return;
550 : :
551 : : #ifdef ENABLE_PROFILER
552 : :
553 : 6 : g_return_if_fail(!self->capture);
554 : :
555 [ - + ]: 6 : if (self->target_capture) {
556 : 0 : self->capture = sysprof_capture_writer_ref(self->target_capture);
557 [ - + ]: 6 : } else if (self->fd != -1) {
558 : 0 : self->capture = sysprof_capture_writer_new_from_fd(self->fd, 0);
559 : 0 : self->fd = -1;
560 : : } else {
561 : 6 : std::string path;
562 [ + + ]: 6 : if (self->filename)
563 : 3 : path = self->filename;
564 : : else
565 : 3 : path = std::format("gjs-{}.syscap", self->pid);
566 : :
567 : 6 : self->capture = sysprof_capture_writer_new(path.c_str(), 0);
568 : 6 : }
569 : :
570 [ - + ]: 6 : if (!self->capture) {
571 : 0 : gjs_warning("Failed to open profile capture");
572 : 0 : return;
573 : : }
574 : :
575 : : // Automatically flush to be resilient against SIGINT, etc
576 [ + - ]: 6 : if (!self->periodic_flush) {
577 : 6 : self->periodic_flush =
578 : 6 : g_timeout_source_new_seconds(FLUSH_DELAY.count());
579 : 6 : g_source_set_name(self->periodic_flush,
580 : : "[sysprof-capture-writer-flush]");
581 : 6 : g_source_set_priority(self->periodic_flush, G_PRIORITY_LOW + 100);
582 : 6 : g_source_set_callback(self->periodic_flush,
583 : : G_SOURCE_FUNC(profiler_auto_flush_cb), self,
584 : : nullptr);
585 : 6 : g_source_attach(self->periodic_flush,
586 : : g_main_context_get_thread_default());
587 : : }
588 : :
589 [ - + ]: 6 : if (!gjs_profiler_extract_maps(self)) {
590 : 0 : gjs_warning("Failed to extract proc maps");
591 [ # # ]: 0 : g_clear_pointer(&self->capture, sysprof_capture_writer_unref);
592 [ # # ]: 0 : g_clear_pointer(&self->periodic_flush, g_source_destroy);
593 : 0 : return;
594 : : }
595 : :
596 [ - + ]: 6 : if (!gjs_profiler_define_counters(self)) {
597 : 0 : gjs_warning("Failed to define sysprof counters");
598 [ # # ]: 0 : g_clear_pointer(&self->capture, sysprof_capture_writer_unref);
599 [ # # ]: 0 : g_clear_pointer(&self->periodic_flush, g_source_destroy);
600 : 0 : return;
601 : : }
602 : :
603 : : // Setup our signal handler for SIGPROF delivery
604 : 6 : struct sigaction sa = {.sa_flags = SA_RESTART | SA_SIGINFO};
605 : 6 : sa.sa_sigaction = gjs_profiler_sigprof;
606 : 6 : sigemptyset(&sa.sa_mask);
607 : :
608 [ - + ]: 6 : if (sigaction(SIGPROF, &sa, nullptr) == -1) {
609 : 0 : gjs_warning("Failed to register sigaction handler: {}",
610 : : g_strerror(errno));
611 [ # # ]: 0 : g_clear_pointer(&self->capture, sysprof_capture_writer_unref);
612 [ # # ]: 0 : g_clear_pointer(&self->periodic_flush, g_source_destroy);
613 : 0 : return;
614 : : }
615 : :
616 : : /*
617 : : * Create our SIGPROF timer
618 : : *
619 : : * We want to receive a SIGPROF signal on the JS thread using our configured
620 : : * sampling frequency. Instead of allowing any thread to be notified, we set
621 : : * the _tid value to ensure that only our thread gets delivery of the
622 : : * signal. This feature is generally just for threading implementations, but
623 : : * it works for us as well and ensures that the thread is blocked while we
624 : : * capture the stack.
625 : : */
626 : 6 : struct sigevent sev = {.sigev_signo = SIGPROF,
627 : : .sigev_notify = SIGEV_THREAD_ID};
628 : 6 : sev._sigev_un._tid = syscall(__NR_gettid);
629 : :
630 [ - + ]: 6 : if (timer_create(CLOCK_MONOTONIC, &sev, &self->timer) == -1) {
631 : 0 : gjs_warning("Failed to create profiler timer: {}", g_strerror(errno));
632 [ # # ]: 0 : g_clear_pointer(&self->capture, sysprof_capture_writer_unref);
633 [ # # ]: 0 : g_clear_pointer(&self->periodic_flush, g_source_destroy);
634 : 0 : return;
635 : : }
636 : :
637 : : // Calculate sampling interval
638 : 6 : struct itimerspec its = {
639 : : .it_interval = {.tv_sec = 0,
640 : : .tv_nsec =
641 : 6 : std::chrono::nanoseconds{SAMPLING_PERIOD}.count()},
642 : : .it_value = {
643 : : .tv_sec = 0,
644 : 6 : .tv_nsec = std::chrono::nanoseconds{SAMPLING_PERIOD}.count()}};
645 : : struct itimerspec old_its;
646 : :
647 : : // Now start this timer
648 [ - + ]: 6 : if (timer_settime(self->timer, 0, &its, &old_its) != 0) {
649 : 0 : gjs_warning("Failed to enable profiler timer: {}", g_strerror(errno));
650 : 0 : timer_delete(self->timer);
651 [ # # ]: 0 : g_clear_pointer(&self->capture, sysprof_capture_writer_unref);
652 [ # # ]: 0 : g_clear_pointer(&self->periodic_flush, g_source_destroy);
653 : 0 : return;
654 : : }
655 : :
656 : 6 : self->running = true;
657 : :
658 : : // Notify the JS runtime of where to put stack info
659 : 6 : js::SetContextProfilingStack(self->cx, &self->stack);
660 : :
661 : : // Start recording stack info
662 : 6 : js::EnableContextProfilingStack(self->cx, true);
663 : :
664 : 6 : gjs_message("Profiler started");
665 : :
666 : : #else // !ENABLE_PROFILER
667 : :
668 : : self->running = true;
669 : : gjs_message("Profiler is disabled. Recompile with it enabled to use");
670 : :
671 : : #endif // ENABLE_PROFILER
672 : : }
673 : :
674 : : /**
675 : : * gjs_profiler_stop:
676 : : * @self: A #GjsProfiler
677 : : *
678 : : * Stops a currently running #GjsProfiler. If the profiler is not running, this
679 : : * function will do nothing.
680 : : *
681 : : * Some work may be delayed until the end of the capture. Such delayed work
682 : : * includes flushing the resulting samples and file location information to
683 : : * disk.
684 : : *
685 : : * This may block while writing to disk. Generally, the writes are delivered to
686 : : * a tmpfs device, and are therefore negligible.
687 : : */
688 : 6 : void gjs_profiler_stop(GjsProfiler* self) {
689 : : // Note: can be called from a signal handler
690 : :
691 : 6 : g_assert(self);
692 : :
693 [ - + ]: 6 : if (!self->running)
694 : 0 : return;
695 : :
696 : : #ifdef ENABLE_PROFILER
697 : :
698 : : // Write last value of memory counters, to avoid gaps in sysprof graph
699 : 6 : ProfilerTimePoint now = profiler_timestamp();
700 : : std::array<unsigned, GJS_N_COUNTERS> ids;
701 : : std::array<SysprofCaptureCounterValue, GJS_N_COUNTERS> values;
702 : :
703 : : # define FETCH_COUNTERS(name, ix) \
704 : : { \
705 : : uint64_t count = GJS_GET_COUNTER(name); \
706 : : ids[ix] = self->counter_base + (ix); \
707 : : values[ix].v64 = count; \
708 : : }
709 : 96 : GJS_FOR_EACH_COUNTER(FETCH_COUNTERS);
710 : : # undef FETCH_COUNTERS
711 : :
712 : 6 : if (!sysprof_capture_writer_set_counters(
713 [ - + ]: 6 : self->capture, now.time_since_epoch().count(), -1, self->pid,
714 : 12 : ids.data(), values.data(), GJS_N_COUNTERS))
715 : 0 : gjs_warning("Failed to write last value of memory counters");
716 : :
717 : 6 : struct itimerspec its = {.it_interval = {.tv_sec = 0}};
718 : 6 : timer_settime(self->timer, 0, &its, nullptr);
719 : 6 : timer_delete(self->timer);
720 : :
721 : 6 : js::EnableContextProfilingStack(self->cx, false);
722 : 6 : js::SetContextProfilingStack(self->cx, nullptr);
723 : :
724 : 6 : sysprof_capture_writer_flush(self->capture);
725 : :
726 [ + - ]: 6 : g_clear_pointer(&self->capture, sysprof_capture_writer_unref);
727 [ + - ]: 6 : g_clear_pointer(&self->periodic_flush, g_source_destroy);
728 : :
729 : 6 : gjs_message("Profiler stopped");
730 : :
731 : : #endif // ENABLE_PROFILER
732 : :
733 : 6 : self->running = false;
734 : : }
735 : :
736 : : #ifdef ENABLE_PROFILER
737 : :
738 : 0 : static gboolean gjs_profiler_sigusr2(void* data) {
739 : 0 : GjsContext* gjs_context = GJS_CONTEXT(data);
740 : 0 : GjsProfiler* current_profiler = gjs_context_get_profiler(gjs_context);
741 : :
742 [ # # ]: 0 : if (current_profiler) {
743 [ # # ]: 0 : if (gjs_profiler_is_running(current_profiler))
744 : 0 : gjs_profiler_stop(current_profiler);
745 : : else
746 : 0 : gjs_profiler_start(current_profiler);
747 : : }
748 : :
749 : 0 : return G_SOURCE_CONTINUE;
750 : : }
751 : :
752 : : #endif // ENABLE_PROFILER
753 : :
754 : : /**
755 : : * gjs_profiler_setup_signals:
756 : : * @gjs_context: a #GjsContext with a profiler attached
757 : : *
758 : : * If you want to simply allow profiling of your process with minimal fuss,
759 : : * simply call gjs_profiler_setup_signals(). This will allow enabling and
760 : : * disabling the profiler with SIGUSR2. You must call this from main()
761 : : * immediately when your program starts and must not block SIGUSR2 from your
762 : : * signal mask.
763 : : *
764 : : * If this is not sufficient, use gjs_profiler_chain_signal() from your own
765 : : * signal handler to pass the signal to a GjsProfiler.
766 : : */
767 : 0 : void gjs_profiler_setup_signals(GjsProfiler* self, GjsContext* gjs_context) {
768 : 0 : g_return_if_fail(gjs_context == profiling_context);
769 : :
770 : : #ifdef ENABLE_PROFILER
771 : :
772 [ # # ]: 0 : if (self->sigusr2_id != 0)
773 : 0 : return;
774 : :
775 : 0 : self->sigusr2_id =
776 : 0 : g_unix_signal_add(SIGUSR2, gjs_profiler_sigusr2, gjs_context);
777 : :
778 : : #else // !ENABLE_PROFILER
779 : :
780 : : gjs_message("Profiler is disabled. Not setting up signals");
781 : : (void)self;
782 : :
783 : : #endif // ENABLE_PROFILER
784 : : }
785 : :
786 : : /**
787 : : * gjs_profiler_chain_signal:
788 : : * @gjs_context: a #GjsContext with a profiler attached
789 : : * @info: #siginfo_t passed in to signal handler
790 : : *
791 : : * Use this to pass a signal info caught by another signal handler to a
792 : : * GjsProfiler. This might be needed if you have your own complex signal
793 : : * handling system for which GjsProfiler cannot simply add a SIGUSR2 handler.
794 : : *
795 : : * This function should only be called from the JS thread.
796 : : *
797 : : * Returns: true if the signal was handled.
798 : : */
799 : 0 : bool gjs_profiler_chain_signal(GjsContext* gjs_context, siginfo_t* info) {
800 : : #ifdef ENABLE_PROFILER
801 : :
802 [ # # ]: 0 : if (info) {
803 [ # # ]: 0 : if (info->si_signo == SIGPROF) {
804 : 0 : gjs_profiler_sigprof(SIGPROF, info, nullptr);
805 : 0 : return true;
806 : : }
807 : :
808 [ # # ]: 0 : if (info->si_signo == SIGUSR2) {
809 : 0 : gjs_profiler_sigusr2(gjs_context);
810 : 0 : return true;
811 : : }
812 : : }
813 : :
814 : : #else // !ENABLE_PROFILER
815 : :
816 : : (void)gjs_context;
817 : : (void)info;
818 : :
819 : : #endif // ENABLE_PROFILER
820 : :
821 : 0 : return false;
822 : : }
823 : :
824 : : /**
825 : : * gjs_profiler_set_capture_writer:
826 : : * @self: A #GjsProfiler
827 : : * @capture: (nullable): A #SysprofCaptureWriter
828 : : *
829 : : * Set the capture writer to which profiling data is written when the @self is
830 : : * stopped.
831 : : */
832 : 0 : void gjs_profiler_set_capture_writer(GjsProfiler* self, void* capture) {
833 : 0 : g_return_if_fail(self);
834 : 0 : g_return_if_fail(!self->running);
835 : :
836 : : #ifdef ENABLE_PROFILER
837 [ # # ]: 0 : g_clear_pointer(&self->target_capture, sysprof_capture_writer_unref);
838 : 0 : self->target_capture =
839 [ # # ]: 0 : capture ? sysprof_capture_writer_ref(
840 : : reinterpret_cast<SysprofCaptureWriter*>(capture))
841 : : : nullptr;
842 : : #else
843 : : // Unused in the no-profiler case
844 : : (void)capture;
845 : : #endif
846 : : }
847 : :
848 : : /**
849 : : * gjs_profiler_set_filename:
850 : : * @self: A #GjsProfiler
851 : : * @filename: string containing a filename
852 : : *
853 : : * Set the file to which profiling data is written when the @self is stopped. By
854 : : * default, this is `gjs-$PID.syscap` in the current directory.
855 : : */
856 : 3 : void gjs_profiler_set_filename(GjsProfiler* self, const char* filename) {
857 : 3 : g_return_if_fail(self);
858 : 3 : g_return_if_fail(!self->running);
859 : :
860 [ - + ]: 3 : g_free(self->filename);
861 : 3 : self->filename = g_strdup(filename);
862 : : }
863 : :
864 : 0 : void gjs_profiler_add_mark(GjsProfiler* self, ProfilerTimePoint time,
865 : : ProfilerDuration duration, const char* group,
866 : : const char* name, const char* message) {
867 : 0 : g_return_if_fail(self);
868 : 0 : g_return_if_fail(group);
869 : 0 : g_return_if_fail(name);
870 : :
871 : : #ifdef ENABLE_PROFILER
872 [ # # # # ]: 0 : if (self->running && self->capture != nullptr) {
873 : 0 : sysprof_capture_writer_add_mark(
874 : 0 : self->capture, time.time_since_epoch().count(), -1, self->pid,
875 : : duration.count(), group, name, message);
876 : : }
877 : : #else
878 : : // Unused in the no-profiler case
879 : : (void)time;
880 : : (void)duration;
881 : : (void)message;
882 : : #endif
883 : : }
884 : :
885 : 0 : bool gjs_profiler_sample_gc_memory_info(
886 : : GjsProfiler* self, const int64_t gc_counters[Gjs::GCCounters::N_COUNTERS]) {
887 : 0 : g_return_val_if_fail(self, false);
888 : :
889 : : #ifdef ENABLE_PROFILER
890 [ # # # # ]: 0 : if (self->running && self->capture) {
891 : : unsigned ids[Gjs::GCCounters::N_COUNTERS];
892 : : SysprofCaptureCounterValue values[Gjs::GCCounters::N_COUNTERS];
893 : :
894 [ # # ]: 0 : for (size_t ix = 0; ix < Gjs::GCCounters::N_COUNTERS; ix++) {
895 : 0 : ids[ix] = self->gc_counter_base + ix;
896 : 0 : values[ix].v64 = gc_counters[ix];
897 : : }
898 : :
899 : 0 : ProfilerTimePoint time = profiler_timestamp();
900 : 0 : if (!sysprof_capture_writer_set_counters(
901 [ # # ]: 0 : self->capture, time.time_since_epoch().count(), -1, self->pid,
902 : : ids, values, Gjs::GCCounters::N_COUNTERS))
903 : 0 : return false;
904 : : }
905 : : #else
906 : : // Unused in the no-profiler case
907 : : (void)gc_counters;
908 : : #endif
909 : 0 : return true;
910 : : }
911 : :
912 : 0 : void gjs_profiler_set_fd(GjsProfiler* self, int fd) {
913 : 0 : g_return_if_fail(self);
914 : 0 : g_return_if_fail(!self->filename);
915 : 0 : g_return_if_fail(!self->running);
916 : :
917 : : #ifdef ENABLE_PROFILER
918 [ # # ]: 0 : if (self->fd != fd) {
919 [ # # ]: 0 : if (self->fd != -1)
920 : 0 : close(self->fd);
921 : 0 : self->fd = fd;
922 : : }
923 : : #else
924 : : (void)fd; // Unused in the no-profiler case
925 : : #endif
926 : : }
927 : :
928 : 0 : void gjs_profiler_set_finalize_status(GjsProfiler* self,
929 : : JSFinalizeStatus status) {
930 : : #ifdef ENABLE_PROFILER
931 : : // Implementation note for mozjs-140:
932 : : //
933 : : // Sweeping happens in three phases:
934 : : //
935 : : // 1st phase (JSFINALIZE_GROUP_PREPARE): the collector prepares to sweep a
936 : : // group of zones.
937 : : //
938 : : // 2nd phase (JSFINALIZE_GROUP_START): weak references to unmarked things
939 : : // have been removed, but no GC thing has been swept.
940 : : //
941 : : // 3rd Phase (JSFINALIZE_GROUP_END): all dead GC things for a group of zones
942 : : // have been swept. The above repeats for each sweep group.
943 : : //
944 : : // JSFINALIZE_COLLECTION_END occurs at the end of all GC. (see
945 : : // js/src/gc/GC.cpp, GCRuntime::beginSweepPhase, beginSweepingSweepGroup,
946 : : // and endSweepPhase, all called from incrementalSlice).
947 : : //
948 : : // Incremental GC muddies the waters, because BeginSweepPhase is always run
949 : : // to entirety, but SweepPhase can be run incrementally and mixed with JS
950 : : // code runs or even native code, when MaybeGC/IncrementalGC return. After
951 : : // GROUP_START, the collector may yield to the mutator meaning JS code can
952 : : // run between the callback for GROUP_START and GROUP_END.
953 : :
954 : 0 : ProfilerTimePoint now = profiler_timestamp();
955 : :
956 [ # # # # : 0 : switch (status) {
# ]
957 : 0 : case JSFINALIZE_GROUP_PREPARE:
958 : 0 : self->sweep_begin_time = Some(now);
959 : 0 : break;
960 : 0 : case JSFINALIZE_GROUP_START:
961 : 0 : self->group_sweep_begin_time = Some(now);
962 : 0 : break;
963 : 0 : case JSFINALIZE_GROUP_END:
964 [ # # ]: 0 : if (self->group_sweep_begin_time) {
965 : 0 : gjs_profiler_add_mark(self, *self->group_sweep_begin_time,
966 : 0 : now - *self->group_sweep_begin_time,
967 : : "GJS", "Group sweep", nullptr);
968 : : }
969 : 0 : self->group_sweep_begin_time = Nothing{};
970 : 0 : break;
971 : 0 : case JSFINALIZE_COLLECTION_END:
972 [ # # ]: 0 : if (self->sweep_begin_time) {
973 : 0 : gjs_profiler_add_mark(self, *self->sweep_begin_time,
974 : 0 : now - *self->sweep_begin_time, "GJS",
975 : : "Sweep", nullptr);
976 : : }
977 : 0 : self->sweep_begin_time = Nothing{};
978 : 0 : break;
979 : 0 : default:
980 : : g_assert_not_reached();
981 : : }
982 : : #else
983 : : (void)self;
984 : : (void)status;
985 : : #endif
986 : 0 : }
987 : :
988 : 0 : void gjs_profiler_set_gc_status(GjsProfiler* self, JSGCStatus status,
989 : : JS::GCReason reason) {
990 : : #ifdef ENABLE_PROFILER
991 : 0 : ProfilerTimePoint now = profiler_timestamp();
992 : :
993 [ # # # ]: 0 : switch (status) {
994 : 0 : case JSGC_BEGIN:
995 : 0 : self->gc_begin_time = Some(now);
996 : 0 : self->gc_reason = gjs_explain_gc_reason(reason);
997 : 0 : break;
998 : 0 : case JSGC_END:
999 [ # # ]: 0 : if (self->gc_begin_time) {
1000 : 0 : gjs_profiler_add_mark(self, *self->gc_begin_time,
1001 : 0 : now - *self->gc_begin_time, "GJS",
1002 : : "Garbage collection", self->gc_reason);
1003 : : }
1004 : 0 : self->gc_begin_time = Nothing{};
1005 : 0 : self->gc_reason = nullptr;
1006 : 0 : break;
1007 : 0 : default:
1008 : : g_assert_not_reached();
1009 : : }
1010 : : #else
1011 : : (void)self;
1012 : : (void)status;
1013 : : (void)reason;
1014 : : #endif
1015 : 0 : }
|
