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