1052454 - Intermittent OS X build failure "Undefined subroutine &FileAttrCache::complain called at build/macosx/universal/unify line 1422" ("make[2]: *** [postflight_all] Error 5")

Status: RESOLVED FIXED

(Firefox Build System :: General, defect)

Description

[Ed Morley [:emorley]]

OS X 10.7 mozilla-inbound build on 2014-08-11 17:37:35 PDT for push 1150a58d8b3a

slave: bld-lion-r5-051

https://tbpl.mozilla.org/php/getParsedLog.php?id=45710086&tree=Mozilla-Inbound

{
mkdir -p /builds/slave/m-in-osx64-0000000000000000000/build/obj-firefox/x86_64/dist/ && \
	cd dist/test-stage && \
	  zip -rq9D '/builds/slave/m-in-osx64-0000000000000000000/build/obj-firefox/x86_64/dist/firefox-34.0a1.en-US.mac64.tests.zip' \
	  * -x \*/.mkdir.done
rm -rf /builds/slave/m-in-osx64-0000000000000000000/build/obj-firefox/i386/dist/universal/test-stage
if test -d /builds/slave/m-in-osx64-0000000000000000000/build/obj-firefox/i386/dist/test-stage -a                 \
                -d /builds/slave/m-in-osx64-0000000000000000000/build/obj-firefox/x86_64/dist/test-stage; then              \
           cp /builds/slave/m-in-osx64-0000000000000000000/build/obj-firefox/i386/dist/test-stage/mochitest/automation.py \
             /builds/slave/m-in-osx64-0000000000000000000/build/obj-firefox/x86_64/dist/test-stage/mochitest/;              \
           cp -RL /builds/slave/m-in-osx64-0000000000000000000/build/obj-firefox/i386/dist/test-stage/mochitest/extensions/specialpowers \
             /builds/slave/m-in-osx64-0000000000000000000/build/obj-firefox/x86_64/dist/test-stage/mochitest/extensions/;              \
           cp /builds/slave/m-in-osx64-0000000000000000000/build/obj-firefox/i386/dist/test-stage/xpcshell/automation.py  \
             /builds/slave/m-in-osx64-0000000000000000000/build/obj-firefox/x86_64/dist/test-stage/xpcshell/;               \
           cp /builds/slave/m-in-osx64-0000000000000000000/build/obj-firefox/i386/dist/test-stage/reftest/automation.py   \
             /builds/slave/m-in-osx64-0000000000000000000/build/obj-firefox/x86_64/dist/test-stage/reftest/;                \
           cp -RL /builds/slave/m-in-osx64-0000000000000000000/build/obj-firefox/i386/dist/test-stage/reftest/specialpowers \
             /builds/slave/m-in-osx64-0000000000000000000/build/obj-firefox/x86_64/dist/test-stage/reftest/;              \
           /builds/slave/m-in-osx64-0000000000000000000/build/build/macosx/universal/unify                 \
             --unify-with-sort "\.manifest$" \
             --unify-with-sort "all-test-dirs\.list$"               \
             /builds/slave/m-in-osx64-0000000000000000000/build/obj-firefox/i386/dist/test-stage                          \
             /builds/slave/m-in-osx64-0000000000000000000/build/obj-firefox/x86_64/dist/test-stage                          \
             /builds/slave/m-in-osx64-0000000000000000000/build/obj-firefox/i386/dist/universal/test-stage; fi
/builds/slave/m-in-osx64-0000000000000000000/build/build/macosx/universal/unify: warning: makeUniversalDirectory: only in x86 /builds/slave/m-in-osx64-0000000000000000000/build/obj-firefox/x86_64/dist/test-stage/cppunittests:
  TestJemalloc
Undefined subroutine &FileAttrCache::complain called at /builds/slave/m-in-osx64-0000000000000000000/build/build/macosx/universal/unify line 1422.
make[2]: *** [postflight_all] Error 5
make[1]: *** [realbuild] Error 2
make: *** [build] Error 2
program finished with exit code 2
elapsedTime=1977.185705
========= Finished compile failed (results: 2, elapsed: 32 mins, 57 secs) (at 2014-08-11 18:11:17.703809) =========
}

Added the "make[2]: *** [postflight_all] Error 5" to the summary to hopefully make this TBPL-starable.

Comment 1

[Ed Morley [:emorley]]

https://tbpl.mozilla.org/php/getParsedLog.php?id=45744572&tree=Fx-Team

OS X 10.7 fx-team build on 2014-08-12 03:39:38 PDT for push 4821747ca37d

slave: bld-lion-r5-051

Comment 2

[Ed Morley [:emorley]]

Similar:

https://tbpl.mozilla.org/php/getParsedLog.php?id=45739388&tree=Mozilla-Aurora

OS X 10.7 mozilla-aurora build on 2014-08-12 02:40:58 PDT for push 81d788a4bf74

slave: bld-lion-r5-051

if test -d /builds/slave/m-aurora-osx64-000000000000000/build/obj-firefox/i386/dist/test-stage -a                 \
                -d /builds/slave/m-aurora-osx64-000000000000000/build/obj-firefox/x86_64/dist/test-stage; then              \
           cp /builds/slave/m-aurora-osx64-000000000000000/build/obj-firefox/i386/dist/test-stage/mochitest/automation.py \
             /builds/slave/m-aurora-osx64-000000000000000/build/obj-firefox/x86_64/dist/test-stage/mochitest/;              \
           cp -RL /builds/slave/m-aurora-osx64-000000000000000/build/obj-firefox/i386/dist/test-stage/mochitest/extensions/specialpowers \
             /builds/slave/m-aurora-osx64-000000000000000/build/obj-firefox/x86_64/dist/test-stage/mochitest/extensions/;              \
           cp /builds/slave/m-aurora-osx64-000000000000000/build/obj-firefox/i386/dist/test-stage/xpcshell/automation.py  \
             /builds/slave/m-aurora-osx64-000000000000000/build/obj-firefox/x86_64/dist/test-stage/xpcshell/;               \
           cp /builds/slave/m-aurora-osx64-000000000000000/build/obj-firefox/i386/dist/test-stage/reftest/automation.py   \
             /builds/slave/m-aurora-osx64-000000000000000/build/obj-firefox/x86_64/dist/test-stage/reftest/;                \
           cp -RL /builds/slave/m-aurora-osx64-000000000000000/build/obj-firefox/i386/dist/test-stage/reftest/specialpowers \
             /builds/slave/m-aurora-osx64-000000000000000/build/obj-firefox/x86_64/dist/test-stage/reftest/;              \
           /builds/slave/m-aurora-osx64-000000000000000/build/build/macosx/universal/unify                 \
             --unify-with-sort "\.manifest$" \
             --unify-with-sort "all-test-dirs\.list$"               \
             /builds/slave/m-aurora-osx64-000000000000000/build/obj-firefox/i386/dist/test-stage                          \
             /builds/slave/m-aurora-osx64-000000000000000/build/obj-firefox/x86_64/dist/test-stage                          \
             /builds/slave/m-aurora-osx64-000000000000000/build/obj-firefox/i386/dist/universal/test-stage; fi
/builds/slave/m-aurora-osx64-000000000000000/build/build/macosx/universal/unify: warning: makeUniversalDirectory: only in x86 /builds/slave/m-aurora-osx64-000000000000000/build/obj-firefox/x86_64/dist/test-stage/cppunittests:
  TestJemalloc
/builds/slave/m-aurora-osx64-000000000000000/build/build/macosx/universal/unify: copyIfIdentical: compare:  while comparing:
  /builds/slave/m-aurora-osx64-000000000000000/build/obj-firefox/i386/dist/test-stage/mochitest/tests/dom/encoding/test/unit/test_shift_jis.js,
  /builds/slave/m-aurora-osx64-000000000000000/build/obj-firefox/x86_64/dist/test-stage/mochitest/tests/dom/encoding/test/unit/test_shift_jis.js
make[2]: *** [postflight_all] Error 1
make[1]: *** [realbuild] Error 2
make: *** [build] Error 2
program finished with exit code 2
elapsedTime=1413.299004
========= Finished compile failed (results: 2, elapsed: 23 mins, 33 secs) (at 2014-08-12 03:05:12.681372) =========

Comment 3

[(not currently active) Ted Mielczarek]

The error message about complain just seems to be a bug in an error-handling code path. I poked around trying to reproduce this locally and the closest I could come is if I didn't have read permission on one of the files. (I could get the error about line 1412, not 1422.) Line 1412 is where it tries to open the file, 1422 is where it tries to read it. I'm not sure why we'd error reading the file if we already opened it, this whole thing smells of disk errors.

I can patch unify to give us useful error messages here, at least.

Comment 4

[(not currently active) Ted Mielczarek]

Attachment: fix error messages from unify script

Hopefully I won't have to touch Perl code for another 10 years after this. I'm okay with a rubber stamp here, I had to look up Perl's scoping rules just to figure this out.

Comment 5

[(not currently active) Ted Mielczarek]

Landing this patch isn't going to fix the issue here, it will just give us better errors when it happens.

Comment 6

[(not currently active) Ted Mielczarek]

Also, I think the real story here is "bld-lion-r5-051 has a bad disk".

Comment 7

[Ed Morley [:emorley]]

(In reply to Ted Mielczarek [:ted.mielczarek] from comment #6)
> Also, I think the real story here is "bld-lion-r5-051 has a bad disk".

Ah dammit I normally remember to check the machine name on subsequent occurrences; I'll disable it.

Comment 8

[Ed Morley [:emorley]]

Done; bug 882686.

Comment 9

[Gregory Szorc [:gps]]

Comment on attachment 8471646 [details] [diff] [review]
fix error messages from unify script

Review of attachment 8471646 [details] [diff] [review]:
-----------------------------------------------------------------

Don't tell anybody I know Perl :)

Comment 10

[(not currently active) Ted Mielczarek]

https://hg.mozilla.org/integration/mozilla-inbound/rev/27e0ef1812cc

Comment 11

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/mozilla-central/rev/27e0ef1812cc

Comment 12

[(not currently active) Ted Mielczarek]

Ryan: those unaffected tags are bogus, in that the bug in unify exists on those branches. (It's probably not important to backport though.)

Comment 13

[Legacy TBPL/Treeherder Robot]

KWierso
https://tbpl.mozilla.org/php/getParsedLog.php?id=46804131&tree=Fx-Team
OS X 10.7 fx-team build on 2014-08-26 15:58:35
revision: f688f262758d
slave: bld-lion-r5-080

make[3]: *** [stage-package] Error 1
make[2]: *** [postflight_all] Error 2
make[1]: *** [realbuild] Error 2
make: *** [build] Error 2

Comment 14

[Nigel Babu [:nigelb]]

Ted, does this failure look related to this bug?

https://tbpl.mozilla.org/php/getParsedLog.php?id=47283753&tree=Mozilla-Inbound

Comment 15

[Phil Ringnalda (:philor)]

No, that's what it says it is, "compare: Input/output error while comparing" as in, the disk on the slave is starting to fail and failed while it was reading those two files.