Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/12029/
Java: 64bit/jdk1.8.0_60-ea-b06 -XX:+UseCompressedOops -XX:+UseSerialGC

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([E920AC7E46B8C7CB:B71A4E037A2E3B87]: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 9506 lines...]
   [junit4] Suite: org.apache.solr.search.function.TestFunctionQuery
   [junit4]   2> Creating dataDir: 
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.search.function.TestFunctionQuery
 E920AC7E46B8C7CB-001/init-core-data-001
   [junit4]   2> 353638 T3744 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl 
(true) and clientAuth (false)
   [junit4]   2> 353638 T3744 oas.SolrTestCaseJ4.initCore ####initCore
   [junit4]   2> 353638 T3744 oasc.SolrResourceLoader.<init> new 
SolrResourceLoader for directory: 
'/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/'
   [junit4]   2> 353639 T3744 oasc.SolrResourceLoader.replaceClassLoader Adding 
'file:/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/lib/classes/'
 to classloader
   [junit4]   2> 353639 T3744 oasc.SolrResourceLoader.replaceClassLoader Adding 
'file:/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/lib/README'
 to classloader
   [junit4]   2> 353647 T3744 oasc.SolrConfig.refreshRequestParams current 
version of requestparams : -1
   [junit4]   2> 353649 T3744 oasc.SolrConfig.<init> Using Lucene MatchVersion: 
6.0.0
   [junit4]   2> 353654 T3744 oasc.SolrConfig.<init> Loaded SolrConfig: 
solrconfig-functionquery.xml
   [junit4]   2> 353655 T3744 oass.IndexSchema.readSchema Reading Solr Schema 
from 
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/schema11.xml
   [junit4]   2> 353658 T3744 oass.IndexSchema.readSchema [null] Schema 
name=example
   [junit4]   2> 353680 T3744 oass.IndexSchema.readSchema default search field 
in schema is text
   [junit4]   2> 353681 T3744 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 353683 T3744 oasc.SolrResourceLoader.locateSolrHome JNDI not 
configured for solr (NoInitialContextEx)
   [junit4]   2> 353683 T3744 oasc.SolrResourceLoader.locateSolrHome using 
system property solr.solr.home: 
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr
   [junit4]   2> 353683 T3744 oasc.SolrResourceLoader.<init> new 
SolrResourceLoader for directory: 
'/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/'
   [junit4]   2> 353689 T3744 oasc.CoreContainer.<init> New CoreContainer 
1303020405
   [junit4]   2> 353689 T3744 oasc.CoreContainer.load Loading cores into 
CoreContainer 
[instanceDir=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/]
   [junit4]   2> 353689 T3744 oasc.CoreContainer.load loading shared library: 
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/lib
   [junit4]   2> 353689 T3744 oasc.SolrResourceLoader.addToClassLoader WARN 
Can't find (or read) directory to add to classloader: lib (resolved as: 
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/lib).
   [junit4]   2> 353702 T3744 oashc.HttpShardHandlerFactory.getParameter 
Setting socketTimeout to: 600000
   [junit4]   2> 353703 T3744 oashc.HttpShardHandlerFactory.getParameter 
Setting urlScheme to: null
   [junit4]   2> 353703 T3744 oashc.HttpShardHandlerFactory.getParameter 
Setting connTimeout to: 60000
   [junit4]   2> 353703 T3744 oashc.HttpShardHandlerFactory.getParameter 
Setting maxConnectionsPerHost to: 20
   [junit4]   2> 353703 T3744 oashc.HttpShardHandlerFactory.getParameter 
Setting maxConnections to: 10000
   [junit4]   2> 353703 T3744 oashc.HttpShardHandlerFactory.getParameter 
Setting corePoolSize to: 0
   [junit4]   2> 353703 T3744 oashc.HttpShardHandlerFactory.getParameter 
Setting maximumPoolSize to: 2147483647
   [junit4]   2> 353703 T3744 oashc.HttpShardHandlerFactory.getParameter 
Setting maxThreadIdleTime to: 5
   [junit4]   2> 353703 T3744 oashc.HttpShardHandlerFactory.getParameter 
Setting sizeOfQueue to: -1
   [junit4]   2> 353703 T3744 oashc.HttpShardHandlerFactory.getParameter 
Setting fairnessPolicy to: false
   [junit4]   2> 353704 T3744 oashc.HttpShardHandlerFactory.getParameter 
Setting useRetries to: false
   [junit4]   2> 353705 T3744 oasu.UpdateShardHandler.<init> Creating 
UpdateShardHandler HTTP client with params: 
socketTimeout=30000&connTimeout=30000&retry=true
   [junit4]   2> 353706 T3744 oasl.LogWatcher.createWatcher SLF4J impl is 
org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 353707 T3744 oasl.LogWatcher.newRegisteredLogWatcher 
Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 353707 T3744 oasc.CoreContainer.load Node Name: testNode
   [junit4]   2> 353707 T3744 oasc.CoreDescriptor.<init> CORE DESCRIPTOR: 
{name=collection1, config=solrconfig-functionquery.xml, transient=false, 
schema=schema11.xml, loadOnStartup=true, instanceDir=collection1, 
collection=collection1, 
absoluteInstDir=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/,
 
dataDir=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.search.function.TestFunctionQuery
 E920AC7E46B8C7CB-001/init-core-data-001, shard=shard1}
   [junit4]   2> 353708 T3745 oasc.SolrResourceLoader.<init> new 
SolrResourceLoader for directory: 
'/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/'
   [junit4]   2> 353708 T3745 oasc.SolrResourceLoader.replaceClassLoader Adding 
'file:/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/lib/classes/'
 to classloader
   [junit4]   2> 353708 T3745 oasc.SolrResourceLoader.replaceClassLoader Adding 
'file:/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/lib/README'
 to classloader
   [junit4]   2> 353716 T3745 oasc.SolrConfig.refreshRequestParams current 
version of requestparams : -1
   [junit4]   2> 353718 T3745 oasc.SolrConfig.<init> Using Lucene MatchVersion: 
6.0.0
   [junit4]   2> 353723 T3745 oasc.SolrConfig.<init> Loaded SolrConfig: 
solrconfig-functionquery.xml
   [junit4]   2> 353724 T3745 oass.IndexSchema.readSchema Reading Solr Schema 
from 
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/schema11.xml
   [junit4]   2> 353726 T3745 oass.IndexSchema.readSchema [collection1] Schema 
name=example
   [junit4]   2> 353745 T3745 oass.IndexSchema.readSchema default search field 
in schema is text
   [junit4]   2> 353745 T3745 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 353747 T3745 oasc.CoreContainer.create Creating SolrCore 
'collection1' using configuration from instancedir 
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/
   [junit4]   2> 353747 T3745 oasc.SolrCore.initDirectoryFactory 
org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 353747 T3745 oasc.SolrCore.<init> [collection1] Opening new 
SolrCore at 
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/,
 
dataDir=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.search.function.TestFunctionQuery
 E920AC7E46B8C7CB-001/init-core-data-001/
   [junit4]   2> 353747 T3745 oasc.SolrCore.<init> JMX monitoring not detected 
for core: collection1
   [junit4]   2> 353747 T3745 oasc.CachingDirectoryFactory.get return new 
directory for 
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.search.function.TestFunctionQuery
 E920AC7E46B8C7CB-001/init-core-data-001
   [junit4]   2> 353748 T3745 oasc.SolrCore.getNewIndexDir New index directory 
detected: old=null 
new=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.search.function.TestFunctionQuery
 E920AC7E46B8C7CB-001/init-core-data-001/index/
   [junit4]   2> 353748 T3745 oasc.SolrCore.initIndex WARN [collection1] Solr 
index directory 
'/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.search.function.TestFunctionQuery
 E920AC7E46B8C7CB-001/init-core-data-001/index' doesn't exist. Creating new 
index...
   [junit4]   2> 353748 T3745 oasc.CachingDirectoryFactory.get return new 
directory for 
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.search.function.TestFunctionQuery
 E920AC7E46B8C7CB-001/init-core-data-001/index
   [junit4]   2> 353748 T3745 oasu.RandomMergePolicy.<init> RandomMergePolicy 
wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: 
maxMergeAtOnce=25, maxMergeAtOnceExplicit=47, maxMergedSegmentMB=69.4765625, 
floorSegmentMB=1.076171875, forceMergeDeletesPctAllowed=15.213841425657339, 
segmentsPerTier=32.0, maxCFSSegmentSizeMB=8.796093022207999E12, 
noCFSRatio=0.7962630161231019
   [junit4]   2> 353748 T3745 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@3e2ec8c7 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@91e8268),segFN=segments_1,generation=1}
   [junit4]   2> 353749 T3745 oasc.SolrDeletionPolicy.updateCommits newest 
commit generation = 1
   [junit4]   2> 353750 T3745 oasc.SolrCore.loadUpdateProcessorChains no 
updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 353751 T3745 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 353752 T3745 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 353752 T3745 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 353753 T3745 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 353754 T3745 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> 353754 T3745 oasc.SolrCore.initStatsCache Using default 
statsCache cache: org.apache.solr.search.stats.LocalStatsCache
   [junit4]   2> 353754 T3745 oasu.CommitTracker.<init> Hard AutoCommit: 
disabled
   [junit4]   2> 353755 T3745 oasu.CommitTracker.<init> Soft AutoCommit: 
disabled
   [junit4]   2> 353755 T3745 oasu.RandomMergePolicy.<init> RandomMergePolicy 
wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: 
maxMergeAtOnce=49, maxMergeAtOnceExplicit=50, maxMergedSegmentMB=36.44921875, 
floorSegmentMB=1.2255859375, forceMergeDeletesPctAllowed=22.027613562565307, 
segmentsPerTier=15.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
   [junit4]   2> 353755 T3745 oasc.SolrDeletionPolicy.onInit 
SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@3e2ec8c7 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@91e8268),segFN=segments_1,generation=1}
   [junit4]   2> 353755 T3745 oasc.SolrDeletionPolicy.updateCommits newest 
commit generation = 1
   [junit4]   2> 353755 T3745 oass.SolrIndexSearcher.<init> Opening 
Searcher@655818ce[collection1] main
   [junit4]   2> 353756 T3745 oasr.ManagedResourceStorage.newStorageIO WARN 
Cannot write to config directory 
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf;
 switching to use InMemory storage instead.
   [junit4]   2> 353756 T3745 oasr.RestManager.init Initializing RestManager 
with initArgs: {}
   [junit4]   2> 353756 T3745 oasr.ManagedResourceStorage.load Reading 
_rest_managed.json using InMemoryStorage
   [junit4]   2> 353756 T3745 oasr.RestManager.init Initializing 0 registered 
ManagedResources
   [junit4]   2> 353756 T3745 oash.ReplicationHandler.inform Commits will be 
reserved for  10000
   [junit4]   2> 353756 T3746 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@655818ce[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 353756 T3745 oasc.CoreContainer.registerCore registering core: 
collection1
   [junit4]   2> 353757 T3744 oas.SolrTestCaseJ4.initCore ####initCore end
   [junit4]   2> 353760 T3744 oas.SolrTestCaseJ4.setUp ###Starting testFuncs
   [junit4]   2> ASYNC  NEW_CORE C2059 name=collection1 
org.apache.solr.core.SolrCore@448be4f
   [junit4]   2> 353761 T3744 C2059 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[1]} 0 1
   [junit4]   2> 353763 T3744 C2059 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 353764 T3744 C2059 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@3e2ec8c7 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@91e8268),segFN=segments_1,generation=1}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@3e2ec8c7 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@91e8268),segFN=segments_2,generation=2}
   [junit4]   2> 353765 T3744 C2059 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 2
   [junit4]   2> 353766 T3744 C2059 oass.SolrIndexSearcher.<init> Opening 
Searcher@2866236c[collection1] main
   [junit4]   2> 353767 T3744 C2059 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 353767 T3746 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@2866236c[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.0.0):c1)))}
   [junit4]   2> 353767 T3744 C2059 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 4
   [junit4]   2> 353770 T3744 C2059 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q=1.0&defType=func&fl=*,score&fq=id:1&wt=xml} 
hits=1 status=0 QTime=2 
   [junit4]   2> 353771 T3744 C2059 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q=e()&defType=func&fl=*,score&fq=id:1&wt=xml} 
hits=1 status=0 QTime=1 
   [junit4]   2> 353771 T3744 C2059 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q=pi()&defType=func&fl=*,score&fq=id:1&wt=xml} 
hits=1 status=0 QTime=0 
   [junit4]   2> 353773 T3744 C2059 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=add(2,3)&defType=func&fl=*,score&fq=id:1&wt=xml} hits=1 status=0 
QTime=1 
   [junit4]   2> 353774 T3744 C2059 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=mul(2,3)&defType=func&fl=*,score&fq=id:1&wt=xml} hits=1 status=0 
QTime=0 
   [junit4]   2> 353776 T3744 C2059 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q=rad(45)&defType=func&fl=*,score&fq=id:1&wt=xml} 
hits=1 status=0 QTime=1 
   [junit4]   2> 353776 T3744 C2059 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q=deg(.5)&defType=func&fl=*,score&fq=id:1&wt=xml} 
hits=1 status=0 QTime=0 
   [junit4]   2> 353777 T3744 C2059 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q=sqrt(9)&defType=func&fl=*,score&fq=id:1&wt=xml} 
hits=1 status=0 QTime=0 
   [junit4]   2> 353778 T3744 C2059 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q=cbrt(8)&defType=func&fl=*,score&fq=id:1&wt=xml} 
hits=1 status=0 QTime=0 
   [junit4]   2> 353779 T3744 C2059 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=max(0,1)&defType=func&fl=*,score&fq=id:1&wt=xml} hits=1 status=0 
QTime=1 
   [junit4]   2> 353779 T3744 C2059 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=max(10,3,8,7,5,4)&defType=func&fl=*,score&fq=id:1&wt=xml} hits=1 
status=0 QTime=0 
   [junit4]   2> 353780 T3744 C2059 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=min(0,1)&defType=func&fl=*,score&fq=id:1&wt=xml} hits=1 status=0 
QTime=0 
   [junit4]   2> 353781 T3744 C2059 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=min(10,3,8,7,5,4)&defType=func&fl=*,score&fq=id:1&wt=xml} hits=1 
status=0 QTime=0 
   [junit4]   2> 353782 T3744 C2059 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=log(100)&defType=func&fl=*,score&fq=id:1&wt=xml} hits=1 status=0 
QTime=1 
   [junit4]   2> 353782 T3744 C2059 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q=ln(3)&defType=func&fl=*,score&fq=id:1&wt=xml} 
hits=1 status=0 QTime=0 
   [junit4]   2> 353783 T3744 C2059 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q=exp(1)&defType=func&fl=*,score&fq=id:1&wt=xml} 
hits=1 status=0 QTime=0 
   [junit4]   2> 353784 T3744 C2059 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q=sin(.5)&defType=func&fl=*,score&fq=id:1&wt=xml} 
hits=1 status=0 QTime=0 
   [junit4]   2> 353785 T3744 C2059 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q=cos(.5)&defType=func&fl=*,score&fq=id:1&wt=xml} 
hits=1 status=0 QTime=1 
   [junit4]   2> 353785 T3744 C2059 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q=tan(.5)&defType=func&fl=*,score&fq=id:1&wt=xml} 
hits=1 status=0 QTime=0 
   [junit4]   2> 353786 T3744 C2059 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=asin(.5)&defType=func&fl=*,score&fq=id:1&wt=xml} hits=1 status=0 
QTime=0 
   [junit4]   2> 353787 T3744 C2059 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=acos(.5)&defType=func&fl=*,score&fq=id:1&wt=xml} hits=1 status=0 
QTime=1 
   [junit4]   2> 353787 T3744 C2059 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=atan(.5)&defType=func&fl=*,score&fq=id:1&wt=xml} hits=1 status=0 
QTime=0 
   [junit4]   2> 353788 T3744 C2059 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=sinh(.5)&defType=func&fl=*,score&fq=id:1&wt=xml} hits=1 status=0 
QTime=0 
   [junit4]   2> 353788 T3744 C2059 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=cosh(.5)&defType=func&fl=*,score&fq=id:1&wt=xml} hits=1 status=0 
QTime=0 
   [junit4]   2> 353790 T3744 C2059 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=tanh(.5)&defType=func&fl=*,score&fq=id:1&wt=xml} hits=1 status=0 
