nux-1.14.0
|
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