828997 - 30 second+ hangs under nsHttpChannel::UpdateExpirationTime

Status: RESOLVED WONTFIX

(Core :: Networking: Cache, defect)

Description

[Chris Jones [:cjones] inactive; ni?/f?/r? if you need me]

(Filing from Chrome ;) .)

Observed when trying to use firefox on a system under heavy disk stress.  Backtrace is

(gdb) bt
#0  __lll_lock_wait () at ../nptl/sysdeps/unix/sysv/linux/x86_64/lowlevellock.S:132
#1  0x00007f57af1f809b in _L_lock_1006 () from /lib/x86_64-linux-gnu/libpthread.so.0
#2  0x00007f57af1f801c in __pthread_mutex_lock (mutex=0x7f57941dfea0) at pthread_mutex_lock.c:101
#3  0x00007f57ae0eb569 in PR_Lock () from /home/cjones/Desktop/firefox/libnspr4.so
#4  0x00007f57ab01d631 in nsCacheService::Lock(mozilla::Telemetry::ID) () from /home/cjones/Desktop/firefox/libxul.so
#5  0x00007f57ab01aeb3 in nsCacheEntryDescriptor::SetExpirationTime(unsigned int) () from /home/cjones/Desktop/firefox/libxul.so
#6  0x00007f57ab046642 in mozilla::net::nsHttpChannel::UpdateExpirationTime() () from /home/cjones/Desktop/firefox/libxul.so
#7  0x00007f57ab04743f in mozilla::net::nsHttpChannel::InitCacheEntry() () from /home/cjones/Desktop/firefox/libxul.so
#8  0x00007f57ab04b02b in mozilla::net::nsHttpChannel::ContinueProcessNormal(tag_nsresult) () from /home/cjones/Desktop/firefox/libxul.so
#9  0x00007f57ab04b85d in mozilla::net::nsHttpChannel::ProcessNormal() () from /home/cjones/Desktop/firefox/libxul.so
#10 0x00007f57ab04bbb0 in mozilla::net::nsHttpChannel::ProcessResponse() () from /home/cjones/Desktop/firefox/libxul.so
#11 0x00007f57ab04edcd in mozilla::net::nsHttpChannel::OnStartRequest(nsIRequest*, nsISupports*) () from /home/cjones/Desktop/firefox/libxul.so
#12 0x00007f57aaff39ca in nsInputStreamPump::OnStateStart() () from /home/cjones/Desktop/firefox/libxul.so
#13 0x00007f57aaff3d7f in nsInputStreamPump::OnInputStreamReady(nsIAsyncInputStream*) () from /home/cjones/Desktop/firefox/libxul.so
#14 0x00007f57ab69992a in nsInputStreamReadyEvent::Run() () from /home/cjones/Desktop/firefox/libxul.so
#15 0x00007f57ab6a8112 in nsThread::ProcessNextEvent(bool, bool*) () from /home/cjones/Desktop/firefox/libxul.so
#16 0x00007f57ab68108c in NS_ProcessNextEvent_P(nsIThread*, bool) () from /home/cjones/Desktop/firefox/libxul.so
#17 0x00007f57ab613157 in mozilla::ipc::MessagePump::Run(base::MessagePump::Delegate*) () from /home/cjones/Desktop/firefox/libxul.so
#18 0x00007f57ab6c9cd3 in MessageLoop::Run() () from /home/cjones/Desktop/firefox/libxul.so
#19 0x00007f57aa952504 in nsBaseAppShell::Run() () from /home/cjones/Desktop/firefox/libxul.so
#20 0x00007f57aa885d6a in nsAppStartup::Run() () from /home/cjones/Desktop/firefox/libxul.so
#21 0x00007f57aafe1d0b in XREMain::XRE_mainRun() () from /home/cjones/Desktop/firefox/libxul.so
#22 0x00007f57aa3e0c6c in XREMain::XRE_main(int, char**, nsXREAppData const*) () from /home/cjones/Desktop/firefox/libxul.so
#23 0x00007f57aa3e0dff in XRE_main () from /home/cjones/Desktop/firefox/libxul.so
#24 0x00000000004076cb in do_main(int, char**, nsIFile*) ()
#25 0x000000000040798f in main ()

Looks to me like we're blocking on a lock that's being held by a thread doing disk IO.

Comment 1

[Josh Aas]

Should be covered by bug 763555, which is our top Q1 cache priority.

Comment 2

[Honza Bambas (:mayhemer)]

Chris, if you experience this next time, please check which other thread and where is keeping the lock.  It would be very interesting to know.  Thanks.

Comment 3

[Patrick McManus [:mcmanus]]

new cache code now..