nux-1.14.0
test_logger.cpp
00001 #include "NuxCore/Logger.h"
00002 #include "NuxCore/LoggingWriter.h"
00003 
00004 #include <cstdlib>
00005 
00006 #include <gtest/gtest.h>
00007 #include <gmock/gmock.h>
00008 
00009 
00010 using namespace nux::logging;
00011 using namespace testing;
00012 
00013 namespace nux {
00014 namespace logging {
00015 // Declare the hidden function so we can call it.
00016 void reset_logging();
00017 }
00018 }
00019 
00020 
00021 namespace {
00022 
00023 TEST(TestLogger, TestSimpleConstruction) {
00024   Logger logger("");
00025   EXPECT_EQ(logger.module(), "");
00026   EXPECT_TRUE(logger.IsErrorEnabled());
00027   EXPECT_TRUE(logger.IsWarningEnabled());
00028   EXPECT_FALSE(logger.IsInfoEnabled());
00029   EXPECT_FALSE(logger.IsDebugEnabled());
00030 }
00031 
00032 TEST(TestLogger, TestModuleName) {
00033   Logger logger("nux.logging");
00034   EXPECT_EQ(logger.module(), "nux.logging");
00035 }
00036 
00037 TEST(TestLogger, TestSetLevel) {
00038   Logger logger("testing");
00039   EXPECT_EQ(logger.GetLogLevel(), Level::NotSpecified);
00040   EXPECT_EQ(logger.GetEffectiveLogLevel(), Level::Warning);
00041   EXPECT_TRUE(logger.IsErrorEnabled());
00042   EXPECT_TRUE(logger.IsWarningEnabled());
00043   EXPECT_FALSE(logger.IsInfoEnabled());
00044   EXPECT_FALSE(logger.IsDebugEnabled());
00045   logger.SetLogLevel(Level::Debug);
00046   EXPECT_EQ(logger.GetLogLevel(), Level::Debug);
00047   EXPECT_EQ(logger.GetEffectiveLogLevel(), Level::Debug);
00048   EXPECT_TRUE(logger.IsErrorEnabled());
00049   EXPECT_TRUE(logger.IsWarningEnabled());
00050   EXPECT_TRUE(logger.IsInfoEnabled());
00051   EXPECT_TRUE(logger.IsDebugEnabled());
00052   logger.SetLogLevel(Level::Info);
00053   EXPECT_EQ(logger.GetLogLevel(), Level::Info);
00054   EXPECT_EQ(logger.GetEffectiveLogLevel(), Level::Info);
00055   EXPECT_TRUE(logger.IsErrorEnabled());
00056   EXPECT_TRUE(logger.IsWarningEnabled());
00057   EXPECT_TRUE(logger.IsInfoEnabled());
00058   EXPECT_FALSE(logger.IsDebugEnabled());
00059   logger.SetLogLevel(Level::Warning);
00060   EXPECT_EQ(logger.GetLogLevel(), Level::Warning);
00061   EXPECT_EQ(logger.GetEffectiveLogLevel(), Level::Warning);
00062   EXPECT_TRUE(logger.IsErrorEnabled());
00063   EXPECT_TRUE(logger.IsWarningEnabled());
00064   EXPECT_FALSE(logger.IsInfoEnabled());
00065   EXPECT_FALSE(logger.IsDebugEnabled());
00066   logger.SetLogLevel(Level::Error);
00067   EXPECT_EQ(logger.GetLogLevel(), Level::Error);
00068   EXPECT_EQ(logger.GetEffectiveLogLevel(), Level::Error);
00069   EXPECT_TRUE(logger.IsErrorEnabled());
00070   EXPECT_FALSE(logger.IsWarningEnabled());
00071   EXPECT_FALSE(logger.IsInfoEnabled());
00072   EXPECT_FALSE(logger.IsDebugEnabled());
00073   logger.SetLogLevel(Level::NotSpecified);
00074   EXPECT_EQ(logger.GetLogLevel(), Level::NotSpecified);
00075   EXPECT_EQ(logger.GetEffectiveLogLevel(), Level::Warning);
00076 }
00077 
00078 TEST(TestLogger, TestLevelsSharedForSameModule) {
00079   Logger logger1("testing.module");
00080   Logger logger2("testing.module");
00081 
00082   logger1.SetLogLevel(Level::Info);
00083   EXPECT_TRUE(logger1.IsInfoEnabled());
00084   EXPECT_TRUE(logger2.IsInfoEnabled());
00085 }
00086 
00087 TEST(TestLogger, TestModuleLowered) {
00088   Logger logger1("TESTING.MODULE");
00089   Logger logger2("Testing");
00090 
00091   EXPECT_THAT(logger1.module(), Eq("testing.module"));
00092   EXPECT_THAT(logger2.module(), Eq("testing"));
00093 }
00094 
00095 TEST(TestLogger, TestLevelsInherited) {
00096   Logger root("");
00097   Logger first("first");
00098   Logger second("first.second");
00099 
00100   root.SetLogLevel(Level::Error);
00101   EXPECT_EQ(root.GetLogLevel(), Level::Error);
00102   EXPECT_EQ(root.GetEffectiveLogLevel(), Level::Error);
00103   EXPECT_EQ(first.GetLogLevel(), Level::NotSpecified);
00104   EXPECT_EQ(first.GetEffectiveLogLevel(), Level::Error);
00105   EXPECT_EQ(second.GetLogLevel(), Level::NotSpecified);
00106   EXPECT_EQ(second.GetEffectiveLogLevel(), Level::Error);
00107 
00108   first.SetLogLevel(Level::Debug);
00109   EXPECT_EQ(root.GetLogLevel(), Level::Error);
00110   EXPECT_EQ(root.GetEffectiveLogLevel(), Level::Error);
00111   EXPECT_EQ(first.GetLogLevel(), Level::Debug);
00112   EXPECT_EQ(first.GetEffectiveLogLevel(), Level::Debug);
00113   EXPECT_EQ(second.GetLogLevel(), Level::NotSpecified);
00114   EXPECT_EQ(second.GetEffectiveLogLevel(), Level::Debug);
00115 
00116   second.SetLogLevel(Level::Info);
00117   EXPECT_EQ(root.GetLogLevel(), Level::Error);
00118   EXPECT_EQ(root.GetEffectiveLogLevel(), Level::Error);
00119   EXPECT_EQ(first.GetLogLevel(), Level::Debug);
00120   EXPECT_EQ(first.GetEffectiveLogLevel(), Level::Debug);
00121   EXPECT_EQ(second.GetLogLevel(), Level::Info);
00122   EXPECT_EQ(second.GetEffectiveLogLevel(), Level::Info);
00123 
00124   first.SetLogLevel(Level::NotSpecified);
00125   EXPECT_EQ(root.GetLogLevel(), Level::Error);
00126   EXPECT_EQ(root.GetEffectiveLogLevel(), Level::Error);
00127   EXPECT_EQ(first.GetLogLevel(), Level::NotSpecified);
00128   EXPECT_EQ(first.GetEffectiveLogLevel(), Level::Error);
00129   EXPECT_EQ(second.GetLogLevel(), Level::Info);
00130   EXPECT_EQ(second.GetEffectiveLogLevel(), Level::Info);
00131 }
00132 
00133 class UseTimezone
00134 {
00135 public:
00136   UseTimezone(std::string const& tz)
00137     {
00138       char* old_tz = ::getenv("TZ");
00139       if (old_tz) {
00140         // std::strings don't like beeing assigned NULL
00141         old_tz_ = old_tz;
00142       }
00143       ::setenv("TZ", tz.c_str(), true);
00144       ::tzset();
00145     }
00146 
00147   ~UseTimezone()
00148     {
00149       if (old_tz_.empty()) {
00150         ::unsetenv("TZ");
00151       }
00152       else {
00153         ::setenv("TZ", old_tz_.c_str(), true);
00154       }
00155       ::tzset();
00156     }
00157 private:
00158   std::string old_tz_;
00159 };
00160 
00161 TEST(TestLoggingWriter, TestWriteMessage) {
00162   std::stringstream out;
00163   Writer& writer = Writer::Instance();
00164   writer.SetOutputStream(out);
00165 
00166   // set a known timezone
00167   UseTimezone timezone(":Antarctica/Vostok");
00168   // This time is known to be: 2010-09-10 12:34:45 (UTC+12)
00169   std::time_t when = 1284078885;
00170   writer.WriteMessage(Level::Error, "test.module", "testfile.cpp",
00171                       1234, when, "my message");
00172   std::string result = out.str();
00173   // Vostok is UTC+6
00174   EXPECT_THAT(result, Eq("ERROR 2010-09-10 06:34:45 test.module testfile.cpp:1234 my message\n"));
00175 }
00176 
00177 TEST(TestLogStream, TestSimpleConstruction) {
00178   // First test is to make sure a LogStream can be constructed and destructed.
00179   LogStream test(Level::Debug, "module", "filename", 42);
00180 }
00181 
00182 TEST(TestLogStream, TestOutput) {
00183   // First test is to make sure a LogStream can be constructed and destructed.
00184   std::stringstream out;
00185   Writer::Instance().SetOutputStream(out);
00186 
00187   LogStream test(Level::Debug, "module", "filename", 42);
00188   test << "testing message" << std::flush;
00189 
00190   std::string result = out.str();
00191 
00192   EXPECT_THAT(result, StartsWith("DEBUG"));
00193   EXPECT_THAT(result, HasSubstr("module filename:42"));
00194   EXPECT_THAT(result, EndsWith("testing message\n"));
00195 }
00196 
00197 TEST(TestLogStream, TestShortenedFilename) {
00198   // Filenames only show the last path segment.
00199   std::stringstream out;
00200   Writer::Instance().SetOutputStream(out);
00201 
00202   LogStream test(Level::Debug, "module", "/some/absolute/filename", 42);
00203   test << "testing message" << std::flush;
00204 
00205   std::string result = out.str();
00206 
00207   EXPECT_THAT(result, HasSubstr("module filename:42"));
00208 }
00209 
00210 TEST(TestLogStream, TestTemporary) {
00211   // First test is to make sure a LogStream can be constructed and destructed.
00212   std::stringstream out;
00213   Writer::Instance().SetOutputStream(out);
00214 
00215   LogStream(Level::Debug, "module", "filename", 42).stream() << "testing message";
00216 
00217   std::string result = out.str();
00218 
00219   EXPECT_THAT(result, StartsWith("DEBUG"));
00220   EXPECT_THAT(result, HasSubstr(" module filename:42"));
00221   EXPECT_THAT(result, EndsWith("testing message\n"));
00222 }
00223 
00224 TEST(TestLogStream, TestDebugMacro) {
00225   // First test is to make sure a LogStream can be constructed and destructed.
00226   std::stringstream out;
00227   Writer::Instance().SetOutputStream(out);
00228   int counter = 0;
00229 
00230   Logger logger("test.module");
00231 
00232   LOG_DEBUG(logger) << ++counter << "Not output, as not debug.";
00233 
00234   logger.SetLogLevel(Level::Debug);
00235 
00236   LOG_DEBUG(logger) << ++counter << " Is output now.";
00237 
00238   std::string result = out.str();
00239 
00240   EXPECT_THAT(result, StartsWith("DEBUG"));
00241   EXPECT_THAT(result, HasSubstr(" test.module test_logger.cpp"));
00242   EXPECT_THAT(result, EndsWith("1 Is output now.\n"));
00243   // Also only one line.
00244   EXPECT_THAT(counter, Eq(1));
00245 }
00246 
00247 TEST(TestLogStream, TestBlockTracer) {
00248   std::stringstream out;
00249   Writer::Instance().SetOutputStream(out);
00250 
00251   Logger logger("test");
00252   logger.SetLogLevel(Level::Debug);
00253   {
00254     BlockTracer tracer(logger, Level::Debug, "func_name", "file_name", 42);
00255   }
00256 
00257   std::string result = out.str();
00258 
00259   EXPECT_THAT(result, MatchesRegex("DEBUG .+ test file_name:42 \\+func_name\n"
00260                                    "DEBUG .+ test file_name:42 -func_name\n"));
00261 }
00262 
00263 
00264 TEST(TestLogHelpers, TestGetLoggingLevel) {
00265   EXPECT_THAT(get_logging_level("trace"), Eq(Level::Trace));
00266   EXPECT_THAT(get_logging_level("TrAce"), Eq(Level::Trace));
00267   EXPECT_THAT(get_logging_level("TRACE"), Eq(Level::Trace));
00268   EXPECT_THAT(get_logging_level("debug"), Eq(Level::Debug));
00269   EXPECT_THAT(get_logging_level("DEBUG"), Eq(Level::Debug));
00270   EXPECT_THAT(get_logging_level("info"), Eq(Level::Info));
00271   EXPECT_THAT(get_logging_level("INFO"), Eq(Level::Info));
00272   EXPECT_THAT(get_logging_level("warn"), Eq(Level::Warning));
00273   EXPECT_THAT(get_logging_level("WARN"), Eq(Level::Warning));
00274   EXPECT_THAT(get_logging_level("warning"), Eq(Level::Warning));
00275   EXPECT_THAT(get_logging_level("WARNING"), Eq(Level::Warning));
00276   EXPECT_THAT(get_logging_level("error"), Eq(Level::Error));
00277   EXPECT_THAT(get_logging_level("ERROR"), Eq(Level::Error));
00278   // Unknown levels result in WARNING
00279   EXPECT_THAT(get_logging_level("critical"), Eq(Level::Warning));
00280   EXPECT_THAT(get_logging_level("not_specified"), Eq(Level::Warning));
00281   EXPECT_THAT(get_logging_level("other"), Eq(Level::Warning));
00282 }
00283 
00284 TEST(TestLogHelpers, TestResetLogging) {
00285   // First set root and another.
00286   Logger("").SetLogLevel(Level::Debug);
00287   Logger("test.module").SetLogLevel(Level::Info);
00288 
00289   reset_logging();
00290 
00291   std::string levels = dump_logging_levels();
00292 
00293   EXPECT_THAT(levels, Eq("<root> WARNING"));
00294 }
00295 
00296 
00297 TEST(TestLogHelpers, TestConfigureLoggingNull) {
00298 
00299   reset_logging();
00300   Logger("").SetLogLevel(Level::Debug);
00301   Logger("test.module").SetLogLevel(Level::Info);
00302   // Configure passed a null pointer does nothing.
00303   configure_logging(NULL);
00304   std::string levels = dump_logging_levels();
00305 
00306   EXPECT_THAT(levels, Eq("<root> DEBUG\n"
00307                          "test.module INFO"));
00308 }
00309 
00310 TEST(TestLogHelpers, TestConfigureLoggingRoot) {
00311   reset_logging();
00312   configure_logging("<root>=debug");
00313   std::string levels = dump_logging_levels();
00314   EXPECT_THAT(levels, Eq("<root> DEBUG"));
00315 }
00316 
00317 TEST(TestLogHelpers, TestConfigureLoggingSingleModule) {
00318   reset_logging();
00319   configure_logging("test.module=debug");
00320   std::string levels = dump_logging_levels();
00321   EXPECT_THAT(levels, Eq("<root> WARNING\n"
00322                          "test.module DEBUG"));
00323 }
00324 
00325 TEST(TestLogHelpers, TestConfigureLoggingMultipleModules) {
00326   reset_logging();
00327   configure_logging("module=info;sub.module=debug;other.module=warning");
00328   std::string levels = dump_logging_levels();
00329   EXPECT_THAT(levels, Eq("<root> WARNING\n"
00330                          "module INFO\n"
00331                          "other.module WARNING\n"
00332                          "sub.module DEBUG"));
00333 }
00334 
00335 } // anon namespace
 All Classes Namespaces Functions Variables Typedefs Enumerations Enumerator Friends