1460782 - Perma JavaScript error: resource://gre/modules/addons/XPIProvider.jsm -> jar:file:///home/cltbld/workspace/build/application/firefox/browser/features/[e-mail]!/bootstrap.js, line 33: TypeError: NetworkError

Status: RESOLVED FIXED

(Firefox :: New Tab Page, defect, P1)

Description

[Treeherder Bug Filer]

Filed by: dluca [at] mozilla.com

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

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

Comment 1

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

This spams the log but is not fatal:

16:41:55     INFO -  TEST-START | tp6_google
16:41:55     INFO -  Initialising browser for tp6_google test...
16:41:55     INFO -  Cloning profile located at /home/cltbld/workspace/build/tests/talos/talos/base_profile
16:41:55     INFO -  Installing Add-ons:
16:41:55     INFO -  ['/home/cltbld/workspace/build/tests/talos/talos/talos-powers', '/home/cltbld/workspace/build/tests/talos/talos/pageloader']
16:41:55     INFO -  Application command: /home/cltbld/workspace/build/application/firefox/firefox  http://localhost:32875/getInfo.html -profile /tmp/tmp5A0pA_/profile
16:41:55     INFO -  TEST-INFO | started process 17976 (/home/cltbld/workspace/build/application/firefox/firefox  http://localhost:32875/getInfo.html)
16:41:57     INFO -  __metrics	Screen width/height:1600/1200
16:41:57     INFO -  	colorDepth:24
16:41:57     INFO -  	Browser inner width/height: 1280/966
16:41:57     INFO -  __metrics
16:41:57     INFO -  1525995717311	addons.xpi	WARN	Exception running bootstrap method shutdown on [e-mail]: [Exception... "Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIObserverService.removeObserver]"  nsresult: "0x80004005 (NS_ERROR_FAILURE)"  location: "JS frame :: resource://activity-stream/lib/TelemetryFeed.jsm :: uninit :: line 493"  data: no] Stack trace: uninit()@resource://activity-stream/lib/TelemetryFeed.jsm:493
16:41:57     INFO -  onAction()@resource://activity-stream/lib/TelemetryFeed.jsm:451
16:41:57     INFO -  _middleware/</<()@resource://activity-stream/lib/Store.jsm:51
16:41:57     INFO -  Store/this[method]()@resource://activity-stream/lib/Store.jsm:29
16:41:57     INFO -  uninit()@resource://activity-stream/lib/Store.jsm:166
16:41:57     INFO -  uninit()@resource://activity-stream/lib/ActivityStream.jsm:314
16:41:57     INFO -  uninit()@resource://gre/modules/addons/XPIProvider.jsm -> jar:file:///home/cltbld/workspace/build/application/firefox/browser/features/[e-mail]!/bootstrap.js:79
16:41:57     INFO -  shutdown()@resource://gre/modules/addons/XPIProvider.jsm -> jar:file:///home/cltbld/workspace/build/application/firefox/browser/features/[e-mail]!/bootstrap.js:187
16:41:57     INFO -  callBootstrapMethod()@resource://gre/modules/addons/XPIProvider.jsm:2751
16:41:57     INFO -  observe()@resource://gre/modules/addons/XPIProvider.jsm:1669
16:41:57     INFO -  forceQuit()@resource://gre/modules/addons/XPIProvider.jsm -> file:///tmp/tmp5A0pA_/profile/extensions/[e-mail]/bootstrap.js:235
16:41:57     INFO -  whenDone()@resource://gre/modules/addons/XPIProvider.jsm -> file:///tmp/tmp5A0pA_/profile/extensions/[e-mail]/bootstrap.js:220
16:41:57    ERROR -  JavaScript error: resource://gre/modules/addons/XPIProvider.jsm -> jar:file:///home/cltbld/workspace/build/application/firefox/browser/features/[e-mail]!/bootstrap.js, line 33: TypeError: NetworkError when attempting to fetch resource.
16:41:57    ERROR -  JavaScript error: resource://gre/modules/addons/XPIProvider.jsm -> jar:file:///home/cltbld/workspace/build/application/firefox/browser/features/[e-mail]!/bootstrap.js, line 33: TypeError: NetworkError when attempting to fetch resource.
16:41:57    ERROR -  JavaScript error: resource://gre/modules/addons/XPIProvider.jsm -> jar:file:///home/cltbld/workspace/build/application/firefox/browser/features/[e-mail]!/bootstrap.js, line 33: TypeError: NetworkError when attempting to fetch resource.
16:41:57    ERROR -  JavaScript error: resource://gre/modules/addons/XPIProvider.jsm -> jar:file:///home/cltbld/workspace/build/application/firefox/browser/features/[e-mail]!/bootstrap.js, line 33: TypeError: NetworkError when attempting to fetch resource.
16:41:57    ERROR -  JavaScript error: resource://gre/modules/addons/XPIProvider.jsm -> jar:file:///home/cltbld/workspace/build/application/firefox/browser/features/[e-mail]!/bootstrap.js, line 33: TypeError: NetworkError when attempting to fetch resource.
16:41:57    ERROR -  JavaScript error: resource://gre/modules/addons/XPIProvider.jsm -> jar:file:///home/cltbld/workspace/build/application/firefox/browser/features/[e-mail]!/bootstrap.js, line 33: TypeError: NetworkError when attempting to fetch resource.
16:41:57     INFO -  console.error: (new Error("Connection closed before committing the transaction.", "resource://gre/modules/Sqlite.jsm", 632))
16:41:57     INFO -  JavaScript error: resource://gre/modules/AsyncShutdown.jsm, line 683: Error: Phase "profile-before-change" is finished, it is too late to register completion condition "JSON store: writing data"
16:41:57     INFO -  JavaScript error: jar:file:///home/cltbld/workspace/build/application/firefox/browser/omni.ja!/components/nsBrowserGlue.js, line 1214: NS_ERROR_XPC_JAVASCRIPT_ERROR_WITH_DETAILS: [JavaScript Error: "Phase "profile-before-change" is finished, it is too late to register completion condition "JSON store: writing data"" {file: "resource://gre/modules/AsyncShutdown.jsm" line: 683}]'[JavaScript Error: "Phase "profile-before-change" is finished, it is too late to register completion condition "JSON store: writing data"" {file: "resource://gre/modules/AsyncShutdown.jsm" line: 683}]' when calling method: [nsIHandlerService::asyncInit]
16:41:57     INFO -  console.error: PushService:
16:41:57     INFO -    clearOriginData: Error clearing origin data:
16:41:57     INFO -    UnknownError
16:41:57     INFO -  console.error: PushService:
16:41:57     INFO -    stateChangeProcessEnqueue: Error transitioning state
16:41:57     INFO -    UnknownError

Comment 2

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

Ed, can you check what's up with that failure? It spams the failure summary for at least Talos jobs.

Comment 3

[Intermittent Failures Robot]

7 failures in 660 pushes (0.011 failures/push) were associated with this bug in the last 7 days.    

Repository breakdown:
* mozilla-inbound: 4
* autoland: 3

Platform breakdown:
* linux64: 4
* osx-10-10: 3

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1460782&startday=2018-05-07&endday=2018-05-13&tree=trunk

Comment 4

[Ed Lee :Mardak]

Looks like activity stream is being told to shutdown before it has finished initializing. This shows up as 2 exceptions:
1) TelemetryFeed.js calling removeObserver
2) bootstrap.js trying to fetch

