OPENSSL_init_crypto with OPENSSL_INIT_NO_ATEXIT issue

Previous Topic Next Topic
 
classic Classic list List threaded Threaded
10 messages Options
Reply | Threaded
Open this post in threaded view
|

OPENSSL_init_crypto with OPENSSL_INIT_NO_ATEXIT issue

Dan Heinz

I have a static library using OpenSSL (built as static library with the no-pinshared parameter in the configuration) that is then included in a DLL that gets loaded and unloaded many times by the calling application.  Now that the code is in 1.1.1c to allow me to manually shutdown the OpenSSL library, I’ve run into an issue when loading and unloading my DLL multiple times from the calling application.  I am testing this on Windows 10.  A summary of what I am doing:

  1. Calling executable calls LoadLibrary to load the DLL containing the static library that uses OpenSSL.
  2. Calling executable calls a function of the now loaded DLL.
  3. The DLL function calls a function in the static library to initialize OpenSSL using: openssl_result = OPENSSL_init_crypto(OPENSSL_INIT_NO_ATEXIT, NULL);
  4. The DLL function calls a function in the static library to decrypt some data using the RSA_private_decrypt OpenSSL API.
  5. The DLL function calls a function in the static library to shutdown OpenSSL using: OPENSSL_cleanup(); (required)  and CRYPTO_cleanup_all_ex_data(); (not sure if this is needed).
  6. The calling executable uses FreeLibrary to unload the DLL.
  7. The calling executable goes to step 1 to  repeat the process.

Iterating through the above steps always fails on iteration 1077.  OpenSLL reports the error:
error:4088003:rsa routines:RSA_setup_binding:BN lib

 

After some debugging, I see that the failure happens in the function CRYPTO_THREAD_init_local in threads_win.c.  *key = TlsAlloc(); fails with the error TLS_OUT_OF_INDEXES.

 

Is something not being freed? Is there something additional I need to do at shutdown? 

 

Reply | Threaded
Open this post in threaded view
|

Re: OPENSSL_init_crypto with OPENSSL_INIT_NO_ATEXIT issue

Matt Caswell-2


On 09/08/2019 14:33, Dan Heinz wrote:

> I have a static library using OpenSSL (built as static library with the
> no-pinshared parameter in the configuration) that is then included in a DLL that
> gets loaded and unloaded many times by the calling application.  Now that the
> code is in 1.1.1c to allow me to manually shutdown the OpenSSL library, I’ve run
> into an issue when loading and unloading my DLL multiple times from the calling
> application.  I am testing this on Windows 10.  A summary of what I am doing:
>
>  1. Calling executable calls LoadLibrary to load the DLL containing the static
>     library that uses OpenSSL.
>  2. Calling executable calls a function of the now loaded DLL.
>  3. The DLL function calls a function in the static library to initialize
>     OpenSSL using: openssl_result = OPENSSL_init_crypto(OPENSSL_INIT_NO_ATEXIT,
>     NULL);
>  4. The DLL function calls a function in the static library to decrypt some data
>     using the RSA_private_decrypt OpenSSL API.
>  5. The DLL function calls a function in the static library to shutdown OpenSSL
>     using: OPENSSL_cleanup(); (required)  and CRYPTO_cleanup_all_ex_data(); (not
>     sure if this is needed).
>  6. The calling executable uses FreeLibrary to unload the DLL.
>  7. The calling executable goes to step 1 to  repeat the process.
>
> Iterating through the above steps always fails on iteration 1077.  OpenSLL
> reports the error:
> error:4088003:rsa routines:RSA_setup_binding:BN lib
>
>  
>
> After some debugging, I see that the failure happens in the function
> CRYPTO_THREAD_init_local in threads_win.c.  *key = TlsAlloc(); fails with the
> error TLS_OUT_OF_INDEXES.
>
> Is something not being freed? Is there something additional I need to do at
> shutdown? 

For every call of CRYPTO_THREAD_init_local() while the library is running you
should see a matching call to CRYPTO_THREAD_cleanup_local() to cleanup the index
(as a result of an OPENSSL_cleanup() call). If you don't see that then an index
is leaking.

Matt

Reply | Threaded
Open this post in threaded view
|

RE: OPENSSL_init_crypto with OPENSSL_INIT_NO_ATEXIT issue

Dan Heinz
On 09/08/2019 14:33, Dan Heinz wrote:

>> I have a static library using OpenSSL (built as static library with
>> the no-pinshared parameter in the configuration) that is then included
>> in a DLL that gets loaded and unloaded many times by the calling
>> application.  Now that the code is in 1.1.1c to allow me to manually
>> shutdown the OpenSSL library, I've run into an issue when loading and
>> unloading my DLL multiple times from the calling application.  I am testing this on Windows 10.  A summary of what I am doing:
>>
>>  1. Calling executable calls LoadLibrary to load the DLL containing the static
>>     library that uses OpenSSL.
>>  2. Calling executable calls a function of the now loaded DLL.
>>  3. The DLL function calls a function in the static library to initialize
>>     OpenSSL using: openssl_result = OPENSSL_init_crypto(OPENSSL_INIT_NO_ATEXIT,
>>     NULL);
>>  4. The DLL function calls a function in the static library to decrypt some data
>>     using the RSA_private_decrypt OpenSSL API.
>>  5. The DLL function calls a function in the static library to shutdown OpenSSL
>>     using: OPENSSL_cleanup(); (required)  and CRYPTO_cleanup_all_ex_data(); (not
>>     sure if this is needed).
>>  6. The calling executable uses FreeLibrary to unload the DLL.
>>  7. The calling executable goes to step 1 to  repeat the process.
>>
>> Iterating through the above steps always fails on iteration 1077. 
>> OpenSLL reports the error:
>> error:4088003:rsa routines:RSA_setup_binding:BN lib
>>
>>  
>>
>> After some debugging, I see that the failure happens in the function
>> CRYPTO_THREAD_init_local in threads_win.c.  *key = TlsAlloc(); fails
>> with the error TLS_OUT_OF_INDEXES.
>>
>> Is something not being freed? Is there something additional I need to
>> do at shutdown?

>For every call of CRYPTO_THREAD_init_local() while the library is running you should see a matching call to CRYPTO_THREAD_cleanup_local() to cleanup the index (as a result of an OPENSSL_cleanup() call). If you don't see that then an >index is leaking.


Thanks for the guidance, Matt.  I added some code to output the counts of the calls to TlsAlloc and TlsFree.  I see 4 allocations and 4 matching deallocations for each iteration of my tests.  
The allocations/deallocations are for:

destructor_key.value in OPENSSL_cleanup()
private_drbg    (from CRYPTO_THREAD_init_local(&private_drbg, NULL))
public_drbg     (from CRYPTO_THREAD_init_local(&public_drbg, NULL))
err_thread_local    (fromCRYPTO_THREAD_init_local(&err_thread_local, NULL))

On the 1076th test iteration, I get the error (TLS_OUT_OF_INDEXES) from TlsAlloc.

I checked for any errors from TlsFree during the tests and it always returns success.
One thing I did notice is that the index value (from this line: *key = TlsAlloc()) is always incremented by 1 after each test iteration.  The destructor_key.value always stayed the same number (7), but the other three allocations always incremented the value of the key variable.  By the time my test reaches the 1076th iteration, the value of key is just under 2000.  For example the indices from TlsAlloc might be 10,11, and 12 and the next iteration they are 11, 12, 13.  MS documentation states "The maximum number of indexes per process is 1,088"  which seems to coincide with the number of my test iterations.  None of my code uses thread local storage.  Any ideas?  

Here's some output from my tests (note the key values keep incrementing).
Iteration: 1    ***********************************************
Key value: 7
TlsAlloc called.  AllocationCount: 1
Key value: 9
TlsAlloc called.  AllocationCount: 2
Key value: 10
TlsAlloc called.  AllocationCount: 3
Key value: 11
TlsAlloc called.  AllocationCount: 4
TlsFree called.   AllocationCount: 3
TlsFree called.   AllocationCount: 2
TlsFree called.   AllocationCount: 1
TlsFree called.   AllocationCount: 0
Iteration: 2    ***********************************************
Key value: 7
TlsAlloc called.  AllocationCount: 1
Key value: 10
TlsAlloc called.  AllocationCount: 2
Key value: 11
TlsAlloc called.  AllocationCount: 3
Key value: 12
TlsAlloc called.  AllocationCount: 4
TlsFree called.   AllocationCount: 3
TlsFree called.   AllocationCount: 2
TlsFree called.   AllocationCount: 1
TlsFree called.   AllocationCount: 0

.....

Iteration: 1076    ***********************************************
Key value: 7
TlsAlloc called.  AllocationCount: 1
Key value: 1086
TlsAlloc called.  AllocationCount: 2
Key value: 1087
TlsAlloc called.  AllocationCount: 3
Key value: 4294967295 (this is TLS_OUT_OF_INDEXES)



Reply | Threaded
Open this post in threaded view
|

Re: OPENSSL_init_crypto with OPENSSL_INIT_NO_ATEXIT issue

Matt Caswell-2


