Give better warnings if connection_close_unattached_ap gets called twice or called on a marked connection; rename it to connection_mark_unattached_ap.

svn:r3990

8 files changed, 52 insertions, 43 deletions

diff --git a/src/or/circuitbuild.c b/src/or/circuitbuild.c
index 9dced9354b..03c818ad66 100644
--- a/src/or/circuitbuild.c
+++ b/src/or/circuitbuild.c
@@ -723,7 +723,7 @@ int circuit_truncated(circuit_t *circ, crypt_path_t *layer) {
         /* no need to send 'end' relay cells,
          * because the other side's already dead
          */
-        connection_close_unattached_ap(stream, END_STREAM_REASON_DESTROY);
+        connection_mark_unattached_ap(stream, END_STREAM_REASON_DESTROY);
       }
     }
 
diff --git a/src/or/connection_edge.c b/src/or/connection_edge.c
index 23293819d3..b176dff971 100644
--- a/src/or/connection_edge.c
+++ b/src/or/connection_edge.c
@@ -25,21 +25,26 @@ static int address_is_in_virtual_range(const char *addr);
  * has_sent_end to 1, and mark the conn.
  */
 void
-connection_close_unattached_ap(connection_t *conn, int endreason) {
+_connection_mark_unattached_ap(connection_t *conn, int endreason,
+                               int line, const char *file) {
 
   tor_assert(conn->type == CONN_TYPE_AP);
   conn->has_sent_end = 1; /* no circ yet */
 
+  if (conn->marked_for_close) {
+      log(LOG_WARN,"Duplicate call to connection_mark_unattached_ap at %s:%d (first marked at %s:%d)",
+          file, line,
+          conn->marked_for_close_file,conn->marked_for_close);
+    return;
+  }
+
   if (!conn->socks_request->has_finished) {
     socks5_reply_status_t socksreason =
       connection_edge_end_reason_socks5_response(endreason);
 
-//XXX Bug: it's not marked for close yet, so the below things won't
-// be defined yet. -RD
     if (endreason == END_STREAM_REASON_ALREADY_SOCKS_REPLIED)
       log_fn(LOG_WARN,"Bug: stream (marked at %s:%d) sending two socks replies?",
-             conn->marked_for_close_file?conn->marked_for_close_file:"",
-             conn->marked_for_close);
+             file, line);
 
     if (conn->socks_request->command == SOCKS_COMMAND_CONNECT)
       connection_ap_handshake_socks_reply(conn, NULL, 0, socksreason);
@@ -47,10 +52,9 @@ connection_close_unattached_ap(connection_t *conn, int endreason) {
       connection_ap_handshake_socks_resolved(conn,RESOLVED_TYPE_ERROR,0,NULL);
   }
 
-//XXX Bug: this means that marked-for-close-file and marked-for-close
-// will all be defined as being inside this function. that's not what
-// we had in mind. -RD
-  connection_mark_for_close(conn);
+  _connection_mark_for_close(conn);
+  conn->marked_for_close_file = file;
+  conn->marked_for_close = line;
   conn->hold_open_until_flushed = 1;
 }
 
@@ -146,7 +150,7 @@ int connection_edge_destroy(uint16_t circ_id, connection_t *conn) {
   log_fn(LOG_INFO,"CircID %d: At an edge. Marking connection for close.",
          circ_id);
   if (conn->type == CONN_TYPE_AP) {
-    connection_close_unattached_ap(conn, END_STREAM_REASON_DESTROY);
+    connection_mark_unattached_ap(conn, END_STREAM_REASON_DESTROY);
   } else {
     conn->has_sent_end = 1; /* we're closing the circuit, nothing to send to */
     connection_mark_for_close(conn);
@@ -316,7 +320,7 @@ void connection_ap_expire_beginning(void) {
     if (conn->state == AP_CONN_STATE_CONTROLLER_WAIT) {
       if (now - conn->timestamp_lastread >= 120) {
         log_fn(LOG_NOTICE, "Closing unattached stream.");
-        connection_close_unattached_ap(conn, END_STREAM_REASON_TIMEOUT);
+        connection_mark_unattached_ap(conn, END_STREAM_REASON_TIMEOUT);
       }
       continue;
     }
@@ -330,7 +334,7 @@ void connection_ap_expire_beginning(void) {
     if (!circ) { /* it's vanished? */
       log_fn(LOG_INFO,"Conn is waiting (address %s), but lost its circ.",
              conn->socks_request->address);
-      connection_close_unattached_ap(conn, END_STREAM_REASON_TIMEOUT);
+      connection_mark_unattached_ap(conn, END_STREAM_REASON_TIMEOUT);
       continue;
     }
     if (circ->purpose == CIRCUIT_PURPOSE_C_REND_JOINED) {
@@ -338,7 +342,7 @@ void connection_ap_expire_beginning(void) {
         log_fn(LOG_NOTICE,"Rend stream is %d seconds late. Giving up on address '%s'.",
                (int)(now - conn->timestamp_lastread), conn->socks_request->address);
         connection_edge_end(conn, END_STREAM_REASON_TIMEOUT, conn->cpath_layer);
-        connection_close_unattached_ap(conn, END_STREAM_REASON_TIMEOUT);
+        connection_mark_unattached_ap(conn, END_STREAM_REASON_TIMEOUT);
       }
       continue;
     }
@@ -359,7 +363,7 @@ void connection_ap_expire_beginning(void) {
     conn->timestamp_lastread += 15;
     /* move it back into 'pending' state, and try to attach. */
     if (connection_ap_detach_retriable(conn, circ)<0) {
-      connection_close_unattached_ap(conn, END_STREAM_REASON_CANT_ATTACH);
+      connection_mark_unattached_ap(conn, END_STREAM_REASON_CANT_ATTACH);
     }
   } /* end for */
 }
@@ -382,7 +386,7 @@ void connection_ap_attach_pending(void)
         conn->state != AP_CONN_STATE_CIRCUIT_WAIT)
       continue;
     if (connection_ap_handshake_attach_circuit(conn) < 0) {
-      connection_close_unattached_ap(conn, END_STREAM_REASON_CANT_ATTACH);
+      connection_mark_unattached_ap(conn, END_STREAM_REASON_CANT_ATTACH);
     }
   }
 }
@@ -883,7 +887,7 @@ static int connection_ap_handshake_process_socks(connection_t *conn) {
       log_fn(LOG_WARN,"Fetching socks handshake failed. Closing.");
       connection_ap_handshake_socks_reply(conn, NULL, 0, SOCKS5_GENERAL_ERROR);
     }
-    connection_close_unattached_ap(conn, END_STREAM_REASON_ALREADY_SOCKS_REPLIED);
+    connection_mark_unattached_ap(conn, END_STREAM_REASON_ALREADY_SOCKS_REPLIED);
     return -1;
   } /* else socks handshake is done, continue processing */
 
