Closed Bug 1496387 Opened 1 year ago Closed 1 year 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)

defect

Tracking

()

RESOLVED FIXED

People

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

References

Details

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

Attachments

(1 file)

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: 1 year ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla64
Duplicate of this bug: 1508885
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
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: 1 year ago1 year 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.