You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@trafficserver.apache.org by James Peach <jp...@apache.org> on 2014/05/27 03:00:59 UTC
Re: git commit: TS-2753: Add more SPDY and HTTPS statistics Reviewed:
Bryan Call
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, bcall@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 <su...@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
>
Re: git commit: TS-2753: Add more SPDY and HTTPS statistics Reviewed:
Bryan Call
Posted by James Peach <jp...@apache.org>.
On May 27, 2014, at 9:14 AM, Sudheer Vinukonda <su...@yahoo-inc.com> wrote:
>
>
> On 5/27/14, 8:47 AM, "James Peach" <jp...@apache.org> wrote:
>
>> On May 27, 2014, at 7:33 AM, Sudheer Vinukonda <su...@yahoo-inc.com>
>> wrote:
>>
>>>
>>>
>>> On 5/26/14, 6:00 PM, "James Peach" <jp...@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.
>>
>> This is a very shaky rationale for this metric and a very limited use
>> case. If you want to measure SSL handshake time, then you should measure
>> it directly.
>>
>> If you try to measure it with this metric, you will need to use the
>> connection_count metrics, which are also of dubious general utility since
>> they are counters, not gauges. Even when you do that, all you can do is
>> measure the average, which is not very interesting. You really want to
>> measure the average and the variance, or even generate a heat map. To do
>> this, you need per-request values.
>>
>> I think that you should nuke this metric and write a plugin to gather the
>> data you actually need. Use or extend the transaction milestone API to
>> get the session accept timestamp. You can use the kernel TCP info socket
>> option to measure round trips, estimated latency, etc.
>
> We have post processing tools that collect this metric pretty regularly
> and should be able to give the variance/average etc. Yes, we do plan to
> extend the transaction milestone API to get the session accept timestamp.
How can you get variance of a total?
J
Re: git commit: TS-2753: Add more SPDY and HTTPS statistics Reviewed:
Bryan Call
Posted by James Peach <jp...@apache.org>.
On May 27, 2014, at 9:14 AM, Sudheer Vinukonda <su...@yahoo-inc.com> wrote:
>
>
> On 5/27/14, 8:47 AM, "James Peach" <jp...@apache.org> wrote:
>
>> On May 27, 2014, at 7:33 AM, Sudheer Vinukonda <su...@yahoo-inc.com>
>> wrote:
>>
>>>
>>>
>>> On 5/26/14, 6:00 PM, "James Peach" <jp...@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.
>>
>> This is a very shaky rationale for this metric and a very limited use
>> case. If you want to measure SSL handshake time, then you should measure
>> it directly.
>>
>> If you try to measure it with this metric, you will need to use the
>> connection_count metrics, which are also of dubious general utility since
>> they are counters, not gauges. Even when you do that, all you can do is
>> measure the average, which is not very interesting. You really want to
>> measure the average and the variance, or even generate a heat map. To do
>> this, you need per-request values.
>>
>> I think that you should nuke this metric and write a plugin to gather the
>> data you actually need. Use or extend the transaction milestone API to
>> get the session accept timestamp. You can use the kernel TCP info socket
>> option to measure round trips, estimated latency, etc.
>
> We have post processing tools that collect this metric pretty regularly
> and should be able to give the variance/average etc. Yes, we do plan to
> extend the transaction milestone API to get the session accept timestamp.
How can you get variance of a total?
J
Re: git commit: TS-2753: Add more SPDY and HTTPS statistics
Reviewed: Bryan Call
Posted by Sudheer Vinukonda <su...@yahoo-inc.com>.
On 5/27/14, 8:47 AM, "James Peach" <jp...@apache.org> wrote:
>On May 27, 2014, at 7:33 AM, Sudheer Vinukonda <su...@yahoo-inc.com>
>wrote:
>
>>
>>
>> On 5/26/14, 6:00 PM, "James Peach" <jp...@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.
>
>This is a very shaky rationale for this metric and a very limited use
>case. If you want to measure SSL handshake time, then you should measure
>it directly.
>
>If you try to measure it with this metric, you will need to use the
>connection_count metrics, which are also of dubious general utility since
>they are counters, not gauges. Even when you do that, all you can do is
>measure the average, which is not very interesting. You really want to
>measure the average and the variance, or even generate a heat map. To do
>this, you need per-request values.
>
>I think that you should nuke this metric and write a plugin to gather the
>data you actually need. Use or extend the transaction milestone API to
>get the session accept timestamp. You can use the kernel TCP info socket
>option to measure round trips, estimated latency, etc.
We have post processing tools that collect this metric pretty regularly
and should be able to give the variance/average etc. Yes, we do plan to
extend the transaction milestone API to get the session accept timestamp.
>
>>> 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, bcall@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 <su...@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/CHAN
>>>>GE
>>>> 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/ioco
>>>>re
>>>> /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/ioco
>>>>re
>>>> /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/ioco
>>>>re
>>>> /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/ioco
>>>>re
>>>> /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/ioco
>>>>re
>>>> /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/prox
>>>>y/
>>>> 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/prox
>>>>y/
>>>> 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/prox
>>>>y/
>>>> 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/prox
>>>>y/
>>>> 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/prox
>>>>y/
>>>> 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/prox
>>>>y/
>>>> 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/prox
>>>>y/
>>>> 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
>>>>
>>>
>>
>
Re: git commit: TS-2753: Add more SPDY and HTTPS statistics Reviewed:
Bryan Call
Posted by James Peach <jp...@apache.org>.
On May 27, 2014, at 7:33 AM, Sudheer Vinukonda <su...@yahoo-inc.com> wrote:
>
>
> On 5/26/14, 6:00 PM, "James Peach" <jp...@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.
This is a very shaky rationale for this metric and a very limited use case. If you want to measure SSL handshake time, then you should measure it directly.
If you try to measure it with this metric, you will need to use the connection_count metrics, which are also of dubious general utility since they are counters, not gauges. Even when you do that, all you can do is measure the average, which is not very interesting. You really want to measure the average and the variance, or even generate a heat map. To do this, you need per-request values.
I think that you should nuke this metric and write a plugin to gather the data you actually need. Use or extend the transaction milestone API to get the session accept timestamp. You can use the kernel TCP info socket option to measure round trips, estimated latency, etc.
>> 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, bcall@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 <su...@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
>>>
>>
>
Re: git commit: TS-2753: Add more SPDY and HTTPS statistics Reviewed:
Bryan Call
Posted by James Peach <jp...@apache.org>.
On May 27, 2014, at 7:33 AM, Sudheer Vinukonda <su...@yahoo-inc.com> wrote:
>
>
> On 5/26/14, 6:00 PM, "James Peach" <jp...@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.
This is a very shaky rationale for this metric and a very limited use case. If you want to measure SSL handshake time, then you should measure it directly.
If you try to measure it with this metric, you will need to use the connection_count metrics, which are also of dubious general utility since they are counters, not gauges. Even when you do that, all you can do is measure the average, which is not very interesting. You really want to measure the average and the variance, or even generate a heat map. To do this, you need per-request values.
I think that you should nuke this metric and write a plugin to gather the data you actually need. Use or extend the transaction milestone API to get the session accept timestamp. You can use the kernel TCP info socket option to measure round trips, estimated latency, etc.
>> 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, bcall@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 <su...@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
>>>
>>
>
Re: git commit: TS-2753: Add more SPDY and HTTPS statistics
Reviewed: Bryan Call
Posted by Sudheer Vinukonda <su...@yahoo-inc.com>.
On 5/26/14, 6:00 PM, "James Peach" <jp...@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, bcall@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 <su...@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
>>
>
Re: git commit: TS-2753: Add more SPDY and HTTPS statistics Reviewed:
Bryan Call
Posted by James Peach <jp...@apache.org>.
On May 27, 2014, at 6:47 AM, Alan M. Carroll <am...@network-geographics.com> wrote:
> James,
>
> Monday, May 26, 2014, 8:00:59 PM, you wrote:
>
>> Where is proxy.process.spdy.total_streams decremented?
>
> I don't think it is - it is counting the total number of streams, which can only increase. The "ACTIVE" variants count the number of objects currently extant. This is parallel to things like "total_client_connections".
So this is a counter of SPDY requests? Why doesn't this mirror the proxy.process.http hierarchy? Are request double-counted in the spdy and http metric herarchies?
J
Re: git commit: TS-2753: Add more SPDY and HTTPS statistics Reviewed: Bryan Call
Posted by "Alan M. Carroll" <am...@network-geographics.com>.
James,
Monday, May 26, 2014, 8:00:59 PM, you wrote:
> Where is proxy.process.spdy.total_streams decremented?
I don't think it is - it is counting the total number of streams, which can only increase. The "ACTIVE" variants count the number of objects currently extant. This is parallel to things like "total_client_connections".
Re: git commit: TS-2753: Add more SPDY and HTTPS statistics Reviewed:
Bryan Call
Posted by James Peach <jp...@apache.org>.
On May 29, 2014, at 12:19 AM, Wei Sun <su...@yahoo-inc.com> wrote:
>
>
> On 5/29/14, 1:36 AM, "Bryan Call" <bc...@yahoo-inc.com> wrote:
>
>>
>> On May 26, 2014, at 6:00 PM, James Peach <jp...@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.
>>
>> We wanted to get a better picture of the SSL handshake time so we can
>> included it into the total request time and also look at it to see how
>> much time we are saving on average by using session tickets and session
>> caching. Measuring SSL handshake time should ideally be measured by the
>> client, so we are trying to do the best we can with this approach.
>>
>>>
>>> What doesproxy.process.spdy.total_time mean, and how would I use it?
>>
>> This is the total time spent on SPDY requests. I think it is self
>> explanatory.
>>
>>>
>>> Why does proxy.process.ssl.total_success_handshake_count only count
>>> successes? What about failed handshakes?
>>
>> When I was looking through the stats I saw that Ron was keeping track of
>> the error cases. I would have to double check to make sure he is keeping
>> track of the failed handshakes.
>>
>>>
>>> Where is proxy.process.spdy.total_streams decremented?
>>
>> Total stats are normally not decremented and are a total count since the
>> system has been running or since the last time the stats were reset. We
>> don't want to decrement it and there is another stat to see the number of
>> active streams.
>>
>>>
>>> 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?
>>
>> There is a proxy.process.http.total_client_connections already. After
>> the commit I was thinking that proxy.process.https.connection_count name
>> should be changed to be more inline with the http stat.
>>
>>>
>>> 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.
>>
>> Yes, this can be cleaned up.
>
> Looks like submit_time is created before ::accept() in
> do_blocking_accept(), might not be accurate to measure the starting time.
I wonder if that's a bug. NetAccept::acceptFastEvent() and net_accept() both set it after the accept.
>
>>
>> -Bryan
>>
>>>
>>> On May 23, 2014, at 1:14 PM, bcall@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 <su...@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/CHANG
>>>> ES
>>>> ----------------------------------------------------------------------
>>>> 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/iocor
>>>> e/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/iocor
>>>> e/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/iocor
>>>> e/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/iocor
>>>> e/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/iocor
>>>> e/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
Re: git commit: TS-2753: Add more SPDY and HTTPS statistics Reviewed:
Bryan Call
Posted by James Peach <jp...@apache.org>.
On May 29, 2014, at 12:19 AM, Wei Sun <su...@yahoo-inc.com> wrote:
>
>
> On 5/29/14, 1:36 AM, "Bryan Call" <bc...@yahoo-inc.com> wrote:
>
>>
>> On May 26, 2014, at 6:00 PM, James Peach <jp...@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.
>>
>> We wanted to get a better picture of the SSL handshake time so we can
>> included it into the total request time and also look at it to see how
>> much time we are saving on average by using session tickets and session
>> caching. Measuring SSL handshake time should ideally be measured by the
>> client, so we are trying to do the best we can with this approach.
>>
>>>
>>> What doesproxy.process.spdy.total_time mean, and how would I use it?
>>
>> This is the total time spent on SPDY requests. I think it is self
>> explanatory.
>>
>>>
>>> Why does proxy.process.ssl.total_success_handshake_count only count
>>> successes? What about failed handshakes?
>>
>> When I was looking through the stats I saw that Ron was keeping track of
>> the error cases. I would have to double check to make sure he is keeping
>> track of the failed handshakes.
>>
>>>
>>> Where is proxy.process.spdy.total_streams decremented?
>>
>> Total stats are normally not decremented and are a total count since the
>> system has been running or since the last time the stats were reset. We
>> don't want to decrement it and there is another stat to see the number of
>> active streams.
>>
>>>
>>> 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?
>>
>> There is a proxy.process.http.total_client_connections already. After
>> the commit I was thinking that proxy.process.https.connection_count name
>> should be changed to be more inline with the http stat.
>>
>>>
>>> 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.
>>
>> Yes, this can be cleaned up.
>
> Looks like submit_time is created before ::accept() in
> do_blocking_accept(), might not be accurate to measure the starting time.
I wonder if that's a bug. NetAccept::acceptFastEvent() and net_accept() both set it after the accept.
>
>>
>> -Bryan
>>
>>>
>>> On May 23, 2014, at 1:14 PM, bcall@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 <su...@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/CHANG
>>>> ES
>>>> ----------------------------------------------------------------------
>>>> 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/iocor
>>>> e/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/iocor
>>>> e/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/iocor
>>>> e/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/iocor
>>>> e/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/iocor
>>>> e/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
Re: git commit: TS-2753: Add more SPDY and HTTPS statistics
Reviewed: Bryan Call
Posted by Wei Sun <su...@yahoo-inc.com>.
On 5/29/14, 1:36 AM, "Bryan Call" <bc...@yahoo-inc.com> wrote:
>
>On May 26, 2014, at 6:00 PM, James Peach <jp...@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.
>
>We wanted to get a better picture of the SSL handshake time so we can
>included it into the total request time and also look at it to see how
>much time we are saving on average by using session tickets and session
>caching. Measuring SSL handshake time should ideally be measured by the
>client, so we are trying to do the best we can with this approach.
>
>>
>> What doesproxy.process.spdy.total_time mean, and how would I use it?
>
>This is the total time spent on SPDY requests. I think it is self
>explanatory.
>
>>
>> Why does proxy.process.ssl.total_success_handshake_count only count
>>successes? What about failed handshakes?
>
>When I was looking through the stats I saw that Ron was keeping track of
>the error cases. I would have to double check to make sure he is keeping
>track of the failed handshakes.
>
>>
>> Where is proxy.process.spdy.total_streams decremented?
>
>Total stats are normally not decremented and are a total count since the
>system has been running or since the last time the stats were reset. We
>don't want to decrement it and there is another stat to see the number of
>active streams.
>
>>
>> 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?
>
>There is a proxy.process.http.total_client_connections already. After
>the commit I was thinking that proxy.process.https.connection_count name
>should be changed to be more inline with the http stat.
>
>>
>> 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.
>
>Yes, this can be cleaned up.
Looks like submit_time is created before ::accept() in
do_blocking_accept(), might not be accurate to measure the starting time.
>
>-Bryan
>
>>
>> On May 23, 2014, at 1:14 PM, bcall@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 <su...@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/CHANG
>>>ES
>>> ----------------------------------------------------------------------
>>> 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/iocor
>>>e/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/iocor
>>>e/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/iocor
>>>e/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/iocor
>>>e/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/iocor
>>>e/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
>>>
>>
>
Re: git commit: TS-2753: Add more SPDY and HTTPS statistics Reviewed: Bryan Call
Posted by Bryan Call <bc...@yahoo-inc.com>.
On May 26, 2014, at 6:00 PM, James Peach <jp...@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.
We wanted to get a better picture of the SSL handshake time so we can included it into the total request time and also look at it to see how much time we are saving on average by using session tickets and session caching. Measuring SSL handshake time should ideally be measured by the client, so we are trying to do the best we can with this approach.
>
> What doesproxy.process.spdy.total_time mean, and how would I use it?
This is the total time spent on SPDY requests. I think it is self explanatory.
>
> Why does proxy.process.ssl.total_success_handshake_count only count successes? What about failed handshakes?
When I was looking through the stats I saw that Ron was keeping track of the error cases. I would have to double check to make sure he is keeping track of the failed handshakes.
>
> Where is proxy.process.spdy.total_streams decremented?
Total stats are normally not decremented and are a total count since the system has been running or since the last time the stats were reset. We don't want to decrement it and there is another stat to see the number of active streams.
>
> 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?
There is a proxy.process.http.total_client_connections already. After the commit I was thinking that proxy.process.https.connection_count name should be changed to be more inline with the http stat.
>
> 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.
Yes, this can be cleaned up.
-Bryan
>
> On May 23, 2014, at 1:14 PM, bcall@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 <su...@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
>>
>