From e0e4394dc85b026147d4b8b056428c8c4172692a Mon Sep 17 00:00:00 2001 From: Martin Mares Date: Sun, 8 Jun 2003 11:02:23 +0000 Subject: [PATCH] Better statistics. --- netgrind/netgrind.c | 68 ++++++++++++++++++++++----- netgrind/netgrind.h | 15 ++++-- netgrind/save.c | 112 +++++++++++++++++++++++++++++++++----------- netgrind/tcp.c | 48 ++++++++++++------- 4 files changed, 182 insertions(+), 61 deletions(-) diff --git a/netgrind/netgrind.c b/netgrind/netgrind.c index 6c0507d..e46dd3a 100644 --- a/netgrind/netgrind.c +++ b/netgrind/netgrind.c @@ -16,6 +16,7 @@ #include #include #include +#include #include @@ -30,12 +31,38 @@ void die(byte *msg, ...) exit(1); } +/*** MANUAL MULTIPLEXER ***/ + +static void mux_open(struct flow *f, u64 when) +{ + u32 saddr = ntohl(f->saddr); + u32 daddr = ntohl(f->daddr); + uns sport = ntohs(f->sport); + uns dport = ntohs(f->dport); + struct appl_hooks *appl = &appl_sink; + + if (dport == 80 || dport == 8080 || dport == 8081 || dport == 3128) + { + appl = &appl_asave; + save_dir = "flows"; + } + f->appl = appl; + appl->open(f, when); +} + +struct appl_hooks appl_mux = { + .open = mux_open, + .input = sink_input, + .close = sink_close +}; + /*** PCAP INTERFACE ***/ static void (*link_handler)(struct pkt *); -static struct pkt_stats stat_pcap_incomplete; +static struct pkt_stats stat_pcap_incomplete, stat_pcap_in; static uns in_count, start_sec; +static u64 last_timestamp; static int link_setup_handler(int dlt) { @@ -48,6 +75,8 @@ static int link_setup_handler(int dlt) static void got_pcap_packet(u_char *userdata UNUSED, const struct pcap_pkthdr *hdr, const u_char *pkt) { + stat_pcap_in.packets++; + stat_pcap_in.bytes += hdr->len; if (hdr->caplen != hdr->len) { stat_pcap_incomplete.packets++; @@ -58,18 +87,21 @@ static void got_pcap_packet(u_char *userdata UNUSED, const struct pcap_pkthdr *h { if (!in_count) start_sec = hdr->ts.tv_sec; - fprintf(stderr, "%d packets, %d seconds, %d conns (%d still open)\r", + fprintf(stderr, "%d packets, %d seconds, %d conns (%d open)\r", in_count, (int)hdr->ts.tv_sec - start_sec, - tcp_total_flows, tcp_num_flows); + cnt_tcp_flows, tcp_num_flows); fflush(stderr); } in_count++; struct pkt *p = pkt_new(0, hdr->len); memcpy(pkt_append(p, hdr->len), pkt, hdr->len); p->timestamp = (u64)hdr->ts.tv_sec * 1000000 + hdr->ts.tv_usec; + last_timestamp = p->timestamp; link_handler(p); } +/*** MAIN ***/ + static void usage(void) { fprintf(stderr, "Usage: netgrind [] \n\ @@ -79,6 +111,8 @@ static void usage(void) -d Dump connections to a given directory\n\ -D Dump connections with more details\n\ -f Apply filter expression\n\ +-s Dump connection summary\n\ +-t Calculate statistics only\n\ -w TCP: Wait for ACK before processing packets\n\ "); exit(1); @@ -93,8 +127,8 @@ int main(int argc, char **argv) byte *filter = NULL; struct bpf_program filter_prog; - tcp_default_appl = &appl_sink; - while ((c = getopt(argc, argv, "ac:d:D:f:w")) >= 0) + tcp_default_appl = &appl_mux; + while ((c = getopt(argc, argv, "ac:d:D:f:stw")) >= 0) switch (c) { case 'a': @@ -117,6 +151,12 @@ int main(int argc, char **argv) case 'w': tcp_wait_for_ack = 1; break; + case 's': + tcp_default_appl = &appl_summary; + break; + case 't': + tcp_default_appl = &appl_sink; + break; default: usage(); } @@ -138,28 +178,32 @@ int main(int argc, char **argv) } if (pcap_loop(pcap, max_packets, got_pcap_packet, NULL) < 0) die("Capture failed: %s", pcap_geterr(pcap)); - tcp_cleanup(); - printf("Pcap: %Ld(%Ld) incomplete\n", + tcp_cleanup(last_timestamp); + printf("# Netgrind statistics:\n"); + printf("# Pcap: %Ld(%Ld) in, %Ld(%Ld) incomplete\n", + stat_pcap_in.packets, stat_pcap_in.bytes, stat_pcap_incomplete.packets, stat_pcap_incomplete.bytes); - printf("Link: %Ld(%Ld) in, %Ld(%Ld) dwarves, %Ld(%Ld) strangers, %Ld(%Ld) ARPs\n", + printf("# Link: %Ld(%Ld) in, %Ld(%Ld) dwarves, %Ld(%Ld) strangers, %Ld(%Ld) ARPs\n", stat_link_in.packets, stat_link_in.bytes, stat_link_dwarf.packets, stat_link_dwarf.bytes, stat_link_unknown.packets, stat_link_unknown.bytes, stat_link_arp.packets, stat_link_arp.bytes); - printf("IP: %Ld(%Ld) in, %Ld(%Ld) invalid, %Ld(%Ld) boring, %Ld(%Ld) fragmented, %Ld(%Ld) bad checksum\n", + printf("# IP: %Ld(%Ld) in, %Ld(%Ld) invalid, %Ld(%Ld) boring, %Ld(%Ld) fragmented, %Ld(%Ld) bad checksum\n", stat_ip_in.packets, stat_ip_in.bytes, stat_ip_invalid.packets, stat_ip_invalid.bytes, stat_ip_uninteresting.packets, stat_ip_uninteresting.bytes, stat_ip_fragmented.packets, stat_ip_fragmented.bytes, stat_ip_badsum.packets, stat_ip_badsum.bytes); - printf("TCP: %Ld(%Ld) in, %Ld(%Ld) invalid, %Ld(%Ld) bad checksum, %Ld(%Ld) unmatched, %Ld(%Ld) on closed connections, %Ld(%Ld) in unexpected state; %d flows\n", + printf("# TCP: %Ld(%Ld) in, %Ld(%Ld) invalid, %Ld(%Ld) bad checksum, %Ld(%Ld) unmatched, %Ld(%Ld) on closed connections, %Ld(%Ld) in unexpected state\n", stat_tcp_in.packets, stat_tcp_in.bytes, stat_tcp_invalid.packets, stat_tcp_invalid.bytes, stat_tcp_badsum.packets, stat_tcp_badsum.bytes, stat_tcp_unmatched.packets, stat_tcp_unmatched.bytes, stat_tcp_on_closed.packets, stat_tcp_on_closed.bytes, - stat_tcp_bad_state.packets, stat_tcp_bad_state.bytes, - tcp_total_flows); + stat_tcp_bad_state.packets, stat_tcp_bad_state.bytes); + printf("# Flows: %d total: %d closed, %d reset, %d timed out, %d overlap end, %d corrupted\n", + cnt_tcp_flows, cnt_tcp_causes[CAUSE_CLOSE], cnt_tcp_causes[CAUSE_RESET], + cnt_tcp_causes[CAUSE_TIMEOUT], cnt_tcp_causes[CAUSE_DOOMSDAY], cnt_tcp_causes[CAUSE_CORRUPT]); pcap_close(pcap); return 0; } diff --git a/netgrind/netgrind.h b/netgrind/netgrind.h index fca6c53..2f53adf 100644 --- a/netgrind/netgrind.h +++ b/netgrind/netgrind.h @@ -27,7 +27,7 @@ void ip_got_packet(struct pkt *p); extern struct pkt_stats stat_tcp_in, stat_tcp_invalid, stat_tcp_badsum, stat_tcp_unmatched, stat_tcp_on_closed, stat_tcp_bad_state; -extern uns tcp_total_flows, tcp_num_flows, tcp_max_flows; +extern uns cnt_tcp_flows, cnt_tcp_causes[], tcp_num_flows, tcp_max_flows; /* config switches */ extern uns tcp_arrival_times; @@ -58,13 +58,16 @@ struct flow { void *appl_data; struct pipe pipe[2]; struct pkt_stats stat_raw; + uns cnt_unexpected; }; enum close_cause { CAUSE_CLOSE, CAUSE_RESET, CAUSE_TIMEOUT, - CAUSE_DOOMSDAY + CAUSE_DOOMSDAY, + CAUSE_CORRUPT, + CAUSE_MAX }; struct appl_hooks { @@ -76,13 +79,17 @@ struct appl_hooks { struct iphdr; void tcp_init(void); -void tcp_cleanup(void); +void tcp_cleanup(u64 timestamp); void tcp_got_packet(struct iphdr *iph, struct pkt *p); extern struct appl_hooks *tcp_default_appl; /* save.c */ -extern struct appl_hooks appl_sink, appl_save, appl_asave; +extern struct appl_hooks appl_sink, appl_save, appl_asave, appl_summary; extern uns asave_width; extern byte *save_dir; + +void sink_open(struct flow *f, u64 when); +void sink_close(struct flow *f, int cause, u64 when); +void sink_input(struct flow *f, int dir, struct pkt *p); diff --git a/netgrind/save.c b/netgrind/save.c index 69c31da..56d496e 100644 --- a/netgrind/save.c +++ b/netgrind/save.c @@ -14,19 +14,32 @@ #include #include #include +#include #include byte *save_dir; -static void sink_open(struct flow *f UNUSED, u64 when UNUSED) +#define TIMESTAMP_LEN 32 +static void format_timestamp(byte *buf, u64 time) { + struct tm *tm; + time_t t = time / 1000000; + tm = localtime(&t); + ASSERT(tm); + int len = strftime(buf, TIMESTAMP_LEN, "%Y-%m-%d %H:%M:%S", tm); + ASSERT(len); + sprintf(buf+len, ".%03d", (uns)(time%1000000)/1000); } -static void sink_close(struct flow *f UNUSED, int cause UNUSED, u64 when UNUSED) +void sink_open(struct flow *f UNUSED, u64 when UNUSED) { } -static void sink_input(struct flow *f UNUSED, int dir UNUSED, struct pkt *p) +void sink_close(struct flow *f UNUSED, int cause UNUSED, u64 when UNUSED) +{ +} + +void sink_input(struct flow *f UNUSED, int dir UNUSED, struct pkt *p) { pkt_free(p); } @@ -48,7 +61,9 @@ static void save_open(struct flow *f, u64 when UNUSED) for (uns dir=0; dir<2; dir++) { byte name[256]; - sprintf(name, "%s/%06u-%04x:%d-%04x:%d-%c", save_dir, save_counter, f->saddr, f->sport, f->daddr, f->dport, 'A' + dir); + sprintf(name, "%s/%06u-%d.%d.%d.%d:%d-%d.%d.%d.%d:%d-%c", save_dir, save_counter, + IPQUAD(f->saddr), ntohs(f->sport), IPQUAD(f->daddr), ntohs(f->dport), + 'A' + dir); if (!(s->file[dir] = fopen(name, "w"))) die("Unable to create %s: %m", name); } @@ -89,13 +104,8 @@ static void asave_event(struct asave_state *s, u64 time, byte *msg, ...) va_list args; va_start(args, msg); - if (time == ~(u64)0) - fprintf(s->file, "????.??? "); - else - { - time -= s->start_time; - fprintf(s->file, "%04d.%03d ", (int)(time/1000000), (int)(time%1000000)/1000); - } + time -= s->start_time; + fprintf(s->file, "%04d.%03d ", (int)(time/1000000), (int)(time%1000000)/1000); vfprintf(s->file, msg, args); va_end(args); } @@ -103,21 +113,25 @@ static void asave_event(struct asave_state *s, u64 time, byte *msg, ...) static void asave_open(struct flow *f, u64 when) { struct asave_state *s = xmalloc(sizeof(*s)); - byte name[256]; + byte name[256], stamp[TIMESTAMP_LEN]; static uns asave_counter; - sprintf(name, "%s/%06u-%04x:%d-%04x:%d", save_dir, asave_counter++, f->saddr, f->sport, f->daddr, f->dport); + sprintf(name, "%s/%06u-%d.%d.%d.%d:%d-%d.%d.%d.%d:%d", save_dir, asave_counter++, + IPQUAD(f->saddr), ntohs(f->sport), + IPQUAD(f->daddr), ntohs(f->dport)); if (!(s->file = fopen(name, "w"))) die("Unable to create %s: %m", name); f->appl_data = s; s->start_time = when; - asave_event(s, when, "Initiated: %d.%d.%d.%d:%d -> %d.%d.%d.%d:%d\n", + asave_event(s, when, "Connection: %d.%d.%d.%d:%d -> %d.%d.%d.%d:%d\n", IPQUAD(f->saddr), ntohs(f->sport), IPQUAD(f->daddr), ntohs(f->dport)); + format_timestamp(stamp, when); + asave_event(s, when, "Initiated on: %s\n", stamp); } static void asave_close(struct flow *f, int cause, u64 when) { struct asave_state *s = f->appl_data; - static byte *close_reasons[] = { "Close", "Connection reset", "Timeout", "Doomsday" }; + static byte *close_reasons[] = { "Close", "Connection reset", "Timeout", "Doomsday", "Corrupted" }; asave_event(s, when, "Terminated: %s\n", close_reasons[cause]); asave_event(s, when, "TX %Ld bytes in %Ld packets, RX %Ld bytes in %Ld packets\n", f->pipe[1].stat.bytes, f->pipe[1].stat.packets, @@ -135,17 +149,8 @@ static void asave_input(struct flow *f, int dir, struct pkt *p) asave_event(s, p->timestamp, (dir ? ">>> " : "<<< ")); uns len = pkt_len(p); uns cnt = 0; - uns last_char = 0; for (uns i=0; i= asave_width) - { - if (last_char != '\n') - fputc('\\', s->file); - fputc('\n', s->file); - asave_event(s, p->timestamp, (dir ? ">>> " : "<<< ")); - cnt = 0; - } uns c = p->data[i]; if (c == '\n') cnt = ~0U; @@ -159,12 +164,19 @@ static void asave_input(struct flow *f, int dir, struct pkt *p) fprintf(s->file, "<%02x>", c); cnt += 4; } - last_char = c; + if (cnt >= asave_width+10 || (cnt == asave_width && i < len-1 && p->data[i+1] != '\n')) + { + if (c != '\n') + fputc('\\', s->file); + fputc('\n', s->file); + if (i < len-1) + asave_event(s, p->timestamp, (dir ? ">>> " : "<<< ")); + cnt = 0; + } } if (cnt) { - if (last_char != '\n') - fputc('\\', s->file); + fputc('\\', s->file); fputc('\n', s->file); } pkt_free(p); @@ -175,3 +187,49 @@ struct appl_hooks appl_asave = { .input = asave_input, .close = asave_close }; + +struct summary_state { + u64 estab_time; +}; + +static void summary_open(struct flow *f, u64 when) +{ + struct summary_state *s = xmalloc(sizeof(*s)); + f->appl_data = s; + s->estab_time = when; +} + +static void summary_close(struct flow *f, int cause, u64 when) +{ + static int summary_cnt; + if (!summary_cnt++) + printf("# timestamp source destination elapsed close tx rx oh KB/s\n"); + /* 2003-06-06 22:38:34.076 81.27.194.19:1165 195.113.31.123:22 1.604 OK 1991 12656 11% 8.914 */ + + struct summary_state *s = f->appl_data; + u64 duration = when - s->estab_time; + byte src[22], dst[22]; + byte stamp[TIMESTAMP_LEN]; + static byte *sum_causes[] = { "OK", "RE", "TO", "DD", "CO" }; + format_timestamp(stamp, s->estab_time); + sprintf(src, "%d.%d.%d.%d:%d", IPQUAD(f->saddr), ntohs(f->sport)); + sprintf(dst, "%d.%d.%d.%d:%d", IPQUAD(f->daddr), ntohs(f->dport)); + double braw = f->stat_raw.bytes; + double beff = f->pipe[0].stat.bytes + f->pipe[1].stat.bytes; + double over = 100 * ((braw - beff) / braw); + double avs = duration ? ((beff / ((double)duration/1000000)) / 1024) : 1e30; + printf("%s %-21s %-21s %6d.%03d %s %7Ld %7Ld %3d%% ", + stamp, src, dst, + (uns)(duration/1000000), (uns)(duration%1000000)/1000, sum_causes[cause], + f->pipe[1].stat.bytes, f->pipe[0].stat.bytes, + CLAMP((int)over,0,100)); + printf((avs < 100) ? "%6.3f" : "%6.0f", MIN(avs, 999999)); + putchar('\n'); + xfree(s); +} + +struct appl_hooks appl_summary = { + .open = summary_open, + .input = sink_input, + .close = summary_close +}; diff --git a/netgrind/tcp.c b/netgrind/tcp.c index 338eaaa..e78cb64 100644 --- a/netgrind/tcp.c +++ b/netgrind/tcp.c @@ -25,7 +25,7 @@ struct pkt_stats stat_tcp_in, stat_tcp_invalid, stat_tcp_badsum, stat_tcp_unmatched, stat_tcp_on_closed, stat_tcp_bad_state; -uns tcp_total_flows; +uns cnt_tcp_flows, cnt_tcp_causes[CAUSE_MAX]; uns tcp_arrival_times, tcp_wait_for_ack; struct appl_hooks *tcp_default_appl; @@ -109,7 +109,7 @@ static struct flow *flow_create(u32 saddr, u32 daddr, u32 sport, u32 dport) flow_hash[h] = f; flow_heap[++tcp_num_flows] = f; f->heap_pos = tcp_num_flows; - tcp_total_flows++; + cnt_tcp_flows++; return f; } @@ -119,17 +119,14 @@ static void flow_set_timeout(struct flow *f, u32 when) HEAP_CHANGE(struct flow *, flow_heap, tcp_num_flows, FLOW_HEAP_LESS, FLOW_HEAP_SWAP, f->heap_pos); } -static uns flow_now(struct pkt *p) +static uns timestamp_to_now(u64 timestamp) { - return p->timestamp >> 20; + return timestamp >> 20; } -static u64 flow_now_to_time(uns now) +static u64 now_to_timestamp(uns now) { - if (now == ~0U) - return ~(u64)0; - else - return (u64)now << 20; + return (u64)now << 20; } static inline int tcp_seq_le(u32 a, u32 b) @@ -142,15 +139,26 @@ static inline int tcp_seq_lt(u32 a, u32 b) return (a != b && tcp_seq_le(a, b)); } -static void tcp_time_step(uns now) +static void tcp_time_step(uns now, uns doomsday) { - while (tcp_num_flows && flow_heap[1]->timeout <= now) + while (tcp_num_flows && (flow_heap[1]->timeout <= now || doomsday)) { struct flow *f = flow_heap[1]; HEAP_DELMIN(struct flow *, flow_heap, tcp_num_flows, FLOW_HEAP_LESS, FLOW_HEAP_SWAP); - DBG("TIMEOUT for flow %p(%s/%s)\n", f, pipe_state_names[f->pipe[0].state], pipe_state_names[f->pipe[1].state]); + DBG("%s for flow %p(%s/%s)\n", (doomsday ? "DOOMSDAY" : "TIMEOUT"), f, + pipe_state_names[f->pipe[0].state], pipe_state_names[f->pipe[1].state]); if (f->pipe[0].state != FLOW_FINISHED || f->pipe[1].state != FLOW_FINISHED) - f->appl->close(f, (now == ~0U) ? CAUSE_DOOMSDAY : CAUSE_TIMEOUT, flow_now_to_time(now)); + { + uns cause; + if (f->cnt_unexpected) + cause = CAUSE_CORRUPT; + else if (doomsday) + cause = CAUSE_DOOMSDAY; + else + cause = CAUSE_TIMEOUT; + cnt_tcp_causes[cause]++; + f->appl->close(f, cause, now_to_timestamp(now)); + } for (uns i=0; i<2; i++) { struct pkt *p; @@ -244,9 +252,9 @@ void tcp_got_packet(struct iphdr *iph, struct pkt *p) u16 len; } fakehdr; struct pkt *q; - uns now = flow_now(p); + uns now = timestamp_to_now(p->timestamp); - tcp_time_step(now); + tcp_time_step(now, 0); pkt_account(&stat_tcp_in, p); if (!(tcph = pkt_peek(p, sizeof(*tcph)))) @@ -329,6 +337,7 @@ void tcp_got_packet(struct iphdr *iph, struct pkt *p) if (tcph->rst) { DBG("RESET\n"); + cnt_tcp_causes[CAUSE_RESET]++; f->appl->close(f, CAUSE_RESET, p->timestamp); a->state = b->state = FLOW_FINISHED; flow_set_timeout(f, now + 120); @@ -394,6 +403,7 @@ void tcp_got_packet(struct iphdr *iph, struct pkt *p) if (a->state == FLOW_FINISHED) { DBG("CLOSED BOTH WAYS\n"); + cnt_tcp_causes[CAUSE_CLOSE]++; f->appl->close(f, CAUSE_CLOSE, p->timestamp); flow_set_timeout(f, now + 300); /* FIXME */ goto drop; @@ -404,7 +414,7 @@ void tcp_got_packet(struct iphdr *iph, struct pkt *p) else if (tcp_seq_lt(a->queue_start_seq, ack)) { DBG("DAMNED, ACK FOR UNCAUGHT DATA!\n"); - goto invalid; + goto unexpected; } else if (b->state == FLOW_SYN_SENT_ACK || b->state == FLOW_SYN_SENT) goto unex; @@ -465,6 +475,8 @@ void tcp_got_packet(struct iphdr *iph, struct pkt *p) unex: DBG("UNEXPECTED\n"); + unexpected: + f->cnt_unexpected++; pkt_account(&stat_tcp_bad_state, p); goto drop; @@ -480,7 +492,7 @@ void tcp_init(void) flow_rehash(); } -void tcp_cleanup(void) +void tcp_cleanup(u64 timestamp) { - tcp_time_step(~0U); + tcp_time_step(timestamp_to_now(timestamp), 1); } -- 2.39.2