Tom Cherry | a687242 | 2020-04-17 13:05:11 -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 "logging_splitters.h" |
| 18 | |
| 19 | #include <string> |
| 20 | #include <vector> |
| 21 | |
| 22 | #include <android-base/strings.h> |
| 23 | #include <gtest/gtest.h> |
| 24 | |
| 25 | namespace android { |
| 26 | namespace base { |
| 27 | |
| 28 | void TestNewlineSplitter(const std::string& input, |
| 29 | const std::vector<std::string>& expected_output) { |
| 30 | std::vector<std::string> output; |
| 31 | auto logger_function = [&](const char* msg, int length) { |
| 32 | if (length == -1) { |
| 33 | output.push_back(msg); |
| 34 | } else { |
| 35 | output.push_back(std::string(msg, length)); |
| 36 | } |
| 37 | }; |
| 38 | SplitByLines(input.c_str(), logger_function); |
| 39 | |
| 40 | EXPECT_EQ(expected_output, output); |
| 41 | } |
| 42 | |
| 43 | TEST(logging_splitters, NewlineSplitter_EmptyString) { |
| 44 | TestNewlineSplitter("", std::vector<std::string>{""}); |
| 45 | } |
| 46 | |
| 47 | TEST(logging_splitters, NewlineSplitter_BasicString) { |
| 48 | TestNewlineSplitter("normal string", std::vector<std::string>{"normal string"}); |
| 49 | } |
| 50 | |
| 51 | TEST(logging_splitters, NewlineSplitter_ormalBasicStringTrailingNewline) { |
| 52 | TestNewlineSplitter("normal string\n", std::vector<std::string>{"normal string", ""}); |
| 53 | } |
| 54 | |
| 55 | TEST(logging_splitters, NewlineSplitter_MultilineTrailing) { |
| 56 | TestNewlineSplitter("normal string\nsecond string\nthirdstring", |
| 57 | std::vector<std::string>{"normal string", "second string", "thirdstring"}); |
| 58 | } |
| 59 | |
| 60 | TEST(logging_splitters, NewlineSplitter_MultilineTrailingNewline) { |
| 61 | TestNewlineSplitter( |
| 62 | "normal string\nsecond string\nthirdstring\n", |
| 63 | std::vector<std::string>{"normal string", "second string", "thirdstring", ""}); |
| 64 | } |
| 65 | |
| 66 | TEST(logging_splitters, NewlineSplitter_MultilineEmbeddedNewlines) { |
| 67 | TestNewlineSplitter( |
| 68 | "normal string\n\n\nsecond string\n\nthirdstring\n", |
| 69 | std::vector<std::string>{"normal string", "", "", "second string", "", "thirdstring", ""}); |
| 70 | } |
| 71 | |
| 72 | void TestLogdChunkSplitter(const std::string& tag, const std::string& file, |
| 73 | const std::string& input, |
| 74 | const std::vector<std::string>& expected_output) { |
| 75 | std::vector<std::string> output; |
| 76 | auto logger_function = [&](LogId, LogSeverity, const char*, const char* msg) { |
| 77 | output.push_back(msg); |
| 78 | }; |
| 79 | |
| 80 | SplitByLogdChunks(MAIN, FATAL, tag.c_str(), file.empty() ? nullptr : file.c_str(), 1000, |
| 81 | input.c_str(), logger_function); |
| 82 | |
| 83 | auto return_lengths = [&] { |
| 84 | std::string sizes; |
| 85 | sizes += "expected_output sizes:"; |
| 86 | for (const auto& string : expected_output) { |
| 87 | sizes += " " + std::to_string(string.size()); |
| 88 | } |
| 89 | sizes += "\noutput sizes:"; |
| 90 | for (const auto& string : output) { |
| 91 | sizes += " " + std::to_string(string.size()); |
| 92 | } |
| 93 | return sizes; |
| 94 | }; |
| 95 | |
| 96 | EXPECT_EQ(expected_output, output) << return_lengths(); |
| 97 | } |
| 98 | |
| 99 | TEST(logging_splitters, LogdChunkSplitter_EmptyString) { |
| 100 | TestLogdChunkSplitter("tag", "", "", std::vector<std::string>{""}); |
| 101 | } |
| 102 | |
| 103 | TEST(logging_splitters, LogdChunkSplitter_BasicString) { |
| 104 | TestLogdChunkSplitter("tag", "", "normal string", std::vector<std::string>{"normal string"}); |
| 105 | } |
| 106 | |
| 107 | TEST(logging_splitters, LogdChunkSplitter_NormalBasicStringTrailingNewline) { |
| 108 | TestLogdChunkSplitter("tag", "", "normal string\n", std::vector<std::string>{"normal string\n"}); |
| 109 | } |
| 110 | |
| 111 | TEST(logging_splitters, LogdChunkSplitter_MultilineTrailing) { |
| 112 | TestLogdChunkSplitter("tag", "", "normal string\nsecond string\nthirdstring", |
| 113 | std::vector<std::string>{"normal string\nsecond string\nthirdstring"}); |
| 114 | } |
| 115 | |
| 116 | TEST(logging_splitters, LogdChunkSplitter_MultilineTrailingNewline) { |
| 117 | TestLogdChunkSplitter("tag", "", "normal string\nsecond string\nthirdstring\n", |
| 118 | std::vector<std::string>{"normal string\nsecond string\nthirdstring\n"}); |
| 119 | } |
| 120 | |
| 121 | TEST(logging_splitters, LogdChunkSplitter_MultilineEmbeddedNewlines) { |
| 122 | TestLogdChunkSplitter( |
| 123 | "tag", "", "normal string\n\n\nsecond string\n\nthirdstring\n", |
| 124 | std::vector<std::string>{"normal string\n\n\nsecond string\n\nthirdstring\n"}); |
| 125 | } |
| 126 | |
| 127 | // This test should return the same string, the logd logger itself will truncate down to size. |
| 128 | // This has historically been the behavior both in libbase and liblog. |
| 129 | TEST(logging_splitters, LogdChunkSplitter_HugeLineNoNewline) { |
| 130 | auto long_string = std::string(LOGGER_ENTRY_MAX_PAYLOAD, 'x'); |
| 131 | ASSERT_EQ(LOGGER_ENTRY_MAX_PAYLOAD, static_cast<int>(long_string.size())); |
| 132 | |
| 133 | TestLogdChunkSplitter("tag", "", long_string, std::vector{long_string}); |
| 134 | } |
| 135 | |
| 136 | std::string ReduceToMaxSize(const std::string& tag, const std::string& string) { |
| 137 | return string.substr(0, LOGGER_ENTRY_MAX_PAYLOAD - tag.size() - 35); |
| 138 | } |
| 139 | |
| 140 | TEST(logging_splitters, LogdChunkSplitter_MultipleHugeLineNoNewline) { |
| 141 | auto long_string_x = std::string(LOGGER_ENTRY_MAX_PAYLOAD, 'x'); |
| 142 | auto long_string_y = std::string(LOGGER_ENTRY_MAX_PAYLOAD, 'y'); |
| 143 | auto long_string_z = std::string(LOGGER_ENTRY_MAX_PAYLOAD, 'z'); |
| 144 | |
| 145 | auto long_strings = long_string_x + '\n' + long_string_y + '\n' + long_string_z; |
| 146 | |
| 147 | std::string tag = "tag"; |
| 148 | std::vector expected = {ReduceToMaxSize(tag, long_string_x), ReduceToMaxSize(tag, long_string_y), |
| 149 | long_string_z}; |
| 150 | |
| 151 | TestLogdChunkSplitter(tag, "", long_strings, expected); |
| 152 | } |
| 153 | |
| 154 | // With a ~4k buffer, we should print 2 long strings per logger call. |
| 155 | TEST(logging_splitters, LogdChunkSplitter_Multiple2kLines) { |
| 156 | std::vector expected = { |
| 157 | std::string(2000, 'a') + '\n' + std::string(2000, 'b'), |
| 158 | std::string(2000, 'c') + '\n' + std::string(2000, 'd'), |
| 159 | std::string(2000, 'e') + '\n' + std::string(2000, 'f'), |
| 160 | }; |
| 161 | |
| 162 | auto long_strings = Join(expected, '\n'); |
| 163 | |
| 164 | TestLogdChunkSplitter("tag", "", long_strings, expected); |
| 165 | } |
| 166 | |
| 167 | TEST(logging_splitters, LogdChunkSplitter_ExactSizedLines) { |
| 168 | const char* tag = "tag"; |
| 169 | ptrdiff_t max_size = LOGGER_ENTRY_MAX_PAYLOAD - strlen(tag) - 35; |
| 170 | auto long_string_a = std::string(max_size, 'a'); |
| 171 | auto long_string_b = std::string(max_size, 'b'); |
| 172 | auto long_string_c = std::string(max_size, 'c'); |
| 173 | |
| 174 | auto long_strings = long_string_a + '\n' + long_string_b + '\n' + long_string_c; |
| 175 | |
| 176 | TestLogdChunkSplitter(tag, "", long_strings, |
| 177 | std::vector{long_string_a, long_string_b, long_string_c}); |
| 178 | } |
| 179 | |
| 180 | TEST(logging_splitters, LogdChunkSplitter_UnderEqualOver) { |
| 181 | std::string tag = "tag"; |
| 182 | ptrdiff_t max_size = LOGGER_ENTRY_MAX_PAYLOAD - tag.size() - 35; |
| 183 | |
| 184 | auto first_string_size = 1000; |
| 185 | auto first_string = std::string(first_string_size, 'a'); |
| 186 | auto second_string_size = max_size - first_string_size - 1; |
| 187 | auto second_string = std::string(second_string_size, 'b'); |
| 188 | |
| 189 | auto exact_string = std::string(max_size, 'c'); |
| 190 | |
| 191 | auto large_string = std::string(max_size + 50, 'd'); |
| 192 | |
| 193 | auto final_string = std::string("final string!\n\nfinal \n \n final \n"); |
| 194 | |
| 195 | std::vector expected = {first_string + '\n' + second_string, exact_string, |
| 196 | ReduceToMaxSize(tag, large_string), final_string}; |
| 197 | |
| 198 | std::vector input_strings = {first_string + '\n' + second_string, exact_string, large_string, |
| 199 | final_string}; |
| 200 | auto long_strings = Join(input_strings, '\n'); |
| 201 | |
| 202 | TestLogdChunkSplitter(tag, "", long_strings, expected); |
| 203 | } |
| 204 | |
| 205 | TEST(logging_splitters, LogdChunkSplitter_WithFile) { |
| 206 | std::string tag = "tag"; |
| 207 | std::string file = "/path/to/myfile.cpp"; |
| 208 | int line = 1000; |
| 209 | auto file_header = StringPrintf("%s:%d] ", file.c_str(), line); |
| 210 | ptrdiff_t max_size = LOGGER_ENTRY_MAX_PAYLOAD - tag.size() - 35; |
| 211 | |
| 212 | auto first_string_size = 1000; |
| 213 | auto first_string = std::string(first_string_size, 'a'); |
| 214 | auto second_string_size = max_size - first_string_size - 1 - 2 * file_header.size(); |
| 215 | auto second_string = std::string(second_string_size, 'b'); |
| 216 | |
| 217 | auto exact_string = std::string(max_size - file_header.size(), 'c'); |
| 218 | |
| 219 | auto large_string = std::string(max_size + 50, 'd'); |
| 220 | |
| 221 | auto final_string = std::string("final string!"); |
| 222 | |
| 223 | std::vector expected = { |
| 224 | file_header + first_string + '\n' + file_header + second_string, file_header + exact_string, |
| 225 | file_header + ReduceToMaxSize(file_header + tag, large_string), file_header + final_string}; |
| 226 | |
| 227 | std::vector input_strings = {first_string + '\n' + second_string, exact_string, large_string, |
| 228 | final_string}; |
| 229 | auto long_strings = Join(input_strings, '\n'); |
| 230 | |
| 231 | TestLogdChunkSplitter(tag, file, long_strings, expected); |
| 232 | } |
| 233 | |
| 234 | // We set max_size based off of tag, so if it's too large, the buffer will be sized wrong. |
| 235 | // We could recover from this, but it's certainly an error for someone to attempt to use a tag this |
| 236 | // large, so we abort instead. |
| 237 | TEST(logging_splitters, LogdChunkSplitter_TooLongTag) { |
| 238 | auto long_tag = std::string(5000, 'x'); |
| 239 | auto logger_function = [](LogId, LogSeverity, const char*, const char*) {}; |
| 240 | ASSERT_DEATH( |
| 241 | SplitByLogdChunks(MAIN, ERROR, long_tag.c_str(), nullptr, 0, "message", logger_function), ""); |
| 242 | } |
| 243 | |
| 244 | // We do handle excessively large file names correctly however. |
| 245 | TEST(logging_splitters, LogdChunkSplitter_TooLongFile) { |
| 246 | auto long_file = std::string(5000, 'x'); |
| 247 | std::string tag = "tag"; |
| 248 | |
| 249 | std::vector expected = {ReduceToMaxSize(tag, long_file), ReduceToMaxSize(tag, long_file)}; |
| 250 | |
| 251 | TestLogdChunkSplitter(tag, long_file, "can't see me\nor me", expected); |
| 252 | } |
| 253 | |
| 254 | void TestStderrOutputGenerator(const char* tag, const char* file, int line, const char* message, |
| 255 | const std::string& expected) { |
| 256 | // All log messages will show "01-01 00:00:00" |
| 257 | struct tm now = { |
| 258 | .tm_sec = 0, |
| 259 | .tm_min = 0, |
| 260 | .tm_hour = 0, |
| 261 | .tm_mday = 1, |
| 262 | .tm_mon = 0, |
| 263 | .tm_year = 1970, |
| 264 | }; |
| 265 | |
| 266 | int pid = 1234; // All log messages will have 1234 for their PID. |
| 267 | uint64_t tid = 4321; // All log messages will have 4321 for their TID. |
| 268 | |
| 269 | auto result = StderrOutputGenerator(now, pid, tid, ERROR, tag, file, line, message); |
| 270 | EXPECT_EQ(expected, result); |
| 271 | } |
| 272 | |
| 273 | TEST(logging_splitters, StderrOutputGenerator_Basic) { |
| 274 | TestStderrOutputGenerator(nullptr, nullptr, 0, "simple message", |
| 275 | "nullptr E 01-01 00:00:00 1234 4321 simple message\n"); |
| 276 | TestStderrOutputGenerator("tag", nullptr, 0, "simple message", |
| 277 | "tag E 01-01 00:00:00 1234 4321 simple message\n"); |
| 278 | TestStderrOutputGenerator( |
| 279 | "tag", "/path/to/some/file", 0, "simple message", |
| 280 | "tag E 01-01 00:00:00 1234 4321 /path/to/some/file:0] simple message\n"); |
| 281 | } |
| 282 | |
| 283 | TEST(logging_splitters, StderrOutputGenerator_NewlineTagAndFile) { |
| 284 | TestStderrOutputGenerator("tag\n\n", nullptr, 0, "simple message", |
| 285 | "tag\n\n E 01-01 00:00:00 1234 4321 simple message\n"); |
| 286 | TestStderrOutputGenerator( |
| 287 | "tag", "/path/to/some/file\n\n", 0, "simple message", |
| 288 | "tag E 01-01 00:00:00 1234 4321 /path/to/some/file\n\n:0] simple message\n"); |
| 289 | } |
| 290 | |
| 291 | TEST(logging_splitters, StderrOutputGenerator_TrailingNewLine) { |
| 292 | TestStderrOutputGenerator( |
| 293 | "tag", nullptr, 0, "simple message\n", |
| 294 | "tag E 01-01 00:00:00 1234 4321 simple message\ntag E 01-01 00:00:00 1234 4321 \n"); |
| 295 | } |
| 296 | |
| 297 | TEST(logging_splitters, StderrOutputGenerator_MultiLine) { |
| 298 | const char* expected_result = |
| 299 | "tag E 01-01 00:00:00 1234 4321 simple message\n" |
| 300 | "tag E 01-01 00:00:00 1234 4321 \n" |
| 301 | "tag E 01-01 00:00:00 1234 4321 \n" |
| 302 | "tag E 01-01 00:00:00 1234 4321 another message \n" |
| 303 | "tag E 01-01 00:00:00 1234 4321 \n" |
| 304 | "tag E 01-01 00:00:00 1234 4321 final message \n" |
| 305 | "tag E 01-01 00:00:00 1234 4321 \n" |
| 306 | "tag E 01-01 00:00:00 1234 4321 \n" |
| 307 | "tag E 01-01 00:00:00 1234 4321 \n"; |
| 308 | |
| 309 | TestStderrOutputGenerator("tag", nullptr, 0, |
| 310 | "simple message\n\n\nanother message \n\n final message \n\n\n", |
| 311 | expected_result); |
| 312 | } |
| 313 | |
| 314 | TEST(logging_splitters, StderrOutputGenerator_MultiLineLong) { |
| 315 | auto long_string_a = std::string(4000, 'a'); |
| 316 | auto long_string_b = std::string(4000, 'b'); |
| 317 | |
| 318 | auto message = long_string_a + '\n' + long_string_b; |
| 319 | auto expected_result = "tag E 01-01 00:00:00 1234 4321 " + long_string_a + '\n' + |
| 320 | "tag E 01-01 00:00:00 1234 4321 " + long_string_b + '\n'; |
| 321 | TestStderrOutputGenerator("tag", nullptr, 0, message.c_str(), expected_result); |
| 322 | } |
| 323 | |
| 324 | } // namespace base |
| 325 | } // namespace android |