From c6bf28f3f739fddb11b9d2dec25d0be87453ff3f Mon Sep 17 00:00:00 2001 From: Rouli Date: Tue, 19 Mar 2013 18:21:52 +0200 Subject: adding tcp and ssl setup timestamps to get better resolution on flows performance --- libmproxy/flow.py | 19 +++++++++++++++++-- libmproxy/proxy.py | 8 ++++++++ test/test_server.py | 28 ++++++++++++++++++++++++++++ 3 files changed, 53 insertions(+), 2 deletions(-) diff --git a/libmproxy/flow.py b/libmproxy/flow.py index 7bd58dc6..c318aac8 100644 --- a/libmproxy/flow.py +++ b/libmproxy/flow.py @@ -288,8 +288,15 @@ class Request(HTTPMsg): method: HTTP method timestamp_end: Seconds since the epoch signifying request transmission ended + + tcp_setup_timestamp: Seconds since the epoch signifying remote TCP connection setup completion time + (or None, if request didn't results TCP setup) + + ssl_setup_timestamp: Seconds since the epoch signifying remote SSL encryption setup completion time + (or None, if request didn't results SSL setup) + """ - def __init__(self, client_conn, httpversion, host, port, scheme, method, path, headers, content, timestamp_start=None, timestamp_end=None): + def __init__(self, client_conn, httpversion, host, port, scheme, method, path, headers, content, timestamp_start=None, timestamp_end=None, tcp_setup_timestamp=None, ssl_setup_timestamp=None): assert isinstance(headers, ODictCaseless) self.client_conn = client_conn self.httpversion = httpversion @@ -298,6 +305,8 @@ class Request(HTTPMsg): self.timestamp_start = timestamp_start or utils.timestamp() self.timestamp_end = max(timestamp_end or utils.timestamp(), timestamp_start) self.close = False + self.tcp_setup_timestamp = tcp_setup_timestamp + self.ssl_setup_timestamp = ssl_setup_timestamp # Have this request's cookies been modified by sticky cookies or auth? self.stickycookie = False @@ -361,6 +370,8 @@ class Request(HTTPMsg): self.content = state["content"] self.timestamp_start = state["timestamp_start"] self.timestamp_end = state["timestamp_end"] + self.tcp_setup_timestamp = state["tcp_setup_timestamp"] + self.ssl_setup_timestamp = state["ssl_setup_timestamp"] def _get_state(self): return dict( @@ -374,7 +385,9 @@ class Request(HTTPMsg): headers = self.headers._get_state(), content = self.content, timestamp_start = self.timestamp_start, - timestamp_end = self.timestamp_end + timestamp_end = self.timestamp_end, + tcp_setup_timestamp = self.tcp_setup_timestamp, + ssl_setup_timestamp = self.ssl_setup_timestamp ) @classmethod @@ -391,6 +404,8 @@ class Request(HTTPMsg): state["content"], state["timestamp_start"], state["timestamp_end"], + state["tcp_setup_timestamp"], + state["ssl_setup_timestamp"] ) def __hash__(self): diff --git a/libmproxy/proxy.py b/libmproxy/proxy.py index 3d55190d..0de1c2e2 100644 --- a/libmproxy/proxy.py +++ b/libmproxy/proxy.py @@ -55,9 +55,13 @@ class ServerConnection(tcp.TCPClient): self.config = config self.scheme, self.sni = scheme, sni self.requestcount = 0 + self.tcp_setup_timestamp = None + self.ssl_setup_timestamp = None + def connect(self): tcp.TCPClient.connect(self) + self.tcp_setup_timestamp = time.time() if self.scheme == "https": clientcert = None if self.config.clientcerts: @@ -66,6 +70,7 @@ class ServerConnection(tcp.TCPClient): clientcert = path try: self.convert_to_ssl(cert=clientcert, sni=self.sni) + self.ssl_setup_timestamp = time.time() except tcp.NetLibError, v: raise ProxyError(400, str(v)) @@ -224,6 +229,9 @@ class ProxyHandler(tcp.BaseHandler): while 1: sc = self.get_server_connection(cc, scheme, host, port, self.sni) sc.send(request) + if sc.requestcount == 1: # add timestamps only for first request (others are not directly affected) + request.tcp_setup_timestamp = sc.tcp_setup_timestamp + request.ssl_setup_timestamp = sc.ssl_setup_timestamp sc.rfile.reset_timestamps() try: httpversion, code, msg, headers, content = http.read_response( diff --git a/test/test_server.py b/test/test_server.py index f12fbcee..fbd5af39 100644 --- a/test/test_server.py +++ b/test/test_server.py @@ -267,7 +267,35 @@ class TestProxy(tservers.HTTPProxTest): request = self.master.state.view[1].request assert request.timestamp_end - request.timestamp_start <= 0.1 + def test_request_tcp_setup_timestamp_presence(self): + # tests that the first request in a tcp connection has a tcp_setup_timestamp + # while others do not + connection = socket.socket(socket.AF_INET, socket.SOCK_STREAM) + connection.connect(("localhost", self.proxy.port)) + connection.send("GET http://localhost:%d/p/304:b@1k HTTP/1.1\r\n"%self.server.port) + connection.send("\r\n"); + connection.recv(5000) + connection.send("GET http://localhost:%d/p/304:b@1k HTTP/1.1\r\n"%self.server.port) + connection.send("\r\n"); + connection.recv(5000) + connection.close() + + first_request = self.master.state.view[0].request + second_request = self.master.state.view[1].request + assert first_request.tcp_setup_timestamp + assert first_request.ssl_setup_timestamp == None + assert second_request.tcp_setup_timestamp == None + assert second_request.ssl_setup_timestamp == None + +class TestProxySSL(tservers.HTTPProxTest): + ssl=True + def test_request_ssl_setup_timestamp_presence(self): + # tests that the ssl timestamp is present when ssl is used + f = self.pathod("304:b@10k") + assert f.status_code == 304 + first_request = self.master.state.view[0].request + assert first_request.ssl_setup_timestamp class MasterFakeResponse(tservers.TestMaster): def handle_request(self, m): -- cgit v1.2.3