< Previous by Date Date Index Next by Date >
  Thread Index Next in Thread >

[reSIProcate] race condition in resip::Log::timestamp


Hi,

I'm using resiprocate library version 1.8.8 under Oracle Linux Server 6.5 and see the following race condition under Helgrind:

==8418== 88 errors in context 96 of 102:
==8418== ----------------------------------------------------------------
==8418== 
==8418== Lock at 0x7FEFDB008 was first observed
==8418==    at 0x4A0BDA3: pthread_mutex_init (hg_intercepts.c:429)
==8418==    by 0x3BB0566DDA: resip::SipStack::SipStack(resip::Security*, std::vector<resip::GenericIPAddress, std::allocat
or<resip::GenericIPAddress> > const&, resip::AsyncProcessHandler*, bool, void (*)(int, int, char const*, int), resip::Comp
ression*, resip::FdPollGrp*) (SipStack.cxx:97)
==8418==    by 0x6B5D52: main (ProxyDaemon.cxx:831)
==8418== 
==8418== Possible data race during write of size 4 at 0x7068E88 by thread #18
==8418== Locks held: none
==8418==    at 0x4A063C0: free (vg_replace_malloc.c:446)
==8418==    by 0x3BA3A9DBE8: tzset_internal (tzset.c:435)
==8418==    by 0x3BA3A9DD68: __tz_convert (tzset.c:624)
==8418==    by 0x3BAFC3B63A: resip::Log::timestamp(resip::Data&) (Log.cxx:437)
==8418==    by 0x3BAFC3CF43: resip::Log::tags(resip::Log::Level, resip::Subsystem const&, char const*, int, std::ostream&)
 (Log.cxx:388)
==8418==    by 0x3BAFC3D22C: resip::Log::Guard::Guard(resip::Log::Level, resip::Subsystem const&, char const*, int) (Log.c
xx:731)
==8418==    by 0x3BB058E5CB: resip::TransportSelector::determineSourceInterface(resip::SipMessage*, resip::Tuple const&) c
onst (TransportSelector.cxx:747)
==8418==    by 0x3BB05914C7: resip::TransportSelector::transmit(resip::SipMessage*, resip::Tuple&, resip::SendData*) (Tran
sportSelector.cxx:851)
==8418==    by 0x3BB058662F: resip::TransactionState::process(resip::TransactionController&, resip::TransactionMessage*) (TransactionState.cxx:406)
==8418==    by 0x3BB0577B0B: resip::TransactionController::process(int) (TransactionController.cxx:141)
==8418==    by 0x3BB056A260: resip::TransactionControllerThread::thread() (TransactionControllerThread.hxx:30)
==8418==    by 0x3BAFC47359: threadIfThreadWrapper (ThreadIf.cxx:51)
==8418== 
==8418== This conflicts with a previous write of size 4 by thread #21
==8418== Locks held: 1, at address 0x7FEFDB008
==8418==    at 0x4A063C0: free (vg_replace_malloc.c:446)
==8418==    by 0x3BA3A9DBE8: tzset_internal (tzset.c:435)
==8418==    by 0x3BA3A9DD68: __tz_convert (tzset.c:624)
==8418==    by 0x3BAFC3B63A: resip::Log::timestamp(resip::Data&) (Log.cxx:437)
==8418==    by 0x3BAFC3CF43: resip::Log::tags(resip::Log::Level, resip::Subsystem const&, char const*, int, std::ostream&) (Log.cxx:388)
==8418==    by 0x3BAFC3D22C: resip::Log::Guard::Guard(resip::Log::Level, resip::Subsystem const&, char const*, int) (Log.cxx:731)
==8418==    by 0x3BB057255E: resip::TuSelectorTimerQueue::add(unsigned int, resip::Message*) (TimerQueue.cxx:124)
==8418==    by 0x3BB0566088: resip::SipStack::postMS(std::auto_ptr<resip::ApplicationMessage>, unsigned int, resip::TransactionUser*) (SipStack.cxx:697)

Apparently localtime() is used in resip::Log::timestamp:

    420    if (result == -1)
    421    {
    422       /* If we can't get the time of day, don't print a timestamp.
    423          Under Unix, this will never happen:  gettimeofday can fail only
    424          if the timezone is invalid which it can't be, since it is
    425          uninitialized]or if tv or tz are invalid pointers. */
    426       datebuf [0] = 0;
    427    }
    428    else
    429    {
    430       /* The tv_sec field represents the number of seconds passed since
    431          the Epoch, which is exactly the argument gettimeofday needs. */
    432       const time_t timeInSeconds = (time_t) tv.tv_sec;
    433       strftime (datebuf,
    434                 datebufSize,
    435                 "%Y%m%d-%H%M%S", /* guaranteed to fit in 256 chars,
    436                                     hence don't check return code */
    437                 localtime (&timeInSeconds));
    438    }

Which is not thread-safe according to 'man 3 localtime':

       The four functions asctime(), ctime(), gmtime() and localtime() return a pointer to  static  data  and
       hence  are not thread-safe.  Thread-safe versions asctime_r(), ctime_r(), gmtime_r() and localtime_r()
       are specified by SUSv2, and available since libc 5.2.5.

Could you please comment this Helgrind report? Is it "fixable" from your side?

Thank you!
Dean