OLD | NEW |
| (Empty) |
1 // Copyright 2017 The Chromium Authors. All rights reserved. | |
2 // Use of this source code is governed by a BSD-style license that can be | |
3 // found in the LICENSE file. | |
4 | |
5 #include "chrome/browser/chromeos/system_logs/single_log_source.h" | |
6 | |
7 #include <string> | |
8 | |
9 #include "base/bind.h" | |
10 #include "base/files/file_path.h" | |
11 #include "base/files/file_util.h" | |
12 #include "base/files/scoped_temp_dir.h" | |
13 #include "base/macros.h" | |
14 #include "base/memory/ptr_util.h" | |
15 #include "base/run_loop.h" | |
16 #include "base/strings/string_split.h" | |
17 #include "base/test/scoped_task_environment.h" | |
18 #include "base/time/time.h" | |
19 #include "content/public/test/test_browser_thread_bundle.h" | |
20 #include "testing/gtest/include/gtest/gtest.h" | |
21 | |
22 namespace system_logs { | |
23 | |
24 namespace { | |
25 | |
26 // Counts number of lines in a string. | |
27 size_t GetNumLinesInString(const std::string& string) { | |
28 size_t split_size = base::SplitString(string, "\n", base::KEEP_WHITESPACE, | |
29 base::SPLIT_WANT_ALL) | |
30 .size(); | |
31 // If there is an extra newline at the end, it will generate an extra empty | |
32 // string. Do not count this as an extra line. | |
33 if (!string.empty() && string.back() == '\n') | |
34 --split_size; | |
35 | |
36 return split_size; | |
37 } | |
38 | |
39 } // namespace | |
40 | |
41 class SingleLogSourceTest : public ::testing::Test { | |
42 public: | |
43 SingleLogSourceTest() | |
44 : scoped_task_environment_( | |
45 base::test::ScopedTaskEnvironment::MainThreadType::UI), | |
46 num_callback_calls_(0) { | |
47 InitializeTestLogDir(); | |
48 } | |
49 | |
50 ~SingleLogSourceTest() override { | |
51 SingleLogSource::SetChromeStartTimeForTesting(nullptr); | |
52 } | |
53 | |
54 protected: | |
55 // Sets up a dummy system log directory. | |
56 void InitializeTestLogDir() { | |
57 ASSERT_TRUE(log_dir_.CreateUniqueTempDir()); | |
58 | |
59 // Create file "messages". | |
60 const base::FilePath messages_path = log_dir_.GetPath().Append("messages"); | |
61 base::WriteFile(messages_path, "", 0); | |
62 EXPECT_TRUE(base::PathExists(messages_path)) << messages_path.value(); | |
63 | |
64 // Create file "ui/ui.LATEST". | |
65 const base::FilePath ui_dir_path = log_dir_.GetPath().Append("ui"); | |
66 ASSERT_TRUE(base::CreateDirectory(ui_dir_path)) << ui_dir_path.value(); | |
67 | |
68 const base::FilePath ui_latest_path = ui_dir_path.Append("ui.LATEST"); | |
69 base::WriteFile(ui_latest_path, "", 0); | |
70 ASSERT_TRUE(base::PathExists(ui_latest_path)) << ui_latest_path.value(); | |
71 } | |
72 | |
73 // Initializes the unit under test, |source_| to read a file from the dummy | |
74 // system log directory. | |
75 void InitializeSource(SingleLogSource::SupportedSource source_type) { | |
76 source_ = base::MakeUnique<SingleLogSource>(source_type); | |
77 source_->log_file_dir_path_ = log_dir_.GetPath(); | |
78 log_file_path_ = source_->log_file_dir_path_.Append(source_->source_name()); | |
79 ASSERT_TRUE(base::PathExists(log_file_path_)) << log_file_path_.value(); | |
80 } | |
81 | |
82 // Writes/appends (respectively) a string |input| to file indicated by | |
83 // |relative_path| under |log_dir_|. | |
84 bool WriteFile(const base::FilePath& relative_path, | |
85 const std::string& input) { | |
86 return base::WriteFile(log_dir_.GetPath().Append(relative_path), | |
87 input.data(), | |
88 input.size()) == static_cast<int>(input.size()); | |
89 } | |
90 bool AppendToFile(const base::FilePath& relative_path, | |
91 const std::string& input) { | |
92 return base::AppendToFile(log_dir_.GetPath().Append(relative_path), | |
93 input.data(), input.size()); | |
94 } | |
95 | |
96 // Moves source file to destination path, then creates an empty file at the | |
97 // path of the original source file. | |
98 // | |
99 // |src_relative_path|: Source file path relative to |log_dir_|. | |
100 // |dest_relative_path|: Destination path relative to |log_dir_|. | |
101 bool RotateFile(const base::FilePath& src_relative_path, | |
102 const base::FilePath& dest_relative_path) { | |
103 return base::Move(log_dir_.GetPath().Append(src_relative_path), | |
104 log_dir_.GetPath().Append(dest_relative_path)) && | |
105 WriteFile(src_relative_path, ""); | |
106 } | |
107 | |
108 // Calls source_.Fetch() to start a logs fetch operation. Passes in | |
109 // OnFileRead() as a callback. Runs until Fetch() has completed. | |
110 void FetchFromSource() { | |
111 source_->Fetch( | |
112 base::Bind(&SingleLogSourceTest::OnFileRead, base::Unretained(this))); | |
113 scoped_task_environment_.RunUntilIdle(); | |
114 } | |
115 | |
116 // Callback for fetching logs from |source_|. Overwrites the previous stored | |
117 // value of |latest_response_|. | |
118 void OnFileRead(SystemLogsResponse* response) { | |
119 ++num_callback_calls_; | |
120 if (response->empty()) | |
121 return; | |
122 | |
123 // Since |source_| represents a single log source, it should only return a | |
124 // single string result. | |
125 EXPECT_EQ(1U, response->size()); | |
126 latest_response_ = std::move(response->begin()->second); | |
127 } | |
128 | |
129 int num_callback_calls() const { return num_callback_calls_; } | |
130 | |
131 const std::string& latest_response() const { return latest_response_; } | |
132 | |
133 const base::FilePath& log_file_path() const { return log_file_path_; } | |
134 | |
135 private: | |
136 // For running scheduled tasks. | |
137 base::test::ScopedTaskEnvironment scoped_task_environment_; | |
138 | |
139 // Creates the necessary browser threads. Defined after | |
140 // |scoped_task_environment_| in order to use the MessageLoop it created. | |
141 content::TestBrowserThreadBundle browser_thread_bundle_; | |
142 | |
143 // Unit under test. | |
144 std::unique_ptr<SingleLogSource> source_; | |
145 | |
146 // Counts the number of times that |source_| has invoked the callback. | |
147 int num_callback_calls_; | |
148 | |
149 // Stores the string response returned from |source_| the last time it invoked | |
150 // OnFileRead. | |
151 std::string latest_response_; | |
152 | |
153 // Temporary dir for creating a dummy log file. | |
154 base::ScopedTempDir log_dir_; | |
155 | |
156 // Path to the dummy log file in |log_dir_|. | |
157 base::FilePath log_file_path_; | |
158 | |
159 DISALLOW_COPY_AND_ASSIGN(SingleLogSourceTest); | |
160 }; | |
161 | |
162 TEST_F(SingleLogSourceTest, EmptyFile) { | |
163 InitializeSource(SingleLogSource::SupportedSource::kMessages); | |
164 FetchFromSource(); | |
165 | |
166 EXPECT_EQ(1, num_callback_calls()); | |
167 EXPECT_EQ("", latest_response()); | |
168 } | |
169 | |
170 TEST_F(SingleLogSourceTest, SingleRead) { | |
171 InitializeSource(SingleLogSource::SupportedSource::kUiLatest); | |
172 | |
173 EXPECT_TRUE(AppendToFile(base::FilePath("ui/ui.LATEST"), "Hello world!\n")); | |
174 FetchFromSource(); | |
175 | |
176 EXPECT_EQ(1, num_callback_calls()); | |
177 EXPECT_EQ("Hello world!\n", latest_response()); | |
178 } | |
179 | |
180 TEST_F(SingleLogSourceTest, IncrementalReads) { | |
181 InitializeSource(SingleLogSource::SupportedSource::kMessages); | |
182 | |
183 EXPECT_TRUE(AppendToFile(base::FilePath("messages"), "Hello world!\n")); | |
184 FetchFromSource(); | |
185 | |
186 EXPECT_EQ(1, num_callback_calls()); | |
187 EXPECT_EQ("Hello world!\n", latest_response()); | |
188 | |
189 EXPECT_TRUE(AppendToFile(base::FilePath("messages"), | |
190 "The quick brown fox jumps over the lazy dog\n")); | |
191 FetchFromSource(); | |
192 | |
193 EXPECT_EQ(2, num_callback_calls()); | |
194 EXPECT_EQ("The quick brown fox jumps over the lazy dog\n", latest_response()); | |
195 | |
196 EXPECT_TRUE(AppendToFile(base::FilePath("messages"), | |
197 "Some like it hot.\nSome like it cold\n")); | |
198 FetchFromSource(); | |
199 | |
200 EXPECT_EQ(3, num_callback_calls()); | |
201 EXPECT_EQ("Some like it hot.\nSome like it cold\n", latest_response()); | |
202 | |
203 // As a sanity check, read entire contents of file separately to make sure it | |
204 // was written incrementally, and hence read incrementally. | |
205 std::string file_contents; | |
206 EXPECT_TRUE(base::ReadFileToString(log_file_path(), &file_contents)); | |
207 EXPECT_EQ( | |
208 "Hello world!\nThe quick brown fox jumps over the lazy dog\n" | |
209 "Some like it hot.\nSome like it cold\n", | |
210 file_contents); | |
211 } | |
212 | |
213 // The log files read by SingleLogSource are not expected to be overwritten. | |
214 // This test is just to ensure that the SingleLogSource class is robust enough | |
215 // not to break in the event of an overwrite. | |
216 TEST_F(SingleLogSourceTest, FileOverwrite) { | |
217 InitializeSource(SingleLogSource::SupportedSource::kUiLatest); | |
218 | |
219 EXPECT_TRUE(AppendToFile(base::FilePath("ui/ui.LATEST"), "0123456789\n")); | |
220 FetchFromSource(); | |
221 | |
222 EXPECT_EQ(1, num_callback_calls()); | |
223 EXPECT_EQ("0123456789\n", latest_response()); | |
224 | |
225 // Overwrite the file. | |
226 EXPECT_TRUE(WriteFile(base::FilePath("ui/ui.LATEST"), "abcdefg\n")); | |
227 FetchFromSource(); | |
228 | |
229 // Should re-read from the beginning. | |
230 EXPECT_EQ(2, num_callback_calls()); | |
231 EXPECT_EQ("abcdefg\n", latest_response()); | |
232 | |
233 // Append to the file to make sure incremental read still works. | |
234 EXPECT_TRUE(AppendToFile(base::FilePath("ui/ui.LATEST"), "hijk\n")); | |
235 FetchFromSource(); | |
236 | |
237 EXPECT_EQ(3, num_callback_calls()); | |
238 EXPECT_EQ("hijk\n", latest_response()); | |
239 | |
240 // Overwrite again, this time with a longer length than the existing file. | |
241 // Previous contents: | |
242 // abcdefg~hijk~ <-- "~" is a single-char representation of newline. | |
243 // New contents: | |
244 // lmnopqrstuvwxyz~ <-- excess text beyond end of prev contents: "yz~" | |
245 EXPECT_TRUE(WriteFile(base::FilePath("ui/ui.LATEST"), "lmnopqrstuvwxyz\n")); | |
246 FetchFromSource(); | |
247 | |
248 EXPECT_EQ(4, num_callback_calls()); | |
249 EXPECT_EQ("yz\n", latest_response()); | |
250 } | |
251 | |
252 TEST_F(SingleLogSourceTest, IncompleteLines) { | |
253 InitializeSource(SingleLogSource::SupportedSource::kMessages); | |
254 | |
255 EXPECT_TRUE(AppendToFile(base::FilePath("messages"), "0123456789")); | |
256 FetchFromSource(); | |
257 | |
258 EXPECT_EQ(1, num_callback_calls()); | |
259 EXPECT_EQ("", latest_response()); | |
260 | |
261 EXPECT_TRUE(AppendToFile(base::FilePath("messages"), "abcdefg")); | |
262 FetchFromSource(); | |
263 | |
264 EXPECT_EQ(2, num_callback_calls()); | |
265 EXPECT_EQ("", latest_response()); | |
266 | |
267 EXPECT_TRUE(AppendToFile(base::FilePath("messages"), "hijk\n")); | |
268 FetchFromSource(); | |
269 | |
270 EXPECT_EQ(3, num_callback_calls()); | |
271 // All the previously written text should be read this time. | |
272 EXPECT_EQ("0123456789abcdefghijk\n", latest_response()); | |
273 | |
274 // Check ability to read whole lines while leaving the remainder for later. | |
275 EXPECT_TRUE(AppendToFile(base::FilePath("messages"), "Hello world\n")); | |
276 EXPECT_TRUE(AppendToFile(base::FilePath("messages"), "Goodbye world")); | |
277 FetchFromSource(); | |
278 | |
279 EXPECT_EQ(4, num_callback_calls()); | |
280 EXPECT_EQ("Hello world\n", latest_response()); | |
281 | |
282 EXPECT_TRUE(AppendToFile(base::FilePath("messages"), "\n")); | |
283 FetchFromSource(); | |
284 | |
285 EXPECT_EQ(5, num_callback_calls()); | |
286 EXPECT_EQ("Goodbye world\n", latest_response()); | |
287 } | |
288 | |
289 TEST_F(SingleLogSourceTest, Anonymize) { | |
290 InitializeSource(SingleLogSource::SupportedSource::kUiLatest); | |
291 | |
292 EXPECT_TRUE(AppendToFile(base::FilePath("ui/ui.LATEST"), | |
293 "My MAC address is: 11:22:33:44:55:66\n")); | |
294 FetchFromSource(); | |
295 | |
296 EXPECT_EQ(1, num_callback_calls()); | |
297 EXPECT_EQ("My MAC address is: 11:22:33:00:00:01\n", latest_response()); | |
298 | |
299 // Suppose the write operation is not atomic, and the MAC address is written | |
300 // across two separate writes. | |
301 EXPECT_TRUE(AppendToFile(base::FilePath("ui/ui.LATEST"), | |
302 "Your MAC address is: AB:88:C")); | |
303 FetchFromSource(); | |
304 | |
305 EXPECT_EQ(2, num_callback_calls()); | |
306 EXPECT_EQ("", latest_response()); | |
307 | |
308 EXPECT_TRUE(AppendToFile(base::FilePath("ui/ui.LATEST"), "D:99:EF:77\n")); | |
309 FetchFromSource(); | |
310 | |
311 EXPECT_EQ(3, num_callback_calls()); | |
312 EXPECT_EQ("Your MAC address is: ab:88:cd:00:00:02\n", latest_response()); | |
313 } | |
314 | |
315 TEST_F(SingleLogSourceTest, HandleLogFileRotation) { | |
316 InitializeSource(SingleLogSource::SupportedSource::kMessages); | |
317 | |
318 EXPECT_TRUE(AppendToFile(base::FilePath("messages"), "1st log file\n")); | |
319 FetchFromSource(); | |
320 EXPECT_EQ(1, num_callback_calls()); | |
321 EXPECT_EQ("1st log file\n", latest_response()); | |
322 | |
323 // Rotate file. Make sure the rest of the old file and the contents of the new | |
324 // file are both read. | |
325 EXPECT_TRUE(AppendToFile(base::FilePath("messages"), "More 1st log file\n")); | |
326 EXPECT_TRUE( | |
327 RotateFile(base::FilePath("messages"), base::FilePath("messages.1"))); | |
328 EXPECT_TRUE(AppendToFile(base::FilePath("messages"), "2nd log file\n")); | |
329 | |
330 FetchFromSource(); | |
331 EXPECT_EQ(2, num_callback_calls()); | |
332 EXPECT_EQ("More 1st log file\n2nd log file\n", latest_response()); | |
333 | |
334 // Rotate again, but this time omit the newline before rotating. | |
335 EXPECT_TRUE(AppendToFile(base::FilePath("messages"), "No newline here...")); | |
336 EXPECT_TRUE( | |
337 RotateFile(base::FilePath("messages"), base::FilePath("messages.1"))); | |
338 EXPECT_TRUE(AppendToFile(base::FilePath("messages"), "3rd log file\n")); | |
339 EXPECT_TRUE(AppendToFile(base::FilePath("messages"), "Also no newline here")); | |
340 | |
341 FetchFromSource(); | |
342 EXPECT_EQ(3, num_callback_calls()); | |
343 // Make sure the rotation didn't break anything: the last part of the new file | |
344 // does not end with a newline; thus the new file should not be read. | |
345 EXPECT_EQ("No newline here...3rd log file\n", latest_response()); | |
346 | |
347 // Finish the previous read attempt by adding the missing newline. | |
348 EXPECT_TRUE(AppendToFile(base::FilePath("messages"), "...yet\n")); | |
349 FetchFromSource(); | |
350 EXPECT_EQ(4, num_callback_calls()); | |
351 EXPECT_EQ("Also no newline here...yet\n", latest_response()); | |
352 } | |
353 | |
354 TEST_F(SingleLogSourceTest, ReadRecentLinesFromMessages) { | |
355 // Write some lines to messages. Use various timestamp styles. Some lines have | |
356 // timestamps, Some do not. All timestamps are in chronological order. | |
357 const base::FilePath messages_path = base::FilePath("messages"); | |
358 // All timestamps below include time zone info. Some are EDT (-0400) and | |
359 // others are PDT (-0700). These make sure that SingleLogSource is able to | |
360 // read various standard timestamp formats. | |
361 EXPECT_TRUE( | |
362 AppendToFile(messages_path, "13 Jun 2017 15:00:00 -0400 : Alpha\n")); | |
363 EXPECT_TRUE( | |
364 AppendToFile(messages_path, "13-Jun-2017 15:30 -04:00 : Bravo\n")); | |
365 EXPECT_TRUE(AppendToFile(messages_path, "Missing timestamp #1\n")); | |
366 EXPECT_TRUE( | |
367 AppendToFile(messages_path, "2017-06-13 3:30pm -04:00 : Charlie\n")); | |
368 EXPECT_TRUE(AppendToFile(messages_path, "\n")); | |
369 EXPECT_TRUE( | |
370 AppendToFile(messages_path, "13 Jun 2017 13:30:00 -0700 : Delta\n")); | |
371 EXPECT_TRUE( | |
372 AppendToFile(messages_path, "Tue Jun 13 17:00 EDT 2017 : Echo\n")); | |
373 EXPECT_TRUE(AppendToFile(messages_path, "Missing timestamp #2\n")); | |
374 EXPECT_TRUE( | |
375 AppendToFile(messages_path, "2017-06-13T17:30:00.125-04:00 : Foxtrot\n")); | |
376 EXPECT_TRUE( | |
377 AppendToFile(messages_path, "2017-06-13 3:00:00 PM PDT : Golf\n")); | |
378 | |
379 // The timestamp of the first message in file "messages". | |
380 base::Time first_line_time; | |
381 EXPECT_TRUE( | |
382 base::Time::FromString("13 Jun 2017 15:00:00 EDT", &first_line_time)); | |
383 | |
384 // Confirm that it was correctly parsed. | |
385 base::Time::Exploded exploded; | |
386 first_line_time.UTCExplode(&exploded); | |
387 EXPECT_EQ(2017, exploded.year); | |
388 EXPECT_EQ(6, exploded.month); | |
389 EXPECT_EQ(2 /* Tue */, exploded.day_of_week); | |
390 EXPECT_EQ(13, exploded.day_of_month); | |
391 EXPECT_EQ(15 + 4 /* Convert from EDT to UTC */, exploded.hour); | |
392 EXPECT_EQ(0, exploded.minute); | |
393 EXPECT_EQ(0, exploded.second); | |
394 EXPECT_EQ(0, exploded.millisecond); | |
395 | |
396 // Provide a fake Chrome start time for testing: 15:00 EDT | |
397 base::Time chrome_start_time = first_line_time; | |
398 SingleLogSource::SetChromeStartTimeForTesting(&chrome_start_time); | |
399 | |
400 // Read from messages. The first line of messages should not have been read. | |
401 InitializeSource(SingleLogSource::SupportedSource::kMessages); | |
402 FetchFromSource(); | |
403 EXPECT_EQ(1, num_callback_calls()); | |
404 EXPECT_EQ(10U, GetNumLinesInString(latest_response())) << latest_response(); | |
405 | |
406 // Update Chrome start time to: 15:15 EDT | |
407 chrome_start_time += base::TimeDelta::FromMinutes(15); | |
408 SingleLogSource::SetChromeStartTimeForTesting(&chrome_start_time); | |
409 | |
410 InitializeSource(SingleLogSource::SupportedSource::kMessages); | |
411 FetchFromSource(); | |
412 EXPECT_EQ(2, num_callback_calls()); | |
413 EXPECT_EQ(9U, GetNumLinesInString(latest_response())) << latest_response(); | |
414 | |
415 // Update Chrome start time: 15:45 EDT | |
416 chrome_start_time += base::TimeDelta::FromMinutes(30); | |
417 SingleLogSource::SetChromeStartTimeForTesting(&chrome_start_time); | |
418 | |
419 InitializeSource(SingleLogSource::SupportedSource::kMessages); | |
420 FetchFromSource(); | |
421 EXPECT_EQ(3, num_callback_calls()); | |
422 EXPECT_EQ(5U, GetNumLinesInString(latest_response())) << latest_response(); | |
423 | |
424 // Update Chrome start time: 17:10 EDT | |
425 chrome_start_time = first_line_time + base::TimeDelta::FromHours(2) + | |
426 base::TimeDelta::FromMinutes(10); | |
427 SingleLogSource::SetChromeStartTimeForTesting(&chrome_start_time); | |
428 | |
429 InitializeSource(SingleLogSource::SupportedSource::kMessages); | |
430 FetchFromSource(); | |
431 EXPECT_EQ(4, num_callback_calls()); | |
432 EXPECT_EQ(4U, GetNumLinesInString(latest_response())) << latest_response(); | |
433 | |
434 // Update Chrome start time: 17:40:00.125 EDT | |
435 chrome_start_time += | |
436 base::TimeDelta::FromMinutes(30) + base::TimeDelta::FromMilliseconds(125); | |
437 SingleLogSource::SetChromeStartTimeForTesting(&chrome_start_time); | |
438 | |
439 InitializeSource(SingleLogSource::SupportedSource::kMessages); | |
440 FetchFromSource(); | |
441 EXPECT_EQ(5, num_callback_calls()); | |
442 EXPECT_EQ(2U, GetNumLinesInString(latest_response())) << latest_response(); | |
443 | |
444 // Update Chrome start time: 17:40:00.126 EDT | |
445 chrome_start_time += base::TimeDelta::FromMilliseconds(1); | |
446 SingleLogSource::SetChromeStartTimeForTesting(&chrome_start_time); | |
447 | |
448 InitializeSource(SingleLogSource::SupportedSource::kMessages); | |
449 FetchFromSource(); | |
450 EXPECT_EQ(6, num_callback_calls()); | |
451 EXPECT_EQ(1U, GetNumLinesInString(latest_response())) << latest_response(); | |
452 | |
453 // Update Chrome start time: 18:10 EDT | |
454 chrome_start_time = first_line_time + base::TimeDelta::FromHours(3) + | |
455 base::TimeDelta::FromMinutes(10); | |
456 SingleLogSource::SetChromeStartTimeForTesting(&chrome_start_time); | |
457 | |
458 InitializeSource(SingleLogSource::SupportedSource::kMessages); | |
459 FetchFromSource(); | |
460 EXPECT_EQ(7, num_callback_calls()); | |
461 EXPECT_EQ(1U, GetNumLinesInString(latest_response())) << latest_response(); | |
462 | |
463 // Update Chrome start time: 18:15 EDT | |
464 chrome_start_time += base::TimeDelta::FromMinutes(5); | |
465 SingleLogSource::SetChromeStartTimeForTesting(&chrome_start_time); | |
466 | |
467 InitializeSource(SingleLogSource::SupportedSource::kMessages); | |
468 FetchFromSource(); | |
469 EXPECT_EQ(8, num_callback_calls()); | |
470 EXPECT_EQ(0U, GetNumLinesInString(latest_response())) << latest_response(); | |
471 } | |
472 | |
473 } // namespace system_logs | |
OLD | NEW |