On 13/08/2019 19:16, Dan Heinz wrote:

> On 09/08/2019 14:33, Dan Heinz wrote:
>>> I have a static library using OpenSSL (built as static library with the
>>> no-pinshared parameter in the configuration) that is then included in a
>>> DLL that gets loaded and unloaded many times by the calling application.
>>> Now that the code is in 1.1.1c to allow me to manually shutdown the
>>> OpenSSL library, I've run into an issue when loading and unloading my DLL
>>> multiple times from the calling application.  I am testing this on
>>> Windows 10.  A summary of what I am doing:
>>>
>>> 1. Calling executable calls LoadLibrary to load the DLL containing the
>>> static library that uses OpenSSL. 2. Calling executable calls a function
>>> of the now loaded DLL. 3. The DLL function calls a function in the static
>>> library to initialize OpenSSL using: openssl_result =
>>> OPENSSL_init_crypto(OPENSSL_INIT_NO_ATEXIT, NULL); 4. The DLL function
>>> calls a function in the static library to decrypt some data using the
>>> RSA_private_decrypt OpenSSL API. 5. The DLL function calls a function in
>>> the static library to shutdown OpenSSL using: OPENSSL_cleanup();
>>> (required)  and CRYPTO_cleanup_all_ex_data(); (not sure if this is
>>> needed). 6. The calling executable uses FreeLibrary to unload the DLL. 7.
>>> The calling executable goes to step 1 to  repeat the process.
>>>
>>> Iterating through the above steps always fails on iteration 1077. OpenSLL
>>> reports the error: error:4088003:rsa routines:RSA_setup_binding:BN lib
>>>
>>>
>>>
>>> After some debugging, I see that the failure happens in the function
>>> CRYPTO_THREAD_init_local in threads_win.c.  *key = TlsAlloc(); fails with
>>> the error TLS_OUT_OF_INDEXES.
>>>
>>> Is something not being freed? Is there something additional I need to do
>>> at shutdown?
>
>> For every call of CRYPTO_THREAD_init_local() while the library is running
>> you should see a matching call to CRYPTO_THREAD_cleanup_local() to cleanup
>> the index (as a result of an OPENSSL_cleanup() call). If you don't see that
>> then an >index is leaking.
>
>
> Thanks for the guidance, Matt.  I added some code to output the counts of the
> calls to TlsAlloc and TlsFree.  I see 4 allocations and 4 matching
> deallocations for each iteration of my tests. The allocations/deallocations
> are for:
>
> destructor_key.value in OPENSSL_cleanup() private_drbg    (from
> CRYPTO_THREAD_init_local(&private_drbg, NULL)) public_drbg     (from
> CRYPTO_THREAD_init_local(&public_drbg, NULL)) err_thread_local
> (fromCRYPTO_THREAD_init_local(&err_thread_local, NULL))
>
> On the 1076th test iteration, I get the error (TLS_OUT_OF_INDEXES) from
> TlsAlloc.
>
> I checked for any errors from TlsFree during the tests and it always returns
> success. One thing I did notice is that the index value (from this line: *key
> = TlsAlloc()) is always incremented by 1 after each test iteration.  The
> destructor_key.value always stayed the same number (7), but the other three
> allocations always incremented the value of the key variable.

That is quite strange behaviour. I can't think of a good reason why that
particular index should always be the same while the others increment.

I suppose the 4 deallocation calls that you see are deallocating the correct
index? And that the TlsFree calls actually succeed?

I'm not really a Windows programmer, so perhaps others who have more knowledge
of Windows than I do can make some suggestions.

Matt


>  By the time my
> test reaches the 1076th iteration, the value of key is just under 2000.  For
> example the indices from TlsAlloc might be 10,11, and 12 and the next
> iteration they are 11, 12, 13.  MS documentation states "The maximum number
> of indexes per process is 1,088"  which seems to coincide with the number of
> my test iterations.  None of my code uses thread local storage.  Any ideas?
>
>
> Here's some output from my tests (note the key values keep incrementing).
> Iteration: 1    *********************************************** Key value: 7
> TlsAlloc called.  AllocationCount: 1 Key value: 9 TlsAlloc called.
> AllocationCount: 2 Key value: 10 TlsAlloc called.  AllocationCount: 3 Key
> value: 11 TlsAlloc called.  AllocationCount: 4 TlsFree called.
> AllocationCount: 3 TlsFree called.   AllocationCount: 2 TlsFree called.
> AllocationCount: 1 TlsFree called.   AllocationCount: 0 Iteration: 2
> *********************************************** Key value: 7 TlsAlloc called.
> AllocationCount: 1 Key value: 10 TlsAlloc called.  AllocationCount: 2 Key
> value: 11 TlsAlloc called.  AllocationCount: 3 Key value: 12 TlsAlloc called.
> AllocationCount: 4 TlsFree called.   AllocationCount: 3 TlsFree called.
> AllocationCount: 2 TlsFree called.   AllocationCount: 1 TlsFree called.
> AllocationCount: 0
>
> .....
>
> Iteration: 1076    *********************************************** Key value:
> 7 TlsAlloc called.  AllocationCount: 1 Key value: 1086 TlsAlloc called.
> AllocationCount: 2 Key value: 1087 TlsAlloc called.  AllocationCount: 3 Key
> value: 4294967295 (this is TLS_OUT_OF_INDEXES)
>
>
>
Reply | Threaded
Open this post in threaded view
|

