Merge pull request #1294 from dgarske/log_improve

Improvements to logging
This commit is contained in:
toddouska
2018-01-04 10:15:22 -08:00
committed by GitHub
4 changed files with 130 additions and 132 deletions

View File

@@ -32,15 +32,6 @@
#include <wolfssl/wolfcrypt/error-crypt.h> #include <wolfssl/wolfcrypt/error-crypt.h>
#ifdef __cplusplus
extern "C" {
#endif
WOLFSSL_API int wolfSSL_Debugging_ON(void);
WOLFSSL_API void wolfSSL_Debugging_OFF(void);
#ifdef __cplusplus
}
#endif
#if defined(OPENSSL_EXTRA) || defined(DEBUG_WOLFSSL_VERBOSE) #if defined(OPENSSL_EXTRA) || defined(DEBUG_WOLFSSL_VERBOSE)
static wolfSSL_Mutex debug_mutex; /* mutex for access to debug structure */ static wolfSSL_Mutex debug_mutex; /* mutex for access to debug structure */
@@ -63,7 +54,7 @@ static struct wc_error_queue* wc_last_node;
#if defined(DEBUG_WOLFSSL) #ifdef DEBUG_WOLFSSL
/* Set these to default values initially. */ /* Set these to default values initially. */
static wolfSSL_Logging_cb log_function = NULL; static wolfSSL_Logging_cb log_function = NULL;
@@ -72,17 +63,12 @@ static int loggingEnabled = 0;
#endif /* DEBUG_WOLFSSL */ #endif /* DEBUG_WOLFSSL */
/* allow this to be set to NULL, so logs can be redirected to default output */
int wolfSSL_SetLoggingCb(wolfSSL_Logging_cb f) int wolfSSL_SetLoggingCb(wolfSSL_Logging_cb f)
{ {
#ifdef DEBUG_WOLFSSL #ifdef DEBUG_WOLFSSL
int res = 0; log_function = f;
return 0;
if (f)
log_function = f;
else
res = BAD_FUNC_ARG;
return res;
#else #else
(void)f; (void)f;
return NOT_COMPILED_IN; return NOT_COMPILED_IN;
@@ -122,6 +108,8 @@ void wolfSSL_Debugging_OFF(void)
int sprintf(char* buf, const char *fmt, ...); int sprintf(char* buf, const char *fmt, ...);
#elif defined(MICRIUM) #elif defined(MICRIUM)
#include <bsp_ser.h> #include <bsp_ser.h>
#elif defined(WOLFSSL_USER_LOG)
/* user includes their own headers */
#else #else
#include <stdio.h> /* for default printf stuff */ #include <stdio.h> /* for default printf stuff */
#endif #endif
@@ -135,30 +123,32 @@ static void wolfssl_log(const int logLevel, const char *const logMessage)
if (log_function) if (log_function)
log_function(logLevel, logMessage); log_function(logLevel, logMessage);
else { else {
if (loggingEnabled) { #if defined(WOLFSSL_USER_LOG)
#if defined(THREADX) && !defined(THREADX_NO_DC_PRINTF) WOLFSSL_USER_LOG(logMessage);
dc_log_printf("%s\n", logMessage);
#elif defined(MICRIUM)
BSP_Ser_Printf("%s\r\n", logMessage);
#elif defined(WOLFSSL_MDK_ARM)
fflush(stdout) ;
printf("%s\n", logMessage);
fflush(stdout) ;
#elif defined(WOLFSSL_LOG_PRINTF) #elif defined(WOLFSSL_LOG_PRINTF)
printf("%s\n", logMessage); printf("%s\n", logMessage);
#elif defined(THREADX) && !defined(THREADX_NO_DC_PRINTF)
dc_log_printf("%s\n", logMessage);
#elif defined(MICRIUM)
BSP_Ser_Printf("%s\r\n", logMessage);
#elif defined(WOLFSSL_MDK_ARM)
fflush(stdout) ;
printf("%s\n", logMessage);
fflush(stdout) ;
#elif defined(WOLFSSL_UTASKER) #elif defined(WOLFSSL_UTASKER)
fnDebugMsg((char*)logMessage); fnDebugMsg((char*)logMessage);
fnDebugMsg("\r\n"); fnDebugMsg("\r\n");
#elif defined(MQX_USE_IO_OLD) #elif defined(MQX_USE_IO_OLD)
fprintf(_mqxio_stderr, "%s\n", logMessage); fprintf(_mqxio_stderr, "%s\n", logMessage);
#else #else
fprintf(stderr, "%s\n", logMessage); fprintf(stderr, "%s\n", logMessage);
#endif #endif
}
} }
} }
#ifndef WOLFSSL_DEBUG_ERRORS_ONLY
void WOLFSSL_MSG(const char* msg) void WOLFSSL_MSG(const char* msg)
{ {
if (loggingEnabled) if (loggingEnabled)
@@ -223,58 +213,74 @@ void WOLFSSL_LEAVE(const char* msg, int ret)
wolfssl_log(LEAVE_LOG , buffer); wolfssl_log(LEAVE_LOG , buffer);
} }
} }
#endif /* DEBUG_WOLFSSL */ #endif /* !WOLFSSL_DEBUG_ERRORS_ONLY */
#endif /* DEBUG_WOLFSSL */
/* /*
* When using OPENSSL_EXTRA or DEBUG_WOLFSSL_VERBOSE macro then WOLFSSL_ERROR is * When using OPENSSL_EXTRA or DEBUG_WOLFSSL_VERBOSE macro then WOLFSSL_ERROR is
* mapped to new funtion WOLFSSL_ERROR_LINE which gets the line # and function * mapped to new funtion WOLFSSL_ERROR_LINE which gets the line # and function
* name where WOLFSSL_ERROR is called at. * name where WOLFSSL_ERROR is called at.
*/ */
#if (defined(DEBUG_WOLFSSL) || defined(WOLFSSL_NGINX)) || defined(WOLFSSL_HAPROXY) #if defined(DEBUG_WOLFSSL) || defined(WOLFSSL_NGINX) || defined(WOLFSSL_HAPROXY)
#if (defined(OPENSSL_EXTRA) || defined(DEBUG_WOLFSSL_VERBOSE))
#if defined(OPENSSL_EXTRA) || defined(DEBUG_WOLFSSL_VERBOSE)
void WOLFSSL_ERROR_LINE(int error, const char* func, unsigned int line, void WOLFSSL_ERROR_LINE(int error, const char* func, unsigned int line,
const char* file, void* usrCtx) const char* file, void* usrCtx)
#else #else
void WOLFSSL_ERROR(int error) void WOLFSSL_ERROR(int error)
#endif #endif
{ {
#if defined(DEBUG_WOLFSSL) && !defined(WOLFSSL_NGINX) #ifdef WOLFSSL_ASYNC_CRYPT
if (loggingEnabled && error != WC_PENDING_E) if (error != WC_PENDING_E)
#endif #endif
{ {
char buffer[WOLFSSL_MAX_ERROR_SZ]; char buffer[WOLFSSL_MAX_ERROR_SZ];
#if defined(OPENSSL_EXTRA) || defined(DEBUG_WOLFSSL_VERBOSE)
(void)usrCtx; /* a user ctx for future flexibility */
(void)func;
if (wc_LockMutex(&debug_mutex) != 0) { #if defined(OPENSSL_EXTRA) || defined(DEBUG_WOLFSSL_VERBOSE)
WOLFSSL_MSG("Lock debug mutex failed"); (void)usrCtx; /* a user ctx for future flexibility */
XSNPRINTF(buffer, sizeof(buffer), (void)func;
"wolfSSL error occurred, error = %d", error);
}
else {
if (error < 0) error = error - (2*error); /*get absolute value*/
XSNPRINTF(buffer, sizeof(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); if (wc_LockMutex(&debug_mutex) != 0) {
} WOLFSSL_MSG("Lock debug mutex failed");
#else
XSNPRINTF(buffer, sizeof(buffer), XSNPRINTF(buffer, sizeof(buffer),
"wolfSSL error occurred, error = %d", error); "wolfSSL error occurred, error = %d", error);
#endif }
#ifdef DEBUG_WOLFSSL else {
wolfssl_log(ERROR_LOG , buffer); if (error < 0)
#endif error = error - (2 * error); /* get absolute value */
XSNPRINTF(buffer, sizeof(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
XSNPRINTF(buffer, sizeof(buffer),
"wolfSSL error occurred, error = %d", error);
#endif
#ifdef DEBUG_WOLFSSL
if (loggingEnabled)
wolfssl_log(ERROR_LOG , buffer);
#endif
} }
} }
void WOLFSSL_ERROR_MSG(const char* msg)
{
#ifdef DEBUG_WOLFSSL
if (loggingEnabled)
wolfssl_log(ERROR_LOG , msg);
#else
(void)msg;
#endif
}
#endif /* DEBUG_WOLFSSL || WOLFSSL_NGINX || WOLFSSL_HAPROXY */ #endif /* DEBUG_WOLFSSL || WOLFSSL_NGINX || WOLFSSL_HAPROXY */
#if defined(OPENSSL_EXTRA) || defined(DEBUG_WOLFSSL_VERBOSE) #if defined(OPENSSL_EXTRA) || defined(DEBUG_WOLFSSL_VERBOSE)

View File

@@ -324,16 +324,6 @@ int memcb_test(void);
int blob_test(void); int blob_test(void);
#endif #endif
#if defined(DEBUG_WOLFSSL) && !defined(HAVE_VALGRIND) && \
!defined(OPENSSL_EXTRA) && !defined(HAVE_STACK_SIZE)
#ifdef __cplusplus
extern "C" {
#endif
WOLFSSL_API int wolfSSL_Debugging_ON(void);
#ifdef __cplusplus
} /* extern "C" */
#endif
#endif
/* General big buffer size for many tests. */ /* General big buffer size for many tests. */
#define FOURK_BUF 4096 #define FOURK_BUF 4096
@@ -861,12 +851,10 @@ int wolfcrypt_test(void* args)
printf( "mp test passed!\n"); printf( "mp test passed!\n");
#endif #endif
#ifdef HAVE_VALGRIND
if ( (ret = logging_test()) != 0) if ( (ret = logging_test()) != 0)
return err_sys("logging test failed!\n", ret); return err_sys("logging test failed!\n", ret);
else else
printf( "logging test passed!\n"); printf( "logging test passed!\n");
#endif
if ( (ret = mutex_test()) != 0) if ( (ret = mutex_test()) != 0)
return err_sys("mutex test failed!\n", ret); return err_sys("mutex test failed!\n", ret);
@@ -15092,24 +15080,15 @@ done:
} }
#endif #endif
#ifdef HAVE_VALGRIND
/* Need a static build to have access to symbols. */
#ifndef WOLFSSL_SSL_H
/* APIs hiding in ssl.h */
extern int wolfSSL_Debugging_ON(void);
extern void wolfSSL_Debugging_OFF(void);
#endif
#ifdef DEBUG_WOLFSSL #ifdef DEBUG_WOLFSSL
static int log_cnt = 0; static THREAD_LS_T int log_cnt = 0;
static void my_Logging_cb(const int logLevel, const char *const logMessage) static void my_Logging_cb(const int logLevel, const char *const logMessage)
{ {
(void)logLevel; (void)logLevel;
(void)logMessage; (void)logMessage;
log_cnt++; log_cnt++;
} }
#endif #endif /* DEBUG_WOLFSSL */
int logging_test(void) int logging_test(void)
{ {
@@ -15117,55 +15096,60 @@ int logging_test(void)
const char* msg = "Testing, testing. 1, 2, 3, 4 ..."; const char* msg = "Testing, testing. 1, 2, 3, 4 ...";
byte a[8] = { 1, 2, 3, 4, 5, 6, 7, 8 }; byte a[8] = { 1, 2, 3, 4, 5, 6, 7, 8 };
byte b[256]; byte b[256];
size_t i; int i;
for (i = 0; i < sizeof(b); i++) for (i = 0; i < (int)sizeof(b); i++)
b[i] = i; b[i] = i;
if (wolfSSL_Debugging_ON() != 0) if (wolfSSL_Debugging_ON() != 0)
return -7900; return -7900;
if (wolfSSL_SetLoggingCb(NULL) != BAD_FUNC_ARG)
if (wolfSSL_SetLoggingCb(my_Logging_cb) != 0)
return -7901; return -7901;
WOLFSSL_MSG(msg); WOLFSSL_MSG(msg);
WOLFSSL_BUFFER(a, sizeof(a)); WOLFSSL_BUFFER(a, sizeof(a));
WOLFSSL_BUFFER(b, sizeof(b)); WOLFSSL_BUFFER(b, sizeof(b));
WOLFSSL_BUFFER(NULL, 0); WOLFSSL_BUFFER(NULL, 0);
WOLFSSL_ERROR(MEMORY_E);
WOLFSSL_ERROR_MSG(msg);
/* turn off logs */
wolfSSL_Debugging_OFF(); wolfSSL_Debugging_OFF();
/* capture log count */
i = log_cnt;
/* validate no logs are output when disabled */
WOLFSSL_MSG(msg); WOLFSSL_MSG(msg);
WOLFSSL_BUFFER(a, sizeof(a));
WOLFSSL_BUFFER(b, sizeof(b)); WOLFSSL_BUFFER(b, sizeof(b));
WOLFSSL_BUFFER(NULL, 0);
WOLFSSL_ERROR(MEMORY_E);
WOLFSSL_ERROR_MSG(msg);
if (wolfSSL_SetLoggingCb(my_Logging_cb) != 0) /* check the logs were disabled */
return -7902; if (i != log_cnt)
wolfSSL_Debugging_OFF();
WOLFSSL_MSG(msg);
WOLFSSL_BUFFER(b, sizeof(b));
if (log_cnt != 0)
return -7903;
if (wolfSSL_Debugging_ON() != 0)
return -7904; return -7904;
WOLFSSL_MSG(msg); /* restore callback and leave logging enabled */
WOLFSSL_BUFFER(b, sizeof(b)); wolfSSL_SetLoggingCb(NULL);
wolfSSL_Debugging_ON();
/* suppress unused args */
(void)a;
(void)b;
/* One call for each line of output. */
if (log_cnt != 17)
return -7905;
#else #else
if (wolfSSL_Debugging_ON() != NOT_COMPILED_IN) if (wolfSSL_Debugging_ON() != NOT_COMPILED_IN)
return -7906; return -7906;
wolfSSL_Debugging_OFF(); wolfSSL_Debugging_OFF();
if (wolfSSL_SetLoggingCb(NULL) != NOT_COMPILED_IN) if (wolfSSL_SetLoggingCb(NULL) != NOT_COMPILED_IN)
return -7907; return -7907;
#endif #endif /* DEBUG_WOLFSSL */
return 0; return 0;
} }
#endif
int mutex_test(void) int mutex_test(void)
{ {

View File

@@ -30,6 +30,7 @@
/* for users not using preprocessor flags*/ /* for users not using preprocessor flags*/
#include <wolfssl/wolfcrypt/settings.h> #include <wolfssl/wolfcrypt/settings.h>
#include <wolfssl/version.h> #include <wolfssl/version.h>
#include <wolfssl/wolfcrypt/logging.h>
#ifdef HAVE_WOLF_EVENT #ifdef HAVE_WOLF_EVENT
#include <wolfssl/wolfcrypt/wolfevent.h> #include <wolfssl/wolfcrypt/wolfevent.h>
@@ -1321,11 +1322,6 @@ WOLFSSL_API const char* wolfSSL_lib_version(void);
/* which library version do we have in hex */ /* which library version do we have in hex */
WOLFSSL_API unsigned int wolfSSL_lib_version_hex(void); WOLFSSL_API unsigned int wolfSSL_lib_version_hex(void);
/* turn logging on, only if compiled in */
WOLFSSL_API int wolfSSL_Debugging_ON(void);
/* turn logging off */
WOLFSSL_API void wolfSSL_Debugging_OFF(void);
/* do accept or connect depedning on side */ /* do accept or connect depedning on side */
WOLFSSL_API int wolfSSL_negotiate(WOLFSSL* ssl); WOLFSSL_API int wolfSSL_negotiate(WOLFSSL* ssl);
/* turn on wolfSSL data compression */ /* turn on wolfSSL data compression */

View File

@@ -33,7 +33,7 @@
#endif #endif
enum CYA_Log_Levels { enum wc_LogLevels {
ERROR_LOG = 0, ERROR_LOG = 0,
INFO_LOG, INFO_LOG,
ENTER_LOG, ENTER_LOG,
@@ -42,10 +42,16 @@ enum CYA_Log_Levels {
}; };
typedef void (*wolfSSL_Logging_cb)(const int logLevel, typedef void (*wolfSSL_Logging_cb)(const int logLevel,
const char *const logMessage); const char *const logMessage);
WOLFSSL_API int wolfSSL_SetLoggingCb(wolfSSL_Logging_cb log_function); WOLFSSL_API int wolfSSL_SetLoggingCb(wolfSSL_Logging_cb log_function);
/* turn logging on, only if compiled in */
WOLFSSL_API int wolfSSL_Debugging_ON(void);
/* turn logging off */
WOLFSSL_API void wolfSSL_Debugging_OFF(void);
#if defined(OPENSSL_EXTRA) || defined(DEBUG_WOLFSSL_VERBOSE) #if defined(OPENSSL_EXTRA) || defined(DEBUG_WOLFSSL_VERBOSE)
WOLFSSL_LOCAL int wc_LoggingInit(void); WOLFSSL_LOCAL int wc_LoggingInit(void);
WOLFSSL_LOCAL int wc_LoggingCleanup(void); WOLFSSL_LOCAL int wc_LoggingCleanup(void);
@@ -59,9 +65,10 @@ WOLFSSL_API int wolfSSL_SetLoggingCb(wolfSSL_Logging_cb log_function);
#if !defined(NO_FILESYSTEM) && !defined(NO_STDIO_FILESYSTEM) #if !defined(NO_FILESYSTEM) && !defined(NO_STDIO_FILESYSTEM)
WOLFSSL_API void wc_ERR_print_errors_fp(FILE* fp); WOLFSSL_API void wc_ERR_print_errors_fp(FILE* fp);
#endif #endif
#endif /* defined(OPENSSL_EXTRA) || defined(DEBUG_WOLFSSL_VERBOSE) */ #endif /* OPENSSL_EXTRA || DEBUG_WOLFSSL_VERBOSE */
#ifdef DEBUG_WOLFSSL
#if defined(DEBUG_WOLFSSL) && !defined(WOLFSSL_DEBUG_ERRORS_ONLY)
#if defined(_WIN32) #if defined(_WIN32)
#if defined(INTIME_RTOS) #if defined(INTIME_RTOS)
#define __func__ NULL #define __func__ NULL
@@ -73,15 +80,15 @@ WOLFSSL_API int wolfSSL_SetLoggingCb(wolfSSL_Logging_cb log_function);
/* a is prepended to m and b is appended, creating a log msg a + m + b */ /* 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 #define WOLFSSL_LOG_CAT(a, m, b) #a " " m " " #b
void WOLFSSL_ENTER(const char* msg); WOLFSSL_API void WOLFSSL_ENTER(const char* msg);
void WOLFSSL_LEAVE(const char* msg, int ret); WOLFSSL_API void WOLFSSL_LEAVE(const char* msg, int ret);
#define WOLFSSL_STUB(m) \ #define WOLFSSL_STUB(m) \
WOLFSSL_MSG(WOLFSSL_LOG_CAT(wolfSSL Stub, m, not implemented)) WOLFSSL_MSG(WOLFSSL_LOG_CAT(wolfSSL Stub, m, not implemented))
void WOLFSSL_MSG(const char* msg); WOLFSSL_API void WOLFSSL_MSG(const char* msg);
void WOLFSSL_BUFFER(const byte* buffer, word32 length); WOLFSSL_API void WOLFSSL_BUFFER(const byte* buffer, word32 length);
#else /* DEBUG_WOLFSSL */ #else
#define WOLFSSL_ENTER(m) #define WOLFSSL_ENTER(m)
#define WOLFSSL_LEAVE(m, r) #define WOLFSSL_LEAVE(m, r)
@@ -90,18 +97,23 @@ WOLFSSL_API int wolfSSL_SetLoggingCb(wolfSSL_Logging_cb log_function);
#define WOLFSSL_MSG(m) #define WOLFSSL_MSG(m)
#define WOLFSSL_BUFFER(b, l) #define WOLFSSL_BUFFER(b, l)
#endif /* DEBUG_WOLFSSL */ #endif /* DEBUG_WOLFSSL && !WOLFSSL_DEBUG_ERRORS_ONLY */
#if (defined(DEBUG_WOLFSSL) || defined(WOLFSSL_NGINX)) || defined(WOLFSSL_HAPROXY) #if defined(DEBUG_WOLFSSL) || defined(WOLFSSL_NGINX) || defined(WOLFSSL_HAPROXY)
#if (defined(OPENSSL_EXTRA) || defined(DEBUG_WOLFSSL_VERBOSE))
void WOLFSSL_ERROR_LINE(int err, const char* func, unsigned int line, #if defined(OPENSSL_EXTRA) || defined(DEBUG_WOLFSSL_VERBOSE)
WOLFSSL_API void WOLFSSL_ERROR_LINE(int err, const char* func, unsigned int line,
const char* file, void* ctx); const char* file, void* ctx);
#define WOLFSSL_ERROR(x) WOLFSSL_ERROR_LINE((x), __func__, __LINE__, __FILE__,NULL) #define WOLFSSL_ERROR(x) \
WOLFSSL_ERROR_LINE((x), __func__, __LINE__, __FILE__, NULL)
#else #else
void WOLFSSL_ERROR(int); WOLFSSL_API void WOLFSSL_ERROR(int err);
#endif #endif
WOLFSSL_API void WOLFSSL_ERROR_MSG(const char* msg);
#else #else
#define WOLFSSL_ERROR(e) #define WOLFSSL_ERROR(e)
#define WOLFSSL_ERROR_MSG(m)
#endif #endif
#ifdef __cplusplus #ifdef __cplusplus