From 96c06899d95eaf01d05561554b21e8c63baa7129 Mon Sep 17 00:00:00 2001 From: ming Date: Thu, 27 Jul 2017 06:07:54 +0000 Subject: [PATCH 75/76] Fixed #2030: Improve error handling in OpenSSL socket --- pjlib/src/pj/ssl_sock_ossl.c | 173 ++++++++++++++++++++++++++++++++++++++----- 1 file changed, 156 insertions(+), 17 deletions(-) diff --git a/pjlib/src/pj/ssl_sock_ossl.c b/pjlib/src/pj/ssl_sock_ossl.c index c466b3c..b8175e1 100644 --- a/pjlib/src/pj/ssl_sock_ossl.c +++ b/pjlib/src/pj/ssl_sock_ossl.c @@ -298,14 +298,104 @@ static pj_status_t flush_delayed_send(pj_ssl_sock_t *ssock); /* Expected maximum value of reason component in OpenSSL error code */ #define MAX_OSSL_ERR_REASON 1200 -static pj_status_t STATUS_FROM_SSL_ERR(pj_ssl_sock_t *ssock, - unsigned long err) + +static char *SSLErrorString (int err) { - pj_status_t status; + switch (err) { + case SSL_ERROR_NONE: + return "SSL_ERROR_NONE"; + case SSL_ERROR_ZERO_RETURN: + return "SSL_ERROR_ZERO_RETURN"; + case SSL_ERROR_WANT_READ: + return "SSL_ERROR_WANT_READ"; + case SSL_ERROR_WANT_WRITE: + return "SSL_ERROR_WANT_WRITE"; + case SSL_ERROR_WANT_CONNECT: + return "SSL_ERROR_WANT_CONNECT"; + case SSL_ERROR_WANT_ACCEPT: + return "SSL_ERROR_WANT_ACCEPT"; + case SSL_ERROR_WANT_X509_LOOKUP: + return "SSL_ERROR_WANT_X509_LOOKUP"; + case SSL_ERROR_SYSCALL: + return "SSL_ERROR_SYSCALL"; + case SSL_ERROR_SSL: + return "SSL_ERROR_SSL"; + default: + return "SSL_ERROR_UNKNOWN"; + } +} - /* General SSL error, dig more from OpenSSL error queue */ - if (err == SSL_ERROR_SSL) - err = ERR_get_error(); +#define ERROR_LOG(msg, err) \ + PJ_LOG(2,("SSL", "%s (%s): Level: %d err: <%lu> <%s-%s-%s> len: %d", \ + msg, action, level, err, \ + (ERR_lib_error_string(err)? ERR_lib_error_string(err): "???"), \ + (ERR_func_error_string(err)? ERR_func_error_string(err):"???"),\ + (ERR_reason_error_string(err)? \ + ERR_reason_error_string(err): "???"), len)); + +static void SSLLogErrors(char * action, int ret, int ssl_err, int len) +{ + char *ssl_err_str = SSLErrorString(ssl_err); + + if (!action) { + action = "UNKNOWN"; + } + + switch (ssl_err) { + case SSL_ERROR_SYSCALL: + { + unsigned long err2 = ERR_get_error(); + if (err2) { + int level = 0; + while (err2) { + ERROR_LOG("SSL_ERROR_SYSCALL", err2); + level++; + err2 = ERR_get_error(); + } + } else if (ret == 0) { + /* An EOF was observed that violates the protocol */ + + /* The TLS/SSL handshake was not successful but was shut down + * controlled and by the specifications of the TLS/SSL protocol. + */ + } else if (ret == -1) { + /* BIO error - look for more info in errno... */ + char errStr[250] = ""; + strerror_r(errno, errStr, sizeof(errStr)); + /* for now - continue logging these if they occur.... */ + PJ_LOG(4,("SSL", "BIO error, SSL_ERROR_SYSCALL (%s): " + "errno: <%d> <%s> len: %d", + action, errno, errStr, len)); + } else { + /* ret!=0 & ret!=-1 & nothing on error stack - is this valid??? */ + PJ_LOG(2,("SSL", "SSL_ERROR_SYSCALL (%s) ret: %d len: %d", + action, ret, len)); + } + break; + } + case SSL_ERROR_SSL: + { + unsigned long err2 = ERR_get_error(); + int level = 0; + + while (err2) { + ERROR_LOG("SSL_ERROR_SSL", err2); + level++; + err2 = ERR_get_error(); + } + break; + } + default: + PJ_LOG(2,("SSL", "%lu [%s] (%s) ret: %d len: %d", + ssl_err, ssl_err_str, action, ret, len)); + break; + } +} + + +static pj_status_t GET_STATUS_FROM_SSL_ERR(unsigned long err) +{ + pj_status_t status; /* OpenSSL error range is much wider than PJLIB errno space, so * if it exceeds the space, only the error reason will be kept. @@ -317,13 +407,49 @@ static pj_status_t STATUS_FROM_SSL_ERR(pj_ssl_sock_t *ssock, status = ERR_GET_REASON(err); status += PJ_SSL_ERRNO_START; - ssock->last_err = err; return status; } +/* err contains ERR_get_error() status */ +static pj_status_t STATUS_FROM_SSL_ERR(char *action, pj_ssl_sock_t *ssock, + unsigned long err) +{ + int level = 0; + int len = 0; //dummy + + ERROR_LOG("STATUS_FROM_SSL_ERR", err); + level++; + + /* General SSL error, dig more from OpenSSL error queue */ + if (err == SSL_ERROR_SSL) { + err = ERR_get_error(); + ERROR_LOG("STATUS_FROM_SSL_ERR", err); + } + + ssock->last_err = err; + return GET_STATUS_FROM_SSL_ERR(err); +} + +/* err contains SSL_get_error() status */ +static pj_status_t STATUS_FROM_SSL_ERR2(char *action, pj_ssl_sock_t *ssock, + int ret, int err, int len) +{ + unsigned long ssl_err = err; + + if (err == SSL_ERROR_SSL) { + ssl_err = ERR_peek_error(); + } + + /* Dig for more from OpenSSL error queue */ + SSLLogErrors(action, ret, err, len); + + ssock->last_err = ssl_err; + return GET_STATUS_FROM_SSL_ERR(ssl_err); +} + static pj_status_t GET_SSL_STATUS(pj_ssl_sock_t *ssock) { - return STATUS_FROM_SSL_ERR(ssock, ERR_get_error()); + return STATUS_FROM_SSL_ERR("status", ssock, ERR_get_error()); } @@ -1514,7 +1640,7 @@ static pj_bool_t on_handshake_complete(pj_ssl_sock_t *ssock, unsigned long err; err = ERR_get_error(); if (err != SSL_ERROR_NONE) - status = STATUS_FROM_SSL_ERR(ssock, err); + status = STATUS_FROM_SSL_ERR("connecting", ssock, err); } reset_ssl_sock_state(ssock); } @@ -1833,11 +1959,11 @@ static pj_status_t do_handshake(pj_ssl_sock_t *ssock) } if (err < 0) { - err = SSL_get_error(ssock->ossl_ssl, err); - if (err != SSL_ERROR_NONE && err != SSL_ERROR_WANT_READ) + int err2 = SSL_get_error(ssock->ossl_ssl, err); + if (err2 != SSL_ERROR_NONE && err2 != SSL_ERROR_WANT_READ) { /* Handshake fails */ - status = STATUS_FROM_SSL_ERR(ssock, err); + status = STATUS_FROM_SSL_ERR2("Handshake", ssock, err, err2, 0); return status; } } @@ -1913,6 +2039,7 @@ static pj_bool_t asock_on_data_read (pj_activesock_t *asock, read_data_t *buf = *(OFFSET_OF_READ_DATA_PTR(ssock, data)); void *data_ = (pj_int8_t*)buf->data + buf->len; int size_ = (int)(ssock->read_size - buf->len); + int len = size_; /* SSL_read() may write some data to BIO write when re-negotiation * is on progress, so let's protect it with write mutex. @@ -1965,10 +2092,22 @@ static pj_bool_t asock_on_data_read (pj_activesock_t *asock, */ if (err != SSL_ERROR_NONE && err != SSL_ERROR_WANT_READ) { - /* Reset SSL socket state, then return PJ_FALSE */ - status = STATUS_FROM_SSL_ERR(ssock, err); - reset_ssl_sock_state(ssock); - goto on_error; + if (err == SSL_ERROR_SYSCALL && size_ == -1 && + ERR_peek_error() == 0 && errno == 0) + { + status = STATUS_FROM_SSL_ERR2("Read", ssock, size_, + err, len); + PJ_LOG(4,("SSL", "SSL_read() = -1, with " + "SSL_ERROR_SYSCALL, no SSL error, " + "and errno = 0 - skip BIO error")); + /* Ignore these errors */ + } else { + /* Reset SSL socket state, then return PJ_FALSE */ + status = STATUS_FROM_SSL_ERR2("Read", ssock, size_, + err, len); + reset_ssl_sock_state(ssock); + goto on_error; + } } status = do_handshake(ssock); @@ -2856,7 +2995,7 @@ static pj_status_t ssl_write(pj_ssl_sock_t *ssock, status = PJ_EBUSY; } else { /* Some problem occured */ - status = STATUS_FROM_SSL_ERR(ssock, err); + status = STATUS_FROM_SSL_ERR2("Write", ssock, nwritten, err, size); } } else { /* nwritten < *size, shouldn't happen, unless write BIO cannot hold -- 2.9.4