Ticket #5079: 0001-bug5079-Scrub-IPs-before-displaying-them-in-logs.patch

File 0001-bug5079-Scrub-IPs-before-displaying-them-in-logs.patch, 18.3 KB (added by cjbprime, 9 years ago)
  • src/main.c

    From 499be399c172c1562a350d4d78e3e178daeea994 Mon Sep 17 00:00:00 2001
    From: Chris Ball <chris@printf.net>
    Date: Sun, 12 Feb 2012 15:21:30 -0500
    Subject: [PATCH] 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 |  102 +++++++++++++++++++++++++++++++-------------------------
     src/util.c    |    9 +++++
     src/util.h    |    4 ++
     5 files changed, 82 insertions(+), 50 deletions(-)
    
    diff --git a/src/main.c b/src/main.c
    index 7ebdd51..31878f9 100644
    a b static struct event *sig_term; 
    3535
    3636/* Pluggable transport proxy mode. ('External' or 'Managed') */
    3737static int is_external_proxy=1;
     38/* Whether to scrub connection addresses -- on by default */
     39int safe_logging=1;
    3840
    3941/**
    4042   Prints the obfsproxy usage instructions then exits.
    usage(void) 
    5254  fprintf(stderr, "\n* obfsproxy_args:\n"
    5355          "--log-file=<file> ~ set logfile\n"
    5456          "--log-min-severity=warn|info|debug ~ set minimum logging severity\n"
    55           "--no-log ~ disable logging\n");
     57          "--no-log ~ disable logging\n"
     58          "--no-safe-logging ~ disable safe (scrubbed address) logging\n");
    5659
    5760  exit(1);
    5861}
    handle_obfsproxy_args(const char *const *argv) 
    164167      }
    165168
    166169      logsev_set=1;
     170    } else if (!strncmp(argv[i], "--no-safe-logging", 18)) {
     171      safe_logging=0;
    167172    } else if (!strncmp(argv[i], "--managed", 10)) {
    168173      is_external_proxy=0;
    169174    } else {
  • src/managed.c

    diff --git a/src/managed.c b/src/managed.c
    index 01814f8..2c3f967 100644
    a b print_protocol_line(const char *format, ...) 
    153153  vprintf(format, ap);
    154154  fflush(stdout);
    155155
    156   /* log the protocol message */
    157   log_debug("We sent:");
    158   log_debug_raw(format, ap2);
     156  /* log the protocol message -- unless safe_logging is on, in which case
     157   * we censor it because the METHOD line contains the bridge address.
     158   */
     159  if (!safe_logging) {
     160    log_debug("We sent:");
     161    log_debug_raw(format, ap2);
     162  }
    159163
    160164  va_end(ap);
    161165  va_end(ap2);
  • src/network.c

    diff --git a/src/network.c b/src/network.c
    index 27eb2ee..b347ecb 100644
    a b open_listeners(struct event_base *base, config_t *cfg) 
    236236
    237237      if (!lsn->listener) {
    238238        log_warn("Failed to open listening socket on %s: %s",
    239                  lsn->address,
     239                 safe_str_client(lsn->address),
    240240                 evutil_socket_error_to_string(EVUTIL_SOCKET_ERROR()));
    241241        listener_free(lsn);
    242242        return 0;
    listener_cb(struct evconnlistener *evcl, evutil_socket_t fd, 
    299299
    300300  if (!conn || !buf) {
    301301    log_warn("%s: failed to set up new connection from %s.",
    302              lsn->address, peername);
     302             safe_str_client(lsn->address), safe_str_client(peername));
    303303    if (buf)
    304304      bufferevent_free(buf);
    305305    else
    listener_cb(struct evconnlistener *evcl, evutil_socket_t fd, 
    313313  if (!connections)
    314314    connections = smartlist_create();
    315315  smartlist_add(connections, conn);
    316   log_debug("%s: new connection from %s (%d total)", lsn->address, peername,
    317             smartlist_len(connections));
     316  log_debug("%s: new connection from %s (%d total)",
     317            safe_str_client(lsn->address),
     318            safe_str_client(peername),
     319            smartlist_len(connections));
    318320
    319321  conn->peername = peername;
    320322  conn->buffer = buf;
    simple_client_listener_cb(conn_t *conn) 
    336338{
    337339  obfs_assert(conn);
    338340  obfs_assert(conn->mode == LSN_SIMPLE_CLIENT);
    339   log_debug("%s: simple client connection", conn->peername);
     341  log_debug("%s: simple client connection", safe_str_client(conn->peername));
    340342
    341343  bufferevent_setcb(conn->buffer, upstream_read_cb, NULL, error_cb, conn);
    342344
    simple_client_listener_cb(conn_t *conn) 
    345347    return;
    346348  }
    347349
    348   log_debug("%s: setup complete", conn->peername);
     350  log_debug("%s: setup complete", safe_str_client(conn->peername));
    349351}
    350352
    351353/**
    socks_client_listener_cb(conn_t *conn) 
    357359{
    358360  obfs_assert(conn);
    359361  obfs_assert(conn->mode == LSN_SOCKS_CLIENT);
    360   log_debug("%s: socks client connection", conn->peername);
     362  log_debug("%s: socks client connection", safe_str_client(conn->peername));
    361363
    362364  circuit_create_socks(conn);
    363365
    socks_client_listener_cb(conn_t *conn) 
    367369  /* Do not create a circuit at this time; the socks handler will do
    368370     it after it learns the remote peer address. */
    369371
    370   log_debug("%s: setup complete", conn->peername);
     372  log_debug("%s: setup complete", safe_str_client(conn->peername));
    371373}
    372374
    373375/**
    simple_server_listener_cb(conn_t *conn) 
    379381{
    380382  obfs_assert(conn);
    381383  obfs_assert(conn->mode == LSN_SIMPLE_SERVER);
    382   log_debug("%s: server connection", conn->peername);
     384  log_debug("%s: server connection", safe_str_client(conn->peername));
    383385
    384386  bufferevent_setcb(conn->buffer, downstream_read_cb, NULL, error_cb, conn);
    385387
    simple_server_listener_cb(conn_t *conn) 
    388390    return;
    389391  }
    390392
    391   log_debug("%s: setup complete", conn->peername);
     393  log_debug("%s: setup complete", safe_str_client(conn->peername));
    392394}
    393395
    394396/**
    conn_free(conn_t *conn) 
    403405    if (connections) {
    404406      smartlist_remove(connections, conn);
    405407      log_debug("Closing connection with %s; %d remaining",
    406                 conn->peername ? conn->peername : "'unknown'",
     408                safe_str_client(conn->peername) ? safe_str_client(conn->peername) : "'unknown'",
    407409                smartlist_len(connections));
    408410    }
    409411    if (conn->peername)
    static void 
    430432conn_free_on_flush(struct bufferevent *bev, void *arg)
    431433{
    432434  conn_t *conn = arg;
    433   log_debug("%s for %s", __func__, conn->peername);
     435  log_debug("%s for %s", __func__, safe_str_client(conn->peername));
    434436
    435437  if (evbuffer_get_length(bufferevent_get_output(bev)) == 0)
    436438    conn_free(conn);
    open_outbound(conn_t *conn, bufferevent_data_cb readcb) 
    506508  conn_t *newconn;
    507509
    508510  if (!addr) {
    509     log_warn("%s: no target addresses available", conn->peername);
     511    log_warn("%s: no target addresses available", safe_str_client(conn->peername));
    510512    return NULL;
    511513  }
    512514
    513515  buf = bufferevent_socket_new(base, -1, BEV_OPT_CLOSE_ON_FREE);
    514516  if (!buf) {
    515     log_warn("%s: unable to create outbound socket buffer", conn->peername);
     517    log_warn("%s: unable to create outbound socket buffer", safe_str_client(conn->peername));
    516518    return NULL;
    517519  }
    518520
    519521  newconn = proto_conn_create(conn->cfg);
    520522  if (!newconn) {
    521523    log_warn("%s: failed to allocate state for outbound connection",
    522              conn->peername);
     524             safe_str_client(conn->peername));
    523525    bufferevent_free(buf);
    524526    return NULL;
    525527  }
    open_outbound(conn_t *conn, bufferevent_data_cb readcb) 
    530532  do {
    531533    peername = printable_address(addr->ai_addr, addr->ai_addrlen);
    532534    log_info("%s (%s): trying to connect to %s",
    533              conn->peername, conn->cfg->vtable->name, peername);
     535             safe_str_client(conn->peername), conn->cfg->vtable->name, peername);
    534536    if (bufferevent_socket_connect(buf, addr->ai_addr, addr->ai_addrlen) >= 0)
    535537      goto success;
    536538    log_info("%s: connection to %s failed: %s",
    537              conn->peername, peername,
     539             safe_str_client(conn->peername), peername,
    538540             evutil_socket_error_to_string(EVUTIL_SOCKET_ERROR()));
    539541    free(peername);
    540542    addr = addr->ai_next;
    541543  } while (addr);
    542544
    543545  log_warn("%s: all outbound connection attempts failed",
    544            conn->peername);
     546           safe_str_client(conn->peername));
    545547
    546548  conn_free(newconn);
    547549  return NULL;
    open_outbound_hostname(conn_t *conn, int af, const char *addr, uint16_t port) 
    567569
    568570  buf = bufferevent_socket_new(base, -1, BEV_OPT_CLOSE_ON_FREE);
    569571  if (!buf) {
    570     log_warn("%s: unable to create outbound socket buffer", conn->peername);
     572    log_warn("%s: unable to create outbound socket buffer", safe_str_client(conn->peername));
    571573    return NULL;
    572574  }
    573575  newconn = proto_conn_create(conn->cfg);
    574576  if (!newconn) {
    575577    log_warn("%s: failed to allocate state for outbound connection",
    576              conn->peername);
     578             safe_str_client(conn->peername));
    577579    bufferevent_free(buf);
    578580    return NULL;
    579581  }
    open_outbound_hostname(conn_t *conn, int af, const char *addr, uint16_t port) 
    604606  if (bufferevent_socket_connect_hostname(buf, get_evdns_base(),
    605607                                          af, addr, port) < 0) {
    606608    log_warn("%s: outbound connection to %s:%u failed: %s",
    607              conn->peername, addr, port,
     609             safe_str_client(conn->peername), addr, port,
    608610             evutil_socket_error_to_string(EVUTIL_SOCKET_ERROR()));
    609611    conn_free(newconn);
    610612    return NULL;
    socks_read_cb(struct bufferevent *bev, void *arg) 
    626628  socks_state_t *socks;
    627629  enum socks_ret socks_ret;
    628630
    629   log_debug("%s: %s", conn->peername, __func__);
     631  log_debug("%s: %s", safe_str_client(conn->peername), __func__);
     632
    630633  obfs_assert(conn->circuit);
    631634  obfs_assert(conn->circuit->socks_state);
    632635  socks = conn->circuit->socks_state;
    socks_read_cb(struct bufferevent *bev, void *arg) 
    642645      const char *addr=NULL;
    643646      r = socks_state_get_address(socks, &af, &addr, &port);
    644647      obfs_assert(r==0);
     648
    645649      log_info("%s: socks: trying to connect to %s:%u",
    646                conn->peername, addr, port);
     650               safe_str_client(conn->peername), safe_str_client(addr), port);
    647651      if (circuit_add_down(conn->circuit,
    648652                           open_outbound_hostname(conn, af, addr, port))) {
    649653        /* XXXX send socks reply */
    upstream_read_cb(struct bufferevent *bev, void *arg) 
    686690{
    687691  conn_t *up = arg;
    688692  conn_t *down;
    689   log_debug("%s: %s, %lu bytes available", up->peername, __func__,
     693  log_debug("%s: %s, %lu bytes available", safe_str_client(up->peername), __func__,
    690694            (unsigned long)evbuffer_get_length(bufferevent_get_input(bev)));
    691695
    692696  obfs_assert(up->buffer == bev);
    upstream_read_cb(struct bufferevent *bev, void *arg) 
    699703  if (proto_send(up,
    700704                 bufferevent_get_input(up->buffer),
    701705                 bufferevent_get_output(down->buffer))) {
    702     log_debug("%s: error during transmit.", up->peername);
     706    log_debug("%s: error during transmit.",
     707              safe_str_client(up->peername));
    703708    conn_free(up);
    704709  } else {
    705     log_debug("%s: transmitted %lu bytes", down->peername,
     710    log_debug("%s: transmitted %lu bytes",
     711              safe_str_client(down->peername),
    706712              (unsigned long)
    707713              evbuffer_get_length(bufferevent_get_output(down->buffer)));
    708714  }
    downstream_read_cb(struct bufferevent *bev, void *arg) 
    720726  conn_t *up;
    721727  enum recv_ret r;
    722728
    723   log_debug("%s: %s, %lu bytes available", down->peername, __func__,
     729  log_debug("%s: %s, %lu bytes available",
     730            safe_str_client(down->peername), __func__,
    724731            (unsigned long)evbuffer_get_length(bufferevent_get_input(bev)));
    725732
    726733  obfs_assert(down->buffer == bev);
    downstream_read_cb(struct bufferevent *bev, void *arg) 
    736743                 bufferevent_get_output(up->buffer));
    737744
    738745  if (r == RECV_BAD) {
    739     log_debug("%s: error during receive.", down->peername);
     746    log_debug("%s: error during receive.", safe_str_client(down->peername));
    740747    conn_free(down);
    741748  } else {
    742     log_debug("%s: forwarded %lu bytes", down->peername,
     749    log_debug("%s: forwarded %lu bytes", safe_str_client(down->peername),
    743750              (unsigned long)
    744751              evbuffer_get_length(bufferevent_get_output(up->buffer)));
    745752    if (r == RECV_SEND_PENDING) {
    746       log_debug("%s: reply of %lu bytes", down->peername,
     753      log_debug("%s: reply of %lu bytes", safe_str_client(down->peername),
    747754                (unsigned long)
    748755                evbuffer_get_length(bufferevent_get_input(up->buffer)));
    749756      if (proto_send(up,
    750757                     bufferevent_get_input(up->buffer),
    751758                     bufferevent_get_output(down->buffer)) < 0) {
    752         log_debug("%s: error during reply.", down->peername);
     759        log_debug("%s: error during reply.", safe_str_client(down->peername));
    753760        conn_free(down);
    754761      } else {
    755         log_debug("%s: transmitted %lu bytes", down->peername,
     762        log_debug("%s: transmitted %lu bytes", safe_str_client(down->peername),
    756763                  (unsigned long)
    757764                  evbuffer_get_length(bufferevent_get_output(down->buffer)));
    758765      }
    error_or_eof(conn_t *conn) 
    772779  struct bufferevent *bev_err = conn->buffer;
    773780  struct bufferevent *bev_flush;
    774781
    775   log_debug("%s for %s", __func__, conn->peername);
     782  log_debug("%s for %s", __func__, safe_str_client(conn->peername));
    776783  if (!circ || !circ->upstream || !circ->downstream || !circ->is_open
    777784      || circ->is_flushing) {
    778785    conn_free(conn);
    error_cb(struct bufferevent *bev, short what, void *arg) 
    809816{
    810817  conn_t *conn = arg;
    811818  int errcode = EVUTIL_SOCKET_ERROR();
    812   log_debug("%s for %s: what=0x%04x errno=%d", __func__, conn->peername,
     819  log_debug("%s for %s: what=0x%04x errno=%d", __func__, safe_str_client(conn->peername),
    813820            what, errcode);
    814821
    815822  /* It should be impossible to get here with BEV_EVENT_CONNECTED. */
    error_cb(struct bufferevent *bev, short what, void *arg) 
    817824
    818825  if (what & BEV_EVENT_ERROR) {
    819826    log_warn("Error talking to %s: %s",
    820              conn->peername,
     827             safe_str_client(conn->peername),
    821828             evutil_socket_error_to_string(errcode));
    822829  } else if (what & BEV_EVENT_EOF) {
    823     log_info("EOF from %s", conn->peername);
     830    log_info("EOF from %s", safe_str_client(conn->peername));
    824831  } else if (what & BEV_EVENT_TIMEOUT) {
    825     log_info("Timeout talking to %s", conn->peername);
     832    log_info("Timeout talking to %s", safe_str_client(conn->peername));
    826833  }
    827834  error_or_eof(conn);
    828835}
    flush_error_cb(struct bufferevent *bev, short what, void *arg) 
    836843{
    837844  conn_t *conn = arg;
    838845  int errcode = EVUTIL_SOCKET_ERROR();
    839   log_debug("%s for %s: what=0x%04x errno=%d", __func__, conn->peername,
     846  log_debug("%s for %s: what=0x%04x errno=%d", __func__, safe_str_client(conn->peername),
    840847            what, errcode);
    841848
    842849  /* It should be impossible to get here with BEV_EVENT_CONNECTED. */
    flush_error_cb(struct bufferevent *bev, short what, void *arg) 
    846853  obfs_assert(conn->circuit->is_flushing);
    847854
    848855  log_warn("Error during flush of connection with %s: %s",
    849            conn->peername,
     856           safe_str_client(conn->peername),
    850857           evutil_socket_error_to_string(errcode));
    851858  conn_free(conn);
    852859  return;
    static void 
    862869pending_conn_cb(struct bufferevent *bev, short what, void *arg)
    863870{
    864871  conn_t *conn = arg;
    865   log_debug("%s: %s", conn->peername, __func__);
     872  log_debug("%s: %s", safe_str_client(conn->peername), __func__);
    866873
    867874  /* Upon successful connection, enable traffic on both sides of the
    868875     connection, and replace this callback with the regular error_cb */
    pending_conn_cb(struct bufferevent *bev, short what, void *arg) 
    873880
    874881    circ->is_open = 1;
    875882
    876     log_debug("%s: Successful connection", conn->peername);
     883    log_debug("%s: Successful connection", safe_str_client(conn->peername));
    877884
    878885    /* Queue handshake, if any. */
    879886    if (proto_handshake(circ->downstream,
    880887                        bufferevent_get_output(circ->downstream->buffer))<0) {
    881       log_debug("%s: Error during handshake", conn->peername);
     888      log_debug("%s: Error during handshake", safe_str_client(conn->peername));
    882889      conn_free(conn);
    883890      return;
    884891    }
    pending_socks_cb(struct bufferevent *bev, short what, void *arg) 
    910917  conn_t *up;
    911918  socks_state_t *socks;
    912919
    913   log_debug("%s: %s", down->peername, __func__);
     920  log_debug("%s: %s", safe_str_client(down->peername), __func__);
    914921
    915922  obfs_assert(circ);
    916923  obfs_assert(circ->upstream);
    pending_socks_cb(struct bufferevent *bev, short what, void *arg) 
    958965      connected to. */
    959966
    960967      char *peername = printable_address(sa, slen);
     968
    961969      if (down->peername) {
    962970        log_debug("We connected to our SOCKS destination! "
    963971                  "Replacing peername '%s' with '%s'",
    964                   down->peername, peername);
     972                  safe_str_client(down->peername),
     973                  safe_str_client(peername));
    965974        free(down->peername);
    966975      }
    967976      down->peername = peername;
    pending_socks_cb(struct bufferevent *bev, short what, void *arg) 
    980989    circ->socks_state = NULL;
    981990    circ->is_open = 1;
    982991    log_debug("%s: Successful outbound connection to %s",
    983               up->peername, down->peername);
     992              safe_str_client(up->peername),
     993              safe_str_client(down->peername));
    984994
    985995    bufferevent_setcb(up->buffer, upstream_read_cb, NULL, error_cb, up);
    986996    bufferevent_setcb(down->buffer, downstream_read_cb, NULL, error_cb, down);
    pending_socks_cb(struct bufferevent *bev, short what, void *arg) 
    989999
    9901000    /* Queue handshake, if any. */
    9911001    if (proto_handshake(down, bufferevent_get_output(down->buffer))) {
    992       log_debug("%s: Error during handshake", down->peername);
     1002      log_debug("%s: Error during handshake", safe_str_client(down->peername));
    9931003      conn_free(down);
    9941004      return;
    9951005    }
  • src/util.c

    diff --git a/src/util.c b/src/util.c
    index f2089df..7ab3567 100644
    a b resolve_address_port(const char *address, int nodns, int passive, 
    215215  return ai;
    216216}
    217217
     218const char *
     219safe_str_client(const char *address)
     220{
     221  if (safe_logging)
     222    return "[scrubbed]";
     223  else
     224    return address;
     225}
     226
    218227char *
    219228printable_address(struct sockaddr *addr, socklen_t addrlen)
    220229{
  • src/util.h

    diff --git a/src/util.h b/src/util.h
    index 3396abf..5b758cf 100644
    a b int obfs_snprintf(char *str, size_t size, 
    153153    "yyyy-mm-dd hh:mm:ss" (without quotes). */
    154154#define ISO_TIME_LEN 19
    155155
     156/** Safely log an address, scrubbing if necessary. */
     157extern int safe_logging; /* defined in main.c */
     158const char * safe_str_client(const char *address);
     159
    156160/** Set the log method, and open the logfile 'filename' if appropriate. */
    157161int log_set_method(int method, const char *filename);
    158162