Skip to content

Commit

Permalink
[logging] Introduced log modules and categories selection
Browse files Browse the repository at this point in the history
Currently it is possible to disable some part of logs based on
their level, but not on their origin module (region). After
introducing specific log modules selection it would be
convenient to make controlling those modules log categories
possible as well.

Summary of changes:
* Added definitions for every existing log module that are by
default set to 1, but can be ovewritten to 0.
* Introduced IsModuleCategoryEnabled macro that returns
category state (0/1) for specific log module.
* To avoid creating dozens of new definitions for every
module-category combination, IsModuleCategoryEnabled macro
by default returns corresponding global category value
(CHIP_DETAIL/PROGRESS/ERROR/AUTOMATION_LOGGING). If any
category value was defined for specific module, it is used
instead of global one.
* Added filtering based on the mentioned definitions, so
ChipInternalLog and ChipInternalLogByteSpan has definitions
provided only if corresponding origin module is enabled and the
specific category for this module is enabled.
* Disabled some modules for nrfconnect platform that saved ~10,5k
of flash.
  • Loading branch information
kkasperczyk-no committed Dec 22, 2022
1 parent 8055d86 commit 44473e2
Show file tree
Hide file tree
Showing 33 changed files with 360 additions and 119 deletions.
2 changes: 1 addition & 1 deletion examples/common/pigweed/RpcService.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -115,7 +115,7 @@ void Start(void (*RegisterServices)(pw::rpc::Server &), ::chip::rpc::Mutex * uar
// Declare a buffer for decoding incoming HDLC frames.
std::array<std::byte, kMaxTransmissionUnit> input_buffer;

Logging::Log(Logging::kLogModule_NotSpecified, Logging::kLogCategory_Detail, "Starting pw_rpc server");
Logging::Log(Logging::kLogModule_NotSpecified, Logging::kLogCategory_DETAIL, "Starting pw_rpc server");
pw::hdlc::ReadAndProcessPackets(server, input_buffer);
}

Expand Down
2 changes: 1 addition & 1 deletion examples/platform/openiotsdk/app/openiotsdk_platform.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -145,7 +145,7 @@ int openiotsdk_chip_init(void)
CHIP_ERROR err;

#if NDEBUG
chip::Logging::SetLogFilter(chip::Logging::LogCategory::kLogCategory_Progress);
chip::Logging::SetLogFilter(chip::Logging::LogCategory::kLogCategory_PROGRESS);
#endif

err = MemoryInit();
Expand Down
4 changes: 2 additions & 2 deletions src/app/util/ember-print.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -37,7 +37,7 @@ void emberAfPrint(int category, const char * format, ...)
{
va_list args;
va_start(args, format);
chip::Logging::LogV(chip::Logging::kLogModule_Zcl, chip::Logging::kLogCategory_Progress, format, args);
chip::Logging::LogV(chip::Logging::kLogModule_Zcl, chip::Logging::kLogCategory_PROGRESS, format, args);
va_end(args);
}
}
Expand All @@ -49,7 +49,7 @@ void emberAfPrintln(int category, const char * format, ...)
{
va_list args;
va_start(args, format);
chip::Logging::LogV(chip::Logging::kLogModule_Zcl, chip::Logging::kLogCategory_Progress, format, args);
chip::Logging::LogV(chip::Logging::kLogModule_Zcl, chip::Logging::kLogCategory_PROGRESS, format, args);
va_end(args);
}
}
Expand Down
8 changes: 4 additions & 4 deletions src/app/util/ember-print.h
Original file line number Diff line number Diff line change
Expand Up @@ -25,7 +25,7 @@

/**
* @brief Prints a log message
* @param category - Currently ignored as zcl categories do not map to chip categories. Defaults to kLogCategory_Progress
* @param category - Currently ignored as zcl categories do not map to chip categories. Defaults to kLogCategory_PROGRESS
* @param format - Format string to print
*/
#if CHIP_PROGRESS_LOGGING
Expand All @@ -36,7 +36,7 @@ void emberAfPrint(int category, const char * format, ...) ENFORCE_FORMAT(2, 3);

