2 * Copyright 2004-present Facebook, Inc.
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
8 * http://www.apache.org/licenses/LICENSE-2.0
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.
16 #include <folly/experimental/logging/LogCategory.h>
17 #include <folly/experimental/logging/LogHandler.h>
18 #include <folly/experimental/logging/LogMessage.h>
19 #include <folly/experimental/logging/Logger.h>
20 #include <folly/experimental/logging/LoggerDB.h>
21 #include <folly/experimental/logging/test/TestLogHandler.h>
22 #include <folly/portability/GTest.h>
24 using namespace folly;
25 using std::make_shared;
27 class LoggerTest : public ::testing::Test {
29 void SetUp() override {
30 auto* category = logger_.getCategory();
32 handler_ = make_shared<TestLogHandler>();
33 category->addHandler(handler_);
34 category->setLevel(LogLevel::DEBUG, true);
37 static StringPiece pathBasename(StringPiece path) {
38 auto idx = path.rfind('/');
39 if (idx == StringPiece::npos) {
42 return path.subpiece(idx + 1);
45 LoggerDB db_{LoggerDB::TESTING};
46 Logger logger_{&db_, "test"};
47 std::shared_ptr<TestLogHandler> handler_;
50 TEST_F(LoggerTest, basic) {
52 auto expectedLine = __LINE__ + 1;
53 FB_LOG(logger_, WARN, "hello world");
55 auto& messages = handler_->getMessages();
56 ASSERT_EQ(1, messages.size());
57 EXPECT_EQ("hello world", messages[0].first.getMessage());
58 EXPECT_EQ("LoggerTest.cpp", pathBasename(messages[0].first.getFileName()));
59 EXPECT_EQ(expectedLine, messages[0].first.getLineNumber());
60 EXPECT_EQ(LogLevel::WARN, messages[0].first.getLevel());
61 EXPECT_FALSE(messages[0].first.containsNewlines());
62 EXPECT_EQ(logger_.getCategory(), messages[0].first.getCategory());
63 EXPECT_EQ(logger_.getCategory(), messages[0].second);
66 TEST_F(LoggerTest, subCategory) {
67 // Log from a sub-category.
68 Logger subLogger{&db_, "test.foo.bar"};
69 auto expectedLine = __LINE__ + 1;
70 FB_LOG(subLogger, ERR, "sub-category\nlog message");
72 auto& messages = handler_->getMessages();
73 ASSERT_EQ(1, messages.size());
74 EXPECT_EQ("sub-category\nlog message", messages[0].first.getMessage());
75 EXPECT_EQ("LoggerTest.cpp", pathBasename(messages[0].first.getFileName()));
76 EXPECT_EQ(expectedLine, messages[0].first.getLineNumber());
77 EXPECT_EQ(LogLevel::ERR, messages[0].first.getLevel());
78 EXPECT_TRUE(messages[0].first.containsNewlines());
79 EXPECT_EQ(subLogger.getCategory(), messages[0].first.getCategory());
80 EXPECT_EQ(logger_.getCategory(), messages[0].second);
83 TEST_F(LoggerTest, formatMessage) {
84 auto expectedLine = __LINE__ + 1;
85 FB_LOGF(logger_, WARN, "num events: {:06d}, duration: {:6.3f}", 1234, 5.6789);
87 auto& messages = handler_->getMessages();
88 ASSERT_EQ(1, messages.size());
90 "num events: 001234, duration: 5.679", messages[0].first.getMessage());
91 EXPECT_EQ("LoggerTest.cpp", pathBasename(messages[0].first.getFileName()));
92 EXPECT_EQ(expectedLine, messages[0].first.getLineNumber());
93 EXPECT_EQ(LogLevel::WARN, messages[0].first.getLevel());
94 EXPECT_FALSE(messages[0].first.containsNewlines());
95 EXPECT_EQ(logger_.getCategory(), messages[0].first.getCategory());
96 EXPECT_EQ(logger_.getCategory(), messages[0].second);
99 TEST_F(LoggerTest, follyFormatError) {
100 // If we pass in a bogus format string, logf() should not throw.
101 // It should instead log a message, just complaining about the format error.
103 logger_, WARN, "param1: {:06d}, param2: {:6.3f}", 1234, "hello world!");
105 auto& messages = handler_->getMessages();
106 ASSERT_EQ(1, messages.size());
108 "error formatting log message: "
109 "invalid format argument {:6.3f}: invalid specifier 'f'; "
110 "format string: \"param1: {:06d}, param2: {:6.3f}\", "
111 "arguments: (int: 1234), (char [13]: hello world!)",
112 messages[0].first.getMessage());
113 EXPECT_EQ("LoggerTest.cpp", pathBasename(messages[0].first.getFileName()));
114 EXPECT_EQ(LogLevel::WARN, messages[0].first.getLevel());
115 EXPECT_FALSE(messages[0].first.containsNewlines());
116 EXPECT_EQ(logger_.getCategory(), messages[0].first.getCategory());
117 EXPECT_EQ(logger_.getCategory(), messages[0].second);
120 TEST_F(LoggerTest, toString) {
121 // Use the log API that calls folly::to<string>
122 auto expectedLine = __LINE__ + 1;
123 FB_LOG(logger_, DBG5, "status=", 5, " name=", "foobar");
125 auto& messages = handler_->getMessages();
126 ASSERT_EQ(1, messages.size());
127 EXPECT_EQ("status=5 name=foobar", messages[0].first.getMessage());
128 EXPECT_EQ("LoggerTest.cpp", pathBasename(messages[0].first.getFileName()));
129 EXPECT_EQ(expectedLine, messages[0].first.getLineNumber());
130 EXPECT_EQ(LogLevel::DBG5, messages[0].first.getLevel());
131 EXPECT_FALSE(messages[0].first.containsNewlines());
132 EXPECT_EQ(logger_.getCategory(), messages[0].first.getCategory());
133 EXPECT_EQ(logger_.getCategory(), messages[0].second);
136 class ToStringFailure {};
137 class FormattableButNoToString {};
139 [[noreturn]] void toAppend(
140 const ToStringFailure& /* arg */,
141 std::string* /* result */) {
142 throw std::runtime_error(
143 "error converting ToStringFailure object to a string");
148 class FormatValue<ToStringFailure> {
150 explicit FormatValue(ToStringFailure) {}
152 template <class FormatCallback>
153 void format(FormatArg& arg, FormatCallback& cb) const {
154 FormatValue<std::string>("ToStringFailure").format(arg, cb);
159 class FormatValue<FormattableButNoToString> {
161 explicit FormatValue(FormattableButNoToString) {}
163 template <class FormatCallback>
164 void format(FormatArg&, FormatCallback&) const {
165 throw std::runtime_error("test");
170 TEST_F(LoggerTest, toStringError) {
171 // Use the folly::to<string> log API, with an object that will throw
172 // an exception when we try to convert it to a string.
174 // The logging code should not throw, but should instead log a message
175 // with some detail about the failure.
177 auto expectedLine = __LINE__ + 1;
178 FB_LOG(logger_, DBG1, "status=", obj, " name=", "foobar");
180 auto& messages = handler_->getMessages();
181 ASSERT_EQ(1, messages.size());
183 "error constructing log message: "
184 "error converting ToStringFailure object to a string",
185 messages[0].first.getMessage());
186 EXPECT_EQ("LoggerTest.cpp", pathBasename(messages[0].first.getFileName()));
187 EXPECT_EQ(expectedLine, messages[0].first.getLineNumber());
188 EXPECT_EQ(LogLevel::DBG1, messages[0].first.getLevel());
189 EXPECT_FALSE(messages[0].first.containsNewlines());
190 EXPECT_EQ(logger_.getCategory(), messages[0].first.getCategory());
191 EXPECT_EQ(logger_.getCategory(), messages[0].second);
194 TEST_F(LoggerTest, formatFallbackError) {
195 // Check the behavior if logf() fails, and toAppend() also fails.
197 FB_LOGF(logger_, WARN, "param1: {}, param2: {}, {}", 1234, obj);
199 auto& messages = handler_->getMessages();
200 ASSERT_EQ(1, messages.size());
202 "error formatting log message: "
203 "invalid format argument {}: argument index out of range, max=2; "
204 "format string: \"param1: {}, param2: {}, {}\", "
205 "arguments: (int: 1234), (ToStringFailure: <error_converting_to_string>)",
206 messages[0].first.getMessage());
207 EXPECT_EQ("LoggerTest.cpp", pathBasename(messages[0].first.getFileName()));
208 EXPECT_EQ(LogLevel::WARN, messages[0].first.getLevel());
209 EXPECT_FALSE(messages[0].first.containsNewlines());
210 EXPECT_EQ(logger_.getCategory(), messages[0].first.getCategory());
211 EXPECT_EQ(logger_.getCategory(), messages[0].second);
214 TEST_F(LoggerTest, formatFallbackUnsupported) {
215 // Check the behavior if logf() fails, and toAppend() also fails.
216 FormattableButNoToString obj;
217 FB_LOGF(logger_, WARN, "param1: {}, param2: {}", 1234, obj);
219 auto& messages = handler_->getMessages();
220 ASSERT_EQ(1, messages.size());
222 "error formatting log message: "
224 "format string: \"param1: {}, param2: {}\", "
225 "arguments: (int: 1234), "
226 "(FormattableButNoToString: <no_string_conversion>)",
227 messages[0].first.getMessage());
228 EXPECT_EQ("LoggerTest.cpp", pathBasename(messages[0].first.getFileName()));
229 EXPECT_EQ(LogLevel::WARN, messages[0].first.getLevel());
230 EXPECT_FALSE(messages[0].first.containsNewlines());
231 EXPECT_EQ(logger_.getCategory(), messages[0].first.getCategory());
232 EXPECT_EQ(logger_.getCategory(), messages[0].second);
235 TEST_F(LoggerTest, streamingArgs) {
236 auto& messages = handler_->getMessages();
238 // Test with only streaming arguments
239 std::string foo = "bar";
240 FB_LOG(logger_, WARN) << "foo=" << foo << ", test=0x" << std::hex << 35;
241 ASSERT_EQ(1, messages.size());
242 EXPECT_EQ("foo=bar, test=0x23", messages[0].first.getMessage());
243 EXPECT_EQ("LoggerTest.cpp", pathBasename(messages[0].first.getFileName()));
244 EXPECT_EQ(LogLevel::WARN, messages[0].first.getLevel());
245 EXPECT_FALSE(messages[0].first.containsNewlines());
246 EXPECT_EQ(logger_.getCategory(), messages[0].first.getCategory());
247 EXPECT_EQ(logger_.getCategory(), messages[0].second);
250 // Test with both function-style and streaming arguments
251 FB_LOG(logger_, WARN, "foo=", foo) << " hello, "
253 ASSERT_EQ(1, messages.size());
254 EXPECT_EQ("foo=bar hello, world: 34", messages[0].first.getMessage());
255 EXPECT_EQ("LoggerTest.cpp", pathBasename(messages[0].first.getFileName()));
256 EXPECT_EQ(LogLevel::WARN, messages[0].first.getLevel());
257 EXPECT_FALSE(messages[0].first.containsNewlines());
258 EXPECT_EQ(logger_.getCategory(), messages[0].first.getCategory());
259 EXPECT_EQ(logger_.getCategory(), messages[0].second);
262 // Test with format-style and streaming arguments
263 FB_LOGF(logger_, WARN, "foo={}, x={}", foo, 34) << ", also " << 12;
264 ASSERT_EQ(1, messages.size());
265 EXPECT_EQ("foo=bar, x=34, also 12", messages[0].first.getMessage());
266 EXPECT_EQ("LoggerTest.cpp", pathBasename(messages[0].first.getFileName()));
267 EXPECT_EQ(LogLevel::WARN, messages[0].first.getLevel());
268 EXPECT_FALSE(messages[0].first.containsNewlines());
269 EXPECT_EQ(logger_.getCategory(), messages[0].first.getCategory());
270 EXPECT_EQ(logger_.getCategory(), messages[0].second);
274 TEST_F(LoggerTest, escapeSequences) {
275 // Escape characters (and any other unprintable characters) in the log
276 // message should be escaped when logged.
277 auto expectedLine = __LINE__ + 1;
278 FB_LOG(logger_, WARN, "hello \033[34mworld\033[0m!");
280 auto& messages = handler_->getMessages();
281 ASSERT_EQ(1, messages.size());
282 EXPECT_EQ("hello \\x1b[34mworld\\x1b[0m!", messages[0].first.getMessage());
283 EXPECT_EQ("LoggerTest.cpp", pathBasename(messages[0].first.getFileName()));
284 EXPECT_EQ(expectedLine, messages[0].first.getLineNumber());
285 EXPECT_EQ(LogLevel::WARN, messages[0].first.getLevel());
286 EXPECT_FALSE(messages[0].first.containsNewlines());
287 EXPECT_EQ(logger_.getCategory(), messages[0].first.getCategory());
288 EXPECT_EQ(logger_.getCategory(), messages[0].second);
291 TEST_F(LoggerTest, logMacros) {
292 Logger foo{&db_, "test.foo.bar"};
293 Logger foobar{&db_, "test.foo.bar"};
294 Logger footest{&db_, "test.foo.test"};
295 Logger footest1234{&db_, "test.foo.test.1234"};
296 Logger other{&db_, "test.other"};
297 db_.setLevel("test", LogLevel::ERR);
298 db_.setLevel("test.foo", LogLevel::DBG2);
299 db_.setLevel("test.foo.test", LogLevel::DBG7);
301 auto& messages = handler_->getMessages();
303 // test.other's effective level should be ERR, so a warning
304 // message to it should be discarded
305 FB_LOG(other, WARN, "this should be discarded");
306 ASSERT_EQ(0, messages.size());
308 // Disabled log messages should not evaluate their arguments
309 bool argumentEvaluated = false;
310 auto getValue = [&] {
311 argumentEvaluated = true;
314 FB_LOG(foobar, DBG3, "discarded message: ", getValue());
315 EXPECT_FALSE(argumentEvaluated);
317 FB_LOG(foobar, DBG1, "this message should pass: ", getValue());
318 ASSERT_EQ(1, messages.size());
319 EXPECT_EQ("this message should pass: 5", messages[0].first.getMessage());
320 EXPECT_TRUE(argumentEvaluated);
323 // Similar checks with FB_LOGF()
324 argumentEvaluated = false;
325 FB_LOGF(footest1234, DBG9, "failing log check: {}", getValue());
326 EXPECT_FALSE(argumentEvaluated);
328 FB_LOGF(footest1234, DBG5, "passing log: {:03}", getValue());
329 ASSERT_EQ(1, messages.size());
330 EXPECT_EQ("passing log: 005", messages[0].first.getMessage());
331 EXPECT_TRUE(argumentEvaluated);
334 // Bad format arguments should not throw
335 FB_LOGF(footest1234, ERR, "whoops: {}, {}", getValue());
336 ASSERT_EQ(1, messages.size());
338 "error formatting log message: "
339 "invalid format argument {}: argument index out of range, max=1; "
340 "format string: \"whoops: {}, {}\", "
341 "arguments: (int: 5)",
342 messages[0].first.getMessage());