Verified Commit 49160da7 authored by Michal 'vorner' Vaner's avatar Michal 'vorner' Vaner
Browse files

Logging configurable by environment variables

* Configure logging through environment variables.
* Describe how to use it.
* Compile trace logging in by default again. Can still be disabled by a
  compile switch, to get some more performance.
* Disable most of the logging in tests.
parent bfaf14ee
Pipeline #1760 passed with stage
in 1 minute and 14 seconds
......@@ -4,7 +4,7 @@ LDFLAGS += -pthread
VALGRIND := valgrind --leak-check=full --show-leak-kinds=all --track-fds=yes --trace-children=no --child-silent-after-fork=yes --track-origins=yes --error-exitcode=1
MAX_LOG_LEVEL := DBG
MAX_LOG_LEVEL := TRACE
include $(S)/build/Makefile.top
......
......@@ -29,4 +29,24 @@ Then install all relevant dependencies and their headers:
Then compile:
make RELEASE=1
make RELEASE=1 MAX_LOG_LEVEL=DBG
Running
-------
You can get inspired by the `launch` script. You need to set up iptables to
pass the relevant traffic to it through NF QUEUE. Then you need to pass the
configuration in a lua file. You can also specify how much is logged, through
the environment variables `PAKOND_STDERR_LEVEL` and `PAKOND_SYSLOG_LEVEL`.
These specify which severity (and more severe) is logged to stderr and syslog
respectively. The levels are:
- TRACE
- DBG
- INFO
- WARN
- ERROR
- FATAL
Note that what is logged is also limited by what logging is compiled in with
the `MAX_LOG_LEVEL` make option above.
• When merged with the utest branch, check that there are no additional
thread-enabled tests.
#!/bin/sh
#!/bin/bash
: ${PAKOND_STDERR_LEVEL:=DBG} ${PAKOND_SYSLOG_LEVEL:=FATAL}
export PAKOND_STDERR_LEVEL PAKOND_SYSLOG_LEVEL
iptables -A INPUT -j NFQUEUE --queue-num 0
iptables -A OUTPUT -j NFQUEUE --queue-num 1
......
......@@ -24,6 +24,7 @@ using namespace Pakon;
int main(int argc, const char *argv[]) {
try {
loggingInitialize();
MainThread thread(std::vector<std::string>(argv + 1, argv + argc));
thread.run();
return 0;
......
......@@ -19,9 +19,47 @@
#include "util.hpp"
#include <syslog.h>
#include <cstdlib>
namespace Pakon {
std::mutex logMutex;
namespace {
const int prios[] = {
[TRACE] = LOG_MAKEPRI(LOG_DAEMON, LOG_DEBUG),
[DBG] = LOG_MAKEPRI(LOG_DAEMON, LOG_DEBUG),
[INFO] = LOG_MAKEPRI(LOG_DAEMON, LOG_INFO),
[WARN] = LOG_MAKEPRI(LOG_DAEMON, LOG_WARNING),
[ERROR] = LOG_MAKEPRI(LOG_DAEMON, LOG_ERR),
[FATAL] = LOG_MAKEPRI(LOG_DAEMON, LOG_CRIT),
};
LogLevel name2Level(const char *name) {
if (!name)
name = "";
for (size_t i = 0; i < sizeof logNames / sizeof logNames[0]; i ++)
if (strcasecmp(name, logNames[i]) == 0)
return static_cast<LogLevel>(i);
// If we don't recognize it, do it at a very verbose level
return TRACE;
}
}
// This is also limited by what is compiled in with MAX_LOG_LEVEL
LogLevel maxLogLevelStderr = TRACE;
LogLevel maxLogLevelSyslog = TRACE;
void doSyslog(LogLevel level, const std::string &msg) {
syslog(prios[level], "%s", msg.c_str());
}
void loggingInitialize() {
maxLogLevelStderr = name2Level(getenv("PAKOND_STDERR_LEVEL"));
maxLogLevelSyslog = name2Level(getenv("PAKOND_SYSLOG_LEVEL"));
openlog("pakond", LOG_PID, LOG_DAEMON);
}
uint64_t timeMsec(clockid_t id) {
struct timespec ts;
......
......@@ -132,15 +132,36 @@ enum LogLevel {
FATAL
};
// Initialize logging based on environment variables.
void loggingInitialize();
#ifndef MAX_LOG_LEVEL
#define MAX_LOG_LEVEL DBG
#endif
// Allows compiling some things completely out
/*
* Is this log severity level enabled at all?
* This is a compile time configuration (though that define).
*/
constexpr bool logEnabled(LogLevel level) { return level >= MAX_LOG_LEVEL; }
extern LogLevel maxLogLevelStderr;
extern LogLevel maxLogLevelSyslog;
// Is this log severity level enabled on stderr?
static inline bool logEnabledStderr(LogLevel level) {
return level >= maxLogLevelStderr;
}
// Is this log severity level enabled on syslog?
static inline bool logEnabledSyslog(LogLevel level) {
return level >= maxLogLevelSyslog;
}
// Send this message to the syslog
void doSyslog(LogLevel level, const std::string &msg);
static const char *logNames[] = { "TRACE", "DBG", "INFO", "WARN", "ERROR", "FATAL" };
static inline const char *logName(LogLevel level) {
static const char *names[] = { "TRACE", "DBG", "INFO", "WARN", "ERROR", "FATAL" };
return names[level];
return logNames[level];
}
/*
* A bit of template magic…
......@@ -159,13 +180,34 @@ template<class Stream, class Head, class ...Tail> void logPrint(Stream &stream,
logPrint(stream, tail...);
}
template<class ...Msgs> void log(LogLevel level, const char *file, size_t line, const char *function, const Msgs &...msgs) {
if (logEnabled(level)) {
if (!logEnabled(level))
return;
/*
* Technically, this is not thread safe. It is, however, thread-safe
* to check if it was already initialized. And in the main library we do
* initialize that in the main() before starting all the threads.
*
* The trick is here to initialize logging in unit tests. They are mostly
* single-threaded, with a workaround at each multi-threaded test.
*/
static bool initialized = false;
if (!initialized)
loggingInitialize();
const bool enabledSyslog = logEnabledSyslog(level);
const bool enabledStderr = logEnabledStderr(level);
if (enabledStderr || enabledSyslog) {
// Construct the message in memory and output it at once (hopufully atomic)
std::stringstream output;
output << std::left << logName(level) << "\t" << std::setw(23) << file << std::setw(0) << "\t" << line << "\t" << std::setw(55) << function << std::setw(0) << "\t" << std::this_thread::get_id() << "\t";
logPrint(output, msgs...);
output << std::endl;
std::cerr << output.str();
const std::string &str = output.str();
if (enabledSyslog)
doSyslog(level, str);
if (enabledStderr) {
std::stringstream output_full;
output_full << std::left << logName(level) << "\t" << std::setw(23) << file << std::setw(0) << "\t" << line << "\t" << std::setw(55) << function << std::setw(0) << "\t" << std::this_thread::get_id() << "\t" << str;
std::cerr << output_full.str();
}
}
}
#define LOG(LEVEL, ...) do { log(LEVEL, __FILE__, __LINE__, __PRETTY_FUNCTION__, __VA_ARGS__); } while (0)
......
......@@ -28,7 +28,7 @@ endef
$(eval $(foreach TEST,$(TESTS),$(call DO_TEST,$(TEST))))
test-%: $(O)/bin/ctest-% FORCE
$<
PAKOND_SYSLOG_LEVEL=FATAL PAKOND_STDERR_LEVEL=FATAL $<
valgrind-%: $(O)/bin/ctest-% FORCE
IN_VALGRIND=yes $(VALGRIND) $<
PAKOND_SYSLOG_LEVEL=FATAL PAKOND_STDERR_LEVEL=FATAL IN_VALGRIND=yes $(VALGRIND) $<
......@@ -126,6 +126,7 @@ void wait(list<thread> &threads) {
* In this test we have enough space for all items to fit (but only just).
*/
template<bool keepDeleted, bool sizeLimit> void concurrentTest() {
TRC; // To initialize logging before we run threads
const bool inVal = inValgrind();
const size_t threadCount = inVal ? 2 : 10;
const size_t itemCount = inVal ? 1000 : 100000;
......@@ -201,6 +202,7 @@ BOOST_AUTO_TEST_CASE(concurrentNoLimit) {
// Not all things fit. Try stuffing them there and see that the correct ones fall out.
BOOST_AUTO_TEST_CASE(lru) {
TRC; // To initialize logging before we run threads
const bool inVal = inValgrind();
const size_t threadCount = inVal ? 2 : 10;
const size_t itemCount = inVal ? 1000 : 100000;
......
Markdown is supported
0% or .
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment