Bug 81141 - REGRESSION(r103452): 100% CPU usage and 5s pause after clicking on a link in Yahoo Mail
Summary: REGRESSION(r103452): 100% CPU usage and 5s pause after clicking on a link in ...
Status: RESOLVED FIXED
Alias: None
Product: WebKit
Classification: Unclassified
Component: DOM (show other bugs)
Version: 528+ (Nightly build)
Hardware: Mac OS X 10.7
: P2 Normal
Assignee: Adam Klein
URL:
Keywords: InRadar
Depends on:
Blocks:
 
Reported: 2012-03-14 12:16 PDT by Jon Lee
Modified: 2012-03-15 18:24 PDT (History)
9 users (show)

See Also:


Attachments
Patch (6.29 KB, patch)
2012-03-14 16:20 PDT, Adam Klein
no flags Details | Formatted Diff | Diff

Note You need to log in before you can comment on or make changes to this bug.
Description Jon Lee 2012-03-14 12:16:00 PDT
Log into yahoo mail, and try to open an email that contain an email link. Just loading that email causes a spike in CPU. Opening the link is delayed by quite a few seconds before it opens in a new tab.

CC'ed devs involved in checkin.

<rdar://problem/10839734>
Comment 1 Adam Klein 2012-03-14 12:36:17 PDT
Can't reproduce with latest Chrome Canary on Mac. Given the nature of http://trac.webkit.org/changeset/103452, I'm quite surprised it'd cause a regression that doesn't manifest itself on all ports (leaving aside that the change was supposed to have no effect on behavior). Can you give some background on how you narrowed the regression down to this change?
Comment 2 Jon Lee 2012-03-14 13:14:51 PDT
(In reply to comment #1)
> Can't reproduce with latest Chrome Canary on Mac. Given the nature of http://trac.webkit.org/changeset/103452, I'm quite surprised it'd cause a regression that doesn't manifest itself on all ports (leaving aside that the change was supposed to have no effect on behavior). Can you give some background on how you narrowed the regression down to this change?

We have an internal tool that allows us to binary search builds in order to hunt down checkins that cause regressions.
Comment 3 Adam Klein 2012-03-14 13:26:57 PDT
I can't reproduce this at r109773 on WebKit Mac/Snow Leopard. Is there something Lion-specific about it?
Comment 4 Jon Lee 2012-03-14 14:05:44 PDT
An excerpt of the spin dump on Lion:

382 WebCore::JSHTMLElement::put(JSC::JSCell*, JSC::ExecState*, JSC::Identifier const&, JSC::JSValue, JSC::PutPropertySlot&) + 62 (in WebCore) [0x10707705e]
  382 bool JSC::lookupPut<WebCore::JSHTMLElement>(JSC::ExecState*, JSC::Identifier const&, JSC::JSValue, JSC::HashTable const*, WebCore::JSHTMLElement*, bool) + 251 (in WebCore) [0x10707786b]
    382 WebCore::setJSHTMLElementId(JSC::ExecState*, JSC::JSObject*, JSC::JSValue) + 104 (in WebCore) [0x1069493b8]
      382 WebCore::Element::setAttributeInternal(unsigned long, WebCore::QualifiedName const&, WTF::AtomicString const&, WebCore::EInUpdateStyleAttribute) + 381 (in WebCore) [0x106ed620d]
        382 WebCore::Node::dispatchSubtreeModifiedEvent() + 297 (in WebCore) [0x1068622c9]
          382 WebCore::Node::dispatchScopedEvent(WTF::PassRefPtr<WebCore::Event>) + 67 (in WebCore) [0x106a59583]
            382 WebCore::EventDispatcher::dispatchScopedEvent(WebCore::Node*, WTF::PassRefPtr<WebCore::EventDispatchMediator>) + 204 (in WebCore) [0x106ed965c]
              382 WebCore::ScopedEventQueue::enqueueEventDispatchMediator(WTF::PassRefPtr<WebCore::EventDispatchMediator>) + 175 (in WebCore) [0x1072527ff]
                382 WebCore::EventDispatcher::dispatchEvent(WebCore::Node*, WTF::PassRefPtr<WebCore::EventDispatchMediator>) + 146 (in WebCore) [0x106ed9572]
                  382 WebCore::EventDispatchMediator::dispatchEvent(WebCore::EventDispatcher*) const + 37 (in WebCore) [0x1067afff5]
                    382 WebCore::EventDispatcher::dispatchEvent(WTF::PassRefPtr<WebCore::Event>) + 943 (in WebCore) [0x1067b03df]
                      382 WebCore::EventContext::handleLocalEvents(WebCore::Event*) const + 86 (in WebCore) [0x106859796]
                        382 WebCore::Node::handleLocalEvents(WebCore::Event*) + 170 (in WebCore) [0x1067b0bba]
                          382 WebCore::EventTarget::fireEventListeners(WebCore::Event*) + 69 (in WebCore) [0x1067b0ae5]
                            382 WebCore::EventTarget::fireEventListeners(WebCore::Event*, WebCore::EventTargetData*, WTF::Vector<WebCore::RegisteredEventListener, 1ul>&) + 212 (in WebCore) [0x10684dc94]
                              382 WebCore::JSEventListener::handleEvent(WebCore::ScriptExecutionContext*, WebCore::Event*) + 920 (in WebCore) [0x10684e188]
                                382 JSC::call(JSC::ExecState*, JSC::JSValue, JSC::CallType, JSC::CallData const&, JSC::JSValue, JSC::ArgList const&) + 49 (in JavaScriptCore) [0x10647a941]
                                  382 JSC::Interpreter::executeCall(JSC::ExecState*, JSC::JSObject*, JSC::CallType, JSC::CallData const&, JSC::JSValue, JSC::ArgList const&) + 879 (in JavaScriptCore) [0x10647acbf]
                                    374 ??? [0x50e0d571edc9]
                                      374 operationPutByIdNonStrict + 64 (in JavaScriptCore) [0x1065462b0]
                                        374 WebCore::JSHTMLElement::put(JSC::JSCell*, JSC::ExecState*, JSC::Identifier const&, JSC::JSValue, JSC::PutPropertySlot&) + 62 (in WebCore) [0x10707705e]
                                          374 bool JSC::lookupPut<WebCore::JSHTMLElement>(JSC::ExecState*, JSC::Identifier const&, JSC::JSValue, JSC::HashTable const*, WebCore::JSHTMLElement*, bool) + 251 (in WebCore) [0x10707786b]
                                            374 WebCore::setJSHTMLElementId(JSC::ExecState*, JSC::JSObject*, JSC::JSValue) + 104 (in WebCore) [0x1069493b8]
                                              374 WebCore::Element::setAttributeInternal(unsigned long, WebCore::QualifiedName const&, WTF::AtomicString const&, WebCore::EInUpdateStyleAttribute) + 381 (in WebCore) [0x106ed620d]
                                                374 WebCore::Node::dispatchSubtreeModifiedEvent() + 297 (in WebCore) [0x1068622c9]
                                                  374 WebCore::Node::dispatchScopedEvent(WTF::PassRefPtr<WebCore::Event>) + 67 (in WebCore) [0x106a59583]
                                                    374 WebCore::EventDispatcher::dispatchScopedEvent(WebCore::Node*, WTF::PassRefPtr<WebCore::EventDispatchMediator>) + 204 (in WebCore) [0x106ed965c]
                                                      374 WebCore::ScopedEventQueue::enqueueEventDispatchMediator(WTF::PassRefPtr<WebCore::EventDispatchMediator>) + 175 (in WebCore) [0x1072527ff]
                                                        374 WebCore::EventDispatcher::dispatchEvent(WebCore::Node*, WTF::PassRefPtr<WebCore::EventDispatchMediator>) + 146 (in WebCore) [0x106ed9572]
                                                          374 WebCore::EventDispatchMediator::dispatchEvent(WebCore::EventDispatcher*) const + 37 (in WebCore) [0x1067afff5]
                                                            374 WebCore::EventDispatcher::dispatchEvent(WTF::PassRefPtr<WebCore::Event>) + 835 (in WebCore) [0x1067b0373]
                                                              374 WebCore::Node::handleLocalEvents(WebCore::Event*) + 170 (in WebCore) [0x1067b0bba]
                                                                374 WebCore::EventTarget::fireEventListeners(WebCore::Event*) + 69 (in WebCore) [0x1067b0ae5]
                                                                  374 WebCore::EventTarget::fireEventListeners(WebCore::Event*, WebCore::EventTargetData*, WTF::Vector<WebCore::RegisteredEventListener, 1ul>&) + 212 (in WebCore) [0x10684dc94]
                                                                    374 WebCore::JSEventListener::handleEvent(WebCore::ScriptExecutionContext*, WebCore::Event*) + 920 (in WebCore) [0x10684e188]
                                                                      374 JSC::call(JSC::ExecState*, JSC::JSValue, JSC::CallType, JSC::CallData const&, JSC::JSValue, JSC::ArgList const&) + 49 (in JavaScriptCore) [0x10647a941]
                                                                        374 JSC::Interpreter::executeCall(JSC::ExecState*, JSC::JSObject*, JSC::CallType, JSC::CallData const&, JSC::JSValue, JSC::ArgList const&) + 879 (in JavaScriptCore) [0x10647acbf]
                                                                          365 ??? [0x50e0d571edc9]
                                                                            365 operationPutByIdNonStrict + 64 (in JavaScriptCore) [0x1065462b0]
                                                                              365 WebCore::JSHTMLElement::put(JSC::JSCell*, JSC::ExecState*, JSC::Identifier const&, JSC::JSValue, JSC::PutPropertySlot&) + 62 (in WebCore) [0x10707705e]
                                                                                365 bool JSC::lookupPut<WebCore::JSHTMLElement>(JSC::ExecState*, JSC::Identifier const&, JSC::JSValue, JSC::HashTable const*, WebCore::JSHTMLElement*, bool) + 251 (in WebCore) [0x10707786b]
                                                                                  365 WebCore::setJSHTMLElementId(JSC::ExecState*, JSC::JSObject*, JSC::JSValue) + 104 (in WebCore) [0x1069493b8]
                                                                                    365 WebCore::Element::setAttributeInternal(unsigned long, WebCore::QualifiedName const&, WTF::AtomicString const&, WebCore::EInUpdateStyleAttribute) + 381 (in WebCore) [0x106ed620d]
                                                                                      365 WebCore::Node::dispatchSubtreeModifiedEvent() + 297 (in WebCore) [0x1068622c9]

etc.etc.

Looks like there is recursive invocation of the mutation event. You can see this by getting the nightlies surrounding the change.
Comment 5 Adam Klein 2012-03-14 15:14:12 PDT
Thanks for the spin dump.

Looks like there's a DOMSubtreeModified listener modifying the ID each time it's called. Before r103452, only adding or removing an attribute would cause this event to fire, not modifying an existing one. Now it's possible to spin with a simple listener like:

function() { someDiv.id = 'foo'; }

This new behavior was an inadvertent side effect of a refactor that made the code more consistent. Based on the (rather unfortunately broad) spec, http://www.w3.org/TR/DOM-Level-3-Events/#event-type-DOMSubtreeModified, it seems like the behavior after r103452 is closer to the spec, and this sort of bug is easy to fix for a web app. But we could still consider suppressing the event in this case, given that mutation events are deprecated and to avoid making them any more powerful (useful to webapps) than they already were.

Adding some folks who may have input.
Comment 6 Adam Klein 2012-03-14 16:20:38 PDT
Created attachment 131952 [details]
Patch
Comment 7 Ryosuke Niwa 2012-03-14 17:38:26 PDT
Do we really want to make this change? It seems like this is an evangelical issue unless we see the same issues on other websites.
Comment 8 Adam Klein 2012-03-15 10:55:22 PDT
(In reply to comment #7)
> Do we really want to make this change? It seems like this is an evangelical issue unless we see the same issues on other websites.

My thinking (and Ojan's too) is that there's nothing to be gained from making DOMSubtreeModified any more useful. So given that WebKit didn't previously fire it in the case of an attribute modification, why not treat the change in behavior as a regression just like any other?
Comment 9 Ryosuke Niwa 2012-03-15 11:02:18 PDT
(In reply to comment #8)
> (In reply to comment #7)
> > Do we really want to make this change? It seems like this is an evangelical issue unless we see the same issues on other websites.
> 
> My thinking (and Ojan's too) is that there's nothing to be gained from making DOMSubtreeModified any more useful. So given that WebKit didn't previously fire it in the case of an attribute modification, why not treat the change in behavior as a regression just like any other?

On the other hand, don't they (website) have the same issue on Gecko?
Comment 10 Adam Klein 2012-03-15 11:09:16 PDT
(In reply to comment #9)
> (In reply to comment #8)
> > (In reply to comment #7)
> > > Do we really want to make this change? It seems like this is an evangelical issue unless we see the same issues on other websites.
> > 
> > My thinking (and Ojan's too) is that there's nothing to be gained from making DOMSubtreeModified any more useful. So given that WebKit didn't previously fire it in the case of an attribute modification, why not treat the change in behavior as a regression just like any other?
> 
> On the other hand, don't they (website) have the same issue on Gecko?

Sure. I'm not arguing that websites that do this are correct.

But what's the upside of this change in behavior? The only effects it has are

1. Make DOMSubtreeModified more accurate.

2. Make pages (or extensions) that make use of DOMSubtreeModified slower.

I claim we don't care much about (1). And (2) definitely seems bad. Do you think (1) is a worthy goal?
Comment 11 Ryosuke Niwa 2012-03-15 11:14:43 PDT
(In reply to comment #10)
> Sure. I'm not arguing that websites that do this are correct.
> 
> But what's the upside of this change in behavior? The only effects it has are
> 
> 1. Make DOMSubtreeModified more accurate.
> 
> 2. Make pages (or extensions) that make use of DOMSubtreeModified slower.
> 
> I claim we don't care much about (1). And (2) definitely seems bad. Do you think (1) is a worthy goal?

I think (1) is worthy goal for now. We might decide to kill mutation events in near future, but until that day comes, we should try to be spec-compliant as much as possible. I'd argue that the only case we might willingly diverge is when we have significant security implications (e.g. editing, adoptNode, etc...)
Comment 12 Adam Klein 2012-03-15 11:19:37 PDT
(In reply to comment #11)
> (In reply to comment #10)
> > Sure. I'm not arguing that websites that do this are correct.
> > 
> > But what's the upside of this change in behavior? The only effects it has are
> > 
> > 1. Make DOMSubtreeModified more accurate.
> > 
> > 2. Make pages (or extensions) that make use of DOMSubtreeModified slower.
> > 
> > I claim we don't care much about (1). And (2) definitely seems bad. Do you think (1) is a worthy goal?
> 
> I think (1) is worthy goal for now. We might decide to kill mutation events in near future, but until that day comes, we should try to be spec-compliant as much as possible. I'd argue that the only case we might willingly diverge is when we have significant security implications (e.g. editing, adoptNode, etc...)

Note that spec compliance for DOMSubtreeModified is open to interpretation (we could fire it arbitrarily later than the mutations it's notifying about). I'm not sure that "spec compliance" is a good argument for this case (see http://www.w3.org/TR/DOM-Level-3-Events/#event-type-DOMSubtreeModified for the wording).

Anyone from Apple care to comment, given that this started from a radr issue?
Comment 13 Jon Lee 2012-03-15 11:57:35 PDT
(In reply to comment #12)
> Anyone from Apple care to comment, given that this started from a radr issue?
I agree with Adam. I'm not an expert on mutation events, but from what I can tell, this event is deprecated, which means everyone is discouraged from using it. I don't think trying to improve a deprecated behavior makes anything better. At best it won't affect anyone because no one's using the feature, in which case, why make the change, and at worst we break a major site, like this one. So it seems lose/lose to me.
Comment 14 Ryosuke Niwa 2012-03-15 13:48:31 PDT
Okay, Anne also agrees with you all so I have no problem with landing this patch.
Comment 15 WebKit Review Bot 2012-03-15 18:24:24 PDT
Comment on attachment 131952 [details]
Patch

Clearing flags on attachment: 131952

Committed r110925: <http://trac.webkit.org/changeset/110925>
Comment 16 WebKit Review Bot 2012-03-15 18:24:29 PDT
All reviewed patches have been landed.  Closing bug.