[Author Prev][Author Next][Thread Prev][Thread Next][Author Index][Thread Index]

[tor-commits] [obfsproxy/master] bug5079: Scrub IPs before displaying them in logs.



commit 15ab15881a9216d75ee66cf825f298a8445fd8f0
Author: Chris Ball <chris@xxxxxxxxxx>
Date:   Sun Feb 12 19:26:22 2012 -0500

    bug5079: Scrub IPs before displaying them in logs.
    
    Scrubbing is turned on by default and can be disabled with "--no-safe-logging".
    
    The scrubbing implemented here goes farther than Tor, in that it scrubs the
    client addresses too; this avoids putting live obfsproxy bridge addresses in
    the log.  As a side effect, protocol traffic between obfsproxy and Tor is no
    longer logged -- it can also contain addresses.
---
 src/main.c    |    7 +++-
 src/managed.c |   10 ++++--
 src/network.c |  100 +++++++++++++++++++++++++++++++-------------------------
 src/util.c    |    9 +++++
 src/util.h    |    4 ++
 5 files changed, 81 insertions(+), 49 deletions(-)

diff --git a/src/main.c b/src/main.c
index 7ebdd51..31878f9 100644
--- a/src/main.c
+++ b/src/main.c
@@ -35,6 +35,8 @@ static struct event *sig_term;
 
 /* Pluggable transport proxy mode. ('External' or 'Managed') */
 static int is_external_proxy=1;
+/* Whether to scrub connection addresses -- on by default */
+int safe_logging=1;
 
 /**
    Prints the obfsproxy usage instructions then exits.
@@ -52,7 +54,8 @@ usage(void)
   fprintf(stderr, "\n* obfsproxy_args:\n"
           "--log-file=<file> ~ set logfile\n"
           "--log-min-severity=warn|info|debug ~ set minimum logging severity\n"
-          "--no-log ~ disable logging\n");
+          "--no-log ~ disable logging\n"
+          "--no-safe-logging ~ disable safe (scrubbed address) logging\n");
 
   exit(1);
 }
@@ -164,6 +167,8 @@ handle_obfsproxy_args(const char *const *argv)
       }
 
       logsev_set=1;
+    } else if (!strncmp(argv[i], "--no-safe-logging", 18)) {
+      safe_logging=0;
     } else if (!strncmp(argv[i], "--managed", 10)) {
       is_external_proxy=0;
     } else {
diff --git a/src/managed.c b/src/managed.c
index 01814f8..2c3f967 100644
--- a/src/managed.c
+++ b/src/managed.c
@@ -153,9 +153,13 @@ print_protocol_line(const char *format, ...)
   vprintf(format, ap);
   fflush(stdout);
 
-  /* log the protocol message */
-  log_debug("We sent:");
-  log_debug_raw(format, ap2);
+  /* log the protocol message -- unless safe_logging is on, in which case
+   * we censor it because the METHOD line contains the bridge address.
+   */
+  if (!safe_logging) {
+    log_debug("We sent:");
+    log_debug_raw(format, ap2);
+  }
 
   va_end(ap);
   va_end(ap2);
diff --git a/src/network.c b/src/network.c
index e61e82d..5e3e788 100644
--- a/src/network.c
+++ b/src/network.c
@@ -236,7 +236,7 @@ open_listeners(struct event_base *base, config_t *cfg)
 
       if (!lsn->listener) {
         log_warn("Failed to open listening socket on %s: %s",
-                 lsn->address,
+                 safe_str_client(lsn->address),
                  evutil_socket_error_to_string(EVUTIL_SOCKET_ERROR()));
         listener_free(lsn);
         return 0;
@@ -299,7 +299,7 @@ listener_cb(struct evconnlistener *evcl, evutil_socket_t fd,
 
   if (!conn || !buf) {
     log_warn("%s: failed to set up new connection from %s.",
-             lsn->address, peername);
+             safe_str_client(lsn->address), safe_str_client(peername));
     if (buf)
       bufferevent_free(buf);
     else
@@ -313,8 +313,10 @@ listener_cb(struct evconnlistener *evcl, evutil_socket_t fd,
   if (!connections)
     connections = smartlist_create();
   smartlist_add(connections, conn);
-  log_debug("%s: new connection from %s (%d total)", lsn->address, peername,
-            smartlist_len(connections));
+  log_debug("%s: new connection from %s (%d total)",
+	    safe_str_client(lsn->address),
+	    safe_str_client(peername),
+	    smartlist_len(connections));
 
   conn->peername = peername;
   conn->buffer = buf;
@@ -336,7 +338,7 @@ simple_client_listener_cb(conn_t *conn)
 {
   obfs_assert(conn);
   obfs_assert(conn->mode == LSN_SIMPLE_CLIENT);
-  log_debug("%s: simple client connection", conn->peername);
+  log_debug("%s: simple client connection", safe_str_client(conn->peername));
 
   bufferevent_setcb(conn->buffer, upstream_read_cb, NULL, error_cb, conn);
 
@@ -345,7 +347,7 @@ simple_client_listener_cb(conn_t *conn)
     return;
   }
 
-  log_debug("%s: setup complete", conn->peername);
+  log_debug("%s: setup complete", safe_str_client(conn->peername));
 }
 
 /**
@@ -357,7 +359,7 @@ socks_client_listener_cb(conn_t *conn)
 {
   obfs_assert(conn);
   obfs_assert(conn->mode == LSN_SOCKS_CLIENT);
-  log_debug("%s: socks client connection", conn->peername);
+  log_debug("%s: socks client connection", safe_str_client(conn->peername));
 
   circuit_create_socks(conn);
 
@@ -367,7 +369,7 @@ socks_client_listener_cb(conn_t *conn)
   /* Do not create a circuit at this time; the socks handler will do
      it after it learns the remote peer address. */
 
-  log_debug("%s: setup complete", conn->peername);
+  log_debug("%s: setup complete", safe_str_client(conn->peername));
 }
 
 /**
@@ -379,7 +381,7 @@ simple_server_listener_cb(conn_t *conn)
 {
   obfs_assert(conn);
   obfs_assert(conn->mode == LSN_SIMPLE_SERVER);
-  log_debug("%s: server connection", conn->peername);
+  log_debug("%s: server connection", safe_str_client(conn->peername));
 
   bufferevent_setcb(conn->buffer, downstream_read_cb, NULL, error_cb, conn);
 
@@ -388,7 +390,7 @@ simple_server_listener_cb(conn_t *conn)
     return;
   }
 
-  log_debug("%s: setup complete", conn->peername);
+  log_debug("%s: setup complete", safe_str_client(conn->peername));
 }
 
 /**
@@ -403,7 +405,7 @@ conn_free(conn_t *conn)
     if (connections) {
       smartlist_remove(connections, conn);
       log_debug("Closing connection with %s; %d remaining",
-                conn->peername ? conn->peername : "'unknown'",
+                safe_str_client(conn->peername) ? safe_str_client(conn->peername) : "'unknown'",
                 smartlist_len(connections));
     }
     if (conn->peername)
@@ -430,7 +432,7 @@ static void
 conn_free_on_flush(struct bufferevent *bev, void *arg)
 {
   conn_t *conn = arg;
-  log_debug("%s for %s", __func__, conn->peername);
+  log_debug("%s for %s", __func__, safe_str_client(conn->peername));
 
   if (evbuffer_get_length(bufferevent_get_output(bev)) == 0)
     conn_free(conn);
@@ -506,20 +508,20 @@ open_outbound(conn_t *conn, bufferevent_data_cb readcb)
   conn_t *newconn;
 
   if (!addr) {
-    log_warn("%s: no target addresses available", conn->peername);
+    log_warn("%s: no target addresses available", safe_str_client(conn->peername));
     return NULL;
   }
 
   buf = bufferevent_socket_new(base, -1, BEV_OPT_CLOSE_ON_FREE);
   if (!buf) {
-    log_warn("%s: unable to create outbound socket buffer", conn->peername);
+    log_warn("%s: unable to create outbound socket buffer", safe_str_client(conn->peername));
     return NULL;
   }
 
   newconn = proto_conn_create(conn->cfg);
   if (!newconn) {
     log_warn("%s: failed to allocate state for outbound connection",
-             conn->peername);
+             safe_str_client(conn->peername));
     bufferevent_free(buf);
     return NULL;
   }
@@ -532,7 +534,7 @@ open_outbound(conn_t *conn, bufferevent_data_cb readcb)
     if (bufferevent_socket_connect(buf, addr->ai_addr, addr->ai_addrlen) >= 0)
       goto success;
     log_info("%s: connection to %s failed: %s",
-             conn->peername, peername,
+             safe_str_client(conn->peername), safe_str_client(peername),
              evutil_socket_error_to_string(EVUTIL_SOCKET_ERROR()));
     free(peername);
     addr = addr->ai_next;
@@ -546,7 +548,7 @@ open_outbound(conn_t *conn, bufferevent_data_cb readcb)
 
  success:
   log_info("%s (%s): Successful outbound connection to '%s'.",
-           conn->peername, conn->cfg->vtable->name, peername);
+           safe_str_client(conn->peername), conn->cfg->vtable->name, safe_str_client(peername));
   bufferevent_enable(buf, EV_READ|EV_WRITE);
   newconn->peername = peername;
   obfs_assert(connections);
@@ -567,13 +569,13 @@ open_outbound_hostname(conn_t *conn, int af, const char *addr, uint16_t port)
 
   buf = bufferevent_socket_new(base, -1, BEV_OPT_CLOSE_ON_FREE);
   if (!buf) {
-    log_warn("%s: unable to create outbound socket buffer", conn->peername);
+    log_warn("%s: unable to create outbound socket buffer", safe_str_client(conn->peername));
     return NULL;
   }
   newconn = proto_conn_create(conn->cfg);
   if (!newconn) {
     log_warn("%s: failed to allocate state for outbound connection",
-             conn->peername);
+             safe_str_client(conn->peername));
     bufferevent_free(buf);
     return NULL;
   }
@@ -604,7 +606,7 @@ open_outbound_hostname(conn_t *conn, int af, const char *addr, uint16_t port)
   if (bufferevent_socket_connect_hostname(buf, get_evdns_base(),
                                           af, addr, port) < 0) {
     log_warn("%s: outbound connection to %s:%u failed: %s",
-             conn->peername, addr, port,
+             safe_str_client(conn->peername), addr, port,
              evutil_socket_error_to_string(EVUTIL_SOCKET_ERROR()));
     conn_free(newconn);
     return NULL;
@@ -626,7 +628,8 @@ socks_read_cb(struct bufferevent *bev, void *arg)
   socks_state_t *socks;
   enum socks_ret socks_ret;
 
-  log_debug("%s: %s", conn->peername, __func__);
+  log_debug("%s: %s", safe_str_client(conn->peername), __func__);
+
   obfs_assert(conn->circuit);
   obfs_assert(conn->circuit->socks_state);
   socks = conn->circuit->socks_state;
@@ -642,8 +645,9 @@ socks_read_cb(struct bufferevent *bev, void *arg)
       const char *addr=NULL;
       r = socks_state_get_address(socks, &af, &addr, &port);
       obfs_assert(r==0);
+
       log_info("%s: socks: trying to connect to %s:%u",
-               conn->peername, addr, port);
+               safe_str_client(conn->peername), safe_str_client(addr), port);
       if (circuit_add_down(conn->circuit,
                            open_outbound_hostname(conn, af, addr, port))) {
         /* XXXX send socks reply */
@@ -686,7 +690,7 @@ upstream_read_cb(struct bufferevent *bev, void *arg)
 {
   conn_t *up = arg;
   conn_t *down;
-  log_debug("%s: %s, %lu bytes available", up->peername, __func__,
+  log_debug("%s: %s, %lu bytes available", safe_str_client(up->peername), __func__,
             (unsigned long)evbuffer_get_length(bufferevent_get_input(bev)));
 
   obfs_assert(up->buffer == bev);
@@ -699,10 +703,12 @@ upstream_read_cb(struct bufferevent *bev, void *arg)
   if (proto_send(up,
                  bufferevent_get_input(up->buffer),
                  bufferevent_get_output(down->buffer))) {
-    log_debug("%s: error during transmit.", up->peername);
+    log_debug("%s: error during transmit.",
+              safe_str_client(up->peername));
     conn_free(up);
   } else {
-    log_debug("%s: transmitted %lu bytes", down->peername,
+    log_debug("%s: transmitted %lu bytes",
+              safe_str_client(down->peername),
               (unsigned long)
               evbuffer_get_length(bufferevent_get_output(down->buffer)));
   }
@@ -720,7 +726,8 @@ downstream_read_cb(struct bufferevent *bev, void *arg)
   conn_t *up;
   enum recv_ret r;
 
-  log_debug("%s: %s, %lu bytes available", down->peername, __func__,
+  log_debug("%s: %s, %lu bytes available",
+            safe_str_client(down->peername), __func__,
             (unsigned long)evbuffer_get_length(bufferevent_get_input(bev)));
 
   obfs_assert(down->buffer == bev);
@@ -736,23 +743,23 @@ downstream_read_cb(struct bufferevent *bev, void *arg)
                  bufferevent_get_output(up->buffer));
 
   if (r == RECV_BAD) {
-    log_debug("%s: error during receive.", down->peername);
+    log_debug("%s: error during receive.", safe_str_client(down->peername));
     conn_free(down);
   } else {
-    log_debug("%s: forwarded %lu bytes", down->peername,
+    log_debug("%s: forwarded %lu bytes", safe_str_client(down->peername),
               (unsigned long)
               evbuffer_get_length(bufferevent_get_output(up->buffer)));
     if (r == RECV_SEND_PENDING) {
-      log_debug("%s: reply of %lu bytes", down->peername,
+      log_debug("%s: reply of %lu bytes", safe_str_client(down->peername),
                 (unsigned long)
                 evbuffer_get_length(bufferevent_get_input(up->buffer)));
       if (proto_send(up,
                      bufferevent_get_input(up->buffer),
                      bufferevent_get_output(down->buffer)) < 0) {
-        log_debug("%s: error during reply.", down->peername);
+        log_debug("%s: error during reply.", safe_str_client(down->peername));
         conn_free(down);
       } else {
-        log_debug("%s: transmitted %lu bytes", down->peername,
+        log_debug("%s: transmitted %lu bytes", safe_str_client(down->peername),
                   (unsigned long)
                   evbuffer_get_length(bufferevent_get_output(down->buffer)));
       }
@@ -772,7 +779,7 @@ error_or_eof(conn_t *conn)
   struct bufferevent *bev_err = conn->buffer;
   struct bufferevent *bev_flush;
 
-  log_debug("%s for %s", __func__, conn->peername);
+  log_debug("%s for %s", __func__, safe_str_client(conn->peername));
   if (!circ || !circ->upstream || !circ->downstream || !circ->is_open
       || circ->is_flushing) {
     conn_free(conn);
@@ -809,7 +816,7 @@ error_cb(struct bufferevent *bev, short what, void *arg)
 {
   conn_t *conn = arg;
   int errcode = EVUTIL_SOCKET_ERROR();
-  log_debug("%s for %s: what=0x%04x errno=%d", __func__, conn->peername,
+  log_debug("%s for %s: what=0x%04x errno=%d", __func__, safe_str_client(conn->peername),
             what, errcode);
 
   /* It should be impossible to get here with BEV_EVENT_CONNECTED. */
@@ -817,12 +824,12 @@ error_cb(struct bufferevent *bev, short what, void *arg)
 
   if (what & BEV_EVENT_ERROR) {
     log_warn("Error talking to %s: %s",
-             conn->peername,
+             safe_str_client(conn->peername),
              evutil_socket_error_to_string(errcode));
   } else if (what & BEV_EVENT_EOF) {
-    log_info("EOF from %s", conn->peername);
+    log_info("EOF from %s", safe_str_client(conn->peername));
   } else if (what & BEV_EVENT_TIMEOUT) {
-    log_info("Timeout talking to %s", conn->peername);
+    log_info("Timeout talking to %s", safe_str_client(conn->peername));
   }
   error_or_eof(conn);
 }
@@ -836,7 +843,7 @@ flush_error_cb(struct bufferevent *bev, short what, void *arg)
 {
   conn_t *conn = arg;
   int errcode = EVUTIL_SOCKET_ERROR();
-  log_debug("%s for %s: what=0x%04x errno=%d", __func__, conn->peername,
+  log_debug("%s for %s: what=0x%04x errno=%d", __func__, safe_str_client(conn->peername),
             what, errcode);
 
   /* It should be impossible to get here with BEV_EVENT_CONNECTED. */
@@ -846,7 +853,7 @@ flush_error_cb(struct bufferevent *bev, short what, void *arg)
   obfs_assert(conn->circuit->is_flushing);
 
   log_warn("Error during flush of connection with %s: %s",
-           conn->peername,
+           safe_str_client(conn->peername),
            evutil_socket_error_to_string(errcode));
   conn_free(conn);
   return;
@@ -862,7 +869,7 @@ static void
 pending_conn_cb(struct bufferevent *bev, short what, void *arg)
 {
   conn_t *conn = arg;
-  log_debug("%s: %s", conn->peername, __func__);
+  log_debug("%s: %s", safe_str_client(conn->peername), __func__);
 
   /* Upon successful connection, enable traffic on both sides of the
      connection, and replace this callback with the regular error_cb */
@@ -873,12 +880,12 @@ pending_conn_cb(struct bufferevent *bev, short what, void *arg)
 
     circ->is_open = 1;
 
-    log_debug("%s: Successful connection", conn->peername);
+    log_debug("%s: Successful connection", safe_str_client(conn->peername));
 
     /* Queue handshake, if any. */
     if (proto_handshake(circ->downstream,
                         bufferevent_get_output(circ->downstream->buffer))<0) {
-      log_debug("%s: Error during handshake", conn->peername);
+      log_debug("%s: Error during handshake", safe_str_client(conn->peername));
       conn_free(conn);
       return;
     }
@@ -910,7 +917,7 @@ pending_socks_cb(struct bufferevent *bev, short what, void *arg)
   conn_t *up;
   socks_state_t *socks;
 
-  log_debug("%s: %s", down->peername, __func__);
+  log_debug("%s: %s", safe_str_client(down->peername), __func__);
 
   obfs_assert(circ);
   obfs_assert(circ->upstream);
@@ -958,10 +965,12 @@ pending_socks_cb(struct bufferevent *bev, short what, void *arg)
       connected to. */
 
       char *peername = printable_address(sa, slen);
+
       if (down->peername) {
         log_debug("We connected to our SOCKS destination! "
                   "Replacing peername '%s' with '%s'",
-                  down->peername, peername);
+                  safe_str_client(down->peername),
+                  safe_str_client(peername));
         free(down->peername);
       }
       down->peername = peername;
@@ -980,7 +989,8 @@ pending_socks_cb(struct bufferevent *bev, short what, void *arg)
     circ->socks_state = NULL;
     circ->is_open = 1;
     log_debug("%s: Successful outbound connection to %s",
-              up->peername, down->peername);
+              safe_str_client(up->peername),
+              safe_str_client(down->peername));
 
     bufferevent_setcb(up->buffer, upstream_read_cb, NULL, error_cb, up);
     bufferevent_setcb(down->buffer, downstream_read_cb, NULL, error_cb, down);
@@ -989,7 +999,7 @@ pending_socks_cb(struct bufferevent *bev, short what, void *arg)
 
     /* Queue handshake, if any. */
     if (proto_handshake(down, bufferevent_get_output(down->buffer))) {
-      log_debug("%s: Error during handshake", down->peername);
+      log_debug("%s: Error during handshake", safe_str_client(down->peername));
       conn_free(down);
       return;
     }
diff --git a/src/util.c b/src/util.c
index f2089df..7ab3567 100644
--- a/src/util.c
+++ b/src/util.c
@@ -215,6 +215,15 @@ resolve_address_port(const char *address, int nodns, int passive,
   return ai;
 }
 
+const char *
+safe_str_client(const char *address)
+{
+  if (safe_logging)
+    return "[scrubbed]";
+  else
+    return address;
+}
+
 char *
 printable_address(struct sockaddr *addr, socklen_t addrlen)
 {
diff --git a/src/util.h b/src/util.h
index 3396abf..5b758cf 100644
--- a/src/util.h
+++ b/src/util.h
@@ -153,6 +153,10 @@ int obfs_snprintf(char *str, size_t size,
     "yyyy-mm-dd hh:mm:ss" (without quotes). */
 #define ISO_TIME_LEN 19
 
+/** Safely log an address, scrubbing if necessary. */
+extern int safe_logging; /* defined in main.c */
+const char * safe_str_client(const char *address);
+
 /** Set the log method, and open the logfile 'filename' if appropriate. */
 int log_set_method(int method, const char *filename);
 



_______________________________________________
tor-commits mailing list
tor-commits@xxxxxxxxxxxxxxxxxxxx
https://lists.torproject.org/cgi-bin/mailman/listinfo/tor-commits