1
0
mirror of https://github.com/codership/wsrep-lib.git synced 2025-07-03 16:22:35 +03:00

Debug log level implementation

Debug log will now filter output based on debug level that is enabled.
This commit is contained in:
mkaruza
2019-02-12 10:44:26 +01:00
committed by Teemu Ollakka
parent 510c7f767f
commit be98517cb3
9 changed files with 131 additions and 74 deletions

View File

@ -27,6 +27,9 @@ option(WSREP_LIB_WITH_COVERAGE "Compile with coverage instrumentation" OFF)
option(WSREP_LIB_STRICT_BUILD_FLAGS "Compile with strict build flags" OFF)
option(WSREP_LIB_MAINTAINER_MODE "Fail compilation on any warnings" OFF)
# Compiler options
set(CMAKE_CXX_STANDARD 11)
# CXX flags
set(CMAKE_CXX_FLAGS "${CMAKE_CXX_FLAGS} -Wall -Wextra -Woverloaded-virtual -g")

View File

@ -674,7 +674,7 @@ namespace wsrep
int debug_log_level() const
{
return std::max(debug_log_level_,
server_state_.debug_log_level());
wsrep::log::debug_log_level());
}
//

View File

@ -25,6 +25,12 @@
#include <iosfwd>
#include <sstream>
#include <atomic>
#define WSREP_LOG_DEBUG(debug_level_fn, debug_level, msg) \
do { \
if (debug_level_fn >= debug_level) wsrep::log_debug() << msg; \
} while (0)
namespace wsrep
{
@ -39,6 +45,14 @@ namespace wsrep
error
};
enum debug_level
{
debug_level_server_state = 1,
debug_level_transaction,
debug_level_streaming,
debug_level_client_state
};
/**
* Signature for user defined logger callback function.
*/
@ -85,6 +99,17 @@ namespace wsrep
* Set user defined logger callback function.
*/
static void logger_fn(logger_fn_type);
/**
* Set debug log level from client
*/
static void debug_log_level(int debug_level);
/**
* Get current debug log level
*/
static int debug_log_level();
private:
log(const log&);
log& operator=(const log&);
@ -94,6 +119,7 @@ namespace wsrep
static wsrep::mutex& mutex_;
static std::ostream& os_;
static logger_fn_type logger_fn_;
static std::atomic_int debug_log_level_;
};
class log_error : public log

View File

@ -87,6 +87,7 @@
#include "id.hpp"
#include "view.hpp"
#include "transaction_id.hpp"
#include "logger.hpp"
#include "provider.hpp"
#include "compiler.hpp"
@ -542,17 +543,10 @@ namespace wsrep
* - 0 - No debug logging.
* - 1..n - Debug logging with increasing verbosity.
*/
void debug_log_level(int level) { debug_log_level_ = level; }
/**
*
*/
int debug_log_level() const { return debug_log_level_; }
/**
* @todo Set filter for debug logging.
*/
void debug_log_filter(const std::string&);
void debug_log_level(int level)
{
wsrep::log::debug_log_level(level);
}
wsrep::mutex& mutex() { return mutex_; }
@ -611,7 +605,6 @@ namespace wsrep
, connected_gtid_()
, current_view_()
, last_committed_gtid_()
, debug_log_level_(0)
{ }
private:
@ -701,7 +694,6 @@ namespace wsrep
wsrep::gtid connected_gtid_;
wsrep::view current_view_;
wsrep::gtid last_committed_gtid_;
int debug_log_level_;
};

View File

@ -62,12 +62,16 @@ namespace wsrep
{
if (fragment_size)
{
wsrep::log_debug() << "Enabling streaming: "
<< fragment_unit << " " << fragment_size;
WSREP_LOG_DEBUG(wsrep::log::debug_log_level(),
wsrep::log::debug_level_streaming,
"Enabling streaming: "
<< fragment_unit << " " << fragment_size);
}
else
{
wsrep::log_debug() << "Disabling streaming";
WSREP_LOG_DEBUG(wsrep::log::debug_log_level(),
wsrep::log::debug_level_streaming,
"Disabling streaming");
}
fragment_unit_ = fragment_unit;
fragment_size_ = fragment_size;
@ -76,8 +80,10 @@ namespace wsrep
void enable(enum fragment_unit fragment_unit, size_t fragment_size)
{
wsrep::log_debug() << "Enabling streaming: "
<< fragment_unit << " " << fragment_size;
WSREP_LOG_DEBUG(wsrep::log::debug_log_level(),
wsrep::log::debug_level_streaming,
"Enabling streaming: "
<< fragment_unit << " " << fragment_size);
assert(fragment_size > 0);
fragment_unit_ = fragment_unit;
fragment_size_ = fragment_size;
@ -89,7 +95,9 @@ namespace wsrep
void disable()
{
wsrep::log_debug() << "Disabling streaming";
WSREP_LOG_DEBUG(wsrep::log::debug_log_level(),
wsrep::log::debug_level_streaming,
"Disabling streaming");
fragment_size_ = 0;
}

View File

@ -454,15 +454,15 @@ void wsrep::client_state::update_last_written_gtid(const wsrep::gtid& gtid)
void wsrep::client_state::debug_log_state(const char* context) const
{
if (debug_log_level() >= 1)
{
wsrep::log_debug() << context
WSREP_LOG_DEBUG(debug_log_level(),
wsrep::log::debug_level_client_state,
context
<< "(" << id_.get()
<< "," << to_c_string(state_)
<< "," << to_c_string(mode_)
<< "," << wsrep::to_string(current_error_)
<< ")";
}
<< ")");
}
void wsrep::client_state::state(

View File

@ -25,8 +25,19 @@ std::ostream& wsrep::log::os_ = std::cout;
static wsrep::default_mutex log_mutex_;
wsrep::mutex& wsrep::log::mutex_ = log_mutex_;
wsrep::log::logger_fn_type wsrep::log::logger_fn_ = 0;
std::atomic_int wsrep::log::debug_log_level_(0);
void wsrep::log::logger_fn(wsrep::log::logger_fn_type logger_fn)
{
logger_fn_ = logger_fn;
}
void wsrep::log::debug_log_level(int debug_log_level)
{
debug_log_level_.store(debug_log_level, std::memory_order_relaxed);
}
int wsrep::log::debug_log_level()
{
return debug_log_level_.load(std::memory_order_relaxed);
}

View File

@ -31,6 +31,7 @@
#include <sstream>
#include <algorithm>
//////////////////////////////////////////////////////////////////////////////
// Helpers //
//////////////////////////////////////////////////////////////////////////////
@ -168,10 +169,11 @@ static int apply_write_set(wsrep::server_state& server_state,
// may be delivered here. The message below has
// been intentionally turned into a debug message,
// rather than warning.
wsrep::log_debug()
<< "Could not find applier context for "
WSREP_LOG_DEBUG(wsrep::log::debug_log_level(),
wsrep::log::debug_level_server_state,
"Could not find applier context for "
<< ws_meta.server_id()
<< ": " << ws_meta.transaction_id();
<< ": " << ws_meta.transaction_id());
ret = high_priority_service.log_dummy_write_set(
ws_handle, ws_meta);
}
@ -435,7 +437,9 @@ wsrep::seqno wsrep::server_state::desync_and_pause()
// communicate with the rest of the cluster. However, this
// error can be tolerated because if the provider can be
// paused succesfully below.
wsrep::log_debug() << "Failed to desync server before pause";
WSREP_LOG_DEBUG(wsrep::log::debug_log_level(),
wsrep::log::debug_level_server_state,
"Failed to desync server before pause");
desync_successful = false;
}
else
@ -967,7 +971,9 @@ void wsrep::server_state::start_streaming_client(
wsrep::client_state* client_state)
{
wsrep::unique_lock<wsrep::mutex> lock(mutex_);
wsrep::log_debug() << "Start streaming client: " << client_state->id();
WSREP_LOG_DEBUG(wsrep::log::debug_log_level(),
wsrep::log::debug_level_server_state,
"Start streaming client: " << client_state->id());
if (streaming_clients_.insert(
std::make_pair(client_state->id(), client_state)).second == false)
{
@ -981,8 +987,10 @@ void wsrep::server_state::convert_streaming_client_to_applier(
wsrep::client_state* client_state)
{
wsrep::unique_lock<wsrep::mutex> lock(mutex_);
wsrep::log_debug() << "Convert streaming client to applier "
<< client_state->id();
WSREP_LOG_DEBUG(wsrep::log::debug_log_level(),
wsrep::log::debug_level_server_state,
"Convert streaming client to applier "
<< client_state->id());
streaming_clients_map::iterator i(
streaming_clients_.find(client_state->id()));
assert(i != streaming_clients_.end());
@ -1027,7 +1035,9 @@ void wsrep::server_state::stop_streaming_client(
wsrep::client_state* client_state)
{
wsrep::unique_lock<wsrep::mutex> lock(mutex_);
wsrep::log_debug() << "Stop streaming client: " << client_state->id();
WSREP_LOG_DEBUG(wsrep::log::debug_log_level(),
wsrep::log::debug_level_server_state,
"Stop streaming client: " << client_state->id());
streaming_clients_map::iterator i(
streaming_clients_.find(client_state->id()));
assert(i != streaming_clients_.end());
@ -1157,9 +1167,11 @@ void wsrep::server_state::state(
assert(0);
}
wsrep::log_debug() << "server " << name_ << " state change: "
WSREP_LOG_DEBUG(wsrep::log::debug_log_level(),
wsrep::log::debug_level_server_state,
"server " << name_ << " state change: "
<< to_c_string(state_) << " -> "
<< to_c_string(state);
<< to_c_string(state));
state_hist_.push_back(state_);
server_service_.log_state_change(state_, state);
state_ = state;
@ -1255,9 +1267,11 @@ void wsrep::server_state::close_orphaned_sr_transactions(
server_id_cmp(i->first.first)) ==
current_view_.members().end())
{
wsrep::log_debug() << "Removing SR fragments for "
WSREP_LOG_DEBUG(wsrep::log::debug_log_level(),
wsrep::log::debug_level_server_state,
"Removing SR fragments for "
<< i->first.first
<< ", " << i->first.second;
<< ", " << i->first.second);
wsrep::id server_id(i->first.first);
wsrep::transaction_id transaction_id(i->first.second);
wsrep::high_priority_service* streaming_applier(i->second);

View File

@ -29,14 +29,6 @@
#include <sstream>
#include <memory>
#define WSREP_TC_LOG_DEBUG(level, msg) \
do { \
if (client_state_.debug_log_level() < level) \
{ } \
else wsrep::log_debug() << msg; \
} while (0)
namespace
{
class storage_service_deleter
@ -824,7 +816,9 @@ bool wsrep::transaction::bf_abort(
if (active() == false)
{
WSREP_TC_LOG_DEBUG(1, "Transaction not active, skipping bf abort");
WSREP_LOG_DEBUG(client_state_.debug_log_level(),
wsrep::log::debug_level_transaction,
"Transaction not active, skipping bf abort");
}
else
{
@ -842,7 +836,9 @@ bool wsrep::transaction::bf_abort(
switch (status)
{
case wsrep::provider::success:
WSREP_TC_LOG_DEBUG(1, "Seqno " << bf_seqno
WSREP_LOG_DEBUG(client_state_.debug_log_level(),
wsrep::log::debug_level_transaction,
"Seqno " << bf_seqno
<< " succesfully BF aborted " << id_
<< " victim_seqno " << victim_seqno);
bf_abort_state_ = state();
@ -850,7 +846,8 @@ bool wsrep::transaction::bf_abort(
ret = true;
break;
default:
WSREP_TC_LOG_DEBUG(1,
WSREP_LOG_DEBUG(client_state_.debug_log_level(),
wsrep::log::debug_level_transaction,
"Seqno " << bf_seqno
<< " failed to BF abort " << id_
<< " with status " << status
@ -860,7 +857,9 @@ bool wsrep::transaction::bf_abort(
break;
}
default:
WSREP_TC_LOG_DEBUG(1, "BF abort not allowed in state "
WSREP_LOG_DEBUG(client_state_.debug_log_level(),
wsrep::log::debug_level_transaction,
"BF abort not allowed in state "
<< wsrep::to_string(state()));
break;
}
@ -937,13 +936,13 @@ void wsrep::transaction::state(
wsrep::unique_lock<wsrep::mutex>& lock __attribute__((unused)),
enum wsrep::transaction::state next_state)
{
if (client_state_.debug_log_level() >= 1)
{
log_debug() << "client: " << client_state_.id().get()
WSREP_LOG_DEBUG(client_state_.debug_log_level(),
wsrep::log::debug_level_transaction,
"client: " << client_state_.id().get()
<< " txc: " << id().get()
<< " state: " << to_string(state_)
<< " -> " << to_string(next_state);
}
<< " -> " << to_string(next_state));
assert(lock.owns_lock());
// BF aborter is allowed to change the state to must abort and
// further to aborting and aborted if the background rollbacker
@ -1524,8 +1523,10 @@ void wsrep::transaction::cleanup()
void wsrep::transaction::debug_log_state(
const char* context) const
{
WSREP_TC_LOG_DEBUG(
1, context
WSREP_LOG_DEBUG(
client_state_.debug_log_level(),
wsrep::log::debug_level_transaction,
context
<< "\n server: " << server_id_
<< ", client: " << int64_t(client_state_.id().get())
<< ", state: " << wsrep::to_c_string(client_state_.state())
@ -1554,7 +1555,9 @@ void wsrep::transaction::debug_log_state(
void wsrep::transaction::debug_log_key_append(const wsrep::key& key)
{
WSREP_TC_LOG_DEBUG(2, "key_append"
WSREP_LOG_DEBUG(client_state_.debug_log_level(),
wsrep::log::debug_level_transaction,
"key_append: "
<< "trx_id: "
<< int64_t(id().get())
<< " append key: " << key);