/**
* @brief Prints a log followed by new line line
* @param category - Currently ignored as zcl categories do not map to chip categories. Defaults to kLogCategory_Progress
* @param category - Currently ignored as zcl categories do not map to chip categories. Defaults to kLogCategory_PROGRESS
* @param format - Format string to print
*/
#if CHIP_PW_TOKENIZER_LOGGING
Expand All @@ -49,7 +49,7 @@ void emberAfPrintln(int category, const char * format, ...) ENFORCE_FORMAT(2, 3)

/**
* @brief Prints a buffer
* @param category - Currently ignored as zcl categories do not map to chip categories. Defaults to kLogCategory_Progress.
* @param category - Currently ignored as zcl categories do not map to chip categories. Defaults to kLogCategory_PROGRESS.
* @param buffer - Buffer to print.
* @param length - Length of buffer
* @param withSpace - Pass in true if a space should be printed between each byte.
Expand All @@ -62,7 +62,7 @@ void emberAfPrintBuffer(int category, const uint8_t * buffer, uint16_t length, b

/**
* @brief Prints a strings
* @param category - Currently ignored as zcl categories do not map to chip categories. Defaults to kLogCategory_Progress.
* @param category - Currently ignored as zcl categories do not map to chip categories. Defaults to kLogCategory_PROGRESS.
* @param string - Buffer to print as a string
*/
#if CHIP_PROGRESS_LOGGING
Expand Down
12 changes: 6 additions & 6 deletions src/controller/ExamplePersistentStorage.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -37,7 +37,7 @@ constexpr const char kPortKey[] = "ListenPort";
constexpr const char kLoggingKey[] = "LoggingLevel";
constexpr const char kLocalNodeIdKey[] = "LocalNodeId";
constexpr const char kCommissionerCATsKey[] = "CommissionerCATs";
constexpr LogCategory kDefaultLoggingLevel = kLogCategory_Automation;
constexpr LogCategory kDefaultLoggingLevel = kLogCategory_AUTOMATION;

std::string GetFilename(const char * name)
{
Expand Down Expand Up @@ -231,23 +231,23 @@ LogCategory PersistentStorage::GetLoggingLevel()
{
if (strcasecmp(value, "none") == 0)
{
chipLogLevel = kLogCategory_None;
chipLogLevel = kLogCategory_NONE;
}
else if (strcasecmp(value, "error") == 0)
{
chipLogLevel = kLogCategory_Error;
chipLogLevel = kLogCategory_ERROR;
}
else if (strcasecmp(value, "progress") == 0)
{
chipLogLevel = kLogCategory_Progress;
chipLogLevel = kLogCategory_PROGRESS;
}
else if (strcasecmp(value, "detail") == 0)
{
chipLogLevel = kLogCategory_Detail;
chipLogLevel = kLogCategory_DETAIL;
}
else if (strcasecmp(value, "automation") == 0)
{
chipLogLevel = kLogCategory_Automation;
chipLogLevel = kLogCategory_AUTOMATION;
}
}

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -332,7 +332,7 @@ uint8_t pychip_DeviceController_GetLogFilter()
#if _CHIP_USE_LOGGING
return chip::Logging::GetLogFilter();
#else
return chip::Logging::kLogCategory_None;
return chip::Logging::kLogCategory_NONE;
#endif
}

Expand Down
2 changes: 1 addition & 1 deletion src/darwin/Framework/CHIP/MTRFramework.mm
Original file line number Diff line number Diff line change
Expand Up @@ -33,6 +33,6 @@ void MTRFrameworkInit()

// Suppress CHIP logging until we actually need it for redirection
// (see MTRSetLogCallback()). Logging to os_log is always enabled.
chip::Logging::SetLogFilter(chip::Logging::kLogCategory_None);
chip::Logging::SetLogFilter(chip::Logging::kLogCategory_NONE);
});
}
10 changes: 5 additions & 5 deletions src/darwin/Framework/CHIP/MTRLogging.mm
Original file line number Diff line number Diff line change
Expand Up @@ -26,9 +26,9 @@

using namespace chip::Logging;

