On 18/02/16 00:13, Michel wrote:
> Hi Matt, 
> 
> Thanks for the suggestion.
> 
> This is what was printed to stderr :
> OPENSSL_INIT: ossl_init_base: Setting up stop handlers
> OPENSSL_INIT: ossl_init_add_all_ciphers: openssl_add_all_ciphers_internal()
> OPENSSL_INIT: ossl_init_add_all_digests: openssl_add_all_digests_internal()
> OPENSSL_INIT: ossl_init_ssl_base: Adding SSL ciphers and digests
> OPENSSL_INIT: ossl_init_ssl_base: SSL_COMP_get_compression_methods()
> OPENSSL_INIT: ossl_init_ssl_base: SSL_add_ssl_module()
> OPENSSL_INIT: ossl_init_load_ssl_strings: ERR_load_SSL_strings()
> OPENSSL_INIT: ossl_init_async: async_init()
> OPENSSL_INIT: ossl_init_load_crypto_strings:
> err_load_crypto_strings_intern()
> OPENSSL_INIT: ossl_init_thread_start: marking thread for err_state
> OPENSSL_INIT: ossl_init_thread_start: marking thread for err_state
> OPENSSL_INIT: ossl_init_thread_stop: ERR_remove_thread_state(NULL)
> OPENSSL_INIT: ssl_library_stop: SSL_COMP_free_compression_methods()
> OPENSSL_INIT: ssl_library_stop: ERR_free_strings()
> OPENSSL_INIT: OPENSSL_cleanup: ERR_free_strings()
> OPENSSL_INIT: OPENSSL_INIT_library_stop: CRYPTO_cleanup_all_ex_data()
> OPENSSL_INIT: OPENSSL_INIT_library_stop: EVP_cleanup()
> OPENSSL_INIT: OPENSSL_INIT_library_stop: CONF_modules_free()
> OPENSSL_INIT: OPENSSL_INIT_library_stop: RAND_cleanup()
> 
> Shouldn't there be at least another line with ERR_remove_thread_state() (one
> for each thread) ?

Yes. I can see we have two of these:

OPENSSL_INIT: ossl_init_thread_start: marking thread for err_state
OPENSSL_INIT: ossl_init_thread_start: marking thread for err_state

Which means that the init code has spotted that there are two threads
running and has initialised the error system for both of them.

But we only get one of these:

OPENSSL_INIT: ossl_init_thread_stop: ERR_remove_thread_state(NULL)

Which means only one of the two threads has subsequently been de-inited.
That's very odd.

I have two possible theories:
1) OPENSSL_thread_stop() is not actually getting called as we think it is.
Or
2) The Thread Local Structure that keeps track of what things need
cleanup is not being obtained correctly for some reason during the
thread stop...so we have "forgotten" that we initialised the error system.

To try and help narrow down which of these possibilities it is I have
created a patch (attached) which bumps up the logging significantly.
Please can you apply it, rerun your code (with OPENSSL_INIT_DEBUG
defined still) and post the output here?

Thanks

Matt


> This test program launch 1 server thread and 1 client thread.
> Both of them have OPENSSL_thread_stop() in their [pre-]exit member function.
> 
> Michel.
> 
> -----Message d'origine-----
> De : openssl-dev [mailto:openssl-dev-boun...@openssl.org] De la part de Matt
> Caswell
> Envoyé : mercredi 17 février 2016 17:23
> À : openssl-dev@openssl.org
> Objet : Re: [openssl-dev] memory leaks detected using libSSL 1.1
> 
>> Am I missing anything else ?
> 
> That should be sufficient (although the OPENSSL_cleanup() should not be
> required).
> 
> You could try compiling OpenSSL with OPENSSL_INIT_DEBUG defined, e.g.
> 
> perl Configure your-platform-here -DOPENSSL_INIT_DEBUG
> 
> This should print out some debugging information to stderr every time the
> init functions attempt to do something interesting. In particular when you
> call OPENSSL_thread_stop() you should see the following printed
> out:
> 
> OPENSSL_INIT: ossl_init_thread_stop: ERR_remove_thread_state(NULL)
> 
> Matt
> 
From 6679ef43680a63aac9430bfbc6d49014d5675948 Mon Sep 17 00:00:00 2001
From: Matt Caswell <m...@openssl.org>
Date: Thu, 18 Feb 2016 09:32:42 +0000
Subject: [PATCH] Add some additional logging to thread stop code

---
 crypto/init.c | 77 ++++++++++++++++++++++++++++++++++++++++++++++++++++++-----
 1 file changed, 71 insertions(+), 6 deletions(-)

diff --git a/crypto/init.c b/crypto/init.c
index 25e3dc7..c4d5c81 100644
--- a/crypto/init.c
+++ b/crypto/init.c
@@ -194,14 +194,36 @@ static struct thread_local_inits_st *ossl_init_get_thread_local(int alloc)
 {
     struct thread_local_inits_st *local = TlsGetValue(threadstopkey);
 
+#ifdef OPENSSL_INIT_DEBUG
+    DWORD threadid;
+    threadid = GetCurrentThreadId();
+    fprintf(stderr, "OPENSSL_INIT: ossl_init_get_thread_local: "
+                    "Starting: Local value is %s, alloc is %d (%ld)\n",
+                    ((local == NULL)?"NULL":"NOT NULL"), alloc, threadid);
+#endif
+
     if (local == NULL && alloc) {
+#ifdef OPENSSL_INIT_DEBUG
+        fprintf(stderr, "OPENSSL_INIT: ossl_init_get_thread_local: "
+                        "Allocating a new local structure (%ld)\n", threadid);
+#endif
         local = OPENSSL_zalloc(sizeof *local);
         TlsSetValue(threadstopkey, local);
     }
     if (!alloc) {
+#ifdef OPENSSL_INIT_DEBUG
+        fprintf(stderr, "OPENSSL_INIT: ossl_init_get_thread_local: "
+                        "Clearing Thread Locals (%ld)\n", threadid);
+#endif
         TlsSetValue(threadstopkey, NULL);
     }
 
+#ifdef OPENSSL_INIT_DEBUG
+    fprintf(stderr, "OPENSSL_INIT: ossl_init_get_thread_local: "
+                    "Ending: Local value is %s, alloc is %d (%ld)\n",
+                    ((local == NULL)?"NULL":"NOT NULL"), alloc, threadid);
+#endif
+
     return local;
 }
 
@@ -477,14 +499,26 @@ static void ossl_init_zlib(void)
 
 static void ossl_init_thread_stop(struct thread_local_inits_st *locals)
 {
+#ifdef OPENSSL_INIT_DEBUG
+    DWORD threadid;
+    threadid = GetCurrentThreadId();
+    fprintf(stderr, "OPENSSL_INIT: ossl_init_thread_stop: "
+                        "starting (%ld)\n", threadid);
+#endif
+
     /* Can't do much about this */
-    if (locals == NULL)
+    if (locals == NULL) {
+#ifdef OPENSSL_INIT_DEBUG
+        fprintf(stderr, "OPENSSL_INIT: ossl_init_thread_stop: "
+                        "locals are NULL returning (%ld)\n", threadid);
+#endif
         return;
+    }
 
     if (locals->async) {
 #ifdef OPENSSL_INIT_DEBUG
         fprintf(stderr, "OPENSSL_INIT: ossl_init_thread_stop: "
-                        "ASYNC_cleanup_thread()\n");
+                        "ASYNC_cleanup_thread() (%ld)\n", threadid);
 #endif
         ASYNC_cleanup_thread();
     }
@@ -492,32 +526,58 @@ static void ossl_init_thread_stop(struct thread_local_inits_st *locals)
     if (locals->err_state) {
 #ifdef OPENSSL_INIT_DEBUG
         fprintf(stderr, "OPENSSL_INIT: ossl_init_thread_stop: "
-                        "ERR_remove_thread_state(NULL)\n");
+                        "ERR_remove_thread_state(NULL) (%ld)\n", threadid);
 #endif
         ERR_remove_thread_state(NULL);
     }
 
     OPENSSL_free(locals);
     ossl_init_thread_stop_cleanup();
+#ifdef OPENSSL_INIT_DEBUG
+        fprintf(stderr, "OPENSSL_INIT: ossl_init_thread_stop: "
+                        "end (%ld)\n", threadid);
+#endif
 }
 
 void OPENSSL_thread_stop(void)
 {
+#ifdef OPENSSL_INIT_DEBUG
+    DWORD threadid;
+    threadid = GetCurrentThreadId();
+    fprintf(stderr, "OPENSSL_INIT: OPENSSL_thread_stop: "
+                        "starting (%ld)\n", threadid);
+#endif
     ossl_init_thread_stop(
         (struct thread_local_inits_st *)ossl_init_get_thread_local(0));
+#ifdef OPENSSL_INIT_DEBUG
+    fprintf(stderr, "OPENSSL_INIT: OPENSSL_thread_stop: "
+                        "ending (%ld)\n", threadid);
+#endif
 }
 
 int ossl_init_thread_start(uint64_t opts)
 {
     struct thread_local_inits_st *locals = ossl_init_get_thread_local(1);
 
-    if (locals == NULL)
+#ifdef OPENSSL_INIT_DEBUG
+    DWORD threadid;
+    threadid = GetCurrentThreadId();
+    fprintf(stderr, "OPENSSL_INIT: ossl_init_thread_start: "
+                    "Starting (%ld)\n", threadid);
+#endif
+
+    if (locals == NULL) {
+#ifdef OPENSSL_INIT_DEBUG
+        fprintf(stderr, "OPENSSL_INIT: ossl_init_thread_start: "
+                        "locals are NULL returning (%ld)\n", threadid);
+#endif
         return 0;
+    }
 
     if (opts & OPENSSL_INIT_THREAD_ASYNC) {
 #ifdef OPENSSL_INIT_DEBUG
         fprintf(stderr, "OPENSSL_INIT: ossl_init_thread_start: "
-                        "marking thread for async\n");
+                        "marking thread for async (%ld)\n", threadid);
 #endif
         locals->async = 1;
     }
@@ -525,11 +585,16 @@ int ossl_init_thread_start(uint64_t opts)
     if (opts & OPENSSL_INIT_THREAD_ERR_STATE) {
 #ifdef OPENSSL_INIT_DEBUG
         fprintf(stderr, "OPENSSL_INIT: ossl_init_thread_start: "
-                        "marking thread for err_state\n");
+                        "marking thread for err_state (%ld)\n", threadid);
 #endif
         locals->err_state = 1;
     }
 
+#ifdef OPENSSL_INIT_DEBUG
+    fprintf(stderr, "OPENSSL_INIT: ossl_init_thread_start: "
+                    "End (%ld)\n", threadid);
+#endif
+
     return 1;
 }
 
-- 
2.5.0

-- 
openssl-dev mailing list
To unsubscribe: https://mta.openssl.org/mailman/listinfo/openssl-dev

Reply via email to