[JENKINS] Lucene-Solr-5.x-MacOSX (64bit/jdk1.8.0) - Build # 2028 - Failure!

[Policeman Jenkins Server]

Build: http://jenkins.thetaphi.de/job/Lucene-Solr-5.x-MacOSX/2028/
Java: 64bit/jdk1.8.0 -XX:-UseCompressedOops -XX:+UseG1GC

1 tests failed.
FAILED:  
org.apache.solr.search.function.TestFunctionQuery.testPseudoFieldFunctions

Error Message:
unexpected map keys [e] @ response/docs/[0]

Stack Trace:
java.lang.RuntimeException: unexpected map keys [e] @ response/docs/[0]
        at 
__randomizedtesting.SeedInfo.seed([2BA203EDCC552176:7598E190F0C3DD3A]:0)
        at org.apache.solr.SolrTestCaseJ4.assertJQ(SolrTestCaseJ4.java:882)
        at org.apache.solr.SolrTestCaseJ4.assertJQ(SolrTestCaseJ4.java:829)
        at 
org.apache.solr.search.function.TestFunctionQuery.testPseudoFieldFunctions(TestFunctionQuery.java:739)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at 
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at 
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:497)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1627)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:836)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:872)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:886)
        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.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
        at 
org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
        at 
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
        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:365)
        at 
com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798)
        at 
com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:845)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:747)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:781)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:792)
        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 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
        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 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:54)
        at 
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
        at 
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
        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:365)
        at java.lang.Thread.run(Thread.java:745)




Build Log:
[...truncated 20124 lines...]
   [junit4] Suite: org.apache.solr.search.function.TestFunctionQuery
   [junit4]   2> Creating dataDir: 
/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.search.function.TestFunctionQuery
 2BA203EDCC552176-001/init-core-data-001
   [junit4]   2> 1291619 T5537 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl 
(false) and clientAuth (false)
   [junit4]   2> 1291620 T5537 oas.SolrTestCaseJ4.initCore ####initCore
   [junit4]   2> 1291620 T5537 oasc.SolrResourceLoader.<init> new 
SolrResourceLoader for directory: 
'/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/core/src/test-files/solr/collection1/'
   [junit4]   2> 1291621 T5537 oasc.SolrResourceLoader.replaceClassLoader 
Adding 
'file:/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/core/src/test-files/solr/collection1/lib/classes/'
 to classloader
   [junit4]   2> 1291621 T5537 oasc.SolrResourceLoader.replaceClassLoader 
Adding 
'file:/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/core/src/test-files/solr/collection1/lib/README'
 to classloader
   [junit4]   2> 1291685 T5537 oasc.SolrConfig.refreshRequestParams current 
version of requestparams : -1
   [junit4]   2> 1291688 T5537 oasc.SolrConfig.<init> Using Lucene 
MatchVersion: 5.1.0
   [junit4]   2> 1291698 T5537 oasc.SolrConfig.<init> Loaded SolrConfig: 
solrconfig-functionquery.xml
   [junit4]   2> 1291699 T5537 oass.IndexSchema.readSchema Reading Solr Schema 
from 
/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/schema11.xml
   [junit4]   2> 1291702 T5537 oass.IndexSchema.readSchema [null] Schema 
name=example
   [junit4]   2> 1291748 T5537 oass.IndexSchema.readSchema default search field 
in schema is text
   [junit4]   2> 1291749 T5537 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1291754 T5537 oasc.SolrResourceLoader.locateSolrHome JNDI not 
configured for solr (NoInitialContextEx)
   [junit4]   2> 1291754 T5537 oasc.SolrResourceLoader.locateSolrHome using 
system property solr.solr.home: 
/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/core/src/test-files/solr
   [junit4]   2> 1291755 T5537 oasc.SolrResourceLoader.<init> new 
SolrResourceLoader for directory: 
'/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/core/src/test-files/solr/'
   [junit4]   2> 1291772 T5537 oasc.CoreContainer.<init> New CoreContainer 
1306916543
   [junit4]   2> 1291772 T5537 oasc.CoreContainer.load Loading cores into 
CoreContainer 
[instanceDir=/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/core/src/test-files/solr/]
   [junit4]   2> 1291772 T5537 oasc.CoreContainer.load loading shared library: 
/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/core/src/test-files/solr/lib
   [junit4]   2> 1291773 T5537 oasc.SolrResourceLoader.addToClassLoader WARN 
Can't find (or read) directory to add to classloader: lib (resolved as: 
/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/core/src/test-files/solr/lib).
   [junit4]   2> 1291783 T5537 oashc.HttpShardHandlerFactory.getParameter 
Setting socketTimeout to: 600000
   [junit4]   2> 1291783 T5537 oashc.HttpShardHandlerFactory.getParameter 
Setting urlScheme to: null
   [junit4]   2> 1291783 T5537 oashc.HttpShardHandlerFactory.getParameter 
Setting connTimeout to: 60000
   [junit4]   2> 1291785 T5537 oashc.HttpShardHandlerFactory.getParameter 
Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1291785 T5537 oashc.HttpShardHandlerFactory.getParameter 
Setting maxConnections to: 10000
   [junit4]   2> 1291785 T5537 oashc.HttpShardHandlerFactory.getParameter 
Setting corePoolSize to: 0
   [junit4]   2> 1291785 T5537 oashc.HttpShardHandlerFactory.getParameter 
Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1291786 T5537 oashc.HttpShardHandlerFactory.getParameter 
Setting maxThreadIdleTime to: 5
   [junit4]   2> 1291786 T5537 oashc.HttpShardHandlerFactory.getParameter 
Setting sizeOfQueue to: -1
   [junit4]   2> 1291786 T5537 oashc.HttpShardHandlerFactory.getParameter 
Setting fairnessPolicy to: false
   [junit4]   2> 1291786 T5537 oashc.HttpShardHandlerFactory.getParameter 
Setting useRetries to: false
   [junit4]   2> 1291786 T5537 oasu.UpdateShardHandler.<init> Creating 
UpdateShardHandler HTTP client with params: 
socketTimeout=30000&connTimeout=30000&retry=true
   [junit4]   2> 1291787 T5537 oasl.LogWatcher.createWatcher SLF4J impl is 
org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1291787 T5537 oasl.LogWatcher.newRegisteredLogWatcher 
Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1291787 T5537 oasc.CoreContainer.load Node Name: testNode
   [junit4]   2> 1291791 T5537 oasc.CoreDescriptor.<init> CORE DESCRIPTOR: 
{name=collection1, config=solrconfig-functionquery.xml, transient=false, 
schema=schema11.xml, loadOnStartup=true, instanceDir=collection1, 
collection=collection1, 
absoluteInstDir=/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/core/src/test-files/solr/collection1/,
 
dataDir=/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.search.function.TestFunctionQuery
 2BA203EDCC552176-001/init-core-data-001, shard=shard1}
   [junit4]   2> 1291792 T5538 oasc.SolrResourceLoader.<init> new 
SolrResourceLoader for directory: 
'/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/core/src/test-files/solr/collection1/'
   [junit4]   2> 1291793 T5538 oasc.SolrResourceLoader.replaceClassLoader 
Adding 
'file:/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/core/src/test-files/solr/collection1/lib/classes/'
 to classloader
   [junit4]   2> 1291793 T5538 oasc.SolrResourceLoader.replaceClassLoader 
Adding 
'file:/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/core/src/test-files/solr/collection1/lib/README'
 to classloader
   [junit4]   2> 1291818 T5538 oasc.SolrConfig.refreshRequestParams current 
version of requestparams : -1
   [junit4]   2> 1291822 T5538 oasc.SolrConfig.<init> Using Lucene 
MatchVersion: 5.1.0
   [junit4]   2> 1291828 T5538 oasc.SolrConfig.<init> Loaded SolrConfig: 
solrconfig-functionquery.xml
   [junit4]   2> 1291829 T5538 oass.IndexSchema.readSchema Reading Solr Schema 
from 
/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/schema11.xml
   [junit4]   2> 1291832 T5538 oass.IndexSchema.readSchema [collection1] Schema 
name=example
   [junit4]   2> 1291879 T5538 oass.IndexSchema.readSchema default search field 
in schema is text
   [junit4]   2> 1291879 T5538 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1291882 T5538 oasc.CoreContainer.create Creating SolrCore 
'collection1' using configuration from instancedir 
/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/core/src/test-files/solr/collection1/
   [junit4]   2> 1291882 T5538 oasc.SolrCore.initDirectoryFactory 
org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1291883 T5538 oasc.SolrCore.<init> [collection1] Opening new 
SolrCore at 
/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/core/src/test-files/solr/collection1/,
 
dataDir=/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.search.function.TestFunctionQuery
 2BA203EDCC552176-001/init-core-data-001/
   [junit4]   2> 1291883 T5538 oasc.SolrCore.<init> JMX monitoring not detected 
for core: collection1
   [junit4]   2> 1291883 T5538 oasc.CachingDirectoryFactory.get return new 
directory for 
/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.search.function.TestFunctionQuery
 2BA203EDCC552176-001/init-core-data-001
   [junit4]   2> 1291883 T5538 oasc.SolrCore.getNewIndexDir New index directory 
detected: old=null 
new=/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.search.function.TestFunctionQuery
 2BA203EDCC552176-001/init-core-data-001/index/
   [junit4]   2> 1291883 T5538 oasc.SolrCore.initIndex WARN [collection1] Solr 
index directory 
'/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.search.function.TestFunctionQuery
 2BA203EDCC552176-001/init-core-data-001/index' doesn't exist. Creating new 
index...
   [junit4]   2> 1291884 T5538 oasc.CachingDirectoryFactory.get return new 
directory for 
/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.search.function.TestFunctionQuery
 2BA203EDCC552176-001/init-core-data-001/index
   [junit4]   2> 1291884 T5538 oasu.RandomMergePolicy.<init> RandomMergePolicy 
wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: 
maxMergeAtOnce=37, maxMergeAtOnceExplicit=23, maxMergedSegmentMB=1.10546875, 
floorSegmentMB=1.4267578125, forceMergeDeletesPctAllowed=13.173477914929876, 
segmentsPerTier=22.0, maxCFSSegmentSizeMB=8.796093022207999E12, 
noCFSRatio=0.8563561517548555
   [junit4]   2> 1291885 T5538 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@7b01b479 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2e3253fb),segFN=segments_1,generation=1}
   [junit4]   2> 1291885 T5538 oasc.SolrDeletionPolicy.updateCommits newest 
commit generation = 1
   [junit4]   2> 1291888 T5538 oasc.SolrCore.loadUpdateProcessorChains no 
updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1291893 T5538 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1291895 T5538 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1291896 T5538 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1291897 T5538 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1291900 T5538 oasc.RequestHandlers.initHandlersFromConfig 
Registered paths: 
/admin/mbeans,standard,/update/csv,/update/json/docs,/admin/luke,/admin/segments,/get,/admin/system,/replication,/admin/properties,/reloadCache,/config,/schema,/admin/plugins,/admin/logging,/update/json,/admin/threads,/admin/ping,/update,/admin/file
   [junit4]   2> 1291901 T5538 oasc.SolrCore.initStatsCache Using default 
statsCache cache: org.apache.solr.search.stats.LocalStatsCache
   [junit4]   2> 1291901 T5538 oasu.CommitTracker.<init> Hard AutoCommit: 
disabled
   [junit4]   2> 1291901 T5538 oasu.CommitTracker.<init> Soft AutoCommit: 
disabled
   [junit4]   2> 1291902 T5538 oasu.RandomMergePolicy.<init> RandomMergePolicy 
wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: 
maxMergeAtOnce=47, maxMergeAtOnceExplicit=39, maxMergedSegmentMB=34.6142578125, 
floorSegmentMB=0.6162109375, forceMergeDeletesPctAllowed=15.48438551141711, 
segmentsPerTier=27.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
   [junit4]   2> 1291902 T5538 oasc.SolrDeletionPolicy.onInit 
SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@7b01b479 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2e3253fb),segFN=segments_1,generation=1}
   [junit4]   2> 1291902 T5538 oasc.SolrDeletionPolicy.updateCommits newest 
commit generation = 1
   [junit4]   2> 1291903 T5538 oass.SolrIndexSearcher.<init> Opening 
Searcher@3c062e93[collection1] main
   [junit4]   2> 1291904 T5538 oasr.ManagedResourceStorage.newStorageIO WARN 
Cannot write to config directory 
/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/core/src/test-files/solr/collection1/conf;
 switching to use InMemory storage instead.
   [junit4]   2> 1291904 T5538 oasr.RestManager.init Initializing RestManager 
with initArgs: {}
   [junit4]   2> 1291904 T5538 oasr.ManagedResourceStorage.load Reading 
_rest_managed.json using InMemoryStorage
   [junit4]   2> 1291904 T5538 oasr.RestManager.init Initializing 0 registered 
ManagedResources
   [junit4]   2> 1291905 T5538 oash.ReplicationHandler.inform Commits will be 
reserved for  10000
   [junit4]   2> 1291905 T5539 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@3c062e93[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 1291905 T5538 oasc.CoreContainer.registerCore registering 
core: collection1
   [junit4]   2> 1291908 T5537 oas.SolrTestCaseJ4.initCore ####initCore end
   [junit4]   2> 1291911 T5537 oas.SolrTestCaseJ4.setUp ###Starting 
testDegreeRads
   [junit4]   2> ASYNC  NEW_CORE C1993 name=collection1 
org.apache.solr.core.SolrCore@7984f979
   [junit4]   2> 1291912 T5537 C1993 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[1]} 0 1
   [junit4]   2> 1291914 T5537 C1993 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[2]} 0 0
   [junit4]   2> ASYNC  NEW_CORE C1994 name=collection1 
org.apache.solr.core.SolrCore@7984f979
   [junit4]   2> 1291928 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[3]} 0 0
   [junit4]   2> 1291929 T5537 C1994 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1291933 T5537 C1994 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@7b01b479 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2e3253fb),segFN=segments_1,generation=1}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@7b01b479 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2e3253fb),segFN=segments_2,generation=2}
   [junit4]   2> 1291934 T5537 C1994 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 2
   [junit4]   2> 1291936 T5537 C1994 oass.SolrIndexSearcher.<init> Opening 
Searcher@363617b9[collection1] main
   [junit4]   2> 1291937 T5537 C1994 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 1291937 T5539 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@363617b9[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(5.1.0):c3)))}
   [junit4]   2> 1291937 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 8
   [junit4]   2> 1291942 T5537 C1994 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q={!func}rad(x_td)&fl=*,score&fq=id:1&wt=xml} 
hits=1 status=0 QTime=1 
   [junit4]   2> 1291943 T5537 C1994 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q={!func}rad(x_td)&fl=*,score&fq=id:2&wt=xml} 
hits=1 status=0 QTime=0 
   [junit4]   2> 1291944 T5537 C1994 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q={!func}rad(x_td)&fl=*,score&fq=id:3&wt=xml} 
hits=1 status=0 QTime=0 
   [junit4]   2> 1291945 T5537 C1994 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q={!func}deg(y_td)&fl=*,score&fq=id:1&wt=xml} 
hits=1 status=0 QTime=0 
   [junit4]   2> 1291946 T5537 C1994 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q={!func}deg(y_td)&fl=*,score&fq=id:2&wt=xml} 
hits=1 status=0 QTime=1 
   [junit4]   2> 1291946 T5537 C1994 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q={!func}deg(y_td)&fl=*,score&fq=id:3&wt=xml} 
hits=1 status=0 QTime=0 
   [junit4]   2> 1291947 T5537 oas.SolrTestCaseJ4.tearDown ###Ending 
testDegreeRads
   [junit4]   2> 1291950 T5537 oas.SolrTestCaseJ4.setUp ###Starting 
testStrDistance
   [junit4]   2> 1291954 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[1]} 0 4
   [junit4]   2> 1291955 T5537 C1994 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1291958 T5537 C1994 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@7b01b479 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2e3253fb),segFN=segments_2,generation=2}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@7b01b479 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2e3253fb),segFN=segments_3,generation=3}
   [junit4]   2> 1291958 T5537 C1994 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 3
   [junit4]   2> 1291959 T5537 C1994 oass.SolrIndexSearcher.<init> Opening 
Searcher@148c7d14[collection1] main
   [junit4]   2> 1291959 T5537 C1994 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 1291959 T5539 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@148c7d14[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(5.1.0):c3/1:delGen=1)
 Uninverting(_1(5.1.0):c1)))}
   [junit4]   2> 1291959 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 4
   [junit4]   2> 1291984 T5537 C1994 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}strdist(x_s,+'foit',+edit)&fl=*,score&fq=id:1&wt=xml} hits=1 
status=0 QTime=24 
   [junit4]   2> 1291986 T5537 C1994 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}strdist(x_s,+'foit',+jw)&fl=*,score&fq=id:1&wt=xml} hits=1 
status=0 QTime=1 
   [junit4]   2> 1291995 T5537 C1994 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}strdist(x_s,+'foit',+ngram,+2)&fl=*,score&fq=id:1&wt=xml} 
hits=1 status=0 QTime=7 
   [junit4]   2> 1291995 T5537 C1994 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=id:1&fl=good:strdist(x_s,+'toil',+edit)&fl=bad1:strdist(missing1_s,+missing2_s,+edit)&fl=bad2:strdist(missing1_s,+'something',+edit)&fl=bad3:strdist(missing1_s,+x_s,+edit)&wt=xml}
 hits=1 status=0 QTime=0 
   [junit4]   2> 1291997 T5537 C1994 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}strdist(missing1_s,+missing2_s,+edit)&fl=score&fq=id:1&wt=xml} 
hits=1 status=0 QTime=0 
   [junit4]   2> 1291997 T5537 C1994 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}strdist(missing1_s,+x_s,+edit)&fl=score&fq=id:1&wt=xml} hits=1 
status=0 QTime=0 
   [junit4]   2> 1291998 T5537 C1994 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}strdist(missing1_s,+'const',+edit)&fl=score&fq=id:1&wt=xml} 
hits=1 status=0 QTime=0 
   [junit4]   2> 1291999 T5537 oas.SolrTestCaseJ4.tearDown ###Ending 
testStrDistance
   [junit4]   2> 1292001 T5537 oas.SolrTestCaseJ4.setUp ###Starting 
testMissingFieldFunctionBehavior
   [junit4]   2> 1292002 T5537 C1994 oasu.DirectUpdateHandler2.deleteAll 
[collection1] REMOVING ALL DOCUMENTS FROM INDEX
   [junit4]   2> 1292003 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 1
   [junit4]   2> 1292004 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[1]} 0 1
   [junit4]   2> 1292004 T5537 C1994 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1292006 T5537 C1994 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@7b01b479 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2e3253fb),segFN=segments_3,generation=3}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@7b01b479 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2e3253fb),segFN=segments_4,generation=4}
   [junit4]   2> 1292007 T5537 C1994 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 4
   [junit4]   2> 1292008 T5537 C1994 oass.SolrIndexSearcher.<init> Opening 
Searcher@9d75330[collection1] main
   [junit4]   2> 1292008 T5537 C1994 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 1292008 T5539 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@9d75330[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_2(5.1.0):c1)))}
   [junit4]   2> 1292009 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 5
   [junit4]   2> 1292020 T5537 C1994 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=id:1&fl=noval_if:if(no__vals____s,42,-99)&fl=noval_def:def(no__vals____s,-99)&fl=noval_not:not(no__vals____s)&fl=noval_exists:exists(no__vals____s)&wt=xml}
 hits=1 status=0 QTime=11 
   [junit4]   2> 1292022 T5537 C1994 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=id:1&fl=noval_if:if(no__vals____b,42,-99)&fl=noval_def:def(no__vals____b,-99)&fl=noval_not:not(no__vals____b)&fl=noval_exists:exists(no__vals____b)&wt=xml}
 hits=1 status=0 QTime=0 
   [junit4]   2> 1292033 T5537 C1994 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=id:1&fl=noval_if:if(no__vals____dt,42,-99)&fl=noval_def:def(no__vals____dt,-99)&fl=noval_not:not(no__vals____dt)&fl=noval_exists:exists(no__vals____dt)&wt=xml}
 hits=1 status=0 QTime=1 
   [junit4]   2> 1292034 T5537 C1994 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=id:1&fl=noval_if:if(no__vals____tdt,42,-99)&fl=noval_def:def(no__vals____tdt,-99)&fl=noval_not:not(no__vals____tdt)&fl=noval_exists:exists(no__vals____tdt)&wt=xml}
 hits=1 status=0 QTime=0 
   [junit4]   2> 1292035 T5537 C1994 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=id:1&fl=noval_if:if(no__vals____i,42,-99)&fl=noval_def:def(no__vals____i,-99)&fl=noval_not:not(no__vals____i)&fl=noval_exists:exists(no__vals____i)&wt=xml}
 hits=1 status=0 QTime=0 
   [junit4]   2> 1292037 T5537 C1994 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=id:1&fl=noval_if:if(no__vals____l,42,-99)&fl=noval_def:def(no__vals____l,-99)&fl=noval_not:not(no__vals____l)&fl=noval_exists:exists(no__vals____l)&wt=xml}
 hits=1 status=0 QTime=0 
   [junit4]   2> 1292038 T5537 C1994 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=id:1&fl=noval_if:if(no__vals____f,42,-99)&fl=noval_def:def(no__vals____f,-99)&fl=noval_not:not(no__vals____f)&fl=noval_exists:exists(no__vals____f)&wt=xml}
 hits=1 status=0 QTime=0 
   [junit4]   2> 1292039 T5537 C1994 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=id:1&fl=noval_if:if(no__vals____d,42,-99)&fl=noval_def:def(no__vals____d,-99)&fl=noval_not:not(no__vals____d)&fl=noval_exists:exists(no__vals____d)&wt=xml}
 hits=1 status=0 QTime=0 
   [junit4]   2> 1292040 T5537 C1994 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=id:1&fl=noval_if:if(no__vals____ti,42,-99)&fl=noval_def:def(no__vals____ti,-99)&fl=noval_not:not(no__vals____ti)&fl=noval_exists:exists(no__vals____ti)&wt=xml}
 hits=1 status=0 QTime=0 
   [junit4]   2> 1292046 T5537 C1994 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=id:1&fl=noval_if:if(no__vals____tl,42,-99)&fl=noval_def:def(no__vals____tl,-99)&fl=noval_not:not(no__vals____tl)&fl=noval_exists:exists(no__vals____tl)&wt=xml}
 hits=1 status=0 QTime=0 
   [junit4]   2> 1292047 T5537 C1994 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=id:1&fl=noval_if:if(no__vals____tf,42,-99)&fl=noval_def:def(no__vals____tf,-99)&fl=noval_not:not(no__vals____tf)&fl=noval_exists:exists(no__vals____tf)&wt=xml}
 hits=1 status=0 QTime=0 
   [junit4]   2> 1292048 T5537 C1994 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=id:1&fl=noval_if:if(no__vals____td,42,-99)&fl=noval_def:def(no__vals____td,-99)&fl=noval_not:not(no__vals____td)&fl=noval_exists:exists(no__vals____td)&wt=xml}
 hits=1 status=0 QTime=0 
   [junit4]   2> 1292050 T5537 oas.SolrTestCaseJ4.tearDown ###Ending 
testMissingFieldFunctionBehavior
   [junit4]   2> 1292054 T5537 oas.SolrTestCaseJ4.setUp ###Starting 
testSortByFunc
   [junit4]   2> 1292055 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[1]} 0 0
   [junit4]   2> 1292056 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[2]} 0 1
   [junit4]   2> 1292056 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[3]} 0 0
   [junit4]   2> 1292057 T5537 C1994 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1292061 T5537 C1994 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@7b01b479 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2e3253fb),segFN=segments_4,generation=4}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@7b01b479 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2e3253fb),segFN=segments_5,generation=5}
   [junit4]   2> 1292061 T5537 C1994 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 5
   [junit4]   2> 1292061 T5537 C1994 oass.SolrIndexSearcher.<init> Opening 
Searcher@1bc8bc2a[collection1] main
   [junit4]   2> 1292062 T5537 C1994 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 1292062 T5539 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@1bc8bc2a[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_3(5.1.0):c3)))}
   [junit4]   2> 1292064 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 7
   [junit4]   2> 1292065 T5537 C1994 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=id:[1+TO+3]&fl=x_i&sort=add(x_i,x_i)+desc&wt=xml} hits=3 status=0 
QTime=1 
   [junit4]   2> 1292066 T5537 C1994 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=id:[1+TO+3]&fl=x_i&x=add(x_i,x_i)&sort=const_s+asc,+$x+asc&wt=xml} 
hits=3 status=0 QTime=1 
   [junit4]   2> 1292067 T5537 C1994 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=id:[1+TO+3]&fl=x_i&x=5&y=add(x_i,x_i)&sort=$x+asc,+const_s+asc,+$y+desc&wt=xml}
 hits=3 status=0 QTime=0 
   [junit4]   2> 1292067 T5537 C1994 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=id:[1+TO+3]&const=50&fl=x_i&sort=add(+10+,+10+)+asc,+const_s+asc,+add(x_i+,+$const)+desc&wt=xml}
 hits=3 status=0 QTime=0 
   [junit4]   2> 1292068 T5537 C1994 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=id:[1+TO+3]&fl=x_i&sort=const_s+asc,+{!key%3Dfoo}add(x_i,x_i)+desc&wt=xml}
 hits=3 status=0 QTime=0 
   [junit4]   2> 1292068 T5537 C1994 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=id:[1+TO+3]&fl=x_i&sort={!key%3Dfoo}add(x_i,x_i)+desc,+const_s+asc&wt=xml}
 hits=3 status=0 QTime=0 
   [junit4]   2> 1292069 T5537 C1994 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=id:[1+TO+3]&fl=x_i&sort={!key%3Dbar}add(10,20)+asc,+const_s+asc,+{!key%3Dfoo}add(x_i,x_i)+desc&wt=xml}
 hits=3 status=0 QTime=0 
   [junit4]   2> 1292069 T5537 C1994 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=id:[1+TO+3]&fl=x_i&sort={!key%3Dbar+v%3D$s1}+asc,+{!key%3Dfoo+v%3D$s2}+desc&wt=xml&s1=add(3,4)&s2=add(x_i,5)}
 hits=3 status=0 QTime=0 
   [junit4]   2> 1292070 T5537 C1994 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=id:[1+TO+3]&fl=x_i&sort={!key%3Dbar+v%3D$s1}asc,const_s+asc,{!key%3Dfoo+v%3D$s2}desc&wt=xml&s1=add(3,4)&s2=add(x_i,5)}
 hits=3 status=0 QTime=0 
   [junit4]   2> 1292073 T5537 C1994 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q=id:[1+TO+3]&fl=x_i&sort=1_s+asc&wt=xml} hits=3 
status=0 QTime=3 
   [junit4]   2> 1292073 T5537 C1994 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q=id:[1+TO+3]&fl=x_i&sort=x:x_i+desc&wt=xml} 
hits=3 status=0 QTime=0 
   [junit4]   2> 1292074 T5537 C1994 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q=id:[1+TO+3]&fl=x_i&sort=1-1_s+asc&wt=xml} 
hits=3 status=0 QTime=0 
   [junit4]   2> 1292075 T5537 C1994 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=id:[1+TO+3]&fl=x_i&sort=[]_s+asc,+{!key%3Dfoo}add(x_i,x_i)+desc&wt=xml}
 hits=3 status=0 QTime=1 
   [junit4]   2> 1292076 T5537 C1994 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=id:[1+TO+3]&fl=x_i&sort={!lucene+v%3D'id:3'}desc,+{!key%3Dfoo}add(x_i,x_i)+asc&wt=xml}
 hits=3 status=0 QTime=0 
   [junit4]   2> 1292077 T5537 oas.SolrTestCaseJ4.tearDown ###Ending 
testSortByFunc
   [junit4]   2> 1292083 T5537 oas.SolrTestCaseJ4.setUp ###Starting 
testFieldValueSourceParser
   [junit4]   2> 1292084 T5537 C1994 oasu.DirectUpdateHandler2.deleteAll 
[collection1] REMOVING ALL DOCUMENTS FROM INDEX
   [junit4]   2> 1292084 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 0
   [junit4]   2> 1292086 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[100.0]} 0 1
   [junit4]   2> 1292086 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[-4.0]} 0 0
   [junit4]   2> 1292087 T5537 C1994 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1292089 T5537 C1994 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@7b01b479 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2e3253fb),segFN=segments_5,generation=5}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@7b01b479 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2e3253fb),segFN=segments_6,generation=6}
   [junit4]   2> 1292089 T5537 C1994 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 6
   [junit4]   2> 1292090 T5537 C1994 oass.SolrIndexSearcher.<init> Opening 
Searcher@5165620a[collection1] main
   [junit4]   2> 1292090 T5537 C1994 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 1292091 T5539 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@5165620a[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_4(5.1.0):c2)))}
   [junit4]   2> 1292091 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 4
   [junit4]   2> 1292092 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[0.0]} 0 0
   [junit4]   2> 1292093 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[10.0]} 0 0
   [junit4]   2> 1292093 T5537 C1994 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1292096 T5537 C1994 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@7b01b479 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2e3253fb),segFN=segments_6,generation=6}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@7b01b479 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2e3253fb),segFN=segments_7,generation=7}
   [junit4]   2> 1292096 T5537 C1994 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 7
   [junit4]   2> 1292097 T5537 C1994 oass.SolrIndexSearcher.<init> Opening 
