I do not understand the kernel behavior reflected in this trace
output. For fd 3 (principal.ok), we see:
fcntl64(3, F_OFD_SETLKW, {l_type=F_WRLCK, l_whence=SEEK_SET, l_start=0,
l_len=6950411022381350912}) = -1 EINVAL (Invalid argument)
fcntl64(3, F_SETLKW, {l_type=F_WRLCK, l_whence=SEEK_SET, l_start=0, l_len=0}) = 0
fcntl64(3, F_OFD_SETLKW, {l_type=F_UNLCK, l_whence=SEEK_SET, l_start=0,
l_len=6950411022381350912}) = 0
fcntl64(3, F_OFD_SETLKW, {l_type=F_WRLCK, l_whence=SEEK_SET, l_start=0,
l_len=6950411022381350912}
So it tries to acquire an OFD lock and fails, then falls back to a POSIX
lock. When it releases the lock, releasing it as an OFD lock succeeds,
so it doesn't fall back to releasing a POSIX lock. It then tries to
acquire an OFD lock and deadlocks against its POSIX lock.
For fd 5 (kadm5.lock), it also falls back to acquiring a POSIX lock.
Releasing the lock as an OFD lock fails, so it correctly falls back to
releasing its POSIX lock:
fcntl64(5, F_OFD_SETLKW, {l_type=F_WRLCK, l_whence=SEEK_SET, l_start=0,
l_len=6950411022381350912}) = -1 EINVAL (Invalid argument)
fcntl64(5, F_SETLKW, {l_type=F_WRLCK, l_whence=SEEK_SET, l_start=0, l_len=0}) = 0
fcntl64(5, F_OFD_SETLKW, {l_type=F_UNLCK, l_whence=SEEK_SET, l_start=0,
l_len=6950411022381350912}) = -1 EINVAL (Invalid argument)
fcntl64(5, F_SETLKW, {l_type=F_UNLCK, l_whence=SEEK_SET, l_start=0, l_len=0}) = 0
>From the code, l_len should clearly be 0 (see lib/krb5/os/lock_file.c
line 131), but strace is displaying a large number instead. I don't
know if this is an strace display bug or something else, and whether it
is related to the EINVAL results. The large value appears in both
successful and failed F_OFD_SETLKW/F_UNLCK calls.