Boost Users :

Date view	Thread view	Subject view	Author view

Subject: Re: [Boost-users] Tracking down a race condition
From: Shiou Ming Lee (shiouming.lee_at_[hidden])
Date: 2010-01-23 22:21:43

Next message: Robert Ramey: "Re: [Boost-users] binary size:boost::serialization and boost::variant"
Previous message: Jeff: "Re: [Boost-users] bjam library build problem in 1.41 for VS 2005?"
In reply to: Stephen Torri: "[Boost-users] Tracking down a race condition"
Next in thread: Roland Bock: "Re: [Boost-users] Tracking down a race condition"

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 (
http://www.google.com.sg/search?q=gdb+tutorial). Honestly I'm relatively
green in using gdb especially in debugging multi-threaded code so please
share your approach :)

On Sun, Jan 24, 2010 at 5:09 AM, Stephen Torri <storri_at_[hidden]> wrote:

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

text/html attachment: attachment

Next message: Robert Ramey: "Re: [Boost-users] binary size:boost::serialization and boost::variant"
Previous message: Jeff: "Re: [Boost-users] bjam library build problem in 1.41 for VS 2005?"
In reply to: Stephen Torri: "[Boost-users] Tracking down a race condition"
Next in thread: Roland Bock: "Re: [Boost-users] Tracking down a race condition"

Date view	Thread view	Subject view	Author view

Boost-users list run by williamkempf at hotmail.com, kalb at libertysoft.com, bjorn.karlsson at readsoft.com, gregod at cs.rpi.edu, wekempf at cox.net