Closed Bug 1367329 Opened 7 years ago Closed 7 years ago

Intermittent mozmake.EXE[1]: *** [js/src/check] Error 2 after TypeError: not all arguments converted during string formatting

Categories

(Firefox Build System :: General, defect)

Product:
Firefox Build System
Component:
General
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

(firefox55 fixed, firefox56 fixed)

Status:
RESOLVED FIXED
Milestone:
mozilla56
Tracking Flags:
Tracking Status
firefox55 --- fixed
firefox56 --- fixed

People

(Reporter: aryx, Assigned: gps)

References

Details

(Keywords: intermittent-failure, Whiteboard: [stockwell fixed:other])

Attachments

(1 file)

bug 1367329 - fix error handling code in mozversioncontrol.
59 bytes, text/x-review-board-request
gps
: review+
Details 
https://treeherder.mozilla.org/logviewer.html#?job_id=101444549&repo=autoland

05:41:57     INFO - mozmake.EXE[2]: Entering directory 'z:/task_1495602898/build/src/obj-firefox/js/src'
05:41:57     INFO - (cd z:/task_1495602898/build/src/js/src && z:/task_1495602898/build/src/obj-firefox/_virtualenv/Scripts/python.exe z:/task_1495602898/build/src/config/check_spidermonkey_style.py);
05:41:57     INFO - MALLOC_LOG=test_output.log MOZ_REPLACE_MALLOC_LIB=z:/task_1495602898/build/src/obj-firefox/memory/replace/logalloc/replay/../logalloc.dll ./logalloc-replay.exe < z:/task_1495602898/build/src/memory/replace/logalloc/replay/replay.log
05:41:57     INFO - (cd z:/task_1495602898/build/src/js/src && z:/task_1495602898/build/src/obj-firefox/_virtualenv/Scripts/python.exe z:/task_1495602898/build/src/config/check_macroassembler_style.py);
05:41:57     INFO - (cd z:/task_1495602898/build/src && z:/task_1495602898/build/src/obj-firefox/_virtualenv/Scripts/python.exe z:/task_1495602898/build/src/config/check_js_msg_encoding.py);
05:41:57     INFO - (cd z:/task_1495602898/build/src && z:/task_1495602898/build/src/obj-firefox/_virtualenv/Scripts/python.exe z:/task_1495602898/build/src/config/check_js_opcode.py);
05:41:57     INFO - #0 mapped: 1048576; allocated: 0; waste: 0; dirty: 0; bookkeep: 4096; binunused: 0
05:41:57     INFO - #10 mapped: 2097152; allocated: 10336; waste: 0; dirty: 0; bookkeep: 9280; binunused: 66400
05:41:57     INFO - sed -n '/jemalloc_stats/,$p' test_output.log | z:/task_1495602898/build/src/obj-firefox/_virtualenv/Scripts/python.exe z:/task_1495602898/build/src/memory/replace/logalloc/replay/logalloc_munge.py | diff -w - expected_output.log
05:41:57     INFO - processing z:/task_1495602898/build/src/config/tests/src-simple/jar.mn
05:41:57     INFO - mozmake.EXE[4]: Leaving directory 'z:/task_1495602898/build/src/obj-firefox/config/tests/src-simple'
05:41:57     INFO - Comparing manifests...
05:41:57     INFO - Could not find 'hg' on the path.
05:41:57     INFO - mozmake.EXE[2]: Leaving directory 'z:/task_1495602898/build/src/obj-firefox/memory/replace/logalloc/replay'
05:41:57     INFO - Traceback (most recent call last):
05:41:57     INFO -   File "z:/task_1495602898/build/src/config/check_spidermonkey_style.py", line 597, in <module>
05:41:57     INFO -     main()
05:41:57     INFO -   File "z:/task_1495602898/build/src/config/check_spidermonkey_style.py", line 586, in main
05:41:57     INFO -     ok = check_style()
05:41:57     INFO -   File "z:/task_1495602898/build/src/config/check_spidermonkey_style.py", line 252, in check_style
05:41:57     INFO -     repo = get_repository_from_env()
05:41:57     INFO -   File "z:\task_1495602898\build\src\python\mozversioncontrol\mozversioncontrol\__init__.py", line 162, in get_repository_from_env
05:41:57     INFO -     return get_repository_object(path)
05:41:57     INFO -   File "z:\task_1495602898\build\src\python\mozversioncontrol\mozversioncontrol\__init__.py", line 143, in get_repository_object
05:41:57     INFO -     return HgRepository(path)
05:41:57     INFO -   File "z:\task_1495602898\build\src\python\mozversioncontrol\mozversioncontrol\__init__.py", line 87, in __init__
05:41:57     INFO -     super(HgRepository, self).__init__(path, 'hg')
05:41:57     INFO -   File "z:\task_1495602898\build\src\python\mozversioncontrol\mozversioncontrol\__init__.py", line 37, in __init__
05:41:57     INFO -     self._tool = get_tool_path(tool)
05:41:57     INFO -   File "z:\task_1495602898\build\src\python\mozversioncontrol\mozversioncontrol\__init__.py", line 31, in get_tool_path
05:41:57     INFO -     'date.' % tool)
05:41:57     INFO - TypeError: not all arguments converted during string formatting
05:41:57     INFO - Makefile:61: recipe for target 'check-style' failed
05:41:57     INFO - mozmake.EXE[2]: *** [check-style] Error 1
05:41:57     INFO - TEST-PASS | check_js_opcode.py | ok
05:41:57     INFO - Archive:  ../../../dist/xpi-stage/test_jar_mn/chrome/test.jar
05:41:57     INFO -  extracting: ../../../dist/xpi-stage/test_jar_mn/chrome/test/one/file.xml
05:41:57     INFO -  extracting: ../../../dist/xpi-stage/test_jar_mn/chrome/test/one/preproc
05:41:57     INFO -  extracting: ../../../dist/xpi-stage/test_jar_mn/chrome/test/one/some.css
05:41:57     INFO -  extracting: ../../../dist/xpi-stage/test_jar_mn/chrome/test/two/otherfile.xml
05:41:57     INFO -  extracting: ../../../dist/xpi-stage/test_jar_mn/chrome/test/three/l10nfile.txt
05:41:57     INFO - Comparing packages...
05:41:57     INFO - mozmake.EXE[3]: Leaving directory 'z:/task_1495602898/build/src/obj-firefox/config/tests/src-simple'
05:41:57     INFO - z:/task_1495602898/build/src/mozmake.EXE -C tests/src-simple check-flat
05:41:57     INFO - mozmake.EXE[3]: Entering directory 'z:/task_1495602898/build/src/obj-firefox/config/tests/src-simple'
05:41:57     INFO - if test -d ../../../dist/xpi-stage/test_jar_mn; then rm -rf ../../../dist/xpi-stage/test_jar_mn; fi;
05:41:57     INFO - z:/task_1495602898/build/src/mozmake.EXE realchrome MOZ_JAR_MAKER_FILE_FORMAT=flat
05:41:57     INFO - mozmake.EXE[4]: Entering directory 'z:/task_1495602898/build/src/obj-firefox/config/tests/src-simple'
05:41:57     INFO - mkdir -p '../../../dist/xpi-stage/test_jar_mn/chrome/'
05:41:57     INFO - z:/task_1495602898/build/src/obj-firefox/_virtualenv/Scripts/python.exe -m mozbuild.action.jar_maker   -d ../../../dist/xpi-stage/test_jar_mn -t z:/task_1495602898/build/src -f flat  --relativesrcdir=config/tests/src-simple -c z:/task_1495602898/build/src/config/tests/src-simple/l10n  -DA11Y_LOG=1 -DACCESSIBILITY=1 -DBUILD_CTYPES=1 -DCROSS_COMPILE='' -DD_INO=d_ino -DE10S_TESTING_ONLY=1 -DEARLY_BETA_OR_EARLIER=1 -DENABLE_INTL_API=1 -DENABLE_SYSTEM_EXTENSION_DIRS=1 -DENABLE_TESTS=1 -DEXPOSE_INTL_API=1 -DFIREFOX_VERSION=55.0a1 -DFORCE_PR_LOG=1 -DGTEST_HAS_RTTI=0 -DHAVE_CPUID_H=1 -DHAVE_FORCEINLINE=1 -DHAVE_INTTYPES_H=1 -DHAVE_IO_H=1 -DHAVE_ISATTY=1 -DHAVE_LOCALECONV=1 -DHAVE_MALLOC_H=1 -DHAVE_SEH_EXCEPTIONS=1 -DHAVE_STDINT_H=1 -DHAVE_SYS_TYPES_H=1 -DHAVE_UINT64_T=1 -DJS_DEFAULT_JITREPORT_GRANULARITY=3 -DMALLOC_H='<malloc.h>' -DMALLOC_USABLE_SIZE_CONST_PTR=const -DMOZILLA_UAVERSION='"55.0"' -DMOZILLA_VERSION='"55.0a1"' -DMOZILLA_VERSION_U=55.0a1 -DMOZ_ADDON_SIGNING=1 -DMOZ_ALLOW_LEGACY_EXTENSIONS=1 -DMOZ_APP_UA_NAME='""' -DMOZ_APP_UA_VERSION='"55.0a1"' -DMOZ_B2G_OS_NAME='""' -DMOZ_B2G_VERSION='"1.0.0"' -DMOZ_BUILD_APP=browser -DMOZ_BUILD_WEBRENDER=1 -DMOZ_BUNDLED_FONTS=1 -DMOZ_CLANG_PLUGIN=1 -DMOZ_CONTENT_SANDBOX=1 -DMOZ_CRASHREPORTER=1 -DMOZ_CRASHREPORTER_ENABLE_PERCENT=100 -DMOZ_CRASHREPORTER_INJECTOR=1 -DMOZ_DATA_REPORTING=1 -DMOZ_DIRECTSHOW=1 -DMOZ_DISTRIBUTION_ID='"org.mozilla"' -DMOZ_DLL_SUFFIX='".dll"' -DMOZ_ENABLE_MASK_AS_SHORTHAND=1 -DMOZ_ENABLE_SIGNMAR=1 -DMOZ_ENABLE_SKIA=1 -DMOZ_ENABLE_SKIA_PDF=1 -DMOZ_ENABLE_SKIA_PDF_SFNTLY=1 -DMOZ_FEEDS=1 -DMOZ_FFVPX=1 -DMOZ_FMP4=1 -DMOZ_GECKO_PROFILER=1 -DMOZ_GMP_SANDBOX=1 -DMOZ_INSTRUMENT_EVENT_LOOP=1 -DMOZ_LIBAV_FFT=1 -DMOZ_LOGGING=1 -DMOZ_MACBUNDLE_ID=org.mozilla.nightly -DMOZ_MAINTENANCE_SERVICE=1 -DMOZ_MEMORY=1 -DMOZ_MEMORY_WINDOWS=1 -DMOZ_MSVC_STL_WRAP_RAISE=1 -DMOZ_PEERCONNECTION=1 -DMOZ_PERMISSIONS=1 -DMOZ_PHOENIX=1 -DMOZ_PHOTON_ANIMATIONS=1 -DMOZ_PHOTON_THEME=1 -DMOZ_PLACES=1 -DMOZ_PROFILING=1 -DMOZ_RAW=1 -DMOZ_REPLACE_MALLOC=1 -DMOZ_RUST_URLPARSE=1 -DMOZ_SAMPLE_TYPE_FLOAT32=1 -DMOZ_SANDBOX=1 -DMOZ_SCTP=1 -DMOZ_SECUREELEMENT=1 -DMOZ_SERVICES_HEALTHREPORT=1 -DMOZ_SRTP=1 -DMOZ_STATIC_JS=1 -DMOZ_TREE_CAIRO=1 -DMOZ_TREE_PIXMAN=1 -DMOZ_UPDATER=1 -DMOZ_UPDATE_CHANNEL=default -DMOZ_USER_DIR='"Mozilla"' -DMOZ_VORBIS=1 -DMOZ_VPX_NO_MEM_REPORTING=1 -DMOZ_VTUNE=1 -DMOZ_WEBM_ENCODER=1 -DMOZ_WEBRTC=1 -DMOZ_WEBRTC_ASSERT_ALWAYS=1 -DMOZ_WEBRTC_SIGNALING=1 -DMOZ_WEBSPEECH=1 -DMOZ_WEBSPEECH_TEST_BACKEND=1 -DMOZ_WMF=1 -DMOZ_XUL=1 -DMSVC_HAS_DIA_SDK=1 -DNIGHTLY_BUILD=1 -DNOMINMAX=1 -DNO_NSPR_10_SUPPORT=1 -DNS_ENABLE_TSF=1 -DNS_PRINTING=1 -DNS_PRINT_PREVIEW=1 -DSTATIC_JS_API=1 -DSTDC_HEADERS=1 -DTARGET_XPCOM_ABI='"x86-msvc"' -DUSE_SKIA=1 -DUSE_SKIA_GPU=1 -DU_STATIC_IMPLEMENTATION=1 -DU_USING_ICU_NAMESPACE=0 -DVPX_X86_ASM=1 -DWIN32=1 -DWIN32_LEAN_AND_MEAN=1 -DWINVER=0x601 -DXP_WIN=1 -DXP_WIN32=1 -DX_DISPLAY_MISSING=1 -D_CRT_NONSTDC_NO_WARNINGS=1 -D_CRT_SECURE_NO_WARNINGS=1 -D_USE_MATH_DEFINES=1 -D_WIN32_IE=0x0800 -D_WIN32_WINNT=0x601 -D_WINDOWS=1 -D_X86_=1 -DAB_CD=en-US -DAB_CD=ab-X-stuff  z:/task_1495602898/build/src/config/tests/src-simple/jar.mn
05:41:57     INFO - processing z:/task_1495602898/build/src/config/tests/src-simple/jar.mn
05:41:57     INFO - mozmake.EXE[4]: Leaving directory 'z:/task_1495602898/build/src/obj-firefox/config/tests/src-simple'
05:41:57     INFO - Comparing manifests...
05:41:57     INFO - Comparing packages...
05:41:57     INFO - mozmake.EXE[3]: Leaving directory 'z:/task_1495602898/build/src/obj-firefox/config/tests/src-simple'
05:41:57     INFO - z:/task_1495602898/build/src/mozmake.EXE -C tests/src-simple check-flat USE_EXTENSION_MANIFEST=1
05:41:57     INFO - mozmake.EXE[3]: Entering directory 'z:/task_1495602898/build/src/obj-firefox/config/tests/src-simple'
05:41:57     INFO - if test -d ../../../dist/xpi-stage/test_jar_mn; then rm -rf ../../../dist/xpi-stage/test_jar_mn; fi;
05:41:57     INFO - z:/task_1495602898/build/src/mozmake.EXE realchrome MOZ_JAR_MAKER_FILE_FORMAT=flat
05:41:58     INFO - mozmake.EXE[4]: Entering directory 'z:/task_1495602898/build/src/obj-firefox/config/tests/src-simple'
05:41:58     INFO - mkdir -p '../../../dist/xpi-stage/test_jar_mn/chrome/'
05:41:58     INFO - z:/task_1495602898/build/src/obj-firefox/_virtualenv/Scripts/python.exe -m mozbuild.action.jar_maker   -d ../../../dist/xpi-stage/test_jar_mn -t z:/task_1495602898/build/src -f flat  -e --relativesrcdir=config/tests/src-simple -c z:/task_1495602898/build/src/config/tests/src-simple/l10n  -DA11Y_LOG=1 -DACCESSIBILITY=1 -DBUILD_CTYPES=1 -DCROSS_COMPILE='' -DD_INO=d_ino -DE10S_TESTING_ONLY=1 -DEARLY_BETA_OR_EARLIER=1 -DENABLE_INTL_API=1 -DENABLE_SYSTEM_EXTENSION_DIRS=1 -DENABLE_TESTS=1 -DEXPOSE_INTL_API=1 -DFIREFOX_VERSION=55.0a1 -DFORCE_PR_LOG=1 -DGTEST_HAS_RTTI=0 -DHAVE_CPUID_H=1 -DHAVE_FORCEINLINE=1 -DHAVE_INTTYPES_H=1 -DHAVE_IO_H=1 -DHAVE_ISATTY=1 -DHAVE_LOCALECONV=1 -DHAVE_MALLOC_H=1 -DHAVE_SEH_EXCEPTIONS=1 -DHAVE_STDINT_H=1 -DHAVE_SYS_TYPES_H=1 -DHAVE_UINT64_T=1 -DJS_DEFAULT_JITREPORT_GRANULARITY=3 -DMALLOC_H='<malloc.h>' -DMALLOC_USABLE_SIZE_CONST_PTR=const -DMOZILLA_UAVERSION='"55.0"' -DMOZILLA_VERSION='"55.0a1"' -DMOZILLA_VERSION_U=55.0a1 -DMOZ_ADDON_SIGNING=1 -DMOZ_ALLOW_LEGACY_EXTENSIONS=1 -DMOZ_APP_UA_NAME='""' -DMOZ_APP_UA_VERSION='"55.0a1"' -DMOZ_B2G_OS_NAME='""' -DMOZ_B2G_VERSION='"1.0.0"' -DMOZ_BUILD_APP=browser -DMOZ_BUILD_WEBRENDER=1 -DMOZ_BUNDLED_FONTS=1 -DMOZ_CLANG_PLUGIN=1 -DMOZ_CONTENT_SANDBOX=1 -DMOZ_CRASHREPORTER=1 -DMOZ_CRASHREPORTER_ENABLE_PERCENT=100 -DMOZ_CRASHREPORTER_INJECTOR=1 -DMOZ_DATA_REPORTING=1 -DMOZ_DIRECTSHOW=1 -DMOZ_DISTRIBUTION_ID='"org.mozilla"' -DMOZ_DLL_SUFFIX='".dll"' -DMOZ_ENABLE_MASK_AS_SHORTHAND=1 -DMOZ_ENABLE_SIGNMAR=1 -DMOZ_ENABLE_SKIA=1 -DMOZ_ENABLE_SKIA_PDF=1 -DMOZ_ENABLE_SKIA_PDF_SFNTLY=1 -DMOZ_FEEDS=1 -DMOZ_FFVPX=1 -DMOZ_FMP4=1 -DMOZ_GECKO_PROFILER=1 -DMOZ_GMP_SANDBOX=1 -DMOZ_INSTRUMENT_EVENT_LOOP=1 -DMOZ_LIBAV_FFT=1 -DMOZ_LOGGING=1 -DMOZ_MACBUNDLE_ID=org.mozilla.nightly -DMOZ_MAINTENANCE_SERVICE=1 -DMOZ_MEMORY=1 -DMOZ_MEMORY_WINDOWS=1 -DMOZ_MSVC_STL_WRAP_RAISE=1 -DMOZ_PEERCONNECTION=1 -DMOZ_PERMISSIONS=1 -DMOZ_PHOENIX=1 -DMOZ_PHOTON_ANIMATIONS=1 -DMOZ_PHOTON_THEME=1 -DMOZ_PLACES=1 -DMOZ_PROFILING=1 -DMOZ_RAW=1 -DMOZ_REPLACE_MALLOC=1 -DMOZ_RUST_URLPARSE=1 -DMOZ_SAMPLE_TYPE_FLOAT32=1 -DMOZ_SANDBOX=1 -DMOZ_SCTP=1 -DMOZ_SECUREELEMENT=1 -DMOZ_SERVICES_HEALTHREPORT=1 -DMOZ_SRTP=1 -DMOZ_STATIC_JS=1 -DMOZ_TREE_CAIRO=1 -DMOZ_TREE_PIXMAN=1 -DMOZ_UPDATER=1 -DMOZ_UPDATE_CHANNEL=default -DMOZ_USER_DIR='"Mozilla"' -DMOZ_VORBIS=1 -DMOZ_VPX_NO_MEM_REPORTING=1 -DMOZ_VTUNE=1 -DMOZ_WEBM_ENCODER=1 -DMOZ_WEBRTC=1 -DMOZ_WEBRTC_ASSERT_ALWAYS=1 -DMOZ_WEBRTC_SIGNALING=1 -DMOZ_WEBSPEECH=1 -DMOZ_WEBSPEECH_TEST_BACKEND=1 -DMOZ_WMF=1 -DMOZ_XUL=1 -DMSVC_HAS_DIA_SDK=1 -DNIGHTLY_BUILD=1 -DNOMINMAX=1 -DNO_NSPR_10_SUPPORT=1 -DNS_ENABLE_TSF=1 -DNS_PRINTING=1 -DNS_PRINT_PREVIEW=1 -DSTATIC_JS_API=1 -DSTDC_HEADERS=1 -DTARGET_XPCOM_ABI='"x86-msvc"' -DUSE_SKIA=1 -DUSE_SKIA_GPU=1 -DU_STATIC_IMPLEMENTATION=1 -DU_USING_ICU_NAMESPACE=0 -DVPX_X86_ASM=1 -DWIN32=1 -DWIN32_LEAN_AND_MEAN=1 -DWINVER=0x601 -DXP_WIN=1 -DXP_WIN32=1 -DX_DISPLAY_MISSING=1 -D_CRT_NONSTDC_NO_WARNINGS=1 -D_CRT_SECURE_NO_WARNINGS=1 -D_USE_MATH_DEFINES=1 -D_WIN32_IE=0x0800 -D_WIN32_WINNT=0x601 -D_WINDOWS=1 -D_X86_=1 -DAB_CD=en-US -DAB_CD=ab-X-stuff  z:/task_1495602898/build/src/config/tests/src-simple/jar.mn
05:41:58     INFO - processing z:/task_1495602898/build/src/config/tests/src-simple/jar.mn
05:41:58     INFO - mozmake.EXE[4]: Leaving directory 'z:/task_1495602898/build/src/obj-firefox/config/tests/src-simple'
05:41:58     INFO - Comparing manifests...
05:41:58     INFO - Comparing packages...
05:41:58     INFO - mozmake.EXE[3]: Leaving directory 'z:/task_1495602898/build/src/obj-firefox/config/tests/src-simple'
05:41:58     INFO - mozmake.EXE[2]: Leaving directory 'z:/task_1495602898/build/src/obj-firefox/config'
05:41:59     INFO - TEST-PASS | check_js_msg_encoding.py | z:\task_1495602898\build\src\dom/bindings/Errors.msg | ok
05:41:59     INFO - TEST-PASS | check_js_msg_encoding.py | z:\task_1495602898\build\src\js/src/ctypes/ctypes.msg | ok
05:41:59     INFO - TEST-PASS | check_js_msg_encoding.py | z:\task_1495602898\build\src\js/src/js.msg | ok
05:41:59     INFO - TEST-PASS | check_js_msg_encoding.py | z:\task_1495602898\build\src\js/src/jsshell.msg | ok
05:41:59     INFO - TEST-PASS | check_js_msg_encoding.py | z:\task_1495602898\build\src\js/xpconnect/src/jsshell.msg | ok
05:41:59     INFO - TEST-PASS | check_macroassembler_style.py | ok
05:41:59     INFO - mozmake.EXE[2]: Target 'check' not remade because of errors.
05:41:59     INFO - mozmake.EXE[2]: Leaving directory 'z:/task_1495602898/build/src/obj-firefox/js/src'
05:41:59     INFO - z:/task_1495602898/build/src/config/recurse.mk:100: recipe for target 'js/src/check' failed
05:41:59     INFO - mozmake.EXE[1]: *** [js/src/check] Error 2
05:41:59     INFO - mozmake.EXE[1]: Target 'recurse_check' not remade because of errors.
05:41:59     INFO - mozmake.EXE[1]: Leaving directory 'z:/task_1495602898/build/src/obj-firefox'
05:41:59     INFO - z:/task_1495602898/build/src/config/recurse.mk:32: recipe for target 'check' failed
05:41:59     INFO - mozmake.EXE: *** [check] Error 2
05:41:59     INFO - 2
Component: JavaScript Engine → General
Depends on: 1364651
Product: Core → Taskcluster
This is still happening since the landing of bug 1364651.
No longer depends on: 1364651
I see 35 instances in the last week, so our second week of high failures.

