1 /*
2  * Copyright (C) 2017 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 "MediaMetricsService"
19 #include <utils/Log.h>
20 
21 #include "MediaMetricsService.h"
22 #include "ValidateId.h"
23 #include "iface_statsd.h"
24 
25 #include <pwd.h> //getpwuid
26 
27 #include <android-base/stringprintf.h>
28 #include <android/content/pm/IPackageManagerNative.h>  // package info
29 #include <audio_utils/clock.h>                 // clock conversions
30 #include <binder/IPCThreadState.h>             // get calling uid
31 #include <binder/IServiceManager.h>            // checkCallingPermission
32 #include <cutils/properties.h>                 // for property_get
33 #include <mediautils/MemoryLeakTrackUtil.h>
34 #include <memunreachable/memunreachable.h>
35 #include <private/android_filesystem_config.h> // UID
36 #include <stats_media_metrics.h>
37 
38 #include <set>
39 
40 namespace android {
41 
42 using base::StringPrintf;
43 using mediametrics::Item;
44 using mediametrics::startsWith;
45 
46 // individual records kept in memory: age or count
47 // age: <= 28 hours (1 1/6 days)
48 // count: hard limit of # records
49 // (0 for either of these disables that threshold)
50 //
51 static constexpr nsecs_t kMaxRecordAgeNs = 28 * 3600 * NANOS_PER_SECOND;
52 // 2019/6: average daily per device is currently 375-ish;
53 // setting this to 2000 is large enough to catch most devices
54 // we'll lose some data on very very media-active devices, but only for
55 // the gms collection; statsd will have already covered those for us.
56 // This also retains enough information to help with bugreports
57 static constexpr size_t kMaxRecords = 2000;
58 
59 // max we expire in a single call, to constrain how long we hold the
60 // mutex, which also constrains how long a client might wait.
61 static constexpr size_t kMaxExpiredAtOnce = 50;
62 
63 // TODO: need to look at tuning kMaxRecords and friends for low-memory devices
64 
65 /* static */
roundTime(nsecs_t timeNs)66 nsecs_t MediaMetricsService::roundTime(nsecs_t timeNs)
67 {
68     return (timeNs + NANOS_PER_SECOND / 2) / NANOS_PER_SECOND * NANOS_PER_SECOND;
69 }
70 
71 /* static */
useUidForPackage(const std::string & package,const std::string & installer)72 bool MediaMetricsService::useUidForPackage(
73         const std::string& package, const std::string& installer)
74 {
75     // NOLINTBEGIN(bugprone-branch-clone)
76     if (strchr(package.c_str(), '.') == nullptr) {
77         return false;  // not of form 'com.whatever...'; assume internal and ok
78     } else if (strncmp(package.c_str(), "android.", 8) == 0) {
79         return false;  // android.* packages are assumed fine
80     } else if (strncmp(installer.c_str(), "com.android.", 12) == 0) {
81         return false;  // from play store
82     } else if (strncmp(installer.c_str(), "com.google.", 11) == 0) {
83         return false;  // some google source
84     } else if (strcmp(installer.c_str(), "preload") == 0) {
85         return false;  // preloads
86     } else {
87         return true;  // we're not sure where it came from, use uid only.
88     }
89     // NOLINTEND(bugprone-branch-clone)
90 }
91 
92 /* static */
93 std::pair<std::string, int64_t>
getSanitizedPackageNameAndVersionCode(uid_t uid)94 MediaMetricsService::getSanitizedPackageNameAndVersionCode(uid_t uid) {
95     // Meyer's singleton, initialized on first access.
96     // mUidInfo is locked internally.
97     static mediautils::UidInfo uidInfo;
98 
99     // get info.
100     mediautils::UidInfo::Info info = uidInfo.getInfo(uid);
101     if (useUidForPackage(info.package, info.installer)) {
102         return { std::to_string(uid), /* versionCode */ 0 };
103     } else {
104         return { info.package, info.versionCode };
105     }
106 }
107 
MediaMetricsService()108 MediaMetricsService::MediaMetricsService()
109         : mMaxRecords(kMaxRecords),
110           mMaxRecordAgeNs(kMaxRecordAgeNs),
111           mMaxRecordsExpiredAtOnce(kMaxExpiredAtOnce)
112 {
113     ALOGD("%s", __func__);
114 }
115 
~MediaMetricsService()116 MediaMetricsService::~MediaMetricsService()
117 {
118     ALOGD("%s", __func__);
119     // the class destructor clears anyhow, but we enforce clearing items first.
120     mItemsDiscarded += (int64_t)mItems.size();
121     mItems.clear();
122 }
123 
submitInternal(mediametrics::Item * item,bool release)124 status_t MediaMetricsService::submitInternal(mediametrics::Item *item, bool release)
125 {
126     // calling PID is 0 for one-way calls.
127     const pid_t pid = IPCThreadState::self()->getCallingPid();
128     const pid_t pid_given = item->getPid();
129     const uid_t uid = IPCThreadState::self()->getCallingUid();
130     const uid_t uid_given = item->getUid();
131 
132     //ALOGD("%s: caller pid=%d uid=%d,  item pid=%d uid=%d", __func__,
133     //        (int)pid, (int)uid, (int) pid_given, (int)uid_given);
134 
135     bool isTrusted;
136     switch (uid) {
137     case AID_AUDIOSERVER:
138     case AID_BLUETOOTH:
139     case AID_CAMERA:
140     case AID_DRM:
141     case AID_MEDIA:
142     case AID_MEDIA_CODEC:
143     case AID_MEDIA_EX:
144     case AID_MEDIA_DRM:
145     // case AID_SHELL: // DEBUG ONLY - used for mediametrics_tests to add new keys
146     case AID_SYSTEM:
147         // trusted source, only override default values
148         isTrusted = true;
149         if (uid_given == (uid_t)-1) {
150             item->setUid(uid);
151         }
152         if (pid_given == (pid_t)-1) {
153             item->setPid(pid); // if one-way then this is 0.
154         }
155         break;
156     default:
157         isTrusted = false;
158         item->setPid(pid); // always use calling pid, if one-way then this is 0.
159         item->setUid(uid);
160         break;
161     }
162 
163     // Overwrite package name and version if the caller was untrusted or empty
164     if (!isTrusted || item->getPkgName().empty()) {
165         const uid_t uidItem = item->getUid();
166         const auto [ pkgName, version ] =
167                 MediaMetricsService::getSanitizedPackageNameAndVersionCode(uidItem);
168         item->setPkgName(pkgName);
169         item->setPkgVersionCode(version);
170     }
171 
172     ALOGV("%s: isTrusted:%d given uid %d; sanitized uid: %d sanitized pkg: %s "
173           "sanitized pkg version: %lld",
174           __func__,
175           (int)isTrusted,
176           uid_given, item->getUid(),
177           item->getPkgName().c_str(),
178           (long long)item->getPkgVersionCode());
179 
180     mItemsSubmitted++;
181 
182     // validate the record; we discard if we don't like it
183     if (isContentValid(item, isTrusted) == false) {
184         if (release) delete item;
185         return PERMISSION_DENIED;
186     }
187 
188     // XXX: if we have a sessionid in the new record, look to make
189     // sure it doesn't appear in the finalized list.
190 
191     if (item->count() == 0) {
192         ALOGV("%s: dropping empty record...", __func__);
193         if (release) delete item;
194         return BAD_VALUE;
195     }
196 
197     if (!isTrusted || item->getTimestamp() == 0) {
198         // Statsd logs two times for events: ElapsedRealTimeNs (BOOTTIME) and
199         // WallClockTimeNs (REALTIME), but currently logs REALTIME to cloud.
200         //
201         // For consistency and correlation with other logging mechanisms
202         // we use REALTIME here.
203         const int64_t now = systemTime(SYSTEM_TIME_REALTIME);
204         item->setTimestamp(now);
205     }
206 
207     // now attach either the item or its dup to a const shared pointer
208     std::shared_ptr<const mediametrics::Item> sitem(release ? item : item->dup());
209 
210     // register log session ids with singleton.
211     if (startsWith(item->getKey(), "metrics.manager")) {
212         std::string logSessionId;
213         if (item->get("logSessionId", &logSessionId)
214                 && mediametrics::stringutils::isLogSessionId(logSessionId.c_str())) {
215             mediametrics::ValidateId::get()->registerId(logSessionId);
216         }
217     }
218 
219     (void)mAudioAnalytics.submit(sitem, isTrusted);
220 
221     (void)dump2Statsd(sitem, mStatsdLog);  // failure should be logged in function.
222     saveItem(sitem);
223     return NO_ERROR;
224 }
225 
dump(int fd,const Vector<String16> & args)226 status_t MediaMetricsService::dump(int fd, const Vector<String16>& args)
227 {
228     if (checkCallingPermission(String16("android.permission.DUMP")) == false) {
229         const std::string result = StringPrintf("Permission Denial: "
230                 "can't dump MediaMetricsService from pid=%d, uid=%d\n",
231                 IPCThreadState::self()->getCallingPid(),
232                 IPCThreadState::self()->getCallingUid());
233         write(fd, result.c_str(), result.size());
234         return NO_ERROR;
235     }
236 
237     static const String16 allOption("--all");
238     static const String16 clearOption("--clear");
239     static const String16 heapOption("--heap");
240     static const String16 helpOption("--help");
241     static const String16 prefixOption("--prefix");
242     static const String16 sinceOption("--since");
243     static const String16 unreachableOption("--unreachable");
244 
245     bool all = false;
246     bool clear = false;
247     bool heap = false;
248     bool unreachable = false;
249     int64_t sinceNs = 0;
250     std::string prefix;
251 
252     const size_t n = args.size();
253     for (size_t i = 0; i < n; i++) {
254         if (args[i] == allOption) {
255             all = true;
256         } else if (args[i] == clearOption) {
257             clear = true;
258         } else if (args[i] == heapOption) {
259             heap = true;
260         } else if (args[i] == helpOption) {
261             // TODO: consider function area dumping.
262             // dumpsys media.metrics audiotrack,codec
263             // or dumpsys media.metrics audiotrack codec
264 
265             static constexpr char result[] =
266                     "Recognized parameters:\n"
267                     "--all         show all records\n"
268                     "--clear       clear out saved records\n"
269                     "--heap        show heap usage (top 100)\n"
270                     "--help        display help\n"
271                     "--prefix X    process records for component X\n"
272                     "--since X     X < 0: records from -X seconds in the past\n"
273                     "              X = 0: ignore\n"
274                     "              X > 0: records from X seconds since Unix epoch\n"
275                     "--unreachable show unreachable memory (leaks)\n";
276             write(fd, result, std::size(result));
277             return NO_ERROR;
278         } else if (args[i] == prefixOption) {
279             ++i;
280             if (i < n) {
281                 prefix = String8(args[i]).c_str();
282             }
283         } else if (args[i] == sinceOption) {
284             ++i;
285             if (i < n) {
286                 String8 value(args[i]);
287                 char *endp;
288                 const char *p = value.c_str();
289                 const auto sec = (int64_t)strtoll(p, &endp, 10);
290                 if (endp == p || *endp != '\0' || sec == 0) {
291                     sinceNs = 0;
292                 } else if (sec < 0) {
293                     sinceNs = systemTime(SYSTEM_TIME_REALTIME) + sec * NANOS_PER_SECOND;
294                 } else {
295                     sinceNs = sec * NANOS_PER_SECOND;
296                 }
297             }
298         } else if (args[i] == unreachableOption) {
299             unreachable = true;
300         }
301     }
302     std::stringstream result;
303     {
304         std::lock_guard _l(mLock);
305 
306         if (clear) {
307             mItemsDiscarded += (int64_t)mItems.size();
308             mItems.clear();
309             mAudioAnalytics.clear();
310         } else {
311             result << StringPrintf("Dump of the %s process:\n", kServiceName);
312             const char *prefixptr = prefix.size() > 0 ? prefix.c_str() : nullptr;
313             result << dumpHeaders(sinceNs, prefixptr);
314             result << dumpQueue(sinceNs, prefixptr);
315 
316             // TODO: maybe consider a better way of dumping audio analytics info.
317             const int32_t linesToDump = all ? INT32_MAX : 1000;
318             auto [ dumpString, lines ] = mAudioAnalytics.dump(linesToDump, sinceNs, prefixptr);
319             result << dumpString;
320             if (lines == linesToDump) {
321                 result << "-- some lines may be truncated --\n";
322             }
323 
324             const int32_t heatLinesToDump = all ? INT32_MAX : 20;
325             const auto [ heatDumpString, heatLines] =
326                     mAudioAnalytics.dumpHeatMap(heatLinesToDump);
327             result << "\n" << heatDumpString;
328             if (heatLines == heatLinesToDump) {
329                 result << "-- some lines may be truncated --\n";
330             }
331 
332             const int32_t healthLinesToDump = all ? INT32_MAX : 15;
333             result << "\nHealth Message Log:";
334             const auto [ healthDumpString, healthLines ] =
335                     mAudioAnalytics.dumpHealth(healthLinesToDump);
336             result << "\n" << healthDumpString;
337             if (healthLines == healthLinesToDump) {
338                 result << "-- some lines may be truncated --\n";
339             }
340 
341             const int32_t spatializerLinesToDump = all ? INT32_MAX : 15;
342             result << "\nSpatializer Message Log:";
343             const auto [ spatializerDumpString, spatializerLines ] =
344                     mAudioAnalytics.dumpSpatializer(spatializerLinesToDump);
345             result << "\n" << spatializerDumpString;
346             if (spatializerLines == spatializerLinesToDump) {
347                 result << "-- some lines may be truncated --\n";
348             }
349 
350             result << "\nLogSessionId:\n"
351                    << mediametrics::ValidateId::get()->dump();
352 
353             // Dump the statsd atoms we sent out.
354             result << "\nStatsd atoms:\n"
355                    << mStatsdLog->dumpToString("  " /* prefix */,
356                            all ? STATSD_LOG_LINES_MAX : STATSD_LOG_LINES_DUMP);
357         }
358     }
359     const std::string str = result.str();
360     write(fd, str.c_str(), str.size());
361 
362     // Check heap and unreachable memory outside of lock.
363     if (heap) {
364         dprintf(fd, "\nDumping heap:\n");
365         std::string s = dumpMemoryAddresses(100 /* limit */);
366         write(fd, s.c_str(), s.size());
367     }
368     if (unreachable) {
369         dprintf(fd, "\nDumping unreachable memory:\n");
370         // TODO - should limit be an argument parameter?
371         std::string s = GetUnreachableMemoryString(true /* contents */, 100 /* limit */);
372         write(fd, s.c_str(), s.size());
373     }
374     return NO_ERROR;
375 }
376 
377 // dump headers
dumpHeaders(int64_t sinceNs,const char * prefix)378 std::string MediaMetricsService::dumpHeaders(int64_t sinceNs, const char* prefix)
379 {
380     std::stringstream result;
381     if (mediametrics::Item::isEnabled()) {
382         result << "Metrics gathering: enabled\n";
383     } else {
384         result << "Metrics gathering: DISABLED via property\n";
385     }
386     result << StringPrintf(
387             "Since Boot: Submissions: %lld Accepted: %lld\n",
388             (long long)mItemsSubmitted.load(), (long long)mItemsFinalized);
389     result << StringPrintf(
390             "Records Discarded: %lld (by Count: %lld by Expiration: %lld)\n",
391             (long long)mItemsDiscarded, (long long)mItemsDiscardedCount,
392             (long long)mItemsDiscardedExpire);
393     if (prefix != nullptr) {
394         result << "Restricting to prefix " << prefix << "\n";
395     }
396     if (sinceNs != 0) {
397         result << "Emitting Queue entries more recent than: " << sinceNs << "\n";
398     }
399     return result.str();
400 }
401 
402 // TODO: should prefix be a set<string>?
dumpQueue(int64_t sinceNs,const char * prefix)403 std::string MediaMetricsService::dumpQueue(int64_t sinceNs, const char* prefix)
404 {
405     if (mItems.empty()) {
406         return "empty\n";
407     }
408     std::stringstream result;
409     int slot = 0;
410     for (const auto &item : mItems) {         // TODO: consider std::lower_bound() on mItems
411         if (item->getTimestamp() < sinceNs) { // sinceNs == 0 means all items shown
412             continue;
413         }
414         if (prefix != nullptr && !startsWith(item->getKey(), prefix)) {
415             ALOGV("%s: omit '%s', it's not '%s'",
416                     __func__, item->getKey().c_str(), prefix);
417             continue;
418         }
419         result << StringPrintf("%5d: %s\n", slot, item->toString().c_str());
420         slot++;
421     }
422     return result.str();
423 }
424 
425 //
426 // Our Cheap in-core, non-persistent records management.
427 
428 // if item != NULL, it's the item we just inserted
429 // true == more items eligible to be recovered
expirations(const std::shared_ptr<const mediametrics::Item> & item)430 bool MediaMetricsService::expirations(const std::shared_ptr<const mediametrics::Item>& item)
431 {
432     bool more = false;
433 
434     // check queue size
435     size_t overlimit = 0;
436     if (mMaxRecords > 0 && mItems.size() > mMaxRecords) {
437         overlimit = mItems.size() - mMaxRecords;
438         if (overlimit > mMaxRecordsExpiredAtOnce) {
439             more = true;
440             overlimit = mMaxRecordsExpiredAtOnce;
441         }
442     }
443 
444     // check queue times
445     size_t expired = 0;
446     if (!more && mMaxRecordAgeNs > 0) {
447         const nsecs_t now = systemTime(SYSTEM_TIME_REALTIME);
448         // we check one at a time, skip search would be more efficient.
449         size_t i = overlimit;
450         for (; i < mItems.size(); ++i) {
451             auto &oitem = mItems[i];
452             nsecs_t when = oitem->getTimestamp();
453             if (oitem.get() == item.get()) {
454                 break;
455             }
456             if (now > when && (now - when) <= mMaxRecordAgeNs) {
457                 break; // Note SYSTEM_TIME_REALTIME may not be monotonic.
458             }
459             if (i >= mMaxRecordsExpiredAtOnce) {
460                 // this represents "one too many"; tell caller there are
461                 // more to be reclaimed.
462                 more = true;
463                 break;
464             }
465         }
466         expired = i - overlimit;
467     }
468 
469     if (const size_t toErase = overlimit + expired;
470             toErase > 0) {
471         mItemsDiscardedCount += (int64_t)overlimit;
472         mItemsDiscardedExpire += (int64_t)expired;
473         mItemsDiscarded += (int64_t)toErase;
474         mItems.erase(mItems.begin(), mItems.begin() + (ptrdiff_t)toErase); // erase from front
475     }
476     return more;
477 }
478 
processExpirations()479 void MediaMetricsService::processExpirations()
480 {
481     bool more;
482     do {
483         sleep(1);
484         std::lock_guard _l(mLock);
485         more = expirations(nullptr);
486     } while (more);
487 }
488 
saveItem(const std::shared_ptr<const mediametrics::Item> & item)489 void MediaMetricsService::saveItem(const std::shared_ptr<const mediametrics::Item>& item)
490 {
491     std::lock_guard _l(mLock);
492     // we assume the items are roughly in time order.
493     mItems.emplace_back(item);
494     if (isPullable(item->getKey())) {
495         registerStatsdCallbacksIfNeeded();
496         mPullableItems[item->getKey()].emplace_back(item);
497     }
498     ++mItemsFinalized;
499     if (expirations(item)
500             && (!mExpireFuture.valid()
501                || mExpireFuture.wait_for(std::chrono::seconds(0)) == std::future_status::ready)) {
502         mExpireFuture = std::async(std::launch::async, [this] { processExpirations(); });
503     }
504 }
505 
506 /* static */
isContentValid(const mediametrics::Item * item,bool isTrusted)507 bool MediaMetricsService::isContentValid(const mediametrics::Item *item, bool isTrusted)
508 {
509     if (isTrusted) return true;
510     // untrusted uids can only send us a limited set of keys
511     const std::string &key = item->getKey();
512     if (startsWith(key, "audio.")) return true;
513     if (startsWith(key, "drm.vendor.")) return true;
514     if (startsWith(key, "mediadrm.")) return true;
515 
516     // the list of allowedKey uses statsd_handlers
517     // in iface_statsd.cpp as reference
518     // drmmanager is from a trusted uid, therefore not needed here
519     for (const char *allowedKey : {
520                                      // legacy audio
521                                      "audiopolicy",
522                                      "audiorecord",
523                                      "audiothread",
524                                      "audiotrack",
525                                      // other media
526                                      "codec",
527                                      "videofreeze",
528                                      "videojudder",
529                                      "extractor",
530                                      "mediadrm",
531                                      "mediaparser",
532                                      "nuplayer",
533                                  }) {
534         if (key == allowedKey) {
535             return true;
536         }
537     }
538     ALOGD("%s: invalid key: %s", __func__, item->toString().c_str());
539     return false;
540 }
541 
542 // are we rate limited, normally false
isRateLimited(mediametrics::Item *) const543 bool MediaMetricsService::isRateLimited(mediametrics::Item *) const
544 {
545     return false;
546 }
547 
registerStatsdCallbacksIfNeeded()548 void MediaMetricsService::registerStatsdCallbacksIfNeeded()
549 {
550     if (mStatsdRegistered.test_and_set()) {
551         return;
552     }
553     auto tag = stats::media_metrics::MEDIA_DRM_ACTIVITY_INFO;
554     auto cb = MediaMetricsService::pullAtomCallback;
555     AStatsManager_setPullAtomCallback(tag, /* metadata */ nullptr, cb, this);
556 }
557 
558 /* static */
isPullable(const std::string & key)559 bool MediaMetricsService::isPullable(const std::string &key)
560 {
561     static const std::set<std::string> pullableKeys{
562         "mediadrm",
563     };
564     return pullableKeys.count(key);
565 }
566 
567 /* static */
atomTagToKey(int32_t atomTag)568 std::string MediaMetricsService::atomTagToKey(int32_t atomTag)
569 {
570     switch (atomTag) {
571     case stats::media_metrics::MEDIA_DRM_ACTIVITY_INFO:
572         return "mediadrm";
573     }
574     return {};
575 }
576 
577 /* static */
pullAtomCallback(int32_t atomTag,AStatsEventList * data,void * cookie)578 AStatsManager_PullAtomCallbackReturn MediaMetricsService::pullAtomCallback(
579         int32_t atomTag, AStatsEventList* data, void* cookie)
580 {
581     MediaMetricsService* svc = reinterpret_cast<MediaMetricsService*>(cookie);
582     return svc->pullItems(atomTag, data);
583 }
584 
pullItems(int32_t atomTag,AStatsEventList * data)585 AStatsManager_PullAtomCallbackReturn MediaMetricsService::pullItems(
586         int32_t atomTag, AStatsEventList* data)
587 {
588     const std::string key(atomTagToKey(atomTag));
589     if (key.empty()) {
590         return AStatsManager_PULL_SKIP;
591     }
592     std::lock_guard _l(mLock);
593     bool dumped = false;
594     for (auto &item : mPullableItems[key]) {
595         if (const auto sitem = item.lock()) {
596             dumped |= dump2Statsd(sitem, data, mStatsdLog);
597         }
598     }
599     mPullableItems[key].clear();
600     return dumped ? AStatsManager_PULL_SUCCESS : AStatsManager_PULL_SKIP;
601 }
602 } // namespace android
603