Closed Bug 809171 Opened 12 years ago Closed 12 years ago

Work - Sync setup fails, unresponsive script (async.js:127, async.js:94, async.js:96)

Categories

(Firefox for Metro Graveyard :: Sync, defect)

x86
Windows 8.1
defect
Not set
normal

Tracking

(Not tracked)

RESOLVED FIXED
Firefox 23

People

(Reporter: ally, Assigned: jimm)

References

Details

(Whiteboard: [sync:metro] feature=work)

Attachments

(4 files)

1) set up sync on tablet, pair with jpake to a desktop with credentials (aurora fwiw) 2) progress bar pops up on both machines 3) progress bar on desktop on finishes 4) progress bar on metro hangs at halfway point. win8 pops up 'unresponsive script' warning for async.js ln 94 5) I click ok (figuring the wifi is spotty) to let it run 6) 15+ minutes later, on win8 the last sync is still listed as in progress, the progress bar is still hanging, no logs of any sort appear. However, the jpake appears to have completed as the correct credentials are on the machine.
Blocks: 801056
I also note that there is an Error: uncaught exception: Error opening input scream (invalid filename?) appearing in my error console. hard to say if that occurs at the same time as the pref pane & console cannot both be open at the same time
Keywords: verifyme
QA Contact: jbecerra
I'm making some changes to the build config associated with sync code, I can test this after I'm done.
Depends on: 815320
OS: Mac OS X → Windows 8 Metro
Version: unspecified → Trunk
Attached file log 1 (deleted) —
I did find two logs after I got setup to (mostly) complete (round 4 or 5 with mbrubecks patch for setup) I did not find any success logs. they may be relevant, or a different problem.
Attached file log 2 (deleted) —
I have not been able to reproduce this bug on my Samsung Series 7.
No longer depends on: 815320
Depends on: 817076
In testing on a fresh profile I get the following: 1) successful setup and the start of sync (bookmarks) I have a lot of bookmarks, so this takes a long time. During the process I don't see the progress meter in the metro overlay advance. 2) I get a slow script dialog and hit ok This appears to break the sync process, the sync engine then goes into a continuous loop as such: 1354640326861 Sync.Collection DEBUG mesg: GET success 200 https://phx-sync439.services.mozilla.com/1.1/u... 1354640326939 Sync.Collection DEBUG GET success 200 https://phx-sync439.services.mozilla.com/1.1/uvcu... 1354640328290 Sync.SyncScheduler DEBUG Global Score threshold hit, triggering sync. 1354640328309 Sync.Service DEBUG User-Agent: MetroFirefox/20.0a1 FxSync/1.22.0.20121204103324. 1354640328314 Sync.Service INFO Starting sync at 2012-12-04 10:58:48 1354640328319 Sync.Service DEBUG Exception: Could not acquire lock. Label: "service.js: sync". No traceback available 1354640328324 Sync.Service INFO Cannot start sync: already syncing? This repeats over and over.
On a restart of the browser, sync kicks in a syncs everything again. I also see sync hitting the network once ever two or three seconds, which seems very wrong.
Blocks: metro-sync
No longer blocks: 801056
This may be the result of WeaveGlue.sync() running its own dispatch loop. We should investigate interaction between WeaveGlue.sync()'s implementation and the metro event dispatch requirements. (See the metro dispatch loop in nsAppShell.)
Keywords: verifyme
Whiteboard: [sync] → [sync][metro-mvp][LOE:2]
(In reply to Jim Mathies [:jimm] from comment #9) > This may be the result of WeaveGlue.sync() running its own dispatch loop. We > should investigate interaction between WeaveGlue.sync()'s implementation and > the metro event dispatch requirements. (See the metro dispatch loop in > nsAppShell.) WeaveGlue is really bitrotted, by the look of it. (For example, Weave.Engines no longer exists.) I would be really surprised if it worked at all. But that's neither here nor there. WeaveGlue does not run any kind of dispatch loop, and neither does Sync. Sync spins the main event loop while waiting for async callbacks (which causes all kinds of potential havoc from re-entrancy, but that's another story). WeaveGlue.sync simply calls Service.sync. (Note that it should not: it should call SyncScheduler.scheduleNextSync(). Like I said, bitrotted.) (In reply to Jim Mathies [:jimm] from comment #7) > This appears to break the sync process, the sync engine then goes into a > continuous loop as such: If you kill the script, it'll never release the lock, and Sync won't work again for the duration of the session. Don't Do That®. :)
Whiteboard: [sync][metro-mvp][LOE:2] → [sync:metro][metro-mvp][LOE:2]
Whiteboard: [sync:metro][metro-mvp][LOE:2] → [metro-mvp] [LOE:2] [sync:metro]
Whiteboard: [metro-mvp] [LOE:2] [sync:metro] → [metro-mvp] [LOE:2] [sync:metro] feature=work
Blocks: 831614
Summary: Sync setup fails, unresponsive script async.js ln 94 → Work - Sync setup fails, unresponsive script async.js ln 94
Blocks: 831615
No longer blocks: metro-sync
general->sync 10 bugs
Component: General → Sync
No longer blocks: 831614
Blocks: 849312
No longer blocks: 831615
Summary: Work - Sync setup fails, unresponsive script async.js ln 94 → Work - Sync setup fails, unresponsive script (async.js:127, async.js:94, async.js:96)
Whiteboard: [metro-mvp] [LOE:2] [sync:metro] feature=work → [sync:metro] feature=work
This is kind of interesting. I tend to get this after syncing all my bookmaks, which can take a bit of time. From the start of the bookmark engine sync, a total time of 52 seconds is taken - 1367441882237 Sync.Engine.Bookmarks DEBUG Engine syncIDs: sGgVEoWmvTwv,3bvG8tC9eY69 1367441934758 Sync.Engine.Bookmarks INFO Records: 1238 applied, 1238 successfully, 0 failed to apply, 0 newly failed to apply, 18 reconciled. 1367441934758 - 1367441882237 = 52,521 / 1000 = 52.521s and the duration calculation for the slow script dialog matches this perfectly: http://mxr.mozilla.org/mozilla-central/source/dom/base/nsJSEnvironment.cpp#730 which equals 54425000 (54.425s) which triggers the dialog. During all this the event loop is being processed. But our slow script detection seems to get tripped up by the top level bookmarks code being on the stack for a long time.
(In reply to Richard Newman [:rnewman] from comment #10) > (In reply to Jim Mathies [:jimm] from comment #9) > > This may be the result of WeaveGlue.sync() running its own dispatch loop. We > > should investigate interaction between WeaveGlue.sync()'s implementation and > > the metro event dispatch requirements. (See the metro dispatch loop in > > nsAppShell.) > > WeaveGlue is really bitrotted, by the look of it. (For example, > Weave.Engines no longer exists.) > > I would be really surprised if it worked at all. > > But that's neither here nor there. > > WeaveGlue does not run any kind of dispatch loop, and neither does Sync. > Sync spins the main event loop while waiting for async callbacks (which > causes all kinds of potential havoc from re-entrancy, but that's another > story). > > WeaveGlue.sync simply calls Service.sync. > > (Note that it should not: it should call SyncScheduler.scheduleNextSync(). > Like I said, bitrotted.) So I wonder if it's the chrome script that calls WeaveGlue.sync that's getting caught? I need to dig into our sync setup ui.
Ok, I've been able to address this per rnewman's advice by swapping out the call to sync() with scheduleNextSync(0) here - http://mxr.mozilla.org/mozilla-central/source/browser/metro/base/content/sync.js#373 We should do the same for the sync button and any other calls to the "sync" api. I'll also file a follow up on ripping out any use of bitrotted Weave code.
> I'll also file a follow up on ripping out any use of bitrotted Weave code. WeaveGlue, not 'Weave code'. I'm also going to rename this module to 'Sync'.
Attached patch patch (deleted) — Splinter Review
This is a pretty minor change, most of the changes involve renaming WeaveGlue to Sync. I've also replaced two calls to Weave.sync() with Weave.Service.scheduler.scheduleNextSync(0), which fixes the slow script problem.
Assignee: nobody → jmathies
Attachment #744305 - Flags: review?(mbrubeck)
Attachment #744305 - Flags: review?(mbrubeck) → review+
Status: NEW → RESOLVED
Closed: 12 years ago
Resolution: --- → FIXED
Target Milestone: --- → Firefox 23
OS: Windows 8 Metro → Windows 8.1
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: