Project

General

Profile

Actions

Bug #455

closed

OSD::_create_lock_pg

Added by Wido den Hollander over 13 years ago. Updated over 13 years ago.

Status:
Resolved
Priority:
Normal
Assignee:
-
Category:
OSD
Target version:
-
% Done:

0%

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

Description

This morning I upgraded to the latest unstable ( 0b7c1afc43202953123f335057b9a5da428bc9a2 ), but when doing so, 10 of my 12 OSD's crashed with the following back trace:

Core was generated by `/usr/bin/cosd -i 2 -c /etc/ceph/ceph.conf'.
Program terminated with signal 6, Aborted.
#0  0x00007f9f117b0a75 in raise () from /lib/libc.so.6
(gdb) bt
#0  0x00007f9f117b0a75 in raise () from /lib/libc.so.6
#1  0x00007f9f117b45c0 in abort () from /lib/libc.so.6
#2  0x00007f9f120668e5 in __gnu_cxx::__verbose_terminate_handler() () from /usr/lib/libstdc++.so.6
#3  0x00007f9f12064d16 in ?? () from /usr/lib/libstdc++.so.6
#4  0x00007f9f12064d43 in std::terminate() () from /usr/lib/libstdc++.so.6
#5  0x00007f9f12064e3e in __cxa_throw () from /usr/lib/libstdc++.so.6
#6  0x00000000005c6ba8 in ceph::__ceph_assert_fail (assertion=0x5f7d98 "!store->collection_exists(coll_t(pgid))", 
    file=<value optimized out>, line=902, func=<value optimized out>) at common/assert.cc:30
#7  0x00000000004dd01d in OSD::_create_lock_pg (this=0x1c9f000, pgid=DWARF-2 expression error: DW_OP_reg operations must be used either alone or in conjuction with DW_OP_piece.
) at osd/OSD.cc:902
#8  0x00000000004f3ebb in OSD::handle_pg_notify (this=0x1c9f000, m=<value optimized out>) at osd/OSD.cc:3547
#9  0x00000000004f483d in OSD::_dispatch (this=0x1c9f000, m=0x1cb4c40) at osd/OSD.cc:2127
#10 0x00000000004f5129 in OSD::ms_dispatch (this=0x1c9f000, m=0x1cb4c40) at osd/OSD.cc:1956
#11 0x0000000000460af9 in Messenger::ms_deliver_dispatch (this=0x1c9d000) at msg/Messenger.h:97
#12 SimpleMessenger::dispatch_entry (this=0x1c9d000) at msg/SimpleMessenger.cc:342
#13 0x000000000045a37c in SimpleMessenger::DispatchThread::entry (this=0x1c9d488) at msg/SimpleMessenger.h:558
#14 0x000000000046e85a in Thread::_entry_func (arg=0x6bb7) at ./common/Thread.h:39
#15 0x00007f9f128ab9ca in start_thread () from /lib/libpthread.so.0
#16 0x00007f9f118636fd in clone () from /lib/libc.so.6
#17 0x0000000000000000 in ?? ()

I've uploaded the logs, cores and binaries to logger.ceph.widodh.nl:/srv/ceph/issues/osd_crash_create_lock_pg

The timestamps were all preserved, so they should match the log files.

After starting all the OSD's manually (with some pauze in between) they started to run, but the cluster wouldn't recover:

2010-10-02 10:42:01.477025    pg v339914: 3296 pgs: 3 creating, 101 active+clean, 168 peering, 2788 active+clean+degraded, 236 degraded+peering; 1442 GB data, 593 GB used, 1584 GB / 2178 GB avail; 1511545/3227908 degraded (46.827%)
2010-10-02 10:42:03.486299    pg v339915: 3296 pgs: 1 creating, 103 active+clean, 168 peering, 2788 active+clean+degraded, 236 degraded+peering; 1442 GB data, 1130 GB used, 3022 GB / 4153 GB avail; 1511545/3227908 degraded (46.827%)
2010-10-02 10:42:24.247506   osd e17614: 12 osds: 12 up, 12 in
2010-10-02 10:42:24.544186    pg v339916: 3295 pgs: 103 active+clean, 168 peering, 2788 active+clean+degraded, 236 degraded+peering; 1442 GB data, 1130 GB used, 3022 GB / 4153 GB avail; 1511545/3227908 degraded (46.827%)
2010-10-02 10:42:47.117378   log 2010-10-02 10:41:45.737347 mon0 [2001:16f8:10:2::c3c3:3f9b]:6789/0 67 : [INF] osd0 [2001:16f8:10:2::c3c3:8f6b]:6800/4074 failed (by osd6 [2001:16f8:10:2::c3c3:3f6c]:6800/7925)
2010-10-02 10:42:47.117378   log 2010-10-02 10:41:45.737500 mon0 [2001:16f8:10:2::c3c3:3f9b]:6789/0 68 : [INF] osd5 [2001:16f8:10:2::c3c3:3b6a]:6800/5449 failed (by osd6 [2001:16f8:10:2::c3c3:3f6c]:6800/7925)
2010-10-02 10:42:52.280467   log 2010-10-02 10:41:50.738303 mon0 [2001:16f8:10:2::c3c3:3f9b]:6789/0 69 : [INF] osd0 [2001:16f8:10:2::c3c3:8f6b]:6800/4074 failed (by osd6 [2001:16f8:10:2::c3c3:3f6c]:6800/7925)
2010-10-02 10:42:52.280467   log 2010-10-02 10:41:50.738477 mon0 [2001:16f8:10:2::c3c3:3f9b]:6789/0 70 : [INF] osd5 [2001:16f8:10:2::c3c3:3b6a]:6800/5449 failed (by osd6 [2001:16f8:10:2::c3c3:3f6c]:6800/7925)
2010-10-02 10:42:57.403565   osd e17615: 12 osds: 10 up, 12 in
2010-10-02 10:42:57.530072   log 2010-10-02 10:41:56.000109 mon0 [2001:16f8:10:2::c3c3:3f9b]:6789/0 71 : [INF] osd0 [2001:16f8:10:2::c3c3:8f6b]:6800/4074 failed (by osd6 [2001:16f8:10:2::c3c3:3f6c]:6800/7925)
2010-10-02 10:42:57.530072   log 2010-10-02 10:41:56.000275 mon0 [2001:16f8:10:2::c3c3:3f9b]:6789/0 72 : [INF] osd5 [2001:16f8:10:2::c3c3:3b6a]:6800/5449 failed (by osd6 [2001:16f8:10:2::c3c3:3f6c]:6800/7925)
2010-10-02 10:42:57.782387    pg v339917: 3295 pgs: 103 active+clean, 168 peering, 2788 active+clean+degraded, 236 degraded+peering; 1442 GB data, 1130 GB used, 3022 GB / 4153 GB avail; 1511545/3227908 degraded (46.827%)
2010-10-02 10:42:58.930449   osd e17616: 12 osds: 12 up, 12 in
2010-10-02 10:42:59.405541    pg v339918: 3295 pgs: 103 active+clean, 168 peering, 2788 active+clean+degraded, 236 degraded+peering; 1442 GB data, 1130 GB used, 3022 GB / 4153 GB avail; 1511545/3227908 degraded (46.827%)
2010-10-02 10:42:59.547091   log 2010-10-02 10:40:49.769174 osd5 [2001:16f8:10:2::c3c3:3b6a]:6800/5449 1 : [WRN] map e17615 wrongly marked me down
2010-10-02 10:42:59.547091   log 2010-10-02 10:40:49.784113 osd0 [2001:16f8:10:2::c3c3:8f6b]:6800/4074 1 : [WRN] map e17615 wrongly marked me down
2010-10-02 10:42:59.547091   log 2010-10-02 10:41:58.732677 mon0 [2001:16f8:10:2::c3c3:3f9b]:6789/0 73 : [INF] osd0 [2001:16f8:10:2::c3c3:8f6b]:6800/4074 boot
2010-10-02 10:42:59.547091   log 2010-10-02 10:41:58.732780 mon0 [2001:16f8:10:2::c3c3:3f9b]:6789/0 74 : [INF] osd5 [2001:16f8:10:2::c3c3:3b6a]:6800/5449 boot

My cluster has a total of 6300GB with all 12 OSD's up, but here it stays stuck at 4100GB, missing 2200GB of space.

Also, osd0 and osd5 (which got marked down) were never down after I started them.

A few minutes later osd8 also got marked down (wrongly).

These OSD's weren't busy at all, their load was 0.00 at that moment, so it can't be because they were responding too slow.

Doing a write to the cluster (for example creating a pool) gave it a small "kick" where it would start to recover a bit more, but it won't recover fully.

Am I in a situation because of my cluster which is already running for a long time and new users will never get into this situation? Would a fresh mkcephfs be a bit easier?

Actions #1

Updated by Wido den Hollander over 13 years ago

A bit later, osd11 crashed with the same backtrace.

I manually marked it "out", but that wouldn't trigger a recovery either, the cluster stays at:

2010-10-02 11:06:01.150119    pg v339997: 3327 pgs: 129 active+clean, 168 peering, 2794 active+clean+degraded, 236 degraded+peering; 1442 GB data, 1076 GB used, 2882 GB / 3959 GB avail; 1511545/3227908 degraded (46.827%)

With all the 12 OSD's up.

Actions #2

Updated by Wido den Hollander over 13 years ago

I just checked (haven't check the cluster state for about a day and a half) and then found that osd11 crashed again with the same backtrace.

Actions #3

Updated by Sage Weil over 13 years ago

  • Status changed from New to Resolved
Actions

Also available in: Atom PDF