Skip to content

Add: Server-side TLS handshake milestones and timing fixes #12860

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Open
bryancall wants to merge 6 commits into
base: master
Choose a base branch
from
Open

Add: Server-side TLS handshake milestones and timing fixes #12860

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
6 commits
Select commit Hold shift + click to select a range
07e0f9c
Add server-side TLS handshake milestones and fix outbound TLS timing
bryancall Feb 5, 2026
9bac89e
Fix difference_msec() to check both start and end milestones for unset
bryancall Feb 5, 2026
d0ab0ac
Use SM_START as base for server_tls_handshake in slow log
bryancall Feb 5, 2026
9ef7b31
Add comments explaining the two server connection paths
bryancall Feb 5, 2026
16951f2
Make slow_log_report.pl backward compatible with old log format
bryancall Feb 5, 2026
2f0b819
Use pre-remap URL in slow log output
bryancall Feb 6, 2026
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 2 additions & 0 deletions doc/admin-guide/plugins/lua.en.rst
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -4971,6 +4971,8 @@ Milestone constants
TS_LUA_MILESTONE_PLUGIN_TOTAL
TS_LUA_MILESTONE_TLS_HANDSHAKE_START
TS_LUA_MILESTONE_TLS_HANDSHAKE_END
TS_LUA_MILESTONE_SERVER_TLS_HANDSHAKE_START
TS_LUA_MILESTONE_SERVER_TLS_HANDSHAKE_END


:ref:`TOP <admin-plugins-ts-lua>`
Expand Down
12 changes: 10 additions & 2 deletions doc/developer-guide/api/functions/TSHttpTxnMilestoneGet.en.rst
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -132,11 +132,19 @@ is successful.

.. enumerator:: TS_MILESTONE_TLS_HANDSHAKE_START

Timestamp when the server starts the TLS handshake. 0 if no handshake is performed (connection reuse).
Timestamp when the client starts the TLS handshake with the proxy. 0 if no handshake is performed (connection reuse).

.. enumerator:: TS_MILESTONE_TLS_HANDSHAKE_END

Timestamp when the server completes the TLS handshake. 0 if no handshake is performed (connection reuse).
Timestamp when the client completes the TLS handshake with the proxy. 0 if no handshake is performed (connection reuse).

.. enumerator:: TS_MILESTONE_SERVER_TLS_HANDSHAKE_START

Timestamp when the proxy starts the TLS handshake with the origin server. 0 if no handshake is performed (connection reuse or non-TLS origin).

.. enumerator:: TS_MILESTONE_SERVER_TLS_HANDSHAKE_END

Timestamp when the proxy completes the TLS handshake with the origin server. 0 if no handshake is performed (connection reuse or non-TLS origin).

.. enumerator:: TS_MILESTONE_LAST_ENTRY