static_assert(MTRLogTypeError == (NSInteger) kLogCategory_Error, "MTRLogType* != kLogCategory_*");
static_assert(MTRLogTypeProgress == (NSInteger) kLogCategory_Progress, "MTRLogType* != kLogCategory_*");
static_assert(MTRLogTypeDetail == (NSInteger) kLogCategory_Detail, "MTRLogType* != kLogCategory_*");
static_assert(MTRLogTypeError == (NSInteger) kLogCategory_ERROR, "MTRLogType* != kLogCategory_*");
static_assert(MTRLogTypeProgress == (NSInteger) kLogCategory_PROGRESS, "MTRLogType* != kLogCategory_*");
static_assert(MTRLogTypeDetail == (NSInteger) kLogCategory_DETAIL, "MTRLogType* != kLogCategory_*");

static os_unfair_lock logCallbackLock = OS_UNFAIR_LOCK_INIT;
static MTRLogCallback logCallback = nil;
Expand All @@ -48,7 +48,7 @@ static void MTRLogCallbackTrampoline(const char * moduleName, uint8_t category,
NSString * message = [[NSString alloc] initWithFormat:@(format) arguments:args];
#pragma clang diagnostic pop

auto type = std::min(static_cast<MTRLogType>(category), MTRLogTypeDetail); // hide kLogCategory_Automation
auto type = std::min(static_cast<MTRLogType>(category), MTRLogTypeDetail); // hide kLogCategory_AUTOMATION
callback(type, @(moduleName), message);
}

Expand All @@ -63,7 +63,7 @@ void MTRSetLogCallback(MTRLogType logTypeThreshold, MTRLogCallback _Nullable cal
logCallback = callback;
} else {
logCallback = nil;
SetLogFilter(kLogCategory_None);
SetLogFilter(kLogCategory_NONE);
SetLogRedirectCallback(nullptr);
}
os_unfair_lock_unlock(&logCallbackLock);
Expand Down
8 changes: 4 additions & 4 deletions src/lib/core/CHIPConfig.h
Original file line number Diff line number Diff line change
Expand Up @@ -331,7 +331,7 @@
*
* @brief
* If asserted (1), enable logging of all messages in the
* chip::Logging::LogCategory::kLogCategory_Error category.
* chip::Logging::LogCategory::kLogCategory_ERROR category.
*
*/
#ifndef CHIP_ERROR_LOGGING
Expand All @@ -343,7 +343,7 @@
*
* @brief
* If asserted (1), enable logging of all messages in the
* chip::Logging::LogCategory::kLogCategory_Progress category.
* chip::Logging::LogCategory::kLogCategory_PROGRESS category.
*
*/
#ifndef CHIP_PROGRESS_LOGGING
Expand All @@ -355,7 +355,7 @@
*
* @brief
* If asserted (1), enable logging of all messages in the
* chip::Logging::kLogCategory_Detail category.
* chip::Logging::kLogCategory_DETAIL category.
*
*/
#ifndef CHIP_DETAIL_LOGGING
Expand All @@ -367,7 +367,7 @@
*
* @brief
* If asserted (1), enable logging of all messages in the
* chip::Logging::kLogCategory_Automation category.
* chip::Logging::kLogCategory_AUTOMATION category.
*
*/
#ifndef CHIP_AUTOMATION_LOGGING
Expand Down
6 changes: 3 additions & 3 deletions src/lib/support/logging/CHIPLogging.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -181,7 +181,7 @@ void LogByteSpan(uint8_t module, uint8_t category, const chip::ByteSpan & span)
}
else
{
Log(module, chip::Logging::kLogCategory_Error, "Failed to print ByteSpan buffer");
Log(module, chip::Logging::kLogCategory_ERROR, "Failed to print ByteSpan buffer");
return;
}
}
Expand All @@ -206,7 +206,7 @@ void LogV(uint8_t module, uint8_t category, const char * msg, va_list args)
}

#if CHIP_LOG_FILTERING
uint8_t gLogFilter = kLogCategory_Max;
uint8_t gLogFilter = kLogCategory_MAX;

