[tor-commits] [stegotorus/master] Add an abbreviated packet tracing mode.
zwol at torproject.org
zwol at torproject.org
Fri Jul 20 23:17:08 UTC 2012
commit 8c3ec7d7253545e94da1ee64598b5bfe5ffb92c5
Author: Zack Weinberg <zackw at cmu.edu>
Date: Wed Jun 20 17:10:24 2012 -0700
Add an abbreviated packet tracing mode.
---
src/protocol/chop.cc | 44 +++++++++++++++++++++++++++++++++++++++++++-
src/util.cc | 29 ++++++++++++++++++-----------
src/util.h | 4 ++++
3 files changed, 65 insertions(+), 12 deletions(-)
diff --git a/src/protocol/chop.cc b/src/protocol/chop.cc
index cde40b2..c865c9b 100644
--- a/src/protocol/chop.cc
+++ b/src/protocol/chop.cc
@@ -387,6 +387,7 @@ struct chop_config_t : config_t
vector<struct evutil_addrinfo *> down_addresses;
vector<steg_config_t *> steg_targets;
chop_circuit_table circuits;
+ bool trace_packets;
CONFIG_DECLARE_METHODS(chop);
};
@@ -396,6 +397,7 @@ struct chop_config_t : config_t
chop_config_t::chop_config_t()
{
ignore_socks_destination = true;
+ trace_packets = false;
}
chop_config_t::~chop_config_t()
@@ -450,6 +452,13 @@ chop_config_t::init(int n_options, const char *const *options)
n_options--;
}
+ if (!strcmp(options[1], "--trace-packets")) {
+ options++;
+ n_options--;
+ trace_packets = true;
+ log_enable_timestamps();
+ }
+
up_address = resolve_address_port(options[1], 1, listen_up, defport);
if (!up_address) {
log_warn("chop: invalid up address: %s", options[1]);
@@ -881,11 +890,21 @@ chop_circuit_t::send_targeted(chop_conn_t *conn, size_t d, size_t p, opcode_t f,
return -1;
}
- char fallbackbuf[3];
+ char fallbackbuf[4];
log_debug(conn, "transmitting block %u <d=%lu p=%lu f=%s>",
hdr.seqno(), (unsigned long)hdr.dlen(), (unsigned long)hdr.plen(),
opname(hdr.opcode(), fallbackbuf));
+ if (config->trace_packets)
+ fprintf(stderr, "T:%.4f: ckt %u <ntp %u outq %lu>: send %lu <d=%lu p=%lu f=%s>\n",
+ log_get_timestamp(), this->serial,
+ this->recv_queue.window(),
+ (unsigned long)evbuffer_get_length(bufferevent_get_input(this->up_buffer)),
+ (unsigned long)hdr.seqno(),
+ (unsigned long)hdr.dlen(),
+ (unsigned long)hdr.plen(),
+ opname(hdr.opcode(), fallbackbuf));
+
if (conn->send(block)) {
evbuffer_free(block);
return -1;
@@ -1292,6 +1311,19 @@ chop_conn_t::recv()
(unsigned long)hdr.plen(),
opname(hdr.opcode(), fallbackbuf),
c[9], c[10], c[11], c[12], c[13], c[14], c[15]);
+
+ if (config->trace_packets)
+ fprintf(stderr, "T:%.4f: ckt %u <ntp %u outq %lu>: recv-error "
+ "%lu <d=%lu p=%lu f=%s c=%02x%02x%02x%02x%02x%02x%02x>\n",
+ log_get_timestamp(), upstream->serial,
+ upstream->recv_queue.window(),
+ (unsigned long)evbuffer_get_length(bufferevent_get_input(upstream->up_buffer)),
+ (unsigned long)hdr.seqno(),
+ (unsigned long)hdr.dlen(),
+ (unsigned long)hdr.plen(),
+ opname(hdr.opcode(), fallbackbuf),
+ c[9], c[10], c[11], c[12], c[13], c[14], c[15]);
+
return -1;
}
if (avail < hdr.total_len()) {
@@ -1319,6 +1351,16 @@ chop_conn_t::recv()
hdr.seqno(), (unsigned long)hdr.dlen(), (unsigned long)hdr.plen(),
opname(hdr.opcode(), fallbackbuf));
+ if (config->trace_packets)
+ fprintf(stderr, "T:%.4f: ckt %u <ntp %u outq %lu>: recv %lu <d=%lu p=%lu f=%s>\n",
+ log_get_timestamp(), upstream->serial,
+ upstream->recv_queue.window(),
+ (unsigned long)evbuffer_get_length(bufferevent_get_input(upstream->up_buffer)),
+ (unsigned long)hdr.seqno(),
+ (unsigned long)hdr.dlen(),
+ (unsigned long)hdr.plen(),
+ opname(hdr.opcode(), fallbackbuf));
+
evbuffer *data = evbuffer_new();
if (!data || (hdr.dlen() && evbuffer_add(data, decodebuf, hdr.dlen()))) {
log_warn(this, "failed to extract data from decode buffer");
diff --git a/src/util.cc b/src/util.cc
index 4fe576a..3900f21 100644
--- a/src/util.cc
+++ b/src/util.cc
@@ -461,8 +461,8 @@ log_open(const char *filename)
if (!log_dest)
return -1;
+ setvbuf(log_dest, 0, _IONBF, 0);
fputs("\nBrand new log:\n", log_dest);
- fflush(log_dest);
return 0;
}
@@ -494,6 +494,7 @@ log_set_method(int method, const char *filename)
return 0;
case LOG_METHOD_STDERR:
+ setvbuf(stderr, 0, _IONBF, 0);
log_dest = stderr;
return 0;
@@ -525,8 +526,20 @@ log_set_min_severity(const char* sev_string)
void
log_enable_timestamps()
{
- log_timestamps = true;
- gettimeofday(&log_ts_base, 0);
+ if (!log_timestamps) {
+ log_timestamps = true;
+ gettimeofday(&log_ts_base, 0);
+ }
+}
+
+/** Get a timestamp, as a floating-point number of seconds. */
+double
+log_get_timestamp()
+{
+ struct timeval now, delta;
+ gettimeofday(&now, 0);
+ timeval_subtract(&now, &log_ts_base, &delta);
+ return delta.tv_sec + double(delta.tv_usec) / 1e6;
}
/** True if the minimum log severity is "debug". Used in a few places
@@ -554,7 +567,6 @@ logv(int severity, const char *format, va_list ap)
vfprintf(log_dest, format, ap);
putc('\n', log_dest);
- fflush(log_dest);
}
static bool
@@ -567,13 +579,8 @@ logpfx(int severity, const char *fn)
if (!log_dest || severity < log_min_sev)
return false;
- if (log_timestamps) {
- struct timeval now, delta;
- gettimeofday(&now, 0);
- timeval_subtract(&now, &log_ts_base, &delta);
- fprintf(log_dest, "%.4f ",
- delta.tv_sec + double(delta.tv_usec) / 1e6);
- }
+ if (log_timestamps)
+ fprintf(log_dest, "%.4f ", log_get_timestamp());
fprintf(log_dest, "[%s] ", sev_to_string(severity));
if (log_min_sev == LOG_SEV_DEBUG && fn)
diff --git a/src/util.h b/src/util.h
index 62908d1..ab4038a 100644
--- a/src/util.h
+++ b/src/util.h
@@ -178,6 +178,10 @@ int log_set_min_severity(const char* sev_string);
/** Request timestamps on all log messages. */
void log_enable_timestamps();
+/** Get a timestamp consistent with the timestamps used for log messages.
+ You must have called log_enable_timestamps to use this. */
+double log_get_timestamp();
+
/** True if debug messages are being logged. Guard expensive debugging
checks with this, to avoid doing useless work when the messages are
just going to be thrown away anyway. */
More information about the tor-commits
mailing list