first pass: obey log convention

ERR is if something fatal just happened

WARNING is something bad happened, but we're still running. The bad thing
is either a bug in the code, an attack or buggy protocol/implementation
of the remote peer, etc. The operator should examine the bad thing and
try to correct it.
(No error or warning messages should be expected. I expect most people
to run on -l warning eventually.)

NOTICE is never ever used.

INFO means something happened (maybe bad, maybe ok), but there's nothing
you need to (or can) do about it.

DEBUG is for everything louder than INFO.


svn:r486

src/or/buffers.c

@@ -221,7 +221,7 @@ int write_to_buf(const char *string, int string_len, buf_t *buf) {
   /* this is the point where you would grow the buffer, if you want to */
 
   if (string_len + buf->datalen > buf->len) { /* we're out of luck */
-    log_fn(LOG_DEBUG, "buflen too small. Time to implement growing dynamic bufs.");
+    log_fn(LOG_WARNING, "buflen too small. Time to implement growing dynamic bufs.");
     return -1;
   }
 
@@ -280,11 +280,11 @@ int fetch_from_buf_http(buf_t *buf,
   log_fn(LOG_DEBUG,"headerlen %d, bodylen %d.",headerlen,bodylen);
 
   if(headers_out && max_headerlen <= headerlen) {
-    log_fn(LOG_DEBUG,"headerlen %d larger than %d. Failing.", headerlen, max_headerlen-1);
+    log_fn(LOG_WARNING,"headerlen %d larger than %d. Failing.", headerlen, max_headerlen-1);
     return -1;
   }
   if(body_out && max_bodylen <= bodylen) {
-    log_fn(LOG_DEBUG,"bodylen %d larger than %d. Failing.", bodylen, max_bodylen-1);
+    log_fn(LOG_WARNING,"bodylen %d larger than %d. Failing.", bodylen, max_bodylen-1);
     return -1;
   }
 
@@ -346,33 +346,33 @@ int fetch_from_buf_socks(buf_t *buf,
   socks4_info.destip = ntohl(*(uint32_t*)(buf->buf+4));
 
   if(socks4_info.version != 4) {
-    log_fn(LOG_NOTICE,"Unrecognized version %d.",socks4_info.version);
+    log_fn(LOG_WARNING,"Unrecognized version %d.",socks4_info.version);
     return -1;
   }
 
   if(socks4_info.command != 1) { /* not a connect? we don't support it. */
-    log_fn(LOG_NOTICE,"command %d not '1'.",socks4_info.command);
+    log_fn(LOG_WARNING,"command %d not '1'.",socks4_info.command);
     return -1;
   }
 
   port = socks4_info.destport;
   if(!port) {
-    log_fn(LOG_NOTICE,"Port is zero.");
+    log_fn(LOG_WARNING,"Port is zero.");
     return -1;
   }
 
   if(!socks4_info.destip) {
-    log_fn(LOG_NOTICE,"DestIP is zero.");
+    log_fn(LOG_WARNING,"DestIP is zero.");
     return -1;
   }
 
   if(socks4_info.destip >> 8) {
     struct in_addr in;
-    log_fn(LOG_NOTICE,"destip not in form 0.0.0.x.");
+    log_fn(LOG_DEBUG,"destip not in form 0.0.0.x.");
     in.s_addr = htonl(socks4_info.destip);
     tmpbuf = inet_ntoa(in);
     if(max_addrlen <= strlen(tmpbuf)) {
-      log_fn(LOG_DEBUG,"socks4 addr too long.");
+      log_fn(LOG_WARNING,"socks4 addr too long.");
       return -1;
     }
     log_fn(LOG_DEBUG,"Successfully read destip (%s)", tmpbuf);
@@ -393,7 +393,7 @@ int fetch_from_buf_socks(buf_t *buf,
       return 0;
     }
     if(max_addrlen <= next-startaddr) {
-      log_fn(LOG_DEBUG,"Destaddr not here yet.");
+      log_fn(LOG_WARNING,"Destaddr too long.");
       return -1;
     }
   }

src/or/circuit.c

@@ -121,9 +121,8 @@ static void circuit_free_cpath_node(crypt_path_t *victim) {
 static aci_t get_unique_aci_by_addr_port(uint32_t addr, uint16_t port, int aci_type) {
   aci_t test_aci;
   connection_t *conn;
-
-#ifdef SEQUENTIAL_ACI
   uint16_t high_bit;
+
   high_bit = (aci_type == ACI_TYPE_HIGHER) ? 1<<15 : 0;
   conn = connection_exact_get_by_addr_port(addr,port);
   if (!conn)
@@ -141,31 +140,6 @@ static aci_t get_unique_aci_by_addr_port(uint32_t addr, uint16_t port, int aci_t
     }
     test_aci |= high_bit;
   } while(circuit_get_by_aci_conn(test_aci, conn));
-  return test_aci;
-#else
-try_again:
-  log_fn(LOG_DEBUG,"trying to get a unique aci");
-
-  if (CRYPTO_PSEUDO_RAND_INT(test_aci))
-    return -1;
-
-  if(aci_type == ACI_TYPE_LOWER && test_aci >= (1<<15))
-    test_aci -= (1<<15);
-  if(aci_type == ACI_TYPE_HIGHER && test_aci < (1<<15))
-    test_aci += (1<<15);
-  /* if aci_type == ACI_BOTH, don't filter any of it */
-
-  if(test_aci == 0)
-    goto try_again;
-
-  conn = connection_exact_get_by_addr_port(addr,port);
-  if(!conn) /* there can't be a conflict -- no connection of that sort yet */
-    return test_aci;
-
-  if(circuit_get_by_aci_conn(test_aci, conn))
-    goto try_again;
-#endif
-
   return test_aci;
 }
 
@@ -256,7 +230,7 @@ int circuit_deliver_relay_cell(cell_t *cell, circuit_t *circ,
   log_fn(LOG_DEBUG,"direction %d, streamid %d before crypt.", cell_direction, *(int*)(cell->payload+1));
 
   if(relay_crypt(circ, buf, 1+CELL_PAYLOAD_SIZE, cell_direction, &layer_hint, &recognized, &conn) < 0) {
-    log_fn(LOG_DEBUG,"relay crypt failed. Dropping connection.");
+    log_fn(LOG_WARNING,"relay crypt failed. Dropping connection.");
     return -1;
   }
 
@@ -302,7 +276,7 @@ int relay_crypt(circuit_t *circ, char *in, int inlen, char cell_direction,
     if(circ->cpath) { /* we're at the beginning of the circuit. We'll want to do layered crypts. */
       thishop = circ->cpath;
       if(thishop->state != CPATH_STATE_OPEN) {
-        log_fn(LOG_INFO,"Relay cell before first created cell?");
+        log_fn(LOG_WARNING,"Relay cell before first created cell?");
         return -1;
       }
       do { /* Remember: cpath is in forward order, that is, first hop first. */
@@ -311,7 +285,7 @@ int relay_crypt(circuit_t *circ, char *in, int inlen, char cell_direction,
         log_fn(LOG_DEBUG,"before decrypt: %d",*(int*)(in+2));
         /* decrypt */
         if(crypto_cipher_decrypt(thishop->b_crypto, in, inlen, out)) {
-          log_fn(LOG_ERR,"Error performing decryption:%s",crypto_perror());
+          log_fn(LOG_WARNING,"Error performing onion decryption: %s", crypto_perror());
           return -1;
         }
         memcpy(in,out,inlen);
@@ -330,7 +304,7 @@ int relay_crypt(circuit_t *circ, char *in, int inlen, char cell_direction,
 
       log_fn(LOG_DEBUG,"before encrypt: %d",*(int*)(in+2));
       if(crypto_cipher_encrypt(circ->p_crypto, in, inlen, out)) {
-        log_fn(LOG_ERR,"Encryption failed for ACI : %u (%s).",
+        log_fn(LOG_WARNING,"Onion encryption failed for ACI %u: %s",
             circ->p_aci, crypto_perror());
         return -1;
       }
@@ -351,7 +325,7 @@ int relay_crypt(circuit_t *circ, char *in, int inlen, char cell_direction,
 
         log_fn(LOG_DEBUG,"before encrypt: %d",*(int*)(in+2));
         if(crypto_cipher_encrypt(thishop->f_crypto, in, inlen, out)) {
-          log_fn(LOG_ERR,"Error performing encryption:%s",crypto_perror());
+          log_fn(LOG_WARNING,"Error performing encryption: %s", crypto_perror());
           return -1;
         }
         memcpy(in,out,inlen);
@@ -362,7 +336,7 @@ int relay_crypt(circuit_t *circ, char *in, int inlen, char cell_direction,
     } else { /* we're in the middle. Just one crypt. */
 
       if(crypto_cipher_decrypt(circ->n_crypto,in, inlen, out)) {
-        log_fn(LOG_ERR,"Decryption failed for ACI : %u (%s).",
+        log_fn(LOG_WARNING,"Decryption failed for ACI %u: %s",
                circ->n_aci, crypto_perror());
         return -1;
       }
@@ -645,7 +619,7 @@ void circuit_launch_new(int failure_status) {
 retry_circuit:
 
   if(failures > 5) {
-    log_fn(LOG_INFO,"Giving up, %d failures.", failures);
+    log_fn(LOG_INFO,"Giving up for now, %d failures.", failures);
     return;
   }
 
@@ -667,7 +641,7 @@ int circuit_establish_circuit(void) {
   circ->state = CIRCUIT_STATE_OR_WAIT;
   circ->cpath = onion_generate_cpath(&firsthop);
   if(!circ->cpath) {
-    log_fn(LOG_DEBUG,"Generating cpath failed.");
+    log_fn(LOG_INFO,"Generating cpath failed.");
     circuit_close(circ);
     return -1;
   }
@@ -681,7 +655,7 @@ int circuit_establish_circuit(void) {
     circ->n_addr = firsthop->addr;
     circ->n_port = firsthop->or_port;
     if(options.OnionRouter) { /* we would be connected if he were up. but he's not. */
-      log_fn(LOG_DEBUG,"Route's firsthop isn't connected.");
+      log_fn(LOG_INFO,"Route's firsthop isn't connected.");
       circuit_close(circ); 
       return -1;
     }
@@ -689,7 +663,7 @@ int circuit_establish_circuit(void) {
     if(!n_conn) { /* launch the connection */
       n_conn = connection_or_connect(firsthop);
       if(!n_conn) { /* connect failed, forget the whole thing */
-        log_fn(LOG_DEBUG,"connect to firsthop failed. Closing.");
+        log_fn(LOG_INFO,"connect to firsthop failed. Closing.");
         circuit_close(circ);
         return -1;
       }
@@ -705,7 +679,7 @@ int circuit_establish_circuit(void) {
     circ->n_conn = n_conn;
     log_fn(LOG_DEBUG,"Conn open. Delivering first onion skin.");
     if(circuit_send_next_onion_skin(circ) < 0) {
-      log_fn(LOG_DEBUG,"circuit_send_next_onion_skin failed.");
+      log_fn(LOG_INFO,"circuit_send_next_onion_skin failed.");
       circuit_close(circ);
       return -1;
     }
@@ -726,7 +700,7 @@ void circuit_n_conn_open(connection_t *or_conn) {
     log_fn(LOG_DEBUG,"Found circ, sending onion skin.");
     circ->n_conn = or_conn;
     if(circuit_send_next_onion_skin(circ) < 0) {
-      log_fn(LOG_DEBUG,"circuit marked for closing.");
+      log_fn(LOG_INFO,"send_next_onion_skin failed; circuit marked for closing.");
       circuit_close(circ);
       return; /* FIXME will want to try the other circuits too? */
     }
@@ -752,7 +726,7 @@ int circuit_send_next_onion_skin(circuit_t *circ) {
     cell.length = DH_ONIONSKIN_LEN;
 
     if(onion_skin_create(circ->n_conn->onion_pkey, &(circ->cpath->handshake_state), cell.payload) < 0) {
-      log_fn(LOG_INFO,"onion_skin_create (first hop) failed.");
+      log_fn(LOG_WARNING,"onion_skin_create (first hop) failed.");
       return -1;
     }
 
@@ -772,13 +746,13 @@ int circuit_send_next_onion_skin(circuit_t *circ) {
         hop=hop->next) ;
     if(hop == circ->cpath) { /* done building the circuit. whew. */
       circ->state = CIRCUIT_STATE_OPEN;
-      log_fn(LOG_DEBUG,"circuit built!");
+      log_fn(LOG_INFO,"circuit built!");
       return 0;
     }
 
     router = router_get_by_addr_port(hop->addr,hop->port);
     if(!router) {
-      log_fn(LOG_INFO,"couldn't lookup router %d:%d",hop->addr,hop->port);
+      log_fn(LOG_WARNING,"couldn't lookup router %d:%d",hop->addr,hop->port);
       return -1;
     }
 
@@ -792,14 +766,14 @@ int circuit_send_next_onion_skin(circuit_t *circ) {
     *(uint32_t*)(cell.payload+RELAY_HEADER_SIZE) = htonl(hop->addr);
     *(uint16_t*)(cell.payload+RELAY_HEADER_SIZE+4) = htons(hop->port);
     if(onion_skin_create(router->onion_pkey, &(hop->handshake_state), cell.payload+RELAY_HEADER_SIZE+6) < 0) {
-      log_fn(LOG_INFO,"onion_skin_create failed.");
+      log_fn(LOG_WARNING,"onion_skin_create failed.");
       return -1;
     }
 
     log_fn(LOG_DEBUG,"Sending extend relay cell.");
     /* send it to hop->prev, because it will transfer it to a create cell and then send to hop */
     if(circuit_deliver_relay_cell(&cell, circ, CELL_DIRECTION_OUT, hop->prev) < 0) {
-      log_fn(LOG_DEBUG,"failed to deliver extend cell. Closing.");
+      log_fn(LOG_WARNING,"failed to deliver extend cell. Closing.");
       return -1;
     }
     hop->state = CPATH_STATE_AWAITING_KEYS;
@@ -855,7 +829,7 @@ int circuit_extend(cell_t *cell, circuit_t *circ) {
   log_fn(LOG_DEBUG,"aci_type = %u.",aci_type);
   circ->n_aci = get_unique_aci_by_addr_port(circ->n_addr, circ->n_port, aci_type);
   if(!circ->n_aci) {
-    log_fn(LOG_ERR,"failed to get unique aci.");
+    log_fn(LOG_WARNING,"failed to get unique aci.");
     return -1;
   }
   log_fn(LOG_DEBUG,"Chosen ACI %u.",circ->n_aci);
@@ -889,14 +863,14 @@ int circuit_finish_handshake(circuit_t *circ, char *reply) {
         hop != circ->cpath && hop->state == CPATH_STATE_OPEN;
         hop=hop->next) ;
     if(hop == circ->cpath) { /* got an extended when we're all done? */
-      log_fn(LOG_INFO,"got extended when circ already built? Closing.");
+      log_fn(LOG_WARNING,"got extended when circ already built? Closing.");
       return -1;
     }
   }
   assert(hop->state == CPATH_STATE_AWAITING_KEYS);
 
   if(onion_skin_client_handshake(hop->handshake_state, reply, keys, 32) < 0) {
-    log_fn(LOG_ERR,"onion_skin_client_handshake failed.");
+    log_fn(LOG_WARNING,"onion_skin_client_handshake failed.");
     return -1;
   }
 
@@ -906,18 +880,18 @@ int circuit_finish_handshake(circuit_t *circ, char *reply) {
   log_fn(LOG_DEBUG,"hop %d init cipher forward %d, backward %d.", (uint32_t)hop, *(uint32_t*)keys, *(uint32_t*)(keys+16));
   if (!(hop->f_crypto =
         crypto_create_init_cipher(CIRCUIT_CIPHER,keys,iv,1))) {
-    log(LOG_ERR,"Cipher initialization failed.");
+    log(LOG_WARNING,"forward cipher initialization failed.");
     return -1;
   }
 
   if (!(hop->b_crypto =
         crypto_create_init_cipher(CIRCUIT_CIPHER,keys+16,iv,0))) {
-    log(LOG_ERR,"Cipher initialization failed.");
+    log(LOG_WARNING,"backward cipher initialization failed.");
     return -1;
   }
 
   hop->state = CPATH_STATE_OPEN;
-  log_fn(LOG_DEBUG,"Completed.");
+  log_fn(LOG_INFO,"finished");
   return 0;
 }
 
@@ -935,7 +909,7 @@ int circuit_truncated(circuit_t *circ, crypt_path_t *layer) {
 
     for(stream = circ->p_streams; stream; stream=stream->next_stream) {
       if(stream->cpath_layer == victim) {
-        log_fn(LOG_DEBUG, "Marking stream %d for close.", *(int*)stream->stream_id);
+        log_fn(LOG_INFO, "Marking stream %d for close.", *(int*)stream->stream_id);
         stream->marked_for_close = 1;
       }
     }
@@ -944,7 +918,7 @@ int circuit_truncated(circuit_t *circ, crypt_path_t *layer) {
     circuit_free_cpath_node(victim);
   }
 
-  log_fn(LOG_DEBUG, "Complete.");
+  log_fn(LOG_INFO, "finished");
   return 0;
 }
 

src/or/command.c

@@ -77,7 +77,7 @@ void command_process_cell(cell_t *cell, connection_t *conn) {
                                 command_process_destroy_cell);
       break;
     default:
-      log(LOG_DEBUG,"Cell of unknown type (%d) received. Dropping.", cell->command);
+      log_fn(LOG_WARNING,"Cell of unknown type (%d) received. Dropping.", cell->command);
       break;
   }
 }
@@ -88,14 +88,14 @@ static void command_process_create_cell(cell_t *cell, connection_t *conn) {
   circ = circuit_get_by_aci_conn(cell->aci, conn);
 
   if(circ) {
-    log_fn(LOG_DEBUG,"received CREATE cell for known circ. Dropping.");
+    log_fn(LOG_WARNING,"received CREATE cell for known circ. Dropping.");
     return;
   }
 
   circ = circuit_new(cell->aci, conn);
   circ->state = CIRCUIT_STATE_ONIONSKIN_PENDING;
   if(cell->length != DH_ONIONSKIN_LEN) {
-    log_fn(LOG_DEBUG,"Bad cell length %d. Dropping.", cell->length);
+    log_fn(LOG_WARNING,"Bad cell length %d. Dropping.", cell->length);
     circuit_close(circ);
     return;
   }
@@ -104,11 +104,11 @@ static void command_process_create_cell(cell_t *cell, connection_t *conn) {
 
   /* hand it off to the cpuworkers, and then return */
   if(assign_to_cpuworker(NULL, CPUWORKER_TASK_ONION, circ) < 0) {
-    log_fn(LOG_DEBUG,"Failed to hand off onionskin. Closing.");
+    log_fn(LOG_WARNING,"Failed to hand off onionskin. Closing.");
     circuit_close(circ);
     return;
   }
-  log_fn(LOG_DEBUG,"success: handed off onionskin.");
+  log_fn(LOG_INFO,"success: handed off onionskin.");
 }
 
 static void command_process_created_cell(cell_t *cell, connection_t *conn) {
@@ -118,12 +118,13 @@ static void command_process_created_cell(cell_t *cell, connection_t *conn) {
   circ = circuit_get_by_aci_conn(cell->aci, conn);
 
   if(!circ) {
-    log_fn(LOG_DEBUG,"received CREATED cell for unknown circ. Dropping.");
+    log_fn(LOG_WARNING,"received CREATED cell for unknown circ. Dropping.");
     return;
   }
 
   if(circ->n_aci != cell->aci) {
-    log_fn(LOG_DEBUG,"got created cell from OPward? Dropping.");
+    log_fn(LOG_WARNING,"got created cell from OPward? Closing.");
+    circuit_close(circ);
     return;
   }
   assert(cell->length == DH_KEY_LEN);
@@ -131,13 +132,13 @@ static void command_process_created_cell(cell_t *cell, connection_t *conn) {
   if(circ->cpath) { /* we're the OP. Handshake this. */
     log_fn(LOG_DEBUG,"at OP. Finishing handshake.");
     if(circuit_finish_handshake(circ, cell->payload) < 0) {
-      log_fn(LOG_INFO,"circuit_finish_handshake failed.");
+      log_fn(LOG_WARNING,"circuit_finish_handshake failed.");
       circuit_close(circ);
       return;
     }
     log_fn(LOG_DEBUG,"Moving to next skin.");
     if(circuit_send_next_onion_skin(circ) < 0) {
-      log_fn(LOG_INFO,"circuit_send_next_onion_skin failed.");
+      log_fn(LOG_WARNING,"circuit_send_next_onion_skin failed.");
       circuit_close(circ);
       return;
     }
@@ -151,9 +152,9 @@ static void command_process_created_cell(cell_t *cell, connection_t *conn) {
     newcell.length = RELAY_HEADER_SIZE + cell->length;
     memcpy(newcell.payload+RELAY_HEADER_SIZE, cell->payload, DH_KEY_LEN);
 
-    log_fn(LOG_DEBUG,"Sending extended relay cell.");
+    log_fn(LOG_INFO,"Converting created cell to extended relay cell, sending.");
     if(circuit_deliver_relay_cell(&newcell, circ, CELL_DIRECTION_IN, NULL) < 0) {
-      log_fn(LOG_DEBUG,"failed to deliver extended cell. Closing.");
+      log_fn(LOG_WARNING,"failed to deliver extended cell. Closing.");
       circuit_close(circ);
       return;
     }
@@ -166,26 +167,27 @@ static void command_process_relay_cell(cell_t *cell, connection_t *conn) {
   circ = circuit_get_by_aci_conn(cell->aci, conn);
 
   if(!circ) {
-    log_fn(LOG_DEBUG,"unknown circuit %d. Dropping.", cell->aci);
+    log_fn(LOG_INFO,"unknown circuit %d. Dropping.", cell->aci);
     return;
   }
 
   if(circ->state == CIRCUIT_STATE_ONIONSKIN_PENDING) {
-    log_fn(LOG_DEBUG,"circuit in create_wait. Dropping.");
+    log_fn(LOG_WARNING,"circuit in create_wait. Closing.");
+    circuit_close(circ);
     return;
   }
 
   if(cell->aci == circ->p_aci) { /* it's an outgoing cell */
     cell->aci = circ->n_aci; /* switch it */
     if(circuit_deliver_relay_cell(cell, circ, CELL_DIRECTION_OUT, conn->cpath_layer) < 0) {
-      log_fn(LOG_INFO,"circuit_deliver_relay_cell (forward) failed. Closing.");
+      log_fn(LOG_WARNING,"circuit_deliver_relay_cell (forward) failed. Closing.");
       circuit_close(circ);
       return;
     }
   } else { /* it's an ingoing cell */
     cell->aci = circ->p_aci; /* switch it */
     if(circuit_deliver_relay_cell(cell, circ, CELL_DIRECTION_IN, NULL) < 0) {
-      log_fn(LOG_DEBUG,"circuit_deliver_relay_cell (backward) failed. Closing.");
+      log_fn(LOG_WARNING,"circuit_deliver_relay_cell (backward) failed. Closing.");
       circuit_close(circ);
       return;
     }
@@ -198,7 +200,7 @@ static void command_process_destroy_cell(cell_t *cell, connection_t *conn) {
   circ = circuit_get_by_aci_conn(cell->aci, conn);
 
   if(!circ) {
-    log_fn(LOG_DEBUG,"unknown circuit %d. Dropping.", cell->aci);
+    log_fn(LOG_INFO,"unknown circuit %d. Dropping.", cell->aci);
     return;
   }
 

src/or/config.c

@@ -163,7 +163,7 @@ static int config_compare(struct config_line *c, char *key, int type, void *arg)
     case CONFIG_TYPE_BOOL:
       i = atoi(c->value);
       if (i != 0 && i != 1) {
-        log(LOG_ERR, "Boolean keyword '%s' expects 0 or 1", c->key);
+        log(LOG_WARNING, "Boolean keyword '%s' expects 0 or 1", c->key);
         return 0;
       }
       *(int *)arg = i;
@@ -259,7 +259,7 @@ int getconfig(int argc, char **argv, or_options_t *options) {
   log(LOG_DEBUG,"Opening config file '%s'",fname);
 
   cf = config_open(fname);
-  if(!cf) { /* it's defined but not there. that's no good. */
+  if(!cf) {
     log(LOG_ERR, "Unable to open configuration file '%s'.",fname);
     return -1;
   }

src/or/connection.c

@@ -129,7 +129,7 @@ int connection_create_listener(struct sockaddr_in *bindaddr, int type) {
 
   s = socket(PF_INET,SOCK_STREAM,IPPROTO_TCP);
   if (s < 0) { 
-    log_fn(LOG_ERR,"Socket creation failed.");
+    log_fn(LOG_WARNING,"Socket creation failed.");
     return -1;
   }
 
@@ -137,12 +137,12 @@ int connection_create_listener(struct sockaddr_in *bindaddr, int type) {
 
   if(bind(s,(struct sockaddr *)bindaddr,sizeof(*bindaddr)) < 0) {
     perror("bind ");
-    log(LOG_ERR,"Could not bind to port %u.",ntohs(bindaddr->sin_port));
+    log(LOG_WARNING,"Could not bind to port %u.",ntohs(bindaddr->sin_port));
     return -1;
   }
 
   if(listen(s,SOMAXCONN) < 0) {
-    log(LOG_ERR,"Could not listen on port %u.",ntohs(bindaddr->sin_port));
+    log(LOG_WARNING,"Could not listen on port %u.",ntohs(bindaddr->sin_port));
     return -1;
   }
 
@@ -150,7 +150,7 @@ int connection_create_listener(struct sockaddr_in *bindaddr, int type) {
 
   conn = connection_new(type);
   if(!conn) {
-    log_fn(LOG_DEBUG,"connection_new failed. Giving up.");
+    log_fn(LOG_WARNING,"connection_new failed. Giving up.");
     return -1;
   }
   conn->s = s;
@@ -158,7 +158,7 @@ int connection_create_listener(struct sockaddr_in *bindaddr, int type) {
   conn->bandwidth = -1;
 
   if(connection_add(conn) < 0) { /* no space, forget it */
-    log_fn(LOG_DEBUG,"connection_add failed. Giving up.");
+    log_fn(LOG_WARNING,"connection_add failed. Giving up.");
     connection_free(conn);
     return -1;
   }
@@ -172,7 +172,6 @@ int connection_create_listener(struct sockaddr_in *bindaddr, int type) {
 }
 
 int connection_handle_listener_read(connection_t *conn, int new_type) {
-
   int news; /* the new socket */
   connection_t *newconn;
   struct sockaddr_in remote; /* information about the remote peer when connecting to other routers */
@@ -193,7 +192,7 @@ int connection_handle_listener_read(connection_t *conn, int new_type) {
 #endif
     }
     /* else there was a real error. */
-    log_fn(LOG_ERR,"accept() failed. Closing.");
+    log_fn(LOG_WARNING,"accept() failed. Closing listener.");
     return -1;
   }
   log(LOG_INFO,"Connection accepted on socket %d (child of fd %d).",news, conn->s);
@@ -201,6 +200,10 @@ int connection_handle_listener_read(connection_t *conn, int new_type) {
   set_socket_nonblocking(news);
 
   newconn = connection_new(new_type);
+  if(!newconn) {
+    log_fn(LOG_WARNING,"connection_new failed. Giving up.");
+    return 0;
+  }
   newconn->s = news;
 
   if(!connection_speaks_cells(newconn)) {
@@ -230,9 +233,7 @@ static int connection_init_accepted_conn(connection_t *conn) {
 
   switch(conn->type) {
     case CONN_TYPE_OR:
-      if(connection_tls_start_handshake(conn, 1) < 0)
-        return -1;
-      break;
+      return connection_tls_start_handshake(conn, 1);
     case CONN_TYPE_AP:
       conn->state = AP_CONN_STATE_SOCKS_WAIT;
       break;
@@ -247,7 +248,7 @@ int connection_tls_start_handshake(connection_t *conn, int receiving) {
   conn->state = OR_CONN_STATE_HANDSHAKING;
   conn->tls = tor_tls_new(conn->s, receiving);
   if(!conn->tls) {
-    log_fn(LOG_ERR,"tor_tls_new failed. Closing.");
+    log_fn(LOG_WARNING,"tor_tls_new failed. Closing.");
     return -1;
   }
   connection_start_reading(conn);
@@ -261,7 +262,7 @@ static int connection_tls_continue_handshake(connection_t *conn) {
   switch(tor_tls_handshake(conn->tls)) {
     case TOR_TLS_ERROR:
     case TOR_TLS_CLOSE:
-      log_fn(LOG_DEBUG,"tls error. breaking.");
+      log_fn(LOG_INFO,"tls error. breaking.");
       return -1;
     case TOR_TLS_DONE:
      return connection_tls_finish_handshake(conn);
@@ -288,25 +289,25 @@ static int connection_tls_finish_handshake(connection_t *conn) {
     if(tor_tls_peer_has_cert(conn->tls)) { /* it's another OR */
       pk = tor_tls_verify(conn->tls);
       if(!pk) {
-        log_fn(LOG_INFO,"Other side has a cert but it's bad. Closing.");
+        log_fn(LOG_WARNING,"Other side has a cert but it's invalid. Closing.");
         return -1;
       }
       router = router_get_by_link_pk(pk);
       if (!router) {
-        log_fn(LOG_INFO,"Unrecognized public key from peer. Closing.");
+        log_fn(LOG_WARNING,"Unrecognized public key from peer. Closing.");
         crypto_free_pk_env(pk);
         return -1;
       }
       if(conn->link_pkey) { /* I initiated this connection. */
         if(crypto_pk_cmp_keys(conn->link_pkey, pk)) {
-          log_fn(LOG_INFO,"We connected to '%s' but he gave us a different key. Closing.", router->nickname);
+          log_fn(LOG_WARNING,"We connected to '%s' but he gave us a different key. Closing.", router->nickname);
           crypto_free_pk_env(pk);
           return -1;
         }
         log_fn(LOG_DEBUG,"The router's pk matches the one we meant to connect to. Good.");
       } else {
         if(connection_exact_get_by_addr_port(router->addr,router->or_port)) {
-          log_fn(LOG_INFO,"That router is already connected. Dropping.");
+          log_fn(LOG_INFO,"Router %s is already connected. Dropping.", router->nickname);
           return -1;
         }
         connection_or_init_conn_from_router(conn, router);
@@ -317,22 +318,22 @@ static int connection_tls_finish_handshake(connection_t *conn) {
     }
   } else { /* I'm a client */
     if(!tor_tls_peer_has_cert(conn->tls)) { /* it's a client too?! */
-      log_fn(LOG_INFO,"Neither peer sent a cert! Closing.");
+      log_fn(LOG_WARNING,"Neither peer sent a cert! Closing.");
       return -1;
     }
     pk = tor_tls_verify(conn->tls);
     if(!pk) {
-      log_fn(LOG_INFO,"Other side has a cert but it's bad. Closing.");
+      log_fn(LOG_WARNING,"Other side has a cert but it's invalid. Closing.");
       return -1;
     }
     router = router_get_by_link_pk(pk);
     if (!router) {
-      log_fn(LOG_INFO,"Unrecognized public key from peer. Closing.");
+      log_fn(LOG_WARNING,"Unrecognized public key from peer. Closing.");
       crypto_free_pk_env(pk);
       return -1;
     }
     if(crypto_pk_cmp_keys(conn->link_pkey, pk)) {
-      log_fn(LOG_INFO,"We connected to '%s' but he gave us a different key. Closing.", router->nickname);
+      log_fn(LOG_WARNING,"We connected to '%s' but he gave us a different key. Closing.", router->nickname);
       crypto_free_pk_env(pk);
       return -1;
     }
@@ -355,7 +356,7 @@ int connection_connect(connection_t *conn, char *address, uint32_t addr, uint16_
 
   s=socket(PF_INET,SOCK_STREAM,IPPROTO_TCP);
   if (s < 0) {
-    log_fn(LOG_ERR,"Error creating network socket.");
+    log_fn(LOG_WARNING,"Error creating network socket.");
     return -1;
   }
   set_socket_nonblocking(s);
@@ -371,7 +372,7 @@ int connection_connect(connection_t *conn, char *address, uint32_t addr, uint16_
     if(!ERRNO_CONN_EINPROGRESS(errno)) {
       /* yuck. kill it. */
       perror("connect");
-      log_fn(LOG_DEBUG,"Connect failed.");
+      log_fn(LOG_INFO,"Connect() to %s:%u failed.",address,port);
       return -1;
     } else {
       /* it's in progress. set state appropriately and return. */
@@ -382,7 +383,7 @@ int connection_connect(connection_t *conn, char *address, uint32_t addr, uint16_
   }
 
   /* it succeeded. we're connected. */
-  log_fn(LOG_DEBUG,"Connection to %s:%u established.",address,port);
+  log_fn(LOG_INFO,"Connection to %s:%u established.",address,port);
   conn->s = s;
   return 1;
 }
@@ -455,7 +456,7 @@ int connection_handle_read(connection_t *conn) {
     return -1;
   }
   if(!connection_state_is_open(conn) && conn->receiver_bucket == 0) {
-    log_fn(LOG_DEBUG,"receiver bucket reached 0 before handshake finished. Closing.");
+    log_fn(LOG_WARNING,"receiver bucket reached 0 before handshake finished. Closing.");
     return -1;
   }
   return 0;
@@ -498,7 +499,7 @@ int connection_read_to_buf(connection_t *conn) {
     switch(result) {
       case TOR_TLS_ERROR:
       case TOR_TLS_CLOSE:
-        log_fn(LOG_DEBUG,"tls error. breaking.");
+        log_fn(LOG_INFO,"tls error. breaking.");
         return -1; /* XXX deal with close better */
       case TOR_TLS_WANTWRITE:
         connection_start_writing(conn);
@@ -557,7 +558,7 @@ int connection_handle_write(connection_t *conn) {
   struct timeval now;
 
   if(connection_is_listener(conn)) {
-    log_fn(LOG_DEBUG,"Got a listener socket. Can't happen!");
+    log_fn(LOG_WARNING,"Got a listener socket. Can't happen!");
     return -1;
   }
 
@@ -574,7 +575,7 @@ int connection_handle_write(connection_t *conn) {
     switch(flush_buf_tls(conn->tls, conn->outbuf, &conn->outbuf_flushlen)) {
       case TOR_TLS_ERROR:
       case TOR_TLS_CLOSE:
-        log_fn(LOG_DEBUG,"tls error. breaking.");
+        log_fn(LOG_INFO,"tls error. breaking.");
         return -1; /* XXX deal with close better */
       case TOR_TLS_WANTWRITE:
         log_fn(LOG_DEBUG,"wanted write.");
@@ -696,7 +697,7 @@ int connection_process_inbuf(connection_t *conn) {
     case CONN_TYPE_CPUWORKER:
       return connection_cpu_process_inbuf(conn); 
     default:
-      log_fn(LOG_DEBUG,"got unexpected conn->type.");
+      log_fn(LOG_WARNING,"got unexpected conn->type %d.", conn->type);
       return -1;
   }
 }
@@ -720,7 +721,7 @@ int connection_finished_flushing(connection_t *conn) {
     case CONN_TYPE_CPUWORKER:
       return connection_cpu_finished_flushing(conn);
     default:
-      log_fn(LOG_DEBUG,"got unexpected conn->type.");
+      log_fn(LOG_WARNING,"got unexpected conn->type %d.", conn->type);
       return -1;
   }
 }

src/or/connection_edge.c

@@ -44,13 +44,13 @@ int connection_edge_process_inbuf(connection_t *conn) {
     cell.aci = circ->n_aci;
 
     if (circuit_deliver_relay_cell(&cell, circ, CELL_DIRECTION(conn->type), conn->cpath_layer) < 0) {
-      log(LOG_DEBUG,"circuit_deliver_relay_cell failed. Closing.");
+      log_fn(LOG_WARNING,"(fd %d) circuit_deliver_relay_cell failed. Closing.", conn->s);
       circuit_close(circ);
     }
     return 0;
 #else 
     /* eof reached, kill it. */
-    log_fn(LOG_DEBUG,"conn reached eof. Closing.");
+    log_fn(LOG_INFO,"conn (fd %d) reached eof. Closing.", conn->s);
     return -1;
 #endif
   }
@@ -64,7 +64,7 @@ int connection_edge_process_inbuf(connection_t *conn) {
         return -1;
       return 0;
     case EXIT_CONN_STATE_CONNECTING:
-      log_fn(LOG_DEBUG,"text from server while in 'connecting' state at exit. Leaving it on buffer.");
+      log_fn(LOG_INFO,"text from server while in 'connecting' state at exit. Leaving it on buffer.");
       return 0;
   }
 
@@ -76,7 +76,7 @@ int connection_edge_send_command(connection_t *fromconn, circuit_t *circ, int re
   int cell_direction;
 
   if(!circ) {
-    log_fn(LOG_DEBUG,"no circ. Closing.");
+    log_fn(LOG_WARNING,"no circ. Closing.");
     return -1;
   }
 
@@ -101,7 +101,7 @@ int connection_edge_send_command(connection_t *fromconn, circuit_t *circ, int re
   log_fn(LOG_INFO,"delivering %d cell %s.", relay_command, cell_direction == CELL_DIRECTION_OUT ? "forward" : "backward");
 
   if(circuit_deliver_relay_cell(&cell, circ, cell_direction, fromconn ? fromconn->cpath_layer : NULL) < 0) {
-    log_fn(LOG_DEBUG,"circuit_deliver_relay_cell failed. Closing.");
+    log_fn(LOG_WARNING,"circuit_deliver_relay_cell failed. Closing.");
     circuit_close(circ);
     return 0;
   }
@@ -134,7 +134,7 @@ int connection_edge_process_relay_cell(cell_t *cell, circuit_t *circ, connection
         dns_cancel_pending_resolve(conn->address, conn);
       }
     } else {
-      log_fn(LOG_DEBUG,"Got an unexpected relay cell, not in 'open' state. Dropping.");
+      log_fn(LOG_WARNING,"Got an unexpected relay cell, not in 'open' state. Dropping.");
     }
     return 0;
   }
@@ -142,18 +142,18 @@ int connection_edge_process_relay_cell(cell_t *cell, circuit_t *circ, connection
   switch(relay_command) {
     case RELAY_COMMAND_BEGIN:
       if(edge_type == EDGE_AP) {
-        log_fn(LOG_INFO,"relay begin request unsupported. Dropping.");
+        log_fn(LOG_WARNING,"relay begin request unsupported at AP. Dropping.");
         return 0;
       }
       if(conn) {
-        log_fn(LOG_INFO,"begin cell for known stream. Dropping.");
+        log_fn(LOG_WARNING,"begin cell for known stream. Dropping.");
         return 0;
       }
       return connection_exit_begin_conn(cell, circ);
     case RELAY_COMMAND_DATA:
       if((edge_type == EDGE_AP && --layer_hint->deliver_window < 0) ||
          (edge_type == EDGE_EXIT && --circ->deliver_window < 0)) {
-        log_fn(LOG_DEBUG,"circ deliver_window below 0. Killing.");
+        log_fn(LOG_WARNING,"(relay data) circ deliver_window below 0. Killing.");
         return -1;
       }
       log_fn(LOG_DEBUG,"circ deliver_window now %d.", edge_type == EDGE_AP ? layer_hint->deliver_window : circ->deliver_window);
@@ -162,12 +162,12 @@ int connection_edge_process_relay_cell(cell_t *cell, circuit_t *circ, connection
         return -1;
 
       if(!conn) {
-        log_fn(LOG_DEBUG,"relay cell dropped, unknown stream %d.",*(int*)conn->stream_id);
+        log_fn(LOG_INFO,"relay cell dropped, unknown stream %d.",*(int*)conn->stream_id);
         return 0;
       }
 
       if(--conn->deliver_window < 0) { /* is it below 0 after decrement? */
-        log_fn(LOG_DEBUG,"conn deliver_window below 0. Killing.");
+        log_fn(LOG_WARNING,"(relay data) conn deliver_window below 0. Killing.");
         return -1; /* somebody's breaking protocol. kill the whole circuit. */
       }
 
@@ -182,10 +182,10 @@ int connection_edge_process_relay_cell(cell_t *cell, circuit_t *circ, connection
       return 0;
     case RELAY_COMMAND_END:
       if(!conn) {
-        log_fn(LOG_DEBUG,"end cell dropped, unknown stream %d.",*(int*)conn->stream_id);
+        log_fn(LOG_INFO,"end cell dropped, unknown stream %d.",*(int*)conn->stream_id);
         return 0;
       }
-      log_fn(LOG_DEBUG,"end cell for stream %d. Removing stream.",*(int*)conn->stream_id);
+      log_fn(LOG_INFO,"end cell for stream %d. Removing stream.",*(int*)conn->stream_id);
 
 #ifdef HALF_OPEN
       conn->done_sending = 1;
@@ -197,24 +197,24 @@ int connection_edge_process_relay_cell(cell_t *cell, circuit_t *circ, connection
       break;
     case RELAY_COMMAND_EXTEND:
       if(conn) {
-        log_fn(LOG_INFO,"'extend' for non-zero stream. Dropping.");
+        log_fn(LOG_WARNING,"'extend' for non-zero stream. Dropping.");
         return 0;
       }
       return circuit_extend(cell, circ);
     case RELAY_COMMAND_EXTENDED:
       if(edge_type == EDGE_EXIT) {
-        log_fn(LOG_INFO,"'extended' unsupported at exit. Dropping.");
+        log_fn(LOG_WARNING,"'extended' unsupported at exit. Dropping.");
         return 0;
       }
       log_fn(LOG_DEBUG,"Got an extended cell! Yay.");
       if(circuit_finish_handshake(circ, cell->payload+RELAY_HEADER_SIZE) < 0) {
-        log_fn(LOG_INFO,"circuit_finish_handshake failed.");
+        log_fn(LOG_WARNING,"circuit_finish_handshake failed.");
         return -1;
       }
       return circuit_send_next_onion_skin(circ);
     case RELAY_COMMAND_TRUNCATE:
       if(edge_type == EDGE_AP) {
-        log_fn(LOG_INFO,"'truncate' unsupported at AP. Dropping.");
+        log_fn(LOG_WARNING,"'truncate' unsupported at AP. Dropping.");
         return 0;
       }
       if(circ->n_conn) {
@@ -225,20 +225,20 @@ int connection_edge_process_relay_cell(cell_t *cell, circuit_t *circ, connection
       return connection_edge_send_command(NULL, circ, RELAY_COMMAND_TRUNCATED);
     case RELAY_COMMAND_TRUNCATED:
       if(edge_type == EDGE_EXIT) {
-        log_fn(LOG_INFO,"'truncated' unsupported at exit. Dropping.");
+        log_fn(LOG_WARNING,"'truncated' unsupported at exit. Dropping.");
         return 0;
       }
       return circuit_truncated(circ, layer_hint);
     case RELAY_COMMAND_CONNECTED:
       if(edge_type == EDGE_EXIT) {
-        log_fn(LOG_INFO,"'connected' unsupported at exit. Dropping.");
+        log_fn(LOG_WARNING,"'connected' unsupported at exit. Dropping.");
         return 0;
       }
       if(!conn) {
-        log_fn(LOG_DEBUG,"connected cell dropped, unknown stream %d.",*(int*)conn->stream_id);
+        log_fn(LOG_INFO,"connected cell dropped, unknown stream %d.",*(int*)conn->stream_id);
         break;
       }
-      log_fn(LOG_DEBUG,"Connected! Notifying application.");
+      log_fn(LOG_INFO,"Connected! Notifying application.");
       if(connection_ap_handshake_socks_reply(conn, SOCKS4_REQUEST_GRANTED) < 0) {
         conn->marked_for_close = 1;
       }
@@ -264,7 +264,8 @@ int connection_edge_process_relay_cell(cell_t *cell, circuit_t *circ, connection
       connection_package_raw_inbuf(conn); /* handle whatever might still be on the inbuf */
       break;
     default:
-      log_fn(LOG_DEBUG,"unknown relay command %d.",relay_command);
+      log_fn(LOG_WARNING,"unknown relay command %d.",relay_command);
+      return -1;
   }
   return 0;
 }
@@ -289,7 +290,7 @@ int connection_edge_finished_flushing(connection_t *conn) {
       }
       /* the connect has finished. */
 
-      log_fn(LOG_DEBUG,"Exit connection to %s:%u established.",
+      log_fn(LOG_INFO,"Exit connection to %s:%u established.",
           conn->address,conn->port);
 
       conn->state = EXIT_CONN_STATE_OPEN;
@@ -304,10 +305,9 @@ int connection_edge_finished_flushing(connection_t *conn) {
       connection_stop_writing(conn);
       return connection_consider_sending_sendme(conn, conn->type);
     default:
-      log_fn(LOG_DEBUG,"BUG: called in unexpected state.");
-      return 0;
+      log_fn(LOG_WARNING,"BUG: called in unexpected state.");
+      return -1;
   }
-
   return 0;
 }
 
@@ -323,7 +323,7 @@ repeat_connection_package_raw_inbuf:
  
   circ = circuit_get_by_conn(conn);
   if(!circ) {
-    log_fn(LOG_DEBUG,"conn has no circuits!");
+    log_fn(LOG_INFO,"conn has no circuits! Closing.");
     return -1;
   }
  
@@ -331,7 +331,7 @@ repeat_connection_package_raw_inbuf:
     return 0;
  
   if(conn->package_window <= 0) {
-    log_fn(LOG_ERR,"called with package_window 0. Tell Roger.");
+    log_fn(LOG_WARNING,"called with package_window 0. Tell Roger.");
     connection_stop_reading(conn);
     return 0;
   }
@@ -363,7 +363,7 @@ repeat_connection_package_raw_inbuf:
   if(conn->type == CONN_TYPE_EXIT) {
     cell.aci = circ->p_aci;
     if(circuit_deliver_relay_cell(&cell, circ, CELL_DIRECTION_IN, NULL) < 0) {
-      log_fn(LOG_DEBUG,"circuit_deliver_relay_cell (backward) failed. Closing.");
+      log_fn(LOG_WARNING,"circuit_deliver_relay_cell (backward) failed. Closing.");
       circuit_close(circ);
       return 0;
     }
@@ -373,7 +373,7 @@ repeat_connection_package_raw_inbuf:
     assert(conn->type == CONN_TYPE_AP);
     cell.aci = circ->n_aci;
     if(circuit_deliver_relay_cell(&cell, circ, CELL_DIRECTION_OUT, conn->cpath_layer) < 0) {
-      log_fn(LOG_DEBUG,"circuit_deliver_relay_cell (forward) failed. Closing.");
+      log_fn(LOG_WARNING,"circuit_deliver_relay_cell (forward) failed. Closing.");
       circuit_close(circ);
       return 0;
     }
@@ -404,7 +404,7 @@ int connection_consider_sending_sendme(connection_t *conn, int edge_type) {
   circ = circuit_get_by_conn(conn);
   if(!circ) {
     /* this can legitimately happen if the destroy has already arrived and torn down the circuit */
-    log_fn(LOG_DEBUG,"No circuit associated with conn. Skipping.");
+    log_fn(LOG_INFO,"No circuit associated with conn. Skipping.");
     return 0;
   }
  
@@ -423,7 +423,7 @@ int connection_consider_sending_sendme(connection_t *conn, int edge_type) {
     log_fn(LOG_DEBUG,"Outbuf %d, Queueing stream sendme.", conn->outbuf_flushlen);
     conn->deliver_window += STREAMWINDOW_INCREMENT;
     if(circuit_deliver_relay_cell(&cell, circ, CELL_DIRECTION(edge_type), conn->cpath_layer) < 0) {
-      log_fn(LOG_DEBUG,"circuit_deliver_relay_cell failed. Closing.");
+      log_fn(LOG_WARNING,"circuit_deliver_relay_cell failed. Closing.");
       circuit_close(circ);
       return 0;
     }
@@ -444,7 +444,7 @@ static int connection_ap_handshake_process_socks(connection_t *conn) {
   switch(fetch_from_buf_socks(conn->inbuf,
                               destaddr, sizeof(destaddr), &destport)) {
     case -1:
-      log_fn(LOG_DEBUG,"Fetching socks handshake failed. Closing.");
+      log_fn(LOG_WARNING,"Fetching socks handshake failed. Closing.");
       connection_ap_handshake_socks_reply(conn, SOCKS4_REQUEST_REJECT);
       return -1;
     case 0:
@@ -501,7 +501,7 @@ static int connection_ap_handshake_send_begin(connection_t *ap_conn, circuit_t *
     1 + STREAM_ID_SIZE + RELAY_HEADER_SIZE;
   log_fn(LOG_DEBUG,"Sending relay cell (id %d) to begin stream %d.", *(int *)(cell.payload+1),*(int *)ap_conn->stream_id);
   if(circuit_deliver_relay_cell(&cell, circ, CELL_DIRECTION_OUT, ap_conn->cpath_layer) < 0) {
-    log_fn(LOG_DEBUG,"failed to deliver begin cell. Closing.");
+    log_fn(LOG_WARNING,"failed to deliver begin cell. Closing.");
     return -1;
   }
   ap_conn->package_window = STREAMWINDOW_START;
@@ -542,14 +542,14 @@ static int connection_exit_begin_conn(cell_t *cell, circuit_t *circ) {
   *colon = 0;
 
   if(!atoi(colon+1)) { /* bad port */
-    log_fn(LOG_DEBUG,"relay begin cell has invalid port. Dropping.");
+    log_fn(LOG_WARNING,"relay begin cell has invalid port. Dropping.");
     return 0;
   }
 
   log_fn(LOG_DEBUG,"Creating new exit connection.");
   n_stream = connection_new(CONN_TYPE_EXIT);
   if(!n_stream) {
-    log_fn(LOG_DEBUG,"connection_new failed. Dropping.");
+    log_fn(LOG_WARNING,"connection_new failed. Dropping.");
     return 0;
   }
 
@@ -563,7 +563,7 @@ static int connection_exit_begin_conn(cell_t *cell, circuit_t *circ) {
   n_stream->package_window = STREAMWINDOW_START;
   n_stream->deliver_window = STREAMWINDOW_START;
   if(connection_add(n_stream) < 0) { /* no space, forget it */
-    log_fn(LOG_DEBUG,"connection_add failed. Dropping.");
+    log_fn(LOG_WARNING,"connection_add failed. Dropping.");
     connection_free(n_stream);
     return 0;
   }
@@ -579,7 +579,7 @@ static int connection_exit_begin_conn(cell_t *cell, circuit_t *circ) {
         return 0;
       /* else fall through */
     case -1: /* resolve failed */
-      log_fn(LOG_DEBUG,"Couldn't queue resolve request.");
+      log_fn(LOG_WARNING,"Couldn't queue resolve request.");
       connection_remove(n_stream);
       connection_free(n_stream);
     case 0: /* resolve added to pending list */
@@ -612,7 +612,7 @@ int connection_exit_connect(connection_t *conn) {
   connection_set_poll_socket(conn);
   conn->state = EXIT_CONN_STATE_OPEN;
   if(connection_wants_to_flush(conn)) { /* in case there are any queued data cells */
-    log_fn(LOG_ERR,"tell roger: newly connected conn had data waiting!");
+    log_fn(LOG_WARNING,"tell roger: newly connected conn had data waiting!");
 //    connection_start_writing(conn);
   }
 //   connection_process_inbuf(conn);

src/or/connection_or.c

@@ -31,7 +31,7 @@ int connection_or_process_inbuf(connection_t *conn) {
   assert(conn && conn->type == CONN_TYPE_OR);
 
   if(conn->inbuf_reached_eof) {
-    log_fn(LOG_DEBUG,"conn reached eof. Closing.");
+    log_fn(LOG_INFO,"conn reached eof. Closing.");
     return -1;
   }
 
@@ -57,16 +57,17 @@ int connection_or_finished_flushing(connection_t *conn) {
       }
       /* the connect has finished. */
 
-      log_fn(LOG_DEBUG,"OR connect() to router %s:%u finished.",
+      log_fn(LOG_INFO,"OR connect() to router %s:%u finished.",
           conn->address,conn->port);
 
       if(connection_tls_start_handshake(conn, 0) < 0)
         return -1;
+      return 0;
     case OR_CONN_STATE_OPEN:
       connection_stop_writing(conn);
       return 0;
     default:
-      log_fn(LOG_ERR,"BUG: called in unexpected state.");
+      log_fn(LOG_WARNING,"BUG: called in unexpected state.");
       return 0;
   }
 }
@@ -91,7 +92,7 @@ connection_t *connection_or_connect(routerinfo_t *router) {
   assert(router);
 
   if(router_is_me(router->addr, router->or_port)) {
-    /* this is me! don't connect to me. */
+    /* this is me! don't connect to me. XXX use nickname/key */
     log(LOG_DEBUG,"connection_or_connect(): This is me. Skipping.");
     return NULL;
   }
@@ -104,6 +105,7 @@ connection_t *connection_or_connect(routerinfo_t *router) {
 
   conn = connection_new(CONN_TYPE_OR);
   if(!conn) {
+    log_fn(LOG_WARNING,"connection_new failed; skipping.");
     return NULL;
   }
 

src/or/cpuworker.c

@@ -31,14 +31,9 @@ int connection_cpu_finished_flushing(connection_t *conn) {
 }
 
 static void tag_pack(char *tag, uint32_t addr, uint16_t port, aci_t aci) {
-  struct in_addr in;
-
   *(uint32_t *)tag = addr;
   *(uint16_t *)(tag+4) = port;
   *(aci_t *)(tag+6) = aci;
-
-  in.s_addr = htonl(addr);
-  log_fn(LOG_DEBUG,"onion was from %s:%d, aci %d.", inet_ntoa(in), port, aci);
 }
 
 static void tag_unpack(char *tag, uint32_t *addr, uint16_t *port, aci_t *aci) {
@@ -63,7 +58,7 @@ int connection_cpu_process_inbuf(connection_t *conn) {
   assert(conn && conn->type == CONN_TYPE_CPUWORKER);
 
   if(conn->inbuf_reached_eof) {
-    log_fn(LOG_ERR,"Read eof. Worker dying.");
+    log_fn(LOG_WARNING,"Read eof. Worker dying.");
     if(conn->state != CPUWORKER_STATE_IDLE) {
       /* XXX the circ associated with this cpuworker will wait forever. Oops. */
       num_cpuworkers_busy--;
@@ -87,17 +82,17 @@ int connection_cpu_process_inbuf(connection_t *conn) {
       circ = circuit_get_by_aci_conn(aci, p_conn);
 
     if(!circ) {
-      log_fn(LOG_DEBUG,"processed onion for a circ that's gone. Dropping.");
+      log_fn(LOG_INFO,"processed onion for a circ that's gone. Dropping.");
       goto done_processing;
     }
     assert(circ->p_conn);
     if(*buf == 0) {
-      log_fn(LOG_DEBUG,"decoding onionskin failed. Closing.");
+      log_fn(LOG_WARNING,"decoding onionskin failed. Closing.");
       circuit_close(circ);
       goto done_processing;
     }
     if(onionskin_answer(circ, buf+1+TAG_LEN, buf+1+TAG_LEN+DH_KEY_LEN) < 0) {
-      log_fn(LOG_DEBUG,"onionskin_answer failed. Closing.");
+      log_fn(LOG_WARNING,"onionskin_answer failed. Closing.");
       circuit_close(circ);
       goto done_processing;
     }
@@ -131,18 +126,18 @@ int cpuworker_main(void *data) {
   for(;;) {
 
     if(read(fd, &question_type, 1) != 1) {
-      log_fn(LOG_INFO,"read type failed. Exiting.");
+      log_fn(LOG_ERR,"read type failed. Exiting.");
       spawn_exit();
     }
     assert(question_type == CPUWORKER_TASK_ONION);
 
     if(read_all(fd, tag, TAG_LEN) != TAG_LEN) {
-      log_fn(LOG_INFO,"read tag failed. Exiting.");
+      log_fn(LOG_ERR,"read tag failed. Exiting.");
       spawn_exit();
     }
 
     if(read_all(fd, question, DH_ONIONSKIN_LEN) != DH_ONIONSKIN_LEN) {
-      log_fn(LOG_INFO,"read question failed. Exiting.");
+      log_fn(LOG_ERR,"read question failed. Exiting.");
       spawn_exit();
     }
 
@@ -150,18 +145,18 @@ int cpuworker_main(void *data) {
       if(onion_skin_server_handshake(question, get_onion_key(),
         reply_to_proxy, keys, 32) < 0) {
         /* failure */
-        log_fn(LOG_ERR,"onion_skin_server_handshake failed.");
+        log_fn(LOG_WARNING,"onion_skin_server_handshake failed.");
         memset(buf,0,LEN_ONION_RESPONSE); /* send all zeros for failure */
       } else {
         /* success */
-        log_fn(LOG_DEBUG,"onion_skin_server_handshake succeeded.");
+        log_fn(LOG_INFO,"onion_skin_server_handshake succeeded.");
         buf[0] = 1; /* 1 means success */
         memcpy(buf+1,tag,TAG_LEN);
         memcpy(buf+1+TAG_LEN,reply_to_proxy,DH_KEY_LEN);
         memcpy(buf+1+TAG_LEN+DH_KEY_LEN,keys,32);
       }
       if(write_all(fd, buf, LEN_ONION_RESPONSE) != LEN_ONION_RESPONSE) {
-        log_fn(LOG_INFO,"writing response buf failed. Exiting.");
+        log_fn(LOG_ERR,"writing response buf failed. Exiting.");
         spawn_exit();
       }
       log_fn(LOG_DEBUG,"finished writing response.");
@@ -198,7 +193,7 @@ static int spawn_cpuworker(void) {
   conn->address = strdup("localhost");
 
   if(connection_add(conn) < 0) { /* no space, forget it */
-    log_fn(LOG_INFO,"connection_add failed. Giving up.");
+    log_fn(LOG_WARNING,"connection_add failed. Giving up.");
     connection_free(conn); /* this closes fd[0] */
     return -1;
   }
@@ -219,7 +214,7 @@ static void spawn_enough_cpuworkers(void) {
 
   while(num_cpuworkers < num_cpuworkers_needed) {
     if(spawn_cpuworker() < 0) {
-      log_fn(LOG_ERR,"spawn failed!");
+      log_fn(LOG_WARNING,"spawn failed!");
       return;
     }
     num_cpuworkers++;
@@ -238,7 +233,7 @@ static void process_pending_task(connection_t *cpuworker) {
   if(!circ)
     return;
   if(assign_to_cpuworker(cpuworker, CPUWORKER_TASK_ONION, circ) < 0)
-    log_fn(LOG_DEBUG,"assign_to_cpuworker failed. Ignoring.");
+    log_fn(LOG_WARNING,"assign_to_cpuworker failed. Ignoring.");
 }
 
 /* if cpuworker is defined, assert that he's idle, and use him. else,
@@ -270,7 +265,7 @@ int assign_to_cpuworker(connection_t *cpuworker, unsigned char question_type,
     assert(cpuworker);
 
     if(!circ->p_conn) {
-      log_fn(LOG_DEBUG,"circ->p_conn gone. Failing circ.");
+      log_fn(LOG_INFO,"circ->p_conn gone. Failing circ.");
       return -1;
     }
     tag_pack(tag, circ->p_conn->addr, circ->p_conn->port, circ->p_aci);
@@ -281,7 +276,7 @@ int assign_to_cpuworker(connection_t *cpuworker, unsigned char question_type,
     if(connection_write_to_buf(&question_type, 1, cpuworker) < 0 ||
        connection_write_to_buf(tag, sizeof(tag), cpuworker) < 0 ||
        connection_write_to_buf(circ->onionskin, DH_ONIONSKIN_LEN, cpuworker) < 0) {
-      log_fn(LOG_NOTICE,"Write failed. Closing worker and failing circ.");
+      log_fn(LOG_WARNING,"Write failed. Closing worker and failing circ.");
       cpuworker->marked_for_close = 1;
       return -1;
     }

src/or/directory.c

@@ -55,8 +55,9 @@ void directory_initiate_command(routerinfo_t *router, int command) {
   if (router->identity_pkey)
     conn->identity_pkey = crypto_pk_dup_key(router->identity_pkey);
   else {
-    log_fn(LOG_ERR, "No signing key known for dirserver %s; signature won't be checked", conn->address);
+    log_fn(LOG_WARNING, "No signing key known for dirserver %s; signature won't be checked", conn->address);
     conn->identity_pkey = NULL;
+    /* XXX is there really any situation where router doesn't have an identity_pkey? */
   }
 
   if(connection_add(conn) < 0) { /* no space, forget it */
@@ -95,7 +96,7 @@ static int directory_send_command(connection_t *conn, int command) {
   switch(command) {
     case DIR_CONN_STATE_CONNECTING_FETCH:
       if(connection_write_to_buf(fetchstring, strlen(fetchstring), conn) < 0) {
-        log_fn(LOG_DEBUG,"Couldn't write fetch to buffer.");
+        log_fn(LOG_WARNING,"Couldn't write fetch to buffer.");
         return -1;
       }
       conn->state = DIR_CONN_STATE_CLIENT_SENDING_FETCH;
@@ -103,13 +104,13 @@ static int directory_send_command(connection_t *conn, int command) {
     case DIR_CONN_STATE_CONNECTING_UPLOAD:
       s = router_get_my_descriptor();
       if(!s) {
-        log_fn(LOG_DEBUG,"Failed to get my descriptor.");
+        log_fn(LOG_WARNING,"Failed to get my descriptor.");
         return -1;
       }
       snprintf(tmp, sizeof(tmp), "POST / HTTP/1.0\r\nContent-Length: %d\r\n\r\n%s",
                strlen(s), s);
       if(connection_write_to_buf(tmp, strlen(tmp), conn) < 0) {
-        log_fn(LOG_DEBUG,"Couldn't write post/descriptor to buffer.");
+        log_fn(LOG_WARNING,"Couldn't write post/descriptor to buffer.");
         return -1;
       }
       conn->state = DIR_CONN_STATE_CLIENT_SENDING_UPLOAD;
@@ -126,7 +127,7 @@ static void directory_rebuild(void) {
   if(directory_dirty) {
     if (dump_signed_directory_to_string(the_directory, MAX_DIR_SIZE,
                                         get_identity_key())) {
-      log(LOG_ERR, "Error writing directory");
+      log(LOG_WARNING, "Error creating directory");
       return;
     }
     directorylen = strlen(the_directory);
@@ -148,24 +149,24 @@ int connection_dir_process_inbuf(connection_t *conn) {
         switch(fetch_from_buf_http(conn->inbuf,
                                    NULL, 0, the_directory, MAX_DIR_SIZE)) {
           case -1: /* overflow */
-            log_fn(LOG_DEBUG,"'fetch' response too large. Failing.");
+            log_fn(LOG_WARNING,"'fetch' response too large. Failing.");
             return -1;
           case 0:
-            log_fn(LOG_DEBUG,"'fetch' response not all here, but we're at eof. Closing.");
+            log_fn(LOG_INFO,"'fetch' response not all here, but we're at eof. Closing.");
             return -1;
           /* case 1, fall through */
         }
         /* XXX check headers, at least make sure returned 2xx */
         directorylen = strlen(the_directory);
-        log_fn(LOG_DEBUG,"Received directory (size %d):\n%s", directorylen, the_directory);
+        log_fn(LOG_INFO,"Received directory (size %d):\n%s", directorylen, the_directory);
         if(directorylen == 0) {
-          log_fn(LOG_DEBUG,"Empty directory. Ignoring.");
+          log_fn(LOG_INFO,"Empty directory. Ignoring.");
           return -1;
         }
         if(router_get_dir_from_string(the_directory, conn->identity_pkey) < 0){
-          log_fn(LOG_DEBUG,"...but parsing failed. Ignoring.");
+          log_fn(LOG_INFO,"...but parsing failed. Ignoring.");
         } else {
-          log_fn(LOG_DEBUG,"and got an %s directory; updated routers.", 
+          log_fn(LOG_INFO,"and got an %s directory; updated routers.", 
               conn->identity_pkey ? "authenticated" : "unauthenticated");
         }
         if(options.OnionRouter) { /* connect to them all */
@@ -174,10 +175,10 @@ int connection_dir_process_inbuf(connection_t *conn) {
         return -1;
       case DIR_CONN_STATE_CLIENT_READING_UPLOAD:
         /* XXX make sure there's a 200 OK on the buffer */
-        log_fn(LOG_DEBUG,"eof while reading upload response. Finished.");
+        log_fn(LOG_INFO,"eof while reading upload response. Finished.");
         return -1;
       default:
-        log_fn(LOG_DEBUG,"conn reached eof, not reading. Closing.");
+        log_fn(LOG_INFO,"conn reached eof, not reading. Closing.");
         return -1;
     }
   }
@@ -200,7 +201,7 @@ static int directory_handle_command(connection_t *conn) {
   switch(fetch_from_buf_http(conn->inbuf,
                              headers, sizeof(headers), body, sizeof(body))) {
     case -1: /* overflow */
-      log_fn(LOG_DEBUG,"input too large. Failing.");
+      log_fn(LOG_WARNING,"input too large. Failing.");
       return -1;
     case 0:
       log_fn(LOG_DEBUG,"command not all here yet.");
@@ -215,14 +216,14 @@ static int directory_handle_command(connection_t *conn) {
     directory_rebuild(); /* rebuild it now, iff it's dirty */
 
     if(directorylen == 0) {
-      log_fn(LOG_DEBUG,"My directory is empty. Closing.");
+      log_fn(LOG_WARNING,"My directory is empty. Closing.");
       return -1;
     }
 
     log_fn(LOG_DEBUG,"Dumping directory to client."); 
     if((connection_write_to_buf(answerstring, strlen(answerstring), conn) < 0) ||
        (connection_write_to_buf(the_directory, directorylen, conn) < 0)) {
-      log_fn(LOG_DEBUG,"Failed to write answerstring+directory to outbuf.");
+      log_fn(LOG_WARNING,"Failed to write answerstring+directory to outbuf.");
       return -1;
     }
     conn->state = DIR_CONN_STATE_SERVER_WRITING;
@@ -233,14 +234,14 @@ static int directory_handle_command(connection_t *conn) {
     /* XXX should check url and http version */
     log_fn(LOG_DEBUG,"Received POST command, body '%s'", body);
     if(connection_write_to_buf(answerstring, strlen(answerstring), conn) < 0) {
-      log_fn(LOG_DEBUG,"Failed to write answerstring to outbuf.");
+      log_fn(LOG_WARNING,"Failed to write answerstring to outbuf.");
       return -1;
     }
     conn->state = DIR_CONN_STATE_SERVER_WRITING;
     return 0;
   }
 
-  log_fn(LOG_DEBUG,"Got headers with unknown command. Closing.");
+  log_fn(LOG_WARNING,"Got headers with unknown command. Closing.");
   return -1;
 }
 
@@ -263,7 +264,7 @@ int connection_dir_finished_flushing(connection_t *conn) {
       }
       /* the connect has finished. */
 
-      log_fn(LOG_DEBUG,"Dir connection to router %s:%u established.",
+      log_fn(LOG_INFO,"Dir connection to router %s:%u established.",
           conn->address,conn->port);
 
       return directory_send_command(conn, conn->state);
@@ -278,13 +279,12 @@ int connection_dir_finished_flushing(connection_t *conn) {
       connection_watch_events(conn, POLLIN);
       return 0;
     case DIR_CONN_STATE_SERVER_WRITING:
-      log_fn(LOG_DEBUG,"Finished writing server response. Closing.");
+      log_fn(LOG_INFO,"Finished writing server response. Closing.");
       return -1; /* kill it */
     default:
-      log_fn(LOG_DEBUG,"BUG: called in unexpected state.");
-      return 0;
+      log_fn(LOG_WARNING,"BUG: called in unexpected state.");
+      return -1;
   }
-
   return 0;
 }
 

src/or/dns.c

@@ -160,7 +160,7 @@ static int assign_to_dnsworker(connection_t *exitconn) {
   dnsconn = connection_get_by_type_state(CONN_TYPE_DNSWORKER, DNSWORKER_STATE_IDLE);
 
   if(!dnsconn) {
-    log_fn(LOG_INFO,"no idle dns workers. Failing.");
+    log_fn(LOG_WARNING,"no idle dns workers. Failing.");
     dns_cancel_pending_resolve(exitconn->address, NULL);
     return -1;
   }
@@ -173,7 +173,7 @@ static int assign_to_dnsworker(connection_t *exitconn) {
   /* FFFF we should have it retry if the first worker bombs out */
   if(connection_write_to_buf(&len, 1, dnsconn) < 0 ||
      connection_write_to_buf(dnsconn->address, len, dnsconn) < 0) {
-    log_fn(LOG_NOTICE,"Write failed. Closing worker and failing resolve.");
+    log_fn(LOG_WARNING,"Write failed. Closing worker and failing resolve.");
     dnsconn->marked_for_close = 1;
     dns_cancel_pending_resolve(exitconn->address, NULL);
     return -1;
@@ -196,7 +196,7 @@ void dns_cancel_pending_resolve(char *question, connection_t *onlyconn) {
 
   resolve = SPLAY_FIND(cache_tree, &cache_root, &search);
   if(!resolve) {
-    log_fn(LOG_INFO,"Answer to unasked question '%s'? Dropping.", question);
+    log_fn(LOG_WARNING,"Question '%s' is not pending. Dropping.", question);
     return;
   }
 
@@ -261,7 +261,7 @@ static void dns_found_answer(char *question, uint32_t answer) {
 
   resolve = SPLAY_FIND(cache_tree, &cache_root, &search);
   if(!resolve) {
-    log_fn(LOG_INFO,"Answer to unasked question '%s'? Dropping.", question);
+    log_fn(LOG_WARNING,"Answer to unasked question '%s'? Dropping.", question);
     return;
   }
 
@@ -299,7 +299,7 @@ int connection_dns_process_inbuf(connection_t *conn) {
   assert(conn && conn->type == CONN_TYPE_DNSWORKER);
 
   if(conn->inbuf_reached_eof) {
-    log(LOG_ERR,"connection_dnsworker_process_inbuf(): Read eof. Worker dying.");
+    log_fn(LOG_WARNING,"Read eof. Worker dying.");
     if(conn->state == DNSWORKER_STATE_BUSY) {
       dns_cancel_pending_resolve(conn->address, NULL);
       num_dnsworkers_busy--;
@@ -338,31 +338,31 @@ int dnsworker_main(void *data) {
   for(;;) {
 
     if(read(fd, &question_len, 1) != 1) {
-      log(LOG_INFO,"dnsworker_main(): read length failed. Exiting.");
+      log_fn(LOG_ERR,"read length failed. Child exiting.");
       spawn_exit();
     }
     assert(question_len > 0);
 
     if(read_all(fd, question, question_len) != question_len) {
-      log(LOG_INFO,"dnsworker_main(): read hostname failed. Exiting.");
+      log_fn(LOG_ERR,"read hostname failed. Child exiting.");
       spawn_exit();
     }
     question[question_len] = 0; /* null terminate it */
 
     rent = gethostbyname(question);
     if (!rent) {
-      log(LOG_INFO,"dnsworker_main(): Could not resolve dest addr %s. Returning nulls.",question);
+      log_fn(LOG_INFO,"Could not resolve dest addr %s. Returning nulls.",question);
       if(write_all(fd, "\0\0\0\0", 4) != 4) {
-        log(LOG_INFO,"dnsworker_main(): writing nulls failed. Exiting.");
+        log_fn(LOG_ERR,"writing nulls failed. Child exiting.");
         spawn_exit();
       }
     } else {
       assert(rent->h_length == 4); /* break to remind us if we move away from ipv4 */
       if(write_all(fd, rent->h_addr, 4) != 4) {
-        log(LOG_INFO,"dnsworker_main(): writing answer failed. Exiting.");
+        log_fn(LOG_INFO,"writing answer failed. Child exiting.");
         spawn_exit();
       }
-      log(LOG_INFO,"dnsworker_main(): Answered question '%s'.",question);
+      log_fn(LOG_INFO,"Answered question '%s'.",question);
     }
   }
   return 0; /* windows wants this function to return an int */
@@ -396,7 +396,7 @@ static int spawn_dnsworker(void) {
   conn->address = strdup("localhost");
 
   if(connection_add(conn) < 0) { /* no space, forget it */
-    log_fn(LOG_INFO,"connection_add failed. Giving up.");
+    log_fn(LOG_WARNING,"connection_add failed. Giving up.");
     connection_free(conn); /* this closes fd[0] */
     return -1;
   }
@@ -433,7 +433,7 @@ static void spawn_enough_dnsworkers(void) {
 
   while(num_dnsworkers < num_dnsworkers_needed) {
     if(spawn_dnsworker() < 0) {
-      log(LOG_ERR,"spawn_enough_dnsworkers(): spawn failed!");
+      log(LOG_WARNING,"spawn_enough_dnsworkers(): spawn failed!");
       return;
     }
     num_dnsworkers++;

src/or/main.c

@@ -79,7 +79,7 @@ crypto_pk_env_t *get_identity_key(void) {
 int connection_add(connection_t *conn) {
 
   if(nfds >= options.MaxConn-1) {
-    log(LOG_INFO,"connection_add(): failing because nfds is too high.");
+    log(LOG_WARNING,"connection_add(): failing because nfds is too high.");
     return -1;
   }
   
@@ -302,7 +302,7 @@ static void conn_write(int i) {
   assert_connection_ok(conn, time(NULL));
 
   if(connection_handle_write(conn) < 0) { /* this connection is broken. remove it. */
-    log_fn(LOG_DEBUG,"%s connection broken, removing.", conn_type_to_string[conn->type]);
+    log_fn(LOG_INFO,"%s connection broken, removing.", conn_type_to_string[conn->type]);
     connection_remove(conn);
     connection_free(conn);
     if(i<nfds) { /* we just replaced the one at i with a new one. process it too. */
@@ -317,7 +317,7 @@ static void check_conn_marked(int i) {
   conn = connection_array[i];
   assert_connection_ok(conn, time(NULL));
   if(conn->marked_for_close) {
-    log_fn(LOG_DEBUG,"Cleaning up connection.");
+    log_fn(LOG_INFO,"Cleaning up connection (fd %d).",conn->s);
     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? */
       if(connection_speaks_cells(conn)) {
@@ -407,7 +407,7 @@ static int prepare_for_poll(void) {
         if((!options.OnionRouter && !circuit_get_by_conn(conn)) ||
            (!connection_state_is_open(conn))) {
           /* we're an onion proxy, with no circuits; or our handshake has expired. kill it. */
-          log_fn(LOG_DEBUG,"Expiring connection to %d (%s:%d).",
+          log_fn(LOG_INFO,"Expiring connection to %d (%s:%d).",
               i,conn->address, conn->port);
           conn->marked_for_close = 1;
         } else {
@@ -667,7 +667,7 @@ static int do_main_loop(void) {
       /* fetch a new directory */
       if(options.DirPort) {
         if(router_get_list_from_file(options.RouterFile) < 0) {
-          log(LOG_ERR,"Error reloading router list. Continuing with old list.");
+          log(LOG_WARNING,"Error reloading router list. Continuing with old list.");
         }
       } else {
         directory_initiate_command(router_pick_directory_server(), DIR_CONN_STATE_CONNECTING_FETCH);
@@ -723,7 +723,7 @@ static void catch(int the_signal) {
 //    case SIGABRT:
     case SIGTERM:
     case SIGINT:
-      log(LOG_NOTICE,"Catching signal %d, exiting cleanly.", the_signal);
+      log(LOG_ERR,"Catching signal %d, exiting cleanly.", the_signal);
       exit(0);
     case SIGHUP:
       please_reset = 1;
@@ -735,7 +735,7 @@ static void catch(int the_signal) {
       please_reap_children = 1;
       break;
     default:
-      log(LOG_ERR,"Caught signal %d that we can't handle??", the_signal);
+      log(LOG_WARNING,"Caught signal %d that we can't handle??", the_signal);
   }
 #endif /* signal stuff */
 }
@@ -781,19 +781,19 @@ int dump_router_to_string(char *s, int maxlen, routerinfo_t *router,
 
   if(crypto_pk_write_public_key_to_string(router->onion_pkey,
                                           &onion_pkey,&onion_pkeylen)<0) {
-    log_fn(LOG_ERR,"write onion_pkey to string failed!");
+    log_fn(LOG_WARNING,"write onion_pkey to string failed!");
     return -1;
   }
 
   if(crypto_pk_write_public_key_to_string(router->identity_pkey,
                                           &identity_pkey,&identity_pkeylen)<0) {
-    log_fn(LOG_ERR,"write identity_pkey to string failed!");
+    log_fn(LOG_WARNING,"write identity_pkey to string failed!");
     return -1;
   }
 
   if(crypto_pk_write_public_key_to_string(router->link_pkey,
                                           &link_pkey,&link_pkeylen)<0) {
-    log_fn(LOG_ERR,"write link_pkey to string failed!");
+    log_fn(LOG_WARNING,"write link_pkey to string failed!");
     return -1;
   }
   
@@ -812,7 +812,7 @@ int dump_router_to_string(char *s, int maxlen, routerinfo_t *router,
   free(link_pkey);
   free(identity_pkey);
 
-  if(result < 0 || result > maxlen) {
+  if(result < 0 || result >= maxlen) {
     /* apparently different glibcs do different things on snprintf error.. so check both */
     return -1;
   }
@@ -838,13 +838,14 @@ int dump_router_to_string(char *s, int maxlen, routerinfo_t *router,
     return -1;
 
   if (crypto_pk_private_sign(ident_key, digest, 20, signature) < 0) {
-    log_fn(LOG_ERR, "Error signing digest");
+    log_fn(LOG_WARNING, "Error signing digest");
     return -1;
   }
   strcat(s+written, "-----BEGIN SIGNATURE-----\n");
   written += strlen(s+written);
   if (base64_encode(s+written, maxlen-written, signature, 128) < 0) {
-    log_fn(LOG_ERR, "Couldn't base64-encode signature");
+    log_fn(LOG_WARNING, "Couldn't base64-encode signature");
+    /* XXX Nick: do we really mean to fall through here? */
   }
   written += strlen(s+written);
   strcat(s+written, "-----END SIGNATURE-----\n");
@@ -881,7 +882,7 @@ build_directory(directory_t *dir) {
     router = router_get_by_addr_port(conn->addr,conn->port);
     if(!router) {
       /* XXX this legitimately happens when conn is an OP. How to detect this? */
-      log(LOG_ERR,"build_directory(): couldn't find router %d:%d!",
+      log(LOG_INFO,"build_directory(): couldn't find router %d:%d!",
           conn->addr,conn->port);
       continue;
     }
@@ -900,7 +901,7 @@ dump_signed_directory_to_string(char *s, int maxlen,
 {
   directory_t dir;
   if (build_directory(&dir)) {
-    log(LOG_ERR,"dump_signed_directory_to_string(): build_directory failed.");
+    log(LOG_WARNING,"dump_signed_directory_to_string(): build_directory failed.");
     return -1;
   }
   return dump_signed_directory_to_string_impl(s, maxlen, &dir, private_key);
@@ -933,7 +934,7 @@ dump_signed_directory_to_string_impl(char *s, int maxlen, directory_t *dir,
     written = dump_router_to_string(cp, eos-cp, router, private_key);
 
     if(written < 0) { 
-      log(LOG_ERR,"dump_signed_directory_to_string(): tried to exceed string length.");
+      log(LOG_WARNING,"dump_signed_directory_to_string(): tried to exceed string length.");
       cp[maxlen-1] = 0; /* make sure it's null terminated */
       free(dir->routers);
       return -1;
@@ -951,11 +952,11 @@ dump_signed_directory_to_string_impl(char *s, int maxlen, directory_t *dir,
   cp = s + i;
   
   if (crypto_SHA_digest(s, i, digest)) {
-    log(LOG_ERR,"dump_signed_directory_to_string(): couldn't compute digest");
+    log(LOG_WARNING,"dump_signed_directory_to_string(): couldn't compute digest");
     return -1;
   }
   if (crypto_pk_private_sign(private_key, digest, 20, signature) < 0) {
-    log(LOG_ERR,"dump_signed_directory_to_string(): couldn't sign digest");
+    log(LOG_WARNING,"dump_signed_directory_to_string(): couldn't sign digest");
     return -1;
   }
   
@@ -965,7 +966,7 @@ dump_signed_directory_to_string_impl(char *s, int maxlen, directory_t *dir,
   i = strlen(s);
   cp = s+i;
   if (base64_encode(cp, maxlen-i, signature, 128) < 0) {
-    log_fn(LOG_ERR," couldn't base64-encode signature");
+    log_fn(LOG_WARNING," couldn't base64-encode signature");
     return -1;
   }
 
@@ -974,7 +975,7 @@ dump_signed_directory_to_string_impl(char *s, int maxlen, directory_t *dir,
   strncat(cp, "-----END SIGNATURE-----\n", maxlen-i);
   i = strlen(s);
   if (i == maxlen) {
-    log(LOG_ERR,"dump_signed_directory_to_string(): tried to exceed string length.");
+    log(LOG_WARNING,"dump_signed_directory_to_string(): tried to exceed string length.");
     return -1;
   }
 
@@ -994,7 +995,7 @@ static int init_descriptor(void) {
   char localhostname[256];
 
   if(gethostname(localhostname,sizeof(localhostname)) < 0) {
-    log_fn(LOG_ERR,"Error obtaining local hostname");
+    log_fn(LOG_WARNING,"Error obtaining local hostname");
     return -1;
   }
   ri = tor_malloc(sizeof(routerinfo_t));
@@ -1013,7 +1014,7 @@ static int init_descriptor(void) {
     routerinfo_free(desc_routerinfo);
   desc_routerinfo = ri;
   if (dump_router_to_string(descriptor, 8192, ri, get_identity_key())<0) {
-    log_fn(LOG_ERR, "Couldn't dump router to string.");
+    log_fn(LOG_WARNING, "Couldn't dump router to string.");
     return -1;
   }
   return 0;

src/or/onion.c

@@ -51,7 +51,7 @@ int onion_pending_add(circuit_t *circ) {
   assert(!ol_tail->next);
 
   if(ol_length >= options.MaxOnionsPending) {
-    log_fn(LOG_INFO,"Already have %d onions queued. Closing.", ol_length);
+    log_fn(LOG_WARNING,"Already have %d onions queued. Closing.", ol_length);
     free(tmp);
     return -1;
   }
@@ -141,13 +141,13 @@ int onionskin_answer(circuit_t *circ, unsigned char *payload, unsigned char *key
 
   if (!(circ->n_crypto =
         crypto_create_init_cipher(CIRCUIT_CIPHER,keys,iv,0))) {
-    log_fn(LOG_ERR,"Cipher initialization failed (n).");
+    log_fn(LOG_WARNING,"Cipher initialization failed (n).");
     return -1;
   }
 
   if (!(circ->p_crypto =
         crypto_create_init_cipher(CIRCUIT_CIPHER,keys+16,iv,1))) {
-    log_fn(LOG_ERR,"Cipher initialization failed (p).");
+    log_fn(LOG_WARNING,"Cipher initialization failed (p).");
     return -1;
   }
 
@@ -195,25 +195,25 @@ static unsigned int *new_route(double cw, routerinfo_t **rarray, int rarray_len,
 
   *routelen = chooselen(cw);
   if (*routelen == -1) {
-    log(LOG_ERR,"Choosing route length failed.");
+    log_fn(LOG_WARNING,"Choosing route length failed.");
     return NULL;
   }
-  log(LOG_DEBUG,"new_route(): Chosen route length %d.",*routelen);
+  log_fn(LOG_DEBUG,"Chosen route length %d.",*routelen);
 
   num_acceptable_routers = count_acceptable_routers(rarray, rarray_len);
 
   if(num_acceptable_routers < 2) {
-    log(LOG_INFO,"new_route(): Not enough acceptable routers. Failing.");
+    log_fn(LOG_INFO,"Not enough acceptable routers. Failing.");
     return NULL;
   }
 
   if(num_acceptable_routers < *routelen) {
-    log(LOG_NOTICE,"new_route(): Cutting routelen from %d to %d.",*routelen, num_acceptable_routers);
+    log_fn(LOG_INFO,"Not enough routers: cutting routelen from %d to %d.",*routelen, num_acceptable_routers);
     *routelen = num_acceptable_routers;
   }
 
   if(*routelen < 1) {
-    log(LOG_ERR,"new_route(): Didn't find any acceptable routers. Failing.");
+    log_fn(LOG_WARNING,"Didn't find any acceptable routers. Failing.");
     return NULL;
   }
 
@@ -229,18 +229,18 @@ static unsigned int *new_route(double cw, routerinfo_t **rarray, int rarray_len,
     }
 
     choice = choice % rarray_len;
-    log(LOG_DEBUG,"new_route(): Contemplating router %u.",choice);
+    log_fn(LOG_DEBUG,"Contemplating router %u.",choice);
     if(choice == oldchoice ||
        (oldchoice < rarray_len && !crypto_pk_cmp_keys(rarray[choice]->onion_pkey, rarray[oldchoice]->onion_pkey)) ||
       (options.OnionRouter && !connection_twin_get_by_addr_port(rarray[choice]->addr, rarray[choice]->or_port))) {
       /* Same router as last choice, or router twin,
        *   or no routers with that key are connected to us.
        * Try again. */
-      log(LOG_DEBUG,"new_route(): Picked a router %d that won't work as next hop.",choice);
+      log_fn(LOG_DEBUG,"Picked a router %d that won't work as next hop.",choice);
       i--;
       continue;  
     }
-    log(LOG_DEBUG,"new_route(): Chosen router %u for hop %u.",choice,i);
+    log_fn(LOG_DEBUG,"Chosen router %u for hop %u.",choice,i);
     oldchoice = choice;
     route[i] = choice;
   }
@@ -254,23 +254,23 @@ static int count_acceptable_routers(routerinfo_t **rarray, int rarray_len) {
   connection_t *conn;
 
   for(i=0;i<rarray_len;i++) {
-    log(LOG_DEBUG,"Contemplating whether router %d is a new option...",i);
+    log_fn(LOG_DEBUG,"Contemplating whether router %d is a new option...",i);
     if(options.OnionRouter) {
       conn = connection_exact_get_by_addr_port(rarray[i]->addr, rarray[i]->or_port);
       if(!conn || conn->type != CONN_TYPE_OR || conn->state != OR_CONN_STATE_OPEN) {
-        log(LOG_DEBUG,"Nope, %d is not connected.",i);
+        log_fn(LOG_DEBUG,"Nope, %d is not connected.",i);
         goto next_i_loop;
       }
     }
     for(j=0;j<i;j++) {
       if(!crypto_pk_cmp_keys(rarray[i]->onion_pkey, rarray[j]->onion_pkey)) {
         /* these guys are twins. so we've already counted him. */
-        log(LOG_DEBUG,"Nope, %d is a twin of %d.",i,j);
+        log_fn(LOG_DEBUG,"Nope, %d is a twin of %d.",i,j);
         goto next_i_loop;
       }
     }
     num++;
-    log(LOG_DEBUG,"I like %d. num_acceptable_routers now %d.",i, num);
+    log_fn(LOG_DEBUG,"I like %d. num_acceptable_routers now %d.",i, num);
     next_i_loop:
       ; /* our compiler may need an explicit statement after the label */
   }
@@ -297,10 +297,10 @@ crypt_path_t *onion_generate_cpath(routerinfo_t **firsthop) {
   /* choose a route */
   route = new_route(options.CoinWeight, rarray, rarray_len, &routelen);
   if (!route) {
-    log(LOG_ERR,"onion_generate_cpath(): Error choosing a route through the OR network.");
+    log_fn(LOG_INFO,"Error choosing a route through the OR network.");
     return NULL;
   }
-  log(LOG_DEBUG,"onion_generate_cpath(): Chosen a route of length %u: ",routelen);
+  log_fn(LOG_DEBUG,"Chosen a route of length %u: ",routelen);
 
   *firsthop = rarray[route[routelen-1]];
   assert(*firsthop); /* should always be defined */
@@ -308,7 +308,7 @@ crypt_path_t *onion_generate_cpath(routerinfo_t **firsthop) {
   for(i=0; i<routelen; i++) {
     netaddr.s_addr = htonl((rarray[route[i]])->addr);
 
-    log(LOG_DEBUG,"onion_generate_cpath(): %u : %s:%u, %u/%u",routelen-i,
+    log_fn(LOG_DEBUG,"%u : %s:%u, %u/%u",routelen-i,
         inet_ntoa(netaddr),
         (rarray[route[i]])->or_port,
         (int) (rarray[route[i]])->onion_pkey,
@@ -338,7 +338,7 @@ crypt_path_t *onion_generate_cpath(routerinfo_t **firsthop) {
     hop->package_window = CIRCWINDOW_START;
     hop->deliver_window = CIRCWINDOW_START;
 
-    log(LOG_DEBUG,"onion_generate_cpath() : Building hop %u of crypt path.",i+1);
+    log_fn(LOG_DEBUG,"Building hop %u of crypt path.",i+1);
   }
 
   /* now link cpath->prev to the end of cpath */

src/or/or.h

@@ -7,8 +7,6 @@
 
 #include "orconfig.h"
 
-#define SEQUENTIAL_ACI
-
 #include <stdio.h>
 #include <stdlib.h>
 #include <limits.h>
@@ -291,10 +289,8 @@ struct connection_t {
 
 /* Used only by OR connections: */
   tor_tls *tls;
-#ifdef SEQUENTIAL_ACI
   uint16_t next_aci; /* Which ACI do we try to use next on this connection? 
                       * This is always in the range 0..1<<15-1.*/
-#endif
 
 /* Used only by edge connections: */
   char stream_id[STREAM_ID_SIZE];

src/or/routers.c

@@ -45,13 +45,14 @@ int learn_my_address(struct sockaddr_in *me) {
   if(!already_learned) {
     /* obtain local host information */
     if(gethostname(localhostname,sizeof(localhostname)) < 0) {
-      log_fn(LOG_ERR,"Error obtaining local hostname");
+      log_fn(LOG_WARNING,"Error obtaining local hostname");
       return -1;
     }
     log_fn(LOG_DEBUG,"localhostname is '%s'.",localhostname);
     localhost = gethostbyname(localhostname);
     if (!localhost) {
-      log_fn(LOG_ERR,"Error obtaining local host info.");
+      log_fn(LOG_WARNING,"Error obtaining local host info.");
+      /* XXX maybe this is worse than warning? bad things happen when we don't know ourselves */
       return -1;
     }
     memset(&answer,0,sizeof(struct sockaddr_in));
@@ -184,6 +185,7 @@ int router_is_me(uint32_t addr, uint16_t port)
  
   if(learn_my_address(&me) < 0)
     return -1;
+    /* XXX people call this function like a boolean. that's bad news: -1 is true. */
 
   if(ntohl(me.sin_addr.s_addr) == addr && ntohs(me.sin_port) == port)
     return 1;
@@ -265,26 +267,26 @@ int router_get_list_from_file(char *routerfile)
   assert(routerfile);
   
   if (strcspn(routerfile,CONFIG_LEGAL_FILENAME_CHARACTERS) != 0) {
-    log_fn(LOG_ERR,"Filename %s contains illegal characters.",routerfile);
+    log_fn(LOG_WARNING,"Filename %s contains illegal characters.",routerfile);
     return -1;
   }
   
   if(stat(routerfile, &statbuf) < 0) {
-    log_fn(LOG_ERR,"Could not stat %s.",routerfile);
+    log_fn(LOG_WARNING,"Could not stat %s.",routerfile);
     return -1;
   }
 
   /* open the router list */
   fd = open(routerfile,O_RDONLY,0);
   if (fd<0) {
-    log_fn(LOG_ERR,"Could not open %s.",routerfile);
+    log_fn(LOG_WARNING,"Could not open %s.",routerfile);
     return -1;
   }
 
   string = tor_malloc(statbuf.st_size+1);
 
   if(read(fd,string,statbuf.st_size) != statbuf.st_size) {
-    log_fn(LOG_ERR,"Couldn't read all %ld bytes of file '%s'.",
+    log_fn(LOG_WARNING,"Couldn't read all %ld bytes of file '%s'.",
            (long)statbuf.st_size,routerfile);
     free(string);
     close(fd);
@@ -295,7 +297,7 @@ int router_get_list_from_file(char *routerfile)
   string[statbuf.st_size] = 0; /* null terminate it */
 
   if(router_get_list_from_string(string) < 0) {
-    log_fn(LOG_ERR,"The routerfile itself was corrupt.");
+    log_fn(LOG_WARNING,"The routerfile itself was corrupt.");
     free(string);
     return -1;
   }
@@ -548,11 +550,11 @@ static char *find_whitespace(char *s) {
 int router_get_list_from_string(char *s) 
 {
   if (router_get_list_from_string_impl(&s, &directory)) {
-    log(LOG_ERR, "Error parsing router file");
+    log(LOG_WARNING, "Error parsing router file");
     return -1;
   }
   if (router_resolve_directory(directory)) {
-    log(LOG_ERR, "Error resolving directory");
+    log(LOG_WARNING, "Error resolving directory");
     return -1;
   }
   return 0;
@@ -564,23 +566,23 @@ static int router_get_hash_impl(char *s, char *digest, const char *start_str,
   char *start, *end;
   start = strstr(s, start_str);
   if (!start) {
-    log_fn(LOG_ERR,"couldn't find \"%s\"",start_str);
+    log_fn(LOG_WARNING,"couldn't find \"%s\"",start_str);
     return -1;
   }
   end = strstr(start+strlen(start_str), end_str);
   if (!end) {
-    log_fn(LOG_ERR,"couldn't find \"%s\"",end_str);
+    log_fn(LOG_WARNING,"couldn't find \"%s\"",end_str);
     return -1;
   }
   end = strchr(end, '\n');
   if (!end) {
-    log_fn(LOG_ERR,"couldn't find EOL");
+    log_fn(LOG_WARNING,"couldn't find EOL");
     return -1;
   }
   ++end;
   
   if (crypto_SHA_digest(start, end-start, digest)) {
-    log_fn(LOG_ERR,"couldn't compute digest");
+    log_fn(LOG_WARNING,"couldn't compute digest");
     return -1;
   }
 
@@ -620,19 +622,19 @@ int compare_recommended_versions(char *myversion, char *start) {
 int router_get_dir_from_string(char *s, crypto_pk_env_t *pkey)
 {
   if (router_get_dir_from_string_impl(s, &directory, pkey)) {
-    log(LOG_ERR, "router_get_dir_from_string: Couldn't parse directory.");
+    log_fn(LOG_WARNING, "Couldn't parse directory.");
     return -1;
   }
   if (router_resolve_directory(directory)) {
-    log(LOG_ERR, "Error resolving directory");
+    log_fn(LOG_WARNING, "Error resolving directory");
     return -1;
   }
   if (compare_recommended_versions(VERSION, directory->software_versions) < 0) {
-    log(LOG_ERR, "You are running tor version %s, which is no longer supported.\nPlease upgrade to one of %s.", VERSION, RECOMMENDED_SOFTWARE_VERSIONS);
+    log(LOG_WARNING, "You are running tor version %s, which is no longer supported.\nPlease upgrade to one of %s.", VERSION, RECOMMENDED_SOFTWARE_VERSIONS);
     if(options.IgnoreVersion) {
       log(LOG_WARNING, "IgnoreVersion is set. If it breaks, we told you so.");
     } else {
-      log(LOG_ERR,"Set IgnoreVersion config variable if you want to survive this error.");
+      log(LOG_ERR,"Set IgnoreVersion config variable if you want to proceed.");
       fflush(0);
       exit(0);
     }
@@ -653,19 +655,19 @@ int router_get_dir_from_string_impl(char *s, directory_t **dest,
 #define NEXT_TOK()                                                      \
   do {                                                                  \
     if (router_get_next_token(&s, &tok)) {                              \
-      log(LOG_ERR, "Error reading directory: %s", tok.val.error);       \
+      log_fn(LOG_WARNING, "Error reading directory: %s", tok.val.error);\
       return -1;                                                        \
     } } while (0)
 #define TOK_IS(type,name)                                               \
   do {                                                                  \
     if (tok.tp != type) {                                               \
       router_release_token(&tok);                                       \
-      log(LOG_ERR, "Error reading directory: expected %s", name);       \
+      log_fn(LOG_WARNING, "Error reading directory: expected %s", name);\
       return -1;                                                        \
     } } while(0)
 
   if (router_get_dir_hash(s, digest)) {
-    log(LOG_ERR, "Unable to compute digest of directory");
+    log_fn(LOG_WARNING, "Unable to compute digest of directory");
     goto err;
   }
   NEXT_TOK();
@@ -674,13 +676,13 @@ int router_get_dir_from_string_impl(char *s, directory_t **dest,
   NEXT_TOK();
   TOK_IS(K_RECOMMENDED_SOFTWARE, "recommended-software");
   if (tok.val.cmd.n_args != 1) {
-    log(LOG_ERR, "Invalid recommded-software line");
+    log_fn(LOG_WARNING, "Invalid recommded-software line");
     goto err;
   }
   versions = strdup(tok.val.cmd.args[0]);
   
   if (router_get_list_from_string_impl(&s, &new_dir)) {
-    log(LOG_ERR, "Error reading routers from directory");
+    log_fn(LOG_WARNING, "Error reading routers from directory");
     goto err;
   }
   new_dir->software_versions = versions;
@@ -692,12 +694,12 @@ int router_get_dir_from_string_impl(char *s, directory_t **dest,
   if (pkey) {
     if (crypto_pk_public_checksig(pkey, tok.val.signature, 128, signed_digest)
         != 20) {
-      log(LOG_ERR, "Error reading directory: invalid signature.");
+      log_fn(LOG_WARNING, "Error reading directory: invalid signature.");
       free(tok.val.signature);
       goto err;
     }
     if (memcmp(digest, signed_digest, 20)) {
-      log(LOG_ERR, "Error reading directory: signature does not match.");
+      log_fn(LOG_WARNING, "Error reading directory: signature does not match.");
       free(tok.val.signature);
       goto err;
     }
@@ -737,11 +739,11 @@ int router_get_list_from_string_impl(char **s, directory_t **dest)
       break;
     router = router_get_entry_from_string(s);
     if (!router) {
-      log(LOG_ERR, "Error reading router");
+      log_fn(LOG_WARNING, "Error reading router");
       return -1;
     }
     if (rarray_len >= MAX_ROUTERS_IN_DIR) {
-      log(LOG_ERR, "router_get_list_from_string_tok(): too many routers");
+      log_fn(LOG_WARNING, "too many routers");
       routerinfo_free(router);
       continue;
     } 
@@ -764,7 +766,7 @@ router_resolve(routerinfo_t *router)
 
   rent = (struct hostent *)gethostbyname(router->address);
   if (!rent) {
-    log(LOG_ERR,"router_resolve(): Could not get address for router %s.",router->address);
+    log_fn(LOG_WARNING,"Could not get address for router %s.",router->address);
     return -1; 
   }
   assert(rent->h_length == 4);
@@ -785,8 +787,8 @@ router_resolve_directory(directory_t *dir)
   for (i = 0; i < max; ++i) {
     remove = 0;
     if (router_resolve(dir->routers[i])) {
-      log(LOG_INFO, "Couldn't resolve router %s; removing",
-          dir->routers[i]->address);
+      log_fn(LOG_WARNING, "Couldn't resolve router %s; removing",
+             dir->routers[i]->address);
       remove = 1;
       routerinfo_free(dir->routers[i]);
     } else if (router_is_me(dir->routers[i]->addr, dir->routers[i]->or_port)) {
@@ -818,7 +820,7 @@ routerinfo_t *router_get_entry_from_string(char**s) {
 
 #define NEXT_TOKEN()                                                     \
   do { if (router_get_next_token(s, tok)) {                              \
-      log(LOG_ERR, "Error reading directory: %s", tok->val.error);       \
+      log_fn(LOG_WARNING, "Error reading directory: %s", tok->val.error);\
       goto err;                                                          \
     } } while(0)
 
@@ -831,7 +833,7 @@ routerinfo_t *router_get_entry_from_string(char**s) {
 
   if (tok->tp != K_ROUTER) {
     router_release_token(tok);
-    log(LOG_ERR,"router_get_entry_from_string(): Entry does not start with \"router\"");
+    log_fn(LOG_WARNING,"Entry does not start with \"router\"");
     return NULL;
   }
 
@@ -842,7 +844,7 @@ routerinfo_t *router_get_entry_from_string(char**s) {
   router->onion_pkey = router->identity_pkey = router->link_pkey = NULL; 
 
   if (tok->val.cmd.n_args != 5) {
-    log(LOG_ERR,"router_get_entry_from_string(): Wrong # of arguments to \"router\"");
+    log_fn(LOG_WARNING,"Wrong # of arguments to \"router\"");
     goto err;
   }
 
@@ -854,7 +856,7 @@ routerinfo_t *router_get_entry_from_string(char**s) {
   /* Read router->or_port */
   router->or_port = atoi(ARGS[1]);
   if(!router->or_port) {
-    log(LOG_ERR,"router_get_entry_from_string(): or_port unreadable or 0. Failing.");
+    log_fn(LOG_WARNING,"or_port unreadable or 0. Failing.");
     goto err;
   }
   
@@ -867,39 +869,39 @@ routerinfo_t *router_get_entry_from_string(char**s) {
   /* Router->bandwidth */
   router->bandwidth = atoi(ARGS[4]);
   if (!router->bandwidth) {
-    log(LOG_ERR,"router_get_entry_from_string(): bandwidth unreadable or 0. Failing.");
+    log_fn(LOG_WARNING,"bandwidth unreadable or 0. Failing.");
   }
   
-  log(LOG_DEBUG,"or_port %d, ap_port %d, dir_port %d, bandwidth %d.",
+  log_fn(LOG_DEBUG,"or_port %d, ap_port %d, dir_port %d, bandwidth %d.",
     router->or_port, router->ap_port, router->dir_port, router->bandwidth);
 
   NEXT_TOKEN();
   if (tok->tp != K_ONION_KEY) {
-    log_fn(LOG_ERR, "Missing onion-key"); goto err;
+    log_fn(LOG_WARNING, "Missing onion-key"); goto err;
   }
   NEXT_TOKEN();
   if (tok->tp != _PUBLIC_KEY) {
-    log_fn(LOG_ERR, "Missing onion key"); goto err;
+    log_fn(LOG_WARNING, "Missing onion key"); goto err;
   } /* XXX Check key length */
   router->onion_pkey = tok->val.public_key;
 
   NEXT_TOKEN();
   if (tok->tp != K_LINK_KEY) {
-    log_fn(LOG_ERR, "Missing link-key");  goto err;
+    log_fn(LOG_WARNING, "Missing link-key");  goto err;
   }
   NEXT_TOKEN();
   if (tok->tp != _PUBLIC_KEY) {
-    log_fn(LOG_ERR, "Missing link key"); goto err;
+    log_fn(LOG_WARNING, "Missing link key"); goto err;
   } /* XXX Check key length */
   router->link_pkey = tok->val.public_key;
 
   NEXT_TOKEN();
   if (tok->tp != K_SIGNING_KEY) {
-    log_fn(LOG_ERR, "Missing signing-key"); goto err;
+    log_fn(LOG_WARNING, "Missing signing-key"); goto err;
   }
   NEXT_TOKEN();
   if (tok->tp != _PUBLIC_KEY) {
-    log_fn(LOG_ERR, "Missing signing key"); goto err;
+    log_fn(LOG_WARNING, "Missing signing key"); goto err;
   }
   router->identity_pkey = tok->val.public_key;
 
@@ -910,12 +912,12 @@ routerinfo_t *router_get_entry_from_string(char**s) {
   }
   
   if (tok->tp != K_ROUTER_SIGNATURE) {
-    log_fn(LOG_ERR,"Missing router signature");
+    log_fn(LOG_WARNING,"Missing router signature");
     goto err;
   }
   NEXT_TOKEN();
   if (tok->tp != _SIGNATURE) {
-    log_fn(LOG_ERR,"Missing router signature");
+    log_fn(LOG_WARNING,"Missing router signature");
     goto err;
   }
   assert (router->identity_pkey);
@@ -924,11 +926,11 @@ routerinfo_t *router_get_entry_from_string(char**s) {
    * XXX relay signed router blocks. */
   if (crypto_pk_public_checksig(router->identity_pkey, tok->val.signature,
                                 128, signed_digest) != 20) {
-    log_fn(LOG_ERR, "Invalid signature");
+    log_fn(LOG_WARNING, "Invalid signature");
     goto err;
   }
   if (memcmp(digest, signed_digest, 20)) {
-    log_fn(LOG_ERR, "Mismatched signature");
+    log_fn(LOG_WARNING, "Mismatched signature");
     goto err;
   }
 #endif
@@ -965,21 +967,6 @@ static void router_free_exit_policy(routerinfo_t *router) {
   }
 }
 
-#if 0
-void test_write_pkey(crypto_pk_env_t *pkey) {
-  char *string;
-  int len;
-
-  log(LOG_DEBUG,"Trying test write.");
-  if(crypto_pk_write_public_key_to_string(pkey,&string,&len)<0) {
-    log(LOG_DEBUG,"router_get_entry_from_string(): write pkey to string failed\n");
-    return;
-  }
-  log(LOG_DEBUG,"I did it: len %d, string '%s'.",len,string);
-  free(string);
-}
-#endif
-
 static int router_add_exit_policy(routerinfo_t *router, 
                                   directory_token_t *tok) {
   struct exit_policy_t *tmpe, *newe;
@@ -1010,7 +997,7 @@ static int router_add_exit_policy(routerinfo_t *router,
   newe->address = strdup(arg);
   newe->port = strdup(colon+1);
 
-  log(LOG_DEBUG,"router_add_exit_policy(): %s %s:%s",
+  log_fn(LOG_DEBUG,"%s %s:%s",
       newe->policy_type == EXIT_POLICY_REJECT ? "reject" : "accept",
       newe->address, newe->port);
 
@@ -1028,7 +1015,7 @@ static int router_add_exit_policy(routerinfo_t *router,
 
 policy_read_failed:
   assert(newe->string);
-  log(LOG_INFO,"router_add_exit_policy(): Couldn't parse line '%s'. Dropping", newe->string);
+  log_fn(LOG_WARNING,"Couldn't parse line '%s'. Dropping", newe->string);
   if(newe->string)
     free(newe->string);
   if(newe->address)
@@ -1046,7 +1033,7 @@ int router_compare_to_exit_policy(connection_t *conn) {
   struct exit_policy_t *tmpe;
 
   if(!my_routerinfo) {
-    log(LOG_WARNING, "router_compare_to_exit_policy(): my_routerinfo undefined! Rejected.");
+    log_fn(LOG_WARNING, "my_routerinfo undefined! Rejected.");
     return -1;
   }
 
@@ -1057,7 +1044,7 @@ int router_compare_to_exit_policy(connection_t *conn) {
     /* Totally ignore the address field of the exit policy, for now. */
 
     if(!strcmp(tmpe->port,"*") || atoi(tmpe->port) == conn->port) {
-      log(LOG_INFO,"router_compare_to_exit_policy(): Port '%s' matches '%d'. %s.",
+      log_fn(LOG_INFO,"Port '%s' matches '%d'. %s.",
           tmpe->port, conn->port,
           tmpe->policy_type == EXIT_POLICY_ACCEPT ? "Accepting" : "Rejecting");
       if(tmpe->policy_type == EXIT_POLICY_ACCEPT)