Combine tcpdump packets into requests and response times.

requestor.awk

#!/usr/bin/awk -f

# #
# 
# Inspired by http://www.percona.com/doc/percona-toolkit/2.1/pt-tcp-model.html
# 
# Example usage: 
# $ tcpdump -i any -s 0 -nnq -tt  'tcp port 80 and (((ip[2:2] - ((ip[0]&0xf)<<2))  - ((tcp[12]&0xf0)>>2)) != 0)'
# 1349692787.492311 IP X.X.X.X.XXXX > X.X.X.X.XXXX: tcp 1448
# $ ./requestor.awk dump.file
# 1000000029 2012-10-08 23:39:45 X.X.X.X.XXXX 0.269577 X.X.X.X.XXXX
# #
BEGIN {
	count = 1000000000;
}
{
 # time is in unix timestamp format
 time = $1;
 # ignore after the ':'
 gsub(/\:\ .*/, "", $0);
 sport = $3;
 gsub(/.*\./, "", sport);
 dport = $5;
 gsub(/.*\./, "", dport);
 # smaller port is likely to be the server
 if (sport > dport) {
	server = $3; 
	client=$5;
	status="r";
 } else {
	server=$5;
	client =$3;
	status="s";
 } 
 # print request[client]status" "sport"->"dport;
 if (client != "" && request[client]status == "s") {
 	# create new request
	request[client] = "s";
	request[client, "id"] = count++;
	request[client, "server"] = server;
	request[client, "sendStartTime"] = request[client, "sendEndTime"] = time;
	request[client, "receiveStartTime"] = request[client, "receiveEndTime"] = "";
 } else if (request[client]status == "ss") {
 	request[client, "sendEndTime"] = time;
 } else if (request[client]status == "sr") {
 	request[client] = "r";
 	request[client, "receiveStartTime"] = request[client, "receiveEndTime"] = time;
 } else if (request[client]status == "rr") {
 	request[client, "receiveEndTime"] = time;
 } else if (request[client]status == "rs") {
 	# log completed request
	r = request[client, "receiveStartTime"] - request[client, "sendEndTime"];
	# nicetime needs gnu awk! 
	nicetime = strftime("%Y-%m-%d %H:%M:%S",request[client, "sendEndTime"]);
	printf "%s %s %s %.8f %s\n", request[client, "id"], nicetime, client, r, request[client, "server"];

 	# create new request
	request[client] = "s";
	request[client, "id"] = count++;
	request[client, "server"] = server;
	request[client, "sendStartTime"] = request[client, "sendEndTime"] = time;
	request[client, "receiveStartTime"] = request[client, "receiveEndTime"] = "";
 } else if (request[client]status == "r") {
 	# response without request
 	print "ERROR:"$0;
 }
}
END {
	# flush the rest
	for (client in request) {
		if (request[client] == "r") {
			r = request[client, "receiveStartTime"] - request[client, "sendEndTime"];
			# nicetime needs gnu awk! 
			nicetime = strftime("%Y-%m-%d %H:%M:%S",request[client, "sendEndTime"]);
			printf "%s %s %s %.8f %s\n", request[client, "id"], nicetime, client, r, request[client, "server"];
		} else if (request[client] == "s") {
			print "ERROR:"request[client, "id"]" "client" "request[client, "server"];;
		}
	}
}

responses.awk

#!/usr/bin/awk -f

