search

staticanalysis / data-race-test

Automatically exported from code.google.com/p/data-race-test
0 stars 0 forks source link

PrintfTests.Simple report races on Windows #53

Open GoogleCodeExporter opened 9 years ago

GoogleCodeExporter commented 9 years ago 
Assigning to Eugene since he knows some background (see r2490)

Vista:
WARNING: Possible data race during read of size 4 at 0C5D07FC: {{{
   T1 (L{L36}):
    #0  _stbuf f:/dd/vctools/crt_bld/self_x86/crt/src/_sftbuf.c:82
    #1  fprintf f:/dd/vctools/crt_bld/self_x86/crt/src/fprintf.c:69
    #2  PrintfTests_Simple::Worker1 z:/tsan-workspace/git/unittest/racecheck_unittest.cc:7413
    #3  MyThread::ThreadBody z:/tsan-workspace/git/unittest/thread_wrappers_win.h:223
    #4  BaseThreadInitThunk C:\Windows\syswow64\kernel32.dll
  Concurrent write(s) happened at (OR AFTER) these points:
   T2 (L{L37}):
    #0  _stbuf f:/dd/vctools/crt_bld/self_x86/crt/src/_sftbuf.c:82
    #1  fprintf f:/dd/vctools/crt_bld/self_x86/crt/src/fprintf.c:69
    #2  PrintfTests_Simple::Worker1 z:/tsan-workspace/git/unittest/racecheck_unittest.cc:7412
    #3  MyThread::ThreadBody z:/tsan-workspace/git/unittest/thread_wrappers_win.h:223
    #4  BaseThreadInitThunk C:\Windows\syswow64\kernel32.dll
  Locks involved in this report (reporting last lock sites): {L36, L37}
   L36 (0C5D0CE0)
    #0  RtlEnterCriticalSection C:\Windows\SysWOW64\ntdll.dll
    #1  _lock f:/dd/vctools/crt_bld/self_x86/crt/src/mlock.c:348
    #2  _lock_file f:/dd/vctools/crt_bld/self_x86/crt/src/_file.c:231
    #3  fprintf f:/dd/vctools/crt_bld/self_x86/crt/src/fprintf.c:63
    #4  PrintfTests_Simple::Worker1 z:/tsan-workspace/git/unittest/racecheck_unittest.cc:7413
    #5  MyThread::ThreadBody z:/tsan-workspace/git/unittest/thread_wrappers_win.h:223
    #6  BaseThreadInitThunk C:\Windows\syswow64\kernel32.dll
   L37 (0C5D0CF8)
    #0  RtlEnterCriticalSection C:\Windows\SysWOW64\ntdll.dll
    #1  _lock f:/dd/vctools/crt_bld/self_x86/crt/src/mlock.c:348
    #2  _lock_file f:/dd/vctools/crt_bld/self_x86/crt/src/_file.c:231
    #3  fprintf f:/dd/vctools/crt_bld/self_x86/crt/src/fprintf.c:63
    #4  PrintfTests_Simple::Worker1 z:/tsan-workspace/git/unittest/racecheck_unittest.cc:7412
    #5  MyThread::ThreadBody z:/tsan-workspace/git/unittest/thread_wrappers_win.h:223
    #6  BaseThreadInitThunk C:\Windows\syswow64\kernel32.dll
   Race verifier data: 00480B65,00480B65
}}}