Searcher@522990cf[collection1] main
   [junit4]   2> 1292098 T5539 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@522990cf[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_4(5.1.0):c2)
 Uninverting(_5(5.1.0):c2)))}
   [junit4]   2> 1292098 T5537 C1994 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 1292099 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 6
   [junit4]   2> 1292100 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[25.0]} 0 0
   [junit4]   2> 1292101 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[5.0]} 0 0
   [junit4]   2> 1292102 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[77.0]} 0 0
   [junit4]   2> 1292103 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[1.0]} 0 0
   [junit4]   2> 1292103 T5537 C1994 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1292106 T5537 C1994 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@7b01b479 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2e3253fb),segFN=segments_7,generation=7}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@7b01b479 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2e3253fb),segFN=segments_8,generation=8}
   [junit4]   2> 1292107 T5537 C1994 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 8
   [junit4]   2> 1292107 T5537 C1994 oass.SolrIndexSearcher.<init> Opening 
Searcher@366d5e8d[collection1] main
   [junit4]   2> 1292108 T5539 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@366d5e8d[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_4(5.1.0):c2)
 Uninverting(_5(5.1.0):c2) Uninverting(_6(5.1.0):c4)))}
   [junit4]   2> 1292109 T5537 C1994 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 1292109 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 6
   [junit4]   2> 1292111 T5537 C1994 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}field("CoMpleX+\"+fieldName+_f")&indent=on&fl=*,score&rows=100&wt=xml}
 hits=8 status=0 QTime=0 
   [junit4]   2> 1292113 T5537 C1994 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}sqrt(field("CoMpleX+\"+fieldName+_f"))&indent=on&fl=*,score&rows=100&wt=xml}
 hits=8 status=0 QTime=0 
   [junit4]   2> 1292117 T5537 C1994 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}log(field("CoMpleX+\"+fieldName+_f"))&indent=on&fl=*,score&rows=100&wt=xml}
 hits=8 status=0 QTime=0 
   [junit4]   2> 1292122 T5537 oas.SolrTestCaseJ4.tearDown ###Ending 
testFieldValueSourceParser
   [junit4]   2> 1292125 T5537 oas.SolrTestCaseJ4.setUp ###Starting 
testTotalTermFreq
   [junit4]   2> 1292126 T5537 C1994 oasu.DirectUpdateHandler2.deleteAll 
[collection1] REMOVING ALL DOCUMENTS FROM INDEX
   [junit4]   2> 1292126 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 1
   [junit4]   2> 1292127 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[1]} 0 0
   [junit4]   2> 1292128 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[2]} 0 0
   [junit4]   2> 1292128 T5537 C1994 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1292130 T5537 C1994 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@7b01b479 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2e3253fb),segFN=segments_8,generation=8}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@7b01b479 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2e3253fb),segFN=segments_9,generation=9}
   [junit4]   2> 1292131 T5537 C1994 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 9
   [junit4]   2> 1292132 T5537 C1994 oass.SolrIndexSearcher.<init> Opening 
Searcher@7e94cc36[collection1] main
   [junit4]   2> 1292133 T5537 C1994 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 1292133 T5539 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@7e94cc36[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_7(5.1.0):c2)))}
   [junit4]   2> 1292133 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 5
   [junit4]   2> 1292135 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[3]} 0 1
   [junit4]   2> 1292135 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[4]} 0 0
   [junit4]   2> 1292136 T5537 C1994 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1292138 T5537 C1994 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@7b01b479 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2e3253fb),segFN=segments_9,generation=9}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@7b01b479 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2e3253fb),segFN=segments_a,generation=10}
   [junit4]   2> 1292138 T5537 C1994 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 10
   [junit4]   2> 1292139 T5537 C1994 oass.SolrIndexSearcher.<init> Opening 
Searcher@61c32a94[collection1] main
   [junit4]   2> 1292139 T5539 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@61c32a94[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_7(5.1.0):c2)
 Uninverting(_8(5.1.0):c2)))}
   [junit4]   2> 1292140 T5537 C1994 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 1292140 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 4
   [junit4]   2> 1292140 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[5]} 0 0
   [junit4]   2> 1292141 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[6]} 0 0
   [junit4]   2> 1292142 T5537 C1994 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1292145 T5537 C1994 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@7b01b479 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2e3253fb),segFN=segments_a,generation=10}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@7b01b479 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2e3253fb),segFN=segments_b,generation=11}
   [junit4]   2> 1292145 T5537 C1994 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 11
   [junit4]   2> 1292145 T5537 C1994 oass.SolrIndexSearcher.<init> Opening 
Searcher@4006de0c[collection1] main
   [junit4]   2> 1292146 T5539 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@4006de0c[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_7(5.1.0):c2)
 Uninverting(_8(5.1.0):c2) Uninverting(_9(5.1.0):c2)))}
   [junit4]   2> 1292146 T5537 C1994 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 1292147 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 5
   [junit4]   2> 1292158 T5537 C1994 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}totaltermfreq('a_t','cow')&fl=*,score&fq=id:6&wt=xml} hits=1 
status=0 QTime=11 
   [junit4]   2> 1292159 T5537 C1994 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}ttf(a_t,'cow')&fl=*,score&fq=id:6&wt=xml} hits=1 status=0 
QTime=0 
   [junit4]   2> 1292164 T5537 C1994 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}sumtotaltermfreq('a_t')&fl=*,score&fq=id:6&wt=xml} hits=1 
status=0 QTime=5 
   [junit4]   2> 1292165 T5537 C1994 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q={!func}sttf(a_t)&fl=*,score&fq=id:6&wt=xml} 
hits=1 status=0 QTime=0 
   [junit4]   2> 1292166 T5537 oas.SolrTestCaseJ4.tearDown ###Ending 
testTotalTermFreq
   [junit4]   2> 1292170 T5537 oas.SolrTestCaseJ4.setUp ###Starting 
testExternalField
   [junit4]   2> 1292170 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[100.0]} 0 0
   [junit4]   2> 1292171 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[-4.0]} 0 0
   [junit4]   2> 1292171 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[0.0]} 0 0
   [junit4]   2> 1292172 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[10.0]} 0 0
   [junit4]   2> 1292172 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[10.0]} 0 0
   [junit4]   2> 1292173 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[25.0]} 0 0
   [junit4]   2> 1292173 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[25.0]} 0 0
   [junit4]   2> 1292174 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[5.0]} 0 0
   [junit4]   2> 1292174 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[77.0]} 0 0
   [junit4]   2> 1292175 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[23.0]} 0 0
   [junit4]   2> 1292175 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[55.0]} 0 0
   [junit4]   2> 1292176 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[55.0]} 0 0
   [junit4]   2> 1292177 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[-78.0]} 0 0
   [junit4]   2> 1292177 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[-45.0]} 0 0
   [junit4]   2> 1292178 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[-24.0]} 0 0
   [junit4]   2> 1292178 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[63.0]} 0 0
   [junit4]   2> 1292179 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[78.0]} 0 0
   [junit4]   2> 1292180 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[94.0]} 0 0
   [junit4]   2> 1292180 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[22.0]} 0 0
   [junit4]   2> 1292181 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[34.0]} 0 0
   [junit4]   2> 1292181 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[34.0]} 0 0
   [junit4]   2> 1292182 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[54321.0]} 0 1
   [junit4]   2> 1292182 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[261.0]} 0 0
   [junit4]   2> 1292182 T5537 C1994 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1292185 T5537 C1994 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@7b01b479 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2e3253fb),segFN=segments_b,generation=11}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@7b01b479 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2e3253fb),segFN=segments_c,generation=12}
   [junit4]   2> 1292185 T5537 C1994 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 12
   [junit4]   2> 1292186 T5537 C1994 oass.SolrIndexSearcher.<init> Opening 
Searcher@7f65409b[collection1] main
   [junit4]   2> 1292187 T5539 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@7f65409b[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_7(5.1.0):c2)
 Uninverting(_8(5.1.0):c2) Uninverting(_9(5.1.0):c2/1:delGen=1) 
Uninverting(_a(5.1.0):c23/4:delGen=1)))}
   [junit4]   2> 1292188 T5537 C1994 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 1292188 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 6
   [junit4]   2> 1292188 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[-627.0]} 0 0
   [junit4]   2> 1292189 T5537 C1994 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1292191 T5537 C1994 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@7b01b479 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2e3253fb),segFN=segments_c,generation=12}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@7b01b479 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2e3253fb),segFN=segments_d,generation=13}
   [junit4]   2> 1292191 T5537 C1994 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 13
   [junit4]   2> 1292191 T5537 C1994 oass.SolrIndexSearcher.<init> Opening 
Searcher@344df23e[collection1] main
   [junit4]   2> 1292192 T5537 C1994 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 1292192 T5539 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@344df23e[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_7(5.1.0):c2)
 Uninverting(_8(5.1.0):c2) Uninverting(_9(5.1.0):c2/1:delGen=1) 
Uninverting(_a(5.1.0):c23/4:delGen=1) Uninverting(_b(5.1.0):c1)))}
   [junit4]   2> 1292192 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 3
   [junit4]   2> 1292237 T5537 C1994 oassf.FileFloatSource.getFloats Loaded 
external value source external_foo_extf
   [junit4]   2> 1292237 T5537 C1994 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}foo_extf&indent=on&fl=*,score&rows=100&wt=xml} hits=25 
status=0 QTime=44 
   [junit4]   2> 1292239 T5537 C1994 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}log(foo_extf)&indent=on&fl=*,score&rows=100&wt=xml} hits=25 
status=0 QTime=0 
   [junit4]   2> 1292240 T5537 C1994 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}sqrt(foo_extf)&indent=on&fl=*,score&rows=100&wt=xml} hits=25 
