Add startup time from idle statistics

Test: audioflinger dumpsys
Bug: 135729709
Bug: 124765214
Change-Id: I443f18fc80595810cf10d990a237139f8d35241c
(cherry picked from commit 81f79936b6dce64f6f7630a3b5cf8270f270d260)
Signed-off-by: Aniket Kumar Lata <alata@codeaurora.org>
This commit is contained in:
Andy Hung 2019-07-01 18:26:00 -07:00 committed by George Gao
parent a1f48fa465
commit c6bfd4a648
2 changed files with 26 additions and 0 deletions

View File

@ -4549,6 +4549,11 @@ static int out_dump(const struct audio_stream *stream, int fd)
dprintf(fd, " Fifo frame underruns: %s\n", buffer); dprintf(fd, " Fifo frame underruns: %s\n", buffer);
} }
if (out->start_latency_ms.n > 0) {
simple_stats_to_string(&out->start_latency_ms, buffer, sizeof(buffer));
dprintf(fd, " Start latency ms: %s\n", buffer);
}
if (locked) { if (locked) {
pthread_mutex_unlock(&out->lock); pthread_mutex_unlock(&out->lock);
} }
@ -5705,6 +5710,8 @@ static ssize_t out_write(struct audio_stream_out *stream, const void *buffer,
if (out->standby) { if (out->standby) {
out->standby = false; out->standby = false;
const int64_t startNs = systemTime(SYSTEM_TIME_MONOTONIC);
pthread_mutex_lock(&adev->lock); pthread_mutex_lock(&adev->lock);
if (out->usecase == USECASE_COMPRESS_VOIP_CALL) if (out->usecase == USECASE_COMPRESS_VOIP_CALL)
ret = voice_extn_compress_voip_start_output_stream(out); ret = voice_extn_compress_voip_start_output_stream(out);
@ -5732,6 +5739,10 @@ static ssize_t out_write(struct audio_stream_out *stream, const void *buffer,
} }
if (out->set_dual_mono) if (out->set_dual_mono)
audio_extn_send_dual_mono_mixing_coefficients(out); audio_extn_send_dual_mono_mixing_coefficients(out);
// log startup time in ms.
simple_stats_log(
&out->start_latency_ms, (systemTime(SYSTEM_TIME_MONOTONIC) - startNs) * 1e-6);
} }
if (adev->is_channel_status_set == false && if (adev->is_channel_status_set == false &&
@ -6646,6 +6657,12 @@ static int in_dump(const struct audio_stream *stream,
dprintf(fd, " Frames read: %lld\n", (long long)in->frames_read); dprintf(fd, " Frames read: %lld\n", (long long)in->frames_read);
dprintf(fd, " Frames muted: %lld\n", (long long)in->frames_muted); dprintf(fd, " Frames muted: %lld\n", (long long)in->frames_muted);
char buffer[256]; // for statistics formatting
if (in->start_latency_ms.n > 0) {
simple_stats_to_string(&in->start_latency_ms, buffer, sizeof(buffer));
dprintf(fd, " Start latency ms: %s\n", buffer);
}
if (locked) { if (locked) {
pthread_mutex_unlock(&in->lock); pthread_mutex_unlock(&in->lock);
} }
@ -6908,6 +6925,8 @@ static ssize_t in_read(struct audio_stream_in *stream, void *buffer,
} }
if (in->standby) { if (in->standby) {
const int64_t startNs = systemTime(SYSTEM_TIME_MONOTONIC);
pthread_mutex_lock(&adev->lock); pthread_mutex_lock(&adev->lock);
if (in->usecase == USECASE_COMPRESS_VOIP_CALL) if (in->usecase == USECASE_COMPRESS_VOIP_CALL)
ret = voice_extn_compress_voip_start_input_stream(in); ret = voice_extn_compress_voip_start_input_stream(in);
@ -6922,6 +6941,10 @@ static ssize_t in_read(struct audio_stream_in *stream, void *buffer,
goto exit; goto exit;
} }
in->standby = 0; in->standby = 0;
// log startup time in ms.
simple_stats_log(
&in->start_latency_ms, (systemTime(SYSTEM_TIME_MONOTONIC) - startNs) * 1e-6);
} }
/* Avoid read if capture_stopped is set */ /* Avoid read if capture_stopped is set */

View File

@ -465,6 +465,7 @@ struct stream_out {
int64_t last_fifo_time_ns; int64_t last_fifo_time_ns;
simple_stats_t fifo_underruns; // TODO: keep a list of the last N fifo underrun times. simple_stats_t fifo_underruns; // TODO: keep a list of the last N fifo underrun times.
simple_stats_t start_latency_ms;
}; };
struct stream_in { struct stream_in {
@ -518,6 +519,8 @@ struct stream_in {
int64_t frames_muted; /* total frames muted, not cleared when entering standby */ int64_t frames_muted; /* total frames muted, not cleared when entering standby */
error_log_t *error_log; error_log_t *error_log;
simple_stats_t start_latency_ms;
}; };
typedef enum { typedef enum {