static void ssl_info_callback(const SSL *ssl, int where, int ret) {
const char *s;
int w;
w = where & ~SSL_ST_MASK;
if (w & SSL_ST_CONNECT)
s = "SSL_connect";
else if (w & SSL_ST_ACCEPT)
s = "SSL_accept";
else
s = "undefined";
if (where & SSL_CB_LOOP)
debug(DBG_DBG, "%s:%s\n", s, SSL_state_string_long(ssl));
else if (where & SSL_CB_ALERT) {
s = (where & SSL_CB_READ) ? "read" : "write";
debug(DBG_DBG, "SSL3 alert %s:%s:%s\n", s, SSL_alert_type_string_long(ret), SSL_alert_desc_string_long(ret));
}
else if (where & SSL_CB_EXIT) {
if (ret == 0)
debug(DBG_DBG, "%s:failed in %s\n", s, SSL_state_string_long(ssl));
else if (ret < 0)
debug(DBG_DBG, "%s:error in %s\n", s, SSL_state_string_long(ssl));
}
}
static void ssl_info_cb(const SSL *ssl, int where, int ret)
{
const char *str;
int w;
wpa_printf(MSG_DEBUG, "SSL: (where=0x%x ret=0x%x)", where, ret);
w = where & ~SSL_ST_MASK;
if (w & SSL_ST_CONNECT)
str = "SSL_connect";
else if (w & SSL_ST_ACCEPT)
str = "SSL_accept";
else
str = "undefined";
if (where & SSL_CB_LOOP) {
wpa_printf(MSG_DEBUG, "SSL: %s:%s",
str, SSL_state_string_long(ssl));
} else if (where & SSL_CB_ALERT) {
wpa_printf(MSG_INFO, "SSL: SSL3 alert: %s:%s:%s",
where & SSL_CB_READ ?
"read (authentication server reported an error)" :
"write (local SSL3 detected an error)",
SSL_alert_type_string_long(ret),
SSL_alert_desc_string_long(ret));
} else if (where & SSL_CB_EXIT && ret <= 0) {
wpa_printf(MSG_DEBUG, "SSL: %s:%s in %s",
str, ret == 0 ? "failed" : "error",
SSL_state_string_long(ssl));
}
}
/*
** Roughly copied from the openssl sample app in the openssl package
*/
PRIVATE void apps_ssl_info_callback (SSL * s, int where, int ret)
{
char *str;
int w = where & ~SSL_ST_MASK;
if (w & SSL_ST_CONNECT)
str="SSL_connect";
else if (w & SSL_ST_ACCEPT)
str="SSL_accept";
else
str="undefined";
if (where & SSL_CB_LOOP) {
HTTRACE(PROT_TRACE, "%s: %s\n" _ str _ SSL_state_string_long(s));
} else if (where & SSL_CB_ALERT) {
str = (where & SSL_CB_READ) ? "read" : "write";
HTTRACE(PROT_TRACE, "SSL3 alert %s:%s:%s\n" _ str _
SSL_alert_type_string_long(ret) _
SSL_alert_desc_string_long(ret));
} else if (where & SSL_CB_EXIT) {
if (ret == 0) {
HTTRACE(PROT_TRACE, "%s: failed in %s\n" _ str _ SSL_state_string_long(s));
} else if (ret < 0) {
HTTRACE(PROT_TRACE, "%s: error in %s\n" _ str _ SSL_state_string_long(s));
}
}
}
static void openssl_info_callback(const SSL *ssl, int where, int ret)
{
struct ssl_iostream *ssl_io;
ssl_io = SSL_get_ex_data(ssl, dovecot_ssl_extdata_index);
if ((where & SSL_CB_ALERT) != 0) {
switch (ret & 0xff) {
case SSL_AD_CLOSE_NOTIFY:
i_debug("%sSSL alert: %s",
ssl_io->log_prefix,
SSL_alert_desc_string_long(ret));
break;
default:
i_debug("%sSSL alert: where=0x%x, ret=%d: %s %s",
ssl_io->log_prefix, where, ret,
SSL_alert_type_string_long(ret),
SSL_alert_desc_string_long(ret));
break;
}
} else if (ret == 0) {
i_debug("%sSSL failed: where=0x%x: %s",
ssl_io->log_prefix, where, SSL_state_string_long(ssl));
} else {
i_debug("%sSSL: where=0x%x, ret=%d: %s",
ssl_io->log_prefix, where, ret,
SSL_state_string_long(ssl));
}
}
static void
log_state (GstDtlsConnection * self, const gchar * str)
{
GstDtlsConnectionPrivate *priv = self->priv;
guint states = 0;
states |= (! !SSL_is_init_finished (priv->ssl) << 0);
states |= (! !SSL_in_init (priv->ssl) << 4);
states |= (! !SSL_in_before (priv->ssl) << 8);
states |= (! !SSL_in_connect_init (priv->ssl) << 12);
states |= (! !SSL_in_accept_init (priv->ssl) << 16);
states |= (! !SSL_want_write (priv->ssl) << 20);
states |= (! !SSL_want_read (priv->ssl) << 24);
#if OPENSSL_VERSION_NUMBER < 0x10100001L
GST_LOG_OBJECT (self, "%s: role=%s buf=(%d,%p:%d/%d) %x|%x %s",
str,
priv->is_client ? "client" : "server",
pqueue_size (priv->ssl->d1->sent_messages),
priv->bio_buffer,
priv->bio_buffer_offset,
priv->bio_buffer_len,
states, SSL_get_state (priv->ssl), SSL_state_string_long (priv->ssl));
#else
GST_LOG_OBJECT (self, "%s: role=%s buf=(%p:%d/%d) %x|%x %s",
str,
priv->is_client ? "client" : "server",
priv->bio_buffer,
priv->bio_buffer_offset,
priv->bio_buffer_len,
states, SSL_get_state (priv->ssl), SSL_state_string_long (priv->ssl));
#endif
}
void
apps_ssl_info_callback(const SSL * s, int where, int ret)
{
const char *str;
int w;
w = where & ~SSL_ST_MASK;
if (w & SSL_ST_CONNECT)
str = "SSL_connect";
else if (w & SSL_ST_ACCEPT)
str = "SSL_accept";
else
str = "undefined";
if (where & SSL_CB_LOOP) {
BIO_printf(bio_err, "%s:%s\n", str, SSL_state_string_long(s));
} else if (where & SSL_CB_ALERT) {
str = (where & SSL_CB_READ) ? "read" : "write";
BIO_printf(bio_err, "SSL3 alert %s:%s:%s\n", str,
SSL_alert_type_string_long(ret),
SSL_alert_desc_string_long(ret));
} else if (where & SSL_CB_EXIT) {
if (ret == 0)
BIO_printf(bio_err, "%s:failed in %s\n",
str, SSL_state_string_long(s));
else if (ret < 0) {
BIO_printf(bio_err, "%s:error in %s\n",
str, SSL_state_string_long(s));
}
}
}
inline
void DtlsTransport::onSSLInfo(int where, int ret)
{
MS_TRACE();
int w = where & -SSL_ST_MASK;
const char* role;
if (w & SSL_ST_CONNECT) role = "client";
else if (w & SSL_ST_ACCEPT) role = "server";
else role = "undefined";
if (where & SSL_CB_LOOP)
{
MS_DEBUG("[role:%s, action:'%s']", role, SSL_state_string_long(this->ssl));
}
else if (where & SSL_CB_ALERT)
{
const char* alert_type;
switch (*SSL_alert_type_string(ret))
{
case 'W': alert_type = "warning"; break;
case 'F': alert_type = "fatal"; break;
default: alert_type = "undefined";
}
if (where & SSL_CB_READ)
MS_DEBUG("received DTLS %s alert: %s", alert_type, SSL_alert_desc_string_long(ret));
else if (where & SSL_CB_WRITE)
MS_DEBUG("sending DTLS %s alert: %s", alert_type, SSL_alert_desc_string_long(ret));
else
MS_DEBUG("DTLS %s alert: %s", alert_type, SSL_alert_desc_string_long(ret));
}
else if (where & SSL_CB_EXIT)
{
if (ret == 0)
MS_DEBUG("[role:%s, failed:'%s']", role, SSL_state_string_long(this->ssl));
else if (ret < 0)
MS_DEBUG("role: %s, waiting:'%s']", role, SSL_state_string_long(this->ssl));
}
else if (where & SSL_CB_HANDSHAKE_START)
{
MS_DEBUG("DTLS handshake start");
}
else if (where & SSL_CB_HANDSHAKE_DONE)
{
MS_DEBUG("DTLS handshake done");
this->handshakeDoneNow = true;
}
// NOTE: checking SSL_get_shutdown(this->ssl) & SSL_RECEIVED_SHUTDOWN here upon
// receipt of a close alert does not work (the flag is set after this callback).
}
static void ssl_info_callback(const SSL *s, int where, int ret)
{
const char *str;
int w;
w = where & ~SSL_ST_MASK;
if (w & SSL_ST_CONNECT) str="SSL_connect";
else if (w & SSL_ST_ACCEPT) str="SSL_accept";
else str="undefined";
if (where & SSL_CB_LOOP)
{
log(L_DEBUG, "SSL: %s", SSL_state_string_long((SSL*)s));
}
else if (where & SSL_CB_ALERT)
{
str=(where & SSL_CB_READ)?"read":"write";
log(L_DEBUG, "SSL: SSL3 alert %s:%s:%s", str,
SSL_alert_type_string_long(ret),
SSL_alert_desc_string_long(ret));
}
else if (where & SSL_CB_EXIT)
{
if (ret == 0)
log(L_DEBUG, "SSL: %s:failed in %s",
str,SSL_state_string_long((SSL*)s));
else if (ret < 0)
{
log(L_DEBUG, "SSL: %s:%s", str,SSL_state_string_long((SSL*)s));
}
}
else if (where & SSL_CB_ALERT)
{
str=(where & SSL_CB_READ)?"read":"write";
log(L_DEBUG, "SSL: SSL3 alert %s:%s:%s", str,
SSL_alert_type_string_long(ret),
SSL_alert_desc_string_long(ret));
}
else if (where & SSL_CB_EXIT)
{
if (ret == 0)
log(L_DEBUG, "SSL: %s:failed in %s",
str,SSL_state_string_long((SSL*)s));
else if (ret < 0)
{
log(L_DEBUG, "SSL: %s:error in %s",
str,SSL_state_string_long((SSL*)s));
}
}
}
/******************************************************************************
******************************************************************************
** Higher Level SSL_CTX Wrappers **
******************************************************************************
******************************************************************************/
static void
log_callback(const SSL *ssl, int where, int ret)
{
const char *retstr = "";
int should_log = 0;
lcbio_SOCKET *sock = SSL_get_app_data(ssl);
/* Ignore low-level SSL stuff */
if (where & SSL_CB_ALERT) {
should_log = 1;
}
if (where == SSL_CB_HANDSHAKE_START || where == SSL_CB_HANDSHAKE_DONE) {
should_log = 1;
}
if ((where & SSL_CB_EXIT) && ret == 0) {
should_log = 1;
}
if (!should_log) {
return;
}
retstr = SSL_alert_type_string(ret);
lcb_log(LOGARGS(ssl, LCB_LOG_TRACE), "sock=%p: ST(0x%x). %s. R(0x%x)%s",
(void*)sock, where, SSL_state_string_long(ssl), ret, retstr);
if (where == SSL_CB_HANDSHAKE_DONE) {
lcb_log(LOGARGS(ssl, LCB_LOG_DEBUG), "sock=%p. Using SSL version %s. Cipher=%s", (void*)sock, SSL_get_version(ssl), SSL_get_cipher_name(ssl));
}
}
/* TODO(jboeuf): Remove when we are past the debugging phase with this code. */
static void ssl_log_where_info(const SSL* ssl, int where, int flag,
const char* msg) {
if ((where & flag) && tsi_tracing_enabled) {
gpr_log(GPR_INFO, "%20.20s - %30.30s - %5.10s", msg,
SSL_state_string_long(ssl), SSL_state_string(ssl));
}
}
/**
* Callback used for debugging
*/
static void sslLogCallback(const SSL *ssl, int where, int ret) {
const char *retstr = "";
int should_log = 1;
/* Ignore low-level SSL stuff */
if (where & SSL_CB_ALERT) {
should_log = 1;
}
if (where == SSL_CB_HANDSHAKE_START || where == SSL_CB_HANDSHAKE_DONE) {
should_log = 1;
}
if ((where & SSL_CB_EXIT) && ret == 0) {
should_log = 1;
}
if (!should_log) {
return;
}
retstr = SSL_alert_type_string(ret);
printf("ST(0x%x). %s. R(0x%x)%s\n", where, SSL_state_string_long(ssl), ret, retstr);
if (where == SSL_CB_HANDSHAKE_DONE) {
printf("Using SSL version %s. Cipher=%s\n", SSL_get_version(ssl), SSL_get_cipher_name(ssl));
}
}
void cbtls_info(const SSL *s, int where, int ret)
{
const char *str, *state;
int w;
REQUEST *request = SSL_get_ex_data(s, FR_TLS_EX_INDEX_REQUEST);
char buffer[1024];
w = where & ~SSL_ST_MASK;
if (w & SSL_ST_CONNECT) str=" TLS_connect";
else if (w & SSL_ST_ACCEPT) str=" TLS_accept";
else str=" (other)";
state = SSL_state_string_long(s);
state = state ? state : "NULL";
buffer[0] = '\0';
if (where & SSL_CB_LOOP) {
RDEBUG2("%s: %s", str, state);
} else if (where & SSL_CB_HANDSHAKE_START) {
RDEBUG2("%s: %s", str, state);
} else if (where & SSL_CB_HANDSHAKE_DONE) {
RDEBUG2("%s: %s", str, state);
} else if (where & SSL_CB_ALERT) {
str=(where & SSL_CB_READ)?"read":"write";
snprintf(buffer, sizeof(buffer), "TLS Alert %s:%s:%s",
str,
SSL_alert_type_string_long(ret),
SSL_alert_desc_string_long(ret));
} else if (where & SSL_CB_EXIT) {
if (ret == 0) {
snprintf(buffer, sizeof(buffer), "%s: failed in %s",
str, state);
} else if (ret < 0) {
if (SSL_want_read(s)) {
RDEBUG2("%s: Need to read more data: %s",
str, state);
} else {
snprintf(buffer, sizeof(buffer),
"%s: error in %s", str, state);
}
}
}
if (buffer[0]) {
radlog(L_ERR, "%s", buffer);
if (request) {
VALUE_PAIR *vp;
vp = pairmake("Module-Failure-Message", buffer, T_OP_ADD);
if (vp) pairadd(&request->packet->vps, vp);
}
}
}
void SSL_CTX_info_callback(const SSL* ssl, int where, int ret)
{
FUNC_ENTRY;
if (where & SSL_CB_LOOP)
{
Log(TRACE_PROTOCOL, 1, "SSL state %s:%s:%s",
(where & SSL_ST_CONNECT) ? "connect" : (where & SSL_ST_ACCEPT) ? "accept" : "undef",
SSL_state_string_long(ssl), SSL_get_cipher_name(ssl));
}
else if (where & SSL_CB_EXIT)
{
Log(TRACE_PROTOCOL, 1, "SSL %s:%s",
(where & SSL_ST_CONNECT) ? "connect" : (where & SSL_ST_ACCEPT) ? "accept" : "undef",
SSL_state_string_long(ssl));
}
else if (where & SSL_CB_ALERT)
{
Log(TRACE_PROTOCOL, 1, "SSL alert %s:%s:%s",
(where & SSL_CB_READ) ? "read" : "write",
SSL_alert_type_string_long(ret), SSL_alert_desc_string_long(ret));
}
else if (where & SSL_CB_HANDSHAKE_START)
{
Log(TRACE_PROTOCOL, 1, "SSL handshake started %s:%s:%s",
(where & SSL_CB_READ) ? "read" : "write",
SSL_alert_type_string_long(ret), SSL_alert_desc_string_long(ret));
}
else if (where & SSL_CB_HANDSHAKE_DONE)
{
Log(TRACE_PROTOCOL, 1, "SSL handshake done %s:%s:%s",
(where & SSL_CB_READ) ? "read" : "write",
SSL_alert_type_string_long(ret), SSL_alert_desc_string_long(ret));
Log(TRACE_PROTOCOL, 1, "SSL certificate verification: %s",
SSL_get_verify_result_string(SSL_get_verify_result(ssl)));
}
else
{
Log(TRACE_PROTOCOL, 1, "SSL state %s:%s:%s", SSL_state_string_long(ssl),
SSL_alert_type_string_long(ret), SSL_alert_desc_string_long(ret));
}
FUNC_EXIT;
}
@return: A string representing the state\n\
";
static PyObject *
ssl_Connection_state_string(ssl_ConnectionObj *self, PyObject *args)
{
if (!PyArg_ParseTuple(args, ":state_string"))
return NULL;
return PyText_FromString(SSL_state_string_long(self->ssl));
}
static void openssl_info_callback(const SSL *ssl, int where, int ret)
{
struct ssl_iostream *ssl_io;
ssl_io = SSL_get_ex_data(ssl, dovecot_ssl_extdata_index);
if ((where & SSL_CB_ALERT) != 0) {
i_warning("%s: SSL alert: where=0x%x, ret=%d: %s %s",
ssl_io->source, where, ret,
SSL_alert_type_string_long(ret),
SSL_alert_desc_string_long(ret));
} else if (ret == 0) {
i_warning("%s: SSL failed: where=0x%x: %s",
ssl_io->source, where, SSL_state_string_long(ssl));
} else {
i_debug("%s: SSL: where=0x%x, ret=%d: %s",
ssl_io->source, where, ret,
SSL_state_string_long(ssl));
}
}
/******************************************************************************
******************************************************************************
** Higher Level SSL_CTX Wrappers **
******************************************************************************
******************************************************************************/
static void
log_callback(const SSL *ssl, int where, int ret)
{
const char *retstr = "";
lcbio_SOCKET *sock = SSL_get_app_data(ssl);
if (where & SSL_CB_ALERT) {
retstr = SSL_alert_type_string(ret);
}
lcb_log(LOGARGS(ssl, LCB_LOG_TRACE), "sock=%p: ST(0x%x). %s. R(0x%x)%s",
(void*)sock, where, SSL_state_string_long(ssl), ret, retstr);
}
USES_APPLE_DEPRECATED_API /* OpenSSL API has been deprecated by Apple */
#include <freeradius-devel/radiusd.h>
#ifdef WITH_TLS
void cbtls_info(SSL const *s, int where, int ret)
{
char const *str, *state;
int w;
REQUEST *request = SSL_get_ex_data(s, FR_TLS_EX_INDEX_REQUEST);
char buffer[1024];
w = where & ~SSL_ST_MASK;
if (w & SSL_ST_CONNECT) str=" TLS_connect";
else if (w & SSL_ST_ACCEPT) str=" TLS_accept";
else str=" (other)";
state = SSL_state_string_long(s);
state = state ? state : "NULL";
buffer[0] = '\0';
if (where & SSL_CB_LOOP) {
RDEBUG2("%s: %s", str, state);
} else if (where & SSL_CB_HANDSHAKE_START) {
RDEBUG2("%s: %s", str, state);
} else if (where & SSL_CB_HANDSHAKE_DONE) {
RDEBUG2("%s: %s", str, state);
} else if (where & SSL_CB_ALERT) {
str=(where & SSL_CB_READ)?"read":"write";
snprintf(buffer, sizeof(buffer), "TLS Alert %s:%s:%s",
str,
SSL_alert_type_string_long(ret),
SSL_alert_desc_string_long(ret));
} else if (where & SSL_CB_EXIT) {
if (ret == 0) {
snprintf(buffer, sizeof(buffer), "%s: failed in %s",
str, state);
} else if (ret < 0) {
if (SSL_want_read(s)) {
RDEBUG2("%s: Need to read more data: %s",
str, state);
} else {
snprintf(buffer, sizeof(buffer),
"%s: error in %s", str, state);
}
}
}
if (buffer[0] && request) {
REDEBUG("SSL says: %s", buffer);
}
}
/* Debug callback tracks SSL connection states and errors.
* Initialized by SSL_CTX_set_info_callback. Invoked when
* tb_errorlevel >= TN_NOTICE. Copied from apps/s_cb.c.
*/
void info_cb(SSL *s,int where,int ret) {
char *str="undefined";
int w=where& ~SSL_ST_MASK;
if (w & SSL_ST_CONNECT) str="SSL_connect";
else if (w & SSL_ST_ACCEPT) str="SSL_accept";
if (where & SSL_CB_LOOP)
fprintf(stderr,"%s:%s\n",str,SSL_state_string_long(s));
else if (where & SSL_CB_ALERT) {
str=(where & SSL_CB_READ)?"read":"write";
fprintf(stderr,"SSL3 alert %s:%s:%s\n",
str,
SSL_alert_type_string_long(ret),
SSL_alert_desc_string_long(ret));
}
else if (where & SSL_CB_EXIT) {
if (ret == 0)
fprintf(stderr,"%s:failed in %s\n",str,SSL_state_string_long(s));
else if (ret < 0)
fprintf(stderr,"%s:error in %s\n",str,SSL_state_string_long(s));
}
}
static void __apn_ssl_info_callback(const SSL *ssl, int where, int ret) {
apn_ctx_t *ctx = SSL_CTX_get_ex_data(ssl->ctx, 0);
if (!ctx) {
return;
}
if (where & SSL_CB_LOOP) {
apn_log(ctx, APN_LOG_LEVEL_INFO, "ssl: %s:%s:%s",
(where & SSL_ST_CONNECT) ? "connect" : "undef",
SSL_state_string_long(ssl),
SSL_get_cipher_name(ssl));
} else if (where & SSL_CB_EXIT) {
apn_log(ctx, APN_LOG_LEVEL_INFO, "ssl: %s:%s", (where & SSL_ST_CONNECT) ? "connect" : "undef",
SSL_state_string_long(ssl));
} else if (where & SSL_CB_ALERT) {
apn_log(ctx, APN_LOG_LEVEL_INFO, "ssl: alert %s:%s", (where & SSL_CB_READ) ? "read" : "write",
SSL_state_string_long(ssl), SSL_alert_desc_string_long(ret));
} else if (where & SSL_CB_HANDSHAKE_START) {
apn_log(ctx, APN_LOG_LEVEL_INFO, "ssl: handshake started %s:%s:%s", (where & SSL_CB_READ) ? "read" : "write",
SSL_state_string_long(ssl), SSL_alert_desc_string_long(ret));
}
else if (where & SSL_CB_HANDSHAKE_DONE) {
apn_log(ctx, APN_LOG_LEVEL_INFO, "ssl: handshake done %s:%s:%s", (where & SSL_CB_READ) ? "read" : "write",
SSL_state_string_long(ssl), SSL_alert_desc_string_long(ret));
} else {
apn_log(ctx, APN_LOG_LEVEL_INFO, "ssl: state %s:%s:%s", SSL_state_string_long(ssl),
SSL_alert_type_string_long(ret), SSL_alert_desc_string_long(ret));
}
}
/* SSL info callback, this is used to trace engine state changes
* and to check when the handshake is finished, so we can display
* some cipher and session information and process callbacks.
*/
void ssl_info(SSL *ssl, int where, int ret)
{
int sock;
X509 *cert;
char buf[256];
ssl_appdata *data;
SSL_CIPHER *cipher;
int secret, processed;
/* We're doing non-blocking IO, so we check here if the handshake has
finished */
if (where & SSL_CB_HANDSHAKE_DONE) {
if (!(data = (ssl_appdata *) SSL_get_app_data(ssl)))
return;
/* Callback for completed handshake. Cheaper and more convenient than
using H_tls */
sock = SSL_get_fd(ssl);
if (data->cb)
data->cb(sock);
/* Call TLS binds. We allow scripts to take over or disable displaying of
certificate information. */
if (check_tcl_tls(sock))
return;
putlog(data->loglevel, "*", "TLS: handshake successful. Secure connection "
"established.");
if ((cert = SSL_get_peer_certificate(ssl)))
ssl_showcert(cert, data->loglevel);
else
putlog(data->loglevel, "*", "TLS: peer did not present a certificate");
/* Display cipher information */
cipher = SSL_get_current_cipher(ssl);
processed = SSL_CIPHER_get_bits(cipher, &secret);
putlog(data->loglevel, "*", "TLS: cipher used: %s %s; %d bits (%d secret)",
SSL_CIPHER_get_name(cipher), SSL_CIPHER_get_version(cipher),
processed, secret);
/* secret are the actually secret bits. If processed and secret differ,
the rest of the bits are fixed, i.e. for limited export ciphers */
/* More verbose information, for debugging only */
SSL_CIPHER_description(cipher, buf, sizeof buf);
debug1("TLS: cipher details: %s", buf);
}
/* Display the state of the engine for debugging purposes */
debug1("TLS: state change: %s", SSL_state_string_long(ssl));
}
void cbtls_info(const SSL *s, int where, int ret)
{
const char *str, *state;
int w;
REQUEST *request = SSL_get_ex_data(s, FR_TLS_EX_INDEX_REQUEST);
char buffer[1024];
w = where & ~SSL_ST_MASK;
if (w & SSL_ST_CONNECT) str=" TLS_connect";
else if (w & SSL_ST_ACCEPT) str=" TLS_accept";
else str=" (other)";
state = SSL_state_string_long(s);
state = state ? state : "NULL";
buffer[0] = '\0';
if (where & SSL_CB_LOOP) {
RDEBUG2("%s: %s", str, state);
} else if (where & SSL_CB_HANDSHAKE_START) {
RDEBUG2("%s: %s", str, state);
} else if (where & SSL_CB_HANDSHAKE_DONE) {
RDEBUG2("%s: %s", str, state);
} else if (where & SSL_CB_ALERT) {
str=(where & SSL_CB_READ)?"read":"write";
snprintf(buffer, sizeof(buffer), "TLS Alert %s:%s:%s",
str,
SSL_alert_type_string_long(ret),
SSL_alert_desc_string_long(ret));
} else if (where & SSL_CB_EXIT) {
if (ret == 0) {
snprintf(buffer, sizeof(buffer), "%s: failed in %s",
str, state);
} else if (ret < 0) {
if (SSL_want_read(s)) {
RDEBUG2("%s: Need to read more data: %s",
str, state);
} else {
snprintf(buffer, sizeof(buffer),
"%s: error in %s", str, state);
}
}
}
if (buffer[0] && request) {
RDEBUGE("SSL says: %s", buffer);
}
}
// Nicked straight from the SSL_CTX_set_info_callback man page.
void infoCallback(const SSL *ssl, int where, int ret)
{
const char *str;
int w = where & ~SSL_ST_MASK;
if (w & SSL_ST_CONNECT) {
str = "SSL_connect";
} else if (w & SSL_ST_ACCEPT) {
str = "SSL_accept";
} else {
str = "undefined";
}
if (where & SSL_CB_LOOP) {
fprintf(stderr,"%s: %s\n",str,SSL_state_string_long(ssl));
} else if (where & SSL_CB_ALERT) {
str = (where & SSL_CB_READ)?"read":"write";
fprintf(stderr, "SSL3 alert %s: %s: %s\n",
str,
SSL_alert_type_string_long(ret),
SSL_alert_desc_string_long(ret));
} else if (where & SSL_CB_EXIT) {
if (ret == 0) {
fprintf(stderr, "%s: failed in %s\n",
str, SSL_state_string_long(ssl));
} else if (ret < 0) {
fprintf(stderr, "%s: error in %s\n",
str, SSL_state_string_long(ssl));
}
} else if (where & SSL_CB_HANDSHAKE_START) {
fprintf(stderr, "SSL3 Handshake start %d\n", ret);
} else if (where & SSL_CB_HANDSHAKE_DONE) {
fprintf(stderr, "SSL3 Handshake done %d\n", ret);
} else {
fprintf(stderr,"infoCallback: 0x%04x %d\n", where, ret);
}
}
Sint32 SSLSocket::read(void* ptr, Uint32 size)
{
PEG_METHOD_ENTER(TRC_SSL, "SSLSocket::read()");
Sint32 rc;
PEG_TRACE_CSTRING(TRC_SSL, Tracer::LEVEL4, "---> SSL: (r) ");
PEG_TRACE_CSTRING(TRC_SSL, Tracer::LEVEL4,
SSL_state_string_long(static_cast<SSL*>(_SSLConnection)));
rc = SSL_read(static_cast<SSL*>(_SSLConnection), (char *)ptr, size);
_sslReadErrno = errno;
PEG_METHOD_EXIT();
return rc;
}
static void apps_ssl_info_callback(const SSL * s, int where, int ret)
{
char *str;
int w;
if (var_imapd_tls_loglevel==0) return;
w = where & ~SSL_ST_MASK;
if (w & SSL_ST_CONNECT)
str = "SSL_connect";
else if (w & SSL_ST_ACCEPT)
str = "SSL_accept";
else
str = "undefined";
if (where & SSL_CB_LOOP) {
if (tls_serverengine && (var_imapd_tls_loglevel >= 2))
syslog(LOG_DEBUG, "%s:%s", str, SSL_state_string_long(s));
} else if (where & SSL_CB_ALERT) {
str = (where & SSL_CB_READ) ? "read" : "write";
if ((tls_serverengine && (var_imapd_tls_loglevel >= 2)) ||
((ret & 0xff) != SSL3_AD_CLOSE_NOTIFY))
syslog(LOG_DEBUG, "SSL3 alert %s:%s:%s", str,
SSL_alert_type_string_long(ret),
SSL_alert_desc_string_long(ret));
} else if (where & SSL_CB_EXIT) {
if (ret == 0)
syslog(LOG_DEBUG, "%s:failed in %s",
str, SSL_state_string_long(s));
else if (ret < 0) {
syslog(LOG_DEBUG, "%s:error in %s",
str, SSL_state_string_long(s));
}
}
}
int krypt_do_handshake(krypt_t *kconn, uint8_t *buf, size_t buf_data_size)
{
int ret = 0;
int nbyte = 0;
int status = -1;
if (buf != NULL && buf_data_size > 0) {
nbyte = BIO_write(kconn->network_bio, buf, buf_data_size);
}
ret = SSL_do_handshake(kconn->ssl);
jlog(L_NOTICE, "SSL state: %s", SSL_state_string_long(kconn->ssl));
if (ret > 0 && !SSL_is_init_finished(kconn->ssl)) {
// Need more data to continue ?
jlog(L_ERROR, "handshake need more data to continue ??");
status = 1;
}
else if (ret > 0 && SSL_is_init_finished(kconn->ssl)) {
// Handshake successfully completed
post_handshake_check(kconn);
kconn->status = KRYPT_SECURE;
status = 0;
}
else if (ret == 0) {
// Error
kconn->status = KRYPT_FAIL;
jlog(L_ERROR, "ssl_get_error: %d\n", SSL_get_error(kconn->ssl, ret));
ssl_error_stack();
jlog(L_ERROR, "handshake error");
status = -1;
}
else if (ret < 0) {
// Need more data to continue
status = 1;
}
nbyte = BIO_ctrl_pending(kconn->network_bio);
if (nbyte > 0) { // Read pending data into the BIO
nbyte = BIO_read(kconn->network_bio, kconn->buf_encrypt, kconn->buf_encrypt_size);
kconn->buf_encrypt_data_size = nbyte; // FIXME dynamic buffer
}
return status;
}
static void
info_callback (INFO_CALLBACK_SSL_CONST SSL * s, int where, int ret)
{
if (where & SSL_CB_LOOP)
{
dmsg (D_HANDSHAKE_VERBOSE, "SSL state (%s): %s",
where & SSL_ST_CONNECT ? "connect" :
where & SSL_ST_ACCEPT ? "accept" :
"undefined", SSL_state_string_long (s));
}
else if (where & SSL_CB_ALERT)
{
dmsg (D_HANDSHAKE_VERBOSE, "SSL alert (%s): %s: %s",
where & SSL_CB_READ ? "read" : "write",
SSL_alert_type_string_long (ret),
SSL_alert_desc_string_long (ret));
}
}
/*
* call-seq:
* ssl.state => string
*/
static VALUE
ossl_ssl_get_state(VALUE self)
{
SSL *ssl;
VALUE ret;
Data_Get_Struct(self, SSL, ssl);
if (!ssl) {
rb_warning("SSL session is not started yet.");
return Qnil;
}
ret = rb_str_new2(SSL_state_string(ssl));
if (ruby_verbose) {
rb_str_cat2(ret, ": ");
rb_str_cat2(ret, SSL_state_string_long(ssl));
}
return ret;
}
/*
* Format SSL state into newly allocated string.
* Returns pointer to string that must be freed by caller, or NULL on error.
*/
char *
ssl_ssl_state_to_str(SSL *ssl)
{
char *str = NULL;
int rv;
rv = asprintf(&str, "%08x = %s%s%s%04x = %s (%s) [%s]",
ssl->state,
(ssl->state & SSL_ST_CONNECT) ? "SSL_ST_CONNECT|" : "",
(ssl->state & SSL_ST_ACCEPT) ? "SSL_ST_ACCEPT|" : "",
(ssl->state & SSL_ST_BEFORE) ? "SSL_ST_BEFORE|" : "",
ssl->state & SSL_ST_MASK,
SSL_state_string(ssl),
SSL_state_string_long(ssl),
(ssl->type == SSL_ST_CONNECT) ? "connect socket"
: "accept socket");
return (rv < 0) ? NULL : str;
}
void cbtls_info(const SSL *s, int where, int ret)
{
const char *str, *state;
int w;
EAP_HANDLER *handler = (EAP_HANDLER *)SSL_get_ex_data(s, 0);
REQUEST *request = NULL;
if (handler) request = handler->request;
w = where & ~SSL_ST_MASK;
if (w & SSL_ST_CONNECT) str=" TLS_connect";
else if (w & SSL_ST_ACCEPT) str=" TLS_accept";
else str=" (other)";
state = SSL_state_string_long(s);
state = state ? state : "NULL";
if (where & SSL_CB_LOOP) {
RDEBUG2("%s: %s\n", str, state);
} else if (where & SSL_CB_HANDSHAKE_START) {
RDEBUG2("%s: %s\n", str, state);
} else if (where & SSL_CB_HANDSHAKE_DONE) {
RDEBUG2("%s: %s\n", str, state);
} else if (where & SSL_CB_ALERT) {
str=(where & SSL_CB_READ)?"read":"write";
radlog(L_ERR,"TLS Alert %s:%s:%s\n", str,
SSL_alert_type_string_long(ret),
SSL_alert_desc_string_long(ret));
} else if (where & SSL_CB_EXIT) {
if (ret == 0) {
radlog(L_ERR, "%s:failed in %s\n", str, state);
} else if (ret < 0) {
if (SSL_want_read(s)) {
RDEBUG2("%s: Need to read more data: %s",
str, state);
} else {
radlog(L_ERR, "%s:error in %s\n", str, state);
}
}
}
}
NOEXPORT void info_callback(const SSL *ssl, int where, int ret) {
CLI *c;
SSL_CTX *ctx;
const char *state_string;
c=SSL_get_ex_data((SSL *)ssl, index_cli);
if(c) {
int state=SSL_get_state((SSL *)ssl);
#if 0
s_log(LOG_DEBUG, "state = %x", state);
#endif
/* log the client certificate request (if received) */
#ifndef SSL3_ST_CR_CERT_REQ_A
if(state==TLS_ST_CR_CERT_REQ)
#else
if(state==SSL3_ST_CR_CERT_REQ_A)
#endif
print_client_CA_list(SSL_get_client_CA_list(ssl));
#ifndef SSL3_ST_CR_SRVR_DONE_A
if(state==TLS_ST_CR_SRVR_DONE)
#else
if(state==SSL3_ST_CR_SRVR_DONE_A)
#endif
if(!SSL_get_client_CA_list(ssl))
s_log(LOG_INFO, "Client certificate not requested");
/* prevent renegotiation DoS attack */
if((where&SSL_CB_HANDSHAKE_DONE)
&& c->reneg_state==RENEG_INIT) {
/* first (initial) handshake was completed, remember this,
* so that further renegotiation attempts can be detected */
c->reneg_state=RENEG_ESTABLISHED;
} else if((where&SSL_CB_ACCEPT_LOOP)
&& c->reneg_state==RENEG_ESTABLISHED) {
#ifndef SSL3_ST_SR_CLNT_HELLO_A
if(state==TLS_ST_SR_CLNT_HELLO
|| state==TLS_ST_SR_CLNT_HELLO) {
#else
if(state==SSL3_ST_SR_CLNT_HELLO_A
|| state==SSL23_ST_SR_CLNT_HELLO_A) {
#endif
/* client hello received after initial handshake,
* this means renegotiation -> mark it */
c->reneg_state=RENEG_DETECTED;
}
}
if(c->opt->log_level<LOG_DEBUG) /* performance optimization */
return;
}
if(where & SSL_CB_LOOP) {
state_string=SSL_state_string_long(ssl);
if(strcmp(state_string, "unknown state"))
s_log(LOG_DEBUG, "SSL state (%s): %s",
where & SSL_ST_CONNECT ? "connect" :
where & SSL_ST_ACCEPT ? "accept" :
"undefined", state_string);
} else if(where & SSL_CB_ALERT) {
s_log(LOG_DEBUG, "SSL alert (%s): %s: %s",
where & SSL_CB_READ ? "read" : "write",
SSL_alert_type_string_long(ret),
SSL_alert_desc_string_long(ret));
} else if(where==SSL_CB_HANDSHAKE_DONE) {
ctx=SSL_get_SSL_CTX((SSL *)ssl);
if(c->opt->option.client) {
s_log(LOG_DEBUG, "%6ld client connect(s) requested",
SSL_CTX_sess_connect(ctx));
s_log(LOG_DEBUG, "%6ld client connect(s) succeeded",
SSL_CTX_sess_connect_good(ctx));
s_log(LOG_DEBUG, "%6ld client renegotiation(s) requested",
SSL_CTX_sess_connect_renegotiate(ctx));
} else {
s_log(LOG_DEBUG, "%6ld server accept(s) requested",
SSL_CTX_sess_accept(ctx));
s_log(LOG_DEBUG, "%6ld server accept(s) succeeded",
SSL_CTX_sess_accept_good(ctx));
s_log(LOG_DEBUG, "%6ld server renegotiation(s) requested",
SSL_CTX_sess_accept_renegotiate(ctx));
}
/* according to the source it not only includes internal
and external session caches, but also session tickets */
s_log(LOG_DEBUG, "%6ld session reuse(s)",
SSL_CTX_sess_hits(ctx));
if(!c->opt->option.client) { /* server session cache stats */
s_log(LOG_DEBUG, "%6ld internal session cache item(s)",
SSL_CTX_sess_number(ctx));
s_log(LOG_DEBUG, "%6ld internal session cache fill-up(s)",
SSL_CTX_sess_cache_full(ctx));
s_log(LOG_DEBUG, "%6ld internal session cache miss(es)",
SSL_CTX_sess_misses(ctx));
s_log(LOG_DEBUG, "%6ld external session cache hit(s)",
SSL_CTX_sess_cb_hits(ctx));
s_log(LOG_DEBUG, "%6ld expired session(s) retrieved",
SSL_CTX_sess_timeouts(ctx));
}
}
}
/**************************************** SSL error reporting */
void sslerror(char *txt) { /* OpenSSL error handler */
unsigned long err;
err=ERR_get_error();
if(err) {
sslerror_queue();
sslerror_log(err, txt);
} else {
s_log(LOG_ERR, "%s: Peer suddenly disconnected", txt);
}
}