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.
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/CHANGES > ---------------------------------------------------------------------- > 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 >
