1372505 - shutdownhang | _PR_MD_WAIT_CV | _PR_WaitCondVar | mozilla::CondVar::Wait | nsEventQueue::GetEvent | nsThread::nsChainedEventQueue::GetEvent | nsThread::GetEvent | nsThread::ProcessNextEvent | NS_ProcessNextEvent | mozilla::net::nsHttpConnectionMgr::Shu...

Status: RESOLVED WORKSFORME

(NSS :: Libraries, defect, P3)

Description

[Suburp]

User Agent: Mozilla/5.0 (Windows NT 6.1; WOW64; rv:53.0) Gecko/20100101 Firefox/53.0
Build ID: 20170518000419

Steps to reproduce:

start FF (since FF37), bowse for 1 sec to 30 min, crash.
Restart, crash, etc



Actual results:


FF appears to "hang", I can still browse the menu, see the settings cand change them, but open and close tabs, but no data gets loaded from the web anymore. Videos still play until the loaded buffer has played through and then they also receive no further data.


Upon closing, it taks precisely 3 minutes until the crash signature finally appears. If I terminate via ctl alt del, no crash signature ever surfaces. If I let FF running, no crash signature ever surfaces.

So, while the signature is "shutdownhang", the source is a crash in the core itself, whether or not any website is browsed makes no difference.


Is a direct dependent of:
https://bugzilla.mozilla.org/show_bug.cgi?id=1158189

A couple of crash signatures:

https://crash-stats.mozilla.com/report/index/6e1c9e69-6bb8-4c03-bd49-f86540170612


bp-e45a10c5-7db6-4af8-bebc-baa1e0170613
	13-6-17	10:13
bp-6e1c9e69-6bb8-4c03-bd49-f86540170612
	12-6-17	13:48
bp-3b5452aa-5be5-4522-863c-4f4410170612
	12-6-17	13:19
bp-8a0bc6a3-273a-470d-81d7-6ed780170612
	12-6-17	12:42
bp-018effd2-702a-422e-a435-48bec0170612
	12-6-17	11:49
bp-5c6dec2c-fc11-4038-acfe-c4a850170609
	9-6-17	17:10
bp-4dd96521-18b6-4b43-aa7e-b82590170609
	9-6-17	15:36
bp-fcb36750-690e-4e3c-9c28-da7660170609
	9-6-17	11:19
bp-11f75e27-f3ed-4d6a-ae16-d1dc20170608
	8-6-17	15:11
bp-34c11ad1-6405-473b-87f1-78c980170608
	8-6-17	11:24
bp-99446238-dc17-4a2f-8c0a-5bae50170608
	8-6-17	10:12
bp-c2920591-3741-4330-9cc7-636830170608
	8-6-17	08:40
bp-b502b1f5-9e53-4dbc-ba18-a58550170607
	7-6-17	16:41
bp-f4fb56aa-6b72-43f1-8bec-e31d20170607
	7-6-17	12:00
bp-69fad5d0-2fae-42fe-88a7-401c40170607
	7-6-17	11:58
bp-5e0eb35c-ff15-4469-a5d6-957020170601
	1-6-17	18:36
bp-ac2c2c9c-3381-4a2d-a59d-871880170601
	1-6-17	18:15
bp-5dec50d7-89fd-49d7-b23d-43d220170601
	1-6-17	18:04
bp-6688ad21-45fc-4686-9640-4d8a90170601
	1-6-17	17:48
bp-761015f8-39e0-4605-951a-481be0170601
	1-6-17	17:34
bp-2d67b8d1-f519-4364-8007-6d5210170601
	1-6-17	17:14
bp-de7b8337-3724-4fe4-a746-781e30170531
	31-5-17	17:16
bp-de79567a-63cb-45b8-9b82-7b9630170531
	31-5-17	14:49
bp-0d2ac137-c155-46c8-ac27-aed890170531
	31-5-17	11:16




Expected results:

no exception breakpoint

Comment 1

[Suburp]

if you need more signatures.

In FF 53.0.3, signature is
 [@ shutdownhang | _PR_MD_WAIT_CV | _PR_WaitCondVar | mozilla::CondVar::Wait | nsEventQueue::GetEvent | nsThread::nsChainedEventQueue::GetEvent | nsThread::GetEvent | nsThread::ProcessNextEvent | NS_ProcessNextEvent | mozilla::net::nsHttpConnectionMgr::Shu... ]


in 52.0.2, signature is
[@ shutdownhang | mozilla::CondVar::Wait | nsEventQueue::GetEvent | nsThread::nsChainedEventQueue::GetEvent | nsThread::GetEvent | nsThread::ProcessNextEvent | NS_ProcessNextEvent | mozilla::net::nsHttpConnectionMgr::Shutdown ]



bp-318617f4-3860-4c64-b3c0-0caf00170524
	24-5-17	13:59
bp-3e882ca4-c3fd-4dc8-976a-e26cb1170522
	22-5-17	16:14
bp-0aced2b7-a79d-43c8-a203-7bb520170521
	21-5-17	23:37
bp-5eafdeec-ec4e-4630-aed5-f11031170519
	19-5-17	17:21
bp-26f0713b-f8de-485c-9d70-0d9a40170519
	19-5-17	11:22
bp-f8eb83fa-85f9-4621-a8f6-ee8e70170519
	19-5-17	11:22
bp-0b052ad4-90f4-4ce3-af7b-890230170519
	19-5-17	11:22
bp-e0f01ac2-f635-440c-9216-3616d0170518
	18-5-17	17:16
bp-979fa594-8d06-4f69-bba0-33c110170518
	18-5-17	15:20
bp-8380f008-f327-424b-aa43-ee1851170517
	17-5-17	08:57
bp-08af97af-9294-4482-bb4a-822d10170517
	17-5-17	08:30
bp-99a4055c-3593-4c5a-a72a-681c00170515
	15-5-17	12:57
bp-8336305a-a8f6-44b9-98ca-e82c50170515
	15-5-17	12:55
bp-89ca8ceb-f27c-4d15-bba8-03b211170512
	12-5-17	16:29
bp-80713f17-aa93-4150-b648-53aaa0170512
	12-5-17	11:39
bp-1dfeff36-25ff-4b90-a29b-4f79c1170509
	9-5-17	14:41
bp-8bd516e2-9329-482a-b41b-42aa00170504
	4-5-17	17:13
bp-bab9f383-d857-4e8c-8cc2-888130170426
	26-4-17	16:26
bp-00ea53ed-f67c-4781-bc27-cc3650170426
	26-4-17	11:42
bp-5df64860-a649-4415-9ebc-553610170424
	24-4-17	13:33
bp-47cd6a35-be10-47d5-b825-1a10d2170404
	4-4-17	17:06
bp-a2ad2f33-c0ae-495e-af23-c50442170329
	29-3-17	12:26
bp-9e64ddec-f2ca-41a9-8b96-ee2582170315
	15-3-17	17:58


Dragana, is this just a duplicate or a different issue?

Comment 2

[Dragana Damjanovic [:dragana]]

Thanks!
This is happening for you pretty regularly.

Comment 3

[Dragana Damjanovic [:dragana]]

The hang is in nss:

