From 06e15c8b7cd9a8111b438c4ba58d47fda92894bd Mon Sep 17 00:00:00 2001 From: Alexander Færøy Date: Tue, 7 Feb 2017 14:24:51 +0000 Subject: Add debug log statement when sending a directory command. This patch adds a debug log statement when sending a request to a directory server. The information logged includes: the payload size (if available), the total size of the request, the address and port of the directory server, and the purpose of the directory connection. See: https://bugs.torproject.org/21206 --- src/or/directory.c | 27 ++++++++++++++++++++++++--- 1 file changed, 24 insertions(+), 3 deletions(-) (limited to 'src/or') diff --git a/src/or/directory.c b/src/or/directory.c index 93dc488d15..90d6fbfc2b 100644 --- a/src/or/directory.c +++ b/src/or/directory.c @@ -14,6 +14,7 @@ #include "connection.h" #include "connection_edge.h" #include "control.h" +#include "compat.h" #define DIRECTORY_PRIVATE #include "directory.h" #include "dirserv.h" @@ -1469,7 +1470,9 @@ directory_send_command(dir_connection_t *conn, char decorated_address[128]; smartlist_t *headers = smartlist_new(); char *url; + size_t url_len; char request[8192]; + size_t request_len, total_request_len = 0; const char *httpcommand = NULL; tor_assert(conn); @@ -1615,8 +1618,14 @@ directory_send_command(dir_connection_t *conn, } tor_snprintf(request, sizeof(request), "%s %s", httpcommand, proxystring); - connection_write_to_buf(request, strlen(request), TO_CONN(conn)); - connection_write_to_buf(url, strlen(url), TO_CONN(conn)); + + request_len = strlen(request); + total_request_len += request_len; + connection_write_to_buf(request, request_len, TO_CONN(conn)); + + url_len = strlen(url); + total_request_len += url_len; + connection_write_to_buf(url, url_len, TO_CONN(conn)); tor_free(url); if (!strcmp(httpcommand, "POST") || payload) { @@ -1631,15 +1640,27 @@ directory_send_command(dir_connection_t *conn, tor_free(header); } - connection_write_to_buf(request, strlen(request), TO_CONN(conn)); + request_len = strlen(request); + total_request_len += request_len; + connection_write_to_buf(request, request_len, TO_CONN(conn)); if (payload) { /* then send the payload afterwards too */ connection_write_to_buf(payload, payload_len, TO_CONN(conn)); + total_request_len += payload_len; } SMARTLIST_FOREACH(headers, char *, h, tor_free(h)); smartlist_free(headers); + + log_debug(LD_DIR, + "Sent request to directory server '%s:%d': " + "(purpose: %d, request size: " U64_FORMAT ", " + "payload size: " U64_FORMAT ")", + conn->base_.address, conn->base_.port, + conn->base_.purpose, + U64_PRINTF_ARG(total_request_len), + U64_PRINTF_ARG(payload ? payload_len : 0)); } /** Parse an HTTP request string headers of the form -- cgit v1.2.3-54-g00ecf From bf37ca07fcccca873f1085d203e98eb41052893d Mon Sep 17 00:00:00 2001 From: Alexander Færøy Date: Tue, 7 Feb 2017 14:29:37 +0000 Subject: Be explicit about body size in log messages. This patch makes the log-statements in `connection_dir_client_reached_eof` more explicit by writing "body size" instead of just "size" which could be confused as being the size of the entire response, which would include HTTP status-line and headers. See: https://bugs.torproject.org/21206 --- src/or/directory.c | 16 ++++++++-------- 1 file changed, 8 insertions(+), 8 deletions(-) (limited to 'src/or') diff --git a/src/or/directory.c b/src/or/directory.c index 90d6fbfc2b..3881adba78 100644 --- a/src/or/directory.c +++ b/src/or/directory.c @@ -2119,7 +2119,7 @@ connection_dir_client_reached_eof(dir_connection_t *conn) networkstatus_consensus_download_failed(status_code, flavname); return -1; } - log_info(LD_DIR,"Received consensus directory (size %d) from server " + log_info(LD_DIR,"Received consensus directory (body size %d) from server " "'%s:%d'", (int)body_len, conn->base_.address, conn->base_.port); if ((r=networkstatus_set_current_consensus(body, flavname, 0, conn->identity_digest))<0) { @@ -2158,7 +2158,7 @@ connection_dir_client_reached_eof(dir_connection_t *conn) tor_free(body); tor_free(headers); tor_free(reason); return -1; } - log_info(LD_DIR,"Received authority certificates (size %d) from server " + log_info(LD_DIR,"Received authority certificates (body size %d) from server " "'%s:%d'", (int)body_len, conn->base_.address, conn->base_.port); /* @@ -2194,7 +2194,7 @@ connection_dir_client_reached_eof(dir_connection_t *conn) if (conn->base_.purpose == DIR_PURPOSE_FETCH_STATUS_VOTE) { const char *msg; int st; - log_info(LD_DIR,"Got votes (size %d) from server %s:%d", + log_info(LD_DIR,"Got votes (body size %d) from server %s:%d", (int)body_len, conn->base_.address, conn->base_.port); if (status_code != 200) { log_warn(LD_DIR, @@ -2214,7 +2214,7 @@ connection_dir_client_reached_eof(dir_connection_t *conn) } if (conn->base_.purpose == DIR_PURPOSE_FETCH_DETACHED_SIGNATURES) { const char *msg = NULL; - log_info(LD_DIR,"Got detached signatures (size %d) from server %s:%d", + log_info(LD_DIR,"Got detached signatures (body size %d) from server %s:%d", (int)body_len, conn->base_.address, conn->base_.port); if (status_code != 200) { log_warn(LD_DIR, @@ -2238,7 +2238,7 @@ connection_dir_client_reached_eof(dir_connection_t *conn) int n_asked_for = 0; int descriptor_digests = conn->requested_resource && !strcmpstart(conn->requested_resource,"d/"); - log_info(LD_DIR,"Received %s (size %d) from server '%s:%d'", + log_info(LD_DIR,"Received %s (body size %d) from server '%s:%d'", was_ei ? "extra server info" : "server info", (int)body_len, conn->base_.address, conn->base_.port); if (conn->requested_resource && @@ -2316,7 +2316,7 @@ connection_dir_client_reached_eof(dir_connection_t *conn) if (conn->base_.purpose == DIR_PURPOSE_FETCH_MICRODESC) { smartlist_t *which = NULL; log_info(LD_DIR,"Received answer to microdescriptor request (status %d, " - "size %d) from server '%s:%d'", + "body size %d) from server '%s:%d'", status_code, (int)body_len, conn->base_.address, conn->base_.port); tor_assert(conn->requested_resource && @@ -2468,7 +2468,7 @@ connection_dir_client_reached_eof(dir_connection_t *conn) conn->identity_digest, \ NULL) ) tor_assert(conn->rend_data); - log_info(LD_REND,"Received rendezvous descriptor (size %d, status %d " + log_info(LD_REND,"Received rendezvous descriptor (body size %d, status %d " "(%s))", (int)body_len, status_code, escaped(reason)); switch (status_code) { @@ -3742,7 +3742,7 @@ directory_handle_command_post,(dir_connection_t *conn, const char *headers, if (connection_dir_is_encrypted(conn) && !strcmpstart(url,"/tor/rendezvous2/publish")) { if (rend_cache_store_v2_desc_as_dir(body) < 0) { - log_warn(LD_REND, "Rejected v2 rend descriptor (length %d) from %s.", + log_warn(LD_REND, "Rejected v2 rend descriptor (body size %d) from %s.", (int)body_len, conn->base_.address); write_http_status_line(conn, 400, "Invalid v2 service descriptor rejected"); -- cgit v1.2.3-54-g00ecf From 56bbaed0dc61190e730178d1d5a7f0cc10625bdd Mon Sep 17 00:00:00 2001 From: Alexander Færøy Date: Tue, 7 Feb 2017 14:34:49 +0000 Subject: Log response size in connection_dir_client_reached_eof() This patch ensures that we log the size of the inbuf when a directory client have reached EOF on the connection. See: https://bugs.torproject.org/21206 --- src/or/directory.c | 10 ++++++++-- 1 file changed, 8 insertions(+), 2 deletions(-) (limited to 'src/or') diff --git a/src/or/directory.c b/src/or/directory.c index 3881adba78..36714bc110 100644 --- a/src/or/directory.c +++ b/src/or/directory.c @@ -1954,6 +1954,9 @@ connection_dir_client_reached_eof(dir_connection_t *conn) conn->base_.purpose == DIR_PURPOSE_FETCH_MICRODESC); time_t now = time(NULL); int src_code; + size_t received_bytes; + + received_bytes = connection_get_inbuf_len(TO_CONN(conn)); switch (connection_fetch_from_buf_http(TO_CONN(conn), &headers, MAX_HEADERS_SIZE, @@ -1982,10 +1985,13 @@ connection_dir_client_reached_eof(dir_connection_t *conn) log_debug(LD_DIR, "Received response from directory server '%s:%d': %d %s " - "(purpose: %d)", + "(purpose: %d, response size: " U64_FORMAT ", " + "compression: %d)", conn->base_.address, conn->base_.port, status_code, escaped(reason), - conn->base_.purpose); + conn->base_.purpose, + U64_PRINTF_ARG(received_bytes), + compression); if (conn->guard_state) { /* we count the connection as successful once we can read from it. We do -- cgit v1.2.3-54-g00ecf From a0ee5777b091b6af55615f3bcf5f518fc8e2d2a7 Mon Sep 17 00:00:00 2001 From: Alexander Færøy Date: Thu, 9 Feb 2017 16:48:11 +0000 Subject: Change RELAY_BEGINDIR to RELAY_BEGIN_DIR in comments. This is a purely cosmetic patch that changes RELAY_BEGINDIR in various comments to RELAY_BEGIN_DIR, which should make it easier to grep for the symbols. --- src/or/connection_edge.c | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) (limited to 'src/or') diff --git a/src/or/connection_edge.c b/src/or/connection_edge.c index ef551048b8..ca68099d5f 100644 --- a/src/or/connection_edge.c +++ b/src/or/connection_edge.c @@ -29,7 +29,7 @@ *
  • DNS lookup streams, created on the exit side in response to * a RELAY_RESOLVE cell from a client. *
  • Tunneled directory streams, created on the directory cache side - * in response to a RELAY_BEGINDIR cell. These streams attach directly + * in response to a RELAY_BEGIN_DIR cell. These streams attach directly * to a dir_connection_t object without ever using TCP. * * @@ -1762,7 +1762,7 @@ connection_ap_handshake_rewrite_and_attach(entry_connection_t *conn, conn->entry_cfg.ipv6_traffic = 0; /* Still handling CONNECT. Now, check for exit enclaves. (Which we - * don't do on BEGINDIR, or when there is a chosen exit.) + * don't do on BEGIN_DIR, or when there is a chosen exit.) * * TODO: Should we remove this? Exit enclaves are nutty and don't * work very well @@ -2995,7 +2995,7 @@ connection_ap_handshake_socks_reply(entry_connection_t *conn, char *reply, return; } -/** Read a RELAY_BEGIN or RELAY_BEGINDIR cell from cell, decode it, and +/** Read a RELAY_BEGIN or RELAY_BEGIN_DIR cell from cell, decode it, and * place the result in bcell. On success return 0; on failure return * <0 and set *end_reason_out to the end reason we should send back to * the client. -- cgit v1.2.3-54-g00ecf From 89334a040d6496191e3cee1d69ecd3c0e566583a Mon Sep 17 00:00:00 2001 From: Alexander Færøy Date: Fri, 10 Feb 2017 23:01:52 +0000 Subject: Remove unused variable in directory_command_should_use_begindir() This patch removes the unused router_purpose variable in directory_command_should_use_begindir(). --- src/or/directory.c | 6 ++---- 1 file changed, 2 insertions(+), 4 deletions(-) (limited to 'src/or') diff --git a/src/or/directory.c b/src/or/directory.c index 36714bc110..4ef39af1dd 100644 --- a/src/or/directory.c +++ b/src/or/directory.c @@ -1078,11 +1078,10 @@ directory_must_use_begindir(const or_options_t *options) static int directory_command_should_use_begindir(const or_options_t *options, const tor_addr_t *addr, - int or_port, uint8_t router_purpose, + int or_port, dir_indirection_t indirection, const char **reason) { - (void) router_purpose; tor_assert(reason); *reason = NULL; @@ -1190,8 +1189,7 @@ directory_initiate_command_rend(const tor_addr_port_t *or_addr_port, * send our directory request)? */ const int use_begindir = directory_command_should_use_begindir(options, &or_addr_port->addr, or_addr_port->port, - router_purpose, indirection, - &begindir_reason); + indirection, &begindir_reason); /* Will the connection go via a three-hop Tor circuit? Note that this * is separate from whether it will use_begindir. */ const int anonymized_connection = dirind_is_anon(indirection); -- cgit v1.2.3-54-g00ecf From 3848d236439d476793f03699519a818f26f56c6c Mon Sep 17 00:00:00 2001 From: Alexander Færøy Date: Mon, 13 Feb 2017 16:57:21 +0000 Subject: Save number of sent/received RELAY_DATA cells for directory connections. This patch makes us store the number of sent and received RELAY_DATA cells used for directory connections. We log the numbers after we have received an EOF in connection_dir_client_reached_eof() from the directory server. --- src/or/directory.c | 13 +++++++++---- src/or/or.h | 8 ++++++++ src/or/relay.c | 20 ++++++++++++++++++++ 3 files changed, 37 insertions(+), 4 deletions(-) (limited to 'src/or') diff --git a/src/or/directory.c b/src/or/directory.c index 4ef39af1dd..78cee29690 100644 --- a/src/or/directory.c +++ b/src/or/directory.c @@ -1983,12 +1983,17 @@ connection_dir_client_reached_eof(dir_connection_t *conn) log_debug(LD_DIR, "Received response from directory server '%s:%d': %d %s " - "(purpose: %d, response size: " U64_FORMAT ", " - "compression: %d)", + "(purpose: %d, response size: " U64_FORMAT +#ifdef MEASUREMENTS_21206 + ", data cells received: %d, data cells sent: %d" +#endif + ", compression: %d)", conn->base_.address, conn->base_.port, status_code, - escaped(reason), - conn->base_.purpose, + escaped(reason), conn->base_.purpose, U64_PRINTF_ARG(received_bytes), +#ifdef MEASUREMENTS_21206 + conn->data_cells_received, conn->data_cells_sent, +#endif compression); if (conn->guard_state) { diff --git a/src/or/or.h b/src/or/or.h index 0db9f23604..0e2dc2401b 100644 --- a/src/or/or.h +++ b/src/or/or.h @@ -1786,6 +1786,14 @@ typedef struct dir_connection_t { * that's going away and being used on channels instead. The dirserver still * needs this for the incoming side, so it's moved here. */ uint64_t dirreq_id; + +#ifdef MEASUREMENTS_21206 + /** Number of RELAY_DATA cells received. */ + uint32_t data_cells_received; + + /** Number of RELAY_DATA cells sent. */ + uint32_t data_cells_sent; +#endif } dir_connection_t; /** Subtype of connection_t for an connection to a controller. */ diff --git a/src/or/relay.c b/src/or/relay.c index 2e76a8ec36..6b3f34f3e5 100644 --- a/src/or/relay.c +++ b/src/or/relay.c @@ -732,6 +732,16 @@ connection_edge_send_command(edge_connection_t *fromconn, return -1; } +#ifdef MEASUREMENTS_21206 + /* Keep track of the number of RELAY_DATA cells sent for directory + * connections. */ + connection_t *linked_conn = TO_CONN(fromconn)->linked_conn; + + if (linked_conn && linked_conn->type == CONN_TYPE_DIR) { + ++(TO_DIR_CONN(linked_conn)->data_cells_sent); + } +#endif + return relay_send_command_from_edge(fromconn->stream_id, circ, relay_command, payload, payload_len, cpath_layer); @@ -1585,6 +1595,16 @@ connection_edge_process_relay_cell(cell_t *cell, circuit_t *circ, connection_write_to_buf((char*)(cell->payload + RELAY_HEADER_SIZE), rh.length, TO_CONN(conn)); +#ifdef MEASUREMENTS_21206 + /* Count number of RELAY_DATA cells received on a linked directory + * connection. */ + connection_t *linked_conn = TO_CONN(conn)->linked_conn; + + if (linked_conn && linked_conn->type == CONN_TYPE_DIR) { + ++(TO_DIR_CONN(linked_conn)->data_cells_received); + } +#endif + if (!optimistic_data) { /* Only send a SENDME if we're not getting optimistic data; otherwise * a SENDME could arrive before the CONNECTED. -- cgit v1.2.3-54-g00ecf