Closed Bug 1267480 Opened 9 years ago Closed 8 years ago

Intermittent browser/components/preferences/in-content/tests/browser_security.js | This test exceeded the timeout threshold. It should be rewritten or split up.

Categories

(Firefox :: Settings UI, defect, P3)

48 Branch
defect

Tracking

()

RESOLVED FIXED
Firefox 55
Tracking Status
firefox48 --- affected
firefox49 --- affected

People

(Reporter: KWierso, Assigned: jaws)

References

Details

(Keywords: intermittent-failure, Whiteboard: [stockwell fixed])

Attachments

(1 file, 1 obsolete file)

Bulk assigning P3 to all open intermittent bugs without a priority set in Firefox components per bug 1298978.
Priority: -- → P3
browser/components/preferences/in-content-old/tests/browser_security.js
Summary: Intermittent browser_security.js | This test exceeded the timeout threshold. It should be rewritten or split up. → Intermittent browser/components/preferences/in-content-old/tests/browser_security.js | This test exceeded the timeout threshold. It should be rewritten or split up.
Whiteboard: [stockwell needswork]
doing many retriggers:
https://treeherder.mozilla.org/#/jobs?repo=mozilla-inbound&filter-searchStr=debug%20browser-chrome-e10s-4%20linux&tochange=f2bc0c02b50c5417f6a7f10345e22326df28fee4&fromchange=c46c8e2804c2a64e8436290c032a3e8bf32b63b5&selectedJob=86482870

typically we run in 50-55 seconds, timing out around 110 seconds.

A log file https://public-artifacts.taskcluster.net/SlU_K-LgQ_6jGGnl2jWJcw/0/public/logs/live_backing.log, yields:
[task 2017-03-26T06:32:40.968509Z] 06:32:40     INFO - TEST-INFO | started process screentopng
[task 2017-03-26T06:32:44.461082Z] 06:32:44     INFO - TEST-INFO | screentopng: exit 0
[task 2017-03-26T06:32:44.471440Z] 06:32:44     INFO - Buffered messages logged at 06:30:46
[task 2017-03-26T06:32:44.473546Z] 06:32:44     INFO - Entering test bound 
[task 2017-03-26T06:32:44.477172Z] 06:32:44     INFO - Buffered messages logged at 06:30:49
[task 2017-03-26T06:32:44.481261Z] 06:32:44     INFO - TEST-PASS | browser/components/preferences/in-content-old/tests/browser_security.js | safebrowsing preference is initialized correctly - 
[task 2017-03-26T06:32:44.491976Z] 06:32:44     INFO - TEST-PASS | browser/components/preferences/in-content-old/tests/browser_security.js | block downloads checkbox is set correctly - 
[task 2017-03-26T06:32:44.494248Z] 06:32:44     INFO - TEST-PASS | browser/components/preferences/in-content-old/tests/browser_security.js | block uncommon checkbox is set correctly - 
[task 2017-03-26T06:32:44.497986Z] 06:32:44     INFO - Buffered messages logged at 06:30:50
[task 2017-03-26T06:32:44.503479Z] 06:32:44     INFO - TEST-PASS | browser/components/preferences/in-content-old/tests/browser_security.js | safebrowsing.enabled is set correctly - 
[task 2017-03-26T06:32:44.506270Z] 06:32:44     INFO - TEST-PASS | browser/components/preferences/in-content-old/tests/browser_security.js | safebrowsing.malware.enabled is set correctly - 
[task 2017-03-26T06:32:44.517081Z] 06:32:44     INFO - TEST-PASS | browser/components/preferences/in-content-old/tests/browser_security.js | block downloads checkbox is set correctly - 
[task 2017-03-26T06:32:44.528381Z] 06:32:44     INFO - TEST-PASS | browser/components/preferences/in-content-old/tests/browser_security.js | block uncommon checkbox is set correctly - 
[task 2017-03-26T06:32:44.536319Z] 06:32:44     INFO - Buffered messages logged at 06:30:54
[task 2017-03-26T06:32:44.538845Z] 06:32:44     INFO - TEST-PASS | browser/components/preferences/in-content-old/tests/browser_security.js | safebrowsing preference is initialized correctly - 
[task 2017-03-26T06:32:44.541299Z] 06:32:44     INFO - TEST-PASS | browser/components/preferences/in-content-old/tests/browser_security.js | block downloads checkbox is set correctly - 
[task 2017-03-26T06:32:44.544671Z] 06:32:44     INFO - TEST-PASS | browser/components/preferences/in-content-old/tests/browser_security.js | block uncommon checkbox is set correctly - 
[task 2017-03-26T06:32:44.555406Z] 06:32:44     INFO - TEST-PASS | browser/components/preferences/in-content-old/tests/browser_security.js | safebrowsing.enabled is set correctly - 
[task 2017-03-26T06:32:44.557763Z] 06:32:44     INFO - TEST-PASS | browser/components/preferences/in-content-old/tests/browser_security.js | safebrowsing.malware.enabled is set correctly - 
[task 2017-03-26T06:32:44.564811Z] 06:32:44     INFO - TEST-PASS | browser/components/preferences/in-content-old/tests/browser_security.js | block downloads checkbox is set correctly - 
[task 2017-03-26T06:32:44.569203Z] 06:32:44     INFO - TEST-PASS | browser/components/preferences/in-content-old/tests/browser_security.js | block uncommon checkbox is set correctly - 
[task 2017-03-26T06:32:44.573688Z] 06:32:44     INFO - Buffered messages logged at 06:30:59
[task 2017-03-26T06:32:44.578529Z] 06:32:44     INFO - TEST-PASS | browser/components/preferences/in-content-old/tests/browser_security.js | safebrowsing preference is initialized correctly - 
[task 2017-03-26T06:32:44.588904Z] 06:32:44     INFO - TEST-PASS | browser/components/preferences/in-content-old/tests/browser_security.js | block downloads checkbox is set correctly - 
[task 2017-03-26T06:32:44.595099Z] 06:32:44     INFO - TEST-PASS | browser/components/preferences/in-content-old/tests/browser_security.js | block uncommon checkbox is set correctly - 
[task 2017-03-26T06:32:44.602188Z] 06:32:44     INFO - TEST-PASS | browser/components/preferences/in-content-old/tests/browser_security.js | safebrowsing.enabled is set correctly - 
[task 2017-03-26T06:32:44.608672Z] 06:32:44     INFO - TEST-PASS | browser/components/preferences/in-content-old/tests/browser_security.js | safebrowsing.malware.enabled is set correctly - 
[task 2017-03-26T06:32:44.611088Z] 06:32:44     INFO - TEST-PASS | browser/components/preferences/in-content-old/tests/browser_security.js | block downloads checkbox is set correctly - 
[task 2017-03-26T06:32:44.621176Z] 06:32:44     INFO - TEST-PASS | browser/components/preferences/in-content-old/tests/browser_security.js | block uncommon checkbox is set correctly - 
[task 2017-03-26T06:32:44.629970Z] 06:32:44     INFO - Buffered messages logged at 06:31:03
[task 2017-03-26T06:32:44.632364Z] 06:32:44     INFO - TEST-PASS | browser/components/preferences/in-content-old/tests/browser_security.js | safebrowsing preference is initialized correctly - 
[task 2017-03-26T06:32:44.635266Z] 06:32:44     INFO - TEST-PASS | browser/components/preferences/in-content-old/tests/browser_security.js | block downloads checkbox is set correctly - 
[task 2017-03-26T06:32:44.641231Z] 06:32:44     INFO - TEST-PASS | browser/components/preferences/in-content-old/tests/browser_security.js | block uncommon checkbox is set correctly - 
[task 2017-03-26T06:32:44.645147Z] 06:32:44     INFO - Buffered messages logged at 06:31:04
[task 2017-03-26T06:32:44.656127Z] 06:32:44     INFO - TEST-PASS | browser/components/preferences/in-content-old/tests/browser_security.js | safebrowsing.enabled is set correctly - 
[task 2017-03-26T06:32:44.660569Z] 06:32:44     INFO - TEST-PASS | browser/components/preferences/in-content-old/tests/browser_security.js | safebrowsing.malware.enabled is set correctly - 
[task 2017-03-26T06:32:44.662998Z] 06:32:44     INFO - TEST-PASS | browser/components/preferences/in-content-old/tests/browser_security.js | block downloads checkbox is set correctly - 
[task 2017-03-26T06:32:44.670974Z] 06:32:44     INFO - TEST-PASS | browser/components/preferences/in-content-old/tests/browser_security.js | block uncommon checkbox is set correctly - 
[task 2017-03-26T06:32:44.675544Z] 06:32:44     INFO - Leaving test bound 
[task 2017-03-26T06:32:44.677673Z] 06:32:44     INFO - Entering test bound 
[task 2017-03-26T06:32:44.684906Z] 06:32:44     INFO - Buffered messages logged at 06:31:12
[task 2017-03-26T06:32:44.687064Z] 06:32:44     INFO - TEST-PASS | browser/components/preferences/in-content-old/tests/browser_security.js | downloads preference is initialized correctly - 
[task 2017-03-26T06:32:44.689455Z] 06:32:44     INFO - TEST-PASS | browser/components/preferences/in-content-old/tests/browser_security.js | block uncommon checkbox is set correctly - 
[task 2017-03-26T06:32:44.700276Z] 06:32:44     INFO - TEST-PASS | browser/components/preferences/in-content-old/tests/browser_security.js | safebrowsing.downloads preference is set correctly - 
[task 2017-03-26T06:32:44.703189Z] 06:32:44     INFO - TEST-PASS | browser/components/preferences/in-content-old/tests/browser_security.js | block uncommon checkbox is set correctly - 
[task 2017-03-26T06:32:44.712097Z] 06:32:44     INFO - Buffered messages logged at 06:31:27
[task 2017-03-26T06:32:44.720892Z] 06:32:44     INFO - TEST-PASS | browser/components/preferences/in-content-old/tests/browser_security.js | downloads preference is initialized correctly - 
[task 2017-03-26T06:32:44.724150Z] 06:32:44     INFO - TEST-PASS | browser/components/preferences/in-content-old/tests/browser_security.js | block uncommon checkbox is set correctly - 
[task 2017-03-26T06:32:44.736358Z] 06:32:44     INFO - TEST-PASS | browser/components/preferences/in-content-old/tests/browser_security.js | safebrowsing.downloads preference is set correctly - 
[task 2017-03-26T06:32:44.738676Z] 06:32:44     INFO - TEST-PASS | browser/components/preferences/in-content-old/tests/browser_security.js | block uncommon checkbox is set correctly - 
[task 2017-03-26T06:32:44.747419Z] 06:32:44     INFO - Buffered messages logged at 06:31:28
[task 2017-03-26T06:32:44.752249Z] 06:32:44     INFO - Leaving test bound 
[task 2017-03-26T06:32:44.761696Z] 06:32:44     INFO - Entering test bound 
[task 2017-03-26T06:32:44.763620Z] 06:32:44     INFO - Buffered messages logged at 06:31:37
[task 2017-03-26T06:32:44.765901Z] 06:32:44     INFO - TEST-PASS | browser/components/preferences/in-content-old/tests/browser_security.js | unwanted/uncommon preference is initialized correctly - 
[task 2017-03-26T06:32:44.769391Z] 06:32:44     INFO - TEST-PASS | browser/components/preferences/in-content-old/tests/browser_security.js | block_potentially_unwanted is set correctly - 
[task 2017-03-26T06:32:44.781109Z] 06:32:44     INFO - TEST-PASS | browser/components/preferences/in-content-old/tests/browser_security.js | block_uncommon is set correctly - 
[task 2017-03-26T06:32:44.788117Z] 06:32:44     INFO - TEST-PASS | browser/components/preferences/in-content-old/tests/browser_security.js | malware table doesn't include goog-unwanted-shavar - 
[task 2017-03-26T06:32:44.793110Z] 06:32:44     INFO - TEST-PASS | browser/components/preferences/in-content-old/tests/browser_security.js | malware table doesn't include test-unwanted-simple - 
[task 2017-03-26T06:32:44.801540Z] 06:32:44     INFO - TEST-PASS | browser/components/preferences/in-content-old/tests/browser_security.js | malware table has been sorted - ["goog-malware-proto","goog-malware-shavar","goog-unwanted-proto","test-malware-simple"] deepEqual ["goog-malware-proto","goog-malware-shavar","goog-unwanted-proto","test-malware-simple"] - 
[task 2017-03-26T06:32:44.805516Z] 06:32:44     INFO - Buffered messages logged at 06:31:45
[task 2017-03-26T06:32:44.807879Z] 06:32:44     INFO - TEST-PASS | browser/components/preferences/in-content-old/tests/browser_security.js | unwanted/uncommon preference is initialized correctly - 
[task 2017-03-26T06:32:44.821222Z] 06:32:44     INFO - TEST-PASS | browser/components/preferences/in-content-old/tests/browser_security.js | block_potentially_unwanted is set correctly - 
[task 2017-03-26T06:32:44.831277Z] 06:32:44     INFO - TEST-PASS | browser/components/preferences/in-content-old/tests/browser_security.js | block_uncommon is set correctly - 
[task 2017-03-26T06:32:44.833595Z] 06:32:44     INFO - TEST-PASS | browser/components/preferences/in-content-old/tests/browser_security.js | malware table doesn't include goog-unwanted-shavar - 
[task 2017-03-26T06:32:44.835949Z] 06:32:44     INFO - TEST-PASS | browser/components/preferences/in-content-old/tests/browser_security.js | malware table doesn't include test-unwanted-simple - 
[task 2017-03-26T06:32:44.841348Z] 06:32:44     INFO - TEST-PASS | browser/components/preferences/in-content-old/tests/browser_security.js | malware table has been sorted - ["goog-malware-proto","goog-malware-shavar","goog-unwanted-proto","goog-unwanted-shavar","test-malware-simple","test-unwanted-si deepEqual ["goog-malware-proto","goog-malware-shavar","goog-unwanted-proto","goog-unwanted-shavar","test-malware-simple","test-unwanted-si - 
[task 2017-03-26T06:32:44.848674Z] 06:32:44     INFO - Buffered messages logged at 06:31:55
[task 2017-03-26T06:32:44.852345Z] 06:32:44     INFO - TEST-PASS | browser/components/preferences/in-content-old/tests/browser_security.js | unwanted/uncommon preference is initialized correctly - 
[task 2017-03-26T06:32:44.854640Z] 06:32:44     INFO - TEST-PASS | browser/components/preferences/in-content-old/tests/browser_security.js | block_potentially_unwanted is set correctly - 
[task 2017-03-26T06:32:44.867535Z] 06:32:44     INFO - TEST-PASS | browser/components/preferences/in-content-old/tests/browser_security.js | block_uncommon is set correctly - 
[task 2017-03-26T06:32:44.870373Z] 06:32:44     INFO - TEST-PASS | browser/components/preferences/in-content-old/tests/browser_security.js | malware table doesn't include goog-unwanted-shavar - 
[task 2017-03-26T06:32:44.874073Z] 06:32:44     INFO - TEST-PASS | browser/components/preferences/in-content-old/tests/browser_security.js | malware table doesn't include test-unwanted-simple - 
[task 2017-03-26T06:32:44.878160Z] 06:32:44     INFO - TEST-PASS | browser/components/preferences/in-content-old/tests/browser_security.js | malware table has been sorted - ["goog-malware-proto","goog-malware-shavar","goog-unwanted-proto","goog-unwanted-shavar","test-malware-simple","test-unwanted-si deepEqual ["goog-malware-proto","goog-malware-shavar","goog-unwanted-proto","goog-unwanted-shavar","test-malware-simple","test-unwanted-si - 
[task 2017-03-26T06:32:44.883270Z] 06:32:44     INFO - Buffered messages logged at 06:32:36
[task 2017-03-26T06:32:44.888876Z] 06:32:44     INFO - TEST-PASS | browser/components/preferences/in-content-old/tests/browser_security.js | unwanted/uncommon preference is initialized correctly - 
[task 2017-03-26T06:32:44.891448Z] 06:32:44     INFO - TEST-PASS | browser/components/preferences/in-content-old/tests/browser_security.js | block_potentially_unwanted is set correctly - 
[task 2017-03-26T06:32:44.894572Z] 06:32:44     INFO - TEST-PASS | browser/components/preferences/in-content-old/tests/browser_security.js | block_uncommon is set correctly - 
[task 2017-03-26T06:32:44.904904Z] 06:32:44     INFO - TEST-PASS | browser/components/preferences/in-content-old/tests/browser_security.js | malware table doesn't include goog-unwanted-shavar - 
[task 2017-03-26T06:32:44.916023Z] 06:32:44     INFO - TEST-PASS | browser/components/preferences/in-content-old/tests/browser_security.js | malware table doesn't include test-unwanted-simple - 
[task 2017-03-26T06:32:44.918873Z] 06:32:44     INFO - TEST-PASS | browser/components/preferences/in-content-old/tests/browser_security.js | malware table has been sorted - ["goog-malware-proto","goog-malware-shavar","goog-unwanted-proto","goog-unwanted-shavar","test-malware-simple","test-unwanted-si deepEqual ["goog-malware-proto","goog-malware-shavar","goog-unwanted-proto","goog-unwanted-shavar","test-malware-simple","test-unwanted-si - 
[task 2017-03-26T06:32:44.928179Z] 06:32:44     INFO - Buffered messages logged at 06:32:38
[task 2017-03-26T06:32:44.930465Z] 06:32:44     INFO - Leaving test bound 
[task 2017-03-26T06:32:44.933664Z] 06:32:44     INFO - Buffered messages finished
[task 2017-03-26T06:32:44.948684Z] 06:32:44     INFO - TEST-UNEXPECTED-FAIL | browser/components/preferences/in-content-old/tests/browser_security.js | This test exceeded the timeout threshold. It should be rewritten or split up. If that's not possible, use requestLongerTimeout(N), but only as a last resort. - 
[task 2017-03-26T06:32:44.958843Z] 06:32:44     INFO - GECKO(2018) | MEMORY STAT | vsize 1021MB | residentFast 274MB | heapAllocated 96MB
[task 2017-03-26T06:32:44.964748Z] 06:32:44     INFO - TEST-OK | browser/components/preferences/in-content-old/tests/browser_security.js | took 114380ms
ok, so the in-content-old was a single instance, it appears that all the instances are in-content, hmm
Summary: Intermittent browser/components/preferences/in-content-old/tests/browser_security.js | This test exceeded the timeout threshold. It should be rewritten or split up. → Intermittent browser/components/preferences/in-content/tests/browser_security.js | This test exceeded the timeout threshold. It should be rewritten or split up.
ok, this typically runs in 75-80 seconds but it timing out at 90 seconds!  That means we are close.

here is a log (https://public-artifacts.taskcluster.net/a_gACThsRiOd-eWYq72JbQ/0/public/logs/live_backing.log ) output from the test:
[task 2017-03-30T03:15:16.627782Z] 03:15:16     INFO - Not taking screenshot here: see the one that was previously logged
[task 2017-03-30T03:15:16.630843Z] 03:15:16     INFO - Buffered messages logged at 03:13:44
[task 2017-03-30T03:15:16.631166Z] 03:15:16     INFO - Entering test bound 
[task 2017-03-30T03:15:16.632963Z] 03:15:16     INFO - Buffered messages logged at 03:13:55
[task 2017-03-30T03:15:16.634981Z] 03:15:16     INFO - TEST-PASS | browser/components/preferences/in-content/tests/browser_security.js | safebrowsing preference is initialized correctly - 
[task 2017-03-30T03:15:16.638105Z] 03:15:16     INFO - TEST-PASS | browser/components/preferences/in-content/tests/browser_security.js | block downloads checkbox is set correctly - 
[task 2017-03-30T03:15:16.640213Z] 03:15:16     INFO - TEST-PASS | browser/components/preferences/in-content/tests/browser_security.js | block uncommon checkbox is set correctly - 
[task 2017-03-30T03:15:16.646495Z] 03:15:16     INFO - TEST-PASS | browser/components/preferences/in-content/tests/browser_security.js | safebrowsing.enabled is set correctly - 
[task 2017-03-30T03:15:16.653624Z] 03:15:16     INFO - TEST-PASS | browser/components/preferences/in-content/tests/browser_security.js | safebrowsing.malware.enabled is set correctly - 
[task 2017-03-30T03:15:16.655689Z] 03:15:16     INFO - TEST-PASS | browser/components/preferences/in-content/tests/browser_security.js | block downloads checkbox is set correctly - 
[task 2017-03-30T03:15:16.658439Z] 03:15:16     INFO - TEST-PASS | browser/components/preferences/in-content/tests/browser_security.js | block uncommon checkbox is set correctly - 
[task 2017-03-30T03:15:16.661340Z] 03:15:16     INFO - Buffered messages logged at 03:14:08
[task 2017-03-30T03:15:16.666525Z] 03:15:16     INFO - TEST-PASS | browser/components/preferences/in-content/tests/browser_security.js | safebrowsing preference is initialized correctly - 
[task 2017-03-30T03:15:16.670506Z] 03:15:16     INFO - TEST-PASS | browser/components/preferences/in-content/tests/browser_security.js | block downloads checkbox is set correctly - 
[task 2017-03-30T03:15:16.674043Z] 03:15:16     INFO - TEST-PASS | browser/components/preferences/in-content/tests/browser_security.js | block uncommon checkbox is set correctly - 
[task 2017-03-30T03:15:16.676652Z] 03:15:16     INFO - TEST-PASS | browser/components/preferences/in-content/tests/browser_security.js | safebrowsing.enabled is set correctly - 
[task 2017-03-30T03:15:16.679542Z] 03:15:16     INFO - TEST-PASS | browser/components/preferences/in-content/tests/browser_security.js | safebrowsing.malware.enabled is set correctly - 
[task 2017-03-30T03:15:16.681759Z] 03:15:16     INFO - TEST-PASS | browser/components/preferences/in-content/tests/browser_security.js | block downloads checkbox is set correctly - 
[task 2017-03-30T03:15:16.687649Z] 03:15:16     INFO - TEST-PASS | browser/components/preferences/in-content/tests/browser_security.js | block uncommon checkbox is set correctly - 
[task 2017-03-30T03:15:16.690391Z] 03:15:16     INFO - Buffered messages logged at 03:14:16
[task 2017-03-30T03:15:16.694615Z] 03:15:16     INFO - TEST-PASS | browser/components/preferences/in-content/tests/browser_security.js | safebrowsing preference is initialized correctly - 
[task 2017-03-30T03:15:16.696615Z] 03:15:16     INFO - TEST-PASS | browser/components/preferences/in-content/tests/browser_security.js | block downloads checkbox is set correctly - 
[task 2017-03-30T03:15:16.698558Z] 03:15:16     INFO - TEST-PASS | browser/components/preferences/in-content/tests/browser_security.js | block uncommon checkbox is set correctly - 
[task 2017-03-30T03:15:16.700586Z] 03:15:16     INFO - TEST-PASS | browser/components/preferences/in-content/tests/browser_security.js | safebrowsing.enabled is set correctly - 
[task 2017-03-30T03:15:16.703551Z] 03:15:16     INFO - TEST-PASS | browser/components/preferences/in-content/tests/browser_security.js | safebrowsing.malware.enabled is set correctly - 
[task 2017-03-30T03:15:16.705792Z] 03:15:16     INFO - TEST-PASS | browser/components/preferences/in-content/tests/browser_security.js | block downloads checkbox is set correctly - 
[task 2017-03-30T03:15:16.714887Z] 03:15:16     INFO - TEST-PASS | browser/components/preferences/in-content/tests/browser_security.js | block uncommon checkbox is set correctly - 
[task 2017-03-30T03:15:16.718666Z] 03:15:16     INFO - Buffered messages logged at 03:14:22
[task 2017-03-30T03:15:16.720863Z] 03:15:16     INFO - TEST-PASS | browser/components/preferences/in-content/tests/browser_security.js | safebrowsing preference is initialized correctly - 
[task 2017-03-30T03:15:16.723072Z] 03:15:16     INFO - TEST-PASS | browser/components/preferences/in-content/tests/browser_security.js | block downloads checkbox is set correctly - 
[task 2017-03-30T03:15:16.728148Z] 03:15:16     INFO - TEST-PASS | browser/components/preferences/in-content/tests/browser_security.js | block uncommon checkbox is set correctly - 
[task 2017-03-30T03:15:16.730263Z] 03:15:16     INFO - Buffered messages logged at 03:14:23
[task 2017-03-30T03:15:16.734823Z] 03:15:16     INFO - TEST-PASS | browser/components/preferences/in-content/tests/browser_security.js | safebrowsing.enabled is set correctly - 
[task 2017-03-30T03:15:16.737165Z] 03:15:16     INFO - TEST-PASS | browser/components/preferences/in-content/tests/browser_security.js | safebrowsing.malware.enabled is set correctly - 
[task 2017-03-30T03:15:16.739543Z] 03:15:16     INFO - TEST-PASS | browser/components/preferences/in-content/tests/browser_security.js | block downloads checkbox is set correctly - 
[task 2017-03-30T03:15:16.746874Z] 03:15:16     INFO - TEST-PASS | browser/components/preferences/in-content/tests/browser_security.js | block uncommon checkbox is set correctly - 
[task 2017-03-30T03:15:16.750552Z] 03:15:16     INFO - Buffered messages logged at 03:14:24
[task 2017-03-30T03:15:16.752651Z] 03:15:16     INFO - Leaving test bound 
[task 2017-03-30T03:15:16.758387Z] 03:15:16     INFO - Entering test bound 
[task 2017-03-30T03:15:16.760237Z] 03:15:16     INFO - Buffered messages logged at 03:14:30
[task 2017-03-30T03:15:16.762247Z] 03:15:16     INFO - TEST-PASS | browser/components/preferences/in-content/tests/browser_security.js | downloads preference is initialized correctly - 
[task 2017-03-30T03:15:16.764177Z] 03:15:16     INFO - TEST-PASS | browser/components/preferences/in-content/tests/browser_security.js | block uncommon checkbox is set correctly - 
[task 2017-03-30T03:15:16.766337Z] 03:15:16     INFO - TEST-PASS | browser/components/preferences/in-content/tests/browser_security.js | safebrowsing.downloads preference is set correctly - 
[task 2017-03-30T03:15:16.768293Z] 03:15:16     INFO - TEST-PASS | browser/components/preferences/in-content/tests/browser_security.js | block uncommon checkbox is set correctly - 
[task 2017-03-30T03:15:16.770072Z] 03:15:16     INFO - Buffered messages logged at 03:14:37
[task 2017-03-30T03:15:16.774596Z] 03:15:16     INFO - TEST-PASS | browser/components/preferences/in-content/tests/browser_security.js | downloads preference is initialized correctly - 
[task 2017-03-30T03:15:16.776637Z] 03:15:16     INFO - TEST-PASS | browser/components/preferences/in-content/tests/browser_security.js | block uncommon checkbox is set correctly - 
[task 2017-03-30T03:15:16.780561Z] 03:15:16     INFO - TEST-PASS | browser/components/preferences/in-content/tests/browser_security.js | safebrowsing.downloads preference is set correctly - 
[task 2017-03-30T03:15:16.786593Z] 03:15:16     INFO - TEST-PASS | browser/components/preferences/in-content/tests/browser_security.js | block uncommon checkbox is set correctly - 
[task 2017-03-30T03:15:16.788475Z] 03:15:16     INFO - Buffered messages logged at 03:14:38
[task 2017-03-30T03:15:16.790416Z] 03:15:16     INFO - Leaving test bound 
[task 2017-03-30T03:15:16.792696Z] 03:15:16     INFO - Entering test bound 
[task 2017-03-30T03:15:16.796636Z] 03:15:16     INFO - Buffered messages logged at 03:14:48
[task 2017-03-30T03:15:16.800270Z] 03:15:16     INFO - TEST-PASS | browser/components/preferences/in-content/tests/browser_security.js | unwanted/uncommon preference is initialized correctly - 
[task 2017-03-30T03:15:16.802560Z] 03:15:16     INFO - TEST-PASS | browser/components/preferences/in-content/tests/browser_security.js | block_potentially_unwanted is set correctly - 
[task 2017-03-30T03:15:16.804824Z] 03:15:16     INFO - TEST-PASS | browser/components/preferences/in-content/tests/browser_security.js | block_uncommon is set correctly - 
[task 2017-03-30T03:15:16.810824Z] 03:15:16     INFO - TEST-PASS | browser/components/preferences/in-content/tests/browser_security.js | malware table doesn't include goog-unwanted-shavar - 
[task 2017-03-30T03:15:16.815893Z] 03:15:16     INFO - TEST-PASS | browser/components/preferences/in-content/tests/browser_security.js | malware table doesn't include test-unwanted-simple - 
[task 2017-03-30T03:15:16.818241Z] 03:15:16     INFO - TEST-PASS | browser/components/preferences/in-content/tests/browser_security.js | malware table has been sorted - ["goog-malware-proto","goog-malware-shavar","goog-unwanted-proto","test-malware-simple"] deepEqual ["goog-malware-proto","goog-malware-shavar","goog-unwanted-proto","test-malware-simple"] - 
[task 2017-03-30T03:15:16.822821Z] 03:15:16     INFO - Buffered messages logged at 03:14:58
[task 2017-03-30T03:15:16.824983Z] 03:15:16     INFO - TEST-PASS | browser/components/preferences/in-content/tests/browser_security.js | unwanted/uncommon preference is initialized correctly - 
[task 2017-03-30T03:15:16.828717Z] 03:15:16     INFO - Buffered messages logged at 03:14:59
[task 2017-03-30T03:15:16.830657Z] 03:15:16     INFO - TEST-PASS | browser/components/preferences/in-content/tests/browser_security.js | block_potentially_unwanted is set correctly - 
[task 2017-03-30T03:15:16.838109Z] 03:15:16     INFO - TEST-PASS | browser/components/preferences/in-content/tests/browser_security.js | block_uncommon is set correctly - 
[task 2017-03-30T03:15:16.841888Z] 03:15:16     INFO - TEST-PASS | browser/components/preferences/in-content/tests/browser_security.js | malware table doesn't include goog-unwanted-shavar - 
[task 2017-03-30T03:15:16.846716Z] 03:15:16     INFO - TEST-PASS | browser/components/preferences/in-content/tests/browser_security.js | malware table doesn't include test-unwanted-simple - 
[task 2017-03-30T03:15:16.849269Z] 03:15:16     INFO - TEST-PASS | browser/components/preferences/in-content/tests/browser_security.js | malware table has been sorted - ["goog-malware-proto","goog-malware-shavar","goog-unwanted-proto","goog-unwanted-shavar","test-malware-simple","test-unwanted-si deepEqual ["goog-malware-proto","goog-malware-shavar","goog-unwanted-proto","goog-unwanted-shavar","test-malware-simple","test-unwanted-si - 
[task 2017-03-30T03:15:16.855172Z] 03:15:16     INFO - Buffered messages logged at 03:15:07
[task 2017-03-30T03:15:16.857612Z] 03:15:16     INFO - TEST-PASS | browser/components/preferences/in-content/tests/browser_security.js | unwanted/uncommon preference is initialized correctly - 
[task 2017-03-30T03:15:16.862958Z] 03:15:16     INFO - TEST-PASS | browser/components/preferences/in-content/tests/browser_security.js | block_potentially_unwanted is set correctly - 
[task 2017-03-30T03:15:16.866731Z] 03:15:16     INFO - TEST-PASS | browser/components/preferences/in-content/tests/browser_security.js | block_uncommon is set correctly - 
[task 2017-03-30T03:15:16.868894Z] 03:15:16     INFO - TEST-PASS | browser/components/preferences/in-content/tests/browser_security.js | malware table doesn't include goog-unwanted-shavar - 
[task 2017-03-30T03:15:16.871177Z] 03:15:16     INFO - TEST-PASS | browser/components/preferences/in-content/tests/browser_security.js | malware table doesn't include test-unwanted-simple - 
[task 2017-03-30T03:15:16.873917Z] 03:15:16     INFO - TEST-PASS | browser/components/preferences/in-content/tests/browser_security.js | malware table has been sorted - ["goog-malware-proto","goog-malware-shavar","goog-unwanted-proto","goog-unwanted-shavar","test-malware-simple","test-unwanted-si deepEqual ["goog-malware-proto","goog-malware-shavar","goog-unwanted-proto","goog-unwanted-shavar","test-malware-simpl
e","test-unwanted-si - 
[task 2017-03-30T03:15:16.877437Z] 03:15:16     INFO - Buffered messages logged at 03:15:15
[task 2017-03-30T03:15:16.879821Z] 03:15:16     INFO - TEST-PASS | browser/components/preferences/in-content/tests/browser_security.js | unwanted/uncommon preference is initialized correctly - 
[task 2017-03-30T03:15:16.882102Z] 03:15:16     INFO - TEST-PASS | browser/components/preferences/in-content/tests/browser_security.js | block_potentially_unwanted is set correctly - 
[task 2017-03-30T03:15:16.890928Z] 03:15:16     INFO - TEST-PASS | browser/components/preferences/in-content/tests/browser_security.js | block_uncommon is set correctly - 
[task 2017-03-30T03:15:16.893880Z] 03:15:16     INFO - TEST-PASS | browser/components/preferences/in-content/tests/browser_security.js | malware table doesn't include goog-unwanted-shavar - 
[task 2017-03-30T03:15:16.898037Z] 03:15:16     INFO - TEST-PASS | browser/components/preferences/in-content/tests/browser_security.js | malware table doesn't include test-unwanted-simple - 
[task 2017-03-30T03:15:16.900776Z] 03:15:16     INFO - TEST-PASS | browser/components/preferences/in-content/tests/browser_security.js | malware table has been sorted - ["goog-malware-proto","goog-malware-shavar","goog-unwanted-proto","goog-unwanted-shavar","test-malware-simple","test-unwanted-si deepEqual ["goog-malware-proto","goog-malware-shavar","goog-unwanted-proto","goog-unwanted-shavar","test-malware-simple","test-unwanted-si - 
[task 2017-03-30T03:15:16.906942Z] 03:15:16     INFO - Leaving test bound 
[task 2017-03-30T03:15:16.913307Z] 03:15:16     INFO - Buffered messages finished
[task 2017-03-30T03:15:16.915830Z] 03:15:16     INFO - TEST-UNEXPECTED-FAIL | browser/components/preferences/in-content/tests/browser_security.js | This test exceeded the timeout threshold. It should be rewritten or split up. If that's not possible, use requestLongerTimeout(N), but only as a last resort. - 
[task 2017-03-30T03:15:16.918104Z] 03:15:16     INFO - GECKO(1786) | MEMORY STAT | vsize 1029MB | residentFast 339MB | heapAllocated 131MB
[task 2017-03-30T03:15:16.922232Z] 03:15:16     INFO - TEST-OK | browser/components/preferences/in-content/tests/browser_security.js | took 91866ms
given the failure, we hit 2 cycles of checkPrefs but never get anywhere on the 3rd call to it:
https://dxr.mozilla.org/mozilla-central/source/browser/components/preferences/in-content/tests/browser_security.js#131

I see this test was changed on the 29th per bug 1335907, so lets see if Zach or mconley would have ideas of what is going on?
Blocks: 1335907
Flags: needinfo?(herrickz)
Test durations for browser/components/preferences/in-content/tests/browser_security.js on mozilla-central,mozilla-inbound,autoland between 2017-03-20 and 2017-03-27
linux32/debug-chunked:          47.14 s (23.04 s - 75.90 s over 472 runs)
linux32/debug-e10s:             54.09 s (35.51 s - 75.90 s over 320 runs)
linux64/debug-chunked:          46.64 s (23.93 s - 75.12 s over 440 runs)
linux64/debug-e10s:             52.84 s (36.11 s - 75.12 s over 291 runs)

Test durations for browser/components/preferences/in-content/tests/browser_security.js on mozilla-central,mozilla-inbound,autoland between 2017-03-30 and 2017-04-04
linux32/debug-chunked:          68.16 s (25.56 s - 93.72 s over 135 runs)
linux32/debug-e10s:             78.47 s (36.65 s - 93.72 s over 66 runs)
linux64/debug-chunked:          68.65 s (23.49 s - 91.40 s over 198 runs)
linux64/debug-e10s:             78.20 s (48.00 s - 91.40 s over 111 runs)
The failures here are on debug builds and the privacy (nee security) pane has a lot more content so it would make sense that it is slower to load on a debug build. This test just needs splitting up.
Flags: needinfo?(herrickz)
thanks :jaws, that makes sense- maybe Zach could do that for both in-content and in-content-old tests :)
I've got a patch on the way.
Assignee: nobody → jaws
Status: NEW → ASSIGNED
Comment on attachment 8854546 [details]
Bug 1267480 - Split up browser_security.js due to the test timing out.

https://reviewboard.mozilla.org/r/126504/#review129086
Attachment #8854546 - Flags: review?(gijskruitbosch+bugs) → review+
Pushed by jwein@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/28f8a3519d73
Split up browser_security.js due to the test timing out. r=Gijs
sorry had to back this out for mochitest bc6 perma-failing like https://treeherder.mozilla.org/logviewer.html#?job_id=88750338&repo=autoland&lineNumber=5422

https://hg.mozilla.org/integration/autoland/rev/a0d2eafc208f
Flags: needinfo?(jaws)
odd, the resistfingerprinting tests are new as of 6 days ago, but what is more interesting is before this patch they ran in chunk 1 and with this patch they run in chunk 6.

here are the old test dirs in chunk 1:
15:27:03     INFO -  dir: accessible/tests/browser/e10s
15:27:33     INFO -  dir: browser/base/content/test/captivePortal
15:28:02     INFO -  dir: browser/base/content/test/pageinfo
15:28:15     INFO -  dir: browser/base/content/test/webextensions
15:29:01     INFO -  dir: browser/components/customizableui/test
15:31:23     INFO -  dir: browser/components/preferences/in-content/tests
15:33:27     INFO -  dir: browser/components/preferences/in-content-old/tests
15:34:58     INFO -  dir: browser/components/resistfingerprinting/test/browser

here are the test dirs in chunk 6:
19:38:32     INFO -  dir: browser/base/content/test/plugins
19:39:25     INFO -  dir: browser/base/content/test/tabcrashed
19:39:50     INFO -  dir: browser/base/content/test/urlbar
19:41:39     INFO -  dir: browser/base/content/test/webextensions
19:42:25     INFO -  dir: browser/components/extensions/test/browser
19:47:13     INFO -  dir: browser/components/places/tests/browser
19:47:57     INFO -  dir: browser/components/preferences/in-content-old/tests
19:49:25     INFO -  dir: browser/components/resistfingerprinting/test/browser

as this change added 4 new tests (2 to in-content and 2 to in-content-old) it shifted the chunking.  What is confusing is that we stop the browser between directories and generate a fresh profile.  There must be some type of leftover state between runs.  Does anyone have ideas of what state could be left over between browser sessions?
Tim, what do you think is going on here?
Flags: needinfo?(tihuang)
The difference that I see between those two chunks are that:

--- accessible/tests/browser/e10s
--- browser/base/content/test/captivePortal
--- browser/base/content/test/pageinfo
--- browser/components/customizableui/test
--- browser/components/preferences/in-content/tests
+++ browser/base/content/test/plugins
+++ browser/base/content/test/tabcrashed
+++ browser/base/content/test/urlbar
+++ browser/components/extensions/test/browser
+++ browser/components/places/tests/browser

I might be able to speed up the test without splitting it to separate files though.
Flags: needinfo?(jaws)
Attachment #8854546 - Attachment is obsolete: true
(In reply to Jared Wein [:jaws] (please needinfo? me) from comment #27)
> Tim, what do you think is going on here?

These tests will try to calculate the maximum available content size in the test code, and it reports a 900 on window height. However, the content window can still be resized to 1000 on height, which means the maximum available content height reports in gecko is different from the test code. This could happen if some UI element has been displayed in the content, like the crash report UI. So, maybe certain test cases leave a crash report and affect these tests? But, will this happen if every separate folder uses a distinct profile?
Flags: needinfo?(tihuang)
is it possible that crashes are stored in the users profile on the operating system at all and not only in the firefox profile folder?
(In reply to Joel Maher ( :jmaher) from comment #31)
> is it possible that crashes are stored in the users profile on the operating
> system at all and not only in the firefox profile folder?

Yes, they get stored outside the profile. This might explain the problem here.
Comment on attachment 8855122 [details]
Bug 1267480 - Only open the preferences once during the test run and reload it for subsequent tests to improve the speed of the browser_security.js test.

https://reviewboard.mozilla.org/r/127006/#review129862

r=me but I'm not convinced this will fix the issue. Please use leave-open and let's see if we can figure out the crash report stuff.

Really, IMO we should assert at the end of every test file that no new content-crash reports have appeared, and if they did we should fail *that* test (barring some annotation in the test manifest .ini, so we can have tests that test our crashreporting stuff), and remove them, so we don't run into this stuff.

::: browser/components/preferences/in-content-old/tests/browser_security.js:19
(Diff revision 1)
>    originals.forEach(([pref, val]) => Services.prefs.setBoolPref(pref, val))
>    Services.prefs.setCharPref("urlclassifier.malwareTable", originalMalwareTable);
>  });
>  
> +add_task(function* setup() {
> +  yield openPreferencesViaOpenPreferencesAPI("security", undefined, { leaveOpen: true });

Please add a comment here to explain what we're doing.
Attachment #8855122 - Flags: review?(gijskruitbosch+bugs) → review+
I filed bug 1354042 to discuss removing crash artifacts.
(In reply to :Gijs from comment #33)
> Comment on attachment 8855122 [details]
> Bug 1267480 - Only open the preferences once during the test run and reload
> it for subsequent tests to improve the speed of the browser_security.js test.
> 
> https://reviewboard.mozilla.org/r/127006/#review129862
> 
> r=me but I'm not convinced this will fix the issue.

Well, as far as timeouts go it shaved between 5-10s off of the test run on an optimized build so I imagine it will help a good deal on a debug build.
Pushed by jwein@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/476e7a2693ba
Only open the preferences once during the test run and reload it for subsequent tests to improve the speed of the browser_security.js test. r=Gijs
(In reply to Jared Wein [:jaws] (please needinfo? me) from comment #35)
> (In reply to :Gijs from comment #33)
> > Comment on attachment 8855122 [details]
> > Bug 1267480 - Only open the preferences once during the test run and reload
> > it for subsequent tests to improve the speed of the browser_security.js test.
> > 
> > https://reviewboard.mozilla.org/r/127006/#review129862
> > 
> > r=me but I'm not convinced this will fix the issue.
> 
> Well, as far as timeouts go it shaved between 5-10s off of the test run on
> an optimized build so I imagine it will help a good deal on a debug build.

Oh, right, for some reason I was thinking this was hitting the failures from comment #25/26, rather than getting backed out. I agree this will make things faster without altering chunking, which will help. Sorry!

We should ideally have a bug on file for fingerprint stuff causing crashes though. Joel, can you investigate what was crashing there, or redirect to someone who can? Thanks!
Flags: needinfo?(jmaher)
I think the key here is to figure out which specific test is leaving a crash report (or some other artifact) around on the operating system.  It is probably just random luck that the finterprint tests were failing.

we can follow up in https://bugzilla.mozilla.org/show_bug.cgi?id=1354042#c6, that seems like the next logical step.
Flags: needinfo?(jmaher)
https://hg.mozilla.org/mozilla-central/rev/476e7a2693ba
I'm going to remove the leave-open here since bug 1354042 has been filed.
Status: ASSIGNED → RESOLVED
Closed: 8 years ago
Keywords: leave-open
Resolution: --- → FIXED
Target Milestone: --- → Firefox 55
Whiteboard: [stockwell needswork] → [stockwell fixed]
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: