Clean up some logging and interfaces

svn:r2945

src/common/tortls.c

@@ -441,12 +441,13 @@ tor_tls_read(tor_tls *tls, char *cp, size_t len)
   if (r > 0)
     return r;
   err = tor_tls_get_error(tls, r, CATCH_ZERO, "reading", LOG_INFO);
-  log_fn(LOG_DEBUG,"returned r=%d, err=%d",r,err);
   if (err == _TOR_TLS_ZERORETURN) {
+    log_fn(LOG_DEBUG,"read returned r=%d; TLS is closed",r);
     tls->state = TOR_TLS_ST_CLOSED;
     return TOR_TLS_CLOSE;
   } else {
     tor_assert(err != TOR_TLS_DONE);
+    log_fn(LOG_DEBUG,"read returned r=%d, err=%d",r,err);
     return err;
   }
 }
@@ -479,7 +480,6 @@ tor_tls_write(tor_tls *tls, char *cp, size_t n)
     return r;
   }
   if (err == TOR_TLS_WANTWRITE || err == TOR_TLS_WANTREAD) {
-//    log_fn(LOG_INFO,"wantwrite or wantread. remembering the number %d.",n);
     tls->wantwrite_n = n;
   }
   return err;
@@ -685,7 +685,6 @@ tor_tls_verify(tor_tls *tls, crypto_pk_env_t **identity_key)
   if (!(chain = SSL_get_peer_cert_chain(tls->ssl)))
     goto done;
   num_in_chain = sk_X509_num(chain);
-  log_fn(LOG_DEBUG,"Number of certs in chain: %d", num_in_chain);
   /* 1 means we're receiving (server-side), and it's just the id_cert.
    * 2 means we're connecting (client-side), and it's both the link
    * cert and the id_cert.

src/common/util.c

@@ -475,7 +475,6 @@ int base16_decode(char *dest, size_t destlen, const char *src, size_t srclen)
  * ===== */
 
 /** Return the number of microseconds elapsed between *start and *end.
- * If start is after end, return 0.
  */
 long
 tv_udiff(struct timeval *start, struct timeval *end)
@@ -483,17 +482,12 @@ tv_udiff(struct timeval *start, struct timeval *end)
   long udiff;
   long secdiff = end->tv_sec - start->tv_sec;
 
-  if (secdiff+1 > LONG_MAX/1000000) {
+  if (labs(secdiff+1) > LONG_MAX/1000000) {
     log_fn(LOG_WARN, "comparing times too far apart.");
     return LONG_MAX;
   }
 
   udiff = secdiff*1000000L + (end->tv_usec - start->tv_usec);
-  if(udiff < 0) {
-    log_fn(LOG_INFO, "start (%ld.%ld) is after end (%ld.%ld). Returning 0.",
-           (long)start->tv_sec, (long)start->tv_usec, (long)end->tv_sec, (long)end->tv_usec);
-    return 0;
-  }
   return udiff;
 }
 

src/or/command.c

@@ -49,6 +49,10 @@ static void command_time_process_cell(cell_t *cell, connection_t *conn, int *tim
   if (time_passed > 10000) { /* more than 10ms */
     log_fn(LOG_DEBUG,"That call just took %ld ms.",time_passed/1000);
   }
+  if (time_passed < 0) {
+    log_fn(LOG_INFO,"That call took us back in time!");
+    time_passed = 0;
+  }
   *time += time_passed;
 }