status=0 QTime=0 
   [junit4]   2> 1292241 T5537 C1994 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1292242 T5537 C1994 oasu.DirectUpdateHandler2.commit No 
uncommitted changes. Skipping IW.commit.
   [junit4]   2> 1292242 T5537 C1994 oasc.SolrCore.openNewSearcher 
SolrIndexSearcher has not changed - not re-opening: 
org.apache.solr.search.SolrIndexSearcher
   [junit4]   2> 1292243 T5537 C1994 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 1292243 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={=&wt=xml} {commit=} 0 2
   [junit4]   2> 1292244 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {} 0 1
   [junit4]   2> 1292246 T5537 C1994 oassf.FileFloatSource.getFloats Loaded 
external value source external_foo_extf
   [junit4]   2> 1292247 T5537 C1994 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}sqrt(foo_extf)&indent=on&fl=*,score&rows=100&wt=xml} hits=25 
status=0 QTime=3 
   [junit4]   2> 1292248 T5537 C1994 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1292248 T5537 C1994 oasu.DirectUpdateHandler2.commit No 
uncommitted changes. Skipping IW.commit.
   [junit4]   2> 1292249 T5537 C1994 oasc.SolrCore.openNewSearcher 
SolrIndexSearcher has not changed - not re-opening: 
org.apache.solr.search.SolrIndexSearcher
   [junit4]   2> 1292249 T5537 C1994 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 1292249 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={=&wt=xml} {commit=} 0 1
   [junit4]   2> 1292249 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {} 0 0
   [junit4]   2> 1292251 T5537 C1994 oassf.FileFloatSource.getFloats Loaded 
external value source external_foo_extf
   [junit4]   2> 1292251 T5537 C1994 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}foo_extf&indent=on&fl=*,score&rows=100&wt=xml} hits=25 
status=0 QTime=1 
   [junit4]   2> 1292258 T5537 C1994 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1292258 T5537 C1994 oasu.DirectUpdateHandler2.commit No 
uncommitted changes. Skipping IW.commit.
   [junit4]   2> 1292259 T5537 C1994 oasc.SolrCore.openNewSearcher 
SolrIndexSearcher has not changed - not re-opening: 
org.apache.solr.search.SolrIndexSearcher
   [junit4]   2> 1292259 T5537 C1994 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 1292259 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={=&wt=xml} {commit=} 0 1
   [junit4]   2> 1292260 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {} 0 0
   [junit4]   2> 1292262 T5537 C1994 oassf.FileFloatSource.getFloats Loaded 
external value source external_foo_extf
   [junit4]   2> 1292262 T5537 C1994 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}foo_extf&indent=on&fl=*,score&rows=100&wt=xml} hits=25 
status=0 QTime=1 
   [junit4]   2> 1292269 T5537 C1994 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1292270 T5537 C1994 oasu.DirectUpdateHandler2.commit No 
uncommitted changes. Skipping IW.commit.
   [junit4]   2> 1292270 T5537 C1994 oasc.SolrCore.openNewSearcher 
SolrIndexSearcher has not changed - not re-opening: 
org.apache.solr.search.SolrIndexSearcher
   [junit4]   2> 1292270 T5537 C1994 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 1292271 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={=&wt=xml} {commit=} 0 2
   [junit4]   2> 1292271 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {} 0 0
   [junit4]   2> 1292272 T5537 C1994 oassf.FileFloatSource.getFloats Loaded 
external value source external_foo_extf
   [junit4]   2> 1292273 T5537 C1994 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}foo_extf&indent=on&fl=*,score&rows=100&wt=xml} hits=25 
status=0 QTime=1 
   [junit4]   2> 1292280 T5537 C1994 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1292281 T5537 C1994 oasu.DirectUpdateHandler2.commit No 
uncommitted changes. Skipping IW.commit.
   [junit4]   2> 1292281 T5537 C1994 oasc.SolrCore.openNewSearcher 
SolrIndexSearcher has not changed - not re-opening: 
org.apache.solr.search.SolrIndexSearcher
   [junit4]   2> 1292281 T5537 C1994 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 1292281 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={=&wt=xml} {commit=} 0 1
   [junit4]   2> 1292282 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {} 0 0
   [junit4]   2> 1292284 T5537 C1994 oassf.FileFloatSource.getFloats Loaded 
external value source external_foo_extf
   [junit4]   2> 1292284 T5537 C1994 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}foo_extf&indent=on&fl=*,score&rows=100&wt=xml} hits=25 
status=0 QTime=1 
   [junit4]   2> 1292291 T5537 C1994 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1292291 T5537 C1994 oasu.DirectUpdateHandler2.commit No 
uncommitted changes. Skipping IW.commit.
   [junit4]   2> 1292292 T5537 C1994 oasc.SolrCore.openNewSearcher 
SolrIndexSearcher has not changed - not re-opening: 
org.apache.solr.search.SolrIndexSearcher
   [junit4]   2> 1292292 T5537 C1994 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 1292292 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={=&wt=xml} {commit=} 0 1
   [junit4]   2> 1292292 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {} 0 0
   [junit4]   2> 1292294 T5537 C1994 oassf.FileFloatSource.getFloats Loaded 
external value source external_foo_extf
   [junit4]   2> 1292295 T5537 C1994 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}foo_extf&indent=on&fl=*,score&rows=100&wt=xml} hits=25 
status=0 QTime=2 
   [junit4]   2> 1292301 T5537 C1994 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1292302 T5537 C1994 oasu.DirectUpdateHandler2.commit No 
uncommitted changes. Skipping IW.commit.
   [junit4]   2> 1292303 T5537 C1994 oasc.SolrCore.openNewSearcher 
SolrIndexSearcher has not changed - not re-opening: 
org.apache.solr.search.SolrIndexSearcher
   [junit4]   2> 1292303 T5537 C1994 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 1292303 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={=&wt=xml} {commit=} 0 2
   [junit4]   2> 1292304 T5537 C1994 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {} 0 0
   [junit4]   2> 1292305 T5537 C1994 oassf.FileFloatSource.getFloats Loaded 
external value source external_foo_extf
   [junit4]   2> 1292305 T5537 C1994 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}foo_extf&indent=on&fl=*,score&rows=100&wt=xml} hits=25 
status=0 QTime=1 
   [junit4]   2> ASYNC  NEW_CORE C1995 name=collection1 
org.apache.solr.core.SolrCore@7984f979
   [junit4]   2> 1292327 T5537 C1995 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1292327 T5537 C1995 oasu.DirectUpdateHandler2.commit No 
uncommitted changes. Skipping IW.commit.
   [junit4]   2> 1292327 T5537 C1995 oasc.SolrCore.openNewSearcher 
SolrIndexSearcher has not changed - not re-opening: 
org.apache.solr.search.SolrIndexSearcher
   [junit4]   2> 1292328 T5537 C1995 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 1292328 T5537 C1995 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={=&wt=xml} {commit=} 0 1
   [junit4]   2> 1292328 T5537 C1995 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {} 0 0
   [junit4]   2> 1292330 T5537 C1995 oassf.FileFloatSource.getFloats Loaded 
external value source external_foo_extf
   [junit4]   2> 1292331 T5537 C1995 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}foo_extf&indent=on&fl=*,score&rows=100&wt=xml} hits=25 
status=0 QTime=2 
   [junit4]   2> 1292336 T5537 C1995 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1292337 T5537 C1995 oasu.DirectUpdateHandler2.commit No 
uncommitted changes. Skipping IW.commit.
   [junit4]   2> 1292339 T5537 C1995 oasc.SolrCore.openNewSearcher 
SolrIndexSearcher has not changed - not re-opening: 
org.apache.solr.search.SolrIndexSearcher
   [junit4]   2> 1292339 T5537 C1995 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 1292339 T5537 C1995 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={=&wt=xml} {commit=} 0 3
   [junit4]   2> 1292339 T5537 C1995 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {} 0 0
   [junit4]   2> 1292341 T5537 C1995 oassf.FileFloatSource.getFloats Loaded 
external value source external_foo_extf
   [junit4]   2> 1292342 T5537 C1995 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}foo_extf&indent=on&fl=*,score&rows=100&wt=xml} hits=25 
status=0 QTime=2 
   [junit4]   2> 1292347 T5537 C1995 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1292348 T5537 C1995 oasu.DirectUpdateHandler2.commit No 
uncommitted changes. Skipping IW.commit.
   [junit4]   2> 1292348 T5537 C1995 oasc.SolrCore.openNewSearcher 
SolrIndexSearcher has not changed - not re-opening: 
org.apache.solr.search.SolrIndexSearcher
   [junit4]   2> 1292348 T5537 C1995 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 1292349 T5537 C1995 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={=&wt=xml} {commit=} 0 2
   [junit4]   2> 1292349 T5537 C1995 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {} 0 0
   [junit4]   2> 1292351 T5537 C1995 oassf.FileFloatSource.getFloats Loaded 
external value source external_foo_extf
   [junit4]   2> 1292352 T5537 C1995 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}foo_extf&indent=on&fl=*,score&rows=100&wt=xml} hits=25 
status=0 QTime=3 
   [junit4]   2> 1292359 T5537 C1995 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1292359 T5537 C1995 oasu.DirectUpdateHandler2.commit No 
uncommitted changes. Skipping IW.commit.
   [junit4]   2> 1292360 T5537 C1995 oasc.SolrCore.openNewSearcher 
SolrIndexSearcher has not changed - not re-opening: 
org.apache.solr.search.SolrIndexSearcher
   [junit4]   2> 1292360 T5537 C1995 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 1292361 T5537 C1995 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={=&wt=xml} {commit=} 0 2
   [junit4]   2> 1292361 T5537 C1995 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {} 0 0
   [junit4]   2> 1292364 T5537 C1995 oassf.FileFloatSource.getFloats Loaded 
