Closed Bug 492560 Opened 12 years ago Closed 12 years ago

slow script dialog appears while print dialogs are open

Categories

(Core :: DOM: Core & HTML, defect)

x86
macOS
defect
Not set
normal

Tracking

()

RESOLVED FIXED
mozilla1.9.2a1
Tracking Status
status1.9.1 --- .4-fixed

People

(Reporter: Gavin, Assigned: sicking)

References

(Blocks 1 open bug)

Details

(Keywords: verified1.9.1)

Attachments

(5 files, 6 obsolete files)

This might only happen when printing from the DOM's window.print();.

STR:
1) Load data:text/html,<a href="javascript:print()">print</a>
2) Click print
3) Wait/play around with print settings/add a new printer (for 30 seconds or so)

Sometimes the slow script dialog appears behind the print dialog, sometimes it appears after waiting that long and attempting to cancel the dialog. Sometimes it steals focus in a way that seems to break stuff, such that it's impossible to dismiss either dialog.

This might be hard to reproduce consistently.
Flags: blocking1.9.1?
> Sometimes it steals focus in a way that seems to break stuff, such
> that it's impossible to dismiss either dialog.

I haven't yet had a chance to try to reproduce this, but I'll bet it's
bug 476541.

If it's hard to reproduce, it probably shouldn't block 1.9.1.
It's not "hard to reproduce", because I see it fairly often when I'm printing. It is "hard to reproduce consistently", because I'm not able to reproduce it at will with a given set of steps.
(In reply to comment #1)
> > Sometimes it steals focus in a way that seems to break stuff, such
> > that it's impossible to dismiss either dialog.
> 
> I haven't yet had a chance to try to reproduce this, but I'll bet it's
> bug 476541.

Ah, yeah, that seems likely.

I guess this bug should focus on the fact that the slow script warning appears at all, then. It's probably related to the recent comments in bug 492410. It seems like we may be forgetting to take into account sub-event loops (the print dialog's?) when determining whether the slow script warning needs to appear?
Assignee: nobody → general
Component: General → JavaScript Engine
QA Contact: general → general
Sounds like the DOM might need to suspend the timer?  I think we have API for that.
We're going to take bug 492410's disabling of slow scripts for chrome, so this doesn't need to block.
Flags: blocking1.9.1? → blocking1.9.1-
Summary: Slow script dialog appears while print dialog is open → slow script dialog appears while system dialogs are open (file->open, print)
Duplicate of this bug: 493578
I encountered this bug with Gecko/20090526 Shiretoko/3.5pre after clicking a print link on a web page.  The continue script dialog had a somewhat strange interaction with the print dialog, taking focus but not taking foreground.  Took me awhile to figure out why the app was frozen.
Renominating: it turns out that when you're doing something that takes a while, like printing to PDF or picking which printer you want to use, you can get a slow script dialog pretty frequently. The following STR:

1. Go to www.globeandmail.com
2. Click through to any article
3. Click the button to Print the page
4. Click PDF...
5. Spend a few seconds filing it somewhere (maybe 10 or 15s?)

Expected: it saves a PDF

Actual: you get a slow script warning

http://www.grabup.com/uploads/ce75897e02d71dee600e11fa9337a7dc.png
Flags: blocking1.9.1- → blocking1.9.1?
Do we have an API to suspend the timer thread when we spin the event loop this way?

Also: does this happen only on Mac?
We could wallpaper this by bracketing

http://mxr.mozilla.org/mozilla-central/source/dom/base/nsGlobalWindow.cpp#4474

with calls to something that can neuter nsJSContext::DOMOperationCallback.  Don't know if there are other cases that can trip this, though -- alert/prompt/confirm?
Wait, I just saw File -> Open in the summary.  How do we trip that one?
That comes from bug 493578, which may have actually been fixed by bug 492410. It's conceivable that <input type="file">-triggered dialogs have the same issue, though.
http://mxr.mozilla.org/mozilla-central/source/dom/base/nsJSEnvironment.cpp#1104 looks like what we could use to suspend the callback across the print dialog, but nsGlobalWindow can't see nsJSEnvironment::DOMOperationCallback, so we'd need to expose a helper or something.

bent: what say you?
Assignee: general → nobody
Component: JavaScript Engine → DOM
QA Contact: general → general
(In reply to comment #9)
> Also: does this happen only on Mac?

I've only seen it there, and cannot reproduce on Windows.
Component: DOM → JavaScript Engine
Component: JavaScript Engine → DOM
(Would a regression window help us on this bug, or is it not needed?)
Attached patch Possible fix. (obsolete) — Splinter Review
I can't reproduce this, so I can't verify that this actually fixes this bug, but it seems like it should. Can someone who's seeing this give this patch a spin? It's not ready to land, but good enough for testing this theory...
Attached patch Branch patch (obsolete) — Splinter Review
Just pushed this to try, we'll see how it goes.
Tryserver builds for 1.9.1 are beginning to show up here, anyone who was able to reproduce want to give them a spin?

https://build.mozilla.org/tryserver-builds/bturner@mozilla.com-try-37331cf130d/
Because this isn't 100% reproducible, I think we shouldn't block on it, but if this patch gets reviewed (who's good for that) and we're sure that we're pairing our enter-modal-state and exit-modal-state flags in a way that can't be defeated through other exit mechanisms in the print dialog, I'd be happy to take this patch.
Flags: wanted1.9.1.x+
Flags: blocking1.9.1?
Flags: blocking1.9.1-
(In reply to comment #18)
> Tryserver builds for 1.9.1 are beginning to show up here, anyone who was able
> to reproduce want to give them a spin?
> 
> https://build.mozilla.org/tryserver-builds/bturner@mozilla.com-try-37331cf130d/

Unfortunately, I was able to reproduce this bug using that build. In this case I was using the STR from comment 1 (I've also tried others, including using "Print all" in Gmail to attempt to get reliable testcase).
Gavin, any chance you could stick a breakpoint where we call prompt->ConfirmEx() in nsJSContext::DOMOperationCallback() and show us what the stack is when you hit that in this situation?
Attached file stack
Was finally able to catch this in gdb (1.9.1 build without the patch), here's the stack to the prompt->ConfirmEx call.
So I bet the reason our normal alerts don't trigger this is just because of bug 296310....
Attached patch Possible and more likely fix. (obsolete) — Splinter Review
So the reason my first possible fix didn't work here is that we spin the modal print dialog w/o going through the code that notifies the global window about us opening a modal dialog. Ideally there'd be a single place where we could do those notifications, but as evident by gavin's stack it doesn't seem like such a single location exists. So this adds the notifications around the call to the web browser printing code. If this really is a problem for file picker dialogs as well, we'd need to do the same there, and anywhere else where we're opening modal dialogs w/o going through the prompt service, for this approach to work, that is.

This patch is the same as the first attachment, with the exception of the addition of the first hunk (change to nsGlobalWindow::Print(), and one minor tweak to nsJSEnvironment.cpp which doesn't really matter for testing this).
Attachment #380080 - Attachment is obsolete: true
Attachment #380217 - Attachment is obsolete: true
Same for 1.9.1, with one more fix that I forgot in the trunk version (there's two calls into our web browser print code that need the same treatment).
Duplicate of this bug: 486017
For what it's worth, I think that this bug is pretty severe and deserves consideration for the Firefox 3.5 release.  I encountered it several times yesterday while trying to print/save data for some important financial transactions.  If the browser had actually frozen or if I hadn't noticed that a script dialog was hidden behind the print and save dialogs (and worked out what to do with it), it could have been quite bad (dataloss, even?).  If hitting this is common on financial sites (also as first reported in the duplicate above), it could lead to some very unhappy users.
I uploaded the 1.9.1 patch to tryserver. Look for 'printmodal_191'
somewhere here https://build.mozilla.org/tryserver-builds/?C=M;O=D
(Compilation takes an hour or two)
Attached file different stack
Unfortunately I'm still able to get a slow script dialog to appear with that patch applied, though in slightly different circumstances. I now get it as soon as I cancel the dialog. when control returns to the script apparently. The testcase I'm using here is data:text/html,<a href="javascript:print()">print</a> .
Maybe that case is exacerbated by the use of the asynchronously-evaluated javascript: URI, though, which is probably uncommon in practice. I'll test without it.
Attached file yet another stack
This is from canceling the dialog after launching it from data:text/html,<a href="#" onclick="print()">print</a>, still with that patch applied on a 1.9.1 build. For some reason this bug is much easier reproduce now than it was last time I tried (without the patch) - the dialog wasn't even up for 30 seconds and it still triggered the warning when canceling it.
Going to take a look at this in a debugger with Gavin in a bit, seems like we're not resetting the duration math correctly?
So we changed the prefs in 1.9.1 (but not on trunk) to make the timeout for chrome code to be ~20 minutes.

Gavin, are you running a 1.9.1 build with default prefs and still seeing this?
Actually, the timeout is some 146000 years :)
Would chrome code matter here?  It's been pointed out that it's content script that's running when we post the dialog.
(but yes, I'm using a 1.9.1 build with the default pref values)
I did see one problem with the math. The code attempts to deal with multiple nested modal dialogs being entered recursively. However in this case, the time spent in the inner dialog is counted towards both the inner and outer dialog, and thus subtracted twice.

That shouldn't be what causes the problem Gavin is seeing, since it'd have the opposite effect (we'd be waiting too long before bringing up slow script dialog), but it's something we should fix.

I wonder if the problem is that we schedule the slow-script dialog while the print dialog is open. The subtraction doesn't happen until after the print dialog is closed.

I'll try to write up a patch and we'll see if fixing this will help.
I think we need to disconnect the slow-script-checking machinery on the DOM side entirely when we fly a modal dialog, and then reconnect it with a reset counter when the last one comes down?
Attached patch Fixed fix. Trunk version (obsolete) — Splinter Review
Assignee: nobody → jonas
Attachment #380687 - Attachment is obsolete: true
Attachment #380688 - Attachment is obsolete: true
Attachment #382626 - Flags: superreview?(mrbkap)
Attachment #382626 - Flags: review?(mrbkap)
Attached patch Fixed fix. Branch version (obsolete) — Splinter Review
The problem was (assuming I'm correct) that we used mOperationCallbackTime=0 to indicate that mOperationCallbackTime hadn't been set yet. So if no operations callback happened before we opened the modal window, we'd add some time to mOperationCallbackTime, making it non-zero, but very very small. So the next time there was an operations callback we'd immediately put up the slow-script dialog.
Attachment #382631 - Flags: superreview?(mrbkap)
Attachment #382631 - Flags: review?(mrbkap)
Attachment #382626 - Flags: superreview?(mrbkap)
Attachment #382626 - Flags: superreview?(bent.mozilla)
Attachment #382626 - Flags: review?(mrbkap)
Attachment #382626 - Flags: review?(bent.mozilla)
Attachment #382631 - Flags: superreview?(mrbkap)
Attachment #382631 - Flags: superreview?(bent.mozilla)
Attachment #382631 - Flags: review?(mrbkap)
Attachment #382631 - Flags: review?(bent.mozilla)
Attachment #382626 - Flags: superreview?(bent.mozilla)
Attachment #382626 - Flags: review?(bent.mozilla)
Attachment #382626 - Flags: review+
Comment on attachment 382626 [details] [diff] [review]
Fixed fix. Trunk version

>+// XXX bump

This is done, right?

>+  
>+  --mModalStateDepth;
>+  

Trailing whitespace.

>+  if (!mModalStateTime) {
>+    mOperationCallbackTime = PR_Now();
>+  }
>+  else {
>+    mOperationCallbackTime += PR_Now() - mModalStateTime;
>+  }

Add a comment that says why you're doing this. Maybe reverse the order of your if test too.
Attachment #382631 - Flags: superreview?(bent.mozilla)
Attachment #382631 - Flags: review?(bent.mozilla)
Attachment #382631 - Flags: review+
Comment on attachment 382631 [details] [diff] [review]
Fixed fix. Branch version

See previous comments
I've tested a 1.9.1 build with the branch patch and haven't been able to get the slow script dialog to appear anymore, so looking good from my POV.
Attachment #382626 - Attachment is obsolete: true
Attachment #382631 - Attachment is obsolete: true
Attachment #382881 - Flags: superreview?(mrbkap)
Attachment #382631 - Flags: approval1.9.1?
Attachment #382881 - Flags: superreview?(mrbkap) → superreview+
Attachment #382882 - Flags: superreview?(mrbkap) → superreview+
Oh, those srs are conditional on actually removing that trailing whitespace.
Comment on attachment 382882 [details] [diff] [review]
Fix review comments. Branch

Patch should be very safe. It's very understood what the problem in the code is, and the patch is very simple.

At worst we're marking too many or too few places as being in-modal-dialog. Marking too few is no worse than doing nothing, and marking too many would only result in not putting up the slow-script dialog as much as we should.
As for testing. Not really sure if we can write an automated test for this, but gavin did some testing (comment 46) and things seem fine.
Potential ride-along if we have an RC2, IMO. Let's get this on trunk, first?
Landed on trunk earlier today

http://hg.mozilla.org/mozilla-central/rev/497fe6fed36e
Status: NEW → RESOLVED
Closed: 12 years ago
Resolution: --- → FIXED
(In reply to comment #51)
> As for testing. Not really sure if we can write an automated test for this, but
> gavin did some testing (comment 46) and things seem fine.

I'm pretty sure it's within the realm of possibility, given that we control the code that enters this state, gets a notification from the JS engine, and decides what to do based on it.  Might need to be a unit test rather than a mochitest, but it's not like we're risking overdose on those. :)
Whiteboard: [3.5RC2?]
Since this fix ended up being print-specific, I'm going to reopen bug 493578.
Summary: slow script dialog appears while system dialogs are open (file->open, print) → slow script dialog appears while print dialogs are open
Is my reading of this bug correct that it should be fixed in 3.5?  If so, I regret to inform you that the bug is very much alive in the released version of 3.5:  Mozilla/5.0 (Macintosh; U; Intel Mac OS X 10.5; en-US; rv:1.9.1) Gecko/20090624 Firefox/3.5.  If my reading is wrong, does that mean it would be fixed in the next patch?
Attachment #382882 - Flags: approval1.9.1? → approval1.9.1.1?
> Is my reading of this bug correct that it should be fixed in 3.5?

No.

> does that mean it would be fixed in the next patch?

Possibly.  See the approval request on the attachment here.
I'm not sure if this has been stated specifically yet, but this bug can put Firefox in a state of having multiple modal dialogs where the application is basically frozen, and the only way out is to do a force quit (which is a bit worse than just having to click continue).
(In reply to comment #58)

It was alluded to in comment #1 (and part of comment #0).

The issue you've described is bug 476541.
Comment on attachment 382882 [details] [diff] [review]
Fix review comments. Branch

Is there no way to add a test for this?
Attachment #382882 - Flags: approval1.9.1.1?
Attachment #382882 - Flags: approval1.9.1.2? → approval1.9.1.3?
Comment on attachment 382882 [details] [diff] [review]
Fix review comments. Branch

Not for 1.9.1.2.
Comment on attachment 382882 [details] [diff] [review]
Fix review comments. Branch

Approved for 1.9.1.4, a=dveditz for release-drivers
Attachment #382882 - Flags: approval1.9.1.3? → approval1.9.1.4+
Would be great if someone could land this since I'm on vacation
Keywords: checkin-needed
Ben or Blake: Can you shepherd this in?
http://hg.mozilla.org/releases/mozilla-1.9.1/rev/30aba29be97c
Keywords: checkin-needed
Whiteboard: [3.5RC2?]
Target Milestone: --- → mozilla1.9.2a1
Verified fixed in 1.9.1.4 with Mozilla/5.0 (Macintosh; U; Intel Mac OS X 10.6; en-US; rv:1.9.1.4pre) Gecko/20090914 Shiretoko/3.5.4pre. It also reproduces on Windows with 1.9.1.3 and is fixed there in 1.9.1.4 as well.
Keywords: verified1.9.1
Component: DOM → DOM: Core & HTML
You need to log in before you can comment on or make changes to this bug.