• Home
  • Line#
  • Scopes#
  • Navigate#
  • Raw
  • Download
1 /*
2  * Copyright (C) 2019 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 "src/trace_processor/importers/common/clock_tracker.h"
18 
19 #include <random>
20 
21 #include "perfetto/ext/base/optional.h"
22 #include "src/trace_processor/storage/trace_storage.h"
23 #include "src/trace_processor/types/trace_processor_context.h"
24 #include "test/gtest_and_gmock.h"
25 
26 #include "protos/perfetto/common/builtin_clock.pbzero.h"
27 #include "protos/perfetto/trace/clock_snapshot.pbzero.h"
28 
29 namespace perfetto {
30 namespace trace_processor {
31 namespace {
32 
33 using ::testing::NiceMock;
34 using Clock = protos::pbzero::ClockSnapshot::Clock;
35 
36 constexpr auto REALTIME = protos::pbzero::BUILTIN_CLOCK_REALTIME;
37 constexpr auto BOOTTIME = protos::pbzero::BUILTIN_CLOCK_BOOTTIME;
38 constexpr auto MONOTONIC = protos::pbzero::BUILTIN_CLOCK_MONOTONIC;
39 constexpr auto MONOTONIC_COARSE =
40     protos::pbzero::BUILTIN_CLOCK_MONOTONIC_COARSE;
41 constexpr auto MONOTONIC_RAW = protos::pbzero::BUILTIN_CLOCK_MONOTONIC_RAW;
42 
43 class ClockTrackerTest : public ::testing::Test {
44  public:
ClockTrackerTest()45   ClockTrackerTest() { context_.storage.reset(new TraceStorage()); }
46 
47   TraceProcessorContext context_;
48   ClockTracker ct_{&context_};
49 };
50 
TEST_F(ClockTrackerTest,ClockDomainConversions)51 TEST_F(ClockTrackerTest, ClockDomainConversions) {
52   EXPECT_EQ(ct_.ToTraceTime(REALTIME, 0), base::nullopt);
53 
54   ct_.AddSnapshot({{REALTIME, 10}, {BOOTTIME, 10010}});
55   ct_.AddSnapshot({{REALTIME, 20}, {BOOTTIME, 20220}});
56   ct_.AddSnapshot({{REALTIME, 30}, {BOOTTIME, 30030}});
57   ct_.AddSnapshot({{MONOTONIC, 1000}, {BOOTTIME, 100000}});
58 
59   EXPECT_EQ(ct_.ToTraceTime(REALTIME, 0), 10000);
60   EXPECT_EQ(ct_.ToTraceTime(REALTIME, 1), 10001);
61   EXPECT_EQ(ct_.ToTraceTime(REALTIME, 9), 10009);
62   EXPECT_EQ(ct_.ToTraceTime(REALTIME, 10), 10010);
63   EXPECT_EQ(ct_.ToTraceTime(REALTIME, 11), 10011);
64   EXPECT_EQ(ct_.ToTraceTime(REALTIME, 19), 10019);
65   EXPECT_EQ(ct_.ToTraceTime(REALTIME, 20), 20220);
66   EXPECT_EQ(ct_.ToTraceTime(REALTIME, 21), 20221);
67   EXPECT_EQ(ct_.ToTraceTime(REALTIME, 29), 20229);
68   EXPECT_EQ(ct_.ToTraceTime(REALTIME, 30), 30030);
69   EXPECT_EQ(ct_.ToTraceTime(REALTIME, 40), 30040);
70 
71   EXPECT_EQ(ct_.ToTraceTime(MONOTONIC, 0), 100000 - 1000);
72   EXPECT_EQ(ct_.ToTraceTime(MONOTONIC, 999), 100000 - 1);
73   EXPECT_EQ(ct_.ToTraceTime(MONOTONIC, 1000), 100000);
74   EXPECT_EQ(ct_.ToTraceTime(MONOTONIC, 1e6),
75             static_cast<int64_t>(100000 - 1000 + 1e6));
76 }
77 
78 // When a clock moves backwards conversions *from* that clock are forbidden
79 // but conversions *to* that clock should still work.
80 // Think to the case of REALTIME going backwards from 3AM to 2AM during DST day.
81 // You can't convert 2.10AM REALTIME to BOOTTIME because there are two possible
82 // answers, but you can still unambiguosly convert BOOTTIME into REALTIME.
TEST_F(ClockTrackerTest,RealTimeClockMovingBackwards)83 TEST_F(ClockTrackerTest, RealTimeClockMovingBackwards) {
84   ct_.AddSnapshot({{BOOTTIME, 10010}, {REALTIME, 10}});
85 
86   // At this point conversions are still possible in both ways because we
87   // haven't broken monotonicity yet.
88   EXPECT_EQ(ct_.Convert(REALTIME, 11, BOOTTIME), 10011);
89 
90   ct_.AddSnapshot({{BOOTTIME, 10020}, {REALTIME, 20}});
91   ct_.AddSnapshot({{BOOTTIME, 30040}, {REALTIME, 40}});
92   ct_.AddSnapshot({{BOOTTIME, 40030}, {REALTIME, 30}});
93 
94   // Now only BOOTIME -> REALTIME conversion should be possible.
95   EXPECT_FALSE(ct_.Convert(REALTIME, 11, BOOTTIME));
96   EXPECT_EQ(ct_.Convert(BOOTTIME, 10011, REALTIME), 11);
97   EXPECT_EQ(ct_.Convert(BOOTTIME, 10029, REALTIME), 29);
98   EXPECT_EQ(ct_.Convert(BOOTTIME, 40030, REALTIME), 30);
99   EXPECT_EQ(ct_.Convert(BOOTTIME, 40040, REALTIME), 40);
100 
101   ct_.AddSnapshot({{BOOTTIME, 50000}, {REALTIME, 50}});
102   EXPECT_EQ(ct_.Convert(BOOTTIME, 50005, REALTIME), 55);
103 
104   ct_.AddSnapshot({{BOOTTIME, 60020}, {REALTIME, 20}});
105   EXPECT_EQ(ct_.Convert(BOOTTIME, 60020, REALTIME), 20);
106 }
107 
108 // Simulate the following scenario:
109 // MONOTONIC = MONOTONIC_COARSE + 10
110 // BOOTTIME = MONOTONIC + 1000 (until T=200)
111 // BOOTTIME = MONOTONIC + 2000 (from T=200)
112 // Then resolve MONOTONIC_COARSE. This requires a two-level resolution:
113 // MONOTONIC_COARSE -> MONOTONIC -> BOOTTIME.
TEST_F(ClockTrackerTest,ChainedResolutionSimple)114 TEST_F(ClockTrackerTest, ChainedResolutionSimple) {
115   ct_.AddSnapshot({{MONOTONIC_COARSE, 1}, {MONOTONIC, 11}});
116   ct_.AddSnapshot({{MONOTONIC, 100}, {BOOTTIME, 1100}});
117   ct_.AddSnapshot({{MONOTONIC, 200}, {BOOTTIME, 2200}});
118 
119   EXPECT_EQ(ct_.Convert(MONOTONIC, 100, MONOTONIC_COARSE), 90);
120   EXPECT_EQ(ct_.Convert(MONOTONIC_COARSE, 20, MONOTONIC), 30);
121 
122   // MONOTONIC_COARSE@100 == MONOTONIC@110 == BOOTTIME@1100.
123   EXPECT_EQ(ct_.ToTraceTime(MONOTONIC, 110), 1110);
124   EXPECT_EQ(*ct_.ToTraceTime(MONOTONIC_COARSE, 100), 100 + 10 + 1000);
125   EXPECT_EQ(*ct_.ToTraceTime(MONOTONIC_COARSE, 202), 202 + 10 + 2000);
126 }
127 
TEST_F(ClockTrackerTest,ChainedResolutionHard)128 TEST_F(ClockTrackerTest, ChainedResolutionHard) {
129   // MONOTONIC_COARSE = MONOTONIC_RAW - 1.
130   ct_.AddSnapshot({{MONOTONIC_RAW, 10}, {MONOTONIC_COARSE, 9}});
131 
132   // MONOTONIC = MONOTONIC_COARSE - 50.
133   ct_.AddSnapshot({{MONOTONIC_COARSE, 100}, {MONOTONIC, 50}});
134 
135   // BOOTTIME = MONOTONIC + 1000 until T=100 (see below).
136   ct_.AddSnapshot({{MONOTONIC, 1}, {BOOTTIME, 1001}, {REALTIME, 10001}});
137 
138   // BOOTTIME = MONOTONIC + 2000 from T=100.
139   // At the same time, REALTIME goes backwards.
140   ct_.AddSnapshot({{MONOTONIC, 101}, {BOOTTIME, 2101}, {REALTIME, 9101}});
141 
142   // 1-hop conversions.
143   EXPECT_EQ(ct_.Convert(MONOTONIC_RAW, 2, MONOTONIC_COARSE), 1);
144   EXPECT_EQ(ct_.Convert(MONOTONIC_COARSE, 1, MONOTONIC_RAW), 2);
145   EXPECT_EQ(ct_.Convert(MONOTONIC_RAW, 100001, MONOTONIC_COARSE), 100000);
146   EXPECT_EQ(ct_.Convert(MONOTONIC_COARSE, 100000, MONOTONIC_RAW), 100001);
147 
148   // 2-hop conversions (MONOTONIC_RAW <-> MONOTONIC_COARSE <-> MONOTONIC).
149   // From above, MONOTONIC = (MONOTONIC_RAW - 1) - 50.
150   EXPECT_EQ(ct_.Convert(MONOTONIC_RAW, 53, MONOTONIC), 53 - 1 - 50);
151   EXPECT_EQ(ct_.Convert(MONOTONIC, 2, MONOTONIC_RAW), 2 + 1 + 50);
152 
153   // 3-hop conversions (as above + BOOTTIME)
154   EXPECT_EQ(ct_.Convert(MONOTONIC_RAW, 53, BOOTTIME), 53 - 1 - 50 + 1000);
155   EXPECT_EQ(ct_.Convert(BOOTTIME, 1002, MONOTONIC_RAW), 1002 - 1000 + 1 + 50);
156 
157   EXPECT_EQ(*ct_.Convert(MONOTONIC_RAW, 753, BOOTTIME), 753 - 1 - 50 + 2000);
158   EXPECT_EQ(ct_.Convert(BOOTTIME, 2702, MONOTONIC_RAW), 2702 - 2000 + 1 + 50);
159 
160   // 3-hop conversion to REALTIME, one way only (REALTIME goes backwards).
161   EXPECT_EQ(*ct_.Convert(MONOTONIC_RAW, 53, REALTIME), 53 - 1 - 50 + 10000);
162   EXPECT_EQ(*ct_.Convert(MONOTONIC_RAW, 753, REALTIME), 753 - 1 - 50 + 9000);
163 }
164 
165 // Regression test for b/158182858. When taking two snapshots back-to-back,
166 // MONOTONIC_COARSE might be stuck to the last value. We should still be able
167 // to convert both ways in this case.
TEST_F(ClockTrackerTest,NonStrictlyMonotonic)168 TEST_F(ClockTrackerTest, NonStrictlyMonotonic) {
169   ct_.AddSnapshot({{BOOTTIME, 101}, {MONOTONIC, 51}, {MONOTONIC_COARSE, 50}});
170   ct_.AddSnapshot({{BOOTTIME, 105}, {MONOTONIC, 55}, {MONOTONIC_COARSE, 50}});
171 
172   // This last snapshot is deliberately identical to the previous one. This
173   // is to simulate the case of taking two snapshots so close to each other that
174   // all clocks are identical.
175   ct_.AddSnapshot({{BOOTTIME, 105}, {MONOTONIC, 55}, {MONOTONIC_COARSE, 50}});
176 
177   EXPECT_EQ(ct_.Convert(MONOTONIC_COARSE, 49, MONOTONIC), 50);
178   EXPECT_EQ(ct_.Convert(MONOTONIC_COARSE, 50, MONOTONIC), 55);
179   EXPECT_EQ(ct_.Convert(MONOTONIC_COARSE, 51, MONOTONIC), 56);
180 
181   EXPECT_EQ(ct_.Convert(MONOTONIC_COARSE, 40, BOOTTIME), 91);
182   EXPECT_EQ(ct_.Convert(MONOTONIC_COARSE, 50, BOOTTIME), 105);
183   EXPECT_EQ(ct_.Convert(MONOTONIC_COARSE, 55, BOOTTIME), 110);
184 
185   EXPECT_EQ(ct_.Convert(BOOTTIME, 91, MONOTONIC_COARSE), 40);
186   EXPECT_EQ(ct_.Convert(BOOTTIME, 105, MONOTONIC_COARSE), 50);
187   EXPECT_EQ(ct_.Convert(BOOTTIME, 110, MONOTONIC_COARSE), 55);
188 }
189 
TEST_F(ClockTrackerTest,SequenceScopedClocks)190 TEST_F(ClockTrackerTest, SequenceScopedClocks) {
191   ct_.AddSnapshot({{MONOTONIC, 1000}, {BOOTTIME, 100000}});
192 
193   ClockTracker::ClockId c64_1 = ct_.SeqScopedClockIdToGlobal(1, 64);
194   ClockTracker::ClockId c65_1 = ct_.SeqScopedClockIdToGlobal(1, 65);
195   ClockTracker::ClockId c66_1 = ct_.SeqScopedClockIdToGlobal(1, 66);
196   ClockTracker::ClockId c66_2 = ct_.SeqScopedClockIdToGlobal(2, 64);
197 
198   ct_.AddSnapshot(
199       {{MONOTONIC, 10000},
200        {c64_1, 100000},
201        {c65_1, 100, /*unit_multiplier_ns=*/1000, /*is_incremental=*/false},
202        {c66_1, 10, /*unit_multiplier_ns=*/1000, /*is_incremental=*/true}});
203 
204   // c64_1 is non-incremental and in nanos.
205   EXPECT_EQ(*ct_.Convert(c64_1, 150000, MONOTONIC), 60000);
206   EXPECT_EQ(*ct_.Convert(c64_1, 150000, BOOTTIME), 159000);
207   EXPECT_EQ(*ct_.ToTraceTime(c64_1, 150000), 159000);
208 
209   // c65_1 is non-incremental and in micros.
210   EXPECT_EQ(*ct_.Convert(c65_1, 150, MONOTONIC), 60000);
211   EXPECT_EQ(*ct_.Convert(c65_1, 150, BOOTTIME), 159000);
212   EXPECT_EQ(*ct_.ToTraceTime(c65_1, 150), 159000);
213 
214   // c66_1 is incremental and in micros.
215   EXPECT_EQ(*ct_.Convert(c66_1, 1 /* abs 11 */, MONOTONIC), 11000);
216   EXPECT_EQ(*ct_.Convert(c66_1, 1 /* abs 12 */, MONOTONIC), 12000);
217   EXPECT_EQ(*ct_.Convert(c66_1, 1 /* abs 13 */, BOOTTIME), 112000);
218   EXPECT_EQ(*ct_.ToTraceTime(c66_1, 2 /* abs 15 */), 114000);
219 
220   ct_.AddSnapshot(
221       {{MONOTONIC, 20000},
222        {c66_1, 20, /*unit_multiplier_ns=*/1000, /*is_incremental=*/true}});
223   ct_.AddSnapshot(
224       {{MONOTONIC, 20000},
225        {c66_2, 20, /*unit_multiplier_ns=*/1000, /*is_incremental=*/true}});
226 
227   // c66_1 and c66_2 are both incremental and in micros, but shouldn't affect
228   // each other.
229   EXPECT_EQ(*ct_.Convert(c66_1, 1 /* abs 21 */, MONOTONIC), 21000);
230   EXPECT_EQ(*ct_.Convert(c66_2, 2 /* abs 22 */, MONOTONIC), 22000);
231   EXPECT_EQ(*ct_.Convert(c66_1, 1 /* abs 22 */, MONOTONIC), 22000);
232   EXPECT_EQ(*ct_.Convert(c66_2, 2 /* abs 24 */, MONOTONIC), 24000);
233   EXPECT_EQ(*ct_.Convert(c66_1, 1 /* abs 23 */, BOOTTIME), 122000);
234   EXPECT_EQ(*ct_.Convert(c66_2, 2 /* abs 26 */, BOOTTIME), 125000);
235   EXPECT_EQ(*ct_.ToTraceTime(c66_1, 2 /* abs 25 */), 124000);
236   EXPECT_EQ(*ct_.ToTraceTime(c66_2, 4 /* abs 30 */), 129000);
237 }
238 
239 // Tests that the cache doesn't affect the results of Convert() in unexpected
240 // ways.
TEST_F(ClockTrackerTest,CacheDoesntAffectResults)241 TEST_F(ClockTrackerTest, CacheDoesntAffectResults) {
242   std::minstd_rand rnd;
243   int last_mono = 0;
244   int last_boot = 0;
245   int last_raw = 0;
246   static const int increments[] = {1, 2, 10};
247   for (int i = 0; i < 1000; i++) {
248     last_mono += increments[rnd() % base::ArraySize(increments)];
249     last_boot += increments[rnd() % base::ArraySize(increments)];
250     ct_.AddSnapshot({{MONOTONIC, last_mono}, {BOOTTIME, last_boot}});
251 
252     last_raw += increments[rnd() % base::ArraySize(increments)];
253     last_boot += increments[rnd() % base::ArraySize(increments)];
254     ct_.AddSnapshot({{MONOTONIC_RAW, last_raw}, {BOOTTIME, last_boot}});
255   }
256 
257   for (int i = 0; i < 1000; i++) {
258     int64_t val = static_cast<int64_t>(rnd()) % 10000;
259     for (int j = 0; j < 5; j++) {
260       ClockTracker::ClockId src;
261       ClockTracker::ClockId tgt;
262       if (j == 0) {
263         std::tie(src, tgt) = std::make_tuple(MONOTONIC, BOOTTIME);
264       } else if (j == 1) {
265         std::tie(src, tgt) = std::make_tuple(MONOTONIC_RAW, BOOTTIME);
266       } else if (j == 2) {
267         std::tie(src, tgt) = std::make_tuple(BOOTTIME, MONOTONIC);
268       } else if (j == 3) {
269         std::tie(src, tgt) = std::make_tuple(BOOTTIME, MONOTONIC_RAW);
270       } else if (j == 4) {
271         std::tie(src, tgt) = std::make_tuple(MONOTONIC_RAW, MONOTONIC);
272       } else {
273         PERFETTO_FATAL("j out of bounds");
274       }
275       // It will still write the cache, just not lookup.
276       ct_.set_cache_lookups_disabled_for_testing(true);
277       auto not_cached = ct_.Convert(src, val, tgt);
278 
279       // This should 100% hit the cache.
280       ct_.set_cache_lookups_disabled_for_testing(false);
281       auto cached = ct_.Convert(src, val, tgt);
282 
283       ASSERT_EQ(not_cached, cached);
284     }
285   }
286 }
287 
288 }  // namespace
289 }  // namespace trace_processor
290 }  // namespace perfetto
291