[LU-11102] lock revoke may not take effect

• Type: Bug
• Resolution: Fixed
• Priority: Critical
• Fix Version/s: Lustre 2.12.0
• Affects Version/s: Lustre 2.10.0, Lustre 2.11.0
• Severity: 3
• Assignee: Lai Siyao
• Reporter: Lai Siyao

Description

Under some situations lock revoke may not take effect, suppose a concurrent setattr on a striped directory and rename under this directory:
1. setattr takes UPDATE lock of directory, but not unlock it yet (i.e., this lock is not downgraded to COS lock).
2. a concurrent 'mv' under this directory will first getattr file by name, this getattr will revoke UPDATE lock of this directory, since this getattr is not a distributed operation, this revoke does nothing.
3. setattr unlocks this UPDATE lock and downgrade it to COS mode, which notifies getattr that its lock is granted.
4. rename tries to lock UPDATE lock of this directory, but this lock was revoked before (though nothing did), it won't revoke again, rename will wait until setattr transaction commit.

Issue Links

• is related to: LU-11170 sanity test 415 fails with 'rename took N > M sec'
• is related to: LU-11270 Racer is stuck on ldlm lock
• is related to: LU-11082 stuck threads on MDS

Comments

[Gerrit Updater]

Andreas Dilger ([e-mail]) merged in patch https://review.whamcloud.com/32933/
Subject: LU-11102 test: test fewer files on ZFS system
Project: fs/lustre-release
Branch: master
Current Patch Set:
Commit: 7fc6eacc9bad7991932f3cd53fe7db8ad42a665e

[Lai Siyao]

https://testing.whamcloud.com/test_sets/36d6c354-969b-11e8-87f3-52540065bddc shows this test may fail on ZFS system, but the log shows everything is fine, maybe it's just slower on ZFS because this test triggers a lot of sync, so I add a patch to test with fewer files on ZFS system.

00000100:00100000:0.0:1533234765.487631:0:1111:0:(service.c:2179:ptlrpc_server_handle_request()) Handled RPC pname:cluuid+ref:pid:xid:nid:opc mdt00_004:2f34b462-f472-4056-b60b-b18d27585747+52:29420:x1607707738583120:12345-10.9.5.233@tcp:36 Request processed in 188518us (188545us total) trans 30064828518 rc 0/0
00000100:00100000:0.0:1533234767.038819:0:1111:0:(service.c:2179:ptlrpc_server_handle_request()) Handled RPC pname:cluuid+ref:pid:xid:nid:opc mdt00_004:2f34b462-f472-4056-b60b-b18d27585747+51:29425:x1607707738583376:12345-10.9.5.233@tcp:36 Request processed in 342118us (342149us total) trans 30064828525 rc 0/0
00000100:00100000:0.0:1533234780.768498:0:13204:0:(service.c:2179:ptlrpc_server_handle_request()) Handled RPC pname:cluuid+ref:pid:xid:nid:opc mdt00_005:2f34b462-f472-4056-b60b-b18d27585747+43:29457:x1607707738585616:12345-10.9.5.233@tcp:36 Request processed in 304782us (304807us total) trans 30064828581 rc 0/0
00000100:00100000:0.0:1533234783.263416:0:27386:0:(service.c:2179:ptlrpc_server_handle_request()) Handled RPC pname:cluuid+ref:pid:xid:nid:opc mdt00_002:2f34b462-f472-4056-b60b-b18d27585747+41:29466:x1607707738586192:12345-10.9.5.233@tcp:36 Request processed in 324538us (324557us total) trans 30064828595 rc 0/0
00000100:00100000:1.0:1533234784.844937:0:27386:0:(service.c:2179:ptlrpc_server_handle_request()) Handled RPC pname:cluuid+ref:pid:xid:nid:opc mdt00_002:2f34b462-f472-4056-b60b-b18d27585747+40:29470:x1607707738586448:12345-10.9.5.233@tcp:36 Request processed in 330485us (330510us total) trans 30064828602 rc 0/0
00000100:00100000:1.0:1533234785.995696:0:27386:0:(service.c:2179:ptlrpc_server_handle_request()) Handled RPC pname:cluuid+ref:pid:xid:nid:opc mdt00_002:2f34b462-f472-4056-b60b-b18d27585747+39:29474:x1607707738586704:12345-10.9.5.233@tcp:36 Request processed in 260063us (260092us total) trans 30064828609 rc 0/0
00000100:00100000:1.0:1533234786.611092:0:27386:0:(service.c:2179:ptlrpc_server_handle_request()) Handled RPC pname:cluuid+ref:pid:xid:nid:opc mdt00_002:2f34b462-f472-4056-b60b-b18d27585747+41:29476:x1607707738586832:12345-10.9.5.233@tcp:36 Request processed in 253504us (253534us total) trans 30064828612 rc 0/0
00000100:00100000:1.0:1533234787.789783:0:27386:0:(service.c:2179:ptlrpc_server_handle_request()) Handled RPC pname:cluuid+ref:pid:xid:nid:opc mdt00_002:2f34b462-f472-4056-b60b-b18d27585747+38:29481:x1607707738587152:12345-10.9.5.233@tcp:36 Request processed in 544241us (544269us total) trans 30064828619 rc 0/0
00000100:00100000:1.0:1533234789.474735:0:27386:0:(service.c:2179:ptlrpc_server_handle_request()) Handled RPC pname:cluuid+ref:pid:xid:nid:opc mdt00_002:2f34b462-f472-4056-b60b-b18d27585747+37:29485:x1607707738587408:12345-10.9.5.233@tcp:36 Request processed in 278538us (278567us total) trans 30064828626 rc 0/0
00000100:00100000:1.0:1533234790.474337:0:27386:0:(service.c:2179:ptlrpc_server_handle_request()) Handled RPC pname:cluuid+ref:pid:xid:nid:opc mdt00_002:2f34b462-f472-4056-b60b-b18d27585747+36:29489:x1607707738587664:12345-10.9.5.233@tcp:36 Request processed in 281511us (281540us total) trans 30064828633 rc 0/0
00000100:00100000:1.0:1533234791.552662:0:27386:0:(service.c:2179:ptlrpc_server_handle_request()) Handled RPC pname:cluuid+ref:pid:xid:nid:opc mdt00_002:2f34b462-f472-4056-b60b-b18d27585747+35:29493:x1607707738587920:12345-10.9.5.233@tcp:36 Request processed in 236237us (236258us total) trans 30064828640 rc 0/0
00000100:00100000:0.0:1533234792.903815:0:27386:0:(service.c:2179:ptlrpc_server_handle_request()) Handled RPC pname:cluuid+ref:pid:xid:nid:opc mdt00_002:2f34b462-f472-4056-b60b-b18d27585747+33:29499:x1607707738588368:12345-10.9.5.233@tcp:36 Request processed in 212071us (212102us total) trans 30064828651 rc 0/0
00000100:00100000:1.0:1533234793.704464:0:29335:0:(service.c:2179:ptlrpc_server_handle_request()) Handled RPC pname:cluuid+ref:pid:xid:nid:opc mdt00_003:2f34b462-f472-4056-b60b-b18d27585747+32:29503:x1607707738588624:12345-10.9.5.233@tcp:36 Request processed in 255002us (255020us total) trans 30064828658 rc 0/0
00000100:00100000:0.0:1533234795.052945:0:13204:0:(service.c:2179:ptlrpc_server_handle_request()) Handled RPC pname:cluuid+ref:pid:xid:nid:opc mdt00_005:2f34b462-f472-4056-b60b-b18d27585747+31:29507:x1607707738588880:12345-10.9.5.233@tcp:36 Request processed in 330962us (330981us total) trans 30064828665 rc 0/0
00000100:00100000:1.0:1533234795.933959:0:13204:0:(service.c:2179:ptlrpc_server_handle_request()) Handled RPC pname:cluuid+ref:pid:xid:nid:opc mdt00_005:2f34b462-f472-4056-b60b-b18d27585747+30:29511:x1607707738589136:12345-10.9.5.233@tcp:36 Request processed in 281057us (281076us total) trans 30064828672 rc 0/0
00000100:00100000:0.0:1533234799.414898:0:13204:0:(service.c:2179:ptlrpc_server_handle_request()) Handled RPC pname:cluuid+ref:pid:xid:nid:opc mdt00_005:2f34b462-f472-4056-b60b-b18d27585747+29:29515:x1607707738589456:12345-10.9.5.233@tcp:36 Request processed in 1534920us (1534949us total) trans 30064828679 rc 0/0
00000100:00100000:1.0:1533234799.814291:0:13204:0:(service.c:2179:ptlrpc_server_handle_request()) Handled RPC pname:cluuid+ref:pid:xid:nid:opc mdt00_005:2f34b462-f472-4056-b60b-b18d27585747+31:29517:x1607707738589584:12345-10.9.5.233@tcp:36 Request processed in 242121us (242147us total) trans 30064828683 rc 0/0
00000100:00100000:1.0:1533234800.933214:0:13204:0:(service.c:2179:ptlrpc_server_handle_request()) Handled RPC pname:cluuid+ref:pid:xid:nid:opc mdt00_005:2f34b462-f472-4056-b60b-b18d27585747+28:29521:x1607707738589840:12345-10.9.5.233@tcp:36 Request processed in 275937us (275980us total) trans 30064828689 rc 0/0
00000100:00100000:1.0:1533234802.446459:0:13204:0:(service.c:2179:ptlrpc_server_handle_request()) Handled RPC pname:cluuid+ref:pid:xid:nid:opc mdt00_005:2f34b462-f472-4056-b60b-b18d27585747+27:29525:x1607707738590096:12345-10.9.5.233@tcp:36 Request processed in 675885us (675913us total) trans 30064828696 rc 0/0
00000100:00100000:0.0:1533234803.561883:0:29335:0:(service.c:2179:ptlrpc_server_handle_request()) Handled RPC pname:cluuid+ref:pid:xid:nid:opc mdt00_003:2f34b462-f472-4056-b60b-b18d27585747+26:29529:x1607707738590416:12345-10.9.5.233@tcp:36 Request processed in 182042us (182076us total) trans 30064828703 rc 0/0
00000100:00100000:0.0:1533234805.587818:0:21305:0:(service.c:2179:ptlrpc_server_handle_request()) Handled RPC pname:cluuid+ref:pid:xid:nid:opc mdt00_009:2f34b462-f472-4056-b60b-b18d27585747+25:29533:x1607707738590672:12345-10.9.5.233@tcp:36 Request processed in 240344us (240363us total) trans 30064828710 rc 0/0


00000080:00200000:1.0:1533234793.012979:0:29503:0:(namei.c:1585:ll_rename()) VFS Op:oldname=f415.sanity.483, src_dir=[0x2c00013a6:0xc:0x0](ffff9ce7d429ad90), newname=f415.sanity-new.483, tgt_dir=[0x2c00013a6:0xc:0x0](ffff9ce7d429ad90)
00000080:00200000:0.0:1533234793.595477:0:29505:0:(namei.c:1585:ll_rename()) VFS Op:oldname=f415.sanity.484, src_dir=[0x2c00013a6:0xc:0x0](ffff9ce7d429ad90), newname=f415.sanity-new.484, tgt_dir=[0x2c00013a6:0xc:0x0](ffff9ce7d429ad90)
00000080:00200000:0.0:1533234794.285507:0:29507:0:(namei.c:1585:ll_rename()) VFS Op:oldname=f415.sanity.485, src_dir=[0x2c00013a6:0xc:0x0](ffff9ce7d429ad90), newname=f415.sanity-new.485, tgt_dir=[0x2c00013a6:0xc:0x0](ffff9ce7d429ad90)
00000080:00200000:1.0:1533234794.717644:0:29509:0:(namei.c:1585:ll_rename()) VFS Op:oldname=f415.sanity.486, src_dir=[0x2c00013a6:0xc:0x0](ffff9ce7d429ad90), newname=f415.sanity-new.486, tgt_dir=[0x2c00013a6:0xc:0x0](ffff9ce7d429ad90)
00000080:00200000:1.0:1533234795.216400:0:29511:0:(namei.c:1585:ll_rename()) VFS Op:oldname=f415.sanity.487, src_dir=[0x2c00013a6:0xc:0x0](ffff9ce7d429ad90), newname=f415.sanity-new.487, tgt_dir=[0x2c00013a6:0xc:0x0](ffff9ce7d429ad90)
00000080:00200000:0.0:1533234795.786463:0:29513:0:(namei.c:1585:ll_rename()) VFS Op:oldname=f415.sanity.488, src_dir=[0x2c00013a6:0xc:0x0](ffff9ce7d429ad90), newname=f415.sanity-new.488, tgt_dir=[0x2c00013a6:0xc:0x0](ffff9ce7d429ad90)
00000080:00200000:0.0:1533234797.443481:0:29515:0:(namei.c:1585:ll_rename()) VFS Op:oldname=f415.sanity.489, src_dir=[0x2c00013a6:0xc:0x0](ffff9ce7d429ad90), newname=f415.sanity-new.489, tgt_dir=[0x2c00013a6:0xc:0x0](ffff9ce7d429ad90)
00000080:00200000:0.0:1533234799.135678:0:29517:0:(namei.c:1585:ll_rename()) VFS Op:oldname=f415.sanity.490, src_dir=[0x2c00013a6:0xc:0x0](ffff9ce7d429ad90), newname=f415.sanity-new.490, tgt_dir=[0x2c00013a6:0xc:0x0](ffff9ce7d429ad90)
00000080:00200000:0.0:1533234799.604788:0:29519:0:(namei.c:1585:ll_rename()) VFS Op:oldname=f415.sanity.491, src_dir=[0x2c00013a6:0xc:0x0](ffff9ce7d429ad90), newname=f415.sanity-new.491, tgt_dir=[0x2c00013a6:0xc:0x0](ffff9ce7d429ad90)
00000080:00200000:0.0:1533234800.220776:0:29521:0:(namei.c:1585:ll_rename()) VFS Op:oldname=f415.sanity.492, src_dir=[0x2c00013a6:0xc:0x0](ffff9ce7d429ad90), newname=f415.sanity-new.492, tgt_dir=[0x2c00013a6:0xc:0x0](ffff9ce7d429ad90)
00000080:00200000:1.0:1533234800.721058:0:29523:0:(namei.c:1585:ll_rename()) VFS Op:oldname=f415.sanity.493, src_dir=[0x2c00013a6:0xc:0x0](ffff9ce7d429ad90), newname=f415.sanity-new.493, tgt_dir=[0x2c00013a6:0xc:0x0](ffff9ce7d429ad90)
00000080:00200000:1.0:1533234801.334046:0:29525:0:(namei.c:1585:ll_rename()) VFS Op:oldname=f415.sanity.494, src_dir=[0x2c00013a6:0xc:0x0](ffff9ce7d429ad90), newname=f415.sanity-new.494, tgt_dir=[0x2c00013a6:0xc:0x0](ffff9ce7d429ad90)
00000080:00200000:1.0:1533234802.226146:0:29527:0:(namei.c:1585:ll_rename()) VFS Op:oldname=f415.sanity.495, src_dir=[0x2c00013a6:0xc:0x0](ffff9ce7d429ad90), newname=f415.sanity-new.495, tgt_dir=[0x2c00013a6:0xc:0x0](ffff9ce7d429ad90)
00000080:00200000:0.0:1533234802.943331:0:29529:0:(namei.c:1585:ll_rename()) VFS Op:oldname=f415.sanity.496, src_dir=[0x2c00013a6:0xc:0x0](ffff9ce7d429ad90), newname=f415.sanity-new.496, tgt_dir=[0x2c00013a6:0xc:0x0](ffff9ce7d429ad90)
00000080:00200000:0.0:1533234803.710463:0:29531:0:(namei.c:1585:ll_rename()) VFS Op:oldname=f415.sanity.497, src_dir=[0x2c00013a6:0xc:0x0](ffff9ce7d429ad90), newname=f415.sanity-new.497, tgt_dir=[0x2c00013a6:0xc:0x0](ffff9ce7d429ad90)
00000080:00200000:0.0:1533234804.911002:0:29533:0:(namei.c:1585:ll_rename()) VFS Op:oldname=f415.sanity.498, src_dir=[0x2c00013a6:0xc:0x0](ffff9ce7d429ad90), newname=f415.sanity-new.498, tgt_dir=[0x2c00013a6:0xc:0x0](ffff9ce7d429ad90)
00000080:00200000:1.0:1533234805.698636:0:29535:0:(namei.c:1585:ll_rename()) VFS Op:oldname=f415.sanity.499, src_dir=[0x2c00013a6:0xc:0x0](ffff9ce7d429ad90), newname=f415.sanity-new.499, tgt_dir=[0x2c00013a6:0xc:0x0](ffff9ce7d429ad90)


00000080:00200000:1.0:1533234792.933728:0:29502:0:(llite_lib.c:1589:ll_setattr_raw()) lustre: setattr inode [0x2c00013a6:0xc:0x0](ffff9ce7d429ad90) from 11264 to 131290, valid 20070, hsm_import 0
00000080:00200000:0.0:1533234793.268569:0:29504:0:(llite_lib.c:1589:ll_setattr_raw()) lustre: setattr inode [0x2c00013a6:0xc:0x0](ffff9ce7d429ad90) from 11264 to 131290, valid 20070, hsm_import 0
00000080:00200000:0.0:1533234794.029610:0:29506:0:(llite_lib.c:1589:ll_setattr_raw()) lustre: setattr inode [0x2c00013a6:0xc:0x0](ffff9ce7d429ad90) from 11264 to 131290, valid 20070, hsm_import 0
00000080:00200000:1.0:1533234794.617157:0:29508:0:(llite_lib.c:1589:ll_setattr_raw()) lustre: setattr inode [0x2c00013a6:0xc:0x0](ffff9ce7d429ad90) from 11264 to 131290, valid 20070, hsm_import 0
00000080:00200000:0.0:1533234794.956394:0:29510:0:(llite_lib.c:1589:ll_setattr_raw()) lustre: setattr inode [0x2c00013a6:0xc:0x0](ffff9ce7d429ad90) from 11264 to 131290, valid 20070, hsm_import 0
00000080:00200000:0.0:1533234795.498048:0:29512:0:(llite_lib.c:1589:ll_setattr_raw()) lustre: setattr inode [0x2c00013a6:0xc:0x0](ffff9ce7d429ad90) from 11264 to 131290, valid 20070, hsm_import 0
00000080:00200000:0.0:1533234795.994119:0:29514:0:(llite_lib.c:1589:ll_setattr_raw()) lustre: setattr inode [0x2c00013a6:0xc:0x0](ffff9ce7d429ad90) from 11264 to 131290, valid 20070, hsm_import 0
00000080:00200000:1.0:1533234798.979155:0:29516:0:(llite_lib.c:1589:ll_setattr_raw()) lustre: setattr inode [0x2c00013a6:0xc:0x0](ffff9ce7d429ad90) from 11264 to 131290, valid 20070, hsm_import 0
00000080:00200000:0.0:1533234799.379232:0:29518:0:(llite_lib.c:1589:ll_setattr_raw()) lustre: setattr inode [0x2c00013a6:0xc:0x0](ffff9ce7d429ad90) from 11264 to 131290, valid 20070, hsm_import 0
00000080:00200000:1.0:1533234799.703506:0:29520:0:(llite_lib.c:1589:ll_setattr_raw()) lustre: setattr inode [0x2c00013a6:0xc:0x0](ffff9ce7d429ad90) from 11264 to 131290, valid 20070, hsm_import 0
00000080:00200000:1.0:1533234800.497299:0:29522:0:(llite_lib.c:1589:ll_setattr_raw()) lustre: setattr inode [0x2c00013a6:0xc:0x0](ffff9ce7d429ad90) from 11264 to 131290, valid 20070, hsm_import 0
00000080:00200000:0.0:1533234800.942789:0:29524:0:(llite_lib.c:1589:ll_setattr_raw()) lustre: setattr inode [0x2c00013a6:0xc:0x0](ffff9ce7d429ad90) from 11264 to 131290, valid 20070, hsm_import 0
00000080:00200000:0.0:1533234802.010655:0:29526:0:(llite_lib.c:1589:ll_setattr_raw()) lustre: setattr inode [0x2c00013a6:0xc:0x0](ffff9ce7d429ad90) from 11264 to 131290, valid 20070, hsm_import 0
00000080:00200000:0.0:1533234802.362924:0:29528:0:(llite_lib.c:1589:ll_setattr_raw()) lustre: setattr inode [0x2c00013a6:0xc:0x0](ffff9ce7d429ad90) from 11264 to 131290, valid 20070, hsm_import 0
00000080:00200000:1.0:1533234803.126157:0:29530:0:(llite_lib.c:1589:ll_setattr_raw()) lustre: setattr inode [0x2c00013a6:0xc:0x0](ffff9ce7d429ad90) from 11264 to 131290, valid 20070, hsm_import 0
00000080:00200000:1.0:1533234804.268186:0:29532:0:(llite_lib.c:1589:ll_setattr_raw()) lustre: setattr inode [0x2c00013a6:0xc:0x0](ffff9ce7d429ad90) from 11264 to 131290, valid 20070, hsm_import 0
00000080:00200000:1.0:1533234805.151920:0:29534:0:(llite_lib.c:1589:ll_setattr_raw()) lustre: setattr inode [0x2c00013a6:0xc:0x0](ffff9ce7d429ad90) from 11264 to 131290, valid 20070, hsm_import 0
00000080:00200000:0.0:1533234805.854663:0:29536:0:(llite_lib.c:1589:ll_setattr_raw()) lustre: setattr inode [0x2c00013a6:0xc:0x0](ffff9ce7d429ad90) from 11264 to 131290, valid 20070, hsm_import 0
00000080:00200000:1.0:1533234806.508497:0:29538:0:(llite_lib.c:1589:ll_setattr_raw()) lustre: setattr inode [0x2c00013a6:0xc:0x0](ffff9ce7d429ad90) from 11264 to 131290, valid 20070, hsm_import 0

[Gerrit Updater]

Lai Siyao ([e-mail]) uploaded a new patch: https://review.whamcloud.com/32933
Subject: LU-11102 test: test fewer files on ZFS system
Project: fs/lustre-release
Branch: master
Current Patch Set: 1
Commit: 5c0c5e45ea9e3d9283ab389643f6593c96a211ad

[Gerrit Updater]

Lai Siyao ([e-mail]) uploaded a new patch: https://review.whamcloud.com/32923
Subject: LU-11102 ldlm: run local lock bl_ast only when necessary
Project: fs/lustre-release
Branch: b2_10
Current Patch Set: 1
Commit: 347be4f8fb89edf526df85a299f84842d61f04e2

[Peter Jones]

Landed for 2.12

[Gerrit Updater]

Oleg Drokin ([e-mail]) merged in patch https://review.whamcloud.com/32738/
Subject: LU-11102 ldlm: run local lock bl_ast only when necessary
Project: fs/lustre-release
Branch: master
Current Patch Set:
Commit: 954cc6754b19a5eb4b9f717f79037c40baa87f3f

[Peter Jones]

https://review.whamcloud.com/#/c/32738/