Closed Bug 1281586 Opened 4 years ago Closed 3 years ago

Intermittent toolkit/mozapps/update/tests/unit_service_updater/marStageSuccessPartialSvc.js | checkCallbackServiceLog - TypeError: logContents is null at ../data/xpcshellUtilsAUS.js:3514

Categories

(Toolkit :: Application Update, defect, P3)

x86
Windows XP
defect

Tracking

()

RESOLVED WORKSFORME

People

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

References

Details

(Keywords: intermittent-failure)

Attachments

(2 files, 3 obsolete files)

Likely a Win XP debug only failure and now that these tests have been disabled in bug 1291985 on Win XP debug I am resolving as duplicate. Please reopen or file a new bug if this intermittent is seen again.
Status: NEW → RESOLVED
Closed: 3 years ago
OS: Unspecified → Windows XP
Hardware: Unspecified → x86
Resolution: --- → DUPLICATE
Duplicate of bug: 1291985
Opt, https://treeherder.mozilla.org/logviewer.html#?job_id=35225964&repo=mozilla-inbound
Status: RESOLVED → REOPENED
Resolution: DUPLICATE → ---
Note: every check passes in this test except for the very last one which checks the maintenance service log in checkCallbackLog. It is also the only test that failed.
Attached patch patch - cleanup logging (obsolete) — Splinter Review
Not sure what is happening here but I'd like to at least get the logging cleaned up sooner rather than later.
Assignee: nobody → robert.strong.bugs
Status: REOPENED → ASSIGNED
Attachment #8787745 - Flags: review?(mhowell)
Attached patch patch - cleanup logging (obsolete) — Splinter Review
Attachment #8787745 - Attachment is obsolete: true
Attachment #8787745 - Flags: review?(mhowell)
Attachment #8787746 - Flags: review?(mhowell)
Comment on attachment 8787746 [details] [diff] [review]
patch - cleanup logging

bah, screwed this up
Attachment #8787746 - Attachment is obsolete: true
Attachment #8787746 - Flags: review?(mhowell)
Shows that similar tests passed before and after this failure.

08:30:31     INFO -  TEST-START | <service test path>bootstrapSvc.js
08:30:36     INFO -  TEST-PASS | <service test path>bootstrapSvc.js | took 4826ms
08:30:36     INFO -  TEST-START | <service test path>marSuccessCompleteSvc.js
08:30:41     INFO -  TEST-PASS | <service test path>marSuccessCompleteSvc.js | took 5685ms
08:30:41     INFO -  TEST-START | <service test path>marSuccessPartialSvc.js
08:30:51     INFO -  TEST-PASS | <service test path>marSuccessPartialSvc.js | took 9511ms
08:30:51     INFO -  TEST-START | <service test path>marFailurePartialSvc.js
08:30:56     INFO -  TEST-PASS | <service test path>marFailurePartialSvc.js | took 4701ms
08:30:56     INFO -  TEST-START | <service test path>marStageSuccessCompleteSvc.js
08:31:17     INFO -  TEST-PASS | <service test path>marStageSuccessCompleteSvc.js | took 21178ms
08:31:17     INFO -  TEST-START | <service test path>marStageSuccessPartialSvc.js
08:31:48  WARNING -  TEST-UNEXPECTED-FAIL | <service test path>marStageSuccessPartialSvc.js | xpcshell return code: 0
08:31:48     INFO -  TEST-INFO took 31610ms
08:31:48     INFO -  >>>>>>>
08:31:48     INFO -  (xpcshell/head.js) | test MAIN run_test pending (1)
08:31:48     INFO -  "08:31:17:725 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [setupTestCommon : 777] start - general test setup"

<snip of passing checks>

