Search code examples
boostboost-asiovalgrindboost-thread

Is there a bug in the boost asio HTTP Server 3 example or boost bug?


boost library version 1.53
Debian Linux 6.0 ( Linux 2.6.32-5-amd64 on x86_64 )

It is hard to test own software when valgrind log contains lots of warnings.
So with no changes I built the HTTP server3 example and run it under the Valgrind.
Take a look, please. Did I miss something?

valgrind --tool=helgrind --log-file=valgrind.log ./server3 0.0.0.0 83 5 /root/server3
Here is the Helgrind log (edited to 30000 body characters limit, full log http://pastebin.com/Vkbr9vsA):

Helgrind, a thread error detector
Copyright (C) 2007-2012, and GNU GPL'd, by OpenWorks LLP et al.
Using Valgrind-3.9.0.SVN and LibVEX; rerun with -h for copyright info
Command: ./server3 0.0.0.0 83 5 /root/server3
Parent PID: 8662

Lock at 0x524F5E0 was first observed
   at 0x4C2C692: pthread_mutex_lock (hg_intercepts.c:495)
   by 0x5043388: ??? (in /usr/lib/libboost_thread.so.1.53.0)
   by 0x5043498: boost::detail::set_current_thread_data(boost::detail::thread_data_base*) (in /usr/lib/libboost_thread.so.1.53.0)
   by 0x504380E: ??? (in /usr/lib/libboost_thread.so.1.53.0)
   by 0x4C2D6FE: mythread_wrapper (hg_intercepts.c:219)
   by 0x5256B4F: start_thread (pthread_create.c:304)
   by 0x5CE5A7C: clone (clone.S:112)

Possible data race during read of size 8 at 0x524F4E8 by thread #3
Locks held: none
   at 0x5043356: ??? (in /usr/lib/libboost_thread.so.1.53.0)
   by 0x5043498: boost::detail::set_current_thread_data(boost::detail::thread_data_base*) (in /usr/lib/libboost_thread.so.1.53.0)
   by 0x504380E: ??? (in /usr/lib/libboost_thread.so.1.53.0)
   by 0x4C2D6FE: mythread_wrapper (hg_intercepts.c:219)
   by 0x5256B4F: start_thread (pthread_create.c:304)
   by 0x5CE5A7C: clone (clone.S:112)

This conflicts with a previous write of size 8 by thread #2
Locks held: 1, at address 0x524F5E0
   at 0x5043416: ??? (in /usr/lib/libboost_thread.so.1.53.0)
   by 0x5043498: boost::detail::set_current_thread_data(boost::detail::thread_data_base*) (in /usr/lib/libboost_thread.so.1.53.0)
   by 0x504380E: ??? (in /usr/lib/libboost_thread.so.1.53.0)
   by 0x4C2D6FE: mythread_wrapper (hg_intercepts.c:219)
   by 0x5256B4F: start_thread (pthread_create.c:304)
   by 0x5CE5A7C: clone (clone.S:112)

----------------------------------------------------------------

Possible data race during read of size 4 at 0x524F60C by thread #3
Locks held: none
   at 0x50496D4: boost::detail::get_once_per_thread_epoch() (in /usr/lib/libboost_thread.so.1.53.0)
   by 0x5043361: ??? (in /usr/lib/libboost_thread.so.1.53.0)
   by 0x5043498: boost::detail::set_current_thread_data(boost::detail::thread_data_base*) (in /usr/lib/libboost_thread.so.1.53.0)
   by 0x504380E: ??? (in /usr/lib/libboost_thread.so.1.53.0)
   by 0x4C2D6FE: mythread_wrapper (hg_intercepts.c:219)
   by 0x5256B4F: start_thread (pthread_create.c:304)
   by 0x5CE5A7C: clone (clone.S:112)

This conflicts with a previous write of size 4 by thread #2
Locks held: none
   at 0x525C27B: pthread_key_create (pthread_key_create.c:44)
   by 0x525C82F: pthread_once (pthread_once.S:104)
   by 0x50496D3: boost::detail::get_once_per_thread_epoch() (in /usr/lib/libboost_thread.so.1.53.0)
   by 0x5043361: ??? (in /usr/lib/libboost_thread.so.1.53.0)
   by 0x5043498: boost::detail::set_current_thread_data(boost::detail::thread_data_base*) (in /usr/lib/libboost_thread.so.1.53.0)
   by 0x504380E: ??? (in /usr/lib/libboost_thread.so.1.53.0)
   by 0x4C2D6FE: mythread_wrapper (hg_intercepts.c:219)
   by 0x5256B4F: start_thread (pthread_create.c:304)

----------------------------------------------------------------

Possible data race during read of size 8 at 0x524F4E8 by thread #1
Locks held: 1, at address 0x61A1E20
   at 0x5043356: ??? (in /usr/lib/libboost_thread.so.1.53.0)
   by 0x5043478: boost::detail::get_current_thread_data() (in /usr/lib/libboost_thread.so.1.53.0)
   by 0x5047875: boost::detail::interruption_checker::interruption_checker(pthread_mutex_t*, pthread_cond_t*) (in /usr/lib/libboost_thread.so.1.53.0)
   by 0x5044002: boost::thread::join_noexcept() (in /usr/lib/libboost_thread.so.1.53.0)
   by 0x42660E: boost::thread::join() (thread.hpp:751)
   by 0x4215C5: http::server3::server::run() (server.cpp:63)
   by 0x41A65B: main (main.cpp:37)

----------------------------------------------------------------

Possible data race during read of size 4 at 0x524F60C by thread #1
Locks held: 1, at address 0x61A1E20
   at 0x50496D4: boost::detail::get_once_per_thread_epoch() (in /usr/lib/libboost_thread.so.1.53.0)
   by 0x5043361: ??? (in /usr/lib/libboost_thread.so.1.53.0)
   by 0x5043478: boost::detail::get_current_thread_data() (in /usr/lib/libboost_thread.so.1.53.0)
   by 0x5047875: boost::detail::interruption_checker::interruption_checker(pthread_mutex_t*, pthread_cond_t*) (in /usr/lib/libboost_thread.so.1.53.0)
   by 0x5044002: boost::thread::join_noexcept() (in /usr/lib/libboost_thread.so.1.53.0)
   by 0x42660E: boost::thread::join() (thread.hpp:751)
   by 0x4215C5: http::server3::server::run() (server.cpp:63)
   by 0x41A65B: main (main.cpp:37)

This conflicts with a previous write of size 4 by thread #2
Locks held: none
   at 0x525C27B: pthread_key_create (pthread_key_create.c:44)
   by 0x525C82F: pthread_once (pthread_once.S:104)
   by 0x50496D3: boost::detail::get_once_per_thread_epoch() (in /usr/lib/libboost_thread.so.1.53.0)
   by 0x5043361: ??? (in /usr/lib/libboost_thread.so.1.53.0)
   by 0x5043498: boost::detail::set_current_thread_data(boost::detail::thread_data_base*) (in /usr/lib/libboost_thread.so.1.53.0)
   by 0x504380E: ??? (in /usr/lib/libboost_thread.so.1.53.0)
   by 0x4C2D6FE: mythread_wrapper (hg_intercepts.c:219)
   by 0x5256B4F: start_thread (pthread_create.c:304)

----------------------------------------------------------------

Possible data race during write of size 4 at 0x61A36B8 by thread #6
Locks held: none
   at 0x4223B0: boost::asio::detail::epoll_reactor::descriptor_state::set_ready_events(unsigned int) (epoll_reactor.hpp:68)
   by 0x4228A5: boost::asio::detail::epoll_reactor::run(bool, boost::asio::detail::op_queue<boost::asio::detail::task_io_service_operation>&) (epoll_reactor.ipp:430)
   by 0x423629: boost::asio::detail::task_io_service::do_run_one(boost::asio::detail::scoped_lock<boost::asio::detail::posix_mutex>&, boost::asio::detail::task_io_service_thread_info&, boost::system::error_code const&) (task_io_service.ipp:396)
   by 0x423302: boost::asio::detail::task_io_service::run(boost::system::error_code&) (task_io_service.ipp:153)
   by 0x42393A: boost::asio::io_service::run() (io_service.ipp:59)
   by 0x42EB34: boost::_mfi::mf0<unsigned long, boost::asio::io_service>::operator()(boost::asio::io_service*) const (mem_fn_template.hpp:49)
   by 0x42EA72: unsigned long boost::_bi::list1<boost::_bi::value<boost::asio::io_service*> >::operator()<unsigned long, boost::_mfi::mf0<unsigned long, boost::asio::io_service>, boost::_bi::list0>(boost::_bi::type<unsigned long>, boost::_mfi::mf0<unsigned long, boost::asio::io_service>&, boost::_bi::list0&, long) (bind.hpp:243)
   by 0x42E91E: boost::_bi::bind_t<unsigned long, boost::_mfi::mf0<unsigned long, boost::asio::io_service>, boost::_bi::list1<boost::_bi::value<boost::asio::io_service*> > >::operator()() (bind_template.hpp:20)
   by 0x42E65D: boost::detail::thread_data<boost::_bi::bind_t<unsigned long, boost::_mfi::mf0<unsigned long, boost::asio::io_service>, boost::_bi::list1<boost::_bi::value<boost::asio::io_service*> > > >::run() (thread.hpp:117)
   by 0x5043818: ??? (in /usr/lib/libboost_thread.so.1.53.0)
   by 0x4C2D6FE: mythread_wrapper (hg_intercepts.c:219)
   by 0x5256B4F: start_thread (pthread_create.c:304)

Address 0x61A36B8 is 24 bytes inside a block of size 160 alloc'd
   at 0x4C28A3A: operator new(unsigned long) (vg_replace_malloc.c:298)
   by 0x42806A: boost::asio::detail::epoll_reactor::descriptor_state* boost::asio::detail::object_pool_access::create<boost::asio::detail::epoll_reactor::descriptor_state>() (object_pool.hpp:35)
   by 0x4267B8: boost::asio::detail::object_pool<boost::asio::detail::epoll_reactor::descriptor_state>::alloc() (object_pool.hpp:89)
   by 0x4229E3: boost::asio::detail::epoll_reactor::allocate_descriptor_state() (epoll_reactor.ipp:512)
   by 0x4223D4: boost::asio::detail::epoll_reactor::register_descriptor(int, boost::asio::detail::epoll_reactor::descriptor_state*&) (epoll_reactor.ipp:151)
   by 0x424405: boost::asio::detail::reactive_socket_service_base::do_assign(boost::asio::detail::reactive_socket_service_base::base_implementation_type&, int, int const&, boost::system::error_code&) (reactive_socket_service_base.ipp:182)
   by 0x42DA98: boost::asio::detail::reactive_socket_service<boost::asio::ip::tcp>::assign(boost::asio::detail::reactive_socket_service<boost::asio::ip::tcp>::implementation_type&, boost::asio::ip::tcp const&, int const&, boost::system::error_code&) (reactive_socket_service.hpp:117)
   by 0x42D75C: boost::asio::stream_socket_service<boost::asio::ip::tcp>::assign(boost::asio::detail::reactive_socket_service<boost::asio::ip::tcp>::implementation_type&, boost::asio::ip::tcp const&, int const&, boost::system::error_code&) (stream_socket_service.hpp:138)
   by 0x42D263: boost::asio::basic_socket<boost::asio::ip::tcp, boost::asio::stream_socket_service<boost::asio::ip::tcp> >::assign(boost::asio::ip::tcp const&, int const&, boost::system::error_code&) (basic_socket.hpp:285)
   by 0x42CAD7: boost::asio::detail::reactive_socket_accept_op_base<boost::asio::basic_socket<boost::asio::ip::tcp, boost::asio::stream_socket_service<boost::asio::ip::tcp> >, boost::asio::ip::tcp>::do_perform(boost::asio::detail::reactor_op*) (reactive_socket_accept_op.hpp:66)
   by 0x409DE0: boost::asio::detail::reactor_op::perform() (reactor_op.hpp:40)
   by 0x422C2F: boost::asio::detail::epoll_reactor::descriptor_state::perform_io(unsigned int) (epoll_reactor.ipp:622)

----------------------------------------------------------------

Possible data race during write of size 8 at 0x61A36A8 by thread #6
Locks held: none
   at 0x410E9E: void boost::asio::detail::op_queue_access::next<boost::asio::detail::task_io_service_operation, boost::asio::detail::task_io_service_operation>(boost::asio::detail::task_io_service_operation*&, boost::asio::detail::task_io_service_operation*) (op_queue.hpp:41)
   by 0x40EBEE: boost::asio::detail::op_queue<boost::asio::detail::task_io_service_operation>::push(boost::asio::detail::task_io_service_operation*) (op_queue.hpp:107)
   by 0x4228BB: boost::asio::detail::epoll_reactor::run(bool, boost::asio::detail::op_queue<boost::asio::detail::task_io_service_operation>&) (epoll_reactor.ipp:431)
   by 0x423629: boost::asio::detail::task_io_service::do_run_one(boost::asio::detail::scoped_lock<boost::asio::detail::posix_mutex>&, boost::asio::detail::task_io_service_thread_info&, boost::system::error_code const&) (task_io_service.ipp:396)
   by 0x423302: boost::asio::detail::task_io_service::run(boost::system::error_code&) (task_io_service.ipp:153)
   by 0x42393A: boost::asio::io_service::run() (io_service.ipp:59)
   by 0x42EB34: boost::_mfi::mf0<unsigned long, boost::asio::io_service>::operator()(boost::asio::io_service*) const (mem_fn_template.hpp:49)
   by 0x42EA72: unsigned long boost::_bi::list1<boost::_bi::value<boost::asio::io_service*> >::operator()<unsigned long, boost::_mfi::mf0<unsigned long, boost::asio::io_service>, boost::_bi::list0>(boost::_bi::type<unsigned long>, boost::_mfi::mf0<unsigned long, boost::asio::io_service>&, boost::_bi::list0&, long) (bind.hpp:243)
   by 0x42E91E: boost::_bi::bind_t<unsigned long, boost::_mfi::mf0<unsigned long, boost::asio::io_service>, boost::_bi::list1<boost::_bi::value<boost::asio::io_service*> > >::operator()() (bind_template.hpp:20)
   by 0x42E65D: boost::detail::thread_data<boost::_bi::bind_t<unsigned long, boost::_mfi::mf0<unsigned long, boost::asio::io_service>, boost::_bi::list1<boost::_bi::value<boost::asio::io_service*> > > >::run() (thread.hpp:117)
   by 0x5043818: ??? (in /usr/lib/libboost_thread.so.1.53.0)
   by 0x4C2D6FE: mythread_wrapper (hg_intercepts.c:219)

Address 0x61A36A8 is 8 bytes inside a block of size 160 alloc'd
   at 0x4C28A3A: operator new(unsigned long) (vg_replace_malloc.c:298)
   by 0x42806A: boost::asio::detail::epoll_reactor::descriptor_state* boost::asio::detail::object_pool_access::create<boost::asio::detail::epoll_reactor::descriptor_state>() (object_pool.hpp:35)
   by 0x4267B8: boost::asio::detail::object_pool<boost::asio::detail::epoll_reactor::descriptor_state>::alloc() (object_pool.hpp:89)
   by 0x4229E3: boost::asio::detail::epoll_reactor::allocate_descriptor_state() (epoll_reactor.ipp:512)
   by 0x4223D4: boost::asio::detail::epoll_reactor::register_descriptor(int, boost::asio::detail::epoll_reactor::descriptor_state*&) (epoll_reactor.ipp:151)
   by 0x424405: boost::asio::detail::reactive_socket_service_base::do_assign(boost::asio::detail::reactive_socket_service_base::base_implementation_type&, int, int const&, boost::system::error_code&) (reactive_socket_service_base.ipp:182)
   by 0x42DA98: boost::asio::detail::reactive_socket_service<boost::asio::ip::tcp>::assign(boost::asio::detail::reactive_socket_service<boost::asio::ip::tcp>::implementation_type&, boost::asio::ip::tcp const&, int const&, boost::system::error_code&) (reactive_socket_service.hpp:117)
   by 0x42D75C: boost::asio::stream_socket_service<boost::asio::ip::tcp>::assign(boost::asio::detail::reactive_socket_service<boost::asio::ip::tcp>::implementation_type&, boost::asio::ip::tcp const&, int const&, boost::system::error_code&) (stream_socket_service.hpp:138)
   by 0x42D263: boost::asio::basic_socket<boost::asio::ip::tcp, boost::asio::stream_socket_service<boost::asio::ip::tcp> >::assign(boost::asio::ip::tcp const&, int const&, boost::system::error_code&) (basic_socket.hpp:285)
   by 0x42CAD7: boost::asio::detail::reactive_socket_accept_op_base<boost::asio::basic_socket<boost::asio::ip::tcp, boost::asio::stream_socket_service<boost::asio::ip::tcp> >, boost::asio::ip::tcp>::do_perform(boost::asio::detail::reactor_op*) (reactive_socket_accept_op.hpp:66)
   by 0x409DE0: boost::asio::detail::reactor_op::perform() (reactor_op.hpp:40)
   by 0x422C2F: boost::asio::detail::epoll_reactor::descriptor_state::perform_io(unsigned int) (epoll_reactor.ipp:622)

----------------------------------------------------------------

Thread #2: lock order "0x64C720 before 0x619E550" violated

Observed (incorrect) order is: acquisition of lock at 0x619E550
   at 0x4C2C692: pthread_mutex_lock (hg_intercepts.c:495)
   by 0x408545: boost::asio::detail::posix_mutex::lock() (posix_mutex.hpp:52)
   by 0x40D9E1: boost::asio::detail::scoped_lock<boost::asio::detail::posix_mutex>::scoped_lock(boost::asio::detail::posix_mutex&) (scoped_lock.hpp:36)
   by 0x422BD3: boost::asio::detail::epoll_reactor::descriptor_state::perform_io(unsigned int) (epoll_reactor.ipp:611)
   by 0x422D38: boost::asio::detail::epoll_reactor::descriptor_state::do_complete(boost::asio::detail::task_io_service*, boost::asio::detail::task_io_service_operation*, boost::system::error_code const&, unsigned long) (epoll_reactor.ipp:648)
   by 0x409C69: boost::asio::detail::task_io_service_operation::complete(boost::asio::detail::task_io_service&, boost::system::error_code const&, unsigned long) (task_io_service_operation.hpp:37)
   by 0x4236AD: boost::asio::detail::task_io_service::do_run_one(boost::asio::detail::scoped_lock<boost::asio::detail::posix_mutex>&, boost::asio::detail::task_io_service_thread_info&, boost::system::error_code const&) (task_io_service.ipp:412)
   by 0x423302: boost::asio::detail::task_io_service::run(boost::system::error_code&) (task_io_service.ipp:153)
   by 0x42393A: boost::asio::io_service::run() (io_service.ipp:59)
   by 0x42EB34: boost::_mfi::mf0<unsigned long, boost::asio::io_service>::operator()(boost::asio::io_service*) const (mem_fn_template.hpp:49)
   by 0x42EA72: unsigned long boost::_bi::list1<boost::_bi::value<boost::asio::io_service*> >::operator()<unsigned long, boost::_mfi::mf0<unsigned long, boost::asio::io_service>, boost::_bi::list0>(boost::_bi::type<unsigned long>, boost::_mfi::mf0<unsigned long, boost::asio::io_service>&, boost::_bi::list0&, long) (bind.hpp:243)
   by 0x42E91E: boost::_bi::bind_t<unsigned long, boost::_mfi::mf0<unsigned long, boost::asio::io_service>, boost::_bi::list1<boost::_bi::value<boost::asio::io_service*> > >::operator()() (bind_template.hpp:20)

 followed by a later acquisition of lock at 0x64C720
   at 0x4C2C692: pthread_mutex_lock (hg_intercepts.c:495)
   by 0x408845: boost::asio::detail::posix_static_mutex::lock() (posix_static_mutex.hpp:44)
   by 0x40E523: boost::asio::detail::scoped_lock<boost::asio::detail::posix_static_mutex>::scoped_lock(boost::asio::detail::posix_static_mutex&) (scoped_lock.hpp:36)
   by 0x424EE7: boost::asio::detail::signal_set_service::deliver_signal(int) (signal_set_service.ipp:431)
   by 0x42477C: boost::asio::detail::signal_set_service::pipe_read_op::do_perform(boost::asio::detail::reactor_op*) (signal_set_service.ipp:95)
   by 0x409DE0: boost::asio::detail::reactor_op::perform() (reactor_op.hpp:40)
   by 0x422C2F: boost::asio::detail::epoll_reactor::descriptor_state::perform_io(unsigned int) (epoll_reactor.ipp:622)
   by 0x422D38: boost::asio::detail::epoll_reactor::descriptor_state::do_complete(boost::asio::detail::task_io_service*, boost::asio::detail::task_io_service_operation*, boost::system::error_code const&, unsigned long) (epoll_reactor.ipp:648)
   by 0x409C69: boost::asio::detail::task_io_service_operation::complete(boost::asio::detail::task_io_service&, boost::system::error_code const&, unsigned long) (task_io_service_operation.hpp:37)
   by 0x4236AD: boost::asio::detail::task_io_service::do_run_one(boost::asio::detail::scoped_lock<boost::asio::detail::posix_mutex>&, boost::asio::detail::task_io_service_thread_info&, boost::system::error_code const&) (task_io_service.ipp:412)
   by 0x423302: boost::asio::detail::task_io_service::run(boost::system::error_code&) (task_io_service.ipp:153)
   by 0x42393A: boost::asio::io_service::run() (io_service.ipp:59)

Required order was established by acquisition of lock at 0x64C720
   at 0x4C2C692: pthread_mutex_lock (hg_intercepts.c:495)
   by 0x408845: boost::asio::detail::posix_static_mutex::lock() (posix_static_mutex.hpp:44)
   by 0x40E523: boost::asio::detail::scoped_lock<boost::asio::detail::posix_static_mutex>::scoped_lock(boost::asio::detail::posix_static_mutex&) (scoped_lock.hpp:36)
   by 0x425060: boost::asio::detail::signal_set_service::add_service(boost::asio::detail::signal_set_service*) (signal_set_service.ipp:467)
   by 0x4248BB: boost::asio::detail::signal_set_service::signal_set_service(boost::asio::io_service&) (signal_set_service.ipp:128)
   by 0x42558B: boost::asio::signal_set_service::signal_set_service(boost::asio::io_service&) (signal_set_service.hpp:53)
   by 0x42B628: boost::asio::io_service::service* boost::asio::detail::service_registry::create<boost::asio::signal_set_service>(boost::asio::io_service&) (service_registry.hpp:81)
   by 0x408742: boost::asio::detail::service_registry::do_use_service(boost::asio::io_service::service::key const&, boost::asio::io_service::service* (*)(boost::asio::io_service&)) (service_registry.ipp:123)
   by 0x42A92F: boost::asio::signal_set_service& boost::asio::detail::service_registry::use_service<boost::asio::signal_set_service>() (service_registry.hpp:48)
   by 0x42984A: boost::asio::signal_set_service& boost::asio::use_service<boost::asio::signal_set_service>(boost::asio::io_service&) (io_service.hpp:33)
   by 0x428633: boost::asio::basic_io_object<boost::asio::signal_set_service, false>::basic_io_object(boost::asio::io_service&) (basic_io_object.hpp:90)
   by 0x42753A: boost::asio::basic_signal_set<boost::asio::signal_set_service>::basic_signal_set(boost::asio::io_service&) (basic_signal_set.hpp:106)

 followed by a later acquisition of lock at 0x619E550
   at 0x4C2C692: pthread_mutex_lock (hg_intercepts.c:495)
   by 0x408545: boost::asio::detail::posix_mutex::lock() (posix_mutex.hpp:52)
   by 0x40D9E1: boost::asio::detail::scoped_lock<boost::asio::detail::posix_mutex>::scoped_lock(boost::asio::detail::posix_mutex&) (scoped_lock.hpp:36)
   by 0x4224E4: boost::asio::detail::epoll_reactor::register_internal_descriptor(int, int, boost::asio::detail::epoll_reactor::descriptor_state*&, boost::asio::detail::reactor_op*) (epoll_reactor.ipp:179)
   by 0x4250FC: boost::asio::detail::signal_set_service::add_service(boost::asio::detail::signal_set_service*) (signal_set_service.ipp:485)
   by 0x4248BB: boost::asio::detail::signal_set_service::signal_set_service(boost::asio::io_service&) (signal_set_service.ipp:128)
   by 0x42558B: boost::asio::signal_set_service::signal_set_service(boost::asio::io_service&) (signal_set_service.hpp:53)
   by 0x42B628: boost::asio::io_service::service* boost::asio::detail::service_registry::create<boost::asio::signal_set_service>(boost::asio::io_service&) (service_registry.hpp:81)
   by 0x408742: boost::asio::detail::service_registry::do_use_service(boost::asio::io_service::service::key const&, boost::asio::io_service::service* (*)(boost::asio::io_service&)) (service_registry.ipp:123)
   by 0x42A92F: boost::asio::signal_set_service& boost::asio::detail::service_registry::use_service<boost::asio::signal_set_service>() (service_registry.hpp:48)
   by 0x42984A: boost::asio::signal_set_service& boost::asio::use_service<boost::asio::signal_set_service>(boost::asio::io_service&) (io_service.hpp:33)
   by 0x428633: boost::asio::basic_io_object<boost::asio::signal_set_service, false>::basic_io_object(boost::asio::io_service&) (basic_io_object.hpp:90)

----------------------------------------------------------------

Thread #1: lock order "0x619E550 before 0x64C720" violated

Observed (incorrect) order is: acquisition of lock at 0x64C720
   at 0x4C2C692: pthread_mutex_lock (hg_intercepts.c:495)
   by 0x408845: boost::asio::detail::posix_static_mutex::lock() (posix_static_mutex.hpp:44)
   by 0x40E523: boost::asio::detail::scoped_lock<boost::asio::detail::posix_static_mutex>::scoped_lock(boost::asio::detail::posix_static_mutex&) (scoped_lock.hpp:36)
   by 0x425166: boost::asio::detail::signal_set_service::remove_service(boost::asio::detail::signal_set_service*) (signal_set_service.ipp:492)
   by 0x4248F0: boost::asio::detail::signal_set_service::shutdown_service() (signal_set_service.ipp:138)
   by 0x42564D: boost::asio::signal_set_service::shutdown_service() (signal_set_service.hpp:110)
   by 0x41AA69: boost::asio::detail::service_registry::~service_registry() (service_registry.ipp:37)
   by 0x41AB32: boost::asio::io_service::~io_service() (io_service.ipp:53)
   by 0x41B178: http::server3::server::~server() (in /root/server3/server3)
   by 0x41A66A: main (main.cpp:37)

 followed by a later acquisition of lock at 0x619E550
   at 0x4C2C692: pthread_mutex_lock (hg_intercepts.c:495)
   by 0x408545: boost::asio::detail::posix_mutex::lock() (posix_mutex.hpp:52)
   by 0x40D9E1: boost::asio::detail::scoped_lock<boost::asio::detail::posix_mutex>::scoped_lock(boost::asio::detail::posix_mutex&) (scoped_lock.hpp:36)
   by 0x40AC3A: boost::asio::detail::epoll_reactor::deregister_descriptor(int, boost::asio::detail::epoll_reactor::descriptor_state*&, bool) (epoll_reactor.ipp:307)
   by 0x4251BC: boost::asio::detail::signal_set_service::remove_service(boost::asio::detail::signal_set_service*) (signal_set_service.ipp:499)
   by 0x4248F0: boost::asio::detail::signal_set_service::shutdown_service() (signal_set_service.ipp:138)
   by 0x42564D: boost::asio::signal_set_service::shutdown_service() (signal_set_service.hpp:110)
   by 0x41AA69: boost::asio::detail::service_registry::~service_registry() (service_registry.ipp:37)
   by 0x41AB32: boost::asio::io_service::~io_service() (io_service.ipp:53)
   by 0x41B178: http::server3::server::~server() (in /root/server3/server3)
   by 0x41A66A: main (main.cpp:37)

Required order was established by acquisition of lock at 0x619E550
   at 0x4C2C692: pthread_mutex_lock (hg_intercepts.c:495)
   by 0x408545: boost::asio::detail::posix_mutex::lock() (posix_mutex.hpp:52)
   by 0x40D9E1: boost::asio::detail::scoped_lock<boost::asio::detail::posix_mutex>::scoped_lock(boost::asio::detail::posix_mutex&) (scoped_lock.hpp:36)
   by 0x422BD3: boost::asio::detail::epoll_reactor::descriptor_state::perform_io(unsigned int) (epoll_reactor.ipp:611)
   by 0x422D38: boost::asio::detail::epoll_reactor::descriptor_state::do_complete(boost::asio::detail::task_io_service*, boost::asio::detail::task_io_service_operation*, boost::system::error_code const&, unsigned long) (epoll_reactor.ipp:648)
   by 0x409C69: boost::asio::detail::task_io_service_operation::complete(boost::asio::detail::task_io_service&, boost::system::error_code const&, unsigned long) (task_io_service_operation.hpp:37)
   by 0x4236AD: boost::asio::detail::task_io_service::do_run_one(boost::asio::detail::scoped_lock<boost::asio::detail::posix_mutex>&, boost::asio::detail::task_io_service_thread_info&, boost::system::error_code const&) (task_io_service.ipp:412)
   by 0x423302: boost::asio::detail::task_io_service::run(boost::system::error_code&) (task_io_service.ipp:153)
   by 0x42393A: boost::asio::io_service::run() (io_service.ipp:59)
   by 0x42EB34: boost::_mfi::mf0<unsigned long, boost::asio::io_service>::operator()(boost::asio::io_service*) const (mem_fn_template.hpp:49)
   by 0x42EA72: unsigned long boost::_bi::list1<boost::_bi::value<boost::asio::io_service*> >::operator()<unsigned long, boost::_mfi::mf0<unsigned long, boost::asio::io_service>, boost::_bi::list0>(boost::_bi::type<unsigned long>, boost::_mfi::mf0<unsigned long, boost::asio::io_service>&, boost::_bi::list0&, long) (bind.hpp:243)
   by 0x42E91E: boost::_bi::bind_t<unsigned long, boost::_mfi::mf0<unsigned long, boost::asio::io_service>, boost::_bi::list1<boost::_bi::value<boost::asio::io_service*> > >::operator()() (bind_template.hpp:20)

 followed by a later acquisition of lock at 0x64C720
   at 0x4C2C692: pthread_mutex_lock (hg_intercepts.c:495)
   by 0x408845: boost::asio::detail::posix_static_mutex::lock() (posix_static_mutex.hpp:44)
   by 0x40E523: boost::asio::detail::scoped_lock<boost::asio::detail::posix_static_mutex>::scoped_lock(boost::asio::detail::posix_static_mutex&) (scoped_lock.hpp:36)
   by 0x424EE7: boost::asio::detail::signal_set_service::deliver_signal(int) (signal_set_service.ipp:431)
   by 0x42477C: boost::asio::detail::signal_set_service::pipe_read_op::do_perform(boost::asio::detail::reactor_op*) (signal_set_service.ipp:95)
   by 0x409DE0: boost::asio::detail::reactor_op::perform() (reactor_op.hpp:40)
   by 0x422C2F: boost::asio::detail::epoll_reactor::descriptor_state::perform_io(unsigned int) (epoll_reactor.ipp:622)
   by 0x422D38: boost::asio::detail::epoll_reactor::descriptor_state::do_complete(boost::asio::detail::task_io_service*, boost::asio::detail::task_io_service_operation*, boost::system::error_code const&, unsigned long) (epoll_reactor.ipp:648)
   by 0x409C69: boost::asio::detail::task_io_service_operation::complete(boost::asio::detail::task_io_service&, boost::system::error_code const&, unsigned long) (task_io_service_operation.hpp:37)
   by 0x4236AD: boost::asio::detail::task_io_service::do_run_one(boost::asio::detail::scoped_lock<boost::asio::detail::posix_mutex>&, boost::asio::detail::task_io_service_thread_info&, boost::system::error_code const&) (task_io_service.ipp:412)
   by 0x423302: boost::asio::detail::task_io_service::run(boost::system::error_code&) (task_io_service.ipp:153)
   by 0x42393A: boost::asio::io_service::run() (io_service.ipp:59)

Solution

  • The HTTP Server 3 example uses a pool of threads. And while Valgrind is an immensely useful suite of programs, using it correctly requires a bit of tact. As the helgrind documentation states, it is best to start using helgrind early in a project. Throwing an existing multi-threaded program at helgrind is very likely to report many false positives in my experience. As an example, helgrind cannot always detect data races when using posix condition variables, this quote is from the helgrind documentation I linked previously

    Avoid POSIX condition variables. If you can, use POSIX semaphores (sem_t, sem_post, sem_wait) to do inter-thread event signalling. Semaphores with an initial value of zero are particularly useful for this.

    It is possible this is the cause of the false positives you have cited. Both the Asio and Thread libraries use condition variables as part of their implementation. I very much doubt the possible data races or incorrect lock ordering is due to a bug in either library. It's worth quoting Jeff Atwood's First Rule of Programming here

    An essential part of being a humble programmer is realizing that whenever there's a problem with the code you've written, it's always your fault. It is possible that a bug exists in the OS, the compiler, or a third-party product -- but this should not be your first thought. It is much more likely that the bug exists in the application code under development.