For (1), TelemetryFeed trying to removeObserver that hadn't been added yet must mean INIT hasn't triggered? Or probably more likely feeds.telemetry is turned off... but then why is it getting UNINIT?

For (2), it's fetching to figure out what potential jsms are loaded to save them for unloading. I suppose this one could just be silently ignored? Once activity stream is a component instead of an add-on bug 1329955, it wouldn't need to try to handle being uninstalled…

Although why this started failing recently… Looks like Store.jsm now awaits on indexeddb before initializing feeds now. Maybe that is now delaying things long enough for tests to finish and want to shut down?

Comment 5

[Andrei Oprea [:andreio]]

The telemetry feed is initialized before the wait for indexeddb [0] but looking through other usages of Services.obs it seems common practice to check some `init` flag before calling removeObserver so we should be guarding against this exception anyway.

[0] https://github.com/mozilla/activity-stream/blob/90ce2ea229d1dc661d2476c4910078d5bd530e64/system-addon/lib/Store.jsm#L122-L125

Comment 6

[Andrei Oprea [:andreio]]

Actually the feed is enabled later than I thought [0] after the await for indexededb, yeah seems likely that we are seeing the behavior from comment 4 

[0] https://github.com/mozilla/activity-stream/blob/90ce2ea229d1dc661d2476c4910078d5bd530e64/system-addon/lib/Store.jsm#L139-L141

Comment 7

[GitHub Bugzilla PR Linker]

Attachment: Link to GitHub pull-request: https://github.com/mozilla/activity-stream/pull/4152

Comment 8

[Intermittent Failures Robot]

16 failures in 99 pushes (0.162 failures/push) were associated with this bug yesterday.    

Repository breakdown:
* mozilla-central: 7
* autoland: 6
* mozilla-inbound: 3

Platform breakdown:
* linux64: 10
* linux64-qr: 3
* osx-10-10: 2
* linux64-nightly: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1460782&startday=2018-05-18&endday=2018-05-18&tree=trunk

