Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

core(logger): add CV_LOG_ONCE_xxx() CV_LOG_IF_xxx() macros #16704

Merged
merged 2 commits into from Mar 4, 2020
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Jump to
Jump to file
Failed to load files.
Diff view
Diff view
93 changes: 84 additions & 9 deletions modules/core/include/opencv2/core/utils/logger.hpp
Expand Up @@ -57,26 +57,101 @@ CV_EXPORTS void writeLogMessage(LogLevel logLevel, const char* message);
# endif
#endif

#define CV_LOG_WITH_TAG(tag, msgLevel, extra_check0, extra_check1, msg_prefix, ...) \
for(;;) { \
extra_check0; \
if (cv::utils::logging::getLogLevel() < msgLevel) break; \
extra_check1; \
std::stringstream ss; ss msg_prefix << __VA_ARGS__; \
cv::utils::logging::internal::writeLogMessage(msgLevel, ss.str().c_str()); \
break; \
}

#define CV_LOG_FATAL(tag, ...) CV_LOG_WITH_TAG(tag, cv::utils::logging::LOG_LEVEL_FATAL, , , , __VA_ARGS__)
#define CV_LOG_ERROR(tag, ...) CV_LOG_WITH_TAG(tag, cv::utils::logging::LOG_LEVEL_ERROR, , , , __VA_ARGS__)
#define CV_LOG_WARNING(tag, ...) CV_LOG_WITH_TAG(tag, cv::utils::logging::LOG_LEVEL_WARNING, , , , __VA_ARGS__)
#define CV_LOG_INFO(tag, ...) CV_LOG_WITH_TAG(tag, cv::utils::logging::LOG_LEVEL_INFO, , , , __VA_ARGS__)
#define CV_LOG_DEBUG(tag, ...) CV_LOG_WITH_TAG(tag, cv::utils::logging::LOG_LEVEL_DEBUG, , , , __VA_ARGS__)
#define CV_LOG_VERBOSE(tag, v, ...) CV_LOG_WITH_TAG(tag, cv::utils::logging::LOG_LEVEL_VERBOSE, , , << "[VERB" << v << ":" << cv::utils::getThreadID() << "] ", __VA_ARGS__)

#define CV_LOG_FATAL(tag, ...) for(;;) { if (cv::utils::logging::getLogLevel() < cv::utils::logging::LOG_LEVEL_FATAL) break; std::stringstream ss; ss << __VA_ARGS__; cv::utils::logging::internal::writeLogMessage(cv::utils::logging::LOG_LEVEL_FATAL, ss.str().c_str()); break; }
#define CV_LOG_ERROR(tag, ...) for(;;) { if (cv::utils::logging::getLogLevel() < cv::utils::logging::LOG_LEVEL_ERROR) break; std::stringstream ss; ss << __VA_ARGS__; cv::utils::logging::internal::writeLogMessage(cv::utils::logging::LOG_LEVEL_ERROR, ss.str().c_str()); break; }
#define CV_LOG_WARNING(tag, ...) for(;;) { if (cv::utils::logging::getLogLevel() < cv::utils::logging::LOG_LEVEL_WARNING) break; std::stringstream ss; ss << __VA_ARGS__; cv::utils::logging::internal::writeLogMessage(cv::utils::logging::LOG_LEVEL_WARNING, ss.str().c_str()); break; }
#if CV_LOG_STRIP_LEVEL <= CV_LOG_LEVEL_INFO
#undef CV_LOG_INFO
#define CV_LOG_INFO(tag, ...)
#else
#define CV_LOG_INFO(tag, ...) for(;;) { if (cv::utils::logging::getLogLevel() < cv::utils::logging::LOG_LEVEL_INFO) break; std::stringstream ss; ss << __VA_ARGS__; cv::utils::logging::internal::writeLogMessage(cv::utils::logging::LOG_LEVEL_INFO, ss.str().c_str()); break; }
#endif

#if CV_LOG_STRIP_LEVEL <= CV_LOG_LEVEL_DEBUG
#undef CV_LOG_DEBUG
#define CV_LOG_DEBUG(tag, ...)
#else
#define CV_LOG_DEBUG(tag, ...) for(;;) { if (cv::utils::logging::getLogLevel() < cv::utils::logging::LOG_LEVEL_DEBUG) break; std::stringstream ss; ss << __VA_ARGS__; cv::utils::logging::internal::writeLogMessage(cv::utils::logging::LOG_LEVEL_DEBUG, ss.str().c_str()); break; }
#endif

#if CV_LOG_STRIP_LEVEL <= CV_LOG_LEVEL_VERBOSE
#undef CV_LOG_VERBOSE
#define CV_LOG_VERBOSE(tag, v, ...)
#else
#define CV_LOG_VERBOSE(tag, v, ...) for(;;) { if (cv::utils::logging::getLogLevel() < cv::utils::logging::LOG_LEVEL_VERBOSE) break; std::stringstream ss; ss << "[VERB" << v << ":" << cv::utils::getThreadID() << "] " << __VA_ARGS__; cv::utils::logging::internal::writeLogMessage(cv::utils::logging::LOG_LEVEL_VERBOSE, ss.str().c_str()); break; }
#endif

//! @cond IGNORED
#define CV__LOG_ONCE_CHECK_PRE \
static bool _cv_log_once_ ## __LINE__ = false; \
if (_cv_log_once_ ## __LINE__) break;

#define CV__LOG_ONCE_CHECK_POST \
_cv_log_once_ ## __LINE__ = true;

#define CV__LOG_IF_CHECK(logging_cond) \
if (!(logging_cond)) break;

//! @endcond


// CV_LOG_ONCE_XXX macros

#define CV_LOG_ONCE_ERROR(tag, ...) CV_LOG_WITH_TAG(tag, cv::utils::logging::LOG_LEVEL_ERROR, CV__LOG_ONCE_CHECK_PRE, CV__LOG_ONCE_CHECK_POST, , __VA_ARGS__)
#define CV_LOG_ONCE_WARNING(tag, ...) CV_LOG_WITH_TAG(tag, cv::utils::logging::LOG_LEVEL_WARNING, CV__LOG_ONCE_CHECK_PRE, CV__LOG_ONCE_CHECK_POST, , __VA_ARGS__)
#define CV_LOG_ONCE_INFO(tag, ...) CV_LOG_WITH_TAG(tag, cv::utils::logging::LOG_LEVEL_INFO, CV__LOG_ONCE_CHECK_PRE, CV__LOG_ONCE_CHECK_POST, , __VA_ARGS__)
#define CV_LOG_ONCE_DEBUG(tag, ...) CV_LOG_WITH_TAG(tag, cv::utils::logging::LOG_LEVEL_DEBUG, CV__LOG_ONCE_CHECK_PRE, CV__LOG_ONCE_CHECK_POST, , __VA_ARGS__)
#define CV_LOG_ONCE_VERBOSE(tag, v, ...) CV_LOG_WITH_TAG(tag, cv::utils::logging::LOG_LEVEL_VERBOSE, CV__LOG_ONCE_CHECK_PRE, CV__LOG_ONCE_CHECK_POST, << "[VERB" << v << ":" << cv::utils::getThreadID() << "] ", __VA_ARGS__)

#if CV_LOG_STRIP_LEVEL <= CV_LOG_LEVEL_INFO
#undef CV_LOG_ONCE_INFO
#define CV_LOG_ONCE_INFO(tag, ...)
#endif

#if CV_LOG_STRIP_LEVEL <= CV_LOG_LEVEL_DEBUG
#undef CV_LOG_ONCE_DEBUG
#define CV_LOG_ONCE_DEBUG(tag, ...)
#endif

#if CV_LOG_STRIP_LEVEL <= CV_LOG_LEVEL_VERBOSE
#undef CV_LOG_ONCE_VERBOSE
#define CV_LOG_ONCE_VERBOSE(tag, v, ...)
#endif


// CV_LOG_IF_XXX macros

#define CV_LOG_IF_FATAL(tag, logging_cond, ...) CV_LOG_WITH_TAG(tag, cv::utils::logging::LOG_LEVEL_FATAL, , CV__LOG_IF_CHECK(logging_cond), , __VA_ARGS__)
#define CV_LOG_IF_ERROR(tag, logging_cond, ...) CV_LOG_WITH_TAG(tag, cv::utils::logging::LOG_LEVEL_ERROR, , CV__LOG_IF_CHECK(logging_cond), , __VA_ARGS__)
#define CV_LOG_IF_WARNING(tag, logging_cond, ...) CV_LOG_WITH_TAG(tag, cv::utils::logging::LOG_LEVEL_WARNING, , CV__LOG_IF_CHECK(logging_cond), , __VA_ARGS__)
#define CV_LOG_IF_INFO(tag, logging_cond, ...) CV_LOG_WITH_TAG(tag, cv::utils::logging::LOG_LEVEL_INFO, , CV__LOG_IF_CHECK(logging_cond), , __VA_ARGS__)
#define CV_LOG_IF_DEBUG(tag, logging_cond, ...) CV_LOG_WITH_TAG(tag, cv::utils::logging::LOG_LEVEL_DEBUG, , CV__LOG_IF_CHECK(logging_cond), , __VA_ARGS__)
#define CV_LOG_IF_VERBOSE(tag, v, logging_cond, ...) CV_LOG_WITH_TAG(tag, cv::utils::logging::LOG_LEVEL_VERBOSE, , CV__LOG_IF_CHECK(logging_cond), << "[VERB" << v << ":" << cv::utils::getThreadID() << "] ", __VA_ARGS__)

#if CV_LOG_STRIP_LEVEL <= CV_LOG_LEVEL_INFO
#undef CV_LOG_IF_INFO
#define CV_LOG_IF_INFO(tag, logging_cond, ...)
#endif

#if CV_LOG_STRIP_LEVEL <= CV_LOG_LEVEL_DEBUG
#undef CV_LOG_IF_DEBUG
#define CV_LOG_IF_DEBUG(tag, logging_cond, ...)
#endif

#if CV_LOG_STRIP_LEVEL <= CV_LOG_LEVEL_VERBOSE
#undef CV_LOG_IF_VERBOSE
#define CV_LOG_IF_VERBOSE(tag, v, logging_cond, ...)
#endif


//! @}

}}} // namespace
Expand Down
4 changes: 2 additions & 2 deletions modules/core/src/logger.cpp
Expand Up @@ -83,8 +83,8 @@ void writeLogMessage(LogLevel logLevel, const char* message)
case LOG_LEVEL_INFO: ss << "[ INFO:" << threadID << "] " << message << std::endl; break;
case LOG_LEVEL_DEBUG: ss << "[DEBUG:" << threadID << "] " << message << std::endl; break;
case LOG_LEVEL_VERBOSE: ss << message << std::endl; break;
default:
return;
case LOG_LEVEL_SILENT: return; // avoid compiler warning about incomplete switch
case ENUM_LOG_LEVEL_FORCE_INT: return; // avoid compiler warning about incomplete switch
}
#ifdef __ANDROID__
int android_logLevel = ANDROID_LOG_INFO;
Expand Down
50 changes: 50 additions & 0 deletions modules/core/test/test_utils.cpp
Expand Up @@ -2,6 +2,9 @@
// It is subject to the license terms in the LICENSE file found in the top-level directory
// of this distribution and at http://opencv.org/license.html.
#include "test_precomp.hpp"
#include "opencv2/core/utils/logger.defines.hpp"
#undef CV_LOG_STRIP_LEVEL
#define CV_LOG_STRIP_LEVEL CV_LOG_LEVEL_VERBOSE + 1
#include "opencv2/core/utils/logger.hpp"
#include "opencv2/core/utils/buffer_area.private.hpp"

