Changed logging to call TraceEvent directly

This commit is contained in:
Alvin Moore 2018-07-12 13:24:40 -07:00
parent a034acf3bd
commit 6e4265fcc7
4 changed files with 51 additions and 107 deletions

View File

@ -36,24 +36,12 @@
#include <string.h>
#include <limits.h>
TraceEventRefData::TraceEventRefData(const char* type) : traceEvent(new TraceEvent(type)) {
}
TraceEventRefData::TraceEventRefData(Severity sev, const char* type) : traceEvent(new TraceEvent(sev, type)) {
}
TraceEventRefData::TraceEventRefData(const char* type, UID uid) : traceEvent(new TraceEvent(type, uid)) {
}
TraceEventRefData::TraceEventRefData(Severity sev, const char* type, UID uid) : traceEvent(new TraceEvent(sev, type, uid)) {
}
TraceEventRefData::~TraceEventRefData() {
delete traceEvent;
}
FDBLibTLSPolicy::FDBLibTLSPolicy(Reference<FDBLibTLSPlugin> plugin):
plugin(plugin), tls_cfg(NULL), roots(NULL), session_created(false), ca_data_set(false),
cert_data_set(false), key_data_set(false), verify_peers_set(false) {
if ((tls_cfg = tls_config_new()) == NULL) {
logf(SevError, "FDBLibTLSConfigError");
TraceEvent(SevError, "FDBLibTLSConfigError");
throw std::runtime_error("FDBLibTLSConfigError");
}
@ -72,14 +60,14 @@ ITLSSession* FDBLibTLSPolicy::create_session(bool is_client, const char* servern
// servername, since this will be ignored - the servername should be
// matched by the verify criteria instead.
if (verify_peers_set && servername != NULL) {
logf(SevError, "FDBLibTLSVerifyPeersWithServerName");
TraceEvent(SevError, "FDBLibTLSVerifyPeersWithServerName");
return NULL;
}
// If verify peers has not been set, then require a server name to
// avoid an accidental lack of name validation.
if (!verify_peers_set && servername == NULL) {
logf(SevError, "FDBLibTLSNoServerName");
TraceEvent(SevError, "FDBLibTLSNoServerName");
return NULL;
}
}
@ -112,17 +100,6 @@ static int password_cb(char *buf, int size, int rwflag, void *u) {
return plen;
}
// Assumes SevInfo severity
TraceEventRef FDBLibTLSPolicy::logf( const char* type) {
TraceEventRef tev(new TraceEventRefData(type));
tev->trace().suppressFor(1.0, true);
return tev;
}
TraceEventRef FDBLibTLSPolicy::logf( Severity severity, const char* type) {
return TraceEventRef(new TraceEventRefData(severity, type));
}
struct stack_st_X509* FDBLibTLSPolicy::parse_cert_pem(const uint8_t* cert_pem, size_t cert_pem_len) {
struct stack_st_X509 *certs = NULL;
X509 *cert = NULL;
@ -133,18 +110,18 @@ struct stack_st_X509* FDBLibTLSPolicy::parse_cert_pem(const uint8_t* cert_pem, s
if (cert_pem_len > INT_MAX)
goto err;
if ((bio = BIO_new_mem_buf((void *)cert_pem, cert_pem_len)) == NULL) {
logf(SevError, "FDBLibTLSOutOfMemory");
TraceEvent(SevError, "FDBLibTLSOutOfMemory");
goto err;
}
if ((certs = sk_X509_new_null()) == NULL) {
logf(SevError, "FDBLibTLSOutOfMemory");
TraceEvent(SevError, "FDBLibTLSOutOfMemory");
goto err;
}
ERR_clear_error();
while ((cert = PEM_read_bio_X509(bio, NULL, password_cb, NULL)) != NULL) {
if (!sk_X509_push(certs, cert)) {
logf(SevError, "FDBLibTLSOutOfMemory");
TraceEvent(SevError, "FDBLibTLSOutOfMemory");
goto err;
}
}
@ -155,12 +132,12 @@ struct stack_st_X509* FDBLibTLSPolicy::parse_cert_pem(const uint8_t* cert_pem, s
char errbuf[256];
ERR_error_string_n(errnum, errbuf, sizeof(errbuf));
logf(SevError, "FDBLibTLSCertDataError")->trace().detail("LibcryptoErrorMessage", errbuf);
TraceEvent(SevError, "FDBLibTLSCertDataError").detail("LibcryptoErrorMessage", errbuf);
goto err;
}
if (sk_X509_num(certs) < 1) {
logf(SevError, "FDBLibTLSNoCerts");
TraceEvent(SevError, "FDBLibTLSNoCerts");
goto err;
}
@ -178,11 +155,11 @@ struct stack_st_X509* FDBLibTLSPolicy::parse_cert_pem(const uint8_t* cert_pem, s
bool FDBLibTLSPolicy::set_ca_data(const uint8_t* ca_data, int ca_len) {
if (ca_data_set) {
logf(SevError, "FDBLibTLSCAAlreadySet");
TraceEvent(SevError, "FDBLibTLSCAAlreadySet");
return false;
}
if (session_created) {
logf(SevError, "FDBLibTLSPolicyAlreadyActive");
TraceEvent(SevError, "FDBLibTLSPolicyAlreadyActive");
return false;
}
@ -193,7 +170,7 @@ bool FDBLibTLSPolicy::set_ca_data(const uint8_t* ca_data, int ca_len) {
return false;
if (tls_config_set_ca_mem(tls_cfg, ca_data, ca_len) == -1) {
logf(SevError, "FDBLibTLSCAError")->trace().detail("LibTLSErrorMessage", tls_config_error(tls_cfg));
TraceEvent(SevError, "FDBLibTLSCAError").detail("LibTLSErrorMessage", tls_config_error(tls_cfg));
return false;
}
@ -204,16 +181,16 @@ bool FDBLibTLSPolicy::set_ca_data(const uint8_t* ca_data, int ca_len) {
bool FDBLibTLSPolicy::set_cert_data(const uint8_t* cert_data, int cert_len) {
if (cert_data_set) {
logf(SevError, "FDBLibTLSCertAlreadySet");
TraceEvent(SevError, "FDBLibTLSCertAlreadySet");
return false;
}
if (session_created) {
logf(SevError, "FDBLibTLSPolicyAlreadyActive");
TraceEvent(SevError, "FDBLibTLSPolicyAlreadyActive");
return false;
}
if (tls_config_set_cert_mem(tls_cfg, cert_data, cert_len) == -1) {
logf(SevError, "FDBLibTLSCertError")->trace().detail("LibTLSErrorMessage", tls_config_error(tls_cfg));
TraceEvent(SevError, "FDBLibTLSCertError").detail("LibTLSErrorMessage", tls_config_error(tls_cfg));
return false;
}
@ -228,11 +205,11 @@ bool FDBLibTLSPolicy::set_key_data(const uint8_t* key_data, int key_len, const c
bool rc = false;
if (key_data_set) {
logf(SevError, "FDBLibTLSKeyAlreadySet");
TraceEvent(SevError, "FDBLibTLSKeyAlreadySet");
goto err;
}
if (session_created) {
logf(SevError, "FDBLibTLSPolicyAlreadyActive");
TraceEvent(SevError, "FDBLibTLSPolicyAlreadyActive");
goto err;
}
@ -241,7 +218,7 @@ bool FDBLibTLSPolicy::set_key_data(const uint8_t* key_data, int key_len, const c
long len;
if ((bio = BIO_new_mem_buf((void *)key_data, key_len)) == NULL) {
logf(SevError, "FDBLibTLSOutOfMemory");
TraceEvent(SevError, "FDBLibTLSOutOfMemory");
goto err;
}
ERR_clear_error();
@ -251,33 +228,33 @@ bool FDBLibTLSPolicy::set_key_data(const uint8_t* key_data, int key_len, const c
if ((ERR_GET_LIB(errnum) == ERR_LIB_PEM && ERR_GET_REASON(errnum) == PEM_R_BAD_DECRYPT) ||
(ERR_GET_LIB(errnum) == ERR_LIB_EVP && ERR_GET_REASON(errnum) == EVP_R_BAD_DECRYPT)) {
logf(SevError, "FDBLibTLSIncorrectPassword");
TraceEvent(SevError, "FDBLibTLSIncorrectPassword");
} else {
ERR_error_string_n(errnum, errbuf, sizeof(errbuf));
logf(SevError, "FDBLibTLSPrivateKeyError")->trace().detail("LibcryptoErrorMessage", errbuf);
TraceEvent(SevError, "FDBLibTLSPrivateKeyError").detail("LibcryptoErrorMessage", errbuf);
}
goto err;
}
BIO_free(bio);
if ((bio = BIO_new(BIO_s_mem())) == NULL) {
logf(SevError, "FDBLibTLSOutOfMemory");
TraceEvent(SevError, "FDBLibTLSOutOfMemory");
goto err;
}
if (!PEM_write_bio_PrivateKey(bio, key, NULL, NULL, 0, NULL, NULL)) {
logf(SevError, "FDBLibTLSOutOfMemory");
TraceEvent(SevError, "FDBLibTLSOutOfMemory");
goto err;
}
if ((len = BIO_get_mem_data(bio, &data)) <= 0) {
logf(SevError, "FDBLibTLSOutOfMemory");
TraceEvent(SevError, "FDBLibTLSOutOfMemory");
goto err;
}
if (tls_config_set_key_mem(tls_cfg, (const uint8_t *)data, len) == -1) {
logf(SevError, "FDBLibTLSKeyError")->trace().detail("LibTLSErrorMessage", tls_config_error(tls_cfg));
TraceEvent(SevError, "FDBLibTLSKeyError").detail("LibTLSErrorMessage", tls_config_error(tls_cfg));
goto err;
}
} else {
if (tls_config_set_key_mem(tls_cfg, key_data, key_len) == -1) {
logf(SevError, "FDBLibTLSKeyError")->trace().detail("LibTLSErrorMessage", tls_config_error(tls_cfg));
TraceEvent(SevError, "FDBLibTLSKeyError").detail("LibTLSErrorMessage", tls_config_error(tls_cfg));
goto err;
}
}
@ -293,16 +270,16 @@ bool FDBLibTLSPolicy::set_key_data(const uint8_t* key_data, int key_len, const c
bool FDBLibTLSPolicy::set_verify_peers(int count, const uint8_t* verify_peers[], int verify_peers_len[]) {
if (verify_peers_set) {
logf(SevError, "FDBLibTLSVerifyPeersAlreadySet");
TraceEvent(SevError, "FDBLibTLSVerifyPeersAlreadySet");
return false;
}
if (session_created) {
logf(SevError, "FDBLibTLSPolicyAlreadyActive");
TraceEvent(SevError, "FDBLibTLSPolicyAlreadyActive");
return false;
}
if (count < 1) {
logf(SevError, "FDBLibTLSNoVerifyPeers");
TraceEvent(SevError, "FDBLibTLSNoVerifyPeers");
return false;
}
@ -326,7 +303,7 @@ bool FDBLibTLSPolicy::set_verify_peers(int count, const uint8_t* verify_peers[],
} catch ( const std::runtime_error& e ) {
verify_rules.clear();
std::string verifyString((const char*)verify_peers[i], verify_peers_len[i]);
logf(SevError, "FDBLibTLSVerifyPeersParseError")->trace().detail("Config", verifyString);
TraceEvent(SevError, "FDBLibTLSVerifyPeersParseError").detail("Config", verifyString);
return false;
}
}

View File

@ -33,24 +33,6 @@
#include <string>
#include <vector>
class TraceEventRefData;
typedef Reference<TraceEventRefData> TraceEventRef;
class TraceEventRefData : public ReferenceCounted<TraceEventRefData> {
public:
TraceEventRefData(const char* type);
TraceEventRefData(Severity sev, const char* type);
TraceEventRefData(const char* type, UID uid);
TraceEventRefData(Severity sev, const char* type, UID uid);
virtual ~TraceEventRefData();
virtual void addref() { ReferenceCounted<TraceEventRefData>::addref(); }
virtual void delref() { ReferenceCounted<TraceEventRefData>::delref(); }
TraceEvent& trace() { return *traceEvent; }
protected:
TraceEvent* traceEvent;
};
struct FDBLibTLSPolicy: ITLSPolicy, ReferenceCounted<FDBLibTLSPolicy> {
FDBLibTLSPolicy(Reference<FDBLibTLSPlugin> plugin);
virtual ~FDBLibTLSPolicy();
@ -71,9 +53,6 @@ struct FDBLibTLSPolicy: ITLSPolicy, ReferenceCounted<FDBLibTLSPolicy> {
virtual bool set_key_data(const uint8_t* key_data, int key_len, const char* password);
virtual bool set_verify_peers(int count, const uint8_t* verify_peers[], int verify_peers_len[]);
TraceEventRef logf(const char* type); // Assumes SevInfo severity
TraceEventRef logf(Severity, const char* type);
struct tls_config* tls_cfg;
bool session_created;

View File

@ -57,37 +57,39 @@ static ssize_t tls_write_func(struct tls *ctx, const void *buf, size_t buflen, v
return (ssize_t)rv;
}
FDBLibTLSSession::FDBLibTLSSession(Reference<FDBLibTLSPolicy> policy, bool is_client, const char* servername, TLSSendCallbackFunc send_func, void* send_ctx, TLSRecvCallbackFunc recv_func, void* recv_ctx, void* uid) :
FDBLibTLSSession::FDBLibTLSSession(Reference<FDBLibTLSPolicy> policy, bool is_client, const char* servername, TLSSendCallbackFunc send_func, void* send_ctx, TLSRecvCallbackFunc recv_func, void* recv_ctx, void* uidptr) :
tls_ctx(NULL), tls_sctx(NULL), is_client(is_client), policy(policy), send_func(send_func), send_ctx(send_ctx),
recv_func(recv_func), recv_ctx(recv_ctx), handshake_completed(false), uid(uid) {
recv_func(recv_func), recv_ctx(recv_ctx), handshake_completed(false) {
if (uidptr)
uid = * (UID*) uidptr;
if (is_client) {
if ((tls_ctx = tls_client()) == NULL) {
logf(SevError, "FDBLibTLSClientError");
TraceEvent(SevError, "FDBLibTLSClientError", uid);
throw std::runtime_error("FDBLibTLSClientError");
}
if (tls_configure(tls_ctx, policy->tls_cfg) == -1) {
logf(SevError, "FDBLibTLSConfigureError")->trace().detail("LibTLSErrorMessage", tls_error(tls_ctx));
TraceEvent(SevError, "FDBLibTLSConfigureError", uid).detail("LibTLSErrorMessage", tls_error(tls_ctx));
tls_free(tls_ctx);
throw std::runtime_error("FDBLibTLSConfigureError");
}
if (tls_connect_cbs(tls_ctx, tls_read_func, tls_write_func, this, servername) == -1) {
logf(SevError, "FDBLibTLSConnectError")->trace().detail("LibTLSErrorMessage", tls_error(tls_ctx));
TraceEvent(SevError, "FDBLibTLSConnectError", uid).detail("LibTLSErrorMessage", tls_error(tls_ctx));
tls_free(tls_ctx);
throw std::runtime_error("FDBLibTLSConnectError");
}
} else {
if ((tls_sctx = tls_server()) == NULL) {
logf(SevError, "FDBLibTLSServerError");
TraceEvent(SevError, "FDBLibTLSServerError", uid);
throw std::runtime_error("FDBLibTLSServerError");
}
if (tls_configure(tls_sctx, policy->tls_cfg) == -1) {
logf(SevError, "FDBLibTLSConfigureError")->trace().detail("LibTLSErrorMessage", tls_error(tls_ctx));
TraceEvent(SevError, "FDBLibTLSConfigureError", uid).detail("LibTLSErrorMessage", tls_error(tls_ctx));
tls_free(tls_sctx);
throw std::runtime_error("FDBLibTLSConfigureError");
}
if (tls_accept_cbs(tls_sctx, &tls_ctx, tls_read_func, tls_write_func, this) == -1) {
logf(SevError, "FDBLibTLSAcceptError")->trace().detail("LibTLSErrorMessage", tls_error(tls_ctx));
TraceEvent(SevError, "FDBLibTLSAcceptError", uid).detail("LibTLSErrorMessage", tls_error(tls_ctx));
tls_free(tls_sctx);
throw std::runtime_error("FDBLibTLSAcceptError");
}
@ -226,17 +228,6 @@ bool match_criteria(X509* cert, X509_NAME* subject, NID nid, const std::string&
return false;
}
// Assumes SevInfo severity
TraceEventRef FDBLibTLSSession::logf( const char* type) {
auto traceEvent = (uid) ? TraceEventRef(new TraceEventRefData(type, *(UID*) uid)) : TraceEventRef(new TraceEventRefData(type));
traceEvent->trace().suppressFor(1.0, true);
return traceEvent;
}
TraceEventRef FDBLibTLSSession::logf( Severity severity, const char* type) {
return (uid) ? TraceEventRef(new TraceEventRefData(severity, type, *(UID*)uid)) : TraceEventRef(new TraceEventRefData(severity, type));
}
std::tuple<bool,std::string> FDBLibTLSSession::check_verify(Reference<FDBLibTLSVerify> verify, struct stack_st_X509 *certs) {
X509_STORE_CTX *store_ctx = NULL;
X509_NAME *subject, *issuer;
@ -252,7 +243,7 @@ std::tuple<bool,std::string> FDBLibTLSSession::check_verify(Reference<FDBLibTLSV
// Verify the certificate.
if ((store_ctx = X509_STORE_CTX_new()) == NULL) {
logf(SevError, "FDBLibTLSOutOfMemory");
TraceEvent(SevError, "FDBLibTLSOutOfMemory", uid);
reason = "FDBLibTLSOutOfMemory";
goto err;
}
@ -332,7 +323,7 @@ bool FDBLibTLSSession::verify_peer() {
return true;
if ((cert_pem = tls_peer_cert_chain_pem(tls_ctx, &cert_pem_len)) == NULL) {
logf(SevError, "FDBLibTLSNoCertError");
TraceEvent(SevError, "FDBLibTLSNoCertError", uid);
goto err;
}
if ((certs = policy->parse_cert_pem(cert_pem, cert_pem_len)) == NULL)
@ -353,7 +344,7 @@ bool FDBLibTLSSession::verify_peer() {
if (!rc) {
// log the various failure reasons
for (std::string reason : verify_failure_reasons) {
logf(reason.c_str());
TraceEvent(reason.c_str(), uid);
}
}
@ -377,27 +368,27 @@ int FDBLibTLSSession::handshake() {
case TLS_WANT_POLLOUT:
return WANT_WRITE;
default:
logf("FDBLibTLSHandshakeError")->trace().detail("LibcryptoErrorMessage", tls_error(tls_ctx));
TraceEvent("FDBLibTLSHandshakeError", uid).detail("LibcryptoErrorMessage", tls_error(tls_ctx)).suppressFor(1.0, true);
return FAILED;
}
}
int FDBLibTLSSession::read(uint8_t* data, int length) {
if (!handshake_completed) {
logf(SevError, "FDBLibTLSReadHandshakeError");
TraceEvent(SevError, "FDBLibTLSReadHandshakeError");
return FAILED;
}
ssize_t n = tls_read(tls_ctx, data, length);
if (n > 0) {
if (n > INT_MAX) {
logf(SevError, "FDBLibTLSReadOverflow");
TraceEvent(SevError, "FDBLibTLSReadOverflow");
return FAILED;
}
return (int)n;
}
if (n == 0) {
logf("FDBLibTLSReadEOF");
TraceEvent("FDBLibTLSReadEOF").suppressFor(1.0, true);
return FAILED;
}
if (n == TLS_WANT_POLLIN)
@ -405,26 +396,26 @@ int FDBLibTLSSession::read(uint8_t* data, int length) {
if (n == TLS_WANT_POLLOUT)
return WANT_WRITE;
logf("FDBLibTLSReadError")->trace().detail("LibTLSErrorMessage", tls_error(tls_ctx));
TraceEvent("FDBLibTLSReadError", uid).detail("LibTLSErrorMessage", tls_error(tls_ctx)).suppressFor(1.0, true);
return FAILED;
}
int FDBLibTLSSession::write(const uint8_t* data, int length) {
if (!handshake_completed) {
logf(SevError, "FDBLibTLSWriteHandshakeError");
TraceEvent(SevError, "FDBLibTLSWriteHandshakeError", uid);
return FAILED;
}
ssize_t n = tls_write(tls_ctx, data, length);
if (n > 0) {
if (n > INT_MAX) {
logf(SevError, "FDBLibTLSWriteOverflow");
TraceEvent(SevError, "FDBLibTLSWriteOverflow", uid);
return FAILED;
}
return (int)n;
}
if (n == 0) {
logf("FDBLibTLSWriteEOF");
TraceEvent("FDBLibTLSWriteEOF", uid).suppressFor(1.0, true);
return FAILED;
}
if (n == TLS_WANT_POLLIN)
@ -432,6 +423,6 @@ int FDBLibTLSSession::write(const uint8_t* data, int length) {
if (n == TLS_WANT_POLLOUT)
return WANT_WRITE;
logf("FDBLibTLSWriteError")->trace().detail("LibTLSErrorMessage", tls_error(tls_ctx));
TraceEvent("FDBLibTLSWriteError", uid).detail("LibTLSErrorMessage", tls_error(tls_ctx)).suppressFor(1.0, true);
return FAILED;
}

View File

@ -47,9 +47,6 @@ struct FDBLibTLSSession : ITLSSession, ReferenceCounted<FDBLibTLSSession> {
Reference<FDBLibTLSPolicy> policy;
TraceEventRef logf(const char* type); // Assumes SevInfo severity
TraceEventRef logf(Severity, const char* type);
bool is_client;
struct tls *tls_ctx;
@ -62,7 +59,7 @@ struct FDBLibTLSSession : ITLSSession, ReferenceCounted<FDBLibTLSSession> {
bool handshake_completed;
void* uid;
UID uid;
};
#endif /* FDB_LIBTLS_SESSION_H */