| /* |
| * Copyright (C) 2013-2014 The Android Open Source Project |
| * |
| * Licensed under the Apache License, Version 2.0 (the "License"); |
| * you may not use this file except in compliance with the License. |
| * You may obtain a copy of the License at |
| * |
| * http://www.apache.org/licenses/LICENSE-2.0 |
| * |
| * Unless required by applicable law or agreed to in writing, software |
| * distributed under the License is distributed on an "AS IS" BASIS, |
| * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. |
| * See the License for the specific language governing permissions and |
| * limitations under the License. |
| */ |
| |
| #include <sys/socket.h> |
| #include <cutils/sockets.h> |
| #include <log/log.h> |
| #include <log/logger.h> |
| #include <log/log_read.h> |
| |
| #include "benchmark.h" |
| |
| // enhanced version of LOG_FAILURE_RETRY to add support for EAGAIN and |
| // non-syscall libs. Since we are benchmarking, or using this in the emergency |
| // signal to stuff a terminating code, we do NOT want to introduce |
| // a syscall or usleep on EAGAIN retry. |
| #define LOG_FAILURE_RETRY(exp) ({ \ |
| typeof (exp) _rc; \ |
| do { \ |
| _rc = (exp); \ |
| } while (((_rc == -1) \ |
| && ((errno == EINTR) \ |
| || (errno == EAGAIN))) \ |
| || (_rc == -EINTR) \ |
| || (_rc == -EAGAIN)); \ |
| _rc; }) |
| |
| /* |
| * Measure the fastest rate we can reliabley stuff print messages into |
| * the log at high pressure. Expect this to be less than double the process |
| * wakeup time (2ms?) |
| */ |
| static void BM_log_maximum_retry(int iters) { |
| StartBenchmarkTiming(); |
| |
| for (int i = 0; i < iters; ++i) { |
| LOG_FAILURE_RETRY( |
| __android_log_print(ANDROID_LOG_INFO, |
| "BM_log_maximum_retry", "%d", i)); |
| } |
| |
| StopBenchmarkTiming(); |
| } |
| BENCHMARK(BM_log_maximum_retry); |
| |
| /* |
| * Measure the fastest rate we can stuff print messages into the log |
| * at high pressure. Expect this to be less than double the process wakeup |
| * time (2ms?) |
| */ |
| static void BM_log_maximum(int iters) { |
| StartBenchmarkTiming(); |
| |
| for (int i = 0; i < iters; ++i) { |
| __android_log_print(ANDROID_LOG_INFO, "BM_log_maximum", "%d", i); |
| } |
| |
| StopBenchmarkTiming(); |
| } |
| BENCHMARK(BM_log_maximum); |
| |
| /* |
| * Measure the time it takes to submit the android logging call using |
| * discrete acquisition under light load. Expect this to be a pair of |
| * syscall periods (2us). |
| */ |
| static void BM_clock_overhead(int iters) { |
| for (int i = 0; i < iters; ++i) { |
| StartBenchmarkTiming(); |
| StopBenchmarkTiming(); |
| } |
| } |
| BENCHMARK(BM_clock_overhead); |
| |
| /* |
| * Measure the time it takes to submit the android logging call using |
| * discrete acquisition under light load. Expect this to be a dozen or so |
| * syscall periods (40us). |
| */ |
| static void BM_log_overhead(int iters) { |
| for (int i = 0; i < iters; ++i) { |
| StartBenchmarkTiming(); |
| __android_log_print(ANDROID_LOG_INFO, "BM_log_overhead", "%d", i); |
| StopBenchmarkTiming(); |
| usleep(1000); |
| } |
| } |
| BENCHMARK(BM_log_overhead); |
| |
| static void caught_latency(int signum) |
| { |
| unsigned long long v = 0xDEADBEEFA55A5AA5ULL; |
| |
| LOG_FAILURE_RETRY(__android_log_btwrite(0, EVENT_TYPE_LONG, &v, sizeof(v))); |
| } |
| |
| static unsigned long long caught_convert(char *cp) |
| { |
| unsigned long long l = cp[0] & 0xFF; |
| l |= (unsigned long long) (cp[1] & 0xFF) << 8; |
| l |= (unsigned long long) (cp[2] & 0xFF) << 16; |
| l |= (unsigned long long) (cp[3] & 0xFF) << 24; |
| l |= (unsigned long long) (cp[4] & 0xFF) << 32; |
| l |= (unsigned long long) (cp[5] & 0xFF) << 40; |
| l |= (unsigned long long) (cp[6] & 0xFF) << 48; |
| l |= (unsigned long long) (cp[7] & 0xFF) << 56; |
| return l; |
| } |
| |
| static const int alarm_time = 3; |
| |
| /* |
| * Measure the time it takes for the logd posting call to acquire the |
| * timestamp to place into the internal record. Expect this to be less than |
| * 4 syscalls (3us). |
| */ |
| static void BM_log_latency(int iters) { |
| pid_t pid = getpid(); |
| |
| struct logger_list * logger_list = android_logger_list_open(LOG_ID_EVENTS, |
| O_RDONLY, 0, pid); |
| |
| if (!logger_list) { |
| fprintf(stderr, "Unable to open events log: %s\n", strerror(errno)); |
| exit(EXIT_FAILURE); |
| } |
| |
| signal(SIGALRM, caught_latency); |
| alarm(alarm_time); |
| |
| for (int j = 0, i = 0; i < iters && j < 10*iters; ++i, ++j) { |
| log_time ts; |
| LOG_FAILURE_RETRY(( |
| clock_gettime(CLOCK_REALTIME, &ts), |
| android_btWriteLog(0, EVENT_TYPE_LONG, &ts, sizeof(ts)))); |
| |
| for (;;) { |
| log_msg log_msg; |
| int ret = android_logger_list_read(logger_list, &log_msg); |
| alarm(alarm_time); |
| |
| if (ret <= 0) { |
| iters = i; |
| break; |
| } |
| if ((log_msg.entry.len != (4 + 1 + 8)) |
| || (log_msg.id() != LOG_ID_EVENTS)) { |
| continue; |
| } |
| |
| char* eventData = log_msg.msg(); |
| |
| if (eventData[4] != EVENT_TYPE_LONG) { |
| continue; |
| } |
| log_time tx(eventData + 4 + 1); |
| if (ts != tx) { |
| if (0xDEADBEEFA55A5AA5ULL == caught_convert(eventData + 4 + 1)) { |
| iters = i; |
| break; |
| } |
| continue; |
| } |
| |
| uint64_t start = ts.nsec(); |
| uint64_t end = log_msg.nsec(); |
| if (end >= start) { |
| StartBenchmarkTiming(start); |
| StopBenchmarkTiming(end); |
| } else { |
| --i; |
| } |
| break; |
| } |
| } |
| |
| signal(SIGALRM, SIG_DFL); |
| alarm(0); |
| |
| android_logger_list_free(logger_list); |
| } |
| BENCHMARK(BM_log_latency); |
| |
| static void caught_delay(int signum) |
| { |
| unsigned long long v = 0xDEADBEEFA55A5AA6ULL; |
| |
| LOG_FAILURE_RETRY(__android_log_btwrite(0, EVENT_TYPE_LONG, &v, sizeof(v))); |
| } |
| |
| /* |
| * Measure the time it takes for the logd posting call to make it into |
| * the logs. Expect this to be less than double the process wakeup time (2ms). |
| */ |
| static void BM_log_delay(int iters) { |
| pid_t pid = getpid(); |
| |
| struct logger_list * logger_list = android_logger_list_open(LOG_ID_EVENTS, |
| O_RDONLY, 0, pid); |
| |
| if (!logger_list) { |
| fprintf(stderr, "Unable to open events log: %s\n", strerror(errno)); |
| exit(EXIT_FAILURE); |
| } |
| |
| signal(SIGALRM, caught_delay); |
| alarm(alarm_time); |
| |
| StartBenchmarkTiming(); |
| |
| for (int i = 0; i < iters; ++i) { |
| log_time ts(CLOCK_REALTIME); |
| |
| LOG_FAILURE_RETRY( |
| android_btWriteLog(0, EVENT_TYPE_LONG, &ts, sizeof(ts))); |
| |
| for (;;) { |
| log_msg log_msg; |
| int ret = android_logger_list_read(logger_list, &log_msg); |
| alarm(alarm_time); |
| |
| if (ret <= 0) { |
| iters = i; |
| break; |
| } |
| if ((log_msg.entry.len != (4 + 1 + 8)) |
| || (log_msg.id() != LOG_ID_EVENTS)) { |
| continue; |
| } |
| |
| char* eventData = log_msg.msg(); |
| |
| if (eventData[4] != EVENT_TYPE_LONG) { |
| continue; |
| } |
| log_time tx(eventData + 4 + 1); |
| if (ts != tx) { |
| if (0xDEADBEEFA55A5AA6ULL == caught_convert(eventData + 4 + 1)) { |
| iters = i; |
| break; |
| } |
| continue; |
| } |
| |
| break; |
| } |
| } |
| |
| signal(SIGALRM, SIG_DFL); |
| alarm(0); |
| |
| StopBenchmarkTiming(); |
| |
| android_logger_list_free(logger_list); |
| } |
| BENCHMARK(BM_log_delay); |