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 <audio_utils/clock.h>    // clock conversions
25 #include <cutils/properties.h>
26 #include <statslog.h>             // statsd
27 
28 #include "AudioTypes.h"           // string to int conversions
29 #include "MediaMetricsService.h"  // package info
30 #include "StringUtils.h"
31 
32 #define PROP_AUDIO_ANALYTICS_CLOUD_ENABLED "persist.audio.analytics.cloud.enabled"
33 
34 namespace android::mediametrics {
35 
36 // Enable for testing of delivery to statsd. Caution if this is enabled, all protos MUST exist.
37 #define STATSD_ENABLE
38 
39 #ifdef STATSD_ENABLE
40 #define CONDITION(INT_VALUE) (INT_VALUE)  // allow value
41 #else
42 #define CONDITION(INT_VALUE) (int(0))     // mask value since the proto may not be defined yet.
43 #endif
44 
45 // Maximum length of a device name.
46 // static constexpr size_t STATSD_DEVICE_NAME_MAX_LENGTH = 32; // unused since we suppress
47 
48 // Transmit Enums to statsd in integer or strings  (this must match the atoms.proto)
49 static constexpr bool STATSD_USE_INT_FOR_ENUM = false;
50 
51 // derive types based on integer or strings.
52 using short_enum_type_t = std::conditional_t<STATSD_USE_INT_FOR_ENUM, int32_t, std::string>;
53 using long_enum_type_t = std::conditional_t<STATSD_USE_INT_FOR_ENUM, int64_t, std::string>;
54 
55 // Convert std::string to char *
56 template <typename T>
ENUM_EXTRACT(const T & x)57 auto ENUM_EXTRACT(const T& x) {
58     if constexpr (std::is_same_v<std::decay_t<T>, std::string>) {
59         return x.c_str();
60     } else {
61         return x;
62     }
63 }
64 
65 static constexpr const auto LOG_LEVEL = android::base::VERBOSE;
66 
67 static constexpr int PREVIOUS_STATE_EXPIRE_SEC = 60 * 60; // 1 hour.
68 
69 static constexpr const char * SUPPRESSED = "SUPPRESSED";
70 
71 /*
72  * For logging purposes, we list all of the MediaMetrics atom fields,
73  * which can then be associated with consecutive arguments to the statsd write.
74  */
75 
76 static constexpr const char * const AudioRecordDeviceUsageFields[] = {
77     "mediametrics_audiorecorddeviceusage_reported", // proto number
78     "devices",
79     "device_names",
80     "device_time_nanos",
81     "encoding",
82     "frame_count",
83     "interval_count",
84     "sample_rate",
85     "flags",
86     "package_name",
87     "selected_device_id",
88     "caller",
89     "source",
90 };
91 
92 static constexpr const char * const AudioThreadDeviceUsageFields[] = {
93     "mediametrics_audiothreaddeviceusage_reported",
94     "devices",
95     "device_names",
96     "device_time_nanos",
97     "encoding",
98     "frame_count",
99     "interval_count",
100     "sample_rate",
101     "flags",
102     "xruns",
103     "type",
104 };
105 
106 static constexpr const char * const AudioTrackDeviceUsageFields[] = {
107     "mediametrics_audiotrackdeviceusage_reported",
108     "devices",
109     "device_names",
110     "device_time_nanos",
111     "encoding",
112     "frame_count",
113     "interval_count",
114     "sample_rate",
115     "flags",
116     "xruns",
117     "package_name",
118     "device_latency_millis",
119     "device_startup_millis",
120     "device_volume",
121     "selected_device_id",
122     "stream_type",
123     "usage",
124     "content_type",
125     "caller",
126     "traits",
127 };
128 
129 static constexpr const char * const AudioDeviceConnectionFields[] = {
130     "mediametrics_audiodeviceconnection_reported",
131     "input_devices",
132     "output_devices",
133     "device_names",
134     "result",
135     "time_to_connect_millis",
136     "connection_count",
137 };
138 
139 /**
140  * sendToStatsd is a helper method that sends the arguments to statsd
141  * and returns a pair { result, summary_string }.
142  */
143 template <size_t N, typename ...Types>
sendToStatsd(const char * const (& fields)[N],Types...args)144 std::pair<int, std::string> sendToStatsd(const char * const (& fields)[N], Types ... args)
145 {
146     int result = 0;
147     std::stringstream ss;
148 
149 #ifdef STATSD_ENABLE
150     result = android::util::stats_write(args...);
151     ss << "result:" << result;
152 #endif
153     ss << " { ";
154     stringutils::fieldPrint(ss, fields, args...);
155     ss << "}";
156     return { result, ss.str() };
157 }
158 
AudioAnalytics()159 AudioAnalytics::AudioAnalytics()
160     : mDeliverStatistics(property_get_bool(PROP_AUDIO_ANALYTICS_CLOUD_ENABLED, true))
161 {
162     SetMinimumLogSeverity(android::base::DEBUG); // for LOG().
163     ALOGD("%s", __func__);
164 
165     // Add action to save AnalyticsState if audioserver is restarted.
166     // This triggers on an item of "audio.flinger"
167     // with a property "event" set to "AudioFlinger" (the constructor).
168     mActions.addAction(
169         AMEDIAMETRICS_KEY_AUDIO_FLINGER "." AMEDIAMETRICS_PROP_EVENT,
170         std::string(AMEDIAMETRICS_PROP_EVENT_VALUE_CTOR),
171         std::make_shared<AnalyticsActions::Function>(
172             [this](const std::shared_ptr<const android::mediametrics::Item> &item){
173                 ALOGW("(key=%s) Audioflinger constructor event detected", item->getKey().c_str());
174                 mPreviousAnalyticsState.set(std::make_shared<AnalyticsState>(
175                         *mAnalyticsState.get()));
176                 // Note: get returns shared_ptr temp, whose lifetime is extended
177                 // to end of full expression.
178                 mAnalyticsState->clear();  // TODO: filter the analytics state.
179                 // Perhaps report this.
180 
181                 // Set up a timer to expire the previous audio state to save space.
182                 // Use the transaction log size as a cookie to see if it is the
183                 // same as before.  A benign race is possible where a state is cleared early.
184                 const size_t size = mPreviousAnalyticsState->transactionLog().size();
185                 mTimedAction.postIn(
186                         std::chrono::seconds(PREVIOUS_STATE_EXPIRE_SEC), [this, size](){
187                     if (mPreviousAnalyticsState->transactionLog().size() == size) {
188                         ALOGD("expiring previous audio state after %d seconds.",
189                                 PREVIOUS_STATE_EXPIRE_SEC);
190                         mPreviousAnalyticsState->clear();  // removes data from the state.
191                     }
192                 });
193             }));
194 
195     // Handle device use record statistics
196     mActions.addAction(
197         AMEDIAMETRICS_KEY_PREFIX_AUDIO_RECORD "*." AMEDIAMETRICS_PROP_EVENT,
198         std::string(AMEDIAMETRICS_PROP_EVENT_VALUE_ENDAUDIOINTERVALGROUP),
199         std::make_shared<AnalyticsActions::Function>(
200             [this](const std::shared_ptr<const android::mediametrics::Item> &item){
201                 mDeviceUse.endAudioIntervalGroup(item, DeviceUse::RECORD);
202             }));
203 
204     // Handle device use thread statistics
205     mActions.addAction(
206         AMEDIAMETRICS_KEY_PREFIX_AUDIO_THREAD "*." AMEDIAMETRICS_PROP_EVENT,
207         std::string(AMEDIAMETRICS_PROP_EVENT_VALUE_ENDAUDIOINTERVALGROUP),
208         std::make_shared<AnalyticsActions::Function>(
209             [this](const std::shared_ptr<const android::mediametrics::Item> &item){
210                 mDeviceUse.endAudioIntervalGroup(item, DeviceUse::THREAD);
211             }));
212 
213     // Handle device use track statistics
214     mActions.addAction(
215         AMEDIAMETRICS_KEY_PREFIX_AUDIO_TRACK "*." AMEDIAMETRICS_PROP_EVENT,
216         std::string(AMEDIAMETRICS_PROP_EVENT_VALUE_ENDAUDIOINTERVALGROUP),
217         std::make_shared<AnalyticsActions::Function>(
218             [this](const std::shared_ptr<const android::mediametrics::Item> &item){
219                 mDeviceUse.endAudioIntervalGroup(item, DeviceUse::TRACK);
220             }));
221 
222 
223     // Handle device connection statistics
224 
225     // We track connections (not disconnections) for the time to connect.
226     // TODO: consider BT requests in their A2dp service
227     // AudioManager.setBluetoothA2dpDeviceConnectionStateSuppressNoisyIntent
228     // AudioDeviceBroker.postBluetoothA2dpDeviceConnectionStateSuppressNoisyIntent
229     // AudioDeviceBroker.postA2dpActiveDeviceChange
230     mActions.addAction(
231         "audio.device.a2dp.state",
232         "connected",
233         std::make_shared<AnalyticsActions::Function>(
234             [this](const std::shared_ptr<const android::mediametrics::Item> &item){
235                 mDeviceConnection.a2dpConnected(item);
236             }));
237     // If audio is active, we expect to see a createAudioPatch after the device is connected.
238     mActions.addAction(
239         AMEDIAMETRICS_KEY_PREFIX_AUDIO_THREAD "*." AMEDIAMETRICS_PROP_EVENT,
240         std::string("createAudioPatch"),
241         std::make_shared<AnalyticsActions::Function>(
242             [this](const std::shared_ptr<const android::mediametrics::Item> &item){
243                 mDeviceConnection.createPatch(item);
244             }));
245 
246     // Called from BT service
247     mActions.addAction(
248         AMEDIAMETRICS_KEY_PREFIX_AUDIO_DEVICE
249         "postBluetoothA2dpDeviceConnectionStateSuppressNoisyIntent"
250         "." AMEDIAMETRICS_PROP_STATE,
251         "connected",
252         std::make_shared<AnalyticsActions::Function>(
253             [this](const std::shared_ptr<const android::mediametrics::Item> &item){
254                 mDeviceConnection.postBluetoothA2dpDeviceConnectionStateSuppressNoisyIntent(item);
255             }));
256 
257     // Handle power usage
258     mActions.addAction(
259         AMEDIAMETRICS_KEY_PREFIX_AUDIO_TRACK "*." AMEDIAMETRICS_PROP_EVENT,
260         std::string(AMEDIAMETRICS_PROP_EVENT_VALUE_ENDAUDIOINTERVALGROUP),
261         std::make_shared<AnalyticsActions::Function>(
262             [this](const std::shared_ptr<const android::mediametrics::Item> &item){
263                 mAudioPowerUsage.checkTrackRecord(item, true /* isTrack */);
264             }));
265 
266     mActions.addAction(
267         AMEDIAMETRICS_KEY_PREFIX_AUDIO_RECORD "*." AMEDIAMETRICS_PROP_EVENT,
268         std::string(AMEDIAMETRICS_PROP_EVENT_VALUE_ENDAUDIOINTERVALGROUP),
269         std::make_shared<AnalyticsActions::Function>(
270             [this](const std::shared_ptr<const android::mediametrics::Item> &item){
271                 mAudioPowerUsage.checkTrackRecord(item, false /* isTrack */);
272             }));
273 
274     mActions.addAction(
275         AMEDIAMETRICS_KEY_AUDIO_FLINGER "." AMEDIAMETRICS_PROP_EVENT,
276         std::string(AMEDIAMETRICS_PROP_EVENT_VALUE_SETMODE),
277         std::make_shared<AnalyticsActions::Function>(
278             [this](const std::shared_ptr<const android::mediametrics::Item> &item){
279                 // ALOGD("(key=%s) Audioflinger setMode", item->getKey().c_str());
280                 mAudioPowerUsage.checkMode(item);
281             }));
282 
283     mActions.addAction(
284         AMEDIAMETRICS_KEY_AUDIO_FLINGER "." AMEDIAMETRICS_PROP_EVENT,
285         std::string(AMEDIAMETRICS_PROP_EVENT_VALUE_SETVOICEVOLUME),
286         std::make_shared<AnalyticsActions::Function>(
287             [this](const std::shared_ptr<const android::mediametrics::Item> &item){
288                 // ALOGD("(key=%s) Audioflinger setVoiceVolume", item->getKey().c_str());
289                 mAudioPowerUsage.checkVoiceVolume(item);
290             }));
291 
292     mActions.addAction(
293         AMEDIAMETRICS_KEY_PREFIX_AUDIO_THREAD "*." AMEDIAMETRICS_PROP_EVENT,
294         std::string("createAudioPatch"),
295         std::make_shared<AnalyticsActions::Function>(
296             [this](const std::shared_ptr<const android::mediametrics::Item> &item){
297                 mAudioPowerUsage.checkCreatePatch(item);
298             }));
299 }
300 
~AudioAnalytics()301 AudioAnalytics::~AudioAnalytics()
302 {
303     ALOGD("%s", __func__);
304     mTimedAction.quit(); // ensure no deferred access during destructor.
305 }
306 
submit(const std::shared_ptr<const mediametrics::Item> & item,bool isTrusted)307 status_t AudioAnalytics::submit(
308         const std::shared_ptr<const mediametrics::Item>& item, bool isTrusted)
309 {
310     if (!startsWith(item->getKey(), AMEDIAMETRICS_KEY_PREFIX_AUDIO)) return BAD_VALUE;
311     status_t status = mAnalyticsState->submit(item, isTrusted);
312     if (status != NO_ERROR) return status;  // may not be permitted.
313 
314     // Only if the item was successfully submitted (permission)
315     // do we check triggered actions.
316     checkActions(item);
317     return NO_ERROR;
318 }
319 
dump(int32_t lines,int64_t sinceNs,const char * prefix) const320 std::pair<std::string, int32_t> AudioAnalytics::dump(
321         int32_t lines, int64_t sinceNs, const char *prefix) const
322 {
323     std::stringstream ss;
324     int32_t ll = lines;
325 
326     if (ll > 0) {
327         auto [s, l] = mAnalyticsState->dump(ll, sinceNs, prefix);
328         ss << s;
329         ll -= l;
330     }
331     if (ll > 0) {
332         ss << "Prior audioserver state:\n";
333         --ll;
334     }
335     if (ll > 0) {
336         auto [s, l] = mPreviousAnalyticsState->dump(ll, sinceNs, prefix);
337         ss << s;
338         ll -= l;
339     }
340 
341     if (ll > 0) {
342         // Print the statsd atoms we sent out.
343         const std::string statsd = mStatsdLog.dumpToString("  " /* prefix */, ll - 1);
344         const size_t n = std::count(statsd.begin(), statsd.end(), '\n') + 1; // we control this.
345         if ((size_t)ll >= n) {
346             if (n == 1) {
347                 ss << "Statsd atoms: empty or truncated\n";
348             } else {
349                 ss << "Statsd atoms:\n" << statsd;
350             }
351             ll -= n;
352         }
353     }
354 
355     if (ll > 0 && prefix == nullptr) {
356         auto [s, l] = mAudioPowerUsage.dump(ll);
357         ss << s;
358         ll -= l;
359     }
360 
361     return { ss.str(), lines - ll };
362 }
363 
checkActions(const std::shared_ptr<const mediametrics::Item> & item)364 void AudioAnalytics::checkActions(const std::shared_ptr<const mediametrics::Item>& item)
365 {
366     auto actions = mActions.getActionsForItem(item); // internally locked.
367     // Execute actions with no lock held.
368     for (const auto& action : actions) {
369         (*action)(item);
370     }
371 }
372 
373 // HELPER METHODS
374 
getThreadFromTrack(const std::string & track) const375 std::string AudioAnalytics::getThreadFromTrack(const std::string& track) const
376 {
377     int32_t threadId_int32{};
378     if (mAnalyticsState->timeMachine().get(
379             track, AMEDIAMETRICS_PROP_THREADID, &threadId_int32) != NO_ERROR) {
380         return {};
381     }
382     return std::string(AMEDIAMETRICS_KEY_PREFIX_AUDIO_THREAD) + std::to_string(threadId_int32);
383 }
384 
385 // DeviceUse helper class.
endAudioIntervalGroup(const std::shared_ptr<const android::mediametrics::Item> & item,ItemType itemType) const386 void AudioAnalytics::DeviceUse::endAudioIntervalGroup(
387        const std::shared_ptr<const android::mediametrics::Item> &item, ItemType itemType) const {
388     const std::string& key = item->getKey();
389     const std::string id = key.substr(
390             (itemType == THREAD ? sizeof(AMEDIAMETRICS_KEY_PREFIX_AUDIO_THREAD)
391             : itemType == TRACK ? sizeof(AMEDIAMETRICS_KEY_PREFIX_AUDIO_TRACK)
392             : sizeof(AMEDIAMETRICS_KEY_PREFIX_AUDIO_RECORD))
393              - 1);
394     // deliver statistics
395     int64_t deviceTimeNs = 0;
396     mAudioAnalytics.mAnalyticsState->timeMachine().get(
397             key, AMEDIAMETRICS_PROP_DEVICETIMENS, &deviceTimeNs);
398     std::string encoding;
399     mAudioAnalytics.mAnalyticsState->timeMachine().get(
400             key, AMEDIAMETRICS_PROP_ENCODING, &encoding);
401     int32_t frameCount = 0;
402     mAudioAnalytics.mAnalyticsState->timeMachine().get(
403             key, AMEDIAMETRICS_PROP_FRAMECOUNT, &frameCount);
404     std::string inputDevicePairs;
405     mAudioAnalytics.mAnalyticsState->timeMachine().get(
406             key, AMEDIAMETRICS_PROP_INPUTDEVICES, &inputDevicePairs);
407     int32_t intervalCount = 0;
408     mAudioAnalytics.mAnalyticsState->timeMachine().get(
409             key, AMEDIAMETRICS_PROP_INTERVALCOUNT, &intervalCount);
410     std::string outputDevicePairs;
411     mAudioAnalytics.mAnalyticsState->timeMachine().get(
412             key, AMEDIAMETRICS_PROP_OUTPUTDEVICES, &outputDevicePairs);
413     int32_t sampleRate = 0;
414     mAudioAnalytics.mAnalyticsState->timeMachine().get(
415             key, AMEDIAMETRICS_PROP_SAMPLERATE, &sampleRate);
416     std::string flags;
417     mAudioAnalytics.mAnalyticsState->timeMachine().get(
418             key, AMEDIAMETRICS_PROP_FLAGS, &flags);
419 
420     // We may have several devices.
421     // Accumulate the bit flags for input and output devices.
422     std::stringstream oss;
423     long_enum_type_t outputDeviceBits{};
424     {   // compute outputDevices
425         const auto devaddrvec = stringutils::getDeviceAddressPairs(outputDevicePairs);
426         for (const auto& [device, addr] : devaddrvec) {
427             if (oss.tellp() > 0) oss << "|";  // delimit devices with '|'.
428             oss << device;
429             outputDeviceBits += types::lookup<types::OUTPUT_DEVICE, long_enum_type_t>(device);
430         }
431     }
432     const std::string outputDevices = oss.str();
433 
434     std::stringstream iss;
435     long_enum_type_t inputDeviceBits{};
436     {   // compute inputDevices
437         const auto devaddrvec = stringutils::getDeviceAddressPairs(inputDevicePairs);
438         for (const auto& [device, addr] : devaddrvec) {
439             if (iss.tellp() > 0) iss << "|";  // delimit devices with '|'.
440             iss << device;
441             inputDeviceBits += types::lookup<types::INPUT_DEVICE, long_enum_type_t>(device);
442         }
443     }
444     const std::string inputDevices = iss.str();
445 
446     // Get connected device name if from bluetooth.
447     bool isBluetooth = false;
448 
449     std::string inputDeviceNames;  // not filled currently.
450     std::string outputDeviceNames;
451     if (outputDevices.find("AUDIO_DEVICE_OUT_BLUETOOTH") != std::string::npos) {
452         isBluetooth = true;
453         outputDeviceNames = SUPPRESSED;
454 #if 0   // TODO(b/161554630) sanitize name
455         mAudioAnalytics.mAnalyticsState->timeMachine().get(
456             "audio.device.bt_a2dp", AMEDIAMETRICS_PROP_NAME, &outputDeviceNames);
457         // Remove | if present
458         stringutils::replace(outputDeviceNames, "|", '?');
459         if (outputDeviceNames.size() > STATSD_DEVICE_NAME_MAX_LENGTH) {
460             outputDeviceNames.resize(STATSD_DEVICE_NAME_MAX_LENGTH); // truncate
461         }
462 #endif
463     }
464 
465     switch (itemType) {
466     case RECORD: {
467         std::string callerName;
468         const bool clientCalled = mAudioAnalytics.mAnalyticsState->timeMachine().get(
469                 key, AMEDIAMETRICS_PROP_CALLERNAME, &callerName) == OK;
470 
471         std::string packageName;
472         int64_t versionCode = 0;
473         int32_t uid = -1;
474         mAudioAnalytics.mAnalyticsState->timeMachine().get(
475                 key, AMEDIAMETRICS_PROP_ALLOWUID, &uid);
476         if (uid != -1) {
477             std::tie(packageName, versionCode) =
478                     MediaMetricsService::getSanitizedPackageNameAndVersionCode(uid);
479         }
480 
481         int32_t selectedDeviceId = 0;
482         mAudioAnalytics.mAnalyticsState->timeMachine().get(
483                 key, AMEDIAMETRICS_PROP_SELECTEDDEVICEID, &selectedDeviceId);
484         std::string source;
485         mAudioAnalytics.mAnalyticsState->timeMachine().get(
486                 key, AMEDIAMETRICS_PROP_SOURCE, &source);
487 
488         const auto callerNameForStats =
489                 types::lookup<types::CALLER_NAME, short_enum_type_t>(callerName);
490         const auto encodingForStats = types::lookup<types::ENCODING, short_enum_type_t>(encoding);
491         const auto flagsForStats = types::lookup<types::INPUT_FLAG, short_enum_type_t>(flags);
492         const auto sourceForStats = types::lookup<types::SOURCE_TYPE, short_enum_type_t>(source);
493 
494         LOG(LOG_LEVEL) << "key:" << key
495               << " id:" << id
496               << " inputDevices:" << inputDevices << "(" << inputDeviceBits
497               << ") inputDeviceNames:" << inputDeviceNames
498               << " deviceTimeNs:" << deviceTimeNs
499               << " encoding:" << encoding << "(" << encodingForStats
500               << ") frameCount:" << frameCount
501               << " intervalCount:" << intervalCount
502               << " sampleRate:" << sampleRate
503               << " flags:" << flags << "(" << flagsForStats
504               << ") packageName:" << packageName
505               << " selectedDeviceId:" << selectedDeviceId
506               << " callerName:" << callerName << "(" << callerNameForStats
507               << ") source:" << source << "(" << sourceForStats << ")";
508         if (clientCalled  // only log if client app called AudioRecord.
509                 && mAudioAnalytics.mDeliverStatistics) {
510             const auto [ result, str ] = sendToStatsd(AudioRecordDeviceUsageFields,
511                     CONDITION(android::util::MEDIAMETRICS_AUDIORECORDDEVICEUSAGE_REPORTED)
512                     , ENUM_EXTRACT(inputDeviceBits)
513                     , inputDeviceNames.c_str()
514                     , deviceTimeNs
515                     , ENUM_EXTRACT(encodingForStats)
516                     , frameCount
517                     , intervalCount
518                     , sampleRate
519                     , ENUM_EXTRACT(flagsForStats)
520 
521                     , packageName.c_str()
522                     , selectedDeviceId
523                     , ENUM_EXTRACT(callerNameForStats)
524                     , ENUM_EXTRACT(sourceForStats)
525                     );
526             ALOGV("%s: statsd %s", __func__, str.c_str());
527             mAudioAnalytics.mStatsdLog.log("%s", str.c_str());
528         }
529     } break;
530     case THREAD: {
531         std::string type;
532         mAudioAnalytics.mAnalyticsState->timeMachine().get(
533                 key, AMEDIAMETRICS_PROP_TYPE, &type);
534         int32_t underrun = 0; // zero for record types
535         mAudioAnalytics.mAnalyticsState->timeMachine().get(
536                 key, AMEDIAMETRICS_PROP_UNDERRUN, &underrun);
537 
538         const bool isInput = types::isInputThreadType(type);
539         const auto encodingForStats = types::lookup<types::ENCODING, short_enum_type_t>(encoding);
540         const auto flagsForStats =
541                 (isInput ? types::lookup<types::INPUT_FLAG, short_enum_type_t>(flags)
542                         : types::lookup<types::OUTPUT_FLAG, short_enum_type_t>(flags));
543         const auto typeForStats = types::lookup<types::THREAD_TYPE, short_enum_type_t>(type);
544 
545         LOG(LOG_LEVEL) << "key:" << key
546               << " id:" << id
547               << " inputDevices:" << inputDevices << "(" << inputDeviceBits
548               << ") outputDevices:" << outputDevices << "(" << outputDeviceBits
549               << ") inputDeviceNames:" << inputDeviceNames
550               << " outputDeviceNames:" << outputDeviceNames
551               << " deviceTimeNs:" << deviceTimeNs
552               << " encoding:" << encoding << "(" << encodingForStats
553               << ") frameCount:" << frameCount
554               << " intervalCount:" << intervalCount
555               << " sampleRate:" << sampleRate
556               << " underrun:" << underrun
557               << " flags:" << flags << "(" << flagsForStats
558               << ") type:" << type << "(" << typeForStats
559               << ")";
560         if (mAudioAnalytics.mDeliverStatistics) {
561             const auto [ result, str ] = sendToStatsd(AudioThreadDeviceUsageFields,
562                 CONDITION(android::util::MEDIAMETRICS_AUDIOTHREADDEVICEUSAGE_REPORTED)
563                 , isInput ? ENUM_EXTRACT(inputDeviceBits) : ENUM_EXTRACT(outputDeviceBits)
564                 , isInput ? inputDeviceNames.c_str() : outputDeviceNames.c_str()
565                 , deviceTimeNs
566                 , ENUM_EXTRACT(encodingForStats)
567                 , frameCount
568                 , intervalCount
569                 , sampleRate
570                 , ENUM_EXTRACT(flagsForStats)
571                 , underrun
572                 , ENUM_EXTRACT(typeForStats)
573             );
574             ALOGV("%s: statsd %s", __func__, str.c_str());
575             mAudioAnalytics.mStatsdLog.log("%s", str.c_str());
576         }
577     } break;
578     case TRACK: {
579         std::string callerName;
580         const bool clientCalled = mAudioAnalytics.mAnalyticsState->timeMachine().get(
581                 key, AMEDIAMETRICS_PROP_CALLERNAME, &callerName) == OK;
582 
583         std::string contentType;
584         mAudioAnalytics.mAnalyticsState->timeMachine().get(
585                 key, AMEDIAMETRICS_PROP_CONTENTTYPE, &contentType);
586         double deviceLatencyMs = 0.;
587         mAudioAnalytics.mAnalyticsState->timeMachine().get(
588                 key, AMEDIAMETRICS_PROP_DEVICELATENCYMS, &deviceLatencyMs);
589         double deviceStartupMs = 0.;
590         mAudioAnalytics.mAnalyticsState->timeMachine().get(
591                 key, AMEDIAMETRICS_PROP_DEVICESTARTUPMS, &deviceStartupMs);
592         double deviceVolume = 0.;
593         mAudioAnalytics.mAnalyticsState->timeMachine().get(
594                 key, AMEDIAMETRICS_PROP_DEVICEVOLUME, &deviceVolume);
595         std::string packageName;
596         int64_t versionCode = 0;
597         int32_t uid = -1;
598         mAudioAnalytics.mAnalyticsState->timeMachine().get(
599                 key, AMEDIAMETRICS_PROP_ALLOWUID, &uid);
600         if (uid != -1) {
601             std::tie(packageName, versionCode) =
602                     MediaMetricsService::getSanitizedPackageNameAndVersionCode(uid);
603         }
604         double playbackPitch = 0.;
605         mAudioAnalytics.mAnalyticsState->timeMachine().get(
606                 key, AMEDIAMETRICS_PROP_PLAYBACK_PITCH, &playbackPitch);
607         double playbackSpeed = 0.;
608         mAudioAnalytics.mAnalyticsState->timeMachine().get(
609                 key, AMEDIAMETRICS_PROP_PLAYBACK_SPEED, &playbackSpeed);
610         int32_t selectedDeviceId = 0;
611         mAudioAnalytics.mAnalyticsState->timeMachine().get(
612                 key, AMEDIAMETRICS_PROP_SELECTEDDEVICEID, &selectedDeviceId);
613         std::string streamType;
614         mAudioAnalytics.mAnalyticsState->timeMachine().get(
615                 key, AMEDIAMETRICS_PROP_STREAMTYPE, &streamType);
616         std::string traits;
617         mAudioAnalytics.mAnalyticsState->timeMachine().get(
618                 key, AMEDIAMETRICS_PROP_TRAITS, &traits);
619         int32_t underrun = 0;
620         mAudioAnalytics.mAnalyticsState->timeMachine().get(
621                 key, AMEDIAMETRICS_PROP_UNDERRUN, &underrun);
622         std::string usage;
623         mAudioAnalytics.mAnalyticsState->timeMachine().get(
624                 key, AMEDIAMETRICS_PROP_USAGE, &usage);
625 
626         const auto callerNameForStats =
627                 types::lookup<types::CALLER_NAME, short_enum_type_t>(callerName);
628         const auto contentTypeForStats =
629                 types::lookup<types::CONTENT_TYPE, short_enum_type_t>(contentType);
630         const auto encodingForStats = types::lookup<types::ENCODING, short_enum_type_t>(encoding);
631         const auto flagsForStats = types::lookup<types::OUTPUT_FLAG, short_enum_type_t>(flags);
632         const auto streamTypeForStats =
633                 types::lookup<types::STREAM_TYPE, short_enum_type_t>(streamType);
634         const auto traitsForStats =
635                  types::lookup<types::TRACK_TRAITS, short_enum_type_t>(traits);
636         const auto usageForStats = types::lookup<types::USAGE, short_enum_type_t>(usage);
637 
638         LOG(LOG_LEVEL) << "key:" << key
639               << " id:" << id
640               << " outputDevices:" << outputDevices << "(" << outputDeviceBits
641               << ") outputDeviceNames:" << outputDeviceNames
642               << " deviceTimeNs:" << deviceTimeNs
643               << " encoding:" << encoding << "(" << encodingForStats
644               << ") frameCount:" << frameCount
645               << " intervalCount:" << intervalCount
646               << " sampleRate:" << sampleRate
647               << " underrun:" << underrun
648               << " flags:" << flags << "(" << flagsForStats
649               << ") callerName:" << callerName << "(" << callerNameForStats
650               << ") contentType:" << contentType << "(" << contentTypeForStats
651               << ") deviceLatencyMs:" << deviceLatencyMs
652               << " deviceStartupMs:" << deviceStartupMs
653               << " deviceVolume:" << deviceVolume
654               << " packageName:" << packageName
655               << " playbackPitch:" << playbackPitch
656               << " playbackSpeed:" << playbackSpeed
657               << " selectedDeviceId:" << selectedDeviceId
658               << " streamType:" << streamType << "(" << streamTypeForStats
659               << ") traits:" << traits << "(" << traitsForStats
660               << ") usage:" << usage << "(" << usageForStats
661               << ")";
662         if (clientCalled // only log if client app called AudioTracks
663                 && mAudioAnalytics.mDeliverStatistics) {
664             const auto [ result, str ] = sendToStatsd(AudioTrackDeviceUsageFields,
665                     CONDITION(android::util::MEDIAMETRICS_AUDIOTRACKDEVICEUSAGE_REPORTED)
666                     , ENUM_EXTRACT(outputDeviceBits)
667                     , outputDeviceNames.c_str()
668                     , deviceTimeNs
669                     , ENUM_EXTRACT(encodingForStats)
670                     , frameCount
671                     , intervalCount
672                     , sampleRate
673                     , ENUM_EXTRACT(flagsForStats)
674                     , underrun
675                     , packageName.c_str()
676                     , (float)deviceLatencyMs
677                     , (float)deviceStartupMs
678                     , (float)deviceVolume
679                     , selectedDeviceId
680                     , ENUM_EXTRACT(streamTypeForStats)
681                     , ENUM_EXTRACT(usageForStats)
682                     , ENUM_EXTRACT(contentTypeForStats)
683                     , ENUM_EXTRACT(callerNameForStats)
684                     , ENUM_EXTRACT(traitsForStats)
685                     );
686             ALOGV("%s: statsd %s", __func__, str.c_str());
687             mAudioAnalytics.mStatsdLog.log("%s", str.c_str());
688         }
689         } break;
690     }
691 
692     // Report this as needed.
693     if (isBluetooth) {
694         // report this for Bluetooth
695     }
696 }
697 
698 // DeviceConnection helper class.
a2dpConnected(const std::shared_ptr<const android::mediametrics::Item> & item)699 void AudioAnalytics::DeviceConnection::a2dpConnected(
700        const std::shared_ptr<const android::mediametrics::Item> &item) {
701     const std::string& key = item->getKey();
702     const int64_t atNs = item->getTimestamp();
703     {
704         std::lock_guard l(mLock);
705         mA2dpConnectionServiceNs = atNs;
706         ++mA2dpConnectionServices;
707 
708         if (mA2dpConnectionRequestNs == 0) {
709             mAudioAnalytics.mTimedAction.postIn(std::chrono::seconds(5), [this](){ expire(); });
710         }
711         // This sets the time we were connected.  Now we look for the delta in the future.
712     }
713     std::string name;
714     item->get(AMEDIAMETRICS_PROP_NAME, &name);
715     ALOGD("(key=%s) a2dp connected device:%s atNs:%lld",
716             key.c_str(), name.c_str(), (long long)atNs);
717 }
718 
createPatch(const std::shared_ptr<const android::mediametrics::Item> & item)719 void AudioAnalytics::DeviceConnection::createPatch(
720        const std::shared_ptr<const android::mediametrics::Item> &item) {
721     std::lock_guard l(mLock);
722     if (mA2dpConnectionServiceNs == 0) return; // patch unrelated to us.
723     const std::string& key = item->getKey();
724     std::string outputDevices;
725     item->get(AMEDIAMETRICS_PROP_OUTPUTDEVICES, &outputDevices);
726     if (outputDevices.find("AUDIO_DEVICE_OUT_BLUETOOTH_A2DP") != std::string::npos) {
727         // TODO compare address
728         int64_t timeDiffNs = item->getTimestamp();
729         if (mA2dpConnectionRequestNs == 0) {
730             ALOGD("%s: A2DP create patch didn't see a connection request", __func__);
731             timeDiffNs -= mA2dpConnectionServiceNs;
732         } else {
733             timeDiffNs -= mA2dpConnectionRequestNs;
734         }
735 
736         mA2dpConnectionRequestNs = 0;
737         mA2dpConnectionServiceNs = 0;
738         ++mA2dpConnectionSuccesses;
739 
740         const auto connectionTimeMs = float(timeDiffNs * 1e-6);
741 
742         const auto outputDeviceBits = types::lookup<types::OUTPUT_DEVICE, long_enum_type_t>(
743                 "AUDIO_DEVICE_OUT_BLUETOOTH_A2DP");
744 
745         LOG(LOG_LEVEL) << "key:" << key
746                 << " A2DP SUCCESS"
747                 << " outputDevices:" << outputDeviceBits
748                 << " deviceName:" << mA2dpDeviceName
749                 << " connectionTimeMs:" <<  connectionTimeMs;
750         if (mAudioAnalytics.mDeliverStatistics) {
751             const long_enum_type_t inputDeviceBits{};
752 
753             const auto [ result, str ] = sendToStatsd(AudioDeviceConnectionFields,
754                     CONDITION(android::util::MEDIAMETRICS_AUDIODEVICECONNECTION_REPORTED)
755                     , ENUM_EXTRACT(inputDeviceBits)
756                     , ENUM_EXTRACT(outputDeviceBits)
757                     , mA2dpDeviceName.c_str()
758                     , types::DEVICE_CONNECTION_RESULT_SUCCESS
759                     , connectionTimeMs
760                     , /* connection_count */ 1
761                     );
762             ALOGV("%s: statsd %s", __func__, str.c_str());
763             mAudioAnalytics.mStatsdLog.log("%s", str.c_str());
764         }
765     }
766 }
767 
768 // Called through AudioManager when the BT service wants to enable
postBluetoothA2dpDeviceConnectionStateSuppressNoisyIntent(const std::shared_ptr<const android::mediametrics::Item> & item)769 void AudioAnalytics::DeviceConnection::postBluetoothA2dpDeviceConnectionStateSuppressNoisyIntent(
770         const std::shared_ptr<const android::mediametrics::Item> &item) {
771     const int64_t atNs = item->getTimestamp();
772     const std::string& key = item->getKey();
773     std::string state;
774     item->get(AMEDIAMETRICS_PROP_STATE, &state);
775     if (state != "connected") return;
776 
777     std::string name;
778     item->get(AMEDIAMETRICS_PROP_NAME, &name);
779     {
780         std::lock_guard l(mLock);
781         mA2dpConnectionRequestNs = atNs;
782         ++mA2dpConnectionRequests;
783         mA2dpDeviceName = SUPPRESSED; // TODO(b/161554630) sanitize name
784     }
785     ALOGD("(key=%s) a2dp connection name:%s request atNs:%lld",
786             key.c_str(), name.c_str(), (long long)atNs);
787     // TODO: attempt to cancel a timed event, rather than let it expire.
788     mAudioAnalytics.mTimedAction.postIn(std::chrono::seconds(5), [this](){ expire(); });
789 }
790 
expire()791 void AudioAnalytics::DeviceConnection::expire() {
792     std::lock_guard l(mLock);
793     if (mA2dpConnectionRequestNs == 0) return; // ignore (this was an internal connection).
794 
795     const long_enum_type_t inputDeviceBits{};
796     const auto outputDeviceBits = types::lookup<types::OUTPUT_DEVICE, long_enum_type_t>(
797             "AUDIO_DEVICE_OUT_BLUETOOTH_A2DP");
798 
799     if (mA2dpConnectionServiceNs == 0) {
800         ++mA2dpConnectionJavaServiceCancels;  // service did not connect to A2DP
801 
802         LOG(LOG_LEVEL) << "A2DP CANCEL"
803                 << " outputDevices:" << outputDeviceBits
804                 << " deviceName:" << mA2dpDeviceName;
805         if (mAudioAnalytics.mDeliverStatistics) {
806             const auto [ result, str ] = sendToStatsd(AudioDeviceConnectionFields,
807                     CONDITION(android::util::MEDIAMETRICS_AUDIODEVICECONNECTION_REPORTED)
808                     , ENUM_EXTRACT(inputDeviceBits)
809                     , ENUM_EXTRACT(outputDeviceBits)
810                     , mA2dpDeviceName.c_str()
811                     , types::DEVICE_CONNECTION_RESULT_JAVA_SERVICE_CANCEL
812                     , /* connection_time_ms */ 0.f
813                     , /* connection_count */ 1
814                     );
815             ALOGV("%s: statsd %s", __func__, str.c_str());
816             mAudioAnalytics.mStatsdLog.log("%s", str.c_str());
817         }
818         return;
819     }
820 
821     // AudioFlinger didn't play - an expiration may occur because there is no audio playing.
822     // Should we check elsewhere?
823     // TODO: disambiguate this case.
824     mA2dpConnectionRequestNs = 0;
825     mA2dpConnectionServiceNs = 0;
826     ++mA2dpConnectionUnknowns;  // connection result unknown
827 
828     LOG(LOG_LEVEL) << "A2DP UNKNOWN"
829             << " outputDevices:" << outputDeviceBits
830             << " deviceName:" << mA2dpDeviceName;
831     if (mAudioAnalytics.mDeliverStatistics) {
832         const auto [ result, str ] = sendToStatsd(AudioDeviceConnectionFields,
833                 CONDITION(android::util::MEDIAMETRICS_AUDIODEVICECONNECTION_REPORTED)
834                 , ENUM_EXTRACT(inputDeviceBits)
835                 , ENUM_EXTRACT(outputDeviceBits)
836                 , mA2dpDeviceName.c_str()
837                 , types::DEVICE_CONNECTION_RESULT_UNKNOWN
838                 , /* connection_time_ms */ 0.f
839                 , /* connection_count */ 1
840                 );
841         ALOGV("%s: statsd %s", __func__, str.c_str());
842         mAudioAnalytics.mStatsdLog.log("%s", str.c_str());
843     }
844 }
845 
846 } // namespace android::mediametrics
847