Expand Down
2 changes: 1 addition & 1 deletion include/proxy/Milestones.h
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -64,7 +64,7 @@ template <class T, size_t entries> class Milestones
int64_t
difference_msec(T ms_start, T ms_end, int64_t missing = -1) const // Return "missing" when Milestone is not set
{
if (this->_milestones[static_cast<size_t>(ms_end)] == 0) {
if (this->_milestones[static_cast<size_t>(ms_start)] == 0 || this->_milestones[static_cast<size_t>(ms_end)] == 0) {
return missing;
}
return ink_hrtime_to_msec(this->_milestones[static_cast<size_t>(ms_end)] - this->_milestones[static_cast<size_t>(ms_start)]);
Expand Down
2 changes: 2 additions & 0 deletions include/ts/apidefs.h.in
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -978,6 +978,8 @@ enum TSMilestonesType {
TS_MILESTONE_PLUGIN_TOTAL,
TS_MILESTONE_TLS_HANDSHAKE_START,
TS_MILESTONE_TLS_HANDSHAKE_END,
TS_MILESTONE_SERVER_TLS_HANDSHAKE_START,
TS_MILESTONE_SERVER_TLS_HANDSHAKE_END,
TS_MILESTONE_LAST_ENTRY,
};

Expand Down
54 changes: 29 additions & 25 deletions plugins/lua/ts_lua_http_milestone.cc
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -19,30 +19,32 @@
#include "ts_lua_util.h"

typedef enum {
TS_LUA_MILESTONE_UA_BEGIN = TS_MILESTONE_UA_BEGIN,
TS_LUA_MILESTONE_UA_FIRST_READ = TS_MILESTONE_UA_FIRST_READ,
TS_LUA_MILESTONE_UA_READ_HEADER_DONE = TS_MILESTONE_UA_READ_HEADER_DONE,
TS_LUA_MILESTONE_UA_BEGIN_WRITE = TS_MILESTONE_UA_BEGIN_WRITE,
TS_LUA_MILESTONE_UA_CLOSE = TS_MILESTONE_UA_CLOSE,
TS_LUA_MILESTONE_SERVER_FIRST_CONNECT = TS_MILESTONE_SERVER_FIRST_CONNECT,
TS_LUA_MILESTONE_SERVER_CONNECT = TS_MILESTONE_SERVER_CONNECT,
TS_LUA_MILESTONE_SERVER_CONNECT_END = TS_MILESTONE_SERVER_CONNECT_END,
TS_LUA_MILESTONE_SERVER_BEGIN_WRITE = TS_MILESTONE_SERVER_BEGIN_WRITE,
TS_LUA_MILESTONE_SERVER_FIRST_READ = TS_MILESTONE_SERVER_FIRST_READ,
TS_LUA_MILESTONE_SERVER_READ_HEADER_DONE = TS_MILESTONE_SERVER_READ_HEADER_DONE,
TS_LUA_MILESTONE_SERVER_CLOSE = TS_MILESTONE_SERVER_CLOSE,
TS_LUA_MILESTONE_CACHE_OPEN_READ_BEGIN = TS_MILESTONE_CACHE_OPEN_READ_BEGIN,
TS_LUA_MILESTONE_CACHE_OPEN_READ_END = TS_MILESTONE_CACHE_OPEN_READ_END,
TS_LUA_MILESTONE_CACHE_OPEN_WRITE_BEGIN = TS_MILESTONE_CACHE_OPEN_WRITE_BEGIN,
TS_LUA_MILESTONE_CACHE_OPEN_WRITE_END = TS_MILESTONE_CACHE_OPEN_WRITE_END,
TS_LUA_MILESTONE_DNS_LOOKUP_BEGIN = TS_MILESTONE_DNS_LOOKUP_BEGIN,
TS_LUA_MILESTONE_DNS_LOOKUP_END = TS_MILESTONE_DNS_LOOKUP_END,
TS_LUA_MILESTONE_SM_START = TS_MILESTONE_SM_START,
TS_LUA_MILESTONE_SM_FINISH = TS_MILESTONE_SM_FINISH,
TS_LUA_MILESTONE_PLUGIN_ACTIVE = TS_MILESTONE_PLUGIN_ACTIVE,
TS_LUA_MILESTONE_PLUGIN_TOTAL = TS_MILESTONE_PLUGIN_TOTAL,
TS_LUA_MILESTONE_TLS_HANDSHAKE_START = TS_MILESTONE_TLS_HANDSHAKE_START,
TS_LUA_MILESTONE_TLS_HANDSHAKE_END = TS_MILESTONE_TLS_HANDSHAKE_END
TS_LUA_MILESTONE_UA_BEGIN = TS_MILESTONE_UA_BEGIN,
TS_LUA_MILESTONE_UA_FIRST_READ = TS_MILESTONE_UA_FIRST_READ,
TS_LUA_MILESTONE_UA_READ_HEADER_DONE = TS_MILESTONE_UA_READ_HEADER_DONE,
TS_LUA_MILESTONE_UA_BEGIN_WRITE = TS_MILESTONE_UA_BEGIN_WRITE,
TS_LUA_MILESTONE_UA_CLOSE = TS_MILESTONE_UA_CLOSE,
TS_LUA_MILESTONE_SERVER_FIRST_CONNECT = TS_MILESTONE_SERVER_FIRST_CONNECT,
TS_LUA_MILESTONE_SERVER_CONNECT = TS_MILESTONE_SERVER_CONNECT,
TS_LUA_MILESTONE_SERVER_CONNECT_END = TS_MILESTONE_SERVER_CONNECT_END,
TS_LUA_MILESTONE_SERVER_BEGIN_WRITE = TS_MILESTONE_SERVER_BEGIN_WRITE,
TS_LUA_MILESTONE_SERVER_FIRST_READ = TS_MILESTONE_SERVER_FIRST_READ,
TS_LUA_MILESTONE_SERVER_READ_HEADER_DONE = TS_MILESTONE_SERVER_READ_HEADER_DONE,
TS_LUA_MILESTONE_SERVER_CLOSE = TS_MILESTONE_SERVER_CLOSE,
TS_LUA_MILESTONE_CACHE_OPEN_READ_BEGIN = TS_MILESTONE_CACHE_OPEN_READ_BEGIN,
TS_LUA_MILESTONE_CACHE_OPEN_READ_END = TS_MILESTONE_CACHE_OPEN_READ_END,
TS_LUA_MILESTONE_CACHE_OPEN_WRITE_BEGIN = TS_MILESTONE_CACHE_OPEN_WRITE_BEGIN,
TS_LUA_MILESTONE_CACHE_OPEN_WRITE_END = TS_MILESTONE_CACHE_OPEN_WRITE_END,
TS_LUA_MILESTONE_DNS_LOOKUP_BEGIN = TS_MILESTONE_DNS_LOOKUP_BEGIN,
TS_LUA_MILESTONE_DNS_LOOKUP_END = TS_MILESTONE_DNS_LOOKUP_END,
TS_LUA_MILESTONE_SM_START = TS_MILESTONE_SM_START,
TS_LUA_MILESTONE_SM_FINISH = TS_MILESTONE_SM_FINISH,
TS_LUA_MILESTONE_PLUGIN_ACTIVE = TS_MILESTONE_PLUGIN_ACTIVE,
TS_LUA_MILESTONE_PLUGIN_TOTAL = TS_MILESTONE_PLUGIN_TOTAL,
TS_LUA_MILESTONE_TLS_HANDSHAKE_START = TS_MILESTONE_TLS_HANDSHAKE_START,
TS_LUA_MILESTONE_TLS_HANDSHAKE_END = TS_MILESTONE_TLS_HANDSHAKE_END,
TS_LUA_MILESTONE_SERVER_TLS_HANDSHAKE_START = TS_MILESTONE_SERVER_TLS_HANDSHAKE_START,
TS_LUA_MILESTONE_SERVER_TLS_HANDSHAKE_END = TS_MILESTONE_SERVER_TLS_HANDSHAKE_END
} TSLuaMilestoneType;

ts_lua_var_item ts_lua_milestone_type_vars[] = {TS_LUA_MAKE_VAR_ITEM(TS_LUA_MILESTONE_UA_BEGIN),
Expand All @@ -68,7 +70,9 @@ ts_lua_var_item ts_lua_milestone_type_vars[] = {TS_LUA_MAKE_VAR_ITEM(TS_LUA_MILE
TS_LUA_MAKE_VAR_ITEM(TS_LUA_MILESTONE_PLUGIN_ACTIVE),
TS_LUA_MAKE_VAR_ITEM(TS_LUA_MILESTONE_PLUGIN_TOTAL),
TS_LUA_MAKE_VAR_ITEM(TS_LUA_MILESTONE_TLS_HANDSHAKE_START),
TS_LUA_MAKE_VAR_ITEM(TS_LUA_MILESTONE_TLS_HANDSHAKE_END)};
TS_LUA_MAKE_VAR_ITEM(TS_LUA_MILESTONE_TLS_HANDSHAKE_END),
TS_LUA_MAKE_VAR_ITEM(TS_LUA_MILESTONE_SERVER_TLS_HANDSHAKE_START),
TS_LUA_MAKE_VAR_ITEM(TS_LUA_MILESTONE_SERVER_TLS_HANDSHAKE_END)};

static void ts_lua_inject_http_milestone_variables(lua_State *L);

Expand Down
6 changes: 6 additions & 0 deletions src/iocore/net/SSLNetVConnection.cc
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -1579,6 +1579,12 @@ SSLNetVConnection::sslClientHandShakeEvent(int &err)
Metrics::Counter::increment(ssl_rsb.total_success_handshake_count_out);

sslHandshakeStatus = SSLHandshakeStatus::SSL_HANDSHAKE_DONE;

// Record TLS handshake end time for outbound connections
if (this->get_tls_handshake_begin_time()) {
this->_record_tls_handshake_end_time();
}

return EVENT_DONE;

case SSL_ERROR_WANT_WRITE:
Expand Down
47 changes: 38 additions & 9 deletions src/proxy/http/HttpSM.cc
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -1881,21 +1881,39 @@ HttpSM::state_http_server_open(int event, void *data)
case CONNECT_EVENT_RETRY:
do_http_server_open();
break;
case CONNECT_EVENT_TXN:
case CONNECT_EVENT_TXN: {
// Multiplexed connection path (e.g. HTTP/2): ConnectingEntry created the session
// and dispatched this event. Get the netvc from the PoolableSession.
SMDbg(dbg_ctl_http, "Connection handshake complete via CONNECT_EVENT_TXN");
if (this->create_server_txn(static_cast<PoolableSession *>(data))) {
PoolableSession *session = static_cast<PoolableSession *>(data);
ink_assert(session != nullptr);
// Capture server TLS handshake timing from the session's netvc
if (auto *netvc = session->get_netvc()) {
if (auto tbs = netvc->get_service<TLSBasicSupport>()) {
milestones[TS_MILESTONE_SERVER_TLS_HANDSHAKE_START] = tbs->get_tls_handshake_begin_time();
milestones[TS_MILESTONE_SERVER_TLS_HANDSHAKE_END] = tbs->get_tls_handshake_end_time();
}
}
if (this->create_server_txn(session)) {
t_state.current.server->clear_connect_fail();
handle_http_server_open();
} else { // Failed to create transaction. Maybe too many active transactions already
// Try again (probably need a bounding counter here)
do_http_server_open(false);
}
return 0;
}
case VC_EVENT_READ_COMPLETE:
case VC_EVENT_WRITE_READY:
case VC_EVENT_WRITE_COMPLETE:
// Update the time out to the regular connection timeout.
// Direct connection path (e.g. HTTP/1): HttpSM owns the netvc directly
// and creates the session itself.
SMDbg(dbg_ctl_http_ss, "Connection handshake complete");
// Capture server TLS handshake timing if this is a TLS connection
if (auto tbs = _netvc->get_service<TLSBasicSupport>()) {
milestones[TS_MILESTONE_SERVER_TLS_HANDSHAKE_START] = tbs->get_tls_handshake_begin_time();
milestones[TS_MILESTONE_SERVER_TLS_HANDSHAKE_END] = tbs->get_tls_handshake_end_time();
}
this->create_server_txn(this->create_server_session(*_netvc, _netvc_read_buffer, _netvc_reader));
t_state.current.server->clear_connect_fail();
handle_http_server_open();
Expand Down Expand Up @@ -7755,12 +7773,21 @@ HttpSM::update_stats()

// print slow requests if the threshold is set (> 0) and if we are over the time threshold
if (t_state.txn_conf->slow_log_threshold != 0 && ink_hrtime_from_msec(t_state.txn_conf->slow_log_threshold) < total_time) {
// Use the unmapped (pre-remap) URL so the slow log shows the incoming client URL.
// unmapped_url may not be valid if the transaction ended before reaching the remap
// stage (e.g. client timeout during header read, malformed request). In that case
// fall back to client_request URL which hasn't been remapped yet either.
char url_string[256] = "";
int offset = 0;
int skip = 0;

t_state.hdr_info.client_request.url_print(url_string, sizeof(url_string) - 1, &offset, &skip);
url_string[offset] = 0; // NULL terminate the string
int url_length = 0;
if (t_state.unmapped_url.valid()) {
t_state.unmapped_url.string_get_buf(url_string, sizeof(url_string) - 1, &url_length);
} else {
int offset = 0;
int skip = 0;
t_state.hdr_info.client_request.url_print(url_string, sizeof(url_string) - 1, &offset, &skip);
url_length = offset;
}
url_string[url_length] = 0; // NULL terminate the string

// unique id
char unique_id_string[128] = "";
Expand Down Expand Up @@ -7799,7 +7826,7 @@ HttpSM::update_stats()
"fd: %d "
"client state: %d "
"server state: %d "
"tls_handshake: %.3f "
"ua_tls_handshake: %.3f "
"ua_begin: %.3f "
"ua_first_read: %.3f "
"ua_read_header_done: %.3f "
Expand All @@ -7811,6 +7838,7 @@ HttpSM::update_stats()
"dns_lookup_end: %.3f "
"server_connect: %.3f "
"server_connect_end: %.3f "
"server_tls_handshake: %.3f "
"server_first_read: %.3f "
"server_read_header_done: %.3f "
"server_close: %.3f "
Expand All @@ -7834,6 +7862,7 @@ HttpSM::update_stats()
milestones.difference_sec(TS_MILESTONE_SM_START, TS_MILESTONE_DNS_LOOKUP_END),
milestones.difference_sec(TS_MILESTONE_SM_START, TS_MILESTONE_SERVER_CONNECT),
milestones.difference_sec(TS_MILESTONE_SM_START, TS_MILESTONE_SERVER_CONNECT_END),
milestones.difference_sec(TS_MILESTONE_SM_START, TS_MILESTONE_SERVER_TLS_HANDSHAKE_END),
milestones.difference_sec(TS_MILESTONE_SM_START, TS_MILESTONE_SERVER_FIRST_READ),
milestones.difference_sec(TS_MILESTONE_SM_START, TS_MILESTONE_SERVER_READ_HEADER_DONE),
milestones.difference_sec(TS_MILESTONE_SM_START, TS_MILESTONE_SERVER_CLOSE),
Expand Down
54 changes: 30 additions & 24 deletions src/proxy/logging/LogField.cc
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -191,30 +191,36 @@ struct milestone {
};

static const milestone milestones[] = {
{"TS_MILESTONE_UA_BEGIN", TS_MILESTONE_UA_BEGIN },
{"TS_MILESTONE_UA_FIRST_READ", TS_MILESTONE_UA_FIRST_READ },
{"TS_MILESTONE_UA_READ_HEADER_DONE", TS_MILESTONE_UA_READ_HEADER_DONE },
{"TS_MILESTONE_UA_BEGIN_WRITE", TS_MILESTONE_UA_BEGIN_WRITE },
{"TS_MILESTONE_UA_CLOSE", TS_MILESTONE_UA_CLOSE },
{"TS_MILESTONE_SERVER_FIRST_CONNECT", TS_MILESTONE_SERVER_FIRST_CONNECT },
{"TS_MILESTONE_SERVER_CONNECT", TS_MILESTONE_SERVER_CONNECT },
{"TS_MILESTONE_SERVER_CONNECT_END", TS_MILESTONE_SERVER_CONNECT_END },
{"TS_MILESTONE_SERVER_BEGIN_WRITE", TS_MILESTONE_SERVER_BEGIN_WRITE },
{"TS_MILESTONE_SERVER_FIRST_READ", TS_MILESTONE_SERVER_FIRST_READ },
{"TS_MILESTONE_SERVER_READ_HEADER_DONE", TS_MILESTONE_SERVER_READ_HEADER_DONE},
{"TS_MILESTONE_SERVER_CLOSE", TS_MILESTONE_SERVER_CLOSE },
{"TS_MILESTONE_CACHE_OPEN_READ_BEGIN", TS_MILESTONE_CACHE_OPEN_READ_BEGIN },
{"TS_MILESTONE_CACHE_OPEN_READ_END", TS_MILESTONE_CACHE_OPEN_READ_END },
{"TS_MILESTONE_CACHE_OPEN_WRITE_BEGIN", TS_MILESTONE_CACHE_OPEN_WRITE_BEGIN },
{"TS_MILESTONE_CACHE_OPEN_WRITE_END", TS_MILESTONE_CACHE_OPEN_WRITE_END },
{"TS_MILESTONE_DNS_LOOKUP_BEGIN", TS_MILESTONE_DNS_LOOKUP_BEGIN },
{"TS_MILESTONE_DNS_LOOKUP_END", TS_MILESTONE_DNS_LOOKUP_END },
{"TS_MILESTONE_SM_START", TS_MILESTONE_SM_START },
{"TS_MILESTONE_SM_FINISH", TS_MILESTONE_SM_FINISH },
{"TS_MILESTONE_PLUGIN_ACTIVE", TS_MILESTONE_PLUGIN_ACTIVE },
{"TS_MILESTONE_PLUGIN_TOTAL", TS_MILESTONE_PLUGIN_TOTAL },
{"TS_MILESTONE_TLS_HANDSHAKE_START", TS_MILESTONE_TLS_HANDSHAKE_START },
{"TS_MILESTONE_TLS_HANDSHAKE_END", TS_MILESTONE_TLS_HANDSHAKE_END },
{"TS_MILESTONE_UA_BEGIN", TS_MILESTONE_UA_BEGIN },
{"TS_MILESTONE_UA_FIRST_READ", TS_MILESTONE_UA_FIRST_READ },
{"TS_MILESTONE_UA_READ_HEADER_DONE", TS_MILESTONE_UA_READ_HEADER_DONE },
{"TS_MILESTONE_UA_BEGIN_WRITE", TS_MILESTONE_UA_BEGIN_WRITE },
{"TS_MILESTONE_UA_CLOSE", TS_MILESTONE_UA_CLOSE },
{"TS_MILESTONE_SERVER_FIRST_CONNECT", TS_MILESTONE_SERVER_FIRST_CONNECT },
{"TS_MILESTONE_SERVER_CONNECT", TS_MILESTONE_SERVER_CONNECT },
{"TS_MILESTONE_SERVER_CONNECT_END", TS_MILESTONE_SERVER_CONNECT_END },
{"TS_MILESTONE_SERVER_BEGIN_WRITE", TS_MILESTONE_SERVER_BEGIN_WRITE },
{"TS_MILESTONE_SERVER_FIRST_READ", TS_MILESTONE_SERVER_FIRST_READ },
{"TS_MILESTONE_SERVER_READ_HEADER_DONE", TS_MILESTONE_SERVER_READ_HEADER_DONE },
{"TS_MILESTONE_SERVER_CLOSE", TS_MILESTONE_SERVER_CLOSE },
{"TS_MILESTONE_CACHE_OPEN_READ_BEGIN", TS_MILESTONE_CACHE_OPEN_READ_BEGIN },
{"TS_MILESTONE_CACHE_OPEN_READ_END", TS_MILESTONE_CACHE_OPEN_READ_END },
{"TS_MILESTONE_CACHE_OPEN_WRITE_BEGIN", TS_MILESTONE_CACHE_OPEN_WRITE_BEGIN },
{"TS_MILESTONE_CACHE_OPEN_WRITE_END", TS_MILESTONE_CACHE_OPEN_WRITE_END },
{"TS_MILESTONE_DNS_LOOKUP_BEGIN", TS_MILESTONE_DNS_LOOKUP_BEGIN },
{"TS_MILESTONE_DNS_LOOKUP_END", TS_MILESTONE_DNS_LOOKUP_END },
{"TS_MILESTONE_SM_START", TS_MILESTONE_SM_START },
{"TS_MILESTONE_SM_FINISH", TS_MILESTONE_SM_FINISH },
{"TS_MILESTONE_PLUGIN_ACTIVE", TS_MILESTONE_PLUGIN_ACTIVE },
{"TS_MILESTONE_PLUGIN_TOTAL", TS_MILESTONE_PLUGIN_TOTAL },
{"TS_MILESTONE_TLS_HANDSHAKE_START",
TS_MILESTONE_TLS_HANDSHAKE_START }, // RENAME in ATS 11 - this is the client-side TLS handshake
{"TS_MILESTONE_TLS_HANDSHAKE_END", TS_MILESTONE_TLS_HANDSHAKE_END }, // RENAME in ATS 11 - this is the client-side TLS handshake
{"TS_MILESTONE_SERVER_TLS_HANDSHAKE_START", TS_MILESTONE_SERVER_TLS_HANDSHAKE_START},
{"TS_MILESTONE_SERVER_TLS_HANDSHAKE_END", TS_MILESTONE_SERVER_TLS_HANDSHAKE_END },
// TODO: Add these in ATS 11, remove TLS_HANDSHAKE_* above
// {"TS_MILESTONE_UA_TLS_HANDSHAKE_START", TS_MILESTONE_UA_TLS_HANDSHAKE_START },
// {"TS_MILESTONE_UA_TLS_HANDSHAKE_END", TS_MILESTONE_UA_TLS_HANDSHAKE_END },
};

void
Expand Down
13 changes: 8 additions & 5 deletions tools/slow_log_report.pl
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -41,10 +41,12 @@ ($)
printf("%25s %10s %10s %10s %10s %10s %10s %10s %10s\n",
'key', 'total', 'count', 'mean', 'median', '95th', '99th', 'min', 'max');
foreach my $key (
'tls_handshake', 'ua_begin', 'ua_first_read', 'ua_read_header_done', 'cache_open_read_begin',
'cache_open_read_end', 'cache_open_write_begin', 'cache_open_write_end', 'dns_lookup_begin',
'dns_lookup_end', 'server_connect', 'server_connect_end', 'server_first_read',
'server_read_header_done', 'server_close', 'ua_close', 'sm_finish', 'plugin_active', 'plugin_total'
'tls_handshake', # TODO ATS 11: remove once old log format is no longer supported
'ua_tls_handshake', 'ua_begin', 'ua_first_read', 'ua_read_header_done',
'cache_open_read_begin', 'cache_open_read_end', 'cache_open_write_begin', 'cache_open_write_end',
'dns_lookup_begin', 'dns_lookup_end', 'server_connect', 'server_connect_end', 'server_tls_handshake',
'server_first_read', 'server_read_header_done', 'server_close', 'ua_close', 'sm_finish',
'plugin_active', 'plugin_total'
)
{

Expand Down Expand Up @@ -78,7 +80,8 @@ ($)
s/unique id/unique_id/;
s/server state/server_state/;
s/client state/client_state/;
if (m|Slow Request: .+ (tls_handshake: .+)|) {
# TODO ATS 11: remove 'tls_handshake' match once old log format is no longer supported
if (m|Slow Request: .+ ((?:ua_)?tls_handshake: .+)|) {
my %data = split(/: | /, $1);
foreach my $key (keys %data) {
next if (!defined $data{$key});
Expand Down