You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2014/01/28 16:50:46 UTC
[JENKINS] Lucene-Solr-NightlyTests-trunk - Build # 504 - Still
Failing
Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-trunk/504/
1 tests failed.
REGRESSION: org.apache.solr.TestDistributedSearch.testDistribSearch
Error Message:
Captured an uncaught exception in thread: Thread[id=5749, name=Thread-3072, state=RUNNABLE, group=TGRP-TestDistributedSearch]
Stack Trace:
com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=5749, name=Thread-3072, state=RUNNABLE, group=TGRP-TestDistributedSearch]
at __randomizedtesting.SeedInfo.seed([C4FE0FE8C0397FBB:451881F0B7661F87]:0)
Caused by: java.lang.RuntimeException: org.apache.solr.client.solrj.SolrServerException: Timeout occured while waiting response from server at: http://127.0.0.1:58848
at __randomizedtesting.SeedInfo.seed([C4FE0FE8C0397FBB]:0)
at org.apache.solr.BaseDistributedSearchTestCase$5.run(BaseDistributedSearchTestCase.java:580)
Caused by: org.apache.solr.client.solrj.SolrServerException: Timeout occured while waiting response from server at: http://127.0.0.1:58848
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:503)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:199)
at org.apache.solr.client.solrj.request.QueryRequest.process(QueryRequest.java:90)
at org.apache.solr.client.solrj.SolrServer.query(SolrServer.java:301)
at org.apache.solr.BaseDistributedSearchTestCase$5.run(BaseDistributedSearchTestCase.java:575)
Caused by: java.net.SocketTimeoutException: Read timed out
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(SocketInputStream.java:150)
at java.net.SocketInputStream.read(SocketInputStream.java:121)
at org.apache.http.impl.io.AbstractSessionInputBuffer.fillBuffer(AbstractSessionInputBuffer.java:160)
at org.apache.http.impl.io.SocketInputBuffer.fillBuffer(SocketInputBuffer.java:84)
at org.apache.http.impl.io.AbstractSessionInputBuffer.readLine(AbstractSessionInputBuffer.java:273)
at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:140)
at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:57)
at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:260)
at org.apache.http.impl.AbstractHttpClientConnection.receiveResponseHeader(AbstractHttpClientConnection.java:283)
at org.apache.http.impl.conn.DefaultClientConnection.receiveResponseHeader(DefaultClientConnection.java:251)
at org.apache.http.impl.conn.ManagedClientConnectionImpl.receiveResponseHeader(ManagedClientConnectionImpl.java:197)
at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:271)
at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:123)
at org.apache.http.impl.client.DefaultRequestDirector.tryExecute(DefaultRequestDirector.java:682)
at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:486)
at org.apache.http.impl.client.AbstractHttpClient.doExecute(AbstractHttpClient.java:863)
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82)
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:106)
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:57)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:395)
... 4 more
Build Log:
[...truncated 10265 lines...]
[junit4] Suite: org.apache.solr.TestDistributedSearch
[junit4] 2> 816374 T5462 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4] 2> 816378 T5462 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> 816382 T5462 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 816386 T5462 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:58832
[junit4] 2> 816387 T5462 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 816388 T5462 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 816388 T5462 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr
[junit4] 2> 816388 T5462 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/'
[junit4] 2> 816426 T5462 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/solr.xml
[junit4] 2> 816520 T5462 oasc.CoreContainer.<init> New CoreContainer 968610347
[junit4] 2> 816521 T5462 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/]
[junit4] 2> 816523 T5462 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 816523 T5462 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 816523 T5462 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 816524 T5462 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 816524 T5462 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 816524 T5462 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 816525 T5462 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 816525 T5462 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 816526 T5462 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 816538 T5462 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 816539 T5462 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 816539 T5462 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 816545 T5472 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1
[junit4] 2> 816547 T5472 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/'
[junit4] 2> 816548 T5472 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/lib/classes/' to classloader
[junit4] 2> 816548 T5472 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/lib/README' to classloader
[junit4] 2> 816622 T5472 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 816711 T5472 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 816712 T5472 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 816722 T5472 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 817348 T5472 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 817360 T5472 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 817364 T5472 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 817376 T5472 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 817381 T5472 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 817385 T5472 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 817385 T5472 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 817386 T5472 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 817387 T5472 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 817387 T5472 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 817388 T5472 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 817388 T5472 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 817388 T5472 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/, dataDir=./org.apache.solr.TestDistributedSearch-1390921282461/control/data/
[junit4] 2> 817389 T5472 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6486d2c3
[junit4] 2> 817389 T5472 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.TestDistributedSearch-1390921282461/control/data
[junit4] 2> 817390 T5472 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.TestDistributedSearch-1390921282461/control/data/index/
[junit4] 2> 817390 T5472 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.TestDistributedSearch-1390921282461/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 817390 T5472 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.TestDistributedSearch-1390921282461/control/data/index
[junit4] 2> 817391 T5472 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=5, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5573319808339914]
[junit4] 2> 817392 T5472 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RateLimitedDirectoryWrapper(org.apache.lucene.store.RAMDirectory@62dbf367 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7d4e58d1))),segFN=segments_1,generation=1}
[junit4] 2> 817392 T5472 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 817393 T5472 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4] 2> 817396 T5472 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 817397 T5472 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 817397 T5472 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe-allfields"
[junit4] 2> 817397 T5472 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4] 2> 817397 T5472 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 817398 T5472 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 817398 T5472 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "uniq-fields"
[junit4] 2> 817398 T5472 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4] 2> 817399 T5472 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 817399 T5472 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 817399 T5472 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 817400 T5472 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 817400 T5472 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 817400 T5472 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 817401 T5472 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 817401 T5472 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 817402 T5472 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4] 2> 817403 T5472 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4] 2> 817403 T5472 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 817404 T5472 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 817404 T5472 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 817405 T5472 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4] 2> 817405 T5472 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4] 2> 817405 T5472 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4] 2> 817406 T5472 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 817406 T5472 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 817407 T5472 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 817408 T5472 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 817408 T5472 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 817409 T5472 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 817409 T5472 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 817410 T5472 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 817410 T5472 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 817411 T5472 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4] 2> 817412 T5472 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4] 2> 817428 T5472 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 817430 T5472 oasc.SolrCore.initDeprecatedSupport WARN solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4] 2> 817436 T5472 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 817436 T5472 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 817437 T5472 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=38, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=1.580078125, noCFSRatio=0.6563156596758443]
[junit4] 2> 817437 T5472 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RateLimitedDirectoryWrapper(org.apache.lucene.store.RAMDirectory@62dbf367 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7d4e58d1))),segFN=segments_1,generation=1}
[junit4] 2> 817438 T5472 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 817438 T5472 oass.SolrIndexSearcher.<init> Opening Searcher@7db39843 main
[junit4] 2> 817438 T5472 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4] 2> 817472 T5472 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4] 2> 817536 T5473 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7db39843 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 817543 T5472 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 817554 T5462 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1
[junit4] 2> 817554 T5462 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 817557 T5462 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 817561 T5462 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:58835
[junit4] 2> 817561 T5462 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 817562 T5462 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 817562 T5462 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr
[junit4] 2> 817563 T5462 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/'
[junit4] 2> 817600 T5462 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/solr.xml
[junit4] 2> 817693 T5462 oasc.CoreContainer.<init> New CoreContainer 1236910256
[junit4] 2> 817693 T5462 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/]
[junit4] 2> 817695 T5462 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 817695 T5462 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 817696 T5462 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 817696 T5462 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 817697 T5462 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 817697 T5462 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 817697 T5462 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 817698 T5462 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 817698 T5462 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 817711 T5462 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 817711 T5462 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 817712 T5462 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 817717 T5484 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1
[junit4] 2> 817719 T5484 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/'
[junit4] 2> 817720 T5484 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/lib/classes/' to classloader
[junit4] 2> 817720 T5484 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/lib/README' to classloader
[junit4] 2> 817793 T5484 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 817881 T5484 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 817882 T5484 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 817892 T5484 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 818503 T5484 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 818516 T5484 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 818519 T5484 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 818527 T5484 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 818530 T5484 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 818533 T5484 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 818533 T5484 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 818534 T5484 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 818534 T5484 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 818535 T5484 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 818535 T5484 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 818535 T5484 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 818535 T5484 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/, dataDir=./org.apache.solr.TestDistributedSearch-1390921282461/shard0/data/
[junit4] 2> 818536 T5484 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6486d2c3
[junit4] 2> 818536 T5484 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.TestDistributedSearch-1390921282461/shard0/data
[junit4] 2> 818537 T5484 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.TestDistributedSearch-1390921282461/shard0/data/index/
[junit4] 2> 818537 T5484 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.TestDistributedSearch-1390921282461/shard0/data/index' doesn't exist. Creating new index...
[junit4] 2> 818537 T5484 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.TestDistributedSearch-1390921282461/shard0/data/index
[junit4] 2> 818537 T5484 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=5, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5573319808339914]
[junit4] 2> 818538 T5484 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RateLimitedDirectoryWrapper(org.apache.lucene.store.RAMDirectory@7213a1e8 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@76768933))),segFN=segments_1,generation=1}
[junit4] 2> 818538 T5484 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 818538 T5484 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4] 2> 818542 T5484 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 818542 T5484 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 818542 T5484 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe-allfields"
[junit4] 2> 818542 T5484 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4] 2> 818542 T5484 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 818543 T5484 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 818543 T5484 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "uniq-fields"
[junit4] 2> 818543 T5484 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4] 2> 818543 T5484 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 818544 T5484 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 818544 T5484 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 818544 T5484 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 818544 T5484 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 818544 T5484 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 818545 T5484 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 818545 T5484 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 818546 T5484 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4] 2> 818547 T5484 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4] 2> 818547 T5484 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 818547 T5484 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 818548 T5484 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 818548 T5484 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4] 2> 818549 T5484 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4] 2> 818549 T5484 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4] 2> 818549 T5484 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 818559 T5484 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 818559 T5484 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 818560 T5484 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 818560 T5484 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 818561 T5484 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 818561 T5484 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 818561 T5484 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 818562 T5484 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 818562 T5484 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4] 2> 818563 T5484 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4] 2> 818574 T5484 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 818575 T5484 oasc.SolrCore.initDeprecatedSupport WARN solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4] 2> 818579 T5484 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 818579 T5484 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 818579 T5484 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=38, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=1.580078125, noCFSRatio=0.6563156596758443]
[junit4] 2> 818580 T5484 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RateLimitedDirectoryWrapper(org.apache.lucene.store.RAMDirectory@7213a1e8 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@76768933))),segFN=segments_1,generation=1}
[junit4] 2> 818580 T5484 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 818580 T5484 oass.SolrIndexSearcher.<init> Opening Searcher@256c96a4 main
[junit4] 2> 818581 T5484 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4] 2> 818588 T5484 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4] 2> 818645 T5485 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@256c96a4 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 818654 T5484 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 818655 T5462 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1
[junit4] 2> 818656 T5462 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> ASYNC NEW_CORE C2167 name=collection1 org.apache.solr.core.SolrCore@626e0cbf
[junit4] 2> 818659 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {deleteByQuery=*:* (-1458486677067530240)} 0 1
[junit4] 2> ASYNC NEW_CORE C2168 name=collection1 org.apache.solr.core.SolrCore@6e8fa3e
[junit4] 2> 818662 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {deleteByQuery=*:* (-1458486677070675968)} 0 1
[junit4] 2> 818670 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[1 (1458486677075918848)]} 0 4
[junit4] 2> 818678 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[1 (1458486677083258880)]} 0 5
[junit4] 2> 818683 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[2 (1458486677091647488)]} 0 2
[junit4] 2> 818689 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[2 (1458486677096890368)]} 0 3
[junit4] 2> 818693 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[3 (1458486677102133248)]} 0 2
[junit4] 2> 818697 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[3 (1458486677106327552)]} 0 2
[junit4] 2> 818702 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[4 (1458486677111570432)]} 0 2
[junit4] 2> 818707 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[4 (1458486677115764736)]} 0 3
[junit4] 2> 818713 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[5 (1458486677122056192)]} 0 3
[junit4] 2> 818718 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[5 (1458486677127299072)]} 0 3
[junit4] 2> 818722 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[6 (1458486677132541952)]} 0 2
[junit4] 2> 818727 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[6 (1458486677137784832)]} 0 2
[junit4] 2> 818732 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[7 (1458486677143027712)]} 0 2
[junit4] 2> 818737 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[7 (1458486677148270592)]} 0 2
[junit4] 2> 818742 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[8 (1458486677153513472)]} 0 2
[junit4] 2> 818747 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[8 (1458486677158756352)]} 0 2
[junit4] 2> 818750 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[9 (1458486677162950656)]} 0 1
[junit4] 2> 818754 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[9 (1458486677167144960)]} 0 1
[junit4] 2> 818757 T5465 C2167 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 818770 T5465 C2167 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RateLimitedDirectoryWrapper(org.apache.lucene.store.RAMDirectory@62dbf367 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7d4e58d1))),segFN=segments_1,generation=1}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RateLimitedDirectoryWrapper(org.apache.lucene.store.RAMDirectory@62dbf367 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7d4e58d1))),segFN=segments_2,generation=2}
[junit4] 2> 818772 T5465 C2167 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4] 2> 818773 T5465 C2167 oass.SolrIndexSearcher.<init> Opening Searcher@72206b16 main
[junit4] 2> 818774 T5465 C2167 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 818776 T5473 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@72206b16 main{StandardDirectoryReader(segments_2:3:nrt _0(5.0):C9)}
[junit4] 2> 818776 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&commit=true&version=2&softCommit=false&waitSearcher=true} {commit=} 0 19
[junit4] 2> 818779 T5477 C2168 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 818793 T5477 C2168 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RateLimitedDirectoryWrapper(org.apache.lucene.store.RAMDirectory@7213a1e8 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@76768933))),segFN=segments_1,generation=1}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RateLimitedDirectoryWrapper(org.apache.lucene.store.RAMDirectory@7213a1e8 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@76768933))),segFN=segments_2,generation=2}
[junit4] 2> 818794 T5477 C2168 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4] 2> 818796 T5477 C2168 oass.SolrIndexSearcher.<init> Opening Searcher@72305034 main
[junit4] 2> 818796 T5477 C2168 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 818798 T5485 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@72305034 main{StandardDirectoryReader(segments_2:3:nrt _0(5.0):C9)}
[junit4] 2> 818799 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&commit=true&version=2&softCommit=false&waitSearcher=true} {commit=} 0 20
[junit4] 2> 818805 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10 (1458486677218525184)]} 0 3
[junit4] 2> 818810 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10 (1458486677224816640)]} 0 2
[junit4] 2> 818814 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[11 (1458486677230059520)]} 0 1
[junit4] 2> 818818 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[11 (1458486677234253824)]} 0 1
[junit4] 2> 818822 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[12 (1458486677238448128)]} 0 1
[junit4] 2> 818826 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[12 (1458486677242642432)]} 0 1
[junit4] 2> 818830 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[13 (1458486677246836736)]} 0 1
[junit4] 2> 818834 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[13 (1458486677251031040)]} 0 1
[junit4] 2> 818839 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[1001 (1458486677255225344)]} 0 2
[junit4] 2> 818842 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[1001 (1458486677259419648)]} 0 1
[junit4] 2> 818846 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[14 (1458486677263613952)]} 0 1
[junit4] 2> 818850 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[14 (1458486677267808256)]} 0 1
[junit4] 2> 818855 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[15 (1458486677272002560)]} 0 2
[junit4] 2> 818858 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[15 (1458486677276196864)]} 0 1
[junit4] 2> 818862 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[16 (1458486677280391168)]} 0 1
[junit4] 2> 818866 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[16 (1458486677284585472)]} 0 1
[junit4] 2> 818873 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[17 (1458486677288779776)]} 0 4
[junit4] 2> 818880 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[17 (1458486677296119808)]} 0 4
[junit4] 2> 818884 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[100 (1458486677303459840)]} 0 1
[junit4] 2> 818888 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[100 (1458486677307654144)]} 0 1
[junit4] 2> 818893 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[101 (1458486677311848448)]} 0 2
[junit4] 2> 818897 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[101 (1458486677317091328)]} 0 1
[junit4] 2> 818902 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[102 (1458486677322334208)]} 0 1
[junit4] 2> 818907 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[102 (1458486677326528512)]} 0 2
[junit4] 2> 818911 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[103 (1458486677331771392)]} 0 1
[junit4] 2> 818915 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[103 (1458486677335965696)]} 0 1
[junit4] 2> 818919 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[104 (1458486677340160000)]} 0 1
[junit4] 2> 818923 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[104 (1458486677343305728)]} 0 2
[junit4] 2> 818927 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[105 (1458486677348548608)]} 0 1
[junit4] 2> 818931 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[105 (1458486677352742912)]} 0 1
[junit4] 2> 818935 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[106 (1458486677355888640)]} 0 2
[junit4] 2> 818940 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[106 (1458486677361131520)]} 0 2
[junit4] 2> 818944 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[107 (1458486677366374400)]} 0 1
[junit4] 2> 818948 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[107 (1458486677370568704)]} 0 1
[junit4] 2> 818953 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[108 (1458486677374763008)]} 0 2
[junit4] 2> 818957 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[108 (1458486677380005888)]} 0 1
[junit4] 2> 818961 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[109 (1458486677384200192)]} 0 1
[junit4] 2> 818965 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[109 (1458486677387345920)]} 0 2
[junit4] 2> 818969 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[110 (1458486677392588800)]} 0 1
[junit4] 2> 818974 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[110 (1458486677396783104)]} 0 2
[junit4] 2> 818979 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[111 (1458486677402025984)]} 0 2
[junit4] 2> 818983 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[111 (1458486677406220288)]} 0 2
[junit4] 2> 818986 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[112 (1458486677410414592)]} 0 1
[junit4] 2> 818990 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[112 (1458486677414608896)]} 0 1
[junit4] 2> 818994 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[113 (1458486677418803200)]} 0 1
[junit4] 2> 818998 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[113 (1458486677421948928)]} 0 2
[junit4] 2> 819002 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[114 (1458486677427191808)]} 0 1
[junit4] 2> 819006 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[114 (1458486677431386112)]} 0 1
[junit4] 2> 819011 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[115 (1458486677435580416)]} 0 2
[junit4] 2> 819014 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[115 (1458486677439774720)]} 0 1
[junit4] 2> 819019 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[116 (1458486677443969024)]} 0 2
[junit4] 2> 819022 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[116 (1458486677447114752)]} 0 2
[junit4] 2> 819026 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[117 (1458486677451309056)]} 0 2
[junit4] 2> 819030 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[117 (1458486677455503360)]} 0 2
[junit4] 2> 819035 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[118 (1458486677460746240)]} 0 2
[junit4] 2> 819039 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[118 (1458486677464940544)]} 0 2
[junit4] 2> 819043 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[119 (1458486677469134848)]} 0 2
[junit4] 2> 819046 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[119 (1458486677473329152)]} 0 1
[junit4] 2> 819051 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[120 (1458486677477523456)]} 0 2
[junit4] 2> 819054 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[120 (1458486677481717760)]} 0 1
[junit4] 2> 819058 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[121 (1458486677485912064)]} 0 1
[junit4] 2> 819063 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[121 (1458486677490106368)]} 0 2
[junit4] 2> 819067 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[122 (1458486677495349248)]} 0 1
[junit4] 2> 819071 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[122 (1458486677499543552)]} 0 1
[junit4] 2> 819075 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[123 (1458486677503737856)]} 0 1
[junit4] 2> 819079 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[123 (1458486677507932160)]} 0 1
[junit4] 2> 819084 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[124 (1458486677512126464)]} 0 2
[junit4] 2> 819088 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[124 (1458486677517369344)]} 0 1
[junit4] 2> 819092 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[125 (1458486677521563648)]} 0 1
[junit4] 2> 819096 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[125 (1458486677525757952)]} 0 1
[junit4] 2> 819100 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[126 (1458486677529952256)]} 0 1
[junit4] 2> 819104 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[126 (1458486677533097984)]} 0 2
[junit4] 2> 819108 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[127 (1458486677538340864)]} 0 1
[junit4] 2> 819112 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[127 (1458486677542535168)]} 0 1
[junit4] 2> 819117 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[128 (1458486677546729472)]} 0 2
[junit4] 2> 819121 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[128 (1458486677551972352)]} 0 1
[junit4] 2> 819125 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[129 (1458486677556166656)]} 0 1
[junit4] 2> 819129 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[129 (1458486677560360960)]} 0 1
[junit4] 2> 819134 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[130 (1458486677564555264)]} 0 2
[junit4] 2> 819138 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[130 (1458486677569798144)]} 0 1
[junit4] 2> 819142 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[131 (1458486677573992448)]} 0 1
[junit4] 2> 819147 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[131 (1458486677578186752)]} 0 2
[junit4] 2> 819151 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[132 (1458486677583429632)]} 0 1
[junit4] 2> 819156 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[132 (1458486677587623936)]} 0 2
[junit4] 2> 819160 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[133 (1458486677592866816)]} 0 1
[junit4] 2> 819164 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[133 (1458486677596012544)]} 0 2
[junit4] 2> 819168 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[134 (1458486677601255424)]} 0 1
[junit4] 2> 819172 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[134 (1458486677604401152)]} 0 2
[junit4] 2> 819175 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[135 (1458486677608595456)]} 0 1
[junit4] 2> 819178 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[135 (1458486677611741184)]} 0 1
[junit4] 2> 819182 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[136 (1458486677615935488)]} 0 1
[junit4] 2> 819185 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[136 (1458486677619081216)]} 0 1
[junit4] 2> 819189 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[137 (1458486677623275520)]} 0 1
[junit4] 2> 819193 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[137 (1458486677627469824)]} 0 1
[junit4] 2> 819198 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[138 (1458486677631664128)]} 0 2
[junit4] 2> 819202 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[138 (1458486677635858432)]} 0 2
[junit4] 2> 819206 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[139 (1458486677640052736)]} 0 2
[junit4] 2> 819210 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[139 (1458486677644247040)]} 0 2
[junit4] 2> 819214 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[140 (1458486677648441344)]} 0 2
[junit4] 2> 819217 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[140 (1458486677652635648)]} 0 1
[junit4] 2> 819222 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[141 (1458486677656829952)]} 0 2
[junit4] 2> 819225 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[141 (1458486677661024256)]} 0 1
[junit4] 2> 819230 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[142 (1458486677665218560)]} 0 2
[junit4] 2> 819233 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[142 (1458486677669412864)]} 0 1
[junit4] 2> 819238 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[143 (1458486677673607168)]} 0 2
[junit4] 2> 819241 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[143 (1458486677677801472)]} 0 1
[junit4] 2> 819245 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[144 (1458486677680947200)]} 0 2
[junit4] 2> 819248 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[144 (1458486677685141504)]} 0 1
[junit4] 2> 819252 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[145 (1458486677688287232)]} 0 2
[junit4] 2> 819255 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[145 (1458486677692481536)]} 0 1
[junit4] 2> 819259 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[146 (1458486677695627264)]} 0 2
[junit4] 2> 819262 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[146 (1458486677699821568)]} 0 1
[junit4] 2> 819266 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[147 (1458486677702967296)]} 0 2
[junit4] 2> 819269 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[147 (1458486677707161600)]} 0 1
[junit4] 2> 819273 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[148 (1458486677711355904)]} 0 1
[junit4] 2> 819277 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[148 (1458486677715550208)]} 0 1
[junit4] 2> 819281 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[149 (1458486677719744512)]} 0 1
[junit4] 2> 819284 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[149 (1458486677722890240)]} 0 1
[junit4] 2> 819286 T5465 C2167 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 819311 T5465 C2167 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RateLimitedDirectoryWrapper(org.apache.lucene.store.RAMDirectory@62dbf367 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7d4e58d1))),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RateLimitedDirectoryWrapper(org.apache.lucene.store.RAMDirectory@62dbf367 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7d4e58d1))),segFN=segments_3,generation=3}
[junit4] 2> 819311 T5465 C2167 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4] 2> 819313 T5465 C2167 oass.SolrIndexSearcher.<init> Opening Searcher@3b80afa0 main
[junit4] 2> 819314 T5465 C2167 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 819316 T5473 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3b80afa0 main{StandardDirectoryReader(segments_3:5:nrt _0(5.0):C9 _1(5.0):C59)}
[junit4] 2> 819316 T5465 C2167 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&commit=true&version=2&softCommit=false&waitSearcher=true} {commit=} 0 30
[junit4] 2> 819319 T5477 C2168 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 819343 T5477 C2168 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RateLimitedDirectoryWrapper(org.apache.lucene.store.RAMDirectory@7213a1e8 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@76768933))),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RateLimitedDirectoryWrapper(org.apache.lucene.store.RAMDirectory@7213a1e8 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@76768933))),segFN=segments_3,generation=3}
[junit4] 2> 819343 T5477 C2168 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4] 2> 819345 T5477 C2168 oass.SolrIndexSearcher.<init> Opening Searcher@42c85801 main
[junit4] 2> 819346 T5477 C2168 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 819347 T5485 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@42c85801 main{StandardDirectoryReader(segments_3:5:nrt _0(5.0):C9 _1(5.0):C59)}
[junit4] 2> 819348 T5477 C2168 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&commit=true&version=2&softCommit=false&waitSearcher=true} {commit=} 0 29
[junit4] 2> 819371 T5465 C2167 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&distrib=false&sort=n_ti1+desc&version=2&q=*:*} hits=68 status=0 QTime=20
[junit4] 2> 819482 T5478 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&isShard=true&rows=10&distrib=false&fl=id&start=0&sort=n_ti1+desc&version=2&shard.url=[ff01::083]:33332/|127.0.0.1:58835/&fsv=true&q=*:*&NOW=1390921285457} hits=68 status=0 QTime=29
[junit4] 2> 819502 T5478 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&isShard=true&distrib=false&version=2&shard.url=[ff01::083]:33332/|127.0.0.1:58835/&ids=145,129,112,109,132,110,120,123,1001,103&q=*:*&NOW=1390921285457} status=0 QTime=3
[junit4] 2> 819505 T5477 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&sort=n_ti1+desc&version=2&shards=[ff01::083]:33332/|127.0.0.1:58835/&q=*:*} hits=68 status=0 QTime=130
[junit4] 2> 819506 T5462 oas.BaseDistributedSearchTestCase.query starting stress...
[junit4] 2> 819512 T5478 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&isShard=true&rows=10&distrib=false&fl=id&start=0&sort=n_ti1+desc&version=2&shard.url=[ff01::083]:33332/|127.0.0.1:58835/&fsv=true&q=*:*&NOW=1390921285591} hits=68 status=0 QTime=0
[junit4] 2> 819512 T5482 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&isShard=true&rows=10&distrib=false&fl=id&start=0&sort=n_ti1+desc&version=2&shard.url=[ff01::083]:33332/|127.0.0.1:58835/&fsv=true&q=*:*&NOW=1390921285592} hits=68 status=0 QTime=0
[junit4] 2> 819512 T5481 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&isShard=true&rows=10&distrib=false&fl=id&start=0&sort=n_ti1+desc&version=2&shard.url=[ff01::083]:33332/|127.0.0.1:58835/&fsv=true&q=*:*&NOW=1390921285592} hits=68 status=0 QTime=0
[junit4] 2> 819516 T5482 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&isShard=true&distrib=false&version=2&shard.url=[ff01::083]:33332/|127.0.0.1:58835/&ids=145,129,112,109,132,110,120,123,1001,103&q=*:*&NOW=1390921285591} status=0 QTime=1
[junit4] 2> 819517 T5478 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&isShard=true&distrib=false&version=2&shard.url=[ff01::083]:33332/|127.0.0.1:58835/&ids=145,129,112,109,132,110,120,123,1001,103&q=*:*&NOW=1390921285592} status=0 QTime=1
[junit4] 2> 819517 T5481 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&isShard=true&distrib=false&version=2&shard.url=[ff01::083]:33332/|127.0.0.1:58835/&ids=145,129,112,109,132,110,120,123,1001,103&q=*:*&NOW=1390921285592} status=0 QTime=1
[junit4] 2> 819517 T5479 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&sort=n_ti1+desc&version=2&shards=[ff01::083]:33332/|127.0.0.1:58835/&q=*:*} hits=68 status=0 QTime=8
[junit4] 2> 819518 T5480 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&sort=n_ti1+desc&version=2&shards=[ff01::083]:33332/|127.0.0.1:58835/&q=*:*} hits=68 status=0 QTime=8
[junit4] 2> 819519 T5477 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&sort=n_ti1+desc&version=2&shards=[ff01::083]:33332/|127.0.0.1:58835/&q=*:*} hits=68 status=0 QTime=9
[junit4] 2> 819523 T5481 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&isShard=true&rows=10&distrib=false&fl=id&start=0&sort=n_ti1+desc&version=2&shard.url=[ff01::083]:33332/|127.0.0.1:58835/&fsv=true&q=*:*&NOW=1390921285603} hits=68 status=0 QTime=0
[junit4] 2> 819524 T5478 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&isShard=true&rows=10&distrib=false&fl=id&start=0&sort=n_ti1+desc&version=2&shard.url=[ff01::083]:33332/|127.0.0.1:58835/&fsv=true&q=*:*&NOW=1390921285603} hits=68 status=0 QTime=0
[junit4] 2> 819524 T5482 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&isShard=true&rows=10&distrib=false&fl=id&start=0&sort=n_ti1+desc&version=2&shard.url=[ff01::083]:33332/|127.0.0.1:58835/&fsv=true&q=*:*&NOW=1390921285604} hits=68 status=0 QTime=0
[junit4] 2> 819527 T5481 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&isShard=true&distrib=false&version=2&shard.url=[ff01::083]:33332/|127.0.0.1:58835/&ids=145,129,112,109,132,110,120,123,1001,103&q=*:*&NOW=1390921285603} status=0 QTime=1
[junit4] 2> 819528 T5482 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&isShard=true&distrib=false&version=2&shard.url=[ff01::083]:33332/|127.0.0.1:58835/&ids=145,129,112,109,132,110,120,123,1001,103&q=*:*&NOW=1390921285603} status=0 QTime=1
[junit4] 2> 819528 T5478 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&isShard=true&distrib=false&version=2&shard.url=[ff01::083]:33332/|127.0.0.1:58835/&ids=145,129,112,109,132,110,120,123,1001,103&q=*:*&NOW=1390921285604} status=0 QTime=1
[junit4] 2> 819528 T5479 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&sort=n_ti1+desc&version=2&shards=[ff01::083]:33332/|127.0.0.1:58835/&q=*:*} hits=68 status=0 QTime=7
[junit4] 2> 819529 T5480 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&sort=n_ti1+desc&version=2&shards=[ff01::083]:33332/|127.0.0.1:58835/&q=*:*} hits=68 status=0 QTime=8
[junit4] 2> 819530 T5477 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&sort=n_ti1+desc&version=2&shards=[ff01::083]:33332/|127.0.0.1:58835/&q=*:*} hits=68 status=0 QTime=8
[junit4] 2> 819533 T5465 C2167 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&distrib=false&sort=n_ti1+asc&version=2&q=*:*} hits=68 status=0 QTime=0
[junit4] 2> 819540 T5478 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&isShard=true&rows=10&distrib=false&fl=id&start=0&sort=n_ti1+asc&version=2&shard.url=[ff01::083]:33332/|[ff01::114]:33332/|127.0.0.1:58835/&fsv=true&q=*:*&NOW=1390921285620} hits=68 status=0 QTime=0
[junit4] 2> 819545 T5478 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&isShard=true&distrib=false&version=2&shard.url=[ff01::083]:33332/|[ff01::114]:33332/|127.0.0.1:58835/&ids=121,136,13,133,142,128,107,137,141,113&q=*:*&NOW=1390921285620} status=0 QTime=1
[junit4] 2> 819549 T5477 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&sort=n_ti1+asc&version=2&shards=[ff01::083]:33332/|[ff01::114]:33332/|127.0.0.1:58835/&q=*:*} hits=68 status=0 QTime=11
[junit4] 2> 819550 T5462 oas.BaseDistributedSearchTestCase.query starting stress...
[junit4] 2> 819556 T5482 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&isShard=true&rows=10&distrib=false&fl=id&start=0&sort=n_ti1+asc&version=2&shard.url=[ff01::083]:33332/|[ff01::114]:33332/|127.0.0.1:58835/&fsv=true&q=*:*&NOW=1390921285635} hits=68 status=0 QTime=0
[junit4] 2> 819556 T5478 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&isShard=true&rows=10&distrib=false&fl=id&start=0&sort=n_ti1+asc&version=2&shard.url=[ff01::083]:33332/|[ff01::114]:33332/|127.0.0.1:58835/&fsv=true&q=*:*&NOW=1390921285635} hits=68 status=0 QTime=0
[junit4] 2> 819556 T5481 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&isShard=true&rows=10&distrib=false&fl=id&start=0&sort=n_ti1+asc&version=2&shard.url=[ff01::083]:33332/|[ff01::114]:33332/|127.0.0.1:58835/&fsv=true&q=*:*&NOW=1390921285635} hits=68 status=0 QTime=0
[junit4] 2> 819560 T5478 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&isShard=true&distrib=false&version=2&shard.url=[ff01::083]:33332/|[ff01::114]:33332/|127.0.0.1:58835/&ids=121,136,13,133,142,128,107,137,141,113&q=*:*&NOW=1390921285635} status=0 QTime=1
[junit4] 2> 819561 T5482 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&isShard=true&distrib=false&version=2&shard.url=[ff01::083]:33332/|[ff01::114]:33332/|127.0.0.1:58835/&ids=121,136,13,133,142,128,107,137,141,113&q=*:*&NOW=1390921285635} status=0 QTime=1
[junit4] 2> 819561 T5480 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&sort=n_ti1+asc&version=2&shards=[ff01::083]:33332/|[ff01::114]:33332/|127.0.0.1:58835/&q=*:*} hits=68 status=0 QTime=8
[junit4] 2> 819561 T5481 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&isShard=true&distrib=false&version=2&shard.url=[ff01::083]:33332/|[ff01::114]:33332/|127.0.0.1:58835/&ids=121,136,13,133,142,128,107,137,141,113&q=*:*&NOW=1390921285635} status=0 QTime=1
[junit4] 2> 819563 T5479 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&sort=n_ti1+asc&version=2&shards=[ff01::083]:33332/|[ff01::114]:33332/|127.0.0.1:58835/&q=*:*} hits=68 status=0 QTime=10
[junit4] 2> 819563 T5477 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&sort=n_ti1+asc&version=2&shards=[ff01::083]:33332/|[ff01::114]:33332/|127.0.0.1:58835/&q=*:*} hits=68 status=0 QTime=10
[junit4] 2> 819569 T5481 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&isShard=true&rows=10&distrib=false&fl=id&start=0&sort=n_ti1+asc&version=2&shard.url=[ff01::083]:33332/|[ff01::114]:33332/|127.0.0.1:58835/&fsv=true&q=*:*&NOW=1390921285649} hits=68 status=0 QTime=0
[junit4] 2> 819570 T5482 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&isShard=true&rows=10&distrib=false&fl=id&start=0&sort=n_ti1+asc&version=2&shard.url=[ff01::083]:33332/|[ff01::114]:33332/|127.0.0.1:58835/&fsv=true&q=*:*&NOW=1390921285647} hits=68 status=0 QTime=0
[junit4] 2> 819571 T5478 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&isShard=true&rows=10&distrib=false&fl=id&start=0&sort=n_ti1+asc&version=2&shard.url=[ff01::083]:33332/|[ff01::114]:33332/|127.0.0.1:58835/&fsv=true&q=*:*&NOW=1390921285648} hits=68 status=0 QTime=0
[junit4] 2> 819573 T5481 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&isShard=true&distrib=false&version=2&shard.url=[ff01::083]:33332/|[ff01::114]:33332/|127.0.0.1:58835/&ids=121,136,13,133,142,128,107,137,141,113&q=*:*&NOW=1390921285649} status=0 QTime=1
[junit4] 2> 819574 T5482 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&isShard=true&distrib=false&version=2&shard.url=[ff01::083]:33332/|[ff01::114]:33332/|127.0.0.1:58835/&ids=121,136,13,133,142,128,107,137,141,113&q=*:*&NOW=1390921285647} status=0 QTime=1
[junit4] 2> 819574 T5477 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&sort=n_ti1+asc&version=2&shards=[ff01::083]:33332/|[ff01::114]:33332/|127.0.0.1:58835/&q=*:*} hits=68 status=0 QTime=7
[junit4] 2> 819575 T5478 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&isShard=true&distrib=false&version=2&shard.url=[ff01::083]:33332/|[ff01::114]:33332/|127.0.0.1:58835/&ids=121,136,13,133,142,128,107,137,141,113&q=*:*&NOW=1390921285648} status=0 QTime=1
[junit4] 2> 819575 T5480 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&sort=n_ti1+asc&version=2&shards=[ff01::083]:33332/|[ff01::114]:33332/|127.0.0.1:58835/&q=*:*} hits=68 status=0 QTime=10
[junit4] 2> 819577 T5479 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&sort=n_ti1+asc&version=2&shards=[ff01::083]:33332/|[ff01::114]:33332/|127.0.0.1:58835/&q=*:*} hits=68 status=0 QTime=11
[junit4] 2> 819581 T5465 C2167 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&distrib=false&sort=n_f1+desc&version=2&q=*:*} hits=68 status=0 QTime=1
[junit4] 2> 819592 T5478 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&isShard=true&rows=10&distrib=false&fl=id&start=0&sort=n_f1+desc&version=2&shard.url=[ff01::114]:33332/|[ff01::083]:33332/|[ff01::213]:33332/|127.0.0.1:58835/&fsv=true&q=*:*&NOW=1390921285668} hits=68 status=0 QTime=1
[junit4] 2> 819597 T5478 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&isShard=true&distrib=false&version=2&shard.url=[ff01::114]:33332/|[ff01::083]:33332/|[ff01::213]:33332/|127.0.0.1:58835/&ids=146,3,135,105,129,109,136,15,100,113&q=*:*&NOW=1390921285668} status=0 QTime=1
[junit4] 2> 819599 T5479 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&sort=n_f1+desc&version=2&shards=[ff01::114]:33332/|[ff01::083]:33332/|[ff01::213]:33332/|127.0.0.1:58835/&q=*:*} hits=68 status=0 QTime=13
[junit4] 2> 819600 T5462 oas.BaseDistributedSearchTestCase.query starting stress...
[junit4] 2> 819607 T5482 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&isShard=true&rows=10&distrib=false&fl=id&start=0&sort=n_f1+desc&version=2&shard.url=[ff01::114]:33332/|[ff01::083]:33332/|[ff01::213]:33332/|127.0.0.1:58835/&fsv=true&q=*:*&NOW=1390921285686} hits=68 status=0 QTime=0
[junit4] 2> 819607 T5478 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&isShard=true&rows=10&distrib=false&fl=id&start=0&sort=n_f1+desc&version=2&shard.url=[ff01::114]:33332/|[ff01::083]:33332/|[ff01::213]:33332/|127.0.0.1:58835/&fsv=true&q=*:*&NOW=1390921285686} hits=68 status=0 QTime=0
[junit4] 2> 819607 T5481 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&isShard=true&rows=10&distrib=false&fl=id&start=0&sort=n_f1+desc&version=2&shard.url=[ff01::114]:33332/|[ff01::083]:33332/|[ff01::213]:33332/|127.0.0.1:58835/&fsv=true&q=*:*&NOW=1390921285686} hits=68 status=0 QTime=0
[junit4] 2> 819612 T5481 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&isShard=true&distrib=false&version=2&shard.url=[ff01::114]:33332/|[ff01::083]:33332/|[ff01::213]:33332/|127.0.0.1:58835/&ids=146,3,135,105,129,109,136,15,100,113&q=*:*&NOW=1390921285686} status=0 QTime=1
[junit4] 2> 819612 T5478 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&isShard=true&distrib=false&version=2&shard.url=[ff01::114]:33332/|[ff01::083]:33332/|[ff01::213]:33332/|127.0.0.1:58835/&ids=146,3,135,105,129,109,136,15,100,113&q=*:*&NOW=1390921285686} status=0 QTime=1
[junit4] 2> 819612 T5482 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&isShard=true&distrib=false&version=2&shard.url=[ff01::114]:33332/|[ff01::083]:33332/|[ff01::213]:33332/|127.0.0.1:58835/&ids=146,3,135,105,129,109,136,15,100,113&q=*:*&NOW=1390921285686} status=0 QTime=1
[junit4] 2> 819613 T5479 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&sort=n_f1+desc&version=2&shards=[ff01::114]:33332/|[ff01::083]:33332/|[ff01::213]:33332/|127.0.0.1:58835/&q=*:*} hits=68 status=0 QTime=9
[junit4] 2> 819614 T5477 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&sort=n_f1+desc&version=2&shards=[ff01::114]:33332/|[ff01::083]:33332/|[ff01::213]:33332/|127.0.0.1:58835/&q=*:*} hits=68 status=0 QTime=10
[junit4] 2> 819614 T5480 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&sort=n_f1+desc&version=2&shards=[ff01::114]:33332/|[ff01::083]:33332/|[ff01::213]:33332/|127.0.0.1:58835/&q=*:*} hits=68 status=0 QTime=10
[junit4] 2> 819620 T5482 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&isShard=true&rows=10&distrib=false&fl=id&start=0&sort=n_f1+desc&version=2&shard.url=[ff01::114]:33332/|[ff01::083]:33332/|[ff01::213]:33332/|127.0.0.1:58835/&fsv=true&q=*:*&NOW=1390921285699} hits=68 status=0 QTime=0
[junit4] 2> 819620 T5481 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&isShard=true&rows=10&distrib=false&fl=id&start=0&sort=n_f1+desc&version=2&shard.url=[ff01::114]:33332/|[ff01::083]:33332/|[ff01::213]:33332/|127.0.0.1:58835/&fsv=true&q=*:*&NOW=1390921285699} hits=68 status=0 QTime=0
[junit4] 2> 819620 T5478 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&isShard=true&rows=10&distrib=false&fl=id&start=0&sort=n_f1+desc&version=2&shard.url=[ff01::114]:33332/|[ff01::083]:33332/|[ff01::213]:33332/|127.0.0.1:58835/&fsv=true&q=*:*&NOW=1390921285699} hits=68 status=0 QTime=0
[junit4] 2> 819623 T5481 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&isShard=true&distrib=false&version=2&shard.url=[ff01::114]:33332/|[ff01::083]:33332/|[ff01::213]:33332/|127.0.0.1:58835/&ids=146,3,135,105,129,109,136,15,100,113&q=*:*&NOW=1390921285699} status=0 QTime=0
[junit4] 2> 819625 T5482 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&isShard=true&distrib=false&version=2&shard.url=[ff01::114]:33332/|[ff01::083]:33332/|[ff01::213]:33332/|127.0.0.1:58835/&ids=146,3,135,105,129,109,136,15,100,113&q=*:*&NOW=1390921285699} status=0 QTime=1
[junit4] 2> 819625 T5479 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&sort=n_f1+desc&version=2&shards=[ff01::114]:33332/|[ff01::083]:33332/|[ff01::213]:33332/|127.0.0.1:58835/&q=*:*} hits=68 status=0 QTime=8
[junit4] 2> 819625 T5478 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&isShard=true&distrib=false&version=2&shard.url=[ff01::114]:33332/|[ff01::083]:33332/|[ff01::213]:33332/|127.0.0.1:58835/&ids=146,3,135,105,129,109,136,15,100,113&q=*:*&NOW=1390921285699} status=0 QTime=1
[junit4] 2> 819626 T5477 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&sort=n_f1+desc&version=2&shards=[ff01::114]:33332/|[ff01::083]:33332/|[ff01::213]:33332/|127.0.0.1:58835/&q=*:*} hits=68 status=0 QTime=9
[junit4] 2> 819627 T5480 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&sort=n_f1+desc&version=2&shards=[ff01::114]:33332/|[ff01::083]:33332/|[ff01::213]:33332/|127.0.0.1:58835/&q=*:*} hits=68 status=0 QTime=10
[junit4] 2> 819630 T5465 C2167 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&distrib=false&sort=n_f1+asc&version=2&q=*:*} hits=68 status=0 QTime=0
[junit4] 2> 819637 T5478 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&isShard=true&rows=10&distrib=false&fl=id&start=0&sort=n_f1+asc&version=2&shard.url=127.0.0.1:58835/|[ff01::083]:33332/&fsv=true&q=*:*&NOW=1390921285716} hits=68 status=0 QTime=0
[junit4] 2> 819641 T5478 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&isShard=true&distrib=false&version=2&shard.url=127.0.0.1:58835/|[ff01::083]:33332/&ids=125,116,130,12,134,143,123,139,137,11&q=*:*&NOW=1390921285716} status=0 QTime=0
[junit4] 2> 819644 T5480 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&sort=n_f1+asc&version=2&shards=127.0.0.1:58835/|[ff01::083]:33332/&q=*:*} hits=68 status=0 QTime=10
[junit4] 2> 819645 T5462 oas.BaseDistributedSearchTestCase.query starting stress...
[junit4] 2> 819651 T5482 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&isShard=true&rows=10&distrib=false&fl=id&start=0&sort=n_f1+asc&version=2&shard.url=127.0.0.1:58835/|[ff01::083]:33332/&fsv=true&q=*:*&NOW=1390921285730} hits=68 status=0 QTime=0
[junit4] 2> 819651 T5481 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&isShard=true&rows=10&distrib=false&fl=id&start=0&sort=n_f1+asc&version=2&shard.url=127.0.0.1:58835/|[ff01::083]:33332/&fsv=true&q=*:*&NOW=1390921285730} hits=68 status=0 QTime=0
[junit4] 2> 819651 T5478 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&isShard=true&rows=10&distrib=false&fl=id&start=0&sort=n_f1+asc&version=2&shard.url=127.0.0.1:58835/|[ff01::083]:33332/&fsv=true&q=*:*&NOW=1390921285730} hits=68 status=0 QTime=0
[junit4] 2> 819654 T5481 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&isShard=true&distrib=false&version=2&shard.url=127.0.0.1:58835/|[ff01::083]:33332/&ids=125,116,130,12,134,143,123,139,137,11&q=*:*&NOW=1390921285730} status=0 QTime=0
[junit4] 2> 819655 T5482 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&isShard=true&distrib=false&version=2&shard.url=127.0.0.1:58835/|[ff01::083]:33332/&ids=125,116,130,12,134,143,123,139,137,11&q=*:*&NOW=1390921285730} status=0 QTime=0
[junit4] 2> 819656 T5477 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&sort=n_f1+asc&version=2&shards=127.0.0.1:58835/|[ff01::083]:33332/&q=*:*} hits=68 status=0 QTime=8
[junit4] 2> 819656 T5478 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&isShard=true&distrib=false&version=2&shard.url=127.0.0.1:58835/|[ff01::083]:33332/&ids=125,116,130,12,134,143,123,139,137,11&q=*:*&NOW=1390921285730} status=0 QTime=1
[junit4] 2> 819657 T5480 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&sort=n_f1+asc&version=2&shards=127.0.0.1:58835/|[ff01::083]:33332/&q=*:*} hits=68 status=0 QTime=9
[junit4] 2> 819657 T5479 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&sort=n_f1+asc&version=2&shards=127.0.0.1:58835/|[ff01::083]:33332/&q=*:*} hits=68 status=0 QTime=9
[junit4] 2> 819662 T5482 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&isShard=true&rows=10&distrib=false&fl=id&start=0&sort=n_f1+asc&version=2&shard.url=127.0.0.1:58835/|[ff01::083]:33332/&fsv=true&q=*:*&NOW=1390921285742} hits=68 status=0 QTime=0
[junit4] 2> 819662 T5478 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&isShard=true&rows=10&distrib=false&fl=id&start=0&sort=n_f1+asc&version=2&shard.url=127.0.0.1:58835/|[ff01::083]:33332/&fsv=true&q=*:*&NOW=1390921285741} hits=68 status=0 QTime=0
[junit4] 2> 819663 T5481 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&isShard=true&rows=10&distrib=false&fl=id&start=0&sort=n_f1+asc&version=2&shard.url=127.0.0.1:58835/|[ff01::083]:33332/&fsv=true&q=*:*&NOW=1390921285743} hits=68 status=0 QTime=0
[junit4] 2> 819665 T5482 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&isShard=true&distrib=false&version=2&shard.url=127.0.0.1:58835/|[ff01::083]:33332/&ids=125,116,130,12,134,143,123,139,137,11&q=*:*&NOW=1390921285741} status=0 QTime=0
[junit4] 2> 819665 T5478 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&isShard=true&distrib=false&version=2&shard.url=127.0.0.1:58835/|[ff01::083]:33332/&ids=125,116,130,12,134,143,123,139,137,11&q=*:*&NOW=1390921285742} status=0 QTime=0
[junit4] 2> 819666 T5481 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&isShard=true&distrib=false&version=2&shard.url=127.0.0.1:58835/|[ff01::083]:33332/&ids=125,116,130,12,134,143,123,139,137,11&q=*:*&NOW=1390921285743} status=0 QTime=0
[junit4] 2> 819667 T5477 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&sort=n_f1+asc&version=2&shards=127.0.0.1:58835/|[ff01::083]:33332/&q=*:*} hits=68 status=0 QTime=8
[junit4] 2> 819667 T5480 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&sort=n_f1+asc&version=2&shards=127.0.0.1:58835/|[ff01::083]:33332/&q=*:*} hits=68 status=0 QTime=7
[junit4] 2> 819668 T5479 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&sort=n_f1+asc&version=2&shards=127.0.0.1:58835/|[ff01::083]:33332/&q=*:*} hits=68 status=0 QTime=7
[junit4] 2> 819672 T5465 C2167 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&distrib=false&sort=n_tf1+desc&version=2&q=*:*} hits=68 status=0 QTime=1
[junit4] 2> 819678 T5481 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&isShard=true&rows=10&distrib=false&fl=id&start=0&sort=n_tf1+desc&version=2&shard.url=127.0.0.1:58835/|[ff01::083]:33332/&fsv=true&q=*:*&NOW=1390921285757} hits=68 status=0 QTime=1
[junit4] 2> 819681 T5481 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&isShard=true&distrib=false&version=2&shard.url=127.0.0.1:58835/|[ff01::083]:33332/&ids=114,129,119,148,102,133,142,110,128,100&q=*:*&NOW=1390921285757} status=0 QTime=0
[junit4] 2> 819683 T5479 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&sort=n_tf1+desc&version=2&shards=127.0.0.1:58835/|[ff01::083]:33332/&q=*:*} hits=68 status=0 QTime=8
[junit4] 2> 819684 T5462 oas.BaseDistributedSearchTestCase.query starting stress...
[junit4] 2> 819689 T5481 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&isShard=true&rows=10&distrib=false&fl=id&start=0&sort=n_tf1+desc&version=2&shard.url=127.0.0.1:58835/|[ff01::083]:33332/&fsv=true&q=*:*&NOW=1390921285769} hits=68 status=0 QTime=0
[junit4] 2> 819689 T5478 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&isShard=true&rows=10&distrib=false&fl=id&start=0&sort=n_tf1+desc&version=2&shard.url=127.0.0.1:58835/|[ff01::083]:33332/&fsv=true&q=*:*&NOW=1390921285769} hits=68 status=0 QTime=0
[junit4] 2> 819689 T5482 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&isShard=true&rows=10&distrib=false&fl=id&start=0&sort=n_tf1+desc&version=2&shard.url=127.0.0.1:58835/|[ff01::083]:33332/&fsv=true&q=*:*&NOW=1390921285769} hits=68 status=0 QTime=0
[junit4] 2> 819692 T5481 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&isShard=true&distrib=false&version=2&shard.url=127.0.0.1:58835/|[ff01::083]:33332/&ids=114,129,119,148,102,133,142,110,128,100&q=*:*&NOW=1390921285769} status=0 QTime=0
[junit4] 2> 819692 T5482 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&isShard=true&distrib=false&version=2&shard.url=127.0.0.1:58835/|[ff01::083]:33332/&ids=114,129,119,148,102,133,142,110,128,100&q=*:*&NOW=1390921285769} status=0 QTime=0
[junit4] 2> 819693 T5478 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&isShard=true&distrib=false&version=2&shard.url=127.0.0.1:58835/|[ff01::083]:33332/&ids=114,129,119,148,102,133,142,110,128,100&q=*:*&NOW=1390921285769} status=0 QTime=0
[junit4] 2> 819694 T5480 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&sort=n_tf1+desc&version=2&shards=127.0.0.1:58835/|[ff01::083]:33332/&q=*:*} hits=68 status=0 QTime=7
[junit4] 2> 819694 T5477 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&sort=n_tf1+desc&version=2&shards=127.0.0.1:58835/|[ff01::083]:33332/&q=*:*} hits=68 status=0 QTime=7
[junit4] 2> 819695 T5479 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&sort=n_tf1+desc&version=2&shards=127.0.0.1:58835/|[ff01::083]:33332/&q=*:*} hits=68 status=0 QTime=8
[junit4] 2> 819699 T5482 C2168 oasc.SolrCore.execute [collection1] webapp= path=/select params={wt=javabin&isShard=true&rows=10&distrib=false&fl=id&start=0&sort=n_tf1+desc&version=2&shard.url=127.0.0.1:58835/|[ff01::083]:33332/&fsv=true&q=*:*&NOW=1390921285779} hits=68 status=0 QTime=0
[junit4] 2> 819699 T5478 C2168 oasc.SolrCore.execute [collection1] webapp= pa
[...truncated too long message...]
tedSearch-1390921282461/shard2/data/index [CachedDir<<refCount=0;path=./org.apache.solr.TestDistributedSearch-1390921282461/shard2/data/index;done=false>>]
[junit4] 2> 1128823 T5462 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.TestDistributedSearch-1390921282461/shard2/data/index
[junit4] 2> 1128823 T5462 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.TestDistributedSearch-1390921282461/shard2/data [CachedDir<<refCount=0;path=./org.apache.solr.TestDistributedSearch-1390921282461/shard2/data;done=false>>]
[junit4] 2> 1128824 T5462 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.TestDistributedSearch-1390921282461/shard2/data
[junit4] 2> 1128825 T5462 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/,null}
[junit4] 2> 1128932 T5462 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4] 2> NOTE: download the large Jenkins line-docs file by running 'ant get-jenkins-line-docs' in the lucene directory.
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestDistributedSearch -Dtests.method=testDistribSearch -Dtests.seed=C4FE0FE8C0397FBB -Dtests.multiplier=2 -Dtests.nightly=true -Dtests.slow=true -Dtests.linedocsfile=/home/hudson/lucene-data/enwiki.random.lines.txt -Dtests.locale=es_GT -Dtests.timezone=Europe/Madrid -Dtests.file.encoding=UTF-8
[junit4] ERROR 313s J1 | TestDistributedSearch.testDistribSearch <<<
[junit4] > Throwable #1: com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=5749, name=Thread-3072, state=RUNNABLE, group=TGRP-TestDistributedSearch]
[junit4] > at __randomizedtesting.SeedInfo.seed([C4FE0FE8C0397FBB:451881F0B7661F87]:0)
[junit4] > Caused by: java.lang.RuntimeException: org.apache.solr.client.solrj.SolrServerException: Timeout occured while waiting response from server at: http://127.0.0.1:58848
[junit4] > at __randomizedtesting.SeedInfo.seed([C4FE0FE8C0397FBB]:0)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase$5.run(BaseDistributedSearchTestCase.java:580)
[junit4] > Caused by: org.apache.solr.client.solrj.SolrServerException: Timeout occured while waiting response from server at: http://127.0.0.1:58848
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:503)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:199)
[junit4] > at org.apache.solr.client.solrj.request.QueryRequest.process(QueryRequest.java:90)
[junit4] > at org.apache.solr.client.solrj.SolrServer.query(SolrServer.java:301)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase$5.run(BaseDistributedSearchTestCase.java:575)
[junit4] > Caused by: java.net.SocketTimeoutException: Read timed out
[junit4] > at java.net.SocketInputStream.socketRead0(Native Method)
[junit4] > at java.net.SocketInputStream.read(SocketInputStream.java:150)
[junit4] > at java.net.SocketInputStream.read(SocketInputStream.java:121)
[junit4] > at org.apache.http.impl.io.AbstractSessionInputBuffer.fillBuffer(AbstractSessionInputBuffer.java:160)
[junit4] > at org.apache.http.impl.io.SocketInputBuffer.fillBuffer(SocketInputBuffer.java:84)
[junit4] > at org.apache.http.impl.io.AbstractSessionInputBuffer.readLine(AbstractSessionInputBuffer.java:273)
[junit4] > at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:140)
[junit4] > at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:57)
[junit4] > at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:260)
[junit4] > at org.apache.http.impl.AbstractHttpClientConnection.receiveResponseHeader(AbstractHttpClientConnection.java:283)
[junit4] > at org.apache.http.impl.conn.DefaultClientConnection.receiveResponseHeader(DefaultClientConnection.java:251)
[junit4] > at org.apache.http.impl.conn.ManagedClientConnectionImpl.receiveResponseHeader(ManagedClientConnectionImpl.java:197)
[junit4] > at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:271)
[junit4] > at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:123)
[junit4] > at org.apache.http.impl.client.DefaultRequestDirector.tryExecute(DefaultRequestDirector.java:682)
[junit4] > at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:486)
[junit4] > at org.apache.http.impl.client.AbstractHttpClient.doExecute(AbstractHttpClient.java:863)
[junit4] > at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82)
[junit4] > at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:106)
[junit4] > at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:57)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:395)
[junit4] > ... 4 more
[junit4] 2> 1128948 T5462 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: test params are: codec=Lucene46: {foo_b=PostingsFormat(name=MockSep), n_d1=PostingsFormat(name=Lucene41VarGapFixedInterval), foo_d=PostingsFormat(name=SimpleText), a_si=PostingsFormat(name=Memory doPackFST= true), range_facet_si=PostingsFormat(name=Memory doPackFST= true), text=PostingsFormat(name=MockSep), n_f1=PostingsFormat(name=Memory doPackFST= true), a_n_tdt=PostingsFormat(name=MockSep), lowerfilt=PostingsFormat(name=Memory doPackFST= true), foo_f=PostingsFormat(name=MockSep), b_n_tdt=PostingsFormat(name=Lucene41VarGapFixedInterval), n_l1=PostingsFormat(name=Lucene41VarGapFixedInterval), a_t=PostingsFormat(name=Lucene41VarGapFixedInterval), range_facet_sl=PostingsFormat(name=MockSep), other_tl1=PostingsFormat(name=Lucene41VarGapFixedInterval), range_facet_l=PostingsFormat(name=Lucene41VarGapFixedInterval), n_tf1=PostingsFormat(name=Lucene41VarGapFixedInterval), rnd_b=PostingsFormat(name=SimpleText), intDefault=PostingsFormat(name=Lucene41VarGapFixedInterval), n_td1=PostingsFormat(name=Memory doPackFST= true), lowerfilt1and2=PostingsFormat(name=Memory doPackFST= true), multiDefault=PostingsFormat(name=Memory doPackFST= true), n_ti1=PostingsFormat(name=SimpleText), n_tl1=PostingsFormat(name=Memory doPackFST= true), timestamp=PostingsFormat(name=Lucene41VarGapFixedInterval), n_dt1=PostingsFormat(name=Memory doPackFST= true), _version_=PostingsFormat(name=Lucene41VarGapFixedInterval), id=PostingsFormat(name=SimpleText), oddField_s=PostingsFormat(name=MockSep), SubjectTerms_mfacet=PostingsFormat(name=Lucene41VarGapFixedInterval), n_tdt1=PostingsFormat(name=Lucene41VarGapFixedInterval)}, docValues:{timestamp=DocValuesFormat(name=Memory)}, sim=DefaultSimilarity, locale=es_GT, timezone=Europe/Madrid
[junit4] 2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Oracle Corporation 1.7.0_25 (64-bit)/cpus=16,threads=1,free=58156304,total=413073408
[junit4] 2> NOTE: All tests run in this JVM: [TestLazyCores, SolrPluginUtilsTest, TestAddFieldRealTimeGet, PathHierarchyTokenizerFactoryTest, IndexBasedSpellCheckerTest, TestXIncludeConfig, XmlUpdateRequestHandlerTest, TestPhraseSuggestions, StandardRequestHandlerTest, TestSchemaNameResource, ChaosMonkeySafeLeaderTest, TestPartialUpdateDeduplication, TestMultiCoreConfBootstrap, MigrateRouteKeyTest, DocValuesMultiTest, TestSolrDeletionPolicy2, UniqFieldsUpdateProcessorFactoryTest, TestSolrQueryParserDefaultOperatorResource, TestIBSimilarityFactory, ShardRoutingCustomTest, ChaosMonkeyNothingIsSafeTest, BadIndexSchemaTest, StressHdfsTest, TestFiltering, MultiTermTest, CollectionsAPIDistributedZkTest, CurrencyFieldOpenExchangeTest, TestStressUserVersions, ModifyConfFileTest, TestQueryTypes, SolrCmdDistributorTest, TestHashPartitioner, AlternateDirectoryTest, SpellCheckCollatorTest, TestArbitraryIndexDir, TestDistributedGrouping, TestBinaryField, IndexSchemaRuntimeFieldTest, NoFacetTest, TestSolrCoreProperties, TestSolr4Spatial, PluginInfoTest, DateFieldTest, TestSimpleQParserPlugin, TestRandomMergePolicy, AliasIntegrationTest, TestAtomicUpdateErrorCases, TestCursorMarkWithoutUniqueKey, TestCollationField, TestAnalyzedSuggestions, FileUtilsTest, TestDistributedSearch]
[junit4] Completed on J1 in 312.62s, 1 test, 1 error <<< FAILURES!
[...truncated 725 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/build.xml:460: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/build.xml:433: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/build.xml:39: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/extra-targets.xml:37: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build.xml:189: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/common-build.xml:491: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/lucene/common-build.xml:1268: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/lucene/common-build.xml:901: There were test failures: 365 suites, 1603 tests, 1 error, 33 ignored (5 assumptions)
Total time: 134 minutes 33 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure