// #endif G_OS_UNIX
};
+struct _GDBusMethodInvocation
+{
+ /*< private >*/
+ struct GObject parent_instance;
+
+ /* construct-only properties */
+ ptr_t sender; // const gchar *
+ ptr_t object_path; // const gchar *;
+ ptr_t interface_name ;// const gchar *;
+ ptr_t method_name; // const gchar *;
+ ptr_t method_info; // GDBusMethodInfo *
+ ptr_t property_info; // GDBusPropertyInfo *
+ ptr_t connection; // GDBusConnection *
+ ptr_t message; // GDBusMessage *
+ ptr_t parameters; // GVariant *
+ ptr_t user_data; // gpointer
+};
+
#endif // HOSTCOMPAT_GIO_H
--- /dev/null
+#include <hostcompat/linux/sched.h>
+#include <hostcompat/uapi/linux/ptrace.h>
+#include <hostcompat/dbus/gio.h>
+#include "dbus-glib-tools.h"
+
+/* This histogram is meant to keep time intervals used for preparing a message to send
+ * by the sending API, just before such message is passed to 'gdbus' thread. */
+BPF_HISTOGRAM(timings);
+
+/* This hashmap contains mapping from a message pointer to a timestamp.
+ * It is meant to keep timestamps of using the sending API. */
+BPF_HASH(msg_sending, key_pointer_t, timestamp_value_t);
+
+int handle_send_message(struct pt_regs *ctx,
+ void *connection, /* GDBusConnection */
+ struct GDBusMessage *message
+ /* we don't care about the rest of arguments */
+ ) {
+ key_pointer_t key;
+ timestamp_value_t value;
+
+ key_pointer_set_pointer(&key, message);
+ timestamp_value_set_timestamp(&value);
+
+ msg_sending.update(&key, &value);
+ return 0;
+}
+
+int handle_worker_send_message(struct pt_regs *ctx,
+ void *worker,
+ struct GDBusMessage *message,
+ char *blob,
+ size_t blob_len) {
+ key_pointer_t key;
+ timestamp_value_t *value;
+ u64 timestamp = get_current_timestamp();
+
+ key_pointer_set_pointer(&key, message);
+ value = msg_sending.lookup(&key);
+ if (value == 0)
+ return 0;
+
+ timestamp -= timestamp_value_get_timestamp(value);
+ msg_sending.delete(&key);
+
+ timings.increment(bpf_log2l(ns_to_us(timestamp)));
+
+ return 0;
+}
+
+int handle_message_delete(struct pt_regs *ctx, struct GDBusMessage *msg) {
+ key_pointer_t key;
+ key_pointer_set_pointer(&key, msg);
+ msg_sending.delete(&key);
+ return 0;
+}
--- /dev/null
+#!/usr/bin/python3
+
+from bcc import BPF
+from time import sleep
+import argparse
+
+parser = argparse.ArgumentParser(
+ description="Measure time interval between using the sending API for a message and handling it in a gdbus thread in glib",
+ formatter_class=argparse.RawDescriptionHelpFormatter)
+parser.add_argument("interval", nargs="?", default=2,
+ help="output interval, in seconds")
+parser.add_argument("count", nargs="?", default=-1,
+ help="number of outputs")
+
+args = parser.parse_args()
+interval = int(args.interval)
+loop = 0
+count = int(args.count)
+
+b = BPF(src_file="dbus-glib-client-sending.c")
+
+# Setup uprobes
+
+# ****** General
+b.attach_uprobe(name="gio-2.0", sym="g_dbus_connection_send_message_unlocked", fn_name="handle_send_message")
+b.attach_uprobe(name="gio-2.0", sym="_g_dbus_worker_send_message", fn_name="handle_worker_send_message")
+# this uprobe function detects destroying of a message and removes any existing references
+b.attach_uprobe(name="gio-2.0", sym="g_dbus_message_finalize", fn_name="handle_message_delete")
+
+# GO!
+print("Hit Ctrl-C to end.")
+
+while (1):
+ sleep(interval)
+ loop = loop + 1
+ print("\n%d:" % loop)
+ b["timings"].print_log2_hist("us")
+
+ # Kinda debug part, but important - it shows any leftovers in hashmaps.
+ # This way, if it shows up, we can tell how bad it is.
+ msgs = len(b["msg_sending"].items())
+
+ if msgs > 0:
+ print(" containers stats:")
+ print(' msg_sending:', msgs)
+
+ if count == loop:
+ print('Finished')
+ break
--- /dev/null
+#include <hostcompat/linux/sched.h>
+#include <hostcompat/uapi/linux/ptrace.h>
+#include <hostcompat/dbus/gio.h>
+#include "dbus-glib-tools.h"
+/*
+ * This file contains functions aimed to measure the time interval between receiving a message and
+ * making it available in a target thread.
+ * They are meant to be compiled to eBPF byte code, and attached to appropriate uprobes.
+ *
+ * The general idea is:
+ * 1. Detect receiving of a message in on_worker_message_received
+ * Record timestamp: map message (serial, pointer?) -> timestamp
+ * key: (pid, pointer)
+ * value: timestamp
+ * 2. Detect first (possible) occurrence in a client thread, where the message data is available.
+ * The exact functions and data tracing flow depend on the message type.
+ * 3. Measure the time between 1 and 2.
+ */
+
+/* This hashmap contains mapping from a message pointer to a timestamp.
+ * It is meant to keep timestamps of detection of message receiving. */
+BPF_HASH(msg_on_worker_received, key_pointer_t, timestamp_value_t);
+
+/* This histogram is meant to keep time intervals between detection of a message receiving
+ * and making its data available in a target thread. */
+BPF_HISTOGRAM(timings);
+
+int handle_on_worker_received(struct pt_regs *ctx, struct GDBusMessage *msg, void *user_data) {
+ key_pointer_t key;
+ timestamp_value_t value;
+
+ key_pointer_set_pointer(&key, msg);
+ timestamp_value_set_timestamp(&value);
+
+ msg_on_worker_received.update(&key, &value);
+ return 0;
+}
+
+int handle_message_delete(struct pt_regs *ctx, struct GDBusMessage *msg) {
+ key_pointer_t key;
+ key_pointer_set_pointer(&key, msg);
+ msg_on_worker_received.delete(&key);
+ return 0;
+}
+
+/********** method calls *************/
+struct value_msg_ptr_t {
+ struct GDBusMessage *msg_ptr;
+};
+typedef struct value_msg_ptr_t value_msg_ptr_t;
+
+static void value_msg_ptr_set_msg_ptr(value_msg_ptr_t *value, void *msg_ptr) {
+ value->msg_ptr = (struct GDBusMessage *)msg_ptr;
+}
+static struct GDBusMessage *value_msg_ptr_get_msg_ptr(value_msg_ptr_t *value) {
+ return value->msg_ptr;
+}
+
+/* There is an intermediate step for method calls - we track creation of
+ * GDBusMethodInvocation for a given message, and then we track when
+ * it is about to be used */
+/* This hashmap tracks invocation->message relationships */
+BPF_HASH(invocation_to_message, key_pointer_t, value_msg_ptr_t);
+
+int handle_ret_method_invocation_new(struct pt_regs *ctx) {
+ struct _GDBusMethodInvocation *invocation_ptr =
+ (struct _GDBusMethodInvocation *)PT_REGS_RC(ctx);
+ key_pointer_t key;
+ value_msg_ptr_t value;
+
+ key_pointer_set_pointer(&key, invocation_ptr);
+ value_msg_ptr_set_msg_ptr(&value, (void *)invocation_ptr->message);
+
+ invocation_to_message.update(&key, &value);
+ return 0;
+}
+
+int handle_call_in_idle_cb(struct pt_regs *ctx, void *user_data) {
+/* user_data is GDBusMethodInvocation */
+ key_pointer_t itm_key;
+ value_msg_ptr_t *itm_value;
+ struct GDBusMessage *message;
+
+ key_pointer_t wrk_key;
+ timestamp_value_t *wrk_value;
+ u64 timestamp = get_current_timestamp();
+
+ key_pointer_set_pointer(&itm_key, user_data);
+
+ itm_value = invocation_to_message.lookup(&itm_key);
+ if (itm_value == 0)
+ return 0;
+
+ message = value_msg_ptr_get_msg_ptr(itm_value);
+ invocation_to_message.delete(&itm_key);
+
+ key_pointer_set_pointer(&wrk_key, message);
+ wrk_value = msg_on_worker_received.lookup(&wrk_key);
+ if (wrk_value == 0) {
+ bpf_trace_printk("no message %p connected to invocation\n", message);
+ bpf_trace_printk(" for pid %u\n", wrk_key.pid);
+ return 0;
+ }
+
+ timestamp -= timestamp_value_get_timestamp(wrk_value);
+ msg_on_worker_received.delete(&wrk_key);
+
+ timings.increment(bpf_log2l(ns_to_us(timestamp)));
+
+ return 0;
+}
+
+int handle_finalize_invocation(struct pt_regs *ctx, struct _GDBusMethodInvocation *invocation) {
+ key_pointer_t itm_key;
+ key_pointer_set_pointer(&itm_key, invocation);
+ invocation_to_message.delete(&itm_key);
+ return 0;
+}
+
+/************** method returns, errors *******************/
+/* There is an intermediate step for method returns and errors - we track association of
+ * a GTask with a given message, and then we track when
+ * it is about to be used */
+/* This hashmap tracks task->message relationships */
+BPF_HASH(task_to_message, key_pointer_t, value_msg_ptr_t);
+
+int handle_task_return_pointer(struct pt_regs *ctx, void *task, struct GDBusMessage *message) {
+ key_pointer_t key;
+ value_msg_ptr_t value;
+
+ /* first, check if we track such message pointer */
+ key_pointer_t wrk_key;
+ key_pointer_set_pointer(&wrk_key, message);
+ if (msg_on_worker_received.lookup(&wrk_key) == 0)
+ return 0;
+
+ /* ok, we track it, let's track the task */
+ key_pointer_set_pointer(&key, task);
+ value_msg_ptr_set_msg_ptr(&value, message);
+
+ task_to_message.update(&key, &value);
+ return 0;
+}
+
+int handle_task_return_now(struct pt_regs *ctx, void *task) {
+ key_pointer_t ttm_key;
+ value_msg_ptr_t *ttm_value;
+ struct GDBusMessage *message;
+
+ key_pointer_t wrk_key;
+ timestamp_value_t *wrk_value;
+ u64 timestamp = get_current_timestamp();
+
+ key_pointer_set_pointer(&ttm_key, task);
+ ttm_value = task_to_message.lookup(&ttm_key);
+ if (ttm_value == 0)
+ return 0;
+
+ message = value_msg_ptr_get_msg_ptr(ttm_value);
+ task_to_message.delete(&ttm_key);
+
+ key_pointer_set_pointer(&wrk_key, message);
+ wrk_value = msg_on_worker_received.lookup(&wrk_key);
+ if (wrk_value == 0) {
+ bpf_trace_printk("no message %p connected to task\n", message);
+ bpf_trace_printk(" for pid %u\n", wrk_key.pid);
+ return 0;
+ }
+
+ timestamp -= timestamp_value_get_timestamp(wrk_value);
+ msg_on_worker_received.delete(&wrk_key);
+
+ timings.increment(bpf_log2l(ns_to_us(timestamp)));
+
+ return 0;
+}
+
+int handle_finalize_task(struct pt_regs *ctx, void *invocation) {
+ key_pointer_t ttm_key;
+
+ key_pointer_set_pointer(&ttm_key, invocation);
+ task_to_message.delete(&ttm_key);
+ return 0;
+}
+
+/************** signals *******************/
+/* The SignalInstance is taken from gio source code. It's only here, not in gio.h,
+ * as it is a very specialized struct, used only for passing signals
+ * between gdbus and client threads. It is very, very unlikely to be
+ * needed anywhere else.
+ */
+typedef struct {
+ ptr_t subscriber; // SignalSubscriber *subscriber; /* (owned) */
+ ptr_t message; // GDBusMessage *message;
+ ptr_t connection; // GDBusConnection *connection;
+ ptr_t sender; // const gchar *sender; /* (nullable) for peer-to-peer connections */
+ ptr_t path; // const gchar *path;
+ ptr_t interface; // const gchar *interface;
+ ptr_t member; // const gchar *member;
+} SignalInstance;
+
+/* We measure only the first subscriber, if any.
+ * If a signal is received, but there are no subscribers, then no measurements are recorded.
+ */
+int handle_emit_signal(struct pt_regs *ctx, void *user_data) {
+ SignalInstance *signal_instance = user_data;
+ key_pointer_t key;
+ timestamp_value_t *value;
+ u64 timestamp = get_current_timestamp();
+
+ key_pointer_set_pointer(&key, (void *)signal_instance->message);
+ value = msg_on_worker_received.lookup(&key);
+ if (value == 0)
+ return 0;
+
+ timestamp -= timestamp_value_get_timestamp(value);
+ msg_on_worker_received.delete(&key);
+
+ timings.increment(bpf_log2l(ns_to_us(timestamp)));
+
+ return 0;
+}
--- /dev/null
+#!/usr/bin/python3
+
+from bcc import BPF
+from time import sleep
+import argparse
+
+parser = argparse.ArgumentParser(
+ description="Measure time interval between receiving a message and handling it in a client thread in glib",
+ formatter_class=argparse.RawDescriptionHelpFormatter)
+parser.add_argument("--no-method-calls", action="store_true",
+ help="disable detecting D-Bus method calls")
+parser.add_argument("--no-method-returns-and-errors", action="store_true",
+ help="disable detecting D-Bus method returns and errors")
+parser.add_argument("--no-signals", action="store_true",
+ help="disable detecting D-Bus signals")
+parser.add_argument("interval", nargs="?", default=2,
+ help="output interval, in seconds")
+parser.add_argument("count", nargs="?", default=-1,
+ help="number of outputs")
+
+args = parser.parse_args()
+interval = int(args.interval)
+loop = 0
+count = int(args.count)
+
+b = BPF(src_file="dbus-glib-receiving.c")
+
+# Setup uprobes
+
+# ****** General
+
+# this uprobe function detects an incoming, constructed message and stores a reference to it
+# it also stores time of detection of the message
+b.attach_uprobe(name="gio-2.0", sym="on_worker_message_received", fn_name="handle_on_worker_received")
+
+# this uprobe function detects destroying of a message and removes any existing references
+b.attach_uprobe(name="gio-2.0", sym="g_dbus_message_finalize", fn_name="handle_message_delete")
+
+# ****** Receiving method calls
+if not args.no_method_calls:
+ # this uprobe function detects when a GDBusMethodInvocation is created, and stores a reference to it
+ b.attach_uretprobe(name="gio-2.0", sym="_g_dbus_method_invocation_new", fn_name="handle_ret_method_invocation_new")
+
+ # this uprobe function detects when a GDBusMethodInvocation is handled in a client thread
+ # it removes any existing references to the invocation and the message associated with the invocation
+ # it also records time interval between detection of the message and this point
+ b.attach_uprobe(name="gio-2.0", sym="call_in_idle_cb", fn_name="handle_call_in_idle_cb")
+
+ # this uprobe function detects non-handled method invocations for removing references
+ b.attach_uprobe(name="gio-2.0", sym="g_dbus_method_invocation_finalize", fn_name="handle_finalize_invocation")
+
+# ***** Receiving method returns and errors
+
+if not args.no_method_returns_and_errors:
+ # this uprobe function detects when a task is associated with a message, and stores a reference to it
+ b.attach_uprobe(name="gio-2.0", sym="g_task_return_pointer", fn_name="handle_task_return_pointer")
+
+ # this uprobe function detects when a task is handled in a client thread
+ # it removes any existing references to the task and the message associated with the task
+ # it also records time interval between detection of the message and this point
+ b.attach_uprobe(name="gio-2.0", sym="g_task_return_now", fn_name="handle_task_return_now")
+
+ # this uprobe function detects non-handled tasks for removing references
+ b.attach_uprobe(name="gio-2.0", sym="g_task_finalize", fn_name="handle_finalize_task")
+
+# ***** Receiving signals
+if not args.no_method_returns_and_errors:
+ # this uprobe function detects when a signal is about to be delivered in a client thread
+ # it removes any existing references to the message
+ # it also records time interval between detection of the message and this point
+ # thus, it records only timings for the very first subscriber that receives the signal
+ b.attach_uprobe(name="gio-2.0", sym="emit_signal_instance_in_idle_cb", fn_name="handle_emit_signal")
+
+# GO!
+print("Hit Ctrl-C to end.")
+
+while (1):
+ sleep(interval)
+ loop = loop + 1
+ print("\n%d:" % loop)
+ b["timings"].print_log2_hist("us")
+
+ # Kinda debug part, but important - it shows any leftovers in hashmaps.
+ # This way, if it shows up, we can tell how bad it is.
+ msgs = len(b["msg_on_worker_received"].items())
+ invocations = len(b["invocation_to_message"].items())
+ tasks = len(b["task_to_message"].items())
+
+ if msgs + invocations + tasks > 0:
+ print(" containers stats:")
+ if msgs > 0: print(' msg_on_worker_received:', msgs)
+ if invocations > 0: print(' invocation_to_message :', invocations)
+ if tasks > 0: print(' task_to_message :', tasks)
+
+ if count == loop:
+ print('Finished')
+ break
--- /dev/null
+#include <hostcompat/linux/sched.h>
+#include <hostcompat/uapi/linux/ptrace.h>
+#include <hostcompat/dbus/gio.h>
+#include "dbus-glib-tools.h"
+
+/* This histogram is meant to keep time intervals between detection of sending of a message
+ * and making its data available in a gdbus thread. */
+BPF_HISTOGRAM(timings);
+
+/* This hashmap contains mapping from a message pointer to a timestamp.
+ * It is meant to keep timestamps of detection of passing a message for sending
+ * to a gdbus thread from a client thread. */
+BPF_HASH(msg_sending, key_pointer_t, timestamp_value_t);
+
+int handle_worker_send_message(struct pt_regs *ctx,
+ void *worker,
+ struct GDBusMessage *message,
+ char *blob,
+ size_t blob_len) {
+ key_pointer_t key;
+ timestamp_value_t value;
+
+ key_pointer_set_pointer(&key, message);
+ timestamp_value_set_timestamp(&value);
+
+ msg_sending.update(&key, &value);
+ return 0;
+}
+
+int handle_about_to_be_sent(struct pt_regs *ctx,
+ struct GDBusMessage *message,
+ void *user_data) {
+ key_pointer_t key;
+ timestamp_value_t *value;
+ u64 timestamp = get_current_timestamp();
+
+ key_pointer_set_pointer(&key, message);
+ value = msg_sending.lookup(&key);
+ if (value == 0)
+ return 0;
+
+ timestamp -= timestamp_value_get_timestamp(value);
+ msg_sending.delete(&key);
+
+ timings.increment(bpf_log2l(ns_to_us(timestamp)));
+
+ return 0;
+}
+
+int handle_message_delete(struct pt_regs *ctx, struct GDBusMessage *msg) {
+ key_pointer_t key;
+ key_pointer_set_pointer(&key, msg);
+ msg_sending.delete(&key);
+ return 0;
+}
--- /dev/null
+#!/usr/bin/python3
+
+from bcc import BPF
+from time import sleep
+import argparse
+
+parser = argparse.ArgumentParser(
+ description="Measure time interval between using the sending API for a message and handling it in a gdbus thread in glib",
+ formatter_class=argparse.RawDescriptionHelpFormatter)
+parser.add_argument("interval", nargs="?", default=2,
+ help="output interval, in seconds")
+parser.add_argument("count", nargs="?", default=-1,
+ help="number of outputs")
+
+args = parser.parse_args()
+interval = int(args.interval)
+loop = 0
+count = int(args.count)
+
+b = BPF(src_file="dbus-glib-sending.c")
+
+# Setup uprobes
+
+# ****** General
+b.attach_uprobe(name="gio-2.0", sym="_g_dbus_worker_send_message", fn_name="handle_worker_send_message")
+b.attach_uprobe(name="gio-2.0", sym="on_worker_message_about_to_be_sent", fn_name="handle_about_to_be_sent")
+# this uprobe function detects destroying of a message and removes any existing references
+b.attach_uprobe(name="gio-2.0", sym="g_dbus_message_finalize", fn_name="handle_message_delete")
+
+# GO!
+print("Hit Ctrl-C to end.")
+
+while (1):
+ sleep(interval)
+ loop = loop + 1
+ print("\n%d:" % loop)
+ b["timings"].print_log2_hist("us")
+
+ # Kinda debug part, but important - it shows any leftovers in hashmaps.
+ # This way, if it shows up, we can tell how bad it is.
+ msgs = len(b["msg_sending"].items())
+
+ if msgs > 0:
+ print(" containers stats:")
+ print(' msg_sending:', msgs)
+
+ if count == loop:
+ print('Finished')
+ break
--- /dev/null
+#pragma once
+
+#include <hostcompat/dbus/gio.h>
+
+typedef struct {
+ ptr_t pointer;
+ u32 pid;
+ u32 padding;
+} key_pointer_t;
+
+static key_pointer_t *key_pointer_set_pointer(key_pointer_t *key, void *ptr) {
+ key->pointer = (ptr_t)ptr;
+ key->pid = bpf_get_current_pid_tgid() >> 32;
+ key->padding = 0;
+ return key;
+}
+
+typedef struct {
+ u64 timestamp;
+} timestamp_value_t;
+
+static u64 get_current_timestamp(void) {
+ return bpf_ktime_get_ns();
+}
+
+static timestamp_value_t *timestamp_value_set_timestamp(timestamp_value_t *value) {
+ value->timestamp = get_current_timestamp();
+ return value;
+}
+
+static u64 timestamp_value_get_timestamp(timestamp_value_t *value) {
+ return value->timestamp;
+}
+
+static u64 ns_to_us(u64 ts) {
+ return ts / 1000;
+}
projects / platform / upstream / bcc.git / commitdiff