Re: Threadsanitizer Detection on GM

Hongxu Chen <[email protected]> Wed, 6 Feb 2019 02:25:53 +0800
Newsgroups gmane.comp.video.graphicsmagick.bugs
Message-ID <CAJPBKOH661Pmid7jCs5QaTX_YfO+qNC-6sbQ4FhWzzagML46Ug@mail.gmail.com>
--===============1381456323417732948==
Content-Type: multipart/alternative; boundary="000000000000fe47d4058129bde3"

--000000000000fe47d4058129bde3
Content-Type: text/plain; charset="UTF-8"

Hi Bob,

  Thanks for the reply!
  I inline some more comments below.

On Wed, Feb 6, 2019 at 1:55 AM Bob Friesenhahn <[email protected]>
wrote:

> On Wed, 6 Feb 2019, Hongxu Chen wrote:
>
> >    It is known that threadsanitizer has many false positives when
> > detecting concurrent bugs with projects that depend on openmp, and GM is
> > one of them. But I saw this commit (https://reviews.llvm.org/D13072),
> and
> > it seems to solve the problem.
> >    There is also a blog post about this
> > https://xrunhprof.wordpress.com/2018/08/27/tsan-with-openmp.  So I
> followed
> > the advice; and I built openmp with -DLIBOMP_TSAN_SUPPORT=TRUE and GM
> with
> > threadsanitizer and by running "gm convert", I can see some data races
> > reported. My question is:
> >    1. Can I rely on this result and think there are some data races?
> >    2. Or can I even build openmp with -DLIBOMP_TSAN_SUPPORT=TRUE and
> > threadsanitizer
> > as well?
>
> I saw part of your large attachment, which can not possibly be sent on
> a mailing list like this.
>
OK, I will be careful next time.

>
> The symbols I see warned about (e.g. __kmp_global) are not part of
> GraphicsMagick.  They appear to be part of the TSAN library
> implementation so something is wrong with the testing.  The article
> you provided a reference to shows that the reports should be about the
> code being intentionally tested.
>
That seems a part of openmp.  I built an openmp without TSAN but with
-DLIBOMP_TSAN_SUPPORT=TRUE only, there are still some warnings.
However the warnings are something like:

WARNING: ThreadSanitizer: data race (pid=29974)
  Atomic write of size 8 at 0x7ffee84393b8 by thread T6:
    #0 __tsan_atomic64_fetch_add <null> (gm+0x476040)
    #1 .omp_outlined. /home/exp/work/gm/GM-tsan/magick/gradient.c:123:7
(gm+0xafa24b)
    #2 __kmp_invoke_microtask
/home/exp/work/imagemagick/openmp/BUILD/../runtime/src/z_Linux_asm.s:1399
(libomp.so+0x7a292)

  Previous read of size 8 at 0x7ffee84393b8 by main thread:
    #0 .omp_outlined. /home/exp/work/gm/GM-tsan/magick/gradient.c:124:11
(gm+0xafa261)
    #1 __kmp_invoke_microtask
/home/exp/work/imagemagick/openmp/BUILD/../runtime/src/z_Linux_asm.s:1399
(libomp.so+0x7a292)
    #2 DrawImage /home/exp/work/gm/GM-tsan/magick/render.c:3538:20
(gm+0x624fd1)
    #3 DrawPatternPath /home/exp/work/gm/GM-tsan/magick/render.c:4610:10
(gm+0x631457)
    #4 DrawImage /home/exp/work/gm/GM-tsan/magick/render.c:2797:22
(gm+0x61d3a8)
    #5 ReadMVGImage /home/exp/work/gm/GM-tsan/coders/mvg.c:237:10
(gm+0x8e2ea6)
    #6 ReadImage /home/exp/work/gm/GM-tsan/magick/constitute.c:1607:13
(gm+0x555462)
    #7 ReadSVGImage /home/exp/work/gm/GM-tsan/coders/svg.c:3945:13
(gm+0x98ca4b)
    #8 ReadImage /home/exp/work/gm/GM-tsan/magick/constitute.c:1607:13
(gm+0x555462)
    #9 ConvertImageCommand
/home/exp/work/gm/GM-tsan/magick/command.c:4362:22 (gm+0x4e225a)
    #10 MagickCommand /home/exp/work/gm/GM-tsan/magick/command.c:8886:17
(gm+0x5136b2)
    #11 GMCommandSingle /home/exp/work/gm/GM-tsan/magick/command.c:17408:10
(gm+0x539381)
    #12 GMCommand /home/exp/work/gm/GM-tsan/magick/command.c:17461:16
(gm+0x539025)
    #13 main /home/exp/work/gm/GM-tsan/utilities/gm.c:61:10 (gm+0x4c242b)

  Location is stack of main thread.

  Thread T6 (tid=29981, running) created by main thread at:
    #0 pthread_create <null> (gm+0x433666)
    #1 __kmp_create_worker
/home/exp/work/imagemagick/openmp/BUILD/../runtime/src/z_Linux_util.cpp:958:14
(libomp.so+0x6ef74)
    #2 DrawImage /home/exp/work/gm/GM-tsan/magick/render.c:3538:20
(gm+0x624fd1)
    #3 DrawPatternPath /home/exp/work/gm/GM-tsan/magick/render.c:4610:10
(gm+0x631457)
    #4 DrawImage /home/exp/work/gm/GM-tsan/magick/render.c:2797:22
(gm+0x61d3a8)
    #5 ReadMVGImage /home/exp/work/gm/GM-tsan/coders/mvg.c:237:10
(gm+0x8e2ea6)
    #6 ReadImage /home/exp/work/gm/GM-tsan/magick/constitute.c:1607:13
(gm+0x555462)
    #7 ReadSVGImage /home/exp/work/gm/GM-tsan/coders/svg.c:3945:13
(gm+0x98ca4b)
    #8 ReadImage /home/exp/work/gm/GM-tsan/magick/constitute.c:1607:13
(gm+0x555462)
    #9 ConvertImageCommand
/home/exp/work/gm/GM-tsan/magick/command.c:4362:22 (gm+0x4e225a)
    #10 MagickCommand /home/exp/work/gm/GM-tsan/magick/command.c:8886:17
(gm+0x5136b2)
    #11 GMCommandSingle /home/exp/work/gm/GM-tsan/magick/command.c:17408:10
(gm+0x539381)
    #12 GMCommand /home/exp/work/gm/GM-tsan/magick/command.c:17461:16
(gm+0x539025)
    #13 main /home/exp/work/gm/GM-tsan/utilities/gm.c:61:10 (gm+0x4c242b)

SUMMARY: ThreadSanitizer: data race
(/home/exp/work/gm/GM-tsan/install/bin/gm+0x476040) in
__tsan_atomic64_fetch_add

This is suspicious since "omp_outlined" seems to cause the false alarms.
I also noticed this:
https://stackoverflow.com/questions/33004809/can-i-use-thread-sanitizer-for-openmp-programs
And maybe I will try https://github.com/PRUNER/archer instead.

>
> Recent GraphicsMagick uses 'pragma omp atomic' and 'pragma omp flush'
> in pixel_iterator.c rather than using critical sections.  I am not
> sure how a data-race detector deals with OpenMP 'flush' requests
> (synchronize thread cached memory with with shared memory) since they
> are not the same as a lock and might look like a data-race.  Releases
> prior to 1.3.31 used critical sections.
>
I'm trying some concurrent detection techniques, so I can try GM versions
prior to 1.3.31,
so thanks for this tip!

>
> Long ago I used valgrind's helgrind and drd modes to search for data
> races.  This required building a replacement libgomp based on pthreads
> rather than special Linux interfaces.
>
Yeah, there seems a "-disable-linux-futex" for gcc to build openmp. And I
was just
wondering whether  ` -DLIBOMP_TSAN_SUPPORT=TRUE` is the equivalent
(unfortunately, it seems NOT). I guess I will ask the ThreadSanitizer
community for
some more help.

>
> There are two things which are normally shared in GM OpenMP loops
> other than one mutex lock in pixel_cache.c.  These are the error
> status (to know when all the threads in the team should try to quit
> because one of them reported an error), and the progress callback (to
> report progress if a progress monitor is enabled).
>
> Independent testing and analysis of GraphicsMagick is certainly
> valuable, but it is wise to identify specific code which should be
> corrected.
>
> Bob
> --
> Bob Friesenhahn
> [email protected], http://www.simplesystems.org/users/bfriesen/
> GraphicsMagick Maintainer,    http://www.GraphicsMagick.org/
> Public Key,     http://www.simplesystems.org/users/bfriesen/public-key.txt
>
>
> _______________________________________________
> Graphicsmagick-bugs mailing list
> [email protected]
> https://lists.sourceforge.net/lists/listinfo/graphicsmagick-bugs
>

--000000000000fe47d4058129bde3
Content-Type: text/html; charset="UTF-8"
Content-Transfer-Encoding: quoted-printable

<div dir=3D"ltr"><div dir=3D"ltr"><div dir=3D"ltr"><div dir=3D"ltr"><div di=
r=3D"ltr"><div dir=3D"ltr"><div dir=3D"ltr"><div dir=3D"ltr">Hi Bob,=C2=A0<=
/div><div dir=3D"ltr"><br></div><div>=C2=A0 Thanks for the reply!</div><div=
>=C2=A0 I inline some more comments below.<br><br></div><div class=3D"gmail=
_quote"><div dir=3D"ltr" class=3D"gmail_attr">On Wed, Feb 6, 2019 at 1:55 A=
M Bob Friesenhahn &lt;<a href=3D"mailto:[email protected]">bfrie=
[email protected]</a>&gt; wrote:<br></div><blockquote class=3D"gmail_=
quote" style=3D"margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,=
204);padding-left:1ex">On Wed, 6 Feb 2019, Hongxu Chen wrote:<br>
<br>
&gt;=C2=A0 =C2=A0 It is known that threadsanitizer has many false positives=
 when<br>
&gt; detecting concurrent bugs with projects that depend on openmp, and GM =
is<br>
&gt; one of them. But I saw this commit (<a href=3D"https://reviews.llvm.or=
g/D13072" rel=3D"noreferrer" target=3D"_blank">https://reviews.llvm.org/D13=
072</a>), and<br>
&gt; it seems to solve the problem.<br>
&gt;=C2=A0 =C2=A0 There is also a blog post about this<br>
&gt; <a href=3D"https://xrunhprof.wordpress.com/2018/08/27/tsan-with-openmp=
" rel=3D"noreferrer" target=3D"_blank">https://xrunhprof.wordpress.com/2018=
/08/27/tsan-with-openmp</a>.=C2=A0 So I followed<br>
&gt; the advice; and I built openmp with -DLIBOMP_TSAN_SUPPORT=3DTRUE and G=
M with<br>
&gt; threadsanitizer and by running &quot;gm convert&quot;, I can see some =
data races<br>
&gt; reported. My question is:<br>
&gt;=C2=A0 =C2=A0 1. Can I rely on this result and think there are some dat=
a races?<br>
&gt;=C2=A0 =C2=A0 2. Or can I even build openmp with -DLIBOMP_TSAN_SUPPORT=
=3DTRUE and<br>
&gt; threadsanitizer<br>
&gt; as well?<br>
<br>
I saw part of your large attachment, which can not possibly be sent on <br>
a mailing list like this.<br></blockquote><div>OK, I will be careful next t=
ime.=C2=A0</div><blockquote class=3D"gmail_quote" style=3D"margin:0px 0px 0=
px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex">
<br>
The symbols I see warned about (e.g. __kmp_global) are not part of <br>
GraphicsMagick.=C2=A0 They appear to be part of the TSAN library <br>
implementation so something is wrong with the testing.=C2=A0 The article <b=
r>
you provided a reference to shows that the reports should be about the <br>
code being intentionally tested.<br></blockquote><div>That seems a part of =
openmp.=C2=A0 I built an openmp without TSAN but with</div><div>-DLIBOMP_TS=
AN_SUPPORT=3DTRUE only, there are still some warnings.</div><div>However th=
e warnings are something like:</div><div><br></div><div><div>WARNING: Threa=
dSanitizer: data race (pid=3D29974)</div><div>=C2=A0 Atomic write of size 8=
 at 0x7ffee84393b8 by thread T6:</div><div>=C2=A0 =C2=A0 #0 __tsan_atomic64=
