From nobody Sun Dec 14 22:18:29 2025 Delivered-To: importer@patchew.org Authentication-Results: mx.zohomail.com; dkim=pass; spf=pass (zohomail.com: domain of gnu.org designates 209.51.188.17 as permitted sender) smtp.mailfrom=qemu-devel-bounces+importer=patchew.org@nongnu.org; dmarc=pass(p=none dis=none) header.from=linaro.org ARC-Seal: i=1; a=rsa-sha256; t=1754619038; cv=none; d=zohomail.com; s=zohoarc; b=Bf+is3QJ5DjZiP9r9hKER+WnAdTHCpRUzfoc3w05KrIjWArpphxyqmDAeoxfvUCUWcTD3P/WvfPabmqV4x27AdrXaMCdDsGpS6lcDM0/07izkf0I8UvJyOIKC1cWl7smeGi/LrnztbIUTLaOtBXsHKzXg5NNqYofbUkgHu/q1Pw= ARC-Message-Signature: i=1; a=rsa-sha256; c=relaxed/relaxed; d=zohomail.com; s=zohoarc; t=1754619038; h=Content-Transfer-Encoding:Cc:Cc:Date:Date:From:From:In-Reply-To:List-Subscribe:List-Post:List-Id:List-Archive:List-Help:List-Unsubscribe:MIME-Version:Message-ID:References:Sender:Subject:Subject:To:To:Message-Id:Reply-To; bh=co5Pn4vXxl2xGepzoq0rmC9u8lz8ngf1vfiSXSUCvG8=; b=euDfBcG0zyc6tQK31mCQjZeRaNJNFpTGYCUiuxaMDp7i8022gmuuuAODD9EuPIMtMBnEpN/E/13SazB/1uKF+7EdGqrJU9J0gkc+f6qOvywvMT0RiefyXrFB47f6xiWpGNvsVbdksgU+fwpKMau7bV+xDHYowyk5DNYYmZK1qjI= ARC-Authentication-Results: i=1; mx.zohomail.com; dkim=pass; spf=pass (zohomail.com: domain of gnu.org designates 209.51.188.17 as permitted sender) smtp.mailfrom=qemu-devel-bounces+importer=patchew.org@nongnu.org; dmarc=pass header.from= (p=none dis=none) Return-Path: Received: from lists.gnu.org (lists.gnu.org [209.51.188.17]) by mx.zohomail.com with SMTPS id 175461903856723.98555193331447; Thu, 7 Aug 2025 19:10:38 -0700 (PDT) Received: from localhost ([::1] helo=lists1p.gnu.org) by lists.gnu.org with esmtp (Exim 4.90_1) (envelope-from ) id 1ukCVy-0008GD-HR; Thu, 07 Aug 2025 22:07:26 -0400 Received: from eggs.gnu.org ([2001:470:142:3::10]) by lists.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.90_1) (envelope-from ) id 1ukCVt-00087o-7y for qemu-devel@nongnu.org; Thu, 07 Aug 2025 22:07:23 -0400 Received: from mail-pj1-x102f.google.com ([2607:f8b0:4864:20::102f]) by eggs.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_128_GCM_SHA256:128) (Exim 4.90_1) (envelope-from ) id 1ukCVn-0003UL-Qt for qemu-devel@nongnu.org; Thu, 07 Aug 2025 22:07:20 -0400 Received: by mail-pj1-x102f.google.com with SMTP id 98e67ed59e1d1-32117db952aso1548821a91.0 for ; Thu, 07 Aug 2025 19:07:14 -0700 (PDT) Received: from pc.. ([38.41.223.211]) by smtp.gmail.com with ESMTPSA id 41be03b00d2f7-b428ba4cf35sm3705433a12.14.2025.08.07.19.07.11 (version=TLS1_3 cipher=TLS_AES_256_GCM_SHA384 bits=256/256); Thu, 07 Aug 2025 19:07:12 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=linaro.org; s=google; t=1754618833; x=1755223633; darn=nongnu.org; h=content-transfer-encoding:mime-version:references:in-reply-to :message-id:date:subject:cc:to:from:from:to:cc:subject:date :message-id:reply-to; bh=co5Pn4vXxl2xGepzoq0rmC9u8lz8ngf1vfiSXSUCvG8=; b=XBZmjdfSROgWc7iUcQMERZWGioCMqIq/DKf1uPbALaT3KoJrqFWt6Kpch6emUrdhYo LC8WDnmLWwLXu16hlCC7neI5dALGfTAtPUyiBcgqSW/V/Pz5jcEu3mFtgTUDlB40iztc /wVXL4Ze4vaw8p6mIyw3dAMOcP9AvSFXuL3vehcYu9TUTs5hPiTDYvrpvRutcxnVpcis YwcVqq1Fq/NtwSXfZ/dwRvM3EWu+rfF9C48jpxQ9Mnsk3YPBTv4PPI1sOUhUPyF7JDoW 8S2RYaM8kIZ0J0uDZYwcQ96PFwv4ZoAmiKL9XvcQrZf35IeHQ4g/kElExtwUzeSMelRm vsrQ== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20230601; t=1754618833; x=1755223633; h=content-transfer-encoding:mime-version:references:in-reply-to :message-id:date:subject:cc:to:from:x-gm-message-state:from:to:cc :subject:date:message-id:reply-to; bh=co5Pn4vXxl2xGepzoq0rmC9u8lz8ngf1vfiSXSUCvG8=; b=gxumFNvNN/7GiK/axYA8WZVihGad+wTTWSWld2bByoi2eR9ridneCkNyp9C3aFHR+E 7MsZQu6pYcSDgCZl35VBxYkg5HDjPw1zojszABWvF4jptmefR3jOnAyLi87tJABT1+Sx 1yNrrNpco4CqmKGq1OiqIPZ5lYavDLAaHMLOAR/8GJWqp4UHG8lJW8gBePR3LyR9JPzu yu3CcEfB58Lnra44gbTQE/GaXxoe8VVUOFfnxfGnXB9cx+zkbq1uyZNJzVG9RYcOQOB6 RpnNedHQ8pq0zXM/CiL/m9vbfrzQF9eUfBTXIVNmAnRhkeS91Z0/Uh3QNmqYIjSezZhP oeQg== X-Forwarded-Encrypted: i=1; AJvYcCXQOWT/yFrS5jjejgW1FSlk20Pz1TW045PDZvy+9XjtCPE9Esw3f8JyDAzP8GbMGOihYqaopjAUQn+J@nongnu.org X-Gm-Message-State: AOJu0YzwXF4mZAdAt5Kr8rlTjc3F8hcM9vkE4PjYX4DcRXPZjBbPE5t4 BukDWXShqpB56AKFQOPFVzqCuyEcE/7xvUkJJB8zZTEAvt6yXJg6U851Ox14Wjqtfmo= X-Gm-Gg: ASbGncsQKmZMRZv8SpW+x1lcjNykFJ3bhMEaFQ2iO0nqu0pth5MuMIt+eO47iYVfEv5 pK0gD7Nmfd3ezbZHNFvZRfcE+yrwkEEpl0DMyiAl1tqbp/Nnp132UQHUaZib342oJdkHWicF/PP zCWWeJoUhmEnkncJA7gLQA39Djx1rSV1cv9vSDhj9Gw6yqk8aXaOy9kyyKc9Tcv+BLBnzu2HXuz ukSg1nqSZJ6C/yXMgLU5Sqnfr7G5TPvHfDYN57ddIrczqd89uxbbuWpg1XJWX/9X+u1l9hFFTHl UdGYrlXaV4zlPjk2i6gJXWCL2dM7x3EgjIaY81wnbrw2DEbfY6HhPpCVbFr5VYmud2jVel0+MdQ dGgGT/fu7/HXEbgk4M4g1Ug== X-Google-Smtp-Source: AGHT+IGhdg2jqJpyG8AyVPo6vT1FWqETi+LzEUAlo92PQifS6LiHWVcb6mcEju8fksSiEJS0IgVHCA== X-Received: by 2002:a17:90b:224e:b0:31f:210e:e34a with SMTP id 98e67ed59e1d1-321839f0c96mr1723085a91.8.1754618832853; Thu, 07 Aug 2025 19:07:12 -0700 (PDT) From: Pierrick Bouvier To: pierrick.bouvier@linaro.org, qemu-devel@nongnu.org Cc: Mahmoud Mandour , =?UTF-8?q?Philippe=20Mathieu-Daud=C3=A9?= , rowan Hart , Gustavo Romero , Manos Pitsidianakis , =?UTF-8?q?Alex=20Benn=C3=A9e?= , Alexandre Iooss , Peter Maydell , Richard Henderson Subject: [PATCH v5 4/9] contrib/plugins/uftrace: implement tracing Date: Thu, 7 Aug 2025 19:06:57 -0700 Message-ID: <20250808020702.410109-5-pierrick.bouvier@linaro.org> X-Mailer: git-send-email 2.47.2 In-Reply-To: <20250808020702.410109-1-pierrick.bouvier@linaro.org> References: <20250808020702.410109-1-pierrick.bouvier@linaro.org> MIME-Version: 1.0 Content-Transfer-Encoding: quoted-printable Received-SPF: pass (zohomail.com: domain of gnu.org designates 209.51.188.17 as permitted sender) client-ip=209.51.188.17; envelope-from=qemu-devel-bounces+importer=patchew.org@nongnu.org; helo=lists.gnu.org; Received-SPF: pass client-ip=2607:f8b0:4864:20::102f; envelope-from=pierrick.bouvier@linaro.org; helo=mail-pj1-x102f.google.com X-Spam_score_int: -20 X-Spam_score: -2.1 X-Spam_bar: -- X-Spam_report: (-2.1 / 5.0 requ) BAYES_00=-1.9, DKIM_SIGNED=0.1, DKIM_VALID=-0.1, DKIM_VALID_AU=-0.1, DKIM_VALID_EF=-0.1, RCVD_IN_DNSWL_NONE=-0.0001, SPF_HELO_NONE=0.001, SPF_PASS=-0.001 autolearn=ham autolearn_force=no X-Spam_action: no action X-BeenThere: qemu-devel@nongnu.org X-Mailman-Version: 2.1.29 Precedence: list List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: qemu-devel-bounces+importer=patchew.org@nongnu.org Sender: qemu-devel-bounces+importer=patchew.org@nongnu.org X-ZohoMail-DKIM: pass (identity @linaro.org) X-ZM-MESSAGEID: 1754619040367124100 Content-Type: text/plain; charset="utf-8" We implement tracing, following uftrace format. Trace is flushed every 32 MB, so file operations don't impact performance at runtime. A different trace is generated per cpu, and we ensure they have a unique name, based on vcpu_index, while keeping room for privilege level coming in next commit. Signed-off-by: Pierrick Bouvier --- contrib/plugins/uftrace.c | 149 +++++++++++++++++++++++++++++++++++++- 1 file changed, 148 insertions(+), 1 deletion(-) diff --git a/contrib/plugins/uftrace.c b/contrib/plugins/uftrace.c index d51faceb344..402a242433e 100644 --- a/contrib/plugins/uftrace.c +++ b/contrib/plugins/uftrace.c @@ -12,6 +12,13 @@ #include #include #include +#include +#include +#include +#include + +#define MiB (INT64_C(1) << 20) +#define NANOSECONDS_PER_SECOND 1000000000LL =20 QEMU_PLUGIN_EXPORT int qemu_plugin_version =3D QEMU_PLUGIN_VERSION; =20 @@ -24,6 +31,13 @@ typedef struct { uint64_t frame_pointer; } CallstackEntry; =20 +typedef struct { + GArray *t; + GString *path; + GString *name; + uint32_t id; +} Trace; + typedef struct Cpu Cpu; =20 typedef struct { @@ -34,6 +48,7 @@ typedef struct { } CpuOps; =20 typedef struct Cpu { + Trace *trace; Callstack *cs; GByteArray *buf; CpuOps ops; @@ -44,9 +59,41 @@ typedef struct { struct qemu_plugin_register *reg_fp; } Aarch64Cpu; =20 +typedef struct { + uint64_t timestamp; + uint64_t data; +} UftraceEntry; + +typedef enum { + UFTRACE_ENTRY, + UFTRACE_EXIT, + UFTRACE_LOST, + UFTRACE_EVENT +} UftraceRecordType; + static struct qemu_plugin_scoreboard *score; static CpuOps arch_ops; =20 +static uint64_t gettime_ns(void) +{ +#ifdef _WIN32 + /* + * On Windows, timespec_get is available only with UCRT, but not with + * MinGW64 environment. Simplify by using only gettimeofday on this + * platform. This may result in a precision loss. + */ + struct timeval tv; + gettimeofday(&tv, NULL); + uint64_t now_ns =3D tv.tv_sec * NANOSECONDS_PER_SECOND + tv.tv_usec * = 1000; +#else + /* We need nanosecond precision for short lived functions. */ + struct timespec ts; + timespec_get(&ts, TIME_UTC); + uint64_t now_ns =3D ts.tv_sec * NANOSECONDS_PER_SECOND + ts.tv_nsec; +#endif + return now_ns; +} + static Callstack *callstack_new(void) { Callstack *cs =3D g_new0(Callstack, 1); @@ -112,6 +159,85 @@ static CallstackEntry callstack_pop(Callstack *cs) return e; } =20 +static Trace *trace_new(uint32_t id, GString *name) +{ + Trace *t =3D g_new0(Trace, 1); + t->t =3D g_array_new(false, false, sizeof(UftraceEntry)); + t->path =3D g_string_new(NULL); + g_string_append_printf(t->path, "./uftrace.data/%"PRIu32".dat", id); + t->name =3D g_string_new(name->str); + t->id =3D id; + return t; +} + +static void trace_free(Trace *t) +{ + g_assert(t->t->len =3D=3D 0); + g_array_free(t->t, true); + t->t =3D NULL; + g_string_free(t->path, true); + t->path =3D NULL; + g_string_free(t->name, true); + t->name =3D NULL; + g_free(t); +} + +static void trace_flush(Trace *t, bool append) +{ + int create_dir =3D g_mkdir_with_parents("./uftrace.data", + S_IRWXU | S_IRWXG | S_IRWXO); + g_assert(create_dir =3D=3D 0); + FILE *dat =3D fopen(t->path->str, append ? "a" : "w"); + g_assert(dat); + GArray *data =3D t->t; + if (data->len) { + fwrite(data->data, data->len, sizeof(UftraceEntry), dat); + } + fclose(dat); + g_array_set_size(data, 0); +} + +static void trace_add_entry(Trace *t, uint64_t timestamp, uint64_t pc, + size_t depth, UftraceRecordType type) +{ + /* libmcount/record.c:record_event */ + const uint64_t record_magic =3D 0x5; + uint64_t data =3D type | record_magic << 3; + data +=3D depth << 6; + data +=3D pc << 16; + UftraceEntry e =3D {.timestamp =3D timestamp, .data =3D data}; + g_array_append_val(t->t, e); + if (t->t->len * sizeof(UftraceEntry) > 32 * MiB) { + trace_flush(t, true); + } +} + +static void trace_enter_function(Trace *t, uint64_t timestamp, + uint64_t pc, size_t depth) +{ + trace_add_entry(t, timestamp, pc, depth, UFTRACE_ENTRY); +} + +static void trace_exit_function(Trace *t, uint64_t timestamp, + uint64_t pc, size_t depth) +{ + trace_add_entry(t, timestamp, pc, depth, UFTRACE_EXIT); +} + +static void trace_enter_stack(Trace *t, Callstack *cs, uint64_t timestamp) +{ + for (size_t depth =3D 1; depth <=3D callstack_depth(cs); ++depth) { + trace_enter_function(t, timestamp, callstack_at(cs, depth)->pc, de= pth); + } +} + +static void trace_exit_stack(Trace *t, Callstack *cs, uint64_t timestamp) +{ + for (size_t depth =3D callstack_depth(cs); depth > 0; --depth) { + trace_exit_function(t, timestamp, callstack_at(cs, depth)->pc, dep= th); + } +} + static uint64_t cpu_read_register64(Cpu *cpu, struct qemu_plugin_register = *reg) { GByteArray *buf =3D cpu->buf; @@ -223,7 +349,9 @@ static void track_callstack(unsigned int cpu_index, voi= d *udata) { uint64_t pc =3D (uintptr_t) udata; Cpu *cpu =3D qemu_plugin_scoreboard_find(score, cpu_index); + uint64_t timestamp =3D gettime_ns(); Callstack *cs =3D cpu->cs; + Trace *t =3D cpu->trace; =20 uint64_t fp =3D cpu->ops.get_frame_pointer(cpu); if (!fp && callstack_empty(cs)) { @@ -232,6 +360,7 @@ static void track_callstack(unsigned int cpu_index, voi= d *udata) * long as a proper call does not happen. */ callstack_push(cs, (CallstackEntry){.frame_pointer =3D fp, .pc =3D= pc}); + trace_enter_function(t, timestamp, pc, callstack_depth(cs)); return; } =20 @@ -244,7 +373,8 @@ static void track_callstack(unsigned int cpu_index, voi= d *udata) CallstackEntry caller =3D callstack_caller(cs); if (fp =3D=3D caller.frame_pointer) { /* return */ - callstack_pop(cs); + CallstackEntry e =3D callstack_pop(cs); + trace_exit_function(t, timestamp, e.pc, callstack_depth(cs)); return; } =20 @@ -252,12 +382,16 @@ static void track_callstack(unsigned int cpu_index, v= oid *udata) if (caller_fp =3D=3D top.frame_pointer) { /* call */ callstack_push(cs, (CallstackEntry){.frame_pointer =3D fp, .pc =3D= pc}); + trace_enter_function(t, timestamp, pc, callstack_depth(cs)); return; } =20 /* discontinuity, exit current stack and unwind new one */ + trace_exit_stack(t, cs, timestamp); callstack_clear(cs); + cpu_unwind_stack(cpu, fp, pc); + trace_enter_stack(t, cs, timestamp); } =20 static void vcpu_tb_trans(qemu_plugin_id_t id, struct qemu_plugin_tb *tb) @@ -296,6 +430,16 @@ static void vcpu_init(qemu_plugin_id_t id, unsigned in= t vcpu_index) cpu->ops.init(cpu); cpu->buf =3D g_byte_array_new(); =20 + g_assert(vcpu_index < UINT32_MAX / 100); + /* trace_id is: cpu_number * 100 */ + uint32_t trace_id =3D (vcpu_index + 1) * 100; + + g_autoptr(GString) trace_name =3D g_string_new(NULL); + g_string_append_printf(trace_name, "cpu%u", vcpu_index); + cpu->trace =3D trace_new(trace_id, trace_name); + /* create/truncate trace file */ + trace_flush(cpu->trace, false); + cpu->cs =3D callstack_new(); } =20 @@ -304,6 +448,7 @@ static void vcpu_end(unsigned int vcpu_index) Cpu *cpu =3D qemu_plugin_scoreboard_find(score, vcpu_index); g_byte_array_free(cpu->buf, true); =20 + trace_free(cpu->trace); callstack_free(cpu->cs); memset(cpu, 0, sizeof(Cpu)); } @@ -311,6 +456,8 @@ static void vcpu_end(unsigned int vcpu_index) static void at_exit(qemu_plugin_id_t id, void *data) { for (size_t i =3D 0; i < qemu_plugin_num_vcpus(); ++i) { + Cpu *cpu =3D qemu_plugin_scoreboard_find(score, i); + trace_flush(cpu->trace, true); vcpu_end(i); } =20 --=20 2.47.2