1485221 - Intermittent MS-016 INFRA-ERROR: The new screen resolution or mouse positions are not what we expected

Status: RESOLVED INCOMPLETE

(Infrastructure & Operations Graveyard :: CIDuty, task, P5)

Description

[Treeherder Bug Filer]

Filed by: aciure [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=195078562&repo=autoland

https://queue.taskcluster.net/v1/task/e5ie1oIlTWOOK0C1m3Rfiw/runs/0/artifacts/public/logs/live_backing.log

https://hg.mozilla.org/mozilla-central/raw-file/tip/layout/tools/reftest/reftest-analyzer.xhtml#logurl=https://queue.taskcluster.net/v1/task/e5ie1oIlTWOOK0C1m3Rfiw/runs/0/artifacts/public/logs/live_backing.log&only_show_unexpected=1&only_show_unexpected=1

15:01:15     INFO - [mozharness: 2018-08-21 15:01:15.122000Z] Finished stage-files step (success)
15:01:15     INFO - [mozharness: 2018-08-21 15:01:15.122000Z] Running run-tests step.
15:01:15     INFO - Running pre-action listener: _resource_record_pre_action
15:01:15     INFO - Running pre-action listener: _set_gcov_prefix
15:01:15     INFO - Running main action method: run_tests
15:01:15     INFO - Running pre test command run mouse & screen adjustment script with 'c:\mozilla-build\python\python.exe C:\Users\task_1534862131\mozharness\external_tools\mouse_and_screen_resolution.py --configuration-file C:\Users\task_1534862131\mozharness\external_tools\machine-configuration.json'
15:01:15     INFO - Running command: ('c:\\mozilla-build\\python\\python.exe', 'C:\\Users\\task_1534862131\\mozharness\\external_tools\\mouse_and_screen_resolution.py', '--configuration-file', 'C:\\Users\\task_1534862131\\mozharness\\external_tools\\machine-configuration.json') in C:\Users\task_1534862131\build
15:01:15     INFO - Copy/paste: c:\mozilla-build\python\python.exe C:\Users\task_1534862131\mozharness\external_tools\mouse_and_screen_resolution.py --configuration-file C:\Users\task_1534862131\mozharness\external_tools\machine-configuration.json
15:01:18     INFO -  Screen resolution (current): (1024, 768)
15:01:18     INFO -  Changing the screen resolution...
15:01:18     INFO -  Screen resolution (new): (1280, 1024)
15:01:18     INFO -  Mouse position (current): (1013, 265)
15:01:18     INFO -  Mouse position (new): (1013, 265)
15:01:18     INFO -  INFRA-ERROR: The new screen resolution or mouse positions are not what we expected
15:01:18    ERROR - Return code: 1
15:01:18    ERROR - 1 not in success codes: [0]
15:01:18  WARNING - setting return code to 3
15:01:18     INFO - Running post-action listener: _package_coverage_data
15:01:18     INFO - Running post-action listener: _resource_record_post_action
15:01:18     INFO - Running post-action listener: process_java_coverage_data
15:01:18     INFO - [mozharness: 2018-08-21 15:01:18.207000Z] Finished run-tests step (failed)
15:01:18    FATAL - Uncaught exception: Traceback (most recent call last):
15:01:18    FATAL -   File "C:\Users\task_1534862131\mozharness\mozharness\base\script.py", line 2088, in run
15:01:18    FATAL -     self.run_action(action)
15:01:18    FATAL -   File "C:\Users\task_1534862131\mozharness\mozharness\base\script.py", line 2026, in run_action
15:01:18    FATAL -     self._possibly_run_method("preflight_%s" % method_name)
15:01:18    FATAL -   File "C:\Users\task_1534862131\mozharness\mozharness\base\script.py", line 1967, in _possibly_run_method
15:01:18    FATAL -     return getattr(self, method_name)()
15:01:18    FATAL -   File "C:\Users\task_1534862131\mozharness\mozharness\mozilla\testing\testbase.py", line 741, in preflight_run_tests
15:01:18    FATAL -     self._run_cmd_checks(c.get('preflight_run_cmd_suites', []))
15:01:18    FATAL -   File "C:\Users\task_1534862131\mozharness\mozharness\mozilla\testing\testbase.py", line 735, in _run_cmd_checks
15:01:18    FATAL -     fatal_exit_code=suite.get('fatal_exit_code', 3))
15:01:18    FATAL -   File "C:\Users\task_1534862131\mozharness\mozharness\base\script.py", line 1473, in run_command
15:01:18    FATAL -     self.fatal("Halting on failure while running %s" % command,
15:01:18    FATAL - TypeError: not all arguments converted during string formatting
15:01:18    FATAL - Running post_fatal callback...
15:01:18    FATAL - Exiting -1
15:01:18     INFO - Running post-run listener: _resource_record_post_run
15:01:18     INFO - instance_metadata.json not found; unable to determine instance type
15:01:18     INFO - Validating Perfherder data against C:\Users\task_1534862131\mozharness\external_tools\performance-artifact-schema.json
15:01:18     INFO - PERFHERDER_DATA: {"framework": {"name": "job_resource_usage"}, "suites": [{"subtests": [{"name": "cpu_percent", "value": 7.184374999999999}, {"name": "io_write_bytes", "value": 35271680}, {"name": "io.read_bytes", "value": 188928}, {"name": "io_write_time", "value": 1}, {"name": "io_read_time", "value": 0}], "extraOptions": ["e10s", "buildbot-unknown"], "name": "reftest.reftest.reftest.1.overall"}, {"subtests": [{"name": "time", "value": 1.7420001029968262}, {"name": "cpu_percent", "value": 14.925}], "name": "reftest.reftest.reftest.1.install"}, {"subtests": [{"name": "time", "value": 0.0}], "name": "reftest.reftest.reftest.1.stage-files"}, {"subtests": [{"name": "time", "value": 3.0850000381469727}, {"name": "cpu_percent", "value": 0.775}], "name": "reftest.reftest.reftest.1.run-tests"}]}
15:01:18     INFO - Total resource usage - Wall time: 4s; CPU: 1.0%; Read bytes: 188928; Write bytes: 35271680; Read time: 0; Write time: 1
15:01:18     INFO - TinderboxPrint: CPU usage<br/>0.8%
15:01:18     INFO - TinderboxPrint: I/O read bytes / time<br/>188,928 / 0
15:01:18     INFO - TinderboxPrint: I/O write bytes / time<br/>35,271,680 / 1
15:01:18     INFO - TinderboxPrint: CPU idle<br/>29.9 (92.8%)
15:01:18     INFO - TinderboxPrint: CPU system<br/>0.8 (2.6%)
15:01:18     INFO - TinderboxPrint: CPU user<br/>1.5 (4.6%)
15:01:18     INFO - install - Wall time: 2s; CPU: 15.0%; Read bytes: 4096; Write bytes: 814080; Read time: 0; Write time: 0
15:01:18     INFO - stage-files - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
15:01:18     INFO - run-tests - Wall time: 3s; CPU: 1.0%; Read bytes: 0; Write bytes: 22057472; Read time: 0; Write time: 1
15:01:18     INFO - Running post-run listener: copy_logs_to_upload_dir
15:01:18     INFO - Copying logs to upload dir...

Comment 1

[Zsolt Fay [:zfay]]

This belongs to the pool of workers Mark is testing the new generic worker on. I believe this may be of interest to you Mark.

Comment 2

[Mark Cornmesser [:markco]]

Is this a one off failure? Or have we seen this multiple times? 

Might be my bad. I was spot checking this node yesterday. If the VNC connection was still active it may had affected the the mouse pointer location.

Comment 3

[Intermittent Failures Robot]

1 failures in 2568 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:
* autoland: 1

Platform breakdown:
* windows10-64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1485221&startday=2018-08-20&endday=2018-08-26&tree=all

Comment 4

[Firefox Bug Husbandry Bot]

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup