Mark Salyzyn | 65772ca | 2013-12-13 11:10:11 -0800 | [diff] [blame] | 1 | /* |
| 2 | * Copyright (C) 2013-2014 The Android Open Source Project |
| 3 | * |
| 4 | * Licensed under the Apache License, Version 2.0 (the "License"); |
| 5 | * you may not use this file except in compliance with the License. |
| 6 | * You may obtain a copy of the License at |
| 7 | * |
| 8 | * http://www.apache.org/licenses/LICENSE-2.0 |
| 9 | * |
| 10 | * Unless required by applicable law or agreed to in writing, software |
| 11 | * distributed under the License is distributed on an "AS IS" BASIS, |
| 12 | * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. |
| 13 | * See the License for the specific language governing permissions and |
| 14 | * limitations under the License. |
| 15 | */ |
| 16 | |
Mark Salyzyn | ef7c411 | 2014-03-11 10:35:58 -0700 | [diff] [blame] | 17 | #include <ctype.h> |
Mark Salyzyn | 9812fc4 | 2015-10-06 08:59:02 -0700 | [diff] [blame] | 18 | #include <dirent.h> |
Mark Salyzyn | 65772ca | 2013-12-13 11:10:11 -0800 | [diff] [blame] | 19 | #include <signal.h> |
| 20 | #include <stdio.h> |
Mark Salyzyn | 9879ac8 | 2014-06-03 11:24:34 -0700 | [diff] [blame] | 21 | #include <stdlib.h> |
Mark Salyzyn | ef7c411 | 2014-03-11 10:35:58 -0700 | [diff] [blame] | 22 | #include <string.h> |
Mark Salyzyn | 9812fc4 | 2015-10-06 08:59:02 -0700 | [diff] [blame] | 23 | #include <sys/types.h> |
Mark Salyzyn | 1ab87e7 | 2016-04-01 07:52:20 -0700 | [diff] [blame] | 24 | #include <sys/wait.h> |
Mark Salyzyn | ef7c411 | 2014-03-11 10:35:58 -0700 | [diff] [blame] | 25 | |
Mark Salyzyn | 65772ca | 2013-12-13 11:10:11 -0800 | [diff] [blame] | 26 | #include <gtest/gtest.h> |
| 27 | #include <log/log.h> |
| 28 | #include <log/logger.h> |
| 29 | #include <log/log_read.h> |
| 30 | |
| 31 | // enhanced version of LOG_FAILURE_RETRY to add support for EAGAIN and |
| 32 | // non-syscall libs. Since we are only using this in the emergency of |
| 33 | // a signal to stuff a terminating code into the logs, we will spin rather |
| 34 | // than try a usleep. |
| 35 | #define LOG_FAILURE_RETRY(exp) ({ \ |
| 36 | typeof (exp) _rc; \ |
| 37 | do { \ |
| 38 | _rc = (exp); \ |
| 39 | } while (((_rc == -1) \ |
| 40 | && ((errno == EINTR) \ |
| 41 | || (errno == EAGAIN))) \ |
| 42 | || (_rc == -EINTR) \ |
| 43 | || (_rc == -EAGAIN)); \ |
| 44 | _rc; }) |
| 45 | |
| 46 | static const char begin[] = "--------- beginning of "; |
| 47 | |
Mark Salyzyn | 65772ca | 2013-12-13 11:10:11 -0800 | [diff] [blame] | 48 | TEST(logcat, buckets) { |
| 49 | FILE *fp; |
| 50 | |
Mark Salyzyn | ef7c411 | 2014-03-11 10:35:58 -0700 | [diff] [blame] | 51 | ASSERT_TRUE(NULL != (fp = popen( |
Mark Salyzyn | 65772ca | 2013-12-13 11:10:11 -0800 | [diff] [blame] | 52 | "logcat -b radio -b events -b system -b main -d 2>/dev/null", |
| 53 | "r"))); |
| 54 | |
| 55 | char buffer[5120]; |
| 56 | |
| 57 | int ids = 0; |
| 58 | int count = 0; |
| 59 | |
| 60 | while (fgets(buffer, sizeof(buffer), fp)) { |
| 61 | if (!strncmp(begin, buffer, sizeof(begin) - 1)) { |
| 62 | while (char *cp = strrchr(buffer, '\n')) { |
| 63 | *cp = '\0'; |
| 64 | } |
| 65 | log_id_t id = android_name_to_log_id(buffer + sizeof(begin) - 1); |
| 66 | ids |= 1 << id; |
| 67 | ++count; |
| 68 | } |
| 69 | } |
| 70 | |
| 71 | pclose(fp); |
| 72 | |
Mark Salyzyn | ef7c411 | 2014-03-11 10:35:58 -0700 | [diff] [blame] | 73 | EXPECT_EQ(15, ids); |
Mark Salyzyn | 65772ca | 2013-12-13 11:10:11 -0800 | [diff] [blame] | 74 | |
Mark Salyzyn | ef7c411 | 2014-03-11 10:35:58 -0700 | [diff] [blame] | 75 | EXPECT_EQ(4, count); |
Mark Salyzyn | 65772ca | 2013-12-13 11:10:11 -0800 | [diff] [blame] | 76 | } |
| 77 | |
Mark Salyzyn | f28f6a9 | 2015-08-31 08:01:33 -0700 | [diff] [blame] | 78 | TEST(logcat, year) { |
Mark Salyzyn | b6bee33 | 2015-09-08 08:56:32 -0700 | [diff] [blame] | 79 | |
Mark Salyzyn | ba7a9a0 | 2015-12-01 15:57:25 -0800 | [diff] [blame] | 80 | if (android_log_clockid() == CLOCK_MONOTONIC) { |
Mark Salyzyn | b6bee33 | 2015-09-08 08:56:32 -0700 | [diff] [blame] | 81 | fprintf(stderr, "Skipping test, logd is monotonic time\n"); |
| 82 | return; |
| 83 | } |
| 84 | |
Mark Salyzyn | f28f6a9 | 2015-08-31 08:01:33 -0700 | [diff] [blame] | 85 | FILE *fp; |
| 86 | |
| 87 | char needle[32]; |
| 88 | time_t now; |
| 89 | time(&now); |
| 90 | struct tm *ptm; |
| 91 | #if !defined(_WIN32) |
| 92 | struct tm tmBuf; |
| 93 | ptm = localtime_r(&now, &tmBuf); |
| 94 | #else |
| 95 | ptm = localtime(&&now); |
| 96 | #endif |
| 97 | strftime(needle, sizeof(needle), "[ %Y-", ptm); |
| 98 | |
| 99 | ASSERT_TRUE(NULL != (fp = popen( |
| 100 | "logcat -v long -v year -b all -t 3 2>/dev/null", |
| 101 | "r"))); |
| 102 | |
| 103 | char buffer[5120]; |
| 104 | |
| 105 | int count = 0; |
| 106 | |
| 107 | while (fgets(buffer, sizeof(buffer), fp)) { |
| 108 | if (!strncmp(buffer, needle, strlen(needle))) { |
| 109 | ++count; |
| 110 | } |
| 111 | } |
| 112 | |
| 113 | pclose(fp); |
| 114 | |
| 115 | ASSERT_EQ(3, count); |
| 116 | } |
| 117 | |
Mark Salyzyn | b6bee33 | 2015-09-08 08:56:32 -0700 | [diff] [blame] | 118 | // Return a pointer to each null terminated -v long time field. |
| 119 | char *fgetLongTime(char *buffer, size_t buflen, FILE *fp) { |
| 120 | while (fgets(buffer, buflen, fp)) { |
| 121 | char *cp = buffer; |
| 122 | if (*cp != '[') { |
| 123 | continue; |
| 124 | } |
| 125 | while (*++cp == ' ') { |
| 126 | ; |
| 127 | } |
| 128 | char *ep = cp; |
| 129 | while (isdigit(*ep)) { |
| 130 | ++ep; |
| 131 | } |
| 132 | if ((*ep != '-') && (*ep != '.')) { |
| 133 | continue; |
| 134 | } |
| 135 | // Find PID field |
| 136 | while (((ep = strchr(ep, ':'))) && (*++ep != ' ')) { |
| 137 | ; |
| 138 | } |
| 139 | if (!ep) { |
| 140 | continue; |
| 141 | } |
| 142 | ep -= 7; |
| 143 | *ep = '\0'; |
| 144 | return cp; |
| 145 | } |
| 146 | return NULL; |
| 147 | } |
| 148 | |
Mark Salyzyn | f28f6a9 | 2015-08-31 08:01:33 -0700 | [diff] [blame] | 149 | TEST(logcat, tz) { |
Mark Salyzyn | b6bee33 | 2015-09-08 08:56:32 -0700 | [diff] [blame] | 150 | |
Mark Salyzyn | ba7a9a0 | 2015-12-01 15:57:25 -0800 | [diff] [blame] | 151 | if (android_log_clockid() == CLOCK_MONOTONIC) { |
Mark Salyzyn | b6bee33 | 2015-09-08 08:56:32 -0700 | [diff] [blame] | 152 | fprintf(stderr, "Skipping test, logd is monotonic time\n"); |
| 153 | return; |
| 154 | } |
| 155 | |
Mark Salyzyn | 3c535de | 2016-04-12 11:07:26 -0700 | [diff] [blame] | 156 | int tries = 3; // in case run too soon after system start or buffer clear |
| 157 | int count; |
Mark Salyzyn | f28f6a9 | 2015-08-31 08:01:33 -0700 | [diff] [blame] | 158 | |
Mark Salyzyn | 3c535de | 2016-04-12 11:07:26 -0700 | [diff] [blame] | 159 | do { |
| 160 | FILE *fp; |
Mark Salyzyn | f28f6a9 | 2015-08-31 08:01:33 -0700 | [diff] [blame] | 161 | |
Mark Salyzyn | 3c535de | 2016-04-12 11:07:26 -0700 | [diff] [blame] | 162 | ASSERT_TRUE(NULL != (fp = popen( |
| 163 | "logcat -v long -v America/Los_Angeles -b all -t 3 2>/dev/null", |
| 164 | "r"))); |
Mark Salyzyn | f28f6a9 | 2015-08-31 08:01:33 -0700 | [diff] [blame] | 165 | |
Mark Salyzyn | 3c535de | 2016-04-12 11:07:26 -0700 | [diff] [blame] | 166 | char buffer[5120]; |
Mark Salyzyn | f28f6a9 | 2015-08-31 08:01:33 -0700 | [diff] [blame] | 167 | |
Mark Salyzyn | 3c535de | 2016-04-12 11:07:26 -0700 | [diff] [blame] | 168 | count = 0; |
| 169 | |
| 170 | while (fgetLongTime(buffer, sizeof(buffer), fp)) { |
| 171 | if (strstr(buffer, " -0700") || strstr(buffer, " -0800")) { |
| 172 | ++count; |
| 173 | } |
Mark Salyzyn | f28f6a9 | 2015-08-31 08:01:33 -0700 | [diff] [blame] | 174 | } |
Mark Salyzyn | f28f6a9 | 2015-08-31 08:01:33 -0700 | [diff] [blame] | 175 | |
Mark Salyzyn | 3c535de | 2016-04-12 11:07:26 -0700 | [diff] [blame] | 176 | pclose(fp); |
| 177 | |
| 178 | } while ((count < 3) && --tries && (sleep(1), true)); |
Mark Salyzyn | f28f6a9 | 2015-08-31 08:01:33 -0700 | [diff] [blame] | 179 | |
| 180 | ASSERT_EQ(3, count); |
| 181 | } |
| 182 | |
| 183 | TEST(logcat, ntz) { |
| 184 | FILE *fp; |
| 185 | |
| 186 | ASSERT_TRUE(NULL != (fp = popen( |
| 187 | "logcat -v long -v America/Los_Angeles -v zone -b all -t 3 2>/dev/null", |
| 188 | "r"))); |
| 189 | |
| 190 | char buffer[5120]; |
| 191 | |
| 192 | int count = 0; |
| 193 | |
Mark Salyzyn | b6bee33 | 2015-09-08 08:56:32 -0700 | [diff] [blame] | 194 | while (fgetLongTime(buffer, sizeof(buffer), fp)) { |
| 195 | if (strstr(buffer, " -0700") || strstr(buffer, " -0800")) { |
Mark Salyzyn | f28f6a9 | 2015-08-31 08:01:33 -0700 | [diff] [blame] | 196 | ++count; |
| 197 | } |
| 198 | } |
| 199 | |
| 200 | pclose(fp); |
| 201 | |
| 202 | ASSERT_EQ(0, count); |
| 203 | } |
| 204 | |
Mark Salyzyn | 3c535de | 2016-04-12 11:07:26 -0700 | [diff] [blame] | 205 | void do_tail(int num) { |
| 206 | int tries = 3; // in case run too soon after system start or buffer clear |
| 207 | int count; |
| 208 | |
| 209 | do { |
| 210 | char buffer[5120]; |
| 211 | |
| 212 | snprintf(buffer, sizeof(buffer), |
| 213 | "logcat -v long -b radio -b events -b system -b main -t %d 2>/dev/null", |
| 214 | num); |
| 215 | |
| 216 | FILE *fp; |
| 217 | ASSERT_TRUE(NULL != (fp = popen(buffer, "r"))); |
| 218 | |
| 219 | count = 0; |
| 220 | |
| 221 | while (fgetLongTime(buffer, sizeof(buffer), fp)) { |
| 222 | ++count; |
| 223 | } |
| 224 | |
| 225 | pclose(fp); |
| 226 | |
| 227 | } while ((count < num) && --tries && (sleep(1), true)); |
| 228 | |
| 229 | ASSERT_EQ(num, count); |
| 230 | } |
| 231 | |
Mark Salyzyn | 65772ca | 2013-12-13 11:10:11 -0800 | [diff] [blame] | 232 | TEST(logcat, tail_3) { |
Mark Salyzyn | 3c535de | 2016-04-12 11:07:26 -0700 | [diff] [blame] | 233 | do_tail(3); |
Mark Salyzyn | 65772ca | 2013-12-13 11:10:11 -0800 | [diff] [blame] | 234 | } |
| 235 | |
| 236 | TEST(logcat, tail_10) { |
Mark Salyzyn | 3c535de | 2016-04-12 11:07:26 -0700 | [diff] [blame] | 237 | do_tail(10); |
Mark Salyzyn | 65772ca | 2013-12-13 11:10:11 -0800 | [diff] [blame] | 238 | } |
| 239 | |
| 240 | TEST(logcat, tail_100) { |
Mark Salyzyn | 3c535de | 2016-04-12 11:07:26 -0700 | [diff] [blame] | 241 | do_tail(100); |
Mark Salyzyn | 65772ca | 2013-12-13 11:10:11 -0800 | [diff] [blame] | 242 | } |
| 243 | |
| 244 | TEST(logcat, tail_1000) { |
Mark Salyzyn | 3c535de | 2016-04-12 11:07:26 -0700 | [diff] [blame] | 245 | do_tail(1000); |
Mark Salyzyn | 65772ca | 2013-12-13 11:10:11 -0800 | [diff] [blame] | 246 | } |
| 247 | |
Mark Salyzyn | ef7c411 | 2014-03-11 10:35:58 -0700 | [diff] [blame] | 248 | TEST(logcat, tail_time) { |
| 249 | FILE *fp; |
| 250 | |
| 251 | ASSERT_TRUE(NULL != (fp = popen("logcat -v long -b all -t 10 2>&1", "r"))); |
| 252 | |
| 253 | char buffer[5120]; |
| 254 | char *last_timestamp = NULL; |
| 255 | char *first_timestamp = NULL; |
| 256 | int count = 0; |
Mark Salyzyn | ef7c411 | 2014-03-11 10:35:58 -0700 | [diff] [blame] | 257 | |
Mark Salyzyn | b6bee33 | 2015-09-08 08:56:32 -0700 | [diff] [blame] | 258 | char *cp; |
| 259 | while ((cp = fgetLongTime(buffer, sizeof(buffer), fp))) { |
| 260 | ++count; |
| 261 | if (!first_timestamp) { |
| 262 | first_timestamp = strdup(cp); |
Mark Salyzyn | ef7c411 | 2014-03-11 10:35:58 -0700 | [diff] [blame] | 263 | } |
Mark Salyzyn | b6bee33 | 2015-09-08 08:56:32 -0700 | [diff] [blame] | 264 | free(last_timestamp); |
| 265 | last_timestamp = strdup(cp); |
Mark Salyzyn | ef7c411 | 2014-03-11 10:35:58 -0700 | [diff] [blame] | 266 | } |
| 267 | pclose(fp); |
| 268 | |
| 269 | EXPECT_EQ(10, count); |
| 270 | EXPECT_TRUE(last_timestamp != NULL); |
| 271 | EXPECT_TRUE(first_timestamp != NULL); |
| 272 | |
| 273 | snprintf(buffer, sizeof(buffer), "logcat -v long -b all -t '%s' 2>&1", |
| 274 | first_timestamp); |
| 275 | ASSERT_TRUE(NULL != (fp = popen(buffer, "r"))); |
| 276 | |
| 277 | int second_count = 0; |
| 278 | int last_timestamp_count = -1; |
| 279 | |
Mark Salyzyn | b6bee33 | 2015-09-08 08:56:32 -0700 | [diff] [blame] | 280 | while ((cp = fgetLongTime(buffer, sizeof(buffer), fp))) { |
| 281 | ++second_count; |
| 282 | if (first_timestamp) { |
| 283 | // we can get a transitory *extremely* rare failure if hidden |
| 284 | // underneath the time is *exactly* XX-XX XX:XX:XX.XXX000000 |
| 285 | EXPECT_STREQ(cp, first_timestamp); |
| 286 | free(first_timestamp); |
| 287 | first_timestamp = NULL; |
| 288 | } |
| 289 | if (!strcmp(cp, last_timestamp)) { |
| 290 | last_timestamp_count = second_count; |
Mark Salyzyn | ef7c411 | 2014-03-11 10:35:58 -0700 | [diff] [blame] | 291 | } |
| 292 | } |
| 293 | pclose(fp); |
| 294 | |
| 295 | free(last_timestamp); |
| 296 | last_timestamp = NULL; |
Mark Salyzyn | b6bee33 | 2015-09-08 08:56:32 -0700 | [diff] [blame] | 297 | free(first_timestamp); |
Mark Salyzyn | ef7c411 | 2014-03-11 10:35:58 -0700 | [diff] [blame] | 298 | |
| 299 | EXPECT_TRUE(first_timestamp == NULL); |
| 300 | EXPECT_LE(count, second_count); |
| 301 | EXPECT_LE(count, last_timestamp_count); |
| 302 | } |
| 303 | |
Mark Salyzyn | 65772ca | 2013-12-13 11:10:11 -0800 | [diff] [blame] | 304 | TEST(logcat, End_to_End) { |
| 305 | pid_t pid = getpid(); |
| 306 | |
| 307 | log_time ts(CLOCK_MONOTONIC); |
| 308 | |
| 309 | ASSERT_LT(0, __android_log_btwrite(0, EVENT_TYPE_LONG, &ts, sizeof(ts))); |
| 310 | |
| 311 | FILE *fp; |
Mark Salyzyn | ef7c411 | 2014-03-11 10:35:58 -0700 | [diff] [blame] | 312 | ASSERT_TRUE(NULL != (fp = popen( |
Mark Salyzyn | a5e2429 | 2014-09-18 10:25:38 -0700 | [diff] [blame] | 313 | "logcat -v brief -b events -t 100 2>/dev/null", |
Mark Salyzyn | 65772ca | 2013-12-13 11:10:11 -0800 | [diff] [blame] | 314 | "r"))); |
| 315 | |
| 316 | char buffer[5120]; |
| 317 | |
| 318 | int count = 0; |
| 319 | |
| 320 | while (fgets(buffer, sizeof(buffer), fp)) { |
| 321 | int p; |
| 322 | unsigned long long t; |
| 323 | |
| 324 | if ((2 != sscanf(buffer, "I/[0] ( %d): %llu", &p, &t)) |
| 325 | || (p != pid)) { |
| 326 | continue; |
| 327 | } |
| 328 | |
| 329 | log_time tx((const char *) &t); |
| 330 | if (ts == tx) { |
| 331 | ++count; |
| 332 | } |
| 333 | } |
| 334 | |
| 335 | pclose(fp); |
| 336 | |
| 337 | ASSERT_EQ(1, count); |
| 338 | } |
| 339 | |
Mark Salyzyn | 9879ac8 | 2014-06-03 11:24:34 -0700 | [diff] [blame] | 340 | TEST(logcat, get_size) { |
Mark Salyzyn | 65772ca | 2013-12-13 11:10:11 -0800 | [diff] [blame] | 341 | FILE *fp; |
| 342 | |
Mark Salyzyn | 9879ac8 | 2014-06-03 11:24:34 -0700 | [diff] [blame] | 343 | // NB: crash log only available in user space |
Mark Salyzyn | ef7c411 | 2014-03-11 10:35:58 -0700 | [diff] [blame] | 344 | ASSERT_TRUE(NULL != (fp = popen( |
Mark Salyzyn | a5e2429 | 2014-09-18 10:25:38 -0700 | [diff] [blame] | 345 | "logcat -v brief -b radio -b events -b system -b main -g 2>/dev/null", |
Mark Salyzyn | 65772ca | 2013-12-13 11:10:11 -0800 | [diff] [blame] | 346 | "r"))); |
| 347 | |
| 348 | char buffer[5120]; |
| 349 | |
| 350 | int count = 0; |
| 351 | |
| 352 | while (fgets(buffer, sizeof(buffer), fp)) { |
| 353 | int size, consumed, max, payload; |
Mark Salyzyn | 9812fc4 | 2015-10-06 08:59:02 -0700 | [diff] [blame] | 354 | char size_mult[3], consumed_mult[3]; |
Mark Salyzyn | 9879ac8 | 2014-06-03 11:24:34 -0700 | [diff] [blame] | 355 | long full_size, full_consumed; |
Mark Salyzyn | 65772ca | 2013-12-13 11:10:11 -0800 | [diff] [blame] | 356 | |
| 357 | size = consumed = max = payload = 0; |
Mark Salyzyn | 9879ac8 | 2014-06-03 11:24:34 -0700 | [diff] [blame] | 358 | // NB: crash log can be very small, not hit a Kb of consumed space |
| 359 | // doubly lucky we are not including it. |
Mark Salyzyn | d03caa2 | 2014-07-10 14:07:39 -0700 | [diff] [blame] | 360 | if (6 != sscanf(buffer, "%*s ring buffer is %d%2s (%d%2s consumed)," |
Mark Salyzyn | 9879ac8 | 2014-06-03 11:24:34 -0700 | [diff] [blame] | 361 | " max entry is %db, max payload is %db", |
Mark Salyzyn | d03caa2 | 2014-07-10 14:07:39 -0700 | [diff] [blame] | 362 | &size, size_mult, &consumed, consumed_mult, |
Mark Salyzyn | 9879ac8 | 2014-06-03 11:24:34 -0700 | [diff] [blame] | 363 | &max, &payload)) { |
| 364 | fprintf(stderr, "WARNING: Parse error: %s", buffer); |
| 365 | continue; |
| 366 | } |
| 367 | full_size = size; |
Mark Salyzyn | d03caa2 | 2014-07-10 14:07:39 -0700 | [diff] [blame] | 368 | switch(size_mult[0]) { |
Mark Salyzyn | 9879ac8 | 2014-06-03 11:24:34 -0700 | [diff] [blame] | 369 | case 'G': |
| 370 | full_size *= 1024; |
| 371 | /* FALLTHRU */ |
| 372 | case 'M': |
| 373 | full_size *= 1024; |
| 374 | /* FALLTHRU */ |
| 375 | case 'K': |
| 376 | full_size *= 1024; |
Mark Salyzyn | d03caa2 | 2014-07-10 14:07:39 -0700 | [diff] [blame] | 377 | /* FALLTHRU */ |
| 378 | case 'b': |
Mark Salyzyn | 9879ac8 | 2014-06-03 11:24:34 -0700 | [diff] [blame] | 379 | break; |
| 380 | } |
| 381 | full_consumed = consumed; |
Mark Salyzyn | d03caa2 | 2014-07-10 14:07:39 -0700 | [diff] [blame] | 382 | switch(consumed_mult[0]) { |
Mark Salyzyn | 9879ac8 | 2014-06-03 11:24:34 -0700 | [diff] [blame] | 383 | case 'G': |
| 384 | full_consumed *= 1024; |
| 385 | /* FALLTHRU */ |
| 386 | case 'M': |
| 387 | full_consumed *= 1024; |
| 388 | /* FALLTHRU */ |
| 389 | case 'K': |
| 390 | full_consumed *= 1024; |
Mark Salyzyn | d03caa2 | 2014-07-10 14:07:39 -0700 | [diff] [blame] | 391 | /* FALLTHRU */ |
| 392 | case 'b': |
Mark Salyzyn | 9879ac8 | 2014-06-03 11:24:34 -0700 | [diff] [blame] | 393 | break; |
| 394 | } |
| 395 | EXPECT_GT((full_size * 9) / 4, full_consumed); |
| 396 | EXPECT_GT(full_size, max); |
| 397 | EXPECT_GT(max, payload); |
| 398 | |
| 399 | if ((((full_size * 9) / 4) >= full_consumed) |
| 400 | && (full_size > max) |
Mark Salyzyn | 65772ca | 2013-12-13 11:10:11 -0800 | [diff] [blame] | 401 | && (max > payload)) { |
| 402 | ++count; |
| 403 | } |
| 404 | } |
| 405 | |
| 406 | pclose(fp); |
| 407 | |
| 408 | ASSERT_EQ(4, count); |
| 409 | } |
| 410 | |
Mark Salyzyn | b149e24 | 2014-04-30 09:39:09 -0700 | [diff] [blame] | 411 | static void caught_blocking(int /*signum*/) |
Mark Salyzyn | 65772ca | 2013-12-13 11:10:11 -0800 | [diff] [blame] | 412 | { |
| 413 | unsigned long long v = 0xDEADBEEFA55A0000ULL; |
| 414 | |
| 415 | v += getpid() & 0xFFFF; |
| 416 | |
| 417 | LOG_FAILURE_RETRY(__android_log_btwrite(0, EVENT_TYPE_LONG, &v, sizeof(v))); |
| 418 | } |
| 419 | |
| 420 | TEST(logcat, blocking) { |
| 421 | FILE *fp; |
Mark Salyzyn | 9b98649 | 2014-01-22 10:30:09 -0800 | [diff] [blame] | 422 | unsigned long long v = 0xDEADBEEFA55F0000ULL; |
Mark Salyzyn | 65772ca | 2013-12-13 11:10:11 -0800 | [diff] [blame] | 423 | |
| 424 | pid_t pid = getpid(); |
| 425 | |
| 426 | v += pid & 0xFFFF; |
| 427 | |
Mark Salyzyn | 9b98649 | 2014-01-22 10:30:09 -0800 | [diff] [blame] | 428 | LOG_FAILURE_RETRY(__android_log_btwrite(0, EVENT_TYPE_LONG, &v, sizeof(v))); |
| 429 | |
| 430 | v &= 0xFFFFFFFFFFFAFFFFULL; |
| 431 | |
Mark Salyzyn | ef7c411 | 2014-03-11 10:35:58 -0700 | [diff] [blame] | 432 | ASSERT_TRUE(NULL != (fp = popen( |
Mark Salyzyn | 65772ca | 2013-12-13 11:10:11 -0800 | [diff] [blame] | 433 | "( trap exit HUP QUIT INT PIPE KILL ; sleep 6; echo DONE )&" |
Mark Salyzyn | a5e2429 | 2014-09-18 10:25:38 -0700 | [diff] [blame] | 434 | " logcat -v brief -b events 2>&1", |
Mark Salyzyn | 65772ca | 2013-12-13 11:10:11 -0800 | [diff] [blame] | 435 | "r"))); |
| 436 | |
| 437 | char buffer[5120]; |
| 438 | |
| 439 | int count = 0; |
| 440 | |
| 441 | int signals = 0; |
| 442 | |
| 443 | signal(SIGALRM, caught_blocking); |
| 444 | alarm(2); |
| 445 | while (fgets(buffer, sizeof(buffer), fp)) { |
Mark Salyzyn | 65772ca | 2013-12-13 11:10:11 -0800 | [diff] [blame] | 446 | |
Mark Salyzyn | 65772ca | 2013-12-13 11:10:11 -0800 | [diff] [blame] | 447 | if (!strncmp(buffer, "DONE", 4)) { |
| 448 | break; |
| 449 | } |
| 450 | |
Mark Salyzyn | 9b98649 | 2014-01-22 10:30:09 -0800 | [diff] [blame] | 451 | ++count; |
| 452 | |
Mark Salyzyn | 65772ca | 2013-12-13 11:10:11 -0800 | [diff] [blame] | 453 | int p; |
| 454 | unsigned long long l; |
| 455 | |
| 456 | if ((2 != sscanf(buffer, "I/[0] ( %u): %lld", &p, &l)) |
| 457 | || (p != pid)) { |
| 458 | continue; |
| 459 | } |
| 460 | |
| 461 | if (l == v) { |
| 462 | ++signals; |
| 463 | break; |
| 464 | } |
| 465 | } |
| 466 | alarm(0); |
| 467 | signal(SIGALRM, SIG_DFL); |
| 468 | |
| 469 | // Generate SIGPIPE |
| 470 | fclose(fp); |
| 471 | caught_blocking(0); |
| 472 | |
| 473 | pclose(fp); |
| 474 | |
Mark Salyzyn | ef7c411 | 2014-03-11 10:35:58 -0700 | [diff] [blame] | 475 | EXPECT_LE(2, count); |
Mark Salyzyn | 65772ca | 2013-12-13 11:10:11 -0800 | [diff] [blame] | 476 | |
Mark Salyzyn | ef7c411 | 2014-03-11 10:35:58 -0700 | [diff] [blame] | 477 | EXPECT_EQ(1, signals); |
Mark Salyzyn | 65772ca | 2013-12-13 11:10:11 -0800 | [diff] [blame] | 478 | } |
Mark Salyzyn | 5d3d1f1 | 2013-12-09 13:47:00 -0800 | [diff] [blame] | 479 | |
Mark Salyzyn | b149e24 | 2014-04-30 09:39:09 -0700 | [diff] [blame] | 480 | static void caught_blocking_tail(int /*signum*/) |
Mark Salyzyn | 5d3d1f1 | 2013-12-09 13:47:00 -0800 | [diff] [blame] | 481 | { |
| 482 | unsigned long long v = 0xA55ADEADBEEF0000ULL; |
| 483 | |
| 484 | v += getpid() & 0xFFFF; |
| 485 | |
| 486 | LOG_FAILURE_RETRY(__android_log_btwrite(0, EVENT_TYPE_LONG, &v, sizeof(v))); |
| 487 | } |
| 488 | |
| 489 | TEST(logcat, blocking_tail) { |
| 490 | FILE *fp; |
Mark Salyzyn | 9b98649 | 2014-01-22 10:30:09 -0800 | [diff] [blame] | 491 | unsigned long long v = 0xA55FDEADBEEF0000ULL; |
Mark Salyzyn | 5d3d1f1 | 2013-12-09 13:47:00 -0800 | [diff] [blame] | 492 | |
| 493 | pid_t pid = getpid(); |
| 494 | |
| 495 | v += pid & 0xFFFF; |
| 496 | |
Mark Salyzyn | 9b98649 | 2014-01-22 10:30:09 -0800 | [diff] [blame] | 497 | LOG_FAILURE_RETRY(__android_log_btwrite(0, EVENT_TYPE_LONG, &v, sizeof(v))); |
| 498 | |
| 499 | v &= 0xFFFAFFFFFFFFFFFFULL; |
| 500 | |
Mark Salyzyn | ef7c411 | 2014-03-11 10:35:58 -0700 | [diff] [blame] | 501 | ASSERT_TRUE(NULL != (fp = popen( |
Mark Salyzyn | 5d3d1f1 | 2013-12-09 13:47:00 -0800 | [diff] [blame] | 502 | "( trap exit HUP QUIT INT PIPE KILL ; sleep 6; echo DONE )&" |
Mark Salyzyn | a5e2429 | 2014-09-18 10:25:38 -0700 | [diff] [blame] | 503 | " logcat -v brief -b events -T 5 2>&1", |
Mark Salyzyn | 5d3d1f1 | 2013-12-09 13:47:00 -0800 | [diff] [blame] | 504 | "r"))); |
| 505 | |
| 506 | char buffer[5120]; |
| 507 | |
| 508 | int count = 0; |
| 509 | |
| 510 | int signals = 0; |
| 511 | |
| 512 | signal(SIGALRM, caught_blocking_tail); |
| 513 | alarm(2); |
| 514 | while (fgets(buffer, sizeof(buffer), fp)) { |
Mark Salyzyn | 5d3d1f1 | 2013-12-09 13:47:00 -0800 | [diff] [blame] | 515 | |
Mark Salyzyn | 5d3d1f1 | 2013-12-09 13:47:00 -0800 | [diff] [blame] | 516 | if (!strncmp(buffer, "DONE", 4)) { |
| 517 | break; |
| 518 | } |
| 519 | |
Mark Salyzyn | 9b98649 | 2014-01-22 10:30:09 -0800 | [diff] [blame] | 520 | ++count; |
| 521 | |
Mark Salyzyn | 5d3d1f1 | 2013-12-09 13:47:00 -0800 | [diff] [blame] | 522 | int p; |
| 523 | unsigned long long l; |
| 524 | |
| 525 | if ((2 != sscanf(buffer, "I/[0] ( %u): %lld", &p, &l)) |
| 526 | || (p != pid)) { |
| 527 | continue; |
| 528 | } |
| 529 | |
| 530 | if (l == v) { |
| 531 | if (count >= 5) { |
| 532 | ++signals; |
| 533 | } |
| 534 | break; |
| 535 | } |
| 536 | } |
| 537 | alarm(0); |
| 538 | signal(SIGALRM, SIG_DFL); |
| 539 | |
Mark Salyzyn | 9b98649 | 2014-01-22 10:30:09 -0800 | [diff] [blame] | 540 | // Generate SIGPIPE |
Mark Salyzyn | 5d3d1f1 | 2013-12-09 13:47:00 -0800 | [diff] [blame] | 541 | fclose(fp); |
| 542 | caught_blocking_tail(0); |
| 543 | |
| 544 | pclose(fp); |
| 545 | |
Mark Salyzyn | ef7c411 | 2014-03-11 10:35:58 -0700 | [diff] [blame] | 546 | EXPECT_LE(2, count); |
Mark Salyzyn | 9b98649 | 2014-01-22 10:30:09 -0800 | [diff] [blame] | 547 | |
Mark Salyzyn | ef7c411 | 2014-03-11 10:35:58 -0700 | [diff] [blame] | 548 | EXPECT_EQ(1, signals); |
Mark Salyzyn | 9b98649 | 2014-01-22 10:30:09 -0800 | [diff] [blame] | 549 | } |
| 550 | |
Mark Salyzyn | d03caa2 | 2014-07-10 14:07:39 -0700 | [diff] [blame] | 551 | TEST(logcat, logrotate) { |
| 552 | static const char form[] = "/data/local/tmp/logcat.logrotate.XXXXXX"; |
| 553 | char buf[sizeof(form)]; |
| 554 | ASSERT_TRUE(NULL != mkdtemp(strcpy(buf, form))); |
| 555 | |
| 556 | static const char comm[] = "logcat -b radio -b events -b system -b main" |
| 557 | " -d -f %s/log.txt -n 7 -r 1"; |
| 558 | char command[sizeof(buf) + sizeof(comm)]; |
Mark Salyzyn | 9812fc4 | 2015-10-06 08:59:02 -0700 | [diff] [blame] | 559 | snprintf(command, sizeof(command), comm, buf); |
Mark Salyzyn | d03caa2 | 2014-07-10 14:07:39 -0700 | [diff] [blame] | 560 | |
| 561 | int ret; |
| 562 | EXPECT_FALSE((ret = system(command))); |
| 563 | if (!ret) { |
Mark Salyzyn | 9812fc4 | 2015-10-06 08:59:02 -0700 | [diff] [blame] | 564 | snprintf(command, sizeof(command), "ls -s %s 2>/dev/null", buf); |
Mark Salyzyn | d03caa2 | 2014-07-10 14:07:39 -0700 | [diff] [blame] | 565 | |
| 566 | FILE *fp; |
| 567 | EXPECT_TRUE(NULL != (fp = popen(command, "r"))); |
| 568 | if (fp) { |
| 569 | char buffer[5120]; |
| 570 | int count = 0; |
| 571 | |
| 572 | while (fgets(buffer, sizeof(buffer), fp)) { |
Mark Salyzyn | d03caa2 | 2014-07-10 14:07:39 -0700 | [diff] [blame] | 573 | static const char total[] = "total "; |
Mark Salyzyn | 9812fc4 | 2015-10-06 08:59:02 -0700 | [diff] [blame] | 574 | int num; |
| 575 | char c; |
Mark Salyzyn | d03caa2 | 2014-07-10 14:07:39 -0700 | [diff] [blame] | 576 | |
Mark Salyzyn | 9812fc4 | 2015-10-06 08:59:02 -0700 | [diff] [blame] | 577 | if ((2 == sscanf(buffer, "%d log.tx%c", &num, &c)) && |
Mark Salyzyn | 8beb0d3 | 2015-12-15 10:39:07 -0800 | [diff] [blame] | 578 | (num <= 40)) { |
Mark Salyzyn | d03caa2 | 2014-07-10 14:07:39 -0700 | [diff] [blame] | 579 | ++count; |
| 580 | } else if (strncmp(buffer, total, sizeof(total) - 1)) { |
| 581 | fprintf(stderr, "WARNING: Parse error: %s", buffer); |
| 582 | } |
| 583 | } |
| 584 | pclose(fp); |
Mark Salyzyn | b6bee33 | 2015-09-08 08:56:32 -0700 | [diff] [blame] | 585 | if ((count != 7) && (count != 8)) { |
| 586 | fprintf(stderr, "count=%d\n", count); |
| 587 | } |
Mark Salyzyn | d03caa2 | 2014-07-10 14:07:39 -0700 | [diff] [blame] | 588 | EXPECT_TRUE(count == 7 || count == 8); |
| 589 | } |
| 590 | } |
Mark Salyzyn | 9812fc4 | 2015-10-06 08:59:02 -0700 | [diff] [blame] | 591 | snprintf(command, sizeof(command), "rm -rf %s", buf); |
Mark Salyzyn | d03caa2 | 2014-07-10 14:07:39 -0700 | [diff] [blame] | 592 | EXPECT_FALSE(system(command)); |
| 593 | } |
| 594 | |
Aristidis Papaioannou | eba7344 | 2014-10-16 22:19:55 -0700 | [diff] [blame] | 595 | TEST(logcat, logrotate_suffix) { |
| 596 | static const char tmp_out_dir_form[] = "/data/local/tmp/logcat.logrotate.XXXXXX"; |
| 597 | char tmp_out_dir[sizeof(tmp_out_dir_form)]; |
| 598 | ASSERT_TRUE(NULL != mkdtemp(strcpy(tmp_out_dir, tmp_out_dir_form))); |
| 599 | |
| 600 | static const char logcat_cmd[] = "logcat -b radio -b events -b system -b main" |
| 601 | " -d -f %s/log.txt -n 10 -r 1"; |
| 602 | char command[sizeof(tmp_out_dir) + sizeof(logcat_cmd)]; |
Mark Salyzyn | 9812fc4 | 2015-10-06 08:59:02 -0700 | [diff] [blame] | 603 | snprintf(command, sizeof(command), logcat_cmd, tmp_out_dir); |
Aristidis Papaioannou | eba7344 | 2014-10-16 22:19:55 -0700 | [diff] [blame] | 604 | |
| 605 | int ret; |
| 606 | EXPECT_FALSE((ret = system(command))); |
| 607 | if (!ret) { |
Mark Salyzyn | 9812fc4 | 2015-10-06 08:59:02 -0700 | [diff] [blame] | 608 | snprintf(command, sizeof(command), "ls %s 2>/dev/null", tmp_out_dir); |
Aristidis Papaioannou | eba7344 | 2014-10-16 22:19:55 -0700 | [diff] [blame] | 609 | |
| 610 | FILE *fp; |
| 611 | EXPECT_TRUE(NULL != (fp = popen(command, "r"))); |
| 612 | char buffer[5120]; |
| 613 | int log_file_count = 0; |
| 614 | |
| 615 | while (fgets(buffer, sizeof(buffer), fp)) { |
| 616 | static const char rotated_log_filename_prefix[] = "log.txt."; |
| 617 | static const size_t rotated_log_filename_prefix_len = |
| 618 | strlen(rotated_log_filename_prefix); |
Aristidis Papaioannou | eba7344 | 2014-10-16 22:19:55 -0700 | [diff] [blame] | 619 | static const char log_filename[] = "log.txt"; |
| 620 | |
| 621 | if (!strncmp(buffer, rotated_log_filename_prefix, rotated_log_filename_prefix_len)) { |
| 622 | // Rotated file should have form log.txt.## |
| 623 | char* rotated_log_filename_suffix = buffer + rotated_log_filename_prefix_len; |
| 624 | char* endptr; |
| 625 | const long int suffix_value = strtol(rotated_log_filename_suffix, &endptr, 10); |
| 626 | EXPECT_EQ(rotated_log_filename_suffix + 2, endptr); |
| 627 | EXPECT_LE(suffix_value, 10); |
| 628 | EXPECT_GT(suffix_value, 0); |
| 629 | ++log_file_count; |
| 630 | continue; |
| 631 | } |
| 632 | |
| 633 | if (!strncmp(buffer, log_filename, strlen(log_filename))) { |
| 634 | ++log_file_count; |
| 635 | continue; |
| 636 | } |
| 637 | |
| 638 | fprintf(stderr, "ERROR: Unexpected file: %s", buffer); |
| 639 | ADD_FAILURE(); |
| 640 | } |
| 641 | pclose(fp); |
| 642 | EXPECT_EQ(11, log_file_count); |
| 643 | } |
Mark Salyzyn | 9812fc4 | 2015-10-06 08:59:02 -0700 | [diff] [blame] | 644 | snprintf(command, sizeof(command), "rm -rf %s", tmp_out_dir); |
| 645 | EXPECT_FALSE(system(command)); |
| 646 | } |
| 647 | |
| 648 | TEST(logcat, logrotate_continue) { |
| 649 | static const char tmp_out_dir_form[] = "/data/local/tmp/logcat.logrotate.XXXXXX"; |
| 650 | char tmp_out_dir[sizeof(tmp_out_dir_form)]; |
| 651 | ASSERT_TRUE(NULL != mkdtemp(strcpy(tmp_out_dir, tmp_out_dir_form))); |
| 652 | |
| 653 | static const char log_filename[] = "log.txt"; |
| 654 | static const char logcat_cmd[] = "logcat -b all -d -f %s/%s -n 256 -r 1024"; |
| 655 | static const char cleanup_cmd[] = "rm -rf %s"; |
| 656 | char command[sizeof(tmp_out_dir) + sizeof(logcat_cmd) + sizeof(log_filename)]; |
| 657 | snprintf(command, sizeof(command), logcat_cmd, tmp_out_dir, log_filename); |
| 658 | |
| 659 | int ret; |
| 660 | EXPECT_FALSE((ret = system(command))); |
| 661 | if (ret) { |
| 662 | snprintf(command, sizeof(command), cleanup_cmd, tmp_out_dir); |
| 663 | EXPECT_FALSE(system(command)); |
| 664 | return; |
| 665 | } |
| 666 | FILE *fp; |
| 667 | snprintf(command, sizeof(command), "%s/%s", tmp_out_dir, log_filename); |
| 668 | EXPECT_TRUE(NULL != ((fp = fopen(command, "r")))); |
| 669 | if (!fp) { |
| 670 | snprintf(command, sizeof(command), cleanup_cmd, tmp_out_dir); |
| 671 | EXPECT_FALSE(system(command)); |
| 672 | return; |
| 673 | } |
| 674 | char *line = NULL; |
| 675 | char *last_line = NULL; // this line is allowed to stutter, one-line overlap |
| 676 | char *second_last_line = NULL; |
| 677 | size_t len = 0; |
| 678 | while (getline(&line, &len, fp) != -1) { |
| 679 | free(second_last_line); |
| 680 | second_last_line = last_line; |
| 681 | last_line = line; |
| 682 | line = NULL; |
| 683 | } |
| 684 | fclose(fp); |
| 685 | free(line); |
| 686 | if (second_last_line == NULL) { |
| 687 | fprintf(stderr, "No second to last line, using last, test may fail\n"); |
| 688 | second_last_line = last_line; |
| 689 | last_line = NULL; |
| 690 | } |
| 691 | free(last_line); |
| 692 | EXPECT_TRUE(NULL != second_last_line); |
| 693 | if (!second_last_line) { |
| 694 | snprintf(command, sizeof(command), cleanup_cmd, tmp_out_dir); |
| 695 | EXPECT_FALSE(system(command)); |
| 696 | return; |
| 697 | } |
| 698 | // re-run the command, it should only add a few lines more content if it |
| 699 | // continues where it left off. |
| 700 | snprintf(command, sizeof(command), logcat_cmd, tmp_out_dir, log_filename); |
| 701 | EXPECT_FALSE((ret = system(command))); |
| 702 | if (ret) { |
| 703 | snprintf(command, sizeof(command), cleanup_cmd, tmp_out_dir); |
| 704 | EXPECT_FALSE(system(command)); |
| 705 | return; |
| 706 | } |
| 707 | DIR *dir; |
| 708 | EXPECT_TRUE(NULL != (dir = opendir(tmp_out_dir))); |
| 709 | if (!dir) { |
| 710 | snprintf(command, sizeof(command), cleanup_cmd, tmp_out_dir); |
| 711 | EXPECT_FALSE(system(command)); |
| 712 | return; |
| 713 | } |
| 714 | struct dirent *entry; |
| 715 | unsigned count = 0; |
| 716 | while ((entry = readdir(dir))) { |
| 717 | if (strncmp(entry->d_name, log_filename, sizeof(log_filename) - 1)) { |
| 718 | continue; |
| 719 | } |
| 720 | snprintf(command, sizeof(command), "%s/%s", tmp_out_dir, entry->d_name); |
| 721 | EXPECT_TRUE(NULL != ((fp = fopen(command, "r")))); |
| 722 | if (!fp) { |
| 723 | fprintf(stderr, "%s ?\n", command); |
| 724 | continue; |
| 725 | } |
| 726 | line = NULL; |
| 727 | size_t number = 0; |
| 728 | while (getline(&line, &len, fp) != -1) { |
| 729 | ++number; |
| 730 | if (!strcmp(line, second_last_line)) { |
| 731 | EXPECT_TRUE(++count <= 1); |
| 732 | fprintf(stderr, "%s(%zu):\n", entry->d_name, number); |
| 733 | } |
| 734 | } |
| 735 | fclose(fp); |
| 736 | free(line); |
| 737 | unlink(command); |
| 738 | } |
| 739 | closedir(dir); |
| 740 | if (count > 1) { |
| 741 | char *brk = strpbrk(second_last_line, "\r\n"); |
| 742 | if (!brk) { |
| 743 | brk = second_last_line + strlen(second_last_line); |
| 744 | } |
| 745 | fprintf(stderr, "\"%.*s\" occured %u times\n", |
| 746 | (int)(brk - second_last_line), second_last_line, count); |
| 747 | } |
| 748 | free(second_last_line); |
| 749 | |
| 750 | snprintf(command, sizeof(command), cleanup_cmd, tmp_out_dir); |
Aristidis Papaioannou | eba7344 | 2014-10-16 22:19:55 -0700 | [diff] [blame] | 751 | EXPECT_FALSE(system(command)); |
| 752 | } |
| 753 | |
Mark Salyzyn | 1ab87e7 | 2016-04-01 07:52:20 -0700 | [diff] [blame] | 754 | TEST(logcat, logrotate_nodir) { |
| 755 | // expect logcat to error out on writing content and exit(1) for nodir |
| 756 | EXPECT_EQ(W_EXITCODE(1, 0), |
| 757 | system("logcat -b all -d" |
| 758 | " -f /das/nein/gerfingerpoken/logcat/log.txt" |
| 759 | " -n 256 -r 1024")); |
| 760 | } |
| 761 | |
| 762 | static void caught_blocking_clear(int /*signum*/) { |
Mark Salyzyn | 9b98649 | 2014-01-22 10:30:09 -0800 | [diff] [blame] | 763 | unsigned long long v = 0xDEADBEEFA55C0000ULL; |
| 764 | |
| 765 | v += getpid() & 0xFFFF; |
| 766 | |
| 767 | LOG_FAILURE_RETRY(__android_log_btwrite(0, EVENT_TYPE_LONG, &v, sizeof(v))); |
| 768 | } |
| 769 | |
| 770 | TEST(logcat, blocking_clear) { |
| 771 | FILE *fp; |
| 772 | unsigned long long v = 0xDEADBEEFA55C0000ULL; |
| 773 | |
| 774 | pid_t pid = getpid(); |
| 775 | |
| 776 | v += pid & 0xFFFF; |
| 777 | |
| 778 | // This test is racey; an event occurs between clear and dump. |
| 779 | // We accept that we will get a false positive, but never a false negative. |
Mark Salyzyn | ef7c411 | 2014-03-11 10:35:58 -0700 | [diff] [blame] | 780 | ASSERT_TRUE(NULL != (fp = popen( |
Mark Salyzyn | 9b98649 | 2014-01-22 10:30:09 -0800 | [diff] [blame] | 781 | "( trap exit HUP QUIT INT PIPE KILL ; sleep 6; echo DONE )&" |
| 782 | " logcat -b events -c 2>&1 ;" |
Mark Salyzyn | a5e2429 | 2014-09-18 10:25:38 -0700 | [diff] [blame] | 783 | " logcat -v brief -b events 2>&1", |
Mark Salyzyn | 9b98649 | 2014-01-22 10:30:09 -0800 | [diff] [blame] | 784 | "r"))); |
| 785 | |
| 786 | char buffer[5120]; |
| 787 | |
| 788 | int count = 0; |
| 789 | |
| 790 | int signals = 0; |
| 791 | |
| 792 | signal(SIGALRM, caught_blocking_clear); |
| 793 | alarm(2); |
| 794 | while (fgets(buffer, sizeof(buffer), fp)) { |
Mark Salyzyn | 9b98649 | 2014-01-22 10:30:09 -0800 | [diff] [blame] | 795 | |
| 796 | if (!strncmp(buffer, "clearLog: ", 10)) { |
| 797 | fprintf(stderr, "WARNING: Test lacks permission to run :-(\n"); |
| 798 | count = signals = 1; |
| 799 | break; |
| 800 | } |
| 801 | |
| 802 | if (!strncmp(buffer, "DONE", 4)) { |
| 803 | break; |
| 804 | } |
| 805 | |
| 806 | ++count; |
| 807 | |
| 808 | int p; |
| 809 | unsigned long long l; |
| 810 | |
| 811 | if ((2 != sscanf(buffer, "I/[0] ( %u): %lld", &p, &l)) |
| 812 | || (p != pid)) { |
| 813 | continue; |
| 814 | } |
| 815 | |
| 816 | if (l == v) { |
| 817 | if (count > 1) { |
| 818 | fprintf(stderr, "WARNING: Possible false positive\n"); |
| 819 | } |
| 820 | ++signals; |
| 821 | break; |
| 822 | } |
| 823 | } |
| 824 | alarm(0); |
| 825 | signal(SIGALRM, SIG_DFL); |
| 826 | |
| 827 | // Generate SIGPIPE |
| 828 | fclose(fp); |
| 829 | caught_blocking_clear(0); |
| 830 | |
| 831 | pclose(fp); |
| 832 | |
Mark Salyzyn | ef7c411 | 2014-03-11 10:35:58 -0700 | [diff] [blame] | 833 | EXPECT_LE(1, count); |
Mark Salyzyn | 5d3d1f1 | 2013-12-09 13:47:00 -0800 | [diff] [blame] | 834 | |
Mark Salyzyn | ef7c411 | 2014-03-11 10:35:58 -0700 | [diff] [blame] | 835 | EXPECT_EQ(1, signals); |
Mark Salyzyn | 5d3d1f1 | 2013-12-09 13:47:00 -0800 | [diff] [blame] | 836 | } |
Mark Salyzyn | 95cfc7b | 2014-03-11 11:20:56 -0700 | [diff] [blame] | 837 | |
Mark Salyzyn | 95cfc7b | 2014-03-11 11:20:56 -0700 | [diff] [blame] | 838 | static bool get_white_black(char **list) { |
| 839 | FILE *fp; |
| 840 | |
| 841 | fp = popen("logcat -p 2>/dev/null", "r"); |
| 842 | if (fp == NULL) { |
| 843 | fprintf(stderr, "ERROR: logcat -p 2>/dev/null\n"); |
| 844 | return false; |
| 845 | } |
| 846 | |
| 847 | char buffer[5120]; |
| 848 | |
| 849 | while (fgets(buffer, sizeof(buffer), fp)) { |
| 850 | char *hold = *list; |
| 851 | char *buf = buffer; |
| 852 | while (isspace(*buf)) { |
| 853 | ++buf; |
| 854 | } |
| 855 | char *end = buf + strlen(buf); |
| 856 | while (isspace(*--end) && (end >= buf)) { |
| 857 | *end = '\0'; |
| 858 | } |
| 859 | if (end < buf) { |
| 860 | continue; |
| 861 | } |
| 862 | if (hold) { |
| 863 | asprintf(list, "%s %s", hold, buf); |
| 864 | free(hold); |
| 865 | } else { |
| 866 | asprintf(list, "%s", buf); |
| 867 | } |
| 868 | } |
| 869 | pclose(fp); |
| 870 | return *list != NULL; |
| 871 | } |
| 872 | |
| 873 | static bool set_white_black(const char *list) { |
| 874 | FILE *fp; |
| 875 | |
| 876 | char buffer[5120]; |
| 877 | |
Mark Salyzyn | 9879ac8 | 2014-06-03 11:24:34 -0700 | [diff] [blame] | 878 | snprintf(buffer, sizeof(buffer), "logcat -P '%s' 2>&1", list ? list : ""); |
Mark Salyzyn | 95cfc7b | 2014-03-11 11:20:56 -0700 | [diff] [blame] | 879 | fp = popen(buffer, "r"); |
| 880 | if (fp == NULL) { |
| 881 | fprintf(stderr, "ERROR: %s\n", buffer); |
| 882 | return false; |
| 883 | } |
| 884 | |
| 885 | while (fgets(buffer, sizeof(buffer), fp)) { |
| 886 | char *buf = buffer; |
| 887 | while (isspace(*buf)) { |
| 888 | ++buf; |
| 889 | } |
| 890 | char *end = buf + strlen(buf); |
Mark Salyzyn | 9879ac8 | 2014-06-03 11:24:34 -0700 | [diff] [blame] | 891 | while ((end > buf) && isspace(*--end)) { |
Mark Salyzyn | 95cfc7b | 2014-03-11 11:20:56 -0700 | [diff] [blame] | 892 | *end = '\0'; |
| 893 | } |
Mark Salyzyn | 9879ac8 | 2014-06-03 11:24:34 -0700 | [diff] [blame] | 894 | if (end <= buf) { |
Mark Salyzyn | 95cfc7b | 2014-03-11 11:20:56 -0700 | [diff] [blame] | 895 | continue; |
| 896 | } |
| 897 | fprintf(stderr, "%s\n", buf); |
| 898 | pclose(fp); |
| 899 | return false; |
| 900 | } |
| 901 | return pclose(fp) == 0; |
| 902 | } |
| 903 | |
| 904 | TEST(logcat, white_black_adjust) { |
| 905 | char *list = NULL; |
| 906 | char *adjust = NULL; |
| 907 | |
Mark Salyzyn | 9879ac8 | 2014-06-03 11:24:34 -0700 | [diff] [blame] | 908 | get_white_black(&list); |
Mark Salyzyn | 95cfc7b | 2014-03-11 11:20:56 -0700 | [diff] [blame] | 909 | |
Mark Salyzyn | 22e287d | 2014-03-21 13:12:16 -0700 | [diff] [blame] | 910 | static const char adjustment[] = "~! 300/20 300/25 2000 ~1000/5 ~1000/30"; |
Mark Salyzyn | 95cfc7b | 2014-03-11 11:20:56 -0700 | [diff] [blame] | 911 | ASSERT_EQ(true, set_white_black(adjustment)); |
| 912 | ASSERT_EQ(true, get_white_black(&adjust)); |
Mark Salyzyn | ef7c411 | 2014-03-11 10:35:58 -0700 | [diff] [blame] | 913 | EXPECT_STREQ(adjustment, adjust); |
Mark Salyzyn | 95cfc7b | 2014-03-11 11:20:56 -0700 | [diff] [blame] | 914 | free(adjust); |
| 915 | adjust = NULL; |
| 916 | |
Mark Salyzyn | 22e287d | 2014-03-21 13:12:16 -0700 | [diff] [blame] | 917 | static const char adjustment2[] = "300/20 300/21 2000 ~1000"; |
| 918 | ASSERT_EQ(true, set_white_black(adjustment2)); |
| 919 | ASSERT_EQ(true, get_white_black(&adjust)); |
Mark Salyzyn | ef7c411 | 2014-03-11 10:35:58 -0700 | [diff] [blame] | 920 | EXPECT_STREQ(adjustment2, adjust); |
Mark Salyzyn | 22e287d | 2014-03-21 13:12:16 -0700 | [diff] [blame] | 921 | free(adjust); |
| 922 | adjust = NULL; |
| 923 | |
Mark Salyzyn | 95cfc7b | 2014-03-11 11:20:56 -0700 | [diff] [blame] | 924 | ASSERT_EQ(true, set_white_black(list)); |
Mark Salyzyn | 9879ac8 | 2014-06-03 11:24:34 -0700 | [diff] [blame] | 925 | get_white_black(&adjust); |
| 926 | EXPECT_STREQ(list ? list : "", adjust ? adjust : ""); |
Mark Salyzyn | 95cfc7b | 2014-03-11 11:20:56 -0700 | [diff] [blame] | 927 | free(adjust); |
| 928 | adjust = NULL; |
| 929 | |
| 930 | free(list); |
| 931 | list = NULL; |
| 932 | } |
Casey Dahlin | 0f7732d | 2016-03-17 16:18:55 -0700 | [diff] [blame] | 933 | |
| 934 | TEST(logcat, regex) { |
| 935 | FILE *fp; |
| 936 | int count = 0; |
| 937 | |
| 938 | char buffer[5120]; |
| 939 | |
| 940 | snprintf(buffer, sizeof(buffer), "logcat --pid %d -d -e logcat_test_a+b", getpid()); |
| 941 | |
| 942 | LOG_FAILURE_RETRY(__android_log_print(ANDROID_LOG_WARN, "logcat_test", "logcat_test_ab")); |
| 943 | LOG_FAILURE_RETRY(__android_log_print(ANDROID_LOG_WARN, "logcat_test", "logcat_test_b")); |
| 944 | LOG_FAILURE_RETRY(__android_log_print(ANDROID_LOG_WARN, "logcat_test", "logcat_test_aaaab")); |
| 945 | LOG_FAILURE_RETRY(__android_log_print(ANDROID_LOG_WARN, "logcat_test", "logcat_test_aaaa")); |
| 946 | |
| 947 | // Let the logs settle |
| 948 | sleep(1); |
| 949 | |
| 950 | ASSERT_TRUE(NULL != (fp = popen(buffer, "r"))); |
| 951 | |
| 952 | while (fgets(buffer, sizeof(buffer), fp)) { |
| 953 | if (!strncmp(begin, buffer, sizeof(begin) - 1)) { |
| 954 | continue; |
| 955 | } |
| 956 | |
| 957 | EXPECT_TRUE(strstr(buffer, "logcat_test_") != NULL); |
| 958 | |
| 959 | count++; |
| 960 | } |
| 961 | |
| 962 | pclose(fp); |
| 963 | |
| 964 | ASSERT_EQ(2, count); |
| 965 | } |
Casey Dahlin | 1164ef6 | 2016-03-17 14:04:52 -0700 | [diff] [blame] | 966 | |
| 967 | TEST(logcat, maxcount) { |
| 968 | FILE *fp; |
| 969 | int count = 0; |
| 970 | |
| 971 | char buffer[5120]; |
| 972 | |
| 973 | snprintf(buffer, sizeof(buffer), "logcat --pid %d -d --max-count 3", getpid()); |
| 974 | |
| 975 | LOG_FAILURE_RETRY(__android_log_print(ANDROID_LOG_WARN, "logcat_test", "logcat_test")); |
| 976 | LOG_FAILURE_RETRY(__android_log_print(ANDROID_LOG_WARN, "logcat_test", "logcat_test")); |
| 977 | LOG_FAILURE_RETRY(__android_log_print(ANDROID_LOG_WARN, "logcat_test", "logcat_test")); |
| 978 | LOG_FAILURE_RETRY(__android_log_print(ANDROID_LOG_WARN, "logcat_test", "logcat_test")); |
| 979 | |
| 980 | // Let the logs settle |
| 981 | sleep(1); |
| 982 | |
| 983 | ASSERT_TRUE(NULL != (fp = popen(buffer, "r"))); |
| 984 | |
| 985 | while (fgets(buffer, sizeof(buffer), fp)) { |
| 986 | if (!strncmp(begin, buffer, sizeof(begin) - 1)) { |
| 987 | continue; |
| 988 | } |
| 989 | |
| 990 | count++; |
| 991 | } |
| 992 | |
| 993 | pclose(fp); |
| 994 | |
| 995 | ASSERT_EQ(3, count); |
| 996 | } |