XlogHeader2.h
SOURCES
AsyncFileWriterTest.cpp
+ GlogFormatterTest.cpp
ImmediateFileWriterTest.cpp
LogCategoryTest.cpp
LoggerDBTest.cpp
experimental/JSONSchema.h \
experimental/LockFreeRingBuffer.h \
experimental/logging/AsyncFileWriter.h \
+ experimental/logging/GlogStyleFormatter.h \
experimental/logging/ImmediateFileWriter.h \
experimental/logging/LogCategory.h \
experimental/logging/LogFormatter.h \
--- /dev/null
+/*
+ * Copyright 2004-present Facebook, Inc.
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ * http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+#include <folly/experimental/logging/GlogStyleFormatter.h>
+
+#include <folly/Format.h>
+#include <folly/experimental/logging/LogLevel.h>
+#include <folly/experimental/logging/LogMessage.h>
+
+namespace {
+using folly::StringPiece;
+using folly::LogLevel;
+
+StringPiece getGlogLevelName(LogLevel level) {
+ if (level < LogLevel::INFO) {
+ return "VERBOSE";
+ } else if (level < LogLevel::WARN) {
+ return "INFO";
+ } else if (level < LogLevel::ERROR) {
+ return "WARNING";
+ } else if (level < LogLevel::CRITICAL) {
+ return "ERROR";
+ }
+ return "CRITICAL";
+}
+}
+
+namespace folly {
+
+std::string GlogStyleFormatter::formatMessage(
+ const LogMessage& message,
+ const LogCategory* /* handlerCategory */) {
+ // Get the local time info
+ struct tm ltime;
+ auto timeSinceEpoch = message.getTimestamp().time_since_epoch();
+ auto epochSeconds =
+ std::chrono::duration_cast<std::chrono::seconds>(timeSinceEpoch);
+ std::chrono::microseconds usecs =
+ std::chrono::duration_cast<std::chrono::microseconds>(timeSinceEpoch) -
+ epochSeconds;
+ time_t unixTimestamp = epochSeconds.count();
+ if (!localtime_r(&unixTimestamp, <ime)) {
+ memset(<ime, 0, sizeof(ltime));
+ }
+
+ auto basename = message.getFileBaseName();
+ auto headerFormatter = folly::format(
+ "{}{:02d}{:02d} {:02d}:{:02d}:{:02d}.{:06d} {:5d} {}:{}] ",
+ getGlogLevelName(message.getLevel())[0],
+ ltime.tm_mon + 1,
+ ltime.tm_mday,
+ ltime.tm_hour,
+ ltime.tm_min,
+ ltime.tm_sec,
+ usecs.count(),
+ message.getThreadID(),
+ basename,
+ message.getLineNumber());
+
+ // TODO: Support including thread names and thread context info.
+
+ // The fixed portion of the header takes up 31 bytes.
+ //
+ // The variable portions that we can't account for here include the line
+ // number and the thread ID (just in case it is larger than 6 digits long).
+ // Here we guess that 40 bytes will be long enough to include room for this.
+ //
+ // If this still isn't long enough the string will grow as necessary, so the
+ // code will still be correct, but just slightly less efficient than if we
+ // had allocated a large enough buffer the first time around.
+ size_t headerLengthGuess = 40 + basename.size();
+
+ // Format the data into a buffer.
+ std::string buffer;
+ StringPiece msgData{message.getMessage()};
+ if (message.containsNewlines()) {
+ // If there are multiple lines in the log message, add a header
+ // before each one.
+ std::string header;
+ header.reserve(headerLengthGuess);
+ headerFormatter.appendTo(header);
+
+ // Make a guess at how many lines will be in the message, just to make an
+ // initial buffer allocation. If the guess is too small then the string
+ // will reallocate and grow as necessary, it will just be slightly less
+ // efficient than if we had guessed enough space.
+ size_t numLinesGuess = 4;
+ buffer.reserve(((header.size() + 1) * numLinesGuess) + msgData.size());
+
+ size_t idx = 0;
+ while (true) {
+ auto end = msgData.find('\n', idx);
+ if (end == StringPiece::npos) {
+ end = msgData.size();
+ }
+
+ buffer.append(header);
+ auto line = msgData.subpiece(idx, end - idx);
+ buffer.append(line.data(), line.size());
+ buffer.push_back('\n');
+
+ if (end == msgData.size()) {
+ break;
+ }
+ idx = end + 1;
+ }
+ } else {
+ buffer.reserve(headerLengthGuess + msgData.size());
+ headerFormatter.appendTo(buffer);
+ buffer.append(msgData.data(), msgData.size());
+ buffer.push_back('\n');
+ }
+
+ return buffer;
+}
+}
--- /dev/null
+/*
+ * Copyright 2004-present Facebook, Inc.
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ * http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+#pragma once
+
+#include <folly/Range.h>
+#include <folly/experimental/logging/LogFormatter.h>
+
+namespace folly {
+
+/**
+ * A LogFormatter implementation that produces messages in a format similar to
+ * that produced by the Google logging library.
+ *
+ * The glog message format is:
+ *
+ * LmmDD HH:MM:SS.USECS THREAD [THREADNAME] (THREADCTX) FILE:LINE] MSG
+ *
+ * L: A 1-character code describing the log level (e.g., E, W, I, V)
+ * mm: 2-digit month
+ * DD: 2-digit day
+ * HH: 2-digit hour, 24-hour format
+ * MM: 2-digit minute
+ * SS: 2-digit second
+ * USECS: 6-digit microseconds
+ * THREAD: Thread ID
+ * FILE: Filename (just the last component)
+ * LINE: Line number
+ * MSG: The actual log message
+ *
+ * [THREADNAME] is the thread name, and is only included if --logthreadnames
+ * was enabled on the command line.
+ *
+ * (THREADCTX) is thread-local log context data, if it has been set. (This is
+ * a Facebook-specific modification, and is disabled unless --logthreadcontext
+ * was enabled on the command line.)
+ *
+ * Exception information and a custom log prefix may also appear after the
+ * file name and line number, before the ']' character.
+ */
+class GlogStyleFormatter : public LogFormatter {
+ public:
+ std::string formatMessage(
+ const LogMessage& message,
+ const LogCategory* handlerCategory) override;
+};
+}
libfollylogging_la_SOURCES = \
AsyncFileWriter.cpp \
+ GlogStyleFormatter.cpp \
ImmediateFileWriter.cpp \
LogCategory.cpp \
Logger.cpp \
--- /dev/null
+/*
+ * Copyright 2004-present Facebook, Inc.
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ * http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+#include <cstdlib>
+
+#include <folly/experimental/logging/GlogStyleFormatter.h>
+#include <folly/experimental/logging/LogMessage.h>
+#include <folly/experimental/logging/Logger.h>
+#include <folly/experimental/logging/LoggerDB.h>
+#include <folly/init/Init.h>
+#include <folly/portability/GTest.h>
+
+using namespace folly;
+
+namespace {
+/**
+ * Helper function to format a LogMessage using the GlogStyleFormatter.
+ *
+ * formatMsg() accepts the timestamp as a plain integer simply to reduce the
+ * verbosity of the test code.
+ *
+ * Note that in this test's main() function we set the timezone to "UTC"
+ * so that the logged time values will be consistent regardless of the actual
+ * local time on this host.
+ */
+std::string formatMsg(
+ LogLevel level,
+ StringPiece msg,
+ StringPiece filename,
+ unsigned int lineNumber,
+ // Default timestamp: 2017-04-17 13:45:56.123456 UTC
+ uint64_t timestampNS = 1492436756123456789ULL) {
+ LoggerDB db{LoggerDB::TESTING};
+ auto* category = db.getCategory("test");
+ GlogStyleFormatter formatter;
+
+ std::chrono::system_clock::time_point logTimePoint{
+ std::chrono::nanoseconds{timestampNS}};
+ LogMessage logMessage{
+ category, level, logTimePoint, filename, lineNumber, msg.str()};
+
+ return formatter.formatMessage(logMessage, category);
+}
+} // unnamed namespace
+
+TEST(GlogFormatter, log) {
+ auto tid = getOSThreadID();
+
+ // Test a very simple single-line log message
+ auto expected = folly::sformat(
+ "W0417 13:45:56.123456 {:5d} myfile.cpp:1234] hello world\n", tid);
+ EXPECT_EQ(
+ expected, formatMsg(LogLevel::WARN, "hello world", "myfile.cpp", 1234));
+}
+
+TEST(GlogFormatter, filename) {
+ auto tid = getOSThreadID();
+
+ // Make sure only the file basename gets logged
+ auto expected = folly::sformat(
+ "W0417 13:45:56.123456 {:5d} myfile.cpp:1234] hello world\n", tid);
+ EXPECT_EQ(
+ expected,
+ formatMsg(
+ LogLevel::WARN,
+ "hello world",
+ "src/test/logging/code/myfile.cpp",
+ 1234));
+
+ // Log a message with a very long file name.
+ expected = folly::sformat(
+ "W0417 13:45:56.123456 {:5d} "
+ "this_is_a_really_long_file_name_that_will_probably_exceed_"
+ "our_buffer_allocation_guess.cpp:123456789] oh noes\n",
+ tid);
+ EXPECT_EQ(
+ expected,
+ formatMsg(
+ LogLevel::WARN,
+ "oh noes",
+ "this_is_a_really_long_file_name_that_will_probably_exceed_"
+ "our_buffer_allocation_guess.cpp",
+ 123456789));
+}
+
+TEST(GlogFormatter, multiline) {
+ auto tid = getOSThreadID();
+ std::map<std::string, std::string> formatMap{
+ {"tid", folly::to<std::string>(tid)}};
+
+ // Log a multi-line message
+ auto expected = folly::svformat(
+ "V0417 13:45:56.123456 {tid:>5s} rodent.cpp:777] Eeek, a mouse!\n"
+ "V0417 13:45:56.123456 {tid:>5s} rodent.cpp:777] . .\n"
+ "V0417 13:45:56.123456 {tid:>5s} rodent.cpp:777] ( ).( )\n"
+ "V0417 13:45:56.123456 {tid:>5s} rodent.cpp:777] (o o) .-._.'\n"
+ "V0417 13:45:56.123456 {tid:>5s} rodent.cpp:777] ( - )\n"
+ "V0417 13:45:56.123456 {tid:>5s} rodent.cpp:777] mm mm\n"
+ "V0417 13:45:56.123456 {tid:>5s} rodent.cpp:777] \n"
+ "V0417 13:45:56.123456 {tid:>5s} rodent.cpp:777] =============\n",
+ formatMap);
+ EXPECT_EQ(
+ expected,
+ formatMsg(
+ LogLevel::DBG9,
+ "Eeek, a mouse!\n"
+ " . .\n"
+ " ( ).( )\n"
+ " (o o) .-._.'\n"
+ " ( - )\n"
+ " mm mm\n"
+ "\n"
+ "=============",
+ "src/rodent.cpp",
+ 777));
+}
+
+TEST(GlogFormatter, singleNewline) {
+ auto tid = getOSThreadID();
+ std::map<std::string, std::string> formatMap{
+ {"tid", folly::to<std::string>(tid)}};
+
+ // Logging a single newline is basically two empty strings.
+ auto expected = folly::svformat(
+ "V0417 13:45:56.123456 {tid:>5s} foo.txt:123] \n"
+ "V0417 13:45:56.123456 {tid:>5s} foo.txt:123] \n",
+ formatMap);
+ EXPECT_EQ(expected, formatMsg(LogLevel::DBG9, "\n", "foo.txt", 123));
+}
+
+TEST(GlogFormatter, unprintableChars) {
+ auto tid = getOSThreadID();
+
+ // Unprintable characters should be backslash escaped, as should backslashes.
+ auto expected = folly::sformat(
+ "E0417 13:45:56.123456 {:5d} escapes.cpp:97] foo\\x07bar\\x1btest\n",
+ tid);
+ EXPECT_EQ(
+ expected,
+ formatMsg(LogLevel::ERROR, "foo\abar\x1btest", "escapes.cpp", 97));
+ expected = folly::sformat(
+ "I0417 13:45:56.123456 {:5d} escapes.cpp:98] foo\\\\bar\"test\n", tid);
+ EXPECT_EQ(
+ expected, formatMsg(LogLevel::INFO, "foo\\bar\"test", "escapes.cpp", 98));
+ expected = folly::sformat(
+ "C0417 13:45:56.123456 {:5d} escapes.cpp:99] nul\\x00byte\n", tid);
+ EXPECT_EQ(
+ expected,
+ formatMsg(
+ LogLevel::CRITICAL, std::string("nul\0byte", 8), "escapes.cpp", 99));
+}
+
+int main(int argc, char* argv[]) {
+ testing::InitGoogleTest(&argc, argv);
+ folly::init(&argc, &argv);
+
+ // Some of our tests check timestamps emitted by the formatter.
+ // Set the timezone to a consistent value so that the tests are not
+ // affected by the local time of the user running the test.
+ //
+ // UTC is the only timezone that we can really rely on to work consistently.
+ // This will work even in the absence of a proper tzdata installation on the
+ // local system.
+ setenv("TZ", "UTC", 1);
+
+ return RUN_ALL_TESTS();
+}
projects / folly.git / commitdiff