QTime=1 
   [junit4]   2> 353790 T3744 C2059 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=ceil(2.3)&defType=func&fl=*,score&fq=id:1&wt=xml} hits=1 status=0 
QTime=0 
   [junit4]   2> 353791 T3744 C2059 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=floor(2.3)&defType=func&fl=*,score&fq=id:1&wt=xml} hits=1 status=0 
QTime=0 
   [junit4]   2> 353791 T3744 C2059 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=rint(2.3)&defType=func&fl=*,score&fq=id:1&wt=xml} hits=1 status=0 
QTime=0 
   [junit4]   2> 353794 T3744 C2059 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=pow(2,0.5)&defType=func&fl=*,score&fq=id:1&wt=xml} hits=1 status=0 
QTime=2 
   [junit4]   2> 353794 T3744 C2059 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=hypot(3,4)&defType=func&fl=*,score&fq=id:1&wt=xml} hits=1 status=0 
QTime=0 
   [junit4]   2> 353795 T3744 C2059 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=atan2(.25,.5)&defType=func&fl=*,score&fq=id:1&wt=xml} hits=1 status=0 
QTime=0 
   [junit4]   2> 353802 T3744 oas.SolrTestCaseJ4.tearDown ###Ending testFuncs
   [junit4]   2> 353804 T3744 oas.SolrTestCaseJ4.setUp ###Starting 
testExternalFileFieldNumericKey
   [junit4]   2> 353805 T3744 C2059 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[991]} 0 0
   [junit4]   2> 353806 T3744 C2059 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[992]} 0 0
   [junit4]   2> 353806 T3744 C2059 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[993]} 0 0
   [junit4]   2> 353807 T3744 C2059 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 353809 T3744 C2059 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@3e2ec8c7 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@91e8268),segFN=segments_2,generation=2}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@3e2ec8c7 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@91e8268),segFN=segments_3,generation=3}
   [junit4]   2> 353809 T3744 C2059 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 3
   [junit4]   2> 353810 T3744 C2059 oass.SolrIndexSearcher.<init> Opening 
Searcher@26486333[collection1] main
   [junit4]   2> 353810 T3744 C2059 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 353810 T3746 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@26486333[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.0.0):c1)
 Uninverting(_1(6.0.0):c3)))}
   [junit4]   2> 353811 T3744 C2059 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 4
   [junit4]   2> 353814 T3744 C2059 oassf.FileFloatSource.getFloats ERROR Error 
loading external value source + fileName + 
org.apache.solr.common.SolrException: Invalid Number: 
   [junit4]   2> 353814 T3744 C2059 oassf.FileFloatSource.getFloats Loaded 
external value source external_eff_trie
   [junit4]   2> 353814 T3744 C2059 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}eff_trie&indent=on&fl=*,score&rows=100&wt=xml} hits=4 status=0 
QTime=2 
   [junit4]   2> 353816 T3744 oas.SolrTestCaseJ4.tearDown ###Ending 
testExternalFileFieldNumericKey
   [junit4]   2> 353818 T3744 oas.SolrTestCaseJ4.setUp ###Starting 
testStrDistance
   [junit4]   2> 353819 T3744 C2059 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[1]} 0 1
   [junit4]   2> 353819 T3744 C2059 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 353821 T3744 C2059 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@3e2ec8c7 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@91e8268),segFN=segments_3,generation=3}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@3e2ec8c7 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@91e8268),segFN=segments_4,generation=4}
   [junit4]   2> 353822 T3744 C2059 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 4
   [junit4]   2> 353822 T3744 C2059 oass.SolrIndexSearcher.<init> Opening 
Searcher@7652f6ef[collection1] main
   [junit4]   2> 353822 T3744 C2059 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 353822 T3746 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@7652f6ef[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_1(6.0.0):c3)
 Uninverting(_2(6.0.0):c1)))}
   [junit4]   2> 353823 T3744 C2059 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 4
   [junit4]   2> 353833 T3744 C2059 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=10 
   [junit4]   2> 353834 T3744 C2059 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=0 
   [junit4]   2> 353836 T3744 C2059 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=1 
   [junit4]   2> 353838 T3744 C2059 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=1 
   [junit4]   2> 353840 T3744 C2059 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=1 
   [junit4]   2> 353840 T3744 C2059 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> 353841 T3744 C2059 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> 353842 T3744 oas.SolrTestCaseJ4.tearDown ###Ending 
testStrDistance
   [junit4]   2> 353844 T3744 oas.SolrTestCaseJ4.setUp ###Starting 
testTotalTermFreq
   [junit4]   2> 353844 T3744 C2059 oasu.DirectUpdateHandler2.deleteAll 
[collection1] REMOVING ALL DOCUMENTS FROM INDEX
   [junit4]   2> 353844 T3744 C2059 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 0
   [junit4]   2> 353846 T3744 C2059 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[1]} 0 1
   [junit4]   2> 353847 T3744 C2059 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[2]} 0 1
   [junit4]   2> 353847 T3744 C2059 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 353849 T3744 C2059 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@3e2ec8c7 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@91e8268),segFN=segments_4,generation=4}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@3e2ec8c7 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@91e8268),segFN=segments_5,generation=5}
   [junit4]   2> 353850 T3744 C2059 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 5
   [junit4]   2> 353851 T3744 C2059 oass.SolrIndexSearcher.<init> Opening 
Searcher@76ab8513[collection1] main
   [junit4]   2> 353851 T3744 C2059 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 353851 T3746 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@76ab8513[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_3(6.0.0):c2)))}
   [junit4]   2> 353851 T3744 C2059 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 4
   [junit4]   2> 353852 T3744 C2059 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[3]} 0 0
   [junit4]   2> 353853 T3744 C2059 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[4]} 0 0
   [junit4]   2> 353853 T3744 C2059 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 353855 T3744 C2059 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@3e2ec8c7 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@91e8268),segFN=segments_5,generation=5}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@3e2ec8c7 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@91e8268),segFN=segments_6,generation=6}
   [junit4]   2> 353856 T3744 C2059 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 6
   [junit4]   2> 353856 T3744 C2059 oass.SolrIndexSearcher.<init> Opening 
Searcher@1c84be9c[collection1] main
   [junit4]   2> 353856 T3744 C2059 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 353856 T3746 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@1c84be9c[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_3(6.0.0):c2)
 Uninverting(_4(6.0.0):c2)))}
   [junit4]   2> 353857 T3744 C2059 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 4
   [junit4]   2> 353857 T3744 C2059 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[5]} 0 0
   [junit4]   2> 353858 T3744 C2059 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[6]} 0 0
   [junit4]   2> 353858 T3744 C2059 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 353861 T3744 C2059 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@3e2ec8c7 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@91e8268),segFN=segments_6,generation=6}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@3e2ec8c7 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@91e8268),segFN=segments_7,generation=7}
   [junit4]   2> 353861 T3744 C2059 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 7
   [junit4]   2> 353862 T3744 C2059 oass.SolrIndexSearcher.<init> Opening 
Searcher@57d097bb[collection1] main
   [junit4]   2> 353862 T3744 C2059 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 353862 T3746 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@57d097bb[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_3(6.0.0):c2)
 Uninverting(_4(6.0.0):c2) Uninverting(_5(6.0.0):c2)))}
   [junit4]   2> 353862 T3744 C2059 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 4
   [junit4]   2> 353866 T3744 C2059 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=3 
   [junit4]   2> 353867 T3744 C2059 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> 353869 T3744 C2059 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=1 
   [junit4]   2> 353870 T3744 C2059 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> 353871 T3744 oas.SolrTestCaseJ4.tearDown ###Ending 
testTotalTermFreq
   [junit4]   2> 353874 T3744 oas.SolrTestCaseJ4.setUp ###Starting 
testFieldValueSourceParser
   [junit4]   2> 353874 T3744 C2059 oasu.DirectUpdateHandler2.deleteAll 
[collection1] REMOVING ALL DOCUMENTS FROM INDEX
   [junit4]   2> 353874 T3744 C2059 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 0
   [junit4]   2> 353875 T3744 C2059 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[100.0]} 0 0
   [junit4]   2> 353876 T3744 C2059 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[-4.0]} 0 0
   [junit4]   2> 353876 T3744 C2059 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 353878 T3744 C2059 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@3e2ec8c7 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@91e8268),segFN=segments_7,generation=7}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@3e2ec8c7 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@91e8268),segFN=segments_8,generation=8}
   [junit4]   2> 353879 T3744 C2059 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 8
   [junit4]   2> 353880 T3744 C2059 oass.SolrIndexSearcher.<init> Opening 
