CustomLogFormatterTest.cpp File Reference

#include <cstdlib>
#include <folly/init/Init.h>
#include <folly/logging/CustomLogFormatter.h>
#include <folly/logging/LogMessage.h>
#include <folly/logging/Logger.h>
#include <folly/logging/LoggerDB.h>
#include <folly/portability/GTest.h>
#include <folly/portability/Stdlib.h>

Go to the source code of this file.

Functions
	TEST (CustomLogFormatter, log)
	TEST (CustomLogFormatter, filename)
	TEST (CustomLogFormatter, functionName)
	TEST (CustomLogFormatter, multiline)
	TEST (CustomLogFormatter, singleNewline)
	TEST (CustomLogFormatter, coloring)
	TEST (CustomLogFormatter, unprintableChars)
	TEST (CustomLogFormatter, invalidFormatStrings)
	TEST (CustomLogFormatter, validFormatStringsEdgeCases)
int	main (int argc, char *argv[])

Function Documentation

int main	(	int	argc,
		char *	argv[]
	)

Definition at line 380 of file CustomLogFormatterTest.cpp.

References folly::init(), testing::InitGoogleTest(), and RUN_ALL_TESTS().

                                 {
  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();
}

TEST	(	CustomLogFormatter	,
		log
	)

Definition at line 77 of file CustomLogFormatterTest.cpp.

References EXPECT_EQ, folly::getOSThreadID(), folly::sformat(), and folly::WARN.

                              {
  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(
          kGlogFormatString,
          LogLevel::WARN,
          "hello world",
          "myfile.cpp",
          "testFunction",
          1234));
}

TEST	(	CustomLogFormatter	,
		filename
	)

Definition at line 94 of file CustomLogFormatterTest.cpp.

References EXPECT_EQ, folly::getOSThreadID(), folly::sformat(), and folly::WARN.

                                   {
  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(
          kGlogFormatString,
          LogLevel::WARN,
          "hello world",
          "src/test/logging/code/myfile.cpp",
          "testFunction",
          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(
          kGlogFormatString,
          LogLevel::WARN,
          "oh noes",
          "this_is_a_really_long_file_name_that_will_probably_exceed_"
          "our_buffer_allocation_guess.cpp",
          "testFunction",
          123456789));
}

TEST	(	CustomLogFormatter	,
		functionName
	)

Definition at line 128 of file CustomLogFormatterTest.cpp.

References EXPECT_EQ, folly::getOSThreadID(), folly::sformat(), and folly::WARN.

                                       {
  auto tid = getOSThreadID();

  // Make sure the function name gets logged
  auto expected = folly::sformat(
      "W0417 13:45:56.123456 {:5d} myfile.cpp:1234 testFunction()] "
      "hello world\n",
      tid);
  EXPECT_EQ(
      expected,
      formatMsg(
          kGlogFormatStringWithFunctionName,
          LogLevel::WARN,
          "hello world",
          "src/test/logging/code/myfile.cpp",
          "testFunction",
          1234));
}

TEST	(	CustomLogFormatter	,
		multiline
	)

Definition at line 147 of file CustomLogFormatterTest.cpp.

References folly::DBG9, EXPECT_EQ, folly::getOSThreadID(), and folly::svformat().

                                    {
  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(
          kGlogFormatString,
          LogLevel::DBG9,
          "Eeek, a mouse!\n"
          "   .   .\n"
          "  ( ).( )\n"
          "   (o o) .-._.'\n"
          "  (  -  )\n"
          "   mm mm\n"
          "\n"
          "=============",
          "src/rodent.cpp",
          "testFunction",
          777));
}

TEST	(	CustomLogFormatter	,
		singleNewline
	)

Definition at line 181 of file CustomLogFormatterTest.cpp.

References folly::DBG9, EXPECT_EQ, folly::getOSThreadID(), and folly::svformat().

                                        {
  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(
          kGlogFormatString,
          LogLevel::DBG9,
          "\n",
          "foo.txt",
          "testFunction",
          123));
}

TEST	(	CustomLogFormatter	,
		coloring
	)

Definition at line 202 of file CustomLogFormatterTest.cpp.

References folly::CRITICAL, folly::DBG9, folly::ERR, EXPECT_EQ, folly::FATAL, folly::getOSThreadID(), folly::INFO, folly::svformat(), and folly::WARN.

                                   {
  auto tid = getOSThreadID();
  std::map<std::string, std::string> formatMap{
      {"tid", folly::to<std::string>(tid)}};

  { // Logging a DBG9 message should log in grey color (\033[1;30m) and should
    // call reset color at the end of the message (\033[0m)
    auto expected = folly::svformat(
        "\033[1;30mV0417 13:45:56.123456 {tid:>5s} foo.txt:123] DBG9\033[0m\n",
        formatMap);
    EXPECT_EQ(
        expected,
        formatMsg(
            kGlogFormatString,
            LogLevel::DBG9,
            "DBG9",
            "foo.txt",
            "testFunction",
            123,
            true));
  }
  { // Logging an INFO message when coloring enabled is displayed as regular
    // message. i.e. no color or reset sequence
    auto expected = folly::svformat(
        "I0417 13:45:56.123456 {tid:>5s} foo.txt:123] INFO\n", formatMap);
    EXPECT_EQ(
        expected,
        formatMsg(
            kGlogFormatString,
            LogLevel::INFO,
            "INFO",
            "foo.txt",
            "testFunction",
            123,
            true));
  }
  { // Logging a WARN message should log in yellow color (\033[33m) and should
    // call reset color at the end of the message (\033[0m)
    auto expected = folly::svformat(
        "\033[33mW0417 13:45:56.123456 {tid:>5s} foo.txt:123] WARN\033[0m\n",
        formatMap);
    EXPECT_EQ(
        expected,
        formatMsg(
            kGlogFormatString,
            LogLevel::WARN,
            "WARN",
            "foo.txt",
            "testFunction",
            123,
            true));
  }
  { // Logging a ERR message should log in red color (\033[31m) and should
    // call reset color at the end of the message (\033[0m)
    auto expected = folly::svformat(
        "\033[31mE0417 13:45:56.123456 {tid:>5s} foo.txt:123] ERR\033[0m\n",
        formatMap);
    EXPECT_EQ(
        expected,
        formatMsg(
            kGlogFormatString,
            LogLevel::ERR,
            "ERR",
            "foo.txt",
            "testFunction",
            123,
            true));
  }
  { // Logging a CRITICAL message should log bold in red background (\033[1;41m)
    // and should call reset color at the end of the message (\033[0m)
    auto expected = folly::svformat(
        "\033[1;41mC0417 13:45:56.123456 {tid:>5s} foo.txt:123] "
        "CRITICAL\033[0m\n",
        formatMap);
    EXPECT_EQ(
        expected,
        formatMsg(
            kGlogFormatString,
            LogLevel::CRITICAL,
            "CRITICAL",
            "foo.txt",
            "testFunction",
            123,
            true));
  }
  { // Logging a FATAL message should log bold in red background (\033[1;41m)
    // and should call reset color at the end of the message (\033[0m)
    auto expected = folly::svformat(
        "\033[1;41mF0417 13:45:56.123456 {tid:>5s} foo.txt:123] "
        "FATAL\033[0m\n",
        formatMap);
    EXPECT_EQ(
        expected,
        formatMsg(
            kGlogFormatString,
            LogLevel::FATAL,
            "FATAL",
            "foo.txt",
            "testFunction",
            123,
            true));
  }
}

TEST	(	CustomLogFormatter	,
		unprintableChars
	)

Definition at line 306 of file CustomLogFormatterTest.cpp.

References folly::CRITICAL, folly::ERR, EXPECT_EQ, folly::getOSThreadID(), folly::INFO, folly::sformat(), and string.

                                           {
  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(
          kGlogFormatString,
          LogLevel::ERR,
          "foo\abar\x1btest",
          "escapes.cpp",
          "testFunction",
          97));
  expected = folly::sformat(
      "I0417 13:45:56.123456 {:5d} escapes.cpp:98] foo\\\\bar\"test\n", tid);
  EXPECT_EQ(
      expected,
      formatMsg(
          kGlogFormatString,
          LogLevel::INFO,
          "foo\\bar\"test",
          "escapes.cpp",
          "testFunction",
          98));
  expected = folly::sformat(
      "C0417 13:45:56.123456 {:5d} escapes.cpp:99] nul\\x00byte\n", tid);
  EXPECT_EQ(
      expected,
      formatMsg(
          kGlogFormatString,
          LogLevel::CRITICAL,
          std::string("nul\0byte", 8),
          "escapes.cpp",
          "testFunction",
          99));
}

TEST	(	CustomLogFormatter	,
		invalidFormatStrings
	)

Definition at line 346 of file CustomLogFormatterTest.cpp.

References EXPECT_THROW.

                                               {
  EXPECT_THROW(CustomLogFormatter("{", false), std::runtime_error);
  EXPECT_THROW(CustomLogFormatter("{}", false), std::runtime_error);
  EXPECT_THROW(CustomLogFormatter("{0}", false), std::runtime_error);
  EXPECT_THROW(CustomLogFormatter("{WRONG}", false), std::runtime_error);
  EXPECT_THROW(CustomLogFormatter("{L} {FORMAT}", false), std::runtime_error);
  EXPECT_THROW(CustomLogFormatter("{L}{m:1} {KEY}", false), std::runtime_error);
  EXPECT_THROW(CustomLogFormatter("{L", false), std::runtime_error);
}

TEST	(	CustomLogFormatter	,
		validFormatStringsEdgeCases
	)

Definition at line 356 of file CustomLogFormatterTest.cpp.

References folly::ERR, EXPECT_EQ, and folly::INFO.

                                                      {
  EXPECT_EQ("msg\n", formatMsg("", LogLevel::INFO, "msg", "file", "fun", 99));
  EXPECT_EQ(
      "I msg\n", formatMsg("{L}", LogLevel::INFO, "msg", "file", "fun", 99));
  EXPECT_EQ(
      "{L} msg\n",
      formatMsg("{{L}}", LogLevel::INFO, "msg", "file", "fun", 99));
  EXPECT_EQ(
      "E:099 msg\n",
      formatMsg("{L}:{LINE:03}", LogLevel::ERR, "msg", "file", "fun", 99));
  EXPECT_EQ(
      "{L}:099 msg\n",
      formatMsg("{{L}}:{LINE:03}", LogLevel::ERR, "msg", "file", "fun", 99));
  EXPECT_EQ(
      "E:099{ msg\n",
      formatMsg("{L}:{LINE:03}{{", LogLevel::ERR, "msg", "file", "fun", 99));
  EXPECT_EQ(
      "E:099} msg\n",
      formatMsg("{L}:{LINE:03}}}", LogLevel::ERR, "msg", "file", "fun", 99));
  EXPECT_EQ(
      "{E} msg\n",
      formatMsg("{{{L}}}", LogLevel::ERR, "msg", "file", "fun", 99));
}