Flow 1.0.2
Flow project: Full implementation reference.
|
Interface that the user should implement, passing the implementing Logger into logging classes (Flow's own classes like net_flow::Node; and user's own logging classes) at construction (plus free/static
logging functions).
More...
#include <log.hpp>
Public Member Functions | |
virtual bool | should_log (Sev sev, const Component &component) const =0 |
Given attributes of a hypothetical message that would be logged, return true if that message should be logged and false otherwise (e.g., if the verbosity of the message is above the current configured verbosity threshold for the Component specified). More... | |
virtual bool | logs_asynchronously () const =0 |
Must return true if do_log() at least sometimes logs the given message and metadata (e.g., time stamp) after do_log() returns; false if this never occurs (i.e., it logs synchronously, always). More... | |
virtual void | do_log (Msg_metadata *metadata, util::String_view msg)=0 |
Given a message and its severity, logs that message and possibly severity WITHOUT checking whether it should be logged (i.e., without performing logic that should_log() performs). More... | |
std::ostream * | this_thread_ostream () const |
Returns the stream dedicated to the executing thread and this Logger, so that the caller can apply state-setting formatters to it. More... | |
Public Member Functions inherited from flow::util::Null_interface | |
virtual | ~Null_interface ()=0 |
Boring virtual destructor. More... | |
Public Member Functions inherited from flow::util::Unique_id_holder | |
Unique_id_holder () | |
Thread-safely construct an ID whose value is different from any other object of this class, past or future. More... | |
Unique_id_holder (const Unique_id_holder &) | |
This copy constructor is identical in behavior to Unique_id_holder(), the default ctor. More... | |
id_t | unique_id () const |
Raw unique ID identifying this object as well as any object of a derived type. More... | |
const Unique_id_holder & | operator= (const Unique_id_holder &) const |
This assignment operator is a const no-op. More... | |
Static Public Member Functions | |
static void | this_thread_set_logged_nickname (util::String_view thread_nickname=util::String_view(), Logger *logger_ptr=0, bool also_set_os_name=true) |
Sets or unsets the current thread's logging-worthy string name; optionally sets the OS thread name (such as visible in top output). More... | |
static std::ostream & | this_thread_logged_name_os_manip (std::ostream &os) |
ostream manipulator function that, if output via operator<< to an ostream , will cause the current thread's logging-worthy string name to be output to that stream. More... | |
static void | set_thread_info_in_msg_metadata (Msg_metadata *msg_metadata) |
Loads msg_metadata->m_call_thread_nickname (if set) or else msg_metadata->m_call_thread_id , based on whether/how this_thread_set_logged_nickname() was last called in the current thread. More... | |
static void | set_thread_info (std::string *call_thread_nickname, flow::util::Thread_id *call_thread_id) |
Same as set_thread_info_in_msg_metadata() but targets the given two variables as opposed to a Msg_metadata. More... | |
Static Public Member Functions inherited from flow::util::Unique_id_holder | |
static id_t | create_unique_id () |
Short-hand for Unique_id_holder().unique_id() ; useful when all you want is the unique integer itself. More... | |
Static Private Attributes | |
static boost::thread_specific_ptr< std::string > | s_this_thread_nickname_ptr |
Thread-local storage for each thread's logged name (null pointer, which is default, means no nickname stored). More... | |
Additional Inherited Members | |
Public Types inherited from flow::util::Unique_id_holder | |
using | id_t = uint64_t |
Raw integer type to uniquely identify a thing. 64-bit width should make overflow extremely hard to reach. More... | |
Interface that the user should implement, passing the implementing Logger into logging classes (Flow's own classes like net_flow::Node; and user's own logging classes) at construction (plus free/static
logging functions).
The class (or function) will then implicitly use that Logger in the logging apparatus (such as FLOW_LOG_...()
macros) to log messages into the user's preferred logging output(s). One can think of the class implementing this interface as the glue between Flow logging and either the user's lower-level logging system or some output device (like console, files) directly.
The reason should_log() and do_log() are decoupled like this is for a fast implementation of the FLOW_LOG_...()
macros (see FLOW_LOG_WITH_CHECKING() in particular).
There is also a small set of app-wide (static
) utilities, including the ability to nickname any given thread, which causes that nickname (instead of the thread ID) to be logged in subsequent log messages.
As slightly advanced ostream
users know, an ostream
carries state that can be set via explicit method calls such as ostream::setf()
and via "printing" manipulators such as std::hex
to a given ostream
. Regular values printed to ostream
will come out differently depending on the current state (e.g., << 14
may show up as a decimal or a hex integer depending on preceding formatters). If you use these state-affecting features, be aware of the following semantics:
ostream
for every distinct combination (logger
, T), where:logger
is a distinct Logger object, as identified by the address in its Logger::this
pointer.ostream
s – from that thread. (The APIs that qualify are essentially various APIs that actually log messages or attempt to set formatting for subsequent messages or are used to subsequently do either.)logger
, T) combo's ostream
as being created on-demand the first time a given Logger logger
attempts to do something logging-related from a given thread T. Subsequently, with that combo used again and again, the stream is internally looked up with high performance. The on-demand creation is slower but relatively rare given the low expected count of threads and Logger
s.operator<<()
operands passed to a logging API. However, note that for it to take effect, it must not be filtered out by a Sev filter check (basically, the containing log message must actually end up in the log, not filtered away).std::setfill
, std::hex
, boost::chrono::seconds
, etc.ostream S
, where to get access to S
one would call Logger::this_thread_ostream() to receive the pointer ‘&S’, for the current thread and the Logger on which the method is executed. Once you have S
, you may call state manipulators such as S.setf();
or, again, manipulators via S << std::hex;
and similar.S << "Hello, world!";
) will result in undefined behavior. Do not. Use logging APIs for that.ostream
for ultimate output of characters (and it absolutely does not have to do any such thing), that ostream
is totally orthogonal and irrelevant to the one being discussed here. E.g., Simple_ostream_logger may print to std::cout
, but the formatters we are discussing affect a totally different, internal stream, not that std::cout
. In fact, the internal stream is in memory, not file/console/whatever. I point this out only to avoid confusion.The simplicity of the Logger interface, and the lack of mandatory rigidity in how one might configure it (particularly w/r/t per-Component
verbosity and output format), assures the sky is the limit for how one implements their own custom Logger. However, in the absence of great reasons not to, we suggest one follows the lead of out-of-the-box existing Logger
s in Flow, which adds a degree of rigidity as to the implementation but also seems to provide all the features seemingly commonly desired in practice. Namely, like (say) Simple_ostream_logger, Buffer_logger, and Async_file_logger, do this:
ostream
-subclass member to a target device, if at all possible. (boost.asio will let you even write to network this way; but at least console output, file output, and memory string output are 100% practical via ostream
s. Existing Logger
s provide examples.)ostream
, the formatting thereof being configurable in a uniform way via the saved Config.Logger
subclass constructor. The user would simply follow the documentation for Config, and you need neither re-implement nor re-document configurability of your Logger.Reminder: Config and Ostream_log_msg_writer are optional to use, and one can use one, both, or neither (though the latter itself does expect one of the former; of course you can just load up your own new Config, in case you don't want to use a user Config taken via your constructor API). However, unless there's something insufficient about them, various benefits abound in using both. Furthermore, if something is lacking, consider extending that system to the benefit of all/most other Logger
s as opposed to throwing it away and re-implementing something new for just your new Logger.
Having decided on that stuff, you also need to decide whether you will write to the output device/whatever synchronously or asynchronously. To wit, the thread safety discussion:
The degree of thread safety for either of the 2 main operations is completely up to the subclass implementer. Informally, we suggest here that you think about this topic carefully. In particular, without locking, do_log() may run concurrently with itself from multiple threads; depending on the medium to which it is writing, this may result in corruption or ugly output or turn out fine, depending on how you define "fine." Whether this is a concern or not is up to you. Note, however, that in practice as of this writing at least one Flow module (flow::net_flow) will definitely potentially execute should_log() and do_log() concurrently with themselves from multiple threads on the same Logger. In general that should be expected in all but the simplest single-threaded apps.
Implementation suggestions for Logger subclasses with respect to thread safety: There are 2 likeliest patterns one can use.
FILE*
or ofstream
), which is likely after each message, is usually synchronous and can be sporadically slow (consider having to spin up a sleeping hard drive for instance). That would not only block the log-call-site thread but also any competing logging threads at that time. That is probably fine in many non-production scenarios, but in a production heavy-duty server it's not OK.Both general patterns are formally supported. To use pattern 1, have your Logger implementation's logs_asynchronously() return false
. To use pattern 2, have it use true
. The precise implications are documented in doc header of do_log().
We assume for this discussion that the notion of order of final output (to device/file/network/whatever) exists, and that the Logger implementation indeed safely outputs message M1 entirely before M2, or vice versa, for every pair of messages (in this context by message we mean message+metadata pair) ever passed to do_log(). With that assumption in effect (IF indeed it is), the present text requires that the following is guaranteed:
L.do_log(M1);
is called before L.do_log(M2)
, and both are successfully output by L, then the final output order must have M1 precede M2, not vice versa.Note that this is only tangentially related to any time stamps one might see in the final output.
See also notes on log output order in FLOW_LOG_WARNING() doc header (which applies to all log call sites). The behavior described there is a function of the underlying Logger following the above formal requirements for thread-safe Logger implementations.
|
pure virtual |
Given a message and its severity, logs that message and possibly severity WITHOUT checking whether it should be logged (i.e., without performing logic that should_log() performs).
The logging is guaranteed to be synchronous if !logs_asynchronously()
; but may be asynchronous otherwise (more on this below).
The convenience macros FLOW_LOG_...()
combine this with should_log() to make it so that a message is only constructed if should_log() == true
, and if so, constructs and logs it; otherwise almost no computing or storage resources are spent, and the message is not logged.
Expectations of what should or should not be included in msg
are of some importance. They are as follows. To summarize, msg
should include the message (as specified typically as the ARG_stream_fragment
arg to FLOW_LOG_WARNING() and buddies); and *msg_metadata
should include everything else. This design provides maximum flexibility to the Logger::do_log() implementation to structure the final output's contents (in the log file, or console, or wherever) as it sees fit, cosmetically and size-wise.
Note on trailing newline(s): msg
must include any trailing newline(s) that are required to be output. By convention, do_log() itself will print a message terminator (often in fact a newline) after each message, if applicable. Hence typically there is no trailing newline at the end of most msg
s, and one would include N of them if and only if one intentionally desires N trailing blank lines (possible but atypical).
Let ASYNC = the value logs_asynchronously() returns (note for a given *this
it must always be the same value by that API's contract). Then do_log() must act as follows:
false
: Do not make a copy of msg
; output it synchronously. Do not make a copy of *metadata
. Do not delete metadata
. Output any of its contents synchronously.true
: Optionally make a copy of msg
, unless you are able to output it synchronously, in which case there is no need. Do not make a copy of *metadata
. You must delete metadata
at some point; failing to do so will leak it. (Note: We are intentionally avoiding using shared_ptr
or even unique_ptr
, for the perf savings, since logging is ubiquitous.) Output *metadata
contents either synchronously or asynchronously.The only formal requirement, however, is simply: You must delete metadata;
at some future point <=iff=> ASYNC is true
. The other requirements just above are informal but of no less import.
msg
.metadata | All information to potentially log in addition to msg . |
msg | The message. See details above. Short version: exclude anything from metadata ; exclude any ever-present terminating newline. |
Implemented in flow::log::Async_file_logger, flow::log::Buffer_logger, flow::log::Serial_file_logger, and flow::log::Simple_ostream_logger.
|
pure virtual |
Must return true
if do_log() at least sometimes logs the given message and metadata (e.g., time stamp) after do_log() returns; false
if this never occurs (i.e., it logs synchronously, always).
do_log() doc header formally describes the implications of this.
This must always return the same value, for a given *this
.
This method is intended for internal use by the flow::log system; informally it is not expected the user will call it. Technically there is no harm in doing so. (It would have been private
but cannot due to certain C++ limitations, and certain contrived ways to do it are just not worth the trouble.)
The "certain C++ limitations" are that FLOW_LOG_WITHOUT_CHECKING() must access it, but it is a macro and cannot be involved in friend
ship. A contrived way to resolve it would be to make some detail/
helper free function the friend
, which would call this method, and invoke that free function from the macro. All that just to move a harmless thing into private
– I think not worth it, but an argument could be made.
Implemented in flow::log::Async_file_logger, flow::log::Buffer_logger, flow::log::Serial_file_logger, and flow::log::Simple_ostream_logger.
|
static |
Same as set_thread_info_in_msg_metadata() but targets the given two variables as opposed to a Msg_metadata.
call_thread_nickname | Non-null pointer to value to modify. See above. |
call_thread_id | Non-null pointer to value to modify. See above. |
Definition at line 125 of file log.cpp.
References s_this_thread_nickname_ptr.
Referenced by set_thread_info_in_msg_metadata().
|
static |
Loads msg_metadata->m_call_thread_nickname
(if set) or else msg_metadata->m_call_thread_id
, based on whether/how this_thread_set_logged_nickname() was last called in the current thread.
The two members should be set to ther default-constructed values on entry to the present function.
msg_metadata | Non-null pointer to structure to modify. See above. |
Definition at line 144 of file log.cpp.
References flow::log::Msg_metadata::m_call_thread_id, flow::log::Msg_metadata::m_call_thread_nickname, and set_thread_info().
|
pure virtual |
Given attributes of a hypothetical message that would be logged, return true
if that message should be logged and false
otherwise (e.g., if the verbosity of the message is above the current configured verbosity threshold for the Component specified).
The convenience macros FLOW_LOG_...()
combine this with do_log() to make it so that a message is only built if should_log() == true
, and (if so) builds and logs it; otherwise almost no computing or storage resources are spent, and the message is neither built nor logged logged. The verb "to build message" here more formally means "to execute the `ostream<<` fragment passed to macro by
writing characters to some internally maintained `ostream` accordingly."
sev | Severity of the message. |
component | Component of the message. Reminder: component.empty() == true is allowed; which isn't to say it will or won't result in this method returning true , but that it will return and not act in undefined fashion. |
true
if it should be logged; false
if it should not. Implemented in flow::log::Async_file_logger, flow::log::Buffer_logger, flow::log::Serial_file_logger, and flow::log::Simple_ostream_logger.
Referenced by flow::async::asio_exec_ctx_post(), flow::perf::Checkpointing_timer::Checkpointing_timer(), flow::net_flow::Low_lvl_packet::create_from_raw_data_packet(), flow::util::Basic_blob< Allocator, S_SHARING_ALLOWED >::emplace_copy(), flow::util::Basic_blob< Allocator, S_SHARING_ALLOWED >::make_zero(), flow::util::Basic_blob< Allocator, S_SHARING_ALLOWED >::reserve(), flow::util::Basic_blob< Allocator, S_SHARING_ALLOWED >::share(), flow::util::Basic_blob< Allocator, S_SHARING_ALLOWED >::share_after_split_equally_impl(), flow::util::Basic_blob< Allocator, S_SHARING_ALLOWED >::share_after_split_left(), flow::util::Basic_blob< Allocator, S_SHARING_ALLOWED >::share_after_split_right(), flow::net_flow::Drop_timer::start_timer(), flow::util::Basic_blob< Allocator, S_SHARING_ALLOWED >::sub_copy(), and flow::util::Basic_blob< Allocator, S_SHARING_ALLOWED >::swap_impl().
|
static |
ostream
manipulator function that, if output via operator<<
to an ostream
, will cause the current thread's logging-worthy string name to be output to that stream.
See this_thread_set_logged_nickname() for details of what this string will actually be.
Recall that an ostream
manipulator is invoked in the style of endl
and flush
; for example: cout << endl;
. It is atypical to call it directly as opposed to via the overloaded "shift" operator.
Note that typically this is not invoked directly by the user but rather used in the FLOW_LOG_...()
macros' implementation guts which is the original use case and hence reason for its existence. However, there's no rule against direct uses, and it could prove useful at some point. Any use beyond logging or debugging is not recommended however (in particular, do not use to make any algorithmic decisions).
This call is safe w/r/t concurrent execution with itself and this_thread_set_logged_nickname() in other thread(s).
os | Stream to which to write thread's name. |
os
. Definition at line 108 of file log.cpp.
References s_this_thread_nickname_ptr.
std::ostream * flow::log::Logger::this_thread_ostream | ( | ) | const |
Returns the stream dedicated to the executing thread and this
Logger, so that the caller can apply state-setting formatters to it.
If you write characters to it, or otherwise do anything othen than set formatting state, or try to affect buffering behavior, behavior is undefined. Usage example:
Note that you could just as well apply the intended formatters via regular log statements. However, there are disadvantages to that approach – but they do not always apply. The disadvantages are listed below; but the short version is you should typically use the present method if and only if you are attempting to affect subsequent logging at large, not a particular fragment of a particular message.
Formally, the disadvantages of affecting formatting state of the underlying stream via log macros:
FLOW_LOG_INFO_WITHOUT_CHECKING(...formatter... << ...formatter... << ...);
. This is stylistically dubious, because the lack of characters being output means the severity (INFO in this case) is disregarded and is a dummy value.<<
operator arguments, there are others than do not use that syntax. For example, ostream::setf()
is a method of std::ostream
. Thus the log macros do not help.Recall that the stream involved is completely orthogonal to any underlying stream that may be ultimately output to by Logger for the actual, ultimate output of characters. E.g., if Logger happens to be Simple_ostream_logger targeted at std::cout
, the above snippet would in no way touch std::cout
formatting. In fact, Logger may not even use streams for output; that is an orthogonal implementation detail.
Definition at line 150 of file log.cpp.
References flow::log::Thread_local_string_appender::appender_ostream(), and flow::log::Thread_local_string_appender::get_this_thread_string_appender().
Referenced by flow::log::beautify_chrono_logger_this_thread().
|
static |
Sets or unsets the current thread's logging-worthy string name; optionally sets the OS thread name (such as visible in top
output).
The logging-worthy name is always set or unset; the OS name is modified only if also_set_os_name == true
arg is set. thread_nickname
can thus be set to something more descriptive than any default, such as: "native_main" or "worker_port_2231."
FLOW_LOG_*()
macros pass it automatically to the appropriate log::Logger. All out-of-the-box Logger
s will then log either the name set here (if not blank) or the thread ID (if blank). (Custom Logger
s can ignore these data and not log them; but presumably most will at least optionally log them.)ps H -C $cmd -o pid\ tid\ cmd\ comm # The comm column will be the thread name; set $proc = process name.
top -H
(thread mode – or just top
and press H key for the same effect).More precisely, there are 3 states for each thread: before this_thread_set_logged_nickname() is called; after it is called with blank name; and after it's called non-blank name. The semantics are as follows:
thread_nickname
.ps
, top
, etc. will show the thread name as equal to the process name.ps
, top
, etc. will show the thread name as the thread ID (truncated to N characters, though this is unlikely to be exceeded by real thread IDs).ps
, top
, etc. will show the thread name as equal to thread_nickname
(truncated to N characters).thread_nickname
is blank. Then ps
, top
, etc. output will still be useful and possible to cross-reference with log output, say.man pthread_setname_np
as 15 not counting the NUL terminator. Therefore ideally keep the thread_nickname.size()
to at most N.Subsequently obtaining the nickname involves a linear string copy; the cost of this is worth considering given that this is potentially done for every single log call site, if the nickname is indeed set. However, most string
implementations provide an optimization that uses a union
(or equivalent) technique to store short strings in the same place as the data members (pointer, size, capacity) required for long strings; meaning such short string
s cost no more to copy than an empty one does. In gcc 5, this is 15 bytes or char
s, but implementations vary.
Therefore, it is actively encouraged that you keep the length of thread_nickname
low. "Low" depends on the compiler, but keeping it somewhere at or under 15 characters is likely good. If you do so, the effective cost (at a log call site) will be the same as if thread_nickname.empty()
, so one could not do better. Note, also, that the OS-name (in Linux) max length happens to also be 15 (see N discussion above), so there is convenient synergy there.
This call is safe w/r/t concurrent execution with itself and this_thread_logged_name_os_manip() in other thread(s) for a given *this
. It is thread-local in nature.
this_thread_set_logged_nickname() is an incomplete name, in that it (optionally) also affects the OS thread name. The function was not renamed for compatibility reasons, as the technically incomplete name is in my (ygoldfel) opinion still acceptably descriptive.
thread_nickname | New nickname of thread; or "" to request the thread to not be nicknamed (thread ID will be used). In the "" case, no particular thread ID format should ever be assumed; it may be OS-dependent; but it can be informally assumed to be useful for thread identification purposes (probably unique per thread and somewhat readable, etc.). The non-blank value is copied and saved. |
logger_ptr | If non-null, this Logger will be used to log an INFO-severity message indicating the thread ID and new nickname (conceptually: [INFO] T...nickname...: Thread ...ID... has new nickname.). If null, nothing is logged. |
also_set_os_name | If and only true , thread_nickname (whether blank or not) also affects the current OS thread name. Otherwise it is not affected. |
Logger
s, since it is an app-wide function and potentially would want to be reflected in multiple loggers. It could take a pair of iterators or a container (in both cases, of template argument type). Arguably, though, this is overkill; as (1) most code paths deal with only one get_logger()
-owning object each; (2) naming of a thread is obvious enough in subsequent logs (hence this message only calls attention to that operation plus notes the thread ID before the nickname assignment, not necessarily the most critical of information). Certainly this zero-to-one-Logger
version must continue to be available for syntactic-sugary convenience, even if the to-do is performed. Definition at line 36 of file log.cpp.
References FLOW_ERROR_SYS_ERROR_LOG_WARNING, FLOW_LOG_INFO, FLOW_LOG_SET_CONTEXT, FLOW_LOG_WARNING, flow::util::ostream_op_string(), and s_this_thread_nickname_ptr.
|
staticprivate |
Thread-local storage for each thread's logged name (null pointer, which is default, means no nickname stored).
Definition at line 1561 of file log.hpp.
Referenced by set_thread_info(), this_thread_logged_name_os_manip(), and this_thread_set_logged_nickname().