diff --git a/liblog/tests/liblog_benchmark.cpp b/liblog/tests/liblog_benchmark.cpp index 3f795526c..c4bf95962 100644 --- a/liblog/tests/liblog_benchmark.cpp +++ b/liblog/tests/liblog_benchmark.cpp @@ -527,11 +527,13 @@ BENCHMARK(BM_log_print_overhead); /* * Measure the time it takes to submit the android event logging call * using discrete acquisition (StartBenchmarkTiming() -> StopBenchmarkTiming()) - * under light load. Expect this to be a dozen or so syscall periods (40us) + * under light load. Expect this to be a long path to logger to convert the + * unknown tag (0) into a tagname (less than 200us). */ static void BM_log_event_overhead(int iters) { for (unsigned long long i = 0; i < (unsigned)iters; ++i) { StartBenchmarkTiming(); + // log tag number 0 is not known, nor shall it ever be known __android_log_btwrite(0, EVENT_TYPE_LONG, &i, sizeof(i)); StopBenchmarkTiming(); logd_yield(); @@ -539,6 +541,28 @@ static void BM_log_event_overhead(int iters) { } BENCHMARK(BM_log_event_overhead); +/* + * Measure the time it takes to submit the android event logging call + * using discrete acquisition (StartBenchmarkTiming() -> StopBenchmarkTiming()) + * under light load with a known logtag. Expect this to be a dozen or so + * syscall periods (less than 40us) + */ +static void BM_log_event_overhead_42(int iters) { + for (unsigned long long i = 0; i < (unsigned)iters; ++i) { + StartBenchmarkTiming(); + // In system/core/logcat/event.logtags: + // # These are used for testing, do not modify without updating + // # tests/framework-tests/src/android/util/EventLogFunctionalTest.java. + // # system/core/liblog/tests/liblog_benchmark.cpp + // # system/core/liblog/tests/liblog_test.cpp + // 42 answer (to life the universe etc|3) + __android_log_btwrite(42, EVENT_TYPE_LONG, &i, sizeof(i)); + StopBenchmarkTiming(); + logd_yield(); + } +} +BENCHMARK(BM_log_event_overhead_42); + static void BM_log_event_overhead_null(int iters) { set_log_null(); BM_log_event_overhead(iters); diff --git a/logcat/event.logtags b/logcat/event.logtags index 909f8e200..9f053511b 100644 --- a/logcat/event.logtags +++ b/logcat/event.logtags @@ -36,6 +36,8 @@ # These are used for testing, do not modify without updating # tests/framework-tests/src/android/util/EventLogFunctionalTest.java. +# system/core/liblog/tests/liblog_benchmark.cpp +# system/core/liblog/tests/liblog_test.cpp 42 answer (to life the universe etc|3) 314 pi 2718 e diff --git a/logd/tests/logd_test.cpp b/logd/tests/logd_test.cpp index ddff39350..d0101edf6 100644 --- a/logd/tests/logd_test.cpp +++ b/logd/tests/logd_test.cpp @@ -426,7 +426,7 @@ TEST(logd, benchmark) { " BM_log_maximum_retry" " BM_log_maximum" " BM_clock_overhead" - " BM_log_overhead" + " BM_log_print_overhead" " BM_log_latency" " BM_log_delay", "r"))); @@ -434,13 +434,13 @@ TEST(logd, benchmark) { char buffer[5120]; static const char* benchmarks[] = { - "BM_log_maximum_retry ", "BM_log_maximum ", "BM_clock_overhead ", - "BM_log_overhead ", "BM_log_latency ", "BM_log_delay " + "BM_log_maximum_retry ", "BM_log_maximum ", "BM_clock_overhead ", + "BM_log_print_overhead ", "BM_log_latency ", "BM_log_delay " }; static const unsigned int log_maximum_retry = 0; static const unsigned int log_maximum = 1; static const unsigned int clock_overhead = 2; - static const unsigned int log_overhead = 3; + static const unsigned int log_print_overhead = 3; static const unsigned int log_latency = 4; static const unsigned int log_delay = 5; @@ -469,21 +469,23 @@ TEST(logd, benchmark) { } EXPECT_GE(200000UL, ns[log_maximum_retry]); // 104734 user + EXPECT_NE(0UL, ns[log_maximum_retry]); // failure to parse EXPECT_GE(90000UL, ns[log_maximum]); // 46913 user + EXPECT_NE(0UL, ns[log_maximum]); // failure to parse EXPECT_GE(4096UL, ns[clock_overhead]); // 4095 + EXPECT_NE(0UL, ns[clock_overhead]); // failure to parse - EXPECT_GE(250000UL, ns[log_overhead]); // 126886 user + EXPECT_GE(250000UL, ns[log_print_overhead]); // 126886 user + EXPECT_NE(0UL, ns[log_print_overhead]); // failure to parse EXPECT_GE(10000000UL, ns[log_latency]); // 1453559 user space (background cgroup) + EXPECT_NE(0UL, ns[log_latency]); // failure to parse EXPECT_GE(20000000UL, ns[log_delay]); // 10500289 user - - for (unsigned i = 0; i < arraysize(ns); ++i) { - EXPECT_NE(0UL, ns[i]); - } + EXPECT_NE(0UL, ns[log_delay]); // failure to parse alloc_statistics(&buf, &len);