1738300 - Permanent Android cppunit TestBaseProfiler | test failed with return code 139 when Gecko 95 merges to Beta on 2021-11-01

Status: RESOLVED FIXED

(Core :: Gecko Profiler, defect, P2)

Description

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

• central-as-beta simulation
• How to run these simulations
• Failure log

Android 7.0 x86-64 WebRender debug-isolated-process is the only Android platform for which it passes. Could this be related to Fission being turned off for testing (bug 1736859)? I will do a Try push for this and post the result here.

[task 2021-10-28T13:33:21.327Z] 13:33:21     INFO -  TEST-START | TestBaseProfiler
[task 2021-10-28T13:33:26.996Z] 13:33:26     INFO -  TestBaseProfiler |
[task 2021-10-28T13:33:26.996Z] 13:33:26     INFO -  BaseTestProfiler -- pid: 4714, tid: 4714
[task 2021-10-28T13:33:26.996Z] 13:33:26     INFO -  TestProfilerUtils...
[task 2021-10-28T13:33:26.996Z] 13:33:26     INFO -  TestProfilerUtils done
[task 2021-10-28T13:33:26.996Z] 13:33:26     INFO -  TestProfiler starting -- pid: 4714, tid: 4714
[task 2021-10-28T13:33:26.996Z] 13:33:26     INFO -  TestPowerOfTwoMask...
[task 2021-10-28T13:33:26.996Z] 13:33:26     INFO -  TestPowerOfTwoMask done
[task 2021-10-28T13:33:26.996Z] 13:33:26     INFO -  TestPowerOfTwo...
[task 2021-10-28T13:33:26.996Z] 13:33:26     INFO -  TestPowerOfTwo done
[task 2021-10-28T13:33:26.997Z] 13:33:26     INFO -  TestLEB128...
[task 2021-10-28T13:33:26.997Z] 13:33:26     INFO -  TestLEB128 done
[task 2021-10-28T13:33:26.997Z] 13:33:26     INFO -  TestJSONTimeOutput...
[task 2021-10-28T13:33:26.997Z] 13:33:26     INFO -  TestJSONTimeOutput done
[task 2021-10-28T13:33:26.997Z] 13:33:26     INFO -  TestChunk...
[task 2021-10-28T13:33:26.997Z] 13:33:26     INFO -  TestChunk done
[task 2021-10-28T13:33:26.997Z] 13:33:26     INFO -  TestChunkManagerSingle...
[task 2021-10-28T13:33:26.997Z] 13:33:26     INFO -  TestChunkManagerSingle done
[task 2021-10-28T13:33:26.997Z] 13:33:26     INFO -  TestChunkManagerWithLocalLimit...
[task 2021-10-28T13:33:26.999Z] 13:33:26     INFO -  TestChunkManagerWithLocalLimit - Shuffle test timestamps: 9915.959000 9908.140000 9909.848000 9905.674000 9925.653000 9898.945000 9951.320000 9911.793000 9913.802000 9896.522000 9932.859000 9951.890000 9903.003000 9952.901000 9900.506000 9916.459000 9936.520000 9953.982000 9946.556000 9904.691000 9913.297000 9899.968000 9949.051000 9917.929000 9909.339000 9895.029000 9906.652000 9899.480000 9940.252000 9929.835000 9926.393000 9930.840000 9943.344000 9942.796000 9895.868000 9939.261000 9947.535000 9893.749000 9931.875000 9904.157000 9941.786000 9912.288000 9934.531000 9907.155000 9896.848000 9912.794000 9936.032000 9941.275000 9908.619000 9933.375000 9901.015000 9897.206000 9894.472000 9914.963000 9949.721000 9911.320000 9901.495000 9903.502000 9932.365000 9898.264000 9930.326000 9934.060000 9945.566000 9897.756000 9907.635000 9952.393000 9946.063000 9917.440000 9950.704000 9910.349000 9901.996000 9905.194000 9939.755000 9937.011000 9915.467000 9902.499000 9948.526000 9944.483000 9943.857000 9895.510000 9947.045000 9945.026000 9938.051000 9914.472000 9896.197000 9906.157000 9950.204000 9918.429000 9938.541000 9935.504000 9910.828000 9931.332000 9935.018000 9942.298000 9937.536000 9940.759000 9926.891000 9953.404000 9948.025000 9916.951000
[task 2021-10-28T13:33:26.999Z] 13:33:26     INFO -  TestChunkManagerWithLocalLimit done
[task 2021-10-28T13:33:26.999Z] 13:33:26     INFO -  TestControlledChunkManagerUpdate...
[task 2021-10-28T13:33:26.999Z] 13:33:26     INFO -  TestControlledChunkManagerUpdate done
[task 2021-10-28T13:33:26.999Z] 13:33:26     INFO -  TestControlledChunkManagerWithLocalLimit...
[task 2021-10-28T13:33:26.999Z] 13:33:26     INFO -  TestControlledChunkManagerWithLocalLimit done
[task 2021-10-28T13:33:26.999Z] 13:33:26     INFO -  TestChunkedBuffer...
[task 2021-10-28T13:33:26.999Z] 13:33:26     INFO -  TestChunkedBuffer done
[task 2021-10-28T13:33:26.999Z] 13:33:26     INFO -  TestChunkedBufferSingle...
[task 2021-10-28T13:33:26.999Z] 13:33:26     INFO -  TestChunkedBufferSingle done
[task 2021-10-28T13:33:26.999Z] 13:33:26     INFO -  TestModuloBuffer...
[task 2021-10-28T13:33:27.000Z] 13:33:26     INFO -  TestModuloBuffer done
[task 2021-10-28T13:33:27.000Z] 13:33:27     INFO -  TestBlocksRingBufferAPI...
[task 2021-10-28T13:33:27.000Z] 13:33:27     INFO -  TestBlocksRingBufferAPI done
[task 2021-10-28T13:33:27.000Z] 13:33:27     INFO -  TestBlocksRingBufferUnderlyingBufferChanges...
[task 2021-10-28T13:33:27.000Z] 13:33:27     INFO -  TestBlocksRingBufferUnderlyingBufferChanges done
[task 2021-10-28T13:33:27.000Z] 13:33:27     INFO -  TestBlocksRingBufferThreading...
[task 2021-10-28T13:33:27.000Z] 13:33:27     INFO -  Reader: range=1..1 (0 bytes) pushed=0 cleared=0 (alive=0)
[task 2021-10-28T13:33:27.000Z] 13:33:27     INFO -  Reader: range=1..1741 (1740 bytes) pushed=348 cleared=0 (alive=348)
[task 2021-10-28T13:33:27.000Z] 13:33:27     INFO -  Reader: range=17501..25677 (8176 bytes) pushed=2279 cleared=1879 (alive=400)
[task 2021-10-28T13:33:27.001Z] 13:33:27     INFO -  Reader: range=43576..51764 (8188 bytes) pushed=3900 cleared=3413 (alive=487)
[task 2021-10-28T13:33:27.001Z] 13:33:27     INFO -  Reader: range=70631..78820 (8189 bytes) pushed=5572 cleared=5092 (alive=480)
[task 2021-10-28T13:33:27.001Z] 13:33:27     INFO -  Reader: range=97237..105420 (8183 bytes) pushed=7295 cleared=6744 (alive=551)
[task 2021-10-28T13:33:27.001Z] 13:33:27     INFO -  Reader: range=122976..131160 (8184 bytes) pushed=8977 cleared=8459 (alive=518)
[task 2021-10-28T13:33:27.001Z] 13:33:27     INFO -  Reader: range=150741..158922 (8181 bytes) pushed=10675 cleared=10142 (alive=533)
[task 2021-10-28T13:33:27.001Z] 13:33:27     INFO -  Reader: range=175557..183745 (8188 bytes) pushed=12135 cleared=11678 (alive=457)
[task 2021-10-28T13:33:27.001Z] 13:33:27     INFO -  Reader: range=200156..208327 (8171 bytes) pushed=13770 cleared=13239 (alive=531)
[task 2021-10-28T13:33:27.002Z] 13:33:27     INFO -  Reader: range=226229..234408 (8179 bytes) pushed=15342 cleared=14909 (alive=433)
[task 2021-10-28T13:33:27.002Z] 13:33:27     INFO -  Reader: range=250667..258850 (8183 bytes) pushed=16899 cleared=16341 (alive=558)
[task 2021-10-28T13:33:27.002Z] 13:33:27     INFO -  Reader: range=277147..285326 (8179 bytes) pushed=18413 cleared=17993 (alive=420)
[task 2021-10-28T13:33:27.002Z] 13:33:27     INFO -  Reader: range=302285..310451 (8166 bytes) pushed=20002 cleared=19450 (alive=552)
[task 2021-10-28T13:33:27.002Z] 13:33:27     INFO -  Reader: range=329658..337845 (8187 bytes) pushed=21698 cleared=21188 (alive=510)
[task 2021-10-28T13:33:27.002Z] 13:33:27     INFO -  Reader: range=352691..360880 (8189 bytes) pushed=23118 cleared=22626 (alive=492)
[task 2021-10-28T13:33:27.002Z] 13:33:27     INFO -  Reader: range=378024..386214 (8190 bytes) pushed=24684 cleared=24160 (alive=524)
[task 2021-10-28T13:33:27.003Z] 13:33:27     INFO -  Reader: range=402818..410994 (8176 bytes) pushed=26274 cleared=25778 (alive=496)
[task 2021-10-28T13:33:27.003Z] 13:33:27     INFO -  Reader: range=429287..437477 (8190 bytes) pushed=27871 cleared=27380 (alive=491)
[task 2021-10-28T13:33:27.003Z] 13:33:27     INFO -  Reader: range=459078..467258 (8180 bytes) pushed=29474 cleared=29026 (alive=448)
[task 2021-10-28T13:33:27.003Z] 13:33:27     INFO -  Reader: range=486277..494468 (8191 bytes) pushed=30820 cleared=30450 (alive=370)
[task 2021-10-28T13:33:27.003Z] 13:33:27     INFO -  Reader: range=517560..525734 (8174 bytes) pushed=31973 cleared=31712 (alive=261)
[task 2021-10-28T13:33:27.003Z] 13:33:27     INFO -  Reader: range=542721..550913 (8192 bytes) pushed=32768 cleared=32512 (alive=256)
[task 2021-10-28T13:33:27.003Z] 13:33:27     INFO -  TestBlocksRingBufferThreading done
[task 2021-10-28T13:33:27.003Z] 13:33:27     INFO -  TestBlocksRingBufferSerialization...
[task 2021-10-28T13:33:27.004Z] 13:33:27     INFO -  TestBlocksRingBufferSeSegmentation fault
[task 2021-10-28T13:33:27.076Z] 13:33:27     INFO -  mozcrash checking /tmp/tmpken749wi for minidumps...
[task 2021-10-28T13:33:27.077Z] 13:33:27  WARNING -  TEST-UNEXPECTED-FAIL | TestBaseProfiler | test failed with return code 139

Comment 1

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

Could this be related to Fission being turned off for testing (bug 1736859)? I will do a Try push for this and post the result here.

Try push is still affected.

Comment 2

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

Bug 1734747 re-enabled PGO for those builds and bisection on Try confirms the issue started after the changes landed.

Comment 3

[Intermittent Failures Robot]

1 failures in 2845 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• try: 1

Platform and build breakdown:

• android-em-7-0-x86_64-shippable-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1738300&startday=2021-10-25&endday=2021-10-31&tree=all

Comment 4

[Gerald Squelart (he/him) (not at Mozilla since 2022-09-15)]

BlocksRingBuffer is slated for removal (bug 1695120).
So if it's too much trouble to debug, we could just bypass these tests as a quick fix here, with e.g.: #ifndef ANDROID, or even #if 0.

Glandium, would you like to have a go at it first, in case it could highlight potential issues in other code?

Comment 5

[Mike Hommey [:glandium]]

The test that is crashing is actually TestUniqueJSONStrings. I'm still trying to get more useful info about the crash.

Comment 6

[Gerald Squelart (he/him) (not at Mozilla since 2022-09-15)]

(In reply to Mike Hommey [:glandium] from comment #5)

The test that is crashing is actually TestUniqueJSONStrings. I'm still trying to get more useful info about the crash.

Oh no, that's a more important one that we still need!

Wild guesses:
Could it be one of those situations with malloc/new in one lib, free/delete in another one? We've had that kind of problem a few years ago.
As the name suggests, we use UniquePtrs in there, so could this be due to the incorrect deleter function being called?

Good luck, and let me know if I can help once you have more info.

Comment 7

[Mike Hommey [:glandium]]

There is what seems to be a miscompilation in mozilla::baseprofiler::ChunkedJSONWriteFunc::AllocChunk(unsigned long). Essentially, it's triggering a use-after-free because it's freeing the newChunk at the end of the function (because it doesn't actually realize the move). I'm testing a (stupid) workaround, but I'm also trying to track the miscompilation down to report it upstream if it's fully confirmed to be one. It seems to be LTO-specific.

Comment 8

[BugBot [:suhaib / :marco/ :calixte]]

Set release status flags based on info from the regressing bug 1734747

Comment 9

[Mike Hommey [:glandium]]

Filed https://bugs.llvm.org/show_bug.cgi?id=52412

Comment 10

[Mike Hommey [:glandium]]

Attachment: Bug 1738300 - Apply clang upstream patch fixing miscompilation.

Comment 11

[Cosmin Sabou [:CosminS]]

Patch works in today's beta-sim.

Comment 12

[Intermittent Failures Robot]

15 failures in 3030 pushes (0.005 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-beta: 13
• try: 2

Platform and build breakdown:

• android-em-7-0-x86_64-shippable-qr: 7
  • opt: 7
• android-em-7-0-x86_64-shippable-lite-qr: 8
  • opt: 8

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1738300&startday=2021-11-01&endday=2021-11-07&tree=all

Comment 13

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/a0832f8ecfd6
Apply clang upstream patch fixing miscompilation. r=firefox-build-system-reviewers,mhentges

Comment 14

[Mike Hommey [:glandium]]

Comment on attachment 9249356 [details]
Bug 1738300 - Apply clang upstream patch fixing miscompilation.

Beta/Release Uplift Approval Request

• User impact if declined: Miscompilation on Android that can lead to random behavior and/or crashes
• Is this code covered by automated tests?: No
• Has the fix been verified in Nightly?: Yes
• Needs manual test from QE?: No
• If yes, steps to reproduce:
• List of other uplifts needed: None
• Risk to taking this patch: Low
• Why is the change risky/not risky? (and alternatives if risky): This is a toolchain change that only really affects Android builds because it fixes an optimization that happens when optimizing for size, which we only do for Android. The fix itself is rather straightforward and is not expected to have ill side effects.
• String changes made/needed:

Comment 15

[Cristina Cozmuta (:CrissCozmuta)]

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

Comment 16

[Pascal Chevrel:pascalc (PTO until April 26)]

Comment on attachment 9249356 [details]
Bug 1738300 - Apply clang upstream patch fixing miscompilation.

Approved for 95 beta 6, thanks.

Comment 17

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/releases/mozilla-beta/rev/8087a345219b

Comment 18

[Intermittent Failures Robot]

14 failures in 2723 pushes (0.005 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-beta: 14

Platform and build breakdown:

• android-em-7-0-x86_64-shippable-qr: 7
  • opt: 7
• android-em-7-0-x86_64-shippable-lite-qr: 7
  • opt: 7

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1738300&startday=2021-11-08&endday=2021-11-14&tree=all