Ceph » rbd

2016-09-01T20:31:50.916 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== Thread #14: lock order "0x7C99258 before 0x7D16310" violated
2016-09-01T20:31:50.916 INFO:tasks.workunit.client.0.vpm041.stderr:==21289==
2016-09-01T20:31:50.916 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== Observed (incorrect) order is: acquisition of lock at 0x7D16310
2016-09-01T20:31:50.916 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:31:50.920 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x135EF387: Mutex::Lock(bool) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:31:50.920 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x134A87C7: librbd::AioCompletion::complete() (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:31:50.920 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x134A9B36: librbd::AioCompletion::complete_request(long) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:31:50.920 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x1347A5E8: Context::complete(int) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:31:50.921 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x13497BD6: C_GatherBase<Context, Context>::sub_finish(Context*, int) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:31:50.921 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x13497CE1: C_GatherBase<Context, Context>::C_GatherSub::finish(int) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:31:50.921 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x134917A8: C_GatherBase<Context, Context>::C_GatherSub::complete(int) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:31:50.921 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x13493CE3: void finish_contexts<Context>(CephContext*, std::list<Context*, std::allocator<Context*> >&, int) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:31:50.921 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x134880ED: ObjectCacher::bh_write_commit(long, sobject_t, std::vector<std::pair<long, unsigned long>, std::allocator<std::pair<long, unsigned long> > >&, unsigned long, int) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:31:50.921 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x13496AC7: ObjectCacher::C_WriteCommit::finish(int) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:31:50.921 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x1347A5E8: Context::complete(int) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:31:50.921 INFO:tasks.workunit.client.0.vpm041.stderr:==21289==
2016-09-01T20:31:50.921 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== followed by a later acquisition of lock at 0x7C99258
2016-09-01T20:31:50.921 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:31:50.921 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x135EF387: Mutex::Lock(bool) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:31:50.922 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x134B13C1: librbd::AsyncOperation::finish_op() (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:31:50.922 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x134A895F: librbd::AioCompletion::complete() (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:31:50.922 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x134A9B36: librbd::AioCompletion::complete_request(long) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:31:50.922 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x1347A5E8: Context::complete(int) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:31:50.922 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x13497BD6: C_GatherBase<Context, Context>::sub_finish(Context*, int) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:31:50.922 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x13497CE1: C_GatherBase<Context, Context>::C_GatherSub::finish(int) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:31:50.922 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x134917A8: C_GatherBase<Context, Context>::C_GatherSub::complete(int) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:31:50.922 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x13493CE3: void finish_contexts<Context>(CephContext*, std::list<Context*, std::allocator<Context*> >&, int) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:31:50.922 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x134880ED: ObjectCacher::bh_write_commit(long, sobject_t, std::vector<std::pair<long, unsigned long>, std::allocator<std::pair<long, unsigned long> > >&, unsigned long, int) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:31:50.922 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x13496AC7: ObjectCacher::C_WriteCommit::finish(int) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:31:50.922 INFO:tasks.workunit.client.0.vpm041.stderr:==21289==
2016-09-01T20:31:50.923 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== Required order was established by acquisition of lock at 0x7C99258
2016-09-01T20:31:50.923 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:31:50.923 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x135EF387: Mutex::Lock(bool) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:31:50.923 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x13617B9E: ThreadPool::worker(ThreadPool::WorkThread*) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:31:50.923 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x13618B7F: ThreadPool::WorkThread::entry() (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:31:50.923 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x4C30FA6: ? (in /usr/lib/valgrind/vgpreload_helgrind-amd64-linux.so)
2016-09-01T20:31:50.923 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x4E45183: start_thread (pthread_create.c:312)
2016-09-01T20:31:50.923 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x515537C: clone (clone.S:111)
2016-09-01T20:31:50.923 INFO:tasks.workunit.client.0.vpm041.stderr:==21289==
2016-09-01T20:31:50.923 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== followed by a later acquisition of lock at 0x7D16310
2016-09-01T20:31:50.924 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:31:50.924 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x135EF387: Mutex::Lock(bool) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:31:50.924 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x134A8C51: librbd::AioCompletion::start_op(bool) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:31:50.924 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x134AA5FA: librbd::AioImageRequestWQ::_void_dequeue() (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:31:50.924 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x13617663: ThreadPool::worker(ThreadPool::WorkThread*) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:31:50.924 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x13618B7F: ThreadPool::WorkThread::entry() (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:31:50.924 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x4C30FA6: ? (in /usr/lib/valgrind/vgpreload_helgrind-amd64-linux.so)
2016-09-01T20:31:50.924 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x4E45183: start_thread (pthread_create.c:312)
2016-09-01T20:31:50.924 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x515537C: clone (clone.S:111)
2016-09-01T20:31:50.924 INFO:tasks.workunit.client.0.vpm041.stderr:==21289==
2016-09-01T20:31:50.924 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== Lock at 0x7C99258 was first observed
2016-09-01T20:31:50.925 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:31:50.925 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:31:50.925 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x13614B04: ThreadPool::ThreadPool(CephContext*, std::string, std::string, int, char const*) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:31:50.925 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x134BFBAA: librbd::ImageCtx::get_thread_pool_instance(CephContext*) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:31:50.925 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x134F5D15: librbd::create(librados::IoCtx&, char const*, unsigned long, librbd::ImageOptions&, std::string const&, std::string const&) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:31:50.925 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x13470E3D: rbd_create4 (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:31:50.925 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x131ED7EF: __pyx_pf_3rbd_3RBD_2create (rbd.c:4374)
2016-09-01T20:31:50.925 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x131ED7EF: __pyx_pw_3rbd_3RBD_3create (rbd.c:3869)
2016-09-01T20:31:50.925 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x499BE4: PyEval_EvalFrameEx (in /usr/bin/python2.7)
2016-09-01T20:31:50.925 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x499EF1: PyEval_EvalFrameEx (in /usr/bin/python2.7)
2016-09-01T20:31:50.925 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x4A1C99: ? (in /usr/bin/python2.7)
2016-09-01T20:31:50.925 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x505F95: PyObject_Call (in /usr/bin/python2.7)
2016-09-01T20:31:50.926 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x49B079: PyEval_EvalFrameEx (in /usr/bin/python2.7)
2016-09-01T20:31:50.926 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== Address 0x7c99258 is 56 bytes inside a block of size 408 alloc'd
2016-09-01T20:31:50.926 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:31:50.926 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x134BFB49: librbd::ImageCtx::get_thread_pool_instance(CephContext*) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:31:50.926 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x134F5D15: librbd::create(librados::IoCtx&, char const*, unsigned long, librbd::ImageOptions&, std::string const&, std::string const&) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:31:50.926 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x13470E3D: rbd_create4 (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:31:50.926 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x131ED7EF: __pyx_pf_3rbd_3RBD_2create (rbd.c:4374)
2016-09-01T20:31:50.926 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x131ED7EF: __pyx_pw_3rbd_3RBD_3create (rbd.c:3869)
2016-09-01T20:31:50.926 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x499BE4: PyEval_EvalFrameEx (in /usr/bin/python2.7)
2016-09-01T20:31:50.926 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x499EF1: PyEval_EvalFrameEx (in /usr/bin/python2.7)
2016-09-01T20:31:50.926 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x4A1C99: ? (in /usr/bin/python2.7)
2016-09-01T20:31:50.927 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x505F95: PyObject_Call (in /usr/bin/python2.7)
2016-09-01T20:31:50.927 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x49B079: PyEval_EvalFrameEx (in /usr/bin/python2.7)
2016-09-01T20:31:50.927 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x4A090B: PyEval_EvalCodeEx (in /usr/bin/python2.7)
2016-09-01T20:31:50.927 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x49AB44: PyEval_EvalFrameEx (in /usr/bin/python2.7)
2016-09-01T20:31:50.927 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== Block was alloc'd by thread #1
2016-09-01T20:31:50.927 INFO:tasks.workunit.client.0.vpm041.stderr:==21289==
2016-09-01T20:31:50.927 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== Lock at 0x7D16310 was first observed
2016-09-01T20:31:50.927 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:31:50.928 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x135EF108: Mutex::Mutex(std::string const&, bool, bool, bool, CephContext*) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:31:50.928 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x134AC868: librbd::AioImageRequestWQ::write(unsigned long, unsigned long, char const*, int) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:31:50.928 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x13469B74: rbd_write2 (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:31:50.928 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x131EA586: __pyx_pf_3rbd_5Image_66write (rbd.c:16518)
2016-09-01T20:31:50.928 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x131EA586: __pyx_pw_3rbd_5Image_67write (rbd.c:16410)
2016-09-01T20:31:50.928 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x49968C: PyEval_EvalFrameEx (in /usr/bin/python2.7)
2016-09-01T20:31:50.928 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x4A1C99: ? (in /usr/bin/python2.7)
2016-09-01T20:31:50.928 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x505F95: PyObject_Call (in /usr/bin/python2.7)
2016-09-01T20:31:50.928 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x49B079: PyEval_EvalFrameEx (in /usr/bin/python2.7)
2016-09-01T20:31:50.928 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x499EF1: PyEval_EvalFrameEx (in /usr/bin/python2.7)
2016-09-01T20:31:50.928 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x4A1C99: ? (in /usr/bin/python2.7)
2016-09-01T20:31:50.929 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x505F95: PyObject_Call (in /usr/bin/python2.7)
2016-09-01T20:31:50.929 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== Address 0x7d16310 is 16 bytes inside a block of size 416 alloc'd
2016-09-01T20:31:50.929 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:31:50.929 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x134AC834: librbd::AioImageRequestWQ::write(unsigned long, unsigned long, char const*, int) (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:31:50.929 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x13469B74: rbd_write2 (in /usr/lib/librbd.so.1.0.0)
2016-09-01T20:31:50.929 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x131EA586: __pyx_pf_3rbd_5Image_66write (rbd.c:16518)
2016-09-01T20:31:50.929 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x131EA586: __pyx_pw_3rbd_5Image_67write (rbd.c:16410)
2016-09-01T20:31:50.929 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x49968C: PyEval_EvalFrameEx (in /usr/bin/python2.7)
2016-09-01T20:31:50.929 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x4A1C99: ? (in /usr/bin/python2.7)
2016-09-01T20:31:50.929 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x505F95: PyObject_Call (in /usr/bin/python2.7)
2016-09-01T20:31:50.929 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x49B079: PyEval_EvalFrameEx (in /usr/bin/python2.7)
2016-09-01T20:31:50.930 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x499EF1: PyEval_EvalFrameEx (in /usr/bin/python2.7)
2016-09-01T20:31:50.930 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x4A1C99: ? (in /usr/bin/python2.7)
2016-09-01T20:31:50.930 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x505F95: PyObject_Call (in /usr/bin/python2.7)
2016-09-01T20:31:50.930 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== by 0x49B079: PyEval_EvalFrameEx (in /usr/bin/python2.7)
2016-09-01T20:31:50.930 INFO:tasks.workunit.client.0.vpm041.stderr:==21289== Block was alloc'd by thread #1