uint8_t GetLogFilter()
{
Expand All @@ -222,7 +222,7 @@ void SetLogFilter(uint8_t category)

uint8_t GetLogFilter()
{
return kLogCategory_Max;
return kLogCategory_MAX;
}

void SetLogFilter(uint8_t category)
Expand Down
69 changes: 62 additions & 7 deletions src/lib/support/logging/CHIPLogging.h
Original file line number Diff line number Diff line change
Expand Up @@ -100,7 +100,7 @@ DLL_EXPORT void SetLogFilter(uint8_t category);
* category.
*
*/
#define ChipLogError(MOD, MSG, ...) ChipInternalLog(MOD, Error, MSG, ##__VA_ARGS__)
#define ChipLogError(MOD, MSG, ...) ChipInternalLog(MOD, ERROR, MSG, ##__VA_ARGS__)
#else // CHIP_ERROR_LOGGING
#define ChipLogError(MOD, MSG, ...) ((void) 0)
#endif // CHIP_ERROR_LOGGING
Expand All @@ -114,7 +114,7 @@ DLL_EXPORT void SetLogFilter(uint8_t category);
* category.
*
*/
#define ChipLogProgress(MOD, MSG, ...) ChipInternalLog(MOD, Progress, MSG, ##__VA_ARGS__)
#define ChipLogProgress(MOD, MSG, ...) ChipInternalLog(MOD, PROGRESS, MSG, ##__VA_ARGS__)
#else // CHIP_PROGRESS_LOGGING
#define ChipLogProgress(MOD, MSG, ...) ((void) 0)
#endif // CHIP_PROGRESS_LOGGING
Expand All @@ -128,7 +128,7 @@ DLL_EXPORT void SetLogFilter(uint8_t category);
* category.
*
*/
#define ChipLogDetail(MOD, MSG, ...) ChipInternalLog(MOD, Detail, MSG, ##__VA_ARGS__)
#define ChipLogDetail(MOD, MSG, ...) ChipInternalLog(MOD, DETAIL, MSG, ##__VA_ARGS__)

/**
* @def ChipLogByteSpan(MOD, DATA)
Expand All @@ -137,7 +137,7 @@ DLL_EXPORT void SetLogFilter(uint8_t category);
* Log a byte span for the specified module in the 'Detail' category.
*
*/
#define ChipLogByteSpan(MOD, DATA) ChipInternalLogByteSpan(MOD, Detail, DATA)
#define ChipLogByteSpan(MOD, DATA) ChipInternalLogByteSpan(MOD, DETAIL, DATA)
#else // CHP_DETAIL_LOGGING
#define ChipLogDetail(MOD, MSG, ...) ((void) 0)
#define ChipLogByteSpan(MOD, DATA) ((void) 0)
Expand All @@ -152,7 +152,7 @@ DLL_EXPORT void SetLogFilter(uint8_t category);
* category.
*
*/
#define ChipLogAutomation(MSG, ...) ChipInternalLog(Automation, Automation, MSG, ##__VA_ARGS__)
#define ChipLogAutomation(MSG, ...) ChipInternalLog(Automation, AUTOMATION, MSG, ##__VA_ARGS__)
#else // CHIP_AUTOMATION_LOGGING
#define ChipLogAutomation(MOD, MSG, ...) ((void) 0)
#endif // CHIP_AUTOMATION_LOGGING
Expand Down Expand Up @@ -346,6 +346,52 @@ DLL_LOCAL inline bool IsCategoryEnabled(uint8_t category)
}
#endif // CHIP_LOG_FILTERING

