CephFS.mgr(vfs): Failures in smb2 sharemode, rename, deny, lock and rw test suites

[Shwetha-Acharya]

There are some unrelated failures in #82:

cephfs.mgr.vfs:

failure: samba3.smb2.deny.deny2 [
Exception: ../../source4/torture/smb2/deny.c:486: Expression `res == denytable[i].result' failed: Result RW did not match deny table -]

gpfs.scale:

failure: samba3.smb2.lock.replay_smb3_specification_durable [
Exception: ../../source4/torture/smb2/lock.c:3206: io.out.durable_open was 0 (0x0), expected 1 (0x1): (../../source4/torture/smb2/lock.c:3206)]

gpfs.vfs:

failure: samba3.smb2.lock.replay_smb3_specification_durable [
Exception: ../../source4/torture/smb2/lock.c:3206: io.out.durable_open was 0 (0x0), expected 1 (0x1): (../../source4/torture/smb2/lock.c:3206)]

[anoopcs9]

There are some unrelated failures in #82:

cephfs.mgr.vfs:

failure: samba3.smb2.deny.deny2 [ Exception: ../../source4/torture/smb2/deny.c:486: Expression `res == denytable[i].result' failed: Result RW did not match deny table -]

There are other failures mostly leading to a common pattern and is currently under investigation(mostly by me).

We have been noticing these failures as soon as we started running the full test-suite against shares configured by ceph smb mgr module. It's just that I didn't manage to file an issue officially. Thanks for creating an umbrella tracker.

gpfs.scale:

failure: samba3.smb2.lock.replay_smb3_specification_durable [ Exception: ../../source4/torture/smb2/lock.c:3206: io.out.durable_open was 0 (0x0), expected 1 (0x1): (../../source4/torture/smb2/lock.c:3206)]

gpfs.vfs:

failure: samba3.smb2.lock.replay_smb3_specification_durable [ Exception: ../../source4/torture/smb2/lock.c:3206: io.out.durable_open was 0 (0x0), expected 1 (0x1): (../../source4/torture/smb2/lock.c:3206)]

We've had more failures with GPFS related tests for a while and never bothered to try looking into it. I can only expect them to be untouched for a while.

[anoopcs9]

smb2.sharemode

test: samba3.smb2.sharemode.sharemode-access
time: 2024-08-27 02:29:47.157429Z
index 0, sharemode R, access mask 0x000001
index 1, sharemode R, access mask 0x000002
time: 2024-08-27 02:29:47.345800Z
failure: samba3.smb2.sharemode.sharemode-access [
Exception: ../../source4/torture/smb2/sharemode.c:524: status was NT_STATUS_OK, expected NT_STATUS_SHARING_VIOLATION: Unexpected status on second create.
]
test: samba3.smb2.sharemode.access-sharemode
time: 2024-08-27 02:29:47.345840Z
index 0, access mask 0x000001, sharemode R
index 1, access mask 0x000002, sharemode R
time: 2024-08-27 02:29:47.528613Z
failure: samba3.smb2.sharemode.access-sharemode [
Exception: ../../source4/torture/smb2/sharemode.c:606: status was NT_STATUS_OK, expected NT_STATUS_SHARING_VIOLATION: Unexpected status on second create.
]

smb2.rename

test: samba3.smb2.rename.close-full-information
time: 2024-08-27 02:30:12.461403Z
time: 2024-08-27 02:30:12.630714Z
failure: samba3.smb2.rename.close-full-information [
Exception: (../../source4/torture/smb2/rename.c:1654) Incorrect status NT_STATUS_NOT_FOUND - should be NT_STATUS_OK
]

smb2.deny

test: samba3.smb2.deny.deny2
time: 2024-08-27 02:30:15.733230Z
31: denytest2.exe NTCREATEX_SHARE_ACCESS_NONE SEC_FILE_READ_DATA|SEC_FILE_WRITE_DATA NTCREATEX_SHARE_ACCESS_NONE SEC_FILE_READ_DATA|SEC_FILE_WRITE_DATA RW (correct=-)
time: 2024-08-27 02:30:15.951926Z
failure: samba3.smb2.deny.deny2 [
Exception: ../../source4/torture/smb2/deny.c:486: Expression `res == denytable[i].result' failed: Result RW did not match deny table -
]

smb2.lock

test: samba3.smb2.lock.overlap
time: 2024-08-27 02:30:18.237972Z
Testing overlapping locks:
the same session/handle cannot set overlapping exclusive locks
the same session/handle can set overlapping shared locks
** a different session can set overlapping exclusive locks
a different session can set overlapping shared locks
a different handle cannot set overlapping exclusive locks
a different handle can set overlapping shared locks
the same handle cannot coalesce read locks
the server doesn't have the NT byte range lock bug
time: 2024-08-27 02:30:18.489324Z
failure: samba3.smb2.lock.overlap [
Exception: ../../source4/torture/smb2/lock.c:2732: subtest failed
]

smb2.rw

test: samba3.smb2.rw.rw1
time: 2024-08-27 02:30:52.531417Z
Checking data integrity over 10 ops
time: 2024-08-27 02:30:52.774210Z
failure: samba3.smb2.rw.rw1 [
Exception: ../../source4/torture/smb2/read_write.c:136: status was NT_STATUS_NOT_FOUND, expected NT_STATUS_OK: close failed (NT_STATUS_NOT_FOUND)
]

Above failures are not seen with shares(using vfs_ceph) setup outside ceph smb mgr module.

[anoopcs9]

Finally, almost an year later, I had a break through 😮‍💨 . I noticed that root user (from passdb added via smbpasswd) never had the mentioned failures and this was the trigger to look around the following log entries:

share_mode_entry_prepare_lock_fn: get_share_mode_lock_internal failed: NT_STATUS_NOT_FOUND
close_remove_share_mode: share_mode_entry_prepare_lock_del() failed for torture2.lck - NT_STATUS_NOT_FOUND

Combining it with the testparm warning, all we have to do is to modify the permissions for /var/lib/samba so that all configured users have access to whatever tdbs they are allowed to look for.

See ceph/ceph#64454 for some details.

[anoopcs9]

Detailed RCA (based on failure for smb2.rw.rw1):

test: samba3.smb2.rw.rw1
time: 2024-08-27 02:30:52.531417Z
Checking data integrity over 10 ops
time: 2024-08-27 02:30:52.774210Z
failure: samba3.smb2.rw.rw1 [
Exception: ../../source4/torture/smb2/read_write.c:136: status was NT_STATUS_NOT_FOUND, expected NT_STATUS_OK: close failed (NT_STATUS_NOT_FOUND)
]

In the flow of requests inside smb2.rw.rw1, it initially creates a file with SEC_FILE_ALL (consider RDWR) and further opens it with SEC_FILE_READ_DATA (consider RDONLY) from a second tree connect. During the second open we check for any existing share mode entries from locking.tdb and it finds the RDWR handle. Now there's a check to make sure that the existing entry is not stale based on the corresponding server_id (which includes pid and unique_id among others) for the entry. This server_id existence is verified in two steps:

1. Check by issuing kill(pid, 0) to the pid itself.
2. If the process exists, read the unique_id already present in the corresponding lockfile named with the pid.

Here is where the internal failure happens. lockfile in this case is something that gets created under <lock directory>/msg.lock/<pid> with a specially crafted content when a particular smbd process appears on a host. <lock directory> is explicitly set to /var/lib/samba/lock for RPM builds using --with-lockdir in configure stage and with smb mgr module the default permissions (0755) for /var/lib/samba are overwritten (0770). Thus an attempt to open the lockfile fails with EACCES because smbd is already impersonated as the user and not root. Finally this ends up removing the existing entry assuming the client is no longer valid. Thereon the new entry is made and read-write phase is successfully completed. When it tries to close the first handle, the corresponding share mode entry is absent (which got removed during second open) and NT_STATUS_NOT_FOUND is returned.

[anoopcs9]

ceph/ceph#64454 is merged, closing the issue.