pthread_cond_timedwait problem

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

On macOS I see an extra mutex.

That doesn’t surprise me, but that’s probably the result of my not understanding your setup properly. When I run your cond_timedwait_test.c code natively and set a breakpoint on pthread_mutex_lock, I hit that breakpoint a lot inside the dynamic linker and various loaded-by-default libraries. But I suspect that you’re doing stuff to avoid that, like statically linking the executable [1].

Share and Enjoy

Quinn “The Eskimo!” @ Developer Technical Support @ Apple
let myEmail = "eskimo" + "1" + "@" + "apple.com"

[1] Not something we support in general but tools like this often have to stray from the supported path.

pthread_cond_timedwait problem
 
 
Q