pthread_cond_timedwait problem

Question

Created 3h

Replies 0

Boosts 0

Participants 1

I'm trying to debug an issue with the Valgrind tool Helgrind. This is on masOS 11 (I've also seen it on 12, probably the same for other macOS versions).

Here is the testcase.

#include <pthread.h>
#include <string.h>
#include <assert.h>
#include <errno.h>

int main(void)
{
   pthread_mutex_t mutex = PTHREAD_MUTEX_INITIALIZER;
   pthread_cond_t cond = PTHREAD_COND_INITIALIZER;
   int res;

   // This time has most definitely passed already. (Epoch)
   struct timespec now;
   memset(&now, 0, sizeof(now));

   res = pthread_mutex_lock(&mutex);
   assert(res == 0);
   res = pthread_cond_timedwait(&cond, &mutex, &now);
   assert(res == ETIMEDOUT);

   res = pthread_mutex_unlock(&mutex);
   assert(res == 0);

   res = pthread_mutex_destroy(&mutex);
   assert(res == 0);
   res = pthread_cond_destroy(&cond);
   assert(res == 0);
}

The error that I'm getting from Helgrind is

==56754== Thread #1 unlocked a not-locked lock at 0x1048C7A08
==56754==    at 0x10020E2F9: mutex_unlock_WRK (hg_intercepts.c:1255)
==56754==    by 0x10020E278: pthread_mutex_unlock (hg_intercepts.c:1278)
==56754==    by 0x7FF80F526813: _pthread_cond_wait (in /usr/lib/system/libsystem_pthread.dylib)
==56754==    by 0x10020E812: pthread_cond_timedwait_WRK (hg_intercepts.c:1465)
==56754==    by 0x10020E6A8: pthread_cond_timedwait (hg_intercepts.c:1512)
==56754==    by 0x100003DD2: main (cond_timedwait_test.c:18)
==56754==  Lock at 0x1048C7A08 was first observed
==56754==    at 0x10020DE91: mutex_lock_WRK (hg_intercepts.c:1009)
==56754==    by 0x10020DD68: pthread_mutex_lock (hg_intercepts.c:1031)
==56754==    by 0x100003D7D: main (cond_timedwait_test.c:16)
==56754==  Address 0x1048c7a08 is on thread #1's stack
==56754==  in frame #5, created by main (cond_timedwait_test.c:7)

If I turn on extra tracing then on FreeBSD the Helgrind pthread traces correspond to the C source.

On macOS I see an extra mutex.

<< pthread_mxlock 0x7ff850c41 :: mxlock -> 0 >> << pthread_mxunlk 0x7ff850c41 :: mxunlk -> 0 >>

^^ I don't know what this mutex is

<< pthread_mxlock 0x1048c7a08 :: mxlock -> 0 >> ^^ this is the user mutex

<< pthread_mxlock 0x7ff850c41 :: mxlock -> 0 >> << pthread_cond_timedwait 0x1048c79d8 0x1048c7a08 0x1048c79c0<< pthread_mxunlk 0x7ff850c41 :: mxunlk -> 0 >> ^^ pthread_cond_timedwait unlocking the non-user mutex

<< pthread_mxlock 0x7ff850c41 :: mxlock -> 0 >> << pthread_mxunlk 0x7ff850c41 :: mxunlk -> 0 >> << pthread_mxunlk 0x1048c7a08 [error here] :: mxunlk -> 0 >> << pthread_mxlock 0x1048c7a08 :: mxlock -> 0 >> << pthread_mxlock 0x7ff850c41 :: mxlock -> 0 >> cotimedwait -> 60 >>

In these traces the "-> 0" is the return code, showing that all of the calls succeeded.

I need to do more debugging inside Helgrind. In the traces above I only see the user mutex being locked and then unlocked.

Can anyone explain why I'm seeing an extra mutex in there? I'll have a poke around the XNU source

Boost