diff options
author | Alan Stokes | 2017-08-01 10:43:02 -0500 |
---|---|---|
committer | Alan Stokes | 2017-08-25 12:21:36 -0500 |
commit | e0515d6dba5fa50e6319ab65b94232ed88bebd72 (patch) | |
tree | 63f54512f400fbe51adb5b4137209bcda12596db /liblog | |
parent | 3094de968443c60345f63318f14a5d919df762d5 (diff) | |
download | platform-system-core-e0515d6dba5fa50e6319ab65b94232ed88bebd72.tar.gz platform-system-core-e0515d6dba5fa50e6319ab65b94232ed88bebd72.tar.xz platform-system-core-e0515d6dba5fa50e6319ab65b94232ed88bebd72.zip |
Reading from logd in WRAP mode is expected to take a long time,
don't abort it after 30s.
Adds a new CTS test to verify the behaviour.
Bug: 64143705
Test: New and existing CTS tests pass. Manual testing with logcat.
(cherry picked from commit 64acdf77d6f89a72be9192b35e0fc34242c23e34)
Change-Id: Ic2ec131a3aee293ee865c46e62566ddd82ec2507
Diffstat (limited to 'liblog')
-rw-r--r-- | liblog/logd_reader.c | 14 | ||||
-rw-r--r-- | liblog/tests/Android.mk | 3 | ||||
-rw-r--r-- | liblog/tests/log_wrap_test.cpp | 121 |
3 files changed, 135 insertions, 3 deletions
diff --git a/liblog/logd_reader.c b/liblog/logd_reader.c index 600f4bb0b..603ba2469 100644 --- a/liblog/logd_reader.c +++ b/liblog/logd_reader.c | |||
@@ -590,20 +590,30 @@ static int logdRead(struct android_log_logger_list* logger_list, | |||
590 | 590 | ||
591 | memset(log_msg, 0, sizeof(*log_msg)); | 591 | memset(log_msg, 0, sizeof(*log_msg)); |
592 | 592 | ||
593 | unsigned int new_alarm = 0; | ||
593 | if (logger_list->mode & ANDROID_LOG_NONBLOCK) { | 594 | if (logger_list->mode & ANDROID_LOG_NONBLOCK) { |
595 | if ((logger_list->mode & ANDROID_LOG_WRAP) && | ||
596 | (logger_list->start.tv_sec || logger_list->start.tv_nsec)) { | ||
597 | /* b/64143705 */ | ||
598 | new_alarm = (ANDROID_LOG_WRAP_DEFAULT_TIMEOUT * 11) / 10 + 10; | ||
599 | logger_list->mode &= ~ANDROID_LOG_WRAP; | ||
600 | } else { | ||
601 | new_alarm = 30; | ||
602 | } | ||
603 | |||
594 | memset(&ignore, 0, sizeof(ignore)); | 604 | memset(&ignore, 0, sizeof(ignore)); |
595 | ignore.sa_handler = caught_signal; | 605 | ignore.sa_handler = caught_signal; |
596 | sigemptyset(&ignore.sa_mask); | 606 | sigemptyset(&ignore.sa_mask); |
597 | /* particularily useful if tombstone is reporting for logd */ | 607 | /* particularily useful if tombstone is reporting for logd */ |
598 | sigaction(SIGALRM, &ignore, &old_sigaction); | 608 | sigaction(SIGALRM, &ignore, &old_sigaction); |
599 | old_alarm = alarm(30); | 609 | old_alarm = alarm(new_alarm); |
600 | } | 610 | } |
601 | 611 | ||
602 | /* NOTE: SOCK_SEQPACKET guarantees we read exactly one full entry */ | 612 | /* NOTE: SOCK_SEQPACKET guarantees we read exactly one full entry */ |
603 | ret = recv(ret, log_msg, LOGGER_ENTRY_MAX_LEN, 0); | 613 | ret = recv(ret, log_msg, LOGGER_ENTRY_MAX_LEN, 0); |
604 | e = errno; | 614 | e = errno; |
605 | 615 | ||
606 | if (logger_list->mode & ANDROID_LOG_NONBLOCK) { | 616 | if (new_alarm) { |
607 | if ((ret == 0) || (e == EINTR)) { | 617 | if ((ret == 0) || (e == EINTR)) { |
608 | e = EAGAIN; | 618 | e = EAGAIN; |
609 | ret = -1; | 619 | ret = -1; |
diff --git a/liblog/tests/Android.mk b/liblog/tests/Android.mk index 91044ab75..5571ce955 100644 --- a/liblog/tests/Android.mk +++ b/liblog/tests/Android.mk | |||
@@ -64,7 +64,8 @@ test_src_files := \ | |||
64 | log_radio_test.cpp \ | 64 | log_radio_test.cpp \ |
65 | log_read_test.cpp \ | 65 | log_read_test.cpp \ |
66 | log_system_test.cpp \ | 66 | log_system_test.cpp \ |
67 | log_time_test.cpp | 67 | log_time_test.cpp \ |
68 | log_wrap_test.cpp | ||
68 | 69 | ||
69 | # Build tests for the device (with .so). Run with: | 70 | # Build tests for the device (with .so). Run with: |
70 | # adb shell /data/nativetest/liblog-unit-tests/liblog-unit-tests | 71 | # adb shell /data/nativetest/liblog-unit-tests/liblog-unit-tests |
diff --git a/liblog/tests/log_wrap_test.cpp b/liblog/tests/log_wrap_test.cpp new file mode 100644 index 000000000..ebf0b1505 --- /dev/null +++ b/liblog/tests/log_wrap_test.cpp | |||
@@ -0,0 +1,121 @@ | |||
1 | /* | ||
2 | * Copyright (C) 2013-2017 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 <sys/types.h> | ||
18 | #include <time.h> | ||
19 | #include <unistd.h> | ||
20 | |||
21 | #include <string> | ||
22 | |||
23 | #include <android-base/chrono_utils.h> | ||
24 | #include <android-base/stringprintf.h> | ||
25 | #include <android/log.h> // minimal logging API | ||
26 | #include <gtest/gtest.h> | ||
27 | #include <log/log_properties.h> | ||
28 | #include <log/log_read.h> | ||
29 | #include <log/log_time.h> | ||
30 | #include <log/log_transport.h> | ||
31 | |||
32 | #ifdef __ANDROID__ | ||
33 | static void read_with_wrap() { | ||
34 | android_set_log_transport(LOGGER_LOGD); | ||
35 | |||
36 | // Read the last line in the log to get a starting timestamp. We're assuming | ||
37 | // the log is not empty. | ||
38 | const int mode = ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK; | ||
39 | struct logger_list* logger_list = | ||
40 | android_logger_list_open(LOG_ID_MAIN, mode, 1000, 0); | ||
41 | |||
42 | ASSERT_NE(logger_list, nullptr); | ||
43 | |||
44 | log_msg log_msg; | ||
45 | int ret = android_logger_list_read(logger_list, &log_msg); | ||
46 | android_logger_list_close(logger_list); | ||
47 | ASSERT_GT(ret, 0); | ||
48 | |||
49 | log_time start(log_msg.entry.sec, log_msg.entry.nsec); | ||
50 | ASSERT_NE(start, log_time()); | ||
51 | |||
52 | logger_list = | ||
53 | android_logger_list_alloc_time(mode | ANDROID_LOG_WRAP, start, 0); | ||
54 | ASSERT_NE(logger_list, nullptr); | ||
55 | |||
56 | struct logger* logger = android_logger_open(logger_list, LOG_ID_MAIN); | ||
57 | EXPECT_NE(logger, nullptr); | ||
58 | if (logger) { | ||
59 | android_logger_list_read(logger_list, &log_msg); | ||
60 | } | ||
61 | |||
62 | android_logger_list_close(logger_list); | ||
63 | } | ||
64 | |||
65 | static void caught_signal(int /* signum */) { | ||
66 | } | ||
67 | #endif | ||
68 | |||
69 | // b/64143705 confirm fixed | ||
70 | TEST(liblog, wrap_mode_blocks) { | ||
71 | #ifdef __ANDROID__ | ||
72 | |||
73 | android::base::Timer timer; | ||
74 | |||
75 | // The read call is expected to take up to 2 hours in the happy case. | ||
76 | // We only want to make sure it waits for longer than 30s, but we can't | ||
77 | // use an alarm as the implementation uses it. So we run the test in | ||
78 | // a separate process. | ||
79 | pid_t pid = fork(); | ||
80 | |||
81 | if (pid == 0) { | ||
82 | // child | ||
83 | read_with_wrap(); | ||
84 | _exit(0); | ||
85 | } | ||
86 | |||
87 | struct sigaction ignore, old_sigaction; | ||
88 | memset(&ignore, 0, sizeof(ignore)); | ||
89 | ignore.sa_handler = caught_signal; | ||
90 | sigemptyset(&ignore.sa_mask); | ||
91 | sigaction(SIGALRM, &ignore, &old_sigaction); | ||
92 | alarm(45); | ||
93 | |||
94 | bool killed = false; | ||
95 | for (;;) { | ||
96 | siginfo_t info = {}; | ||
97 | // This wait will succeed if the child exits, or fail with EINTR if the | ||
98 | // alarm goes off first - a loose approximation to a timed wait. | ||
99 | int ret = waitid(P_PID, pid, &info, WEXITED); | ||
100 | if (ret >= 0 || errno != EINTR) { | ||
101 | EXPECT_EQ(ret, 0); | ||
102 | if (!killed) { | ||
103 | EXPECT_EQ(info.si_status, 0); | ||
104 | } | ||
105 | break; | ||
106 | } | ||
107 | unsigned int alarm_left = alarm(0); | ||
108 | if (alarm_left > 0) { | ||
109 | alarm(alarm_left); | ||
110 | } else { | ||
111 | kill(pid, SIGTERM); | ||
112 | killed = true; | ||
113 | } | ||
114 | } | ||
115 | |||
116 | alarm(0); | ||
117 | EXPECT_GT(timer.duration(), std::chrono::seconds(40)); | ||
118 | #else | ||
119 | GTEST_LOG_(INFO) << "This test does nothing.\n"; | ||
120 | #endif | ||
121 | } | ||