Project

General

Profile

Actions

Bug #6684

closed

osd/PGLog.cc: 402: FAILED assert(log.head >= olog.tail && olog.head >= log.tail)

Added by Ivan Kudryavtsev over 10 years ago. Updated about 10 years ago.

Status:
Rejected
Priority:
Normal
Assignee:
-
Category:
-
Target version:
-
% Done:

0%

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

Description

Hello, Guys, I'm in a big trouble. After upgrading Bobtail to cuttlefish I met in a
great troubles, unable to make cluster work for 18 hours already, so I really need your help.

My OSDs are crushing and not starting. Log of one of them is attached. upgraded node where it to dumpling, all
mons are dumpling, all osds except it are bobtail.


Files

ceph-osd.39.log.bz2 (221 KB) ceph-osd.39.log.bz2 Ivan Kudryavtsev, 10/30/2013 06:25 AM
ceph-osd.39.log.bz2 (6.79 MB) ceph-osd.39.log.bz2 Ivan Kudryavtsev, 10/30/2013 10:17 AM
logs.tbz2 (17.2 MB) logs.tbz2 Ivan Kudryavtsev, 10/31/2013 10:14 AM
Actions #1

Updated by Ivan Kudryavtsev over 10 years ago

Also it seems, that my meta information is corrupted, I have a lot of images in RBD and now, I don't see any:

rbd: pool rbd doesn't contain rbd images

Ceph -s:

root@ceph-mon-mds-0:~# ceph -s
cluster e74c9e0b-40ce-45e4-904a-676cbaaf042d
health HEALTH_WARN 910 pgs backfill; 106 pgs backfilling; 1012 pgs degraded; 19 pgs down; 83 pgs incomplete; 32 pgs peering; 1 pgs recovery_wait; 28 pgs stale; 115 pgs stuck inactive; 28 pgs stuck stale; 1132 pgs stuck unclean; 10 requests are blocked > 32 sec; recovery 5234340/9695952 degraded (53.985%); recovering 40 o/s, 116MB/s; mds cluster is degraded; clock skew detected on mon.0, mon.1
monmap e1: 3 mons at {0=10.252.0.3:6789/0,1=10.252.0.4:6789/0,2=10.252.0.2:6789/0}, election epoch 5486, quorum 0,1,2 0,1,2
osdmap e51526: 48 osds: 41 up, 41 in
pgmap v22251590: 1344 pgs: 212 active+clean, 5 active+remapped+wait_backfill, 194 active+degraded+wait_backfill, 13 down+peering, 13 stale+peering, 5 active+degraded+backfilling, 711 active+degraded+remapped+wait_backfill, 6 stale+down+peering, 74 incomplete, 101 active+degraded+remapped+backfilling, 9 stale+incomplete, 1 active+recovery_wait+degraded+remapped; 6883 GB data, 9043 GB used, 36941 GB / 46031 GB avail; 5234340/9695952 degraded (53.985%); recovering 40 o/s, 116MB/s
mdsmap e564: 1/1/1 up {0=2=up:replay}, 2 up:standby

Actions #2

Updated by Ivan Kudryavtsev over 10 years ago

During recovery some osds crashing and after crash unable to up again, looks like in topic "Domino crash" regarding osd behavior.

Actions #3

Updated by Sage Weil over 10 years ago

  • Subject changed from Sorry, it's very urgent. OSD is not started. Log attached. to osd/PGLog.cc: 402: FAILED assert(log.head >= olog.tail && olog.head >= log.tail)

Can you set 'debug osd = 20' and 'debug ms = 1', and restart and osd so that we have a complete log leading up to the crash?

Actions #4

Updated by Ivan Kudryavtsev over 10 years ago

Here it is.

Actions #5

Updated by Ivan Kudryavtsev over 10 years ago

It's on dumpling node.

root@ceph-osd-1-2:/# ceph -v
ceph version 0.67.4 (ad85b8bfafea6232d64cb7ba76a8b6e8252fa0c7)

Actions #6

Updated by Sage Weil over 10 years ago

can you turn up the logs on osd.42 too, and then restart this same osd (to reproduce the same crash), and then attach both logs (osd.39 and osd.42)?

Actions #7

Updated by Ivan Kudryavtsev over 10 years ago

Here it is, attached.

Actions #8

Updated by Ivan Kudryavtsev over 10 years ago

I also have

2013-11-01 00:13:25.635829 mon.0 [WRN] mon.2 10.252.0.4:6789/0 clock skew 0.870987s > max 0.05s
2013-11-01 00:13:25.636643 mon.0 [WRN] mon.1 10.252.0.3:6789/0 clock skew 0.575035s > max 0.05s

warnings, but already did ntpdate-debian on all mon nodes, but not restarted mons. Should I?

Actions #9

Updated by Sage Weil over 10 years ago

Ivan Kudryavtsev wrote:

I also have

2013-11-01 00:13:25.635829 mon.0 [WRN] mon.2 10.252.0.4:6789/0 clock skew 0.870987s > max 0.05s
2013-11-01 00:13:25.636643 mon.0 [WRN] mon.1 10.252.0.3:6789/0 clock skew 0.575035s > max 0.05s

warnings, but already did ntpdate-debian on all mon nodes, but not restarted mons. Should I?

those warnigns should stop as soon as the clocks are in sync.. if you still see them rerun ntpdate.

not related to the osd problem.

Actions #10

Updated by Sage Weil over 10 years ago

2013-10-31 00:12:19.028961 7ffae583c700 10 osd.39 pg_epoch: 51814 pg[2.1c( v 49563'1841509 (46592'1839920,49563'1841509] lb 19b4001c/rb.0.dcd4f.238e1f29.000000043779/head//2 local-les=49344 n=18 ec=1 les/c 51746/51747 51811/51813/51329) [42,39,6]/[42,39,6,37] r=1 lpr=51813 pi=47601-51812/86 lcod 0'0 remapped NOTIFY] handle_peering_event: epoch_sent: 51814 epoch_requested: 51814 MLogRec from 42
2013-10-31 00:12:19.029020 7ffae583c700 10 osd.39 pg_epoch: 51814 pg[2.1c( v 49563'1841509 (46592'1839920,49563'1841509] lb 19b4001c/rb.0.dcd4f.238e1f29.000000043779/head//2 local-les=49344 n=18 ec=1 les/c 51746/51747 51811/51813/51329) [42,39,6]/[42,39,6,37] r=1 lpr=51813 pi=47601-51812/86 lcod 0'0 remapped NOTIFY] state<Started/Stray>: got info+log from osd.42 2.1c( empty local-les=51814 n=0 ec=1 les/c 51746/51747 51811/51813/51329) log(0'0,0'0]

Actions #11

Updated by Ivan Kudryavtsev over 10 years ago

Any chance I can start these OSD without losing data on them?

Actions #12

Updated by Sage Weil over 10 years ago

oh, looking more closely, it looks like osd.42 is trying to activate but has no data for this pg. is it possible you've done any shenanigans like 'ceph pg force_create_pg ...' at some point in the past?

try just stopping osd.42 and starting osd.39 in its stead, that might get around it, at least for this particular pg. :/

Actions #13

Updated by Ivan Kudryavtsev over 10 years ago

is it possible you've done any shenanigans like 'ceph pg force_create_pg ...' at some point in the past?

Yes, indeed. It sesms that I have another pgs like that how could I discover them. Stopping 42 and starting 39 didn't help, probably another pgs like this.

Actions #14

Updated by Sage Weil over 10 years ago

Ivan Kudryavtsev wrote:

is it possible you've done any shenanigans like 'ceph pg force_create_pg ...' at some point in the past?

Yes, indeed. It sesms that I have another pgs like that how could I discover them. Stopping 42 and starting 39 didn't help, probably another pgs like this.

:( i think that is the source of the problem. force_create_pg should never be used unless you really know what you are doing.

i think the way to repair this is to identify each pg that is preventing the osds from starting, looking at every osd that has a copy, and on those osds where the data directory (/var/lib/ceph/osd/ceph-*/current/$pgid_head), stop the osd, and then use the ceph_filestore_dump utility to export the empty pg (just in case!) and then remove it. once all the empty versions of the pg are removed and only the ones with data exist, the cluster will stop being confused and start. i suspect it will take several iterations of doing this, though. if you know which pgs in the past you did force_create_pg on, that will help (it should be the same pgs that are causing problems now).

Actions #15

Updated by Samuel Just about 10 years ago

  • Status changed from New to Rejected
Actions

Also available in: Atom PDF