cleanups, bugfixes, more verbose logs

Fixed up the assert_*_ok funcs some (more work remains)

Changed config so it reads either /etc/torrc or the -f arg, never both

Finally tracked down a nasty bug with our use of tls:
  It turns out that if you ask SSL_read() for no more than n bytes, it
  will read the entire record from the network (and maybe part of the next
  record, I'm not sure), give you n bytes of it, and keep the remaining
  bytes internally. This is fine, except our poll-for-read looks at the
  network, and there are no bytes pending on the network, so we never know
  to ask SSL_read() for more bytes. Currently I've hacked it so if we ask
  for n bytes and it returns n bytes, then it reads again right then. This
  will interact poorly with our rate limiting; we need a cleaner solution.


svn:r481

src/or/buffers.c

@@ -69,7 +69,7 @@ int read_to_buf(int s, int at_most, char **buf, int *buflen, int *buf_datalen, i
     return 0;
   } else { /* we read some bytes */
     *buf_datalen += read_result;
-//    log_fn(LOG_DEBUG,"Read %d bytes. %d on inbuf.",read_result, *buf_datalen);
+    log_fn(LOG_DEBUG,"Read %d bytes. %d on inbuf.",read_result, *buf_datalen);
     return read_result;
   }
 }
@@ -88,6 +88,7 @@ int read_to_buf_tls(tor_tls *tls, int at_most, char **buf, int *buflen, int *buf
   if (r<0) 
     return r;
   *buf_datalen += r;
+  log_fn(LOG_DEBUG,"Read %d bytes. %d on inbuf.",r, *buf_datalen);
   return r;
 } 
 
@@ -147,6 +148,8 @@ int flush_buf_tls(tor_tls *tls, char **buf, int *buflen, int *buf_flushlen, int
   *buf_datalen -= r;
   *buf_flushlen -= r;
   memmove(*buf, *buf+r, *buf_datalen);
+  log_fn(LOG_DEBUG,"flushed %d bytes, %d ready to flush, %d remain.",
+    r,*buf_flushlen,*buf_datalen);
   return r;
 }
 
@@ -168,7 +171,7 @@ int write_to_buf(char *string, int string_len,
 
   memcpy(*buf+*buf_datalen, string, string_len);
   *buf_datalen += string_len;
-//  log_fn(LOG_DEBUG,"added %d bytes to buf (now %d total).",string_len, *buf_datalen);
+  log_fn(LOG_DEBUG,"added %d bytes to buf (now %d total).",string_len, *buf_datalen);
   return *buf_datalen;
 }
 

src/or/circuit.c

@@ -949,7 +949,7 @@ int circuit_truncated(circuit_t *circ, crypt_path_t *layer) {
 }
 
 
-void assert_cpath_layer_ok(crypt_path_t *cp)
+void assert_cpath_layer_ok(const crypt_path_t *cp)
 {
   assert(cp->f_crypto);
   assert(cp->b_crypto);
@@ -960,8 +960,10 @@ void assert_cpath_layer_ok(crypt_path_t *cp)
     case CPATH_STATE_CLOSED:
     case CPATH_STATE_OPEN:
       assert(!cp->handshake_state);
+      break;
     case CPATH_STATE_AWAITING_KEYS:
       assert(cp->handshake_state);
+      break;
     default:
       assert(0);
     }
@@ -969,7 +971,7 @@ void assert_cpath_layer_ok(crypt_path_t *cp)
   assert(cp->deliver_window >= 0);
 }
 
-void assert_cpath_ok(crypt_path_t *cp)
+void assert_cpath_ok(const crypt_path_t *cp)
 {
   while(cp->prev)
     cp = cp->prev;
@@ -989,7 +991,7 @@ void assert_cpath_ok(crypt_path_t *cp)
   }
 }
 
-void assert_circuit_ok(circuit_t *c) 
+void assert_circuit_ok(const circuit_t *c) 
 {
   connection_t *conn;
 

src/or/config.c

@@ -230,7 +230,7 @@ static void config_assign(or_options_t *options, struct config_line *list) {
 int getconfig(int argc, char **argv, or_options_t *options) {
   struct config_line *cl;
   FILE *cf;
-  char fname[256];
+  char *fname;
   int i;
   int result = 0;
 
@@ -247,40 +247,29 @@ int getconfig(int argc, char **argv, or_options_t *options) {
   options->TotalBandwidth = 800000; /* at most 800kB/s total sustained incoming */
   options->NumCpus = 1;
   options->CertFile = "default.cert";
-//  options->ReconnectPeriod = 6001;
-
-/* get config lines from /etc/torrc and assign them */
-#define rcfile "torrc"
-  snprintf(fname,256,"/etc/%s",rcfile);
-
-  cf = config_open(fname);
-  if(cf) {
-    /* we got it open. pull out the config lines. */
-    cl = config_get_lines(cf);
-    config_assign(options,cl);
-    config_free_lines(cl);
-    config_close(cf);
-  }
-  /* if we failed to open it, ignore */
 
 /* learn config file name, get config lines, assign them */
   i = 1;
   while(i < argc-1 && strcmp(argv[i],"-f")) {
-//    log(LOG_DEBUG,"examining arg %d (%s), it's not -f.",i,argv[i]);
     i++;
   }
   if(i < argc-1) { /* we found one */
-    log(LOG_DEBUG,"Opening specified config file '%s'",argv[i+1]);
-    cf = config_open(argv[i+1]);
-    if(!cf) { /* it's defined but not there. that's no good. */
-      log(LOG_ERR, "Unable to open configuration file '%s'.",argv[i+1]);
-      return -1;
-    }
-    cl = config_get_lines(cf);
-    config_assign(options,cl);
-    config_free_lines(cl);
-    config_close(cf);
+    fname = argv[i+1];
+  } else { /* didn't find one, try /etc/torrc */
+    fname = "/etc/torrc";
   }
+  log(LOG_DEBUG,"Opening config file '%s'",fname);
+
+  cf = config_open(fname);
+  if(!cf) { /* it's defined but not there. that's no good. */
+    log(LOG_ERR, "Unable to open configuration file '%s'.",fname);
+    return -1;
+  }
+
+  cl = config_get_lines(cf);
+  config_assign(options,cl);
+  config_free_lines(cl);
+  config_close(cf);
  
 /* go through command-line variables too */
   cl = config_get_commandlines(argc,argv);
@@ -334,7 +323,7 @@ int getconfig(int argc, char **argv, or_options_t *options) {
 
   if(options->OnionRouter && options->Nickname == NULL) {
     log_fn(LOG_ERR,"Nickname required for OnionRouter, but not found.");
-    return -1;
+    result = -1;
   }
 
   if(options->DirPort > 0 && options->SigningPrivateKeyFile == NULL) {

src/or/connection.c

@@ -150,6 +150,8 @@ int connection_create_listener(struct sockaddr_in *bindaddr, int type) {
     return -1;
   }
   conn->s = s;
+  conn->receiver_bucket = -1; /* non-cell connections don't do receiver buckets */
+  conn->bandwidth = -1;
 
   if(connection_add(conn) < 0) { /* no space, forget it */
     log_fn(LOG_DEBUG,"connection_add failed. Giving up.");
@@ -478,6 +480,8 @@ int connection_read_to_buf(connection_t *conn) {
       at_most = 10*(CELL_PAYLOAD_SIZE - RELAY_HEADER_SIZE);
     }
 
+    at_most = 103; /* an unusual number, to force bugs into the open */
+
     if(at_most > global_read_bucket)
       at_most = global_read_bucket;
   }
@@ -521,7 +525,11 @@ int connection_read_to_buf(connection_t *conn) {
     log_fn(LOG_DEBUG,"buckets (%d, %d) exhausted. Pausing.", global_read_bucket, conn->receiver_bucket);
     conn->wants_to_read = 1;
     connection_stop_reading(conn);
+    return 0;
   }
+  if(connection_speaks_cells(conn) && conn->state != OR_CONN_STATE_CONNECTING)
+    if(result == at_most)
+      return connection_read_to_buf(conn);
   return 0;
 }
 
@@ -572,10 +580,12 @@ int connection_handle_write(connection_t *conn) {
         log_fn(LOG_DEBUG,"tls error. breaking.");
         return -1; /* XXX deal with close better */
       case TOR_TLS_WANTWRITE:
+        log_fn(LOG_DEBUG,"wanted write.");
         /* we're already writing */
         return 0;
       case TOR_TLS_WANTREAD:
         /* Make sure to avoid a loop if the receive buckets are empty. */
+        log_fn(LOG_DEBUG,"wanted read.");
         if(!connection_is_reading(conn)) {
           connection_stop_writing(conn);
           conn->wants_to_write = 1;
@@ -721,6 +731,7 @@ int connection_finished_flushing(connection_t *conn) {
 
 void assert_connection_ok(connection_t *conn, time_t now)
 {
+  return;
   assert(conn);
   assert(conn->type >= _CONN_TYPE_MIN);
   assert(conn->type <= _CONN_TYPE_MAX);
@@ -730,24 +741,29 @@ void assert_connection_ok(connection_t *conn, time_t now)
   
   /* buffers */
   assert(conn->inbuf);
-  assert(conn->inbuflen <= conn->inbuf_datalen);
+  assert(conn->inbuflen >= conn->inbuf_datalen);
   assert(conn->inbuflen >= 0);
-  assert(conn->inbuf_datalen > 0);
+  assert(conn->inbuf_datalen >= 0);
   assert(conn->outbuf);
-  assert(conn->outbuflen <= conn->outbuf_datalen);
+  assert(conn->outbuflen >= conn->outbuf_datalen);
   assert(conn->outbuflen >= 0);
-  assert(conn->outbuf_datalen > 0);
+  assert(conn->outbuf_datalen >= 0);
 
   assert(!now || conn->timestamp_lastread <= now);
   assert(!now || conn->timestamp_lastwritten <= now);
   assert(conn->timestamp_created <= conn->timestamp_lastread);
   assert(conn->timestamp_created <= conn->timestamp_lastwritten);
   
+  if(conn->type != CONN_TYPE_OR && conn->type != CONN_TYPE_DIR)
+    assert(!conn->pkey);
+  /* pkey is set if we're a dir client, or if we're an OR in state OPEN
+   * connected to another OR.
+   */
+
   if (conn->type != CONN_TYPE_OR) {
     assert(conn->bandwidth == -1);
     assert(conn->receiver_bucket == -1);
     /* Addr, port, address XXX */
-    assert(!conn->pkey);
     assert(!conn->tls);
   } else {
     assert(conn->bandwidth);
@@ -755,7 +771,6 @@ void assert_connection_ok(connection_t *conn, time_t now)
     assert(conn->receiver_bucket <= 10*conn->bandwidth);
     assert(conn->addr && conn->port);
     assert(conn->address);
-    assert(conn->pkey);
     if (conn->state != OR_CONN_STATE_CONNECTING)
       assert(conn->tls);
   }
@@ -772,8 +787,10 @@ void assert_connection_ok(connection_t *conn, time_t now)
     assert(!conn->next_stream || 
            conn->next_stream->type == CONN_TYPE_EXIT ||
            conn->next_stream->type == CONN_TYPE_AP);
-    assert(conn->cpath_layer);
-    assert_cpath_layer_ok(conn->cpath_layer);
+    if(conn->type == CONN_TYPE_AP && conn->state == AP_CONN_STATE_OPEN)
+      assert(conn->cpath_layer);
+    if(conn->cpath_layer)
+      assert_cpath_layer_ok(conn->cpath_layer);
     /* XXX unchecked, package window, deliver window. */
   }
 

src/or/connection_or.c

@@ -144,13 +144,12 @@ int connection_write_cell_to_buf(const cell_t *cellp, connection_t *conn) {
   return connection_write_to_buf(n, CELL_NETWORK_SIZE, conn);
 }
 
+/* if there's a whole cell there, pull it off and process it. */
 int connection_process_cell_from_inbuf(connection_t *conn) {
-  /* check if there's a whole cell there.
-   *    * if yes, pull it off, decrypt it if we're not doing TLS, and process it.
-   *       */
   char buf[CELL_NETWORK_SIZE];
   cell_t cell;
  
+  log_fn(LOG_DEBUG,"%d: starting, inbuf_datalen %d.",conn->s,conn->inbuf_datalen);
   if(conn->inbuf_datalen < CELL_NETWORK_SIZE) /* entire response available? */
     return 0; /* not yet */
  
@@ -159,7 +158,6 @@ int connection_process_cell_from_inbuf(connection_t *conn) {
   /* retrieve cell info from buf (create the host-order struct from the network-order string) */
   cell_unpack(&cell, buf);
  
-//  log_fn(LOG_DEBUG,"Decrypted cell is of type %u (ACI %u).",cellp->command,cellp->aci);
   command_process_cell(&cell, conn);
  
   return connection_process_inbuf(conn); /* process the remainder of the buffer */

src/or/main.c

@@ -256,7 +256,7 @@ static void conn_read(int i) {
      * discussion of POLLIN vs POLLHUP */
 
   conn = connection_array[i];
-  //log_fn(LOG_DEBUG,"socket %d wants to read.",conn->s);
+  log_fn(LOG_DEBUG,"socket %d wants to read.",conn->s);
  
   assert_connection_ok(conn, time(NULL));
 
@@ -284,7 +284,7 @@ static void conn_write(int i) {
     return; /* this conn doesn't want to write */
 
   conn = connection_array[i];
-  //log_fn(LOG_DEBUG,"socket %d wants to write.",conn->s);
+  log_fn(LOG_DEBUG,"socket %d wants to write.",conn->s);
 
   assert_connection_ok(conn, time(NULL));
 
@@ -307,7 +307,12 @@ static void check_conn_marked(int i) {
     log_fn(LOG_DEBUG,"Cleaning up connection.");
     if(conn->s >= 0) { /* might be an incomplete edge connection */
       /* FIXME there's got to be a better way to check for this -- and make other checks? */
-      connection_handle_write(conn); /* flush it first */
+      if(connection_speaks_cells(conn) && conn->state != OR_CONN_STATE_CONNECTING)
+        flush_buf_tls(conn->tls, &conn->outbuf, &conn->outbuflen,
+                      &conn->outbuf_flushlen, &conn->outbuf_datalen);
+      else
+        flush_buf(conn->s, &conn->outbuf, &conn->outbuflen,
+                  &conn->outbuf_flushlen, &conn->outbuf_datalen);
       if(connection_wants_to_flush(conn)) /* not done flushing */
         log_fn(LOG_WARNING,"Conn (socket %d) still wants to flush. Losing %d bytes!",conn->s, conn->inbuf_datalen);
     }

src/or/or.h

@@ -118,7 +118,7 @@
 #define CONN_TYPE_DIR 9
 #define CONN_TYPE_DNSWORKER 10
 #define CONN_TYPE_CPUWORKER 11
-#define _CONN_TYPE_MAX 3
+#define _CONN_TYPE_MAX 11
 
 #define LISTENER_STATE_READY 0
 
@@ -490,9 +490,9 @@ int circuit_extend(cell_t *cell, circuit_t *circ);
 int circuit_finish_handshake(circuit_t *circ, char *reply);
 int circuit_truncated(circuit_t *circ, crypt_path_t *layer);
 
-void assert_cpath_ok(crypt_path_t *c);
-void assert_cpath_layer_ok(crypt_path_t *c);
-void assert_circuit_ok(circuit_t *c);
+void assert_cpath_ok(const crypt_path_t *c);
+void assert_cpath_layer_ok(const crypt_path_t *c);
+void assert_circuit_ok(const circuit_t *c);
 
 /********************************* command.c ***************************/