xtimer: check in xtimer_mutex_lock_timeout timeout callback if a thread blocked on mutex

[JulianHolzwarth]

The tracking pr: #11660

This pr is the same pr as #10872 with a test and edited commit message.
it also includes a throwaway test commit.

Contribution description

Prevent a possible race condition for xtimer_mutex_lock_timeout when _mutex_timeout fires just after the mutex was locked but before the xtimer was removed

The flow

int xtimer_mutex_lock_timeout(mutex_t *mutex, uint64_t timeout) {
   ...
    mutex_lock(mutex);
    <- mutex locked ->
    <- _mutex_timeout fires and tries to remove thread from mutex queue ->
    xtimer_remove(&t);
    ...
}

Testing procedure

with the fix the test works,

BOARD=native make -C tests/xtimer_mutex_lock_timeout/ flash test
...
starting test: xtimer mutex lock timeout
OK
> 

without the fix

git revert HEAD
BOARD=native make -C tests/xtimer_mutex_lock_timeout/ flash test
...
starting test: xtimer mutex lock timeout
sys/xtimer/xtimer.c:239 => 0x56596856
*** RIOT kernel panic:
FAILED ASSERTION.

*** halted.


native: exiting
Unexpected end of file in expect script at "child.expect("OK")" (tests/xtimer_mutex_lock_timeout/tests/01-run.py:24)

issues/PRs references

This is the same pr as #10872 with a test.
#11660: tracking pr for xtimer_mutex_lock_timeout function

[cladmi]

We updated the pull request from @pwillem with a test to show the assertion.

The difference in the commit will be reverted when removing the throwaway commit.

The fix is included in #11225 but the pull request does other things that do not all works. Better fix one thing at a time to simplify the review and documentation.

[cladmi]

I contributed to this pull request so cannot really review myself.
The goal was to add the test and include a way to show the issue in the commit message.

The testing procedure gives the same result with BOARD=samr21-xpro.

2019-05-17 17:31:52,573 - INFO # mutex_timeout_test   tests xtimer mutex lock timeout
> 2019-05-17 17:31:52,614 - INFO #  mutex_timeout_test
2019-05-17 17:31:52,618 - INFO # starting test: xtimer mutex lock timeout
2019-05-17 17:31:52,618 - INFO # 0x16ff
2019-05-17 17:31:52,621 - INFO # *** RIOT kernel panic:
2019-05-17 17:31:52,622 - INFO # FAILED ASSERTION.
2019-05-17 17:31:52,622 - INFO # 
2019-05-17 17:31:52,623 - INFO # *** halted.

[cladmi]

Missing new line at the end.

[cladmi]

We noticed more issues as this change breaks the case where xtimer_sleep spins…
It needs more pre-changes to have this correct.

[vincent-d]

@JulianHolzwarth @cladmi thanks for taking care of this. I've not been very active on RIOT recently, but I'll try to take a look at this one and test ASAP.

[cladmi]

@vincent-d there are way more issues than this, and basically, what does not go in the normal timeout during mutex_lock is not working correctly, and cannot work. We just need to find a way to see how to fix one case without introducing new bugs in a minimal way.

[JulianHolzwarth]

I will close this pr.
There are more issues.
I will solve them with the tracking pr:

• [TRACKING] xtimer/xtimer.c: xtimer_mutex_lock_timeout fix and improvements [TRACKING] xtimer/xtimer.c: xtimer_mutex_lock_timeout fix and improvements #11660