logcat: test: modernize

- split sequential sort output test out as a benchmark check
- Allow up to two failures of sort results because of occasional reader locks.
- logcat -g output was changed to handle wider set of values incorporating a
  multiplier for UX, and would not pass test if 'logcat -G 1M' was run.
- If spam filter is turned off, prune checks would fail, allowed for an
  empty default.

Change-Id: I06d6089e18279df7525d1c16a1f76b3125ddbf05
This commit is contained in:
Mark Salyzyn 2014-06-03 11:24:34 -07:00
parent 4e6aa6a227
commit 9879ac8e12
3 changed files with 203 additions and 112 deletions

View File

@ -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 := \
@ -28,7 +24,29 @@ test_c_flags := \
-g \
-Wall -Wextra \
-Werror \
-fno-builtin
-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,7 +54,7 @@ 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)

View File

@ -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);
}

View File

@ -17,6 +17,7 @@
#include <ctype.h>
#include <signal.h>
#include <stdio.h>
#include <stdlib.h>
#include <string.h>
#include <gtest/gtest.h>
@ -41,99 +42,6 @@
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);
EXPECT_EQ(0, next_lt_last);
EXPECT_LT(100, count);
}
TEST(logcat, buckets) {
FILE *fp;
@ -362,9 +270,10 @@ TEST(logcat, End_to_End) {
ASSERT_EQ(1, count);
}
TEST(logcat, get_) {
TEST(logcat, get_size) {
FILE *fp;
// 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")));
@ -375,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;
}
@ -649,7 +594,7 @@ static bool set_white_black(const char *list) {
char buffer[5120];
snprintf(buffer, sizeof(buffer), "logcat -P '%s' 2>&1", list);
snprintf(buffer, sizeof(buffer), "logcat -P '%s' 2>&1", list ? list : "");
fp = popen(buffer, "r");
if (fp == NULL) {
fprintf(stderr, "ERROR: %s\n", buffer);
@ -662,10 +607,10 @@ static bool set_white_black(const char *list) {
++buf;
}
char *end = buf + strlen(buf);
while (isspace(*--end) && (end >= buf)) {
while ((end > buf) && isspace(*--end)) {
*end = '\0';
}
if (end < buf) {
if (end <= buf) {
continue;
}
fprintf(stderr, "%s\n", buf);
@ -679,7 +624,7 @@ TEST(logcat, white_black_adjust) {
char *list = NULL;
char *adjust = NULL;
ASSERT_EQ(true, get_white_black(&list));
get_white_black(&list);
static const char adjustment[] = "~! 300/20 300/25 2000 ~1000/5 ~1000/30";
ASSERT_EQ(true, set_white_black(adjustment));
@ -696,8 +641,8 @@ TEST(logcat, white_black_adjust) {
adjust = NULL;
ASSERT_EQ(true, set_white_black(list));
ASSERT_EQ(true, get_white_black(&adjust));
EXPECT_STREQ(list, adjust);
get_white_black(&adjust);
EXPECT_STREQ(list ? list : "", adjust ? adjust : "");
free(adjust);
adjust = NULL;