Personally I will first try to output few lines of simple message to std err, see if if key codes (i.e. add_Trace(), processTraces(), constructor and destructor, ...) was executed AND in the correct order, providing that the problem is not too race to replicate. If it does not help then only I will use gdb for stepping through it (<a href="http://www.google.com.sg/search?q=gdb+tutorial">http://www.google.com.sg/search?q=gdb+tutorial</a>). Honestly I'm relatively green in using gdb especially in debugging multi-threaded code so please share your approach :)<br> <br><br><div class="gmail_quote">On Sun, Jan 24, 2010 at 5:09 AM, Stephen Torri <span dir="ltr"><<a href="mailto:storri@torri.org">storri@torri.org</a>></span> wrote:<br><blockquote class="gmail_quote" style="border-left: 1px solid rgb(204, 204, 204); margin: 0pt 0pt 0pt 0.8ex; padding-left: 1ex;"> In the logging example I have been working on to learn more about boost<br> threads I have run across what I think is a race condition. If I compile<br> and run this sample program it will sometimes write out an error message<br> to a file. For example:<br> <br> 2010-01-23_16:2:23 (pid=10948 thread_id=0x92ce448) (II) funky<br> <br> Other times I see the file is blank. So can I say conclusively that its<br> a race condition? No. Either what is happening is a race condition where<br> the file is closed before the contents are written to the file or<br> something else is causing the logging message to be written sometimes<br> and not at others.<br> <br> So to recap:<br> <br> --- How can you track down a race condition?<br> --- Can I use 'strace' or 'gdb'?<br> <br> Stephen<br> <br> -------------------------------------------<br> #include <boost/cstdint.hpp><br> #include <boost/shared_ptr.hpp><br> #include <boost/thread/mutex.hpp><br> #include <boost/thread/condition_variable.hpp><br> #include <boost/thread/thread.hpp><br> #include <boost/utility.hpp><br> #include <boost/thread/once.hpp><br> #include <boost/scoped_ptr.hpp><br> #include <boost/type_traits/aligned_storage.hpp><br> #include <boost/bind.hpp><br> #include <boost/format.hpp><br> #include <boost/date_time/posix_time/posix_time.hpp><br> #include <boost/cstdint.hpp><br> <br> #include <fstream><br> #include <sstream><br> #include <vector><br> <br> namespace myproject { namespace api {<br> <br> � �/*!<br> � � * \brief Trace level constants<br> � � * \date 2003<br> � � * \author Stephen Torri<br> � � */<br> � �class TraceLevel {<br> � �public:<br> � � �enum Values {<br> � � � �NONE = 0,<br> � � � �WARN = 10,<br> � � � �ERROR = 20,<br> � � � �INFO = 30,<br> � � � �DEBUG = 40,<br> � � � �DETAIL = 50,<br> � � � �DATA = 60<br> � � �};<br> � �};<br> <br> �} // namespace api<br> } // namespace myproject<br> <br> namespace myproject { namespace interface {<br> <br> � �class ITraceable {<br> � �public:<br> <br> � � �typedef boost::shared_ptr<ITraceable> ptr_t;<br> <br> � � �virtual std::string get_Formatted_String() = 0;<br> <br> � � �virtual boost::uint32_t getLevel() = 0;<br> <br> � � �virtual boost::uint32_t getPID() = 0;<br> <br> � � �virtual boost::thread::id getThreadID() = 0;<br> � �};<br> �} // namespace interface<br> } // namespace myproject<br> <br> namespace myproject { namespace trace {<br> <br> � �class StringTraceable : public interface::ITraceable<br> � �{<br> � �public:<br> <br> � � �StringTraceable ( boost::uint32_t area, boost::uint32_t level, std::string name )<br> � � � �: m_area ( area ),<br> � � � � �m_level ( level ),<br> � � � � �m_name ( name )<br> � � �{<br> #ifndef WIN32<br> � � � �m_pid = getpid();<br> #else<br> � � � �m_pid = GetCurrentProcessId();<br> #endif /* WIN32 */<br> <br> � � � �m_thread_id = boost::this_thread::get_id();<br> � � �}<br> <br> � � �virtual ~StringTraceable(){}<br> <br> � � �virtual std::string get_Formatted_String()<br> � � �{<br> � � � �return m_name;<br> � � �}<br> <br> � � �virtual boost::uint32_t getLevel()<br> � � �{<br> � � � �return m_level;<br> � � �}<br> <br> � � �virtual boost::uint32_t getPID()<br> � � �{<br> � � � �return m_pid;<br> � � �}<br> <br> � � �virtual boost::thread::id getThreadID()<br> � � �{<br> � � � �return m_thread_id;<br> � � �}<br> <br> � �private:<br> <br> � � �boost::uint32_t m_area;<br> � � �boost::uint32_t m_level;<br> � � �boost::uint32_t m_pid;<br> � � �boost::thread::id m_thread_id;<br> � � �std::string m_name;<br> � �};<br> <br> � �template <typename UnsignedType><br> � �class NumberTraceable : public interface::ITraceable<br> � �{<br> � �public:<br> <br> � � �NumberTraceable ( boost::uint32_t area, boost::uint32_t level, std::string name, UnsignedType line )<br> � � � �: m_area ( area ),<br> � � � � �m_level ( level ),<br> � � � � �m_name ( name ),<br> � � � � �m_line ( line )<br> � � �{<br> #ifndef WIN32<br> � � � �m_pid = getpid();<br> #else<br> � � � �m_pid = GetCurrentProcessId();<br> #endif /* WIN32 */<br> <br> � � � �m_thread_id = boost::this_thread::get_id();<br> � � �}<br> <br> � � �virtual ~NumberTraceable(){}<br> <br> � � �virtual std::string get_Formatted_String()<br> � � �{<br> � � � �return m_name;<br> � � �}<br> <br> � � �virtual boost::uint32_t getLevel()<br> � � �{<br> � � � �return m_level;<br> � � �}<br> <br> � � �virtual boost::uint32_t getPID()<br> � � �{<br> � � � �return m_pid;<br> � � �}<br> <br> � � �virtual boost::thread::id getThreadID()<br> � � �{<br> � � � �return m_thread_id;<br> � � �}<br> <br> � �private:<br> <br> � � �boost::uint32_t m_area;<br> � � �boost::uint32_t m_level;<br> � � �boost::uint32_t m_pid;<br> � � �boost::thread::id m_thread_id;<br> � � �std::string m_name;<br> � � �UnsignedType m_line;<br> � �};<br> <br> <br> � �template <typename T><br> � �struct storage_for<br> � �{<br> � � �boost::aligned_storage<sizeof(T), boost::alignment_of<T>::value> data;<br> � �};<br> <br> � �template <typename T><br> � �class Singleton : boost::noncopyable<br> � �{<br> � �public:<br> <br> � � �static T& Instance()<br> � � �{<br> � � � �boost::call_once ( init, m_flag );<br> � � � �return *m_obj;<br> � � �}<br> <br> � � �static void init ()<br> � � �{<br> � � � �m_obj.reset ( new T() );<br> � � �}<br> <br> � �protected:<br> <br> � � �~Singleton(){}<br> � � �Singleton(){}<br> <br> � �private:<br> <br> � � �static boost::scoped_ptr<T> m_obj;<br> � � �static boost::once_flag m_flag;<br> � �};<br> <br> �} // namespace trace<br> } // namespace trace<br> <br> template <typename T> boost::scoped_ptr<T> myproject::trace::Singleton<T>::m_obj ( 0 );<br> template <typename T> boost::once_flag myproject::trace::Singleton<T>::m_flag = BOOST_ONCE_INIT;<br> <br> namespace myproject { namespace trace {<br> <br> � �class Trace_State_Utils {<br> � �public:<br> <br> � � �static std::string get_Level_String ( boost::uint32_t level )<br> � � �{<br> � � � �// Write message prefix<br> � � � �if ( level == api::TraceLevel::WARN )<br> � � � � � �{<br> � � � � � � � �return "(WW) ";<br> � � � � � �}<br> � � � �else if ( level == api::TraceLevel::ERROR )<br> � � � � � �{<br> � � � � � � � �return "(EE) ";<br> � � � � � �}<br> � � � �else if ( level == api::TraceLevel::INFO )<br> � � � � � �{<br> � � � � � � � �return "(II) ";<br> � � � � � �}<br> � � � �else if ( level == api::TraceLevel::DEBUG )<br> � � � � � �{<br> � � � � � � � �return "(DEBUG) ";<br> � � � � � �}<br> � � � �else if ( level == api::TraceLevel::DETAIL )<br> � � � � � �{<br> � � � � � � � �return "(DETAIL) ";<br> � � � � � �}<br> � � � �else if ( level == api::TraceLevel::DATA )<br> � � � � � �{<br> � � � � � � � �return "(DATA) ";<br> � � � � � �}<br> � � � �else<br> � � � � � �{<br> � � � � � � � �// We should not be here<br> � � � � � � � �abort();<br> � � � � � �}<br> � � �}<br> � �};<br> <br> <br> � �/* Idea taken from <a href="http://www.codeproject.com/debug/xytrace.asp" target="_blank">http://www.codeproject.com/debug/xytrace.asp</a><br> � � * (28 Jan 2002 - Xiangyang Liu)<br> � � *<br> � � * I have modified this so that we don't use varargs and use constant types<br> � � */<br> � �class Trace_State {<br> � �public:<br> <br> � � �typedef boost::shared_ptr<Trace_State> ptr_t;<br> <br> � � �Trace_State()<br> � � � �: m_file_prefix ( "Trace" )<br> � � �{}<br> <br> <br> � � �virtual ~Trace_State();<br> <br> � � �Trace_State ( std::string prefix );<br> <br> � � �void set_Trace_File_Prefix ( std::string name );<br> <br> � � �void set_Trace_Level ( boost::uint32_t level );<br> <br> � � �void set_Trace_Area_Mask ( boost::uint32_t mask );<br> <br> � � �void open_Trace_File ( void );<br> <br> � � �std::string get_ID_String ( void );<br> <br> � � �void close_Trace_File ( void );<br> <br> � � �boost::uint32_t get_Trace_Level ( void ) const;<br> <br> � � �boost::uint32_t get_Trace_Area_Mask ( void ) const;<br> <br> � � �bool is_Valid_Level ( boost::uint32_t lvl );<br> <br> � � �bool is_Valid_Area_Mask ( boost::uint32_t mask );<br> <br> <br> � � �void write_Message ( interface::ITraceable::ptr_t trace )<br> � � �{<br> � � � �// Write ID<br> � � � �m_log_stream << boost::format("%s (pid=%d thread_id=" )<br> � � � � �% this->get_ID_String()<br> � � � � �% trace->getPID()<br> � � � � � � � � � � << trace->getThreadID()<br> � � � � � � � � � � << ") "<br> � � � � � � � � � � << std::flush;<br> <br> � � � �m_log_stream << Trace_State_Utils::get_Level_String(trace->getLevel()) << trace->get_Formatted_String() << std::endl << std::flush;<br> � � �}<br> <br> <br> � �private:<br> <br> � � �std::string m_file_prefix;<br> <br> � � �std::ofstream m_log_stream;<br> � �};<br> <br> �} /* namespace trace */<br> } /* namespace trace */<br> <br> <br> namespace myproject { namespace trace {<br> <br> � �Trace_State::Trace_State( std::string prefix )<br> � � � �: m_file_prefix ( prefix )<br> � �{}<br> <br> � �Trace_State::~Trace_State()<br> � �{<br> � � � �this->close_Trace_File();<br> � �}<br> <br> � �void<br> � �Trace_State::set_Trace_File_Prefix ( std::string name )<br> � �{<br> � �}<br> <br> � �bool<br> � �Trace_State::is_Valid_Level ( boost::uint32_t lvl )<br> � �{<br> � � �return true;<br> � �}<br> <br> � �bool<br> � �Trace_State::is_Valid_Area_Mask ( boost::uint32_t )<br> � �{<br> � � �return true;<br> � �}<br> <br> � �void<br> � �Trace_State::set_Trace_Level ( boost::uint32_t level )<br> � �{<br> � �}<br> <br> � �void<br> � �Trace_State::set_Trace_Area_Mask ( boost::uint32_t mask )<br> � �{<br> � �}<br> <br> � �void<br> � �Trace_State::open_Trace_File ( void )<br> � �{<br> � � � �if ( ! m_log_stream.is_open() )<br> � � � � � �{<br> � � � � � � �// Create file name<br> � � � � � � �std::stringstream name;<br> <br> � � � � � � �name << boost::format("%s_%s.txt")<br> � � � � � � � �% m_file_prefix<br> � � � � � � � �% this->get_ID_String();<br> <br> � � � � � � �std::string file_name = name.str();<br> <br> � � � � � � �m_log_stream.open ( file_name.c_str() );<br> � � � � � �}<br> � �}<br> <br> � �std::string<br> � �Trace_State::get_ID_String ( void )<br> � �{<br> � � � �// Create id string<br> � � � �std::stringstream name;<br> <br> � � � �// Get current time<br> � � � �boost::posix_time::ptime now = boost::posix_time::second_clock::local_time();<br> <br> � � � �std::tm tm_ref = boost::posix_time::to_tm ( now );<br> <br> � � � �boost::gregorian::date today = now.date();<br> <br> � � � �name << boost::format ( "%1%_%2%:%3%:%4%" )<br> � � � � � �% boost::gregorian::to_iso_extended_string ( today )<br> � � � � � �% tm_ref.tm_hour<br> � � � � � �% tm_ref.tm_min<br> � � � � � �% tm_ref.tm_sec;<br> <br> � � � �return name.str();<br> � �}<br> <br> � �void<br> � �Trace_State::close_Trace_File ( void )<br> � �{<br> � � � �if ( m_log_stream.is_open() )<br> � � � � � �{<br> � � � � � � �m_log_stream << std::flush;<br> <br> � � � � � � �m_log_stream.close();<br> � � � � � �}<br> � �}<br> <br> � �boost::uint32_t<br> � �Trace_State::get_Trace_Level ( void ) const<br> � �{<br> � � � �return 0;<br> � �}<br> <br> � �boost::uint32_t<br> � �Trace_State::get_Trace_Area_Mask ( void ) const<br> � �{<br> � � � �return 0;<br> � �}<br> <br> } /* namespace trace */<br> } /* namespace trace */<br> <br> <br> <br> namespace myproject { namespace trace {<br> <br> � �//<br> � �// Turn Trace into a singleton class that contains a worker thread<br> � �// - Wait for data<br> � �// � - If data exists then process<br> � �// � - Else wait<br> � �// Add method for adding a ITraceable object. This will lock the logging vector, add<br> � �// �element then signal the boost condition variable<br> � �class Trace : public Singleton<Trace> {<br> <br> � � �friend class Singleton<Trace>;<br> <br> � �public:<br> <br> � � �~Trace();<br> <br> � � �static void write_Trace ( boost::uint32_t area, boost::uint32_t level, std::string name )<br> � � �{<br> � � � �interface::ITraceable::ptr_t string_ptr ( new StringTraceable ( area, level, name ) );<br> � � � �Trace::Instance().add_Trace ( string_ptr );<br> � � �}<br> <br> � � �template <typename UnsignedType><br> � � �static void write_Trace ( boost::uint32_t area, boost::uint32_t level, std::string format, UnsignedType value )<br> � � �{<br> � � � �interface::ITraceable::ptr_t unsigned_ptr ( new NumberTraceable<UnsignedType> ( area, level, format, value ) );<br> � � � �Trace::Instance().add_Trace ( unsigned_ptr );<br> � � �}<br> <br> � � �void add_Trace ( interface::ITraceable::ptr_t trace );<br> <br> � � �void set_Trace_Level ( boost::uint32_t level );<br> <br> � � �void set_Trace_Area_Mask ( boost::uint32_t mask );<br> <br> � � �void open_Trace_File ();<br> <br> � � �void close_Trace_File();<br> <br> � �private:<br> <br> � � �Trace();<br> <br> � � �// Worker thread functions<br> � � �void threadMain();<br> � � �void processTraces(boost::unique_lock<boost::mutex>& lock);<br> <br> � � �// Synchronization variables<br> � � �boost::mutex m_lock;<br> � � �boost::condition_variable m_condition;<br> <br> � � �// Data variables<br> � � �typedef std::vector < myproject::interface::ITraceable::ptr_t > QueueType;<br> � � �QueueType m_queue;<br> <br> � � �// Thread variables<br> � � �boost::shared_ptr<boost::thread> m_thread;<br> � � �bool m_hasWork;<br> <br> � � �// Logging<br> � � �Trace_State m_state;<br> � �};<br> <br> �} /* namespace trace */<br> } /* namespace myproject */<br> <br> namespace myproject { namespace trace {<br> <br> � �Trace::Trace ()<br> � � �: m_hasWork ( true ),<br> � � � �m_state ( "Trace" )<br> � �{<br> � � �// start thread<br> � � �m_thread = boost::shared_ptr<boost::thread> ( new boost::thread ( boost::bind ( &Trace::threadMain, this ) ) );<br> � �}<br> <br> � �Trace::~Trace()<br> � �{<br> � � �// stop thread<br> � � �{<br> � � � �boost::lock_guard<boost::mutex> lock ( m_lock );<br> � � � �m_hasWork = false;<br> � � �}<br> <br> � � �m_condition.notify_one();<br> <br> � � �m_thread->join();<br> � �}<br> <br> � �void Trace::add_Trace ( interface::ITraceable::ptr_t trace )<br> � �{<br> � � �// lock queue<br> � � �{<br> � � � �boost::lock_guard<boost::mutex> lock ( m_lock );<br> � � � �m_queue.push_back ( trace );<br> � � �}<br> <br> � � �m_condition.notify_one();<br> � �}<br> <br> � �void Trace::threadMain()<br> � �{<br> � � �boost::unique_lock<boost::mutex> lock ( m_lock );<br> <br> � � �while ( m_hasWork )<br> � � � �{<br> � � � � �if ( m_queue.size() == 0 )<br> � � � � � �{<br> � � � � � � �m_condition.wait ( lock );<br> � � � � � �}<br> � � � � �else<br> � � � � � �{<br> � � � � � � �this->processTraces(lock);<br> � � � � � �}<br> � � � �}<br> � �}<br> <br> � �void Trace::processTraces(boost::unique_lock<boost::mutex>& lock)<br> � �{<br> � � �assert ( lock.owns_lock() );<br> <br> � � �QueueType local_queue ( m_queue.begin(), m_queue.end() );<br> � � �m_queue.clear();<br> <br> � � �lock.unlock();<br> <br> � � �for ( QueueType::iterator pos = local_queue.begin();<br> � � � � � �pos != local_queue.end();<br> � � � � � �pos++ )<br> � � � �{<br> � � � � �myproject::interface::ITraceable::ptr_t trace_obj = (*pos);<br> � � � � �m_state.write_Message ( trace_obj );<br> � � � �}<br> <br> � � �lock.lock();<br> � �}<br> <br> � �void Trace::set_Trace_Level ( boost::uint32_t level )<br> � �{<br> � � �m_state.set_Trace_Level ( level );<br> � �}<br> <br> � �void Trace::set_Trace_Area_Mask ( boost::uint32_t mask )<br> � �{<br> � � �m_state.set_Trace_Area_Mask ( mask );<br> � �}<br> <br> � �void Trace::open_Trace_File()<br> � �{<br> � � �m_state.open_Trace_File();<br> � �}<br> <br> � �void Trace::close_Trace_File()<br> � �{<br> � � �m_state.close_Trace_File();<br> � �}<br> <br> �} /* namespace trace */<br> } /* namespace myproject */<br> <br> <br> int main ( int, char** )<br> {<br> �namespace trace = myproject::trace;<br> �namespace api = myproject::api;<br> <br> �trace::Trace::Instance().open_Trace_File();<br> <br> �myproject::interface::ITraceable::ptr_t tmp_ptr ( new trace::StringTraceable( 0, api::TraceLevel::INFO, "funky" ) );<br> <br> �trace::Trace::Instance().add_Trace ( tmp_ptr );<br> <br> �trace::Trace::Instance().close_Trace_File();<br> }<br> <br> <br> _______________________________________________<br> Boost-users mailing list<br> <a href="mailto:Boost-users@lists.boost.org">Boost-users@lists.boost.org</a><br> <a href="http://lists.boost.org/mailman/listinfo.cgi/boost-users" target="_blank">http://lists.boost.org/mailman/listinfo.cgi/boost-users</a><br> </blockquote></div><br>