From 709b91e1e8a646f17117fc5e9baa224182cbec64 Mon Sep 17 00:00:00 2001 From: Andy Hung Date: Sat, 4 Apr 2020 14:23:36 -0700 Subject: [PATCH] MediaMetrics: Update dumpsys parameters Make --prefix and --since work for analytics. Test: adb shell dumpsys media.metrics --all Test: adb shell dumpsys media.metrics --clear Test: adb shell dumpsys media.metrics --heap Test: adb shell dumpsys media.metrics --help Test: adb shell dumpsys media.metrics --prefix c Test: adb shell dumpsys media.metrics --prefix audio.volume Test: adb shell dumpsys media.metrics --since -100 Test: adb shell dumpsys media.metrics --unreachable Bug: 149850236 Change-Id: Id3e0cb6fe789027b5d5c86cce93ce07f636736bf --- .../include/media/MediaMetricsItem.h | 4 +- services/mediametrics/AnalyticsState.h | 13 +- services/mediametrics/AudioAnalytics.cpp | 11 +- services/mediametrics/AudioAnalytics.h | 11 +- services/mediametrics/MediaMetricsService.cpp | 177 ++++++++---------- services/mediametrics/MediaMetricsService.h | 7 +- services/mediametrics/TimeMachine.h | 35 ++-- services/mediametrics/TransactionLog.h | 48 +++-- 8 files changed, 159 insertions(+), 147 deletions(-) diff --git a/media/libmediametrics/include/media/MediaMetricsItem.h b/media/libmediametrics/include/media/MediaMetricsItem.h index 08720f157c..591e714ea0 100644 --- a/media/libmediametrics/include/media/MediaMetricsItem.h +++ b/media/libmediametrics/include/media/MediaMetricsItem.h @@ -208,11 +208,11 @@ static inline constexpr const char *BUNDLE_PROPERTY_COUNT = "_propertyCount"; template static inline bool startsWith(const std::string &s, const char (&comp)[N]) { - return !strncmp(s.c_str(), comp, N - 1); + return !strncmp(s.c_str(), comp, N - 1); // last char is null termination } static inline bool startsWith(const std::string& s, const std::string& comp) { - return !strncmp(s.c_str(), comp.c_str(), comp.size() - 1); + return !strncmp(s.c_str(), comp.c_str(), comp.size()); } /** diff --git a/services/mediametrics/AnalyticsState.h b/services/mediametrics/AnalyticsState.h index 290ed21306..e8fedcfeb3 100644 --- a/services/mediametrics/AnalyticsState.h +++ b/services/mediametrics/AnalyticsState.h @@ -84,8 +84,11 @@ public: * delivered. * * \param lines the maximum number of lines in the string returned. + * \param sinceNs the nanoseconds since Unix epoch to start dump (0 shows all) + * \param prefix the desired key prefix to match (nullptr shows all) */ - std::pair dump(int32_t lines = INT32_MAX) const { + std::pair dump( + int32_t lines = INT32_MAX, int64_t sinceNs = 0, const char *prefix = nullptr) const { std::stringstream ss; int32_t ll = lines; @@ -94,8 +97,8 @@ public: --ll; } if (ll > 0) { - auto [s, l] = mTransactionLog.dump(ll); - ss << s; + auto [s, l] = mTransactionLog.dump(ll, sinceNs, prefix); + ss << std::move(s); ll -= l; } if (ll > 0) { @@ -103,8 +106,8 @@ public: --ll; } if (ll > 0) { - auto [s, l] = mTimeMachine.dump(ll); - ss << s; + auto [s, l] = mTimeMachine.dump(ll, sinceNs, prefix); + ss << std::move(s); ll -= l; } return { ss.str(), lines - ll }; diff --git a/services/mediametrics/AudioAnalytics.cpp b/services/mediametrics/AudioAnalytics.cpp index 126e501238..f80516e9c0 100644 --- a/services/mediametrics/AudioAnalytics.cpp +++ b/services/mediametrics/AudioAnalytics.cpp @@ -107,14 +107,15 @@ status_t AudioAnalytics::submit( return NO_ERROR; } -std::pair AudioAnalytics::dump(int32_t lines) const +std::pair AudioAnalytics::dump( + int32_t lines, int64_t sinceNs, const char *prefix) const { std::stringstream ss; int32_t ll = lines; if (ll > 0) { - auto [s, l] = mAnalyticsState->dump(ll); - ss << s; + auto [s, l] = mAnalyticsState->dump(ll, sinceNs, prefix); + ss << std::move(s); ll -= l; } if (ll > 0) { @@ -122,8 +123,8 @@ std::pair AudioAnalytics::dump(int32_t lines) const --ll; } if (ll > 0) { - auto [s, l] = mPreviousAnalyticsState->dump(ll); - ss << s; + auto [s, l] = mPreviousAnalyticsState->dump(ll, sinceNs, prefix); + ss << std::move(s); ll -= l; } return { ss.str(), lines - ll }; diff --git a/services/mediametrics/AudioAnalytics.h b/services/mediametrics/AudioAnalytics.h index 4a42e22566..ba4c3f23f9 100644 --- a/services/mediametrics/AudioAnalytics.h +++ b/services/mediametrics/AudioAnalytics.h @@ -60,8 +60,17 @@ public: * delivered. * * \param lines the maximum number of lines in the string returned. + * \param sinceNs the nanoseconds since Unix epoch to start dump (0 shows all) + * \param prefix the desired key prefix to match (nullptr shows all) */ - std::pair dump(int32_t lines = INT32_MAX) const; + std::pair dump( + int32_t lines = INT32_MAX, int64_t sinceNs = 0, const char *prefix = nullptr) const; + + void clear() { + // underlying state is locked. + mPreviousAnalyticsState->clear(); + mAnalyticsState->clear(); + } private: diff --git a/services/mediametrics/MediaMetricsService.cpp b/services/mediametrics/MediaMetricsService.cpp index d76bc2c0ee..b9703ba6e7 100644 --- a/services/mediametrics/MediaMetricsService.cpp +++ b/services/mediametrics/MediaMetricsService.cpp @@ -207,69 +207,66 @@ status_t MediaMetricsService::dump(int fd, const Vector& args) return NO_ERROR; } + static const String16 allOption("--all"); + static const String16 clearOption("--clear"); static const String16 heapOption("--heap"); + static const String16 helpOption("--help"); + static const String16 prefixOption("--prefix"); + static const String16 sinceOption("--since"); static const String16 unreachableOption("--unreachable"); - bool heap = false; - bool unreachable = false; - const String16 protoOption("--proto"); - const String16 clearOption("--clear"); + bool all = false; bool clear = false; - const String16 sinceOption("--since"); - nsecs_t ts_since = 0; - const String16 helpOption("--help"); - const String16 onlyOption("--only"); - std::string only; - const int n = args.size(); - for (int i = 0; i < n; i++) { - if (args[i] == clearOption) { + bool heap = false; + bool unreachable = false; + int64_t sinceNs = 0; + std::string prefix; + + const size_t n = args.size(); + for (size_t i = 0; i < n; i++) { + if (args[i] == allOption) { + all = true; + } else if (args[i] == clearOption) { clear = true; } else if (args[i] == heapOption) { heap = true; - } else if (args[i] == protoOption) { - i++; + } else if (args[i] == helpOption) { + // TODO: consider function area dumping. + // dumpsys media.metrics audiotrack,codec + // or dumpsys media.metrics audiotrack codec + + result.append("Recognized parameters:\n"); + result.append("--all show all records\n"); + result.append("--clear clear out saved records\n"); + result.append("--heap show heap usage (top 100)\n"); + result.append("--help display help\n"); + result.append("--prefix X process records for component X\n"); + result.append("--since X X < 0: records from -X seconds in the past\n"); + result.append(" X = 0: ignore\n"); + result.append(" X > 0: records from X seconds since Unix epoch\n"); + result.append("--unreachable show unreachable memory (leaks)\n"); + write(fd, result.string(), result.size()); + return NO_ERROR; + } else if (args[i] == prefixOption) { + ++i; if (i < n) { - // ignore - } else { - result.append("missing value for -proto\n\n"); + prefix = String8(args[i]).string(); } } else if (args[i] == sinceOption) { - i++; + ++i; if (i < n) { String8 value(args[i]); char *endp; const char *p = value.string(); - ts_since = strtoll(p, &endp, 10); - if (endp == p || *endp != '\0') { - ts_since = 0; + long long sec = strtoll(p, &endp, 10); + if (endp == p || *endp != '\0' || sec == 0) { + sinceNs = 0; + } else if (sec < 0) { + sinceNs = systemTime(SYSTEM_TIME_REALTIME) + sec * NANOS_PER_SECOND; + } else { + sinceNs = sec * NANOS_PER_SECOND; } - } else { - ts_since = 0; } - // command line is milliseconds; internal units are nano-seconds - ts_since *= NANOS_PER_MILLISECOND; - } else if (args[i] == onlyOption) { - i++; - if (i < n) { - String8 value(args[i]); - only = value.string(); - } - } else if (args[i] == helpOption) { - // TODO: consider function area dumping. - // dumpsys media.metrics audiotrack,codec - // or dumpsys media.metrics audiotrack codec - - result.append("Recognized parameters:\n"); - result.append("--heap heap usage (top 100)\n"); - result.append("--help this help message\n"); - result.append("--proto # dump using protocol #"); - result.append("--clear clears out saved records\n"); - result.append("--only X process records for component X\n"); - result.append("--since X include records since X\n"); - result.append(" (X is milliseconds since the UNIX epoch)\n"); - result.append("--unreachable unreachable memory (leaks)\n"); - write(fd, result.string(), result.size()); - return NO_ERROR; } else if (args[i] == unreachableOption) { unreachable = true; } @@ -278,21 +275,23 @@ status_t MediaMetricsService::dump(int fd, const Vector& args) { std::lock_guard _l(mLock); - result.appendFormat("Dump of the %s process:\n", kServiceName); - dumpHeaders_l(result, ts_since); - dumpRecent_l(result, ts_since, only.c_str()); - if (clear) { mItemsDiscarded += mItems.size(); mItems.clear(); - // shall we clear the summary data too? - } - // TODO: maybe consider a better way of dumping audio analytics info. - constexpr int32_t linesToDump = 1000; - auto [ dumpString, lines ] = mAudioAnalytics.dump(linesToDump); - result.append(dumpString.c_str()); - if (lines == linesToDump) { - result.append("-- some lines may be truncated --\n"); + mAudioAnalytics.clear(); + } else { + result.appendFormat("Dump of the %s process:\n", kServiceName); + const char *prefixptr = prefix.size() > 0 ? prefix.c_str() : nullptr; + dumpHeaders_l(result, sinceNs, prefixptr); + dumpQueue_l(result, sinceNs, prefixptr); + + // TODO: maybe consider a better way of dumping audio analytics info. + const int32_t linesToDump = all ? INT32_MAX : 1000; + auto [ dumpString, lines ] = mAudioAnalytics.dump(linesToDump, sinceNs, prefixptr); + result.append(dumpString.c_str()); + if (lines == linesToDump) { + result.append("-- some lines may be truncated --\n"); + } } } write(fd, result.string(), result.size()); @@ -313,7 +312,7 @@ status_t MediaMetricsService::dump(int fd, const Vector& args) } // dump headers -void MediaMetricsService::dumpHeaders_l(String8 &result, nsecs_t ts_since) +void MediaMetricsService::dumpHeaders_l(String8 &result, int64_t sinceNs, const char* prefix) { if (mediametrics::Item::isEnabled()) { result.append("Metrics gathering: enabled\n"); @@ -327,54 +326,36 @@ void MediaMetricsService::dumpHeaders_l(String8 &result, nsecs_t ts_since) "Records Discarded: %lld (by Count: %lld by Expiration: %lld)\n", (long long)mItemsDiscarded, (long long)mItemsDiscardedCount, (long long)mItemsDiscardedExpire); - if (ts_since != 0) { + if (prefix != nullptr) { + result.appendFormat("Restricting to prefix %s", prefix); + } + if (sinceNs != 0) { result.appendFormat( "Emitting Queue entries more recent than: %lld\n", - (long long)ts_since); + (long long)sinceNs); } } -void MediaMetricsService::dumpRecent_l( - String8 &result, nsecs_t ts_since, const char * only) +// TODO: should prefix be a set? +void MediaMetricsService::dumpQueue_l(String8 &result, int64_t sinceNs, const char* prefix) { - if (only != nullptr && *only == '\0') { - only = nullptr; + if (mItems.empty()) { + result.append("empty\n"); + return; } - result.append("\nFinalized Metrics (oldest first):\n"); - dumpQueue_l(result, ts_since, only); - - // show who is connected and injecting records? - // talk about # records fed to the 'readers' - // talk about # records we discarded, perhaps "discarded w/o reading" too -} - -void MediaMetricsService::dumpQueue_l(String8 &result) { - dumpQueue_l(result, (nsecs_t) 0, nullptr /* only */); -} -void MediaMetricsService::dumpQueue_l( - String8 &result, nsecs_t ts_since, const char * only) { int slot = 0; - - if (mItems.empty()) { - result.append("empty\n"); - } else { - for (const auto &item : mItems) { - nsecs_t when = item->getTimestamp(); - if (when < ts_since) { - continue; - } - // TODO: Only should be a set - if (only != nullptr && - item->getKey() /* std::string */ != only) { - ALOGV("%s: omit '%s', it's not '%s'", - __func__, item->getKey().c_str(), only); - continue; - } - result.appendFormat("%5d: %s\n", - slot, item->toString().c_str()); - slot++; + for (const auto &item : mItems) { // TODO: consider std::lower_bound() on mItems + if (item->getTimestamp() < sinceNs) { // sinceNs == 0 means all items shown + continue; + } + if (prefix != nullptr && !startsWith(item->getKey(), prefix)) { + ALOGV("%s: omit '%s', it's not '%s'", + __func__, item->getKey().c_str(), prefix); + continue; } + result.appendFormat("%5d: %s\n", slot, item->toString().c_str()); + slot++; } } diff --git a/services/mediametrics/MediaMetricsService.h b/services/mediametrics/MediaMetricsService.h index 935bee2ddd..a93f7fbbcf 100644 --- a/services/mediametrics/MediaMetricsService.h +++ b/services/mediametrics/MediaMetricsService.h @@ -85,11 +85,8 @@ private: bool expirations_l(const std::shared_ptr& item); // support for generating output - void dumpQueue_l(String8 &result); - void dumpQueue_l(String8 &result, nsecs_t, const char *only); - void dumpHeaders_l(String8 &result, nsecs_t ts_since); - void dumpSummaries_l(String8 &result, nsecs_t ts_since, const char * only); - void dumpRecent_l(String8 &result, nsecs_t ts_since, const char * only); + void dumpQueue_l(String8 &result, int64_t sinceNs, const char* prefix); + void dumpHeaders_l(String8 &result, int64_t sinceNs, const char* prefix); // The following variables accessed without mLock diff --git a/services/mediametrics/TimeMachine.h b/services/mediametrics/TimeMachine.h index a4c36936ec..75819ba478 100644 --- a/services/mediametrics/TimeMachine.h +++ b/services/mediametrics/TimeMachine.h @@ -149,8 +149,11 @@ private: int32_t ll = lines; for (auto& tsPair : mPropertyMap) { if (ll <= 0) break; - ss << dump(mKey, tsPair, time); - --ll; + std::string s = dump(mKey, tsPair, time); + if (s.size() > 0) { + --ll; + ss << std::move(s); + } } return { ss.str(), lines - ll }; } @@ -165,7 +168,7 @@ private: const auto timeSequence = tsPair.second; auto eptr = timeSequence.lower_bound(time); if (eptr == timeSequence.end()) { - return tsPair.first + "={};\n"; + return {}; // don't dump anything. tsPair.first + "={};\n"; } std::stringstream ss; ss << key << "." << tsPair.first << "={"; @@ -407,25 +410,23 @@ public: * * \param lines the maximum number of lines in the string returned. * \param key selects only that key. - * \param time to start the dump from. + * \param sinceNs the nanoseconds since Unix epoch to start dump (0 shows all) + * \param prefix the desired key prefix to match (nullptr shows all) */ std::pair dump( - int32_t lines = INT32_MAX, const std::string &key = {}, int64_t time = 0) const { + int32_t lines = INT32_MAX, int64_t sinceNs = 0, const char *prefix = nullptr) const { std::lock_guard lock(mLock); - if (!key.empty()) { // use std::regex - const auto it = mHistory.find(key); - if (it == mHistory.end()) return {}; - std::lock_guard lock(getLockForKey(it->first)); - return it->second->dump(lines, time); - } - std::stringstream ss; int32_t ll = lines; - for (const auto &[lkey, lhist] : mHistory) { - std::lock_guard lock(getLockForKey(lkey)); - if (lines <= 0) break; - auto [s, l] = lhist->dump(ll, time); - ss << s; + + for (auto it = prefix != nullptr ? mHistory.lower_bound(prefix) : mHistory.begin(); + it != mHistory.end(); + ++it) { + if (ll <= 0) break; + if (prefix != nullptr && !startsWith(it->first, prefix)) break; + std::lock_guard lock(getLockForKey(it->first)); + auto [s, l] = it->second->dump(ll, sinceNs); + ss << std::move(s); ll -= l; } return { ss.str(), lines - ll }; diff --git a/services/mediametrics/TransactionLog.h b/services/mediametrics/TransactionLog.h index 190a99eec0..2359eec220 100644 --- a/services/mediametrics/TransactionLog.h +++ b/services/mediametrics/TransactionLog.h @@ -127,8 +127,11 @@ public: * for subsequent line limiting. * * \param lines the maximum number of lines in the string returned. + * \param sinceNs the nanoseconds since Unix epoch to start dump (0 shows all) + * \param prefix the desired key prefix to match (nullptr shows all) */ - std::pair dump(int32_t lines) const { + std::pair dump( + int32_t lines, int64_t sinceNs, const char *prefix = nullptr) const { std::stringstream ss; int32_t ll = lines; std::lock_guard lock(mLock); @@ -138,26 +141,25 @@ public: ss << "Consolidated:\n"; --ll; } - for (const auto &log : mLog) { - if (ll <= 0) break; - ss << " " << log.second->toString() << "\n"; - --ll; - } + auto [s, l] = dumpMapTimeItem(mLog, ll, sinceNs, prefix); + ss << std::move(s); + ll -= l; // Grouped by item key (category) if (ll > 0) { ss << "Categorized:\n"; --ll; } - for (const auto &itemMap : mItemMap) { + + for (auto it = prefix != nullptr ? mItemMap.lower_bound(prefix) : mItemMap.begin(); + it != mItemMap.end(); + ++it) { if (ll <= 0) break; - ss << " " << itemMap.first << "\n"; - --ll; - for (const auto &item : itemMap.second) { - if (ll <= 0) break; - ss << " " << item.second->toString() << "\n"; - --ll; - } + if (prefix != nullptr && !startsWith(it->first, prefix)) break; + auto [s, l] = dumpMapTimeItem(it->second, ll - 1, sinceNs, prefix); + if (l == 0) continue; // don't show empty groups (due to sinceNs). + ss << " " << it->first << "\n" << std::move(s); + ll -= l + 1; } return { ss.str(), lines - ll }; } @@ -184,6 +186,24 @@ private: using MapTimeItem = std::multimap>; + static std::pair dumpMapTimeItem( + const MapTimeItem& mapTimeItem, + int32_t lines, int64_t sinceNs = 0, const char *prefix = nullptr) { + std::stringstream ss; + int32_t ll = lines; + // Note: for our data, mapTimeItem.lower_bound(0) == mapTimeItem.begin(). + for (auto it = mapTimeItem.lower_bound(sinceNs); + it != mapTimeItem.end(); ++it) { + if (ll <= 0) break; + if (prefix != nullptr && !startsWith(it->second->getKey(), prefix)) { + continue; + } + ss << " " << it->second->toString() << "\n"; + --ll; + } + return { ss.str(), lines - ll }; + } + // GUARDED_BY mLock /** * Garbage collects if the TimeMachine size exceeds the high water mark.