New issue
Advanced search Search tips

Issue 692856 link

Starred by 2 users

Issue metadata

Status: Fixed
Owner:
Closed: Aug 2017
Components:
EstimatedDays: ----
NextAction: ----
OS: All
Pri: 1
Type: Bug

Blocked on:
issue 694702
issue 746115

Blocking:
issue 749773



Sign in to add a comment

ScriptResource::isLoaded() is false when PendingScript::getSource() is called due to revalidation

Project Member Reported by erikc...@chromium.org, Feb 16 2017

Issue description

I tried opening a bunch of pages from cnn.com [world, news, travel ,etc] in separate tabs.
TOT: 618b40d65c8372e95c3fb7bf848560b2a9b14a34
  5 dcheck_always_on = true                                                         
  6 is_component_build = false                                                      
  7 is_debug = false                                                                
  8 symbol_level = 1                                                                
  9 use_goma = true                                                                 
 10 enable_profiling = true  

[33312:775:0215/170413.103187:FATAL:PendingScript.cpp(189)] Check failed: resource()->isLoaded(). 
0   Chromium Framework                  0x0000000104ae028c base::debug::StackTrace::StackTrace(unsigned long) + 28
1   Chromium Framework                  0x0000000104b05923 logging::LogMessage::~LogMessage() + 67
2   Chromium Framework                  0x0000000108d0a16e blink::PendingScript::getSource(blink::KURL const&, bool&) const + 142
3   Chromium Framework                  0x0000000108d2b97b blink::ScriptLoader::execute() + 283
4   Chromium Framework                  0x0000000108d2c91f blink::ScriptRunner::executeTask() + 63
5   Chromium Framework                  0x0000000104ae0c35 base::debug::TaskAnnotator::RunTask(char const*, base::PendingTask*) + 309
6   Chromium Framework                  0x0000000108426eb2 blink::scheduler::TaskQueueManager::ProcessTaskFromWorkQueue(blink::scheduler::internal::WorkQueue*, bool, blink::scheduler::LazyNow, base::TimeTicks*) + 1522
7   Chromium Framework                  0x000000010842494b blink::scheduler::TaskQueueManager::DoWork(bool) + 1035
8   Chromium Framework                  0x00000001084290cc void base::internal::FunctorTraits<void (blink::scheduler::TaskQueueManager::*)(bool), void>::Invoke<base::WeakPtr<blink::scheduler::TaskQueueManager> const&, bool const&>(void (blink::scheduler::TaskQueueManager::*)(bool), base::WeakPtr<blink::scheduler::TaskQueueManager> const&&&, bool const&&&) + 156
9   Chromium Framework                  0x0000000104ae0c35 base::debug::TaskAnnotator::RunTask(char const*, base::PendingTask*) + 309
10  Chromium Framework                  0x0000000104b1e349 base::MessageLoop::RunTask(base::PendingTask*) + 441
11  Chromium Framework                  0x0000000104b1e70c base::MessageLoop::DeferOrRunPendingTask(base::PendingTask) + 44
12  Chromium Framework                  0x0000000104b1ec13 base::MessageLoop::DoWork() + 483
13  Chromium Framework                  0x0000000104b23840 base::MessagePumpCFRunLoopBase::RunWork() + 48
14  Chromium Framework                  0x0000000104b06d9a base::mac::CallWithEHFrame(void () block_pointer) + 10
15  Chromium Framework                  0x0000000104b23214 base::MessagePumpCFRunLoopBase::RunWorkSource(void*) + 68
16  CoreFoundation                      0x00007fff847857e1 __CFRUNLOOP_IS_CALLING_OUT_TO_A_SOURCE0_PERFORM_FUNCTION__ + 17
17  CoreFoundation                      0x00007fff84764f1c __CFRunLoopDoSources0 + 556
18  CoreFoundation                      0x00007fff8476443f __CFRunLoopRun + 927
19  CoreFoundation                      0x00007fff84763e38 CFRunLoopRunSpecific + 296
20  Foundation                          0x00007fff87472ed9 -[NSRunLoop(NSRunLoop) runMode:beforeDate:] + 270
21  Chromium Framework                  0x0000000104b2417e base::MessagePumpNSRunLoop::DoRun(base::MessagePump::Delegate*) + 126
22  Chromium Framework                  0x0000000104b23697 base::MessagePumpCFRunLoopBase::Run(base::MessagePump::Delegate*) + 119
23  Chromium Framework                  0x0000000104b1e072 base::MessageLoop::RunHandler() + 354
24  Chromium Framework                  0x0000000104b55097 base::RunLoop::Run() + 151
25  Chromium Framework                  0x000000010a079256 content::RendererMain(content::MainFunctionParams const&) + 742
26  Chromium Framework                  0x00000001044b7000 content::ContentMainRunnerImpl::Run() + 528
27  Chromium Framework                  0x00000001044b6076 content::ContentMain(content::ContentMainParams const&) + 54
28  Chromium Framework                  0x00000001025cd8bb ChromeMain + 75
29  Chromium Helper                     0x0000000102395daa main + 522
30  libdyld.dylib                       0x00007fff888ac5ad start + 1
31  ???                                 0x0000000000000012 0x0 + 18
 
