793641 - Prefix mozharness hg errors with "Automation Error:" so TBPL's parser recognises it

Status: RESOLVED FIXED

(Release Engineering :: Applications: MozharnessCore, defect)

Description

[Ed Morley [:emorley]]

Whilst some of these failure modes are set to RETRY, it would be nice if TBPL's annotated summary showed the reason for the retry, without having to open the log, eg for:

{
========= Started clone build tools failed (results: 5, elapsed: 1 secs) (at 2012-09-24 03:17:20.662054) =========
hg clone http://hg.mozilla.org/build/tools tools
 in dir /Users/cltbld/talos-slave/test/. (timeout 1320 secs)
 watching logfiles {}
 argv: ['hg', 'clone', 'http://hg.mozilla.org/build/tools', 'tools']
 environment:
  Apple_PubSub_Socket_Render=/tmp/launch-0HWyTr/Render
  CVS_RSH=ssh
  DISPLAY=/tmp/launch-OkShAP/org.x:0
  HOME=/Users/cltbld
  LOGNAME=cltbld
  PATH=/usr/bin:/bin:/usr/sbin:/sbin:/usr/local/bin:/usr/X11/bin
  PWD=/Users/cltbld/talos-slave/test
  PYTHONPATH=/Library/Python/2.5/site-packages
  SHELL=/bin/bash
  SSH_AUTH_SOCK=/tmp/launch-BiBKpA/Listeners
  TMPDIR=/var/folders/Hs/HsDn6a9SG8idoIya6p9mtE+++TI/-Tmp-/
  USER=cltbld
  VERSIONER_PYTHON_PREFER_32_BIT=no
  VERSIONER_PYTHON_VERSION=2.6
  __CF_USER_TEXT_ENCODING=0x1F5:0:0
 using PTY: False
abort: HTTP Error 500: Internal Server Error
program finished with exit code 255
elapsedTime=1.266496
========= Finished clone build tools failed (results: 5, elapsed: 1 secs) (at 2012-09-24 03:17:21.955880) =========
}

Also, with mock:
https://tbpl.mozilla.org/php/getParsedLog.php?id=15474942&tree=Firefox
{
========= Started 'mock_mozilla -v ...' failed (results: 2, elapsed: 1 mins, 19 secs) (at 2012-09-24 03:35:21.332596) =========
mock_mozilla -v -r mozilla-centos6-i386 --cwd /builds/slave/m-cen-andrd-ntly --unpriv --shell '/usr/bin/env HG_SHARE_BASE_DIR="/builds/hg-shared" JARSIGNER="/builds/slave/m-cen-andrd-ntly/tools/release/signing/mozpass.py" MOZ_CRASHREPORTER_NO_REPORT="1" IS_NIGHTLY="yes" SYMBOL_SERVER_HOST="symbols1.dmz.phx1.mozilla.com" CCACHE_DIR="/builds/ccache" POST_SYMBOL_UPLOAD_CMD="/usr/local/bin/post-symbol-upload.py" MOZ_SYMBOLS_EXTRA_BUILDID="mozilla-central" SYMBOL_SERVER_SSH_KEY="/home/mock_mozilla/.ssh/ffxbld_dsa" PATH="/tools/jdk6/bin:/opt/local/bin:/tools/python/bin:/tools/buildbot/bin:/usr/kerberos/bin:/usr/local/bin:/bin:/usr/bin:/home/" MOZ_UPDATE_CHANNEL="nightly" CCACHE_BASEDIR="/builds/slave/m-cen-andrd-ntly" TINDERBOX_OUTPUT="1" CCACHE_COMPRESS="1" SYMBOL_SERVER_PATH="/mnt/netapp/breakpad/symbols_mob/" MOZ_OBJDIR="obj-firefox" LC_ALL="C" SYMBOL_SERVER_USER="ffxbld" JAVA_HOME="/tools/jdk6" DISPLAY=":2" CCACHE_UMASK="002" python mozharness/scripts/multil10n.py --config-file multi_locale/mozilla-central_android.json --merge-locales --only-pull-locale-source --only-add-locales --only-package-multi'
 in dir /builds/slave/m-cen-andrd-ntly (timeout 1200 secs)
 watching logfiles {}
 argv: ['mock_mozilla', '-v', '-r', 'mozilla-centos6-i386', '--cwd', '/builds/slave/m-cen-andrd-ntly', '--unpriv', '--shell', '/usr/bin/env HG_SHARE_BASE_DIR="/builds/hg-shared" JARSIGNER="/builds/slave/m-cen-andrd-ntly/tools/release/signing/mozpass.py" MOZ_CRASHREPORTER_NO_REPORT="1" IS_NIGHTLY="yes" SYMBOL_SERVER_HOST="symbols1.dmz.phx1.mozilla.com" CCACHE_DIR="/builds/ccache" POST_SYMBOL_UPLOAD_CMD="/usr/local/bin/post-symbol-upload.py" MOZ_SYMBOLS_EXTRA_BUILDID="mozilla-central" SYMBOL_SERVER_SSH_KEY="/home/mock_mozilla/.ssh/ffxbld_dsa" PATH="/tools/jdk6/bin:/opt/local/bin:/tools/python/bin:/tools/buildbot/bin:/usr/kerberos/bin:/usr/local/bin:/bin:/usr/bin:/home/" MOZ_UPDATE_CHANNEL="nightly" CCACHE_BASEDIR="/builds/slave/m-cen-andrd-ntly" TINDERBOX_OUTPUT="1" CCACHE_COMPRESS="1" SYMBOL_SERVER_PATH="/mnt/netapp/breakpad/symbols_mob/" MOZ_OBJDIR="obj-firefox" LC_ALL="C" SYMBOL_SERVER_USER="ffxbld" JAVA_HOME="/tools/jdk6" DISPLAY=":2" CCACHE_UMASK="002" python mozharness/scripts/multil10n.py --config-file multi_locale/mozilla-central_android.json --merge-locales --only-pull-locale-source --only-add-locales --only-package-multi']
...
...
06:36:29     INFO - Setting /builds/slave/m-cen-andrd-ntly/l10n-central/it to http://hg.mozilla.org/l10n-central/it.
06:36:29     INFO - Cloning http://hg.mozilla.org/l10n-central/it to /builds/slave/m-cen-andrd-ntly/l10n-central/it.
06:36:29     INFO - Running command: ['hg', '--config', 'ui.merge=internal:merge', 'clone', u'http://hg.mozilla.org/l10n-central/it', u'/builds/slave/m-cen-andrd-ntly/l10n-central/it']
06:36:29     INFO - Copy/paste: hg --config ui.merge=internal:merge clone http://hg.mozilla.org/l10n-central/it /builds/slave/m-cen-andrd-ntly/l10n-central/it
06:36:40    ERROR -  abort: HTTP Error 500: Internal Server Error
06:36:40    ERROR - Return code: 255
06:36:40     INFO - Updating /builds/slave/m-cen-andrd-ntly/l10n-central/it.
06:36:40    ERROR - Can't run command ['hg', '--config', 'ui.merge=internal:merge', 'branch'] in non-existent directory /builds/slave/m-cen-andrd-ntly/l10n-central/it!
06:36:40    ERROR - Can't run command ['hg', '--config', 'ui.merge=internal:merge', 'update', '-C'] in non-existent directory /builds/slave/m-cen-andrd-ntly/l10n-central/it!
06:36:40    FATAL - Unable to update /builds/slave/m-cen-andrd-ntly/l10n-central/it!
06:36:40    FATAL - Exiting -1
}

Comment 1

[Ed Morley [:emorley]]

(We can also just add "abort: HTTP Error 500: Internal Server Error" to TBPL's regex list if it's too much of a PITA to prefix, but I'd like to avoid bloating TBPL's parser if possible).

Comment 2

[Armen [:armenzg]]

I think for mock it will be easier to append "Automation Error" since it is running inside of mozharness (it seems so from the log output).

For the tools checkout, perhaps calling hgtool.py as a proxy to "hg clone" could allow us to introduce such.

I know that we would like to reduce how many regex's too match on a log!

Comment 3

[[e-mail] (:bhearsum)]

I don't think this is easily prefixable. That output comes from hg, not from any of our tools. Basically, we'd have to parse the log for the sole purpose of changing it. That seems pretty silly to do when TBPL can just catch it itself IMO.

Comment 4

[Armen [:armenzg]]

I assumed that hgtool.py (not hg clone) would be able to try/catch some errors and prefix the "Automation Error".

tbpl is indeed the easier place to patch.

I believe further discussion of what things should be parsed where is needed.
Improve our return code story would also help! :D

Comment 5

[[e-mail] (:bhearsum)]

The build/tools clone doesn't happen through hgtool.py.

Comment 6

[Aki Sasaki (not active)]

Attachment: [mozharness] add Automation Error: explanation lines below hg errors

Mozharness is already parsing the log, so this is easy enough to add.

Comment 7

[Armen [:armenzg]]

Comment on attachment 664091 [details] [diff] [review]
[mozharness] add Automation Error: explanation lines below hg errors

Thanks aki!

Comment 8

[Aki Sasaki (not active)]

Comment on attachment 664091 [details] [diff] [review]
[mozharness] add Automation Error: explanation lines below hg errors

http://hg.mozilla.org/build/mozharness/rev/ce1f9128639c

Comment 10

[Ed Morley [:emorley]]

Thank you for the patch :-)

I'll morph this to just be about the mozharness case, and file another for TBPL coping with build/tools clone failures.