[Qemu-devel] [RFC PATCH V4 5/6] 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 and we limit the number of messages to 100.
If desired, this can be changed in cpu-exec.c

Signed-off-by: Sebastian Tanase <address@hidden>
Tested-by: Camille Bégué <address@hidden>

Conflicts:
        cpu-exec.c
---
 cpu-exec.c | 39 ++++++++++++++++++++++++++++++++++-----
 1 file changed, 34 insertions(+), 5 deletions(-)

diff --git a/cpu-exec.c b/cpu-exec.c
index 9ed6ac1..b62df15 100644
--- a/cpu-exec.c
+++ b/cpu-exec.c
@@ -29,6 +29,7 @@
 typedef struct SyncClocks {
     int64_t diff_clk;
     int64_t original_instr_counter;
+    int64_t realtime_clock;
 } SyncClocks;
 
 #if !defined(CONFIG_USER_ONLY)
@@ -37,6 +38,9 @@ typedef struct SyncClocks {
  * oscillate around 0.
  */
 #define VM_CLOCK_ADVANCE 3000000
+#define THRESHOLD_REDUCE 1.5
+#define MAX_DELAY_PRINT_RATE 2
+#define MAX_NB_PRINTS 100
 
 static int64_t delay_host(int64_t diff_clk)
 {
@@ -80,6 +84,28 @@ static void align_clocks(SyncClocks *sc, const CPUState *cpu)
     sc->diff_clk = delay_host(sc->diff_clk);
 }
 
+static void print_delay(const SyncClocks *sc)
+{
+    static float threshold_delay;
+    static int64_t last_realtime_clock;
+    static int nb_prints;
+
+    if (icount_align_option &&
+        (sc->realtime_clock - last_realtime_clock) / 1000000000LL
+        >= MAX_DELAY_PRINT_RATE && nb_prints < MAX_NB_PRINTS) {
+        if ((-sc->diff_clk / (float)1000000000LL > threshold_delay) ||
+            (-sc->diff_clk / (float)1000000000LL <
+             (threshold_delay - THRESHOLD_REDUCE))) {
+            threshold_delay = (-sc->diff_clk / 1000000000LL) + 1;
+            printf("Warning: The guest is now late by %.1f to %.1f seconds\n",
+                   threshold_delay - 1,
+                   threshold_delay);
+            nb_prints++;
+            last_realtime_clock = sc->realtime_clock;
+        }
+    }
+}
+
 static void init_delay_params(SyncClocks *sc,
                               const CPUState *cpu)
 {
@@ -87,15 +113,18 @@ static void init_delay_params(SyncClocks *sc,
     if (!icount_align_option) {
         return;
     }
-    int64_t realtime_clock_value, virtual_clock_value;
-    realtime_clock_value = qemu_clock_get_ns(QEMU_CLOCK_REALTIME);
-    virtual_clock_value = qemu_clock_get_ns(QEMU_CLOCK_VIRTUAL);
+    sc->realtime_clock = qemu_clock_get_ns(QEMU_CLOCK_REALTIME);
     /* Compute offset between the 2 clocks. */
     if (!clocks_offset) {
-        clocks_offset = realtime_clock_value - virtual_clock_value;
+        clocks_offset = sc->realtime_clock -
+                        qemu_clock_get_ns(QEMU_CLOCK_VIRTUAL);
     }
-    sc->diff_clk = virtual_clock_value - realtime_clock_value + clocks_offset;
+    sc->diff_clk = qemu_clock_get_ns(QEMU_CLOCK_VIRTUAL) -
+                   sc->realtime_clock + clocks_offset;
     sc->original_instr_counter = cpu->icount_extra + cpu->icount_decr.u16.low;
+    /* Print every 2s max if the guest is late. We limit the number
+       of printed messages to NB_PRINT_MAX(currently 100) */
+    print_delay(sc);
 }
 #else
 static void align_clocks(SyncClocks *sc, const CPUState *cpu)
-- 
2.0.0.rc2