Bug 82505 – several http tests are flaky and crashing on win, debug

• Component: Tools / Tests
• Status: RESOLVED FIXED

[Dirk Pranke]

See:

http://test-results.appspot.com/dashboards/flakiness_dashboard.html#tests=http%2Ftests%2Fxmlhttprequest%2Fredirect-cross-origin-post.html

Looks like this has been flaky on windows for a *long* time ... http://code.google.com/p/chromium/issues/detail?id=28092

[Dirk Pranke]

However, the failures actually appear to be stack traces ... I don't know why they're not being reported as crashes. I tried a bit to reproduce this yesterday on linux locally, but had no luck. Perhaps someone can take a look?

[Bill Budge]

I looked at this in the VS debugger by loading the page in TestShell. The test passes but hits a DCHECK in timer.cc (this also seems to be the case from a quick look at the flakiness dashboard logs)

Here's the code:

void Timer::AbandonScheduledTask() {
  DCHECK(thread_id_ == 0 ||
         thread_id_ == static_cast<int>(PlatformThread::CurrentId()));
  if (scheduled_task_) {
    scheduled_task_->Abandon();
    scheduled_task_ = NULL;
  }
}

Here's the stack trace. I don't know what's going on but hopefully someone can shed some light.

 	test_shell.exe!base::debug::BreakDebugger()  Line 107	C++
 	test_shell.exe!logging::LogMessage::~LogMessage()  Line 642	C++
>	test_shell.exe!base::Timer::AbandonScheduledTask()  Line 145	C++
 	test_shell.exe!base::Timer::StopAndAbandon()  Line 138	C++
 	test_shell.exe!base::Timer::~Timer()  Line 81	C++
 	test_shell.exe!base::BaseTimerMethodPointer<`anonymous namespace'::RequestProxy,1>::~BaseTimerMethodPointer<`anonymous namespace'::RequestProxy,1>()  + 0x16 bytes	C++
 	test_shell.exe!base::RepeatingTimer<`anonymous namespace'::RequestProxy>::~RepeatingTimer<`anonymous namespace'::RequestProxy>()  + 0x16 bytes	C++
 	test_shell.exe!`anonymous namespace'::RequestProxy::~RequestProxy()  Line 315 + 0x27 bytes	C++
 	test_shell.exe!`anonymous namespace'::RequestProxy::`scalar deleting destructor'()  + 0x16 bytes	C++
 	test_shell.exe!base::RefCountedThreadSafe<`anonymous namespace'::RequestProxy,base::DefaultRefCountedThreadSafeTraits<`anonymous namespace'::RequestProxy> >::DeleteInternal(const `anonymous-namespace'::RequestProxy * x=0x0c707e48)  Line 151 + 0x3e bytes	C++
 	test_shell.exe!base::DefaultRefCountedThreadSafeTraits<`anonymous namespace'::RequestProxy>::Destruct(const `anonymous-namespace'::RequestProxy * x=0x0c707e48)  Line 117 + 0x9 bytes	C++
 	test_shell.exe!base::RefCountedThreadSafe<`anonymous namespace'::RequestProxy,base::DefaultRefCountedThreadSafeTraits<`anonymous namespace'::RequestProxy> >::Release()  Line 145 + 0x21 bytes	C++
 	test_shell.exe!base::internal::MaybeRefcount<1,`anonymous namespace'::RequestProxy *>::Release(`anonymous-namespace'::RequestProxy * o=0x0c707e48)  Line 466 + 0xe bytes	C++
 	test_shell.exe!base::internal::BindState<base::internal::RunnableAdapter<void (__thiscall `anonymous namespace'::RequestProxy::*)(net::URLRequestStatus const &,std::basic_string<char,std::char_traits<char>,std::allocator<char> > const &,base::TimeTicks const &)>,void __cdecl(`anonymous namespace'::RequestProxy *,net::URLRequestStatus const &,std::basic_string<char,std::char_traits<char>,std::allocator<char> > const &,base::TimeTicks const &),void __cdecl(`anonymous namespace'::RequestProxy *,net::URLRequestStatus,std::basic_string<char,std::char_traits<char>,std::allocator<char> >,base::TimeTicks)>::~BindState<base::internal::RunnableAdapter<void (__thiscall `anonymous namespace'::RequestProxy::*)(net::URLRequestStatus const &,std::basic_string<char,std::char_traits<char>,std::allocator<char> > const &,base::TimeTicks const &)>,void __cdecl(`anonymous namespace'::RequestProxy *,net::URLRequestStatus const &,std::basic_string<char,std::char_traits<char>,std::allocator<char> > const &,base::TimeTicks const &),void __cdecl(`anonymous namespace'::RequestProxy *,net::URLRequestStatus,std::basic_string<char,std::char_traits<char>,std::allocator<char> >,base::TimeTicks)>()  Line 2655 + 0xc bytes	C++
 	test_shell.exe!base::internal::BindState<base::internal::RunnableAdapter<void (__thiscall `anonymous namespace'::RequestProxy::*)(net::URLRequestStatus const &,std::basic_string<char,std::char_traits<char>,std::allocator<char> > const &,base::TimeTicks const &)>,void __cdecl(`anonymous namespace'::RequestProxy *,net::URLRequestStatus const &,std::basic_string<char,std::char_traits<char>,std::allocator<char> > const &,base::TimeTicks const &),void __cdecl(`anonymous namespace'::RequestProxy *,net::URLRequestStatus,std::basic_string<char,std::char_traits<char>,std::allocator<char> >,base::TimeTicks)>::`scalar deleting destructor'()  + 0x16 bytes	C++
 	test_shell.exe!base::RefCountedThreadSafe<base::internal::BindStateBase,base::DefaultRefCountedThreadSafeTraits<base::internal::BindStateBase> >::DeleteInternal(const base::internal::BindStateBase * x=0x0c6e6098)  Line 151 + 0x3e bytes	C++
 	test_shell.exe!base::DefaultRefCountedThreadSafeTraits<base::internal::BindStateBase>::Destruct(const base::internal::BindStateBase * x=0x0c6e6098)  Line 117 + 0x9 bytes	C++
 	test_shell.exe!base::RefCountedThreadSafe<base::internal::BindStateBase,base::DefaultRefCountedThreadSafeTraits<base::internal::BindStateBase> >::Release()  Line 145 + 0x21 bytes	C++
 	test_shell.exe!scoped_refptr<base::internal::BindStateBase>::~scoped_refptr<base::internal::BindStateBase>()  Line 244	C++
 	test_shell.exe!base::internal::CallbackBase::~CallbackBase()  Line 33 + 0x8 bytes	C++
 	test_shell.exe!base::Callback<void __cdecl(void)>::~Callback<void __cdecl(void)>()  + 0x16 bytes	C++
 	test_shell.exe!base::PendingTask::~PendingTask()  Line 32 + 0xb bytes	C++
 	test_shell.exe!MessageLoop::DoWork()  Line 661 + 0xc bytes	C++
 	test_shell.exe!base::MessagePumpForUI::DoRunLoop()  Line 203 + 0x1d bytes	C++
 	test_shell.exe!base::MessagePumpWin::RunWithDispatcher(base::MessagePump::Delegate * delegate=0x0029fc94, base::MessagePumpWin::Dispatcher * dispatcher=0x00000000)  Line 51 + 0xf bytes	C++
 	test_shell.exe!base::MessagePumpWin::Run(base::MessagePump::Delegate * delegate=0x0029fc94)  Line 64 + 0x1c bytes	C++
 	test_shell.exe!MessageLoop::RunInternal()  Line 417 + 0x2a bytes	C++
 	test_shell.exe!MessageLoop::RunHandler()  Line 391	C++
 	test_shell.exe!MessageLoop::Run()  Line 301	C++
 	test_shell.exe!main(int argc=4, char * * argv=0x003225d8)  Line 334	C++
 	test_shell.exe!__tmainCRTStartup()  Line 266 + 0x19 bytes	C
 	test_shell.exe!mainCRTStartup()  Line 182	C
 	kernel32.dll!76a73677() 	
 	[Frames below may be incorrect and/or missing, no symbols loaded for kernel32.dll]	
 	ntdll.dll!77679f42() 	
 	ntdll.dll!77679f15()

[Tony Chang]

It looks like this is because of the call to  logging::SetLogAssertHandler(UnitTestAssertHandler); in webkit_support.cc.  This causes us to not crash when we hit an assert.  I think we're not supposed to set this for DRT or test_shell.

It looks like the code has been this way for a long time (at least 18 months?).  Maybe we've never properly crashed on ASSERTs in debug?

[Dirk Pranke]

Looks like a few other tests are hitting this as well:

http/tests/xmlhttprequest/redirect-cross-origin-post.html
http/tests/media/media-can-load-when-hidden.html
http/tests/xmlhttprequest/upload-onloadend-event-after-abort.html
http/tests/xmlhttprequest/upload-onprogress-event.html
http/tests/xmlhttprequest/upload-onloadend-event-after-sync-requests.html

Note that after tony's change in chromium r129689 we're at least getting proper crashes.

[Ami Fischman]

The crash is caused by a bug in chromium's simple_resource_loader_bridge.cc; opened http://crbug.com/122182 and sent CR for it in https://chromiumcodereview.appspot.com/10012010/

Also, the failing media test (http/tests/media/media-can-load-when-hidden.html) doesn't actually need to be an http test, so I'm moving it into LayoutTests/media (and de-racing it) in bug 83296.

[Ami Fischman]

The Timer check triggered by ~RequestProxy() is fixed in http://src.chromium.org/viewvc/chrome?view=rev&revision=131170
When this rolls into WebKit deps I'll post a patch to remove the failure expectations.

[Ami Fischman]

Created attachment 136085 [details]
Patch

[WebKit Review Bot]

Comment on attachment 136085 [details]
Patch

Clearing flags on attachment: 136085

Committed r113566: <http://trac.webkit.org/changeset/113566>

[WebKit Review Bot]

All reviewed patches have been landed.  Closing bug.