diff -Naur pjproject-2.6-orig/pjlib/src/pj/ssl_sock_ossl.c pjproject-2.6/pjlib/src/pj/ssl_sock_ossl.c --- pjproject-2.6-orig/pjlib/src/pj/ssl_sock_ossl.c 2017-01-24 05:41:05.000000000 +0000 +++ pjproject-2.6/pjlib/src/pj/ssl_sock_ossl.c 2017-05-16 13:52:43.538936628 +0100 @@ -291,14 +291,121 @@ /* 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, + +static char *SSLErrorString (int err) +{ + 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"; + } +} + + +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) { + PJ_LOG(2,("SSL", "SSL_ERROR_SYSCALL (%s): Level: %d err: <%lu> <%s-%s-%s> len: %d", + action, level, err2, + (ERR_lib_error_string(err2)? ERR_lib_error_string(err2): "???"), + (ERR_func_error_string(err2)? ERR_func_error_string(err2): "???"), + (ERR_reason_error_string(err2)? ERR_reason_error_string(err2): "???"), len)); + 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(2,("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) { + PJ_LOG(2,("SSL", "SSL_ERROR_SSL (%s): Level: %d err: <%lu> <%s-%s-%s> len: %d", + action, level, err2, + (ERR_lib_error_string(err2)? ERR_lib_error_string(err2): "???"), + (ERR_func_error_string(err2)? ERR_func_error_string(err2): "???"), + (ERR_reason_error_string(err2)? ERR_reason_error_string(err2): "???"), len)); + 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; + } + //PJ_LOG(3,("SSL", "Exiting SSLLogErrors")); +} + + +// err contains ERR_get_error() status +static pj_status_t STATUS_FROM_SSL_ERR(char *action, pj_ssl_sock_t *ssock, unsigned long err) { pj_status_t status; /* General SSL error, dig more from OpenSSL error queue */ - if (err == SSL_ERROR_SSL) + int level = 0; + PJ_LOG(2,("SSL", "STATUS_FROM_SSL_ERR (%s): Level: %d err: <%lu> <%s-%s-%s>", + 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): "???"))); + if (err == SSL_ERROR_SSL) { err = ERR_get_error(); + PJ_LOG(2,("SSL", "STATUS_FROM_SSL_ERR (%s): Level: %d err: <%lu> <%s-%s-%s>", + 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): "???"))); + } /* OpenSSL error range is much wider than PJLIB errno space, so * if it exceeds the space, only the error reason will be kept. @@ -314,9 +421,37 @@ return status; } +// 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) +{ + pj_status_t status; + + 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); + + /* OpenSSL error range is much wider than PJLIB errno space, so + * if it exceeds the space, only the error reason will be kept. + * Note that the last native error will be kept as is and can be + * retrieved via SSL socket info. + */ + status = ERR_GET_LIB(ssl_err)*MAX_OSSL_ERR_REASON + ERR_GET_REASON(ssl_err); + if (status > PJ_SSL_ERRNO_SPACE_SIZE) + status = ERR_GET_REASON(ssl_err); + + status += PJ_SSL_ERRNO_START; + ssock->last_err = ssl_err; + return status; +} + 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()); } @@ -1491,7 +1626,7 @@ 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); } @@ -1810,11 +1945,11 @@ } 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; } } @@ -1890,6 +2025,7 @@ 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. @@ -1938,10 +2074,26 @@ */ 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); +#define EXPERIMENTAL 1 +#if EXPERIMENTAL + // experimental... + 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(2,("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; + } +#else + status = STATUS_FROM_SSL_ERR2("Read", ssock, size_, err, len); reset_ssl_sock_state(ssock); goto on_error; +#endif } status = do_handshake(ssock); @@ -2825,7 +2977,7 @@ 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 diff -Naur pjproject-2.6-orig/pjsip/src/pjsip/sip_transport_tls.c pjproject-2.6/pjsip/src/pjsip/sip_transport_tls.c --- pjproject-2.6-orig/pjsip/src/pjsip/sip_transport_tls.c 2017-01-19 07:41:25.000000000 +0000 +++ pjproject-2.6/pjsip/src/pjsip/sip_transport_tls.c 2017-05-05 07:01:47.006862461 +0100 @@ -1177,7 +1177,7 @@ &tls->base.local_addr); } - PJ_LOG(4,(tls->base.obj_name, + PJ_LOG(2,(tls->base.obj_name, "TLS transport %.*s:%d is connecting to %.*s:%d...", (int)tls->base.local_name.host.slen, tls->base.local_name.host.ptr, @@ -1567,7 +1567,7 @@ } else { /* Transport is closed */ - PJ_LOG(4,(tls->base.obj_name, "TLS connection closed")); + PJ_LOG(2,(tls->base.obj_name, "TLS connection closed")); tls_init_shutdown(tls, status); @@ -1776,7 +1776,7 @@ /* Mark that pending connect() operation has completed. */ tls->has_pending_connect = PJ_FALSE; - PJ_LOG(4,(tls->base.obj_name, + PJ_LOG(2,(tls->base.obj_name, "TLS transport %.*s:%d is connected to %.*s:%d", (int)tls->base.local_name.host.slen, tls->base.local_name.host.ptr,