[go: nahoru, domu]
Google Git
Sign in
chromium / chromium / src / 85285b04a02b765d7e4741f1e1588ae520c226d6 / . / base / logging_unittest.cc
blob: 841e5f730deb4e76bd2dcefe69a34f7a403272fc [file] [log] [blame]
jeffbailey@chromium.org998e6d92011-04-02 21:13:21[diff] [blame]1// Copyright (c) 2011 The Chromium Authors. All rights reserved.
akalin@chromium.org521b0c42010-10-01 23:02:36[diff] [blame]2// Use of this source code is governed by a BSD-style license that can be
3// found in the LICENSE file.
4
Collin Baker89e9e072019-06-10 22:39:05[diff] [blame]5#include <sstream>
Jan Wilken Dörriead587c32021-03-11 14:09:27[diff] [blame]6#include <string>
Collin Baker89e9e072019-06-10 22:39:05[diff] [blame]7
alex-accc1bde62017-04-19 08:33:55[diff] [blame]8#include "base/bind.h"
9#include "base/callback.h"
Eric Willigersa6b71342020-10-13 08:23:58[diff] [blame]10#include "base/command_line.h"
alex-accc1bde62017-04-19 08:33:55[diff] [blame]11#include "base/compiler_specific.h"
Wez6c8acb82019-07-18 00:32:59[diff] [blame]12#include "base/files/file_util.h"
13#include "base/files/scoped_temp_dir.h"
14#include "base/logging.h"
Yuta Hijikata9b7279a2020-08-26 16:10:54[diff] [blame]15#include "base/no_destructor.h"
Sharon Yanga4b908de2019-05-07 22:19:03[diff] [blame]16#include "base/run_loop.h"
Peter Collingbourne5a35305d2019-02-06 02:51:43[diff] [blame]17#include "base/sanitizer_buildflags.h"
Jan Wilken Dörrie3c1c8fdf2021-01-22 08:17:46[diff] [blame]18#include "base/strings/string16.h"
alex-accc1bde62017-04-19 08:33:55[diff] [blame]19#include "base/strings/string_piece.h"
Jan Wilken Dörrie3c1c8fdf2021-01-22 08:17:46[diff] [blame]20#include "base/strings/utf_string_conversions.h"
Guido Urdanetaef4e91942020-11-09 15:06:24[diff] [blame]21#include "base/test/bind.h"
Yuta Hijikata9b7279a2020-08-26 16:10:54[diff] [blame]22#include "base/test/scoped_logging_settings.h"
Gabriel Charettec7108742019-08-23 03:31:40[diff] [blame]23#include "base/test/task_environment.h"
Scott Grahamd90951b2017-11-28 23:53:26[diff] [blame]24#include "build/build_config.h"
Yuta Hijikata000df18f2020-11-18 06:55:58[diff] [blame]25#include "build/chromeos_buildflags.h"
akalin@chromium.org521b0c42010-10-01 23:02:36[diff] [blame]26
27#include "testing/gmock/include/gmock/gmock.h"
28#include "testing/gtest/include/gtest/gtest.h"
29
primianof5316722017-02-21 13:09:26[diff] [blame]30#if defined(OS_POSIX)
31#include <signal.h>
32#include <unistd.h>
33#include "base/posix/eintr_wrapper.h"
34#endif // OS_POSIX
35
Sean McAllister39b8d342020-08-25 09:08:32[diff] [blame]36#if defined(OS_LINUX) || defined(OS_CHROMEOS) || defined(OS_ANDROID)
primianof5316722017-02-21 13:09:26[diff] [blame]37#include <ucontext.h>
38#endif
39
scottmga17c8db2017-02-15 21:35:49[diff] [blame]40#if defined(OS_WIN)
Gabriel Charetteb69fcd42019-08-23 02:13:29[diff] [blame]41#include <windows.h>
Gabriel Charettec7108742019-08-23 03:31:40[diff] [blame]42#include <excpt.h>
scottmga17c8db2017-02-15 21:35:49[diff] [blame]43#endif // OS_WIN
44
Scott Grahamd90951b2017-11-28 23:53:26[diff] [blame]45#if defined(OS_FUCHSIA)
Sharon Yanga4b908de2019-05-07 22:19:03[diff] [blame]46#include <fuchsia/logger/cpp/fidl.h>
Sharon Yanga4b908de2019-05-07 22:19:03[diff] [blame]47#include <lib/fidl/cpp/binding.h>
Sharon Yanga7939252019-09-19 17:22:23[diff] [blame]48#include <lib/sys/cpp/component_context.h>
David Purselldc329442019-07-17 16:30:38[diff] [blame]49#include <lib/zx/channel.h>
Wez157707d62018-07-10 22:48:47[diff] [blame]50#include <lib/zx/event.h>
David Purselldc329442019-07-17 16:30:38[diff] [blame]51#include <lib/zx/exception.h>
Wez157707d62018-07-10 22:48:47[diff] [blame]52#include <lib/zx/process.h>
53#include <lib/zx/thread.h>
54#include <lib/zx/time.h>
Fabrice de Gans-Riberia2a53862018-06-08 18:04:26[diff] [blame]55#include <zircon/process.h>
Fabrice de Gans-Riberia2a53862018-06-08 18:04:26[diff] [blame]56#include <zircon/syscalls/debug.h>
David Purselldc329442019-07-17 16:30:38[diff] [blame]57#include <zircon/syscalls/exception.h>
Wez157707d62018-07-10 22:48:47[diff] [blame]58#include <zircon/types.h>
David Purselldc329442019-07-17 16:30:38[diff] [blame]59
Scott Grahamd90951b2017-11-28 23:53:26[diff] [blame]60#include "base/fuchsia/fuchsia_logging.h"
Sharon Yangb2ff20e2020-06-19 12:54:01[diff] [blame]61#include "base/fuchsia/process_context.h"
David Dorwin753eff82020-10-06 22:33:01[diff] [blame]62#include "base/fuchsia/test_log_listener_safe.h"
Sharon Yanga4b908de2019-05-07 22:19:03[diff] [blame]63#endif // OS_FUCHSIA
Scott Grahamd90951b2017-11-28 23:53:26[diff] [blame]64
akalin@chromium.org521b0c42010-10-01 23:02:36[diff] [blame]65namespace logging {
66
67namespace {
68
69using ::testing::Return;
alex-accc1bde62017-04-19 08:33:55[diff] [blame]70using ::testing::_;
akalin@chromium.org521b0c42010-10-01 23:02:36[diff] [blame]71
Yuta Hijikata9b7279a2020-08-26 16:10:54[diff] [blame]72class LoggingTest : public testing::Test {
73 protected:
74 const ScopedLoggingSettings& scoped_logging_settings() {
75 return scoped_logging_settings_;
akalin@chromium.org5e987802010-11-01 19:49:22[diff] [blame]76 }
akalin@chromium.org521b0c42010-10-01 23:02:36[diff] [blame]77
78 private:
Gabriel Charette16229682019-09-05 20:14:39[diff] [blame]79 base::test::SingleThreadTaskEnvironment task_environment_{
80 base::test::SingleThreadTaskEnvironment::MainThreadType::IO};
Yuta Hijikata9b7279a2020-08-26 16:10:54[diff] [blame]81 ScopedLoggingSettings scoped_logging_settings_;
akalin@chromium.org521b0c42010-10-01 23:02:36[diff] [blame]82};
83
84class MockLogSource {
85 public:
86 MOCK_METHOD0(Log, const char*());
87};
88
alex-accc1bde62017-04-19 08:33:55[diff] [blame]89class MockLogAssertHandler {
90 public:
91 MOCK_METHOD4(
92 HandleLogAssert,
93 void(const char*, int, const base::StringPiece, const base::StringPiece));
94};
95
akalin@chromium.org521b0c42010-10-01 23:02:36[diff] [blame]96TEST_F(LoggingTest, BasicLogging) {
97 MockLogSource mock_log_source;
wez8ccfd32a2017-03-13 22:54:27[diff] [blame]98 EXPECT_CALL(mock_log_source, Log())
99 .Times(DCHECK_IS_ON() ? 16 : 8)
100 .WillRepeatedly(Return("log message"));
akalin@chromium.org521b0c42010-10-01 23:02:36[diff] [blame]101
Lei Zhang93dd4252020-10-23 18:45:53[diff] [blame]102 SetMinLogLevel(LOGGING_INFO);
akalin@chromium.org521b0c42010-10-01 23:02:36[diff] [blame]103
104 EXPECT_TRUE(LOG_IS_ON(INFO));
Wezad51a5a2019-11-26 20:39:02[diff] [blame]105 EXPECT_EQ(DCHECK_IS_ON(), DLOG_IS_ON(INFO));
akalin@chromium.org521b0c42010-10-01 23:02:36[diff] [blame]106 EXPECT_TRUE(VLOG_IS_ON(0));
107
108 LOG(INFO) << mock_log_source.Log();
109 LOG_IF(INFO, true) << mock_log_source.Log();
110 PLOG(INFO) << mock_log_source.Log();
111 PLOG_IF(INFO, true) << mock_log_source.Log();
112 VLOG(0) << mock_log_source.Log();
113 VLOG_IF(0, true) << mock_log_source.Log();
vitalybuka@chromium.orgc914d8a2014-04-23 01:11:01[diff] [blame]114 VPLOG(0) << mock_log_source.Log();
115 VPLOG_IF(0, true) << mock_log_source.Log();
akalin@chromium.org521b0c42010-10-01 23:02:36[diff] [blame]116
117 DLOG(INFO) << mock_log_source.Log();
118 DLOG_IF(INFO, true) << mock_log_source.Log();
119 DPLOG(INFO) << mock_log_source.Log();
120 DPLOG_IF(INFO, true) << mock_log_source.Log();
121 DVLOG(0) << mock_log_source.Log();
122 DVLOG_IF(0, true) << mock_log_source.Log();
vitalybuka@chromium.orgc914d8a2014-04-23 01:11:01[diff] [blame]123 DVPLOG(0) << mock_log_source.Log();
124 DVPLOG_IF(0, true) << mock_log_source.Log();
akalin@chromium.org521b0c42010-10-01 23:02:36[diff] [blame]125}
126
akalin@chromium.orgdeba0ff2010-11-03 05:30:14[diff] [blame]127TEST_F(LoggingTest, LogIsOn) {
Lei Zhang93dd4252020-10-23 18:45:53[diff] [blame]128 SetMinLogLevel(LOGGING_INFO);
akalin@chromium.orgdeba0ff2010-11-03 05:30:14[diff] [blame]129 EXPECT_TRUE(LOG_IS_ON(INFO));
130 EXPECT_TRUE(LOG_IS_ON(WARNING));
131 EXPECT_TRUE(LOG_IS_ON(ERROR));
akalin@chromium.orgdeba0ff2010-11-03 05:30:14[diff] [blame]132 EXPECT_TRUE(LOG_IS_ON(FATAL));
133 EXPECT_TRUE(LOG_IS_ON(DFATAL));
134
Lei Zhang93dd4252020-10-23 18:45:53[diff] [blame]135 SetMinLogLevel(LOGGING_WARNING);
akalin@chromium.orgdeba0ff2010-11-03 05:30:14[diff] [blame]136 EXPECT_FALSE(LOG_IS_ON(INFO));
137 EXPECT_TRUE(LOG_IS_ON(WARNING));
138 EXPECT_TRUE(LOG_IS_ON(ERROR));
akalin@chromium.orgdeba0ff2010-11-03 05:30:14[diff] [blame]139 EXPECT_TRUE(LOG_IS_ON(FATAL));
140 EXPECT_TRUE(LOG_IS_ON(DFATAL));
141
Lei Zhang93dd4252020-10-23 18:45:53[diff] [blame]142 SetMinLogLevel(LOGGING_ERROR);
akalin@chromium.orgdeba0ff2010-11-03 05:30:14[diff] [blame]143 EXPECT_FALSE(LOG_IS_ON(INFO));
144 EXPECT_FALSE(LOG_IS_ON(WARNING));
145 EXPECT_TRUE(LOG_IS_ON(ERROR));
akalin@chromium.orgdeba0ff2010-11-03 05:30:14[diff] [blame]146 EXPECT_TRUE(LOG_IS_ON(FATAL));
147 EXPECT_TRUE(LOG_IS_ON(DFATAL));
148
Lei Zhang93dd4252020-10-23 18:45:53[diff] [blame]149 SetMinLogLevel(LOGGING_FATAL + 1);
akalin@chromium.orgdeba0ff2010-11-03 05:30:14[diff] [blame]150 EXPECT_FALSE(LOG_IS_ON(INFO));
151 EXPECT_FALSE(LOG_IS_ON(WARNING));
152 EXPECT_FALSE(LOG_IS_ON(ERROR));
danakjf8e9c302021-01-27 21:37:23[diff] [blame]153 // LOG_IS_ON(FATAL) should always be true.
akalin@chromium.orgdeba0ff2010-11-03 05:30:14[diff] [blame]154 EXPECT_TRUE(LOG_IS_ON(FATAL));
danakjf8e9c302021-01-27 21:37:23[diff] [blame]155 // If DCHECK_IS_ON() then DFATAL is FATAL.
156 EXPECT_EQ(DCHECK_IS_ON(), LOG_IS_ON(DFATAL));
akalin@chromium.orgdeba0ff2010-11-03 05:30:14[diff] [blame]157}
158
skobesc78c0ad72015-12-07 20:21:23[diff] [blame]159TEST_F(LoggingTest, LoggingIsLazyBySeverity) {
akalin@chromium.org521b0c42010-10-01 23:02:36[diff] [blame]160 MockLogSource mock_log_source;
161 EXPECT_CALL(mock_log_source, Log()).Times(0);
162
Lei Zhang93dd4252020-10-23 18:45:53[diff] [blame]163 SetMinLogLevel(LOGGING_WARNING);
akalin@chromium.org521b0c42010-10-01 23:02:36[diff] [blame]164
165 EXPECT_FALSE(LOG_IS_ON(INFO));
166 EXPECT_FALSE(DLOG_IS_ON(INFO));
167 EXPECT_FALSE(VLOG_IS_ON(1));
168
169 LOG(INFO) << mock_log_source.Log();
170 LOG_IF(INFO, false) << mock_log_source.Log();
171 PLOG(INFO) << mock_log_source.Log();
172 PLOG_IF(INFO, false) << mock_log_source.Log();
173 VLOG(1) << mock_log_source.Log();
174 VLOG_IF(1, true) << mock_log_source.Log();
vitalybuka@chromium.orgc914d8a2014-04-23 01:11:01[diff] [blame]175 VPLOG(1) << mock_log_source.Log();
176 VPLOG_IF(1, true) << mock_log_source.Log();
akalin@chromium.org521b0c42010-10-01 23:02:36[diff] [blame]177
178 DLOG(INFO) << mock_log_source.Log();
179 DLOG_IF(INFO, true) << mock_log_source.Log();
180 DPLOG(INFO) << mock_log_source.Log();
181 DPLOG_IF(INFO, true) << mock_log_source.Log();
182 DVLOG(1) << mock_log_source.Log();
183 DVLOG_IF(1, true) << mock_log_source.Log();
vitalybuka@chromium.orgc914d8a2014-04-23 01:11:01[diff] [blame]184 DVPLOG(1) << mock_log_source.Log();
185 DVPLOG_IF(1, true) << mock_log_source.Log();
akalin@chromium.org521b0c42010-10-01 23:02:36[diff] [blame]186}
187
skobesc78c0ad72015-12-07 20:21:23[diff] [blame]188TEST_F(LoggingTest, LoggingIsLazyByDestination) {
189 MockLogSource mock_log_source;
190 MockLogSource mock_log_source_error;
191 EXPECT_CALL(mock_log_source, Log()).Times(0);
192
193 // Severity >= ERROR is always printed to stderr.
194 EXPECT_CALL(mock_log_source_error, Log()).Times(1).
195 WillRepeatedly(Return("log message"));
196
197 LoggingSettings settings;
198 settings.logging_dest = LOG_NONE;
199 InitLogging(settings);
200
201 LOG(INFO) << mock_log_source.Log();
202 LOG(WARNING) << mock_log_source.Log();
203 LOG(ERROR) << mock_log_source_error.Log();
204}
205
Sharon Yang7cb919a2019-05-20 20:27:15[diff] [blame]206// Check that logging to stderr is gated on LOG_TO_STDERR.
207TEST_F(LoggingTest, LogToStdErrFlag) {
208 LoggingSettings settings;
209 settings.logging_dest = LOG_NONE;
210 InitLogging(settings);
211 MockLogSource mock_log_source;
212 EXPECT_CALL(mock_log_source, Log()).Times(0);
213 LOG(INFO) << mock_log_source.Log();
214
215 settings.logging_dest = LOG_TO_STDERR;
216 MockLogSource mock_log_source_stderr;
217 InitLogging(settings);
218 EXPECT_CALL(mock_log_source_stderr, Log()).Times(1).WillOnce(Return("foo"));
219 LOG(INFO) << mock_log_source_stderr.Log();
220}
221
Wez6c8acb82019-07-18 00:32:59[diff] [blame]222// Check that messages with severity ERROR or higher are always logged to
223// stderr if no log-destinations are set, other than LOG_TO_FILE.
224// This test is currently only POSIX-compatible.
225#if defined(OS_POSIX) || defined(OS_FUCHSIA)
226namespace {
227void TestForLogToStderr(int log_destinations,
228 bool* did_log_info,
229 bool* did_log_error) {
230 const char kInfoLogMessage[] = "This is an INFO level message";
231 const char kErrorLogMessage[] = "Here we have a message of level ERROR";
232 base::ScopedTempDir temp_dir;
233 ASSERT_TRUE(temp_dir.CreateUniqueTempDir());
234
235 // Set up logging.
236 LoggingSettings settings;
237 settings.logging_dest = log_destinations;
238 base::FilePath file_logs_path;
239 if (log_destinations & LOG_TO_FILE) {
240 file_logs_path = temp_dir.GetPath().Append("file.log");
Robbie McElrath8bf49842019-08-20 22:22:53[diff] [blame]241 settings.log_file_path = file_logs_path.value().c_str();
Wez6c8acb82019-07-18 00:32:59[diff] [blame]242 }
243 InitLogging(settings);
244
245 // Create a file and change stderr to write to that file, to easily check
246 // contents.
247 base::FilePath stderr_logs_path = temp_dir.GetPath().Append("stderr.log");
248 base::File stderr_logs = base::File(
249 stderr_logs_path,
250 base::File::FLAG_CREATE | base::File::FLAG_WRITE | base::File::FLAG_READ);
251 base::ScopedFD stderr_backup = base::ScopedFD(dup(STDERR_FILENO));
252 int dup_result = dup2(stderr_logs.GetPlatformFile(), STDERR_FILENO);
253 ASSERT_EQ(dup_result, STDERR_FILENO);
254
255 LOG(INFO) << kInfoLogMessage;
256 LOG(ERROR) << kErrorLogMessage;
257
258 // Restore the original stderr logging destination.
259 dup_result = dup2(stderr_backup.get(), STDERR_FILENO);
260 ASSERT_EQ(dup_result, STDERR_FILENO);
261
262 // Check which of the messages were written to stderr.
263 std::string written_logs;
264 ASSERT_TRUE(base::ReadFileToString(stderr_logs_path, &written_logs));
265 *did_log_info = written_logs.find(kInfoLogMessage) != std::string::npos;
266 *did_log_error = written_logs.find(kErrorLogMessage) != std::string::npos;
267}
268} // namespace
269
270TEST_F(LoggingTest, AlwaysLogErrorsToStderr) {
271 bool did_log_info = false;
272 bool did_log_error = false;
273
274 // When no destinations are specified, ERRORs should still log to stderr.
275 TestForLogToStderr(LOG_NONE, &did_log_info, &did_log_error);
276 EXPECT_FALSE(did_log_info);
277 EXPECT_TRUE(did_log_error);
278
279 // Logging only to a file should also log ERRORs to stderr as well.
280 TestForLogToStderr(LOG_TO_FILE, &did_log_info, &did_log_error);
281 EXPECT_FALSE(did_log_info);
282 EXPECT_TRUE(did_log_error);
283
284 // ERRORs should not be logged to stderr if any destination besides FILE is
285 // set.
286 TestForLogToStderr(LOG_TO_SYSTEM_DEBUG_LOG, &did_log_info, &did_log_error);
287 EXPECT_FALSE(did_log_info);
288 EXPECT_FALSE(did_log_error);
289
290 // Both ERRORs and INFO should be logged if LOG_TO_STDERR is set.
291 TestForLogToStderr(LOG_TO_STDERR, &did_log_info, &did_log_error);
292 EXPECT_TRUE(did_log_info);
293 EXPECT_TRUE(did_log_error);
294}
295#endif
296
Yuta Hijikata000df18f2020-11-18 06:55:58[diff] [blame]297#if BUILDFLAG(IS_CHROMEOS_ASH)
Robbie McElrath8bf49842019-08-20 22:22:53[diff] [blame]298TEST_F(LoggingTest, InitWithFileDescriptor) {
299 const char kErrorLogMessage[] = "something bad happened";
300
301 // Open a file to pass to the InitLogging.
302 base::ScopedTempDir temp_dir;
303 ASSERT_TRUE(temp_dir.CreateUniqueTempDir());
304 base::FilePath file_log_path = temp_dir.GetPath().Append("file.log");
305 FILE* log_file = fopen(file_log_path.value().c_str(), "w");
306 CHECK(log_file);
307
308 // Set up logging.
309 LoggingSettings settings;
310 settings.logging_dest = LOG_TO_FILE;
311 settings.log_file = log_file;
312 InitLogging(settings);
313
314 LOG(ERROR) << kErrorLogMessage;
315
316 // Check the message was written to the log file.
317 std::string written_logs;
318 ASSERT_TRUE(base::ReadFileToString(file_log_path, &written_logs));
319 ASSERT_NE(written_logs.find(kErrorLogMessage), std::string::npos);
320}
321
322TEST_F(LoggingTest, DuplicateLogFile) {
323 const char kErrorLogMessage1[] = "something really bad happened";
324 const char kErrorLogMessage2[] = "some other bad thing happened";
325
326 base::ScopedTempDir temp_dir;
327 ASSERT_TRUE(temp_dir.CreateUniqueTempDir());
328 base::FilePath file_log_path = temp_dir.GetPath().Append("file.log");
329
330 // Set up logging.
331 LoggingSettings settings;
332 settings.logging_dest = LOG_TO_FILE;
333 settings.log_file_path = file_log_path.value().c_str();
334 InitLogging(settings);
335
336 LOG(ERROR) << kErrorLogMessage1;
337
338 // Duplicate the log FILE, close the original (to make sure we actually
339 // duplicated it), and write to the duplicate.
340 FILE* log_file_dup = DuplicateLogFILE();
341 CHECK(log_file_dup);
342 CloseLogFile();
343 fprintf(log_file_dup, "%s\n", kErrorLogMessage2);
344 fflush(log_file_dup);
345
346 // Check the messages were written to the log file.
347 std::string written_logs;
348 ASSERT_TRUE(base::ReadFileToString(file_log_path, &written_logs));
349 ASSERT_NE(written_logs.find(kErrorLogMessage1), std::string::npos);
350 ASSERT_NE(written_logs.find(kErrorLogMessage2), std::string::npos);
351 fclose(log_file_dup);
352}
Yuta Hijikata000df18f2020-11-18 06:55:58[diff] [blame]353#endif // BUILDFLAG(IS_CHROMEOS_ASH)
Robbie McElrath8bf49842019-08-20 22:22:53[diff] [blame]354
scottmga17c8db2017-02-15 21:35:49[diff] [blame]355#if defined(OFFICIAL_BUILD) && defined(OS_WIN)
356NOINLINE void CheckContainingFunc(int death_location) {
357 CHECK(death_location != 1);
358 CHECK(death_location != 2);
359 CHECK(death_location != 3);
360}
361
362int GetCheckExceptionData(EXCEPTION_POINTERS* p, DWORD* code, void** addr) {
363 *code = p->ExceptionRecord->ExceptionCode;
364 *addr = p->ExceptionRecord->ExceptionAddress;
365 return EXCEPTION_EXECUTE_HANDLER;
366}
367
368TEST_F(LoggingTest, CheckCausesDistinctBreakpoints) {
369 DWORD code1 = 0;
370 DWORD code2 = 0;
371 DWORD code3 = 0;
372 void* addr1 = nullptr;
373 void* addr2 = nullptr;
374 void* addr3 = nullptr;
375
376 // Record the exception code and addresses.
377 __try {
378 CheckContainingFunc(1);
379 } __except (
380 GetCheckExceptionData(GetExceptionInformation(), &code1, &addr1)) {
381 }
382
383 __try {
384 CheckContainingFunc(2);
385 } __except (
386 GetCheckExceptionData(GetExceptionInformation(), &code2, &addr2)) {
387 }
388
389 __try {
390 CheckContainingFunc(3);
391 } __except (
392 GetCheckExceptionData(GetExceptionInformation(), &code3, &addr3)) {
393 }
394
395 // Ensure that the exception codes are correct (in particular, breakpoints,
396 // not access violations).
397 EXPECT_EQ(STATUS_BREAKPOINT, code1);
398 EXPECT_EQ(STATUS_BREAKPOINT, code2);
399 EXPECT_EQ(STATUS_BREAKPOINT, code3);
400
401 // Ensure that none of the CHECKs are colocated.
402 EXPECT_NE(addr1, addr2);
403 EXPECT_NE(addr1, addr3);
404 EXPECT_NE(addr2, addr3);
405}
Fabrice de Gans-Riberia2a53862018-06-08 18:04:26[diff] [blame]406#elif defined(OS_FUCHSIA)
primianof5316722017-02-21 13:09:26[diff] [blame]407
Fabrice de Gans-Riberia2a53862018-06-08 18:04:26[diff] [blame]408// CHECK causes a direct crash (without jumping to another function) only in
409// official builds. Unfortunately, continuous test coverage on official builds
410// is lower. Furthermore, since the Fuchsia implementation uses threads, it is
411// not possible to rely on an implementation of CHECK that calls abort(), which
412// takes down the whole process, preventing the thread exception handler from
413// handling the exception. DO_CHECK here falls back on IMMEDIATE_CRASH() in
414// non-official builds, to catch regressions earlier in the CQ.
415#if defined(OFFICIAL_BUILD)
416#define DO_CHECK CHECK
417#else
418#define DO_CHECK(cond) \
419 if (!(cond)) { \
420 IMMEDIATE_CRASH(); \
421 }
422#endif
423
Fabrice de Gans-Riberia2a53862018-06-08 18:04:26[diff] [blame]424struct thread_data_t {
425 // For signaling the thread ended properly.
David Purselldc329442019-07-17 16:30:38[diff] [blame]426 zx::event event;
427 // For catching thread exceptions. Created by the crashing thread.
428 zx::channel channel;
Fabrice de Gans-Riberia2a53862018-06-08 18:04:26[diff] [blame]429 // Location where the thread is expected to crash.
430 int death_location;
431};
432
David Purselldc329442019-07-17 16:30:38[diff] [blame]433// Indicates the exception channel has been created successfully.
434constexpr zx_signals_t kChannelReadySignal = ZX_USER_SIGNAL_0;
Fabrice de Gans-Riberia2a53862018-06-08 18:04:26[diff] [blame]435
David Purselldc329442019-07-17 16:30:38[diff] [blame]436// Indicates an error setting up the crash thread.
437constexpr zx_signals_t kCrashThreadErrorSignal = ZX_USER_SIGNAL_1;
438
439void* CrashThread(void* arg) {
Fabrice de Gans-Riberia2a53862018-06-08 18:04:26[diff] [blame]440 thread_data_t* data = (thread_data_t*)arg;
441 int death_location = data->death_location;
442
David Purselldc329442019-07-17 16:30:38[diff] [blame]443 // Register the exception handler.
444 zx_status_t status =
445 zx::thread::self()->create_exception_channel(0, &data->channel);
Fabrice de Gans-Riberia2a53862018-06-08 18:04:26[diff] [blame]446 if (status != ZX_OK) {
David Purselldc329442019-07-17 16:30:38[diff] [blame]447 data->event.signal(0, kCrashThreadErrorSignal);
Fabrice de Gans-Riberia2a53862018-06-08 18:04:26[diff] [blame]448 return nullptr;
449 }
David Purselldc329442019-07-17 16:30:38[diff] [blame]450 data->event.signal(0, kChannelReadySignal);
Fabrice de Gans-Riberia2a53862018-06-08 18:04:26[diff] [blame]451
452 DO_CHECK(death_location != 1);
453 DO_CHECK(death_location != 2);
454 DO_CHECK(death_location != 3);
455
456 // We should never reach this point, signal the thread incorrectly ended
457 // properly.
David Purselldc329442019-07-17 16:30:38[diff] [blame]458 data->event.signal(0, kCrashThreadErrorSignal);
Fabrice de Gans-Riberia2a53862018-06-08 18:04:26[diff] [blame]459 return nullptr;
460}
461
David Gilhooleyb2ae430d2020-09-16 19:25:04[diff] [blame]462// Helper function to call pthread_exit(nullptr).
463_Noreturn __NO_SAFESTACK void exception_pthread_exit() {
464 pthread_exit(nullptr);
465}
466
Fabrice de Gans-Riberia2a53862018-06-08 18:04:26[diff] [blame]467// Runs the CrashThread function in a separate thread.
468void SpawnCrashThread(int death_location, uintptr_t* child_crash_addr) {
Wez157707d62018-07-10 22:48:47[diff] [blame]469 zx::event event;
David Purselldc329442019-07-17 16:30:38[diff] [blame]470 zx_status_t status = zx::event::create(0, &event);
Fabrice de Gans-Riberia2a53862018-06-08 18:04:26[diff] [blame]471 ASSERT_EQ(status, ZX_OK);
472
473 // Run the thread.
David Purselldc329442019-07-17 16:30:38[diff] [blame]474 thread_data_t thread_data = {std::move(event), zx::channel(), death_location};
Fabrice de Gans-Riberia2a53862018-06-08 18:04:26[diff] [blame]475 pthread_t thread;
476 int ret = pthread_create(&thread, nullptr, CrashThread, &thread_data);
477 ASSERT_EQ(ret, 0);
478
David Purselldc329442019-07-17 16:30:38[diff] [blame]479 // Wait for the thread to set up its exception channel.
480 zx_signals_t signals = 0;
481 status =
482 thread_data.event.wait_one(kChannelReadySignal | kCrashThreadErrorSignal,
483 zx::time::infinite(), &signals);
484 ASSERT_EQ(status, ZX_OK);
485 ASSERT_EQ(signals, kChannelReadySignal);
486
487 // Wait for the exception and read it out of the channel.
488 status =
489 thread_data.channel.wait_one(ZX_CHANNEL_READABLE | ZX_CHANNEL_PEER_CLOSED,
490 zx::time::infinite(), &signals);
Fabrice de Gans-Riberia2a53862018-06-08 18:04:26[diff] [blame]491 ASSERT_EQ(status, ZX_OK);
492 // Check the thread did crash and not terminate.
David Purselldc329442019-07-17 16:30:38[diff] [blame]493 ASSERT_FALSE(signals & ZX_CHANNEL_PEER_CLOSED);
494
495 zx_exception_info_t exception_info;
496 zx::exception exception;
497 status = thread_data.channel.read(
498 0, &exception_info, exception.reset_and_get_address(),
499 sizeof(exception_info), 1, nullptr, nullptr);
500 ASSERT_EQ(status, ZX_OK);
Fabrice de Gans-Riberia2a53862018-06-08 18:04:26[diff] [blame]501
David Gilhooleyb2ae430d2020-09-16 19:25:04[diff] [blame]502 // Get the crash address and point the thread towards exiting.
Wez157707d62018-07-10 22:48:47[diff] [blame]503 zx::thread zircon_thread;
David Purselldc329442019-07-17 16:30:38[diff] [blame]504 status = exception.get_thread(&zircon_thread);
Fabrice de Gans-Riberia2a53862018-06-08 18:04:26[diff] [blame]505 ASSERT_EQ(status, ZX_OK);
506 zx_thread_state_general_regs_t buffer;
Wez157707d62018-07-10 22:48:47[diff] [blame]507 status = zircon_thread.read_state(ZX_THREAD_STATE_GENERAL_REGS, &buffer,
508 sizeof(buffer));
Fabrice de Gans-Riberia2a53862018-06-08 18:04:26[diff] [blame]509 ASSERT_EQ(status, ZX_OK);
510#if defined(ARCH_CPU_X86_64)
511 *child_crash_addr = static_cast<uintptr_t>(buffer.rip);
David Gilhooleyb2ae430d2020-09-16 19:25:04[diff] [blame]512 buffer.rip = reinterpret_cast<uintptr_t>(exception_pthread_exit);
Fabrice de Gans-Riberia2a53862018-06-08 18:04:26[diff] [blame]513#elif defined(ARCH_CPU_ARM64)
514 *child_crash_addr = static_cast<uintptr_t>(buffer.pc);
David Gilhooleyb2ae430d2020-09-16 19:25:04[diff] [blame]515 buffer.pc = reinterpret_cast<uintptr_t>(exception_pthread_exit);
Fabrice de Gans-Riberia2a53862018-06-08 18:04:26[diff] [blame]516#else
517#error Unsupported architecture
518#endif
David Gilhooleyb2ae430d2020-09-16 19:25:04[diff] [blame]519 ASSERT_EQ(zircon_thread.write_state(ZX_THREAD_STATE_GENERAL_REGS, &buffer,
520 sizeof(buffer)),
521 ZX_OK);
Fabrice de Gans-Riberia2a53862018-06-08 18:04:26[diff] [blame]522
David Gilhooleyb2ae430d2020-09-16 19:25:04[diff] [blame]523 // Clear the exception so the thread continues.
524 uint32_t state = ZX_EXCEPTION_STATE_HANDLED;
525 ASSERT_EQ(
526 exception.set_property(ZX_PROP_EXCEPTION_STATE, &state, sizeof(state)),
527 ZX_OK);
528 exception.reset();
529
530 // Join the exiting pthread.
531 ASSERT_EQ(pthread_join(thread, nullptr), 0);
Fabrice de Gans-Riberia2a53862018-06-08 18:04:26[diff] [blame]532}
533
534TEST_F(LoggingTest, CheckCausesDistinctBreakpoints) {
535 uintptr_t child_crash_addr_1 = 0;
536 uintptr_t child_crash_addr_2 = 0;
537 uintptr_t child_crash_addr_3 = 0;
538
539 SpawnCrashThread(1, &child_crash_addr_1);
540 SpawnCrashThread(2, &child_crash_addr_2);
541 SpawnCrashThread(3, &child_crash_addr_3);
542
543 ASSERT_NE(0u, child_crash_addr_1);
544 ASSERT_NE(0u, child_crash_addr_2);
545 ASSERT_NE(0u, child_crash_addr_3);
546 ASSERT_NE(child_crash_addr_1, child_crash_addr_2);
547 ASSERT_NE(child_crash_addr_1, child_crash_addr_3);
548 ASSERT_NE(child_crash_addr_2, child_crash_addr_3);
549}
primianob4da3ca2017-02-21 21:50:27[diff] [blame]550#elif defined(OS_POSIX) && !defined(OS_NACL) && !defined(OS_IOS) && \
primianof5316722017-02-21 13:09:26[diff] [blame]551 (defined(ARCH_CPU_X86_FAMILY) || defined(ARCH_CPU_ARM_FAMILY))
552
553int g_child_crash_pipe;
554
555void CheckCrashTestSighandler(int, siginfo_t* info, void* context_ptr) {
556 // Conversely to what clearly stated in "man 2 sigaction", some Linux kernels
557 // do NOT populate the |info->si_addr| in the case of a SIGTRAP. Hence we
558 // need the arch-specific boilerplate below, which is inspired by breakpad.
559 // At the same time, on OSX, ucontext.h is deprecated but si_addr works fine.
560 uintptr_t crash_addr = 0;
Avi Drissman78281f32020-07-31 03:09:03[diff] [blame]561#if defined(OS_MAC)
primianof5316722017-02-21 13:09:26[diff] [blame]562 crash_addr = reinterpret_cast<uintptr_t>(info->si_addr);
Avi Drissman78281f32020-07-31 03:09:03[diff] [blame]563#else // OS_*
Tom Anderson13734d42018-02-24 04:45:47[diff] [blame]564 ucontext_t* context = reinterpret_cast<ucontext_t*>(context_ptr);
primianof5316722017-02-21 13:09:26[diff] [blame]565#if defined(ARCH_CPU_X86)
566 crash_addr = static_cast<uintptr_t>(context->uc_mcontext.gregs[REG_EIP]);
567#elif defined(ARCH_CPU_X86_64)
568 crash_addr = static_cast<uintptr_t>(context->uc_mcontext.gregs[REG_RIP]);
569#elif defined(ARCH_CPU_ARMEL)
570 crash_addr = static_cast<uintptr_t>(context->uc_mcontext.arm_pc);
571#elif defined(ARCH_CPU_ARM64)
572 crash_addr = static_cast<uintptr_t>(context->uc_mcontext.pc);
573#endif // ARCH_*
Avi Drissman78281f32020-07-31 03:09:03[diff] [blame]574#endif // OS_*
primianof5316722017-02-21 13:09:26[diff] [blame]575 HANDLE_EINTR(write(g_child_crash_pipe, &crash_addr, sizeof(uintptr_t)));
576 _exit(0);
577}
578
579// CHECK causes a direct crash (without jumping to another function) only in
580// official builds. Unfortunately, continuous test coverage on official builds
581// is lower. DO_CHECK here falls back on a home-brewed implementation in
582// non-official builds, to catch regressions earlier in the CQ.
583#if defined(OFFICIAL_BUILD)
584#define DO_CHECK CHECK
585#else
586#define DO_CHECK(cond) \
587 if (!(cond)) \
588 IMMEDIATE_CRASH()
589#endif
590
591void CrashChildMain(int death_location) {
592 struct sigaction act = {};
593 act.sa_sigaction = CheckCrashTestSighandler;
594 act.sa_flags = SA_SIGINFO;
Ivan Kotenkova16212a52017-11-08 12:37:33[diff] [blame]595 ASSERT_EQ(0, sigaction(SIGTRAP, &act, nullptr));
596 ASSERT_EQ(0, sigaction(SIGBUS, &act, nullptr));
597 ASSERT_EQ(0, sigaction(SIGILL, &act, nullptr));
primianof5316722017-02-21 13:09:26[diff] [blame]598 DO_CHECK(death_location != 1);
599 DO_CHECK(death_location != 2);
600 printf("\n");
601 DO_CHECK(death_location != 3);
602
603 // Should never reach this point.
604 const uintptr_t failed = 0;
605 HANDLE_EINTR(write(g_child_crash_pipe, &failed, sizeof(uintptr_t)));
Nico Weberca5f9592019-01-31 14:35:41[diff] [blame]606}
primianof5316722017-02-21 13:09:26[diff] [blame]607
608void SpawnChildAndCrash(int death_location, uintptr_t* child_crash_addr) {
609 int pipefd[2];
610 ASSERT_EQ(0, pipe(pipefd));
611
612 int pid = fork();
613 ASSERT_GE(pid, 0);
614
615 if (pid == 0) { // child process.
616 close(pipefd[0]); // Close reader (parent) end.
617 g_child_crash_pipe = pipefd[1];
618 CrashChildMain(death_location);
619 FAIL() << "The child process was supposed to crash. It didn't.";
620 }
621
622 close(pipefd[1]); // Close writer (child) end.
623 DCHECK(child_crash_addr);
624 int res = HANDLE_EINTR(read(pipefd[0], child_crash_addr, sizeof(uintptr_t)));
625 ASSERT_EQ(static_cast<int>(sizeof(uintptr_t)), res);
626}
627
628TEST_F(LoggingTest, CheckCausesDistinctBreakpoints) {
629 uintptr_t child_crash_addr_1 = 0;
630 uintptr_t child_crash_addr_2 = 0;
631 uintptr_t child_crash_addr_3 = 0;
632
633 SpawnChildAndCrash(1, &child_crash_addr_1);
634 SpawnChildAndCrash(2, &child_crash_addr_2);
635 SpawnChildAndCrash(3, &child_crash_addr_3);
636
637 ASSERT_NE(0u, child_crash_addr_1);
638 ASSERT_NE(0u, child_crash_addr_2);
639 ASSERT_NE(0u, child_crash_addr_3);
640 ASSERT_NE(child_crash_addr_1, child_crash_addr_2);
641 ASSERT_NE(child_crash_addr_1, child_crash_addr_3);
642 ASSERT_NE(child_crash_addr_2, child_crash_addr_3);
643}
644#endif // OS_POSIX
scottmga17c8db2017-02-15 21:35:49[diff] [blame]645
akalin@chromium.org521b0c42010-10-01 23:02:36[diff] [blame]646TEST_F(LoggingTest, DebugLoggingReleaseBehavior) {
weza245bd072017-06-18 23:26:34[diff] [blame]647#if DCHECK_IS_ON()
akalin@chromium.org521b0c42010-10-01 23:02:36[diff] [blame]648 int debug_only_variable = 1;
649#endif
650 // These should avoid emitting references to |debug_only_variable|
651 // in release mode.
652 DLOG_IF(INFO, debug_only_variable) << "test";
653 DLOG_ASSERT(debug_only_variable) << "test";
654 DPLOG_IF(INFO, debug_only_variable) << "test";
655 DVLOG_IF(1, debug_only_variable) << "test";
656}
657
alex-accc1bde62017-04-19 08:33:55[diff] [blame]658TEST_F(LoggingTest, NestedLogAssertHandlers) {
659 ::testing::InSequence dummy;
660 ::testing::StrictMock<MockLogAssertHandler> handler_a, handler_b;
661
662 EXPECT_CALL(
663 handler_a,
664 HandleLogAssert(
hans297a9142017-04-20 18:14:53[diff] [blame]665 _, _, base::StringPiece("First assert must be caught by handler_a"),
alex-accc1bde62017-04-19 08:33:55[diff] [blame]666 _));
667 EXPECT_CALL(
668 handler_b,
alex-ac4df548e2017-04-20 17:42:38[diff] [blame]669 HandleLogAssert(
hans297a9142017-04-20 18:14:53[diff] [blame]670 _, _, base::StringPiece("Second assert must be caught by handler_b"),
alex-ac4df548e2017-04-20 17:42:38[diff] [blame]671 _));
alex-accc1bde62017-04-19 08:33:55[diff] [blame]672 EXPECT_CALL(
673 handler_a,
alex-ac4df548e2017-04-20 17:42:38[diff] [blame]674 HandleLogAssert(
675 _, _,
hans297a9142017-04-20 18:14:53[diff] [blame]676 base::StringPiece("Last assert must be caught by handler_a again"),
alex-ac4df548e2017-04-20 17:42:38[diff] [blame]677 _));
alex-accc1bde62017-04-19 08:33:55[diff] [blame]678
kylechar85644172019-05-15 13:39:11[diff] [blame]679 logging::ScopedLogAssertHandler scoped_handler_a(base::BindRepeating(
alex-accc1bde62017-04-19 08:33:55[diff] [blame]680 &MockLogAssertHandler::HandleLogAssert, base::Unretained(&handler_a)));
681
hans297a9142017-04-20 18:14:53[diff] [blame]682 // Using LOG(FATAL) rather than CHECK(false) here since log messages aren't
683 // preserved for CHECKs in official builds.
684 LOG(FATAL) << "First assert must be caught by handler_a";
alex-accc1bde62017-04-19 08:33:55[diff] [blame]685
686 {
kylechar85644172019-05-15 13:39:11[diff] [blame]687 logging::ScopedLogAssertHandler scoped_handler_b(base::BindRepeating(
alex-accc1bde62017-04-19 08:33:55[diff] [blame]688 &MockLogAssertHandler::HandleLogAssert, base::Unretained(&handler_b)));
hans297a9142017-04-20 18:14:53[diff] [blame]689 LOG(FATAL) << "Second assert must be caught by handler_b";
alex-accc1bde62017-04-19 08:33:55[diff] [blame]690 }
691
hans297a9142017-04-20 18:14:53[diff] [blame]692 LOG(FATAL) << "Last assert must be caught by handler_a again";
alex-accc1bde62017-04-19 08:33:55[diff] [blame]693}
694
jyasskin@chromium.org81411c62014-07-08 23:03:06[diff] [blame]695// Test that defining an operator<< for a type in a namespace doesn't prevent
696// other code in that namespace from calling the operator<<(ostream, wstring)
697// defined by logging.h. This can fail if operator<<(ostream, wstring) can't be
698// found by ADL, since defining another operator<< prevents name lookup from
699// looking in the global namespace.
700namespace nested_test {
701 class Streamable {};
pkasting99867ef2014-10-16 23:49:24[diff] [blame]702 ALLOW_UNUSED_TYPE std::ostream& operator<<(std::ostream& out,
703 const Streamable&) {
jyasskin@chromium.org81411c62014-07-08 23:03:06[diff] [blame]704 return out << "Streamable";
705 }
706 TEST_F(LoggingTest, StreamingWstringFindsCorrectOperator) {
707 std::wstring wstr = L"Hello World";
708 std::ostringstream ostr;
709 ostr << wstr;
710 EXPECT_EQ("Hello World", ostr.str());
711 }
712} // namespace nested_test
713
Scott Grahamd90951b2017-11-28 23:53:26[diff] [blame]714#if defined(OS_FUCHSIA)
Sharon Yanga4b908de2019-05-07 22:19:03[diff] [blame]715
Sharon Yanga4b908de2019-05-07 22:19:03[diff] [blame]716// Verifies that calling the log macro goes to the Fuchsia system logs.
717TEST_F(LoggingTest, FuchsiaSystemLogging) {
Wezc146e492020-12-08 18:54:36[diff] [blame]718 constexpr char kLogMessage[] = "system log!";
719
720 base::SimpleTestLogListener listener;
721
722 // Connect the test LogListenerSafe to the Log.
723 std::unique_ptr<fuchsia::logger::LogFilterOptions> options =
724 std::make_unique<fuchsia::logger::LogFilterOptions>();
725 options->tags = {"base_unittests__exec"};
726 fuchsia::logger::LogPtr log = base::ComponentContextForProcess()
727 ->svc()
728 ->Connect<fuchsia::logger::Log>();
729 listener.ListenToLog(log.get(), std::move(options));
730
731 // Emit the test log message, and spin the loop until it is reported to the
732 // test listener.
Sharon Yanga4b908de2019-05-07 22:19:03[diff] [blame]733 LOG(ERROR) << kLogMessage;
734
Wezc146e492020-12-08 18:54:36[diff] [blame]735 base::Optional<fuchsia::logger::LogMessage> logged_message =
736 listener.RunUntilMessageReceived(kLogMessage);
Wez224c0bf62019-05-24 19:26:13[diff] [blame]737
Wezc146e492020-12-08 18:54:36[diff] [blame]738 ASSERT_TRUE(logged_message.has_value());
739 EXPECT_EQ(logged_message->severity,
Wez224c0bf62019-05-24 19:26:13[diff] [blame]740 static_cast<int32_t>(fuchsia::logger::LogLevelFilter::ERROR));
Wezc146e492020-12-08 18:54:36[diff] [blame]741 ASSERT_EQ(logged_message->tags.size(), 1u);
742 EXPECT_EQ(logged_message->tags[0], base::CommandLine::ForCurrentProcess()
743 ->GetProgram()
744 .BaseName()
745 .AsUTF8Unsafe());
Sharon Yanga4b908de2019-05-07 22:19:03[diff] [blame]746}
747
Scott Grahamd90951b2017-11-28 23:53:26[diff] [blame]748TEST_F(LoggingTest, FuchsiaLogging) {
749 MockLogSource mock_log_source;
750 EXPECT_CALL(mock_log_source, Log())
751 .Times(DCHECK_IS_ON() ? 2 : 1)
752 .WillRepeatedly(Return("log message"));
753
Lei Zhang93dd4252020-10-23 18:45:53[diff] [blame]754 SetMinLogLevel(LOGGING_INFO);
Scott Grahamd90951b2017-11-28 23:53:26[diff] [blame]755
756 EXPECT_TRUE(LOG_IS_ON(INFO));
Wezad51a5a2019-11-26 20:39:02[diff] [blame]757 EXPECT_EQ(DCHECK_IS_ON(), DLOG_IS_ON(INFO));
Scott Grahamd90951b2017-11-28 23:53:26[diff] [blame]758
759 ZX_LOG(INFO, ZX_ERR_INTERNAL) << mock_log_source.Log();
760 ZX_DLOG(INFO, ZX_ERR_INTERNAL) << mock_log_source.Log();
761
762 ZX_CHECK(true, ZX_ERR_INTERNAL);
763 ZX_DCHECK(true, ZX_ERR_INTERNAL);
764}
Wezc146e492020-12-08 18:54:36[diff] [blame]765
Scott Grahamd90951b2017-11-28 23:53:26[diff] [blame]766#endif // defined(OS_FUCHSIA)
767
James Cooka0536c32018-08-01 20:13:31[diff] [blame]768TEST_F(LoggingTest, LogPrefix) {
James Cooka0536c32018-08-01 20:13:31[diff] [blame]769 // Use a static because only captureless lambdas can be converted to a
770 // function pointer for SetLogMessageHandler().
Yuta Hijikata9b7279a2020-08-26 16:10:54[diff] [blame]771 static base::NoDestructor<std::string> log_string;
James Cooka0536c32018-08-01 20:13:31[diff] [blame]772 SetLogMessageHandler([](int severity, const char* file, int line,
773 size_t start, const std::string& str) -> bool {
Yuta Hijikata9b7279a2020-08-26 16:10:54[diff] [blame]774 *log_string = str;
James Cooka0536c32018-08-01 20:13:31[diff] [blame]775 return true;
776 });
777
Yuta Hijikata9b7279a2020-08-26 16:10:54[diff] [blame]778 // Logging with a prefix includes the prefix string.
James Cooka0536c32018-08-01 20:13:31[diff] [blame]779 const char kPrefix[] = "prefix";
780 SetLogPrefix(kPrefix);
781 LOG(ERROR) << "test"; // Writes into |log_string|.
Yuta Hijikata9b7279a2020-08-26 16:10:54[diff] [blame]782 EXPECT_NE(std::string::npos, log_string->find(kPrefix));
James Cooka0536c32018-08-01 20:13:31[diff] [blame]783 // Logging without a prefix does not include the prefix string.
784 SetLogPrefix(nullptr);
785 LOG(ERROR) << "test"; // Writes into |log_string|.
Yuta Hijikata9b7279a2020-08-26 16:10:54[diff] [blame]786 EXPECT_EQ(std::string::npos, log_string->find(kPrefix));
James Cooka0536c32018-08-01 20:13:31[diff] [blame]787}
788
Yuta Hijikata000df18f2020-11-18 06:55:58[diff] [blame]789#if BUILDFLAG(IS_CHROMEOS_ASH)
Yuta Hijikata9b7279a2020-08-26 16:10:54[diff] [blame]790TEST_F(LoggingTest, LogCrosSyslogFormat) {
791 // Set log format to syslog format.
792 scoped_logging_settings().SetLogFormat(LogFormat::LOG_FORMAT_SYSLOG);
793
794 const char* kTimestampPattern = R"(\d\d\d\d\-\d\d\-\d\d)" // date
795 R"(T\d\d\:\d\d\:\d\d\.\d\d\d\d\d\d)" // time
796 R"(Z.+\n)"; // timezone
797
798 // Use a static because only captureless lambdas can be converted to a
799 // function pointer for SetLogMessageHandler().
800 static base::NoDestructor<std::string> log_string;
801 SetLogMessageHandler([](int severity, const char* file, int line,
802 size_t start, const std::string& str) -> bool {
803 *log_string = str;
804 return true;
805 });
806
807 {
808 // All flags are true.
809 SetLogItems(true, true, true, true);
810 const char* kExpected =
811 R"(\S+ \d+ ERROR \S+\[\d+:\d+\]\: \[\S+\] message\n)";
812
813 LOG(ERROR) << "message";
814
815 EXPECT_THAT(*log_string, ::testing::MatchesRegex(kTimestampPattern));
816 EXPECT_THAT(*log_string, ::testing::MatchesRegex(kExpected));
817 }
818
819 {
820 // Timestamp is true.
821 SetLogItems(false, false, true, false);
822 const char* kExpected = R"(\S+ ERROR \S+\: \[\S+\] message\n)";
823
824 LOG(ERROR) << "message";
825
826 EXPECT_THAT(*log_string, ::testing::MatchesRegex(kTimestampPattern));
827 EXPECT_THAT(*log_string, ::testing::MatchesRegex(kExpected));
828 }
829
830 {
831 // PID and timestamp are true.
832 SetLogItems(true, false, true, false);
833 const char* kExpected = R"(\S+ ERROR \S+\[\d+\]: \[\S+\] message\n)";
834
835 LOG(ERROR) << "message";
836
837 EXPECT_THAT(*log_string, ::testing::MatchesRegex(kTimestampPattern));
838 EXPECT_THAT(*log_string, ::testing::MatchesRegex(kExpected));
839 }
840
841 {
842 // ThreadID and timestamp are true.
843 SetLogItems(false, true, true, false);
844 const char* kExpected = R"(\S+ ERROR \S+\[:\d+\]: \[\S+\] message\n)";
845
846 LOG(ERROR) << "message";
847
848 EXPECT_THAT(*log_string, ::testing::MatchesRegex(kTimestampPattern));
849 EXPECT_THAT(*log_string, ::testing::MatchesRegex(kExpected));
850 }
851
852 {
853 // All flags are false.
854 SetLogItems(false, false, false, false);
855 const char* kExpected = R"(ERROR \S+: \[\S+\] message\n)";
856
857 LOG(ERROR) << "message";
858
859 EXPECT_THAT(*log_string, ::testing::MatchesRegex(kExpected));
860 }
861}
Yuta Hijikata000df18f2020-11-18 06:55:58[diff] [blame]862#endif // BUILDFLAG(IS_CHROMEOS_ASH)
Yuta Hijikata9b7279a2020-08-26 16:10:54[diff] [blame]863
Jan Wilken Dörrie3c1c8fdf2021-01-22 08:17:46[diff] [blame]864// We define a custom operator<< for string16 so we can use it with logging.
865// This tests that conversion.
866TEST_F(LoggingTest, String16) {
867 // Basic stream test.
868 {
869 std::ostringstream stream;
Jan Wilken Dörrie85285b02021-03-11 23:38:47[diff] [blame^]870 stream << "Empty '" << std::u16string() << "' standard '"
871 << std::u16string(base::ASCIIToUTF16("Hello, world")) << "'";
Jan Wilken Dörrie3c1c8fdf2021-01-22 08:17:46[diff] [blame]872 EXPECT_STREQ("Empty '' standard 'Hello, world'", stream.str().c_str());
873 }
874
875 // Interesting edge cases.
876 {
877 // These should each get converted to the invalid character: EF BF BD.
Jan Wilken Dörrie85285b02021-03-11 23:38:47[diff] [blame^]878 std::u16string initial_surrogate;
Jan Wilken Dörrie3c1c8fdf2021-01-22 08:17:46[diff] [blame]879 initial_surrogate.push_back(0xd800);
Jan Wilken Dörrie85285b02021-03-11 23:38:47[diff] [blame^]880 std::u16string final_surrogate;
Jan Wilken Dörrie3c1c8fdf2021-01-22 08:17:46[diff] [blame]881 final_surrogate.push_back(0xdc00);
882
883 // Old italic A = U+10300, will get converted to: F0 90 8C 80 'z'.
Jan Wilken Dörrie85285b02021-03-11 23:38:47[diff] [blame^]884 std::u16string surrogate_pair;
Jan Wilken Dörrie3c1c8fdf2021-01-22 08:17:46[diff] [blame]885 surrogate_pair.push_back(0xd800);
886 surrogate_pair.push_back(0xdf00);
887 surrogate_pair.push_back('z');
888
889 // Will get converted to the invalid char + 's': EF BF BD 's'.
Jan Wilken Dörrie85285b02021-03-11 23:38:47[diff] [blame^]890 std::u16string unterminated_surrogate;
Jan Wilken Dörrie3c1c8fdf2021-01-22 08:17:46[diff] [blame]891 unterminated_surrogate.push_back(0xd800);
892 unterminated_surrogate.push_back('s');
893
894 std::ostringstream stream;
895 stream << initial_surrogate << "," << final_surrogate << ","
896 << surrogate_pair << "," << unterminated_surrogate;
897
898 EXPECT_STREQ("\xef\xbf\xbd,\xef\xbf\xbd,\xf0\x90\x8c\x80z,\xef\xbf\xbds",
899 stream.str().c_str());
900 }
901}
902
akalin@chromium.org521b0c42010-10-01 23:02:36[diff] [blame]903} // namespace
904
905} // namespace logging