1 /*
2 * Copyright (C) 2021 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 // Unit Test for TranscodingLogger
18
19 // #define LOG_NDEBUG 0
20 #define LOG_TAG "TranscodingLoggerTest"
21
22 #include <android-base/logging.h>
23 #include <gtest/gtest.h>
24 #include <media/NdkCommon.h>
25 #include <media/TranscodingLogger.h>
26 #include <statslog_media.h>
27 #include <utils/Log.h>
28
29 #include <chrono>
30
31 namespace android {
32
33 using Reason = TranscodingLogger::SessionEndedReason;
34
35 // Data structure corresponding to MediaTranscodingEnded atom.
36 struct SessionEndedAtom {
SessionEndedAtomandroid::SessionEndedAtom37 SessionEndedAtom(int32_t atomCode, int32_t reason, int32_t callingUid, int32_t status,
38 int32_t transcoderFps, int32_t srcWidth, int32_t srcHeight,
39 char const* srcMime, int32_t srcProfile, int32_t srcLevel, int32_t srcFps,
40 int32_t srcDurationMs, bool srcIsHdr, int32_t dstWidth, int32_t dstHeight,
41 char const* dstMime, bool dstIsHdr)
42 : atomCode(atomCode),
43 reason(reason),
44 callingUid(callingUid),
45 status(status),
46 transcoderFps(transcoderFps),
47 srcWidth(srcWidth),
48 srcHeight(srcHeight),
49 srcMime(srcMime),
50 srcProfile(srcProfile),
51 srcLevel(srcLevel),
52 srcFps(srcFps),
53 srcDurationMs(srcDurationMs),
54 srcIsHdr(srcIsHdr),
55 dstWidth(dstWidth),
56 dstHeight(dstHeight),
57 dstMime(dstMime),
58 dstIsHdr(dstIsHdr) {}
59
60 int32_t atomCode;
61 int32_t reason;
62 int32_t callingUid;
63 int32_t status;
64 int32_t transcoderFps;
65 int32_t srcWidth;
66 int32_t srcHeight;
67 std::string srcMime;
68 int32_t srcProfile;
69 int32_t srcLevel;
70 int32_t srcFps;
71 int32_t srcDurationMs;
72 bool srcIsHdr;
73 int32_t dstWidth;
74 int32_t dstHeight;
75 std::string dstMime;
76 bool dstIsHdr;
77 };
78
79 // Default configuration values.
80 static constexpr int32_t kDefaultCallingUid = 1;
81 static constexpr std::chrono::microseconds kDefaultTranscodeDuration = std::chrono::seconds{2};
82
83 static constexpr int32_t kDefaultSrcWidth = 1920;
84 static constexpr int32_t kDefaultSrcHeight = 1080;
85 static const std::string kDefaultSrcMime{AMEDIA_MIMETYPE_VIDEO_HEVC};
86 static constexpr int32_t kDefaultSrcProfile = 1; // HEVC Main
87 static constexpr int32_t kDefaultSrcLevel = 65536; // HEVCMainTierLevel51
88 static constexpr int32_t kDefaultSrcFps = 30;
89 static constexpr int32_t kDefaultSrcFrameCount = 120;
90 static constexpr int64_t kDefaultSrcDurationUs = 1000000 * kDefaultSrcFrameCount / kDefaultSrcFps;
91
92 static constexpr int32_t kDefaultDstWidth = 1280;
93 static constexpr int32_t kDefaultDstHeight = 720;
94 static const std::string kDefaultDstMime{AMEDIA_MIMETYPE_VIDEO_AVC};
95
96 // Util for creating a default source video format.
CreateSrcFormat()97 static AMediaFormat* CreateSrcFormat() {
98 AMediaFormat* fmt = AMediaFormat_new();
99 AMediaFormat_setInt32(fmt, AMEDIAFORMAT_KEY_WIDTH, kDefaultSrcWidth);
100 AMediaFormat_setInt32(fmt, AMEDIAFORMAT_KEY_HEIGHT, kDefaultSrcHeight);
101 AMediaFormat_setString(fmt, AMEDIAFORMAT_KEY_MIME, kDefaultSrcMime.c_str());
102 AMediaFormat_setInt32(fmt, AMEDIAFORMAT_KEY_PROFILE, kDefaultSrcProfile);
103 AMediaFormat_setInt32(fmt, AMEDIAFORMAT_KEY_LEVEL, kDefaultSrcLevel);
104 AMediaFormat_setInt32(fmt, AMEDIAFORMAT_KEY_FRAME_RATE, kDefaultSrcFps);
105 AMediaFormat_setInt32(fmt, AMEDIAFORMAT_KEY_FRAME_COUNT, kDefaultSrcFrameCount);
106 AMediaFormat_setInt64(fmt, AMEDIAFORMAT_KEY_DURATION, kDefaultSrcDurationUs);
107 return fmt;
108 }
109
110 // Util for creating a default destination video format.
CreateDstFormat()111 static AMediaFormat* CreateDstFormat() {
112 AMediaFormat* fmt = AMediaFormat_new();
113 AMediaFormat_setInt32(fmt, AMEDIAFORMAT_KEY_WIDTH, kDefaultDstWidth);
114 AMediaFormat_setInt32(fmt, AMEDIAFORMAT_KEY_HEIGHT, kDefaultDstHeight);
115 AMediaFormat_setString(fmt, AMEDIAFORMAT_KEY_MIME, kDefaultDstMime.c_str());
116 return fmt;
117 }
118
119 class TranscodingLoggerTest : public ::testing::Test {
120 public:
TranscodingLoggerTest()121 TranscodingLoggerTest() { ALOGI("TranscodingLoggerTest created"); }
122
SetUp()123 void SetUp() override {
124 ALOGI("TranscodingLoggerTest set up");
125 mLogger.reset(new TranscodingLogger());
126 mLoggedAtoms.clear();
127 mSrcFormat.reset();
128 mDstFormat.reset();
129
130 // Set a custom atom writer that saves all data, so the test can validate it afterwards.
131 mLogger->setSessionEndedAtomWriter(
132 [=](int32_t atomCode, int32_t reason, int32_t callingUid, int32_t status,
133 int32_t transcoderFps, int32_t srcWidth, int32_t srcHeight, char const* srcMime,
134 int32_t srcProfile, int32_t srcLevel, int32_t srcFps, int32_t srcDurationMs,
135 bool srcIsHdr, int32_t dstWidth, int32_t dstHeight, char const* dstMime,
136 bool dstIsHdr) -> int {
137 mLoggedAtoms.emplace_back(atomCode, reason, callingUid, status, transcoderFps,
138 srcWidth, srcHeight, srcMime, srcProfile, srcLevel,
139 srcFps, srcDurationMs, srcIsHdr, dstWidth, dstHeight,
140 dstMime, dstIsHdr);
141 return 0;
142 });
143 }
144
logSession(const std::chrono::steady_clock::time_point & time,Reason reason,int status,AMediaFormat * srcFormat,AMediaFormat * dstFormat)145 void logSession(const std::chrono::steady_clock::time_point& time, Reason reason, int status,
146 AMediaFormat* srcFormat, AMediaFormat* dstFormat) {
147 mLogger->logSessionEnded(time, reason, kDefaultCallingUid, status,
148 kDefaultTranscodeDuration, srcFormat, dstFormat);
149 }
150
logSession(const std::chrono::steady_clock::time_point & time,Reason reason,int status)151 void logSession(const std::chrono::steady_clock::time_point& time, Reason reason, int status) {
152 if (!mSrcFormat) {
153 mSrcFormat = std::shared_ptr<AMediaFormat>(CreateSrcFormat(), &AMediaFormat_delete);
154 }
155 if (!mDstFormat) {
156 mDstFormat = std::shared_ptr<AMediaFormat>(CreateDstFormat(), &AMediaFormat_delete);
157 }
158 logSession(time, reason, status, mSrcFormat.get(), mDstFormat.get());
159 }
160
logSessionFinished(const std::chrono::steady_clock::time_point & time)161 void logSessionFinished(const std::chrono::steady_clock::time_point& time) {
162 logSession(time, Reason::FINISHED, 0);
163 }
164
logSessionFailed(const std::chrono::steady_clock::time_point & time)165 void logSessionFailed(const std::chrono::steady_clock::time_point& time) {
166 logSession(time, Reason::ERROR, AMEDIA_ERROR_UNKNOWN);
167 }
168
logCount() const169 int logCount() const { return mLoggedAtoms.size(); }
170
validateLatestAtom(Reason reason,int status,bool passthrough=false)171 void validateLatestAtom(Reason reason, int status, bool passthrough = false) {
172 const SessionEndedAtom& atom = mLoggedAtoms.back();
173
174 EXPECT_EQ(atom.atomCode, android::media::stats::MEDIA_TRANSCODING_SESSION_ENDED);
175 EXPECT_EQ(atom.reason, static_cast<int>(reason));
176 EXPECT_EQ(atom.callingUid, kDefaultCallingUid);
177 EXPECT_EQ(atom.status, status);
178 EXPECT_EQ(atom.srcWidth, kDefaultSrcWidth);
179 EXPECT_EQ(atom.srcHeight, kDefaultSrcHeight);
180 EXPECT_EQ(atom.srcMime, kDefaultSrcMime);
181 EXPECT_EQ(atom.srcProfile, kDefaultSrcProfile);
182 EXPECT_EQ(atom.srcLevel, kDefaultSrcLevel);
183 EXPECT_EQ(atom.srcFps, kDefaultSrcFps);
184 EXPECT_EQ(atom.srcDurationMs, kDefaultSrcDurationUs / 1000);
185 EXPECT_FALSE(atom.srcIsHdr);
186 EXPECT_EQ(atom.dstWidth, passthrough ? kDefaultSrcWidth : kDefaultDstWidth);
187 EXPECT_EQ(atom.dstHeight, passthrough ? kDefaultSrcHeight : kDefaultDstHeight);
188 EXPECT_EQ(atom.dstMime, passthrough ? "passthrough" : kDefaultDstMime);
189 EXPECT_FALSE(atom.dstIsHdr);
190
191 // Transcoder frame rate is only present on successful sessions.
192 if (status == AMEDIA_OK) {
193 std::chrono::duration<double> seconds{kDefaultTranscodeDuration};
194 const int32_t transcoderFps =
195 static_cast<int32_t>(kDefaultSrcFrameCount / seconds.count());
196 EXPECT_EQ(atom.transcoderFps, transcoderFps);
197 } else {
198 EXPECT_EQ(atom.transcoderFps, -1);
199 }
200 }
201
TearDown()202 void TearDown() override { ALOGI("TranscodingLoggerTest tear down"); }
~TranscodingLoggerTest()203 ~TranscodingLoggerTest() { ALOGD("TranscodingLoggerTest destroyed"); }
204
205 std::shared_ptr<TranscodingLogger> mLogger;
206 std::vector<SessionEndedAtom> mLoggedAtoms;
207
208 std::shared_ptr<AMediaFormat> mSrcFormat;
209 std::shared_ptr<AMediaFormat> mDstFormat;
210 };
211
TEST_F(TranscodingLoggerTest,TestDailyLogQuota)212 TEST_F(TranscodingLoggerTest, TestDailyLogQuota) {
213 ALOGD("TestDailyLogQuota");
214 auto start = std::chrono::steady_clock::now();
215
216 EXPECT_LT(TranscodingLogger::kMaxSuccessfulAtomsPerDay, TranscodingLogger::kMaxAtomsPerDay);
217
218 // 1. Check that the first kMaxSuccessfulAtomsPerDay successful atoms are logged.
219 for (int i = 0; i < TranscodingLogger::kMaxSuccessfulAtomsPerDay; ++i) {
220 logSessionFinished(start + std::chrono::seconds{i});
221 EXPECT_EQ(logCount(), i + 1);
222 }
223
224 // 2. Check that subsequent successful atoms within the same 24h interval are not logged.
225 for (int i = 1; i < 24; ++i) {
226 logSessionFinished(start + std::chrono::hours{i});
227 EXPECT_EQ(logCount(), TranscodingLogger::kMaxSuccessfulAtomsPerDay);
228 }
229
230 // 3. Check that failed atoms are logged up to kMaxAtomsPerDay.
231 for (int i = TranscodingLogger::kMaxSuccessfulAtomsPerDay;
232 i < TranscodingLogger::kMaxAtomsPerDay; ++i) {
233 logSessionFailed(start + std::chrono::seconds{i});
234 EXPECT_EQ(logCount(), i + 1);
235 }
236
237 // 4. Check that subsequent failed atoms within the same 24h interval are not logged.
238 for (int i = 1; i < 24; ++i) {
239 logSessionFailed(start + std::chrono::hours{i});
240 EXPECT_EQ(logCount(), TranscodingLogger::kMaxAtomsPerDay);
241 }
242
243 // 5. Check that failed and successful atoms are logged again after 24h.
244 logSessionFinished(start + std::chrono::hours{24});
245 EXPECT_EQ(logCount(), TranscodingLogger::kMaxAtomsPerDay + 1);
246
247 logSessionFailed(start + std::chrono::hours{24} + std::chrono::seconds{1});
248 EXPECT_EQ(logCount(), TranscodingLogger::kMaxAtomsPerDay + 2);
249 }
250
TEST_F(TranscodingLoggerTest,TestNullFormats)251 TEST_F(TranscodingLoggerTest, TestNullFormats) {
252 ALOGD("TestNullFormats");
253 auto srcFormat = std::shared_ptr<AMediaFormat>(CreateSrcFormat(), &AMediaFormat_delete);
254 auto dstFormat = std::shared_ptr<AMediaFormat>(CreateDstFormat(), &AMediaFormat_delete);
255 auto now = std::chrono::steady_clock::now();
256
257 // Source format null, should not log.
258 logSession(now, Reason::FINISHED, AMEDIA_OK, nullptr /*srcFormat*/, dstFormat.get());
259 EXPECT_EQ(logCount(), 0);
260
261 // Both formats null, should not log.
262 logSession(now, Reason::FINISHED, AMEDIA_OK, nullptr /*srcFormat*/, nullptr /*dstFormat*/);
263 EXPECT_EQ(logCount(), 0);
264
265 // Destination format null (passthrough mode), should log.
266 logSession(now, Reason::FINISHED, AMEDIA_OK, srcFormat.get(), nullptr /*dstFormat*/);
267 EXPECT_EQ(logCount(), 1);
268 validateLatestAtom(Reason::FINISHED, AMEDIA_OK, true /*passthrough*/);
269 }
270
TEST_F(TranscodingLoggerTest,TestAtomContentCorrectness)271 TEST_F(TranscodingLoggerTest, TestAtomContentCorrectness) {
272 ALOGD("TestAtomContentCorrectness");
273 auto now = std::chrono::steady_clock::now();
274
275 // Log and validate a failure.
276 logSession(now, Reason::ERROR, AMEDIA_ERROR_MALFORMED);
277 EXPECT_EQ(logCount(), 1);
278 validateLatestAtom(Reason::ERROR, AMEDIA_ERROR_MALFORMED);
279
280 // Log and validate a success.
281 logSession(now, Reason::FINISHED, AMEDIA_OK);
282 EXPECT_EQ(logCount(), 2);
283 validateLatestAtom(Reason::FINISHED, AMEDIA_OK);
284 }
285
286 } // namespace android
287