You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2013/01/20 16:38:18 UTC
[JENKINS] Lucene-Solr-4.x-Windows (32bit/jdk1.7.0_10) - Build #
2421 - Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Windows/2421/
Java: 32bit/jdk1.7.0_10 -client -XX:+UseG1GC
1 tests failed.
FAILED: junit.framework.TestSuite.org.apache.solr.cloud.ShardRoutingTest
Error Message:
ERROR: SolrIndexSearcher opens=82 closes=81
Stack Trace:
java.lang.AssertionError: ERROR: SolrIndexSearcher opens=82 closes=81
at __randomizedtesting.SeedInfo.seed([69E0283D754A2040]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.apache.solr.SolrTestCaseJ4.endTrackingSearchers(SolrTestCaseJ4.java:246)
at org.apache.solr.SolrTestCaseJ4.afterClass(SolrTestCaseJ4.java:97)
at sun.reflect.GeneratedMethodAccessor22.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:601)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:700)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:722)
Build Log:
[...truncated 8604 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.ShardRoutingTest
[junit4:junit4] 2> 0 T617 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4:junit4] 2> 3 T617 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4] 2> Creating dataDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solrtest-ShardRoutingTest-1358694790892
[junit4:junit4] 2> 5 T617 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4] 2> 6 T618 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4] 2> 10 T618 oazs.ZooKeeperServer.setTickTime tickTime set to 1000
[junit4:junit4] 2> 10 T618 oazs.ZooKeeperServer.setMinSessionTimeout minSessionTimeout set to -1
[junit4:junit4] 2> 10 T618 oazs.ZooKeeperServer.setMaxSessionTimeout maxSessionTimeout set to -1
[junit4:junit4] 2> 11 T618 oazs.NIOServerCnxnFactory.configure binding to port 0.0.0.0/0.0.0.0:0
[junit4:junit4] 2> 12 T618 oazsp.FileTxnSnapLog.save Snapshotting: 0x0 to C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-1358694790891\zookeeper\server1\data\version-2\snapshot.0
[junit4:junit4] 2> 107 T617 oasc.ZkTestServer.run start zk server on port:50259
[junit4:junit4] 2> 107 T617 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:50259 sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@18b1f0c
[junit4:junit4] 2> 110 T617 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 112 T623 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:50259. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 113 T623 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:50259, initiating session
[junit4:junit4] 2> 114 T619 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:50262
[junit4:junit4] 2> 114 T619 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:50262
[junit4:junit4] 2> 114 T621 oazsp.FileTxnLog.append Creating new log file: log.1
[junit4:junit4] 2> 119 T621 oazs.ZooKeeperServer.finishSessionInit Established session 0x13c588536f60000 with negotiated timeout 10000 for client /127.0.0.1:50262
[junit4:junit4] 2> 119 T623 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:50259, sessionid = 0x13c588536f60000, negotiated timeout = 10000
[junit4:junit4] 2> 119 T624 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@18b1f0c name:ZooKeeperConnection Watcher:127.0.0.1:50259 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 120 T617 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 120 T617 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4] 2> 124 T622 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13c588536f60000
[junit4:junit4] 2> 125 T617 oaz.ZooKeeper.close Session: 0x13c588536f60000 closed
[junit4:junit4] 2> 126 T619 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:50262 which had sessionid 0x13c588536f60000
[junit4:junit4] 2> 126 T617 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:50259/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@1a44c8f
[junit4:junit4] 2> 126 T624 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 128 T617 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 128 T625 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:50259. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 130 T625 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:50259, initiating session
[junit4:junit4] 2> 130 T619 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:50265
[junit4:junit4] 2> 130 T619 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:50265
[junit4:junit4] 2> 132 T621 oazs.ZooKeeperServer.finishSessionInit Established session 0x13c588536f60001 with negotiated timeout 10000 for client /127.0.0.1:50265
[junit4:junit4] 2> 132 T625 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:50259, sessionid = 0x13c588536f60001, negotiated timeout = 10000
[junit4:junit4] 2> 132 T626 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1a44c8f name:ZooKeeperConnection Watcher:127.0.0.1:50259/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 132 T617 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 133 T617 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4] 2> 139 T617 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4] 2> 143 T617 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4] 2> 147 T617 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4] 2> 152 T617 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\solrconfig.xml to /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 153 T617 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 162 T617 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\schema15.xml to /configs/conf1/schema.xml
[junit4:junit4] 2> 163 T617 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4] 2> 169 T617 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4] 2> 170 T617 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4] 2> 175 T617 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4] 2> 176 T617 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4] 2> 181 T617 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\currency.xml to /configs/conf1/currency.xml
[junit4:junit4] 2> 181 T617 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4] 2> 186 T617 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 186 T617 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 193 T617 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 194 T617 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 199 T617 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 199 T617 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 203 T617 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4] 2> 203 T617 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4] 2> 209 T622 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13c588536f60001
[junit4:junit4] 2> 211 T619 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:50265 which had sessionid 0x13c588536f60001
[junit4:junit4] 2> 211 T617 oaz.ZooKeeper.close Session: 0x13c588536f60001 closed
[junit4:junit4] 2> 211 T626 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 539 T617 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 545 T617 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50266
[junit4:junit4] 2> 545 T617 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 545 T617 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 547 T617 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-controljetty-1358694791099
[junit4:junit4] 2> 547 T617 oasc.CoreContainer$Initializer.initialize looking for solr.xml: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-controljetty-1358694791099\solr.xml
[junit4:junit4] 2> 548 T617 oasc.CoreContainer.<init> New CoreContainer 9795465
[junit4:junit4] 2> 548 T617 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-controljetty-1358694791099\'
[junit4:junit4] 2> 549 T617 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-controljetty-1358694791099\'
[junit4:junit4] 2> 595 T617 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 60000
[junit4:junit4] 2> 596 T617 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 596 T617 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 596 T617 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 597 T617 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 597 T617 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 598 T617 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 598 T617 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 598 T617 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 598 T617 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=60000&connTimeout=15000&retry=false
[junit4:junit4] 2> 615 T617 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 637 T617 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:50259/solr
[junit4:junit4] 2> 637 T617 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 637 T617 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:50259 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@b5b546
[junit4:junit4] 2> 639 T617 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 640 T636 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:50259. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 641 T636 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:50259, initiating session
[junit4:junit4] 2> 641 T619 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:50271
[junit4:junit4] 2> 641 T619 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:50271
[junit4:junit4] 2> 658 T621 oazs.ZooKeeperServer.finishSessionInit Established session 0x13c588536f60002 with negotiated timeout 20000 for client /127.0.0.1:50271
[junit4:junit4] 2> 658 T636 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:50259, sessionid = 0x13c588536f60002, negotiated timeout = 20000
[junit4:junit4] 2> 659 T637 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@b5b546 name:ZooKeeperConnection Watcher:127.0.0.1:50259 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 660 T617 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 661 T622 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13c588536f60002
[junit4:junit4] 2> 664 T619 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:50271 which had sessionid 0x13c588536f60002
[junit4:junit4] 2> 665 T617 oaz.ZooKeeper.close Session: 0x13c588536f60002 closed
[junit4:junit4] 2> 665 T637 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 665 T617 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=60000&connTimeout=15000
[junit4:junit4] 2> 674 T617 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:50259/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@aa80eb
[junit4:junit4] 2> 677 T617 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 678 T638 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:50259. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 678 T638 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:50259, initiating session
[junit4:junit4] 2> 679 T619 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:50274
[junit4:junit4] 2> 679 T619 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:50274
[junit4:junit4] 2> 681 T621 oazs.ZooKeeperServer.finishSessionInit Established session 0x13c588536f60003 with negotiated timeout 20000 for client /127.0.0.1:50274
[junit4:junit4] 2> 681 T638 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:50259, sessionid = 0x13c588536f60003, negotiated timeout = 20000
[junit4:junit4] 2> 682 T639 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@aa80eb name:ZooKeeperConnection Watcher:127.0.0.1:50259/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 682 T617 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 686 T622 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c588536f60003 type:create cxid:0x2 zxid:0x1a txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 689 T617 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4] 2> 692 T617 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50266_
[junit4:junit4] 2> 693 T622 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c588536f60003 type:delete cxid:0x7 zxid:0x1c txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:50266_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:50266_
[junit4:junit4] 2> 695 T617 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50266_
[junit4:junit4] 2> 701 T617 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4] 2> 709 T622 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c588536f60003 type:delete cxid:0x15 zxid:0x21 txntype:-1 reqpath:n/a Error Path:/solr/overseer_elect/leader Error:KeeperErrorCode = NoNode for /solr/overseer_elect/leader
[junit4:junit4] 2> 711 T617 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 716 T617 oasc.Overseer.start Overseer (id=89043421816553475-127.0.0.1:50266_-n_0000000000) starting
[junit4:junit4] 2> 717 T622 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c588536f60003 type:create cxid:0x1a zxid:0x23 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 719 T622 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c588536f60003 type:create cxid:0x1b zxid:0x24 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 721 T622 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c588536f60003 type:create cxid:0x1c zxid:0x25 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 724 T622 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c588536f60003 type:create cxid:0x1d zxid:0x26 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 726 T641 oasc.OverseerCollectionProcessor.run Process current queue of collection messages
[junit4:junit4] 2> 727 T617 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4] 2> 733 T617 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 738 T640 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 778 T642 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-controljetty-1358694791099\collection1
[junit4:junit4] 2> 778 T642 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4] 2> 779 T642 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 779 T642 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4] 2> 782 T642 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-controljetty-1358694791099\collection1\'
[junit4:junit4] 2> 783 T642 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardRoutingTest-controljetty-1358694791099/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 784 T642 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardRoutingTest-controljetty-1358694791099/collection1/lib/README' to classloader
[junit4:junit4] 2> 854 T642 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_42
[junit4:junit4] 2> 948 T642 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 950 T642 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 955 T642 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 1578 T642 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 1582 T642 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 1610 T642 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-controljetty-1358694791099\collection1\, dataDir=.\org.apache.solr.cloud.ShardRoutingTest-1358694790891/control/data\
[junit4:junit4] 2> 1610 T642 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@184a49
[junit4:junit4] 2> 1613 T642 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 1648 T642 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-1358694790891\control\data forceNew:false
[junit4:junit4] 2> 1649 T642 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-1358694790891\control\data
[junit4:junit4] 2> 1649 T642 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ShardRoutingTest-1358694790891/control/data\index/
[junit4:junit4] 2> 1651 T642 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory '.\org.apache.solr.cloud.ShardRoutingTest-1358694790891\control\data\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 1651 T642 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-1358694790891\control\data\index forceNew:false
[junit4:junit4] 2> 1663 T642 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=RateLimitedDirectoryWrapper(org.apache.lucene.store.SimpleFSDirectory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ShardRoutingTest-1358694790891\control\data\index lockFactory=org.apache.lucene.store.NativeFSLockFactory@f4be9b),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 1663 T642 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 1665 T642 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-1358694790891\control\data\index
[junit4:junit4] 2> 1666 T642 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4] 2> 1668 T642 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 1668 T642 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4] 2> 1668 T642 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 1669 T642 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4] 2> 1669 T642 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 1669 T642 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 1669 T642 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 1670 T642 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 1671 T642 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 1671 T642 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4] 2> 1672 T642 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4] 2> 1672 T642 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 1673 T642 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4] 2> 1673 T642 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4] 2> 1673 T642 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4] 2> 1674 T642 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 1674 T642 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 1674 T642 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 1675 T642 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 1676 T642 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 1676 T642 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 1677 T642 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 1677 T642 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 1677 T642 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 1678 T642 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4] 2> 1679 T642 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4] 2> 1690 T642 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 1696 T642 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4] 2> 1697 T642 oasc.SolrCore.initDeprecatedSupport WARNING adding ShowFileRequestHandler with hidden files: [SCHEMA.XML, OLD_SYNONYMS.TXT, STOPWORDS.TXT, PROTWORDS.TXT, OPEN-EXCHANGE-RATES.JSON, SYNONYMS.TXT, CURRENCY.XML, MAPPING-ISOLATIN1ACCENT.TXT]
[junit4:junit4] 2> 1701 T642 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-1358694790891\control\data
[junit4:junit4] 2> 1702 T642 oass.SolrIndexSearcher.<init> Opening Searcher@f63490 main
[junit4:junit4] 2> 1703 T642 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 1704 T642 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 1704 T642 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4] 2> 1715 T642 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4] 2> 1769 T643 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@f63490 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 1773 T642 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 1774 T642 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1775 T622 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c588536f60003 type:create cxid:0x5c zxid:0x29 txntype:-1 reqpath:n/a Error Path:/solr/overseer/queue Error:KeeperErrorCode = NoNode for /solr/overseer/queue
[junit4:junit4] 2> 2247 T640 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2249 T640 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "node_name":"127.0.0.1:50266_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50266"}
[junit4:junit4] 2> 2249 T640 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4:junit4] 2> 2249 T640 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4] 2> 2251 T622 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c588536f60003 type:create cxid:0x64 zxid:0x2c txntype:-1 reqpath:n/a Error Path:/solr/overseer/queue-work Error:KeeperErrorCode = NoNode for /solr/overseer/queue-work
[junit4:junit4] 2> 2273 T639 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4:junit4] 2> 2781 T642 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 2781 T642 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:50266 collection:control_collection shard:shard1
[junit4:junit4] 2> 2783 T642 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4:junit4] 2> 2811 T622 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c588536f60003 type:delete cxid:0x7e zxid:0x36 txntype:-1 reqpath:n/a Error Path:/solr/collections/control_collection/leaders Error:KeeperErrorCode = NoNode for /solr/collections/control_collection/leaders
[junit4:junit4] 2> 2814 T642 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 2815 T622 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c588536f60003 type:create cxid:0x7f zxid:0x37 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 2824 T642 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 2824 T642 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 2825 T642 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:50266/collection1/
[junit4:junit4] 2> 2825 T642 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 2825 T642 oasc.SyncStrategy.syncToMe http://127.0.0.1:50266/collection1/ has no replicas
[junit4:junit4] 2> 2826 T642 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:50266/collection1/
[junit4:junit4] 2> 2826 T642 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4:junit4] 2> 2843 T622 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c588536f60003 type:create cxid:0x89 zxid:0x3b txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 3786 T640 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 3813 T639 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4:junit4] 2> 3870 T642 oasc.ZkController.register We are http://127.0.0.1:50266/collection1/ and leader is http://127.0.0.1:50266/collection1/
[junit4:junit4] 2> 3870 T642 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:50266
[junit4:junit4] 2> 3870 T642 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 3871 T642 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 3871 T642 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 3877 T642 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 3879 T617 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 3880 T617 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 3881 T617 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 3902 T617 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 3913 T617 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:50259/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@1d7c2f8
[junit4:junit4] 2> 3915 T617 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 3917 T644 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:50259. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 3919 T644 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:50259, initiating session
[junit4:junit4] 2> 3919 T619 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:50277
[junit4:junit4] 2> 3920 T619 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:50277
[junit4:junit4] 2> 3923 T621 oazs.ZooKeeperServer.finishSessionInit Established session 0x13c588536f60004 with negotiated timeout 10000 for client /127.0.0.1:50277
[junit4:junit4] 2> 3923 T644 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:50259, sessionid = 0x13c588536f60004, negotiated timeout = 10000
[junit4:junit4] 2> 3924 T645 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1d7c2f8 name:ZooKeeperConnection Watcher:127.0.0.1:50259/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 3925 T617 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 3928 T617 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 3932 T617 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4] 2> 4282 T617 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 4286 T617 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50278
[junit4:junit4] 2> 4286 T617 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 4286 T617 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 4286 T617 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-jetty1-1358694794820
[junit4:junit4] 2> 4287 T617 oasc.CoreContainer$Initializer.initialize looking for solr.xml: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-jetty1-1358694794820\solr.xml
[junit4:junit4] 2> 4287 T617 oasc.CoreContainer.<init> New CoreContainer 18799905
[junit4:junit4] 2> 4287 T617 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-jetty1-1358694794820\'
[junit4:junit4] 2> 4288 T617 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-jetty1-1358694794820\'
[junit4:junit4] 2> 4334 T617 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 60000
[junit4:junit4] 2> 4336 T617 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 4336 T617 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 4336 T617 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 4336 T617 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 4336 T617 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 4337 T617 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 4337 T617 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 4338 T617 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 4338 T617 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=60000&connTimeout=15000&retry=false
[junit4:junit4] 2> 4358 T617 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 4379 T617 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:50259/solr
[junit4:junit4] 2> 4380 T617 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 4380 T617 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:50259 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@1f737d2
[junit4:junit4] 2> 4382 T617 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 4383 T655 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:50259. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 4384 T655 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:50259, initiating session
[junit4:junit4] 2> 4384 T619 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:50283
[junit4:junit4] 2> 4385 T619 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:50283
[junit4:junit4] 2> 4396 T621 oazs.ZooKeeperServer.finishSessionInit Established session 0x13c588536f60005 with negotiated timeout 20000 for client /127.0.0.1:50283
[junit4:junit4] 2> 4396 T655 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:50259, sessionid = 0x13c588536f60005, negotiated timeout = 20000
[junit4:junit4] 2> 4397 T656 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1f737d2 name:ZooKeeperConnection Watcher:127.0.0.1:50259 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 4397 T617 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 4400 T622 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13c588536f60005
[junit4:junit4] 2> 4402 T619 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:50283 which had sessionid 0x13c588536f60005
[junit4:junit4] 2> 4402 T617 oaz.ZooKeeper.close Session: 0x13c588536f60005 closed
[junit4:junit4] 2> 4402 T656 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 4402 T617 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=60000&connTimeout=15000
[junit4:junit4] 2> 4412 T617 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:50259/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@1cf613e
[junit4:junit4] 2> 4415 T617 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 4416 T657 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:50259. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 4417 T657 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:50259, initiating session
[junit4:junit4] 2> 4418 T619 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:50286
[junit4:junit4] 2> 4419 T619 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:50286
[junit4:junit4] 2> 4421 T621 oazs.ZooKeeperServer.finishSessionInit Established session 0x13c588536f60006 with negotiated timeout 20000 for client /127.0.0.1:50286
[junit4:junit4] 2> 4421 T657 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:50259, sessionid = 0x13c588536f60006, negotiated timeout = 20000
[junit4:junit4] 2> 4421 T658 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1cf613e name:ZooKeeperConnection Watcher:127.0.0.1:50259/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 4422 T617 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 4423 T622 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c588536f60006 type:create cxid:0x1 zxid:0x49 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 4425 T622 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c588536f60006 type:create cxid:0x2 zxid:0x4a txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 4427 T617 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50278_
[junit4:junit4] 2> 4428 T622 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c588536f60006 type:delete cxid:0x4 zxid:0x4b txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:50278_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:50278_
[junit4:junit4] 2> 4430 T617 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50278_
[junit4:junit4] 2> 4435 T639 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
[junit4:junit4] 2> 4436 T645 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 4438 T639 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 4442 T617 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 4450 T659 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-jetty1-1358694794820\collection1
[junit4:junit4] 2> 4450 T659 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 4451 T659 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 4451 T659 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 4453 T659 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-jetty1-1358694794820\collection1\'
[junit4:junit4] 2> 4454 T659 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardRoutingTest-jetty1-1358694794820/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 4455 T659 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardRoutingTest-jetty1-1358694794820/collection1/lib/README' to classloader
[junit4:junit4] 2> 4522 T659 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_42
[junit4:junit4] 2> 4596 T659 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 4598 T659 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 4604 T659 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 5262 T659 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 5266 T659 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 5296 T659 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-jetty1-1358694794820\collection1\, dataDir=.\org.apache.solr.cloud.ShardRoutingTest-1358694790891/jetty1\
[junit4:junit4] 2> 5296 T659 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@184a49
[junit4:junit4] 2> 5297 T659 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 5298 T659 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-1358694790891\jetty1 forceNew:false
[junit4:junit4] 2> 5298 T659 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-1358694790891\jetty1
[junit4:junit4] 2> 5298 T659 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ShardRoutingTest-1358694790891/jetty1\index/
[junit4:junit4] 2> 5300 T659 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory '.\org.apache.solr.cloud.ShardRoutingTest-1358694790891\jetty1\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 5300 T659 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-1358694790891\jetty1\index forceNew:false
[junit4:junit4] 2> 5311 T659 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=RateLimitedDirectoryWrapper(org.apache.lucene.store.SimpleFSDirectory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ShardRoutingTest-1358694790891\jetty1\index lockFactory=org.apache.lucene.store.NativeFSLockFactory@df9f0e),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 5311 T659 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 5313 T659 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-1358694790891\jetty1\index
[junit4:junit4] 2> 5313 T659 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4] 2> 5315 T659 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 5315 T659 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4] 2> 5315 T659 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 5316 T659 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4] 2> 5316 T659 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 5317 T659 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 5317 T659 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 5318 T659 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 5318 T659 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 5319 T659 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4] 2> 5319 T659 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4] 2> 5320 T659 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 5320 T659 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4] 2> 5320 T659 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4] 2> 5321 T659 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4] 2> 5322 T659 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 5322 T659 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 5323 T659 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 5323 T659 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 5324 T659 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 5324 T659 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 5325 T659 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 5326 T659 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 5326 T659 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 5327 T659 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4] 2> 5328 T640 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 5328 T659 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4] 2> 5328 T640 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "node_name":"127.0.0.1:50266_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50266"}
[junit4:junit4] 2> 5341 T659 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 5346 T658 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 5348 T645 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 5348 T639 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 5351 T659 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4] 2> 5354 T659 oasc.SolrCore.initDeprecatedSupport WARNING adding ShowFileRequestHandler with hidden files: [SCHEMA.XML, OLD_SYNONYMS.TXT, STOPWORDS.TXT, PROTWORDS.TXT, OPEN-EXCHANGE-RATES.JSON, SYNONYMS.TXT, CURRENCY.XML, MAPPING-ISOLATIN1ACCENT.TXT]
[junit4:junit4] 2> 5358 T659 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-1358694790891\jetty1
[junit4:junit4] 2> 5359 T659 oass.SolrIndexSearcher.<init> Opening Searcher@88743b main
[junit4:junit4] 2> 5361 T659 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 5362 T659 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 5362 T659 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4] 2> 5372 T659 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4] 2> 5430 T660 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@88743b main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 5435 T659 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 5435 T659 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 6860 T640 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 6862 T640 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=4 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "numShards":"4",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:50278_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50278"}
[junit4:junit4] 2> 6862 T640 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 4
[junit4:junit4] 2> 6862 T640 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4] 2> 6877 T645 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 6878 T639 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 6878 T658 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 7438 T659 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 7438 T659 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:50278 collection:collection1 shard:shard1
[junit4:junit4] 2> 7440 T659 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4] 2> 7466 T622 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c588536f60006 type:delete cxid:0x51 zxid:0x5b txntype:-1 reqpath:n/a Error Path:/solr/collections/collection1/leaders Error:KeeperErrorCode = NoNode for /solr/collections/collection1/leaders
[junit4:junit4] 2> 7468 T659 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 7470 T622 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c588536f60006 type:create cxid:0x52 zxid:0x5c txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 7478 T659 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 7478 T659 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 7478 T659 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:50278/collection1/
[junit4:junit4] 2> 7479 T659 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 7479 T659 oasc.SyncStrategy.syncToMe http://127.0.0.1:50278/collection1/ has no replicas
[junit4:junit4] 2> 7479 T659 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:50278/collection1/
[junit4:junit4] 2> 7480 T659 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4] 2> 7495 T622 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c588536f60006 type:create cxid:0x5c zxid:0x60 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 8390 T640 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 8513 T645 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 8514 T639 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 8515 T658 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 8573 T659 oasc.ZkController.register We are http://127.0.0.1:50278/collection1/ and leader is http://127.0.0.1:50278/collection1/
[junit4:junit4] 2> 8573 T659 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:50278
[junit4:junit4] 2> 8574 T659 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 8574 T659 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 8575 T659 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 8605 T659 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 8609 T617 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 8609 T617 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 8611 T617 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 8943 T617 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 8947 T617 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50287
[junit4:junit4] 2> 8947 T617 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 8948 T617 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 8948 T617 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-jetty2-1358694799517
[junit4:junit4] 2> 8950 T617 oasc.CoreContainer$Initializer.initialize looking for solr.xml: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-jetty2-1358694799517\solr.xml
[junit4:junit4] 2> 8950 T617 oasc.CoreContainer.<init> New CoreContainer 7950836
[junit4:junit4] 2> 8951 T617 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-jetty2-1358694799517\'
[junit4:junit4] 2> 8952 T617 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-jetty2-1358694799517\'
[junit4:junit4] 2> 8996 T617 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 60000
[junit4:junit4] 2> 8998 T617 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 8998 T617 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 8998 T617 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 8999 T617 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 8999 T617 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 8999 T617 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 9000 T617 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 9000 T617 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 9001 T617 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=60000&connTimeout=15000&retry=false
[junit4:junit4] 2> 9015 T617 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 9037 T617 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:50259/solr
[junit4:junit4] 2> 9038 T617 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 9038 T617 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:50259 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@130ebf9
[junit4:junit4] 2> 9040 T617 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 9041 T670 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:50259. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 9042 T670 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:50259, initiating session
[junit4:junit4] 2> 9042 T619 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:50292
[junit4:junit4] 2> 9043 T619 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:50292
[junit4:junit4] 2> 9053 T621 oazs.ZooKeeperServer.finishSessionInit Established session 0x13c588536f60007 with negotiated timeout 20000 for client /127.0.0.1:50292
[junit4:junit4] 2> 9053 T670 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:50259, sessionid = 0x13c588536f60007, negotiated timeout = 20000
[junit4:junit4] 2> 9054 T671 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@130ebf9 name:ZooKeeperConnection Watcher:127.0.0.1:50259 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 9054 T617 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 9056 T622 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13c588536f60007
[junit4:junit4] 2> 9058 T671 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 9058 T617 oaz.ZooKeeper.close Session: 0x13c588536f60007 closed
[junit4:junit4] 2> 9059 T617 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=60000&connTimeout=15000
[junit4:junit4] 2> 9060 T619 oazs.NIOServerCnxn.doIO WARNING caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x13c588536f60007, likely client has closed socket
[junit4:junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
[junit4:junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4:junit4] 2> at java.lang.Thread.run(Thread.java:722)
[junit4:junit4] 2>
[junit4:junit4] 2> 9061 T619 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:50292 which had sessionid 0x13c588536f60007
[junit4:junit4] 2> 9064 T617 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:50259/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@189cb94
[junit4:junit4] 2> 9067 T617 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 9068 T672 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:50259. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 9069 T672 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:50259, initiating session
[junit4:junit4] 2> 9069 T619 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:50295
[junit4:junit4] 2> 9070 T619 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:50295
[junit4:junit4] 2> 9072 T621 oazs.ZooKeeperServer.finishSessionInit Established session 0x13c588536f60008 with negotiated timeout 20000 for client /127.0.0.1:50295
[junit4:junit4] 2> 9073 T672 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:50259, sessionid = 0x13c588536f60008, negotiated timeout = 20000
[junit4:junit4] 2> 9073 T673 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@189cb94 name:ZooKeeperConnection Watcher:127.0.0.1:50259/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 9073 T617 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 9074 T622 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c588536f60008 type:create cxid:0x1 zxid:0x6d txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 9077 T622 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c588536f60008 type:create cxid:0x2 zxid:0x6e txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 9078 T617 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50287_
[junit4:junit4] 2> 9089 T622 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c588536f60008 type:delete cxid:0x4 zxid:0x6f txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:50287_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:50287_
[junit4:junit4] 2> 9094 T617 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50287_
[junit4:junit4] 2> 9098 T658 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 9099 T645 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 9099 T639 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 9103 T658 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 9104 T645 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 9104 T639 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 9108 T617 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 9144 T674 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-jetty2-1358694799517\collection1
[junit4:junit4] 2> 9144 T674 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 9146 T674 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 9146 T674 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 9149 T674 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-jetty2-1358694799517\collection1\'
[junit4:junit4] 2> 9150 T674 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardRoutingTest-jetty2-1358694799517/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 9151 T674 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardRoutingTest-jetty2-1358694799517/collection1/lib/README' to classloader
[junit4:junit4] 2> 9210 T674 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_42
[junit4:junit4] 2> 9291 T674 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 9293 T674 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 9299 T674 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 9975 T674 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 9979 T674 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 10009 T674 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-jetty2-1358694799517\collection1\, dataDir=.\org.apache.solr.cloud.ShardRoutingTest-1358694790891/jetty2\
[junit4:junit4] 2> 10009 T674 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@184a49
[junit4:junit4] 2> 10010 T674 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 10011 T674 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-1358694790891\jetty2 forceNew:false
[junit4:junit4] 2> 10012 T674 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-1358694790891\jetty2
[junit4:junit4] 2> 10013 T674 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ShardRoutingTest-1358694790891/jetty2\index/
[junit4:junit4] 2> 10014 T674 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory '.\org.apache.solr.cloud.ShardRoutingTest-1358694790891\jetty2\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 10015 T674 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-1358694790891\jetty2\index forceNew:false
[junit4:junit4] 2> 10023 T674 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=RateLimitedDirectoryWrapper(org.apache.lucene.store.SimpleFSDirectory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ShardRoutingTest-1358694790891\jetty2\index lockFactory=org.apache.lucene.store.NativeFSLockFactory@1a09adf),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 10024 T674 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 10025 T674 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-1358694790891\jetty2\index
[junit4:junit4] 2> 10025 T674 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4] 2> 10028 T674 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 10028 T674 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4] 2> 10028 T674 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 10029 T674 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4] 2> 10029 T674 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 10029 T674 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 10029 T674 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 10030 T674 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 10031 T674 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 10031 T674 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4] 2> 10032 T674 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4] 2> 10032 T674 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 10033 T674 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4] 2> 10033 T674 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4] 2> 10033 T674 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4] 2> 10034 T674 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 10034 T674 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 10035 T674 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 10036 T674 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 10036 T674 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 10036 T674 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 10036 T674 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 10037 T674 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 10038 T674 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 10038 T674 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4] 2> 10039 T674 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4] 2> 10050 T674 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 10056 T674 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4] 2> 10059 T674 oasc.SolrCore.initDeprecatedSupport WARNING adding ShowFileRequestHandler with hidden files: [SCHEMA.XML, OLD_SYNONYMS.TXT, STOPWORDS.TXT, PROTWORDS.TXT, OPEN-EXCHANGE-RATES.JSON, SYNONYMS.TXT, CURRENCY.XML, MAPPING-ISOLATIN1ACCENT.TXT]
[junit4:junit4] 2> 10061 T674 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-1358694790891\jetty2
[junit4:junit4] 2> 10064 T674 oass.SolrIndexSearcher.<init> Opening Searcher@94308a main
[junit4:junit4] 2> 10066 T674 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 10067 T674 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 10067 T674 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4] 2> 10068 T640 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 10069 T640 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=4 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "numShards":"4",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:50278_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50278"}
[junit4:junit4] 2> 10078 T673 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 10078 T645 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 10081 T639 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 10083 T674 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4] 2> 10078 T658 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 10147 T675 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@94308a main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 10152 T674 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 10152 T674 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 11602 T640 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 11603 T640 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=4 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "numShards":"4",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:50287_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50287"}
[junit4:junit4] 2> 11603 T640 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=4
[junit4:junit4] 2> 11603 T640 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4:junit4] 2> 11611 T658 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 11611 T673 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 11612 T645 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 11612 T639 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 12155 T674 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 12155 T674 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:50287 collection:collection1 shard:shard2
[junit4:junit4] 2> 12157 T674 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4:junit4] 2> 12174 T622 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c588536f60008 type:delete cxid:0x50 zxid:0x7e txntype:-1 reqpath:n/a Error Path:/solr/collections/collection1/leaders/shard2 Error:KeeperErrorCode = NoNode for /solr/collections/collection1/leaders/shard2
[junit4:junit4] 2> 12176 T674 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 12177 T622 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c588536f60008 type:create cxid:0x51 zxid:0x7f txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 12181 T674 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 12182 T674 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 12182 T674 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:50287/collection1/
[junit4:junit4] 2> 12182 T674 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 12182 T674 oasc.SyncStrategy.syncToMe http://127.0.0.1:50287/collection1/ has no replicas
[junit4:junit4] 2> 12182 T674 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:50287/collection1/
[junit4:junit4] 2> 12183 T674 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4] 2> 12189 T622 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c588536f60008 type:create cxid:0x5a zxid:0x82 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 13119 T640 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 13138 T673 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 13138 T658 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 13139 T639 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 13139 T645 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 13159 T674 oasc.ZkController.register We are http://127.0.0.1:50287/collection1/ and leader is http://127.0.0.1:50287/collection1/
[junit4:junit4] 2> 13159 T674 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:50287
[junit4:junit4] 2> 13159 T674 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 13159 T674 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 13159 T674 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 13162 T674 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 13163 T617 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 13163 T617 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 13165 T617 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 13497 T617 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 13501 T617 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50296
[junit4:junit4] 2> 13502 T617 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 13503 T617 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 13503 T617 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-jetty3-1358694804067
[junit4:junit4] 2> 13504 T617 oasc.CoreContainer$Initializer.initialize looking for solr.xml: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-jetty3-1358694804067\solr.xml
[junit4:junit4] 2> 13504 T617 oasc.CoreContainer.<init> New CoreContainer 7820550
[junit4:junit4] 2> 13504 T617 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-jetty3-1358694804067\'
[junit4:junit4] 2> 13505 T617 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-jetty3-1358694804067\'
[junit4:junit4] 2> 13552 T617 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 60000
[junit4:junit4] 2> 13553 T617 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 13553 T617 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 13553 T617 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 13554 T617 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 13554 T617 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 13554 T617 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 13555 T617 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 13555 T617 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 13556 T617 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=60000&connTimeout=15000&retry=false
[junit4:junit4] 2> 13571 T617 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 13593 T617 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:50259/solr
[junit4:junit4] 2> 13594 T617 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 13594 T617 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:50259 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@12d3863
[junit4:junit4] 2> 13596 T617 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 13597 T685 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:50259. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 13598 T685 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:50259, initiating session
[junit4:junit4] 2> 13598 T619 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:50301
[junit4:junit4] 2> 13598 T619 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:50301
[junit4:junit4] 2> 13610 T621 oazs.ZooKeeperServer.finishSessionInit Established session 0x13c588536f60009 with negotiated timeout 20000 for client /127.0.0.1:50301
[junit4:junit4] 2> 13610 T685 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:50259, sessionid = 0x13c588536f60009, negotiated timeout = 20000
[junit4:junit4] 2> 13611 T686 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@12d3863 name:ZooKeeperConnection Watcher:127.0.0.1:50259 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 13611 T617 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 13615 T622 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13c588536f60009
[junit4:junit4] 2> 13617 T619 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:50301 which had sessionid 0x13c588536f60009
[junit4:junit4] 2> 13617 T617 oaz.ZooKeeper.close Session: 0x13c588536f60009 closed
[junit4:junit4] 2> 13618 T686 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 13618 T617 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=60000&connTimeout=15000
[junit4:junit4] 2> 13625 T617 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:50259/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@13db014
[junit4:junit4] 2> 13627 T617 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 13627 T687 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:50259. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 13628 T687 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:50259, initiating session
[junit4:junit4] 2> 13628 T619 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:50304
[junit4:junit4] 2> 13629 T619 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:50304
[junit4:junit4] 2> 13631 T621 oazs.ZooKeeperServer.finishSessionInit Established session 0x13c588536f6000a with negotiated timeout 20000 for client /127.0.0.1:50304
[junit4:junit4] 2> 13631 T687 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:50259, sessionid = 0x13c588536f6000a, negotiated timeout = 20000
[junit4:junit4] 2> 13631 T688 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@13db014 name:ZooKeeperConnection Watcher:127.0.0.1:50259/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 13632 T617 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 13633 T622 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c588536f6000a type:create cxid:0x1 zxid:0x8f txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 13635 T622 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c588536f6000a type:create cxid:0x2 zxid:0x90 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 13637 T617 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50296_
[junit4:junit4] 2> 13638 T622 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c588536f6000a type:delete cxid:0x4 zxid:0x91 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:50296_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:50296_
[junit4:junit4] 2> 13639 T617 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50296_
[junit4:junit4] 2> 13642 T658 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 13643 T645 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 13643 T639 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 13644 T673 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 13644 T673 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 13646 T658 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 13649 T645 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 13649 T639 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 13650 T617 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 13660 T689 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-jetty3-1358694804067\collection1
[junit4:junit4] 2> 13660 T689 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 13661 T689 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 13661 T689 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 13663 T689 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-jetty3-1358694804067\collection1\'
[junit4:junit4] 2> 13664 T689 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardRoutingTest-jetty3-1358694804067/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 13664 T689 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardRoutingTest-jetty3-1358694804067/collection1/lib/README' to classloader
[junit4:junit4] 2> 13723 T689 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_42
[junit4:junit4] 2> 13804 T689 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 13805 T689 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 13811 T689 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 14531 T689 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 14536 T689 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 14570 T689 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-jetty3-1358694804067\collection1\, dataDir=.\org.apache.solr.cloud.ShardRoutingTest-1358694790891/jetty3\
[junit4:junit4] 2> 14570 T689 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@184a49
[junit4:junit4] 2> 14571 T689 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 14571 T689 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-1358694790891\jetty3 forceNew:false
[junit4:junit4] 2> 14572 T689 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-1358694790891\jetty3
[junit4:junit4] 2> 14572 T689 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ShardRoutingTest-1358694790891/jetty3\index/
[junit4:junit4] 2> 14574 T689 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory '.\org.apache.solr.cloud.ShardRoutingTest-1358694790891\jetty3\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 14575 T689 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-1358694790891\jetty3\index forceNew:false
[junit4:junit4] 2> 14587 T689 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=RateLimitedDirectoryWrapper(org.apache.lucene.store.SimpleFSDirectory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ShardRoutingTest-1358694790891\jetty3\index lockFactory=org.apache.lucene.store.NativeFSLockFactory@17ca5f4),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 14587 T689 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 14589 T689 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-1358694790891\jetty3\index
[junit4:junit4] 2> 14589 T689 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4] 2> 14591 T689 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 14591 T689 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4] 2> 14591 T689 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 14592 T689 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4] 2> 14592 T689 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 14593 T689 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 14593 T689 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 14594 T689 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 14594 T689 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 14595 T689 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4] 2> 14596 T689 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4] 2> 14596 T689 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 14597 T689 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4] 2> 14597 T689 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4] 2> 14597 T689 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4] 2> 14598 T689 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 14598 T689 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 14599 T689 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 14600 T689 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 14600 T689 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 14601 T689 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 14601 T689 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 14602 T689 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 14603 T689 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 14603 T689 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4] 2> 14604 T689 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4] 2> 14616 T689 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 14620 T689 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4] 2> 14622 T689 oasc.SolrCore.initDeprecatedSupport WARNING adding ShowFileRequestHandler with hidden files: [SCHEMA.XML, OLD_SYNONYMS.TXT, STOPWORDS.TXT, PROTWORDS.TXT, OPEN-EXCHANGE-RATES.JSON, SYNONYMS.TXT, CURRENCY.XML, MAPPING-ISOLATIN1ACCENT.TXT]
[junit4:junit4] 2> 14625 T689 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-1358694790891\jetty3
[junit4:junit4] 2> 14627 T689 oass.SolrIndexSearcher.<init> Opening Searcher@f5d13b main
[junit4:junit4] 2> 14629 T689 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 14629 T689 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 14630 T689 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4] 2> 14641 T689 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4] 2> 14651 T640 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 14652 T640 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=4 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "numShards":"4",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:50287_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50287"}
[junit4:junit4] 2> 14666 T688 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 14667 T639 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 14667 T645 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 14668 T658 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 14668 T673 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 14704 T690 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@f5d13b main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 14709 T689 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 14709 T689 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 16183 T640 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 16184 T640 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=4 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "numShards":"4",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:50296_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50296"}
[junit4:junit4] 2> 16184 T640 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=4
[junit4:junit4] 2> 16185 T640 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4:junit4] 2> 16199 T673 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 16199 T688 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 16200 T645 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 16200 T639 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 16200 T658 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 16711 T689 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 16711 T689 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:50296 collection:collection1 shard:shard3
[junit4:junit4] 2> 16712 T689 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
[junit4:junit4] 2> 16722 T622 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c588536f6000a type:delete cxid:0x50 zxid:0xa0 txntype:-1 reqpath:n/a Error Path:/solr/collections/collection1/leaders/shard3 Error:KeeperErrorCode = NoNode for /solr/collections/collection1/leaders/shard3
[junit4:junit4] 2> 16724 T689 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 16724 T622 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c588536f6000a type:create cxid:0x51 zxid:0xa1 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 16728 T689 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 16728 T689 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 16728 T689 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:50296/collection1/
[junit4:junit4] 2> 16728 T689 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 16729 T689 oasc.SyncStrategy.syncToMe http://127.0.0.1:50296/collection1/ has no replicas
[junit4:junit4] 2> 16729 T689 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:50296/collection1/
[junit4:junit4] 2> 16729 T689 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
[junit4:junit4] 2> 16735 T622 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c588536f6000a type:create cxid:0x5a zxid:0xa4 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 17708 T640 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 17723 T673 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 17724 T645 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 17724 T688 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 17724 T658 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 17724 T639 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 17754 T689 oasc.ZkController.register We are http://127.0.0.1:50296/collection1/ and leader is http://127.0.0.1:50296/collection1/
[junit4:junit4] 2> 17754 T689 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:50296
[junit4:junit4] 2> 17754 T689 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 17754 T689 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 17755 T689 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 17758 T689 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 17759 T617 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 17759 T617 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 17760 T617 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 18090 T617 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 18094 T617 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50305
[junit4:junit4] 2> 18096 T617 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 18096 T617 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 18096 T617 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-jetty4-1358694808657
[junit4:junit4] 2> 18097 T617 oasc.CoreContainer$Initializer.initialize looking for solr.xml: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-jetty4-1358694808657\solr.xml
[junit4:junit4] 2> 18097 T617 oasc.CoreContainer.<init> New CoreContainer 29788452
[junit4:junit4] 2> 18098 T617 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-jetty4-1358694808657\'
[junit4:junit4] 2> 18098 T617 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-jetty4-1358694808657\'
[junit4:junit4] 2> 18175 T617 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 60000
[junit4:junit4] 2> 18176 T617 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 18176 T617 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 18177 T617 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 18177 T617 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 18177 T617 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 18178 T617 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 18178 T617 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 18179 T617 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 18179 T617 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=60000&connTimeout=15000&retry=false
[junit4:junit4] 2> 18195 T617 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 18217 T617 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:50259/solr
[junit4:junit4] 2> 18218 T617 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 18218 T617 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:50259 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@ff0d39
[junit4:junit4] 2> 18220 T617 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 18221 T700 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:50259. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 18222 T700 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:50259, initiating session
[junit4:junit4] 2> 18222 T619 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:50310
[junit4:junit4] 2> 18223 T619 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:50310
[junit4:junit4] 2> 18234 T621 oazs.ZooKeeperServer.finishSessionInit Established session 0x13c588536f6000b with negotiated timeout 20000 for client /127.0.0.1:50310
[junit4:junit4] 2> 18234 T700 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:50259, sessionid = 0x13c588536f6000b, negotiated timeout = 20000
[junit4:junit4] 2> 18234 T701 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@ff0d39 name:ZooKeeperConnection Watcher:127.0.0.1:50259 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 18235 T617 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 18237 T622 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13c588536f6000b
[junit4:junit4] 2> 18254 T617 oaz.ZooKeeper.close Session: 0x13c588536f6000b closed
[junit4:junit4] 2> 18254 T619 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:50310 which had sessionid 0x13c588536f6000b
[junit4:junit4] 2> 18255 T617 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=60000&connTimeout=15000
[junit4:junit4] 2> 18255 T701 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 18261 T617 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:50259/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@14a1a2b
[junit4:junit4] 2> 18263 T617 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 18264 T702 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:50259. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 18264 T702 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:50259, initiating session
[junit4:junit4] 2> 18264 T619 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:50313
[junit4:junit4] 2> 18265 T619 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:50313
[junit4:junit4] 2> 18267 T621 oazs.ZooKeeperServer.finishSessionInit Established session 0x13c588536f6000c with negotiated timeout 20000 for client /127.0.0.1:50313
[junit4:junit4] 2> 18267 T702 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:50259, sessionid = 0x13c588536f6000c, negotiated timeout = 20000
[junit4:junit4] 2> 18267 T703 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@14a1a2b name:ZooKeeperConnection Watcher:127.0.0.1:50259/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 18267 T617 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 18268 T622 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c588536f6000c type:create cxid:0x1 zxid:0xb1 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 18270 T622 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c588536f6000c type:create cxid:0x2 zxid:0xb2 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 18272 T617 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50305_
[junit4:junit4] 2> 18274 T622 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c588536f6000c type:delete cxid:0x4 zxid:0xb3 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:50305_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:50305_
[junit4:junit4] 2> 18275 T617 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50305_
[junit4:junit4] 2> 18279 T688 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 18281 T658 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 18280 T639 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 18280 T645 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 18282 T673 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 18282 T673 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 18286 T688 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 18286 T645 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 18286 T639 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 18288 T658 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 18290 T617 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 18299 T704 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-jetty4-1358694808657\collection1
[junit4:junit4] 2> 18299 T704 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 18300 T704 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 18300 T704 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 18302 T704 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-jetty4-1358694808657\collection1\'
[junit4:junit4] 2> 18304 T704 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardRoutingTest-jetty4-1358694808657/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 18305 T704 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardRoutingTest-jetty4-1358694808657/collection1/lib/README' to classloader
[junit4:junit4] 2> 18363 T704 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_42
[junit4:junit4] 2> 18439 T704 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 18441 T704 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 18447 T704 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 19144 T704 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 19148 T704 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 19183 T704 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-jetty4-1358694808657\collection1\, dataDir=.\org.apache.solr.cloud.ShardRoutingTest-1358694790891/jetty4\
[junit4:junit4] 2> 19183 T704 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@184a49
[junit4:junit4] 2> 19183 T704 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 19184 T704 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-1358694790891\jetty4 forceNew:false
[junit4:junit4] 2> 19186 T704 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-1358694790891\jetty4
[junit4:junit4] 2> 19186 T704 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ShardRoutingTest-1358694790891/jetty4\index/
[junit4:junit4] 2> 19187 T704 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory '.\org.apache.solr.cloud.ShardRoutingTest-1358694790891\jetty4\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 19188 T704 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-1358694790891\jetty4\index forceNew:false
[junit4:junit4] 2> 19198 T704 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=RateLimitedDirectoryWrapper(org.apache.lucene.store.SimpleFSDirectory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ShardRoutingTest-1358694790891\jetty4\index lockFactory=org.apache.lucene.store.NativeFSLockFactory@2fa64b),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 19198 T704 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 19200 T704 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-1358694790891\jetty4\index
[junit4:junit4] 2> 19201 T704 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4] 2> 19202 T704 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 19202 T704 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4] 2> 19203 T704 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 19203 T704 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4] 2> 19203 T704 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 19203 T704 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 19203 T704 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 19205 T704 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 19205 T704 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 19206 T704 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4] 2> 19206 T704 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4] 2> 19207 T704 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 19207 T704 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4] 2> 19207 T704 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4] 2> 19207 T704 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4] 2> 19209 T704 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 19209 T704 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 19210 T704 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 19210 T704 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 19211 T704 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 19211 T704 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 19212 T704 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 19213 T704 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 19213 T704 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 19214 T704 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4] 2> 19214 T704 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4] 2> 19227 T704 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 19232 T704 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4] 2> 19235 T704 oasc.SolrCore.initDeprecatedSupport WARNING adding ShowFileRequestHandler with hidden files: [SCHEMA.XML, OLD_SYNONYMS.TXT, STOPWORDS.TXT, PROTWORDS.TXT, OPEN-EXCHANGE-RATES.JSON, SYNONYMS.TXT, CURRENCY.XML, MAPPING-ISOLATIN1ACCENT.TXT]
[junit4:junit4] 2> 19240 T640 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 19241 T704 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-1358694790891\jetty4
[junit4:junit4] 2> 19241 T640 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=4 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "numShards":"4",
[junit4:junit4] 2> "shard":"shard3",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:50296_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50296"}
[junit4:junit4] 2> 19244 T704 oass.SolrIndexSearcher.<init> Opening Searcher@45cf39 main
[junit4:junit4] 2> 19247 T704 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 19247 T704 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 19248 T704 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4] 2> 19259 T673 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 19260 T703 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 19260 T688 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 19263 T658 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 19264 T639 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 19260 T645 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 19267 T704 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4] 2> 19333 T705 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@45cf39 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 19341 T704 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 19341 T704 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 20782 T640 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 20783 T640 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=4 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "numShards":"4",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:50305_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50305"}
[junit4:junit4] 2> 20783 T640 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=4
[junit4:junit4] 2> 20783 T640 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard4
[junit4:junit4] 2> 20796 T688 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 20796 T673 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 20796 T658 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 20796 T639 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 20796 T645 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 20796 T703 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 21345 T704 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 21345 T704 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:50305 collection:collection1 shard:shard4
[junit4:junit4] 2> 21347 T704 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard4/election
[junit4:junit4] 2> 21366 T622 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c588536f6000c type:delete cxid:0x50 zxid:0xc2 txntype:-1 reqpath:n/a Error Path:/solr/collections/collection1/leaders/shard4 Error:KeeperErrorCode = NoNode for /solr/collections/collection1/leaders/shard4
[junit4:junit4] 2> 21368 T704 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 21369 T622 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c588536f6000c type:create cxid:0x51 zxid:0xc3 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 21373 T704 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 21374 T704 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 21374 T704 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:50305/collection1/
[junit4:junit4] 2> 21374 T704 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 21375 T704 oasc.SyncStrategy.syncToMe http://127.0.0.1:50305/collection1/ has no replicas
[junit4:junit4] 2> 21375 T704 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:50305/collection1/
[junit4:junit4] 2> 21376 T704 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard4
[junit4:junit4] 2> 21384 T622 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c588536f6000c type:create cxid:0x5a zxid:0xc6 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 22306 T640 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 22323 T673 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 22323 T688 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 22324 T703 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 22324 T645 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 22324 T639 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 22323 T658 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 22354 T704 oasc.ZkController.register We are http://127.0.0.1:50305/collection1/ and leader is http://127.0.0.1:50305/collection1/
[junit4:junit4] 2> 22354 T704 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:50305
[junit4:junit4] 2> 22354 T704 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 22354 T704 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 22355 T704 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 22358 T704 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 22360 T617 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 22360 T617 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 22361 T617 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 22706 T617 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 22710 T617 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50314
[junit4:junit4] 2> 22711 T617 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 22711 T617 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 22712 T617 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-jetty5-1358694813257
[junit4:junit4] 2> 22712 T617 oasc.CoreContainer$Initializer.initialize looking for solr.xml: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-jetty5-1358694813257\solr.xml
[junit4:junit4] 2> 22713 T617 oasc.CoreContainer.<init> New CoreContainer 28276370
[junit4:junit4] 2> 22713 T617 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-jetty5-1358694813257\'
[junit4:junit4] 2> 22713 T617 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-jetty5-1358694813257\'
[junit4:junit4] 2> 22762 T617 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 60000
[junit4:junit4] 2> 22763 T617 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 22763 T617 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 22764 T617 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 22764 T617 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 22764 T617 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 22764 T617 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 22764 T617 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 22765 T617 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 22766 T617 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=60000&connTimeout=15000&retry=false
[junit4:junit4] 2> 22782 T617 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 22807 T617 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:50259/solr
[junit4:junit4] 2> 22808 T617 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 22808 T617 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:50259 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@1a4ae29
[junit4:junit4] 2> 22810 T617 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 22810 T715 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:50259. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 22811 T715 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:50259, initiating session
[junit4:junit4] 2> 22811 T619 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:50319
[junit4:junit4] 2> 22812 T619 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:50319
[junit4:junit4] 2> 22822 T621 oazs.ZooKeeperServer.finishSessionInit Established session 0x13c588536f6000d with negotiated timeout 20000 for client /127.0.0.1:50319
[junit4:junit4] 2> 22822 T715 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:50259, sessionid = 0x13c588536f6000d, negotiated timeout = 20000
[junit4:junit4] 2> 22822 T716 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1a4ae29 name:ZooKeeperConnection Watcher:127.0.0.1:50259 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 22823 T617 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 22825 T622 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13c588536f6000d
[junit4:junit4] 2> 22826 T619 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:50319 which had sessionid 0x13c588536f6000d
[junit4:junit4] 2> 22826 T617 oaz.ZooKeeper.close Session: 0x13c588536f6000d closed
[junit4:junit4] 2> 22827 T617 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=60000&connTimeout=15000
[junit4:junit4] 2> 22828 T716 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 22831 T617 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:50259/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@1ace695
[junit4:junit4] 2> 22833 T617 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 22834 T717 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:50259. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 22834 T717 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:50259, initiating session
[junit4:junit4] 2> 22834 T619 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:50322
[junit4:junit4] 2> 22835 T619 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:50322
[junit4:junit4] 2> 22836 T621 oazs.ZooKeeperServer.finishSessionInit Established session 0x13c588536f6000e with negotiated timeout 20000 for client /127.0.0.1:50322
[junit4:junit4] 2> 22836 T717 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:50259, sessionid = 0x13c588536f6000e, negotiated timeout = 20000
[junit4:junit4] 2> 22837 T718 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1ace695 name:ZooKeeperConnection Watcher:127.0.0.1:50259/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 22837 T617 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 22839 T622 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c588536f6000e type:create cxid:0x1 zxid:0xd3 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 22840 T622 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c588536f6000e type:create cxid:0x2 zxid:0xd4 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 22843 T617 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50314_
[junit4:junit4] 2> 22844 T622 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c588536f6000e type:delete cxid:0x4 zxid:0xd5 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:50314_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:50314_
[junit4:junit4] 2> 22847 T617 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50314_
[junit4:junit4] 2> 22850 T688 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 22851 T658 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 22851 T645 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 22852 T639 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 22852 T673 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4] 2> 22853 T673 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 6)
[junit4:junit4] 2> 22853 T703 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4] 2> 22853 T703 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 6)
[junit4:junit4] 2> 22855 T688 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4] 2> 22856 T658 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4] 2> 22859 T645 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4] 2> 22860 T639 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4] 2> 22863 T617 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 22870 T719 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-jetty5-1358694813257\collection1
[junit4:junit4] 2> 22870 T719 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 22871 T719 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 22871 T719 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 22874 T719 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-jetty5-1358694813257\collection1\'
[junit4:junit4] 2> 22876 T719 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardRoutingTest-jetty5-1358694813257/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 22877 T719 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardRoutingTest-jetty5-1358694813257/collection1/lib/README' to classloader
[junit4:junit4] 2> 22936 T719 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_42
[junit4:junit4] 2> 23020 T719 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 23021 T719 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 23028 T719 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 23776 T719 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 23783 T719 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 23820 T719 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-jetty5-1358694813257\collection1\, dataDir=.\org.apache.solr.cloud.ShardRoutingTest-1358694790891/jetty5\
[junit4:junit4] 2> 23821 T719 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@184a49
[junit4:junit4] 2> 23821 T719 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 23825 T719 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-1358694790891\jetty5 forceNew:false
[junit4:junit4] 2> 23826 T719 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-1358694790891\jetty5
[junit4:junit4] 2> 23826 T719 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ShardRoutingTest-1358694790891/jetty5\index/
[junit4:junit4] 2> 23828 T719 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory '.\org.apache.solr.cloud.ShardRoutingTest-1358694790891\jetty5\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 23829 T719 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-1358694790891\jetty5\index forceNew:false
[junit4:junit4] 2> 23836 T640 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 23837 T640 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=4 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "numShards":"4",
[junit4:junit4] 2> "shard":"shard4",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:50305_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50305"}
[junit4:junit4] 2> 23842 T719 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=RateLimitedDirectoryWrapper(org.apache.lucene.store.SimpleFSDirectory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ShardRoutingTest-1358694790891\jetty5\index lockFactory=org.apache.lucene.store.NativeFSLockFactory@2c04e4),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 23843 T719 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 23845 T719 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-1358694790891\jetty5\index
[junit4:junit4] 2> 23846 T719 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4] 2> 23848 T719 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 23848 T719 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4] 2> 23849 T719 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 23849 T719 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4] 2> 23850 T719 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 23851 T719 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 23851 T719 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 23853 T718 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 6)
[junit4:junit4] 2> 23853 T673 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 6)
[junit4:junit4] 2> 23853 T719 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 23854 T658 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 6)
[junit4:junit4] 2> 23855 T688 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 6)
[junit4:junit4] 2> 23854 T719 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 23856 T719 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4] 2> 23857 T645 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 6)
[junit4:junit4] 2> 23859 T703 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 6)
[junit4:junit4] 2> 23857 T719 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4] 2> 23860 T719 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 23860 T719 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4] 2> 23861 T719 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4] 2> 23861 T719 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4] 2> 23862 T719 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 23862 T719 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 23864 T719 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 23860 T639 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 6)
[junit4:junit4] 2> 23864 T719 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 23865 T719 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 23866 T719 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 23867 T719 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 23867 T719 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 23868 T719 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 23869 T719 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4] 2> 23869 T719 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4] 2> 23888 T719 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 23897 T719 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4] 2> 23899 T719 oasc.SolrCore.initDeprecatedSupport WARNING adding ShowFileRequestHandler with hidden files: [SCHEMA.XML, OLD_SYNONYMS.TXT, STOPWORDS.TXT, PROTWORDS.TXT, OPEN-EXCHANGE-RATES.JSON, SYNONYMS.TXT, CURRENCY.XML, MAPPING-ISOLATIN1ACCENT.TXT]
[junit4:junit4] 2> 23904 T719 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-1358694790891\jetty5
[junit4:junit4] 2> 23906 T719 oass.SolrIndexSearcher.<init> Opening Searcher@116c0df main
[junit4:junit4] 2> 23908 T719 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 23908 T719 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 23908 T719 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4] 2> 23918 T719 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4] 2> 23979 T720 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@116c0df main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 23989 T719 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 23989 T719 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 25370 T640 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 25371 T640 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=4 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "numShards":"4",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:50314_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50314"}
[junit4:junit4] 2> 25371 T640 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=4
[junit4:junit4] 2> 25371 T640 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4] 2> 25390 T673 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 6)
[junit4:junit4] 2> 25390 T718 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 6)
[junit4:junit4] 2> 25392 T658 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 6)
[junit4:junit4] 2> 25392 T688 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 6)
[junit4:junit4] 2> 25391 T639 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 6)
[junit4:junit4] 2> 25391 T645 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 6)
[junit4:junit4] 2> 25391 T703 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 6)
[junit4:junit4] 2> 25994 T719 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 25994 T719 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:50314 collection:collection1 shard:shard1
[junit4:junit4] 2> 25998 T719 oasc.ZkController.register We are http://127.0.0.1:50314/collection1/ and leader is http://127.0.0.1:50278/collection1/
[junit4:junit4] 2> 25999 T719 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:50314
[junit4:junit4] 2> 25999 T719 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 25999 T719 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C43 name=collection1 org.apache.solr.core.SolrCore@f84fa7 url=http://127.0.0.1:50314/collection1 node=127.0.0.1:50314_ C43_STATE=coll:collection1 core:collection1 props:{shard=null, roles=null, state=down, core=collection1, collection=collection1, node_name=127.0.0.1:50314_, base_url=http://127.0.0.1:50314}
[junit4:junit4] 2> 26000 T721 C43 P50314 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 26001 T721 C43 P50314 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 26001 T719 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 26001 T721 C43 P50314 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 26002 T721 C43 P50314 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 26002 T617 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 26003 T617 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 26003 T617 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 26004 T721 C43 P50314 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 26376 T617 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 26382 T617 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50324
[junit4:junit4] 2> 26383 T617 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 26383 T617 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 26384 T617 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-jetty6-1358694816901
[junit4:junit4] 2> 26384 T617 oasc.CoreContainer$Initializer.initialize looking for solr.xml: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-jetty6-1358694816901\solr.xml
[junit4:junit4] 2> 26384 T617 oasc.CoreContainer.<init> New CoreContainer 10854362
[junit4:junit4] 2> 26384 T617 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-jetty6-1358694816901\'
[junit4:junit4] 2> 26385 T617 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-jetty6-1358694816901\'
[junit4:junit4] 2> 26435 T617 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 60000
[junit4:junit4] 2> 26436 T617 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 26437 T617 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 26437 T617 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 26437 T617 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 26438 T617 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 26439 T617 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 26439 T617 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 26440 T617 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 26441 T617 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=60000&connTimeout=15000&retry=false
[junit4:junit4] 2> 26456 T617 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 26482 T617 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:50259/solr
[junit4:junit4] 2> 26483 T617 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 26484 T617 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:50259 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@1666c1c
[junit4:junit4] 2> 26485 T617 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 26486 T731 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:50259. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 26487 T731 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:50259, initiating session
[junit4:junit4] 2> 26487 T619 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:50329
[junit4:junit4] 2> 26488 T619 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:50329
[junit4:junit4] 2> 26500 T621 oazs.ZooKeeperServer.finishSessionInit Established session 0x13c588536f6000f with negotiated timeout 20000 for client /127.0.0.1:50329
[junit4:junit4] 2> 26500 T731 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:50259, sessionid = 0x13c588536f6000f, negotiated timeout = 20000
[junit4:junit4] 2> 26501 T732 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1666c1c name:ZooKeeperConnection Watcher:127.0.0.1:50259 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 26502 T617 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 26505 T622 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13c588536f6000f
[junit4:junit4] 2> 26507 T617 oaz.ZooKeeper.close Session: 0x13c588536f6000f closed
[junit4:junit4] 2> 26508 T619 oazs.NIOServerCnxn.doIO WARNING caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x13c588536f6000f, likely client has closed socket
[junit4:junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
[junit4:junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4:junit4] 2> at java.lang.Thread.run(Thread.java:722)
[junit4:junit4] 2>
[junit4:junit4] 2> 26508 T732 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 26508 T619 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:50329 which had sessionid 0x13c588536f6000f
[junit4:junit4] 2> 26508 T617 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=60000&connTimeout=15000
[junit4:junit4] 2> 26516 T617 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:50259/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@1461f0e
[junit4:junit4] 2> 26519 T617 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 26520 T733 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:50259. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 26520 T733 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:50259, initiating session
[junit4:junit4] 2> 26521 T619 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:50332
[junit4:junit4] 2> 26521 T619 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:50332
[junit4:junit4] 2> 26523 T621 oazs.ZooKeeperServer.finishSessionInit Established session 0x13c588536f60010 with negotiated timeout 20000 for client /127.0.0.1:50332
[junit4:junit4] 2> 26523 T733 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:50259, sessionid = 0x13c588536f60010, negotiated timeout = 20000
[junit4:junit4] 2> 26523 T734 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1461f0e name:ZooKeeperConnection Watcher:127.0.0.1:50259/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 26524 T617 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 26526 T622 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c588536f60010 type:create cxid:0x1 zxid:0xe6 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 26528 T622 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c588536f60010 type:create cxid:0x2 zxid:0xe7 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 26531 T617 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50324_
[junit4:junit4] 2> 26532 T622 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c588536f60010 type:delete cxid:0x4 zxid:0xe8 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:50324_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:50324_
[junit4:junit4] 2> 26533 T617 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50324_
[junit4:junit4] 2> 26539 T688 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 6)
[junit4:junit4] 2> 26539 T658 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 6)
[junit4:junit4] 2> 26539 T645 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 6)
[junit4:junit4] 2> 26540 T639 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 6)
[junit4:junit4] 2> 26542 T718 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4] 2> 26542 T718 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 7)
[junit4:junit4] 2> 26543 T673 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4] 2> 26543 T673 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 7)
[junit4:junit4] 2> 26543 T703 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4] 2> 26544 T703 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 7)
[junit4:junit4] 2> 26547 T688 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4] 2> 26549 T658 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4] 2> 26548 T645 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4] 2> 26549 T639 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4] 2> 26553 T617 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 26563 T735 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-jetty6-1358694816901\collection1
[junit4:junit4] 2> 26563 T735 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 26564 T735 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 26564 T735 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 26567 T735 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-jetty6-1358694816901\collection1\'
[junit4:junit4] 2> 26570 T735 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardRoutingTest-jetty6-1358694816901/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 26570 T735 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardRoutingTest-jetty6-1358694816901/collection1/lib/README' to classloader
[junit4:junit4] 2> 26637 T735 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_42
[junit4:junit4] 2> 26728 T735 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 26729 T735 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 26736 T735 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 26904 T640 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 26905 T640 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=4 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "numShards":"4",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"recovering",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:50314_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50314"}
[junit4:junit4] 2> 26914 T673 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 7)
[junit4:junit4] 2> 26915 T703 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 7)
[junit4:junit4] 2> 26915 T645 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 7)
[junit4:junit4] 2> 26915 T718 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 7)
[junit4:junit4] 2> 26915 T639 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 7)
[junit4:junit4] 2> 26916 T734 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 7)
[junit4:junit4] 2> 26917 T688 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 7)
[junit4:junit4] 2> 26918 T658 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 7)
[junit4:junit4] 2> 27437 T735 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 27441 T735 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 27469 T735 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-jetty6-1358694816901\collection1\, dataDir=.\org.apache.
[...truncated too long message...]
[junit4:junit4] 2> !!!! WARNING: best effort to remove C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-1358694790891\jetty8 FAILED !!!!!
[junit4:junit4] 2> !!!! WARNING: best effort to remove C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-1358694790891 FAILED !!!!!
[junit4:junit4] 2> 46537 T617 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4:junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4:junit4] 2> 46539 T617 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4] 2> 169246 T770 oasc.CachingDirectoryFactory.close SEVERE Timeout waiting for all directory ref counts to be released
[junit4:junit4] 2> 169246 T770 oasc.SolrException.log SEVERE Error closing directory:java.lang.AssertionError: 1
[junit4:junit4] 2> at org.apache.solr.core.CachingDirectoryFactory.close(CachingDirectoryFactory.java:139)
[junit4:junit4] 2> at org.apache.solr.core.SolrCore.close(SolrCore.java:1011)
[junit4:junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:233)
[junit4:junit4] 2> at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:156)
[junit4:junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:100)
[junit4:junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4:junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:129)
[junit4:junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4:junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4:junit4] 2>
[junit4:junit4] 2> 169248 T770 oasc.CachingDirectoryFactory.close Closing directory when closing factory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-1358694790891\jetty8\index
[junit4:junit4] 2> 169248 T770 oasc.CachingDirectoryFactory.closeDirectory Closing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardRoutingTest-1358694790891\jetty8\index
[junit4:junit4] 2> 169248 T770 oascc.ZkStateReader$3.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 169248 T770 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 169250 T770 oascc.ZkStateReader$2.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 169250 T770 oasc.LeaderElector$1.process WARNING org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/election
[junit4:junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4:junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4:junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
[junit4:junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:236)
[junit4:junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:233)
[junit4:junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
[junit4:junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:233)
[junit4:junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:84)
[junit4:junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4:junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:129)
[junit4:junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4:junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4:junit4] 2>
[junit4:junit4] 2> 169251 T770 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 169892 T617 oas.SolrTestCaseJ4.endTrackingSearchers SEVERE ERROR: SolrIndexSearcher opens=82 closes=81
[junit4:junit4] 2> NOTE: test params are: codec=Lucene40, sim=RandomSimilarityProvider(queryNorm=true,coord=no): {}, locale=es_SV, timezone=America/Bahia_Banderas
[junit4:junit4] 2> NOTE: Windows 7 6.1 x86/Oracle Corporation 1.7.0_10 (32-bit)/cpus=2,threads=1,free=149374360,total=289406976
[junit4:junit4] 2> NOTE: All tests run in this JVM: [TestValueSourceCache, DateMathParserTest, XmlUpdateRequestHandlerTest, DefaultValueUpdateProcessorTest, TestFaceting, TestArbitraryIndexDir, StatsComponentTest, TestAnalyzedSuggestions, TestQuerySenderNoQuery, DOMUtilTest, CurrencyFieldTest, TestPostingsSolrHighlighter, TestLMJelinekMercerSimilarityFactory, FieldAnalysisRequestHandlerTest, StatelessScriptUpdateProcessorFactoryTest, TestAtomicUpdateErrorCases, ClusterStateUpdateTest, MultiTermTest, CoreAdminHandlerTest, TestConfig, CollectionsAPIDistributedZkTest, IndexSchemaTest, TestSuggestSpellingConverter, SearchHandlerTest, RequiredFieldsTest, TestSort, RecoveryZkTest, TestSystemIdResolver, TestSolrQueryParser, TestJmxMonitoredMap, BasicZkTest, ZkSolrClientTest, DocumentBuilderTest, ShardRoutingTest]
[junit4:junit4] 2> NOTE: reproduce with: ant test -Dtestcase=ShardRoutingTest -Dtests.seed=69E0283D754A2040 -Dtests.slow=true -Dtests.locale=es_SV -Dtests.timezone=America/Bahia_Banderas -Dtests.file.encoding=US-ASCII
[junit4:junit4] ERROR 0.00s | ShardRoutingTest (suite) <<<
[junit4:junit4] > Throwable #1: java.lang.AssertionError: ERROR: SolrIndexSearcher opens=82 closes=81
[junit4:junit4] > at __randomizedtesting.SeedInfo.seed([69E0283D754A2040]:0)
[junit4:junit4] > at org.junit.Assert.fail(Assert.java:93)
[junit4:junit4] > at org.apache.solr.SolrTestCaseJ4.endTrackingSearchers(SolrTestCaseJ4.java:246)
[junit4:junit4] > at org.apache.solr.SolrTestCaseJ4.afterClass(SolrTestCaseJ4.java:97)
[junit4:junit4] > at sun.reflect.GeneratedMethodAccessor22.invoke(Unknown Source)
[junit4:junit4] > at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4:junit4] > at java.lang.reflect.Method.invoke(Method.java:601)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:700)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
[junit4:junit4] > at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
[junit4:junit4] > at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4] > at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
[junit4:junit4] > at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4:junit4] > at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
[junit4:junit4] > at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
[junit4:junit4] > at java.lang.Thread.run(Thread.java:722)
[junit4:junit4] Completed in 169.99s, 1 test, 1 failure <<< FAILURES!
[...truncated 674 lines...]
BUILD FAILED
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:344: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:39: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build.xml:178: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\common-build.xml:428: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\lucene\common-build.xml:1176: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\lucene\common-build.xml:841: There were test failures: 248 suites, 1034 tests, 1 suite-level error, 14 ignored (9 assumptions)
Total time: 49 minutes 43 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Description set: Java: 32bit/jdk1.7.0_10 -client -XX:+UseG1GC
Email was triggered for: Failure
Sending email for trigger: Failure