1410148 - Intermittent subprocess.CalledProcessError: Command '[u'/builds/worker/workspace/build/src/clang/bin/llvm-dsymutil', '--arch=x86_64', '/builds/worker/workspace/build/src/obj-firefox/toolkit/library/XUL']' returned non-zero exit status -11

Status: RESOLVED FIXED

(Firefox Build System :: General, defect)

Description

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

This seems to be a pretty frequent (~20% of runs) failure which started a few hours ago for OS X Cross Compiled opt.

Ted, can you take a look at the issue, please?

First failure on integration branches: https://treeherder.mozilla.org/#/jobs?repo=autoland&revision=8e0c08885611569371c51a2e6ad128fce3879b32&filter-resultStatus=testfailed&filter-resultStatus=busted&filter-resultStatus=exception&filter-resultStatus=retry&filter-resultStatus=usercancel&filter-resultStatus=runnable
Failure log: https://treeherder.mozilla.org/logviewer.html#?job_id=138201168&repo=autoland

[task 2017-10-19T14:29:02.423Z] 14:29:02     INFO -  gmake[5]: Entering directory '/builds/worker/workspace/build/src/obj-firefox/toolkit/library'
[task 2017-10-19T14:29:02.424Z] 14:29:02     INFO -  /builds/worker/workspace/build/src/obj-firefox/_virtualenv/bin/python -m mozbuild.action.dumpsymbols /builds/worker/workspace/build/src/obj-firefox/toolkit/library/XUL /builds/worker/workspace/build/src/obj-firefox/toolkit/library/XUL_syms.track
[task 2017-10-19T14:29:02.424Z] 14:29:02     INFO -  Starting Mac pre-processing on file: /builds/worker/workspace/build/src/obj-firefox/toolkit/library/XUL
[task 2017-10-19T14:29:02.424Z] 14:29:02     INFO -  Running Mac pre-processing on file: /builds/worker/workspace/build/src/obj-firefox/toolkit/library/XUL
[task 2017-10-19T14:29:02.425Z] 14:29:02     INFO -  /builds/worker/workspace/build/src/clang/bin/llvm-dsymutil --arch=x86_64 /builds/worker/workspace/build/src/obj-firefox/toolkit/library/XUL
[task 2017-10-19T14:29:02.425Z] 14:29:02     INFO -  while processing /builds/worker/workspace/build/src/obj-firefox/toolkit/library/x86_64-apple-darwin/release/libgkrust.a(gkrust-dfe50c863337d8a0.0.o):
[task 2017-10-19T14:29:02.425Z] 14:29:02     INFO -  warning: could not find referenced DIE
^^ tons of these

[task 2017-10-19T14:29:03.343Z] 14:29:03     INFO -  while processing /builds/worker/workspace/build/src/obj-firefox/toolkit/library/x86_64-apple-darwin/release/libgkrust.a(gkrust-dfe50c863337d8a0.0.o):
[task 2017-10-19T14:29:03.343Z] 14:29:03     INFO -  warning: could not find referenced DIE
[task 2017-10-19T14:29:03.343Z] 14:29:03     INFO -  #0 0x00000000007a8715 llvm::sys::PrintStackTrace(llvm::raw_ostream&) (/builds/worker/workspace/build/src/clang/bin/llvm-dsymutil+0x7a8715)
[task 2017-10-19T14:29:03.343Z] 14:29:03     INFO -  #1 0x00000000007a8d66 SignalHandler(int) (/builds/worker/workspace/build/src/clang/bin/llvm-dsymutil+0x7a8d66)
[task 2017-10-19T14:29:03.343Z] 14:29:03     INFO -  #2 0x00007fdd53a9e7e0 __restore_rt (/lib64/libpthread.so.0+0xf7e0)
[task 2017-10-19T14:29:03.344Z] 14:29:03     INFO -  #3 0x00000000006d68a7 llvm::DWARFDebugInfoEntryMinimal::getAttributeValue(llvm::DWARFUnit const*, unsigned short, llvm::DWARFFormValue&) const (/builds/worker/workspace/build/src/clang/bin/llvm-dsymutil+0x6d68a7)
[task 2017-10-19T14:29:03.344Z] 14:29:03     INFO -  #4 0x00000000006d635e llvm::DWARFDebugInfoEntryMinimal::getName(llvm::DWARFUnit const*, llvm::DINameKind) const (/builds/worker/workspace/build/src/clang/bin/llvm-dsymutil+0x6d635e)
^^ tons of these

[task 2017-10-19T14:29:03.396Z] 14:29:03     INFO -  Stack dump:
[task 2017-10-19T14:29:03.396Z] 14:29:03     INFO -  0.	Program arguments: /builds/worker/workspace/build/src/clang/bin/llvm-dsymutil --arch=x86_64 /builds/worker/workspace/build/src/obj-firefox/toolkit/library/XUL
[task 2017-10-19T14:29:03.397Z] 14:29:03     INFO -  Error running dsymutil: Command '[u'/builds/worker/workspace/build/src/clang/bin/llvm-dsymutil', '--arch=x86_64', '/builds/worker/workspace/build/src/obj-firefox/toolkit/library/XUL']' returned non-zero exit status -11
[task 2017-10-19T14:29:03.397Z] 14:29:03     INFO -  Traceback (most recent call last):
[task 2017-10-19T14:29:03.397Z] 14:29:03     INFO -    File "/builds/worker/workspace/build/src/toolkit/crashreporter/tools/symbolstore.py", line 888, in <module>
[task 2017-10-19T14:29:03.397Z] 14:29:03     INFO -      main()
[task 2017-10-19T14:29:03.397Z] 14:29:03     INFO -    File "/builds/worker/workspace/build/src/toolkit/crashreporter/tools/symbolstore.py", line 884, in main
[task 2017-10-19T14:29:03.397Z] 14:29:03     INFO -      dumper.Process(args[2])
[task 2017-10-19T14:29:03.398Z] 14:29:03     INFO -    File "/builds/worker/workspace/build/src/toolkit/crashreporter/tools/symbolstore.py", line 501, in Process
[task 2017-10-19T14:29:03.398Z] 14:29:03     INFO -      self.ProcessFile(file_to_process)
[task 2017-10-19T14:29:03.398Z] 14:29:03     INFO -    File "/builds/worker/workspace/build/src/toolkit/crashreporter/tools/symbolstore.py", line 758, in ProcessFile
[task 2017-10-19T14:29:03.398Z] 14:29:03     INFO -      dsymbundle = self.GenerateDSYM(file)
[task 2017-10-19T14:29:03.398Z] 14:29:03     INFO -    File "/builds/worker/workspace/build/src/toolkit/crashreporter/tools/symbolstore.py", line 792, in GenerateDSYM
[task 2017-10-19T14:29:03.399Z] 14:29:03     INFO -      subprocess.check_call(cmd, stdout=open(os.devnull, 'w'))
[task 2017-10-19T14:29:03.399Z] 14:29:03     INFO -    File "/usr/lib/python2.7/subprocess.py", line 540, in check_call
[task 2017-10-19T14:29:03.399Z] 14:29:03     INFO -      raise CalledProcessError(retcode, cmd)
[task 2017-10-19T14:29:03.399Z] 14:29:03     INFO -  subprocess.CalledProcessError: Command '[u'/builds/worker/workspace/build/src/clang/bin/llvm-dsymutil', '--arch=x86_64', '/builds/worker/workspace/build/src/obj-firefox/toolkit/library/XUL']' returned non-zero exit status -11
[task 2017-10-19T14:29:03.400Z] 14:29:03     INFO -  Running: /builds/worker/workspace/build/src/obj-firefox/_virtualenv/bin/python /builds/worker/workspace/build/src/toolkit/crashreporter/tools/symbolstore.py -c -a x86_64 --vcs-info --install-manifest=/builds/worker/workspace/build/src/obj-firefox/_build_manifests/install/dist_include,/builds/worker/workspace/build/src/obj-firefox/dist/include -s /builds/worker/workspace/build/src /builds/worker/workspace/build/src/obj-firefox/dist/host/bin/dump_syms /builds/worker/workspace/build/src/obj-firefox/dist/crashreporter-symbols /builds/worker/workspace/build/src/obj-firefox/toolkit/library/XUL

Comment 1

[(not currently active) Ted Mielczarek]

This sounds like a reoccurrence of bug 1397382, which we thought we fixed in bug 1381043. The changeset linked in comment 0 is a servo merge, so it's entirely possible that some new Rust code has caused another kind of failure.

We can try backing out https://hg.mozilla.org/mozilla-central/rev/95555b11aaaf, which should wallpaper over this again until we get a new fix.

Comment 2

[Mike Hommey [:glandium]]

Note it's a different stack trace than bug 1397382.

Comment 3

[(not currently active) Ted Mielczarek]

Yeah, I should have clarified, it's probably a different dsymutil crash that's just also caused by Rust debug info.

Comment 4

[Mike Hommey [:glandium]]

broken rust debug info.

Comment 5

[Intermittent Failures Robot]

5 failures in 864 pushes (0.006 failures/push) were associated with this bug in the last 7 days.    

Repository breakdown:
* autoland: 4
* mozilla-inbound: 1

Platform breakdown:
* osx-cross: 5

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1410148&startday=2017-10-16&endday=2017-10-22&tree=all

Comment 6

[Intermittent Failures Robot]

3 failures in 857 pushes (0.004 failures/push) were associated with this bug in the last 7 days.    

Repository breakdown:
* mozilla-inbound: 3

Platform breakdown:
* osx-cross: 3

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1410148&startday=2017-10-30&endday=2017-11-05&tree=all

Comment 7

[Intermittent Failures Robot]

8 failures in 849 pushes (0.009 failures/push) were associated with this bug in the last 7 days.    

Repository breakdown:
* autoland: 5
* mozilla-inbound: 3

Platform breakdown:
* osx-cross: 8

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1410148&startday=2017-11-06&endday=2017-11-12&tree=all

Comment 8

[(not currently active) Ted Mielczarek]

Attachment: bug 1410148 - try to work around llvm-dsymutil crashes again by lowering rust debuginfo level on cross-mac builds.

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

Comment 9

[Nick Alexander :nalexander [he/him]]

Comment on attachment 8928232 [details]
bug 1410148 - try to work around llvm-dsymutil crashes again by lowering rust debuginfo level on cross-mac builds.

https://reviewboard.mozilla.org/r/199454/#review204560

lgtm.

::: build/moz.configure/toolchain.configure:1366
(Diff revision 1)
>      if opt_level == '0' and not debug_rust:
>          debug_assertions = False
>  
>      if debug_symbols:
> +        if host.kernel == 'Linux' and target.kernel == 'Darwin':
> +            # hack to work around dsymutil failing on cross-OSX builds (bug 1410148)

nit: generally we prefer full sentences.

Comment 10

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/mozilla-inbound/rev/e963baf002da
try to work around llvm-dsymutil crashes again by lowering rust debuginfo level on cross-mac builds. r=nalexander

Comment 11

[(not currently active) Ted Mielczarek]

I'm going to tag this leave-open, even if this patch makes it go away we should figure out why llvm-dsymutil is crashing (again). I suspect we'd have to replicate glandium's work in bug 1381043. Given how many times we've seen this, maybe we should write down some steps for getting a smaller reproducible testcase out of a try build?

Comment 12

[Noemi Erli[:noemi_erli]]

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

Comment 13

[Intermittent Failures Robot]

3 failures in 762 pushes (0.004 failures/push) were associated with this bug in the last 7 days.    

Repository breakdown:
* mozilla-central: 2
* try: 1

Platform breakdown:
* osx-cross: 3

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1410148&startday=2017-11-13&endday=2017-11-19&tree=all

Comment 14

[Intermittent Failures Robot]

3 failures in 744 pushes (0.004 failures/push) were associated with this bug in the last 7 days.    

Repository breakdown:
* autoland: 3

Platform breakdown:
* osx-cross: 3

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1410148&startday=2017-11-20&endday=2017-11-26&tree=all

Comment 15

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

This started again yesterday and is permafailing for the nightly (3 runs failed, furthermore 3 normal builds on that push and 2 dark matter detector ones so far).

I am sorry to bother you on the first day of PTO. Please take a look at this.

Comment 16

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

This is permafailing on central (not on autoland or inbound), so no OS X nightlies.

Comment 17

[Intermittent Failures Robot]

22 failures in 50 pushes (0.44 failures/push) were associated with this bug yesterday.    

Repository breakdown:
* mozilla-central: 19
* autoland: 2
* mozilla-inbound: 1

Platform breakdown:
* osx-cross: 18
* osx-10-10-dmd: 3
* android-4-3-armv7-api16: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1410148&startday=2017-12-22&endday=2017-12-22&tree=all

Comment 18

[Chris Cooper [:coop] (he/him)]

Attachment: Disable debuginfo for Rust entirely (temporary)

I can't push to Try right now, but this patch should unblock us.

Comment 19

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/mozilla-central/rev/1a76c0899bc6
Attempt to fix OS X cross-compile builds on central by changing rust debug log level to 0. r=Aryx a=bustage-fix-attempt

Comment 20

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

Comment on attachment 8938762 [details] [diff] [review]
Disable debuginfo for Rust entirely (temporary)

https://hg.mozilla.org/mozilla-central/rev/1a76c0899bc68acd6b77dd1796870eac3fb0f112

Comment 21

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

This fixed the OS X build bustage on central.

Comment 22

[Intermittent Failures Robot]

54 failures in 590 pushes (0.092 failures/push) were associated with this bug in the last 7 days. 

This is the #15 most frequent failure this week.  

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. **  

Repository breakdown:
* mozilla-central: 29
* autoland: 16
* mozilla-inbound: 9

Platform breakdown:
* osx-cross: 34
* windows7-32: 8
* osx-10-10-dmd: 4
* linux64-qr: 3
* windows10-64: 2
* android-4-3-armv7-api16: 2
* linux64: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1410148&startday=2017-12-18&endday=2017-12-24&tree=all

Comment 23

[Mike Hommey [:glandium]]

Attachment: Bug 1410148 - Backport llvm r289565 to clang 3.9.

I was able to reproduce the failure to apply llvm-dsymutil on the last
mozilla-central revision before debug info was temporarily disabled for
rust, and validated that the problem was gone in clang 4.

After some bisection, r289565 was identified as having fixed the
problem, which, reading the commit message, makes sense.

It was however not possible to simply cherry-pick, because of multiple
code changes between 3.9 and 4. However, apart from the volume of
conflicting changes, it was more or less straightforward to backport.

Interestingly, the patch for r313872 was relying on changes from
r289565, which is why it required a variant specifically for 3.9, but
now we can use the same patch as for other versions. Well, except
there's a small difference in the context, and build-clang.py doesn't
allow fuzz, so we manually edit the patch to remove that line from the
context.

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

Comment 24

[Mike Hommey [:glandium]]

Attachment: Bug 1410148 - Fully re-enable debug info on mac builds.

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

Comment 25

[Gregory Szorc [:gps]]

Comment on attachment 8938991 [details]
Bug 1410148 - Backport llvm r289565 to clang 3.9.

https://reviewboard.mozilla.org/r/209446/#review215198

This is mostly a rubber stamp, since I'm not intimately familiar with Clang's internals.

Comment 26

[Gregory Szorc [:gps]]

Comment on attachment 8938992 [details]
Bug 1410148 - Fully re-enable debug info on mac builds.

https://reviewboard.mozilla.org/r/209448/#review215200

Comment 27

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/593515920c7e
Backport llvm r289565 to clang 3.9. r=gps
https://hg.mozilla.org/integration/autoland/rev/f77f58a060ad
Fully re-enable debug info on mac builds. r=gps

Comment 28

[Andrei Ciure[:aciure]]

Backed out 2 changesets (bug 1410148) for bustage failures on python\mozbuild\mozbuild\test\configure\lint.py r=backout a=backout on a CLOSED TREE

https://treeherder.mozilla.org/logviewer.html#?job_id=153558063&repo=autoland

https://hg.mozilla.org/integration/autoland/rev/fda16de8ddff41c4c62f3ea5d577761159dcd23d

https://treeherder.mozilla.org/#/jobs?repo=autoland&revision=f77f58a060adccc5369a1617330520d67067eaae

Comment 29

[Mike Hommey [:glandium]]

Comment on attachment 8938991 [details]
Bug 1410148 - Backport llvm r289565 to clang 3.9.

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/209446/diff/1-2/

Comment 30

[Mike Hommey [:glandium]]

Comment on attachment 8938992 [details]
Bug 1410148 - Fully re-enable debug info on mac builds.

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/209448/diff/1-2/

Comment 31

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/8696ea000827
Backport llvm r289565 to clang 3.9. r=gps
https://hg.mozilla.org/integration/autoland/rev/5fa379ef34e9
Fully re-enable debug info on mac builds. r=gps

Comment 32

[Narcis Beleuzu [:NarcisB]]

https://hg.mozilla.org/mozilla-central/rev/8696ea000827
https://hg.mozilla.org/mozilla-central/rev/5fa379ef34e9

Comment 33

[Ionuț Goldan [:igoldan]]

:glandium Looks like this brought a small improvement:

== Change summary for alert #11055 (as of Fri, 29 Dec 2017 21:24:07 GMT) ==

Improvements:

  5%  Strings PerfIsUTF8Example3 osx-10-10 opt      8,336.42 -> 7,914.67

For up to date results, see: https://treeherder.mozilla.org/perf.html#/alerts?id=11055

Comment 34

[Mike Hommey [:glandium]]

(In reply to Ionuț Goldan [:igoldan], Performance Sheriffing from comment #33)
> :glandium Looks like this brought a small improvement:
> 
> == Change summary for alert #11055 (as of Fri, 29 Dec 2017 21:24:07 GMT) ==
> 
> Improvements:
> 
>   5%  Strings PerfIsUTF8Example3 osx-10-10 opt      8,336.42 -> 7,914.67
> 
> For up to date results, see:
> https://treeherder.mozilla.org/perf.html#/alerts?id=11055

O_o sounds like a misattribution.

Comment 35

[(not currently active) Ted Mielczarek]

glandium: thanks again for dealing with another one of these difficult-to-handle llvm-dsymutil crashes. I filed bug 1429056 to try to figure out a better plan for dealing with this sort of situation in the future.