Closed Bug 1436208 Opened 6 years ago Closed 6 years ago

Intermittent subprocess.CalledProcessError: Command '[u'/builds/worker/workspace/build/src/obj-firefox/_virtualenv/bin/python', u'/builds/worker/workspace/build/src/toolkit/crashreporter/tools/symbolstore.py', '-c', '-a', u'x86_64', '--vcs-info',

Categories

(Firefox Build System :: General, defect, P5)

defect

Tracking

(firefox60 fixed)

RESOLVED FIXED
mozilla60
Tracking Status
firefox60 --- fixed

People

(Reporter: intermittent-bug-filer, Assigned: glandium)

Details

(Keywords: intermittent-failure)

Attachments

(1 file)

Filed by: archaeopteryx [at] coole-files.de

https://treeherder.mozilla.org/logviewer.html#?job_id=160687209&repo=mozilla-central

https://queue.taskcluster.net/v1/task/ODoRBkEDRVKjy74Ymhxw0g/runs/0/artifacts/public/logs/live_backing.log

[task 2018-02-06T22:39:01.245Z] 22:39:01     INFO -  while processing /builds/worker/workspace/build/src/obj-firefox/toolkit/library/x86_64-apple-darwin/release/libgkrust.a(gkrust-6535834335eb48b9.gkrust0.rcgu.o):
[task 2018-02-06T22:39:01.245Z] 22:39:01     INFO -  warning: could not find referenced DIE
[task 2018-02-06T22:39:01.245Z] 22:39:01     INFO -  while processing /builds/worker/workspace/build/src/obj-firefox/toolkit/library/x86_64-apple-darwin/release/libgkrust.a(gkrust-6535834335eb48b9.gkrust0.rcgu.o):
[task 2018-02-06T22:39:01.245Z] 22:39:01     INFO -  warning: could not find referenced DIE
[task 2018-02-06T22:39:01.245Z] 22:39:01     INFO -  #0 0x000000000080151a llvm::sys::PrintStackTrace(llvm::raw_ostream&) (/builds/worker/workspace/build/src/llvm-dsymutil/bin/llvm-dsymutil+0x80151a)
[task 2018-02-06T22:39:01.246Z] 22:39:01     INFO -  #1 0x00000000007ff9de llvm::sys::RunSignalHandlers() (/builds/worker/workspace/build/src/llvm-dsymutil/bin/llvm-dsymutil+0x7ff9de)
[task 2018-02-06T22:39:01.247Z] 22:39:01     INFO -  #2 0x00000000007ffb1a SignalHandler(int) (/builds/worker/workspace/build/src/llvm-dsymutil/bin/llvm-dsymutil+0x7ffb1a)
[task 2018-02-06T22:39:01.247Z] 22:39:01     INFO -  #3 0x00007f2ff92a80a0 __restore_rt (/lib/x86_64-linux-gnu/libpthread.so.0+0xf0a0)
[task 2018-02-06T22:39:01.247Z] 22:39:01     INFO -  #4 0x00000000006e6449 llvm::DWARFDataExtractor::getRelocatedValue(unsigned int, unsigned int*, unsigned long*) const (/builds/worker/workspace/build/src/llvm-dsymutil/bin/llvm-dsymutil+0x6e6449)
[task 2018-02-06T22:39:01.247Z] 22:39:01     INFO -  #5 0x00000000006fb499 llvm::DWARFFormValue::extractValue(llvm::DWARFDataExtractor const&, unsigned int*, llvm::DWARFFormParams, llvm::DWARFUnit const*) (/builds/worker/workspace/build/src/llvm-dsymutil/bin/llvm-dsymutil+0x6fb499)
[task 2018-02-06T22:39:01.248Z] 22:39:01     INFO -  #6 0x00000000006d5b4a llvm::DWARFAbbreviationDeclaration::getAttributeValue(unsigned int, llvm::dwarf::Attribute, llvm::DWARFUnit const&) const (/builds/worker/workspace/build/src/llvm-dsymutil/bin/llvm-dsymutil+0x6d5b4a)
[task 2018-02-06T22:39:01.248Z] 22:39:01     INFO -  #7 0x00000000006f6bb3 llvm::DWARFDie::find(llvm::dwarf::Attribute) const (/builds/worker/workspace/build/src/llvm-dsymutil/bin/llvm-dsymutil+0x6f6bb3)
[task 2018-02-06T22:39:01.248Z] 22:39:01     INFO -  #8 0x00000000006f6cbe llvm::DWARFDie::getAttributeValueAsReferencedDie(llvm::dwarf::Attribute) const (/builds/worker/workspace/build/src/llvm-dsymutil/bin/llvm-dsymutil+0x6f6cbe)
[task 2018-02-06T22:39:01.248Z] 22:39:01     INFO -  #9 0x00000000006f6dfe llvm::DWARFDie::findRecursively(llvm::ArrayRef<llvm::dwarf::Attribute>) const (/builds/worker/workspace/build/src/llvm-dsymutil/bin/llvm-dsymutil+0x6f6dfe)
[task 2018-02-06T22:39:01.248Z] 22:39:01     INFO -  #10 0x00000000006f6e22 llvm::DWARFDie::findRecursively(llvm::ArrayRef<llvm::dwarf::Attribute>) const (/builds/worker/workspace/build/src/llvm-dsymutil/bin/llvm-dsymutil+0x6f6e22)
[task 2018-02-06T22:39:01.248Z] 22:39:01     INFO -  Stack dump:
[task 2018-02-06T22:39:01.249Z] 22:39:01     INFO -  0.	Program arguments: /builds/worker/workspace/build/src/llvm-dsymutil/bin/llvm-dsymutil --arch=x86_64 /builds/worker/workspace/build/src/obj-firefox/toolkit/library/XUL
[task 2018-02-06T22:39:01.249Z] 22:39:01     INFO -  Segmentation fault (core dumped)
[task 2018-02-06T22:39:01.249Z] 22:39:01     INFO -  /builds/worker/workspace/build/src/llvm-dsymutil/bin/llvm-dsymutil crashed. Trying to get a reduced testcase.
[task 2018-02-06T22:39:01.249Z] 22:39:01     INFO -  Segmentation fault (core dumped)
[task 2018-02-06T22:39:01.249Z] 22:39:01     INFO -  Could reproduce with a reduced testcase. Creating an artifact.
[task 2018-02-06T22:39:01.249Z] 22:39:01     INFO -  Check the dsymutil-crasher.tar.xz artifact.
[task 2018-02-06T22:39:01.250Z] 22:39:01     INFO -  Error running dsymutil: Command '[u'/builds/worker/workspace/build/src/build/macosx/llvm-dsymutil', '--arch=x86_64', '/builds/worker/workspace/build/src/obj-firefox/toolkit/library/XUL']' returned non-zero exit status 139
[task 2018-02-06T22:39:01.250Z] 22:39:01     INFO -  Traceback (most recent call last):
[task 2018-02-06T22:39:01.250Z] 22:39:01     INFO -    File "/builds/worker/workspace/build/src/toolkit/crashreporter/tools/symbolstore.py", line 885, in <module>
[task 2018-02-06T22:39:01.250Z] 22:39:01     INFO -      main()
[task 2018-02-06T22:39:01.250Z] 22:39:01     INFO -    File "/builds/worker/workspace/build/src/toolkit/crashreporter/tools/symbolstore.py", line 881, in main
[task 2018-02-06T22:39:01.250Z] 22:39:01     INFO -      dumper.Process(args[2])
[task 2018-02-06T22:39:01.251Z] 22:39:01     INFO -    File "/builds/worker/workspace/build/src/toolkit/crashreporter/tools/symbolstore.py", line 498, in Process
[task 2018-02-06T22:39:01.251Z] 22:39:01     INFO -      self.ProcessFile(file_to_process)
[task 2018-02-06T22:39:01.251Z] 22:39:01     INFO -    File "/builds/worker/workspace/build/src/toolkit/crashreporter/tools/symbolstore.py", line 755, in ProcessFile
[task 2018-02-06T22:39:01.251Z] 22:39:01     INFO -      dsymbundle = self.GenerateDSYM(file)
[task 2018-02-06T22:39:01.251Z] 22:39:01     INFO -    File "/builds/worker/workspace/build/src/toolkit/crashreporter/tools/symbolstore.py", line 789, in GenerateDSYM
[task 2018-02-06T22:39:01.251Z] 22:39:01     INFO -      subprocess.check_call(cmd, stdout=open(os.devnull, 'w'))
[task 2018-02-06T22:39:01.251Z] 22:39:01     INFO -    File "/usr/lib/python2.7/subprocess.py", line 540, in check_call
[task 2018-02-06T22:39:01.251Z] 22:39:01     INFO -      raise CalledProcessError(retcode, cmd)
[task 2018-02-06T22:39:01.252Z] 22:39:01     INFO -  subprocess.CalledProcessError: Command '[u'/builds/worker/workspace/build/src/build/macosx/llvm-dsymutil', '--arch=x86_64', '/builds/worker/workspace/build/src/obj-firefox/toolkit/library/XUL']' returned non-zero exit status 139
[task 2018-02-06T22:39:01.252Z] 22:39:01     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
[task 2018-02-06T22:39:01.252Z] 22:39:01     INFO -  Traceback (most recent call last):
[task 2018-02-06T22:39:01.252Z] 22:39:01     INFO -    File "/usr/lib/python2.7/runpy.py", line 162, in _run_module_as_main
[task 2018-02-06T22:39:01.252Z] 22:39:01     INFO -      "__main__", fname, loader, pkg_name)
[task 2018-02-06T22:39:01.252Z] 22:39:01     INFO -    File "/usr/lib/python2.7/runpy.py", line 72, in _run_code
[task 2018-02-06T22:39:01.252Z] 22:39:01     INFO -      exec code in run_globals
[task 2018-02-06T22:39:01.252Z] 22:39:01     INFO -    File "/builds/worker/workspace/build/src/python/mozbuild/mozbuild/action/dumpsymbols.py", line 79, in <module>
[task 2018-02-06T22:39:01.252Z] 22:39:01     INFO -      sys.exit(main(sys.argv[1:]))
[task 2018-02-06T22:39:01.253Z] 22:39:01     INFO -    File "/builds/worker/workspace/build/src/python/mozbuild/mozbuild/action/dumpsymbols.py", line 75, in main
[task 2018-02-06T22:39:01.253Z] 22:39:01     INFO -      return dump_symbols(*argv)
[task 2018-02-06T22:39:01.253Z] 22:39:01     INFO -    File "/builds/worker/workspace/build/src/python/mozbuild/mozbuild/action/dumpsymbols.py", line 64, in dump_symbols
[task 2018-02-06T22:39:01.253Z] 22:39:01     INFO -      out_files = subprocess.check_output(args)
[task 2018-02-06T22:39:01.253Z] 22:39:01     INFO -    File "/usr/lib/python2.7/subprocess.py", line 573, in check_output
[task 2018-02-06T22:39:01.253Z] 22:39:01     INFO -      raise CalledProcessError(retcode, cmd, output=output)
[task 2018-02-06T22:39:01.253Z] 22:39:01     INFO -  subprocess.CalledProcessError: Command '[u'/builds/worker/workspace/build/src/obj-firefox/_virtualenv/bin/python', u'/builds/worker/workspace/build/src/toolkit/crashreporter/tools/symbolstore.py', '-c', '-a', u'x86_64', '--vcs-info', u'--install-manifest=/builds/worker/workspace/build/src/obj-firefox/_build_manifests/install/dist_include,/builds/worker/workspace/build/src/obj-firefox/dist/include', '-s', u'/builds/worker/workspace/build/src', u'/builds/worker/workspace/build/src/obj-firefox/dist/host/bin/dump_syms', u'/builds/worker/workspace/build/src/obj-firefox/dist/crashreporter-symbols', '/builds/worker/workspace/build/src/obj-firefox/toolkit/library/XUL']' returned non-zero exit status 1
[task 2018-02-06T22:39:01.253Z] 22:39:01     INFO -  /builds/worker/workspace/build/src/config/rules.mk:820: recipe for target 'XUL_syms.track' failed
[task 2018-02-06T22:39:01.253Z] 22:39:01     INFO -  make[4]: *** [XUL_syms.track] Error 1
[task 2018-02-06T22:39:01.254Z] 22:39:01     INFO -  make[4]: Leaving directory '/builds/worker/workspace/build/src/obj-firefox/toolkit/library'
[task 2018-02-06T22:39:01.254Z] 22:39:01     INFO -  /builds/worker/workspace/build/src/config/recurse.mk:73: recipe for target 'toolkit/library/syms' failed
[task 2018-02-06T22:39:01.254Z] 22:39:01     INFO -  make[3]: *** [toolkit/library/syms] Error 2
Filed https://bugs.llvm.org/show_bug.cgi?id=36257

