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