Pages loading extremely slow on Firefox and timing out on Chrome

[Alexander Johnson]

I'm using BrowserMob in embedded mode to record HTTP/S traffic for Java Selenium tests.

I never got BrowserMob to work for Chrome, but it used to work fine on Firefox until version 35 got released.  I never figured out why, but I couldn't get BrowserMob (version 2.0-beta10) to run stably after that.

Eventually I gave up and switched to LittleProxy as per a recommendation on Patrick's blog.  I've found LittleProxy to be a lot faster and never had any performance or stability issues with it.  Unfortunately it doesn't expose the full path in the URI (just the domain), so by itself it's incapable of recording or manipulating the full URL and/or parameters.

When I saw that BrowserMob contributors were incorporating LittleProxy on GitHub I was ecstatic!  I decided to build the 2.10-beta-1-SNAPSHOT from today and see if the stability had improved.

It has not.  After the proxy starts and the Selenium WebDriver makes the first navigation request the browser hangs for about 2 minutes before anything shows up.  When it does all of the images are stripped from the page and the text is aligned very strangely.  Fortunately the links still show up so my tests can proceed to the next page.  That page takes another minute to load and is still missing some images, but seems to be more fully loaded.  Starting with the third page everything seems to begin working as expected.  I'm not sure what's happening here, but it seems like there's some sort of timeout which is preventing javascript and/or image files from making it through the proxy (only theorizing here).

Chrome also still doesn't seem to work behind BrowserMob the way I'm running it (it works fine when using LittleProxy directly).

Here's the code I'm using to generate/start the proxy:

/**

 * Generates a BrowserMobProxyServer object.  This proxy will be run asynchronously on a separate thread.
 * Method is synchronized to prevent port collisions while starting the proxy on multiple test threads.
 * @return proxyServer: the HttpProxyServer object that was generated
 */
private synchronized static BrowserMobProxyServer generateProxyServer()
{
    // Create the proxy server object
    BrowserMobProxyServer proxyServer = new BrowserMobProxyServer();
    long associatedThreadId = Thread.currentThread().getId();

    // Generate and attach proxy request filter
    ProxyRequestFilter proxyRequestFilter = new ProxyRequestFilter(associatedThreadId);
    Context.put("proxyRequestFilter", proxyRequestFilter);
    proxyServer.addRequestFilter(proxyRequestFilter);

    // Generate and attach proxy response filter
    ProxyResponseFilter proxyResponseFilter = new ProxyResponseFilter(associatedThreadId);
    Context.put("proxyResponseFilter", proxyResponseFilter);
    proxyServer.addResponseFilter(proxyResponseFilter);

    // Load port configuration for proxy (defaults to 0, which signals Proxy to find its own port)
    int port = Config.getInteger("proxyPort");

    // Start the proxy server
    String proxyInfo = String.format("Starting proxy server on port [%s]... ", port == 0 ? "next available" : port);
    try
    {
        proxyServer.start(port);
    }
    catch(Exception e)
    {
        CombinedLogger.error(proxyInfo + "FAILURE (HALTING)!", e);
    }
    CombinedLogger.info(proxyInfo + "success");
    return proxyServer;

}.

Note that the problems occur even if the request/response filters are set to do nothing.

Here's the code that's used to configure the WebDriver to connect to the proxy (this code is identical to what was used with LittleProxy directly):

private static void configureGenericCapabilities(DesiredCapabilities capabilities)

{
    if(Config.getBoolean("useProxy"))
    {
        // Start the proxy server
        BrowserMobProxyServer proxyServer = generateProxyServer();
        Context.put("proxyServer", proxyServer);

        // Get the proxy server address.  Note:  The NODE_NAME variable (used by Jenkins) overrides any value
        // which was set for proxyServerAddress.  This allows us to redirect browsers back to the Jenkins
        // machines without knowing beforehand what the machine label is.  If you still want to manually configure
        // the proxy server address for Jenkins jobs you'll also need to set
        // proxyServerAddressOverridesJenkinsNodeName to true.
        String proxyServerAddress = Config.getString("proxyServerAddress");
        if(!Config.getBoolean("proxyServerAddressOverridesJenkinsNodeName"))
        {
            String jenkinsNodeName = Config.getString("NODE_NAME");
            if(jenkinsNodeName != null && !jenkinsNodeName.isEmpty())
            {
                String infoString = String.format("Jenkins NODE_NAME variable has been externally set to [%s].  " +
                                                  "Using this value to assign proxy server address to current " +
                                                  "node.  Please set proxyServerAddressOverridesJenkinsNodeName " +
                                                  "to true if you still wish to manually define the proxy " +
                                                  "server address.", jenkinsNodeName);
                CombinedLogger.info(infoString);
                proxyServerAddress = jenkinsNodeName;
            }
        }

        // Add proxy connection information to the WebDriver capabilities object
        Proxy proxy = new Proxy();
        proxy.setProxyType(Proxy.ProxyType.MANUAL);
        proxy.setHttpProxy(String.format("%s:%s", proxyServerAddress, proxyServer.getPort()));
        proxy.setSslProxy(String.format("%s:%s", proxyServerAddress, proxyServer.getPort()));
        capabilities.setCapability(CapabilityType.PROXY, proxy);
    }
    capabilities.setCapability(CapabilityType.ACCEPT_SSL_CERTS, true);
    capabilities.setCapability(CapabilityType.SUPPORTS_JAVASCRIPT, true);
    capabilities.setCapability(CapabilityType.SUPPORTS_WEB_STORAGE, false);
}

