Project

General

Profile

Bug #22678

block checksum mismatch from rocksdb

Added by Mike O'Connor over 3 years ago. Updated over 3 years ago.

Status:
Duplicate
Priority:
High
Assignee:
-
Target version:
% Done:

0%

Source:
Community (user)
Tags:
Backport:
Regression:
No
Severity:
2 - major
Reviewed:
Affected Versions:
ceph-qa-suite:
Pull request ID:
Crash signature (v1):
Crash signature (v2):

Description

Hi
There seems to be a crash bug in the Luminous OSD code which causes OSDs to crash.

Jan 15 15:54:43 pve ceph-osd[29759]: 2018-01-15 15:54:43.557716 7f683157e700 -1 abort: Corruption: block checksum mismatch*** Caught signal (Aborted) **
Jan 15 15:54:43 pve ceph-osd[29759]:  in thread 7f683157e700 thread_name:tp_osd_tp
Jan 15 15:54:43 pve ceph-osd[29759]:  ceph version 12.2.2 (215dd7151453fae88e6f968c975b6ce309d42dcf) luminous (stable)
Jan 15 15:54:43 pve ceph-osd[29759]:  1: (()+0xa16664) [0x5626f6077664]
Jan 15 15:54:43 pve ceph-osd[29759]:  2: (()+0x110c0) [0x7f684996f0c0]
Jan 15 15:54:43 pve ceph-osd[29759]:  3: (gsignal()+0xcf) [0x7f6848936fcf]
Jan 15 15:54:43 pve ceph-osd[29759]:  4: (abort()+0x16a) [0x7f68489383fa]
Jan 15 15:54:43 pve ceph-osd[29759]:  5: (RocksDBStore::get(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, char const*, unsigned long, ceph::buffer:
:list*)+0x29f) [0x5626f5fb595f]
Jan 15 15:54:43 pve ceph-osd[29759]:  6: (BlueStore::Collection::get_onode(ghobject_t const&, bool)+0x5ae) [0x5626f5f392ae]
Jan 15 15:54:43 pve ceph-osd[29759]:  7: (BlueStore::read(boost::intrusive_ptr<ObjectStore::CollectionImpl>&, ghobject_t const&, unsigned long, unsigned long, ceph::buffer::list&, unsigned
int)+0xfc) [0x5626f5f64a9c]
Jan 15 15:54:43 pve ceph-osd[29759]:  8: (ECBackend::handle_sub_read(pg_shard_t, ECSubRead const&, ECSubReadReply*, ZTracer::Trace const&)+0x239) [0x5626f5df1209]
Jan 15 15:54:43 pve ceph-osd[29759]:  9: (ECBackend::_handle_message(boost::intrusive_ptr<OpRequest>)+0x50d) [0x5626f5df29cd]
Jan 15 15:54:43 pve ceph-osd[29759]:  10: (PGBackend::handle_message(boost::intrusive_ptr<OpRequest>)+0x50) [0x5626f5cd1be0]
Jan 15 15:54:43 pve ceph-osd[29759]:  11: (PrimaryLogPG::do_request(boost::intrusive_ptr<OpRequest>&, ThreadPool::TPHandle&)+0x503) [0x5626f5c37a73]
Jan 15 15:54:43 pve ceph-osd[29759]:  12: (OSD::dequeue_op(boost::intrusive_ptr<PG>, boost::intrusive_ptr<OpRequest>, ThreadPool::TPHandle&)+0x3ab) [0x5626f5ab59eb]
Jan 15 15:54:43 pve ceph-osd[29759]:  13: (PGQueueable::RunVis::operator()(boost::intrusive_ptr<OpRequest> const&)+0x5a) [0x5626f5d53eba]
Jan 15 15:54:43 pve ceph-osd[29759]:  14: (OSD::ShardedOpWQ::_process(unsigned int, ceph::heartbeat_handle_d*)+0x103d) [0x5626f5adcf4d]
Jan 15 15:54:43 pve ceph-osd[29759]:  15: (ShardedThreadPool::shardedthreadpool_worker(unsigned int)+0x8ef) [0x5626f60c406f]
Jan 15 15:54:43 pve ceph-osd[29759]:  16: (ShardedThreadPool::WorkThreadSharded::entry()+0x10) [0x5626f60c7370]
Jan 15 15:54:43 pve ceph-osd[29759]:  17: (()+0x7494) [0x7f6849965494]
Jan 15 15:54:43 pve ceph-osd[29759]:  18: (clone()+0x3f) [0x7f68489ecaff]
Jan 15 15:54:43 pve ceph-osd[29759]: 2018-01-15 15:54:43.562224 7f683157e700 -1 *** Caught signal (Aborted) **
Jan 15 15:54:43 pve ceph-osd[29759]:  in thread 7f683157e700 thread_name:tp_osd_tp
Jan 15 15:54:43 pve ceph-osd[29759]:  ceph version 12.2.2 (215dd7151453fae88e6f968c975b6ce309d42dcf) luminous (stable)
Jan 15 15:54:43 pve ceph-osd[29759]:  1: (()+0xa16664) [0x5626f6077664]
Jan 15 15:54:43 pve ceph-osd[29759]:  2: (()+0x110c0) [0x7f684996f0c0]
Jan 15 15:54:43 pve ceph-osd[29759]:  3: (gsignal()+0xcf) [0x7f6848936fcf]
Jan 15 15:54:43 pve ceph-osd[29759]:  4: (abort()+0x16a) [0x7f68489383fa]
Jan 15 15:54:43 pve ceph-osd[29759]:  5: (RocksDBStore::get(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, char const*, unsigned long, ceph::buffer:
:list*)+0x29f) [0x5626f5fb595f]
Jan 15 15:54:43 pve ceph-osd[29759]:  6: (BlueStore::Collection::get_onode(ghobject_t const&, bool)+0x5ae) [0x5626f5f392ae]
Jan 15 15:54:43 pve ceph-osd[29759]:  7: (BlueStore::read(boost::intrusive_ptr<ObjectStore::CollectionImpl>&, ghobject_t const&, unsigned long, unsigned long, ceph::buffer::list&, unsigned
int)+0xfc) [0x5626f5f64a9c]
Jan 15 15:54:43 pve ceph-osd[29759]:  8: (ECBackend::handle_sub_read(pg_shard_t, ECSubRead const&, ECSubReadReply*, ZTracer::Trace const&)+0x239) [0x5626f5df1209]
Jan 15 15:54:43 pve ceph-osd[29759]:  9: (ECBackend::_handle_message(boost::intrusive_ptr<OpRequest>)+0x50d) [0x5626f5df29cd]
Jan 15 15:54:43 pve ceph-osd[29759]:  10: (PGBackend::handle_message(boost::intrusive_ptr<OpRequest>)+0x50) [0x5626f5cd1be0]
Jan 15 15:54:43 pve ceph-osd[29759]:  11: (PrimaryLogPG::do_request(boost::intrusive_ptr<OpRequest>&, ThreadPool::TPHandle&)+0x503) [0x5626f5c37a73]
Jan 15 15:54:43 pve ceph-osd[29759]:  12: (OSD::dequeue_op(boost::intrusive_ptr<PG>, boost::intrusive_ptr<OpRequest>, ThreadPool::TPHandle&)+0x3ab) [0x5626f5ab59eb]
Jan 15 15:54:43 pve ceph-osd[29759]:  13: (PGQueueable::RunVis::operator()(boost::intrusive_ptr<OpRequest> const&)+0x5a) [0x5626f5d53eba]
Jan 15 15:54:43 pve ceph-osd[29759]:  14: (OSD::ShardedOpWQ::_process(unsigned int, ceph::heartbeat_handle_d*)+0x103d) [0x5626f5adcf4d]
Jan 15 15:54:43 pve ceph-osd[29759]:  15: (ShardedThreadPool::shardedthreadpool_worker(unsigned int)+0x8ef) [0x5626f60c406f]
Jan 15 15:54:43 pve ceph-osd[29759]:  16: (ShardedThreadPool::WorkThreadSharded::entry()+0x10) [0x5626f60c7370]
Jan 15 15:54:43 pve ceph-osd[29759]:  17: (()+0x7494) [0x7f6849965494]
Jan 15 15:54:43 pve ceph-osd[29759]:  18: (clone()+0x3f) [0x7f68489ecaff]
Jan 15 15:54:43 pve ceph-osd[29759]:  NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this.
Jan 15 15:54:43 pve ceph-osd[29759]:     -1> 2018-01-15 15:54:43.557716 7f683157e700 -1 abort: Corruption: block checksum mismatch
Jan 15 15:54:43 pve ceph-osd[29759]:      0> 2018-01-15 15:54:43.562224 7f683157e700 -1 *** Caught signal (Aborted) **
Jan 15 15:54:43 pve ceph-osd[29759]:  in thread 7f683157e700 thread_name:tp_osd_tp
Jan 15 15:54:43 pve ceph-osd[29759]:  ceph version 12.2.2 (215dd7151453fae88e6f968c975b6ce309d42dcf) luminous (stable)
Jan 15 15:54:43 pve ceph-osd[29759]:  1: (()+0xa16664) [0x5626f6077664]
Jan 15 15:54:43 pve ceph-osd[29759]:  2: (()+0x110c0) [0x7f684996f0c0]
Jan 15 15:54:43 pve ceph-osd[29759]:  3: (gsignal()+0xcf) [0x7f6848936fcf]
Jan 15 15:54:43 pve ceph-osd[29759]:  4: (abort()+0x16a) [0x7f68489383fa]
Jan 15 15:54:43 pve ceph-osd[29759]:  5: (RocksDBStore::get(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, char const*, unsigned long, ceph::buffer::list*)+0x29f) [0x5626f5fb595f]
Jan 15 15:54:43 pve ceph-osd[29759]:  6: (BlueStore::Collection::get_onode(ghobject_t const&, bool)+0x5ae) [0x5626f5f392ae]
Jan 15 15:54:43 pve ceph-osd[29759]:  7: (BlueStore::read(boost::intrusive_ptr<ObjectStore::CollectionImpl>&, ghobject_t const&, unsigned long, unsigned long, ceph::buffer::list&, unsigned int)+0xfc) [0x5626f5f64a9c]
Jan 15 15:54:43 pve ceph-osd[29759]:  8: (ECBackend::handle_sub_read(pg_shard_t, ECSubRead const&, ECSubReadReply*, ZTracer::Trace const&)+0x239) [0x5626f5df1209]
Jan 15 15:54:43 pve ceph-osd[29759]:  9: (ECBackend::_handle_message(boost::intrusive_ptr<OpRequest>)+0x50d) [0x5626f5df29cd]
Jan 15 15:54:43 pve ceph-osd[29759]:  10: (PGBackend::handle_message(boost::intrusive_ptr<OpRequest>)+0x50) [0x5626f5cd1be0]
Jan 15 15:54:43 pve ceph-osd[29759]:  11: (PrimaryLogPG::do_request(boost::intrusive_ptr<OpRequest>&, ThreadPool::TPHandle&)+0x503) [0x5626f5c37a73]
Jan 15 15:54:43 pve ceph-osd[29759]:  12: (OSD::dequeue_op(boost::intrusive_ptr<PG>, boost::intrusive_ptr<OpRequest>, ThreadPool::TPHandle&)+0x3ab) [0x5626f5ab59eb]
Jan 15 15:54:43 pve ceph-osd[29759]:  13: (PGQueueable::RunVis::operator()(boost::intrusive_ptr<OpRequest> const&)+0x5a) [0x5626f5d53eba]
Jan 15 15:54:43 pve ceph-osd[29759]:  14: (OSD::ShardedOpWQ::_process(unsigned int, ceph::heartbeat_handle_d*)+0x103d) [0x5626f5adcf4d]
Jan 15 15:54:43 pve ceph-osd[29759]:  15: (ShardedThreadPool::shardedthreadpool_worker(unsigned int)+0x8ef) [0x5626f60c406f]
Jan 15 15:54:43 pve ceph-osd[29759]:  16: (ShardedThreadPool::WorkThreadSharded::entry()+0x10) [0x5626f60c7370]
Jan 15 15:54:43 pve ceph-osd[29759]:  17: (()+0x7494) [0x7f6849965494]
Jan 15 15:54:43 pve ceph-osd[29759]:  18: (clone()+0x3f) [0x7f68489ecaff]
Jan 15 15:54:43 pve ceph-osd[29759]:  NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this.

I can provide a copy of the dump file if needed but it will not fit inside 1000KB

Happy to provide whatever I can in the way of other detail.

Thanks
Mike


Related issues

Related to bluestore - Bug #22102: BlueStore crashed on rocksdb checksum mismatch Won't Fix 11/10/2017

History

#1 Updated by Greg Farnum over 3 years ago

  • Project changed from Ceph to bluestore
  • Category deleted (OSD)

#2 Updated by Sage Weil over 3 years ago

  • Subject changed from OSD Crash - block checksum mismatch to block checksum mismatch from rocksdb
  • Status changed from New to Need More Info
  • Priority changed from Normal to High

Could it be that the device has an actual media error? Can you check dmesg for errors?

#3 Updated by Sage Weil over 3 years ago

oh, see #22102.

was the workload cephfs?

#4 Updated by Sage Weil over 3 years ago

  • Status changed from Need More Info to Duplicate

#5 Updated by Sage Weil over 3 years ago

  • Related to Bug #22102: BlueStore crashed on rocksdb checksum mismatch added

#6 Updated by Mike O'Connor over 3 years ago

I'm able to create a crash easily by just copying files in to CephFS, but I was able to cause the crash with just RBD before I configured the CephFS.
I've checked the hard drives extensivly and have not found any issues with the drives (all 18 of them) The crash does not seem to ever be related to any one or two drives.

