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