[PR38292] corrupted profile info with -O[23] -fprofile-use

Bug #598462 reported by Matthias Klose
10
This bug affects 1 person
Affects Status Importance Assigned to Milestone
Linaro GCC
Won't Fix
Low
Unassigned
gcc
Fix Released
Medium
gcc-4.4 (Ubuntu)
Undecided
Unassigned
gcc-4.5 (Ubuntu)
Undecided
Unassigned

Bug Description

Binary package hint: gcc-4.4

seen with a profiled build (make profile-opt
PROFILE_TASK='$(srcdir)/Lib/test/regrtest.py') building python-3.0rc3 on
i486-linux-gnu. Using pybench as the PROFILE_TASK doesn't show this bug).

gcc -pthread -c -fno-strict-aliasing -DNDEBUG -g -O2 -Wall -Wstrict-prototypes
-fprofile-use -I. -IInclude -I../Include -DPy_BUILD_CORE -o Modules/config.o
Modules/config.c
../Python/thread.c: In function 'PyThread_acquire_lock':
../Python/thread.c:419: error: corrupted profile info: number of executions for
edge 16-3 thought to be -1
../Python/thread.c:419: error: corrupted profile info: number of executions for
edge 16-17 thought to be 5657524
make[3]: *** [Python/thread.o] Error 1

Revision history for this message
In , Jakub-gcc (jakub-gcc) wrote :

Subject: Bug 38292

Author: jakub
Date: Wed Feb 4 19:50:58 2009
New Revision: 143937

URL: http://gcc.gnu.org/viewcvs?root=gcc&view=rev&rev=143937
Log:
 PR tree-optimization/38977
 PR gcov-profile/38292
 * calls.c (special_function_p): Disregard __builtin_
 prefix.

Modified:
    trunk/gcc/ChangeLog
    trunk/gcc/calls.c

Revision history for this message
In , Matthias Klose (doko) wrote :

still seen with a backport of the patch to the 4.3 branch and with trunk 20090211 on amd64. works on i486.

gcc -pthread -c -fno-strict-aliasing -DNDEBUG -g -fwrapv -O3 -Wall -Wstrict-prototypes -fprofile-use -I. -IInclude -I../Include -DPy_BUILD_CORE -o Modules/config.o Modules/config.c
../Python/thread.c: In function 'PyThread_acquire_lock':
../Python/thread.c:423: error: corrupted profile info: profile data is not flow-consistent
../Python/thread.c:423: error: corrupted profile info: number of executions for edge 16-3 thought to be -7
../Python/thread.c:423: error: corrupted profile info: number of executions for edge 16-17 thought to be 4920917

Revision history for this message
In , Rguenth (rguenth) wrote :

Can you check if moving the PR38977 fix to special_function_p (handling
plain fork there) fixes it? What is the contents of thread.c?

Revision history for this message
In , Matthias Klose (doko) wrote :

Created attachment 17286
thread.c source file

Revision history for this message
In , Matthias Klose (doko) wrote :

Created attachment 17287
thread_pthread.h header

Revision history for this message
In , Matthias Klose (doko) wrote :

a build with the suggested change doesn't show any change.

