Commit 7ec4be04 authored by Dominik Charousset's avatar Dominik Charousset Committed by Dominik Charousset

Use bounded queue for the logger, cleanup code

- Use detail::ringbuffer as queue for the logger
- Limit queue size to 128 per default
- Consolidate various flags and parameters in a simple bitfield
- Re-assign log level integer values:
  * Log level QUIET is now 0
  * TRACE has now the new maximum value 15
  * Added 9 currently unused values for later extensions
- Use names, not integers for the CAF_LOG_LEVEL variable in CMake
- Remove several #ifdef-blocks in the logger implementation
  * A log level of QUIET already makes these code paths unreachable
  * Enables users to compile without CAF logging but still the logger
parent ce577346
...@@ -368,7 +368,22 @@ endif() ...@@ -368,7 +368,22 @@ endif()
################################################################################ ################################################################################
if(NOT CAF_LOG_LEVEL) if(NOT CAF_LOG_LEVEL)
set(CAF_LOG_LEVEL "-1") set(CAF_LOG_LEVEL "QUIET")
endif()
# set human-readable representation for log level
if(CAF_LOG_LEVEL STREQUAL "ERROR")
set(CAF_LOG_LEVEL_INT 3)
elseif(CAF_LOG_LEVEL STREQUAL "WARNING")
set(CAF_LOG_LEVEL_INT 6)
elseif(CAF_LOG_LEVEL STREQUAL "INFO")
set(CAF_LOG_LEVEL_INT 9)
elseif(CAF_LOG_LEVEL STREQUAL "DEBUG")
set(CAF_LOG_LEVEL_INT 12)
elseif(CAF_LOG_LEVEL STREQUAL "TRACE")
set(CAF_LOG_LEVEL_INT 15)
else()
set(CAF_LOG_LEVEL_INT 0)
endif() endif()
################################################################################ ################################################################################
...@@ -662,23 +677,6 @@ add_custom_target(gui_dummy SOURCES configure ${script_files}) ...@@ -662,23 +677,6 @@ add_custom_target(gui_dummy SOURCES configure ${script_files})
# print summary # # print summary #
################################################################################ ################################################################################
# set human-readable representation for log level
set(LOG_LEVEL_STR "none")
if(CAF_LOG_LEVEL)
if(${CAF_LOG_LEVEL} EQUAL 0)
set(LOG_LEVEL_STR "ERROR")
elseif(${CAF_LOG_LEVEL} EQUAL 1)
set(LOG_LEVEL_STR "WARNING")
elseif(${CAF_LOG_LEVEL} EQUAL 2)
set(LOG_LEVEL_STR "INFO")
elseif(${CAF_LOG_LEVEL} EQUAL 3)
set(LOG_LEVEL_STR "DEBUG")
elseif(${CAF_LOG_LEVEL} EQUAL 4)
set(LOG_LEVEL_STR "TRACE")
else()
set(LOG_LEVEL_STR "invalid")
endif()
endif()
# little helper macro to invert a boolean # little helper macro to invert a boolean
macro(invertYesNo in out) macro(invertYesNo in out)
if(${in}) if(${in})
......
...@@ -21,7 +21,7 @@ ...@@ -21,7 +21,7 @@
// this header is auto-generated by CMake // this header is auto-generated by CMake
#define CAF_LOG_LEVEL @CAF_LOG_LEVEL@ #define CAF_LOG_LEVEL @CAF_LOG_LEVEL_INT@
#cmakedefine CAF_NO_MEM_MANAGEMENT #cmakedefine CAF_NO_MEM_MANAGEMENT
......
...@@ -283,27 +283,7 @@ while [ $# -ne 0 ]; do ...@@ -283,27 +283,7 @@ while [ $# -ne 0 ]; do
;; ;;
--with-log-level=*) --with-log-level=*)
level=`echo "$optarg" | tr '[:lower:]' '[:upper:]'` level=`echo "$optarg" | tr '[:lower:]' '[:upper:]'`
case $level in append_cache_entry CAF_LOG_LEVEL STRING "$level"
ERROR)
append_cache_entry CAF_LOG_LEVEL STRING 0
;;
WARNING)
append_cache_entry CAF_LOG_LEVEL STRING 1
;;
INFO)
append_cache_entry CAF_LOG_LEVEL STRING 2
;;
DEBUG)
append_cache_entry CAF_LOG_LEVEL STRING 3
;;
TRACE)
append_cache_entry CAF_LOG_LEVEL STRING 4
;;
*)
echo "Invalid log level '$level'. Try '$0 --help' to see valid values."
exit 1
;;
esac
;; ;;
--with-clang=*) --with-clang=*)
clang="$optarg" clang="$optarg"
......
...@@ -30,22 +30,21 @@ ...@@ -30,22 +30,21 @@
#include "caf/abstract_actor.hpp" #include "caf/abstract_actor.hpp"
#include "caf/config.hpp" #include "caf/config.hpp"
#include "caf/deep_to_string.hpp" #include "caf/deep_to_string.hpp"
#include "caf/detail/arg_wrapper.hpp"
#include "caf/detail/pretty_type_name.hpp"
#include "caf/detail/ringbuffer.hpp"
#include "caf/detail/scope_guard.hpp"
#include "caf/detail/shared_spinlock.hpp"
#include "caf/fwd.hpp" #include "caf/fwd.hpp"
#include "caf/intrusive/drr_queue.hpp"
#include "caf/intrusive/fifo_inbox.hpp"
#include "caf/intrusive/singly_linked.hpp"
#include "caf/ref_counted.hpp" #include "caf/ref_counted.hpp"
#include "caf/string_view.hpp" #include "caf/string_view.hpp"
#include "caf/timestamp.hpp" #include "caf/timestamp.hpp"
#include "caf/type_nr.hpp" #include "caf/type_nr.hpp"
#include "caf/unifyn.hpp" #include "caf/unifyn.hpp"
#include "caf/intrusive/drr_queue.hpp"
#include "caf/intrusive/fifo_inbox.hpp"
#include "caf/intrusive/singly_linked.hpp"
#include "caf/detail/arg_wrapper.hpp"
#include "caf/detail/pretty_type_name.hpp"
#include "caf/detail/scope_guard.hpp"
#include "caf/detail/shared_spinlock.hpp"
/* /*
* To enable logging, you have to define CAF_DEBUG. This enables * To enable logging, you have to define CAF_DEBUG. This enables
* CAF_LOG_ERROR messages. To enable more debugging output, you can * CAF_LOG_ERROR messages. To enable more debugging output, you can
...@@ -66,16 +65,59 @@ namespace caf { ...@@ -66,16 +65,59 @@ namespace caf {
/// default, the logger generates log4j compatible output. /// default, the logger generates log4j compatible output.
class logger : public ref_counted { class logger : public ref_counted {
public: public:
// -- friends ----------------------------------------------------------------
friend class actor_system; friend class actor_system;
// -- constants --------------------------------------------------------------
/// Configures the size of the circular event queue.
static constexpr size_t queue_size = 128;
// -- member types -----------------------------------------------------------
/// Combines various logging-related flags and parameters into a bitfield.
struct config {
/// Stores `max(file_verbosity, console_verbosity)`.
unsigned verbosity : 4;
/// Configures the verbosity for file output.
unsigned file_verbosity : 4;
/// Configures the verbosity for console output.
unsigned console_verbosity : 4;
/// Configures whether the logger immediately writes its output in the
/// calling thread, bypassing its queue. Use this option only in
/// single-threaded test environments.
bool inline_output : 1;
/// Configures whether the logger generates colored output.
bool console_coloring : 1;
config();
};
/// Encapsulates a single logging event. /// Encapsulates a single logging event.
struct event : intrusive::singly_linked<event> { struct event {
// -- constructors, destructors, and assignment operators ------------------
event() = default; event() = default;
event(event&&) = default;
event(const event&) = default;
event& operator=(event&&) = default;
event& operator=(const event&) = default;
event(int lvl, string_view cat, string_view full_fun, string_view fun, event(int lvl, string_view cat, string_view full_fun, string_view fun,
string_view fn, int line, std::string msg, std::thread::id t, string_view fn, int line, std::string msg, std::thread::id t,
actor_id a, timestamp ts); actor_id a, timestamp ts);
// -- member variables -----------------------------------------------------
/// Level/priority of the event. /// Level/priority of the event.
int level; int level;
...@@ -107,37 +149,6 @@ public: ...@@ -107,37 +149,6 @@ public:
timestamp tstamp; timestamp tstamp;
}; };
struct policy {
// -- member types ---------------------------------------------------------
using mapped_type = event;
using task_size_type = long;
using deleter_type = std::default_delete<event>;
using unique_pointer = std::unique_ptr<event, deleter_type>;
using queue_type = intrusive::drr_queue<policy>;
using deficit_type = long;
// -- static member functions ----------------------------------------------
static inline void release(mapped_type* ptr) noexcept {
detail::disposer d;
d(ptr);
}
static inline task_size_type task_size(const mapped_type&) noexcept {
return 1;
}
static inline deficit_type quantum(const queue_type&, deficit_type x) {
return x;
}
};
/// Internal representation of format string entites. /// Internal representation of format string entites.
enum field_type { enum field_type {
invalid_field, invalid_field,
...@@ -196,37 +207,52 @@ public: ...@@ -196,37 +207,52 @@ public:
std::string str_; std::string str_;
}; };
/// Returns the ID of the actor currently associated to the calling thread. // -- constructors, destructors, and assignment operators --------------------
actor_id thread_local_aid();
/// Associates an actor ID to the calling thread and returns the last value.
actor_id thread_local_aid(actor_id aid);
/// Writes an entry to the log file.
void log(event* x);
~logger() override; ~logger() override;
/** @cond PRIVATE */ // -- logging ----------------------------------------------------------------
static void set_current_actor_system(actor_system*); /// Writes an entry to the event-queue of the logger.
/// @thread-safe
void log(event&& x);
static logger* current_logger(); // -- properties -------------------------------------------------------------
/// Returns the ID of the actor currently associated to the calling thread.
actor_id thread_local_aid();
bool accepts(int level, string_view cname); /// Associates an actor ID to the calling thread and returns the last value.
actor_id thread_local_aid(actor_id aid);
/** @endcond */ /// Returns whether the logger is configured to accept input for given
/// component and log level.
bool accepts(int level, string_view component_name);
/// Returns the output format used for the log file. /// Returns the output format used for the log file.
inline const line_format& file_format() const { const line_format& file_format() const {
return file_format_; return file_format_;
} }
/// Returns the output format used for the console. /// Returns the output format used for the console.
inline const line_format& console_format() const { const line_format& console_format() const {
return console_format_; return console_format_;
} }
int verbosity() const noexcept {
return static_cast<int>(cfg_.verbosity);
}
int file_verbosity() const noexcept {
return static_cast<int>(cfg_.file_verbosity);
}
int console_verbosity() const noexcept {
return static_cast<int>(cfg_.console_verbosity);
}
// -- static utility functions -----------------------------------------------
/// Renders the prefix (namespace and class) of a fully qualified function. /// Renders the prefix (namespace and class) of a fully qualified function.
static void render_fun_prefix(std::ostream& out, const event& x); static void render_fun_prefix(std::ostream& out, const event& x);
...@@ -239,9 +265,6 @@ public: ...@@ -239,9 +265,6 @@ public:
/// Renders the date of `x` in ISO 8601 format. /// Renders the date of `x` in ISO 8601 format.
static void render_date(std::ostream& out, timestamp x); static void render_date(std::ostream& out, timestamp x);
/// Renders `x` using the line format `lf` to `out`.
void render(std::ostream& out, const line_format& lf, const event& x) const;
/// Parses `format_str` into a format description vector. /// Parses `format_str` into a format description vector.
/// @warning The returned vector can have pointers into `format_str`. /// @warning The returned vector can have pointers into `format_str`.
static line_format parse_format(const std::string& format_str); static line_format parse_format(const std::string& format_str);
...@@ -249,6 +272,11 @@ public: ...@@ -249,6 +272,11 @@ public:
/// Skips path in `filename`. /// Skips path in `filename`.
static string_view skip_path(string_view filename); static string_view skip_path(string_view filename);
// -- utility functions ------------------------------------------------------
/// Renders `x` using the line format `lf` to `out`.
void render(std::ostream& out, const line_format& lf, const event& x) const;
/// Returns a string representation of the joined groups of `x` if `x` is an /// Returns a string representation of the joined groups of `x` if `x` is an
/// actor with the `subscriber` mixin. /// actor with the `subscriber` mixin.
template <class T> template <class T>
...@@ -272,30 +300,37 @@ public: ...@@ -272,30 +300,37 @@ public:
return "[]"; return "[]";
} }
// -- individual flags ------------------------------------------------------- // -- thread-local properties ------------------------------------------------
/// Stores the actor system for the current thread.
static void set_current_actor_system(actor_system*);
/// Returns the logger for the current thread or `nullptr` if none is
/// registered.
static logger* current_logger();
private:
// -- constructors, destructors, and assignment operators --------------------
static constexpr int inline_output_flag = 0x01; logger(actor_system& sys);
static constexpr int uncolored_console_flag = 0x02; // -- initialization ---------------------------------------------------------
static constexpr int colored_console_flag = 0x04; void init(actor_system_config& cfg);
// -- composed flags --------------------------------------------------------- // -- event handling ---------------------------------------------------------
static constexpr int console_output_flag = 0x06; void handle_event(const event& x);
private: void handle_file_event(const event& x);
void handle_event(event& x);
void handle_file_event(event& x); void handle_console_event(const event& x);
void handle_console_event(event& x);
void log_first_line(); void log_first_line();
void log_last_line(); void log_last_line();
logger(actor_system& sys); // -- thread management ------------------------------------------------------
void init(actor_system_config& cfg);
void run(); void run();
...@@ -303,68 +338,98 @@ private: ...@@ -303,68 +338,98 @@ private:
void stop(); void stop();
inline bool has(int flag) const noexcept { // -- member variables -------------------------------------------------------
return (flags_ & flag) != 0;
}
inline void set(int flag) noexcept { // Configures verbosity and output generation.
flags_ |= flag; config cfg_;
}
// Filters events by component name.
std::string component_filter;
// References the parent system.
actor_system& system_; actor_system& system_;
int max_level_;
int console_level_; // Guards aids_.
int file_level_;
int flags_;
detail::shared_spinlock aids_lock_; detail::shared_spinlock aids_lock_;
// Maps thread IDs to actor IDs.
std::unordered_map<std::thread::id, actor_id> aids_; std::unordered_map<std::thread::id, actor_id> aids_;
std::thread thread_;
std::mutex queue_mtx_; // Identifies the thread that called `logger::start`.
std::condition_variable queue_cv_;
intrusive::fifo_inbox<policy> queue_;
std::thread::id parent_thread_; std::thread::id parent_thread_;
// Timestamp of the first log event.
timestamp t0_; timestamp t0_;
// Format for generating file output.
line_format file_format_; line_format file_format_;
// Format for generating console output.
line_format console_format_; line_format console_format_;
// Stream for file output.
std::fstream file_; std::fstream file_;
std::string component_filter;
// Filled with log events by other threads.
detail::ringbuffer<event, 128> queue_;
// Executes `logger::run`.
std::thread thread_;
}; };
/// @relates logger::field_type
std::string to_string(logger::field_type x); std::string to_string(logger::field_type x);
/// @relates logger::field
std::string to_string(const logger::field& x); std::string to_string(const logger::field& x);
/// @relates logger::field
bool operator==(const logger::field& x, const logger::field& y); bool operator==(const logger::field& x, const logger::field& y);
} // namespace caf } // namespace caf
#define CAF_VOID_STMT static_cast<void>(0) // -- macro constants ----------------------------------------------------------
#define CAF_CAT(a, b) a##b /// Integer value for the QUIET log level.
#define CAF_LOG_LEVEL_QUIET 0
#define CAF_LOG_LEVEL_QUIET -1 /// Integer value for the ERROR log level.
#define CAF_LOG_LEVEL_ERROR 0 #define CAF_LOG_LEVEL_ERROR 3
#define CAF_LOG_LEVEL_WARNING 1
#define CAF_LOG_LEVEL_INFO 2
#define CAF_LOG_LEVEL_DEBUG 3
#define CAF_LOG_LEVEL_TRACE 4
#define CAF_ARG(argument) caf::detail::make_arg_wrapper(#argument, argument) /// Integer value for the WARNING log level.
#define CAF_LOG_LEVEL_WARNING 6
#define CAF_ARG2(argname, argval) caf::detail::make_arg_wrapper(argname, argval) /// Integer value for the INFO log level.
#define CAF_LOG_LEVEL_INFO 9
#define CAF_ARG3(argname, first, last) \ /// Integer value for the DEBUG log level.
caf::detail::make_arg_wrapper(argname, first, last) #define CAF_LOG_LEVEL_DEBUG 12
/// Integer value for the TRACE log level.
#define CAF_LOG_LEVEL_TRACE 15
/// Expands to a no-op.
#define CAF_VOID_STMT static_cast<void>(0)
#ifndef CAF_LOG_COMPONENT
/// Name of the current component when logging.
#define CAF_LOG_COMPONENT "caf"
#endif // CAF_LOG_COMPONENT
// -- utility macros -----------------------------------------------------------
#ifdef CAF_MSVC #ifdef CAF_MSVC
/// Expands to a string representation of the current funciton name that
/// includes the full function name and its signature.
#define CAF_PRETTY_FUN __FUNCSIG__ #define CAF_PRETTY_FUN __FUNCSIG__
#else // CAF_MSVC #else // CAF_MSVC
/// Expands to a string representation of the current funciton name that
/// includes the full function name and its signature.
#define CAF_PRETTY_FUN __PRETTY_FUNCTION__ #define CAF_PRETTY_FUN __PRETTY_FUNCTION__
#endif // CAF_MSVC #endif // CAF_MSVC
#ifndef CAF_LOG_COMPONENT /// Concatenates `a` and `b` to a single preprocessor token.
#define CAF_LOG_COMPONENT "caf" #define CAF_CAT(a, b) a##b
#endif // CAF_LOG_COMPONENT
#define CAF_LOG_MAKE_EVENT(aid, component, loglvl, message) \ #define CAF_LOG_MAKE_EVENT(aid, component, loglvl, message) \
::caf::logger::event { \ ::caf::logger::event { \
...@@ -374,7 +439,19 @@ bool operator==(const logger::field& x, const logger::field& y); ...@@ -374,7 +439,19 @@ bool operator==(const logger::field& x, const logger::field& y);
::std::this_thread::get_id(), aid, ::caf::make_timestamp() \ ::std::this_thread::get_id(), aid, ::caf::make_timestamp() \
} }
#if CAF_LOG_LEVEL == -1 /// Expands to `argument = <argument>` in log output.
#define CAF_ARG(argument) caf::detail::make_arg_wrapper(#argument, argument)
/// Expands to `argname = <argval>` in log output.
#define CAF_ARG2(argname, argval) caf::detail::make_arg_wrapper(argname, argval)
/// Expands to `argname = [argval, last)` in log output.
#define CAF_ARG3(argname, first, last) \
caf::detail::make_arg_wrapper(argname, first, last)
// -- logging macros -----------------------------------------------------------
#if CAF_LOG_LEVEL == CAF_LOG_LEVEL_QUIET
#define CAF_LOG_IMPL(unused1, unused2, unused3) #define CAF_LOG_IMPL(unused1, unused2, unused3)
...@@ -391,7 +468,7 @@ inline caf::actor_id caf_set_aid_dummy() { return 0; } ...@@ -391,7 +468,7 @@ inline caf::actor_id caf_set_aid_dummy() { return 0; }
#define CAF_LOG_TRACE(unused) #define CAF_LOG_TRACE(unused)
#else // CAF_LOG_LEVEL #else // CAF_LOG_LEVEL == CAF_LOG_LEVEL_QUIET
#define CAF_LOG_IMPL(component, loglvl, message) \ #define CAF_LOG_IMPL(component, loglvl, message) \
do { \ do { \
...@@ -399,8 +476,7 @@ inline caf::actor_id caf_set_aid_dummy() { return 0; } ...@@ -399,8 +476,7 @@ inline caf::actor_id caf_set_aid_dummy() { return 0; }
if (CAF_UNIFYN(caf_logger) != nullptr \ if (CAF_UNIFYN(caf_logger) != nullptr \
&& CAF_UNIFYN(caf_logger)->accepts(loglvl, component)) \ && CAF_UNIFYN(caf_logger)->accepts(loglvl, component)) \
CAF_UNIFYN(caf_logger) \ CAF_UNIFYN(caf_logger) \
->log( \ ->log(CAF_LOG_MAKE_EVENT(CAF_UNIFYN(caf_logger)->thread_local_aid(), \
new CAF_LOG_MAKE_EVENT(CAF_UNIFYN(caf_logger)->thread_local_aid(), \
component, loglvl, message)); \ component, loglvl, message)); \
} while (false) } while (false)
...@@ -458,60 +534,49 @@ inline caf::actor_id caf_set_aid_dummy() { return 0; } ...@@ -458,60 +534,49 @@ inline caf::actor_id caf_set_aid_dummy() { return 0; }
#define CAF_LOG_ERROR(output) \ #define CAF_LOG_ERROR(output) \
CAF_LOG_IMPL(CAF_LOG_COMPONENT, CAF_LOG_LEVEL_ERROR, output) CAF_LOG_IMPL(CAF_LOG_COMPONENT, CAF_LOG_LEVEL_ERROR, output)
#endif // CAF_LOG_LEVEL #endif // CAF_LOG_LEVEL == CAF_LOG_LEVEL_QUIET
#ifndef CAF_LOG_INFO #ifndef CAF_LOG_INFO
# define CAF_LOG_INFO(output) CAF_VOID_STMT #define CAF_LOG_INFO(output) CAF_VOID_STMT
#endif #define CAF_LOG_INFO_IF(cond, output) CAF_VOID_STMT
#else // CAF_LOG_INFO
#define CAF_LOG_INFO_IF(cond, output) \
if (cond) \
CAF_LOG_IMPL(CAF_LOG_COMPONENT, CAF_LOG_LEVEL_INFO, output); \
CAF_VOID_STMT
#endif // CAF_LOG_INFO
#ifndef CAF_LOG_DEBUG #ifndef CAF_LOG_DEBUG
# define CAF_LOG_DEBUG(output) CAF_VOID_STMT #define CAF_LOG_DEBUG(output) CAF_VOID_STMT
#endif #define CAF_LOG_DEBUG_IF(cond, output) CAF_VOID_STMT
#else // CAF_LOG_DEBUG
#ifndef CAF_LOG_WARNING
# define CAF_LOG_WARNING(output) CAF_VOID_STMT
#endif
#ifndef CAF_LOG_ERROR
# define CAF_LOG_ERROR(output) CAF_VOID_STMT
#endif
#ifdef CAF_LOG_LEVEL
#define CAF_LOG_DEBUG_IF(cond, output) \ #define CAF_LOG_DEBUG_IF(cond, output) \
if (cond) { \ if (cond) \
CAF_LOG_IMPL(CAF_LOG_COMPONENT, CAF_LOG_LEVEL_DEBUG, output); \ CAF_LOG_IMPL(CAF_LOG_COMPONENT, CAF_LOG_LEVEL_DEBUG, output); \
} \
CAF_VOID_STMT
#define CAF_LOG_INFO_IF(cond, output) \
if (cond) { \
CAF_LOG_IMPL(CAF_LOG_COMPONENT, CAF_LOG_LEVEL_INFO, output); \
} \
CAF_VOID_STMT CAF_VOID_STMT
#endif // CAF_LOG_DEBUG
#ifndef CAF_LOG_WARNING
#define CAF_LOG_WARNING(output) CAF_VOID_STMT
#define CAF_LOG_WARNING_IF(cond, output) CAF_VOID_STMT
#else // CAF_LOG_WARNING
#define CAF_LOG_WARNING_IF(cond, output) \ #define CAF_LOG_WARNING_IF(cond, output) \
if (cond) { \ if (cond) \
CAF_LOG_IMPL(CAF_LOG_COMPONENT, CAF_LOG_LEVEL_WARNING, output); \ CAF_LOG_IMPL(CAF_LOG_COMPONENT, CAF_LOG_LEVEL_WARNING, output); \
} \
CAF_VOID_STMT CAF_VOID_STMT
#endif // CAF_LOG_WARNING
#ifndef CAF_LOG_ERROR
#define CAF_LOG_ERROR(output) CAF_VOID_STMT
#define CAF_LOG_ERROR_IF(cond, output) CAF_VOID_STMT
#else // CAF_LOG_ERROR
#define CAF_LOG_ERROR_IF(cond, output) \ #define CAF_LOG_ERROR_IF(cond, output) \
if (cond) { \ if (cond) \
CAF_LOG_IMPL(CAF_LOG_COMPONENT, CAF_LOG_LEVEL_ERROR, output); \ CAF_LOG_IMPL(CAF_LOG_COMPONENT, CAF_LOG_LEVEL_ERROR, output); \
} \
CAF_VOID_STMT CAF_VOID_STMT
#endif // CAF_LOG_ERROR
#else // CAF_LOG_LEVEL // -- macros for logging CE-0001 events ----------------------------------------
#define CAF_LOG_DEBUG_IF(unused1, unused2)
#define CAF_LOG_INFO_IF(unused1, unused2)
#define CAF_LOG_WARNING_IF(unused1, unused2)
#define CAF_LOG_ERROR_IF(unused1, unused2)
#endif // CAF_LOG_LEVEL
// -- Standardized CAF events according to SE-0001.
/// The log component responsible for logging control flow events that are /// The log component responsible for logging control flow events that are
/// crucial for understanding happens-before relations. See RFC SE-0001. /// crucial for understanding happens-before relations. See RFC SE-0001.
......
...@@ -48,11 +48,22 @@ namespace caf { ...@@ -48,11 +48,22 @@ namespace caf {
namespace { namespace {
constexpr string_view log_level_name[] = { constexpr string_view log_level_name[] = {
"QUIET",
"",
"",
"ERROR", "ERROR",
"",
"",
"WARN", "WARN",
"",
"",
"INFO", "INFO",
"",
"",
"DEBUG", "DEBUG",
"TRACE" "",
"",
"TRACE",
}; };
constexpr string_view fun_prefixes[] = { constexpr string_view fun_prefixes[] = {
...@@ -70,6 +81,26 @@ constexpr string_view anon_ns[] = { ...@@ -70,6 +81,26 @@ constexpr string_view anon_ns[] = {
"`anonymous-namespace'", // MSVC "`anonymous-namespace'", // MSVC
}; };
/// Converts a verbosity atom to its integer counterpart.
unsigned to_level_int(atom_value x) {
switch (atom_uint(to_lowercase(x))) {
default:
return CAF_LOG_LEVEL_QUIET;
case atom_uint("quiet"):
return CAF_LOG_LEVEL_QUIET;
case atom_uint("error"):
return CAF_LOG_LEVEL_ERROR;
case atom_uint("warning"):
return CAF_LOG_LEVEL_WARNING;
case atom_uint("info"):
return CAF_LOG_LEVEL_INFO;
case atom_uint("debug"):
return CAF_LOG_LEVEL_DEBUG;
case atom_uint("trace"):
return CAF_LOG_LEVEL_TRACE;
}
}
// Reduces symbol by printing all prefixes to `out` and returning the // Reduces symbol by printing all prefixes to `out` and returning the
// remainder. For example, "ns::foo::bar" prints "ns.foo" to `out` and returns // remainder. For example, "ns::foo::bar" prints "ns.foo" to `out` and returns
// "bar". // "bar".
...@@ -214,6 +245,15 @@ inline logger* get_current_logger() { ...@@ -214,6 +245,15 @@ inline logger* get_current_logger() {
} // namespace <anonymous> } // namespace <anonymous>
logger::config::config()
: verbosity(CAF_LOG_LEVEL),
file_verbosity(CAF_LOG_LEVEL),
console_verbosity(CAF_LOG_LEVEL),
inline_output(false),
console_coloring(false) {
// nop
}
logger::event::event(int lvl, string_view cat, string_view full_fun, logger::event::event(int lvl, string_view cat, string_view full_fun,
string_view fun, string_view fn, int line, std::string msg, string_view fun, string_view fn, int line, std::string msg,
std::thread::id t, actor_id a, timestamp ts) std::thread::id t, actor_id a, timestamp ts)
...@@ -292,14 +332,12 @@ actor_id logger::thread_local_aid(actor_id aid) { ...@@ -292,14 +332,12 @@ actor_id logger::thread_local_aid(actor_id aid) {
return 0; // was empty before return 0; // was empty before
} }
void logger::log(event* x) { void logger::log(event&& x) {
CAF_ASSERT(x->level >= 0 && x->level <= 4); CAF_ASSERT(x->level >= 0 && x->level <= 4);
if (has(inline_output_flag)) { if (cfg_.inline_output)
std::unique_ptr<event> ptr{x}; handle_event(x);
handle_event(*ptr); else
} else { queue_.push_back(std::move(x));
queue_.synchronized_push_back(queue_mtx_, queue_cv_,x);
}
} }
void logger::set_current_actor_system(actor_system* x) { void logger::set_current_actor_system(actor_system* x) {
...@@ -315,7 +353,7 @@ logger* logger::current_logger() { ...@@ -315,7 +353,7 @@ logger* logger::current_logger() {
bool logger::accepts(int level, string_view cname) { bool logger::accepts(int level, string_view cname) {
CAF_ASSERT(level >= 0 && level <= 4); CAF_ASSERT(level >= 0 && level <= 4);
if (level > max_level_) if (level > cfg_.verbosity)
return false; return false;
if (!component_filter.empty()) { if (!component_filter.empty()) {
auto it = std::search(component_filter.begin(), component_filter.end(), auto it = std::search(component_filter.begin(), component_filter.end(),
...@@ -325,6 +363,10 @@ bool logger::accepts(int level, string_view cname) { ...@@ -325,6 +363,10 @@ bool logger::accepts(int level, string_view cname) {
return true; return true;
} }
logger::logger(actor_system& sys) : system_(sys) {
// nop
}
logger::~logger() { logger::~logger() {
stop(); stop();
// tell system our dtor is done // tell system our dtor is done
...@@ -333,46 +375,8 @@ logger::~logger() { ...@@ -333,46 +375,8 @@ logger::~logger() {
system_.logger_dtor_cv_.notify_one(); system_.logger_dtor_cv_.notify_one();
} }
logger::logger(actor_system& sys)
: system_(sys),
max_level_(CAF_LOG_LEVEL),
flags_(0),
queue_(policy{}) {
// nop
}
namespace {
int to_level_int(const atom_value atom) {
switch (atom_uint(atom)) {
case atom_uint("quiet"):
case atom_uint("QUIET"):
return CAF_LOG_LEVEL_QUIET;
case atom_uint("error"):
case atom_uint("ERROR"):
return CAF_LOG_LEVEL_ERROR;
case atom_uint("warning"):
case atom_uint("WARNING"):
return CAF_LOG_LEVEL_WARNING;
case atom_uint("info"):
case atom_uint("INFO"):
return CAF_LOG_LEVEL_INFO;
case atom_uint("debug"):
case atom_uint("DEBUG"):
return CAF_LOG_LEVEL_DEBUG;
case atom_uint("trace"):
case atom_uint("TRACE"):
return CAF_LOG_LEVEL_TRACE;
default: {
// nop
}
}
return CAF_LOG_LEVEL_QUIET;
}
} // namespace
void logger::init(actor_system_config& cfg) { void logger::init(actor_system_config& cfg) {
CAF_IGNORE_UNUSED(cfg); CAF_IGNORE_UNUSED(cfg);
#if CAF_LOG_LEVEL >= 0
namespace lg = defaults::logger; namespace lg = defaults::logger;
component_filter = get_or(cfg, "logger.component-filter", component_filter = get_or(cfg, "logger.component-filter",
lg::component_filter); lg::component_filter);
...@@ -383,9 +387,9 @@ void logger::init(actor_system_config& cfg) { ...@@ -383,9 +387,9 @@ void logger::init(actor_system_config& cfg) {
file_verbosity = get_or(cfg, "logger.file-verbosity", file_verbosity); file_verbosity = get_or(cfg, "logger.file-verbosity", file_verbosity);
console_verbosity = console_verbosity =
get_or(cfg, "logger.console-verbosity", console_verbosity); get_or(cfg, "logger.console-verbosity", console_verbosity);
file_level_ = to_level_int(file_verbosity); cfg_.file_verbosity = to_level_int(file_verbosity);
console_level_ = to_level_int(console_verbosity); cfg_.console_verbosity = to_level_int(console_verbosity);
max_level_ = std::max(file_level_, console_level_); cfg_.verbosity = std::max(cfg_.file_verbosity, cfg_.console_verbosity);
// Parse the format string. // Parse the format string.
file_format_ = file_format_ =
parse_format(get_or(cfg, "logger.file-format", lg::file_format)); parse_format(get_or(cfg, "logger.file-format", lg::file_format));
...@@ -393,13 +397,14 @@ void logger::init(actor_system_config& cfg) { ...@@ -393,13 +397,14 @@ void logger::init(actor_system_config& cfg) {
lg::console_format)); lg::console_format));
// Set flags. // Set flags.
if (get_or(cfg, "logger.inline-output", false)) if (get_or(cfg, "logger.inline-output", false))
set(inline_output_flag); cfg_.inline_output = true;
auto con_atm = get_or(cfg, "logger.console", lg::console); auto con_atm = get_or(cfg, "logger.console", lg::console);
if (con_atm == atom("UNCOLORED")) if (to_lowercase(con_atm) == atom("colored")) {
set(uncolored_console_flag); cfg_.console_coloring = true;
else if (con_atm == atom("COLORED")) } else if (to_lowercase(con_atm) != atom("uncolored")) {
set(colored_console_flag); // Disable console output if neither 'colored' nor 'uncolored' are present.
#endif cfg_.console_verbosity = CAF_LOG_LEVEL_QUIET;
}
} }
void logger::render_fun_prefix(std::ostream& out, const event& x) { void logger::render_fun_prefix(std::ostream& out, const event& x) {
...@@ -543,42 +548,29 @@ string_view logger::skip_path(string_view path) { ...@@ -543,42 +548,29 @@ string_view logger::skip_path(string_view path) {
} }
void logger::run() { void logger::run() {
#if CAF_LOG_LEVEL >= 0
log_first_line(); log_first_line();
// receive log entries from other threads and actors for (;;) {
bool stop = false; queue_.wait_nonempty();
auto f = [&](event& x) { auto& e = queue_.front();
// empty message means: shut down if (e.message.empty()) {
if (x.message.empty()) {
stop = true;
return intrusive::task_result::stop;
}
handle_event(x);
return intrusive::task_result::resume;
};
do {
// make sure we have data to read and consume events
queue_.synchronized_await(queue_mtx_, queue_cv_);
queue_.new_round(1000, f);
} while (!stop);
log_last_line(); log_last_line();
#endif return;
}
handle_event(e);
queue_.pop_front();
}
} }
void logger::handle_file_event(event& x) { void logger::handle_file_event(const event& x) {
// Print to file if available. // Print to file if available.
if (file_ && x.level <= file_level_) if (file_ && x.level <= file_verbosity())
render(file_, file_format_, x); render(file_, file_format_, x);
} }
void logger::handle_console_event(event& x) { void logger::handle_console_event(const event& x) {
// Stop if no console output is configured. if (x.level > console_verbosity())
if (!has(console_output_flag) || x.level > console_level_)
return; return;
if (has(uncolored_console_flag)) { if (cfg_.console_coloring) {
render(std::clog, console_format_, x);
std::clog << std::endl;
} else {
switch (x.level) { switch (x.level) {
default: default:
break; break;
...@@ -600,63 +592,50 @@ void logger::handle_console_event(event& x) { ...@@ -600,63 +592,50 @@ void logger::handle_console_event(event& x) {
} }
render(std::clog, console_format_, x); render(std::clog, console_format_, x);
std::clog << term::reset_endl; std::clog << term::reset_endl;
} else {
render(std::clog, console_format_, x);
std::clog << std::endl;
} }
} }
void logger::handle_event(event& x) { void logger::handle_event(const event& x) {
handle_file_event(x); handle_file_event(x);
handle_console_event(x); handle_console_event(x);
} }
void logger::log_first_line() { void logger::log_first_line() {
auto make_event = [&](string_view config_val, auto e = CAF_LOG_MAKE_EVENT(0, CAF_LOG_COMPONENT, CAF_LOG_LEVEL_DEBUG, "");
const atom_value default_val) -> event { auto make_message = [&](string_view config_name, atom_value default_value) {
std::string msg = "level = "; std::string msg = "level = ";
msg += to_string(get_or(system_.config(), config_val, default_val)); msg += to_string(get_or(system_.config(), config_name, default_value));
msg += ", node = "; msg += ", node = ";
msg += to_string(system_.node()); msg += to_string(system_.node());
return {CAF_LOG_LEVEL_INFO, msg += ", component_filter = ";
CAF_LOG_COMPONENT, msg += deep_to_string(component_filter);
CAF_PRETTY_FUN, return msg;
__func__,
__FILE__,
__LINE__,
std::move(msg),
std::this_thread::get_id(),
0,
make_timestamp()};
}; };
event file = make_event("logger.file-verbosity", defaults::logger::file_verbosity); namespace lg = defaults::logger;
handle_file_event(file); e.message = make_message("logger.file-verbosity", lg::file_verbosity);
event console = make_event("logger.console-verbosity", defaults::logger::console_verbosity); handle_file_event(e);
handle_console_event(console); e.message = make_message("logger.console-verbosity", lg::console_verbosity);
handle_console_event(e);
} }
void logger::log_last_line() { void logger::log_last_line() {
event tmp{CAF_LOG_LEVEL_INFO, auto e = CAF_LOG_MAKE_EVENT(0, CAF_LOG_COMPONENT, CAF_LOG_LEVEL_DEBUG, "");
CAF_LOG_COMPONENT, handle_event(e);
CAF_PRETTY_FUN,
__func__,
__FILE__,
__LINE__,
"EOF",
std::this_thread::get_id(),
0,
make_timestamp()};
handle_event(tmp);
} }
void logger::start() { void logger::start() {
#if CAF_LOG_LEVEL >= 0
parent_thread_ = std::this_thread::get_id(); parent_thread_ = std::this_thread::get_id();
if (max_level_ == CAF_LOG_LEVEL_QUIET) if (verbosity() == CAF_LOG_LEVEL_QUIET)
return; return;
t0_ = make_timestamp(); t0_ = make_timestamp();
auto f = get_or(system_.config(), "logger.file-name", auto f = get_or(system_.config(), "logger.file-name",
defaults::logger::file_name); defaults::logger::file_name);
if (f.empty()) { if (f.empty()) {
// No need to continue if console and log file are disabled. // No need to continue if console and log file are disabled.
if (has(console_output_flag)) if (console_verbosity() == CAF_LOG_LEVEL_QUIET)
return; return;
} else { } else {
// Replace placeholders. // Replace placeholders.
...@@ -685,7 +664,7 @@ void logger::start() { ...@@ -685,7 +664,7 @@ void logger::start() {
return; return;
} }
} }
if (has(inline_output_flag)) if (cfg_.inline_output)
log_first_line(); log_first_line();
else else
thread_ = std::thread{[this] { thread_ = std::thread{[this] {
...@@ -694,21 +673,18 @@ void logger::start() { ...@@ -694,21 +673,18 @@ void logger::start() {
this->run(); this->run();
this->system_.thread_terminates(); this->system_.thread_terminates();
}}; }};
#endif
} }
void logger::stop() { void logger::stop() {
#if CAF_LOG_LEVEL >= 0 if (cfg_.inline_output) {
if (has(inline_output_flag)) {
log_last_line(); log_last_line();
return; return;
} }
if (!thread_.joinable()) if (!thread_.joinable())
return; return;
// an empty string means: shut down // A default-constructed event causes the logger to shutdown.
queue_.synchronized_push_back(queue_mtx_, queue_cv_, new event); queue_.push_back(event{});
thread_.join(); thread_.join();
#endif
} }
std::string to_string(logger::field_type x) { std::string to_string(logger::field_type x) {
......
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