1446665 - frequent bustage for Linux x64 opt build-linux64-base-toolchains/opt (Bb) with "profile data may be out of date" when Gecko 61 merges to Beta on 2018-04-26

Status: RESOLVED FIXED

(Firefox Build System :: General, defect)

Description

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

central-as-beta simulation: https://treeherder.mozilla.org/#/jobs?repo=try&revision=3b12ef97b1b8da8b50098088781dfa7770f17809&filter-resultStatus=testfailed&filter-resultStatus=busted&filter-resultStatus=exception&filter-resultStatus=retry&filter-resultStatus=usercancel&filter-resultStatus=runnable&selectedJob=168682577

This issue didn't show up in yesterday's simulation. Fallout from bug 1444291?

Log: https://treeherder.mozilla.org/logviewer.html#?job_id=168682513&repo=try

/builds/worker/workspace/build/src/security/sandbox/common/SandboxSettings.cpp:100:1: error: source locations for function '_ZN7mozillaL26SandboxSettingsConstructorEP11nsISupportsRK4nsIDPPv' have changed, the profile data may be out of date [-Werror]

Comment 1

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

Issue didn't reproduce with today's central-as-beta simulations: https://treeherder.mozilla.org/#/jobs?repo=try&revision=9b01463adc3d463336d837c987bca01fbf5afb6a&filter-resultStatus=testfailed&filter-resultStatus=busted&filter-resultStatus=exception&filter-resultStatus=retry&filter-resultStatus=usercancel&filter-resultStatus=runnable&group_state=expanded

Pushlog from yesterday to today: https://hg.mozilla.org/mozilla-central/pushloghtml?fromchange=97160a734959af73cc97af0bf8d198e301ebedae%20&tochange=2c4a055ed5d45fe9ca33ae1b450b40e31c9fb8aa

Fixed by a toolchain rebuild?

Comment 2

[Haik Aftandilian [:haik]]

I made sure the failing revision didn't include the backed out version of bug 1444291 and it didn't.

The changes in bug 1444291 to SandboxSettings.{h,cpp} were ifdef'd to be Mac only, but line numbers for functions on Linux would have still changed. Not knowing how PGO builds work, this sounds like a build system bug where intermediate files are not getting automatically overwritten when source files change, but I would expect that to cause major problems.

@ted, have you ever seen this type of intermittent build failure?

Comment 3

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

This hit again and like the first time for both the early and the late beta simulations:

Early beta: https://treeherder.mozilla.org/#/jobs?repo=try&revision=678c235ce9b3c3d02b54f1b5055ee983b44df155&filter-resultStatus=testfailed&filter-resultStatus=busted&filter-resultStatus=exception&filter-resultStatus=retry&filter-resultStatus=usercancel&filter-resultStatus=runnable&selectedJob=169161525
Late beta: https://treeherder.mozilla.org/#/jobs?repo=try&revision=3d5fd30ab9ba2f0a90cb515f5f53462e0f1ef806&filter-resultStatus=testfailed&filter-resultStatus=busted&filter-resultStatus=exception&filter-resultStatus=retry&filter-resultStatus=usercancel&filter-resultStatus=runnable&selectedJob=169161828

Log: https://treeherder.mozilla.org/logviewer.html#?job_id=169161525&repo=try

/builds/worker/workspace/build/src/js/src/ctypes/Library.cpp:383:1: error: source locations for function '_ZNK2JS5Value7isMagicE10JSWhyMagic.isra.6' have changed, the profile data may be out of date [-Werror]
/builds/worker/workspace/build/src/js/src/ctypes/Library.cpp:383:1: error: source locations for function '_ZNK2JS5Value7isMagicE10JSWhyMagic.isra.6' have changed, the profile data may be out of date [-Werror]
/builds/worker/workspace/build/src/js/src/ctypes/Library.cpp:383:1: error: source locations for function '_ZNK2JS5Value11isPrimitiveEv' have changed, the profile data may be out of date [-Werror]
/builds/worker/workspace/build/src/js/src/ctypes/Library.cpp:383:1: error: source locations for function '_ZNK2JS5Value11isPrimitiveEv' have changed, the profile data may be out of date [-Werror]

