[LU-10457] open_by_handle_at() in write mode triggers ETXTBSY

• Type: Bug
• Resolution: Duplicate
• Priority: Major
• Severity: 3
• Assignee: Oleg Drokin
• Reporter: Diego Moreno (Inactive)

Description

If open_by_handle_at() is called in O_WRONLY or O_RDWR mode and then the file descriptor is closed, other lustre clients will still report ETXTBSY.

Example:

On cn16
=======
bschubert@cn16 ~>sudo ~/src/test/open-test /mnt/lustre_client-ES24/bschubert/ime/test7 1
Opened /mnt/lustre_client-ES24/bschubert/ime/test7/test7, fd: 4
Closed d: 4

Now on cn41
=========
bschubert@cn41 ~>/mnt/lustre_client-ES24/bschubert/ime//test7
-bash: /mnt/lustre_client-ES24/bschubert/ime//test7: Text file busy

test7 is just any file which has the the execution bit set.

Issue Links

• duplicates: LU-8585 All Lustre test suites should pass with subdirectory mount
• is duplicated by: LU-10667 Open by handle and normal open results in incorrect ETXTBSY behavior
• is related to: LU-12661 sanity test_817: FAIL: failed to execute 'true' command
• is related to: LU-4398 mdt_object_open_lock() may not flush conflicting handles

Comments

[Li Xi (Inactive)]

> Which Lustre version is this with? 

I was testing on master branch. I guess you are using IEEL3 (2.7)? Something might have been changed between them.

[John Hammond]

This is resolved by https://review.whamcloud.com/#/c/9063/ (LU-4398 mdt: acquire an open lock for write or execute). But that change was reverted from master due to the metadata performance impact described by DDN in LU-5197.

Perhaps the exiting functionality of open leases could be used in the open by handle path to address this issue without incurring the performance drop.

[Oleg Drokin]

Please note that /mnt/lustre and /mnt/lustre 2 are different mountpoints, so they act the same as two different nodes, just more convenient to test.

[Bernd Schubert]

Ah, actually Li was also using two different nodes. Sorry, I only saw server17-el7 and didn't notice the differentiation between -vm1 and -vm3.

Which Lustre version is this with? On the systems I tested with, it would never succeed to execute on the other node, until either

• the node the had opened the file would execute it itself
• the node the had opened the file would unmount lustre
• I would be patient and wait for a very long time (> 30min)

[Bernd Schubert]

Hmm, I can't imagine how that this works as it is supposed to, even in the NFS case. Maybe I should have pointed this out in more detail, but in my initial example I used two different nodes.
For NFS or any other overlay file system, one can expect that there are multiple nodes involved. For NFS users typically would create/modify files on their desktop to later on execute them natively on Lustre.
For the IME use case, the file is opened for multiple reasons in RW mode on the ime server, but users also later on want to use the files natively on Lustre.

[Oleg Drokin]

I guess I did not read it far enough, yes there's one ETXTBUSY report due to the open lock.

it appears that the name_to_handle_at/open_by_handle_at use nfs-encoded export operation leading to the nfs detecting logic to trigger so the system sort of operates as designed.

It's going to be tricky to separate real nfs from these users I guess and we don't want the extra lock hit when opening the file. I guess the new downgrade logic might help us here to get a bigger lock and then just drop the unneeded bit.

[Oleg Drokin]

Hm, I tested this on the latest master on rhel7.2 (disregard the centos6 in the hostname) and don't see any problems, what version are you testing on, what kernel:

[root@centos6-16 tests]# cat /tmp/test.sh
#!/bin/bash

cp /bin/ls /mnt/lustre
/mnt/lustre/ls -ld .
/tmp/open-test /mnt/lustre/ls 2

TIME=0
while ! /mnt/lustre2/ls -ld . ; do echo nope ; TIME=$((TIME + 1)) ; sleep 1 ; done

echo Waited $TIME seconds for the open to clear
[root@centos6-16 tests]# bash /tmp/test.sh
drwxrwxr-x 12 green green 12288 Jan  4 01:37 .
Opened /mnt/lustre/ls/ls, fd: 4
Closed d: 4
/tmp/test.sh: line 8: /mnt/lustre2/ls: Text file busy
nope
drwxrwxr-x 12 green green 12288 Jan  4 01:37 .
Waited 1 seconds for the open to clear

[Li Xi (Inactive)]

The open-test get the LDLM lock when opening file because ldd->lld_nfs_dentry is set to 1 in ll_iget_for_nfs().

 

[Li Xi (Inactive)]

So following things happend in sequence:

1. open-test got LDLM lock of the file ./test
2. open-test closed the file, yet do not call ll_md_real_close() because holding the LDLM lock
3. ./test program tried to open the file with EXEC yet got -ETXTBUSY in mdt_write_deny()
4. The mdt_blocking_ast() was triggered, it cancels of the LDLM lock got by open-test program, and mdt_mfd_close()/mdt_write_put() is called to release the reference
5. The next run of open-test can succeed because of step 4.

[Li Xi (Inactive)]

When open-test closing the file, no mdt_mfd_close() is called on MDS side. And the trace on client side confirmed that  ll_md_close() dosn't call ll_md_real_close() because md_lock_match() returns 8. So, this program holds some LDLM lock when closing?

00000002:00000001:0.0:1515116985.549766:0:22146:0:(mdc_locks.c:149:mdc_lock_match()) Process leaving (rc=8 : 8 : 8)
00800000:00000001:0.0:1515116985.549766:0:22146:0:(obd_class.h:1740:md_lock_match()) Process leaving (rc=8 : 8 : 8)
00800000:00000001:0.0:1515116985.549767:0:22146:0:(lmv_obd.c:2965:lmv_lock_match()) Process leaving (rc=8 : 8 : 8)
00000080:00000001:0.0:1515116985.549768:0:22146:0:(obd_class.h:1740:md_lock_match()) Process leaving (rc=8 : 8 : 8)
00000080:00000001:0.0:1515116985.549771:0:22146:0:(file.c:314:ll_md_close()) Process leaving (rc=0 : 0 : 0)

[Li Xi (Inactive)]

As expected, mdt_write_deny() returns -ETXTBUSY when the failure happens

 
00000004:00000001:0.0:1515116333.246172:0:12336:0:(mdt_open.c:342:mdt_mfd_open()) Process entered
00000004:00000001:0.0:1515116333.246173:0:12336:0:(mdt_open.c:174:mdt_write_deny()) Process entered
00000004:00000001:0.0:1515116333.246174:0:12336:0:(mdt_open.c:181:mdt_write_deny()) Process leaving (rc=18446744073709551590 : -26 : ffffffffffffffe6)
00000004:00000001:0.0:1515116333.246175:0:12336:0:(mdt_open.c:391:mdt_mfd_open()) Process leaving (rc=18446744073709551590 : -26 : ffffffffffffffe6)
00000004:00000001:0.0:1515116333.246176:0:12336:0:(mdt_open.c:615:mdt_finish_open()) Process leaving (rc=18446744073709551590 : -26 : ffffffffffffffe6)
00000004:00000001:0.0:1515116333.246178:0:12336:0:(mdt_open.c:1589:mdt_reint_open()) Process leaving