Looking if it's straightforward to fix, but current llvm trunk is still broken.
Assignee: nobody → mh+mozilla
I've identified how the rust compiler is breaking us here by creating self-referencing DIEs:
https://bugs.llvm.org/show_bug.cgi?id=36257#c5

I'm testing a workaround, but these recurring rustc dwarf bustage are frustrating (and also mean that the debug info we get for crash analysis might as well be completely busted)
Tom or Michael, can one of you answer to https://bugs.llvm.org/show_bug.cgi?id=36257#c6 ?
Flags: needinfo?(ttromey)
Flags: needinfo?(mwoerister)
Comment on attachment 8948880 [details]
Bug 1436208 - Avoid infinite loops in llvm-dsymutil when rust produces broken self-referencing DIEs.

https://reviewboard.mozilla.org/r/218276/#review224266

Stamp!

::: taskcluster/scripts/misc/build-llvm-dsymutil.sh:19
(Diff revision 1)
>  git clone -n https://github.com/llvm-mirror/llvm
>  
>  cd llvm
>  git checkout 4727bc748a48e46824eae55a81ae890cd25c3a34
>  
> +patch -p1 <<'EOF'

Nit -- looks like there might be some extra whitespace in this patch.
Attachment #8948880 - Flags: review+
Attachment #8948880 - Flags: review?(core-build-config-reviews)
(In reply to Nick Alexander :nalexander from comment #5)
> Nit -- looks like there might be some extra whitespace in this patch.

That's how diffs are: the first column is either a space, a + or a -.
Pushed by mh@glandium.org:
https://hg.mozilla.org/integration/autoland/rev/936e0d73d429
Avoid infinite loops in llvm-dsymutil when rust produces broken self-referencing DIEs. r=nalexander
https://hg.mozilla.org/mozilla-central/rev/936e0d73d429
Status: NEW → RESOLVED
Closed: 6 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla60
(In reply to Mike Hommey [:glandium] from comment #3)
> Tom or Michael, can one of you answer to
> https://bugs.llvm.org/show_bug.cgi?id=36257#c6 ?

I posted this to the llvm bug: https://bugs.llvm.org/show_bug.cgi?id=36257#c10
I hope it helps at least a little.
Flags: needinfo?(mwoerister)
(In reply to Michael Woerister from comment #10)
> (In reply to Mike Hommey [:glandium] from comment #3)
> > Tom or Michael, can one of you answer to
> > https://bugs.llvm.org/show_bug.cgi?id=36257#c6 ?
> 
> I posted this to the llvm bug:
> https://bugs.llvm.org/show_bug.cgi?id=36257#c10
> I hope it helps at least a little.

The llvm-dis output is massive. Like hundreds of megabytes massive. I found things related to the broken dwarf in it, but it seems consistent. And on the DWARF side, it seems we're in deep inlining territory, and it also seems the self-referencing DIE is only the tip of the iceberg, because I can't make sense of many of the DW_AT_abstract_origin in the same region of the DWARF. But I don't know much about DWARF and llvm-dis output.

So, in case you want to look at it for yourself, here is the llvm-dis output I generated:
https://queue.taskcluster.net/v1/task/HlVAwKWVQoGz27TAvs2-Bg/runs/0/artifacts/public/build/gkrust-6535834335eb48b9.gkrust0.rcgu.ll.xz
And in case it doesn't match exactly the dwarf linked in the llvm bug, the corresponding one:
https://queue.taskcluster.net/v1/task/HlVAwKWVQoGz27TAvs2-Bg/runs/0/artifacts/public/build/dsymutil-crasher.tar.xz
Flags: needinfo?(mwoerister)
> The llvm-dis output is massive. Like hundreds of megabytes massive.

I'm not surprised, unfortunately :)

> But I don't know much about DWARF and llvm-dis output.

I don't know much about that part of DWARF either. It's probably best if you post that link to the LLVM bug. Maybe they can make something of it.
Flags: needinfo?(mwoerister)
Product: Core → Firefox Build System

Clearing my NI. In the upstream bug, :glandium says that this is fixed in clang 7, so maybe this one can be closed as well?

Flags: needinfo?(ttromey)

In fact this one is closed.

You need to log in before you can comment on or make changes to this bug.