Actions
Bug #24639
closed[segfault] segfault in BlueFS::read
% Done:
0%
Source:
Community (user)
Tags:
Backport:
Regression:
No
Severity:
3 - minor
Reviewed:
Affected Versions:
ceph-qa-suite:
Pull request ID:
Crash signature (v1):
Crash signature (v2):
Description
Via ceph-deploy on my admin host; I created two encrypted bluestore OSDs which after between 4 and 24 hours started persistently flapping with a segfault in the systemd logs. The crash happens immediately on launch, 100% of the time on both OSDs.
The crash happens in the same stack for both ceph-osd and ceph-bluestore-tool.
Realizing the affected host was behind the rest of the recently-upgraded-to-Luminous cluster (exact version unknown, probably latest 16.04 LTS in Canonical repo), I proceeded to upgrade via the Luminous PPA, hoping it was an issue with the experimental bluestore code).
I have now reproduced the bug with Luminous, upgraded the host to 18.04 LTS, and further to Mimic, and not seen a change in behavior, leading me to believe these OSDs are now in some data state which reliably reproduces this issue.
Jun 23 20:12:19 Largo systemd[1]: ceph-osd@0.service: Service hold-off time over, scheduling restart. Jun 23 20:12:19 Largo systemd[1]: ceph-osd@0.service: Scheduled restart job, restart counter is at 51. Jun 23 20:12:19 Largo systemd[1]: Stopped Ceph object storage daemon osd.0. Jun 23 20:12:19 Largo systemd[1]: Starting Ceph object storage daemon osd.0... Jun 23 20:12:19 Largo systemd[1]: Started Ceph object storage daemon osd.0. Jun 23 20:12:20 Largo ceph-osd[58404]: 2018-06-23 20:12:20.022 7fdb54cc2280 -1 Public network was set, but cluster network was not set Jun 23 20:12:20 Largo ceph-osd[58404]: 2018-06-23 20:12:20.022 7fdb54cc2280 -1 Using public network also for cluster network Jun 23 20:12:20 Largo ceph-osd[58404]: starting osd.0 at - osd_data /var/lib/ceph/osd/ceph-0 /var/lib/ceph/osd/ceph-0/journal Jun 23 20:12:20 Largo ceph-osd[58404]: *** Caught signal (Segmentation fault) ** Jun 23 20:12:20 Largo ceph-osd[58404]: in thread 7fdb54cc2280 thread_name:ceph-osd Jun 23 20:12:20 Largo ceph-osd[58404]: ceph version 13.2.0 (79a10589f1f80dfe21e8f9794365ed98143071c4) mimic (stable) Jun 23 20:12:20 Largo ceph-osd[58404]: 1: (()+0x915140) [0x55ed327c7140] Jun 23 20:12:20 Largo ceph-osd[58404]: 2: (()+0x12890) [0x7fdb4a5dc890] Jun 23 20:12:20 Largo ceph-osd[58404]: 3: (BlueFS::_read(BlueFS::FileReader*, BlueFS::FileReaderBuffer*, unsigned long, unsigned long, ceph::buffer::list*, char*)+0x367) [ Jun 23 20:12:20 Largo ceph-osd[58404]: 4: (BlueFS::_replay(bool, bool)+0x214) [0x55ed3277c654] Jun 23 20:12:20 Largo ceph-osd[58404]: 5: (BlueFS::mount()+0x1f1) [0x55ed32780ea1] Jun 23 20:12:20 Largo ceph-osd[58404]: 6: (BlueStore::_open_db(bool, bool)+0x1840) [0x55ed326abae0] Jun 23 20:12:20 Largo ceph-osd[58404]: 7: (BlueStore::_mount(bool, bool)+0x4b7) [0x55ed326db407] Jun 23 20:12:20 Largo ceph-osd[58404]: 8: (OSD::init()+0x295) [0x55ed32286305] Jun 23 20:12:20 Largo ceph-osd[58404]: 9: (main()+0x268d) [0x55ed3217507d] Jun 23 20:12:20 Largo ceph-osd[58404]: 10: (__libc_start_main()+0xe7) [0x7fdb49495b97] Jun 23 20:12:20 Largo ceph-osd[58404]: 11: (_start()+0x2a) [0x55ed3223d38a] Jun 23 20:12:20 Largo ceph-osd[58404]: 2018-06-23 20:12:20.318 7fdb54cc2280 -1 *** Caught signal (Segmentation fault) ** Jun 23 20:12:20 Largo ceph-osd[58404]: in thread 7fdb54cc2280 thread_name:ceph-osd Jun 23 20:12:20 Largo ceph-osd[58404]: ceph version 13.2.0 (79a10589f1f80dfe21e8f9794365ed98143071c4) mimic (stable) Jun 23 20:12:20 Largo ceph-osd[58404]: 1: (()+0x915140) [0x55ed327c7140] Jun 23 20:12:20 Largo ceph-osd[58404]: 2: (()+0x12890) [0x7fdb4a5dc890] Jun 23 20:12:20 Largo ceph-osd[58404]: 3: (BlueFS::_read(BlueFS::FileReader*, BlueFS::FileReaderBuffer*, unsigned long, unsigned long, ceph::buffer::list*, char*)+0x367) [ Jun 23 20:12:20 Largo ceph-osd[58404]: 4: (BlueFS::_replay(bool, bool)+0x214) [0x55ed3277c654] Jun 23 20:12:20 Largo ceph-osd[58404]: 5: (BlueFS::mount()+0x1f1) [0x55ed32780ea1] Jun 23 20:12:20 Largo ceph-osd[58404]: 6: (BlueStore::_open_db(bool, bool)+0x1840) [0x55ed326abae0] Jun 23 20:12:20 Largo ceph-osd[58404]: 7: (BlueStore::_mount(bool, bool)+0x4b7) [0x55ed326db407] Jun 23 20:12:20 Largo ceph-osd[58404]: 8: (OSD::init()+0x295) [0x55ed32286305] Jun 23 20:12:20 Largo ceph-osd[58404]: 9: (main()+0x268d) [0x55ed3217507d] Jun 23 20:12:20 Largo ceph-osd[58404]: 10: (__libc_start_main()+0xe7) [0x7fdb49495b97] Jun 23 20:12:20 Largo ceph-osd[58404]: 11: (_start()+0x2a) [0x55ed3223d38a] Jun 23 20:12:20 Largo ceph-osd[58404]: NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this. Jun 23 20:12:20 Largo ceph-osd[58404]: -39> 2018-06-23 20:12:20.022 7fdb54cc2280 -1 Public network was set, but cluster network was not set Jun 23 20:12:20 Largo ceph-osd[58404]: -38> 2018-06-23 20:12:20.022 7fdb54cc2280 -1 Using public network also for cluster network Jun 23 20:12:20 Largo ceph-osd[58404]: 0> 2018-06-23 20:12:20.318 7fdb54cc2280 -1 *** Caught signal (Segmentation fault) ** Jun 23 20:12:20 Largo ceph-osd[58404]: in thread 7fdb54cc2280 thread_name:ceph-osd Jun 23 20:12:20 Largo ceph-osd[58404]: ceph version 13.2.0 (79a10589f1f80dfe21e8f9794365ed98143071c4) mimic (stable) Jun 23 20:12:20 Largo ceph-osd[58404]: 1: (()+0x915140) [0x55ed327c7140] Jun 23 20:12:20 Largo ceph-osd[58404]: 2: (()+0x12890) [0x7fdb4a5dc890] Jun 23 20:12:20 Largo ceph-osd[58404]: 3: (BlueFS::_read(BlueFS::FileReader*, BlueFS::FileReaderBuffer*, unsigned long, unsigned long, ceph::buffer::list*, char*)+0x367) [ Jun 23 20:12:20 Largo ceph-osd[58404]: 4: (BlueFS::_replay(bool, bool)+0x214) [0x55ed3277c654] Jun 23 20:12:20 Largo ceph-osd[58404]: 5: (BlueFS::mount()+0x1f1) [0x55ed32780ea1] Jun 23 20:12:20 Largo ceph-osd[58404]: 6: (BlueStore::_open_db(bool, bool)+0x1840) [0x55ed326abae0] Jun 23 20:12:20 Largo ceph-osd[58404]: 7: (BlueStore::_mount(bool, bool)+0x4b7) [0x55ed326db407] Jun 23 20:12:20 Largo ceph-osd[58404]: 8: (OSD::init()+0x295) [0x55ed32286305] Jun 23 20:12:20 Largo ceph-osd[58404]: 9: (main()+0x268d) [0x55ed3217507d] Jun 23 20:12:20 Largo ceph-osd[58404]: 10: (__libc_start_main()+0xe7) [0x7fdb49495b97] Jun 23 20:12:20 Largo ceph-osd[58404]: 11: (_start()+0x2a) [0x55ed3223d38a] Jun 23 20:12:20 Largo ceph-osd[58404]: NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this. Jun 23 20:12:20 Largo systemd[1]: ceph-osd@0.service: Main process exited, code=dumped, status=11/SEGV Jun 23 20:12:20 Largo systemd[1]: ceph-osd@0.service: Failed with result 'core-dump'.
Starting program: /usr/bin/ceph-bluestore-tool fsck --path /var/lib/ceph/osd/ceph-0 --no-mon-config
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
[New Thread 0x7fffea952700 (LWP 62958)]
[New Thread 0x7fffe997a700 (LWP 62959)]
[New Thread 0x7fffe9179700 (LWP 62960)]
[New Thread 0x7fffe8978700 (LWP 62961)]
[New Thread 0x7fffe8177700 (LWP 62962)]
[New Thread 0x7fffe7976700 (LWP 62963)]
Thread 1 "ceph-bluestore-" hit Breakpoint 1, BlueFS::_read (this=this@entry=0x55555688c600, h=h@entry=0x555556862e80, buf=buf@entry=0x555556862e88, off=0,
len=<optimised out>, outbl=outbl@entry=0x7fffffffaf10, out=0x0) at ./src/os/bluestore/BlueFS.cc:1097
1097 in ./src/os/bluestore/BlueFS.cc
(gdb) bt
#0 BlueFS::_read (this=this@entry=0x55555688c600, h=h@entry=0x555556862e80, buf=buf@entry=0x555556862e88, off=0, len=<optimised out>, outbl=outbl@entry=0x7fffffffaf10,
out=0x0) at ./src/os/bluestore/BlueFS.cc:1097
#1 0x00005555557a99c4 in BlueFS::_replay (this=this@entry=0x55555688c600, noop=noop@entry=false, to_stdout=to_stdout@entry=false) at ./src/os/bluestore/BlueFS.cc:596
#2 0x00005555557ae211 in BlueFS::mount (this=0x55555688c600) at ./src/os/bluestore/BlueFS.cc:440
#3 0x0000555555812400 in BlueStore::_open_db (this=this@entry=0x7fffffffc680, create=create@entry=false, to_repair_db=to_repair_db@entry=false)
at ./src/os/bluestore/BlueStore.cc:4845
#4 0x0000555555836c71 in BlueStore::_fsck (this=0x7fffffffc680, deep=false, repair=<optimised out>) at ./src/os/bluestore/BlueStore.cc:5867
#5 0x00005555556ccd57 in BlueStore::fsck (deep=<optimised out>, this=0x7fffffffc680) at ./src/os/bluestore/BlueStore.h:2171
#6 main (argc=<optimised out>, argv=<optimised out>) at ./src/os/bluestore/bluestore_tool.cc:306
(gdb) s
Thread 1 "ceph-bluestore-" received signal SIGSEGV, Segmentation fault.
BlueFS::_read (this=this@entry=0x55555688c600, h=h@entry=0x555556862e80, buf=buf@entry=0x555556862e88, off=0, len=<optimised out>, outbl=outbl@entry=0x7fffffffaf10,
out=0x0) at ./src/os/bluestore/BlueFS.cc:1097
1097 in ./src/os/bluestore/BlueFS.cc
(gdb)
Files
Updated by Rowan James almost 6 years ago
I'm about to see if I can get a debug build reproducing it; but in the meantime I'm pretty sure this is the line:
The local variables immediately before the crash:
(gdb) info locals want = <optimised out> eof_offset = <optimised out> x_off = 0 p = non-dereferenceable iterator for std::vector l = <optimised out> r = <optimised out> left = <optimised out> r = <optimised out> __func__ = "_read" ret = 0 __PRETTY_FUNCTION__ = <optimised out>
Updated by Igor Fedotov almost 6 years ago
Rowan,
do you remember what were BlueFS volume sizes for that breaking OSDs?
Actions
#3
Updated by Compile Nix over 5 years ago
- File ceph-osd-7fd70dd8de00.log ceph-osd-7fd70dd8de00.log added
- File ceph-bluestore-tool-7fb75ca61e00.log ceph-bluestore-tool-7fb75ca61e00.log added
I think i have the exact same problem with one of my OSD's, which were created with ceph-deploy on Ceph v12.2.7 and fails to start within 7 days since creation. Currently it's the only OSD which this problem.
Sep 07 03:20:44 pve6 ceph-osd[2096257]: /mnt/npool/a.antreich/ceph/ceph-12.2.7/src/os/bluestore/BlueFS.cc: In function 'int BlueFS::_read(BlueFS::FileReader*, BlueFS::FileReaderBuffer*, uint64_t, size_t, ceph::bufferlist*, char*)' thread 7fd70dd8de00 time 2018-09-07 03:20:44.927338 Sep 07 03:20:44 pve6 ceph-osd[2096257]: /mnt/npool/a.antreich/ceph/ceph-12.2.7/src/os/bluestore/BlueFS.cc: 976: FAILED assert(r == 0) Sep 07 03:20:44 pve6 ceph-osd[2096257]: ceph version 12.2.7 (94ce186ac93bb28c3c444bccfefb8a31eb0748e4) luminous (stable) Sep 07 03:20:44 pve6 ceph-osd[2096257]: 1: (ceph::__ceph_assert_fail(char const*, char const*, int, char const*)+0x102) [0x55e4bb876282] Sep 07 03:20:44 pve6 ceph-osd[2096257]: 2: (BlueFS::_read(BlueFS::FileReader*, BlueFS::FileReaderBuffer*, unsigned long, unsigned long, ceph::buffer::list*, char*)+0xf7a) [0x55e4bb7dd50a] Sep 07 03:20:44 pve6 ceph-osd[2096257]: 3: (BlueRocksSequentialFile::Read(unsigned long, rocksdb::Slice*, char*)+0x34) [0x55e4bb803664] Sep 07 03:20:44 pve6 ceph-osd[2096257]: 4: (rocksdb::SequentialFileReader::Read(unsigned long, rocksdb::Slice*, char*)+0x70) [0x55e4bbc51b00] Sep 07 03:20:44 pve6 ceph-osd[2096257]: 5: (rocksdb::log::Reader::ReadMore(unsigned long*, int*)+0xe0) [0x55e4bbbae9c0] Sep 07 03:20:44 pve6 ceph-osd[2096257]: 6: (rocksdb::log::Reader::ReadPhysicalRecord(rocksdb::Slice*, unsigned long*)+0x44) [0x55e4bbbaea94] Sep 07 03:20:44 pve6 ceph-osd[2096257]: 7: (rocksdb::log::Reader::ReadRecord(rocksdb::Slice*, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >*, rocksdb::WALRecoveryMode)+0xda) [0x55e4bbbaed5a] Sep 07 03:20:44 pve6 ceph-osd[2096257]: 8: (rocksdb::DBImpl::RecoverLogFiles(std::vector<unsigned long, std::allocator<unsigned long> > const&, unsigned long*, bool)+0x141d) [0x55e4bbba056d] Sep 07 03:20:44 pve6 ceph-osd[2096257]: 9: (rocksdb::DBImpl::Recover(std::vector<rocksdb::ColumnFamilyDescriptor, std::allocator<rocksdb::ColumnFamilyDescriptor> > const&, bool, bool, bool)+0x8c4) [0x55e4bbba1ec4] Sep 07 03:20:44 pve6 ceph-osd[2096257]: 10: (rocksdb::DB::Open(rocksdb::DBOptions const&, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, std::vector<rocksdb::ColumnFamilyDescriptor, std::allocator<rocksdb::ColumnFamilyDescriptor> > const&, std::vector<rocksdb::ColumnFamilyHandle*, std::allocator<rocksdb::ColumnFamilyHandle*> >*, rocksdb::DB**)+0xedf) [0x55e4bbba328f] Sep 07 03:20:44 pve6 ceph-osd[2096257]: 11: (rocksdb::DB::Open(rocksdb::Options const&, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, rocksdb::DB**)+0x6a7) [0x55e4bbba4ae7] Sep 07 03:20:44 pve6 ceph-osd[2096257]: 12: (RocksDBStore::do_open(std::ostream&, bool)+0x908) [0x55e4bb76dce8] Sep 07 03:20:44 pve6 ceph-osd[2096257]: 13: (BlueStore::_open_db(bool)+0xbeb) [0x55e4bb6f6abb] Sep 07 03:20:44 pve6 ceph-osd[2096257]: 14: (BlueStore::_mount(bool)+0x2b4) [0x55e4bb730434] Sep 07 03:20:44 pve6 ceph-osd[2096257]: 15: (OSD::init()+0x3e2) [0x55e4bb28b762] Sep 07 03:20:44 pve6 ceph-osd[2096257]: 16: (main()+0x308f) [0x55e4bb196e8f] Sep 07 03:20:44 pve6 ceph-osd[2096257]: 17: (__libc_start_main()+0xf1) [0x7fd70a3482e1] Sep 07 03:20:44 pve6 ceph-osd[2096257]: 18: (_start()+0x2a) [0x55e4bb221a9a] Sep 07 03:20:44 pve6 ceph-osd[2096257]: NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this.
The full log is attached as ceph-osd-7fd70dd8de00.log
# ceph-bluestore-tool fsck --path /var/lib/ceph/osd/ceph-20
/mnt/npool/a.antreich/ceph/ceph-12.2.7/src/os/bluestore/BlueFS.cc: In function 'int BlueFS::_read(BlueFS::FileReader*, BlueFS::FileReaderBuffer*, uint64_t, size_t, ceph::bufferlist*, char*)' thread 7fb75ca61e00 time 2018-09-07 03:29:26.294513
/mnt/npool/a.antreich/ceph/ceph-12.2.7/src/os/bluestore/BlueFS.cc: 976: FAILED assert(r == 0)
ceph version 12.2.7 (94ce186ac93bb28c3c444bccfefb8a31eb0748e4) luminous (stable)
1: (ceph::__ceph_assert_fail(char const*, char const*, int, char const*)+0x102) [0x7fb75309ba82]
2: (BlueFS::_read(BlueFS::FileReader*, BlueFS::FileReaderBuffer*, unsigned long, unsigned long, ceph::buffer::list*, char*)+0xf7a) [0x5562b87f06ea]
3: (BlueRocksSequentialFile::Read(unsigned long, rocksdb::Slice*, char*)+0x34) [0x5562b89dc8e4]
4: (rocksdb::SequentialFileReader::Read(unsigned long, rocksdb::Slice*, char*)+0x70) [0x5562b8b05e70]
5: (rocksdb::log::Reader::ReadMore(unsigned long*, int*)+0xe0) [0x5562b8a61e20]
6: (rocksdb::log::Reader::ReadPhysicalRecord(rocksdb::Slice*, unsigned long*)+0x44) [0x5562b8a61ef4]
7: (rocksdb::log::Reader::ReadRecord(rocksdb::Slice*, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >*, rocksdb::WALRecoveryMode)+0xda) [0x5562b8a621ba]
8: (rocksdb::DBImpl::RecoverLogFiles(std::vector<unsigned long, std::allocator<unsigned long> > const&, unsigned long*, bool)+0x141d) [0x5562b8a5381d]
9: (rocksdb::DBImpl::Recover(std::vector<rocksdb::ColumnFamilyDescriptor, std::allocator<rocksdb::ColumnFamilyDescriptor> > const&, bool, bool, bool)+0x8c4) [0x5562b8a55174]
10: (rocksdb::DB::Open(rocksdb::DBOptions const&, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, std::vector<rocksdb::ColumnFamilyDescriptor, std::allocator<rocksdb::ColumnFamilyDescriptor> > const&, std::vector<rocksdb::ColumnFamilyHandle*, std::allocator<rocksdb::ColumnFamilyHandle*> >*, rocksdb::DB**)+0xedf) [0x5562b8a5653f]
11: (rocksdb::DB::Open(rocksdb::Options const&, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, rocksdb::DB**)+0x6a7) [0x5562b8a57d97]
12: (RocksDBStore::do_open(std::ostream&, bool)+0x908) [0x5562b88daba8]
13: (BlueStore::_open_db(bool)+0xbeb) [0x5562b8867bcb]
14: (BlueStore::_fsck(bool, bool)+0x41a) [0x5562b8898f8a]
15: (main()+0xf9e) [0x5562b875df5e]
16: (__libc_start_main()+0xf1) [0x7fb7502eb2e1]
17: (_start()+0x2a) [0x5562b87df6fa]
NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this.
2018-09-07 03:29:26.297842 7fb75ca61e00 -1 /mnt/npool/a.antreich/ceph/ceph-12.2.7/src/os/bluestore/BlueFS.cc: In function 'int BlueFS::_read(BlueFS::FileReader*, BlueFS::FileReaderBuffer*, uint64_t, size_t, ceph::bufferlist*, char*)' thread 7fb75ca61e00 time 2018-09-07 03:29:26.294513
/mnt/npool/a.antreich/ceph/ceph-12.2.7/src/os/bluestore/BlueFS.cc: 976: FAILED assert(r == 0)
0> 2018-09-07 03:29:26.299884 7fb75ca61e00 -1 *** Caught signal (Aborted) **
[1] 2125848 abort ceph-bluestore-tool fsck --path /var/lib/ceph/osd/ceph-20
The full log is attached as ceph-bluestore-tool-7fb75ca61e00.log
Updated by Sage Weil over 5 years ago
- Status changed from New to Need More Info
can you do ceph-bluestore-tool fsck --path ... --log-file log --log-level 20 and attach the output?
Updated by Compile Nix over 5 years ago
I don't have the osd and disk anymore and can confirm that the disk itself was in a terrible state (many hardware related errors via S.M.A.R.T), so i replaced it with a new one.
I didn't run into this problem, since the replacement.
Updated by Sage Weil about 5 years ago
- Status changed from Need More Info to Can't reproduce
sounds like a hardware problem then!
Updated by Igor Fedotov almost 4 years ago
- Related to Bug #45519: OSD asserts during block allocation for BlueFS added
Actions