For reference: proxyServerAddress is localhost when I'm seeing these issues and I'm not running through Selenium Grid at the moment.

What might be different about BrowserMob sitting on top of LittleProxy (or Jetty for that matter) that causes it to fail in these scenarios?

[je...@outlook.com]

Hi Alexander,

Nothing stands out in your code that would indicate an issue to me. Two things I'd suggest to start with:

First, pull the latest code from master and run your test again. We just fixed a host of minor issues and a couple major ones, so your issue may have gotten fixed as well.

Second, if you still experience the issue even with the latest code, can you try commenting out all calls to proxyServer.addResponseFilter(...) entirely? Behind the scenes, adding a filter will cause Netty to wait for the entire response from the server before beginning to send it to the client. This can negatively impact the performance of a page, especially large pages or slow/latent connections.

If neither of those work, can you paste the BMP log output from your run? It would also help if there is a public website you know that experiences this issue, so we can reproduce and debug it.

BrowserMob Proxy 2.1.0 is still in the pre-beta 1 stage, so some defects are inevitable. I'd like to get any major known defects resolved ASAP so we can get beta-1 released to Central!

Thanks-
Jason

[Alexander Johnson]

Hi Jason,

Thanks for all of the work you've been doing!  I've synced and built the latest commit.  The problem still persists.  I believe the issue is with how we're formatting our URLs for the test environment.  In production our URL is something like this:

http://product.company.com

If I run my tests against production through browsermob-core-littleproxy they work fine.  However, in our test environment the URL is formatted like this:

http://product.company.com.test.environment.net

When I run my tests in the test environment through browsermob-core-littleproxy they're unable to reach our pages.

I went looking for a URL outside of our firewall that you can use to reproduce the issue.  Most of them are working fine (including HTTPS sites such as USBank).  I did find this though (content is coincidentally relevant):

http://docs.racket-lang.org/net/url.html

Interestingly, if I don't add any filters the Racket page loads fine but our test environment pages still won't load.  It seems like there may be two issues which are both related to URL formatting.

I've attached the output for the test when loading both our page and the Racket page as well as both with and without the filters added.  The part that stands out the most to me is this:

"3679 [LittleProxy-ClientToProxyWorker-0] INFO org.littleshoot.proxy.impl.ClientToProxyConnection - (AWAITING_INITIAL) [id: 0xcad2d495, /0:0:0:0:0:0:0:1:49588 => /0:0:0:0:0:0:0:1:49574]: Bad Host product.company.com.test.environment.net:443"

If you need anything else to troubleshoot the issue please let me know.

Thank you for your time,

-Alex

[je...@outlook.com]

Hi Alex,

The problem with the racket page appears to be the lack of a dependency. If you add this to your pom, it should solve your problem:

<dependency>
    <groupId>com.jcraft</groupId>
    <artifactId>jzlib</artifactId>
    <version>1.1.3</version>
</dependency>

I'm not sure why it's not included by default. I'll see if it makes sense to add it.

The 2nd error you mentioned, the Bad Host error, is caused by a failure to resolve the hostname using DNS. Can you run the test in AdvancedHostResolver#testResolveAddress(), replacing www.yahoo.com with the test environment hostname that is failing?

[Alex Johnson]

Confirming that adding a dependency on jzlib solves the problem with loading Racket when request/response filters are added.  Thanks for that.

The AdvancedHostResolver#testResolveAddress test passes for http://product.company.com in about 400 milliseconds.

When I run the same test for http://product.company.com.test.environment.net it takes 2 minutes and 32 seconds, but it does pass.

Do you think there's some sort of DNS resolution timeout that's set too high before it looks in the right place (IE: tries to connect to a central server somewhere before using the local one)?

--

---
You received this message because you are subscribed to a topic in the Google Groups "BrowserMob Proxy" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/browsermob-proxy/1X2OTEuor38/unsubscribe.
To unsubscribe from this group and all its topics, send an email to browsermob-pro...@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

[Alexander Johnson]

