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, ERROR, "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::ERROR, 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 messages[0].first.getMessage());
112 EXPECT_EQ("LoggerTest.cpp", pathBasename(messages[0].first.getFileName()));
113 EXPECT_EQ(LogLevel::WARN, messages[0].first.getLevel());
114 EXPECT_FALSE(messages[0].first.containsNewlines());
115 EXPECT_EQ(logger_.getCategory(), messages[0].first.getCategory());
116 EXPECT_EQ(logger_.getCategory(), messages[0].second);
119 TEST_F(LoggerTest, toString) {
120 // Use the log API that calls folly::to<string>
121 auto expectedLine = __LINE__ + 1;
122 FB_LOG(logger_, DBG5, "status=", 5, " name=", "foobar");
124 auto& messages = handler_->getMessages();
125 ASSERT_EQ(1, messages.size());
126 EXPECT_EQ("status=5 name=foobar", messages[0].first.getMessage());
127 EXPECT_EQ("LoggerTest.cpp", pathBasename(messages[0].first.getFileName()));
128 EXPECT_EQ(expectedLine, messages[0].first.getLineNumber());
129 EXPECT_EQ(LogLevel::DBG5, messages[0].first.getLevel());
130 EXPECT_FALSE(messages[0].first.containsNewlines());
131 EXPECT_EQ(logger_.getCategory(), messages[0].first.getCategory());
132 EXPECT_EQ(logger_.getCategory(), messages[0].second);
135 class ToStringFailure {};
137 [[noreturn]] void toAppend(
138 const ToStringFailure& /* arg */,
139 std::string* /* result */) {
140 throw std::runtime_error(
141 "error converting ToStringFailure object to a string");
144 TEST_F(LoggerTest, toStringError) {
145 // Use the folly::to<string> log API, with an object that will throw
146 // an exception when we try to convert it to a string.
148 // The logging code should not throw, but should instead log a message
149 // with some detail about the failure.
151 auto expectedLine = __LINE__ + 1;
152 FB_LOG(logger_, DBG1, "status=", obj, " name=", "foobar");
154 auto& messages = handler_->getMessages();
155 ASSERT_EQ(1, messages.size());
157 "error constructing log message: "
158 "error converting ToStringFailure object to a string",
159 messages[0].first.getMessage());
160 EXPECT_EQ("LoggerTest.cpp", pathBasename(messages[0].first.getFileName()));
161 EXPECT_EQ(expectedLine, messages[0].first.getLineNumber());
162 EXPECT_EQ(LogLevel::DBG1, messages[0].first.getLevel());
163 EXPECT_FALSE(messages[0].first.containsNewlines());
164 EXPECT_EQ(logger_.getCategory(), messages[0].first.getCategory());
165 EXPECT_EQ(logger_.getCategory(), messages[0].second);
168 TEST_F(LoggerTest, streamingArgs) {
169 auto& messages = handler_->getMessages();
171 // Test with only streaming arguments
172 std::string foo = "bar";
173 FB_LOG(logger_, WARN) << "foo=" << foo << ", test=0x" << std::hex << 35;
174 ASSERT_EQ(1, messages.size());
175 EXPECT_EQ("foo=bar, test=0x23", messages[0].first.getMessage());
176 EXPECT_EQ("LoggerTest.cpp", pathBasename(messages[0].first.getFileName()));
177 EXPECT_EQ(LogLevel::WARN, messages[0].first.getLevel());
178 EXPECT_FALSE(messages[0].first.containsNewlines());
179 EXPECT_EQ(logger_.getCategory(), messages[0].first.getCategory());
180 EXPECT_EQ(logger_.getCategory(), messages[0].second);
183 // Test with both function-style and streaming arguments
184 FB_LOG(logger_, WARN, "foo=", foo) << " hello, "
186 ASSERT_EQ(1, messages.size());
187 EXPECT_EQ("foo=bar hello, world: 34", messages[0].first.getMessage());
188 EXPECT_EQ("LoggerTest.cpp", pathBasename(messages[0].first.getFileName()));
189 EXPECT_EQ(LogLevel::WARN, messages[0].first.getLevel());
190 EXPECT_FALSE(messages[0].first.containsNewlines());
191 EXPECT_EQ(logger_.getCategory(), messages[0].first.getCategory());
192 EXPECT_EQ(logger_.getCategory(), messages[0].second);
195 // Test with format-style and streaming arguments
196 FB_LOGF(logger_, WARN, "foo={}, x={}", foo, 34) << ", also " << 12;
197 ASSERT_EQ(1, messages.size());
198 EXPECT_EQ("foo=bar, x=34, also 12", messages[0].first.getMessage());
199 EXPECT_EQ("LoggerTest.cpp", pathBasename(messages[0].first.getFileName()));
200 EXPECT_EQ(LogLevel::WARN, messages[0].first.getLevel());
201 EXPECT_FALSE(messages[0].first.containsNewlines());
202 EXPECT_EQ(logger_.getCategory(), messages[0].first.getCategory());
203 EXPECT_EQ(logger_.getCategory(), messages[0].second);
207 TEST_F(LoggerTest, escapeSequences) {
208 // Escape characters (and any other unprintable characters) in the log
209 // message should be escaped when logged.
210 auto expectedLine = __LINE__ + 1;
211 FB_LOG(logger_, WARN, "hello \033[34mworld\033[0m!");
213 auto& messages = handler_->getMessages();
214 ASSERT_EQ(1, messages.size());
215 EXPECT_EQ("hello \\x1b[34mworld\\x1b[0m!", messages[0].first.getMessage());
216 EXPECT_EQ("LoggerTest.cpp", pathBasename(messages[0].first.getFileName()));
217 EXPECT_EQ(expectedLine, messages[0].first.getLineNumber());
218 EXPECT_EQ(LogLevel::WARN, messages[0].first.getLevel());
219 EXPECT_FALSE(messages[0].first.containsNewlines());
220 EXPECT_EQ(logger_.getCategory(), messages[0].first.getCategory());
221 EXPECT_EQ(logger_.getCategory(), messages[0].second);
224 TEST_F(LoggerTest, logMacros) {
225 Logger foo{&db_, "test.foo.bar"};
226 Logger foobar{&db_, "test.foo.bar"};
227 Logger footest{&db_, "test.foo.test"};
228 Logger footest1234{&db_, "test.foo.test.1234"};
229 Logger other{&db_, "test.other"};
230 db_.setLevel("test", LogLevel::ERROR);
231 db_.setLevel("test.foo", LogLevel::DBG2);
232 db_.setLevel("test.foo.test", LogLevel::DBG7);
234 auto& messages = handler_->getMessages();
236 // test.other's effective level should be ERROR, so a warning
237 // message to it should be discarded
238 FB_LOG(other, WARN, "this should be discarded");
239 ASSERT_EQ(0, messages.size());
241 // Disabled log messages should not evaluate their arguments
242 bool argumentEvaluated = false;
243 auto getValue = [&] {
244 argumentEvaluated = true;
247 FB_LOG(foobar, DBG3, "discarded message: ", getValue());
248 EXPECT_FALSE(argumentEvaluated);
250 FB_LOG(foobar, DBG1, "this message should pass: ", getValue());
251 ASSERT_EQ(1, messages.size());
252 EXPECT_EQ("this message should pass: 5", messages[0].first.getMessage());
253 EXPECT_TRUE(argumentEvaluated);
256 // Similar checks with FB_LOGF()
257 argumentEvaluated = false;
258 FB_LOGF(footest1234, DBG9, "failing log check: {}", getValue());
259 EXPECT_FALSE(argumentEvaluated);
261 FB_LOGF(footest1234, DBG5, "passing log: {:03}", getValue());
262 ASSERT_EQ(1, messages.size());
263 EXPECT_EQ("passing log: 005", messages[0].first.getMessage());
264 EXPECT_TRUE(argumentEvaluated);
267 // Bad format arguments should not throw
268 FB_LOGF(footest1234, ERROR, "whoops: {}, {}", getValue());
269 ASSERT_EQ(1, messages.size());
271 "error formatting log message: "
272 "invalid format argument {}: argument index out of range, max=1; "
273 "format string: \"whoops: {}, {}\"",
274 messages[0].first.getMessage());