Components: -Blink Blink>Loader
Hi erikchen@,

How often does this crash occur? Is this reproducible? Is this a regression?

I looked into the code, and I found there might be a slight chance for the DCHECK failure when revalidation of the ScriptResource occurs. This can occur when we access the same script URL from e.g. multiple frames/tabs in the same renderer. The failure is likely to be rare and flaky/not reproducible reliably, not a recent regression.

I tried running a release build of chrome with dchecks enabled [for other reasons] and ran into a bunch of dchecks. I forget if this one happened more than once. I can repost if the error happens again.
Owner: hirosh...@chromium.org
Status: Started (was: Untriaged)
Thanks!

I'll add some CHECK()s on canary to see whether my hypothesis is correct.

I was thinking about creating a test, but it turned hard: Probably a reproducible layout test is impossible. We might create a unit test, but we lack unit tests for ScriptLoader...
Blockedon: 694702
Project Member

Comment 6 by bugdroid1@chromium.org, Feb 25 2017

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/6dc58b5746363ddbb99addb4c06c69a385212b7d

commit 6dc58b5746363ddbb99addb4c06c69a385212b7d
Author: hiroshige <hiroshige@chromium.org>
Date: Sat Feb 25 03:26:35 2017

Check whether ScriptResource is still loading due to revalidation

ScriptResource is assumed to be already loaded when it is used by
ScriptResource::script() and PendingScript.
However, there might slight chances that isLoaded() is false due to
revalidation, possibly causing  Issue 692856 .

In order to check whether and how often revalidation can cause
isLoaded() to be false in existing DCHECK()s, this CL replaces
DCHECK(isLoaded()) with three CHECK()s, each of which fails when:
1. isLoaded() is false not because of revalidation,
2. isLoaded() is false because revalidation is ongoing and response is
   already received, and
3. isLoaded() is false because revalidation is ongoing and response is
   not yet received.

BUG= 692856 

