On 5/26/14, 6:00 PM, "James Peach" <jpe...@apache.org> wrote:
>Bryan, > >How are you expecting proxy.process.ssl.total_handshake_time to be used? >What units is it in? Unless I'm missing something, the aggregate >handshake time does not seem very interesting. >From what I can see in the patch, proxy.process.ssl.total_handshake_time = proxy.process.ssl.total_*successful*_handshake_time and this is likely meant to be used with proxy.process.ssl.total_success_handshake_count, to determine the average *successful* handshake duration. This should be useful in measuring the ssl handshake latency and perhaps how much improvement is seen with features such as ssl session reuse or spdy. > >What does proxy.process.spdy.total_time mean, and how would I use it? > >Why does proxy.process.ssl.total_success_handshake_count only count >successes? What about failed handshakes? > >Where is proxy.process.spdy.total_streams decremented? > >Where is proxy.process.https.connection_count decremented? Why is it >persistent? If it's measuring the total number of https connections >accepted, where is proxy.process.http.connection_count? > >SSL_INCREMENT_DYN_STAT_EX is not a great name, and it's only used once. >Does it really need a global macro? > >I'm not sure that sslHandshakeBeginTime is needed; >UnixNetVConnection::submit_time seems to be there to mark the birth time >of a netvc. > >On May 23, 2014, at 1:14 PM, bc...@apache.org wrote: > >> Repository: trafficserver >> Updated Branches: >> refs/heads/master 33a477145 -> 12bde5b9c >> >> >> TS-2753: Add more SPDY and HTTPS statistics >> Reviewed: Bryan Call >> >> >> Project: http://git-wip-us.apache.org/repos/asf/trafficserver/repo >> Commit: >>http://git-wip-us.apache.org/repos/asf/trafficserver/commit/12bde5b9 >> Tree: http://git-wip-us.apache.org/repos/asf/trafficserver/tree/12bde5b9 >> Diff: http://git-wip-us.apache.org/repos/asf/trafficserver/diff/12bde5b9 >> >> Branch: refs/heads/master >> Commit: 12bde5b9cfbc99a6bc9227166b0107cee35d8f9f >> Parents: 33a4771 >> Author: Wei Sun <sun...@yahoo-inc.com> >> Authored: Fri May 23 13:14:31 2014 -0700 >> Committer: Bryan Call <bc...@apache.org> >> Committed: Fri May 23 13:14:31 2014 -0700 >> >> ---------------------------------------------------------------------- >> CHANGES | 2 ++ >> iocore/net/P_SSLNetVConnection.h | 1 + >> iocore/net/P_SSLUtils.h | 3 +++ >> iocore/net/SSLNetVConnection.cc | 9 +++++++++ >> iocore/net/SSLNextProtocolAccept.cc | 1 + >> iocore/net/SSLUtils.cc | 8 ++++++++ >> proxy/http/HttpClientSession.cc | 4 ++++ >> proxy/http/HttpConfig.cc | 6 ++++++ >> proxy/http/HttpConfig.h | 3 +++ >> proxy/http/HttpTransact.cc | 4 ++++ >> proxy/spdy/SpdyClientSession.cc | 2 ++ >> proxy/spdy/SpdyCommon.cc | 4 ++++ >> proxy/spdy/SpdyCommon.h | 8 ++++++++ >> 13 files changed, 55 insertions(+) >> ---------------------------------------------------------------------- >> >> >> >>http://git-wip-us.apache.org/repos/asf/trafficserver/blob/12bde5b9/CHANGE >>S >> ---------------------------------------------------------------------- >> diff --git a/CHANGES b/CHANGES >> index c589668..8793946 100644 >> --- a/CHANGES >> +++ b/CHANGES >> @@ -1,6 +1,8 @@ >> -*- coding: >>utf-8 -*- >> Changes with Apache Traffic Server 5.0.0 >> >> + *) [TS-2753] Add more SPDY and HTTPS statistics >> + >> *) [TS-2677] Don't apply path / scheme URL changes in remap when >>method is >> CONNECT. >> >> >> >>http://git-wip-us.apache.org/repos/asf/trafficserver/blob/12bde5b9/iocore >>/net/P_SSLNetVConnection.h >> ---------------------------------------------------------------------- >> diff --git a/iocore/net/P_SSLNetVConnection.h >>b/iocore/net/P_SSLNetVConnection.h >> index 47861e4..c464e60 100644 >> --- a/iocore/net/P_SSLNetVConnection.h >> +++ b/iocore/net/P_SSLNetVConnection.h >> @@ -101,6 +101,7 @@ public: >> virtual ~SSLNetVConnection() { } >> >> SSL *ssl; >> + ink_hrtime sslHandshakeBeginTime; >> >> static int advertise_next_protocol(SSL * ssl, const unsigned char ** >>out, unsigned * outlen, void *); >> static int select_next_protocol(SSL * ssl, const unsigned char ** >>out, unsigned char * outlen, const unsigned char * in, unsigned inlen, >>void *); >> >> >>http://git-wip-us.apache.org/repos/asf/trafficserver/blob/12bde5b9/iocore >>/net/P_SSLUtils.h >> ---------------------------------------------------------------------- >> diff --git a/iocore/net/P_SSLUtils.h b/iocore/net/P_SSLUtils.h >> index 7297eac..5145cb7 100644 >> --- a/iocore/net/P_SSLUtils.h >> +++ b/iocore/net/P_SSLUtils.h >> @@ -62,6 +62,8 @@ enum SSL_Stats >> ssl_user_agent_session_hit_stat, >> ssl_user_agent_session_miss_stat, >> ssl_user_agent_session_timeout_stat, >> + ssl_total_handshake_time_stat, >> + ssl_total_success_handshake_count_stat, >> >> ssl_cipher_stats_start = 100, >> ssl_cipher_stats_end = 300, >> @@ -75,6 +77,7 @@ extern RecRawStatBlock *ssl_rsb; >> #define SSL_INCREMENT_DYN_STAT(x) RecIncrRawStat(ssl_rsb, NULL, (int) >>x, 1) >> #define SSL_DECREMENT_DYN_STAT(x) RecIncrRawStat(ssl_rsb, NULL, (int) >>x, -1) >> #define SSL_SET_COUNT_DYN_STAT(x,count) RecSetRawStatCount(ssl_rsb, x, >>count) >> +#define SSL_INCREMENT_DYN_STAT_EX(x, y) RecIncrRawStat(ssl_rsb, NULL, >>(int) x, y) >> #define SSL_CLEAR_DYN_STAT(x) \ >> do { \ >> RecSetRawStatSum(ssl_rsb, (x), 0); \ >> >> >>http://git-wip-us.apache.org/repos/asf/trafficserver/blob/12bde5b9/iocore >>/net/SSLNetVConnection.cc >> ---------------------------------------------------------------------- >> diff --git a/iocore/net/SSLNetVConnection.cc >>b/iocore/net/SSLNetVConnection.cc >> index 57c022c..11e9d1e 100644 >> --- a/iocore/net/SSLNetVConnection.cc >> +++ b/iocore/net/SSLNetVConnection.cc >> @@ -468,6 +468,7 @@ SSLNetVConnection::SSLNetVConnection(): >> npnEndpoint(NULL) >> { >> ssl = NULL; >> + sslHandshakeBeginTime = 0; >> } >> >> void >> @@ -572,6 +573,14 @@ SSLNetVConnection::sslServerHandShakeEvent(int >>&err) >> >> sslHandShakeComplete = true; >> >> + if (sslHandshakeBeginTime) { >> + const ink_hrtime ssl_handshake_time = ink_get_hrtime() - >>sslHandshakeBeginTime; >> + Debug("ssl", "ssl handshake time:%" PRId64, ssl_handshake_time); >> + sslHandshakeBeginTime = 0; >> + SSL_INCREMENT_DYN_STAT_EX(ssl_total_handshake_time_stat, >>ssl_handshake_time); >> + SSL_INCREMENT_DYN_STAT(ssl_total_success_handshake_count_stat); >> + } >> + >> { >> const unsigned char * proto = NULL; >> unsigned len = 0; >> >> >>http://git-wip-us.apache.org/repos/asf/trafficserver/blob/12bde5b9/iocore >>/net/SSLNextProtocolAccept.cc >> ---------------------------------------------------------------------- >> diff --git a/iocore/net/SSLNextProtocolAccept.cc >>b/iocore/net/SSLNextProtocolAccept.cc >> index 92524d0..558a1b1 100644 >> --- a/iocore/net/SSLNextProtocolAccept.cc >> +++ b/iocore/net/SSLNextProtocolAccept.cc >> @@ -119,6 +119,7 @@ SSLNextProtocolAccept::mainEvent(int event, void * >>edata) >> { >> SSLNetVConnection * netvc = ssl_netvc_cast(event, edata); >> >> + netvc->sslHandshakeBeginTime = ink_get_hrtime(); >> Debug("ssl", "[SSLNextProtocolAccept:mainEvent] event %d netvc %p", >>event, netvc); >> >> switch (event) { >> >> >>http://git-wip-us.apache.org/repos/asf/trafficserver/blob/12bde5b9/iocore >>/net/SSLUtils.cc >> ---------------------------------------------------------------------- >> diff --git a/iocore/net/SSLUtils.cc b/iocore/net/SSLUtils.cc >> index f5083b9..8d80c90 100644 >> --- a/iocore/net/SSLUtils.cc >> +++ b/iocore/net/SSLUtils.cc >> @@ -634,6 +634,14 @@ SSLInitializeStatistics() >> RECD_INT, RECP_PERSISTENT, (int) >>ssl_origin_server_unknown_ca_stat, >> RecRawStatSyncSum); >> >> + // SSL handshake time >> + RecRegisterRawStat(ssl_rsb, RECT_PROCESS, >>"proxy.process.ssl.total_handshake_time", >> + RECD_INT, RECP_PERSISTENT, (int) >>ssl_total_handshake_time_stat, >> + RecRawStatSyncSum); >> + RecRegisterRawStat(ssl_rsb, RECT_PROCESS, >>"proxy.process.ssl.total_success_handshake_count", >> + RECD_INT, RECP_PERSISTENT, (int) >>ssl_total_success_handshake_count_stat, >> + RecRawStatSyncCount); >> + >> // Get and register the SSL cipher stats. Note that we are using the >>default SSL context to obtain >> // the cipher list. This means that the set of ciphers is fixed by >>the build configuration and not >> // filtered by proxy.config.ssl.server.cipher_suite. This keeps the >>set of cipher suites stable across >> >> >>http://git-wip-us.apache.org/repos/asf/trafficserver/blob/12bde5b9/proxy/ >>http/HttpClientSession.cc >> ---------------------------------------------------------------------- >> diff --git a/proxy/http/HttpClientSession.cc >>b/proxy/http/HttpClientSession.cc >> index 0620b3b..3f00cd4 100644 >> --- a/proxy/http/HttpClientSession.cc >> +++ b/proxy/http/HttpClientSession.cc >> @@ -191,6 +191,10 @@ HttpClientSession::new_connection(NetVConnection * >>new_vc, bool backdoor, MIOBuf >> HTTP_INCREMENT_DYN_STAT(http_current_client_connections_stat); >> conn_decrease = true; >> HTTP_INCREMENT_DYN_STAT(http_total_client_connections_stat); >> + if (static_cast<HttpProxyPort::TransportType>(new_vc->attributes) == >>HttpProxyPort::TRANSPORT_SSL) { >> + HTTP_INCREMENT_DYN_STAT(https_connection_count_stat); >> + } >> + >> /* inbound requests stat should be incremented here, not after the >> * header has been read */ >> HTTP_INCREMENT_DYN_STAT(http_total_incoming_connections_stat); >> >> >>http://git-wip-us.apache.org/repos/asf/trafficserver/blob/12bde5b9/proxy/ >>http/HttpConfig.cc >> ---------------------------------------------------------------------- >> diff --git a/proxy/http/HttpConfig.cc b/proxy/http/HttpConfig.cc >> index 0d9c9e3..62d6304 100644 >> --- a/proxy/http/HttpConfig.cc >> +++ b/proxy/http/HttpConfig.cc >> @@ -1198,6 +1198,12 @@ register_stat_callbacks() >> RECD_COUNTER, RECP_PERSISTENT, >> (int) http_total_x_redirect_stat, >>RecRawStatSyncCount); >> >> + RecRegisterRawStat(http_rsb, RECT_PROCESS, >> + "proxy.process.https.incoming_requests", >> + RECD_COUNTER, RECP_PERSISTENT, (int) >>https_incoming_requests_stat, RecRawStatSyncCount); >> + RecRegisterRawStat(http_rsb, RECT_PROCESS, >> + "proxy.process.https.connection_count", >> + RECD_COUNTER, RECP_PERSISTENT, (int) >>https_connection_count_stat, RecRawStatSyncCount); >> } >> >> >> >> >>http://git-wip-us.apache.org/repos/asf/trafficserver/blob/12bde5b9/proxy/ >>http/HttpConfig.h >> ---------------------------------------------------------------------- >> diff --git a/proxy/http/HttpConfig.h b/proxy/http/HttpConfig.h >> index 15f4b79..4805097 100644 >> --- a/proxy/http/HttpConfig.h >> +++ b/proxy/http/HttpConfig.h >> @@ -337,6 +337,9 @@ enum >> http_response_status_505_count_stat, >> http_response_status_5xx_count_stat, >> >> + https_incoming_requests_stat, >> + https_connection_count_stat, >> + >> http_stat_count >> }; >> >> >> >>http://git-wip-us.apache.org/repos/asf/trafficserver/blob/12bde5b9/proxy/ >>http/HttpTransact.cc >> ---------------------------------------------------------------------- >> diff --git a/proxy/http/HttpTransact.cc b/proxy/http/HttpTransact.cc >> index 0167136..1d94dec 100644 >> --- a/proxy/http/HttpTransact.cc >> +++ b/proxy/http/HttpTransact.cc >> @@ -1293,6 +1293,10 @@ HttpTransact::HandleRequest(State* s) >> >> HTTP_INCREMENT_TRANS_STAT(http_incoming_requests_stat); >> >> + if (s->client_info.port_attribute == HttpProxyPort::TRANSPORT_SSL) { >> + HTTP_INCREMENT_TRANS_STAT(https_incoming_requests_stat); >> + } >> + >> if (s->api_release_server_session == true) { >> s->api_release_server_session = false; >> } >> >> >>http://git-wip-us.apache.org/repos/asf/trafficserver/blob/12bde5b9/proxy/ >>spdy/SpdyClientSession.cc >> ---------------------------------------------------------------------- >> diff --git a/proxy/spdy/SpdyClientSession.cc >>b/proxy/spdy/SpdyClientSession.cc >> index fcb79fb..47f57c3 100644 >> --- a/proxy/spdy/SpdyClientSession.cc >> +++ b/proxy/spdy/SpdyClientSession.cc >> @@ -101,6 +101,7 @@ SpdyClientSession::init(NetVConnection * netvc, >>spdy::SessionVersion vers) >> // with no increment. It seems a lesser thing to have the thread >>counts >> // a little off but globally consistent. >> SpdyStatIncrCount(Config::STAT_ACTIVE_SESSION_COUNT, netvc); >> + SpdyStatIncrCount(Config::STAT_TOTAL_CONNECTION_COUNT, netvc); >> >> ink_release_assert(r == 0); >> sm_id = atomic_inc(g_sm_id); >> @@ -398,6 +399,7 @@ spdy_read_fetch_body_callback(spdylay_session * >>/*session*/, int32_t stream_id, >> if (already < (int64_t)length) { >> if (req->event == TS_FETCH_EVENT_EXT_BODY_DONE) { >> TSHRTime end_time = TShrtime(); >> + SpdyStatIncr(Config::STAT_TOTAL_STREAM_TIME, sm, end_time - >>req->start_time); >> Debug("spdy", "----Request[%" PRIu64 ":%d] %s %lld %d", >>sm->sm_id, req->stream_id, >> req->url.c_str(), (end_time - >>req->start_time)/TS_HRTIME_MSECOND, >> req->fetch_data_len); >> >> >>http://git-wip-us.apache.org/repos/asf/trafficserver/blob/12bde5b9/proxy/ >>spdy/SpdyCommon.cc >> ---------------------------------------------------------------------- >> diff --git a/proxy/spdy/SpdyCommon.cc b/proxy/spdy/SpdyCommon.cc >> index 0b89bf8..d5687f4 100644 >> --- a/proxy/spdy/SpdyCommon.cc >> +++ b/proxy/spdy/SpdyCommon.cc >> @@ -30,6 +30,8 @@ Config SPDY_CFG; >> static char const * const SPDY_STAT_ACTIVE_SESSION_NAME = >>"proxy.process.spdy.active_sessions"; >> static char const * const SPDY_STAT_ACTIVE_STREAM_NAME = >>"proxy.process.spdy.active_streams"; >> static char const * const SPDY_STAT_TOTAL_STREAM_NAME = >>"proxy.process.spdy.total_streams"; >> +static char const * const SPDY_STAT_TOTAL_TIME_NAME = >>"proxy.process.spdy.total_time"; >> +static char const * const SPDY_STAT_TOTAL_CONNECTION_NAME = >>"proxy.process.spdy.connection_count"; >> >> string >> http_date(time_t t) >> @@ -56,6 +58,8 @@ spdy_config_load() >> RecRegisterRawStat(SPDY_CFG.rsb, RECT_PROCESS, >>SPDY_STAT_ACTIVE_SESSION_NAME, RECD_INT, RECP_NON_PERSISTENT, >>static_cast<int>(Config::STAT_ACTIVE_SESSION_COUNT), >>RecRawStatSyncCount); >> RecRegisterRawStat(SPDY_CFG.rsb, RECT_PROCESS, >>SPDY_STAT_ACTIVE_STREAM_NAME, RECD_INT, RECP_NON_PERSISTENT, >>static_cast<int>(Config::STAT_ACTIVE_STREAM_COUNT), RecRawStatSyncCount); >> RecRegisterRawStat(SPDY_CFG.rsb, RECT_PROCESS, >>SPDY_STAT_TOTAL_STREAM_NAME, RECD_INT, RECP_NON_PERSISTENT, >>static_cast<int>(Config::STAT_TOTAL_STREAM_COUNT), RecRawStatSyncCount); >> + RecRegisterRawStat(SPDY_CFG.rsb, RECT_PROCESS, >>SPDY_STAT_TOTAL_TIME_NAME, RECD_INT, RECP_NON_PERSISTENT, >>static_cast<int>(Config::STAT_TOTAL_STREAM_TIME), RecRawStatSyncSum); >> + RecRegisterRawStat(SPDY_CFG.rsb, RECT_PROCESS, >>SPDY_STAT_TOTAL_CONNECTION_NAME, RECD_INT, RECP_NON_PERSISTENT, >>static_cast<int>(Config::STAT_TOTAL_CONNECTION_COUNT), >>RecRawStatSyncCount); >> >> return 0; >> } >> >> >>http://git-wip-us.apache.org/repos/asf/trafficserver/blob/12bde5b9/proxy/ >>spdy/SpdyCommon.h >> ---------------------------------------------------------------------- >> diff --git a/proxy/spdy/SpdyCommon.h b/proxy/spdy/SpdyCommon.h >> index 92ab047..330a979 100644 >> --- a/proxy/spdy/SpdyCommon.h >> +++ b/proxy/spdy/SpdyCommon.h >> @@ -73,6 +73,9 @@ struct Config { >> STAT_ACTIVE_SESSION_COUNT, ///< Current # of active SPDY sessions. >> STAT_ACTIVE_STREAM_COUNT, ///< Current # of active SPDY streams. >> STAT_TOTAL_STREAM_COUNT, ///< Total number of streams created. >> + STAT_TOTAL_STREAM_TIME, //< Total stream time >> + STAT_TOTAL_CONNECTION_COUNT, //< Total connections running spdy >> + >> N_STATS ///< Terminal counter, NOT A STAT INDEX. >> }; >> RecRawStatBlock* rsb; ///< Container for statistics. >> @@ -112,4 +115,9 @@ SpdyStatDecrCount(Config::StatIndex idx, >>Continuation* contp) { >> RecIncrRawStatCount(SPDY_CFG.rsb, contp->mutex->thread_holding, idx, >>-1); >> } >> >> +inline void >> +SpdyStatIncr(Config::StatIndex idx, Continuation* contp, const int64_t >>incr) { >> + RecIncrRawStat(SPDY_CFG.rsb, contp->mutex->thread_holding, idx, >>incr); >> +} >> + >> #endif >> >
