Bug 181137 – Release assert in addResourceTiming when a cache resource is requested during style recalc

• Component: WebCore Misc.
• Status: RESOLVED FIXED

[Ryosuke Niwa]

When a previously loaded resource is requested during a style resolution, we end up trying to synchronously dispatch resourcetimingbufferfull event.
e.g.
 WebCore: WebCore::EventTarget::dispatchEvent(WebCore::Event&)
 WebCore: WebCore::Performance::addResourceTiming(WebCore::ResourceTiming&&)
   WebCore: WebCore::ResourceTimingInformation::addResourceTiming(WebCore::CachedResource&, WebCore::Document&, WebCore::ResourceTiming&&)
     WebCore: WebCore::CachedResourceLoader::requestResource(WebCore::CachedResource::Type, WebCore::CachedResourceRequest&&, WebCore::CachedResourceLoader::ForPreload, WebCore::CachedResourceLoader::DeferOption)
       WebCore: WebCore::CachedResourceLoader::requestImage(WebCore::CachedResourceRequest&&)
         WebCore: WebCore::CSSImageValue::loadImage(WebCore::CachedResourceLoader&, WebCore::ResourceLoaderOptions const&)
          WebCore: WebCore::StyleCachedImage::load(WebCore::CachedResourceLoader&, WebCore::ResourceLoaderOptions const&)
            WebCore: WebCore::Style::loadPendingImage(WebCore::Document&, WebCore::StyleImage const*, WebCore::Element const*, WebCore::Style::LoadPolicy)
              WebCore: WebCore::Style::loadPendingResources(WebCore::RenderStyle&, WebCore::Document&, WebCore::Element const*)
                WebCore: WebCore::RenderElement::initializeStyle()
                 WebCore: WebCore::RenderTreeUpdater::createRenderer(WebCore::Element&, WebCore::RenderStyle&&)
                   WebCore: WebCore::RenderTreeUpdater::updateElementRenderer(WebCore::Element&, WebCore::Style::ElementUpdate const&)
                     WebCore: WebCore::RenderTreeUpdater::updateRenderTree(WebCore::ContainerNode&)
                       WebCore: WebCore::RenderTreeUpdater::commit(std::__::unique_ptr<WebCore::Style::Update const, std::__::default_delete<WebCore::Style::Update const> >)
                         WebCore: WebCore::Document::resolveStyle(WebCore::Document::ResolveStyleType)
                           WebCore: WebCore::Document::updateStyleIfNeeded()
                            pruning:  WebCore: WebCore::Document::updateLayout()

[Ryosuke Niwa]

<rdar://problem/35666574>

[Ryosuke Niwa]

Created attachment 330146 [details]
Fixes the bug

[EWS Watchlist]

Comment on attachment 330146 [details]
Fixes the bug

Attachment 330146 [details] did not pass mac-ews (mac):
Output: http://webkit-queues.webkit.org/results/5806447

New failing tests:
http/wpt/resource-timing/rt-performance-extensions.worker.html
http/wpt/resource-timing/rt-performance-extensions.html

[EWS Watchlist]

Created attachment 330150 [details]
Archive of layout-test-results from ews102 for mac-elcapitan

The attached test failures were seen while running run-webkit-tests on the mac-ews.
Bot: ews102  Port: mac-elcapitan  Platform: Mac OS X 10.11.6

[EWS Watchlist]

Comment on attachment 330146 [details]
Fixes the bug

Attachment 330146 [details] did not pass mac-wk2-ews (mac-wk2):
Output: http://webkit-queues.webkit.org/results/5806557

New failing tests:
http/wpt/resource-timing/rt-performance-extensions.worker.html
http/wpt/resource-timing/rt-performance-extensions.html

[EWS Watchlist]

Created attachment 330151 [details]
Archive of layout-test-results from ews105 for mac-elcapitan-wk2

The attached test failures were seen while running run-webkit-tests on the mac-wk2-ews.
Bot: ews105  Port: mac-elcapitan-wk2  Platform: Mac OS X 10.11.6

[EWS Watchlist]

Comment on attachment 330146 [details]
Fixes the bug

Attachment 330146 [details] did not pass mac-debug-ews (mac):
Output: http://webkit-queues.webkit.org/results/5806564

New failing tests:
http/wpt/resource-timing/rt-performance-extensions.worker.html
http/wpt/resource-timing/rt-performance-extensions.html

[EWS Watchlist]

Created attachment 330152 [details]
Archive of layout-test-results from ews115 for mac-elcapitan

The attached test failures were seen while running run-webkit-tests on the mac-debug-ews.
Bot: ews115  Port: mac-elcapitan  Platform: Mac OS X 10.11.6

[Ryosuke Niwa]

Created attachment 330154 [details]
Fixes one more bug

[Simon Fraser (smfr)]

Comment on attachment 330154 [details]
Fixes one more bug

View in context: https://bugs.webkit.org/attachment.cgi?id=330154&action=review

> Source/WebCore/page/Performance.cpp:181
> +    Ref<PerformanceResourceTiming> entry = PerformanceResourceTiming::create(m_timeOrigin, WTFMove(resourceTiming));

