You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2013/08/09 08:43:21 UTC
[JENKINS] Lucene-Solr-4.x-Linux (64bit/jdk1.6.0_45) - Build # 6852
- Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/6852/
Java: 64bit/jdk1.6.0_45 -XX:-UseCompressedOops -XX:+UseParallelGC
1 tests failed.
REGRESSION: org.apache.solr.client.solrj.embedded.SolrExampleJettyTest.testStatistics
Error Message:
IOException occured when talking to server at: https://127.0.0.1:53138/solr/collection1
Stack Trace:
org.apache.solr.client.solrj.SolrServerException: IOException occured when talking to server at: https://127.0.0.1:53138/solr/collection1
at __randomizedtesting.SeedInfo.seed([D959E841EEE15DBA:2EF0DB2542CC8752]:0)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:435)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
at org.apache.solr.client.solrj.request.AbstractUpdateRequest.process(AbstractUpdateRequest.java:117)
at org.apache.solr.client.solrj.SolrServer.add(SolrServer.java:116)
at org.apache.solr.client.solrj.SolrServer.add(SolrServer.java:102)
at org.apache.solr.client.solrj.SolrExampleTests.testStatistics(SolrExampleTests.java:816)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:662)
Caused by: org.apache.http.NoHttpResponseException: The target server failed to respond
at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:95)
at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:62)
at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:254)
at org.apache.http.impl.AbstractHttpClientConnection.receiveResponseHeader(AbstractHttpClientConnection.java:289)
at org.apache.http.impl.conn.DefaultClientConnection.receiveResponseHeader(DefaultClientConnection.java:252)
at org.apache.http.impl.conn.ManagedClientConnectionImpl.receiveResponseHeader(ManagedClientConnectionImpl.java:191)
at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:300)
at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:127)
at org.apache.http.impl.client.DefaultRequestDirector.tryExecute(DefaultRequestDirector.java:717)
at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:522)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:365)
... 45 more
Build Log:
[...truncated 10295 lines...]
[junit4] Suite: org.apache.solr.client.solrj.embedded.SolrExampleJettyTest
[junit4] 2> 59577 T185 oas.SolrJettyTestBase.beforeSolrJettyTestBase Randomized ssl (true) and clientAuth (false)
[junit4] 2> 59578 T185 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J1/./solrtest-SolrExampleJettyTest-1376030385208
[junit4] 2> 59579 T185 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 59587 T185 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 59842 T185 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1] of [SSLv2Hello, SSLv3, TLSv1]
[junit4] 2> 59862 T185 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:53138
[junit4] 2> 59863 T185 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 59863 T185 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 59864 T185 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/example/solr
[junit4] 2> 59864 T185 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/example/solr/'
[junit4] 2> 59880 T185 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/example/solr/solr.xml
[junit4] 2> 59938 T185 oasc.ConfigSolrXml.<init> Config-defined core root directory:
[junit4] 2> 59938 T185 oasc.CoreContainer.<init> New CoreContainer 714996484
[junit4] 2> 59939 T185 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/example/solr/]
[junit4] 2> 59940 T185 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4] 2> 59940 T185 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 59941 T185 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4] 2> 59941 T185 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 59941 T185 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 59941 T185 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 59942 T185 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 59942 T185 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 59942 T185 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 59943 T185 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4] 2> 59948 T185 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/example/solr
[junit4] 2> 59949 T185 oasc.CorePropertiesLocator.discoverUnder Found core collection1 in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/example/solr/collection1/
[junit4] 2> 59953 T185 oasc.CorePropertiesLocator.discover Found 1 core definitions
[junit4] 2> 59953 T195 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/example/solr/collection1
[junit4] 2> 59954 T195 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/example/solr/collection1/'
[junit4] 2> 60027 T195 oasc.SolrConfig.initLibs Adding specified lib dirs to ClassLoader
[junit4] 2> 60027 T195 oasc.SolrResourceLoader.addToClassLoader WARN No files added to classloader from lib: ../../../contrib/extraction/lib (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/example/solr/collection1/../../../contrib/extraction/lib).
[junit4] 2> 60027 T195 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/example/solr/collection1/../../../dist).
[junit4] 2> 60028 T195 oasc.SolrResourceLoader.addToClassLoader WARN No files added to classloader from lib: ../../../contrib/clustering/lib/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/example/solr/collection1/../../../contrib/clustering/lib).
[junit4] 2> 60028 T195 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/example/solr/collection1/../../../dist).
[junit4] 2> 60029 T195 oasc.SolrResourceLoader.addToClassLoader WARN No files added to classloader from lib: ../../../contrib/langid/lib/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/example/solr/collection1/../../../contrib/langid/lib).
[junit4] 2> 60029 T195 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/example/solr/collection1/../../../dist).
[junit4] 2> 60029 T195 oasc.SolrResourceLoader.addToClassLoader WARN No files added to classloader from lib: ../../../contrib/velocity/lib (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/example/solr/collection1/../../../contrib/velocity/lib).
[junit4] 2> 60030 T195 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/example/solr/collection1/../../../dist).
[junit4] 2> 60071 T195 oasu.SolrIndexConfig.<init> IndexWriter infoStream solr logging is enabled
[junit4] 2> 60074 T195 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
[junit4] 2> 60164 T195 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 60165 T195 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 60227 T195 oass.IndexSchema.readSchema [collection1] Schema name=example
[junit4] 2> 60917 T195 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 60942 T195 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 60952 T195 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 61030 T195 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 61031 T195 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/example/solr/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J1/solrtest-SolrExampleJettyTest-1376030385208/
[junit4] 2> 61031 T195 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@28b301f2
[junit4] 2> 61032 T195 oasc.SolrCore.initListeners [collection1] Added SolrEventListener for newSearcher: org.apache.solr.core.QuerySenderListener{queries=[]}
[junit4] 2> 61032 T195 oasc.SolrCore.initListeners [collection1] Added SolrEventListener for firstSearcher: org.apache.solr.core.QuerySenderListener{queries=[{q=static firstSearcher warming in solrconfig.xml}]}
[junit4] 2> 61033 T195 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J1/solrtest-SolrExampleJettyTest-1376030385208
[junit4] 2> 61033 T195 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J1/solrtest-SolrExampleJettyTest-1376030385208/index/
[junit4] 2> 61033 T195 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J1/solrtest-SolrExampleJettyTest-1376030385208/index' doesn't exist. Creating new index...
[junit4] 2> 61034 T195 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J1/solrtest-SolrExampleJettyTest-1376030385208/index
[junit4] 2> 61036 T195 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-83-thread-1]: init: current segments file is "null"; deletionPolicy=org.apache.solr.core.IndexDeletionPolicyWrapper@4f4f4c7a
[junit4] 2> 61037 T195 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-83-thread-1]: now checkpoint "" [0 segments ; isCommit = false]
[junit4] 2> 61037 T195 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-83-thread-1]: 0 msec to checkpoint
[junit4] 2> 61037 T195 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-83-thread-1]: init: create=true
[junit4] 2> 61038 T195 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-83-thread-1]:
[junit4] 2> dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@6c9d2223 lockFactory=org.apache.lucene.store.NativeFSLockFactory@9c304c7; maxCacheMB=0.9052734375 maxMergeSizeMB=0.8291015625))
[junit4] 2> index=
[junit4] 2> version=4.5-SNAPSHOT
[junit4] 2> matchVersion=LUCENE_45
[junit4] 2> analyzer=null
[junit4] 2> ramBufferSizeMB=100.0
[junit4] 2> maxBufferedDocs=-1
[junit4] 2> maxBufferedDeleteTerms=-1
[junit4] 2> mergedSegmentWarmer=null
[junit4] 2> readerTermsIndexDivisor=1
[junit4] 2> termIndexInterval=32
[junit4] 2> delPolicy=org.apache.solr.core.IndexDeletionPolicyWrapper
[junit4] 2> commit=null
[junit4] 2> openMode=CREATE
[junit4] 2> similarity=org.apache.lucene.search.similarities.DefaultSimilarity
[junit4] 2> mergeScheduler=ConcurrentMergeScheduler: maxThreadCount=1, maxMergeCount=2, mergeThreadPriority=-1
[junit4] 2> default WRITE_LOCK_TIMEOUT=1000
[junit4] 2> writeLockTimeout=1000
[junit4] 2> codec=Lucene42
[junit4] 2> infoStream=org.apache.solr.update.LoggingInfoStream
[junit4] 2> mergePolicy=[TieredMergePolicy: maxMergeAtOnce=10, maxMergeAtOnceExplicit=30, maxMergedSegmentMB=5120.0, floorSegmentMB=2.0, forceMergeDeletesPctAllowed=10.0, segmentsPerTier=10.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> indexerThreadPool=org.apache.lucene.index.ThreadAffinityDocumentsWriterThreadPool@5f260643
[junit4] 2> readerPooling=false
[junit4] 2> perThreadHardLimitMB=1945
[junit4] 2> useCompoundFile=false
[junit4] 2>
[junit4] 2> 61038 T195 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-83-thread-1]: now flush at close waitForMerges=true
[junit4] 2> 61039 T195 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-83-thread-1]: start flush: applyAllDeletes=true
[junit4] 2> 61039 T195 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-83-thread-1]: index before flush
[junit4] 2> 61039 T195 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-83-thread-1]: coreLoadExecutor-83-thread-1 startFullFlush
[junit4] 2> 61040 T195 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-83-thread-1]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 61040 T195 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-83-thread-1]: coreLoadExecutor-83-thread-1 finishFullFlush success=true
[junit4] 2> 61040 T195 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-83-thread-1]: apply all deletes during flush
[junit4] 2> 61041 T195 oasu.LoggingInfoStream.message [BD][coreLoadExecutor-83-thread-1]: prune sis=org.apache.lucene.index.SegmentInfos@39654982 minGen=9223372036854775807 packetCount=0
[junit4] 2> 61041 T195 oasu.LoggingInfoStream.message [CMS][coreLoadExecutor-83-thread-1]: now merge
[junit4] 2> 61041 T195 oasu.LoggingInfoStream.message [CMS][coreLoadExecutor-83-thread-1]: index:
[junit4] 2> 61042 T195 oasu.LoggingInfoStream.message [CMS][coreLoadExecutor-83-thread-1]: no more merges pending; now return
[junit4] 2> 61042 T195 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-83-thread-1]: waitForMerges
[junit4] 2> 61042 T195 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-83-thread-1]: waitForMerges done
[junit4] 2> 61042 T195 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-83-thread-1]: now call final commit()
[junit4] 2> 61043 T195 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-83-thread-1]: commit: start
[junit4] 2> 61043 T195 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-83-thread-1]: commit: enter lock
[junit4] 2> 61043 T195 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-83-thread-1]: commit: now prepare
[junit4] 2> 61044 T195 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-83-thread-1]: prepareCommit: flush
[junit4] 2> 61044 T195 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-83-thread-1]: index before flush
[junit4] 2> 61044 T195 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-83-thread-1]: coreLoadExecutor-83-thread-1 startFullFlush
[junit4] 2> 61045 T195 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-83-thread-1]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 61045 T195 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-83-thread-1]: apply all deletes during flush
[junit4] 2> 61045 T195 oasu.LoggingInfoStream.message [BD][coreLoadExecutor-83-thread-1]: prune sis=org.apache.lucene.index.SegmentInfos@39654982 minGen=9223372036854775807 packetCount=0
[junit4] 2> 61046 T195 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-83-thread-1]: coreLoadExecutor-83-thread-1 finishFullFlush success=true
[junit4] 2> 61046 T195 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-83-thread-1]: startCommit(): start
[junit4] 2> 61047 T195 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-83-thread-1]: startCommit index= changeCount=1
[junit4] 2> 61047 T195 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-83-thread-1]: done all syncs: []
[junit4] 2> 61048 T195 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-83-thread-1]: commit: pendingCommit != null
[junit4] 2> 61048 T195 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-83-thread-1]: commit: wrote segments file "segments_1"
[junit4] 2> 61048 T195 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-83-thread-1]: now checkpoint "" [0 segments ; isCommit = true]
[junit4] 2> 61049 T195 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@6c9d2223 lockFactory=org.apache.lucene.store.NativeFSLockFactory@9c304c7; maxCacheMB=0.9052734375 maxMergeSizeMB=0.8291015625)),segFN=segments_1,generation=1}
[junit4] 2> 61049 T195 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 61049 T195 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-83-thread-1]: 1 msec to checkpoint
[junit4] 2> 61050 T195 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-83-thread-1]: commit: done
[junit4] 2> 61050 T195 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-83-thread-1]: at close:
[junit4] 2> 61051 T195 oasc.SolrCore.initWriters created json: solr.JSONResponseWriter
[junit4] 2> 61051 T195 oasc.SolrCore.initWriters adding lazy queryResponseWriter: solr.VelocityResponseWriter
[junit4] 2> 61051 T195 oasc.SolrCore.initWriters created velocity: solr.VelocityResponseWriter
[junit4] 2> 61052 T195 oasc.SolrCore.initWriters created xslt: solr.XSLTResponseWriter
[junit4] 2> 61052 T195 oasr.XSLTResponseWriter.init xsltCacheLifetimeSeconds=5
[junit4] 2> 61060 T195 oasc.RequestHandlers.initHandlersFromConfig created /select: solr.SearchHandler
[junit4] 2> 61060 T195 oasc.RequestHandlers.initHandlersFromConfig created /query: solr.SearchHandler
[junit4] 2> 61061 T195 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 61062 T195 oasc.RequestHandlers.initHandlersFromConfig created /browse: solr.SearchHandler
[junit4] 2> 61062 T195 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 61063 T195 oasc.RequestHandlers.initHandlersFromConfig created /update/json: solr.JsonUpdateRequestHandler
[junit4] 2> 61063 T195 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: solr.CSVRequestHandler
[junit4] 2> 61063 T195 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.extraction.ExtractingRequestHandler
[junit4] 2> 61064 T195 oasc.RequestHandlers.initHandlersFromConfig created /update/extract: solr.extraction.ExtractingRequestHandler
[junit4] 2> 61064 T195 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.FieldAnalysisRequestHandler
[junit4] 2> 61065 T195 oasc.RequestHandlers.initHandlersFromConfig created /analysis/field: solr.FieldAnalysisRequestHandler
[junit4] 2> 61065 T195 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.DocumentAnalysisRequestHandler
[junit4] 2> 61065 T195 oasc.RequestHandlers.initHandlersFromConfig created /analysis/document: solr.DocumentAnalysisRequestHandler
[junit4] 2> 61066 T195 oasc.RequestHandlers.initHandlersFromConfig created /admin/: solr.admin.AdminHandlers
[junit4] 2> 61067 T195 oasc.RequestHandlers.initHandlersFromConfig created /admin/ping: solr.PingRequestHandler
[junit4] 2> 61067 T195 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4] 2> 61068 T195 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 61068 T195 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
[junit4] 2> 61068 T195 oasc.RequestHandlers.initHandlersFromConfig created /spell: solr.SearchHandler
[junit4] 2> 61068 T195 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
[junit4] 2> 61069 T195 oasc.RequestHandlers.initHandlersFromConfig created /tvrh: solr.SearchHandler
[junit4] 2> 61069 T195 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
[junit4] 2> 61069 T195 oasc.RequestHandlers.initHandlersFromConfig created /terms: solr.SearchHandler
[junit4] 2> 61069 T195 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
[junit4] 2> 61070 T195 oasc.RequestHandlers.initHandlersFromConfig created /elevate: solr.SearchHandler
[junit4] 2> 61072 T195 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 61073 T195 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 61074 T195 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 61078 T195 oass.SolrIndexSearcher.<init> Opening Searcher@544a7629 main
[junit4] 2> 61079 T195 oasu.CommitTracker.<init> Hard AutoCommit: if uncommited for 15000ms;
[junit4] 2> 61079 T195 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 61080 T195 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4] 2> 61080 T195 oass.DirectSolrSpellChecker.init init: {name=default,field=text,classname=solr.DirectSolrSpellChecker,distanceMeasure=internal,accuracy=0.5,maxEdits=2,minPrefix=1,maxInspections=5,minQueryLength=4,maxQueryFrequency=0.01}
[junit4] 2> 61080 T195 oashc.SpellCheckComponent.inform No queryConverter defined, using default converter
[junit4] 2> 61081 T195 oashc.QueryElevationComponent.inform Loading QueryElevation from: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/example/solr/collection1/conf/elevate.xml
[junit4] 2> 61095 T195 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4] 2> 61095 T196 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@544a7629 main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> ASYNC NEW_CORE C129 name=collection1 org.apache.solr.core.SolrCore@6944ffa4
[junit4] 2> 61097 T196 C129 oasc.SolrCore.execute [collection1] webapp=null path=null params={event=firstSearcher&q=static+firstSearcher+warming+in+solrconfig.xml&distrib=false} hits=0 status=0 QTime=1
[junit4] 2> 61097 T196 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 61098 T196 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: default
[junit4] 2> 61098 T196 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: wordbreak
[junit4] 2> 61101 T196 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@544a7629 main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 61105 T195 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 61106 T185 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J1
[junit4] 2> 61106 T185 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 61106 T185 oas.SolrJettyTestBase.createJetty Jetty Assigned Port#53138
[junit4] 2> 61114 T185 oas.SolrTestCaseJ4.setUp ###Starting testFaceting
[junit4] 2> 61114 T185 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 61234 T192 C129 oasu.LoggingInfoStream.message [IFD][qtp1478287298-192]: init: current segments file is "segments_1"; deletionPolicy=org.apache.solr.core.IndexDeletionPolicyWrapper@4f4f4c7a
[junit4] 2> 61234 T192 C129 oasu.LoggingInfoStream.message [IFD][qtp1478287298-192]: init: load commit "segments_1"
[junit4] 2> 61235 T192 C129 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@6c9d2223 lockFactory=org.apache.lucene.store.NativeFSLockFactory@9c304c7; maxCacheMB=0.9052734375 maxMergeSizeMB=0.8291015625)),segFN=segments_1,generation=1}
[junit4] 2> 61235 T192 C129 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 61236 T192 C129 oasu.LoggingInfoStream.message [IFD][qtp1478287298-192]: now checkpoint "" [0 segments ; isCommit = false]
[junit4] 2> 61236 T192 C129 oasu.LoggingInfoStream.message [IFD][qtp1478287298-192]: 0 msec to checkpoint
[junit4] 2> 61237 T192 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-192]: init: create=false
[junit4] 2> 61237 T192 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-192]:
[junit4] 2> dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@6c9d2223 lockFactory=org.apache.lucene.store.NativeFSLockFactory@9c304c7; maxCacheMB=0.9052734375 maxMergeSizeMB=0.8291015625))
[junit4] 2> index=
[junit4] 2> version=4.5-SNAPSHOT
[junit4] 2> matchVersion=LUCENE_45
[junit4] 2> analyzer=null
[junit4] 2> ramBufferSizeMB=100.0
[junit4] 2> maxBufferedDocs=-1
[junit4] 2> maxBufferedDeleteTerms=-1
[junit4] 2> mergedSegmentWarmer=null
[junit4] 2> readerTermsIndexDivisor=1
[junit4] 2> termIndexInterval=32
[junit4] 2> delPolicy=org.apache.solr.core.IndexDeletionPolicyWrapper
[junit4] 2> commit=null
[junit4] 2> openMode=APPEND
[junit4] 2> similarity=org.apache.lucene.search.similarities.DefaultSimilarity
[junit4] 2> mergeScheduler=ConcurrentMergeScheduler: maxThreadCount=1, maxMergeCount=2, mergeThreadPriority=-1
[junit4] 2> default WRITE_LOCK_TIMEOUT=1000
[junit4] 2> writeLockTimeout=1000
[junit4] 2> codec=Lucene42
[junit4] 2> infoStream=org.apache.solr.update.LoggingInfoStream
[junit4] 2> mergePolicy=[TieredMergePolicy: maxMergeAtOnce=10, maxMergeAtOnceExplicit=30, maxMergedSegmentMB=5120.0, floorSegmentMB=2.0, forceMergeDeletesPctAllowed=10.0, segmentsPerTier=10.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> indexerThreadPool=org.apache.lucene.index.ThreadAffinityDocumentsWriterThreadPool@637533df
[junit4] 2> readerPooling=false
[junit4] 2> perThreadHardLimitMB=1945
[junit4] 2> useCompoundFile=false
[junit4] 2>
[junit4] 2> 61238 T192 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-192]: flush at getReader
[junit4] 2> 61239 T192 C129 oasu.LoggingInfoStream.message [DW][qtp1478287298-192]: qtp1478287298-192 startFullFlush
[junit4] 2> 61239 T192 C129 oasu.LoggingInfoStream.message [DW][qtp1478287298-192]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 61240 T192 C129 oasu.LoggingInfoStream.message [DW][qtp1478287298-192]: qtp1478287298-192: flush naked frozen global deletes
[junit4] 2> 61240 T192 C129 oasu.LoggingInfoStream.message [BD][qtp1478287298-192]: push deletes 1 deleted queries bytesUsed=36 delGen=1 packetCount=1 totBytesUsed=36
[junit4] 2> 61241 T192 C129 oasu.LoggingInfoStream.message [DW][qtp1478287298-192]: flush: push buffered deletes: 1 deleted queries bytesUsed=36
[junit4] 2> 61241 T192 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-192]: apply all deletes during flush
[junit4] 2> 61242 T192 C129 oasu.LoggingInfoStream.message [BD][qtp1478287298-192]: prune sis=org.apache.lucene.index.SegmentInfos@895772a minGen=9223372036854775807 packetCount=1
[junit4] 2> 61242 T192 C129 oasu.LoggingInfoStream.message [BD][qtp1478287298-192]: pruneDeletes: prune 1 packets; 0 packets remain
[junit4] 2> 61243 T192 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-192]: return reader version=1 reader=StandardDirectoryReader(segments_1:1:nrt)
[junit4] 2> 61243 T192 C129 oasu.LoggingInfoStream.message [DW][qtp1478287298-192]: qtp1478287298-192 finishFullFlush success=true
[junit4] 2> 61244 T192 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-192]: getReader took 6 msec
[junit4] 2> 61244 T192 C129 oass.SolrIndexSearcher.<init> Opening Searcher@2ff1bf46 realtime
[junit4] 2> 61245 T192 C129 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {deleteByQuery=*:* (-1442872438934208512)} 0 13
[junit4] 2> 61250 T193 C129 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 61250 T193 C129 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
[junit4] 2> 61251 T193 C129 oasu.LoggingInfoStream.message [DW][qtp1478287298-193]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 61251 T193 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-193]: nrtIsCurrent: infoVersion matches: true; DW changes: false; BD changes: false
[junit4] 2> 61252 T193 C129 oasu.LoggingInfoStream.message [DW][qtp1478287298-193]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 61252 T193 C129 oass.SolrIndexSearcher.<init> Opening Searcher@4fbf7435 main
[junit4] 2> 61253 T193 C129 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 61253 T196 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@4fbf7435 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 61254 T196 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 61258 T196 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4fbf7435 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 61259 T193 C129 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 9
[junit4] 2> 61263 T194 C129 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={q=*:*&wt=javabin&version=2} hits=0 status=0 QTime=0
[junit4] 2> 61276 T192 C129 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[1 (1442872438971957248), 2 (1442872438974054400), 3 (1442872438974054401), 4 (1442872438975102976), 5 (1442872438976151552), 6 (1442872438976151553), 7 (1442872438977200128), 8 (1442872438978248704), 9 (1442872438978248705), 10 (1442872438979297280)]} 0 8
[junit4] 2> 61280 T193 C129 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 61280 T193 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-193]: commit: start
[junit4] 2> 61281 T193 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-193]: commit: enter lock
[junit4] 2> 61281 T193 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-193]: commit: now prepare
[junit4] 2> 61282 T193 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-193]: prepareCommit: flush
[junit4] 2> 61282 T193 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-193]: index before flush
[junit4] 2> 61283 T193 C129 oasu.LoggingInfoStream.message [DW][qtp1478287298-193]: qtp1478287298-193 startFullFlush
[junit4] 2> 61283 T193 C129 oasu.LoggingInfoStream.message [DW][qtp1478287298-193]: anyChanges? numDocsInRam=10 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 61284 T193 C129 oasu.LoggingInfoStream.message [DWFC][qtp1478287298-193]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0 9 deleted terms (unique count=9) bytesUsed=2062, segment=_0, aborting=false, numDocsInRAM=10, deleteQueue=DWDQ: [ generation: 1 ]]
[junit4] 2> 61284 T193 C129 oasu.LoggingInfoStream.message [DWPT][qtp1478287298-193]: flush postings as segment _0 numDocs=10
[junit4] 2> 61289 T193 C129 oasu.LoggingInfoStream.message [DWPT][qtp1478287298-193]: new segment has 0 deleted docs
[junit4] 2> 61289 T193 C129 oasu.LoggingInfoStream.message [DWPT][qtp1478287298-193]: new segment has no vectors; norms; no docValues; prox; freqs
[junit4] 2> 61289 T193 C129 oasu.LoggingInfoStream.message [DWPT][qtp1478287298-193]: flushedFiles=[_0.fnm, _0_Lucene41_0.doc, _0_Lucene41_0.pos, _0.nvd, _0.fdx, _0.nvm, _0_Lucene41_0.tim, _0_Lucene41_0.tip, _0.fdt]
[junit4] 2> 61290 T193 C129 oasu.LoggingInfoStream.message [DWPT][qtp1478287298-193]: flushed codec=Lucene42
[junit4] 2> 61291 T193 C129 oasu.LoggingInfoStream.message [DWPT][qtp1478287298-193]: flushed: segment=_0 ramUsed=0.082 MB newFlushedSize(includes docstores)=0.001 MB docs/MB=7,715.791
[junit4] 2> 61291 T193 C129 oasu.LoggingInfoStream.message [DW][qtp1478287298-193]: publishFlushedSegment seg-private deletes=null
[junit4] 2> 61293 T193 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-193]: publishFlushedSegment
[junit4] 2> 61293 T193 C129 oasu.LoggingInfoStream.message [BD][qtp1478287298-193]: push deletes 10 deleted terms (unique count=10) bytesUsed=1024 delGen=3 packetCount=1 totBytesUsed=1024
[junit4] 2> 61294 T193 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-193]: publish sets newSegment delGen=4 seg=_0(4.5):C10
[junit4] 2> 61294 T193 C129 oasu.LoggingInfoStream.message [IFD][qtp1478287298-193]: now checkpoint "_0(4.5):C10" [1 segments ; isCommit = false]
[junit4] 2> 61295 T193 C129 oasu.LoggingInfoStream.message [IFD][qtp1478287298-193]: 0 msec to checkpoint
[junit4] 2> 61295 T193 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-193]: apply all deletes during flush
[junit4] 2> 61296 T193 C129 oasu.LoggingInfoStream.message [BD][qtp1478287298-193]: applyDeletes: infos=[_0(4.5):C10] packetCount=1
[junit4] 2> 61296 T193 C129 oasu.LoggingInfoStream.message [BD][qtp1478287298-193]: applyDeletes took 0 msec
[junit4] 2> 61297 T193 C129 oasu.LoggingInfoStream.message [BD][qtp1478287298-193]: prune sis=org.apache.lucene.index.SegmentInfos@895772a minGen=5 packetCount=1
[junit4] 2> 61297 T193 C129 oasu.LoggingInfoStream.message [BD][qtp1478287298-193]: pruneDeletes: prune 1 packets; 0 packets remain
[junit4] 2> 61297 T193 C129 oasu.LoggingInfoStream.message [DW][qtp1478287298-193]: qtp1478287298-193 finishFullFlush success=true
[junit4] 2> 61298 T193 C129 oasu.LoggingInfoStream.message [TMP][qtp1478287298-193]: findMerges: 1 segments
[junit4] 2> 61299 T193 C129 oasu.LoggingInfoStream.message [TMP][qtp1478287298-193]: seg=_0(4.5):C10 size=0.001 MB [floored]
[junit4] 2> 61299 T193 C129 oasu.LoggingInfoStream.message [TMP][qtp1478287298-193]: allowedSegmentCount=1 vs count=1 (eligible count=1) tooBigCount=0
[junit4] 2> 61299 T193 C129 oasu.LoggingInfoStream.message [CMS][qtp1478287298-193]: now merge
[junit4] 2> 61300 T193 C129 oasu.LoggingInfoStream.message [CMS][qtp1478287298-193]: index: _0(4.5):C10
[junit4] 2> 61300 T193 C129 oasu.LoggingInfoStream.message [CMS][qtp1478287298-193]: no more merges pending; now return
[junit4] 2> 61301 T193 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-193]: startCommit(): start
[junit4] 2> 61301 T193 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-193]: startCommit index=_0(4.5):C10 changeCount=3
[junit4] 2> 61302 T193 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-193]: done all syncs: [_0.fnm, _0_Lucene41_0.doc, _0_Lucene41_0.pos, _0.nvd, _0.fdx, _0.si, _0.nvm, _0_Lucene41_0.tim, _0.fdt, _0_Lucene41_0.tip]
[junit4] 2> 61302 T193 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-193]: commit: pendingCommit != null
[junit4] 2> 61303 T193 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-193]: commit: wrote segments file "segments_2"
[junit4] 2> 61303 T193 C129 oasu.LoggingInfoStream.message [IFD][qtp1478287298-193]: now checkpoint "_0(4.5):C10" [1 segments ; isCommit = true]
[junit4] 2> 61304 T193 C129 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@6c9d2223 lockFactory=org.apache.lucene.store.NativeFSLockFactory@9c304c7; maxCacheMB=0.9052734375 maxMergeSizeMB=0.8291015625)),segFN=segments_1,generation=1}
[junit4] 2> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@6c9d2223 lockFactory=org.apache.lucene.store.NativeFSLockFactory@9c304c7; maxCacheMB=0.9052734375 maxMergeSizeMB=0.8291015625)),segFN=segments_2,generation=2}
[junit4] 2> 61304 T193 C129 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4] 2> 61305 T193 C129 oasu.LoggingInfoStream.message [IFD][qtp1478287298-193]: deleteCommits: now decRef commit "segments_1"
[junit4] 2> 61305 T193 C129 oasu.LoggingInfoStream.message [IFD][qtp1478287298-193]: delete "segments_1"
[junit4] 2> 61306 T193 C129 oasu.LoggingInfoStream.message [IFD][qtp1478287298-193]: 2 msec to checkpoint
[junit4] 2> 61306 T193 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-193]: commit: done
[junit4] 2> 61307 T193 C129 oasu.LoggingInfoStream.message [DW][qtp1478287298-193]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 61307 T193 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-193]: nrtIsCurrent: infoVersion matches: false; DW changes: false; BD changes: false
[junit4] 2> 61308 T193 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-193]: flush at getReader
[junit4] 2> 61308 T193 C129 oasu.LoggingInfoStream.message [DW][qtp1478287298-193]: qtp1478287298-193 startFullFlush
[junit4] 2> 61309 T193 C129 oasu.LoggingInfoStream.message [DW][qtp1478287298-193]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 61309 T193 C129 oasu.LoggingInfoStream.message [DWFC][qtp1478287298-193]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=null, aborting=false, numDocsInRAM=0, deleteQueue=DWDQ: [ generation: 2 ]]
[junit4] 2> 61310 T193 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-193]: apply all deletes during flush
[junit4] 2> 61310 T193 C129 oasu.LoggingInfoStream.message [BD][qtp1478287298-193]: applyDeletes: no deletes; skipping
[junit4] 2> 61311 T193 C129 oasu.LoggingInfoStream.message [BD][qtp1478287298-193]: prune sis=org.apache.lucene.index.SegmentInfos@895772a minGen=5 packetCount=0
[junit4] 2> 61312 T193 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-193]: return reader version=3 reader=StandardDirectoryReader(segments_2:3:nrt _0(4.5):C10)
[junit4] 2> 61313 T193 C129 oasu.LoggingInfoStream.message [DW][qtp1478287298-193]: qtp1478287298-193 finishFullFlush success=true
[junit4] 2> 61313 T193 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-193]: getReader took 5 msec
[junit4] 2> 61313 T193 C129 oass.SolrIndexSearcher.<init> Opening Searcher@17973271 main
[junit4] 2> 61314 T193 C129 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 61314 T196 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@17973271 main{StandardDirectoryReader(segments_2:3:nrt _0(4.5):C10)}
[junit4] 2> 61315 T196 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 61322 T196 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@17973271 main{StandardDirectoryReader(segments_2:3:nrt _0(4.5):C10)}
[junit4] 2> 61323 T193 C129 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 43
[junit4] 2> 61327 T194 C129 oasr.UnInvertedField.<init> UnInverted multi-valued field {field=features,memSize=4564,tindexSize=44,time=0,phase1=0,nTerms=4,bigTerms=2,termInstances=4,uses=0}
[junit4] 2> 61328 T194 C129 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={facet=true&facet.mincount=0&q=*:*&facet.field=features&wt=javabin&version=2&rows=0} hits=10 status=0 QTime=1
[junit4] 2> 61333 T191 C129 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={facet=true&facet.mincount=0&q=*:*&facet.field=features&wt=javabin&fq=features:two&version=2&rows=0} hits=5 status=0 QTime=1
[junit4] 2> 61337 T192 C129 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={facet=true&facet.mincount=4&q=*:*&facet.field=features&wt=javabin&fq=features:two&version=2&rows=0} hits=5 status=0 QTime=1
[junit4] 2> 61341 T193 C129 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={facet=true&facet.mincount=-1&q=*:*&facet.field=features&wt=javabin&fq=features:two&version=2&rows=0} hits=5 status=0 QTime=1
[junit4] 2> 61342 T185 oas.SolrTestCaseJ4.tearDown ###Ending testFaceting
[junit4] 2> 61353 T185 oas.SolrTestCaseJ4.setUp ###Starting testMultiContentStreamRequest
[junit4] 2> 61357 T194 C129 oasu.LoggingInfoStream.message [DW][qtp1478287298-194]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 61358 T194 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-194]: nrtIsCurrent: infoVersion matches: true; DW changes: true; BD changes: false
[junit4] 2> 61358 T194 C129 oasu.LoggingInfoStream.message [DW][qtp1478287298-194]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 61359 T194 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-194]: flush at getReader
[junit4] 2> 61359 T194 C129 oasu.LoggingInfoStream.message [DW][qtp1478287298-194]: qtp1478287298-194 startFullFlush
[junit4] 2> 61360 T194 C129 oasu.LoggingInfoStream.message [DW][qtp1478287298-194]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 61360 T194 C129 oasu.LoggingInfoStream.message [DWFC][qtp1478287298-194]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=null, aborting=false, numDocsInRAM=0, deleteQueue=DWDQ: [ generation: 3 ]]
[junit4] 2> 61361 T194 C129 oasu.LoggingInfoStream.message [DW][qtp1478287298-194]: qtp1478287298-194: flush naked frozen global deletes
[junit4] 2> 61361 T194 C129 oasu.LoggingInfoStream.message [BD][qtp1478287298-194]: push deletes 1 deleted queries bytesUsed=36 delGen=7 packetCount=1 totBytesUsed=36
[junit4] 2> 61361 T194 C129 oasu.LoggingInfoStream.message [DW][qtp1478287298-194]: flush: push buffered deletes: 1 deleted queries bytesUsed=36
[junit4] 2> 61362 T194 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-194]: apply all deletes during flush
[junit4] 2> 61362 T194 C129 oasu.LoggingInfoStream.message [BD][qtp1478287298-194]: applyDeletes: infos=[_0(4.5):C10] packetCount=1
[junit4] 2> 61364 T194 C129 oasu.LoggingInfoStream.message [BD][qtp1478287298-194]: seg=_0(4.5):C10 segGen=5 coalesced deletes=[CoalescedDeletes(termSets=1,queries=1)] newDelCount=10 100% deleted
[junit4] 2> 61364 T194 C129 oasu.LoggingInfoStream.message [BD][qtp1478287298-194]: applyDeletes took 2 msec
[junit4] 2> 61365 T194 C129 oasu.LoggingInfoStream.message [IFD][qtp1478287298-194]: now checkpoint "_0(4.5):C10/10" [1 segments ; isCommit = false]
[junit4] 2> 61365 T194 C129 oasu.LoggingInfoStream.message [IFD][qtp1478287298-194]: 0 msec to checkpoint
[junit4] 2> 61366 T194 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-194]: drop 100% deleted segments: _0(4.5):C10/10
[junit4] 2> 61366 T194 C129 oasu.LoggingInfoStream.message [IFD][qtp1478287298-194]: now checkpoint "" [0 segments ; isCommit = false]
[junit4] 2> 61367 T194 C129 oasu.LoggingInfoStream.message [IFD][qtp1478287298-194]: 0 msec to checkpoint
[junit4] 2> 61367 T194 C129 oasu.LoggingInfoStream.message [BD][qtp1478287298-194]: prune sis=org.apache.lucene.index.SegmentInfos@895772a minGen=9223372036854775807 packetCount=1
[junit4] 2> 61367 T194 C129 oasu.LoggingInfoStream.message [BD][qtp1478287298-194]: pruneDeletes: prune 1 packets; 0 packets remain
[junit4] 2> 61368 T194 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-194]: return reader version=5 reader=StandardDirectoryReader(segments_2:5:nrt)
[junit4] 2> 61368 T194 C129 oasu.LoggingInfoStream.message [DW][qtp1478287298-194]: qtp1478287298-194 finishFullFlush success=true
[junit4] 2> 61369 T194 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-194]: getReader took 10 msec
[junit4] 2> 61369 T194 C129 oass.SolrIndexSearcher.<init> Opening Searcher@15a08be5 realtime
[junit4] 2> 61370 T194 C129 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {deleteByQuery=*:* (-1442872439065280512)} 0 14
[junit4] 2> 61374 T191 C129 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 61374 T191 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-191]: commit: start
[junit4] 2> 61375 T191 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-191]: commit: enter lock
[junit4] 2> 61375 T191 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-191]: commit: now prepare
[junit4] 2> 61376 T191 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-191]: prepareCommit: flush
[junit4] 2> 61376 T191 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-191]: index before flush
[junit4] 2> 61377 T191 C129 oasu.LoggingInfoStream.message [DW][qtp1478287298-191]: qtp1478287298-191 startFullFlush
[junit4] 2> 61377 T191 C129 oasu.LoggingInfoStream.message [DW][qtp1478287298-191]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 61377 T191 C129 oasu.LoggingInfoStream.message [DWFC][qtp1478287298-191]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=null, aborting=false, numDocsInRAM=0, deleteQueue=DWDQ: [ generation: 4 ]]
[junit4] 2> 61378 T191 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-191]: apply all deletes during flush
[junit4] 2> 61378 T191 C129 oasu.LoggingInfoStream.message [BD][qtp1478287298-191]: prune sis=org.apache.lucene.index.SegmentInfos@895772a minGen=9223372036854775807 packetCount=0
[junit4] 2> 61379 T191 C129 oasu.LoggingInfoStream.message [DW][qtp1478287298-191]: qtp1478287298-191 finishFullFlush success=true
[junit4] 2> 61379 T191 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-191]: startCommit(): start
[junit4] 2> 61380 T191 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-191]: startCommit index= changeCount=6
[junit4] 2> 61381 T191 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-191]: done all syncs: []
[junit4] 2> 61381 T191 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-191]: commit: pendingCommit != null
[junit4] 2> 61382 T191 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-191]: commit: wrote segments file "segments_3"
[junit4] 2> 61382 T191 C129 oasu.LoggingInfoStream.message [IFD][qtp1478287298-191]: now checkpoint "" [0 segments ; isCommit = true]
[junit4] 2> 61383 T191 C129 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@6c9d2223 lockFactory=org.apache.lucene.store.NativeFSLockFactory@9c304c7; maxCacheMB=0.9052734375 maxMergeSizeMB=0.8291015625)),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@6c9d2223 lockFactory=org.apache.lucene.store.NativeFSLockFactory@9c304c7; maxCacheMB=0.9052734375 maxMergeSizeMB=0.8291015625)),segFN=segments_3,generation=3}
[junit4] 2> 61383 T191 C129 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4] 2> 61384 T191 C129 oasu.LoggingInfoStream.message [IFD][qtp1478287298-191]: deleteCommits: now decRef commit "segments_2"
[junit4] 2> 61384 T191 C129 oasu.LoggingInfoStream.message [IFD][qtp1478287298-191]: delete "_0.fnm"
[junit4] 2> 61385 T191 C129 oasu.LoggingInfoStream.message [IFD][qtp1478287298-191]: delete "_0_Lucene41_0.doc"
[junit4] 2> 61385 T191 C129 oasu.LoggingInfoStream.message [IFD][qtp1478287298-191]: unable to remove file "_0_Lucene41_0.doc": java.io.IOException: MockDirectoryWrapper: file "_0_Lucene41_0.doc" is still open: cannot delete; Will re-try later.
[junit4] 2> 61386 T191 C129 oasu.LoggingInfoStream.message [IFD][qtp1478287298-191]: delete "_0_Lucene41_0.pos"
[junit4] 2> 61386 T191 C129 oasu.LoggingInfoStream.message [IFD][qtp1478287298-191]: unable to remove file "_0_Lucene41_0.pos": java.io.IOException: MockDirectoryWrapper: file "_0_Lucene41_0.pos" is still open: cannot delete; Will re-try later.
[junit4] 2> 61387 T191 C129 oasu.LoggingInfoStream.message [IFD][qtp1478287298-191]: delete "_0.nvd"
[junit4] 2> 61387 T191 C129 oasu.LoggingInfoStream.message [IFD][qtp1478287298-191]: unable to remove file "_0.nvd": java.io.IOException: MockDirectoryWrapper: file "_0.nvd" is still open: cannot delete; Will re-try later.
[junit4] 2> 61387 T191 C129 oasu.LoggingInfoStream.message [IFD][qtp1478287298-191]: delete "segments_2"
[junit4] 2> 61388 T191 C129 oasu.LoggingInfoStream.message [IFD][qtp1478287298-191]: delete "_0.fdx"
[junit4] 2> 61388 T191 C129 oasu.LoggingInfoStream.message [IFD][qtp1478287298-191]: delete "_0.si"
[junit4] 2> 61389 T191 C129 oasu.LoggingInfoStream.message [IFD][qtp1478287298-191]: delete "_0.nvm"
[junit4] 2> 61389 T191 C129 oasu.LoggingInfoStream.message [IFD][qtp1478287298-191]: delete "_0_Lucene41_0.tim"
[junit4] 2> 61390 T191 C129 oasu.LoggingInfoStream.message [IFD][qtp1478287298-191]: unable to remove file "_0_Lucene41_0.tim": java.io.IOException: MockDirectoryWrapper: file "_0_Lucene41_0.tim" is still open: cannot delete; Will re-try later.
[junit4] 2> 61390 T191 C129 oasu.LoggingInfoStream.message [IFD][qtp1478287298-191]: delete "_0.fdt"
[junit4] 2> 61391 T191 C129 oasu.LoggingInfoStream.message [IFD][qtp1478287298-191]: unable to remove file "_0.fdt": java.io.IOException: MockDirectoryWrapper: file "_0.fdt" is still open: cannot delete; Will re-try later.
[junit4] 2> 61391 T191 C129 oasu.LoggingInfoStream.message [IFD][qtp1478287298-191]: delete "_0_Lucene41_0.tip"
[junit4] 2> 61391 T191 C129 oasu.LoggingInfoStream.message [IFD][qtp1478287298-191]: 9 msec to checkpoint
[junit4] 2> 61392 T191 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-191]: commit: done
[junit4] 2> 61392 T191 C129 oasu.LoggingInfoStream.message [DW][qtp1478287298-191]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 61393 T191 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-191]: nrtIsCurrent: infoVersion matches: true; DW changes: false; BD changes: false
[junit4] 2> 61393 T191 C129 oasu.LoggingInfoStream.message [DW][qtp1478287298-191]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 61394 T191 C129 oass.SolrIndexSearcher.<init> Opening Searcher@65e26e12 main
[junit4] 2> 61394 T191 C129 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 61394 T196 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@65e26e12 main{StandardDirectoryReader(segments_2:5:nrt)}
[junit4] 2> 61395 T196 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 61398 T196 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@65e26e12 main{StandardDirectoryReader(segments_2:5:nrt)}
[junit4] 2> 61398 T196 oasu.LoggingInfoStream.message [IFD][searcherExecutor-84-thread-1]: delete pending file _0_Lucene41_0.doc
[junit4] 2> 61398 T196 oasu.LoggingInfoStream.message [IFD][searcherExecutor-84-thread-1]: delete "_0_Lucene41_0.doc"
[junit4] 2> 61399 T196 oasu.LoggingInfoStream.message [IFD][searcherExecutor-84-thread-1]: delete pending file _0_Lucene41_0.pos
[junit4] 2> 61399 T196 oasu.LoggingInfoStream.message [IFD][searcherExecutor-84-thread-1]: delete "_0_Lucene41_0.pos"
[junit4] 2> 61399 T196 oasu.LoggingInfoStream.message [IFD][searcherExecutor-84-thread-1]: delete pending file _0.nvd
[junit4] 2> 61399 T196 oasu.LoggingInfoStream.message [IFD][searcherExecutor-84-thread-1]: delete "_0.nvd"
[junit4] 2> 61400 T196 oasu.LoggingInfoStream.message [IFD][searcherExecutor-84-thread-1]: delete pending file _0_Lucene41_0.tim
[junit4] 2> 61400 T196 oasu.LoggingInfoStream.message [IFD][searcherExecutor-84-thread-1]: delete "_0_Lucene41_0.tim"
[junit4] 2> 61400 T196 oasu.LoggingInfoStream.message [IFD][searcherExecutor-84-thread-1]: delete pending file _0.fdt
[junit4] 2> 61400 T196 oasu.LoggingInfoStream.message [IFD][searcherExecutor-84-thread-1]: delete "_0.fdt"
[junit4] 2> 61401 T191 C129 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 27
[junit4] 2> 61404 T192 C129 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={q=*:*&wt=javabin&version=2} hits=0 status=0 QTime=0
[junit4] 2> 61431 T193 C129 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 61431 T193 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-193]: commit: start
[junit4] 2> 61432 T193 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-193]: commit: enter lock
[junit4] 2> 61432 T193 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-193]: commit: now prepare
[junit4] 2> 61432 T193 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-193]: prepareCommit: flush
[junit4] 2> 61432 T193 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-193]: index before flush
[junit4] 2> 61433 T193 C129 oasu.LoggingInfoStream.message [DW][qtp1478287298-193]: qtp1478287298-193 startFullFlush
[junit4] 2> 61433 T193 C129 oasu.LoggingInfoStream.message [DW][qtp1478287298-193]: anyChanges? numDocsInRam=5 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 61434 T193 C129 oasu.LoggingInfoStream.message [DWFC][qtp1478287298-193]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0 4 deleted terms (unique count=4) bytesUsed=955, segment=_1, aborting=false, numDocsInRAM=5, deleteQueue=DWDQ: [ generation: 5 ]]
[junit4] 2> 61434 T193 C129 oasu.LoggingInfoStream.message [DWPT][qtp1478287298-193]: flush postings as segment _1 numDocs=5
[junit4] 2> 61448 T193 C129 oasu.LoggingInfoStream.message [DWPT][qtp1478287298-193]: new segment has 0 deleted docs
[junit4] 2> 61448 T193 C129 oasu.LoggingInfoStream.message [DWPT][qtp1478287298-193]: new segment has no vectors; norms; no docValues; prox; freqs
[junit4] 2> 61449 T193 C129 oasu.LoggingInfoStream.message [DWPT][qtp1478287298-193]: flushedFiles=[_1.nvm, _1_Lucene41_0.pos, _1.fdx, _1_Lucene41_0.doc, _1_Lucene41_0.pay, _1.fdt, _1_Lucene41_0.tim, _1.nvd, _1_Lucene41_0.tip, _1.fnm]
[junit4] 2> 61449 T193 C129 oasu.LoggingInfoStream.message [DWPT][qtp1478287298-193]: flushed codec=Lucene42
[junit4] 2> 61450 T193 C129 oasu.LoggingInfoStream.message [DWPT][qtp1478287298-193]: flushed: segment=_1 ramUsed=0.115 MB newFlushedSize(includes docstores)=0.007 MB docs/MB=728.684
[junit4] 2> 61450 T193 C129 oasu.LoggingInfoStream.message [DW][qtp1478287298-193]: publishFlushedSegment seg-private deletes=null
[junit4] 2> 61450 T193 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-193]: publishFlushedSegment
[junit4] 2> 61451 T193 C129 oasu.LoggingInfoStream.message [BD][qtp1478287298-193]: push deletes 5 deleted terms (unique count=5) bytesUsed=1024 delGen=10 packetCount=1 totBytesUsed=1024
[junit4] 2> 61451 T193 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-193]: publish sets newSegment delGen=11 seg=_1(4.5):C5
[junit4] 2> 61452 T193 C129 oasu.LoggingInfoStream.message [IFD][qtp1478287298-193]: now checkpoint "_1(4.5):C5" [1 segments ; isCommit = false]
[junit4] 2> 61452 T193 C129 oasu.LoggingInfoStream.message [IFD][qtp1478287298-193]: 0 msec to checkpoint
[junit4] 2> 61452 T193 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-193]: apply all deletes during flush
[junit4] 2> 61452 T193 C129 oasu.LoggingInfoStream.message [BD][qtp1478287298-193]: applyDeletes: infos=[_1(4.5):C5] packetCount=1
[junit4] 2> 61453 T193 C129 oasu.LoggingInfoStream.message [BD][qtp1478287298-193]: applyDeletes took 1 msec
[junit4] 2> 61453 T193 C129 oasu.LoggingInfoStream.message [BD][qtp1478287298-193]: prune sis=org.apache.lucene.index.SegmentInfos@895772a minGen=12 packetCount=1
[junit4] 2> 61453 T193 C129 oasu.LoggingInfoStream.message [BD][qtp1478287298-193]: pruneDeletes: prune 1 packets; 0 packets remain
[junit4] 2> 61454 T193 C129 oasu.LoggingInfoStream.message [DW][qtp1478287298-193]: qtp1478287298-193 finishFullFlush success=true
[junit4] 2> 61454 T193 C129 oasu.LoggingInfoStream.message [TMP][qtp1478287298-193]: findMerges: 1 segments
[junit4] 2> 61455 T193 C129 oasu.LoggingInfoStream.message [TMP][qtp1478287298-193]: seg=_1(4.5):C5 size=0.007 MB [floored]
[junit4] 2> 61455 T193 C129 oasu.LoggingInfoStream.message [TMP][qtp1478287298-193]: allowedSegmentCount=1 vs count=1 (eligible count=1) tooBigCount=0
[junit4] 2> 61455 T193 C129 oasu.LoggingInfoStream.message [CMS][qtp1478287298-193]: now merge
[junit4] 2> 61455 T193 C129 oasu.LoggingInfoStream.message [CMS][qtp1478287298-193]: index: _1(4.5):C5
[junit4] 2> 61456 T193 C129 oasu.LoggingInfoStream.message [CMS][qtp1478287298-193]: no more merges pending; now return
[junit4] 2> 61456 T193 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-193]: startCommit(): start
[junit4] 2> 61456 T193 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-193]: startCommit index=_1(4.5):C5 changeCount=9
[junit4] 2> 61457 T193 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-193]: done all syncs: [_1.fdx, _1_Lucene41_0.pos, _1.nvm, _1_Lucene41_0.doc, _1.fdt, _1_Lucene41_0.pay, _1.si, _1_Lucene41_0.tim, _1.nvd, _1_Lucene41_0.tip, _1.fnm]
[junit4] 2> 61457 T193 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-193]: commit: pendingCommit != null
[junit4] 2> 61458 T193 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-193]: commit: wrote segments file "segments_4"
[junit4] 2> 61458 T193 C129 oasu.LoggingInfoStream.message [IFD][qtp1478287298-193]: now checkpoint "_1(4.5):C5" [1 segments ; isCommit = true]
[junit4] 2> 61459 T193 C129 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@6c9d2223 lockFactory=org.apache.lucene.store.NativeFSLockFactory@9c304c7; maxCacheMB=0.9052734375 maxMergeSizeMB=0.8291015625)),segFN=segments_3,generation=3}
[junit4] 2> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@6c9d2223 lockFactory=org.apache.lucene.store.NativeFSLockFactory@9c304c7; maxCacheMB=0.9052734375 maxMergeSizeMB=0.8291015625)),segFN=segments_4,generation=4}
[junit4] 2> 61459 T193 C129 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 4
[junit4] 2> 61459 T193 C129 oasu.LoggingInfoStream.message [IFD][qtp1478287298-193]: deleteCommits: now decRef commit "segments_3"
[junit4] 2> 61459 T193 C129 oasu.LoggingInfoStream.message [IFD][qtp1478287298-193]: delete "segments_3"
[junit4] 2> 61460 T193 C129 oasu.LoggingInfoStream.message [IFD][qtp1478287298-193]: 1 msec to checkpoint
[junit4] 2> 61460 T193 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-193]: commit: done
[junit4] 2> 61460 T193 C129 oasu.LoggingInfoStream.message [DW][qtp1478287298-193]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 61461 T193 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-193]: nrtIsCurrent: infoVersion matches: false; DW changes: false; BD changes: false
[junit4] 2> 61461 T193 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-193]: flush at getReader
[junit4] 2> 61461 T193 C129 oasu.LoggingInfoStream.message [DW][qtp1478287298-193]: qtp1478287298-193 startFullFlush
[junit4] 2> 61462 T193 C129 oasu.LoggingInfoStream.message [DW][qtp1478287298-193]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 61462 T193 C129 oasu.LoggingInfoStream.message [DWFC][qtp1478287298-193]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=null, aborting=false, numDocsInRAM=0, deleteQueue=DWDQ: [ generation: 6 ]]
[junit4] 2> 61462 T193 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-193]: apply all deletes during flush
[junit4] 2> 61463 T193 C129 oasu.LoggingInfoStream.message [BD][qtp1478287298-193]: applyDeletes: no deletes; skipping
[junit4] 2> 61463 T193 C129 oasu.LoggingInfoStream.message [BD][qtp1478287298-193]: prune sis=org.apache.lucene.index.SegmentInfos@895772a minGen=12 packetCount=0
[junit4] 2> 61465 T193 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-193]: return reader version=7 reader=StandardDirectoryReader(segments_4:7:nrt _1(4.5):C5)
[junit4] 2> 61465 T193 C129 oasu.LoggingInfoStream.message [DW][qtp1478287298-193]: qtp1478287298-193 finishFullFlush success=true
[junit4] 2> 61466 T193 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-193]: getReader took 5 msec
[junit4] 2> 61466 T193 C129 oass.SolrIndexSearcher.<init> Opening Searcher@69c78571 main
[junit4] 2> 61467 T193 C129 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 61467 T196 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@69c78571 main{StandardDirectoryReader(segments_4:7:nrt _1(4.5):C5)}
[junit4] 2> 61467 T196 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 61471 T196 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@69c78571 main{StandardDirectoryReader(segments_4:7:nrt _1(4.5):C5)}
[junit4] 2> 61472 T193 C129 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={waitSearcher=true&echoParams=ALL&commit=true&a=ሴ&wt=javabin&version=2&softCommit=false} {add=[SP2514N (1442872439124000768), 6H500F0 (1442872439129243648), TWINX2048-3200PRO (1442872439133437952), VS1GB400C3 (1442872439137632256), VDBDB1A16 (1442872439139729408)],commit=} 0 60
[junit4] 2> 61476 T191 C129 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={q=*:*&wt=javabin&version=2} hits=5 status=0 QTime=0
[junit4] 2> 61480 T185 oas.SolrTestCaseJ4.tearDown ###Ending testMultiContentStreamRequest
[junit4] 2> 61507 T185 oas.SolrTestCaseJ4.setUp ###Starting testPingHandler
[junit4] 2> 61511 T192 C129 oasu.LoggingInfoStream.message [DW][qtp1478287298-192]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 61511 T192 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-192]: nrtIsCurrent: infoVersion matches: true; DW changes: true; BD changes: false
[junit4] 2> 61512 T192 C129 oasu.LoggingInfoStream.message [DW][qtp1478287298-192]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 61512 T192 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-192]: flush at getReader
[junit4] 2> 61512 T192 C129 oasu.LoggingInfoStream.message [DW][qtp1478287298-192]: qtp1478287298-192 startFullFlush
[junit4] 2> 61513 T192 C129 oasu.LoggingInfoStream.message [DW][qtp1478287298-192]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 61513 T192 C129 oasu.LoggingInfoStream.message [DWFC][qtp1478287298-192]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=null, aborting=false, numDocsInRAM=0, deleteQueue=DWDQ: [ generation: 7 ]]
[junit4] 2> 61514 T192 C129 oasu.LoggingInfoStream.message [DW][qtp1478287298-192]: qtp1478287298-192: flush naked frozen global deletes
[junit4] 2> 61514 T192 C129 oasu.LoggingInfoStream.message [BD][qtp1478287298-192]: push deletes 1 deleted queries bytesUsed=36 delGen=14 packetCount=1 totBytesUsed=36
[junit4] 2> 61514 T192 C129 oasu.LoggingInfoStream.message [DW][qtp1478287298-192]: flush: push buffered deletes: 1 deleted queries bytesUsed=36
[junit4] 2> 61515 T192 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-192]: apply all deletes during flush
[junit4] 2> 61515 T192 C129 oasu.LoggingInfoStream.message [BD][qtp1478287298-192]: applyDeletes: infos=[_1(4.5):C5] packetCount=1
[junit4] 2> 61516 T192 C129 oasu.LoggingInfoStream.message [BD][qtp1478287298-192]: seg=_1(4.5):C5 segGen=12 coalesced deletes=[CoalescedDeletes(termSets=1,queries=1)] newDelCount=5 100% deleted
[junit4] 2> 61516 T192 C129 oasu.LoggingInfoStream.message [BD][qtp1478287298-192]: applyDeletes took 1 msec
[junit4] 2> 61516 T192 C129 oasu.LoggingInfoStream.message [IFD][qtp1478287298-192]: now checkpoint "_1(4.5):C5/5" [1 segments ; isCommit = false]
[junit4] 2> 61517 T192 C129 oasu.LoggingInfoStream.message [IFD][qtp1478287298-192]: 0 msec to checkpoint
[junit4] 2> 61517 T192 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-192]: drop 100% deleted segments: _1(4.5):C5/5
[junit4] 2> 61517 T192 C129 oasu.LoggingInfoStream.message [IFD][qtp1478287298-192]: now checkpoint "" [0 segments ; isCommit = false]
[junit4] 2> 61518 T192 C129 oasu.LoggingInfoStream.message [IFD][qtp1478287298-192]: 0 msec to checkpoint
[junit4] 2> 61518 T192 C129 oasu.LoggingInfoStream.message [BD][qtp1478287298-192]: prune sis=org.apache.lucene.index.SegmentInfos@895772a minGen=9223372036854775807 packetCount=1
[junit4] 2> 61518 T192 C129 oasu.LoggingInfoStream.message [BD][qtp1478287298-192]: pruneDeletes: prune 1 packets; 0 packets remain
[junit4] 2> 61519 T192 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-192]: return reader version=9 reader=StandardDirectoryReader(segments_4:9:nrt)
[junit4] 2> 61519 T192 C129 oasu.LoggingInfoStream.message [DW][qtp1478287298-192]: qtp1478287298-192 finishFullFlush success=true
[junit4] 2> 61519 T192 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-192]: getReader took 7 msec
[junit4] 2> 61520 T192 C129 oass.SolrIndexSearcher.<init> Opening Searcher@5a86506a realtime
[junit4] 2> 61520 T192 C129 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {deleteByQuery=*:* (-1442872439225712640)} 0 10
[junit4] 2> 61524 T193 C129 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 61524 T193 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-193]: commit: start
[junit4] 2> 61524 T193 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-193]: commit: enter lock
[junit4] 2> 61525 T193 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-193]: commit: now prepare
[junit4] 2> 61525 T193 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-193]: prepareCommit: flush
[junit4] 2> 61525 T193 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-193]: index before flush
[junit4] 2> 61526 T193 C129 oasu.LoggingInfoStream.message [DW][qtp1478287298-193]: qtp1478287298-193 startFullFlush
[junit4] 2> 61526 T193 C129 oasu.LoggingInfoStream.message [DW][qtp1478287298-193]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 61526 T193 C129 oasu.LoggingInfoStream.message [DWFC][qtp1478287298-193]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=null, aborting=false, numDocsInRAM=0, deleteQueue=DWDQ: [ generation: 8 ]]
[junit4] 2> 61526 T193 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-193]: apply all deletes during flush
[junit4] 2> 61527 T193 C129 oasu.LoggingInfoStream.message [BD][qtp1478287298-193]: prune sis=org.apache.lucene.index.SegmentInfos@895772a minGen=9223372036854775807 packetCount=0
[junit4] 2> 61527 T193 C129 oasu.LoggingInfoStream.message [DW][qtp1478287298-193]: qtp1478287298-193 finishFullFlush success=true
[junit4] 2> 61527 T193 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-193]: startCommit(): start
[junit4] 2> 61528 T193 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-193]: startCommit index= changeCount=12
[junit4] 2> 61528 T193 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-193]: done all syncs: []
[junit4] 2> 61528 T193 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-193]: commit: pendingCommit != null
[junit4] 2> 61529 T193 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-193]: commit: wrote segments file "segments_5"
[junit4] 2> 61529 T193 C129 oasu.LoggingInfoStream.message [IFD][qtp1478287298-193]: now checkpoint "" [0 segments ; isCommit = true]
[junit4] 2> 61530 T193 C129 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@6c9d2223 lockFactory=org.apache.lucene.store.NativeFSLockFactory@9c304c7; maxCacheMB=0.9052734375 maxMergeSizeMB=0.8291015625)),segFN=segments_4,generation=4}
[junit4] 2> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@6c9d2223 lockFactory=org.apache.lucene.store.NativeFSLockFactory@9c304c7; maxCacheMB=0.9052734375 maxMergeSizeMB=0.8291015625)),segFN=segments_5,generation=5}
[junit4] 2> 61530 T193 C129 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 5
[junit4] 2> 61530 T193 C129 oasu.LoggingInfoStream.message [IFD][qtp1478287298-193]: deleteCommits: now decRef commit "segments_4"
[junit4] 2> 61530 T193 C129 oasu.LoggingInfoStream.message [IFD][qtp1478287298-193]: delete "_1.fdx"
[junit4] 2> 61531 T193 C129 oasu.LoggingInfoStream.message [IFD][qtp1478287298-193]: delete "_1_Lucene41_0.pos"
[junit4] 2> 61531 T193 C129 oasu.LoggingInfoStream.message [IFD][qtp1478287298-193]: unable to remove file "_1_Lucene41_0.pos": java.io.IOException: MockDirectoryWrapper: file "_1_Lucene41_0.pos" is still open: cannot delete; Will re-try later.
[junit4] 2> 61531 T193 C129 oasu.LoggingInfoStream.message [IFD][qtp1478287298-193]: delete "_1.nvm"
[junit4] 2> 61532 T193 C129 oasu.LoggingInfoStream.message [IFD][qtp1478287298-193]: delete "_1_Lucene41_0.doc"
[junit4] 2> 61532 T193 C129 oasu.LoggingInfoStream.message [IFD][qtp1478287298-193]: unable to remove file "_1_Lucene41_0.doc": java.io.IOException: MockDirectoryWrapper: file "_1_Lucene41_0.doc" is still open: cannot delete; Will re-try later.
[junit4] 2> 61532 T193 C129 oasu.LoggingInfoStream.message [IFD][qtp1478287298-193]: delete "_1.fdt"
[junit4] 2> 61533 T193 C129 oasu.LoggingInfoStream.message [IFD][qtp1478287298-193]: unable to remove file "_1.fdt": java.io.IOException: MockDirectoryWrapper: file "_1.fdt" is still open: cannot delete; Will re-try later.
[junit4] 2> 61533 T193 C129 oasu.LoggingInfoStream.message [IFD][qtp1478287298-193]: delete "_1_Lucene41_0.pay"
[junit4] 2> 61533 T193 C129 oasu.LoggingInfoStream.message [IFD][qtp1478287298-193]: unable to remove file "_1_Lucene41_0.pay": java.io.IOException: MockDirectoryWrapper: file "_1_Lucene41_0.pay" is still open: cannot delete; Will re-try later.
[junit4] 2> 61534 T193 C129 oasu.LoggingInfoStream.message [IFD][qtp1478287298-193]: delete "_1.si"
[junit4] 2> 61534 T193 C129 oasu.LoggingInfoStream.message [IFD][qtp1478287298-193]: delete "_1_Lucene41_0.tim"
[junit4] 2> 61534 T193 C129 oasu.LoggingInfoStream.message [IFD][qtp1478287298-193]: unable to remove file "_1_Lucene41_0.tim": java.io.IOException: MockDirectoryWrapper: file "_1_Lucene41_0.tim" is still open: cannot delete; Will re-try later.
[junit4] 2> 61535 T193 C129 oasu.LoggingInfoStream.message [IFD][qtp1478287298-193]: delete "_1.nvd"
[junit4] 2> 61535 T193 C129 oasu.LoggingInfoStream.message [IFD][qtp1478287298-193]: unable to remove file "_1.nvd": java.io.IOException: MockDirectoryWrapper: file "_1.nvd" is still open: cannot delete; Will re-try later.
[junit4] 2> 61535 T193 C129 oasu.LoggingInfoStream.message [IFD][qtp1478287298-193]: delete "_1_Lucene41_0.tip"
[junit4] 2> 61536 T193 C129 oasu.LoggingInfoStream.message [IFD][qtp1478287298-193]: delete "_1.fnm"
[junit4] 2> 61536 T193 C129 oasu.LoggingInfoStream.message [IFD][qtp1478287298-193]: delete "segments_4"
[junit4] 2> 61536 T193 C129 oasu.LoggingInfoStream.message [IFD][qtp1478287298-193]: 6 msec to checkpoint
[junit4] 2> 61536 T193 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-193]: commit: done
[junit4] 2> 61537 T193 C129 oasu.LoggingInfoStream.message [DW][qtp1478287298-193]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 61537 T193 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-193]: nrtIsCurrent: infoVersion matches: true; DW changes: false; BD changes: false
[junit4] 2> 61537 T193 C129 oasu.LoggingInfoStream.message [DW][qtp1478287298-193]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 61538 T193 C129 oass.SolrIndexSearcher.<init> Opening Searcher@2e45105c main
[junit4] 2> 61538 T193 C129 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 61538 T196 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@2e45105c main{StandardDirectoryReader(segments_4:9:nrt)}
[junit4] 2> 61539 T196 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 61542 T196 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2e45105c main{StandardDirectoryReader(segments_4:9:nrt)}
[junit4] 2> 61543 T196 oasu.LoggingInfoStream.message [IFD][searcherExecutor-84-thread-1]: delete pending file _1_Lucene41_0.pos
[junit4] 2> 61544 T196 oasu.LoggingInfoStream.message [IFD][searcherExecutor-84-thread-1]: delete "_1_Lucene41_0.pos"
[junit4] 2> 61544 T196 oasu.LoggingInfoStream.message [IFD][searcherExecutor-84-thread-1]: delete pending file _1_Lucene41_0.doc
[junit4] 2> 61544 T196 oasu.LoggingInfoStream.message [IFD][searcherExecutor-84-thread-1]: delete "_1_Lucene41_0.doc"
[junit4] 2> 61545 T196 oasu.LoggingInfoStream.message [IFD][searcherExecutor-84-thread-1]: delete pending file _1.fdt
[junit4] 2> 61545 T196 oasu.LoggingInfoStream.message [IFD][searcherExecutor-84-thread-1]: delete "_1.fdt"
[junit4] 2> 61545 T196 oasu.LoggingInfoStream.message [IFD][searcherExecutor-84-thread-1]: delete pending file _1_Lucene41_0.pay
[junit4] 2> 61545 T196 oasu.LoggingInfoStream.message [IFD][searcherExecutor-84-thread-1]: delete "_1_Lucene41_0.pay"
[junit4] 2> 61546 T196 oasu.LoggingInfoStream.message [IFD][searcherExecutor-84-thread-1]: delete pending file _1_Lucene41_0.tim
[junit4] 2> 61546 T196 oasu.LoggingInfoStream.message [IFD][searcherExecutor-84-thread-1]: delete "_1_Lucene41_0.tim"
[junit4] 2> 61546 T196 oasu.LoggingInfoStream.message [IFD][searcherExecutor-84-thread-1]: delete pending file _1.nvd
[junit4] 2> 61546 T196 oasu.LoggingInfoStream.message [IFD][searcherExecutor-84-thread-1]: delete "_1.nvd"
[junit4] 2> 61547 T193 C129 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 23
[junit4] 2> 61550 T191 C129 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={q=*:*&wt=javabin&version=2} hits=0 status=0 QTime=0
[junit4] 2> 61554 T192 C129 oasc.SolrCore.execute [collection1] webapp=/solr path=/admin/ping params={wt=javabin&version=2} hits=0 status=0 QTime=1
[junit4] 2> 61555 T192 C129 oasc.SolrCore.execute [collection1] webapp=/solr path=/admin/ping params={wt=javabin&version=2} status=0 QTime=2
[junit4] 2> 61556 T185 oas.SolrTestCaseJ4.tearDown ###Ending testPingHandler
[junit4] 2> 61568 T185 oas.SolrTestCaseJ4.setUp ###Starting testAddRetrieve
[junit4] 2> 61572 T194 C129 oasu.LoggingInfoStream.message [DW][qtp1478287298-194]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 61573 T194 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-194]: nrtIsCurrent: infoVersion matches: true; DW changes: true; BD changes: false
[junit4] 2> 61573 T194 C129 oasu.LoggingInfoStream.message [DW][qtp1478287298-194]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 61573 T194 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-194]: flush at getReader
[junit4] 2> 61574 T194 C129 oasu.LoggingInfoStream.message [DW][qtp1478287298-194]: qtp1478287298-194 startFullFlush
[junit4] 2> 61574 T194 C129 oasu.LoggingInfoStream.message [DW][qtp1478287298-194]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 61575 T194 C129 oasu.LoggingInfoStream.message [DWFC][qtp1478287298-194]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=null, aborting=false, numDocsInRAM=0, deleteQueue=DWDQ: [ generation: 9 ]]
[junit4] 2> 61575 T194 C129 oasu.LoggingInfoStream.message [DW][qtp1478287298-194]: qtp1478287298-194: flush naked frozen global deletes
[junit4] 2> 61576 T194 C129 oasu.LoggingInfoStream.message [BD][qtp1478287298-194]: push deletes 1 deleted queries bytesUsed=36 delGen=17 packetCount=1 totBytesUsed=36
[junit4] 2> 61576 T194 C129 oasu.LoggingInfoStream.message [DW][qtp1478287298-194]: flush: push buffered deletes: 1 deleted queries bytesUsed=36
[junit4] 2> 61577 T194 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-194]: apply all deletes during flush
[junit4] 2> 61577 T194 C129 oasu.LoggingInfoStream.message [BD][qtp1478287298-194]: prune sis=org.apache.lucene.index.SegmentInfos@895772a minGen=9223372036854775807 packetCount=1
[junit4] 2> 61578 T194 C129 oasu.LoggingInfoStream.message [BD][qtp1478287298-194]: pruneDeletes: prune 1 packets; 0 packets remain
[junit4] 2> 61578 T194 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-194]: return reader version=9 reader=StandardDirectoryReader(segments_5:9:nrt)
[junit4] 2> 61578 T194 C129 oasu.LoggingInfoStream.message [DW][qtp1478287298-194]: qtp1478287298-194 finishFullFlush success=true
[junit4] 2> 61579 T194 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-194]: getReader took 6 msec
[junit4] 2> 61580 T194 C129 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {deleteByQuery=*:* (-1442872439289675776)} 0 9
[junit4] 2> 61585 T193 C129 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[id1 (1442872439302258688), id2 (1442872439303307264)]} 0 2
[junit4] 2> 61588 T191 C129 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 61589 T191 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-191]: commit: start
[junit4] 2> 61589 T191 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-191]: commit: enter lock
[junit4] 2> 61590 T191 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-191]: commit: now prepare
[junit4] 2> 61590 T191 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-191]: prepareCommit: flush
[junit4] 2> 61590 T191 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-191]: index before flush
[junit4] 2> 61591 T191 C129 oasu.LoggingInfoStream.message [DW][qtp1478287298-191]: qtp1478287298-191 startFullFlush
[junit4] 2> 61591 T191 C129 oasu.LoggingInfoStream.message [DW][qtp1478287298-191]: anyChanges? numDocsInRam=2 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 61592 T191 C129 oasu.LoggingInfoStream.message [DWFC][qtp1478287298-191]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0 1 deleted terms (unique count=1) bytesUsed=231, segment=_2, aborting=false, numDocsInRAM=2, deleteQueue=DWDQ: [ generation: 10 ]]
[junit4] 2> 61592 T191 C129 oasu.LoggingInfoStream.message [DWPT][qtp1478287298-191]: flush postings as segment _2 numDocs=2
[junit4] 2> 61596 T191 C129 oasu.LoggingInfoStream.message [DWPT][qtp1478287298-191]: new segment has 0 deleted docs
[junit4] 2> 61597 T191 C129 oasu.LoggingInfoStream.message [DWPT][qtp1478287298-191]: new segment has no vectors; norms; no docValues; prox; freqs
[junit4] 2> 61597 T191 C129 oasu.LoggingInfoStream.message [DWPT][qtp1478287298-191]: flushedFiles=[_2_Lucene41_0.pos, _2.nvm, _2_Lucene41_0.tim, _2.nvd, _2.fdt, _2_Lucene41_0.doc, _2_Lucene41_0.tip, _2.fdx, _2.fnm]
[junit4] 2> 61598 T191 C129 oasu.LoggingInfoStream.message [DWPT][qtp1478287298-191]: flushed codec=Lucene42
[junit4] 2> 61599 T191 C129 oasu.LoggingInfoStream.message [DWPT][qtp1478287298-191]: flushed: segment=_2 ramUsed=0.08 MB newFlushedSize(includes docstores)=0.002 MB docs/MB=1,252.779
[junit4] 2> 61599 T191 C129 oasu.LoggingInfoStream.message [DW][qtp1478287298-191]: publishFlushedSegment seg-private deletes=null
[junit4] 2> 61600 T191 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-191]: publishFlushedSegment
[junit4] 2> 61600 T191 C129 oasu.LoggingInfoStream.message [BD][qtp1478287298-191]: push deletes 2 deleted terms (unique count=2) bytesUsed=1024 delGen=19 packetCount=1 totBytesUsed=1024
[junit4] 2> 61601 T191 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-191]: publish sets newSegment delGen=20 seg=_2(4.5):C2
[junit4] 2> 61601 T191 C129 oasu.LoggingInfoStream.message [IFD][qtp1478287298-191]: now checkpoint "_2(4.5):C2" [1 segments ; isCommit = false]
[junit4] 2> 61602 T191 C129 oasu.LoggingInfoStream.message [IFD][qtp1478287298-191]: 0 msec to checkpoint
[junit4] 2> 61602 T191 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-191]: apply all deletes during flush
[junit4] 2> 61603 T191 C129 oasu.LoggingInfoStream.message [BD][qtp1478287298-191]: applyDeletes: infos=[_2(4.5):C2] packetCount=1
[junit4] 2> 61603 T191 C129 oasu.LoggingInfoStream.message [BD][qtp1478287298-191]: applyDeletes took 0 msec
[junit4] 2> 61603 T191 C129 oasu.LoggingInfoStream.message [BD][qtp1478287298-191]: prune sis=org.apache.lucene.index.SegmentInfos@895772a minGen=21 packetCount=1
[junit4] 2> 61604 T191 C129 oasu.LoggingInfoStream.message [BD][qtp1478287298-191]: pruneDeletes: prune 1 packets; 0 packets remain
[junit4] 2> 61604 T191 C129 oasu.LoggingInfoStream.message [DW][qtp1478287298-191]: qtp1478287298-191 finishFullFlush success=true
[junit4] 2> 61605 T191 C129 oasu.LoggingInfoStream.message [TMP][qtp1478287298-191]: findMerges: 1 segments
[junit4] 2> 61605 T191 C129 oasu.LoggingInfoStream.message [TMP][qtp1478287298-191]: seg=_2(4.5):C2 size=0.001 MB [floored]
[junit4] 2> 61606 T191 C129 oasu.LoggingInfoStream.message [TMP][qtp1478287298-191]: allowedSegmentCount=1 vs count=1 (eligible count=1) tooBigCount=0
[junit4] 2> 61606 T191 C129 oasu.LoggingInfoStream.message [CMS][qtp1478287298-191]: now merge
[junit4] 2> 61607 T191 C129 oasu.LoggingInfoStream.message [CMS][qtp1478287298-191]: index: _2(4.5):C2
[junit4] 2> 61607 T191 C129 oasu.LoggingInfoStream.message [CMS][qtp1478287298-191]: no more merges pending; now return
[junit4] 2> 61608 T191 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-191]: startCommit(): start
[junit4] 2> 61608 T191 C129 oasu.LoggingInfoStream.message [IW][qtp1478287298-191]: startCommit inde
[...truncated too long message...]
=/solr path=/get params={id=DOCID&fl=id,name,aaa:[value+v%3Daaa]&wt=xml&qt=/get&version=2.2} status=0 QTime=0
[junit4] 2> 268124 T185 oas.SolrTestCaseJ4.tearDown ###Ending testRealtimeGet
[junit4] 2> 268163 T185 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=714996484
[junit4] 2> 268164 T185 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@6944ffa4
[junit4] 2> 268183 T185 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=62,autocommit maxTime=15000ms,autocommits=1,soft autocommits=3,optimizes=2,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=1,cumulative_adds=213,cumulative_deletesById=5,cumulative_deletesByQuery=32,cumulative_errors=1}
[junit4] 2> 268184 T185 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 268184 T185 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 268185 T185 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 268185 T185 C134 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[D959E841EEE15DBA]-worker]: now flush at close waitForMerges=true
[junit4] 2> 268185 T185 C134 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[D959E841EEE15DBA]-worker]: start flush: applyAllDeletes=true
[junit4] 2> 268186 T185 C134 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[D959E841EEE15DBA]-worker]: index before flush _1a(4.5):C1
[junit4] 2> 268186 T185 C134 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleJettyTest-seed#[D959E841EEE15DBA]-worker]: SUITE-SolrExampleJettyTest-seed#[D959E841EEE15DBA]-worker startFullFlush
[junit4] 2> 268186 T185 C134 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleJettyTest-seed#[D959E841EEE15DBA]-worker]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 268187 T185 C134 oasu.LoggingInfoStream.message [DWFC][SUITE-SolrExampleJettyTest-seed#[D959E841EEE15DBA]-worker]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=null, aborting=false, numDocsInRAM=0, deleteQueue=DWDQ: [ generation: 140 ]]
[junit4] 2> 268187 T185 C134 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleJettyTest-seed#[D959E841EEE15DBA]-worker]: SUITE-SolrExampleJettyTest-seed#[D959E841EEE15DBA]-worker finishFullFlush success=true
[junit4] 2> 268187 T185 C134 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[D959E841EEE15DBA]-worker]: apply all deletes during flush
[junit4] 2> 268188 T185 C134 oasu.LoggingInfoStream.message [BD][SUITE-SolrExampleJettyTest-seed#[D959E841EEE15DBA]-worker]: applyDeletes: no deletes; skipping
[junit4] 2> 268188 T185 C134 oasu.LoggingInfoStream.message [BD][SUITE-SolrExampleJettyTest-seed#[D959E841EEE15DBA]-worker]: prune sis=org.apache.lucene.index.SegmentInfos@895772a minGen=263 packetCount=0
[junit4] 2> 268188 T185 C134 oasu.LoggingInfoStream.message [CMS][SUITE-SolrExampleJettyTest-seed#[D959E841EEE15DBA]-worker]: now merge
[junit4] 2> 268189 T185 C134 oasu.LoggingInfoStream.message [CMS][SUITE-SolrExampleJettyTest-seed#[D959E841EEE15DBA]-worker]: index: _1a(4.5):C1
[junit4] 2> 268189 T185 C134 oasu.LoggingInfoStream.message [CMS][SUITE-SolrExampleJettyTest-seed#[D959E841EEE15DBA]-worker]: no more merges pending; now return
[junit4] 2> 268189 T185 C134 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[D959E841EEE15DBA]-worker]: waitForMerges
[junit4] 2> 268189 T185 C134 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[D959E841EEE15DBA]-worker]: waitForMerges done
[junit4] 2> 268190 T185 C134 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[D959E841EEE15DBA]-worker]: now call final commit()
[junit4] 2> 268190 T185 C134 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[D959E841EEE15DBA]-worker]: commit: start
[junit4] 2> 268190 T185 C134 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[D959E841EEE15DBA]-worker]: commit: enter lock
[junit4] 2> 268191 T185 C134 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[D959E841EEE15DBA]-worker]: commit: now prepare
[junit4] 2> 268191 T185 C134 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[D959E841EEE15DBA]-worker]: prepareCommit: flush
[junit4] 2> 268191 T185 C134 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[D959E841EEE15DBA]-worker]: index before flush _1a(4.5):C1
[junit4] 2> 268191 T185 C134 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleJettyTest-seed#[D959E841EEE15DBA]-worker]: SUITE-SolrExampleJettyTest-seed#[D959E841EEE15DBA]-worker startFullFlush
[junit4] 2> 268192 T185 C134 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleJettyTest-seed#[D959E841EEE15DBA]-worker]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 268192 T185 C134 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[D959E841EEE15DBA]-worker]: apply all deletes during flush
[junit4] 2> 268192 T185 C134 oasu.LoggingInfoStream.message [BD][SUITE-SolrExampleJettyTest-seed#[D959E841EEE15DBA]-worker]: applyDeletes: no deletes; skipping
[junit4] 2> 268193 T185 C134 oasu.LoggingInfoStream.message [BD][SUITE-SolrExampleJettyTest-seed#[D959E841EEE15DBA]-worker]: prune sis=org.apache.lucene.index.SegmentInfos@895772a minGen=263 packetCount=0
[junit4] 2> 268193 T185 C134 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleJettyTest-seed#[D959E841EEE15DBA]-worker]: SUITE-SolrExampleJettyTest-seed#[D959E841EEE15DBA]-worker finishFullFlush success=true
[junit4] 2> 268193 T185 C134 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[D959E841EEE15DBA]-worker]: startCommit(): start
[junit4] 2> 268194 T185 C134 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[D959E841EEE15DBA]-worker]: skip startCommit(): no changes pending
[junit4] 2> 268194 T185 C134 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[D959E841EEE15DBA]-worker]: commit: pendingCommit == null; skip
[junit4] 2> 268194 T185 C134 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[D959E841EEE15DBA]-worker]: commit: done
[junit4] 2> 268195 T185 C134 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[D959E841EEE15DBA]-worker]: at close: _1a(4.5):C1
[junit4] 2> 268196 T185 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 268196 T185 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 268196 T185 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J1/solrtest-SolrExampleJettyTest-1376030385208 [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J1/solrtest-SolrExampleJettyTest-1376030385208;done=false>>]
[junit4] 2> 268197 T185 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J1/solrtest-SolrExampleJettyTest-1376030385208
[junit4] 2> 268197 T185 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J1/solrtest-SolrExampleJettyTest-1376030385208/index [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J1/solrtest-SolrExampleJettyTest-1376030385208/index;done=false>>]
[junit4] 2> 268197 T185 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J1/solrtest-SolrExampleJettyTest-1376030385208/index
[junit4] 2> 268198 T185 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4] 2> 268248 T185 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: test params are: codec=Lucene42: {}, docValues:{}, sim=DefaultSimilarity, locale=ar_KW, timezone=Etc/GMT-8
[junit4] 2> NOTE: Linux 3.2.0-51-generic amd64/Sun Microsystems Inc. 1.6.0_45 (64-bit)/cpus=8,threads=1,free=99984600,total=160628736
[junit4] 2> NOTE: All tests run in this JVM: [FacetFieldTest, TestLBHttpSolrServer, TestNamedListCodec, SolrExampleBinaryTest, SolrExampleJettyTest]
[junit4] Completed on J1 in 208.73s, 27 tests, 1 error <<< FAILURES!
[...truncated 28 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:395: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:375: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build.xml:194: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/common-build.xml:449: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:1233: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:876: There were test failures: 46 suites, 272 tests, 1 error
Total time: 46 minutes 44 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.6.0_45 -XX:-UseCompressedOops -XX:+UseParallelGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure