hcq/MaxScale
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

Check log priority before logging

Browse Source 
With this change, whether something should be logged or, that is,
whether the used log priority is enabled or not, is checked before
the logging function is called. That should save a few cycles.

Now mxs_log_message() always logs a message, without consideration
for whether the priority is enabled or not. The inline function
mxs_log_is_priority_enabled() returns true if a particular priority
is enabled and the MXS_LOG_MESSAGE() macro (that MXS_ERROR etc. are
expanded into) call that before calling the actual logging function.
This commit is contained in:
Johan Wikman
2016-10-24 13:01:11 +03:00
parent bd4542139c
commit 1a2e0ba3ee
2 changed files with 107 additions and 101 deletions
Download Patch File Download Diff File Expand all files Collapse all files

11
include/maxscale/log_manager.h
View File

@ -15,6 +15,7 @@
*/ */
#include <maxscale/cdefs.h> #include <maxscale/cdefs.h>
#include <assert.h>
#include <stdbool.h> #include <stdbool.h>
#include <syslog.h> #include <syslog.h>
#include <unistd.h> #include <unistd.h>
@ -111,6 +112,12 @@ void mxs_log_set_throttling(const MXS_LOG_THROTTLING* throttling);
void mxs_log_get_throttling(MXS_LOG_THROTTLING* throttling); void mxs_log_get_throttling(MXS_LOG_THROTTLING* throttling);
static inline bool mxs_log_priority_is_enabled(int priority)
{
assert((priority & ~LOG_PRIMASK) == 0);
return MXS_LOG_PRIORITY_IS_ENABLED(priority);
}
int mxs_log_message(int priority, int mxs_log_message(int priority,
const char* modname, const char* modname,
const char* file, int line, const char* function, const char* file, int line, const char* function,
@ -126,7 +133,9 @@ int mxs_log_message(int priority,
* MXS_ERROR, MXS_WARNING, etc. macros instead. * MXS_ERROR, MXS_WARNING, etc. macros instead.
*/ */
#define MXS_LOG_MESSAGE(priority, format, ...)\ #define MXS_LOG_MESSAGE(priority, format, ...)\
mxs_log_message(priority, MXS_MODULE_NAME, __FILE__, __LINE__, __func__, format, ##__VA_ARGS__) (mxs_log_priority_is_enabled(priority) ? \
mxs_log_message(priority, MXS_MODULE_NAME, __FILE__, __LINE__, __func__, format, ##__VA_ARGS__) :\
0)
/** /**
* Log an alert, error, warning, notice, info, or debug message. * Log an alert, error, warning, notice, info, or debug message.

197
server/core/log_manager.cc
View File

@ -2913,131 +2913,128 @@ int mxs_log_message(int priority,
if ((priority & ~LOG_PRIMASK) == 0) // Check that the priority is ok, if ((priority & ~LOG_PRIMASK) == 0) // Check that the priority is ok,
{ {
if (MXS_LOG_PRIORITY_IS_ENABLED(priority)) message_suppression_t status = MESSAGE_NOT_SUPPRESSED;
{
message_suppression_t status = MESSAGE_NOT_SUPPRESSED;
// We only throttle errors and warnings. Info and debug messages // We only throttle errors and warnings. Info and debug messages
// are never on during normal operation, so if they are enabled, // are never on during normal operation, so if they are enabled,
// we are presumably debugging something. Notice messages are // we are presumably debugging something. Notice messages are
// assumed to be logged for a reason and always in a context where // assumed to be logged for a reason and always in a context where
// flooding cannot be caused. // flooding cannot be caused.
if ((priority == LOG_ERR) || (priority == LOG_WARNING)) if ((priority == LOG_ERR) || (priority == LOG_WARNING))
{
status = message_status(file, line);
}
if (status != MESSAGE_STILL_SUPPRESSED)
{
va_list valist;
int modname_len = modname ? strlen(modname) + 3 : 0; // +3 due to "[...] "
static const char SUPPRESSION[] =
" (subsequent similar messages suppressed for %lu milliseconds)";
int suppression_len = 0;
size_t suppress_ms = log_config.throttling.suppress_ms;
if (status == MESSAGE_SUPPRESSED)
{ {
status = message_status(file, line); suppression_len += sizeof(SUPPRESSION) - 1; // Remove trailing NULL
suppression_len -= 3; // Remove the %lu
suppression_len += UINTLEN(suppress_ms);
} }
if (status != MESSAGE_STILL_SUPPRESSED) /**
* Find out the length of log string (to be formatted str).
*/
va_start(valist, format);
int message_len = vsnprintf(NULL, 0, format, valist);
va_end(valist);
if (message_len >= 0)
{ {
va_list valist; log_prefix_t prefix = priority_to_prefix(priority);
int modname_len = modname ? strlen(modname) + 3 : 0; // +3 due to "[...] " static const char FORMAT_FUNCTION[] = "(%s): ";
static const char SUPPRESSION[] = // Other thread might change log_config.augmentation.
" (subsequent similar messages suppressed for %lu milliseconds)"; int augmentation = log_config.augmentation;
int suppression_len = 0; int augmentation_len = 0;
size_t suppress_ms = log_config.throttling.suppress_ms;
if (status == MESSAGE_SUPPRESSED) switch (augmentation)
{ {
suppression_len += sizeof(SUPPRESSION) - 1; // Remove trailing NULL case MXS_LOG_AUGMENT_WITH_FUNCTION:
suppression_len -= 3; // Remove the %lu augmentation_len = sizeof(FORMAT_FUNCTION) - 1; // Remove trailing 0
suppression_len += UINTLEN(suppress_ms); augmentation_len -= 2; // Remove the %s
augmentation_len += strlen(function);
break;
default:
break;
} }
/** int buffer_len = 0;
* Find out the length of log string (to be formatted str). buffer_len += prefix.len;
*/ buffer_len += modname_len;
va_start(valist, format); buffer_len += augmentation_len;
int message_len = vsnprintf(NULL, 0, format, valist); buffer_len += message_len;
va_end(valist); buffer_len += suppression_len;
buffer_len += 1; // Trailing NULL
if (message_len >= 0) if (buffer_len > MAX_LOGSTRLEN)
{ {
log_prefix_t prefix = priority_to_prefix(priority); message_len -= (buffer_len - MAX_LOGSTRLEN);
buffer_len = MAX_LOGSTRLEN;
static const char FORMAT_FUNCTION[] = "(%s): "; ss_dassert(prefix.len + modname_len +
augmentation_len + message_len + suppression_len + 1 == buffer_len);
}
// Other thread might change log_config.augmentation. char buffer[buffer_len];
int augmentation = log_config.augmentation;
int augmentation_len = 0; char *prefix_text = buffer;
char *modname_text = prefix_text + prefix.len;
char *augmentation_text = modname_text + modname_len;
char *message_text = augmentation_text + augmentation_len;
char *suppression_text = message_text + message_len;
strcpy(prefix_text, prefix.text);
if (modname_len)
{
strcpy(modname_text, "[");
strcat(modname_text, modname);
strcat(modname_text, "] ");
}
if (augmentation_len)
{
int len = 0;
switch (augmentation) switch (augmentation)
{ {
case MXS_LOG_AUGMENT_WITH_FUNCTION: case MXS_LOG_AUGMENT_WITH_FUNCTION:
augmentation_len = sizeof(FORMAT_FUNCTION) - 1; // Remove trailing 0 len = sprintf(augmentation_text, FORMAT_FUNCTION, function);
augmentation_len -= 2; // Remove the %s
augmentation_len += strlen(function);
break; break;
default: default:
break; assert(!true);
} }
int buffer_len = 0; assert(len == augmentation_len);
buffer_len += prefix.len;
buffer_len += modname_len;
buffer_len += augmentation_len;
buffer_len += message_len;
buffer_len += suppression_len;
buffer_len += 1; // Trailing NULL
if (buffer_len > MAX_LOGSTRLEN)
{
message_len -= (buffer_len - MAX_LOGSTRLEN);
buffer_len = MAX_LOGSTRLEN;
ss_dassert(prefix.len + modname_len +
augmentation_len + message_len + suppression_len + 1 == buffer_len);
}
char buffer[buffer_len];
char *prefix_text = buffer;
char *modname_text = prefix_text + prefix.len;
char *augmentation_text = modname_text + modname_len;
char *message_text = augmentation_text + augmentation_len;
char *suppression_text = message_text + message_len;
strcpy(prefix_text, prefix.text);
if (modname_len)
{
strcpy(modname_text, "[");
strcat(modname_text, modname);
strcat(modname_text, "] ");
}
if (augmentation_len)
{
int len = 0;
switch (augmentation)
{
case MXS_LOG_AUGMENT_WITH_FUNCTION:
len = sprintf(augmentation_text, FORMAT_FUNCTION, function);
break;
default:
assert(!true);
}
assert(len == augmentation_len);
}
va_start(valist, format);
vsnprintf(message_text, message_len + 1, format, valist);
va_end(valist);
if (suppression_len)
{
sprintf(suppression_text, SUPPRESSION, suppress_ms);
}
enum log_flush flush = priority_to_flush(priority);
err = log_write(priority, file, line, function, prefix.len, buffer_len, buffer, flush);
} }
va_start(valist, format);
vsnprintf(message_text, message_len + 1, format, valist);
va_end(valist);
if (suppression_len)
{
sprintf(suppression_text, SUPPRESSION, suppress_ms);
}
enum log_flush flush = priority_to_flush(priority);
err = log_write(priority, file, line, function, prefix.len, buffer_len, buffer, flush);
} }
} }
} }