auto?

> Source/WebCore/page/Performance.cpp:189
> +        queueEntry(entry.get());

This might read better as enqueueEntry()

> Source/WebCore/page/Performance.cpp:193
> +    if (isResourceTimingBufferFull()) {

Odd that you check m_resourceTimingBufferFull above, but isResourceTimingBufferFull() here.

> Source/WebCore/page/Performance.cpp:215
> +        m_resourceTimingBufferFull = true;

I would like this line explained by a comment.

> Source/WebCore/page/Performance.cpp:221
> +        unsigned remainingBufferSize = m_resourceTimingBufferSize - m_resourceTimingBuffer.size();

I hope that never underflows. Maybe ASSERT(m_resourceTimingBufferSize >= m_resourceTimingBuffer.size())?

> Source/WebCore/page/Performance.cpp:230
> +        for (; i < remainingBufferSize && i < backupBuffer.size(); i++)
> +            m_resourceTimingBuffer.append(backupBuffer[i].copyRef());
> +        for (; i < backupBuffer.size(); i++)
> +            m_backupResourceTimingBuffer.append(backupBuffer[i].copyRef());

Is there a way to do this by moving ranges of vector items?

[Ryosuke Niwa]

(In reply to Simon Fraser (smfr) from comment #10)
> Comment on attachment 330154 [details]
> Fixes one more bug
> 
> View in context:
> https://bugs.webkit.org/attachment.cgi?id=330154&action=review
> 
> > Source/WebCore/page/Performance.cpp:181
> > +    Ref<PerformanceResourceTiming> entry = PerformanceResourceTiming::create(m_timeOrigin, WTFMove(resourceTiming));
> 
> auto?

Fixed.

> > Source/WebCore/page/Performance.cpp:189
> > +        queueEntry(entry.get());
> 
> This might read better as enqueueEntry()

Yeah, I think it does but that's not a function I'm adding or modifying so I'd keep it as is for now.

> > Source/WebCore/page/Performance.cpp:193
> > +    if (isResourceTimingBufferFull()) {
> 
> Odd that you check m_resourceTimingBufferFull above, but
> isResourceTimingBufferFull() here.

Actually, the code under if (m_resourceTimingBufferFull) is a dead code since m_shouldUseBackupBuffer is always true whenever m_resourceTimingBufferFull is true. Deleted that branch. That means we also don't need m_resourceTimingBufferFull instance variable so removed that.

> 
> > Source/WebCore/page/Performance.cpp:215
> > +        m_resourceTimingBufferFull = true;
> 
> I would like this line explained by a comment.

This flag has been removed.

> > Source/WebCore/page/Performance.cpp:221
> > +        unsigned remainingBufferSize = m_resourceTimingBufferSize - m_resourceTimingBuffer.size();
> 
> I hope that never underflows. Maybe ASSERT(m_resourceTimingBufferSize >=
> m_resourceTimingBuffer.size())?

Sure, I'd even release-assert that since this is not a performance critical code path.

> > Source/WebCore/page/Performance.cpp:230
> > +        for (; i < remainingBufferSize && i < backupBuffer.size(); i++)
> > +            m_resourceTimingBuffer.append(backupBuffer[i].copyRef());
> > +        for (; i < backupBuffer.size(); i++)
> > +            m_backupResourceTimingBuffer.append(backupBuffer[i].copyRef());
> 
> Is there a way to do this by moving ranges of vector items?

I guess we could do:
unsigned i = 0;
for (auto& item : backupBuffer) {
    if (i < remainingBufferSize)
        m_resourceTimingBuffer.append(item.copyRef());
    else
        m_backupResourceTimingBuffer.append(item.copyRef());
    i++;
}
But I'm not certain if it's cleaner.

[Ryosuke Niwa]

Created attachment 330774 [details]
Patch for landing

[Ryosuke Niwa]

Created attachment 330775 [details]
Patch for landing

[Ryosuke Niwa]

Comment on attachment 330775 [details]
Patch for landing

Wait for EWS.

[Joseph Pecoraro]

Looks good to me too@

[EWS Watchlist]

Comment on attachment 330775 [details]
Patch for landing

Attachment 330775 [details] did not pass mac-ews (mac):
Output: http://webkit-queues.webkit.org/results/5986367

New failing tests:
http/wpt/resource-timing/rt-performance-extensions.worker.html
http/wpt/resource-timing/rt-performance-extensions.html

[EWS Watchlist]

Created attachment 330784 [details]
Archive of layout-test-results from ews103 for mac-elcapitan

The attached test failures were seen while running run-webkit-tests on the mac-ews.
Bot: ews103  Port: mac-elcapitan  Platform: Mac OS X 10.11.6

[Ryosuke Niwa]

Oops, no, that wasn't a dead code. It was preventing resourcetimingbufferfull from gettin dispatched multiple times. Restoring the flag.

[EWS Watchlist]

Comment on attachment 330775 [details]
Patch for landing

Attachment 330775 [details] did not pass mac-wk2-ews (mac-wk2):
Output: http://webkit-queues.webkit.org/results/5986783

New failing tests:
http/wpt/resource-timing/rt-performance-extensions.worker.html

[EWS Watchlist]

Created attachment 330786 [details]
Archive of layout-test-results from ews104 for mac-elcapitan-wk2

The attached test failures were seen while running run-webkit-tests on the mac-wk2-ews.
Bot: ews104  Port: mac-elcapitan-wk2  Platform: Mac OS X 10.11.6

[Ryosuke Niwa]

Comment on attachment 330154 [details]
Fixes one more bug

View in context: https://bugs.webkit.org/attachment.cgi?id=330154&action=review

>>> Source/WebCore/page/Performance.cpp:193
>>> +    if (isResourceTimingBufferFull()) {
>> 
>> Odd that you check m_resourceTimingBufferFull above, but isResourceTimingBufferFull() here.
> 
> Actually, the code under if (m_resourceTimingBufferFull) is a dead code since m_shouldUseBackupBuffer is always true whenever m_resourceTimingBufferFull is true. Deleted that branch. That means we also don't need m_resourceTimingBufferFull instance variable so removed that.

Actually, that code was necessary. It was used when resourcetimingbufferfull had fired but the buffer had not been cleared.
Restoring the code with some comments:

    if (m_shouldUseBackupBuffer) {
        // We're waiting for resourceTimingBufferFullTimer to be fired.
        m_backupResourceTimingBuffer.append(WTFMove(entry));
        return;
    }

    if (m_resourceTimingBufferFullFlag) {
        // We fired resourcetimingbufferfull evnet but the author script didn't clear the buffer.
        // Notify performance observers but don't add it to the buffer.
        queueEntry(entry.get());
        return;
    }

[Ryosuke Niwa]

(In reply to Ryosuke Niwa from comment #21)
> Comment on attachment 330154 [details]
> Fixes one more bug
> 
> View in context:
> https://bugs.webkit.org/attachment.cgi?id=330154&action=review
> 
> >>> Source/WebCore/page/Performance.cpp:193
> >>> +    if (isResourceTimingBufferFull()) {
> >> 
> >> Odd that you check m_resourceTimingBufferFull above, but isResourceTimingBufferFull() here.
> > 
> > Actually, the code under if (m_resourceTimingBufferFull) is a dead code since m_shouldUseBackupBuffer is always true whenever m_resourceTimingBufferFull is true. Deleted that branch. That means we also don't need m_resourceTimingBufferFull instance variable so removed that.
> 
> Actually, that code was necessary. It was used when resourcetimingbufferfull
> had fired but the buffer had not been cleared.
> Restoring the code with some comments:
> 
>     if (m_shouldUseBackupBuffer) {
>         // We're waiting for resourceTimingBufferFullTimer to be fired.
>         m_backupResourceTimingBuffer.append(WTFMove(entry));
>         return;
>     }

Renamed this instance variable to m_waitingForBackupBufferToBeProcessed instead so that code reads better:
    if (m_waitingForBackupBufferToBeProcessed) {
        m_backupResourceTimingBuffer.append(WTFMove(entry));
        return;
    }

[Ryosuke Niwa]

Created attachment 330787 [details]
Patch for landing

[EWS Watchlist]

Comment on attachment 330787 [details]
Patch for landing

Attachment 330787 [details] did not pass mac-ews (mac):
Output: http://webkit-queues.webkit.org/results/5988382

New failing tests:
http/tests/performance/performance-resource-timing-resourcetimingbufferfull-crash.html

[EWS Watchlist]

Created attachment 330791 [details]
Archive of layout-test-results from ews100 for mac-elcapitan

The attached test failures were seen while running run-webkit-tests on the mac-ews.
Bot: ews100  Port: mac-elcapitan  Platform: Mac OS X 10.11.6

[Ryosuke Niwa]

Created attachment 330793 [details]
Patch for landing

[WebKit Commit Bot]

Comment on attachment 330793 [details]
Patch for landing

Clearing flags on attachment: 330793

Committed r226617: <https://trac.webkit.org/changeset/226617>

[WebKit Commit Bot]

All reviewed patches have been landed.  Closing bug.

[Chris Dumez]

Comment on attachment 330793 [details]
Patch for landing

View in context: https://bugs.webkit.org/attachment.cgi?id=330793&action=review

> Source/WebCore/page/Performance.h:115
> +    Timer m_resourceTimingBufferFullTimer;

Performance is exposed to workers so I do not think this timer is OK. See rdar://problem/36904312. I believe we now run code on the main thread when this timer fires instead of the worker thread.

[Chris Dumez]

Comment on attachment 330793 [details]
Patch for landing

View in context: https://bugs.webkit.org/attachment.cgi?id=330793&action=review

>> Source/WebCore/page/Performance.h:115
>> +    Timer m_resourceTimingBufferFullTimer;
> 
> Performance is exposed to workers so I do not think this timer is OK. See rdar://problem/36904312. I believe we now run code on the main thread when this timer fires instead of the worker thread.

Nope, looks like I was wrong. The timer does fire on the background thread in case of workers. So it we have a lot of crashes when this timer fires on the main thread (rdar://problem/36904312), however it is not related to workers. Something else is going on.