Project Home
Project Home
Documents
Documents
Wiki
Wiki
Discussion Forums
Discussions
Project Information
Project Info
Forum Topic - Unexpected result of pthread_mutex_condlock: (3 Items)
   
Unexpected result of pthread_mutex_condlock  
With 6.3.2 procnto-smp on quad-core our QA managed to crash program on assert (repeatable so far) that 
pthread_cond_timedwait returns an unexpected error code.
The source lines look like this

		timespec tsStopTime;
		nsec2timespec(&tsStopTime, ullWaitStopTime);

		iWaitRes = pthread_cond_timedwait(&cv->m_cond, &cv->m_mutex, &tsStopTime);
		CHECKE(iWaitRes == EOK || iWaitRes == ETIMEDOUT);

The disassembled code is 
...
sub    $0x4,%esp
lea    -0x18(%ebp),%eax // struct timespec
push   %eax
pushl  -0xc(%ebp) // mutex
mov    -0xc(%ebp),%eax
add    $0x8,%eax
push   %eax // condvar
call   0x804e5a8 <pthread_cond_timedwait@plt>
add    $0x10,%esp // Store result
mov    %eax,-0x10(%ebp)
cmpl   $0x0,-0x10(%ebp) // Check for EOK
je     0x82cf998 <_ZN14CPlatformUtils24WaitCondVarConditionNanoEPvy+190>
cmpl   $0x104,-0x10(%ebp) // Check for ETIMEDOUT
je     0x82cf998 <_ZN14CPlatformUtils24WaitCondVarConditionNanoEPvy+190>
sub    $0xc,%esp // Fail assertion check
push   $0x0
push   $0x1
push   $0x836e4c0
push   $0x619
push   $0x836e9c0
call   0x82ca788 <_Z11assert_failPKciS0_bi>

So, the result is stored on stack but there is really not much time and chances for it to get corrupted, + values of 
stack variables before and after -0x10+$ebp ('tsStopTime' and 'cv' pointer) look correct.

The condvar with its dedicated mutex look fine
(gdb) p cv[0]
$3 = {m_mutex = {count = -2147483647, owner = 10747906}, m_cond = {count = 2, owner = 4294967291}}
(gdb) x/4wx  cv
0x840b308:      0x80000001      0x00a40002      0x00000002      0xfffffffb

Stop time is OK too
(gdb) p tsStopTime
$7 = {tv_sec = 4512764, tv_nsec = 125003096}

But the result returned is somewhat unexpected
(gdb) p iWaitRes
$5 = 33554432
(gdb) x &iWaitRes
0x7fc6d28:      0x02000000

So, the question is: were there any issues of this kind reported/fixed since 6.3.2?
Re: Unexpected result of pthread_cond_timedwait  
Update:
The issue can be recreated even in release build when return of pthread_cond_timedwait is not stored on stack but 
checked directly from register.

> With 6.3.2 procnto-smp on quad-core our QA managed to crash program on assert 
> (repeatable so far) that pthread_cond_timedwait returns an unexpected error 
> code.
> The source lines look like this
> 
> 		timespec tsStopTime;
> 		nsec2timespec(&tsStopTime, ullWaitStopTime);
> 
> 		iWaitRes = pthread_cond_timedwait(&cv->m_cond, &cv->m_mutex, &tsStopTime);
> 		CHECKE(iWaitRes == EOK || iWaitRes == ETIMEDOUT);
> 
> The disassembled code is 
> ...
> sub    $0x4,%esp
> lea    -0x18(%ebp),%eax // struct timespec
> push   %eax
> pushl  -0xc(%ebp) // mutex
> mov    -0xc(%ebp),%eax
> add    $0x8,%eax
> push   %eax // condvar
> call   0x804e5a8 <pthread_cond_timedwait@plt>
> add    $0x10,%esp // Store result
> mov    %eax,-0x10(%ebp)
> cmpl   $0x0,-0x10(%ebp) // Check for EOK
> je     0x82cf998 <_ZN14CPlatformUtils24WaitCondVarConditionNanoEPvy+190>
> cmpl   $0x104,-0x10(%ebp) // Check for ETIMEDOUT
> je     0x82cf998 <_ZN14CPlatformUtils24WaitCondVarConditionNanoEPvy+190>
> sub    $0xc,%esp // Fail assertion check
> push   $0x0
> push   $0x1
> push   $0x836e4c0
> push   $0x619
> push   $0x836e9c0
> call   0x82ca788 <_Z11assert_failPKciS0_bi>
> 
> So, the result is stored on stack but there is really not much time and 
> chances for it to get corrupted, + values of stack variables before and after 
> -0x10+$ebp ('tsStopTime' and 'cv' pointer) look correct.
> 
> The condvar with its dedicated mutex look fine
> (gdb) p cv[0]
> $3 = {m_mutex = {count = -2147483647, owner = 10747906}, m_cond = {count = 2, 
> owner = 4294967291}}
> (gdb) x/4wx  cv
> 0x840b308:      0x80000001      0x00a40002      0x00000002      0xfffffffb
> 
> Stop time is OK too
> (gdb) p tsStopTime
> $7 = {tv_sec = 4512764, tv_nsec = 125003096}
> 
> But the result returned is somewhat unexpected
> (gdb) p iWaitRes
> $5 = 33554432
> (gdb) x &iWaitRes
> 0x7fc6d28:      0x02000000
> 
> So, the question is: were there any issues of this kind reported/fixed since 6
> .3.2?


