1 /* 2 * Copyright (C) 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 <fcntl.h> 18 #include <inttypes.h> 19 #include <poll.h> 20 #include <signal.h> 21 #include <stdio.h> 22 #include <string.h> 23 24 #include <string> 25 26 #include <gtest/gtest.h> 27 28 #include <android-base/stringprintf.h> 29 #include <cutils/sockets.h> 30 #include <log/log.h> 31 #include <log/logger.h> 32 33 #include "../LogReader.h" // pickup LOGD_SNDTIMEO 34 35 /* 36 * returns statistics 37 */ 38 static void my_android_logger_get_statistics(char *buf, size_t len) 39 { 40 snprintf(buf, len, "getStatistics 0 1 2 3 4"); 41 int sock = socket_local_client("logd", 42 ANDROID_SOCKET_NAMESPACE_RESERVED, 43 SOCK_STREAM); 44 if (sock >= 0) { 45 if (write(sock, buf, strlen(buf) + 1) > 0) { 46 ssize_t ret; 47 while ((ret = read(sock, buf, len)) > 0) { 48 if ((size_t)ret == len) { 49 break; 50 } 51 len -= ret; 52 buf += ret; 53 54 struct pollfd p = { 55 .fd = sock, 56 .events = POLLIN, 57 .revents = 0 58 }; 59 60 ret = poll(&p, 1, 20); 61 if ((ret <= 0) || !(p.revents & POLLIN)) { 62 break; 63 } 64 } 65 } 66 close(sock); 67 } 68 } 69 70 static void alloc_statistics(char **buffer, size_t *length) 71 { 72 size_t len = 8192; 73 char *buf; 74 75 for(int retry = 32; (retry >= 0); delete [] buf, --retry) { 76 buf = new char [len]; 77 my_android_logger_get_statistics(buf, len); 78 79 buf[len-1] = '\0'; 80 size_t ret = atol(buf) + 1; 81 if (ret < 4) { 82 delete [] buf; 83 buf = NULL; 84 break; 85 } 86 bool check = ret <= len; 87 len = ret; 88 if (check) { 89 break; 90 } 91 len += len / 8; // allow for some slop 92 } 93 *buffer = buf; 94 *length = len; 95 } 96 97 static char *find_benchmark_spam(char *cp) 98 { 99 // liblog_benchmarks has been run designed to SPAM. The signature of 100 // a noisiest UID statistics is: 101 // 102 // Chattiest UIDs in main log buffer: Size Pruned 103 // UID PACKAGE BYTES LINES 104 // 0 root 54164 147569 105 // 106 char *benchmark = NULL; 107 do { 108 static const char signature[] = "\n0 root "; 109 110 benchmark = strstr(cp, signature); 111 if (!benchmark) { 112 break; 113 } 114 cp = benchmark + sizeof(signature); 115 while (isspace(*cp)) { 116 ++cp; 117 } 118 benchmark = cp; 119 #ifdef DEBUG 120 char *end = strstr(benchmark, "\n"); 121 if (end == NULL) { 122 end = benchmark + strlen(benchmark); 123 } 124 fprintf(stderr, "parse for spam counter in \"%.*s\"\n", 125 (int)(end - benchmark), benchmark); 126 #endif 127 // content 128 while (isdigit(*cp)) { 129 ++cp; 130 } 131 while (isspace(*cp)) { 132 ++cp; 133 } 134 // optional +/- field? 135 if ((*cp == '-') || (*cp == '+')) { 136 while (isdigit(*++cp) || 137 (*cp == '.') || (*cp == '%') || (*cp == 'X')) { 138 ; 139 } 140 while (isspace(*cp)) { 141 ++cp; 142 } 143 } 144 // number of entries pruned 145 unsigned long value = 0; 146 while (isdigit(*cp)) { 147 value = value * 10ULL + *cp - '0'; 148 ++cp; 149 } 150 if (value > 10UL) { 151 break; 152 } 153 benchmark = NULL; 154 } while (*cp); 155 return benchmark; 156 } 157 158 TEST(logd, statistics) { 159 size_t len; 160 char *buf; 161 162 alloc_statistics(&buf, &len); 163 164 ASSERT_TRUE(NULL != buf); 165 166 // remove trailing FF 167 char *cp = buf + len - 1; 168 *cp = '\0'; 169 bool truncated = *--cp != '\f'; 170 if (!truncated) { 171 *cp = '\0'; 172 } 173 174 // squash out the byte count 175 cp = buf; 176 if (!truncated) { 177 while (isdigit(*cp) || (*cp == '\n')) { 178 ++cp; 179 } 180 } 181 182 fprintf(stderr, "%s", cp); 183 184 EXPECT_LT((size_t)64, strlen(cp)); 185 186 EXPECT_EQ(0, truncated); 187 188 char *main_logs = strstr(cp, "\nChattiest UIDs in main "); 189 EXPECT_TRUE(NULL != main_logs); 190 191 char *radio_logs = strstr(cp, "\nChattiest UIDs in radio "); 192 EXPECT_TRUE(NULL != radio_logs); 193 194 char *system_logs = strstr(cp, "\nChattiest UIDs in system "); 195 EXPECT_TRUE(NULL != system_logs); 196 197 char *events_logs = strstr(cp, "\nChattiest UIDs in events "); 198 EXPECT_TRUE(NULL != events_logs); 199 200 delete [] buf; 201 } 202 203 static void caught_signal(int /* signum */) { } 204 205 static void dump_log_msg(const char *prefix, 206 log_msg *msg, unsigned int version, int lid) { 207 std::cout << std::flush; 208 std::cerr << std::flush; 209 fflush(stdout); 210 fflush(stderr); 211 switch(msg->entry.hdr_size) { 212 case 0: 213 version = 1; 214 break; 215 216 case sizeof(msg->entry_v2): 217 if (version == 0) { 218 version = 2; 219 } 220 break; 221 } 222 223 fprintf(stderr, "%s: v%u[%u] ", prefix, version, msg->len()); 224 if (version != 1) { 225 fprintf(stderr, "hdr_size=%u ", msg->entry.hdr_size); 226 } 227 fprintf(stderr, "pid=%u tid=%u %u.%09u ", 228 msg->entry.pid, msg->entry.tid, msg->entry.sec, msg->entry.nsec); 229 switch(version) { 230 case 1: 231 break; 232 case 2: 233 fprintf(stderr, "euid=%u ", msg->entry_v2.euid); 234 break; 235 case 3: 236 default: 237 lid = msg->entry.lid; 238 break; 239 } 240 241 switch(lid) { 242 case 0: 243 fprintf(stderr, "lid=main "); 244 break; 245 case 1: 246 fprintf(stderr, "lid=radio "); 247 break; 248 case 2: 249 fprintf(stderr, "lid=events "); 250 break; 251 case 3: 252 fprintf(stderr, "lid=system "); 253 break; 254 case 4: 255 fprintf(stderr, "lid=crash "); 256 break; 257 case 5: 258 fprintf(stderr, "lid=security "); 259 break; 260 case 6: 261 fprintf(stderr, "lid=kernel "); 262 break; 263 default: 264 if (lid >= 0) { 265 fprintf(stderr, "lid=%d ", lid); 266 } 267 } 268 269 unsigned int len = msg->entry.len; 270 fprintf(stderr, "msg[%u]={", len); 271 unsigned char *cp = reinterpret_cast<unsigned char *>(msg->msg()); 272 while(len) { 273 unsigned char *p = cp; 274 while (*p && (((' ' <= *p) && (*p < 0x7F)) || (*p == '\n'))) { 275 ++p; 276 } 277 if (((p - cp) > 3) && !*p && ((unsigned int)(p - cp) < len)) { 278 fprintf(stderr, "\""); 279 while (*cp) { 280 if (*cp != '\n') { 281 fprintf(stderr, "%c", *cp); 282 } else { 283 fprintf(stderr, "\\n"); 284 } 285 ++cp; 286 --len; 287 } 288 fprintf(stderr, "\""); 289 } else { 290 fprintf(stderr, "%02x", *cp); 291 } 292 ++cp; 293 if (--len) { 294 fprintf(stderr, ", "); 295 } 296 } 297 fprintf(stderr, "}\n"); 298 fflush(stderr); 299 } 300 301 TEST(logd, both) { 302 log_msg msg; 303 304 // check if we can read any logs from logd 305 bool user_logger_available = false; 306 bool user_logger_content = false; 307 308 int fd = socket_local_client("logdr", 309 ANDROID_SOCKET_NAMESPACE_RESERVED, 310 SOCK_SEQPACKET); 311 if (fd >= 0) { 312 struct sigaction ignore, old_sigaction; 313 memset(&ignore, 0, sizeof(ignore)); 314 ignore.sa_handler = caught_signal; 315 sigemptyset(&ignore.sa_mask); 316 sigaction(SIGALRM, &ignore, &old_sigaction); 317 unsigned int old_alarm = alarm(10); 318 319 static const char ask[] = "dumpAndClose lids=0,1,2,3"; 320 user_logger_available = write(fd, ask, sizeof(ask)) == sizeof(ask); 321 322 user_logger_content = recv(fd, msg.buf, sizeof(msg), 0) > 0; 323 324 if (user_logger_content) { 325 dump_log_msg("user", &msg, 3, -1); 326 } 327 328 alarm(old_alarm); 329 sigaction(SIGALRM, &old_sigaction, NULL); 330 331 close(fd); 332 } 333 334 // check if we can read any logs from kernel logger 335 bool kernel_logger_available = false; 336 bool kernel_logger_content = false; 337 338 static const char *loggers[] = { 339 "/dev/log/main", "/dev/log_main", 340 "/dev/log/radio", "/dev/log_radio", 341 "/dev/log/events", "/dev/log_events", 342 "/dev/log/system", "/dev/log_system", 343 }; 344 345 for (unsigned int i = 0; i < (sizeof(loggers) / sizeof(loggers[0])); ++i) { 346 fd = open(loggers[i], O_RDONLY); 347 if (fd < 0) { 348 continue; 349 } 350 kernel_logger_available = true; 351 fcntl(fd, F_SETFL, O_RDONLY | O_NONBLOCK); 352 int result = TEMP_FAILURE_RETRY(read(fd, msg.buf, sizeof(msg))); 353 if (result > 0) { 354 kernel_logger_content = true; 355 dump_log_msg("kernel", &msg, 0, i / 2); 356 } 357 close(fd); 358 } 359 360 static const char yes[] = "\xE2\x9C\x93"; 361 static const char no[] = "\xE2\x9c\x98"; 362 fprintf(stderr, 363 "LOGGER Available Content\n" 364 "user %-13s%s\n" 365 "kernel %-13s%s\n" 366 " status %-11s%s\n", 367 (user_logger_available) ? yes : no, 368 (user_logger_content) ? yes : no, 369 (kernel_logger_available) ? yes : no, 370 (kernel_logger_content) ? yes : no, 371 (user_logger_available && kernel_logger_available) ? "ERROR" : "ok", 372 (user_logger_content && kernel_logger_content) ? "ERROR" : "ok"); 373 374 EXPECT_EQ(0, user_logger_available && kernel_logger_available); 375 EXPECT_EQ(0, !user_logger_available && !kernel_logger_available); 376 EXPECT_EQ(0, user_logger_content && kernel_logger_content); 377 EXPECT_EQ(0, !user_logger_content && !kernel_logger_content); 378 } 379 380 // BAD ROBOT 381 // Benchmark threshold are generally considered bad form unless there is 382 // is some human love applied to the continued maintenance and whether the 383 // thresholds are tuned on a per-target basis. Here we check if the values 384 // are more than double what is expected. Doubling will not prevent failure 385 // on busy or low-end systems that could have a tendency to stretch values. 386 // 387 // The primary goal of this test is to simulate a spammy app (benchmark 388 // being the worst) and check to make sure the logger can deal with it 389 // appropriately by checking all the statistics are in an expected range. 390 // 391 TEST(logd, benchmark) { 392 size_t len; 393 char *buf; 394 395 alloc_statistics(&buf, &len); 396 bool benchmark_already_run = buf && find_benchmark_spam(buf); 397 delete [] buf; 398 399 if (benchmark_already_run) { 400 fprintf(stderr, "WARNING: spam already present and too much history\n" 401 " false OK for prune by worst UID check\n"); 402 } 403 404 FILE *fp; 405 406 // Introduce some extreme spam for the worst UID filter 407 ASSERT_TRUE(NULL != (fp = popen( 408 "/data/nativetest/liblog-benchmarks/liblog-benchmarks", 409 "r"))); 410 411 char buffer[5120]; 412 413 static const char *benchmarks[] = { 414 "BM_log_maximum_retry ", 415 "BM_log_maximum ", 416 "BM_clock_overhead ", 417 "BM_log_overhead ", 418 "BM_log_latency ", 419 "BM_log_delay " 420 }; 421 static const unsigned int log_maximum_retry = 0; 422 static const unsigned int log_maximum = 1; 423 static const unsigned int clock_overhead = 2; 424 static const unsigned int log_overhead = 3; 425 static const unsigned int log_latency = 4; 426 static const unsigned int log_delay = 5; 427 428 unsigned long ns[sizeof(benchmarks) / sizeof(benchmarks[0])]; 429 430 memset(ns, 0, sizeof(ns)); 431 432 while (fgets(buffer, sizeof(buffer), fp)) { 433 for (unsigned i = 0; i < sizeof(ns) / sizeof(ns[0]); ++i) { 434 char *cp = strstr(buffer, benchmarks[i]); 435 if (!cp) { 436 continue; 437 } 438 sscanf(cp, "%*s %lu %lu", &ns[i], &ns[i]); 439 fprintf(stderr, "%-22s%8lu\n", benchmarks[i], ns[i]); 440 } 441 } 442 int ret = pclose(fp); 443 444 if (!WIFEXITED(ret) || (WEXITSTATUS(ret) == 127)) { 445 fprintf(stderr, 446 "WARNING: " 447 "/data/nativetest/liblog-benchmarks/liblog-benchmarks missing\n" 448 " can not perform test\n"); 449 return; 450 } 451 452 EXPECT_GE(200000UL, ns[log_maximum_retry]); // 104734 user 453 454 EXPECT_GE(90000UL, ns[log_maximum]); // 46913 user 455 456 EXPECT_GE(4096UL, ns[clock_overhead]); // 4095 457 458 EXPECT_GE(250000UL, ns[log_overhead]); // 126886 user 459 460 EXPECT_GE(10000000UL, ns[log_latency]); // 1453559 user space (background cgroup) 461 462 EXPECT_GE(20000000UL, ns[log_delay]); // 10500289 user 463 464 for (unsigned i = 0; i < sizeof(ns) / sizeof(ns[0]); ++i) { 465 EXPECT_NE(0UL, ns[i]); 466 } 467 468 alloc_statistics(&buf, &len); 469 470 bool collected_statistics = !!buf; 471 EXPECT_EQ(true, collected_statistics); 472 473 ASSERT_TRUE(NULL != buf); 474 475 char *benchmark_statistics_found = find_benchmark_spam(buf); 476 ASSERT_TRUE(benchmark_statistics_found != NULL); 477 478 // Check how effective the SPAM filter is, parse out Now size. 479 // 0 root 54164 147569 480 // ^-- benchmark_statistics_found 481 482 unsigned long nowSpamSize = atol(benchmark_statistics_found); 483 484 delete [] buf; 485 486 ASSERT_NE(0UL, nowSpamSize); 487 488 // Determine if we have the spam filter enabled 489 int sock = socket_local_client("logd", 490 ANDROID_SOCKET_NAMESPACE_RESERVED, 491 SOCK_STREAM); 492 493 ASSERT_TRUE(sock >= 0); 494 495 static const char getPruneList[] = "getPruneList"; 496 if (write(sock, getPruneList, sizeof(getPruneList)) > 0) { 497 char buffer[80]; 498 memset(buffer, 0, sizeof(buffer)); 499 read(sock, buffer, sizeof(buffer)); 500 char *cp = strchr(buffer, '\n'); 501 if (!cp || (cp[1] != '~') || (cp[2] != '!')) { 502 close(sock); 503 fprintf(stderr, 504 "WARNING: " 505 "Logger has SPAM filtration turned off \"%s\"\n", buffer); 506 return; 507 } 508 } else { 509 int save_errno = errno; 510 close(sock); 511 FAIL() << "Can not send " << getPruneList << " to logger -- " << strerror(save_errno); 512 } 513 514 static const unsigned long expected_absolute_minimum_log_size = 65536UL; 515 unsigned long totalSize = expected_absolute_minimum_log_size; 516 static const char getSize[] = { 517 'g', 'e', 't', 'L', 'o', 'g', 'S', 'i', 'z', 'e', ' ', 518 LOG_ID_MAIN + '0', '\0' 519 }; 520 if (write(sock, getSize, sizeof(getSize)) > 0) { 521 char buffer[80]; 522 memset(buffer, 0, sizeof(buffer)); 523 read(sock, buffer, sizeof(buffer)); 524 totalSize = atol(buffer); 525 if (totalSize < expected_absolute_minimum_log_size) { 526 fprintf(stderr, 527 "WARNING: " 528 "Logger had unexpected referenced size \"%s\"\n", buffer); 529 totalSize = expected_absolute_minimum_log_size; 530 } 531 } 532 close(sock); 533 534 // logd allows excursions to 110% of total size 535 totalSize = (totalSize * 11 ) / 10; 536 537 // 50% threshold for SPAM filter (<20% typical, lots of engineering margin) 538 ASSERT_GT(totalSize, nowSpamSize * 2); 539 } 540 541 // b/26447386 confirm fixed 542 void timeout_negative(const char *command) { 543 log_msg msg_wrap, msg_timeout; 544 bool content_wrap = false, content_timeout = false, written = false; 545 unsigned int alarm_wrap = 0, alarm_timeout = 0; 546 // A few tries to get it right just in case wrap kicks in due to 547 // content providers being active during the test. 548 int i = 3; 549 550 while (--i) { 551 int fd = socket_local_client("logdr", 552 ANDROID_SOCKET_NAMESPACE_RESERVED, 553 SOCK_SEQPACKET); 554 ASSERT_LT(0, fd); 555 556 std::string ask(command); 557 558 struct sigaction ignore, old_sigaction; 559 memset(&ignore, 0, sizeof(ignore)); 560 ignore.sa_handler = caught_signal; 561 sigemptyset(&ignore.sa_mask); 562 sigaction(SIGALRM, &ignore, &old_sigaction); 563 unsigned int old_alarm = alarm(3); 564 565 size_t len = ask.length() + 1; 566 written = write(fd, ask.c_str(), len) == (ssize_t)len; 567 if (!written) { 568 alarm(old_alarm); 569 sigaction(SIGALRM, &old_sigaction, NULL); 570 close(fd); 571 continue; 572 } 573 574 content_wrap = recv(fd, msg_wrap.buf, sizeof(msg_wrap), 0) > 0; 575 576 alarm_wrap = alarm(5); 577 578 content_timeout = recv(fd, msg_timeout.buf, sizeof(msg_timeout), 0) > 0; 579 if (!content_timeout) { // make sure we hit dumpAndClose 580 content_timeout = recv(fd, msg_timeout.buf, sizeof(msg_timeout), 0) > 0; 581 } 582 583 alarm_timeout = alarm((old_alarm <= 0) 584 ? old_alarm 585 : (old_alarm > (1 + 3 - alarm_wrap)) 586 ? old_alarm - 3 + alarm_wrap 587 : 2); 588 sigaction(SIGALRM, &old_sigaction, NULL); 589 590 close(fd); 591 592 if (!content_wrap && !alarm_wrap && content_timeout && alarm_timeout) { 593 break; 594 } 595 } 596 597 if (content_wrap) { 598 dump_log_msg("wrap", &msg_wrap, 3, -1); 599 } 600 601 if (content_timeout) { 602 dump_log_msg("timeout", &msg_timeout, 3, -1); 603 } 604 605 EXPECT_TRUE(written); 606 EXPECT_TRUE(content_wrap); 607 EXPECT_NE(0U, alarm_wrap); 608 EXPECT_TRUE(content_timeout); 609 EXPECT_NE(0U, alarm_timeout); 610 } 611 612 TEST(logd, timeout_no_start) { 613 timeout_negative("dumpAndClose lids=0,1,2,3,4,5 timeout=6"); 614 } 615 616 TEST(logd, timeout_start_epoch) { 617 timeout_negative("dumpAndClose lids=0,1,2,3,4,5 timeout=6 start=0.000000000"); 618 } 619 620 // b/26447386 refined behavior 621 TEST(logd, timeout) { 622 log_msg msg_wrap, msg_timeout; 623 bool content_wrap = false, content_timeout = false, written = false; 624 unsigned int alarm_wrap = 0, alarm_timeout = 0; 625 // A few tries to get it right just in case wrap kicks in due to 626 // content providers being active during the test 627 int i = 5; 628 log_time now(android_log_clockid()); 629 now.tv_sec -= 30; // reach back a moderate period of time 630 631 while (--i) { 632 int fd = socket_local_client("logdr", 633 ANDROID_SOCKET_NAMESPACE_RESERVED, 634 SOCK_SEQPACKET); 635 ASSERT_LT(0, fd); 636 637 std::string ask = android::base::StringPrintf( 638 "dumpAndClose lids=0,1,2,3,4,5 timeout=6 start=%" 639 PRIu32 ".%09" PRIu32, 640 now.tv_sec, now.tv_nsec); 641 642 struct sigaction ignore, old_sigaction; 643 memset(&ignore, 0, sizeof(ignore)); 644 ignore.sa_handler = caught_signal; 645 sigemptyset(&ignore.sa_mask); 646 sigaction(SIGALRM, &ignore, &old_sigaction); 647 unsigned int old_alarm = alarm(3); 648 649 size_t len = ask.length() + 1; 650 written = write(fd, ask.c_str(), len) == (ssize_t)len; 651 if (!written) { 652 alarm(old_alarm); 653 sigaction(SIGALRM, &old_sigaction, NULL); 654 close(fd); 655 continue; 656 } 657 658 content_wrap = recv(fd, msg_wrap.buf, sizeof(msg_wrap), 0) > 0; 659 660 alarm_wrap = alarm(5); 661 662 content_timeout = recv(fd, msg_timeout.buf, sizeof(msg_timeout), 0) > 0; 663 if (!content_timeout) { // make sure we hit dumpAndClose 664 content_timeout = recv(fd, msg_timeout.buf, sizeof(msg_timeout), 0) > 0; 665 } 666 667 alarm_timeout = alarm((old_alarm <= 0) 668 ? old_alarm 669 : (old_alarm > (1 + 3 - alarm_wrap)) 670 ? old_alarm - 3 + alarm_wrap 671 : 2); 672 sigaction(SIGALRM, &old_sigaction, NULL); 673 674 close(fd); 675 676 if (!content_wrap && !alarm_wrap && content_timeout && alarm_timeout) { 677 break; 678 } 679 680 // modify start time in case content providers are relatively 681 // active _or_ inactive during the test. 682 if (content_timeout) { 683 log_time msg(msg_timeout.entry.sec, msg_timeout.entry.nsec); 684 EXPECT_FALSE(msg < now); 685 if (msg > now) { 686 now = msg; 687 now.tv_sec += 30; 688 msg = log_time(android_log_clockid()); 689 if (now > msg) { 690 now = msg; 691 --now.tv_sec; 692 } 693 } 694 } else { 695 now.tv_sec -= 120; // inactive, reach further back! 696 } 697 } 698 699 if (content_wrap) { 700 dump_log_msg("wrap", &msg_wrap, 3, -1); 701 } 702 703 if (content_timeout) { 704 dump_log_msg("timeout", &msg_timeout, 3, -1); 705 } 706 707 if (content_wrap || !content_timeout) { 708 fprintf(stderr, "now=%" PRIu32 ".%09" PRIu32 "\n", 709 now.tv_sec, now.tv_nsec); 710 } 711 712 EXPECT_TRUE(written); 713 EXPECT_FALSE(content_wrap); 714 EXPECT_EQ(0U, alarm_wrap); 715 EXPECT_TRUE(content_timeout); 716 EXPECT_NE(0U, alarm_timeout); 717 } 718 719 // b/27242723 confirmed fixed 720 TEST(logd, SNDTIMEO) { 721 static const unsigned sndtimeo = LOGD_SNDTIMEO; // <sigh> it has to be done! 722 static const unsigned sleep_time = sndtimeo + 3; 723 static const unsigned alarm_time = sleep_time + 5; 724 725 int fd; 726 727 ASSERT_TRUE((fd = socket_local_client("logdr", 728 ANDROID_SOCKET_NAMESPACE_RESERVED, 729 SOCK_SEQPACKET)) > 0); 730 731 struct sigaction ignore, old_sigaction; 732 memset(&ignore, 0, sizeof(ignore)); 733 ignore.sa_handler = caught_signal; 734 sigemptyset(&ignore.sa_mask); 735 sigaction(SIGALRM, &ignore, &old_sigaction); 736 unsigned int old_alarm = alarm(alarm_time); 737 738 static const char ask[] = "stream lids=0,1,2,3,4,5,6"; // all sources 739 bool reader_requested = write(fd, ask, sizeof(ask)) == sizeof(ask); 740 EXPECT_TRUE(reader_requested); 741 742 log_msg msg; 743 bool read_one = recv(fd, msg.buf, sizeof(msg), 0) > 0; 744 745 EXPECT_TRUE(read_one); 746 if (read_one) { 747 dump_log_msg("user", &msg, 3, -1); 748 } 749 750 fprintf (stderr, "Sleep for >%d seconds logd SO_SNDTIMEO ...\n", sndtimeo); 751 sleep(sleep_time); 752 753 // flush will block if we did not trigger. if it did, last entry returns 0 754 int recv_ret; 755 do { 756 recv_ret = recv(fd, msg.buf, sizeof(msg), 0); 757 } while (recv_ret > 0); 758 int save_errno = (recv_ret < 0) ? errno : 0; 759 760 EXPECT_NE(0U, alarm(old_alarm)); 761 sigaction(SIGALRM, &old_sigaction, NULL); 762 763 EXPECT_EQ(0, recv_ret); 764 if (recv_ret > 0) { 765 dump_log_msg("user", &msg, 3, -1); 766 } 767 EXPECT_EQ(0, save_errno); 768 769 close(fd); 770 } 771
