Bug #17201
closedhelgrind: false positive lock order violation between journal and librbd
0%
Description
2016-09-01T20:25:58.599 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== Thread #21: lock order "0x7CA9070 before 0x7CF3C28" violated
2016-09-01T20:25:58.599 INFO:tasks.workunit.client.0.vpm041.stderr:==21289==
2016-09-01T20:25:58.600 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== Observed (incorrect) order is: acquisition of lock at 0x7CF3C28
2016-09-01T20:25:58.600 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== at 0x4C32536: pthread_mutex_lock (in /usr/lib/valgrind/vgpreload_helgrind-amd64-linux.so)
2016-09-01T20:25:58.601 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x135EF387: Mutex::Lock(bool) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:25:58.602 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x135D9211: journal::JournalRecorder::flush(Context*) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:25:58.602 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x135C3C04: journal::Journaler::stop_append(Context*) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:25:58.602 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x1350D737: librbd::Journal<librbd::ImageCtx>::close(Context*) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:25:58.603 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x1353A953: librbd::exclusive_lock::ReleaseRequest<librbd::ImageCtx>::send_close_journal() (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:25:58.603 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x1353AC93: librbd::exclusive_lock::ReleaseRequest<librbd::ImageCtx>::handle_flush_notifies(int*) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:25:58.604 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x1353AE3A: librbd::util::detail::C_StateCallbackAdapter<librbd::exclusive_lock::ReleaseRequest<librbd::ImageCtx>, &librbd::exclusive_lock::ReleaseRequest<librbd::ImageCtx>::handle_flush_notifies, true>::complete(int) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:25:58.604 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x134C3623: ContextWQ::process(Context*) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:25:58.604 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x13617B94: ThreadPool::worker(ThreadPool::WorkThread*) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:25:58.605 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x13618B7F: ThreadPool::WorkThread::entry() (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:25:58.609 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x4C30FA6: ? (in /usr/lib/valgrind/vgpreload_helgrind-amd64-linux.so)
2016-09-01T20:25:58.610 INFO:tasks.workunit.client.0.vpm041.stderr:==21289==
2016-09-01T20:25:58.610 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== followed by a later acquisition of lock at 0x7CA9070
2016-09-01T20:25:58.611 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== at 0x4C32536: pthread_mutex_lock (in /usr/lib/valgrind/vgpreload_helgrind-amd64-linux.so)
2016-09-01T20:25:58.611 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x135EF387: Mutex::Lock(bool) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:25:58.612 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x135E5B66: journal::ObjectRecorder::cancel_append_task() (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:25:58.612 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x135E84F4: journal::ObjectRecorder::flush(Context*) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:25:58.613 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x135D9298: journal::JournalRecorder::flush(Context*) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:25:58.613 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x135C3C04: journal::Journaler::stop_append(Context*) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:25:58.614 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x1350D737: librbd::Journal<librbd::ImageCtx>::close(Context*) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:25:58.614 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x1353A953: librbd::exclusive_lock::ReleaseRequest<librbd::ImageCtx>::send_close_journal() (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:25:58.615 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x1353AC93: librbd::exclusive_lock::ReleaseRequest<librbd::ImageCtx>::handle_flush_notifies(int*) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:25:58.615 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x1353AE3A: librbd::util::detail::C_StateCallbackAdapter<librbd::exclusive_lock::ReleaseRequest<librbd::ImageCtx>, &librbd::exclusive_lock::ReleaseRequest<librbd::ImageCtx>::handle_flush_notifies, true>::complete(int) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:25:58.616 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x134C3623: ContextWQ::process(Context*) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:25:58.616 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x13617B94: ThreadPool::worker(ThreadPool::WorkThread*) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:25:58.617 INFO:tasks.workunit.client.0.vpm041.stderr:==21289==
2016-09-01T20:25:58.617 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== Lock at 0x7CA9070 was first observed
2016-09-01T20:25:58.618 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== at 0x4C321AA: pthread_mutex_init (in /usr/lib/valgrind/vgpreload_helgrind-amd64-linux.so)
2016-09-01T20:25:58.618 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x135EF088: Mutex::Mutex(std::string const&, bool, bool, bool, CephContext*) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:25:58.618 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x134BF950: librbd::ImageCtx::get_timer_instance(CephContext*, SafeTimer**, Mutex**) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:25:58.621 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x1355B258: librbd::journal::CreateRequest<librbd::ImageCtx>::create_journal() (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:25:58.622 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x1355C9C7: librbd::journal::CreateRequest<librbd::ImageCtx>::get_pool_id() (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:25:58.622 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x1355CC39: librbd::journal::CreateRequest<librbd::ImageCtx>::send() (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:25:58.622 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x1353FF21: librbd::image::CreateRequest<librbd::ImageCtx>::journal_create() (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:25:58.622 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x1354079A: librbd::image::CreateRequest<librbd::ImageCtx>::handle_fetch_mirror_mode(int*) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:25:58.623 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x13541E7D: void librbd::util::detail::rados_state_callback<librbd::image::CreateRequest<librbd::ImageCtx>, &librbd::image::CreateRequest<librbd::ImageCtx>::handle_fetch_mirror_mode, true>(void*, void*) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:25:58.623 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x82FD69C: librados::C_AioComplete::finish(int) (in /usr/lib/librados.so.2.0.0)
2016-09-01T20:25:58.623 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x82E1738: Context::complete(int) (in /usr/lib/librados.so.2.0.0)
2016-09-01T20:25:58.623 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x838EB55: Finisher::finisher_thread_entry() (in /usr/lib/librados.so.2.0.0)
2016-09-01T20:25:58.623 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== Address 0x7ca9070 is 224 bytes inside a block of size 296 alloc'd
2016-09-01T20:25:58.623 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== at 0x4C2C500: operator new(unsigned long) (in /usr/lib/valgrind/vgpreload_helgrind-amd64-linux.so)
2016-09-01T20:25:58.623 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x134BF8F1: librbd::ImageCtx::get_timer_instance(CephContext*, SafeTimer**, Mutex**) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:25:58.624 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x1355B258: librbd::journal::CreateRequest<librbd::ImageCtx>::create_journal() (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:25:58.624 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x1355C9C7: librbd::journal::CreateRequest<librbd::ImageCtx>::get_pool_id() (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:25:58.624 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x1355CC39: librbd::journal::CreateRequest<librbd::ImageCtx>::send() (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:25:58.624 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x1353FF21: librbd::image::CreateRequest<librbd::ImageCtx>::journal_create() (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:25:58.624 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x1354079A: librbd::image::CreateRequest<librbd::ImageCtx>::handle_fetch_mirror_mode(int*) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:25:58.624 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x13541E7D: void librbd::util::detail::rados_state_callback<librbd::image::CreateRequest<librbd::ImageCtx>, &librbd::image::CreateRequest<librbd::ImageCtx>::handle_fetch_mirror_mode, true>(void*, void*) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:25:58.624 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x82FD69C: librados::C_AioComplete::finish(int) (in /usr/lib/librados.so.2.0.0)
2016-09-01T20:25:58.624 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x82E1738: Context::complete(int) (in /usr/lib/librados.so.2.0.0)
2016-09-01T20:25:58.625 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x838EB55: Finisher::finisher_thread_entry() (in /usr/lib/librados.so.2.0.0)
2016-09-01T20:25:58.625 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x4C30FA6: ? (in /usr/lib/valgrind/vgpreload_helgrind-amd64-linux.so)
2016-09-01T20:25:58.625 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== Block was alloc'd by thread #14
2016-09-01T20:25:58.625 INFO:tasks.workunit.client.0.vpm041.stderr:==21289==
2016-09-01T20:25:58.626 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== Lock at 0x7CF3C28 was first observed
2016-09-01T20:25:58.626 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== at 0x4C321AA: pthread_mutex_init (in /usr/lib/valgrind/vgpreload_helgrind-amd64-linux.so)
2016-09-01T20:25:58.626 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x135EF088: Mutex::Mutex(std::string const&, bool, bool, bool, CephContext*) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:25:58.626 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x135DC366: journal::JournalRecorder::JournalRecorder(librados::IoCtx&, std::string const&, boost::intrusive_ptr<journal::JournalMetadata> const&, unsigned int, unsigned long, double) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:25:58.626 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x135C2740: journal::Journaler::start_append(int, unsigned long, double) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:25:58.626 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x1350C05B: librbd::Journal<librbd::ImageCtx>::start_append() (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:25:58.626 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x1350C261: librbd::Journal<librbd::ImageCtx>::handle_flushing_replay() (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:25:58.626 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x1350C467: librbd::Journal<librbd::ImageCtx>::handle_replay_complete(int)::{lambda(int)#1}::operator()(int) const (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:25:58.626 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x134B49D9: FunctionContext::finish(int) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:25:58.627 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x1347A5E8: Context::complete(int) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:25:58.627 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x134C3623: ContextWQ::process(Context*) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:25:58.627 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x13617B94: ThreadPool::worker(ThreadPool::WorkThread*) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:25:58.627 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x13618B7F: ThreadPool::WorkThread::entry() (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:25:58.627 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== Address 0x7cf3c28 is 104 bytes inside a block of size 248 alloc'd
2016-09-01T20:25:58.627 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== at 0x4C2C500: operator new(unsigned long) (in /usr/lib/valgrind/vgpreload_helgrind-amd64-linux.so)
2016-09-01T20:25:58.628 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x135C271C: journal::Journaler::start_append(int, unsigned long, double) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:25:58.630 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x1350C05B: librbd::Journal<librbd::ImageCtx>::start_append() (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:25:58.631 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x1350C261: librbd::Journal<librbd::ImageCtx>::handle_flushing_replay() (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:25:58.631 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x1350C467: librbd::Journal<librbd::ImageCtx>::handle_replay_complete(int)::{lambda(int)#1}::operator()(int) const (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:25:58.631 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x134B49D9: FunctionContext::finish(int) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:25:58.631 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x1347A5E8: Context::complete(int) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:25:58.631 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x134C3623: ContextWQ::process(Context*) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:25:58.631 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x13617B94: ThreadPool::worker(ThreadPool::WorkThread*) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:25:58.631 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x13618B7F: ThreadPool::WorkThread::entry() (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:25:58.631 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x4C30FA6: ??? (in /usr/lib/valgrind/vgpreload_helgrind-amd64-linux.so)
2016-09-01T20:25:58.631 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x4E45183: start_thread (pthread_create.c:312)
2016-09-01T20:25:58.632 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== Block was alloc'd by thread #21
2016-09-01T20:25:58.632 INFO:tasks.workunit.client.0.vpm041.stderr:==21289==
Updated by Jason Dillaman over 7 years ago
Also:
2016-09-01T20:32:00.355 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== Thread #21: lock order "0x7CF1078 before 0x7CD9128" violated
2016-09-01T20:32:00.355 INFO:tasks.workunit.client.0.vpm041.stderr:==21289==
2016-09-01T20:32:00.355 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== Observed (incorrect) order is: acquisition of lock at 0x7CD9128
2016-09-01T20:32:00.356 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== at 0x4C32536: pthread_mutex_lock (in /usr/lib/valgrind/vgpreload_helgrind-amd64-linux.so)
2016-09-01T20:32:00.356 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x135EF387: Mutex::Lock(bool) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:32:00.356 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x13516AD1: librbd::Journal<librbd::ImageCtx>::append_io_events(librbd::journal::EventType, std::list<ceph::buffer::list, std::allocator<ceph::buffer::list> > const&, std::list<librbd::AioObjectRequestHandle*, std::allocator<librbd::AioObjectRequestHandle*> > const&, unsigned long, unsigned long, bool) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:32:00.356 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x135176B1: librbd::Journal<librbd::ImageCtx>::append_io_event(librbd::journal::EventEntry&&, std::list<librbd::AioObjectRequestHandle*, std::allocator<librbd::AioObjectRequestHandle*> > const&, unsigned long, unsigned long, bool) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:32:00.356 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x13594426: librbd::AioImageDiscard<librbd::ImageCtx>::append_journal_event(std::list<librbd::AioObjectRequestHandle*, std::allocator<librbd::AioObjectRequestHandle*> > const&, bool) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:32:00.356 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x1359423E: librbd::AbstractAioImageWrite<librbd::ImageCtx>::send_request() (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:32:00.356 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x135927F8: librbd::AioImageRequest<librbd::ImageCtx>::send() (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:32:00.357 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x134ABE58: librbd::AioImageRequestWQ::process(librbd::AioImageRequest<librbd::ImageCtx>*) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:32:00.357 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x13617B94: ThreadPool::worker(ThreadPool::WorkThread*) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:32:00.357 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x13618B7F: ThreadPool::WorkThread::entry() (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:32:00.357 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x4C30FA6: ? (in /usr/lib/valgrind/vgpreload_helgrind-amd64-linux.so)
2016-09-01T20:32:00.357 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x4E45183: start_thread (pthread_create.c:312)
2016-09-01T20:32:00.357 INFO:tasks.workunit.client.0.vpm041.stderr:==21289==
2016-09-01T20:32:00.357 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== followed by a later acquisition of lock at 0x7CF1078
2016-09-01T20:32:00.357 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== at 0x4C32536: pthread_mutex_lock (in /usr/lib/valgrind/vgpreload_helgrind-amd64-linux.so)
2016-09-01T20:32:00.358 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x135EF387: Mutex::Lock(bool) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:32:00.358 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x135DB889: journal::JournalRecorder::append(unsigned long, ceph::buffer::list const&) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:32:00.358 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x135C280C: journal::Journaler::append(unsigned long, ceph::buffer::list const&) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:32:00.358 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x13516B46: librbd::Journal<librbd::ImageCtx>::append_io_events(librbd::journal::EventType, std::list<ceph::buffer::list, std::allocator<ceph::buffer::list> > const&, std::list<librbd::AioObjectRequestHandle*, std::allocator<librbd::AioObjectRequestHandle*> > const&, unsigned long, unsigned long, bool) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:32:00.358 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x135176B1: librbd::Journal<librbd::ImageCtx>::append_io_event(librbd::journal::EventEntry&&, std::list<librbd::AioObjectRequestHandle*, std::allocator<librbd::AioObjectRequestHandle*> > const&, unsigned long, unsigned long, bool) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:32:00.358 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x13594426: librbd::AioImageDiscard<librbd::ImageCtx>::append_journal_event(std::list<librbd::AioObjectRequestHandle*, std::allocator<librbd::AioObjectRequestHandle*> > const&, bool) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:32:00.358 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x1359423E: librbd::AbstractAioImageWrite<librbd::ImageCtx>::send_request() (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:32:00.358 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x135927F8: librbd::AioImageRequest<librbd::ImageCtx>::send() (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:32:00.359 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x134ABE58: librbd::AioImageRequestWQ::process(librbd::AioImageRequest<librbd::ImageCtx>*) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:32:00.359 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x13617B94: ThreadPool::worker(ThreadPool::WorkThread*) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:32:00.359 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x13618B7F: ThreadPool::WorkThread::entry() (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:32:00.359 INFO:tasks.workunit.client.0.vpm041.stderr:==21289==
2016-09-01T20:32:00.359 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== Lock at 0x7CF1078 was first observed
2016-09-01T20:32:00.360 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== at 0x4C321AA: pthread_mutex_init (in /usr/lib/valgrind/vgpreload_helgrind-amd64-linux.so)
2016-09-01T20:32:00.360 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x135EF088: Mutex::Mutex(std::string const&, bool, bool, bool, CephContext*) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:32:00.360 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x135DC366: journal::JournalRecorder::JournalRecorder(librados::IoCtx&, std::string const&, boost::intrusive_ptr<journal::JournalMetadata> const&, unsigned int, unsigned long, double) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:32:00.360 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x135C2740: journal::Journaler::start_append(int, unsigned long, double) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:32:00.360 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x1350C05B: librbd::Journal<librbd::ImageCtx>::start_append() (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:32:00.360 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x1350C261: librbd::Journal<librbd::ImageCtx>::handle_flushing_replay() (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:32:00.360 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x1350C467: librbd::Journal<librbd::ImageCtx>::handle_replay_complete(int)::{lambda(int)#1}::operator()(int) const (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:32:00.361 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x134B49D9: FunctionContext::finish(int) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:32:00.361 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x1347A5E8: Context::complete(int) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:32:00.361 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x134C3623: ContextWQ::process(Context*) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:32:00.361 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x13617B94: ThreadPool::worker(ThreadPool::WorkThread*) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:32:00.361 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x13618B7F: ThreadPool::WorkThread::entry() (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:32:00.361 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== Address 0x7cf1078 is 104 bytes inside a block of size 248 alloc'd
2016-09-01T20:32:00.361 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== at 0x4C2C500: operator new(unsigned long) (in /usr/lib/valgrind/vgpreload_helgrind-amd64-linux.so)
2016-09-01T20:32:00.362 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x135C271C: journal::Journaler::start_append(int, unsigned long, double) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:32:00.362 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x1350C05B: librbd::Journal<librbd::ImageCtx>::start_append() (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:32:00.362 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x1350C261: librbd::Journal<librbd::ImageCtx>::handle_flushing_replay() (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:32:00.362 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x1350C467: librbd::Journal<librbd::ImageCtx>::handle_replay_complete(int)::{lambda(int)#1}::operator()(int) const (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:32:00.362 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x134B49D9: FunctionContext::finish(int) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:32:00.362 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x1347A5E8: Context::complete(int) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:32:00.362 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x134C3623: ContextWQ::process(Context*) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:32:00.362 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x13617B94: ThreadPool::worker(ThreadPool::WorkThread*) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:32:00.363 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x13618B7F: ThreadPool::WorkThread::entry() (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:32:00.363 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x4C30FA6: ? (in /usr/lib/valgrind/vgpreload_helgrind-amd64-linux.so)
2016-09-01T20:32:00.363 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x4E45183: start_thread (pthread_create.c:312)
2016-09-01T20:32:00.363 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== Block was alloc'd by thread #21
2016-09-01T20:32:00.363 INFO:tasks.workunit.client.0.vpm041.stderr:==21289==
2016-09-01T20:32:00.363 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== Lock at 0x7CD9128 was first observed
2016-09-01T20:32:00.363 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== at 0x4C321AA: pthread_mutex_init (in /usr/lib/valgrind/vgpreload_helgrind-amd64-linux.so)
2016-09-01T20:32:00.364 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x135EF088: Mutex::Mutex(std::string const&, bool, bool, bool, CephContext*) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:32:00.364 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x1351987A: librbd::Journal<librbd::ImageCtx>::Journal(librbd::ImageCtx&) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:32:00.364 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x134BC640: librbd::ImageCtx::create_journal() (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:32:00.364 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x1353546E: librbd::exclusive_lock::AcquireRequest<librbd::ImageCtx>::send_open_journal() (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:32:00.364 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x13536764: librbd::exclusive_lock::AcquireRequest<librbd::ImageCtx>::handle_open_object_map(int*) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:32:00.364 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x13536A0A: librbd::util::detail::C_StateCallbackAdapter<librbd::exclusive_lock::AcquireRequest<librbd::ImageCtx>, &librbd::exclusive_lock::AcquireRequest<librbd::ImageCtx>::handle_open_object_map, true>::complete(int) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:32:00.364 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x1356AA20: void librbd::util::detail::rados_state_callback<librbd::object_map::RefreshRequest<librbd::ImageCtx>, &librbd::object_map::RefreshRequest<librbd::ImageCtx>::handle_load, true>(void*, void*) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:32:00.364 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x82FD69C: librados::C_AioComplete::finish(int) (in /usr/lib/librados.so.2.0.0)
2016-09-01T20:32:00.365 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x82E1738: Context::complete(int) (in /usr/lib/librados.so.2.0.0)
2016-09-01T20:32:00.365 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x838EB55: Finisher::finisher_thread_entry() (in /usr/lib/librados.so.2.0.0)
2016-09-01T20:32:00.365 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x4C30FA6: ? (in /usr/lib/valgrind/vgpreload_helgrind-amd64-linux.so)
2016-09-01T20:32:00.365 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== Address 0x7cd9128 is 264 bytes inside a block of size 536 alloc'd
2016-09-01T20:32:00.365 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== at 0x4C2C500: operator new(unsigned long) (in /usr/lib/valgrind/vgpreload_helgrind-amd64-linux.so)
2016-09-01T20:32:00.365 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x134BC632: librbd::ImageCtx::create_journal() (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:32:00.365 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x1353546E: librbd::exclusive_lock::AcquireRequest<librbd::ImageCtx>::send_open_journal() (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:32:00.366 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x13536764: librbd::exclusive_lock::AcquireRequest<librbd::ImageCtx>::handle_open_object_map(int*) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:32:00.366 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x13536A0A: librbd::util::detail::C_StateCallbackAdapter<librbd::exclusive_lock::AcquireRequest<librbd::ImageCtx>, &librbd::exclusive_lock::AcquireRequest<librbd::ImageCtx>::handle_open_object_map, true>::complete(int) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:32:00.366 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x1356AA20: void librbd::util::detail::rados_state_callback<librbd::object_map::RefreshRequest<librbd::ImageCtx>, &librbd::object_map::RefreshRequest<librbd::ImageCtx>::handle_load, true>(void*, void*) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:32:00.366 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x82FD69C: librados::C_AioComplete::finish(int) (in /usr/lib/librados.so.2.0.0)
2016-09-01T20:32:00.366 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x82E1738: Context::complete(int) (in /usr/lib/librados.so.2.0.0)
2016-09-01T20:32:00.366 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x838EB55: Finisher::finisher_thread_entry() (in /usr/lib/librados.so.2.0.0)
2016-09-01T20:32:00.367 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x4C30FA6: ? (in /usr/lib/valgrind/vgpreload_helgrind-amd64-linux.so)
2016-09-01T20:32:00.367 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x4E45183: start_thread (pthread_create.c:312)
2016-09-01T20:32:00.367 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x515537C: clone (clone.S:111)
2016-09-01T20:32:00.367 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== Block was alloc'd by thread #14
Updated by Jason Dillaman over 7 years ago
- Status changed from New to Won't Fix
Helgrind is non-functional under master branch due to std::mutex -- no need to fix warnings.