From: john.groups_at_[hidden]
Date: 2008-01-19 22:37:55
Author: jtorjo
Date: 2008-01-19 22:37:54 EST (Sat, 19 Jan 2008)
New Revision: 42874
URL: http://svn.boost.org/trac/boost/changeset/42874
Log:
[logging]
v0.20.9, 19 jan 2008
- added profiler - allow profiling the logging code
- solved bug in logger_holder_by_value - many thanks to Olaf!
Added:
sandbox/logging/boost/logging/profile.hpp (contents, props changed)
Text files modified:
sandbox/logging/boost/logging/detail/log_keeper.hpp | 2
sandbox/logging/boost/logging/detail/logger_base.hpp | 2
sandbox/logging/boost/logging/detail/raw_doc/changelog.hpp | 4
sandbox/logging/boost/logging/detail/raw_doc/todo.hpp | 8
sandbox/logging/boost/logging/writer/on_dedicated_thread.hpp | 4
sandbox/logging/lib/logging/internal/vc8/loggingvc8/loggingvc8.vcproj | 11 -
sandbox/logging/lib/logging/internal/vc8/loggingvc8/test_now.cpp | 188 ++++++++++++++-------------------------
7 files changed, 84 insertions(+), 135 deletions(-)
Modified: sandbox/logging/boost/logging/detail/log_keeper.hpp
==============================================================================
--- sandbox/logging/boost/logging/detail/log_keeper.hpp (original)
+++ sandbox/logging/boost/logging/detail/log_keeper.hpp 2008-01-19 22:37:54 EST (Sat, 19 Jan 2008)
@@ -87,7 +87,7 @@
template<class type, class gather_msg = default_> struct logger_holder_by_value : logger_holder<type, gather_msg> {
typedef logger_holder<type, gather_msg> base_type;
- BOOST_LOGGING_FORWARD_CONSTRUCTOR_INIT(logger_holder_by_value, m_log, init)
+ BOOST_LOGGING_FORWARD_CONSTRUCTOR_INIT(logger_holder_by_value, m_log_value, init)
private:
void init() {
base_type::init( &m_log_value);
Modified: sandbox/logging/boost/logging/detail/logger_base.hpp
==============================================================================
--- sandbox/logging/boost/logging/detail/logger_base.hpp (original)
+++ sandbox/logging/boost/logging/detail/logger_base.hpp 2008-01-19 22:37:54 EST (Sat, 19 Jan 2008)
@@ -25,7 +25,7 @@
#include <boost/logging/detail/after_being_destroyed.hpp>
#ifndef JT28092007_logger_HPP_DEFINED
-#error don't include this directly. include <boost/logging/logging.hpp> instead
+#error donot include this directly. include <boost/logging/logging.hpp> instead
#endif
namespace boost { namespace logging {
Modified: sandbox/logging/boost/logging/detail/raw_doc/changelog.hpp
==============================================================================
--- sandbox/logging/boost/logging/detail/raw_doc/changelog.hpp (original)
+++ sandbox/logging/boost/logging/detail/raw_doc/changelog.hpp 2008-01-19 22:37:54 EST (Sat, 19 Jan 2008)
@@ -1,7 +1,9 @@
/**
@page page_changelog Changelog
-_at_section changelog_cur_ver Current Version: v0.20.8, 19 jan 2008
+@section changelog_cur_ver Current Version: v0.20.9, 19 jan 2008
+- added profiler - allow profiling the logging code
+- solved bug in logger_holder_by_value - many thanks to Olaf!
- refactored logger_holder - that is, we need to return logger_holder,
but keep logger_holder_by_value, for after_destroyed to work
- added test for using logger after it's been destroyed
Modified: sandbox/logging/boost/logging/detail/raw_doc/todo.hpp
==============================================================================
--- sandbox/logging/boost/logging/detail/raw_doc/todo.hpp (original)
+++ sandbox/logging/boost/logging/detail/raw_doc/todo.hpp 2008-01-19 22:37:54 EST (Sat, 19 Jan 2008)
@@ -24,6 +24,9 @@
- @c normal on_dedicated_thead - remove dependency on boost::thread
+- @c normal profiler - we can care about threads as well (that is, for instance, when logging on another thread, see how much time
+ it takes from the threads that actually work)
+
- @c low in the same way I've created convert_to_base(), I can create a convert_to_top(), on top of which
I can create my own way to gather message, and then write it.
@@ -37,16 +40,13 @@
- @c high test TSS on vs2003 and gcc/pthreads \n
(note: tested on pthreads; however - about internal implementation : 2 TSS objects are leaked on pthreads, need to see why)
-- @c must_have if *used* before main, it'll cache the messages, and then write them ASAP; \n
- will have a func - like, do_write() - which will write all that was cached, and then turn cache off \n
- ----- i have to see if reasonable to later ask if a log is enabled or not, or just dump all messages written before initializing the log
-
- @c normal allow to see how much time logging actually takes \n
This should work even if logging happens on a dedicated thread. Give a name to your tracker - so you can track logging time when messages are logged,
and time logging actually happens (on dedicated thread).
I should feature this on the documentation - I don't think any other lib has this! I should be able to add this for filter as well.
- @c low configuration : should allow the library to be configured at runtime, from a file, much like log4j
+ note: see formatter::named_spacer, destination::named
- Votes : 1
- @c low hierarchical logs : just like log4j - be able to have some logs inherit from parent logs
Added: sandbox/logging/boost/logging/profile.hpp
==============================================================================
--- (empty file)
+++ sandbox/logging/boost/logging/profile.hpp 2008-01-19 22:37:54 EST (Sat, 19 Jan 2008)
@@ -0,0 +1,199 @@
+// profiler.hpp
+
+// Boost Logging library
+//
+// Author: John Torjo, www.torjo.com
+//
+// Copyright (C) 2007 John Torjo (see www.torjo.com for email)
+//
+// Distributed under the Boost Software License, Version 1.0.
+// (See accompanying file LICENSE_1_0.txt or copy at
+// http://www.boost.org/LICENSE_1_0.txt)
+//
+// See http://www.boost.org for updates, documentation, and revision history.
+// See http://www.torjo.com/log2/ for more details
+
+/**
+ Allows you to profile your application' logging
+
+ That is, see how much CPU time is taken for logging
+*/
+
+#ifndef JT28092007_profiler_HPP_DEFINED
+#define JT28092007_profiler_HPP_DEFINED
+
+#if defined(_MSC_VER) && (_MSC_VER >= 1020)
+# pragma once
+#endif
+
+#include <boost/logging/detail/fwd.hpp>
+
+#include <boost/date_time/microsec_time_clock.hpp>
+#include <boost/date_time/posix_time/posix_time_types.hpp>
+#include <boost/date_time/posix_time/ptime.hpp>
+#include <boost/function.hpp>
+#include <string>
+#include <sstream>
+
+namespace boost { namespace logging { namespace profile {
+
+
+/**
+ @brief Computes profiling information, and can show it to the user
+
+*/
+struct compute {
+ enum type {
+ gather = 0,
+ writer,
+ filter,
+ on_other_thread,
+
+ last_ = on_other_thread
+ };
+
+ typedef ::boost::function<void(const std::string&)> log_function;
+ static void nothing(const std::string&) {}
+
+ static compute & inst() {
+ static compute c;
+ return c;
+ }
+
+ void add_period(const ::boost::int64_t & mcs, type t) {
+ // note : this will work even after this object has been destroyed (since it's a global)
+ m_cpu_times[t] += mcs;
+ }
+
+ void log_results(log_function l) {
+ m_log = l;
+ }
+protected:
+ compute() {
+ m_log = ¬hing;
+ }
+ ~compute() {
+ dump_results();
+ }
+private:
+ void dump_results() {
+ std::ostringstream out;
+ out << "gather time: "
+ << (m_cpu_times[gather] / 1000000) << "." << (m_cpu_times[gather] % 1000000) << " seconds " << std::endl;
+ out << "write time: "
+ << (m_cpu_times[writer] / 1000000) << "." << (m_cpu_times[writer] % 1000000) << " seconds " << std::endl;
+ out << "filter time: "
+ << (m_cpu_times[filter] / 1000000) << "." << (m_cpu_times[filter] % 1000000) << " seconds " << std::endl;
+ out << "otherthread time: "
+ << (m_cpu_times[on_other_thread] / 1000000) << "." << (m_cpu_times[on_other_thread] % 1000000) << " seconds " << std::endl;
+ m_log( out.str() );
+ }
+
+private:
+ compute(const compute&);
+ void operator=(const compute&);
+
+private:
+ // the CPU time taken for each activity
+ //
+ // note: we don't use std::vector; we want this to be available even after destruction
+ // (if logs are used after they've been destroyed
+ boost::int64_t m_cpu_times[ last_ + 1];
+
+ // where should we dump the results?
+ log_function m_log;
+};
+
+
+
+struct scoped_compute {
+ compute& m_comp;
+ compute::type m_type;
+
+ ::boost::posix_time::ptime m_start, m_end;
+
+ scoped_compute(compute& comp, compute::type type) : m_comp(comp), m_type(type) {
+ m_start = ::boost::posix_time::microsec_clock::local_time();
+ }
+ ~scoped_compute() {
+ m_end = ::boost::posix_time::microsec_clock::local_time();
+ m_comp.add_period( (m_end - m_start).total_microseconds() , m_type);
+ }
+
+};
+
+
+template<class msg_type, class base_type> struct on_dedicated_thread ;
+
+template<class gather_msg> struct compute_gather : gather_msg {
+ compute_gather() : m_lk( get_compute(), compute::gather) {}
+ compute_gather(const compute_gather& other) : : m_lk( get_compute(), compute::gather), gather_msg(other) {}
+
+ compute& get_compute() const { return compute::inst(); }
+private:
+ scoped_compute m_lk;
+};
+
+template<class writer_msg> struct compute_write : writer_msg {
+ compute& get_compute() const { return compute::inst(); }
+
+ template<class msg_type> void operator()(const msg_type& msg) const {
+ scoped_compute lk( get_compute(), compute::writer );
+ writer_msg::operator()(msg);
+ }
+
+ // just in case you do write on another thread
+ virtual void write_array() const {
+ scoped_compute lk( get_compute(), compute::on_other_thread );
+ write_array_impl( *this);
+ }
+private:
+ template<class msg_type, class base_type> void write_array_impl(const on_dedicated_thread<msg_type,base_type> &) const {
+ // call base class's implementation
+ writer_msg::write_array();
+ }
+
+ // does not derive from on_dedicated_thread
+ void write_array_impl(...) const {}
+};
+
+/**
+ In case you want to profile your filter, there's just one requirement:
+ - your function must be called @c is_enabled() and be const
+*/
+template<class filter_msg> struct compute_filter : filter_msg {
+ // is_enabled - for any up to 5 params - const function
+ compute& get_compute() const { return compute::inst(); }
+
+ bool is_enabled() const {
+ scoped_compute lk( get_compute(), compute::filter );
+ return filter_msg::is_enabled();
+ }
+ template<class p1> bool is_enabled(const p1 & v1) const {
+ scoped_compute lk( get_compute(), compute::filter );
+ return filter_msg::is_enabled(v1);
+ }
+ template<class p1, class p2> bool is_enabled(const p1 & v1, const p2 &v2) const {
+ scoped_compute lk( get_compute(), compute::filter );
+ return filter_msg::is_enabled(v1, v2);
+ }
+ template<class p1, class p2, class p3> bool is_enabled(const p1 & v1, const p2 &v2, const p3 & v3) const {
+ scoped_compute lk( get_compute(), compute::filter );
+ return filter_msg::is_enabled(v1, v2, v3);
+ }
+ template<class p1, class p2, class p3, class p4> bool is_enabled(const p1 & v1, const p2 &v2, const p3 & v3, const p4 & v4) const {
+ scoped_compute lk( get_compute(), compute::filter );
+ return filter_msg::is_enabled(v1, v2, v3, v4);
+ }
+ template<class p1, class p2, class p3, class p4, class p5> bool is_enabled(const p1 & v1, const p2 &v2, const p3 & v3, const p4 & v4, class p5 & v5) const {
+ scoped_compute lk( get_compute(), compute::filter );
+ return filter_msg::is_enabled(v1, v2, v3, v4, v5);
+ }
+
+};
+
+
+}}}
+
+#endif
+
Modified: sandbox/logging/boost/logging/writer/on_dedicated_thread.hpp
==============================================================================
--- sandbox/logging/boost/logging/writer/on_dedicated_thread.hpp (original)
+++ sandbox/logging/boost/logging/writer/on_dedicated_thread.hpp 2008-01-19 22:37:54 EST (Sat, 19 Jan 2008)
@@ -176,7 +176,9 @@
}
}
- void write_array() const {
+protected:
+ // note: this is virtual, so that if you want to do profiling, you can (that is, you can override this as well
+ virtual void write_array() const {
typedef typename context_type::array array;
array msgs;
Modified: sandbox/logging/lib/logging/internal/vc8/loggingvc8/loggingvc8.vcproj
==============================================================================
--- sandbox/logging/lib/logging/internal/vc8/loggingvc8/loggingvc8.vcproj (original)
+++ sandbox/logging/lib/logging/internal/vc8/loggingvc8/loggingvc8.vcproj 2008-01-19 22:37:54 EST (Sat, 19 Jan 2008)
@@ -328,13 +328,6 @@
<File
RelativePath=".\test_now.cpp"
>
- <FileConfiguration
- Name="Test|Win32"
- >
- <Tool
- Name="VCCLCompilerTool"
- />
- </FileConfiguration>
</File>
</Filter>
<Filter
@@ -457,6 +450,10 @@
>
</File>
<File
+ RelativePath="..\..\..\..\..\boost\logging\profile.hpp"
+ >
+ </File>
+ <File
RelativePath="..\..\..\..\..\boost\logging\detail\scenario.hpp"
>
</File>
Modified: sandbox/logging/lib/logging/internal/vc8/loggingvc8/test_now.cpp
==============================================================================
--- sandbox/logging/lib/logging/internal/vc8/loggingvc8/test_now.cpp (original)
+++ sandbox/logging/lib/logging/internal/vc8/loggingvc8/test_now.cpp 2008-01-19 22:37:54 EST (Sat, 19 Jan 2008)
@@ -1,149 +1,97 @@
-/**
-_at_example mul_levels_mul_logers.cpp
+// log.h
+#ifndef LOG_H_header
+#define LOG_H_header
-_at_copydoc mul_levels_mul_logers
-
-_at_page mul_levels_mul_logers mul_levels_mul_logers.cpp Example
+#include <boost/logging/format_fwd.hpp>
+// If you want to use tags...
+#include <boost/logging/tags.hpp>
+// Step 1: Specify the class to hold the message
+namespace b_l = boost::logging;
+typedef b_l::tag::holder<
+ // string class
+ b_l::optimize::cache_string_one_str<>,
+ // tags
+ b_l::tag::thread_id, b_l::tag::time> log_string_type;
+// note: if you don't use tags, you can simply use a string class:
+// typedef b_l::optimize::cache_string_one_str<> log_string_type;
+BOOST_LOG_FORMAT_MSG( log_string_type )
-This usage:
-- You have multiple levels (in this example: debug < info < error)
-- You want to format the message before it's written
- (in this example: prefix it by time, by index and append newline to it)
-- You have several loggers
-- Each logger has several log destinations
+// if not compiling fast...
+#ifndef BOOST_LOG_COMPILE_FAST
+#include <boost/logging/format.hpp>
+#include <boost/logging/writer/ts_write.hpp>
-Optimizations:
-- use a cache string (from optimize namespace), in order to make formatting the message faster
+// If you use tags...
+#include <boost/logging/format/formatter/tags.hpp>
-Logs:
-- Error messages go into err.txt file
- - formatting - prefix each message by time, index, and append newline
-- Info output goes to console, and a file called out.txt
- - formatting - prefix each message by "[app]", time, and append newline
-- Debug messages go to the debug output window, and a file called out.txt
- - formatting - prefix each message by "[dbg]", time, and append newline
+// uncomment if you want to use do logging on a dedicated thread
+// #include <boost/logging/writer/on_dedicated_thread.hpp>
+#endif
-Here's how the output will look like:
+// Step 3 : Specify your logging class(es)
+using namespace boost::logging::scenario::usage;
+typedef use<
+ // how often do you manipulate (change) the filter?
+ filter_::change::often<10>,
+ // does the filter use levels?
+ filter_::level::no_levels,
+ // how often do you manipulate (change) the logger?
+ logger_::change::often<10>,
+ // for the logger: do you favor speed or correctness?
+ logger_::favor::correctness> finder;
+
+// Step 4: declare which filters and loggers you'll use
+BOOST_DECLARE_LOG_FILTER(g_l_filter, finder::filter)
+BOOST_DECLARE_LOG(g_l, finder::logger)
-The debug output window:
-_at_code
-07:52.30 [dbg] this is so cool 1
-07:52.30 [dbg] this is so cool again 2
-_at_endcode
+// Step 5: define the macros through which you'll log
+#define L_ BOOST_LOG_USE_LOG_IF_FILTER(g_l(), g_log_filter()->is_enabled() )
+// initialize thy logs..
+void init_logs();
-The console:
-_at_code
-07:52.30 [app] hello, world
-07:52.30 [app] good to be back ;) 4
-_at_endcode
+#endif
-The out.txt file:
-_at_code
-07:52.30 [dbg] this is so cool 1
-07:52.30 [dbg] this is so cool again 2
-07:52.30 [app] hello, world
-07:52.30 [app] good to be back ;) 4
-_at_endcode
-The err.txt file
-_at_code
-07:52.30 [1] first error 3
-07:52.30 [2] second error 5
-_at_endcode
-*/
-#include <boost/logging/format_fwd.hpp>
-// Step 1: Optimize : use a cache string, to make formatting the message faster
-BOOST_LOG_FORMAT_MSG( optimize::cache_string_one_str<> )
-#include <boost/logging/format.hpp>
-// Step 3 : Specify your logging class(es)
-typedef boost::logging::logger_format_write< > log_type;
-// Step 4: declare which filters and loggers you'll use (usually in a header file)
-BOOST_DECLARE_LOG_FILTER(g_log_level, boost::logging::level::holder ) // holds the application log level
-BOOST_DECLARE_LOG(g_log_err, log_type)
-BOOST_DECLARE_LOG(g_log_app, log_type)
-BOOST_DECLARE_LOG(g_log_dbg, log_type)
-// Step 5: define the macros through which you'll log
-#define LDBG_ BOOST_LOG_USE_LOG_IF_LEVEL(g_log_dbg(), g_log_level(), debug ) << "[dbg] "
-#define LERR_ BOOST_LOG_USE_LOG_IF_LEVEL(g_log_err(), g_log_level(), error )
-#define LAPP_ BOOST_LOG_USE_LOG_IF_LEVEL(g_log_app(), g_log_level(), info ) << "[app] "
+// log.cpp
+#include <boost/logging/format.hpp>
+#include <boost/logging/writer/ts_write.hpp>
+#include <boost/logging/format/formatter/tags.hpp>
-// Step 6: Define the filters and loggers you'll use (usually in a source file)
-BOOST_DEFINE_LOG_FILTER(g_log_level, boost::logging::level::holder )
-BOOST_DEFINE_LOG(g_log_err, log_type)
-BOOST_DEFINE_LOG(g_log_app, log_type)
-BOOST_DEFINE_LOG(g_log_dbg, log_type)
+// uncomment if you want to use do logging on a dedicated thread
+// #include <boost/logging/writer/on_dedicated_thread.hpp>
using namespace boost::logging;
-void mul_levels_mul_logers_example() {
- // Step 7: add formatters and destinations
- // That is, how the message is to be formatted and where should it be written to
-
- // Err log
- g_log_err()->writer().add_formatter( formatter::idx(), "[%] " );
- g_log_err()->writer().add_formatter( formatter::time("$hh:$mm.$ss ") );
- g_log_err()->writer().add_formatter( formatter::append_newline() );
- g_log_err()->writer().add_destination( destination::file("err.txt") );
-
- destination::file out("out.txt");
- // App log
- g_log_app()->writer().add_formatter( formatter::time("$hh:$mm.$ss ") );
- g_log_app()->writer().add_formatter( formatter::append_newline() );
- g_log_app()->writer().add_destination( out );
- g_log_app()->writer().add_destination( destination::cout() );
-
- // Debug log
- g_log_dbg()->writer().add_formatter( formatter::time("$hh:$mm.$ss ") );
- g_log_dbg()->writer().add_formatter( formatter::append_newline() );
- g_log_dbg()->writer().add_destination( out );
- g_log_dbg()->writer().add_destination( destination::dbg_window() );
-
- g_log_app()->turn_cache_off();
- g_log_err()->turn_cache_off();
- g_log_dbg()->turn_cache_off();
-
- // Step 8: use it...
- int i = 1;
- LDBG_ << "this is so cool " << i++;
- LDBG_ << "this is so cool again " << i++;
- LERR_ << "first error " << i++;
-
- std::string hello = "hello", world = "world";
- LAPP_ << hello << ", " << world;
-
- g_log_level()->set_enabled(level::error);
- LDBG_ << "this will not be written anywhere";
- LAPP_ << "this won't be written anywhere either";
-
- g_log_level()->set_enabled(level::info);
- LAPP_ << "good to be back ;) " << i++;
- LERR_ << "second error " << i++;
-
- // Step 9 : Enjoy!
+// Step 6: Define the filters and loggers you'll use
+BOOST_DEFINE_LOG_FILTER(g_log_filter, finder::filter )
+BOOST_DEFINE_LOG(g_l, finder::logger)
+
+
+void init_logs() {
+ // Add formatters and destinations
+ // That is, how the message is to be formatted...
+ g_l()->writer().add_formatter( formatter::tag::thread_id() );
+ g_l()->writer().add_formatter( formatter::tag::time("$hh:$mm.$ss ") );
+ g_l()->writer().add_formatter( formatter::idx() );
+ g_l()->writer().add_formatter( formatter::append_newline() );
+
+ // ... and where should it be written to
+ g_l()->writer().add_destination( destination::cout() );
+ g_l()->writer().add_destination( destination::dbg_window() );
+ g_l()->writer().add_destination( destination::file("out.txt") );
}
-
-
-
-
-int main() {
- mul_levels_mul_logers_example();
-}
-
-
-// End of file
-