Update:  I've spent some time debugging and the problem appears to be specific to IPv6.

In net.lightbody.bmp.proxy.dns.DnsJavaResolver there's a function called resolveRemapped:

@Override
public Collection<InetAddress> resolveRemapped(String remappedHost) {
    // special case for IP literals: return the InetAddress without doing a dnsjava lookup. dnsjava seems to handle ipv4 literals
    // reasonably well, but does not handle ipv6 literals (with or without [] brackets) correctly.
    // note this does not work properly for ipv6 literals with a scope identifier, which is a known issue for InetAddresses.isInetAddress().
    // (dnsjava also handles the situation incorrectly)
    if (InetAddresses.isInetAddress(remappedHost)) {
        return Collections.singletonList(InetAddresses.forString(remappedHost));
    }

    List<InetAddress> addresses = new ArrayList<InetAddress>();

    // retrieve both IPv4 and IPv6 addresses
    addresses.addAll(resolveHostByType(remappedHost, Type.A));
    addresses.addAll(resolveHostByType(remappedHost, Type.AAAA));

    return addresses;
}

I'm noticing that the address returns fine for IPv4 (Type A), but fails to return for IPv6 (Type AAAA).  I'm willing to bet it has something to do with our corporate firewall.  I've traced the lookups for both our production and our lab URLs and they're completely identical all the way through the dnsjava call stack.  The only difference is that the query for our production URL gets a response right away whereas the query for the lab URL throws a SocketTimeoutException (10 seconds).  This gets repeated several times both internally and when BrowserMob calls dnsjava.  This seems to be why its taking ~2 minutes before Browsermob gives up on the IPv6 lookup and returns the IPv4 address.

If I comment out the IPv6 lookup then everything works fine and my pages load as expected!  I'm wondering if it would make sense to add a check between these two lookups and return immediately if an IPv4 address was found?  Are there any scenarios where both an IPv4 and IPv6 address would be present/useful?  I think I'll go ahead and make this modification locally.  Let me know if I should send a pull request.

-Alex

[je...@outlook.com]

Thanks for looking into this further, Alex. I like your suggestion of returning immediately if an IPv4 address is found, at least to work around this issue for now. I'm in the middle of some updates to the resolvers and I'll include that change. In the meantime, could you try adding this to your code, before calling start():

proxy.setHostNameResolver(ClientUtil.createNativeResolver());

That will use the native JDK resolver by default instead of dnsjava. I'm considering removing dnsjava as the default resolver when using the LittleProxy implementation, since it often seems to cause more problems than it solves.

Thanks-
Jason

[je...@outlook.com]

The resolver updates you suggested have been merged, so you shouldn't see this issue any longer. Could you give it a try? We're extremely close to the first 2.1 beta release to Central, and any extra testing would be fantastic!

[Alexander Johnson]

Hi Jason,

I just built the latest version and unfortunately I'm having some issues.  I don't think the IPv4/IPv6 change is the problem though since I made that same change locally and it worked fine.  I've narrowed it down to the following test case:

1. Start BrowserMob/LittleProxy
   
2. Start Selenium WebDriver
   
3. Tell WebDriver to navigate to http://www.google.com
   
4. Tell WebDriver to navigate to http://www.google.com again

The first time it loads Google I'm noticing two strange things:

1. The URL shown in the address bar is https://www.google.com/?gws_rd=ssl instead of just http://www.google.com
   
2. None of the images load:

The second time it navigates to Google it doesn't seem to connect at all.  The following screen is shown instead:

In the logs there's something from Netty about 'originalHost' already being in use.  I've attached the full debug log from the test case mentioned above.

Would you mind taking a look?  If this does not repro for you then I can try and dive in or strip it down to a shareable project without all of our enterprise stuff included.  However, I might not have time to do that until next week.

For what it's worth, this is happening on both Chrome & Firefox either with or without any filters attached.  If I revert the Browsermob version to what we had last week then everything starts working again.

Thanks,

-Alex

[je...@outlook.com]

Hi Alex,

Are you specifying version 4.0.23 of netty in your pom? The issue you're seeing may be a result of a defect that has since been fixed. Can you specify 4.0.27, or remove the explicit netty dependency? BMP pulls in 4.0.27 by default.

The URL with the query param you're seeing is expected behavior. Google responds with a 302 when you try to visit the non-https version of google.com.

Thanks-
Jason

[Alexander Johnson]

Hi Jason,

Problem solved!  It looks like net.lightbody.bmp:browsermob-littleproxy-core is depending on an artifact called net.lightbody.bmp:littleproxy with an unspecified version.  This is resolving to a 1.1.0-beta-bmp-4 version in my local Maven repository.  The 1.1.0-beta-bmp-4 version of net.lightbody.bmp:littleproxy is pulling in the 4.0.23 version of io.netty:netty-all.  I was able to resolve this by declaring a direct dependency on the 4.0.27 version as you suggested.  I believe this could also be prevented from within Browsermob by adding a netty exclusion to the net.lightbody.bmp:littleproxy dependency in net.lightbody.bmp:browsermob-littleproxy-core's pom file.  Would that work?  Here's the output I saw when running mvn dependency:tree:

