Closed Bug 1598628 Opened 5 years ago Closed 5 years ago

Perma Late Beta TEST-UNEXPECTED-FAIL : xperf: File 'c:\windows\system32\windows.globalization.dll' (normalized from 'C:\Windows\System32\Windows.Globalization.dll') was accessed and we were not expecting it. when Gecko 72 merges to Beta on 2019-12-02

Categories

(Core :: Internationalization, defect)

defect
Not set
normal

Tracking

()

VERIFIED FIXED
mozilla72
Tracking Status
firefox-esr68 --- unaffected
firefox70 --- unaffected
firefox71 --- unaffected
firefox72 + verified

People

(Reporter: malexandru, Assigned: jfkthame)

References

(Regression)

Details

(Keywords: regression)

Attachments

(1 file)

Central as Late Beta simulation: https://treeherder.mozilla.org/#/jobs?repo=try&resultStatus=success%2Ctestfailed%2Cbusted%2Cexception%2Crunnable&revision=25d80e91ccc4cc561379dcf6a885834720d722e2&searchStr=%28x%2Ctalos&selectedJob=277652973

Failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=277652973&repo=try&lineNumber=1674

[task 2019-11-22T13:53:23.185Z] 13:53:23 INFO - PID 2028 | [#98] youtube.com/www.youtube.com/music.html Cycles:1 Average:513.00 Median:513.00 stddev:0.00 (0.0%)
[task 2019-11-22T13:53:23.185Z] 13:53:23 INFO - PID 2028 | Values: 513.0
[task 2019-11-22T13:53:23.185Z] 13:53:23 INFO - PID 2028 |
[task 2019-11-22T13:53:23.185Z] 13:53:23 INFO - PID 2028 | [#99] people.com.cn/people.com.cn/index.html Cycles:1 Average:610.00 Median:610.00 stddev:0.00 (0.0%)
[task 2019-11-22T13:53:23.185Z] 13:53:23 INFO - PID 2028 | Values: 610.0
[task 2019-11-22T13:53:23.185Z] 13:53:23 INFO - PID 2028 | -------- Summary: end --------
[task 2019-11-22T13:53:23.185Z] 13:53:23 INFO - PID 2028 |
[task 2019-11-22T13:53:23.243Z] 13:53:23 INFO - PID 2028 | [Parent 7744, Gecko_IOThread] WARNING: file z:/task_1574426437/build/src/ipc/chromium/src/base/process_util_win.cc, line 160
[task 2019-11-22T13:53:23.606Z] 13:53:23 INFO - TEST-INFO | 2028: exit 0
[task 2019-11-22T13:53:26.143Z] 13:53:26 INFO - The trace you have just captured "Z:\task_1574430151\build\test.etl.kernel" may contain personally identifiable information, including but not necessarily limited to paths to files accessed, paths to registry accessed and process names. Exact information depends on the events that were logged. Please be aware of this when sharing out this trace with other people.
[task 2019-11-22T13:53:26.143Z] 13:53:26 INFO - The trace you have just captured "Z:\task_1574430151\build\test.etl.user" may contain personally identifiable information, including but not necessarily limited to paths to files accessed, paths to registry accessed and process names. Exact information depends on the events that were logged. Please be aware of this when sharing out this trace with other people.
[task 2019-11-22T13:53:35.468Z] 13:53:35 INFO - Merged Etl: test.etl
[task 2019-11-22T13:55:32.935Z] 13:55:32 INFO - reading etl filename: test.etl
[task 2019-11-22T13:55:32.935Z] 13:55:32 INFO - etlparser: in readfile: test.etl.csv
[task 2019-11-22T13:55:32.935Z] 13:55:32 INFO - TEST-UNEXPECTED-FAIL : xperf: File 'c:\windows\system32\windows.globalization.dll' (normalized from 'C:\Windows\System32\Windows.Globalization.dll') was accessed and we were not expecting it. DiskReadCount: 8, DiskWriteCount: 0, DiskReadBytes: 126976, DiskWriteBytes: 0
[task 2019-11-22T13:55:34.327Z] 13:55:34 INFO - extending with xperf!
[task 2019-11-22T13:55:34.327Z] 13:55:34 INFO - Detected a regression for tp5n
[task 2019-11-22T13:55:34.329Z] 13:55:34 INFO - TEST-UNEXPECTED-FAIL | tp5n | Talos has found a regression, if you have questions ask for help in irc on #perf
[task 2019-11-22T13:55:34.329Z] 13:55:34 ERROR - Traceback (most recent call last):
[task 2019-11-22T13:55:34.329Z] 13:55:34 INFO - File "Z:\task_1574430151\build\tests\talos\talos\run_tests.py", line 290, in run_tests
[task 2019-11-22T13:55:34.329Z] 13:55:34 INFO - talos_results.add(mytest.runTest(browser_config, test))
[task 2019-11-22T13:55:34.329Z] 13:55:34 INFO - File "Z:\task_1574430151\build\tests\talos\talos\ttest.py", line 64, in runTest
[task 2019-11-22T13:55:34.329Z] 13:55:34 INFO - return self._runTest(browser_config, test_config, setup)
[task 2019-11-22T13:55:34.329Z] 13:55:34 INFO - File "Z:\task_1574430151\build\tests\talos\talos\ttest.py", line 269, in _runTest
[task 2019-11-22T13:55:34.329Z] 13:55:34 INFO - 'Talos has found a regression, if you have questions'
[task 2019-11-22T13:55:34.329Z] 13:55:34 INFO - TalosRegression: Talos has found a regression, if you have questions ask for help in irc on #perf
[task 2019-11-22T13:55:34.329Z] 13:55:34 INFO - TEST-INFO took 238133ms
[task 2019-11-22T13:55:34.329Z] 13:55:34 INFO - SUITE-END | took 238s
[task 2019-11-22T13:55:34.765Z] 13:55:34 ERROR - Return code: 1
[task 2019-11-22T13:55:34.765Z] 13:55:34 WARNING - setting return code to 1
[task 2019-11-22T13:55:34.765Z] 13:55:34 ERROR - # TBPL WARNING #
[task 2019-11-22T13:55:34.765Z] 13:55:34 INFO - Running post-action listener: _package_coverage_data
[task 2019-11-22T13:55:34.765Z] 13:55:34 INFO - Running post-action listener: _resource_record_post_action
[task 2019-11-22T13:55:34.765Z] 13:55:34 INFO - Running post-action listener: process_java_coverage_data
[task 2019-11-22T13:55:34.765Z] 13:55:34 INFO - [mozharness: 2019-11-22 13:55:34.765000Z] Finished run-tests step (success)
[task 2019-11-22T13:55:34.765Z] 13:55:34 INFO - Running post-run listener: _resource_record_post_run
[task 2019-11-22T13:55:34.870Z] 13:55:34 INFO - Total resource usage - Wall time: 241s; CPU: 21.0%; Read bytes: 1373974016; Write bytes: 3758907904; Read time: 16; Write time: 40
[task 2019-11-22T13:55:34.870Z] 13:55:34 INFO - TinderboxPrint: CPU usage<br/>21.1%
[task 2019-11-22T13:55:34.870Z] 13:55:34 INFO - TinderboxPrint: I/O read bytes / time<br/>1,373,974,016 / 16
[task 2019-11-22T13:55:34.870Z] 13:55:34 INFO - TinderboxPrint: I/O write bytes / time<br/>3,758,907,904 / 40
[task 2019-11-22T13:55:34.870Z] 13:55:34 INFO - TinderboxPrint: CPU idle<br/>1,522.6 (78.8%)
[task 2019-11-22T13:55:34.870Z] 13:55:34 INFO - TinderboxPrint: CPU system<br/>198.0 (10.3%)
[task 2019-11-22T13:55:34.871Z] 13:55:34 INFO - TinderboxPrint: CPU user<br/>208.1 (10.8%)
[task 2019-11-22T13:55:34.871Z] 13:55:34 INFO - install - Wall time: 2s; CPU: 14.0%; Read bytes: 427520; Write bytes: 479232; Read time: 0; Write time: 0
[task 2019-11-22T13:55:34.874Z] 13:55:34 INFO - run-tests - Wall time: 240s; CPU: 21.0%; Read bytes: 1373546496; Write bytes: 3753263616; Read time: 16; Write time: 40
[task 2019-11-22T13:55:34.932Z] 13:55:34 WARNING - returning nonzero exit status 1
[taskcluster 2019-11-22T13:55:34.976Z] Exit Code: 1
[taskcluster 2019-11-22T13:55:34.976Z] User Time: 0s
[taskcluster 2019-11-22T13:55:34.976Z] Kernel Time: 0s
[taskcluster 2019-11-22T13:55:34.976Z] Wall Time: 5m22.6479705s
[taskcluster 2019-11-22T13:55:34.976Z] Result: FAILED
[taskcluster 2019-11-22T13:55:34.976Z] === Task Finished ===
[taskcluster 2019-11-22T13:55:34.976Z] Task Duration: 5m22.649931s
[taskcluster 2019-11-22T13:55:35.287Z] Uploading artifact public/logs/localconfig.json from file logs\localconfig.json with content encoding "gzip", mime type "application/octet-stream" and expiry 2019-12-06T13:50:05.542Z
[taskcluster 2019-11-22T13:55:35.435Z] Uploading artifact public/test_info/resource-usage.json from file build\blobber_upload_dir\resource-usage.json with content encoding "gzip", mime type "application/octet-stream" and expiry 2019-12-06T13:50:05.542Z
[taskcluster 2019-11-22T13:55:35.579Z] Uploading artifact public/test_info/xperf_errorsummary.log from file build\blobber_upload_dir\xperf_errorsummary.log with content encoding "gzip", mime type "text/plain" and expiry 2019-12-06T13:50:05.542Z
[taskcluster 2019-11-22T13:55:35.686Z] Uploading artifact public/test_info/xperf_raw.log from file build\blobber_upload_dir\xperf_raw.log with content encoding "gzip", mime type "text/plain" and expiry 2019-12-06T13:50:05.542Z
[taskcluster 2019-11-22T13:55:36.017Z] Uploading redirect artifact public/logs/live.log to URL https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/dk47-BopRqyaaAkoKcG2vg/runs/0/artifacts/public/logs/live_backing.log with mime type "text/plain; charset=utf-8" and expiry 2019-12-06T13:50:05.542Z
[taskcluster:error] exit status 1

Jonathan, could this be caused by the changes in Bug 1593414?

Flags: needinfo?(jfkthame)

Yes, this sounds like it's to be expected. In bug 1593414 we depend on Windows globalization APIs that we weren't using previously, so it makes sense we would access Windows.Globalization.dll.

Presumably we need to update something to note that this is expected? I'm afraid I don't know where that expectation is maintained...

Flags: needinfo?(jfkthame)

maybe testing/talos/talos/xtalos/xperf_whitelist.json?

Flags: needinfo?(jfkthame)

(In reply to Julien Cristau [:jcristau] from comment #2)

maybe testing/talos/talos/xtalos/xperf_whitelist.json?

Hmm, that seems plausible, thanks. (Although TBH, I don't really understand the criteria that determine whether something is present there; it does not seem to be an exhaustive list of all the files that we'd touch during a test run.)

Anyhow, we can add Windows.Globalization.dll there and presumably this issue will go away.

Flags: needinfo?(jfkthame)
Assignee: nobody → jfkthame
Flags: needinfo?(jfkthame)

Thanks for testing! Yes, I've just submitted it to Lando.

Flags: needinfo?(jfkthame)
Pushed by jkew@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/e19228b7fd46
Add an entry for windows.globalization.dll to xperf_whitelist.json. r=jmaher
Status: NEW → RESOLVED
Closed: 5 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla72
Has Regression Range: --- → yes
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: