Back to index

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