external value source external_foo_extf
   [junit4]   2> 1292364 T5537 C1995 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}foo_extf&indent=on&fl=*,score&rows=100&wt=xml} hits=25 
status=0 QTime=2 
   [junit4]   2> 1292369 T5537 oas.SolrTestCaseJ4.tearDown ###Ending 
testExternalField
   [junit4]   2> 1292373 T5537 oas.SolrTestCaseJ4.setUp ###Starting 
testPseudoFieldFunctions
   [junit4]   2> 1292374 T5537 C1995 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[1]} 0 0
   [junit4]   2> 1292375 T5537 C1995 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[2]} 0 0
   [junit4]   2> 1292375 T5537 C1995 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1292378 T5537 C1995 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@7b01b479 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2e3253fb),segFN=segments_d,generation=13}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@7b01b479 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2e3253fb),segFN=segments_e,generation=14}
   [junit4]   2> 1292379 T5537 C1995 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 14
   [junit4]   2> 1292379 T5537 C1995 oass.SolrIndexSearcher.<init> Opening 
Searcher@6900c503[collection1] main
   [junit4]   2> 1292380 T5537 C1995 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 1292380 T5539 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@6900c503[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_8(5.1.0):c2)
 Uninverting(_9(5.1.0):c2/1:delGen=1) Uninverting(_a(5.1.0):c23/4:delGen=1) 
Uninverting(_b(5.1.0):c1) Uninverting(_c(5.1.0):c2)))}
   [junit4]   2> 1292381 T5537 C1995 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 6
   [junit4]   2> 1292391 T5537 C1995 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=id:1&fl=a:1,b:2.0,c:'X',d:{!func}foo_s,e:{!func}bar_s&wt=xml} hits=1 
status=0 QTime=10 
   [junit4]   2> 1292393 T5537 oas.SolrTestCaseJ4.assertJQ ERROR query failed 
JSON validation. error=unexpected map keys [e] @ response/docs/[0]
   [junit4]   2>         expected =/response/docs/[0]=={'a':1, 
'b':2.0,'c':'X','d':'A'}
   [junit4]   2>         response = {
   [junit4]   2>          "responseHeader":{
   [junit4]   2>            "status":0,
   [junit4]   2>            "QTime":10},
   [junit4]   2>          "response":{"numFound":1,"start":0,"docs":[
   [junit4]   2>              {
   [junit4]   2>                "a":1,
   [junit4]   2>                "b":2.0,
   [junit4]   2>                "c":"X",
   [junit4]   2>                "d":"A",
   [junit4]   2>                "e":null}]
   [junit4]   2>          }}
   [junit4]   2>        
   [junit4]   2>         request = 
q=id:1&fl=a:1,b:2.0,c:'X',d:{!func}foo_s,e:{!func}bar_s&wt=xml
   [junit4]   2> 1292393 T5537 oas.SolrTestCaseJ4.tearDown ###Ending 
testPseudoFieldFunctions
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=TestFunctionQuery 
-Dtests.method=testPseudoFieldFunctions -Dtests.seed=2BA203EDCC552176 
-Dtests.slow=true -Dtests.locale=ar_DZ -Dtests.timezone=Asia/Karachi 
-Dtests.asserts=true -Dtests.file.encoding=UTF-8
   [junit4] ERROR   0.03s J0 | TestFunctionQuery.testPseudoFieldFunctions <<<
   [junit4]    > Throwable #1: java.lang.RuntimeException: unexpected map keys 
[e] @ response/docs/[0]
   [junit4]    >        at 
__randomizedtesting.SeedInfo.seed([2BA203EDCC552176:7598E190F0C3DD3A]:0)
   [junit4]    >        at 
org.apache.solr.SolrTestCaseJ4.assertJQ(SolrTestCaseJ4.java:882)
   [junit4]    >        at 
org.apache.solr.SolrTestCaseJ4.assertJQ(SolrTestCaseJ4.java:829)
   [junit4]    >        at 
org.apache.solr.search.function.TestFunctionQuery.testPseudoFieldFunctions(TestFunctionQuery.java:739)
   [junit4]    >        at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 1292409 T5537 oas.SolrTestCaseJ4.setUp ###Starting 
testExternalFieldValueSourceParser
   [junit4]   2> 1292410 T5537 C1995 oasu.DirectUpdateHandler2.deleteAll 
[collection1] REMOVING ALL DOCUMENTS FROM INDEX
   [junit4]   2> 1292411 T5537 C1995 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 1
   [junit4]   2> 1292412 T5537 C1995 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[100.0]} 0 0
   [junit4]   2> 1292413 T5537 C1995 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[-4.0]} 0 0
   [junit4]   2> 1292414 T5537 C1995 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[0.0]} 0 0
   [junit4]   2> 1292415 T5537 C1995 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1292417 T5537 C1995 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@7b01b479 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2e3253fb),segFN=segments_e,generation=14}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@7b01b479 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2e3253fb),segFN=segments_f,generation=15}
   [junit4]   2> 1292417 T5537 C1995 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 15
   [junit4]   2> 1292419 T5537 C1995 oass.SolrIndexSearcher.<init> Opening 
Searcher@460bfc9c[collection1] main
   [junit4]   2> 1292419 T5537 C1995 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 1292419 T5539 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@460bfc9c[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_d(5.1.0):c3)))}
   [junit4]   2> 1292420 T5537 C1995 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 5
   [junit4]   2> 1292421 T5537 C1995 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[10.0]} 0 0
   [junit4]   2> 1292422 T5537 C1995 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1292425 T5537 C1995 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@7b01b479 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2e3253fb),segFN=segments_f,generation=15}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@7b01b479 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2e3253fb),segFN=segments_g,generation=16}
   [junit4]   2> 1292426 T5537 C1995 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 16
   [junit4]   2> 1292428 T5537 C1995 oass.SolrIndexSearcher.<init> Opening 
Searcher@4cc9c607[collection1] main
   [junit4]   2> 1292428 T5537 C1995 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 1292428 T5539 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@4cc9c607[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_d(5.1.0):c3)
 Uninverting(_e(5.1.0):c1)))}
   [junit4]   2> 1292429 T5537 C1995 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 7
   [junit4]   2> 1292431 T5537 C1995 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[25.0]} 0 1
   [junit4]   2> 1292432 T5537 C1995 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[5.0]} 0 0
   [junit4]   2> 1292433 T5537 C1995 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[5.0]} 0 0
   [junit4]   2> 1292433 T5537 C1995 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[77.0]} 0 0
   [junit4]   2> 1292435 T5537 C1995 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[23.0]} 0 0
   [junit4]   2> 1292436 T5537 C1995 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[55.0]} 0 0
   [junit4]   2> 1292436 T5537 C1995 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[55.0]} 0 0
   [junit4]   2> 1292437 T5537 C1995 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[-78.0]} 0 0
   [junit4]   2> 1292438 T5537 C1995 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[-45.0]} 0 0
   [junit4]   2> 1292438 T5537 C1995 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[-24.0]} 0 0
   [junit4]   2> 1292439 T5537 C1995 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[-24.0]} 0 0
   [junit4]   2> 1292439 T5537 C1995 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[63.0]} 0 0
   [junit4]   2> 1292440 T5537 C1995 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[78.0]} 0 0
   [junit4]   2> 1292440 T5537 C1995 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[78.0]} 0 0
   [junit4]   2> 1292441 T5537 C1995 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[94.0]} 0 0
   [junit4]   2> 1292442 T5537 C1995 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[22.0]} 0 0
   [junit4]   2> 1292443 T5537 C1995 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[34.0]} 0 0
   [junit4]   2> 1292444 T5537 C1995 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[54321.0]} 0 0
   [junit4]   2> 1292445 T5537 C1995 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[261.0]} 0 0
   [junit4]   2> 1292445 T5537 C1995 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[-627.0]} 0 0
   [junit4]   2> 1292446 T5537 C1995 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[-627.0]} 0 0
   [junit4]   2> 1292447 T5537 C1995 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1292451 T5537 C1995 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@7b01b479 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2e3253fb),segFN=segments_g,generation=16}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@7b01b479 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2e3253fb),segFN=segments_h,generation=17}
   [junit4]   2> 1292451 T5537 C1995 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 17
   [junit4]   2> 1292452 T5537 C1995 oass.SolrIndexSearcher.<init> Opening 
Searcher@30fbde5d[collection1] main
   [junit4]   2> 1292453 T5539 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@30fbde5d[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_d(5.1.0):c3)
 Uninverting(_e(5.1.0):c1) Uninverting(_f(5.1.0):c21/5:delGen=1)))}
   [junit4]   2> 1292453 T5537 C1995 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 1292453 T5537 C1995 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 6
   [junit4]   2> 1292454 T5537 C1995 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1292454 T5537 C1995 oasu.DirectUpdateHandler2.commit No 
uncommitted changes. Skipping IW.commit.
   [junit4]   2> 1292454 T5537 C1995 oasc.SolrCore.openNewSearcher 
SolrIndexSearcher has not changed - not re-opening: 
org.apache.solr.search.SolrIndexSearcher
   [junit4]   2> 1292455 T5537 C1995 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 1292455 T5537 C1995 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 1
   [junit4]   2> 1292457 T5537 C1995 oassf.FileFloatSource.getFloats Loaded 
external value source external_CoMpleX fieldName _extf
   [junit4]   2> 1292458 T5537 C1995 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}field("CoMpleX+fieldName+_extf")&indent=on&fl=*,score&rows=100&wt=xml}
 hits=20 status=0 QTime=2 
   [junit4]   2> 1292459 T5537 C1995 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}log(field("CoMpleX+fieldName+_extf"))&indent=on&fl=*,score&rows=100&wt=xml}
 hits=20 status=0 QTime=0 
   [junit4]   2> 1292460 T5537 C1995 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}sqrt(field("CoMpleX+fieldName+_extf"))&indent=on&fl=*,score&rows=100&wt=xml}
 hits=20 status=0 QTime=1 
   [junit4]   2> 1292461 T5537 C1995 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[10000]} 0 0
   [junit4]   2> 1292463 T5537 C1995 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1292465 T5537 C1995 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@7b01b479 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2e3253fb),segFN=segments_h,generation=17}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@7b01b479 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2e3253fb),segFN=segments_i,generation=18}
   [junit4]   2> 1292466 T5537 C1995 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 18
   [junit4]   2> 1292466 T5537 C1995 oass.SolrIndexSearcher.<init> Opening 
