798433 - history failed: NS_ERROR_XPC_JAVASCRIPT_ERROR_WITH_DETAILS

Status: NEW

(Firefox :: Sync, defect)

Description

[Gervase Markham [:gerv]]

Attachment: Sync log with problem

My history is failing to sync. Sample log attached, although I have many more. Please let me know what other info I can provide to help debug the problem.

This is causing Firefox to say "Sync has not been able to complete during the last 7 days. Please check your network settings." This is a misleading error message. If at least some modules are able to complete, then clearly it can't be a problem with the network settings. This message, or at least its second sentence should only be displayed when failure is total.

Gerv

Comment 1

[Gregory Szorc [:gps]]

Comment on attachment 668493 [details]
Sync log with problem

Interesting error log. The most interesting bit:

1349456204035	Sync.Engine.History	INFO	87 outgoing items pre-reconciliation
1349456216801	Sync.Engine.History	WARN	DATA LOSS: Both local and remote changes to record: -c0-GBY3Llov
1349456216986	Sync.SyncScheduler	DEBUG	Next sync in 90000 ms.
1349456222434	Sync.Engine.History	WARN	DATA LOSS: Both local and remote changes to record: 237GNou_5jme
1349456224855	Sync.Status	DEBUG	Status for engine history: error.engine.reason.unknown_fail
1349456224855	Sync.Status	DEBUG	Status.service: success.status_ok => error.sync.failed_partial
1349456224855	Sync.ErrorHandler	DEBUG	history failed: NS_ERROR_XPC_JAVASCRIPT_ERROR_WITH_DETAILS JS Stack trace: [e-mail]:400 < [e-mail]:873 < [e-mail]:1284 < [e-mail]:142 < [e-mail]:481 < [e-mail]:1399 < [e-mail]:1292 < [e-mail]:142 < [e-mail]:97 < [e-mail]:1192 < @service.js:1183 < [e-mail]:71 < [e-mail]:1171

Magic 8 ball says: Places DB corruption.

Comment 2

[Gregory Szorc [:gps]]

If Firefox says "Sync has not been able to complete during the last 7 days" that means Sync hasn't fully completed a sync in the last 7 days. If you have been getting history failures for 7 days without a successful sync, you will see this message.

How many sync error logs do you see in about:sync-log. I'm guessing a lot since oh, 7 days ago. If you enable services.sync.log.appender.file.logOnSuccess in about:config, I'm going to guess that you will see no successful Sync logs until the underlying problem (likely places corruption) is addressed.

Comment 3

[Gervase Markham [:gerv]]

(In reply to Gregory Szorc [:gps] from comment #2)
> If Firefox says "Sync has not been able to complete during the last 7 days"
> that means Sync hasn't fully completed a sync in the last 7 days. If you
> have been getting history failures for 7 days without a successful sync, you
> will see this message.

Sure. It's not that part I object to. It's the suggestion that network settings could be at fault. Clearly, Firefox knows this is not the case, because _some_ bits of sync worked fine.

> How many sync error logs do you see in about:sync-log. I'm guessing a lot
> since oh, 7 days ago.

About 1 an hour since the 5th; a few less further back, although that could have been because I was using my computer less.

> If you enable
> services.sync.log.appender.file.logOnSuccess in about:config, I'm going to
> guess that you will see no successful Sync logs until the underlying problem
> (likely places corruption) is addressed.

I'm sure that's true. But let's say my problem is Places corruption. How, as an average user, could I ever diagnose that? Shouldn't Sync give me a better error message and suggestions on how to fix the problem? Shouldn't Places detect that it has a corruption problem and fix itself or even purge itself?

Gerv

Comment 4

[Gregory Szorc [:gps]]

(In reply to Gervase Markham [:gerv] from comment #3)
> (In reply to Gregory Szorc [:gps] from comment #2)
> > If Firefox says "Sync has not been able to complete during the last 7 days"
> > that means Sync hasn't fully completed a sync in the last 7 days. If you
> > have been getting history failures for 7 days without a successful sync, you
> > will see this message.
> 
> Sure. It's not that part I object to. It's the suggestion that network
> settings could be at fault. Clearly, Firefox knows this is not the case,
> because _some_ bits of sync worked fine.

Yes, the messaging to blame network connections could definitely be improved.


> > How many sync error logs do you see in about:sync-log. I'm guessing a lot
> > since oh, 7 days ago.
> 
> About 1 an hour since the 5th; a few less further back, although that could
> have been because I was using my computer less.

Yeah, you most likely have Places corruption.

> > If you enable
> > services.sync.log.appender.file.logOnSuccess in about:config, I'm going to
> > guess that you will see no successful Sync logs until the underlying problem
> > (likely places corruption) is addressed.
> 
> I'm sure that's true. But let's say my problem is Places corruption. How, as
> an average user, could I ever diagnose that? Shouldn't Sync give me a better
> error message and suggestions on how to fix the problem? Shouldn't Places
> detect that it has a corruption problem and fix itself or even purge itself?

That's a good question. AFAIK Places is supposed to do this automatically, which is why Sync doesn't implement Places smarts. Also, it is difficult for Sync to differentiate between Places corruptions and a random API call failing.

CC'ing mak for Places expertise.

Comment 5

[Marco Bonardo [:mak]]

(In reply to Gregory Szorc [:gps] from comment #4)
> That's a good question. AFAIK Places is supposed to do this automatically,
> which is why Sync doesn't implement Places smarts. Also, it is difficult for
> Sync to differentiate between Places corruptions and a random API call
> failing.

Corruption handling is simple for now, if the db is detected as corrupt (thus not recoverable) we rename it to places.sqlite.corrupt and create a new one. Though, since bug 431274 is not fixed, we don't have a backup, so history in the new database is empty.
That said, this case doesn't look like actual file corruption, that kind of corruption would "just" cause history loss but everything would keep working.

So, please I need at least to know if you have a places.sqlite.corrupt file, and what this extension says if you run an integrity check https://addons.mozilla.org/en-US/firefox/addon/places-maintenance/

Comment 6

[Marco Bonardo [:mak]]

PS: remember to backup profile before any testing on it, don't want you to lose more data than you could have already...

Comment 7

[Gervase Markham [:gerv]]

mak: I do not have a places.sqlite.corrupt file in my profile. If I install the extension you name above, bring up the Preferences, tick "Integrity Check" and hit "Execute", it says:

> Integrity check
+ The database is sane

I can provide you a copy of my places.sqlite file by email if you think it will help. I trust you not to treat it properly :-)

Gerv

Comment 8

[Marco Bonardo [:mak]]

Sure I may take a look at it, if it's not too huge just mail it to my mozilla.com address.

Btw, the above test excludes a physical database corruption, may be a data coherency issue (though would be the first one I hear about in history, usually it's bookmarks that go mad), otherwise the issue could be on remote sync data (though I don't know that well enough to guess anything).

Comment 9

[Marco Bonardo [:mak]]

I took a look at the database, ran many queries to find strange entries, compared to mine, but didn't find anything strange, it just looks plain valid.  No idea atm.

Comment 10

[Richard Newman [:rnewman]]

(In reply to Marco Bonardo [:mak] from comment #9)
> I took a look at the database, ran many queries to find strange entries,
> compared to mine, but didn't find anything strange, it just looks plain
> valid.  No idea atm.

FWIW, we had a few IRC reports recently (e.g., mrz on 2012-09-06) of errors that didn't show up in Places Maintenance, but were fixed by blowing away places.db (i.e., logical inconsistencies). mrz's bookmark bar was missing, for example.

Sorry for not taking the time to try to capture DBs; was kinda rushed with other stuff, and presumed this was the background noise of occasional DB corruption.

Comment 11

[:Felipe Gomes (needinfo for replies!)]

Attachment: Sync-log error

I started getting the same error this week, and can help debug if wanted.
Attached is one of my failed logs

Comment 12

[:Felipe Gomes (needinfo for replies!)]

FWIW I have no places.sqlite.corrupt file, and the Places Maintenance add-on says the database is sane:

> Integrity check
+ The database is sane
> Coherence check
+ The database is coherent

Comment 13

[Tracy Walker [:tracy]]

Just curious, for those seeing this, at some time before this started happening, did you do some history deletion? Just asking to see if we can start to nail down STR's. Can you think of something besides just accumulating browsing history?

Comment 14

[:Felipe Gomes (needinfo for replies!)]

I don't recall deleting any history entries recently

Comment 15

[Gervase Markham [:gerv]]

I don't remember deleting any history entries recently, but I've also probably had this problem for quite some time.

Gerv

Comment 16

[Marco Bonardo [:mak]]

(In reply to Richard Newman [:rnewman] from comment #10)
> FWIW, we had a few IRC reports recently (e.g., mrz on 2012-09-06) of errors
> that didn't show up in Places Maintenance, but were fixed by blowing away
> places.db (i.e., logical inconsistencies). mrz's bookmark bar was missing,
> for example.

Bookmarks are far easier to have coherency issues due to their complexity, but history is just a flat join, I can't see how it could go mad. The only things that come to my mind is invalid values, like for example invalid guids, or visit types, or negatives, future dates... but looking at the DB I got I didn't find any of those.

Comment 17

[Marco Bonardo [:mak]]

Another question to restrict the field of research, do you by chance all have a  Firefox on Android linked to the Sync account? Since it doesn't use Places anymore there could be some incompatibility issue in sharing data.

Comment 18

[Gervase Markham [:gerv]]

Yep, I have a linked Android.

I think someone is going to need to watch the code as it processes the SQL and work out which part of it is causing it to barf...

Gerv

Comment 19

[Gervase Markham [:gerv]]

mak: were you able to reproduce the problem with the sqlite file I sent you?

Gerv