[BUG] futex(FUTEX_LOCK_PI2): timed out PI waiter keeps owner boosted until it gets the CPU

[Alexander Krabler]

Hello,

when using PI futexes with timeout, priority inversion can happen,
as after the timeout the priority of the lock owner task is not
reset until the waiter gets scheduled.

The priority of the lock owner seems to be only reset when either of:
* the lock owner unlocks the mutex (FUTEX_UNLOCK_PI).
* the waiter gets scheduled after the timeout
  and deboosts the lock owner actively.

If both threads run on the same CPU, by chance or because actively
pinned to the same CPU, then the lock owner can prevent
the high priority task from running.
After the high priority task times out on waiting for the lock,
it runs only if the lock owner voluntarily relinquishes the CPU
or unlocks the mutex.
If it does not, it can prevent the high priority task from running
for an unbounded amount of time.

Commit b40c927345a9 ("hrtimer: Use hrtimer_start_expires_user() for hrtimer sleepers")
(since 7.2) changed the logic to avoid going through
the clock event device and wakeups, when the timeout already expired.
Before that change, you can observe the above behaviour
even when using already expired timeouts.

The issue is fully reproducible.
The example uses two threads, pi_waiter and pi_owner.
Both tasks are pinned to the same CPU, and use SCHED_FIFO
with priority 2 (97) and 1 (98) respectively.
The PI futex is locked by pi_owner and never released.
pi_waiter tries to get the PI futex with a 1ms timeout.
As a consequence, pi_owner gets its priority boosted correctly
and gets scheduled.

After the timeout, pi_waiter is woken up correctly.
However, pi_owner has its priority still inherited from pi_waiter and
prevents pi_waiter from running until it voluntarily gives up the CPU.
The priority boost of pi_owner is only reverted when pi_waiter finally
gets CPU time.

Tested on 7.4-rc2 (7475ea8b) x86_64 and on 6.12 aarch64.
Observed on both PREEMPT_RT and PREEMPT_DYNAMIC.
The reproducer exits with status 1 on all tested kernels.

------------------------ >8 ------------------------
/*
 * Run with CAP_SYS_NICE or RLIMIT_RTPRIO set to >=2.
 * A FUTEX_LOCK_PI2 waiter that times out should drop the PI boost of the
 * lock owner.
 * Exit code 0: boost dropped, 1: owner kept the boost, 2: setup error.
 */

#define _GNU_SOURCE
#include <errno.h>
#include <linux/futex.h>
#include <pthread.h>
#include <sched.h>
#include <stdatomic.h>
#include <stdbool.h>
#include <stdint.h>
#include <stdio.h>
#include <stdlib.h>
#include <sys/syscall.h>
#include <time.h>
#include <unistd.h>

#define NSEC_PER_SEC 1000000000LL
#define NSEC_PER_MSEC 1000000LL

/* Our PI mutex (futex-based). */
static uint32_t ftx;
static atomic_bool lock_returned;

static void die(const char *msg, int err)
{
        errno = err;
        perror(msg);
        exit(2);
}

static int64_t now_ns(void)
{
        struct timespec ts;
        clock_gettime(CLOCK_MONOTONIC, &ts);
        return ts.tv_sec * NSEC_PER_SEC + ts.tv_nsec;
}

static long futex_lock_pi2_1ms_timeout(uint32_t *uaddr)
{
        int64_t deadline = now_ns() + 1 * NSEC_PER_MSEC;
        struct timespec ts = {
            .tv_sec = deadline / NSEC_PER_SEC,
            .tv_nsec = deadline % NSEC_PER_SEC,
        };
        return syscall(SYS_futex, uaddr, FUTEX_LOCK_PI2, 0, &ts);
}

static void busy_sleep_ms(long ms)
{
        int64_t start = now_ns();
        while (now_ns() - start < ms * NSEC_PER_MSEC)
                ;
}

static void pin_to_cpu0(void)
{
        cpu_set_t set;
        int ret;

        CPU_ZERO(&set);
        CPU_SET(0, &set);
        ret = pthread_setaffinity_np(pthread_self(), sizeof(set), &set);
        if (ret)
                die("pthread_setaffinity_np", ret);
}

static void set_fifo_prio(int prio)
{
        struct sched_param param = {.sched_priority = prio};
        if (sched_setscheduler(0, SCHED_FIFO, &param))
                die("sched_setscheduler", errno);
}

static void *waiter_thread(void *arg)
{
        (void)arg;
        pthread_setname_np(pthread_self(), "pi_waiter");

        if (futex_lock_pi2_1ms_timeout(&ftx) == 0)
                die("FUTEX_LOCK_PI2 unexpectedly acquired the lock", 0);
        if (errno != ETIMEDOUT)
                die("FUTEX_LOCK_PI2 did not time out", errno);

        /*
         * After the timeout expired, the owner must have been deboosted,
         * so we preempt it and get here while the owner is still busy looping.
         */
        atomic_store(&lock_returned, true);
        return NULL;
}

int main(void)
{
        pthread_t thd;
        bool ok;
        int ret;

        pthread_setname_np(pthread_self(), "pi_owner");

        /* Uncontended PI futex. Acquire from user space, never released. */
        ftx = gettid();

        /* Pin both threads to the same CPU. */
        pin_to_cpu0();

        /* Use realtime scheduling. Inherited by waiter. */
        set_fifo_prio(2);

        ret = pthread_create(&thd, NULL, waiter_thread, NULL);
        if (ret)
                die("pthread_create", ret);

        /*
         * Reduce our own priority. Makes sure the other thread can run
         * and attempt to acquire the mutex (boost us back to 2).
         */
        set_fifo_prio(1);

        busy_sleep_ms(10);

        /*
         * Must be read before joining, while we still hog the CPU.
         * If the flag is unset, we did keep our priority boost
         * (and therefore were not preempted),
         * although nobody waits on the PI futex anymore.
         */
        ok = atomic_load(&lock_returned);

        pthread_join(thd, NULL);
        return !ok;
}
------------------------ >8 ------------------------

Relevant ftrace events:
       pi_waiter-7339  [000] 67127.305214: sys_enter_futex:      uaddr: 0x55e4dc9de08c, op: 0x0000000d, val: 0x00000000, utime: 0x7f3702911e00, uaddr2: 0x7f3702b48010, val3: 0x00000000
       pi_waiter-7339  [000] 67127.305218: hrtimer_setup:        hrtimer=0xffffd27f8f3f3b50 clockid=CLOCK_MONOTONIC mode=0x0
       pi_waiter-7339  [000] 67127.305228: sched_pi_setprio:     comm=pi_owner pid=7338 oldprio=98 newprio=97
       pi_waiter-7339  [000] 67127.305231: hrtimer_start:        hrtimer=0xffffd27f8f3f3b50 function=hrtimer_wakeup/0x0 expires=67127276392278 softexpires=67127276392278
       pi_waiter-7339  [000] 67127.305235: sched_switch:         pi_waiter:7339 [97] S ==> pi_owner:7338 [97]
...
        pi_owner-7338  [000] 67127.306216: hrtimer_expire_entry: hrtimer=0xffffd27f8f3f3b50 now=67127276396064 function=hrtimer_wakeup/0x0
        pi_owner-7338  [000] 67127.306216: sched_waking:         comm=pi_waiter pid=7339 prio=97 target_cpu=000
        pi_owner-7338  [000] 67127.306227: sched_wakeup:         pi_waiter:7339 [97] CPU:000
        pi_owner-7338  [000] 67127.306228: hrtimer_expire_exit:  hrtimer=0xffffd27f8f3f3b50
        pi_owner-7338  [000] 67127.306229: hrtimer_rearm:        next_event=67127277000000 deferred=1
...
... After here, pi_owner should drop back to its old prio (98).
... But it keeps its prio until it voluntarily gives up the CPU
... (pthread_join in the example).
...
        pi_owner-7338  [000] 67127.315249: sys_enter_futex:      op=FUTEX_WAIT_BITSET|FUTEX_CLOCK_REALTIME uaddr=0x7f3702912ce8 val=0x00000002 utime=0x00000000 val3=0xffffffff
        pi_owner-7338  [000] 67127.315272: sched_switch:         pi_owner:7338 [97] S ==> pi_waiter:7339 [97]
       pi_waiter-7339  [000] 67127.315279: sched_pi_setprio:     comm=pi_owner pid=7338 oldprio=97 newprio=98
       pi_waiter-7339  [000] 67127.315284: sys_exit_futex:       0xffffffffffffff92


The same issue happens with FUTEX_LOCK_PI, too.
Is this considered a bug? In the documentation,
I couldn't find anything that would explain the seen behaviour.

Thanks,
Alexander

-- 
KUKA Deutschland GmbH
Board of Directors: Michael Jürgens (Chairman), Johan Naten, Hui Zhang
Registered Office: Augsburg HRB 14914