[INFO] +- net.lightbody.bmp:browsermob-core-littleproxy:jar:2.1.0-beta-1-5.28.2015:compile
[INFO] |  +- net.lightbody.bmp:browsermob-core:jar:2.1.0-beta-1-5.28.2015:compile
[INFO] |  |  +- (com.fasterxml.jackson.core:jackson-core:jar:2.4.4:compile - omitted for conflict with 2.5.3)
[INFO] |  |  +- (com.fasterxml.jackson.core:jackson-databind:jar:2.4.4:compile - omitted for conflict with 2.5.3)
[INFO] |  |  +- (com.fasterxml.jackson.core:jackson-annotations:jar:2.4.4:compile - omitted for conflict with 2.5.0)
[INFO] |  |  +- (org.slf4j:slf4j-api:jar:1.7.12:compile - omitted for conflict with 1.7.7)
[INFO] |  |  +- org.slf4j:jcl-over-slf4j:jar:1.7.12:compile
[INFO] |  |  |  \- (org.slf4j:slf4j-api:jar:1.7.12:compile - omitted for conflict with 1.7.7)
[INFO] |  |  +- org.apache.httpcomponents:httpmime:jar:4.3.4:compile
[INFO] |  |  +- (commons-io:commons-io:jar:2.4:compile - omitted for duplicate)
[INFO] |  |  +- (com.google.guava:guava:jar:18.0:compile - omitted for duplicate)
[INFO] |  |  +- net.sf.uadetector:uadetector-resources:jar:2014.10:compile
[INFO] |  |  |  +- net.sf.uadetector:uadetector-core:jar:0.9.22:compile
[INFO] |  |  |  |  +- net.sf.qualitycheck:quality-check:jar:1.3:compile
[INFO] |  |  |  |  |  \- (com.google.code.findbugs:jsr305:jar:2.0.1:compile - omitted for conflict with 2.0.0)
[INFO] |  |  |  |  +- (com.google.code.findbugs:jsr305:jar:2.0.3:compile - omitted for conflict with 2.0.0)
[INFO] |  |  |  |  +- javax.annotation:jsr250-api:jar:1.0:compile
[INFO] |  |  |  |  \- (org.slf4j:slf4j-api:jar:1.7.7:compile - omitted for duplicate)
[INFO] |  |  |  \- (org.slf4j:slf4j-api:jar:1.7.7:compile - omitted for duplicate)
[INFO] |  |  \- dnsjava:dnsjava:jar:2.1.7:compile
[INFO] |  +- net.lightbody.bmp:littleproxy:jar:1.1.0-beta-bmp-4:compile
[INFO] |  |  +- (com.google.guava:guava:jar:14.0.1:compile - omitted for conflict with 18.0)
[INFO] |  |  +- commons-cli:commons-cli:jar:1.2:compile
[INFO] |  |  +- (commons-codec:commons-codec:jar:1.7:compile - omitted for conflict with 1.9)
[INFO] |  |  +- (commons-io:commons-io:jar:2.4:compile - omitted for duplicate)
[INFO] |  |  +- (org.apache.commons:commons-lang3:jar:3.1:compile - omitted for duplicate)
[INFO] |  |  +- io.netty:netty-all:jar:4.0.23.Final:compile
[INFO] |  |  \- (org.slf4j:slf4j-api:jar:1.7.2:compile - omitted for conflict with 1.7.7)
[INFO] |  \- com.jcraft:jzlib:jar:1.1.3:compile

Thanks,

-Alex

[je...@outlook.com]

Awesome! I'm very happy this is finally working for you. Thank you for testing this and helping identify these issues! I just merged a PR that declares an explicit dependency on netty, as you suggested, so that should force the netty version, unless projects explicitly override it. We actually do need to pull in the transitive netty dependencyfrom LittleProxy, but we need to use a more recent netty with recent bugfixes.

Thanks again, Alex! We're about to release 2.1.0-beta-1, and you have been a huge help getting some of critical issues identified and resolved.

-Jason

[Alex Johnson]

Awesome, glad to help!  I'm looking forward to the release.  This tool makes my job a whole lot easier.

Thanks,

-Alex

--

[Alex Johnson]

Ah, just noticed it's officially out.  Excellent!

[je...@outlook.com]

Yes, thanks in no small part to your efforts. If you do encounter any issues with the release, feel free to ask here or open a new issue on github.

Thanks again!
-Jason