RE: SimplePostToolTest very slow
: the main problem with any security manager is: To check if a connection : is allowed, it has to resolve DNS and look the IP up in the policy. Can we update the secuity policy to fail fast anytime a DNS lookup happens? even if it happens implicitly in situations like this (URL.hashCode) so we can more easily find problems like this via test Exceptions instead of via slow tests? (I'm not saying it's a good idea to do this -- i don't know -- it might make more trouble then it's worth ... i'm just trying to udnerstand if it's possible) -Hoss - To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org For additional commands, e-mail: dev-h...@lucene.apache.org
Re: SimplePostToolTest very slow
Solr tests will all completely fail in that case then: just like they do when i run them on my laptop with internet disconnected. thats because it looks up its own hostname: which involves reverse/forward dns lookups. On Mon, Sep 16, 2013 at 1:07 PM, Chris Hostetter hossman_luc...@fucit.org wrote: : the main problem with any security manager is: To check if a connection : is allowed, it has to resolve DNS and look the IP up in the policy. Can we update the secuity policy to fail fast anytime a DNS lookup happens? even if it happens implicitly in situations like this (URL.hashCode) so we can more easily find problems like this via test Exceptions instead of via slow tests? (I'm not saying it's a good idea to do this -- i don't know -- it might make more trouble then it's worth ... i'm just trying to udnerstand if it's possible) -Hoss - To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org For additional commands, e-mail: dev-h...@lucene.apache.org - To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org For additional commands, e-mail: dev-h...@lucene.apache.org
RE: SimplePostToolTest very slow
Hallo Shai,
the main problem with any security manager is: To check if a connection is
allowed, it has to resolve DNS and look the IP up in the policy.
As Robert said before: The fix is easy: To emulate a broken URL use one of the
non-routeable local IPv6 prefixes. We do this in Solr tests already to emulate
broken cloud slaves, see the abstract solr cloud test class. We should use one
of these URLs instead of example.com. I disagree with changing the security
policy at all, because it helps to fix broken tests (like this one *g*) and
prevents external hackers to overtake my own test instance, because Solr runs
on 0.0.0.0, so while running tests you can easily connect to solr from
internet. The security manager prevents this, too.
Uwe
-
Uwe Schindler
H.-H.-Meier-Allee 63, D-28213 Bremen
http://www.thetaphi.de/ http://www.thetaphi.de
eMail: u...@thetaphi.de
From: Shai Erera [mailto:ser...@gmail.com]
Sent: Saturday, September 14, 2013 6:32 AM
To: dev@lucene.apache.org
Subject: Re: SimplePostToolTest very slow
OK, I think I've made some progress -- configuration issue, but not proxies, it
seems to be our security manager/policy.
I printed system properties and env in setUp and ran only a single test
(testIsOn) to compare the output. I didn't notice any proxy settings, but I did
notice that from Ant we're using our own security manager and policy. So when I
ran the test from eclipse using
-Djava.security.manager=org.apache.lucene.util.TestSecurityManager
-Djava.security.policy=D:\dev\lucene\lucene-trunk\lucene\tools\junit4\tests.policy,
it ran for 23s too (I only ran a single test method).
I don't think it's related to TestSecurityManager, since it only checks that
System.exit isn't called from tests.
Looking at tests.policy, there are a bunch of socket connection related lines
.. I'm guess it's somewhere there, though I don't know this stuff.
I will try to look into it more later.
Shai
On Sat, Sep 14, 2013 at 6:59 AM, Shai Erera ser...@gmail.com wrote:
I still don't see why you'd get different timings between Eclipse and
Ant if you're running with the same VM -- it should be pretty
consistent (either it caches dns lookups or it doesn't).
I agree, it's suspicious. I searched for URL performance differences between
eclipse and Ant and hit this page: http://ant.apache.org/manual/proxy.html. It
suggests Ant uses different proxy settings by default for its own tasks as well
as 3rd party tasks that use java.net.URL. I tried running with -autoproxy but
from Ant each test method still takes ~23s vs Eclipse which is ~0.1s.
Will be interesting to identify the differences .. I think it's a configuration
issue, as Eclipse needs to make URL connections for e.g. its marketplace, so
maybe it comes pre-configured somehow. I'm now curious, I'll dig :).
Shai
On Sat, Sep 14, 2013 at 12:33 AM, Chris Hostetter hossman_luc...@fucit.org
wrote:
: If you want to experiment, a really trivial test is below -- on my system,
: there is a ~5 second gap between each pair of INIT and H1 timestamps,
: but no other odd gaps in subsequent timestamps -- suggesting no caching of
: DNS per hostname, but that the URL class doesn't re-lookup on subsequent
: hashCode() calls.
Or maybe i could actually cut paste the test this time...
import java.net.URL;
import org.apache.lucene.util.LuceneTestCase;
public class TestURLDNSAbsurdity extends LuceneTestCase {
public void testHowSlowCanYouGo() throws Exception {
go(1);
go(2);
}
public void go(String s) throws Exception {
System.out.println(s + PRE: + System.currentTimeMillis());
URL url = new URL(http://example.com/;);
System.out.println(s + INIT: + System.currentTimeMillis());
int h1 = url.hashCode();
System.out.println(s + H1: + System.currentTimeMillis());
int h2 = url.hashCode();
System.out.println(s + H2: + System.currentTimeMillis());
boolean e1 = url.equals(this);
System.out.println(s + E1: + System.currentTimeMillis());
boolean e2 = url.equals(this);
System.out.println(s + E2: + System.currentTimeMillis());
assertEquals(h1,h2);
assertEquals(e1,e2);
}
}
...
[junit4] Started J0 PID(31843@frisbee).
[junit4] Suite: org.apache.solr.util.TestURLDNSAbsurdity
[junit4] 1 1 PRE: 1379107971313
[junit4] 1 1INIT: 1379107971314
[junit4] 1 1 H1: 1379107976449
[junit4] 1 1 H2: 1379107976449
[junit4] 1 1 E1: 1379107976449
[junit4] 1 1 E2: 1379107976449
[junit4] 1 2 PRE: 1379107976450
[junit4] 1 2INIT: 1379107976450
[junit4] 1 2 H1: 1379107981510
[junit4] 1 2 H2: 1379107981510
[junit4] 1 2 E1: 1379107981510
[junit4] 1 2 E2: 1379107981510
[junit4] OK 10.3s | TestURLDNSAbsurdity.testHowSlowCanYouGo
-Hoss
-
To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org
For additional commands
Re: SimplePostToolTest very slow
Can you check if you're using the same virtual machine from Eclipse and from command line? Maybe it's a different vendor/architecture/version? I will look into this if you can't figure it out before me. Just give me the full ANT line you were using. Dawid On Fri, Sep 13, 2013 at 6:15 PM, Shai Erera ser...@gmail.com wrote: Yes it happens with the same seed. And it happened both times I ran it: from Ant it takes ~280s, from eclipse ~1s. Both times the test seems successful, and the outputs looks the same, so I guess it means it does the same thing when run from eclipse and ant. Am I the only one that experiences this slowness? Shai On Fri, Sep 13, 2013 at 7:06 PM, Dawid Weiss dawid.we...@cs.put.poznan.pl wrote: Is it with the same seed? Dawid On Fri, Sep 13, 2013 at 1:04 PM, Michael McCandless luc...@mikemccandless.com wrote: It passes when run from Eclipse? It seems crazy that it can take 280 sec from ant but 1 sec from Eclipse. Maybe it's not actually running, when running from Eclipse? +1 for @Nightly it we can't get to the bottom of it ... Mike McCandless http://blog.mikemccandless.com On Thu, Sep 12, 2013 at 5:03 PM, Shai Erera ser...@gmail.com wrote: Hi I was running Solr tests now and thought they hung, but eventually they continued and I noticed that SimplePostToolTest took 280s to complete. I tried from eclipse, and it took 1s. Tried from Ant again, 276s. I compared (briefly) the outputs of the test from eclipse and Ant, and they look similar. Is this expected? Maybe when the test runs from Ant it does more work (i.e. system properties that are sent from build.xml but not in eclipse cause it to index more data or something?). If it helps, here's what the test prints: [junit4] Suite: org.apache.solr.util.SimplePostToolTest [junit4] 2 log4j:WARN No such property [conversionPattern] in org.apache.solr.util.SolrLogLayout. [junit4] 2 396 T24 oas.SolrTestCaseJ4.setUp ###Starting testIsOn [junit4] 2 23126 T24 oas.SolrTestCaseJ4.tearDown ###Ending testIsOn [junit4] OK 22.8s | SimplePostToolTest.testIsOn [junit4] 2 23163 T24 oas.SolrTestCaseJ4.setUp ###Starting testAppendUrlPath [junit4] 2 54667 T24 oas.SolrTestCaseJ4.tearDown ###Ending testAppendUrlPath [junit4] OK 31.5s | SimplePostToolTest.testAppendUrlPath [junit4] 2 54682 T24 oas.SolrTestCaseJ4.setUp ###Starting testGuessType [junit4] 2 77185 T24 oas.SolrTestCaseJ4.tearDown ###Ending testGuessType [junit4] OK 22.5s | SimplePostToolTest.testGuessType [junit4] 2 77198 T24 oas.SolrTestCaseJ4.setUp ###Starting testTypeSupported [junit4] 2 99701 T24 oas.SolrTestCaseJ4.tearDown ###Ending testTypeSupported [junit4] OK 22.5s | SimplePostToolTest.testTypeSupported [junit4] 2 99712 T24 oas.SolrTestCaseJ4.setUp ###Starting testRobotsExclusion [junit4] 2 122214 T24 oas.SolrTestCaseJ4.tearDown ###Ending testRobotsExclusion [junit4] OK 22.5s | SimplePostToolTest.testRobotsExclusion [junit4] 2 15 T24 oas.SolrTestCaseJ4.setUp ###Starting testParseArgsAndInit [junit4] 2 144727 T24 oas.SolrTestCaseJ4.tearDown ###Ending testParseArgsAndInit [junit4] OK 22.5s | SimplePostToolTest.testParseArgsAndInit [junit4] 2 144736 T24 oas.SolrTestCaseJ4.setUp ###Starting testDoWebMode [junit4] 2 SimplePostTool: WARNING: The URL http://example.com/disallowed returned a HTTP result status of 403 [junit4] 2 185795 T24 oas.SolrTestCaseJ4.tearDown ###Ending testDoWebMode [junit4] 1 Entering crawl at level 0 (1 links total, 1 new) [junit4] 1 POSTed web resource http://example.com (depth: 0) [junit4] 1 Entering crawl at level 1 (2 links total, 2 new) [junit4] 1 POSTed web resource http://example.com/page2 (depth: 1) [junit4] 1 POSTed web resource http://example.com/page1 (depth: 1) [junit4] 1 Entering crawl at level 2 (2 links total, 2 new) [junit4] 1 POSTed web resource http://example.com/page1/foo (depth: 2) [junit4] 1 Entering crawl at level 3 (1 links total, 1 new) [junit4] 1 POSTed web resource http://example.com/page1/foo/bar (depth: 3) [junit4] 1 Entering crawl at level 0 (1 links total, 1 new) [junit4] 1 POSTed web resource http://example.com (depth: 0) [junit4] 1 Entering crawl at level 1 (2 links total, 2 new) [junit4] 1 POSTed web resource http://example.com/page2 (depth: 1) [junit4] 1 POSTed web resource http://example.com/page1 (depth: 1) [junit4] 1 Entering crawl at level 0 (1 links total, 1 new) [junit4] 1 POSTed web resource http://example.com (depth: 0) [junit4] 1 Entering crawl at level 1 (2 links total, 2 new) [junit4] 1 POSTed web resource http://example.com/page2 (depth: 1) [junit4] 1 POSTed web resource http://example.com/page1 (depth:
Re: SimplePostToolTest very slow
It passes when run from Eclipse? It seems crazy that it can take 280 sec from ant but 1 sec from Eclipse. Maybe it's not actually running, when running from Eclipse? +1 for @Nightly it we can't get to the bottom of it ... Mike McCandless http://blog.mikemccandless.com On Thu, Sep 12, 2013 at 5:03 PM, Shai Erera ser...@gmail.com wrote: Hi I was running Solr tests now and thought they hung, but eventually they continued and I noticed that SimplePostToolTest took 280s to complete. I tried from eclipse, and it took 1s. Tried from Ant again, 276s. I compared (briefly) the outputs of the test from eclipse and Ant, and they look similar. Is this expected? Maybe when the test runs from Ant it does more work (i.e. system properties that are sent from build.xml but not in eclipse cause it to index more data or something?). If it helps, here's what the test prints: [junit4] Suite: org.apache.solr.util.SimplePostToolTest [junit4] 2 log4j:WARN No such property [conversionPattern] in org.apache.solr.util.SolrLogLayout. [junit4] 2 396 T24 oas.SolrTestCaseJ4.setUp ###Starting testIsOn [junit4] 2 23126 T24 oas.SolrTestCaseJ4.tearDown ###Ending testIsOn [junit4] OK 22.8s | SimplePostToolTest.testIsOn [junit4] 2 23163 T24 oas.SolrTestCaseJ4.setUp ###Starting testAppendUrlPath [junit4] 2 54667 T24 oas.SolrTestCaseJ4.tearDown ###Ending testAppendUrlPath [junit4] OK 31.5s | SimplePostToolTest.testAppendUrlPath [junit4] 2 54682 T24 oas.SolrTestCaseJ4.setUp ###Starting testGuessType [junit4] 2 77185 T24 oas.SolrTestCaseJ4.tearDown ###Ending testGuessType [junit4] OK 22.5s | SimplePostToolTest.testGuessType [junit4] 2 77198 T24 oas.SolrTestCaseJ4.setUp ###Starting testTypeSupported [junit4] 2 99701 T24 oas.SolrTestCaseJ4.tearDown ###Ending testTypeSupported [junit4] OK 22.5s | SimplePostToolTest.testTypeSupported [junit4] 2 99712 T24 oas.SolrTestCaseJ4.setUp ###Starting testRobotsExclusion [junit4] 2 122214 T24 oas.SolrTestCaseJ4.tearDown ###Ending testRobotsExclusion [junit4] OK 22.5s | SimplePostToolTest.testRobotsExclusion [junit4] 2 15 T24 oas.SolrTestCaseJ4.setUp ###Starting testParseArgsAndInit [junit4] 2 144727 T24 oas.SolrTestCaseJ4.tearDown ###Ending testParseArgsAndInit [junit4] OK 22.5s | SimplePostToolTest.testParseArgsAndInit [junit4] 2 144736 T24 oas.SolrTestCaseJ4.setUp ###Starting testDoWebMode [junit4] 2 SimplePostTool: WARNING: The URL http://example.com/disallowed returned a HTTP result status of 403 [junit4] 2 185795 T24 oas.SolrTestCaseJ4.tearDown ###Ending testDoWebMode [junit4] 1 Entering crawl at level 0 (1 links total, 1 new) [junit4] 1 POSTed web resource http://example.com (depth: 0) [junit4] 1 Entering crawl at level 1 (2 links total, 2 new) [junit4] 1 POSTed web resource http://example.com/page2 (depth: 1) [junit4] 1 POSTed web resource http://example.com/page1 (depth: 1) [junit4] 1 Entering crawl at level 2 (2 links total, 2 new) [junit4] 1 POSTed web resource http://example.com/page1/foo (depth: 2) [junit4] 1 Entering crawl at level 3 (1 links total, 1 new) [junit4] 1 POSTed web resource http://example.com/page1/foo/bar (depth: 3) [junit4] 1 Entering crawl at level 0 (1 links total, 1 new) [junit4] 1 POSTed web resource http://example.com (depth: 0) [junit4] 1 Entering crawl at level 1 (2 links total, 2 new) [junit4] 1 POSTed web resource http://example.com/page2 (depth: 1) [junit4] 1 POSTed web resource http://example.com/page1 (depth: 1) [junit4] 1 Entering crawl at level 0 (1 links total, 1 new) [junit4] 1 POSTed web resource http://example.com (depth: 0) [junit4] 1 Entering crawl at level 1 (2 links total, 2 new) [junit4] 1 POSTed web resource http://example.com/page2 (depth: 1) [junit4] 1 POSTed web resource http://example.com/page1 (depth: 1) [junit4] 1 Entering crawl at level 2 (2 links total, 2 new) [junit4] 1 POSTed web resource http://example.com/disallowed (depth: 2) [junit4] 1 POSTed web resource http://example.com/page1/foo (depth: 2) [junit4] 1 Entering crawl at level 3 (1 links total, 1 new) [junit4] 1 POSTed web resource http://example.com/page1/foo/bar (depth: 3) [junit4] OK 41.1s | SimplePostToolTest.testDoWebMode [junit4] 2 185806 T24 oas.SolrTestCaseJ4.setUp ###Starting testAppendParam [junit4] 2 208310 T24 oas.SolrTestCaseJ4.tearDown ###Ending testAppendParam [junit4] OK 22.5s | SimplePostToolTest.testAppendParam [junit4] 2 208320 T24 oas.SolrTestCaseJ4.setUp ###Starting testComputeFullUrl [junit4] 2 230822 T24 oas.SolrTestCaseJ4.tearDown ###Ending testComputeFullUrl [junit4] OK 22.5s | SimplePostToolTest.testComputeFullUrl [junit4] 2 230832 T24 oas.SolrTestCaseJ4.setUp ###Starting
Re: SimplePostToolTest very slow
Yes it happens with the same seed. And it happened both times I ran it: from Ant it takes ~280s, from eclipse ~1s. Both times the test seems successful, and the outputs looks the same, so I guess it means it does the same thing when run from eclipse and ant. Am I the only one that experiences this slowness? Shai On Fri, Sep 13, 2013 at 7:06 PM, Dawid Weiss dawid.we...@cs.put.poznan.plwrote: Is it with the same seed? Dawid On Fri, Sep 13, 2013 at 1:04 PM, Michael McCandless luc...@mikemccandless.com wrote: It passes when run from Eclipse? It seems crazy that it can take 280 sec from ant but 1 sec from Eclipse. Maybe it's not actually running, when running from Eclipse? +1 for @Nightly it we can't get to the bottom of it ... Mike McCandless http://blog.mikemccandless.com On Thu, Sep 12, 2013 at 5:03 PM, Shai Erera ser...@gmail.com wrote: Hi I was running Solr tests now and thought they hung, but eventually they continued and I noticed that SimplePostToolTest took 280s to complete. I tried from eclipse, and it took 1s. Tried from Ant again, 276s. I compared (briefly) the outputs of the test from eclipse and Ant, and they look similar. Is this expected? Maybe when the test runs from Ant it does more work (i.e. system properties that are sent from build.xml but not in eclipse cause it to index more data or something?). If it helps, here's what the test prints: [junit4] Suite: org.apache.solr.util.SimplePostToolTest [junit4] 2 log4j:WARN No such property [conversionPattern] in org.apache.solr.util.SolrLogLayout. [junit4] 2 396 T24 oas.SolrTestCaseJ4.setUp ###Starting testIsOn [junit4] 2 23126 T24 oas.SolrTestCaseJ4.tearDown ###Ending testIsOn [junit4] OK 22.8s | SimplePostToolTest.testIsOn [junit4] 2 23163 T24 oas.SolrTestCaseJ4.setUp ###Starting testAppendUrlPath [junit4] 2 54667 T24 oas.SolrTestCaseJ4.tearDown ###Ending testAppendUrlPath [junit4] OK 31.5s | SimplePostToolTest.testAppendUrlPath [junit4] 2 54682 T24 oas.SolrTestCaseJ4.setUp ###Starting testGuessType [junit4] 2 77185 T24 oas.SolrTestCaseJ4.tearDown ###Ending testGuessType [junit4] OK 22.5s | SimplePostToolTest.testGuessType [junit4] 2 77198 T24 oas.SolrTestCaseJ4.setUp ###Starting testTypeSupported [junit4] 2 99701 T24 oas.SolrTestCaseJ4.tearDown ###Ending testTypeSupported [junit4] OK 22.5s | SimplePostToolTest.testTypeSupported [junit4] 2 99712 T24 oas.SolrTestCaseJ4.setUp ###Starting testRobotsExclusion [junit4] 2 122214 T24 oas.SolrTestCaseJ4.tearDown ###Ending testRobotsExclusion [junit4] OK 22.5s | SimplePostToolTest.testRobotsExclusion [junit4] 2 15 T24 oas.SolrTestCaseJ4.setUp ###Starting testParseArgsAndInit [junit4] 2 144727 T24 oas.SolrTestCaseJ4.tearDown ###Ending testParseArgsAndInit [junit4] OK 22.5s | SimplePostToolTest.testParseArgsAndInit [junit4] 2 144736 T24 oas.SolrTestCaseJ4.setUp ###Starting testDoWebMode [junit4] 2 SimplePostTool: WARNING: The URL http://example.com/disallowed returned a HTTP result status of 403 [junit4] 2 185795 T24 oas.SolrTestCaseJ4.tearDown ###Ending testDoWebMode [junit4] 1 Entering crawl at level 0 (1 links total, 1 new) [junit4] 1 POSTed web resource http://example.com (depth: 0) [junit4] 1 Entering crawl at level 1 (2 links total, 2 new) [junit4] 1 POSTed web resource http://example.com/page2 (depth: 1) [junit4] 1 POSTed web resource http://example.com/page1 (depth: 1) [junit4] 1 Entering crawl at level 2 (2 links total, 2 new) [junit4] 1 POSTed web resource http://example.com/page1/foo(depth: 2) [junit4] 1 Entering crawl at level 3 (1 links total, 1 new) [junit4] 1 POSTed web resource http://example.com/page1/foo/bar (depth: 3) [junit4] 1 Entering crawl at level 0 (1 links total, 1 new) [junit4] 1 POSTed web resource http://example.com (depth: 0) [junit4] 1 Entering crawl at level 1 (2 links total, 2 new) [junit4] 1 POSTed web resource http://example.com/page2 (depth: 1) [junit4] 1 POSTed web resource http://example.com/page1 (depth: 1) [junit4] 1 Entering crawl at level 0 (1 links total, 1 new) [junit4] 1 POSTed web resource http://example.com (depth: 0) [junit4] 1 Entering crawl at level 1 (2 links total, 2 new) [junit4] 1 POSTed web resource http://example.com/page2 (depth: 1) [junit4] 1 POSTed web resource http://example.com/page1 (depth: 1) [junit4] 1 Entering crawl at level 2 (2 links total, 2 new) [junit4] 1 POSTed web resource http://example.com/disallowed(depth: 2) [junit4] 1 POSTed web resource http://example.com/page1/foo(depth: 2) [junit4] 1 Entering crawl at level 3 (1 links total, 1 new) [junit4] 1 POSTed web resource
Re: SimplePostToolTest very slow
Is it with the same seed? Dawid On Fri, Sep 13, 2013 at 1:04 PM, Michael McCandless luc...@mikemccandless.com wrote: It passes when run from Eclipse? It seems crazy that it can take 280 sec from ant but 1 sec from Eclipse. Maybe it's not actually running, when running from Eclipse? +1 for @Nightly it we can't get to the bottom of it ... Mike McCandless http://blog.mikemccandless.com On Thu, Sep 12, 2013 at 5:03 PM, Shai Erera ser...@gmail.com wrote: Hi I was running Solr tests now and thought they hung, but eventually they continued and I noticed that SimplePostToolTest took 280s to complete. I tried from eclipse, and it took 1s. Tried from Ant again, 276s. I compared (briefly) the outputs of the test from eclipse and Ant, and they look similar. Is this expected? Maybe when the test runs from Ant it does more work (i.e. system properties that are sent from build.xml but not in eclipse cause it to index more data or something?). If it helps, here's what the test prints: [junit4] Suite: org.apache.solr.util.SimplePostToolTest [junit4] 2 log4j:WARN No such property [conversionPattern] in org.apache.solr.util.SolrLogLayout. [junit4] 2 396 T24 oas.SolrTestCaseJ4.setUp ###Starting testIsOn [junit4] 2 23126 T24 oas.SolrTestCaseJ4.tearDown ###Ending testIsOn [junit4] OK 22.8s | SimplePostToolTest.testIsOn [junit4] 2 23163 T24 oas.SolrTestCaseJ4.setUp ###Starting testAppendUrlPath [junit4] 2 54667 T24 oas.SolrTestCaseJ4.tearDown ###Ending testAppendUrlPath [junit4] OK 31.5s | SimplePostToolTest.testAppendUrlPath [junit4] 2 54682 T24 oas.SolrTestCaseJ4.setUp ###Starting testGuessType [junit4] 2 77185 T24 oas.SolrTestCaseJ4.tearDown ###Ending testGuessType [junit4] OK 22.5s | SimplePostToolTest.testGuessType [junit4] 2 77198 T24 oas.SolrTestCaseJ4.setUp ###Starting testTypeSupported [junit4] 2 99701 T24 oas.SolrTestCaseJ4.tearDown ###Ending testTypeSupported [junit4] OK 22.5s | SimplePostToolTest.testTypeSupported [junit4] 2 99712 T24 oas.SolrTestCaseJ4.setUp ###Starting testRobotsExclusion [junit4] 2 122214 T24 oas.SolrTestCaseJ4.tearDown ###Ending testRobotsExclusion [junit4] OK 22.5s | SimplePostToolTest.testRobotsExclusion [junit4] 2 15 T24 oas.SolrTestCaseJ4.setUp ###Starting testParseArgsAndInit [junit4] 2 144727 T24 oas.SolrTestCaseJ4.tearDown ###Ending testParseArgsAndInit [junit4] OK 22.5s | SimplePostToolTest.testParseArgsAndInit [junit4] 2 144736 T24 oas.SolrTestCaseJ4.setUp ###Starting testDoWebMode [junit4] 2 SimplePostTool: WARNING: The URL http://example.com/disallowed returned a HTTP result status of 403 [junit4] 2 185795 T24 oas.SolrTestCaseJ4.tearDown ###Ending testDoWebMode [junit4] 1 Entering crawl at level 0 (1 links total, 1 new) [junit4] 1 POSTed web resource http://example.com (depth: 0) [junit4] 1 Entering crawl at level 1 (2 links total, 2 new) [junit4] 1 POSTed web resource http://example.com/page2 (depth: 1) [junit4] 1 POSTed web resource http://example.com/page1 (depth: 1) [junit4] 1 Entering crawl at level 2 (2 links total, 2 new) [junit4] 1 POSTed web resource http://example.com/page1/foo (depth: 2) [junit4] 1 Entering crawl at level 3 (1 links total, 1 new) [junit4] 1 POSTed web resource http://example.com/page1/foo/bar (depth: 3) [junit4] 1 Entering crawl at level 0 (1 links total, 1 new) [junit4] 1 POSTed web resource http://example.com (depth: 0) [junit4] 1 Entering crawl at level 1 (2 links total, 2 new) [junit4] 1 POSTed web resource http://example.com/page2 (depth: 1) [junit4] 1 POSTed web resource http://example.com/page1 (depth: 1) [junit4] 1 Entering crawl at level 0 (1 links total, 1 new) [junit4] 1 POSTed web resource http://example.com (depth: 0) [junit4] 1 Entering crawl at level 1 (2 links total, 2 new) [junit4] 1 POSTed web resource http://example.com/page2 (depth: 1) [junit4] 1 POSTed web resource http://example.com/page1 (depth: 1) [junit4] 1 Entering crawl at level 2 (2 links total, 2 new) [junit4] 1 POSTed web resource http://example.com/disallowed (depth: 2) [junit4] 1 POSTed web resource http://example.com/page1/foo (depth: 2) [junit4] 1 Entering crawl at level 3 (1 links total, 1 new) [junit4] 1 POSTed web resource http://example.com/page1/foo/bar (depth: 3) [junit4] OK 41.1s | SimplePostToolTest.testDoWebMode [junit4] 2 185806 T24 oas.SolrTestCaseJ4.setUp ###Starting testAppendParam [junit4] 2 208310 T24 oas.SolrTestCaseJ4.tearDown ###Ending testAppendParam [junit4] OK 22.5s | SimplePostToolTest.testAppendParam [junit4] 2 208320 T24 oas.SolrTestCaseJ4.setUp ###Starting testComputeFullUrl [junit4] 2 230822 T24 oas.SolrTestCaseJ4.tearDown ###Ending testComputeFullUrl
Re: SimplePostToolTest very slow
Sounds more like a timeout. I mean, posting documents should be reasonably fast. -- Jack Krupansky -Original Message- From: Michael McCandless Sent: Friday, September 13, 2013 7:04 AM To: Lucene/Solr dev Subject: Re: SimplePostToolTest very slow It passes when run from Eclipse? It seems crazy that it can take 280 sec from ant but 1 sec from Eclipse. Maybe it's not actually running, when running from Eclipse? +1 for @Nightly it we can't get to the bottom of it ... Mike McCandless http://blog.mikemccandless.com On Thu, Sep 12, 2013 at 5:03 PM, Shai Erera ser...@gmail.com wrote: Hi I was running Solr tests now and thought they hung, but eventually they continued and I noticed that SimplePostToolTest took 280s to complete. I tried from eclipse, and it took 1s. Tried from Ant again, 276s. I compared (briefly) the outputs of the test from eclipse and Ant, and they look similar. Is this expected? Maybe when the test runs from Ant it does more work (i.e. system properties that are sent from build.xml but not in eclipse cause it to index more data or something?). If it helps, here's what the test prints: [junit4] Suite: org.apache.solr.util.SimplePostToolTest [junit4] 2 log4j:WARN No such property [conversionPattern] in org.apache.solr.util.SolrLogLayout. [junit4] 2 396 T24 oas.SolrTestCaseJ4.setUp ###Starting testIsOn [junit4] 2 23126 T24 oas.SolrTestCaseJ4.tearDown ###Ending testIsOn [junit4] OK 22.8s | SimplePostToolTest.testIsOn [junit4] 2 23163 T24 oas.SolrTestCaseJ4.setUp ###Starting testAppendUrlPath [junit4] 2 54667 T24 oas.SolrTestCaseJ4.tearDown ###Ending testAppendUrlPath [junit4] OK 31.5s | SimplePostToolTest.testAppendUrlPath [junit4] 2 54682 T24 oas.SolrTestCaseJ4.setUp ###Starting testGuessType [junit4] 2 77185 T24 oas.SolrTestCaseJ4.tearDown ###Ending testGuessType [junit4] OK 22.5s | SimplePostToolTest.testGuessType [junit4] 2 77198 T24 oas.SolrTestCaseJ4.setUp ###Starting testTypeSupported [junit4] 2 99701 T24 oas.SolrTestCaseJ4.tearDown ###Ending testTypeSupported [junit4] OK 22.5s | SimplePostToolTest.testTypeSupported [junit4] 2 99712 T24 oas.SolrTestCaseJ4.setUp ###Starting testRobotsExclusion [junit4] 2 122214 T24 oas.SolrTestCaseJ4.tearDown ###Ending testRobotsExclusion [junit4] OK 22.5s | SimplePostToolTest.testRobotsExclusion [junit4] 2 15 T24 oas.SolrTestCaseJ4.setUp ###Starting testParseArgsAndInit [junit4] 2 144727 T24 oas.SolrTestCaseJ4.tearDown ###Ending testParseArgsAndInit [junit4] OK 22.5s | SimplePostToolTest.testParseArgsAndInit [junit4] 2 144736 T24 oas.SolrTestCaseJ4.setUp ###Starting testDoWebMode [junit4] 2 SimplePostTool: WARNING: The URL http://example.com/disallowed returned a HTTP result status of 403 [junit4] 2 185795 T24 oas.SolrTestCaseJ4.tearDown ###Ending testDoWebMode [junit4] 1 Entering crawl at level 0 (1 links total, 1 new) [junit4] 1 POSTed web resource http://example.com (depth: 0) [junit4] 1 Entering crawl at level 1 (2 links total, 2 new) [junit4] 1 POSTed web resource http://example.com/page2 (depth: 1) [junit4] 1 POSTed web resource http://example.com/page1 (depth: 1) [junit4] 1 Entering crawl at level 2 (2 links total, 2 new) [junit4] 1 POSTed web resource http://example.com/page1/foo (depth: 2) [junit4] 1 Entering crawl at level 3 (1 links total, 1 new) [junit4] 1 POSTed web resource http://example.com/page1/foo/bar (depth: 3) [junit4] 1 Entering crawl at level 0 (1 links total, 1 new) [junit4] 1 POSTed web resource http://example.com (depth: 0) [junit4] 1 Entering crawl at level 1 (2 links total, 2 new) [junit4] 1 POSTed web resource http://example.com/page2 (depth: 1) [junit4] 1 POSTed web resource http://example.com/page1 (depth: 1) [junit4] 1 Entering crawl at level 0 (1 links total, 1 new) [junit4] 1 POSTed web resource http://example.com (depth: 0) [junit4] 1 Entering crawl at level 1 (2 links total, 2 new) [junit4] 1 POSTed web resource http://example.com/page2 (depth: 1) [junit4] 1 POSTed web resource http://example.com/page1 (depth: 1) [junit4] 1 Entering crawl at level 2 (2 links total, 2 new) [junit4] 1 POSTed web resource http://example.com/disallowed (depth: 2) [junit4] 1 POSTed web resource http://example.com/page1/foo (depth: 2) [junit4] 1 Entering crawl at level 3 (1 links total, 1 new) [junit4] 1 POSTed web resource http://example.com/page1/foo/bar (depth: 3) [junit4] OK 41.1s | SimplePostToolTest.testDoWebMode [junit4] 2 185806 T24 oas.SolrTestCaseJ4.setUp ###Starting testAppendParam [junit4] 2 208310 T24 oas.SolrTestCaseJ4.tearDown ###Ending testAppendParam [junit4] OK 22.5s | SimplePostToolTest.testAppendParam [junit4] 2 208320 T24 oas.SolrTestCaseJ4.setUp ###Starting testComputeFullUrl [junit4] 2 230822 T24
Re: SimplePostToolTest very slow
: Am I the only one that experiences this slowness? I can reproduce the speeds you are seeing from ant (no IDE to test from on my end) It looks like some sort of delay in init ... every test has ~25s delay, and changing the SimplePostTool instances to static and switching the @Before to @BeforeClass causes the whole tests runtime to drop down to 50 seconds for me. I bet this is something related to hostname resolution with the example.com domain used in this test ... a MockPageFetcher is used hat never hits the URLs in question, but i bet somewhere in init they are still getting resolved. I'll keep digging. -Hoss - To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org For additional commands, e-mail: dev-h...@lucene.apache.org
Re: SimplePostToolTest very slow
: and changing the SimplePostTool instances to static and switching the : @Before to @BeforeClass causes the whole tests runtime to drop down to 50 : seconds for me. i couldn't leave that change in because it introduced failures depending on test ordering (i thought those SimplePostTool objects were treated as immutible, but i was wrong) however: switching all usages of example.com to a 127.42.42.42 seems to have fixed things. Shai: can you confirm this patch resolves things for you... https://issues.apache.org/jira/browse/SOLR-5241 -Hoss - To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org For additional commands, e-mail: dev-h...@lucene.apache.org
Re: SimplePostToolTest very slow
Does this test actually try to connect to those URLs? If not then a fake:// URL handler would be a very elegant solution not reaching to the DNS subsystem at all? Not that I want to write it -- I remember it was kind of nightmarish :) Dawid On Fri, Sep 13, 2013 at 8:48 PM, Chris Hostetter hossman_luc...@fucit.org wrote: : and changing the SimplePostTool instances to static and switching the : @Before to @BeforeClass causes the whole tests runtime to drop down to 50 : seconds for me. i couldn't leave that change in because it introduced failures depending on test ordering (i thought those SimplePostTool objects were treated as immutible, but i was wrong) however: switching all usages of example.com to a 127.42.42.42 seems to have fixed things. Shai: can you confirm this patch resolves things for you... https://issues.apache.org/jira/browse/SOLR-5241 -Hoss - To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org For additional commands, e-mail: dev-h...@lucene.apache.org - To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org For additional commands, e-mail: dev-h...@lucene.apache.org
Re: SimplePostToolTest very slow
With the patch on SOLR-5241, the test runs for 1.8-3.2s, so this seems to solve the problem. I'm running w/ IBM J9 1.7.0, but it also happens w/ Oracle 1.7.0 (seems to be even slower!), in both Ant and Eclipse. You can reproduce by running ant test -Dtestcase=SimplePostToolTest from /solr/core. No specific seed as it's consistently slow without the patch, and fast with it. Thanks Hoss! Shai On Fri, Sep 13, 2013 at 10:02 PM, Dawid Weiss dawid.we...@cs.put.poznan.plwrote: Does this test actually try to connect to those URLs? If not then a fake:// URL handler would be a very elegant solution not reaching to the DNS subsystem at all? Not that I want to write it -- I remember it was kind of nightmarish :) Dawid On Fri, Sep 13, 2013 at 8:48 PM, Chris Hostetter hossman_luc...@fucit.org wrote: : and changing the SimplePostTool instances to static and switching the : @Before to @BeforeClass causes the whole tests runtime to drop down to 50 : seconds for me. i couldn't leave that change in because it introduced failures depending on test ordering (i thought those SimplePostTool objects were treated as immutible, but i was wrong) however: switching all usages of example.com to a 127.42.42.42 seems to have fixed things. Shai: can you confirm this patch resolves things for you... https://issues.apache.org/jira/browse/SOLR-5241 -Hoss - To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org For additional commands, e-mail: dev-h...@lucene.apache.org - To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org For additional commands, e-mail: dev-h...@lucene.apache.org
Re: SimplePostToolTest very slow
Loggers On Fri, Sep 13, 2013 at 4:22 PM, Dawid Weiss dawid.we...@cs.put.poznan.pl wrote: I still don't see why you'd get different timings between Eclipse and Ant if you're running with the same VM -- it should be pretty consistent (either it caches dns lookups or it doesn't). D. On Fri, Sep 13, 2013 at 10:01 PM, Shai Erera ser...@gmail.com wrote: With the patch on SOLR-5241, the test runs for 1.8-3.2s, so this seems to solve the problem. I'm running w/ IBM J9 1.7.0, but it also happens w/ Oracle 1.7.0 (seems to be even slower!), in both Ant and Eclipse. You can reproduce by running ant test -Dtestcase=SimplePostToolTest from /solr/core. No specific seed as it's consistently slow without the patch, and fast with it. Thanks Hoss! Shai On Fri, Sep 13, 2013 at 10:02 PM, Dawid Weiss dawid.we...@cs.put.poznan.pl wrote: Does this test actually try to connect to those URLs? If not then a fake:// URL handler would be a very elegant solution not reaching to the DNS subsystem at all? Not that I want to write it -- I remember it was kind of nightmarish :) Dawid On Fri, Sep 13, 2013 at 8:48 PM, Chris Hostetter hossman_luc...@fucit.org wrote: : and changing the SimplePostTool instances to static and switching the : @Before to @BeforeClass causes the whole tests runtime to drop down to 50 : seconds for me. i couldn't leave that change in because it introduced failures depending on test ordering (i thought those SimplePostTool objects were treated as immutible, but i was wrong) however: switching all usages of example.com to a 127.42.42.42 seems to have fixed things. Shai: can you confirm this patch resolves things for you... https://issues.apache.org/jira/browse/SOLR-5241 -Hoss - To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org For additional commands, e-mail: dev-h...@lucene.apache.org - To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org For additional commands, e-mail: dev-h...@lucene.apache.org - To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org For additional commands, e-mail: dev-h...@lucene.apache.org - To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org For additional commands, e-mail: dev-h...@lucene.apache.org
Re: SimplePostToolTest very slow
I still don't see why you'd get different timings between Eclipse and Ant if you're running with the same VM -- it should be pretty consistent (either it caches dns lookups or it doesn't). D. On Fri, Sep 13, 2013 at 10:01 PM, Shai Erera ser...@gmail.com wrote: With the patch on SOLR-5241, the test runs for 1.8-3.2s, so this seems to solve the problem. I'm running w/ IBM J9 1.7.0, but it also happens w/ Oracle 1.7.0 (seems to be even slower!), in both Ant and Eclipse. You can reproduce by running ant test -Dtestcase=SimplePostToolTest from /solr/core. No specific seed as it's consistently slow without the patch, and fast with it. Thanks Hoss! Shai On Fri, Sep 13, 2013 at 10:02 PM, Dawid Weiss dawid.we...@cs.put.poznan.pl wrote: Does this test actually try to connect to those URLs? If not then a fake:// URL handler would be a very elegant solution not reaching to the DNS subsystem at all? Not that I want to write it -- I remember it was kind of nightmarish :) Dawid On Fri, Sep 13, 2013 at 8:48 PM, Chris Hostetter hossman_luc...@fucit.org wrote: : and changing the SimplePostTool instances to static and switching the : @Before to @BeforeClass causes the whole tests runtime to drop down to 50 : seconds for me. i couldn't leave that change in because it introduced failures depending on test ordering (i thought those SimplePostTool objects were treated as immutible, but i was wrong) however: switching all usages of example.com to a 127.42.42.42 seems to have fixed things. Shai: can you confirm this patch resolves things for you... https://issues.apache.org/jira/browse/SOLR-5241 -Hoss - To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org For additional commands, e-mail: dev-h...@lucene.apache.org - To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org For additional commands, e-mail: dev-h...@lucene.apache.org - To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org For additional commands, e-mail: dev-h...@lucene.apache.org
Re: SimplePostToolTest very slow
They should actually be faster in Ant than they are in Eclipse (because Eclipse displays logs in the console and Ant flushes them to a file)? Dawid On Fri, Sep 13, 2013 at 10:29 PM, Robert Muir rcm...@gmail.com wrote: Loggers On Fri, Sep 13, 2013 at 4:22 PM, Dawid Weiss dawid.we...@cs.put.poznan.pl wrote: I still don't see why you'd get different timings between Eclipse and Ant if you're running with the same VM -- it should be pretty consistent (either it caches dns lookups or it doesn't). D. On Fri, Sep 13, 2013 at 10:01 PM, Shai Erera ser...@gmail.com wrote: With the patch on SOLR-5241, the test runs for 1.8-3.2s, so this seems to solve the problem. I'm running w/ IBM J9 1.7.0, but it also happens w/ Oracle 1.7.0 (seems to be even slower!), in both Ant and Eclipse. You can reproduce by running ant test -Dtestcase=SimplePostToolTest from /solr/core. No specific seed as it's consistently slow without the patch, and fast with it. Thanks Hoss! Shai On Fri, Sep 13, 2013 at 10:02 PM, Dawid Weiss dawid.we...@cs.put.poznan.pl wrote: Does this test actually try to connect to those URLs? If not then a fake:// URL handler would be a very elegant solution not reaching to the DNS subsystem at all? Not that I want to write it -- I remember it was kind of nightmarish :) Dawid On Fri, Sep 13, 2013 at 8:48 PM, Chris Hostetter hossman_luc...@fucit.org wrote: : and changing the SimplePostTool instances to static and switching the : @Before to @BeforeClass causes the whole tests runtime to drop down to 50 : seconds for me. i couldn't leave that change in because it introduced failures depending on test ordering (i thought those SimplePostTool objects were treated as immutible, but i was wrong) however: switching all usages of example.com to a 127.42.42.42 seems to have fixed things. Shai: can you confirm this patch resolves things for you... https://issues.apache.org/jira/browse/SOLR-5241 -Hoss - To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org For additional commands, e-mail: dev-h...@lucene.apache.org - To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org For additional commands, e-mail: dev-h...@lucene.apache.org - To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org For additional commands, e-mail: dev-h...@lucene.apache.org - To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org For additional commands, e-mail: dev-h...@lucene.apache.org - To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org For additional commands, e-mail: dev-h...@lucene.apache.org
Re: SimplePostToolTest very slow
: I still don't see why you'd get different timings between Eclipse and : Ant if you're running with the same VM -- it should be pretty : consistent (either it caches dns lookups or it doesn't). Maybe Eclipse mucks with networkaddress.cache.ttl networkaddress.cache.negative.ttl ? If you want to experiment, a really trivial test is below -- on my system, there is a ~5 second gap between each pair of INIT and H1 timestamps, but no other odd gaps in subsequent timestamps -- suggesting no caching of DNS per hostname, but that the URL class doesn't re-lookup on subsequent hashCode() calls. -Hoss - To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org For additional commands, e-mail: dev-h...@lucene.apache.org
Re: SimplePostToolTest very slow
: If you want to experiment, a really trivial test is below -- on my system,
: there is a ~5 second gap between each pair of INIT and H1 timestamps,
: but no other odd gaps in subsequent timestamps -- suggesting no caching of
: DNS per hostname, but that the URL class doesn't re-lookup on subsequent
: hashCode() calls.
Or maybe i could actually cut paste the test this time...
import java.net.URL;
import org.apache.lucene.util.LuceneTestCase;
public class TestURLDNSAbsurdity extends LuceneTestCase {
public void testHowSlowCanYouGo() throws Exception {
go(1);
go(2);
}
public void go(String s) throws Exception {
System.out.println(s + PRE: + System.currentTimeMillis());
URL url = new URL(http://example.com/;);
System.out.println(s + INIT: + System.currentTimeMillis());
int h1 = url.hashCode();
System.out.println(s + H1: + System.currentTimeMillis());
int h2 = url.hashCode();
System.out.println(s + H2: + System.currentTimeMillis());
boolean e1 = url.equals(this);
System.out.println(s + E1: + System.currentTimeMillis());
boolean e2 = url.equals(this);
System.out.println(s + E2: + System.currentTimeMillis());
assertEquals(h1,h2);
assertEquals(e1,e2);
}
}
...
[junit4] Started J0 PID(31843@frisbee).
[junit4] Suite: org.apache.solr.util.TestURLDNSAbsurdity
[junit4] 1 1 PRE: 1379107971313
[junit4] 1 1INIT: 1379107971314
[junit4] 1 1 H1: 1379107976449
[junit4] 1 1 H2: 1379107976449
[junit4] 1 1 E1: 1379107976449
[junit4] 1 1 E2: 1379107976449
[junit4] 1 2 PRE: 1379107976450
[junit4] 1 2INIT: 1379107976450
[junit4] 1 2 H1: 1379107981510
[junit4] 1 2 H2: 1379107981510
[junit4] 1 2 E1: 1379107981510
[junit4] 1 2 E2: 1379107981510
[junit4] OK 10.3s | TestURLDNSAbsurdity.testHowSlowCanYouGo
-Hoss
-
To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org
For additional commands, e-mail: dev-h...@lucene.apache.org
Re: SimplePostToolTest very slow
I still don't see why you'd get different timings between Eclipse and
Ant if you're running with the same VM -- it should be pretty
consistent (either it caches dns lookups or it doesn't).
I agree, it's suspicious. I searched for URL performance differences
between eclipse and Ant and hit this page:
http://ant.apache.org/manual/proxy.html. It suggests Ant uses different
proxy settings by default for its own tasks as well as 3rd party tasks that
use java.net.URL. I tried running with -autoproxy but from Ant each test
method still takes ~23s vs Eclipse which is ~0.1s.
Will be interesting to identify the differences .. I think it's a
configuration issue, as Eclipse needs to make URL connections for e.g. its
marketplace, so maybe it comes pre-configured somehow. I'm now curious,
I'll dig :).
Shai
On Sat, Sep 14, 2013 at 12:33 AM, Chris Hostetter
hossman_luc...@fucit.orgwrote:
: If you want to experiment, a really trivial test is below -- on my
system,
: there is a ~5 second gap between each pair of INIT and H1 timestamps,
: but no other odd gaps in subsequent timestamps -- suggesting no caching
of
: DNS per hostname, but that the URL class doesn't re-lookup on
subsequent
: hashCode() calls.
Or maybe i could actually cut paste the test this time...
import java.net.URL;
import org.apache.lucene.util.LuceneTestCase;
public class TestURLDNSAbsurdity extends LuceneTestCase {
public void testHowSlowCanYouGo() throws Exception {
go(1);
go(2);
}
public void go(String s) throws Exception {
System.out.println(s + PRE: + System.currentTimeMillis());
URL url = new URL(http://example.com/;);
System.out.println(s + INIT: + System.currentTimeMillis());
int h1 = url.hashCode();
System.out.println(s + H1: + System.currentTimeMillis());
int h2 = url.hashCode();
System.out.println(s + H2: + System.currentTimeMillis());
boolean e1 = url.equals(this);
System.out.println(s + E1: + System.currentTimeMillis());
boolean e2 = url.equals(this);
System.out.println(s + E2: + System.currentTimeMillis());
assertEquals(h1,h2);
assertEquals(e1,e2);
}
}
...
[junit4] Started J0 PID(31843@frisbee).
[junit4] Suite: org.apache.solr.util.TestURLDNSAbsurdity
[junit4] 1 1 PRE: 1379107971313
[junit4] 1 1INIT: 1379107971314
[junit4] 1 1 H1: 1379107976449
[junit4] 1 1 H2: 1379107976449
[junit4] 1 1 E1: 1379107976449
[junit4] 1 1 E2: 1379107976449
[junit4] 1 2 PRE: 1379107976450
[junit4] 1 2INIT: 1379107976450
[junit4] 1 2 H1: 1379107981510
[junit4] 1 2 H2: 1379107981510
[junit4] 1 2 E1: 1379107981510
[junit4] 1 2 E2: 1379107981510
[junit4] OK 10.3s | TestURLDNSAbsurdity.testHowSlowCanYouGo
-Hoss
-
To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org
For additional commands, e-mail: dev-h...@lucene.apache.org
Re: SimplePostToolTest very slow
OK, I think I've made some progress -- configuration issue, but not
proxies, it seems to be our security manager/policy.
I printed system properties and env in setUp and ran only a single test
(testIsOn) to compare the output. I didn't notice any proxy settings, but I
did notice that from Ant we're using our own security manager and policy.
So when I ran the test from eclipse using
-Djava.security.manager=org.apache.lucene.util.TestSecurityManager
-Djava.security.policy=D:\dev\lucene\lucene-trunk\lucene\tools\junit4\tests.policy,
it ran for 23s too (I only ran a single test method).
I don't think it's related to TestSecurityManager, since it only checks
that System.exit isn't called from tests.
Looking at tests.policy, there are a bunch of socket connection related
lines .. I'm guess it's somewhere there, though I don't know this stuff.
I will try to look into it more later.
Shai
On Sat, Sep 14, 2013 at 6:59 AM, Shai Erera ser...@gmail.com wrote:
I still don't see why you'd get different timings between Eclipse and
Ant if you're running with the same VM -- it should be pretty
consistent (either it caches dns lookups or it doesn't).
I agree, it's suspicious. I searched for URL performance differences
between eclipse and Ant and hit this page:
http://ant.apache.org/manual/proxy.html. It suggests Ant uses different
proxy settings by default for its own tasks as well as 3rd party tasks that
use java.net.URL. I tried running with -autoproxy but from Ant each test
method still takes ~23s vs Eclipse which is ~0.1s.
Will be interesting to identify the differences .. I think it's a
configuration issue, as Eclipse needs to make URL connections for e.g. its
marketplace, so maybe it comes pre-configured somehow. I'm now curious,
I'll dig :).
Shai
On Sat, Sep 14, 2013 at 12:33 AM, Chris Hostetter
hossman_luc...@fucit.org wrote:
: If you want to experiment, a really trivial test is below -- on my
system,
: there is a ~5 second gap between each pair of INIT and H1
timestamps,
: but no other odd gaps in subsequent timestamps -- suggesting no caching
of
: DNS per hostname, but that the URL class doesn't re-lookup on
subsequent
: hashCode() calls.
Or maybe i could actually cut paste the test this time...
import java.net.URL;
import org.apache.lucene.util.LuceneTestCase;
public class TestURLDNSAbsurdity extends LuceneTestCase {
public void testHowSlowCanYouGo() throws Exception {
go(1);
go(2);
}
public void go(String s) throws Exception {
System.out.println(s + PRE: + System.currentTimeMillis());
URL url = new URL(http://example.com/;);
System.out.println(s + INIT: + System.currentTimeMillis());
int h1 = url.hashCode();
System.out.println(s + H1: + System.currentTimeMillis());
int h2 = url.hashCode();
System.out.println(s + H2: + System.currentTimeMillis());
boolean e1 = url.equals(this);
System.out.println(s + E1: + System.currentTimeMillis());
boolean e2 = url.equals(this);
System.out.println(s + E2: + System.currentTimeMillis());
assertEquals(h1,h2);
assertEquals(e1,e2);
}
}
...
[junit4] Started J0 PID(31843@frisbee).
[junit4] Suite: org.apache.solr.util.TestURLDNSAbsurdity
[junit4] 1 1 PRE: 1379107971313
[junit4] 1 1INIT: 1379107971314
[junit4] 1 1 H1: 1379107976449
[junit4] 1 1 H2: 1379107976449
[junit4] 1 1 E1: 1379107976449
[junit4] 1 1 E2: 1379107976449
[junit4] 1 2 PRE: 1379107976450
[junit4] 1 2INIT: 1379107976450
[junit4] 1 2 H1: 1379107981510
[junit4] 1 2 H2: 1379107981510
[junit4] 1 2 E1: 1379107981510
[junit4] 1 2 E2: 1379107981510
[junit4] OK 10.3s | TestURLDNSAbsurdity.testHowSlowCanYouGo
-Hoss
-
To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org
For additional commands, e-mail: dev-h...@lucene.apache.org
SimplePostToolTest very slow
Hi I was running Solr tests now and thought they hung, but eventually they continued and I noticed that SimplePostToolTest took 280s to complete. I tried from eclipse, and it took 1s. Tried from Ant again, 276s. I compared (briefly) the outputs of the test from eclipse and Ant, and they look similar. Is this expected? Maybe when the test runs from Ant it does more work (i.e. system properties that are sent from build.xml but not in eclipse cause it to index more data or something?). If it helps, here's what the test prints: [junit4] Suite: org.apache.solr.util.SimplePostToolTest [junit4] 2 log4j:WARN No such property [conversionPattern] in org.apache.solr.util.SolrLogLayout. [junit4] 2 396 T24 oas.SolrTestCaseJ4.setUp ###Starting testIsOn [junit4] 2 23126 T24 oas.SolrTestCaseJ4.tearDown ###Ending testIsOn [junit4] OK 22.8s | SimplePostToolTest.testIsOn [junit4] 2 23163 T24 oas.SolrTestCaseJ4.setUp ###Starting testAppendUrlPath [junit4] 2 54667 T24 oas.SolrTestCaseJ4.tearDown ###Ending testAppendUrlPath [junit4] OK 31.5s | SimplePostToolTest.testAppendUrlPath [junit4] 2 54682 T24 oas.SolrTestCaseJ4.setUp ###Starting testGuessType [junit4] 2 77185 T24 oas.SolrTestCaseJ4.tearDown ###Ending testGuessType [junit4] OK 22.5s | SimplePostToolTest.testGuessType [junit4] 2 77198 T24 oas.SolrTestCaseJ4.setUp ###Starting testTypeSupported [junit4] 2 99701 T24 oas.SolrTestCaseJ4.tearDown ###Ending testTypeSupported [junit4] OK 22.5s | SimplePostToolTest.testTypeSupported [junit4] 2 99712 T24 oas.SolrTestCaseJ4.setUp ###Starting testRobotsExclusion [junit4] 2 122214 T24 oas.SolrTestCaseJ4.tearDown ###Ending testRobotsExclusion [junit4] OK 22.5s | SimplePostToolTest.testRobotsExclusion [junit4] 2 15 T24 oas.SolrTestCaseJ4.setUp ###Starting testParseArgsAndInit [junit4] 2 144727 T24 oas.SolrTestCaseJ4.tearDown ###Ending testParseArgsAndInit [junit4] OK 22.5s | SimplePostToolTest.testParseArgsAndInit [junit4] 2 144736 T24 oas.SolrTestCaseJ4.setUp ###Starting testDoWebMode [junit4] 2 SimplePostTool: WARNING: The URL http://example.com/disallowed returned a HTTP result status of 403 [junit4] 2 185795 T24 oas.SolrTestCaseJ4.tearDown ###Ending testDoWebMode [junit4] 1 Entering crawl at level 0 (1 links total, 1 new) [junit4] 1 POSTed web resource http://example.com (depth: 0) [junit4] 1 Entering crawl at level 1 (2 links total, 2 new) [junit4] 1 POSTed web resource http://example.com/page2 (depth: 1) [junit4] 1 POSTed web resource http://example.com/page1 (depth: 1) [junit4] 1 Entering crawl at level 2 (2 links total, 2 new) [junit4] 1 POSTed web resource http://example.com/page1/foo (depth: 2) [junit4] 1 Entering crawl at level 3 (1 links total, 1 new) [junit4] 1 POSTed web resource http://example.com/page1/foo/bar(depth: 3) [junit4] 1 Entering crawl at level 0 (1 links total, 1 new) [junit4] 1 POSTed web resource http://example.com (depth: 0) [junit4] 1 Entering crawl at level 1 (2 links total, 2 new) [junit4] 1 POSTed web resource http://example.com/page2 (depth: 1) [junit4] 1 POSTed web resource http://example.com/page1 (depth: 1) [junit4] 1 Entering crawl at level 0 (1 links total, 1 new) [junit4] 1 POSTed web resource http://example.com (depth: 0) [junit4] 1 Entering crawl at level 1 (2 links total, 2 new) [junit4] 1 POSTed web resource http://example.com/page2 (depth: 1) [junit4] 1 POSTed web resource http://example.com/page1 (depth: 1) [junit4] 1 Entering crawl at level 2 (2 links total, 2 new) [junit4] 1 POSTed web resource http://example.com/disallowed (depth: 2) [junit4] 1 POSTed web resource http://example.com/page1/foo (depth: 2) [junit4] 1 Entering crawl at level 3 (1 links total, 1 new) [junit4] 1 POSTed web resource http://example.com/page1/foo/bar(depth: 3) [junit4] OK 41.1s | SimplePostToolTest.testDoWebMode [junit4] 2 185806 T24 oas.SolrTestCaseJ4.setUp ###Starting testAppendParam [junit4] 2 208310 T24 oas.SolrTestCaseJ4.tearDown ###Ending testAppendParam [junit4] OK 22.5s | SimplePostToolTest.testAppendParam [junit4] 2 208320 T24 oas.SolrTestCaseJ4.setUp ###Starting testComputeFullUrl [junit4] 2 230822 T24 oas.SolrTestCaseJ4.tearDown ###Ending testComputeFullUrl [junit4] OK 22.5s | SimplePostToolTest.testComputeFullUrl [junit4] 2 230832 T24 oas.SolrTestCaseJ4.setUp ###Starting testNormalizeUrlEnding [junit4] 2 253334 T24 oas.SolrTestCaseJ4.tearDown ###Ending testNormalizeUrlEnding [junit4] OK 22.5s | SimplePostToolTest.testNormalizeUrlEnding [junit4] 2 253344 T24 oas.SolrTestCaseJ4.setUp ###Starting testDoFilesMode [junit4] 2 275848 T24 oas.SolrTestCaseJ4.tearDown ###Ending testDoFilesMode [junit4] 1 Indexing directory
