Closed Bug 1439979 Opened 6 years ago Closed 4 years ago

Intermittent Talos [taskcluster:error] Task aborted - max run time exceeded

Categories

(Testing :: Talos, defect, P2)

Product:
Testing
Component:
Talos
Type:
defect

Tracking

(Not tracked)

Status:
RESOLVED DUPLICATE of bug 1589796

People

(Reporter: RaulG, Assigned: igoldan)

References

Details

(Keywords: intermittent-failure, regression) 

https://treeherder.mozilla.org/#/jobs?repo=mozilla-inbound&revision=1162b0f53b85870409c6ffcf9075e43321da5588&filter-resultStatus=retry&filter-resultStatus=usercancel&filter-resultStatus=runnable&filter-resultStatus=testfailed&filter-resultStatus=busted&filter-resultStatus=exception&filter-resultStatus=success&filter-resultStatus=superseded&filter-resultStatus=pending&filter-resultStatus=running&group_state=expanded&selectedJob=163445983&filter-searchStr=tp6

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

06:49:02     INFO -  For request https://www.google.com/textinputassistant/tia.png found exact replay match
06:49:02     INFO -  127.0.0.1:49232: GET https://www.google.com/textinputassistant/tia.png HTTP/2.0
06:49:02     INFO -  [replay]               << 200  258b
06:49:02     INFO -  For request https://apis.google.com/_/scs/abc-static/_/js/k=gapi.gapi.en.73fNb0waPA0.O/m=gapi_iframes,googleapis_client,plusone/rt=j/sv=1/d=1/ed=1/rs=AHpOoo-_k7tqnIuPk4-ENH1q2yvjBHndsA/cb=gapi.loaded_0 found exact replay match
06:49:02     INFO -  127.0.0.1:49234: GET https://apis.google.com/_/scs/abc-static/_/js/k=gapi.gapi.en.73fNb0waPA0.O/m=gapi_iframes,googleapis_client,plusone/rt=j/sv=1/d=1/ed=1/rs=AHpOoo-_k7tqnIuPk4-ENH1q2yvjBHndsA/cb=gapi.loaded_0 HTTP/2.0
06:49:02     INFO -  [replay]               << 200  41.42k
06:51:52     INFO -  127.0.0.1:49228: HTTP/2 connection terminated by client: error code: 0, last stream id: 0, additional data: None
06:51:52     INFO -  127.0.0.1:49226: HTTP/2 connection terminated by client: error code: 0, last stream id: 0, additional data: None
06:51:52     INFO -  127.0.0.1:49226: clientdisconnect
06:51:52     INFO -  127.0.0.1:49228: clientdisconnect
06:51:53     INFO -  127.0.0.1:49224: HTTP/2 connection terminated by client: error code: 0, last stream id: 0, additional data: None
06:51:53     INFO -  127.0.0.1:49232: HTTP/2 connection terminated by client: error code: 0, last stream id: 0, additional data: None
06:51:53     INFO -  127.0.0.1:49234: HTTP/2 connection terminated by client: error code: 0, last stream id: 0, additional data: None
06:51:53     INFO -  127.0.0.1:49230: HTTP/2 connection terminated by client: error code: 0, last stream id: 0, additional data: None
06:51:53     INFO -  127.0.0.1:49232: clientdisconnect
06:51:53     INFO -  127.0.0.1:49234: clientdisconnect
06:51:53     INFO -  127.0.0.1:49230: clientdisconnect
06:51:53     INFO -  127.0.0.1:49224: clientdisconnect
[taskcluster 2018-02-21T14:54:41.503Z] Aborting task - max run time exceeded!
[taskcluster 2018-02-21T14:54:41.506Z] Exit Code: -1
[taskcluster 2018-02-21T14:54:41.507Z] === Task Finished ===
Failing on tp6_youtube as well:
https://treeherder.mozilla.org/logviewer.html#?job_id=164100674&repo=autoland
22:48:18     INFO -  TEST-START | tp6_youtube
22:48:18     INFO -  Initialising browser for tp6_youtube test...
22:48:18     INFO -  Cloning profile located at /Users/cltbld/tasks/task_1519452736/build/tests/talos/talos/base_profile
22:48:18     INFO -  Installing Add-ons:
22:48:18     INFO -  ['/Users/cltbld/tasks/task_1519452736/build/tests/talos/talos/talos-powers', '/Users/cltbld/tasks/task_1519452736/build/tests/talos/talos/pageloader']
22:48:18     INFO -  Application command: /Users/cltbld/tasks/task_1519452736/build/application/Firefox Nightly.app/Contents/MacOS/firefox  http://localhost:49224/getInfo.html -foreground -profile /var/folders/xp/jb3pnj6j44d_dbqnvtl776bc00000w/T/tmp0vIHxl/profile
22:48:18     INFO -  TEST-INFO | started process 1711 (/Users/cltbld/tasks/task_1519452736/build/application/Firefox Nightly.app/Contents/MacOS/firefox  http://localhost:49224/getInfo.html -foreground)
[...............]
22:55:32     INFO -  127.0.0.1:49364: HTTP/2 connection terminated by client: error code: 0, last stream id: 0, additional data: None
22:55:32     INFO -  127.0.0.1:49364: clientdisconnect
22:56:15     INFO -  127.0.0.1:49366: HTTP/2 connection terminated by client: error code: 0, last stream id: 0, additional data: None
22:56:15     INFO -  127.0.0.1:49366: clientdisconnect
[taskcluster 2018-02-24T07:05:30.854Z] Aborting task - max run time exceeded!
[taskcluster 2018-02-24T07:05:30.858Z] Exit Code: -1
[taskcluster 2018-02-24T07:05:30.858Z] === Task Finished ===
Summary: tp6_google Aborting task - max run time exceeded! → tp6_google, tp6_youtube | Aborting task - max run time exceeded!
Summary: tp6_google, tp6_youtube | Aborting task - max run time exceeded! → tp6_google, tp6_youtube,about_preferences_basic,dromaeo_css,ts_paint_webext,a11yr,tp5o| Aborting task - max run time exceeded!
There have been 32 failures in the last week (42 according to the Neglected Oranges filter).
Summary: tp6_google, tp6_youtube,about_preferences_basic,dromaeo_css,ts_paint_webext,a11yr,tp5o| Aborting task - max run time exceeded!

Only fails on opt build type.
Platforms:
- macosx64-nightly:21
- OS X 10.10: 11

Here is a recent log file:
https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-central&job_id=165097553
Flags: needinfo?(rwood)
Whiteboard: [stockwell needswork]
all profiling and tp6 tests- lets focus on profiling first, then tp6 once that dust settles.
(In reply to OrangeFactor Robot from comment #8)

Definitely some kind of issue with tp6_google stalling out - and then eventually reaching the max runtime. Happens at various cycles but seems to be a common theme right before it stalls out, there's a bunch of requests for urls that don't exist inside the mitmproxy recording, which we intentionally kill via our custom playback script:

"server_playback: killed non-replay request"

Which shouldn't be a problem but it looks like when tp6_google stalls out, there are a fair number of these non-replay requests. My theory is that these non-replay requests must be blocking the page from finishing to load, so pageloader is still awaiting for the hero element to be loaded but it never is. I'll do a bunch of local runs and see if I can reproduce it.

Sample log:

06:04:40     INFO -  PID 1711 | Cycle 1(20): loaded https://www.google.com/#hl=en&q=barack+obama (next: https://www.google.com/#hl=en&q=barack+obama)
06:04:40     INFO -  PID 1711 | Waiting for idle-callback
06:04:41     INFO -  For request https://www.google.com/ found exact replay match
06:04:41     INFO -  127.0.0.1:49232: GET https://www.google.com/ HTTP/2.0
06:04:41     INFO -  [replay]               << 302  259b
06:04:41     INFO -  For request https://www.google.ca/?gfe_rd=cr&ei=EwY3WdejM8KR8QfHk5OIBA found exact replay match
06:04:41     INFO -  127.0.0.1:49234: GET https://www.google.ca/?gfe_rd=cr&ei=EwY3WdejM8KR8QfHk5OIBA HTTP/2.0
06:04:41     INFO -  [replay]               << 200  61.74k
06:04:41     INFO -  For request https://www.google.ca/search?hl=en&q=barack+obama&ei=FAY3WaDyBoS0jwPFiLugAw found exact replay match
06:04:41     INFO -  127.0.0.1:49234: GET https://www.google.ca/search?hl=en&q=barack+obama&ei=FAY3WaDyBoS0jwPFiLugAw HTTP/2.0
06:04:41     INFO -  [replay]               << 200  138.03k
06:04:41     INFO -  For request https://id.google.ca/verify/q6JL9CoQtrBBFNyEhd7okDAAAABJ3yEA2_od8JAJaTdwpUzLgiiG-CAOHUwiMktJrkRX8KAJzeYZDsA0M9vDQrKYXnM found exact replay match
06:04:41     INFO -  127.0.0.1:49240: GET https://id.google.ca/verify/q6JL9CoQtrBBFNyEhd7okDAAAABJ3yEA2_od8JAJaTdwpUzLgiiG-CAOHUwiMktJrkRX8KAJzeYZDsA0M9vDQrKYXnM HTTP/2.0
06:04:41     INFO -  [replay]               << 200  0b
06:04:41     INFO -  For request https://www.google.ca/client_204?&atyp=i&biw=1024&bih=694&ei=FAY3WeO-PMLcjAPuvZgI best match https://www.google.ca/client_204?&atyp=i&biw=1047&bih=631&ei=FAY3WeO-PMLcjAPuvZgI with score==13
06:04:41     INFO -  127.0.0.1:49234: GET https://www.google.ca/client_204?&atyp=i&biw=1024&bih=694&ei=FAY3WeO-PMLcjAPuvZgI HTTP/2.0
06:04:41     INFO -  [replay]               << 204  0b
06:04:42     INFO -  127.0.0.1:49244: clientconnect
06:04:42     INFO -  server_playback: killed non-replay request https://csi.gstatic.com/csi?v=3&s=gapi_module&action=gapi_iframes__googleapis_cli12&it=mli.116,mei.14&srt=16&e=abc_l0,abc_m0,abc_pgapi_iframes__googleapis_cli12,abc_u0&rt=
06:04:42     INFO -  127.0.0.1:49244: GET https://csi.gstatic.com/csi?v=3&s=gapi_module&action=gapi_iframes__googleapis_cli12&it=mli.116,mei.14&srt=16&e=abc_l0,abc_m0,abc_pgapi_iframes__googleapis_cli12,abc_u0&rt= HTTP/2.0
06:04:42     INFO -                << 404 Not Found 0b
06:04:42     INFO -  For request https://www.google.ca/gen_204?s=web&atyp=csi&ei=FAY3WeO-PMLcjAPuvZgI&imc=21&imn=21&imp=19&adh=&xjs=init.44.20.sb.24.p.10.dvl.4.foot.2.m.2&ima=8&rt=xjsls.56,prt.60,iml.138,dcl.116,xjses.164,jraids.202,jraide.232,xjsee.294,xjs.296,iuml_rcs.426,iuml_nre.426,ol.1030,aft.134,wsrt.70,cst.0,dnst.0,rqst.10,rspt.0,sslt.0,rqstt.6,unt.0,cstt.0,dit.170 best match https://www.google.ca/gen_204?s=web&atyp=csi&ei=FAY3WeO-PMLcjAPuvZgI&imc=21&imn=21&imp=19&adh=&xjs=init.49.20.sb.28.p.10.dvl.4.fpe.2.r.1&ima=8&rt=xjsls.86,prt.88,iml.196,dcl.205,xjses.232,jraids.274,jraide.296,xjsee.361,xjs.362,iuml_rcs.569,iuml_nre.569,ol.598,aft.192,wsrt.1015,cst.0,dnst.0,rqst.914,rspt.2,rqstt.69,unt.-2,cstt.-2,dit.1210 with score==37
06:04:42     INFO -  127.0.0.1:49234: GET https://www.google.ca/gen_204?s=web&atyp=csi&ei=FAY3WeO-PMLcjAPuvZgI&imc=21&imn=21&imp=19&adh=&xjs=init.44.20.sb.24.p.10.dvl.4.foot.2.m.2&ima=8&rt=xjsls.56,prt.60,iml.138,dcl.116,xjses.164,jraids.202,jraide.232,xjsee.294,xjs.296,iuml_rcs.426,iuml_nre.426,ol.1030,aft.134,wsrt.70,cst.0,dnst.0,rqst.10,rspt.0,sslt.0,rqstt.6,unt.0,cstt.0,dit.170 HTTP/2.0
06:04:42     INFO -  [replay]               << 204  0b
06:04:43     INFO -  server_playback: killed non-replay request https://www.google.ca/gen_204?atyp=i&ct=slh&cad=&ei=FAY3WeO-PMLcjAPuvZgI&m=HV&t=C&s=1&v=2&pv=0.2333544504940681&me=1:1520258653196,x:4,V,0,0,1024,694:0,N,1,FAY3WeO-PMLcjAPuvZgI:0,R,1,3,13,22,120,47:0,R,1,36,166,175,600,342:0,R,1,37,166,205,600,288:0,R,1,38,146,205,640,288:0,R,1,55,166,557,600,76:0,R,1,61,166,659,600,98:0,R,1,120,820,175,248,1019:0,R,1,121,822,175,278,1001:0,R,1,125,822,175,278,153:0,R,1,144,822,340,278,56:0,R,1,155,822,412,278,41:0,R,1,157,822,467,278,81:0,R,1,158,837,467,248,81:0,R,1,161,822,561,278,48:0,R,1,165,822,616,278,16:0,R,1,168,822,639,278,16:0,R,1,172,822,662,278,16:0,R,1,177,822,685,278,32:4,B,2040:636,e,H&zx=1520258683130
06:04:43     INFO -  127.0.0.1:49234: POST https://www.google.ca/gen_204?atyp=i&ct=slh&cad=&ei=FAY3WeO-PMLcjAPuvZgI&m=HV&t=C&s=1&v=2&pv=0.2333544504940681&me=1:1520258653196,x:4,V,0,0,1024,694:0,N,1,FAY3WeO-PMLcjAPuvZgI:0,R,1,3,13,22,120,47:0,R,1,36,166,175,600,342:0,R,1,37,166,205,600,288:0,R,1,38,146,205,640,288:0,R,1,55,166,557,600,76:0,R,1,61,166,659,600,98:0,R,1,120,820,175,248,1019:0,R,1,121,822,175,278,1001:0,R,1,125,822,175,278,153:0,R,1,144,822,340,278,56:0,R,1,155,822,412,278,41:0,R,1,157,822,467,278,81:0,R,1,158,837,467,248,81:0,R,1,161,822,561,278,48:0,R,1,165,822,616,278,16:0,R,1,168,822,639,278,16:0,R,1,172,822,662,278,16:0,R,1,177,822,685,278,32:4,B,2040:636,e,H&zx=1520258683130 HTTP/2.0
06:04:43     INFO -                << 404 Not Found 0b
06:04:47     INFO -  server_playback: killed non-replay request https://www.google.ca/gen_204?atyp=i&ct=slh&cad=&ei=FAY3WeO-PMLcjAPuvZgI&m=HV&t=C&s=2&v=2&pv=0.725588597635468&me=1:1520258654932,x:2,V,0,0,1024,694:0,N,1,FAY3WeO-PMLcjAPuvZgI:0,R,1,3,13,22,120,47:0,R,1,36,166,175,600,342:0,R,1,37,166,205,600,288:0,R,1,38,146,205,640,288:0,R,1,55,166,557,600,76:0,R,1,61,166,659,600,98:0,R,1,120,820,175,248,1019:0,R,1,121,822,175,278,1001:0,R,1,125,822,175,278,153:0,R,1,144,822,340,278,56:0,R,1,155,822,412,278,41:0,R,1,157,822,467,278,81:0,R,1,158,837,467,248,81:0,R,1,161,822,561,278,48:0,R,1,165,822,616,278,16:0,R,1,168,822,639,278,16:0,R,1,172,822,662,278,16:0,R,1,177,822,685,278,32:4,B,2040:588,e,H&zx=1520258687130
06:04:47     INFO -  127.0.0.1:49234: POST https://www.google.ca/gen_204?atyp=i&ct=slh&cad=&ei=FAY3WeO-PMLcjAPuvZgI&m=HV&t=C&s=2&v=2&pv=0.725588597635468&me=1:1520258654932,x:2,V,0,0,1024,694:0,N,1,FAY3WeO-PMLcjAPuvZgI:0,R,1,3,13,22,120,47:0,R,1,36,166,175,600,342:0,R,1,37,166,205,600,288:0,R,1,38,146,205,640,288:0,R,1,55,166,557,600,76:0,R,1,61,166,659,600,98:0,R,1,120,820,175,248,1019:0,R,1,121,822,175,278,1001:0,R,1,125,822,175,278,153:0,R,1,144,822,340,278,56:0,R,1,155,822,412,278,41:0,R,1,157,822,467,278,81:0,R,1,158,837,467,248,81:0,R,1,161,822,561,278,48:0,R,1,165,822,616,278,16:0,R,1,168,822,639,278,16:0,R,1,172,822,662,278,16:0,R,1,177,822,685,278,32:4,B,2040:588,e,H&zx=1520258687130 HTTP/2.0
06:04:47     INFO -                << 404 Not Found 0b
06:04:52     INFO -  server_playback: killed non-replay request https://www.google.ca/gen_204?atyp=i&ct=slh&cad=&ei=FAY3WeO-PMLcjAPuvZgI&m=HV&t=C&s=3&v=2&pv=0.9168953662225396&me=1:1520258656448,x:4,V,0,0,1024,694:0,N,1,FAY3WeO-PMLcjAPuvZgI:0,R,1,3,13,22,120,47:0,R,1,36,166,175,600,342:0,R,1,37,166,205,600,288:0,R,1,38,146,205,640,288:0,R,1,55,166,557,600,76:0,R,1,61,166,659,600,98:0,R,1,120,820,175,248,1019:0,R,1,121,822,175,278,1001:0,R,1,125,822,175,278,153:0,R,1,144,822,340,278,56:0,R,1,155,822,412,278,41:0,R,1,157,822,467,278,81:0,R,1,158,837,467,248,81:0,R,1,161,822,561,278,48:0,R,1,165,822,616,278,16:0,R,1,168,822,639,278,16:0,R,1,172,822,662,278,16:0,R,1,177,822,685,278,32:8,B,2040:622,e,H&zx=1520258692132
06:04:52     INFO -  127.0.0.1:49234: POST https://www.google.ca/gen_204?atyp=i&ct=slh&cad=&ei=FAY3WeO-PMLcjAPuvZgI&m=HV&t=C&s=3&v=2&pv=0.9168953662225396&me=1:1520258656448,x:4,V,0,0,1024,694:0,N,1,FAY3WeO-PMLcjAPuvZgI:0,R,1,3,13,22,120,47:0,R,1,36,166,175,600,342:0,R,1,37,166,205,600,288:0,R,1,38,146,205,640,288:0,R,1,55,166,557,600,76:0,R,1,61,166,659,600,98:0,R,1,120,820,175,248,1019:0,R,1,121,822,175,278,1001:0,R,1,125,822,175,278,153:0,R,1,144,822,340,278,56:0,R,1,155,822,412,278,41:0,R,1,157,822,467,278,81:0,R,1,158,837,467,248,81:0,R,1,161,822,561,278,48:0,R,1,165,822,616,278,16:0,R,1,168,822,639,278,16:0,R,1,172,822,662,278,16:0,R,1,177,822,685,278,32:8,B,2040:622,e,H&zx=1520258692132 HTTP/2.0
06:04:52     INFO -                << 404 Not Found 0b
06:04:57     INFO -  server_playback: killed non-replay request https://www.google.ca/gen_204?atyp=i&ct=slh&cad=&ei=FAY3WeO-PMLcjAPuvZgI&m=HV&t=C&s=4&v=2&pv=0.27735978633393954&me=1:1520258657932,x:8,V,0,0,1024,694:0,N,1,FAY3WeO-PMLcjAPuvZgI:0,R,1,3,13,22,120,47:0,R,1,36,166,175,600,342:0,R,1,37,166,205,600,288:0,R,1,38,146,205,640,288:0,R,1,55,166,557,600,76:0,R,1,61,166,659,600,98:0,R,1,120,820,175,248,1019:0,R,1,121,822,175,278,1001:0,R,1,125,822,175,278,153:0,R,1,144,822,340,278,56:0,R,1,155,822,412,278,41:0,R,1,157,822,467,278,81:0,R,1,158,837,467,248,81:0,R,1,161,822,561,278,48:0,R,1,165,822,616,278,16:0,R,1,168,822,639,278,16:0,R,1,172,822,662,278,16:0,R,1,177,822,685,278,32:2,B,2040:662,e,H&zx=1520258697134
06:04:57     INFO -  127.0.0.1:49234: POST https://www.google.ca/gen_204?atyp=i&ct=slh&cad=&ei=FAY3WeO-PMLcjAPuvZgI&m=HV&t=C&s=4&v=2&pv=0.27735978633393954&me=1:1520258657932,x:8,V,0,0,1024,694:0,N,1,FAY3WeO-PMLcjAPuvZgI:0,R,1,3,13,22,120,47:0,R,1,36,166,175,600,342:0,R,1,37,166,205,600,288:0,R,1,38,146,205,640,288:0,R,1,55,166,557,600,76:0,R,1,61,166,659,600,98:0,R,1,120,820,175,248,1019:0,R,1,121,822,175,278,1001:0,R,1,125,822,175,278,153:0,R,1,144,822,340,278,56:0,R,1,155,822,412,278,41:0,R,1,157,822,467,278,81:0,R,1,158,837,467,248,81:0,R,1,161,822,561,278,48:0,R,1,165,822,616,278,16:0,R,1,168,822,639,278,16:0,R,1,172,822,662,278,16:0,R,1,177,822,685,278,32:2,B,2040:662,e,H&zx=1520258697134 HTTP/2.0
06:04:57     INFO -                << 404 Not Found 0b
06:05:02     INFO -  server_playback: killed non-replay request https://www.google.ca/gen_204?atyp=i&ct=slh&cad=&ei=FAY3WeO-PMLcjAPuvZgI&m=HV&t=C&s=5&v=2&pv=0.35844780834444256&me=1:1520258659712,x:4,V,0,0,1024,694:0,B,2040:0,N,1,FAY3WeO-PMLcjAPuvZgI:0,R,1,3,13,22,120,47:0,R,1,36,166,175,600,342:0,R,1,37,166,205,600,288:0,R,1,38,146,205,640,288:0,R,1,55,166,557,600,76:0,R,1,61,166,659,600,98:0,R,1,120,820,175,248,1019:0,R,1,121,822,175,278,1001:0,R,1,125,822,175,278,153:0,R,1,144,822,340,278,56:0,R,1,155,822,412,278,41:0,R,1,157,822,467,278,81:0,R,1,158,837,467,248,81:0,R,1,161,822,561,278,48:0,R,1,165,822,616,278,16:0,R,1,168,822,639,278,16:0,R,1,172,822,662,278,16:0,R,1,177,822,685,278,32:548,e,H&zx=1520258702134
06:05:02     INFO -  127.0.0.1:49234: POST https://www.google.ca/gen_204?atyp=i&ct=slh&cad=&ei=FAY3WeO-PMLcjAPuvZgI&m=HV&t=C&s=5&v=2&pv=0.35844780834444256&me=1:1520258659712,x:4,V,0,0,1024,694:0,B,2040:0,N,1,FAY3WeO-PMLcjAPuvZgI:0,R,1,3,13,22,120,47:0,R,1,36,166,175,600,342:0,R,1,37,166,205,600,288:0,R,1,38,146,205,640,288:0,R,1,55,166,557,600,76:0,R,1,61,166,659,600,98:0,R,1,120,820,175,248,1019:0,R,1,121,822,175,278,1001:0,R,1,125,822,175,278,153:0,R,1,144,822,340,278,56:0,R,1,155,822,412,278,41:0,R,1,157,822,467,278,81:0,R,1,158,837,467,248,81:0,R,1,161,822,561,278,48:0,R,1,165,822,616,278,16:0,R,1,168,822,639,278,16:0,R,1,172,822,662,278,16:0,R,1,177,822,685,278,32:548,e,H&zx=1520258702134 HTTP/2.0
06:05:02     INFO -                << 404 Not Found 0b
06:05:07     INFO -  server_playback: killed non-replay request https://www.google.ca/gen_204?atyp=i&ct=slh&cad=&ei=FAY3WeO-PMLcjAPuvZgI&m=HV&t=C&s=6&v=2&pv=0.35717010050672093&me=1:1520258661100,x:2,V,0,0,1024,694:0,N,1,FAY3WeO-PMLcjAPuvZgI:0,R,1,3,13,22,120,47:0,R,1,36,166,175,600,342:0,R,1,37,166,205,600,288:0,R,1,38,146,205,640,288:0,R,1,55,166,557,600,76:0,R,1,61,166,659,600,98:0,R,1,120,820,175,248,1019:0,R,1,121,822,175,278,1001:0,R,1,125,822,175,278,153:0,R,1,144,822,340,278,56:0,R,1,155,822,412,278,41:0,R,1,157,822,467,278,81:0,R,1,158,837,467,248,81:0,R,1,161,822,561,278,48:0,R,1,165,822,616,278,16:0,R,1,168,822,639,278,16:0,R,1,172,822,662,278,16:0,R,1,177,822,685,278,32:4,B,2040:726,e,H&zx=1520258707134
06:05:07     INFO -  127.0.0.1:49234: POST https://www.google.ca/gen_204?atyp=i&ct=slh&cad=&ei=FAY3WeO-PMLcjAPuvZgI&m=HV&t=C&s=6&v=2&pv=0.35717010050672093&me=1:1520258661100,x:2,V,0,0,1024,694:0,N,1,FAY3WeO-PMLcjAPuvZgI:0,R,1,3,13,22,120,47:0,R,1,36,166,175,600,342:0,R,1,37,166,205,600,288:0,R,1,38,146,205,640,288:0,R,1,55,166,557,600,76:0,R,1,61,166,659,600,98:0,R,1,120,820,175,248,1019:0,R,1,121,822,175,278,1001:0,R,1,125,822,175,278,153:0,R,1,144,822,340,278,56:0,R,1,155,822,412,278,41:0,R,1,157,822,467,278,81:0,R,1,158,837,467,248,81:0,R,1,161,822,561,278,48:0,R,1,165,822,616,278,16:0,R,1,168,822,639,278,16:0,R,1,172,822,662,278,16:0,R,1,177,822,685,278,32:4,B,2040:726,e,H&zx=1520258707134 HTTP/2.0
06:05:07     INFO -                << 404 Not Found 0b
06:05:11     INFO -  For request http://detectportal.firefox.com/success.txt best match http://detectportal.firefox.com/success.txt with score==3
06:05:11     INFO -  127.0.0.1:49229: GET http://detectportal.firefox.com/success.txt
06:05:11     INFO -  [replay]               << 200 OK 8b
06:05:12     INFO -  server_playback: killed non-replay request https://www.google.ca/gen_204?atyp=i&ct=slh&cad=&ei=FAY3WeO-PMLcjAPuvZgI&m=HV&t=C&s=7&v=2&pv=0.20828564208992872&me=1:1520258662528,x:2,V,0,0,1024,694:0,B,2040:0,N,1,FAY3WeO-PMLcjAPuvZgI:0,R,1,3,13,22,120,47:0,R,1,36,166,175,600,342:0,R,1,37,166,205,600,288:0,R,1,38,146,205,640,288:0,R,1,55,166,557,600,76:0,R,1,61,166,659,600,98:0,R,1,120,820,175,248,1019:0,R,1,121,822,175,278,1001:0,R,1,125,822,175,278,153:0,R,1,144,822,340,278,56:0,R,1,155,822,412,278,41:0,R,1,157,822,467,278,81:0,R,1,158,837,467,248,81:0,R,1,161,822,561,278,48:0,R,1,165,822,616,278,16:0,R,1,168,822,639,278,16:0,R,1,172,822,662,278,16:0,R,1,177,822,685,278,32:598,e,H&zx=1520258712134
06:05:12     INFO -  127.0.0.1:49234: POST https://www.google.ca/gen_204?atyp=i&ct=slh&cad=&ei=FAY3WeO-PMLcjAPuvZgI&m=HV&t=C&s=7&v=2&pv=0.20828564208992872&me=1:1520258662528,x:2,V,0,0,1024,694:0,B,2040:0,N,1,FAY3WeO-PMLcjAPuvZgI:0,R,1,3,13,22,120,47:0,R,1,36,166,175,600,342:0,R,1,37,166,205,600,288:0,R,1,38,146,205,640,288:0,R,1,55,166,557,600,76:0,R,1,61,166,659,600,98:0,R,1,120,820,175,248,1019:0,R,1,121,822,175,278,1001:0,R,1,125,822,175,278,153:0,R,1,144,822,340,278,56:0,R,1,155,822,412,278,41:0,R,1,157,822,467,278,81:0,R,1,158,837,467,248,81:0,R,1,161,822,561,278,48:0,R,1,165,822,616,278,16:0,R,1,168,822,639,278,16:0,R,1,172,822,662,278,16:0,R,1,177,822,685,278,32:598,e,H&zx=1520258712134 HTTP/2.0
06:05:12     INFO -                << 404 Not Found 0b
06:05:17     INFO -  server_playback: killed non-replay request https://www.google.ca/gen_204?atyp=i&ct=slh&cad=&ei=FAY3WeO-PMLcjAPuvZgI&m=HV&t=C&s=8&v=2&pv=0.9513503450316902&me=1:1520258663926,x:2,V,0,0,1024,694:0,N,1,FAY3WeO-PMLcjAPuvZgI:0,R,1,3,13,22,120,47:0,R,1,36,166,175,600,342:0,R,1,37,166,205,600,288:0,R,1,38,146,205,640,288:0,R,1,55,166,557,600,76:0,R,1,61,166,659,600,98:0,R,1,120,820,175,248,1019:0,R,1,121,822,175,278,1001:0,R,1,125,822,175,278,153:0,R,1,144,822,340,278,56:0,R,1,155,822,412,278,41:0,R,1,157,822,467,278,81:0,R,1,158,837,467,248,81:0,R,1,161,822,561,278,48:0,R,1,165,822,616,278,16:0,R,1,168,822,639,278,16:0,R,1,172,822,662,278,16:0,R,1,177,822,685,278,32:2,B,2040:694,e,H&zx=1520258717134
06:05:17     INFO -  127.0.0.1:49234: POST https://www.google.ca/gen_204?atyp=i&ct=slh&cad=&ei=FAY3WeO-PMLcjAPuvZgI&m=HV&t=C&s=8&v=2&pv=0.9513503450316902&me=1:1520258663926,x:2,V,0,0,1024,694:0,N,1,FAY3WeO-PMLcjAPuvZgI:0,R,1,3,13,22,120,47:0,R,1,36,166,175,600,342:0,R,1,37,166,205,600,288:0,R,1,38,146,205,640,288:0,R,1,55,166,557,600,76:0,R,1,61,166,659,600,98:0,R,1,120,820,175,248,1019:0,R,1,121,822,175,278,1001:0,R,1,125,822,175,278,153:0,R,1,144,822,340,278,56:0,R,1,155,822,412,278,41:0,R,1,157,822,467,278,81:0,R,1,158,837,467,248,81:0,R,1,161,822,561,278,48:0,R,1,165,822,616,278,16:0,R,1,168,822,639,278,16:0,R,1,172,822,662,278,16:0,R,1,177,822,685,278,32:2,B,2040:694,e,H&zx=1520258717134 HTTP/2.0
06:05:17     INFO -                << 404 Not Found 0b
06:05:22     INFO -  server_playback: killed non-replay request https://www.google.ca/gen_204?atyp=i&ct=slh&cad=&ei=FAY3WeO-PMLcjAPuvZgI&m=HV&t=C&s=9&v=2&pv=0.4524756539030591&me=1:1520258665342,x:2,V,0,0,1024,694:0,B,2040:0,N,1,FAY3WeO-PMLcjAPuvZgI:0,R,1,3,13,22,120,47:0,R,1,36,166,175,600,342:0,R,1,37,166,205,600,288:0,R,1,38,146,205,640,288:0,R,1,55,166,557,600,76:0,R,1,61,166,659,600,98:0,R,1,120,820,175,248,1019:0,R,1,121,822,175,278,1001:0,R,1,125,822,175,278,153:0,R,1,144,822,340,278,56:0,R,1,155,822,412,278,41:0,R,1,157,822,467,278,81:0,R,1,158,837,467,248,81:0,R,1,161,822,561,278,48:0,R,1,165,822,616,278,16:0,R,1,168,822,639,278,16:0,R,1,172,822,662,278,16:0,R,1,177,822,685,278,32:584,e,H&zx=1520258722134
06:05:22     INFO -  127.0.0.1:49234: POST https://www.google.ca/gen_204?atyp=i&ct=slh&cad=&ei=FAY3WeO-PMLcjAPuvZgI&m=HV&t=C&s=9&v=2&pv=0.4524756539030591&me=1:1520258665342,x:2,V,0,0,1024,694:0,B,2040:0,N,1,FAY3WeO-PMLcjAPuvZgI:0,R,1,3,13,22,120,47:0,R,1,36,166,175,600,342:0,R,1,37,166,205,600,288:0,R,1,38,146,205,640,288:0,R,1,55,166,557,600,76:0,R,1,61,166,659,600,98:0,R,1,120,820,175,248,1019:0,R,1,121,822,175,278,1001:0,R,1,125,822,175,278,153:0,R,1,144,822,340,278,56:0,R,1,155,822,412,278,41:0,R,1,157,822,467,278,81:0,R,1,158,837,467,248,81:0,R,1,161,822,561,278,48:0,R,1,165,822,616,278,16:0,R,1,168,822,639,278,16:0,R,1,172,822,662,278,16:0,R,1,177,822,685,278,32:584,e,H&zx=1520258722134 HTTP/2.0
06:05:22     INFO -                << 404 Not Found 0b
06:05:27     INFO -  server_playback: killed non-replay request https://www.google.ca/gen_204?atyp=i&ct=slh&cad=&ei=FAY3WeO-PMLcjAPuvZgI&m=HV&t=C&s=10&v=2&pv=0.6970043760026999&me=1:1520258666610,x:0,V,0,0,1024,694:0,N,1,FAY3WeO-PMLcjAPuvZgI:0,R,1,3,13,22,120,47:0,R,1,36,166,175,600,342:0,R,1,37,166,205,600,288:0,R,1,38,146,205,640,288:0,R,1,55,166,557,600,76:0,R,1,61,166,659,600,98:0,R,1,120,820,175,248,1019:0,R,1,121,822,175,278,1001:0,R,1,125,822,175,278,153:0,R,1,144,822,340,278,56:0,R,1,155,822,412,278,41:0,R,1,157,822,467,278,81:0,R,1,158,837,467,248,81:0,R,1,161,822,561,278,48:0,R,1,165,822,616,278,16:0,R,1,168,822,639,278,16:0,R,1,172,822,662,278,16:0,R,1,177,822,685,278,32:2,B,2040:584,e,H&zx=1520258727134
06:05:27     INFO -  127.0.0.1:49234: POST https://www.google.ca/gen_204?atyp=i&ct=slh&cad=&ei=FAY3WeO-PMLcjAPuvZgI&m=HV&t=C&s=10&v=2&pv=0.6970043760026999&me=1:1520258666610,x:0,V,0,0,1024,694:0,N,1,FAY3WeO-PMLcjAPuvZgI:0,R,1,3,13,22,120,47:0,R,1,36,166,175,600,342:0,R,1,37,166,205,600,288:0,R,1,38,146,205,640,288:0,R,1,55,166,557,600,76:0,R,1,61,166,659,600,98:0,R,1,120,820,175,248,1019:0,R,1,121,822,175,278,1001:0,R,1,125,822,175,278,153:0,R,1,144,822,340,278,56:0,R,1,155,822,412,278,41:0,R,1,157,822,467,278,81:0,R,1,158,837,467,248,81:0,R,1,161,822,561,278,48:0,R,1,165,822,616,278,16:0,R,1,168,822,639,278,16:0,R,1,172,822,662,278,16:0,R,1,177,822,685,278,32:2,B,2040:584,e,H&zx=1520258727134 HTTP/2.0
06:05:27     INFO -                << 404 Not Found 0b

<and repeat several more 404's until the test time is exceeded>
Flags: needinfo?(rwood)
Enabling http2 priority requests in mitmproxy (--http2-priority) doesn't make a difference, nor does ignoring (not processing) requests for gstatic.com.

The tp6 failure always happens when during playback, it tries to go to gstatic.com (google's servers for static images, etc) and then for some reason gets a bunch of 404's - non-replay requests. In other tp6 google runs that are green, it goes to gstatic.com just fine, but a match for the requested items are found in the playback archive so it continues fine.
Finally was able to reproduce the tp6_google failure locally; during one of the tp6_google cycles, the test just stalls... the page was loaded (from what I could tell) but talos was still awaiting the hero element. Took hundreds and hundreds of page cycles to reproduce, but good to know it does happen locally as well.
Hey :tarek, if you have a couple of minutes could you please have a look at this log? This is a sample of the tp6_google test not finishing (the hero element is never fully loaded) - any ideas? I have some extra debugging in it. It's like at this point most of the requests become non-replay requests (noted by our custom playback script [1] and are killed):

https://taskcluster-artifacts.net/XYVOZIS4R--CADC05j2_dQ/0/public/logs/live_backing.log

I've tried a few things but stuck as to how to fix this. It doesn't happen often, but often enough to be a consistent intermittent failure.

[1] https://searchfox.org/mozilla-central/rev/8976abf9cab8eb4661665cc86bd355cd08238011/testing/talos/talos/mitmproxy/alternate-server-replay.py#176
Flags: needinfo?(tarek)
I am not sure what's a non-replay request exactly, but for the hero element the only thing I could think of is a failure in the IntersectionObserver. Do you think we can add some logs there?
Flags: needinfo?(tarek)
There have been 33 total failures in the last 7 days.

Failures per platform and builds:

OS X 10.10 / opt: 25
Windows 7 / opt & pgo: 5
windows10-64 / opt: 1
macosx64-nightly / opt: 1
windows10-64-nightly /opt: 1

Recent log file and snippet with the failure:
https://treeherder.mozilla.org/logviewer.html#?repo=autoland&job_id=173347581

14:06:51     INFO -  127.0.0.1:49262: clientdisconnect
14:06:51     INFO -  127.0.0.1:49252: clientdisconnect
[taskcluster 2018-04-12T21:16:58.992Z] Aborting task - max run time exceeded!
[taskcluster 2018-04-12T21:16:58.996Z] Exit Code: -1
[taskcluster 2018-04-12T21:16:58.996Z] === Task Finished ===
[taskcluster 2018-04-12T21:16:58.996Z] Task Duration: 19m58.871790873s
Flags: needinfo?(rwood)
Whiteboard: [stockwell unknown] → [stockwell needswork]
With some local debugging (for the tp6 osx issue) I noticed that the hero element obs.disconnect in the pageloader content code is being done after sending the PageLoader:LoadEvent. With debugging output after sending the PageLoader:LoadEvent and the obs.disconnect is not reached. I'm wondering if maybe the obs.disconnect is not happening and maybe causing issues with future pagecycles perhaps. Just a theory.

I have a patch doing the obs.disconnect once the element is loaded 100% but before sending the PageLoader:LoadEvent, plus with extra debugging and verbose mitmdump output turned on. Try is currently closed but once it's open I'll land this debugging patch and see how tp6 on osx goes.
Flags: needinfo?(rwood)
This bug has failed 48 times in the last 7 days on OSX, and Windows affecting opt, pgo, debug build types.

:rwod do you have any updates on this Bug?
Flags: needinfo?(rwood)
:rwood, I looked at this and see this is really osx tp6- maybe raptor will fix this? :)

after looking at a few logs it looks like:
* some cases we fail to find a elementtiming element, this error: https://searchfox.org/mozilla-central/source/testing/talos/talos/pageloader/chrome/lh_hero.js#27
* other cases we seem to hang after finding/loading the page

I suspect issues with mitmproxy not serving the test properly- as this is OSX, maybe we need to update things- maybe we need to wait for mitmproxy to warm up, maybe the browser has issues with mitmproxy and there is a race condition in the network stack on the machine.

thoughts?
Yes exactly, there's the two issues, I was able to reproduce the one (just stalling out after loading) but that took alot of tries to repro, but still not a good issue.

I already looked through all the mitmproxy/mitmdump options and tried some but nothing really applies, also I added extra debugging but didn't get anything obvious out of it.

That's a really interesting point about 'warm up' that never occurred to me that maybe we are starting the test just a bit too early before playback is at the right place.

I'll try adding a delay after we start playback but before the test starts, and land that on try to see if it makes any difference. Thanks!
Flags: needinfo?(rwood)
I would also like to upgrade our mitmproxy production version to the latest release, I have filed Bug 1457274
(In reply to Robert Wood [:rwood] from comment #34)
> https://treeherder.mozilla.org/#/jobs?repo=try&revision=d6315f6e4765ce93b88ae9f08a01c66d56c14048

Nope, doesn't make a difference unfortunately. Next I'll try a 30 second delay between page cycles to see if that makes any difference, guessing not but worth a try ;)
(In reply to Robert Wood [:rwood] from comment #37)
> https://treeherder.mozilla.org/#/jobs?repo=try&revision=ab70bcc42f21f50c5ec6161020fc56123593374a

Nope, a delay of 10 seconds between page cycles had no effect.
There are 34 failures over the past week for this bug, majority of them on OS X 10.10, opt build type.

Recent log: https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-inbound&job_id=177121116
This bug has failed 46 times in the last 7 days on OSX, Windows 7 and Windows 10, affecting opt and pgo build types.
Failing tests opt-talos-tp6-e10s,opt-talos-tp6-stylo-threads-e10s.
Log: https://treeherder.mozilla.org/logviewer.html#?repo=autoland&job_id=177963993&lineNumber=1-1414 


:rwood could you please take a look at this bug?
Flags: needinfo?(rwood)
Summary: tp6_google, tp6_youtube,about_preferences_basic,dromaeo_css,ts_paint_webext,a11yr,tp5o| Aborting task - max run time exceeded! → talos performance (tp6_google, tp6_youtube, ...)about_preferences_basic,dromaeo_css,ts_paint_webext,a11yr,tp5o| Aborting task - max run time exceeded!
Update:
There have been 64 failures in the last 7 days.
The majority of fails are on the OS X platform and on the opt build.

Failures per platform:

- OS X 10.10: 45
- linux64-qr: 5
- windows10-64: 4
- windows10-64-qr: 3
- windows7-32: 4
- linux64: 2
- macosx64-nightly: 1

Failure per build type:

- opt: 57
- pgo: 7

Recent log file: https://treeherder.mozilla.org/logviewer.html#?job_id=179379034&repo=mozilla-inbound
Summary:  talos performance (tp6_google, tp6_youtube, ...)about_preferences_basic,dromaeo_css,ts_paint_webext,a11yr,tp5o| Aborting task - max run time exceeded!
you can see this is split between windows and osx- it looks to be tp6 specifically;  This failure rate is so high we should look into this sooner rather than later.  I don't know why this started, but it seems to have picked up around May 18th, I started with some retriggers on mozilla-central:
https://treeherder.mozilla.org/#/jobs?repo=mozilla-central&filter-searchStr=tp6%20osx&tochange=1d26b327ee6bcccdd7d3535cd5352a8ac3fb7d53&fromchange=54063deb2f1caf8c4acf6461d3ba779805835c96
looking at this, I see where linux picked up (osx is hard to tell because it was perma fail for a couple hours):
https://treeherder.mozilla.org/#/jobs?repo=autoland&filter-searchStr=opt%20tp6%20linux&tochange=d52c1a18a259f8bc0be20aa246fc9f08f07d2d7c&selectedJob=179649188&fromchange=905c4c76602d0a0aea147e9fb7bfffeea02d5a52

it looks like bug 1217748 is the root cause.

:aryx, do you agree, if so- could you back that out?
Flags: needinfo?(rwood) → needinfo?(aryx.bugmail)
Bug 1217748 has been backed out.
Flags: needinfo?(aryx.bugmail)
Whiteboard: [stockwell disable-recommended] → [stockwell fixed:backout]
Update:
There have been 45 failures in the last 7 days. 

Failures per platform and build type:
osx-10-10 / opt: 23
linux64-qr / opt: 10
linux64 / opt & pgo: 5
windows7-32 / pgo & opt: 3
windows10-64 / pgo: 2
windows10-64-qr / opt: 1
macosx64-nightly / opt: 1

Summary: talos performance (tp6_google, tp6_youtube, ...)about_preferences_basic,dromaeo_css,ts_paint_webext,a11yr,tp5o| Aborting task - max run time exceeded!
Here is a recent log file:
https://treeherder.mozilla.org/logviewer.html#?job_id=181530737&repo=autoland
Flags: needinfo?(jmaher)
I am not sure why tp6 is timing out randomly.  Most tasks run in 4-5 minutes, a few can take up to 8 minutes if they have delays downloading/setting up.  The task is set for a 20 minute timeout.  This appears to happen across OS flavors, indicating this is not an OS issue, but more of a Firefox issue.  I think this is similar to bug 1414495 although that is mochitest/win10 specific now.  I believe we start up the browser, the browser hits URLs during initialization, then never actually loads the test.

:rwood, can you give an estimate how long it will be before tp6 is running on raptor?  That might change enough variables that this is "fixed"
Flags: needinfo?(jmaher) → needinfo?(rwood)
Goal is to have it in production over the next few weeks (it's only on OSX on try currently). Unfortunately the Raptor webext is currently blocked by an issue introduced in 1406181. Once that's resolved it's my priority to roll Raptor tp6 out on the other platforms.
Flags: needinfo?(rwood)
In the lat 7 days, there are 32 failures. 
They occur on osx-10-10 (opt), macosx64-nightly (opt), windows10-64-nightly (opt), linux64 (pgo), linux64-qr (opt).
Recent failure log: https://treeherder.mozilla.org/logviewer.html#?job_id=184094776&repo=autoland&lineNumber=1035
21:35:02     INFO -  127.0.0.1:50425: HTTP/2 connection terminated by client: error code: 0, last stream id: 0, additional data: None
21:35:02     INFO -  127.0.0.1:50417: clientdisconnect
21:35:02     INFO -  127.0.0.1:50423: clientdisconnect
21:35:02     INFO -  127.0.0.1:50425: clientdisconnect
21:35:03     INFO -  127.0.0.1:50427: HTTP/2 connection terminated by client: error code: 0, last stream id: 0, additional data: None
21:35:03     INFO -  127.0.0.1:50427: clientdisconnect
[taskcluster:error] Aborting task...
[taskcluster 2018-06-21T04:45:04.133Z] === Task Finished ===
[taskcluster 2018-06-21T04:45:04.133Z] Task Duration: 19m59.41226836s
[taskcluster 2018-06-21T04:45:04.450Z] Uploading artifact public/logs/localconfig.json from file logs/localconfig.json with content encoding "gzip", mime type "application/json" and expiry 2019-06-21T04:01:14.659Z
[taskcluster 2018-06-21T04:45:05.296Z] Uploading artifact public/logs/talos_critical.log from file logs/talos_critical.log with content encoding "gzip", mime type "text/plain" and expiry 2019-06-21T04:01:14.659Z
[taskcluster 2018-06-21T04:45:05.651Z] Uploading artifact public/logs/talos_error.log from file logs/talos_error.log with content encoding "gzip", mime type "text/plain" and expiry 2019-06-21T04:01:14.659Z
[taskcluster 2018-06-21T04:45:06.000Z] Uploading artifact public/logs/talos_fatal.log from file logs/talos_fatal.log with content encoding "gzip", mime type "text/plain" and expiry 2019-06-21T04:01:14.659Z
[taskcluster 2018-06-21T04:45:06.353Z] Uploading artifact public/logs/talos_info.log from file logs/talos_info.log with content encoding "gzip", mime type "text/plain" and expiry 2019-06-21T04:01:14.659Z
[taskcluster 2018-06-21T04:45:06.995Z] Uploading artifact public/logs/talos_raw.log from file logs/talos_raw.log with content encoding "gzip", mime type "text/plain" and expiry 2019-06-21T04:01:14.659Z
[taskcluster 2018-06-21T04:45:07.353Z] Uploading artifact public/logs/talos_warning.log from file logs/talos_warning.log with content encoding "gzip", mime type "text/plain" and expiry 2019-06-21T04:01:14.659Z
[taskcluster 2018-06-21T04:45:07.706Z] Uploading artifact public/test_info/tp6-e10s_errorsummary.log from file build/blobber_upload_dir/tp6-e10s_errorsummary.log with content encoding "gzip", mime type "text/plain" and expiry 2019-06-21T04:01:14.659Z
[taskcluster 2018-06-21T04:45:08.064Z] Uploading artifact public/test_info/tp6-e10s_raw.log from file build/blobber_upload_dir/tp6-e10s_raw.log with content encoding "gzip", mime type "text/plain" and expiry 2019-06-21T04:01:14.659Z
[taskcluster:error] Task aborted - max run time exceeded
Whiteboard: [stockwell fixed:backout] → [stockwell fixed:backout][stockwell needswork]
Summary: talos performance (tp6_google, tp6_youtube, ...)about_preferences_basic,dromaeo_css,ts_paint_webext,a11yr,tp5o| Aborting task - max run time exceeded! → talos performance (tp5o_webext, tp6_google, tp6_youtube, ...)about_preferences_basic,dromaeo_css,ts_paint_webext,a11yr,tp5o| Aborting task - max run time exceeded!
still waiting on raptor- this is running on linux now, windows is proving to be more problematic.
Over the last 7 days there are 51 failures on this bug. These happen on windows7-32, windows10-64-qr, windows10-64-nightly, windows10-64, osx-10-10, macosx64-nightly, linux64-qr, linux64

Here is the most recent log example: https://treeherder.mozilla.org/logviewer.html#?job_id=185442796&repo=mozilla-inbound
Update:
There have been 55 total failures in the last week.
Occurrences per platform and build type:
- 28 failures on osx-10-10 / opt
- 7 failures on macosx64-nightly / opt
- 4 failures on linux64/ opt & pgo
- 4 failures on windows10-64 / opt, asan & debug
- 4 failures on windows10-64-nightly / opt
- 4 failures on windows10-64-qr / opt & debug
- 2 failures on linux64-qr / opt
- 1 failure on linux64-nightly / opt
- 1 failure on windows7-32 / pgo

Recent log file with failure:
https://treeherder.mozilla.org/logviewer.html#?job_id=186997876&repo=autoland&lineNumber=1417
In the last 7 days there were 51 occurrences for this bug.
They occur on OS X, linux64 and windows7-32, opt and pgo builds.

recent log: https://treeherder.mozilla.org/logviewer.html#?job_id=187790717&repo=mozilla-central&lineNumber=873
Flags: needinfo?(rwood)
:rwood:

Hi,

Did you have a chance to take a loot at this yet?
This bug has still a high failures rate on weekly basis.

Here is a recent log:
https://treeherder.mozilla.org/logviewer.html#?job_id=193542153&repo=mozilla-central&lineNumber=9077

Can you please take a look at it?
This bug has failed 44 times in the last 7 days. It fails on all platforms, except android, build types are opt and pgo.

Here is a recent log:
https://treeherder.mozilla.org/logviewer.html#?job_id=195524583&repo=mozilla-central&lineNumber=607

TEST-INFO | started process 7016 (C:\Users\task_1535033062\build\application\firefox\firefox http://localhost:49811/getInfo.html)
14:07:19    ERROR -  JavaScript error: resource:///modules/ProcessHangMonitor.jsm, line 412: TypeError: win.gBrowser is undefined
14:07:19     INFO -  console.error: "Could not getBaseDomain() for \"[xpconnect wrapped nsIURI]\"" ({})
14:07:20     INFO -  __metrics	Screen width/height:1280/1024
14:07:20     INFO -  	colorDepth:24
14:07:20     INFO -  	Browser inner width/height: 1280/910
14:07:20     INFO -  __metrics
14:07:20     INFO -  WebGL(000001ECDAFB3800)::ForceLoseContext
14:07:20     INFO -  WebGL(000001ECDAFB5800)::ForceLoseContext
14:07:20     INFO -  about:support	{"application":{"name":"Firefox","osVersion":"Windows_NT 10.0","version":"63.0a1","buildID":"20180823121641","userAgent":"Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:63.0) Gecko/20100101 Firefox/63.0","safeMode":false,"updateChannel":"default","supportURL":"https://support.mozilla.org/1/firefox/63.0a1/WINNT/en-US/","numTotalWindows":2,"numRemoteWindows":2,"remoteAutoStart":true,"currentContentProcesses":4,"maxContentProcesses":4,"autoStartStatus":1,"policiesStatus":0,"keyGoogleFound":true,"keyMozillaFound":true},"securitySoftware":{"registeredAntiVirus":"","registeredAntiSpyware":"","registeredFirewall":""},"modifiedPreferences":{"browser.cache.disk.filesystem_reported":1,"browser.cache.disk.smart_size.enabled":false,"browser.cache.disk.smart_size.first_run":false,"browser.link.open_newwindow":2,"browser.sessionstore.resume_from_crash":false,"browser.startup.homepage_override.mstone":"63.0a1","browser.startup.homepage_override.buildID":"20180823121641","browser.tabs.remote.autostart":true,"browser.tabs.warnOnClose":false,"browser.urlbar.placeholderName":"Google","browser.urlbar.userMadeSearchSuggestionsChoice":true,"dom.allow_scripts_to_close_windows":true,"dom.disable_open_during_load":false,"dom.disable_window_flip":true,"dom.disable_window_move_resize":true,"dom.forms.autocomplete.formautofill":true,"dom.max_chrome_script_run_time":0,"dom.max_script_run_time":0,"dom.performance.time_to_non_blank_paint.enabled":true,"dom.send_after_paint_to_content":true,"extensions.checkCompatibility":false,"extensions.lastAppVersion":"63.0a1","general.useragent.updates.enabled":false,"layers.mlgpu.sanity-test-failed":false,"media.allowed-to-play.enabled":true,"media.autoplay.ask-permission":false,"media.autoplay.block-webaudio":false,"media.autoplay.default":0,"media.autoplay.enabled.user-gestures-needed":true,"media.capturestream_hints.enabled":true,"media.gmp-manager.updateEnabled":false,"media.gmp-manager.url":"http://127.0.0.1/gmpmanager-dummy/update.xml","media.gmp.storage.version.observed":1,"media.hardware-video-decoding.failed":false,"media.libavcodec.allow-obsolete":true,"media.navigator.enabled":true,"media.navigator.permission.disabled":true,"media.peerconnection.enabled":true,"network.http.speculative-parallel-limit":0,"places.database.lastMaintenance":2147483647,"places.history.expiration.transient_current_max_pages":112348,"plugin.state.flash":0,"plugins.flashBlock.enabled":false,"privacy.sanitize.pending":"[{\"id\":\"newtab-container\",\"itemsToClear\":[],\"options\":{}}]","privacy.reduceTimerPrecision":false,"privacy.trackingprotection.annotate_channels":false,"privacy.trackingprotection.enabled":false,"privacy.trackingprotection.introURL":"http://127.0.0.1/trackingprotection/tour","privacy.trackingprotection.pbmode.enabled":false,"security.enable_java":false,"security.fileuri.strict_origin_policy":false,"security.notification_enable_delay":0,"security.sandbox.content.tempDirSuffix":"{4d9d7d60-b3c7-4913-80ef-4e132db6baa8}","security.turn_off_all_security_so_that_viruses_can_take_over_this_computer":true,"services.sync.engine.addresses.available":true,"services.sync.engine.creditcards.available":true},"lockedPreferences":{},"media":{"currentAudioBackend":"unknown","currentMaxAudioChannels":0,"currentPreferredSampleRate":44100,"audioOutputDevices":[],"audioInputDevices":[]},"javaScript":{"incrementalGCEnabled":true},"accessibility":{"isActive":false,"forceDisabled":0,"handlerUsed":false,"instantiator":""},"libraryVersions":{"NSPR":{"minVersion":"4.20 Beta","version":"4.20 Beta"},"NSS":{"minVersion":"3.39 Beta","version":"3.39 Beta"},"NSSUTIL":{"minVersion":"3.39 Beta","version":"3.39 Beta"},"NSSSSL":{"minVersion":"3.39 Beta","version":"3.39 Beta"},"NSSSMIME":{"minVersion":"3.39 Beta","version":"3.39 Beta"}},"userJS":{"exists":true},"intl":{"localeService":{"requested":["en-US"],"available":["en-US"],"supported":["en-US"],"regionalPrefs":["en-US"],"defaultLocale":"en-US"},"osPrefs":{"systemLocales":["en-US"],"regionalPrefsLocales":["en-US"]}},"crashes":{"submitted":[],"pending":0},"sandbox":{"contentSandboxLevel":5,"effectiveContentSandboxLevel":5},"graphics":{"numTotalWindows":3,"numAcceleratedWindows":3,"windowLayerManagerType":"Direct3D 11","windowLayerManagerRemote":true,"windowUsingAdvancedLayers":true,"adapterDescription":"Intel(R) Iris(R) Pro Graphics P580","adapterVendorID":"0x8086","adapterDeviceID":"0x193a","adapterSubsysID":"18a9103c","adapterRAM":"Unknown","adapterDrivers":"igdumdim64 igd10iumd64 igd10iumd64 igd12umd64 igdumdim32 igd10iumd32 igd10iumd32 igd12umd32","driverVersion":"22.20.16.4815","driverDate":"9-26-2017","adapterDescription2":"","adapterVendorID2":"","adapterDeviceID2":"","adapterSubsysID2":"","adapterRAM2":"","adapterDrivers2":"","driverVersion2":"","driverDate2":"","isGPU2Active":false,"direct2DEnabled":true,"directWriteEnabled":true,"directWriteVersion":"10.0.15063.0","usesTiling":false,"contentUsesTiling":false,"offMainThreadPaintEnabled":true,"offMainThreadPaintWorkerCount":4,"webgl1Renderer":"Google Inc. -- ANGLE (Intel(R) Iris(R) Pro Graphics P580 Direct3D11 vs_5_0 ps_5_0)","webgl1Version":"OpenGL ES 2.0 (ANGLE 2.1.0.ae3b5a6552ee)","webgl1DriverExtensions":"GL_ANGLE_client_arrays GL_ANGLE_depth_texture GL_ANGLE_explicit_context GL_ANGLE_explicit_context_gles1 GL_ANGLE_framebuffer_blit GL_ANGLE_framebuffer_multisample GL_ANGLE_instanced_arrays GL_ANGLE_lossy_etc_decode GL_ANGLE_pack_reverse_row_order GL_ANGLE_program_cache_control GL_ANGLE_request_extension GL_ANGLE_robust_client_memory GL_ANGLE_texture_compression_dxt3 GL_ANGLE_texture_compression_dxt5 GL_ANGLE_texture_usage GL_ANGLE_translated_shader_source GL_CHROMIUM_bind_generates_resource GL_CHROMIUM_bind_uniform_location GL_CHROMIUM_color_buffer_float_rgb GL_CHROMIUM_color_buffer_float_rgba GL_CHROMIUM_copy_compressed_texture GL_CHROMIUM_copy_texture GL_CHROMIUM_sync_query GL_EXT_blend_minmax GL_EXT_color_buffer_half_float GL_EXT_debug_marker GL_EXT_discard_framebuffer GL_EXT_disjoint_timer_query GL_EXT_draw_buffers GL_EXT_frag_depth GL_EXT_map_buffer_range GL_EXT_occlusion_query_boolean GL_EXT_read_format_bgra GL_EXT_robustness GL_EXT_sRGB GL_EXT_shader_texture_lod GL_EXT_texture_compression_dxt1 GL_EXT_texture_compression_s3tc_srgb GL_EXT_texture_filter_anisotropic GL_EXT_texture_format_BGRA8888 GL_EXT_texture_rg GL_EXT_texture_storage GL_EXT_unpack_subimage GL_KHR_debug GL_KHR_robust_buffer_access_behavior GL_NV_EGL_stream_consumer_external GL_NV_fence GL_NV_pack_subimage GL_NV_pixel_buffer_object GL_OES_EGL_image GL_OES_EGL_image_external GL_OES_compressed_ETC1_RGB8_texture GL_OES_depth32 GL_OES_element_index_uint GL_OES_get_program_binary GL_OES_mapbuffer GL_OES_packed_depth_stencil GL_OES_rgb8_rgba8 GL_OES_standard_derivatives GL_OES_surfaceless_context GL_OES_texture_float GL_OES_texture_float_linear GL_OES_texture_half_float GL_OES_texture_half_float_linear GL_OES_texture_npot GL_OES_vertex_array_object OES_compressed_EAC_R11_signed_texture OES_compressed_EAC_R11_unsigned_texture OES_compressed_EAC_RG11_signed_texture OES_compressed_EAC_RG11_unsigned_texture OES_compressed_ETC2_RGB8_texture OES_compressed_ETC2_RGBA8_texture OES_compressed_ETC2_punchthroughA_RGBA8_texture OES_compressed_ETC2_punchthroughA_sRGB8_alpha_texture OES_compressed_ETC2_sRGB8_alpha8_texture OES_compressed_ETC2_sRGB8_texture ","webgl1Extensions":"ANGLE_instanced_arrays EXT_blend_minmax EXT_color_buffer_half_float EXT_frag_depth EXT_sRGB EXT_shader_texture_lod EXT_texture_filter_anisotropic EXT_disjoint_timer_query OES_element_index_uint OES_standard_derivatives OES_texture_float OES_texture_float_linear OES_texture_half_float OES_texture_half_float_linear OES_vertex_array_object WEBGL_color_buffer_float WEBGL_compressed_texture_s3tc WEBGL_compressed_texture_s3tc_srgb WEBGL_debug_renderer_info WEBGL_debug_shaders WEBGL_depth_texture WEBGL_draw_buffers WEBGL_lose_context","webgl1WSIInfo":"EGL_VENDOR: Google Inc. (adapter LUID: 000000000000484f)\nEGL_VERSION: 1.4 (ANGLE 2.1.0.ae3b5a6552ee)\nEGL_EXTENSIONS: EGL_EXT_create_context_robustness EGL_ANGLE_d3d_share_handle_client_buffer EGL_ANGLE_d3d_texture_client_buffer EGL_ANGLE_surface_d3d_texture_2d_share_handle EGL_ANGLE_query_surface_pointer EGL_ANGLE_window_fixed_size EGL_ANGLE_keyed_mutex EGL_ANGLE_surface_orientation EGL_ANGLE_direct_composition EGL_NV_post_sub_buffer EGL_KHR_create_context EGL_EXT_device_query EGL_KHR_image EGL_KHR_image_base EGL_KHR_gl_texture_2D_image EGL_KHR_gl_texture_cubemap_image EGL_KHR_gl_renderbuffer_image EGL_KHR_get_all_proc_addresses EGL_KHR_stream EGL_KHR_stream_consumer_gltexture EGL_NV_stream_consumer_gltexture_yuv EGL_ANGLE_flexible_surface_compatibility EGL_ANGLE_stream_producer_d3d_texture EGL_ANGLE_create_context_webgl_compatibility EGL_CHROMIUM_create_context_bind_generates_resource EGL_CHROMIUM_sync_control EGL_EXT_pixel_format_float EGL_KHR_surfaceless_context EGL_ANGLE_display_texture_share_group EGL_ANGLE_create_context_client_arrays EGL_ANGLE_program_cache_control EGL_ANGLE_robust_resource_initialization EGL_ANGLE_create_context_extensions_enabled \nEGL_EXTENSIONS(nullptr): EGL_EXT_client_extensions EGL_EXT_platform_base EGL_EXT_platform_device EGL_ANGLE_platform_angle EGL_ANGLE_platform_angle_d3d EGL_ANGLE_device_creation EGL_ANGLE_device_creation_d3d11 EGL_ANGLE_experimental_present_path EGL_KHR_client_get_all_proc_addresses EGL_ANGLE_explicit_context ","webgl2Renderer":"Google Inc. -- ANGLE (Intel(R) Iris(R) Pro Graphics P580 Direct3D11 vs_5_0 ps_5_0)","webgl2Version":"OpenGL ES 3.0 (ANGLE 2.1.0.ae3b5a6552ee)","webgl2DriverExtensions":"GL_ANGLE_client_arrays GL_ANGLE_depth_texture GL_ANGLE_explicit_context GL_ANGLE_explicit_context_gles1 GL_ANGLE_framebuffer_blit GL_ANGLE_framebuffer_multisample GL_ANGLE_instanced_arrays GL_ANGLE_lossy_etc_decode GL_ANGLE_multiview GL_ANGLE_pack_reverse_row_order GL_ANGLE_program_cache_control GL_ANGLE_request_extension GL_ANGLE_robust_client_memory GL_ANGLE_texture_compression_dxt3 GL_ANGLE_texture_compression_dxt5 GL_ANGLE_texture_usage GL_ANGLE_translated_shader_source GL_CHROMIUM_bind_generates_resource GL_CHROMIUM_bind_uniform_location GL_CHROMIUM_color_buffer_float_rgb GL_CHROMIUM_color_buffer_float_rgba GL_CHROMIUM_copy_compressed_texture GL_CHROMIUM_copy_texture GL_CHROMIUM_sync_query GL_EXT_blend_minmax GL_EXT_color_buffer_float GL_EXT_color_buffer_half_float GL_EXT_debug_marker GL_EXT_discard_framebuffer GL_EXT_disjoint_timer_query GL_EXT_draw_buffers GL_EXT_frag_depth GL_EXT_map_buffer_range GL_EXT_occlusion_query_boolean GL_EXT_read_format_bgra GL_EXT_robustness GL_EXT_sRGB GL_EXT_shader_texture_lod GL_EXT_texture_compression_dxt1 GL_EXT_texture_compression_s3tc_srgb GL_EXT_texture_filter_anisotropic GL_EXT_texture_format_BGRA8888 GL_EXT_texture_norm16 GL_EXT_texture_rg GL_EXT_texture_storage GL_EXT_unpack_subimage GL_KHR_debug GL_KHR_robust_buffer_access_behavior GL_NV_EGL_stream_consumer_external GL_NV_fence GL_NV_pack_subimage GL_NV_pixel_buffer_object GL_OES_EGL_image GL_OES_EGL_image_external GL_OES_EGL_image_external_essl3 GL_OES_compressed_ETC1_RGB8_texture GL_OES_depth32 GL_OES_element_index_uint GL_OES_get_program_binary GL_OES_mapbuffer GL_OES_packed_depth_stencil GL_OES_rgb8_rgba8 GL_OES_standard_derivatives GL_OES_surfaceless_context GL_OES_texture_float GL_OES_texture_float_linear GL_OES_texture_half_float GL_OES_texture_half_float_linear GL_OES_texture_npot GL_OES_vertex_array_object OES_compressed_EAC_R11_signed_texture OES_compressed_EAC_R11_unsigned_texture OES_compressed_EAC_RG11_signed_texture OES_compressed_EAC_RG11_unsigned_texture OES_compressed_ETC2_RGB8_texture OES_compressed_ETC2_RGBA8_texture OES_compressed_ETC2_punchthroughA_RGBA8_texture OES_compressed_ETC2_punchthroughA_sRGB8_alpha_texture OES_compressed_ETC2_sRGB8_alpha8_texture OES_compressed_ETC2_sRGB8_texture ","webgl2Extensions":"EXT_color_buffer_float EXT_texture_filter_anisotropic EXT_disjoint_timer_query OES_texture_float_linear WEBGL_compressed_texture_s3tc WEBGL_compressed_texture_s3tc_srgb WEBGL_debug_renderer_info WEBGL_debug_shaders WEBGL_lose_context","webgl2WSIInfo":"EGL_VENDOR: Google Inc. (adapter LUID: 000000000000484f)\nEGL_VERSION: 1.4 (ANGLE 2.1.0.ae3b5a6552ee)\nEGL_EXTENSIONS: EGL_EXT_create_context_robustness EGL_ANGLE_d3d_share_handle_client_buffer EGL_ANGLE_d3d_texture_client_buffer EGL_ANGLE_surface_d3d_texture_2d_share_handle EGL_ANGLE_query_surface_pointer EGL_ANGLE_window_fixed_size EGL_ANGLE_keyed_mutex EGL_ANGLE_surface_orientation EGL_ANGLE_direct_composition EGL_NV_post_sub_buffer EGL_KHR_create_context EGL_EXT_device_query EGL_KHR_image EGL_KHR_image_base EGL_KHR_gl_texture_2D_image EGL_KHR_gl_texture_cubemap_image EGL_KHR_gl_renderbuffer_image EGL_KHR_get_all_proc_addresses EGL_KHR_stream EGL_KHR_stream_consumer_gltexture EGL_NV_stream_consumer_gltexture_yuv EGL_ANGLE_flexible_surface_compatibility EGL_ANGLE_stream_producer_d3d_texture EGL_ANGLE_create_context_webgl_compatibility EGL_CHROMIUM_create_context_bind_generates_resource EGL_CHROMIUM_sync_control EGL_EXT_pixel_format_float EGL_KHR_surfaceless_context EGL_ANGLE_display_texture_share_group EGL_ANGLE_create_context_client_arrays EGL_ANGLE_program_cache_control EGL_ANGLE_robust_resource_initialization EGL_ANGLE_create_context_extensions_enabled \nEGL_EXTENSIONS(nullptr): EGL_EXT_client_extensions EGL_EXT_platform_base EGL_EXT_platform_device EGL_ANGLE_platform_angle EGL_ANGLE_platform_angle_d3d EGL_ANGLE_device_creation EGL_ANGLE_device_creation_d3d11 EGL_ANGLE_experimental_present_path EGL_KHR_client_get_all_proc_addresses EGL_ANGLE_explicit_context ","info":{"AzureCanvasBackend (UI Process)":"skia","AzureFallbackCanvasBackend (UI Process)":"cairo","AzureContentBackend (UI Process)":"skia","AzureCanvasBackend":"direct2d 1.1","AzureContentBackend":"direct2d 1.1","AzureCanvasAccelerated":0,"ApzWheelInput":1,"ApzDragInput":1,"ApzKeyboardInput":1,"ApzAutoscrollInput":1},"featureLog":{"features":[{"name":"HW_COMPOSITING","description":"Compositing","status":"available","log":[{"type":"default","status":"available"}]},{"name":"D3D11_COMPOSITING","description":"Direct3D11 Compositing","status":"available","log":[{"type":"default","status":"available"}]},{"name":"DIRECT2D","description":"Direct2D","status":"available","log":[{"type":"default","status":"available"}]},{"name":"D3D11_HW_ANGLE","description":"Direct3D11 hardware ANGLE","status":"available","log":[{"type":"default","status":"available"}]},{"name":"GPU_PROCESS","description":"GPU Process","status":"available","log":[{"type":"default","status":"available"}]},{"name":"WEBRENDER","description":"WebRender","status":"opt-in","log":[{"type":"default","status":"opt-in","message":"WebRender is an opt-in feature"}]},{"name":"WEBRENDER_QUALIFIED","description":"WebRender qualified","status":"blocked","log":[{"type":"default","status":"available"},{"type":"env","status":"blocked","message":"No qualified hardware"}]},{"name":"OMTP","description":"Off Main Thread Painting","status":"available","log":[{"type":"default","status":"available"}]},{"name":"ADVANCED_LAYERS","description":"Advanced Layers","status":"available","log":[{"type":"default","status":"available"}]}],"fallbacks":[]},"crashGuards":[]},"extensions":[{"name":"PageLoader extension","version":"1.0.32","isActive":true,"id":"pageloader@mozilla.org"},{"name":"Talos Powers","version":"1.0.14","isActive":true,"id":"talos-powers@mozilla.org"}],"features":[{"name":"Application Update Service Helper","version":"2.0","id":"aushelper@mozilla.org"},{"name":"Firefox Screenshots","version":"33.0.0","id":"screenshots@mozilla.org"},{"name":"Form Autofill","version":"1.0","id":"formautofill@mozilla.org"},{"name":"Photon onboarding","version":"1.0","id":"onboarding@mozilla.org"},{"name":"Pocket","version":"1.0.5","id":"firefox@getpocket.com"},{"name":"Web Compat","version":"2.0.1","id":"webcompat@mozilla.org"},{"name":"WebCompat Reporter","version":"1.0.0","id":"webcompat-reporter@mozilla.org"}]}[Parent 7016, Gecko_IOThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346
14:07:20     INFO -  [Child 1044, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346
14:07:20     INFO -  [Child 1044, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346
14:07:20     INFO -  [Child 6432, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346
14:07:20     INFO -  [Child 6432, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346
14:07:20     INFO -  [Child 5552, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346
14:07:20     INFO -  [Child 5552, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346
14:07:20     INFO -  [Child 7032, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346
14:07:20     INFO -  [Child 7032, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346
14:07:20     INFO -  ###!!! [Child][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
14:07:20     INFO -  [GPU 6648, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346
14:07:20     INFO -  ###!!! [Child][MessageChannel::SendAndWait] Error: Channel error: cannot send/recv
14:07:20     INFO -  TEST-INFO | 7016: exit 0
Update:
There have been 113 failures in the last 7 days and 196 failures in the last 21 days.
Most of the failures occur on the opt the build type, with some exceptions for pgo and debug.
Failures per platform:
- osx-10-10: 56
- windows7-32: 23
- windows10-64: 14
- windows10-64-qr: 14
- linux64: 3
- windows10-64-nightly: 1
- windows7-32-msvc: 1
- macosx64-qr: 1

Recent relevant log file:
https://treeherder.mozilla.org/logviewer.html#?job_id=196987186&repo=mozilla-inbound&lineNumber=677

Summary: talos performance (tp5o_webext, tp6_google, tp6_youtube, ...)about_preferences_basic,dromaeo_css,ts_paint_webext,a11yr,tp5o| Aborting task - max run time exceeded!
Summary: talos performance (tp5o_webext, tp6_google, tp6_youtube, ...)about_preferences_basic,dromaeo_css,ts_paint_webext,a11yr,tp5o| Aborting task - max run time exceeded! → Intermittent Talos [taskcluster:error] Task aborted - max run time exceeded
There have been 34 failures in the last week
Summary: Intermittent Talos [taskcluster:error] Task aborted - max run time exceeded

Recent relevant log file:
https://treeherder.mozilla.org/logviewer.html#?job_id=198530068&repo=autoland&lineNumber=677

Failures per platform and build type:

- osx-10-10 / opt: 25
- windows7-32 / pgo: 5
- windows10-64-qr / opt: 2
- linux64 / pgo: 1
- macosx64-nightly / opt: 1
There is a total of 54 failures in the last 7 days.

Recent failure log: https://treeherder.mozilla.org/logviewer.html#?job_id=200056926&repo=mozilla-inbound&lineNumber=637

00:24:08     INFO -  127.0.0.1:50733: clientconnect
00:24:08     INFO -  server_playback: killed non-replay request https://aus5.mozilla.org/update/6/Firefox/64.0a1/20180918223402/WINNT_x86-msvc-x64/en-US/default/Windows_NT%2010.0.0.0.15063.0%20(x64)/ISET:SSE4_2,MEM:16253/default/default/update.xml
00:24:08     INFO -  127.0.0.1:50733: GET https://aus5.mozilla.org/update/6/Firefox/64.0a1/20180918223402/WINNT_x86-msvc-x64/en-US/default/Windows_NT%2010.0.0.0.15063.0%20(x64)/ISET:SSE4_2,MEM:16253/default/default/update.xml
00:24:08     INFO -                << 404 Not Found 0b
00:24:33     INFO -  127.0.0.1:50055: clientdisconnect
00:24:33     INFO -  127.0.0.1:50100: HTTP/2 connection terminated by client: error code: 0, last stream id: 0, additional data: None
00:24:33     INFO -  127.0.0.1:50100: clientdisconnect
00:24:34     INFO -  127.0.0.1:50735: clientconnect
00:24:34     INFO -  server_playback: killed non-replay request https://push.services.mozilla.com/
00:24:34     INFO -  127.0.0.1:50735: GET https://push.services.mozilla.com/
00:24:34     INFO -                << 404 Not Found 0b
00:24:34     INFO -  127.0.0.1:50735: clientdisconnect
00:24:41     INFO -  127.0.0.1:50066: HTTP/2 connection terminated by server: error code: 0, last stream id: 0, additional data: None
00:24:41     INFO -  127.0.0.1:50066: clientdisconnect
00:24:42     INFO -  127.0.0.1:50074: HTTP/2 connection terminated by server: error code: 0, last stream id: 0, additional data: None
00:24:42     INFO -  127.0.0.1:50074: clientdisconnect
00:24:42     INFO -  127.0.0.1:50079: HTTP/2 connection terminated by server: error code: 0, last stream id: 0, additional data: None
00:24:42     INFO -  127.0.0.1:50079: clientdisconnect
00:24:56     INFO -  127.0.0.1:50092: HTTP/2 connection terminated by client: error code: 0, last stream id: 0, additional data: None
00:24:56     INFO -  127.0.0.1:50092: clientdisconnect
00:24:57     INFO -  127.0.0.1:50701: HTTP/2 connection terminated by client: error code: 0, last stream id: 0, additional data: None
00:24:57     INFO -  127.0.0.1:50701: clientdisconnect
00:26:03     INFO -  127.0.0.1:50733: clientdisconnect
00:27:14     INFO -  127.0.0.1:50769: clientconnect
00:27:14     INFO -  server_playback: killed non-replay request https://push.services.mozilla.com/
00:27:14     INFO -  127.0.0.1:50769: GET https://push.services.mozilla.com/
00:27:14     INFO -                << 404 Not Found 0b
00:27:14     INFO -  127.0.0.1:50769: clientdisconnect
00:32:34     INFO -  127.0.0.1:50934: clientconnect
00:32:34     INFO -  server_playback: killed non-replay request https://push.services.mozilla.com/
00:32:34     INFO -  127.0.0.1:50934: GET https://push.services.mozilla.com/
00:32:34     INFO -                << 404 Not Found 0b
00:32:34     INFO -  127.0.0.1:50934: clientdisconnect
[taskcluster:error] Aborting task...
[taskcluster 2018-09-19T00:37:17.163Z] SUCCESS: The process with PID 7340 (child process of PID 7916) has been terminated.
[taskcluster 2018-09-19T00:37:17.163Z] SUCCESS: The process with PID 748 (child process of PID 5392) has been terminated.
[taskcluster 2018-09-19T00:37:17.163Z] SUCCESS: The process with PID 2708 (child process of PID 5392) has been terminated.
[taskcluster 2018-09-19T00:37:17.163Z] SUCCESS: The process with PID 6504 (child process of PID 5392) has been terminated.
[taskcluster 2018-09-19T00:37:17.163Z] SUCCESS: The process with PID 7916 (child process of PID 4344) has been terminated.
[taskcluster 2018-09-19T00:37:17.163Z] SUCCESS: The process with PID 5392 (child process of PID 4344) has been terminated.
[taskcluster 2018-09-19T00:37:17.163Z] SUCCESS: The process with PID 2928 (child process of PID 2864) has been terminated.
[taskcluster 2018-09-19T00:37:17.163Z] SUCCESS: The process with PID 4344 (child process of PID 2864) has been terminated.
[taskcluster 2018-09-19T00:37:17.163Z] SUCCESS: The process with PID 6844 (child process of PID 4756) has been terminated.
[taskcluster 2018-09-19T00:37:17.163Z] SUCCESS: The process with PID 2864 (child process of PID 4756) has been terminated.
[taskcluster 2018-09-19T00:37:17.163Z] SUCCESS: The process with PID 4756 (child process of PID 2788) has been terminated.
[taskcluster 2018-09-19T00:37:17.163Z] 
[taskcluster 2018-09-19T00:37:17.163Z] === Task Finished ===
[taskcluster 2018-09-19T00:37:17.163Z] Task Duration: 19m56.193624s
[taskcluster 2018-09-19T00:37:18.060Z] Uploading artifact public/logs/localconfig.json from file logs\localconfig.json with content encoding "gzip", mime type "application/octet-stream" and expiry 2019-09-18T22:35:57.189Z
[taskcluster 2018-09-19T00:37:18.617Z] Uploading artifact public/logs/talos_critical.log from file logs\talos_critical.log with content encoding "gzip", mime type "text/plain" and expiry 2019-09-18T22:35:57.189Z
[taskcluster 2018-09-19T00:37:19.007Z] Uploading artifact public/logs/talos_error.log from file logs\talos_error.log with content encoding "gzip", mime type "text/plain" and expiry 2019-09-18T22:35:57.189Z
[taskcluster 2018-09-19T00:37:19.440Z] Uploading artifact public/logs/talos_fatal.log from file logs\talos_fatal.log with content encoding "gzip", mime type "text/plain" and expiry 2019-09-18T22:35:57.189Z
[taskcluster 2018-09-19T00:37:19.876Z] Uploading artifact public/logs/talos_info.log from file logs\talos_info.log with content encoding "gzip", mime type "text/plain" and expiry 2019-09-18T22:35:57.189Z
[taskcluster 2018-09-19T00:37:20.455Z] Uploading artifact public/logs/talos_raw.log from file logs\talos_raw.log with content encoding "gzip", mime type "text/plain" and expiry 2019-09-18T22:35:57.189Z
[taskcluster 2018-09-19T00:37:20.969Z] Uploading artifact public/logs/talos_warning.log from file logs\talos_warning.log with content encoding "gzip", mime type "text/plain" and expiry 2019-09-18T22:35:57.189Z
[taskcluster 2018-09-19T00:37:21.438Z] Uploading artifact public/test_info/tp6-e10s_errorsummary.log from file build\blobber_upload_dir\tp6-e10s_errorsummary.log with content encoding "gzip", mime type "text/plain" and expiry 2019-09-18T22:35:57.189Z
[taskcluster 2018-09-19T00:37:21.859Z] Uploading artifact public/test_info/tp6-e10s_raw.log from file build\blobber_upload_dir\tp6-e10s_raw.log with content encoding "gzip", mime type "text/plain" and expiry 2019-09-18T22:35:57.189Z
[taskcluster 2018-09-19T00:37:22.492Z] Uploading redirect artifact public/logs/live.log to URL https://queue.taskcluster.net/v1/task/S2g5ry94TrqrMCFKP20fDQ/runs/0/artifacts/public/logs/live_backing.log with mime type "text/plain; charset=utf-8" and expiry 2019-09-18T22:35:57.189Z
[taskcluster:error] Task aborted - max run time exceeded
There are 52 failures in the last 7 days.
They occur mostly on osx-10-10 (opt), and the rest of them on windows10-64, windows7-32, linux64-qr all on opt build type.
Recent failure log: https://treeherder.mozilla.org/logviewer.html#?job_id=202137150&repo=mozilla-central&lineNumber=904
In the last 7 days there are 56 failures, most on OS X 10, some on Windows 7, Windows 10 64, Linux 64, most on Opt.
There are 37 failures in the last 7 days.
They occur on osx-10-10 (opt), linux64 (opt, pgo), windows10-64 (opt, pgo), windows7-32 (opt, pgo).
Recent failure log: https://treeherder.mozilla.org/logviewer.html#?job_id=209018842&repo=mozilla-central&lineNumber=980
There are 44 failures in the past week for this bug.
A spike in failures can be seen around 4th of Nov.
The failures are on linux64, linux64-qr, osx-10-10 and windows7-32 platforms.

Recent log: https://treeherder.mozilla.org/logviewer.html#?job_id=210667879&repo=autoland&lineNumber=709
Failure rate seems to be increasing here again from the 16th

Recent failure log: https://treeherder.mozilla.org/logviewer.html#?job_id=212778814&repo=autoland&lineNumber=1413
Whiteboard: [stockwell fixed:backout][stockwell needswork] → [stockwell fixed:backout][stockwell needswork:owner]
There are 26 total failures in the last 7 days.

Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=214926697&repo=autoland&lineNumber=698

Robert are there updates here?
There are 32 failures asociated to this bug in the last 7 days. These are occurring mostly on OSX opt builds.

:rwood can you take a look.
There are 131 total failures in the last 31 days, majority on osx-10-10 opt, linux64 (opt, pgo) and linux64-qr opt.

Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=219454999&repo=autoland&lineNumber=1422

14:52:54     INFO -  127.0.0.1:50361: POST https://www.google.ca/gen_204?atyp=i&ct=slh&cad=&ei=FAY3WeO-PMLcjAPuvZgI&m=HV&t=C&s=23&v=2&pv=0.814914228582382&me=1:1546296662736,x:4,V,0,0,1024,694:0,N,1,FAY3WeO-PMLcjAPuvZgI:0,R,1,3,13,22,120,47:0,R,1,36,166,175,600,342:0,R,1,37,166,205,600,288:0,R,1,38,146,205,640,288:0,R,1,55,166,557,600,76:0,R,1,61,166,659,600,98:0,R,1,120,820,175,248,1019:0,R,1,121,822,175,278,1001:0,R,1,125,822,175,278,153:0,R,1,144,822,340,278,56:0,R,1,155,822,412,278,41:0,R,1,157,822,467,278,81:0,R,1,158,837,467,248,81:0,R,1,161,822,561,278,48:0,R,1,165,822,616,278,16:0,R,1,168,822,639,278,16:0,R,1,172,822,662,278,16:0,R,1,177,822,685,278,32:1,B,2040:603,e,H&zx=1546296774061 HTTP/2.0
14:52:54     INFO -                << 404 Not Found 0b
14:52:56     INFO -  127.0.0.1:50392: clientconnect
14:52:56     INFO -  server_playback: killed non-replay request https://aus5.mozilla.org/update/6/Firefox/66.0a1/20181231212934/Darwin_x86_64-gcc3/en-US/default/Darwin%2014.5.0/ISET:SSE4_2,MEM:16384/default/default/update.xml
14:52:56     INFO -  127.0.0.1:50392: GET https://aus5.mozilla.org/update/6/Firefox/66.0a1/20181231212934/Darwin_x86_64-gcc3/en-US/default/Darwin%2014.5.0/ISET:SSE4_2,MEM:16384/default/default/update.xml
14:52:56     INFO -                << 404 Not Found 0b
14:53:21     INFO -  127.0.0.1:50357: clientdisconnect

14:53:21     INFO -  127.0.0.1:50363: HTTP/2 connection terminated by client: error code: 0, last stream id: 0, additional data: None
14:53:21     INFO -  127.0.0.1:50365: HTTP/2 connection terminated by client: error code: 0, last stream id: 0, additional data: None
14:53:21     INFO -  127.0.0.1:50363: clientdisconnect
14:53:21     INFO -  127.0.0.1:50365: clientdisconnect
14:53:22     INFO -  127.0.0.1:50369: HTTP/2 connection terminated by client: error code: 0, last stream id: 0, additional data: None
14:53:22     INFO -  127.0.0.1:50369: clientdisconnect
14:53:23     INFO -  127.0.0.1:50394: clientconnect
14:53:23     INFO -  server_playback: killed non-replay request https://push.services.mozilla.com/
14:53:23     INFO -  127.0.0.1:50394: GET https://push.services.mozilla.com/
14:53:23     INFO -                << 404 Not Found 0b
14:53:23     INFO -  127.0.0.1:50394: clientdisconnect
14:53:53     INFO -  127.0.0.1:50359: HTTP/2 connection terminated by client: error code: 0, last stream id: 0, additional data: None
14:53:53     INFO -  127.0.0.1:50359: clientdisconnect
14:53:54     INFO -  127.0.0.1:50367: HTTP/2 connection terminated by client: error code: 0, last stream id: 0, additional data: None
14:53:54     INFO -  127.0.0.1:50367: clientdisconnect
14:53:55     INFO -  127.0.0.1:50379: HTTP/2 connection terminated by client: error code: 0, last stream id: 0, additional data: None
14:53:55     INFO -  127.0.0.1:50379: clientdisconnect
14:54:30     INFO -  127.0.0.1:50361: HTTP/2 connection terminated by server: error code: 0, last stream id: 0, additional data: b'session_timed_out'
14:54:30     INFO -  127.0.0.1:50361: clientdisconnect
14:54:51     INFO -  127.0.0.1:50392: clientdisconnect
14:56:03     INFO -  127.0.0.1:50400: clientconnect
14:56:04     INFO -  server_playback: killed non-replay request https://push.services.mozilla.com/
14:56:04     INFO -  127.0.0.1:50400: GET https://push.services.mozilla.com/
14:56:04     INFO -                << 404 Not Found 0b
14:56:04     INFO -  127.0.0.1:50400: clientdisconnect
14:58:56     INFO -  127.0.0.1:50408: clientconnect
14:58:56     INFO -  127.0.0.1:50408: HTTP protocol error in client request: Invalid HTTP request form (expected: authority or absolute, got: relative)
14:58:56     INFO -  127.0.0.1:50408: clientdisconnect
15:01:24     INFO -  127.0.0.1:50409: clientconnect
15:01:24     INFO -  server_playback: killed non-replay request https://push.services.mozilla.com/
15:01:24     INFO -  127.0.0.1:50409: GET https://push.services.mozilla.com/
15:01:24     INFO -                << 404 Not Found 0b
15:01:24     INFO -  127.0.0.1:50409: clientdisconnect
[taskcluster:error] Aborting task...
[taskcluster 2018-12-31T23:08:33.592Z] === Task Finished ===
[taskcluster 2018-12-31T23:08:33.592Z] Task Duration: 19m59.46594872s
[taskcluster 2018-12-31T23:08:34.123Z] Uploading artifact public/logs/localconfig.json from file logs/localconfig.json with content encoding "gzip", mime type "application/json" and expiry 2019-12-31T21:31:46.159Z
[taskcluster 2018-12-31T23:08:34.856Z] Uploading artifact public/logs/talos_critical.log from file logs/talos_critical.log with content encoding "gzip", mime type "text/plain" and expiry 2019-12-31T21:31:46.159Z
[taskcluster 2018-12-31T23:08:35.277Z] Uploading artifact public/logs/talos_error.log from file logs/talos_error.log with content encoding "gzip", mime type "text/plain" and expiry 2019-12-31T21:31:46.159Z
[taskcluster 2018-12-31T23:08:35.659Z] Uploading artifact public/logs/talos_fatal.log from file logs/talos_fatal.log with content encoding "gzip", mime type "text/plain" and expiry 2019-12-31T21:31:46.159Z
[taskcluster 2018-12-31T23:08:36.071Z] Uploading artifact public/logs/talos_info.log from file logs/talos_info.log with content encoding "gzip", mime type "text/plain" and expiry 2019-12-31T21:31:46.159Z
[taskcluster 2018-12-31T23:08:36.971Z] Uploading artifact public/logs/talos_raw.log from file logs/talos_raw.log with content encoding "gzip", mime type "text/plain" and expiry 2019-12-31T21:31:46.159Z
[taskcluster 2018-12-31T23:08:37.652Z] Uploading artifact public/logs/talos_warning.log from file logs/talos_warning.log with content encoding "gzip", mime type "text/plain" and expiry 2019-12-31T21:31:46.159Z
[taskcluster 2018-12-31T23:08:38.076Z] Uploading artifact public/test_info/tp6-stylo-threads-e10s_errorsummary.log from file build/blobber_upload_dir/tp6-stylo-threads-e10s_errorsummary.log with content encoding "gzip", mime type "text/plain" and expiry 2019-12-31T21:31:46.159Z
[taskcluster 2018-12-31T23:08:38.481Z] Uploading artifact public/test_info/tp6-stylo-threads-e10s_raw.log from file build/blobber_upload_dir/tp6-stylo-threads-e10s_raw.log with content encoding "gzip", mime type "text/plain" and expiry 2019-12-31T21:31:46.159Z
[taskcluster:error] Task aborted - max run time exceeded

Joel, is there anything more we can do to help here?
Flags: needinfo?(jmaher)
this is osx and linux, specifically tp6-stylo-threads.  In the last 4 days (60 commits) on autoland there are 34 instances of this test run on osx and 8 failures, that is a 23.5% failure rate

:rwood, can we revisit turning off tp6-stylo-threads?  We ship with stylo by default?  Do we need this on all platforms as we don't even run this on windows.  Are there regressions found with this?  we don't have anything to compare this against as tp6 on raptor measures 100% different pagesets and metrics.
Flags: needinfo?(jmaher)
Whiteboard: [stockwell fixed:backout][stockwell needswork:owner] → [stockwell needswork:owner]

There are 32 failures associated to this bug in the last 7 days. These are occurring on all platform mainly opt builds.

:rwood can you take a look at this?

In the last 7 days, there are 30 failures. They occur mostly on linux64 opt and osx-10-10 opt.
Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=223458181&repo=autoland&lineNumber=921

This bug has failed 56 times in the last 7 days, Occurs on linux64, osx-10-10, windows10-64 on pgo and opt build types.

Recent log:
https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=224633772&repo=mozilla-inbound&lineNumber=772

rwood: Any update on this bug?

In the last 7 days there has been 1 failure.

Whiteboard: [stockwell disable-recommended]
Flags: needinfo?(rwood)

Hey :bebe can you please as someone on the SV team to have a look at this again? There must be a few other places maybe where we need to extend the taskcluster max job time? Or maybe there are other legit failures here that are just not being caught and causing the max run time to be reached. Thanks!

Flags: needinfo?(fstrugariu)

Several of the most recent windows-7 and windows-10 failures appear to be hangs: There is no test output for 20+ minutes before the task is aborted. Successful tasks usually complete in about 10 minutes, so the existing max-run-time seems appropriate.

From looking at the stack traces it looks like this suite hangs while loading tablemutation.htm at different cycles.

As this is a consistent failure point in this test I would suggest someone with better knowledge of this test to take a look.
Ionut maybe you can help

Flags: needinfo?(fstrugariu) → needinfo?(igoldan)

(In reply to Florin Strugariu [:Bebe] (needinfo me) from comment #170)

From looking at the stack traces it looks like this suite hangs while loading tablemutation.htm at different cycles.

As this is a consistent failure point in this test I would suggest someone with better knowledge of this test to take a look.
Ionut maybe you can help

Will take a look.

Flags: needinfo?(igoldan)
Assignee: nobody → igoldan
Priority: P5 → P2

(In reply to Intermittent Failures Robot from comment #171)

Platform breakdown:

  • windows7-32-shippable: 13
  • windows10-64-shippable-qr: 6
  • linux64-shippable-qr: 1
  • android-hw-p2-8-0-android-aarch64: 1

The Android regression originates from Raptor, not Talos. Am I right, Narcis?

Flags: needinfo?(nbeleuzu)

(In reply to Ionuț Goldan [:igoldan], Performance Sheriff from comment #173)

(In reply to Intermittent Failures Robot from comment #171)

Platform breakdown:

  • windows7-32-shippable: 13
  • windows10-64-shippable-qr: 6
  • linux64-shippable-qr: 1
  • android-hw-p2-8-0-android-aarch64: 1

The Android regression originates from Raptor, not Talos. Am I right, Narcis?

Yes, that is correct.

Flags: needinfo?(nbeleuzu)

Bugbug thinks this bug is a regression, but please revert this change in case of error.

Keywords: regression
Depends on: 1593818

:igoldan - It looks like most of these failures are being reported against bug 1589796 now. If you like, close this bug, duping it against 1589796.

Flags: needinfo?(igoldan)

(In reply to Geoff Brown [:gbrown] from comment #185)

:igoldan - It looks like most of these failures are being reported against bug 1589796 now. If you like, close this bug, duping it against 1589796.

Sure thing. Thanks!

Flags: needinfo?(igoldan)
Status: NEW → RESOLVED
Closed: 4 years ago
Resolution: --- → DUPLICATE
You need to log in before you can comment on or make changes to this bug.