08:31:49     INFO -  "08:31:38:401 | TEST-INFO | ../data/xpcshellUtilsAUS.js -> file:///C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/tests/data/shared.js | [readFileBytes : 358] attempting to read file, path: C:\\slave\\test\\build\\tests\\xpcshell\\tests\\toolkit\\mozapps\\update\\tests\\data\\replace_log_success"
08:31:49     INFO -  TEST-PASS | <service test path>marStageSuccessPartialSvc.js | checkUpdateLogContents - [checkUpdateLogContents : 3035] the update log contents should equal the expected value - true == true
08:31:49     INFO -  "08:31:38:402 | TEST-INFO | C:/slave/test/build/tests/xpcshell/tests/<service test path>marStageSuccessPartialSvc.js | [checkDistributionDir : 107] testing that files aren't added with an add-if instruction when the file's destination directory doesn't exist"
08:31:49     INFO -  "08:31:38:402 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [getMockUpdRootDWin : 1476] returning UpdRootD Path: C:\\Documents and Settings\\cltbld.T-XP32-IX-134\\Local Settings\\Application Data\\Mozilla\\updates\\marStageSuccessPartialSvc"
08:31:49     INFO -  TEST-PASS | <service test path>marStageSuccessPartialSvc.js | checkDistributionDir - [checkDistributionDir : 109] the file or directory should not exist, path: <test_dir_path>/marStageSuccessPartialSvc/dir.app/distribution - true == true
08:31:49     INFO -  TEST-PASS | <service test path>marStageSuccessPartialSvc.js | checkCallbackServiceLog - [checkCallbackServiceLog : 3455] gServiceLaunchedCallbackLog should be defined - true == true
08:31:49     INFO -  (xpcshell/head.js) | test checkCallbackServiceLog pending (3)
08:31:49     INFO -  (xpcshell/head.js) | test checkPostUpdateAppLogFinished finished (3)
08:31:49     INFO -  "CONSOLE_MESSAGE: (info) AUS:SVC Creating UpdateService"
08:31:49     INFO -  "CONSOLE_MESSAGE: (info) AUS:SVC gCanCheckForUpdates - able to check for updates"
08:31:49     INFO -  "CONSOLE_MESSAGE: (info) AUS:SVC isServiceInstalled = true"
08:31:49     INFO -  "CONSOLE_MESSAGE: (info) AUS:SVC getCanApplyUpdates - bypass the write checks because we'll use the service"
08:31:49     INFO -  "CONSOLE_MESSAGE: (info) AUS:SVC getCanApplyUpdates - able to apply updates"
08:31:49     INFO -  "CONSOLE_MESSAGE: (info) AUS:SVC readStatusFile - status: succeeded, path: C:\\Documents and Settings\\cltbld.T-XP32-IX-134\\Local Settings\\Application Data\\Mozilla\\updates\\marStageSuccessPartialSvc\\updates\\0\\update.status"
08:31:49     INFO -  TEST-PASS | <service test path>marStageSuccessPartialSvc.js | checkCallbackServiceLog - [checkCallbackServiceLog : 3455] gServiceLaunchedCallbackLog should be defined - true == true
08:31:49     INFO -  (xpcshell/head.js) | test checkCallbackServiceLog pending (3)
08:31:49     INFO -  (xpcshell/head.js) | test checkCallbackServiceLog finished (3)

<big snip of repeated messages>

