Bug #47457
Updated by Kefu Chai over 3 years ago
<pre>
DEBUG 2020-09-15 10:43:48,695 [shard 0] osd - pg_epoch 20 pg[3.1( v 21'140 (0'0,21'140] local-lis/les=15/16 n=0 ec=15/15 lis/c=15/15 les/c/f=16/16/0 sis=15) [3,1,0] r=1 lpr=15 luod=0'0 lua=0'0 crt=21'139
lcod 21'139 mlcod 21'139 active add_log_entry 21'140 (0'0) modify 3:8c678ee6:::smithi12120850-546:head by client.4229.0:2442 2020-09-15T10:43:48.674253+0000 0 ObjectCleanRegions clean_offsets: [0~75981
5,1231583~18446744073708320032], clean_omap: 1, new_object: 0
DEBUG 2020-09-15 10:43:48,695 [shard 0] osd - pg_epoch 20 pg[3.1( v 21'140 (0'0,21'140] local-lis/les=15/16 n=0 ec=15/15 lis/c=15/15 les/c/f=16/16/0 sis=15) [3,1,0] r=1 lpr=15 luod=0'0 lua=0'0 crt=21'140
lcod 21'139 mlcod 21'139 active append_log approx pg log length = 140
DEBUG 2020-09-15 10:43:48,695 [shard 0] osd - pg_epoch 20 pg[3.1( v 21'140 (0'0,21'140] local-lis/les=15/16 n=0 ec=15/15 lis/c=15/15 les/c/f=16/16/0 sis=15) [3,1,0] r=1 lpr=15 luod=0'0 lua=0'0 crt=21'140
lcod 21'139 mlcod 21'139 active append_log transaction_applied = 1
DEBUG 2020-09-15 10:43:48,695 [shard 0] osd - trim proposed trim_to = 0'0
DEBUG 2020-09-15 10:43:48,695 [shard 0] osd - write_log_and_missing with: dirty_to: 0'0, dirty_from: 4294967295'18446744073709551615, writeout_from: 21'140, trimmed: , trimmed_dups: , clear_divergent_prio
rs: 0
DEBUG 2020-09-15 10:43:48,695 [shard 0] filestore - do_transaction
DEBUG 2020-09-15 10:43:48,695 [shard 0] osd - read: data length: 1
DEBUG 2020-09-15 10:43:48,695 [shard 0] osd - do_osd_ops: osd_op(client.4229.0:2424 3.2 3:40ead659:::smithi12120850-541:head {read 0~1 out=1b} snapc 0={} ondisk+read+rwordered+known_if_redirected e17) v8
- object 3:40ead659:::smithi12120850-541:head all operations successful
DEBUG 2020-09-15 10:43:48,695 [shard 0] osd - do_osd_ops: osd_op(client.4229.0:2424 3.2 3:40ead659:::smithi12120850-541:head {read 0~1 out=1b} snapc 0={} ondisk+read+rwordered+known_if_redirected e17) v8
- object 3:40ead659:::smithi12120850-541:head txn is empty, bypassing mutate
DEBUG 2020-09-15 10:43:48,695 [shard 0] osd - do_osd_ops: osd_op(client.4229.0:2424 3.2 3:40ead659:::smithi12120850-541:head {read 0~1 out=1b} snapc 0={} ondisk+read+rwordered+known_if_redirected e17) v8
- object 3:40ead659:::smithi12120850-541:head sending reply
DEBUG 2020-09-15 10:43:48,695 [shard 0] ms - [osd.1(client) v2:172.21.15.121:6802/18903 >> client.4229 172.21.15.121:0/1605418248@60914] --> #689 === osd_op_reply(2424 smithi12120850-541 {read 0~1 out=1b} v0'0 uv0 ondisk = 0) v8 (43)
DEBUG 2020-09-15 10:43:48,697 [shard 0] osd - do_osd_ops: osd_op(client.4229.0:2409 3.d 3:b4d41631:::smithi12120850-538:head {setxattr (57), truncate 3025359} snapc 0={} ondisk+write+known_if_redirected e17) v8 - object 3:b4d41631:::smithi12120850-538:head sending reply
DEBUG 2020-09-15 10:43:48,697 [shard 0] ms - [osd.1(client) v2:172.21.15.121:6802/18903 >> client.4229 172.21.15.121:0/1605418248@60914] --> #690 === osd_op_reply(2409 smithi12120850-538 {setxattr (57), truncate 3025359} v0'0 uv0 ondisk = 0) v8 (43)
DEBUG 2020-09-15 10:43:48,697 [shard 0] osd - do_osd_ops: osd_op(client.4229.0:2410 3.d 3:b4d41631:::smithi12120850-538:head {read 0~1} snapc 0={} ondisk+read+rwordered+known_if_redirected e17) v8 - object 3:b4d41631:::smithi12120850-538:head - handling op read
DEBUG 2020-09-15 10:43:48,697 [shard 0] osd - handling op read on object 3:b4d41631:::smithi12120850-538:head
TRACE 2020-09-15 10:43:48,697 [shard 0] osd - read: 3:b4d41631:::smithi12120850-538:head 0~1
DEBUG 2020-09-15 10:43:48,697 [shard 0] filestore - read
DEBUG 2020-09-15 10:43:48,698 [shard 0] ms - [osd.1(cluster) v2:172.21.15.121:6803/18903 >> osd.0 v2:172.21.15.121:6801/18902@49168] connect to existing
DEBUG 2020-09-15 10:43:48,698 [shard 0] ms - [osd.1(cluster) v2:172.21.15.121:6803/18903 >> osd.0 v2:172.21.15.121:6801/18902@49168] --> #616 === osd_repop_reply(client.4229.0:2435 3.9 e20/15 ondisk, result = 0) v2 (113)
DEBUG 2020-09-15 10:43:48,699 [shard 0] osd - read: data length: 1
DEBUG 2020-09-15 10:43:48,699 [shard 0] osd - do_osd_ops: osd_op(client.4229.0:2410 3.d 3:b4d41631:::smithi12120850-538:head {read 0~1 out=1b} snapc 0={} ondisk+read+rwordered+known_if_redirected e17) v8 - object 3:b4d41631:::smithi12120850-538:head all operations successful
DEBUG 2020-09-15 10:43:48,699 [shard 0] osd - do_osd_ops: osd_op(client.4229.0:2410 3.d 3:b4d41631:::smithi12120850-538:head {read 0~1 out=1b} snapc 0={} ondisk+read+rwordered+known_if_redirected e17) v8 - object 3:b4d41631:::smithi12120850-538:head txn is empty, bypassing mutate
DEBUG 2020-09-15 10:43:48,699 [shard 0] osd - do_osd_ops: osd_op(client.4229.0:2410 3.d 3:b4d41631:::smithi12120850-538:head {read 0~1 out=1b} snapc 0={} ondisk+read+rwordered+known_if_redirected e17) v8 - object 3:b4d41631:::smithi12120850-538:head sending reply
Segmentation fault.
Backtrace:
void seastar::backtrace<seastar::backtrace_buffer::append_backtrace()::{lambda(seastar::frame)#1}>(seastar::backtrace_buffer::append_backtrace()::{lambda(seastar::frame)#1}&&) at /usr/src/debug/ceph-16.0.0-5537.gce658a6aa76.el8.x86_64/src/seastar/include/seastar/util/backtrace.hh:59
non-virtual thunk to std::_Nested_exception<std::runtime_error>::~_Nested_exception() at /usr/src/debug/ceph-16.0.0-5537.gce658a6aa76.el8.x86_64/src/seastar/src/core/reactor.cc:731
(inlined by) print_with_backtrace at /usr/src/debug/ceph-16.0.0-5537.gce658a6aa76.el8.x86_64/src/seastar/src/core/reactor.cc:752
print_with_backtrace at /usr/src/debug/ceph-16.0.0-5537.gce658a6aa76.el8.x86_64/src/seastar/src/core/reactor.cc:759
non-virtual thunk to std::_Nested_exception<std::runtime_error>::~_Nested_exception() at /usr/src/debug/ceph-16.0.0-5537.gce658a6aa76.el8.x86_64/src/seastar/src/core/reactor.cc:3480
(inlined by) operator() at /usr/src/debug/ceph-16.0.0-5537.gce658a6aa76.el8.x86_64/src/seastar/src/core/reactor.cc:3466
(inlined by) _FUN at /usr/src/debug/ceph-16.0.0-5537.gce658a6aa76.el8.x86_64/src/seastar/src/core/reactor.cc:3462
.annobin_funlockfile.c_end at funlockfile.c:?
non-virtual thunk to std::_Nested_exception<std::runtime_error>::~_Nested_exception() at /opt/rh/gcc-toolset-9/root/usr/include/c++/9/bits/unique_ptr.h:154
(inlined by) ?? at /opt/rh/gcc-toolset-9/root/usr/include/c++/9/bits/unique_ptr.h:353
(inlined by) ?? at /opt/rh/gcc-toolset-9/root/usr/include/c++/9/bits/unique_ptr.h:347
(inlined by) operator() at /usr/src/debug/ceph-16.0.0-5537.gce658a6aa76.el8.x86_64/src/seastar/src/core/reactor.cc:640
(inlined by) _FUN at /usr/src/debug/ceph-16.0.0-5537.gce658a6aa76.el8.x86_64/src/seastar/src/core/reactor.cc:641
.annobin_funlockfile.c_end at funlockfile.c:?
ceph_crc32c_intel_baseline at /usr/src/debug/ceph-16.0.0-5537.gce658a6aa76.el8.x86_64/src/common/crc32c_intel_baseline.c:123
ceph_crc32c at /usr/src/debug/ceph-16.0.0-5537.gce658a6aa76.el8.x86_64/src/include/crc32c.h:50
(inlined by) ceph_crc32c at /usr/src/debug/ceph-16.0.0-5537.gce658a6aa76.el8.x86_64/src/include/crc32c.h:43
(inlined by) ceph::buffer::v15_2_0::list::iterator_impl<true>::crc32c(unsigned long, unsigned int) at /usr/src/debug/ceph-16.0.0-5537.gce658a6aa76.el8.x86_64/src/common/buffer.cc:883
bluestore_blob_t::calc_csum(unsigned long, ceph::buffer::v15_2_0::list const&) at /usr/src/debug/ceph-16.0.0-5537.gce658a6aa76.el8.x86_64/src/common/Checksummer.h:91
(inlined by) ?? at /usr/src/debug/ceph-16.0.0-5537.gce658a6aa76.el8.x86_64/src/common/Checksummer.h:229
(inlined by) ?? at /usr/src/debug/ceph-16.0.0-5537.gce658a6aa76.el8.x86_64/src/common/Checksummer.h:203
(inlined by) bluestore_blob_t::calc_csum(unsigned long, ceph::buffer::v15_2_0::list const&) at /usr/src/debug/ceph-16.0.0-5537.gce658a6aa76.el8.x86_64/src/os/bluestore/bluestore_types.cc:734
BlueStore::_do_alloc_write(BlueStore::TransContext*, boost::intrusive_ptr<BlueStore::Collection>, boost::intrusive_ptr<BlueStore::Onode>, BlueStore::WriteContext*) at /usr/src/debug/ceph-16.0.0-5537.gce658a6aa76.el8.x86_64/src/os/bluestore/BlueStore.cc:13706
BlueStore::_do_write(BlueStore::TransContext*, boost::intrusive_ptr<BlueStore::Collection>&, boost::intrusive_ptr<BlueStore::Onode>, unsigned long, unsigned long, ceph::buffer::v15_2_0::list&, unsigned int) at /usr/src/debug/ceph-16.0.0-5537.gce658a6aa76.el8.x86_64/src/os/bluestore/BlueStore.cc:14076
BlueStore::_write(BlueStore::TransContext*, boost::intrusive_ptr<BlueStore::Collection>&, boost::intrusive_ptr<BlueStore::Onode>&, unsigned long, unsigned long, ceph::buffer::v15_2_0::list&, unsigned int) at /usr/src/debug/ceph-16.0.0-5537.gce658a6aa76.el8.x86_64/src/os/bluestore/BlueStore.cc:14155
BlueStore::_txc_add_transaction(BlueStore::TransContext*, ceph::os::Transaction*) at /usr/src/debug/ceph-16.0.0-5537.gce658a6aa76.el8.x86_64/src/os/bluestore/BlueStore.cc:12492
BlueStore::queue_transactions(boost::intrusive_ptr<ObjectStore::CollectionImpl>&, std::vector<ceph::os::Transaction, std::allocator<ceph::os::Transaction> >&, boost::intrusive_ptr<TrackedOp>, ThreadPool::TPHandle*) at /usr/src/debug/ceph-16.0.0-5537.gce658a6aa76.el8.x86_64/src/os/bluestore/BlueStore.cc:12237
crimson::os::AlienStore::~AlienStore() at /usr/src/debug/ceph-16.0.0-5537.gce658a6aa76.el8.x86_64/src/os/ObjectStore.h:221
(inlined by) operator() at /usr/src/debug/ceph-16.0.0-5537.gce658a6aa76.el8.x86_64/src/crimson/os/alienstore/alien_store.cc:375
(inlined by) ?? at /opt/rh/gcc-toolset-9/root/usr/include/c++/9/bits/invoke.h:60
(inlined by) ?? at /opt/rh/gcc-toolset-9/root/usr/include/c++/9/bits/invoke.h:95
(inlined by) ?? at /opt/rh/gcc-toolset-9/root/usr/include/c++/9/tuple:1684
(inlined by) ?? at /opt/rh/gcc-toolset-9/root/usr/include/c++/9/tuple:1694
(inlined by) operator() at /usr/src/debug/ceph-16.0.0-5537.gce658a6aa76.el8.x86_64/src/crimson/os/alienstore/thread_pool.h:113
(inlined by) process at /usr/src/debug/ceph-16.0.0-5537.gce658a6aa76.el8.x86_64/src/crimson/os/alienstore/thread_pool.h:42
crimson::os::ThreadPool::loop(std::chrono::duration<long, std::ratio<1l, 1000l> >) at /usr/src/debug/ceph-16.0.0-5537.gce658a6aa76.el8.x86_64/src/crimson/os/alienstore/thread_pool.cc:61
</pre>
https://pulpito.ceph.com/kchai-2020-09-15_10:24:22-crimson-rados-wip-47311-kefu-distro-basic-smithi/5436939/