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.
18 #include <folly/experimental/logging/GlogStyleFormatter.h>
19 #include <folly/experimental/logging/LogMessage.h>
20 #include <folly/experimental/logging/Logger.h>
21 #include <folly/experimental/logging/LoggerDB.h>
22 #include <folly/init/Init.h>
23 #include <folly/portability/GTest.h>
25 using namespace folly;
29 * Helper function to format a LogMessage using the GlogStyleFormatter.
31 * formatMsg() accepts the timestamp as a plain integer simply to reduce the
32 * verbosity of the test code.
34 * Note that in this test's main() function we set the timezone to "UTC"
35 * so that the logged time values will be consistent regardless of the actual
36 * local time on this host.
38 std::string formatMsg(
42 unsigned int lineNumber,
43 // Default timestamp: 2017-04-17 13:45:56.123456 UTC
44 uint64_t timestampNS = 1492436756123456789ULL) {
45 LoggerDB db{LoggerDB::TESTING};
46 auto* category = db.getCategory("test");
47 GlogStyleFormatter formatter;
49 std::chrono::system_clock::time_point logTimePoint{
50 std::chrono::nanoseconds{timestampNS}};
51 LogMessage logMessage{
52 category, level, logTimePoint, filename, lineNumber, msg.str()};
54 return formatter.formatMessage(logMessage, category);
56 } // unnamed namespace
58 TEST(GlogFormatter, log) {
59 auto tid = getOSThreadID();
61 // Test a very simple single-line log message
62 auto expected = folly::sformat(
63 "W0417 13:45:56.123456 {:5d} myfile.cpp:1234] hello world\n", tid);
65 expected, formatMsg(LogLevel::WARN, "hello world", "myfile.cpp", 1234));
68 TEST(GlogFormatter, filename) {
69 auto tid = getOSThreadID();
71 // Make sure only the file basename gets logged
72 auto expected = folly::sformat(
73 "W0417 13:45:56.123456 {:5d} myfile.cpp:1234] hello world\n", tid);
79 "src/test/logging/code/myfile.cpp",
82 // Log a message with a very long file name.
83 expected = folly::sformat(
84 "W0417 13:45:56.123456 {:5d} "
85 "this_is_a_really_long_file_name_that_will_probably_exceed_"
86 "our_buffer_allocation_guess.cpp:123456789] oh noes\n",
93 "this_is_a_really_long_file_name_that_will_probably_exceed_"
94 "our_buffer_allocation_guess.cpp",
98 TEST(GlogFormatter, multiline) {
99 auto tid = getOSThreadID();
100 std::map<std::string, std::string> formatMap{
101 {"tid", folly::to<std::string>(tid)}};
103 // Log a multi-line message
104 auto expected = folly::svformat(
105 "V0417 13:45:56.123456 {tid:>5s} rodent.cpp:777] Eeek, a mouse!\n"
106 "V0417 13:45:56.123456 {tid:>5s} rodent.cpp:777] . .\n"
107 "V0417 13:45:56.123456 {tid:>5s} rodent.cpp:777] ( ).( )\n"
108 "V0417 13:45:56.123456 {tid:>5s} rodent.cpp:777] (o o) .-._.'\n"
109 "V0417 13:45:56.123456 {tid:>5s} rodent.cpp:777] ( - )\n"
110 "V0417 13:45:56.123456 {tid:>5s} rodent.cpp:777] mm mm\n"
111 "V0417 13:45:56.123456 {tid:>5s} rodent.cpp:777] \n"
112 "V0417 13:45:56.123456 {tid:>5s} rodent.cpp:777] =============\n",
130 TEST(GlogFormatter, singleNewline) {
131 auto tid = getOSThreadID();
132 std::map<std::string, std::string> formatMap{
133 {"tid", folly::to<std::string>(tid)}};
135 // Logging a single newline is basically two empty strings.
136 auto expected = folly::svformat(
137 "V0417 13:45:56.123456 {tid:>5s} foo.txt:123] \n"
138 "V0417 13:45:56.123456 {tid:>5s} foo.txt:123] \n",
140 EXPECT_EQ(expected, formatMsg(LogLevel::DBG9, "\n", "foo.txt", 123));
143 TEST(GlogFormatter, unprintableChars) {
144 auto tid = getOSThreadID();
146 // Unprintable characters should be backslash escaped, as should backslashes.
147 auto expected = folly::sformat(
148 "E0417 13:45:56.123456 {:5d} escapes.cpp:97] foo\\x07bar\\x1btest\n",
152 formatMsg(LogLevel::ERR, "foo\abar\x1btest", "escapes.cpp", 97));
153 expected = folly::sformat(
154 "I0417 13:45:56.123456 {:5d} escapes.cpp:98] foo\\\\bar\"test\n", tid);
156 expected, formatMsg(LogLevel::INFO, "foo\\bar\"test", "escapes.cpp", 98));
157 expected = folly::sformat(
158 "C0417 13:45:56.123456 {:5d} escapes.cpp:99] nul\\x00byte\n", tid);
162 LogLevel::CRITICAL, std::string("nul\0byte", 8), "escapes.cpp", 99));
165 int main(int argc, char* argv[]) {
166 testing::InitGoogleTest(&argc, argv);
167 folly::init(&argc, &argv);
169 // Some of our tests check timestamps emitted by the formatter.
170 // Set the timezone to a consistent value so that the tests are not
171 // affected by the local time of the user running the test.
173 // UTC is the only timezone that we can really rely on to work consistently.
174 // This will work even in the absence of a proper tzdata installation on the
176 setenv("TZ", "UTC", 1);
178 return RUN_ALL_TESTS();