RE: OPENSSL_init_crypto with OPENSSL_INIT_NO_ATEXIT issue

Michael Wojcik
The output certainly suggests something is calling TlsAlloc between the call made for destructor_key.value and the one for private_drbg, and that index is never freed. You always get 7 when allocating destructor_key.value because that index was freed when you unloaded OpenSSL, and so it's the next available one when you load OpenSSL again.

It may not be OpenSSL itself that's calling TlsAlloc and not releasing an index - it may be one of its dependencies.

Have you duplicated this under a debugger, with a breakpoint on TlsAlloc? The earlier messages suggest that you may have, but it's not entirely clear from what you posted. You ought to be able to catch the offending call and get at least a partial traceback.

If you're having trouble tracing it, you could try adding this:

{int i; for (i=8; i<private_drbg; i++) TlsSetValue(i, (LPVOID)-1);}

right after the code that calls TlsAlloc for private_drbg, and seeing what blows up. Not entirely conventional, but it might be revealing.

--
Michael Wojcik
Distinguished Engineer, Micro Focus


Reply | Threaded
Open this post in threaded view
|

Openssl and tls 1.2

Somshekar C Kadam
In reply to this post by Dan Heinz
Hi ,
we are running java 1.6 (older build) and java 1.8(newer build) on the same arm target board with different builds.
On 1.6 java we have Linux Kernel 2.6.35 and with Java 1.8 Linux kernel 4.x. version. so 2 environments and 2 use cases newer and older build. 

we see it takes less than 2 seconds using java 1.6. (older build)
we see it takes 10 seconds using java 1.8 (newer build)

On Java 1.8 did try disabling GCM ciphers and trying still we get the same 10 seconds delay. 

Attaching log of tls handshake for both. Not sure its to do with tls, may be java is causing the delay. 

I am not sure, please provide any pointers or feedback to rootcause it that will help to understand why we get 10seconds delay.

One more info if just use curl on on newer build setup, it works fine within 2 seconds to access the https link. 

Regards
Somshekar C Kadam
9036660538



normal-log-java1.6.txt (21K) Download Attachment
normal-log-java-1.8.txt (22K) Download Attachment
Reply | Threaded
Open this post in threaded view
|

Re: Openssl and tls 1.2

Viktor Dukhovni
Java's TLS library is not OpenSSL.  This is not the right list
for help with TLS in JDK8.  Speculatively, the timeout might be
related to IPv6 being enabled on the board with JDK8 and Linux 4.x.
Perhaps you're trying the IPv6 address, timing out, and then failing
over to IPv4.  Or some middle-box is choking on larger client hellos.
You'll need to analyze a packet capture.

> On Aug 14, 2019, at 1:29 PM, Somshekar C Kadam <[hidden email]> wrote:
>
> Hi ,
> we are running java 1.6 (older build) and java 1.8(newer build) on the same arm target board with different builds.
> On 1.6 java we have Linux Kernel 2.6.35 and with Java 1.8 Linux kernel 4.x. version. so 2 environments and 2 use cases newer and older build.
> while we access https website link https://transparencyreport.google.com/https/overview?hl=en
>
> we see it takes less than 2 seconds using java 1.6. (older build)
> we see it takes 10 seconds using java 1.8 (newer build)
>
> On Java 1.8 did try disabling GCM ciphers and trying still we get the same 10 seconds delay.
>
> Attaching log of tls handshake for both. Not sure its to do with tls, may be java is causing the delay.
>
> I am not sure, please provide any pointers or feedback to rootcause it that will help to understand why we get 10seconds delay.
>
> One more info if just use curl on on newer build setup, it works fine within 2 seconds to access the https link.

Curl may well be using OpenSSL, but that's not where you're seeing
a problem, so the help you'll get on this list is rather limited.
Try wireshark or similar.

--
        Viktor.

Reply | Threaded
Open this post in threaded view
|

Re: Openssl and tls 1.2

Somshekar C Kadam
Thanks Viktor for clarification 

Regards
Somshekar C Kadam
9036660538


On Wed, Aug 14, 2019 at 9:43 AM Viktor Dukhovni <[hidden email]> wrote:
Java's TLS library is not OpenSSL.  This is not the right list
for help with TLS in JDK8.  Speculatively, the timeout might be
related to IPv6 being enabled on the board with JDK8 and Linux 4.x.
Perhaps you're trying the IPv6 address, timing out, and then failing
over to IPv4.  Or some middle-box is choking on larger client hellos.
You'll need to analyze a packet capture.

> On Aug 14, 2019, at 1:29 PM, Somshekar C Kadam <[hidden email]> wrote:
>
> Hi ,
> we are running java 1.6 (older build) and java 1.8(newer build) on the same arm target board with different builds.
> On 1.6 java we have Linux Kernel 2.6.35 and with Java 1.8 Linux kernel 4.x. version. so 2 environments and 2 use cases newer and older build.
> while we access https website link https://transparencyreport.google.com/https/overview?hl=en
>
> we see it takes less than 2 seconds using java 1.6. (older build)
> we see it takes 10 seconds using java 1.8 (newer build)
>
> On Java 1.8 did try disabling GCM ciphers and trying still we get the same 10 seconds delay.
>
> Attaching log of tls handshake for both. Not sure its to do with tls, may be java is causing the delay.
>
> I am not sure, please provide any pointers or feedback to rootcause it that will help to understand why we get 10seconds delay.
>
> One more info if just use curl on on newer build setup, it works fine within 2 seconds to access the https link.

Curl may well be using OpenSSL, but that's not where you're seeing
a problem, so the help you'll get on this list is rather limited.
Try wireshark or similar.

--
        Viktor.

Reply | Threaded
Open this post in threaded view
|

RE: OPENSSL_init_crypto with OPENSSL_INIT_NO_ATEXIT issue

Dan Heinz
In reply to this post by Michael Wojcik
>The output certainly suggests something is calling TlsAlloc between the call made for destructor_key.value and the one for private_drbg, and that index is never freed. You always get 7 when allocating destructor_key.value because that >index was freed when you unloaded OpenSSL, and so it's the next available one when you load OpenSSL again.
>
>It may not be OpenSSL itself that's calling TlsAlloc and not releasing an index - it may be one of its dependencies.
>
>Have you duplicated this under a debugger, with a breakpoint on TlsAlloc? The earlier messages suggest that you may have, but it's not entirely clear from what you posted. You ought to be able to catch the offending call and get at >least a partial traceback.
>
>If you're having trouble tracing it, you could try adding this:
>
>{int i; for (i=8; i<private_drbg; i++) TlsSetValue(i, (LPVOID)-1);}
>
>right after the code that calls TlsAlloc for private_drbg, and seeing what blows up. Not entirely conventional, but it might be revealing.

After some further debugging, it appears there is an unknown TSAlloc called which returned index 8.  OpenSSL was allocating index 7, then the index 8 was allocated somewhere outside the OpenSSL library, and finally OpenSSL allocated indexes 9, 10, and 11.  I was able to call TlsFree(8) in my DLLMain when my DLL is unloaded and I didn't have any more issues.  Obviously, that is not a fix and I was further able to track down at least where the allocation was happening.  It is actually in a call to libxml2 and does not appear to be related to OpenSSL.  Now I just need to figure out why libxml2 is not freeing it.

Thank you Matt and Michael for you help.  :-)


Reply | Threaded
Open this post in threaded view
|

RE: OPENSSL_init_crypto with OPENSSL_INIT_NO_ATEXIT issue

Michael Wojcik
> From: openssl-users [mailto:[hidden email]] On Behalf Of
> Dan Heinz
> Sent: Thursday, August 15, 2019 13:19
> blows up. Not entirely conventional, but it might be revealing.
>
> It is actually in a call to libxml2 and does not
> appear to be related to OpenSSL.  Now I just need to figure out why libxml2
> is not freeing it.

Some quick online searching (I don't have the source for libxml2 handy on this machine) suggests it may be the globalkey variable, allocated in xmlOnceInit. Some old messages from the libxml2 mailing list suggest it ought to be TlsFree'd in the DLL_PROCESS_DETACH case of libxml2's DllMain.

If I were investigating this, I'd grab the libxml2 sources and build it for debug, then debug the process at fault with breakpoints set appropriately.

--
Michael Wojcik
Distinguished Engineer, Micro Focus