MXS-2014 Implement MaxScale log manager using maxbase/log.h
This commit is contained in:
Johan Wikman
parent
52e6e10e28
commit
952ee0c15f
@ -19,199 +19,70 @@
|
||||
#include <syslog.h>
|
||||
#include <unistd.h>
|
||||
|
||||
#include <maxbase/jansson.h>
|
||||
#include <maxbase/log.h>
|
||||
#include <maxbase/string.h>
|
||||
|
||||
MXS_BEGIN_DECLS
|
||||
|
||||
/**
|
||||
* If MXS_MODULE_NAME is defined before log_manager.h is included, then all
|
||||
* logged messages will be prefixed with that string enclosed in square brackets.
|
||||
* For instance, the following
|
||||
*
|
||||
* #define MXS_MODULE_NAME "xyz"
|
||||
* #include <log_manager.h>
|
||||
*
|
||||
* will lead to every logged message looking like:
|
||||
*
|
||||
* 2016-08-12 13:49:11 error : [xyz] The gadget was not ready
|
||||
*
|
||||
* In general, the value of MXS_MODULE_NAME should be the name of the shared
|
||||
* library to which the source file, where MXS_MODULE_NAME is defined, belongs.
|
||||
*
|
||||
* Note that a file that is compiled into multiple modules should
|
||||
* have MXS_MODULE_NAME defined as something else than the name of a real
|
||||
* module, or not at all.
|
||||
*
|
||||
* Any file that is compiled into maxscale-common should *not* have
|
||||
* MXS_MODULE_NAME defined.
|
||||
*/
|
||||
#if !defined(MXS_MODULE_NAME)
|
||||
#define MXS_MODULE_NAME NULL
|
||||
#endif
|
||||
|
||||
typedef enum
|
||||
{
|
||||
MXS_LOG_TARGET_DEFAULT,
|
||||
MXS_LOG_TARGET_FS, // File system
|
||||
MXS_LOG_TARGET_STDOUT, // Standard output
|
||||
} mxs_log_target_t;
|
||||
|
||||
/**
|
||||
* Thread-specific logging information.
|
||||
*/
|
||||
typedef struct mxs_log_info
|
||||
{
|
||||
size_t li_sesid;
|
||||
int li_enabled_priorities;
|
||||
} mxs_log_info_t;
|
||||
|
||||
extern int mxs_log_enabled_priorities;
|
||||
|
||||
/**
|
||||
* Check if specified log type is enabled in general or if it is enabled
|
||||
* for the current session.
|
||||
*
|
||||
* @param priority One of the syslog LOG_ERR, LOG_WARNING, etc. constants.
|
||||
*/
|
||||
#define MXS_LOG_PRIORITY_IS_ENABLED(priority) \
|
||||
((mxs_log_enabled_priorities & (1 << priority)) ? true : false)
|
||||
|
||||
/**
|
||||
* LOG_AUGMENT_WITH_FUNCTION Each logged line is suffixed with [function-name].
|
||||
*/
|
||||
typedef enum
|
||||
{
|
||||
MXS_LOG_AUGMENT_WITH_FUNCTION = 1,
|
||||
MXS_LOG_AUGMENTATION_MASK = (MXS_LOG_AUGMENT_WITH_FUNCTION)
|
||||
} mxs_log_augmentation_t;
|
||||
|
||||
typedef struct mxs_log_throttling
|
||||
{
|
||||
size_t count; // Maximum number of a specific message...
|
||||
size_t window_ms; // ...during this many milliseconds.
|
||||
size_t suppress_ms; // If exceeded, suppress such messages for this many ms.
|
||||
} MXS_LOG_THROTTLING;
|
||||
|
||||
bool mxs_log_init2(const char* ident, const char* logdir, mxs_log_target_t target,
|
||||
size_t (*get_context)(char*, size_t));
|
||||
bool mxs_log_init(const char* ident, const char* logdir, mxs_log_target_t target);
|
||||
void mxs_log_finish(void);
|
||||
bool mxs_log_rotate();
|
||||
int mxs_log_set_priority_enabled(int priority, bool enabled);
|
||||
void mxs_log_set_syslog_enabled(bool enabled);
|
||||
void mxs_log_set_maxlog_enabled(bool enabled);
|
||||
void mxs_log_set_highprecision_enabled(bool enabled);
|
||||
void mxs_log_set_augmentation(int bits);
|
||||
void mxs_log_set_throttling(const MXS_LOG_THROTTLING* throttling);
|
||||
|
||||
void mxs_log_get_throttling(MXS_LOG_THROTTLING* throttling);
|
||||
json_t* mxs_logs_to_json(const char* host);
|
||||
|
||||
static inline bool mxs_log_priority_is_enabled(int priority)
|
||||
{
|
||||
assert((priority & ~LOG_PRIMASK) == 0);
|
||||
return MXS_LOG_PRIORITY_IS_ENABLED(priority) || priority == LOG_ALERT;
|
||||
}
|
||||
|
||||
int mxs_log_message(int priority,
|
||||
const char* modname,
|
||||
const char* file, int line, const char* function,
|
||||
const char* format, ...) mxs_attribute((format(printf, 6, 7)));
|
||||
/**
|
||||
* Log an error, warning, notice, info, or debug message.
|
||||
*
|
||||
* @param priority One of the syslog constants (LOG_ERR, LOG_WARNING, ...)
|
||||
* @param format The printf format of the message.
|
||||
* @param ... Arguments, depending on the format.
|
||||
*
|
||||
* NOTE: Should typically not be called directly. Use some of the
|
||||
* MXS_ERROR, MXS_WARNING, etc. macros instead.
|
||||
*/
|
||||
#define MXS_LOG_MESSAGE(priority, format, ...)\
|
||||
(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.
|
||||
*
|
||||
* MXS_ALERT Not throttled To be used when the system is about to go down in flames.
|
||||
* MXS_ERROR Throttled For errors.
|
||||
* MXS_WARNING Throttled For warnings.
|
||||
* MXS_NOTICE Not Throttled For messages deemed important, typically used during startup.
|
||||
* MXS_INFO Not Throttled For information thought to be of value for investigating some problem.
|
||||
* MXS_DEBUG Not Throttled For debugging messages during development. Should be removed when a
|
||||
* feature is ready.
|
||||
*
|
||||
* @param format The printf format of the message.
|
||||
* @param ... Arguments, depending on the format.
|
||||
*/
|
||||
#define MXS_ALERT(format, ...) MXS_LOG_MESSAGE(LOG_ALERT, format, ##__VA_ARGS__)
|
||||
#define MXS_ERROR(format, ...) MXS_LOG_MESSAGE(LOG_ERR, format, ##__VA_ARGS__)
|
||||
#define MXS_WARNING(format, ...) MXS_LOG_MESSAGE(LOG_WARNING, format, ##__VA_ARGS__)
|
||||
#define MXS_NOTICE(format, ...) MXS_LOG_MESSAGE(LOG_NOTICE, format, ##__VA_ARGS__)
|
||||
#define MXS_INFO(format, ...) MXS_LOG_MESSAGE(LOG_INFO, format, ##__VA_ARGS__)
|
||||
|
||||
#if defined(SS_DEBUG)
|
||||
#define MXS_DEBUG(format, ...) MXS_LOG_MESSAGE(LOG_DEBUG, format, ##__VA_ARGS__)
|
||||
#else
|
||||
#define MXS_DEBUG(format, ...)
|
||||
#if !defined(MXB_MODULE_NAME)
|
||||
#define MXB_MODULE_NAME MXS_MODULE_NAME
|
||||
#endif
|
||||
|
||||
/**
|
||||
* Log an out of memory error using custom message.
|
||||
*
|
||||
* @param message Text to be logged.
|
||||
*/
|
||||
// TODO: In an OOM situation, the default logging will (most likely) *not* work,
|
||||
// TODO: as memory is allocated as part of the process. A custom route, that does
|
||||
// TODO: not allocate memory, must be created for OOM messages.
|
||||
// TODO: So, currently these are primarily placeholders.
|
||||
#define MXS_OOM_MESSAGE(message) MXS_ERROR("OOM: %s", message);
|
||||
typedef mxb_log_target_t mxs_log_target_t;
|
||||
#define MXS_LOG_TARGET_DEFAULT MXB_LOG_TARGET_DEFAULT
|
||||
#define MXS_LOG_TARGET_FS MXB_LOG_TARGET_FS
|
||||
#define MXS_LOG_TARGET_STDOUT MXB_LOG_TARGET_STDOUT
|
||||
|
||||
typedef MXB_LOG_THROTTLING MXS_LOG_THROTTLING;
|
||||
|
||||
/**
|
||||
* Log an out of memory error using custom message, if the
|
||||
* provided pointer is NULL.
|
||||
* Initializes MaxScale log manager
|
||||
*
|
||||
* @param p If NULL, an OOM message will be logged.
|
||||
* @param message Text to be logged.
|
||||
* @param ident The syslog ident. If NULL, then the program name is used.
|
||||
* @param logdir The directory for the log file. If NULL, file output is discarded.
|
||||
* @param target Logging target
|
||||
*
|
||||
* @return true if succeed, otherwise false
|
||||
*/
|
||||
#define MXS_OOM_MESSAGE_IFNULL(p, m) do { if (!p) { MXS_OOM_MESSAGE(m); } } while (false)
|
||||
bool mxs_log_init(const char* ident, const char* logdir, mxs_log_target_t target);
|
||||
|
||||
/**
|
||||
* Log an out of memory error using a default message.
|
||||
*/
|
||||
#define MXS_OOM() MXS_OOM_MESSAGE(__func__)
|
||||
#define mxs_log_finish mxb_log_finish
|
||||
#define mxs_log_message mxb_log_message
|
||||
#define mxs_log_rotate mxb_log_rotate
|
||||
|
||||
/**
|
||||
* Log an out of memory error using a default message, if the
|
||||
* provided pointer is NULL.
|
||||
*
|
||||
* @param p If NULL, an OOM message will be logged.
|
||||
*/
|
||||
#define MXS_OOM_IFNULL(p) do { if (!p) { MXS_OOM(); } } while (false)
|
||||
#define mxs_log_get_throttling mxb_log_get_throttling
|
||||
// TODO: Rename mxs_log_priority_is_enabled -> mxs_log_is_priority_enabled
|
||||
#define mxs_log_priority_is_enabled mxb_log_is_priority_enabled
|
||||
#define mxs_log_set_augmentation mxb_log_set_augmentation
|
||||
#define mxs_log_set_highprecision_enabled mxb_log_set_highprecision_enabled
|
||||
#define mxs_log_set_maxlog_enabled mxb_log_set_maxlog_enabled
|
||||
#define mxs_log_set_highprecision_enabled mxb_log_set_highprecision_enabled
|
||||
#define mxs_log_set_priority_enabled mxb_log_set_priority_enabled
|
||||
#define mxs_log_set_syslog_enabled mxb_log_set_syslog_enabled
|
||||
#define mxs_log_set_throttling mxb_log_set_throttling
|
||||
|
||||
enum
|
||||
{
|
||||
MXS_OOM_MESSAGE_MAXLEN = 80 /** Maximum length of an OOM message, including the
|
||||
trailing NULL. If longer, it will be cut. */
|
||||
};
|
||||
#define MXS_LOG_PRIORITY_IS_ENABLED MXB_LOG_PRIORITY_IS_ENABLED
|
||||
|
||||
/**
|
||||
* Return a thread specific pointer to a string describing the error
|
||||
* code passed as argument. The string is obtained using strerror_r.
|
||||
*
|
||||
* @param error One of the errno error codes.
|
||||
*
|
||||
* @return Thread specific pointer to string describing the error code.
|
||||
*
|
||||
* @attention The function is thread safe, but not re-entrant. That is,
|
||||
* calling it twice with different error codes between two sequence points
|
||||
* will not work. E.g:
|
||||
*
|
||||
* printf("EINVAL = %s, EACCESS = %s",
|
||||
* mxs_strerror(EINVAL), mxs_strerror(EACCESS));
|
||||
*/
|
||||
const char* mxs_strerror(int error);
|
||||
json_t* mxs_logs_to_json(const char* host);
|
||||
|
||||
#define MXS_LOG_MESSAGE MXB_LOG_MESSAGE
|
||||
|
||||
#define MXS_ALERT MXB_ALERT
|
||||
#define MXS_ERROR MXB_ERROR
|
||||
#define MXS_WARNING MXB_WARNING
|
||||
#define MXS_NOTICE MXB_NOTICE
|
||||
#define MXS_INFO MXB_INFO
|
||||
#define MXS_DEBUG MXB_DEBUG
|
||||
|
||||
#define MXS_OOM_MESSAGE MXB_OOM_MESSAGE
|
||||
#define MXS_OOM_MESSAGE_IFNULL MXB_OOM_MESSAGE_IFNULL
|
||||
#define MXS_OOM MXB_OOM
|
||||
#define MXS_OOM_IFNULL MXB_OOM_IFNULL
|
||||
|
||||
#define mxs_strerror mxb_strerror
|
||||
|
||||
MXS_END_DECLS
|
||||
|
||||
@ -16,290 +16,22 @@
|
||||
#include <sys/time.h>
|
||||
#include <syslog.h>
|
||||
|
||||
#include <cerrno>
|
||||
#include <cinttypes>
|
||||
#include <string>
|
||||
#include <mutex>
|
||||
|
||||
#include <maxbase/atomic.h>
|
||||
#include <maxbase/string.h>
|
||||
#include <maxbase/log.h>
|
||||
#include <maxbase/logger.hh>
|
||||
|
||||
#include <maxscale/alloc.h>
|
||||
#include <maxscale/config.h>
|
||||
#include <maxscale/debug.h>
|
||||
#include <maxscale/json_api.h>
|
||||
#include <maxscale/session.h>
|
||||
#include <maxscale/utils.h>
|
||||
|
||||
static std::unique_ptr<mxb::Logger> logger;
|
||||
|
||||
const std::string LOGFILE_NAME = "maxscale.log";
|
||||
|
||||
/**
|
||||
* Default augmentation.
|
||||
*/
|
||||
static int DEFAULT_LOG_AUGMENTATION = 0;
|
||||
// A message that is logged 10 times in 1 second will be suppressed for 10 seconds.
|
||||
static MXS_LOG_THROTTLING DEFAULT_LOG_THROTTLING = { 10, 1000, 10000 };
|
||||
|
||||
static struct
|
||||
{
|
||||
int augmentation; // Can change during the lifetime of log_manager.
|
||||
bool do_highprecision; // Can change during the lifetime of log_manager.
|
||||
bool do_syslog; // Can change during the lifetime of log_manager.
|
||||
bool do_maxlog; // Can change during the lifetime of log_manager.
|
||||
MXS_LOG_THROTTLING throttling; // Can change during the lifetime of log_manager.
|
||||
bool use_stdout; // Can NOT change during the lifetime of log_manager.
|
||||
} log_config =
|
||||
{
|
||||
DEFAULT_LOG_AUGMENTATION, // augmentation
|
||||
false, // do_highprecision
|
||||
true, // do_syslog
|
||||
true, // do_maxlog
|
||||
DEFAULT_LOG_THROTTLING, // throttling
|
||||
false // use_stdout
|
||||
};
|
||||
|
||||
/**
|
||||
* Variable holding the enabled priorities information.
|
||||
* Used from logging macros.
|
||||
*/
|
||||
int mxs_log_enabled_priorities = (1 << LOG_ERR) | (1 << LOG_NOTICE) | (1 << LOG_WARNING);
|
||||
|
||||
/**
|
||||
* BUFSIZ comes from the system. It equals with block size or
|
||||
* its multiplication.
|
||||
*/
|
||||
#define MAX_LOGSTRLEN BUFSIZ
|
||||
|
||||
/**
|
||||
* Returns the current time.
|
||||
*
|
||||
* @return Current monotonic raw time in milliseconds.
|
||||
*/
|
||||
static uint64_t time_monotonic_ms()
|
||||
{
|
||||
struct timespec now;
|
||||
clock_gettime(CLOCK_MONOTONIC, &now);
|
||||
|
||||
return now.tv_sec * 1000 + now.tv_nsec / 1000000;
|
||||
}
|
||||
|
||||
namespace
|
||||
{
|
||||
|
||||
typedef enum message_suppression
|
||||
{
|
||||
MESSAGE_NOT_SUPPRESSED, // Message is not suppressed.
|
||||
MESSAGE_SUPPRESSED, // Message is suppressed for the first time (for this round)
|
||||
MESSAGE_STILL_SUPPRESSED // Message is still suppressed (for this round)
|
||||
} message_suppression_t;
|
||||
const char* LOGFILE_NAME = "maxscale.log";
|
||||
|
||||
class MessageRegistryKey
|
||||
{
|
||||
public:
|
||||
const char* filename;
|
||||
const int linenumber;
|
||||
|
||||
/**
|
||||
* @brief Constructs a message stats key
|
||||
*
|
||||
* @param filename The filename where the message was reported. Must be a
|
||||
* statically allocated buffer, e.g. __FILE__.
|
||||
* @param linenumber The linenumber where the message was reported.
|
||||
*/
|
||||
MessageRegistryKey(const char* filename, int linenumber)
|
||||
: filename(filename)
|
||||
, linenumber(linenumber)
|
||||
{
|
||||
}
|
||||
|
||||
bool eq(const MessageRegistryKey& other) const
|
||||
{
|
||||
return
|
||||
filename == other.filename && // Yes, we compare the pointer values and not the strings.
|
||||
linenumber == other.linenumber;
|
||||
}
|
||||
|
||||
size_t hash() const
|
||||
{
|
||||
/*
|
||||
* This is an implementation of the Jenkin's one-at-a-time hash function.
|
||||
* https://en.wikipedia.org/wiki/Jenkins_hash_function
|
||||
*/
|
||||
uint64_t key1 = (uint64_t)filename;
|
||||
uint16_t key2 = (uint16_t)linenumber; // The first 48 bits are likely to be 0.
|
||||
|
||||
uint32_t hash_value = 0;
|
||||
size_t i;
|
||||
|
||||
for (i = 0; i < sizeof(key1); ++i)
|
||||
{
|
||||
hash_value += (key1 >> i * 8) & 0xff;
|
||||
hash_value += (hash_value << 10);
|
||||
hash_value ^= (hash_value >> 6);
|
||||
}
|
||||
|
||||
for (i = 0; i < sizeof(key2); ++i)
|
||||
{
|
||||
hash_value += (key1 >> i * 8) & 0xff;
|
||||
hash_value += (hash_value << 10);
|
||||
hash_value ^= (hash_value >> 6);
|
||||
}
|
||||
|
||||
hash_value += (hash_value << 3);
|
||||
hash_value ^= (hash_value >> 11);
|
||||
hash_value += (hash_value << 15);
|
||||
return hash_value;
|
||||
}
|
||||
};
|
||||
|
||||
class MessageRegistryStats
|
||||
{
|
||||
public:
|
||||
MessageRegistryStats()
|
||||
: m_first_ms(time_monotonic_ms())
|
||||
, m_last_ms(0)
|
||||
, m_count(0)
|
||||
{
|
||||
}
|
||||
|
||||
message_suppression_t update_suppression(const MXS_LOG_THROTTLING& t)
|
||||
{
|
||||
message_suppression_t rv = MESSAGE_NOT_SUPPRESSED;
|
||||
|
||||
uint64_t now_ms = time_monotonic_ms();
|
||||
|
||||
std::lock_guard<std::mutex> guard(m_lock);
|
||||
|
||||
++m_count;
|
||||
|
||||
// Less that t.window_ms milliseconds since the message was logged
|
||||
// the last time. May have to be throttled.
|
||||
if (m_count < t.count)
|
||||
{
|
||||
// t.count times has not been reached, still ok to log.
|
||||
}
|
||||
else if (m_count == t.count)
|
||||
{
|
||||
// t.count times has been reached. Was it within the window?
|
||||
if (now_ms - m_first_ms < t.window_ms)
|
||||
{
|
||||
// Within the window, suppress the message.
|
||||
rv = MESSAGE_SUPPRESSED;
|
||||
}
|
||||
else
|
||||
{
|
||||
// Not within the window, reset the situation.
|
||||
|
||||
// The flooding situation is analyzed window by window.
|
||||
// That means that if there in each of two consequtive
|
||||
// windows are not enough messages for throttling to take
|
||||
// effect, but there would be if the window was placed at a
|
||||
// slightly different position (e.g. starting in the middle
|
||||
// of the first and ending in the middle of the second) it
|
||||
// will go undetected and no throttling will be made.
|
||||
// However, if that's the case, it was a spike so the
|
||||
// flooding will stop anyway.
|
||||
|
||||
m_first_ms = now_ms;
|
||||
m_count = 1;
|
||||
}
|
||||
}
|
||||
else
|
||||
{
|
||||
// In suppression mode.
|
||||
if (now_ms - m_first_ms < (t.window_ms + t.suppress_ms))
|
||||
{
|
||||
// Still in the suppression window.
|
||||
rv = MESSAGE_STILL_SUPPRESSED;
|
||||
}
|
||||
else
|
||||
{
|
||||
// We have exited the suppression window, reset the situation.
|
||||
m_first_ms = now_ms;
|
||||
m_count = 1;
|
||||
}
|
||||
}
|
||||
|
||||
m_last_ms = now_ms;
|
||||
|
||||
return rv;
|
||||
}
|
||||
|
||||
private:
|
||||
std::mutex m_lock;
|
||||
uint64_t m_first_ms; /** The time when the error was logged the first time in this window. */
|
||||
uint64_t m_last_ms; /** The time when the error was logged the last time. */
|
||||
size_t m_count; /** How many times the error has been reported within this window. */
|
||||
};
|
||||
|
||||
}
|
||||
|
||||
namespace std
|
||||
{
|
||||
|
||||
template<>
|
||||
struct hash<MessageRegistryKey>
|
||||
{
|
||||
typedef MessageRegistryKey Key;
|
||||
typedef size_t result_type;
|
||||
|
||||
size_t operator()(const MessageRegistryKey& key) const
|
||||
{
|
||||
return key.hash();
|
||||
}
|
||||
};
|
||||
|
||||
template<>
|
||||
struct equal_to<MessageRegistryKey>
|
||||
{
|
||||
typedef bool result_type;
|
||||
typedef MessageRegistryKey first_argument_type;
|
||||
typedef MessageRegistryKey second_argument_type;
|
||||
|
||||
bool operator()(const MessageRegistryKey& lhs, const MessageRegistryKey& rhs) const
|
||||
{
|
||||
return lhs.eq(rhs);
|
||||
}
|
||||
};
|
||||
|
||||
}
|
||||
|
||||
namespace
|
||||
{
|
||||
|
||||
class MessageRegistry
|
||||
{
|
||||
public:
|
||||
typedef MessageRegistryKey Key;
|
||||
typedef MessageRegistryStats Stats;
|
||||
|
||||
MessageRegistry(const MessageRegistry&) = delete;
|
||||
MessageRegistry& operator=(const MessageRegistry&) = delete;
|
||||
|
||||
MessageRegistry()
|
||||
{
|
||||
}
|
||||
|
||||
Stats& get_stats(const Key& key)
|
||||
{
|
||||
std::lock_guard<std::mutex> guard(m_lock);
|
||||
return m_registry[key];
|
||||
}
|
||||
|
||||
private:
|
||||
std::mutex m_lock;
|
||||
std::unordered_map<Key, Stats> m_registry;
|
||||
};
|
||||
|
||||
}
|
||||
|
||||
static std::unique_ptr<MessageRegistry> message_registry;
|
||||
static size_t (*get_context)(char* buffer, size_t len);
|
||||
|
||||
static size_t mxs_get_context(char* buffer, size_t len)
|
||||
size_t mxs_get_context(char* buffer, size_t len)
|
||||
{
|
||||
ss_dassert(len >= 20); // Needed for "9223372036854775807"
|
||||
|
||||
@ -317,581 +49,15 @@ static size_t mxs_get_context(char* buffer, size_t len)
|
||||
return len;
|
||||
}
|
||||
|
||||
/**
|
||||
* Initializes log manager
|
||||
*
|
||||
* @param ident The syslog ident. If NULL, then the program name is used.
|
||||
* @param logdir The directory for the log file. If NULL, file output is discarded.
|
||||
* @param target Logging target
|
||||
*
|
||||
* @return true if succeed, otherwise false
|
||||
*/
|
||||
bool mxs_log_init2(const char* ident, const char* logdir, mxs_log_target_t target,
|
||||
size_t (*gc)(char*, size_t))
|
||||
{
|
||||
static bool log_init_done = false;
|
||||
ss_dassert(!log_init_done);
|
||||
log_init_done = true;
|
||||
|
||||
openlog(ident, LOG_PID | LOG_ODELAY, LOG_USER);
|
||||
|
||||
// Tests mainly pass a NULL logdir with MXS_LOG_TARGET_STDOUT but using
|
||||
// /dev/null as the default allows total suppression of logging
|
||||
std::string filename = "/dev/null";
|
||||
|
||||
if (logdir)
|
||||
{
|
||||
filename = std::string(logdir) + "/" + LOGFILE_NAME;
|
||||
}
|
||||
|
||||
message_registry.reset(new (std::nothrow) MessageRegistry);
|
||||
|
||||
switch (target)
|
||||
{
|
||||
case MXS_LOG_TARGET_FS:
|
||||
case MXS_LOG_TARGET_DEFAULT:
|
||||
logger = mxb::FileLogger::create(filename);
|
||||
break;
|
||||
|
||||
case MXS_LOG_TARGET_STDOUT:
|
||||
logger = mxb::StdoutLogger::create(filename);
|
||||
break;
|
||||
|
||||
default:
|
||||
ss_dassert(!true);
|
||||
break;
|
||||
}
|
||||
|
||||
get_context = gc;
|
||||
|
||||
return logger && message_registry;
|
||||
}
|
||||
|
||||
bool mxs_log_init(const char* ident, const char* logdir, mxs_log_target_t target)
|
||||
{
|
||||
return mxs_log_init2(ident, logdir, target, mxs_get_context);
|
||||
return mxb_log_init(ident, logdir, LOGFILE_NAME, target, mxs_get_context);
|
||||
}
|
||||
|
||||
/**
|
||||
* End log manager
|
||||
*/
|
||||
void mxs_log_finish(void)
|
||||
namespace
|
||||
{
|
||||
closelog();
|
||||
}
|
||||
|
||||
std::string get_timestamp(void)
|
||||
{
|
||||
time_t t = time(NULL);
|
||||
struct tm tm;
|
||||
localtime_r(&t, &tm);
|
||||
const char* timestamp_formatstr = "%04d-%02d-%02d %02d:%02d:%02d ";
|
||||
static int required = snprintf(NULL, 0, timestamp_formatstr,
|
||||
tm.tm_year + 1900, tm.tm_mon + 1, tm.tm_mday, tm.tm_hour,
|
||||
tm.tm_min, tm.tm_sec);
|
||||
char buf[required + 1];
|
||||
|
||||
snprintf(buf, sizeof(buf), timestamp_formatstr,
|
||||
tm.tm_year + 1900, tm.tm_mon + 1, tm.tm_mday, tm.tm_hour,
|
||||
tm.tm_min, tm.tm_sec);
|
||||
|
||||
return buf;
|
||||
}
|
||||
|
||||
std::string get_timestamp_hp(void)
|
||||
{
|
||||
struct timeval tv;
|
||||
gettimeofday(&tv, NULL);
|
||||
struct tm tm;
|
||||
localtime_r(&tv.tv_sec, &tm);
|
||||
int usec = tv.tv_usec / 1000;
|
||||
|
||||
const char* timestamp_formatstr_hp = "%04d-%02d-%02d %02d:%02d:%02d.%03d ";
|
||||
static int required = snprintf(NULL, 0, timestamp_formatstr_hp,
|
||||
tm.tm_year + 1900, tm.tm_mon + 1, tm.tm_mday,
|
||||
tm.tm_hour, tm.tm_min, tm.tm_sec, usec);
|
||||
|
||||
char buf[required + 1];
|
||||
|
||||
snprintf(buf, sizeof(buf), timestamp_formatstr_hp,
|
||||
tm.tm_year + 1900, tm.tm_mon + 1, tm.tm_mday,
|
||||
tm.tm_hour, tm.tm_min, tm.tm_sec, usec);
|
||||
|
||||
return buf;
|
||||
}
|
||||
|
||||
/**
|
||||
* write a message to the MaxScale log
|
||||
*
|
||||
* @param priority Syslog priority
|
||||
* @param str string to be written to log (null terminated)
|
||||
*
|
||||
* @return 0 on succeess, -1 on error
|
||||
*/
|
||||
static int log_write(int priority, const char* str)
|
||||
{
|
||||
ss_dassert(str);
|
||||
ss_dassert((priority & ~(LOG_PRIMASK | LOG_FACMASK)) == 0);
|
||||
|
||||
std::string msg = log_config.do_highprecision ? get_timestamp_hp() : get_timestamp();
|
||||
msg += str;
|
||||
|
||||
// Remove any user-generated newlines.
|
||||
// This is safe to do as we know the message is not full of newlines
|
||||
while (msg.back() == '\n')
|
||||
{
|
||||
msg.pop_back();
|
||||
}
|
||||
|
||||
// Add a final newline into the message
|
||||
msg.push_back('\n');
|
||||
|
||||
return logger->write(msg.c_str(), msg.length()) ? 0 : -1;
|
||||
}
|
||||
|
||||
/**
|
||||
* Set log augmentation.
|
||||
*
|
||||
* @param bits One of the log_augmentation_t constants.
|
||||
*/
|
||||
void mxs_log_set_augmentation(int bits)
|
||||
{
|
||||
log_config.augmentation = bits & MXS_LOG_AUGMENTATION_MASK;
|
||||
}
|
||||
|
||||
/**
|
||||
* Enable/disable syslog logging.
|
||||
*
|
||||
* @param enabled True, if high precision logging should be enabled, false if it should be disabled.
|
||||
*/
|
||||
void mxs_log_set_highprecision_enabled(bool enabled)
|
||||
{
|
||||
log_config.do_highprecision = enabled;
|
||||
|
||||
MXS_NOTICE("highprecision logging is %s.", enabled ? "enabled" : "disabled");
|
||||
}
|
||||
|
||||
/**
|
||||
* Enable/disable syslog logging.
|
||||
*
|
||||
* @param enabled True, if syslog logging should be enabled, false if it should be disabled.
|
||||
*/
|
||||
void mxs_log_set_syslog_enabled(bool enabled)
|
||||
{
|
||||
log_config.do_syslog = enabled;
|
||||
|
||||
MXS_NOTICE("syslog logging is %s.", enabled ? "enabled" : "disabled");
|
||||
}
|
||||
|
||||
/**
|
||||
* Enable/disable maxscale log logging.
|
||||
*
|
||||
* @param enabled True, if syslog logging should be enabled, false if it should be disabled.
|
||||
*/
|
||||
void mxs_log_set_maxlog_enabled(bool enabled)
|
||||
{
|
||||
log_config.do_maxlog = enabled;
|
||||
|
||||
MXS_NOTICE("maxlog logging is %s.", enabled ? "enabled" : "disabled");
|
||||
}
|
||||
|
||||
/**
|
||||
* Set the log throttling parameters.
|
||||
*
|
||||
* @param throttling The throttling parameters.
|
||||
*/
|
||||
void mxs_log_set_throttling(const MXS_LOG_THROTTLING* throttling)
|
||||
{
|
||||
// No locking; it does not have any real impact, even if the struct
|
||||
// is used right when its values are modified.
|
||||
log_config.throttling = *throttling;
|
||||
|
||||
if ((log_config.throttling.count == 0) ||
|
||||
(log_config.throttling.window_ms == 0) ||
|
||||
(log_config.throttling.suppress_ms == 0))
|
||||
{
|
||||
MXS_NOTICE("Log throttling has been disabled.");
|
||||
}
|
||||
else
|
||||
{
|
||||
MXS_NOTICE("A message that is logged %lu times in %lu milliseconds, "
|
||||
"will be suppressed for %lu milliseconds.",
|
||||
log_config.throttling.count,
|
||||
log_config.throttling.window_ms,
|
||||
log_config.throttling.suppress_ms);
|
||||
}
|
||||
}
|
||||
|
||||
/**
|
||||
* Get the log throttling parameters.
|
||||
*
|
||||
* @param throttling The throttling parameters.
|
||||
*/
|
||||
void mxs_log_get_throttling(MXS_LOG_THROTTLING* throttling)
|
||||
{
|
||||
// No locking; this is used only from maxadmin and an inconsistent set
|
||||
// may be returned only if mxs_log_set_throttling() is called via an
|
||||
// other instance of maxadmin at the very same moment.
|
||||
*throttling = log_config.throttling;
|
||||
}
|
||||
|
||||
/**
|
||||
* Rotate the log
|
||||
*
|
||||
* @return True if the rotating was successful
|
||||
*/
|
||||
bool mxs_log_rotate()
|
||||
{
|
||||
return logger->rotate();
|
||||
}
|
||||
|
||||
static const char* level_name(int level)
|
||||
{
|
||||
switch (level)
|
||||
{
|
||||
case LOG_EMERG:
|
||||
return "emergency";
|
||||
case LOG_ALERT:
|
||||
return "alert";
|
||||
case LOG_CRIT:
|
||||
return "critical";
|
||||
case LOG_ERR:
|
||||
return "error";
|
||||
case LOG_WARNING:
|
||||
return "warning";
|
||||
case LOG_NOTICE:
|
||||
return "notice";
|
||||
case LOG_INFO:
|
||||
return "informational";
|
||||
case LOG_DEBUG:
|
||||
return "debug";
|
||||
default:
|
||||
ss_dassert(!true);
|
||||
return "unknown";
|
||||
}
|
||||
}
|
||||
|
||||
/**
|
||||
* Enable/disable a particular syslog priority.
|
||||
*
|
||||
* @param priority One of the LOG_ERR etc. constants from sys/syslog.h.
|
||||
* @param enabled True if the priority should be enabled, false if it to be disabled.
|
||||
*
|
||||
* @return 0 if the priority was valid, -1 otherwise.
|
||||
*/
|
||||
int mxs_log_set_priority_enabled(int level, bool enable)
|
||||
{
|
||||
int rv = -1;
|
||||
const char* text = (enable ? "enable" : "disable");
|
||||
|
||||
if ((level & ~LOG_PRIMASK) == 0)
|
||||
{
|
||||
int bit = (1 << level);
|
||||
|
||||
if (enable)
|
||||
{
|
||||
// TODO: Put behind spinlock.
|
||||
mxs_log_enabled_priorities |= bit;
|
||||
}
|
||||
else
|
||||
{
|
||||
mxs_log_enabled_priorities &= ~bit;
|
||||
}
|
||||
|
||||
MXS_NOTICE("The logging of %s messages has been %sd.", level_name(level), text);
|
||||
}
|
||||
else
|
||||
{
|
||||
MXS_ERROR("Attempt to %s unknown syslog priority %d.", text, level);
|
||||
}
|
||||
|
||||
return rv;
|
||||
}
|
||||
|
||||
typedef struct log_prefix
|
||||
{
|
||||
const char* text; // The prefix, e.g. "error: "
|
||||
int len; // The length of the prefix without the trailing NULL.
|
||||
} log_prefix_t;
|
||||
|
||||
static const char PREFIX_EMERG[] = "emerg : ";
|
||||
static const char PREFIX_ALERT[] = "alert : ";
|
||||
static const char PREFIX_CRIT[] = "crit : ";
|
||||
static const char PREFIX_ERROR[] = "error : ";
|
||||
static const char PREFIX_WARNING[] = "warning: ";
|
||||
static const char PREFIX_NOTICE[] = "notice : ";
|
||||
static const char PREFIX_INFO[] = "info : ";
|
||||
static const char PREFIX_DEBUG[] = "debug : ";
|
||||
|
||||
static log_prefix_t level_to_prefix(int level)
|
||||
{
|
||||
ss_dassert((level & ~LOG_PRIMASK) == 0);
|
||||
|
||||
log_prefix_t prefix;
|
||||
|
||||
switch (level)
|
||||
{
|
||||
case LOG_EMERG:
|
||||
prefix.text = PREFIX_EMERG;
|
||||
prefix.len = sizeof(PREFIX_EMERG);
|
||||
break;
|
||||
|
||||
case LOG_ALERT:
|
||||
prefix.text = PREFIX_ALERT;
|
||||
prefix.len = sizeof(PREFIX_ALERT);
|
||||
break;
|
||||
|
||||
case LOG_CRIT:
|
||||
prefix.text = PREFIX_CRIT;
|
||||
prefix.len = sizeof(PREFIX_CRIT);
|
||||
break;
|
||||
|
||||
case LOG_ERR:
|
||||
prefix.text = PREFIX_ERROR;
|
||||
prefix.len = sizeof(PREFIX_ERROR);
|
||||
break;
|
||||
|
||||
case LOG_WARNING:
|
||||
prefix.text = PREFIX_WARNING;
|
||||
prefix.len = sizeof(PREFIX_WARNING);
|
||||
break;
|
||||
|
||||
case LOG_NOTICE:
|
||||
prefix.text = PREFIX_NOTICE;
|
||||
prefix.len = sizeof(PREFIX_NOTICE);
|
||||
break;
|
||||
|
||||
case LOG_INFO:
|
||||
prefix.text = PREFIX_INFO;
|
||||
prefix.len = sizeof(PREFIX_INFO);
|
||||
break;
|
||||
|
||||
case LOG_DEBUG:
|
||||
prefix.text = PREFIX_DEBUG;
|
||||
prefix.len = sizeof(PREFIX_DEBUG);
|
||||
break;
|
||||
|
||||
default:
|
||||
ss_dassert(!true);
|
||||
prefix.text = PREFIX_ERROR;
|
||||
prefix.len = sizeof(PREFIX_ERROR);
|
||||
break;
|
||||
}
|
||||
|
||||
--prefix.len; // Remove trailing NULL.
|
||||
|
||||
return prefix;
|
||||
}
|
||||
|
||||
static message_suppression_t message_status(const char* file, int line)
|
||||
{
|
||||
message_suppression_t rv = MESSAGE_NOT_SUPPRESSED;
|
||||
|
||||
// Copy the config to prevent the values from changing while we are using
|
||||
// them. It does not matter if they are changed just when we are copying
|
||||
// them, but we want to use one set of values throughout the function.
|
||||
MXS_LOG_THROTTLING t = log_config.throttling;
|
||||
|
||||
if ((t.count != 0) && (t.window_ms != 0) && (t.suppress_ms != 0))
|
||||
{
|
||||
MessageRegistry::Key key(file, line);
|
||||
MessageRegistry::Stats& stats = message_registry->get_stats(key);
|
||||
|
||||
rv = stats.update_suppression(t);
|
||||
}
|
||||
|
||||
return rv;
|
||||
}
|
||||
|
||||
/**
|
||||
* Log a message of a particular priority.
|
||||
*
|
||||
* @param priority One of the syslog constants: LOG_ERR, LOG_WARNING, ...
|
||||
* @param modname The name of the module.
|
||||
* @param file The name of the file where the message was logged.
|
||||
* @param line The line where the message was logged.
|
||||
* @param function The function where the message was logged.
|
||||
* @param format The printf format of the following arguments.
|
||||
* @param ... Optional arguments according to the format.
|
||||
*/
|
||||
int mxs_log_message(int priority,
|
||||
const char* modname,
|
||||
const char* file, int line, const char* function,
|
||||
const char* format, ...)
|
||||
{
|
||||
int err = 0;
|
||||
|
||||
ss_dassert(logger && message_registry);
|
||||
ss_dassert((priority & ~(LOG_PRIMASK | LOG_FACMASK)) == 0);
|
||||
|
||||
int level = priority & LOG_PRIMASK;
|
||||
|
||||
if ((priority & ~(LOG_PRIMASK | LOG_FACMASK)) == 0) // Check that the priority is ok,
|
||||
{
|
||||
message_suppression_t status = MESSAGE_NOT_SUPPRESSED;
|
||||
|
||||
// We only throttle errors and warnings. Info and debug messages
|
||||
// are never on during normal operation, so if they are enabled,
|
||||
// we are presumably debugging something. Notice messages are
|
||||
// assumed to be logged for a reason and always in a context where
|
||||
// flooding cannot be caused.
|
||||
if ((level == LOG_ERR) || (level == LOG_WARNING))
|
||||
{
|
||||
status = message_status(file, line);
|
||||
}
|
||||
|
||||
if (status != MESSAGE_STILL_SUPPRESSED)
|
||||
{
|
||||
va_list valist;
|
||||
|
||||
char context[32]; // The documentation will guarantee a buffer of at least 32 bytes.
|
||||
int context_len = 0;
|
||||
|
||||
if (get_context)
|
||||
{
|
||||
context_len = get_context(context, sizeof(context));
|
||||
|
||||
if (context_len != 0)
|
||||
{
|
||||
context_len += 3; // The added "() "
|
||||
}
|
||||
}
|
||||
|
||||
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)
|
||||
{
|
||||
suppression_len += sizeof(SUPPRESSION) - 1; // Remove trailing NULL
|
||||
suppression_len -= 3; // Remove the %lu
|
||||
suppression_len += UINTLEN(suppress_ms);
|
||||
}
|
||||
|
||||
/**
|
||||
* 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)
|
||||
{
|
||||
log_prefix_t prefix = level_to_prefix(level);
|
||||
|
||||
static const char FORMAT_FUNCTION[] = "(%s): ";
|
||||
|
||||
// Other thread might change log_config.augmentation.
|
||||
int augmentation = log_config.augmentation;
|
||||
int augmentation_len = 0;
|
||||
|
||||
switch (augmentation)
|
||||
{
|
||||
case MXS_LOG_AUGMENT_WITH_FUNCTION:
|
||||
augmentation_len = sizeof(FORMAT_FUNCTION) - 1; // Remove trailing 0
|
||||
augmentation_len -= 2; // Remove the %s
|
||||
augmentation_len += strlen(function);
|
||||
break;
|
||||
|
||||
default:
|
||||
break;
|
||||
}
|
||||
|
||||
int buffer_len = 0;
|
||||
buffer_len += prefix.len;
|
||||
buffer_len += context_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 + context_len + modname_len +
|
||||
augmentation_len + message_len + suppression_len + 1 == buffer_len);
|
||||
}
|
||||
|
||||
char buffer[buffer_len];
|
||||
|
||||
char *prefix_text = buffer;
|
||||
char *context_text = prefix_text + prefix.len;
|
||||
char *modname_text = context_text + context_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 (context_len)
|
||||
{
|
||||
strcpy(context_text, "(");
|
||||
strcat(context_text, context);
|
||||
strcat(context_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:
|
||||
ss_dassert(!true);
|
||||
}
|
||||
|
||||
(void)len;
|
||||
ss_dassert(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);
|
||||
}
|
||||
|
||||
if (log_config.do_syslog && LOG_PRI(priority) != LOG_DEBUG)
|
||||
{
|
||||
// Debug messages are never logged into syslog
|
||||
syslog(priority, "%s", context_text);
|
||||
}
|
||||
|
||||
err = log_write(priority, buffer);
|
||||
}
|
||||
}
|
||||
}
|
||||
else
|
||||
{
|
||||
MXS_WARNING("Invalid syslog priority: %d", priority);
|
||||
}
|
||||
|
||||
return err;
|
||||
}
|
||||
|
||||
const char* mxs_strerror(int error)
|
||||
{
|
||||
return mxb_strerror(error);
|
||||
}
|
||||
|
||||
json_t* get_log_priorities()
|
||||
{
|
||||
@ -925,28 +91,31 @@ json_t* get_log_priorities()
|
||||
return arr;
|
||||
}
|
||||
|
||||
}
|
||||
|
||||
json_t* mxs_logs_to_json(const char* host)
|
||||
{
|
||||
ss_dassert(logger && message_registry);
|
||||
json_t* param = json_object();
|
||||
json_object_set_new(param, "highprecision", json_boolean(log_config.do_highprecision));
|
||||
json_object_set_new(param, "maxlog", json_boolean(log_config.do_maxlog));
|
||||
json_object_set_new(param, "syslog", json_boolean(log_config.do_syslog));
|
||||
json_object_set_new(param, "highprecision", json_boolean(mxb_log_is_highprecision_enabled()));
|
||||
json_object_set_new(param, "maxlog", json_boolean(mxb_log_is_maxlog_enabled()));
|
||||
json_object_set_new(param, "syslog", json_boolean(mxb_log_is_syslog_enabled()));
|
||||
|
||||
MXB_LOG_THROTTLING t;
|
||||
mxb_log_get_throttling(&t);
|
||||
json_t* throttling = json_object();
|
||||
json_object_set_new(throttling, "count", json_integer(log_config.throttling.count));
|
||||
json_object_set_new(throttling, "suppress_ms", json_integer(log_config.throttling.suppress_ms));
|
||||
json_object_set_new(throttling, "window_ms", json_integer(log_config.throttling.window_ms));
|
||||
json_object_set_new(throttling, "count", json_integer(t.count));
|
||||
json_object_set_new(throttling, "suppress_ms", json_integer(t.suppress_ms));
|
||||
json_object_set_new(throttling, "window_ms", json_integer(t.window_ms));
|
||||
json_object_set_new(param, "throttling", throttling);
|
||||
json_object_set_new(param, "log_warning", json_boolean(mxs_log_priority_is_enabled(LOG_WARNING)));
|
||||
json_object_set_new(param, "log_notice", json_boolean(mxs_log_priority_is_enabled(LOG_NOTICE)));
|
||||
json_object_set_new(param, "log_info", json_boolean(mxs_log_priority_is_enabled(LOG_INFO)));
|
||||
json_object_set_new(param, "log_debug", json_boolean(mxs_log_priority_is_enabled(LOG_DEBUG)));
|
||||
json_object_set_new(param, "log_warning", json_boolean(mxb_log_is_priority_enabled(LOG_WARNING)));
|
||||
json_object_set_new(param, "log_notice", json_boolean(mxb_log_is_priority_enabled(LOG_NOTICE)));
|
||||
json_object_set_new(param, "log_info", json_boolean(mxb_log_is_priority_enabled(LOG_INFO)));
|
||||
json_object_set_new(param, "log_debug", json_boolean(mxb_log_is_priority_enabled(LOG_DEBUG)));
|
||||
json_object_set_new(param, "log_to_shm", json_boolean(false));
|
||||
|
||||
json_t* attr = json_object();
|
||||
json_object_set_new(attr, CN_PARAMETERS, param);
|
||||
json_object_set_new(attr, "log_file", json_string(logger->filename()));
|
||||
json_object_set_new(attr, "log_file", json_string(mxb_log_get_filename()));
|
||||
json_object_set_new(attr, "log_priorities", get_log_priorities());
|
||||
|
||||
json_t* data = json_object();
|
||||
|
||||
Loading…
x
Reference in New Issue
Block a user