Bug 56186 - http/tests/misc/script-async.html failed once on Windows
Summary: http/tests/misc/script-async.html failed once on Windows
Status: NEW
Alias: None
Product: WebKit
Classification: Unclassified
Component: Tools / Tests (show other bugs)
Version: 528+ (Nightly build)
Hardware: PC Windows 7
: P2 Normal
Assignee: Tony Gentilcore
URL: http://build.webkit.org/results/Windo...
Keywords: InRadar, LayoutTestFailure, MakingBotsRed, PlatformOnly
Depends on:
Blocks:
 
Reported: 2011-03-11 06:39 PST by Adam Roben (:aroben)
Modified: 2011-05-04 10:26 PDT (History)
5 users (show)

See Also:


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Adam Roben (:aroben) 2011-03-11 06:39:57 PST
http/tests/misc/script-async.html failed once on Windows. See the URL for the diff.
Comment 1 Jessie Berlin 2011-03-11 07:12:45 PST
<rdar://problem/9121059>
Comment 2 Tony Gentilcore 2011-03-11 08:33:03 PST
I thought the http tests were notoriously flaky on Windows due to http server issues. Are they really stable?

I'll patch this test to improve the failure message so we can tell what is going on if it happens again.
Comment 3 Tony Gentilcore 2011-03-11 08:42:10 PST
(In reply to comment #2)
> I thought the http tests were notoriously flaky on Windows due to http server issues. Are they really stable?
> 
> I'll patch this test to improve the failure message so we can tell what is going on if it happens again.

Scratch that comment entirely. The actual result is in the failure message. We executed the slow async script twice which is a serious bug and not caused by the http server. We need to investigate how this could happen.
Comment 4 Tony Gentilcore 2011-03-11 08:58:21 PST
Looking back on the chromium bots, we can see this has failed twice on the Win debug bots in recent times (at r80408 and r80410).

http://test-results.appspot.com/dashboards/flakiness_dashboard.html#tests=http%2Ftests%2Fmisc%2Fscript-async.html&group=%40ToT%20-%20chromium.org

ASSERTION FAILED: m_loadEventDelayCount
Backtrace:
	WebCore::Document::decrementLoadEventDelayCount [0x012E5DE6+54] (e:\b\build\slave\webkit_win__dbg__2_\build\src\third_party\webkit\source\webcore\dom\document.cpp:4962)
	WebCore::AsyncScriptRunner::timerFired [0x01568D52+242] (e:\b\build\slave\webkit_win__dbg__2_\build\src\third_party\webkit\source\webcore\dom\asyncscriptrunner.cpp:89)
	WebCore::Timer<WebCore::AsyncScriptRunner>::fired [0x01568F93+35] (e:\b\build\slave\webkit_win__dbg__2_\build\src\third_party\webkit\source\webcore\platform\timer.h:100)
	WebCore::ResourceHandle::prepareForURL [0x017DB669+1129]
	WebCore::ResourceHandle::prepareForURL [0x017DB586+902]
	webkit_glue::WebKitClientImpl::DoTimeout [0x00AE683B+43] (e:\b\build\slave\webkit_win__dbg__2_\build\src\webkit\glue\webkitclient_impl.h:86)
	DispatchToMethod<webkit_glue::WebKitClientImpl,void (__thiscall webkit_glue::WebKitClientImpl::*)(void)> [0x00AE7A9C+12] (e:\b\build\slave\webkit_win__dbg__2_\build\src\base\tuple.h:541)
	base::BaseTimer<webkit_glue::WebKitClientImpl,0>::TimerTask::Run [0x00AE73E4+84] (e:\b\build\slave\webkit_win__dbg__2_\build\src\base\timer.h:160)
	MessageLoop::RunTask [0x01CC6820+272] (e:\b\build\slave\webkit_win__dbg__2_\build\src\base\message_loop.cc:367)
	MessageLoop::DeferOrRunPendingTask [0x01CC6955+53] (e:\b\build\slave\webkit_win__dbg__2_\build\src\base\message_loop.cc:379)
	MessageLoop::DoWork [0x01CC746C+236] (e:\b\build\slave\webkit_win__dbg__2_\build\src\base\message_loop.cc:569)
	base::MessagePumpForUI::DoRunLoop [0x01D0E6E4+84] (e:\b\build\slave\webkit_win__dbg__2_\build\src\base\message_pump_win.cc:201)
	base::MessagePumpWin::RunWithDispatcher [0x01D0DF52+130] (e:\b\build\slave\webkit_win__dbg__2_\build\src\base\message_pump_win.cc:49)
	base::MessagePumpWin::Run [0x01D0E1BC+28] (e:\b\build\slave\webkit_win__dbg__2_\build\src\base\message_pump_win.h:79)
	MessageLoop::RunInternal [0x01CC6667+247] (e:\b\build\slave\webkit_win__dbg__2_\build\src\base\message_loop.cc:342)
	MessageLoop::RunHandler [0x01CC643E+46] (e:\b\build\slave\webkit_win__dbg__2_\build\src\base\message_loop.cc:316)
	MessageLoop::Run [0x01CC5D4A+58] (e:\b\build\slave\webkit_win__dbg__2_\build\src\base\message_loop.cc:240)
	webkit_support::RunMessageLoop [0x008AB70F+15] (e:\b\build\slave\webkit_win__dbg__2_\build\src\webkit\support\webkit_support.cc:360)
	TestShell::waitTestFinished [0x00428F2D+141] (e:\b\build\slave\webkit_win__dbg__2_\build\src\third_party\webkit\tools\dumprendertree\chromium\testshellwin.cpp:106)
	TestShell::runFileTest [0x0044243F+447] (e:\b\build\slave\webkit_win__dbg__2_\build\src\third_party\webkit\tools\dumprendertree\chromium\testshell.cpp:196)
	runTest [0x00419B5D+733] (e:\b\build\slave\webkit_win__dbg__2_\build\src\third_party\webkit\tools\dumprendertree\chromium\dumprendertree.cpp:119)
	main [0x00419425+1717] (e:\b\build\slave\webkit_win__dbg__2_\build\src\third_party\webkit\tools\dumprendertree\chromium\dumprendertree.cpp:214)
	__tmainCRTStartup [0x00A30CE7+279] (f:\dd\vctools\crt_bld\self_x86\crt\src\crt0.c:266)
	mainCRTStartup [0x00A30BBF+15] (f:\dd\vctools\crt_bld\self_x86\crt\src\crt0.c:182)
	RegisterWaitForInputIdle [0x7C817077+73]
Comment 5 Tony Gentilcore 2011-03-11 09:27:52 PST
ScriptElement::notifyFinished() calls AsyncScriptRunner::executeScriptSoon() and immediately clears its CachedScript to prevent further notifyFinished() notifications. AsyncScriptRunner starts a timer which, upon execution, clears the member with the list of scripts to execute soon and then executes them. So under normal operation, I don't see how we could get double execution.

1,500 runs of the test on mac doesn't repro the problem. I'll warm up a win build and try to repro there, but if that doesn't work, I'm not sure where to go from here.
Comment 6 Tony Gentilcore 2011-03-11 10:26:23 PST
A different handful of tests seem to fail on the win 7 bot nearly every run. I'm growing more skeptical this is actually an issue in the script running code.
Comment 8 Gavin Peters 2011-05-04 10:26:55 PDT
http://code.google.com/p/chromium/issues/detail?id=75604 over on Chrome appears to be the same issue.  I think we're looking at the timer firing twice.