usage: timestamp-based-on-real-time=[on|off]

Instead of using number of instructions executed (which is per vcpu), we
use the wall time for timestamps. This is useful when tracing user mode
programs as well.

Signed-off-by: Pierrick Bouvier <pierrick.bouvier@linaro.org>
---
 contrib/plugins/uftrace.c | 29 +++++++++++++++++++++++++++++
 1 file changed, 29 insertions(+)

diff --git a/contrib/plugins/uftrace.c b/contrib/plugins/uftrace.c
index bd4219db693..9211f273700 100644
--- a/contrib/plugins/uftrace.c
+++ b/contrib/plugins/uftrace.c
@@ -94,8 +94,28 @@ enum uftrace_record_type {
 static struct qemu_plugin_scoreboard *score;
 static uint64_t trace_sample;
 static bool trace_privilege_level;
+static bool timestamp_based_on_real_time;
 static CpuOps arch_ops;
 
+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.
+     */
+    struct timeval tv;
+    gettimeofday(&tv, NULL);
+    uint64_t now_ns = tv.tv_sec * 1000 * 1000 * 1000 + tv.tv_usec * 1000;
+#else
+    struct timespec ts;
+    timespec_get(&ts, TIME_UTC);
+    uint64_t now_ns = ts.tv_sec * 1000 * 1000 * 1000 + ts.tv_nsec;
+#endif
+    return now_ns;
+}
+
 static void uftrace_write_map(bool system_emulation)
 {
     const char *path = "./uftrace.data/sid-0.map";
@@ -454,6 +474,9 @@ static void cpu_set_new_sample(Cpu *cpu, uint64_t timestamp)
 
 static uint64_t cpu_get_timestamp(const Cpu *cpu)
 {
+    if (timestamp_based_on_real_time) {
+        return gettime_ns();
+    }
     return cpu->insn_count;
 }
 
@@ -866,6 +889,12 @@ QEMU_PLUGIN_EXPORT int qemu_plugin_install(qemu_plugin_id_t id,
                 fprintf(stderr, "boolean argument parsing failed: %s\n", opt);
                 return -1;
             }
+        } else if (g_strcmp0(tokens[0], "timestamp-based-on-real-time") == 0) {
+            if (!qemu_plugin_bool_parse(tokens[0], tokens[1],
+                                        &timestamp_based_on_real_time)) {
+                fprintf(stderr, "boolean argument parsing failed: %s\n", opt);
+                return -1;
+            }
         } else {
             fprintf(stderr, "option parsing failed: %s\n", opt);
             return -1;
-- 
2.47.2

Pierrick Bouvier <pierrick.bouvier@linaro.org> writes:

> usage: timestamp-based-on-real-time=[on|off]
>
> Instead of using number of instructions executed (which is per vcpu), we
> use the wall time for timestamps. This is useful when tracing user mode
> programs as well.

Arguably it is the more useful default when examining flame graphs. The
instruction count is entirely artificial and wouldn't map onto real
execution time anyway.

Maybe use-icount-for-ts and default to off?

>
> Signed-off-by: Pierrick Bouvier <pierrick.bouvier@linaro.org>
> ---
>  contrib/plugins/uftrace.c | 29 +++++++++++++++++++++++++++++
>  1 file changed, 29 insertions(+)
>
> diff --git a/contrib/plugins/uftrace.c b/contrib/plugins/uftrace.c
> index bd4219db693..9211f273700 100644
> --- a/contrib/plugins/uftrace.c
> +++ b/contrib/plugins/uftrace.c
> @@ -94,8 +94,28 @@ enum uftrace_record_type {
>  static struct qemu_plugin_scoreboard *score;
>  static uint64_t trace_sample;
>  static bool trace_privilege_level;
> +static bool timestamp_based_on_real_time;
>  static CpuOps arch_ops;
>  
> +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.
> +     */
> +    struct timeval tv;
> +    gettimeofday(&tv, NULL);
> +    uint64_t now_ns = tv.tv_sec * 1000 * 1000 * 1000 + tv.tv_usec * 1000;
> +#else
> +    struct timespec ts;
> +    timespec_get(&ts, TIME_UTC);
> +    uint64_t now_ns = ts.tv_sec * 1000 * 1000 * 1000 + ts.tv_nsec;

Why use timspec_get here, QEMU's own timer uses:

  /* get host real time in nanosecond */
  static inline int64_t get_clock_realtime(void)
  {
      struct timeval tv;

      gettimeofday(&tv, NULL);
      return tv.tv_sec * 1000000000LL + (tv.tv_usec * 1000);
  }


> +#endif
> +    return now_ns;
> +}
> +
>  static void uftrace_write_map(bool system_emulation)
>  {
>      const char *path = "./uftrace.data/sid-0.map";
> @@ -454,6 +474,9 @@ static void cpu_set_new_sample(Cpu *cpu, uint64_t timestamp)
>  
>  static uint64_t cpu_get_timestamp(const Cpu *cpu)
>  {
> +    if (timestamp_based_on_real_time) {
> +        return gettime_ns();
> +    }
>      return cpu->insn_count;
>  }
>  
> @@ -866,6 +889,12 @@ QEMU_PLUGIN_EXPORT int qemu_plugin_install(qemu_plugin_id_t id,
>                  fprintf(stderr, "boolean argument parsing failed: %s\n", opt);
>                  return -1;
>              }
> +        } else if (g_strcmp0(tokens[0], "timestamp-based-on-real-time") == 0) {
> +            if (!qemu_plugin_bool_parse(tokens[0], tokens[1],
> +                                        &timestamp_based_on_real_time)) {
> +                fprintf(stderr, "boolean argument parsing failed: %s\n", opt);
> +                return -1;
> +            }
>          } else {
>              fprintf(stderr, "option parsing failed: %s\n", opt);
>              return -1;

-- 
Alex Bennée
Virtualisation Tech Lead @ Linaro

On 8/5/25 3:23 AM, Alex Bennée wrote:
> Pierrick Bouvier <pierrick.bouvier@linaro.org> writes:
> 
>> usage: timestamp-based-on-real-time=[on|off]
>>
>> Instead of using number of instructions executed (which is per vcpu), we
>> use the wall time for timestamps. This is useful when tracing user mode
>> programs as well.
> 
> Arguably it is the more useful default when examining flame graphs. The
> instruction count is entirely artificial and wouldn't map onto real
> execution time anyway.
> 
> Maybe use-icount-for-ts and default to off?
>

I don't mind changing the default if you prefer so.

>>
>> Signed-off-by: Pierrick Bouvier <pierrick.bouvier@linaro.org>
>> ---
>>   contrib/plugins/uftrace.c | 29 +++++++++++++++++++++++++++++
>>   1 file changed, 29 insertions(+)
>>
>> diff --git a/contrib/plugins/uftrace.c b/contrib/plugins/uftrace.c
>> index bd4219db693..9211f273700 100644
>> --- a/contrib/plugins/uftrace.c
>> +++ b/contrib/plugins/uftrace.c
>> @@ -94,8 +94,28 @@ enum uftrace_record_type {
>>   static struct qemu_plugin_scoreboard *score;
>>   static uint64_t trace_sample;
>>   static bool trace_privilege_level;
>> +static bool timestamp_based_on_real_time;
>>   static CpuOps arch_ops;
>>   
>> +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.
>> +     */
>> +    struct timeval tv;
>> +    gettimeofday(&tv, NULL);
>> +    uint64_t now_ns = tv.tv_sec * 1000 * 1000 * 1000 + tv.tv_usec * 1000;
>> +#else
>> +    struct timespec ts;
>> +    timespec_get(&ts, TIME_UTC);
>> +    uint64_t now_ns = ts.tv_sec * 1000 * 1000 * 1000 + ts.tv_nsec;
> 
> Why use timspec_get here, QEMU's own timer uses:
> 
>    /* get host real time in nanosecond */
>    static inline int64_t get_clock_realtime(void)
>    {
>        struct timeval tv;
> 
>        gettimeofday(&tv, NULL);
>        return tv.tv_sec * 1000000000LL + (tv.tv_usec * 1000);
>    }
>

We need nanoseconds timestamps (which timespec offers and not 
gettimeofday), or we lose precision for short lived functions, resulting 
in bad shaped traces.

> 
>> +#endif
>> +    return now_ns;
>> +}
>> +
>>   static void uftrace_write_map(bool system_emulation)
>>   {
>>       const char *path = "./uftrace.data/sid-0.map";
>> @@ -454,6 +474,9 @@ static void cpu_set_new_sample(Cpu *cpu, uint64_t timestamp)
>>   
>>   static uint64_t cpu_get_timestamp(const Cpu *cpu)
>>   {
>> +    if (timestamp_based_on_real_time) {
>> +        return gettime_ns();
>> +    }
>>       return cpu->insn_count;
>>   }
>>   
>> @@ -866,6 +889,12 @@ QEMU_PLUGIN_EXPORT int qemu_plugin_install(qemu_plugin_id_t id,
>>                   fprintf(stderr, "boolean argument parsing failed: %s\n", opt);
>>                   return -1;
>>               }
>> +        } else if (g_strcmp0(tokens[0], "timestamp-based-on-real-time") == 0) {
>> +            if (!qemu_plugin_bool_parse(tokens[0], tokens[1],
>> +                                        &timestamp_based_on_real_time)) {
>> +                fprintf(stderr, "boolean argument parsing failed: %s\n", opt);
>> +                return -1;
>> +            }
>>           } else {
>>               fprintf(stderr, "option parsing failed: %s\n", opt);
>>               return -1;
>