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