From 92bfc6a70ef6b6a7b39f277fcaca7240bb9b905f Mon Sep 17 00:00:00 2001 From: Yu-Hsuan Date: Mon, 15 Apr 2024 12:29:30 +0800 Subject: CRAS: Log samples dropped of devices Add UMA DeviceSamplesDropped.{Device_type} to log the number of samples dropped. BUG=b:333632030 TEST=Use stressapptest to tigger overrun and check the UMA logs. Change-Id: Iaeab8a8b037545d316c4a31f4f678d8b3e21e6ef Reviewed-on: https://chromium-review.googlesource.com/c/chromiumos/third_party/adhd/+/5449641 Tested-by: chromeos-cop-builder@chromeos-cop.iam.gserviceaccount.com Reviewed-by: Li-Yu Yu Commit-Queue: Yu-Hsuan Hsu --- cras/client/cras-sys/src/lib.rs | 3 +++ .../deprecated/cras_test_client/cras_test_client.c | 2 ++ cras/include/cras_types.h | 1 + cras/src/server/audio_thread.c | 1 + cras/src/server/cras_iodev.c | 7 +++++ cras/src/server/cras_iodev.h | 10 +++++++ cras/src/server/cras_server_metrics.c | 31 ++++++++++++++++++++++ cras/src/server/cras_server_metrics.h | 3 +++ cras/src/server/dev_io.c | 2 ++ cras/src/tests/metrics_stub.cc | 4 +++ cras/src/tests/server_metrics_unittest.cc | 5 ++++ 11 files changed, 69 insertions(+) diff --git a/cras/client/cras-sys/src/lib.rs b/cras/client/cras-sys/src/lib.rs index 35c9f633..3ac69a16 100644 --- a/cras/client/cras-sys/src/lib.rs +++ b/cras/client/cras-sys/src/lib.rs @@ -400,6 +400,7 @@ impl Default for audio_dev_debug_info { num_underruns: 0, num_underruns_during_nc: 0, num_severe_underruns: 0, + num_samples_dropped: 0, highest_hw_level: 0, runtime_sec: 0, runtime_nsec: 0, @@ -428,6 +429,7 @@ pub struct AudioDevDebugInfo { pub num_underruns: u32, pub num_underruns_during_nc: u32, pub num_severe_underruns: u32, + pub num_samples_dropped: u32, pub highest_hw_level: u32, #[serde(rename = "runtime_sec", serialize_with = "serialize_duration_secs")] pub runtime: Duration, @@ -455,6 +457,7 @@ impl From for AudioDevDebugInfo { num_underruns: info.num_underruns, num_underruns_during_nc: info.num_underruns_during_nc, num_severe_underruns: info.num_severe_underruns, + num_samples_dropped: info.num_samples_dropped, highest_hw_level: info.highest_hw_level, runtime: Duration::new(info.runtime_sec.into(), info.runtime_nsec), longest_wake: Duration::new(info.longest_wake_sec.into(), info.longest_wake_nsec), diff --git a/cras/deprecated/cras_test_client/cras_test_client.c b/cras/deprecated/cras_test_client/cras_test_client.c index aff4a8ee..9666bc5c 100644 --- a/cras/deprecated/cras_test_client/cras_test_client.c +++ b/cras/deprecated/cras_test_client/cras_test_client.c @@ -1134,6 +1134,7 @@ static void print_aligned_audio_debug_info(const struct audio_debug_info* info, "num_underruns: %u\n" "num_underruns_during_nc: %u\n" "num_severe_underruns: %u\n" + "num_samples_dropped: %u\n" "highest_hw_level: %u\n" "runtime: %u.%09u\n" "longest_wake: %u.%09u\n" @@ -1149,6 +1150,7 @@ static void print_aligned_audio_debug_info(const struct audio_debug_info* info, (unsigned int)info->devs[i].num_underruns, (unsigned int)info->devs[i].num_underruns_during_nc, (unsigned int)info->devs[i].num_severe_underruns, + (unsigned int)info->devs[i].num_samples_dropped, (unsigned int)info->devs[i].highest_hw_level, (unsigned int)info->devs[i].runtime_sec, (unsigned int)info->devs[i].runtime_nsec, diff --git a/cras/include/cras_types.h b/cras/include/cras_types.h index 00738c29..998db882 100644 --- a/cras/include/cras_types.h +++ b/cras/include/cras_types.h @@ -462,6 +462,7 @@ struct __attribute__((__packed__)) audio_dev_debug_info { uint32_t num_underruns; uint32_t num_underruns_during_nc; uint32_t num_severe_underruns; + uint32_t num_samples_dropped; uint32_t highest_hw_level; uint32_t runtime_sec; uint32_t runtime_nsec; diff --git a/cras/src/server/audio_thread.c b/cras/src/server/audio_thread.c index d74f6e13..2cadf3ce 100644 --- a/cras/src/server/audio_thread.c +++ b/cras/src/server/audio_thread.c @@ -514,6 +514,7 @@ static void append_dev_dump_info(struct audio_dev_debug_info* di, di->num_underruns_during_nc = cras_iodev_get_num_underruns_during_nc(adev->dev); di->num_severe_underruns = cras_iodev_get_num_severe_underruns(adev->dev); + di->num_samples_dropped = cras_iodev_get_num_samples_dropped(adev->dev); di->highest_hw_level = adev->dev->highest_hw_level; di->internal_gain_scaler = (adev->dev->direction == CRAS_STREAM_INPUT) ? adev->dev->internal_gain_scaler diff --git a/cras/src/server/cras_iodev.c b/cras/src/server/cras_iodev.c index 6cc5800f..ae547b45 100644 --- a/cras/src/server/cras_iodev.c +++ b/cras/src/server/cras_iodev.c @@ -1196,6 +1196,7 @@ int cras_iodev_open(struct cras_iodev* iodev, iodev->largest_cb_level = 0; iodev->num_underruns = 0; iodev->num_underruns_during_nc = 0; + iodev->num_samples_dropped = 0; iodev->reset_request_pending = 0; iodev->state = CRAS_IODEV_STATE_OPEN; @@ -1807,6 +1808,11 @@ unsigned int cras_iodev_get_num_severe_underruns( return 0; } +unsigned int cras_iodev_get_num_samples_dropped( + const struct cras_iodev* iodev) { + return iodev->num_samples_dropped; +} + int cras_iodev_reset_request(struct cras_iodev* iodev) { /* Ignore requests if there is a pending request. * This function sends the request from audio thread to main @@ -2041,6 +2047,7 @@ static int cras_iodev_drop_frames(struct cras_iodev* iodev, rate_estimator_add_frames(iodev->rate_est, -frames); } + iodev->num_samples_dropped += dropped_frames; ATLOG(atlog, AUDIO_THREAD_DEV_DROP_FRAMES, iodev->info.idx, dropped_frames, 0); diff --git a/cras/src/server/cras_iodev.h b/cras/src/server/cras_iodev.h index ef9e02e9..1addb76a 100644 --- a/cras/src/server/cras_iodev.h +++ b/cras/src/server/cras_iodev.h @@ -395,6 +395,8 @@ struct cras_iodev { unsigned int num_underruns; // Number of underruns while AP NC is running. unsigned int num_underruns_during_nc; + // Number of samples dropped. + unsigned int num_samples_dropped; double rate_est_underrun; // Timestamp of the last update to the reset quota. struct timespec last_reset_timeref; @@ -900,6 +902,14 @@ unsigned int cras_iodev_get_num_underruns_during_nc( unsigned int cras_iodev_get_num_severe_underruns( const struct cras_iodev* iodev); +/* Get number of samples dropped so far. + * Args: + * iodev[in] - The device. + * Returns: + * An unsigned int for number of samples dropped. + */ +unsigned int cras_iodev_get_num_samples_dropped(const struct cras_iodev* iodev); + /* Get number of valid frames in the hardware buffer. The valid frames does * not include zero samples we filled with before. * Args: diff --git a/cras/src/server/cras_server_metrics.c b/cras/src/server/cras_server_metrics.c index a15a1b87..83c26407 100644 --- a/cras/src/server/cras_server_metrics.c +++ b/cras/src/server/cras_server_metrics.c @@ -43,6 +43,7 @@ const char kDeviceNoiseCancellationStatus[] = "Cras.DeviceNoiseCancellationStatus"; const char kDeviceSampleFormat[] = "Cras.DeviceSampleFormat"; const char kDeviceSampleRate[] = "Cras.DeviceSampleRate"; +const char kDeviceSamplesDropped[] = "Cras.DeviceSamplesDropped"; const char kDeviceDspOffloadStatus[] = "Cras.DeviceDspOffloadStatus"; const char kFetchDelayMilliSeconds[] = "Cras.FetchDelayMilliSeconds"; const char kFetchDelayCount[] = "Cras.FetchDelayCount"; @@ -147,6 +148,7 @@ enum CRAS_SERVER_METRICS_TYPE { DEVICE_NOISE_CANCELLATION_STATUS, DEVICE_SAMPLE_FORMAT, DEVICE_SAMPLE_RATE, + DEVICE_SAMPLES_DROPPED, DEVICE_DSP_OFFLOAD_STATUS, DLC_MANAGER_STATUS, HIGHEST_DEVICE_DELAY_INPUT, @@ -1195,6 +1197,29 @@ int cras_server_metrics_num_underruns_during_apnc(struct cras_iodev* iodev) { return 0; } +int cras_server_metrics_device_samples_dropped(struct cras_iodev* iodev) { + struct cras_server_metrics_message msg = CRAS_MAIN_MESSAGE_INIT; + union cras_server_metrics_data data; + int err; + + if (iodev->direction != CRAS_STREAM_INPUT) { + return 0; + } + + data.device_data.value = cras_iodev_get_num_samples_dropped(iodev); + data.device_data.type = get_metrics_device_type(iodev); + + init_server_metrics_msg(&msg, DEVICE_SAMPLES_DROPPED, data); + err = cras_server_metrics_message_send((struct cras_main_message*)&msg); + if (err < 0) { + syslog(LOG_WARNING, + "Failed to send metrics message: DEVICE_SAMPLES_DROPPED"); + return err; + } + + return 0; +} + // Logs the frequency of missed callback. static int cras_server_metrics_missed_cb_frequency( const struct cras_rstream* stream) { @@ -2000,6 +2025,12 @@ static void handle_metrics_message(struct cras_main_message* msg, void* arg) { case DEVICE_SAMPLE_RATE: metrics_device_sample_rate(metrics_msg->data.device_data); break; + case DEVICE_SAMPLES_DROPPED: + log_histogram_each_level( + 2, (unsigned)metrics_msg->data.device_data.value, 0, 2000000000, 50, + kDeviceSamplesDropped, + metrics_device_type_str(metrics_msg->data.device_data.type)); + break; case DEVICE_DSP_OFFLOAD_STATUS: metrics_device_dsp_offload_status(metrics_msg->data.device_data); break; diff --git a/cras/src/server/cras_server_metrics.h b/cras/src/server/cras_server_metrics.h index e621a5a3..88860a77 100644 --- a/cras/src/server/cras_server_metrics.h +++ b/cras/src/server/cras_server_metrics.h @@ -154,6 +154,9 @@ int cras_server_metrics_device_sample_format(struct cras_iodev* iodev); // Logs the sample rate of a device. int cras_server_metrics_device_sample_rate(struct cras_iodev* iodev); +// Logs the sample dropped of a device. +int cras_server_metrics_device_samples_dropped(struct cras_iodev* iodev); + // Logs the device type when cras clients request to set aec ref. int cras_server_metrics_set_aec_ref_device_type(struct cras_iodev* iodev); diff --git a/cras/src/server/dev_io.c b/cras/src/server/dev_io.c index dcb6556b..88b0042d 100644 --- a/cras/src/server/dev_io.c +++ b/cras/src/server/dev_io.c @@ -1490,6 +1490,8 @@ void dev_io_rm_open_dev(struct open_dev** odev_list, cras_server_metrics_num_underruns_during_apnc(dev_to_rm->dev); } + cras_server_metrics_device_samples_dropped(dev_to_rm->dev); + // Metrics logs the delay of this device. cras_server_metrics_highest_device_delay(dev_to_rm->dev->highest_hw_level, dev_to_rm->dev->largest_cb_level, diff --git a/cras/src/tests/metrics_stub.cc b/cras/src/tests/metrics_stub.cc index fd05e524..3cf6410d 100644 --- a/cras/src/tests/metrics_stub.cc +++ b/cras/src/tests/metrics_stub.cc @@ -31,6 +31,10 @@ int cras_server_metrics_device_sample_rate(struct cras_iodev* iodev) { return 0; } +int cras_server_metrics_device_samples_dropped(struct cras_iodev* iodev) { + return 0; +} + int cras_server_metrics_device_configure_time(struct cras_iodev* iodev, struct timespec* beg, struct timespec* end) { diff --git a/cras/src/tests/server_metrics_unittest.cc b/cras/src/tests/server_metrics_unittest.cc index 1f666277..c57593d2 100644 --- a/cras/src/tests/server_metrics_unittest.cc +++ b/cras/src/tests/server_metrics_unittest.cc @@ -586,5 +586,10 @@ unsigned int cras_iodev_get_num_underruns_during_nc( return iodev->num_underruns_during_nc; } +unsigned int cras_iodev_get_num_samples_dropped( + const struct cras_iodev* iodev) { + return iodev->num_samples_dropped; +} + } // extern "C" } // namespace -- cgit v1.2.3