28 Jul
2020
28 Jul
'20
2:18 p.m.
Hi,
we observe crashes in librbd1 on specific workloads in virtual machines
on Ubuntu 20.04 hosts with librbd1=15.2.4-1focal.
The changes in
https://github.com/ceph/ceph/commit/50694f790245ca90a3b8a644da7b128a7a148cc6
could be related, but do not easily apply against v15.2.4.
We have collected several backtraces, using a reliable local
reproducer.
(This is a resent of the message stuck in the moderation queue since yesterday.)
Best regards
Johannes
VM in libvirt with:
<pre>
<disk type='network' device='disk'>
<driver name='qemu' type='raw' discard='unmap'/>
<source protocol='rbd' name='pool/disk' index='4'>
<!-- omitted -->
</source>
<iotune>
<read_bytes_sec>209715200</read_bytes_sec>
<write_bytes_sec>209715200</write_bytes_sec>
<read_iops_sec>5000</read_iops_sec>
<write_iops_sec>5000</write_iops_sec>
<read_bytes_sec_max>314572800</read_bytes_sec_max>
<write_bytes_sec_max>314572800</write_bytes_sec_max>
<read_iops_sec_max>7500</read_iops_sec_max>
<write_iops_sec_max>7500</write_iops_sec_max>
<read_bytes_sec_max_length>60</read_bytes_sec_max_length>
<write_bytes_sec_max_length>60</write_bytes_sec_max_length>
<read_iops_sec_max_length>60</read_iops_sec_max_length>
<write_iops_sec_max_length>60</write_iops_sec_max_length>
</iotune>
</disk>
</pre>
workload:
<pre>
fio --rw=write --name=test --size=10M
timeout 30s fio --rw=write --name=test --size=20G
timeout 3m fio --rw=write --name=test --size=20G --direct=1
timeout 1m fio --rw=randrw --name=test --size=20G --direct=1
timeout 10s fio --numjobs=8 --rw=randrw --name=test --size=1G --direct=1
# the backtraces are then observed while the following command is running
fio --ioengine=libaio --iodepth=16 --numjobs=8 --rw=randrw --name=test --size=1G
--direct=1
</pre>
observed stack traces
three times:
<pre>
#0 librbd::io::AioCompletion::complete_event_socket (this=this@entry=0x557f633e9400) at
./src/common/event_socket.h:32
#1 0x00007ffb9740ba34 in librbd::io::AioCompletion::complete_external_callback
(this=this@entry=0x557f633f7600) at ./src/librbd/io/AioCompletion.cc:262
#2 0x00007ffb9740ce98 in librbd::io::AioCompletion::complete (this=0x557f633f7600) at
./src/librbd/io/AioCompletion.cc:104
#3 0x00007ffb9740d1a0 in librbd::io::AioCompletion::complete_request
(this=0x557f633f7600, r=r@entry=4096) at ./src/librbd/io/AioCompletion.cc:229
#4 0x00007ffb9742fdca in librbd::io::ReadResult::C_ObjectReadRequest::finish
(this=0x7ffb68364a60, r=4096) at ./src/librbd/io/ReadResult.cc:155
#5 0x00007ffb9728334d in Context::complete (this=0x7ffb68364a60, r=<optimized out>)
at ./src/include/Context.h:77
#6 0x00007ffb9742c7d9 in librbd::io::ObjectDispatchSpec::C_Dispatcher::finish
(this=0x7ffb6832bed0, r=<optimized out>) at
./src/librbd/io/ObjectDispatchSpec.cc:32
#7 0x00007ffb9742c735 in librbd::io::ObjectDispatchSpec::C_Dispatcher::complete
(this=<optimized out>, r=<optimized out>) at
./src/librbd/io/ObjectDispatchSpec.cc:23
#8 0x00007ffb9755e942 in librbd::io::ObjectRequest<librbd::ImageCtx>::finish
(this=this@entry=0x7ffb683394a0, r=r@entry=0) at ./src/include/Context.h:78
#9 0x00007ffb97562e3b in
librbd::io::ObjectReadRequest<librbd::ImageCtx>::handle_read_object
(this=0x7ffb683394a0, r=0) at ./src/log/SubsystemMap.h:72
#10 0x00007ffb970f4177 in librados::C_AioComplete::finish (this=0x7ffb68362e30,
r=<optimized out>) at ./src/librados/AioCompletionImpl.h:140
#11 0x00007ffb970afd1d in Context::complete (this=0x7ffb68362e30, r=<optimized out>)
at ./src/include/Context.h:77
#12 0x00007ffb8765791d in Finisher::finisher_thread_entry (this=0x557f63387a30) at
./src/common/Finisher.cc:66
#13 0x00007ffb9946f609 in start_thread (arg=<optimized out>) at
pthread_create.c:477
#14 0x00007ffb99396103 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
</pre>
once:
<pre>
#0 0x00007fe7a972169d in
std::atomic<boost::lockfree::detail::tagged_ptr<boost::lockfree::queue<librbd::io::AioCompletion*,
boost::lockfree::allocator<std::allocator<void> > >::node> >::load
(__m=std::memory_order_acquire, this=<optimized out>) at
/usr/include/c++/9/atomic:250
#1 boost::lockfree::queue<librbd::io::AioCompletion*,
boost::lockfree::allocator<std::allocator<void> > >::do_push<false>
(t=<optimized out>, this=<optimized out>) at
./obj-x86_64-linux-gnu/boost/include/boost/lockfree/queue.hpp:311
#2 boost::lockfree::queue<librbd::io::AioCompletion*,
boost::lockfree::allocator<std::allocator<void> > >::push (t=<optimized
out>, this=<optimized out>) at
./obj-x86_64-linux-gnu/boost/include/boost/lockfree/queue.hpp:280
#3 librbd::io::AioCompletion::complete_event_socket (this=this@entry=0x5613db630440) at
./src/librbd/io/AioCompletion.cc:276
#4 0x00007fe7a9721a34 in librbd::io::AioCompletion::complete_external_callback
(this=this@entry=0x5613dbbfa2c0) at ./src/librbd/io/AioCompletion.cc:262
#5 0x00007fe7a9722e98 in librbd::io::AioCompletion::complete (this=0x5613dbbfa2c0) at
./src/librbd/io/AioCompletion.cc:104
#6 0x00007fe7a97231a0 in librbd::io::AioCompletion::complete_request
(this=0x5613dbbfa2c0, r=r@entry=4096) at ./src/librbd/io/AioCompletion.cc:229
#7 0x00007fe7a9745dca in librbd::io::ReadResult::C_ObjectReadRequest::finish
(this=0x5613dc6a5c90, r=4096) at ./src/librbd/io/ReadResult.cc:155
#8 0x00007fe7a959934d in Context::complete (this=0x5613dc6a5c90, r=<optimized out>)
at ./src/include/Context.h:77
#9 0x00007fe7a97427d9 in librbd::io::ObjectDispatchSpec::C_Dispatcher::finish
(this=0x5613db8bae40, r=<optimized out>) at
./src/librbd/io/ObjectDispatchSpec.cc:32
#10 0x00007fe7a9742735 in librbd::io::ObjectDispatchSpec::C_Dispatcher::complete
(this=<optimized out>, r=<optimized out>) at
./src/librbd/io/ObjectDispatchSpec.cc:23
#11 0x00007fe7a9874942 in librbd::io::ObjectRequest<librbd::ImageCtx>::finish
(this=this@entry=0x5613dbbfc900, r=r@entry=0) at ./src/include/Context.h:78
#12 0x00007fe7a9878e3b in
librbd::io::ObjectReadRequest<librbd::ImageCtx>::handle_read_object
(this=0x5613dbbfc900, r=0) at ./src/log/SubsystemMap.h:72
#13 0x00007fe7a940a177 in librados::C_AioComplete::finish (this=0x5613db85e6d0,
r=<optimized out>) at ./src/librados/AioCompletionImpl.h:140
#14 0x00007fe7a93c5d1d in Context::complete (this=0x5613db85e6d0, r=<optimized out>)
at ./src/include/Context.h:77
#15 0x00007fe79b65791d in Finisher::finisher_thread_entry (this=0x5613db369ee0) at
./src/common/Finisher.cc:66
#16 0x00007fe7ab788609 in start_thread (arg=<optimized out>) at
pthread_create.c:477
#17 0x00007fe7ab6af103 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
</pre>
twice:
<pre>
#0
boost::lockfree::detail::tagged_ptr<boost::lockfree::detail::freelist_stack<boost::lockfree::queue<librbd::io::AioCompletion*,
boost::lockfree::allocator<std::allocator<void> > >::node,
std::allocator<boost::lockfree::queue<librbd::io::AioCompletion*,
boost::lockfree::allocator<std::allocator<void> > >::node>
>::freelist_node>::extract_ptr (i=<error reading variable>) at
./obj-x86_64-linux-gnu/boost/include/boost/lockfree/detail/tagged_ptr_ptrcompression.hpp:113
#1
boost::lockfree::detail::tagged_ptr<boost::lockfree::detail::freelist_stack<boost::lockfree::queue<librbd::io::AioCompletion*,
boost::lockfree::allocator<std::allocator<void> > >::node,
std::allocator<boost::lockfree::queue<librbd::io::AioCompletion*,
boost::lockfree::allocator<std::allocator<void> > >::node>
>::freelist_node>::get_ptr (this=0xfffff40ee9c0) at
./obj-x86_64-linux-gnu/boost/include/boost/lockfree/detail/tagged_ptr_ptrcompression.hpp:115
#2
boost::lockfree::detail::freelist_stack<boost::lockfree::queue<librbd::io::AioCompletion*,
boost::lockfree::allocator<std::allocator<void> > >::node,
std::allocator<boost::lockfree::queue<librbd::io::AioCompletion*,
boost::lockfree::allocator<std::allocator<void> > >::node>
>::allocate_impl<false> (this=<optimized out>) at
./obj-x86_64-linux-gnu/boost/include/boost/lockfree/detail/freelist.hpp:187
#3
boost::lockfree::detail::freelist_stack<boost::lockfree::queue<librbd::io::AioCompletion*,
boost::lockfree::allocator<std::allocator<void> > >::node,
std::allocator<boost::lockfree::queue<librbd::io::AioCompletion*,
boost::lockfree::allocator<std::allocator<void> > >::node>
>::allocate<true, false> (this=<optimized out>) at
./obj-x86_64-linux-gnu/boost/include/boost/lockfree/detail/freelist.hpp:168
#4
boost::lockfree::detail::freelist_stack<boost::lockfree::queue<librbd::io::AioCompletion*,
boost::lockfree::allocator<std::allocator<void> > >::node,
std::allocator<boost::lockfree::queue<librbd::io::AioCompletion*,
boost::lockfree::allocator<std::allocator<void> > >::node>
>::construct<true, false, librbd::io::AioCompletion*,
boost::lockfree::queue<librbd::io::AioCompletion*,
boost::lockfree::allocator<std::allocator<void> > >::node*>
(arg2=<optimized out>, arg1=<optimized out>, this=<optimized out>) at
./obj-x86_64-linux-gnu/boost/include/boost/lockfree/detail/freelist.hpp:100
#5 boost::lockfree::queue<librbd::io::AioCompletion*,
boost::lockfree::allocator<std::allocator<void> > >::do_push<false>
(t=<optimized out>, this=<optimized out>) at
./obj-x86_64-linux-gnu/boost/include/boost/lockfree/queue.hpp:302
#6 boost::lockfree::queue<librbd::io::AioCompletion*,
boost::lockfree::allocator<std::allocator<void> > >::push (t=<optimized
out>, this=<optimized out>) at
./obj-x86_64-linux-gnu/boost/include/boost/lockfree/queue.hpp:280
#7 librbd::io::AioCompletion::complete_event_socket (this=this@entry=0x560f5e10c000) at
./src/librbd/io/AioCompletion.cc:276
#8 0x00007f8c8bcada34 in librbd::io::AioCompletion::complete_external_callback
(this=this@entry=0x560f5edd5d30) at ./src/librbd/io/AioCompletion.cc:262
#9 0x00007f8c8bcaee98 in librbd::io::AioCompletion::complete (this=0x560f5edd5d30) at
./src/librbd/io/AioCompletion.cc:104
#10 0x00007f8c8bcaf1a0 in librbd::io::AioCompletion::complete_request
(this=0x560f5edd5d30, r=r@entry=4096) at ./src/librbd/io/AioCompletion.cc:229
#11 0x00007f8c8bcd1dca in librbd::io::ReadResult::C_ObjectReadRequest::finish
(this=0x7f8bc4342280, r=4096) at ./src/librbd/io/ReadResult.cc:155
#12 0x00007f8c8bb2534d in Context::complete (this=0x7f8bc4342280, r=<optimized out>)
at ./src/include/Context.h:77
#13 0x00007f8c8bcce7d9 in librbd::io::ObjectDispatchSpec::C_Dispatcher::finish
(this=0x7f8bc4326820, r=<optimized out>) at
./src/librbd/io/ObjectDispatchSpec.cc:32
#14 0x00007f8c8bcce735 in librbd::io::ObjectDispatchSpec::C_Dispatcher::complete
(this=<optimized out>, r=<optimized out>) at
./src/librbd/io/ObjectDispatchSpec.cc:23
#15 0x00007f8c8be00942 in librbd::io::ObjectRequest<librbd::ImageCtx>::finish
(this=this@entry=0x7f8bc42b2a30, r=r@entry=0) at ./src/include/Context.h:78
#16 0x00007f8c8be04e3b in
librbd::io::ObjectReadRequest<librbd::ImageCtx>::handle_read_object
(this=0x7f8bc42b2a30, r=0) at ./src/log/SubsystemMap.h:72
#17 0x00007f8c8b996177 in librados::C_AioComplete::finish (this=0x7f8bc43423b0,
r=<optimized out>) at ./src/librados/AioCompletionImpl.h:140
#18 0x00007f8c8b951d1d in Context::complete (this=0x7f8bc43423b0, r=<optimized out>)
at ./src/include/Context.h:77
#19 0x00007f8c82f4291d in Finisher::finisher_thread_entry (this=0x560f5f44b180) at
./src/common/Finisher.cc:66
#20 0x00007f8c91e1a609 in start_thread (arg=<optimized out>) at
pthread_create.c:477
#21 0x00007f8c91d41103 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
</pre>
once:
<pre>
#0
boost::lockfree::detail::tagged_ptr<boost::lockfree::detail::freelist_stack<boost::lockfree::queue<librbd::io::AioCompletion*,
boost::lockfree::allocator<std::allocator<void> > >::node,
std::allocator<boost::lockfree::queue<librbd::io::AioCompletion*,
boost::lockfree::allocator<std::allocator<void> > >::node>
>::freelist_node>::extract_ptr (i=<error reading variable>) at
./obj-x86_64-linux-gnu/boost/include/boost/lockfree/detail/tagged_ptr_ptrcompression.hpp:113
#1
boost::lockfree::detail::tagged_ptr<boost::lockfree::detail::freelist_stack<boost::lockfree::queue<librbd::io::AioCompletion*,
boost::lockfree::allocator<std::allocator<void> > >::node,
std::allocator<boost::lockfree::queue<librbd::io::AioCompletion*,
boost::lockfree::allocator<std::allocator<void> > >::node>
>::freelist_node>::get_ptr (this=0xfffff40ee9c0) at
./obj-x86_64-linux-gnu/boost/include/boost/lockfree/detail/tagged_ptr_ptrcompression.hpp:115
#2
boost::lockfree::detail::freelist_stack<boost::lockfree::queue<librbd::io::AioCompletion*,
boost::lockfree::allocator<std::allocator<void> > >::node,
std::allocator<boost::lockfree::queue<librbd::io::AioCompletion*,
boost::lockfree::allocator<std::allocator<void> > >::node>
>::allocate_impl<false> (this=<optimized out>) at
./obj-x86_64-linux-gnu/boost/include/boost/lockfree/detail/freelist.hpp:187
#3
boost::lockfree::detail::freelist_stack<boost::lockfree::queue<librbd::io::AioCompletion*,
boost::lockfree::allocator<std::allocator<void> > >::node,
std::allocator<boost::lockfree::queue<librbd::io::AioCompletion*,
boost::lockfree::allocator<std::allocator<void> > >::node>
>::allocate<true, false> (this=<optimized out>) at
./obj-x86_64-linux-gnu/boost/include/boost/lockfree/detail/freelist.hpp:168
#4
boost::lockfree::detail::freelist_stack<boost::lockfree::queue<librbd::io::AioCompletion*,
boost::lockfree::allocator<std::allocator<void> > >::node,
std::allocator<boost::lockfree::queue<librbd::io::AioCompletion*,
boost::lockfree::allocator<std::allocator<void> > >::node>
>::construct<true, false, librbd::io::AioCompletion*,
boost::lockfree::queue<librbd::io::AioCompletion*,
boost::lockfree::allocator<std::allocator<void> > >::node*>
(arg2=<optimized out>, arg1=<optimized out>, this=<optimized out>) at
./obj-x86_64-linux-gnu/boost/include/boost/lockfree/detail/freelist.hpp:100
#5 boost::lockfree::queue<librbd::io::AioCompletion*,
boost::lockfree::allocator<std::allocator<void> > >::do_push<false>
(t=<optimized out>, this=<optimized out>) at
./obj-x86_64-linux-gnu/boost/include/boost/lockfree/queue.hpp:302
#6 boost::lockfree::queue<librbd::io::AioCompletion*,
boost::lockfree::allocator<std::allocator<void> > >::push (t=<optimized
out>, this=<optimized out>) at
./obj-x86_64-linux-gnu/boost/include/boost/lockfree/queue.hpp:280
#7 librbd::io::AioCompletion::complete_event_socket (this=this@entry=0x55d1b89113c0) at
./src/librbd/io/AioCompletion.cc:276
#8 0x00007f275f6d7a34 in librbd::io::AioCompletion::complete_external_callback
(this=this@entry=0x55d1b8a7a0d0) at ./src/librbd/io/AioCompletion.cc:262
#9 0x00007f275f6d8e98 in librbd::io::AioCompletion::complete (this=0x55d1b8a7a0d0) at
./src/librbd/io/AioCompletion.cc:104
#10 0x00007f275f6d91a0 in librbd::io::AioCompletion::complete_request
(this=0x55d1b8a7a0d0, r=<optimized out>) at ./src/librbd/io/AioCompletion.cc:229
#11 0x00007f275f54f34d in Context::complete (this=0x7f268833f850, r=<optimized out>)
at ./src/include/Context.h:77
#12 0x00007f274f6b647b in ThreadPool::worker (this=0x55d1b9d04860, wt=<optimized
out>) at ./src/common/WorkQueue.cc:118
#13 0x00007f274f6b7545 in ThreadPool::WorkThread::entry (this=<optimized out>) at
./src/common/WorkQueue.h:466
#14 0x00007f276173e609 in start_thread (arg=<optimized out>) at
pthread_create.c:477
#15 0x00007f2761665103 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
</pre>
28 Jul
28 Jul
3:49 p.m.
On Tue, Jul 28, 2020 at 7:19 AM Johannes Naab
<johannes.naab(a)hetzner-cloud.de> wrote:
Hi,
we observe crashes in librbd1 on specific workloads in virtual machines
on Ubuntu 20.04 hosts with librbd1=15.2.4-1focal.
The changes in
https://github.com/ceph/ceph/commit/50694f790245ca90a3b8a644da7b128a7a148cc6
could be related, but do not easily apply against v15.2.4.
I don't think that commit is related. That commit fixed an issue in
the python-rbd test suite where the "wait_for_complete_and_cb" API
method could return before the callback was invoked when running with
multiple IO threads (Octopus is locked to a single thread).
We have collected several backtraces, using a reliable
local
reproducer.
(This is a resent of the message stuck in the moderation queue since yesterday.)
Best regards
Johannes
VM in libvirt with:
<pre>
<disk type='network' device='disk'>
<driver name='qemu' type='raw' discard='unmap'/>
<source protocol='rbd' name='pool/disk' index='4'>
<!-- omitted -->
</source>
<iotune>
<read_bytes_sec>209715200</read_bytes_sec>
<write_bytes_sec>209715200</write_bytes_sec>
<read_iops_sec>5000</read_iops_sec>
<write_iops_sec>5000</write_iops_sec>
<read_bytes_sec_max>314572800</read_bytes_sec_max>
<write_bytes_sec_max>314572800</write_bytes_sec_max>
<read_iops_sec_max>7500</read_iops_sec_max>
<write_iops_sec_max>7500</write_iops_sec_max>
<read_bytes_sec_max_length>60</read_bytes_sec_max_length>
<write_bytes_sec_max_length>60</write_bytes_sec_max_length>
<read_iops_sec_max_length>60</read_iops_sec_max_length>
<write_iops_sec_max_length>60</write_iops_sec_max_length>
</iotune>
</disk>
</pre>
workload:
<pre>
fio --rw=write --name=test --size=10M
timeout 30s fio --rw=write --name=test --size=20G
timeout 3m fio --rw=write --name=test --size=20G --direct=1
timeout 1m fio --rw=randrw --name=test --size=20G --direct=1
timeout 10s fio --numjobs=8 --rw=randrw --name=test --size=1G --direct=1
# the backtraces are then observed while the following command is running
fio --ioengine=libaio --iodepth=16 --numjobs=8 --rw=randrw --name=test --size=1G
--direct=1
I'm not sure I understand this workload. Are you running these 6 "fio"
processes sequentially or concurrently? Does it only crash on that
last one? Do you have "exclusive-lock" enabled on the image since
"--numjobs 8" would cause lots of lock fighting if it was enabled.
Are all the crashes seg faults? They all seem to hint that the
internal ImageCtx instance was destroyed somehow while there was still
in-flight IO. If the crashes appeared during the "timeout XYZ fio ..."
calls, I would think it's highly likely that "fio" is incorrectly
closing the RBD image while there was still in-flight IO via its
signal handler.
</pre>
observed stack traces
three times:
<pre>
#0 librbd::io::AioCompletion::complete_event_socket (this=this@entry=0x557f633e9400) at
./src/common/event_socket.h:32
#1 0x00007ffb9740ba34 in librbd::io::AioCompletion::complete_external_callback
(this=this@entry=0x557f633f7600) at ./src/librbd/io/AioCompletion.cc:262
#2 0x00007ffb9740ce98 in librbd::io::AioCompletion::complete (this=0x557f633f7600) at
./src/librbd/io/AioCompletion.cc:104
#3 0x00007ffb9740d1a0 in librbd::io::AioCompletion::complete_request
(this=0x557f633f7600, r=r@entry=4096) at ./src/librbd/io/AioCompletion.cc:229
#4 0x00007ffb9742fdca in librbd::io::ReadResult::C_ObjectReadRequest::finish
(this=0x7ffb68364a60, r=4096) at ./src/librbd/io/ReadResult.cc:155
#5 0x00007ffb9728334d in Context::complete (this=0x7ffb68364a60, r=<optimized
out>) at ./src/include/Context.h:77
#6 0x00007ffb9742c7d9 in librbd::io::ObjectDispatchSpec::C_Dispatcher::finish
(this=0x7ffb6832bed0, r=<optimized out>) at
./src/librbd/io/ObjectDispatchSpec.cc:32
#7 0x00007ffb9742c735 in librbd::io::ObjectDispatchSpec::C_Dispatcher::complete
(this=<optimized out>, r=<optimized out>) at
./src/librbd/io/ObjectDispatchSpec.cc:23
#8 0x00007ffb9755e942 in librbd::io::ObjectRequest<librbd::ImageCtx>::finish
(this=this@entry=0x7ffb683394a0, r=r@entry=0) at ./src/include/Context.h:78
#9 0x00007ffb97562e3b in
librbd::io::ObjectReadRequest<librbd::ImageCtx>::handle_read_object
(this=0x7ffb683394a0, r=0) at ./src/log/SubsystemMap.h:72
#10 0x00007ffb970f4177 in librados::C_AioComplete::finish (this=0x7ffb68362e30,
r=<optimized out>) at ./src/librados/AioCompletionImpl.h:140
#11 0x00007ffb970afd1d in Context::complete (this=0x7ffb68362e30, r=<optimized
out>) at ./src/include/Context.h:77
#12 0x00007ffb8765791d in Finisher::finisher_thread_entry (this=0x557f63387a30) at
./src/common/Finisher.cc:66
#13 0x00007ffb9946f609 in start_thread (arg=<optimized out>) at
pthread_create.c:477
#14 0x00007ffb99396103 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
</pre>
once:
<pre>
#0 0x00007fe7a972169d in
std::atomic<boost::lockfree::detail::tagged_ptr<boost::lockfree::queue<librbd::io::AioCompletion*,
boost::lockfree::allocator<std::allocator<void> > >::node> >::load
(__m=std::memory_order_acquire, this=<optimized out>) at
/usr/include/c++/9/atomic:250
#1 boost::lockfree::queue<librbd::io::AioCompletion*,
boost::lockfree::allocator<std::allocator<void> > >::do_push<false>
(t=<optimized out>, this=<optimized out>) at
./obj-x86_64-linux-gnu/boost/include/boost/lockfree/queue.hpp:311
#2 boost::lockfree::queue<librbd::io::AioCompletion*,
boost::lockfree::allocator<std::allocator<void> > >::push (t=<optimized
out>, this=<optimized out>) at
./obj-x86_64-linux-gnu/boost/include/boost/lockfree/queue.hpp:280
#3 librbd::io::AioCompletion::complete_event_socket (this=this@entry=0x5613db630440) at
./src/librbd/io/AioCompletion.cc:276
#4 0x00007fe7a9721a34 in librbd::io::AioCompletion::complete_external_callback
(this=this@entry=0x5613dbbfa2c0) at ./src/librbd/io/AioCompletion.cc:262
#5 0x00007fe7a9722e98 in librbd::io::AioCompletion::complete (this=0x5613dbbfa2c0) at
./src/librbd/io/AioCompletion.cc:104
#6 0x00007fe7a97231a0 in librbd::io::AioCompletion::complete_request
(this=0x5613dbbfa2c0, r=r@entry=4096) at ./src/librbd/io/AioCompletion.cc:229
#7 0x00007fe7a9745dca in librbd::io::ReadResult::C_ObjectReadRequest::finish
(this=0x5613dc6a5c90, r=4096) at ./src/librbd/io/ReadResult.cc:155
#8 0x00007fe7a959934d in Context::complete (this=0x5613dc6a5c90, r=<optimized
out>) at ./src/include/Context.h:77
#9 0x00007fe7a97427d9 in librbd::io::ObjectDispatchSpec::C_Dispatcher::finish
(this=0x5613db8bae40, r=<optimized out>) at
./src/librbd/io/ObjectDispatchSpec.cc:32
#10 0x00007fe7a9742735 in librbd::io::ObjectDispatchSpec::C_Dispatcher::complete
(this=<optimized out>, r=<optimized out>) at
./src/librbd/io/ObjectDispatchSpec.cc:23
#11 0x00007fe7a9874942 in librbd::io::ObjectRequest<librbd::ImageCtx>::finish
(this=this@entry=0x5613dbbfc900, r=r@entry=0) at ./src/include/Context.h:78
#12 0x00007fe7a9878e3b in
librbd::io::ObjectReadRequest<librbd::ImageCtx>::handle_read_object
(this=0x5613dbbfc900, r=0) at ./src/log/SubsystemMap.h:72
#13 0x00007fe7a940a177 in librados::C_AioComplete::finish (this=0x5613db85e6d0,
r=<optimized out>) at ./src/librados/AioCompletionImpl.h:140
#14 0x00007fe7a93c5d1d in Context::complete (this=0x5613db85e6d0, r=<optimized
out>) at ./src/include/Context.h:77
#15 0x00007fe79b65791d in Finisher::finisher_thread_entry (this=0x5613db369ee0) at
./src/common/Finisher.cc:66
#16 0x00007fe7ab788609 in start_thread (arg=<optimized out>) at
pthread_create.c:477
#17 0x00007fe7ab6af103 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
</pre>
twice:
<pre>
#0
boost::lockfree::detail::tagged_ptr<boost::lockfree::detail::freelist_stack<boost::lockfree::queue<librbd::io::AioCompletion*,
boost::lockfree::allocator<std::allocator<void> > >::node,
std::allocator<boost::lockfree::queue<librbd::io::AioCompletion*,
boost::lockfree::allocator<std::allocator<void> > >::node>
>::freelist_node>::extract_ptr (i=<error reading variable>) at
./obj-x86_64-linux-gnu/boost/include/boost/lockfree/detail/tagged_ptr_ptrcompression.hpp:113
#1
boost::lockfree::detail::tagged_ptr<boost::lockfree::detail::freelist_stack<boost::lockfree::queue<librbd::io::AioCompletion*,
boost::lockfree::allocator<std::allocator<void> > >::node,
std::allocator<boost::lockfree::queue<librbd::io::AioCompletion*,
boost::lockfree::allocator<std::allocator<void> > >::node>
>::freelist_node>::get_ptr (this=0xfffff40ee9c0) at
./obj-x86_64-linux-gnu/boost/include/boost/lockfree/detail/tagged_ptr_ptrcompression.hpp:115
#2
boost::lockfree::detail::freelist_stack<boost::lockfree::queue<librbd::io::AioCompletion*,
boost::lockfree::allocator<std::allocator<void> > >::node,
std::allocator<boost::lockfree::queue<librbd::io::AioCompletion*,
boost::lockfree::allocator<std::allocator<void> > >::node>
>::allocate_impl<false> (this=<optimized out>) at
./obj-x86_64-linux-gnu/boost/include/boost/lockfree/detail/freelist.hpp:187
#3
boost::lockfree::detail::freelist_stack<boost::lockfree::queue<librbd::io::AioCompletion*,
boost::lockfree::allocator<std::allocator<void> > >::node,
std::allocator<boost::lockfree::queue<librbd::io::AioCompletion*,
boost::lockfree::allocator<std::allocator<void> > >::node>
>::allocate<true, false> (this=<optimized out>) at
./obj-x86_64-linux-gnu/boost/include/boost/lockfree/detail/freelist.hpp:168
#4
boost::lockfree::detail::freelist_stack<boost::lockfree::queue<librbd::io::AioCompletion*,
boost::lockfree::allocator<std::allocator<void> > >::node,
std::allocator<boost::lockfree::queue<librbd::io::AioCompletion*,
boost::lockfree::allocator<std::allocator<void> > >::node>
>::construct<true, false, librbd::io::AioCompletion*,
boost::lockfree::queue<librbd::io::AioCompletion*,
boost::lockfree::allocator<std::allocator<void> > >::node*>
(arg2=<optimized out>, arg1=<optimized out>, this=<optimized out>) at
./obj-x86_64-linux-gnu/boost/include/boost/lockfree/detail/freelist.hpp:100
#5 boost::lockfree::queue<librbd::io::AioCompletion*,
boost::lockfree::allocator<std::allocator<void> > >::do_push<false>
(t=<optimized out>, this=<optimized out>) at
./obj-x86_64-linux-gnu/boost/include/boost/lockfree/queue.hpp:302
#6 boost::lockfree::queue<librbd::io::AioCompletion*,
boost::lockfree::allocator<std::allocator<void> > >::push (t=<optimized
out>, this=<optimized out>) at
./obj-x86_64-linux-gnu/boost/include/boost/lockfree/queue.hpp:280
#7 librbd::io::AioCompletion::complete_event_socket (this=this@entry=0x560f5e10c000) at
./src/librbd/io/AioCompletion.cc:276
#8 0x00007f8c8bcada34 in librbd::io::AioCompletion::complete_external_callback
(this=this@entry=0x560f5edd5d30) at ./src/librbd/io/AioCompletion.cc:262
#9 0x00007f8c8bcaee98 in librbd::io::AioCompletion::complete (this=0x560f5edd5d30) at
./src/librbd/io/AioCompletion.cc:104
#10 0x00007f8c8bcaf1a0 in librbd::io::AioCompletion::complete_request
(this=0x560f5edd5d30, r=r@entry=4096) at ./src/librbd/io/AioCompletion.cc:229
#11 0x00007f8c8bcd1dca in librbd::io::ReadResult::C_ObjectReadRequest::finish
(this=0x7f8bc4342280, r=4096) at ./src/librbd/io/ReadResult.cc:155
#12 0x00007f8c8bb2534d in Context::complete (this=0x7f8bc4342280, r=<optimized
out>) at ./src/include/Context.h:77
#13 0x00007f8c8bcce7d9 in librbd::io::ObjectDispatchSpec::C_Dispatcher::finish
(this=0x7f8bc4326820, r=<optimized out>) at
./src/librbd/io/ObjectDispatchSpec.cc:32
#14 0x00007f8c8bcce735 in librbd::io::ObjectDispatchSpec::C_Dispatcher::complete
(this=<optimized out>, r=<optimized out>) at
./src/librbd/io/ObjectDispatchSpec.cc:23
#15 0x00007f8c8be00942 in librbd::io::ObjectRequest<librbd::ImageCtx>::finish
(this=this@entry=0x7f8bc42b2a30, r=r@entry=0) at ./src/include/Context.h:78
#16 0x00007f8c8be04e3b in
librbd::io::ObjectReadRequest<librbd::ImageCtx>::handle_read_object
(this=0x7f8bc42b2a30, r=0) at ./src/log/SubsystemMap.h:72
#17 0x00007f8c8b996177 in librados::C_AioComplete::finish (this=0x7f8bc43423b0,
r=<optimized out>) at ./src/librados/AioCompletionImpl.h:140
#18 0x00007f8c8b951d1d in Context::complete (this=0x7f8bc43423b0, r=<optimized
out>) at ./src/include/Context.h:77
#19 0x00007f8c82f4291d in Finisher::finisher_thread_entry (this=0x560f5f44b180) at
./src/common/Finisher.cc:66
#20 0x00007f8c91e1a609 in start_thread (arg=<optimized out>) at
pthread_create.c:477
#21 0x00007f8c91d41103 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
</pre>
once:
<pre>
#0
boost::lockfree::detail::tagged_ptr<boost::lockfree::detail::freelist_stack<boost::lockfree::queue<librbd::io::AioCompletion*,
boost::lockfree::allocator<std::allocator<void> > >::node,
std::allocator<boost::lockfree::queue<librbd::io::AioCompletion*,
boost::lockfree::allocator<std::allocator<void> > >::node>
>::freelist_node>::extract_ptr (i=<error reading variable>) at
./obj-x86_64-linux-gnu/boost/include/boost/lockfree/detail/tagged_ptr_ptrcompression.hpp:113
#1
boost::lockfree::detail::tagged_ptr<boost::lockfree::detail::freelist_stack<boost::lockfree::queue<librbd::io::AioCompletion*,
boost::lockfree::allocator<std::allocator<void> > >::node,
std::allocator<boost::lockfree::queue<librbd::io::AioCompletion*,
boost::lockfree::allocator<std::allocator<void> > >::node>
>::freelist_node>::get_ptr (this=0xfffff40ee9c0) at
./obj-x86_64-linux-gnu/boost/include/boost/lockfree/detail/tagged_ptr_ptrcompression.hpp:115
#2
boost::lockfree::detail::freelist_stack<boost::lockfree::queue<librbd::io::AioCompletion*,
boost::lockfree::allocator<std::allocator<void> > >::node,
std::allocator<boost::lockfree::queue<librbd::io::AioCompletion*,
boost::lockfree::allocator<std::allocator<void> > >::node>
>::allocate_impl<false> (this=<optimized out>) at
./obj-x86_64-linux-gnu/boost/include/boost/lockfree/detail/freelist.hpp:187
#3
boost::lockfree::detail::freelist_stack<boost::lockfree::queue<librbd::io::AioCompletion*,
boost::lockfree::allocator<std::allocator<void> > >::node,
std::allocator<boost::lockfree::queue<librbd::io::AioCompletion*,
boost::lockfree::allocator<std::allocator<void> > >::node>
>::allocate<true, false> (this=<optimized out>) at
./obj-x86_64-linux-gnu/boost/include/boost/lockfree/detail/freelist.hpp:168
#4
boost::lockfree::detail::freelist_stack<boost::lockfree::queue<librbd::io::AioCompletion*,
boost::lockfree::allocator<std::allocator<void> > >::node,
std::allocator<boost::lockfree::queue<librbd::io::AioCompletion*,
boost::lockfree::allocator<std::allocator<void> > >::node>
>::construct<true, false, librbd::io::AioCompletion*,
boost::lockfree::queue<librbd::io::AioCompletion*,
boost::lockfree::allocator<std::allocator<void> > >::node*>
(arg2=<optimized out>, arg1=<optimized out>, this=<optimized out>) at
./obj-x86_64-linux-gnu/boost/include/boost/lockfree/detail/freelist.hpp:100
#5 boost::lockfree::queue<librbd::io::AioCompletion*,
boost::lockfree::allocator<std::allocator<void> > >::do_push<false>
(t=<optimized out>, this=<optimized out>) at
./obj-x86_64-linux-gnu/boost/include/boost/lockfree/queue.hpp:302
#6 boost::lockfree::queue<librbd::io::AioCompletion*,
boost::lockfree::allocator<std::allocator<void> > >::push (t=<optimized
out>, this=<optimized out>) at
./obj-x86_64-linux-gnu/boost/include/boost/lockfree/queue.hpp:280
#7 librbd::io::AioCompletion::complete_event_socket (this=this@entry=0x55d1b89113c0) at
./src/librbd/io/AioCompletion.cc:276
#8 0x00007f275f6d7a34 in librbd::io::AioCompletion::complete_external_callback
(this=this@entry=0x55d1b8a7a0d0) at ./src/librbd/io/AioCompletion.cc:262
#9 0x00007f275f6d8e98 in librbd::io::AioCompletion::complete (this=0x55d1b8a7a0d0) at
./src/librbd/io/AioCompletion.cc:104
#10 0x00007f275f6d91a0 in librbd::io::AioCompletion::complete_request
(this=0x55d1b8a7a0d0, r=<optimized out>) at ./src/librbd/io/AioCompletion.cc:229
#11 0x00007f275f54f34d in Context::complete (this=0x7f268833f850, r=<optimized
out>) at ./src/include/Context.h:77
#12 0x00007f274f6b647b in ThreadPool::worker (this=0x55d1b9d04860, wt=<optimized
out>) at ./src/common/WorkQueue.cc:118
#13 0x00007f274f6b7545 in ThreadPool::WorkThread::entry (this=<optimized out>) at
./src/common/WorkQueue.h:466
#14 0x00007f276173e609 in start_thread (arg=<optimized out>) at
pthread_create.c:477
#15 0x00007f2761665103 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
</pre>
_______________________________________________
ceph-users mailing list -- ceph-users(a)ceph.io
To unsubscribe send an email to ceph-users-leave(a)ceph.io
--
Jason
4:44 p.m.
On 2020-07-28 14:49, Jason Dillaman wrote:
The workload is a virtual machine with the above libvirt device
configuration. Within that virtual machine, the workload is run
sequentially (as script crash.sh) on the xfs formatted device.
I.e. librbd/ceph should only the one qemu process, which is then running
the workload.
Only the last fio invocation causes the problems.
When skipping some (I did not test it exhaustively) of the fio
invocations, the crash is no longer reliably triggered.
VM in libvirt
with:
<pre>
<disk type='network' device='disk'>
<driver name='qemu' type='raw' discard='unmap'/>
<source protocol='rbd' name='pool/disk' index='4'>
<!-- omitted -->
</source>
<iotune>
<read_bytes_sec>209715200</read_bytes_sec>
<write_bytes_sec>209715200</write_bytes_sec>
<read_iops_sec>5000</read_iops_sec>
<write_iops_sec>5000</write_iops_sec>
<read_bytes_sec_max>314572800</read_bytes_sec_max>
<write_bytes_sec_max>314572800</write_bytes_sec_max>
<read_iops_sec_max>7500</read_iops_sec_max>
<write_iops_sec_max>7500</write_iops_sec_max>
<read_bytes_sec_max_length>60</read_bytes_sec_max_length>
<write_bytes_sec_max_length>60</write_bytes_sec_max_length>
<read_iops_sec_max_length>60</read_iops_sec_max_length>
<write_iops_sec_max_length>60</write_iops_sec_max_length>
</iotune>
</disk>
</pre>
workload:
<pre>
fio --rw=write --name=test --size=10M
timeout 30s fio --rw=write --name=test --size=20G
timeout 3m fio --rw=write --name=test --size=20G --direct=1
timeout 1m fio --rw=randrw --name=test --size=20G --direct=1
timeout 10s fio --numjobs=8 --rw=randrw --name=test --size=1G --direct=1
# the backtraces are then observed while the following command is running
fio --ioengine=libaio --iodepth=16 --numjobs=8 --rw=randrw --name=test --size=1G
--direct=1
I'm not sure I understand this workload. Are you running these 6 "fio"
processes sequentially or concurrently? Does it only crash on that
last one? Do you have "exclusive-lock" enabled on the image since
"--numjobs 8" would cause lots of lock fighting if it was enabled. Are all the crashes seg faults? They all seem to hint
that the
internal ImageCtx instance was destroyed somehow while there was still
in-flight IO. If the crashes appeared during the "timeout XYZ fio ..."
calls, I would think it's highly likely that "fio" is incorrectly
closing the RBD image while there was still in-flight IO via its
signal handler.
They are all segfaults of the qemu process, captured on the host system.
librbd should not see any image open/closing during the workload run
within the VM.
The `timeout` is used to approximate the initial (manual) workload
generation, which caused a crash.
4:52 p.m.
On Tue, Jul 28, 2020 at 9:44 AM Johannes Naab
<johannes.naab(a)hetzner-cloud.de> wrote:
--
Jason
On 2020-07-28 14:49, Jason Dillaman wrote:
The workload is a virtual machine with the above libvirt device
configuration. Within that virtual machine, the workload is run
sequentially (as script crash.sh) on the xfs formatted device.
I.e. librbd/ceph should only the one qemu process, which is then running
the workload.
Only the last fio invocation causes the problems.
When skipping some (I did not test it exhaustively) of the fio
invocations, the crash is no longer reliably triggered.
Hmm, all those crash backtraces are in
"AioCompletion::complete_event_socket", but QEMU does not have any
code that utilizes the event socket notification system. AFAIK, only
the fio librbd engine has integrated with that callback system.
VM in
libvirt with:
<pre>
<disk type='network' device='disk'>
<driver name='qemu' type='raw' discard='unmap'/>
<source protocol='rbd' name='pool/disk' index='4'>
<!-- omitted -->
</source>
<iotune>
<read_bytes_sec>209715200</read_bytes_sec>
<write_bytes_sec>209715200</write_bytes_sec>
<read_iops_sec>5000</read_iops_sec>
<write_iops_sec>5000</write_iops_sec>
<read_bytes_sec_max>314572800</read_bytes_sec_max>
<write_bytes_sec_max>314572800</write_bytes_sec_max>
<read_iops_sec_max>7500</read_iops_sec_max>
<write_iops_sec_max>7500</write_iops_sec_max>
<read_bytes_sec_max_length>60</read_bytes_sec_max_length>
<write_bytes_sec_max_length>60</write_bytes_sec_max_length>
<read_iops_sec_max_length>60</read_iops_sec_max_length>
<write_iops_sec_max_length>60</write_iops_sec_max_length>
</iotune>
</disk>
</pre>
workload:
<pre>
fio --rw=write --name=test --size=10M
timeout 30s fio --rw=write --name=test --size=20G
timeout 3m fio --rw=write --name=test --size=20G --direct=1
timeout 1m fio --rw=randrw --name=test --size=20G --direct=1
timeout 10s fio --numjobs=8 --rw=randrw --name=test --size=1G --direct=1
# the backtraces are then observed while the following command is running
fio --ioengine=libaio --iodepth=16 --numjobs=8 --rw=randrw --name=test --size=1G
--direct=1
I'm not sure I understand this workload. Are you running these 6 "fio"
processes sequentially or concurrently? Does it only crash on that
last one? Do you have "exclusive-lock" enabled on the image since
"--numjobs 8" would cause lots of lock fighting if it was enabled. Are all the
crashes seg faults? They all seem to hint that the
internal ImageCtx instance was destroyed somehow while there was still
in-flight IO. If the crashes appeared during the "timeout XYZ fio ..."
calls, I would think it's highly likely that "fio" is incorrectly
closing the RBD image while there was still in-flight IO via its
signal handler.
They are all segfaults of the qemu process, captured on the host system.
librbd should not see any image open/closing during the workload run
within the VM.
The `timeout` is used to approximate the initial (manual) workload
generation, which caused a crash.
6:19 p.m.
On 2020-07-28 15:52, Jason Dillaman wrote:
On Tue, Jul 28, 2020 at 9:44 AM Johannes Naab
<johannes.naab(a)hetzner-cloud.de> wrote:
The host is an Ubuntu 20.04 with minor backports in libvirt (6.0.0-0ubuntu8.1)
and qemu (1:4.2-3ubuntu6.3) for specific CPU IDs, and the ceph.com librbd1.
Upon further testing, changing the libvirt device configuration to:
On 2020-07-28 14:49, Jason Dillaman wrote:
The workload is a virtual machine with the above libvirt device
configuration. Within that virtual machine, the workload is run
sequentially (as script crash.sh) on the xfs formatted device.
I.e. librbd/ceph should only the one qemu process, which is then running
the workload.
Only the last fio invocation causes the problems.
When skipping some (I did not test it exhaustively) of the fio
invocations, the crash is no longer reliably triggered.
Hmm, all those crash backtraces are in
"AioCompletion::complete_event_socket", but QEMU does not have any
code that utilizes the event socket notification system. AFAIK, only
the fio librbd engine has integrated with that callback system.
VM in
libvirt with:
<pre>
<disk type='network' device='disk'>
<driver name='qemu' type='raw' discard='unmap'/>
<source protocol='rbd' name='pool/disk' index='4'>
<!-- omitted -->
</source>
<iotune>
<read_bytes_sec>209715200</read_bytes_sec>
<write_bytes_sec>209715200</write_bytes_sec>
<read_iops_sec>5000</read_iops_sec>
<write_iops_sec>5000</write_iops_sec>
<read_bytes_sec_max>314572800</read_bytes_sec_max>
<write_bytes_sec_max>314572800</write_bytes_sec_max>
<read_iops_sec_max>7500</read_iops_sec_max>
<write_iops_sec_max>7500</write_iops_sec_max>
<read_bytes_sec_max_length>60</read_bytes_sec_max_length>
<write_bytes_sec_max_length>60</write_bytes_sec_max_length>
<read_iops_sec_max_length>60</read_iops_sec_max_length>
<write_iops_sec_max_length>60</write_iops_sec_max_length>
</iotune>
</disk>
</pre>
workload:
<pre>
fio --rw=write --name=test --size=10M
timeout 30s fio --rw=write --name=test --size=20G
timeout 3m fio --rw=write --name=test --size=20G --direct=1
timeout 1m fio --rw=randrw --name=test --size=20G --direct=1
timeout 10s fio --numjobs=8 --rw=randrw --name=test --size=1G --direct=1
# the backtraces are then observed while the following command is running
fio --ioengine=libaio --iodepth=16 --numjobs=8 --rw=randrw --name=test --size=1G
--direct=1
I'm not sure I understand this workload. Are you running these 6 "fio"
processes sequentially or concurrently? Does it only crash on that
last one? Do you have "exclusive-lock" enabled on the image since
"--numjobs 8" would cause lots of lock fighting if it was enabled. <driver name='qemu' type='raw'
cache='none' io='native' discard='unmap'/>
(adding cache='none' amd io='native'), did not yet resurface the crash.
Based on my understanding, cache='writeback' and io='thread' are the
defaults when not otherwise configured. However, I do not yet fully
understand the dependencies between those options.
Are the libvirt <driver cache='...'> and librbd caches distinct, or do
they refer to the same cache
(http://lists.ceph.com/pipermail/ceph-users-ceph.com/2016-March/008486.html)?
Are all the crashes seg faults? They all seem to hint
that the
internal ImageCtx instance was destroyed somehow while there was still
in-flight IO. If the crashes appeared during the "timeout XYZ fio ..."
calls, I would think it's highly likely that "fio" is incorrectly
closing the RBD image while there was still in-flight IO via its
signal handler.
They are all segfaults of the qemu process, captured on the host system.
librbd should not see any image open/closing during the workload run
within the VM.
The `timeout` is used to approximate the initial (manual) workload
generation, which caused a crash.
6:39 p.m.
On Tue, Jul 28, 2020 at 11:19 AM Johannes Naab
<johannes.naab(a)hetzner-cloud.de> wrote:
On 2020-07-28 15:52, Jason Dillaman wrote:
The "io=native" vs "io=threads" is a no-op for all by file-based IO.
The "cache" setting will just configure the librbd in-memory cache
mode (disabled, write-through, or write-back).
On Tue, Jul 28, 2020 at 9:44 AM Johannes Naab
<johannes.naab(a)hetzner-cloud.de> wrote:
The host is an Ubuntu 20.04 with minor backports in libvirt (6.0.0-0ubuntu8.1)
and qemu (1:4.2-3ubuntu6.3) for specific CPU IDs, and the ceph.com librbd1.
Upon further testing, changing the libvirt device configuration to:
On 2020-07-28 14:49, Jason Dillaman wrote:
Hmm, all those crash backtraces are in
"AioCompletion::complete_event_socket", but QEMU does not have any
code that utilizes the event socket notification system. AFAIK, only
the fio librbd engine has integrated with that callback system.
> VM in libvirt with:
> <pre>
> <disk type='network' device='disk'>
> <driver name='qemu' type='raw' discard='unmap'/>
> <source protocol='rbd' name='pool/disk'
index='4'>
> <!-- omitted -->
> </source>
> <iotune>
> <read_bytes_sec>209715200</read_bytes_sec>
> <write_bytes_sec>209715200</write_bytes_sec>
> <read_iops_sec>5000</read_iops_sec>
> <write_iops_sec>5000</write_iops_sec>
> <read_bytes_sec_max>314572800</read_bytes_sec_max>
> <write_bytes_sec_max>314572800</write_bytes_sec_max>
> <read_iops_sec_max>7500</read_iops_sec_max>
> <write_iops_sec_max>7500</write_iops_sec_max>
> <read_bytes_sec_max_length>60</read_bytes_sec_max_length>
> <write_bytes_sec_max_length>60</write_bytes_sec_max_length>
> <read_iops_sec_max_length>60</read_iops_sec_max_length>
> <write_iops_sec_max_length>60</write_iops_sec_max_length>
> </iotune>
> </disk>
> </pre>
>
> workload:
> <pre>
> fio --rw=write --name=test --size=10M
> timeout 30s fio --rw=write --name=test --size=20G
> timeout 3m fio --rw=write --name=test --size=20G --direct=1
> timeout 1m fio --rw=randrw --name=test --size=20G --direct=1
> timeout 10s fio --numjobs=8 --rw=randrw --name=test --size=1G --direct=1
> # the backtraces are then observed while the following command is running
> fio --ioengine=libaio --iodepth=16 --numjobs=8 --rw=randrw --name=test --size=1G
--direct=1
I'm not sure I understand this workload. Are you running these 6 "fio"
processes sequentially or concurrently? Does it only crash on that
last one? Do you have "exclusive-lock" enabled on the image since
"--numjobs 8" would cause lots of lock fighting if it was enabled.
The workload is a virtual machine with the above libvirt device
configuration. Within that virtual machine, the workload is run
sequentially (as script crash.sh) on the xfs formatted device.
I.e. librbd/ceph should only the one qemu process, which is then running
the workload.
Only the last fio invocation causes the problems.
When skipping some (I did not test it exhaustively) of the fio
invocations, the crash is no longer reliably triggered. <driver name='qemu' type='raw'
cache='none' io='native' discard='unmap'/>
(adding cache='none' amd io='native'), did not yet resurface the crash.
Based on my understanding, cache='writeback' and io='thread' are the
defaults when not otherwise configured. However, I do not yet fully
understand the dependencies between those options. Are the libvirt <driver cache='...'> and
librbd caches distinct, or do
they refer to the same cache
(http://lists.ceph.com/pipermail/ceph-users-ceph.com/2016-March/008486.html)?
--
Jason
Are all the crashes seg faults? They all seem to hint
that the
internal ImageCtx instance was destroyed somehow while there was still
in-flight IO. If the crashes appeared during the "timeout XYZ fio ..."
calls, I would think it's highly likely that "fio" is incorrectly
closing the RBD image while there was still in-flight IO via its
signal handler.
They are all segfaults of the qemu process, captured on the host system.
librbd should not see any image open/closing during the workload run
within the VM.
The `timeout` is used to approximate the initial (manual) workload
generation, which caused a crash.
6:40 p.m.
On Tue, Jul 28, 2020 at 11:39 AM Jason Dillaman <jdillama(a)redhat.com> wrote:
On Tue, Jul 28, 2020 at 11:19 AM Johannes Naab
<johannes.naab(a)hetzner-cloud.de> wrote:
"for all non file-based"
On 2020-07-28 15:52, Jason Dillaman wrote:
The "io=native" vs "io=threads" is a no-op for all by file-based IO.
On Tue, Jul 28, 2020 at 9:44 AM Johannes Naab
<johannes.naab(a)hetzner-cloud.de> wrote:
The host is an Ubuntu 20.04 with minor backports in libvirt (6.0.0-0ubuntu8.1)
and qemu (1:4.2-3ubuntu6.3) for specific CPU IDs, and the ceph.com librbd1.
Upon further testing, changing the libvirt device configuration to:
On 2020-07-28 14:49, Jason Dillaman wrote:
>> VM in libvirt with:
>> <pre>
>> <disk type='network' device='disk'>
>> <driver name='qemu' type='raw'
discard='unmap'/>
>> <source protocol='rbd' name='pool/disk'
index='4'>
>> <!-- omitted -->
>> </source>
>> <iotune>
>> <read_bytes_sec>209715200</read_bytes_sec>
>> <write_bytes_sec>209715200</write_bytes_sec>
>> <read_iops_sec>5000</read_iops_sec>
>> <write_iops_sec>5000</write_iops_sec>
>> <read_bytes_sec_max>314572800</read_bytes_sec_max>
>> <write_bytes_sec_max>314572800</write_bytes_sec_max>
>> <read_iops_sec_max>7500</read_iops_sec_max>
>> <write_iops_sec_max>7500</write_iops_sec_max>
>> <read_bytes_sec_max_length>60</read_bytes_sec_max_length>
>> <write_bytes_sec_max_length>60</write_bytes_sec_max_length>
>> <read_iops_sec_max_length>60</read_iops_sec_max_length>
>> <write_iops_sec_max_length>60</write_iops_sec_max_length>
>> </iotune>
>> </disk>
>> </pre>
>>
>> workload:
>> <pre>
>> fio --rw=write --name=test --size=10M
>> timeout 30s fio --rw=write --name=test --size=20G
>> timeout 3m fio --rw=write --name=test --size=20G --direct=1
>> timeout 1m fio --rw=randrw --name=test --size=20G --direct=1
>> timeout 10s fio --numjobs=8 --rw=randrw --name=test --size=1G --direct=1
>> # the backtraces are then observed while the following command is running
>> fio --ioengine=libaio --iodepth=16 --numjobs=8 --rw=randrw --name=test --size=1G
--direct=1
>
> I'm not sure I understand this workload. Are you running these 6 "fio"
> processes sequentially or concurrently? Does it only crash on that
> last one? Do you have "exclusive-lock" enabled on the image since
> "--numjobs 8" would cause lots of lock fighting if it was enabled.
The workload is a virtual machine with the above libvirt device
configuration. Within that virtual machine, the workload is run
sequentially (as script crash.sh) on the xfs formatted device.
I.e. librbd/ceph should only the one qemu process, which is then running
the workload.
Only the last fio invocation causes the problems.
When skipping some (I did not test it exhaustively) of the fio
invocations, the crash is no longer reliably triggered.
Hmm, all those crash backtraces are in
"AioCompletion::complete_event_socket", but QEMU does not have any
code that utilizes the event socket notification system. AFAIK, only
the fio librbd engine has integrated with that callback system.
<driver name='qemu' type='raw'
cache='none' io='native' discard='unmap'/>
(adding cache='none' amd io='native'), did not yet resurface the crash.
Based on my understanding, cache='writeback' and io='thread' are the
defaults when not otherwise configured. However, I do not yet fully
understand the dependencies between those options. The "cache" setting will just configure the
librbd in-memory cache
mode (disabled, write-through, or write-back).
--
Jason
Are the libvirt <driver
cache='...'> and librbd caches distinct, or do
they refer to the same cache
(http://lists.ceph.com/pipermail/ceph-users-ceph.com/2016-March/008486.html)?
--
Jason > Are
all the crashes seg faults? They all seem to hint that the
> internal ImageCtx instance was destroyed somehow while there was still
> in-flight IO. If the crashes appeared during the "timeout XYZ fio ..."
> calls, I would think it's highly likely that "fio" is incorrectly
> closing the RBD image while there was still in-flight IO via its
> signal handler.
They are all segfaults of the qemu process, captured on the host system.
librbd should not see any image open/closing during the workload run
within the VM.
The `timeout` is used to approximate the initial (manual) workload
generation, which caused a crash.
1373
days inactive
1373
days old
6 comments
2 participants
participants (2)
-
Jason Dillaman -
Johannes Naab