Windows 7:
WARNING: Possible data race during read of size 4 at 0C5CF75C: {{{
   T1 (L{L20}):
    #0  _stbuf f:/dd/vctools/crt_bld/self_x86/crt/src/_sftbuf.c:82
    #1  fprintf f:/dd/vctools/crt_bld/self_x86/crt/src/fprintf.c:69
    #2  PrintfTests_Simple::Worker1 c:/timurrrr/tsan/unittest/racecheck_unittest.cc:7413
    #3  MyThread::ThreadBody c:/timurrrr/tsan/unittest/thread_wrappers_win.h:223
    #4  BaseThreadInitThunk C:\Windows\syswow64\kernel32.dll
  Concurrent write(s) happened at (OR AFTER) these points:
   T2 (L{L21}):
    #0  _stbuf f:/dd/vctools/crt_bld/self_x86/crt/src/_sftbuf.c:82
    #1  fprintf f:/dd/vctools/crt_bld/self_x86/crt/src/fprintf.c:69
    #2  PrintfTests_Simple::Worker1 c:/timurrrr/tsan/unittest/racecheck_unittest.cc:7412
    #3  MyThread::ThreadBody c:/timurrrr/tsan/unittest/thread_wrappers_win.h:223
    #4  BaseThreadInitThunk C:\Windows\syswow64\kernel32.dll
  Locks involved in this report (reporting last lock sites): {L20, L21}
   L20 (0C5CFC40)
    #0  RtlEnterCriticalSection C:\Windows\SysWOW64\ntdll.dll
    #1  _lock f:/dd/vctools/crt_bld/self_x86/crt/src/mlock.c:348
    #2  _lock_file f:/dd/vctools/crt_bld/self_x86/crt/src/_file.c:231
    #3  fprintf f:/dd/vctools/crt_bld/self_x86/crt/src/fprintf.c:63
    #4  PrintfTests_Simple::Worker1 c:/timurrrr/tsan/unittest/racecheck_unittest.cc:7413
    #5  MyThread::ThreadBody c:/timurrrr/tsan/unittest/thread_wrappers_win.h:223
    #6  BaseThreadInitThunk C:\Windows\syswow64\kernel32.dll
   L21 (0C5CFC58)
    #0  RtlEnterCriticalSection C:\Windows\SysWOW64\ntdll.dll
    #1  _lock f:/dd/vctools/crt_bld/self_x86/crt/src/mlock.c:348
    #2  _lock_file f:/dd/vctools/crt_bld/self_x86/crt/src/_file.c:231
    #3  fprintf f:/dd/vctools/crt_bld/self_x86/crt/src/fprintf.c:63
    #4  PrintfTests_Simple::Worker1 c:/timurrrr/tsan/unittest/racecheck_unittest.cc:7412
    #5  MyThread::ThreadBody c:/timurrrr/tsan/unittest/thread_wrappers_win.h:223
    #6  BaseThreadInitThunk C:\Windows\syswow64\kernel32.dll
   Race verifier data: 00480755,00480755
}}}

Original issue reported on code.google.com by timurrrr on 16 Nov 2010 at 3:34

GoogleCodeExporter commented 9 years ago 
I've ignored _stbuf for now in r2640

Original comment by timurrrr on 16 Nov 2010 at 3:41