:ted, is this something you can help look into in the next week?
Flags: needinfo?(ted)
Whiteboard: [stockwell needswork]
The log shows:
05:41:57     INFO - Could not find 'hg' on the path.

I guess these builds must have hg somewhere, since they're cloning the repository, but maybe it's not in PATH? The TypeError there is just an error in string formatting in the error message it's trying to generate:
https://dxr.mozilla.org/mozilla-central/rev/95543bdc59bd038a3d5d084b85a4fec493c349ee/python/mozversioncontrol/mozversioncontrol/__init__.py#29

That string is split over multiple lines using +, and the string formatting isn't correct.
Flags: needinfo?(ted)
It's odd that it can't find hg.exe, since the mozharness logging shows:
05:18:09     INFO -  'PATH': 'C:\\Program Files\\Mercurial;C:\\mozilla-build\\7zip;C:\\mozilla-build\\info-zip;C:\\mozilla-build\\kdiff3;C:\\mozilla-build\\moztools-x64\\bin;C:\\mozilla-build\\mozmake;C:\\mozilla-build\\msys\\bin;C:\\mozilla-build\\msys\\local\\bin;C:\\mozilla-build\\nsis-3.01;C:\\mozilla-build\\nsis-3.0b3;C:\\mozilla-build\\nsis-2.46u;C:\\mozilla-build\\python;C:\\mozilla-build\\python\\Scripts;C:\\mozilla-build\\upx391w;C:\\mozilla-build\\wget;C:\\mozilla-build\\yasm;C:\\Windows\\system32;C:\\Windows;C:\\Windows\\System32\\Wbem;C:\\Windows\\System32\\WindowsPowerShell\\v1.0\\;C:\\Program Files\\Amazon\\cfn-bootstrap\\;C:\\Program Files (x86)\\GNU\\GnuPG\\pub;C:\\Program Files (x86)\\Windows Kits\\10\\Windows Performance Toolkit\\;c:\\mozilla-build\\python\\lib\\site-packages\\pywin32_system32',

and hg.exe is clearly in c:\Program Files\Mercurial:
[taskcluster 2017-05-24T05:15:03.669Z] Executing command 0: "c:\Program Files\Mercurial\hg.exe" robustcheckout --sharebase y:\hg-shared --purge --upstream https://hg.mozilla.org/mozilla-unified --revision 99b2c5908c1edc8bbbf40f08f008360d89d43669 https://hg.mozilla.org/integration/autoland/ .\build\src
if this is intermittent, could we have an issue during machine provisioning that messes up the path or some of the dependencies for hg?
I'm not sure, it's a very odd failure mode! hg.exe is certainly present while cloning the repository, but somehow it's not found during `make check`? Very reminiscent of bug 1365918, but that was fixed.
Can more debugging be added to https://dxr.mozilla.org/mozilla-central/rev/f8bb96fb5c4f9960c5f754f877eceb677df18ddc/third_party/python/which/which.py#248 to see how the search is performed (e.g. does it consider PATHEXT env variable etc)?

If we can get it to spit out which directories it searched in, which file extensions it considered, what it found in those directories it searched in (even if just for one try push) we should be able to pinpoint why hg wasn't found.

My guess is the "Could not find 'hg' on the path." log could indeed be the root cause (looking through brassstacks it appeared in all the logs I saw). To be safe, we should probably first check it doesn't also appear in passing cases (i.e. corresponds 1:1 with instances of "TypeError: not all arguments converted during string formatting").
(In reply to Pete Moore [:pmoore][:pete] from comment #11)
> Can more debugging be added to
> https://dxr.mozilla.org/mozilla-central/rev/
> f8bb96fb5c4f9960c5f754f877eceb677df18ddc/third_party/python/which/which.
> py#248 to see how the search is performed (e.g. does it consider PATHEXT env
> variable etc)?

We could, but you can also just look a little farther up in that file to see that it does consider PATHEXT etc. :)

FWIW, we use the `which` module extensively in the build system, notably a lot in moz.configure, so I have a hard time believing it's a bug there.
 
> My guess is the "Could not find 'hg' on the path." log could indeed be the
> root cause (looking through brassstacks it appeared in all the logs I saw).
> To be safe, we should probably first check it doesn't also appear in passing
> cases (i.e. corresponds 1:1 with instances of "TypeError: not all arguments
> converted during string formatting").

Yes, if you look at my link in comment 3 you can see that the TypeError is just an exception in the error-handling path in this code when it can't find hg.
That patch isn't going to fix this issue, it just fixes the error handling path there so we'll get the intended exception instead of TypeError.
Keywords: leave-open
(In reply to Ted Mielczarek [:ted.mielczarek] from comment #12)
> (In reply to Pete Moore [:pmoore][:pete] from comment #11)
> > Can more debugging be added to
> > https://dxr.mozilla.org/mozilla-central/rev/
> > f8bb96fb5c4f9960c5f754f877eceb677df18ddc/third_party/python/which/which.
> > py#248 to see how the search is performed (e.g. does it consider PATHEXT env
> > variable etc)?
> 
> We could, but you can also just look a little farther up in that file to see
> that it does consider PATHEXT etc. :)
> 
> FWIW, we use the `which` module extensively in the build system, notably a
> lot in moz.configure, so I have a hard time believing it's a bug there.

This exercise was just a proposal to find out why c:\Program Files\Mercurial\hg.exe can't be found, e.g. to narrow down the options to:

1) c:\Program Files\Mercurial\hg.exe genuinely does not exist (e.g. it has been deleted)
2) the PATH passed to the function is incorrect (i.e. not the same as the PATH in the successful invocations, something modified it)
3) the PATH passed is correct, but something has tampered with PATHEXT since previous successful invocations
4) c:\Program Files\Mercurial\hg.exe exists, but for some reason is now not executable / owned by the wrong user / was replaced with a symlink etc
5) the entire C: drive is suddenly inaccessible
....

By logging all the inputs, all the outputs, and snapshotting the respective directory contents at that moment in time, we should be able to narrow down the cause.
Comment on attachment 8880463 [details]
bug 1367329 - fix error handling code in mozversioncontrol.

https://reviewboard.mozilla.org/r/151808/#review156854

I wonder why my various linters didn't catch this :/
Attachment #8880463 - Flags: review?(gps) → review+
Pushed by tmielczarek@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/77038889d2a8
fix error handling code in mozversioncontrol. r=gps
See Also: → 1377216
:ted, can you look into this again, we still have many failures each week.
Component: General → Build Config
Product: Taskcluster → Core
Seems like a dupe of bug 1377216.
Yes, the current failure is bug 1377216, which I just wrote patches for. So hopefully this error's days are numbered.
Assignee: nobody → gps
Status: NEW → RESOLVED
Closed: 7 years ago
Keywords: leave-open
Resolution: --- → FIXED
Oh, not marking as dupe because the patch for the failure in the bug summary landed. Bug 1377216 actually tracks the current error.
Whiteboard: [stockwell needswork] → [stockwell fixed:other]
status-firefox55: --- → affected
status-firefox56: --- → fixed
Target Milestone: --- → mozilla56
Product: Core → Firefox Build System
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: