// Copyright 2020 The ChromiumOS Authors // Use of this source code is governed by a BSD-style license that can be // found in the LICENSE file. #include "sommelier-tracing.h" // NOLINT(build/include_directory) #include #include #include #include #include #include #include #include #include #include #include "sommelier.h" // NOLINT(build/include_directory) #include "sommelier-ctx.h" // NOLINT(build/include_directory) #if defined(_M_IA64) || defined(_M_IX86) || defined(__ia64__) || \ defined(__i386__) || defined(__amd64__) || defined(__x86_64__) || \ defined(_M_AMD64) #define HAS_RDTSC #ifdef _MSC_VER #include #else #include #endif #endif #if defined(_M_ARM) || defined(_M_ARMT) || defined(__arm__) || \ defined(__thumb__) || defined(__aarch64__) // TODO(jbates): support ARM CPU counter #endif #if defined(PERFETTO_TRACING) PERFETTO_TRACK_EVENT_STATIC_STORAGE(); std::unique_ptr tracing_session; void initialize_tracing(bool in_process_backend, bool system_backend) { perfetto::TracingInitArgs args; if (in_process_backend) { args.backends |= perfetto::kInProcessBackend; } if (system_backend) { args.backends |= perfetto::kSystemBackend; } perfetto::Tracing::Initialize(args); perfetto::TrackEvent::Register(); } void enable_tracing(bool create_session) { perfetto::TraceConfig cfg; cfg.add_buffers()->set_size_kb(1024); // Record up to 1 MiB. auto* ds_cfg = cfg.add_data_sources()->mutable_config(); ds_cfg->set_name("track_event"); if (create_session) { tracing_session = perfetto::Tracing::NewTrace(); tracing_session->Setup(cfg); tracing_session->StartBlocking(); } } void dump_trace(const char* trace_filename) { if (!trace_filename || !*trace_filename || !tracing_session) { return; } std::vector trace_data(tracing_session->ReadTraceBlocking()); // Write the trace into a file. int fd = open(trace_filename, O_RDWR | O_CREAT | O_TRUNC, 0644); if (fd == -1) { fprintf(stderr, "error: unable to open trace file %s: %s\n", trace_filename, strerror(errno)); return; } size_t pos = 0; do { ssize_t ret = write(fd, &trace_data[pos], trace_data.size() - pos); if (ret < 0) { if (errno == EINTR || errno == EAGAIN) { continue; } fprintf(stderr, "error: unable to write trace file %s: %s\n", trace_filename, strerror(errno)); close(fd); return; } pos += ret; } while (pos < trace_data.size()); close(fd); } // Returns NULL if atom is not recognized. static const char* xcb_atom_to_string(uint32_t atom) { switch (atom) { case XCB_ATOM_NONE: return "XCB_ATOM_NONE"; case XCB_ATOM_PRIMARY: return "XCB_ATOM_PRIMARY"; case XCB_ATOM_SECONDARY: return "XCB_ATOM_SECONDARY"; case XCB_ATOM_ARC: return "XCB_ATOM_ARC"; case XCB_ATOM_ATOM: return "XCB_ATOM_ATOM"; case XCB_ATOM_BITMAP: return "XCB_ATOM_BITMAP"; case XCB_ATOM_CARDINAL: return "XCB_ATOM_CARDINAL"; case XCB_ATOM_COLORMAP: return "XCB_ATOM_COLORMAP"; case XCB_ATOM_CURSOR: return "XCB_ATOM_CURSOR"; case XCB_ATOM_CUT_BUFFER0: return "XCB_ATOM_CUT_BUFFER0"; case XCB_ATOM_CUT_BUFFER1: return "XCB_ATOM_CUT_BUFFER1"; case XCB_ATOM_CUT_BUFFER2: return "XCB_ATOM_CUT_BUFFER2"; case XCB_ATOM_CUT_BUFFER3: return "XCB_ATOM_CUT_BUFFER3"; case XCB_ATOM_CUT_BUFFER4: return "XCB_ATOM_CUT_BUFFER4"; case XCB_ATOM_CUT_BUFFER5: return "XCB_ATOM_CUT_BUFFER5"; case XCB_ATOM_CUT_BUFFER6: return "XCB_ATOM_CUT_BUFFER6"; case XCB_ATOM_CUT_BUFFER7: return "XCB_ATOM_CUT_BUFFER7"; case XCB_ATOM_DRAWABLE: return "XCB_ATOM_DRAWABLE"; case XCB_ATOM_FONT: return "XCB_ATOM_FONT"; case XCB_ATOM_INTEGER: return "XCB_ATOM_INTEGER"; case XCB_ATOM_PIXMAP: return "XCB_ATOM_PIXMAP"; case XCB_ATOM_POINT: return "XCB_ATOM_POINT"; case XCB_ATOM_RECTANGLE: return "XCB_ATOM_RECTANGLE"; case XCB_ATOM_RESOURCE_MANAGER: return "XCB_ATOM_RESOURCE_MANAGER"; case XCB_ATOM_RGB_COLOR_MAP: return "XCB_ATOM_RGB_COLOR_MAP"; case XCB_ATOM_RGB_BEST_MAP: return "XCB_ATOM_RGB_BEST_MAP"; case XCB_ATOM_RGB_BLUE_MAP: return "XCB_ATOM_RGB_BLUE_MAP"; case XCB_ATOM_RGB_DEFAULT_MAP: return "XCB_ATOM_RGB_DEFAULT_MAP"; case XCB_ATOM_RGB_GRAY_MAP: return "XCB_ATOM_RGB_GRAY_MAP"; case XCB_ATOM_RGB_GREEN_MAP: return "XCB_ATOM_RGB_GREEN_MAP"; case XCB_ATOM_RGB_RED_MAP: return "XCB_ATOM_RGB_RED_MAP"; case XCB_ATOM_STRING: return "XCB_ATOM_STRING"; case XCB_ATOM_VISUALID: return "XCB_ATOM_VISUALID"; case XCB_ATOM_WINDOW: return "XCB_ATOM_WINDOW"; case XCB_ATOM_WM_COMMAND: return "XCB_ATOM_WM_COMMAND"; case XCB_ATOM_WM_HINTS: return "XCB_ATOM_WM_HINTS"; case XCB_ATOM_WM_CLIENT_MACHINE: return "XCB_ATOM_WM_CLIENT_MACHINE"; case XCB_ATOM_WM_ICON_NAME: return "XCB_ATOM_WM_ICON_NAME"; case XCB_ATOM_WM_ICON_SIZE: return "XCB_ATOM_WM_ICON_SIZE"; case XCB_ATOM_WM_NAME: return "XCB_ATOM_WM_NAME"; case XCB_ATOM_WM_NORMAL_HINTS: return "XCB_ATOM_WM_NORMAL_HINTS"; case XCB_ATOM_WM_SIZE_HINTS: return "XCB_ATOM_WM_SIZE_HINTS"; case XCB_ATOM_WM_ZOOM_HINTS: return "XCB_ATOM_WM_ZOOM_HINTS"; case XCB_ATOM_MIN_SPACE: return "XCB_ATOM_MIN_SPACE"; case XCB_ATOM_NORM_SPACE: return "XCB_ATOM_NORM_SPACE"; case XCB_ATOM_MAX_SPACE: return "XCB_ATOM_MAX_SPACE"; case XCB_ATOM_END_SPACE: return "XCB_ATOM_END_SPACE"; case XCB_ATOM_SUPERSCRIPT_X: return "XCB_ATOM_SUPERSCRIPT_X"; case XCB_ATOM_SUPERSCRIPT_Y: return "XCB_ATOM_SUPERSCRIPT_Y"; case XCB_ATOM_SUBSCRIPT_X: return "XCB_ATOM_SUBSCRIPT_X"; case XCB_ATOM_SUBSCRIPT_Y: return "XCB_ATOM_SUBSCRIPT_Y"; case XCB_ATOM_UNDERLINE_POSITION: return "XCB_ATOM_UNDERLINE_POSITION"; case XCB_ATOM_UNDERLINE_THICKNESS: return "XCB_ATOM_UNDERLINE_THICKNESS"; case XCB_ATOM_STRIKEOUT_ASCENT: return "XCB_ATOM_STRIKEOUT_ASCENT"; case XCB_ATOM_STRIKEOUT_DESCENT: return "XCB_ATOM_STRIKEOUT_DESCENT"; case XCB_ATOM_ITALIC_ANGLE: return "XCB_ATOM_ITALIC_ANGLE"; case XCB_ATOM_X_HEIGHT: return "XCB_ATOM_X_HEIGHT"; case XCB_ATOM_QUAD_WIDTH: return "XCB_ATOM_QUAD_WIDTH"; case XCB_ATOM_WEIGHT: return "XCB_ATOM_WEIGHT"; case XCB_ATOM_POINT_SIZE: return "XCB_ATOM_POINT_SIZE"; case XCB_ATOM_RESOLUTION: return "XCB_ATOM_RESOLUTION"; case XCB_ATOM_COPYRIGHT: return "XCB_ATOM_COPYRIGHT"; case XCB_ATOM_NOTICE: return "XCB_ATOM_NOTICE"; case XCB_ATOM_FONT_NAME: return "XCB_ATOM_FONT_NAME"; case XCB_ATOM_FAMILY_NAME: return "XCB_ATOM_FAMILY_NAME"; case XCB_ATOM_FULL_NAME: return "XCB_ATOM_FULL_NAME"; case XCB_ATOM_CAP_HEIGHT: return "XCB_ATOM_CAP_HEIGHT"; case XCB_ATOM_WM_CLASS: return "XCB_ATOM_WM_CLASS"; case XCB_ATOM_WM_TRANSIENT_FOR: return "XCB_ATOM_WM_TRANSIENT_FOR"; default: return NULL; } } // Annotate with the string representation of an atom. // // Supports well-known XCB atoms, and the fetched sl_context::atoms list. (To // add an atom you're interested in debugging, modify |sl_context_atom_name|.) void perfetto_annotate_atom(struct sl_context* ctx, const perfetto::EventContext& perfetto, const char* event_name, xcb_atom_t atom) { auto* dbg = perfetto.event()->add_debug_annotations(); dbg->set_name(event_name); // Quickest option is to look up the XCB atoms, which have static values. const char* atom_str = xcb_atom_to_string(atom); if (atom_str) { dbg->set_string_value(atom_str, strlen(atom_str)); return; } // Failing that, check if we've fetched this atom. for (unsigned i = 0; i < ARRAY_SIZE(ctx->atoms); ++i) { if (atom == ctx->atoms[i].value) { const char* name = sl_context_atom_name(i); if (name != nullptr) { dbg->set_string_value(name, strlen(name)); return; } } } // If we reach here, we didn't find the atom name. // We could ask the X server but that would require a round-trip. std::string unknown("set_string_value(unknown); } void perfetto_annotate_xcb_property_state(const perfetto::EventContext& event, const char* name, unsigned int state) { auto* dbg = event.event()->add_debug_annotations(); dbg->set_name(name); if (state == XCB_PROPERTY_NEW_VALUE) { static const std::string prop_new("XCB_PROPERTY_NEW_VALUE"); dbg->set_string_value(prop_new); } else if (state == XCB_PROPERTY_DELETE) { static const std::string prop_delete("XCB_PROPERTY_DELETE"); dbg->set_string_value(prop_delete); } else { static const std::string unknown(""); dbg->set_string_value(unknown); } } // Annotate the given Perfetto EventContext with the name (if known) and the ID // of the given window. // // Slow (iterates a linked list); only intended to be called if tracing is // enabled. void perfetto_annotate_window(struct sl_context* ctx, const perfetto::EventContext& perfetto, const char* event_name, xcb_window_t window_id) { auto* dbg = perfetto.event()->add_debug_annotations(); dbg->set_name(event_name); struct sl_window* window = sl_lookup_window(ctx, window_id); std::ostringstream value; if (window != NULL && window->name != NULL) { value << window->name << " '; dbg->set_string_value(value.str()); } void perfetto_annotate_size_hints(const perfetto::EventContext& perfetto, const sl_wm_size_hints& size_hints) { auto* dbg = perfetto.event()->add_debug_annotations(); dbg->set_name("size_hints.flags"); std::string flags; if (size_hints.flags & US_POSITION) flags += "US_POSITION|"; if (size_hints.flags & US_SIZE) flags += "US_SIZE|"; if (size_hints.flags & P_POSITION) flags += "P_POSITION|"; if (size_hints.flags & P_SIZE) flags += "P_SIZE|"; if (size_hints.flags & P_MIN_SIZE) flags += "P_MIN_SIZE|"; if (size_hints.flags & P_MAX_SIZE) flags += "P_MAX_SIZE|"; if (size_hints.flags & P_RESIZE_INC) flags += "P_RESIZE_INC|"; if (size_hints.flags & P_ASPECT) flags += "P_ASPECT|"; if (size_hints.flags & P_BASE_SIZE) flags += "P_BASE_SIZE|"; if (size_hints.flags & P_WIN_GRAVITY) flags += "P_WIN_GRAVITY|"; if (!flags.empty()) flags.pop_back(); // remove trailing '|' dbg->set_string_value(flags); dbg = perfetto.event()->add_debug_annotations(); dbg->set_name("size_hints.x"); dbg->set_int_value(size_hints.x); dbg = perfetto.event()->add_debug_annotations(); dbg->set_name("size_hints.y"); dbg->set_int_value(size_hints.y); dbg = perfetto.event()->add_debug_annotations(); dbg->set_name("size_hints.width"); dbg->set_int_value(size_hints.width); dbg = perfetto.event()->add_debug_annotations(); dbg->set_name("size_hints.height"); dbg->set_int_value(size_hints.height); dbg = perfetto.event()->add_debug_annotations(); dbg->set_name("size_hints.min_width"); dbg->set_int_value(size_hints.min_width); dbg = perfetto.event()->add_debug_annotations(); dbg->set_name("size_hints.min_height"); dbg->set_int_value(size_hints.min_height); dbg = perfetto.event()->add_debug_annotations(); dbg->set_name("size_hints.max_width"); dbg->set_int_value(size_hints.max_width); dbg = perfetto.event()->add_debug_annotations(); dbg->set_name("size_hints.max_height"); dbg->set_int_value(size_hints.max_height); dbg = perfetto.event()->add_debug_annotations(); dbg->set_name("size_hints.width_inc"); dbg->set_int_value(size_hints.width_inc); dbg = perfetto.event()->add_debug_annotations(); dbg->set_name("size_hints.height_inc"); dbg->set_int_value(size_hints.height_inc); dbg = perfetto.event()->add_debug_annotations(); dbg->set_name("size_hints.min_aspect.x"); dbg->set_int_value(size_hints.min_aspect.x); dbg = perfetto.event()->add_debug_annotations(); dbg->set_name("size_hints.min_aspect.y"); dbg->set_int_value(size_hints.min_aspect.y); dbg = perfetto.event()->add_debug_annotations(); dbg->set_name("size_hints.max_aspect.x"); dbg->set_int_value(size_hints.max_aspect.x); dbg = perfetto.event()->add_debug_annotations(); dbg->set_name("size_hints.max_aspect.y"); dbg->set_int_value(size_hints.max_aspect.y); dbg = perfetto.event()->add_debug_annotations(); dbg->set_name("size_hints.base_width"); dbg->set_int_value(size_hints.base_width); dbg = perfetto.event()->add_debug_annotations(); dbg->set_name("size_hints.base_height"); dbg->set_int_value(size_hints.base_height); dbg = perfetto.event()->add_debug_annotations(); dbg->set_name("size_hints.win_gravity"); dbg->set_int_value(size_hints.win_gravity); } // Add a Perfetto annotation for an X property storing a list of cardinals. void perfetto_annotate_cardinal_list(const perfetto::EventContext& perfetto, const char* event_name, xcb_get_property_reply_t* reply) { auto* dbg = perfetto.event()->add_debug_annotations(); dbg->set_name(event_name); if (reply == nullptr) { static const std::string null_str(""); dbg->set_string_value(null_str); return; } uint32_t length = xcb_get_property_value_length(reply); if (length % sizeof(uint32_t) != 0) { static const std::string invalid(""); dbg->set_string_value(invalid); return; } uint32_t* val = static_cast(xcb_get_property_value(reply)); uint32_t items = length / sizeof(uint32_t); if (items == 0) { static const std::string empty(""); dbg->set_string_value(empty); return; } std::ostringstream str; str << '[' << val[0]; for (uint32_t i = 1; i < items; ++i) { str << ", " << val[i]; } str << ']'; dbg->set_string_value(str.str()); } static inline uint64_t get_cpu_ticks() { #ifdef HAS_RDTSC return __rdtsc(); #else return 0; #endif } static inline uint64_t get_timestamp_ns(clockid_t cid) { struct timespec ts = {}; clock_gettime(cid, &ts); return static_cast(ts.tv_sec * 1000000000LL + ts.tv_nsec); } void perfetto_annotate_time_sync(const perfetto::EventContext& perfetto) { uint64_t boot_time = get_timestamp_ns(CLOCK_BOOTTIME); uint64_t cpu_time = get_cpu_ticks(); uint64_t monotonic_time = get_timestamp_ns(CLOCK_MONOTONIC); // Read again to avoid cache miss overhead. boot_time = get_timestamp_ns(CLOCK_BOOTTIME); cpu_time = get_cpu_ticks(); monotonic_time = get_timestamp_ns(CLOCK_MONOTONIC); auto* dbg = perfetto.event()->add_debug_annotations(); dbg->set_name("clock_sync_boottime"); dbg->set_uint_value(boot_time); dbg = perfetto.event()->add_debug_annotations(); dbg->set_name("clock_sync_monotonic"); dbg->set_uint_value(monotonic_time); dbg = perfetto.event()->add_debug_annotations(); dbg->set_name("clock_sync_cputime"); dbg->set_uint_value(cpu_time); } #else // Stubs. void initialize_tracing(bool in_process_backend, bool system_backend) {} void enable_tracing(bool create_session) {} void dump_trace(const char* trace_filename) {} #endif // PERFETTO_TRACING