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