Track audio timer starts and stops.  Also trace delayed audio timer calls.

Signed-off-by: Gerd Hoffmann <kraxel@redhat.com>
---
 audio/audio.c      | 28 +++++++++++++++++++++++++---
 audio/trace-events |  5 +++++
 2 files changed, 30 insertions(+), 3 deletions(-)

diff --git a/audio/audio.c b/audio/audio.c
index d6e91901aa..1ace47f510 100644
--- a/audio/audio.c
+++ b/audio/audio.c
@@ -29,6 +29,7 @@
 #include "sysemu/sysemu.h"
 #include "qemu/cutils.h"
 #include "sysemu/replay.h"
+#include "trace.h"
 
 #define AUDIO_CAP "audio"
 #include "audio_int.h"
@@ -1129,6 +1130,10 @@ static void audio_pcm_print_info (const char *cap, struct audio_pcm_info *info)
 /*
  * Timer
  */
+
+static bool audio_timer_running;
+static uint64_t audio_timer_last;
+
 static int audio_is_timer_needed (void)
 {
     HWVoiceIn *hwi = NULL;
@@ -1148,14 +1153,31 @@ static void audio_reset_timer (AudioState *s)
     if (audio_is_timer_needed ()) {
         timer_mod_anticipate_ns(s->ts,
             qemu_clock_get_ns(QEMU_CLOCK_VIRTUAL) + conf.period.ticks);
-    }
-    else {
-        timer_del (s->ts);
+        if (!audio_timer_running) {
+            audio_timer_running = true;
+            audio_timer_last = qemu_clock_get_ns(QEMU_CLOCK_VIRTUAL);
+            trace_audio_timer_start(conf.period.ticks / SCALE_MS);
+        }
+    } else {
+        timer_del(s->ts);
+        if (audio_timer_running) {
+            audio_timer_running = false;
+            trace_audio_timer_stop();
+        }
     }
 }
 
 static void audio_timer (void *opaque)
 {
+    int64_t now, diff;
+
+    now = qemu_clock_get_ns(QEMU_CLOCK_VIRTUAL);
+    diff = now - audio_timer_last;
+    if (diff > conf.period.ticks * 3 / 2) {
+        trace_audio_timer_delayed(diff / SCALE_MS);
+    }
+    audio_timer_last = now;
+
     audio_run ("timer");
     audio_reset_timer (opaque);
 }
diff --git a/audio/trace-events b/audio/trace-events
index d37639e611..c986469319 100644
--- a/audio/trace-events
+++ b/audio/trace-events
@@ -15,3 +15,8 @@ alsa_no_frames(int state) "No frames available and ALSA state is %d"
 # audio/ossaudio.c
 oss_version(int version) "OSS version = 0x%x"
 oss_invalid_available_size(int size, int bufsize) "Invalid available size, size=%d bufsize=%d"
+
+# audio/audio.c
+audio_timer_start(int interval) "interval %d ms"
+audio_timer_stop(void) ""
+audio_timer_delayed(int interval) "interval %d ms"
-- 
2.9.3

On 07/02/2018 01:15 PM, Gerd Hoffmann wrote:
> Track audio timer starts and stops.  Also trace delayed audio timer calls.
> 
> Signed-off-by: Gerd Hoffmann <kraxel@redhat.com>
> ---
>  audio/audio.c      | 28 +++++++++++++++++++++++++---
>  audio/trace-events |  5 +++++
>  2 files changed, 30 insertions(+), 3 deletions(-)
> 
> diff --git a/audio/audio.c b/audio/audio.c
> index d6e91901aa..1ace47f510 100644
> --- a/audio/audio.c
> +++ b/audio/audio.c
> @@ -29,6 +29,7 @@
>  #include "sysemu/sysemu.h"
>  #include "qemu/cutils.h"
>  #include "sysemu/replay.h"
> +#include "trace.h"
>  
>  #define AUDIO_CAP "audio"
>  #include "audio_int.h"
> @@ -1129,6 +1130,10 @@ static void audio_pcm_print_info (const char *cap, struct audio_pcm_info *info)
>  /*
>   * Timer
>   */
> +
> +static bool audio_timer_running;
> +static uint64_t audio_timer_last;
> +
>  static int audio_is_timer_needed (void)
>  {
>      HWVoiceIn *hwi = NULL;
> @@ -1148,14 +1153,31 @@ static void audio_reset_timer (AudioState *s)
>      if (audio_is_timer_needed ()) {
>          timer_mod_anticipate_ns(s->ts,
>              qemu_clock_get_ns(QEMU_CLOCK_VIRTUAL) + conf.period.ticks);
> -    }
> -    else {
> -        timer_del (s->ts);
> +        if (!audio_timer_running) {
> +            audio_timer_running = true;
> +            audio_timer_last = qemu_clock_get_ns(QEMU_CLOCK_VIRTUAL);
> +            trace_audio_timer_start(conf.period.ticks / SCALE_MS);

Thanks for the changes.

Reviewed-by: Philippe Mathieu-Daudé <f4bug@amsat.org>
Tested-by: Philippe Mathieu-Daudé <f4bug@amsat.org>

> +        }
> +    } else {
> +        timer_del(s->ts);
> +        if (audio_timer_running) {
> +            audio_timer_running = false;
> +            trace_audio_timer_stop();
> +        }
>      }
>  }
>  
>  static void audio_timer (void *opaque)
>  {
> +    int64_t now, diff;
> +
> +    now = qemu_clock_get_ns(QEMU_CLOCK_VIRTUAL);
> +    diff = now - audio_timer_last;
> +    if (diff > conf.period.ticks * 3 / 2) {
> +        trace_audio_timer_delayed(diff / SCALE_MS);
> +    }
> +    audio_timer_last = now;
> +
>      audio_run ("timer");
>      audio_reset_timer (opaque);
>  }
> diff --git a/audio/trace-events b/audio/trace-events
> index d37639e611..c986469319 100644
> --- a/audio/trace-events
> +++ b/audio/trace-events
> @@ -15,3 +15,8 @@ alsa_no_frames(int state) "No frames available and ALSA state is %d"
>  # audio/ossaudio.c
>  oss_version(int version) "OSS version = 0x%x"
>  oss_invalid_available_size(int size, int bufsize) "Invalid available size, size=%d bufsize=%d"
> +
> +# audio/audio.c
> +audio_timer_start(int interval) "interval %d ms"
> +audio_timer_stop(void) ""
> +audio_timer_delayed(int interval) "interval %d ms"
>