Hi all,
I have a ceph cluster with 8 nodes with 3 osds in each node, and 3 monitors.
While Client IO and recovery IO was going on, removed one of the osd due to
some reasons.
Osd crashed with assert :
1: (OSD::shutdown()+0x176f) [0x61e94f]
2: (OSD::handle_signal(int)+0x60) [0x61f210]
3: (SignalHandler::entry()+0x19f) [0x97584f]
4: (()+0x8182) [0x7fa9836b2182]
5: (clone()+0x6d) [0x7fa981a5330d]
pg 4.53 has refcount more than 0, resulted in this assertion failure.
int OSD::shutdown()
{
if (!service.prepare_to_stop())
return 0; // already shutting down
osd_lock.Lock();
if (is_stopping()) {
osd_lock.Unlock();
return 0;
}
derr << "shutdown" << dendl;
set_state(STATE_STOPPING);
....
// Shutdown PGs
{
RWLock::RLocker l(pg_map_lock);
for (ceph::unordered_map<spg_t, PG*>::iterator p = pg_map.begin();
p != pg_map.end();
++p) {
dout(20) << " kicking pg " << p->first << dendl;
p->second->lock();
p->second->on_shutdown();
p->second->unlock();
p->second->osr->flush();
}
}
// finish ops
op_shardedwq.drain(); // should already be empty except for lagard PGs
{
Mutex::Locker l(finished_lock);
finished.clear(); // zap waiters (bleh, this is messy)
}
....
// Remove PGs
#ifdef PG_DEBUG_REFS
service.dump_live_pgids();
#endif
{
RWLock::RLocker l(pg_map_lock);
for (ceph::unordered_map<spg_t, PG*>::iterator p = pg_map.begin();
p != pg_map.end();
++p) {
dout(20) << " kicking pg " << p->first << dendl;
p->second->lock();
if (p->second->ref.read() != 1) {
derr << "pgid " << p->first << " has ref count of "
<< p->second->ref.read() << dendl;
assert(0);
}
p->second->unlock();
p->second->put("PGMap");
}
pg_map.clear();
}
#ifdef PG_DEBUG_REFS
service.dump_live_pgids();
#endif
...
}
I could see this PG been kicked off by the OSD earlier, but this could be due
to some write ops are still stuck here or someone else is referring this pg. To
dump any pg references we should have the ceph built with pgrefdebugging.
-3031> 2014-06-19 08:28:27.037414 7fa95b007700 20 osd.23 1551 kicking pg 4.53
-3030> 2014-06-19 08:28:27.037417 7fa95b007700 30 osd.23 pg_epoch: 1551
pg[4.53( v 1551'2203 (0'0,1551'2203] local-les=1500 n=461 ec=108 les/c
1500/1510 1499/1499/1499) [23,18,8] r=0 lpr=1499 luod=1551'2201 crt=1498'2116
lcod 1551'2200 mlcod 1551'2200 active+clean] lock
-3029> 2014-06-19 08:28:27.037425 7fa95b007700 10 osd.23 pg_epoch: 1551
pg[4.53( v 1551'2203 (0'0,1551'2203] local-les=1500 n=461 ec=108 les/c
1500/1510 1499/1499/1499) [23,18,8] r=0 lpr=1499 luod=1551'2201 crt=1498'2116
lcod 1551'2200 mlcod 1551'2200 active+clean] on_shutdown
-3028> 2014-06-19 08:28:27.037434 7fa95b007700 10 osd.23 pg_epoch: 1551
pg[4.53( v 1551'2203 (0'0,1551'2203] local-les=1500 n=461 ec=108 les/c
1500/1510 1499/1499/1499) [23,18,8] r=0 lpr=1499 luod=1551'2201 crt=1498'2116
lcod 1551'2200 mlcod 1551'2200 active+clean] cancel_copy_ops
-3027> 2014-06-19 08:28:27.037442 7fa95b007700 10 osd.23 pg_epoch: 1551
pg[4.53( v 1551'2203 (0'0,1551'2203] local-les=1500 n=461 ec=108 les/c
1500/1510 1499/1499/1499) [23,18,8] r=0 lpr=1499 luod=1551'2201 crt=1498'2116
lcod 1551'2200 mlcod 1551'2200 active+clean] cancel_flush_ops
-3026> 2014-06-19 08:28:27.037486 7fa95b007700 10 osd.23 pg_epoch: 1551
pg[4.53( v 1551'2203 (0'0,1551'2203] local-les=1500 n=461 ec=108 les/c
1500/1510 1499/1499/1499) [23,18,8] r=0 lpr=1499 luod=1551'2201 crt=1498'2116
lcod 1551'2200 mlcod 1551'2200 active+clean] applying repop tid 3755
-3025> 2014-06-19 08:28:27.037494 7fa95b007700 20 osd.23 pg_epoch: 1551
pg[4.53( v 1551'2203 (0'0,1551'2203] local-les=1500 n=461 ec=108 les/c
1500/1510 1499/1499/1499) [23,18,8] r=0 lpr=1499 luod=1551'2201 crt=1498'2116
lcod 1551'2200 mlcod 1551'2200 active+clean] remove_repop repgather(0x15548c00
1551'2202 rep_tid=3755 committed?=0 applied?=0 lock=0
op=osd_op(client.5117.1:3911087 rbd_data.16862ae8944a.0000000000038629 [write
2293760~524288] 4.3d302453 ondisk+write e1551) v4)
-3024> 2014-06-19 08:28:27.037509 7fa95b007700 15 osd.23 pg_epoch: 1551
pg[4.53( v 1551'2203 (0'0,1551'2203] local-les=1500 n=461 ec=108 les/c
1500/1510 1499/1499/1499) [23,18,8] r=0 lpr=1499 luod=1551'2201 crt=1498'2116
lcod 1551'2200 mlcod 1551'2200 active+clean] requeue_ops
-3023> 2014-06-19 08:28:27.037518 7fa95b007700 10 osd.23 pg_epoch: 1551
pg[4.53( v 1551'2203 (0'0,1551'2203] local-les=1500 n=461 ec=108 les/c
1500/1510 1499/1499/1499) [23,18,8] r=0 lpr=1499 luod=1551'2201 crt=1498'2116
lcod 1551'2200 mlcod 1551'2200 active+clean] applying repop tid 3756
-3022> 2014-06-19 08:28:27.037526 7fa95b007700 20 osd.23 pg_epoch: 1551
pg[4.53( v 1551'2203 (0'0,1551'2203] local-les=1500 n=461 ec=108 les/c
1500/1510 1499/1499/1499) [23,18,8] r=0 lpr=1499 luod=1551'2201 crt=1498'2116
lcod 1551'2200 mlcod 1551'2200 active+clean] remove_repop repgather(0x161d1780
1551'2203 rep_tid=3756 committed?=0 applied?=0 lock=0
op=osd_op(client.5117.1:3911088 rbd_data.16862ae8944a.0000000000038629 [write
2818048~200704] 4.3d302453 ondisk+write e1551) v4)
-3021> 2014-06-19 08:28:27.037538 7fa95b007700 15 osd.23 pg_epoch: 1551
pg[4.53( v 1551'2203 (0'0,1551'2203] local-les=1500 n=461 ec=108 les/c
1500/1510 1499/1499/1499) [23,18,8] r=0 lpr=1499 luod=1551'2201 crt=1498'2116
lcod 1551'2200 mlcod 1551'2200 active+clean] requeue_ops
-3020> 2014-06-19 08:28:27.037549 7fa95b007700 10 osd.23 pg_epoch: 1551
pg[4.53( v 1551'2203 (0'0,1551'2203] local-les=1500 n=461 ec=108 les/c
1500/1510 1499/1499/1499) [23,18,8] r=0 lpr=1499 luod=1551'2201 crt=1498'2116
lcod 1551'2200 mlcod 1551'2200 active+clean] clear_primary_state
-3019> 2014-06-19 08:28:27.037562 7fa95b007700 20 osd.23 pg_epoch: 1551
pg[4.53( v 1551'2203 (0'0,1551'2203] local-les=1500 n=461 ec=108 les/c
1500/1510 1499/1499/1499) [23,18,8] r=0 lpr=1499 luod=0'0 crt=1498'2116 lcod
1551'2200 mlcod 0'0 active+clean] agent_stop
-3018> 2014-06-19 08:28:27.037570 7fa95b007700 10 osd.23 pg_epoch: 1551
pg[4.53( v 1551'2203 (0'0,1551'2203] local-les=1500 n=461 ec=108 les/c
1500/1510 1499/1499/1499) [23,18,8] r=0 lpr=1499 luod=0'0 crt=1498'2116 lcod
1551'2200 mlcod 0'0 active+clean] cancel_recovery
-3017> 2014-06-19 08:28:27.037578 7fa95b007700 10 osd.23 pg_epoch: 1551
pg[4.53( v 1551'2203 (0'0,1551'2203] local-les=1500 n=461 ec=108 les/c
1500/1510 1499/1499/1499) [23,18,8] r=0 lpr=1499 luod=0'0 crt=1498'2116 lcod
1551'2200 mlcod 0'0 active+clean] clear_recovery_state
Seems to be a recent issue in the shutdown path when writes are in progress.
Sahana Lokeshappa
________________________________
PLEASE NOTE: The information contained in this electronic mail message is
intended only for the use of the designated recipient(s) named above. If the
reader of this message is not the intended recipient, you are hereby notified
that you have received this message in error and that any review,
dissemination, distribution, or copying of this message is strictly prohibited.
If you have received this communication in error, please notify the sender by
telephone or e-mail (as shown above) immediately and destroy any and all copies
of this message in your possession (whether hard copies or electronically
stored copies).
_______________________________________________
ceph-users mailing list
ceph-users@lists.ceph.com
http://lists.ceph.com/listinfo.cgi/ceph-users-ceph.com
