New issue
Advanced search Search tips

Issue 620334 link

Starred by 2 users

Issue metadata

Status: Fixed
Owner:
Closed: Sep 2016
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: All
Pri: 1
Type: Bug-Regression

Blocking:
issue 596622



Sign in to add a comment

DCHECK firing in webgl_conformance_tests: FATAL:ResourceLoader.cpp(228): Check failed: request.priority() == ResourceLoadPriorityHighest

Project Member Reported by kjellander@chromium.org, Jun 15 2016

Issue description

Starting with pauljensen@'s https://codereview.chromium.org/2067633003 there were several failure on a row on Mac:
https://build.chromium.org/p/chromium.gpu/builders/Mac%2010.10%20Retina%20Debug%20%28AMD%29/builds/9375 
https://build.chromium.org/p/chromium.gpu/builders/Mac%2010.10%20Retina%20Release%20%28AMD%29/builds/9882 
https://build.chromium.org/p/chromium.gpu/builders/Mac%2010.10%20Debug%20%28Intel%29/builds/10205 

The WebglConformance.conformance_misc_bad_arguments_test test is the one crashing over and over, like this:

[ RUN      ] WebglConformance.conformance_misc_bad_arguments_test
(INFO) 2016-06-15 07:45:39,043 cache_temperature.EnsurePageCacheTemperature:55  PageCacheTemperature: any
[8800:1299:0615/074539:FATAL:ResourceLoader.cpp(228)] Check failed: request.priority() == ResourceLoadPriorityHighest. 
0   Chromium Framework                  0x0000000106d72473 _ZN4base5debug10StackTraceC1Ev + 19
1   Chromium Framework                  0x0000000106d90f57 _ZN7logging10LogMessageD2Ev + 71
2   Chromium Framework                  0x0000000109c25e26 _ZN5blink14ResourceLoader20requestSynchronouslyERKNS_15ResourceRequestE + 134
3   Chromium Framework                  0x0000000109c1aa88 _ZN5blink15ResourceFetcher9startLoadEPNS_8ResourceE + 440
4   Chromium Framework                  0x0000000109c19b9e _ZN5blink15ResourceFetcher15requestResourceERNS_12FetchRequestERKNS_15ResourceFactoryERKNS_14SubstituteDataE + 2462
5   Chromium Framework                  0x0000000109c0976b _ZN5blink11RawResource5fetchERNS_12FetchRequestEPNS_15ResourceFetcherE + 139
6   Chromium Framework                  0x0000000109d6b15b _ZN5blink24DocumentThreadableLoader11loadRequestERKNS_15ResourceRequestENS_21ResourceLoaderOptionsE + 1291
7   Chromium Framework                  0x0000000109d6b627 _ZN5blink24DocumentThreadableLoader22dispatchInitialRequestERKNS_15ResourceRequestE + 215
8   Chromium Framework                  0x0000000109d6a50c _ZN5blink24DocumentThreadableLoader5startERKNS_15ResourceRequestE + 1804
9   Chromium Framework                  0x0000000109eb9063 _ZN5blink14XMLHttpRequest13createRequestEN3WTF10PassRefPtrINS_15EncodedFormDataEEERNS_14ExceptionStateE + 1779
10  Chromium Framework                  0x0000000109eb7a7d _ZN5blink14XMLHttpRequest4sendERKN3WTF6StringERNS_14ExceptionStateE + 1037
11  Chromium Framework                  0x0000000109eb74ab _ZN5blink14XMLHttpRequest4sendERKNS_62ArrayBufferOrArrayBufferViewOrBlobOrDocumentOrStringOrFormDataERNS_14ExceptionStateE + 91
12  Chromium Framework                  0x000000010a1f8f60 _ZN5blink24XMLHttpRequestV8InternalL18sendMethodCallbackERKN2v820FunctionCallbackInfoINS1_5ValueEEE + 336
13  Chromium Framework                  0x00000001088bbefa _ZN2v88internal25FunctionCallbackArguments4CallEPFvRKNS_20FunctionCallbackInfoINS_5ValueEEEE + 314
14  Chromium Framework                  0x0000000108903636 _ZN2v88internal12_GLOBAL__N_119HandleApiCallHelperEPNS0_7IsolateENS1_16BuiltinArgumentsILNS0_21BuiltinExtraArgumentsE3EEE + 1606
15  Chromium Framework                  0x00000001089379fb _ZN2v88internalL26Builtin_Impl_HandleApiCallENS0_12_GLOBAL__N_116BuiltinArgumentsILNS0_21BuiltinExtraArgumentsE3EEEPNS0_7IsolateE + 59
16  Chromium Framework                  0x000000010890feb6 _ZN2v88internalL21Builtin_HandleApiCallEiPPNS0_6ObjectEPNS0_7IsolateE + 406
17  ???                                 0x0000264f10b06327 0x0 + 42121024267047
18  ???                                 0x0000264f119c1cd5 0x0 + 42121039715541