Searcher@5e0e42f0[collection1] main
   [junit4]   2> 353880 T3744 C2059 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 353880 T3746 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@5e0e42f0[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_6(6.0.0):c2)))}
   [junit4]   2> 353881 T3744 C2059 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 5
   [junit4]   2> 353882 T3744 C2059 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[0.0]} 0 1
   [junit4]   2> 353882 T3744 C2059 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[10.0]} 0 0
   [junit4]   2> 353883 T3744 C2059 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[10.0]} 0 0
   [junit4]   2> 353883 T3744 C2059 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[25.0]} 0 0
   [junit4]   2> 353884 T3744 C2059 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[25.0]} 0 0
   [junit4]   2> 353884 T3744 C2059 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 353887 T3744 C2059 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@3e2ec8c7 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@91e8268),segFN=segments_8,generation=8}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@3e2ec8c7 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@91e8268),segFN=segments_9,generation=9}
   [junit4]   2> 353887 T3744 C2059 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 9
   [junit4]   2> 353888 T3744 C2059 oass.SolrIndexSearcher.<init> Opening 
Searcher@6079b69[collection1] main
   [junit4]   2> 353888 T3746 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@6079b69[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_6(6.0.0):c2)
 Uninverting(_7(6.0.0):c5/2:delGen=1)))}
   [junit4]   2> 353889 T3744 C2059 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 353893 T3744 C2059 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 9
   [junit4]   2> 353894 T3744 C2059 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[5.0]} 0 0
   [junit4]   2> 353894 T3744 C2059 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[77.0]} 0 0
   [junit4]   2> 353895 T3744 C2059 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[1.0]} 0 0
   [junit4]   2> 353895 T3744 C2059 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 353898 T3744 C2059 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@3e2ec8c7 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@91e8268),segFN=segments_9,generation=9}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@3e2ec8c7 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@91e8268),segFN=segments_a,generation=10}
   [junit4]   2> 353899 T3744 C2059 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 10
   [junit4]   2> 353899 T3744 C2059 oass.SolrIndexSearcher.<init> Opening 
Searcher@4ddedcfe[collection1] main
   [junit4]   2> 353899 T3744 C2059 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 353899 T3746 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@4ddedcfe[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_6(6.0.0):c2)
 Uninverting(_7(6.0.0):c5/2:delGen=1) Uninverting(_8(6.0.0):c3)))}
   [junit4]   2> 353900 T3744 C2059 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 5
   [junit4]   2> 353901 T3744 C2059 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=1 
   [junit4]   2> 353903 T3744 C2059 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> 353905 T3744 C2059 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> 353905 T3744 oas.SolrTestCaseJ4.tearDown ###Ending 
testFieldValueSourceParser
   [junit4]   2> 353908 T3744 oas.SolrTestCaseJ4.setUp ###Starting 
testExternalFieldValueSourceParser
   [junit4]   2> 353908 T3744 C2059 oasu.DirectUpdateHandler2.deleteAll 
[collection1] REMOVING ALL DOCUMENTS FROM INDEX
   [junit4]   2> 353909 T3744 C2059 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 1
   [junit4]   2> 353910 T3744 C2059 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[100.0]} 0 0
   [junit4]   2> 353910 T3744 C2059 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[-4.0]} 0 0
   [junit4]   2> 353911 T3744 C2059 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[0.0]} 0 0
   [junit4]   2> 353911 T3744 C2059 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[10.0]} 0 0
   [junit4]   2> 353912 T3744 C2059 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[25.0]} 0 0
   [junit4]   2> 353913 T3744 C2059 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[5.0]} 0 1
   [junit4]   2> 353913 T3744 C2059 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[77.0]} 0 0
   [junit4]   2> 353914 T3744 C2059 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[77.0]} 0 0
   [junit4]   2> 353914 T3744 C2059 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[23.0]} 0 0
   [junit4]   2> 353915 T3744 C2059 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[55.0]} 0 0
   [junit4]   2> 353915 T3744 C2059 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[-78.0]} 0 0
   [junit4]   2> 353916 T3744 C2059 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[-45.0]} 0 0
   [junit4]   2> ASYNC  NEW_CORE C2060 name=collection1 
org.apache.solr.core.SolrCore@448be4f
   [junit4]   2> 353925 T3744 C2060 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[-24.0]} 0 0
   [junit4]   2> 353926 T3744 C2060 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 353928 T3744 C2060 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@3e2ec8c7 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@91e8268),segFN=segments_a,generation=10}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@3e2ec8c7 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@91e8268),segFN=segments_b,generation=11}
   [junit4]   2> 353928 T3744 C2060 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 11
   [junit4]   2> 353929 T3744 C2060 oass.SolrIndexSearcher.<init> Opening 
Searcher@769c7063[collection1] main
   [junit4]   2> 353930 T3744 C2060 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 353930 T3746 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@769c7063[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_9(6.0.0):c13/1:delGen=1)))}
   [junit4]   2> 353930 T3744 C2060 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 4
   [junit4]   2> 353931 T3744 C2060 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[63.0]} 0 0
   [junit4]   2> 353932 T3744 C2060 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[78.0]} 0 0
   [junit4]   2> 353932 T3744 C2060 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[94.0]} 0 0
   [junit4]   2> 353933 T3744 C2060 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[22.0]} 0 0
   [junit4]   2> 353933 T3744 C2060 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[22.0]} 0 0
   [junit4]   2> 353934 T3744 C2060 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[34.0]} 0 0
   [junit4]   2> 353934 T3744 C2060 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[54321.0]} 0 0
   [junit4]   2> 353935 T3744 C2060 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 353937 T3744 C2060 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@3e2ec8c7 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@91e8268),segFN=segments_b,generation=11}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@3e2ec8c7 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@91e8268),segFN=segments_c,generation=12}
   [junit4]   2> 353937 T3744 C2060 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 12
   [junit4]   2> 353938 T3744 C2060 oass.SolrIndexSearcher.<init> Opening 
Searcher@71ef5a9e[collection1] main
   [junit4]   2> 353938 T3746 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@71ef5a9e[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_9(6.0.0):c13/1:delGen=1)
 Uninverting(_a(6.0.0):c7/1:delGen=1)))}
   [junit4]   2> 353938 T3744 C2060 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 353939 T3744 C2060 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 4
   [junit4]   2> 353939 T3744 C2060 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[261.0]} 0 0
   [junit4]   2> 353940 T3744 C2060 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 353942 T3744 C2060 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@3e2ec8c7 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@91e8268),segFN=segments_c,generation=12}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@3e2ec8c7 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@91e8268),segFN=segments_d,generation=13}
   [junit4]   2> 353942 T3744 C2060 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 13
   [junit4]   2> 353943 T3744 C2060 oass.SolrIndexSearcher.<init> Opening 
Searcher@53e828ab[collection1] main
   [junit4]   2> 353943 T3746 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@53e828ab[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_9(6.0.0):c13/1:delGen=1)
 Uninverting(_a(6.0.0):c7/1:delGen=1) Uninverting(_b(6.0.0):c1)))}
   [junit4]   2> 353943 T3744 C2060 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 353943 T3744 C2060 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 3
   [junit4]   2> 353944 T3744 C2060 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[-627.0]} 0 0
   [junit4]   2> 353945 T3744 C2060 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[-627.0]} 0 0
   [junit4]   2> 353945 T3744 C2060 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 353947 T3744 C2060 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@3e2ec8c7 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@91e8268),segFN=segments_d,generation=13}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@3e2ec8c7 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@91e8268),segFN=segments_e,generation=14}
   [junit4]   2> 353948 T3744 C2060 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 14
   [junit4]   2> 353948 T3744 C2060 oass.SolrIndexSearcher.<init> Opening 
Searcher@6ec20cd8[collection1] main
   [junit4]   2> 353949 T3744 C2060 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 353949 T3746 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@6ec20cd8[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_9(6.0.0):c13/1:delGen=1)
 Uninverting(_a(6.0.0):c7/1:delGen=1) Uninverting(_b(6.0.0):c1) 
Uninverting(_c(6.0.0):c2/1:delGen=1)))}
   [junit4]   2> 353949 T3744 C2060 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 4
   [junit4]   2> 353950 T3744 C2060 oassf.FileFloatSource.getFloats Loaded 
external value source external_CoMpleX fieldName _extf
   [junit4]   2> 353951 T3744 C2060 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=1 
   [junit4]   2> 353953 T3744 C2060 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> 353953 T3744 C2060 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=0 
   [junit4]   2> 353954 T3744 C2060 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[10000]} 0 0
   [junit4]   2> 353955 T3744 C2060 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 353957 T3744 C2060 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@3e2ec8c7 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@91e8268),segFN=segments_e,generation=14}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@3e2ec8c7 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@91e8268),segFN=segments_f,generation=15}
   [junit4]   2> 353957 T3744 C2060 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 15
   [junit4]   2> 353958 T3744 C2060 oass.SolrIndexSearcher.<init> Opening 
Searcher@4ae78e89[collection1] main
   [junit4]   2> 353958 T3744 C2060 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 353958 T3746 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@4ae78e89[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_9(6.0.0):c13/1:delGen=1)
 Uninverting(_a(6.0.0):c7/1:delGen=1) Uninverting(_b(6.0.0):c1) 
Uninverting(_c(6.0.0):c2/1:delGen=1) Uninverting(_d(6.0.0):c1)))}
   [junit4]   2> 353958 T3744 C2060 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 3
   [junit4]   2> 353960 T3744 C2060 oassf.FileFloatSource.getFloats Loaded 
external value source external_CoMpleX fieldName _extf
   [junit4]   2> 353960 T3744 C2060 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=1 
   [junit4]   2> 353961 T3744 oas.SolrTestCaseJ4.tearDown ###Ending 
testExternalFieldValueSourceParser
   [junit4]   2> 353963 T3744 oas.SolrTestCaseJ4.setUp ###Starting 
testSortByFunc
   [junit4]   2> 353964 T3744 C2060 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[1]} 0 1
   [junit4]   2> 353964 T3744 C2060 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[2]} 0 0
   [junit4]   2> 353965 T3744 C2060 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[3]} 0 0
   [junit4]   2> 353965 T3744 C2060 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 353971 T3744 C2060 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@3e2ec8c7 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@91e8268),segFN=segments_f,generation=15}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@3e2ec8c7 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@91e8268),segFN=segments_g,generation=16}
   [junit4]   2> 353971 T3744 C2060 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 16
   [junit4]   2> 353972 T3744 C2060 oass.SolrIndexSearcher.<init> Opening 
Searcher@54c790d2[collection1] main
   [junit4]   2> 353972 T3744 C2060 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 353972 T3746 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@54c790d2[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_9(6.0.0):c13/1:delGen=1)
 Uninverting(_a(6.0.0):c7/1:delGen=1) Uninverting(_b(6.0.0):c1) 
Uninverting(_c(6.0.0):c2/1:delGen=1) Uninverting(_d(6.0.0):c1) 
Uninverting(_e(6.0.0):c3)))}
   [junit4]   2> 353973 T3744 C2060 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 8
   [junit4]   2> 353974 T3744 C2060 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=0 
   [junit4]   2> 353975 T3744 C2060 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=0 
   [junit4]   2> 353976 T3744 C2060 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> 353977 T3744 C2060 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> 353977 T3744 C2060 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> 353978 T3744 C2060 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=1 
   [junit4]   2> 353978 T3744 C2060 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> 353979 T3744 C2060 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> 353980 T3744 C2060 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=1 
   [junit4]   2> 353980 T3744 C2060 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=0 
   [junit4]   2> 353981 T3744 C2060 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=1 
   [junit4]   2> 353982 T3744 C2060 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> 353983 T3744 C2060 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> 353987 T3744 C2060 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=4 
   [junit4]   2> 353987 T3744 oas.SolrTestCaseJ4.tearDown ###Ending 
testSortByFunc
   [junit4]   2> 353990 T3744 oas.SolrTestCaseJ4.setUp ###Starting 
testBooleanFunctions
   [junit4]   2> 353991 T3744 C2060 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[1]} 0 1
   [junit4]   2> 353991 T3744 C2060 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[2]} 0 0
   [junit4]   2> 353992 T3744 C2060 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 353995 T3744 C2060 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@3e2ec8c7 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@91e8268),segFN=segments_g,generation=16}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@3e2ec8c7 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@91e8268),segFN=segments_h,generation=17}
   [junit4]   2> 353996 T3744 C2060 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 17
   [junit4]   2> 353996 T3744 C2060 oass.SolrIndexSearcher.<init> Opening 
Searcher@44c99fa1[collection1] main
   [junit4]   2> 353997 T3744 C2060 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 353997 T3746 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@44c99fa1[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_9(6.0.0):c13/1:delGen=1)
 Uninverting(_a(6.0.0):c7/1:delGen=1) Uninverting(_b(6.0.0):c1) 
Uninverting(_c(6.0.0):c2/1:delGen=1) Uninverting(_d(6.0.0):c1) 
Uninverting(_e(6.0.0):c3/2:delGen=1) Uninverting(_f(6.0.0):c2)))}
   [junit4]   2> 353997 T3744 C2060 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 5
   [junit4]   2> 353998 T3744 C2060 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q=id:1&fl=a:testfunc(1)&wt=xml} hits=1 status=0 
QTime=0 
   [junit4]   2> 354000 T3744 C2060 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=1 
   [junit4]   2> 354001 T3744 C2060 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> 354003 T3744 C2060 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=1 
   [junit4]   2> 354004 T3744 C2060 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=1 
   [junit4]   2> 354005 T3744 C2060 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=0 
   [junit4]   2> 354006 T3744 C2060 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> 354007 T3744 C2060 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=1 
   [junit4]   2> 354010 T3744 C2060 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=3 
   [junit4]   2> 354011 T3744 C2060 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> 354012 T3744 C2060 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> 354012 T3744 oas.SolrTestCaseJ4.tearDown ###Ending 
testBooleanFunctions
   [junit4]   2> 354015 T3744 oas.SolrTestCaseJ4.setUp ###Starting 
testDegreeRads
   [junit4]   2> 354016 T3744 C2060 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[1]} 0 1
   [junit4]   2> 354016 T3744 C2060 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[2]} 0 0
   [junit4]   2> 354017 T3744 C2060 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[3]} 0 0
   [junit4]   2> 354018 T3744 C2060 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 354021 T3744 C2060 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@3e2ec8c7 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@91e8268),segFN=segments_h,generation=17}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@3e2ec8c7 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@91e8268),segFN=segments_i,generation=18}
   [junit4]   2> 354021 T3744 C2060 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 18
   [junit4]   2> 354022 T3744 C2060 oass.SolrIndexSearcher.<init> Opening 
Searcher@44a8c76a[collection1] main
   [junit4]   2> 354022 T3744 C2060 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 354022 T3746 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@44a8c76a[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_9(6.0.0):c13/1:delGen=1)
 Uninverting(_a(6.0.0):c7/1:delGen=1) Uninverting(_b(6.0.0):c1) 
Uninverting(_c(6.0.0):c2/1:delGen=1) Uninverting(_d(6.0.0):c1) 
Uninverting(_g(6.0.0):c3)))}
   [junit4]   2> 354023 T3744 C2060 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 5
   [junit4]   2> 354024 T3744 C2060 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> 354025 T3744 C2060 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> 354026 T3744 C2060 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> 354027 T3744 C2060 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=1 
   [junit4]   2> 354027 T3744 C2060 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=0 
   [junit4]   2> 354028 T3744 C2060 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> 354028 T3744 oas.SolrTestCaseJ4.tearDown ###Ending 
testDegreeRads
   [junit4]   2> 354032 T3744 oas.SolrTestCaseJ4.setUp ###Starting testGeneral
   [junit4]   2> 354032 T3744 C2060 oasu.DirectUpdateHandler2.deleteAll 
[collection1] REMOVING ALL DOCUMENTS FROM INDEX
   [junit4]   2> 354032 T3744 C2060 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 0
   [junit4]   2> 354034 T3744 C2060 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[1]} 0 1
   [junit4]   2> 354034 T3744 C2060 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[2]} 0 0
   [junit4]   2> 354035 T3744 C2060 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 354036 T3744 C2060 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@3e2ec8c7 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@91e8268),segFN=segments_i,generation=18}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@3e2ec8c7 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@91e8268),segFN=segments_j,generation=19}
   [junit4]   2> 354037 T3744 C2060 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 19
   [junit4]   2> 354038 T3744 C2060 oass.SolrIndexSearcher.<init> Opening 
Searcher@2d5df740[collection1] main
   [junit4]   2> 354038 T3744 C2060 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 354038 T3746 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@2d5df740[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_h(6.0.0):c2)))}
   [junit4]   2> 354039 T3744 C2060 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 4
   [junit4]   2> 354040 T3744 C2060 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[3]} 0 1
   [junit4]   2> 354040 T3744 C2060 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[4]} 0 0
   [junit4]   2> 354041 T3744 C2060 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 354043 T3744 C2060 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@3e2ec8c7 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@91e8268),segFN=segments_j,generation=19}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@3e2ec8c7 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@91e8268),segFN=segments_k,generation=20}
   [junit4]   2> 354044 T3744 C2060 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 20
   [junit4]   2> 354044 T3744 C2060 oass.SolrIndexSearcher.<init> Opening 
Searcher@7023661d[collection1] main
   [junit4]   2> 354045 T3744 C2060 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 354045 T3746 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@7023661d[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_h(6.0.0):c2)
 Uninverting(_i(6.0.0):c2)))}
   [junit4]   2> 354045 T3744 C2060 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 4
   [junit4]   2> 354046 T3744 C2060 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[5]} 0 0
   [junit4]   2> 354047 T3744 C2060 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[6]} 0 1
   [junit4]   2> 354047 T3744 C2060 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 354050 T3744 C2060 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@3e2ec8c7 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@91e8268),segFN=segments_k,generation=20}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@3e2ec8c7 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@91e8268),segFN=segments_l,generation=21}
   [junit4]   2> 354050 T3744 C2060 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 21
   [junit4]   2> 354051 T3744 C2060 oass.SolrIndexSearcher.<init> Opening 
Searcher@21d1c4c8[collection1] main
   [junit4]   2> 354051 T3744 C2060 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 354051 T3746 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@21d1c4c8[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_h(6.0.0):c2)
 Uninverting(_i(6.0.0):c2) Uninverting(_j(6.0.0):c2)))}
   [junit4]   2> 354051 T3744 C2060 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 4
   [junit4]   2> 354054 T3744 C2060 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q={!func}numdocs()&fl=*,score&fq=id:6&wt=xml} 
hits=1 status=0 QTime=2 
   [junit4]   2> 354055 T3744 C2060 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> 354056 T3744 C2060 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> 354057 T3744 C2060 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=0 
   [junit4]   2> 354058 T3744 C2060 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 status=0 QTime=1 
   [junit4]   2> 354060 T3744 C2060 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}termfreq(a_t,cow)&fl=*,score&fq=id:6&wt=xml} hits=1 status=0 
QTime=2 
   [junit4]   2> 354060 T3744 C2060 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}termfreq(nofield_t,cow)&fl=*,score&fq=id:6&wt=xml} hits=1 
status=0 QTime=0 
   [junit4]   2> 354061 T3744 C2060 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}docfreq(nofield_t,cow)&fl=*,score&fq=id:6&wt=xml} hits=1 
status=0 QTime=0 
   [junit4]   2> 354062 T3744 C2060 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}idf(nofield_t,cow)&fl=*,score&fq=id:6&wt=xml} hits=1 status=0 
QTime=1 
   [junit4]   2> 354064 T3744 C2060 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}tf(nofield_t,cow)&fl=*,score&fq=id:6&wt=xml} hits=1 status=0 
QTime=1 
   [junit4]   2> 354065 T3744 C2060 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q={!func}idf(a_t,cow)&fl=*,score&fq=id:6&wt=xml} 
hits=1 status=0 QTime=0 
   [junit4]   2> 354065 T3744 C2060 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q={!func}tf(a_t,cow)&fl=*,score&fq=id:6&wt=xml} 
hits=1 status=0 QTime=0 
   [junit4]   2> 354067 T3744 C2060 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q={!func}norm(a_t)&fl=*,score&fq=id:2&wt=xml} 
hits=1 status=0 QTime=1 
   [junit4]   2> 354068 T3744 C2060 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q={!func}ord(id)&fl=*,score&fq=id:6&wt=xml} 
hits=1 status=0 QTime=1 
   [junit4]   2> 354068 T3744 C2060 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q={!func}top(ord(id))&fl=*,score&fq=id:6&wt=xml} 
hits=1 status=0 QTime=0 
   [junit4]   2> 354069 T3744 C2060 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q={!func}rord(id)&fl=*,score&fq=id:1&wt=xml} 
hits=1 status=0 QTime=0 
   [junit4]   2> 354071 T3744 C2060 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q={!func}top(rord(id))&fl=*,score&fq=id:1&wt=xml} 
hits=1 status=0 QTime=0 
   [junit4]   2> 354071 T3744 C2060 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}ms(a_tdt,b_tdt)&fl=*,score&fq=id:1&wt=xml} hits=1 status=0 
QTime=0 
   [junit4]   2> 354072 T3744 C2060 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}ms(b_tdt,a_tdt)&fl=*,score&fq=id:1&wt=xml} hits=1 status=0 
QTime=0 
   [junit4]   2> 354073 T3744 C2060 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}ms(2009-08-31T12:10:10.125Z,2009-08-31T12:10:10.124Z)&fl=*,score&fq=id:1&wt=xml}
 hits=1 status=0 QTime=0 
   [junit4]   2> 354074 T3744 C2060 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}ms(2009-08-31T12:10:10.124Z,a_tdt)&fl=*,score&fq=id:1&wt=xml} 
hits=1 status=0 QTime=1 
   [junit4]   2> 354074 T3744 C2060 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}ms(2009-08-31T12:10:10.125Z,b_tdt)&fl=*,score&fq=id:1&wt=xml} 
hits=1 status=0 QTime=0 
   [junit4]   2> 354075 T3744 C2060 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}ms(2009-08-31T12:10:10.125Z/SECOND,2009-08-31T12:10:10.124Z/SECOND)&fl=*,score&fq=id:1&wt=xml}
 hits=1 status=0 QTime=0 
   [junit4]   2> 354076 T3744 C2060 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q={!func}ms(NOW)&fl=*,score&NOW=1000&wt=xml} 
hits=6 status=0 QTime=0 
   [junit4]   2> 354076 T3744 C2060 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[100]} 0 0
   [junit4]   2> 354077 T3744 C2060 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[101]} 0 0
   [junit4]   2> 354077 T3744 C2060 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[102]} 0 0
   [junit4]   2> 354078 T3744 C2060 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[103]} 0 0
   [junit4]   2> 354078 T3744 C2060 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[104]} 0 0
   [junit4]   2> 354078 T3744 C2060 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[105]} 0 0
   [junit4]   2> 354079 T3744 C2060 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[106]} 0 0
   [junit4]   2> 354079 T3744 C2060 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[107]} 0 0
   [junit4]   2> 354079 T3744 C2060 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[108]} 0 0
   [junit4]   2> 354080 T3744 C2060 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[109]} 0 1
   [junit4]   2> 354080 T3744 C2060 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[110]} 0 0
   [junit4]   2> 354080 T3744 C2060 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[111]} 0 0
   [junit4]   2> 354080 T3744 C2060 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 354082 T3744 C2060 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@3e2ec8c7 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@91e8268),segFN=segments_l,generation=21}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@3e2ec8c7 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@91e8268),segFN=segments_m,generation=22}
   [junit4]   2> 354082 T3744 C2060 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 22
   [junit4]   2> 354083 T3744 C2060 oass.SolrIndexSearcher.<init> Opening 
Searcher@7fb0beab[collection1] main
   [junit4]   2> 354083 T3744 C2060 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 354083 T3746 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@7fb0beab[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_h(6.0.0):c2)
 Uninverting(_i(6.0.0):c2) Uninverting(_j(6.0.0):c2) 
