Merge pull request #701 from JacobBarthelmeh/mutex

better compatibility with printing errors to a file

src/ssl.c

@@ -2734,6 +2734,12 @@ void wolfSSL_ERR_print_errors_fp(FILE* fp, int err)
     fprintf(fp, "%s", data);
 }
 
+#if defined(OPENSSL_EXTRA) || defined(DEBUG_WOLFSSL_VERBOSE)
+void wolfSSL_ERR_dump_errors_fp(FILE* fp)
+{
+    wc_ERR_print_errors_fp(fp);
+}
+#endif
 #endif
 
 
@@ -8307,6 +8313,11 @@ int wolfSSL_Cleanup(void)
     wc_ecc_fp_free();
 #endif
 
+    if (wolfCrypt_Cleanup() != 0) {
+        WOLFSSL_MSG("Error with wolfCrypt_Cleanup call");
+        ret = WC_CLEANUP_E;
+    }
+
     return ret;
 }
 
@@ -20492,13 +20503,15 @@ unsigned long wolfSSL_ERR_peek_last_error_line(const char **file, int *line)
     (void)line;
     (void)file;
 #if defined(DEBUG_WOLFSSL)
-    if (line != NULL) {
+    {
-        *line = (int)wc_last_error_line;
+        int ret;
+
+        if ((ret = wc_PeekErrorNode(-1, file, NULL, line)) < 0) {
+            WOLFSSL_MSG("Issue peeking at error node in queue");
+            return 0;
         }
-    if (file != NULL) {
+        return (unsigned long)ret;
-        *file = (char*)wc_last_error_file;
     }
-    return wc_last_error;
 #else
     return (unsigned long)(0 - NOT_COMPILED_IN);
 #endif

tests/api.c

@@ -2699,6 +2699,11 @@ static void test_wolfSSL_ERR_peek_last_error_line(void)
 #endif
 
     printf(resultFmt, passed);
+
+    printf("\nTesting error print out\n");
+    ERR_print_errors_fp(stdout);
+    printf("Done testing print out\n\n");
+    fflush(stdout);
     #endif /* defined(OPENSSL_EXTRA) && !defined(NO_CERTS) && \
              !defined(NO_FILESYSTEM) && !defined(DEBUG_WOLFSSL) */
 }

wolfcrypt/benchmark/benchmark.c

@@ -499,6 +499,10 @@ int benchmark_test(void *args)
     }
 #endif
 
+    if (wolfCrypt_Cleanup() != 0) {
+        printf("error with wolfCrypt_Cleanup\n");
+    }
+
 #if defined(USE_WOLFSSL_MEMORY) && defined(WOLFSSL_TRACK_MEMORY)
     ShowMemoryTracker();
 #endif

wolfcrypt/src/error.c

@@ -410,6 +410,9 @@ const char* wc_GetErrorString(int error)
     case BAD_KEYWRAP_IV_E:
         return "Decrypted AES key wrap IV does not match expected";
 
+    case WC_CLEANUP_E:
+        return "wolfcrypt cleanup failed";
+
     default:
         return "unknown error number";
 

wolfcrypt/src/logging.c

@@ -41,13 +41,27 @@
     } 
 #endif
 
+#if defined(OPENSSL_EXTRA) || defined(DEBUG_WOLFSSL_VERBOSE)
+static wolfSSL_Mutex debug_mutex; /* mutex for access to debug structure */
+
+/* accessing any node from the queue should be wrapped in a lock of
+ * debug_mutex */
+static void* wc_error_heap;
+struct wc_error_queue {
+    void*  heap; /* the heap hint used with nodes creation */
+    struct wc_error_queue* next;
+    char   error[WOLFSSL_MAX_ERROR_SZ];
+    char   file[WOLFSSL_MAX_ERROR_SZ];
+    int    value;
+    int    line;
+};
+volatile struct wc_error_queue* wc_errors;
+static struct wc_error_queue* wc_last_node;
+/* pointer to last node in queue to make insertion O(1) */
+#endif
+
 
 #ifdef DEBUG_WOLFSSL
-    #if defined(OPENSSL_EXTRA) || defined(DEBUG_WOLFSSL_VERBOSE)
-    volatile char          wc_last_error_file[80];
-    volatile unsigned long wc_last_error_line;
-    volatile unsigned long wc_last_error;
-    #endif
 
 /* Set these to default values initially. */
 static wolfSSL_Logging_cb log_function = 0;
@@ -220,15 +234,23 @@ void WOLFSSL_ERROR(int error)
         #if defined(OPENSSL_EXTRA) || defined(DEBUG_WOLFSSL_VERBOSE)
             (void)usrCtx; /* a user ctx for future flexibility */
             (void)func;
-            if (error < 0) error = error - (2*error); /* get absolute value */
+
-            wc_last_error      = (unsigned long)error;
+            if (wc_LockMutex(&debug_mutex) != 0) {
-            wc_last_error_line = (unsigned long)line;
+                WOLFSSL_MSG("Lock debug mutex failed");
-            XMEMSET((char*)wc_last_error_file, 0, sizeof(file));
+                sprintf(buffer, "wolfSSL error occurred, error = %d", error);
-            if (XSTRLEN(file) < sizeof(file)) {
-	            XSTRNCPY((char*)wc_last_error_file, file, XSTRLEN(file));
             }
+            else {
+                if (error < 0) error = error - (2*error); /*get absolute value*/
                 sprintf(buffer, "wolfSSL error occurred, error = %d line:%d file:%s",
                     error, line, file);
+                if (wc_AddErrorNode(error, line, buffer, (char*)file) != 0) {
+                    WOLFSSL_MSG("Error creating logging node");
+                    /* with void function there is no return here, continue on
+                     * to unlock mutex and log what buffer was created. */
+                }
+
+                wc_UnLockMutex(&debug_mutex);
+            }
         #else
             sprintf(buffer, "wolfSSL error occurred, error = %d", error);
         #endif
@@ -237,3 +259,223 @@ void WOLFSSL_ERROR(int error)
 }
 
 #endif  /* DEBUG_WOLFSSL */
+
+#if defined(OPENSSL_EXTRA) || defined(DEBUG_WOLFSSL_VERBOSE)
+/* Internal function that is called by wolfCrypt_Init() */
+int wc_LoggingInit(void)
+{
+    if (wc_InitMutex(&debug_mutex) != 0) {
+        WOLFSSL_MSG("Bad Init Mutex");
+        return BAD_MUTEX_E;
+    }
+    wc_errors          = NULL;
+    wc_last_node       = NULL;
+
+    return 0;
+}
+
+
+/* internal function that is called by wolfCrypt_Cleanup */
+int wc_LoggingCleanup(void)
+{
+    if (wc_LockMutex(&debug_mutex) != 0) {
+        WOLFSSL_MSG("Lock debug mutex failed");
+        return BAD_MUTEX_E;
+    }
+
+    /* free all nodes from error queue */
+    {
+        struct wc_error_queue* current;
+        struct wc_error_queue* next;
+
+        current = (struct wc_error_queue*)wc_errors;
+        while (current != NULL) {
+            next = current->next;
+            XFREE(current, current->heap, DYNAMIC_TYPE_LOG);
+            current = next;
+        }
+    }
+
+    wc_UnLockMutex(&debug_mutex);
+    if (wc_FreeMutex(&debug_mutex) != 0) {
+        WOLFSSL_MSG("Bad Mutex free");
+        return BAD_MUTEX_E;
+    }
+    return 0;
+}
+
+
+#ifdef DEBUG_WOLFSSL
+/* peek at an error node
+ *
+ * index : if -1 then the most recent node is looked at, otherwise search
+ *         through queue for node at the given index
+ * file  : pointer to internal file string
+ * reason : pointer to internal error reason
+ * line  : line number that error happened at
+ *
+ * Returns a negative value in error case, on success returns the nodes error
+ * value which is positve (absolute value)
+ */
+int wc_PeekErrorNode(int index, const char **file, const char **reason,
+        int *line)
+{
+    struct wc_error_queue* err;
+
+    if (wc_LockMutex(&debug_mutex) != 0) {
+        WOLFSSL_MSG("Lock debug mutex failed");
+        return BAD_MUTEX_E;
+    }
+
+    if (index < 0) {
+        err = wc_last_node;
+        if (err == NULL) {
+            WOLFSSL_MSG("No Errors in queue");
+            wc_UnLockMutex(&debug_mutex);
+            return BAD_STATE_E;
+        }
+    }
+    else {
+        int i;
+
+        err = (struct wc_error_queue*)wc_errors;
+        for (i = 0; i < index; i++) {
+            if (err == NULL) {
+                WOLFSSL_MSG("Error node not found. Bad index?");
+                wc_UnLockMutex(&debug_mutex);
+                return BAD_FUNC_ARG;
+            }
+            err = err->next;
+        }
+    }
+
+    if (file != NULL) {
+        *file = err->file;
+    }
+
+    if (reason != NULL) {
+        *reason = err->error;
+    }
+
+    if (line != NULL) {
+        *line = err->line;
+    }
+
+    wc_UnLockMutex(&debug_mutex);
+
+    return err->value;
+}
+
+
+/* create new error node and add it to the queue
+ * buffers are assumed to be of size WOLFSSL_MAX_ERROR_SZ for this internal
+ * function. debug_mutex should be locked before a call to this function. */
+int wc_AddErrorNode(int error, int line, char* buf, char* file)
+{
+
+    struct wc_error_queue* err;
+
+    err = (struct wc_error_queue*)XMALLOC(
+            sizeof(struct wc_error_queue), wc_error_heap, DYNAMIC_TYPE_LOG);
+    if (err == NULL) {
+        WOLFSSL_MSG("Unable to create error node for log");
+        return MEMORY_E;
+    }
+    else {
+        int sz;
+
+        XMEMSET(err, 0, sizeof(struct wc_error_queue));
+        err->heap = wc_error_heap;
+        sz = (int)XSTRLEN(buf);
+        if (sz > WOLFSSL_MAX_ERROR_SZ - 1) {
+            sz = WOLFSSL_MAX_ERROR_SZ - 1;
+        }
+        if (sz > 0) {
+            XMEMCPY(err->error, buf, sz);
+        }
+
+        sz = (int)XSTRLEN(file);
+        if (sz > WOLFSSL_MAX_ERROR_SZ - 1) {
+            sz = WOLFSSL_MAX_ERROR_SZ - 1;
+        }
+        if (sz > 0) {
+            XMEMCPY(err->file, file, sz);
+        }
+
+        err->value = error;
+        err->line  = line;
+
+        /* make sure is terminated */
+        err->error[WOLFSSL_MAX_ERROR_SZ - 1] = '\0';
+        err->file[WOLFSSL_MAX_ERROR_SZ - 1]  = '\0';
+
+
+        /* since is queue place new node at last of the list */
+        if (wc_last_node == NULL) {
+            /* case of first node added to queue */
+            if (wc_errors != NULL) {
+                /* check for unexpected case before over writing wc_errors */
+                WOLFSSL_MSG("ERROR in adding new node to logging queue!!\n");
+            }
+            else {
+                wc_errors    = err;
+                wc_last_node = err;
+            }
+        }
+        else {
+            wc_last_node->next = err;
+            wc_last_node = err;
+        }
+    }
+
+    return 0;
+}
+#endif /* DEBUG_WOLFSSL */
+
+
+int wc_SetLoggingHeap(void* h)
+{
+    if (wc_LockMutex(&debug_mutex) != 0) {
+        WOLFSSL_MSG("Lock debug mutex failed");
+        return BAD_MUTEX_E;
+    }
+    wc_error_heap = h;
+    wc_UnLockMutex(&debug_mutex);
+    return 0;
+}
+
+#if !defined(NO_FILESYSTEM) && !defined(NO_STDIO_FILESYSTEM)
+/* empties out the error queue into the file */
+void wc_ERR_print_errors_fp(FILE* fp)
+{
+    WOLFSSL_ENTER("wc_ERR_print_errors_fp");
+
+    if (wc_LockMutex(&debug_mutex) != 0) {
+        WOLFSSL_MSG("Lock debug mutex failed");
+    }
+    else {
+        /* free all nodes from error queue and print them to file */
+        {
+            struct wc_error_queue* current;
+            struct wc_error_queue* next;
+
+            current = (struct wc_error_queue*)wc_errors;
+            while (current != NULL) {
+                next = current->next;
+                fprintf(fp, "%s\n", current->error);
+                XFREE(current, current->heap, DYNAMIC_TYPE_LOG);
+                current = next;
+            }
+
+            /* set global pointers to match having been freed */
+            wc_errors    = NULL;
+            wc_last_node = NULL;
+        }
+
+        wc_UnLockMutex(&debug_mutex);
+    }
+}
+#endif /* !defined(NO_FILESYSTEM) && !defined(NO_STDIO_FILESYSTEM) */
+
+#endif /* defined(OPENSSL_EXTRA) || defined(DEBUG_WOLFSSL_VERBOSE) */
+

wolfcrypt/src/wc_port.c

@@ -97,12 +97,35 @@ int wolfCrypt_Init(void)
             wolfSSL_EVP_init();
     #endif
 
+    #if defined(OPENSSL_EXTRA) || defined(DEBUG_WOLFSSL_VERBOSE)
+        if ((ret = wc_LoggingInit()) != 0) {
+            WOLFSSL_MSG("Error creating logging mutex");
+            return ret;
+        }
+    #endif
+
         initRefCount = 1;
     }
 
     return ret;
 }
 
+
+/* return success value is the same as wolfCrypt_Init */
+int wolfCrypt_Cleanup(void)
+{
+    int ret = 0;
+
+    WOLFSSL_ENTER("wolfCrypt_Cleanup");
+
+    #if defined(OPENSSL_EXTRA) || defined(DEBUG_WOLFSSL_VERBOSE)
+        ret = wc_LoggingCleanup();
+    #endif
+
+    return ret;
+}
+
+
 wolfSSL_Mutex* wc_InitAndAllocMutex()
 {
     wolfSSL_Mutex* m = (wolfSSL_Mutex*) XMALLOC(sizeof(wolfSSL_Mutex), NULL,

wolfcrypt/test/test.c

@@ -101,6 +101,9 @@
 #ifdef WOLFSSL_ASYNC_CRYPT
     #include <wolfssl/wolfcrypt/async.h>
 #endif
+#if defined(OPENSSL_EXTRA) || defined(DEBUG_WOLFSSL_VERBOSE)
+    #include <wolfssl/wolfcrypt/logging.h>
+#endif
 
 #ifdef _MSC_VER
     /* 4996 warning to use MS extensions e.g., strcpy_s instead of strncpy */
@@ -326,6 +329,10 @@ int wolfcrypt_test(void* args)
 
     wolfCrypt_Init();
 
+#if defined(OPENSSL_EXTRA) || defined(DEBUG_WOLFSSL_VERBOSE)
+    wc_SetLoggingHeap(HEAP_HINT);
+#endif
+
 #ifdef HAVE_FIPS
     wolfCrypt_SetCb_fips(myFipsCb);
 #endif
@@ -723,6 +730,10 @@ int wolfcrypt_test(void* args)
         printf( "PKCS7encrypted test passed!\n");
 #endif
 
+    if ((ret = wolfCrypt_Cleanup())!= 0) {
+        return err_sys("Error with wolfCrypt_Cleanup!\n", ret);
+    }
+
 #if defined(USE_WOLFSSL_MEMORY) && defined(WOLFSSL_TRACK_MEMORY)
     ShowMemoryTracker();
 #endif

wolfssl/openssl/ssl.h

@@ -106,8 +106,7 @@ typedef WOLFSSL_X509_STORE_CTX X509_STORE_CTX;
 #define SSL_get_shared_ciphers(ctx,buf,len) \
                                 strncpy(buf, "Not Implemented, SSLv2 only", len)
 
-/* @TODO */
+#define ERR_print_errors_fp(file) wolfSSL_ERR_dump_errors_fp((file))
-#define ERR_print_errors_fp(file) wolfSSL_ERR_print_errors_fp((file))
 
 /* at the moment only returns ok */
 #define SSL_get_verify_result         wolfSSL_get_verify_result

wolfssl/ssl.h

@@ -891,6 +891,9 @@ enum {
    since not using thread storage error queue */
 #include <stdio.h>
 WOLFSSL_API void  wolfSSL_ERR_print_errors_fp(FILE*, int err);
+#if defined(OPENSSL_EXTRA) || defined(DEBUG_WOLFSSL_VERBOSE)
+WOLFSSL_API void wolfSSL_ERR_dump_errors_fp(FILE* fp);
+#endif
 #endif
 
 enum { /* ssl Constants */

wolfssl/wolfcrypt/error-crypt.h

@@ -181,6 +181,7 @@ enum {
 
     BAD_KEYWRAP_ALG_E   = -239,
     BAD_KEYWRAP_IV_E    = -240,  /* Decrypted AES key wrap IV incorrect */
+    WC_CLEANUP_E        = -241,  /* wolfcrypt cleanup failed */
 
     MIN_CODE_E          = -300   /* errors -101 - -299 */
 

wolfssl/wolfcrypt/logging.h

@@ -46,6 +46,19 @@ typedef void (*wolfSSL_Logging_cb)(const int logLevel,
 
 WOLFSSL_API int wolfSSL_SetLoggingCb(wolfSSL_Logging_cb log_function);
 
+#if defined(OPENSSL_EXTRA) || defined(DEBUG_WOLFSSL_VERBOSE)
+    WOLFSSL_LOCAL int wc_LoggingInit(void);
+    WOLFSSL_LOCAL int wc_LoggingCleanup(void);
+    WOLFSSL_LOCAL int wc_AddErrorNode(int error, int line, char* buf,
+            char* file);
+    WOLFSSL_LOCAL int wc_PeekErrorNode(int index, const char **file,
+            const char **reason, int *line);
+    WOLFSSL_API   int wc_SetLoggingHeap(void* h);
+    #if !defined(NO_FILESYSTEM) && !defined(NO_STDIO_FILESYSTEM)
+        WOLFSSL_API   void wc_ERR_print_errors_fp(FILE* fp);
+    #endif
+#endif /* defined(OPENSSL_EXTRA) || defined(DEBUG_WOLFSSL_VERBOSE) */
+
 #ifdef DEBUG_WOLFSSL
     /* a is prepended to m and b is appended, creating a log msg a + m + b */
     #define WOLFSSL_LOG_CAT(a, m, b) #a " " m " "  #b
@@ -56,11 +69,6 @@ WOLFSSL_API int wolfSSL_SetLoggingCb(wolfSSL_Logging_cb log_function);
         WOLFSSL_MSG(WOLFSSL_LOG_CAT(wolfSSL Stub, m, not implemented))
 
 #if defined(OPENSSL_EXTRA) || defined(DEBUG_WOLFSSL_VERBOSE)
-    /* make these variables global and declare them in logging.c */
-    extern volatile char          wc_last_error_file[80];
-    extern volatile unsigned long wc_last_error_line;
-    extern volatile unsigned long wc_last_error;
-
     void WOLFSSL_ERROR_LINE(int err, const char* func, unsigned int line,
             const char* file, void* ctx);
     #define WOLFSSL_ERROR(x) WOLFSSL_ERROR_LINE((x), __func__, __LINE__, __FILE__,NULL)

wolfssl/wolfcrypt/types.h

@@ -340,7 +340,8 @@
         DYNAMIC_TYPE_PKCS         = 58,
         DYNAMIC_TYPE_MUTEX        = 59,
         DYNAMIC_TYPE_PKCS7        = 60,
-        DYNAMIC_TYPE_ASN1         = 61
+        DYNAMIC_TYPE_ASN1         = 61,
+        DYNAMIC_TYPE_LOG          = 62
 	};
 
 	/* max error buffer string size */

wolfssl/wolfcrypt/wc_port.h

@@ -186,6 +186,7 @@ WOLFSSL_API int wc_UnLockMutex(wolfSSL_Mutex*);
 
 /* main crypto initialization function */
 WOLFSSL_API int wolfCrypt_Init(void);
+WOLFSSL_API int wolfCrypt_Cleanup(void);
 
 /* filesystem abstraction layer, used by ssl.c */
 #ifndef NO_FILESYSTEM