0 	ntdll.dll 	NtWaitForSingleObject 	
1 	ntdll.dll 	RtlpWaitOnCriticalSection 	
2 	ntdll.dll 	RtlpAllocateListLookup 	
3 	nss3.dll 	PR_Lock 	nsprpub/pr/src/threads/combined/prulock.c:213
4 	nss3.dll 	nssSlot_EnterMonitor 	security/nss/lib/dev/devslot.c:45
5 	nss3.dll 	nssSlot_IsTokenPresent 	security/nss/lib/dev/devslot.c:133
6 	nss3.dll 	nssToken_IsPresent 	security/nss/lib/dev/devtoken.c:1420
7 	nss3.dll 	pk11_IsPresentCertLoad 	security/nss/lib/pk11wrap/pk11slot.c:1480
8 	nss3.dll 	PK11_GetAllTokens 	security/nss/lib/pk11wrap/pk11slot.c:2005
9 	nss3.dll 	PK11_GetBestSlotMultipleWithAttributes 	security/nss/lib/pk11wrap/pk11slot.c:2127
10 	nss3.dll 	PK11_GetBestSlot 	security/nss/lib/pk11wrap/pk11slot.c:2212
11 	nss3.dll 	ssl_IsECCEnabled 	security/nss/lib/ssl/ssl3ecc.c:877
12 	nss3.dll 	ssl_SendSupportedGroupsXtn 	security/nss/lib/ssl/ssl3ecc.c:912
13 	nss3.dll 	ssl3_CallHelloExtensionSenders 	security/nss/lib/ssl/ssl3ext.c:427
14 	nss3.dll 	ssl3_SendClientHello 	security/nss/lib/ssl/ssl3con.c:5247
15 	nss3.dll 	ssl_BeginClientHandshake 	security/nss/lib/ssl/sslcon.c:204
16 	nss3.dll 	ssl_Do1stHandshake 	security/nss/lib/ssl/sslsecur.c:65
17 	nss3.dll 	SSL_ForceHandshake 	security/nss/lib/ssl/sslsecur.c:414
18 	xul.dll 	nsNSSSocketInfo::DriveHandshake() 	security/manager/ssl/nsNSSIOLayer.cpp:369
19 	xul.dll 	mozilla::net::nsHttpConnection::EnsureNPNComplete(nsresult&, unsigned int&) 	netwerk/protocol/http/nsHttpConnection.cpp:381
20 	xul.dll 	mozilla::net::nsHttpConnection::OnSocketWritable() 	netwerk/protocol/http/nsHttpConnection.cpp:1718
21 	xul.dll 	mozilla::net::nsHttpConnection::OnOutputStreamReady(nsIAsyncOutputStream*) 	netwerk/protocol/http/nsHttpConnection.cpp:2250
22 	xul.dll 	mozilla::net::nsSocketOutputStream::OnSocketReady(nsresult) 	netwerk/base/nsSocketTransport2.cpp:555
23 	xul.dll 	mozilla::net::nsSocketTransport::OnSocketReady(PRFileDesc*, short) 	netwerk/base/nsSocketTransport2.cpp:1980
24 	xul.dll 	mozilla::net::nsSocketTransportService::DoPollIteration(mozilla::BaseTimeDuration<mozilla::TimeDurationValueCalculator>*) 	netwerk/base/nsSocketTransportService2.cpp:1134
25 	xul.dll 	mozilla::net::nsSocketTransportService::Run()

Comment 4

[Dragana Damjanovic [:dragana]]

ekr, can you take a look?

Comment 5

[Eric Rescorla (:ekr)]

This isn't a TLS issue. Taubert is probably the expert here.

Comment 6

[Suburp]

FF54.0 examples
https://crash-stats.mozilla.com/report/index/9e41966c-05bd-46a2-8a76-c950a0170614
https://crash-stats.mozilla.com/report/index/235820f5-9bea-48f5-b068-2364a0170614