# #
# Assembles tcpdump output into request-response pairs and calculates approx response times.
# Assumes that lower port numbers belong to servers, and higher port numbers -- clients. Asusmes a client-request-server-response model
# Server port guessing logic can be overriden for particular ports by setting an env variable SERVER_PORTS with comma-reparated server port numbers
# 
# Example usage: 
# $ tcpdump -i any -s 0 -nnq -tt  'tcp and (((ip[2:2] - ((ip[0]&0xf)<<2))  - ((tcp[12]&0xf0)>>2)) != 0)' | tee dump.file
# 1349692787.492311 IP X.X.X.X.XXXX > X.X.X.X.XXXX: tcp 1448
# $ ./responses.awk dump.file
# 1000000029 2012-10-08 23:39:45 X.X.X.X.XXXX X.X.X.X.XXXX 0.269 615 55203
# #
function print_req(requests, key) {
    _rt = requests[key, "response_ts_end"] - requests[key, "ts_end"];
    _nicetime = strftime("%Y-%m-%d %H:%M:%S",requests[key, "response_ts_end"]);
    _client = requests[key, "src_addr"]":"requests[key, "src_port"];
    _server = requests[key, "dst_addr"]":"requests[key, "dst_port"];
    _len = requests[key, "response_size"];
    printf "%s %s %s %s %.3f %d %d \n", requests[key], _nicetime, _client, _server, _rt*1000, requests[key, "size"], _len;
}
BEGIN {
	count = 1000000000;
    start_ts = -1;
    end_ts = -1;
    
    if ("SERVER_PORTS" in ENVIRON) {
        split(ENVIRON["SERVER_PORTS"], ports, ",");
        for (port in ports) {
            SERVER_PORTS[ports[port]] = port;
        }
    }
}
{
 # time is in unix timestamp format
 time = $1;
 if (start_ts == -1) {
    start_ts = time;
 }
 end_ts = time;
 
 len = $NF;
 # ignore after the ':'
 sub(/: .*/, "", $0);

 src = $3;
 sport = $3;
 sub(/\.[0-9]+$/, "", src);
 sub(/.*\./, "", sport);

 dst = $5;
 dport = $5;
 sub(/\.[0-9]+$/, "", dst);
 sub(/.*\./, "", dport);

 sport+=0;
 dport+=0;

 # smaller port is likely to be the server -- used for responses
 if (sport in SERVER_PORTS) {
	is_request = 0;
	server_addr = src;
	client_addr = dst;
    server_port = sport;
    client_port = dport;
 } else if (dport in SERVER_PORTS) {
	is_request = 1;
	server_addr = dst;
	client_addr = src;
    server_port = dport;
    client_port = sport;
 } else if (sport < dport) {
	is_request = 0;
	server_addr = src;
	client_addr = dst;
    server_port = sport;
    client_port = dport;
 } else {
	is_request = 1;
	server_addr = dst;
	client_addr = src;
    server_port = dport;
    client_port = sport;
 }

 client = client_addr":"client_port;
 server = server_addr":"server_port;

 key = client;
 if (is_request) {
     if (!(key in requests) || requests[key] == -1) {
         ## new request
         requests[key] = count;
         requests[key, "ts_start"] = time;
         requests[key, "ts_end"] = time;
         requests[key, "size"] = len;
         requests[key, "src_addr"] = client_addr;
         requests[key, "src_port"] = client_port;
         requests[key, "dst_addr"] = server_addr;
         requests[key, "dst_port"] = server_port;
     } else {
         ## subsequent request
         requests[key, "size"] = len;
         requests[key, "ts_start"] = time;
         requests[key, "ts_end"] = time;
    }
    requests[key] = count++;
    requests[key, "ts_start"] = time;
    requests[key, "ts_end"] = time;
 } else {
     if (!(key in requests)) {
         ## response to an unseen req
         requests[key] = -1;
         requests[key, "ts_start"] = start_ts;
         requests[key, "ts_end"] = start_ts;
         requests[key, "size"] = 0;
         requests[key, "src_addr"] = client_addr;
         requests[key, "src_port"] = client_port;
         requests[key, "dst_addr"] = server_addr;
         requests[key, "dst_port"] = server_port;
     } else {
         ## response to a seen req
     }
     if (!(key""SUBSEP"response_ts_start" in requests)) {
         ## first response
         requests[key, "response_ts_start"] = time;
         requests[key, "response_ts_end"] = time;
         requests[key, "response_size"] = len;
     } else {
         ## subsequent response
         requests[key, "response_ts_end"] = time;
         requests[key, "response_size"] = len;
     }
     print_req(requests, key);
 }

}
END {
}