_fetch_add &lt;null&gt; (gm+0x476040)</div><div>=C2=A0 =C2=A0 #1 .omp_outli=
ned. /home/exp/work/gm/GM-tsan/magick/gradient.c:123:7 (gm+0xafa24b)</div><=
div>=C2=A0 =C2=A0 #2 __kmp_invoke_microtask /home/exp/work/imagemagick/open=
mp/BUILD/../runtime/src/z_Linux_asm.s:1399 (libomp.so+0x7a292)</div><div><b=
r></div><div>=C2=A0 Previous read of size 8 at 0x7ffee84393b8 by main threa=
d:</div><div>=C2=A0 =C2=A0 #0 .omp_outlined. /home/exp/work/gm/GM-tsan/magi=
ck/gradient.c:124:11 (gm+0xafa261)</div><div>=C2=A0 =C2=A0 #1 __kmp_invoke_=
microtask /home/exp/work/imagemagick/openmp/BUILD/../runtime/src/z_Linux_as=
m.s:1399 (libomp.so+0x7a292)</div><div>=C2=A0 =C2=A0 #2 DrawImage /home/exp=
/work/gm/GM-tsan/magick/render.c:3538:20 (gm+0x624fd1)</div><div>=C2=A0 =C2=
=A0 #3 DrawPatternPath /home/exp/work/gm/GM-tsan/magick/render.c:4610:10 (g=
m+0x631457)</div><div>=C2=A0 =C2=A0 #4 DrawImage /home/exp/work/gm/GM-tsan/=
magick/render.c:2797:22 (gm+0x61d3a8)</div><div>=C2=A0 =C2=A0 #5 ReadMVGIma=
ge /home/exp/work/gm/GM-tsan/coders/mvg.c:237:10 (gm+0x8e2ea6)</div><div>=
=C2=A0 =C2=A0 #6 ReadImage /home/exp/work/gm/GM-tsan/magick/constitute.c:16=
07:13 (gm+0x555462)</div><div>=C2=A0 =C2=A0 #7 ReadSVGImage /home/exp/work/=
gm/GM-tsan/coders/svg.c:3945:13 (gm+0x98ca4b)</div><div>=C2=A0 =C2=A0 #8 Re=
adImage /home/exp/work/gm/GM-tsan/magick/constitute.c:1607:13 (gm+0x555462)=
</div><div>=C2=A0 =C2=A0 #9 ConvertImageCommand /home/exp/work/gm/GM-tsan/m=
agick/command.c:4362:22 (gm+0x4e225a)</div><div>=C2=A0 =C2=A0 #10 MagickCom=
mand /home/exp/work/gm/GM-tsan/magick/command.c:8886:17 (gm+0x5136b2)</div>=
<div>=C2=A0 =C2=A0 #11 GMCommandSingle /home/exp/work/gm/GM-tsan/magick/com=
mand.c:17408:10 (gm+0x539381)</div><div>=C2=A0 =C2=A0 #12 GMCommand /home/e=
xp/work/gm/GM-tsan/magick/command.c:17461:16 (gm+0x539025)</div><div>=C2=A0=
 =C2=A0 #13 main /home/exp/work/gm/GM-tsan/utilities/gm.c:61:10 (gm+0x4c242=
b)</div><div><br></div><div>=C2=A0 Location is stack of main thread.</div><=
div><br></div><div>=C2=A0 Thread T6 (tid=3D29981, running) created by main =
thread at:</div><div>=C2=A0 =C2=A0 #0 pthread_create &lt;null&gt; (gm+0x433=
666)</div><div>=C2=A0 =C2=A0 #1 __kmp_create_worker /home/exp/work/imagemag=
ick/openmp/BUILD/../runtime/src/z_Linux_util.cpp:958:14 (libomp.so+0x6ef74)=
</div><div>=C2=A0 =C2=A0 #2 DrawImage /home/exp/work/gm/GM-tsan/magick/rend=
er.c:3538:20 (gm+0x624fd1)</div><div>=C2=A0 =C2=A0 #3 DrawPatternPath /home=
/exp/work/gm/GM-tsan/magick/render.c:4610:10 (gm+0x631457)</div><div>=C2=A0=
 =C2=A0 #4 DrawImage /home/exp/work/gm/GM-tsan/magick/render.c:2797:22 (gm+=
0x61d3a8)</div><div>=C2=A0 =C2=A0 #5 ReadMVGImage /home/exp/work/gm/GM-tsan=
/coders/mvg.c:237:10 (gm+0x8e2ea6)</div><div>=C2=A0 =C2=A0 #6 ReadImage /ho=
me/exp/work/gm/GM-tsan/magick/constitute.c:1607:13 (gm+0x555462)</div><div>=
=C2=A0 =C2=A0 #7 ReadSVGImage /home/exp/work/gm/GM-tsan/coders/svg.c:3945:1=
3 (gm+0x98ca4b)</div><div>=C2=A0 =C2=A0 #8 ReadImage /home/exp/work/gm/GM-t=
san/magick/constitute.c:1607:13 (gm+0x555462)</div><div>=C2=A0 =C2=A0 #9 Co=
nvertImageCommand /home/exp/work/gm/GM-tsan/magick/command.c:4362:22 (gm+0x=
4e225a)</div><div>=C2=A0 =C2=A0 #10 MagickCommand /home/exp/work/gm/GM-tsan=
/magick/command.c:8886:17 (gm+0x5136b2)</div><div>=C2=A0 =C2=A0 #11 GMComma=
ndSingle /home/exp/work/gm/GM-tsan/magick/command.c:17408:10 (gm+0x539381)<=
/div><div>=C2=A0 =C2=A0 #12 GMCommand /home/exp/work/gm/GM-tsan/magick/comm=
and.c:17461:16 (gm+0x539025)</div><div>=C2=A0 =C2=A0 #13 main /home/exp/wor=
k/gm/GM-tsan/utilities/gm.c:61:10 (gm+0x4c242b)</div></div><div><div><br></=
div><div>SUMMARY: ThreadSanitizer: data race (/home/exp/work/gm/GM-tsan/ins=
tall/bin/gm+0x476040) in __tsan_atomic64_fetch_add</div></div><div><br></di=
v><div>This is suspicious since &quot;omp_outlined&quot; seems to cause the=
 false alarms.</div><div>I also noticed this:</div><div><a href=3D"https://=
