commit 452cfaacfc6e6b4313d2170c29e18d6399038999 Author: Nick Mathewson nickm@torproject.org Date: Mon Mar 11 22:06:07 2013 -0400

Track TLS overhead: diagnostic for bug 7707 --- changes/bug7707_diagnostic | 5 +++++ src/common/tortls.c | 25 +++++++++++++++++++++++++ src/common/tortls.h | 2 ++ src/or/status.c | 6 ++++++ 4 files changed, 38 insertions(+), 0 deletions(-)

diff --git a/changes/bug7707_diagnostic b/changes/bug7707_diagnostic new file mode 100644 index 0000000..0c3138e --- /dev/null +++ b/changes/bug7707_diagnostic @@ -0,0 +1,5 @@ + o Minor features: + - Add another diagnostic to the heartbeat message: track and log + overhead that TLS is adding to the data we write. If this is + high, we are sending too little data to SSL_write at a time. + Diagnostic for bug 7707. diff --git a/src/common/tortls.c b/src/common/tortls.c index a08910b..b7e5bc1 100644 --- a/src/common/tortls.c +++ b/src/common/tortls.c @@ -1997,6 +1997,10 @@ tor_tls_free(tor_tls_t *tls) if (!tls) return; tor_assert(tls->ssl); + { + size_t r,w; + tor_tls_get_n_raw_bytes(tls,&r,&w); /* ensure written_by_tls is updated */ + } #ifdef SSL_set_tlsext_host_name SSL_set_tlsext_host_name(tls->ssl, NULL); #endif @@ -2048,6 +2052,13 @@ tor_tls_read(tor_tls_t *tls, char *cp, size_t len) } }

+/** Total number of bytes that we've used TLS to send. Used to track TLS + * overhead. */ +static uint64_t total_bytes_written_over_tls = 0; +/** Total number of bytes that TLS has put on the network for us. Used to + * track TLS overhead. */ +static uint64_t total_bytes_written_by_tls = 0; + /** Underlying function for TLS writing. Write up to <b>n</b> * characters from <b>cp</b> onto <b>tls</b>. On success, returns the * number of characters written. On failure, returns TOR_TLS_ERROR, @@ -2074,6 +2085,7 @@ tor_tls_write(tor_tls_t *tls, const char *cp, size_t n) r = SSL_write(tls->ssl, cp, (int)n); err = tor_tls_get_error(tls, r, 0, "writing", LOG_INFO, LD_NET); if (err == TOR_TLS_DONE) { + total_bytes_written_over_tls += r; return r; } if (err == TOR_TLS_WANTWRITE || err == TOR_TLS_WANTREAD) { @@ -2563,10 +2575,23 @@ tor_tls_get_n_raw_bytes(tor_tls_t *tls, size_t *n_read, size_t *n_written) "r=%lu, last_read=%lu, w=%lu, last_written=%lu", r, tls->last_read_count, w, tls->last_write_count); } + total_bytes_written_by_tls += *n_written; tls->last_read_count = r; tls->last_write_count = w; }

+/** Return a ratio of the bytes that TLS has sent to the bytes that we've told + * it to send. Used to track whether our TLS records are getting too tiny. */ +double +tls_get_write_overhead_ratio(void) +{ + if (total_bytes_written_over_tls == 0) + return 1.0; + + return U64_TO_DBL(total_bytes_written_by_tls) / + U64_TO_DBL(total_bytes_written_over_tls); +} + /** Implement check_no_tls_errors: If there are any pending OpenSSL * errors, log an error message. */ void diff --git a/src/common/tortls.h b/src/common/tortls.h index 1ae6344..49c488b 100644 --- a/src/common/tortls.h +++ b/src/common/tortls.h @@ -95,6 +95,8 @@ void tor_tls_get_buffer_sizes(tor_tls_t *tls, size_t *rbuf_capacity, size_t *rbuf_bytes, size_t *wbuf_capacity, size_t *wbuf_bytes);

+double tls_get_write_overhead_ratio(void); + int tor_tls_used_v1_handshake(tor_tls_t *tls); int tor_tls_received_v3_certificate(tor_tls_t *tls); int tor_tls_get_num_server_handshakes(tor_tls_t *tls); diff --git a/src/or/status.c b/src/or/status.c index 126167d..e44de63 100644 --- a/src/or/status.c +++ b/src/or/status.c @@ -85,6 +85,7 @@ log_heartbeat(time_t now) char *bw_rcvd = NULL; char *uptime = NULL; const routerinfo_t *me; + double r = tls_get_write_overhead_ratio();

const or_options_t *options = get_options(); (void)now; @@ -112,6 +113,11 @@ log_heartbeat(time_t now) 100*(U64_TO_DBL(stats_n_data_bytes_packaged) / U64_TO_DBL(stats_n_data_cells_packaged*RELAY_PAYLOAD_SIZE)) );

+ if (r > 1.0) { + double overhead = ( r - 1.0 ) * 100.0; + log_notice(LD_HEARTBEAT, "TLS write overhead: %.f%%", overhead); + } + tor_free(uptime); tor_free(bw_sent); tor_free(bw_rcvd);