GoogleCodeExporter commented 9 years ago 
One more report:
WARNING: Possible data race during write of size 4 at 1D703008: {{{
   T2693 (L{}):
    #0  free f:/dd/vctools/crt_bld/self_x86/crt/src/free.c:42
    #1  _freefls f:/dd/vctools/crt_bld/self_x86/crt/src/tidtable.c:737
    #2  _freefls f:/dd/vctools/crt_bld/self_x86/crt/src/tidtable.c:674
    #3  RtlProcessFlsData C:\Windows\SysWOW64\ntdll.dll
    #4  RtlAllocateHeap C:\Windows\SysWOW64\ntdll.dll
    #5  LdrShutdownThread C:\Windows\SysWOW64\ntdll.dll
    #6  RtlExitUserThread C:\Windows\SysWOW64\ntdll.dll
    #7  BaseThreadInitThunk C:\Windows\syswow64\kernel32.dll
  Concurrent write(s) happened at (OR AFTER) these points:
   T2694 (L{L20}):
    #0  _getptd_noexit f:/dd/vctools/crt_bld/self_x86/crt/src/tidtable.c:602
    #1  _getptd f:/dd/vctools/crt_bld/self_x86/crt/src/tidtable.c:641
    #2  _LocaleUpdate::_LocaleUpdate f:/dd/vctools/crt_bld/self_x86/crt/src/setlocal.h:264
    #3  _output_l f:/dd/vctools/crt_bld/self_x86/crt/src/output.c:2155
    #4  fprintf f:/dd/vctools/crt_bld/self_x86/crt/src/fprintf.c:70
    #5  fprintf f:/dd/vctools/crt_bld/self_x86/crt/src/fprintf.c:49
    #6  PrintfTests_Simple::Worker1 e:/b/build/slave/full_vista/build/unittest/racecheck_unittest.cc:7410
    #7  MyThread::ThreadBody e:/b/build/slave/full_vista/build/unittest/thread_wrappers_win.h:223
    #8  BaseThreadInitThunk C:\Windows\syswow64\kernel32.dll
   Note: these locks were recently released by T2694 and later acquired by T2693: {L19, L20}
   See http://code.google.com/p/data-race-test/wiki/PureHappensBeforeVsHybrid
  Location 1D703008 is 16 bytes inside a block starting at 1D702FF8 of size 255 allocated by T2677 from heap:
    #0  realloc f:/dd/vctools/crt_bld/self_x86/crt/src/realloc.c:64
    #1  MemoryTypes::ReallocThread e:/b/build/slave/full_vista/build/unittest/racecheck_unittest.cc:6409
    #2  MyThread::ThreadBody e:/b/build/slave/full_vista/build/unittest/thread_wrappers_win.h:223
    #3  BaseThreadInitThunk C:\Windows\syswow64\kernel32.dll
  Locks involved in this report (reporting last lock sites): {L19, L20}
   L19 (0C55FBB8)
    #0  RtlEnterCriticalSection C:\Windows\SysWOW64\ntdll.dll
    #1  _lock f:/dd/vctools/crt_bld/self_x86/crt/src/mlock.c:348
    #2  _lock_file f:/dd/vctools/crt_bld/self_x86/crt/src/_file.c:231
    #3  fprintf f:/dd/vctools/crt_bld/self_x86/crt/src/fprintf.c:63
    #4  fprintf f:/dd/vctools/crt_bld/self_x86/crt/src/fprintf.c:49
    #5  PrintfTests_Simple::Worker1 e:/b/build/slave/full_vista/build/unittest/racecheck_unittest.cc:7414
    #6  MyThread::ThreadBody e:/b/build/slave/full_vista/build/unittest/thread_wrappers_win.h:223
    #7  BaseThreadInitThunk C:\Windows\syswow64\kernel32.dll
   L20 (0C55FBD0)
    #0  RtlEnterCriticalSection C:\Windows\SysWOW64\ntdll.dll
    #1  _lock f:/dd/vctools/crt_bld/self_x86/crt/src/mlock.c:348
    #2  _lock_file f:/dd/vctools/crt_bld/self_x86/crt/src/_file.c:231
    #3  fprintf f:/dd/vctools/crt_bld/self_x86/crt/src/fprintf.c:63
    #4  fprintf f:/dd/vctools/crt_bld/self_x86/crt/src/fprintf.c:49
    #5  PrintfTests_Simple::Worker1 e:/b/build/slave/full_vista/build/unittest/racecheck_unittest.cc:7412
    #6  MyThread::ThreadBody e:/b/build/slave/full_vista/build/unittest/thread_wrappers_win.h:223
    #7  BaseThreadInitThunk C:\Windows\syswow64\kernel32.dll
   Race verifier data: 00441A79,0044B13F
}}}

FYI,
I saw memory leaks detectable by Dr. Memory under _getptd, hmmm

Original comment by timurrrr on 16 Nov 2010 at 4:41

GoogleCodeExporter commented 9 years ago 
the latter report is flaky; seen this on our Vista bot and maybe somewhere else 
as well.

Maybe this is related to a newer version of PIN we're using now (was: 338XY, 
now: 37000)

Original comment by timurrrr on 16 Nov 2010 at 4:48

GoogleCodeExporter commented 9 years ago 
I've ignored _getptr in r2738

Original comment by timurrrr on 24 Nov 2010 at 12:58

GoogleCodeExporter commented 9 years ago 
Re: _getptd
http://www.microsoft.com/msj/0799/win32/win320799.aspx
"Note that the CRT's _getptd function internally calls the operating system's 
TlsGetValue function ..."

Original comment by timurrrr on 24 Nov 2010 at 1:11