Bug #36105
closed
OSD hangs during shutdown
Added by Sage Weil over 5 years ago.
Updated over 5 years ago.
Description
2018-09-20T21:31:59.512 INFO:tasks.workunit.client.0.smithi188.stderr:/home/ubuntu/cephtest/clone.client.0/qa/standalone/osd/osd-backfill-stats.sh:304: TEST_backfill_dowdelete_pool test
2018-09-20T21:31:59.513 INFO:tasks.workunit.client.0.smithi188.stderr:/home/ubuntu/cephtest/clone.client.0/qa/standalone/ceph-helpers.sh:533: delete_pool: local poolname=test
2018-09-20T21:31:59.513 INFO:tasks.workunit.client.0.smithi188.stderr:/home/ubuntu/cephtest/clone.client.0/qa/standalone/ceph-helpers.sh:534: delete_pool: ceph osd pool delete test test --yes-i-really-really-mean-it
2018-09-20T21:32:00.192 INFO:tasks.workunit.client.0.smithi188.stderr:pool 'test' does not exist
2018-09-20T21:32:00.204 INFO:tasks.workunit.client.0.smithi188.stderr:/home/ubuntu/cephtest/clone.client.0/qa/standalone/osd/osd-backfill-stats.sh:305: TEST_backfill_dowkill_daemons td/osd-backfill-stats
2018-09-20T21:32:00.204 INFO:tasks.workunit.client.0.smithi188.stderr://home/ubuntu/cephtest/clone.client.0/qa/standalone/ceph-helpers.sh:345: kill_daemons: shopt -q -o xtrace
2018-09-20T21:32:00.205 INFO:tasks.workunit.client.0.smithi188.stderr://home/ubuntu/cephtest/clone.client.0/qa/standalone/ceph-helpers.sh:345: kill_daemons: echo true
2018-09-20T21:32:00.205 INFO:tasks.workunit.client.0.smithi188.stderr:/home/ubuntu/cephtest/clone.client.0/qa/standalone/ceph-helpers.sh:345: kill_daemons: local trace=true
2018-09-20T21:32:00.205 INFO:tasks.workunit.client.0.smithi188.stderr:/home/ubuntu/cephtest/clone.client.0/qa/standalone/ceph-helpers.sh:346: kill_daemons: true
2018-09-20T21:32:00.205 INFO:tasks.workunit.client.0.smithi188.stderr:/home/ubuntu/cephtest/clone.client.0/qa/standalone/ceph-helpers.sh:346: kill_daemons: shopt -u -o xtrace
2018-09-20T21:38:03.537 INFO:tasks.workunit.client.0.smithi188.stderr:/home/ubuntu/cephtest/clone.client.0/qa/standalone/ceph-helpers.sh:362: kill_daemons: return 1
...
/a/sage-2018-09-20_18:56:20-rados-wip-sage-testing-2018-09-20-0933-distro-basic-smithi/3047210
If I'm reading this right, kill_daemons failed so we hit the ||return 1 and the whole thing failed.
- Description updated (diff)
- Status changed from New to 12
- Priority changed from Normal to High
Yes, the kill_daemons failed because after 6 minutes several terminated OSDs still hadn't finished shutting down. I noticed in one case the last pg message showed a PG in DELETING state.
- Assignee set to David Zafman
I've reproduced this running the test in my local tree. I'll work on generating a core dump to find out what is stuck.
/a/nojha-2018-09-24_16:58:52-rados-master-distro-basic-smithi/3065653/
I'll look at this more tomorrow but I suspect that the following commit from https://github.com/ceph/ceph/pull/22739 is causing a problem:
commit 6c583fe756c82ed6c196caa0ce783765d5e9ee41
Author: Jianpeng Ma <jianpeng.ma@intel.com>
Date: Thu Sep 20 22:10:20 2018 +0800
osd/OSD: choose a fixed thread do oncommits callback function
Now bluestore oncommit callback exec by osd op threads.
If there are multi threads of shard, it will cause out-of order.
For example, threads_per_shard=2
Thread1 Thread2
swap_oncommits(op1_oncommit)
swap_oncommits(op2_oncommit)
OpQueueItem.run(Op3)
op2_oncommit.complete();
op1_oncommit.complete()
This make oncommits out of order.
To avoiding this, we choose a fixed thread which has the smallest
thread_index of shard to do oncommit callback function.
Signed-off-by: Jianpeng Ma <jianpeng.ma@intel.com>
I think thread 54 may be looping while thread 8 is waiting for all 5 threads to finish (4 drained so far)
Thread 54 (Thread 0x7fcac9550700 (LWP 62090)):
#0 WeightedPriorityQueue<OpQueueItem, unsigned long>::empty (this=0x55f091128f80) at /src/ceph/src/common/WeightedPriorityQueue.h:303
#1 0x000055f085e90a56 in OSD::ShardedOpWQ::_process (this=0x55f0920111f8, thread_index=0, hb=0x55f0921f8050) at /src/ceph/src/osd/OSD.cc:10253
#2 0x000055f0864b7586 in ShardedThreadPool::shardedthreadpool_worker (this=0x55f0920109d8, thread_index=0) at /src/ceph/src/common/WorkQueue.cc:340
#3 0x000055f0864c2970 in ShardedThreadPool::WorkThreadSharded::entry (this=<optimized out>) at /src/ceph/src/common/WorkQueue.h:691
#4 0x00007fcaea4c26ba in start_thread (arg=0x7fcac9550700) at pthread_create.c:333
#5 0x00007fcae952a82d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109
Thread 8 (Thread 0x7fcae4de9700 (LWP 62015)):
#0 pthread_cond_wait@@GLIBC_2.3.2 () at ../sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
#1 0x000055f0864c1816 in Cond::Wait (mutex=..., this=0x55f092010ae0) at /src/ceph/src/common/Cond.h:49
#2 ShardedThreadPool::drain (this=0x55f0920109d8) at /src/ceph/src/common/WorkQueue.cc:434
#3 0x000055f085e82249 in ShardedThreadPool::ShardedWQ<OpQueueItem>::drain (this=0x55f0920111f8) at /src/ceph/src/common/WorkQueue.h:676
#4 OSD::shutdown (this=this@entry=0x55f092010000) at /src/ceph/src/osd/OSD.cc:3553
#5 0x000055f085e832db in OSD::handle_signal (this=0x55f092010000, signum=<optimized out>) at /src/ceph/src/osd/OSD.cc:2213
#6 0x000055f08644d172 in SignalHandler::entry (this=0x55f09114a9c0) at /src/ceph/src/global/signal_handler.cc:497
#7 0x00007fcaea4c26ba in start_thread (arg=0x7fcae4de9700) at pthread_create.c:333
#8 0x00007fcae952a82d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109
In all 3 OSDs I found that hung, the last thread to drain is the smallest thread_index (thus the thread that handles oncommits). However, in all 3 cases the context_queue is empty, but pqueue is not.
This issue is that prior to d7ca34e12fd9dd652fe12b5593bf2ccd4ce35b60 the relevant code in OSD::ShardedOpWQ::_process() looked like this:
OpQueueItem item = sdata->pqueue->dequeue();
if (osd->is_stopping()) {
sdata->shard_lock.Unlock();
return; // OSD shutdown, discard.
}
Here when stopping an item is discarded until the queue is empty. Without the dequeue() before returning, the work queue never drains and a thread will infinite loop, but it still resets the heartbeat timeout, so it is not detected internally.
- Status changed from 12 to In Progress
- Subject changed from qa/standalone/osd/osd-backfill-stats.sh failed during shutdown? to OSD hangs during shutdown
- Status changed from In Progress to Resolved
Also available in: Atom
PDF