[Qemu-devel] [RFC PATCH V2 5/5] cpu_exec: Print to console if the guest is late

[Sebastian Tanase]

If the align option is enabled, we print to the user whenever
the guest clock is behind the host clock in order for he/she
to have a hint about the actual performance. The maximum
print interval is 2s so as not to spam the console.

Signed-off-by: Sebastian Tanase <address@hidden>
Tested-by: Camille Bégué <address@hidden>
---
 cpu-exec.c | 32 +++++++++++++++++++++++++++++++-
 1 file changed, 31 insertions(+), 1 deletion(-)

diff --git a/cpu-exec.c b/cpu-exec.c
index 5a3bc5e..a386592 100644
--- a/cpu-exec.c
+++ b/cpu-exec.c
@@ -216,6 +216,8 @@ static void cpu_handle_debug_exception(CPUArchState *env)
  * oscillate around 0.
  */
 #define VM_CLOCK_ADVANCE 3000000
+#define THRESHOLD_REDUCE 1.5
+#define MAX_DELAY_PRINT_RATE 2
 
 static int64_t delay_host(int64_t diff_clk)
 {
@@ -257,6 +259,29 @@ static int64_t align_clocks(int64_t diff_clk, int64_t 
*oic, CPUState *cpu)
     return diff_clk;
 }
 
+static void print_delay(int64_t diff_clk, int64_t realtime_clock)
+{
+    static float threshold_delay;
+    static int64_t last_realtime_clock;
+
+    if ((realtime_clock - last_realtime_clock) / 1000000000LL
+        >= MAX_DELAY_PRINT_RATE) {
+        if (-diff_clk / (float)1000000000LL > threshold_delay) {
+            threshold_delay = (-diff_clk / 1000000000LL) + 1;
+            printf("Warning: The guest is late by %.1f to %.1f seconds\n",
+                   threshold_delay - 1,
+                   threshold_delay);
+        } else if (-diff_clk / (float)1000000000LL <
+                   (threshold_delay - THRESHOLD_REDUCE)) {
+            threshold_delay = (-diff_clk / 1000000000LL) + 1;
+                   printf("Warning: The guest has reduced the delay and is now 
"
+                   "late by %.1f to %.1f seconds\n",
+                   threshold_delay - 1,
+                   threshold_delay);
+        }
+        last_realtime_clock = realtime_clock;
+    }
+}
 #endif /* CONFIG USER ONLY */
 
 /* main execution loop */
@@ -278,6 +303,8 @@ int cpu_exec(CPUArchState *env)
     uint8_t *tc_ptr;
     uintptr_t next_tb;
 #if !(defined(CONFIG_USER_ONLY))
+    /* Print delay control */
+    static int64_t realtime_clock;
     /* Delay algorithm */
     int64_t diff_clk, original_instr_counter;
 #endif
@@ -342,9 +369,12 @@ int cpu_exec(CPUArchState *env)
            This delay includes the delay of the last cycle, so
            what we have to do is sleep until it is 0. As for the
            advance/delay we gain here, we try to fix it next time. */
+        realtime_clock = qemu_clock_get_ns(QEMU_CLOCK_REALTIME);
         diff_clk = qemu_clock_get_ns(QEMU_CLOCK_VIRTUAL) -
-                   qemu_clock_get_ns(QEMU_CLOCK_REALTIME) + clocks_offset;
+                   realtime_clock + clocks_offset;
         original_instr_counter = cpu->icount_extra + cpu->icount_decr.u16.low;
+        /* Print (every 2s max) if the guest is behind the host */
+        print_delay(diff_clk, realtime_clock);
     }
 #endif
     /* prepare setjmp context for exception handling */
-- 
2.0.0.rc2