From nobody Sun Sep 28 16:36:35 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=1758534411; cv=none; d=zohomail.com; s=zohoarc; b=OwgHIB57d/sTodTWX3vEw2e6mtBVAmSYUev7wCr1WyR5ulzqTCI1fXxPA8wW7hhyJluvBhtdyFZX4pmaCjW2kGIcRBTCYVzDuucYP4D9RpEVK5lrEU0ytq45E3gzGDyPuQq9Qh1vuZrq3dzxMNjd96akSlXKu0MXO9b6FUzHRME= ARC-Message-Signature: i=1; a=rsa-sha256; c=relaxed/relaxed; d=zohomail.com; s=zohoarc; t=1758534411; h=Content-Type: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=COW9Y8xwuzCyUVpCahD7I0T5DWgjtjyjaT4BE1jdt0E=; b=Y4QVxbRpSJvqH1OuSw6Mq+4UiKKmDs8m34VThRuCzd3Ao/efz39Tni5yVtogjGzC3zw7SPs3RB0FbCC+JpuQqmLeLqqbcIHya3pdax501/vRbIDix+khYaRBPICNPii6T/dX536DTl0MIiFHbGU8vihfNRyn3GytRJ+qH79919Y= 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 1758534411680224.36463194534394; Mon, 22 Sep 2025 02:46:51 -0700 (PDT) Received: from localhost ([::1] helo=lists1p.gnu.org) by lists.gnu.org with esmtp (Exim 4.90_1) (envelope-from ) id 1v0d65-0006ZU-KM; Mon, 22 Sep 2025 05:44:37 -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 1v0d4z-0005Do-QM for qemu-devel@nongnu.org; Mon, 22 Sep 2025 05:43:31 -0400 Received: from mail-wr1-x435.google.com ([2a00:1450:4864:20::435]) by eggs.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_128_GCM_SHA256:128) (Exim 4.90_1) (envelope-from ) id 1v0d4m-0001yo-Qa for qemu-devel@nongnu.org; Mon, 22 Sep 2025 05:43:24 -0400 Received: by mail-wr1-x435.google.com with SMTP id ffacd0b85a97d-3f2cf786abeso1430878f8f.3 for ; Mon, 22 Sep 2025 02:43:12 -0700 (PDT) Received: from draig.lan ([185.126.160.19]) by smtp.gmail.com with ESMTPSA id 5b1f17b1804b1-464f5a2850csm194393615e9.19.2025.09.22.02.43.09 (version=TLS1_3 cipher=TLS_AES_256_GCM_SHA384 bits=256/256); Mon, 22 Sep 2025 02:43:09 -0700 (PDT) Received: from draig.lan (localhost [IPv6:::1]) by draig.lan (Postfix) with ESMTP id 73C535FA31; Mon, 22 Sep 2025 10:37:13 +0100 (BST) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=linaro.org; s=google; t=1758534191; x=1759138991; 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=COW9Y8xwuzCyUVpCahD7I0T5DWgjtjyjaT4BE1jdt0E=; b=DXtx0A9bqs5FjoJS3pFUV4NgOPfSWArZfvkcbWmCqtGe0y/X6lUqFW87p08sPZB4kV pgCpIuCMhXqUzSY5aDtOa854GfwJSRLI/Q0X0nFpoxRm4Wrcno2PSslCAbV68VC6+zF9 DcUr77JXlMlg16V/4/WWhUOeoC+V0XVCKVNIyRb9N7RcsiIlJwJLry9xVYqchrotzvgZ fHnZIidbdIy1bn7H5sAq9WO9sVUFmOYUQs4k2/4ZeqzVfcAPMjV3J1/MnUtK6bqZt+ub 6LD0JrrsRKUIl6181y1POHvw4WopvTit5/FUZgw2NlCu+RaBdk0xHrnUgrkmPxLkM4+a rGcA== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20230601; t=1758534191; x=1759138991; 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=COW9Y8xwuzCyUVpCahD7I0T5DWgjtjyjaT4BE1jdt0E=; b=o63Fg289D5YGrCkzfwtYxlTPSnWV8/PQ9OR6v78WkbH9EDlwjOe37OgvyfG7BtC9eA 5YCd0cZhIbZrvhfAq4uukt7gYBNSAVFR9zXi9V4Fkw2iHEHRteqaOwvbujEnZa3ZTEyT rKJYcwSQlafNg/3BjQuA5UopB7pH92bgbxCW8FDcxTj+8LMyVyFDtQ5X6ujhaWsbRYPo Pjih5SXxAKKJnquZRDftV6hc/q85GcXCS6N3u13yaxKpL0WCGsQyDxQIRdnsyzi2p984 C7p0SiAGs1GzcxYf9xPQfxGcgRg5xmlhBOemcjhC2VFtvYqQZbbUYYWqoMMHgQOKVZeB u3Vw== X-Gm-Message-State: AOJu0YzzqVJ1G5IY2owr1ridFlu0NwmPskkWvCNhLxqWZlJnHdHYQlYK Cz2hkC4taJQIZYcs5CNACHT4XgwArncuU4HGFTJ/Xd2YunBE7wjV/LnSPiCF2UMz5A8= X-Gm-Gg: ASbGnctevpEpuV349fgiX/58x/RUS608Mag5y6lqiPh+kbIFUzVK5W2DLAtEqf5ZlcU lNlHWMEQvgUqY1MxXCcBYJ+uEBExug4gMfPJaTZatt5UzTBi/y4ZKVPSvANqneHOKHD+sRILgi4 P8aCACIYa9Y74RpwyudIffn98OLW/Z+icRpsyGxPPLw89btK+vS1GYjYXeffl73YII651+i24rH dTYLYJyjSV5Ik2hERn2dyVZu7yIiIn4VhU+Y/Rfc1qxpGJNHc3Xjq1mgktZRv7u/cAuhhoMpay7 iVHi5dm6XD5XXc5+SpwayBdW/KsxYZtckodXk+U1q1ddjKqf/Aa1pGXzWhrMCRaYw7bTibjtu43 vDpGZojXXJTB0aqtRQEu+uxw= X-Google-Smtp-Source: AGHT+IHLbjUF8i0k/tPt7x/Uu2eYY7Q6S0uvgkPi5mtaus/cinWWpe0hTy804rS6nd6Sv5iO7mnudw== X-Received: by 2002:a05:6000:4210:b0:3e7:6197:9947 with SMTP id ffacd0b85a97d-3ee868a74bamr10869516f8f.53.1758534191147; Mon, 22 Sep 2025 02:43:11 -0700 (PDT) From: =?UTF-8?q?Alex=20Benn=C3=A9e?= To: qemu-devel@nongnu.org Cc: Palmer Dabbelt , Alexandre Iooss , Mahmoud Mandour , qemu-riscv@nongnu.org, Daniel Henrique Barboza , Thomas Huth , Peter Maydell , =?UTF-8?q?Alex=20Benn=C3=A9e?= , Alistair Francis , qemu-arm@nongnu.org, =?UTF-8?q?Philippe=20Mathieu-Daud=C3=A9?= , Weiwei Li , Pierrick Bouvier , Liu Zhiwei Subject: [PATCH 20/25] contrib/plugins/uftrace: implement tracing Date: Mon, 22 Sep 2025 10:37:05 +0100 Message-ID: <20250922093711.2768983-21-alex.bennee@linaro.org> X-Mailer: git-send-email 2.47.3 In-Reply-To: <20250922093711.2768983-1-alex.bennee@linaro.org> References: <20250922093711.2768983-1-alex.bennee@linaro.org> MIME-Version: 1.0 Content-Type: text/plain; charset="utf-8" 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=2a00:1450:4864:20::435; envelope-from=alex.bennee@linaro.org; helo=mail-wr1-x435.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=unavailable 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: 1758534412680116600 From: Pierrick Bouvier 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. Uftrace format is not officially documented, but it can be found here: https://github.com/namhyung/uftrace/blob/v0.18/libmcount/record.c#L909 Reviewed-by: Philippe Mathieu-Daud=C3=A9 Signed-off-by: Pierrick Bouvier Message-ID: <20250902075042.223990-5-pierrick.bouvier@linaro.org> Signed-off-by: Alex Benn=C3=A9e --- contrib/plugins/uftrace.c | 152 +++++++++++++++++++++++++++++++++++++- 1 file changed, 151 insertions(+), 1 deletion(-) diff --git a/contrib/plugins/uftrace.c b/contrib/plugins/uftrace.c index bb775916270..b9dcd531987 100644 --- a/contrib/plugins/uftrace.c +++ b/contrib/plugins/uftrace.c @@ -12,6 +12,15 @@ #include #include #include +#include +#include +#include +#include + +#define MiB (INT64_C(1) << 20) +#define NANOSECONDS_PER_SECOND 1000000000LL +#define TRACE_FLUSH_SIZE (32 * MiB) +#define TRACE_ID_SCALE 100 =20 QEMU_PLUGIN_EXPORT int qemu_plugin_version =3D QEMU_PLUGIN_VERSION; =20 @@ -24,6 +33,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 +50,7 @@ typedef struct { } CpuOps; =20 typedef struct Cpu { + Trace *trace; Callstack *cs; GByteArray *buf; CpuOps ops; @@ -44,9 +61,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 +161,86 @@ 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) { + size_t wrote =3D fwrite(data->data, sizeof(UftraceEntry), data->le= n, dat); + g_assert(wrote =3D=3D data->len); + } + 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) +{ + /* https://github.com/namhyung/uftrace/blob/v0.18/libmcount/record.c#L= 909 */ + 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) > TRACE_FLUSH_SIZE) { + 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 +352,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 +363,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 +376,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 +385,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) @@ -297,6 +434,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 / TRACE_ID_SCALE); + /* trace_id is: cpu_number * TRACE_ID_SCALE */ + uint32_t trace_id =3D (vcpu_index + 1) * TRACE_ID_SCALE; + + 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 @@ -305,6 +452,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)); } @@ -312,6 +460,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.3