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 #include <odr_compilation_log.h>
18 
19 #include <time.h>
20 
21 #include <cstdint>
22 #include <ctime>
23 #include <iosfwd>
24 #include <istream>
25 #include <limits>
26 #include <ostream>
27 #include <sstream>
28 #include <string>
29 #include <vector>
30 
31 #include "android-base/file.h"
32 #include "base/common_art_test.h"
33 #include "odrefresh/odrefresh.h"
34 #include "odr_metrics.h"
35 
36 namespace art {
37 namespace odrefresh {
38 
39 const time_t kSecondsPerDay = 86'400;
40 
41 class OdrCompilationLogTest : public CommonArtTest {};
42 
TEST(OdrCompilationLogEntry,Equality)43 TEST(OdrCompilationLogEntry, Equality) {
44   OdrCompilationLogEntry a{1, 2, 3, 4, 5};
45 
46   ASSERT_EQ(a, (OdrCompilationLogEntry{1, 2, 3, 4, 5}));
47   ASSERT_NE(a, (OdrCompilationLogEntry{9, 2, 3, 4, 5}));
48   ASSERT_NE(a, (OdrCompilationLogEntry{1, 9, 3, 4, 5}));
49   ASSERT_NE(a, (OdrCompilationLogEntry{1, 2, 9, 4, 5}));
50   ASSERT_NE(a, (OdrCompilationLogEntry{2, 2, 3, 9, 5}));
51   ASSERT_NE(a, (OdrCompilationLogEntry{2, 2, 3, 5, 9}));
52 }
53 
TEST(OdrCompilationLogEntry,InputOutput)54 TEST(OdrCompilationLogEntry, InputOutput) {
55   const OdrCompilationLogEntry entries[] = {
56       {1, 2, 3, 4, 5},
57       {std::numeric_limits<int64_t>::min(),
58        std::numeric_limits<int64_t>::min(),
59        std::numeric_limits<int32_t>::min(),
60        std::numeric_limits<time_t>::min(),
61        std::numeric_limits<int32_t>::min()},
62       {std::numeric_limits<int64_t>::max(),
63        std::numeric_limits<int64_t>::max(),
64        std::numeric_limits<int32_t>::max(),
65        std::numeric_limits<time_t>::max(),
66        std::numeric_limits<int32_t>::max()},
67        {0, 0, 0, 0, 0},
68       {0x7fedcba9'87654321, 0x5a5a5a5a'5a5a5a5a, 0x12345678, 0x2346789, 0x76543210}
69   };
70   for (const auto& entry : entries) {
71     std::stringstream ss;
72     ss << entry;
73     OdrCompilationLogEntry actual;
74     ss >> actual;
75     ASSERT_EQ(entry, actual);
76   }
77 }
78 
TEST(OdrCompilationLogEntry,TruncatedInput)79 TEST(OdrCompilationLogEntry, TruncatedInput) {
80   std::stringstream ss;
81   ss << "1 2";
82 
83   OdrCompilationLogEntry entry;
84   ss >> entry;
85 
86   ASSERT_TRUE(ss.fail());
87   ASSERT_FALSE(ss.bad());
88 }
89 
TEST(OdrCompilationLogEntry,ReadMultiple)90 TEST(OdrCompilationLogEntry, ReadMultiple) {
91   std::stringstream ss;
92   ss << "0 1 2 3 4\n5 6 7 8 9\n";
93 
94   OdrCompilationLogEntry entry0, entry1;
95   ss >> entry0 >> entry1;
96   ASSERT_EQ(entry0, (OdrCompilationLogEntry{0, 1, 2, 3, 4}));
97   ASSERT_EQ(entry1, (OdrCompilationLogEntry{5, 6, 7, 8, 9}));
98 
99   ASSERT_FALSE(ss.fail());
100   ASSERT_FALSE(ss.bad());
101 }
102 
TEST(OdrCompilationLog,ShouldAttemptCompile)103 TEST(OdrCompilationLog, ShouldAttemptCompile) {
104   OdrCompilationLog ocl(/*compilation_log_path=*/nullptr);
105 
106   ASSERT_TRUE(ocl.ShouldAttemptCompile(
107       /*apex_version=*/1, /*last_update_millis=*/762, OdrMetrics::Trigger::kMissingArtifacts, 0));
108 
109   ocl.Log(
110       /*apex_version=*/1,
111       /*last_update_millis=*/762,
112       OdrMetrics::Trigger::kApexVersionMismatch,
113       ExitCode::kCompilationSuccess);
114   ASSERT_TRUE(ocl.ShouldAttemptCompile(
115       /*apex_version=*/2, /*last_update_millis=*/762, OdrMetrics::Trigger::kApexVersionMismatch));
116   ASSERT_TRUE(ocl.ShouldAttemptCompile(
117       /*apex_version=*/1, /*last_update_millis=*/10000, OdrMetrics::Trigger::kApexVersionMismatch));
118   ASSERT_FALSE(ocl.ShouldAttemptCompile(
119       /*apex_version=*/1, /*last_update_millis=*/762, OdrMetrics::Trigger::kApexVersionMismatch));
120   ASSERT_TRUE(ocl.ShouldAttemptCompile(
121       /*apex_version=*/1, /*last_update_millis=*/762, OdrMetrics::Trigger::kDexFilesChanged));
122   ASSERT_FALSE(ocl.ShouldAttemptCompile(
123       /*apex_version=*/1, /*last_update_millis=*/762, OdrMetrics::Trigger::kUnknown));
124 }
125 
TEST(OdrCompilationLog,BackOffNoHistory)126 TEST(OdrCompilationLog, BackOffNoHistory) {
127   time_t start_time;
128   time(&start_time);
129 
130   OdrCompilationLog ocl(/*compilation_log_path=*/nullptr);
131 
132   ASSERT_TRUE(ocl.ShouldAttemptCompile(
133       /*apex_version=*/1,
134       /*last_update_millis=*/0,
135       OdrMetrics::Trigger::kApexVersionMismatch,
136       start_time));
137 
138   // Start log
139   ocl.Log(/*apex_version=*/1,
140           /*last_update_millis=*/0,
141           OdrMetrics::Trigger::kApexVersionMismatch,
142           start_time,
143           ExitCode::kCompilationFailed);
144   ASSERT_FALSE(ocl.ShouldAttemptCompile(
145       /*apex_version=*/1,
146       /*last_update_millis=*/0,
147       OdrMetrics::Trigger::kApexVersionMismatch,
148       start_time));
149   ASSERT_FALSE(ocl.ShouldAttemptCompile(
150       /*apex_version=*/1,
151       /*last_update_millis=*/0,
152       OdrMetrics::Trigger::kApexVersionMismatch,
153       start_time + kSecondsPerDay / 2));
154   ASSERT_TRUE(ocl.ShouldAttemptCompile(
155       /*apex_version=*/1,
156       /*last_update_millis=*/0,
157       OdrMetrics::Trigger::kApexVersionMismatch,
158       start_time + kSecondsPerDay));
159 
160   // Add one more log entry
161   ocl.Log(/*apex_version=*/1,
162           /*last_update_millis=*/0,
163           OdrMetrics::Trigger::kApexVersionMismatch,
164           start_time,
165           ExitCode::kCompilationFailed);
166   ASSERT_FALSE(ocl.ShouldAttemptCompile(
167       /*apex_version=*/1,
168       /*last_update_millis=*/0,
169       OdrMetrics::Trigger::kApexVersionMismatch,
170       start_time + kSecondsPerDay));
171   ASSERT_TRUE(ocl.ShouldAttemptCompile(
172       /*apex_version=*/1,
173       /*last_update_millis=*/0,
174       OdrMetrics::Trigger::kApexVersionMismatch,
175       start_time + 2 * kSecondsPerDay));
176 
177   // One more.
178   ocl.Log(/*apex_version=*/1,
179           /*last_update_millis=*/0,
180           OdrMetrics::Trigger::kApexVersionMismatch,
181           start_time,
182           ExitCode::kCompilationFailed);
183   ASSERT_FALSE(ocl.ShouldAttemptCompile(
184       /*apex_version=*/1,
185       /*last_update_millis=*/0,
186       OdrMetrics::Trigger::kApexVersionMismatch,
187       start_time + 3 * kSecondsPerDay));
188   ASSERT_TRUE(ocl.ShouldAttemptCompile(
189       /*apex_version=*/1,
190       /*last_update_millis=*/0,
191       OdrMetrics::Trigger::kApexVersionMismatch,
192       start_time + 4 * kSecondsPerDay));
193 
194   // And one for the road.
195   ocl.Log(/*apex_version=*/1,
196           /*last_update_millis=*/0,
197           OdrMetrics::Trigger::kApexVersionMismatch,
198           start_time,
199           ExitCode::kCompilationFailed);
200   ASSERT_FALSE(ocl.ShouldAttemptCompile(
201       /*apex_version=*/1,
202       /*last_update_millis=*/0,
203       OdrMetrics::Trigger::kApexVersionMismatch,
204       start_time + 7 * kSecondsPerDay));
205   ASSERT_TRUE(ocl.ShouldAttemptCompile(
206       /*apex_version=*/1,
207       /*last_update_millis=*/0,
208       OdrMetrics::Trigger::kApexVersionMismatch,
209       start_time + 8 * kSecondsPerDay));
210 }
211 
TEST(OdrCompilationLog,BackOffHappyHistory)212 TEST(OdrCompilationLog, BackOffHappyHistory) {
213   time_t start_time;
214   time(&start_time);
215 
216   OdrCompilationLog ocl(/*compilation_log_path=*/nullptr);
217 
218   // Start log with a successful entry.
219   ocl.Log(/*apex_version=*/1,
220           /*last_update_millis=*/0,
221           OdrMetrics::Trigger::kApexVersionMismatch,
222           start_time,
223           ExitCode::kCompilationSuccess);
224   ASSERT_FALSE(ocl.ShouldAttemptCompile(
225       /*apex_version=*/1,
226       /*last_update_millis=*/0,
227       OdrMetrics::Trigger::kApexVersionMismatch,
228       start_time));
229   ASSERT_FALSE(ocl.ShouldAttemptCompile(
230       /*apex_version=*/1,
231       /*last_update_millis=*/0,
232       OdrMetrics::Trigger::kApexVersionMismatch,
233       start_time + kSecondsPerDay / 4));
234   ASSERT_TRUE(ocl.ShouldAttemptCompile(
235       /*apex_version=*/1,
236       /*last_update_millis=*/0,
237       OdrMetrics::Trigger::kApexVersionMismatch,
238       start_time + kSecondsPerDay / 2));
239 
240   // Add a log entry for a failed compilation.
241   ocl.Log(/*apex_version=*/1,
242           /*last_update_millis=*/0,
243           OdrMetrics::Trigger::kApexVersionMismatch,
244           start_time,
245           ExitCode::kCompilationFailed);
246   ASSERT_FALSE(ocl.ShouldAttemptCompile(
247       /*apex_version=*/1,
248       /*last_update_millis=*/0,
249       OdrMetrics::Trigger::kApexVersionMismatch,
250       start_time + kSecondsPerDay / 2));
251   ASSERT_TRUE(ocl.ShouldAttemptCompile(
252       /*apex_version=*/1,
253       /*last_update_millis=*/0,
254       OdrMetrics::Trigger::kApexVersionMismatch,
255       start_time + kSecondsPerDay));
256 }
257 
TEST_F(OdrCompilationLogTest,LogNumberOfEntriesAndPeek)258 TEST_F(OdrCompilationLogTest, LogNumberOfEntriesAndPeek) {
259   OdrCompilationLog ocl(/*compilation_log_path=*/nullptr);
260 
261   std::vector<OdrCompilationLogEntry> entries = {
262     { 0, 1, 2, 3, 4 },
263     { 1, 2, 3, 4, 5 },
264     { 2, 3, 4, 5, 6 },
265     { 3, 4, 5, 6, 7 },
266     { 4, 5, 6, 7, 8 },
267     { 5, 6, 7, 8, 9 },
268     { 6, 7, 8, 9, 10 }
269   };
270 
271   for (size_t i = 0; i < entries.size(); ++i) {
272     OdrCompilationLogEntry& e = entries[i];
273     ocl.Log(e.apex_version,
274             e.last_update_millis,
275             static_cast<OdrMetrics::Trigger>(e.trigger),
276             e.when,
277             static_cast<ExitCode>(e.exit_code));
278     if (i < OdrCompilationLog::kMaxLoggedEntries) {
279       ASSERT_EQ(i + 1, ocl.NumberOfEntries());
280     } else {
281       ASSERT_EQ(OdrCompilationLog::kMaxLoggedEntries, ocl.NumberOfEntries());
282     }
283 
284     for (size_t j = 0; j < ocl.NumberOfEntries(); ++j) {
285       const OdrCompilationLogEntry* logged = ocl.Peek(j);
286       ASSERT_TRUE(logged != nullptr);
287       const OdrCompilationLogEntry& expected = entries[i + 1 - ocl.NumberOfEntries() + j];
288       ASSERT_EQ(expected, *logged);
289     }
290   }
291 }
292 
TEST_F(OdrCompilationLogTest,LogReadWrite)293 TEST_F(OdrCompilationLogTest, LogReadWrite) {
294   std::vector<OdrCompilationLogEntry> entries = {
295     { 0, 1, 2, 3, 4 },
296     { 1, 2, 3, 4, 5 },
297     { 2, 3, 4, 5, 6 },
298     { 3, 4, 5, 6, 7 },
299     { 4, 5, 6, 7, 8 },
300     { 5, 6, 7, 8, 9 },
301     { 6, 7, 8, 9, 10 }
302   };
303 
304   ScratchFile scratch_file;
305   scratch_file.Close();
306 
307   for (size_t i = 0; i < entries.size(); ++i) {
308     {
309       OdrCompilationLog ocl(scratch_file.GetFilename().c_str());
310       OdrCompilationLogEntry& e = entries[i];
311       ocl.Log(e.apex_version,
312               e.last_update_millis,
313               static_cast<OdrMetrics::Trigger>(e.trigger),
314               e.when,
315               static_cast<ExitCode>(e.exit_code));
316     }
317 
318     {
319       OdrCompilationLog ocl(scratch_file.GetFilename().c_str());
320       if (i < OdrCompilationLog::kMaxLoggedEntries) {
321         ASSERT_EQ(i + 1, ocl.NumberOfEntries());
322       } else {
323         ASSERT_EQ(OdrCompilationLog::kMaxLoggedEntries, ocl.NumberOfEntries());
324       }
325 
326       for (size_t j = 0; j < ocl.NumberOfEntries(); ++j) {
327         const OdrCompilationLogEntry* logged = ocl.Peek(j);
328         ASSERT_TRUE(logged != nullptr);
329         const OdrCompilationLogEntry& expected = entries[i + 1 - ocl.NumberOfEntries() + j];
330         ASSERT_EQ(expected, *logged);
331       }
332     }
333   }
334 }
335 
TEST_F(OdrCompilationLogTest,BackoffBasedOnLog)336 TEST_F(OdrCompilationLogTest, BackoffBasedOnLog) {
337   time_t start_time;
338   time(&start_time);
339 
340   ScratchFile scratch_file;
341   scratch_file.Close();
342 
343   const char* log_path = scratch_file.GetFilename().c_str();
344   {
345     OdrCompilationLog ocl(log_path);
346 
347     ASSERT_TRUE(ocl.ShouldAttemptCompile(
348         /*apex_version=*/1,
349         /*last_update_millis=*/0,
350         OdrMetrics::Trigger::kApexVersionMismatch,
351         start_time));
352   }
353 
354   {
355     OdrCompilationLog ocl(log_path);
356 
357     // Start log
358     ocl.Log(/*apex_version=*/1,
359             /*last_update_millis=*/0,
360             OdrMetrics::Trigger::kApexVersionMismatch,
361             start_time,
362             ExitCode::kCompilationFailed);
363   }
364 
365   {
366     OdrCompilationLog ocl(log_path);
367     ASSERT_FALSE(ocl.ShouldAttemptCompile(
368         /*apex_version=*/1,
369         /*last_update_millis=*/0,
370         OdrMetrics::Trigger::kApexVersionMismatch,
371         start_time));
372     ASSERT_FALSE(ocl.ShouldAttemptCompile(
373         /*apex_version=*/1,
374         /*last_update_millis=*/0,
375         OdrMetrics::Trigger::kApexVersionMismatch,
376         start_time + kSecondsPerDay / 2));
377     ASSERT_TRUE(ocl.ShouldAttemptCompile(
378         /*apex_version=*/1,
379         /*last_update_millis=*/0,
380         OdrMetrics::Trigger::kApexVersionMismatch,
381         start_time + kSecondsPerDay));
382   }
383 
384   {
385     // Add one more log entry
386     OdrCompilationLog ocl(log_path);
387     ocl.Log(/*apex_version=*/1,
388             /*last_update_millis=*/0,
389             OdrMetrics::Trigger::kApexVersionMismatch,
390             start_time,
391             ExitCode::kCompilationFailed);
392   }
393 
394   {
395     OdrCompilationLog ocl(log_path);
396 
397     ASSERT_FALSE(ocl.ShouldAttemptCompile(
398         /*apex_version=*/1,
399         /*last_update_millis=*/0,
400         OdrMetrics::Trigger::kApexVersionMismatch,
401         start_time + kSecondsPerDay));
402     ASSERT_TRUE(ocl.ShouldAttemptCompile(
403         /*apex_version=*/1,
404         /*last_update_millis=*/0,
405         OdrMetrics::Trigger::kApexVersionMismatch,
406         start_time + 2 * kSecondsPerDay));
407   }
408 
409   {
410     // One more log entry.
411     OdrCompilationLog ocl(log_path);
412     ocl.Log(/*apex_version=*/1,
413             /*last_update_millis=*/0,
414             OdrMetrics::Trigger::kApexVersionMismatch,
415             start_time,
416             ExitCode::kCompilationFailed);
417   }
418 
419   {
420     OdrCompilationLog ocl(log_path);
421     ASSERT_FALSE(ocl.ShouldAttemptCompile(
422         /*apex_version=*/1,
423         /*last_update_millis=*/0,
424         OdrMetrics::Trigger::kApexVersionMismatch,
425         start_time + 3 * kSecondsPerDay));
426     ASSERT_TRUE(ocl.ShouldAttemptCompile(
427         /*apex_version=*/1,
428         /*last_update_millis=*/0,
429         OdrMetrics::Trigger::kApexVersionMismatch,
430         start_time + 4 * kSecondsPerDay));
431   }
432 
433   {
434     // And one for the road.
435     OdrCompilationLog ocl(log_path);
436     ocl.Log(/*apex_version=*/1,
437             /*last_update_millis=*/0,
438             OdrMetrics::Trigger::kApexVersionMismatch,
439             start_time,
440             ExitCode::kCompilationFailed);
441   }
442 
443   {
444     OdrCompilationLog ocl(log_path);
445     ASSERT_FALSE(ocl.ShouldAttemptCompile(
446         /*apex_version=*/1,
447         /*last_update_millis=*/0,
448         OdrMetrics::Trigger::kApexVersionMismatch,
449         start_time + 7 * kSecondsPerDay));
450     ASSERT_TRUE(ocl.ShouldAttemptCompile(
451         /*apex_version=*/1,
452         /*last_update_millis=*/0,
453         OdrMetrics::Trigger::kApexVersionMismatch,
454         start_time + 8 * kSecondsPerDay));
455   }
456 }
457 
TEST(OdrCompilationLog,LastUpdateMillisChangeTriggersCompilation)458 TEST(OdrCompilationLog, LastUpdateMillisChangeTriggersCompilation) {
459   time_t start_time;
460   time(&start_time);
461 
462   OdrCompilationLog ocl(/*compilation_log_path=*/nullptr);
463 
464   for (int64_t last_update_millis = 0; last_update_millis < 10000; last_update_millis += 1000) {
465     static const int64_t kApexVersion = 19999;
466     ASSERT_TRUE(ocl.ShouldAttemptCompile(
467         kApexVersion, last_update_millis, OdrMetrics::Trigger::kApexVersionMismatch, start_time));
468     ocl.Log(kApexVersion,
469             last_update_millis,
470             OdrMetrics::Trigger::kApexVersionMismatch,
471             start_time,
472             ExitCode::kCompilationSuccess);
473     ASSERT_FALSE(ocl.ShouldAttemptCompile(kApexVersion,
474                                           last_update_millis,
475                                           OdrMetrics::Trigger::kApexVersionMismatch,
476                                           start_time + 1));
477   }
478 }
479 
TEST(OdrCompilationLog,ApexVersionChangeTriggersCompilation)480 TEST(OdrCompilationLog, ApexVersionChangeTriggersCompilation) {
481   time_t start_time;
482   time(&start_time);
483 
484   OdrCompilationLog ocl(/*compilation_log_path=*/nullptr);
485 
486   for (int64_t apex_version = 0; apex_version < 10000; apex_version += 1000) {
487     static const int64_t kLastUpdateMillis = 777;
488     ASSERT_TRUE(ocl.ShouldAttemptCompile(apex_version,
489                                          kLastUpdateMillis,
490                                          OdrMetrics::Trigger::kApexVersionMismatch,
491                                          start_time + 8 * kSecondsPerDay));
492     ocl.Log(apex_version,
493             kLastUpdateMillis,
494             OdrMetrics::Trigger::kApexVersionMismatch,
495             start_time,
496             ExitCode::kCompilationSuccess);
497     ASSERT_FALSE(ocl.ShouldAttemptCompile(apex_version,
498                                           kLastUpdateMillis,
499                                           OdrMetrics::Trigger::kApexVersionMismatch,
500                                           start_time + 1));
501   }
502 }
503 
TEST_F(OdrCompilationLogTest,NewLogVersionTriggersCompilation)504 TEST_F(OdrCompilationLogTest, NewLogVersionTriggersCompilation) {
505   static const int64_t kApexVersion = 1066;
506   static const int64_t kLastUpdateMillis = 777;
507   time_t start_time;
508   time(&start_time);
509 
510   ScratchFile scratch_file;
511   scratch_file.Close();
512 
513   // Generate a compilation log.
514   {
515     OdrCompilationLog ocl(scratch_file.GetFilename().c_str());
516     for (size_t i = 0; i < OdrCompilationLog::kMaxLoggedEntries; ++i) {
517       ocl.Log(kApexVersion,
518               kLastUpdateMillis,
519               OdrMetrics::Trigger::kApexVersionMismatch,
520               start_time,
521               ExitCode::kCompilationSuccess);
522       ASSERT_FALSE(ocl.ShouldAttemptCompile(
523           kApexVersion, kLastUpdateMillis, OdrMetrics::Trigger::kApexVersionMismatch, start_time));
524     }
525   }
526 
527   // Replace version string in the compilation log.
528   std::string log_text;
529   ASSERT_TRUE(android::base::ReadFileToString(scratch_file.GetFilename(), &log_text));
530   std::string new_log_version = std::string(OdrCompilationLog::kLogVersion) + "a";
531   log_text.replace(0, new_log_version.size() - 1, new_log_version);
532   ASSERT_TRUE(android::base::WriteStringToFile(log_text, scratch_file.GetFilename()));
533 
534   // Read log with updated version entry, check it is treated as out-of-date.
535   {
536     OdrCompilationLog ocl(scratch_file.GetFilename().c_str());
537     ASSERT_TRUE(ocl.ShouldAttemptCompile(
538         kApexVersion, kLastUpdateMillis, OdrMetrics::Trigger::kApexVersionMismatch, start_time));
539     ASSERT_EQ(0u, ocl.NumberOfEntries());
540   }
541 }
542 
543 }  // namespace odrefresh
544 }  // namespace art
545