stackoverflow.com/questions/33004809/can-i-use-thread-sanitizer-for-openmp-=
programs">https://stackoverflow.com/questions/33004809/can-i-use-thread-san=
itizer-for-openmp-programs</a><br></div><div>And maybe I will try=C2=A0<a h=
ref=3D"https://github.com/PRUNER/archer" rel=3D"nofollow" style=3D"margin:0=
px;padding:0px;border:0px;font-variant-numeric:inherit;font-variant-east-as=
ian:inherit;font-stretch:inherit;line-height:inherit;font-family:Arial,&quo=
t;Helvetica Neue&quot;,Helvetica,sans-serif;font-size:15px;vertical-align:b=
aseline;box-sizing:inherit;color:rgb(0,89,153)">https://github.com/PRUNER/a=
rcher</a>=C2=A0instead.</div><blockquote class=3D"gmail_quote" style=3D"mar=
gin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1=
ex">
<br>
Recent GraphicsMagick uses &#39;pragma omp atomic&#39; and &#39;pragma omp =
flush&#39; <br>
in pixel_iterator.c rather than using critical sections.=C2=A0 I am not <br=
>
sure how a data-race detector deals with OpenMP &#39;flush&#39; requests <b=
r>
(synchronize thread cached memory with with shared memory) since they <br>
are not the same as a lock and might look like a data-race.=C2=A0 Releases =
<br>
prior to 1.3.31 used critical sections.<br></blockquote><div>I&#39;m trying=
 some concurrent detection techniques, so I can try GM versions prior to 1.=