Comment 9

[Intermittent Failures Robot]

29 failures in 32 pushes (0.906 failures/push) were associated with this bug yesterday.    

Repository breakdown:
* mozilla-central: 14
* autoland: 8
* mozilla-inbound: 7

Platform breakdown:
* linux64: 19
* linux64-qr: 8
* osx-10-10: 1
* linux64-nightly: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1460782&startday=2018-05-19&endday=2018-05-19&tree=trunk

Comment 10

[Intermittent Failures Robot]

80 failures in 639 pushes (0.125 failures/push) were associated with this bug in the last 7 days. 

This is the #16 most frequent failure this week. 

** This failure happened more than 75 times this week! Resolving this bug is a very high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 1 week, the affected test(s) may be disabled. **   

Repository breakdown:
* mozilla-central: 31
* mozilla-inbound: 24
* autoland: 20
* try: 5

Platform breakdown:
* linux64: 54
* linux64-qr: 19
* osx-10-10: 4
* linux64-nightly: 2
* macosx64-nightly: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1460782&startday=2018-05-14&endday=2018-05-20&tree=trunk

Comment 11

[Andreea Pavel [:apavel]]

:andreio hi, do you have any updates on this? 
In the last 7 days there were 76 total failures the majority on linux64: https://treeherder.mozilla.org/logviewer.html#?job_id=179459520&repo=mozilla-inbound&lineNumber=1119