/*
* CHIP Logging Modules Categories filtering implementation.
*
* @brief
* Macro for use to check if given category is enabled for given log module.
*
* Example Usage:
* Let's assume PROGRESS category control for DeviceLayer log module.
*
* Default behavior - category is not modified, so macro returns global category value:
* IsModuleCategoryEnabled(DeviceLayer, PROGRESS) returns CHIP_PROGRESS_LOGGING
*
* Enabling category - category is enabled for module, ignoring global category value:
* #define CHIP_CONFIG_LOG_MODULE_DeviceLayer_PROGRESS 1
* IsModuleCategoryEnabled(DeviceLayer, PROGRESS) returns 1
*
* Disabling category - category is disabled for module, ignoring global category value:
* #define CHIP_CONFIG_LOG_MODULE_DeviceLayer_PROGRESS 0
* IsModuleCategoryEnabled(DeviceLayer, PROGRESS) returns 0
*
* Algorithm flow:
* 1. IsModuleCategoryEnabled(MOD, CAT) uses MOD and CAT to create strings for category module macro and global category macro,
* and invokes _IsModuleCategoryEnabled1().
* 2. _IsModuleCategoryEnabled1(MOD_CAT, GLOB_CAT) invokes _IsModuleCategoryEnabled2(MOD_CAT, GLOB_CAT) to extract macros
* values.
* 3. _IsModuleCategoryEnabled2(MOD_CAT, GLOB_CAT) uses MOD_CAT to create string for helper macro.
* - If MOD_CAT is 0 the helper macro containing two dummy args is used.
* - If MOD_CAT is 1 the helper macro containing one dummy arg is used.
* - If MOD_CAT doesn't exist, empty is used.
* 4. _IsModuleCategoryEnabled3(DUMMY_ARG, GLOB_CAT) invokes _IsModuleCategoryEnabled4() using different number of arguments
* depending on DUMMY_ARG.
* 5. _IsModuleCategoryEnabled4 output:
* - If category for module was not defined, the DUMMY_ARG was empty, so returning ARG3 is GLOB_CAT.
* - If category for module was defined 1, the DUMMY_ARG had one argument, so returning ARG3 is 1.
* - If category for module was defined 0, the DUMMY_ARG had two arguments, so returning ARG3 is 2.
*
*/
#define IsModuleCategoryEnabled(MOD, CAT) _IsModuleCategoryEnabled1(CHIP_CONFIG_LOG_MODULE_##MOD##_##CAT, CHIP_##CAT##_LOGGING)
#define _IsModuleCategoryEnabled1(MOD_CAT, GLOB_CAT) _IsModuleCategoryEnabled2(MOD_CAT, GLOB_CAT)
#define _IsModuleCategoryEnabled2(MOD_CAT, GLOB_CAT) \
_IsModuleCategoryEnabled3(_IsModuleCategoryEnabled3_DummyArg##MOD_CAT, GLOB_CAT)
#define _IsModuleCategoryEnabled3_DummyArg0 dummyArg1, dummyArg2,
#define _IsModuleCategoryEnabled3_DummyArg1 dummyArg1,
#define _IsModuleCategoryEnabled3(DUMMY_ARG, GLOB_CAT) _IsModuleCategoryEnabled4(DUMMY_ARG 0, 1, GLOB_CAT)
#define _IsModuleCategoryEnabled4(ARG1, ARG2, ARG3, ...) (ARG3)

DLL_LOCAL void Log(uint8_t module, uint8_t category, const char * msg, ...) ENFORCE_FORMAT(3, 4);
DLL_LOCAL void LogByteSpan(uint8_t module, uint8_t category, const ByteSpan & span);
DLL_LOCAL void LogV(uint8_t module, uint8_t category, const char * msg, va_list args) ENFORCE_FORMAT(3, 0);
Expand All @@ -360,8 +406,17 @@ DLL_LOCAL void LogV(uint8_t module, uint8_t category, const char * msg, va_list
#define ChipInternalLog(...) ChipPlatformLog(__VA_ARGS__)
#define ChipInternalLogByteSpan(...) ChipPlatformLogByteSpan(__VA_ARGS__)
#else // CHIP_SYSTEM_CONFIG_PLATFORM_LOG
#define ChipInternalLog(MOD, CAT, MSG, ...) ChipInternalLogImpl(MOD, CAT, MSG, ##__VA_ARGS__)
#define ChipInternalLogByteSpan(MOD, CAT, DATA) ChipInternalLogByteSpanImpl(MOD, CAT, DATA)
#define ChipInternalLog(MOD, CAT, MSG, ...) \
if (CHIP_CONFIG_LOG_MODULE_##MOD && IsModuleCategoryEnabled(MOD, CAT)) \
{ \
ChipInternalLogImpl(MOD, CAT, MSG, ##__VA_ARGS__); \
}

#define ChipInternalLogByteSpan(MOD, CAT, DATA) \
if (CHIP_CONFIG_LOG_MODULE_##MOD && IsModuleCategoryEnabled(MOD, CAT)) \
{ \
ChipInternalLogByteSpanImpl(MOD, CAT, DATA); \
}
#endif // CHIP_SYSTEM_CONFIG_PLATFORM_LOG

#if CHIP_PW_TOKENIZER_LOGGING
Expand Down
Loading

0 comments on commit 44473e2

Please sign in to comment.