3.31,</div><div>so thanks for this tip!=C2=A0<br></div><blockquote class=3D=
"gmail_quote" style=3D"margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(2=
04,204,204);padding-left:1ex">
<br>
Long ago I used valgrind&#39;s helgrind and drd modes to search for data <b=
r>
races.=C2=A0 This required building a replacement libgomp based on pthreads=
 <br>
rather than special Linux interfaces.<br></blockquote><div>Yeah, there seem=
s a &quot;-disable-linux-futex&quot; for gcc to build openmp. And I was jus=
t</div><div>wondering whether=C2=A0 `=C2=A0-DLIBOMP_TSAN_SUPPORT=3DTRUE` is=
 the equivalent</div><div>(unfortunately, it seems NOT). I guess I will ask=
 the ThreadSanitizer community for</div><div>some more help.</div><blockquo=
te class=3D"gmail_quote" style=3D"margin:0px 0px 0px 0.8ex;border-left:1px =
solid rgb(204,204,204);padding-left:1ex">
<br>
There are two things which are normally shared in GM OpenMP loops <br>
other than one mutex lock in pixel_cache.c.=C2=A0 These are the error <br>
status (to know when all the threads in the team should try to quit <br>
because one of them reported an error), and the progress callback (to <br>
report progress if a progress monitor is enabled).<br>
<br>
Independent testing and analysis of GraphicsMagick is certainly <br>
valuable, but it is wise to identify specific code which should be <br>
corrected.<br>
<br>
Bob<br>
-- <br>
Bob Friesenhahn<br>
<a href=3D"mailto:[email protected]" target=3D"_blank">bfriesen@=
simple.dallas.tx.us</a>, <a href=3D"http://www.simplesystems.org/users/bfri=
esen/" rel=3D"noreferrer" target=3D"_blank">http://www.simplesystems.org/us=
ers/bfriesen/</a><br>
GraphicsMagick Maintainer,=C2=A0 =C2=A0 <a href=3D"http://www.GraphicsMagic=
k.org/" rel=3D"noreferrer" target=3D"_blank">http://www.GraphicsMagick.org/=
</a><br>
Public Key,=C2=A0 =C2=A0 =C2=A0<a href=3D"http://www.simplesystems.org/user=
s/bfriesen/public-key.txt" rel=3D"noreferrer" target=3D"_blank">http://www.=
simplesystems.org/users/bfriesen/public-key.txt</a><br>
<br>
<br>
_______________________________________________<br>
Graphicsmagick-bugs mailing list<br>
<a href=3D"mailto:[email protected]" target=3D"_bla=
nk">[email protected]</a><br>
<a href=3D"https://lists.sourceforge.net/lists/listinfo/graphicsmagick-bugs=
" rel=3D"noreferrer" target=3D"_blank">https://lists.sourceforge.net/lists/=
listinfo/graphicsmagick-bugs</a><br>
</blockquote></div></div></div></div></div></div></div></div>

--000000000000fe47d4058129bde3--


--===============1381456323417732948==
Content-Type: text/plain; charset="us-ascii"
MIME-Version: 1.0
Content-Transfer-Encoding: 7bit
Content-Disposition: inline


--===============1381456323417732948==
Content-Type: text/plain; charset="us-ascii"
MIME-Version: 1.0
Content-Transfer-Encoding: 7bit
Content-Disposition: inline

_______________________________________________
Graphicsmagick-bugs mailing list
[email protected]
https://lists.sourceforge.net/lists/listinfo/graphicsmagick-bugs

--===============1381456323417732948==--