Uninverting(_k(6.0.0):c12)))}
   [junit4]   2> 354083 T3744 C2060 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 3
   [junit4]   2> 354084 T3744 C2060 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[120]} 0 0
   [junit4]   2> 354084 T3744 C2060 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[121]} 0 0
   [junit4]   2> 354085 T3744 C2060 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 354086 T3744 C2060 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@3e2ec8c7 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@91e8268),segFN=segments_m,generation=22}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@3e2ec8c7 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@91e8268),segFN=segments_n,generation=23}
   [junit4]   2> 354087 T3744 C2060 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 23
   [junit4]   2> 354087 T3744 C2060 oass.SolrIndexSearcher.<init> Opening 
Searcher@274bd26b[collection1] main
   [junit4]   2> 354087 T3744 C2060 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 354087 T3746 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@274bd26b[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_h(6.0.0):c2)
 Uninverting(_i(6.0.0):c2) Uninverting(_j(6.0.0):c2) Uninverting(_k(6.0.0):c12) 
Uninverting(_l(6.0.0):c2)))}
   [junit4]   2> 354088 T3744 C2060 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 3
   [junit4]   2> 354088 T3744 C2060 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={qq=text:batman&q={!func}query($qq)&fl=*,score&fq=id:120&wt=xml} hits=1 
status=0 QTime=0 
   [junit4]   2> 354089 T3744 C2060 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={qq=text:superman&q={!func}query($qq)&fl=*,score&fq=id:120&wt=xml} 
hits=1 status=0 QTime=0 
   [junit4]   2> 354091 T3744 C2060 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={qq=text:superman&q={!frange+l%3D1+u%3D10}query($qq)&fl=*,score&fq=id:120&wt=xml}
 hits=1 status=0 QTime=1 
   [junit4]   2> 354092 T3744 C2060 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={qq=text:batman&q={!func}sub(div(sum(0.0,product(1,query($qq))),1),0)&fl=*,score&fq=id:120&wt=xml}
 hits=1 status=0 QTime=1 
   [junit4]   2> 354092 T3744 C2060 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={qq=text:superman&q={!func}sub(div(sum(0.0,product(1,query($qq))),1),0)&fl=*,score&fq=id:120&wt=xml}
 hits=1 status=0 QTime=0 
   [junit4]   2> 354093 T3744 C2060 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}add($v1,$v2)&fl=*,score&v1=add($v3,$v4)&fq=id:1&v2=1&v3=2&wt=xml&v4=5}
 hits=1 status=0 QTime=0 
   [junit4]   2> 354096 T3744 C2060 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}dist(2,vector(1,1),$pt)&pt=3,1&fl=*,score&fq=id:1&wt=xml} 
hits=1 status=0 QTime=3 
   [junit4]   2> 354097 T3744 C2060 oasc.SolrException.log Ignoring exception 
matching ignore_exception
   [junit4]   2> 354097 T3744 C2060 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}10+wow+dude+ignore_exception&fl=*,score&wt=xml} status=400 
QTime=0 
   [junit4]   2> 354098 T3744 oasc.SolrException.log Ignoring exception 
matching ignore_exception
   [junit4]   2> 354099 T3744 C2060 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={qq=text:(batman+OR+superman)&q=*:*&sortfunc=query($qq)&fq=id:120+OR+id:121&sort={!func+v%3D$sortfunc}+desc&wt=xml}
 hits=2 status=0 QTime=1 
   [junit4]   2> 354099 T3744 oas.SolrTestCaseJ4.tearDown ###Ending testGeneral
   [junit4]   2> 354101 T3744 oas.SolrTestCaseJ4.setUp ###Starting 
testMissingFieldFunctionBehavior
   [junit4]   2> 354101 T3744 C2060 oasu.DirectUpdateHandler2.deleteAll 
[collection1] REMOVING ALL DOCUMENTS FROM INDEX
   [junit4]   2> 354101 T3744 C2060 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 0
   [junit4]   2> 354102 T3744 C2060 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[1]} 0 0
   [junit4]   2> 354102 T3744 C2060 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 354103 T3744 C2060 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@3e2ec8c7 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@91e8268),segFN=segments_n,generation=23}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@3e2ec8c7 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@91e8268),segFN=segments_o,generation=24}
   [junit4]   2> 354103 T3744 C2060 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 24
   [junit4]   2> 354104 T3744 C2060 oass.SolrIndexSearcher.<init> Opening 
Searcher@57ae6adb[collection1] main
   [junit4]   2> 354104 T3744 C2060 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 354104 T3746 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@57ae6adb[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_m(6.0.0):c1)))}
   [junit4]   2> 354104 T3744 C2060 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 2
   [junit4]   2> 354105 T3744 C2060 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=0 
   [junit4]   2> 354106 T3744 C2060 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> 354107 T3744 C2060 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=0 
   [junit4]   2> 354107 T3744 C2060 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> 354108 T3744 C2060 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> 354109 T3744 C2060 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=1 
   [junit4]   2> 354109 T3744 C2060 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> 354110 T3744 C2060 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> 354111 T3744 C2060 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> 354111 T3744 C2060 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> 354112 T3744 C2060 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> 354113 T3744 C2060 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=1 
   [junit4]   2> 354113 T3744 oas.SolrTestCaseJ4.tearDown ###Ending 
testMissingFieldFunctionBehavior
   [junit4]   2> 354127 T3744 oas.SolrTestCaseJ4.setUp ###Starting 
testPseudoFieldFunctions
   [junit4]   2> 354128 T3744 C2060 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[1]} 0 1
   [junit4]   2> 354129 T3744 C2060 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[2]} 0 0
   [junit4]   2> 354129 T3744 C2060 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 354131 T3744 C2060 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@3e2ec8c7 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@91e8268),segFN=segments_o,generation=24}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@3e2ec8c7 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@91e8268),segFN=segments_p,generation=25}
   [junit4]   2> 354131 T3744 C2060 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 25
   [junit4]   2> 354132 T3744 C2060 oass.SolrIndexSearcher.<init> Opening 
Searcher@40d1a2f4[collection1] main
   [junit4]   2> 354132 T3744 C2060 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 354132 T3746 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@40d1a2f4[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_n(6.0.0):c2)))}
   [junit4]   2> 354132 T3744 C2060 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 3
   [junit4]   2> 354133 T3744 C2060 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=1 
   [junit4]   2> 354133 T3744 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":1},
   [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> 354134 T3744 oas.SolrTestCaseJ4.tearDown ###Ending 
testPseudoFieldFunctions
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=TestFunctionQuery 
-Dtests.method=testPseudoFieldFunctions -Dtests.seed=E920AC7E46B8C7CB 
-Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=sl 
-Dtests.timezone=Europe/Brussels -Dtests.asserts=true 
-Dtests.file.encoding=UTF-8
   [junit4] ERROR   0.03s J0 | TestFunctionQuery.testPseudoFieldFu

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

as not changed - not re-opening: org.apache.solr.search.SolrIndexSearcher
   [junit4]   2> 354377 T3744 C2061 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 354378 T3744 C2061 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={=&wt=xml} {commit=} 0 2
   [junit4]   2> 354378 T3744 C2061 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {} 0 0
   [junit4]   2> 354379 T3744 C2061 oassf.FileFloatSource.getFloats Loaded 
external value source external_foo_extf
   [junit4]   2> 354379 T3744 C2061 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}foo_extf&indent=on&fl=*,score&rows=100&wt=xml} hits=26 
status=0 QTime=1 
   [junit4]   2> 354383 T3744 C2061 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 354383 T3744 C2061 oasu.DirectUpdateHandler2.commit No 
uncommitted changes. Skipping IW.commit.
   [junit4]   2> 354384 T3744 C2061 oasc.SolrCore.openNewSearcher 
SolrIndexSearcher has not changed - not re-opening: 
org.apache.solr.search.SolrIndexSearcher
   [junit4]   2> 354384 T3744 C2061 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 354384 T3744 C2061 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={=&wt=xml} {commit=} 0 1
   [junit4]   2> 354384 T3744 C2061 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {} 0 0
   [junit4]   2> 354385 T3744 C2061 oassf.FileFloatSource.getFloats Loaded 
external value source external_foo_extf
   [junit4]   2> 354385 T3744 C2061 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}foo_extf&indent=on&fl=*,score&rows=100&wt=xml} hits=26 
