1 /*
2 * Copyright (C) 2019 The Android Open Source Project
3 *
4 * Licensed under the Apache License, Version 2.0 (the "License");
5 * you may not use this file except in compliance with the License.
6 * You may obtain a copy of the License at
7 *
8 * http://www.apache.org/licenses/LICENSE-2.0
9 *
10 * Unless required by applicable law or agreed to in writing, software
11 * distributed under the License is distributed on an "AS IS" BASIS,
12 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13 * See the License for the specific language governing permissions and
14 * limitations under the License.
15 */
16
17 //#define LOG_NDEBUG 0
18 #define LOG_TAG "AudioAnalytics"
19 #include <android-base/logging.h>
20 #include <utils/Log.h>
21
22 #include "AudioAnalytics.h"
23
24 #include <aaudio/AAudio.h> // error codes
25 #include <audio_utils/clock.h> // clock conversions
26 #include <cutils/properties.h>
27 #include <stats_media_metrics.h> // statsd
28 #include <system/audio.h>
29
30 #include "AudioTypes.h" // string to int conversions
31 #include "MediaMetricsService.h" // package info
32 #include "StringUtils.h"
33 #include "ValidateId.h"
34
35 #define PROP_AUDIO_ANALYTICS_CLOUD_ENABLED "persist.audio.analytics.cloud.enabled"
36
37 namespace android::mediametrics {
38
39 // Enable for testing of delivery to statsd. Caution if this is enabled, all protos MUST exist.
40 #define STATSD_ENABLE
41
42 #ifdef STATSD_ENABLE
43 #define CONDITION(INT_VALUE) (INT_VALUE) // allow value
44 #else
45 #define CONDITION(INT_VALUE) (int(0)) // mask value since the proto may not be defined yet.
46 #endif
47
48 // Maximum length of a device name.
49 // static constexpr size_t STATSD_DEVICE_NAME_MAX_LENGTH = 32; // unused since we suppress
50
51 // Transmit Enums to statsd in integer or strings (this must match the atoms.proto)
52 static constexpr bool STATSD_USE_INT_FOR_ENUM = false;
53
54 // derive types based on integer or strings.
55 using short_enum_type_t = std::conditional_t<STATSD_USE_INT_FOR_ENUM, int32_t, std::string>;
56 using long_enum_type_t = std::conditional_t<STATSD_USE_INT_FOR_ENUM, int64_t, std::string>;
57
58 // Convert std::string to char *
59 template <typename T>
ENUM_EXTRACT(const T & x)60 auto ENUM_EXTRACT(const T& x) {
61 if constexpr (std::is_same_v<std::decay_t<T>, std::string>) {
62 return x.c_str();
63 } else {
64 return x;
65 }
66 }
67
68 // The status variable contains status_t codes which are used by
69 // the core audio framework. We also consider AAudio status codes.
70 //
71 // Compare with mediametrics::statusToStatusString
72 //
extendedStatusToStatusString(status_t status)73 inline constexpr const char* extendedStatusToStatusString(status_t status) {
74 switch (status) {
75 case BAD_VALUE: // status_t
76 case AAUDIO_ERROR_ILLEGAL_ARGUMENT:
77 case AAUDIO_ERROR_INVALID_FORMAT:
78 case AAUDIO_ERROR_INVALID_RATE:
79 case AAUDIO_ERROR_NULL:
80 case AAUDIO_ERROR_OUT_OF_RANGE:
81 return AMEDIAMETRICS_PROP_STATUS_VALUE_ARGUMENT;
82 case DEAD_OBJECT: // status_t
83 case FAILED_TRANSACTION: // status_t
84 case AAUDIO_ERROR_DISCONNECTED:
85 case AAUDIO_ERROR_INVALID_HANDLE:
86 case AAUDIO_ERROR_NO_SERVICE:
87 return AMEDIAMETRICS_PROP_STATUS_VALUE_IO;
88 case NO_MEMORY: // status_t
89 case AAUDIO_ERROR_NO_FREE_HANDLES:
90 case AAUDIO_ERROR_NO_MEMORY:
91 return AMEDIAMETRICS_PROP_STATUS_VALUE_MEMORY;
92 case PERMISSION_DENIED: // status_t
93 return AMEDIAMETRICS_PROP_STATUS_VALUE_SECURITY;
94 case INVALID_OPERATION: // status_t
95 case NO_INIT: // status_t
96 case AAUDIO_ERROR_INVALID_STATE:
97 case AAUDIO_ERROR_UNAVAILABLE:
98 case AAUDIO_ERROR_UNIMPLEMENTED:
99 return AMEDIAMETRICS_PROP_STATUS_VALUE_STATE;
100 case WOULD_BLOCK: // status_t
101 case AAUDIO_ERROR_TIMEOUT:
102 case AAUDIO_ERROR_WOULD_BLOCK:
103 return AMEDIAMETRICS_PROP_STATUS_VALUE_TIMEOUT;
104 default:
105 if (status >= 0) return AMEDIAMETRICS_PROP_STATUS_VALUE_OK; // non-negative values "OK"
106 [[fallthrough]]; // negative values are error.
107 case UNKNOWN_ERROR: // status_t
108 return AMEDIAMETRICS_PROP_STATUS_VALUE_UNKNOWN;
109 }
110 }
111
112 static constexpr const auto LOG_LEVEL = android::base::VERBOSE;
113
114 static constexpr int PREVIOUS_STATE_EXPIRE_SEC = 60 * 60; // 1 hour.
115
116 static constexpr const char * SUPPRESSED = "SUPPRESSED";
117
118 /*
119 * For logging purposes, we list all of the MediaMetrics atom fields,
120 * which can then be associated with consecutive arguments to the statsd write.
121 */
122
123 static constexpr const char * const AudioRecordDeviceUsageFields[] = {
124 "mediametrics_audiorecorddeviceusage_reported", // proto number
125 "devices",
126 "device_names",
127 "device_time_nanos",
128 "encoding",
129 "frame_count",
130 "interval_count",
131 "sample_rate",
132 "flags",
133 "package_name",
134 "selected_device_id",
135 "caller",
136 "source",
137 "log_session_id",
138 };
139
140 static constexpr const char * const AudioThreadDeviceUsageFields[] = {
141 "mediametrics_audiothreaddeviceusage_reported",
142 "devices",
143 "device_names",
144 "device_time_nanos",
145 "encoding",
146 "frame_count",
147 "interval_count",
148 "sample_rate",
149 "flags",
150 "xruns",
151 "type",
152 };
153
154 static constexpr const char * const AudioTrackDeviceUsageFields[] = {
155 "mediametrics_audiotrackdeviceusage_reported",
156 "devices",
157 "device_names",
158 "device_time_nanos",
159 "encoding",
160 "frame_count",
161 "interval_count",
162 "sample_rate",
163 "flags",
164 "xruns",
165 "package_name",
166 "device_latency_millis",
167 "device_startup_millis",
168 "device_volume",
169 "selected_device_id",
170 "stream_type",
171 "usage",
172 "content_type",
173 "caller",
174 "traits",
175 "log_session_id",
176 };
177
178 static constexpr const char * const AudioRecordStatusFields[] {
179 "mediametrics_audiorecordstatus_reported",
180 "status",
181 "debug_message",
182 "status_subcode",
183 "uid",
184 "event",
185 "input_flags",
186 "source",
187 "encoding",
188 "channel_mask",
189 "buffer_frame_count",
190 "sample_rate",
191 };
192
193 static constexpr const char * const AudioTrackStatusFields[] {
194 "mediametrics_audiotrackstatus_reported",
195 "status",
196 "debug_message",
197 "status_subcode",
198 "uid",
199 "event",
200 "output_flags",
201 "content_type",
202 "usage",
203 "encoding",
204 "channel_mask",
205 "buffer_frame_count",
206 "sample_rate",
207 "speed",
208 "pitch",
209 };
210
211 static constexpr const char * const AudioDeviceConnectionFields[] = {
212 "mediametrics_audiodeviceconnection_reported",
213 "input_devices",
214 "output_devices",
215 "device_names",
216 "result",
217 "time_to_connect_millis",
218 "connection_count",
219 };
220
221 static constexpr const char * const AAudioStreamFields[] {
222 "mediametrics_aaudiostream_reported",
223 "path",
224 "direction",
225 "frames_per_burst",
226 "buffer_size",
227 "buffer_capacity",
228 "channel_count",
229 "total_frames_transferred",
230 "perf_mode_requested",
231 "perf_mode_actual",
232 "sharing",
233 "xrun_count",
234 "device_type",
235 "format_app",
236 "format_device",
237 "log_session_id",
238 "sample_rate",
239 "content_type",
240 "sharing_requested",
241 "format_hardware",
242 "channel_count_hardware",
243 "sample_rate_hardware",
244 "uid",
245 "sample_rate_client",
246 };
247
248 static constexpr const char * HeadTrackerDeviceEnabledFields[] {
249 "mediametrics_headtrackerdeviceenabled_reported",
250 "type",
251 "event",
252 "enabled",
253 };
254
255 static constexpr const char * HeadTrackerDeviceSupportedFields[] {
256 "mediametrics_headtrackerdevicesupported_reported",
257 "type",
258 "event",
259 "supported",
260 };
261
262 static constexpr const char * SpatializerCapabilitiesFields[] {
263 "mediametrics_spatializer_reported",
264 "head_tracking_modes",
265 "spatializer_levels",
266 "spatializer_modes",
267 "channel_masks",
268 };
269
270 static constexpr const char * SpatializerDeviceEnabledFields[] {
271 "mediametrics_spatializerdeviceenabled_reported",
272 "type",
273 "event",
274 "enabled",
275 };
276
277 static constexpr const char * const MidiDeviceCloseFields[] {
278 "mediametrics_midi_device_close_reported",
279 "uid",
280 "midi_device_id",
281 "input_port_count",
282 "output_port_count",
283 "device_type",
284 "is_shared",
285 "supports_ump",
286 "using_alsa",
287 "duration_ns",
288 "opened_count",
289 "closed_count",
290 "device_disconnected",
291 "total_input_bytes",
292 "total_output_bytes",
293 };
294
295 /**
296 * printFields is a helper method that prints the fields and corresponding values
297 * in a human readable style.
298 */
299 template <size_t N, typename ...Types>
printFields(const char * const (& fields)[N],Types...args)300 std::string printFields(const char * const (& fields)[N], Types ... args)
301 {
302 std::stringstream ss;
303 ss << " { ";
304 stringutils::fieldPrint(ss, fields, args...);
305 ss << "}";
306 return ss.str();
307 }
308
309 /**
310 * sendToStatsd is a helper method that sends the arguments to statsd
311 */
312 template <typename ...Types>
sendToStatsd(Types...args)313 int sendToStatsd(Types ... args)
314 {
315 int result = 0;
316
317 #ifdef STATSD_ENABLE
318 if (__builtin_available(android 33, *)) {
319 result = stats::media_metrics::stats_write(args...);
320 }
321 #endif
322 return result;
323 }
324
325 /**
326 * sendToStatsd is a helper method that sends the arguments to statsd
327 * and returns a pair { result, summary_string }.
328 */
329 template <size_t N, typename ...Types>
sendToStatsd(const char * const (& fields)[N],Types...args)330 std::pair<int, std::string> sendToStatsd(const char * const (& fields)[N], Types ... args)
331 {
332 int result = 0;
333 std::stringstream ss;
334
335 #ifdef STATSD_ENABLE
336 if (__builtin_available(android 33, *)) {
337 result = stats::media_metrics::stats_write(args...);
338 }
339 ss << "result:" << result;
340 #endif
341 ss << " { ";
342 stringutils::fieldPrint(ss, fields, args...);
343 ss << "}";
344 return { result, ss.str() };
345 }
346
AudioAnalytics(const std::shared_ptr<StatsdLog> & statsdLog)347 AudioAnalytics::AudioAnalytics(const std::shared_ptr<StatsdLog>& statsdLog)
348 : mDeliverStatistics(property_get_bool(PROP_AUDIO_ANALYTICS_CLOUD_ENABLED, true))
349 , mStatsdLog(statsdLog)
350 , mAudioPowerUsage(this, statsdLog)
351 {
352 SetMinimumLogSeverity(android::base::DEBUG); // for LOG().
353 ALOGD("%s", __func__);
354
355 // Add action to save AnalyticsState if audioserver is restarted.
356 // This triggers on AudioFlinger or AudioPolicy ctors and onFirstRef,
357 // as well as TimeCheck events.
358 mActions.addAction(
359 AMEDIAMETRICS_KEY_AUDIO_FLINGER "." AMEDIAMETRICS_PROP_EVENT,
360 std::string(AMEDIAMETRICS_PROP_EVENT_VALUE_CTOR),
361 std::make_shared<AnalyticsActions::Function>(
362 [this](const std::shared_ptr<const android::mediametrics::Item> &item){
363 mHealth.onAudioServerStart(Health::Module::AUDIOFLINGER, item);
364 }));
365 mActions.addAction(
366 AMEDIAMETRICS_KEY_AUDIO_POLICY "." AMEDIAMETRICS_PROP_EVENT,
367 std::string(AMEDIAMETRICS_PROP_EVENT_VALUE_CTOR),
368 std::make_shared<AnalyticsActions::Function>(
369 [this](const std::shared_ptr<const android::mediametrics::Item> &item){
370 mHealth.onAudioServerStart(Health::Module::AUDIOPOLICY, item);
371 }));
372 mActions.addAction(
373 AMEDIAMETRICS_KEY_AUDIO_FLINGER "." AMEDIAMETRICS_PROP_EVENT,
374 std::string(AMEDIAMETRICS_PROP_EVENT_VALUE_TIMEOUT),
375 std::make_shared<AnalyticsActions::Function>(
376 [this](const std::shared_ptr<const android::mediametrics::Item> &item){
377 mHealth.onAudioServerTimeout(Health::Module::AUDIOFLINGER, item);
378 }));
379 mActions.addAction(
380 AMEDIAMETRICS_KEY_AUDIO_POLICY "." AMEDIAMETRICS_PROP_EVENT,
381 std::string(AMEDIAMETRICS_PROP_EVENT_VALUE_TIMEOUT),
382 std::make_shared<AnalyticsActions::Function>(
383 [this](const std::shared_ptr<const android::mediametrics::Item> &item){
384 mHealth.onAudioServerTimeout(Health::Module::AUDIOPOLICY, item);
385 }));
386
387 // Handle legacy aaudio playback stream statistics
388 mActions.addAction(
389 AMEDIAMETRICS_KEY_PREFIX_AUDIO_TRACK "*." AMEDIAMETRICS_PROP_EVENT,
390 std::string(AMEDIAMETRICS_PROP_EVENT_VALUE_ENDAAUDIOSTREAM),
391 std::make_shared<AnalyticsActions::Function>(
392 [this](const std::shared_ptr<const android::mediametrics::Item> &item) {
393 mAAudioStreamInfo.endAAudioStream(item, AAudioStreamInfo::CALLER_PATH_LEGACY);
394 }));
395
396 // Handle legacy aaudio capture stream statistics
397 mActions.addAction(
398 AMEDIAMETRICS_KEY_PREFIX_AUDIO_RECORD "*." AMEDIAMETRICS_PROP_EVENT,
399 std::string(AMEDIAMETRICS_PROP_EVENT_VALUE_ENDAAUDIOSTREAM),
400 std::make_shared<AnalyticsActions::Function>(
401 [this](const std::shared_ptr<const android::mediametrics::Item> &item) {
402 mAAudioStreamInfo.endAAudioStream(item, AAudioStreamInfo::CALLER_PATH_LEGACY);
403 }));
404
405 // Handle mmap aaudio stream statistics
406 mActions.addAction(
407 AMEDIAMETRICS_KEY_PREFIX_AUDIO_STREAM "*." AMEDIAMETRICS_PROP_EVENT,
408 std::string(AMEDIAMETRICS_PROP_EVENT_VALUE_ENDAAUDIOSTREAM),
409 std::make_shared<AnalyticsActions::Function>(
410 [this](const std::shared_ptr<const android::mediametrics::Item> &item) {
411 mAAudioStreamInfo.endAAudioStream(item, AAudioStreamInfo::CALLER_PATH_MMAP);
412 }));
413
414 // Handle device use record statistics
415 mActions.addAction(
416 AMEDIAMETRICS_KEY_PREFIX_AUDIO_RECORD "*." AMEDIAMETRICS_PROP_EVENT,
417 std::string(AMEDIAMETRICS_PROP_EVENT_VALUE_ENDAUDIOINTERVALGROUP),
418 std::make_shared<AnalyticsActions::Function>(
419 [this](const std::shared_ptr<const android::mediametrics::Item> &item){
420 mDeviceUse.endAudioIntervalGroup(item, DeviceUse::RECORD);
421 }));
422
423 // Handle device use thread statistics
424 mActions.addAction(
425 AMEDIAMETRICS_KEY_PREFIX_AUDIO_THREAD "*." AMEDIAMETRICS_PROP_EVENT,
426 std::string(AMEDIAMETRICS_PROP_EVENT_VALUE_ENDAUDIOINTERVALGROUP),
427 std::make_shared<AnalyticsActions::Function>(
428 [this](const std::shared_ptr<const android::mediametrics::Item> &item){
429 mDeviceUse.endAudioIntervalGroup(item, DeviceUse::THREAD);
430 }));
431
432 // Handle device use track statistics
433 mActions.addAction(
434 AMEDIAMETRICS_KEY_PREFIX_AUDIO_TRACK "*." AMEDIAMETRICS_PROP_EVENT,
435 std::string(AMEDIAMETRICS_PROP_EVENT_VALUE_ENDAUDIOINTERVALGROUP),
436 std::make_shared<AnalyticsActions::Function>(
437 [this](const std::shared_ptr<const android::mediametrics::Item> &item){
438 mDeviceUse.endAudioIntervalGroup(item, DeviceUse::TRACK);
439 }));
440
441
442 // Handle device connection statistics
443
444 // We track connections (not disconnections) for the time to connect.
445 // TODO: consider BT requests in their A2dp service
446 // AudioManager.setBluetoothA2dpDeviceConnectionStateSuppressNoisyIntent
447 // AudioDeviceBroker.postBluetoothA2dpDeviceConnectionStateSuppressNoisyIntent
448 // AudioDeviceBroker.postA2dpActiveDeviceChange
449 mActions.addAction(
450 "audio.device.a2dp.state",
451 "connected",
452 std::make_shared<AnalyticsActions::Function>(
453 [this](const std::shared_ptr<const android::mediametrics::Item> &item){
454 mDeviceConnection.a2dpConnected(item);
455 }));
456 // If audio is active, we expect to see a createAudioPatch after the device is connected.
457 mActions.addAction(
458 AMEDIAMETRICS_KEY_PREFIX_AUDIO_THREAD "*." AMEDIAMETRICS_PROP_EVENT,
459 std::string("createAudioPatch"),
460 std::make_shared<AnalyticsActions::Function>(
461 [this](const std::shared_ptr<const android::mediametrics::Item> &item){
462 mDeviceConnection.createPatch(item);
463 }));
464
465 // Called from BT service
466 mActions.addAction(
467 AMEDIAMETRICS_KEY_PREFIX_AUDIO_DEVICE
468 "postBluetoothA2dpDeviceConnectionStateSuppressNoisyIntent"
469 "." AMEDIAMETRICS_PROP_STATE,
470 "connected",
471 std::make_shared<AnalyticsActions::Function>(
472 [this](const std::shared_ptr<const android::mediametrics::Item> &item){
473 mDeviceConnection.postBluetoothA2dpDeviceConnectionStateSuppressNoisyIntent(item);
474 }));
475
476 // Handle power usage
477 mActions.addAction(
478 AMEDIAMETRICS_KEY_PREFIX_AUDIO_TRACK "*." AMEDIAMETRICS_PROP_EVENT,
479 std::string(AMEDIAMETRICS_PROP_EVENT_VALUE_ENDAUDIOINTERVALGROUP),
480 std::make_shared<AnalyticsActions::Function>(
481 [this](const std::shared_ptr<const android::mediametrics::Item> &item){
482 mAudioPowerUsage.checkTrackRecord(item, true /* isTrack */);
483 }));
484
485 mActions.addAction(
486 AMEDIAMETRICS_KEY_PREFIX_AUDIO_RECORD "*." AMEDIAMETRICS_PROP_EVENT,
487 std::string(AMEDIAMETRICS_PROP_EVENT_VALUE_ENDAUDIOINTERVALGROUP),
488 std::make_shared<AnalyticsActions::Function>(
489 [this](const std::shared_ptr<const android::mediametrics::Item> &item){
490 mAudioPowerUsage.checkTrackRecord(item, false /* isTrack */);
491 }));
492
493 mActions.addAction(
494 AMEDIAMETRICS_KEY_AUDIO_FLINGER "." AMEDIAMETRICS_PROP_EVENT,
495 std::string(AMEDIAMETRICS_PROP_EVENT_VALUE_SETMODE),
496 std::make_shared<AnalyticsActions::Function>(
497 [this](const std::shared_ptr<const android::mediametrics::Item> &item){
498 // ALOGD("(key=%s) Audioflinger setMode", item->getKey().c_str());
499 mAudioPowerUsage.checkMode(item);
500 }));
501
502 mActions.addAction(
503 AMEDIAMETRICS_KEY_AUDIO_FLINGER "." AMEDIAMETRICS_PROP_EVENT,
504 std::string(AMEDIAMETRICS_PROP_EVENT_VALUE_SETVOICEVOLUME),
505 std::make_shared<AnalyticsActions::Function>(
506 [this](const std::shared_ptr<const android::mediametrics::Item> &item){
507 // ALOGD("(key=%s) Audioflinger setVoiceVolume", item->getKey().c_str());
508 mAudioPowerUsage.checkVoiceVolume(item);
509 }));
510
511 mActions.addAction(
512 AMEDIAMETRICS_KEY_PREFIX_AUDIO_THREAD "*." AMEDIAMETRICS_PROP_EVENT,
513 std::string("createAudioPatch"),
514 std::make_shared<AnalyticsActions::Function>(
515 [this](const std::shared_ptr<const android::mediametrics::Item> &item){
516 mAudioPowerUsage.checkCreatePatch(item);
517 }));
518
519 // Handle Spatializer - these keys are prefixed by "audio.spatializer."
520 mActions.addAction(
521 AMEDIAMETRICS_KEY_PREFIX_AUDIO_SPATIALIZER "*." AMEDIAMETRICS_PROP_EVENT,
522 std::monostate{}, /* match any event */
523 std::make_shared<AnalyticsActions::Function>(
524 [this](const std::shared_ptr<const android::mediametrics::Item> &item){
525 mSpatializer.onEvent(item);
526 }));
527
528 // Handle MIDI
529 mActions.addAction(
530 AMEDIAMETRICS_KEY_AUDIO_MIDI "." AMEDIAMETRICS_PROP_EVENT,
531 std::string(AMEDIAMETRICS_PROP_EVENT_VALUE_DEVICECLOSED),
532 std::make_shared<AnalyticsActions::Function>(
533 [this](const std::shared_ptr<const android::mediametrics::Item> &item) {
534 mMidiLogging.onEvent(item);
535 }));
536 }
537
~AudioAnalytics()538 AudioAnalytics::~AudioAnalytics()
539 {
540 ALOGD("%s", __func__);
541 mTimedAction.quit(); // ensure no deferred access during destructor.
542 }
543
submit(const std::shared_ptr<const mediametrics::Item> & item,bool isTrusted)544 status_t AudioAnalytics::submit(
545 const std::shared_ptr<const mediametrics::Item>& item, bool isTrusted)
546 {
547 if (!startsWith(item->getKey(), AMEDIAMETRICS_KEY_PREFIX_AUDIO)) return BAD_VALUE;
548 status_t status = mAnalyticsState->submit(item, isTrusted);
549
550 // Status is selectively authenticated.
551 processStatus(item);
552
553 if (status != NO_ERROR) return status; // may not be permitted.
554
555 // Only if the item was successfully submitted (permission)
556 // do we check triggered actions.
557 processActions(item);
558 return NO_ERROR;
559 }
560
dump(bool details,int32_t lines,int64_t sinceNs,const char * prefix) const561 std::pair<std::string, int32_t> AudioAnalytics::dump(
562 bool details, int32_t lines, int64_t sinceNs, const char *prefix) const
563 {
564 std::stringstream ss;
565 int32_t ll = lines;
566
567 if (ll > 0) {
568 auto [s, l] = mAnalyticsState->dump(details, ll, sinceNs, prefix);
569 ss << s;
570 ll -= l;
571 }
572
573 // use details to dump prior state.
574 if (details && ll > 0) {
575 ss << "Prior audioserver state:\n";
576 --ll;
577 }
578 if (details && ll > 0) {
579 auto [s, l] = mPreviousAnalyticsState->dump(details, ll, sinceNs, prefix);
580 ss << s;
581 ll -= l;
582 }
583
584 if (ll > 0 && prefix == nullptr) {
585 auto [s, l] = mAudioPowerUsage.dump(ll);
586 ss << s;
587 ll -= l;
588 }
589
590 return { ss.str(), lines - ll };
591 }
592
processActions(const std::shared_ptr<const mediametrics::Item> & item)593 void AudioAnalytics::processActions(const std::shared_ptr<const mediametrics::Item>& item)
594 {
595 auto actions = mActions.getActionsForItem(item); // internally locked.
596 // Execute actions with no lock held.
597 for (const auto& action : actions) {
598 (*action)(item);
599 }
600 }
601
processStatus(const std::shared_ptr<const mediametrics::Item> & item)602 void AudioAnalytics::processStatus(const std::shared_ptr<const mediametrics::Item>& item)
603 {
604 int32_t status;
605 if (!item->get(AMEDIAMETRICS_PROP_STATUS, &status)) return;
606
607 // Any record with a status will automatically be added to a heat map.
608 // Standard information.
609 const auto key = item->getKey();
610 const auto uid = item->getUid();
611
612 // from audio.track.10 -> prefix = audio.track, suffix = 10
613 // from audio.track.error -> prefix = audio.track, suffix = error
614 const auto [prefixKey, suffixKey] = stringutils::splitPrefixKey(key);
615
616 std::string message;
617 item->get(AMEDIAMETRICS_PROP_STATUSMESSAGE, &message); // optional
618
619 int32_t subCode = 0; // not used
620 (void)item->get(AMEDIAMETRICS_PROP_STATUSSUBCODE, &subCode); // optional
621
622 std::string eventStr; // optional
623 item->get(AMEDIAMETRICS_PROP_EVENT, &eventStr);
624
625 const std::string statusString = extendedStatusToStatusString(status);
626
627 // Add to the heat map - we automatically track every item's status to see
628 // the types of errors and the frequency of errors.
629 mHeatMap.add(prefixKey, suffixKey, eventStr, statusString, uid, message, subCode);
630
631 // Certain keys/event pairs are sent to statsd. If we get a match (true) we return early.
632 if (reportAudioRecordStatus(item, key, eventStr, statusString, uid, message, subCode)) return;
633 if (reportAudioTrackStatus(item, key, eventStr, statusString, uid, message, subCode)) return;
634 }
635
reportAudioRecordStatus(const std::shared_ptr<const mediametrics::Item> & item,const std::string & key,const std::string & eventStr,const std::string & statusString,uid_t uid,const std::string & message,int32_t subCode) const636 bool AudioAnalytics::reportAudioRecordStatus(
637 const std::shared_ptr<const mediametrics::Item>& item,
638 const std::string& key, const std::string& eventStr,
639 const std::string& statusString, uid_t uid, const std::string& message,
640 int32_t subCode) const
641 {
642 // Note that the prefixes often end with a '.' so we use startsWith.
643 if (!startsWith(key, AMEDIAMETRICS_KEY_PREFIX_AUDIO_RECORD)) return false;
644 if (eventStr == AMEDIAMETRICS_PROP_EVENT_VALUE_CREATE) {
645 const int atom_status = types::lookup<types::STATUS, int32_t>(statusString);
646
647 // currently we only send create status events.
648 const int32_t event = stats::media_metrics::
649 MEDIAMETRICS_AUDIO_RECORD_STATUS_REPORTED__EVENT__AUDIO_RECORD_EVENT_CREATE;
650
651 // The following fields should all be present in a create event.
652 std::string flagsStr;
653 ALOGD_IF(!item->get(AMEDIAMETRICS_PROP_ORIGINALFLAGS, &flagsStr),
654 "%s: %s missing %s field", __func__,
655 AMEDIAMETRICS_KEY_PREFIX_AUDIO_RECORD, AMEDIAMETRICS_PROP_ORIGINALFLAGS);
656 const auto flags = types::lookup<types::INPUT_FLAG, int32_t>(flagsStr);
657
658 // AMEDIAMETRICS_PROP_SESSIONID omitted from atom
659
660 std::string sourceStr;
661 ALOGD_IF(!item->get(AMEDIAMETRICS_PROP_SOURCE, &sourceStr),
662 "%s: %s missing %s field",
663 __func__, AMEDIAMETRICS_KEY_PREFIX_AUDIO_RECORD, AMEDIAMETRICS_PROP_SOURCE);
664 const int32_t source = types::lookup<types::SOURCE_TYPE, int32_t>(sourceStr);
665
666 // AMEDIAMETRICS_PROP_SELECTEDDEVICEID omitted from atom
667
668 std::string encodingStr;
669 ALOGD_IF(!item->get(AMEDIAMETRICS_PROP_ENCODING, &encodingStr),
670 "%s: %s missing %s field",
671 __func__, AMEDIAMETRICS_KEY_PREFIX_AUDIO_RECORD, AMEDIAMETRICS_PROP_ENCODING);
672 const auto encoding = types::lookup<types::ENCODING, int32_t>(encodingStr);
673
674 int32_t channelMask = 0;
675 ALOGD_IF(!item->get(AMEDIAMETRICS_PROP_CHANNELMASK, &channelMask),
676 "%s: %s missing %s field",
677 __func__, AMEDIAMETRICS_KEY_PREFIX_AUDIO_RECORD, AMEDIAMETRICS_PROP_CHANNELMASK);
678 int32_t frameCount = 0;
679 ALOGD_IF(!item->get(AMEDIAMETRICS_PROP_FRAMECOUNT, &frameCount),
680 "%s: %s missing %s field",
681 __func__, AMEDIAMETRICS_KEY_PREFIX_AUDIO_RECORD, AMEDIAMETRICS_PROP_FRAMECOUNT);
682 int32_t sampleRate = 0;
683 ALOGD_IF(!item->get(AMEDIAMETRICS_PROP_SAMPLERATE, &sampleRate),
684 "%s: %s missing %s field",
685 __func__, AMEDIAMETRICS_KEY_PREFIX_AUDIO_RECORD, AMEDIAMETRICS_PROP_SAMPLERATE);
686
687 const auto [ result, str ] = sendToStatsd(AudioRecordStatusFields,
688 CONDITION(stats::media_metrics::MEDIAMETRICS_AUDIORECORDSTATUS_REPORTED)
689 , atom_status
690 , message.c_str()
691 , subCode
692 , uid
693 , event
694 , flags
695 , source
696 , encoding
697 , (int64_t)channelMask
698 , frameCount
699 , sampleRate
700 );
701 ALOGV("%s: statsd %s", __func__, str.c_str());
702 mStatsdLog->log(stats::media_metrics::MEDIAMETRICS_AUDIORECORDSTATUS_REPORTED, str);
703 return true;
704 }
705 return false;
706 }
707
reportAudioTrackStatus(const std::shared_ptr<const mediametrics::Item> & item,const std::string & key,const std::string & eventStr,const std::string & statusString,uid_t uid,const std::string & message,int32_t subCode) const708 bool AudioAnalytics::reportAudioTrackStatus(
709 const std::shared_ptr<const mediametrics::Item>& item,
710 const std::string& key, const std::string& eventStr,
711 const std::string& statusString, uid_t uid, const std::string& message,
712 int32_t subCode) const
713 {
714 // Note that the prefixes often end with a '.' so we use startsWith.
715 if (!startsWith(key, AMEDIAMETRICS_KEY_PREFIX_AUDIO_TRACK)) return false;
716 if (eventStr == AMEDIAMETRICS_PROP_EVENT_VALUE_CREATE) {
717 const int atom_status = types::lookup<types::STATUS, int32_t>(statusString);
718
719 // currently we only send create status events.
720 const int32_t event = stats::media_metrics::
721 MEDIAMETRICS_AUDIO_TRACK_STATUS_REPORTED__EVENT__AUDIO_TRACK_EVENT_CREATE;
722
723 // The following fields should all be present in a create event.
724 std::string flagsStr;
725 ALOGD_IF(!item->get(AMEDIAMETRICS_PROP_ORIGINALFLAGS, &flagsStr),
726 "%s: %s missing %s field",
727 __func__, AMEDIAMETRICS_KEY_PREFIX_AUDIO_TRACK, AMEDIAMETRICS_PROP_ORIGINALFLAGS);
728 const auto flags = types::lookup<types::OUTPUT_FLAG, int32_t>(flagsStr);
729
730 // AMEDIAMETRICS_PROP_SESSIONID omitted from atom
731
732 std::string contentTypeStr;
733 ALOGD_IF(!item->get(AMEDIAMETRICS_PROP_CONTENTTYPE, &contentTypeStr),
734 "%s: %s missing %s field",
735 __func__, AMEDIAMETRICS_KEY_PREFIX_AUDIO_TRACK, AMEDIAMETRICS_PROP_CONTENTTYPE);
736 const auto contentType = types::lookup<types::CONTENT_TYPE, int32_t>(contentTypeStr);
737
738 std::string usageStr;
739 ALOGD_IF(!item->get(AMEDIAMETRICS_PROP_USAGE, &usageStr),
740 "%s: %s missing %s field",
741 __func__, AMEDIAMETRICS_KEY_PREFIX_AUDIO_TRACK, AMEDIAMETRICS_PROP_USAGE);
742 const auto usage = types::lookup<types::USAGE, int32_t>(usageStr);
743
744 // AMEDIAMETRICS_PROP_SELECTEDDEVICEID omitted from atom
745
746 std::string encodingStr;
747 ALOGD_IF(!item->get(AMEDIAMETRICS_PROP_ENCODING, &encodingStr),
748 "%s: %s missing %s field",
749 __func__, AMEDIAMETRICS_KEY_PREFIX_AUDIO_TRACK, AMEDIAMETRICS_PROP_ENCODING);
750 const auto encoding = types::lookup<types::ENCODING, int32_t>(encodingStr);
751
752 int32_t channelMask = 0;
753 ALOGD_IF(!item->get(AMEDIAMETRICS_PROP_CHANNELMASK, &channelMask),
754 "%s: %s missing %s field",
755 __func__, AMEDIAMETRICS_KEY_PREFIX_AUDIO_TRACK, AMEDIAMETRICS_PROP_CHANNELMASK);
756 int32_t frameCount = 0;
757 ALOGD_IF(!item->get(AMEDIAMETRICS_PROP_FRAMECOUNT, &frameCount),
758 "%s: %s missing %s field",
759 __func__, AMEDIAMETRICS_KEY_PREFIX_AUDIO_TRACK, AMEDIAMETRICS_PROP_FRAMECOUNT);
760 int32_t sampleRate = 0;
761 ALOGD_IF(!item->get(AMEDIAMETRICS_PROP_SAMPLERATE, &sampleRate),
762 "%s: %s missing %s field",
763 __func__, AMEDIAMETRICS_KEY_PREFIX_AUDIO_TRACK, AMEDIAMETRICS_PROP_SAMPLERATE);
764 double speed = 0.f; // default is 1.f
765 ALOGD_IF(!item->get(AMEDIAMETRICS_PROP_PLAYBACK_SPEED, &speed),
766 "%s: %s missing %s field",
767 __func__,
768 AMEDIAMETRICS_KEY_PREFIX_AUDIO_TRACK, AMEDIAMETRICS_PROP_PLAYBACK_SPEED);
769 double pitch = 0.f; // default is 1.f
770 ALOGD_IF(!item->get(AMEDIAMETRICS_PROP_PLAYBACK_PITCH, &pitch),
771 "%s: %s missing %s field",
772 __func__,
773 AMEDIAMETRICS_KEY_PREFIX_AUDIO_TRACK, AMEDIAMETRICS_PROP_PLAYBACK_PITCH);
774 const auto [ result, str ] = sendToStatsd(AudioTrackStatusFields,
775 CONDITION(stats::media_metrics::MEDIAMETRICS_AUDIOTRACKSTATUS_REPORTED)
776 , atom_status
777 , message.c_str()
778 , subCode
779 , uid
780 , event
781 , flags
782 , contentType
783 , usage
784 , encoding
785 , (int64_t)channelMask
786 , frameCount
787 , sampleRate
788 , (float)speed
789 , (float)pitch
790 );
791 ALOGV("%s: statsd %s", __func__, str.c_str());
792 mStatsdLog->log(stats::media_metrics::MEDIAMETRICS_AUDIOTRACKSTATUS_REPORTED, str);
793 return true;
794 }
795 return false;
796 }
797
798 // HELPER METHODS
799
getThreadFromTrack(const std::string & track) const800 std::string AudioAnalytics::getThreadFromTrack(const std::string& track) const
801 {
802 int32_t threadId_int32{};
803 if (mAnalyticsState->timeMachine().get(
804 track, AMEDIAMETRICS_PROP_THREADID, &threadId_int32) != NO_ERROR) {
805 return {};
806 }
807 return std::string(AMEDIAMETRICS_KEY_PREFIX_AUDIO_THREAD) + std::to_string(threadId_int32);
808 }
809
810 // DeviceUse helper class.
endAudioIntervalGroup(const std::shared_ptr<const android::mediametrics::Item> & item,ItemType itemType) const811 void AudioAnalytics::DeviceUse::endAudioIntervalGroup(
812 const std::shared_ptr<const android::mediametrics::Item> &item, ItemType itemType) const {
813 const std::string& key = item->getKey();
814 const std::string id = key.substr(
815 (itemType == THREAD ? sizeof(AMEDIAMETRICS_KEY_PREFIX_AUDIO_THREAD)
816 : itemType == TRACK ? sizeof(AMEDIAMETRICS_KEY_PREFIX_AUDIO_TRACK)
817 : sizeof(AMEDIAMETRICS_KEY_PREFIX_AUDIO_RECORD))
818 - 1);
819 // deliver statistics
820 int64_t deviceTimeNs = 0;
821 mAudioAnalytics.mAnalyticsState->timeMachine().get(
822 key, AMEDIAMETRICS_PROP_DEVICETIMENS, &deviceTimeNs);
823 std::string encoding;
824 mAudioAnalytics.mAnalyticsState->timeMachine().get(
825 key, AMEDIAMETRICS_PROP_ENCODING, &encoding);
826 int32_t frameCount = 0;
827 mAudioAnalytics.mAnalyticsState->timeMachine().get(
828 key, AMEDIAMETRICS_PROP_FRAMECOUNT, &frameCount);
829 int32_t intervalCount = 0;
830 mAudioAnalytics.mAnalyticsState->timeMachine().get(
831 key, AMEDIAMETRICS_PROP_INTERVALCOUNT, &intervalCount);
832 int32_t sampleRate = 0;
833 mAudioAnalytics.mAnalyticsState->timeMachine().get(
834 key, AMEDIAMETRICS_PROP_SAMPLERATE, &sampleRate);
835 std::string flags;
836 mAudioAnalytics.mAnalyticsState->timeMachine().get(
837 key, AMEDIAMETRICS_PROP_FLAGS, &flags);
838
839 switch (itemType) {
840 case RECORD: {
841 std::string inputDevicePairs;
842 mAudioAnalytics.mAnalyticsState->timeMachine().get(
843 key, AMEDIAMETRICS_PROP_INPUTDEVICES, &inputDevicePairs);
844
845 const auto [ inputDeviceStatsd, inputDevices ] =
846 stringutils::parseInputDevicePairs(inputDevicePairs);
847 const std::string inputDeviceNames; // not filled currently.
848
849 std::string callerName;
850 const bool clientCalled = mAudioAnalytics.mAnalyticsState->timeMachine().get(
851 key, AMEDIAMETRICS_PROP_CALLERNAME, &callerName) == OK;
852
853 std::string packageName;
854 int64_t versionCode = 0;
855 int32_t uid = -1;
856 mAudioAnalytics.mAnalyticsState->timeMachine().get(
857 key, AMEDIAMETRICS_PROP_ALLOWUID, &uid);
858 if (uid != -1) {
859 std::tie(packageName, versionCode) =
860 MediaMetricsService::getSanitizedPackageNameAndVersionCode(uid);
861 }
862
863 int32_t selectedDeviceId = 0;
864 mAudioAnalytics.mAnalyticsState->timeMachine().get(
865 key, AMEDIAMETRICS_PROP_SELECTEDDEVICEID, &selectedDeviceId);
866 std::string source;
867 mAudioAnalytics.mAnalyticsState->timeMachine().get(
868 key, AMEDIAMETRICS_PROP_SOURCE, &source);
869 // Android S
870 std::string logSessionId;
871 mAudioAnalytics.mAnalyticsState->timeMachine().get(
872 key, AMEDIAMETRICS_PROP_LOGSESSIONID, &logSessionId);
873
874 const auto callerNameForStats =
875 types::lookup<types::CALLER_NAME, short_enum_type_t>(callerName);
876 const auto encodingForStats = types::lookup<types::ENCODING, short_enum_type_t>(encoding);
877 const auto flagsForStats = types::lookup<types::INPUT_FLAG, short_enum_type_t>(flags);
878 const auto sourceForStats = types::lookup<types::SOURCE_TYPE, short_enum_type_t>(source);
879 // Android S
880 const auto logSessionIdForStats = ValidateId::get()->validateId(logSessionId);
881
882 LOG(LOG_LEVEL) << "key:" << key
883 << " id:" << id
884 << " inputDevices:" << inputDevices << "(" << inputDeviceStatsd
885 << ") inputDeviceNames:" << inputDeviceNames
886 << " deviceTimeNs:" << deviceTimeNs
887 << " encoding:" << encoding << "(" << encodingForStats
888 << ") frameCount:" << frameCount
889 << " intervalCount:" << intervalCount
890 << " sampleRate:" << sampleRate
891 << " flags:" << flags << "(" << flagsForStats
892 << ") packageName:" << packageName
893 << " selectedDeviceId:" << selectedDeviceId
894 << " callerName:" << callerName << "(" << callerNameForStats
895 << ") source:" << source << "(" << sourceForStats
896 << ") logSessionId:" << logSessionId << "(" << logSessionIdForStats
897 << ")";
898 if (clientCalled // only log if client app called AudioRecord.
899 && mAudioAnalytics.mDeliverStatistics) {
900 const auto [ result, str ] = sendToStatsd(AudioRecordDeviceUsageFields,
901 CONDITION(stats::media_metrics::MEDIAMETRICS_AUDIORECORDDEVICEUSAGE_REPORTED)
902 , ENUM_EXTRACT(inputDeviceStatsd)
903 , inputDeviceNames.c_str()
904 , deviceTimeNs
905 , ENUM_EXTRACT(encodingForStats)
906 , frameCount
907 , intervalCount
908 , sampleRate
909 , ENUM_EXTRACT(flagsForStats)
910
911 , packageName.c_str()
912 , selectedDeviceId
913 , ENUM_EXTRACT(callerNameForStats)
914 , ENUM_EXTRACT(sourceForStats)
915 , logSessionIdForStats.c_str()
916 );
917 ALOGV("%s: statsd %s", __func__, str.c_str());
918 mAudioAnalytics.mStatsdLog->log(
919 stats::media_metrics::MEDIAMETRICS_AUDIORECORDDEVICEUSAGE_REPORTED, str);
920 }
921 } break;
922 case THREAD: {
923 std::string type;
924 mAudioAnalytics.mAnalyticsState->timeMachine().get(
925 key, AMEDIAMETRICS_PROP_TYPE, &type);
926 int32_t underrun = 0; // zero for record types
927 mAudioAnalytics.mAnalyticsState->timeMachine().get(
928 key, AMEDIAMETRICS_PROP_UNDERRUN, &underrun);
929
930 const bool isInput = types::isInputThreadType(type);
931
932 // get device information
933 std::string devicePairs;
934 std::string deviceStatsd;
935 std::string devices;
936 std::string deviceNames;
937 if (isInput) {
938 // Note we get the "last" device which is the one associated with group.
939 item->get(AMEDIAMETRICS_PROP_PREFIX_LAST AMEDIAMETRICS_PROP_INPUTDEVICES,
940 &devicePairs);
941 std::tie(deviceStatsd, devices) = stringutils::parseInputDevicePairs(devicePairs);
942 } else {
943 // Note we get the "last" device which is the one associated with group.
944 item->get(AMEDIAMETRICS_PROP_PREFIX_LAST AMEDIAMETRICS_PROP_OUTPUTDEVICES,
945 &devicePairs);
946 std::tie(deviceStatsd, devices) = stringutils::parseOutputDevicePairs(devicePairs);
947 deviceNames = mAudioAnalytics.getDeviceNamesFromOutputDevices(devices);
948 }
949
950 const auto encodingForStats = types::lookup<types::ENCODING, short_enum_type_t>(encoding);
951 const auto flagsForStats =
952 (isInput ? types::lookup<types::INPUT_FLAG, short_enum_type_t>(flags)
953 : types::lookup<types::OUTPUT_FLAG, short_enum_type_t>(flags));
954 const auto typeForStats = types::lookup<types::THREAD_TYPE, short_enum_type_t>(type);
955
956 LOG(LOG_LEVEL) << "key:" << key
957 << " id:" << id
958 << " devices:" << devices << "(" << deviceStatsd
959 << ") deviceNames:" << deviceNames
960 << " deviceTimeNs:" << deviceTimeNs
961 << " encoding:" << encoding << "(" << encodingForStats
962 << ") frameCount:" << frameCount
963 << " intervalCount:" << intervalCount
964 << " sampleRate:" << sampleRate
965 << " underrun:" << underrun
966 << " flags:" << flags << "(" << flagsForStats
967 << ") type:" << type << "(" << typeForStats
968 << ")";
969 if (mAudioAnalytics.mDeliverStatistics) {
970 const auto [ result, str ] = sendToStatsd(AudioThreadDeviceUsageFields,
971 CONDITION(stats::media_metrics::MEDIAMETRICS_AUDIOTHREADDEVICEUSAGE_REPORTED)
972 , ENUM_EXTRACT(deviceStatsd)
973 , deviceNames.c_str()
974 , deviceTimeNs
975 , ENUM_EXTRACT(encodingForStats)
976 , frameCount
977 , intervalCount
978 , sampleRate
979 , ENUM_EXTRACT(flagsForStats)
980 , underrun
981 , ENUM_EXTRACT(typeForStats)
982 );
983 ALOGV("%s: statsd %s", __func__, str.c_str());
984 mAudioAnalytics.mStatsdLog->log(
985 stats::media_metrics::MEDIAMETRICS_AUDIOTHREADDEVICEUSAGE_REPORTED, str);
986 }
987 } break;
988 case TRACK: {
989 std::string outputDevicePairs;
990 mAudioAnalytics.mAnalyticsState->timeMachine().get(
991 key, AMEDIAMETRICS_PROP_OUTPUTDEVICES, &outputDevicePairs);
992
993 const auto [ outputDeviceStatsd, outputDevices ] =
994 stringutils::parseOutputDevicePairs(outputDevicePairs);
995 const std::string outputDeviceNames =
996 mAudioAnalytics.getDeviceNamesFromOutputDevices(outputDevices);
997
998 std::string callerName;
999 const bool clientCalled = mAudioAnalytics.mAnalyticsState->timeMachine().get(
1000 key, AMEDIAMETRICS_PROP_CALLERNAME, &callerName) == OK;
1001
1002 std::string contentType;
1003 mAudioAnalytics.mAnalyticsState->timeMachine().get(
1004 key, AMEDIAMETRICS_PROP_CONTENTTYPE, &contentType);
1005 double deviceLatencyMs = 0.;
1006 mAudioAnalytics.mAnalyticsState->timeMachine().get(
1007 key, AMEDIAMETRICS_PROP_DEVICELATENCYMS, &deviceLatencyMs);
1008 double deviceStartupMs = 0.;
1009 mAudioAnalytics.mAnalyticsState->timeMachine().get(
1010 key, AMEDIAMETRICS_PROP_DEVICESTARTUPMS, &deviceStartupMs);
1011 double deviceVolume = 0.;
1012 mAudioAnalytics.mAnalyticsState->timeMachine().get(
1013 key, AMEDIAMETRICS_PROP_DEVICEVOLUME, &deviceVolume);
1014 std::string packageName;
1015 int64_t versionCode = 0;
1016 int32_t uid = -1;
1017 mAudioAnalytics.mAnalyticsState->timeMachine().get(
1018 key, AMEDIAMETRICS_PROP_ALLOWUID, &uid);
1019 if (uid != -1) {
1020 std::tie(packageName, versionCode) =
1021 MediaMetricsService::getSanitizedPackageNameAndVersionCode(uid);
1022 }
1023 double playbackPitch = 0.;
1024 mAudioAnalytics.mAnalyticsState->timeMachine().get(
1025 key, AMEDIAMETRICS_PROP_PLAYBACK_PITCH, &playbackPitch);
1026 double playbackSpeed = 0.;
1027 mAudioAnalytics.mAnalyticsState->timeMachine().get(
1028 key, AMEDIAMETRICS_PROP_PLAYBACK_SPEED, &playbackSpeed);
1029 int32_t selectedDeviceId = 0;
1030 mAudioAnalytics.mAnalyticsState->timeMachine().get(
1031 key, AMEDIAMETRICS_PROP_SELECTEDDEVICEID, &selectedDeviceId);
1032 std::string streamType;
1033 mAudioAnalytics.mAnalyticsState->timeMachine().get(
1034 key, AMEDIAMETRICS_PROP_STREAMTYPE, &streamType);
1035 std::string traits;
1036 mAudioAnalytics.mAnalyticsState->timeMachine().get(
1037 key, AMEDIAMETRICS_PROP_TRAITS, &traits);
1038 int32_t underrun = 0;
1039 mAudioAnalytics.mAnalyticsState->timeMachine().get(
1040 key, AMEDIAMETRICS_PROP_UNDERRUN, &underrun);
1041 std::string usage;
1042 mAudioAnalytics.mAnalyticsState->timeMachine().get(
1043 key, AMEDIAMETRICS_PROP_USAGE, &usage);
1044 // Android S
1045 std::string logSessionId;
1046 mAudioAnalytics.mAnalyticsState->timeMachine().get(
1047 key, AMEDIAMETRICS_PROP_LOGSESSIONID, &logSessionId);
1048
1049 const auto callerNameForStats =
1050 types::lookup<types::CALLER_NAME, short_enum_type_t>(callerName);
1051 const auto contentTypeForStats =
1052 types::lookup<types::CONTENT_TYPE, short_enum_type_t>(contentType);
1053 const auto encodingForStats = types::lookup<types::ENCODING, short_enum_type_t>(encoding);
1054 const auto flagsForStats = types::lookup<types::OUTPUT_FLAG, short_enum_type_t>(flags);
1055 const auto streamTypeForStats =
1056 types::lookup<types::STREAM_TYPE, short_enum_type_t>(streamType);
1057 const auto traitsForStats =
1058 types::lookup<types::TRACK_TRAITS, short_enum_type_t>(traits);
1059 const auto usageForStats = types::lookup<types::USAGE, short_enum_type_t>(usage);
1060 // Android S
1061 const auto logSessionIdForStats = ValidateId::get()->validateId(logSessionId);
1062
1063 LOG(LOG_LEVEL) << "key:" << key
1064 << " id:" << id
1065 << " outputDevices:" << outputDevices << "(" << outputDeviceStatsd
1066 << ") outputDeviceNames:" << outputDeviceNames
1067 << " deviceTimeNs:" << deviceTimeNs
1068 << " encoding:" << encoding << "(" << encodingForStats
1069 << ") frameCount:" << frameCount
1070 << " intervalCount:" << intervalCount
1071 << " sampleRate:" << sampleRate
1072 << " underrun:" << underrun
1073 << " flags:" << flags << "(" << flagsForStats
1074 << ") callerName:" << callerName << "(" << callerNameForStats
1075 << ") contentType:" << contentType << "(" << contentTypeForStats
1076 << ") deviceLatencyMs:" << deviceLatencyMs
1077 << " deviceStartupMs:" << deviceStartupMs
1078 << " deviceVolume:" << deviceVolume
1079 << " packageName:" << packageName
1080 << " playbackPitch:" << playbackPitch
1081 << " playbackSpeed:" << playbackSpeed
1082 << " selectedDeviceId:" << selectedDeviceId
1083 << " streamType:" << streamType << "(" << streamTypeForStats
1084 << ") traits:" << traits << "(" << traitsForStats
1085 << ") usage:" << usage << "(" << usageForStats
1086 << ") logSessionId:" << logSessionId << "(" << logSessionIdForStats
1087 << ")";
1088 if (clientCalled // only log if client app called AudioTracks
1089 && mAudioAnalytics.mDeliverStatistics) {
1090 const auto [ result, str ] = sendToStatsd(AudioTrackDeviceUsageFields,
1091 CONDITION(stats::media_metrics::MEDIAMETRICS_AUDIOTRACKDEVICEUSAGE_REPORTED)
1092 , ENUM_EXTRACT(outputDeviceStatsd)
1093 , outputDeviceNames.c_str()
1094 , deviceTimeNs
1095 , ENUM_EXTRACT(encodingForStats)
1096 , frameCount
1097 , intervalCount
1098 , sampleRate
1099 , ENUM_EXTRACT(flagsForStats)
1100 , underrun
1101 , packageName.c_str()
1102 , (float)deviceLatencyMs
1103 , (float)deviceStartupMs
1104 , (float)deviceVolume
1105 , selectedDeviceId
1106 , ENUM_EXTRACT(streamTypeForStats)
1107 , ENUM_EXTRACT(usageForStats)
1108 , ENUM_EXTRACT(contentTypeForStats)
1109 , ENUM_EXTRACT(callerNameForStats)
1110 , ENUM_EXTRACT(traitsForStats)
1111 , logSessionIdForStats.c_str()
1112 );
1113 ALOGV("%s: statsd %s", __func__, str.c_str());
1114 mAudioAnalytics.mStatsdLog->log(
1115 stats::media_metrics::MEDIAMETRICS_AUDIOTRACKDEVICEUSAGE_REPORTED, str);
1116 }
1117 } break;
1118 }
1119 }
1120
1121 // DeviceConnection helper class.
a2dpConnected(const std::shared_ptr<const android::mediametrics::Item> & item)1122 void AudioAnalytics::DeviceConnection::a2dpConnected(
1123 const std::shared_ptr<const android::mediametrics::Item> &item) {
1124 const std::string& key = item->getKey();
1125 const int64_t atNs = item->getTimestamp();
1126 {
1127 std::lock_guard l(mLock);
1128 mA2dpConnectionServiceNs = atNs;
1129 ++mA2dpConnectionServices;
1130
1131 if (mA2dpConnectionRequestNs == 0) {
1132 mAudioAnalytics.mTimedAction.postIn(std::chrono::seconds(5), [this](){ expire(); });
1133 }
1134 // This sets the time we were connected. Now we look for the delta in the future.
1135 }
1136 std::string name;
1137 item->get(AMEDIAMETRICS_PROP_NAME, &name);
1138 ALOGD("(key=%s) a2dp connected device:%s atNs:%lld",
1139 key.c_str(), name.c_str(), (long long)atNs);
1140 }
1141
createPatch(const std::shared_ptr<const android::mediametrics::Item> & item)1142 void AudioAnalytics::DeviceConnection::createPatch(
1143 const std::shared_ptr<const android::mediametrics::Item> &item) {
1144 std::lock_guard l(mLock);
1145 if (mA2dpConnectionServiceNs == 0) return; // patch unrelated to us.
1146 const std::string& key = item->getKey();
1147 std::string outputDevices;
1148 item->get(AMEDIAMETRICS_PROP_OUTPUTDEVICES, &outputDevices);
1149 if (outputDevices.find("AUDIO_DEVICE_OUT_BLUETOOTH_A2DP") != std::string::npos) {
1150 // TODO compare address
1151 int64_t timeDiffNs = item->getTimestamp();
1152 if (mA2dpConnectionRequestNs == 0) {
1153 ALOGD("%s: A2DP create patch didn't see a connection request", __func__);
1154 timeDiffNs -= mA2dpConnectionServiceNs;
1155 } else {
1156 timeDiffNs -= mA2dpConnectionRequestNs;
1157 }
1158
1159 mA2dpConnectionRequestNs = 0;
1160 mA2dpConnectionServiceNs = 0;
1161 ++mA2dpConnectionSuccesses;
1162
1163 const auto connectionTimeMs = float((double)timeDiffNs * 1e-6);
1164
1165 const auto outputDeviceBits = types::lookup<types::OUTPUT_DEVICE, long_enum_type_t>(
1166 "AUDIO_DEVICE_OUT_BLUETOOTH_A2DP");
1167
1168 LOG(LOG_LEVEL) << "key:" << key
1169 << " A2DP SUCCESS"
1170 << " outputDevices:" << outputDeviceBits
1171 << " deviceName:" << mA2dpDeviceName
1172 << " connectionTimeMs:" << connectionTimeMs;
1173 if (mAudioAnalytics.mDeliverStatistics) {
1174 const long_enum_type_t inputDeviceBits{};
1175
1176 const auto [ result, str ] = sendToStatsd(AudioDeviceConnectionFields,
1177 CONDITION(stats::media_metrics::MEDIAMETRICS_AUDIODEVICECONNECTION_REPORTED)
1178 , ENUM_EXTRACT(inputDeviceBits)
1179 , ENUM_EXTRACT(outputDeviceBits)
1180 , mA2dpDeviceName.c_str()
1181 , types::DEVICE_CONNECTION_RESULT_SUCCESS
1182 , connectionTimeMs
1183 , /* connection_count */ 1
1184 );
1185 ALOGV("%s: statsd %s", __func__, str.c_str());
1186 mAudioAnalytics.mStatsdLog->log(
1187 stats::media_metrics::MEDIAMETRICS_AUDIODEVICECONNECTION_REPORTED, str);
1188 }
1189 }
1190 }
1191
1192 // Called through AudioManager when the BT service wants to enable
postBluetoothA2dpDeviceConnectionStateSuppressNoisyIntent(const std::shared_ptr<const android::mediametrics::Item> & item)1193 void AudioAnalytics::DeviceConnection::postBluetoothA2dpDeviceConnectionStateSuppressNoisyIntent(
1194 const std::shared_ptr<const android::mediametrics::Item> &item) {
1195 const int64_t atNs = item->getTimestamp();
1196 const std::string& key = item->getKey();
1197 std::string state;
1198 item->get(AMEDIAMETRICS_PROP_STATE, &state);
1199 if (state != "connected") return;
1200
1201 std::string name;
1202 item->get(AMEDIAMETRICS_PROP_NAME, &name);
1203 {
1204 std::lock_guard l(mLock);
1205 mA2dpConnectionRequestNs = atNs;
1206 ++mA2dpConnectionRequests;
1207 mA2dpDeviceName = SUPPRESSED; // TODO(b/161554630) sanitize name
1208 }
1209 ALOGD("(key=%s) a2dp connection name:%s request atNs:%lld",
1210 key.c_str(), name.c_str(), (long long)atNs);
1211 // TODO: attempt to cancel a timed event, rather than let it expire.
1212 mAudioAnalytics.mTimedAction.postIn(std::chrono::seconds(5), [this](){ expire(); });
1213 }
1214
expire()1215 void AudioAnalytics::DeviceConnection::expire() {
1216 std::lock_guard l(mLock);
1217 if (mA2dpConnectionRequestNs == 0) return; // ignore (this was an internal connection).
1218
1219 const long_enum_type_t inputDeviceBits{};
1220 const auto outputDeviceBits = types::lookup<types::OUTPUT_DEVICE, long_enum_type_t>(
1221 "AUDIO_DEVICE_OUT_BLUETOOTH_A2DP");
1222
1223 if (mA2dpConnectionServiceNs == 0) {
1224 ++mA2dpConnectionJavaServiceCancels; // service did not connect to A2DP
1225
1226 LOG(LOG_LEVEL) << "A2DP CANCEL"
1227 << " outputDevices:" << outputDeviceBits
1228 << " deviceName:" << mA2dpDeviceName;
1229 if (mAudioAnalytics.mDeliverStatistics) {
1230 const auto [ result, str ] = sendToStatsd(AudioDeviceConnectionFields,
1231 CONDITION(stats::media_metrics::MEDIAMETRICS_AUDIODEVICECONNECTION_REPORTED)
1232 , ENUM_EXTRACT(inputDeviceBits)
1233 , ENUM_EXTRACT(outputDeviceBits)
1234 , mA2dpDeviceName.c_str()
1235 , types::DEVICE_CONNECTION_RESULT_JAVA_SERVICE_CANCEL
1236 , /* connection_time_ms */ 0.f
1237 , /* connection_count */ 1
1238 );
1239 ALOGV("%s: statsd %s", __func__, str.c_str());
1240 mAudioAnalytics.mStatsdLog->log(
1241 stats::media_metrics::MEDIAMETRICS_AUDIODEVICECONNECTION_REPORTED, str);
1242 }
1243 return;
1244 }
1245
1246 // AudioFlinger didn't play - an expiration may occur because there is no audio playing.
1247 // Should we check elsewhere?
1248 // TODO: disambiguate this case.
1249 mA2dpConnectionRequestNs = 0;
1250 mA2dpConnectionServiceNs = 0;
1251 ++mA2dpConnectionUnknowns; // connection result unknown
1252
1253 LOG(LOG_LEVEL) << "A2DP UNKNOWN"
1254 << " outputDevices:" << outputDeviceBits
1255 << " deviceName:" << mA2dpDeviceName;
1256 if (mAudioAnalytics.mDeliverStatistics) {
1257 const auto [ result, str ] = sendToStatsd(AudioDeviceConnectionFields,
1258 CONDITION(stats::media_metrics::MEDIAMETRICS_AUDIODEVICECONNECTION_REPORTED)
1259 , ENUM_EXTRACT(inputDeviceBits)
1260 , ENUM_EXTRACT(outputDeviceBits)
1261 , mA2dpDeviceName.c_str()
1262 , types::DEVICE_CONNECTION_RESULT_UNKNOWN
1263 , /* connection_time_ms */ 0.f
1264 , /* connection_count */ 1
1265 );
1266 ALOGV("%s: statsd %s", __func__, str.c_str());
1267 mAudioAnalytics.mStatsdLog->log(
1268 stats::media_metrics::MEDIAMETRICS_AUDIODEVICECONNECTION_REPORTED, str);
1269 }
1270 }
1271
endAAudioStream(const std::shared_ptr<const android::mediametrics::Item> & item,CallerPath path) const1272 void AudioAnalytics::AAudioStreamInfo::endAAudioStream(
1273 const std::shared_ptr<const android::mediametrics::Item> &item, CallerPath path) const {
1274 const std::string& key = item->getKey();
1275
1276 std::string directionStr;
1277 mAudioAnalytics.mAnalyticsState->timeMachine().get(
1278 key, AMEDIAMETRICS_PROP_DIRECTION, &directionStr);
1279 const auto direction = types::lookup<types::AAUDIO_DIRECTION, int32_t>(directionStr);
1280
1281 int32_t framesPerBurst = -1;
1282 mAudioAnalytics.mAnalyticsState->timeMachine().get(
1283 key, AMEDIAMETRICS_PROP_BURSTFRAMES, &framesPerBurst);
1284
1285 int32_t bufferSizeInFrames = -1;
1286 mAudioAnalytics.mAnalyticsState->timeMachine().get(
1287 key, AMEDIAMETRICS_PROP_BUFFERSIZEFRAMES, &bufferSizeInFrames);
1288
1289 int32_t bufferCapacityInFrames = -1;
1290 mAudioAnalytics.mAnalyticsState->timeMachine().get(
1291 key, AMEDIAMETRICS_PROP_BUFFERCAPACITYFRAMES, &bufferCapacityInFrames);
1292
1293 int32_t channelCount = -1;
1294 mAudioAnalytics.mAnalyticsState->timeMachine().get(
1295 key, AMEDIAMETRICS_PROP_CHANNELCOUNT, &channelCount);
1296 if (channelCount == -1) {
1297 // Try to get channel count from channel mask. From the legacy path,
1298 // only channel mask are logged.
1299 int32_t channelMask = 0;
1300 mAudioAnalytics.mAnalyticsState->timeMachine().get(
1301 key, AMEDIAMETRICS_PROP_CHANNELMASK, &channelMask);
1302 if (channelMask != 0) {
1303 switch (direction) {
1304 case 1: // Output, keep sync with AudioTypes#getAAudioDirection()
1305 channelCount = (int32_t)audio_channel_count_from_out_mask(channelMask);
1306 break;
1307 case 2: // Input, keep sync with AudioTypes#getAAudioDirection()
1308 channelCount = (int32_t)audio_channel_count_from_in_mask(channelMask);
1309 break;
1310 default:
1311 ALOGW("Invalid direction %d", direction);
1312 }
1313 }
1314 }
1315
1316 int64_t totalFramesTransferred = -1;
1317 mAudioAnalytics.mAnalyticsState->timeMachine().get(
1318 key, AMEDIAMETRICS_PROP_FRAMESTRANSFERRED, &totalFramesTransferred);
1319
1320 std::string perfModeRequestedStr;
1321 mAudioAnalytics.mAnalyticsState->timeMachine().get(
1322 key, AMEDIAMETRICS_PROP_PERFORMANCEMODE, &perfModeRequestedStr);
1323 const auto perfModeRequested =
1324 types::lookup<types::AAUDIO_PERFORMANCE_MODE, int32_t>(perfModeRequestedStr);
1325
1326 std::string perfModeActualStr;
1327 mAudioAnalytics.mAnalyticsState->timeMachine().get(
1328 key, AMEDIAMETRICS_PROP_PERFORMANCEMODEACTUAL, &perfModeActualStr);
1329 const auto perfModeActual =
1330 types::lookup<types::AAUDIO_PERFORMANCE_MODE, int32_t>(perfModeActualStr);
1331
1332 std::string sharingModeActualStr;
1333 mAudioAnalytics.mAnalyticsState->timeMachine().get(
1334 key, AMEDIAMETRICS_PROP_SHARINGMODEACTUAL, &sharingModeActualStr);
1335 const auto sharingModeActual =
1336 types::lookup<types::AAUDIO_SHARING_MODE, int32_t>(sharingModeActualStr);
1337
1338 int32_t xrunCount = -1;
1339 mAudioAnalytics.mAnalyticsState->timeMachine().get(
1340 key, AMEDIAMETRICS_PROP_UNDERRUN, &xrunCount);
1341
1342 std::string serializedDeviceTypes;
1343 // TODO: only routed device id is logged, but no device type
1344
1345 std::string formatAppStr;
1346 mAudioAnalytics.mAnalyticsState->timeMachine().get(
1347 key, AMEDIAMETRICS_PROP_ENCODINGCLIENT, &formatAppStr);
1348 const auto formatApp = types::lookup<types::ENCODING, int32_t>(formatAppStr);
1349
1350 std::string formatDeviceStr;
1351 mAudioAnalytics.mAnalyticsState->timeMachine().get(
1352 key, AMEDIAMETRICS_PROP_ENCODING, &formatDeviceStr);
1353 const auto formatDevice = types::lookup<types::ENCODING, int32_t>(formatDeviceStr);
1354
1355 std::string logSessionId;
1356 mAudioAnalytics.mAnalyticsState->timeMachine().get(
1357 key, AMEDIAMETRICS_PROP_LOGSESSIONID, &logSessionId);
1358
1359 int32_t sampleRate = 0;
1360 mAudioAnalytics.mAnalyticsState->timeMachine().get(
1361 key, AMEDIAMETRICS_PROP_SAMPLERATE, &sampleRate);
1362
1363 std::string contentTypeStr;
1364 mAudioAnalytics.mAnalyticsState->timeMachine().get(
1365 key, AMEDIAMETRICS_PROP_CONTENTTYPE, &contentTypeStr);
1366 const auto contentType = types::lookup<types::CONTENT_TYPE, int32_t>(contentTypeStr);
1367
1368 std::string sharingModeRequestedStr;
1369 mAudioAnalytics.mAnalyticsState->timeMachine().get(
1370 key, AMEDIAMETRICS_PROP_SHARINGMODE, &sharingModeRequestedStr);
1371 const auto sharingModeRequested =
1372 types::lookup<types::AAUDIO_SHARING_MODE, int32_t>(sharingModeRequestedStr);
1373
1374 std::string formatHardwareStr;
1375 mAudioAnalytics.mAnalyticsState->timeMachine().get(
1376 key, AMEDIAMETRICS_PROP_ENCODINGHARDWARE, &formatHardwareStr);
1377 const auto formatHardware = types::lookup<types::ENCODING, int32_t>(formatHardwareStr);
1378
1379 int32_t channelCountHardware = -1;
1380 mAudioAnalytics.mAnalyticsState->timeMachine().get(
1381 key, AMEDIAMETRICS_PROP_CHANNELCOUNTHARDWARE, &channelCountHardware);
1382
1383 int32_t sampleRateHardware = 0;
1384 mAudioAnalytics.mAnalyticsState->timeMachine().get(
1385 key, AMEDIAMETRICS_PROP_SAMPLERATEHARDWARE, &sampleRateHardware);
1386
1387 const auto uid = item->getUid();
1388
1389 int32_t sampleRateClient = 0;
1390 mAudioAnalytics.mAnalyticsState->timeMachine().get(
1391 key, AMEDIAMETRICS_PROP_SAMPLERATECLIENT, &sampleRateClient);
1392
1393 LOG(LOG_LEVEL) << "key:" << key
1394 << " path:" << path
1395 << " direction:" << direction << "(" << directionStr << ")"
1396 << " frames_per_burst:" << framesPerBurst
1397 << " buffer_size:" << bufferSizeInFrames
1398 << " buffer_capacity:" << bufferCapacityInFrames
1399 << " channel_count:" << channelCount
1400 << " total_frames_transferred:" << totalFramesTransferred
1401 << " perf_mode_requested:" << perfModeRequested << "(" << perfModeRequestedStr << ")"
1402 << " perf_mode_actual:" << perfModeActual << "(" << perfModeActualStr << ")"
1403 << " sharing:" << sharingModeActual << "(" << sharingModeActualStr << ")"
1404 << " xrun_count:" << xrunCount
1405 << " device_type:" << serializedDeviceTypes
1406 << " format_app:" << formatApp << "(" << formatAppStr << ")"
1407 << " format_device: " << formatDevice << "(" << formatDeviceStr << ")"
1408 << " log_session_id: " << logSessionId
1409 << " sample_rate: " << sampleRate
1410 << " content_type: " << contentType << "(" << contentTypeStr << ")"
1411 << " sharing_requested:" << sharingModeRequested
1412 << "(" << sharingModeRequestedStr << ")"
1413 << " format_hardware:" << formatHardware << "(" << formatHardwareStr << ")"
1414 << " channel_count_hardware:" << channelCountHardware
1415 << " sample_rate_hardware: " << sampleRateHardware
1416 << " uid: " << uid
1417 << " sample_rate_client: " << sampleRateClient;
1418
1419 if (mAudioAnalytics.mDeliverStatistics) {
1420 const stats::media_metrics::BytesField bf_serialized(
1421 serializedDeviceTypes.c_str(), serializedDeviceTypes.size());
1422 const auto result = sendToStatsd(
1423 CONDITION(stats::media_metrics::MEDIAMETRICS_AAUDIOSTREAM_REPORTED)
1424 , path
1425 , direction
1426 , framesPerBurst
1427 , bufferSizeInFrames
1428 , bufferCapacityInFrames
1429 , channelCount
1430 , totalFramesTransferred
1431 , perfModeRequested
1432 , perfModeActual
1433 , sharingModeActual
1434 , xrunCount
1435 , bf_serialized
1436 , formatApp
1437 , formatDevice
1438 , logSessionId.c_str()
1439 , sampleRate
1440 , contentType
1441 , sharingModeRequested
1442 , formatHardware
1443 , channelCountHardware
1444 , sampleRateHardware
1445 , uid
1446 , sampleRateClient
1447 );
1448 std::stringstream ss;
1449 ss << "result:" << result;
1450 const auto fieldsStr = printFields(AAudioStreamFields,
1451 CONDITION(stats::media_metrics::MEDIAMETRICS_AAUDIOSTREAM_REPORTED)
1452 , path
1453 , direction
1454 , framesPerBurst
1455 , bufferSizeInFrames
1456 , bufferCapacityInFrames
1457 , channelCount
1458 , totalFramesTransferred
1459 , perfModeRequested
1460 , perfModeActual
1461 , sharingModeActual
1462 , xrunCount
1463 , serializedDeviceTypes.c_str()
1464 , formatApp
1465 , formatDevice
1466 , logSessionId.c_str()
1467 , sampleRate
1468 , contentType
1469 , sharingModeRequested
1470 , formatHardware
1471 , channelCountHardware
1472 , sampleRateHardware
1473 , uid
1474 , sampleRateClient
1475 );
1476 ss << " " << fieldsStr;
1477 std::string str = ss.str();
1478 ALOGV("%s: statsd %s", __func__, str.c_str());
1479 mAudioAnalytics.mStatsdLog->log(stats::media_metrics::MEDIAMETRICS_AAUDIOSTREAM_REPORTED, str);
1480 }
1481 }
1482
1483 // Create new state, typically occurs after an AudioFlinger ctor event.
newState()1484 void AudioAnalytics::newState()
1485 {
1486 mPreviousAnalyticsState.set(std::make_shared<AnalyticsState>(
1487 *mAnalyticsState.get()));
1488 // Note: get returns shared_ptr temp, whose lifetime is extended
1489 // to end of full expression.
1490 mAnalyticsState->clear(); // TODO: filter the analytics state.
1491 // Perhaps report this.
1492
1493 // Set up a timer to expire the previous audio state to save space.
1494 // Use the transaction log size as a cookie to see if it is the
1495 // same as before. A benign race is possible where a state is cleared early.
1496 const size_t size = mPreviousAnalyticsState->transactionLog().size();
1497 mTimedAction.postIn(
1498 std::chrono::seconds(PREVIOUS_STATE_EXPIRE_SEC), [this, size](){
1499 if (mPreviousAnalyticsState->transactionLog().size() == size) {
1500 ALOGD("expiring previous audio state after %d seconds.",
1501 PREVIOUS_STATE_EXPIRE_SEC);
1502 mPreviousAnalyticsState->clear(); // removes data from the state.
1503 }
1504 });
1505 }
1506
onAudioServerStart(Module module,const std::shared_ptr<const android::mediametrics::Item> & item)1507 void AudioAnalytics::Health::onAudioServerStart(Module module,
1508 const std::shared_ptr<const android::mediametrics::Item> &item)
1509 {
1510 const auto nowTime = std::chrono::system_clock::now();
1511 if (module == Module::AUDIOFLINGER) {
1512 {
1513 std::lock_guard lg(mLock);
1514 // reset state on AudioFlinger construction.
1515 // AudioPolicy is created after AudioFlinger.
1516 mAudioFlingerCtorTime = nowTime;
1517 mSimpleLog.log("AudioFlinger ctor");
1518 }
1519 mAudioAnalytics.newState();
1520 return;
1521 }
1522 if (module == Module::AUDIOPOLICY) {
1523 // A start event occurs when audioserver
1524 //
1525 // (1) Starts the first time
1526 // (2) Restarts because of the TimeCheck watchdog
1527 // (3) Restarts not because of the TimeCheck watchdog.
1528 int64_t executionTimeNs = 0;
1529 (void)item->get(AMEDIAMETRICS_PROP_EXECUTIONTIMENS, &executionTimeNs);
1530 const float loadTimeMs = executionTimeNs * 1e-6f;
1531 std::lock_guard lg(mLock);
1532 const int64_t restarts = mStartCount;
1533 if (mStopCount == mStartCount) {
1534 mAudioPolicyCtorTime = nowTime;
1535 ++mStartCount;
1536 if (mStopCount == 0) {
1537 // (1) First time initialization.
1538 ALOGW("%s: (key=%s) AudioPolicy ctor, loadTimeMs:%f",
1539 __func__, item->getKey().c_str(), loadTimeMs);
1540 mSimpleLog.log("AudioPolicy ctor, loadTimeMs:%f", loadTimeMs);
1541 } else {
1542 // (2) Previous failure caught due to TimeCheck. We know how long restart takes.
1543 const float restartMs =
1544 std::chrono::duration_cast<std::chrono::duration<float, std::milli>>(
1545 mAudioFlingerCtorTime - mStopTime).count();
1546 ALOGW("%s: (key=%s) AudioPolicy ctor, "
1547 "restarts:%lld restartMs:%f loadTimeMs:%f",
1548 __func__, item->getKey().c_str(),
1549 (long long)restarts, restartMs, loadTimeMs);
1550 mSimpleLog.log("AudioPolicy ctor restarts:%lld restartMs:%f loadTimeMs:%f",
1551 (long long)restarts, restartMs, loadTimeMs);
1552 }
1553 } else {
1554 // (3) Previous failure is NOT due to TimeCheck, so we don't know the restart time.
1555 // However we can estimate the uptime from the delta time from previous ctor.
1556 const float uptimeMs =
1557 std::chrono::duration_cast<std::chrono::duration<float, std::milli>>(
1558 nowTime - mAudioFlingerCtorTime).count();
1559 mStopCount = mStartCount;
1560 mAudioPolicyCtorTime = nowTime;
1561 ++mStartCount;
1562
1563 ALOGW("%s: (key=%s) AudioPolicy ctor after uncaught failure, "
1564 "mStartCount:%lld mStopCount:%lld uptimeMs:%f loadTimeMs:%f",
1565 __func__, item->getKey().c_str(),
1566 (long long)mStartCount, (long long)mStopCount, uptimeMs, loadTimeMs);
1567 mSimpleLog.log("AudioPolicy ctor after uncaught failure, "
1568 "restarts:%lld uptimeMs:%f loadTimeMs:%f",
1569 (long long)restarts, uptimeMs, loadTimeMs);
1570 }
1571 }
1572 }
1573
onAudioServerTimeout(Module module,const std::shared_ptr<const android::mediametrics::Item> & item)1574 void AudioAnalytics::Health::onAudioServerTimeout(Module module,
1575 const std::shared_ptr<const android::mediametrics::Item> &item)
1576 {
1577 std::string moduleName = getModuleName(module);
1578 int64_t methodCode{};
1579 std::string methodName;
1580 (void)item->get(AMEDIAMETRICS_PROP_METHODCODE, &methodCode);
1581 (void)item->get(AMEDIAMETRICS_PROP_METHODNAME, &methodName);
1582
1583 std::lock_guard lg(mLock);
1584 if (mStopCount >= mStartCount) {
1585 ALOGD("%s: (key=%s) %s timeout %s(%lld) "
1586 "unmatched mStopCount(%lld) >= mStartCount(%lld), ignoring",
1587 __func__, item->getKey().c_str(), moduleName.c_str(),
1588 methodName.c_str(), (long long)methodCode,
1589 (long long)mStopCount, (long long)mStartCount);
1590 return;
1591 }
1592
1593 const int64_t restarts = mStartCount - 1;
1594 ++mStopCount;
1595 mStopTime = std::chrono::system_clock::now();
1596 const float uptimeMs = std::chrono::duration_cast<std::chrono::duration<float, std::milli>>(
1597 mStopTime - mAudioFlingerCtorTime).count();
1598 ALOGW("%s: (key=%s) %s timeout %s(%lld) restarts:%lld uptimeMs:%f",
1599 __func__, item->getKey().c_str(), moduleName.c_str(),
1600 methodName.c_str(), (long long)methodCode,
1601 (long long)restarts, uptimeMs);
1602 mSimpleLog.log("%s timeout %s(%lld) restarts:%lld uptimeMs:%f",
1603 moduleName.c_str(), methodName.c_str(), (long long)methodCode,
1604 (long long)restarts, uptimeMs);
1605 }
1606
dump(int32_t lines,const char * prefix) const1607 std::pair<std::string, int32_t> AudioAnalytics::Health::dump(
1608 int32_t lines, const char *prefix) const
1609 {
1610 std::lock_guard lg(mLock);
1611 std::string s = mSimpleLog.dumpToString(prefix == nullptr ? "" : prefix, lines);
1612 size_t n = std::count(s.begin(), s.end(), '\n');
1613 return { s, n };
1614 }
1615
1616 // Classifies the setting event for statsd (use generated statsd enums.proto constants).
classifySettingEvent(bool isSetAlready,bool withinBoot)1617 static int32_t classifySettingEvent(bool isSetAlready, bool withinBoot) {
1618 if (isSetAlready) {
1619 return stats::media_metrics::MEDIAMETRICS_SPATIALIZER_DEVICE_ENABLED_REPORTED__EVENT__SPATIALIZER_SETTING_EVENT_NORMAL;
1620 }
1621 if (withinBoot) {
1622 return stats::media_metrics::MEDIAMETRICS_SPATIALIZER_DEVICE_ENABLED_REPORTED__EVENT__SPATIALIZER_SETTING_EVENT_BOOT;
1623 }
1624 return stats::media_metrics::MEDIAMETRICS_SPATIALIZER_DEVICE_ENABLED_REPORTED__EVENT__SPATIALIZER_SETTING_EVENT_FIRST;
1625 }
1626
onEvent(const std::shared_ptr<const android::mediametrics::Item> & item)1627 void AudioAnalytics::Spatializer::onEvent(
1628 const std::shared_ptr<const android::mediametrics::Item> &item)
1629 {
1630 const auto key = item->getKey();
1631
1632 if (!startsWith(key, AMEDIAMETRICS_KEY_PREFIX_AUDIO_SPATIALIZER)) return;
1633
1634 const std::string suffix =
1635 key.substr(std::size(AMEDIAMETRICS_KEY_PREFIX_AUDIO_SPATIALIZER) - 1);
1636
1637 std::string eventStr; // optional - find the actual event string.
1638 (void)item->get(AMEDIAMETRICS_PROP_EVENT, &eventStr);
1639
1640 const size_t delim = suffix.find('.'); // note could use split.
1641 if (delim == suffix.npos) {
1642 // on create with suffix == "0" for the first spatializer effect.
1643
1644 std::string headTrackingModes;
1645 (void)item->get(AMEDIAMETRICS_PROP_HEADTRACKINGMODES, &headTrackingModes);
1646
1647 std::string levels;
1648 (void)item->get(AMEDIAMETRICS_PROP_LEVELS, &levels);
1649
1650 std::string modes;
1651 (void)item->get(AMEDIAMETRICS_PROP_MODES, &modes);
1652
1653 std::string channelMasks;
1654 (void)item->get(AMEDIAMETRICS_PROP_CHANNELMASKS, &channelMasks);
1655
1656 LOG(LOG_LEVEL) << "key:" << key
1657 << " headTrackingModes:" << headTrackingModes
1658 << " levels:" << levels
1659 << " modes:" << modes
1660 << " channelMasks:" << channelMasks
1661 ;
1662
1663 const std::vector<int32_t> headTrackingModesVector =
1664 types::vectorFromMap(headTrackingModes, types::getHeadTrackingModeMap());
1665 const std::vector<int32_t> levelsVector =
1666 types::vectorFromMap(levels, types::getSpatializerLevelMap());
1667 const std::vector<int32_t> modesVector =
1668 types::vectorFromMap(modes, types::getSpatializerModeMap());
1669 const std::vector<int64_t> channelMasksVector =
1670 types::channelMaskVectorFromString(channelMasks);
1671
1672 const auto [ result, str ] = sendToStatsd(SpatializerCapabilitiesFields,
1673 CONDITION(stats::media_metrics::MEDIAMETRICS_SPATIALIZERCAPABILITIES_REPORTED)
1674 , headTrackingModesVector
1675 , levelsVector
1676 , modesVector
1677 , channelMasksVector
1678 );
1679
1680 mAudioAnalytics.mStatsdLog->log(
1681 stats::media_metrics::MEDIAMETRICS_SPATIALIZERCAPABILITIES_REPORTED, str);
1682
1683 std::lock_guard lg(mLock);
1684 if (mFirstCreateTimeNs == 0) {
1685 // Only update the create time once to prevent audioserver restart
1686 // from looking like a boot.
1687 mFirstCreateTimeNs = item->getTimestamp();
1688 }
1689 mSimpleLog.log("%s suffix: %s item: %s",
1690 __func__, suffix.c_str(), item->toString().c_str());
1691 } else {
1692 std::string subtype = suffix.substr(0, delim);
1693 if (subtype != "device") return; // not a device.
1694
1695 const std::string deviceType = suffix.substr(std::size("device.") - 1);
1696
1697 const int32_t deviceTypeStatsd =
1698 types::lookup<types::AUDIO_DEVICE_INFO_TYPE, int32_t>(deviceType);
1699
1700 std::string address;
1701 (void)item->get(AMEDIAMETRICS_PROP_ADDRESS, &address);
1702 std::string enabled;
1703 (void)item->get(AMEDIAMETRICS_PROP_ENABLED, &enabled);
1704 std::string hasHeadTracker;
1705 (void)item->get(AMEDIAMETRICS_PROP_HASHEADTRACKER, &hasHeadTracker);
1706 std::string headTrackerEnabled;
1707 (void)item->get(AMEDIAMETRICS_PROP_HEADTRACKERENABLED, &headTrackerEnabled);
1708
1709 std::lock_guard lg(mLock);
1710
1711 // Validate from our cached state
1712
1713 // Our deviceKey takes the device type and appends the address if any.
1714 // This distinguishes different wireless devices for the purposes of tracking.
1715 std::string deviceKey(deviceType);
1716 deviceKey.append("_").append(address);
1717 DeviceState& deviceState = mDeviceStateMap[deviceKey];
1718
1719 // check whether the settings event is within a certain time of spatializer creation.
1720 const bool withinBoot =
1721 item->getTimestamp() - mFirstCreateTimeNs < kBootDurationThreshold;
1722
1723 if (!enabled.empty()) {
1724 if (enabled != deviceState.enabled) {
1725 const int32_t settingEventStatsd =
1726 classifySettingEvent(!deviceState.enabled.empty(), withinBoot);
1727 deviceState.enabled = enabled;
1728 const bool enabledStatsd = enabled == "true";
1729 const auto [ result, str ] = sendToStatsd(SpatializerDeviceEnabledFields,
1730 CONDITION(stats::media_metrics::MEDIAMETRICS_SPATIALIZERDEVICEENABLED_REPORTED)
1731 , deviceTypeStatsd
1732 , settingEventStatsd
1733 , enabledStatsd
1734 );
1735 mAudioAnalytics.mStatsdLog->log(
1736 stats::media_metrics::MEDIAMETRICS_SPATIALIZERDEVICEENABLED_REPORTED, str);
1737 }
1738 }
1739 if (!hasHeadTracker.empty()) {
1740 if (hasHeadTracker != deviceState.hasHeadTracker) {
1741 const int32_t settingEventStatsd =
1742 classifySettingEvent(!deviceState.hasHeadTracker.empty(), withinBoot);
1743 deviceState.hasHeadTracker = hasHeadTracker;
1744 const bool supportedStatsd = hasHeadTracker == "true";
1745 const auto [ result, str ] = sendToStatsd(HeadTrackerDeviceSupportedFields,
1746 CONDITION(stats::media_metrics::MEDIAMETRICS_HEADTRACKERDEVICESUPPORTED_REPORTED)
1747 , deviceTypeStatsd
1748 , settingEventStatsd
1749 , supportedStatsd
1750 );
1751 mAudioAnalytics.mStatsdLog->log(
1752 stats::media_metrics::MEDIAMETRICS_HEADTRACKERDEVICESUPPORTED_REPORTED, str);
1753 }
1754 }
1755 if (!headTrackerEnabled.empty()) {
1756 if (headTrackerEnabled != deviceState.headTrackerEnabled) {
1757 const int32_t settingEventStatsd =
1758 classifySettingEvent(!deviceState.headTrackerEnabled.empty(), withinBoot);
1759 deviceState.headTrackerEnabled = headTrackerEnabled;
1760 const bool enabledStatsd = headTrackerEnabled == "true";
1761 const auto [ result, str ] = sendToStatsd(HeadTrackerDeviceEnabledFields,
1762 CONDITION(stats::media_metrics::MEDIAMETRICS_HEADTRACKERDEVICEENABLED_REPORTED)
1763 , deviceTypeStatsd
1764 , settingEventStatsd
1765 , enabledStatsd
1766 );
1767 mAudioAnalytics.mStatsdLog->log(
1768 stats::media_metrics::MEDIAMETRICS_HEADTRACKERDEVICEENABLED_REPORTED, str);
1769 }
1770 }
1771 mSimpleLog.log("%s deviceKey: %s item: %s",
1772 __func__, deviceKey.c_str(), item->toString().c_str());
1773 }
1774 }
1775
dump(int32_t lines,const char * prefix) const1776 std::pair<std::string, int32_t> AudioAnalytics::Spatializer::dump(
1777 int32_t lines, const char *prefix) const
1778 {
1779 std::lock_guard lg(mLock);
1780 std::string s = mSimpleLog.dumpToString(prefix == nullptr ? "" : prefix, lines);
1781 size_t n = std::count(s.begin(), s.end(), '\n');
1782 return { s, n };
1783 }
1784
onEvent(const std::shared_ptr<const android::mediametrics::Item> & item) const1785 void AudioAnalytics::MidiLogging::onEvent(
1786 const std::shared_ptr<const android::mediametrics::Item> &item) const {
1787 const std::string& key = item->getKey();
1788
1789 const auto uid = item->getUid();
1790
1791 int32_t deviceId = -1;
1792 mAudioAnalytics.mAnalyticsState->timeMachine().get(
1793 key, AMEDIAMETRICS_PROP_DEVICEID, &deviceId);
1794
1795 int32_t inputPortCount = -1;
1796 mAudioAnalytics.mAnalyticsState->timeMachine().get(
1797 key, AMEDIAMETRICS_PROP_INPUTPORTCOUNT, &inputPortCount);
1798
1799 int32_t outputPortCount = -1;
1800 mAudioAnalytics.mAnalyticsState->timeMachine().get(
1801 key, AMEDIAMETRICS_PROP_OUTPUTPORTCOUNT, &outputPortCount);
1802
1803 int32_t hardwareType = -1;
1804 mAudioAnalytics.mAnalyticsState->timeMachine().get(
1805 key, AMEDIAMETRICS_PROP_HARDWARETYPE, &hardwareType);
1806
1807 std::string isSharedString;
1808 mAudioAnalytics.mAnalyticsState->timeMachine().get(
1809 key, AMEDIAMETRICS_PROP_ISSHARED, &isSharedString);
1810 const bool isShared = (isSharedString == "true");
1811
1812 std::string supportsMidiUmpString;
1813 mAudioAnalytics.mAnalyticsState->timeMachine().get(
1814 key, AMEDIAMETRICS_PROP_SUPPORTSMIDIUMP, &supportsMidiUmpString);
1815 const bool supportsMidiUmp = (supportsMidiUmpString == "true");
1816
1817 std::string usingAlsaString;
1818 mAudioAnalytics.mAnalyticsState->timeMachine().get(
1819 key, AMEDIAMETRICS_PROP_USINGALSA, &usingAlsaString);
1820 const bool usingAlsa = (usingAlsaString == "true");
1821
1822 int64_t durationNs = -1;
1823 mAudioAnalytics.mAnalyticsState->timeMachine().get(
1824 key, AMEDIAMETRICS_PROP_DURATIONNS, &durationNs);
1825
1826 int32_t openedCount = -1;
1827 mAudioAnalytics.mAnalyticsState->timeMachine().get(
1828 key, AMEDIAMETRICS_PROP_OPENEDCOUNT, &openedCount);
1829
1830 int32_t closedCount = -1;
1831 mAudioAnalytics.mAnalyticsState->timeMachine().get(
1832 key, AMEDIAMETRICS_PROP_CLOSEDCOUNT, &closedCount);
1833
1834 std::string deviceDisconnectedString;
1835 mAudioAnalytics.mAnalyticsState->timeMachine().get(
1836 key, AMEDIAMETRICS_PROP_DEVICEDISCONNECTED, &deviceDisconnectedString);
1837 const bool deviceDisconnected = (deviceDisconnectedString == "true");
1838
1839 int32_t totalInputBytes = -1;
1840 mAudioAnalytics.mAnalyticsState->timeMachine().get(
1841 key, AMEDIAMETRICS_PROP_TOTALINPUTBYTES, &totalInputBytes);
1842
1843 int32_t totalOutputBytes = -1;
1844 mAudioAnalytics.mAnalyticsState->timeMachine().get(
1845 key, AMEDIAMETRICS_PROP_TOTALOUTPUTBYTES, &totalOutputBytes);
1846
1847 LOG(LOG_LEVEL) << "key:" << key
1848 << " uid:" << uid
1849 << " id:" << deviceId
1850 << " input_port_count:" << inputPortCount
1851 << " output_port_count:" << outputPortCount
1852 << " device_type:" << hardwareType
1853 << " is_shared:" << isSharedString
1854 << " supports_ump:" << supportsMidiUmpString
1855 << " using_alsa:" << usingAlsaString
1856 << " duration_opened_ms:" << durationNs
1857 << " opened_count:" << openedCount
1858 << " closed_count:" << closedCount
1859 << " device_disconnected:" << deviceDisconnectedString
1860 << " total_input_bytes:" << totalInputBytes
1861 << " total_output_bytes:" << totalOutputBytes;
1862
1863 if (mAudioAnalytics.mDeliverStatistics) {
1864 const auto result = sendToStatsd(
1865 CONDITION(stats::media_metrics::MEDIAMETRICS_MIDI_DEVICE_CLOSE_REPORTED)
1866 , uid
1867 , deviceId
1868 , inputPortCount
1869 , outputPortCount
1870 , hardwareType
1871 , isShared
1872 , supportsMidiUmp
1873 , usingAlsa
1874 , durationNs
1875 , openedCount
1876 , closedCount
1877 , deviceDisconnected
1878 , totalInputBytes
1879 , totalOutputBytes);
1880 std::stringstream ss;
1881 ss << "result:" << result;
1882 const auto fieldsStr = printFields(MidiDeviceCloseFields,
1883 CONDITION(stats::media_metrics::MEDIAMETRICS_MIDI_DEVICE_CLOSE_REPORTED)
1884 , uid
1885 , deviceId
1886 , inputPortCount
1887 , outputPortCount
1888 , hardwareType
1889 , isShared
1890 , supportsMidiUmp
1891 , usingAlsa
1892 , durationNs
1893 , openedCount
1894 , closedCount
1895 , deviceDisconnected
1896 , totalInputBytes
1897 , totalOutputBytes);
1898 ss << " " << fieldsStr;
1899 std::string str = ss.str();
1900 ALOGV("%s: statsd %s", __func__, str.c_str());
1901 mAudioAnalytics.mStatsdLog->log(
1902 stats::media_metrics::MEDIAMETRICS_MIDI_DEVICE_CLOSE_REPORTED, str);
1903 }
1904 }
1905
1906 // This method currently suppresses the name.
getDeviceNamesFromOutputDevices(std::string_view devices) const1907 std::string AudioAnalytics::getDeviceNamesFromOutputDevices(std::string_view devices) const {
1908 std::string deviceNames;
1909 if (stringutils::hasBluetoothOutputDevice(devices)) {
1910 deviceNames = SUPPRESSED;
1911 #if 0 // TODO(b/161554630) sanitize name
1912 mAudioAnalytics.mAnalyticsState->timeMachine().get(
1913 "audio.device.bt_a2dp", AMEDIAMETRICS_PROP_NAME, &deviceNames);
1914 // Remove | if present
1915 stringutils::replace(deviceNames, "|", '?');
1916 if (deviceNames.size() > STATSD_DEVICE_NAME_MAX_LENGTH) {
1917 deviceNames.resize(STATSD_DEVICE_NAME_MAX_LENGTH); // truncate
1918 }
1919 #endif
1920 }
1921 return deviceNames;
1922 }
1923
1924 } // namespace android::mediametrics
1925