Transcoding: Log transcoder level metrics.
- Add transcoder-level metric logging through west world,
to monitor performance and failures.
- Add new unit tests for TranscodingLogger class.
Bug: 179274112
Test: New and existing unit tests.
Change-Id: Ie8d9bc589c714a7b8be8f4f298c4fa75a81a6e56
diff --git a/media/libmediatranscoding/TranscodingLogger.cpp b/media/libmediatranscoding/TranscodingLogger.cpp
new file mode 100644
index 0000000..29a52b0
--- /dev/null
+++ b/media/libmediatranscoding/TranscodingLogger.cpp
@@ -0,0 +1,194 @@
+/*
+ * Copyright (C) 2021 The Android Open Source Project
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ * http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+// #define LOG_NDEBUG 0
+#define LOG_TAG "TranscodingLogger"
+
+#include <media/NdkCommon.h>
+#include <media/TranscodingLogger.h>
+#include <statslog_media.h>
+#include <utils/Log.h>
+
+#include <cmath>
+#include <string>
+
+namespace android {
+
+static_assert(TranscodingLogger::UNKNOWN ==
+ android::media::stats::MEDIA_TRANSCODING_SESSION_ENDED__REASON__UNKNOWN,
+ "Session event mismatch");
+static_assert(TranscodingLogger::FINISHED ==
+ android::media::stats::MEDIA_TRANSCODING_SESSION_ENDED__REASON__FINISHED,
+ "Session event mismatch");
+static_assert(TranscodingLogger::ERROR ==
+ android::media::stats::MEDIA_TRANSCODING_SESSION_ENDED__REASON__ERROR,
+ "Session event mismatch");
+static_assert(TranscodingLogger::PAUSED ==
+ android::media::stats::MEDIA_TRANSCODING_SESSION_ENDED__REASON__PAUSED,
+ "Session event mismatch");
+static_assert(TranscodingLogger::CANCELLED ==
+ android::media::stats::MEDIA_TRANSCODING_SESSION_ENDED__REASON__CANCELLED,
+ "Session event mismatch");
+static_assert(TranscodingLogger::START_FAILED ==
+ android::media::stats::MEDIA_TRANSCODING_SESSION_ENDED__REASON__START_FAILED,
+ "Session event mismatch");
+static_assert(TranscodingLogger::RESUME_FAILED ==
+ android::media::stats::MEDIA_TRANSCODING_SESSION_ENDED__REASON__RESUME_FAILED,
+ "Session event mismatch");
+static_assert(TranscodingLogger::CREATE_FAILED ==
+ android::media::stats::MEDIA_TRANSCODING_SESSION_ENDED__REASON__CREATE_FAILED,
+ "Session event mismatch");
+static_assert(
+ TranscodingLogger::CONFIG_SRC_FAILED ==
+ android::media::stats::MEDIA_TRANSCODING_SESSION_ENDED__REASON__CONFIG_SRC_FAILED,
+ "Session event mismatch");
+static_assert(
+ TranscodingLogger::CONFIG_DST_FAILED ==
+ android::media::stats::MEDIA_TRANSCODING_SESSION_ENDED__REASON__CONFIG_DST_FAILED,
+ "Session event mismatch");
+static_assert(
+ TranscodingLogger::CONFIG_TRACK_FAILED ==
+ android::media::stats::MEDIA_TRANSCODING_SESSION_ENDED__REASON__CONFIG_TRACK_FAILED,
+ "Session event mismatch");
+static_assert(
+ TranscodingLogger::OPEN_SRC_FD_FAILED ==
+ android::media::stats::MEDIA_TRANSCODING_SESSION_ENDED__REASON__OPEN_SRC_FD_FAILED,
+ "Session event mismatch");
+static_assert(
+ TranscodingLogger::OPEN_DST_FD_FAILED ==
+ android::media::stats::MEDIA_TRANSCODING_SESSION_ENDED__REASON__OPEN_DST_FD_FAILED,
+ "Session event mismatch");
+static_assert(TranscodingLogger::NO_TRACKS ==
+ android::media::stats::MEDIA_TRANSCODING_SESSION_ENDED__REASON__NO_TRACKS,
+ "Session event mismatch");
+
+static inline int32_t getInt32(AMediaFormat* fmt, const char* key, int32_t defaultValue = -1) {
+ int32_t value;
+ if (fmt == nullptr || !AMediaFormat_getInt32(fmt, key, &value)) {
+ ALOGW("Unable to get %s", key);
+ value = defaultValue;
+ }
+ return value;
+}
+
+// Note: returned string is owned by format and only valid until the next getString.
+static inline const char* getString(AMediaFormat* fmt, const char* key,
+ const char* defaultValue = "(null)") {
+ const char* value;
+ if (fmt == nullptr || !AMediaFormat_getString(fmt, key, &value)) {
+ ALOGW("Unable to get %s", key);
+ value = defaultValue;
+ }
+ return value;
+}
+
+TranscodingLogger::TranscodingLogger()
+ : mSessionEndedAtomWriter(&android::media::stats::stats_write) {}
+
+void TranscodingLogger::logSessionEnded(enum SessionEndedReason reason, uid_t callingUid,
+ int status, std::chrono::microseconds duration,
+ AMediaFormat* srcFormat, AMediaFormat* dstFormat) {
+ logSessionEnded(std::chrono::steady_clock::now(), reason, callingUid, status, duration,
+ srcFormat, dstFormat);
+}
+
+void TranscodingLogger::logSessionEnded(const std::chrono::steady_clock::time_point& now,
+ enum SessionEndedReason reason, uid_t callingUid,
+ int status, std::chrono::microseconds duration,
+ AMediaFormat* srcFormat, AMediaFormat* dstFormat) {
+ if (srcFormat == nullptr) {
+ ALOGE("Source format is null. Dropping event.");
+ return;
+ }
+
+ if (!shouldLogAtom(now, status)) {
+ ALOGD("Maximum logged event count reached. Dropping event.");
+ return;
+ }
+
+ // Extract the pieces of information to log.
+ const int32_t srcWidth = getInt32(srcFormat, AMEDIAFORMAT_KEY_WIDTH);
+ const int32_t srcHeight = getInt32(srcFormat, AMEDIAFORMAT_KEY_HEIGHT);
+ const char* srcMime = getString(srcFormat, AMEDIAFORMAT_KEY_MIME);
+ const int32_t srcProfile = getInt32(srcFormat, AMEDIAFORMAT_KEY_PROFILE);
+ const int32_t srcLevel = getInt32(srcFormat, AMEDIAFORMAT_KEY_LEVEL);
+ const int32_t srcFrameRate = getInt32(srcFormat, AMEDIAFORMAT_KEY_FRAME_RATE);
+ const int32_t srcFrameCount = getInt32(srcFormat, AMEDIAFORMAT_KEY_FRAME_COUNT);
+ const bool srcIsHdr = AMediaFormatUtils::VideoIsHdr(srcFormat);
+
+ int32_t dstWidth = getInt32(dstFormat, AMEDIAFORMAT_KEY_WIDTH, srcWidth);
+ int32_t dstHeight = getInt32(dstFormat, AMEDIAFORMAT_KEY_HEIGHT, srcHeight);
+ const char* dstMime = dstFormat == nullptr
+ ? "passthrough"
+ : getString(dstFormat, AMEDIAFORMAT_KEY_MIME, srcMime);
+ const bool dstIsHdr = false; // Transcoder always request SDR output.
+
+ int64_t tmpDurationUs;
+ const int32_t srcDurationMs =
+ AMediaFormat_getInt64(srcFormat, AMEDIAFORMAT_KEY_DURATION, &tmpDurationUs)
+ ? static_cast<int32_t>(tmpDurationUs / 1000)
+ : -1;
+
+ int32_t transcodeFrameRate = -1;
+ if (status == 0 && srcFrameCount > 0 && duration.count() > 0) {
+ std::chrono::duration<double> seconds{duration};
+ transcodeFrameRate = static_cast<int32_t>(
+ std::round(static_cast<double>(srcFrameCount) / seconds.count()));
+ }
+
+ // Write the atom.
+ mSessionEndedAtomWriter(android::media::stats::MEDIA_TRANSCODING_SESSION_ENDED,
+ static_cast<int>(reason), callingUid, status, transcodeFrameRate,
+ srcWidth, srcHeight, srcMime, srcProfile, srcLevel, srcFrameRate,
+ srcDurationMs, srcIsHdr, dstWidth, dstHeight, dstMime, dstIsHdr);
+}
+
+bool TranscodingLogger::shouldLogAtom(const std::chrono::steady_clock::time_point& now,
+ int status) {
+ std::scoped_lock lock{mLock};
+ static const std::chrono::hours oneDay(24);
+
+ // Remove events older than one day.
+ while (mLastLoggedAtoms.size() > 0 && (now - mLastLoggedAtoms.front().first) >= oneDay) {
+ if (mLastLoggedAtoms.front().second == AMEDIA_OK) {
+ --mSuccessfulCount;
+ }
+ mLastLoggedAtoms.pop();
+ }
+
+ // Don't log if maximum number of events is reached.
+ if (mLastLoggedAtoms.size() >= kMaxAtomsPerDay) {
+ return false;
+ }
+
+ // Don't log if the event is successful and the maximum number of successful events is reached.
+ if (status == AMEDIA_OK && mSuccessfulCount >= kMaxSuccessfulAtomsPerDay) {
+ return false;
+ }
+
+ // Record the event.
+ if (status == AMEDIA_OK) {
+ ++mSuccessfulCount;
+ }
+ mLastLoggedAtoms.emplace(now, status);
+ return true;
+}
+
+void TranscodingLogger::setSessionEndedAtomWriter(const SessionEndedAtomWriter& writer) {
+ mSessionEndedAtomWriter = writer;
+}
+
+} // namespace android