01:02:16     INFO -  TEST-START | tp6_google
01:02:16     INFO -  Initialising browser for tp6_google test...
01:02:16     INFO -  Cloning profile located at /home/cltbld/workspace/build/tests/talos/talos/base_profile
01:02:16     INFO -  Merging profile: /home/cltbld/workspace/build/tests/talos/talos/profile_data/common
01:02:16     INFO -  Merging profile: /home/cltbld/workspace/build/tests/talos/talos/profile_data/perf
01:02:16     INFO -  Installing Add-ons:
01:02:16     INFO -  ['/home/cltbld/workspace/build/tests/talos/talos/talos-powers', '/home/cltbld/workspace/build/tests/talos/talos/pageloader']
01:02:16     INFO -  Application command: /home/cltbld/workspace/build/application/firefox/firefox  http://localhost:47291/getInfo.html -profile /tmp/tmpGqkCkY/profile
01:02:16     INFO -  TEST-INFO | started process 13254 (/home/cltbld/workspace/build/application/firefox/firefox  http://localhost:47291/getInfo.html)
01:02:17     INFO -  1526889737351	addons.xpi-utils	WARN	Error: Synchronously loading the add-ons database (resource://gre/modules/addons/XPIDatabase.jsm:1386:17) JS Stack trace: [e-mail]:1386:17
01:02:17     INFO -  [e-mail]:2775:9
01:02:17     INFO -  [e-mail]:2324:25
01:02:17     INFO -  [e-mail]:205:12
01:02:17     INFO -  [e-mail]:653:5
01:02:17     INFO -  [e-mail]:812:9
01:02:17     INFO -  [e-mail]:2864:5
01:02:17     INFO -  [e-mail]:66:9
01:02:18     INFO -  __metrics	Screen width/height:1600/1200
01:02:18     INFO -  	colorDepth:24
01:02:18     INFO -  	Browser inner width/height: 1280/966
01:02:18     INFO -  __metrics
01:02:18     INFO -  1526889738651	addons.xpi	WARN	Exception running bootstrap method shutdown on [e-mail]: [Exception... "Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIObserverService.removeObserver]"  nsresult: "0x80004005 (NS_ERROR_FAILURE)"  location: "JS frame :: resource://activity-stream/lib/TelemetryFeed.jsm :: uninit :: line 493"  data: no] Stack trace: uninit()@resource://activity-stream/lib/TelemetryFeed.jsm:493
01:02:18     INFO -  onAction()@resource://activity-stream/lib/TelemetryFeed.jsm:451
01:02:18     INFO -  _middleware/</<()@resource://activity-stream/lib/Store.jsm:51
01:02:18     INFO -  Store/this[method]()@resource://activity-stream/lib/Store.jsm:29
01:02:18     INFO -  uninit()@resource://activity-stream/lib/Store.jsm:166
01:02:18     INFO -  uninit()@resource://activity-stream/lib/ActivityStream.jsm:318
01:02:18     INFO -  uninit()@resource://gre/modules/addons/XPIProvider.jsm -> jar:file:///home/cltbld/workspace/build/application/firefox/browser/features/[e-mail]!/bootstrap.js:79
01:02:18     INFO -  shutdown()@resource://gre/modules/addons/XPIProvider.jsm -> jar:file:///home/cltbld/workspace/build/application/firefox/browser/features/[e-mail]!/bootstrap.js:187
01:02:18     INFO -  callBootstrapMethod()@resource://gre/modules/addons/XPIProvider.jsm:1839
01:02:18     INFO -  shutdown()@resource://gre/modules/addons/XPIProvider.jsm:1963
01:02:18     INFO -  observer()@resource://gre/modules/addons/XPIProvider.jsm:2396
01:02:18     INFO -  forceQuit()@resource://gre/modules/addons/XPIProvider.jsm -> file:///tmp/tmpGqkCkY/profile/extensions/[e-mail]/bootstrap.js:235
01:02:18     INFO -  whenDone()@resource://gre/modules/addons/XPIProvider.jsm -> file:///tmp/tmpGqkCkY/profile/extensions/[e-mail]/bootstrap.js:220
01:02:18    ERROR -  JavaScript error: resource://gre/modules/addons/XPIProvider.jsm -> jar:file:///home/cltbld/workspace/build/application/firefox/browser/features/[e-mail]!/bootstrap.js, line 33: TypeError: NetworkError when attempting to fetch resource.
01:02:18    ERROR -  JavaScript error: resource://gre/modules/addons/XPIProvider.jsm -> jar:file:///home/cltbld/workspace/build/application/firefox/browser/features/[e-mail]!/bootstrap.js, line 33: TypeError: NetworkError when attempting to fetch resource.
01:02:18    ERROR -  JavaScript error: resource://gre/modules/addons/XPIProvider.jsm -> jar:file:///home/cltbld/workspace/build/application/firefox/browser/features/[e-mail]!/bootstrap.js, line 33: TypeError: NetworkError when attempting to fetch resource.
01:02:18    ERROR -  JavaScript error: resource://gre/modules/addons/XPIProvider.jsm -> jar:file:///home/cltbld/workspace/build/application/firefox/browser/features/[e-mail]!/bootstrap.js, line 33: TypeError: NetworkError when attempting to fetch resource.
01:02:18    ERROR -  JavaScript error: resource://gre/modules/addons/XPIProvider.jsm -> jar:file:///home/cltbld/workspace/build/application/firefox/browser/features/[e-mail]!/bootstrap.js, line 33: TypeError: NetworkError when attempting to fetch resource.
01:02:18    ERROR -  JavaScript error: resource://gre/modules/addons/XPIProvider.jsm -> jar:file:///home/cltbld/workspace/build/application/firefox/browser/features/[e-mail]!/bootstrap.js, line 33: TypeError: NetworkError when attempting to fetch resource.
01:02:18     INFO -  JavaScript error: resource://gre/modules/JSONFile.jsm, line 159: Error: Data is not ready.
01:02:18     INFO -  ###!!! [Parent][DispatchAsyncMessage] Error: PBackgroundIDBFactory::Msg_PBackgroundIDBFactoryRequestConstructor Value error: message was deserialized, but contained an illegal value
01:02:18     INFO -  ###!!! [Parent][DispatchAsyncMessage] Error: PBackgroundIDBFactory::Msg_PBackgroundIDBFactoryRequestConstructor Value error: message was deserialized, but contained an illegal value
01:02:18     INFO -  *** UTM:SVC TimerManager:registerTimer called after profile-before-change notification. Ignoring timer registration for id: telemetry_modules_ping
01:02:19     INFO -  TEST-INFO | 13254: exit 0
01:02:19     INFO -  Browser initialized.
01:02:19     INFO -  Using mitmproxy so setting MOZ_DISABLE_NONLOCAL_CONNECTIONS to 0
01:02:19     INFO -  Running cycle 1/1 for tp6_google test...
01:02:19     INFO -  Using env: {'DISPLAY': ':0',
01:02:19     INFO -   'GECKO_HEAD_REPOSITORY': 'https://hg.mozilla.org/integration/mozilla-inbound',
01:02:19     INFO -   'GECKO_HEAD_REV': 'daca961e0469a2786bdfabce6b03b4840f6b8ee9',
01:02:19     INFO -   'HOME': '/home/cltbld',
01:02:19     INFO -   'JSGC_DISABLE_POISONING': '1',
01:02:19     INFO -   'LD_LIBRARY_PATH': '/home/cltbld/workspace/build/application/firefox',
01:02:19     INFO -   'LOGNAME': 'cltbld',
01:02:19     INFO -   'MINIDUMP_SAVE_PATH': '/home/cltbld/workspace/build/blobber_upload_dir',
01:02:19     INFO -   'MINIDUMP_STACKWALK': '/home/cltbld/workspace/build/linux64-minidump_stackwalk',
01:02:19     INFO -   'MOZHARNESS_CONFIG': 'talos/linux_config.py',
01:02:19     INFO -   'MOZHARNESS_SCRIPT': 'talos_script.py',
01:02:19     INFO -   'MOZHARNESS_URL': 'https://queue.taskcluster.net/v1/task/Ey2MFm3aTyKtnbditONmSA/artifacts/public/build/mozharness.zip',
01:02:19     INFO -   'MOZILLA_BUILD_URL': 'https://queue.taskcluster.net/v1/task/Ey2MFm3aTyKtnbditONmSA/artifacts/public/build/target.tar.bz2',
01:02:19     INFO -   'MOZ_AUTOMATION': '1',
01:02:19     INFO -   'MOZ_CRASHREPORTER': '1',
01:02:19     INFO -   'MOZ_CRASHREPORTER_NO_REPORT': '1',
01:02:19     INFO -   'MOZ_DISABLE_NONLOCAL_CONNECTIONS': '0',
01:02:19     INFO -   'MOZ_HIDE_RESULTS_TABLE': '1',
01:02:19     INFO -   'MOZ_NODE_PATH': '/usr/local/bin/node',
01:02:19     INFO -   'MOZ_NO_REMOTE': '1',
01:02:19     INFO -   'MOZ_SOURCE_CHANGESET': 'daca961e0469a2786bdfabce6b03b4840f6b8ee9',
01:02:19     INFO -   'MOZ_SOURCE_REPO': 'https://hg.mozilla.org/integration/mozilla-inbound',
01:02:19     INFO -   'MOZ_UPLOAD_DIR': '/home/cltbld/workspace/build/blobber_upload_dir',
01:02:19     INFO -   'NEED_XVFB': 'false',
01:02:19     INFO -   'NO_EM_RESTART': '1',
01:02:19     INFO -   'NO_FAIL_ON_TEST_ERRORS': '1',
01:02:19     INFO -   'OLDPWD': '/home/cltbld/workspace',
01:02:19     INFO -   'PATH': '/home/cltbld/workspace/build/venv/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11',
01:02:19     INFO -   'PWD': '/home/cltbld/workspace',
01:02:19     INFO -   'PYTHONPATH': '/home/cltbld/workspace/build/tests/talos',
01:02:19     INFO -   'RUN_ID': '0',
01:02:19     INFO -   'RUST_BACKTRACE': 'full',
01:02:19     INFO -   'SCRIPTSPATH': '/home/cltbld/workspace/mozharness',
01:02:19     INFO -   'SHLVL': '1',
01:02:19     INFO -   'STYLO_FORCE_ENABLED': '1',
01:02:19     INFO -   'STYLO_THREADS': '1',
01:02:19     INFO -   'TASK_ID': 'CysumGnMQzO5JagXXUi9eA',
01:02:19     INFO -   'USER': 'cltbld',
01:02:19     INFO -   'XDG_RUNTIME_DIR': '/run/user/1000',
01:02:19     INFO -   'XDG_SESSION_ID': 'c1',
01:02:19     INFO -   'XPCOM_DEBUG_BREAK': 'warn'}
01:02:19     INFO -  TEST-INFO | started process 13517 (/home/cltbld/workspace/build/application/firefox/firefox -profile /tmp/tmpGqkCkY/profile)
01:02:19     INFO -  127.0.0.1:55160: clientconnect
01:02:19     INFO -  For request http://detectportal.firefox.com/success.txt best match http://detectportal.firefox.com/success.txt with score==3
01:02:19     INFO -  127.0.0.1:55160: GET http://detectportal.firefox.com/success.txt
01:02:19     INFO -  [replay]               << 200 OK 8b
01:02:22     INFO -  127.0.0.1:55166: clientconnect
01:02:22     INFO -  For request https://www.google.com/ found exact replay match
01:02:22     INFO -  127.0.0.1:55166: GET https://www.google.com/ HTTP/2.0
01:02:22     INFO -  [replay]               << 302  259b
01:02:22     INFO -  127.0.0.1:55168: clientconnect
01:02:23     INFO -  For request https://www.google.ca/?gfe_rd=cr&ei=EwY3WdejM8KR8QfHk5OIBA found exact replay match
01:02:23     INFO -  127.0.0.1:55168: GET https://www.google.ca/?gfe_rd=cr&ei=EwY3WdejM8KR8QfHk5OIBA HTTP/2.0
01:02:23     INFO -  [replay]               << 200  61.74k
01:02:23     INFO -  For request https://www.google.ca/images/hpp/ic_wahlberg_product_core_48.png8.png found exact replay match
01:02:23     INFO -  127.0.0.1:55168: GET https://www.google.ca/images/hpp/ic_wahlberg_product_core_48.png8.png HTTP/2.0
01:02:23     INFO -  [replay]               << 200  2.04k
01:02:23     INFO -  For request https://www.google.ca/images/branding/googlelogo/2x/googlelogo_color_120x44dp.png found exact replay match
01:02:23     INFO -  127.0.0.1:55168: GET https://www.google.ca/images/branding/googlelogo/2x/googlelogo_color_120x44dp.png HTTP/2.0
01:02:23     INFO -  [replay]               << 200  4.97k
01:02:23     INFO -  127.0.0.1:55170: clientconnect
01:02:23     INFO -  For request https://www.google.ca/images/branding/googlelogo/1x/googlelogo_color_272x92dp.png found exact replay match
01:02:23     INFO -  127.0.0.1:55168: GET https://www.google.ca/images/branding/googlelogo/1x/googlelogo_color_272x92dp.png HTTP/2.0
01:02:23     INFO -  [replay]               << 200  5.83k
01:02:23     INFO -  For request https://www.google.ca/xjs/_/js/k=xjs.s.en.NFKxdS_3-3M.O/m=sx,c,sb,cdos,cr,elog,hsm,jsa,r,qsm,j,p,d,csi/am=AEcoyuMFByD_RwiF4SaEBWkFphjAAQ/rt=j/d=1/t=zcms/rs=ACT90oE09PwA6TV-cBff1IE5v3n_cEqmxA found exact replay match
01:02:23     INFO -  127.0.0.1:55168: GET https://www.google.ca/xjs/_/js/k=xjs.s.en.NFKxdS_3-3M.O/m=sx,c,sb,cdos,cr,elog,hsm,jsa,r,qsm,j,p,d,csi/am=AEcoyuMFByD_RwiF4SaEBWkFphjAAQ/rt=j/d=1/t=zcms/rs=ACT90oE09PwA6TV-cBff1IE5v3n_cEqmxA HTTP/2.0
01:02:23     INFO -  [replay]               << 200  159.34k
01:02:23     INFO -  For request https://www.google.ca/search?hl=en&q=barack+obama&ei=FAY3WaDyBoS0jwPFiLugAw found exact replay match
01:02:23     INFO -  127.0.0.1:55168: GET https://www.google.ca/search?hl=en&q=barack+obama&ei=FAY3WaDyBoS0jwPFiLugAw HTTP/2.0
01:02:23     INFO -  [replay]               << 200  138.03k
01:02:23     INFO -  For request https://www.google.com/textinputassistant/tia.png found exact replay match
01:02:23     INFO -  127.0.0.1:55166: GET https://www.google.com/textinputassistant/tia.png HTTP/2.0
01:02:23     INFO -  [replay]               << 200  258b
01:02:23     INFO -  For request https://www.google.ca/xjs/_/js/k=xjs.s.en.NFKxdS_3-3M.O/m=aa,abd,async,dvl,foot,fpe,ipv6,lu,m,sf,d3l,mids/am=AEcoyuMFByD_RwiF4SaEBWkFphjAAQ/exm=sx,c,sb,cdos,cr,elog,hsm,jsa,r,qsm,j,p,d,csi/rt=j/d=1/ed=1/t=zcms/rs=ACT90oE09PwA6TV-cBff1IE5v3n_cEqmxA found exact replay match
01:02:23     INFO -  127.0.0.1:55168: GET https://www.google.ca/xjs/_/js/k=xjs.s.en.NFKxdS_3-3M.O/m=aa,abd,async,dvl,foot,fpe,ipv6,lu,m,sf,d3l,mids/am=AEcoyuMFByD_RwiF4SaEBWkFphjAAQ/exm=sx,c,sb,cdos,cr,elog,hsm,jsa,r,qsm,j,p,d,csi/rt=j/d=1/ed=1/t=zcms/rs=ACT90oE09PwA6TV-cBff1IE5v3n_cEqmxA HTTP/2.0
01:02:23     INFO -  [replay]               << 200  22.07k
01:02:23     INFO -  127.0.0.1:55172: clientconnect
01:02:23     INFO -  For request https://www.google.ca/images/nav_logo242.png found exact replay match
01:02:23     INFO -  127.0.0.1:55174: clientconnect
01:02:23     INFO -  127.0.0.1:55168: GET https://www.google.ca/images/nav_logo242.png HTTP/2.0
01:02:23     INFO -  [replay]               << 200  16.39k
01:02:23     INFO -  127.0.0.1:55170: CONNECT ssl.gstatic.com:443
01:02:23     INFO -   << Cannot establish TLS with client (sni: ssl.gstatic.com): TlsException("SSL handshake error: SysCallError(-1, 'Unexpected EOF')",)
01:02:23     INFO -  127.0.0.1:55170: clientdisconnect
01:02:23     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
01:02:23     INFO -  127.0.0.1:55168: GET https://www.google.ca/client_204?&atyp=i&biw=1024&bih=694&ei=FAY3WeO-PMLcjAPuvZgI HTTP/2.0
01:02:23     INFO -  [replay]               << 204  0b
01:02:23     INFO -  For request https://www.google.ca/xjs/_/js/k=xjs.s.en.NFKxdS_3-3M.O/m=aa,abd,aspn,async,dvl,foot,fpe,ipv6,lu,m,sf,tl,vs,d3l,tnv,mrn,ssc,strm,twt,me,kptm,ilrp,iuci,shrb,dgm,qtf,tcc,atn/am=AEcoyuMFByD_RwiF4SaEBWkFphjAAQ/exm=sx,c,sb,cdos,cr,elog,hsm,jsa,r,qsm,j,p,d,csi/rt=j/d=1/ed=1/t=zcms/rs=ACT90oE09PwA6TV-cBff1IE5v3n_cEqmxA found exact replay match
01:02:23     INFO -  127.0.0.1:55168: GET https://www.google.ca/xjs/_/js/k=xjs.s.en.NFKxdS_3-3M.O/m=aa,abd,aspn,async,dvl,foot,fpe,ipv6,lu,m,sf,tl,vs,d3l,tnv,mrn,ssc,strm,twt,me,kptm,ilrp,iuci,shrb,dgm,qtf,tcc,atn/am=AEcoyuMFByD_RwiF4SaEBWkFphjAAQ/exm=sx,c,sb,cdos,cr,elog,hsm,jsa,r,qsm,j,p,d,csi/rt=j/d=1/ed=1/t=zcms/rs=ACT90oE09PwA6TV-cBff1IE5v3n_cEqmxA HTTP/2.0
01:02:23     INFO -  [replay]               << 200  74.67k
01:02:23     INFO -  For request https://ssl.gstatic.com/gb/images/i1_1967ca6a.png found exact replay match
01:02:23     INFO -  127.0.0.1:55172: GET https://ssl.gstatic.com/gb/images/i1_1967ca6a.png HTTP/2.0
01:02:23     INFO -  [replay]               << 200  7.15k
01:02:23     INFO -  127.0.0.1:55176: clientconnect
01:02:23     INFO -  For request https://id.google.ca/verify/q6JL9CoQtrBBFNyEhd7okDAAAABJ3yEA2_od8JAJaTdwpUzLgiiG-CAOHUwiMktJrkRX8KAJzeYZDsA0M9vDQrKYXnM found exact replay match
01:02:23     INFO -  127.0.0.1:55174: GET https://id.google.ca/verify/q6JL9CoQtrBBFNyEhd7okDAAAABJ3yEA2_od8JAJaTdwpUzLgiiG-CAOHUwiMktJrkRX8KAJzeYZDsA0M9vDQrKYXnM HTTP/2.0
01:02:23     INFO -  [replay]               << 200  0b
01:02:23     INFO -  For request https://www.google.ca/images/branding/product/ico/googleg_lodp.ico found exact replay match
01:02:23     INFO -  127.0.0.1:55168: GET https://www.google.ca/images/branding/product/ico/googleg_lodp.ico HTTP/2.0
01:02:23     INFO -  [replay]               << 200  1.46k
01:02:23     INFO -  For request https://www.gstatic.com/og/_/js/k=og.og2.en_US.IzWge8zZE98.O/rt=j/m=def/exm=in,fot/d=1/ed=1/rs=AA2YrTvOIkRPzy4fg7cgGSzIAfSp8ASr3A found exact replay match
01:02:23     INFO -  127.0.0.1:55176: GET https://www.gstatic.com/og/_/js/k=og.og2.en_US.IzWge8zZE98.O/rt=j/m=def/exm=in,fot/d=1/ed=1/rs=AA2YrTvOIkRPzy4fg7cgGSzIAfSp8ASr3A HTTP/2.0
01:02:23     INFO -  [replay]               << 200  45.89k
01:02:23     INFO -  127.0.0.1:55178: clientconnect
01:02:24     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
01:02:24     INFO -  127.0.0.1:55178: 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
01:02:24     INFO -  [replay]               << 200  41.42k
01:02:24     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.32.20.sb.17.p.7.dvl.3.foot.3.fpe.1&ima=8&rt=xjsls.38,prt.40,iml.98,dcl.70,xjses.134,jraids.162,jraide.174,xjsee.213,xjs.214,iuml_rcs.268,iuml_nre.268,ol.937,aft.96,wsrt.52,cst.0,dnst.0,rqst.6,rspt.1,sslt.-2,rqstt.2,unt.-2,cstt.-2,dit.118 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
01:02:24     INFO -  127.0.0.1:55168: GET https://www.google.ca/gen_204?s=web&atyp=csi&ei=FAY3WeO-PMLcjAPuvZgI&imc=21&imn=21&imp=19&adh=&xjs=init.32.20.sb.17.p.7.dvl.3.foot.3.fpe.1&ima=8&rt=xjsls.38,prt.40,iml.98,dcl.70,xjses.134,jraids.162,jraide.174,xjsee.213,xjs.214,iuml_rcs.268,iuml_nre.268,ol.937,aft.96,wsrt.52,cst.0,dnst.0,rqst.6,rspt.1,sslt.-2,rqstt.2,unt.-2,cstt.-2,dit.118 HTTP/2.0
01:02:24     INFO -  [replay]               << 204  0b
01:03:19     INFO -  For request http://detectportal.firefox.com/success.txt best match http://detectportal.firefox.com/success.txt with score==3
01:03:19     INFO -  127.0.0.1:55160: GET http://detectportal.firefox.com/success.txt
01:03:19     INFO -  [replay]               << 200 OK 8b
01:05:13     INFO -  127.0.0.1:55176: HTTP/2 connection terminated by client: error code: 0, last stream id: 0, additional data: None
01:05:13     INFO -  127.0.0.1:55166: HTTP/2 connection terminated by client: error code: 0, last stream id: 0, additional data: None
01:05:13     INFO -  127.0.0.1:55172: HTTP/2 connection terminated by client: error code: 0, last stream id: 0, additional data: None
01:05:13     INFO -  127.0.0.1:55166: clientdisconnect
01:05:13     INFO -  127.0.0.1:55172: clientdisconnect
01:05:13     INFO -  127.0.0.1:55174: HTTP/2 connection terminated by client: error code: 0, last stream id: 0, additional data: None
01:05:13     INFO -  127.0.0.1:55174: clientdisconnect
01:05:13     INFO -  127.0.0.1:55176: clientdisconnect
01:05:14     INFO -  127.0.0.1:55178: HTTP/2 connection terminated by client: error code: 0, last stream id: 0, additional data: None
01:05:14     INFO -  127.0.0.1:55178: clientdisconnect
01:05:14     INFO -  127.0.0.1:55168: HTTP/2 connection terminated by client: error code: 0, last stream id: 0, additional data: None
01:05:14     INFO -  127.0.0.1:55168: clientdisconnect
01:05:15     INFO -  127.0.0.1:55160: clientdisconnect
[taskcluster:error]  Task killed because maxRunTime was exceeded

Comment 12

[Intermittent Failures Robot]

40 failures in 86 pushes (0.465 failures/push) were associated with this bug yesterday.    

Repository breakdown:
* autoland: 18
* mozilla-inbound: 12
* mozilla-central: 8
* try: 2

Platform breakdown:
* linux64: 30
* linux64-qr: 10

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1460782&startday=2018-05-21&endday=2018-05-21&tree=trunk

Comment 13

[Intermittent Failures Robot]

56 failures in 111 pushes (0.505 failures/push) were associated with this bug yesterday.    

** This test has failed more than 150 times in the last 21 days. It should be disabled until it can be fixed. ** 

Repository breakdown:
* try: 24
* mozilla-inbound: 15
* autoland: 13
* mozilla-central: 4

Platform breakdown:
* linux64: 27
* linux64-qr: 26
* osx-10-10: 2
* linux64-nightly: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1460782&startday=2018-05-22&endday=2018-05-22&tree=trunk

Comment 14

[[github robot]]

Commit pushed to master at https://github.com/mozilla/activity-stream

https://github.com/mozilla/activity-stream/commit/7ac7bb77c8acf99a841b49c7a1255e0991d90b64
fix(uninit): Silently ignore errors from early shutdown (#4152)

Fix Bug 1460782 - Exception in TelemetryFeed uninit

Comment 15

[Ed Lee :Mardak]

Leaving open until exported to m-c.

Comment 16

[Ed Lee :Mardak]

https://hg.mozilla.org/mozilla-central/rev/238c2caac25d

Comment 17

[Intermittent Failures Robot]

132 failures in 632 pushes (0.209 failures/push) were associated with this bug in the last 7 days. 

This is the #14 most frequent failure this week. 

** This failure happened more than 75 times this week! Resolving this bug is a very high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 1 week, the affected test(s) may be disabled. **   

Repository breakdown:
* autoland: 45
* mozilla-inbound: 37
* try: 34
* mozilla-central: 16

Platform breakdown:
* linux64: 72
* linux64-qr: 56
* osx-10-10: 3
* linux64-nightly: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1460782&startday=2018-05-21&endday=2018-05-27&tree=trunk

Comment 18

[Intermittent Failures Robot]

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

Repository breakdown:
* try: 1

Platform breakdown:
* linux64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1460782&startday=2018-05-28&endday=2018-06-03&tree=trunk