You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@trafficserver.apache.org by sh...@apache.org on 2015/07/10 14:02:11 UTC
trafficserver git commit: TS-3534: Wiretracing SSL Connections. This
closes #246.
Repository: trafficserver
Updated Branches:
refs/heads/master dffd7f892 -> 6e3ce5022
TS-3534: Wiretracing SSL Connections. This closes #246.
Project: http://git-wip-us.apache.org/repos/asf/trafficserver/repo
Commit: http://git-wip-us.apache.org/repos/asf/trafficserver/commit/6e3ce502
Tree: http://git-wip-us.apache.org/repos/asf/trafficserver/tree/6e3ce502
Diff: http://git-wip-us.apache.org/repos/asf/trafficserver/diff/6e3ce502
Branch: refs/heads/master
Commit: 6e3ce5022d67a9c4098595d3d45e24a3c697c80c
Parents: dffd7f8
Author: es@yahoo-inc.com <es...@yahoo-inc.com>
Authored: Thu Oct 2 12:27:56 2014 -0700
Committer: shinrich <sh...@yahoo-inc.com>
Committed: Fri Jul 10 07:00:32 2015 -0500
----------------------------------------------------------------------
iocore/net/Makefile.am | 1 +
iocore/net/P_SSLConfig.h | 7 ++
iocore/net/P_SSLNetVConnection.h | 11 ++
iocore/net/P_UnixNetVConnection.h | 20 ++++
iocore/net/SSLConfig.cc | 32 +++++-
iocore/net/SSLNetVConnection.cc | 191 +++++++++++++++++++++++++++++++--
iocore/net/SSLUtils.cc | 9 +-
iocore/net/UnixNetVConnection.cc | 46 +++++++-
mgmt/RecordsConfig.cc | 8 ++
proxy/http/HttpSM.cc | 29 ++++-
proxy/logging/Log.cc | 49 +++++++++
proxy/logging/Log.h | 15 ++-
12 files changed, 403 insertions(+), 15 deletions(-)
----------------------------------------------------------------------
http://git-wip-us.apache.org/repos/asf/trafficserver/blob/6e3ce502/iocore/net/Makefile.am
----------------------------------------------------------------------
diff --git a/iocore/net/Makefile.am b/iocore/net/Makefile.am
index 81c07ab..7c4b440 100644
--- a/iocore/net/Makefile.am
+++ b/iocore/net/Makefile.am
@@ -25,6 +25,7 @@ AM_CPPFLAGS = \
-I$(top_srcdir)/proxy \
-I$(top_srcdir)/proxy/hdrs \
-I$(top_srcdir)/proxy/shared \
+ -I$(top_srcdir)/proxy/logging \
-I$(top_srcdir)/mgmt \
-I$(top_srcdir)/mgmt/utils \
-I$(top_srcdir)/proxy/api/ts \
http://git-wip-us.apache.org/repos/asf/trafficserver/blob/6e3ce502/iocore/net/P_SSLConfig.h
----------------------------------------------------------------------
diff --git a/iocore/net/P_SSLConfig.h b/iocore/net/P_SSLConfig.h
index 1a6cd60..5c582d1 100644
--- a/iocore/net/P_SSLConfig.h
+++ b/iocore/net/P_SSLConfig.h
@@ -98,6 +98,13 @@ struct SSLConfigParams : public ConfigInfo {
static size_t session_cache_max_bucket_size;
static bool session_cache_skip_on_lock_contention;
+ // TS-3435 Wiretracing for SSL Connections
+ static int ssl_wire_trace_enabled;
+ static char * ssl_wire_trace_addr;
+ static IpAddr * ssl_wire_trace_ip;
+ static int ssl_wire_trace_percentage;
+ static char * ssl_wire_trace_server_name;
+
static init_ssl_ctx_func init_ssl_ctx_cb;
void initialize();
http://git-wip-us.apache.org/repos/asf/trafficserver/blob/6e3ce502/iocore/net/P_SSLNetVConnection.h
----------------------------------------------------------------------
diff --git a/iocore/net/P_SSLNetVConnection.h b/iocore/net/P_SSLNetVConnection.h
index 6a583f5..678035b 100644
--- a/iocore/net/P_SSLNetVConnection.h
+++ b/iocore/net/P_SSLNetVConnection.h
@@ -253,6 +253,16 @@ public:
return eosRcvd;
}
+ bool getSSLTrace() const {
+ return sslTrace || super::origin_trace;
+ };
+
+ void setSSLTrace(bool state){
+ sslTrace = state;
+ };
+
+ bool computeSSLTrace();
+
private:
SSLNetVConnection(const SSLNetVConnection &);
SSLNetVConnection &operator=(const SSLNetVConnection &);
@@ -294,6 +304,7 @@ private:
MIOBuffer *iobuf;
IOBufferReader *reader;
bool eosRcvd;
+ bool sslTrace;
};
typedef int (SSLNetVConnection::*SSLNetVConnHandler)(int, void *);
http://git-wip-us.apache.org/repos/asf/trafficserver/blob/6e3ce502/iocore/net/P_UnixNetVConnection.h
----------------------------------------------------------------------
diff --git a/iocore/net/P_UnixNetVConnection.h b/iocore/net/P_UnixNetVConnection.h
index e11640b..5b3cd9d 100644
--- a/iocore/net/P_UnixNetVConnection.h
+++ b/iocore/net/P_UnixNetVConnection.h
@@ -261,6 +261,11 @@ public:
ink_hrtime submit_time;
OOB_callback *oob_ptr;
bool from_accept_thread;
+
+ // es - origin_trace associated connections
+ bool origin_trace;
+ const sockaddr *origin_trace_addr;
+ int origin_trace_port;
int startEvent(int event, Event *e);
int acceptEvent(int event, Event *e);
@@ -277,6 +282,21 @@ public:
virtual void apply_options();
friend void write_to_net_io(NetHandler *, UnixNetVConnection *, EThread *);
+
+ void setOriginTrace(bool t)
+ {
+ origin_trace = t;
+ }
+
+ void setOriginTraceAddr(const sockaddr *addr)
+ {
+ origin_trace_addr = addr;
+ }
+
+ void setOriginTracePort(int port)
+ {
+ origin_trace_port = port;
+ }
};
extern ClassAllocator<UnixNetVConnection> netVCAllocator;
http://git-wip-us.apache.org/repos/asf/trafficserver/blob/6e3ce502/iocore/net/SSLConfig.cc
----------------------------------------------------------------------
diff --git a/iocore/net/SSLConfig.cc b/iocore/net/SSLConfig.cc
index 0690655..28a9662 100644
--- a/iocore/net/SSLConfig.cc
+++ b/iocore/net/SSLConfig.cc
@@ -52,10 +52,16 @@ int SSLConfigParams::ssl_handshake_timeout_in = 0;
size_t SSLConfigParams::session_cache_number_buckets = 1024;
bool SSLConfigParams::session_cache_skip_on_lock_contention = false;
size_t SSLConfigParams::session_cache_max_bucket_size = 100;
-
init_ssl_ctx_func SSLConfigParams::init_ssl_ctx_cb = NULL;
-static ConfigUpdateHandler<SSLCertificateConfig> *sslCertUpdate;
+// TS-3534 Wiretracing for SSL Connections
+int SSLConfigParams::ssl_wire_trace_enabled = 0;
+char *SSLConfigParams::ssl_wire_trace_addr = NULL;
+IpAddr * SSLConfigParams::ssl_wire_trace_ip = NULL;
+int SSLConfigParams::ssl_wire_trace_percentage = 0;
+char *SSLConfigParams::ssl_wire_trace_server_name = NULL;
+
+static ConfigUpdateHandler<SSLCertificateConfig> * sslCertUpdate;
SSLConfigParams::SSLConfigParams()
{
@@ -97,6 +103,7 @@ SSLConfigParams::cleanup()
ats_free_null(cipherSuite);
ats_free_null(client_cipherSuite);
ats_free_null(dhparamsFile);
+ ats_free_null(ssl_wire_trace_ip);
clientCertLevel = client_verify_depth = verify_depth = clientVerify = 0;
}
@@ -297,6 +304,27 @@ SSLConfigParams::initialize()
ats_free(ssl_client_ca_cert_filename);
REC_ReadConfigInt32(ssl_allow_client_renegotiation, "proxy.config.ssl.allow_client_renegotiation");
+
+ //SSL Wire Trace configurations
+ REC_ReadConfigInteger(ssl_wire_trace_enabled, "proxy.config.ssl.wire_trace_enabled");
+ if(ssl_wire_trace_enabled){
+ // wire trace specific source ip
+ REC_ReadConfigStringAlloc(ssl_wire_trace_addr, "proxy.config.ssl.wire_trace_addr");
+ if(ssl_wire_trace_addr){
+ ssl_wire_trace_ip = new IpAddr();
+ ssl_wire_trace_ip->load(ssl_wire_trace_addr);
+ } else {
+ ssl_wire_trace_ip = NULL;
+ }
+ // wire trace percentage of requests
+ REC_ReadConfigInteger(ssl_wire_trace_percentage, "proxy.config.ssl.wire_trace_percentage");
+ REC_ReadConfigStringAlloc(ssl_wire_trace_server_name, "proxy.config.ssl.wire_trace_server_name");
+ } else {
+ ssl_wire_trace_addr = NULL;
+ ssl_wire_trace_ip = NULL;
+ ssl_wire_trace_percentage = 0;
+ ssl_wire_trace_server_name = NULL;
+ }
}
void
http://git-wip-us.apache.org/repos/asf/trafficserver/blob/6e3ce502/iocore/net/SSLNetVConnection.cc
----------------------------------------------------------------------
diff --git a/iocore/net/SSLNetVConnection.cc b/iocore/net/SSLNetVConnection.cc
index 153aa19..614d39a 100644
--- a/iocore/net/SSLNetVConnection.cc
+++ b/iocore/net/SSLNetVConnection.cc
@@ -25,7 +25,12 @@
#include "P_Net.h"
#include "P_SSLNextProtocolSet.h"
#include "P_SSLUtils.h"
-#include "InkAPIInternal.h" // Added to include the ssl_hook definitions
+#include "InkAPIInternal.h" // Added to include the ssl_hook definitions
+#include "P_SSLConfig.h"
+#include "Log.h"
+
+#include <climits>
+#include <string>
#if !TS_USE_SET_RBIO
// Defined in SSLInternal.c, should probably make a separate include
@@ -194,6 +199,9 @@ ssl_read_from_net(SSLNetVConnection *sslvc, EThread *lthread, int64_t &ret)
int64_t block_write_avail = 0;
ssl_error_t sslErr = SSL_ERROR_NONE;
int64_t nread = 0;
+
+ bool trace = sslvc->getSSLTrace();
+ Debug("ssl", "trace=%s", trace ? "TRUE" : "FALSE");
for (bytes_read = 0; (b != 0) && (sslErr == SSL_ERROR_NONE); b = b->next) {
block_write_avail = b->write_avail();
@@ -206,6 +214,17 @@ ssl_read_from_net(SSLNetVConnection *sslvc, EThread *lthread, int64_t &ret)
sslErr = SSLReadBuffer(sslvc->ssl, b->end() + offset, block_write_avail, nread);
Debug("ssl", "[SSL_NetVConnection::ssl_read_from_net] nread=%d", (int)nread);
+ if (!sslvc->origin_trace) {
+ TraceIn((0 < nread && trace), sslvc->get_remote_addr(), sslvc->get_remote_port(),
+ "WIRE TRACE\tbytes=%d\n%.*s", (int)nread, (int)nread, b->end() + offset);
+ } else {
+ char origin_trace_ip[INET6_ADDRSTRLEN];
+ ats_ip_ntop(sslvc->origin_trace_addr, origin_trace_ip, sizeof (origin_trace_ip));
+ TraceIn((0 < nread && trace), sslvc->get_remote_addr(), sslvc->get_remote_port(),
+ "CLIENT %s:%d\ttbytes=%d\n%.*s", origin_trace_ip, sslvc->origin_trace_port,
+ (int)nread, (int)nread, b->end() + offset);
+ }
+
switch (sslErr) {
case SSL_ERROR_NONE:
@@ -234,30 +253,43 @@ ssl_read_from_net(SSLNetVConnection *sslvc, EThread *lthread, int64_t &ret)
Debug("ssl.error", "[SSL_NetVConnection::ssl_read_from_net] SSL_ERROR_WOULD_BLOCK(read)");
break;
case SSL_ERROR_WANT_X509_LOOKUP:
+ TraceIn(trace, sslvc->get_remote_addr(), sslvc->get_remote_port(),
+ "Want X509 lookup");
event = SSL_READ_WOULD_BLOCK;
SSL_INCREMENT_DYN_STAT(ssl_error_want_x509_lookup);
Debug("ssl.error", "[SSL_NetVConnection::ssl_read_from_net] SSL_ERROR_WOULD_BLOCK(read/x509 lookup)");
break;
case SSL_ERROR_SYSCALL:
+ TraceIn(trace, sslvc->get_remote_addr(), sslvc->get_remote_port(),
+ "Syscall Error: %s", strerror(errno));
SSL_INCREMENT_DYN_STAT(ssl_error_syscall);
if (nread != 0) {
// not EOF
event = SSL_READ_ERROR;
ret = errno;
Debug("ssl.error", "[SSL_NetVConnection::ssl_read_from_net] SSL_ERROR_SYSCALL, underlying IO error: %s", strerror(errno));
+ TraceIn(trace, sslvc->get_remote_addr(), sslvc->get_remote_port(),
+ "Underlying IO error: %d", errno);
} else {
// then EOF observed, treat it as EOS
event = SSL_READ_EOS;
- // Error("[SSL_NetVConnection::ssl_read_from_net] SSL_ERROR_SYSCALL, EOF observed violating SSL protocol");
+ //Error("[SSL_NetVConnection::ssl_read_from_net] SSL_ERROR_SYSCALL, EOF observed violating SSL protocol");
+ TraceIn(trace, sslvc->get_remote_addr(), sslvc->get_remote_port(),
+ "EOF observed violating SSL protocol");
}
break;
case SSL_ERROR_ZERO_RETURN:
+ TraceIn(trace, sslvc->get_remote_addr(), sslvc->get_remote_port(),
+ "Connection closed by peer");
event = SSL_READ_EOS;
SSL_INCREMENT_DYN_STAT(ssl_error_zero_return);
Debug("ssl.error", "[SSL_NetVConnection::ssl_read_from_net] SSL_ERROR_ZERO_RETURN");
break;
case SSL_ERROR_SSL:
default:
+ TraceIn(trace, sslvc->get_remote_addr(), sslvc->get_remote_port(),
+ "SSL Error: sslErr=%d, errno=%d", sslErr,
+ errno);
event = SSL_READ_ERROR;
ret = errno;
SSL_CLR_ERR_INCR_DYN_STAT(sslvc, ssl_error_ssl, "[SSL_NetVConnection::ssl_read_from_net]: errno=%d", errno);
@@ -269,6 +301,7 @@ ssl_read_from_net(SSLNetVConnection *sslvc, EThread *lthread, int64_t &ret)
if (bytes_read > 0) {
Debug("ssl", "[SSL_NetVConnection::ssl_read_from_net] bytes_read=%" PRId64, bytes_read);
+
buf.writer()->fill(bytes_read);
s->vio.ndone += bytes_read;
sslvc->netActivity(lthread);
@@ -440,6 +473,7 @@ SSLNetVConnection::net_read_io(NetHandler *nh, EThread *lthread)
// so it will get forwarded onto the origin server
if (!this->getSSLHandShakeComplete()) {
this->sslHandShakeComplete = 1;
+
// Copy over all data already read in during the SSL_accept
// (the client hello message)
NetState *s = &this->read;
@@ -670,7 +704,10 @@ SSLNetVConnection::load_buffer_and_write(int64_t towrite, int64_t &wattempted, i
if (HttpProxyPort::TRANSPORT_BLIND_TUNNEL == this->attributes) {
return this->super::load_buffer_and_write(towrite, wattempted, total_written, buf, needs);
}
-
+
+ bool trace = getSSLTrace();
+ Debug("ssl", "trace=%s", trace ? "TRUE" : "FALSE");
+
do {
// check if we have done this block
l = b->read_avail();
@@ -716,6 +753,17 @@ SSLNetVConnection::load_buffer_and_write(int64_t towrite, int64_t &wattempted, i
towrite, b);
err = SSLWriteBuffer(ssl, b->start() + offset, l, r);
+ if (!origin_trace) {
+ TraceOut((0 < r && trace), get_remote_addr(), get_remote_port(),
+ "WIRE TRACE\tbytes=%d\n%.*s", (int)r, (int)r, b->start() + offset);
+ } else {
+ char origin_trace_ip[INET6_ADDRSTRLEN];
+ ats_ip_ntop(origin_trace_addr, origin_trace_ip, sizeof (origin_trace_ip));
+ TraceOut((0 < r && trace), get_remote_addr(), get_remote_port(),
+ "CLIENT %s:%d\ttbytes=%d\n%.*s", origin_trace_ip, origin_trace_port,
+ (int)r, (int)r, b->start() + offset);
+ }
+
if (r == l) {
wattempted = total_written;
}
@@ -757,29 +805,38 @@ SSLNetVConnection::load_buffer_and_write(int64_t towrite, int64_t &wattempted, i
break;
case SSL_ERROR_WANT_WRITE:
case SSL_ERROR_WANT_X509_LOOKUP: {
- if (SSL_ERROR_WANT_WRITE == err)
+ if (SSL_ERROR_WANT_WRITE == err) {
SSL_INCREMENT_DYN_STAT(ssl_error_want_write);
- else if (SSL_ERROR_WANT_X509_LOOKUP == err)
+ } else if (SSL_ERROR_WANT_X509_LOOKUP == err) {
SSL_INCREMENT_DYN_STAT(ssl_error_want_x509_lookup);
-
+ TraceOut(trace, get_remote_addr(), get_remote_port(),
+ "Want X509 lookup");
+ }
+
needs |= EVENTIO_WRITE;
r = -EAGAIN;
Debug("ssl.error", "SSL_write-SSL_ERROR_WANT_WRITE");
break;
}
case SSL_ERROR_SYSCALL:
+ TraceOut(trace, get_remote_addr(), get_remote_port(),
+ "Syscall Error: %s", strerror(errno));
r = -errno;
SSL_INCREMENT_DYN_STAT(ssl_error_syscall);
Debug("ssl.error", "SSL_write-SSL_ERROR_SYSCALL");
break;
// end of stream
case SSL_ERROR_ZERO_RETURN:
+ TraceOut(trace, get_remote_addr(), get_remote_port(),
+ "SSL Error: zero return");
r = -errno;
SSL_INCREMENT_DYN_STAT(ssl_error_zero_return);
Debug("ssl.error", "SSL_write-SSL_ERROR_ZERO_RETURN");
break;
case SSL_ERROR_SSL:
default:
+ TraceOut(trace, get_remote_addr(), get_remote_port(),
+ "SSL Error: sslErr=%d, errno=%d", err, errno);
r = -errno;
SSL_CLR_ERR_INCR_DYN_STAT(this, ssl_error_ssl, "SSL_write-SSL_ERROR_SSL errno=%d", errno);
break;
@@ -793,7 +850,7 @@ SSLNetVConnection::SSLNetVConnection()
sslHandShakeComplete(false), sslClientConnection(false), sslClientRenegotiationAbort(false), sslSessionCacheHit(false),
handShakeBuffer(NULL), handShakeHolder(NULL), handShakeReader(NULL), handShakeBioStored(0),
sslPreAcceptHookState(SSL_HOOKS_INIT), sslHandshakeHookState(HANDSHAKE_HOOKS_PRE), npnSet(NULL), npnEndpoint(NULL),
- sessionAcceptPtr(NULL), iobuf(NULL), reader(NULL), eosRcvd(false)
+ sessionAcceptPtr(NULL), iobuf(NULL), reader(NULL), eosRcvd(false), sslTrace(false)
{
}
@@ -885,6 +942,7 @@ SSLNetVConnection::free(EThread *t)
eosRcvd = false;
sslHandShakeComplete = false;
free_handshake_buffers();
+ sslTrace=false;
if (from_accept_thread) {
sslNetVCAllocator.free(this);
@@ -937,6 +995,14 @@ SSLNetVConnection::sslStartHandShake(int event, int &err)
// to negotiate a SSL session, but it's enough to trampoline us into the SNI callback where we
// can select the right server certificate.
this->ssl = make_ssl_connection(lookup->defaultContext(), this);
+#if !(TS_USE_TLS_SNI)
+ // set SSL trace
+ if(SSLConfigParams::ssl_wire_trace_enabled){
+ bool trace = computeSSLTrace();
+ Debug("ssl", "sslnetvc. setting trace to=%s", trace ? "true" : "false");
+ setSSLTrace(trace);
+ }
+#endif
}
if (this->ssl == NULL) {
@@ -1038,6 +1104,8 @@ SSLNetVConnection::sslServerHandShakeEvent(int &err)
}
ssl_error_t ssl_error = SSLAccept(ssl);
+ bool trace = getSSLTrace();
+ Debug("ssl", "trace=%s", trace ? "TRUE" : "FALSE");
if (ssl_error != SSL_ERROR_NONE) {
err = errno;
@@ -1067,6 +1135,10 @@ SSLNetVConnection::sslServerHandShakeEvent(int &err)
}
sslHandShakeComplete = true;
+
+ TraceIn(trace, get_remote_addr(), get_remote_port(),
+ "SSL server handshake completed successfully");
+ // do we want to include cert info in trace?
if (sslHandshakeBeginTime) {
const ink_hrtime ssl_handshake_time = Thread::get_hrtime() - sslHandshakeBeginTime;
@@ -1108,30 +1180,46 @@ SSLNetVConnection::sslServerHandShakeEvent(int &err)
}
Debug("ssl", "client selected next protocol '%.*s'", len, proto);
+ TraceIn(trace, get_remote_addr(), get_remote_port(),
+ "client selected next protocol'%.*s'", len, proto);
} else {
Debug("ssl", "client did not select a next protocol");
+ TraceIn(trace, get_remote_addr(), get_remote_port(),
+ "client did not select a next protocol");
}
}
return EVENT_DONE;
case SSL_ERROR_WANT_CONNECT:
+ TraceIn(trace, get_remote_addr(), get_remote_port(),
+ "SSL server handshake ERROR_WANT_CONNECT");
return SSL_HANDSHAKE_WANT_CONNECT;
case SSL_ERROR_WANT_WRITE:
+ TraceIn(trace, get_remote_addr(), get_remote_port(),
+ "SSL server handshake ERROR_WANT_WRITE");
return SSL_HANDSHAKE_WANT_WRITE;
case SSL_ERROR_WANT_READ:
+ TraceIn(trace, get_remote_addr(), get_remote_port(),
+ "SSL server handshake ERROR_WANT_READ");
return SSL_HANDSHAKE_WANT_READ;
// This value is only defined in openssl has been patched to
// enable the sni callback to break out of the SSL_accept processing
#ifdef SSL_ERROR_WANT_SNI_RESOLVE
case SSL_ERROR_WANT_X509_LOOKUP:
+ TraceIn(trace, get_remote_addr(), get_remote_port(),
+ "SSL server handshake ERROR_WANT_X509_LOOKUP");
return EVENT_CONT;
case SSL_ERROR_WANT_SNI_RESOLVE:
+ TraceIn(trace, get_remote_addr(), get_remote_port(),
+ "SSL server handshake ERROR_WANT_SNI_RESOLVE");
#elif SSL_ERROR_WANT_X509_LOOKUP
case SSL_ERROR_WANT_X509_LOOKUP:
+ TraceIn(trace, get_remote_addr(), get_remote_port(),
+ "SSL server handshake ERROR_WANT_X509_LOOKUP");
#endif
#if defined(SSL_ERROR_WANT_SNI_RESOLVE) || defined(SSL_ERROR_WANT_X509_LOOKUP)
if (this->attributes == HttpProxyPort::TRANSPORT_BLIND_TUNNEL || TS_SSL_HOOK_OP_TUNNEL == hookOpRequested) {
@@ -1145,14 +1233,27 @@ SSLNetVConnection::sslServerHandShakeEvent(int &err)
#endif
case SSL_ERROR_WANT_ACCEPT:
+ TraceIn(trace, get_remote_addr(), get_remote_port(),
+ "SSL server handshake ERROR_WANT_ACCEPT");
return EVENT_CONT;
case SSL_ERROR_SSL:
SSL_CLR_ERR_INCR_DYN_STAT(this, ssl_error_ssl, "SSLNetVConnection::sslServerHandShakeEvent, SSL_ERROR_SSL errno=%d", errno);
- // fall through
+ TraceIn(trace, get_remote_addr(), get_remote_port(),
+ "SSL server handshake ERROR_SSL");
+ return EVENT_ERROR;
+
case SSL_ERROR_ZERO_RETURN:
+ TraceIn(trace, get_remote_addr(), get_remote_port(),
+ "SSL server handshake ERROR_ZERO_RETURN");
+ return EVENT_ERROR;
case SSL_ERROR_SYSCALL:
+ TraceIn(trace, get_remote_addr(), get_remote_port(),
+ "SSL server handshake ERROR_SYSCALL");
+ return EVENT_ERROR;
default:
+ TraceIn(trace, get_remote_addr(), get_remote_port(),
+ "SSL server handshake ERROR_OTHER");
return EVENT_ERROR;
}
}
@@ -1175,6 +1276,9 @@ SSLNetVConnection::sslClientHandShakeEvent(int &err)
SSL_set_ex_data(ssl, get_ssl_client_data_index(), this);
ssl_error_t ssl_error = SSLConnect(ssl);
+ bool trace = getSSLTrace();
+ Debug("ssl", "trace=%s", trace ? "TRUE" : "FALSE");
+
switch (ssl_error) {
case SSL_ERROR_NONE:
if (is_debug_tag_set("ssl")) {
@@ -1192,39 +1296,57 @@ SSLNetVConnection::sslClientHandShakeEvent(int &err)
}
SSL_INCREMENT_DYN_STAT(ssl_total_success_handshake_count_out_stat);
+ TraceIn(trace, get_remote_addr(), get_remote_port(),
+ "SSL client handshake completed successfully");
+ // do we want to include cert info in trace?
+
sslHandShakeComplete = true;
return EVENT_DONE;
case SSL_ERROR_WANT_WRITE:
Debug("ssl.error", "SSLNetVConnection::sslClientHandShakeEvent, SSL_ERROR_WANT_WRITE");
SSL_INCREMENT_DYN_STAT(ssl_error_want_write);
+ TraceIn(trace, get_remote_addr(), get_remote_port(),
+ "SSL client handshake ERROR_WANT_WRITE");
return SSL_HANDSHAKE_WANT_WRITE;
case SSL_ERROR_WANT_READ:
SSL_INCREMENT_DYN_STAT(ssl_error_want_read);
Debug("ssl.error", "SSLNetVConnection::sslClientHandShakeEvent, SSL_ERROR_WANT_READ");
+ TraceIn(trace, get_remote_addr(), get_remote_port(),
+ "SSL client handshake ERROR_WANT_READ");
return SSL_HANDSHAKE_WANT_READ;
case SSL_ERROR_WANT_X509_LOOKUP:
SSL_INCREMENT_DYN_STAT(ssl_error_want_x509_lookup);
Debug("ssl.error", "SSLNetVConnection::sslClientHandShakeEvent, SSL_ERROR_WANT_X509_LOOKUP");
+ TraceIn(trace, get_remote_addr(), get_remote_port(),
+ "SSL client handshake ERROR_WANT_X509_LOOKUP");
break;
case SSL_ERROR_WANT_ACCEPT:
+ TraceIn(trace, get_remote_addr(), get_remote_port(),
+ "SSL client handshake ERROR_WANT_ACCEPT");
return SSL_HANDSHAKE_WANT_ACCEPT;
case SSL_ERROR_WANT_CONNECT:
+ TraceIn(trace, get_remote_addr(), get_remote_port(),
+ "SSL client handshake ERROR_WANT_CONNECT");
break;
case SSL_ERROR_ZERO_RETURN:
SSL_INCREMENT_DYN_STAT(ssl_error_zero_return);
Debug("ssl.error", "SSLNetVConnection::sslClientHandShakeEvent, EOS");
+ TraceIn(trace, get_remote_addr(), get_remote_port(),
+ "SSL client handshake EOS");
return EVENT_ERROR;
case SSL_ERROR_SYSCALL:
err = errno;
SSL_INCREMENT_DYN_STAT(ssl_error_syscall);
Debug("ssl.error", "SSLNetVConnection::sslClientHandShakeEvent, syscall");
+ TraceIn(trace, get_remote_addr(), get_remote_port(),
+ "SSL client handshake Syscall Error: %s", strerror(errno));
return EVENT_ERROR;
break;
@@ -1235,6 +1357,9 @@ SSLNetVConnection::sslClientHandShakeEvent(int &err)
// FIXME -- This triggers a retry on cases of cert validation errors....
Debug("ssl", "SSLNetVConnection::sslClientHandShakeEvent, SSL_ERROR_SSL");
SSL_CLR_ERR_INCR_DYN_STAT(this, ssl_error_ssl, "SSLNetVConnection::sslClientHandShakeEvent, SSL_ERROR_SSL errno=%d", errno);
+ Debug("ssl.error", "SSLNetVConnection::sslClientHandShakeEvent, SSL_ERROR_SSL");
+ TraceIn(trace, get_remote_addr(), get_remote_port(),
+ "SSL client handshake SSL_ERROR");
return EVENT_ERROR;
break;
}
@@ -1375,3 +1500,53 @@ SSLNetVConnection::callHooks(TSHttpHookID eventId)
this->sslHandshakeHookState = holdState;
return reenabled;
}
+
+bool
+SSLNetVConnection::computeSSLTrace()
+{
+ // this has to happen before the handshake or else sni_servername will be NULL
+#if TS_USE_TLS_SNI
+ bool sni_trace;
+ if (ssl) {
+ const char *ssl_servername = SSL_get_servername(ssl, TLSEXT_NAMETYPE_host_name);
+ char *wire_trace_server_name = SSLConfigParams::ssl_wire_trace_server_name;
+ Debug("ssl", "for wiretrace, ssl_servername=%s, wire_trace_server_name=%s", ssl_servername, wire_trace_server_name);
+ sni_trace = ssl_servername && wire_trace_server_name && (0 == strcmp(wire_trace_server_name, ssl_servername));
+ } else {
+ sni_trace = false;
+ }
+#else
+ bool sni_trace = false;
+#endif
+
+ //count based on ip only if they set an IP value
+ const sockaddr *remote_addr = get_remote_addr();
+ bool ip_trace = false;
+ if (SSLConfigParams::ssl_wire_trace_ip) {
+ ip_trace = (*SSLConfigParams::ssl_wire_trace_ip == remote_addr);
+ }
+
+ //count based on percentage
+ int percentage = SSLConfigParams::ssl_wire_trace_percentage;
+ int random;
+ bool trace;
+
+ // we only generate random numbers as needed (to maintain correct percentage)
+ if (SSLConfigParams::ssl_wire_trace_server_name && SSLConfigParams::ssl_wire_trace_ip) {
+ random = this_ethread()->generator.random() % 100; // range [0-99]
+ trace = sni_trace && ip_trace && (percentage > random);
+ } else if (SSLConfigParams::ssl_wire_trace_server_name) {
+ random = this_ethread()->generator.random() % 100; // range [0-99]
+ trace = sni_trace && (percentage > random);
+ } else if (SSLConfigParams::ssl_wire_trace_ip) {
+ random = this_ethread()->generator.random() % 100; // range [0-99]
+ trace = ip_trace && (percentage > random);
+ } else {
+ random = this_ethread()->generator.random() % 100; // range [0-99]
+ trace = percentage > random;
+ }
+
+ Debug("ssl", "ssl_netvc random=%d, trace=%s", random, trace ? "TRUE" : "FALSE");
+
+ return trace;
+}
http://git-wip-us.apache.org/repos/asf/trafficserver/blob/6e3ce502/iocore/net/SSLUtils.cc
----------------------------------------------------------------------
diff --git a/iocore/net/SSLUtils.cc b/iocore/net/SSLUtils.cc
index c4055e0..db89fbd 100644
--- a/iocore/net/SSLUtils.cc
+++ b/iocore/net/SSLUtils.cc
@@ -281,7 +281,14 @@ set_context_cert(SSL *ssl)
bool found = true;
int retval = 1;
- Debug("ssl", "set_context_cert ssl=%p server=%s handshake_complete=%d", ssl, servername, netvc->getSSLHandShakeComplete());
+ Debug("ssl", "set_context_cert ssl=%p server=%s handshake_complete=%d", ssl, servername,
+ netvc->getSSLHandShakeComplete());
+ // set SSL trace (we do this a little later in the USE_TLS_SNI case so we can get the servername
+ if(SSLConfigParams::ssl_wire_trace_enabled){
+ bool trace = netvc->computeSSLTrace();
+ Debug("ssl", "sslnetvc. setting trace to=%s", trace ? "true" : "false");
+ netvc->setSSLTrace(trace);
+ }
// catch the client renegotiation early on
if (SSLConfigParams::ssl_allow_client_renegotiation == false && netvc->getSSLHandShakeComplete()) {
http://git-wip-us.apache.org/repos/asf/trafficserver/blob/6e3ce502/iocore/net/UnixNetVConnection.cc
----------------------------------------------------------------------
diff --git a/iocore/net/UnixNetVConnection.cc b/iocore/net/UnixNetVConnection.cc
index 9087b19..7e871dd 100644
--- a/iocore/net/UnixNetVConnection.cc
+++ b/iocore/net/UnixNetVConnection.cc
@@ -22,6 +22,8 @@
*/
#include "P_Net.h"
+#include "libts.h"
+#include "Log.h"
#define STATE_VIO_OFFSET ((uintptr_t) & ((NetState *)0)->vio)
#define STATE_FROM_VIO(_x) ((NetState *)(((char *)(_x)) - STATE_VIO_OFFSET))
@@ -301,6 +303,27 @@ read_from_net(NetHandler *nh, UnixNetVConnection *vc, EThread *thread)
r = socketManager.readv(vc->con.fd, &tiovec[0], niov);
}
NET_INCREMENT_DYN_STAT(net_calls_to_read_stat);
+
+ if (vc->origin_trace) {
+ char origin_trace_ip[INET6_ADDRSTRLEN];
+
+ ats_ip_ntop(vc->origin_trace_addr, origin_trace_ip, sizeof (origin_trace_ip));
+
+ if (r > 0) {
+ TraceIn((vc->origin_trace), vc->get_remote_addr(), vc->get_remote_port(),
+ "CLIENT %s:%d\tbytes=%d\n%.*s", origin_trace_ip, vc->origin_trace_port, (int)r,
+ (int)r, (char *)tiovec[0].iov_base);
+
+ } else if (r == 0) {
+ TraceIn((vc->origin_trace), vc->get_remote_addr(), vc->get_remote_port(),
+ "CLIENT %s:%d closed connection", origin_trace_ip, vc->origin_trace_port);
+ } else {
+ TraceIn((vc->origin_trace), vc->get_remote_addr(), vc->get_remote_port(),
+ "CLIENT %s:%d error=%s", origin_trace_ip, vc->origin_trace_port, strerror(errno));
+ }
+
+ }
+
total_read += rattempted;
} while (rattempted && r == rattempted && total_read < toread);
@@ -857,7 +880,8 @@ UnixNetVConnection::UnixNetVConnection()
#else
next_inactivity_timeout_at(0), next_activity_timeout_at(0),
#endif
- nh(NULL), id(0), flags(0), recursion(0), submit_time(0), oob_ptr(0), from_accept_thread(false)
+ nh(NULL), id(0), flags(0), recursion(0), submit_time(0), oob_ptr(0), from_accept_thread(false),
+ origin_trace(false), origin_trace_addr(NULL), origin_trace_port(0)
{
memset(&local_addr, 0, sizeof local_addr);
memset(&server_addr, 0, sizeof server_addr);
@@ -938,6 +962,26 @@ UnixNetVConnection::load_buffer_and_write(int64_t towrite, int64_t &wattempted,
r = socketManager.write(con.fd, tiovec[0].iov_base, tiovec[0].iov_len);
else
r = socketManager.writev(con.fd, &tiovec[0], niov);
+
+ if (origin_trace) {
+ char origin_trace_ip[INET6_ADDRSTRLEN];
+ ats_ip_ntop(origin_trace_addr, origin_trace_ip, sizeof (origin_trace_ip));
+
+ if (r > 0) {
+ TraceOut(origin_trace, get_remote_addr(), get_remote_port(),
+ "CLIENT %s:%d\tbytes=%d\n%.*s", origin_trace_ip, origin_trace_port, (int)r,
+ (int)r, (char *)tiovec[0].iov_base);
+
+ } else if (r == 0) {
+ TraceOut(origin_trace, get_remote_addr(), get_remote_port(),
+ "CLIENT %s:%d closed connection", origin_trace_ip, origin_trace_port);
+ } else {
+ TraceOut(origin_trace, get_remote_addr(), get_remote_port(),
+ "CLIENT %s:%d error=%s", origin_trace_ip, origin_trace_port, strerror(errno));
+ }
+
+ }
+
ProxyMutex *mutex = thread->mutex;
NET_INCREMENT_DYN_STAT(net_calls_to_write_stat);
} while (r == wattempted && total_written < towrite);
http://git-wip-us.apache.org/repos/asf/trafficserver/blob/6e3ce502/mgmt/RecordsConfig.cc
----------------------------------------------------------------------
diff --git a/mgmt/RecordsConfig.cc b/mgmt/RecordsConfig.cc
index 5626f9d..c967acd 100644
--- a/mgmt/RecordsConfig.cc
+++ b/mgmt/RecordsConfig.cc
@@ -1284,6 +1284,14 @@ static const RecordElement RecordsConfig[] =
,
{RECT_CONFIG, "proxy.config.ssl.handshake_timeout_in", RECD_INT, "0", RECU_RESTART_TS, RR_NULL, RECC_INT, "[0-65535]", RECA_NULL}
,
+ {RECT_CONFIG, "proxy.config.ssl.wire_trace_enabled", RECD_INT, "0", RECU_RESTART_TS, RR_NULL, RECC_INT, "[0-2]", RECA_NULL}
+ ,
+ {RECT_CONFIG, "proxy.config.ssl.wire_trace_addr", RECD_STRING, NULL , RECU_RESTART_TS, RR_NULL, RECC_IP, "[0-255]\\.[0-255]\\.[0-255]\\.[0-255]", RECA_NULL}
+ ,
+ {RECT_CONFIG, "proxy.config.ssl.wire_trace_percentage", RECD_INT, "0", RECU_RESTART_TS, RR_NULL, RECC_INT, "[0-100]", RECA_NULL}
+ ,
+ {RECT_CONFIG, "proxy.config.ssl.wire_trace_server_name", RECD_STRING, NULL , RECU_RESTART_TS, RR_NULL, RECC_STR, ".*", RECA_NULL}
+ ,
//##############################################################################
//#
//# OCSP (Online Certificate Status Protocol) Stapling Configuration
http://git-wip-us.apache.org/repos/asf/trafficserver/blob/6e3ce502/proxy/http/HttpSM.cc
----------------------------------------------------------------------
diff --git a/proxy/http/HttpSM.cc b/proxy/http/HttpSM.cc
index 985d718..044817b 100644
--- a/proxy/http/HttpSM.cc
+++ b/proxy/http/HttpSM.cc
@@ -38,6 +38,7 @@
#include "ReverseProxy.h"
#include "RemapProcessor.h"
#include "Transform.h"
+#include "P_SSLConfig.h"
#include "HttpPages.h"
@@ -5378,9 +5379,8 @@ HttpSM::do_setup_post_tunnel(HttpVC_t to_vc_type)
// Next order of business if copy the remaining data from the
// header buffer into new buffer
- //
-
client_request_body_bytes = post_buffer->write(ua_buffer_reader, chunked ? ua_buffer_reader->read_avail() : post_bytes);
+
ua_buffer_reader->consume(client_request_body_bytes);
p = tunnel.add_producer(ua_entry->vc, post_bytes - transfered_bytes, buf_start, &HttpSM::tunnel_handler_post_ua, HT_HTTP_CLIENT,
"user agent post");
@@ -5602,6 +5602,31 @@ HttpSM::attach_server_session(HttpServerSession *s)
server_entry->vc = server_session;
server_entry->vc_type = HTTP_SERVER_VC;
server_entry->vc_handler = &HttpSM::state_send_server_request_header;
+
+ // es - is this a concern here in HttpSM? Does it belong somewhere else?
+ // Get server and client connections
+ UnixNetVConnection *server_vc = (UnixNetVConnection *)(server_session->get_netvc());
+ UnixNetVConnection *client_vc = (UnixNetVConnection *)(ua_session->get_netvc());
+ SSLNetVConnection *ssl_vc = dynamic_cast<SSLNetVConnection *>(client_vc);
+ if(ssl_vc != NULL) { //if incoming connection is SSL
+ bool client_trace = ssl_vc->getSSLTrace();
+ if(client_trace) {
+ // get remote address and port to mark corresponding traces
+ const sockaddr *remote_addr = ssl_vc->get_remote_addr();
+ uint16_t remote_port = ssl_vc->get_remote_port();
+ server_vc->setOriginTrace(true);
+ server_vc->setOriginTraceAddr(remote_addr);
+ server_vc->setOriginTracePort(remote_port);
+ } else {
+ server_vc->setOriginTrace(false);
+ server_vc->setOriginTraceAddr(NULL);
+ server_vc->setOriginTracePort(0);
+ }
+ } else {
+ server_vc->setOriginTrace(false);
+ server_vc->setOriginTraceAddr(NULL);
+ server_vc->setOriginTracePort(0);
+ }
// Initiate a read on the session so that the SM and not
// session manager will get called back if the timeout occurs
http://git-wip-us.apache.org/repos/asf/trafficserver/blob/6e3ce502/proxy/logging/Log.cc
----------------------------------------------------------------------
diff --git a/proxy/logging/Log.cc b/proxy/logging/Log.cc
index 482d01d..f565ea0 100644
--- a/proxy/logging/Log.cc
+++ b/proxy/logging/Log.cc
@@ -1014,6 +1014,55 @@ Log::va_error(const char *format, va_list ap)
}
/*-------------------------------------------------------------------------
+ Log::trace
+
+ These functions are used for wiretracing of incoming SSL connections.
+ They are an extension of the existing Log::error functionality but with
+ special formatting and handling of the non null terminated buffer.
+ -------------------------------------------------------------------------*/
+
+void
+Log::trace_in(const sockaddr *peer_addr, uint16_t peer_port,
+ const char *format_string, ...)
+{
+ va_list ap;
+ va_start(ap, format_string);
+ trace_va(true, peer_addr, peer_port, format_string, ap);
+ va_end(ap);
+}
+
+void
+Log::trace_out(const sockaddr *peer_addr, uint16_t peer_port,
+ const char *format_string, ...)
+{
+ va_list ap;
+ va_start(ap, format_string);
+ trace_va(false, peer_addr, peer_port, format_string, ap);
+ va_end(ap);
+}
+
+void
+Log::trace_va(bool in, const sockaddr *peer_addr, uint16_t peer_port,
+ const char *format_string, va_list ap)
+{
+ if (!peer_addr || !format_string) {
+ return;
+ }
+
+ char ip[INET6_ADDRSTRLEN];
+ ats_ip_ntop(peer_addr, ip, sizeof(ip));
+
+ struct timeval tp;
+ ink_gethrtimeofday(&tp, NULL);
+
+ Log::error("[%9d.%03d] Trace {0x%" PRIx64 "} %s %s:%d: ",
+ (int) tp.tv_sec, (int) (tp.tv_usec / 1000),
+ (uint64_t) pthread_self(), in ? "RECV" : "SEND", ip, peer_port);
+ Log::va_error(format_string, ap);
+ Log::error("[End Trace]\n");
+}
+
+/*-------------------------------------------------------------------------
Log::preproc_thread_main
This function defines the functionality of the logging flush prepare
http://git-wip-us.apache.org/repos/asf/trafficserver/blob/6e3ce502/proxy/logging/Log.h
----------------------------------------------------------------------
diff --git a/proxy/logging/Log.h b/proxy/logging/Log.h
index fb194c9..f726d32 100644
--- a/proxy/logging/Log.h
+++ b/proxy/logging/Log.h
@@ -417,7 +417,17 @@ public:
inkcoreapi static int access(LogAccess *lad);
inkcoreapi static int va_error(const char *format, va_list ap);
inkcoreapi static int error(const char *format, ...) TS_PRINTFLIKE(1, 2);
-
+
+ /////////////////////////////////////////////////////////////////////////
+ // 'Wire tracing' enabled by source ip or by percentage of connections //
+ /////////////////////////////////////////////////////////////////////////
+ static void trace_in(const sockaddr *peer_addr, uint16_t peer_port,
+ const char *format_string, ...) TS_PRINTFLIKE(3, 4);
+ static void trace_out(const sockaddr *peer_addr, uint16_t peer_port,
+ const char *format_string, ...) TS_PRINTFLIKE(3, 4);
+ static void trace_va(bool in, const sockaddr *peer_addr, uint16_t peer_port,
+ const char *format_string, va_list ap);
+
// public data members
inkcoreapi static LogObject *error_log;
static LogConfig *config;
@@ -474,4 +484,7 @@ LogRollingEnabledIsValid(int enabled)
return (enabled >= Log::NO_ROLLING || enabled < Log::INVALID_ROLLING_VALUE);
}
+#define TraceIn(flag, ...) if (flag) Log::trace_in(__VA_ARGS__)
+#define TraceOut(flag, ...) if (flag) Log::trace_out(__VA_ARGS__)
+
#endif