Symptom: Adding indentation to log messages sometimes results in no indentation being added to incoming log messages.
Environment: Fedora 13
Boost version: trunk (1.44 prior to beta release)
Boost.Log version: 1.0
Compiler: GCC 4.4.4
Research: As I read the documentation I see that the Boost.Log talks about a non-empty log record is considered to be tied to the current thread. Since my program is single threaded I did not consider my initial attempt of using inline functions in a separate namespace with a namespace variable to keep track of indentation level to be a problem. My first attempt looked like:
namespace project {
namespace log {
static boost::uint32_t indent_level = 0;
#ifdef DEBUG
#include
#include
/*!
* \brief Record the entering of a function
* \param function String name of the function being entered
*/
template <typename Function>
inline void record_enter ( Function const& function )
{
BOOST_LOG_TRIVIAL(trace) << std::string ( indent_level, ' ' ) << boost::str ( boost::format ( "(Enter) %1%" ) % function );
indent_level += 2;
}
/*!
* \brief Record the exiting from a function
* \param function String name of the function being exited
*/
template <typename Function>
inline void record_exit ( Function const& function )
{
BOOST_LOG_TRIVIAL(trace) << std::string ( indent_level, ' ' ) << boost::str ( boost::format ( "(Exit) %1%" ) % function );
indent_level -= 2;
}
/*!
* \brief Record a message with one input
* \param format_string String written in the Boost.Format style to be used to parse input
* \param t1 Input value
*/
template
inline void record_debug ( Format const& format_string, T1 const& t1 )
{
BOOST_LOG_TRIVIAL(debug) << std::string ( indent_level, ' ' ) << boost::str ( boost::format ( format_string ) % t1 );
}
#else
template <typename Function>
inline void record_enter ( Function const& )
{}
template <typename Function>
inline void record_exit ( Function const& )
{}
template
inline void record_debug ( Format const&, T1 const& )
{}
} // namespace log
} // namespace project
#endif
When I run the code I see that the indentation is tracking by steps of 2 as I go into functions and reduced by 2 as I exit. There are exceptions where the indentation is 0 for a few lines or so then resumes the correct level. The problem I think is that there are more than one thread handling what I send to Boost.Log via BOOST_LOG_TRIVIAL. It as if there is one thread that has the correct level and another thread that has indent_level set to 0. For example:
1 [2010-Aug-06 12:03:15.329757] [0x88bb070] [trace] (Enter) void Test::functionA()
2 [2010-Aug-06 12:03:15.330867] [0x88bb070] [debug] Function A: do something
3 [2010-Aug-06 12:03:15.330989] [0x88bb070] [trace] (Enter) double Value::CalcX()
4 [2010-Aug-06 12:03:15.331124] [0x88bb070] [debug] X: 5
5 [2010-Aug-06 12:03:15.331188] [0x88bb070] [debug] Y: 10
6 [2010-Aug-06 12:03:15.331252] [0x88bb070] [trace] (Enter) double Value::CalcX()
My intial guess is that I have Boost.Log compiled multi-threaded and I have a single-threaded solution. Is there a way to track which thread was recording a message in Boost.Log? I would like to confirm Boost.Log is using different threads to handle my messages. Also is there a better way to do what I want?
Stephen
Stephen Torri, PhD
NAVAL SURFACE WARFARE CENTER DAHLGREN
17214 Ave B Suite 121
Dahlgren, Va. 22448
540-653-7055
I am not a contracting officer. I cannot modify or initiate contracts, nor do I have the authority to financially commit the government in any way.