status=0 QTime=0 
   [junit4]   2> 354390 T3744 C2061 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 354390 T3744 C2061 oasu.DirectUpdateHandler2.commit No 
uncommitted changes. Skipping IW.commit.
   [junit4]   2> 354390 T3744 C2061 oasc.SolrCore.openNewSearcher 
SolrIndexSearcher has not changed - not re-opening: 
org.apache.solr.search.SolrIndexSearcher
   [junit4]   2> 354390 T3744 C2061 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 354390 T3744 C2061 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={=&wt=xml} {commit=} 0 0
   [junit4]   2> 354391 T3744 C2061 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {} 0 0
   [junit4]   2> 354392 T3744 C2061 oassf.FileFloatSource.getFloats Loaded 
external value source external_foo_extf
   [junit4]   2> 354392 T3744 C2061 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}foo_extf&indent=on&fl=*,score&rows=100&wt=xml} hits=26 
status=0 QTime=1 
   [junit4]   2> 354395 T3744 oas.SolrTestCaseJ4.tearDown ###Ending 
testExternalField
   [junit4]   2> 354396 T3744 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> 354396 T3744 oasc.CoreContainer.shutdown Shutting down 
CoreContainer instance=1303020405
   [junit4]   2> 354396 T3744 oasc.SolrCore.close [collection1]  CLOSING 
SolrCore org.apache.solr.core.SolrCore@448be4f
   [junit4]   2> 354397 T3744 oasu.DirectUpdateHandler2.close closing 
DirectUpdateHandler2{commits=45,autocommits=0,soft 
autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=123,cumulative_deletesById=0,cumulative_deletesByQuery=5,cumulative_errors=0}
   [junit4]   2> 354397 T3744 oasu.SolrCoreState.decrefSolrCoreState Closing 
SolrCoreState
   [junit4]   2> 354397 T3744 oasu.DefaultSolrCoreState.closeIndexWriter 
SolrCoreState ref count has reached 0 - closing IndexWriter
   [junit4]   2> 354397 T3744 oasu.DefaultSolrCoreState.closeIndexWriter 
closing IndexWriter with IndexWriterCloser
   [junit4]   2> 354398 T3744 oasc.SolrCore.closeSearcher [collection1] Closing 
main searcher on request.
   [junit4]   2> 354398 T3744 oasc.CachingDirectoryFactory.close Closing 
MockDirectoryFactory - 2 directories currently being tracked
   [junit4]   2> 354398 T3744 oasc.CachingDirectoryFactory.closeCacheValue 
looking to close 
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.search.function.TestFunctionQuery
 E920AC7E46B8C7CB-001/init-core-data-001 
[CachedDir<<refCount=0;path=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.search.function.TestFunctionQuery
 E920AC7E46B8C7CB-001/init-core-data-001;done=false>>]
   [junit4]   2> 354398 T3744 oasc.CachingDirectoryFactory.close Closing 
directory: 
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.search.function.TestFunctionQuery
 E920AC7E46B8C7CB-001/init-core-data-001
   [junit4]   2> 354398 T3744 oasc.CachingDirectoryFactory.closeCacheValue 
looking to close 
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.search.function.TestFunctionQuery
 E920AC7E46B8C7CB-001/init-core-data-001/index 
[CachedDir<<refCount=0;path=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.search.function.TestFunctionQuery
 E920AC7E46B8C7CB-001/init-core-data-001/index;done=false>>]
   [junit4]   2> 354399 T3744 oasc.CachingDirectoryFactory.close Closing 
directory: 
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.search.function.TestFunctionQuery
 E920AC7E46B8C7CB-001/init-core-data-001/index
   [junit4]   2> NOTE: leaving temporary files on disk at: 
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.search.function.TestFunctionQuery
 E920AC7E46B8C7CB-001
   [junit4]   2> NOTE: test params are: codec=Asserting(Lucene50): 
{x_td=PostingsFormat(name=Memory doPackFST= false), 
const_s=PostingsFormat(name=Memory doPackFST= false), 
x_i=PostingsFormat(name=LuceneVarGapDocFreqInterval), 
a_tdt=PostingsFormat(name=LuceneVarGapDocFreqInterval), 
1_s=PostingsFormat(name=MockRandom), eff_ti=PostingsFormat(name=MockRandom), 
foo_s=PostingsFormat(name=LuceneVarGapDocFreqInterval), 
x_s=Lucene50(blocksize=128), 1-1_s=PostingsFormat(name=MockRandom), 
y_td=PostingsFormat(name=LuceneVarGapDocFreqInterval), CoMpleX " fieldName 
_f=Lucene50(blocksize=128), foo_tl=PostingsFormat(name=Memory doPackFST= 
false), foo_ti=PostingsFormat(name=LuceneVarGapDocFreqInterval), 
foo_tf=PostingsFormat(name=MockRandom), b_tdt=PostingsFormat(name=Memory 
doPackFST= false), sfile_s=PostingsFormat(name=Memory doPackFST= false), 
a_t=PostingsFormat(name=LuceneVarGapDocFreqInterval), 
x:x_i=Lucene50(blocksize=128), foo_d=PostingsFormat(name=Memory doPackFST= 
false), id=PostingsFormat(name=Memory doPackFST= false), 
text=PostingsFormat(name=MockRandom), yak_i=PostingsFormat(name=MockRandom), 
foo_f=PostingsFormat(name=MockRandom)}, docValues:{}, sim=DefaultSimilarity, 
locale=sl, timezone=Europe/Brussels
   [junit4]   2> NOTE: Linux 3.13.0-46-generic amd64/Oracle Corporation 
1.8.0_60-ea (64-bit)/cpus=12,threads=1,free=213458704,total=509673472
   [junit4]   2> NOTE: All tests run in this JVM: [TestJoin, 
HighlighterConfigTest, TestInfoStreamLogging, TestUpdate, TestCloudPivotFacet, 
TestRealTimeGet, HighlighterTest, TestNonDefinedSimilarityFactory, 
SyncSliceTest, TestRestManager, PeerSyncTest, DateMathParserTest, 
ExternalFileFieldSortTest, HdfsBasicDistributedZkTest, 
DefaultValueUpdateProcessorTest, EnumFieldTest, TestSolrDeletionPolicy1, 
TestFieldResource, URLClassifyProcessorTest, TestMissingGroups, 
DistributedSpellCheckComponentTest, TestConfig, TestWordDelimiterFilterFactory, 
RequestLoggingTest, TestExpandComponent, TestHashQParserPlugin, 
DeleteShardTest, TestClassNameShortening, HdfsSyncSliceTest, 
SaslZkACLProviderTest, UUIDFieldTest, CSVRequestHandlerTest, 
TestStandardQParsers, TestMergePolicyConfig, SimpleCollectionCreateDeleteTest, 
TimeZoneUtilsTest, TestCodecSupport, QueryResultKeyTest, AliasIntegrationTest, 
CachingDirectoryFactoryTest, BasicZkTest, SegmentsInfoRequestHandlerTest, 
TestReloadAndDeleteDocs, TestCloudManagedSchemaConcurrent, 
DistributedSuggestComponentTest, StandardRequestHandlerTest, 
TestSchemaSimilarityResource, TestRequestStatusCollectionAPI, 
PrimitiveFieldTypeTest, TestPhraseSuggestions, MinimalSchemaTest, 
TestFileDictionaryLookup, MultiTermTest, TestFieldCollectionResource, 
HdfsUnloadDistributedZkTest, TestFunctionQuery]
   [junit4] Completed on J0 in 0.78s, 15 tests, 1 error <<< FAILURES!

[...truncated 935 lines...]
BUILD FAILED
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:519: The following 
error occurred while executing this line:
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:467: The following 
error occurred while executing this line:
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:61: The following 
error occurred while executing this line:
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/extra-targets.xml:39: The 
following error occurred while executing this line:
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:191: The 
following error occurred while executing this line:
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:510: The 
following error occurred while executing this line:
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1351: 
The following error occurred while executing this line:
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:958: 
There were test failures: 476 suites, 1893 tests, 1 error, 48 ignored (21 
assumptions)

Total time: 38 minutes 7 seconds
Build step 'Invoke Ant' marked build as failure
[description-setter] Description set: Java: 64bit/jdk1.8.0_60-ea-b06 
-XX:+UseCompressedOops -XX:+UseSerialGC
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

Reply via email to