0 	ntdll.dll 	NtWaitForSingleObject 	
1 	kernelbase.dll 	WaitForSingleObjectEx 	
2 	kernel32.dll 	WaitForSingleObjectExImplementation 	
3 	kernel32.dll 	WaitForSingleObject 	
4 	nss3.dll 	_PR_MD_WAIT_CV 	nsprpub/pr/src/md/windows/w95cv.c:248
5 	nss3.dll 	_PR_WaitCondVar 	nsprpub/pr/src/threads/combined/prucv.c:172
6 	nss3.dll 	PR_WaitCondVar 	nsprpub/pr/src/threads/combined/prucv.c:525
7 	xul.dll 	mozilla::CondVar::Wait(unsigned int) 	obj-firefox/dist/include/mozilla/CondVar.h:79
8 	xul.dll 	nsEventQueue::GetEvent(bool, nsIRunnable**, mozilla::BaseAutoLock<mozilla::Mutex>&) 	xpcom/threads/nsEventQueue.cpp:76
9 	xul.dll 	nsThread::nsChainedEventQueue::GetEvent(bool, nsIRunnable**, mozilla::BaseAutoLock<mozilla::Mutex>&) 	xpcom/threads/nsThread.cpp:820
10 	xul.dll 	nsThread::ProcessNextEvent(bool, bool*) 	xpcom/threads/nsThread.cpp:1237
11 	xul.dll 	NS_ProcessNextEvent(nsIThread*, bool) 	xpcom/threads/nsThreadUtils.cpp:389
12 	xul.dll 	mozilla::net::nsHttpConnectionMgr::Shutdown() 	netwerk/protocol/http/nsHttpConnectionMgr.cpp:186
13 	xul.dll 	mozilla::net::nsHttpHandler::Observe(nsISupports*, char const*, char16_t const*) 	netwerk/protocol/http/nsHttpHandler.cpp:1999
14 	xul.dll 	nsObserverList::NotifyObservers(nsISupports*, char const*, char16_t const*) 	xpcom/ds/nsObserverList.cpp:112
15 	xul.dll 	nsObserverService::NotifyObservers(nsISupports*, char const*, char16_t const*) 	xpcom/ds/nsObserverService.cpp:281
16 	xul.dll 	nsXREDirProvider::DoShutdown() 	toolkit/xre/nsXREDirProvider.cpp:1237
17 	xul.dll 	ScopedXPCOMStartup::~ScopedXPCOMStartup() 	toolkit/xre/nsAppRunner.cpp:1417
18 	xul.dll 	mozilla::UniquePtr<ScopedXPCOMStartup, mozilla::DefaultDelete<ScopedXPCOMStartup> >::reset(ScopedXPCOMStartup*) 	obj-firefox/dist/include/mozilla/UniquePtr.h:345
19 	xul.dll 	mozilla::UniquePtr<ScopedXPCOMStartup, mozilla::DefaultDelete<ScopedXPCOMStartup> >::operator=(std::nullptr_t) 	obj-firefox/dist/include/mozilla/UniquePtr.h:313
20 	xul.dll 	XREMain::XRE_main(int, char** const, mozilla::BootstrapConfig const&) 	toolkit/xre/nsAppRunner.cpp:4705
21 	xul.dll 	XRE_main(int, char** const, mozilla::BootstrapConfig const&) 	toolkit/xre/nsAppRunner.cpp:4768
22 	xul.dll 	mozilla::BootstrapImpl::XRE_main(int, char** const, mozilla::BootstrapConfig const&) 	toolkit/xre/Bootstrap.cpp:45
23 	firefox.exe 	wmain 	toolkit/xre/nsWindowsWMain.cpp:115
24 	firefox.exe 	__scrt_common_main_seh 	f:/dd/vctools/crt/vcstartup/src/startup/exe_common.inl:253
25 	kernel32.dll 	BaseThreadInitThunk 	
26 	ntdll.dll 	__RtlUserThreadStart 	
27 	ntdll.dll 	_RtlUserThreadStart

Comment 7

[Tim Taubert [:ttaubert] (inactive)]

(In reply to Dragana Damjanovic [:dragana] from comment #3)
> The hang is in nss:
> 
> 0 	ntdll.dll 	NtWaitForSingleObject 	
> 1 	ntdll.dll 	RtlpWaitOnCriticalSection 	
> 2 	ntdll.dll 	RtlpAllocateListLookup 	
> 3 	nss3.dll 	PR_Lock 	nsprpub/pr/src/threads/combined/prulock.c:213
> 4 	nss3.dll 	nssSlot_EnterMonitor 	security/nss/lib/dev/devslot.c:45
> 5 	nss3.dll 	nssSlot_IsTokenPresent 	security/nss/lib/dev/devslot.c:133
> 6 	nss3.dll 	nssToken_IsPresent 	security/nss/lib/dev/devtoken.c:1420
> 7 	nss3.dll 	pk11_IsPresentCertLoad 
> security/nss/lib/pk11wrap/pk11slot.c:1480
> 8 	nss3.dll 	PK11_GetAllTokens 	security/nss/lib/pk11wrap/pk11slot.c:2005
> 9 	nss3.dll 	PK11_GetBestSlotMultipleWithAttributes 
> security/nss/lib/pk11wrap/pk11slot.c:2127
> 10 	nss3.dll 	PK11_GetBestSlot 	security/nss/lib/pk11wrap/pk11slot.c:2212
> 11 	nss3.dll 	ssl_IsECCEnabled 	security/nss/lib/ssl/ssl3ecc.c:877

Dragana, how did you get this stack trace? All I see is the other crash reports that point to nsHttpConnectionMgr::Shutdown() in one way or the other. Did you hit this by pure chance or do you have steps to reproduce?

Comment 8

[Dragana Damjanovic [:dragana]]

(In reply to Tim Taubert [:ttaubert] from comment #7)
> (In reply to Dragana Damjanovic [:dragana] from comment #3)
> > The hang is in nss:
> > 
> > 0 	ntdll.dll 	NtWaitForSingleObject 	
> > 1 	ntdll.dll 	RtlpWaitOnCriticalSection 	
> > 2 	ntdll.dll 	RtlpAllocateListLookup 	
> > 3 	nss3.dll 	PR_Lock 	nsprpub/pr/src/threads/combined/prulock.c:213
> > 4 	nss3.dll 	nssSlot_EnterMonitor 	security/nss/lib/dev/devslot.c:45
> > 5 	nss3.dll 	nssSlot_IsTokenPresent 	security/nss/lib/dev/devslot.c:133
> > 6 	nss3.dll 	nssToken_IsPresent 	security/nss/lib/dev/devtoken.c:1420
> > 7 	nss3.dll 	pk11_IsPresentCertLoad 
> > security/nss/lib/pk11wrap/pk11slot.c:1480
> > 8 	nss3.dll 	PK11_GetAllTokens 	security/nss/lib/pk11wrap/pk11slot.c:2005
> > 9 	nss3.dll 	PK11_GetBestSlotMultipleWithAttributes 
> > security/nss/lib/pk11wrap/pk11slot.c:2127
> > 10 	nss3.dll 	PK11_GetBestSlot 	security/nss/lib/pk11wrap/pk11slot.c:2212
> > 11 	nss3.dll 	ssl_IsECCEnabled 	security/nss/lib/ssl/ssl3ecc.c:877
> 
> Dragana, how did you get this stack trace? All I see is the other crash
> reports that point to nsHttpConnectionMgr::Shutdown() in one way or the
> other. Did you hit this by pure chance or do you have steps to reproduce?

There is a lot of different reasons nsHttpConnectionMgr::Shutdown() hangs (the bug following them is 
1158189).

The report seems to be able to reproduce it, ot at least it is happening for him a lot. For him this is not only shutdown hang, but browse is hanging before shutdown. See comment 0 (description).

Comment 9

[Suburp]

The report can easily reproduce it: Start firefox, wait between 2 sec and 40 minutes and no website loads anymore. I can still open new tabs, close tabs, open new windows, etc, but no data is received or transmitted - test entered into text fields is gone after a restart.

Comment 10

[Suburp]

In case you need some more traces - here some of the recent crashes, some after just seconds of starting the browser. All identical in their behaviour. This is happening about 6 times a day since FF37. Very reproducibly.

Rapport-ID 	Verzenddatum
bp-f8b0ef51-b947-4d3d-aed2-66fd40170704
	4-7-17	09:35
bp-116c19be-5096-40ba-a445-93d4b0170704
	4-7-17	09:31
bp-5a40d8e4-11e8-4fe7-bd87-f42610170704
	4-7-17	09:24
bp-f25061dc-c988-4aaa-b357-e5bcb0170703
	3-7-17	19:22
bp-d9209ae1-3016-4f6e-a690-f411a0170703
	3-7-17	16:37
bp-e2c4954a-8212-4c01-9f71-14b710170703
	3-7-17	15:59
bp-1bd96c9c-3ea1-4437-a8e8-be8c40170630
	30-6-17	13:42
bp-93dcee8b-53c9-49a5-b83a-6f8290170630
	30-6-17	12:24
bp-ae3615c8-b716-4fd9-85bc-126420170630
	30-6-17	09:36
bp-64cffca2-6b21-40ed-b1f1-565de0170628
	28-6-17	15:35
bp-bd4cd8c5-9cb4-45c4-b20e-50a660170628
	28-6-17	14:08
bp-af14423b-3f6d-4ad5-9563-c87b10170628
	28-6-17	09:52
bp-fb605ccd-9f18-43a7-bc51-9d2000170628
	28-6-17	09:46
bp-cefe9254-65a9-4e81-8e3c-f5ed60170628
	28-6-17	09:26
bp-2c8d3a51-c9b3-4e6a-9316-0c5fb0170626
	26-6-17	08:57
bp-1be34a07-7a55-4238-92fc-9c9e60170622
	22-6-17	12:30
bp-3426da82-e7aa-4bf2-ab67-052b10170621
	21-6-17	11:18
bp-d5c85122-ca96-400e-81d8-e46290170621
	21-6-17	09:50
bp-17f6af46-03d1-401c-a4a5-683ff0170620
	20-6-17	09:37
bp-4babd843-e904-4339-9adc-aa2950170619
	19-6-17	13:09
bp-4b2af5b6-1d39-4265-8647-c14a00170619
	19-6-17	10:35
bp-9e41966c-05bd-46a2-8a76-c950a0170614
	14-6-17	17:33
bp-235820f5-9bea-48f5-b068-2364a0170614
	14-6-17	17:15

Comment 11

[Suburp]

the entire dmp file can be found here: https://www.dropbox.com/s/0dduyneoi4p62j4/firefox.DMP?dl=0

Comment 12

[Dragana Damjanovic [:dragana]]

I looked at couple of crashes from comment 10 and they are all in nss. Tim can you take a look?

Comment 13

[Tim Taubert [:ttaubert] (inactive)]

https://crash-stats.mozilla.com/report/index/235820f5-9bea-48f5-b068-2364a0170614#allthreads

From what I can tell it's thread 9 that's blocked by 95.

In thread 9, ssl_IsECCEnabled() leads to a nssSlot_EnterMonitor() call that waits for the lock.

In thread 95 we have the CertVerifier that calls C_FindObjectsInit() into PKCS11.dll and waits for some other lock... or maybe user interaction? Not sure what this DLL exactly does here. Before the C_FindObjectsInit() we call nssSession_EnterMonitor(session), and I assume that they both refer to the same lock. A session/slot pair always refer to the same lock.

Suburp is probably using some kind of PKCS11 token with Firefox? The problem is if the token itself locks up on shutdown and never returns from C_FindObjectsInit() we won't unlock, and thus we'll hang.

Good is that this won't affect many users, if my assumption of a non-Firefox/NSS PK11 token is correct. Bad is that I'm not sure what to do about that, except stop using PK11 APIs in libssl.

Suburp, can you please tell us a little more about your setup? It looks like you're using a smart card of some sort?

Comment 14

[Marcia Knous [:marcia]]

Judging from crash stats, this is affecting a lot of users - 3194 crashes/2966 installs. It is currently the #5 overall browser crash on release.

Comment 15

[Franziskus Kiefer [:franziskus]]

Looking at the crash reports this only affects FF 54. Let's see if this is fixed in 55.

Comment 16

[Tim Taubert [:ttaubert] (inactive)]

I see no crash reports in Firefox 55+. Guess we can close this?

Comment 17

[Wayne Mery (:wsmwk)]

(In reply to Tim Taubert [:ttaubert] from comment #16)
> I see no crash reports in Firefox 55+. Guess we can close this?

Some users continue crashing in 55 and 56 for example 
bp-4c852e99-b179-4aec-9ec5-8e8260171012	2017-10-12 06:36:06 	shutdownhang | mozilla::SpinEventLoopUntil<T>   Add term
bp-28c3b79e-6f7d-4488-8b1d-5fa510170812	2017-08-12 05:47:09 	shutdownhang | NtWaitForKeyedEvent | RtlSleepConditionVariableSRW | GetTickCount64 | GetTickCount64 | mozilla::TimeStamp::Now | mozilla::CondVar::Wait   Add term
bp-5663e41b-fee7-4b61-ba74-e6b1e0170809	2017-08-09 05:16:41 	shutdownhang | NtWaitForKeyedEvent | RtlSleepConditionVariableSRW | GetTickCount64 | GetTickCount64 | mozilla::TimeStamp::Now | mozilla::CondVar::Wait   Add term
bp-da708c7b-4f70-48b3-922b-1d1ce0170628	2017-06-28 07:22:36 	shutdownhang | ZwWaitForKeyedEvent | RtlSleepConditionVariableSRW | mozilla::MainThreadIdlePeriod::GetIdlePeriodHint   Add term
bp-f424ff26-133b-4eae-a459-0e2ad0170623	2017-06-23 12:55:30 	shutdownhang | ZwWaitForKeyedEvent | RtlSleepConditionVariableSRW | mozilla::MainThreadIdlePeriod::GetIdlePeriodHint   Add term 

But for the vast majority it does seem to be gone

Comment 18

[Suburp]

resolved