Commit a4aa1c36 authored by Dominik Charousset's avatar Dominik Charousset

Implement format strings for log output

parent a0462d6c
...@@ -47,3 +47,18 @@ max-consecutive-reads=50 ...@@ -47,3 +47,18 @@ max-consecutive-reads=50
heartbeat-interval=0 heartbeat-interval=0
; configures whether the MM detaches its internal utility actors ; configures whether the MM detaches its internal utility actors
middleman-detach-utility-actors=true middleman-detach-utility-actors=true
; when compiling with logging enabled
[logger]
; file name template for output log file files (empty string disables logging)
file-name="actor_log_[PID]_[TIMESTAMP]_[NODE].log"
; format for rendering individual log file entries
file-format="%r %c %p %a %t %C %M %F:%L %m%n"
; mode for console log output generation (none|colored|uncolored)
console='none'
; format for printing individual log entries to the console
console-format="%m"
; excludes listed components from logging
component-filter=""
; configures the severity level for logs (quiet|error|warning|info|debug|trace)
verbosity='trace'
...@@ -72,6 +72,7 @@ set (LIBCAF_CORE_SRCS ...@@ -72,6 +72,7 @@ set (LIBCAF_CORE_SRCS
src/node_id.cpp src/node_id.cpp
src/outgoing_stream_multiplexer.cpp src/outgoing_stream_multiplexer.cpp
src/parse_ini.cpp src/parse_ini.cpp
src/pretty_type_name.cpp
src/private_thread.cpp src/private_thread.cpp
src/proxy_registry.cpp src/proxy_registry.cpp
src/pull5.cpp src/pull5.cpp
......
...@@ -266,10 +266,17 @@ public: ...@@ -266,10 +266,17 @@ public:
// -- config parameters for the logger --------------------------------------- // -- config parameters for the logger ---------------------------------------
std::string logger_filename; std::string logger_file_name;
atom_value logger_verbosity; std::string logger_file_format;
atom_value logger_console; atom_value logger_console;
std::string logger_filter; std::string logger_console_format;
std::string logger_component_filter;
atom_value logger_verbosity;
// -- backward compatibility -------------------------------------------------
std::string& logger_filename CAF_DEPRECATED = logger_file_name;
std::string& logger_filter CAF_DEPRECATED = logger_component_filter;
// -- config parameters of the middleman ------------------------------------- // -- config parameters of the middleman -------------------------------------
......
...@@ -48,6 +48,19 @@ constexpr atom_value atom(char const (&str)[Size]) { ...@@ -48,6 +48,19 @@ constexpr atom_value atom(char const (&str)[Size]) {
return static_cast<atom_value>(detail::atom_val(str)); return static_cast<atom_value>(detail::atom_val(str));
} }
/// Creates an atom from given string literal and return an integer
/// representation of the atom..
template <size_t Size>
constexpr uint64_t atom_uint(char const (&str)[Size]) {
static_assert(Size <= 11, "only 10 characters are allowed");
return detail::atom_val(str);
}
/// Converts an atom to its integer representation.
constexpr uint64_t atom_uint(atom_value x) {
return static_cast<uint64_t>(x);
}
/// Lifts an `atom_value` to a compile-time constant. /// Lifts an `atom_value` to a compile-time constant.
template <atom_value V> template <atom_value V>
struct atom_constant { struct atom_constant {
...@@ -155,24 +168,6 @@ using migrate_atom = atom_constant<atom("migrate")>; ...@@ -155,24 +168,6 @@ using migrate_atom = atom_constant<atom("migrate")>;
/// Used for triggering periodic operations. /// Used for triggering periodic operations.
using tick_atom = atom_constant<atom("tick")>; using tick_atom = atom_constant<atom("tick")>;
/// Used as config parameter for the `logger`.
using trace_log_lvl_atom = atom_constant<atom("TRACE")>;
/// Used as config parameter for the `logger`.
using debug_log_lvl_atom = atom_constant<atom("DEBUG")>;
/// Used as config parameter for the `logger`.
using info_log_lvl_atom = atom_constant<atom("INFO")>;
/// Used as config parameter for the `logger`.
using warning_log_lvl_atom = atom_constant<atom("WARNING")>;
/// Used as config parameter for the `logger`.
using error_log_lvl_atom = atom_constant<atom("ERROR")>;
/// Used as config parameter for the `logger`.
using quiet_log_lvl_atom = atom_constant<atom("QUIET")>;
} // namespace caf } // namespace caf
namespace std { namespace std {
......
/******************************************************************************
* ____ _ _____ *
* / ___| / \ | ___| C++ *
* | | / _ \ | |_ Actor *
* | |___ / ___ \| _| Framework *
* \____/_/ \_|_| *
* *
* Copyright (C) 2011 - 2017 *
* Dominik Charousset <dominik.charousset (at) haw-hamburg.de> *
* *
* Distributed under the terms and conditions of the BSD 3-Clause License or *
* (at your option) under the terms and conditions of the Boost Software *
* License 1.0. See accompanying files LICENSE and LICENSE_ALTERNATIVE. *
* *
* If you did not receive a copy of the license files, see *
* http://opensource.org/licenses/BSD-3-Clause and *
* http://www.boost.org/LICENSE_1_0.txt. *
******************************************************************************/
// The rationale of this header is to provide a serialization API
// that is compatbile to boost.serialization. In particular, the
// design goals are:
// - allow users to integrate existing boost.serialization-based code easily
// - allow to switch out this header with the actual boost header in boost.actor
//
// Differences in semantics are:
// - CAF does *not* respect class versions
// - the `unsigned int` argument is always 0 and ignored by CAF
//
// Since CAF requires all runtime instances to have the same types
// announced, different class versions in a single actor system would
// cause inconsistencies that are not recoverable.
#ifndef CAF_DETAIL_PRETTY_TYPE_NAME_HPP
#define CAF_DETAIL_PRETTY_TYPE_NAME_HPP
#include <string>
#include <typeinfo>
namespace caf {
namespace detail {
void prettify_type_name(std::string& class_name);
void prettify_type_name(std::string& class_name, const char* input_class_name);
std::string pretty_type_name(const std::type_info& x);
} // namespace detail
} // namespace caf
#endif // CAF_DETAIL_PRETTY_TYPE_NAME_HPP
...@@ -32,6 +32,7 @@ ...@@ -32,6 +32,7 @@
#include "caf/config.hpp" #include "caf/config.hpp"
#include "caf/unifyn.hpp" #include "caf/unifyn.hpp"
#include "caf/type_nr.hpp" #include "caf/type_nr.hpp"
#include "caf/timestamp.hpp"
#include "caf/ref_counted.hpp" #include "caf/ref_counted.hpp"
#include "caf/abstract_actor.hpp" #include "caf/abstract_actor.hpp"
#include "caf/deep_to_string.hpp" #include "caf/deep_to_string.hpp"
...@@ -62,15 +63,59 @@ class logger : public ref_counted { ...@@ -62,15 +63,59 @@ class logger : public ref_counted {
public: public:
friend class actor_system; friend class actor_system;
/// Encapsulates a single logging event.
struct event { struct event {
/// Intrusive pointer to the next logging event.
event* next; event* next;
/// Intrusive pointer to the previous logging event.
event* prev; event* prev;
/// Level/priority of the event.
int level; int level;
std::string prefix; /// Name of the category (component) logging the event.
std::string msg; const char* category_name;
explicit event(int lvl = 0, std::string pfx = "", std::string msg = ""); /// Name of the current context as reported by `__PRETTY_FUNCTION__`.
const char* pretty_fun;
/// Name of the current file.
const char* file_name;
/// Current line in the file.
int line_number;
/// User-provided message.
std::string message;
/// Thread ID of the caller.
std::thread::id tid;
/// Actor ID of the caller.
actor_id aid;
/// Timestamp of the event.
timestamp tstamp;
}; };
/// Internal representation of format string entites.
enum field_type {
invalid_field,
category_field,
class_name_field,
date_field,
file_field,
line_field,
message_field,
method_field,
newline_field,
priority_field,
runtime_field,
thread_field,
actor_field,
percent_sign_field,
plain_text_field
};
struct field {
field_type kind;
const char* first;
const char* last;
};
using line_format = std::vector<field>;
template <class T> template <class T>
struct arg_wrapper { struct arg_wrapper {
const char* name; const char* name;
...@@ -124,13 +169,6 @@ public: ...@@ -124,13 +169,6 @@ public:
bool behind_arg_; bool behind_arg_;
}; };
static std::string extract_class_name(const char* prettyfun, size_t strsize);
template <size_t N>
static std::string extract_class_name(const char (&prettyfun)[N]) {
return extract_class_name(prettyfun, N);
}
/// Returns the ID of the actor currently associated to the calling thread. /// Returns the ID of the actor currently associated to the calling thread.
actor_id thread_local_aid(); actor_id thread_local_aid();
...@@ -138,9 +176,7 @@ public: ...@@ -138,9 +176,7 @@ public:
actor_id thread_local_aid(actor_id aid); actor_id thread_local_aid(actor_id aid);
/// Writes an entry to the log file. /// Writes an entry to the log file.
void log(int level, const char* component, const std::string& class_name, void log(event* x);
const char* function_name, const char* c_full_file_name,
int line_num, const std::string& msg);
~logger() override; ~logger() override;
...@@ -150,16 +186,42 @@ public: ...@@ -150,16 +186,42 @@ public:
static logger* current_logger(); static logger* current_logger();
static void log_static(int level, const char* component, bool accepts(int level, const char* cname_begin, const char* cname_end);
const std::string& class_name,
const char* function_name,
const char* file_name, int line_num,
const std::string& msg);
static bool accepts(int level, const char* component); template <size_t N>
bool accepts(int level, const char (&component)[N]) {
return accepts(level, component, component + N);
}
/** @endcond */ /** @endcond */
inline const line_format& file_format() const {
return file_format_;
}
inline const line_format& console_format() const {
return console_format_;
}
/// Renders the prefix (namespace and class) of a fully qualified function.
static void render_fun_prefix(std::ostream& out, const char* pretty_fun);
/// Renders the name of a fully qualified function.
static void render_fun_name(std::ostream& out, const char* pretty_fun);
/// Renders the difference between `t0` and `tn` in milliseconds.
static void render_time_diff(std::ostream& out, timestamp t0, timestamp tn);
/// Renders the date of `x` in ISO 8601 format.
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.
/// @warning The returned vector can have pointers into `format_str`.
static line_format parse_format(const char* format_str);
private: private:
logger(actor_system& sys); logger(actor_system& sys);
...@@ -171,11 +233,6 @@ private: ...@@ -171,11 +233,6 @@ private:
void stop(); void stop();
void log_prefix(std::ostream& out, int level, const char* component,
const std::string& class_name, const char* function_name,
const char* c_full_file_name, int line_num,
const std::thread::id& tid = std::this_thread::get_id());
actor_system& system_; actor_system& system_;
int level_; int level_;
detail::shared_spinlock aids_lock_; detail::shared_spinlock aids_lock_;
...@@ -185,8 +242,17 @@ private: ...@@ -185,8 +242,17 @@ private:
std::condition_variable queue_cv_; std::condition_variable queue_cv_;
detail::single_reader_queue<event> queue_; detail::single_reader_queue<event> queue_;
std::thread::id parent_thread_; std::thread::id parent_thread_;
timestamp t0_;
line_format file_format_;
line_format console_format_;
}; };
std::string to_string(logger::field_type x);
std::string to_string(const logger::field& x);
bool operator==(const logger::field& x, const logger::field& y);
} // namespace caf } // namespace caf
#define CAF_VOID_STMT static_cast<void>(0) #define CAF_VOID_STMT static_cast<void>(0)
...@@ -202,9 +268,9 @@ private: ...@@ -202,9 +268,9 @@ private:
#define CAF_ARG(argument) caf::logger::make_arg_wrapper(#argument, argument) #define CAF_ARG(argument) caf::logger::make_arg_wrapper(#argument, argument)
#ifdef CAF_MSVC #ifdef CAF_MSVC
#define CAF_GET_CLASS_NAME caf::logger::extract_class_name(__FUNCSIG__) #define CAF_PRETTY_FUN __FUNCSIG__
#else // CAF_MSVC #else // CAF_MSVC
#define CAF_GET_CLASS_NAME caf::logger::extract_class_name(__PRETTY_FUNCTION__) #define CAF_PRETTY_FUN __PRETTY_FUNCTION__
#endif // CAF_MSVC #endif // CAF_MSVC
#ifndef CAF_LOG_LEVEL #ifndef CAF_LOG_LEVEL
...@@ -226,19 +292,23 @@ inline caf::actor_id caf_set_aid_dummy() { return 0; } ...@@ -226,19 +292,23 @@ inline caf::actor_id caf_set_aid_dummy() { return 0; }
#else // CAF_LOG_LEVEL #else // CAF_LOG_LEVEL
#define CAF_DEFAULT_LOG_COMPONENT "caf"
#ifndef CAF_LOG_COMPONENT #ifndef CAF_LOG_COMPONENT
#define CAF_LOG_COMPONENT CAF_DEFAULT_LOG_COMPONENT #define CAF_LOG_COMPONENT "caf"
#endif #endif // CAF_LOG_COMPONENT
#define CAF_LOG_IMPL(component, loglvl, message) \ #define CAF_LOG_IMPL(component, loglvl, message) \
do { \ do { \
if (caf::logger::accepts(loglvl, component)) \ auto CAF_UNIFYN(caf_logger) = caf::logger::current_logger(); \
caf::logger::log_static(loglvl, component, CAF_GET_CLASS_NAME, \ if (CAF_UNIFYN(caf_logger) != nullptr \
__func__, __FILE__, __LINE__, \ && CAF_UNIFYN(caf_logger)->accepts(loglvl, component)) \
(caf::logger::line_builder{} << message).get()); \ CAF_UNIFYN(caf_logger) \
} while (0) ->log(new ::caf::logger::event{ \
nullptr, nullptr, loglvl, component, CAF_PRETTY_FUN, __FILE__, \
__LINE__, (::caf::logger::line_builder{} << message).get(), \
::std::this_thread::get_id(), \
CAF_UNIFYN(caf_logger)->thread_local_aid(), \
::caf::make_timestamp()}); \
} while (false)
#define CAF_PUSH_AID(aarg) \ #define CAF_PUSH_AID(aarg) \
auto CAF_UNIFYN(caf_tmp_ptr) = caf::logger::current_logger(); \ auto CAF_UNIFYN(caf_tmp_ptr) = caf::logger::current_logger(); \
...@@ -269,30 +339,25 @@ inline caf::actor_id caf_set_aid_dummy() { return 0; } ...@@ -269,30 +339,25 @@ inline caf::actor_id caf_set_aid_dummy() { return 0; }
#else // CAF_LOG_LEVEL < CAF_LOG_LEVEL_TRACE #else // CAF_LOG_LEVEL < CAF_LOG_LEVEL_TRACE
#define CAF_LOG_TRACE(entry_message) \ #define CAF_LOG_TRACE(entry_message) \
const char* CAF_UNIFYN(func_name_) = __func__; \
CAF_LOG_IMPL(CAF_LOG_COMPONENT, CAF_LOG_LEVEL_TRACE, \ CAF_LOG_IMPL(CAF_LOG_COMPONENT, CAF_LOG_LEVEL_TRACE, \
"ENTRY" << entry_message); \ "ENTRY" << entry_message); \
auto CAF_UNIFYN(caf_log_trace_guard_) = ::caf::detail::make_scope_guard([=] {\ auto CAF_UNIFYN(caf_log_trace_guard_) = ::caf::detail::make_scope_guard( \
if (caf::logger::accepts(CAF_LOG_LEVEL_TRACE, CAF_LOG_COMPONENT)) \ [=] { CAF_LOG_IMPL(CAF_LOG_COMPONENT, CAF_LOG_LEVEL_TRACE, "EXIT"); })
caf::logger::log_static(CAF_LOG_LEVEL_TRACE, CAF_LOG_COMPONENT, \
CAF_GET_CLASS_NAME, CAF_UNIFYN(func_name_), \
__FILE__, __LINE__, "EXIT"); \
})
#endif // CAF_LOG_LEVEL < CAF_LOG_LEVEL_TRACE #endif // CAF_LOG_LEVEL < CAF_LOG_LEVEL_TRACE
#if CAF_LOG_LEVEL >= CAF_LOG_LEVEL_DEBUG #if CAF_LOG_LEVEL >= CAF_LOG_LEVEL_DEBUG
# define CAF_LOG_DEBUG(output) \ #define CAF_LOG_DEBUG(output) \
CAF_LOG_IMPL(CAF_LOG_COMPONENT, CAF_LOG_LEVEL_DEBUG, output) CAF_LOG_IMPL(CAF_LOG_COMPONENT, CAF_LOG_LEVEL_DEBUG, output)
#endif #endif
#if CAF_LOG_LEVEL >= CAF_LOG_LEVEL_INFO #if CAF_LOG_LEVEL >= CAF_LOG_LEVEL_INFO
# define CAF_LOG_INFO(output) \ #define CAF_LOG_INFO(output) \
CAF_LOG_IMPL(CAF_LOG_COMPONENT, CAF_LOG_LEVEL_INFO, output) CAF_LOG_IMPL(CAF_LOG_COMPONENT, CAF_LOG_LEVEL_INFO, output)
#endif #endif
#if CAF_LOG_LEVEL >= CAF_LOG_LEVEL_WARNING #if CAF_LOG_LEVEL >= CAF_LOG_LEVEL_WARNING
# define CAF_LOG_WARNING(output) \ #define CAF_LOG_WARNING(output) \
CAF_LOG_IMPL(CAF_LOG_COMPONENT, CAF_LOG_LEVEL_WARNING, output) CAF_LOG_IMPL(CAF_LOG_COMPONENT, CAF_LOG_LEVEL_WARNING, output)
#endif #endif
...@@ -320,19 +385,27 @@ inline caf::actor_id caf_set_aid_dummy() { return 0; } ...@@ -320,19 +385,27 @@ inline caf::actor_id caf_set_aid_dummy() { return 0; }
#ifdef CAF_LOG_LEVEL #ifdef CAF_LOG_LEVEL
#define CAF_LOG_DEBUG_IF(cond, output) \ #define CAF_LOG_DEBUG_IF(cond, output) \
if (cond) { CAF_LOG_IMPL(CAF_LOG_COMPONENT, CAF_LOG_LEVEL_DEBUG, output); } \ if (cond) { \
CAF_LOG_IMPL(CAF_LOG_COMPONENT, CAF_LOG_LEVEL_DEBUG, output); \
} \
CAF_VOID_STMT CAF_VOID_STMT
#define CAF_LOG_INFO_IF(cond, output) \ #define CAF_LOG_INFO_IF(cond, output) \
if (cond) { CAF_LOG_IMPL(CAF_LOG_COMPONENT, CAF_LOG_LEVEL_INFO, output); } \ if (cond) { \
CAF_LOG_IMPL(CAF_LOG_COMPONENT, CAF_LOG_LEVEL_INFO, output); \
} \
CAF_VOID_STMT CAF_VOID_STMT
#define CAF_LOG_WARNING_IF(cond, output) \ #define CAF_LOG_WARNING_IF(cond, output) \
if (cond) { CAF_LOG_IMPL(CAF_LOG_COMPONENT, CAF_LOG_LEVEL_WARNING, output); }\ if (cond) { \
CAF_LOG_IMPL(CAF_LOG_COMPONENT, CAF_LOG_LEVEL_WARNING, output); \
} \
CAF_VOID_STMT CAF_VOID_STMT
#define CAF_LOG_ERROR_IF(cond, output) \ #define CAF_LOG_ERROR_IF(cond, output) \
if (cond) { CAF_LOG_IMPL(CAF_LOG_COMPONENT, CAF_LOG_LEVEL_ERROR, output); } \ if (cond) { \
CAF_LOG_IMPL(CAF_LOG_COMPONENT, CAF_LOG_LEVEL_ERROR, output); \
} \
CAF_VOID_STMT CAF_VOID_STMT
#else // CAF_LOG_LEVEL #else // CAF_LOG_LEVEL
...@@ -346,20 +419,21 @@ inline caf::actor_id caf_set_aid_dummy() { return 0; } ...@@ -346,20 +419,21 @@ inline caf::actor_id caf_set_aid_dummy() { return 0; }
// -- Standardized CAF events according to SE-0001. // -- Standardized CAF events according to SE-0001.
#define CAF_LOG_EVENT_COMPONENT "se-0001" /// The log component responsible for logging control flow events that are
/// crucial for understanding happens-before relations. See RFC SE-0001.
#define CAF_LOG_FLOW_COMPONENT "caf.flow"
#define CAF_LOG_SPAWN_EVENT(aid, aargs) \ #define CAF_LOG_SPAWN_EVENT(aid, aargs) \
CAF_LOG_IMPL(CAF_LOG_EVENT_COMPONENT, CAF_LOG_LEVEL_DEBUG, \ CAF_LOG_IMPL(CAF_LOG_FLOW_COMPONENT, CAF_LOG_LEVEL_DEBUG, \
"SPAWN ; ID =" << aid \ "SPAWN ; ID =" << aid \
<< "; ARGS =" << deep_to_string(aargs).c_str()) << "; ARGS =" << deep_to_string(aargs).c_str())
#define CAF_LOG_INIT_EVENT(aName, aHide) \ #define CAF_LOG_INIT_EVENT(aName, aHide) \
CAF_LOG_IMPL(CAF_LOG_EVENT_COMPONENT, CAF_LOG_LEVEL_DEBUG, \ CAF_LOG_IMPL(CAF_LOG_FLOW_COMPONENT, CAF_LOG_LEVEL_DEBUG, \
"INIT ; NAME =" << aName << "; HIDDEN =" << aHide) "INIT ; NAME =" << aName << "; HIDDEN =" << aHide)
/// Logs
#define CAF_LOG_SEND_EVENT(ptr) \ #define CAF_LOG_SEND_EVENT(ptr) \
CAF_LOG_IMPL(CAF_LOG_EVENT_COMPONENT, CAF_LOG_LEVEL_DEBUG, \ CAF_LOG_IMPL(CAF_LOG_FLOW_COMPONENT, CAF_LOG_LEVEL_DEBUG, \
"SEND ; TO =" \ "SEND ; TO =" \
<< deep_to_string(strong_actor_ptr{this->ctrl()}).c_str() \ << deep_to_string(strong_actor_ptr{this->ctrl()}).c_str() \
<< "; FROM =" << deep_to_string(ptr->sender).c_str() \ << "; FROM =" << deep_to_string(ptr->sender).c_str() \
...@@ -367,29 +441,29 @@ inline caf::actor_id caf_set_aid_dummy() { return 0; } ...@@ -367,29 +441,29 @@ inline caf::actor_id caf_set_aid_dummy() { return 0; }
<< "; CONTENT =" << deep_to_string(ptr->content()).c_str()) << "; CONTENT =" << deep_to_string(ptr->content()).c_str())
#define CAF_LOG_RECEIVE_EVENT(ptr) \ #define CAF_LOG_RECEIVE_EVENT(ptr) \
CAF_LOG_IMPL(CAF_LOG_EVENT_COMPONENT, CAF_LOG_LEVEL_DEBUG, \ CAF_LOG_IMPL(CAF_LOG_FLOW_COMPONENT, CAF_LOG_LEVEL_DEBUG, \
"RECEIVE ; FROM =" \ "RECEIVE ; FROM =" \
<< deep_to_string(ptr->sender).c_str() \ << deep_to_string(ptr->sender).c_str() \
<< "; STAGES =" << deep_to_string(ptr->stages).c_str() \ << "; STAGES =" << deep_to_string(ptr->stages).c_str() \
<< "; CONTENT =" << deep_to_string(ptr->content()).c_str()) << "; CONTENT =" << deep_to_string(ptr->content()).c_str())
#define CAF_LOG_REJECT_EVENT() \ #define CAF_LOG_REJECT_EVENT() \
CAF_LOG_IMPL(CAF_LOG_EVENT_COMPONENT, CAF_LOG_LEVEL_DEBUG, "REJECT") CAF_LOG_IMPL(CAF_LOG_FLOW_COMPONENT, CAF_LOG_LEVEL_DEBUG, "REJECT")
#define CAF_LOG_ACCEPT_EVENT() \ #define CAF_LOG_ACCEPT_EVENT() \
CAF_LOG_IMPL(CAF_LOG_EVENT_COMPONENT, CAF_LOG_LEVEL_DEBUG, "ACCEPT") CAF_LOG_IMPL(CAF_LOG_FLOW_COMPONENT, CAF_LOG_LEVEL_DEBUG, "ACCEPT")
#define CAF_LOG_DROP_EVENT() \ #define CAF_LOG_DROP_EVENT() \
CAF_LOG_IMPL(CAF_LOG_EVENT_COMPONENT, CAF_LOG_LEVEL_DEBUG, "DROP") CAF_LOG_IMPL(CAF_LOG_FLOW_COMPONENT, CAF_LOG_LEVEL_DEBUG, "DROP")
#define CAF_LOG_SKIP_EVENT() \ #define CAF_LOG_SKIP_EVENT() \
CAF_LOG_IMPL(CAF_LOG_EVENT_COMPONENT, CAF_LOG_LEVEL_DEBUG, "SKIP") CAF_LOG_IMPL(CAF_LOG_FLOW_COMPONENT, CAF_LOG_LEVEL_DEBUG, "SKIP")
#define CAF_LOG_FINALIZE_EVENT() \ #define CAF_LOG_FINALIZE_EVENT() \
CAF_LOG_IMPL(CAF_LOG_EVENT_COMPONENT, CAF_LOG_LEVEL_DEBUG, "FINALIZE") CAF_LOG_IMPL(CAF_LOG_FLOW_COMPONENT, CAF_LOG_LEVEL_DEBUG, "FINALIZE")
#define CAF_LOG_TERMINATE_EVENT(rsn) \ #define CAF_LOG_TERMINATE_EVENT(rsn) \
CAF_LOG_IMPL(CAF_LOG_EVENT_COMPONENT, CAF_LOG_LEVEL_DEBUG, \ CAF_LOG_IMPL(CAF_LOG_FLOW_COMPONENT, CAF_LOG_LEVEL_DEBUG, \
"TERMINATE ; REASON =" << deep_to_string(rsn).c_str()) "TERMINATE ; REASON =" << deep_to_string(rsn).c_str())
#endif // CAF_LOGGER_HPP #endif // CAF_LOGGER_HPP
...@@ -28,6 +28,7 @@ ...@@ -28,6 +28,7 @@
#include <algorithm> #include <algorithm>
#include <type_traits> #include <type_traits>
#include "caf/config.hpp"
#include "caf/detail/type_traits.hpp" #include "caf/detail/type_traits.hpp"
namespace caf { namespace caf {
......
...@@ -41,10 +41,10 @@ public: ...@@ -41,10 +41,10 @@ public:
using path_uptr = std::unique_ptr<upstream_path>; using path_uptr = std::unique_ptr<upstream_path>;
/// Stores all available paths. /// Stores all available paths.
using path_uptr_list = std::vector<path_uptr>; using path_uptr_vec = std::vector<path_uptr>;
/// List of views to paths. /// List of views to paths.
using path_ptr_list = std::vector<path_ptr>; using path_ptr_vec = std::vector<path_ptr>;
/// Describes an assignment of credit to an upstream actor. /// Describes an assignment of credit to an upstream actor.
using assignment_pair = std::pair<upstream_path*, long>; using assignment_pair = std::pair<upstream_path*, long>;
...@@ -98,6 +98,10 @@ public: ...@@ -98,6 +98,10 @@ public:
upstream_path* find(const strong_actor_ptr& x) const; upstream_path* find(const strong_actor_ptr& x) const;
inline const path_uptr_vec& paths() const {
return paths_;
}
// -- required state --------------------------------------------------------- // -- required state ---------------------------------------------------------
inline local_actor* self() const { inline local_actor* self() const {
...@@ -149,7 +153,7 @@ protected: ...@@ -149,7 +153,7 @@ protected:
local_actor* self_; local_actor* self_;
/// List of all known paths. /// List of all known paths.
path_uptr_list paths_; path_uptr_vec paths_;
/// An assignment vector that's re-used whenever calling the policy. /// An assignment vector that's re-used whenever calling the policy.
assignment_vec assignment_vec_; assignment_vec assignment_vec_;
......
...@@ -123,8 +123,11 @@ actor_system_config::actor_system_config() ...@@ -123,8 +123,11 @@ actor_system_config::actor_system_config()
work_stealing_moderate_sleep_duration_us = 50; work_stealing_moderate_sleep_duration_us = 50;
work_stealing_relaxed_steal_interval = 1; work_stealing_relaxed_steal_interval = 1;
work_stealing_relaxed_sleep_duration_us = 10000; work_stealing_relaxed_sleep_duration_us = 10000;
logger_filename = "actor_log_[PID]_[TIMESTAMP]_[NODE].log"; logger_file_name = "actor_log_[PID]_[TIMESTAMP]_[NODE].log";
logger_console = atom("NONE"); logger_file_format = "%r %c %p %a %t %C %M %F:%L %m%n";
logger_console = atom("none");
logger_console_format = "%m";
logger_verbosity = atom("trace");
middleman_network_backend = atom("default"); middleman_network_backend = atom("default");
middleman_enable_automatic_connections = false; middleman_enable_automatic_connections = false;
middleman_max_consecutive_reads = 50; middleman_max_consecutive_reads = 50;
...@@ -159,14 +162,22 @@ actor_system_config::actor_system_config() ...@@ -159,14 +162,22 @@ actor_system_config::actor_system_config()
.add(work_stealing_relaxed_sleep_duration_us, "relaxed-sleep-duration", .add(work_stealing_relaxed_sleep_duration_us, "relaxed-sleep-duration",
"sets the sleep interval between poll attempts during relaxed polling"); "sets the sleep interval between poll attempts during relaxed polling");
opt_group{options_, "logger"} opt_group{options_, "logger"}
.add(logger_filename, "filename", .add(logger_file_name, "file-name",
"sets the filesystem path of the log file") "sets the filesystem path of the log file")
.add(logger_verbosity, "verbosity", .add(logger_file_format, "file-format",
"sets the verbosity (QUIET|ERROR|WARNING|INFO|DEBUG|TRACE)") "sets the line format for individual log file entires")
.add(logger_console, "console", .add(logger_console, "console",
"enables logging to the console via std::clog") "sets the type of output to std::clog (none|colored|uncolored)")
.add(logger_filter, "filter", .add(logger_console_format, "console-format",
"sets a component filter for console log messages"); "sets the line format for printing individual log entires")
.add(logger_component_filter, "component-filter",
"exclude all listed components from logging")
.add(logger_verbosity, "verbosity",
"sets the verbosity (quiet|error|warning|info|debug|trace)")
.add(logger_file_name, "filename",
"deprecated (use file-name instead)")
.add(logger_component_filter, "filter",
"deprecated (use console-component-filter instead)");
opt_group{options_, "middleman"} opt_group{options_, "middleman"}
.add(middleman_network_backend, "network-backend", .add(middleman_network_backend, "network-backend",
"sets the network backend to either 'default' or 'asio' (if available)") "sets the network backend to either 'default' or 'asio' (if available)")
......
...@@ -20,6 +20,8 @@ ...@@ -20,6 +20,8 @@
#include "caf/message_id.hpp" #include "caf/message_id.hpp"
#include "caf/event_based_actor.hpp" #include "caf/event_based_actor.hpp"
#include "caf/detail/pretty_type_name.hpp"
namespace caf { namespace caf {
event_based_actor::event_based_actor(actor_config& cfg) : extended_base(cfg) { event_based_actor::event_based_actor(actor_config& cfg) : extended_base(cfg) {
...@@ -31,7 +33,7 @@ event_based_actor::~event_based_actor() { ...@@ -31,7 +33,7 @@ event_based_actor::~event_based_actor() {
} }
void event_based_actor::initialize() { void event_based_actor::initialize() {
CAF_LOG_TRACE("subtype =" << logger::render_type_name(typeid(*this)).c_str()); CAF_LOG_TRACE("subtype =" << detail::pretty_type_name(typeid(*this)).c_str());
setf(is_initialized_flag); setf(is_initialized_flag);
auto bhvr = make_behavior(); auto bhvr = make_behavior();
CAF_LOG_DEBUG_IF(!bhvr, "make_behavior() did not return a behavior:" CAF_LOG_DEBUG_IF(!bhvr, "make_behavior() did not return a behavior:"
......
...@@ -21,28 +21,23 @@ ...@@ -21,28 +21,23 @@
#include <thread> #include <thread>
#include <cstring> #include <cstring>
#include <iomanip>
#include <fstream> #include <fstream>
#include <algorithm> #include <algorithm>
#include <condition_variable> #include <condition_variable>
#include "caf/config.hpp" #include "caf/config.hpp"
#if defined(CAF_LINUX) || defined(CAF_MACOS)
#include <unistd.h>
#include <cxxabi.h>
#include <sys/types.h>
#endif
#include "caf/string_algorithms.hpp"
#include "caf/term.hpp" #include "caf/term.hpp"
#include "caf/locks.hpp" #include "caf/locks.hpp"
#include "caf/timestamp.hpp" #include "caf/timestamp.hpp"
#include "caf/actor_proxy.hpp" #include "caf/actor_proxy.hpp"
#include "caf/actor_system.hpp" #include "caf/actor_system.hpp"
#include "caf/string_algorithms.hpp"
#include "caf/actor_system_config.hpp" #include "caf/actor_system_config.hpp"
#include "caf/detail/get_process_id.hpp" #include "caf/detail/get_process_id.hpp"
#include "caf/detail/pretty_type_name.hpp"
#include "caf/detail/single_reader_queue.hpp" #include "caf/detail/single_reader_queue.hpp"
namespace caf { namespace caf {
...@@ -51,8 +46,8 @@ namespace { ...@@ -51,8 +46,8 @@ namespace {
constexpr const char* log_level_name[] = { constexpr const char* log_level_name[] = {
"ERROR", "ERROR",
"WARN ", "WARN",
"INFO ", "INFO",
"DEBUG", "DEBUG",
"TRACE" "TRACE"
}; };
...@@ -115,52 +110,8 @@ inline logger* get_current_logger() { ...@@ -115,52 +110,8 @@ inline logger* get_current_logger() {
} }
#endif // CAF_LOG_LEVEL #endif // CAF_LOG_LEVEL
void prettify_type_name(std::string& class_name) {
//replace_all(class_name, " ", "");
replace_all(class_name, "::", ".");
replace_all(class_name, "(anonymousnamespace)", "ANON");
replace_all(class_name, ".__1.", "."); // gets rid of weird Clang-lib names
// hide CAF magic in logs
auto strip_magic = [&](const char* prefix_begin, const char* prefix_end) {
auto last = class_name.end();
auto i = std::search(class_name.begin(), last, prefix_begin, prefix_end);
auto comma_or_angle_bracket = [](char c) { return c == ',' || c == '>'; };
auto e = std::find_if(i, last, comma_or_angle_bracket);
if (i != e) {
std::string substr(i + (prefix_end - prefix_begin), e);
class_name.swap(substr);
}
};
char prefix1[] = "caf.detail.embedded<";
strip_magic(prefix1, prefix1 + (sizeof(prefix1) - 1));
// finally, replace any whitespace with %20
replace_all(class_name, " ", "%20");
}
void prettify_type_name(std::string& class_name, const char* c_class_name) {
# if defined(CAF_LINUX) || defined(CAF_MACOS)
int stat = 0;
std::unique_ptr<char, decltype(free)*> real_class_name{nullptr, free};
auto tmp = abi::__cxa_demangle(c_class_name, nullptr, nullptr, &stat);
real_class_name.reset(tmp);
class_name = stat == 0 ? real_class_name.get() : c_class_name;
# else
class_name = c_class_name;
# endif
prettify_type_name(class_name);
}
} // namespace <anonymous> } // namespace <anonymous>
logger::event::event(int lvl, std::string pfx, std::string content)
: next(nullptr),
prev(nullptr),
level(lvl),
prefix(std::move(pfx)),
msg(std::move(content)) {
// nop
}
logger::line_builder::line_builder() : behind_arg_(false) { logger::line_builder::line_builder() : behind_arg_(false) {
// nop // nop
} }
...@@ -185,43 +136,6 @@ std::string logger::line_builder::get() const { ...@@ -185,43 +136,6 @@ std::string logger::line_builder::get() const {
return std::move(str_); return std::move(str_);
} }
std::string logger::render_type_name(const std::type_info& ti) {
std::string result;
prettify_type_name(result, ti.name());
return result;
}
std::string logger::extract_class_name(const char* prettyfun, size_t strsize) {
auto first = prettyfun;
// set end to beginning of arguments
auto last = std::find(first, prettyfun + strsize, '(');
auto jump_to_next_whitespace = [&] {
// leave `first` unchanged if no whitespaces is present,
// e.g., in constructor signatures
auto tmp = std::find(first, last, ' ');
if (tmp != last)
first = tmp + 1;
};
// skip "virtual" prefix if present
if (strncmp(prettyfun, "virtual ", std::min<size_t>(strsize, 8)) == 0)
jump_to_next_whitespace();
// skip return type
jump_to_next_whitespace();
if (first == last)
return "";
const char sep[] = "::"; // separator for namespaces and classes
auto sep_first = std::begin(sep);
auto sep_last = sep_first + 2; // using end() includes \0
auto colons = first;
decltype(colons) nextcs;
while ((nextcs = std::search(colons + 1, last, sep_first, sep_last)) != last)
colons = nextcs;
std::string result;
result.assign(first, colons);
prettify_type_name(result);
return result;
}
// returns the actor ID for the current thread // returns the actor ID for the current thread
actor_id logger::thread_local_aid() { actor_id logger::thread_local_aid() {
shared_lock<detail::shared_spinlock> guard{aids_lock_}; shared_lock<detail::shared_spinlock> guard{aids_lock_};
...@@ -248,40 +162,9 @@ actor_id logger::thread_local_aid(actor_id aid) { ...@@ -248,40 +162,9 @@ actor_id logger::thread_local_aid(actor_id aid) {
return 0; // was empty before return 0; // was empty before
} }
void logger::log_prefix(std::ostream& out, int level, const char* component, void logger::log(event* x) {
const std::string& class_name, CAF_ASSERT(x->level >= 0 && x->level <= 4);
const char* function_name, const char* c_full_file_name, queue_.synchronized_enqueue(queue_mtx_, queue_cv_,x);
int line_num, const std::thread::id& tid) {
std::string file_name;
std::string full_file_name = c_full_file_name;
auto ri = find(full_file_name.rbegin(), full_file_name.rend(), '/');
if (ri != full_file_name.rend()) {
auto i = ri.base();
if (i == full_file_name.end())
file_name = std::move(full_file_name);
else
file_name = std::string(i, full_file_name.end());
} else {
file_name = std::move(full_file_name);
}
std::ostringstream prefix;
out << timestamp_to_string(make_timestamp()) << " " << component << " "
<< log_level_name[level] << " "
<< "actor" << thread_local_aid() << " " << tid << " "
<< class_name << " " << function_name << " "
<< file_name << ":" << line_num;
}
void logger::log(int level, const char* component,
const std::string& class_name, const char* function_name,
const char* c_full_file_name, int line_num,
const std::string& msg) {
CAF_ASSERT(level >= 0 && level <= 4);
std::ostringstream prefix;
log_prefix(prefix, level, component, class_name, function_name,
c_full_file_name, line_num);
queue_.synchronized_enqueue(queue_mtx_, queue_cv_,
new event{level, prefix.str(), msg});
} }
void logger::set_current_actor_system(actor_system* x) { void logger::set_current_actor_system(actor_system* x) {
...@@ -295,30 +178,14 @@ logger* logger::current_logger() { ...@@ -295,30 +178,14 @@ logger* logger::current_logger() {
return get_current_logger(); return get_current_logger();
} }
void logger::log_static(int level, const char* component, bool logger::accepts(int level, const char* cname_begin,
const std::string& class_name, const char* cname_end) {
const char* function_name, const char* file_name, CAF_ASSERT(cname_begin != nullptr && cname_end != nullptr);
int line_num, const std::string& msg) {
auto ptr = get_current_logger();
if (ptr != nullptr)
ptr->log(level, component, class_name, function_name, file_name, line_num,
msg);
}
bool logger::accepts(int level, const char* component) {
CAF_ASSERT(component != nullptr);
CAF_ASSERT(level >= 0 && level <= 4); CAF_ASSERT(level >= 0 && level <= 4);
auto ptr = get_current_logger(); auto& filter = system_.config().logger_component_filter;
if (ptr == nullptr || level > ptr->level_)
return false;
// TODO: once we've phased out GCC 4.8, we can upgrade this to a regex.
// Until then, we just search for a substring in the filter.
auto& filter = ptr->system_.config().logger_filter;
if (!filter.empty()) { if (!filter.empty()) {
auto it = std::search(filter.begin(), filter.end(), auto it = std::search(filter.begin(), filter.end(), cname_begin, cname_end);
component, component + std::strlen(component)); return it != filter.end();
if (it == filter.end())
return false;
} }
return true; return true;
} }
...@@ -338,40 +205,173 @@ logger::logger(actor_system& sys) : system_(sys) { ...@@ -338,40 +205,173 @@ logger::logger(actor_system& sys) : system_(sys) {
void logger::init(actor_system_config& cfg) { void logger::init(actor_system_config& cfg) {
CAF_IGNORE_UNUSED(cfg); CAF_IGNORE_UNUSED(cfg);
#if defined(CAF_LOG_LEVEL) #if defined(CAF_LOG_LEVEL)
auto lvl_atom = cfg.logger_verbosity; // Parse the configured log leve.
switch (static_cast<uint64_t>(lvl_atom)) { switch (static_cast<uint64_t>(cfg.logger_verbosity)) {
case error_log_lvl_atom::uint_value(): case atom_uint("error"):
case atom_uint("ERROR"):
level_ = CAF_LOG_LEVEL_ERROR; level_ = CAF_LOG_LEVEL_ERROR;
break; break;
case warning_log_lvl_atom::uint_value(): case atom_uint("warning"):
case atom_uint("WARNING"):
level_ = CAF_LOG_LEVEL_WARNING; level_ = CAF_LOG_LEVEL_WARNING;
break; break;
case info_log_lvl_atom::uint_value(): case atom_uint("info"):
case atom_uint("INFO"):
level_ = CAF_LOG_LEVEL_INFO; level_ = CAF_LOG_LEVEL_INFO;
break; break;
case debug_log_lvl_atom::uint_value(): case atom_uint("debug"):
case atom_uint("DEBUG"):
level_ = CAF_LOG_LEVEL_DEBUG; level_ = CAF_LOG_LEVEL_DEBUG;
break; break;
case trace_log_lvl_atom::uint_value(): case atom_uint("trace"):
case atom_uint("TRACE"):
level_ = CAF_LOG_LEVEL_TRACE; level_ = CAF_LOG_LEVEL_TRACE;
break; break;
default: { default: {
level_ = CAF_LOG_LEVEL; level_ = CAF_LOG_LEVEL;
} }
} }
// Parse the format string.
file_format_ = parse_format(cfg.logger_file_format.c_str());
console_format_ = parse_format(cfg.logger_console_format.c_str());
#endif #endif
} }
void logger::render_fun_prefix(std::ostream& out, const char* pretty_fun) {
auto first = pretty_fun;
// set end to beginning of arguments
auto last = std::find_if(first, static_cast<const char*>(nullptr),
[](char x) { return x == '(' || x == '\0'; });
auto strsize = static_cast<size_t>(last - first);
auto jump_to_next_whitespace = [&] {
// leave `first` unchanged if no whitespaces is present,
// e.g., in constructor signatures
auto tmp = std::find(first, last, ' ');
if (tmp != last)
first = tmp + 1;
};
// skip "virtual" prefix if present
if (strncmp(pretty_fun, "virtual ", std::min<size_t>(strsize, 8)) == 0)
jump_to_next_whitespace();
// skip return type
jump_to_next_whitespace();
if (first == last)
return;
const char sep[] = "::"; // separator for namespaces and classes
auto sep_first = std::begin(sep);
auto sep_last = sep_first + 2; // using end() includes \0
auto colons = first;
decltype(colons) nextcs;
while ((nextcs = std::search(colons + 1, last, sep_first, sep_last)) != last)
colons = nextcs;
std::string result;
result.assign(first, colons);
detail::prettify_type_name(result);
out << result;
}
void logger::render_fun_name(std::ostream& out, const char* pretty_fun) {
// Find the end of the function name by looking for the opening parenthesis
// trailing it.
const char* e = nullptr; // safe, because pretty_fun is null-terminated
auto i = std::find_if(pretty_fun, e,
[](char x) { return x == '(' || x == '\0'; });
if (*i == '\0')
return;
/// Now look for the beginning of the function name.
using rev_iter = std::reverse_iterator<const char*>;
auto b = std::find_if(rev_iter(i), rev_iter(pretty_fun),
[](char x) { return x == ':' || x == ' '; });
out.write(b.base(), i - b.base());
}
void logger::render_time_diff(std::ostream& out, timestamp t0, timestamp tn) {
out << std::chrono::duration_cast<std::chrono::milliseconds>(tn - t0).count();
}
void logger::render_date(std::ostream& out, timestamp x) {
auto y = std::chrono::time_point_cast<timestamp::clock::duration>(x);
auto z = timestamp::clock::to_time_t(y);
out << std::put_time(std::localtime(&z), "%F %T");
}
void logger::render(std::ostream& out, const line_format& lf,
const event& x) const {
for (auto& f : lf)
switch (f.kind) {
case category_field: out << x.category_name; break;
case class_name_field: render_fun_prefix(out, x.pretty_fun); break;
case date_field: render_date(out, x.tstamp); break;
case file_field: out << x.file_name; break;
case line_field: out << x.line_number; break;
case message_field: out << x.message; break;
case method_field: render_fun_name(out, x.pretty_fun); break;
case newline_field: out << std::endl; break;
case priority_field: out << log_level_name[x.level]; break;
case runtime_field: render_time_diff(out, t0_, x.tstamp); break;
case thread_field: out << x.tid; break;
case actor_field: out << "actor" << x.aid; break;
case percent_sign_field: out << '%'; break;
case plain_text_field: out.write(f.first, f.last - f.first); break;
default: ; // nop
}
}
logger::line_format logger::parse_format(const char* format_str) {
std::vector<field> res;
auto i = format_str;
auto plain_text_first = i;
bool read_percent_sign = false;
for (; *i != '\0'; ++i) {
if (read_percent_sign) {
field_type ft;
switch (*i) {
case 'c': ft = category_field; break;
case 'C': ft = class_name_field; break;
case 'd': ft = date_field; break;
case 'F': ft = file_field; break;
case 'L': ft = line_field; break;
case 'm': ft = message_field; break;
case 'M': ft = method_field; break;
case 'n': ft = newline_field; break;
case 'p': ft = priority_field; break;
case 'r': ft = runtime_field; break;
case 't': ft = thread_field; break;
case 'a': ft = actor_field; break;
case '%': ft = percent_sign_field; break;
default:
ft = invalid_field;
std::cerr << "invalid field specifier in format string: "
<< *i << std::endl;
}
if (ft != invalid_field)
res.emplace_back(field{ft, nullptr, nullptr});
plain_text_first = i + 1;
read_percent_sign = false;
} else {
if (*i == '%') {
if (plain_text_first != i)
res.emplace_back(field{plain_text_field, plain_text_first, i});
read_percent_sign = true;
}
}
}
if (plain_text_first != i)
res.emplace_back(field{plain_text_field, plain_text_first, i});
return res;
}
void logger::run() { void logger::run() {
#if defined(CAF_LOG_LEVEL) #if defined(CAF_LOG_LEVEL)
t0_ = make_timestamp();
std::fstream file; std::fstream file;
if (system_.config().logger_filename.empty()) { if (system_.config().logger_file_name.empty()) {
// If the console is also disabled, no need to continue. // No need to continue if console and log file are disabled.
if (!(system_.config().logger_console == atom("UNCOLORED") if (!(system_.config().logger_console == atom("UNCOLORED")
|| system_.config().logger_console == atom("COLORED"))) || system_.config().logger_console == atom("COLORED")))
return; return;
} else { } else {
auto f = system_.config().logger_filename; auto f = system_.config().logger_file_name;
// Replace placeholders. // Replace placeholders.
const char pid[] = "[PID]"; const char pid[] = "[PID]";
auto i = std::search(f.begin(), f.end(), std::begin(pid), auto i = std::search(f.begin(), f.end(), std::begin(pid),
...@@ -383,8 +383,8 @@ void logger::run() { ...@@ -383,8 +383,8 @@ void logger::run() {
const char ts[] = "[TIMESTAMP]"; const char ts[] = "[TIMESTAMP]";
i = std::search(f.begin(), f.end(), std::begin(ts), std::end(ts) - 1); i = std::search(f.begin(), f.end(), std::begin(ts), std::end(ts) - 1);
if (i != f.end()) { if (i != f.end()) {
auto now = timestamp_to_string(make_timestamp()); auto t0_str = timestamp_to_string(t0_);
f.replace(i, i + sizeof(ts) - 1, now); f.replace(i, i + sizeof(ts) - 1, t0_str);
} }
const char node[] = "[NODE]"; const char node[] = "[NODE]";
i = std::search(f.begin(), f.end(), std::begin(node), std::end(node) - 1); i = std::search(f.begin(), f.end(), std::begin(node), std::end(node) - 1);
...@@ -400,15 +400,22 @@ void logger::run() { ...@@ -400,15 +400,22 @@ void logger::run() {
} }
if (file) { if (file) {
// log first entry // log first entry
constexpr atom_value level_names[] = { std::string msg = "level = ";
error_log_lvl_atom::value, warning_log_lvl_atom::value, msg += to_string(system_.config().logger_verbosity);
info_log_lvl_atom::value, debug_log_lvl_atom::value, msg += ", node = ";
trace_log_lvl_atom::value}; msg += to_string(system_.node());
auto lvl_atom = level_names[CAF_LOG_LEVEL]; event tmp{nullptr,
log_prefix(file, CAF_LOG_LEVEL_INFO, "caf", "caf.logger", "start", nullptr,
__FILE__, __LINE__, parent_thread_); CAF_LOG_LEVEL_INFO,
file << " level = " << to_string(lvl_atom) << ", node = " CAF_LOG_COMPONENT,
<< to_string(system_.node()) << std::endl; CAF_PRETTY_FUN,
__FILE__,
__LINE__,
std::move(msg),
std::this_thread::get_id(),
0,
make_timestamp()};
render(file, file_format_, tmp);
} }
// receive log entries from other threads and actors // receive log entries from other threads and actors
std::unique_ptr<event> ptr; std::unique_ptr<event> ptr;
...@@ -419,12 +426,13 @@ void logger::run() { ...@@ -419,12 +426,13 @@ void logger::run() {
ptr.reset(queue_.try_pop()); ptr.reset(queue_.try_pop());
CAF_ASSERT(ptr != nullptr); CAF_ASSERT(ptr != nullptr);
// empty message means: shut down // empty message means: shut down
if (ptr->msg.empty()) if (ptr->message.empty()) {
break; break;
}
if (file) if (file)
file << ptr->prefix << ' ' << ptr->msg << std::endl; render(file, file_format_, *ptr);;
if (system_.config().logger_console == atom("UNCOLORED")) { if (system_.config().logger_console == atom("UNCOLORED")) {
std::clog << ptr->msg << std::endl; render(std::clog, console_format_, *ptr);
} else if (system_.config().logger_console == atom("COLORED")) { } else if (system_.config().logger_console == atom("COLORED")) {
switch (ptr->level) { switch (ptr->level) {
default: default:
...@@ -445,13 +453,23 @@ void logger::run() { ...@@ -445,13 +453,23 @@ void logger::run() {
std::clog << term::blue; std::clog << term::blue;
break; break;
} }
std::clog << ptr->msg << term::reset << std::endl; render(std::clog, console_format_, *ptr);
std::clog << term::reset_endl;
} }
} }
if (file) { if (file) {
log_prefix(file, CAF_LOG_LEVEL_INFO, "caf", "caf.logger", "stop", event tmp{nullptr,
__FILE__, __LINE__, parent_thread_); nullptr,
file << " EOF" << std::endl; CAF_LOG_LEVEL_INFO,
CAF_LOG_COMPONENT,
CAF_PRETTY_FUN,
__FILE__,
__LINE__,
"EOF",
std::this_thread::get_id(),
0,
make_timestamp()};
render(file, file_format_, tmp);
} }
#endif #endif
} }
...@@ -459,7 +477,8 @@ void logger::run() { ...@@ -459,7 +477,8 @@ void logger::run() {
void logger::start() { void logger::start() {
#if defined(CAF_LOG_LEVEL) #if defined(CAF_LOG_LEVEL)
parent_thread_ = std::this_thread::get_id(); parent_thread_ = std::this_thread::get_id();
if (system_.config().logger_verbosity == quiet_log_lvl_atom::value) auto verbosity = system_.config().logger_verbosity;
if (verbosity == atom("quiet") || verbosity == atom("QUIET"))
return; return;
thread_ = std::thread{[this] { this->run(); }}; thread_ = std::thread{[this] { this->run(); }};
#endif #endif
...@@ -475,4 +494,34 @@ void logger::stop() { ...@@ -475,4 +494,34 @@ void logger::stop() {
#endif #endif
} }
std::string to_string(logger::field_type x) {
static constexpr const char* names[] = {
"invalid", "category", "class_name", "date", "file",
"line", "message", "method", "newline", "priority",
"runtime", "thread", "actor", "percent_sign", "plain_text"};
return names[static_cast<size_t>(x)];
}
std::string to_string(const logger::field& x) {
std::string result = "field{";
result += to_string(x.kind);
if (x.first != nullptr) {
result += ", \"";
result.insert(result.end(), x.first, x.last);
result += '\"';
}
result += "}";
return result;
}
bool operator==(const logger::field& x, const logger::field& y) {
if (x.kind == y.kind) {
if (x.kind == logger::plain_text_field)
return std::distance(x.first, x.last) == std::distance(y.first, y.last)
&& std::equal(x.first, x.last, y.first);
return true;
}
return false;
}
} // namespace caf } // namespace caf
/******************************************************************************
* ____ _ _____ *
* / ___| / \ | ___| C++ *
* | | / _ \ | |_ Actor *
* | |___ / ___ \| _| Framework *
* \____/_/ \_|_| *
* *
* Copyright (C) 2011 - 2017 *
* Dominik Charousset <dominik.charousset (at) haw-hamburg.de> *
* *
* Distributed under the terms and conditions of the BSD 3-Clause License or *
* (at your option) under the terms and conditions of the Boost Software *
* License 1.0. See accompanying files LICENSE and LICENSE_ALTERNATIVE. *
* *
* If you did not receive a copy of the license files, see *
* http://opensource.org/licenses/BSD-3-Clause and *
* http://www.boost.org/LICENSE_1_0.txt. *
******************************************************************************/
#include "caf/detail/pretty_type_name.hpp"
#include "caf/config.hpp"
#if defined(CAF_LINUX) || defined(CAF_MACOS)
#include <unistd.h>
#include <cxxabi.h>
#include <sys/types.h>
#endif
#include "caf/string_algorithms.hpp"
namespace caf {
namespace detail {
void prettify_type_name(std::string& class_name) {
//replace_all(class_name, " ", "");
replace_all(class_name, "::", ".");
replace_all(class_name, "(anonymousnamespace)", "ANON");
replace_all(class_name, ".__1.", "."); // gets rid of weird Clang-lib names
// hide CAF magic in logs
auto strip_magic = [&](const char* prefix_begin, const char* prefix_end) {
auto last = class_name.end();
auto i = std::search(class_name.begin(), last, prefix_begin, prefix_end);
auto comma_or_angle_bracket = [](char c) { return c == ',' || c == '>'; };
auto e = std::find_if(i, last, comma_or_angle_bracket);
if (i != e) {
std::string substr(i + (prefix_end - prefix_begin), e);
class_name.swap(substr);
}
};
char prefix1[] = "caf.detail.embedded<";
strip_magic(prefix1, prefix1 + (sizeof(prefix1) - 1));
// finally, replace any whitespace with %20
replace_all(class_name, " ", "%20");
}
void prettify_type_name(std::string& class_name, const char* c_class_name) {
# if defined(CAF_LINUX) || defined(CAF_MACOS)
int stat = 0;
std::unique_ptr<char, decltype(free)*> real_class_name{nullptr, free};
auto tmp = abi::__cxa_demangle(c_class_name, nullptr, nullptr, &stat);
real_class_name.reset(tmp);
class_name = stat == 0 ? real_class_name.get() : c_class_name;
# else
class_name = c_class_name;
# endif
prettify_type_name(class_name);
}
std::string pretty_type_name(const std::type_info& x) {
std::string result;
prettify_type_name(result, x.name());
return result;
}
} // namespace detail
} // namespace caf
/******************************************************************************
* ____ _ _____ *
* / ___| / \ | ___| C++ *
* | | / _ \ | |_ Actor *
* | |___ / ___ \| _| Framework *
* \____/_/ \_|_| *
* *
* Copyright (C) 2011 - 2017 *
* Dominik Charousset <dominik.charousset (at) haw-hamburg.de> *
* *
* Distributed under the terms and conditions of the BSD 3-Clause License or *
* (at your option) under the terms and conditions of the Boost Software *
* License 1.0. See accompanying files LICENSE and LICENSE_ALTERNATIVE. *
* *
* If you did not receive a copy of the license files, see *
* http://opensource.org/licenses/BSD-3-Clause and *
* http://www.boost.org/LICENSE_1_0.txt. *
******************************************************************************/
#include "caf/config.hpp"
#define CAF_SUITE logger
#include "caf/test/unit_test.hpp"
#include <string>
#include "caf/all.hpp"
using namespace caf;
using namespace std;
using namespace std::chrono;
namespace {
struct fixture {
fixture() {
cfg.scheduler_policy = caf::atom("testing");
}
void add(logger::field_type kind) {
lf.emplace_back(logger::field{kind, nullptr, nullptr});
}
template <size_t N>
void add(logger::field_type kind, const char (&str)[N]) {
lf.emplace_back(logger::field{kind, str, str + (N - 1)}); // exclude \0
}
template <class F, class... Ts>
string render(F f, Ts&&... xs) {
ostringstream oss;
f(oss, forward<Ts>(xs)...);
return oss.str();
}
actor_system_config cfg;
logger::line_format lf;
};
} // namespace <anonymous>
CAF_TEST_FIXTURE_SCOPE(logger_tests, fixture)
// copy construction, copy assign, move construction, move assign
// and finally serialization round-trip
CAF_TEST(parse_default_format_strings) {
actor_system sys{cfg};
CAF_CHECK_EQUAL(cfg.logger_file_format, "%r %c %p %a %t %C %M %F:%L %m%n");
add(logger::runtime_field);
add(logger::plain_text_field, " ");
add(logger::category_field);
add(logger::plain_text_field, " ");
add(logger::priority_field);
add(logger::plain_text_field, " ");
add(logger::actor_field);
add(logger::plain_text_field, " ");
add(logger::thread_field);
add(logger::plain_text_field, " ");
add(logger::class_name_field);
add(logger::plain_text_field, " ");
add(logger::method_field);
add(logger::plain_text_field, " ");
add(logger::file_field);
add(logger::plain_text_field, ":");
add(logger::line_field);
add(logger::plain_text_field, " ");
add(logger::message_field);
add(logger::newline_field);
CAF_CHECK_EQUAL(sys.logger().file_format(), lf);
CAF_CHECK_EQUAL(logger::parse_format("%r %c %p %a %t %C %M %F:%L %m%n"), lf);
}
CAF_TEST(rendering) {
// Rendering of type names and function names.
const char* foobar = "void ns::foo::bar()";
CAF_CHECK_EQUAL(render(logger::render_fun_name, foobar), "bar");
CAF_CHECK_EQUAL(render(logger::render_fun_prefix, foobar), "ns.foo");
// Rendering of time points.
timestamp t0;
timestamp t1{timestamp::duration{5000000}}; // epoch + 5000000ns (5ms)
CAF_CHECK_EQUAL(render(logger::render_time_diff, t0, t1), "5");
ostringstream t0_iso8601;
auto t0_t = system_clock::to_time_t(system_clock::time_point{});
t0_iso8601 << put_time(localtime(&t0_t), "%F %T");
CAF_CHECK_EQUAL(render(logger::render_date, t0), t0_iso8601.str());
// Rendering of events.
logger::event e{
nullptr,
nullptr,
CAF_LOG_LEVEL_WARNING,
"unit.test",
"void ns::foo::bar()",
"foo.cpp",
42,
"hello world",
this_thread::get_id(),
0,
t0
};
// Exclude %r and %t from rendering test because they are nondeterministic.
actor_system sys{cfg};
auto lf = logger::parse_format("%c %p %a %C %M %F:%L %m");
auto& lg = sys.logger();
using namespace std::placeholders;
auto render_event = bind(&logger::render, &lg, _1, _2, _3);
CAF_CHECK_EQUAL(render(render_event, lf, e),
"unit.test WARN actor0 ns.foo bar foo.cpp:42 hello world");
}
CAF_TEST_FIXTURE_SCOPE_END()
...@@ -652,7 +652,7 @@ struct config : actor_system_config { ...@@ -652,7 +652,7 @@ struct config : actor_system_config {
public: public:
config() { config() {
add_message_type<element_type>("element"); add_message_type<element_type>("element");
logger_filename = "streamlog"; logger_file_name = "streamlog";
} }
}; };
......
...@@ -758,7 +758,7 @@ struct config : public actor_system_config { ...@@ -758,7 +758,7 @@ struct config : public actor_system_config {
"Include hidden (system-level) actors") "Include hidden (system-level) actors")
.add(verbosity, "verbosity,v", "Debug output (from 0 to 2)"); .add(verbosity, "verbosity,v", "Debug output (from 0 to 2)");
// shutdown logging per default // shutdown logging per default
logger_verbosity = quiet_log_lvl_atom::value; logger_verbosity = atom("quiet");
} }
}; };
......
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