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/15 03:20:33 UTC

[JENKINS] Lucene-Solr-4.x-MacOSX (64bit/jdk1.7.0) - Build # 1298 - Still Failing!

Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-MacOSX/1298/
Java: 64bit/jdk1.7.0 -XX:+UseCompressedOops -XX:+UseG1GC

1 tests failed.
FAILED:  org.apache.solr.client.solrj.TestBatchUpdate.testWithXml

Error Message:
IOException occured when talking to server at: https://127.0.0.1:54992/solr/collection1

Stack Trace:
org.apache.solr.client.solrj.SolrServerException: IOException occured when talking to server at: https://127.0.0.1:54992/solr/collection1
	at __randomizedtesting.SeedInfo.seed([C049C687D302B689:6BAB7F715104AFE4]: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.TestBatchUpdate.doIt(TestBatchUpdate.java:130)
	at org.apache.solr.client.solrj.TestBatchUpdate.testWithXml(TestBatchUpdate.java:54)
	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)
	... 46 more




Build Log:
[...truncated 11470 lines...]
   [junit4] Suite: org.apache.solr.client.solrj.TestBatchUpdate
   [junit4]   2> 91441 T241 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (true) and clientAuth (false)
   [junit4]   2> 91441 T241 oas.SolrTestCaseJ4.initCore ####initCore
   [junit4]   2> Creating dataDir: /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-solrj/test/J0/./solrtest-TestBatchUpdate-1392430472279
   [junit4]   2> 91442 T241 oas.SolrTestCaseJ4.initCore ####initCore end
   [junit4]   2> 91442 T241 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 91449 T241 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
   [junit4]   2> 91455 T241 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:54992
   [junit4]   2> 91458 T241 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 91458 T241 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 91458 T241 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/example/solr
   [junit4]   2> 91459 T241 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/example/solr/'
   [junit4]   2> 91488 T241 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/example/solr/solr.xml
   [junit4]   2> 91581 T241 oasc.CorePropertiesLocator.<init> Config-defined core root directory: /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/example/solr
   [junit4]   2> 91581 T241 oasc.CoreContainer.<init> New CoreContainer 1306917113
   [junit4]   2> 91582 T241 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/example/solr/]
   [junit4]   2> 91584 T241 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
   [junit4]   2> 91586 T241 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: null
   [junit4]   2> 91586 T241 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
   [junit4]   2> 91587 T241 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 91587 T241 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 91587 T241 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 91587 T241 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 91588 T241 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 91588 T241 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 91604 T241 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 91605 T241 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 91605 T241 oasc.CoreContainer.load Host Name: 
   [junit4]   2> 91614 T241 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/example/solr
   [junit4]   2> 91627 T241 oasc.CorePropertiesLocator.discoverUnder Found core collection1 in /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/example/solr/collection1/
   [junit4]   2> 91628 T241 oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 91630 T251 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/example/solr/collection1
   [junit4]   2> 91631 T251 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/example/solr/collection1/'
   [junit4]   2> 91683 T251 oasc.SolrConfig.initLibs Adding specified lib dirs to ClassLoader
   [junit4]   2> 91684 T251 oasc.SolrResourceLoader.addToClassLoader WARN No files added to classloader from lib: ../../../contrib/extraction/lib (resolved as: /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/example/solr/collection1/../../../contrib/extraction/lib).
   [junit4]   2> 91684 T251 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/example/solr/collection1/../../../dist).
   [junit4]   2> 91685 T251 oasc.SolrResourceLoader.addToClassLoader WARN No files added to classloader from lib: ../../../contrib/clustering/lib/ (resolved as: /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/example/solr/collection1/../../../contrib/clustering/lib).
   [junit4]   2> 91685 T251 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/example/solr/collection1/../../../dist).
   [junit4]   2> 91686 T251 oasc.SolrResourceLoader.addToClassLoader WARN No files added to classloader from lib: ../../../contrib/langid/lib/ (resolved as: /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/example/solr/collection1/../../../contrib/langid/lib).
   [junit4]   2> 91686 T251 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/example/solr/collection1/../../../dist).
   [junit4]   2> 91686 T251 oasc.SolrResourceLoader.addToClassLoader WARN No files added to classloader from lib: ../../../contrib/velocity/lib (resolved as: /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/example/solr/collection1/../../../contrib/velocity/lib).
   [junit4]   2> 91687 T251 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/example/solr/collection1/../../../dist).
   [junit4]   2> 91771 T251 oasu.SolrIndexConfig.<init> IndexWriter infoStream solr logging is enabled
   [junit4]   2> 91775 T251 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
   [junit4]   2> 91993 T251 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 91994 T251 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 92063 T251 oass.IndexSchema.readSchema [collection1] Schema name=example
   [junit4]   2> 92868 T251 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 92899 T251 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 92907 T251 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 92989 T251 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 92989 T251 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/example/solr/collection1/, dataDir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-solrj/test/J0/solrtest-TestBatchUpdate-1392430472279/
   [junit4]   2> 92989 T251 oasc.JmxMonitoredMap.<init> No JMX servers found, not exposing Solr information with JMX.
   [junit4]   2> 92990 T251 oasc.SolrCore.initListeners [collection1] Added SolrEventListener for newSearcher: org.apache.solr.core.QuerySenderListener{queries=[]}
   [junit4]   2> 92990 T251 oasc.SolrCore.initListeners [collection1] Added SolrEventListener for firstSearcher: org.apache.solr.core.QuerySenderListener{queries=[{q=static firstSearcher warming in solrconfig.xml}]}
   [junit4]   2> 92991 T251 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-solrj/test/J0/solrtest-TestBatchUpdate-1392430472279
   [junit4]   2> 92992 T251 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-solrj/test/J0/solrtest-TestBatchUpdate-1392430472279/index/
   [junit4]   2> 92992 T251 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-solrj/test/J0/solrtest-TestBatchUpdate-1392430472279/index' doesn't exist. Creating new index...
   [junit4]   2> 92993 T251 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-solrj/test/J0/solrtest-TestBatchUpdate-1392430472279/index
   [junit4]   2> 92995 T251 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-113-thread-1]: init: current segments file is "null"; deletionPolicy=org.apache.solr.core.IndexDeletionPolicyWrapper@e77d77b
   [junit4]   2> 92996 T251 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-113-thread-1]: now checkpoint "" [0 segments ; isCommit = false]
   [junit4]   2> 92996 T251 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-113-thread-1]: 0 msec to checkpoint
   [junit4]   2> 92996 T251 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-113-thread-1]: init: create=true
   [junit4]   2> 92996 T251 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-113-thread-1]: 
   [junit4]   2> 	dir=MockDirectoryWrapper(RAMDirectory@24f21ab5 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-solrj/test/J0/solrtest-TestBatchUpdate-1392430472279/index)
   [junit4]   2> 	index=
   [junit4]   2> 	version=4.7-SNAPSHOT
   [junit4]   2> 	matchVersion=LUCENE_47
   [junit4]   2> 	analyzer=null
   [junit4]   2> 	ramBufferSizeMB=100.0
   [junit4]   2> 	maxBufferedDocs=-1
   [junit4]   2> 	maxBufferedDeleteTerms=-1
   [junit4]   2> 	mergedSegmentWarmer=null
   [junit4]   2> 	readerTermsIndexDivisor=1
   [junit4]   2> 	termIndexInterval=32
   [junit4]   2> 	delPolicy=org.apache.solr.core.IndexDeletionPolicyWrapper
   [junit4]   2> 	commit=null
   [junit4]   2> 	openMode=CREATE
   [junit4]   2> 	similarity=org.apache.lucene.search.similarities.DefaultSimilarity
   [junit4]   2> 	mergeScheduler=ConcurrentMergeScheduler: maxThreadCount=1, maxMergeCount=2, mergeThreadPriority=-1
   [junit4]   2> 	default WRITE_LOCK_TIMEOUT=1000
   [junit4]   2> 	writeLockTimeout=1000
   [junit4]   2> 	codec=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@5de3d3a8
   [junit4]   2> 	readerPooling=false
   [junit4]   2> 	perThreadHardLimitMB=1945
   [junit4]   2> 	useCompoundFile=false
   [junit4]   2> 	
   [junit4]   2> 92997 T251 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-113-thread-1]: now flush at close waitForMerges=true
   [junit4]   2> 92997 T251 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-113-thread-1]:   start flush: applyAllDeletes=true
   [junit4]   2> 92997 T251 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-113-thread-1]:   index before flush 
   [junit4]   2> 92997 T251 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-113-thread-1]: coreLoadExecutor-113-thread-1 startFullFlush
   [junit4]   2> 92998 T251 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-113-thread-1]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 92999 T251 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-113-thread-1]: coreLoadExecutor-113-thread-1 finishFullFlush success=true
   [junit4]   2> 92999 T251 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-113-thread-1]: apply all deletes during flush
   [junit4]   2> 92999 T251 oasu.LoggingInfoStream.message [BD][coreLoadExecutor-113-thread-1]: prune sis=org.apache.lucene.index.SegmentInfos@185ceac0 minGen=9223372036854775807 packetCount=0
   [junit4]   2> 93000 T251 oasu.LoggingInfoStream.message [CMS][coreLoadExecutor-113-thread-1]: now merge
   [junit4]   2> 93000 T251 oasu.LoggingInfoStream.message [CMS][coreLoadExecutor-113-thread-1]:   index: 
   [junit4]   2> 93000 T251 oasu.LoggingInfoStream.message [CMS][coreLoadExecutor-113-thread-1]:   no more merges pending; now return
   [junit4]   2> 93000 T251 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-113-thread-1]: waitForMerges
   [junit4]   2> 93000 T251 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-113-thread-1]: waitForMerges done
   [junit4]   2> 93001 T251 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-113-thread-1]: now call final commit()
   [junit4]   2> 93001 T251 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-113-thread-1]: commit: start
   [junit4]   2> 93001 T251 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-113-thread-1]: commit: enter lock
   [junit4]   2> 93001 T251 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-113-thread-1]: commit: now prepare
   [junit4]   2> 93001 T251 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-113-thread-1]: prepareCommit: flush
   [junit4]   2> 93002 T251 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-113-thread-1]:   index before flush 
   [junit4]   2> 93002 T251 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-113-thread-1]: coreLoadExecutor-113-thread-1 startFullFlush
   [junit4]   2> 93002 T251 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-113-thread-1]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 93002 T251 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-113-thread-1]: apply all deletes during flush
   [junit4]   2> 93003 T251 oasu.LoggingInfoStream.message [BD][coreLoadExecutor-113-thread-1]: prune sis=org.apache.lucene.index.SegmentInfos@185ceac0 minGen=9223372036854775807 packetCount=0
   [junit4]   2> 93003 T251 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-113-thread-1]: coreLoadExecutor-113-thread-1 finishFullFlush success=true
   [junit4]   2> 93003 T251 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-113-thread-1]: startCommit(): start
   [junit4]   2> 93003 T251 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-113-thread-1]: startCommit index= changeCount=1
   [junit4]   2> 93004 T251 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-113-thread-1]: done all syncs: []
   [junit4]   2> 93004 T251 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-113-thread-1]: commit: pendingCommit != null
   [junit4]   2> 93004 T251 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-113-thread-1]: commit: wrote segments file "segments_1"
   [junit4]   2> 93004 T251 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-113-thread-1]: now checkpoint "" [0 segments ; isCommit = true]
   [junit4]   2> 93005 T251 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@24f21ab5 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-solrj/test/J0/solrtest-TestBatchUpdate-1392430472279/index),segFN=segments_1,generation=1}
   [junit4]   2> 93015 T251 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 93015 T251 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-113-thread-1]: 11 msec to checkpoint
   [junit4]   2> 93016 T251 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-113-thread-1]: commit: done
   [junit4]   2> 93016 T251 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-113-thread-1]: at close: 
   [junit4]   2> 93027 T251 oasc.SolrCore.initWriters created json: solr.JSONResponseWriter
   [junit4]   2> 93028 T251 oasc.SolrCore.initWriters adding lazy queryResponseWriter: solr.VelocityResponseWriter
   [junit4]   2> 93028 T251 oasc.SolrCore.initWriters created velocity: solr.VelocityResponseWriter
   [junit4]   2> 93028 T251 oasc.SolrCore.initWriters created xslt: solr.XSLTResponseWriter
   [junit4]   2> 93028 T251 oasr.XSLTResponseWriter.init xsltCacheLifetimeSeconds=5
   [junit4]   2> 93052 T251 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 93052 T251 oasc.RequestHandlers.initHandlersFromConfig created /select: solr.SearchHandler
   [junit4]   2> 93052 T251 oasc.RequestHandlers.initHandlersFromConfig created /query: solr.SearchHandler
   [junit4]   2> 93053 T251 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 93054 T251 oasc.RequestHandlers.initHandlersFromConfig created /browse: solr.SearchHandler
   [junit4]   2> 93054 T251 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 93055 T251 oasc.RequestHandlers.initHandlersFromConfig created /update/json: solr.UpdateRequestHandler
   [junit4]   2> 93056 T251 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: solr.UpdateRequestHandler
   [junit4]   2> 93056 T251 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.extraction.ExtractingRequestHandler
   [junit4]   2> 93056 T251 oasc.RequestHandlers.initHandlersFromConfig created /update/extract: solr.extraction.ExtractingRequestHandler
   [junit4]   2> 93056 T251 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.FieldAnalysisRequestHandler
   [junit4]   2> 93057 T251 oasc.RequestHandlers.initHandlersFromConfig created /analysis/field: solr.FieldAnalysisRequestHandler
   [junit4]   2> 93057 T251 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.DocumentAnalysisRequestHandler
   [junit4]   2> 93057 T251 oasc.RequestHandlers.initHandlersFromConfig created /analysis/document: solr.DocumentAnalysisRequestHandler
   [junit4]   2> 93058 T251 oasc.RequestHandlers.initHandlersFromConfig created /admin/: solr.admin.AdminHandlers
   [junit4]   2> 93058 T251 oasc.RequestHandlers.initHandlersFromConfig created /admin/ping: solr.PingRequestHandler
   [junit4]   2> 93059 T251 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
   [junit4]   2> 93060 T251 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 93060 T251 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
   [junit4]   2> 93061 T251 oasc.RequestHandlers.initHandlersFromConfig created /spell: solr.SearchHandler
   [junit4]   2> 93061 T251 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
   [junit4]   2> 93061 T251 oasc.RequestHandlers.initHandlersFromConfig created /suggest: solr.SearchHandler
   [junit4]   2> 93061 T251 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
   [junit4]   2> 93061 T251 oasc.RequestHandlers.initHandlersFromConfig created /tvrh: solr.SearchHandler
   [junit4]   2> 93062 T251 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
   [junit4]   2> 93062 T251 oasc.RequestHandlers.initHandlersFromConfig created /terms: solr.SearchHandler
   [junit4]   2> 93062 T251 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
   [junit4]   2> 93062 T251 oasc.RequestHandlers.initHandlersFromConfig created /elevate: solr.SearchHandler
   [junit4]   2> 93074 T251 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 93076 T251 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 93078 T251 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 93087 T251 oasu.CommitTracker.<init> Hard AutoCommit: if uncommited for 15000ms; 
   [junit4]   2> 93087 T251 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 93088 T251 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-113-thread-1]: init: current segments file is "segments_1"; deletionPolicy=org.apache.solr.core.IndexDeletionPolicyWrapper@e77d77b
   [junit4]   2> 93088 T251 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-113-thread-1]: init: load commit "segments_1"
   [junit4]   2> 93089 T251 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@24f21ab5 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-solrj/test/J0/solrtest-TestBatchUpdate-1392430472279/index),segFN=segments_1,generation=1}
   [junit4]   2> 93089 T251 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 93089 T251 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-113-thread-1]: now checkpoint "" [0 segments ; isCommit = false]
   [junit4]   2> 93089 T251 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-113-thread-1]: 0 msec to checkpoint
   [junit4]   2> 93090 T251 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-113-thread-1]: init: create=false
   [junit4]   2> 93090 T251 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-113-thread-1]: 
   [junit4]   2> 	dir=MockDirectoryWrapper(RAMDirectory@24f21ab5 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-solrj/test/J0/solrtest-TestBatchUpdate-1392430472279/index)
   [junit4]   2> 	index=
   [junit4]   2> 	version=4.7-SNAPSHOT
   [junit4]   2> 	matchVersion=LUCENE_47
   [junit4]   2> 	analyzer=null
   [junit4]   2> 	ramBufferSizeMB=100.0
   [junit4]   2> 	maxBufferedDocs=-1
   [junit4]   2> 	maxBufferedDeleteTerms=-1
   [junit4]   2> 	mergedSegmentWarmer=null
   [junit4]   2> 	readerTermsIndexDivisor=1
   [junit4]   2> 	termIndexInterval=32
   [junit4]   2> 	delPolicy=org.apache.solr.core.IndexDeletionPolicyWrapper
   [junit4]   2> 	commit=null
   [junit4]   2> 	openMode=APPEND
   [junit4]   2> 	similarity=org.apache.lucene.search.similarities.DefaultSimilarity
   [junit4]   2> 	mergeScheduler=ConcurrentMergeScheduler: maxThreadCount=1, maxMergeCount=2, mergeThreadPriority=-1
   [junit4]   2> 	default WRITE_LOCK_TIMEOUT=1000
   [junit4]   2> 	writeLockTimeout=1000
   [junit4]   2> 	codec=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@552f128b
   [junit4]   2> 	readerPooling=false
   [junit4]   2> 	perThreadHardLimitMB=1945
   [junit4]   2> 	useCompoundFile=false
   [junit4]   2> 	
   [junit4]   2> 93090 T251 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-113-thread-1]: flush at getReader
   [junit4]   2> 93090 T251 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-113-thread-1]: coreLoadExecutor-113-thread-1 startFullFlush
   [junit4]   2> 93091 T251 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-113-thread-1]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 93091 T251 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-113-thread-1]: apply all deletes during flush
   [junit4]   2> 93091 T251 oasu.LoggingInfoStream.message [BD][coreLoadExecutor-113-thread-1]: prune sis=org.apache.lucene.index.SegmentInfos@56a8f5e minGen=9223372036854775807 packetCount=0
   [junit4]   2> 93091 T251 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-113-thread-1]: return reader version=1 reader=StandardDirectoryReader(segments_1:1:nrt)
   [junit4]   2> 93092 T251 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-113-thread-1]: coreLoadExecutor-113-thread-1 finishFullFlush success=true
   [junit4]   2> 93092 T251 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-113-thread-1]: getReader took 2 msec
   [junit4]   2> 93092 T251 oass.SolrIndexSearcher.<init> Opening Searcher@7716a60f[collection1] main
   [junit4]   2> 93092 T251 oashc.SpellCheckComponent.inform Initializing spell checkers
   [junit4]   2> 93093 T251 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> 93094 T251 oashc.SpellCheckComponent.inform No queryConverter defined, using default converter
   [junit4]   2> 93094 T251 oashc.SuggestComponent.inform Initializing SuggestComponent
   [junit4]   2> 93094 T251 oasss.SolrSuggester.init init: {name=mySuggester,lookupImpl=FuzzyLookupFactory,dictionaryImpl=DocumentDictionaryFactory,field=cat,weightField=price,suggestAnalyzerFieldType=string}
   [junit4]   2> 93095 T251 oasss.SolrSuggester.init Dictionary loaded with params: {name=mySuggester,lookupImpl=FuzzyLookupFactory,dictionaryImpl=DocumentDictionaryFactory,field=cat,weightField=price,suggestAnalyzerFieldType=string}
   [junit4]   2> 93095 T251 oashc.QueryElevationComponent.inform Loading QueryElevation from: /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/example/solr/collection1/conf/elevate.xml
   [junit4]   2> 93131 T251 oash.ReplicationHandler.inform Commits will be reserved for  10000
   [junit4]   2> 93132 T251 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 93132 T252 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@7716a60f[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 93132 T241 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-solrj/test/J0
   [junit4]   2> 93133 T241 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 93133 T241 oas.SolrJettyTestBase.createJetty Jetty Assigned Port#54992
   [junit4]   2> ASYNC  NEW_CORE C40 name=collection1 org.apache.solr.core.SolrCore@616b99f1
   [junit4]   2> 93133 T252 C40 oasc.SolrCore.execute [collection1] webapp=null path=null params={distrib=false&event=firstSearcher&q=static+firstSearcher+warming+in+solrconfig.xml} hits=0 status=0 QTime=1 
   [junit4]   2> 93134 T252 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
   [junit4]   2> 93134 T252 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: default
   [junit4]   2> 93134 T252 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: wordbreak
   [junit4]   2> 93135 T252 oashc.SuggestComponent$SuggesterListener.newSearcher Loading suggester index for: mySuggester
   [junit4]   2> 93135 T252 oasss.SolrSuggester.reload reload()
   [junit4]   2> 93135 T252 oasss.SolrSuggester.build build()
   [junit4]   2> 93140 T252 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7716a60f[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 93144 T241 oas.SolrTestCaseJ4.setUp ###Starting testWithXml
   [junit4]   2> 93184 T245 C40 oasu.LoggingInfoStream.message [DW][qtp120925460-245]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 93185 T245 C40 oasu.LoggingInfoStream.message [IW][qtp120925460-245]: nrtIsCurrent: infoVersion matches: true; DW changes: true; BD changes: false
   [junit4]   2> 93185 T245 C40 oasu.LoggingInfoStream.message [DW][qtp120925460-245]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 93185 T245 C40 oasu.LoggingInfoStream.message [IW][qtp120925460-245]: flush at getReader
   [junit4]   2> 93186 T245 C40 oasu.LoggingInfoStream.message [DW][qtp120925460-245]: qtp120925460-245 startFullFlush
   [junit4]   2> 93186 T245 C40 oasu.LoggingInfoStream.message [DW][qtp120925460-245]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 93186 T245 C40 oasu.LoggingInfoStream.message [DW][qtp120925460-245]: qtp120925460-245: flush naked frozen global deletes
   [junit4]   2> 93187 T245 C40 oasu.LoggingInfoStream.message [BD][qtp120925460-245]: push deletes  1 deleted queries bytesUsed=32 delGen=2 packetCount=1 totBytesUsed=32
   [junit4]   2> 93187 T245 C40 oasu.LoggingInfoStream.message [DW][qtp120925460-245]: flush: push buffered updates:  1 deleted queries bytesUsed=32
   [junit4]   2> 93188 T245 C40 oasu.LoggingInfoStream.message [IW][qtp120925460-245]: apply all deletes during flush
   [junit4]   2> 93188 T245 C40 oasu.LoggingInfoStream.message [BD][qtp120925460-245]: prune sis=org.apache.lucene.index.SegmentInfos@56a8f5e minGen=9223372036854775807 packetCount=1
   [junit4]   2> 93188 T245 C40 oasu.LoggingInfoStream.message [BD][qtp120925460-245]: pruneDeletes: prune 1 packets; 0 packets remain
   [junit4]   2> 93189 T245 C40 oasu.LoggingInfoStream.message [IW][qtp120925460-245]: return reader version=1 reader=StandardDirectoryReader(segments_1:1:nrt)
   [junit4]   2> 93189 T245 C40 oasu.LoggingInfoStream.message [DW][qtp120925460-245]: qtp120925460-245 finishFullFlush success=true
   [junit4]   2> 93189 T245 C40 oasu.LoggingInfoStream.message [IW][qtp120925460-245]: getReader took 4 msec
   [junit4]   2> 93190 T245 C40 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {deleteByQuery=*:* (-1460069176725995520)} 0 8
   [junit4]   2> 94211 T246 C40 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[1 (1460069176768987136), 2 (1460069176772132864), 3 (1460069176773181440), 4 (1460069176775278592), 5 (1460069176775278593), 6 (1460069176777375744), 7 (1460069176778424320), 8 (1460069176778424321), 9 (1460069176779472896), 10 (1460069176779472897), ... (1000 adds)]} 0 989
   [junit4]   2> 108191 T254 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 108192 T254 oasu.LoggingInfoStream.message [IW][commitScheduler-116-thread-1]: commit: start
   [junit4]   2> 108192 T254 oasu.LoggingInfoStream.message [IW][commitScheduler-116-thread-1]: commit: enter lock
   [junit4]   2> 108192 T254 oasu.LoggingInfoStream.message [IW][commitScheduler-116-thread-1]: commit: now prepare
   [junit4]   2> 108193 T254 oasu.LoggingInfoStream.message [IW][commitScheduler-116-thread-1]: prepareCommit: flush
   [junit4]   2> 108193 T254 oasu.LoggingInfoStream.message [IW][commitScheduler-116-thread-1]:   index before flush 
   [junit4]   2> 108194 T254 oasu.LoggingInfoStream.message [DW][commitScheduler-116-thread-1]: commitScheduler-116-thread-1 startFullFlush
   [junit4]   2> 108195 T254 oasu.LoggingInfoStream.message [DW][commitScheduler-116-thread-1]: anyChanges? numDocsInRam=1000 deletes=true hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 108196 T254 oasu.LoggingInfoStream.message [DWFC][commitScheduler-116-thread-1]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0 999 deleted terms (unique count=999) bytesUsed=166728, segment=_0, aborting=false, numDocsInRAM=1000, deleteQueue=DWDQ: [ generation: 2 ]]
   [junit4]   2> 108226 T254 oasu.LoggingInfoStream.message [DWPT][commitScheduler-116-thread-1]: flush postings as segment _0 numDocs=1000
   [junit4]   2> 108289 T254 oasu.LoggingInfoStream.message [DWPT][commitScheduler-116-thread-1]: new segment has 0 deleted docs
   [junit4]   2> 108289 T254 oasu.LoggingInfoStream.message [DWPT][commitScheduler-116-thread-1]: new segment has no vectors; norms; no docValues; prox; freqs
   [junit4]   2> 108290 T254 oasu.LoggingInfoStream.message [DWPT][commitScheduler-116-thread-1]: flushedFiles=[_0.fdx, _0_Lucene41_0.doc, _0_Lucene41_0.tip, _0_Lucene41_0.tim, _0.fdt, _0.nvm, _0_Lucene41_0.pos, _0.fnm, _0.nvd]
   [junit4]   2> 108290 T254 oasu.LoggingInfoStream.message [DWPT][commitScheduler-116-thread-1]: flushed codec=Lucene46
   [junit4]   2> 108290 T254 oasu.LoggingInfoStream.message [DWPT][commitScheduler-116-thread-1]: flushed: segment=_0 ramUsed=0.286 MB newFlushedSize(includes docstores)=0.026 MB docs/MB=38,788.74
   [junit4]   2> 108291 T254 oasu.LoggingInfoStream.message [DW][commitScheduler-116-thread-1]: publishFlushedSegment seg-private updates=null
   [junit4]   2> 108291 T254 oasu.LoggingInfoStream.message [IW][commitScheduler-116-thread-1]: publishFlushedSegment
   [junit4]   2> 108291 T254 oasu.LoggingInfoStream.message [BD][commitScheduler-116-thread-1]: push deletes  1000 deleted terms (unique count=1000) bytesUsed=3072 delGen=4 packetCount=1 totBytesUsed=3072
   [junit4]   2> 108291 T254 oasu.LoggingInfoStream.message [IW][commitScheduler-116-thread-1]: publish sets newSegment delGen=5 seg=_0(4.7):C1000
   [junit4]   2> 108292 T254 oasu.LoggingInfoStream.message [IFD][commitScheduler-116-thread-1]: now checkpoint "_0(4.7):C1000" [1 segments ; isCommit = false]
   [junit4]   2> 108292 T254 oasu.LoggingInfoStream.message [IFD][commitScheduler-116-thread-1]: 0 msec to checkpoint
   [junit4]   2> 108292 T254 oasu.LoggingInfoStream.message [IW][commitScheduler-116-thread-1]: apply all deletes during flush
   [junit4]   2> 108292 T254 oasu.LoggingInfoStream.message [BD][commitScheduler-116-thread-1]: applyDeletes: infos=[_0(4.7):C1000] packetCount=1
   [junit4]   2> 108293 T254 oasu.LoggingInfoStream.message [BD][commitScheduler-116-thread-1]: applyDeletes took 1 msec
   [junit4]   2> 108293 T254 oasu.LoggingInfoStream.message [BD][commitScheduler-116-thread-1]: prune sis=org.apache.lucene.index.SegmentInfos@56a8f5e minGen=6 packetCount=1
   [junit4]   2> 108293 T254 oasu.LoggingInfoStream.message [BD][commitScheduler-116-thread-1]: pruneDeletes: prune 1 packets; 0 packets remain
   [junit4]   2> 108293 T254 oasu.LoggingInfoStream.message [DW][commitScheduler-116-thread-1]: commitScheduler-116-thread-1 finishFullFlush success=true
   [junit4]   2> 108293 T254 oasu.LoggingInfoStream.message [TMP][commitScheduler-116-thread-1]: findMerges: 1 segments
   [junit4]   2> 108294 T254 oasu.LoggingInfoStream.message [TMP][commitScheduler-116-thread-1]:   seg=_0(4.7):C1000 size=0.025 MB [floored]
   [junit4]   2> 108294 T254 oasu.LoggingInfoStream.message [TMP][commitScheduler-116-thread-1]:   allowedSegmentCount=1 vs count=1 (eligible count=1) tooBigCount=0
   [junit4]   2> 108294 T254 oasu.LoggingInfoStream.message [CMS][commitScheduler-116-thread-1]: now merge
   [junit4]   2> 108295 T254 oasu.LoggingInfoStream.message [CMS][commitScheduler-116-thread-1]:   index: _0(4.7):C1000
   [junit4]   2> 108295 T254 oasu.LoggingInfoStream.message [CMS][commitScheduler-116-thread-1]:   no more merges pending; now return
   [junit4]   2> 108295 T254 oasu.LoggingInfoStream.message [IW][commitScheduler-116-thread-1]: startCommit(): start
   [junit4]   2> 108295 T254 oasu.LoggingInfoStream.message [IW][commitScheduler-116-thread-1]: startCommit index=_0(4.7):C1000 changeCount=3
   [junit4]   2> 108295 T254 oasu.LoggingInfoStream.message [IW][commitScheduler-116-thread-1]: done all syncs: [_0.fdx, _0_Lucene41_0.doc, _0.si, _0_Lucene41_0.tip, _0.fdt, _0_Lucene41_0.tim, _0_Lucene41_0.pos, _0.nvm, _0.fnm, _0.nvd]
   [junit4]   2> 108296 T254 oasu.LoggingInfoStream.message [IW][commitScheduler-116-thread-1]: commit: pendingCommit != null
   [junit4]   2> 108296 T254 oasu.LoggingInfoStream.message [IW][commitScheduler-116-thread-1]: commit: wrote segments file "segments_2"
   [junit4]   2> 108296 T254 oasu.LoggingInfoStream.message [IFD][commitScheduler-116-thread-1]: now checkpoint "_0(4.7):C1000" [1 segments ; isCommit = true]
   [junit4]   2> 108297 T254 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@24f21ab5 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-solrj/test/J0/solrtest-TestBatchUpdate-1392430472279/index),segFN=segments_1,generation=1}
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@24f21ab5 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-solrj/test/J0/solrtest-TestBatchUpdate-1392430472279/index),segFN=segments_2,generation=2}
   [junit4]   2> 108311 T254 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
   [junit4]   2> 108311 T254 oasu.LoggingInfoStream.message [IFD][commitScheduler-116-thread-1]: deleteCommits: now decRef commit "segments_1"
   [junit4]   2> 108311 T254 oasu.LoggingInfoStream.message [IFD][commitScheduler-116-thread-1]: delete "segments_1"
   [junit4]   2> 108331 T254 oasu.LoggingInfoStream.message [IFD][commitScheduler-116-thread-1]: 35 msec to checkpoint
   [junit4]   2> 108331 T254 oasu.LoggingInfoStream.message [IW][commitScheduler-116-thread-1]: commit: done
   [junit4]   2> 108332 T254 oasu.LoggingInfoStream.message [DW][commitScheduler-116-thread-1]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 108332 T254 oasu.LoggingInfoStream.message [IW][commitScheduler-116-thread-1]: nrtIsCurrent: infoVersion matches: false; DW changes: false; BD changes: false
   [junit4]   2> 108332 T254 oasu.LoggingInfoStream.message [IW][commitScheduler-116-thread-1]: flush at getReader
   [junit4]   2> 108333 T254 oasu.LoggingInfoStream.message [DW][commitScheduler-116-thread-1]: commitScheduler-116-thread-1 startFullFlush
   [junit4]   2> 108333 T254 oasu.LoggingInfoStream.message [DW][commitScheduler-116-thread-1]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 108333 T254 oasu.LoggingInfoStream.message [IW][commitScheduler-116-thread-1]: apply all deletes during flush
   [junit4]   2> 108333 T254 oasu.LoggingInfoStream.message [BD][commitScheduler-116-thread-1]: applyDeletes: no deletes; skipping
   [junit4]   2> 108333 T254 oasu.LoggingInfoStream.message [BD][commitScheduler-116-thread-1]: prune sis=org.apache.lucene.index.SegmentInfos@56a8f5e minGen=6 packetCount=0
   [junit4]   2> 108335 T254 oasu.LoggingInfoStream.message [IW][commitScheduler-116-thread-1]: return reader version=3 reader=StandardDirectoryReader(segments_2:3:nrt _0(4.7):C1000)
   [junit4]   2> 108335 T254 oasu.LoggingInfoStream.message [DW][commitScheduler-116-thread-1]: commitScheduler-116-thread-1 finishFullFlush success=true
   [junit4]   2> 108335 T254 oasu.LoggingInfoStream.message [IW][commitScheduler-116-thread-1]: getReader took 3 msec
   [junit4]   2> 108335 T254 oass.SolrIndexSearcher.<init> Opening Searcher@7520923c[collection1] realtime
   [junit4]   2> 108336 T254 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 294440 T248 C40 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 294441 T241 oas.SolrTestCaseJ4.tearDown ###Ending testWithXml
   [junit4]   2> 294441 T248 C40 oasu.LoggingInfoStream.message [DW][qtp120925460-248]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 294442 T248 C40 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
   [junit4]   2> 294462 T248 C40 oasu.LoggingInfoStream.message [DW][qtp120925460-248]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 294463 T248 C40 oasu.LoggingInfoStream.message [IW][qtp120925460-248]: nrtIsCurrent: infoVersion matches: true; DW changes: false; BD changes: false
   [junit4]   2> 294464 T248 C40 oasu.LoggingInfoStream.message [DW][qtp120925460-248]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 294464 T248 C40 oass.SolrIndexSearcher.<init> Opening Searcher@7a8a5fd2[collection1] main
   [junit4]   2> 294464 T248 C40 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 294473 T252 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@7a8a5fd2[collection1] main{StandardDirectoryReader(segments_2:3:nrt _0(4.7):C1000)}
   [junit4]   2> 294473 T252 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
   [junit4]   2> 294473 T252 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7a8a5fd2[collection1] main{StandardDirectoryReader(segments_2:3:nrt _0(4.7):C1000)}
   [junit4]   2> 294473 T248 C40 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&commit=true&waitSearcher=true&softCommit=false&wt=javabin} {commit=} 0 33
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=TestBatchUpdate -Dtests.method=testWithXml -Dtests.seed=C049C687D302B689 -Dtests.slow=true -Dtests.locale=es_NI -Dtests.timezone=Pacific/Kosrae -Dtests.file.encoding=US-ASCII
   [junit4] ERROR    201s | TestBatchUpdate.testWithXml <<<
   [junit4]    > Throwable #1: org.apache.solr.client.solrj.SolrServerException: IOException occured when talking to server at: https://127.0.0.1:54992/solr/collection1
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([C049C687D302B689:6BAB7F715104AFE4]:0)
   [junit4]    > 	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:507)
   [junit4]    > 	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:199)
   [junit4]    > 	at org.apache.solr.client.solrj.request.AbstractUpdateRequest.process(AbstractUpdateRequest.java:117)
   [junit4]    > 	at org.apache.solr.client.solrj.SolrServer.commit(SolrServer.java:168)
   [junit4]    > 	at org.apache.solr.client.solrj.SolrServer.commit(SolrServer.java:146)
   [junit4]    > 	at org.apache.solr.client.solrj.TestBatchUpdate.doIt(TestBatchUpdate.java:130)
   [junit4]    > 	at org.apache.solr.client.solrj.TestBatchUpdate.testWithXml(TestBatchUpdate.java:54)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:744)
   [junit4]    > Caused by: org.apache.http.NoHttpResponseException: The target server failed to respond
   [junit4]    > 	at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:143)
   [junit4]    > 	at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:57)
   [junit4]    > 	at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:260)
   [junit4]    > 	at org.apache.http.impl.AbstractHttpClientConnection.receiveResponseHeader(AbstractHttpClientConnection.java:283)
   [junit4]    > 	at org.apache.http.impl.conn.DefaultClientConnection.receiveResponseHeader(DefaultClientConnection.java:251)
   [junit4]    > 	at org.apache.http.impl.conn.ManagedClientConnectionImpl.receiveResponseHeader(ManagedClientConnectionImpl.java:197)
   [junit4]    > 	at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:271)
   [junit4]    > 	at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:123)
   [junit4]    > 	at org.apache.http.impl.client.DefaultRequestDirector.tryExecute(DefaultRequestDirector.java:682)
   [junit4]    > 	at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:486)
   [junit4]    > 	at org.apache.http.impl.client.AbstractHttpClient.doExecute(AbstractHttpClient.java:863)
   [junit4]    > 	at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82)
   [junit4]    > 	at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:106)
   [junit4]    > 	at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:57)
   [junit4]    > 	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:395)
   [junit4]    > 	... 46 more
   [junit4]   2> 294573 T241 oas.SolrTestCaseJ4.setUp ###Starting testWithBinaryBean
   [junit4]   2> 294607 T245 C40 oasu.LoggingInfoStream.message [DW][qtp120925460-245]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 294607 T245 C40 oasu.LoggingInfoStream.message [IW][qtp120925460-245]: nrtIsCurrent: infoVersion matches: true; DW changes: true; BD changes: false
   [junit4]   2> 294608 T245 C40 oasu.LoggingInfoStream.message [DW][qtp120925460-245]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 294608 T245 C40 oasu.LoggingInfoStream.message [IW][qtp120925460-245]: flush at getReader
   [junit4]   2> 294608 T245 C40 oasu.LoggingInfoStream.message [DW][qtp120925460-245]: qtp120925460-245 startFullFlush
   [junit4]   2> 294608 T245 C40 oasu.LoggingInfoStream.message [DW][qtp120925460-245]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 294609 T245 C40 oasu.LoggingInfoStream.message [DW][qtp120925460-245]: qtp120925460-245: flush naked frozen global deletes
   [junit4]   2> 294609 T245 C40 oasu.LoggingInfoStream.message [BD][qtp120925460-245]: push deletes  1 deleted queries bytesUsed=32 delGen=8 packetCount=1 totBytesUsed=32
   [junit4]   2> 294609 T245 C40 oasu.LoggingInfoStream.message [DW][qtp120925460-245]: flush: push buffered updates:  1 deleted queries bytesUsed=32
   [junit4]   2> 294609 T245 C40 oasu.LoggingInfoStream.message [IW][qtp120925460-245]: apply all deletes during flush
   [junit4]   2> 294610 T245 C40 oasu.LoggingInfoStream.message [BD][qtp120925460-245]: applyDeletes: infos=[_0(4.7):C1000] packetCount=1
   [junit4]   2> 294621 T245 C40 oasu.LoggingInfoStream.message [BD][qtp120925460-245]: seg=_0(4.7):C1000 segGen=6 coalesced deletes=[CoalescedUpdates(termSets=1,queries=1,numericUpdates=0)] newDelCount=1000 100% deleted
   [junit4]   2> 294622 T245 C40 oasu.LoggingInfoStream.message [BD][qtp120925460-245]: applyDeletes took 12 msec
   [junit4]   2> 294622 T245 C40 oasu.LoggingInfoStream.message [IFD][qtp120925460-245]: now checkpoint "_0(4.7):C1000/1000" [1 segments ; isCommit = false]
   [junit4]   2> 294623 T245 C40 oasu.LoggingInfoStream.message [IFD][qtp120925460-245]: 0 msec to checkpoint
   [junit4]   2> 294623 T245 C40 oasu.LoggingInfoStream.message [IW][qtp120925460-245]: drop 100% deleted segments: _0(4.7):C1000/1000
   [junit4]   2> 294623 T245 C40 oasu.LoggingInfoStream.message [IFD][qtp120925460-245]: now checkpoint "" [0 segments ; isCommit = false]
   [junit4]   2> 294624 T245 C40 oasu.LoggingInfoStream.message [IFD][qtp120925460-245]: 0 msec to checkpoint
   [junit4]   2> 294624 T245 C40 oasu.LoggingInfoStream.message [BD][qtp120925460-245]: prune sis=org.apache.lucene.index.SegmentInfos@56a8f5e minGen=9223372036854775807 packetCount=1
   [junit4]   2> 294625 T245 C40 oasu.LoggingInfoStream.message [BD][qtp120925460-245]: pruneDeletes: prune 1 packets; 0 packets remain
   [junit4]   2> 294625 T245 C40 oasu.LoggingInfoStream.message [IW][qtp120925460-245]: return reader version=5 reader=StandardDirectoryReader(segments_2:5:nrt)
   [junit4]   2> 294627 T245 C40 oasu.LoggingInfoStream.message [DW][qtp120925460-245]: qtp120925460-245 finishFullFlush success=true
   [junit4]   2> 294627 T245 C40 oasu.LoggingInfoStream.message [IW][qtp120925460-245]: getReader took 19 msec
   [junit4]   2> 294628 T245 C40 oass.SolrIndexSearcher.<init> Opening Searcher@9f1948[collection1] realtime
   [junit4]   2> 294628 T245 C40 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {deleteByQuery=*:* (-1460069387934367744)} 0 27
   [junit4]   2> 295354 T247 C40 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[1 (1460069388033982464), 2 (1460069388036079616), 3 (1460069388037128192), 4 (1460069388037128193), 5 (1460069388037128194), 6 (1460069388038176768), 7 (1460069388038176769), 8 (1460069388039225344), 9 (1460069388039225345), 10 (1460069388039225346), ... (1000 adds)]} 0 653
   [junit4]   2> 295361 T249 C40 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 295362 T249 C40 oasu.LoggingInfoStream.message [IW][qtp120925460-249]: commit: start
   [junit4]   2> 295363 T249 C40 oasu.LoggingInfoStream.message [IW][qtp120925460-249]: commit: enter lock
   [junit4]   2> 295363 T249 C40 oasu.LoggingInfoStream.message [IW][qtp120925460-249]: commit: now prepare
   [junit4]   2> 295364 T249 C40 oasu.LoggingInfoStream.message [IW][qtp120925460-249]: prepareCommit: flush
   [junit4]   2> 295364 T249 C40 oasu.LoggingInfoStream.message [IW][qtp120925460-249]:   index before flush 
   [junit4]   2> 295364 T249 C40 oasu.LoggingInfoStream.message [DW][qtp120925460-249]: qtp120925460-249 startFullFlush
   [junit4]   2> 295364 T249 C40 oasu.LoggingInfoStream.message [DW][qtp120925460-249]: anyChanges? numDocsInRam=1000 deletes=true hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 295365 T249 C40 oasu.LoggingInfoStream.message [DWFC][qtp120925460-249]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0 999 deleted terms (unique count=999) bytesUsed=166728, segment=_1, aborting=false, numDocsInRAM=1000, deleteQueue=DWDQ: [ generation: 5 ]]
   [junit4]   2> 295369 T249 C40 oasu.LoggingInfoStream.message [DWPT][qtp120925460-249]: flush postings as segment _1 numDocs=1000
   [junit4]   2> 295389 T249 C40 oasu.LoggingInfoStream.message [DWPT][qtp120925460-249]: new segment has 0 deleted docs
   [junit4]   2> 295390 T249 C40 oasu.LoggingInfoStream.message [DWPT][qtp120925460-249]: new segment has no vectors; norms; no docValues; prox; freqs
   [junit4]   2> 295390 T249 C40 oasu.LoggingInfoStream.message [DWPT][qtp120925460-249]: flushedFiles=[_1_Lucene41_0.tip, _1_Lucene41_0.pos, _1_Lucene41_0.tim, _1.fdx, _1_Lucene41_0.doc, _1.fdt, _1.nvm, _1.nvd, _1.fnm]
   [junit4]   2> 295391 T249 C40 oasu.LoggingInfoStream.message [DWPT][qtp120925460-249]: flushed codec=Lucene46
   [junit4]   2> 295391 T249 C40 oasu.LoggingInfoStream.message [DWPT][qtp120925460-249]: flushed: segment=_1 ramUsed=0.286 MB newFlushedSize(includes docstores)=0.026 MB docs/MB=38,862.056
   [junit4]   2> 295392 T249 C40 oasu.LoggingInfoStream.message [DW][qtp120925460-249]: publishFlushedSegment seg-private updates=null
   [junit4]   2> 295392 T249 C40 oasu.LoggingInfoStream.message [IW][qtp120925460-249]: publishFlushedSegment
   [junit4]   2> 295392 T249 C40 oasu.LoggingInfoStream.message [BD][qtp120925460-249]: push deletes  1000 deleted terms (unique count=1000) bytesUsed=3072 delGen=10 packetCount=1 totBytesUsed=3072
   [junit4]   2> 295393 T249 C40 oasu.LoggingInfoStream.message [IW][qtp120925460-249]: publish sets newSegment delGen=11 seg=_1(4.7):C1000
   [junit4]   2> 295393 T249 C40 oasu.LoggingInfoStream.message [IFD][qtp120925460-249]: now checkpoint "_1(4.7):C1000" [1 segments ; isCommit = false]
   [junit4]   2> 295393 T249 C40 oasu.LoggingInfoStream.message [IFD][qtp120925460-249]: 0 msec to checkpoint
   [junit4]   2> 295394 T249 C40 oasu.LoggingInfoStream.message [IW][qtp120925460-249]: apply all deletes during flush
   [junit4]   2> 295394 T249 C40 oasu.LoggingInfoStream.message [BD][qtp120925460-249]: applyDeletes: infos=[_1(4.7):C1000] packetCount=1
   [junit4]   2> 295395 T249 C40 oasu.LoggingInfoStream.message [BD][qtp120925460-249]: applyDeletes took 1 msec
   [junit4]   2> 295395 T249 C40 oasu.LoggingInfoStream.message [BD][qtp120925460-249]: prune sis=org.apache.lucene.index.SegmentInfos@56a8f5e minGen=12 packetCount=1
   [junit4]   2> 295395 T249 C40 oasu.LoggingInfoStream.message [BD][qtp120925460-249]: pruneDeletes: prune 1 packets; 0 packets remain
   [junit4]   2> 295395 T249 C40 oasu.LoggingInfoStream.message [DW][qtp120925460-249]: qtp120925460-249 finishFullFlush success=true
   [junit4]   2> 295396 T249 C40 oasu.LoggingInfoStream.message [TMP][qtp120925460-249]: findMerges: 1 segments
   [junit4]   2> 295396 T249 C40 oasu.LoggingInfoStream.message [TMP][qtp120925460-249]:   seg=_1(4.7):C1000 size=0.025 MB [floored]
   [junit4]   2> 295397 T249 C40 oasu.LoggingInfoStream.message [TMP][qtp120925460-249]:   allowedSegmentCount=1 vs count=1 (eligible count=1) tooBigCount=0
   [junit4]   2> 295397 T249 C40 oasu.LoggingInfoStream.message [CMS][qtp120925460-249]: now merge
   [junit4]   2> 295398 T249 C40 oasu.LoggingInfoStream.message [CMS][qtp120925460-249]:   index: _1(4.7):C1000
   [junit4]   2> 295398 T249 C40 oasu.LoggingInfoStream.message [CMS][qtp120925460-249]:   no more merges pending; now return
   [junit4]   2> 295398 T249 C40 oasu.LoggingInfoStream.message [IW][qtp120925460-249]: startCommit(): start
   [junit4]   2> 295399 T249 C40 oasu.LoggingInfoStream.message [IW][qtp120925460-249]: startCommit index=_1(4.7):C1000 changeCount=8
   [junit4]   2> 295416 T249 C40 oasu.LoggingInfoStream.message [IW][qtp120925460-249]: done all syncs: [_1_Lucene41_0.pos, _1_Lucene41_0.tip, _1_Lucene41_0.tim, _1.si, _1.fdx, _1_Lucene41_0.doc, _1.fdt, _1.nvd, _1.nvm, _1.fnm]
   [junit4]   2> 295417 T249 C40 oasu.LoggingInfoStream.message [IW][qtp120925460-249]: commit: pendingCommit != null
   [junit4]   2> 295417 T249 C40 oasu.LoggingInfoStream.message [IW][qtp120925460-249]: commit: wrote segments file "segments_3"
   [junit4]   2> 295417 T249 C40 oasu.LoggingInfoStream.message [IFD][qtp120925460-249]: now checkpoint "_1(4.7):C1000" [1 segments ; isCommit = true]
   [junit4]   2> 295418 T249 C40 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@24f21ab5 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-solrj/test/J0/solrtest-TestBatchUpdate-1392430472279/index),segFN=segments_2,generation=2}
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@24f21ab5 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-solrj/test/J0/solrtest-TestBatchUpdate-1392430472279/index),segFN=segments_3,generation=3}
   [junit4]   2> 295418 T249 C40 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
   [junit4]   2> 295418 T249 C40 oasu.LoggingInfoStream.message [IFD][qtp120925460-249]: deleteCommits: now decRef commit "segments_2"
   [junit4]   2> 295419 T249 C40 oasu.LoggingInfoStream.message [IFD][qtp120925460-249]: delete "segments_2"
   [junit4]   2> 295419 T249 C40 oasu.LoggingInfoStream.message [IFD][qtp120925460-249]: 1 msec to checkpoint
   [junit4]   2> 295419 T249 C40 oasu.LoggingInfoStream.message [IW][qtp120925460-249]: commit: done
   [junit4]   2> 295420 T249 C40 oasu.LoggingInfoStream.message [DW][qtp120925460-249]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 295420 T249 C40 oasu.LoggingInfoStream.message [IW][qtp120925460-249]: nrtIsCurrent: infoVersion matches: false; DW changes: false; BD changes: false
   [junit4]   2> 295420 T249 C40 oasu.LoggingInfoStream.message [IW][qtp120925460-249]: flush at getReader
   [junit4]   2> 295421 T249 C40 oasu.LoggingInfoStream.message [DW][qtp120925460-249]: qtp120925460-249 startFullFlush
   [junit4]   2> 295421 T249 C40 oasu.LoggingInfoStream.message [DW][qtp120925460-249]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 295421 T249 C40 oasu.LoggingInfoStream.message [IW][qtp120925460-249]: apply all deletes during flush
   [junit4]   2> 295421 T249 C40 oasu.LoggingInfoStream.message [BD][qtp120925460-249]: applyDeletes: no deletes; skipping
   [junit4]   2> 295422 T249 C40 oasu.LoggingInfoStream.message [BD][qtp120925460-249]: prune sis=org.apache.lucene.index.SegmentInfos@56a8f5e minGen=12 packetCount=0
   [junit4]   2> 295424 T249 C40 oasu.LoggingInfoStream.message [IW][qtp120925460-249]: return reader version=7 reader=StandardDirectoryReader(segments_3:7:nrt _1(4.7):C1000)
   [junit4]   2> 295424 T249 C40 oasu.LoggingInfoStream.message [DW][qtp120925460-249]: qtp120925460-249 finishFullFlush success=true
   [junit4]   2> 295424 T249 C40 oasu.LoggingInfoStream.message [IW][qtp120925460-249]: getReader took 4 msec
   [junit4]   2> 295425 T249 C40 oass.SolrIndexSearcher.<init> Opening Searcher@29a198c9[collection1] main
   [junit4]   2> 295426 T249 C40 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 295427 T252 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@29a198c9[collection1] main{StandardDirectoryReader(segments_3:7:nrt _1(4.7):C1000)}
   [junit4]   2> 295427 T252 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
   [junit4]   2> 295427 T252 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@29a198c9[collection1] main{StandardDirectoryReader(segments_3:7:nrt _1(4.7):C1000)}
   [junit4]   2> 295427 T252 oasu.LoggingInfoStream.message [IFD][searcherExecutor-114-thread-1]: delete "_0.fdx"
   [junit4]   2> 295428 T252 oasu.LoggingInfoStream.message [IFD][searcherExecutor-114-thread-1]: delete "_0_Lucene41_0.doc"
   [junit4]   2> 295428 T252 oasu.LoggingInfoStream.message [IFD][searcherExecutor-114-thread-1]: delete "_0.si"
   [junit4]   2> 295428 T252 oasu.LoggingInfoStream.message [IFD][searcherExecutor-114-thread-1]: delete "_0_Lucene41_0.tip"
   [junit4]   2> 295428 T252 oasu.LoggingInfoStream.message [IFD][searcherExecutor-114-thread-1]: delete "_0.fdt"
   [junit4]   2> 295428 T252 oasu.LoggingInfoStream.message [IFD][searcherExecutor-114-thread-1]: delete "_0_Lucene41_0.tim"
   [junit4]   2> 295429 T252 oasu.LoggingInfoStream.message [IFD][searcherExecutor-114-thread-1]: delete "_0_Lucene41_0.pos"
   [junit4]   2> 295429 T252 oasu.LoggingInfoStream.message [IFD][searcherExecutor-114-thread-1]: delete "_0.nvm"
   [junit4]   2> 295429 T252 oasu.LoggingInfoStream.message [IFD][searcherExecutor-114-thread-1]: delete "_0.fnm"
   [junit4]   2> 295429 T252 oasu.LoggingInfoStream.message [IFD][searcherExecutor-114-thread-1]: delete "_0.nvd"
   [junit4]   2> 295430 T249 C40 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&commit=true&waitSearcher=true&softCommit=false&wt=javabin} {commit=} 0 69
   [junit4]   2> 295436 T248 C40 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={version=2&wt=javabin&q=*:*} hits=1000 status=0 QTime=1 
   [junit4]   2> 295439 T241 oas.SolrTestCaseJ4.tearDown ###Ending testWithBinaryBean
   [junit4]   2> 295449 T241 oas.SolrTestCaseJ4.setUp ###Starting testWithBinary
   [junit4]   2> 295463 T250 C40 oasu.LoggingInfoStream.message [DW][qtp120925460-250]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 295464 T250 C40 oasu.LoggingInfoStream.message [IW][qtp120925460-250]: nrtIsCurrent: infoVersion matches: true; DW changes: true; BD changes: false
   [junit4]   2> 295464 T250 C40 oasu.LoggingInfoStream.message [DW][qtp120925460-250]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 295464 T250 C40 oasu.LoggingInfoStream.message [IW][qtp120925460-250]: flush at getReader
   [junit4]   2> 295465 T250 C40 oasu.LoggingInfoStream.message [DW][qtp120925460-250]: qtp120925460-250 startFullFlush
   [junit4]   2> 295465 T250 C40 oasu.LoggingInfoStream.message [DW][qtp120925460-250]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 295465 T250 C40 oasu.LoggingInfoStream.message [DW][qtp120925460-250]: qtp120925460-250: flush naked frozen global deletes
   [junit4]   2> 295466 T250 C40 oasu.LoggingInfoStream.message [BD][qtp120925460-250]: push deletes  1 deleted queries bytesUsed=32 delGen=14 packetCount=1 totBytesUsed=32
   [junit4]   2> 295466 T250 C40 oasu.LoggingInfoStream.message [DW][qtp120925460-250]: flush: push buffered updates:  1 deleted queries bytesUsed=32
   [junit4]   2> 295466 T250 C40 oasu.LoggingInfoStream.message [IW][qtp120925460-250]: apply all deletes during flush
   [junit4]   2> 295467 T250 C40 oasu.LoggingInfoStream.message [BD][qtp120925460-250]: applyDeletes: infos=[_1(4.7):C1000] packetCount=1
   [junit4]   2> 295489 T250 C40 oasu.LoggingInfoStream.message [BD][qtp120925460-250]: seg=_1(4.7):C1000 segGen=12 coalesced deletes=[CoalescedUpdates(termSets=1,queries=1,numericUpdates=0)] newDelCount=1000 100% deleted
   [junit4]   2> 295490 T250 C40 oasu.LoggingInfoStream.message [BD][qtp120925460-250]: applyDeletes took 23 msec
   [junit4]   2> 295490 T250 C40 oasu.LoggingInfoStream.message [IFD][qtp120925460-250]: now checkpoint "_1(4.7):C1000/1000" [1 segments ; isCommit = false]
   [junit4]   2> 295491 T250 C40 oasu.LoggingInfoStream.message [IFD][qtp120925460-250]: 0 msec to checkpoint
   [junit4]   2> 295491 T250 C40 oasu.LoggingInfoStream.message [IW][qtp120925460-250]: drop 100% deleted segments: _1(4.7):C1000/1000
   [junit4]   2> 295491 T250 C40 oasu.LoggingInfoStream.message [IFD][qtp120925460-250]: now checkpoint "" [0 segments ; isCommit = false]
   [junit4]   2> 295492 T250 C40 oasu.LoggingInfoStream.message [IFD][qtp120925460-250]: 0 msec to checkpoint
   [junit4]   2> 295492 T250 C40 oasu.LoggingInfoStream.message [BD][qtp120925460-250]: prune sis=org.apache.lucene.index.SegmentInfos@56a8f5e minGen=9223372036854775807 packetCount=1
   [junit4]   2> 295492 T250 C40 oasu.LoggingInfoStream.message [BD][qtp120925460-250]: pruneDeletes: prune 1 packets; 0 packets remain
   [junit4]   2> 295493 T250 C40 oasu.LoggingInfoStream.message [IW][qtp120925460-250]: return reader version=9 reader=StandardDirectoryReader(segments_3:9:nrt)
   [junit4]   2> 295494 T250 C40 oasu.LoggingInfoStream.message [DW][qtp120925460-250]: qtp120925460-250 finishFullFlush success=true
   [junit4]   2> 295494 T250 C40 oasu.LoggingInfoStream.message [IW][qtp120925460-250]: getReader took 30 msec
   [junit4]   2> 295494 T250 C40 oass.SolrIndexSearcher.<init> Opening Searcher@47ddd39f[collection1] realtime
   [junit4]   2> 295495 T250 C40 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {deleteByQuery=*:* (-1460069388831948800)} 0 33
   [junit4]   2> 295896 T247 C40 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[1 (1460069388884377600), 2 (1460069388887523328), 3 (1460069388888571904), 4 (1460069388888571905), 5 (1460069388888571906), 6 (1460069388888571907), 7 (1460069388889620480), 8 (1460069388889620481), 9 (1460069388890669056), 10 (1460069388890669057), ... (1000 adds)]} 0 384
   [junit4]   2> 295906 T247 C40 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 295906 T247 C40 oasu.LoggingInfoStream.message [IW][qtp120925460-247]: commit: start
   [junit4]   2> 295907 T247 C40 oasu.LoggingInfoStream.message [IW][qtp120925460-247]: commit: enter lock
   [junit4]   2> 295907 T247 C40 oasu.LoggingInfoStream.message [IW][qtp120925460-247]: commit: now prepare
   [junit4]   2> 295907 T247 C40 oasu.LoggingInfoStream.message [IW][qtp120925460-247]: prepareCommit: flush
   [junit4]   2> 295907 T247 C40 oasu.LoggingInfoStream.message [IW][qtp120925460-247]:   index before flush 
   [junit4]   2> 295907 T247 C40 oasu.LoggingInfoStream.message [DW][qtp120925460-247]: qtp120925460-247 startFullFlush
   [junit4]   2> 295908 T247 C40 oasu.LoggingInfoStream.message [DW][qtp120925460-247]: anyChanges? numDocsInRam=1000 deletes=true hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 295909 T247 C40 oasu.LoggingInfoStream.message [DWFC][qtp120925460-247]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0 999 deleted terms (unique count=999) bytesUsed=166728, segment=_2, aborting=false, numDocsInRAM=1000, deleteQueue=DWDQ: [ generation: 8 ]]
   [junit4]   2> 295919 T247 C40 oasu.LoggingInfoStream.message [DWPT][qtp120925460-247]: flush postings as segment _2 numDocs=1000
   [junit4]   2> 295935 T247 C40 oasu.LoggingInfoStream.message [DWPT][qtp120925460-247]: new segment has 0 deleted docs
   [junit4]   2> 295935 T247 C40 oasu.LoggingInfoStream.message [DWPT][qtp120925460-247]: new segment has no vectors; norms; no docValues; prox; freqs
   [junit4]   2> 295935 T247 C40 oasu.LoggingInfoStream.message [DWPT][qtp120925460-247]: flushedFiles=[_2_Lucene41_0.pos, _2.nvm, _2.nvd, _2_Lucene41_0.doc, _2.fnm, _2_Lucene41_0.tim, _2.fdx, _2_Lucene41_0.tip, _2.fdt]
   [junit4]   2> 295936 T247 C40 oasu.LoggingInfoStream.message [DWPT][qtp120925460-247]: flushed codec=Lucene46
   [junit4]   2> 295936 T247 C40 oasu.LoggingInfoStream.message [DWPT][qtp120925460-247]: flushed: segment=_2 ramUsed=0.286 MB newFlushedSize(includes docstores)=0.026 MB docs/MB=38,885.115
   [junit4]   2> 295936 T247 C40 oasu.LoggingInfoStream.message [DW][qtp120925460-247]: publishFlushedSegment seg-private updates=null
   [junit4]   2> 295937 T247 C40 oasu.LoggingInfoStream.message [IW][qtp120925460-247]: publishFlushedSegment
   [junit4]   2> 295937 T247 C40 oasu.LoggingInfoStream.message [BD][qtp120925460-247]: push deletes  1000 deleted terms (unique count=1000) bytesUsed=3072 delGen=16 packetCount=1 totBytesUsed=3072
   [junit4]   2> 295937 T247 C40 oasu.LoggingInfoStream.message [IW][qtp120925460-247]: publish sets newSegment delGen=17 seg=_2(4.7):C1000
   [junit4]   2> 295937 T247 C40 oasu.LoggingInfoStream.message [IFD][qtp120925460-247]: now checkpoint "_2(4.7):C1000" [1 segments ; isCommit = false]
   [junit4]   2> 295938 T247 C40 oasu.LoggingInfoStream.message [IFD][qtp120925460-247]: 0 msec to checkpoint
   [junit4]   2> 295938 T247 C40 oasu.LoggingInfoStream.message [IW][qtp120925460-247]: apply all deletes during flush
   [junit4]   2> 295939 T247 C40 oasu.LoggingInfoStream.message [BD][qtp120925460-247]: applyDeletes: infos=[_2(4.7):C1000] packetCount=1
   [junit4]   2> 295939 T247 C40 oasu.LoggingInfoStream.message [BD][qtp120925460-247]: applyDeletes took 0 msec
   [junit4]   2> 295939 T247 C40 oasu.LoggingInfoStream.message [BD][qtp120925460-247]: prune sis=org.apache.lucene.index.SegmentInfos@56a8f5e minGen=18 packetCount=1
   [junit4]   2> 295939 T247 C40 oasu.LoggingInfoStream.message [BD][qtp120925460-247]: pruneDeletes: prune 1 packets; 0 packets remain
   [junit4]   2> 295940 T247 C40 oasu.LoggingInfoStream.message [DW][qtp120925460-247]: qtp120925460-247 finishFullFlush success=true
   [junit4]   2> 295940 T247 C40 oasu.LoggingInfoStream.message [TMP][qtp120925460-247]: findMerges: 1 segments
   [junit4]   2> 295941 T247 C40 oasu.LoggingInfoStream.message [TMP][qtp120925460-247]:   seg=_2(4.7):C1000 size=0.025 MB [floored]
   [junit4]   2> 295941 T247 C40 oasu.LoggingInfoStream.message [TMP][qtp120925460-247]:   allowedSegmentCount=1 vs count=1 (eligible count=1) tooBigCount=0
   [junit4]   2> 295942 T247 C40 oasu.LoggingInfoStream.message [CMS][qtp120925460-247]: now merge
   [junit4]   2> 295942 T247 C40 oasu.LoggingInfoStream.message [CMS][qtp120925460-247]:   index: _2(4.7):C1000
   [junit4]   2> 295942 T247 C40 oasu.LoggingInfoStream.message [CMS][qtp120925460-247]:   no more merges pending; now return
   [junit4]   2> 295942 T247 C40 oasu.LoggingInfoStream.message [IW][qtp120925460-247]: startCommit(): start
   [junit4]   2> 295943 T247 C40 oasu.LoggingInfoStream.message [IW][qtp120925460-247]: startCommit index=_2(4.7):C1000 changeCount=13
   [junit4]   2> 295943 T247 C40 oasu.LoggingInfoStream.message [IW][qtp120925460-247]: done all syncs: [_2_Lucene41_0.pos, _2.nvm, _2.nvd, _2_Lucene41_0.doc, _2_Lucene41_0.tim, _2.fnm, _2.fdx, _2_Lucene41_0.tip, _2.si, _2.fdt]
   [junit4]   2> 295943 T247 C40 oasu.LoggingInfoStream.message [IW][qtp120925460-247]: commit: pendingCommit != null
   [junit4]   2> 295944 T247 C40 oasu.LoggingInfoStream.message [IW][qtp120925460-247]: commit: wrote segments file "segments_4"
   [junit4]   2> 295945 T247 C40 oasu.LoggingInfoStream.message [IFD][qtp120925460-247]: now checkpoint "_2(4.7):C1000" [1 segments ; isCommit = true]
   [junit4]   2> 295945 T247 C40 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@24f21ab5 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-solrj/test/J0/solrtest-TestBatchUpdate-1392430472279/index),segFN=segments_3,generation=3}
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@24f21ab5 lockFactory=NativeFSLockFactory@/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-solrj/test/J0/solrtest-TestBatchUpdate-1392430472279/index),segFN=segments_4,generation=4}
   [junit4]   2> 295946 T247 C40 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 4
   [junit4]   2> 295947 T247 C40 oasu.LoggingInfoStream.message [IFD][qtp120925460-247]: deleteCommits: now decRef commit "segments_3"
   [junit4]   2> 295947 T247 C40 oasu.LoggingInfoStream.message [IFD][qtp120925460-247]: delete "segments_3"
   [junit4]   2> 295948 T247 C40 oasu.LoggingInfoStream.message [IFD][qtp120925460-247]: 2 msec to checkpoint
   [junit4]   2> 295948 T247 C40 oasu.LoggingInfoStream.message [IW][qtp120925460-247]: commit: done
   [junit4]   2> 295948 T247 C40 oasu.LoggingInfoStream.message [DW][qtp120925460-247]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 295948 T247 C40 oasu.LoggingInfoStream.message [IW][qtp120925460-247]: nrtIsCurrent: infoVersion matches: false; DW changes: false; BD changes: false
   [junit4]   2> 295949 T247 C40 oasu.LoggingInfoStream.message [IW][qtp120925460-247]: flush at getReader
   [junit4]   2> 295949 T247 C40 oasu.LoggingInfoStream.message [DW][qtp120925460-247]: qtp120925460-247 startFullFlush
   [junit4]   2> 295949 T247 C40 oasu.LoggingInfoStream.message [DW][qtp120925460-247]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 295950 T247 C40 oasu.LoggingInfoStream.message [IW][qtp120925460-247]: apply all deletes during flush
   [junit4]   2> 295950 T247 C40 oasu.LoggingInfoStream.message [BD][qtp120925460-247]: applyDeletes: no deletes; skipping
   [junit4]   2> 295950 T247 C40 oasu.LoggingInfoStream.message [BD][qtp120925460-247]: prune sis=org.apache.lucene.index.SegmentInfos@56a8f5e minGen=18 packetCount=0
   [junit4]   2> 295952 T247 C40 oasu.LoggingInfoStream.message [IW][qtp120925460-247]: return reader version=11 reader=StandardDirectoryReader(segments_4:11:nrt _2(4.7):C1000)
   [junit4]   2> 295952 T247 C40 oasu.LoggingInfoStream.message [DW][qtp120925460-247]: qtp120925460-247 finishFullFlush success=true
   [junit4]   2> 295952 T247 C40 oasu.LoggingInfoStream.message [IW][qtp120925460-247]: getReader took 3 msec
   [junit4]   2> 295953 T247 C40 oass.SolrIndexSearcher.<init> Opening Searcher@594482c8[collection1] main
   [junit4]   2> 295953 T252 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@594482c8[collection1] main{StandardDirectoryReader(segments_4:11:nrt _2(4.7):C1000)}
   [junit4]   2> 295953 T252 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
   [junit4]   2> 295954 T252 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@594482c8[collection1] main{StandardDirectoryReader(segments_4:11:nrt _2(4.7):C1000)}
   [junit4]   2> 295955 T252 oasu.LoggingInfoStream.message [IFD][searcherExecutor-114-thread-1]: delete "_1_Lucene41_0.pos"
   [junit4]   2> 295955 T252 oasu.LoggingInfoStream.message [IFD][searcherExecutor-114-thread-1]: delete "_1_Lucene41_0.tip"
   [junit4]   2> 295956 T247 C40 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 295956 T252 oasu.LoggingInfoStream.message [IFD][searcherExecutor-114-thread-1]: delete "_1_Lucene41_0.tim"
   [junit4]   2> 295957 T252 oasu.LoggingInfoStream.message [IFD][searcherExecutor-114-thread-1]: delete "_1.si"
   [junit4]   2> 295957 T252 oasu.LoggingInfoStream.message [IFD][searcherExecutor-114-thread-1]: delete "_1.fdx"
   [junit4]   2> 295957 T252 oasu.LoggingInfoStream.message [IFD][searcherExecutor-114-thread-1]: delete "_1_Lucene41_0.doc"
   [junit4]   2> 295957 T252 oasu.LoggingInfoStream.message [IFD][searcherExecutor-114-thread-1]: delete "_1.fdt"
   [junit4]   2> 295957 T252 oasu.LoggingInfoStream.message [IFD][searcherExecutor-114-thread-1]: delete "_1.nvd"
   [junit4]   2> 295957 T252 oasu.LoggingInfoStream.message [IFD][searcherExecutor-114-thread-1]: delete "_1.nvm"
   [junit4]   2> 295958 T252 oasu.LoggingInfoStream.message [IFD][searcherExecutor-114-thread-1]: delete "_1.fnm"
   [junit4]   2> 295958 T247 C40 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&commit=true&waitSearcher=true&softCommit=false&wt=javabin} {commit=} 0 53
   [junit4]   2> 295974 T247 C40 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={version=2&wt=javabin&q=*:*} hits=1000 status=0 QTime=1 
   [junit4]   2> 295981 T241 oas.SolrTestCaseJ4.tearDown ###Ending testWithBinary
   [junit4]   2> 295997 T241 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1306917113
   [junit4]   2> 295998 T241 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@616b99f1
   [junit4]   2> 296006 T241 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=4,autocommit maxTime=15000ms,autocommits=1,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=3000,cumulative_deletesById=0,cumulative_deletesByQuery=3,cumulative_errors=0,transaction_logs_total_size=58960,transaction_logs_total_number=1}
   [junit4]   2> 296007 T241 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
   [junit4]   2> 296009 T241 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
   [junit4]   2> 296010 T241 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
   [junit4]   2> 296010 T241 C40 oasu.LoggingInfoStream.message [IW][SUITE-TestBatchUpdate-seed#[C049C687D302B689]-worker]: now flush at close waitForMerges=true
   [junit4]   2> 296011 T241 C40 oasu.LoggingInfoStream.message [IW][SUITE-TestBatchUpdate-seed#[C049C687D302B689]-worker]:   start flush: applyAllDeletes=true
   [junit4]   2> 296011 T241 C40 oasu.LoggingInfoStream.message [IW][SUITE-TestBatchUpdate-seed#[C049C687D302B689]-worker]:   index before flush _2(4.7):C1000
   [junit4]   2> 296011 T241 C40 oasu.LoggingInfoStream.message [DW][SUITE-TestBatchUpdate-seed#[C049C687D302B689]-worker]: SUITE-TestBatchUpdate-seed#[C049C687D302B689]-worker startFullFlush
   [junit4]   2> 296012 T241 C40 oasu.LoggingInfoStream.message [DW][SUITE-TestBatchUpdate-seed#[C049C687D302B689]-worker]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 296012 T241 C40 oasu.LoggingInfoStream.message [DW][SUITE-TestBatchUpdate-seed#[C049C687D302B689]-worker]: SUITE-TestBatchUpdate-seed#[C049C687D302B689]-worker finishFullFlush success=true
   [junit4]   2> 296014 T241 C40 oasu.LoggingInfoStream.message [IW][SUITE-TestBatchUpdate-seed#[C049C687D302B689]-worker]: apply all deletes during flush
   [junit4]   2> 296015 T241 C40 oasu.LoggingInfoStream.message [BD][SUITE-TestBatchUpdate-seed#[C049C687D302B689]-worker]: applyDeletes: no deletes; skipping
   [junit4]   2> 296019 T241 C40 oasu.LoggingInfoStream.message [BD][SUITE-TestBatchUpdate-seed#[C049C687D302B689]-worker]: prune sis=org.apache.lucene.index.SegmentInfos@56a8f5e minGen=18 packetCount=0
   [junit4]   2> 296021 T241 C40 oasu.LoggingInfoStream.message [CMS][SUITE-TestBatchUpdate-seed#[C049C687D302B689]-worker]: now merge
   [junit4]   2> 296021 T241 C40 oasu.LoggingInfoStream.message [CMS][SUITE-TestBatchUpdate-seed#[C049C687D302B689]-worker]:   index: _2(4.7):C1000
   [junit4]   2> 296021 T241 C40 oasu.LoggingInfoStream.message [CMS][SUITE-TestBatchUpdate-seed#[C049C687D302B689]-worker]:   no more merges pending; now return
   [junit4]   2> 296023 T241 C40 oasu.LoggingInfoStream.message [IW][SUITE-TestBatchUpdate-seed#[C049C687D302B689]-worker]: waitForMerges
   [junit4]   2> 296023 T241 C40 oasu.LoggingInfoStream.message [IW][SUITE-TestBatchUpdate-seed#[C049C687D302B689]-worker]: waitForMerges done
   [junit4]   2> 296024 T241 C40 oasu.LoggingInfoStream.message [IW][SUITE-TestBatchUpdate-seed#[C049C687D302B689]-worker]: now call final commit()
   [junit4]   2> 296024 T241 C40 oasu.LoggingInfoStream.message [IW][SUITE-TestBatchUpdate-seed#[C049C687D302B689]-worker]: commit: start
   [junit4]   2> 296024 T241 C40 oasu.LoggingInfoStream.message [IW][SUITE-TestBatchUpdate-seed#[C049C687D302B689]-worker]: commit: enter lock
   [junit4]   2> 296025 T241 C40 oasu.LoggingInfoStream.message [IW][SUITE-TestBatchUpdate-seed#[C049C687D302B689]-worker]: commit: now prepare
   [junit4]   2> 296025 T241 C40 oasu.LoggingInfoStream.message [IW][SUITE-TestBatchUpdate-seed#[C049C687D302B689]-worker]: prepareCommit: flush
   [junit4]   2> 296025 T241 C40 oasu.LoggingInfoStream.message [IW][SUITE-TestBatchUpdate-seed#[C049C687D302B689]-worker]:   index before flush _2(4.7):C1000
   [junit4]   2> 296025 T241 C40 oasu.LoggingInfoStream.message [DW][SUITE-TestBatchUpdate-seed#[C049C687D302B689]-worker]: SUITE-TestBatchUpdate-seed#[C049C687D302B689]-worker startFullFlush
   [junit4]   2> 296026 T241 C40 oasu.LoggingInfoStream.message [DW][SUITE-TestBatchUpdate-seed#[C049C687D302B689]-worker]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 296029 T241 C40 oasu.LoggingInfoStream.message [IW][SUITE-TestBatchUpdate-seed#[C049C687D302B689]-worker]: apply all deletes during flush
   [junit4]   2> 296034 T241 C40 oasu.LoggingInfoStream.message [BD][SUITE-TestBatchUpdate-seed#[C049C687D302B689]-worker]: applyDeletes: no deletes; skipping
   [junit4]   2> 296034 T241 C40 oasu.LoggingInfoStream.message [BD][SUITE-TestBatchUpdate-seed#[C049C687D302B689]-worker]: prune sis=org.apache.lucene.index.SegmentInfos@56a8f5e minGen=18 packetCount=0
   [junit4]   2> 296035 T241 C40 oasu.LoggingInfoStream.message [DW][SUITE-TestBatchUpdate-seed#[C049C687D302B689]-worker]: SUITE-TestBatchUpdate-seed#[C049C687D302B689]-worker finishFullFlush success=true
   [junit4]   2> 296035 T241 C40 oasu.LoggingInfoStream.message [IW][SUITE-TestBatchUpdate-seed#[C049C687D302B689]-worker]: startCommit(): start
   [junit4]   2> 296035 T241 C40 oasu.LoggingInfoStream.message [IW][SUITE-TestBatchUpdate-seed#[C049C687D302B689]-worker]:   skip startCommit(): no changes pending
   [junit4]   2> 296035 T241 C40 oasu.LoggingInfoStream.message [IW][SUITE-TestBatchUpdate-seed#[C049C687D302B689]-worker]: commit: pendingCommit == null; skip
   [junit4]   2> 296036 T241 C40 oasu.LoggingInfoStream.message [IW][SUITE-TestBatchUpdate-seed#[C049C687D302B689]-worker]: commit: done
   [junit4]   2> 296036 T241 C40 oasu.LoggingInfoStream.message [IW][SUITE-TestBatchUpdate-seed#[C049C687D302B689]-worker]: at close: _2(4.7):C1000
   [junit4]   2> 296038 T241 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
   [junit4]   2> 296039 T241 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
   [junit4]   2> 296039 T241 oasc.CachingDirectoryFactory.closeCacheValue looking to close /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-solrj/test/J0/solrtest-TestBatchUpdate-1392430472279 [CachedDir<<refCount=0;path=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-solrj/test/J0/solrtest-TestBatchUpdate-1392430472279;done=false>>]
   [junit4]   2> 296039 T241 oasc.CachingDirectoryFactory.close Closing directory: /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-solrj/test/J0/solrtest-TestBatchUpdate-1392430472279
   [junit4]   2> 296040 T241 oasc.CachingDirectoryFactory.closeCacheValue looking to close /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-solrj/test/J0/solrtest-TestBatchUpdate-1392430472279/index [CachedDir<<refCount=0;path=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-solrj/test/J0/solrtest-TestBatchUpdate-1392430472279/index;done=false>>]
   [junit4]   2> 296040 T241 oasc.CachingDirectoryFactory.close Closing directory: /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-solrj/test/J0/solrtest-TestBatchUpdate-1392430472279/index
   [junit4]   2> 296040 T241 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
   [junit4]   2> 296094 T241 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> NOTE: test params are: codec=Lucene42, sim=RandomSimilarityProvider(queryNorm=false,coord=no): {}, locale=es_NI, timezone=Pacific/Kosrae
   [junit4]   2> NOTE: Mac OS X 10.8.5 x86_64/Oracle Corporation 1.7.0_51 (64-bit)/cpus=2,threads=1,free=53059304,total=167772160
   [junit4]   2> NOTE: All tests run in this JVM: [TestLBHttpSolrServer, SolrExampleStreamingTest, NoOpResponseParserTest, SolrDocumentTest, LargeVolumeJettyTest, SolrExceptionTest, TestBatchUpdate]
   [junit4] Completed in 204.72s, 3 tests, 1 error <<< FAILURES!

[...truncated 132 lines...]
BUILD FAILED
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:459: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:439: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:39: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/extra-targets.xml:37: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build.xml:202: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/common-build.xml:491: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/common-build.xml:1308: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/common-build.xml:941: There were test failures: 48 suites, 280 tests, 1 error

Total time: 99 minutes 55 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.7.0 -XX:+UseCompressedOops -XX:+UseG1GC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure



[JENKINS] Lucene-Solr-4.x-MacOSX (64bit/jdk1.7.0) - Build # 1299 - Still Failing!

Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-MacOSX/1299/
Java: 64bit/jdk1.7.0 -XX:-UseCompressedOops -XX:+UseSerialGC

1 tests failed.
FAILED:  junit.framework.TestSuite.org.apache.solr.rest.schema.TestDynamicFieldResource

Error Message:
Clean up static fields (in @AfterClass?), your test seems to hang on to approximately 10,675,848 bytes (threshold is 10,485,760). Field reference sizes (counted individually):   - 10,674,696 bytes, protected static org.apache.solr.util.RestTestHarness org.apache.solr.util.RestTestBase.restTestHarness   - 448 bytes, private static java.util.regex.Pattern org.apache.solr.SolrTestCaseJ4.nonEscapedSingleQuotePattern   - 328 bytes, public static org.junit.rules.TestRule org.apache.solr.SolrTestCaseJ4.solrClassRules   - 312 bytes, private static java.util.regex.Pattern org.apache.solr.SolrTestCaseJ4.escapedSingleQuotePattern   - 224 bytes, protected static java.lang.String org.apache.solr.SolrTestCaseJ4.testSolrHome   - 144 bytes, private static java.lang.String org.apache.solr.SolrTestCaseJ4.factoryProp   - 80 bytes, private static java.lang.String org.apache.solr.SolrTestCaseJ4.coreName   - 72 bytes, public static java.lang.String org.apache.solr.SolrJettyTestBase.context

Stack Trace:
junit.framework.AssertionFailedError: Clean up static fields (in @AfterClass?), your test seems to hang on to approximately 10,675,848 bytes (threshold is 10,485,760). Field reference sizes (counted individually):
  - 10,674,696 bytes, protected static org.apache.solr.util.RestTestHarness org.apache.solr.util.RestTestBase.restTestHarness
  - 448 bytes, private static java.util.regex.Pattern org.apache.solr.SolrTestCaseJ4.nonEscapedSingleQuotePattern
  - 328 bytes, public static org.junit.rules.TestRule org.apache.solr.SolrTestCaseJ4.solrClassRules
  - 312 bytes, private static java.util.regex.Pattern org.apache.solr.SolrTestCaseJ4.escapedSingleQuotePattern
  - 224 bytes, protected static java.lang.String org.apache.solr.SolrTestCaseJ4.testSolrHome
  - 144 bytes, private static java.lang.String org.apache.solr.SolrTestCaseJ4.factoryProp
  - 80 bytes, private static java.lang.String org.apache.solr.SolrTestCaseJ4.coreName
  - 72 bytes, public static java.lang.String org.apache.solr.SolrJettyTestBase.context
	at __randomizedtesting.SeedInfo.seed([16F9F4B730368C62]:0)
	at com.carrotsearch.randomizedtesting.rules.StaticFieldsInvariantRule$1.afterAlways(StaticFieldsInvariantRule.java:127)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:43)
	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)




Build Log:
[...truncated 20221 lines...]
   [junit4] Suite: org.apache.solr.rest.schema.TestDynamicFieldResource
   [junit4]   2> 3277707 T10352 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (false) and clientAuth (false)
   [junit4]   2> 3277709 T10352 oas.SolrTestCaseJ4.initCore ####initCore
   [junit4]   2> Creating dataDir: /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./solrtest-TestDynamicFieldResource-1392485641877
   [junit4]   2> 3277710 T10352 oas.SolrTestCaseJ4.initCore ####initCore end
   [junit4]   2> 3277710 T10352 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 3277720 T10352 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:62265
   [junit4]   2> 3277720 T10352 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 3277721 T10352 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 3277722 T10352 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr
   [junit4]   2> 3277722 T10352 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/'
   [junit4]   2> 3277752 T10352 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/solr.xml
   [junit4]   2> 3277834 T10352 oasc.CoreContainer.<init> New CoreContainer 274590151
   [junit4]   2> 3277835 T10352 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/]
   [junit4]   2> 3277837 T10352 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 3277837 T10352 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 3277837 T10352 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 3277838 T10352 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 3277838 T10352 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 3277839 T10352 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 3277840 T10352 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 3277840 T10352 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 3277841 T10352 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 3277851 T10352 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 3277851 T10352 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 3277852 T10352 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 3277858 T10362 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1
   [junit4]   2> 3277859 T10362 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/'
   [junit4]   2> 3277860 T10362 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/lib/classes/' to classloader
   [junit4]   2> 3277860 T10362 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/lib/README' to classloader
   [junit4]   2> 3277944 T10362 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
   [junit4]   2> 3278019 T10362 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 3278021 T10362 oass.IndexSchema.readSchema Reading Solr Schema from schema-rest.xml
   [junit4]   2> 3278029 T10362 oass.IndexSchema.readSchema [collection1] Schema name=test-rest
   [junit4]   2> 3278588 T10362 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 3278590 T10362 oass.IndexSchema.readSchema query parser default operator is OR
   [junit4]   2> 3278592 T10362 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 3278594 T10362 oass.IndexSchema.readSchema WARN Field title is not multivalued and destination for multiple copyFields (3)
   [junit4]   2> 3278606 T10362 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 3278607 T10362 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/, dataDir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/solrtest-TestDynamicFieldResource-1392485641877/
   [junit4]   2> 3278607 T10362 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@288cafb2
   [junit4]   2> 3278609 T10362 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/solrtest-TestDynamicFieldResource-1392485641877
   [junit4]   2> 3278610 T10362 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/solrtest-TestDynamicFieldResource-1392485641877/index/
   [junit4]   2> 3278610 T10362 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/solrtest-TestDynamicFieldResource-1392485641877/index' doesn't exist. Creating new index...
   [junit4]   2> 3278611 T10362 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/solrtest-TestDynamicFieldResource-1392485641877/index
   [junit4]   2> 3278612 T10362 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1058440377, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
   [junit4]   2> 3278612 T10362 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@149010b7 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5bb3ad64)),segFN=segments_1,generation=1}
   [junit4]   2> 3278613 T10362 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 3278613 T10362 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
   [junit4]   2> 3278617 T10362 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 3278617 T10362 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 3278617 T10362 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe-allfields"
   [junit4]   2> 3278618 T10362 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
   [junit4]   2> 3278618 T10362 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 3278618 T10362 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 3278619 T10362 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "uniq-fields"
   [junit4]   2> 3278619 T10362 oasup.UniqFieldsUpdateProcessorFactory.init WARN Use of the 'fields' init param in UniqFieldsUpdateProcessorFactory is deprecated, please use 'fieldName' (or another FieldMutatingUpdateProcessorFactory selector option) instead
   [junit4]   2> 3278619 T10362 oasup.UniqFieldsUpdateProcessorFactory.init Replacing 'fields' init param with (individual) 'fieldName' params
   [junit4]   2> 3278620 T10362 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
   [junit4]   2> 3278621 T10362 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 3278622 T10362 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 3278622 T10362 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 3278622 T10362 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 3278623 T10362 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 3278623 T10362 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 3278624 T10362 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 3278624 T10362 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 3278625 T10362 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
   [junit4]   2> 3278625 T10362 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
   [junit4]   2> 3278626 T10362 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 3278626 T10362 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 3278627 T10362 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
   [junit4]   2> 3278627 T10362 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
   [junit4]   2> 3278628 T10362 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
   [junit4]   2> 3278628 T10362 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 3278629 T10362 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 3278629 T10362 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 3278630 T10362 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 3278630 T10362 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 3278631 T10362 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 3278631 T10362 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 3278632 T10362 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 3278632 T10362 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 3278633 T10362 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
   [junit4]   2> 3278633 T10362 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
   [junit4]   2> 3278643 T10362 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 3278645 T10362 oasc.SolrCore.initDeprecatedSupport WARN solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
   [junit4]   2> 3278648 T10362 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 3278648 T10362 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 3278649 T10362 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=14, maxMergeAtOnceExplicit=20, maxMergedSegmentMB=27.2724609375, floorSegmentMB=1.572265625, forceMergeDeletesPctAllowed=3.832792082314822, segmentsPerTier=25.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
   [junit4]   2> 3278650 T10362 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@149010b7 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5bb3ad64)),segFN=segments_1,generation=1}
   [junit4]   2> 3278650 T10362 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 3278650 T10362 oass.SolrIndexSearcher.<init> Opening Searcher@4122e324[collection1] main
   [junit4]   2> 3278651 T10362 oashc.SpellCheckComponent.inform Initializing spell checkers
   [junit4]   2> 3278656 T10362 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
   [junit4]   2> 3278691 T10363 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4122e324[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 3278696 T10362 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 3278697 T10352 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 3278698 T10352 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 3278698 T10352 oas.SolrJettyTestBase.createJetty Jetty Assigned Port#62265
   [junit4]   2> 3278710 T10352 oas.SolrTestCaseJ4.setUp ###Starting testGetDynamicField
   [junit4]   2> ASYNC  NEW_CORE C5026 name=collection1 org.apache.solr.core.SolrCore@1aaa5cf0
   [junit4]   2> 3278719 T10358 C5026 oejsh.ContextHandler$Context.log SolrRestApi: [Restlet] Attaching application: org.apache.solr.rest.SolrRestApi@579aa779 to URI: /solr/schema
   [junit4]   2> 3278726 T10358 C5026 oasr.SolrRestApi.createInboundRoot createInboundRoot started
   [junit4]   2> 3278727 T10358 C5026 oasr.SolrRestApi.createInboundRoot createInboundRoot complete
   [junit4]   2> 3278730 T10358 C5026 oasrs.BaseSchemaResource.handlePostExecution [collection1] webapp=/solr path=/schema/dynamicfields/*_i params={wt=xml&indent=on&showDefaults=on} status=0 QTime=14 
   [junit4]   2> ASYNC  NEW_CORE C23 name=collection1 org.apache.solr.core.SolrCore@1aaa5cf0
   [junit4]   2> 1024 T10358 C23 orel.LogFilter.afterHandle 2014-02-16	05:34:02	127.0.0.1	-	127.0.0.1	62265	GET	/solr/schema/dynamicfields/*_i	indent=on&wt=xml&showDefaults=on	200	-	0	11	http://127.0.0.1:62265	Apache-HttpClient/4.3.1 (java 1.5)	-
   [junit4]   2> 3278769 T10352 oas.SolrTestCaseJ4.tearDown ###Ending testGetDynamicField
   [junit4]   2> 3278781 T10352 oas.SolrTestCaseJ4.setUp ###Starting testGetNotFoundDynamicField
   [junit4]   2> 3278791 T10359 C5026 oasrs.BaseSchemaResource.handlePostExecution [collection1] webapp=/solr path=/schema/dynamicfields/*not_in_there params={wt=xml&indent=on} msg={Dynamic field '*not_in_there' not found.} status=404 QTime=4 
   [junit4]   2> 1086 T10359 C23 orel.LogFilter.afterHandle 2014-02-16	05:34:02	127.0.0.1	-	127.0.0.1	62265	GET	/solr/schema/dynamicfields/*not_in_there	indent=on&wt=xml	404	-	0	3	http://127.0.0.1:62265	Apache-HttpClient/4.3.1 (java 1.5)	-
   [junit4]   2> 3278800 T10352 oas.SolrTestCaseJ4.tearDown ###Ending testGetNotFoundDynamicField
   [junit4]   2> 3278816 T10352 oas.SolrTestCaseJ4.setUp ###Starting testJsonGetDynamicField
   [junit4]   2> 3278821 T10360 C5026 oasrs.BaseSchemaResource.handlePostExecution [collection1] webapp=/solr path=/schema/dynamicfields/*_i params={wt=json&indent=on&showDefaults=on} status=0 QTime=2 
   [junit4]   2> 1115 T10360 C23 orel.LogFilter.afterHandle 2014-02-16	05:34:02	127.0.0.1	-	127.0.0.1	62265	GET	/solr/schema/dynamicfields/*_i	indent=on&showDefaults=on&wt=json	200	-	0	1	http://127.0.0.1:62265	Apache-HttpClient/4.3.1 (java 1.5)	-
   [junit4]   2> 3278824 T10352 oas.SolrTestCaseJ4.tearDown ###Ending testJsonGetDynamicField
   [junit4]   2> 3278840 T10352 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=274590151
   [junit4]   2> 3278842 T10352 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@1aaa5cf0
   [junit4]   2> 3278856 T10352 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0,transaction_logs_total_size=0,transaction_logs_total_number=0}
   [junit4]   2> 3278856 T10352 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
   [junit4]   2> 3278857 T10352 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
   [junit4]   2> 3278857 T10352 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
   [junit4]   2> 3278859 T10352 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
   [junit4]   2> 3278859 T10352 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
   [junit4]   2> 3278859 T10352 oasc.CachingDirectoryFactory.closeCacheValue looking to close /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/solrtest-TestDynamicFieldResource-1392485641877 [CachedDir<<refCount=0;path=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/solrtest-TestDynamicFieldResource-1392485641877;done=false>>]
   [junit4]   2> 3278860 T10352 oasc.CachingDirectoryFactory.close Closing directory: /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/solrtest-TestDynamicFieldResource-1392485641877
   [junit4]   2> 3278860 T10352 oasc.CachingDirectoryFactory.closeCacheValue looking to close /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/solrtest-TestDynamicFieldResource-1392485641877/index [CachedDir<<refCount=0;path=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/solrtest-TestDynamicFieldResource-1392485641877/index;done=false>>]
   [junit4]   2> 3278861 T10352 oasc.CachingDirectoryFactory.close Closing directory: /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/solrtest-TestDynamicFieldResource-1392485641877/index
   [junit4]   2> 3278863 T10352 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
   [junit4]   2> 3278918 T10352 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> NOTE: test params are: codec=Asserting, sim=RandomSimilarityProvider(queryNorm=true,coord=no): {}, locale=sl_SI, timezone=Pacific/Funafuti
   [junit4]   2> NOTE: Mac OS X 10.8.5 x86_64/Oracle Corporation 1.7.0_51 (64-bit)/cpus=2,threads=1,free=177949976,total=367706112
   [junit4]   2> NOTE: All tests run in this JVM: [TestXIncludeConfig, TestClassNameShortening, SyncSliceTest, XmlUpdateRequestHandlerTest, MultiTermTest, TestNumberUtils, BadCopyFieldTest, TestSolrQueryParserDefaultOperatorResource, TestRecoveryHdfs, BadComponentTest, EchoParamsTest, TestDistributedMissingSort, MoreLikeThisHandlerTest, ShowFileRequestHandlerTest, TestArbitraryIndexDir, MigrateRouteKeyTest, CircularListTest, TestSolrXmlPersistence, ZkCLITest, TestLFUCache, AutoCommitTest, AnalysisErrorHandlingTest, TermVectorComponentTest, TestValueSourceCache, TestCoreDiscovery, TestOverriddenPrefixQueryForCustomFieldType, SpatialFilterTest, TestDynamicFieldCollectionResource, TestLRUCache, TestRandomFaceting, HdfsBasicDistributedZk2Test, DOMUtilTest, DirectUpdateHandlerTest, TestJoin, TestUpdate, TestHighFrequencyDictionaryFactory, CoreMergeIndexesAdminHandlerTest, TestRealTimeGet, DistributedQueryComponentCustomSortTest, DistributedSuggestComponentTest, OverseerCollectionProcessorTest, TestTrie, TestPerFieldSimilarity, BasicDistributedZkTest, PrimitiveFieldTypeTest, RegexBoostProcessorTest, TestUniqueKeyFieldResource, DeleteReplicaTest, RequiredFieldsTest, TestFastLRUCache, DistributedSpellCheckComponentTest, QueryEqualityTest, TestLazyCores, HdfsChaosMonkeySafeLeaderTest, OpenCloseCoreStressTest, TestPartialUpdateDeduplication, TestCodecSupport, TestStressVersions, TestMultiCoreConfBootstrap, TestFreeTextSuggestions, OutputWriterTest, HighlighterConfigTest, PolyFieldTest, SolrIndexConfigTest, TestSolrIndexConfig, SimpleFacetsTest, OpenExchangeRatesOrgProviderTest, TestFieldTypeCollectionResource, TestManagedSchemaFieldResource, SimplePostToolTest, JSONWriterTest, LeaderElectionIntegrationTest, TestQueryUtils, CollectionsAPIDistributedZkTest, IndexBasedSpellCheckerTest, ScriptEngineTest, DocValuesMissingTest, FastVectorHighlighterTest, TestPHPSerializedResponseWriter, CoreContainerCoreInitFailuresTest, BinaryUpdateRequestHandlerTest, TestCollationKeyRangeQueries, TestSolrXMLSerializer, DocValuesTest, DirectUpdateHandlerOptimizeTest, TermsComponentTest, DocumentBuilderTest, SignatureUpdateProcessorFactoryTest, TestMaxScoreQueryParser, HdfsCollectionsAPIDistributedZkTest, TestSchemaNameResource, TestSimpleQParserPlugin, AlternateDirectoryTest, TestSweetSpotSimilarityFactory, TestSchemaResource, TestFunctionQuery, TestStressReorder, DistribCursorPagingTest, QueryParsingTest, TestFaceting, MBeansHandlerTest, LegacyHTMLStripCharFilterTest, NotRequiredUniqueKeyTest, TestAtomicUpdateErrorCases, TestFieldCollectionResource, LukeRequestHandlerTest, URLClassifyProcessorTest, TestStandardQParsers, FileBasedSpellCheckerTest, TestNoOpRegenerator, CopyFieldTest, TestCopyFieldCollectionResource, TestNonNRTOpen, TestFileDictionaryLookup, PreAnalyzedFieldTest, TestQueryTypes, TestSurroundQueryParser, SuggesterFSTTest, SchemaVersionSpecificBehaviorTest, TestSchemaVersionResource, SoftAutoCommitTest, TestSchemaSimilarityResource, TestDefaultSimilarityFactory, TestIndexingPerformance, TestLMDirichletSimilarityFactory, TestQuerySenderNoQuery, TestAnalyzedSuggestions, PluginInfoTest, ClusterStateUpdateTest, TestPostingsSolrHighlighter, HdfsBasicDistributedZkTest, TestSerializedLuceneMatchVersion, DistributedDebugComponentTest, ShardRoutingCustomTest, TestCloudManagedSchema, TestCollationFieldDocValues, TestDistributedSearch, OverseerTest, CachingDirectoryFactoryTest, TestCharFilters, TriLevelCompositeIdRoutingTest, TestSolrXmlPersistor, TestDocSet, TestSolr4Spatial, UnloadDistributedZkTest, ConnectionManagerTest, DateMathParserTest, ResourceLoaderTest, OverseerRolesTest, AssignTest, SystemInfoHandlerTest, LeaderElectionTest, TestFiltering, SolrTestCaseJ4Test, TestMergePolicyConfig, ExternalFileFieldSortTest, AnalysisAfterCoreReloadTest, SuggesterTest, TestReversedWildcardFilterFactory, ReturnFieldsTest, TestStressRecovery, SynonymTokenizerTest, TestBM25SimilarityFactory, TestShardHandlerFactory, StandardRequestHandlerTest, TestFastOutputStream, ShardRoutingTest, TestReplicationHandler, CursorPagingTest, TestBinaryResponseWriter, TestSolrCoreProperties, TestBlendedInfixSuggestions, TestDocBasedVersionConstraints, SolrInfoMBeanTest, UUIDFieldTest, ChaosMonkeySafeLeaderTest, BasicDistributedZk2Test, BasicZkTest, RecoveryZkTest, FullSolrCloudDistribCmdsTest, ZkSolrClientTest, TestZkChroot, TestRandomDVFaceting, SliceStateUpdateTest, TestDistributedGrouping, TestRecovery, TestHashPartitioner, TermVectorComponentDistributedTest, ZkControllerTest, TestReload, HardAutoCommitTest, DistributedTermsComponentTest, TestRangeQuery, TestCoreContainer, SolrCoreTest, StatsComponentTest, SpellCheckComponentTest, TestGroupingSearch, SolrCmdDistributorTest, QueryElevationComponentTest, PeerSyncTest, BadIndexSchemaTest, ConvertedLegacyTest, TestSort, BasicFunctionalityTest, TestBadConfig, TestIndexSearcher, HighlighterTest, CurrencyFieldOpenExchangeTest, DistributedQueryElevationComponentTest, CurrencyFieldXmlFileTest, SolrIndexSplitterTest, TestExtendedDismaxParser, SpellCheckCollatorTest, CoreAdminHandlerTest, SolrRequestParserTest, TestFoldingMultitermQuery, SuggesterTSTTest, TestStressLucene, SuggesterWFSTTest, TestCSVLoader, NoCacheHeaderTest, WordBreakSolrSpellCheckerTest, SolrCoreCheckLockOnStartupTest, TestPseudoReturnFields, FieldMutatingUpdateProcessorTest, TestWordDelimiterFilterFactory, DefaultValueUpdateProcessorTest, StatelessScriptUpdateProcessorFactoryTest, SortByFunctionTest, TestRemoteStreaming, DocValuesMultiTest, DistanceFunctionTest, TestSolrDeletionPolicy1, XsltUpdateRequestHandlerTest, DebugComponentTest, CacheHeaderTest, DisMaxRequestHandlerTest, TestWriterPerf, DirectSolrSpellCheckerTest, DocumentAnalysisRequestHandlerTest, TestOmitPositions, RequestHandlersTest, PathHierarchyTokenizerFactoryTest, FieldAnalysisRequestHandlerTest, TestSolrQueryParser, IndexSchemaRuntimeFieldTest, LoggingHandlerTest, SolrPluginUtilsTest, IndexSchemaTest, TestJmxIntegration, TestCollationField, UpdateRequestProcessorFactoryTest, TestCSVResponseWriter, UniqFieldsUpdateProcessorFactoryTest, JsonLoaderTest, PingRequestHandlerTest, CSVRequestHandlerTest, TestComponentsName, SearchHandlerTest, SOLR749Test, TestQuerySenderListener, UpdateParamsTest, ResponseLogComponentTest, TestSolrDeletionPolicy2, SampleTest, TestBinaryField, TestSearchPerf, NumericFieldsTest, MinimalSchemaTest, TestElisionMultitermQuery, TestConfig, TestFuzzyAnalyzedSuggestions, DirectSolrConnectionTest, TestLuceneMatchVersion, TestPhraseSuggestions, SpellPossibilityIteratorTest, TestDFRSimilarityFactory, TestLMJelinekMercerSimilarityFactory, TestIBSimilarityFactory, TestFastWriter, TestJmxMonitoredMap, TimeZoneUtilsTest, ChaosMonkeyNothingIsSafeTest, TestSystemIdResolver, PrimUtilsTest, TestSuggestSpellingConverter, DateFieldTest, SpellingQueryConverterTest, RAMDirectoryFactoryTest, ClusterStateTest, TestSolrJ, TestUtils, TestDocumentBuilder, ZkNodePropsTest, SliceStateTest, FileUtilsTest, TestRTGBase, TestCursorMarkWithoutUniqueKey, TestHighlightDedupGrouping, AliasIntegrationTest, CustomCollectionTest, DeleteShardTest, RemoteQueryErrorTest, ShardSplitTest, SolrXmlInZkTest, TestDistribDocBasedVersion, HdfsRecoveryZkTest, HdfsSyncSliceTest, HdfsUnloadDistributedZkTest, StressHdfsTest, QueryResultKeyTest, TestImplicitCoreProperties, TestInfoStreamLogging, TestNRTOpen, TestReloadAndDeleteDocs, TestSolrXml, CoreAdminCreateDiscoverTest, InfoHandlerTest, SuggestComponentTest, TestDefaultSearchFieldResource, TestDynamicFieldResource]
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=TestDynamicFieldResource -Dtests.seed=16F9F4B730368C62 -Dtests.slow=true -Dtests.locale=sl_SI -Dtests.timezone=Pacific/Funafuti -Dtests.file.encoding=ISO-8859-1
   [junit4] ERROR   0.00s | TestDynamicFieldResource (suite) <<<
   [junit4]    > Throwable #1: junit.framework.AssertionFailedError: Clean up static fields (in @AfterClass?), your test seems to hang on to approximately 10,675,848 bytes (threshold is 10,485,760). Field reference sizes (counted individually):
   [junit4]    >   - 10,674,696 bytes, protected static org.apache.solr.util.RestTestHarness org.apache.solr.util.RestTestBase.restTestHarness
   [junit4]    >   - 448 bytes, private static java.util.regex.Pattern org.apache.solr.SolrTestCaseJ4.nonEscapedSingleQuotePattern
   [junit4]    >   - 328 bytes, public static org.junit.rules.TestRule org.apache.solr.SolrTestCaseJ4.solrClassRules
   [junit4]    >   - 312 bytes, private static java.util.regex.Pattern org.apache.solr.SolrTestCaseJ4.escapedSingleQuotePattern
   [junit4]    >   - 224 bytes, protected static java.lang.String org.apache.solr.SolrTestCaseJ4.testSolrHome
   [junit4]    >   - 144 bytes, private static java.lang.String org.apache.solr.SolrTestCaseJ4.factoryProp
   [junit4]    >   - 80 bytes, private static java.lang.String org.apache.solr.SolrTestCaseJ4.coreName
   [junit4]    >   - 72 bytes, public static java.lang.String org.apache.solr.SolrJettyTestBase.context
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([16F9F4B730368C62]:0)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:744)
   [junit4] Completed in 1.56s, 3 tests, 1 failure <<< FAILURES!

[...truncated 84 lines...]
BUILD FAILED
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:459: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:439: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:39: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/extra-targets.xml:37: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build.xml:189: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/common-build.xml:491: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/common-build.xml:1308: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/common-build.xml:941: There were test failures: 362 suites, 1563 tests, 1 suite-level error, 40 ignored (6 assumptions)

Total time: 89 minutes 48 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.7.0 -XX:-UseCompressedOops -XX:+UseSerialGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure