Project

General

Profile

Actions

Bug #7207

closed

Lock contention at filestore I/O (FileStore::lfn_open) during filestore folder splitting bring the cluster's performance degradation

Added by Guang Yang over 10 years ago. Updated about 10 years ago.

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

0%

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

Description

There is a lock contention happening at filestore I/O (FileStore::lfn_open, https://github.com/guangyy/ceph/blob/master/src/os/FileStore.cc#L198), with the lock holding, the thread (either op thread
or filestore thread) will check if it is the time to do folder splitting (max 320 files within a folder as default configured, https://github.com/guangyy/ceph/blob/master/src/os/FileStore.cc#L230), and if that is true, the thread will do the folder splitting which can take up to several seconds, during this time period, all threads trying to do filestore I/O (especially the op thread which is in critical path) would hang waiting for the lock.

So that after running for some time, there are millions of folders needing to be splitted (from level 5 to level 6) and each one could hand OSD op for several seconds (due to the lock contention), that would make the performance degradation for the entire cluster as we observed from 'dump_historic_ops' including: 1) all op threads (doing filestore I/O) hang waiting for the lock. 2) op waiting long time within op working queue as there is no op thread taking it (because of 1). 3) waiting for sub-op as sub-op might be experiencing either 1 or 2.

We deem that as a lock contention issues as one sub folder splitting (there are tens of thousands of such folders managed by an OSD) could block the entire OSD I/O.

A typical event flow for such hang op looks like below (note the latency comes from reached_pg to started): {
"rmw_flags": 4,
"received_at": "2014-01-22 03:43:33.775424",
"age": "158.326674",
"duration": "4.003504",
"flag_point": "waiting for sub ops",
"client_info": { "client": "client.94353",
"tid": 30248979},
"events": [ { "time": "2014-01-22 03:43:33.778359",
"event": "waiting_for_osdmap"}, { "time": "2014-01-22 03:43:33.778640",
"event": "reached_pg"}, { "time": "2014-01-22 03:43:36.302657",
"event": "started"}, { "time": "2014-01-22 03:43:36.303010",
"event": "started"}, { "time": "2014-01-22 03:43:36.309889",
"event": "waiting for subops from [112,200]"}, { "time": "2014-01-22 03:43:36.311360",
"event": "commit_queued_for_journal_write"}, { "time": "2014-01-22 03:43:36.311680",
"event": "write_thread_in_journal_buffer"}, { "time": "2014-01-22 03:43:36.312144",
"event": "journaled_completion_queued"}, { "time": "2014-01-22 03:43:36.312200",
"event": "op_commit"}, { "time": "2014-01-22 03:43:36.337536",
"event": "sub_op_commit_rec"}, { "time": "2014-01-22 03:43:36.482597",
"event": "op_applied"}, { "time": "2014-01-22 03:43:37.778550",
"event": "sub_op_commit_rec"}, { "time": "2014-01-22 03:43:37.778928",
"event": "done"}]},
}

Actions

Also available in: Atom PDF