[LU-7117] replay-single test_70d: timeout and mkdir/rmdir stopped

• Status: Resolved
• Project: Lustre
• Affects Version/s: Lustre 2.8.0, Lustre 2.9.0
• Fix Version/s: Lustre 2.9.0
• Type: Bug
• Priority: Critical
• Reporter: Maloo
• Assignee: Lai Siyao
• Resolution: Fixed
• Severity: 3

Description

This issue was created by maloo for Andreas Dilger <[e-mail]>

This issue relates to the following test suite run: https://testing.hpdd.intel.com/test_sets/56e1b56e-53ff-11e5-8f2c-5254006e85c2.

The sub-test test_70d failed with the following error:

error on LL_IOC_LMV_SETSTRIPE '/mnt/lustre/d70d.replay-single/test1' (3): stripe already set
error: mkdir: create stripe dir '/mnt/lustre/d70d.replay-single/test1' failed
mkdir fails
/usr/lib64/lustre/tests/replay-single.sh: line 2236: kill: (25189) - No such process
mkdir/rmdir 25189 stopped

There are several test failures and timeouts for 70d since 2015-09-02 so I suspect a patch landed on that day or the previous day that introduced a regression.

Info required for matching: replay-single 70d

Issue Links

• is duplicated by: LU-7213 replay-single test_70d: mkdir: create...
• is duplicated by: LU-7924 replay-single test_70d: short descrip...
• is related to: LU-7172 replay-single test_70d hung on MDT un...
• is related to: LU-7775 replay-single test_70d: cannot touch ...
• is related to: LU-6844 replay-single test 70b failure: 'rund...
• is related to: LU-8353 mdt unlink should lock parent before ...
• is related to: LU-8617 replay-single test_70d: stripe alread...

Comments

[James Nunez (Inactive)]

Another failure of replay-single test_70d with logs at https://testing.hpdd.intel.com/test_sets/e4bc4b96-6cb0-11e5-ab7f-5254006e85c2
2015-10-26 15:56:26 - https://testing.hpdd.intel.com/test_sets/0f6e4b5c-7c3b-11e5-bc82-5254006e85c2
2015-11-04 01:58:10 - https://testing.hpdd.intel.com/test_sets/40bafc72-82e0-11e5-8b6b-5254006e85c2

[Bob Glossman (Inactive)]

another on master:
https://testing.hpdd.intel.com/test_sets/65711b06-8857-11e5-84a2-5254006e85c2

[James Nunez (Inactive)]

Another failure of stopping the mkdir/rmdir process, but this one takes place inside the random_fail_mdt() routine. I suspect the cause of the failure is the same since logs are the similar:

shadow-17vm9: CMD: shadow-17vm9.shadow.whamcloud.com lctl get_param -n at_max
shadow-17vm10: CMD: shadow-17vm10.shadow.whamcloud.com lctl get_param -n at_max
touch: cannot touch `/mnt/lustre/d70d.replay-single/test1/a': No such file or directory
touch fails
shadow-17vm9: mdc.lustre-MDT0001-mdc-*.mds_server_uuid in FULL state after 6 sec
shadow-17vm10: mdc.lustre-MDT0001-mdc-*.mds_server_uuid in FULL state after 6 sec
/usr/lib64/lustre/tests/replay-single.sh: line 2114: kill: (16877) - No such process

Logs at
2015-10-27 14:12:35 - https://testing.hpdd.intel.com/test_sets/1637670e-7cf7-11e5-bceb-5254006e85c2
2015-11-12 02:07:27 - https://testing.hpdd.intel.com/test_sets/f8324f14-8924-11e5-8ba4-5254006e85c2

[Jian Yu]

More instance on master:
https://testing.hpdd.intel.com/test_sets/5fc600d8-9836-11e5-8fa3-5254006e85c2

[James Nunez (Inactive)]

Another failure on master with the 'No such file or directory' error:
2015-12-27 14:00:02 - https://testing.hpdd.intel.com/test_sets/6af615f6-acea-11e5-9134-5254006e85c2
2016-01-07 03:11:56 - https://testing.hpdd.intel.com/test_sets/2f511064-b52d-11e5-aa1f-5254006e85c2
2016-01-12 13:29:58 - https://testing.hpdd.intel.com/test_sets/7aeee7ae-b97d-11e5-825c-5254006e85c2
2016-02-03 10:29:58 - https://testing.hpdd.intel.com/test_sets/7cf30a58-caa8-11e5-a610-5254006e85c2

[Jian Yu]

More failure instance on master branch:
https://testing.hpdd.intel.com/test_sets/48380772-c66c-11e5-8cac-5254006e85c2

All of the instances occurred with DNE configuration. Patch review testing on master branch is affected by this failure.

[Richard Henwood (Inactive)]

another master branch failure, during review-dne-part-2:

https://testing.hpdd.intel.com/test_sets/0a65754c-dd7d-11e5-ab2a-5254006e85c2

[Jian Yu]

Occurred again on master branch:
https://testing.hpdd.intel.com/test_sets/4d2a6bf2-fb4c-11e5-acc0-5254006e85c2

[Emoly Liu]

Another failure on master:
https://testing.hpdd.intel.com/test_sets/9bbba39e-0326-11e6-b5f1-5254006e85c2
https://testing.hpdd.intel.com/test_sets/21698126-0fb3-11e6-9b34-5254006e85c2

[nasf (Inactive)]

Another failure instance on master:
https://testing.hpdd.intel.com/test_sets/86f8d552-1c04-11e6-b5f1-5254006e85c2

[John Hammond]

https://testing.hpdd.intel.com/test_sets/59ca4542-1d4a-11e6-9089-5254006e85c2

[nasf (Inactive)]

Another failure instance on master:
https://testing.hpdd.intel.com/test_sets/e17c313a-3096-11e6-acf3-5254006e85c2

[Andreas Dilger]

This is now the number one cause of review test failures on master.

[nasf (Inactive)]

More failure instances on master:
https://testing.hpdd.intel.com/test_sets/478fbade-3180-11e6-bbf5-5254006e85c2
https://testing.hpdd.intel.com/test_sets/9d99755c-316f-11e6-a0ce-5254006e85c2

[Gerrit Updater]

Fan Yong ([e-mail]) uploaded a new patch: http://review.whamcloud.com/20853
Subject: LU-7117 tests: enable full debug for reply-single test_70d
Project: fs/lustre-release
Branch: master
Current Patch Set: 1
Commit: 61ec7fa12d28daffa43bc7a4f0e927d4e6550061

[nasf (Inactive)]

After the painful debugging from millions of lines logs, I found that the failure should related with the following scenario:
1) The client sent unlink (PFID/test1) RPC to the MDT1;
2) The MDT0 failover;
3) The MDT1 is replaying with the MDT0;
4) At that time, the step 1) trigger lookup(test1) RPC from the MDT1 to the MDT0 for the test1's FID.
5) But because the MDT0 recovery is not completed yet, the test1's FID on the MDT0 is still the old one. That means the MDT0 reply the MDT1 with an invalid test1's FID.
6) The MDT1 uses the MDT0 given test1's FID to locate the target child object to be deleted, found nothing. Then the unlink operation failed.

[Alex Zhuravlev]

no new RPCS (except update log redo) should be sent until the recovery is completed?

[Gerrit Updater]

Fan Yong ([e-mail]) uploaded a new patch: http://review.whamcloud.com/20940
Subject: LU-7117 osp: control RPC to be sent when recovery
Project: fs/lustre-release
Branch: master
Current Patch Set: 1
Commit: 5fb68c49af3fa08189110a4e980ad792efd7128b

[nasf (Inactive)]

no new RPCS (except update log redo) should be sent until the recovery is completed?

The MDT0 is in recovery, but MDT1 is normal, so the RPC from the client to MDT1 is not blocked.

[Bob Glossman (Inactive)]

another on master:
https://testing.hpdd.intel.com/test_sets/6a54094a-3a9e-11e6-a0ce-5254006e85c2

[Gerrit Updater]

Lai Siyao ([e-mail]) uploaded a new patch: http://review.whamcloud.com/21064
Subject: LU-7117 mdt: mdt unlink should lock before lookup
Project: fs/lustre-release
Branch: master
Current Patch Set: 1
Commit: 0ae3d50ed2745366f677b79586f3fe72645330ee

[Sebastien Buisson (Inactive)]

Another occurrence:
https://testing.hpdd.intel.com/test_sets/823971fa-433e-11e6-acf3-5254006e85c2

[Bruno Faccini (Inactive)]

+1 on master at https://testing.hpdd.intel.com/test_sets/79710324-49a3-11e6-a80f-5254006e85c2

[Sebastien Buisson (Inactive)]

A lot more occurrences recently, like this one on master:
https://testing.hpdd.intel.com/test_sets/4d6f9aea-4a09-11e6-8968-5254006e85c2

[Andreas Dilger]

How do the patches http://review.whamcloud.com/20940 "LU-7117 osp: control RPC to be sent when recovery" and http://review.whamcloud.com/21064 "LU-7117 mdt: mdt unlink should lock before lookup" relate to each other? Are they both needed? Are they different approaches to fixing the same problem, and only one is needed?

[Andreas Dilger]

Never mind, I see that http://review.whamcloud.com/21064 "LU-7117 mdt: mdt unlink should lock before lookup" is abandoned since it was landed as http://review.whamcloud.com/21088 via LU-8353.

[Gerrit Updater]

Oleg Drokin ([e-mail]) merged in patch http://review.whamcloud.com/20940/
Subject: LU-7117 osp: set ptlrpc_request::rq_allow_replay properly
Project: fs/lustre-release
Branch: master
Current Patch Set:
Commit: e3d507eec50fc1ff79acf2a9f93d52d698c887d7

[Peter Jones]

Landed for 2.9