--- gcc/calls.c~ 2009-02-05 09:30:24.000000000 +0100
+++ gcc/calls.c 2009-02-12 15:17:08.000000000 +0100
@@ -530,6 +530,8 @@
        }
       else if ((tname[0] == 'q' && tname[1] == 's'
                && ! strcmp (tname, "qsetjmp"))
+ || (tname[0] == 'f' && tname[1] == 'o'
+ && ! strcmp (tname, "fork"))
               || (tname[0] == 'v' && tname[1] == 'f'
                   && ! strcmp (tname, "vfork"))
               || (tname[0] == 'g' && tname[1] == 'e'

Revision history for this message
In , Matthias Klose (doko) wrote :

seen as well on sparc-linux, x86_64-linux and i486-linux (when built with -mcpu=i686 -mtune=i586), although triggered in different files.

Revision history for this message
In , Matthias Klose (doko) wrote :

same behaviour with the 4.4.1 release

Revision history for this message
In , Rguenth (rguenth) wrote :

GCC 4.3.4 is being released, adjusting target milestone.

Revision history for this message
In , Rguenth (rguenth) wrote :

GCC 4.3.5 is being released, adjusting target milestone.

Revision history for this message
Matthias Klose (doko) wrote :

Binary package hint: gcc-4.4

seen with a profiled build (make profile-opt
PROFILE_TASK='$(srcdir)/Lib/test/regrtest.py') building python-3.0rc3 on
i486-linux-gnu. Using pybench as the PROFILE_TASK doesn't show this bug).

gcc -pthread -c -fno-strict-aliasing -DNDEBUG -g -O2 -Wall -Wstrict-prototypes
-fprofile-use -I. -IInclude -I../Include -DPy_BUILD_CORE -o Modules/config.o
Modules/config.c
../Python/thread.c: In function 'PyThread_acquire_lock':
../Python/thread.c:419: error: corrupted profile info: number of executions for
edge 16-3 thought to be -1
../Python/thread.c:419: error: corrupted profile info: number of executions for
edge 16-17 thought to be 5657524
make[3]: *** [Python/thread.o] Error 1

tags: added: armel toolchain
Revision history for this message
Matthias Klose (doko) wrote :

tagging for armel (but not specific for armel). the current python2.6 build in maverick does build, but not python3.1 when using the profiled build.

Changed in gcc:
status: Unknown → New
Revision history for this message
Barry Warsaw (barry) wrote :

Fails on amd64 too, building _ssl.c

Revision history for this message
Matthias Klose (doko) wrote :
Changed in gcc-linaro:
importance: Undecided → Low
Revision history for this message
Matthias Klose (doko) wrote :

may turn into a blueprint on implementing profile guided optimization

Changed in gcc-4.4 (Ubuntu):
status: New → Confirmed
Revision history for this message
Matthias Klose (doko) wrote :
Revision history for this message
Loïc Minier (lool) wrote :

(Not a Linaro-specific regression)

Revision history for this message
Michael Hope (michaelh1) wrote :

Note that this is not Linaro specific, but we plan to get PGO working for ARM this cycle:
 https://blueprints.launchpad.net/gcc-linaro/+spec/profiler-driven-feedback

Medium priority so might happen.

Revision history for this message
In , Hubicka (hubicka) wrote :

Richard's reorg of profiling to SSA uncovered some of issues with pure&const functions that are fixed in the current mainline. Can you, please, check if that solves your problem?

Revision history for this message
In , Matthias Klose (doko) wrote :

I ran into bug #47248 trying to build a recent snapshot.

Revision history for this message
Ulrich Weigand (uweigand) wrote :

I just successfully completed a profiled build of python3.2_3.2~b2-1.dsc on armel Natty using the Ubuntu/Linaro 4.5.1-10ubuntu3 system compiler, so the problem seems to no longer exist on 4.5.

Do we still care about 4.4 at this point?

Revision history for this message
Matthias Klose (doko) wrote :

the just uploaded python3.2_3.2~rc1-1ubuntu1 fails with the current Ubuntu/Linaro gcc-4.5 in natty on amd64, i386 and powerpc. armel is the only architecture which seems to build.

Building with gcc-4.6 from the ubuntu-toolchain-r/test ppa fails to build while running the setup.py with the just built python trying to build the extensions.

Revision history for this message
Matthias Klose (doko) wrote :

no, 4.4 is not interesting anymore for this issue.

Changed in gcc-4.4 (Ubuntu):
status: Confirmed → Won't Fix
Changed in gcc-4.5 (Ubuntu):
status: New → Confirmed
Revision history for this message
Matthias Klose (doko) wrote :

with gcc-4.6 from the ~ubuntu-toolchain-r/test PPA I get (with the just built python (built with -fprofile-generate):

build-static$ ./python
XXX lineno: 1101, opcode: 0
Fatal Python error: Py_Initialize: Unable to get the locale encoding
Traceback (most recent call last):
  File "/home/packages/python/3.2/python3.2-3.2~rc1/build-static/../Lib/encodings/__init__.py", line 31, in <module>
XXX lineno: 39, opcode: 0
Aborted

Revision history for this message
In , Matthias Klose (doko) wrote :

trying to build python 3.2~rc1, I run into:

I get (with the just built python (built with -fprofile-generate):

build-static$ ./python
XXX lineno: 1101, opcode: 0
Fatal Python error: Py_Initialize: Unable to get the locale encoding
Traceback (most recent call last):
  File "/home/packages/python/3.2/python3.2-3.2~rc1/build-static/../Lib/encodings/__init__.py", line 31, in <module>
XXX lineno: 39, opcode: 0
Aborted

The build is ok with the normal build.

Revision history for this message
In , Matthias Klose (doko) wrote :

no, normal python build fails too, this is reported as bug #47271.

Revision history for this message
Matthias Klose (doko) wrote :

no, normal python build fails too, this is reported as upstream bug
http://gcc.gnu.org/bugzilla/show_bug.cgi?id=47271

Revision history for this message
In , Matthias Klose (doko) wrote :

hmm, can't set the status back to NEW, just to RESOLVED. ...

a normal build of 3.2rc1 succeeds with trunk r169142 and the proposed fix for PR47271.

the profiled build still fails with:

gcc-4.6 -pthread -c -DNDEBUG -g -fwrapv -O3 -Wall -Wstrict-prototypes -fprofile-use -I. -IInclude -I../Include -DPy_BUILD_CORE -o Python/bltinmodule.o ../Python/bltinmodule.c
../Python/bltinmodule.c: In function 'builtin___build_class__':
../Python/bltinmodule.c:40:23: warning: variable 'nbases' set but not used [-Wunused-but-set-variable]
../Python/bltinmodule.c: In function 'builtin_exec':
../Python/bltinmodule.c:769:9: warning: variable 'plain' set but not used [-Wunused-but-set-variable]
gcc-4.6 -pthread -c -DNDEBUG -g -fwrapv -O3 -Wall -Wstrict-prototypes -fprofile-use -I. -IInclude -I../Include -DPy_BUILD_CORE -o Python/ceval.o ../Python/ceval.c
../Python/ceval.c: In function 'PyEval_RestoreThread':
../Python/ceval.c:4472:1: error: corrupted profile info: profile data is not flow-consistent
../Python/ceval.c:4472:1: error: corrupted profile info: number of executions for edge 4-5 thought to be 2002859
../Python/ceval.c:4472:1: error: corrupted profile info: number of executions for edge 4-1 thought to be -9
make[3]: *** [Python/ceval.o] Error 1

Revision history for this message
Matthias Klose (doko) wrote :

 updated PR38292, still seen with trunk and the proposed fix for PR47271.

Revision history for this message
In , Manu-gcc (manu-gcc) wrote :

(In reply to comment #15)
> hmm, can't set the status back to NEW, just to RESOLVED. ...
>

You have to use your gcc account (I think).

Changed in gcc:
importance: Unknown → Medium
status: New → Confirmed
Revision history for this message
Ulrich Weigand (uweigand) wrote :

I've now reproduced and analyzed the problem on i386 with GCC 4.5, i.e. building python3.2-3.2~rc1 using the 4.5.1-1ubuntu3 compiler.

It turns out that there is no particular bug here (the CFG looks identical in the -fprofile-generate and -fprofile-use cases), but instead we're running in a known limitation of the profiling code: it is not thread-safe.

This means that when using profiling in a multi-threaded application, profile counters may not be fully accurate since counter updates may have been skipped due to race conditions in accessing the counters.

This is consistent with the symptoms we're seeing: the problem disappears on my (single-core) ARM board, but is present on i386/amd64/ppc all of which presumably are built on multi-core machines, which increases the chance of actually running into one of those race conditions. The functions where the problem shows up likewise tend to be places where high thread contention is expected (e.g. synchronization primitives).

The recommended way to deal with this problem is to use the -fprofile-correction flag, which will employ heuristics to attempt to adjust incorrect counters, instead of simply aborting compilation. See the manual page:

       -fprofile-correction
           Profiles collected using an instrumented binary for multi-threaded
           programs may be inconsistent due to missed counter updates. When
           this option is specified, GCC will use heuristics to correct or
           smooth out such inconsistencies. By default, GCC will emit an error
           message when an inconsistent profile is detected.

I've added the -fprofile-correction flag to the build_all_use_profile rule in Makefile.pre.in, and with this change I was able to successfully build the package (only i386 tested).

The issues with 4.6 must be some other problem (note that the profiling code was significantly rewritten between 4.5 and 4.6, so we may well run into new problems here). I'll look into this next.

Revision history for this message
Ulrich Weigand (uweigand) wrote :

It turns out there is no other problem on 4.6. The compiler in the ubuntu-toolchain-r/test ppa does not build Python at all due to PR 47271. After adding the fix for this PR to the ppa package, the compiler runs into the exact same problem as described for 4.5 in the previous comment. By using -fprofile-correction as above, I was able to successfully build the python3.2-3.2~rc1 package with profile-directed feedback enabled (on i386).

So to summarize the problems discussed in this thread:

- GCC 4.6 had a regression where it failed to built Python at all. This is PR 47271, and is already fixed in mainline.

- GCC (any version!) uses thread-unsafe code to update profile counters, which means they can always be slightly wrong when profiling multi-threaded code, and therefore inconsistent with the flow graph. This will happen most frequently on multi-core machines, and in functions that experience high thread contention. The problem can be worked around using -fprofile-correction. Using this flag should enable profiled builds of Python with (at least) GCC 4.5 and 4.6.

Changed in gcc-linaro:
status: New → Triaged
Revision history for this message
Michael Hope (michaelh1) wrote :

Marked as wont-fix as the compiler is working as designed.

Changed in gcc-linaro:
status: Triaged → Won't Fix
Revision history for this message
In , Rguenth (rguenth) wrote :

4.3 branch is being closed, moving to 4.4.7 target.

Revision history for this message
In , Pinskia (pinskia) wrote :

I don't think this is a regression now as we never had good thread support for gcov/profiling. That is we don't do atomic adds for the profiling.

Revision history for this message
In , Rguenth (rguenth) wrote :

We seem to miss a reproducer here.

Changed in gcc:
status: Confirmed → Incomplete
Revision history for this message
In , Jakub-gcc (jakub-gcc) wrote :

4.4 branch is being closed, moving to 4.5.4 target.

Revision history for this message
In , Doko-v (doko-v) wrote :

the python builds works when built using -fprofile-correction

Changed in gcc:
status: Incomplete → Fix Released
To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.