Searcher@2ffb7580[collection1] main
   [junit4]   2> 1292467 T5537 C1995 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 1292467 T5539 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@2ffb7580[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_d(5.1.0):c3)
 Uninverting(_e(5.1.0):c1) Uninverting(_f(5.1.0):c21/5:delGen=1) 
Uninverting(_g(5.1.0):c1)))}
   [junit4]   2> 1292467 T5537 C1995 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 5
   [junit4]   2> 1292469 T5537 C1995 oassf.FileFloatSource.getFloats Loaded 
external value source external_CoMpleX fieldName _extf
   [junit4]   2> 1292470 T5537 C1995 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}sqrt(field("CoMpleX+fieldName+_extf"))&indent=on&fl=*,score&rows=100&wt=xml}
 hits=21 status=0 QTime=2 
   [junit4]   2> 1292470 T5537 oas.SolrTestCaseJ4.tearDown ###Ending 
testExternalFieldValueSourceParser
   [junit4]   2> 1292473 T5537 oas.SolrTestCaseJ4.setUp ###Starting 
testExternalFileFieldNumericKey
   [junit4]   2> 1292474 T5537 C1995 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[991]} 0 1
   [junit4]   2> 1292474 T5537 C1995 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[992]} 0 0
   [junit4]   2> 1292475 T5537 C1995 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[993]} 0 0
   [junit4]   2> 1292475 T5537 C1995 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1292479 T5537 C1995 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@7b01b479 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2e3253fb),segFN=segments_i,generation=18}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@7b01b479 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2e3253fb),segFN=segments_j,generation=19}
   [junit4]   2> 1292479 T5537 C1995 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 19
   [junit4]   2> 1292480 T5537 C1995 oass.SolrIndexSearcher.<init> Opening 
Searcher@36299d53[collection1] main
   [junit4]   2> 1292480 T5537 C1995 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 1292481 T5539 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@36299d53[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_d(5.1.0):c3)
 Uninverting(_e(5.1.0):c1) Uninverting(_f(5.1.0):c21/5:delGen=1) 
Uninverting(_g(5.1.0):c1) Uninverting(_h(5.1.0):c3)))}
   [junit4]   2> 1292481 T5537 C1995 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 6
   [junit4]   2> 1292485 T5537 C1995 oassf.FileFloatSource.getFloats ERROR 
Error loading external value source + fileName + 
org.apache.solr.common.SolrException: Invalid Number: 
   [junit4]   2> 1292485 T5537 C1995 oassf.FileFloatSource.getFloats Loaded 
external value source external_eff_trie
   [junit4]   2> 1292486 T5537 C1995 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}eff_trie&indent=on&fl=*,score&rows=100&wt=xml} hits=24 
status=0 QTime=3 
   [junit4]   2> 1292487 T5537 oas.SolrTestCaseJ4.tearDown ###Ending 
testExternalFileFieldNumericKey
   [junit4]   2> 1292491 T5537 oas.SolrTestCaseJ4.setUp ###Starting 
testExternalFileFieldStringKeys
   [junit4]   2> 1292492 T5537 C1995 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[991]} 0 1
   [junit4]   2> 1292493 T5537 C1995 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[992]} 0 0
   [junit4]   2> 1292493 T5537 C1995 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[993]} 0 0
   [junit4]   2> 1292494 T5537 C1995 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1292500 T5537 C1995 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@7b01b479 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2e3253fb),segFN=segments_j,generation=19}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@7b01b479 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2e3253fb),segFN=segments_k,generation=20}
   [junit4]   2> 1292500 T5537 C1995 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 20
   [junit4]   2> 1292500 T5537 C1995 oass.SolrIndexSearcher.<init> Opening 
Searcher@769b4e41[collection1] main
   [junit4]   2> 1292501 T5539 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@769b4e41[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_d(5.1.0):c3)
 Uninverting(_e(5.1.0):c1) Uninverting(_f(5.1.0):c21/5:delGen=1) 
Uninverting(_g(5.1.0):c1) Uninverting(_i(5.1.0):c3)))}
   [junit4]   2> 1292501 T5537 C1995 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 1292501 T5537 C1995 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 7
   [junit4]   2> 1292504 T5537 C1995 oassf.FileFloatSource.getFloats Loaded 
external value source external_foo_extfs
   [junit4]   2> 1292504 T5537 C1995 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}foo_extfs&indent=on&fl=*,score&rows=100&wt=xml} hits=24 
status=0 QTime=1 
   [junit4]   2> 1292505 T5537 oas.SolrTestCaseJ4.tearDown ###Ending 
testExternalFileFieldStringKeys
   [junit4]   2> 1292508 T5537 oas.SolrTestCaseJ4.setUp ###Starting testGeneral
   [junit4]   2> 1292508 T5537 C1995 oasu.DirectUpdateHandler2.deleteAll 
[collection1] REMOVING ALL DOCUMENTS FROM INDEX
   [junit4]   2> 1292509 T5537 C1995 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 1
   [junit4]   2> 1292510 T5537 C1995 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[1]} 0 1
   [junit4]   2> 1292511 T5537 C1995 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[2]} 0 0
   [junit4]   2> 1292512 T5537 C1995 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1292513 T5537 C1995 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@7b01b479 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2e3253fb),segFN=segments_k,generation=20}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@7b01b479 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2e3253fb),segFN=segments_l,generation=21}
   [junit4]   2> 1292514 T5537 C1995 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 21
   [junit4]   2> 1292515 T5537 C1995 oass.SolrIndexSearcher.<init> Opening 
Searcher@655e10d6[collection1] main
   [junit4]   2> 1292515 T5537 C1995 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 1292515 T5539 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@655e10d6[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_j(5.1.0):c2)))}
   [junit4]   2> 1292517 T5537 C1995 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 6
   [junit4]   2> 1292518 T5537 C1995 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[3]} 0 1
   [junit4]   2> 1292519 T5537 C1995 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[4]} 0 0
   [junit4]   2> 1292519 T5537 C1995 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1292522 T5537 C1995 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@7b01b479 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2e3253fb),segFN=segments_l,generation=21}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@7b01b479 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2e3253fb),segFN=segments_m,generation=22}
   [junit4]   2> 1292523 T5537 C1995 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 22
   [junit4]   2> 1292523 T5537 C1995 oass.SolrIndexSearcher.<init> Opening 
Searcher@59d6d0b9[collection1] main
   [junit4]   2> 1292523 T5537 C1995 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 1292524 T5539 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@59d6d0b9[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_j(5.1.0):c2)
 Uninverting(_k(5.1.0):c2)))}
   [junit4]   2> 1292524 T5537 C1995 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 5
   [junit4]   2> 1292525 T5537 C1995 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[5]} 0 0
   [junit4]   2> 1292525 T5537 C1995 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[6]} 0 0
   [junit4]   2> 1292526 T5537 C1995 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1292528 T5537 C1995 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@7b01b479 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2e3253fb),segFN=segments_m,generation=22}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@7b01b479 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2e3253fb),segFN=segments_n,generation=23}
   [junit4]   2> 1292529 T5537 C1995 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 23
   [junit4]   2> 1292529 T5537 C1995 oass.SolrIndexSearcher.<init> Opening 
Searcher@341cdbe0[collection1] main
   [junit4]   2> 1292529 T5537 C1995 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 1292530 T5539 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@341cdbe0[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_j(5.1.0):c2)
 Uninverting(_k(5.1.0):c2) Uninverting(_l(5.1.0):c2)))}
   [junit4]   2> 1292530 T5537 C1995 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 4
   [junit4]   2> 1292537 T5537 C1995 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q={!func}numdocs()&fl=*,score&fq=id:6&wt=xml} 
hits=1 status=0 QTime=6 
   [junit4]   2> 1292538 T5537 C1995 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q={!func}maxdoc()&fl=*,score&fq=id:6&wt=xml} 
hits=1 status=0 QTime=0 
   [junit4]   2> 1292540 T5537 C1995 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}docfreq(a_t,cow)&fl=*,score&fq=id:6&wt=xml} hits=1 status=0 
QTime=1 
   [junit4]   2> 1292541 T5537 C1995 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}docfreq('a_t','cow')&fl=*,score&fq=id:6&wt=xml} hits=1 
status=0 QTime=1 
   [junit4]   2> 1292541 T5537 C1995 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}docfreq($field,$value)&field=a_t&fl=*,score&fq=id:6&value=cow&wt=xml}
 hits=1 st

[...truncated too long message...]

c(1)&wt=xml} hits=1 status=0 QTime=0 
   [junit4]   2> 1293004 T5537 C1996 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=id:1&fl=t:true(),f:false(),tt:{!func}true,ff:{!func}false&wt=xml} 
hits=1 status=0 QTime=4 
   [junit4]   2> 1293006 T5537 C1996 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q1=text:hello&q=id:1&q2=text:there&fl=t:exists(query($q1)),f:exists(query($q2))&wt=xml}
 hits=1 status=0 QTime=1 
   [junit4]   2> 1293006 T5537 C1996 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=id:1&fl=a1:if(true,'A','B')&fl=b1:if(false,'A',testfunc('B'))&wt=xml} 
