2

I am using spdlog and gtest in my library. I need to save some logs (not gtest logs) from test execution to files. Here is code for creating loggers:

void createLogger() {
    auto debug_logger = spdlog::rotating_logger_mt("debug_logger", "logs/test_debug", 1024 * 1024 * 25, 3);
    debug_logger->set_level(spdlog::level::debug);
    auto logger = spdlog::rotating_logger_mt("logger", "logs/test_info", 1024 * 1024 * 5, 2);
}

It works fine in example program with my library. When I run tests debug_logger saves everything in files but logger saves nothing. When I remove 

debug_logger->set_level(spdlog::level::debug);

debug_logger is not working too. So I thought that it's problem with loggers but when I add

logger->set_level(spdlog::level::info);

it is still not working.

Here is main for tests:

int main(int argc, char **argv) {
    try {
        utility::createLogger();
        ::testing::InitGoogleTest(&argc, argv);
        return RUN_ALL_TESTS();
     } catch (const spdlog::spdlog_ex& ex) {
         std::cout << "Log initialization failed: " << ex.what() << std::endl;
     }
}

Setup and one of test cases:

class CPUTest: public ::testing::Test {

protected:

std::shared_ptr<spdlog::logger> logger;

void SetUp() {
    spdlog::get("logger")->info("test get");
    logger = spdlog::get("logger");
}
};

TEST_F(CPUTest, Resolve15) {
    logger->info("Something from info logger");
    // ...
}

debug_logger with level debug saves info logs too but logger with debug not.

Do you have any clue what is wrong with tests and loggers initialization in my code? Should I use two loggers in my library or one with two files?

wpater
  • 393
  • 3
  • 14
  • In your first example have you tried `logger->set_level(spdlog::level::debug);` instead of `logger->set_level(spdlog::level::info);` to get `logger` working? Debug is a more granular level than info. – James Beilby Mar 13 '18 at 15:13
  • Yes, I have tried it - it's not working too. It's very strange - maybe gtest initialize test classes in some specific order... – wpater Mar 13 '18 at 15:18

2 Answers2

1

There is no need to have two separate loggers. This will just complicate your logic. You should have one logger, for which you will set the granularity level depending on the build type. Something like this:

#ifdef RELEASE
logger->set_level(spdlog::level::info);
#else
logger->set_level(spdlog::level::debug);
#endif

This way, when you build in release mode, the logger will only log info messages, while in release mode it will log both info and debug.

The fact that your debug logger saves info logs too is nothing strange. Almost all logging libraries take this approach. They have different logging granularity levels. For example: info, warning, debug and verbose. Then when you set the level to warning, only warning and info will be logged, while if you select for example verbose, then all types will be logged.

EDIT:

If you really need to split the logs by type into different files, you can write a simple script to do this using your preferred scripting language. I assume the logs from this library are tagged with their type. You can use that to parse the output file and extract the logs of certain type into a separate file. This is quite easy to do. Having two loggers only complicates things, and incurs a performance penalty which is important if your test suite becomes big.

marc_s
  • 732,580
  • 175
  • 1,330
  • 1,459
Marko Popovic
  • 3,999
  • 3
  • 22
  • 37
  • Yes, you are right but how to (in case with one logger) set up sinks for info level and debug level for one logger? I think it is impossible without implementing custom logger. – wpater Mar 13 '18 at 15:59
  • @Nequeq Can you please explain what do you mean by "set up sinks"? BTW, this is not mentioned in your question ... – Marko Popovic Mar 13 '18 at 16:13
  • [Sinks](https://github.com/gabime/spdlog/wiki/4.-Sinks) are used in spdlog for writing logs to files. I have created two loggers with two different files because I need to save debug to one file and info to different - it is in code in question. I didn't find example which shows how to separete logs by level to two sinks and that's why I created two loggers. – wpater Mar 13 '18 at 16:20
1

Due to very long execution of my tests I was killing process. debug logs were saved always in both files, info logs not. It was caused by flush policy in spdlog (debug level is more important and it was flushed very often - I suppose that almost after each call).

info logs are flushed after all tests (not after each test case or each test class). That's why my files were always empty (I killed process).

It is possible to change flush policy for logger by

logger->flush_on(spdlog::level::info);
wpater
  • 393
  • 3
  • 14