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/07/31 19:53:21 UTC
[JENKINS] Lucene-Solr-trunk-Linux (64bit/ibm-j9-jdk7) - Build #
6816 - Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/6816/
Java: 64bit/ibm-j9-jdk7 -Xjit:exclude={org/apache/lucene/util/fst/FST.pack(IIF)Lorg/apache/lucene/util/fst/FST;}
1 tests failed.
REGRESSION: org.apache.solr.client.solrj.SolrExampleXMLTest.testStatistics
Error Message:
IOException occured when talking to server at: https://127.0.0.1:38319/solr/collection1
Stack Trace:
org.apache.solr.client.solrj.SolrServerException: IOException occured when talking to server at: https://127.0.0.1:38319/solr/collection1
at __randomizedtesting.SeedInfo.seed([B111E977CF0EDEE7:46B8DA136323040F]: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:846)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:88)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:55)
at java.lang.reflect.Method.invoke(Method.java:613)
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:780)
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 10747 lines...]
[junit4] Suite: org.apache.solr.client.solrj.SolrExampleXMLTest
[junit4] 2> 15374 T35 oas.SolrJettyTestBase.beforeSolrJettyTestBase Randomized ssl (true) and clientAuth (false)
[junit4] 2> 15375 T35 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-solrj/test/J0/./solrtest-SolrExampleXMLTest-1375292977274
[junit4] 2> 15376 T35 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 15600 T35 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 16758 T35 oejus.SslContextFactory.doStart Enabled Protocols [TLSv1] of [SSLv3, TLSv1, TLSv1.1, TLSv1.2]
[junit4] 2> 16810 T35 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:38319
[junit4] 2> 16832 T35 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 16833 T35 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 16833 T35 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/solr
[junit4] 2> 16834 T35 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/solr/'
[junit4] 2> 16869 T35 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/solr/solr.xml
[junit4] 2> 17051 T35 oasc.ConfigSolrXml.<init> Config-defined core root directory:
[junit4] 2> 17053 T35 oasc.CoreContainer.<init> New CoreContainer 1488333887
[junit4] 2> 17054 T35 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/solr/]
[junit4] 2> 17061 T35 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4] 2> 17061 T35 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 17062 T35 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4] 2> 17063 T35 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 17063 T35 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 17064 T35 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 17064 T35 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 17065 T35 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 17065 T35 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 17066 T35 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4] 2> 17075 T35 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/solr
[junit4] 2> 17077 T35 oasc.CorePropertiesLocator.discoverUnder Found core collection1 in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/solr/collection1/
[junit4] 2> 17079 T35 oasc.CorePropertiesLocator.discover Found 1 core definitions
[junit4] 2> 17081 T47 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/solr/collection1
[junit4] 2> 17082 T47 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/solr/collection1/'
[junit4] 2> 17142 T47 oasc.SolrConfig.initLibs Adding specified lib dirs to ClassLoader
[junit4] 2> 17142 T47 oasc.SolrResourceLoader.addToClassLoader WARN No files added to classloader from lib: ../../../contrib/extraction/lib (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/solr/collection1/../../../contrib/extraction/lib).
[junit4] 2> 17143 T47 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/solr/collection1/../../../dist).
[junit4] 2> 17143 T47 oasc.SolrResourceLoader.addToClassLoader WARN No files added to classloader from lib: ../../../contrib/clustering/lib/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/solr/collection1/../../../contrib/clustering/lib).
[junit4] 2> 17144 T47 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/solr/collection1/../../../dist).
[junit4] 2> 17144 T47 oasc.SolrResourceLoader.addToClassLoader WARN No files added to classloader from lib: ../../../contrib/langid/lib/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/solr/collection1/../../../contrib/langid/lib).
[junit4] 2> 17146 T47 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/solr/collection1/../../../dist).
[junit4] 2> 17148 T47 oasc.SolrResourceLoader.addToClassLoader WARN No files added to classloader from lib: ../../../contrib/velocity/lib (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/solr/collection1/../../../contrib/velocity/lib).
[junit4] 2> 17150 T47 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/solr/collection1/../../../dist).
[junit4] 2> 17242 T47 oasu.SolrIndexConfig.<init> IndexWriter infoStream solr logging is enabled
[junit4] 2> 17250 T47 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 17400 T47 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 17404 T47 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 17492 T47 oass.IndexSchema.readSchema [collection1] Schema name=example
[junit4] 2> 18733 T47 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 18763 T47 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 18788 T47 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 18881 T47 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 18882 T47 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/solr/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-solrj/test/J0/solrtest-SolrExampleXMLTest-1375292977274/
[junit4] 2> 18882 T47 oasc.JmxMonitoredMap.<init> No JMX servers found, not exposing Solr information with JMX.
[junit4] 2> 18883 T47 oasc.SolrCore.initListeners [collection1] Added SolrEventListener for newSearcher: org.apache.solr.core.QuerySenderListener{queries=[]}
[junit4] 2> 18884 T47 oasc.SolrCore.initListeners [collection1] Added SolrEventListener for firstSearcher: org.apache.solr.core.QuerySenderListener{queries=[{q=static firstSearcher warming in solrconfig.xml}]}
[junit4] 2> 18888 T47 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-solrj/test/J0/solrtest-SolrExampleXMLTest-1375292977274
[junit4] 2> 18888 T47 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-solrj/test/J0/solrtest-SolrExampleXMLTest-1375292977274/index/
[junit4] 2> 18889 T47 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-solrj/test/J0/solrtest-SolrExampleXMLTest-1375292977274/index' doesn't exist. Creating new index...
[junit4] 2> 18889 T47 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-solrj/test/J0/solrtest-SolrExampleXMLTest-1375292977274/index
[junit4] 2> 18894 T47 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-11-thread-1]: init: current segments file is "null"; deletionPolicy=org.apache.solr.core.IndexDeletionPolicyWrapper@42a1d486
[junit4] 2> 18895 T47 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-11-thread-1]: now checkpoint "" [0 segments ; isCommit = false]
[junit4] 2> 18895 T47 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-11-thread-1]: 0 msec to checkpoint
[junit4] 2> 18896 T47 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-11-thread-1]: init: create=true
[junit4] 2> 18896 T47 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-11-thread-1]:
[junit4] 2> dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1a1c0ced lockFactory=org.apache.lucene.store.NativeFSLockFactory@b68c292c)
[junit4] 2> index=
[junit4] 2> version=5.0-SNAPSHOT
[junit4] 2> matchVersion=LUCENE_50
[junit4] 2> analyzer=null
[junit4] 2> ramBufferSizeMB=100.0
[junit4] 2> maxBufferedDocs=-1
[junit4] 2> maxBufferedDeleteTerms=-1
[junit4] 2> mergedSegmentWarmer=null
[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@a86d96ff
[junit4] 2> readerPooling=false
[junit4] 2> perThreadHardLimitMB=1945
[junit4] 2> useCompoundFile=false
[junit4] 2>
[junit4] 2> 18897 T47 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-11-thread-1]: now flush at close waitForMerges=true
[junit4] 2> 18897 T47 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-11-thread-1]: start flush: applyAllDeletes=true
[junit4] 2> 18898 T47 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-11-thread-1]: index before flush
[junit4] 2> 18898 T47 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-11-thread-1]: coreLoadExecutor-11-thread-1 startFullFlush
[junit4] 2> 18899 T47 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-11-thread-1]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 18899 T47 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-11-thread-1]: coreLoadExecutor-11-thread-1 finishFullFlush success=true
[junit4] 2> 18900 T47 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-11-thread-1]: apply all deletes during flush
[junit4] 2> 18900 T47 oasu.LoggingInfoStream.message [BD][coreLoadExecutor-11-thread-1]: prune sis=org.apache.lucene.index.SegmentInfos@1b8a8d36 minGen=9223372036854775807 packetCount=0
[junit4] 2> 18902 T47 oasu.LoggingInfoStream.message [CMS][coreLoadExecutor-11-thread-1]: now merge
[junit4] 2> 18902 T47 oasu.LoggingInfoStream.message [CMS][coreLoadExecutor-11-thread-1]: index:
[junit4] 2> 18902 T47 oasu.LoggingInfoStream.message [CMS][coreLoadExecutor-11-thread-1]: no more merges pending; now return
[junit4] 2> 18903 T47 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-11-thread-1]: waitForMerges
[junit4] 2> 18903 T47 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-11-thread-1]: waitForMerges done
[junit4] 2> 18904 T47 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-11-thread-1]: now call final commit()
[junit4] 2> 18905 T47 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-11-thread-1]: commit: start
[junit4] 2> 18905 T47 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-11-thread-1]: commit: enter lock
[junit4] 2> 18906 T47 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-11-thread-1]: commit: now prepare
[junit4] 2> 18906 T47 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-11-thread-1]: prepareCommit: flush
[junit4] 2> 18907 T47 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-11-thread-1]: index before flush
[junit4] 2> 18907 T47 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-11-thread-1]: coreLoadExecutor-11-thread-1 startFullFlush
[junit4] 2> 18908 T47 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-11-thread-1]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 18909 T47 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-11-thread-1]: apply all deletes during flush
[junit4] 2> 18910 T47 oasu.LoggingInfoStream.message [BD][coreLoadExecutor-11-thread-1]: prune sis=org.apache.lucene.index.SegmentInfos@1b8a8d36 minGen=9223372036854775807 packetCount=0
[junit4] 2> 18911 T47 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-11-thread-1]: coreLoadExecutor-11-thread-1 finishFullFlush success=true
[junit4] 2> 18911 T47 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-11-thread-1]: startCommit(): start
[junit4] 2> 18912 T47 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-11-thread-1]: startCommit index= changeCount=1
[junit4] 2> 18914 T47 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-11-thread-1]: done all syncs: []
[junit4] 2> 18915 T47 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-11-thread-1]: commit: pendingCommit != null
[junit4] 2> 18917 T47 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-11-thread-1]: commit: wrote segments file "segments_1"
[junit4] 2> 18918 T47 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-11-thread-1]: now checkpoint "" [0 segments ; isCommit = true]
[junit4] 2> 18919 T47 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1a1c0ced lockFactory=org.apache.lucene.store.NativeFSLockFactory@b68c292c),segFN=segments_1,generation=1}
[junit4] 2> 18920 T47 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 18921 T47 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-11-thread-1]: 3 msec to checkpoint
[junit4] 2> 18922 T47 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-11-thread-1]: commit: done
[junit4] 2> 18923 T47 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-11-thread-1]: at close:
[junit4] 2> 18927 T47 oasc.SolrCore.initWriters created json: solr.JSONResponseWriter
[junit4] 2> 18927 T47 oasc.SolrCore.initWriters adding lazy queryResponseWriter: solr.VelocityResponseWriter
[junit4] 2> 18928 T47 oasc.SolrCore.initWriters created velocity: solr.VelocityResponseWriter
[junit4] 2> 18929 T47 oasc.SolrCore.initWriters created xslt: solr.XSLTResponseWriter
[junit4] 2> 18930 T47 oasr.XSLTResponseWriter.init xsltCacheLifetimeSeconds=5
[junit4] 2> 18937 T47 oasc.RequestHandlers.initHandlersFromConfig created /select: solr.SearchHandler
[junit4] 2> 18938 T47 oasc.RequestHandlers.initHandlersFromConfig created /query: solr.SearchHandler
[junit4] 2> 18939 T47 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 18939 T47 oasc.RequestHandlers.initHandlersFromConfig created /browse: solr.SearchHandler
[junit4] 2> 18940 T47 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 18940 T47 oasc.RequestHandlers.initHandlersFromConfig created /update/json: solr.JsonUpdateRequestHandler
[junit4] 2> 18941 T47 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: solr.CSVRequestHandler
[junit4] 2> 18941 T47 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.extraction.ExtractingRequestHandler
[junit4] 2> 18942 T47 oasc.RequestHandlers.initHandlersFromConfig created /update/extract: solr.extraction.ExtractingRequestHandler
[junit4] 2> 18943 T47 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.FieldAnalysisRequestHandler
[junit4] 2> 18944 T47 oasc.RequestHandlers.initHandlersFromConfig created /analysis/field: solr.FieldAnalysisRequestHandler
[junit4] 2> 18944 T47 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.DocumentAnalysisRequestHandler
[junit4] 2> 18945 T47 oasc.RequestHandlers.initHandlersFromConfig created /analysis/document: solr.DocumentAnalysisRequestHandler
[junit4] 2> 18946 T47 oasc.RequestHandlers.initHandlersFromConfig created /admin/: solr.admin.AdminHandlers
[junit4] 2> 18949 T47 oasc.RequestHandlers.initHandlersFromConfig created /admin/ping: solr.PingRequestHandler
[junit4] 2> 18951 T47 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4] 2> 18955 T47 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 18955 T47 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
[junit4] 2> 18955 T47 oasc.RequestHandlers.initHandlersFromConfig created /spell: solr.SearchHandler
[junit4] 2> 18956 T47 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
[junit4] 2> 18957 T47 oasc.RequestHandlers.initHandlersFromConfig created /tvrh: solr.SearchHandler
[junit4] 2> 18957 T47 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
[junit4] 2> 18958 T47 oasc.RequestHandlers.initHandlersFromConfig created /terms: solr.SearchHandler
[junit4] 2> 18959 T47 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
[junit4] 2> 18959 T47 oasc.RequestHandlers.initHandlersFromConfig created /elevate: solr.SearchHandler
[junit4] 2> 18965 T47 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 18968 T47 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 18975 T47 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 18990 T47 oass.SolrIndexSearcher.<init> Opening Searcher@f989ddef main
[junit4] 2> 18993 T47 oasu.CommitTracker.<init> Hard AutoCommit: if uncommited for 15000ms;
[junit4] 2> 18994 T47 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 18994 T47 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4] 2> 18995 T47 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> 18995 T47 oashc.SpellCheckComponent.inform No queryConverter defined, using default converter
[junit4] 2> 18996 T47 oashc.QueryElevationComponent.inform Loading QueryElevation from: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/solr/collection1/conf/elevate.xml
[junit4] 2> 19009 T47 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4] 2> 19009 T48 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@f989ddef main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 19009 T47 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 19011 T35 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-solrj/test/J0
[junit4] 2> ASYNC NEW_CORE C33 name=collection1 org.apache.solr.core.SolrCore@267af665
[junit4] 2> 19011 T48 C33 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=static+firstSearcher+warming+in+solrconfig.xml&distrib=false&event=firstSearcher} hits=0 status=0 QTime=1
[junit4] 2> 19011 T35 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 19012 T48 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 19012 T35 oas.SolrJettyTestBase.createJetty Jetty Assigned Port#38319
[junit4] 2> 19013 T48 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: default
[junit4] 2> 19013 T48 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: wordbreak
[junit4] 2> 19014 T48 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@f989ddef main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 19023 T35 oas.SolrTestCaseJ4.setUp ###Starting testSetNullUpdateOrder
[junit4] 2> 19047 T35 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> ASYNC NEW_CORE C34 name=collection1 org.apache.solr.core.SolrCore@267af665
[junit4] 2> 20314 T46 C34 oasu.LoggingInfoStream.message [IFD][qtp-266164532-46]: init: current segments file is "segments_1"; deletionPolicy=org.apache.solr.core.IndexDeletionPolicyWrapper@42a1d486
[junit4] 2> 20315 T46 C34 oasu.LoggingInfoStream.message [IFD][qtp-266164532-46]: init: load commit "segments_1"
[junit4] 2> 20316 T46 C34 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1a1c0ced lockFactory=org.apache.lucene.store.NativeFSLockFactory@b68c292c),segFN=segments_1,generation=1}
[junit4] 2> 20317 T46 C34 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 20317 T46 C34 oasu.LoggingInfoStream.message [IFD][qtp-266164532-46]: now checkpoint "" [0 segments ; isCommit = false]
[junit4] 2> 20318 T46 C34 oasu.LoggingInfoStream.message [IFD][qtp-266164532-46]: 0 msec to checkpoint
[junit4] 2> 20319 T46 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-46]: init: create=false
[junit4] 2> 20320 T46 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-46]:
[junit4] 2> dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1a1c0ced lockFactory=org.apache.lucene.store.NativeFSLockFactory@b68c292c)
[junit4] 2> index=
[junit4] 2> version=5.0-SNAPSHOT
[junit4] 2> matchVersion=LUCENE_50
[junit4] 2> analyzer=null
[junit4] 2> ramBufferSizeMB=100.0
[junit4] 2> maxBufferedDocs=-1
[junit4] 2> maxBufferedDeleteTerms=-1
[junit4] 2> mergedSegmentWarmer=null
[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@9f4cd843
[junit4] 2> readerPooling=false
[junit4] 2> perThreadHardLimitMB=1945
[junit4] 2> useCompoundFile=false
[junit4] 2>
[junit4] 2> 20322 T46 C34 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2.2&wt=xml} {add=[testSetNullUpdateOrder (1442099214114881536)]} 0 12
[junit4] 2> 20395 T39 C34 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 20396 T39 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-39]: commit: start
[junit4] 2> 20397 T39 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-39]: commit: enter lock
[junit4] 2> 20397 T39 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-39]: commit: now prepare
[junit4] 2> 20398 T39 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-39]: prepareCommit: flush
[junit4] 2> 20399 T39 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-39]: index before flush
[junit4] 2> 20399 T39 C34 oasu.LoggingInfoStream.message [DW][qtp-266164532-39]: qtp-266164532-39 startFullFlush
[junit4] 2> 20401 T39 C34 oasu.LoggingInfoStream.message [DW][qtp-266164532-39]: anyChanges? numDocsInRam=1 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 20401 T39 C34 oasu.LoggingInfoStream.message [DWFC][qtp-266164532-39]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=_0, aborting=false, numDocsInRAM=1, deleteQueue=DWDQ: [ generation: 0 ]]
[junit4] 2> 20408 T39 C34 oasu.LoggingInfoStream.message [DWPT][qtp-266164532-39]: flush postings as segment _0 numDocs=1
[junit4] 2> 20413 T39 C34 oasu.LoggingInfoStream.message [DWPT][qtp-266164532-39]: new segment has 0 deleted docs
[junit4] 2> 20413 T39 C34 oasu.LoggingInfoStream.message [DWPT][qtp-266164532-39]: new segment has no vectors; no norms; no docValues; no prox; no freqs
[junit4] 2> 20414 T39 C34 oasu.LoggingInfoStream.message [DWPT][qtp-266164532-39]: flushedFiles=[_0.fnm, _0_Lucene41_0.tim, _0_Lucene41_0.doc, _0.fdt, _0_Lucene41_0.tip, _0.fdx]
[junit4] 2> 20415 T39 C34 oasu.LoggingInfoStream.message [DWPT][qtp-266164532-39]: flushed codec=Lucene42
[junit4] 2> 20416 T39 C34 oasu.LoggingInfoStream.message [DWPT][qtp-266164532-39]: flushed: segment=_0 ramUsed=0.063 MB newFlushedSize(includes docstores)=0.001 MB docs/MB=1,144.734
[junit4] 2> 20416 T39 C34 oasu.LoggingInfoStream.message [DW][qtp-266164532-39]: publishFlushedSegment seg-private deletes=null
[junit4] 2> 20417 T39 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-39]: publishFlushedSegment
[junit4] 2> 20418 T39 C34 oasu.LoggingInfoStream.message [BD][qtp-266164532-39]: push deletes 1 deleted terms (unique count=1) bytesUsed=1024 delGen=1 packetCount=1 totBytesUsed=1024
[junit4] 2> 20419 T39 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-39]: publish sets newSegment delGen=2 seg=_0(5.0):C1
[junit4] 2> 20419 T39 C34 oasu.LoggingInfoStream.message [IFD][qtp-266164532-39]: now checkpoint "_0(5.0):C1" [1 segments ; isCommit = false]
[junit4] 2> 20420 T39 C34 oasu.LoggingInfoStream.message [IFD][qtp-266164532-39]: 0 msec to checkpoint
[junit4] 2> 20421 T39 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-39]: apply all deletes during flush
[junit4] 2> 20422 T39 C34 oasu.LoggingInfoStream.message [BD][qtp-266164532-39]: applyDeletes: infos=[_0(5.0):C1] packetCount=1
[junit4] 2> 20422 T39 C34 oasu.LoggingInfoStream.message [BD][qtp-266164532-39]: applyDeletes took 0 msec
[junit4] 2> 20423 T39 C34 oasu.LoggingInfoStream.message [BD][qtp-266164532-39]: prune sis=org.apache.lucene.index.SegmentInfos@d46fa247 minGen=3 packetCount=1
[junit4] 2> 20424 T39 C34 oasu.LoggingInfoStream.message [BD][qtp-266164532-39]: pruneDeletes: prune 1 packets; 0 packets remain
[junit4] 2> 20425 T39 C34 oasu.LoggingInfoStream.message [DW][qtp-266164532-39]: qtp-266164532-39 finishFullFlush success=true
[junit4] 2> 20426 T39 C34 oasu.LoggingInfoStream.message [TMP][qtp-266164532-39]: findMerges: 1 segments
[junit4] 2> 20428 T39 C34 oasu.LoggingInfoStream.message [TMP][qtp-266164532-39]: seg=_0(5.0):C1 size=0.001 MB [floored]
[junit4] 2> 20429 T39 C34 oasu.LoggingInfoStream.message [TMP][qtp-266164532-39]: allowedSegmentCount=1 vs count=1 (eligible count=1) tooBigCount=0
[junit4] 2> 20430 T39 C34 oasu.LoggingInfoStream.message [CMS][qtp-266164532-39]: now merge
[junit4] 2> 20430 T39 C34 oasu.LoggingInfoStream.message [CMS][qtp-266164532-39]: index: _0(5.0):C1
[junit4] 2> 20431 T39 C34 oasu.LoggingInfoStream.message [CMS][qtp-266164532-39]: no more merges pending; now return
[junit4] 2> 20432 T39 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-39]: startCommit(): start
[junit4] 2> 20432 T39 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-39]: startCommit index=_0(5.0):C1 changeCount=3
[junit4] 2> 20433 T39 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-39]: done all syncs: [_0.si, _0_Lucene41_0.doc, _0_Lucene41_0.tim, _0.fnm, _0.fdt, _0_Lucene41_0.tip, _0.fdx]
[junit4] 2> 20434 T39 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-39]: commit: pendingCommit != null
[junit4] 2> 20435 T39 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-39]: commit: wrote segments file "segments_2"
[junit4] 2> 20435 T39 C34 oasu.LoggingInfoStream.message [IFD][qtp-266164532-39]: now checkpoint "_0(5.0):C1" [1 segments ; isCommit = true]
[junit4] 2> 20436 T39 C34 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1a1c0ced lockFactory=org.apache.lucene.store.NativeFSLockFactory@b68c292c),segFN=segments_1,generation=1}
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1a1c0ced lockFactory=org.apache.lucene.store.NativeFSLockFactory@b68c292c),segFN=segments_2,generation=2}
[junit4] 2> 20437 T39 C34 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4] 2> 20438 T39 C34 oasu.LoggingInfoStream.message [IFD][qtp-266164532-39]: deleteCommits: now decRef commit "segments_1"
[junit4] 2> 20438 T39 C34 oasu.LoggingInfoStream.message [IFD][qtp-266164532-39]: delete "segments_1"
[junit4] 2> 20439 T39 C34 oasu.LoggingInfoStream.message [IFD][qtp-266164532-39]: 3 msec to checkpoint
[junit4] 2> 20439 T39 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-39]: commit: done
[junit4] 2> 20440 T39 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-39]: flush at getReader
[junit4] 2> 20441 T39 C34 oasu.LoggingInfoStream.message [DW][qtp-266164532-39]: qtp-266164532-39 startFullFlush
[junit4] 2> 20441 T39 C34 oasu.LoggingInfoStream.message [DW][qtp-266164532-39]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 20442 T39 C34 oasu.LoggingInfoStream.message [DWFC][qtp-266164532-39]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=null, aborting=false, numDocsInRAM=0, deleteQueue=DWDQ: [ generation: 1 ]]
[junit4] 2> 20443 T39 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-39]: apply all deletes during flush
[junit4] 2> 20444 T39 C34 oasu.LoggingInfoStream.message [BD][qtp-266164532-39]: applyDeletes: no deletes; skipping
[junit4] 2> 20444 T39 C34 oasu.LoggingInfoStream.message [BD][qtp-266164532-39]: prune sis=org.apache.lucene.index.SegmentInfos@d46fa247 minGen=3 packetCount=0
[junit4] 2> 20446 T39 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-39]: return reader version=3 reader=StandardDirectoryReader(segments_2:3:nrt _0(5.0):C1)
[junit4] 2> 20446 T39 C34 oasu.LoggingInfoStream.message [DW][qtp-266164532-39]: qtp-266164532-39 finishFullFlush success=true
[junit4] 2> 20447 T39 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-39]: getReader took 7 msec
[junit4] 2> 20448 T39 C34 oass.SolrIndexSearcher.<init> Opening Searcher@8f11c087 main
[junit4] 2> 20451 T48 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@8f11c087 main{StandardDirectoryReader(segments_2:3:nrt _0(5.0):C1)}
[junit4] 2> 20451 T48 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 20453 T48 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@8f11c087 main{StandardDirectoryReader(segments_2:3:nrt _0(5.0):C1)}
[junit4] 2> 20454 T39 C34 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 20454 T39 C34 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={softCommit=false&commit=true&version=2.2&waitSearcher=true&wt=xml} {commit=} 0 59
[junit4] 2> 20466 T45 C34 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2.2&wt=xml} {add=[testSetNullUpdateOrder (1442099214274265088)]} 0 3
[junit4] 2> 20476 T44 C34 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 20476 T44 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-44]: commit: start
[junit4] 2> 20477 T44 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-44]: commit: enter lock
[junit4] 2> 20477 T44 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-44]: commit: now prepare
[junit4] 2> 20478 T44 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-44]: prepareCommit: flush
[junit4] 2> 20478 T44 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-44]: index before flush _0(5.0):C1
[junit4] 2> 20478 T44 C34 oasu.LoggingInfoStream.message [DW][qtp-266164532-44]: qtp-266164532-44 startFullFlush
[junit4] 2> 20479 T44 C34 oasu.LoggingInfoStream.message [DW][qtp-266164532-44]: anyChanges? numDocsInRam=1 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 20479 T44 C34 oasu.LoggingInfoStream.message [DWFC][qtp-266164532-44]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=_1, aborting=false, numDocsInRAM=1, deleteQueue=DWDQ: [ generation: 2 ]]
[junit4] 2> 20480 T44 C34 oasu.LoggingInfoStream.message [DWPT][qtp-266164532-44]: flush postings as segment _1 numDocs=1
[junit4] 2> 20481 T44 C34 oasu.LoggingInfoStream.message [DWPT][qtp-266164532-44]: new segment has 0 deleted docs
[junit4] 2> 20481 T44 C34 oasu.LoggingInfoStream.message [DWPT][qtp-266164532-44]: new segment has no vectors; no norms; no docValues; no prox; no freqs
[junit4] 2> 20482 T44 C34 oasu.LoggingInfoStream.message [DWPT][qtp-266164532-44]: flushedFiles=[_1_Lucene41_0.tim, _1_Lucene41_0.doc, _1.fnm, _1_Lucene41_0.tip, _1.fdt, _1.fdx]
[junit4] 2> 20482 T44 C34 oasu.LoggingInfoStream.message [DWPT][qtp-266164532-44]: flushed codec=Lucene42
[junit4] 2> 20483 T44 C34 oasu.LoggingInfoStream.message [DWPT][qtp-266164532-44]: flushed: segment=_1 ramUsed=0.063 MB newFlushedSize(includes docstores)=0.001 MB docs/MB=1,376.084
[junit4] 2> 20483 T44 C34 oasu.LoggingInfoStream.message [DW][qtp-266164532-44]: publishFlushedSegment seg-private deletes=null
[junit4] 2> 20484 T44 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-44]: publishFlushedSegment
[junit4] 2> 20484 T44 C34 oasu.LoggingInfoStream.message [BD][qtp-266164532-44]: push deletes 1 deleted terms (unique count=1) bytesUsed=1024 delGen=5 packetCount=1 totBytesUsed=1024
[junit4] 2> 20485 T44 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-44]: publish sets newSegment delGen=6 seg=_1(5.0):C1
[junit4] 2> 20485 T44 C34 oasu.LoggingInfoStream.message [IFD][qtp-266164532-44]: now checkpoint "_0(5.0):C1 _1(5.0):C1" [2 segments ; isCommit = false]
[junit4] 2> 20486 T44 C34 oasu.LoggingInfoStream.message [IFD][qtp-266164532-44]: 0 msec to checkpoint
[junit4] 2> 20486 T44 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-44]: apply all deletes during flush
[junit4] 2> 20487 T44 C34 oasu.LoggingInfoStream.message [BD][qtp-266164532-44]: applyDeletes: infos=[_0(5.0):C1, _1(5.0):C1] packetCount=1
[junit4] 2> 20487 T44 C34 oasu.LoggingInfoStream.message [BD][qtp-266164532-44]: seg=_0(5.0):C1 segGen=3 coalesced deletes=[CoalescedDeletes(termSets=1,queries=0)] newDelCount=1 100% deleted
[junit4] 2> 20488 T44 C34 oasu.LoggingInfoStream.message [BD][qtp-266164532-44]: applyDeletes took 1 msec
[junit4] 2> 20488 T44 C34 oasu.LoggingInfoStream.message [IFD][qtp-266164532-44]: now checkpoint "_0(5.0):C1/1 _1(5.0):C1" [2 segments ; isCommit = false]
[junit4] 2> 20489 T44 C34 oasu.LoggingInfoStream.message [IFD][qtp-266164532-44]: 0 msec to checkpoint
[junit4] 2> 20489 T44 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-44]: drop 100% deleted segments: _0(5.0):C1/1
[junit4] 2> 20489 T44 C34 oasu.LoggingInfoStream.message [IFD][qtp-266164532-44]: now checkpoint "_1(5.0):C1" [1 segments ; isCommit = false]
[junit4] 2> 20490 T44 C34 oasu.LoggingInfoStream.message [IFD][qtp-266164532-44]: 0 msec to checkpoint
[junit4] 2> 20490 T44 C34 oasu.LoggingInfoStream.message [BD][qtp-266164532-44]: prune sis=org.apache.lucene.index.SegmentInfos@d46fa247 minGen=7 packetCount=1
[junit4] 2> 20491 T44 C34 oasu.LoggingInfoStream.message [BD][qtp-266164532-44]: pruneDeletes: prune 1 packets; 0 packets remain
[junit4] 2> 20491 T44 C34 oasu.LoggingInfoStream.message [DW][qtp-266164532-44]: qtp-266164532-44 finishFullFlush success=true
[junit4] 2> 20491 T44 C34 oasu.LoggingInfoStream.message [TMP][qtp-266164532-44]: findMerges: 1 segments
[junit4] 2> 20492 T44 C34 oasu.LoggingInfoStream.message [TMP][qtp-266164532-44]: seg=_1(5.0):C1 size=0.001 MB [floored]
[junit4] 2> 20492 T44 C34 oasu.LoggingInfoStream.message [TMP][qtp-266164532-44]: allowedSegmentCount=1 vs count=1 (eligible count=1) tooBigCount=0
[junit4] 2> 20493 T44 C34 oasu.LoggingInfoStream.message [CMS][qtp-266164532-44]: now merge
[junit4] 2> 20493 T44 C34 oasu.LoggingInfoStream.message [CMS][qtp-266164532-44]: index: _1(5.0):C1
[junit4] 2> 20494 T44 C34 oasu.LoggingInfoStream.message [CMS][qtp-266164532-44]: no more merges pending; now return
[junit4] 2> 20494 T44 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-44]: startCommit(): start
[junit4] 2> 20494 T44 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-44]: startCommit index=_1(5.0):C1 changeCount=8
[junit4] 2> 20495 T44 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-44]: done all syncs: [_1.si, _1_Lucene41_0.doc, _1_Lucene41_0.tim, _1.fnm, _1.fdt, _1_Lucene41_0.tip, _1.fdx]
[junit4] 2> 20495 T44 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-44]: commit: pendingCommit != null
[junit4] 2> 20496 T44 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-44]: commit: wrote segments file "segments_3"
[junit4] 2> 20496 T44 C34 oasu.LoggingInfoStream.message [IFD][qtp-266164532-44]: now checkpoint "_1(5.0):C1" [1 segments ; isCommit = true]
[junit4] 2> 20497 T44 C34 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1a1c0ced lockFactory=org.apache.lucene.store.NativeFSLockFactory@b68c292c),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1a1c0ced lockFactory=org.apache.lucene.store.NativeFSLockFactory@b68c292c),segFN=segments_3,generation=3}
[junit4] 2> 20497 T44 C34 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4] 2> 20497 T44 C34 oasu.LoggingInfoStream.message [IFD][qtp-266164532-44]: deleteCommits: now decRef commit "segments_2"
[junit4] 2> 20498 T44 C34 oasu.LoggingInfoStream.message [IFD][qtp-266164532-44]: delete "_0.si"
[junit4] 2> 20498 T44 C34 oasu.LoggingInfoStream.message [IFD][qtp-266164532-44]: delete "segments_2"
[junit4] 2> 20499 T44 C34 oasu.LoggingInfoStream.message [IFD][qtp-266164532-44]: delete "_0_Lucene41_0.doc"
[junit4] 2> 20499 T44 C34 oasu.LoggingInfoStream.message [IFD][qtp-266164532-44]: 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> 20500 T44 C34 oasu.LoggingInfoStream.message [IFD][qtp-266164532-44]: delete "_0_Lucene41_0.tim"
[junit4] 2> 20500 T44 C34 oasu.LoggingInfoStream.message [IFD][qtp-266164532-44]: 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> 20500 T44 C34 oasu.LoggingInfoStream.message [IFD][qtp-266164532-44]: delete "_0.fnm"
[junit4] 2> 20501 T44 C34 oasu.LoggingInfoStream.message [IFD][qtp-266164532-44]: delete "_0.fdt"
[junit4] 2> 20501 T44 C34 oasu.LoggingInfoStream.message [IFD][qtp-266164532-44]: unable to remove file "_0.fdt": java.io.IOException: MockDirectoryWrapper: file "_0.fdt" is still open: cannot delete; Will re-try later.
[junit4] 2> 20502 T44 C34 oasu.LoggingInfoStream.message [IFD][qtp-266164532-44]: delete "_0_Lucene41_0.tip"
[junit4] 2> 20502 T44 C34 oasu.LoggingInfoStream.message [IFD][qtp-266164532-44]: delete "_0.fdx"
[junit4] 2> 20502 T44 C34 oasu.LoggingInfoStream.message [IFD][qtp-266164532-44]: 6 msec to checkpoint
[junit4] 2> 20503 T44 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-44]: commit: done
[junit4] 2> 20503 T44 C34 oasu.LoggingInfoStream.message [DW][qtp-266164532-44]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 20504 T44 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-44]: nrtIsCurrent: infoVersion matches: false; DW changes: false; BD changes: false
[junit4] 2> 20504 T44 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-44]: flush at getReader
[junit4] 2> 20504 T44 C34 oasu.LoggingInfoStream.message [DW][qtp-266164532-44]: qtp-266164532-44 startFullFlush
[junit4] 2> 20505 T44 C34 oasu.LoggingInfoStream.message [DW][qtp-266164532-44]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 20505 T44 C34 oasu.LoggingInfoStream.message [DWFC][qtp-266164532-44]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=null, aborting=false, numDocsInRAM=0, deleteQueue=DWDQ: [ generation: 3 ]]
[junit4] 2> 20506 T44 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-44]: apply all deletes during flush
[junit4] 2> 20506 T44 C34 oasu.LoggingInfoStream.message [BD][qtp-266164532-44]: applyDeletes: no deletes; skipping
[junit4] 2> 20507 T44 C34 oasu.LoggingInfoStream.message [BD][qtp-266164532-44]: prune sis=org.apache.lucene.index.SegmentInfos@d46fa247 minGen=7 packetCount=0
[junit4] 2> 20508 T44 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-44]: return reader version=7 reader=StandardDirectoryReader(segments_3:7:nrt _1(5.0):C1)
[junit4] 2> 20508 T44 C34 oasu.LoggingInfoStream.message [DW][qtp-266164532-44]: qtp-266164532-44 finishFullFlush success=true
[junit4] 2> 20508 T44 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-44]: getReader took 4 msec
[junit4] 2> 20509 T44 C34 oass.SolrIndexSearcher.<init> Opening Searcher@a6f3b3d4 main
[junit4] 2> 20509 T44 C34 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 20509 T48 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@a6f3b3d4 main{StandardDirectoryReader(segments_3:7:nrt _1(5.0):C1)}
[junit4] 2> 20510 T48 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 20510 T48 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@a6f3b3d4 main{StandardDirectoryReader(segments_3:7:nrt _1(5.0):C1)}
[junit4] 2> 20511 T48 oasu.LoggingInfoStream.message [IFD][searcherExecutor-12-thread-1]: delete pending file _0_Lucene41_0.doc
[junit4] 2> 20511 T48 oasu.LoggingInfoStream.message [IFD][searcherExecutor-12-thread-1]: delete "_0_Lucene41_0.doc"
[junit4] 2> 20511 T48 oasu.LoggingInfoStream.message [IFD][searcherExecutor-12-thread-1]: delete pending file _0_Lucene41_0.tim
[junit4] 2> 20512 T48 oasu.LoggingInfoStream.message [IFD][searcherExecutor-12-thread-1]: delete "_0_Lucene41_0.tim"
[junit4] 2> 20512 T48 oasu.LoggingInfoStream.message [IFD][searcherExecutor-12-thread-1]: delete pending file _0.fdt
[junit4] 2> 20512 T48 oasu.LoggingInfoStream.message [IFD][searcherExecutor-12-thread-1]: delete "_0.fdt"
[junit4] 2> 20513 T44 C34 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={softCommit=false&commit=true&version=2.2&waitSearcher=true&wt=xml} {commit=} 0 37
[junit4] 2> 20518 T46 C34 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={q=id:testSetNullUpdateOrder&version=2.2&wt=xml} hits=1 status=0 QTime=0
[junit4] 2> 20522 T35 oas.SolrTestCaseJ4.tearDown ###Ending testSetNullUpdateOrder
[junit4] 2> 20531 T35 oas.SolrTestCaseJ4.setUp ###Starting testLukeHandler
[junit4] 2> 20536 T39 C34 oasu.LoggingInfoStream.message [DW][qtp-266164532-39]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 20537 T39 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-39]: nrtIsCurrent: infoVersion matches: true; DW changes: true; BD changes: false
[junit4] 2> 20537 T39 C34 oasu.LoggingInfoStream.message [DW][qtp-266164532-39]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 20538 T39 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-39]: flush at getReader
[junit4] 2> 20538 T39 C34 oasu.LoggingInfoStream.message [DW][qtp-266164532-39]: qtp-266164532-39 startFullFlush
[junit4] 2> 20539 T39 C34 oasu.LoggingInfoStream.message [DW][qtp-266164532-39]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 20539 T39 C34 oasu.LoggingInfoStream.message [DWFC][qtp-266164532-39]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=null, aborting=false, numDocsInRAM=0, deleteQueue=DWDQ: [ generation: 4 ]]
[junit4] 2> 20540 T39 C34 oasu.LoggingInfoStream.message [DW][qtp-266164532-39]: qtp-266164532-39: flush naked frozen global deletes
[junit4] 2> 20540 T39 C34 oasu.LoggingInfoStream.message [BD][qtp-266164532-39]: push deletes 1 deleted queries bytesUsed=36 delGen=9 packetCount=1 totBytesUsed=36
[junit4] 2> 20541 T39 C34 oasu.LoggingInfoStream.message [DW][qtp-266164532-39]: flush: push buffered deletes: 1 deleted queries bytesUsed=36
[junit4] 2> 20541 T39 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-39]: apply all deletes during flush
[junit4] 2> 20542 T39 C34 oasu.LoggingInfoStream.message [BD][qtp-266164532-39]: applyDeletes: infos=[_1(5.0):C1] packetCount=1
[junit4] 2> 20542 T39 C34 oasu.LoggingInfoStream.message [BD][qtp-266164532-39]: seg=_1(5.0):C1 segGen=7 coalesced deletes=[CoalescedDeletes(termSets=1,queries=1)] newDelCount=1 100% deleted
[junit4] 2> 20543 T39 C34 oasu.LoggingInfoStream.message [BD][qtp-266164532-39]: applyDeletes took 1 msec
[junit4] 2> 20543 T39 C34 oasu.LoggingInfoStream.message [IFD][qtp-266164532-39]: now checkpoint "_1(5.0):C1/1" [1 segments ; isCommit = false]
[junit4] 2> 20544 T39 C34 oasu.LoggingInfoStream.message [IFD][qtp-266164532-39]: 0 msec to checkpoint
[junit4] 2> 20544 T39 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-39]: drop 100% deleted segments: _1(5.0):C1/1
[junit4] 2> 20545 T39 C34 oasu.LoggingInfoStream.message [IFD][qtp-266164532-39]: now checkpoint "" [0 segments ; isCommit = false]
[junit4] 2> 20545 T39 C34 oasu.LoggingInfoStream.message [IFD][qtp-266164532-39]: 0 msec to checkpoint
[junit4] 2> 20546 T39 C34 oasu.LoggingInfoStream.message [BD][qtp-266164532-39]: prune sis=org.apache.lucene.index.SegmentInfos@d46fa247 minGen=9223372036854775807 packetCount=1
[junit4] 2> 20546 T39 C34 oasu.LoggingInfoStream.message [BD][qtp-266164532-39]: pruneDeletes: prune 1 packets; 0 packets remain
[junit4] 2> 20547 T39 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-39]: return reader version=9 reader=StandardDirectoryReader(segments_3:9:nrt)
[junit4] 2> 20547 T39 C34 oasu.LoggingInfoStream.message [DW][qtp-266164532-39]: qtp-266164532-39 finishFullFlush success=true
[junit4] 2> 20548 T39 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-39]: getReader took 10 msec
[junit4] 2> 20548 T39 C34 oass.SolrIndexSearcher.<init> Opening Searcher@a4150b64 realtime
[junit4] 2> 20549 T39 C34 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2.2&wt=xml} {deleteByQuery=*:* (-1442099214349762560)} 0 14
[junit4] 2> 20556 T45 C34 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2.2&wt=xml} {add=[ID0 (1442099214369685504)]} 0 1
[junit4] 2> 20563 T44 C34 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2.2&wt=xml} {add=[ID1 (1442099214377025536)]} 0 1
[junit4] 2> 20570 T46 C34 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2.2&wt=xml} {add=[ID2 (1442099214384365568)]} 0 1
[junit4] 2> 20576 T39 C34 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2.2&wt=xml} {add=[ID3 (1442099214391705600)]} 0 0
[junit4] 2> 20583 T45 C34 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2.2&wt=xml} {add=[ID4 (1442099214397997056)]} 0 1
[junit4] 2> 20594 T44 C34 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 20595 T44 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-44]: commit: start
[junit4] 2> 20596 T44 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-44]: commit: enter lock
[junit4] 2> 20596 T44 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-44]: commit: now prepare
[junit4] 2> 20596 T44 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-44]: prepareCommit: flush
[junit4] 2> 20597 T44 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-44]: index before flush
[junit4] 2> 20597 T44 C34 oasu.LoggingInfoStream.message [DW][qtp-266164532-44]: qtp-266164532-44 startFullFlush
[junit4] 2> 20598 T44 C34 oasu.LoggingInfoStream.message [DW][qtp-266164532-44]: anyChanges? numDocsInRam=5 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 20598 T44 C34 oasu.LoggingInfoStream.message [DWFC][qtp-266164532-44]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0 4 deleted terms (unique count=4) bytesUsed=924, segment=_2, aborting=false, numDocsInRAM=5, deleteQueue=DWDQ: [ generation: 5 ]]
[junit4] 2> 20599 T44 C34 oasu.LoggingInfoStream.message [DWPT][qtp-266164532-44]: flush postings as segment _2 numDocs=5
[junit4] 2> 20600 T44 C34 oasu.LoggingInfoStream.message [DWPT][qtp-266164532-44]: new segment has 0 deleted docs
[junit4] 2> 20601 T44 C34 oasu.LoggingInfoStream.message [DWPT][qtp-266164532-44]: new segment has no vectors; no norms; no docValues; no prox; no freqs
[junit4] 2> 20601 T44 C34 oasu.LoggingInfoStream.message [DWPT][qtp-266164532-44]: flushedFiles=[_2_Lucene41_0.tim, _2_Lucene41_0.doc, _2_Lucene41_0.tip, _2.fnm, _2.fdt, _2.fdx]
[junit4] 2> 20601 T44 C34 oasu.LoggingInfoStream.message [DWPT][qtp-266164532-44]: flushed codec=Lucene42
[junit4] 2> 20602 T44 C34 oasu.LoggingInfoStream.message [DWPT][qtp-266164532-44]: flushed: segment=_2 ramUsed=0.064 MB newFlushedSize(includes docstores)=0.001 MB docs/MB=7,576.416
[junit4] 2> 20603 T44 C34 oasu.LoggingInfoStream.message [DW][qtp-266164532-44]: publishFlushedSegment seg-private deletes=null
[junit4] 2> 20603 T44 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-44]: publishFlushedSegment
[junit4] 2> 20604 T44 C34 oasu.LoggingInfoStream.message [BD][qtp-266164532-44]: push deletes 5 deleted terms (unique count=5) bytesUsed=1024 delGen=11 packetCount=1 totBytesUsed=1024
[junit4] 2> 20604 T44 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-44]: publish sets newSegment delGen=12 seg=_2(5.0):C5
[junit4] 2> 20605 T44 C34 oasu.LoggingInfoStream.message [IFD][qtp-266164532-44]: now checkpoint "_2(5.0):C5" [1 segments ; isCommit = false]
[junit4] 2> 20605 T44 C34 oasu.LoggingInfoStream.message [IFD][qtp-266164532-44]: 0 msec to checkpoint
[junit4] 2> 20606 T44 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-44]: apply all deletes during flush
[junit4] 2> 20606 T44 C34 oasu.LoggingInfoStream.message [BD][qtp-266164532-44]: applyDeletes: infos=[_2(5.0):C5] packetCount=1
[junit4] 2> 20606 T44 C34 oasu.LoggingInfoStream.message [BD][qtp-266164532-44]: applyDeletes took 0 msec
[junit4] 2> 20607 T44 C34 oasu.LoggingInfoStream.message [BD][qtp-266164532-44]: prune sis=org.apache.lucene.index.SegmentInfos@d46fa247 minGen=13 packetCount=1
[junit4] 2> 20607 T44 C34 oasu.LoggingInfoStream.message [BD][qtp-266164532-44]: pruneDeletes: prune 1 packets; 0 packets remain
[junit4] 2> 20608 T44 C34 oasu.LoggingInfoStream.message [DW][qtp-266164532-44]: qtp-266164532-44 finishFullFlush success=true
[junit4] 2> 20608 T44 C34 oasu.LoggingInfoStream.message [TMP][qtp-266164532-44]: findMerges: 1 segments
[junit4] 2> 20609 T44 C34 oasu.LoggingInfoStream.message [TMP][qtp-266164532-44]: seg=_2(5.0):C5 size=0.000 MB [floored]
[junit4] 2> 20609 T44 C34 oasu.LoggingInfoStream.message [TMP][qtp-266164532-44]: allowedSegmentCount=1 vs count=1 (eligible count=1) tooBigCount=0
[junit4] 2> 20610 T44 C34 oasu.LoggingInfoStream.message [CMS][qtp-266164532-44]: now merge
[junit4] 2> 20610 T44 C34 oasu.LoggingInfoStream.message [CMS][qtp-266164532-44]: index: _2(5.0):C5
[junit4] 2> 20611 T44 C34 oasu.LoggingInfoStream.message [CMS][qtp-266164532-44]: no more merges pending; now return
[junit4] 2> 20611 T44 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-44]: startCommit(): start
[junit4] 2> 20612 T44 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-44]: startCommit index=_2(5.0):C5 changeCount=13
[junit4] 2> 20612 T44 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-44]: done all syncs: [_2.si, _2_Lucene41_0.doc, _2_Lucene41_0.tim, _2_Lucene41_0.tip, _2.fnm, _2.fdt, _2.fdx]
[junit4] 2> 20613 T44 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-44]: commit: pendingCommit != null
[junit4] 2> 20614 T44 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-44]: commit: wrote segments file "segments_4"
[junit4] 2> 20614 T44 C34 oasu.LoggingInfoStream.message [IFD][qtp-266164532-44]: now checkpoint "_2(5.0):C5" [1 segments ; isCommit = true]
[junit4] 2> 20615 T44 C34 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1a1c0ced lockFactory=org.apache.lucene.store.NativeFSLockFactory@b68c292c),segFN=segments_3,generation=3}
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1a1c0ced lockFactory=org.apache.lucene.store.NativeFSLockFactory@b68c292c),segFN=segments_4,generation=4}
[junit4] 2> 20615 T44 C34 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 4
[junit4] 2> 20615 T44 C34 oasu.LoggingInfoStream.message [IFD][qtp-266164532-44]: deleteCommits: now decRef commit "segments_3"
[junit4] 2> 20616 T44 C34 oasu.LoggingInfoStream.message [IFD][qtp-266164532-44]: delete "_1.si"
[junit4] 2> 20616 T44 C34 oasu.LoggingInfoStream.message [IFD][qtp-266164532-44]: delete "segments_3"
[junit4] 2> 20617 T44 C34 oasu.LoggingInfoStream.message [IFD][qtp-266164532-44]: delete "_1_Lucene41_0.doc"
[junit4] 2> 20617 T44 C34 oasu.LoggingInfoStream.message [IFD][qtp-266164532-44]: 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> 20618 T44 C34 oasu.LoggingInfoStream.message [IFD][qtp-266164532-44]: delete "_1_Lucene41_0.tim"
[junit4] 2> 20618 T44 C34 oasu.LoggingInfoStream.message [IFD][qtp-266164532-44]: 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> 20618 T44 C34 oasu.LoggingInfoStream.message [IFD][qtp-266164532-44]: delete "_1.fnm"
[junit4] 2> 20619 T44 C34 oasu.LoggingInfoStream.message [IFD][qtp-266164532-44]: delete "_1.fdt"
[junit4] 2> 20619 T44 C34 oasu.LoggingInfoStream.message [IFD][qtp-266164532-44]: unable to remove file "_1.fdt": java.io.IOException: MockDirectoryWrapper: file "_1.fdt" is still open: cannot delete; Will re-try later.
[junit4] 2> 20620 T44 C34 oasu.LoggingInfoStream.message [IFD][qtp-266164532-44]: delete "_1_Lucene41_0.tip"
[junit4] 2> 20620 T44 C34 oasu.LoggingInfoStream.message [IFD][qtp-266164532-44]: delete "_1.fdx"
[junit4] 2> 20621 T44 C34 oasu.LoggingInfoStream.message [IFD][qtp-266164532-44]: 6 msec to checkpoint
[junit4] 2> 20621 T44 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-44]: commit: done
[junit4] 2> 20622 T44 C34 oasu.LoggingInfoStream.message [DW][qtp-266164532-44]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 20622 T44 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-44]: nrtIsCurrent: infoVersion matches: false; DW changes: false; BD changes: false
[junit4] 2> 20622 T44 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-44]: flush at getReader
[junit4] 2> 20623 T44 C34 oasu.LoggingInfoStream.message [DW][qtp-266164532-44]: qtp-266164532-44 startFullFlush
[junit4] 2> 20623 T44 C34 oasu.LoggingInfoStream.message [DW][qtp-266164532-44]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 20624 T44 C34 oasu.LoggingInfoStream.message [DWFC][qtp-266164532-44]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=null, aborting=false, numDocsInRAM=0, deleteQueue=DWDQ: [ generation: 6 ]]
[junit4] 2> 20624 T44 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-44]: apply all deletes during flush
[junit4] 2> 20625 T44 C34 oasu.LoggingInfoStream.message [BD][qtp-266164532-44]: applyDeletes: no deletes; skipping
[junit4] 2> 20625 T44 C34 oasu.LoggingInfoStream.message [BD][qtp-266164532-44]: prune sis=org.apache.lucene.index.SegmentInfos@d46fa247 minGen=13 packetCount=0
[junit4] 2> 20628 T44 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-44]: return reader version=11 reader=StandardDirectoryReader(segments_4:11:nrt _2(5.0):C5)
[junit4] 2> 20628 T44 C34 oasu.LoggingInfoStream.message [DW][qtp-266164532-44]: qtp-266164532-44 finishFullFlush success=true
[junit4] 2> 20629 T44 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-44]: getReader took 7 msec
[junit4] 2> 20629 T44 C34 oass.SolrIndexSearcher.<init> Opening Searcher@80696f0d main
[junit4] 2> 20630 T44 C34 oasu.LoggingInfoStream.message [IFD][qtp-266164532-44]: delete pending file _1_Lucene41_0.doc
[junit4] 2> 20630 T44 C34 oasu.LoggingInfoStream.message [IFD][qtp-266164532-44]: delete "_1_Lucene41_0.doc"
[junit4] 2> 20631 T44 C34 oasu.LoggingInfoStream.message [IFD][qtp-266164532-44]: 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> 20631 T44 C34 oasu.LoggingInfoStream.message [IFD][qtp-266164532-44]: delete pending file _1_Lucene41_0.tim
[junit4] 2> 20632 T44 C34 oasu.LoggingInfoStream.message [IFD][qtp-266164532-44]: delete "_1_Lucene41_0.tim"
[junit4] 2> 20632 T44 C34 oasu.LoggingInfoStream.message [IFD][qtp-266164532-44]: 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> 20633 T44 C34 oasu.LoggingInfoStream.message [IFD][qtp-266164532-44]: delete pending file _1.fdt
[junit4] 2> 20633 T44 C34 oasu.LoggingInfoStream.message [IFD][qtp-266164532-44]: delete "_1.fdt"
[junit4] 2> 20634 T44 C34 oasu.LoggingInfoStream.message [IFD][qtp-266164532-44]: unable to remove file "_1.fdt": java.io.IOException: MockDirectoryWrapper: file "_1.fdt" is still open: cannot delete; Will re-try later.
[junit4] 2> 20634 T44 C34 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 20634 T48 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@80696f0d main{StandardDirectoryReader(segments_4:11:nrt _2(5.0):C5)}
[junit4] 2> 20635 T48 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 20635 T48 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@80696f0d main{StandardDirectoryReader(segments_4:11:nrt _2(5.0):C5)}
[junit4] 2> 20636 T48 oasu.LoggingInfoStream.message [IFD][searcherExecutor-12-thread-1]: delete pending file _1_Lucene41_0.doc
[junit4] 2> 20636 T48 oasu.LoggingInfoStream.message [IFD][searcherExecutor-12-thread-1]: delete "_1_Lucene41_0.doc"
[junit4] 2> 20636 T48 oasu.LoggingInfoStream.message [IFD][searcherExecutor-12-thread-1]: delete pending file _1_Lucene41_0.tim
[junit4] 2> 20636 T48 oasu.LoggingInfoStream.message [IFD][searcherExecutor-12-thread-1]: delete "_1_Lucene41_0.tim"
[junit4] 2> 20637 T48 oasu.LoggingInfoStream.message [IFD][searcherExecutor-12-thread-1]: delete pending file _1.fdt
[junit4] 2> 20637 T48 oasu.LoggingInfoStream.message [IFD][searcherExecutor-12-thread-1]: delete "_1.fdt"
[junit4] 2> 20637 T44 C34 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={softCommit=false&commit=true&version=2.2&waitSearcher=true&wt=xml} {commit=} 0 43
[junit4] 2> 20644 T46 C34 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={q=*:*&version=2.2&wt=xml} hits=5 status=0 QTime=1
[junit4] 2> 20652 T39 C34 oasu.LoggingInfoStream.message [DW][qtp-266164532-39]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 20652 T39 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-39]: nrtIsCurrent: infoVersion matches: true; DW changes: false; BD changes: false
[junit4] 2> 20653 T39 C34 oasu.LoggingInfoStream.message [DW][qtp-266164532-39]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 20654 T39 C34 oasc.SolrCore.execute [collection1] webapp=/solr path=/admin/luke params={version=2.2&wt=xml} status=0 QTime=2
[junit4] 2> 20668 T45 C34 oasu.LoggingInfoStream.message [DW][qtp-266164532-45]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 20668 T45 C34 oasu.LoggingInfoStream.message [IW][qtp-266164532-45]: nrtIsCurrent: infoVersion matches: true; DW changes: false; BD changes: false
[junit4] 2> 20669 T45 C34 oasu.LoggingInfoStream.message [DW][qtp-266164532-45]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 20672 T45 C34 oasc.SolrCore.execute [collection1] webapp=/solr path=/admin/luke params={version=2.2&wt=xml&show=schema} status=0 QTime=4
[junit4] 2> 20933 T35 oas.SolrTestCaseJ4.tearDown ###Ending testLukeHandler
[junit4] 2> 20954 T35 oas.SolrTestCaseJ4.setUp ###Starting testQueryWithParams
[junit4] 2> ASYNC NEW_CORE C35 name=collection1 org.apache.solr.core.SolrCore@267af665
[junit4] 2> 20958 T39 C35 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={q=query&debug=true&version=2.2&wt=xml} hits=0 status=0 QTime=1
[junit4] 2> 20966 T35 oas.SolrTestCaseJ4.tearDown ###Ending testQueryWithParams
[junit4] 2> 20979 T35 oas.SolrTestCaseJ4.setUp ###Starting testSetNullUpdates
[junit4] 2> 20994 T44 C35 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2.2&wt=xml} {add=[testSetNullUpdates (1442099214825816064)]} 0 4
[junit4] 2> 21021 T44 C35 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 21022 T44 C35 oasu.LoggingInfoStream.message [IW][qtp-266164532-44]: commit: start
[junit4] 2> 21022 T44 C35 oasu.LoggingInfoStream.message [IW][qtp-266164532-44]: commit: enter lock
[junit4] 2> 21023 T44 C35 oasu.LoggingInfoStream.message [IW][qtp-266164532-44]: commit: now prepare
[junit4] 2> 21024 T44 C35 oasu.LoggingInfoStream.message [IW][qtp-266164532-44]: prepareCommit: flush
[junit4] 2> 21025 T44 C35 oasu.LoggingInfoStream.message [IW][qtp-266164532-44]: index before flush _2(5.0):C5
[junit4] 2> 21025 T44 C35 oasu.LoggingInfoStream.message [DW][qtp-266164532-44]: qtp-266164532-44 startFullFlush
[junit4] 2> 21026 T44 C35 oasu.LoggingInfoStream.message [DW][qtp-266164532-44]: anyChanges? numDocsInRam=1 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 21027 T44 C35 oasu.LoggingInfoStream.message [DWFC][qtp-266164532-44]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=_3, aborting=false, numDocsInRAM=1, deleteQueue=DWDQ: [ generation: 7 ]]
[junit4] 2> 21034 T44 C35 oasu.LoggingInfoStream.message [DWPT][qtp-266164532-44]: flush postings as segment _3 numDocs=1
[junit4] 2> 21041 T44 C35 oasu.LoggingInfoStream.message [DWPT][qtp-266164532-44]: new segment has 0 deleted docs
[junit4] 2> 21041 T44 C35 oasu.LoggingInfoStream.message [DWPT][qtp-266164532-44]: new segment has no vectors; no norms; no docValues; no prox; no freqs
[junit4] 2> 21042 T44 C35 oasu.LoggingInfoStream.message [DWPT][qtp-266164532-44]: flushedFiles=[_3.fdx, _3_Lucene41_0.tim, _3_Lucene41_0.doc, _3_Lucene41_0.tip, _3.fnm, _3.fdt]
[junit4] 2> 21043 T44 C35 oasu.LoggingInfoStream.message [DWPT][qtp-266164532-44]: flushed codec=Lucene42
[junit4] 2> 21046 T44 C35 oasu.LoggingInfoStream.message [DWPT][qtp-266164532-44]: flushed: segment=_3 ramUsed=0.063 MB newFlushedSize(includes docstores)=0.001 MB docs/MB=1,154.819
[junit4] 2> 21048 T44 C35 oasu.LoggingInfoStream.message [DW][qtp-266164532-44]: publishFlushedSegment seg-private deletes=null
[junit4] 2> 21048 T44 C35 oasu.LoggingInfoStream.message [IW][qtp-266164532-44]: publishFlushedSegment
[junit4] 2> 21049 T44 C35 oasu.LoggingInfoStream.message [BD][qtp-266164532-44]: push deletes 1 deleted terms (unique count=1) bytesUsed=1024 delGen=15 packetCount=1 totBytesUsed=1024
[junit4] 2> 21050 T44 C35 oasu.LoggingInfoStream.message [IW][qtp-266164532-44]: publish sets newSegment delGen=16 seg=_3(5.0):C1
[junit4] 2> 21050 T44 C35 oasu.LoggingInfoStream.message [IFD][qtp-266164532-44]: now checkpoint "_2(5.0):C5 _3(5.0):C1" [2 segments ; isCommit = false]
[junit4] 2> 21053 T44 C35 oasu.LoggingInfoStream.message [IFD][qtp-266164532-44]: 2 msec to checkpoint
[junit4] 2> 21055 T44 C35 oasu.LoggingInfoStream.message [IW][qtp-266164532-44]: apply all deletes during flush
[junit4] 2> 21056 T44 C35 oasu.LoggingInfoStream.message [BD][qtp-266164532-44]: applyDeletes: infos=[_2(5.0):C5, _3(5.0):C1] packetCount=1
[junit4] 2> 21061 T44 C35 oasu.LoggingInfoStream.message [BD][qtp-266164532-44]: seg=_2(5.0):C5 segGen=13 coalesced deletes=[CoalescedDeletes(termSets=1,queries=0)] newDelCount=0
[junit4] 2> 21062 T44 C35 oasu.LoggingInfoStream.message [BD][qtp-266164532-44]: applyDeletes took 7 msec
[junit4] 2> 21063 T44 C35 oasu.LoggingInfoStream.message [BD][qtp-266164532-44]: prune sis=org.apache.lucene.index.SegmentInfos@d46fa247 minGen=17 packetCount=1
[junit4] 2> 21064 T44 C35 oasu.LoggingInfoStream.message [BD][qtp-266164532-44]: pruneDeletes: prune 1 packets; 0 packets remain
[junit4] 2> 21066 T44 C35 oasu.LoggingInfoStream.message [DW][qtp-266164532-44]: qtp-266164532-44 finishFullFlush success=true
[junit4] 2> 21067 T44 C35 oasu.LoggingInfoStream.message [TMP][qtp-266164532-44]: findMerges: 2 segments
[junit4] 2> 21071 T44 C35 oasu.LoggingInfoStream.message [TMP][qtp-266164532-44]: seg=_3(5.0):C1 size=0.001 MB [floored]
[junit4] 2> 21072 T44 C35 oasu.LoggingInfoStream.message [TMP][qtp-266164532-44]: seg=_2(5.0):C5 size=0.000 MB [floored]
[junit4] 2> 21073 T44 C35 oasu.LoggingInfoStream.message [TMP][qtp-266164532-44]: allowedSegmentCount=1 vs count=2 (eligible count=2) tooBigCount=0
[junit4] 2> 21074 T44 C35 oasu.LoggingInfoStream.message [CMS][qtp-266164532-44]: now merge
[junit4] 2> 21074 T44 C35 oasu.LoggingInfoStream.message [CMS][qtp-266164532-44]: index: _2(5.0):C5 _3(5.0):C1
[junit4] 2> 21075 T44 C35 oasu.LoggingInfoStream.message [CMS][qtp-266164532-44]: no more merges pending; now return
[junit4] 2> 21076 T44 C35 oasu.LoggingInfoStream.message [IW][qtp-266164532-44]: startCommit(): start
[junit4] 2> 21077 T44 C35 oasu.LoggingInfoStream.message [IW][qtp-266164532-44]: startCommit index=_2(5.0):C5 _3(5.0):C1 changeCount=16
[junit4] 2> 21084 T44 C35 oasu.LoggingInfoStream.message [IW][qtp-266164532-44]: done all syncs: [_3.fdx, _3_Lucene41_0.tim, _3_Lucene41_0.doc, _2_Lucene41_0.tim, _2_Lucene41_0.doc, _3_Lucene41_0.tip, _2_Lucene41_0.tip, _2.fnm, _3.fnm, _3.si, _2.si, _2.fdt, _3.fdt, _2.fdx]
[junit4] 2> 21085 T44 C35 oasu.LoggingInfoStream.message [IW][qtp-266164532-44]: commit: pendingCommit != null
[junit4] 2> 21087 T44 C35 oasu.LoggingInfoStream.message [IW][qtp-266164532-44]: commit: wrote segments file "segments_5"
[junit4] 2> 21089 T44 C35 oasu.LoggingInfoStream.message [IFD][qtp-266164532-44]: now checkpoint "_2(5.0):C5 _3(5.0):C1" [2 segments ; isCommit = true]
[junit4] 2> 21091 T44 C35 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1a1c0ced lockFactory=org.apache.lucene.store.NativeFSLockFactory@b68c292c),segFN=segments_4,generation=4}
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1a1c0ced lockFactory=org.apache.lucene.store.NativeFSLockFactory@b68c292c),segFN=segments_5,generation=5}
[junit4] 2> 21092 T44 C35 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 5
[junit4] 2> 21092 T44 C35 oasu.LoggingInfoStream.message [IFD][qtp-266164532-44]: deleteCommits: now decRef commit "segments_4"
[junit4] 2> 21093 T44 C35 oasu.LoggingInfoStream.message [IFD][qtp-266164532-44]: delete "segments_4"
[junit4] 2> 21094 T44 C35 oasu.LoggingInfoStream.message [IFD][qtp-266164532-44]: 5 msec to checkpoint
[junit4] 2> 21095 T44 C35 oasu.LoggingInfoStream.message [IW][qtp-266164532-44]: commit: done
[junit4] 2> 21097 T44 C35 oasu.LoggingInfoStream.message [DW][qtp-266164532-44]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 21098 T44 C35 oasu.LoggingInfoStream.message [IW][qtp-266164532-44]: nrtIsCurrent: infoVersion matches: false; DW changes: false; BD changes: false
[junit4] 2> 21099 T44 C35 oasu.LoggingInfoStream.message [IW][qtp-266164532-44]: flush at getReader
[junit4] 2> 21099 T44 C35 oasu.LoggingInfoStream.message [DW][qtp-266164532-44]: qtp-266164532-44 startFullFlush
[junit4] 2> 21100 T44 C35 oasu.LoggingInfoStream.message [DW][qtp-266164532-44]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 21101 T44 C35 oasu.LoggingInfoStream.message [DWFC][qtp-266164532-44]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=null, aborting=false, numDocsInRAM=0, deleteQueue=DWDQ: [ generation: 8 ]]
[junit4] 2> 21103 T44 C35 oasu.LoggingInfoStream.message [IW][qtp-266164532-44]: apply all deletes during flush
[junit4] 2> 21104 T44 C35 oasu.LoggingInfoStream.message [BD][qtp-266164532-44]: applyDeletes: no deletes; skipping
[junit4] 2> 21105 T44 C35 oasu.LoggingInfoStream.message [BD][qtp-266164532-44]: prune sis=org.apache.lucene.index.SegmentInfos@d46fa247 minGen=17 packetCount=0
[junit4] 2> 21115 T44 C35 oasu.LoggingInfoStream.message [IW][qtp-266164532-44]: return reader version=13 reader=StandardDirectoryReader(segments_5:13:nrt _2(5.0):C5 _3(5.0):C1)
[junit4] 2> 21116 T44 C35 oasu.LoggingInfoStream.message [DW][qtp-266164532-44]: qtp-266164532-44 finishFullFlush success=true
[junit4] 2> 21116 T44 C35 oasu.LoggingInfoStream.message [IW][qtp-266164532-44]: getReader took 17 msec
[junit4] 2> 21117 T44 C35 oass.SolrIndexSearcher.<init> Opening Searcher@b8433ced main
[junit4] 2> 21121 T48 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@b8433ced main{StandardDirectoryReader(segments_5:13:nrt _2(5.0):C5 _3(5.0):C1)}
[junit4] 2> 21121 T48 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 21123 T48 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@b8433ced main{StandardDirectoryReader(segments_5:13:nrt _2(5.0):C5 _3(5.0):C1)}
[junit4] 2> 21125 T44 C35 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 21126 T44 C35 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={softCommit=false&commit=true&version=2.2&waitSearcher=true&wt=xml} {commit=} 0 105
[junit4] 2> 21140 T39 C35 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2.2&wt=xml} {add=[testSetNullUpdates (1442099214982053888)]} 0 2
[junit4] 2> 21151 T45 C35 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 21152 T45 C35 oasu.LoggingInfoStream.message [IW][qtp-266164532-45]: commit: start
[junit4] 2> 21153 T45 C35 oasu.LoggingInfoStream.message [IW][qtp-266164532-45]: commit: enter lock
[junit4] 2> 21153 T45 C35 oasu.LoggingInfoStream.message [IW][qtp-266164532-45]: commit: now prepare
[junit4] 2> 21154 T45 C35 oasu.LoggingInfoStream.message [IW][qtp-266164532-45]: prepareCommit: flush
[junit4] 2> 21154 T45 C35 oasu.LoggingInfoStream.message [IW][qtp-266164532-45]: index before flush _2(5.0):C5 _3(5.0):C1
[junit4] 2> 21155 T45 C35 oasu.LoggingInfoStream.message [DW][qtp-266164532-45]: qtp-266164532-45 startFullFlush
[junit4] 2> 21156 T45 C35 oasu.LoggingInfoStream.message [DW][qtp-266164532-45]: anyChanges? numDocsInRam=1 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 21157 T45 C35 oasu.LoggingInfoStream.message [DWFC][qtp-266164532-45]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=_4, aborting=false, numDocsInRAM=1, deleteQueue=DWDQ: [ generation: 9 ]]
[junit4] 2> 21157 T45 C35 oasu.LoggingInfoStream.message [DWPT][qtp-266164532-45]: flush postings as segment _4 numDocs=1
[junit4] 2> 21159 T45 C35 oasu.LoggingInfoStream.message [DWPT][qtp-266164532-45]: new segment has 0 deleted docs
[junit4] 2> 21160 T45 C35 oasu.LoggingInfoStream.message [DWPT][qtp-266164532-45]: new segment has no vectors; no norms; no docValues; no prox; no freqs
[junit4] 2> 21161 T45 C35 oasu.LoggingInfoStream.message [DWPT][qtp-266164532-45]: flushedFiles=[_4.fdx, _4_Lucene41_0.tim, _4_Lucene41_0.doc, _4_Lucene41_0.tip, _4.fnm, _4.fdt]
[junit4] 2> 21161 T45 C35 oasu.LoggingInfoStream.message [DWPT][qtp-266164532-45]: flushed codec=Lucene42
[junit4] 2> 21172 T45 C35 oasu.LoggingInfoStream.message [DWPT][qtp-266164532-45]: flushed: segment=_4 ramUsed=0.063 MB newFlushedSize(includes docstores)=0.001 MB docs/MB=1,394.383
[junit4] 2> 21173 T45 C35 oasu.LoggingInfoStream.message [DW][qtp-266164532-45]: publishFlushedSegment seg-private deletes=null
[junit4] 2> 21173 T45 C35 oasu.LoggingInfoStream.message [IW][qtp-266164532-45]: publishFlushedSegment
[junit4] 2> 21174 T45 C35 oasu.LoggingInfoStream.message [BD][qtp-266164532-45]: push deletes 1 deleted terms (unique count=1) bytesUsed=1024 delGen=19 packetCount=1 totBytesUsed=1024
[junit4] 2> 21175 T45 C35 oasu.LoggingInfoStream.message [IW][qtp-266164532-45]: publish sets newSegment delGen=20 seg=_4(5.0):C1
[junit4] 2> 21176 T45 C35 oasu.LoggingInfoStream.message [IFD][qtp-266164532-45]: now checkpoint "_2(5.0):C5 _3(5.0):C1 _4(5.0):C1" [3 segments ; isCommit = false]
[junit4] 2> 21177 T45 C35 oasu.LoggingInfoStream.message [IFD][qtp-266164532-45]: 0 msec to checkpoint
[junit4] 2> 21177 T45 C35 oasu.LoggingInfoStream.message [IW][qtp-266164532-45]: apply all deletes during flush
[junit4] 2> 21178 T45 C35 oasu.LoggingInfoStream.message [BD][qtp-266164532-45]: applyDeletes: infos=[_2(5.0):C5, _3(5.0):C1, _4(5.0):C1] packetCount=1
[junit4] 2> 21183 T45 C35 oasu.LoggingInfoStream.message [BD][qtp-266164532-45]: seg=_3(5.0):C1 segGen=17 coalesced deletes=[CoalescedDeletes(termSets=1,queries=0)] newDelCount=1 100% deleted
[junit4] 2> 21185 T45 C35 oasu.LoggingInfoStream.message [BD][qtp-266164532-45]: seg=_2(5.0):C5 segGen=17 coalesced deletes=[CoalescedDeletes(termSets=1,queries=0)] newDelCount=0
[junit4] 2> 21186 T45 C35 oasu.LoggingInfoStream.message [BD][qtp-266164532-45]: applyDeletes took 8 msec
[junit4] 2> 21186 T45 C35 oasu.LoggingInfoStream.message [IFD][qtp-266164532-45]: now checkpoint "_2(5.0):C5 _3(5.0):C1/1 _4(5.0):C1" [3 segments ; isCommit = false]
[junit4] 2> 21187 T45 C35 oasu.LoggingInfoStream.message [IFD][qtp-266164532-45]: 0 msec to checkpoint
[junit4] 2> 21188 T45 C35 oasu.LoggingInfoStream.message [IW][qtp-266164532-45]: drop 100% deleted segments: _3(5.0):C1/1
[junit4] 2> 21189 T45 C35 oasu.LoggingInfoStream.message [IFD][qtp-266164532-45]: now checkpoint "_2(5.0):C5 _4(5.0):C1" [2 segments ; isCommit = false]
[junit4] 2> 21191 T45 C35 oasu.LoggingInfoStream.message [IFD][qtp-266164532-45]: 2 msec to checkpoint
[junit4] 2> 21192 T45 C35 oasu.LoggingInfoStream.message [BD][qtp-266164532-45]: prune sis=org.apache.lucene.index.SegmentInfos@d46fa247 minGen=21 packetCount=1
[junit4] 2> 21193 T45 C35 oasu.LoggingInfoStream.message [BD][qtp-266164532-45]: pruneDeletes: prune 1 packets; 0 packets remain
[junit4] 2> 21195 T45 C35 oasu.LoggingInfoStream.message [DW][qtp-266164532-45]: qtp-266164532-45 finishFullFlush success=true
[junit4] 2> 21197 T45 C35 oasu.LoggingInfoStream.message [TMP][qtp-266164532-45]: findMerges: 2 segments
[junit4] 2> 21203 T45 C35 oasu.LoggingInfoStream.message [TMP][qtp-266164532-45]: seg=_4(5.0):C1 size=0.001 MB [floored]
[junit4] 2> 21205 T45 C35 oasu.LoggingInfoStream.message [TMP][qtp-266164532-45]: seg=_2(5.0):C5 size=0.000 MB [floored]
[junit4] 2> 21206 T45 C35 oasu.LoggingInfoStream.message [TMP][qtp-266164532-45]: allowedSegmentCount=1 vs count=2 (eligible count=2) tooBigCount=0
[junit4] 2> 21206 T45 C35 oasu.LoggingInfoStream.message [CMS][qtp-266164532-45]: now merge
[junit4] 2> 21207 T45 C35 oasu.LoggingInfoStream.message [CMS][qtp-266164532-45]: index: _2(5.0):C5 _4(5.0):C1
[junit4] 2> 21208 T45 C35 oasu.LoggingInfoStream.message [CMS][qtp-266164532-45]: no more merges pending; now return
[junit4] 2> 21209 T45 C35 oasu.LoggingInfoStream.message [IW][qtp-266164532-45]: startCommit(): start
[junit4] 2> 21210 T45 C35 oasu.LoggingInfoStream.message [IW][qtp-266164532-45]: startCommit index=_2(5.0):C5 _4(5.0):C1 changeCount=21
[junit4] 2> 21213 T45 C35 oasu.LoggingInfoStream.message [IW][qtp-266164532-45]: done all syncs: [_4.fdx, _4_Lucene41_0.tim, _4_Lucene41_0.doc, _2_Lucene41_0.tim, _2_Lucene41_0.doc, _4_Lucene41_0.tip, _2_Lucene41_0.tip, _2.fnm, _4.fnm, _4.si, _2.si, _2.fdt, _4.fdt, _2.fdx]
[junit4] 2> 21214 T45 C35 oasu.LoggingInfoStream.message [IW][qtp-266164532-45]: commit: pendingCommit != null
[junit4] 2> 21216 T45 C35 oasu.LoggingInfoStream.message [IW][qtp-266164532-45]: commit: wrote segments file "segments_6"
[junit4] 2> 21217 T45 C35 oasu.LoggingInfoStream.message [IFD][qtp-266164532-45]: now checkpoint "_2(5.0):C5 _4(5.0):C1" [2 segments ; isCommit = true]
[junit4] 2> 21219 T45 C35 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1a1c0ced lockFactory=org.apache.lucene.store.NativeFSLockFactory@b68c292c),segFN=segments_5,generation=5}
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1a1c0ced lockFactory=org.apache.lucene.store.NativeFSLockFactory@b68c292c),segFN=segments_6,generation=6}
[junit4] 2> 21220 T45 C35 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 6
[junit4] 2> 21221 T45 C35 oasu.LoggingInfoStream.message [IFD][qtp-266164532-45]: deleteCommits: now decRef commit "segments_5"
[junit4] 2> 21222 T45 C35 oasu.LoggingInfoStream.message [IFD][qtp-266164532-45]: delete "_3.fdx"
[junit4] 2> 21222 T45 C35 oasu.LoggingInfoStream.message [IFD][qtp-266164532-45]: delete "_3_Lucene41_0.tim"
[junit4] 2> 21223 T45 C35 oasu.LoggingInfoStream.message [IFD][qtp-266164532-45]: unable to remove file "_3_Lucene41_0.tim": java.io.IOException: MockDirectoryWrapper: file "_3_Lucene41_0.tim" is still open: cannot delete; Will re-try later.
[junit4] 2> 21224 T45 C35 oasu.LoggingInfoStream.message [IFD][qtp-266164532-45]: delete "_3_Lucene41_0.doc"
[junit4] 2> 21225 T45 C35 oasu.LoggingInfoStream.message [IFD][qtp-266164532-45]: unable to remove file "_3_Lucene41_0.doc": java.io.IOException: MockDirectoryWrapper: file "_3_Lucene41_0.doc" is still open: cannot delete; Will re-try later.
[junit4] 2> 21226 T45 C35 oasu.LoggingInfoStream.message [IFD][qtp-266164532-45]: delete "_3_Lucene41_0.tip"
[junit4] 2> 21227 T45 C35 oasu.LoggingInfoStream.message [IFD][qtp-266164532-45]: delete "_3.fnm"
[junit4] 2> 21228 T45 C35 oasu.LoggingInfoStream.message [IFD][qtp-266164532-45]: delete "_3.si"
[junit4] 2> 21228 T45 C35 oasu.LoggingInfoStream.message [IFD][qtp-266164532-45]: delete "segments_5"
[junit4] 2> 21229 T45 C35 oasu.LoggingInfoStream.message [IFD][qtp-266164532-45]: delete "_3.fdt"
[junit4] 2> 21230 T45 C35 o
[...truncated too long message...]
add=[42 (1442099435842568192)],commit=} 0 31
[junit4] 2> 231803 T39 C48 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={q=北京大学&version=2.2&wt=xml} hits=1 status=0 QTime=1
[junit4] 2> 231804 T35 oas.SolrTestCaseJ4.tearDown ###Ending testChineseDefaults
[junit4] 2> 231863 T35 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1488333887
[junit4] 2> 231864 T35 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@267af665
[junit4] 2> 231865 T35 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=64,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=309,cumulative_deletesById=5,cumulative_deletesByQuery=33,cumulative_errors=1}
[junit4] 2> 231865 T35 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 231866 T35 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 231866 T35 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 231867 T35 C48 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleXMLTest-seed#[B111E977CF0EDEE7]-worker]: now flush at close waitForMerges=true
[junit4] 2> 231867 T35 C48 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleXMLTest-seed#[B111E977CF0EDEE7]-worker]: start flush: applyAllDeletes=true
[junit4] 2> 231867 T35 C48 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleXMLTest-seed#[B111E977CF0EDEE7]-worker]: index before flush _1b(5.0):C1
[junit4] 2> 231868 T35 C48 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleXMLTest-seed#[B111E977CF0EDEE7]-worker]: SUITE-SolrExampleXMLTest-seed#[B111E977CF0EDEE7]-worker startFullFlush
[junit4] 2> 231868 T35 C48 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleXMLTest-seed#[B111E977CF0EDEE7]-worker]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 231869 T35 C48 oasu.LoggingInfoStream.message [DWFC][SUITE-SolrExampleXMLTest-seed#[B111E977CF0EDEE7]-worker]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=null, aborting=false, numDocsInRAM=0, deleteQueue=DWDQ: [ generation: 144 ]]
[junit4] 2> 231869 T35 C48 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleXMLTest-seed#[B111E977CF0EDEE7]-worker]: SUITE-SolrExampleXMLTest-seed#[B111E977CF0EDEE7]-worker finishFullFlush success=true
[junit4] 2> 231870 T35 C48 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleXMLTest-seed#[B111E977CF0EDEE7]-worker]: apply all deletes during flush
[junit4] 2> 231870 T35 C48 oasu.LoggingInfoStream.message [BD][SUITE-SolrExampleXMLTest-seed#[B111E977CF0EDEE7]-worker]: applyDeletes: no deletes; skipping
[junit4] 2> 231871 T35 C48 oasu.LoggingInfoStream.message [BD][SUITE-SolrExampleXMLTest-seed#[B111E977CF0EDEE7]-worker]: prune sis=org.apache.lucene.index.SegmentInfos@d46fa247 minGen=270 packetCount=0
[junit4] 2> 231871 T35 C48 oasu.LoggingInfoStream.message [CMS][SUITE-SolrExampleXMLTest-seed#[B111E977CF0EDEE7]-worker]: now merge
[junit4] 2> 231872 T35 C48 oasu.LoggingInfoStream.message [CMS][SUITE-SolrExampleXMLTest-seed#[B111E977CF0EDEE7]-worker]: index: _1b(5.0):C1
[junit4] 2> 231872 T35 C48 oasu.LoggingInfoStream.message [CMS][SUITE-SolrExampleXMLTest-seed#[B111E977CF0EDEE7]-worker]: no more merges pending; now return
[junit4] 2> 231872 T35 C48 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleXMLTest-seed#[B111E977CF0EDEE7]-worker]: waitForMerges
[junit4] 2> 231873 T35 C48 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleXMLTest-seed#[B111E977CF0EDEE7]-worker]: waitForMerges done
[junit4] 2> 231873 T35 C48 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleXMLTest-seed#[B111E977CF0EDEE7]-worker]: now call final commit()
[junit4] 2> 231874 T35 C48 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleXMLTest-seed#[B111E977CF0EDEE7]-worker]: commit: start
[junit4] 2> 231874 T35 C48 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleXMLTest-seed#[B111E977CF0EDEE7]-worker]: commit: enter lock
[junit4] 2> 231875 T35 C48 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleXMLTest-seed#[B111E977CF0EDEE7]-worker]: commit: now prepare
[junit4] 2> 231875 T35 C48 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleXMLTest-seed#[B111E977CF0EDEE7]-worker]: prepareCommit: flush
[junit4] 2> 231875 T35 C48 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleXMLTest-seed#[B111E977CF0EDEE7]-worker]: index before flush _1b(5.0):C1
[junit4] 2> 231876 T35 C48 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleXMLTest-seed#[B111E977CF0EDEE7]-worker]: SUITE-SolrExampleXMLTest-seed#[B111E977CF0EDEE7]-worker startFullFlush
[junit4] 2> 231876 T35 C48 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleXMLTest-seed#[B111E977CF0EDEE7]-worker]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 231877 T35 C48 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleXMLTest-seed#[B111E977CF0EDEE7]-worker]: apply all deletes during flush
[junit4] 2> 231877 T35 C48 oasu.LoggingInfoStream.message [BD][SUITE-SolrExampleXMLTest-seed#[B111E977CF0EDEE7]-worker]: applyDeletes: no deletes; skipping
[junit4] 2> 231878 T35 C48 oasu.LoggingInfoStream.message [BD][SUITE-SolrExampleXMLTest-seed#[B111E977CF0EDEE7]-worker]: prune sis=org.apache.lucene.index.SegmentInfos@d46fa247 minGen=270 packetCount=0
[junit4] 2> 231878 T35 C48 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleXMLTest-seed#[B111E977CF0EDEE7]-worker]: SUITE-SolrExampleXMLTest-seed#[B111E977CF0EDEE7]-worker finishFullFlush success=true
[junit4] 2> 231879 T35 C48 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleXMLTest-seed#[B111E977CF0EDEE7]-worker]: startCommit(): start
[junit4] 2> 231879 T35 C48 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleXMLTest-seed#[B111E977CF0EDEE7]-worker]: skip startCommit(): no changes pending
[junit4] 2> 231879 T35 C48 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleXMLTest-seed#[B111E977CF0EDEE7]-worker]: commit: pendingCommit == null; skip
[junit4] 2> 231880 T35 C48 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleXMLTest-seed#[B111E977CF0EDEE7]-worker]: commit: done
[junit4] 2> 231880 T35 C48 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleXMLTest-seed#[B111E977CF0EDEE7]-worker]: at close: _1b(5.0):C1
[junit4] 2> 231881 T35 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 231882 T35 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 231882 T35 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-solrj/test/J0/solrtest-SolrExampleXMLTest-1375292977274/index [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-solrj/test/J0/solrtest-SolrExampleXMLTest-1375292977274/index;done=false>>]
[junit4] 2> 231883 T35 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-solrj/test/J0/solrtest-SolrExampleXMLTest-1375292977274/index
[junit4] 2> 231883 T35 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-solrj/test/J0/solrtest-SolrExampleXMLTest-1375292977274 [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-solrj/test/J0/solrtest-SolrExampleXMLTest-1375292977274;done=false>>]
[junit4] 2> 231884 T35 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-solrj/test/J0/solrtest-SolrExampleXMLTest-1375292977274
[junit4] 2> 231884 T35 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4] 2> 231936 T35 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: test params are: codec=Lucene41, sim=RandomSimilarityProvider(queryNorm=false,coord=crazy): {}, locale=sk, timezone=America/Thunder_Bay
[junit4] 2> NOTE: Linux 3.2.0-51-generic amd64/IBM Corporation 1.7.0 (64-bit)/cpus=8,threads=1,free=15499816,total=55640064
[junit4] 2> NOTE: All tests run in this JVM: [SolrExampleEmbeddedTest, TestUpdateRequestCodec, SolrExampleXMLTest]
[junit4] Completed on J0 in 216.77s, 26 tests, 1 error <<< FAILURES!
[...truncated 37 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:389: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:382: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:194: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:449: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1230: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:873: There were test failures: 46 suites, 272 tests, 1 error, 1 ignored
Total time: 35 minutes 2 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/ibm-j9-jdk7 -Xjit:exclude={org/apache/lucene/util/fst/FST.pack(IIF)Lorg/apache/lucene/util/fst/FST;}
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure