From: Adrian Szyndela Date: Fri, 28 Jan 2022 13:59:10 +0000 (+0100) Subject: dbus tools: print averages X-Git-Tag: submit/tizen/20220713.022109~1 X-Git-Url: http://review.tizen.org/git/?a=commitdiff_plain;h=cac411982995ed094ec7a3a29aa22338a9f4971b;p=platform%2Fupstream%2Fbcc.git dbus tools: print averages This adds collecting and printing of average timings for the dbus tools. Unfortunately, it is in a copy & paste style as I didn't find a way to share BPF maps code between the tools. I've even tried static implementation in an included header. Doesn't work. Apparently bcc needs it in one file, analysed by bcc, before it is passed to libllvm's preprocessor. Change-Id: Id1c259b47ee7cfb0b05ac36d4800ea041af11e9c --- diff --git a/tools/dbus-glib-client-sending.c b/tools/dbus-glib-client-sending.c index 340788d7..a98c754f 100644 --- a/tools/dbus-glib-client-sending.c +++ b/tools/dbus-glib-client-sending.c @@ -3,6 +3,20 @@ #include #include "dbus-glib-tools.h" +BPF_ARRAY(count_averages, u64, 2); +#define INDEX_OF_AVERAGE_VALUE 0 +#define INDEX_OF_NUMBER_OF_SAMPLES 1 + +static void average_add(u64 val) { + int avg = INDEX_OF_AVERAGE_VALUE; + u64 *current_avg; + + count_averages.increment(INDEX_OF_NUMBER_OF_SAMPLES); + current_avg = count_averages.lookup(&avg); + if (current_avg) + lock_xadd(current_avg, val); +} + /* 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); @@ -44,6 +58,7 @@ int handle_worker_send_message(struct pt_regs *ctx, msg_sending.delete(&key); timings.increment(bpf_log2l(ns_to_us(timestamp))); + average_add(timestamp); return 0; } diff --git a/tools/dbus-glib-client-sending.py b/tools/dbus-glib-client-sending.py index ce2ee2f3..92dd512d 100755 --- a/tools/dbus-glib-client-sending.py +++ b/tools/dbus-glib-client-sending.py @@ -44,6 +44,9 @@ while (1): print(" containers stats:") print(' msg_sending:', msgs) + if b["count_averages"][1].value > 0: + print('Average:', (b["count_averages"][0].value // b["count_averages"][1].value) // 1000) + if count == loop: print('Finished') break diff --git a/tools/dbus-glib-receiving.c b/tools/dbus-glib-receiving.c index 5da43936..b07ed2fe 100644 --- a/tools/dbus-glib-receiving.c +++ b/tools/dbus-glib-receiving.c @@ -43,6 +43,20 @@ int handle_message_delete(struct pt_regs *ctx, struct GDBusMessage *msg) { return 0; } +BPF_ARRAY(count_averages, u64, 2); +#define INDEX_OF_AVERAGE_VALUE 0 +#define INDEX_OF_NUMBER_OF_SAMPLES 1 + +static void average_add(u64 val) { + int avg = INDEX_OF_AVERAGE_VALUE; + u64 *current_avg; + + count_averages.increment(INDEX_OF_NUMBER_OF_SAMPLES); + current_avg = count_averages.lookup(&avg); + if (current_avg) + lock_xadd(current_avg, val); +} + /********** method calls *************/ struct value_msg_ptr_t { struct GDBusMessage *msg_ptr; @@ -106,6 +120,7 @@ int handle_call_in_idle_cb(struct pt_regs *ctx, void *user_data) { msg_on_worker_received.delete(&wrk_key); timings.increment(bpf_log2l(ns_to_us(timestamp))); + average_add(timestamp); return 0; } @@ -171,6 +186,7 @@ int handle_task_return_now(struct pt_regs *ctx, void *task) { msg_on_worker_received.delete(&wrk_key); timings.increment(bpf_log2l(ns_to_us(timestamp))); + average_add(timestamp); return 0; } @@ -217,6 +233,7 @@ int handle_emit_signal(struct pt_regs *ctx, void *user_data) { msg_on_worker_received.delete(&key); timings.increment(bpf_log2l(ns_to_us(timestamp))); + average_add(timestamp); return 0; } diff --git a/tools/dbus-glib-receiving.py b/tools/dbus-glib-receiving.py index 9587899d..f19c5859 100755 --- a/tools/dbus-glib-receiving.py +++ b/tools/dbus-glib-receiving.py @@ -92,6 +92,9 @@ while (1): if invocations > 0: print(' invocation_to_message :', invocations) if tasks > 0: print(' task_to_message :', tasks) + if b["count_averages"][1].value > 0: + print('Average:', (b["count_averages"][0].value // b["count_averages"][1].value) // 1000) + if count == loop: print('Finished') break diff --git a/tools/dbus-glib-sending.c b/tools/dbus-glib-sending.c index 07008f8b..dcfbfb02 100644 --- a/tools/dbus-glib-sending.c +++ b/tools/dbus-glib-sending.c @@ -3,6 +3,20 @@ #include #include "dbus-glib-tools.h" +BPF_ARRAY(count_averages, u64, 2); +#define INDEX_OF_AVERAGE_VALUE 0 +#define INDEX_OF_NUMBER_OF_SAMPLES 1 + +static void average_add(u64 val) { + int avg = INDEX_OF_AVERAGE_VALUE; + u64 *current_avg; + + count_averages.increment(INDEX_OF_NUMBER_OF_SAMPLES); + current_avg = count_averages.lookup(&avg); + if (current_avg) + lock_xadd(current_avg, val); +} + /* 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); @@ -43,6 +57,7 @@ int handle_about_to_be_sent(struct pt_regs *ctx, msg_sending.delete(&key); timings.increment(bpf_log2l(ns_to_us(timestamp))); + average_add(timestamp); return 0; } diff --git a/tools/dbus-glib-sending.py b/tools/dbus-glib-sending.py index 737e33f5..a87eb7e2 100755 --- a/tools/dbus-glib-sending.py +++ b/tools/dbus-glib-sending.py @@ -44,6 +44,9 @@ while (1): print(" containers stats:") print(' msg_sending:', msgs) + if b["count_averages"][1].value > 0: + print('Average:', (b["count_averages"][0].value // b["count_averages"][1].value) // 1000) + if count == loop: print('Finished') break diff --git a/tools/dbus-latency.c b/tools/dbus-latency.c index f196aa77..9f8e541e 100644 --- a/tools/dbus-latency.c +++ b/tools/dbus-latency.c @@ -27,7 +27,6 @@ struct stats_t { BPF_HASH(msg_sent_addr, u32 , struct data_t); BPF_HASH(msg_latency, struct data_t , struct stats_t); -BPF_HASH(g_serial_addr, struct data_t, struct GDBusMessage *); BPF_HISTOGRAM(latency_histo); static void get_process_data(struct data_t *data) { @@ -156,6 +155,7 @@ static int get_delay(int serial, struct data_t *receiver_data) { return 0; } latency_histo.increment(bpf_log2l(delta)); + receiver_data->pid = s_data.pid; receiver_data->ts = 0; bpf_probe_read(&receiver_data->comm, sizeof(receiver_data->comm), s_data.comm); diff --git a/tools/dbus-latency.py b/tools/dbus-latency.py index 2e997a61..1a302f40 100755 --- a/tools/dbus-latency.py +++ b/tools/dbus-latency.py @@ -48,11 +48,18 @@ while (1): sleep(interval) loop = loop + 1 print("\n%d:" % loop) + latency = b["msg_latency"] if mode =="histogram": b["latency_histo"].print_log2_hist("us") + avgcnt = 0 + avgval = 0 + for v, p in latency.items(): + avgcnt += long(p.count) + avgval += long(p.count) * long(p.avg) + if avgcnt > 0: + print 'Average:', avgval // avgcnt else: print ("%10s %20s %10s %10s %10s" % ("PID", "COMM", "MIN", "AVG", "MAX")) - latency = b["msg_latency"] for v, p in sorted(latency.items(), key=lambda latency: latency[1].avg, reverse=True): print("%10d %20s %10d %10d %10d" % (v.pid, v.comm.encode('string-escape'), int(p.min), int(p.avg), int(p.max)))