We have discovered that the heap walking in RAND_poll function is a cause of deadlock in one of our processes.
OS: Windows Server 2008 R2 (x64) OpenSLL: 0.9.8o This issue could be related to the performance issue reported in: http://rt.openssl.org/Ticket/Display.html?id=2100&user=guest&pass=guest #2100: RAND_poll can be incredibly slow on Windows7 due to Heap32Next In the following call stacks thread 17 (libcurl) and thread 23 (ado) are deadlocked: Thread 17 - System ID 15804 Entry point msvcr90!endthreadex+6f Create time 28/03/2011 10:56:08 Time spent in user mode 0 Days 00:00:01.187 Time spent in kernel mode 0 Days 00:00:00.218 This thread is waiting on critical section 0x0c4c0138 owned by thread 27. Thread 27 in turn is deadlocked with another thread. 17 Id: fb8.3dbc Suspend: 1 Teb: 7ef85000 Unfrozen ChildEBP RetAddr Args to Child 0549dab0 77598dd4 00000cf0 00000000 00000000 ntdll!ZwWaitForSingleObject+0x15 0549db14 77598cb8 00000000 00000000 0549dcc4 ntdll!RtlpWaitOnCriticalSection+0x13e 0549db3c 77598185 0c4c0138 00000000 00000000 ntdll!RtlEnterCriticalSection+0x150 0549db70 7761f6c5 0c4c0000 6b4e7de4 0549dd04 ntdll!RtlLockHeap+0x3d 0549dc58 775edb37 0549dcc4 77603a65 00000000 ntdll!RtlpQueryExtendedHeapInformation+0xbd 0549dc98 776040ff 00000000 00000002 0549dcc4 ntdll!RtlQueryHeapInformation+0x4a 0549dd3c 775e302c 0b450000 75240000 0549de40 ntdll!RtlQueryProcessHeapInformation+0x288 0549ddb8 752d599b 00000fb8 00000014 0b450000 ntdll!RtlQueryProcessDebugInformation+0x28a 0549dde8 0a42fad4 0b450000 a57ffa7c 00000000 kernel32!Heap32Next+0x4d 0549e2fc 0a42ec2d 00c05b98 0a932c38 09f3ebbe libeay32!RAND_poll+0x574 0549e308 09f3ebbe 00c05b98 0a932c38 0835f6ec libeay32!RAND_SSLeay+0x91d 0549e35c 09f3eb81 00c05b98 0a932c38 0835f6ec libcurl!rand_enough+0xe [c:\source\curl-7.21.1\lib\ssluse.c @ 168] 0549e3bc 09f3eab3 00c2a148 00c05b98 0a932c38 libcurl!ossl_seed+0xb1 [c:\source\curl-7.21.1\lib\ssluse.c @ 260] 0549e414 09f3f32d 00c2a148 00c05b98 0a932c38 libcurl!Curl_ossl_seed+0x33 [c:\source\curl-7.21.1\lib\ssluse.c @ 276] 0549e498 09f3f0be 00c4bf58 00000000 00c05b98 libcurl!ossl_connect_step1+0x5d [c:\source\curl-7.21.1\lib\ssluse.c @ 1443] 0549e518 09f42a13 00c4bf58 00000000 00000000 libcurl!ossl_connect_common+0x7e [c:\source\curl-7.21.1\lib\ssluse.c @ 2385] 0549e584 09f3e3ae 00c4bf58 00000000 00c05b98 libcurl!Curl_ossl_connect+0x23 [c:\source\curl-7.21.1\lib\ssluse.c @ 2485] 0549e5e4 09f26156 00c4bf58 00000000 00c05b98 libcurl!Curl_ssl_connect+0x3e [c:\source\curl-7.21.1\lib\sslgen.c @ 196] 0549e648 09f4f1d3 00c4bf58 0549e7d0 00c05b98 libcurl!Curl_http_connect+0xb6 [c:\source\curl-7.21.1\lib\http.c @ 1783] 0549e6ac 09f51eaa 00c4bf58 0549e7d0 00c05b98 libcurl!Curl_protocol_connect+0xc3 [c:\source\curl-7.21.1\lib\url.c @ 3316] 0549e714 09f520ae 00c4bf58 0549e7d0 00c05b98 libcurl!setup_conn+0xfa [c:\source\curl-7.21.1\lib\url.c @ 5007] 0549e774 09f4b2b4 00c4bf58 0549e7d0 00c05b98 libcurl!Curl_async_resolved+0x3e [c:\source\curl-7.21.1\lib\url.c @ 5110] 0549e7dc 09f4aad5 00c2a148 0549e850 00c05b98 libcurl!connect_host+0x74 [c:\source\curl-7.21.1\lib\transfer.c @ 1908] 0549e85c 09f4a9de 00c2a148 00c05b98 0a932c38 libcurl!Curl_do_perform+0x55 [c:\source\curl-7.21.1\lib\transfer.c @ 2034] 0549e8b8 09f1632f 00c2a148 00c05b98 0a932c38 libcurl!Curl_perform+0x1e [c:\source\curl-7.21.1\lib\transfer.c @ 2180] 0549e918 083329d5 00c2a148 a57fce08 0549ebb8 libcurl!curl_easy_perform+0xff [c:\source\curl-7.21.1\lib\easy.c @ 567] Thread 27 - System ID 15272 Entry point msvcr90!endthreadex+6f Create time 28/03/2011 10:56:08 Time spent in user mode 0 Days 00:00:00.00 Time spent in kernel mode 0 Days 00:00:00.00 This thread is waiting on critical section 0x00540138 owned by thread 17. Thread 17 in turn is deadlocked with another thread. 27 Id: fb8.3ba8 Suspend: 1 Teb: 7ef67000 Unfrozen ChildEBP RetAddr Args to Child 0660e088 77598dd4 000005ac 00000000 00000000 ntdll!ZwWaitForSingleObject+0x15 0660e0ec 77598cb8 00000000 00000000 00540000 ntdll!RtlpWaitOnCriticalSection+0x13e 0660e114 77598f39 00540138 6867404c 00078000 ntdll!RtlEnterCriticalSection+0x150 0660e1f0 77593cce 000007f8 00000800 00000000 ntdll!RtlpAllocateHeap+0x159 0660e274 77597bb3 00540000 00800000 000007f8 ntdll!RtlAllocateHeap+0x23a 0660e2c0 77596deb 00000028 686742ec 0b950048 ntdll!RtlpAllocateUserBlock+0xae 0660e350 7758e0d2 0b950048 0b950048 00000000 ntdll!RtlpLowFragHeapAllocFromContext+0x802 0660e3c4 77597ea9 00540000 00000000 00000020 ntdll!RtlAllocateHeap+0x206 0660e3d4 77594829 0c4c0000 0b950048 00000000 ntdll!RtlpAllocateDebugInfo+0x28 0660e410 77592c54 0b950048 00000000 00000000 ntdll!RtlInitializeCriticalSectionEx+0x93 0660e424 7759fd6c 0b950048 0b950048 0c4c0000 ntdll!RtlInitializeCriticalSection+0x12 0660e438 7759fd3a 00000000 00000800 0c4c0000 ntdll!RtlpInitializeLowFragHeap+0x28 0660e448 7759fae4 6867453c 0c4c00cc 0c4c0000 ntdll!RtlpCreateLowFragHeap+0x28 0660e480 7759fb8c 0c4c0000 00000000 0660e56c ntdll!RtlpActivateLowFragmentationHeap+0xc9 0660e490 7759fb58 0c4c0000 686744d0 013ce308 ntdll!RtlpPerformHeapMaintenance+0x2a 0660e56c 77593cce 00001ffa 00002008 00000000 ntdll!RtlpAllocateHeap+0x172 0660e5f0 725896b5 0c4c0000 00000008 00001ffa ntdll!RtlAllocateHeap+0x23a 0660e60c 7259fddb 093fbed8 00001ffa a676c120 sqlsrv32!SQLAllocateMemory+0x20 0660e648 7259fcd5 07889e78 013baa54 0660e6b4 sqlsrv32!SQLAllocConnect+0x14f 0660e658 70610570 00000002 07889e78 013baa54 sqlsrv32!SQLAllocHandle+0x55 0660e6b4 7060fd18 013ac8a0 013ce308 00000000 odbc32!GetInfoForConnection+0x899 0660e6d8 7061b4b2 013ce308 00000000 013ac8a0 odbc32!SQLInternalDriverConnectW+0x15 0660eea4 6cd00466 013ce308 00000000 0ab1d8f8 odbc32!SQLDriverConnectW+0x775 0660ef18 6ccef987 09958148 00000000 0ab1d8f8 msdasql!CODBCHandle::OHDriverConnect+0xc6 0660ef38 6ccf318f 00000000 0ab1d8f8 00000017 msdasql!CHdbcNode::DriverConnect+0x27 0660ef90 6f7462a3 09958148 a6617afb 0ab1d894 msdasql!CImpIDBInitialize::Initialize+0x31f 0660efc4 6f74691f 0ab38760 a6617ac7 0ab10b84 oledb32!CDBInitialize::DoInitialize+0x4c 0660eff8 6f73c18e 0ab1d894 a661658b 078a0434 oledb32!CDBInitialize::Initialize+0xc7 0660f0b4 6f0c967b 0818de14 0660f164 0660f188 oledb32!CDCMPool::CreateResource+0x49d 0660f0f4 6f0cb09b 078a0434 0660f164 0660f188 comsvcs!CHolder::SafeDispenserDriver::CreateResource+0x25 0660f144 6f73d350 00000000 0660f164 0660f188 comsvcs!CHolder::AllocResource+0x301 0660f190 6f74817c 08057870 0ab10b78 080558f4 oledb32!CDCMPool::DrawResource+0x1eb 0660f200 6f73d06b 08057870 0ab10b78 00000017 oledb32!CDCMPoolManager::DrawResource+0x51c 0660f294 6f821cda 0ab10b88 a66181f5 09d4e110 oledb32!CDPO::Initialize+0x2c9 0660f3b4 6f821bdf 09d4e110 00000000 09d4de98 msado15!_ConnectAsync+0x61c 0660f3c8 6f820e41 09d4e110 00c29de0 00000000 msado15!ConnectAsync+0x83 0660f5c8 003c6b62 00d4de98 00000000 00000000 msado15!CConnection::Open+0x109f The fix as suggested in #2100 is to find a alternative source of entropy and not walk the host process's heap list. This does not only have a performance impact on certain windows platforms but actually breaks user code under the right circumstances. Thanks, Hano Botha
|
We have discovered that the heap walking in RAND_poll
function is a cause of deadlock in one of our processes. OS: Windows Server 2008 R2 (x64) OpenSLL: 0.9.8o This issue could be related to the performance issue reported
in: http://rt.openssl.org/Ticket/Display.html?id=2100&user=guest&pass=guest #2100: RAND_poll can be incredibly slow on Windows7 due to
Heap32Next In the following call stacks thread 17 (libcurl) and thread
23 (ado) are deadlocked: Thread 17 - System ID 15804 Entry point
msvcr90!endthreadex+6f Create time
28/03/2011 10:56:08 Time spent in user mode
0 Days 00:00:01.187 Time spent in kernel mode
0 Days 00:00:00.218 This thread is waiting on critical section 0x0c4c0138 owned
by thread 27. Thread 27 in turn is deadlocked with another thread. 17 Id: fb8.3dbc Suspend: 1 Teb: 7ef85000
Unfrozen ChildEBP RetAddr Args to
Child
0549dab0 77598dd4 00000cf0 00000000 00000000
ntdll!ZwWaitForSingleObject+0x15 0549db14 77598cb8 00000000 00000000 0549dcc4
ntdll!RtlpWaitOnCriticalSection+0x13e 0549db3c 77598185 0c4c0138 00000000 00000000
ntdll!RtlEnterCriticalSection+0x150 0549db70 7761f6c5 0c4c0000 6b4e7de4 0549dd04
ntdll!RtlLockHeap+0x3d 0549dc58 775edb37 0549dcc4 77603a65 00000000
ntdll!RtlpQueryExtendedHeapInformation+0xbd 0549dc98 776040ff 00000000 00000002 0549dcc4
ntdll!RtlQueryHeapInformation+0x4a 0549dd3c 775e302c 0b450000 75240000 0549de40
ntdll!RtlQueryProcessHeapInformation+0x288 0549ddb8 752d599b 00000fb8 00000014 0b450000
ntdll!RtlQueryProcessDebugInformation+0x28a 0549dde8 0a42fad4 0b450000 a57ffa7c 00000000
kernel32!Heap32Next+0x4d 0549e2fc 0a42ec2d 00c05b98 0a932c38 09f3ebbe
libeay32!RAND_poll+0x574 0549e308 09f3ebbe 00c05b98 0a932c38 0835f6ec
libeay32!RAND_SSLeay+0x91d 0549e35c 09f3eb81 00c05b98 0a932c38 0835f6ec
libcurl!rand_enough+0xe [c:\source\curl-7.21.1\lib\ssluse.c @ 168] 0549e3bc 09f3eab3 00c2a148 00c05b98 0a932c38
libcurl!ossl_seed+0xb1 [c:\source\curl-7.21.1\lib\ssluse.c @ 260] 0549e414 09f3f32d 00c2a148 00c05b98 0a932c38
libcurl!Curl_ossl_seed+0x33 [c:\source\curl-7.21.1\lib\ssluse.c @ 276] 0549e498 09f3f0be 00c4bf58 00000000 00c05b98
libcurl!ossl_connect_step1+0x5d [c:\source\curl-7.21.1\lib\ssluse.c @ 1443] 0549e518 09f42a13 00c4bf58 00000000 00000000
libcurl!ossl_connect_common+0x7e [c:\source\curl-7.21.1\lib\ssluse.c @ 2385] 0549e584 09f3e3ae 00c4bf58 00000000 00c05b98
libcurl!Curl_ossl_connect+0x23 [c:\source\curl-7.21.1\lib\ssluse.c @ 2485] 0549e5e4 09f26156 00c4bf58 00000000 00c05b98
libcurl!Curl_ssl_connect+0x3e [c:\source\curl-7.21.1\lib\sslgen.c @ 196] 0549e648 09f4f1d3 00c4bf58 0549e7d0 00c05b98
libcurl!Curl_http_connect+0xb6 [c:\source\curl-7.21.1\lib\http.c @ 1783] 0549e6ac 09f51eaa 00c4bf58 0549e7d0 00c05b98
libcurl!Curl_protocol_connect+0xc3 [c:\source\curl-7.21.1\lib\url.c @ 3316] 0549e714 09f520ae 00c4bf58 0549e7d0 00c05b98
libcurl!setup_conn+0xfa [c:\source\curl-7.21.1\lib\url.c @ 5007] 0549e774 09f4b2b4 00c4bf58 0549e7d0 00c05b98
libcurl!Curl_async_resolved+0x3e [c:\source\curl-7.21.1\lib\url.c @ 5110] 0549e7dc 09f4aad5 00c2a148 0549e850 00c05b98
libcurl!connect_host+0x74 [c:\source\curl-7.21.1\lib\transfer.c @ 1908] 0549e85c 09f4a9de 00c2a148 00c05b98 0a932c38
libcurl!Curl_do_perform+0x55 [c:\source\curl-7.21.1\lib\transfer.c @ 2034] 0549e8b8 09f1632f 00c2a148 00c05b98 0a932c38
libcurl!Curl_perform+0x1e [c:\source\curl-7.21.1\lib\transfer.c @ 2180] 0549e918 083329d5 00c2a148 a57fce08 0549ebb8
libcurl!curl_easy_perform+0xff [c:\source\curl-7.21.1\lib\easy.c @ 567] Thread 27 - System ID 15272 Entry point
msvcr90!endthreadex+6f Create time
28/03/2011 10:56:08 Time spent in user mode
0 Days 00:00:00.00 Time spent in kernel mode
0 Days 00:00:00.00 This thread is waiting on critical section 0x00540138 owned
by thread 17. Thread 17 in turn is deadlocked with another thread. 27 Id: fb8.3ba8 Suspend: 1 Teb: 7ef67000
Unfrozen ChildEBP RetAddr Args to
Child
0660e088 77598dd4 000005ac 00000000 00000000
ntdll!ZwWaitForSingleObject+0x15 0660e0ec 77598cb8 00000000 00000000 00540000
ntdll!RtlpWaitOnCriticalSection+0x13e 0660e114 77598f39 00540138 6867404c 00078000 ntdll!RtlEnterCriticalSection+0x150 0660e1f0 77593cce 000007f8 00000800 00000000
ntdll!RtlpAllocateHeap+0x159 0660e274 77597bb3 00540000 00800000 000007f8
ntdll!RtlAllocateHeap+0x23a 0660e2c0 77596deb 00000028 686742ec 0b950048
ntdll!RtlpAllocateUserBlock+0xae 0660e350 7758e0d2 0b950048 0b950048 00000000
ntdll!RtlpLowFragHeapAllocFromContext+0x802 0660e3c4 77597ea9 00540000 00000000 00000020
ntdll!RtlAllocateHeap+0x206 0660e3d4 77594829 0c4c0000 0b950048 00000000
ntdll!RtlpAllocateDebugInfo+0x28 0660e410 77592c54 0b950048 00000000 00000000
ntdll!RtlInitializeCriticalSectionEx+0x93 0660e424 7759fd6c 0b950048 0b950048 0c4c0000
ntdll!RtlInitializeCriticalSection+0x12 0660e438 7759fd3a 00000000 00000800 0c4c0000
ntdll!RtlpInitializeLowFragHeap+0x28 0660e448 7759fae4 6867453c 0c4c00cc 0c4c0000
ntdll!RtlpCreateLowFragHeap+0x28 0660e480 7759fb8c 0c4c0000 00000000 0660e56c
ntdll!RtlpActivateLowFragmentationHeap+0xc9 0660e490 7759fb58 0c4c0000 686744d0 013ce308
ntdll!RtlpPerformHeapMaintenance+0x2a 0660e56c 77593cce 00001ffa 00002008 00000000
ntdll!RtlpAllocateHeap+0x172 0660e5f0 725896b5 0c4c0000 00000008 00001ffa
ntdll!RtlAllocateHeap+0x23a 0660e60c 7259fddb 093fbed8 00001ffa a676c120
sqlsrv32!SQLAllocateMemory+0x20 0660e648 7259fcd5 07889e78 013baa54 0660e6b4 sqlsrv32!SQLAllocConnect+0x14f 0660e658 70610570 00000002 07889e78 013baa54
sqlsrv32!SQLAllocHandle+0x55 0660e6b4 7060fd18 013ac8a0 013ce308 00000000
odbc32!GetInfoForConnection+0x899 0660e6d8 7061b4b2 013ce308 00000000 013ac8a0
odbc32!SQLInternalDriverConnectW+0x15 0660eea4 6cd00466 013ce308 00000000 0ab1d8f8
odbc32!SQLDriverConnectW+0x775 0660ef18 6ccef987 09958148 00000000 0ab1d8f8
msdasql!CODBCHandle::OHDriverConnect+0xc6 0660ef38 6ccf318f 00000000 0ab1d8f8 00000017
msdasql!CHdbcNode::DriverConnect+0x27 0660ef90 6f7462a3 09958148 a6617afb 0ab1d894
msdasql!CImpIDBInitialize::Initialize+0x31f 0660efc4 6f74691f 0ab38760 a6617ac7 0ab10b84
oledb32!CDBInitialize::DoInitialize+0x4c 0660eff8 6f73c18e 0ab1d894 a661658b 078a0434
oledb32!CDBInitialize::Initialize+0xc7 0660f0b4 6f0c967b 0818de14 0660f164 0660f188
oledb32!CDCMPool::CreateResource+0x49d 0660f0f4 6f0cb09b 078a0434 0660f164 0660f188
comsvcs!CHolder::SafeDispenserDriver::CreateResource+0x25 0660f144 6f73d350 00000000 0660f164 0660f188
comsvcs!CHolder::AllocResource+0x301 0660f190 6f74817c 08057870 0ab10b78 080558f4
oledb32!CDCMPool::DrawResource+0x1eb 0660f200 6f73d06b 08057870 0ab10b78 00000017
oledb32!CDCMPoolManager::DrawResource+0x51c 0660f294 6f821cda 0ab10b88 a66181f5 09d4e110
oledb32!CDPO::Initialize+0x2c9 0660f3b4 6f821bdf 09d4e110 00000000 09d4de98
msado15!_ConnectAsync+0x61c 0660f3c8 6f820e41 09d4e110 00c29de0 00000000
msado15!ConnectAsync+0x83 0660f5c8 003c6b62 00d4de98 00000000 00000000
msado15!CConnection::Open+0x109f The fix as suggested in #2100 is to find a alternative
source of entropy and not walk the host process’s heap list. This does not only have a performance impact on certain
windows platforms but actually breaks user code under the right circumstances. Thanks, Hano Botha |