hits=1 status=0 QTime=0 
   [junit4]   2> 1293013 T5537 C1996 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=id:1&fl=t1:and(testfunc(true),true)&fl=f1:and(true,false)&fl=f2:and(false,true)&fl=f3:and(false,false)&wt=xml}
 hits=1 status=0 QTime=6 
   [junit4]   2> 1293015 T5537 C1996 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=id:1&fl=t1:or(testfunc(true),true)&fl=t2:or(true,false)&fl=t3:or(false,true)&fl=f1:or(false,false)&wt=xml}
 hits=1 status=0 QTime=1 
   [junit4]   2> 1293015 T5537 C1996 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=id:1&fl=f1:xor(testfunc(true),true)&fl=t1:xor(true,false)&fl=t2:xor(false,true)&fl=f2:xor(false,false)&wt=xml}
 hits=1 status=0 QTime=0 
   [junit4]   2> 1293016 T5537 C1996 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=id:1&fl=t:not(testfunc(false)),f:not(true)&wt=xml} hits=1 status=0 
QTime=0 
   [junit4]   2> 1293018 T5537 C1996 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=id:1&fl=x:def(id,testfunc(123.0)),+y:def(foo_f,234.0)&wt=xml} hits=1 
status=0 QTime=2 
   [junit4]   2> 1293018 T5537 C1996 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=id:1&fl=x:def(foo_s,'Q'),+y:def(missing_s,'W')&wt=xml} hits=1 
status=0 QTime=0 
   [junit4]   2> 1293020 T5537 C1996 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=id:1&fl=a:not(0),+b:not(1),+c:not(0.0),+d:not(1.1),+e:not('A')&wt=xml}
 hits=1 status=0 QTime=0 
   [junit4]   2> 1293020 T5537 oas.SolrTestCaseJ4.tearDown ###Ending 
testBooleanFunctions
   [junit4]   2> 1293021 T5537 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> 1293021 T5537 oasc.CoreContainer.shutdown Shutting down 
CoreContainer instance=1306916543
   [junit4]   2> 1293022 T5537 oasc.SolrCore.close [collection1]  CLOSING 
SolrCore org.apache.solr.core.SolrCore@7984f979
   [junit4]   2> 1293023 T5537 oasu.DirectUpdateHandler2.close closing 
DirectUpdateHandler2{commits=43,autocommits=0,soft 
autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=120,cumulative_deletesById=0,cumulative_deletesByQuery=5,cumulative_errors=0}
   [junit4]   2> 1293024 T5537 oasu.SolrCoreState.decrefSolrCoreState Closing 
SolrCoreState
   [junit4]   2> 1293024 T5537 oasu.DefaultSolrCoreState.closeIndexWriter 
SolrCoreState ref count has reached 0 - closing IndexWriter
   [junit4]   2> 1293024 T5537 oasu.DefaultSolrCoreState.closeIndexWriter 
closing IndexWriter with IndexWriterCloser
   [junit4]   2> 1293025 T5537 oasc.SolrCore.closeSearcher [collection1] 
Closing main searcher on request.
   [junit4]   2> 1293025 T5537 oasc.CachingDirectoryFactory.close Closing 
MockDirectoryFactory - 2 directories currently being tracked
   [junit4]   2> 1293026 T5537 oasc.CachingDirectoryFactory.closeCacheValue 
looking to close 
/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.search.function.TestFunctionQuery
 2BA203EDCC552176-001/init-core-data-001 
[CachedDir<<refCount=0;path=/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.search.function.TestFunctionQuery
 2BA203EDCC552176-001/init-core-data-001;done=false>>]
   [junit4]   2> 1293026 T5537 oasc.CachingDirectoryFactory.close Closing 
directory: 
/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.search.function.TestFunctionQuery
 2BA203EDCC552176-001/init-core-data-001
   [junit4]   2> 1293026 T5537 oasc.CachingDirectoryFactory.closeCacheValue 
looking to close 
/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.search.function.TestFunctionQuery
 2BA203EDCC552176-001/init-core-data-001/index 
[CachedDir<<refCount=0;path=/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.search.function.TestFunctionQuery
 2BA203EDCC552176-001/init-core-data-001/index;done=false>>]
   [junit4]   2> 1293027 T5537 oasc.CachingDirectoryFactory.close Closing 
directory: 
/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.search.function.TestFunctionQuery
 2BA203EDCC552176-001/init-core-data-001/index
   [junit4]   2> NOTE: leaving temporary files on disk at: 
/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.search.function.TestFunctionQuery
 2BA203EDCC552176-001
   [junit4]   2> NOTE: test params are: codec=Asserting(Lucene50): 
{x_td=PostingsFormat(name=Asserting), const_s=PostingsFormat(name=Asserting), 
x_i=Lucene50(blocksize=128), 1_s=BlockTreeOrds(blocksize=128), 
a_tdt=Lucene50(blocksize=128), eff_ti=PostingsFormat(name=Asserting), 
foo_s=Lucene50(blocksize=128), x_s=Lucene50(blocksize=128), 
y_td=Lucene50(blocksize=128), 1-1_s=BlockTreeOrds(blocksize=128), CoMpleX " 
fieldName _f=Lucene50(blocksize=128), foo_tl=BlockTreeOrds(blocksize=128), 
foo_ti=Lucene50(blocksize=128), foo_tf=PostingsFormat(name=Asserting), 
b_tdt=PostingsFormat(name=Asserting), sfile_s=PostingsFormat(name=Asserting), 
x:x_i=Lucene50(blocksize=128), a_t=Lucene50(blocksize=128), 
foo_d=PostingsFormat(name=Asserting), id=PostingsFormat(name=Asserting), 
text=BlockTreeOrds(blocksize=128), yak_i=BlockTreeOrds(blocksize=128), 
foo_f=BlockTreeOrds(blocksize=128)}, docValues:{}, 
sim=RandomSimilarityProvider(queryNorm=false,coord=crazy): {}, locale=ar_DZ, 
timezone=Asia/Karachi
   [junit4]   2> NOTE: Mac OS X 10.8.5 x86_64/Oracle Corporation 1.8.0_40 
(64-bit)/cpus=3,threads=1,free=69506544,total=308281344
   [junit4]   2> NOTE: All tests run in this JVM: [TestAtomicUpdateErrorCases, 
TestTrackingShardHandlerFactory, TestComplexPhraseQParserPlugin, ZkCLITest, 
TimeZoneUtilsTest, DocValuesMissingTest, BJQParserTest, 
LeaderFailoverAfterPartitionTest, TestHashPartitioner, 
TestManagedSynonymFilterFactory, SolrCoreCheckLockOnStartupTest, 
TestFieldResource, TestQueryTypes, CoreAdminHandlerTest, SolrCoreTest, 
SolrTestCaseJ4Test, TestManagedSchemaFieldResource, JSONWriterTest, 
SuggestComponentTest, TestFileDictionaryLookup, CircularListTest, 
TestAnalyzedSuggestions, TestExactSharedStatsCache, TestLRUCache, 
DeleteShardTest, SliceStateTest, TestUpdate, TestCollationField, 
TestIndexSearcher, RequestLoggingTest, TestInitQParser, 
CoreAdminRequestStatusTest, TestStressVersions, TestFreeTextSuggestions, 
UUIDFieldTest, DistributedDebugComponentTest, TestReplicaProperties, 
DOMUtilTest, NoCacheHeaderTest, ZkControllerTest, FacetPivotSmallTest, 
TestJmxIntegration, LeaderElectionTest, TestNRTOpen, TestSchemaVersionResource, 
TestReplicationHandler, TestArbitraryIndexDir, TestDistributedMissingSort, 
TestManagedResourceStorage, RollingRestartTest, NumericFieldsTest, 
TestCloudSchemaless, TestLazyCores, ClusterStateUpdateTest, 
TestSweetSpotSimilarityFactory, TestDistribDocBasedVersion, 
TestSolrConfigHandlerConcurrent, TestExactStatsCache, TestMaxScoreQueryParser, 
DistributedIntervalFacetingTest, TestQueryUtils, TestFieldSortValues, 
DistribCursorPagingTest, TestPivotHelperCode, AssignTest, PrimUtilsTest, 
UnloadDistributedZkTest, ResponseLogComponentTest, HighlighterMaxOffsetTest, 
TestFastLRUCache, TestReRankQParserPlugin, SuggesterTest, ClusterStateTest, 
BasicDistributedZkTest, TestPerFieldSimilarity, 
DistribDocExpirationUpdateProcessorTest, TestBM25SimilarityFactory, 
DistributedFacetPivotWhiteBoxTest, TestStressLucene, TestRandomDVFaceting, 
TestDynamicFieldResource, FieldAnalysisRequestHandlerTest, 
PingRequestHandlerTest, CollectionsAPIAsyncDistributedZkTest, 
TestHighFrequencyDictionaryFactory, ActionThrottleTest, SuggesterFSTTest, 
TestRawResponseWriter, CursorMarkTest, CloudExitableDirectoryReaderTest, 
DocValuesMultiTest, TestDocumentBuilder, TestShortCircuitedRequests, 
TestWriterPerf, HdfsDirectoryTest, ChangedSchemaMergeTest, DistanceUnitsTest, 
TestOverriddenPrefixQueryForCustomFieldType, TestDistributedSearch, 
TestStressReorder, TestFunctionQuery]
   [junit4] Completed on J0 in 1.44s, 15 tests, 1 error <<< FAILURES!

[...truncated 773 lines...]
BUILD FAILED
/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/build.xml:529: The following 
error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/build.xml:477: The following 
error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/build.xml:61: The following 
error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/extra-targets.xml:39: The 
following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/build.xml:191: The 
following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/common-build.xml:509: The 
following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/lucene/common-build.xml:1370: 
The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/lucene/common-build.xml:976: 
There were test failures: 475 suites, 1892 tests, 1 error, 53 ignored (20 
assumptions)

Total time: 66 minutes 51 seconds
Build step 'Invoke Ant' marked build as failure
[description-setter] Description set: Java: 64bit/jdk1.8.0 
-XX:-UseCompressedOops -XX:+UseG1GC
Archiving artifacts
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any



---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org
For additional commands, e-mail: dev-h...@lucene.apache.org