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 2014/02/19 16:13:20 UTC
[JENKINS] Lucene-Solr-trunk-Linux (32bit/jdk1.7.0_60-ea-b04) -
Build # 9526 - Still Failing!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/9526/
Java: 32bit/jdk1.7.0_60-ea-b04 -server -XX:+UseSerialGC
1 tests failed.
FAILED: org.apache.solr.client.solrj.embedded.SolrExampleJettyTest.testUnicode
Error Message:
IOException occured when talking to server at: https://127.0.0.1:37310/solr/collection1
Stack Trace:
org.apache.solr.client.solrj.SolrServerException: IOException occured when talking to server at: https://127.0.0.1:37310/solr/collection1
at __randomizedtesting.SeedInfo.seed([D76ED9335A6D5E62:CEA26D39F8D78F95]:0)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:507)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:199)
at org.apache.solr.client.solrj.request.AbstractUpdateRequest.process(AbstractUpdateRequest.java:117)
at org.apache.solr.client.solrj.SolrServer.commit(SolrServer.java:168)
at org.apache.solr.client.solrj.SolrServer.commit(SolrServer.java:146)
at org.apache.solr.client.solrj.SolrExampleTests.testUnicode(SolrExampleTests.java:371)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
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:744)
Caused by: org.apache.http.NoHttpResponseException: The target server failed to respond
at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:143)
at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:57)
at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:260)
at org.apache.http.impl.AbstractHttpClientConnection.receiveResponseHeader(AbstractHttpClientConnection.java:283)
at org.apache.http.impl.conn.DefaultClientConnection.receiveResponseHeader(DefaultClientConnection.java:251)
at org.apache.http.impl.conn.ManagedClientConnectionImpl.receiveResponseHeader(ManagedClientConnectionImpl.java:197)
at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:271)
at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:123)
at org.apache.http.impl.client.DefaultRequestDirector.tryExecute(DefaultRequestDirector.java:682)
at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:486)
at org.apache.http.impl.client.AbstractHttpClient.doExecute(AbstractHttpClient.java:863)
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82)
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:106)
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:57)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:395)
... 45 more
Build Log:
[...truncated 11496 lines...]
[junit4] Suite: org.apache.solr.client.solrj.embedded.SolrExampleJettyTest
[junit4] 2> log4j:WARN No such property [conversionPattern] in org.apache.solr.util.SolrLogLayout.
[junit4] 2> 907 T10 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (true) and clientAuth (false)
[junit4] 2> 942 T10 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-solrj/test/J1/./solrtest-SolrExampleJettyTest-1392822543979
[junit4] 2> 944 T10 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 1212 T10 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1673 T10 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
[junit4] 2> 1723 T10 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:37310
[junit4] 2> 1964 T10 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 2006 T10 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 2008 T10 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/solr
[junit4] 2> 2009 T10 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/solr/'
[junit4] 2> 2166 T10 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/solr/solr.xml
[junit4] 2> 2359 T10 oasc.CorePropertiesLocator.<init> Config-defined core root directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/solr
[junit4] 2> 2374 T10 oasc.CoreContainer.<init> New CoreContainer 18438958
[junit4] 2> 2375 T10 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/solr/]
[junit4] 2> 2407 T10 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4] 2> 2408 T10 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: null
[junit4] 2> 2415 T10 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4] 2> 2416 T10 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 2416 T10 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 2417 T10 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 2417 T10 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 2418 T10 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 2418 T10 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 2456 T10 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 2457 T10 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 2460 T10 oasc.CoreContainer.load Host Name:
[junit4] 2> 2548 T10 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/solr
[junit4] 2> 2578 T10 oasc.CorePropertiesLocator.discoverUnder Found core collection1 in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/solr/collection1/
[junit4] 2> 2579 T10 oasc.CorePropertiesLocator.discover Found 1 core definitions
[junit4] 2> 2581 T22 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/solr/collection1
[junit4] 2> 2582 T22 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/solr/collection1/'
[junit4] 2> 2703 T22 oasc.SolrConfig.initLibs Adding specified lib dirs to ClassLoader
[junit4] 2> 2705 T22 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> 2705 T22 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> 2706 T22 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> 2707 T22 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> 2707 T22 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> 2708 T22 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> 2709 T22 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> 2709 T22 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> 2929 T22 oasu.SolrIndexConfig.<init> IndexWriter infoStream solr logging is enabled
[junit4] 2> 2935 T22 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 3109 T22 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 3118 T22 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 3236 T22 oass.IndexSchema.readSchema [collection1] Schema name=example
[junit4] 2> 4144 T22 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 4334 T22 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 4349 T22 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 4561 T22 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 4570 T22 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/J1/solrtest-SolrExampleJettyTest-1392822543979/
[junit4] 2> 4573 T22 oasc.JmxMonitoredMap.<init> No JMX servers found, not exposing Solr information with JMX.
[junit4] 2> 4594 T22 oasc.SolrCore.initListeners [collection1] Added SolrEventListener for newSearcher: org.apache.solr.core.QuerySenderListener{queries=[]}
[junit4] 2> 4594 T22 oasc.SolrCore.initListeners [collection1] Added SolrEventListener for firstSearcher: org.apache.solr.core.QuerySenderListener{queries=[{q=static firstSearcher warming in solrconfig.xml}]}
[junit4] 2> 4623 T22 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-solrj/test/J1/solrtest-SolrExampleJettyTest-1392822543979
[junit4] 2> 4624 T22 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-solrj/test/J1/solrtest-SolrExampleJettyTest-1392822543979/index/
[junit4] 2> 4624 T22 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-solrj/test/J1/solrtest-SolrExampleJettyTest-1392822543979/index' doesn't exist. Creating new index...
[junit4] 2> 4635 T22 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-solrj/test/J1/solrtest-SolrExampleJettyTest-1392822543979/index
[junit4] 2> 4670 T22 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-4-thread-1]: init: current segments file is "null"; deletionPolicy=org.apache.solr.core.IndexDeletionPolicyWrapper@1f31cb6
[junit4] 2> 4672 T22 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-4-thread-1]: now checkpoint "" [0 segments ; isCommit = false]
[junit4] 2> 4672 T22 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-4-thread-1]: 0 msec to checkpoint
[junit4] 2> 4673 T22 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-4-thread-1]: init: create=true
[junit4] 2> 4673 T22 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-4-thread-1]:
[junit4] 2> dir=MockDirectoryWrapper(RAMDirectory@16c84bd lockFactory=NativeFSLockFactory@/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-solrj/test/J1/solrtest-SolrExampleJettyTest-1392822543979/index)
[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=Lucene46
[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@14832f4
[junit4] 2> readerPooling=false
[junit4] 2> perThreadHardLimitMB=1945
[junit4] 2> useCompoundFile=false
[junit4] 2>
[junit4] 2> 4674 T22 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-4-thread-1]: now flush at close waitForMerges=true
[junit4] 2> 4675 T22 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-4-thread-1]: start flush: applyAllDeletes=true
[junit4] 2> 4675 T22 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-4-thread-1]: index before flush
[junit4] 2> 4675 T22 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-4-thread-1]: coreLoadExecutor-4-thread-1 startFullFlush
[junit4] 2> 4676 T22 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-4-thread-1]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 4676 T22 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-4-thread-1]: coreLoadExecutor-4-thread-1 finishFullFlush success=true
[junit4] 2> 4677 T22 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-4-thread-1]: apply all deletes during flush
[junit4] 2> 4679 T22 oasu.LoggingInfoStream.message [BD][coreLoadExecutor-4-thread-1]: prune sis=org.apache.lucene.index.SegmentInfos@e8f749 minGen=9223372036854775807 packetCount=0
[junit4] 2> 4680 T22 oasu.LoggingInfoStream.message [CMS][coreLoadExecutor-4-thread-1]: now merge
[junit4] 2> 4681 T22 oasu.LoggingInfoStream.message [CMS][coreLoadExecutor-4-thread-1]: index:
[junit4] 2> 4681 T22 oasu.LoggingInfoStream.message [CMS][coreLoadExecutor-4-thread-1]: no more merges pending; now return
[junit4] 2> 4682 T22 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-4-thread-1]: waitForMerges
[junit4] 2> 4682 T22 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-4-thread-1]: waitForMerges done
[junit4] 2> 4683 T22 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-4-thread-1]: now call final commit()
[junit4] 2> 4684 T22 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-4-thread-1]: commit: start
[junit4] 2> 4684 T22 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-4-thread-1]: commit: enter lock
[junit4] 2> 4685 T22 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-4-thread-1]: commit: now prepare
[junit4] 2> 4685 T22 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-4-thread-1]: prepareCommit: flush
[junit4] 2> 4686 T22 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-4-thread-1]: index before flush
[junit4] 2> 4686 T22 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-4-thread-1]: coreLoadExecutor-4-thread-1 startFullFlush
[junit4] 2> 4686 T22 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-4-thread-1]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 4687 T22 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-4-thread-1]: apply all deletes during flush
[junit4] 2> 4687 T22 oasu.LoggingInfoStream.message [BD][coreLoadExecutor-4-thread-1]: prune sis=org.apache.lucene.index.SegmentInfos@e8f749 minGen=9223372036854775807 packetCount=0
[junit4] 2> 4688 T22 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-4-thread-1]: coreLoadExecutor-4-thread-1 finishFullFlush success=true
[junit4] 2> 4688 T22 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-4-thread-1]: startCommit(): start
[junit4] 2> 4689 T22 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-4-thread-1]: startCommit index= changeCount=1
[junit4] 2> 4692 T22 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-4-thread-1]: done all syncs: []
[junit4] 2> 4693 T22 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-4-thread-1]: commit: pendingCommit != null
[junit4] 2> 4694 T22 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-4-thread-1]: commit: wrote segments file "segments_1"
[junit4] 2> 4694 T22 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-4-thread-1]: now checkpoint "" [0 segments ; isCommit = true]
[junit4] 2> 4700 T22 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@16c84bd lockFactory=NativeFSLockFactory@/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-solrj/test/J1/solrtest-SolrExampleJettyTest-1392822543979/index),segFN=segments_1,generation=1}
[junit4] 2> 4702 T22 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 4703 T22 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-4-thread-1]: 8 msec to checkpoint
[junit4] 2> 4704 T22 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-4-thread-1]: commit: done
[junit4] 2> 4704 T22 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-4-thread-1]: at close:
[junit4] 2> 4711 T22 oasc.SolrCore.initWriters created json: solr.JSONResponseWriter
[junit4] 2> 4712 T22 oasc.SolrCore.initWriters adding lazy queryResponseWriter: solr.VelocityResponseWriter
[junit4] 2> 4713 T22 oasc.SolrCore.initWriters created velocity: solr.VelocityResponseWriter
[junit4] 2> 4721 T22 oasc.SolrCore.initWriters created xslt: solr.XSLTResponseWriter
[junit4] 2> 4721 T22 oasr.XSLTResponseWriter.init xsltCacheLifetimeSeconds=5
[junit4] 2> 4985 T22 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 5005 T22 oasc.RequestHandlers.initHandlersFromConfig created /select: solr.SearchHandler
[junit4] 2> 5006 T22 oasc.RequestHandlers.initHandlersFromConfig created /query: solr.SearchHandler
[junit4] 2> 5010 T22 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 5011 T22 oasc.RequestHandlers.initHandlersFromConfig created /browse: solr.SearchHandler
[junit4] 2> 5017 T22 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 5017 T22 oasc.RequestHandlers.initHandlersFromConfig created /update/json: solr.UpdateRequestHandler
[junit4] 2> 5018 T22 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: solr.UpdateRequestHandler
[junit4] 2> 5018 T22 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.extraction.ExtractingRequestHandler
[junit4] 2> 5020 T22 oasc.RequestHandlers.initHandlersFromConfig created /update/extract: solr.extraction.ExtractingRequestHandler
[junit4] 2> 5021 T22 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.FieldAnalysisRequestHandler
[junit4] 2> 5021 T22 oasc.RequestHandlers.initHandlersFromConfig created /analysis/field: solr.FieldAnalysisRequestHandler
[junit4] 2> 5022 T22 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.DocumentAnalysisRequestHandler
[junit4] 2> 5022 T22 oasc.RequestHandlers.initHandlersFromConfig created /analysis/document: solr.DocumentAnalysisRequestHandler
[junit4] 2> 5030 T22 oasc.RequestHandlers.initHandlersFromConfig created /admin/: solr.admin.AdminHandlers
[junit4] 2> 5037 T22 oasc.RequestHandlers.initHandlersFromConfig created /admin/ping: solr.PingRequestHandler
[junit4] 2> 5043 T22 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4] 2> 5058 T22 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 5059 T22 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
[junit4] 2> 5059 T22 oasc.RequestHandlers.initHandlersFromConfig created /spell: solr.SearchHandler
[junit4] 2> 5059 T22 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
[junit4] 2> 5060 T22 oasc.RequestHandlers.initHandlersFromConfig created /suggest: solr.SearchHandler
[junit4] 2> 5060 T22 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
[junit4] 2> 5060 T22 oasc.RequestHandlers.initHandlersFromConfig created /tvrh: solr.SearchHandler
[junit4] 2> 5061 T22 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
[junit4] 2> 5061 T22 oasc.RequestHandlers.initHandlersFromConfig created /terms: solr.SearchHandler
[junit4] 2> 5061 T22 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
[junit4] 2> 5062 T22 oasc.RequestHandlers.initHandlersFromConfig created /elevate: solr.SearchHandler
[junit4] 2> 5089 T22 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 5094 T22 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 5095 T22 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 5127 T22 oasu.CommitTracker.<init> Hard AutoCommit: if uncommited for 15000ms;
[junit4] 2> 5128 T22 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 5129 T22 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-4-thread-1]: init: current segments file is "segments_1"; deletionPolicy=org.apache.solr.core.IndexDeletionPolicyWrapper@1f31cb6
[junit4] 2> 5130 T22 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-4-thread-1]: init: load commit "segments_1"
[junit4] 2> 5130 T22 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@16c84bd lockFactory=NativeFSLockFactory@/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-solrj/test/J1/solrtest-SolrExampleJettyTest-1392822543979/index),segFN=segments_1,generation=1}
[junit4] 2> 5131 T22 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 5131 T22 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-4-thread-1]: now checkpoint "" [0 segments ; isCommit = false]
[junit4] 2> 5132 T22 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-4-thread-1]: 0 msec to checkpoint
[junit4] 2> 5132 T22 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-4-thread-1]: init: create=false
[junit4] 2> 5133 T22 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-4-thread-1]:
[junit4] 2> dir=MockDirectoryWrapper(RAMDirectory@16c84bd lockFactory=NativeFSLockFactory@/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-solrj/test/J1/solrtest-SolrExampleJettyTest-1392822543979/index)
[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=Lucene46
[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@1be3a91
[junit4] 2> readerPooling=false
[junit4] 2> perThreadHardLimitMB=1945
[junit4] 2> useCompoundFile=false
[junit4] 2>
[junit4] 2> 5136 T22 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-4-thread-1]: flush at getReader
[junit4] 2> 5136 T22 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-4-thread-1]: coreLoadExecutor-4-thread-1 startFullFlush
[junit4] 2> 5136 T22 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-4-thread-1]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 5137 T22 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-4-thread-1]: apply all deletes during flush
[junit4] 2> 5137 T22 oasu.LoggingInfoStream.message [BD][coreLoadExecutor-4-thread-1]: prune sis=org.apache.lucene.index.SegmentInfos@83ca2e minGen=9223372036854775807 packetCount=0
[junit4] 2> 5140 T22 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-4-thread-1]: return reader version=1 reader=StandardDirectoryReader(segments_1:1:nrt)
[junit4] 2> 5141 T22 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-4-thread-1]: coreLoadExecutor-4-thread-1 finishFullFlush success=true
[junit4] 2> 5141 T22 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-4-thread-1]: getReader took 5 msec
[junit4] 2> 5151 T22 oass.SolrIndexSearcher.<init> Opening Searcher@1a7bd4d[collection1] main
[junit4] 2> 5160 T22 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4] 2> 5175 T22 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> 5190 T22 oashc.SpellCheckComponent.inform No queryConverter defined, using default converter
[junit4] 2> 5192 T22 oashc.SuggestComponent.inform Initializing SuggestComponent
[junit4] 2> 5195 T22 oasss.SolrSuggester.init init: {name=mySuggester,lookupImpl=FuzzyLookupFactory,dictionaryImpl=DocumentDictionaryFactory,field=cat,weightField=price,suggestAnalyzerFieldType=string}
[junit4] 2> 5242 T22 oasss.SolrSuggester.init Dictionary loaded with params: {name=mySuggester,lookupImpl=FuzzyLookupFactory,dictionaryImpl=DocumentDictionaryFactory,field=cat,weightField=price,suggestAnalyzerFieldType=string}
[junit4] 2> 5248 T22 oashc.QueryElevationComponent.inform Loading QueryElevation from: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/solr/collection1/conf/elevate.xml
[junit4] 2> 5316 T22 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4] 2> 5316 T23 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@1a7bd4d[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 5318 T22 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 5326 T10 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-solrj/test/J1
[junit4] 2> 5327 T10 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 5328 T10 oas.SolrJettyTestBase.createJetty Jetty Assigned Port#37310
[junit4] 2> 5361 T10 oas.SolrTestCaseJ4.setUp ###Starting testCommitWithinOnAdd
[junit4] 2> ASYNC NEW_CORE C0 name=collection1 org.apache.solr.core.SolrCore@19bd80e
[junit4] 2> 5409 T23 C0 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=89
[junit4] 2> 5411 T23 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 5411 T23 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: default
[junit4] 2> 5412 T23 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: wordbreak
[junit4] 2> 5412 T23 oashc.SuggestComponent$SuggesterListener.newSearcher Loading suggester index for: mySuggester
[junit4] 2> 5413 T23 oasss.SolrSuggester.reload reload()
[junit4] 2> 5413 T23 oasss.SolrSuggester.build build()
[junit4] 2> 5437 T23 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1a7bd4d[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> ASYNC NEW_CORE C1 name=collection1 org.apache.solr.core.SolrCore@19bd80e
[junit4] 2> 10923 T20 C1 oasu.LoggingInfoStream.message [DW][qtp28033213-20]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 10928 T20 C1 oasu.LoggingInfoStream.message [IW][qtp28033213-20]: nrtIsCurrent: infoVersion matches: true; DW changes: true; BD changes: false
[junit4] 2> 10931 T20 C1 oasu.LoggingInfoStream.message [DW][qtp28033213-20]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 10934 T20 C1 oasu.LoggingInfoStream.message [IW][qtp28033213-20]: flush at getReader
[junit4] 2> 10936 T20 C1 oasu.LoggingInfoStream.message [DW][qtp28033213-20]: qtp28033213-20 startFullFlush
[junit4] 2> 10938 T20 C1 oasu.LoggingInfoStream.message [DW][qtp28033213-20]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 10939 T20 C1 oasu.LoggingInfoStream.message [DW][qtp28033213-20]: qtp28033213-20: flush naked frozen global deletes
[junit4] 2> 10949 T20 C1 oasu.LoggingInfoStream.message [BD][qtp28033213-20]: push deletes 1 deleted queries bytesUsed=32 delGen=2 packetCount=1 totBytesUsed=32
[junit4] 2> 10950 T20 C1 oasu.LoggingInfoStream.message [DW][qtp28033213-20]: flush: push buffered updates: 1 deleted queries bytesUsed=32
[junit4] 2> 10951 T20 C1 oasu.LoggingInfoStream.message [IW][qtp28033213-20]: apply all deletes during flush
[junit4] 2> 10951 T20 C1 oasu.LoggingInfoStream.message [BD][qtp28033213-20]: prune sis=org.apache.lucene.index.SegmentInfos@83ca2e minGen=9223372036854775807 packetCount=1
[junit4] 2> 10952 T20 C1 oasu.LoggingInfoStream.message [BD][qtp28033213-20]: pruneDeletes: prune 1 packets; 0 packets remain
[junit4] 2> 10953 T20 C1 oasu.LoggingInfoStream.message [IW][qtp28033213-20]: return reader version=1 reader=StandardDirectoryReader(segments_1:1:nrt)
[junit4] 2> 10953 T20 C1 oasu.LoggingInfoStream.message [DW][qtp28033213-20]: qtp28033213-20 finishFullFlush success=true
[junit4] 2> 10954 T20 C1 oasu.LoggingInfoStream.message [IW][qtp28033213-20]: getReader took 20 msec
[junit4] 2> 10958 T20 C1 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {deleteByQuery=*:* (-1460480302288732160)} 0 151
[junit4] 2> ASYNC NEW_CORE C2 name=collection1 org.apache.solr.core.SolrCore@19bd80e
[junit4] 2> 11036 T18 C2 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 11038 T18 C2 oasu.LoggingInfoStream.message [DW][qtp28033213-18]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 11040 T18 C2 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
[junit4] 2> 11042 T18 C2 oasu.LoggingInfoStream.message [DW][qtp28033213-18]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 11043 T18 C2 oasu.LoggingInfoStream.message [IW][qtp28033213-18]: nrtIsCurrent: infoVersion matches: true; DW changes: false; BD changes: false
[junit4] 2> 11045 T18 C2 oasu.LoggingInfoStream.message [DW][qtp28033213-18]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 11047 T18 C2 oass.SolrIndexSearcher.<init> Opening Searcher@c2083f[collection1] main
[junit4] 2> 11052 T23 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@c2083f[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 11053 T18 C2 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 11054 T23 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 11056 T23 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@c2083f[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 11059 T18 C2 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&softCommit=false&commit=true&waitSearcher=true&wt=javabin} {commit=} 0 24
[junit4] 2> 11080 T19 C2 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={version=2&q=*:*&wt=javabin} hits=0 status=0 QTime=2
[junit4] 2> 11155 T20 C2 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[id3 (1460480302520467456)]} 0 62
[junit4] 2> 11161 T21 C2 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={version=2&q=*:*&wt=javabin} hits=0 status=0 QTime=1
[junit4] 2> 11655 T26 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 11657 T26 oasu.LoggingInfoStream.message [DW][commitScheduler-8-thread-1]: anyChanges? numDocsInRam=1 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 11657 T26 oasu.LoggingInfoStream.message [IW][commitScheduler-8-thread-1]: nrtIsCurrent: infoVersion matches: false; DW changes: true; BD changes: false
[junit4] 2> 11658 T26 oasu.LoggingInfoStream.message [IW][commitScheduler-8-thread-1]: flush at getReader
[junit4] 2> 11659 T26 oasu.LoggingInfoStream.message [DW][commitScheduler-8-thread-1]: commitScheduler-8-thread-1 startFullFlush
[junit4] 2> 11660 T26 oasu.LoggingInfoStream.message [DW][commitScheduler-8-thread-1]: anyChanges? numDocsInRam=1 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 11661 T26 oasu.LoggingInfoStream.message [DWFC][commitScheduler-8-thread-1]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=_0, aborting=false, numDocsInRAM=1, deleteQueue=DWDQ: [ generation: 2 ]]
[junit4] 2> 11666 T26 oasu.LoggingInfoStream.message [DWPT][commitScheduler-8-thread-1]: flush postings as segment _0 numDocs=1
[junit4] 2> 11712 T26 oasu.LoggingInfoStream.message [DWPT][commitScheduler-8-thread-1]: new segment has 0 deleted docs
[junit4] 2> 11712 T26 oasu.LoggingInfoStream.message [DWPT][commitScheduler-8-thread-1]: new segment has no vectors; norms; no docValues; prox; freqs
[junit4] 2> 11713 T26 oasu.LoggingInfoStream.message [DWPT][commitScheduler-8-thread-1]: flushedFiles=[_0_Lucene41_0.tim, _0_Lucene41_0.tip, _0.nvm, _0.fdt, _0_Lucene41_0.doc, _0_Lucene41_0.pos, _0.nvd, _0.fdx, _0.fnm]
[junit4] 2> 11713 T26 oasu.LoggingInfoStream.message [DWPT][commitScheduler-8-thread-1]: flushed codec=Lucene46
[junit4] 2> 11714 T26 oasu.LoggingInfoStream.message [DWPT][commitScheduler-8-thread-1]: flushed: segment=_0 ramUsed=0.079 MB newFlushedSize(includes docstores)=0.002 MB docs/MB=658.24
[junit4] 2> 11718 T26 oasu.LoggingInfoStream.message [DW][commitScheduler-8-thread-1]: publishFlushedSegment seg-private updates=null
[junit4] 2> 11718 T26 oasu.LoggingInfoStream.message [IW][commitScheduler-8-thread-1]: publishFlushedSegment
[junit4] 2> 11718 T26 oasu.LoggingInfoStream.message [BD][commitScheduler-8-thread-1]: push deletes 1 deleted terms (unique count=1) bytesUsed=1024 delGen=4 packetCount=1 totBytesUsed=1024
[junit4] 2> 11719 T26 oasu.LoggingInfoStream.message [IW][commitScheduler-8-thread-1]: publish sets newSegment delGen=5 seg=_0(5.0):C1
[junit4] 2> 11719 T26 oasu.LoggingInfoStream.message [IFD][commitScheduler-8-thread-1]: now checkpoint "_0(5.0):C1" [1 segments ; isCommit = false]
[junit4] 2> 11720 T26 oasu.LoggingInfoStream.message [IFD][commitScheduler-8-thread-1]: 0 msec to checkpoint
[junit4] 2> 11720 T26 oasu.LoggingInfoStream.message [IW][commitScheduler-8-thread-1]: apply all deletes during flush
[junit4] 2> 11720 T26 oasu.LoggingInfoStream.message [BD][commitScheduler-8-thread-1]: applyDeletes: infos=[_0(5.0):C1] packetCount=1
[junit4] 2> 11721 T26 oasu.LoggingInfoStream.message [BD][commitScheduler-8-thread-1]: applyDeletes took 1 msec
[junit4] 2> 11721 T26 oasu.LoggingInfoStream.message [BD][commitScheduler-8-thread-1]: prune sis=org.apache.lucene.index.SegmentInfos@83ca2e minGen=6 packetCount=1
[junit4] 2> 11721 T26 oasu.LoggingInfoStream.message [BD][commitScheduler-8-thread-1]: pruneDeletes: prune 1 packets; 0 packets remain
[junit4] 2> 11748 T26 oasu.LoggingInfoStream.message [IW][commitScheduler-8-thread-1]: return reader version=3 reader=StandardDirectoryReader(segments_1:3:nrt _0(5.0):C1)
[junit4] 2> 11748 T26 oasu.LoggingInfoStream.message [DW][commitScheduler-8-thread-1]: commitScheduler-8-thread-1 finishFullFlush success=true
[junit4] 2> 11749 T26 oasu.LoggingInfoStream.message [TMP][commitScheduler-8-thread-1]: findMerges: 1 segments
[junit4] 2> 11751 T26 oasu.LoggingInfoStream.message [TMP][commitScheduler-8-thread-1]: seg=_0(5.0):C1 size=0.001 MB [floored]
[junit4] 2> 11751 T26 oasu.LoggingInfoStream.message [TMP][commitScheduler-8-thread-1]: allowedSegmentCount=1 vs count=1 (eligible count=1) tooBigCount=0
[junit4] 2> 11752 T26 oasu.LoggingInfoStream.message [CMS][commitScheduler-8-thread-1]: now merge
[junit4] 2> 11752 T26 oasu.LoggingInfoStream.message [CMS][commitScheduler-8-thread-1]: index: _0(5.0):C1
[junit4] 2> 11753 T26 oasu.LoggingInfoStream.message [CMS][commitScheduler-8-thread-1]: no more merges pending; now return
[junit4] 2> 11753 T26 oasu.LoggingInfoStream.message [IW][commitScheduler-8-thread-1]: getReader took 95 msec
[junit4] 2> 11753 T26 oass.SolrIndexSearcher.<init> Opening Searcher@9618fc[collection1] main
[junit4] 2> 11754 T26 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 11754 T23 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@9618fc[collection1] main{StandardDirectoryReader(segments_1:3:nrt _0(5.0):C1)}
[junit4] 2> 11755 T23 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 11756 T23 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@9618fc[collection1] main{StandardDirectoryReader(segments_1:3:nrt _0(5.0):C1)}
[junit4] 2> 12180 T20 C2 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={version=2&q=id:id3&wt=javabin} hits=1 status=0 QTime=13
[junit4] 2> 12193 T18 C2 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[id4 (1460480303668658176)]} 0 3
[junit4] 2> 12693 T26 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 12694 T26 oasu.LoggingInfoStream.message [DW][commitScheduler-8-thread-1]: anyChanges? numDocsInRam=1 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 12695 T26 oasu.LoggingInfoStream.message [IW][commitScheduler-8-thread-1]: nrtIsCurrent: infoVersion matches: false; DW changes: true; BD changes: false
[junit4] 2> 12695 T26 oasu.LoggingInfoStream.message [IW][commitScheduler-8-thread-1]: flush at getReader
[junit4] 2> 12696 T26 oasu.LoggingInfoStream.message [DW][commitScheduler-8-thread-1]: commitScheduler-8-thread-1 startFullFlush
[junit4] 2> 12696 T26 oasu.LoggingInfoStream.message [DW][commitScheduler-8-thread-1]: anyChanges? numDocsInRam=1 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 12697 T26 oasu.LoggingInfoStream.message [DWFC][commitScheduler-8-thread-1]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=_1, aborting=false, numDocsInRAM=1, deleteQueue=DWDQ: [ generation: 3 ]]
[junit4] 2> 12697 T26 oasu.LoggingInfoStream.message [DWPT][commitScheduler-8-thread-1]: flush postings as segment _1 numDocs=1
[junit4] 2> 12702 T26 oasu.LoggingInfoStream.message [DWPT][commitScheduler-8-thread-1]: new segment has 0 deleted docs
[junit4] 2> 12702 T26 oasu.LoggingInfoStream.message [DWPT][commitScheduler-8-thread-1]: new segment has no vectors; norms; no docValues; prox; freqs
[junit4] 2> 12703 T26 oasu.LoggingInfoStream.message [DWPT][commitScheduler-8-thread-1]: flushedFiles=[_1.nvd, _1_Lucene41_0.tim, _1_Lucene41_0.doc, _1.fdt, _1.nvm, _1_Lucene41_0.pos, _1.fdx, _1.fnm, _1_Lucene41_0.tip]
[junit4] 2> 12703 T26 oasu.LoggingInfoStream.message [DWPT][commitScheduler-8-thread-1]: flushed codec=Lucene46
[junit4] 2> 12704 T26 oasu.LoggingInfoStream.message [DWPT][commitScheduler-8-thread-1]: flushed: segment=_1 ramUsed=0.079 MB newFlushedSize(includes docstores)=0.002 MB docs/MB=658.24
[junit4] 2> 12704 T26 oasu.LoggingInfoStream.message [DW][commitScheduler-8-thread-1]: publishFlushedSegment seg-private updates=null
[junit4] 2> 12705 T26 oasu.LoggingInfoStream.message [IW][commitScheduler-8-thread-1]: publishFlushedSegment
[junit4] 2> 12705 T26 oasu.LoggingInfoStream.message [BD][commitScheduler-8-thread-1]: push deletes 1 deleted terms (unique count=1) bytesUsed=1024 delGen=7 packetCount=1 totBytesUsed=1024
[junit4] 2> 12705 T26 oasu.LoggingInfoStream.message [IW][commitScheduler-8-thread-1]: publish sets newSegment delGen=8 seg=_1(5.0):C1
[junit4] 2> 12706 T26 oasu.LoggingInfoStream.message [IFD][commitScheduler-8-thread-1]: now checkpoint "_0(5.0):C1 _1(5.0):C1" [2 segments ; isCommit = false]
[junit4] 2> 12706 T26 oasu.LoggingInfoStream.message [IFD][commitScheduler-8-thread-1]: 0 msec to checkpoint
[junit4] 2> 12707 T26 oasu.LoggingInfoStream.message [IW][commitScheduler-8-thread-1]: apply all deletes during flush
[junit4] 2> 12707 T26 oasu.LoggingInfoStream.message [BD][commitScheduler-8-thread-1]: applyDeletes: infos=[_0(5.0):C1, _1(5.0):C1] packetCount=1
[junit4] 2> 12715 T26 oasu.LoggingInfoStream.message [BD][commitScheduler-8-thread-1]: seg=_0(5.0):C1 segGen=6 coalesced deletes=[CoalescedUpdates(termSets=1,queries=0,numericUpdates=0)] newDelCount=0
[junit4] 2> 12724 T26 oasu.LoggingInfoStream.message [BD][commitScheduler-8-thread-1]: applyDeletes took 17 msec
[junit4] 2> 12724 T26 oasu.LoggingInfoStream.message [BD][commitScheduler-8-thread-1]: prune sis=org.apache.lucene.index.SegmentInfos@83ca2e minGen=9 packetCount=1
[junit4] 2> 12725 T26 oasu.LoggingInfoStream.message [BD][commitScheduler-8-thread-1]: pruneDeletes: prune 1 packets; 0 packets remain
[junit4] 2> 12727 T26 oasu.LoggingInfoStream.message [IW][commitScheduler-8-thread-1]: return reader version=5 reader=StandardDirectoryReader(segments_1:5:nrt _0(5.0):C1 _1(5.0):C1)
[junit4] 2> 12728 T26 oasu.LoggingInfoStream.message [DW][commitScheduler-8-thread-1]: commitScheduler-8-thread-1 finishFullFlush success=true
[junit4] 2> 12728 T26 oasu.LoggingInfoStream.message [TMP][commitScheduler-8-thread-1]: findMerges: 2 segments
[junit4] 2> 12729 T26 oasu.LoggingInfoStream.message [TMP][commitScheduler-8-thread-1]: seg=_0(5.0):C1 size=0.001 MB [floored]
[junit4] 2> 12729 T26 oasu.LoggingInfoStream.message [TMP][commitScheduler-8-thread-1]: seg=_1(5.0):C1 size=0.001 MB [floored]
[junit4] 2> 12729 T26 oasu.LoggingInfoStream.message [TMP][commitScheduler-8-thread-1]: allowedSegmentCount=1 vs count=2 (eligible count=2) tooBigCount=0
[junit4] 2> 12730 T26 oasu.LoggingInfoStream.message [CMS][commitScheduler-8-thread-1]: now merge
[junit4] 2> 12730 T26 oasu.LoggingInfoStream.message [CMS][commitScheduler-8-thread-1]: index: _0(5.0):C1 _1(5.0):C1
[junit4] 2> 12730 T26 oasu.LoggingInfoStream.message [CMS][commitScheduler-8-thread-1]: no more merges pending; now return
[junit4] 2> 12731 T26 oasu.LoggingInfoStream.message [IW][commitScheduler-8-thread-1]: getReader took 36 msec
[junit4] 2> 12732 T26 oass.SolrIndexSearcher.<init> Opening Searcher@81290d[collection1] main
[junit4] 2> 12733 T26 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 12733 T23 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@81290d[collection1] main{StandardDirectoryReader(segments_1:5:nrt _0(5.0):C1 _1(5.0):C1)}
[junit4] 2> 12733 T23 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 12734 T23 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@81290d[collection1] main{StandardDirectoryReader(segments_1:5:nrt _0(5.0):C1 _1(5.0):C1)}
[junit4] 2> ASYNC NEW_CORE C3 name=collection1 org.apache.solr.core.SolrCore@19bd80e
[junit4] 2> 13200 T18 C3 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={version=2&q=id:id4&wt=javabin} hits=1 status=0 QTime=2
[junit4] 2> 13202 T10 oas.SolrTestCaseJ4.tearDown ###Ending testCommitWithinOnAdd
[junit4] 2> 13223 T10 oas.SolrTestCaseJ4.setUp ###Starting testUpdateMultiValuedField
[junit4] 2> 13229 T19 C3 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[123 (1460480304756031488)]} 0 2
[junit4] 2> 13234 T21 C3 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 13235 T21 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-21]: commit: start
[junit4] 2> 13235 T21 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-21]: commit: enter lock
[junit4] 2> 13236 T21 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-21]: commit: now prepare
[junit4] 2> 13237 T21 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-21]: prepareCommit: flush
[junit4] 2> 13238 T21 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-21]: index before flush _0(5.0):C1 _1(5.0):C1
[junit4] 2> 13238 T21 C3 oasu.LoggingInfoStream.message [DW][qtp28033213-21]: qtp28033213-21 startFullFlush
[junit4] 2> 13239 T21 C3 oasu.LoggingInfoStream.message [DW][qtp28033213-21]: anyChanges? numDocsInRam=1 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 13239 T21 C3 oasu.LoggingInfoStream.message [DWFC][qtp28033213-21]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=_2, aborting=false, numDocsInRAM=1, deleteQueue=DWDQ: [ generation: 4 ]]
[junit4] 2> 13240 T21 C3 oasu.LoggingInfoStream.message [DWPT][qtp28033213-21]: flush postings as segment _2 numDocs=1
[junit4] 2> 13242 T21 C3 oasu.LoggingInfoStream.message [DWPT][qtp28033213-21]: new segment has 0 deleted docs
[junit4] 2> 13243 T21 C3 oasu.LoggingInfoStream.message [DWPT][qtp28033213-21]: new segment has no vectors; no norms; no docValues; no prox; no freqs
[junit4] 2> 13243 T21 C3 oasu.LoggingInfoStream.message [DWPT][qtp28033213-21]: flushedFiles=[_2.fdx, _2.fnm, _2_Lucene41_0.tip, _2_Lucene41_0.tim, _2_Lucene41_0.doc, _2.fdt]
[junit4] 2> 13243 T21 C3 oasu.LoggingInfoStream.message [DWPT][qtp28033213-21]: flushed codec=Lucene46
[junit4] 2> 13244 T21 C3 oasu.LoggingInfoStream.message [DWPT][qtp28033213-21]: flushed: segment=_2 ramUsed=0.063 MB newFlushedSize(includes docstores)=0.001 MB docs/MB=1,762.313
[junit4] 2> 13245 T21 C3 oasu.LoggingInfoStream.message [DW][qtp28033213-21]: publishFlushedSegment seg-private updates=null
[junit4] 2> 13245 T21 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-21]: publishFlushedSegment
[junit4] 2> 13246 T21 C3 oasu.LoggingInfoStream.message [BD][qtp28033213-21]: push deletes 1 deleted terms (unique count=1) bytesUsed=1024 delGen=10 packetCount=1 totBytesUsed=1024
[junit4] 2> 13246 T21 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-21]: publish sets newSegment delGen=11 seg=_2(5.0):C1
[junit4] 2> 13247 T21 C3 oasu.LoggingInfoStream.message [IFD][qtp28033213-21]: now checkpoint "_0(5.0):C1 _1(5.0):C1 _2(5.0):C1" [3 segments ; isCommit = false]
[junit4] 2> 13247 T21 C3 oasu.LoggingInfoStream.message [IFD][qtp28033213-21]: 0 msec to checkpoint
[junit4] 2> 13248 T21 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-21]: apply all deletes during flush
[junit4] 2> 13248 T21 C3 oasu.LoggingInfoStream.message [BD][qtp28033213-21]: applyDeletes: infos=[_0(5.0):C1, _1(5.0):C1, _2(5.0):C1] packetCount=1
[junit4] 2> 13249 T21 C3 oasu.LoggingInfoStream.message [BD][qtp28033213-21]: seg=_1(5.0):C1 segGen=9 coalesced deletes=[CoalescedUpdates(termSets=1,queries=0,numericUpdates=0)] newDelCount=0
[junit4] 2> 13249 T21 C3 oasu.LoggingInfoStream.message [BD][qtp28033213-21]: seg=_0(5.0):C1 segGen=9 coalesced deletes=[CoalescedUpdates(termSets=1,queries=0,numericUpdates=0)] newDelCount=0
[junit4] 2> 13250 T21 C3 oasu.LoggingInfoStream.message [BD][qtp28033213-21]: applyDeletes took 2 msec
[junit4] 2> 13250 T21 C3 oasu.LoggingInfoStream.message [BD][qtp28033213-21]: prune sis=org.apache.lucene.index.SegmentInfos@83ca2e minGen=12 packetCount=1
[junit4] 2> 13251 T21 C3 oasu.LoggingInfoStream.message [BD][qtp28033213-21]: pruneDeletes: prune 1 packets; 0 packets remain
[junit4] 2> 13251 T21 C3 oasu.LoggingInfoStream.message [DW][qtp28033213-21]: qtp28033213-21 finishFullFlush success=true
[junit4] 2> 13252 T21 C3 oasu.LoggingInfoStream.message [TMP][qtp28033213-21]: findMerges: 3 segments
[junit4] 2> 13254 T21 C3 oasu.LoggingInfoStream.message [TMP][qtp28033213-21]: seg=_0(5.0):C1 size=0.001 MB [floored]
[junit4] 2> 13254 T21 C3 oasu.LoggingInfoStream.message [TMP][qtp28033213-21]: seg=_1(5.0):C1 size=0.001 MB [floored]
[junit4] 2> 13255 T21 C3 oasu.LoggingInfoStream.message [TMP][qtp28033213-21]: seg=_2(5.0):C1 size=0.000 MB [floored]
[junit4] 2> 13255 T21 C3 oasu.LoggingInfoStream.message [TMP][qtp28033213-21]: allowedSegmentCount=1 vs count=3 (eligible count=3) tooBigCount=0
[junit4] 2> 13256 T21 C3 oasu.LoggingInfoStream.message [CMS][qtp28033213-21]: now merge
[junit4] 2> 13256 T21 C3 oasu.LoggingInfoStream.message [CMS][qtp28033213-21]: index: _0(5.0):C1 _1(5.0):C1 _2(5.0):C1
[junit4] 2> 13257 T21 C3 oasu.LoggingInfoStream.message [CMS][qtp28033213-21]: no more merges pending; now return
[junit4] 2> 13257 T21 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-21]: startCommit(): start
[junit4] 2> 13258 T21 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-21]: startCommit index=_0(5.0):C1 _1(5.0):C1 _2(5.0):C1 changeCount=7
[junit4] 2> 13259 T21 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-21]: done all syncs: [_0_Lucene41_0.tim, _1.nvd, _0.si, _0.fdt, _2.fdt, _0.fnm, _2_Lucene41_0.tip, _1.nvm, _1.si, _2.si, _1_Lucene41_0.doc, _0_Lucene41_0.pos, _1_Lucene41_0.pos, _1.fdx, _2_Lucene41_0.doc, _1.fnm, _0_Lucene41_0.tip, _1_Lucene41_0.tim, _0.nvm, _2.fdx, _0_Lucene41_0.doc, _2.fnm, _1.fdt, _2_Lucene41_0.tim, _0.fdx, _0.nvd, _1_Lucene41_0.tip]
[junit4] 2> 13259 T21 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-21]: commit: pendingCommit != null
[junit4] 2> 13260 T21 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-21]: commit: wrote segments file "segments_2"
[junit4] 2> 13260 T21 C3 oasu.LoggingInfoStream.message [IFD][qtp28033213-21]: now checkpoint "_0(5.0):C1 _1(5.0):C1 _2(5.0):C1" [3 segments ; isCommit = true]
[junit4] 2> 13261 T21 C3 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@16c84bd lockFactory=NativeFSLockFactory@/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-solrj/test/J1/solrtest-SolrExampleJettyTest-1392822543979/index),segFN=segments_1,generation=1}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@16c84bd lockFactory=NativeFSLockFactory@/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-solrj/test/J1/solrtest-SolrExampleJettyTest-1392822543979/index),segFN=segments_2,generation=2}
[junit4] 2> 13262 T21 C3 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4] 2> 13262 T21 C3 oasu.LoggingInfoStream.message [IFD][qtp28033213-21]: deleteCommits: now decRef commit "segments_1"
[junit4] 2> 13262 T21 C3 oasu.LoggingInfoStream.message [IFD][qtp28033213-21]: delete "segments_1"
[junit4] 2> 13263 T21 C3 oasu.LoggingInfoStream.message [IFD][qtp28033213-21]: 2 msec to checkpoint
[junit4] 2> 13263 T21 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-21]: commit: done
[junit4] 2> 13264 T21 C3 oasu.LoggingInfoStream.message [DW][qtp28033213-21]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 13264 T21 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-21]: nrtIsCurrent: infoVersion matches: false; DW changes: false; BD changes: false
[junit4] 2> 13265 T21 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-21]: flush at getReader
[junit4] 2> 13265 T21 C3 oasu.LoggingInfoStream.message [DW][qtp28033213-21]: qtp28033213-21 startFullFlush
[junit4] 2> 13265 T21 C3 oasu.LoggingInfoStream.message [DW][qtp28033213-21]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 13266 T21 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-21]: apply all deletes during flush
[junit4] 2> 13266 T21 C3 oasu.LoggingInfoStream.message [BD][qtp28033213-21]: applyDeletes: no deletes; skipping
[junit4] 2> 13267 T21 C3 oasu.LoggingInfoStream.message [BD][qtp28033213-21]: prune sis=org.apache.lucene.index.SegmentInfos@83ca2e minGen=12 packetCount=0
[junit4] 2> 13268 T21 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-21]: return reader version=7 reader=StandardDirectoryReader(segments_2:7:nrt _0(5.0):C1 _1(5.0):C1 _2(5.0):C1)
[junit4] 2> 13269 T21 C3 oasu.LoggingInfoStream.message [DW][qtp28033213-21]: qtp28033213-21 finishFullFlush success=true
[junit4] 2> 13269 T21 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-21]: getReader took 4 msec
[junit4] 2> 13270 T21 C3 oass.SolrIndexSearcher.<init> Opening Searcher@187647[collection1] main
[junit4] 2> 13270 T21 C3 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 13270 T23 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@187647[collection1] main{StandardDirectoryReader(segments_2:7:nrt _0(5.0):C1 _1(5.0):C1 _2(5.0):C1)}
[junit4] 2> 13271 T23 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 13271 T23 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@187647[collection1] main{StandardDirectoryReader(segments_2:7:nrt _0(5.0):C1 _1(5.0):C1 _2(5.0):C1)}
[junit4] 2> 13272 T21 C3 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&softCommit=false&commit=true&waitSearcher=true&wt=javabin} {commit=} 0 38
[junit4] 2> 13277 T20 C3 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={version=2&q=id:123&wt=javabin} hits=1 status=0 QTime=1
[junit4] 2> 13298 T18 C3 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[123 (1460480304829431808)]} 0 15
[junit4] 2> 13304 T19 C3 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 13304 T19 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-19]: commit: start
[junit4] 2> 13305 T19 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-19]: commit: enter lock
[junit4] 2> 13305 T19 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-19]: commit: now prepare
[junit4] 2> 13305 T19 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-19]: prepareCommit: flush
[junit4] 2> 13306 T19 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-19]: index before flush _0(5.0):C1 _1(5.0):C1 _2(5.0):C1
[junit4] 2> 13307 T19 C3 oasu.LoggingInfoStream.message [DW][qtp28033213-19]: qtp28033213-19 startFullFlush
[junit4] 2> 13307 T19 C3 oasu.LoggingInfoStream.message [DW][qtp28033213-19]: anyChanges? numDocsInRam=1 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 13307 T19 C3 oasu.LoggingInfoStream.message [DWFC][qtp28033213-19]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=_3, aborting=false, numDocsInRAM=1, deleteQueue=DWDQ: [ generation: 6 ]]
[junit4] 2> 13308 T19 C3 oasu.LoggingInfoStream.message [DWPT][qtp28033213-19]: flush postings as segment _3 numDocs=1
[junit4] 2> 13311 T19 C3 oasu.LoggingInfoStream.message [DWPT][qtp28033213-19]: new segment has 0 deleted docs
[junit4] 2> 13311 T19 C3 oasu.LoggingInfoStream.message [DWPT][qtp28033213-19]: new segment has no vectors; no norms; no docValues; no prox; no freqs
[junit4] 2> 13312 T19 C3 oasu.LoggingInfoStream.message [DWPT][qtp28033213-19]: flushedFiles=[_3_Lucene41_0.tim, _3.fnm, _3_Lucene41_0.doc, _3.fdt, _3_Lucene41_0.tip, _3.fdx]
[junit4] 2> 13312 T19 C3 oasu.LoggingInfoStream.message [DWPT][qtp28033213-19]: flushed codec=Lucene46
[junit4] 2> 13313 T19 C3 oasu.LoggingInfoStream.message [DWPT][qtp28033213-19]: flushed: segment=_3 ramUsed=0.063 MB newFlushedSize(includes docstores)=0.001 MB docs/MB=1,346.054
[junit4] 2> 13313 T19 C3 oasu.LoggingInfoStream.message [DW][qtp28033213-19]: publishFlushedSegment seg-private updates=null
[junit4] 2> 13314 T19 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-19]: publishFlushedSegment
[junit4] 2> 13314 T19 C3 oasu.LoggingInfoStream.message [BD][qtp28033213-19]: push deletes 1 deleted terms (unique count=1) bytesUsed=1024 delGen=14 packetCount=1 totBytesUsed=1024
[junit4] 2> 13315 T19 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-19]: publish sets newSegment delGen=15 seg=_3(5.0):C1
[junit4] 2> 13315 T19 C3 oasu.LoggingInfoStream.message [IFD][qtp28033213-19]: now checkpoint "_0(5.0):C1 _1(5.0):C1 _2(5.0):C1 _3(5.0):C1" [4 segments ; isCommit = false]
[junit4] 2> 13316 T19 C3 oasu.LoggingInfoStream.message [IFD][qtp28033213-19]: 0 msec to checkpoint
[junit4] 2> 13316 T19 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-19]: apply all deletes during flush
[junit4] 2> 13317 T19 C3 oasu.LoggingInfoStream.message [BD][qtp28033213-19]: applyDeletes: infos=[_0(5.0):C1, _1(5.0):C1, _2(5.0):C1, _3(5.0):C1] packetCount=1
[junit4] 2> 13319 T19 C3 oasu.LoggingInfoStream.message [BD][qtp28033213-19]: seg=_2(5.0):C1 segGen=12 coalesced deletes=[CoalescedUpdates(termSets=1,queries=0,numericUpdates=0)] newDelCount=1 100% deleted
[junit4] 2> 13320 T19 C3 oasu.LoggingInfoStream.message [BD][qtp28033213-19]: seg=_1(5.0):C1 segGen=12 coalesced deletes=[CoalescedUpdates(termSets=1,queries=0,numericUpdates=0)] newDelCount=0
[junit4] 2> 13320 T19 C3 oasu.LoggingInfoStream.message [BD][qtp28033213-19]: seg=_0(5.0):C1 segGen=12 coalesced deletes=[CoalescedUpdates(termSets=1,queries=0,numericUpdates=0)] newDelCount=0
[junit4] 2> 13321 T19 C3 oasu.LoggingInfoStream.message [BD][qtp28033213-19]: applyDeletes took 4 msec
[junit4] 2> 13321 T19 C3 oasu.LoggingInfoStream.message [IFD][qtp28033213-19]: now checkpoint "_0(5.0):C1 _1(5.0):C1 _2(5.0):C1/1 _3(5.0):C1" [4 segments ; isCommit = false]
[junit4] 2> 13322 T19 C3 oasu.LoggingInfoStream.message [IFD][qtp28033213-19]: 0 msec to checkpoint
[junit4] 2> 13322 T19 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-19]: drop 100% deleted segments: _2(5.0):C1/1
[junit4] 2> 13323 T19 C3 oasu.LoggingInfoStream.message [IFD][qtp28033213-19]: now checkpoint "_0(5.0):C1 _1(5.0):C1 _3(5.0):C1" [3 segments ; isCommit = false]
[junit4] 2> 13323 T19 C3 oasu.LoggingInfoStream.message [IFD][qtp28033213-19]: 0 msec to checkpoint
[junit4] 2> 13324 T19 C3 oasu.LoggingInfoStream.message [BD][qtp28033213-19]: prune sis=org.apache.lucene.index.SegmentInfos@83ca2e minGen=16 packetCount=1
[junit4] 2> 13324 T19 C3 oasu.LoggingInfoStream.message [BD][qtp28033213-19]: pruneDeletes: prune 1 packets; 0 packets remain
[junit4] 2> 13325 T19 C3 oasu.LoggingInfoStream.message [DW][qtp28033213-19]: qtp28033213-19 finishFullFlush success=true
[junit4] 2> 13325 T19 C3 oasu.LoggingInfoStream.message [TMP][qtp28033213-19]: findMerges: 3 segments
[junit4] 2> 13326 T19 C3 oasu.LoggingInfoStream.message [TMP][qtp28033213-19]: seg=_0(5.0):C1 size=0.001 MB [floored]
[junit4] 2> 13327 T19 C3 oasu.LoggingInfoStream.message [TMP][qtp28033213-19]: seg=_1(5.0):C1 size=0.001 MB [floored]
[junit4] 2> 13327 T19 C3 oasu.LoggingInfoStream.message [TMP][qtp28033213-19]: seg=_3(5.0):C1 size=0.001 MB [floored]
[junit4] 2> 13328 T19 C3 oasu.LoggingInfoStream.message [TMP][qtp28033213-19]: allowedSegmentCount=1 vs count=3 (eligible count=3) tooBigCount=0
[junit4] 2> 13328 T19 C3 oasu.LoggingInfoStream.message [CMS][qtp28033213-19]: now merge
[junit4] 2> 13329 T19 C3 oasu.LoggingInfoStream.message [CMS][qtp28033213-19]: index: _0(5.0):C1 _1(5.0):C1 _3(5.0):C1
[junit4] 2> 13329 T19 C3 oasu.LoggingInfoStream.message [CMS][qtp28033213-19]: no more merges pending; now return
[junit4] 2> 13329 T19 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-19]: startCommit(): start
[junit4] 2> 13330 T19 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-19]: startCommit index=_0(5.0):C1 _1(5.0):C1 _3(5.0):C1 changeCount=12
[junit4] 2> 13331 T19 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-19]: done all syncs: [_0_Lucene41_0.tim, _0.si, _1.nvd, _0.fdt, _1_Lucene41_0.doc, _0_Lucene41_0.pos, _3.fdt, _1_Lucene41_0.pos, _1.fdx, _3.fdx, _1.fnm, _0.fnm, _3.si, _0_Lucene41_0.tip, _0.nvm, _1_Lucene41_0.tim, _3_Lucene41_0.tim, _3.fnm, _0_Lucene41_0.doc, _1.fdt, _3_Lucene41_0.doc, _1.nvm, _3_Lucene41_0.tip, _0.nvd, _0.fdx, _1_Lucene41_0.tip, _1.si]
[junit4] 2> 13331 T19 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-19]: commit: pendingCommit != null
[junit4] 2> 13332 T19 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-19]: commit: wrote segments file "segments_3"
[junit4] 2> 13332 T19 C3 oasu.LoggingInfoStream.message [IFD][qtp28033213-19]: now checkpoint "_0(5.0):C1 _1(5.0):C1 _3(5.0):C1" [3 segments ; isCommit = true]
[junit4] 2> 13333 T19 C3 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@16c84bd lockFactory=NativeFSLockFactory@/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-solrj/test/J1/solrtest-SolrExampleJettyTest-1392822543979/index),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@16c84bd lockFactory=NativeFSLockFactory@/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-solrj/test/J1/solrtest-SolrExampleJettyTest-1392822543979/index),segFN=segments_3,generation=3}
[junit4] 2> 13333 T19 C3 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4] 2> 13334 T19 C3 oasu.LoggingInfoStream.message [IFD][qtp28033213-19]: deleteCommits: now decRef commit "segments_2"
[junit4] 2> 13334 T19 C3 oasu.LoggingInfoStream.message [IFD][qtp28033213-19]: delete "segments_2"
[junit4] 2> 13335 T19 C3 oasu.LoggingInfoStream.message [IFD][qtp28033213-19]: 2 msec to checkpoint
[junit4] 2> 13335 T19 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-19]: commit: done
[junit4] 2> 13335 T19 C3 oasu.LoggingInfoStream.message [DW][qtp28033213-19]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 13336 T19 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-19]: nrtIsCurrent: infoVersion matches: false; DW changes: false; BD changes: false
[junit4] 2> 13336 T19 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-19]: flush at getReader
[junit4] 2> 13337 T19 C3 oasu.LoggingInfoStream.message [DW][qtp28033213-19]: qtp28033213-19 startFullFlush
[junit4] 2> 13337 T19 C3 oasu.LoggingInfoStream.message [DW][qtp28033213-19]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 13338 T19 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-19]: apply all deletes during flush
[junit4] 2> 13338 T19 C3 oasu.LoggingInfoStream.message [BD][qtp28033213-19]: applyDeletes: no deletes; skipping
[junit4] 2> 13338 T19 C3 oasu.LoggingInfoStream.message [BD][qtp28033213-19]: prune sis=org.apache.lucene.index.SegmentInfos@83ca2e minGen=16 packetCount=0
[junit4] 2> 13340 T19 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-19]: return reader version=11 reader=StandardDirectoryReader(segments_3:11:nrt _0(5.0):C1 _1(5.0):C1 _3(5.0):C1)
[junit4] 2> 13340 T19 C3 oasu.LoggingInfoStream.message [DW][qtp28033213-19]: qtp28033213-19 finishFullFlush success=true
[junit4] 2> 13341 T19 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-19]: getReader took 5 msec
[junit4] 2> 13341 T19 C3 oass.SolrIndexSearcher.<init> Opening Searcher@1a81a86[collection1] main
[junit4] 2> 13343 T19 C3 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 13343 T23 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@1a81a86[collection1] main{StandardDirectoryReader(segments_3:11:nrt _0(5.0):C1 _1(5.0):C1 _3(5.0):C1)}
[junit4] 2> 13344 T23 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 13344 T23 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1a81a86[collection1] main{StandardDirectoryReader(segments_3:11:nrt _0(5.0):C1 _1(5.0):C1 _3(5.0):C1)}
[junit4] 2> 13345 T23 oasu.LoggingInfoStream.message [IFD][searcherExecutor-5-thread-1]: delete "_2.fdt"
[junit4] 2> 13345 T23 oasu.LoggingInfoStream.message [IFD][searcherExecutor-5-thread-1]: delete "_2_Lucene41_0.tip"
[junit4] 2> 13345 T23 oasu.LoggingInfoStream.message [IFD][searcherExecutor-5-thread-1]: delete "_2.si"
[junit4] 2> 13346 T23 oasu.LoggingInfoStream.message [IFD][searcherExecutor-5-thread-1]: delete "_2_Lucene41_0.doc"
[junit4] 2> 13346 T23 oasu.LoggingInfoStream.message [IFD][searcherExecutor-5-thread-1]: delete "_2.fdx"
[junit4] 2> 13346 T23 oasu.LoggingInfoStream.message [IFD][searcherExecutor-5-thread-1]: delete "_2.fnm"
[junit4] 2> 13347 T23 oasu.LoggingInfoStream.message [IFD][searcherExecutor-5-thread-1]: delete "_2_Lucene41_0.tim"
[junit4] 2> 13347 T19 C3 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&softCommit=false&commit=true&waitSearcher=true&wt=javabin} {commit=} 0 43
[junit4] 2> 13352 T20 C3 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={version=2&q=id:123&wt=javabin} hits=1 status=0 QTime=0
[junit4] 2> 13360 T18 C3 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[123 (1460480304893394944)]} 0 2
[junit4] 2> 13366 T21 C3 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 13366 T21 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-21]: commit: start
[junit4] 2> 13367 T21 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-21]: commit: enter lock
[junit4] 2> 13367 T21 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-21]: commit: now prepare
[junit4] 2> 13367 T21 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-21]: prepareCommit: flush
[junit4] 2> 13368 T21 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-21]: index before flush _0(5.0):C1 _1(5.0):C1 _3(5.0):C1
[junit4] 2> 13369 T21 C3 oasu.LoggingInfoStream.message [DW][qtp28033213-21]: qtp28033213-21 startFullFlush
[junit4] 2> 13369 T21 C3 oasu.LoggingInfoStream.message [DW][qtp28033213-21]: anyChanges? numDocsInRam=1 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 13369 T21 C3 oasu.LoggingInfoStream.message [DWFC][qtp28033213-21]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=_4, aborting=false, numDocsInRAM=1, deleteQueue=DWDQ: [ generation: 8 ]]
[junit4] 2> 13370 T21 C3 oasu.LoggingInfoStream.message [DWPT][qtp28033213-21]: flush postings as segment _4 numDocs=1
[junit4] 2> 13373 T21 C3 oasu.LoggingInfoStream.message [DWPT][qtp28033213-21]: new segment has 0 deleted docs
[junit4] 2> 13374 T21 C3 oasu.LoggingInfoStream.message [DWPT][qtp28033213-21]: new segment has no vectors; no norms; no docValues; no prox; no freqs
[junit4] 2> 13374 T21 C3 oasu.LoggingInfoStream.message [DWPT][qtp28033213-21]: flushedFiles=[_4.fdx, _4_Lucene41_0.doc, _4_Lucene41_0.tip, _4_Lucene41_0.tim, _4.fdt, _4.fnm]
[junit4] 2> 13375 T21 C3 oasu.LoggingInfoStream.message [DWPT][qtp28033213-21]: flushed codec=Lucene46
[junit4] 2> 13376 T21 C3 oasu.LoggingInfoStream.message [DWPT][qtp28033213-21]: flushed: segment=_4 ramUsed=0.063 MB newFlushedSize(includes docstores)=0.001 MB docs/MB=1,291.35
[junit4] 2> 13377 T21 C3 oasu.LoggingInfoStream.message [DW][qtp28033213-21]: publishFlushedSegment seg-private updates=null
[junit4] 2> 13377 T21 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-21]: publishFlushedSegment
[junit4] 2> 13377 T21 C3 oasu.LoggingInfoStream.message [BD][qtp28033213-21]: push deletes 1 deleted terms (unique count=1) bytesUsed=1024 delGen=18 packetCount=1 totBytesUsed=1024
[junit4] 2> 13378 T21 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-21]: publish sets newSegment delGen=19 seg=_4(5.0):C1
[junit4] 2> 13378 T21 C3 oasu.LoggingInfoStream.message [IFD][qtp28033213-21]: now checkpoint "_0(5.0):C1 _1(5.0):C1 _3(5.0):C1 _4(5.0):C1" [4 segments ; isCommit = false]
[junit4] 2> 13379 T21 C3 oasu.LoggingInfoStream.message [IFD][qtp28033213-21]: 0 msec to checkpoint
[junit4] 2> 13379 T21 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-21]: apply all deletes during flush
[junit4] 2> 13380 T21 C3 oasu.LoggingInfoStream.message [BD][qtp28033213-21]: applyDeletes: infos=[_0(5.0):C1, _1(5.0):C1, _3(5.0):C1, _4(5.0):C1] packetCount=1
[junit4] 2> 13380 T21 C3 oasu.LoggingInfoStream.message [BD][qtp28033213-21]: seg=_3(5.0):C1 segGen=16 coalesced deletes=[CoalescedUpdates(termSets=1,queries=0,numericUpdates=0)] newDelCount=1 100% deleted
[junit4] 2> 13381 T21 C3 oasu.LoggingInfoStream.message [BD][qtp28033213-21]: seg=_1(5.0):C1 segGen=16 coalesced deletes=[CoalescedUpdates(termSets=1,queries=0,numericUpdates=0)] newDelCount=0
[junit4] 2> 13382 T21 C3 oasu.LoggingInfoStream.message [BD][qtp28033213-21]: seg=_0(5.0):C1 segGen=16 coalesced deletes=[CoalescedUpdates(termSets=1,queries=0,numericUpdates=0)] newDelCount=0
[junit4] 2> 13382 T21 C3 oasu.LoggingInfoStream.message [BD][qtp28033213-21]: applyDeletes took 2 msec
[junit4] 2> 13383 T21 C3 oasu.LoggingInfoStream.message [IFD][qtp28033213-21]: now checkpoint "_0(5.0):C1 _1(5.0):C1 _3(5.0):C1/1 _4(5.0):C1" [4 segments ; isCommit = false]
[junit4] 2> 13384 T21 C3 oasu.LoggingInfoStream.message [IFD][qtp28033213-21]: 0 msec to checkpoint
[junit4] 2> 13384 T21 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-21]: drop 100% deleted segments: _3(5.0):C1/1
[junit4] 2> 13385 T21 C3 oasu.LoggingInfoStream.message [IFD][qtp28033213-21]: now checkpoint "_0(5.0):C1 _1(5.0):C1 _4(5.0):C1" [3 segments ; isCommit = false]
[junit4] 2> 13386 T21 C3 oasu.LoggingInfoStream.message [IFD][qtp28033213-21]: 0 msec to checkpoint
[junit4] 2> 13386 T21 C3 oasu.LoggingInfoStream.message [BD][qtp28033213-21]: prune sis=org.apache.lucene.index.SegmentInfos@83ca2e minGen=20 packetCount=1
[junit4] 2> 13387 T21 C3 oasu.LoggingInfoStream.message [BD][qtp28033213-21]: pruneDeletes: prune 1 packets; 0 packets remain
[junit4] 2> 13388 T21 C3 oasu.LoggingInfoStream.message [DW][qtp28033213-21]: qtp28033213-21 finishFullFlush success=true
[junit4] 2> 13388 T21 C3 oasu.LoggingInfoStream.message [TMP][qtp28033213-21]: findMerges: 3 segments
[junit4] 2> 13389 T21 C3 oasu.LoggingInfoStream.message [TMP][qtp28033213-21]: seg=_0(5.0):C1 size=0.001 MB [floored]
[junit4] 2> 13390 T21 C3 oasu.LoggingInfoStream.message [TMP][qtp28033213-21]: seg=_1(5.0):C1 size=0.001 MB [floored]
[junit4] 2> 13390 T21 C3 oasu.LoggingInfoStream.message [TMP][qtp28033213-21]: seg=_4(5.0):C1 size=0.001 MB [floored]
[junit4] 2> 13391 T21 C3 oasu.LoggingInfoStream.message [TMP][qtp28033213-21]: allowedSegmentCount=1 vs count=3 (eligible count=3) tooBigCount=0
[junit4] 2> 13392 T21 C3 oasu.LoggingInfoStream.message [CMS][qtp28033213-21]: now merge
[junit4] 2> 13392 T21 C3 oasu.LoggingInfoStream.message [CMS][qtp28033213-21]: index: _0(5.0):C1 _1(5.0):C1 _4(5.0):C1
[junit4] 2> 13393 T21 C3 oasu.LoggingInfoStream.message [CMS][qtp28033213-21]: no more merges pending; now return
[junit4] 2> 13393 T21 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-21]: startCommit(): start
[junit4] 2> 13394 T21 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-21]: startCommit index=_0(5.0):C1 _1(5.0):C1 _4(5.0):C1 changeCount=17
[junit4] 2> 13395 T21 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-21]: done all syncs: [_0_Lucene41_0.tim, _1.nvd, _0.si, _0.fdt, _0.fnm, _4_Lucene41_0.doc, _4_Lucene41_0.tip, _1.nvm, _1.si, _4.fdx, _1_Lucene41_0.doc, _0_Lucene41_0.pos, _1_Lucene41_0.pos, _4.si, _1.fdx, _1.fnm, _0_Lucene41_0.tip, _1_Lucene41_0.tim, _0.nvm, _0_Lucene41_0.doc, _1.fdt, _4_Lucene41_0.tim, _4.fdt, _4.fnm, _0.fdx, _0.nvd, _1_Lucene41_0.tip]
[junit4] 2> 13396 T21 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-21]: commit: pendingCommit != null
[junit4] 2> 13396 T21 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-21]: commit: wrote segments file "segments_4"
[junit4] 2> 13397 T21 C3 oasu.LoggingInfoStream.message [IFD][qtp28033213-21]: now checkpoint "_0(5.0):C1 _1(5.0):C1 _4(5.0):C1" [3 segments ; isCommit = true]
[junit4] 2> 13397 T21 C3 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@16c84bd lockFactory=NativeFSLockFactory@/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-solrj/test/J1/solrtest-SolrExampleJettyTest-1392822543979/index),segFN=segments_3,generation=3}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@16c84bd lockFactory=NativeFSLockFactory@/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-solrj/test/J1/solrtest-SolrExampleJettyTest-1392822543979/index),segFN=segments_4,generation=4}
[junit4] 2> 13398 T21 C3 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 4
[junit4] 2> 13398 T21 C3 oasu.LoggingInfoStream.message [IFD][qtp28033213-21]: deleteCommits: now decRef commit "segments_3"
[junit4] 2> 13398 T21 C3 oasu.LoggingInfoStream.message [IFD][qtp28033213-21]: delete "segments_3"
[junit4] 2> 13399 T21 C3 oasu.LoggingInfoStream.message [IFD][qtp28033213-21]: 2 msec to checkpoint
[junit4] 2> 13399 T21 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-21]: commit: done
[junit4] 2> 13400 T21 C3 oasu.LoggingInfoStream.message [DW][qtp28033213-21]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 13400 T21 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-21]: nrtIsCurrent: infoVersion matches: false; DW changes: false; BD changes: false
[junit4] 2> 13400 T21 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-21]: flush at getReader
[junit4] 2> 13401 T21 C3 oasu.LoggingInfoStream.message [DW][qtp28033213-21]: qtp28033213-21 startFullFlush
[junit4] 2> 13401 T21 C3 oasu.LoggingInfoStream.message [DW][qtp28033213-21]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 13402 T21 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-21]: apply all deletes during flush
[junit4] 2> 13402 T21 C3 oasu.LoggingInfoStream.message [BD][qtp28033213-21]: applyDeletes: no deletes; skipping
[junit4] 2> 13402 T21 C3 oasu.LoggingInfoStream.message [BD][qtp28033213-21]: prune sis=org.apache.lucene.index.SegmentInfos@83ca2e minGen=20 packetCount=0
[junit4] 2> 13404 T21 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-21]: return reader version=15 reader=StandardDirectoryReader(segments_4:15:nrt _0(5.0):C1 _1(5.0):C1 _4(5.0):C1)
[junit4] 2> 13404 T21 C3 oasu.LoggingInfoStream.message [DW][qtp28033213-21]: qtp28033213-21 finishFullFlush success=true
[junit4] 2> 13405 T21 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-21]: getReader took 5 msec
[junit4] 2> 13405 T21 C3 oass.SolrIndexSearcher.<init> Opening Searcher@172f5d6[collection1] main
[junit4] 2> 13406 T23 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@172f5d6[collection1] main{StandardDirectoryReader(segments_4:15:nrt _0(5.0):C1 _1(5.0):C1 _4(5.0):C1)}
[junit4] 2> 13406 T21 C3 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 13406 T23 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 13407 T23 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@172f5d6[collection1] main{StandardDirectoryReader(segments_4:15:nrt _0(5.0):C1 _1(5.0):C1 _4(5.0):C1)}
[junit4] 2> 13408 T23 oasu.LoggingInfoStream.message [IFD][searcherExecutor-5-thread-1]: delete "_3.fdt"
[junit4] 2> 13408 T23 oasu.LoggingInfoStream.message [IFD][searcherExecutor-5-thread-1]: delete "_3.fdx"
[junit4] 2> 13408 T23 oasu.LoggingInfoStream.message [IFD][searcherExecutor-5-thread-1]: delete "_3.si"
[junit4] 2> 13409 T23 oasu.LoggingInfoStream.message [IFD][searcherExecutor-5-thread-1]: delete "_3_Lucene41_0.tim"
[junit4] 2> 13409 T23 oasu.LoggingInfoStream.message [IFD][searcherExecutor-5-thread-1]: delete "_3.fnm"
[junit4] 2> 13409 T23 oasu.LoggingInfoStream.message [IFD][searcherExecutor-5-thread-1]: delete "_3_Lucene41_0.doc"
[junit4] 2> 13410 T23 oasu.LoggingInfoStream.message [IFD][searcherExecutor-5-thread-1]: delete "_3_Lucene41_0.tip"
[junit4] 2> 13410 T21 C3 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&softCommit=false&commit=true&waitSearcher=true&wt=javabin} {commit=} 0 44
[junit4] 2> 13417 T20 C3 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={version=2&q=id:123&wt=javabin} hits=1 status=0 QTime=1
[junit4] 2> 13420 T10 oas.SolrTestCaseJ4.tearDown ###Ending testUpdateMultiValuedField
[junit4] 2> 13435 T10 oas.SolrTestCaseJ4.setUp ###Starting testGetEmptyResults
[junit4] 2> 13439 T18 C3 oasu.LoggingInfoStream.message [DW][qtp28033213-18]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 13440 T18 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-18]: nrtIsCurrent: infoVersion matches: true; DW changes: true; BD changes: false
[junit4] 2> 13440 T18 C3 oasu.LoggingInfoStream.message [DW][qtp28033213-18]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 13441 T18 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-18]: flush at getReader
[junit4] 2> 13441 T18 C3 oasu.LoggingInfoStream.message [DW][qtp28033213-18]: qtp28033213-18 startFullFlush
[junit4] 2> 13442 T18 C3 oasu.LoggingInfoStream.message [DW][qtp28033213-18]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 13442 T18 C3 oasu.LoggingInfoStream.message [DW][qtp28033213-18]: qtp28033213-18: flush naked frozen global deletes
[junit4] 2> 13442 T18 C3 oasu.LoggingInfoStream.message [BD][qtp28033213-18]: push deletes 1 deleted queries bytesUsed=32 delGen=22 packetCount=1 totBytesUsed=32
[junit4] 2> 13443 T18 C3 oasu.LoggingInfoStream.message [DW][qtp28033213-18]: flush: push buffered updates: 1 deleted queries bytesUsed=32
[junit4] 2> 13443 T18 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-18]: apply all deletes during flush
[junit4] 2> 13444 T18 C3 oasu.LoggingInfoStream.message [BD][qtp28033213-18]: applyDeletes: infos=[_0(5.0):C1, _1(5.0):C1, _4(5.0):C1] packetCount=1
[junit4] 2> 13482 T18 C3 oasu.LoggingInfoStream.message [BD][qtp28033213-18]: seg=_4(5.0):C1 segGen=20 coalesced deletes=[CoalescedUpdates(termSets=1,queries=1,numericUpdates=0)] newDelCount=1 100% deleted
[junit4] 2> 13483 T18 C3 oasu.LoggingInfoStream.message [BD][qtp28033213-18]: seg=_1(5.0):C1 segGen=20 coalesced deletes=[CoalescedUpdates(termSets=1,queries=1,numericUpdates=0)] newDelCount=1 100% deleted
[junit4] 2> 13483 T18 C3 oasu.LoggingInfoStream.message [BD][qtp28033213-18]: seg=_0(5.0):C1 segGen=20 coalesced deletes=[CoalescedUpdates(termSets=1,queries=1,numericUpdates=0)] newDelCount=1 100% deleted
[junit4] 2> 13484 T18 C3 oasu.LoggingInfoStream.message [BD][qtp28033213-18]: applyDeletes took 40 msec
[junit4] 2> 13484 T18 C3 oasu.LoggingInfoStream.message [IFD][qtp28033213-18]: now checkpoint "_0(5.0):C1/1 _1(5.0):C1/1 _4(5.0):C1/1" [3 segments ; isCommit = false]
[junit4] 2> 13485 T18 C3 oasu.LoggingInfoStream.message [IFD][qtp28033213-18]: 0 msec to checkpoint
[junit4] 2> 13485 T18 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-18]: drop 100% deleted segments: _4(5.0):C1/1 _1(5.0):C1/1 _0(5.0):C1/1
[junit4] 2> 13486 T18 C3 oasu.LoggingInfoStream.message [IFD][qtp28033213-18]: now checkpoint "" [0 segments ; isCommit = false]
[junit4] 2> 13486 T18 C3 oasu.LoggingInfoStream.message [IFD][qtp28033213-18]: 0 msec to checkpoint
[junit4] 2> 13486 T18 C3 oasu.LoggingInfoStream.message [BD][qtp28033213-18]: prune sis=org.apache.lucene.index.SegmentInfos@83ca2e minGen=9223372036854775807 packetCount=1
[junit4] 2> 13487 T18 C3 oasu.LoggingInfoStream.message [BD][qtp28033213-18]: pruneDeletes: prune 1 packets; 0 packets remain
[junit4] 2> 13487 T18 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-18]: return reader version=17 reader=StandardDirectoryReader(segments_4:17:nrt)
[junit4] 2> 13488 T18 C3 oasu.LoggingInfoStream.message [DW][qtp28033213-18]: qtp28033213-18 finishFullFlush success=true
[junit4] 2> 13488 T18 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-18]: getReader took 47 msec
[junit4] 2> 13489 T18 C3 oass.SolrIndexSearcher.<init> Opening Searcher@148f4ac[collection1] realtime
[junit4] 2> 13490 T18 C3 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {deleteByQuery=*:* (-1460480304977281024)} 0 52
[junit4] 2> 13494 T21 C3 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 13495 T21 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-21]: commit: start
[junit4] 2> 13496 T21 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-21]: commit: enter lock
[junit4] 2> 13496 T21 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-21]: commit: now prepare
[junit4] 2> 13497 T21 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-21]: prepareCommit: flush
[junit4] 2> 13497 T21 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-21]: index before flush
[junit4] 2> 13498 T21 C3 oasu.LoggingInfoStream.message [DW][qtp28033213-21]: qtp28033213-21 startFullFlush
[junit4] 2> 13498 T21 C3 oasu.LoggingInfoStream.message [DW][qtp28033213-21]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 13499 T21 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-21]: apply all deletes during flush
[junit4] 2> 13499 T21 C3 oasu.LoggingInfoStream.message [BD][qtp28033213-21]: prune sis=org.apache.lucene.index.SegmentInfos@83ca2e minGen=9223372036854775807 packetCount=0
[junit4] 2> 13500 T21 C3 oasu.LoggingInfoStream.message [DW][qtp28033213-21]: qtp28033213-21 finishFullFlush success=true
[junit4] 2> 13501 T21 C3 oasu.LoggingInfoStream.message [IW][qtp28033213-21]: startCommit(): start
[junit4]
[...truncated too long message...]
fq={!field+f%3DinStock}true&fq={!term+f%3Dname}hoss&q=foo&facet=true&facet.query=price:[*+TO+2]&facet.query=price:[2+TO+4]&wt=javabin} hits=0 status=0 QTime=4
[junit4] 2> 220246 T19 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/info/system params={version=2&qt=/admin/info/system&wt=javabin} status=0 QTime=8
[junit4] 2> 220249 T10 oas.SolrTestCaseJ4.tearDown ###Ending testExampleConfig
[junit4] 2> 220272 T10 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=18438958
[junit4] 2> 220273 T10 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@19bd80e
[junit4] 2> 220274 T10 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=66,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=262,cumulative_deletesById=5,cumulative_deletesByQuery=33,cumulative_errors=1,transaction_logs_total_size=1744,transaction_logs_total_number=10}
[junit4] 2> 220274 T10 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 220274 T10 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 220275 T10 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 220275 T10 C14 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[D76ED9335A6D5E62]-worker]: now flush at close waitForMerges=true
[junit4] 2> 220275 T10 C14 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[D76ED9335A6D5E62]-worker]: start flush: applyAllDeletes=true
[junit4] 2> 220276 T10 C14 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[D76ED9335A6D5E62]-worker]: index before flush _1a(5.0):C5
[junit4] 2> 220276 T10 C14 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleJettyTest-seed#[D76ED9335A6D5E62]-worker]: SUITE-SolrExampleJettyTest-seed#[D76ED9335A6D5E62]-worker startFullFlush
[junit4] 2> 220276 T10 C14 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleJettyTest-seed#[D76ED9335A6D5E62]-worker]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 220277 T10 C14 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleJettyTest-seed#[D76ED9335A6D5E62]-worker]: SUITE-SolrExampleJettyTest-seed#[D76ED9335A6D5E62]-worker finishFullFlush success=true
[junit4] 2> 220277 T10 C14 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[D76ED9335A6D5E62]-worker]: apply all deletes during flush
[junit4] 2> 220277 T10 C14 oasu.LoggingInfoStream.message [BD][SUITE-SolrExampleJettyTest-seed#[D76ED9335A6D5E62]-worker]: applyDeletes: no deletes; skipping
[junit4] 2> 220277 T10 C14 oasu.LoggingInfoStream.message [BD][SUITE-SolrExampleJettyTest-seed#[D76ED9335A6D5E62]-worker]: prune sis=org.apache.lucene.index.SegmentInfos@83ca2e minGen=267 packetCount=0
[junit4] 2> 220278 T10 C14 oasu.LoggingInfoStream.message [CMS][SUITE-SolrExampleJettyTest-seed#[D76ED9335A6D5E62]-worker]: now merge
[junit4] 2> 220278 T10 C14 oasu.LoggingInfoStream.message [CMS][SUITE-SolrExampleJettyTest-seed#[D76ED9335A6D5E62]-worker]: index: _1a(5.0):C5
[junit4] 2> 220278 T10 C14 oasu.LoggingInfoStream.message [CMS][SUITE-SolrExampleJettyTest-seed#[D76ED9335A6D5E62]-worker]: no more merges pending; now return
[junit4] 2> 220279 T10 C14 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[D76ED9335A6D5E62]-worker]: waitForMerges
[junit4] 2> 220279 T10 C14 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[D76ED9335A6D5E62]-worker]: waitForMerges done
[junit4] 2> 220279 T10 C14 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[D76ED9335A6D5E62]-worker]: now call final commit()
[junit4] 2> 220279 T10 C14 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[D76ED9335A6D5E62]-worker]: commit: start
[junit4] 2> 220280 T10 C14 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[D76ED9335A6D5E62]-worker]: commit: enter lock
[junit4] 2> 220280 T10 C14 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[D76ED9335A6D5E62]-worker]: commit: now prepare
[junit4] 2> 220280 T10 C14 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[D76ED9335A6D5E62]-worker]: prepareCommit: flush
[junit4] 2> 220280 T10 C14 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[D76ED9335A6D5E62]-worker]: index before flush _1a(5.0):C5
[junit4] 2> 220281 T10 C14 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleJettyTest-seed#[D76ED9335A6D5E62]-worker]: SUITE-SolrExampleJettyTest-seed#[D76ED9335A6D5E62]-worker startFullFlush
[junit4] 2> 220281 T10 C14 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleJettyTest-seed#[D76ED9335A6D5E62]-worker]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 220281 T10 C14 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[D76ED9335A6D5E62]-worker]: apply all deletes during flush
[junit4] 2> 220282 T10 C14 oasu.LoggingInfoStream.message [BD][SUITE-SolrExampleJettyTest-seed#[D76ED9335A6D5E62]-worker]: applyDeletes: no deletes; skipping
[junit4] 2> 220282 T10 C14 oasu.LoggingInfoStream.message [BD][SUITE-SolrExampleJettyTest-seed#[D76ED9335A6D5E62]-worker]: prune sis=org.apache.lucene.index.SegmentInfos@83ca2e minGen=267 packetCount=0
[junit4] 2> 220282 T10 C14 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleJettyTest-seed#[D76ED9335A6D5E62]-worker]: SUITE-SolrExampleJettyTest-seed#[D76ED9335A6D5E62]-worker finishFullFlush success=true
[junit4] 2> 220282 T10 C14 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[D76ED9335A6D5E62]-worker]: startCommit(): start
[junit4] 2> 220283 T10 C14 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[D76ED9335A6D5E62]-worker]: skip startCommit(): no changes pending
[junit4] 2> 220283 T10 C14 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[D76ED9335A6D5E62]-worker]: commit: pendingCommit == null; skip
[junit4] 2> 220283 T10 C14 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[D76ED9335A6D5E62]-worker]: commit: done
[junit4] 2> 220284 T10 C14 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[D76ED9335A6D5E62]-worker]: at close: _1a(5.0):C5
[junit4] 2> 220284 T10 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 220285 T10 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 220285 T10 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-solrj/test/J1/solrtest-SolrExampleJettyTest-1392822543979 [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-solrj/test/J1/solrtest-SolrExampleJettyTest-1392822543979;done=false>>]
[junit4] 2> 220286 T10 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-solrj/test/J1/solrtest-SolrExampleJettyTest-1392822543979
[junit4] 2> 220286 T10 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-solrj/test/J1/solrtest-SolrExampleJettyTest-1392822543979/index [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-solrj/test/J1/solrtest-SolrExampleJettyTest-1392822543979/index;done=false>>]
[junit4] 2> 220286 T10 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-solrj/test/J1/solrtest-SolrExampleJettyTest-1392822543979/index
[junit4] 2> 220287 T10 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4] 2> 220341 T10 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: test params are: codec=Lucene40, sim=DefaultSimilarity, locale=it_IT, timezone=America/Kentucky/Louisville
[junit4] 2> NOTE: Linux 3.8.0-35-generic i386/Oracle Corporation 1.7.0_60-ea (32-bit)/cpus=8,threads=1,free=46155360,total=65011712
[junit4] 2> NOTE: All tests run in this JVM: [SolrExampleJettyTest]
[junit4] Completed on J1 in 220.56s, 27 tests, 1 error <<< FAILURES!
[...truncated 43 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:453: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:433: 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/extra-targets.xml:37: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:202: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:491: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1268: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:901: There were test failures: 48 suites, 280 tests, 1 error
Total time: 57 minutes 57 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/jdk1.7.0_60-ea-b04 -server -XX:+UseSerialGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure
[JENKINS] Lucene-Solr-trunk-Linux (32bit/jdk1.8.0-fcs-b129) - Build
# 9529 - Still Failing!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/9529/
Java: 32bit/jdk1.8.0-fcs-b129 -server -XX:+UseConcMarkSweepGC
All tests passed
Build Log:
[...truncated 49815 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:453: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:392: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/extra-targets.xml:87: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/extra-targets.xml:185: The following files are missing svn:eol-style (or binary svn:mime-type):
* ./solr/licenses/Saxon-HE-9.5.1-4.jar.sha1
* ./solr/licenses/argparse4j-0.4.3.jar.sha1
* ./solr/licenses/jackson-annotations-2.3.1.jar.sha1
* ./solr/licenses/jackson-core-2.3.1.jar.sha1
* ./solr/licenses/jackson-databind-2.3.1.jar.sha1
* ./solr/licenses/kite-morphlines-avro-0.11.0.jar.sha1
* ./solr/licenses/kite-morphlines-core-0.11.0-tests.jar.sha1
* ./solr/licenses/kite-morphlines-core-0.11.0.jar.sha1
* ./solr/licenses/kite-morphlines-hadoop-sequencefile-0.11.0.jar.sha1
* ./solr/licenses/kite-morphlines-json-0.11.0.jar.sha1
* ./solr/licenses/kite-morphlines-saxon-0.11.0.jar.sha1
* ./solr/licenses/kite-morphlines-tika-core-0.11.0.jar.sha1
* ./solr/licenses/kite-morphlines-tika-decompress-0.11.0.jar.sha1
* ./solr/licenses/kite-morphlines-twitter-0.11.0.jar.sha1
Total time: 55 minutes 51 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/jdk1.8.0-fcs-b129 -server -XX:+UseConcMarkSweepGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure
[JENKINS] Lucene-Solr-trunk-Linux (32bit/jdk1.7.0_60-ea-b04) -
Build # 9528 - Still Failing!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/9528/
Java: 32bit/jdk1.7.0_60-ea-b04 -server -XX:+UseG1GC
All tests passed
Build Log:
[...truncated 50454 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:453: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:392: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/extra-targets.xml:87: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/extra-targets.xml:185: The following files are missing svn:eol-style (or binary svn:mime-type):
* ./solr/licenses/Saxon-HE-9.5.1-4.jar.sha1
* ./solr/licenses/argparse4j-0.4.3.jar.sha1
* ./solr/licenses/jackson-annotations-2.3.1.jar.sha1
* ./solr/licenses/jackson-core-2.3.1.jar.sha1
* ./solr/licenses/jackson-databind-2.3.1.jar.sha1
* ./solr/licenses/kite-morphlines-avro-0.11.0.jar.sha1
* ./solr/licenses/kite-morphlines-core-0.11.0-tests.jar.sha1
* ./solr/licenses/kite-morphlines-core-0.11.0.jar.sha1
* ./solr/licenses/kite-morphlines-hadoop-sequencefile-0.11.0.jar.sha1
* ./solr/licenses/kite-morphlines-json-0.11.0.jar.sha1
* ./solr/licenses/kite-morphlines-saxon-0.11.0.jar.sha1
* ./solr/licenses/kite-morphlines-tika-core-0.11.0.jar.sha1
* ./solr/licenses/kite-morphlines-tika-decompress-0.11.0.jar.sha1
* ./solr/licenses/kite-morphlines-twitter-0.11.0.jar.sha1
Total time: 61 minutes 0 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/jdk1.7.0_60-ea-b04 -server -XX:+UseG1GC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure
[JENKINS] Lucene-Solr-trunk-Linux (32bit/jdk1.7.0_60-ea-b04) -
Build # 9527 - Still Failing!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/9527/
Java: 32bit/jdk1.7.0_60-ea-b04 -client -XX:+UseParallelGC
All tests passed
Build Log:
[...truncated 50402 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:453: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:392: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/extra-targets.xml:87: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/extra-targets.xml:185: The following files are missing svn:eol-style (or binary svn:mime-type):
* ./solr/licenses/kite-morphlines-avro-0.11.0.jar.sha1
* ./solr/licenses/kite-morphlines-core-0.11.0-tests.jar.sha1
* ./solr/licenses/kite-morphlines-core-0.11.0.jar.sha1
* ./solr/licenses/kite-morphlines-hadoop-sequencefile-0.11.0.jar.sha1
* ./solr/licenses/kite-morphlines-json-0.11.0.jar.sha1
* ./solr/licenses/kite-morphlines-saxon-0.11.0.jar.sha1
* ./solr/licenses/kite-morphlines-tika-core-0.11.0.jar.sha1
* ./solr/licenses/kite-morphlines-tika-decompress-0.11.0.jar.sha1
* ./solr/licenses/kite-morphlines-twitter-0.11.0.jar.sha1
Total time: 60 minutes 13 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/jdk1.7.0_60-ea-b04 -client -XX:+UseParallelGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure