Closed Bug 1496387 Opened 7 years ago Closed 7 years ago

Test timed out in toolkit/mozapps/update/tests/unit_service_updater/marAppApplyUpdateAppBinInUseStageSuccessSvc_win.js due to path format changing back and forth

Categories

(Toolkit :: Application Update, defect, P5)

Product:
Toolkit
Component:
Application Update
Type:
defect

Tracking

()

Status:
RESOLVED FIXED

People

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

References

Details

(Keywords: intermittent-failure, Whiteboard: [retriggered][stockwell disable-recommended])

Attachments

(1 file)

Avoid changing the path format back and forth in order to reduce possibility of failures
6.10 KB, patch
molly
: review+
Details | Diff | Splinter Review
Filed by: shindli [at] mozilla.com https://treeherder.mozilla.org/logviewer.html#?job_id=203370852&repo=mozilla-inbound https://queue.taskcluster.net/v1/task/MYtNmrXfSLWe8ZXEt4_2jQ/runs/0/artifacts/public/logs/live_backing.log INFO - TEST-START | toolkit/mozapps/update/tests/unit_service_updater/marAppApplyUpdateAppBinInUseStageSuccessSvc_win.js 12:01:09 WARNING - TEST-UNEXPECTED-TIMEOUT | toolkit/mozapps/update/tests/unit_service_updater/marAppApplyUpdateAppBinInUseStageSuccessSvc_win.js | Test timed out 12:01:09 INFO - TEST-INFO took 300000ms 12:01:09 INFO - >>>>>>> 12:01:09 INFO - PID 6676 | Couldn't convert chrome URL: chrome://branding/locale/brand.properties 12:01:09 INFO - PID 6676 | [6676, Main Thread] WARNING: Failed to get directory to cache.: file z:/build/build/src/security/sandbox/win/src/sandboxbroker/sandboxBroker.cpp, line 83 12:01:09 INFO - PID 6676 | [6676, Main Thread] WARNING: Failed to get directory to cache.: file z:/build/build/src/security/sandbox/win/src/sandboxbroker/sandboxBroker.cpp, line 83 12:01:09 INFO - PID 6676 | [6676, Main Thread] WARNING: Failed to get directory to cache.: file z:/build/build/src/security/sandbox/win/src/sandboxbroker/sandboxBroker.cpp, line 83 12:01:09 INFO - PID 6676 | [6676, Main Thread] WARNING: Failed to get directory to cache.: file z:/build/build/src/security/sandbox/win/src/sandboxbroker/sandboxBroker.cpp, line 83 12:01:09 INFO - PID 6676 | [6676, Main Thread] WARNING: Couldn't get the user appdata directory. Crash events may not be produced.: file z:/build/build/src/toolkit/crashreporter/nsExceptionHandler.cpp, line 2733 12:01:09 INFO - (xpcshell/head.js) | test MAIN run_test pending (1) 12:01:09 INFO - "11:56:10:072 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [setupTestCommon : 771] start - general test setup" 12:01:09 INFO - TEST-PASS | toolkit/mozapps/update/tests/unit_service_updater/marAppApplyUpdateAppBinInUseStageSuccessSvc_win.js | setupTestCommon - [setupTestCommon : 773] gTestID should be 'undefined' (setupTestCommon should only be called once) - "undefined" === "undefined" 12:01:09 INFO - TEST-PASS | toolkit/mozapps/update/tests/unit_service_updater/marAppApplyUpdateAppBinInUseStageSuccessSvc_win.js | shouldRunServiceTest - [shouldRunServiceTest : 2247] the file or directory should exist, leafName: updater.exe - true == true 12:01:09 INFO - "11:56:10:076 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [runTestHelperSync : 2027] Running Z:\\task_1538651332\\build\\tests\\xpcshell\\tests\\toolkit\\mozapps\\update\\tests\\data\\TestAUSHelper.exe check-signature Z:\\task_1538651332\\build\\application\\firefox\\updater.exe" 12:01:09 INFO - "11:56:10:115 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [runTestHelperSync : 2027] Running Z:\\task_1538651332\\build\\tests\\xpcshell\\tests\\toolkit\\mozapps\\update\\tests\\data\\TestAUSHelper.exe wait-for-service-stop MozillaMaintenance 10" 12:01:09 INFO - TEST-PASS | toolkit/mozapps/update/tests/unit_service_updater/marAppApplyUpdateAppBinInUseStageSuccessSvc_win.js | shouldRunServiceTest - [shouldRunServiceTest : 2283] the maintenance service should be installed (if not, build system configuration bug?) - 0 != 238 12:01:09 INFO - TEST-PASS | toolkit/mozapps/update/tests/unit_service_updater/marAppApplyUpdateAppBinInUseStageSuccessSvc_win.js | shouldRunServiceTest - [shouldRunServiceTest : 2290] the updater.exe binary should be signed (if not, build system configuration bug?) - true == true 12:01:09 INFO - "11:56:10:126 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [getSpecialFolderDir : 1547] SHGetSpecialFolderPath returned path: C:\\Program Files" 12:01:09 INFO - "11:56:10:126 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [getMaintSvcDir : 1498] using CSIDL_PROGRAM_FILESX86 - maintenance service install directory path: C:\\Program Files\\Mozilla Maintenance Service" 12:01:09 INFO - TEST-PASS | toolkit/mozapps/update/tests/unit_service_updater/marAppApplyUpdateAppBinInUseStageSuccessSvc_win.js | attemptServiceInstall - [attemptServiceInstall : 2512] the file or directory should exist, leafName: Mozilla Maintenance Service - true == true 12:01:09 INFO - TEST-PASS | toolkit/mozapps/update/tests/unit_service_updater/marAppApplyUpdateAppBinInUseStageSuccessSvc_win.js | attemptServiceInstall - [attemptServiceInstall : 2516] the file or directory should exist, leafName: maintenanceservice.exe - true == true 12:01:09 INFO - "11:56:10:129 | TEST-INFO | ../data/xpcshellUtilsAUS.js -> file:///Z:/task_1538651332/build/tests/xpcshell/tests/toolkit/mozapps/update/tests/data/shared.js | [readFileBytes : 355] attempting to read file, path: C:\\Program Files\\Mozilla Maintenance Service\\maintenanceservice.exe" 12:01:09 INFO - "11:56:10:295 | TEST-INFO | ../data/xpcshellUtilsAUS.js -> file:///Z:/task_1538651332/build/tests/xpcshell/tests/toolkit/mozapps/update/tests/data/shared.js | [readFileBytes : 355] attempting to read file, path: Z:\\task_1538651332\\build\\application\\firefox\\maintenanceservice.exe" 12:01:09 INFO - "11:56:10:459 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [attemptServiceInstall : 2521] installed maintenance service binary is the same as the build's maintenance service binary" 12:01:09 INFO - (xpcshell/head.js) | test pending (2) 12:01:09 INFO - "11:56:10:460 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [getSpecialFolderDir : 1547] SHGetSpecialFolderPath returned path: Z:\\task_1538651332\\AppData\\Local" 12:01:09 INFO - "11:56:10:461 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [getSpecialFolderDir : 1547] SHGetSpecialFolderPath returned path: C:\\Program Files" 12:01:09 INFO - "11:56:10:463 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [setupTestCommon : 845] Updates Directory (UpdRootD) Path: Z:\\task_1538651332\\AppData\\Local\\Mozilla\\updates\\marAppApplyUpdateAppBinInUseStageSuccessSvc_win" 12:01:09 INFO - "11:56:10:466 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [setupTestCommon : 875] finish - general test setup" 12:01:09 INFO - "11:56:10:466 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [setupUpdaterTest : 2872] start - updater test setup" 12:01:09 INFO - "11:56:10:482 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TF_FE : 2888] start - setup test file: precomplete" 12:01:09 INFO - "11:56:10:484 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TF_FE : 2917] finish - setup test file: precomplete" 12:01:09 INFO - "11:56:10:485 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TF_FE : 2888] start - setup test file: searchpluginstext0" 12:01:09 INFO - "11:56:10:488 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TF_FE : 2917] finish - setup test file: searchpluginstext0" 12:01:09 INFO - "11:56:10:488 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TF_FE : 2888] start - setup test file: searchpluginspng1.png" 12:01:09 INFO - "11:56:10:489 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TF_FE : 2917] finish - setup test file: searchpluginspng1.png" 12:01:09 INFO - "11:56:10:489 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TF_FE : 2888] start - setup test file: searchpluginspng0.png" 12:01:09 INFO - "11:56:10:492 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TF_FE : 2917] finish - setup test file: searchpluginspng0.png" 12:01:09 INFO - "11:56:10:492 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TF_FE : 2888] start - setup test file: removed-files" 12:01:09 INFO - "11:56:10:495 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TF_FE : 2917] finish - setup test file: removed-files" 12:01:09 INFO - "11:56:10:495 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TF_FE : 2888] start - setup test file: extensions1text0" 12:01:09 INFO - "11:56:10:495 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TF_FE : 2917] finish - setup test file: extensions1text0" 12:01:09 INFO - "11:56:10:495 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TF_FE : 2888] start - setup test file: extensions1png1.png" 12:01:09 INFO - "11:56:10:500 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TF_FE : 2917] finish - setup test file: extensions1png1.png" 12:01:09 INFO - "11:56:10:500 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TF_FE : 2888] start - setup test file: extensions1png0.png" 12:01:09 INFO - "11:56:10:501 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TF_FE : 2917] finish - setup test file: extensions1png0.png" 12:01:09 INFO - "11:56:10:501 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TF_FE : 2888] start - setup test file: extensions0text0" 12:01:09 INFO - "11:56:10:505 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TF_FE : 2917] finish - setup test file: extensions0text0" 12:01:09 INFO - "11:56:10:505 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TF_FE : 2888] start - setup test file: extensions0png1.png" 12:01:09 INFO - "11:56:10:505 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TF_FE : 2917] finish - setup test file: extensions0png1.png" 12:01:09 INFO - "11:56:10:505 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TF_FE : 2888] start - setup test file: extensions0png0.png" 12:01:09 INFO - "11:56:10:506 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TF_FE : 2917] finish - setup test file: extensions0png0.png" 12:01:09 INFO - "11:56:10:506 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TF_FE : 2888] start - setup test file: exe0.exe" 12:01:09 INFO - "11:56:10:510 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TF_FE : 2917] finish - setup test file: exe0.exe" 12:01:09 INFO - "11:56:10:510 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TF_FE : 2888] start - setup test file: 10text0" 12:01:09 INFO - "11:56:10:515 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TF_FE : 2917] finish - setup test file: 10text0" 12:01:09 INFO - "11:56:10:515 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TF_FE : 2888] start - setup test file: 0exe0.exe" 12:01:09 INFO - "11:56:10:520 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TF_FE : 2917] finish - setup test file: 0exe0.exe" 12:01:09 INFO - "11:56:10:520 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TF_FE : 2888] start - setup test file: 00text1" 12:01:09 INFO - "11:56:10:524 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TF_FE : 2917] finish - setup test file: 00text1" 12:01:09 INFO - "11:56:10:524 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TF_FE : 2888] start - setup test file: 00text0" 12:01:09 INFO - "11:56:10:526 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TF_FE : 2917] finish - setup test file: 00text0" 12:01:09 INFO - "11:56:10:527 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TF_FE : 2888] start - setup test file: 00png0.png" 12:01:09 INFO - "11:56:10:527 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TF_FE : 2917] finish - setup test file: 00png0.png" 12:01:09 INFO - "11:56:10:527 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TF_FE : 2888] start - setup test file: 20text0" 12:01:09 INFO - "11:56:10:531 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TF_FE : 2917] finish - setup test file: 20text0" 12:01:09 INFO - "11:56:10:532 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TF_FE : 2888] start - setup test file: 20png0.png" 12:01:09 INFO - "11:56:10:534 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TF_FE : 2917] finish - setup test file: 20png0.png" 12:01:09 INFO - "11:56:10:535 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TF_FE : 2888] start - setup test file: update-settings.ini" 12:01:09 INFO - "11:56:10:538 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TF_FE : 2917] finish - setup test file: update-settings.ini" 12:01:09 INFO - "11:56:10:538 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TF_FE : 2888] start - setup test file: channel-prefs.js" 12:01:09 INFO - "11:56:10:542 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TF_FE : 2917] finish - setup test file: channel-prefs.js" 12:01:09 INFO - "11:56:10:542 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TD_FE : 2923] start - setup test directory: 3/" 12:01:09 INFO - "11:56:10:545 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TD_FE : 2955] finish - setup test directory: 3/" 12:01:09 INFO - "11:56:10:545 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TD_FE : 2923] start - setup test directory: 4/" 12:01:09 INFO - "11:56:10:548 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TD_FE : 2955] finish - setup test directory: 4/" 12:01:09 INFO - "11:56:10:549 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TD_FE : 2923] start - setup test directory: 5/" 12:01:09 INFO - "11:56:10:553 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TD_FE : 2955] finish - setup test directory: 5/" 12:01:09 INFO - "11:56:10:553 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TD_FE : 2923] start - setup test directory: 6/" 12:01:09 INFO - "11:56:10:554 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TD_FE : 2955] finish - setup test directory: 6/" 12:01:09 INFO - "11:56:10:554 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TD_FE : 2923] start - setup test directory: 7/" 12:01:09 INFO - "11:56:10:566 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TD_FE : 2955] finish - setup test directory: 7/" 12:01:09 INFO - "11:56:10:566 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TD_FE : 2923] start - setup test directory: 8/" 12:01:09 INFO - "11:56:10:566 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TD_FE : 2955] finish - setup test directory: 8/" 12:01:09 INFO - "11:56:10:567 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TD_FE : 2923] start - setup test directory: 8/80/" 12:01:09 INFO - "11:56:10:567 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TD_FE : 2955] finish - setup test directory: 8/80/" 12:01:09 INFO - "11:56:10:567 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TD_FE : 2923] start - setup test directory: 8/81/" 12:01:09 INFO - "11:56:10:571 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TD_FE : 2955] finish - setup test directory: 8/81/" 12:01:09 INFO - "11:56:10:571 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TD_FE : 2923] start - setup test directory: 8/82/" 12:01:09 INFO - "11:56:10:572 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TD_FE : 2955] finish - setup test directory: 8/82/" 12:01:09 INFO - "11:56:10:573 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TD_FE : 2923] start - setup test directory: 8/83/" 12:01:09 INFO - "11:56:10:573 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TD_FE : 2955] finish - setup test directory: 8/83/" 12:01:09 INFO - "11:56:10:574 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TD_FE : 2923] start - setup test directory: 8/84/" 12:01:09 INFO - "11:56:10:574 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TD_FE : 2955] finish - setup test directory: 8/84/" 12:01:09 INFO - "11:56:10:574 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TD_FE : 2923] start - setup test directory: 8/85/" 12:01:09 INFO - "11:56:10:575 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TD_FE : 2955] finish - setup test directory: 8/85/" 12:01:09 INFO - "11:56:10:575 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TD_FE : 2923] start - setup test directory: 8/86/" 12:01:09 INFO - "11:56:10:578 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TD_FE : 2955] finish - setup test directory: 8/86/" 12:01:09 INFO - "11:56:10:579 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TD_FE : 2923] start - setup test directory: 8/87/" 12:01:09 INFO - "11:56:10:586 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TD_FE : 2955] finish - setup test directory: 8/87/" 12:01:09 INFO - "11:56:10:586 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TD_FE : 2923] start - setup test directory: 8/88/" 12:01:09 INFO - "11:56:10:587 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TD_FE : 2955] finish - setup test directory: 8/88/" 12:01:09 INFO - "11:56:10:587 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TD_FE : 2923] start - setup test directory: 8/89/" 12:01:09 INFO - "11:56:10:588 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TD_FE : 2955] finish - setup test directory: 8/89/" 12:01:09 INFO - "11:56:10:588 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TD_FE : 2923] start - setup test directory: 9/90/" 12:01:09 INFO - "11:56:10:588 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TD_FE : 2955] finish - setup test directory: 9/90/" 12:01:09 INFO - "11:56:10:589 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TD_FE : 2923] start - setup test directory: 9/91/" 12:01:09 INFO - "11:56:10:592 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TD_FE : 2955] finish - setup test directory: 9/91/" 12:01:09 INFO - "11:56:10:593 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TD_FE : 2923] start - setup test directory: 9/92/" 12:01:09 INFO - "11:56:10:594 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TD_FE : 2955] finish - setup test directory: 9/92/" 12:01:09 INFO - "11:56:10:594 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TD_FE : 2923] start - setup test directory: 9/93/" 12:01:09 INFO - "11:56:10:595 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TD_FE : 2955] finish - setup test directory: 9/93/" 12:01:10 INFO - "11:56:10:595 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TD_FE : 2923] start - setup test directory: 9/94/" 12:01:10 INFO - "11:56:10:596 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TD_FE : 2955] finish - setup test directory: 9/94/" 12:01:10 INFO - "11:56:10:596 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TD_FE : 2923] start - setup test directory: 9/95/" 12:01:10 INFO - "11:56:10:596 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TD_FE : 2955] finish - setup test directory: 9/95/" 12:01:10 INFO - "11:56:10:597 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TD_FE : 2923] start - setup test directory: 9/96/" 12:01:10 INFO - "11:56:10:600 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TD_FE : 2955] finish - setup test directory: 9/96/" 12:01:10 INFO - "11:56:10:600 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TD_FE : 2923] start - setup test directory: 9/97/" 12:01:10 INFO - "11:56:10:608 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TD_FE : 2955] finish - setup test directory: 9/97/" 12:01:10 INFO - "11:56:10:608 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TD_FE : 2923] start - setup test directory: 9/98/" 12:01:10 INFO - "11:56:10:608 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TD_FE : 2955] finish - setup test directory: 9/98/" 12:01:10 INFO - "11:56:10:609 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TD_FE : 2923] start - setup test directory: 9/99/" 12:01:10 INFO - "11:56:10:609 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TD_FE : 2955] finish - setup test directory: 9/99/" 12:01:10 INFO - "11:56:10:610 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TD_FE : 2923] start - setup test directory: 2/20/" 12:01:10 INFO - "11:56:10:610 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TD_FE : 2955] finish - setup test directory: 2/20/" 12:01:10 INFO - "11:56:10:610 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TD_FE : 2923] start - setup test directory: 2/" 12:01:10 INFO - "11:56:10:610 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [SUT_TD_FE : 2955] finish - setup test directory: 2/" 12:01:10 INFO - PID 6676 | *** AUS:SVC readStatusFile - status: pending-service, path: Z:\\task_1538651332\\AppData\\Local\\Mozilla\\updates\\marAppApplyUpdateAppBinInUseStageSuccessSvc_win\\updates\\0\\update.status 12:01:10 INFO - PID 6676 | *** AUS:SVC UpdateManager:_loadXMLFileIntoArray - XML file does not exist. path: Z:\\task_1538651332\\AppData\\Local\\Mozilla\\updates\\marAppApplyUpdateAppBinInUseStageSuccessSvc_win\\updates.xml 12:01:10 INFO - TEST-PASS | toolkit/mozapps/update/tests/unit_service_updater/marAppApplyUpdateAppBinInUseStageSuccessSvc_win.js | setupActiveUpdate - [setupActiveUpdate : 2088] the active update should be defined - true == true 12:01:10 INFO - "11:56:10:646 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [setupUpdaterTest : 2964] finish - updater test setup" 12:01:10 INFO - "11:56:10:646 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [setupAppFiles : 2349] start - copying or creating symlinks to application files for the test" 12:01:10 INFO - TEST-PASS | toolkit/mozapps/update/tests/unit_service_updater/marAppApplyUpdateAppBinInUseStageSuccessSvc_win.js | copyFileToTestAppDir - [copyFileToTestAppDir : 2450] the file or directory should exist, leafName: firefox.exe - true == true 12:01:10 INFO - TEST-PASS | toolkit/mozapps/update/tests/unit_service_updater/marAppApplyUpdateAppBinInUseStageSuccessSvc_win.js | copyFileToTestAppDir - [copyFileToTestAppDir : 2450] the file or directory should exist, leafName: application.ini - true == true 12:01:10 INFO - TEST-PASS | toolkit/mozapps/update/tests/unit_service_updater/marAppApplyUpdateAppBinInUseStageSuccessSvc_win.js | copyFileToTestAppDir - [copyFileToTestAppDir : 2450] the file or directory should exist, leafName: dependentlibs.list - true == true 12:01:10 INFO - TEST-PASS | toolkit/mozapps/update/tests/unit_service_updater/marAppApplyUpdateAppBinInUseStageSuccessSvc_win.js | copyFileToTestAppDir - [copyFileToTestAppDir : 2450] the file or directory should exist, leafName: MSVCP140.dll - true == true 12:01:10 INFO - TEST-PASS | toolkit/mozapps/update/tests/unit_service_updater/marAppApplyUpdateAppBinInUseStageSuccessSvc_win.js | copyFileToTestAppDir - [copyFileToTestAppDir : 2450] the file or directory should exist, leafName: api-ms-win-crt-runtime-l1-1-0.dll - true == true 12:01:10 INFO - TEST-PASS | toolkit/mozapps/update/tests/unit_service_updater/marAppApplyUpdateAppBinInUseStageSuccessSvc_win.js | copyFileToTestAppDir - [copyFileToTestAppDir : 2450] the file or directory should exist, leafName: api-ms-win-crt-string-l1-1-0.dll - true == true 12:01:10 INFO - TEST-PASS | toolkit/mozapps/update/tests/unit_service_updater/marAppApplyUpdateAppBinInUseStageSuccessSvc_win.js | copyFileToTestAppDir - [copyFileToTestAppDir : 2450] the file or directory should exist, leafName: api-ms-win-crt-heap-l1-1-0.dll - true == true 12:01:10 INFO - TEST-PASS | toolkit/mozapps/update/tests/unit_service_updater/marAppApplyUpdateAppBinInUseStageSuccessSvc_win.js | copyFileToTestAppDir - [copyFileToTestAppDir : 2450] the file or directory should exist, leafName: api-ms-win-crt-stdio-l1-1-0.dll - true == true 12:01:10 INFO - TEST-PASS | toolkit/mozapps/update/tests/unit_service_updater/marAppApplyUpdateAppBinInUseStageSuccessSvc_win.js | copyFileToTestAppDir - [copyFileToTestAppDir : 2450] the file or directory should exist, leafName: api-ms-win-crt-convert-l1-1-0.dll - true == true 12:01:10 INFO - TEST-PASS | toolkit/mozapps/update/tests/unit_service_updater/marAppApplyUpdateAppBinInUseStageSuccessSvc_win.js | copyFileToTestAppDir - [copyFileToTestAppDir : 2450] the file or directory should exist, leafName: VCRUNTIME140.dll - true == true 12:01:10 INFO - TEST-PASS | toolkit/mozapps/update/tests/unit_service_updater/marAppApplyUpdateAppBinInUseStageSuccessSvc_win.js | copyFileToTestAppDir - [copyFileToTestAppDir : 2450] the file or directory should exist, leafName: api-ms-win-crt-time-l1-1-0.dll - true == true 12:01:10 INFO - TEST-PASS | toolkit/mozapps/update/tests/unit_service_updater/marAppApplyUpdateAppBinInUseStageSuccessSvc_win.js | copyFileToTestAppDir - [copyFileToTestAppDir : 2450] the file or directory should exist, leafName: api-ms-win-crt-math-l1-1-0.dll - true == true 12:01:10 INFO - TEST-PASS | toolkit/mozapps/update/tests/unit_service_updater/marAppApplyUpdateAppBinInUseStageSuccessSvc_win.js | copyFileToTestAppDir - [copyFileToTestAppDir : 2450] the file or directory should exist, leafName: api-ms-win-crt-filesystem-l1-1-0.dll - true == true 12:01:10 INFO - TEST-PASS | toolkit/mozapps/update/tests/unit_service_updater/marAppApplyUpdateAppBinInUseStageSuccessSvc_win.js | copyFileToTestAppDir - [copyFileToTestAppDir : 2450] the file or directory should exist, leafName: api-ms-win-crt-environment-l1-1-0.dll - true == true 12:01:10 INFO - TEST-PASS | toolkit/mozapps/update/tests/unit_service_updater/marAppApplyUpdateAppBinInUseStageSuccessSvc_win.js | copyFileToTestAppDir - [copyFileToTestAppDir : 2450] the file or directory should exist, leafName: mozglue.dll - true == true 12:01:10 INFO - TEST-PASS | toolkit/mozapps/update/tests/unit_service_updater/marAppApplyUpdateAppBinInUseStageSuccessSvc_win.js | copyFileToTestAppDir - [copyFileToTestAppDir : 2450] the file or directory should exist, leafName: api-ms-win-crt-utility-l1-1-0.dll - true == true 12:01:10 INFO - TEST-PASS | toolkit/mozapps/update/tests/unit_service_updater/marAppApplyUpdateAppBinInUseStageSuccessSvc_win.js | copyFileToTestAppDir - [copyFileToTestAppDir : 2450] the file or directory should exist, leafName: api-ms-win-crt-multibyte-l1-1-0.dll - true == true 12:01:10 INFO - TEST-PASS | toolkit/mozapps/update/tests/unit_service_updater/marAppApplyUpdateAppBinInUseStageSuccessSvc_win.js | copyFileToTestAppDir - [copyFileToTestAppDir : 2450] the file or directory should exist, leafName: nss3.dll - true == true 12:01:10 INFO - TEST-PASS | toolkit/mozapps/update/tests/unit_service_updater/marAppApplyUpdateAppBinInUseStageSuccessSvc_win.js | copyFileToTestAppDir - [copyFileToTestAppDir : 2450] the file or directory should exist, leafName: lgpllibs.dll - true == true 12:01:10 INFO - TEST-PASS | toolkit/mozapps/update/tests/unit_service_updater/marAppApplyUpdateAppBinInUseStageSuccessSvc_win.js | copyFileToTestAppDir - [copyFileToTestAppDir : 2450] the file or directory should exist, leafName: api-ms-win-crt-locale-l1-1-0.dll - true == true 12:01:10 INFO - TEST-PASS | toolkit/mozapps/update/tests/unit_service_updater/marAppApplyUpdateAppBinInUseStageSuccessSvc_win.js | copyFileToTestAppDir - [copyFileToTestAppDir : 2450] the file or directory should exist, leafName: xul.dll - true == true 12:01:10 INFO - TEST-PASS | toolkit/mozapps/update/tests/unit_service_updater/marAppApplyUpdateAppBinInUseStageSuccessSvc_win.js | getTestUpdater - [getTestUpdater : 1774] the file or directory should exist, path: Z:/task_1538651332/build/tests/xpcshell/tests/toolkit/mozapps/update/tests/data/updater.exe - true == true 12:01:10 INFO - "11:56:11:272 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [setupAppFiles : 2403] finish - copying or creating symlinks to application files for the test" 12:01:10 INFO - (xpcshell/head.js) | test setupUpdaterTestFinished pending (3) 12:01:10 INFO - (xpcshell/head.js) | test MAIN run_test finished (3) 12:01:10 INFO - running event loop 12:01:10 INFO - PID 6676 | [6676, Main Thread] WARNING: Could not get the program name for a cubeb stream.: 'NS_SUCCEEDED(rv)', file z:/build/build/src/dom/media/CubebUtils.cpp, line 381 12:01:10 INFO - "CONSOLE_MESSAGE: (info) AUS:SVC readStatusFile - status: pending-service, path: Z:\\task_1538651332\\AppData\\Local\\Mozilla\\updates\\marAppApplyUpdateAppBinInUseStageSuccessSvc_win\\updates\\0\\update.status" 12:01:10 INFO - "CONSOLE_MESSAGE: (info) AUS:SVC UpdateManager:_loadXMLFileIntoArray - XML file does not exist. path: Z:\\task_1538651332\\AppData\\Local\\Mozilla\\updates\\marAppApplyUpdateAppBinInUseStageSuccessSvc_win\\updates.xml" 12:01:10 INFO - "11:56:11:275 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [stageUpdate : 2136] start - attempting to stage update" 12:01:10 INFO - "11:56:11:275 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [getSpecialFolderDir : 1547] SHGetSpecialFolderPath returned path: C:\\Program Files" 12:01:10 INFO - "11:56:11:275 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [getMaintSvcDir : 1498] using CSIDL_PROGRAM_FILESX86 - maintenance service install directory path: C:\\Program Files\\Mozilla Maintenance Service" 12:01:10 INFO - "11:56:11:277 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [setEnvironment : 4325] setting the XRE_NO_WINDOWS_CRASH_DIALOG environment variable to 1... previously it didn't exist" 12:01:10 INFO - "11:56:11:277 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [setEnvironment : 4377] setting the XPCOM_DEBUG_BREAK environment variable to warn... previous value stack-and-abort" 12:01:10 INFO - "11:56:11:277 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [setEnvironment : 4387] setting MOZ_NO_SERVICE_FALLBACK environment variable to 1" 12:01:10 INFO - "11:56:11:278 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [stageUpdate : 2162] finish - attempting to stage update" 12:01:10 INFO - (xpcshell/head.js) | test setupUpdaterTestFinished finished (2) 12:01:10 INFO - PID 6676 | *** AUS:SVC readStatusFile - status: applied, path: Z:\\task_1538651332\\AppData\\Local\\Mozilla\\updates\\marAppApplyUpdateAppBinInUseStageSuccessSvc_win\\updates\\0\\update.status 12:01:10 INFO - PID 6676 | *** AUS:SVC isServiceInstalled - returning true 12:01:10 INFO - PID 6676 | *** AUS:SVC shouldUseService - returning true 12:01:10 INFO - PID 6676 | *** AUS:SVC UpdateManager:refreshUpdateStatus - Notifying observers that the update was staged. topic: update-staged, status: applied-service 12:01:10 INFO - "11:56:12:227 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [observe : 2113] observe called with topic: update-staged, data: applied-service" 12:01:10 INFO - "11:56:12:228 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [resetEnvironment : 4414] setting the XPCOM_DEBUG_BREAK environment variable back to stack-and-abort" 12:01:10 INFO - "11:56:12:228 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [resetEnvironment : 4443] removing the XRE_NO_WINDOWS_CRASH_DIALOG environment variable" 12:01:10 INFO - "11:56:12:229 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [resetEnvironment : 4449] removing MOZ_NO_SERVICE_FALLBACK environment variable" 12:01:10 INFO - (xpcshell/head.js) | test bound checkUpdateStagedState pending (2) 12:01:10 INFO - "CONSOLE_MESSAGE: (info) AUS:SVC readStatusFile - status: applied, path: Z:\\task_1538651332\\AppData\\Local\\Mozilla\\updates\\marAppApplyUpdateAppBinInUseStageSuccessSvc_win\\updates\\0\\update.status" 12:01:10 INFO - "CONSOLE_MESSAGE: (info) AUS:SVC isServiceInstalled - returning true" 12:01:10 INFO - "CONSOLE_MESSAGE: (info) AUS:SVC shouldUseService - returning true" 12:01:10 INFO - "CONSOLE_MESSAGE: (info) AUS:SVC UpdateManager:refreshUpdateStatus - Notifying observers that the update was staged. topic: update-staged, status: applied-service" 12:01:10 INFO - "11:56:12:232 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [waitForApplicationStop : 2608] waiting for maintenanceservice_installer.exe to stop if necessary" 12:01:10 INFO - "11:56:12:232 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [runTestHelperSync : 2027] Running Z:\\task_1538651332\\build\\tests\\xpcshell\\tests\\toolkit\\mozapps\\update\\tests\\data\\TestAUSHelper.exe wait-for-application-exit maintenanceservice_installer.exe 120" 12:01:10 INFO - TEST-PASS | toolkit/mozapps/update/tests/unit_service_updater/marAppApplyUpdateAppBinInUseStageSuccessSvc_win.js | waitForApplicationStop - [waitForApplicationStop : 2613] the process should have stopped, process name: maintenanceservice_installer.exe - 0 == 0 12:01:10 INFO - "11:56:12:241 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [waitForApplicationStop : 2608] waiting for maintenanceservice_tmp.exe to stop if necessary" 12:01:10 INFO - "11:56:12:241 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [runTestHelperSync : 2027] Running Z:\\task_1538651332\\build\\tests\\xpcshell\\tests\\toolkit\\mozapps\\update\\tests\\data\\TestAUSHelper.exe wait-for-application-exit maintenanceservice_tmp.exe 120" 12:01:10 INFO - TEST-PASS | toolkit/mozapps/update/tests/unit_service_updater/marAppApplyUpdateAppBinInUseStageSuccessSvc_win.js | waitForApplicationStop - [waitForApplicationStop : 2613] the process should have stopped, process name: maintenanceservice_tmp.exe - 0 == 0 12:01:10 INFO - "11:56:12:249 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [waitForApplicationStop : 2608] waiting for maintenanceservice.exe to stop if necessary" 12:01:10 INFO - "11:56:12:249 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [runTestHelperSync : 2027] Running Z:\\task_1538651332\\build\\tests\\xpcshell\\tests\\toolkit\\mozapps\\update\\tests\\data\\TestAUSHelper.exe wait-for-application-exit maintenanceservice.exe 120" 12:01:10 INFO - TEST-PASS | toolkit/mozapps/update/tests/unit_service_updater/marAppApplyUpdateAppBinInUseStageSuccessSvc_win.js | waitForApplicationStop - [waitForApplicationStop : 2613] the process should have stopped, process name: maintenanceservice.exe - 0 == 0 12:01:10 INFO - "11:56:12:257 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [waitForServiceStop : 2577] waiting for the maintenance service to stop if necessary" 12:01:10 INFO - "11:56:12:257 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [runTestHelperSync : 2027] Running Z:\\task_1538651332\\build\\tests\\xpcshell\\tests\\toolkit\\mozapps\\update\\tests\\data\\TestAUSHelper.exe wait-for-service-stop MozillaMaintenance 120" 12:01:10 INFO - TEST-PASS | toolkit/mozapps/update/tests/unit_service_updater/marAppApplyUpdateAppBinInUseStageSuccessSvc_win.js | waitForServiceStop - [waitForServiceStop : 2582] the maintenance service should exist - 0 != 238 12:01:10 INFO - "11:56:12:266 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [waitForServiceStop : 2592] service stopped" 12:01:10 INFO - "11:56:12:266 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [waitForApplicationStop : 2608] waiting for maintenanceservice_installer.exe to stop if necessary" 12:01:10 INFO - "11:56:12:266 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [runTestHelperSync : 2027] Running Z:\\task_1538651332\\build\\tests\\xpcshell\\tests\\toolkit\\mozapps\\update\\tests\\data\\TestAUSHelper.exe wait-for-application-exit maintenanceservice_installer.exe 120" 12:01:10 INFO - TEST-PASS | toolkit/mozapps/update/tests/unit_service_updater/marAppApplyUpdateAppBinInUseStageSuccessSvc_win.js | waitForApplicationStop - [waitForApplicationStop : 2613] the process should have stopped, process name: maintenanceservice_installer.exe - 0 == 0 12:01:10 INFO - "11:56:12:274 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [waitForApplicationStop : 2608] waiting for maintenanceservice_tmp.exe to stop if necessary" 12:01:10 INFO - "11:56:12:274 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [runTestHelperSync : 2027] Running Z:\\task_1538651332\\build\\tests\\xpcshell\\tests\\toolkit\\mozapps\\update\\tests\\data\\TestAUSHelper.exe wait-for-application-exit maintenanceservice_tmp.exe 120" 12:01:10 INFO - TEST-PASS | toolkit/mozapps/update/tests/unit_service_updater/marAppApplyUpdateAppBinInUseStageSuccessSvc_win.js | waitForApplicationStop - [waitForApplicationStop : 2613] the process should have stopped, process name: maintenanceservice_tmp.exe - 0 == 0 12:01:10 INFO - "11:56:12:282 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [waitForApplicationStop : 2608] waiting for maintenanceservice.exe to stop if necessary" 12:01:10 INFO - "11:56:12:282 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [runTestHelperSync : 2027] Running Z:\\task_1538651332\\build\\tests\\xpcshell\\tests\\toolkit\\mozapps\\update\\tests\\data\\TestAUSHelper.exe wait-for-application-exit maintenanceservice.exe 120" 12:01:10 INFO - TEST-PASS | toolkit/mozapps/update/tests/unit_service_updater/marAppApplyUpdateAppBinInUseStageSuccessSvc_win.js | waitForApplicationStop - [waitForApplicationStop : 2613] the process should have stopped, process name: maintenanceservice.exe - 0 == 0 12:01:10 INFO - TEST-PASS | toolkit/mozapps/update/tests/unit_service_updater/marAppApplyUpdateAppBinInUseStageSuccessSvc_win.js | checkUpdateStagedState - [checkUpdateStagedState : 2187] the notified state should equal the expected value - "applied-service" == "applied-service" 12:01:10 INFO - TEST-PASS | toolkit/mozapps/update/tests/unit_service_updater/marAppApplyUpdateAppBinInUseStageSuccessSvc_win.js | checkUpdateStagedState - [checkUpdateStagedState : 2191] the status file state should equal the expected value - "applied-service" == "applied-service" 12:01:10 INFO - TEST-PASS | toolkit/mozapps/update/tests/unit_service_updater/marAppApplyUpdateAppBinInUseStageSuccessSvc_win.js | checkUpdateStagedState - [checkUpdateStagedState : 2194] the update state should equal the expected value - "applied-service" == "applied-service" 12:01:10 INFO - TEST-PASS | toolkit/mozapps/update/tests/unit_service_updater/marAppApplyUpdateAppBinInUseStageSuccessSvc_win.js | checkUpdateStagedState - [checkUpdateStagedState : 2199] the file or directory should exist, path: <update_dir_path>/marAppApplyUpdateAppBinInUseStageSuccessSvc_win/updates/last-update.log - true == true 12:01:10 INFO - TEST-PASS | toolkit/mozapps/update/tests/unit_service_updater/marAppApplyUpdateAppBinInUseStageSuccessSvc_win.js | checkUpdateStagedState - [checkUpdateStagedState : 2203] the file or directory should not exist, path: <update_dir_path>/marAppApplyUpdateAppBinInUseStageSuccessSvc_win/updates/0/update.log - true == true 12:01:10 INFO - TEST-PASS | toolkit/mozapps/update/tests/unit_service_updater/marAppApplyUpdateAppBinInUseStageSuccessSvc_win.js | checkUpdateStagedState - [checkUpdateStagedState : 2207] the file or directory should not exist, path: <update_dir_path>/marAppApplyUpdateAppBinInUseStageSuccessSvc_win/updates/backup-update.log - true == true 12:01:10 INFO - TEST-PASS | toolkit/mozapps/update/tests/unit_service_updater/marAppApplyUpdateAppBinInUseStageSuccessSvc_win.js | checkUpdateStagedState - [checkUpdateStagedState : 2213] the file or directory should exist, path: <test_dir_path>/marAppApplyUpdateAppBinInUseStageSuccessSvc_win/dir.app/updated - true == true 12:01:10 INFO - "11:56:12:296 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [getSpecialFolderDir : 1547] SHGetSpecialFolderPath returned path: C:\\Program Files" 12:01:10 INFO - "11:56:12:296 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [getMaintSvcDir : 1498] using CSIDL_PROGRAM_FILESX86 - maintenance service install directory path: C:\\Program Files\\Mozilla Maintenance Service" 12:01:10 INFO - TEST-PASS | toolkit/mozapps/update/tests/unit_service_updater/marAppApplyUpdateAppBinInUseStageSuccessSvc_win.js | checkUpdateStagedState - [checkUpdateStagedState : 2222] the contents of the maintenanceservice.log should not be the same as the original contents - "Disabled unneeded token privilege: SeAssignPrimaryTokenPrivilege.\\r\\nDisabled unneeded token privilege: SeAuditPrivilege.\\r\\nDisabled unneeded token privilege: SeBackupPrivilege.\\r\\nDisabled unneeded token privilege: SeCreateGlobalPrivilege.\\r\\nDisabled unneeded token privilege: SeCreatePagefilePrivilege.\\r\\nDisabled unneeded token privilege: SeCreatePermanentPrivilege.\\r\\nDisabled unneeded token privilege: SeCreateSymbolicLinkPrivilege.\\r\\nCould not disable token privilege value: SeCreateTokenPrivilege. (1300)\\r\\nDisabled unneeded token privilege: SeDebugPrivilege.\\r\\nCould not disable token privilege value: SeEnableDelegationPrivilege. (1300)\\r\\nDisabled unneeded token privilege: SeImpersonatePrivilege.\\r\\nDisabled unneeded token privilege: SeIncreaseBasePriorityPrivilege.\\r\\nDisabled unneeded token privilege: SeIncreaseQuotaPrivilege.\\r\\nDisabled unneeded token privilege: SeIncreaseWorkingSetPrivilege.\\r\\nDisabled unneeded token privilege: SeLoadDriverPrivilege.\\r\\nDisabled unneeded token privilege: SeLockMemoryPrivilege.\\r\\nCould not disable token privilege value: SeMachineAccountPrivilege. (1300)\\r\\nDisabled unneeded token privilege: SeManageVolumePrivilege.\\r\\nDisabled unneeded token privilege: SeProfileSingleProcessPrivilege.\\r\\nCould not disable token privilege value: SeRelabelPrivilege. (1300)\\r\\nCould not disable token privilege value: SeRemoteShutdownPrivilege. (1300)\\r\\nDisabled unneeded token privilege: SeRestorePrivilege.\\r\\nDisabled unneeded token privilege: SeSecurityPrivilege.\\r\\nDisabled unneeded token privilege: SeShutdownPrivilege.\\r\\nCould not disable token privilege value: SeSyncAgentPrivilege. (1300)\\r\\nDisabled unneeded token privilege: SeSystemEnvironmentPrivilege.\\r\\nDisabled unneeded token privilege: SeSystemProfilePrivilege.\\r\\nDisabled unneeded token privilege: SeSystemtimePrivilege.\\r\\nDisabled unneeded token privilege: SeTakeOwnershipPrivilege.\\r\\nDisabled unneeded token privilege: SeTcbPrivilege.\\r\\nDisabled unneeded token privilege: SeTimeZonePrivilege.\\r\\nCould not disable token privilege value: SeTrustedCredManAccessPrivilege. (1300)\\r\\nDisabled unneeded token privilege: SeUndockPrivilege.\\r\\nCould not disable token privilege value: SeUnsolicitedInputPrivilege. (1313)\\r\\nExecuting service command software-update, ID: e2e3a3da-8a27-4ef7-b7a5-afff67cc06c3\\r\\nupdater.exe was compared successfully to the installation directory updater.exe.\\r\\nThe updater.exe application contains the Mozilla updater identity.\\r\\n*** Warning: Could not open key. (2)***\\r\\n*** Warning: Fallback key present, skipping VerifyCertificateTrustForFile check and the certificate attribute registry matching check.***\\r\\nPassed in path: 'Z:\\\\task_1538651332\\\\build\\\\tests\\\\xpcshell\\\\tests\\\\toolkit\\\\mozapps\\\\update\\\\tests\\\\unit_service_updater\\\\marAppApplyUpdateAppBinInUseStageSuccessSvc_win\\\\dir.app\\\\updater.exe'; Using this path for updating: 'C:\\\\Program Files\\\\Mozilla Maintenance Service\\\\update\\\\updater.exe'.\\r\\nupdater.exe was compared successfully to the installation directory updater.exe.\\r\\nThe updater.exe application contains the Mozilla updater identity.\\r\\n*** Warning: Could not open key. (2)***\\r\\n*** Warning: Fallback key present, skipping VerifyCertificateTrustForFile check and the certificate attribute registry matching check.***\\r\\nStarting update process as the service in session 0.\\r\\nStarting service with cmdline: \\"C:\\\\Program Files\\\\Mozilla Maintenance Service\\\\update\\\\updater.exe\\" Z:\\\\task_1538651332\\\\AppData\\\\Local\\\\Mozilla\\\\updates\\\\marAppApplyUpdateAppBinInUseStageSuccessSvc_win\\\\updates\\\\0 Z:\\\\task_1538651332\\\\build\\\\tests\\\\xpcshell\\\\tests\\\\toolkit\\\\mozapps\\\\update\\\\tests\\\\unit_service_updater\\\\marAppApplyUpdateAppBinInUseStageSuccessSvc_win\\\\dir.app Z:\\\\task_1538651332\\\\build\\\\tests\\\\xpcshell\\\\tests\\\\toolkit\\\\mozapps\\\\update\\\\tests\\\\unit_service_updater\\\\marAppApplyUpdateAppBinInUseStageSuccessSvc_win\\\\dir.app\\\\updated -1\\r\\nProcess was started... waiting on result.\\r\\nProcess finished with return code 0.\\r\\nupdater.exe was launched and run successfully!\\r\\nService command software-update complete.\\r\\nservice command MozillaMaintenance complete with result: Success.\\r\\n" != "Disabled unneeded token privilege: SeAssignPrimaryTokenPrivilege.\\r\\nDisabled unneeded token privilege: SeAuditPrivilege.\\r\\nDisabled unneeded token privilege: SeBackupPrivilege.\\r\\nDisabled unneeded token privilege: SeCreateGlobalPrivilege.\\r\\nDisabled unneeded token privilege: SeCreatePagefilePrivilege.\\r\\nDisabled unneeded token privilege: SeCreatePermanentPrivilege.\\r\\nDisabled unneeded token privilege: SeCreateSymbolicLinkPrivilege.\\r\\nCould not disable token privilege value: SeCreateTokenPrivilege. (1300)\\r\\nDisabled unneeded token privilege: SeDebugPrivilege.\\r\\nCould not disable token privilege value: SeEnableDelegationPrivilege. (1300)\\r\\nDisabled unneeded token privilege: SeImpersonatePrivilege.\\r\\nDisabled unneeded token privilege: SeIncreaseBasePriorityPrivilege.\\r\\nDisabled unneeded token privilege: SeIncreaseQuotaPrivilege.\\r\\nDisabled unneeded token privilege: SeIncreaseWorkingSetPrivilege.\\r\\nDisabled unneeded token privilege: SeLoadDriverPrivilege.\\r\\nDisabled unneeded token privilege: SeLockMemoryPrivilege.\\r\\nCould not disable token privilege value: SeMachineAccountPrivilege. (1300)\\r\\nDisabled unneeded token privilege: SeManageVolumePrivilege.\\r\\nDisabled unneeded token privilege: SeProfileSingleProcessPrivilege.\\r\\nCould not disable token privilege value: SeRelabelPrivilege. (1300)\\r\\nCould not disable token privilege value: SeRemoteShutdownPrivilege. (1300)\\r\\nDisabled unneeded token privilege: SeRestorePrivilege.\\r\\nDisabled unneeded token privilege: SeSecurityPrivilege.\\r\\nDisabled unneeded token privilege: SeShutdownPrivilege.\\r\\nCould not disable token privilege value: SeSyncAgentPrivilege. (1300)\\r\\nDisabled unneeded token privilege: SeSystemEnvironmentPrivilege.\\r\\nDisabled unneeded token privilege: SeSystemProfilePrivilege.\\r\\nDisabled unneeded token privilege: SeSystemtimePrivilege.\\r\\nDisabled unneeded token privilege: SeTakeOwnershipPrivilege.\\r\\nDisabled unneeded token privilege: SeTcbPrivilege.\\r\\nDisabled unneeded token privilege: SeTimeZonePrivilege.\\r\\nCould not disable token privilege value: SeTrustedCredManAccessPrivilege. (1300)\\r\\nDisabled unneeded token privilege: SeUndockPrivilege.\\r\\nCould not disable token privilege value: SeUnsolicitedInputPrivilege. (1313)\\r\\nExecuting service command software-update, ID: 7ee4c64c-9fb4-4224-bfc2-ce484c6e57b1\\r\\nupdater.exe was compared successfully to the installation directory updater.exe.\\r\\nThe updater.exe application contains the Mozilla updater identity.\\r\\n*** Warning: Could not open key. (2)***\\r\\n*** Warning: Fallback key present, skipping VerifyCertificateTrustForFile check and the certificate attribute registry matching check.***\\r\\nPassed in path: 'Z:\\\\task_1538651332\\\\build\\\\tests\\\\xpcshell\\\\tests\\\\toolkit\\\\mozapps\\\\update\\\\tests\\\\unit_service_updater\\\\marRMRFDirFileInUseStageFailurePartialSvc_win\\\\dir.app\\\\updater.exe'; Using this path for updating: 'C:\\\\Program Files\\\\Mozilla Maintenance Service\\\\update\\\\updater.exe'.\\r\\nupdater.exe was compared successfully to the installation directory updater.exe.\\r\\nThe updater.exe application contains the Mozilla updater identity.\\r\\n*** Warning: Could not open key. (2)***\\r\\n*** Warning: Fallback key present, skipping VerifyCertificateTrustForFile check and the certificate attribute registry matching check.***\\r\\nStarting update process as the service in session 0.\\r\\nStarting service with cmdline: \\"C:\\\\Program Files\\\\Mozilla Maintenance Service\\\\update\\\\updater.exe\\" Z:\\\\task_1538651332\\\\AppData\\\\Local\\\\Mozilla\\\\updates\\\\marRMRFDirFileInUseStageFailurePartialSvc_win\\\\updates\\\\0 Z:\\\\task_1538651332\\\\build\\\\tests\\\\xpcshell\\\\tests\\\\toolkit\\\\mozapps\\\\update\\\\tests\\\\unit_service_updater\\\\marRMRFDirFileInUseStageFailurePartialSvc_win\\\\dir.app Z:\\\\task_1538651332\\\\build\\\\tests\\\\xpcshell\\\\tests\\\\toolkit\\\\mozapps\\\\update\\\\tests\\\\unit_service_updater\\\\marRMRFDirFileInUseStageFailurePartialSvc_win\\\\dir.app\\\\updated 0/replace Z:\\\\task_1538651332\\\\build\\\\tests\\\\xpcshell\\\\tests\\\\toolkit\\\\mozapps\\\\update\\\\tests\\\\unit_service_updater\\\\marRMRFDirFileInUseStageFailurePartialSvc_win\\\\dir.app Z:\\\\task_1538651332\\\\build\\\\tests\\\\xpcshell\\\\tests\\\\toolkit\\\\mozapps\\\\update\\\\tests\\\\unit_service_updater\\\\marRMRFDirFileInUseStageFailurePartialSvc_win\\\\dir.app\\\\callback_app.exe ./ callback.log \\"Test Arg 2\\" \\"Test Arg 3\\"\\r\\nProcess was started... waiting on result.\\r\\nProcess finished with return code 1.\\r\\n*** Warning: Error running update process. Updating update.status (0)***\\r\\nService command software-update complete.\\r\\nservice command MozillaMaintenance complete with result: Failure.\\r\\n" 12:01:10 INFO - TEST-PASS | toolkit/mozapps/update/tests/unit_service_updater/marAppApplyUpdateAppBinInUseStageSuccessSvc_win.js | checkUpdateStagedState - [checkUpdateStagedState : 2225] the contents of the maintenanceservice.log should contain the successful launch string - 3779 != -1 12:01:10 INFO - (xpcshell/head.js) | test stageUpdateFinished pending (3) 12:01:10 INFO - (xpcshell/head.js) | test bound checkUpdateStagedState finished (3)
> 12:09:41 INFO - PID 7420 | Hit MOZ_CRASH(QueryFullProcessImageNameW failed) at z:/build/build/src/browser/app/winlauncher/LauncherProcessWin.cpp:195 Hmm, we should be more lenient about the failure.
Flags: needinfo?(VYV03354)
QA Contact: robert.strong.bugs
QA Contact: robert.strong.bugs
This only occurs on Win 7 debug, and 2 occurances on windows7-32-msvc on tier2, mozilla-central. Masatoshi and who can to that?
Flags: needinfo?(VYV03354)
I'm working on the fix.
Flags: needinfo?(VYV03354)
QueryFullProcessImageNameW may fail in some environments when dwFlags is zero due to NT-to-DOS path conversions. CreateFile will convert the argumant back to an NT path anyway.
Attachment #9015013 - Flags: review?(mhowell)
Assignee: nobody → VYV03354
Status: NEW → ASSIGNED
Attachment #9015013 - Flags: review?(mhowell) → review+
Pushed by VYV03354@nifty.ne.jp: https://hg.mozilla.org/integration/mozilla-inbound/rev/0db58037928d Avoid changing the path format back and forth in order to reduce possibility of failures. r=mhowell
https://hg.mozilla.org/mozilla-central/rev/0db58037928d
Status: ASSIGNED → RESOLVED
Closed: 7 years ago
status-firefox64: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → mozilla64
Fail reappeared on autoland. Log link: https://treeherder.mozilla.org/logviewer.html#?job_id=213025392&repo=autoland&lineNumber=12922 Log snippet: 00:08:54 INFO - TEST-START | toolkit/mozapps/update/tests/unit_service_updater/marAppApplyUpdateAppBinInUseStageSuccessSvc_win.js 00:13:54 WARNING - TEST-UNEXPECTED-TIMEOUT | toolkit/mozapps/update/tests/unit_service_updater/marAppApplyUpdateAppBinInUseStageSuccessSvc_win.js | Test timed out 00:13:54 INFO - TEST-INFO took 300000ms 00:13:54 INFO - >>>>>>> 00:13:54 INFO - PID 9492 | Couldn't convert chrome URL: chrome://branding/locale/brand.properties 00:13:54 INFO - PID 9492 | [9492, Main Thread] WARNING: Failed to get directory to cache.: file z:/build/build/src/security/sandbox/win/src/sandboxbroker/sandboxBroker.cpp, line 84 00:13:54 INFO - PID 9492 | [9492, Main Thread] WARNING: Failed to get directory to cache.: file z:/build/build/src/security/sandbox/win/src/sandboxbroker/sandboxBroker.cpp, line 84 00:13:54 INFO - PID 9492 | [9492, Main Thread] WARNING: Failed to get directory to cache.: file z:/build/build/src/security/sandbox/win/src/sandboxbroker/sandboxBroker.cpp, line 84 00:13:54 INFO - PID 9492 | [9492, Main Thread] WARNING: Failed to get directory to cache.: file z:/build/build/src/security/sandbox/win/src/sandboxbroker/sandboxBroker.cpp, line 84 00:13:54 INFO - PID 9492 | [9492, Main Thread] WARNING: Failed to get directory to cache.: file z:/build/build/src/security/sandbox/win/src/sandboxbroker/sandboxBroker.cpp, line 84 00:13:54 INFO - PID 9492 | [9492, Main Thread] WARNING: Couldn't get the user appdata directory. Crash events may not be produced.: file z:/build/build/src/toolkit/crashreporter/nsExceptionHandler.cpp, line 2749 00:13:54 INFO - (xpcshell/head.js) | test MAIN run_test pending (1) 00:13:54 INFO - "00:08:54:757 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [setupTestCommon : 774] start - general test setup"
Micah, the fail seems to start from your push https://hg.mozilla.org/integration/autoland/rev/df86262bfccdd4c4f534ec45e0549cd29474c58c Could you please take a look?
Flags: needinfo?(mtigley)
Status: RESOLVED → REOPENED
status-firefox64: fixed → ---
Resolution: FIXED → ---
Target Milestone: mozilla64 → ---
I think bug 1508885 should have been kept open instead of reopening a closed bug and duplicating it to this bug just because the same test happens to fail due to a completely different reason.
Flags: needinfo?(nbeleuzu)
Status: REOPENED → RESOLVED
Closed: 7 years ago → 7 years ago
Flags: needinfo?(nbeleuzu)
Flags: needinfo?(mtigley)
Resolution: --- → FIXED
Changing summary so this doesn't get reopened
Summary: Intermittent TEST-UNEXPECTED-TIMEOUT | toolkit/mozapps/update/tests/unit_service_updater/marAppApplyUpdateAppBinInUseStageSuccessSvc_win.js | Test timed out → Test timed out in toolkit/mozapps/update/tests/unit_service_updater/marAppApplyUpdateAppBinInUseStageSuccessSvc_win.js due to path format changing back and forth
See Also: → 1508940
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: