14 Apr
2021
14 Apr
'21
5:48 a.m.
Hi,
We had a case reported by our customer, when a faulty disk was
returning ENODATA error on directory split and it created some mess
due to transactions aborting a transaction operation when encountering
the directory split error but not aborting the whole transaction,
exectuting another operations.
The kernel log:
2020-12-16T07:02:36.736166+09:00 node5 kernel: [10270806.635341] sd 0:2:10:0: [sdk] tag#1
BRCM Debug mfi stat 0x2d, data len requested/completed 0x4000/0x0
2020-12-16T07:02:36.736180+09:00 node5 kernel: [10270806.635349] sd 0:2:10:0: [sdk] tag#1
FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE
2020-12-16T07:02:36.736181+09:00 node5 kernel: [10270806.635351] sd 0:2:10:0: [sdk] tag#1
Sense Key : Medium Error [current]
2020-12-16T07:02:36.736184+09:00 node5 kernel: [10270806.635353] sd 0:2:10:0: [sdk] tag#1
Add. Sense: Unrecovered read error
2020-12-16T07:02:36.736203+09:00 node5 kernel: [10270806.635355] sd 0:2:10:0: [sdk] tag#1
CDB: Read(16) 88 00 00 00 00 00 02 67 ec 00 00 00 00 20 00 00
2020-12-16T07:02:36.736234+09:00 node5 kernel: [10270806.635357] blk_update_request:
critical medium error, dev sdk, sector 40365056
2020-12-16T07:02:36.736240+09:00 node5 kernel: [10270806.635379] XFS (sdk2): metadata I/O
error: block 0x1edda00 ("xfs_trans_read_buf_map") error 61 numblks 32
2020-12-16T07:02:36.736241+09:00 node5 kernel: [10270806.635384] XFS (sdk2):
xfs_imap_to_bp: xfs_trans_read_buf() returned error -61.
The osd log:
2020-12-16 07:02:36.419810 7f283a43d700 1 _created [2,5,C,A,6] has 447 objects, starting
split in pg 5.452s0_head.
2020-12-16 07:02:36.736125 7f283a43d700 1 _created [2,5,C,A,6] split completed in pg
5.452s0_head.
2020-12-16 07:02:36.736150 7f283a43d700 -1 filestore(/var/lib/ceph/osd/ceph-57) error
creating 0#5:4a3568ed:::<CENSORED>:head#
(/var/lib/ceph/osd/ceph-57/current/5.452s0_head/DIR_2/DIR_5/DIR_C/DIR_A/DIR_6/<CENSORED>__head_B716AC52__5_ffffffffffffffff_0)
in index: (61) No data available
So a transaction operation created a new object file, detected that
the directory needed splitting, tried to split, failed, aborted the
operation in the middle, returned the ENODATA error to
FileStore::_do_transaction, but it was ignored and the transaction
conitnued.
We do not have idea where exactly the split was failing but it seemed
it did not cause data loss, but it aborted a transaction operation in
the middle and it could make some mess.
We were seeing at least two types of such "messy" transactions:
1) On rados writing a new objects, one of the first transaction
operations is OP_TOUCH. It creates the object file, tries to split the
directory, aborts and skips creating the object spill_out attribute
due to this.
2) On rados deleting an object, one of the transactions operations is
OP_COLL_MOVE_RENAME, wich creates a temporary link, which triggers the
directory split and the error, the op is aborted in the middle leaving
the original object file not removed.
So it looks like a bug and could be improved, but the question is if
the upsteam is still interested in improving the filestore in this
area? Should I report it to the tracker?
--
Mykola Golub
15 Apr
15 Apr
11:42 p.m.
Hi Mykola,
On Tue, Apr 13, 2021 at 8:49 PM Mykola Golub <to.my.trociny(a)gmail.com> wrote:
Hi,
We had a case reported by our customer, when a faulty disk was
returning ENODATA error on directory split and it created some mess
due to transactions aborting a transaction operation when encountering
the directory split error but not aborting the whole transaction,
exectuting another operations.
The kernel log:
2020-12-16T07:02:36.736166+09:00 node5 kernel: [10270806.635341] sd 0:2:10:0: [sdk] tag#1
BRCM Debug mfi stat 0x2d, data len requested/completed 0x4000/0x0
2020-12-16T07:02:36.736180+09:00 node5 kernel: [10270806.635349] sd 0:2:10:0: [sdk] tag#1
FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE
2020-12-16T07:02:36.736181+09:00 node5 kernel: [10270806.635351] sd 0:2:10:0: [sdk] tag#1
Sense Key : Medium Error [current]
2020-12-16T07:02:36.736184+09:00 node5 kernel: [10270806.635353] sd 0:2:10:0: [sdk] tag#1
Add. Sense: Unrecovered read error
2020-12-16T07:02:36.736203+09:00 node5 kernel: [10270806.635355] sd 0:2:10:0: [sdk] tag#1
CDB: Read(16) 88 00 00 00 00 00 02 67 ec 00 00 00 00 20 00 00
2020-12-16T07:02:36.736234+09:00 node5 kernel: [10270806.635357] blk_update_request:
critical medium error, dev sdk, sector 40365056
2020-12-16T07:02:36.736240+09:00 node5 kernel: [10270806.635379] XFS (sdk2): metadata I/O
error: block 0x1edda00 ("xfs_trans_read_buf_map") error 61 numblks 32
2020-12-16T07:02:36.736241+09:00 node5 kernel: [10270806.635384] XFS (sdk2):
xfs_imap_to_bp: xfs_trans_read_buf() returned error -61.
The osd log:
2020-12-16 07:02:36.419810 7f283a43d700 1 _created [2,5,C,A,6] has 447 objects, starting
split in pg 5.452s0_head.
2020-12-16 07:02:36.736125 7f283a43d700 1 _created [2,5,C,A,6] split completed in pg
5.452s0_head.
2020-12-16 07:02:36.736150 7f283a43d700 -1 filestore(/var/lib/ceph/osd/ceph-57) error
creating 0#5:4a3568ed:::<CENSORED>:head#
(/var/lib/ceph/osd/ceph-57/current/5.452s0_head/DIR_2/DIR_5/DIR_C/DIR_A/DIR_6/<CENSORED>__head_B716AC52__5_ffffffffffffffff_0)
in index: (61) No data available
So a transaction operation created a new object file, detected that
the directory needed splitting, tried to split, failed, aborted the
operation in the middle, returned the ENODATA error to
FileStore::_do_transaction, but it was ignored and the transaction
conitnued.
We do not have idea where exactly the split was failing but it seemed
it did not cause data loss, but it aborted a transaction operation in
the middle and it could make some mess.
We were seeing at least two types of such "messy" transactions:
1) On rados writing a new objects, one of the first transaction
operations is OP_TOUCH. It creates the object file, tries to split the
directory, aborts and skips creating the object spill_out attribute
due to this.
2) On rados deleting an object, one of the transactions operations is
OP_COLL_MOVE_RENAME, wich creates a temporary link, which triggers the
directory split and the error, the op is aborted in the middle leaving
the original object file not removed.
So it looks like a bug and could be improved, but the question is if
the upsteam is still interested in improving the filestore in this
area? Should I report it to the tracker?
Please feel free to create a tracker for it. Though we are not
actively developing against filestore, if the fix for this issue isn't
too invasive, I don't see any issues in merging it.
Thanks,
Neha
--
Mykola Golub
_______________________________________________
Dev mailing list -- dev(a)ceph.io
To unsubscribe send an email to dev-leave(a)ceph.io
16 Apr
16 Apr
11:09 a.m.
On Thu, Apr 15, 2021 at 02:42:17PM -0700, Neha Ojha wrote:
Thank you, Neha!
Here it is: https://tracker.ceph.com/issues/50395
We would like to work on the fix and I am thinking how to approach it.
I think it is not correct that the result of the directory splitting
(partially related to operation) aborts a transaction operation in the
middle with the error code from directory split. And then the
transaction uses this error code to make a decision how to proceed
with the entire transaction (expecting that the error code came from
the operation itself).
Options that I see:
1) Consider the failed directory split not critical to abort the
operation, i.e. ignore the error and proceed.
2) Consider it critical and just abort the osd.
3) replace the error code returned by directory split with some
special error code, so the upper layer (FileStore::_do_transaction)
could make a propriate decision (abort the transaction?).
4) Combination of (1) and (2): depending on the returned code condider
it either non-critical and ignore or critical and abort the osd.
5) Either (1) or (2) depending on a config option.
I would vote for (1) or (4) but I would love to learn what other
people think about the issue and how it could be approached.
Also, it would be nice to know why it was considered that ENODATA
could be ignored in the transaction. I suppose it is because it was
expected that ENODATA could be returned by getxattr only, when the
attribute does not exist, and it was not expected to affect the
transaction result?
--
Mykola Golub
We were seeing
at least two types of such "messy" transactions:
1) On rados writing a new objects, one of the first transaction
operations is OP_TOUCH. It creates the object file, tries to split the
directory, aborts and skips creating the object spill_out attribute
due to this.
2) On rados deleting an object, one of the transactions operations is
OP_COLL_MOVE_RENAME, wich creates a temporary link, which triggers the
directory split and the error, the op is aborted in the middle leaving
the original object file not removed.
So it looks like a bug and could be improved, but the question is if
the upsteam is still interested in improving the filestore in this
area? Should I report it to the tracker?
Please feel free to create a tracker for it. Though we are not
actively developing against filestore, if the fix for this issue isn't
too invasive, I don't see any issues in merging it.
17 Apr
17 Apr
2:07 a.m.
On Fri, Apr 16, 2021 at 2:10 AM Mykola Golub <to.my.trociny(a)gmail.com> wrote:
On Thu, Apr 15, 2021 at 02:42:17PM -0700, Neha Ojha wrote:
Thank you, Neha!
Here it is: https://tracker.ceph.com/issues/50395
We would like to work on the fix and I am thinking how to approach it.
I think it is not correct that the result of the directory splitting
(partially related to operation) aborts a transaction operation in the
middle with the error code from directory split. And then the
transaction uses this error code to make a decision how to proceed
with the entire transaction (expecting that the error code came from
the operation itself).
Options that I see:
1) Consider the failed directory split not critical to abort the
operation, i.e. ignore the error and proceed.
2) Consider it critical and just abort the osd.
I think it makes sense to handle it like the way an EIO (with
filestore_fail_eio enabled) is handled in filestore and abort.
Neha
Neha
We were
seeing at least two types of such "messy" transactions:
1) On rados writing a new objects, one of the first transaction
operations is OP_TOUCH. It creates the object file, tries to split the
directory, aborts and skips creating the object spill_out attribute
due to this.
2) On rados deleting an object, one of the transactions operations is
OP_COLL_MOVE_RENAME, wich creates a temporary link, which triggers the
directory split and the error, the op is aborted in the middle leaving
the original object file not removed.
So it looks like a bug and could be improved, but the question is if
the upsteam is still interested in improving the filestore in this
area? Should I report it to the tracker?
Please feel free to create a tracker for it. Though we are not
actively developing against filestore, if the fix for this issue isn't
too invasive, I don't see any issues in merging it.
3) replace the error code returned by directory split with some
special error code, so the upper layer (FileStore::_do_transaction)
could make a propriate decision (abort the transaction?).
4) Combination of (1) and (2): depending on the returned code condider
it either non-critical and ignore or critical and abort the osd.
5) Either (1) or (2) depending on a config option.
I would vote for (1) or (4) but I would love to learn what other
people think about the issue and how it could be approached.
Also, it would be nice to know why it was considered that ENODATA
could be ignored in the transaction. I suppose it is because it was
expected that ENODATA could be returned by getxattr only, when the
attribute does not exist, and it was not expected to affect the
transaction result?
--
Mykola Golub
19 Apr
19 Apr
6:45 p.m.
On Fri, Apr 16, 2021 at 05:07:58PM -0700, Neha Ojha wrote:
I think it makes sense to handle it like the way an
EIO (with
filestore_fail_eio enabled) is handled in filestore and abort.
Thanks!
https://github.com/ceph/ceph/pull/40916
--
Mykola Golub
1112
days inactive
1117
days old
4 comments
2 participants
participants (2)
-
Mykola Golub -
Neha Ojha