From a1bccb9b394abf4614bf64259375545f0059972e Mon Sep 17 00:00:00 2001 From: Pavlin Radoslavov Date: Wed, 17 Feb 2016 15:42:38 -0800 Subject: [PATCH] Add support for collecting A2DP Protobuf metrics * Add new function metrics_a2dp_session() to connect A2DP metrics into Protobuf * Add new function btif_update_a2dp_metrics() that is called when the metrics should be callected * Add few more statistics to the BTIF media stats. Change-Id: I5862ac82e55b3546dc1fbde0c78cb4683e40d19e --- btif/include/btif_media.h | 2 +- btif/src/bluetooth.c | 2 ++ btif/src/btif_media_task.c | 68 ++++++++++++++++++++++++++++++++++++++++++++++ osi/include/metrics.h | 26 ++++++++++++++++++ osi/src/metrics.cpp | 48 ++++++++++++++++++++++++++++---- 5 files changed, 140 insertions(+), 6 deletions(-) diff --git a/btif/include/btif_media.h b/btif/include/btif_media.h index 7823af6a1..832a70105 100644 --- a/btif/include/btif_media.h +++ b/btif/include/btif_media.h @@ -300,5 +300,5 @@ void btif_a2dp_set_audio_focus_state(btif_media_audio_focus_state state); #endif void btif_debug_a2dp_dump(int fd); - +void btif_update_a2dp_metrics(void); #endif diff --git a/btif/src/bluetooth.c b/btif/src/bluetooth.c index e1e51853b..218282f68 100644 --- a/btif/src/bluetooth.c +++ b/btif/src/bluetooth.c @@ -329,10 +329,12 @@ static void dump(int fd, const char **arguments) { if (arguments != NULL && arguments[0] != NULL) { if (strncmp(arguments[0], "--proto-text", 11) == 0) { + btif_update_a2dp_metrics(); metrics_print(fd, true); return; } if (strncmp(arguments[0], "--proto-bin", 10) == 0) { + btif_update_a2dp_metrics(); metrics_write(fd, true); return; } diff --git a/btif/src/btif_media_task.c b/btif/src/btif_media_task.c index e7ff9f4de..b44ee3444 100644 --- a/btif/src/btif_media_task.c +++ b/btif/src/btif_media_task.c @@ -63,6 +63,7 @@ #include "osi/include/alarm.h" #include "osi/include/fixed_queue.h" #include "osi/include/log.h" +#include "osi/include/metrics.h" #include "osi/include/mutex.h" #include "osi/include/thread.h" @@ -218,9 +219,17 @@ typedef struct { // Max. premature scheduling delta time (in us) uint64_t max_premature_scheduling_delta_us; + + // Counter for exact scheduling + size_t exact_scheduling_count; + + // Accumulated and counted scheduling time (in us) + uint64_t total_scheduling_time_us; } scheduling_stats_t; typedef struct { + uint64_t session_start_us; + scheduling_stats_t tx_queue_enqueue_stats; scheduling_stats_t tx_queue_dequeue_stats; @@ -399,6 +408,7 @@ static void update_scheduling_stats(scheduling_stats_t *stats, stats->max_overdue_scheduling_delta_us = delta_us; stats->total_overdue_scheduling_delta_us += delta_us; stats->overdue_scheduling_count++; + stats->total_scheduling_time_us += now_us - last_us; } } else if (deadline_us > now_us) { // Premature scheduling @@ -409,7 +419,12 @@ static void update_scheduling_stats(scheduling_stats_t *stats, stats->max_premature_scheduling_delta_us = delta_us; stats->total_premature_scheduling_delta_us += delta_us; stats->premature_scheduling_count++; + stats->total_scheduling_time_us += now_us - last_us; } + } else { + // On-time scheduling + stats->exact_scheduling_count++; + stats->total_scheduling_time_us += now_us - last_us; } } @@ -1349,6 +1364,8 @@ static void btif_media_task_aa_handle_uipc_rx_rdy(void) static void btif_media_thread_init(UNUSED_ATTR void *context) { memset(&btif_media_cb, 0, sizeof(btif_media_cb)); + btif_media_cb.stats.session_start_us = time_now_us(); + UIPC_Init(NULL); #if (BTA_AV_INCLUDED == TRUE) @@ -3063,3 +3080,54 @@ void btif_debug_a2dp_dump(int fd) (unsigned long long)ave_time_us / 1000); } + +void btif_update_a2dp_metrics(void) +{ + uint64_t now_us = time_now_us(); + btif_media_stats_t *stats = &btif_media_cb.stats; + scheduling_stats_t *dequeue_stats = &stats->tx_queue_dequeue_stats; + int32_t media_timer_min_ms = 0; + int32_t media_timer_max_ms = 0; + int32_t media_timer_avg_ms = 0; + int32_t buffer_overruns_max_count = 0; + int32_t buffer_overruns_total = 0; + float buffer_underruns_average = 0.0; + int32_t buffer_underruns_count = 0; + + int64_t session_duration_sec = + (now_us - stats->session_start_us) / (1000 * 1000); + + /* TODO: Disconnect reason is not supported (yet) */ + const char *disconnect_reason = NULL; + uint32_t device_class = BTM_COD_MAJOR_AUDIO; + + if (dequeue_stats->total_updates > 1) { + media_timer_min_ms = BTIF_SINK_MEDIA_TIME_TICK_MS - + (dequeue_stats->max_premature_scheduling_delta_us / 1000); + media_timer_max_ms = BTIF_SINK_MEDIA_TIME_TICK_MS + + (dequeue_stats->max_overdue_scheduling_delta_us / 1000); + + uint64_t total_scheduling_count = + dequeue_stats->overdue_scheduling_count + + dequeue_stats->premature_scheduling_count + + dequeue_stats->exact_scheduling_count; + if (total_scheduling_count > 0) { + media_timer_avg_ms = dequeue_stats->total_scheduling_time_us / + (1000 * total_scheduling_count); + } + + /* + * TODO: What is buffer_overruns_max_count and + * buffer_underruns_average? + */ + buffer_overruns_total = stats->tx_queue_total_dropped_messages; + buffer_underruns_count = stats->media_read_total_underflow_count + + stats->media_read_total_underrun_count; + } + + metrics_a2dp_session(session_duration_sec, disconnect_reason, device_class, + media_timer_min_ms, media_timer_max_ms, + media_timer_avg_ms, buffer_overruns_max_count, + buffer_overruns_total, buffer_underruns_average, + buffer_underruns_count); +} diff --git a/osi/include/metrics.h b/osi/include/metrics.h index 85360f541..4855301af 100644 --- a/osi/include/metrics.h +++ b/osi/include/metrics.h @@ -62,6 +62,32 @@ typedef enum { void metrics_scan_event(bool start, const char *initator, scan_tech_t type, uint32_t results, uint64_t timestamp_ms); +// Record A2DP session information. +// |session_duration_sec| is the session duration (in seconds). +// |device_class| is the device class of the paired device. +// |media_timer_min_ms| is the minimum scheduled time (in milliseconds) +// of the media timer. +// |media_timer_max_ms| is the maximum scheduled time (in milliseconds) +// of the media timer. +// |media_timer_avg_ms| is the average scheduled time (in milliseconds) +// of the media timer. +// |buffer_overruns_max_count| - TODO - not clear what this is. +// |buffer_overruns_total| is the number of times the media buffer with +// audio data has overrun. +// |buffer_underruns_average| - TODO - not clear what this is. +// |buffer_underruns_count| is the number of times there was no enough +// audio data to add to the media buffer. +void metrics_a2dp_session(int64_t session_duration_sec, + const char *disconnect_reason, + uint32_t device_class, + int32_t media_timer_min_ms, + int32_t media_timer_max_ms, + int32_t media_timer_avg_ms, + int32_t buffer_overruns_max_count, + int32_t buffer_overruns_total, + float buffer_underruns_average, + int32_t buffer_underruns_count); + // Writes the metrics, in packed protobuf format, into the descriptor |fd|. // If |clear| is true, metrics events are cleared afterwards. void metrics_write(int fd, bool clear); diff --git a/osi/src/metrics.cpp b/osi/src/metrics.cpp index c1ccfc419..63be98ab8 100644 --- a/osi/src/metrics.cpp +++ b/osi/src/metrics.cpp @@ -32,7 +32,9 @@ extern "C" { #include +using clearcut::connectivity::A2DPSession; using clearcut::connectivity::BluetoothLog; +using clearcut::connectivity::BluetoothSession; using clearcut::connectivity::DeviceInfo; using clearcut::connectivity::DeviceInfo_DeviceType; using clearcut::connectivity::PairEvent; @@ -74,11 +76,10 @@ void metrics_pair_event(uint32_t disconnect_reason, uint64_t timestamp_ms, event->set_disconnect_reason(disconnect_reason); event->set_event_time_millis(timestamp_ms); - } void metrics_wake_event(wake_event_type_t type, const char *requestor, - const char *name, uint64_t timestamp) { + const char *name, uint64_t timestamp_ms) { lazy_initialize(); WakeEvent *event = pending->add_wake_event(); @@ -98,10 +99,9 @@ void metrics_wake_event(wake_event_type_t type, const char *requestor, if (name) event->set_name(name); - event->set_event_time_millis(timestamp); + event->set_event_time_millis(timestamp_ms); } - void metrics_scan_event(bool start, const char *initator, scan_tech_t type, uint32_t results, uint64_t timestamp_ms) { lazy_initialize(); @@ -116,7 +116,7 @@ void metrics_scan_event(bool start, const char *initator, scan_tech_t type, if (initator) event->set_initiator(initator); - ScanEvent_ScanTechnologyType scantype = ScanEvent::SCAN_TYPE_UNKNOWN; + ScanEvent::ScanTechnologyType scantype = ScanEvent::SCAN_TYPE_UNKNOWN; if (type == SCAN_TECH_TYPE_LE) scantype = ScanEvent::SCAN_TECH_TYPE_LE; @@ -132,6 +132,44 @@ void metrics_scan_event(bool start, const char *initator, scan_tech_t type, event->set_event_time_millis(timestamp_ms); } +void metrics_a2dp_session(int64_t session_duration_sec, + const char *disconnect_reason, + uint32_t device_class, + int32_t media_timer_min_ms, + int32_t media_timer_max_ms, + int32_t media_timer_avg_ms, + int32_t buffer_overruns_max_count, + int32_t buffer_overruns_total, + float buffer_underruns_average, + int32_t buffer_underruns_count) { + lazy_initialize(); + + BluetoothSession *bt_session = pending->add_session(); + + // Set connection type: for A2DP it is always BR/EDR + BluetoothSession::ConnectionTechnologyType conn_type = + BluetoothSession::CONNECTION_TECHNOLOGY_TYPE_BREDR; + bt_session->set_connection_technology_type(conn_type); + + bt_session->set_session_duration_sec(session_duration_sec); + if (disconnect_reason != NULL) + bt_session->set_disconnect_reason(disconnect_reason); + + // Set device: class and type are pre-defined + DeviceInfo *info = bt_session->mutable_device_connected_to(); + info->set_device_class(device_class); + info->set_device_type(DeviceInfo::DEVICE_TYPE_BREDR); + + A2DPSession *a2dp_session = bt_session->mutable_a2dp_session(); + a2dp_session->set_media_timer_min_millis(media_timer_min_ms); + a2dp_session->set_media_timer_max_millis(media_timer_max_ms); + a2dp_session->set_media_timer_avg_millis(media_timer_avg_ms); + a2dp_session->set_buffer_overruns_max_count(buffer_overruns_max_count); + a2dp_session->set_buffer_overruns_total(buffer_overruns_total); + a2dp_session->set_buffer_underruns_average(buffer_underruns_average); + a2dp_session->set_buffer_underruns_count(buffer_underruns_count); +} + void metrics_write(int fd, bool clear) { LOG_DEBUG(LOG_TAG, "%s serializing metrics", __func__); lazy_initialize(); -- 2.11.0