[LU-2285] Test failure on replay-ost-single test_3: write page inode failed -2

• Type: Bug
• Resolution: Cannot Reproduce
• Priority: Major
• Affects Version/s: Lustre 2.4.0
• Severity: 3
• Assignee: Li Wei (Inactive)
• Reporter: Maloo

Description

This issue was created by maloo for Oleg Drokin <[e-mail]>

This issue relates to the following test suite run: https://maloo.whamcloud.com/test_sets/70b83f68-2797-11e2-9e20-52540035b04c.

The sub-test test_3 failed with the following error:

test_3 failed with 1

on client we can see in dmesg that the write actually failed.

Lustre: DEBUG MARKER: /usr/sbin/lctl mark == replay-ost-single test 3: Fail OST during write, with verification ================================ 12:42:29 \(1352148149\)
Lustre: DEBUG MARKER: == replay-ost-single test 3: Fail OST during write, with verification ================================ 12:42:29 (1352148149)
LustreError: 17578:0:(vvp_io.c:1037:vvp_io_commit_write()) Write page 11 of inode ffff81031f41fb28 failed -2
Lustre: DEBUG MARKER: /usr/sbin/lctl mark  replay-ost-single test_3: @@@@@@ FAIL: test_3 failed with 1 

Info required for matching: replay-ost-single 3

Issue Links

• is duplicated by: LU-2493 osp_precreate.c:781:osp_precreate_get_id()) ASSERTION( d->opd_pre_used_id < d->opd_pre_last_created )
• is related to: LU-9588 replay-ost-single test cases 3 remove from ALWAYS_EXCEPT
• is related to: LU-2832 Test failure on test suite replay-ost-single test_3: ost_write failure -19

Comments

[Li Wei (Inactive)]

An update on the patches as of Dec 22:

http://review.whamcloud.com/4668 (Debug messages) Landed.
http://review.whamcloud.com/4511 (Orphan cleanup from correct ID) Landed.
http://review.whamcloud.com/4625 (opd_pre_last_created) Landed.
http://review.whamcloud.com/4590 (Block allocation during orphan cleanups) Landed.
http://review.whamcloud.com/4610 (New regression test) Being refreshed.

[Alex Zhuravlev]

> The new test. Still a bit real-time dependent.

there are a lot of tests depending on time already. all the 40-46 in sanityn, for example.

[Li Wei (Inactive)]

http://review.whamcloud.com/4610

The new test. Still a bit real-time dependent.

[Alex Zhuravlev]

look at something like:

/* This will trigger a watchdog timeout */
OBD_FAIL_TIMEOUT(OBD_FAIL_MDS_STATFS_LCW_SLEEP,
(MDT_SERVICE_WATCHDOG_FACTOR *
at_get(&svcpt->scp_at_estimate)) + 1);

[Li Wei (Inactive)]

It is tricky to make sure the file creation (osp_precreate_reserve() and osp_precreate_get_id()) happens after osp_precreate_cleanup_orphans() has read opd_last_used_id and before the orphan cleanup RPC is replied.

[Alex Zhuravlev]

hmm, why is it tricky? basically we want non-empty pool in a specific OSP, then stop corresponded OST, wait till MDS got disconnected and try to create on using that specific OST ?

[Li Wei (Inactive)]

The new test is a bit tricky to get right, but here is a proof-of-concept fix for the major issue: http://review.whamcloud.com/4590.

[Alex Zhuravlev]

no, I think the problem is there and it's more serious than you described. basically there should be no reservations/allocations done during orphan cleanup procedure. so I'm suggesting to develop a test reproducing this at first.

[Li Wei (Inactive)]

Alex, are you suggesting there is no problem needs to be fixed with regard to the race? But I don't get how existing code block allocations during orphan deletions.

[Alex Zhuravlev]

I'd suggest to develop a test which block orphan cleanup procedure on OST and force MDS to allocate pre-created object. the race you described seem to be a subset of general case where any object allocation should be blocked during orphan cleanup procedure.

[Li Wei (Inactive)]

The file creation was satisfied from the pre-created pool without waiting for a pre-creation RPC. The race I was trying to point out is between osp_precreate_get_id() and osp_precreate_cleanup_orphans(). The latter sends on-disk last used IDs to OSTs, while osp_precreate_get_id() increments in-memory last used IDs. Hence, the race may cause the object IDs assigned based on pre-OST-failure counters to be destroyed by the concurrent orphan deletion request. The log shows that this happens.

If osp_precreate_cleanup_orphans() sends in-memory last used IDs instead, this problem would go away, I think. Of course, we need to make sure in-memory last used IDs are properly initialized with their on-disk counterparts before the initial orphan deletions. I haven't tried this yet. Any objections?