1517633 - Intermittent gtest | timed out after 300 seconds without output

Status: RESOLVED DUPLICATE of bug 1115253

(Core :: Audio/Video: GMP, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: rmaries [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=219873817&repo=mozilla-inbound

https://queue.taskcluster.net/v1/task/SJQBlO1LRB-6yV9EWr5WZQ/runs/0/artifacts/public/logs/live_backing.log

22:42:18     INFO - Starting resource monitoring.
22:42:18     INFO - [mozharness: 2019-01-03 22:42:18.245000Z] Finished create-virtualenv step (success)
22:42:18     INFO - [mozharness: 2019-01-03 22:42:18.245000Z] Running install step.
22:42:18     INFO - Running pre-action listener: _resource_record_pre_action
22:42:18     INFO - Running main action method: install
22:42:18     INFO - Getting output from command: ['Z:\\task_1546553712\\build\\venv\\Scripts\\pip', 'freeze']
22:42:18     INFO - Copy/paste: Z:\task_1546553712\build\venv\Scripts\pip freeze
22:42:18     INFO - Reading from file tmpfile_stdout
22:42:18     INFO - Using _rmtree_windows ...
22:42:18     INFO - Running command: del /F /Q "Z:\task_1546553712\tmpfile_stderr"
22:42:18     INFO - Return code: 0
22:42:18     INFO - Using _rmtree_windows ...
22:42:18     INFO - Running command: del /F /Q "Z:\task_1546553712\tmpfile_stdout"
22:42:18     INFO - Return code: 0
22:42:18     INFO - Detecting whether we're running mozinstall >=1.0...
22:42:18     INFO - Getting output from command: ['Z:\\task_1546553712\\build\\venv\\Scripts\\mozinstall', '-h']
22:42:18     INFO - Copy/paste: Z:\task_1546553712\build\venv\Scripts\mozinstall -h
22:42:18     INFO - Reading from file tmpfile_stdout
22:42:18     INFO - Output received:
22:42:18     INFO -  Usage: mozinstall-script.py [options] installer
22:42:18     INFO -  Options:
22:42:18     INFO -    -h, --help            show this help message and exit
22:42:18     INFO -    -d DEST, --destination=DEST
22:42:18     INFO -                          Directory to install application into. [default:
22:42:18     INFO -                          "Z:\task_1546553712"]
22:42:18     INFO -    --app=APP             Application being installed. [default: firefox]
22:42:18     INFO - Using _rmtree_windows ...
22:42:18     INFO - Running command: del /F /Q "Z:\task_1546553712\tmpfile_stderr"
22:42:18     INFO - Return code: 0
22:42:18     INFO - Using _rmtree_windows ...
22:42:18     INFO - Running command: del /F /Q "Z:\task_1546553712\tmpfile_stdout"
22:42:18     INFO - Return code: 0
22:42:18     INFO - mkdir: Z:\task_1546553712\build\application
22:42:18     INFO - Getting output from command: ['Z:\\task_1546553712\\build\\venv\\Scripts\\mozinstall', 'Z:\\task_1546553712\\build\\installer.zip', '--destination', 'Z:\\task_1546553712\\build\\application']
22:42:18     INFO - Copy/paste: Z:\task_1546553712\build\venv\Scripts\mozinstall Z:\task_1546553712\build\installer.zip --destination Z:\task_1546553712\build\application
22:42:22     INFO - Reading from file tmpfile_stdout
22:42:22     INFO - Output received:
22:42:22     INFO -  Z:\task_1546553712\build\application\firefox\firefox.exe
22:42:22     INFO - Using _rmtree_windows ...
22:42:22     INFO - Running command: del /F /Q "Z:\task_1546553712\tmpfile_stderr"
22:42:22     INFO - Return code: 0
22:42:22     INFO - Using _rmtree_windows ...
22:42:22     INFO - Running command: del /F /Q "Z:\task_1546553712\tmpfile_stdout"
22:42:22     INFO - Return code: 0
22:42:22     INFO - Running post-action listener: _resource_record_post_action
22:42:22     INFO - [mozharness: 2019-01-03 22:42:22.864000Z] Finished install step (success)
22:42:22     INFO - [mozharness: 2019-01-03 22:42:22.864000Z] Running stage-files step.
22:42:22     INFO - Running pre-action listener: _resource_record_pre_action
22:42:22     INFO - Running main action method: stage_files
22:42:22     INFO - Moving Z:\task_1546553712\build\tests\bin\plugins\gmp-clearkey to Z:\task_1546553712\build\application\firefox
22:42:22    ERROR - shutil error: Destination path 'Z:\task_1546553712\build\application\firefox\gmp-clearkey' already exists
22:42:22     INFO - Moving Z:\task_1546553712\build\tests\bin\plugins\gmp-fake to Z:\task_1546553712\build\application\firefox
22:42:22     INFO - Moving Z:\task_1546553712\build\tests\bin\plugins\gmp-fakeopenh264 to Z:\task_1546553712\build\application\firefox
22:42:22     INFO - Moving Z:\task_1546553712\build\tests\gtest\dependentlibs.list.gtest to Z:\task_1546553712\build\application\firefox
22:42:22     INFO - copying tree: Z:\task_1546553712\build\tests\gtest\gtest_bin to Z:\task_1546553712\build\application\firefox
22:42:22     INFO - mkdir: Z:\task_1546553712\build\application\firefox\gtest
22:42:22     INFO - copying tree: Z:\task_1546553712\build\tests\gtest\gtest_bin\gtest to Z:\task_1546553712\build\application\firefox\gtest
22:42:22     INFO - rmtree: Z:\task_1546553712\build\application\firefox\gtest
22:42:22     INFO - Using _rmtree_windows ...
22:42:22     INFO - retry: Calling _rmtree_windows with args: ('Z:\\task_1546553712\\build\\application\\firefox\\gtest',), kwargs: {}, attempt #1
22:42:22     INFO - Running command: rmdir /S /Q "Z:\task_1546553712\build\application\firefox\gtest"
22:42:22     INFO - Return code: 0
22:42:24     INFO - Running post-action listener: _resource_record_post_action
22:42:24     INFO - [mozharness: 2019-01-03 22:42:24.163000Z] Finished stage-files step (success)
22:42:24     INFO - [mozharness: 2019-01-03 22:42:24.163000Z] Running run-tests step.
22:42:24     INFO - Running pre-action listener: _resource_record_pre_action
22:42:24     INFO - Running pre-action listener: _set_gcov_prefix
22:42:24     INFO - Running main action method: run_tests
22:42:24     INFO - Running pre test command run mouse & screen adjustment script with 'c:\mozilla-build\python\python.exe Z:\task_1546553712\mozharness\external_tools\mouse_and_screen_resolution.py --configuration-file Z:\task_1546553712\mozharness\external_tools\machine-configuration.json'
22:42:24     INFO - Running command: ('c:\\mozilla-build\\python\\python.exe', 'Z:\\task_1546553712\\mozharness\\external_tools\\mouse_and_screen_resolution.py', '--configuration-file', 'Z:\\task_1546553712\\mozharness\\external_tools\\machine-configuration.json') in Z:\task_1546553712\build
22:42:24     INFO - Copy/paste: c:\mozilla-build\python\python.exe Z:\task_1546553712\mozharness\external_tools\mouse_and_screen_resolution.py --configuration-file Z:\task_1546553712\mozharness\external_tools\machine-configuration.json
22:42:27     INFO -  Screen resolution (current): (1600, 1200)
22:42:27     INFO -  Changing the screen resolution...
22:42:27     INFO -  Screen resolution (new): (1280, 1024)
22:42:27     INFO -  Mouse position (current): (640, 512)
22:42:27     INFO -  Mouse position (new): (1010, 10)
22:42:27     INFO - Return code: 0

Comment 1

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

22:48:26     INFO -  TEST-START | MultiWriterQueue.MultiWriterSingleReader
22:48:27     INFO -  MultiWriterQueue<int, 10, Locking_None> threads=1w+0r loops/thread=2097152 pushes=pops=2097152 duration=0.073535s pushes/s=28519289.010852 buffers: live=1 (w 209716) reusable=104858 (w 104858) alloc=104859 (w 209716)
22:48:28     INFO -  MultiWriterQueue<int, 10, Locking_None> threads=1w+1r loops/thread=2097152 pushes=pops=2097152 duration=1.392329s pushes/s=1506218.864109 buffers: live=1 (w 367) reusable=5 (w 133) alloc=6 (w 367)
22:48:30     INFO -  MultiWriterQueue<int, 10, Locking_None> threads=2w+1r loops/thread=1048576 pushes=pops=2097152 duration=1.395358s pushes/s=1502949.253539 buffers: live=1 (w 4518) reusable=3 (w 895) alloc=4 (w 4518)
22:48:31     INFO -  MultiWriterQueue<int, 10, Locking_None> threads=3w+1r loops/thread=699050 pushes=pops=2097150 duration=1.441336s pushes/s=1455004.730613 buffers: live=1 (w 1680) reusable=4 (w 394) alloc=5 (w 1681)
22:48:33     INFO -  MultiWriterQueue<int, 10, Locking_None> threads=4w+1r loops/thread=524288 pushes=pops=2097152 duration=1.452531s pushes/s=1443791.123723 buffers: live=1 (w 14230) reusable=5 (w 5403) alloc=6 (w 14230)
22:48:33     INFO -  [6044, QuotaManager IO] WARNING: 'NS_FAILED(rv)', file z:/build/build/src/dom/indexedDB/ActorsParent.cpp, line 16550
22:48:33     INFO -  [6044, IPDL Background] WARNING: Maintenance finished with error: NS_ERROR_NOT_AVAILABLE: file z:/build/build/src/dom/indexedDB/ActorsParent.cpp, line 16499
22:48:34     INFO -  MultiWriterQueue<int, 10, Locking_None> threads=5w+1r loops/thread=419430 pushes=pops=2097150 duration=1.481690s pushes/s=1415376.989830 buffers: live=1 (w 20236) reusable=5 (w 707) alloc=6 (w 20236)
22:48:36     INFO -  MultiWriterQueue<int, 10, Locking_None> threads=6w+1r loops/thread=349525 pushes=pops=2097150 duration=1.477547s pushes/s=1419345.459260 buffers: live=1 (w 31899) reusable=4 (w 349) alloc=5 (w 31899)
22:48:37     INFO -  MultiWriterQueue<int, 10, Locking_None> threads=7w+1r loops/thread=299593 pushes=pops=2097151 duration=1.454588s pushes/s=1441748.681433 buffers: live=1 (w 26033) reusable=4 (w 441) alloc=5 (w 26033)
22:48:39     INFO -  MultiWriterQueue<int, 10, Locking_None> threads=8w+1r loops/thread=262144 pushes=pops=2097152 duration=1.456213s pushes/s=1440140.738949 buffers: live=1 (w 37250) reusable=4494 (w 4494) alloc=4495 (w 37250)
22:48:40     INFO -  MultiWriterQueue<int, 10, Locking_None> threads=9w+1r loops/thread=233016 pushes=pops=2097144 duration=1.432954s pushes/s=1463510.714005 buffers: live=1 (w 26176) reusable=1837 (w 1937) alloc=1838 (w 26176)
22:48:42     INFO -  MultiWriterQueue<int, 10, Locking_None> threads=10w+1r loops/thread=209715 pushes=pops=2097150 duration=1.459408s pushes/s=1436986.589150 buffers: live=1 (w 31054) reusable=4 (w 2659) alloc=5 (w 31055)
22:48:44     INFO -  MultiWriterQueue<int, 10, Locking_None> threads=16w+1r loops/thread=131072 pushes=pops=2097152 duration=1.415476s pushes/s=1481587.986694 buffers: live=1 (w 26341) reusable=6099 (w 6099) alloc=6100 (w 26341)
22:48:45     INFO -  MultiWriterQueue<int, 10, Locking_None> threads=32w+1r loops/thread=65536 pushes=pops=2097152 duration=1.590640s pushes/s=1318432.606615 buffers: live=1 (w 35239) reusable=13794 (w 13794) alloc=13795 (w 35239)
22:53:45    ERROR -  gtest TEST-UNEXPECTED-FAIL | gtest | timed out after 300 seconds without output

Comment 2

[Intermittent Failures Robot]

4 failures in 1668 pushes (0.002 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:
* mozilla-inbound: 1
* autoland: 2
* mozilla-central: 1

Platform breakdown:
* linux32: 1
* osx-10-10: 1
* linux64-qr: 1
* windows7-32: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1517633&startday=2018-12-31&endday=2019-01-06&tree=all