From nobody Sun Sep 28 17:12:15 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=1756799575; cv=none; d=zohomail.com; s=zohoarc; b=a0R5HbHtZjK63oPZD/S0PkrIeDpbdBrZF5ZTwOGoOWHhTlbb3224A3NJbmODox1wRyCUxdn22zg6lHf2cRZEprN6QxkLB2NSpkz1SKjE6WEfkt3o6ZdxgH7shMWPhcO3mHeS0B/W2iHFpbIOHaQRAlMc/BRrN+RgYaNFoogb0RQ= ARC-Message-Signature: i=1; a=rsa-sha256; c=relaxed/relaxed; d=zohomail.com; s=zohoarc; t=1756799575; 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=GSfyk/HqfC8n0v5Y6ucX/C1jK6jRJAOoqt5Ytsqhg8I=; b=DIG9slabQTvxAXDfvl7B43zQmYGoSiyCVKviMr4oq8Ag9Gs0uzYzjV9wdq15ep14wWhsi8p2Mv/JO8wLejGVBpS96Mmd5TtPgJda0ZJ+hj7iA2Yyil5Xy0UFw6W+JoZF3nJrFbKqqbIc+lEgvtUIzLjDxB/89jrS7C2ynvQBlzI= 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 1756799575402431.6643323861755; Tue, 2 Sep 2025 00:52:55 -0700 (PDT) Received: from localhost ([::1] helo=lists1p.gnu.org) by lists.gnu.org with esmtp (Exim 4.90_1) (envelope-from ) id 1utLnT-00079O-EI; Tue, 02 Sep 2025 03:51:19 -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 1utLnF-000748-OQ for qemu-devel@nongnu.org; Tue, 02 Sep 2025 03:51:06 -0400 Received: from mail-pf1-x42d.google.com ([2607:f8b0:4864:20::42d]) by eggs.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_128_GCM_SHA256:128) (Exim 4.90_1) (envelope-from ) id 1utLnB-0001uv-FJ for qemu-devel@nongnu.org; Tue, 02 Sep 2025 03:51:05 -0400 Received: by mail-pf1-x42d.google.com with SMTP id d2e1a72fcca58-7725fb32e1bso1662428b3a.1 for ; Tue, 02 Sep 2025 00:51:00 -0700 (PDT) Received: from pc.taild8403c.ts.net ([38.41.223.211]) by smtp.gmail.com with ESMTPSA id d2e1a72fcca58-7723d79fcfesm9642766b3a.16.2025.09.02.00.50.59 (version=TLS1_3 cipher=TLS_AES_256_GCM_SHA384 bits=256/256); Tue, 02 Sep 2025 00:50:59 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=linaro.org; s=google; t=1756799460; x=1757404260; 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=GSfyk/HqfC8n0v5Y6ucX/C1jK6jRJAOoqt5Ytsqhg8I=; b=hIj2zzeqoztzjoH6De5HCvwOmM8gKx6oE3l71L9QYPgHCK3NZx6alJZTLlfArBt4aF mNES1aNfNzDJT9I+423aMYovkVEnHLUelrC0DpFQQEqjCqeOQFmb4wSVt2QQNaHEKfNv 6noI2T0ve35N+EwoQYTiyM1fft16GkkHzVXWdTSysMlDUFG4IovSlWTG69kfEPQL9env tpeB4LM5wtigjlRNfPb4FW6QTNl+TYRbNofKxKtzUwIsQ+SF2leiwC/GyJcCwg9v6uGX SeOmmfIw2Inqf9fuw3X/f/JsLP1KbhSI4csWabrqCcCDE1NqaSX0FKH/v/YROsPZCId1 4bOw== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20230601; t=1756799460; x=1757404260; 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=GSfyk/HqfC8n0v5Y6ucX/C1jK6jRJAOoqt5Ytsqhg8I=; b=Y2njTo8s8CjPIk9/2sIcxK3LVFJ+WTom603Sk4cTZIdSJLXd8ZeC0BwMMNwiB5c4vP b0vVugL//sOw5hLCnxeezXPM0ehMNYPdlITaNMdcsAofYWyp++E7qjkh2N0UCvUdmtMV qHcQbuCZrQ7fq8+M2ALSRviUUg038K+EVlEgyMU7ffUSPe2Yd9BVIbL53CNwcySboN5e HvzXhQH4WRvYr6yZokSUXboiUt/JqrLZDJhFiQA+/BdiWcfrEltXIdApSaaNSAqgCnUR 1xn3oIaYu8v7GJbyfN46EghE1ohdVUrheoqX0NTlj00YT9uoqMUPA/OSB7vt0ym2pHU5 g7vw== X-Forwarded-Encrypted: i=1; AJvYcCW+w2iI6TQPCMctcLpAGo1r12R+09U3Zlw8CR2y2luvJt+dymzLs9OZH86ROyz45kSV1F6S3N7RnXLy@nongnu.org X-Gm-Message-State: AOJu0YyZfi4jFQUTF22t+UtX+ZI4/W3D10c0mCPVA/QcR6GB1rZbVQ1B Fc2rx8l5P/AN60D7o3g+l0xzLRMKfhtJ5raAjxiCSNWbDfAI25zXyevDgOB6mDls0Qc= X-Gm-Gg: ASbGncsDkTOl3jLzi8soV4ZdbB4SThj8eGgmHrzAD4muaXm26wUvVXpaDU50SR06sS3 nlh03GE87xSG0tKwkDvqP79+RI82pglmZ8cYSFMHggVDDzkyKM371e8ZDI5zhXHc1o1Q6x8Qxbc ZletQZZosCK4GkmvjZKDrp/JZAYYwRs/aszlkePMU56rU2B/FpXZw2JbFUMQq6tcki69du66A7v /NFEiJqAdbh41pcpE+DEgSdWGS/zfu++9QfXJzHf8hGf6YLhOwGPgQ57zaOp6RDoePOWJmTqmxo 3b5TY3pcz4I+O4y71di90JTvFP6RmZtU7AEwDnsOLVlLHf9/l3AUnRUfdI3nRojMt39AQF3gtOd VatSkCpv0pMlCNO0g/cM8o8tElC2eRigL3g4Arvt4TzP3QnET9I8DGg== X-Google-Smtp-Source: AGHT+IHVgHvKowN7epw1lJQIRwVAyrPE2dXskSXU0sXIDANUX0/5LF+Kp5EdXHxPwV/MQzN5DQSYYg== X-Received: by 2002:a05:6a00:2e08:b0:76b:f8ee:4eaa with SMTP id d2e1a72fcca58-7723e24ff0cmr12199348b3a.9.1756799459811; Tue, 02 Sep 2025 00:50:59 -0700 (PDT) From: Pierrick Bouvier To: pierrick.bouvier@linaro.org, qemu-devel@nongnu.org Cc: Peter Maydell , =?UTF-8?q?Alex=20Benn=C3=A9e?= , Richard Henderson , =?UTF-8?q?Philippe=20Mathieu-Daud=C3=A9?= , Manos Pitsidianakis , Alexandre Iooss , Gustavo Romero , Mahmoud Mandour , rowan Hart Subject: [PATCH v7 4/9] contrib/plugins/uftrace: implement tracing Date: Tue, 2 Sep 2025 00:50:37 -0700 Message-ID: <20250902075042.223990-5-pierrick.bouvier@linaro.org> X-Mailer: git-send-email 2.47.2 In-Reply-To: <20250902075042.223990-1-pierrick.bouvier@linaro.org> References: <20250902075042.223990-1-pierrick.bouvier@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=2607:f8b0:4864:20::42d; envelope-from=pierrick.bouvier@linaro.org; helo=mail-pf1-x42d.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: 1756799577361124100 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 --- 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.2