Gitiles
Code Review Sign In
gerrit.omnirom.org / android_system_core / 4ab0bc414d8a01df2013ea70f8e10f5daa12bec4 / . / logd / ChattyLogBufferTest.cpp
blob: 8754b885a1d0dc4d421fe7cde945b7d7cabdc00a [file] [log] [blame]
Tom Cherrye18346d2020-05-21 12:13:20 -0700[diff] [blame]1/*
2 * Copyright (C) 2020 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 "LogBufferTest.h"
18
19class ChattyLogBufferTest : public LogBufferTest {};
20
21TEST_P(ChattyLogBufferTest, deduplication_simple) {
22 auto make_message = [&](uint32_t sec, const char* tag, const char* msg,
23 bool regex = false) -> LogMessage {
24 logger_entry entry = {
25 .pid = 1, .tid = 1, .sec = sec, .nsec = 1, .lid = LOG_ID_MAIN, .uid = 0};
26 std::string message;
27 message.push_back(ANDROID_LOG_INFO);
28 message.append(tag);
29 message.push_back('\0');
30 message.append(msg);
31 message.push_back('\0');
32 return {entry, message, regex};
33 };
34
35 // clang-format off
36 std::vector<LogMessage> log_messages = {
37 make_message(0, "test_tag", "duplicate"),
38 make_message(1, "test_tag", "duplicate"),
39 make_message(2, "test_tag", "not_same"),
40 make_message(3, "test_tag", "duplicate"),
41 make_message(4, "test_tag", "duplicate"),
42 make_message(5, "test_tag", "not_same"),
43 make_message(6, "test_tag", "duplicate"),
44 make_message(7, "test_tag", "duplicate"),
45 make_message(8, "test_tag", "duplicate"),
46 make_message(9, "test_tag", "not_same"),
47 make_message(10, "test_tag", "duplicate"),
48 make_message(11, "test_tag", "duplicate"),
49 make_message(12, "test_tag", "duplicate"),
50 make_message(13, "test_tag", "duplicate"),
51 make_message(14, "test_tag", "duplicate"),
52 make_message(15, "test_tag", "duplicate"),
53 make_message(16, "test_tag", "not_same"),
54 make_message(100, "test_tag", "duplicate"),
55 make_message(200, "test_tag", "duplicate"),
56 make_message(300, "test_tag", "duplicate"),
57 };
58 // clang-format on
59 FixupMessages(&log_messages);
60 LogMessages(log_messages);
61
62 std::vector<LogMessage> read_log_messages;
63 std::unique_ptr<LogWriter> test_writer(new TestWriter(&read_log_messages, nullptr));
Tom Cherry855c7c82020-05-28 12:38:21 -0700[diff] [blame]64 std::unique_ptr<FlushToState> flush_to_state = log_buffer_->CreateFlushToState(1, kLogMaskAll);
65 EXPECT_TRUE(log_buffer_->FlushTo(test_writer.get(), *flush_to_state, nullptr));
Tom Cherrye18346d2020-05-21 12:13:20 -0700[diff] [blame]66
67 std::vector<LogMessage> expected_log_messages = {
68 make_message(0, "test_tag", "duplicate"),
69 make_message(1, "test_tag", "duplicate"),
70 make_message(2, "test_tag", "not_same"),
71 make_message(3, "test_tag", "duplicate"),
72 make_message(4, "test_tag", "duplicate"),
73 make_message(5, "test_tag", "not_same"),
74 // 3 duplicate logs together print the first, a 1 count chatty message, then the last.
75 make_message(6, "test_tag", "duplicate"),
Tom Cherry855c7c82020-05-28 12:38:21 -0700[diff] [blame]76 make_message(7, "chatty", "uid=0\\([^\\)]+\\) [^ ]+ identical 1 line", true),
Tom Cherrye18346d2020-05-21 12:13:20 -0700[diff] [blame]77 make_message(8, "test_tag", "duplicate"),
78 make_message(9, "test_tag", "not_same"),
79 // 6 duplicate logs together print the first, a 4 count chatty message, then the last.
80 make_message(10, "test_tag", "duplicate"),
Tom Cherry855c7c82020-05-28 12:38:21 -0700[diff] [blame]81 make_message(14, "chatty", "uid=0\\([^\\)]+\\) [^ ]+ identical 4 lines", true),
Tom Cherrye18346d2020-05-21 12:13:20 -0700[diff] [blame]82 make_message(15, "test_tag", "duplicate"),
83 make_message(16, "test_tag", "not_same"),
84 // duplicate logs > 1 minute apart are not deduplicated.
85 make_message(100, "test_tag", "duplicate"),
86 make_message(200, "test_tag", "duplicate"),
87 make_message(300, "test_tag", "duplicate"),
88 };
89 FixupMessages(&expected_log_messages);
90 CompareLogMessages(expected_log_messages, read_log_messages);
91};
92
93TEST_P(ChattyLogBufferTest, deduplication_overflow) {
94 auto make_message = [&](uint32_t sec, const char* tag, const char* msg,
95 bool regex = false) -> LogMessage {
96 logger_entry entry = {
97 .pid = 1, .tid = 1, .sec = sec, .nsec = 1, .lid = LOG_ID_MAIN, .uid = 0};
98 std::string message;
99 message.push_back(ANDROID_LOG_INFO);
100 message.append(tag);
101 message.push_back('\0');
102 message.append(msg);
103 message.push_back('\0');
104 return {entry, message, regex};
105 };
106
107 uint32_t sec = 0;
108 std::vector<LogMessage> log_messages = {
109 make_message(sec++, "test_tag", "normal"),
110 };
111 size_t expired_per_chatty_message = std::numeric_limits<uint16_t>::max();
112 for (size_t i = 0; i < expired_per_chatty_message + 3; ++i) {
113 log_messages.emplace_back(make_message(sec++, "test_tag", "duplicate"));
114 }
115 log_messages.emplace_back(make_message(sec++, "test_tag", "normal"));
116 FixupMessages(&log_messages);
117 LogMessages(log_messages);
118
119 std::vector<LogMessage> read_log_messages;
120 std::unique_ptr<LogWriter> test_writer(new TestWriter(&read_log_messages, nullptr));
Tom Cherry855c7c82020-05-28 12:38:21 -0700[diff] [blame]121 std::unique_ptr<FlushToState> flush_to_state = log_buffer_->CreateFlushToState(1, kLogMaskAll);
122 EXPECT_TRUE(log_buffer_->FlushTo(test_writer.get(), *flush_to_state, nullptr));
Tom Cherrye18346d2020-05-21 12:13:20 -0700[diff] [blame]123
124 std::vector<LogMessage> expected_log_messages = {
125 make_message(0, "test_tag", "normal"),
126 make_message(1, "test_tag", "duplicate"),
127 make_message(expired_per_chatty_message + 1, "chatty",
Tom Cherry855c7c82020-05-28 12:38:21 -0700[diff] [blame]128 "uid=0\\([^\\)]+\\) [^ ]+ identical 65535 lines", true),
Tom Cherrye18346d2020-05-21 12:13:20 -0700[diff] [blame]129 make_message(expired_per_chatty_message + 2, "chatty",
Tom Cherry855c7c82020-05-28 12:38:21 -0700[diff] [blame]130 "uid=0\\([^\\)]+\\) [^ ]+ identical 1 line", true),
Tom Cherrye18346d2020-05-21 12:13:20 -0700[diff] [blame]131 make_message(expired_per_chatty_message + 3, "test_tag", "duplicate"),
132 make_message(expired_per_chatty_message + 4, "test_tag", "normal"),
133 };
134 FixupMessages(&expected_log_messages);
135 CompareLogMessages(expected_log_messages, read_log_messages);
136}
137
138TEST_P(ChattyLogBufferTest, deduplication_liblog) {
139 auto make_message = [&](uint32_t sec, int32_t tag, int32_t count) -> LogMessage {
140 logger_entry entry = {
141 .pid = 1, .tid = 1, .sec = sec, .nsec = 1, .lid = LOG_ID_EVENTS, .uid = 0};
142 android_log_event_int_t liblog_event = {
143 .header.tag = tag, .payload.type = EVENT_TYPE_INT, .payload.data = count};
144 return {entry, std::string(reinterpret_cast<char*>(&liblog_event), sizeof(liblog_event)),
145 false};
146 };
147
148 // LIBLOG_LOG_TAG
149 std::vector<LogMessage> log_messages = {
150 make_message(0, 1234, 1),
151 make_message(1, LIBLOG_LOG_TAG, 3),
152 make_message(2, 1234, 2),
153 make_message(3, LIBLOG_LOG_TAG, 3),
154 make_message(4, LIBLOG_LOG_TAG, 4),
155 make_message(5, 1234, 223),
156 make_message(6, LIBLOG_LOG_TAG, 2),
157 make_message(7, LIBLOG_LOG_TAG, 3),
158 make_message(8, LIBLOG_LOG_TAG, 4),
159 make_message(9, 1234, 227),
160 make_message(10, LIBLOG_LOG_TAG, 1),
161 make_message(11, LIBLOG_LOG_TAG, 3),
162 make_message(12, LIBLOG_LOG_TAG, 2),
163 make_message(13, LIBLOG_LOG_TAG, 3),
164 make_message(14, LIBLOG_LOG_TAG, 5),
165 make_message(15, 1234, 227),
166 make_message(16, LIBLOG_LOG_TAG, 2),
167 make_message(17, LIBLOG_LOG_TAG, std::numeric_limits<int32_t>::max()),
168 make_message(18, LIBLOG_LOG_TAG, 3),
169 make_message(19, LIBLOG_LOG_TAG, 5),
170 make_message(20, 1234, 227),
171 };
172 FixupMessages(&log_messages);
173 LogMessages(log_messages);
174
175 std::vector<LogMessage> read_log_messages;
176 std::unique_ptr<LogWriter> test_writer(new TestWriter(&read_log_messages, nullptr));
Tom Cherry855c7c82020-05-28 12:38:21 -0700[diff] [blame]177 std::unique_ptr<FlushToState> flush_to_state = log_buffer_->CreateFlushToState(1, kLogMaskAll);
178 EXPECT_TRUE(log_buffer_->FlushTo(test_writer.get(), *flush_to_state, nullptr));
Tom Cherrye18346d2020-05-21 12:13:20 -0700[diff] [blame]179
180 std::vector<LogMessage> expected_log_messages = {
181 make_message(0, 1234, 1),
182 make_message(1, LIBLOG_LOG_TAG, 3),
183 make_message(2, 1234, 2),
184 make_message(3, LIBLOG_LOG_TAG, 3),
185 make_message(4, LIBLOG_LOG_TAG, 4),
186 make_message(5, 1234, 223),
187 // More than 2 liblog events (3 here), sum their value into the third message.
188 make_message(6, LIBLOG_LOG_TAG, 2),
189 make_message(8, LIBLOG_LOG_TAG, 7),
190 make_message(9, 1234, 227),
191 // More than 2 liblog events (5 here), sum their value into the third message.
192 make_message(10, LIBLOG_LOG_TAG, 1),
193 make_message(14, LIBLOG_LOG_TAG, 13),
194 make_message(15, 1234, 227),
195 // int32_t max is the max for a chatty message, beyond that we must use new messages.
196 make_message(16, LIBLOG_LOG_TAG, 2),
197 make_message(17, LIBLOG_LOG_TAG, std::numeric_limits<int32_t>::max()),
198 make_message(19, LIBLOG_LOG_TAG, 8),
199 make_message(20, 1234, 227),
200 };
201 FixupMessages(&expected_log_messages);
202 CompareLogMessages(expected_log_messages, read_log_messages);
203};
204
Tom Cherry855c7c82020-05-28 12:38:21 -0700[diff] [blame]205INSTANTIATE_TEST_CASE_P(ChattyLogBufferTests, ChattyLogBufferTest, testing::Values("chatty"));