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