Comment 4

[(not currently active) Ted Mielczarek]

This isn't something I've seen before. This error comes from `-Wcoverage-mismatch`:
https://github.com/gcc-mirror/gcc/blob/ff6d4d649827edcaa28b31489f24895a196d62b5/gcc/coverage.c#L418

which we enable for PGO:
https://dxr.mozilla.org/mozilla-central/rev/6ff60a083701d08c52702daf50f28e8f46ae3a1c/build/moz.configure/toolchain.configure#1248

...but we also explicitly pass `-Wno-error=coverage-mismatch`:
https://dxr.mozilla.org/mozilla-central/rev/6ff60a083701d08c52702daf50f28e8f46ae3a1c/build/moz.configure/warnings.configure#97

...so I'm not sure why gcc is treating this as an error. I'm also not sure why this is even happening in the first place--this source file is not generated or anything, and the compiler arguments are exactly the same between the two compiles (modulo the expected -fprofile bits):
--- /tmp/bug1446665-compile-1   2018-03-20 09:23:09 -0400
+++ /tmp/bug1446665-compile-2   2018-03-20 09:22:41 -0400
@@ -2,7 +2,7 @@
 /builds/worker/workspace/build/src/gcc/bin/g++
 -std=gnu++14
 -o
-Library.i_o
+Library.o
 -c
 -I/builds/worker/workspace/build/src/obj-firefox/dist/system_wrappers
 -include
@@ -63,11 +63,13 @@
 -Wno-shadow
 -Werror=format
 -fno-strict-aliasing
--fprofile-generate
+-fprofile-use
+-fprofile-correction
+-Wcoverage-mismatch
 -MD
 -MP
 -MF
-.deps/Library.i_o.pp
+.deps/Library.o.pp

Maybe glandium has a better idea?

Comment 5

[(not currently active) Ted Mielczarek]

Hmm, actually, I wonder if this is fallout from the sccache update (bug 1445218), specifically this change:
https://github.com/mozilla/sccache/pull/208

That made it so sccache passed `-P` when running the preprocessor to generate the source hash, which removes #line directives. With that in place, if you made changes to a source file that only changed the line numbers of the file (like platform-specific #ifdefs for a different platform), sccache could still get a cache hit in the `-fprofile-generate` compile, but then presumably the `-fprofile-use` compile would in fact have different line numbers.

Comment 6

[(not currently active) Ted Mielczarek]

Yeah, OK, I can reproduce this locally with a simple testcase:

1) I wrote a simple C source file (https://gist.github.com/dd6df63700437e37f370c33e990ef1cf) and another copy of it with just an additional line of comment in a section that's #ifdef'ed out (https://gist.github.com/96e1eb3972d399c5a814a0e375676c5a):

luser@eye7:/build/gcc-pgo-test$ diff -u test.c test2.c
--- test.c	2018-03-20 09:47:39.483480398 -0400
+++ test2.c	2018-03-20 09:47:34.259491450 -0400
@@ -1,6 +1,7 @@
 #ifdef NOT_DEFINED
 /*
  * blank space
+ * more blank space
  */
 #endif

2) With `gcc -E -P`, the preprocessor output for both files is exactly the same:

luser@eye7:/build/gcc-pgo-test$ gcc -E -P test.c | sha512sum
2b4c1686715b57375ac141452c22f094ce4bbb29a776c3b4e034380b714be11f563b74f56e98420de07c6f2daaf43d23b44d5f05f57ba6cd2b9f83dde1202c1e  -
luser@eye7:/build/gcc-pgo-test$ gcc -E -P test2.c | sha512sum
2b4c1686715b57375ac141452c22f094ce4bbb29a776c3b4e034380b714be11f563b74f56e98420de07c6f2daaf43d23b44d5f05f57ba6cd2b9f83dde1202c1e  -

3) Compiling the first source file with `-fprofile-generate`, linking and running the binary, then compiling again with `-fprofile-use` all works, using sccache to wrap the compiler:

luser@eye7:/build/gcc-pgo-test$ /build/sccache/target/debug/sccache gcc -c -o test.o -fprofile-generate test.c
luser@eye7:/build/gcc-pgo-test$ /build/sccache/target/debug/sccache gcc -o test -fprofile-generate test.o
luser@eye7:/build/gcc-pgo-test$ ./test
luser@eye7:/build/gcc-pgo-test$ /build/sccache/target/debug/sccache gcc -c -o test.o -fprofile-use test.c
luser@eye7:/build/gcc-pgo-test$ /build/sccache/target/debug/sccache gcc -o test -fprofile-use test.oluser@eye7:/build/gcc-pgo-test$ /build/sccache/target/debug/sccache --show-stats
Compile requests                 5
Compile requests executed        1
Cache hits                       0
Cache misses                     1
Cache timeouts                   0
Cache read errors                0
Forced recaches                  0
Cache write errors               0
Compilation failures             0
Cache errors                     0
Non-cacheable compilations       0
Non-cacheable calls              3
Non-compilation calls            1
Unsupported compiler calls       0
Average cache write          0.000 s
Average cache read miss      0.024 s
Average cache read hit       0.000 s
Cache location             Local disk: "/home/luser/.cache/sccache"
Cache size                       5 GiB
Max cache size                  10 GiB

4) Copying the second source file over to test.c then repeating the process hits this error:

luser@eye7:/build/gcc-pgo-test$ cp test2.c test.c
luser@eye7:/build/gcc-pgo-test$ /build/sccache/target/debug/sccache gcc -c -o test.o -fprofile-generate test.c
luser@eye7:/build/gcc-pgo-test$ /build/sccache/target/debug/sccache gcc -o test -fprofile-generate test.o
luser@eye7:/build/gcc-pgo-test$ ./test
luser@eye7:/build/gcc-pgo-test$ /build/sccache/target/debug/sccache gcc -c -o test.o -fprofile-use test.c
test.c: In function ‘main’:
test.c:14:1: error: source locations for function ‘main’ have changed, the profile data may be out of date [-Werror=coverage-mismatch]
 }
 ^
test.c:14:1: error: source locations for function ‘main’ have changed, the profile data may be out of date [-Werror=coverage-mismatch]
test.c: In function ‘foo’:
test.c:14:1: error: source locations for function ‘foo’ have changed, the profile data may be out of date [-Werror=coverage-mismatch]
test.c:14:1: error: source locations for function ‘foo’ have changed, the profile data may be out of date [-Werror=coverage-mismatch]
cc1: some warnings being treated as errors
luser@eye7:/build/gcc-pgo-test$ /build/sccache/target/debug/sccache --show-stats
Compile requests                 8
Compile requests executed        2
Cache hits                       1
Cache misses                     1
Cache timeouts                   0
Cache read errors                0
Forced recaches                  0
Cache write errors               0
Compilation failures             0
Cache errors                     0
Non-cacheable compilations       0
Non-cacheable calls              4
Non-compilation calls            2
Unsupported compiler calls       0
Average cache write          0.000 s
Average cache read miss      0.024 s
Average cache read hit       0.000 s
Cache location             Local disk: "/home/luser/.cache/sccache"
Cache size                       5 GiB
Max cache size                  10 GiB

Comment 7

[(not currently active) Ted Mielczarek]

I landed a fix in sccache:
https://github.com/mozilla/sccache/commit/9f4c18b4a6300e3a9250a09811cc985311c20217

I'll get a patch up for updating sccache again.

Comment 8

[(not currently active) Ted Mielczarek]

Attachment: bug 1446665 - update sccache to pick up a fix for a PGO build failure.

Review commit: https://reviewboard.mozilla.org/r/230624/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/230624/

Comment 9

[Nathan Froyd [:froydnj]]

Comment on attachment 8961811 [details]
bug 1446665 - update sccache to pick up a fix for a PGO build failure.

https://reviewboard.mozilla.org/r/230624/#review236126

Comment 10

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/d2362cea7172
update sccache to pick up a fix for a PGO build failure. r=froydnj

Comment 11

[Raul Gurzau (:RaulG)]

https://hg.mozilla.org/mozilla-central/rev/d2362cea7172