After a while it recovered on all bots without any action taken.
Something seems very fishy with that DCHECK. The bots had like 50 green builds in a row before this started triggering, then 4 red builds in a row with the same failure (in the case of Mac 10.10 Retina Release (AMD)).

Please investigate. Assigning to japhet who touched the DCHECK last according to git blame.
 

Comment 1 by kbr@chromium.org, Jun 15 2016

Components: Blink>Loader
Labels: -Pri-3 Pri-1
Raising to P1 until this is triaged.

Comment 2 by kbr@chromium.org, Jun 15 2016

Blocking: 596622
Summary: DCHECK firing in webgl_conformance_tests (was: DCHECK firing in webgl_conformance_tests on Mac)
This is happening on Windows and Linux too and is affecting the commit queue:
https://chromium-try-flakes.appspot.com/all_flake_occurrences?key=ahVzfmNocm9taXVtLXRyeS1mbGFrZXNyLwsSBUZsYWtlIiR3ZWJnbF9jb25mb3JtYW5jZV90ZXN0cyAod2l0aCBwYXRjaCkM

A few example builds all hitting the same DCHECK in WebglConformance.conformance_misc_bad_arguments_test:
https://build.chromium.org/p/tryserver.chromium.win/builders/win_chromium_rel_ng/builds/239417
https://build.chromium.org/p/tryserver.chromium.win/builders/win_chromium_rel_ng/builds/239415
https://build.chromium.org/p/tryserver.chromium.linux/builders/linux_chromium_rel_ng/builds/246838

This is urgent. Was there a recent change to the loader? If so it should be reverted until these assertion failures are understood.

Comment 3 by kbr@chromium.org, Jun 15 2016

Labels: -OS-Mac OS-All
Summary: DCHECK firing in webgl_conformance_tests: FATAL:ResourceLoader.cpp(228): Check failed: request.priority() == ResourceLoadPriorityHighest (was: DCHECK firing in webgl_conformance_tests)

Comment 4 by kbr@chromium.org, Jun 15 2016

Examining the recent try flakes:
https://chromium-try-flakes.appspot.com/all_flake_occurrences?key=ahVzfmNocm9taXVtLXRyeS1mbGFrZXNyLwsSBUZsYWtlIiR3ZWJnbF9jb25mb3JtYW5jZV90ZXN0cyAod2l0aCBwYXRjaCkM

I can't find evidence of this failure before today, but at least the last 5 flakes in a row have been caused by this DCHECK.

Cc: yhirano@chromium.org
cc yhirano as loading triager. Looks like this might be reproducible with a debugger.

Somehow the synchronous fetch is losing its priority, which should be set here:
https://cs.chromium.org/chromium/src/third_party/WebKit/Source/core/fetch/ResourceFetcher.cpp?rcl=0&l=143
I looked through recent changes in the last 2 days and couldn't find an obvious culprit.

Comment 7 by kbr@chromium.org, Jun 15 2016

japhet@ points out that the most recent possibly relevant change was ~6 days ago:
https://chromium.googlesource.com/chromium/src/+/5b689eeb4cc9dc5636a8db73c79a2674a154e967

I'm not seeing evidence of this failure before today, but it seems clear that something has changed to trigger this DCHECK.

Comment 8 by japhet@chromium.org, Jun 16 2016

It looks like this flake isn't happening today, so...that's something?

The resource load priority logic is unnecessarily complicated, so I wrote a cleanup patch to see if we can refactor this bug away. https://codereview.chromium.org/2072613002/

Comment 9 by kbr@chromium.org, Jun 24 2016

Note: just found another flake:
https://chromium-swarm.appspot.com/user/task/2f9c4a7e8cfa2e11

[ RUN      ] WebglConformance.conformance_misc_bad_arguments_test
(INFO) 2016-06-24 10:37:41,746 cache_temperature.EnsurePageCacheTemperature:55  PageCacheTemperature: any
[3104:2980:0624/103741:FATAL:resourceloader.cpp(230)] Check failed: request.priority() == ResourceLoadPriorityHighest. 
Backtrace:
	base::debug::StackTrace::StackTrace [0x69601E87+23]
	logging::LogMessage::~LogMessage [0x695AA151+49]
	blink::ResourceLoader::requestSynchronously [0x690B1C73+176]
	blink::ResourceLoader::start [0x690B1EC6+201]
	blink::ResourceFetcher::startLoad [0x690AFE42+298]
	blink::ResourceFetcher::requestResource [0x690AF6AA+1565]
	blink::RawResource::fetch [0x690A1C13+128]
	blink::DocumentThreadableLoader::loadRequest [0x69167EF0+597]
	blink::DocumentThreadableLoader::dispatchInitialRequest [0x691673A0+56]
	blink::DocumentThreadableLoader::start [0x6916957C+1025]
	blink::XMLHttpRequest::createRequest [0x6921925A+1199]
	blink::XMLHttpRequest::send [0x6921B9F5+399]
	blink::XMLHttpRequest::send [0x6921BF3C+51]
	blink::Iterable<unsigned int,blink::Node *>::EntrySelector::select [0x68C1DBD4+397]
	v8::internal::FunctionCallbackArguments::Call [0x683BD224+116]
	v8::internal::IncrementalStringBuilder::Append<unsigned char,unsigned short> [0x6841A9DE+1902]
	v8::internal::Builtins::BooleanConstructor_ConstructStub [0x684261E8+34504]
	v8::internal::Isolate::typed_array_prototype [0x68418C00+4272]

