Project

General

Profile

Actions

Bug #3681

closed

kclient fsx fails nightly

Added by Sage Weil over 11 years ago. Updated over 10 years ago.

Status:
Resolved
Priority:
High
Assignee:
-
Category:
-
Target version:
-
% Done:

0%

Source:
Q/A
Tags:
Backport:
Regression:
Severity:
Reviewed:
Affected Versions:
ceph-qa-suite:
Component(FS):
Labels (FS):
Pull request ID:
Crash signature (v1):
Crash signature (v2):

Description

teuthology-2012-12-23_03:00:04-regression-master-testing-gcov/23184 FAIL scheduled_teuthology@teuthology collection:kernel-cephfs clusters:fixed-3.yaml fs:btrfs.yaml tasks:kclient_workunit_suites_fsx.yaml 2122s
teuthology-2012-12-24_03:00:03-regression-master-testing-gcov/23997 FAIL scheduled_teuthology@teuthology collection:kernel-cephfs clusters:fixed-3.yaml fs:btrfs.yaml tasks:kclient_workunit_suites_fsx.yaml 3361s
teuthology-2012-12-25_03:00:02-regression-master-testing-gcov/27378 pass scheduled_teuthology@teuthology collection:kernel-cephfs clusters:fixed-3.yaml fs:btrfs.yaml tasks:kclient_workunit_suites_fsx.yaml 4321s
teuthology-2012-12-26_03:00:10-regression-master-testing-gcov/27759 pass scheduled_teuthology@teuthology collection:kernel-cephfs clusters:fixed-3.yaml fs:btrfs.yaml tasks:kclient_workunit_suites_fsx.yaml 3540s

Files

fsx-failure-syslog (24 MB) fsx-failure-syslog Sam Lang, 01/03/2013 09:32 AM

Related issues 2 (0 open2 closed)

Has duplicate CephFS - Bug #3818: kclient: fsx fails in mapreadDuplicateSam Lang01/16/2013

Actions
Precedes CephFS - Bug #3738: kclient fsx truncate/write multi-client raceResolvedSam Lang12/27/201212/27/2012

Actions
Actions #1

Updated by Sage Weil over 11 years ago

  • Assignee set to Sam Lang
Actions #2

Updated by Sam Lang over 11 years ago

Its most likely all the same bug, but fsx fails in different ways each time (always because of a truncate down). The one I'm looking at does the following:

truncate down from 104576 -> 75711

Then it tries to verify the size with a getattr, but getattr returns 104576. The kernel log shows that:

  • The setattr successfully sets the size:

Dec 31 10:09:58 plana23 kernel: [1218326.551021] ceph: setattr ffff88020ea01c60 size 104576 -> 75711

  • Then on the trace reply:

Dec 31 10:10:07 plana23 kernel: [1218401.360063] ceph: size 104576 -> 75711

  • But then during the getattr, the CAP_TRUNC message arrives:

Dec 31 10:10:12 plana23 kernel: [1218406.195224] ceph: handle_cap_trunc inode ffff88020ea01c60 mds0 seq 154 to 75711 seq 36
Dec 31 10:10:12 plana23 kernel: [1218406.254293] ceph: size 75711 -> 104576

Note that second line is setting the i_size back to 104576, because the CAP_TRUNC message has a truncate_size=75711, but size=104576.

So the problem seems like its coming from the mds. But on inspecting the mds, the Locker::issue_truncate() is called after pop_and_dirty_projected_inode (which should correctly set the inode size to the value sent in the setattr). So its still unclear how the mds is sending back size=104576...

Attached is the client log.

Actions #3

Updated by Sam Lang over 11 years ago

  • Status changed from 12 to 7

The race here is between a truncate down, and completion of osd write ops triggering a cap flush. The exact order that triggers it is:

a) write increases size, updates inode->i_size to 104576
b) setattr to mds for truncate down size 75711
c) write to osds complete, cap flushed, cap update sends size 104576 to mds
d) setattr response, inode->i_size set to 75711
e) cap truncate message received with size 104576, sets inode->i_size to 104576

Pushed a proposed fix to wip-3681, which is currently being tested. This resolves the issue that the setattr is sending a request to the mds if it has the exclusive cap, and ensures that i_size has a correct value, but the same race still exists if the client doesn't have the exclusive cap. Opening a separate bug/issue for the multi-client case.

Actions #4

Updated by Sam Lang over 11 years ago

Proposed fix to set i_size before the setattr request:

This will resolve the above issue, because the cap flush on write finish will send the truncated size to the mds. It may not work for multi-client scenarios, consider the following:

a) clientA write increases size, updates inode->i_size to 104576
b) clientB setattr to mds for truncate down size 75711 [mds size=75711]
c) clientA write to osds complete, cap flushed, cap update sends size 104576 to mds [mds size=104576]
d) clientB setattr response, inode->i_size set to 75711
e) clientB cap truncate message received with size 104576, sets inode->i_size to 104576

Actions #5

Updated by Ian Colle about 11 years ago

  • Status changed from 7 to 12
  • Assignee deleted (Sam Lang)
Actions #6

Updated by Ian Colle about 11 years ago

  • Assignee set to Sage Weil

Should review entire kernel locking around truncate.

Actions #7

Updated by Sage Weil about 11 years ago

  • Assignee deleted (Sage Weil)
Actions #8

Updated by Zheng Yan almost 11 years ago

I think this has already been fixed (a cap revoke bug in the MDS code). When handling truncate request, current MDS revokes write caps from clients.

Actions #9

Updated by Sage Weil over 10 years ago

  • Status changed from 12 to 7

added fsx back into the kcephfs test suite. reportedly fsx now passes, but we should verify before closing this bug.

Actions #10

Updated by Zheng Yan over 10 years ago

  • Status changed from 7 to Resolved
Actions

Also available in: Atom PDF