08:32:07     INFO -  TEST-PASS | <service test path>marStageSuccessPartialSvc.js | checkCallbackServiceLog - [checkCallbackServiceLog : 3455] gServiceLaunchedCallbackLog should be defined - true == true
08:32:07     INFO -  (xpcshell/head.js) | test checkCallbackServiceLog pending (3)
08:32:07     INFO -  (xpcshell/head.js) | test checkCallbackServiceLog finished (3)
08:32:07  WARNING -  TEST-UNEXPECTED-FAIL | <service test path>marStageSuccessPartialSvc.js | checkCallbackServiceLog - TypeError: logContents is null at ../data/xpcshellUtilsAUS.js:3471
08:32:07     INFO -  checkCallbackServiceLog@../data/xpcshellUtilsAUS.js:3471:11
08:32:07     INFO -  do_execute_soon/<.run@C:\slave\test\build\tests\xpcshell\head.js:713:9
08:32:07     INFO -  _do_main@C:\slave\test\build\tests\xpcshell\head.js:210:5
08:32:07     INFO -  _execute_test@C:\slave\test\build\tests\xpcshell\head.js:545:5
08:32:07     INFO -  @-e:1:1
08:32:07     INFO -  exiting test
08:32:07     INFO -  (xpcshell/head.js) | test checkCallbackServiceLog finished (2)
08:32:07     INFO -  "08:31:48:173 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [AGP_cleanup : 3924] start - unregistering directory provider"
08:32:07     INFO -  "08:31:48:173 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [cleanupTestCommon : 885] start - general test cleanup"
08:32:07     INFO -  "08:31:48:177 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [getMockUpdRootDWin : 1476] returning UpdRootD Path: C:\\Documents and Settings\\cltbld.T-XP32-IX-134\\Local Settings\\Application Data\\Mozilla\\updates\\marStageSuccessPartialSvc"
08:32:07     INFO -  "08:31:48:177 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [cleanupTestCommon : 941] attempting to remove directory. Path: C:\\Documents and Settings\\cltbld.T-XP32-IX-134\\Local Settings\\Application Data\\Mozilla\\updates\\marStageSuccessPartialSvc"
08:32:07     INFO -  "08:31:48:177 | TEST-INFO | ../data/xpcshellUtilsAUS.js -> file:///C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/tests/data/shared.js | [removeDirRecursive : 508] attempting to remove directory. Path: C:\\Documents and Settings\\cltbld.T-XP32-IX-134\\Local Settings\\Application Data\\Mozilla\\updates\\marStageSuccessPartialSvc"
08:32:07     INFO -  "08:31:48:192 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [cleanupTestCommon : 979] attempting to remove directory. Path: C:\\slave\\test\\build\\tests\\xpcshell\\tests\\toolkit\\mozapps\\update\\tests\\unit_service_updater\\marStageSuccessPartialSvc"
08:32:07     INFO -  "08:31:48:192 | TEST-INFO | ../data/xpcshellUtilsAUS.js -> file:///C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/tests/data/shared.js | [removeDirRecursive : 508] attempting to remove directory. Path: C:\\slave\\test\\build\\tests\\xpcshell\\tests\\toolkit\\mozapps\\update\\tests\\unit_service_updater\\marStageSuccessPartialSvc"
08:32:07     INFO -  "08:31:48:720 | TEST-INFO | ../data/xpcshellUtilsAUS.js -> file:///C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/tests/data/shared.js | [removeDirRecursive : 512] non-fatal error removing directory. Exception: [Exception... "Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIFile.remove]"  nsresult: "0x80004005 (NS_ERROR_FAILURE)"  location: "JS frame :: ../data/xpcshellUtilsAUS.js -> file:///C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/tests/data/shared.js :: removeDirRecursive :: line 509"  data: no]"
08:32:07     INFO -  "08:31:48:721 | TEST-INFO | ../data/xpcshellUtilsAUS.js -> file:///C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/tests/data/shared.js | [removeDirRecursive : 508] attempting to remove directory. Path: C:\\slave\\test\\build\\tests\\xpcshell\\tests\\toolkit\\mozapps\\update\\tests\\unit_service_updater\\marStageSuccessPartialSvc\\dir.app"
08:32:07     INFO -  "08:31:48:722 | TEST-INFO | ../data/xpcshellUtilsAUS.js -> file:///C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/tests/data/shared.js | [removeDirRecursive : 512] non-fatal error removing directory. Exception: [Exception... "Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIFile.remove]"  nsresult: "0x80004005 (NS_ERROR_FAILURE)"  location: "JS frame :: ../data/xpcshellUtilsAUS.js -> file:///C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/tests/data/shared.js :: removeDirRecursive :: line 509"  data: no]"
08:32:07     INFO -  "08:31:48:722 | TEST-INFO | ../data/xpcshellUtilsAUS.js -> file:///C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/tests/data/shared.js | [removeDirRecursive : 524] attempting to remove file. Path: C:\\slave\\test\\build\\tests\\xpcshell\\tests\\toolkit\\mozapps\\update\\tests\\unit_service_updater\\marStageSuccessPartialSvc\\dir.app\\api-ms-win-crt-convert-l1-1-0.dll"
08:32:07     INFO -  "08:31:48:723 | TEST-INFO | ../data/xpcshellUtilsAUS.js -> file:///C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/tests/data/shared.js | [removeDirRecursive : 527] error removing file. Exception: [Exception... "Component returned failure code: 0x80520015 (NS_ERROR_FILE_ACCESS_DENIED) [nsIFile.remove]"  nsresult: "0x80520015 (NS_ERROR_FILE_ACCESS_DENIED)"  location: "JS frame :: ../data/xpcshellUtilsAUS.js -> file:///C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/tests/data/shared.js :: removeDirRecursive :: line 525"  data: no]"
08:32:07     INFO -  "08:31:48:723 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [cleanupTestCommon : 983] non-fatal error removing directory. Path: C:\\slave\\test\\build\\tests\\xpcshell\\tests\\toolkit\\mozapps\\update\\tests\\unit_service_updater\\marStageSuccessPartialSvc, Exception: [Exception... "Component returned failure code: 0x80520015 (NS_ERROR_FILE_ACCESS_DENIED) [nsIFile.remove]"  nsresult: "0x80520015 (NS_ERROR_FILE_ACCESS_DENIED)"  location: "JS frame :: ../data/xpcshellUtilsAUS.js -> file:///C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/tests/data/shared.js :: removeDirRecursive :: line 525"  data: no]"
08:32:07     INFO -  "08:31:48:723 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [cleanupTestCommon : 990] finish - general test cleanup"
08:32:07     INFO -  "08:31:48:723 | TEST-INFO | ../data/xpcshellUtilsAUS.js | [AGP_cleanup : 3971] finish - unregistering directory provider"
08:32:07     INFO -  <<<<<<<
08:32:07     INFO -  TEST-START | <service test path>marStageFailurePartialSvc.js
08:32:36     INFO -  TEST-PASS | <service test path>marStageFailurePartialSvc.js | took 29417ms
08:32:36     INFO -  TEST-START | <service test path>marCallbackAppSuccessCompleteSvc_win.js
08:32:45     INFO -  TEST-PASS | <service test path>marCallbackAppSuccessCompleteSvc_win.js | took 8842ms
08:32:45     INFO -  TEST-START | <service test path>marCallbackAppSuccessPartialSvc_win.js
08:32:55     INFO -  TEST-PASS | <service test path>marCallbackAppSuccessPartialSvc_win.js | took 9404ms
08:32:55     INFO -  TEST-START | <service test path>marCallbackAppStageSuccessCompleteSvc_win.js
08:33:09     INFO -  TEST-PASS | <service test path>marCallbackAppStageSuccessCompleteSvc_win.js | took 14482ms
08:33:09     INFO -  TEST-START | <service test path>marCallbackAppStageSuccessPartialSvc_win.js
08:33:24     INFO -  TEST-PASS | <service test path>marCallbackAppStageSuccessPartialSvc_win.js | took 14403ms
08:33:24     INFO -  TEST-START | <service test path>marAppInUseSuccessCompleteSvc.js
08:33:33     INFO -  TEST-PASS | <service test path>marAppInUseSuccessCompleteSvc.js | took 9795ms
08:33:33     INFO -  TEST-START | <service test path>marAppInUseStageFailureCompleteSvc_win.js
08:33:43     INFO -  TEST-PASS | <service test path>marAppInUseStageFailureCompleteSvc_win.js | took 9608ms
08:33:43     INFO -  TEST-START | <service test path>marFileLockedFailureCompleteSvc_win.js
08:33:48     INFO -  TEST-PASS | <service test path>marFileLockedFailureCompleteSvc_win.js | took 5265ms
08:33:48     INFO -  TEST-START | <service test path>marFileLockedFailurePartialSvc_win.js
08:33:54     INFO -  TEST-PASS | <service test path>marFileLockedFailurePartialSvc_win.js | took 5140ms
08:33:54     INFO -  TEST-START | <service test path>marFileLockedStageFailureCompleteSvc_win.js
08:34:02     INFO -  TEST-PASS | <service test path>marFileLockedStageFailureCompleteSvc_win.js | took 8046ms
08:34:02     INFO -  TEST-START | <service test path>marFileLockedStageFailurePartialSvc_win.js
08:34:10     INFO -  TEST-PASS | <service test path>marFileLockedStageFailurePartialSvc_win.js | took 7983ms
08:34:10     INFO -  TEST-START | <service test path>marFileInUseSuccessCompleteSvc_win.js
08:34:20     INFO -  TEST-PASS | <service test path>marFileInUseSuccessCompleteSvc_win.js | took 10342ms
08:34:20     INFO -  TEST-START | <service test path>marFileInUseSuccessPartialSvc_win.js
08:34:30     INFO -  TEST-PASS | <service test path>marFileInUseSuccessPartialSvc_win.js | took 10404ms
08:34:30     INFO -  TEST-START | <service test path>marRMRFDirFileInUseSuccessCompleteSvc_win.js
08:34:39     INFO -  TEST-PASS | <service test path>marRMRFDirFileInUseSuccessCompleteSvc_win.js | took 8811ms
08:34:39     INFO -  TEST-START | <service test path>marRMRFDirFileInUseSuccessPartialSvc_win.js
08:34:49     INFO -  TEST-PASS | <service test path>marRMRFDirFileInUseSuccessPartialSvc_win.js | took 9701ms
08:34:49     INFO -  TEST-START | <service test path>marFileInUseStageFailureCompleteSvc_win.js
08:34:58     INFO -  TEST-PASS | <service test path>marFileInUseStageFailureCompleteSvc_win.js | took 9123ms
08:34:58     INFO -  TEST-START | <service test path>marFileInUseStageFailurePartialSvc_win.js
08:35:08     INFO -  TEST-PASS | <service test path>marFileInUseStageFailurePartialSvc_win.js | took 9639ms
08:35:08     INFO -  TEST-START | <service test path>marRMRFDirFileInUseStageFailureCompleteSvc_win.js
08:35:18     INFO -  TEST-PASS | <service test path>marRMRFDirFileInUseStageFailureCompleteSvc_win.js | took 9967ms
08:35:18     INFO -  TEST-START | <service test path>marRMRFDirFileInUseStageFailurePartialSvc_win.js
08:35:28     INFO -  TEST-PASS | <service test path>marRMRFDirFileInUseStageFailurePartialSvc_win.js | took 10030ms
08:35:28     INFO -  TEST-START | <service test path>marAppApplyDirLockedStageFailureSvc_win.js
08:35:31     INFO -  TEST-PASS | <service test path>marAppApplyDirLockedStageFailureSvc_win.js | took 3062ms
08:35:31     INFO -  TEST-START | <service test path>marAppApplyUpdateAppBinInUseStageSuccessSvc_win.js
08:35:40     INFO -  TEST-PASS | <service test path>marAppApplyUpdateAppBinInUseStageSuccessSvc_win.js | took 9561ms
08:35:41     INFO -  TEST-START | <service test path>marAppApplyUpdateSuccessSvc.js
08:35:45     INFO -  TEST-PASS | <service test path>marAppApplyUpdateSuccessSvc.js | took 4484ms
08:35:45     INFO -  TEST-START | <service test path>marAppApplyUpdateStageSuccessSvc.js
08:35:55     INFO -  TEST-PASS | <service test path>marAppApplyUpdateStageSuccessSvc.js | took 9655ms
Attachment #8788523 - Flags: review?(mhowell) → review+
Pushed by rstrong@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/76fc567fe00e
clean up logging in the hope it helps figure out this intermittent. r=mhowell
This happened on 8/24/16, 8/25/16, and 9/2/16
No failures in a very long time.
Status: ASSIGNED → RESOLVED
Closed: 3 years ago3 years ago
Keywords: leave-open
Resolution: --- → WORKSFORME
You need to log in before you can comment on or make changes to this bug.