From 3049f8131243a60f301114203064fc00e386098e Mon Sep 17 00:00:00 2001 From: Jason Eric Klaes Hoetger Date: Sun, 12 Jul 2015 12:16:39 -0700 Subject: [PATCH 1/4] Allow bypassing filters on a per-request basis --- .../filters/BrowserMobHttpFilterChain.java | 6 +- .../lightbody/bmp/proxy/InterceptorTest.java | 60 ++++++++++++++++++- .../net/lightbody/bmp/BrowserMobProxy.java | 12 ++++ 3 files changed, 76 insertions(+), 2 deletions(-) diff --git a/browsermob-core-littleproxy/src/main/java/net/lightbody/bmp/filters/BrowserMobHttpFilterChain.java b/browsermob-core-littleproxy/src/main/java/net/lightbody/bmp/filters/BrowserMobHttpFilterChain.java index 25a6500cd..6f34b6e08 100644 --- a/browsermob-core-littleproxy/src/main/java/net/lightbody/bmp/filters/BrowserMobHttpFilterChain.java +++ b/browsermob-core-littleproxy/src/main/java/net/lightbody/bmp/filters/BrowserMobHttpFilterChain.java @@ -40,7 +40,11 @@ public BrowserMobHttpFilterChain(BrowserMobProxyServer proxyServer, HttpRequest // instantiate all HttpFilters using the proxy's filter factories for (HttpFiltersSource filterFactory : proxyServer.getFilterFactories()) { HttpFilters filter = filterFactory.filterRequest(originalRequest, ctx); - filters.add(filter); + // allow filter factories to avoid adding a filter on a per-request basis by returning a null + // HttpFilters instance + if (filter != null) { + filters.add(filter); + } } } else { filters = Collections.emptyList(); diff --git a/browsermob-core-littleproxy/src/test/java/net/lightbody/bmp/proxy/InterceptorTest.java b/browsermob-core-littleproxy/src/test/java/net/lightbody/bmp/proxy/InterceptorTest.java index c7c5f38b1..c4bbe826b 100644 --- a/browsermob-core-littleproxy/src/test/java/net/lightbody/bmp/proxy/InterceptorTest.java +++ b/browsermob-core-littleproxy/src/test/java/net/lightbody/bmp/proxy/InterceptorTest.java @@ -38,6 +38,7 @@ import java.io.IOException; import java.util.Arrays; import java.util.concurrent.atomic.AtomicBoolean; +import java.util.concurrent.atomic.AtomicInteger; import java.util.concurrent.atomic.AtomicReference; import static org.hamcrest.Matchers.endsWith; @@ -634,6 +635,64 @@ public int getMaximumResponseBufferSizeInBytes() { } } + @Test + public void testCanBypassFilterForRequest() throws IOException { + mockServer.when(request() + .withMethod("GET") + .withPath("/bypassfilter"), + Times.exactly(2)) + .respond(response() + .withStatusCode(200) + .withBody("success")); + + proxy = new BrowserMobProxyServer(); + proxy.start(); + + final AtomicInteger filtersSourceHitCount = new AtomicInteger(); + final AtomicInteger filterHitCount = new AtomicInteger(); + + proxy.addFirstHttpFilterFactory(new HttpFiltersSourceAdapter() { + @Override + public HttpFilters filterRequest(HttpRequest originalRequest) { + if (filtersSourceHitCount.getAndIncrement() == 0) { + return null; + } else { + return new HttpFiltersAdapter(originalRequest) { + @Override + public void serverToProxyResponseReceived() { + filterHitCount.incrementAndGet(); + } + }; + } + } + }); + + // during the first request, the filterRequest(...) method should return null, which will prevent the filter instance from + // being added to the filter chain + try (CloseableHttpClient httpClient = ProxyServerTest.getNewHttpClient(proxy.getPort())) { + CloseableHttpResponse response = httpClient.execute(new HttpGet("http://localhost:" + mockServerPort + "/bypassfilter")); + String responseBody = IOUtils.toStringAndClose(response.getEntity().getContent()); + + assertEquals("Expected server to return a 200", 200, response.getStatusLine().getStatusCode()); + assertEquals("Did not receive expected response from mock server", "success", responseBody); + } + + assertEquals("Expected filters source to be invoked on first request", 1, filtersSourceHitCount.get()); + assertEquals("Expected filter instance to be bypassed on first request", 0, filterHitCount.get()); + + // during the second request, the filterRequest(...) method will return a filter instance, which should be invoked during processing + try (CloseableHttpClient httpClient = ProxyServerTest.getNewHttpClient(proxy.getPort())) { + CloseableHttpResponse response = httpClient.execute(new HttpGet("http://localhost:" + mockServerPort + "/bypassfilter")); + String responseBody = IOUtils.toStringAndClose(response.getEntity().getContent()); + + assertEquals("Expected server to return a 200", 200, response.getStatusLine().getStatusCode()); + assertEquals("Did not receive expected response from mock server", "success", responseBody); + } + + assertEquals("Expected filters source to be invoked again on second request", 2, filtersSourceHitCount.get()); + assertEquals("Expected filter instance to be invoked on second request (only)", 1, filterHitCount.get()); + } + @Test public void testHttpResponseFilterMessageInfoPopulated() throws IOException { mockServer.when(request() @@ -828,7 +887,6 @@ public void filterResponse(HttpResponse response, HttpMessageContents contents, } } - @Test public void testHttpsResponseFilterMessageInfoPopulated() throws IOException { mockServer.when(request() diff --git a/browsermob-core/src/main/java/net/lightbody/bmp/BrowserMobProxy.java b/browsermob-core/src/main/java/net/lightbody/bmp/BrowserMobProxy.java index 14249156f..5306ab401 100644 --- a/browsermob-core/src/main/java/net/lightbody/bmp/BrowserMobProxy.java +++ b/browsermob-core/src/main/java/net/lightbody/bmp/BrowserMobProxy.java @@ -1,5 +1,7 @@ package net.lightbody.bmp; +import io.netty.channel.ChannelHandlerContext; +import io.netty.handler.codec.http.HttpRequest; import net.lightbody.bmp.core.har.Har; import net.lightbody.bmp.filters.RequestFilter; import net.lightbody.bmp.filters.ResponseFilter; @@ -519,6 +521,11 @@ public interface BrowserMobProxy { /** * Adds a new filter factory (request/response interceptor) to the beginning of the HttpFilters chain. *

+ * Usage note: The actual filter (interceptor) instance is created on every request by implementing the + * {@link HttpFiltersSource#filterRequest(HttpRequest, ChannelHandlerContext)} method and returning an + * {@link org.littleshoot.proxy.HttpFilters} instance (typically, a subclass of {@link org.littleshoot.proxy.HttpFiltersAdapter}). + * To disable or bypass a filter on a per-request basis, the filterRequest() method may return null. + *

* Note: This method is only available in the LittleProxy-based implementation of BrowserMob Proxy. The legacy {@link net.lightbody.bmp.proxy.ProxyServer} * implementation will not use the HTTP filters. You must use the addRequestInterceptor() and addResponseInterceptor() methods in * {@link net.lightbody.bmp.proxy.LegacyProxyServer} when using the legacy ProxyServer implementation. @@ -530,6 +537,11 @@ public interface BrowserMobProxy { /** * Adds a new filter factory (request/response interceptor) to the end of the HttpFilters chain. *

+ * Usage note: The actual filter (interceptor) instance is created on every request by implementing the + * {@link HttpFiltersSource#filterRequest(HttpRequest, ChannelHandlerContext)} method and returning an + * {@link org.littleshoot.proxy.HttpFilters} instance (typically, a subclass of {@link org.littleshoot.proxy.HttpFiltersAdapter}). + * To disable or bypass a filter on a per-request basis, the filterRequest() method may return null. + *

* Note: This method is only available in the LittleProxy-based implementation of BrowserMob Proxy. The legacy {@link net.lightbody.bmp.proxy.ProxyServer} * implementation will not use the HTTP filters. You must use the addRequestInterceptor() and addResponseInterceptor() methods in * {@link net.lightbody.bmp.proxy.LegacyProxyServer} when using the legacy ProxyServer implementation. From 4ae77aebdb1540763e6b689ec84de11d1502607d Mon Sep 17 00:00:00 2001 From: Jason Eric Klaes Hoetger Date: Sun, 12 Jul 2015 13:40:09 -0700 Subject: [PATCH 2/4] Added HAR error messages for failed HTTP CONNECTs --- .../lightbody/bmp/BrowserMobProxyServer.java | 21 +- .../bmp/filters/HarCaptureFilter.java | 119 +++---- .../filters/HttpsConnectHarCaptureFilter.java | 313 ++++++++++++++++++ .../bmp/filters/util/HarCaptureUtil.java | 80 +++++ .../net/lightbody/bmp/proxy/NewHarTest.groovy | 59 ++-- 5 files changed, 487 insertions(+), 105 deletions(-) create mode 100644 browsermob-core-littleproxy/src/main/java/net/lightbody/bmp/filters/HttpsConnectHarCaptureFilter.java create mode 100644 browsermob-core-littleproxy/src/main/java/net/lightbody/bmp/filters/util/HarCaptureUtil.java diff --git a/browsermob-core-littleproxy/src/main/java/net/lightbody/bmp/BrowserMobProxyServer.java b/browsermob-core-littleproxy/src/main/java/net/lightbody/bmp/BrowserMobProxyServer.java index 405f2cba2..cc0fdaff4 100644 --- a/browsermob-core-littleproxy/src/main/java/net/lightbody/bmp/BrowserMobProxyServer.java +++ b/browsermob-core-littleproxy/src/main/java/net/lightbody/bmp/BrowserMobProxyServer.java @@ -16,6 +16,7 @@ import net.lightbody.bmp.filters.BlacklistFilter; import net.lightbody.bmp.filters.BrowserMobHttpFilterChain; import net.lightbody.bmp.filters.HarCaptureFilter; +import net.lightbody.bmp.filters.HttpsConnectHarCaptureFilter; import net.lightbody.bmp.filters.HttpsHostCaptureFilter; import net.lightbody.bmp.filters.HttpsOriginalHostCaptureFilter; import net.lightbody.bmp.filters.LatencyFilter; @@ -52,6 +53,7 @@ import org.littleshoot.proxy.HttpProxyServer; import org.littleshoot.proxy.HttpProxyServerBootstrap; import org.littleshoot.proxy.impl.DefaultHttpProxyServer; +import org.littleshoot.proxy.impl.ProxyUtils; import org.openqa.selenium.Proxy; import org.slf4j.Logger; import org.slf4j.LoggerFactory; @@ -1377,7 +1379,24 @@ protected void addHarCaptureFilter() { addHttpFilterFactory(new HttpFiltersSourceAdapter() { @Override public HttpFilters filterRequest(HttpRequest originalRequest, ChannelHandlerContext ctx) { - return new HarCaptureFilter(originalRequest, ctx, getHar(), getCurrentHarPage() == null ? null : getCurrentHarPage().getId(), getHarCaptureTypes()); + Har har = getHar(); + if (har != null) { + return new HarCaptureFilter(originalRequest, ctx, har, getCurrentHarPage() == null ? null : getCurrentHarPage().getId(), getHarCaptureTypes()); + } else { + return null; + } + } + }); + + addHttpFilterFactory(new HttpFiltersSourceAdapter() { + @Override + public HttpFilters filterRequest(HttpRequest originalRequest, ChannelHandlerContext ctx) { + Har har = getHar(); + if (har != null && ProxyUtils.isCONNECT(originalRequest)) { + return new HttpsConnectHarCaptureFilter(originalRequest, ctx, har, getCurrentHarPage() == null ? null : getCurrentHarPage().getId()); + } else { + return null; + } } }); } diff --git a/browsermob-core-littleproxy/src/main/java/net/lightbody/bmp/filters/HarCaptureFilter.java b/browsermob-core-littleproxy/src/main/java/net/lightbody/bmp/filters/HarCaptureFilter.java index f4a05e315..3d4203950 100644 --- a/browsermob-core-littleproxy/src/main/java/net/lightbody/bmp/filters/HarCaptureFilter.java +++ b/browsermob-core-littleproxy/src/main/java/net/lightbody/bmp/filters/HarCaptureFilter.java @@ -24,6 +24,7 @@ import net.lightbody.bmp.core.har.HarPostDataParam; import net.lightbody.bmp.core.har.HarRequest; import net.lightbody.bmp.core.har.HarResponse; +import net.lightbody.bmp.filters.util.HarCaptureUtil; import net.lightbody.bmp.proxy.CaptureType; import net.lightbody.bmp.proxy.util.BrowserMobProxyUtil; import net.lightbody.bmp.util.BrowserMobHttpUtil; @@ -50,38 +51,8 @@ public class HarCaptureFilter extends HttpsAwareFiltersAdapter { private static final Logger log = LoggerFactory.getLogger(HarCaptureFilter.class); /** - * The HTTP version string in the {@link HarResponse} for failed requests. + * The currently active HAR at the time the current request is received. */ - private static final String HTTP_VERSION_STRING_FOR_FAILURE = "unknown"; - - /** - * The HTTP status code in the {@link HarResponse} for failed requests. - */ - private static final int HTTP_STATUS_CODE_FOR_FAILURE = 0; - - /** - * The HTTP status text/reason phrase in the {@link HarResponse} for failed requests. - */ - private static final String HTTP_REASON_PHRASE_FOR_FAILURE = ""; - - /** - * The error message that will be populated in the _error field of the {@link HarResponse} due to a name - * lookup failure. - */ - private static final String RESOLUTION_FAILED_ERROR_MESSAGE = "Unable to resolve host: "; - - /** - * The error message that will be populated in the _error field of the {@link HarResponse} due to a - * connection failure. - */ - private static final String CONNECTION_FAILED_ERROR_MESSAGE = "Unable to connect to host"; - - /** - * The error message that will be populated in the _error field of the {@link HarResponse} when the proxy fails to - * receive a response in a timely manner. - */ - private static final String RESPONSE_TIMED_OUT_ERROR_MESSAGE = "Response timed out"; - private final Har har; /** @@ -302,7 +273,11 @@ public HttpResponse clientToProxyRequest(HttpObject httpObject) { HttpRequest httpRequest = (HttpRequest) httpObject; this.capturedOriginalRequest = httpRequest; - captureRequestUrl(httpRequest); + // associate this request's HarRequest object with the har entry + HarRequest request = createHarRequestForHttpRequest(httpRequest); + harEntry.setRequest(request); + + captureQueryParameters(httpRequest); captureUserAgent(httpRequest); captureRequestHeaderSize(httpRequest); @@ -379,15 +354,15 @@ public HttpObject serverToProxyResponse(HttpObject httpObject) { @Override public void serverToProxyResponseTimedOut() { - if (har == null && !httpConnect) { + if (har == null) { return; } // replace any existing HarResponse that was created if the server sent a partial response - HarResponse response = createHarResponseForFailure(); + HarResponse response = HarCaptureUtil.createHarResponseForFailure(); harEntry.setResponse(response); - response.setError(RESPONSE_TIMED_OUT_ERROR_MESSAGE); + response.setError(HarCaptureUtil.getResponseTimedOutErrorMessage()); // include this timeout time in the HarTimings object @@ -407,11 +382,25 @@ else if (responseReceiveStartedNanos > 0L) { } } - protected void captureRequestUrl(HttpRequest httpRequest) { - HarRequest request = createHarRequestForHttpRequest(httpRequest); + /** + * Creates a HarRequest object using the method, url, and HTTP version of the specified request. + * + * @param httpRequest HTTP request on which the HarRequest will be based + * @return a new HarRequest object + */ + private HarRequest createHarRequestForHttpRequest(HttpRequest httpRequest) { + // the HAR spec defines the request.url field as: + // url [string] - Absolute URL of the request (fragments are not included). + // the URI on the httpRequest may only identify the path of the resource, so find the full URL. + // the full URL consists of the scheme + host + port (if non-standard) + path + query params + fragment. + String url = getFullUrl(httpRequest); + + return new HarRequest(httpRequest.getMethod().toString(), url, httpRequest.getProtocolVersion().text()); + } - harEntry.setRequest(request); + //TODO: add unit tests for these utility-like capture() methods + protected void captureQueryParameters(HttpRequest httpRequest) { // capture query parameters. it is safe to assume the query string is UTF-8, since it "should" be in US-ASCII (a subset of UTF-8), // but sometimes does include UTF-8 characters. QueryStringDecoder queryStringDecoder = new QueryStringDecoder(httpRequest.getUri(), StandardCharsets.UTF_8); @@ -430,22 +419,6 @@ protected void captureRequestUrl(HttpRequest httpRequest) { } } - /** - * Creates a HarRequest object using the method, url, and HTTP version of the specified request. - * - * @param httpRequest HTTP request on which the HarRequest will be based - * @return a new HarRequest object - */ - private HarRequest createHarRequestForHttpRequest(HttpRequest httpRequest) { - // the HAR spec defines the request.url field as: - // url [string] - Absolute URL of the request (fragments are not included). - // the URI on the httpRequest may only identify the path of the resource, so find the full URL. - // the full URL consists of the scheme + host + port (if non-standard) + path + query params + fragment. - String url = getFullUrl(httpRequest); - - return new HarRequest(httpRequest.getMethod().toString(), url, httpRequest.getProtocolVersion().text()); - } - protected void captureUserAgent(HttpRequest httpRequest) { // save the browser and version if it's not yet been set if (har.getLog().getBrowser() == null) { @@ -504,7 +477,7 @@ protected void captureTrailingHeaders(LastHttpContent lastHttpContent) { captureHeaders(headers); } - private void captureHeaders(HttpHeaders headers) { + protected void captureHeaders(HttpHeaders headers) { for (Map.Entry header : headers.entries()) { harEntry.getRequest().getHeaders().add(new HarNameValuePair(header.getKey(), header.getValue())); } @@ -717,15 +690,20 @@ public InetSocketAddress proxyToServerResolutionStarted(String resolvingServerHo @Override public void proxyToServerResolutionFailed(String hostAndPort) { - //TODO: populate values in har for CONNECT requests when resolution fails - if (har == null && !httpConnect) { + // if this was an HTTP CONNECT, remove the timing information for this failed request. timing information will + // be populated by the CONNECT-specific HAR capture filter. + if (httpConnect) { + httpConnectTimes.remove(clientAddress); + } + + if (har == null) { return; } - HarResponse response = createHarResponseForFailure(); + HarResponse response = HarCaptureUtil.createHarResponseForFailure(); harEntry.setResponse(response); - response.setError(RESOLUTION_FAILED_ERROR_MESSAGE + hostAndPort); + response.setError(HarCaptureUtil.getResolutionFailedErrorMessage(hostAndPort)); // record the amount of time we attempted to resolve the hostname in the HarTimings object if (dnsResolutionStartedNanos > 0L) { @@ -783,15 +761,20 @@ public void proxyToServerConnectionSSLHandshakeStarted() { @Override public void proxyToServerConnectionFailed() { - //TODO: populate values in the har when CONNECT requests fail - if (har == null || httpConnect) { + // if this was an HTTP CONNECT, remove the timing information for this failed request. timing information will + // be populated by the CONNECT-specific HAR capture filter. + if (httpConnect) { + httpConnectTimes.remove(clientAddress); + } + + if (har == null) { return; } - HarResponse response = createHarResponseForFailure(); + HarResponse response = HarCaptureUtil.createHarResponseForFailure(); harEntry.setResponse(response); - response.setError(CONNECTION_FAILED_ERROR_MESSAGE); + response.setError(HarCaptureUtil.getConnectionFailedErrorMessage()); // record the amount of time we attempted to connect in the HarTimings object if (connectionStartedNanos > 0L) { @@ -910,14 +893,4 @@ public long getDnsTimeNanos() { } } - /** - * Creates a HarResponse object for failed requests. Normally the HarResponse is populated when the response is received - * from the server, but if the request fails due to a name resolution issue, connection problem, timeout, etc., no - * HarResponse would otherwise be created. - * - * @return a new HarResponse object with invalid HTTP status code (0) and version string ("unknown") - */ - private static HarResponse createHarResponseForFailure() { - return new HarResponse(HTTP_STATUS_CODE_FOR_FAILURE, HTTP_REASON_PHRASE_FOR_FAILURE, HTTP_VERSION_STRING_FOR_FAILURE); - } } diff --git a/browsermob-core-littleproxy/src/main/java/net/lightbody/bmp/filters/HttpsConnectHarCaptureFilter.java b/browsermob-core-littleproxy/src/main/java/net/lightbody/bmp/filters/HttpsConnectHarCaptureFilter.java new file mode 100644 index 000000000..618c1df73 --- /dev/null +++ b/browsermob-core-littleproxy/src/main/java/net/lightbody/bmp/filters/HttpsConnectHarCaptureFilter.java @@ -0,0 +1,313 @@ +package net.lightbody.bmp.filters; + +import io.netty.channel.ChannelHandlerContext; +import io.netty.handler.codec.http.HttpObject; +import io.netty.handler.codec.http.HttpRequest; +import io.netty.handler.codec.http.HttpResponse; +import net.lightbody.bmp.core.har.Har; +import net.lightbody.bmp.core.har.HarEntry; +import net.lightbody.bmp.core.har.HarRequest; +import net.lightbody.bmp.core.har.HarResponse; +import net.lightbody.bmp.core.har.HarTimings; +import net.lightbody.bmp.filters.util.HarCaptureUtil; +import org.littleshoot.proxy.impl.ProxyUtils; + +import java.net.InetSocketAddress; +import java.util.Date; +import java.util.concurrent.TimeUnit; + +/** + * This filter captures HAR data for HTTP CONNECT requests. CONNECTs are "meta" requests that must be made before HTTPS + * requests, but are not populated as separate requests in the HAR. Most information from HTTP CONNECTs (such as SSL + * handshake time, dns resolution time, etc.) is populated in the HAR entry for the first "true" request following the + * CONNECT. This filter captures the timing-related information and makes it available to subsequent filters through + * static methods. This filter also handles HTTP CONNECT errors and creates HAR entries for those errors, since there + * would otherwise not be any record in the HAR of the error (if the CONNECT fails, there will be no subsequent "real" + * request in which to record the error). + * + * TODO: refactor other HTTP CONNECT-specific logic out of HarCaptureFilter + */ +public class HttpsConnectHarCaptureFilter extends HttpsAwareFiltersAdapter { + /** + * The currently active HAR at the time the current request is received. + */ + private final Har har; + + /** + * The currently active page ref at the time the current request is received. + */ + private final String currentPageRef; + + /** + * The time this CONNECT began. Used to populate the HAR entry in case of failure. + */ + private volatile Date requestStartTime; + + /** + * Populated by proxyToServerResolutionStarted when DNS resolution starts. If any previous filters already resolved the address, their resolution time + * will not be included in this time. See {@link HarCaptureFilter#dnsResolutionStartedNanos}. + */ + private volatile long dnsResolutionStartedNanos; + + private volatile long dnsResolutionFinishedNanos; + + private volatile long connectionQueuedNanos; + private volatile long connectionStartedNanos; + private volatile long connectionSucceededTimeNanos; + private volatile long sendStartedNanos; + private volatile long sendFinishedNanos; + + private volatile long responseReceiveStartedNanos; + private volatile long sslHandshakeStartedNanos; + + public HttpsConnectHarCaptureFilter(HttpRequest originalRequest, ChannelHandlerContext ctx, Har har, String currentPageRef) { + super(originalRequest, ctx); + + boolean httpConnect = ProxyUtils.isCONNECT(originalRequest); + + if (!httpConnect) { + this.har = null; + this.currentPageRef = null; + } else { + this.har = har; + this.currentPageRef = currentPageRef; + } + } + + @Override + public HttpResponse clientToProxyRequest(HttpObject httpObject) { + if (har == null) { + return null; + } + + if (httpObject instanceof HttpRequest) { + // store the CONNECT start time in case of failure, so we can populate the HarEntry with it + requestStartTime = new Date(); + } + + return null; + } + + @Override + public void proxyToServerResolutionFailed(String hostAndPort) { + if (har == null) { + return; + } + + // since this is a CONNECT, which is not handled by the HarCaptureFilter, we need to create and populate the + // entire HarEntry and add it to this har. + HarEntry harEntry = createHarEntryForFailedCONNECT(HarCaptureUtil.getResolutionFailedErrorMessage(hostAndPort)); + har.getLog().addEntry(harEntry); + + // record the amount of time we attempted to resolve the hostname in the HarTimings object + if (dnsResolutionStartedNanos > 0L) { + harEntry.getTimings().setDns(System.nanoTime() - dnsResolutionStartedNanos, TimeUnit.NANOSECONDS); + } + } + + @Override + public void proxyToServerConnectionFailed() { + if (har == null) { + return; + } + + // since this is a CONNECT, which is not handled by the HarCaptureFilter, we need to create and populate the + // entire HarEntry and add it to this har. + HarEntry harEntry = createHarEntryForFailedCONNECT(HarCaptureUtil.getConnectionFailedErrorMessage()); + har.getLog().addEntry(harEntry); + + // record the amount of time we attempted to connect in the HarTimings object + if (connectionStartedNanos > 0L) { + harEntry.getTimings().setConnect(System.nanoTime() - connectionStartedNanos, TimeUnit.NANOSECONDS); + } + } + + @Override + public void proxyToServerConnectionSucceeded() { + if (har == null) { + return; + } + + this.connectionSucceededTimeNanos = System.nanoTime(); + } + + @Override + public void proxyToServerConnectionSSLHandshakeStarted() { + if (har == null) { + return; + } + + this.sslHandshakeStartedNanos = System.nanoTime(); + } + + @Override + public void serverToProxyResponseTimedOut() { + if (har == null) { + return; + } + + HarEntry harEntry = createHarEntryForFailedCONNECT(HarCaptureUtil.getResponseTimedOutErrorMessage()); + har.getLog().addEntry(harEntry); + + // include this timeout time in the HarTimings object + long timeoutTimestampNanos = System.nanoTime(); + + // if the proxy started to send the request but has not yet finished, we are currently "sending" + if (sendStartedNanos > 0L && sendFinishedNanos == 0L) { + harEntry.getTimings().setSend(timeoutTimestampNanos - sendStartedNanos, TimeUnit.NANOSECONDS); + } + // if the entire request was sent but the proxy has not begun receiving the response, we are currently "waiting" + else if (sendFinishedNanos > 0L && responseReceiveStartedNanos == 0L) { + harEntry.getTimings().setWait(timeoutTimestampNanos - sendFinishedNanos, TimeUnit.NANOSECONDS); + } + // if the proxy has already begun to receive the response, we are currenting "receiving" + else if (responseReceiveStartedNanos > 0L) { + harEntry.getTimings().setReceive(timeoutTimestampNanos - responseReceiveStartedNanos, TimeUnit.NANOSECONDS); + } + } + + @Override + public void proxyToServerConnectionQueued() { + if (har == null) { + return; + } + + this.connectionQueuedNanos = System.nanoTime(); + } + + + @Override + public InetSocketAddress proxyToServerResolutionStarted(String resolvingServerHostAndPort) { + if (har == null) { + return null; + } + + dnsResolutionStartedNanos = System.nanoTime(); + + return null; + } + + @Override + public void proxyToServerResolutionSucceeded(String serverHostAndPort, InetSocketAddress resolvedRemoteAddress) { + if (har == null) { + return; + } + + this.dnsResolutionFinishedNanos = System.nanoTime(); + } + + @Override + public void proxyToServerConnectionStarted() { + if (har == null) { + return; + } + + this.connectionStartedNanos = System.nanoTime(); + } + + @Override + public void proxyToServerRequestSending() { + if (har == null) { + return; + } + + this.sendStartedNanos = System.nanoTime(); + } + + @Override + public void proxyToServerRequestSent() { + if (har == null) { + return; + } + + this.sendFinishedNanos = System.nanoTime(); + } + + @Override + public void serverToProxyResponseReceiving() { + if (har == null) { + return; + } + + this.responseReceiveStartedNanos = System.nanoTime(); + } + + /** + * Populates timing information in the specified harEntry for failed rquests. Populates as much timing information + * as possible, up to the point of failure. + * + * @param harEntry HAR entry to populate timing information in + */ + private void populateTimingsForFailedCONNECT(HarEntry harEntry) { + HarTimings timings = harEntry.getTimings(); + + if (connectionQueuedNanos > 0L && dnsResolutionStartedNanos > 0L) { + timings.setBlocked(dnsResolutionStartedNanos - connectionQueuedNanos, TimeUnit.NANOSECONDS); + } + + if (dnsResolutionStartedNanos > 0L && dnsResolutionFinishedNanos > 0L) { + timings.setDns(dnsResolutionFinishedNanos - dnsResolutionStartedNanos, TimeUnit.NANOSECONDS); + } + + if (connectionStartedNanos > 0L && connectionSucceededTimeNanos > 0L) { + harEntry.getTimings().setConnect(connectionSucceededTimeNanos - connectionStartedNanos, TimeUnit.NANOSECONDS); + + if (sslHandshakeStartedNanos > 0L) { + harEntry.getTimings().setSsl(connectionSucceededTimeNanos - this.sslHandshakeStartedNanos, TimeUnit.NANOSECONDS); + } + } + + if (sendStartedNanos > 0L && sendFinishedNanos >= 0L) { + harEntry.getTimings().setSend(sendFinishedNanos - sendStartedNanos, TimeUnit.NANOSECONDS); + } + + if (sendFinishedNanos > 0L && responseReceiveStartedNanos >= 0L) { + harEntry.getTimings().setWait(responseReceiveStartedNanos - sendFinishedNanos, TimeUnit.NANOSECONDS); + } + + // since this method is for HTTP CONNECT failures only, we can't populate a "received" time, since that would + // require the CONNECT to be successful, in which case this method wouldn't be called. + } + + /** + * Creates a {@link HarEntry} for a failed CONNECT request. Initializes and populates the entry, including the + * {@link HarRequest}, {@link HarResponse}, and {@link HarTimings}. (Note: only successful timing information is + * populated in the timings object; the calling method must populate the timing information for the final, failed + * step. For example, if DNS resolution failed, this method will populate the network 'blocked' time, but not the DNS + * time.) Populates the specified errorMessage in the {@link HarResponse}'s error field. + * + * @param errorMessage error message to place in the har response + * @return a new HAR entry + */ + private HarEntry createHarEntryForFailedCONNECT(String errorMessage) { + HarEntry harEntry = new HarEntry(currentPageRef); + harEntry.setStartedDateTime(requestStartTime); + + HarRequest request = createRequestForFailedConnect(originalRequest); + harEntry.setRequest(request); + + HarResponse response = HarCaptureUtil.createHarResponseForFailure(); + harEntry.setResponse(response); + + response.setError(errorMessage); + + // populate all timing information for this failed request + populateTimingsForFailedCONNECT(harEntry); + + return harEntry; + } + + /** + * Creates a new {@link HarRequest} object for this failed HTTP CONNECT. Does not populate fields within the request, + * such as the error message. + * + * @param httpConnectRequest the HTTP CONNECT request that failed + * @return a new HAR request object + */ + private HarRequest createRequestForFailedConnect(HttpRequest httpConnectRequest) { + String url = getFullUrl(httpConnectRequest); + + return new HarRequest(httpConnectRequest.getMethod().toString(), url, httpConnectRequest.getProtocolVersion().text()); + } + +} diff --git a/browsermob-core-littleproxy/src/main/java/net/lightbody/bmp/filters/util/HarCaptureUtil.java b/browsermob-core-littleproxy/src/main/java/net/lightbody/bmp/filters/util/HarCaptureUtil.java new file mode 100644 index 000000000..12a49e795 --- /dev/null +++ b/browsermob-core-littleproxy/src/main/java/net/lightbody/bmp/filters/util/HarCaptureUtil.java @@ -0,0 +1,80 @@ +package net.lightbody.bmp.filters.util; + +import net.lightbody.bmp.core.har.HarResponse; + +/** + * Static utility methods for {@link net.lightbody.bmp.filters.HarCaptureFilter} and {@link net.lightbody.bmp.filters.HttpsConnectHarCaptureFilter}. + */ +public class HarCaptureUtil { + /** + * The HTTP version string in the {@link HarResponse} for failed requests. + */ + public static final String HTTP_VERSION_STRING_FOR_FAILURE = "unknown"; + + /** + * The HTTP status code in the {@link HarResponse} for failed requests. + */ + public static final int HTTP_STATUS_CODE_FOR_FAILURE = 0; + + /** + * The HTTP status text/reason phrase in the {@link HarResponse} for failed requests. + */ + public static final String HTTP_REASON_PHRASE_FOR_FAILURE = ""; + + /** + * The error message that will be populated in the _error field of the {@link HarResponse} due to a name + * lookup failure. + */ + private static final String RESOLUTION_FAILED_ERROR_MESSAGE = "Unable to resolve host: "; + + /** + * The error message that will be populated in the _error field of the {@link HarResponse} due to a + * connection failure. + */ + private static final String CONNECTION_FAILED_ERROR_MESSAGE = "Unable to connect to host"; + + /** + * The error message that will be populated in the _error field of the {@link HarResponse} when the proxy fails to + * receive a response in a timely manner. + */ + private static final String RESPONSE_TIMED_OUT_ERROR_MESSAGE = "Response timed out"; + + /** + * Creates a HarResponse object for failed requests. Normally the HarResponse is populated when the response is received + * from the server, but if the request fails due to a name resolution issue, connection problem, timeout, etc., no + * HarResponse would otherwise be created. + * + * @return a new HarResponse object with invalid HTTP status code (0) and version string ("unknown") + */ + public static HarResponse createHarResponseForFailure() { + return new HarResponse(HTTP_STATUS_CODE_FOR_FAILURE, HTTP_REASON_PHRASE_FOR_FAILURE, HTTP_VERSION_STRING_FOR_FAILURE); + } + + /** + * Returns the error message for the HAR response when DNS resolution fails. + * + * @param hostAndPort the host and port of the address lookup that failed + * @return the resolution failed error message + */ + public static String getResolutionFailedErrorMessage(String hostAndPort) { + return RESOLUTION_FAILED_ERROR_MESSAGE + hostAndPort; + } + + /** + * Returns the error message for the HAR response when the connection fails. + * + * @return the connection failed error message + */ + public static String getConnectionFailedErrorMessage() { + return CONNECTION_FAILED_ERROR_MESSAGE; + } + + /** + * Returs the error message for the HAR response when the response from the server times out. + * + * @return the response timed out error message + */ + public static String getResponseTimedOutErrorMessage() { + return RESPONSE_TIMED_OUT_ERROR_MESSAGE; + } +} diff --git a/browsermob-core-littleproxy/src/test/groovy/net/lightbody/bmp/proxy/NewHarTest.groovy b/browsermob-core-littleproxy/src/test/groovy/net/lightbody/bmp/proxy/NewHarTest.groovy index 84f149c44..88d614e06 100644 --- a/browsermob-core-littleproxy/src/test/groovy/net/lightbody/bmp/proxy/NewHarTest.groovy +++ b/browsermob-core-littleproxy/src/test/groovy/net/lightbody/bmp/proxy/NewHarTest.groovy @@ -10,7 +10,7 @@ import net.lightbody.bmp.core.har.HarEntry import net.lightbody.bmp.core.har.HarNameValuePair import net.lightbody.bmp.core.har.HarResponse import net.lightbody.bmp.core.har.HarTimings -import net.lightbody.bmp.filters.HarCaptureFilter +import net.lightbody.bmp.filters.util.HarCaptureUtil import net.lightbody.bmp.proxy.dns.AdvancedHostResolver import net.lightbody.bmp.proxy.test.util.MockServerTest import net.lightbody.bmp.proxy.test.util.ProxyServerTest @@ -18,7 +18,6 @@ import net.lightbody.bmp.proxy.util.IOUtils import org.apache.http.client.methods.CloseableHttpResponse import org.apache.http.client.methods.HttpGet import org.junit.After -import org.junit.Ignore import org.junit.Test import org.mockito.invocation.InvocationOnMock import org.mockito.stubbing.Answer @@ -580,9 +579,9 @@ class NewHarTest extends MockServerTest { HarResponse harResponse = har.log.entries[0].response assertNotNull("No HAR response found", harResponse) - assertEquals("Error in HAR response did not match expected DNS failure error message", HarCaptureFilter.RESOLUTION_FAILED_ERROR_MESSAGE + "www.doesnotexist.address", harResponse.error) - assertEquals("Expected HTTP status code of 0 for failed request", HarCaptureFilter.HTTP_STATUS_CODE_FOR_FAILURE, harResponse.status) - assertEquals("Expected unknown HTTP version for failed request", HarCaptureFilter.HTTP_VERSION_STRING_FOR_FAILURE, harResponse.httpVersion) + assertEquals("Error in HAR response did not match expected DNS failure error message", HarCaptureUtil.getResolutionFailedErrorMessage("www.doesnotexist.address"), harResponse.error) + assertEquals("Expected HTTP status code of 0 for failed request", HarCaptureUtil.HTTP_STATUS_CODE_FOR_FAILURE, harResponse.status) + assertEquals("Expected unknown HTTP version for failed request", HarCaptureUtil.HTTP_VERSION_STRING_FOR_FAILURE, harResponse.httpVersion) assertEquals("Expected default value for headersSize for failed request", -1L, harResponse.headersSize) assertEquals("Expected default value for bodySize for failed request", -1L, harResponse.bodySize) @@ -598,8 +597,6 @@ class NewHarTest extends MockServerTest { assertEquals("Expected HAR timings to contain default values after DNS failure", 0L, harTimings.getReceive(TimeUnit.NANOSECONDS)) } - // TODO: unignore when a strategy for handling failed HTTP CONNECT requests is implemented - @Ignore @Test void testHttpsDnsFailureCapturedInHar() { AdvancedHostResolver mockFailingResolver = mock(AdvancedHostResolver) @@ -625,14 +622,14 @@ class NewHarTest extends MockServerTest { // make sure request data is still captured despite the failure String capturedUrl = har.log.entries[0].request.url - assertEquals("URL captured in HAR did not match request URL", requestUrl, capturedUrl) + assertEquals("URL captured in HAR did not match expected HTTP CONNECT URL", "https://www.doesnotexist.address:443", capturedUrl) HarResponse harResponse = har.log.entries[0].response assertNotNull("No HAR response found", harResponse) - assertEquals("Error in HAR response did not match expected DNS failure error message", HarCaptureFilter.RESOLUTION_FAILED_ERROR_MESSAGE + "www.doesnotexist.address", harResponse.error) - assertEquals("Expected HTTP status code of 0 for failed request", HarCaptureFilter.HTTP_STATUS_CODE_FOR_FAILURE, harResponse.status) - assertEquals("Expected unknown HTTP version for failed request", HarCaptureFilter.HTTP_VERSION_STRING_FOR_FAILURE, harResponse.httpVersion) + assertEquals("Error in HAR response did not match expected DNS failure error message", HarCaptureUtil.getResolutionFailedErrorMessage("www.doesnotexist.address:443"), harResponse.error) + assertEquals("Expected HTTP status code of 0 for failed request", HarCaptureUtil.HTTP_STATUS_CODE_FOR_FAILURE, harResponse.status) + assertEquals("Expected unknown HTTP version for failed request", HarCaptureUtil.HTTP_VERSION_STRING_FOR_FAILURE, harResponse.httpVersion) assertEquals("Expected default value for headersSize for failed request", -1L, harResponse.headersSize) assertEquals("Expected default value for bodySize for failed request", -1L, harResponse.bodySize) @@ -655,7 +652,9 @@ class NewHarTest extends MockServerTest { proxy.newHar() - String requestUrl = "http://localhost:0/some-resource" + // TCP port 2 is reserved for "CompressNET Management Utility". since it's almost certainly not in use, connections + // to port 2 will fail. + String requestUrl = "http://localhost:2/some-resource" ProxyServerTest.getNewHttpClient(proxy.port).withCloseable { CloseableHttpResponse response = it.execute(new HttpGet(requestUrl)) @@ -674,9 +673,9 @@ class NewHarTest extends MockServerTest { HarResponse harResponse = har.log.entries[0].response assertNotNull("No HAR response found", harResponse) - assertEquals("Error in HAR response did not match expected connection failure error message", HarCaptureFilter.CONNECTION_FAILED_ERROR_MESSAGE, harResponse.error) - assertEquals("Expected HTTP status code of 0 for failed request", HarCaptureFilter.HTTP_STATUS_CODE_FOR_FAILURE, harResponse.status) - assertEquals("Expected unknown HTTP version for failed request", HarCaptureFilter.HTTP_VERSION_STRING_FOR_FAILURE, harResponse.httpVersion) + assertEquals("Error in HAR response did not match expected connection failure error message", HarCaptureUtil.getConnectionFailedErrorMessage(), harResponse.error) + assertEquals("Expected HTTP status code of 0 for failed request", HarCaptureUtil.HTTP_STATUS_CODE_FOR_FAILURE, harResponse.status) + assertEquals("Expected unknown HTTP version for failed request", HarCaptureUtil.HTTP_VERSION_STRING_FOR_FAILURE, harResponse.httpVersion) assertEquals("Expected default value for headersSize for failed request", -1L, harResponse.headersSize) assertEquals("Expected default value for bodySize for failed request", -1L, harResponse.bodySize) @@ -691,8 +690,6 @@ class NewHarTest extends MockServerTest { assertEquals("Expected HAR timings to contain default values after connection failure", 0L, harTimings.getReceive(TimeUnit.NANOSECONDS)) } - // TODO: unignore when a strategy for handling failed HTTP CONNECT requests is implemented - @Ignore @Test void testHttpsConnectTimeoutCapturedInHar() { proxy = new BrowserMobProxyServer(); @@ -700,7 +697,9 @@ class NewHarTest extends MockServerTest { proxy.newHar() - String requestUrl = "https://localhost:0/some-resource" + // TCP port 2 is reserved for "CompressNET Management Utility". since it's almost certainly not in use, connections + // to port 2 will fail. + String requestUrl = "https://localhost:2/some-resource" ProxyServerTest.getNewHttpClient(proxy.port).withCloseable { CloseableHttpResponse response = it.execute(new HttpGet(requestUrl)) @@ -714,14 +713,14 @@ class NewHarTest extends MockServerTest { // make sure request data is still captured despite the failure String capturedUrl = har.log.entries[0].request.url - assertEquals("URL captured in HAR did not match request URL", requestUrl, capturedUrl) + assertEquals("URL captured in HAR did not match request URL", "https://localhost:2", capturedUrl) HarResponse harResponse = har.log.entries[0].response assertNotNull("No HAR response found", harResponse) - assertEquals("Error in HAR response did not match expected connection failure error message", HarCaptureFilter.CONNECTION_FAILED_ERROR_MESSAGE, harResponse.error) - assertEquals("Expected HTTP status code of 0 for failed request", HarCaptureFilter.HTTP_STATUS_CODE_FOR_FAILURE, harResponse.status) - assertEquals("Expected unknown HTTP version for failed request", HarCaptureFilter.HTTP_VERSION_STRING_FOR_FAILURE, harResponse.httpVersion) + assertEquals("Error in HAR response did not match expected connection failure error message", HarCaptureUtil.getConnectionFailedErrorMessage(), harResponse.error) + assertEquals("Expected HTTP status code of 0 for failed request", HarCaptureUtil.HTTP_STATUS_CODE_FOR_FAILURE, harResponse.status) + assertEquals("Expected unknown HTTP version for failed request", HarCaptureUtil.HTTP_VERSION_STRING_FOR_FAILURE, harResponse.httpVersion) assertEquals("Expected default value for headersSize for failed request", -1L, harResponse.headersSize) assertEquals("Expected default value for bodySize for failed request", -1L, harResponse.bodySize) @@ -772,9 +771,9 @@ class NewHarTest extends MockServerTest { HarResponse harResponse = har.log.entries[0].response assertNotNull("No HAR response found", harResponse) - assertEquals("Error in HAR response did not match expected response timeout error message", HarCaptureFilter.RESPONSE_TIMED_OUT_ERROR_MESSAGE, harResponse.error) - assertEquals("Expected HTTP status code of 0 for response timeout", HarCaptureFilter.HTTP_STATUS_CODE_FOR_FAILURE, harResponse.status) - assertEquals("Expected unknown HTTP version for response timeout", HarCaptureFilter.HTTP_VERSION_STRING_FOR_FAILURE, harResponse.httpVersion) + assertEquals("Error in HAR response did not match expected response timeout error message", HarCaptureUtil.getResponseTimedOutErrorMessage(), harResponse.error) + assertEquals("Expected HTTP status code of 0 for response timeout", HarCaptureUtil.HTTP_STATUS_CODE_FOR_FAILURE, harResponse.status) + assertEquals("Expected unknown HTTP version for response timeout", HarCaptureUtil.HTTP_VERSION_STRING_FOR_FAILURE, harResponse.httpVersion) assertEquals("Expected default value for headersSize for response timeout", -1L, harResponse.headersSize) assertEquals("Expected default value for bodySize for response timeout", -1L, harResponse.bodySize) @@ -793,8 +792,6 @@ class NewHarTest extends MockServerTest { assertEquals("Expected receive time to not be populated", 0L, harTimings.getReceive(TimeUnit.NANOSECONDS)) } - // TODO: unignore when a strategy for handling failed HTTP CONNECT requests is implemented - @Ignore @Test void testHttpsResponseTimeoutCapturedInHar() { mockServer.when(request() @@ -831,16 +828,16 @@ class NewHarTest extends MockServerTest { HarResponse harResponse = har.log.entries[0].response assertNotNull("No HAR response found", harResponse) - assertEquals("Error in HAR response did not match expected response timeout error message", HarCaptureFilter.RESPONSE_TIMED_OUT_ERROR_MESSAGE, harResponse.error) - assertEquals("Expected HTTP status code of 0 for response timeout", HarCaptureFilter.HTTP_STATUS_CODE_FOR_FAILURE, harResponse.status) - assertEquals("Expected unknown HTTP version for response timeout", HarCaptureFilter.HTTP_VERSION_STRING_FOR_FAILURE, harResponse.httpVersion) + assertEquals("Error in HAR response did not match expected response timeout error message", HarCaptureUtil.RESPONSE_TIMED_OUT_ERROR_MESSAGE, harResponse.error) + assertEquals("Expected HTTP status code of 0 for response timeout", HarCaptureUtil.HTTP_STATUS_CODE_FOR_FAILURE, harResponse.status) + assertEquals("Expected unknown HTTP version for response timeout", HarCaptureUtil.HTTP_VERSION_STRING_FOR_FAILURE, harResponse.httpVersion) assertEquals("Expected default value for headersSize for response timeout", -1L, harResponse.headersSize) assertEquals("Expected default value for bodySize for response timeout", -1L, harResponse.bodySize) HarTimings harTimings = har.log.entries[0].timings assertNotNull("No HAR timings found", harTimings) - assertEquals("Expected ssl timing to contain default value", -1L, harTimings.getSsl(TimeUnit.NANOSECONDS)) + assertThat("Expected ssl timing to be populated", harTimings.getSsl(TimeUnit.NANOSECONDS), greaterThan(0L)) // this timeout was caused by a failure of the server to respond, so dns, connect, send, and wait should all be populated, // but receive should not be populated since no response was received. From 53ff6bf701fd2a32bca4debb741257b0524c9565 Mon Sep 17 00:00:00 2001 From: Jason Eric Klaes Hoetger Date: Sun, 12 Jul 2015 15:44:20 -0700 Subject: [PATCH 3/4] Refactored HarCaptureFilter and HttpConnectHarCaptureFilter. --- .../lightbody/bmp/BrowserMobProxyServer.java | 18 +- .../bmp/filters/HarCaptureFilter.java | 286 +++--------------- ....java => HttpConnectHarCaptureFilter.java} | 186 ++++++++---- .../filters/ResolvedHostnameCacheFilter.java | 74 +++++ .../filters/support/HttpConnectTiming.java | 51 ++++ .../bmp/filters/util/HarCaptureUtil.java | 2 +- .../net/lightbody/bmp/proxy/NewHarTest.groovy | 8 + 7 files changed, 307 insertions(+), 318 deletions(-) rename browsermob-core-littleproxy/src/main/java/net/lightbody/bmp/filters/{HttpsConnectHarCaptureFilter.java => HttpConnectHarCaptureFilter.java} (62%) create mode 100644 browsermob-core-littleproxy/src/main/java/net/lightbody/bmp/filters/ResolvedHostnameCacheFilter.java create mode 100644 browsermob-core-littleproxy/src/main/java/net/lightbody/bmp/filters/support/HttpConnectTiming.java diff --git a/browsermob-core-littleproxy/src/main/java/net/lightbody/bmp/BrowserMobProxyServer.java b/browsermob-core-littleproxy/src/main/java/net/lightbody/bmp/BrowserMobProxyServer.java index cc0fdaff4..23e50c1fc 100644 --- a/browsermob-core-littleproxy/src/main/java/net/lightbody/bmp/BrowserMobProxyServer.java +++ b/browsermob-core-littleproxy/src/main/java/net/lightbody/bmp/BrowserMobProxyServer.java @@ -16,7 +16,8 @@ import net.lightbody.bmp.filters.BlacklistFilter; import net.lightbody.bmp.filters.BrowserMobHttpFilterChain; import net.lightbody.bmp.filters.HarCaptureFilter; -import net.lightbody.bmp.filters.HttpsConnectHarCaptureFilter; +import net.lightbody.bmp.filters.ResolvedHostnameCacheFilter; +import net.lightbody.bmp.filters.HttpConnectHarCaptureFilter; import net.lightbody.bmp.filters.HttpsHostCaptureFilter; import net.lightbody.bmp.filters.HttpsOriginalHostCaptureFilter; import net.lightbody.bmp.filters.LatencyFilter; @@ -1281,6 +1282,13 @@ public boolean isMitmDisabled() { * Adds the basic browsermob-proxy filters, except for the relatively-expensive HAR capture filter. */ protected void addBrowserMobFilters() { + addHttpFilterFactory(new HttpFiltersSourceAdapter() { + @Override + public HttpFilters filterRequest(HttpRequest originalRequest, ChannelHandlerContext ctx) { + return new ResolvedHostnameCacheFilter(originalRequest, ctx); + } + }); + addHttpFilterFactory(new HttpFiltersSourceAdapter() { @Override public HttpFilters filterRequest(HttpRequest originalRequest, ChannelHandlerContext ctx) { @@ -1376,11 +1384,14 @@ private int getMaximumResponseBufferSize() { */ protected void addHarCaptureFilter() { if (harCaptureFilterEnabled.compareAndSet(false, true)) { + // the HAR capture filter is (relatively) expensive, so only enable it when a HAR is being captured. furthermore, + // restricting the HAR capture filter to requests where the HAR exists, as well as excluding HTTP CONNECTs + // from the HAR capture filter, greatly simplifies the filter code. addHttpFilterFactory(new HttpFiltersSourceAdapter() { @Override public HttpFilters filterRequest(HttpRequest originalRequest, ChannelHandlerContext ctx) { Har har = getHar(); - if (har != null) { + if (har != null && !ProxyUtils.isCONNECT(originalRequest)) { return new HarCaptureFilter(originalRequest, ctx, har, getCurrentHarPage() == null ? null : getCurrentHarPage().getId(), getHarCaptureTypes()); } else { return null; @@ -1388,12 +1399,13 @@ public HttpFilters filterRequest(HttpRequest originalRequest, ChannelHandlerCont } }); + // HTTP CONNECTs are a special case, since they require special timing and error handling addHttpFilterFactory(new HttpFiltersSourceAdapter() { @Override public HttpFilters filterRequest(HttpRequest originalRequest, ChannelHandlerContext ctx) { Har har = getHar(); if (har != null && ProxyUtils.isCONNECT(originalRequest)) { - return new HttpsConnectHarCaptureFilter(originalRequest, ctx, har, getCurrentHarPage() == null ? null : getCurrentHarPage().getId()); + return new HttpConnectHarCaptureFilter(originalRequest, ctx, har, getCurrentHarPage() == null ? null : getCurrentHarPage().getId()); } else { return null; } diff --git a/browsermob-core-littleproxy/src/main/java/net/lightbody/bmp/filters/HarCaptureFilter.java b/browsermob-core-littleproxy/src/main/java/net/lightbody/bmp/filters/HarCaptureFilter.java index 3d4203950..168a05bd8 100644 --- a/browsermob-core-littleproxy/src/main/java/net/lightbody/bmp/filters/HarCaptureFilter.java +++ b/browsermob-core-littleproxy/src/main/java/net/lightbody/bmp/filters/HarCaptureFilter.java @@ -1,9 +1,6 @@ package net.lightbody.bmp.filters; -import com.google.common.cache.Cache; -import com.google.common.cache.CacheBuilder; import com.google.common.collect.ImmutableList; -import com.google.common.net.HostAndPort; import io.netty.buffer.ByteBuf; import io.netty.channel.ChannelHandlerContext; import io.netty.handler.codec.http.Cookie; @@ -24,6 +21,7 @@ import net.lightbody.bmp.core.har.HarPostDataParam; import net.lightbody.bmp.core.har.HarRequest; import net.lightbody.bmp.core.har.HarResponse; +import net.lightbody.bmp.filters.support.HttpConnectTiming; import net.lightbody.bmp.filters.util.HarCaptureUtil; import net.lightbody.bmp.proxy.CaptureType; import net.lightbody.bmp.proxy.util.BrowserMobProxyUtil; @@ -43,7 +41,6 @@ import java.util.List; import java.util.Map; import java.util.Set; -import java.util.concurrent.ConcurrentMap; import java.util.concurrent.TimeUnit; import java.util.concurrent.atomic.AtomicInteger; @@ -88,18 +85,11 @@ public class HarCaptureFilter extends HttpsAwareFiltersAdapter { private volatile long connectionQueuedNanos; private volatile long connectionStartedNanos; - private volatile long sslHandshakeStartedNanos; - private volatile long sendStartedNanos; private volatile long sendFinishedNanos; private volatile long responseReceiveStartedNanos; - /** - * True if this is an HTTP CONNECT request, for which some special timing information is needed. - */ - private final boolean httpConnect; - /** * The address of the client making the request. Captured in the constructor and used when calculating and capturing ssl handshake and connect * timing information for SSL connections. @@ -127,62 +117,6 @@ public class HarCaptureFilter extends HttpsAwareFiltersAdapter { */ private volatile boolean addressResolved = false; - /** - * The maximum amount of time to save timing information between an HTTP CONNECT and the subsequent HTTP request. Typically this is done - * immediately, but if for some reason it is not (e.g. due to a client crash or dropped connection), the timing information will be - * kept for this long before being evicted to prevent a memory leak. If a subsequent request does come through after eviction, it will still - * be recorded, but the timing information will not be populated in the HAR. - */ - private static final int HTTP_CONNECT_TIMING_EVICTION_SECONDS = 60; - - /** - * The maximum amount of time to save host name resolution information. This is done in order to populate the server IP address field in the - * har. Unfortunately there is not currently any way to determine the remote IP address of a keep-alive connection in a filter, so caching the - * resolved hostnames gives a generally-reasonable best guess. - */ - private static final int RESOLVED_ADDRESSES_EVICTION_SECONDS = 300; - - /** - * Concurrency of the httpConnectTiming map. Should be approximately equal to the maximum number of simultaneous connection - * attempts (but not necessarily simultaneous connections). A lower value will inhibit performance. - * TODO: tune this value for a large number of concurrent requests. develop a non-cache-based mechanism of passing ssl timings to subsequent requests. - */ - private static final int HTTP_CONNECT_TIMING_CONCURRENCY_LEVEL = 50; - - /** - * Stores HTTP CONNECT timing information for this request, if it is an HTTP CONNECT. - */ - private final HttpConnectTiming httpConnectTiming; - - /** - * Stores SSL connection timing information from HTTP CONNNECT requests. This timing information is stored in the first HTTP request - * after the CONNECT, not in the CONNECT itself, so it needs to be stored across requests. - * - * This is the only state stored across multiple requests. - */ - private static final ConcurrentMap httpConnectTimes; - - /** - * A {@code Map} that provides a reasonable estimate of the upstream server's IP address for keep-alive connections. - * The expiration time is renewed after each access, rather than after each write, so if the connection is consistently kept alive and used, - * the cached IP address will not be evicted. - */ - private static final ConcurrentMap resolvedAddresses; - - static { - Cache connectTimingCache = CacheBuilder.newBuilder() - .expireAfterWrite(HTTP_CONNECT_TIMING_EVICTION_SECONDS, TimeUnit.SECONDS) - .concurrencyLevel(HTTP_CONNECT_TIMING_CONCURRENCY_LEVEL) - .build(); - httpConnectTimes = connectTimingCache.asMap(); - - Cache addressCache = CacheBuilder.newBuilder() - .expireAfterAccess(RESOLVED_ADDRESSES_EVICTION_SECONDS, TimeUnit.SECONDS) - .concurrencyLevel(HTTP_CONNECT_TIMING_CONCURRENCY_LEVEL) - .build(); - resolvedAddresses = addressCache.asMap(); - } - /** * Create a new instance of the HarCaptureFilter that will capture request and response information. If no har is specified in the * constructor, this filter will do nothing. @@ -203,61 +137,44 @@ public class HarCaptureFilter extends HttpsAwareFiltersAdapter { public HarCaptureFilter(HttpRequest originalRequest, ChannelHandlerContext ctx, Har har, String currentPageRef, Set dataToCapture) { super(originalRequest, ctx); - httpConnect = ProxyUtils.isCONNECT(originalRequest); + if (har == null) { + throw new IllegalStateException("Attempted har capture when har is null"); + } + + if (ProxyUtils.isCONNECT(originalRequest)) { + throw new IllegalStateException("Attempted har capture for HTTP CONNECT request"); + } - InetSocketAddress clientAddress = (InetSocketAddress) ctx.channel().remoteAddress(); - this.clientAddress = clientAddress; + this.clientAddress = (InetSocketAddress) ctx.channel().remoteAddress(); - // for HTTP CONNECT calls, create and cache an HTTP CONNECT timing object to capture timing-related information - if (httpConnect) { - this.httpConnectTiming = new HttpConnectTiming(); - httpConnectTimes.put(clientAddress, httpConnectTiming); + if (dataToCapture != null && !dataToCapture.isEmpty()) { + this.dataToCapture = EnumSet.copyOf(dataToCapture); } else { - httpConnectTiming = null; + this.dataToCapture = EnumSet.noneOf(CaptureType.class); } - if (har == null || httpConnect) { - // if har capture is disabled, this filter is a no-op. for HTTP CONNECT requests we still need to capture some basic timing - // information, but no HarEntry will be added to the HarLog. - this.harEntry = null; - this.requestCaptureFilter = null; - this.responseCaptureFilter = null; - this.dataToCapture = null; - this.har = null; + // we may need to capture both the request and the response, so set up the request/response filters and delegate to them when + // the corresponding filter methods are invoked. to save time and memory, only set up the capturing filters when + // we actually need to capture the data. + if (this.dataToCapture.contains(CaptureType.REQUEST_CONTENT) || this.dataToCapture.contains(CaptureType.REQUEST_BINARY_CONTENT)) { + requestCaptureFilter = new ClientRequestCaptureFilter(originalRequest); } else { - if (dataToCapture != null && !dataToCapture.isEmpty()) { - this.dataToCapture = EnumSet.copyOf(dataToCapture); - } else { - this.dataToCapture = EnumSet.noneOf(CaptureType.class); - } - - // we may need to capture both the request and the response, so set up the request/response filters and delegate to them when - // the corresponding filter methods are invoked. to save time and memory, only set up the capturing filters when - // we actually need to capture the data. - if (this.dataToCapture.contains(CaptureType.REQUEST_CONTENT) || this.dataToCapture.contains(CaptureType.REQUEST_BINARY_CONTENT)) { - requestCaptureFilter = new ClientRequestCaptureFilter(originalRequest); - } else { - requestCaptureFilter = null; - } + requestCaptureFilter = null; + } - if (this.dataToCapture.contains(CaptureType.RESPONSE_CONTENT) || this.dataToCapture.contains(CaptureType.RESPONSE_BINARY_CONTENT)) { - responseCaptureFilter = new ServerResponseCaptureFilter(originalRequest, true); - } else { - responseCaptureFilter = null; - } + if (this.dataToCapture.contains(CaptureType.RESPONSE_CONTENT) || this.dataToCapture.contains(CaptureType.RESPONSE_BINARY_CONTENT)) { + responseCaptureFilter = new ServerResponseCaptureFilter(originalRequest, true); + } else { + responseCaptureFilter = null; + } - this.har = har; + this.har = har; - this.harEntry = new HarEntry(currentPageRef); - } + this.harEntry = new HarEntry(currentPageRef); } @Override public HttpResponse clientToProxyRequest(HttpObject httpObject) { - if (har == null) { - return null; - } - // if a ServerResponseCaptureFilter is configured, delegate to it to collect the client request. if it is not // configured, we still need to capture basic information (timings, possibly client headers, etc.), just not content. if (requestCaptureFilter != null) { @@ -319,10 +236,6 @@ public HttpResponse clientToProxyRequest(HttpObject httpObject) { @Override public HttpObject serverToProxyResponse(HttpObject httpObject) { - if (har == null) { - return super.serverToProxyResponse(httpObject); - } - // if a ServerResponseCaptureFilter is configured, delegate to it to collect the server's response. if it is not // configured, we still need to capture basic information (timings, HTTP status, etc.), just not content. if (responseCaptureFilter != null) { @@ -354,10 +267,6 @@ public HttpObject serverToProxyResponse(HttpObject httpObject) { @Override public void serverToProxyResponseTimedOut() { - if (har == null) { - return; - } - // replace any existing HarResponse that was created if the server sent a partial response HarResponse response = HarCaptureUtil.createHarResponseForFailure(); harEntry.setResponse(response); @@ -638,10 +547,10 @@ protected void captureResponseSize(HttpContent httpContent) { } /** - * Populates ssl and connect timing info in the HAR if an entry for this client and server exist in the httpConnectTimes map. + * Populates ssl and connect timing info in the HAR if an entry for this client and server exist in the cache. */ protected void captureConnectTiming() { - HttpConnectTiming httpConnectTiming = httpConnectTimes.remove(clientAddress); + HttpConnectTiming httpConnectTiming = HttpConnectHarCaptureFilter.consumeConnectTimingForConnection(clientAddress); if (httpConnectTiming != null) { harEntry.getTimings().setSsl(httpConnectTiming.getSslHandshakeTimeNanos(), TimeUnit.NANOSECONDS); harEntry.getTimings().setConnect(httpConnectTiming.getConnectTimeNanos(), TimeUnit.NANOSECONDS); @@ -659,7 +568,7 @@ protected void populateAddressFromCache(HttpRequest httpRequest) { String serverHost = getHostAndPort(httpRequest); if (serverHost != null && !serverHost.isEmpty()) { - String resolvedAddress = resolvedAddresses.get(serverHost); + String resolvedAddress = ResolvedHostnameCacheFilter.getPreviouslyResolvedAddressForHost(serverHost); if (resolvedAddress != null) { harEntry.setServerIPAddress(resolvedAddress); } else { @@ -672,34 +581,16 @@ protected void populateAddressFromCache(HttpRequest httpRequest) { @Override public InetSocketAddress proxyToServerResolutionStarted(String resolvingServerHostAndPort) { - if (har == null && !httpConnect) { - return null; - } - dnsResolutionStartedNanos = System.nanoTime(); - if (httpConnect) { - httpConnectTiming.setBlockedTimeNanos(dnsResolutionStartedNanos - connectionQueuedNanos); - } else { - // resolution started means the connection is no longer queued, so populate 'blocked' time - harEntry.getTimings().setBlocked(dnsResolutionStartedNanos - connectionQueuedNanos, TimeUnit.NANOSECONDS); - } + // resolution started means the connection is no longer queued, so populate 'blocked' time + harEntry.getTimings().setBlocked(dnsResolutionStartedNanos - connectionQueuedNanos, TimeUnit.NANOSECONDS); return null; } @Override public void proxyToServerResolutionFailed(String hostAndPort) { - // if this was an HTTP CONNECT, remove the timing information for this failed request. timing information will - // be populated by the CONNECT-specific HAR capture filter. - if (httpConnect) { - httpConnectTimes.remove(clientAddress); - } - - if (har == null) { - return; - } - HarResponse response = HarCaptureUtil.createHarResponseForFailure(); harEntry.setResponse(response); @@ -713,34 +604,16 @@ public void proxyToServerResolutionFailed(String hostAndPort) { @Override public void proxyToServerResolutionSucceeded(String serverHostAndPort, InetSocketAddress resolvedRemoteAddress) { - if (har == null && !httpConnect) { - return; - } - long dnsResolutionFinishedNanos = System.nanoTime(); - if (httpConnect) { - httpConnectTiming.setDnsTimeNanos(dnsResolutionFinishedNanos - dnsResolutionStartedNanos); - } else { - harEntry.getTimings().setDns(dnsResolutionFinishedNanos - dnsResolutionStartedNanos, TimeUnit.NANOSECONDS); - } + harEntry.getTimings().setDns(dnsResolutionFinishedNanos - dnsResolutionStartedNanos, TimeUnit.NANOSECONDS); // the address *should* always be resolved at this point InetAddress resolvedAddress = resolvedRemoteAddress.getAddress(); if (resolvedAddress != null) { addressResolved = true; - if (har != null) { - harEntry.setServerIPAddress(resolvedAddress.getHostAddress()); - } - - // place the resolved host into the hostname cache, so subsequent requests will be able to identify the IP address - HostAndPort parsedHostAndPort = HostAndPort.fromString(serverHostAndPort); - String host = parsedHostAndPort.getHostText(); - - if (host != null && !host.isEmpty()) { - resolvedAddresses.put(host, resolvedAddress.getHostAddress()); - } + harEntry.setServerIPAddress(resolvedAddress.getHostAddress()); } } @@ -754,23 +627,8 @@ public void proxyToServerConnectionStarted() { this.connectionStartedNanos = System.nanoTime(); } - @Override - public void proxyToServerConnectionSSLHandshakeStarted() { - this.sslHandshakeStartedNanos = System.nanoTime(); - } - @Override public void proxyToServerConnectionFailed() { - // if this was an HTTP CONNECT, remove the timing information for this failed request. timing information will - // be populated by the CONNECT-specific HAR capture filter. - if (httpConnect) { - httpConnectTimes.remove(clientAddress); - } - - if (har == null) { - return; - } - HarResponse response = HarCaptureUtil.createHarResponseForFailure(); harEntry.setResponse(response); @@ -784,19 +642,8 @@ public void proxyToServerConnectionFailed() { @Override public void proxyToServerConnectionSucceeded() { - if (har == null && !httpConnect) { - return; - } - long connectionSucceededTimeNanos = System.nanoTime(); - - if (httpConnect) { - // store SSL timing information in the global map so the subsequent HTTP request from the client can capture ssl and connect timing info - httpConnectTiming.setConnectTimeNanos(connectionSucceededTimeNanos - this.connectionStartedNanos); - httpConnectTiming.setSslHandshakeTimeNanos(connectionSucceededTimeNanos - this.sslHandshakeStartedNanos); - } else { - harEntry.getTimings().setConnect(connectionSucceededTimeNanos - connectionStartedNanos, TimeUnit.NANOSECONDS); - } + harEntry.getTimings().setConnect(connectionSucceededTimeNanos - connectionStartedNanos, TimeUnit.NANOSECONDS); } @Override @@ -804,17 +651,13 @@ public void proxyToServerRequestSending() { this.sendStartedNanos = System.nanoTime(); // if the hostname was not resolved (and thus the IP address populated in the har) during this request, populate the IP address from the cache - if (har != null && !addressResolved) { + if (!addressResolved) { populateAddressFromCache(capturedOriginalRequest); } } @Override public void proxyToServerRequestSent() { - if (har == null) { - return; - } - this.sendFinishedNanos = System.nanoTime(); harEntry.getTimings().setSend(sendFinishedNanos - sendStartedNanos, TimeUnit.NANOSECONDS); @@ -822,10 +665,6 @@ public void proxyToServerRequestSent() { @Override public void serverToProxyResponseReceiving() { - if (har == null) { - return; - } - this.responseReceiveStartedNanos = System.nanoTime(); // started to receive response, so populate the 'wait' time @@ -834,63 +673,8 @@ public void serverToProxyResponseReceiving() { @Override public void serverToProxyResponseReceived() { - if (har == null) { - return; - } - long responseReceivedNanos = System.nanoTime(); harEntry.getTimings().setReceive(responseReceivedNanos - responseReceiveStartedNanos, TimeUnit.NANOSECONDS); } - - /** - * Holds the connection-related timing information from an HTTP CONNECT request, so it can be added to the HAR timings for the first - * "real" request to the same host. The HTTP CONNECT and the "real" HTTP requests are processed in different HarCaptureFilter instances. - *

- * Note: The connect time must include the ssl time. According to the HAR spec at https://dvcs.w3.org/hg/webperf/raw-file/tip/specs/HAR/Overview.htm: - 

-     ssl [number, optional] (new in 1.2) - Time required for SSL/TLS negotiation. If this field is defined then the time is also
-     included in the connect field (to ensure backward compatibility with HAR 1.1). Use -1 if the timing does not apply to the
-     current request.
-
- */ - private static class HttpConnectTiming { - private volatile long connectTimeNanos; - private volatile long sslHandshakeTimeNanos; - private volatile long blockedTimeNanos; - private volatile long dnsTimeNanos; - - public void setConnectTimeNanos(long connectTimeNanos) { - this.connectTimeNanos = connectTimeNanos; - } - - public void setSslHandshakeTimeNanos(long sslHandshakeTimeNanos) { - this.sslHandshakeTimeNanos = sslHandshakeTimeNanos; - } - - public void setBlockedTimeNanos(long blockedTimeNanos) { - this.blockedTimeNanos = blockedTimeNanos; - } - - public void setDnsTimeNanos(long dnsTimeNanos) { - this.dnsTimeNanos = dnsTimeNanos; - } - - public long getConnectTimeNanos() { - return connectTimeNanos; - } - - public long getSslHandshakeTimeNanos() { - return sslHandshakeTimeNanos; - } - - public long getBlockedTimeNanos() { - return blockedTimeNanos; - } - - public long getDnsTimeNanos() { - return dnsTimeNanos; - } - } - } diff --git a/browsermob-core-littleproxy/src/main/java/net/lightbody/bmp/filters/HttpsConnectHarCaptureFilter.java b/browsermob-core-littleproxy/src/main/java/net/lightbody/bmp/filters/HttpConnectHarCaptureFilter.java similarity index 62% rename from browsermob-core-littleproxy/src/main/java/net/lightbody/bmp/filters/HttpsConnectHarCaptureFilter.java rename to browsermob-core-littleproxy/src/main/java/net/lightbody/bmp/filters/HttpConnectHarCaptureFilter.java index 618c1df73..f2fb4b5d2 100644 --- a/browsermob-core-littleproxy/src/main/java/net/lightbody/bmp/filters/HttpsConnectHarCaptureFilter.java +++ b/browsermob-core-littleproxy/src/main/java/net/lightbody/bmp/filters/HttpConnectHarCaptureFilter.java @@ -1,5 +1,6 @@ package net.lightbody.bmp.filters; +import com.google.common.cache.CacheBuilder; import io.netty.channel.ChannelHandlerContext; import io.netty.handler.codec.http.HttpObject; import io.netty.handler.codec.http.HttpRequest; @@ -9,11 +10,17 @@ import net.lightbody.bmp.core.har.HarRequest; import net.lightbody.bmp.core.har.HarResponse; import net.lightbody.bmp.core.har.HarTimings; +import net.lightbody.bmp.filters.support.HttpConnectTiming; import net.lightbody.bmp.filters.util.HarCaptureUtil; +import net.lightbody.bmp.util.BrowserMobHttpUtil; import org.littleshoot.proxy.impl.ProxyUtils; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; +import java.net.InetAddress; import java.net.InetSocketAddress; import java.util.Date; +import java.util.concurrent.ConcurrentMap; import java.util.concurrent.TimeUnit; /** @@ -25,9 +32,10 @@ * would otherwise not be any record in the HAR of the error (if the CONNECT fails, there will be no subsequent "real" * request in which to record the error). * - * TODO: refactor other HTTP CONNECT-specific logic out of HarCaptureFilter */ -public class HttpsConnectHarCaptureFilter extends HttpsAwareFiltersAdapter { +public class HttpConnectHarCaptureFilter extends HttpsAwareFiltersAdapter implements ModifiedRequestAwareFilter { + private static final Logger log = LoggerFactory.getLogger(HttpConnectHarCaptureFilter.class); + /** * The currently active HAR at the time the current request is received. */ @@ -43,6 +51,13 @@ public class HttpsConnectHarCaptureFilter extends HttpsAwareFiltersAdapter { */ private volatile Date requestStartTime; + /** + * True if this filter instance processed a {@link #proxyToServerResolutionSucceeded(String, java.net.InetSocketAddress)} call, indicating + * that the hostname was resolved and populated in the HAR (if this is not a CONNECT). + */ +// private volatile boolean addressResolved = false; + private volatile InetAddress resolvedAddress; + /** * Populated by proxyToServerResolutionStarted when DNS resolution starts. If any previous filters already resolved the address, their resolution time * will not be included in this time. See {@link HarCaptureFilter#dnsResolutionStartedNanos}. @@ -60,26 +75,70 @@ public class HttpsConnectHarCaptureFilter extends HttpsAwareFiltersAdapter { private volatile long responseReceiveStartedNanos; private volatile long sslHandshakeStartedNanos; - public HttpsConnectHarCaptureFilter(HttpRequest originalRequest, ChannelHandlerContext ctx, Har har, String currentPageRef) { + /** + * The address of the client making the request. Captured in the constructor and used when calculating and capturing ssl handshake and connect + * timing information for SSL connections. + */ + private final InetSocketAddress clientAddress; + + /** + * Stores HTTP CONNECT timing information for this request, if it is an HTTP CONNECT. + */ + private final HttpConnectTiming httpConnectTiming; + + /** + * The maximum amount of time to save timing information between an HTTP CONNECT and the subsequent HTTP request. Typically this is done + * immediately, but if for some reason it is not (e.g. due to a client crash or dropped connection), the timing information will be + * kept for this long before being evicted to prevent a memory leak. If a subsequent request does come through after eviction, it will still + * be recorded, but the timing information will not be populated in the HAR. + */ + private static final int HTTP_CONNECT_TIMING_EVICTION_SECONDS = 60; + + /** + * Concurrency of the httpConnectTiming map. Should be approximately equal to the maximum number of simultaneous connection + * attempts (but not necessarily simultaneous connections). A lower value will inhibit performance. + * TODO: tune this value for a large number of concurrent requests. develop a non-cache-based mechanism of passing ssl timings to subsequent requests. + */ + private static final int HTTP_CONNECT_TIMING_CONCURRENCY_LEVEL = 50; + + /** + * Stores SSL connection timing information from HTTP CONNNECT requests. This timing information is stored in the first HTTP request + * after the CONNECT, not in the CONNECT itself, so it needs to be stored across requests. + * + * This is the only state stored across multiple requests. + */ + private static final ConcurrentMap httpConnectTimes = + CacheBuilder.newBuilder() + .expireAfterWrite(HTTP_CONNECT_TIMING_EVICTION_SECONDS, TimeUnit.SECONDS) + .concurrencyLevel(HTTP_CONNECT_TIMING_CONCURRENCY_LEVEL) + .build() + .asMap(); + + private volatile HttpRequest modifiedHttpRequest; + + public HttpConnectHarCaptureFilter(HttpRequest originalRequest, ChannelHandlerContext ctx, Har har, String currentPageRef) { super(originalRequest, ctx); - boolean httpConnect = ProxyUtils.isCONNECT(originalRequest); + if (har == null) { + throw new IllegalStateException("Attempted har capture when har is null"); + } - if (!httpConnect) { - this.har = null; - this.currentPageRef = null; - } else { - this.har = har; - this.currentPageRef = currentPageRef; + if (!ProxyUtils.isCONNECT(originalRequest)) { + throw new IllegalStateException("Attempted HTTP CONNECT har capture on non-HTTP CONNECT request"); } + + this.har = har; + this.currentPageRef = currentPageRef; + + this.clientAddress = (InetSocketAddress) ctx.channel().remoteAddress(); + + // create and cache an HTTP CONNECT timing object to capture timing-related information + this.httpConnectTiming = new HttpConnectTiming(); + httpConnectTimes.put(clientAddress, httpConnectTiming); } @Override public HttpResponse clientToProxyRequest(HttpObject httpObject) { - if (har == null) { - return null; - } - if (httpObject instanceof HttpRequest) { // store the CONNECT start time in case of failure, so we can populate the HarEntry with it requestStartTime = new Date(); @@ -90,10 +149,6 @@ public HttpResponse clientToProxyRequest(HttpObject httpObject) { @Override public void proxyToServerResolutionFailed(String hostAndPort) { - if (har == null) { - return; - } - // since this is a CONNECT, which is not handled by the HarCaptureFilter, we need to create and populate the // entire HarEntry and add it to this har. HarEntry harEntry = createHarEntryForFailedCONNECT(HarCaptureUtil.getResolutionFailedErrorMessage(hostAndPort)); @@ -103,14 +158,12 @@ public void proxyToServerResolutionFailed(String hostAndPort) { if (dnsResolutionStartedNanos > 0L) { harEntry.getTimings().setDns(System.nanoTime() - dnsResolutionStartedNanos, TimeUnit.NANOSECONDS); } + + httpConnectTimes.remove(clientAddress); } @Override public void proxyToServerConnectionFailed() { - if (har == null) { - return; - } - // since this is a CONNECT, which is not handled by the HarCaptureFilter, we need to create and populate the // entire HarEntry and add it to this har. HarEntry harEntry = createHarEntryForFailedCONNECT(HarCaptureUtil.getConnectionFailedErrorMessage()); @@ -120,32 +173,25 @@ public void proxyToServerConnectionFailed() { if (connectionStartedNanos > 0L) { harEntry.getTimings().setConnect(System.nanoTime() - connectionStartedNanos, TimeUnit.NANOSECONDS); } + + httpConnectTimes.remove(clientAddress); } @Override public void proxyToServerConnectionSucceeded() { - if (har == null) { - return; - } - this.connectionSucceededTimeNanos = System.nanoTime(); + + httpConnectTiming.setConnectTimeNanos(connectionSucceededTimeNanos - this.connectionStartedNanos); + httpConnectTiming.setSslHandshakeTimeNanos(connectionSucceededTimeNanos - this.sslHandshakeStartedNanos); } @Override public void proxyToServerConnectionSSLHandshakeStarted() { - if (har == null) { - return; - } - this.sslHandshakeStartedNanos = System.nanoTime(); } @Override public void serverToProxyResponseTimedOut() { - if (har == null) { - return; - } - HarEntry harEntry = createHarEntryForFailedCONNECT(HarCaptureUtil.getResponseTimedOutErrorMessage()); har.getLog().addEntry(harEntry); @@ -168,67 +214,46 @@ else if (responseReceiveStartedNanos > 0L) { @Override public void proxyToServerConnectionQueued() { - if (har == null) { - return; - } - this.connectionQueuedNanos = System.nanoTime(); } @Override public InetSocketAddress proxyToServerResolutionStarted(String resolvingServerHostAndPort) { - if (har == null) { - return null; - } - dnsResolutionStartedNanos = System.nanoTime(); + httpConnectTiming.setBlockedTimeNanos(dnsResolutionStartedNanos - connectionQueuedNanos); + return null; } @Override public void proxyToServerResolutionSucceeded(String serverHostAndPort, InetSocketAddress resolvedRemoteAddress) { - if (har == null) { - return; - } - this.dnsResolutionFinishedNanos = System.nanoTime(); + + httpConnectTiming.setDnsTimeNanos(dnsResolutionFinishedNanos - dnsResolutionStartedNanos); + + // the address *should* always be resolved at this point + this.resolvedAddress = resolvedRemoteAddress.getAddress(); } @Override public void proxyToServerConnectionStarted() { - if (har == null) { - return; - } - this.connectionStartedNanos = System.nanoTime(); } @Override public void proxyToServerRequestSending() { - if (har == null) { - return; - } - this.sendStartedNanos = System.nanoTime(); } @Override public void proxyToServerRequestSent() { - if (har == null) { - return; - } - this.sendFinishedNanos = System.nanoTime(); } @Override public void serverToProxyResponseReceiving() { - if (har == null) { - return; - } - this.responseReceiveStartedNanos = System.nanoTime(); } @@ -291,12 +316,33 @@ private HarEntry createHarEntryForFailedCONNECT(String errorMessage) { response.setError(errorMessage); - // populate all timing information for this failed request populateTimingsForFailedCONNECT(harEntry); + populateServerIpAddress(harEntry); + + return harEntry; } + private void populateServerIpAddress(HarEntry harEntry) { + // populate the server IP address if it was resolved as part of this request. otherwise, populate the IP address from the cache. + if (resolvedAddress != null) { + harEntry.setServerIPAddress(resolvedAddress.getHostAddress()); + } else { + String serverHost = BrowserMobHttpUtil.getHostFromRequest(modifiedHttpRequest); + if (serverHost != null && !serverHost.isEmpty()) { + String resolvedAddress = ResolvedHostnameCacheFilter.getPreviouslyResolvedAddressForHost(serverHost); + if (resolvedAddress != null) { + harEntry.setServerIPAddress(resolvedAddress); + } else { + log.warn("Unable to find cached IP address for host: {}. IP address in HAR entry will be blank.", serverHost); + } + } else { + log.warn("Unable to identify host from request uri: {}", modifiedHttpRequest.getUri()); + } + } + } + /** * Creates a new {@link HarRequest} object for this failed HTTP CONNECT. Does not populate fields within the request, * such as the error message. @@ -310,4 +356,18 @@ private HarRequest createRequestForFailedConnect(HttpRequest httpConnectRequest) return new HarRequest(httpConnectRequest.getMethod().toString(), url, httpConnectRequest.getProtocolVersion().text()); } + /** + * Retrieves and removes (thus "consumes") the SSL timing information from the connection cache for the specified address. + * + * @param clientAddress the address of the client connection that established the HTTP tunnel + * @return the timing information for the tunnel previously established from the clientAddress + */ + public static HttpConnectTiming consumeConnectTimingForConnection(InetSocketAddress clientAddress) { + return httpConnectTimes.remove(clientAddress); + } + + @Override + public void setModifiedHttpRequest(HttpRequest modifiedHttpRequest) { + this.modifiedHttpRequest = modifiedHttpRequest; + } } diff --git a/browsermob-core-littleproxy/src/main/java/net/lightbody/bmp/filters/ResolvedHostnameCacheFilter.java b/browsermob-core-littleproxy/src/main/java/net/lightbody/bmp/filters/ResolvedHostnameCacheFilter.java new file mode 100644 index 000000000..6656163b7 --- /dev/null +++ b/browsermob-core-littleproxy/src/main/java/net/lightbody/bmp/filters/ResolvedHostnameCacheFilter.java @@ -0,0 +1,74 @@ +package net.lightbody.bmp.filters; + +import com.google.common.cache.CacheBuilder; +import com.google.common.net.HostAndPort; +import io.netty.channel.ChannelHandlerContext; +import io.netty.handler.codec.http.HttpRequest; +import org.littleshoot.proxy.HttpFiltersAdapter; + +import java.net.InetAddress; +import java.net.InetSocketAddress; +import java.util.concurrent.ConcurrentMap; +import java.util.concurrent.TimeUnit; + +/** + * Caches hostname resolutions reported by the {@link org.littleshoot.proxy.HttpFilters#proxyToServerResolutionSucceeded(String, InetSocketAddress)} + * filter method. Allows access to the resolved IP address on subsequent requests, when the address is not re-resolved because + * the connection has already been established. + */ +public class ResolvedHostnameCacheFilter extends HttpFiltersAdapter { + /** + * The maximum amount of time to save host name resolution information. This is done in order to populate the server IP address field in the + * har. Unfortunately there is not currently any way to determine the remote IP address of a keep-alive connection in a filter, so caching the + * resolved hostnames gives a generally-reasonable best guess. + */ + private static final int RESOLVED_ADDRESSES_EVICTION_SECONDS = 300; + + /** + * Concurrency of the resolvedAddresses map. Should be approximately equal to the maximum number of simultaneous connection + * attempts (but not necessarily simultaneous connections). A lower value will inhibit performance. + */ + private static final int RESOLVED_ADDRESSES_CONCURRENCY_LEVEL = 50; + + /** + * A {@code Map} that provides a reasonable estimate of the upstream server's IP address for keep-alive connections. + * The expiration time is renewed after each access, rather than after each write, so if the connection is consistently kept alive and used, + * the cached IP address will not be evicted. + */ + private static final ConcurrentMap resolvedAddresses = + CacheBuilder.newBuilder() + .expireAfterAccess(RESOLVED_ADDRESSES_EVICTION_SECONDS, TimeUnit.SECONDS) + .concurrencyLevel(RESOLVED_ADDRESSES_CONCURRENCY_LEVEL) + .build() + .asMap(); + + public ResolvedHostnameCacheFilter(HttpRequest originalRequest, ChannelHandlerContext ctx) { + super(originalRequest, ctx); + } + + @Override + public void proxyToServerResolutionSucceeded(String serverHostAndPort, InetSocketAddress resolvedRemoteAddress) { + // the address *should* always be resolved at this point + InetAddress resolvedAddress = resolvedRemoteAddress.getAddress(); + + if (resolvedAddress != null) { + // place the resolved host into the hostname cache, so subsequent requests will be able to identify the IP address + HostAndPort parsedHostAndPort = HostAndPort.fromString(serverHostAndPort); + String host = parsedHostAndPort.getHostText(); + + if (host != null && !host.isEmpty()) { + resolvedAddresses.put(host, resolvedAddress.getHostAddress()); + } + } + } + + /** + * Returns the (cached) address that was previously resolved for the specified host. + * + * @param host hostname that was previously resolved (without a port) + * @return the resolved IP address for the host, or null if the resolved address is not in the cache + */ + public static String getPreviouslyResolvedAddressForHost(String host) { + return resolvedAddresses.get(host); + } +} diff --git a/browsermob-core-littleproxy/src/main/java/net/lightbody/bmp/filters/support/HttpConnectTiming.java b/browsermob-core-littleproxy/src/main/java/net/lightbody/bmp/filters/support/HttpConnectTiming.java new file mode 100644 index 000000000..c18070f7b --- /dev/null +++ b/browsermob-core-littleproxy/src/main/java/net/lightbody/bmp/filters/support/HttpConnectTiming.java @@ -0,0 +1,51 @@ +package net.lightbody.bmp.filters.support; + +/** + * Holds the connection-related timing information from an HTTP CONNECT request, so it can be added to the HAR timings for the first + * "real" request to the same host. The HTTP CONNECT and the "real" HTTP requests are processed in different HarCaptureFilter instances. + *

+ * Note: The connect time must include the ssl time. According to the HAR spec at https://dvcs.w3.org/hg/webperf/raw-file/tip/specs/HAR/Overview.htm: + 

+ ssl [number, optional] (new in 1.2) - Time required for SSL/TLS negotiation. If this field is defined then the time is also
+ included in the connect field (to ensure backward compatibility with HAR 1.1). Use -1 if the timing does not apply to the
+ current request.
+
+ */ +public class HttpConnectTiming { + private volatile long blockedTimeNanos = -1; + private volatile long dnsTimeNanos = -1; + private volatile long connectTimeNanos = -1; + private volatile long sslHandshakeTimeNanos = -1; + + public void setConnectTimeNanos(long connectTimeNanos) { + this.connectTimeNanos = connectTimeNanos; + } + + public void setSslHandshakeTimeNanos(long sslHandshakeTimeNanos) { + this.sslHandshakeTimeNanos = sslHandshakeTimeNanos; + } + + public void setBlockedTimeNanos(long blockedTimeNanos) { + this.blockedTimeNanos = blockedTimeNanos; + } + + public void setDnsTimeNanos(long dnsTimeNanos) { + this.dnsTimeNanos = dnsTimeNanos; + } + + public long getConnectTimeNanos() { + return connectTimeNanos; + } + + public long getSslHandshakeTimeNanos() { + return sslHandshakeTimeNanos; + } + + public long getBlockedTimeNanos() { + return blockedTimeNanos; + } + + public long getDnsTimeNanos() { + return dnsTimeNanos; + } +} diff --git a/browsermob-core-littleproxy/src/main/java/net/lightbody/bmp/filters/util/HarCaptureUtil.java b/browsermob-core-littleproxy/src/main/java/net/lightbody/bmp/filters/util/HarCaptureUtil.java index 12a49e795..6a5914b22 100644 --- a/browsermob-core-littleproxy/src/main/java/net/lightbody/bmp/filters/util/HarCaptureUtil.java +++ b/browsermob-core-littleproxy/src/main/java/net/lightbody/bmp/filters/util/HarCaptureUtil.java @@ -3,7 +3,7 @@ import net.lightbody.bmp.core.har.HarResponse; /** - * Static utility methods for {@link net.lightbody.bmp.filters.HarCaptureFilter} and {@link net.lightbody.bmp.filters.HttpsConnectHarCaptureFilter}. + * Static utility methods for {@link net.lightbody.bmp.filters.HarCaptureFilter} and {@link net.lightbody.bmp.filters.HttpConnectHarCaptureFilter}. */ public class HarCaptureUtil { /** diff --git a/browsermob-core-littleproxy/src/test/groovy/net/lightbody/bmp/proxy/NewHarTest.groovy b/browsermob-core-littleproxy/src/test/groovy/net/lightbody/bmp/proxy/NewHarTest.groovy index 88d614e06..5c8689093 100644 --- a/browsermob-core-littleproxy/src/test/groovy/net/lightbody/bmp/proxy/NewHarTest.groovy +++ b/browsermob-core-littleproxy/src/test/groovy/net/lightbody/bmp/proxy/NewHarTest.groovy @@ -670,6 +670,8 @@ class NewHarTest extends MockServerTest { String capturedUrl = har.log.entries[0].request.url assertEquals("URL captured in HAR did not match request URL", requestUrl, capturedUrl) + assertEquals("Expected IP address to be populated", "127.0.0.1", har.log.entries[0].serverIPAddress) + HarResponse harResponse = har.log.entries[0].response assertNotNull("No HAR response found", harResponse) @@ -715,6 +717,8 @@ class NewHarTest extends MockServerTest { String capturedUrl = har.log.entries[0].request.url assertEquals("URL captured in HAR did not match request URL", "https://localhost:2", capturedUrl) + assertEquals("Expected IP address to be populated", "127.0.0.1", har.log.entries[0].serverIPAddress) + HarResponse harResponse = har.log.entries[0].response assertNotNull("No HAR response found", harResponse) @@ -768,6 +772,8 @@ class NewHarTest extends MockServerTest { String capturedUrl = har.log.entries[0].request.url assertEquals("URL captured in HAR did not match request URL", requestUrl, capturedUrl) + assertEquals("Expected IP address to be populated", "127.0.0.1", har.log.entries[0].serverIPAddress) + HarResponse harResponse = har.log.entries[0].response assertNotNull("No HAR response found", harResponse) @@ -825,6 +831,8 @@ class NewHarTest extends MockServerTest { String capturedUrl = har.log.entries[0].request.url assertEquals("URL captured in HAR did not match request URL", requestUrl, capturedUrl) + assertEquals("Expected IP address to be populated", "127.0.0.1", har.log.entries[0].serverIPAddress) + HarResponse harResponse = har.log.entries[0].response assertNotNull("No HAR response found", harResponse) From 0ebd2e7f91f550706259e560bb024efaa073453b Mon Sep 17 00:00:00 2001 From: Jason Eric Klaes Hoetger Date: Sun, 12 Jul 2015 15:52:51 -0700 Subject: [PATCH 4/4] Minor documentation cleanup --- .../src/main/java/net/lightbody/bmp/BrowserMobProxy.java | 6 ++---- 1 file changed, 2 insertions(+), 4 deletions(-) diff --git a/browsermob-core/src/main/java/net/lightbody/bmp/BrowserMobProxy.java b/browsermob-core/src/main/java/net/lightbody/bmp/BrowserMobProxy.java index 5306ab401..fb84ecd3f 100644 --- a/browsermob-core/src/main/java/net/lightbody/bmp/BrowserMobProxy.java +++ b/browsermob-core/src/main/java/net/lightbody/bmp/BrowserMobProxy.java @@ -1,7 +1,5 @@ package net.lightbody.bmp; -import io.netty.channel.ChannelHandlerContext; -import io.netty.handler.codec.http.HttpRequest; import net.lightbody.bmp.core.har.Har; import net.lightbody.bmp.filters.RequestFilter; import net.lightbody.bmp.filters.ResponseFilter; @@ -522,7 +520,7 @@ public interface BrowserMobProxy { * Adds a new filter factory (request/response interceptor) to the beginning of the HttpFilters chain. *

* Usage note: The actual filter (interceptor) instance is created on every request by implementing the - * {@link HttpFiltersSource#filterRequest(HttpRequest, ChannelHandlerContext)} method and returning an + * {@link HttpFiltersSource#filterRequest(io.netty.handler.codec.http.HttpRequest, io.netty.channel.ChannelHandlerContext)} method and returning an * {@link org.littleshoot.proxy.HttpFilters} instance (typically, a subclass of {@link org.littleshoot.proxy.HttpFiltersAdapter}). * To disable or bypass a filter on a per-request basis, the filterRequest() method may return null. *

@@ -538,7 +536,7 @@ public interface BrowserMobProxy { * Adds a new filter factory (request/response interceptor) to the end of the HttpFilters chain. *

* Usage note: The actual filter (interceptor) instance is created on every request by implementing the - * {@link HttpFiltersSource#filterRequest(HttpRequest, ChannelHandlerContext)} method and returning an + * {@link HttpFiltersSource#filterRequest(io.netty.handler.codec.http.HttpRequest, io.netty.channel.ChannelHandlerContext)} method and returning an * {@link org.littleshoot.proxy.HttpFilters} instance (typically, a subclass of {@link org.littleshoot.proxy.HttpFiltersAdapter}). * To disable or bypass a filter on a per-request basis, the filterRequest() method may return null. *