commit 4190f602bd9edcd0f9f29458dda59e4d664a8b62 Author: David Goulet dgoulet@torproject.org Date: Mon Sep 25 16:20:15 2017 -0400

circuit: Log n_circ_id and global identifier of HS circuits

So we can track them more easily in the logs and match any open/close/free with those identifiers.

Part of #23645

Signed-off-by: David Goulet dgoulet@torproject.org --- src/or/circuituse.c | 59 ++++++++++++++++++++++++++++++++--------------------- 1 file changed, 36 insertions(+), 23 deletions(-)

diff --git a/src/or/circuituse.c b/src/or/circuituse.c index e2b21df01..62cc865f4 100644 --- a/src/or/circuituse.c +++ b/src/or/circuituse.c @@ -2695,9 +2695,10 @@ connection_ap_handshake_attach_circuit(entry_connection_t *conn) tor_assert(rendcirc); /* one is already established, attach */ log_info(LD_REND, - "rend joined circ %u already here. attaching. " - "(stream %d sec old)", - (unsigned)rendcirc->base_.n_circ_id, conn_age); + "rend joined circ %u (id: %" PRIu32 ") already here. " + "Attaching. (stream %d sec old)", + (unsigned) TO_CIRCUIT(rendcirc)->n_circ_id, + rendcirc->global_identifier, conn_age); /* Mark rendezvous circuits as 'newly dirty' every time you use * them, since the process of rebuilding a rendezvous circ is so * expensive. There is a tradeoff between linkability and @@ -2730,9 +2731,10 @@ connection_ap_handshake_attach_circuit(entry_connection_t *conn) if (rendcirc && (rendcirc->base_.purpose == CIRCUIT_PURPOSE_C_REND_READY_INTRO_ACKED)) { log_info(LD_REND, - "pending-join circ %u already here, with intro ack. " - "Stalling. (stream %d sec old)", - (unsigned)rendcirc->base_.n_circ_id, conn_age); + "pending-join circ %u (id: %" PRIu32 ") already here, with " + "intro ack. Stalling. (stream %d sec old)", + (unsigned) TO_CIRCUIT(rendcirc)->n_circ_id, + rendcirc->global_identifier, conn_age); return 0; }

@@ -2744,10 +2746,13 @@ connection_ap_handshake_attach_circuit(entry_connection_t *conn) if (retval > 0) { /* one has already sent the intro. keep waiting. */ tor_assert(introcirc); - log_info(LD_REND, "Intro circ %u present and awaiting ack (rend %u). " - "Stalling. (stream %d sec old)", - (unsigned)introcirc->base_.n_circ_id, - rendcirc ? (unsigned)rendcirc->base_.n_circ_id : 0, + log_info(LD_REND, "Intro circ %u (id: %" PRIu32 ") present and " + "awaiting ACK. Rend circuit %u (id: %" PRIu32 "). " + "Stalling. (stream %d sec old)", + (unsigned) TO_CIRCUIT(introcirc)->n_circ_id, + introcirc->global_identifier, + rendcirc ? (unsigned) TO_CIRCUIT(rendcirc)->n_circ_id : 0, + rendcirc ? rendcirc->global_identifier : 0, conn_age); return 0; } @@ -2757,19 +2762,24 @@ connection_ap_handshake_attach_circuit(entry_connection_t *conn) if (rendcirc && introcirc && rendcirc->base_.purpose == CIRCUIT_PURPOSE_C_REND_READY) { log_info(LD_REND, - "ready rend circ %u already here (no intro-ack yet on " - "intro %u). (stream %d sec old)", - (unsigned)rendcirc->base_.n_circ_id, - (unsigned)introcirc->base_.n_circ_id, conn_age); + "ready rend circ %u (id: %" PRIu32 ") already here. No" + "intro-ack yet on intro %u (id: %" PRIu32 "). " + "(stream %d sec old)", + (unsigned) TO_CIRCUIT(rendcirc)->n_circ_id, + rendcirc->global_identifier, + (unsigned) TO_CIRCUIT(introcirc)->n_circ_id, + introcirc->global_identifier, conn_age);

tor_assert(introcirc->base_.purpose == CIRCUIT_PURPOSE_C_INTRODUCING); if (introcirc->base_.state == CIRCUIT_STATE_OPEN) { int ret; - log_info(LD_REND,"found open intro circ %u (rend %u); sending " - "introduction. (stream %d sec old)", - (unsigned)introcirc->base_.n_circ_id, - (unsigned)rendcirc->base_.n_circ_id, - conn_age); + log_info(LD_REND, "Found open intro circ %u (id: %" PRIu32 "). " + "Rend circuit %u (id: %" PRIu32 "); Sending " + "introduction. (stream %d sec old)", + (unsigned) TO_CIRCUIT(introcirc)->n_circ_id, + introcirc->global_identifier, + (unsigned) TO_CIRCUIT(rendcirc)->n_circ_id, + rendcirc->global_identifier, conn_age); ret = hs_client_send_introduce1(introcirc, rendcirc); switch (ret) { case 0: /* success */ @@ -2793,10 +2803,13 @@ connection_ap_handshake_attach_circuit(entry_connection_t *conn) } }

- log_info(LD_REND, "Intro (%u) and rend (%u) circs are not both ready. " - "Stalling conn. (%d sec old)", - introcirc ? (unsigned)introcirc->base_.n_circ_id : 0, - rendcirc ? (unsigned)rendcirc->base_.n_circ_id : 0, conn_age); + log_info(LD_REND, "Intro %u (id: %" PRIu32 ") and rend circuit %u " + "(id: %" PRIu32 ") circuits are not both ready. " + "Stalling conn. (%d sec old)", + introcirc ? (unsigned) TO_CIRCUIT(introcirc)->n_circ_id : 0, + introcirc ? introcirc->global_identifier : 0, + rendcirc ? (unsigned) TO_CIRCUIT(rendcirc)->n_circ_id : 0, + rendcirc ? rendcirc->global_identifier : 0, conn_age); return 0; } }