Backtrace:
	base::debug::BreakDebugger [0x69606E09+9]
	logging::InitChromeLogging [0x695A73B3+737]
	logging::LogMessage::~LogMessage [0x695AA2E7+455]
	blink::ResourceLoader::requestSynchronously [0x690B1C73+176]
	blink::ResourceLoader::start [0x690B1EC6+201]
	blink::ResourceFetcher::startLoad [0x690AFE42+298]
	blink::ResourceFetcher::requestResource [0x690AF6AA+1565]
	blink::RawResource::fetch [0x690A1C13+128]
	blink::DocumentThreadableLoader::loadRequest [0x69167EF0+597]
	blink::DocumentThreadableLoader::dispatchInitialRequest [0x691673A0+56]
	blink::DocumentThreadableLoader::start [0x6916957C+1025]
	blink::XMLHttpRequest::createRequest [0x6921925A+1199]
	blink::XMLHttpRequest::send [0x6921B9F5+399]
	blink::XMLHttpRequest::send [0x6921BF3C+51]
	blink::Iterable<unsigned int,blink::Node *>::EntrySelector::select [0x68C1DBD4+397]
	v8::internal::FunctionCallbackArguments::Call [0x683BD224+116]
	v8::internal::IncrementalStringBuilder::Append<unsigned char,unsigned short> [0x6841A9DE+1902]
	v8::internal::Builtins::BooleanConstructor_ConstructStub [0x684261E8+34504]
	v8::internal::Isolate::typed_array_prototype [0x68418C00+4272]
	(No symbol) [0x3E20A0DE]
	(No symbol) [0x21A3BC6D]
	v8::internal::StackGuard::ThreadLocal::Initialize [0x6862F34B+523]
	WTF::StringImpl::operator delete [0x69CB297C+1303]
	blink::V8ScriptRunner::runCompiledScript [0x68C02F66+445]
	blink::V8ScriptRunner::compileScript [0x68C02542+200]

Project Member

Comment 10 by bugdroid1@chromium.org, Aug 5 2016

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

commit fd0671f01914a4f5e74620e75f673f213d302823
Author: japhet <japhet@chromium.org>
Date: Fri Aug 05 23:47:02 2016

Make ResourceLoadPriority calculation simpler

* Don't keep a separate ResourceLoadPriority value on
  FetchRequest, just use ResourceRequest::m_priority.
* Make a bit more use of FetchRequest::LazyLoad for cases
  like preloads where the priority of a request should be
  very low.
* ResourceFetcher::loadPriority() shouldn't blindly trust the
  priority given by a caller, and instead takes the max of
  the provided priority and the priority it calculates.
* Add a helper to FetchRequest to make a request synchronous,
  so callers don't need to manually flag the request as
  Highest priority.

This may or may not fix a case where synchronous requests are
incorrectly and flakily being given a priority lower than
Highest.

BUG= 620334 

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

[modify] https://crrev.com/fd0671f01914a4f5e74620e75f673f213d302823/third_party/WebKit/Source/core/fetch/FetchRequest.cpp
[modify] https://crrev.com/fd0671f01914a4f5e74620e75f673f213d302823/third_party/WebKit/Source/core/fetch/FetchRequest.h
[modify] https://crrev.com/fd0671f01914a4f5e74620e75f673f213d302823/third_party/WebKit/Source/core/fetch/RawResource.cpp
[modify] https://crrev.com/fd0671f01914a4f5e74620e75f673f213d302823/third_party/WebKit/Source/core/fetch/ResourceFetcher.cpp
[modify] https://crrev.com/fd0671f01914a4f5e74620e75f673f213d302823/third_party/WebKit/Source/core/fetch/ResourceFetcher.h
[modify] https://crrev.com/fd0671f01914a4f5e74620e75f673f213d302823/third_party/WebKit/Source/core/fetch/XSLStyleSheetResource.cpp
[modify] https://crrev.com/fd0671f01914a4f5e74620e75f673f213d302823/third_party/WebKit/Source/core/html/LinkResource.cpp
[modify] https://crrev.com/fd0671f01914a4f5e74620e75f673f213d302823/third_party/WebKit/Source/core/loader/LinkLoader.cpp

Gentle ping.  Does it look like #10 fixed this issue?  If still P1 could you please assign a milestone?
Status: Fixed (was: Assigned)

Comment 13 by kbr@chromium.org, Sep 30 2016

Thanks Nate for driving this to completion!

Sign in to add a comment