Re: Unexpected result of pthread_cond_timedwait  
And regarding usage...
This is a condvar in a custom threadpool implementation which is broadcasted by each new thread after it sets it state 
as 'started' in an object field. The owners that would like to wait until their threads actually start do wait for the 
codvar and check for 'started' status to appear in the field in the loop until started status is detected or absolute 
wait end time elapses.

> Update:
> The issue can be recreated even in release build when return of 
> pthread_cond_timedwait is not stored on stack but checked directly from 
> register.
> 
> > With 6.3.2 procnto-smp on quad-core our QA managed to crash program on 
> assert 
> > (repeatable so far) that pthread_cond_timedwait returns an unexpected error 
> 
> > code.
> > The source lines look like this
> > 
> > 		timespec tsStopTime;
> > 		nsec2timespec(&tsStopTime, ullWaitStopTime);
> > 
> > 		iWaitRes = pthread_cond_timedwait(&cv->m_cond, &cv->m_mutex, &tsStopTime);
> > 		CHECKE(iWaitRes == EOK || iWaitRes == ETIMEDOUT);
> > 
> > The disassembled code is 
> > ...
> > sub    $0x4,%esp
> > lea    -0x18(%ebp),%eax // struct timespec
> > push   %eax
> > pushl  -0xc(%ebp) // mutex
> > mov    -0xc(%ebp),%eax
> > add    $0x8,%eax
> > push   %eax // condvar
> > call   0x804e5a8 <pthread_cond_timedwait@plt>
> > add    $0x10,%esp // Store result
> > mov    %eax,-0x10(%ebp)
> > cmpl   $0x0,-0x10(%ebp) // Check for EOK
> > je     0x82cf998 <_ZN14CPlatformUtils24WaitCondVarConditionNanoEPvy+190>
> > cmpl   $0x104,-0x10(%ebp) // Check for ETIMEDOUT
> > je     0x82cf998 <_ZN14CPlatformUtils24WaitCondVarConditionNanoEPvy+190>
> > sub    $0xc,%esp // Fail assertion check
> > push   $0x0
> > push   $0x1
> > push   $0x836e4c0
> > push   $0x619
> > push   $0x836e9c0
> > call   0x82ca788 <_Z11assert_failPKciS0_bi>
> > 
> > So, the result is stored on stack but there is really not much time and 
> > chances for it to get corrupted, + values of stack variables before and 
> after 
> > -0x10+$ebp ('tsStopTime' and 'cv' pointer) look correct.
> > 
> > The condvar with its dedicated mutex look fine
> > (gdb) p cv[0]
> > $3 = {m_mutex = {count = -2147483647, owner = 10747906}, m_cond = {count = 2
> , 
> > owner = 4294967291}}
> > (gdb) x/4wx  cv
> > 0x840b308:      0x80000001      0x00a40002      0x00000002      0xfffffffb
> > 
> > Stop time is OK too
> > (gdb) p tsStopTime
> > $7 = {tv_sec = 4512764, tv_nsec = 125003096}
> > 
> > But the result returned is somewhat unexpected
> > (gdb) p iWaitRes
> > $5 = 33554432
> > (gdb) x &iWaitRes
> > 0x7fc6d28:      0x02000000
> > 
> > So, the question is: were there any issues of this kind reported/fixed since
>  6
> > .3.2?