Expand Down Expand Up @@ -287,6 +290,53 @@ TEST(CommandLineParser, testScalar)
EXPECT_EQ(parser.get<Scalar>("s5"), Scalar(5, -4, 3, 2));
}


TEST(Logger, DISABLED_message)
{
int id = 42;
CV_LOG_VERBOSE(NULL, 0, "Verbose message: " << id);
CV_LOG_VERBOSE(NULL, 1, "Verbose message: " << id);
CV_LOG_DEBUG(NULL, "Debug message: " << id);
CV_LOG_INFO(NULL, "Info message: " << id);
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Google Test framework has 2 helper function to capture output: testing::internal::CaptureStdout and testing::internal::CaptureStderr. I would like to suggest to use the following pattern to check that message actually was logged:

    testing::internal::CaptureStdout();
    CV_LOG_INFO(NULL, "Info message: " << id);
    EXPECT_TRUE(testing::internal::GetCapturedStdout().find_first_of("Info message: 42") != std::string::npos);

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thank you for the suggestion.

Actually I want to keep these tests as disabled for now - check compilation only (and run them in manual mode if we have corresponding changes).

CV_LOG_WARNING(NULL, "Warning message: " << id);
CV_LOG_ERROR(NULL, "Error message: " << id);
CV_LOG_FATAL(NULL, "Fatal message: " << id);
}

static int testLoggerMessageOnce(int id)
{
CV_LOG_ONCE_VERBOSE(NULL, 0, "Verbose message: " << id++);
CV_LOG_ONCE_VERBOSE(NULL, 1, "Verbose message: " << id++);
CV_LOG_ONCE_DEBUG(NULL, "Debug message: " << id++);
CV_LOG_ONCE_INFO(NULL, "Info message: " << id++);
CV_LOG_ONCE_WARNING(NULL, "Warning message: " << id++);
CV_LOG_ONCE_ERROR(NULL, "Error message: " << id++);
// doesn't make sense: CV_LOG_ONCE_FATAL
return id;
}
TEST(Logger, DISABLED_message_once)
{
int check_id_first = testLoggerMessageOnce(42);
EXPECT_GT(check_id_first, 42);
int check_id_second = testLoggerMessageOnce(0);
EXPECT_EQ(0, check_id_second);
}

TEST(Logger, DISABLED_message_if)
{
for (int i = 0; i < 100; i++)
{
CV_LOG_IF_VERBOSE(NULL, 0, i == 0 || i == 42, "Verbose message: " << i);
CV_LOG_IF_VERBOSE(NULL, 1, i == 0 || i == 42, "Verbose message: " << i);
CV_LOG_IF_DEBUG(NULL, i == 0 || i == 42, "Debug message: " << i);
CV_LOG_IF_INFO(NULL, i == 0 || i == 42, "Info message: " << i);
CV_LOG_IF_WARNING(NULL, i == 0 || i == 42, "Warning message: " << i);
CV_LOG_IF_ERROR(NULL, i == 0 || i == 42, "Error message: " << i);
CV_LOG_IF_FATAL(NULL, i == 0 || i == 42, "Fatal message: " << i);
}
}


TEST(Samples, findFile)
{
cv::utils::logging::LogLevel prev = cv::utils::logging::setLogLevel(cv::utils::logging::LOG_LEVEL_VERBOSE);
Expand Down