diff options
Diffstat (limited to 'logcat')
| -rw-r--r-- | logcat/Android.mk | 4 | ||||
| -rw-r--r-- | logcat/logcat.cpp | 285 | ||||
| -rw-r--r-- | logcat/tests/Android.mk | 31 | ||||
| -rw-r--r-- | logcat/tests/logcat_benchmark.cpp | 128 | ||||
| -rw-r--r-- | logcat/tests/logcat_test.cpp | 428 |
5 files changed, 731 insertions, 145 deletions
diff --git a/logcat/Android.mk b/logcat/Android.mk index b5e27eb..f46a4de 100644 --- a/logcat/Android.mk +++ b/logcat/Android.mk @@ -7,7 +7,9 @@ LOCAL_SRC_FILES:= logcat.cpp event.logtags LOCAL_SHARED_LIBRARIES := liblog -LOCAL_MODULE:= logcat +LOCAL_MODULE := logcat + +LOCAL_CFLAGS := -Werror include $(BUILD_EXECUTABLE) diff --git a/logcat/logcat.cpp b/logcat/logcat.cpp index 3c33938..7c6af42 100644 --- a/logcat/logcat.cpp +++ b/logcat/logcat.cpp @@ -17,6 +17,7 @@ #include <cutils/sockets.h> #include <log/log.h> +#include <log/log_read.h> #include <log/logger.h> #include <log/logd.h> #include <log/logprint.h> @@ -225,11 +226,21 @@ static void show_help(const char *cmd) " -t <count> print only the most recent <count> lines (implies -d)\n" " -T <count> print only the most recent <count> lines (does not imply -d)\n" " -g get the size of the log's ring buffer and exit\n" - " -b <buffer> Request alternate ring buffer, 'main', 'system', 'radio'\n" - " or 'events'. Multiple -b parameters are allowed and the\n" - " results are interleaved. The default is -b main -b system.\n" - " -B output the log in binary"); - + " -b <buffer> Request alternate ring buffer, 'main', 'system', 'radio',\n" + " 'events', 'crash' or 'all'. Multiple -b parameters are\n" + " allowed and results are interleaved. The default is\n" + " -b main -b system -b crash.\n" + " -B output the log in binary.\n" + " -S output statistics.\n" + " -G <size> set size of log ring buffer, may suffix with K or M.\n" + " -p print prune white and ~black list. Service is specified as\n" + " UID, UID/PID or /PID. Weighed for quicker pruning if prefix\n" + " with ~, otherwise weighed for longevity if unadorned. All\n" + " other pruning activity is oldest first. Special case ~!\n" + " represents an automatic quicker pruning for the noisiest\n" + " UID as determined by the current statistics.\n" + " -P '<list> ...' set prune white and ~black list, using same format as\n" + " printed above. Must be quoted.\n"); fprintf(stderr,"\nfilterspecs are a series of \n" " <tag>[:priority]\n\n" @@ -270,7 +281,29 @@ static int setLogFormat(const char * formatString) return 0; } -extern "C" void logprint_run_tests(void); +static const char multipliers[][2] = { + { "" }, + { "K" }, + { "M" }, + { "G" } +}; + +static unsigned long value_of_size(unsigned long value) +{ + for (unsigned i = 0; + (i < sizeof(multipliers)/sizeof(multipliers[0])) && (value >= 1024); + value /= 1024, ++i) ; + return value; +} + +static const char *multiplier_of_size(unsigned long value) +{ + unsigned i; + for (i = 0; + (i < sizeof(multipliers)/sizeof(multipliers[0])) && (value >= 1024); + value /= 1024, ++i) ; + return multipliers[i]; +} int main(int argc, char **argv) { @@ -278,23 +311,23 @@ int main(int argc, char **argv) int hasSetLogFormat = 0; int clearLog = 0; int getLogSize = 0; + unsigned long setLogSize = 0; + int getPruneList = 0; + char *setPruneList = NULL; + int printStatistics = 0; int mode = O_RDONLY; const char *forceFilters = NULL; log_device_t* devices = NULL; log_device_t* dev; bool needBinary = false; struct logger_list *logger_list; - int tail_lines = 0; + unsigned int tail_lines = 0; + log_time tail_time(log_time::EPOCH); signal(SIGPIPE, exit); g_logformat = android_log_format_new(); - if (argc == 2 && 0 == strcmp(argv[1], "--test")) { - logprint_run_tests(); - exit(0); - } - if (argc == 2 && 0 == strcmp(argv[1], "--help")) { android::show_help(argv[0]); exit(0); @@ -303,7 +336,7 @@ int main(int argc, char **argv) for (;;) { int ret; - ret = getopt(argc, argv, "cdt:T:gsQf:r::n:v:b:B"); + ret = getopt(argc, argv, "cdt:T:gG:sQf:r:n:v:b:BSpP:"); if (ret < 0) { break; @@ -328,14 +361,124 @@ int main(int argc, char **argv) mode = O_RDONLY | O_NDELAY; /* FALLTHRU */ case 'T': - tail_lines = atoi(optarg); + if (strspn(optarg, "0123456789") != strlen(optarg)) { + char *cp = tail_time.strptime(optarg, + log_time::default_format); + if (!cp) { + fprintf(stderr, + "ERROR: -%c \"%s\" not in \"%s\" time format\n", + ret, optarg, log_time::default_format); + exit(1); + } + if (*cp) { + char c = *cp; + *cp = '\0'; + fprintf(stderr, + "WARNING: -%c \"%s\"\"%c%s\" time truncated\n", + ret, optarg, c, cp + 1); + *cp = c; + } + } else { + tail_lines = atoi(optarg); + if (!tail_lines) { + fprintf(stderr, + "WARNING: -%c %s invalid, setting to 1\n", + ret, optarg); + tail_lines = 1; + } + } break; case 'g': getLogSize = 1; break; + case 'G': { + // would use atol if not for the multiplier + char *cp = optarg; + setLogSize = 0; + while (('0' <= *cp) && (*cp <= '9')) { + setLogSize *= 10; + setLogSize += *cp - '0'; + ++cp; + } + + switch(*cp) { + case 'g': + case 'G': + setLogSize *= 1024; + /* FALLTHRU */ + case 'm': + case 'M': + setLogSize *= 1024; + /* FALLTHRU */ + case 'k': + case 'K': + setLogSize *= 1024; + /* FALLTHRU */ + case '\0': + break; + + default: + setLogSize = 0; + } + + if (!setLogSize) { + fprintf(stderr, "ERROR: -G <num><multiplier>\n"); + exit(1); + } + } + break; + + case 'p': + getPruneList = 1; + break; + + case 'P': + setPruneList = optarg; + break; + case 'b': { + if (strcmp(optarg, "all") == 0) { + while (devices) { + dev = devices; + devices = dev->next; + delete dev; + } + + dev = devices = new log_device_t("main", false, 'm'); + android::g_devCount = 1; + if (android_name_to_log_id("system") == LOG_ID_SYSTEM) { + dev->next = new log_device_t("system", false, 's'); + if (dev->next) { + dev = dev->next; + android::g_devCount++; + } + } + if (android_name_to_log_id("radio") == LOG_ID_RADIO) { + dev->next = new log_device_t("radio", false, 'r'); + if (dev->next) { + dev = dev->next; + android::g_devCount++; + } + } + if (android_name_to_log_id("events") == LOG_ID_EVENTS) { + dev->next = new log_device_t("events", true, 'e'); + if (dev->next) { + dev = dev->next; + android::g_devCount++; + needBinary = true; + } + } + if (android_name_to_log_id("crash") == LOG_ID_CRASH) { + dev->next = new log_device_t("crash", false, 'c'); + if (dev->next) { + android::g_devCount++; + } + } + break; + } + bool binary = strcmp(optarg, "events") == 0; if (binary) { needBinary = true; @@ -370,9 +513,6 @@ int main(int argc, char **argv) android::g_logRotateSizeKBytes = DEFAULT_LOG_ROTATE_SIZE_KBYTES; } else { - long logRotateSize; - char *lastDigit; - if (!isdigit(optarg[0])) { fprintf(stderr,"Invalid parameter to -r\n"); android::show_help(argv[0]); @@ -470,6 +610,10 @@ int main(int argc, char **argv) } break; + case 'S': + printStatistics = 1; + break; + default: fprintf(stderr,"Unrecognized Option\n"); android::show_help(argv[0]); @@ -479,10 +623,14 @@ int main(int argc, char **argv) } if (!devices) { - devices = new log_device_t("main", false, 'm'); + dev = devices = new log_device_t("main", false, 'm'); android::g_devCount = 1; if (android_name_to_log_id("system") == LOG_ID_SYSTEM) { - devices->next = new log_device_t("system", false, 's'); + dev = dev->next = new log_device_t("system", false, 's'); + android::g_devCount++; + } + if (android_name_to_log_id("crash") == LOG_ID_CRASH) { + dev = dev->next = new log_device_t("crash", false, 'c'); android::g_devCount++; } } @@ -544,7 +692,11 @@ int main(int argc, char **argv) } dev = devices; - logger_list = android_logger_list_alloc(mode, tail_lines, 0); + if (tail_time != log_time::EPOCH) { + logger_list = android_logger_list_alloc_time(mode, tail_time, 0); + } else { + logger_list = android_logger_list_alloc(mode, tail_lines, 0); + } while (dev) { dev->logger_list = logger_list; dev->logger = android_logger_open(logger_list, @@ -558,38 +710,117 @@ int main(int argc, char **argv) int ret; ret = android_logger_clear(dev->logger); if (ret) { - perror("clearLog"); + perror("failed to clear the log"); exit(EXIT_FAILURE); } } + if (setLogSize && android_logger_set_log_size(dev->logger, setLogSize)) { + perror("failed to set the log size"); + exit(EXIT_FAILURE); + } + if (getLogSize) { - int size, readable; + long size, readable; size = android_logger_get_log_size(dev->logger); if (size < 0) { - perror("getLogSize"); + perror("failed to get the log size"); exit(EXIT_FAILURE); } readable = android_logger_get_log_readable_size(dev->logger); if (readable < 0) { - perror("getLogReadableSize"); + perror("failed to get the readable log size"); exit(EXIT_FAILURE); } - printf("%s: ring buffer is %dKb (%dKb consumed), " + printf("%s: ring buffer is %ld%sb (%ld%sb consumed), " "max entry is %db, max payload is %db\n", dev->device, - size / 1024, readable / 1024, + value_of_size(size), multiplier_of_size(size), + value_of_size(readable), multiplier_of_size(readable), (int) LOGGER_ENTRY_MAX_LEN, (int) LOGGER_ENTRY_MAX_PAYLOAD); } dev = dev->next; } + if (setPruneList) { + size_t len = strlen(setPruneList) + 32; // margin to allow rc + char *buf = (char *) malloc(len); + + strcpy(buf, setPruneList); + int ret = android_logger_set_prune_list(logger_list, buf, len); + free(buf); + + if (ret) { + perror("failed to set the prune list"); + exit(EXIT_FAILURE); + } + } + + if (printStatistics || getPruneList) { + size_t len = 8192; + char *buf; + + for(int retry = 32; + (retry >= 0) && ((buf = new char [len])); + delete [] buf, --retry) { + if (getPruneList) { + android_logger_get_prune_list(logger_list, buf, len); + } else { + android_logger_get_statistics(logger_list, buf, len); + } + buf[len-1] = '\0'; + size_t ret = atol(buf) + 1; + if (ret < 4) { + delete [] buf; + buf = NULL; + break; + } + bool check = ret <= len; + len = ret; + if (check) { + break; + } + } + + if (!buf) { + perror("failed to read data"); + exit(EXIT_FAILURE); + } + + // remove trailing FF + char *cp = buf + len - 1; + *cp = '\0'; + bool truncated = *--cp != '\f'; + if (!truncated) { + *cp = '\0'; + } + + // squash out the byte count + cp = buf; + if (!truncated) { + while (isdigit(*cp)) { + ++cp; + } + if (*cp == '\n') { + ++cp; + } + } + + printf("%s", cp); + delete [] buf; + exit(0); + } + + if (getLogSize) { exit(0); } + if (setLogSize || setPruneList) { + exit(0); + } if (clearLog) { exit(0); } @@ -623,7 +854,7 @@ int main(int argc, char **argv) fprintf(stderr, "read: unexpected length.\n"); exit(EXIT_FAILURE); } - perror("logcat read"); + perror("logcat read failure"); exit(EXIT_FAILURE); } diff --git a/logcat/tests/Android.mk b/logcat/tests/Android.mk index bdaec14..015a23d 100644 --- a/logcat/tests/Android.mk +++ b/logcat/tests/Android.mk @@ -16,11 +16,7 @@ LOCAL_PATH := $(call my-dir) -# ----------------------------------------------------------------------------- -# Unit tests. -# ----------------------------------------------------------------------------- - -test_module := logcat-unit-tests +test_module_prefix := logcat- test_tags := tests test_c_flags := \ @@ -29,6 +25,28 @@ test_c_flags := \ -Wall -Wextra \ -Werror \ -fno-builtin \ + -std=gnu++11 + +# ----------------------------------------------------------------------------- +# Benchmarks (actually a gTest where the result code does not matter) +# ---------------------------------------------------------------------------- + +benchmark_src_files := \ + logcat_benchmark.cpp + +# Build benchmarks for the device. Run with: +# adb shell /data/nativetest/logcat-benchmarks/logcat-benchmarks +include $(CLEAR_VARS) +LOCAL_MODULE := $(test_module_prefix)benchmarks +LOCAL_MODULE_TAGS := $(test_tags) +LOCAL_ADDITIONAL_DEPENDENCIES := $(LOCAL_PATH)/Android.mk +LOCAL_CFLAGS += $(test_c_flags) +LOCAL_SRC_FILES := $(benchmark_src_files) +include $(BUILD_NATIVE_TEST) + +# ----------------------------------------------------------------------------- +# Unit tests. +# ----------------------------------------------------------------------------- test_src_files := \ logcat_test.cpp \ @@ -36,11 +54,10 @@ test_src_files := \ # Build tests for the device (with .so). Run with: # adb shell /data/nativetest/logcat-unit-tests/logcat-unit-tests include $(CLEAR_VARS) -LOCAL_MODULE := $(test_module) +LOCAL_MODULE := $(test_module_prefix)unit-tests LOCAL_MODULE_TAGS := $(test_tags) LOCAL_ADDITIONAL_DEPENDENCIES := $(LOCAL_PATH)/Android.mk LOCAL_CFLAGS += $(test_c_flags) -LOCAL_LDLIBS := -lpthread LOCAL_SHARED_LIBRARIES := liblog LOCAL_SRC_FILES := $(test_src_files) include $(BUILD_NATIVE_TEST) diff --git a/logcat/tests/logcat_benchmark.cpp b/logcat/tests/logcat_benchmark.cpp new file mode 100644 index 0000000..be815be --- /dev/null +++ b/logcat/tests/logcat_benchmark.cpp @@ -0,0 +1,128 @@ +/* + * 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 <stdio.h> +#include <stdlib.h> +#include <string.h> + +#include <gtest/gtest.h> + +static const char begin[] = "--------- beginning of "; + +TEST(logcat, sorted_order) { + FILE *fp; + + ASSERT_TRUE(NULL != (fp = popen( + "logcat -v time -b radio -b events -b system -b main -d 2>/dev/null", + "r"))); + + class timestamp { + private: + int month; + int day; + int hour; + int minute; + int second; + int millisecond; + bool ok; + + public: + void init(const char *buffer) + { + ok = false; + if (buffer != NULL) { + ok = sscanf(buffer, "%d-%d %d:%d:%d.%d ", + &month, &day, &hour, &minute, &second, &millisecond) == 6; + } + } + + timestamp(const char *buffer) + { + init(buffer); + } + + bool operator< (timestamp &T) + { + return !ok || !T.ok + || (month < T.month) + || ((month == T.month) + && ((day < T.day) + || ((day == T.day) + && ((hour < T.hour) + || ((hour == T.hour) + && ((minute < T.minute) + || ((minute == T.minute) + && ((second < T.second) + || ((second == T.second) + && (millisecond < T.millisecond)))))))))); + } + + bool valid(void) + { + return ok; + } + } last(NULL); + + char *last_buffer = NULL; + char buffer[5120]; + + int count = 0; + int next_lt_last = 0; + + while (fgets(buffer, sizeof(buffer), fp)) { + if (!strncmp(begin, buffer, sizeof(begin) - 1)) { + continue; + } + if (!last.valid()) { + free(last_buffer); + last_buffer = strdup(buffer); + last.init(buffer); + } + timestamp next(buffer); + if (next < last) { + if (last_buffer) { + fprintf(stderr, "<%s", last_buffer); + } + fprintf(stderr, ">%s", buffer); + ++next_lt_last; + } + if (next.valid()) { + free(last_buffer); + last_buffer = strdup(buffer); + last.init(buffer); + } + ++count; + } + free(last_buffer); + + pclose(fp); + + static const int max_ok = 2; + + // Allow few fails, happens with readers active + fprintf(stderr, "%s: %d/%d out of order entries\n", + (next_lt_last) + ? ((next_lt_last <= max_ok) + ? "WARNING" + : "ERROR") + : "INFO", + next_lt_last, count); + + EXPECT_GE(max_ok, next_lt_last); + + // sample statistically too small + EXPECT_LT(100, count); +} diff --git a/logcat/tests/logcat_test.cpp b/logcat/tests/logcat_test.cpp index f963a3a..9b316d1 100644 --- a/logcat/tests/logcat_test.cpp +++ b/logcat/tests/logcat_test.cpp @@ -14,8 +14,12 @@ * limitations under the License. */ +#include <ctype.h> #include <signal.h> #include <stdio.h> +#include <stdlib.h> +#include <string.h> + #include <gtest/gtest.h> #include <log/log.h> #include <log/logger.h> @@ -38,88 +42,10 @@ static const char begin[] = "--------- beginning of "; -TEST(logcat, sorted_order) { - FILE *fp; - - ASSERT_EQ(0, NULL == (fp = popen( - "logcat -v time -b radio -b events -b system -b main -d 2>/dev/null", - "r"))); - - class timestamp { - private: - int month; - int day; - int hour; - int minute; - int second; - int millisecond; - bool ok; - - public: - void init(const char *buffer) - { - ok = false; - if (buffer != NULL) { - ok = sscanf(buffer, "%d-%d %d:%d:%d.%d ", - &month, &day, &hour, &minute, &second, &millisecond) == 6; - } - } - - timestamp(const char *buffer) - { - init(buffer); - } - - bool operator< (timestamp &T) - { - return !ok || !T.ok - || (month < T.month) - || ((month == T.month) - && ((day < T.day) - || ((day == T.day) - && ((hour < T.hour) - || ((hour == T.hour) - && ((minute < T.minute) - || ((minute == T.minute) - && ((second < T.second) - || ((second == T.second) - && (millisecond < T.millisecond)))))))))); - } - - bool valid(void) - { - return ok; - } - } last(NULL); - - char buffer[5120]; - - int count = 0; - - while (fgets(buffer, sizeof(buffer), fp)) { - if (!strncmp(begin, buffer, sizeof(begin) - 1)) { - continue; - } - if (!last.valid()) { - last.init(buffer); - } - timestamp next(buffer); - ASSERT_EQ(0, next < last); - if (next.valid()) { - last.init(buffer); - } - ++count; - } - - pclose(fp); - - ASSERT_LT(100, count); -} - TEST(logcat, buckets) { FILE *fp; - ASSERT_EQ(0, NULL == (fp = popen( + ASSERT_TRUE(NULL != (fp = popen( "logcat -b radio -b events -b system -b main -d 2>/dev/null", "r"))); @@ -141,15 +67,15 @@ TEST(logcat, buckets) { pclose(fp); - ASSERT_EQ(15, ids); + EXPECT_EQ(15, ids); - ASSERT_EQ(4, count); + EXPECT_EQ(4, count); } TEST(logcat, tail_3) { FILE *fp; - ASSERT_EQ(0, NULL == (fp = popen( + ASSERT_TRUE(NULL != (fp = popen( "logcat -v long -b radio -b events -b system -b main -t 3 2>/dev/null", "r"))); @@ -173,7 +99,7 @@ TEST(logcat, tail_3) { TEST(logcat, tail_10) { FILE *fp; - ASSERT_EQ(0, NULL == (fp = popen( + ASSERT_TRUE(NULL != (fp = popen( "logcat -v long -b radio -b events -b system -b main -t 10 2>/dev/null", "r"))); @@ -197,7 +123,7 @@ TEST(logcat, tail_10) { TEST(logcat, tail_100) { FILE *fp; - ASSERT_EQ(0, NULL == (fp = popen( + ASSERT_TRUE(NULL != (fp = popen( "logcat -v long -b radio -b events -b system -b main -t 100 2>/dev/null", "r"))); @@ -221,7 +147,7 @@ TEST(logcat, tail_100) { TEST(logcat, tail_1000) { FILE *fp; - ASSERT_EQ(0, NULL == (fp = popen( + ASSERT_TRUE(NULL != (fp = popen( "logcat -v long -b radio -b events -b system -b main -t 1000 2>/dev/null", "r"))); @@ -242,6 +168,72 @@ TEST(logcat, tail_1000) { ASSERT_EQ(1000, count); } +TEST(logcat, tail_time) { + FILE *fp; + + ASSERT_TRUE(NULL != (fp = popen("logcat -v long -b all -t 10 2>&1", "r"))); + + char buffer[5120]; + char *last_timestamp = NULL; + char *first_timestamp = NULL; + int count = 0; + const unsigned int time_length = 18; + const unsigned int time_offset = 2; + + while (fgets(buffer, sizeof(buffer), fp)) { + if ((buffer[0] == '[') && (buffer[1] == ' ') + && isdigit(buffer[time_offset]) && isdigit(buffer[time_offset + 1]) + && (buffer[time_offset + 2] == '-')) { + ++count; + buffer[time_length + time_offset] = '\0'; + if (!first_timestamp) { + first_timestamp = strdup(buffer + time_offset); + } + free(last_timestamp); + last_timestamp = strdup(buffer + time_offset); + } + } + pclose(fp); + + EXPECT_EQ(10, count); + EXPECT_TRUE(last_timestamp != NULL); + EXPECT_TRUE(first_timestamp != NULL); + + snprintf(buffer, sizeof(buffer), "logcat -v long -b all -t '%s' 2>&1", + first_timestamp); + ASSERT_TRUE(NULL != (fp = popen(buffer, "r"))); + + int second_count = 0; + int last_timestamp_count = -1; + + while (fgets(buffer, sizeof(buffer), fp)) { + if ((buffer[0] == '[') && (buffer[1] == ' ') + && isdigit(buffer[time_offset]) && isdigit(buffer[time_offset + 1]) + && (buffer[time_offset + 2] == '-')) { + ++second_count; + buffer[time_length + time_offset] = '\0'; + if (first_timestamp) { + // we can get a transitory *extremely* rare failure if hidden + // underneath the time is *exactly* XX-XX XX:XX:XX.XXX000000 + EXPECT_STREQ(buffer + time_offset, first_timestamp); + free(first_timestamp); + first_timestamp = NULL; + } + if (!strcmp(buffer + time_offset, last_timestamp)) { + last_timestamp_count = second_count; + } + } + } + pclose(fp); + + free(last_timestamp); + last_timestamp = NULL; + + EXPECT_TRUE(first_timestamp == NULL); + EXPECT_LE(count, second_count); + EXPECT_LE(count, last_timestamp_count); +} + TEST(logcat, End_to_End) { pid_t pid = getpid(); @@ -250,7 +242,7 @@ TEST(logcat, End_to_End) { ASSERT_LT(0, __android_log_btwrite(0, EVENT_TYPE_LONG, &ts, sizeof(ts))); FILE *fp; - ASSERT_EQ(0, NULL == (fp = popen( + ASSERT_TRUE(NULL != (fp = popen( "logcat -b events -t 100 2>/dev/null", "r"))); @@ -278,10 +270,11 @@ TEST(logcat, End_to_End) { ASSERT_EQ(1, count); } -TEST(logcat, get_) { +TEST(logcat, get_size) { FILE *fp; - ASSERT_EQ(0, NULL == (fp = popen( + // NB: crash log only available in user space + ASSERT_TRUE(NULL != (fp = popen( "logcat -b radio -b events -b system -b main -g 2>/dev/null", "r"))); @@ -291,13 +284,49 @@ TEST(logcat, get_) { while (fgets(buffer, sizeof(buffer), fp)) { int size, consumed, max, payload; + char size_mult, consumed_mult; + long full_size, full_consumed; size = consumed = max = payload = 0; - if ((4 == sscanf(buffer, "%*s ring buffer is %dKb (%dKb consumed)," - " max entry is %db, max payload is %db", - &size, &consumed, &max, &payload)) - && ((size * 3) >= consumed) - && ((size * 1024) > max) + // NB: crash log can be very small, not hit a Kb of consumed space + // doubly lucky we are not including it. + if (6 != sscanf(buffer, "%*s ring buffer is %d%cb (%d%cb consumed)," + " max entry is %db, max payload is %db", + &size, &size_mult, &consumed, &consumed_mult, + &max, &payload)) { + fprintf(stderr, "WARNING: Parse error: %s", buffer); + continue; + } + full_size = size; + switch(size_mult) { + case 'G': + full_size *= 1024; + /* FALLTHRU */ + case 'M': + full_size *= 1024; + /* FALLTHRU */ + case 'K': + full_size *= 1024; + break; + } + full_consumed = consumed; + switch(consumed_mult) { + case 'G': + full_consumed *= 1024; + /* FALLTHRU */ + case 'M': + full_consumed *= 1024; + /* FALLTHRU */ + case 'K': + full_consumed *= 1024; + break; + } + EXPECT_GT((full_size * 9) / 4, full_consumed); + EXPECT_GT(full_size, max); + EXPECT_GT(max, payload); + + if ((((full_size * 9) / 4) >= full_consumed) + && (full_size > max) && (max > payload)) { ++count; } @@ -308,7 +337,7 @@ TEST(logcat, get_) { ASSERT_EQ(4, count); } -static void caught_blocking(int signum) +static void caught_blocking(int /*signum*/) { unsigned long long v = 0xDEADBEEFA55A0000ULL; @@ -319,13 +348,17 @@ static void caught_blocking(int signum) TEST(logcat, blocking) { FILE *fp; - unsigned long long v = 0xDEADBEEFA55A0000ULL; + unsigned long long v = 0xDEADBEEFA55F0000ULL; pid_t pid = getpid(); v += pid & 0xFFFF; - ASSERT_EQ(0, NULL == (fp = popen( + LOG_FAILURE_RETRY(__android_log_btwrite(0, EVENT_TYPE_LONG, &v, sizeof(v))); + + v &= 0xFFFFFFFFFFFAFFFFULL; + + ASSERT_TRUE(NULL != (fp = popen( "( trap exit HUP QUIT INT PIPE KILL ; sleep 6; echo DONE )&" " logcat -b events 2>&1", "r"))); @@ -339,14 +372,13 @@ TEST(logcat, blocking) { signal(SIGALRM, caught_blocking); alarm(2); while (fgets(buffer, sizeof(buffer), fp)) { - alarm(2); - - ++count; if (!strncmp(buffer, "DONE", 4)) { break; } + ++count; + int p; unsigned long long l; @@ -369,12 +401,12 @@ TEST(logcat, blocking) { pclose(fp); - ASSERT_LT(10, count); + EXPECT_LE(2, count); - ASSERT_EQ(1, signals); + EXPECT_EQ(1, signals); } -static void caught_blocking_tail(int signum) +static void caught_blocking_tail(int /*signum*/) { unsigned long long v = 0xA55ADEADBEEF0000ULL; @@ -385,13 +417,17 @@ static void caught_blocking_tail(int signum) TEST(logcat, blocking_tail) { FILE *fp; - unsigned long long v = 0xA55ADEADBEEF0000ULL; + unsigned long long v = 0xA55FDEADBEEF0000ULL; pid_t pid = getpid(); v += pid & 0xFFFF; - ASSERT_EQ(0, NULL == (fp = popen( + LOG_FAILURE_RETRY(__android_log_btwrite(0, EVENT_TYPE_LONG, &v, sizeof(v))); + + v &= 0xFFFAFFFFFFFFFFFFULL; + + ASSERT_TRUE(NULL != (fp = popen( "( trap exit HUP QUIT INT PIPE KILL ; sleep 6; echo DONE )&" " logcat -b events -T 5 2>&1", "r"))); @@ -405,14 +441,13 @@ TEST(logcat, blocking_tail) { signal(SIGALRM, caught_blocking_tail); alarm(2); while (fgets(buffer, sizeof(buffer), fp)) { - alarm(2); - - ++count; if (!strncmp(buffer, "DONE", 4)) { break; } + ++count; + int p; unsigned long long l; @@ -431,13 +466,186 @@ TEST(logcat, blocking_tail) { alarm(0); signal(SIGALRM, SIG_DFL); - /* Generate SIGPIPE */ + // Generate SIGPIPE fclose(fp); caught_blocking_tail(0); pclose(fp); - ASSERT_LT(5, count); + EXPECT_LE(2, count); + + EXPECT_EQ(1, signals); +} + +static void caught_blocking_clear(int /*signum*/) +{ + unsigned long long v = 0xDEADBEEFA55C0000ULL; + + v += getpid() & 0xFFFF; + + LOG_FAILURE_RETRY(__android_log_btwrite(0, EVENT_TYPE_LONG, &v, sizeof(v))); +} + +TEST(logcat, blocking_clear) { + FILE *fp; + unsigned long long v = 0xDEADBEEFA55C0000ULL; + + pid_t pid = getpid(); + + v += pid & 0xFFFF; + + // This test is racey; an event occurs between clear and dump. + // We accept that we will get a false positive, but never a false negative. + ASSERT_TRUE(NULL != (fp = popen( + "( trap exit HUP QUIT INT PIPE KILL ; sleep 6; echo DONE )&" + " logcat -b events -c 2>&1 ;" + " logcat -b events 2>&1", + "r"))); + + char buffer[5120]; + + int count = 0; + + int signals = 0; + + signal(SIGALRM, caught_blocking_clear); + alarm(2); + while (fgets(buffer, sizeof(buffer), fp)) { + + if (!strncmp(buffer, "clearLog: ", 10)) { + fprintf(stderr, "WARNING: Test lacks permission to run :-(\n"); + count = signals = 1; + break; + } + + if (!strncmp(buffer, "DONE", 4)) { + break; + } + + ++count; + + int p; + unsigned long long l; + + if ((2 != sscanf(buffer, "I/[0] ( %u): %lld", &p, &l)) + || (p != pid)) { + continue; + } + + if (l == v) { + if (count > 1) { + fprintf(stderr, "WARNING: Possible false positive\n"); + } + ++signals; + break; + } + } + alarm(0); + signal(SIGALRM, SIG_DFL); + + // Generate SIGPIPE + fclose(fp); + caught_blocking_clear(0); + + pclose(fp); + + EXPECT_LE(1, count); + + EXPECT_EQ(1, signals); +} + +static bool get_white_black(char **list) { + FILE *fp; + + fp = popen("logcat -p 2>/dev/null", "r"); + if (fp == NULL) { + fprintf(stderr, "ERROR: logcat -p 2>/dev/null\n"); + return false; + } + + char buffer[5120]; + + while (fgets(buffer, sizeof(buffer), fp)) { + char *hold = *list; + char *buf = buffer; + while (isspace(*buf)) { + ++buf; + } + char *end = buf + strlen(buf); + while (isspace(*--end) && (end >= buf)) { + *end = '\0'; + } + if (end < buf) { + continue; + } + if (hold) { + asprintf(list, "%s %s", hold, buf); + free(hold); + } else { + asprintf(list, "%s", buf); + } + } + pclose(fp); + return *list != NULL; +} + +static bool set_white_black(const char *list) { + FILE *fp; + + char buffer[5120]; + + snprintf(buffer, sizeof(buffer), "logcat -P '%s' 2>&1", list ? list : ""); + fp = popen(buffer, "r"); + if (fp == NULL) { + fprintf(stderr, "ERROR: %s\n", buffer); + return false; + } + + while (fgets(buffer, sizeof(buffer), fp)) { + char *buf = buffer; + while (isspace(*buf)) { + ++buf; + } + char *end = buf + strlen(buf); + while ((end > buf) && isspace(*--end)) { + *end = '\0'; + } + if (end <= buf) { + continue; + } + fprintf(stderr, "%s\n", buf); + pclose(fp); + return false; + } + return pclose(fp) == 0; +} - ASSERT_EQ(1, signals); +TEST(logcat, white_black_adjust) { + char *list = NULL; + char *adjust = NULL; + + get_white_black(&list); + + static const char adjustment[] = "~! 300/20 300/25 2000 ~1000/5 ~1000/30"; + ASSERT_EQ(true, set_white_black(adjustment)); + ASSERT_EQ(true, get_white_black(&adjust)); + EXPECT_STREQ(adjustment, adjust); + free(adjust); + adjust = NULL; + + static const char adjustment2[] = "300/20 300/21 2000 ~1000"; + ASSERT_EQ(true, set_white_black(adjustment2)); + ASSERT_EQ(true, get_white_black(&adjust)); + EXPECT_STREQ(adjustment2, adjust); + free(adjust); + adjust = NULL; + + ASSERT_EQ(true, set_white_black(list)); + get_white_black(&adjust); + EXPECT_STREQ(list ? list : "", adjust ? adjust : ""); + free(adjust); + adjust = NULL; + + free(list); + list = NULL; } |