Line data Source code
1 : // Copyright 2014 the V8 project authors. All rights reserved.
2 : // Use of this source code is governed by a BSD-style license that can be
3 : // found in the LICENSE file.
4 :
5 : #include <vector>
6 :
7 : #include "src/counters-inl.h"
8 : #include "src/counters.h"
9 : #include "src/handles-inl.h"
10 : #include "src/objects-inl.h"
11 : #include "src/tracing/tracing-category-observer.h"
12 : #include "testing/gtest/include/gtest/gtest.h"
13 :
14 : namespace v8 {
15 : namespace internal {
16 :
17 : namespace {
18 :
19 : class MockHistogram : public Histogram {
20 : public:
21 2020 : void AddSample(int value) { samples_.push_back(value); }
22 : std::vector<int>* samples() { return &samples_; }
23 :
24 : private:
25 : std::vector<int> samples_;
26 : };
27 :
28 :
29 : class AggregatedMemoryHistogramTest : public ::testing::Test {
30 : public:
31 28 : AggregatedMemoryHistogramTest() : aggregated_(&mock_) {}
32 28 : virtual ~AggregatedMemoryHistogramTest() {}
33 :
34 : void AddSample(double current_ms, double current_value) {
35 14 : aggregated_.AddSample(current_ms, current_value);
36 : }
37 :
38 : std::vector<int>* samples() { return mock_.samples(); }
39 :
40 : private:
41 : AggregatedMemoryHistogram<MockHistogram> aggregated_;
42 : MockHistogram mock_;
43 : };
44 :
45 : class RuntimeCallStatsTest : public ::testing::Test {
46 : public:
47 0 : RuntimeCallStatsTest() {
48 : FLAG_runtime_stats =
49 0 : v8::tracing::TracingCategoryObserver::ENABLED_BY_NATIVE;
50 0 : }
51 0 : virtual ~RuntimeCallStatsTest() {}
52 :
53 : RuntimeCallStats* stats() { return &stats_; }
54 : RuntimeCallStats::CounterId counter_id() {
55 : return &RuntimeCallStats::TestCounter1;
56 : }
57 : RuntimeCallStats::CounterId counter_id2() {
58 : return &RuntimeCallStats::TestCounter2;
59 : }
60 : RuntimeCallStats::CounterId counter_id3() {
61 : return &RuntimeCallStats::TestCounter3;
62 : }
63 : RuntimeCallCounter* counter() { return &(stats()->*counter_id()); }
64 : RuntimeCallCounter* counter2() { return &(stats()->*counter_id2()); }
65 : RuntimeCallCounter* counter3() { return &(stats()->*counter_id3()); }
66 0 : void Sleep(int32_t milliseconds) {
67 : base::ElapsedTimer timer;
68 0 : base::TimeDelta delta = base::TimeDelta::FromMilliseconds(milliseconds);
69 : timer.Start();
70 0 : while (!timer.HasExpired(delta)) {
71 0 : base::OS::Sleep(base::TimeDelta::FromMicroseconds(0));
72 : }
73 0 : }
74 :
75 : const uint32_t kEpsilonMs = 20;
76 :
77 : private:
78 : RuntimeCallStats stats_;
79 : };
80 :
81 : } // namespace
82 :
83 :
84 13158 : TEST_F(AggregatedMemoryHistogramTest, OneSample1) {
85 1 : FLAG_histogram_interval = 10;
86 : AddSample(10, 1000);
87 : AddSample(20, 1000);
88 3 : EXPECT_EQ(1U, samples()->size());
89 2 : EXPECT_EQ(1000, (*samples())[0]);
90 1 : }
91 :
92 :
93 13158 : TEST_F(AggregatedMemoryHistogramTest, OneSample2) {
94 1 : FLAG_histogram_interval = 10;
95 : AddSample(10, 500);
96 : AddSample(20, 1000);
97 3 : EXPECT_EQ(1U, samples()->size());
98 2 : EXPECT_EQ(750, (*samples())[0]);
99 1 : }
100 :
101 :
102 13158 : TEST_F(AggregatedMemoryHistogramTest, OneSample3) {
103 1 : FLAG_histogram_interval = 10;
104 : AddSample(10, 500);
105 : AddSample(15, 500);
106 : AddSample(15, 1000);
107 : AddSample(20, 1000);
108 3 : EXPECT_EQ(1U, samples()->size());
109 2 : EXPECT_EQ(750, (*samples())[0]);
110 1 : }
111 :
112 :
113 13158 : TEST_F(AggregatedMemoryHistogramTest, OneSample4) {
114 1 : FLAG_histogram_interval = 10;
115 : AddSample(10, 500);
116 : AddSample(15, 750);
117 : AddSample(20, 1000);
118 3 : EXPECT_EQ(1U, samples()->size());
119 2 : EXPECT_EQ(750, (*samples())[0]);
120 1 : }
121 :
122 :
123 13158 : TEST_F(AggregatedMemoryHistogramTest, TwoSamples1) {
124 1 : FLAG_histogram_interval = 10;
125 : AddSample(10, 1000);
126 : AddSample(30, 1000);
127 3 : EXPECT_EQ(2U, samples()->size());
128 2 : EXPECT_EQ(1000, (*samples())[0]);
129 2 : EXPECT_EQ(1000, (*samples())[1]);
130 1 : }
131 :
132 :
133 13158 : TEST_F(AggregatedMemoryHistogramTest, TwoSamples2) {
134 1 : FLAG_histogram_interval = 10;
135 : AddSample(10, 1000);
136 : AddSample(20, 1000);
137 : AddSample(30, 1000);
138 3 : EXPECT_EQ(2U, samples()->size());
139 2 : EXPECT_EQ(1000, (*samples())[0]);
140 2 : EXPECT_EQ(1000, (*samples())[1]);
141 1 : }
142 :
143 :
144 13158 : TEST_F(AggregatedMemoryHistogramTest, TwoSamples3) {
145 1 : FLAG_histogram_interval = 10;
146 : AddSample(10, 1000);
147 : AddSample(20, 1000);
148 : AddSample(20, 500);
149 : AddSample(30, 500);
150 3 : EXPECT_EQ(2U, samples()->size());
151 2 : EXPECT_EQ(1000, (*samples())[0]);
152 2 : EXPECT_EQ(500, (*samples())[1]);
153 1 : }
154 :
155 :
156 13158 : TEST_F(AggregatedMemoryHistogramTest, TwoSamples4) {
157 1 : FLAG_histogram_interval = 10;
158 : AddSample(10, 1000);
159 : AddSample(30, 0);
160 3 : EXPECT_EQ(2U, samples()->size());
161 2 : EXPECT_EQ(750, (*samples())[0]);
162 2 : EXPECT_EQ(250, (*samples())[1]);
163 1 : }
164 :
165 :
166 13158 : TEST_F(AggregatedMemoryHistogramTest, TwoSamples5) {
167 1 : FLAG_histogram_interval = 10;
168 : AddSample(10, 0);
169 : AddSample(30, 1000);
170 3 : EXPECT_EQ(2U, samples()->size());
171 2 : EXPECT_EQ(250, (*samples())[0]);
172 2 : EXPECT_EQ(750, (*samples())[1]);
173 1 : }
174 :
175 :
176 13158 : TEST_F(AggregatedMemoryHistogramTest, TwoSamples6) {
177 1 : FLAG_histogram_interval = 10;
178 : AddSample(10, 0);
179 : AddSample(15, 1000);
180 : AddSample(30, 1000);
181 3 : EXPECT_EQ(2U, samples()->size());
182 2 : EXPECT_EQ((500 + 1000) / 2, (*samples())[0]);
183 2 : EXPECT_EQ(1000, (*samples())[1]);
184 1 : }
185 :
186 :
187 13158 : TEST_F(AggregatedMemoryHistogramTest, TwoSamples7) {
188 1 : FLAG_histogram_interval = 10;
189 : AddSample(10, 0);
190 : AddSample(15, 1000);
191 : AddSample(25, 0);
192 : AddSample(30, 1000);
193 3 : EXPECT_EQ(2U, samples()->size());
194 2 : EXPECT_EQ((500 + 750) / 2, (*samples())[0]);
195 2 : EXPECT_EQ((250 + 500) / 2, (*samples())[1]);
196 1 : }
197 :
198 :
199 13158 : TEST_F(AggregatedMemoryHistogramTest, TwoSamples8) {
200 1 : FLAG_histogram_interval = 10;
201 : AddSample(10, 1000);
202 : AddSample(15, 0);
203 : AddSample(25, 1000);
204 : AddSample(30, 0);
205 3 : EXPECT_EQ(2U, samples()->size());
206 2 : EXPECT_EQ((500 + 250) / 2, (*samples())[0]);
207 2 : EXPECT_EQ((750 + 500) / 2, (*samples())[1]);
208 1 : }
209 :
210 :
211 13158 : TEST_F(AggregatedMemoryHistogramTest, ManySamples1) {
212 1 : FLAG_histogram_interval = 10;
213 : const int kMaxSamples = 1000;
214 : AddSample(0, 0);
215 : AddSample(10 * kMaxSamples, 10 * kMaxSamples);
216 3 : EXPECT_EQ(static_cast<unsigned>(kMaxSamples), samples()->size());
217 1001 : for (int i = 0; i < kMaxSamples; i++) {
218 3000 : EXPECT_EQ(i * 10 + 5, (*samples())[i]);
219 : }
220 1 : }
221 :
222 :
223 13158 : TEST_F(AggregatedMemoryHistogramTest, ManySamples2) {
224 1 : FLAG_histogram_interval = 10;
225 : const int kMaxSamples = 1000;
226 : AddSample(0, 0);
227 : AddSample(10 * (2 * kMaxSamples), 10 * (2 * kMaxSamples));
228 3 : EXPECT_EQ(static_cast<unsigned>(kMaxSamples), samples()->size());
229 1001 : for (int i = 0; i < kMaxSamples; i++) {
230 3000 : EXPECT_EQ(i * 10 + 5, (*samples())[i]);
231 : }
232 1 : }
233 :
234 : #define EXPECT_IN_RANGE(start, value, end) \
235 : EXPECT_LE(start, value); \
236 : EXPECT_GE(end, value)
237 :
238 13155 : TEST_F(RuntimeCallStatsTest, RuntimeCallTimer) {
239 : RuntimeCallTimer timer;
240 :
241 0 : Sleep(50);
242 0 : RuntimeCallStats::Enter(stats(), &timer, counter_id());
243 0 : EXPECT_EQ(counter(), timer.counter());
244 0 : EXPECT_EQ(nullptr, timer.parent());
245 0 : EXPECT_TRUE(timer.IsStarted());
246 0 : EXPECT_EQ(&timer, stats()->current_timer());
247 :
248 0 : Sleep(100);
249 :
250 0 : RuntimeCallStats::Leave(stats(), &timer);
251 0 : Sleep(50);
252 0 : EXPECT_FALSE(timer.IsStarted());
253 0 : EXPECT_EQ(1, counter()->count());
254 0 : EXPECT_IN_RANGE(100, counter()->time().InMilliseconds(), 100 + kEpsilonMs);
255 0 : }
256 :
257 13155 : TEST_F(RuntimeCallStatsTest, RuntimeCallTimerSubTimer) {
258 : RuntimeCallTimer timer;
259 : RuntimeCallTimer timer2;
260 :
261 0 : RuntimeCallStats::Enter(stats(), &timer, counter_id());
262 0 : EXPECT_TRUE(timer.IsStarted());
263 0 : EXPECT_FALSE(timer2.IsStarted());
264 0 : EXPECT_EQ(counter(), timer.counter());
265 0 : EXPECT_EQ(nullptr, timer.parent());
266 0 : EXPECT_EQ(&timer, stats()->current_timer());
267 :
268 0 : Sleep(50);
269 :
270 0 : RuntimeCallStats::Enter(stats(), &timer2, counter_id2());
271 : // timer 1 is paused, while timer 2 is active.
272 0 : EXPECT_TRUE(timer2.IsStarted());
273 0 : EXPECT_EQ(counter(), timer.counter());
274 0 : EXPECT_EQ(counter2(), timer2.counter());
275 0 : EXPECT_EQ(nullptr, timer.parent());
276 0 : EXPECT_EQ(&timer, timer2.parent());
277 0 : EXPECT_EQ(&timer2, stats()->current_timer());
278 :
279 0 : Sleep(100);
280 0 : RuntimeCallStats::Leave(stats(), &timer2);
281 :
282 : // The subtimer subtracts its time from the parent timer.
283 0 : EXPECT_TRUE(timer.IsStarted());
284 0 : EXPECT_FALSE(timer2.IsStarted());
285 0 : EXPECT_EQ(0, counter()->count());
286 0 : EXPECT_EQ(1, counter2()->count());
287 0 : EXPECT_EQ(0, counter()->time().InMilliseconds());
288 0 : EXPECT_IN_RANGE(100, counter2()->time().InMilliseconds(), 100 + kEpsilonMs);
289 0 : EXPECT_EQ(&timer, stats()->current_timer());
290 :
291 0 : Sleep(100);
292 :
293 0 : RuntimeCallStats::Leave(stats(), &timer);
294 0 : EXPECT_FALSE(timer.IsStarted());
295 0 : EXPECT_EQ(1, counter()->count());
296 0 : EXPECT_EQ(1, counter2()->count());
297 0 : EXPECT_IN_RANGE(150, counter()->time().InMilliseconds(), 150 + kEpsilonMs);
298 0 : EXPECT_IN_RANGE(100, counter2()->time().InMilliseconds(), 100 + kEpsilonMs);
299 0 : EXPECT_EQ(nullptr, stats()->current_timer());
300 0 : }
301 :
302 13155 : TEST_F(RuntimeCallStatsTest, RuntimeCallTimerRecursive) {
303 : RuntimeCallTimer timer;
304 : RuntimeCallTimer timer2;
305 :
306 0 : RuntimeCallStats::Enter(stats(), &timer, counter_id());
307 0 : EXPECT_EQ(counter(), timer.counter());
308 0 : EXPECT_EQ(nullptr, timer.parent());
309 0 : EXPECT_TRUE(timer.IsStarted());
310 0 : EXPECT_EQ(&timer, stats()->current_timer());
311 :
312 0 : RuntimeCallStats::Enter(stats(), &timer2, counter_id());
313 0 : EXPECT_EQ(counter(), timer2.counter());
314 0 : EXPECT_EQ(nullptr, timer.parent());
315 0 : EXPECT_EQ(&timer, timer2.parent());
316 0 : EXPECT_TRUE(timer2.IsStarted());
317 0 : EXPECT_EQ(&timer2, stats()->current_timer());
318 :
319 0 : Sleep(50);
320 :
321 0 : RuntimeCallStats::Leave(stats(), &timer2);
322 0 : EXPECT_EQ(nullptr, timer.parent());
323 0 : EXPECT_FALSE(timer2.IsStarted());
324 0 : EXPECT_TRUE(timer.IsStarted());
325 0 : EXPECT_EQ(1, counter()->count());
326 0 : EXPECT_IN_RANGE(50, counter()->time().InMilliseconds(), 50 + kEpsilonMs);
327 :
328 0 : Sleep(100);
329 :
330 0 : RuntimeCallStats::Leave(stats(), &timer);
331 0 : EXPECT_FALSE(timer.IsStarted());
332 0 : EXPECT_EQ(2, counter()->count());
333 0 : EXPECT_IN_RANGE(150, counter()->time().InMilliseconds(),
334 0 : 150 + 2 * kEpsilonMs);
335 0 : }
336 :
337 13155 : TEST_F(RuntimeCallStatsTest, RuntimeCallTimerScope) {
338 : {
339 0 : RuntimeCallTimerScope scope(stats(), counter_id());
340 0 : Sleep(50);
341 : }
342 0 : Sleep(100);
343 0 : EXPECT_EQ(1, counter()->count());
344 0 : EXPECT_IN_RANGE(50, counter()->time().InMilliseconds(), 50 + kEpsilonMs);
345 : {
346 0 : RuntimeCallTimerScope scope(stats(), counter_id());
347 0 : Sleep(50);
348 : }
349 0 : EXPECT_EQ(2, counter()->count());
350 0 : EXPECT_IN_RANGE(100, counter()->time().InMilliseconds(),
351 0 : 100 + 2 * kEpsilonMs);
352 0 : }
353 :
354 13155 : TEST_F(RuntimeCallStatsTest, RuntimeCallTimerScopeRecursive) {
355 : {
356 0 : RuntimeCallTimerScope scope(stats(), counter_id());
357 0 : Sleep(50);
358 0 : EXPECT_EQ(0, counter()->count());
359 0 : EXPECT_EQ(0, counter()->time().InMilliseconds());
360 : {
361 0 : RuntimeCallTimerScope scope(stats(), counter_id());
362 0 : Sleep(50);
363 : }
364 0 : EXPECT_EQ(1, counter()->count());
365 0 : EXPECT_IN_RANGE(50, counter()->time().InMilliseconds(), 50 + kEpsilonMs);
366 : }
367 0 : EXPECT_EQ(2, counter()->count());
368 0 : EXPECT_IN_RANGE(100, counter()->time().InMilliseconds(),
369 0 : 100 + 2 * kEpsilonMs);
370 0 : }
371 :
372 13155 : TEST_F(RuntimeCallStatsTest, RenameTimer) {
373 : {
374 0 : RuntimeCallTimerScope scope(stats(), counter_id());
375 0 : Sleep(50);
376 0 : EXPECT_EQ(0, counter()->count());
377 0 : EXPECT_EQ(0, counter2()->count());
378 0 : EXPECT_EQ(0, counter()->time().InMilliseconds());
379 0 : EXPECT_EQ(0, counter2()->time().InMilliseconds());
380 : {
381 0 : RuntimeCallTimerScope scope(stats(), counter_id());
382 0 : Sleep(100);
383 : }
384 0 : CHANGE_CURRENT_RUNTIME_COUNTER(stats(), TestCounter2);
385 0 : EXPECT_EQ(1, counter()->count());
386 0 : EXPECT_EQ(0, counter2()->count());
387 0 : EXPECT_IN_RANGE(100, counter()->time().InMilliseconds(), 100 + kEpsilonMs);
388 0 : EXPECT_IN_RANGE(0, counter2()->time().InMilliseconds(), 0);
389 : }
390 0 : EXPECT_EQ(1, counter()->count());
391 0 : EXPECT_EQ(1, counter2()->count());
392 0 : EXPECT_IN_RANGE(100, counter()->time().InMilliseconds(), 100 + kEpsilonMs);
393 0 : EXPECT_IN_RANGE(50, counter2()->time().InMilliseconds(), 50 + kEpsilonMs);
394 0 : }
395 :
396 13155 : TEST_F(RuntimeCallStatsTest, BasicPrintAndSnapshot) {
397 0 : std::ostringstream out;
398 0 : stats()->Print(out);
399 0 : EXPECT_EQ(0, counter()->count());
400 0 : EXPECT_EQ(0, counter2()->count());
401 0 : EXPECT_EQ(0, counter3()->count());
402 0 : EXPECT_EQ(0, counter()->time().InMilliseconds());
403 0 : EXPECT_EQ(0, counter2()->time().InMilliseconds());
404 0 : EXPECT_EQ(0, counter3()->time().InMilliseconds());
405 :
406 : {
407 0 : RuntimeCallTimerScope scope(stats(), counter_id());
408 0 : Sleep(50);
409 0 : stats()->Print(out);
410 : }
411 0 : stats()->Print(out);
412 0 : EXPECT_EQ(1, counter()->count());
413 0 : EXPECT_EQ(0, counter2()->count());
414 0 : EXPECT_EQ(0, counter3()->count());
415 0 : EXPECT_IN_RANGE(50, counter()->time().InMilliseconds(), 50 + kEpsilonMs);
416 0 : EXPECT_EQ(0, counter2()->time().InMilliseconds());
417 0 : EXPECT_EQ(0, counter3()->time().InMilliseconds());
418 0 : }
419 :
420 13155 : TEST_F(RuntimeCallStatsTest, PrintAndSnapshot) {
421 : {
422 0 : RuntimeCallTimerScope scope(stats(), counter_id());
423 0 : Sleep(100);
424 0 : EXPECT_EQ(0, counter()->count());
425 0 : EXPECT_EQ(0, counter()->time().InMilliseconds());
426 : {
427 0 : RuntimeCallTimerScope scope(stats(), counter_id2());
428 0 : EXPECT_EQ(0, counter2()->count());
429 0 : EXPECT_EQ(0, counter2()->time().InMilliseconds());
430 0 : Sleep(50);
431 :
432 : // This calls Snapshot on the current active timer and sychronizes and
433 : // commits the whole timer stack.
434 0 : std::ostringstream out;
435 0 : stats()->Print(out);
436 0 : EXPECT_EQ(0, counter()->count());
437 0 : EXPECT_EQ(0, counter2()->count());
438 0 : EXPECT_IN_RANGE(100, counter()->time().InMilliseconds(),
439 0 : 100 + kEpsilonMs);
440 0 : EXPECT_IN_RANGE(50, counter2()->time().InMilliseconds(), 50 + kEpsilonMs);
441 : // Calling Print several times shouldn't have a (big) impact on the
442 : // measured times.
443 0 : stats()->Print(out);
444 0 : EXPECT_EQ(0, counter()->count());
445 0 : EXPECT_EQ(0, counter2()->count());
446 0 : EXPECT_IN_RANGE(100, counter()->time().InMilliseconds(),
447 0 : 100 + kEpsilonMs);
448 0 : EXPECT_IN_RANGE(50, counter2()->time().InMilliseconds(), 50 + kEpsilonMs);
449 :
450 0 : Sleep(50);
451 0 : stats()->Print(out);
452 0 : EXPECT_EQ(0, counter()->count());
453 0 : EXPECT_EQ(0, counter2()->count());
454 0 : EXPECT_IN_RANGE(100, counter()->time().InMilliseconds(),
455 0 : 100 + kEpsilonMs);
456 0 : EXPECT_IN_RANGE(100, counter2()->time().InMilliseconds(),
457 0 : 100 + kEpsilonMs);
458 0 : Sleep(50);
459 : }
460 0 : Sleep(50);
461 0 : EXPECT_EQ(0, counter()->count());
462 0 : EXPECT_EQ(1, counter2()->count());
463 0 : EXPECT_IN_RANGE(100, counter()->time().InMilliseconds(), 100 + kEpsilonMs);
464 0 : EXPECT_IN_RANGE(150, counter2()->time().InMilliseconds(), 150 + kEpsilonMs);
465 0 : Sleep(50);
466 : }
467 0 : EXPECT_EQ(1, counter()->count());
468 0 : EXPECT_EQ(1, counter2()->count());
469 0 : EXPECT_IN_RANGE(200, counter()->time().InMilliseconds(), 200 + kEpsilonMs);
470 0 : EXPECT_IN_RANGE(150, counter2()->time().InMilliseconds(),
471 0 : 150 + 2 * kEpsilonMs);
472 0 : }
473 :
474 13155 : TEST_F(RuntimeCallStatsTest, NestedScopes) {
475 : {
476 0 : RuntimeCallTimerScope scope(stats(), counter_id());
477 0 : Sleep(100);
478 : {
479 0 : RuntimeCallTimerScope scope(stats(), counter_id2());
480 0 : Sleep(100);
481 : {
482 0 : RuntimeCallTimerScope scope(stats(), counter_id3());
483 0 : Sleep(50);
484 : }
485 0 : Sleep(50);
486 : {
487 0 : RuntimeCallTimerScope scope(stats(), counter_id3());
488 0 : Sleep(50);
489 : }
490 0 : Sleep(50);
491 : }
492 0 : Sleep(100);
493 : {
494 0 : RuntimeCallTimerScope scope(stats(), counter_id2());
495 0 : Sleep(100);
496 : }
497 0 : Sleep(50);
498 : }
499 0 : EXPECT_EQ(1, counter()->count());
500 0 : EXPECT_EQ(2, counter2()->count());
501 0 : EXPECT_EQ(2, counter3()->count());
502 0 : EXPECT_IN_RANGE(250, counter()->time().InMilliseconds(), 250 + kEpsilonMs);
503 0 : EXPECT_IN_RANGE(300, counter2()->time().InMilliseconds(), 300 + kEpsilonMs);
504 0 : EXPECT_IN_RANGE(100, counter3()->time().InMilliseconds(), 100 + kEpsilonMs);
505 0 : }
506 :
507 : } // namespace internal
508 7893 : } // namespace v8
|