@@ -900,7 +904,7 @@ static int connection_ap_handshake_process_socks(connection_t *conn) {
      */
     log_fn(LOG_WARN,"Missing mapping for virtual address '%s'. Refusing.",
            socks->address);
-    connection_close_unattached_ap(conn, END_STREAM_REASON_INTERNAL);
+    connection_mark_unattached_ap(conn, END_STREAM_REASON_INTERNAL);
     return -1;
   }
 
@@ -914,7 +918,7 @@ static int connection_ap_handshake_process_socks(connection_t *conn) {
     char *s = strrchr(socks->address,'.');
     if (!s || s[1] == '\0') {
       log_fn(LOG_WARN,"Malformed exit address '%s'. Refusing.", socks->address);
-      connection_close_unattached_ap(conn, END_STREAM_REASON_TORPROTOCOL);
+      connection_mark_unattached_ap(conn, END_STREAM_REASON_TORPROTOCOL);
       return -1;
     }
     conn->chosen_exit_name = tor_strdup(s+1);
@@ -926,7 +930,7 @@ static int connection_ap_handshake_process_socks(connection_t *conn) {
 
     if (address_is_invalid_destination(socks->address)) {
       log_fn(LOG_WARN,"Destination '%s' seems to be an invalid hostname. Failing.", socks->address);
-      connection_close_unattached_ap(conn, END_STREAM_REASON_TORPROTOCOL);
+      connection_mark_unattached_ap(conn, END_STREAM_REASON_TORPROTOCOL);
       return -1;
     }
 
@@ -937,14 +941,14 @@ static int connection_ap_handshake_process_socks(connection_t *conn) {
       if (strlen(socks->address) > RELAY_PAYLOAD_SIZE) {
         log_fn(LOG_WARN,"Address to be resolved is too large. Failing.");
         connection_ap_handshake_socks_resolved(conn,RESOLVED_TYPE_ERROR,0,NULL);
-        connection_close_unattached_ap(conn, END_STREAM_REASON_ALREADY_SOCKS_REPLIED);
+        connection_mark_unattached_ap(conn, END_STREAM_REASON_ALREADY_SOCKS_REPLIED);
         return -1;
       }
       if (tor_inet_aton(socks->address, &in)) { /* see if it's an IP already */
         answer = in.s_addr;
         connection_ap_handshake_socks_resolved(conn,RESOLVED_TYPE_IPV4,4,
                                                (char*)&answer);
-        connection_close_unattached_ap(conn, END_STREAM_REASON_ALREADY_SOCKS_REPLIED);
+        connection_mark_unattached_ap(conn, END_STREAM_REASON_ALREADY_SOCKS_REPLIED);
         return 0;
       }
       rep_hist_note_used_resolve(time(NULL)); /* help predict this next time */
@@ -952,7 +956,7 @@ static int connection_ap_handshake_process_socks(connection_t *conn) {
     } else { /* socks->command == SOCKS_COMMAND_CONNECT */
       if (socks->port == 0) {
         log_fn(LOG_NOTICE,"Application asked to connect to port 0. Refusing.");
-        connection_close_unattached_ap(conn, END_STREAM_REASON_TORPROTOCOL);
+        connection_mark_unattached_ap(conn, END_STREAM_REASON_TORPROTOCOL);
         return -1;
       }
       rep_hist_note_used_port(socks->port, time(NULL)); /* help predict this next time */
@@ -961,7 +965,7 @@ static int connection_ap_handshake_process_socks(connection_t *conn) {
     if (! get_options()->LeaveStreamsUnattached) {
       conn->state = AP_CONN_STATE_CIRCUIT_WAIT;
       if (connection_ap_handshake_attach_circuit(conn) < 0) {
-        connection_close_unattached_ap(conn, END_STREAM_REASON_CANT_ATTACH);
+        connection_mark_unattached_ap(conn, END_STREAM_REASON_CANT_ATTACH);
         return -1;
       }
       return 0;
@@ -979,7 +983,7 @@ static int connection_ap_handshake_process_socks(connection_t *conn) {
        * building all the circuits and then realizing it won't work. */
       log_fn(LOG_WARN,"Resolve requests to hidden services not allowed. Failing.");
       connection_ap_handshake_socks_resolved(conn,RESOLVED_TYPE_ERROR,0,NULL);
-      connection_close_unattached_ap(conn, END_STREAM_REASON_ALREADY_SOCKS_REPLIED);
+      connection_mark_unattached_ap(conn, END_STREAM_REASON_ALREADY_SOCKS_REPLIED);
       return -1;
     }
 
@@ -989,7 +993,7 @@ static int connection_ap_handshake_process_socks(connection_t *conn) {
     r = rend_cache_lookup_entry(conn->rend_query, &entry);
     if (r<0) {
       log_fn(LOG_WARN,"Invalid service descriptor %s", conn->rend_query);
-      connection_close_unattached_ap(conn, END_STREAM_REASON_TORPROTOCOL);
+      connection_mark_unattached_ap(conn, END_STREAM_REASON_TORPROTOCOL);
       return -1;
     }
     if (r==0) {
@@ -1004,7 +1008,7 @@ static int connection_ap_handshake_process_socks(connection_t *conn) {
         conn->state = AP_CONN_STATE_CIRCUIT_WAIT;
         log_fn(LOG_INFO, "Descriptor is here and fresh enough. Great.");
         if (connection_ap_handshake_attach_circuit(conn) < 0) {
-          connection_close_unattached_ap(conn, END_STREAM_REASON_CANT_ATTACH);
+          connection_mark_unattached_ap(conn, END_STREAM_REASON_CANT_ATTACH);
           return -1;
         }
         return 0;
@@ -1058,7 +1062,7 @@ int connection_ap_handshake_send_begin(connection_t *ap_conn, circuit_t *circ)
 
   ap_conn->stream_id = get_unique_stream_id_by_circ(circ);
   if (ap_conn->stream_id==0) {
-    connection_close_unattached_ap(ap_conn, END_STREAM_REASON_INTERNAL);
+    connection_mark_unattached_ap(ap_conn, END_STREAM_REASON_INTERNAL);
     circuit_mark_for_close(circ);
     return -1;
   }
@@ -1102,7 +1106,7 @@ int connection_ap_handshake_send_resolve(connection_t *ap_conn, circuit_t *circ)
 
   ap_conn->stream_id = get_unique_stream_id_by_circ(circ);
   if (ap_conn->stream_id==0) {
-    connection_close_unattached_ap(ap_conn, END_STREAM_REASON_INTERNAL);
+    connection_mark_unattached_ap(ap_conn, END_STREAM_REASON_INTERNAL);
     circuit_mark_for_close(circ);
     return -1;
   }
@@ -1173,7 +1177,7 @@ int connection_ap_make_bridge(char *address, uint16_t port) {
 
   /* attaching to a dirty circuit is fine */
   if (connection_ap_handshake_attach_circuit(conn) < 0) {
-    connection_close_unattached_ap(conn, END_STREAM_REASON_CANT_ATTACH);
+    connection_mark_unattached_ap(conn, END_STREAM_REASON_CANT_ATTACH);
     tor_close_socket(fd[1]);
     return -1;
   }
diff --git a/src/or/control.c b/src/or/control.c
index 1fc0f7017a..c494993932 100644
--- a/src/or/control.c
+++ b/src/or/control.c
@@ -738,7 +738,7 @@ static int handle_control_attachstream(connection_t *conn, uint32_t len,
   if (!circ_id) {
     ap_conn->state = AP_CONN_STATE_CIRCUIT_WAIT;
     if (connection_ap_handshake_attach_circuit(ap_conn)<0)
-      connection_close_unattached_ap(ap_conn, END_STREAM_REASON_CANT_ATTACH);
+      connection_mark_unattached_ap(ap_conn, END_STREAM_REASON_CANT_ATTACH);
     send_control_done(conn);
     return 0;
   }
@@ -826,7 +826,7 @@ handle_control_closestream(connection_t *conn, uint32_t len,
                        "No AP connection found with given ID");
     return 0;
   }
-  connection_close_unattached_ap(ap_conn, reason);
+  connection_mark_unattached_ap(ap_conn, reason);
   send_control_done(conn);
   return 0;
 }
diff --git a/src/or/hibernate.c b/src/or/hibernate.c
index df3e83bd51..1df81fdfd5 100644
--- a/src/or/hibernate.c
+++ b/src/or/hibernate.c
@@ -742,7 +742,7 @@ hibernate_go_dormant(time_t now) {
                           conn->cpath_layer);
     log_fn(LOG_INFO,"Closing conn type %d", conn->type);
     if (conn->type == CONN_TYPE_AP) /* send socks failure if needed */
-      connection_close_unattached_ap(conn, END_STREAM_REASON_HIBERNATING);
+      connection_mark_unattached_ap(conn, END_STREAM_REASON_HIBERNATING);
     else
       connection_mark_for_close(conn);
   }
diff --git a/src/or/main.c b/src/or/main.c
index 393e5a69e2..ec07e0fcce 100644
--- a/src/or/main.c
+++ b/src/or/main.c
@@ -478,7 +478,7 @@ void directory_all_unreachable(time_t now) {
                                               AP_CONN_STATE_CIRCUIT_WAIT))) {
     log_fn(LOG_NOTICE,"Network down? Failing connection to '%s:%d'.",
            conn->socks_request->address, conn->socks_request->port);
-    connection_close_unattached_ap(conn, END_STREAM_REASON_NET_UNREACHABLE);
+    connection_mark_unattached_ap(conn, END_STREAM_REASON_NET_UNREACHABLE);
   }
 }
 
diff --git a/src/or/or.h b/src/or/or.h
index 6984ddd72a..d61cde47f3 100644
--- a/src/or/or.h
+++ b/src/or/or.h
@@ -1324,7 +1324,12 @@ int connection_or_nonopen_was_started_here(connection_t *conn);
 
 /********************************* connection_edge.c ***************************/
 
-void connection_close_unattached_ap(connection_t *conn, int endreason);
+#define connection_mark_unattached_ap(conn, endreason) \
+  do { _connection_mark_unattached_ap(conn, endreason, __LINE__, _SHORT_FILE_);\
+  } while (0)
+
+void _connection_mark_unattached_ap(connection_t *conn, int endreason,
+                                    int line, const char *file);
 int connection_edge_reached_eof(connection_t *conn);
 int connection_edge_process_inbuf(connection_t *conn, int package_partial);
 int connection_edge_destroy(uint16_t circ_id, connection_t *conn);
diff --git a/src/or/relay.c b/src/or/relay.c
index f2523b5a25..39cab5311b 100644
--- a/src/or/relay.c
+++ b/src/or/relay.c
@@ -417,7 +417,7 @@ int connection_edge_send_command(connection_t *fromconn, circuit_t *circ,
     log_fn(LOG_WARN,"no circ. Closing conn.");
     tor_assert(fromconn);
     if (fromconn->type == CONN_TYPE_AP) {
-      connection_close_unattached_ap(fromconn, END_STREAM_REASON_INTERNAL);
+      connection_mark_unattached_ap(fromconn, END_STREAM_REASON_INTERNAL);
     } else {
       fromconn->has_sent_end = 1; /* no circ to send to */
       connection_mark_for_close(fromconn);
@@ -614,7 +614,7 @@ connection_edge_process_relay_cell_not_open(
       } else {
         log_fn(LOG_INFO,"Address '%s' resolved to 0.0.0.0. Closing,",
                conn->socks_request->address);
-        connection_close_unattached_ap(conn, END_STREAM_REASON_TORPROTOCOL);
+        connection_mark_unattached_ap(conn, END_STREAM_REASON_TORPROTOCOL);
         return 0;
       }
       client_dns_set_addressmap(conn->socks_request->address, addr,
@@ -669,7 +669,7 @@ connection_edge_process_relay_cell_not_open(
     if (CIRCUIT_IS_ORIGIN(circ))
       circuit_log_path(LOG_INFO,circ);
     if (conn->type == CONN_TYPE_AP) {
-      connection_close_unattached_ap(conn,
+      connection_mark_unattached_ap(conn,
         *(char *)(cell->payload+RELAY_HEADER_SIZE));
     } else {
       conn->has_sent_end = 1; /* we just got an 'end', don't need to send one */
@@ -692,7 +692,7 @@ connection_edge_process_relay_cell_not_open(
       if (!addr) {
         log_fn(LOG_INFO,"...but it claims the IP address was 0.0.0.0. Closing.");
         connection_edge_end(conn, END_STREAM_REASON_TORPROTOCOL, conn->cpath_layer);
-        connection_close_unattached_ap(conn, END_STREAM_REASON_TORPROTOCOL);
+        connection_mark_unattached_ap(conn, END_STREAM_REASON_TORPROTOCOL);
         return 0;
       }
       client_dns_set_addressmap(conn->socks_request->address, addr,
@@ -716,14 +716,14 @@ connection_edge_process_relay_cell_not_open(
     tor_assert(conn->socks_request->command == SOCKS_COMMAND_RESOLVE);
     if (rh->length < 2 || cell->payload[RELAY_HEADER_SIZE+1]+2>rh->length) {
       log_fn(LOG_WARN, "Dropping malformed 'resolved' cell");
-      connection_close_unattached_ap(conn, END_STREAM_REASON_TORPROTOCOL);
+      connection_mark_unattached_ap(conn, END_STREAM_REASON_TORPROTOCOL);
       return 0;
     }
     connection_ap_handshake_socks_resolved(conn,
                    cell->payload[RELAY_HEADER_SIZE], /*answer_type*/
                    cell->payload[RELAY_HEADER_SIZE+1], /*answer_len*/
                    cell->payload+RELAY_HEADER_SIZE+2); /* answer */
-    connection_close_unattached_ap(conn, END_STREAM_REASON_ALREADY_SOCKS_REPLIED);
+    connection_mark_unattached_ap(conn, END_STREAM_REASON_ALREADY_SOCKS_REPLIED);
     return 0;
   }
 
diff --git a/src/or/rendclient.c b/src/or/rendclient.c
index 6791bbd3e4..c63a4d9cb8 100644
--- a/src/or/rendclient.c
+++ b/src/or/rendclient.c
@@ -394,12 +394,12 @@ void rend_client_desc_here(char *query) {
       if (connection_ap_handshake_attach_circuit(conn) < 0) {
         /* it will never work */
         log_fn(LOG_WARN,"attaching to a rend circ failed. Closing conn.");
-        connection_close_unattached_ap(conn, END_STREAM_REASON_CANT_ATTACH);
+        connection_mark_unattached_ap(conn, END_STREAM_REASON_CANT_ATTACH);
       }
       tor_assert(conn->state != AP_CONN_STATE_RENDDESC_WAIT); /* avoid loop */
     } else { /* 404, or fetch didn't get that far */
       log_fn(LOG_NOTICE,"Closing stream for '%s.onion': hidden service is unavailable (try again later).", query);
-      connection_close_unattached_ap(conn, END_STREAM_REASON_TIMEOUT);
+      connection_mark_unattached_ap(conn, END_STREAM_REASON_TIMEOUT);
     }
   }
 }