#7 Updated by Mike O'Connor over 3 years ago

I'm currently backing up all the data on both CephFS and RBD so that if needed I can wipe the configuration and start again. But I really do not want to do that. I'm going to LCA next week and will be away for another week after on work. But I'm happy to try to do any testing I can.

#8 Updated by Mike O'Connor over 3 years ago

I thought part of the issue might be the old firmware on the 3 x LSI SAS9201-8i controller cards. So I upgraded them to the second to last release (P19). The issue continues.
I did not go to P20 as I saw some reports of issues though they were mostly with FreeBSD.

#9 Updated by Sergey Malinin over 3 years ago

I have similar issue with two OSDs (12.2.4) running on the same host. Recreating OSDs did not have any effect, I get this error several times a day.

2018-04-04 18:25:27.344734 7fe844783700 -1 abort: Corruption: block checksum mismatch
2018-04-04 18:25:27.364066 7fe844783700 -1 ** Caught signal (Aborted) *
in thread 7fe844783700 thread_name:tp_osd_tp

ceph version 12.2.4 (52085d5249a80c5f5121a76d6288429f35e4e77b) luminous (stable)
1: (()+0xa74234) [0x556be6903234]
2: (()+0x13150) [0x7fe86485f150]
3: (gsignal()+0xcb) [0x7fe86378f0bb]
4: (abort()+0x16d) [0x7fe863790f5d]
x556be6843532]
5: (RocksDBStore::get(std::__cxx11::basic_string&lt;char, std::char_traits&lt;char&gt;, std::allocator&lt;char&gt; > const&, std::__cxx11::basic_string&lt;char, std::char_traits&lt;char&gt;, std::allocator&lt;char&gt; > const&, ceph::buffer::list*)+0x282) [0
6: (BlueStore::omap_get_header(boost::intrusive_ptr&lt;ObjectStore::CollectionImpl&gt;&, ghobject_t const&, ceph::buffer::list*, bool)+0x16f) [0x556be67c905f]
7: (PrimaryLogPG::do_osd_ops(PrimaryLogPG::OpContext*, std::vector&lt;OSDOp, std::allocator&lt;OSDOp&gt; >&)+0x1ea6) [0x556be64f8f46]
8: (PrimaryLogPG::prepare_transaction(PrimaryLogPG::OpContext*)+0xbf) [0x556be65099af]
9: (PrimaryLogPG::execute_ctx(PrimaryLogPG::OpContext*)+0x2db) [0x556be650a22b]
10: (PrimaryLogPG::do_op(boost::intrusive_ptr&lt;OpRequest&gt;&)+0x308e) [0x556be650ed0e]
11: (PrimaryLogPG::do_request(boost::intrusive_ptr&lt;OpRequest&gt;&, ThreadPool::TPHandle&)+0xea9) [0x556be64c9339]
12: (OSD::dequeue_op(boost::intrusive_ptr&lt;PG&gt;, boost::intrusive_ptr&lt;OpRequest&gt;, ThreadPool::TPHandle&)+0x3a9) [0x556be63423b9]
13: (PGQueueable::RunVis::operator()(boost::intrusive_ptr&lt;OpRequest&gt; const&)+0x57) [0x556be65e5047]
14: (OSD::ShardedOpWQ::_process(unsigned int, ceph::heartbeat_handle_d*)+0x130e) [0x556be636a9ae]
15: (ShardedThreadPool::shardedthreadpool_worker(unsigned int)+0x884) [0x556be694b664]
16: (ShardedThreadPool::WorkThreadSharded::entry()+0x10) [0x556be694e6a0]
17: (()+0x77fc) [0x7fe8648537fc]
18: (clone()+0x3f) [0x7fe86386cb5f]
NOTE: a copy of the executable, or `objdump -rdS &lt;executable&gt;` is needed to interpret this.

#10 Updated by Radoslaw Zarzynski over 3 years ago

Is the error permanent in the sense that an affected OSD doesn't start and must be recreated?

Could you please provide OSD log with increased verbosity levels (debug_bluestore=20, debug_bdev=20, debug_rocksdb=20)? It can be uploaded via the "ceph-post-file":"http://docs.ceph.com/docs/luminous/man/8/ceph-post-file/" tool.

#11 Updated by Sergey Malinin over 3 years ago

After crash OSD restarts and goes on running for a few hours before it crashes again.

I have uploaded log file with debug options set as advised. Upload id is 32943b5d-44a5-405f-9ad7-cb0e7dfa991a
OSD crashed at 20:45:24 log time.

#12 Updated by Sage Weil over 3 years ago

Sergey, can you generate a similar log, but also with 'debug bluefs = 20' enabled? You can even turn down 'debug bluestore = 20' (back to the default) if you need to.

#13 Updated by Sergey Malinin over 3 years ago

debug_bluefs=20

Uploaded with id 5f2ee681-a9d7-4923-899e-5852b3fe18cb

Also available in: Atom PDF