linux-kernel - Re: Several tst-robust* tests time out with recent Linux kernel

lists.openwall.net		lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC
Open Source and information security mailing list archives

Hash Suite: Windows password security audit tool. GUI, reports in PDF.

[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]

Message-ID: <fc3fd07a-218d-406c-918b-e7f701968eb0@linux.ibm.com>
Date: Fri, 19 Jan 2024 14:56:10 +0100
From: Stefan Liebler <stli@...ux.ibm.com>
To: "Edgecombe, Rick P" <rick.p.edgecombe@...el.com>,
        "peterz@...radead.org" <peterz@...radead.org>
Cc: "xry111@...111.site" <xry111@...111.site>,
        "andrealmeid@...lia.com" <andrealmeid@...lia.com>,
        "fweimer@...hat.com" <fweimer@...hat.com>,
        "linux-mm@...ck.org" <linux-mm@...ck.org>,
        "libc-alpha@...rceware.org" <libc-alpha@...rceware.org>,
        "linux-kernel@...r.kernel.org" <linux-kernel@...r.kernel.org>,
        "tglx@...utronix.de" <tglx@...utronix.de>,
        "linux-api@...r.kernel.org" <linux-api@...r.kernel.org>,
        "linux-arch@...r.kernel.org" <linux-arch@...r.kernel.org>,
        Heiko Carstens <hca@...ux.ibm.com>,
        Sven Schnelle <svens@...ux.ibm.com>
Subject: Re: Several tst-robust* tests time out with recent Linux kernel

On 17.11.23 02:22, Edgecombe, Rick P wrote:
> A bit more info...
> 
> The error returned to userspace is originating from:
> https://github.com/torvalds/linux/blob/master/kernel/futex/pi.c#L295
> 
> 'uval' is often zero in that error case, but sometimes just a
> mismatching value like: uval=0x567, task_pid_vnr()=0x564
> 
> 
> Depending on the number of CPUs the VM is running on it reproduces or
> not. When it does reproduce, the newly added path here is taken:
> https://github.com/torvalds/linux/blob/master/kernel/futex/pi.c#L1185
> The path is taken a lot during the test, sometimes >400 times before
> the above linked error is generated during the syscall. When it doesn't
> reproduce, I never saw that new path taken.
> 
> More print statements make the reproduction less reliable, so it does
> seem to have a race in the mix at least somewhat. Otherwise, I haven't
> tried to understand what is going on here with all this highwire
> locking.
> 
> Hope it helps.
Hi,

I've also observed fails in glibc testcase nptl/tst-robust8pi with:
mutex_timedlock of 66 in thread 7 failed with 22
=> pthread_mutex_timedlock returns 22=EINVAL

I've saw it on s390x. There I've used kernel with
commit 120d99901eb288f1d21db3976df4ba347b28f9c7
s390/vfio-ap: do not reset queue removed from host config

But I also saw it on a x86_64 kvm-guest with Fedora 39 and
copr-repository with vanilla kernel:
Linux fedora 6.7.0-0.rc8.20240107gt52b1853b.366.vanilla.fc39.x86_64 #1
SMP PREEMPT_DYNAMIC Sun Jan  7 06:17:30 UTC 2024 x86_64 GNU/Linux

And reported it to libc-alpha ("FAILING nptl/tst-robust8pi"
https://sourceware.org/pipermail/libc-alpha/2024-January/154150.html)
where Florian Weimer pointed me to this thread.

I've reduced the test (see attachement) and now have only one process
with three threads. I only use one mutex with attributes like the
original testcase: PTHREAD_MUTEX_ROBUST_NP, PTHREAD_PROCESS_SHARED,
PTHREAD_PRIO_INHERIT.
Every thread is doing a loop with pthread_mutex_timedlock(abstime={0,0})
and if locked, pthread_mutex_unlock.

I've added some uprobes before and after the futex-syscall in
__futex_lock_pi64(in pthread_mutex_timedlock) and futex_unlock_pi(in
pthread_mutex_unlock). For me __ASSUME_FUTEX_LOCK_PI2 is not available,
but __ASSUME_TIME64_SYSCALLS is defined.

For me it looks like this (simplified ubprobes-trace):
<thread> <timestamp>: <probe>
t1 4309589.419744: before syscall in __futex_lock_pi64

t3 4309589.419745: before syscall in futex_unlock_pi
t2 4309589.419745: before syscall in __futex_lock_pi64

t3 4309589.419747: after syscall in futex_unlock_pi
t2 4309589.419747: after syscall in __futex_lock_pi64 ret=-22=EINVAL

t1 4309589.419748: after syscall in __futex_lock_pi64 ret=-110=ETIMEDOUT

Can you please have a look again?

Bye,
Stefan Liebler
View attachment "tst-robust8pi-20240118.c" of type "text/x-csrc" (4161 bytes)