On 4/26/05, Caleb Epstein <caleb.epstein@gmail.com> wrote:
OK, after seeing two of these tests continue to perform poorly and hang in some cases, I decided it was time to break out the big guns: Purify. It found a number of problems with test_mutex and test_read_write_mutex, which seem to be triggered by Boost.Test making use of a string after it has been freed.
Attached is the Purify output from test_mutex and test_read_write_mutex.
Digging a little deeper, I think the root of the problem is that multiple threads are touching the guts of the Boost.Test logging code at the same time, and its static variables are being manipulated without thread protections. Here's where Purify notices the problem: (/opt/SUNWspro/bin/../WS6U2/bin/sparcv9/dbx) where current thread: t@6 [1] purify_stop_here(0x1, 0x6b8c4, 0x0, 0x0, 0x0, 0x0), at 0x7e944 [2] _x_trap_and_go(0x74, 0x0, 0x42, 0x0, 0x0, 0x0), at 0x7e8dc [3] std::transform<char*,char*,char(*)(char)>(first = 0x1f2e7f "hread/test/util.inl", last = 0x1f2e92 "", result = 0x1f2e7f "hread/test/util.inl", op = 0xb1e98 = &boost::unit_test::set_unix_slash(char)), line 452 in "algorithm.cc" =>[4] boost::unit_test::unit_test_log_t::operator<<(this = 0x1d336c, f = STRUCT), line 277 in "unit_test_log.ipp" [5] boost::test_tools::tt_detail::check_impl(pr = CLASS, check_descr = CLASS, file_name = CLASS, line_num = 34U, tl = PASS, ct = CHECK_EQUAL, num_of_args = 2U, ...), line 144 in "test_tools.ipp" [6] boost::test_tools::tt_detail::check_impl<boost::test_tools::tt_detail::equal_impl_frwd,int,int>(P = STRUCT, check_descr = CLASS, file_name = CLASS, line_num = 34U, tool_level = CHECK, ct = CHECK_EQUAL, arg0 = 1, arg0_descr = 0x191f95 "boost::xtime_get(&xt, boost::TIME_UTC)", arg1 = 1, arg1_descr = 0x191fbc "static_cast<int>(boost::TIME_UTC)"), line 402 in "test_tools.hpp" [7] __unnamed_lpburU7kbCGP9::delay(secs = 0, msecs = 100, nsecs = 0), line 34 in "util.inl" [8] test_lock<boost::mutex>::operator()(this = 0x7e27fbe3), line 44 in "test_mutex.cpp" [9] do_test_mutex(), line 169 in "test_mutex.cpp" [10] boost::detail::function::void_function_invoker0<void(*)(),void>::invoke(function_ptr = UNION), line 103 in "function_template.hpp" [11] boost::function0<void,int>::operator()(this = 0x7e27fd24), line 576 in "function_template.hpp" [12] thread_proxy(param = 0x7e3ffb38), line 113 in "thread.cpp" And here is the method in question: (/opt/SUNWspro/bin/../WS6U2/bin/sparcv9/dbx) l 271 unit_test_log_t& 272 unit_test_log_t::operator<<( log::file const& f ) 273 { 274 assign_op( s_log_impl().m_entry_data.m_file, f.m_file_name, 0 ); 275 276 // normalize file name 277 std::transform( s_log_impl().m_entry_data.m_file.begin(), s_log_impl().m_entry_data.m_file.end(), 278 s_log_impl().m_entry_data.m_file.begin(), 279 &set_unix_slash ); 280 But s_log_impl().m_entry_data.m_file is not equal to f.m_file_name as it should be: (/opt/SUNWspro/bin/../WS6U2/bin/sparcv9/dbx) print f.m_file_name f.m_file_name = { m_begin = 0x191f52 "/home/nbde52d/src/boost-regression/boost/libs/thread/test/util.inl" m_end = 0x191f94 "" } (/opt/SUNWspro/bin/../WS6U2/bin/sparcv9/dbx) print s_log_impl().m_entry_data.m_file boost::unit_test::__unnamed_lpburnXebCmne::s_log_impl().m_entry_data.m_file = { __data_ = { __data_ = 0x1f2f10 "../libs/thread/test/test_mutex.cpp" } __nullref = struct __rwstd::__null_string_ref_rep<char,std::char_traits<char>,std::allocator<char>,__rwstd::__string_ref_rep<std::allocator<char>
/* STATIC CLASS */ }
-- Caleb Epstein caleb dot epstein at gmail dot com