Closed Bug 1152116 Opened 5 years ago Closed 5 years ago

Error Messages in Browser Console from Sync

Categories

(Firefox :: Sync, defect)

All
Windows
defect
Not set

Tracking

()

RESOLVED FIXED
mozilla41
Tracking Status
firefox39 --- affected
firefox41 --- fixed

People

(Reporter: BesTo, Assigned: markh)

Details

Attachments

(1 file)

I logged some errors in the Browser Console from Sync.
Even when the errors are "legal" & OK, they are confusing / not readable for users.
So at leased they should replaced with better error messages.
Btw.: I think this errors happen when FF is in Offline-Mode

1428440759376	Sync.BrowserIDManager	ERROR	Non-authentication error in _fetchTokenForUser: TokenServerClientNetworkError({"error":{}}) (resource://gre/modules/services-common/tokenserverclient.js:36:35) JS Stack trace: @tokenserverclient.js:36:36 < @browserid_identity.js:14:1 < @status.js:15:1 < lazyImport/getter/<@main.js:20:5 < WeaveService.prototype.observe/<.notify<@Weave.js:154:13

1428440843827	Sync.BrowserIDManager	ERROR	Background fetch for key bundle failed: TokenServerClientNetworkError({"error":{}}) (resource://gre/modules/services-common/tokenserverclient.js:36:35) JS Stack trace: @tokenserverclient.js:36:36 < @browserid_identity.js:14:1 < @status.js:15:1 < lazyImport/getter/<@main.js:20:5 < WeaveService.prototype.observe/<.notify<@Weave.js:154:13 Log.jsm:749:0

1428440843833	Sync.BrowserIDManager	ERROR	Could not authenticate: TokenServerClientNetworkError({"error":{}}) (resource://gre/modules/services-common/tokenserverclient.js:36:35) JS Stack trace: @tokenserverclient.js:36:36 < @browserid_identity.js:14:1 < @status.js:15:1 < lazyImport/getter/<@main.js:20:5 < WeaveService.prototype.observe/<.notify<@Weave.js:154:13

TypeError: subject is null forms.js:232:14

A promise chain failed to handle a rejection. Did you forget to '.catch', or did you forget to 'return'?
See https://developer.mozilla.org/Mozilla/JavaScript_code_modules/Promise.jsm/Promise
Date: Tue Apr 07 2015 23:20:55 GMT+0200
Full Message: [object ProgressEvent]
Full Stack: JS frame :: resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js :: PendingErrors.register :: line 162
JS frame :: resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js :: this.PromiseWalker.completePromise :: line 675
JS frame :: resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js :: Handler.prototype.process :: line 870
JS frame :: resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js :: this.PromiseWalker.walkerLoop :: line 746
JS frame :: resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js :: this.PromiseWalker.scheduleWalkerLoop/< :: line 688
native frame :: <unknown filename> :: <TOP_LEVEL> :: line 0

1428444261068	FirefoxAccounts	ERROR	FxA rejecting with error NETWORK_ERROR, details: {"name":"FxAccountsOAuthGrantClientError","code":null,"errno":998,"error":"NETWORK_ERROR","message":"[Exception... \"NS_ERROR_UNKNOWN_HOST\"  nsresult: \"0x804b001e (NS_ERROR_UNKNOWN_HOST)\"  location: \"JS frame :: resource://services-common/rest.js :: onStopRequest :: line 465\"  data: no]"} Log.jsm:749:0

1428444261070	readinglist.scheduler	ERROR	Sync failed, now in state 'other error': Error: NETWORK_ERROR (resource://gre/modules/FxAccounts.jsm:1076:17) JS Stack trace: FxAccountsInternal.prototype._error@FxAccounts.jsm:1076:18 < FxAccountsInternal.prototype._errorToErrorClass@FxAccounts.jsm:1064:14 < FxAccountsInternal.prototype.getOAuthToken/<@FxAccounts.jsm:1034:26 < Handler.prototype.process@Promise-backend.js:870:21 < this.PromiseWalker.walkerLoop@Promise-backend.js:746:7 < this.PromiseWalker.scheduleWalkerLoop/<@Promise-backend.js:688:37 < Promise*this.PromiseWalker.scheduleWalkerLoop@Promise-backend.js:688:5 < this.PromiseWalker.schedulePromise@Promise-backend.js:709:7 < this.PromiseWalker.completePromise@Promise-backend.js:671:7 < this.FxAccountsOAuthGrantClient.prototype._createRequest/</request.onComplete@FxAccountsOAuthGrantClient.jsm:125:1 < onStopRequest@rest.js:467:7 < openModalWindow@nsPrompter.js:370:5 < ModalPrompter.prototype.openPrompt@nsPrompter.js:553:9 < ModalPrompter.prototype.confirmEx@nsPrompter.js:697:9 < UpdateUrlbarSearchSplitterState@browser.js:13151:47 < OverflowableToolbar.prototype.onOverflow@CustomizableUI.jsm:4008:5 < handleEvent@toolbar.xml:93:15
1428459899281	Sync.Engine.Tabs	WARN	Error creating record: [Exception... "Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsISessionStore.getTabState]"  nsresult: "0x80004005 (NS_ERROR_FAILURE)"  location: "JS frame :: resource://gre/modules/services-sync/engines/tabs.js :: TabStore.prototype.getTabState :: line 121"  data: no] Stack trace: TabStore.prototype.getTabState()@resource://gre/modules/services-sync/engines/tabs.js:121 < TabStore.prototype.getAllTabs()@resource://gre/modules/services-sync/engines/tabs.js:137 < TabStore.prototype.createRecord()@resource://gre/modules/services-sync/engines/tabs.js:190 < SyncEngine.prototype._createRecord()@resource://services-sync/engines.js:854 < SyncEngine.prototype._uploadOutgoing()@resource://services-sync/engines.js:1451 < SyncEngine.prototype._sync()@resource://services-sync/engines.js:1522 < WrappedNotify()@resource://services-sync/util.js:148 < Engine.prototype.sync()@resource://services-sync/engines.js:668 < _syncEngine()@resource://services-sync/stages/enginesync.js:199 < sync()@resource://services-sync/stages/enginesync.js:149 < onNotify()@resource://gre/modules/services-sync/service.js:1298 < WrappedNotify()@resource://services-sync/util.js:148 < WrappedLock()@resource://services-sync/util.js:103 < _lockedSync()@resource://gre/modules/services-sync/service.js:1288 < sync/<()@resource://gre/modules/services-sync/service.js:1280 < WrappedCatch()@resource://services-sync/util.js:77 < sync()@resource://gre/modules/services-sync/service.js:1268 < <file:unknown>

mutating the [[Prototype]] of an object will cause your code to run very slowly; instead create the object with the correct initial [[Prototype]] value using Object.create async.js:199:4

1428463564058	readinglist.scheduler	ERROR	Sync failed, now in state 'other error': Error: UNKNOWN_ERROR (resource://gre/modules/FxAccounts.jsm:1076:17) JS Stack trace: FxAccountsInternal.prototype._error@FxAccounts.jsm:1076:18 < FxAccountsInternal.prototype._errorToErrorClass@FxAccounts.jsm:1071:12 < FxAccountsInternal.prototype.getOAuthToken/<@FxAccounts.jsm:1034:26 < Handler.prototype.process@Promise-backend.js:870:21 < this.PromiseWalker.walkerLoop@Promise-backend.js:746:7 < this.PromiseWalker.scheduleWalkerLoop/<@Promise-backend.js:688:37 < Promise*this.PromiseWalker.scheduleWalkerLoop@Promise-backend.js:688:5 < this.PromiseWalker.schedulePromise@Promise-backend.js:709:7 < this.PromiseWalker.completePromise@Promise-backend.js:671:7 < _onComplete@hawkclient.js:231:1 < onComplete@hawkclient.js:272:9 < onStopRequest@rest.js:467:7

1428509078067	Hawk	WARN	hawk request error: [Exception... "NS_ERROR_UNKNOWN_HOST"  nsresult: "0x804b001e (NS_ERROR_UNKNOWN_HOST)"  location: "JS frame :: resource://services-common/rest.js :: onStopRequest :: line 465"  data: no] Stack trace: onStopRequest()@resource://services-common/rest.js:465 < waitForSyncCallback()@resource://services-common/async.js:102 < makeSpinningCallback/callback.wait()@resource://services-common/async.js:145 < this.BrowserIDManager.prototype._getAuthenticationHeader()@resource://gre/modules/services-sync/browserid_identity.js:656 < Res__createRequest()@resource://services-sync/resource.js:175 < _doRequest()@resource://services-sync/resource.js:200 < Res__request()@resource://services-sync/resource.js:404 < Res_post()@resource://services-sync/resource.js:443 < SyncEngine.prototype._uploadOutgoing/doUpload<()@resource://services-sync/engines.js:1423 < innerBind()@resource://services-sync/util.js:525 < SyncEngine.prototype._uploadOutgoing()@resource://services-sync/engines.js:1471 < SyncEngine.prototype._sync()@resource://services-sync/engines.js:1522 < wrappedSync()@resource://gre/modules/services-sync/engines/bookmarks.js:229 < _sync()@resource://gre/modules/services-sync/engines/bookmarks.js:226 < WrappedNotify()@resource://services-sync/util.js:148 < Engine.prototype.sync()@resource://services-sync/engines.js:668 < _syncEngine()@resource://services-sync/stages/enginesync.js:199 < sync()@resource://services-sync/stages/enginesync.js:149 < onNotify()@resource://gre/modules/services-sync/service.js:1298 < WrappedNotify()@resource://services-sync/util.js:148 < WrappedLock()@resource://services-sync/util.js:103 < _lockedSync()@resource://gre/modules/services-sync/service.js:1288 < sync/<()@resource://gre/modules/services-sync/service.js:1280 < WrappedCatch()@resource://services-sync/util.js:77 < sync()@resource://gre/modules/services-sync/service.js:1268 < <file:unknown>

1428509305039	FirefoxAccounts	ERROR	error POSTing /certificate/sign: {"error":{},"errorString":"[Exception... \"NS_ERROR_UNKNOWN_HOST\"  nsresult: \"0x804b001e (NS_ERROR_UNKNOWN_HOST)\"  location: \"JS frame :: resource://services-common/rest.js :: onStopRequest :: line 465\"  data: no]","message":null,"code":null,"errno":null} Log.jsm:749:0

1428509305039	FirefoxAccounts	ERROR	HAWK.signCertificate error: {"error":{},"errorString":"[Exception... \"NS_ERROR_UNKNOWN_HOST\"  nsresult: \"0x804b001e (NS_ERROR_UNKNOWN_HOST)\"  location: \"JS frame :: resource://services-common/rest.js :: onStopRequest :: line 465\"  data: no]","message":null,"code":null,"errno":null} Log.jsm:749:0

1428509305040	Sync.BrowserIDManager	ERROR	Non-authentication error in _fetchTokenForUser: {"error":{},"errorString":"[Exception... \"NS_ERROR_UNKNOWN_HOST\"  nsresult: \"0x804b001e (NS_ERROR_UNKNOWN_HOST)\"  location: \"JS frame :: resource://services-common/rest.js :: onStopRequest :: line 465\"  data: no]","message":null,"code":null,"errno":null} Log.jsm:749:0

1428509309113	Sync.BrowserIDManager	ERROR	Failed to fetch a token for authentication: {"error":{},"errorString":"[Exception... \"NS_ERROR_UNKNOWN_HOST\"  nsresult: \"0x804b001e (NS_ERROR_UNKNOWN_HOST)\"  location: \"JS frame :: resource://services-common/rest.js :: onStopRequest :: line 465\"  data: no]","message":null,"code":null,"errno":null}
yeah, this sucks a little but is "by design" in many respects - by default we log "Error" messages to the browser console, and neutering those specific messages to not be errors doesn't make much sense IMO. I wonder if we should just avoid logging anything to the browser console by default - they generally aren't actionable and they will appear in about:sync-log. Richard, what do you think?
Flags: needinfo?(rnewman)
Perhaps we should disable the console appender by default (but keep the pref), but log a message to the console if an error occurred while syncing, saying to look at about:sync-log for details? Shouldn't be too far off the log-if-error stuff you just touched, right?
Flags: needinfo?(rnewman)
This patch takes the easy option :) It adjusts the default for the console appender to be Log.Level.Fatal (which means by default no log messages should end up in the console in practice), but then does a simple |Cu.reportError("Sync encountered an error - see about:sync-log for the log file.");| if an error log is actually written.
Attachment #8603216 - Flags: feedback?(rnewman)
Comment on attachment 8603216 [details] [diff] [review]
0002-Bug-1152116-prevent-Sync-from-spamming-the-browser-c.patch

Review of attachment 8603216 [details] [diff] [review]:
-----------------------------------------------------------------

::: browser/components/readinglist/Scheduler.jsm
@@ +294,5 @@
>        prefs.set("lastSync", new Date().toString());
>        this.state = this.STATE_OK;
> +      this._logManager.resetFileLog().then(result => {
> +        if (result == this._logManager.ERROR_LOG_WRITTEN) {
> +          Cu.reportError("Readinglist sync encountered an error - see about:sync-log for the log file.");

s/Readinglist/Reading List

(throughout)
Attachment #8603216 - Flags: feedback?(rnewman) → review+
Mark: worth filing separate bugs for (a) not syncing in offline mode, (b) the tabs bug, (c) the forms bug (graceful handling).
Assignee: nobody → markh
Status: NEW → ASSIGNED
Component: Sync → Firefox Sync: Backend
Product: Firefox → Mozilla Services
Version: 39 Branch → unspecified
Thanks!

(In reply to Richard Newman [:rnewman] from comment #6)
> Mark: worth filing separate bugs for (a) not syncing in offline mode

Bug 1165809.

> (b) the tabs bug,

Bug 1165811

> (c) the forms bug (graceful handling).

Not sure what this refers to - I can't see a forms error above.
(In reply to Mark Hammond [:markh] from comment #7)

> > (c) the forms bug (graceful handling).
> 
> Not sure what this refers to - I can't see a forms error above.

TypeError: subject is null forms.js:232:14
https://hg.mozilla.org/mozilla-central/rev/1a8c8fa3ed8d
Status: ASSIGNED → RESOLVED
Closed: 5 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla41
(In reply to Richard Newman [:rnewman] from comment #9)
> TypeError: subject is null forms.js:232:14

Doh! Bug 1166987.
Component: Firefox Sync: Backend → Sync
Product: Cloud Services → Firefox
You need to log in before you can comment on or make changes to this bug.