Review-Url: https://codereview.chromium.org/2706303002
Cr-Commit-Position: refs/heads/master@{#453057}

[modify] https://crrev.com/6dc58b5746363ddbb99addb4c06c69a385212b7d/third_party/WebKit/Source/core/dom/PendingScript.cpp
[modify] https://crrev.com/6dc58b5746363ddbb99addb4c06c69a385212b7d/third_party/WebKit/Source/core/loader/resource/ScriptResource.cpp
[modify] https://crrev.com/6dc58b5746363ddbb99addb4c06c69a385212b7d/third_party/WebKit/Source/platform/loader/fetch/Resource.cpp
[modify] https://crrev.com/6dc58b5746363ddbb99addb4c06c69a385212b7d/third_party/WebKit/Source/platform/loader/fetch/Resource.h

Project Member

Comment 7 by bugdroid1@chromium.org, Feb 27 2017

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/4c7dd9f84d0f9b306bea368e4015fae01fcd6541

commit 4c7dd9f84d0f9b306bea368e4015fae01fcd6541
Author: hiroshige <hiroshige@chromium.org>
Date: Mon Feb 27 04:52:29 2017

Revert of Check whether ScriptResource is still loading due to revalidation (patchset #2 id:20001 of https://codereview.chromium.org/2706303002/ )

Reason for revert:
Sufficient data are collected and thus finishing the
investigation.

BUG=696305

Original issue's description:
> Check whether ScriptResource is still loading due to revalidation
>
> ScriptResource is assumed to be already loaded when it is used by
> ScriptResource::script() and PendingScript.
> However, there might slight chances that isLoaded() is false due to
> revalidation, possibly causing  Issue 692856 .
>
> In order to check whether and how often revalidation can cause
> isLoaded() to be false in existing DCHECK()s, this CL replaces
> DCHECK(isLoaded()) with three CHECK()s, each of which fails when:
> 1. isLoaded() is false not because of revalidation,
> 2. isLoaded() is false because revalidation is ongoing and response is
>    already received, and
> 3. isLoaded() is false because revalidation is ongoing and response is
>    not yet received.
>
> BUG= 692856 
>
> Review-Url: https://codereview.chromium.org/2706303002
> Cr-Commit-Position: refs/heads/master@{#453057}
> Committed: https://chromium.googlesource.com/chromium/src/+/6dc58b5746363ddbb99addb4c06c69a385212b7d

TBR=japhet@chromium.org,kouhei@chromium.org
# Not skipping CQ checks because original CL landed more than 1 days ago.
BUG= 692856 

Review-Url: https://codereview.chromium.org/2714403002
Cr-Commit-Position: refs/heads/master@{#453150}

[modify] https://crrev.com/4c7dd9f84d0f9b306bea368e4015fae01fcd6541/third_party/WebKit/Source/core/dom/PendingScript.cpp
[modify] https://crrev.com/4c7dd9f84d0f9b306bea368e4015fae01fcd6541/third_party/WebKit/Source/core/loader/resource/ScriptResource.cpp
[modify] https://crrev.com/4c7dd9f84d0f9b306bea368e4015fae01fcd6541/third_party/WebKit/Source/platform/loader/fetch/Resource.cpp
[modify] https://crrev.com/4c7dd9f84d0f9b306bea368e4015fae01fcd6541/third_party/WebKit/Source/platform/loader/fetch/Resource.h

Project Member

Comment 8 by bugdroid1@chromium.org, Feb 27 2017

Labels: merge-merged-3025
The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/7f6cd2d8dede99b5d71072e115195de55ae2cacb

commit 7f6cd2d8dede99b5d71072e115195de55ae2cacb
Author: Hiroshige Hayashizaki <hiroshige@chromium.org>
Date: Mon Feb 27 19:10:26 2017

Revert of Check whether ScriptResource is still loading due to revalidation (patchset #2 id:20001 of https://codereview.chromium.org/2706303002/ )

Reason for revert:
Sufficient data are collected and thus finishing the
investigation.

BUG=696305

Original issue's description:
> Check whether ScriptResource is still loading due to revalidation
>
> ScriptResource is assumed to be already loaded when it is used by
> ScriptResource::script() and PendingScript.
> However, there might slight chances that isLoaded() is false due to
> revalidation, possibly causing  Issue 692856 .
>
> In order to check whether and how often revalidation can cause
> isLoaded() to be false in existing DCHECK()s, this CL replaces
> DCHECK(isLoaded()) with three CHECK()s, each of which fails when:
> 1. isLoaded() is false not because of revalidation,
> 2. isLoaded() is false because revalidation is ongoing and response is
>    already received, and
> 3. isLoaded() is false because revalidation is ongoing and response is
>    not yet received.
>
> BUG= 692856 
>
> Review-Url: https://codereview.chromium.org/2706303002
> Cr-Commit-Position: refs/heads/master@{#453057}
> Committed: https://chromium.googlesource.com/chromium/src/+/6dc58b5746363ddbb99addb4c06c69a385212b7d

TBR=japhet@chromium.org,kouhei@chromium.org
BUG= 692856 

Review-Url: https://codereview.chromium.org/2714403002
Cr-Commit-Position: refs/heads/master@{#453150}
(cherry picked from commit 4c7dd9f84d0f9b306bea368e4015fae01fcd6541)

Review-Url: https://codereview.chromium.org/2723583002 .
Cr-Commit-Position: refs/branch-heads/3025@{#4}
Cr-Branched-From: 636f441be350ec76e73b4e4f407bf8a7e86984fd-refs/heads/master@{#453134}

[modify] https://crrev.com/7f6cd2d8dede99b5d71072e115195de55ae2cacb/third_party/WebKit/Source/core/dom/PendingScript.cpp
[modify] https://crrev.com/7f6cd2d8dede99b5d71072e115195de55ae2cacb/third_party/WebKit/Source/core/loader/resource/ScriptResource.cpp
[modify] https://crrev.com/7f6cd2d8dede99b5d71072e115195de55ae2cacb/third_party/WebKit/Source/platform/loader/fetch/Resource.cpp
[modify] https://crrev.com/7f6cd2d8dede99b5d71072e115195de55ae2cacb/third_party/WebKit/Source/platform/loader/fetch/Resource.h

Project Member

Comment 9 by bugdroid1@chromium.org, Feb 27 2017

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/7f6cd2d8dede99b5d71072e115195de55ae2cacb

commit 7f6cd2d8dede99b5d71072e115195de55ae2cacb
Author: Hiroshige Hayashizaki <hiroshige@chromium.org>
Date: Mon Feb 27 19:10:26 2017

Revert of Check whether ScriptResource is still loading due to revalidation (patchset #2 id:20001 of https://codereview.chromium.org/2706303002/ )

Reason for revert:
Sufficient data are collected and thus finishing the
investigation.

BUG=696305

Original issue's description:
> Check whether ScriptResource is still loading due to revalidation
>
> ScriptResource is assumed to be already loaded when it is used by
> ScriptResource::script() and PendingScript.
> However, there might slight chances that isLoaded() is false due to
> revalidation, possibly causing  Issue 692856 .
>
> In order to check whether and how often revalidation can cause
> isLoaded() to be false in existing DCHECK()s, this CL replaces
> DCHECK(isLoaded()) with three CHECK()s, each of which fails when:
> 1. isLoaded() is false not because of revalidation,
> 2. isLoaded() is false because revalidation is ongoing and response is
>    already received, and
> 3. isLoaded() is false because revalidation is ongoing and response is
>    not yet received.
>
> BUG= 692856 
>
> Review-Url: https://codereview.chromium.org/2706303002
> Cr-Commit-Position: refs/heads/master@{#453057}
> Committed: https://chromium.googlesource.com/chromium/src/+/6dc58b5746363ddbb99addb4c06c69a385212b7d

TBR=japhet@chromium.org,kouhei@chromium.org
BUG= 692856 

Review-Url: https://codereview.chromium.org/2714403002
Cr-Commit-Position: refs/heads/master@{#453150}
(cherry picked from commit 4c7dd9f84d0f9b306bea368e4015fae01fcd6541)

Review-Url: https://codereview.chromium.org/2723583002 .
Cr-Commit-Position: refs/branch-heads/3025@{#4}
Cr-Branched-From: 636f441be350ec76e73b4e4f407bf8a7e86984fd-refs/heads/master@{#453134}

[modify] https://crrev.com/7f6cd2d8dede99b5d71072e115195de55ae2cacb/third_party/WebKit/Source/core/dom/PendingScript.cpp
[modify] https://crrev.com/7f6cd2d8dede99b5d71072e115195de55ae2cacb/third_party/WebKit/Source/core/loader/resource/ScriptResource.cpp
[modify] https://crrev.com/7f6cd2d8dede99b5d71072e115195de55ae2cacb/third_party/WebKit/Source/platform/loader/fetch/Resource.cpp
[modify] https://crrev.com/7f6cd2d8dede99b5d71072e115195de55ae2cacb/third_party/WebKit/Source/platform/loader/fetch/Resource.h

Summary: ScriptResource::isLoaded() is false when PendingScript::getSource() is called due to revalidation (was: Check failed: resource()->isLoaded(). )
The assertions introduced by Comment #8 crashes ~2000 times on canary.

Line 231:
> 1. isLoaded() is false not because of revalidation,
None observed.

Line 233:
> 2. isLoaded() is false because revalidation is ongoing and response is
>    already received, and
2 observed.
Query:
custom_data.ChromeCrashProto.magic_signature_1.name='blink::PendingScript::getSource' AND REGEXP(product.Version, '^58.') OMIT RECORD IF SUM(CrashedStackTrace.StackFrame.SourceLine=235) != 0
(The filter by line number is not accurate though)

Line 235:
> 3. isLoaded() is false because revalidation is ongoing and response is
>    not yet received.
More than 1000 observed.

The test CL is already reverted (58.0.3026.0).

So isLoaded() is false due to revalidation (and in most of the cases the response for revalidating request is not yet received).
Changing the issue title.

For crash reports see also 696305.
 Issue 716439  has been merged into this issue.
Blockedon: 746115
Blocking: 749773
Labels: -Pri-3 M-62 OS-All Pri-1
Blockedon: 752711
Project Member

Comment 16 by bugdroid1@chromium.org, Aug 18 2017

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/faad2ba6d3dfbb4e44cdfba0b4bfaeaa47fba244

commit faad2ba6d3dfbb4e44cdfba0b4bfaeaa47fba244
Author: Hiroshige Hayashizaki <hiroshige@chromium.org>
Date: Fri Aug 18 23:03:43 2017

Do not revalidate ScriptResource while it has clients

This is to suppress revalidation until ClassicPendingScript::GetSource()
to avoid DCHECK() failure there.
In the case of ClassicPendingScript, RemoveClient() is called
in ResourceOwner::SetResource(nullptr)
in ClassicPendingScript::DisposeInternal()
in PendingScript::Dispose()
in ScriptLoader::ExecuteScriptBlock() just after ClassicPendingScript::GetSource().

In other ScriptResourceClient subclasses (WorkletScriptLoader and ModuleScriptFetcher),
RemoveClient() is called in NotifyFinished(), and therefore this CL doesn't affect
the revalidation behavior so much.

Bug:  692856 ,  749773 
Change-Id: I28cda31b8c103059fa2e05ef0ad38c9a95e11776
Reviewed-on: https://chromium-review.googlesource.com/620272
Commit-Queue: Hiroshige Hayashizaki <hiroshige@chromium.org>
Reviewed-by: Yutaka Hirano <yhirano@chromium.org>
Reviewed-by: Nate Chapin <japhet@chromium.org>
Cr-Commit-Position: refs/heads/master@{#495728}
[modify] https://crrev.com/faad2ba6d3dfbb4e44cdfba0b4bfaeaa47fba244/third_party/WebKit/Source/core/loader/resource/ScriptResource.cpp
[modify] https://crrev.com/faad2ba6d3dfbb4e44cdfba0b4bfaeaa47fba244/third_party/WebKit/Source/core/loader/resource/ScriptResource.h

Blockedon: -752711
Labels: Merge-Request-61
Status: Fixed (was: Started)
The short-term fix (Comment #16) was landed on 62.0.3190.0 and has stayed on canary for 2~3 days.

According to Blink.MemoryCache.RevalidationPolicy.Script/Blink.MemoryCache.RevalidationPolicy.Preload.Script UMAs, MemoryCache hit rates don't seem to be affected (Revalidation rate was 00.37%/01.82% on 62.0.3189.0 and 00.36%/01.88% on 62.0.3190.0, on Aug 19 1-day UMA) and thus I don't expect performance regression.

Closing as fixed.
Labels: -Merge-Request-61
Removing Merge-Request-61.

Sign in to add a comment