commit 15ab15881a9216d75ee66cf825f298a8445fd8f0
Author: Chris Ball <chris(a)printf.net>
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);
