[JENKINS] Lucene-Solr-trunk-Linux (64bit/jdk1.9.0-ea-b54) - Build # 12033 - Still Failing!

[Policeman Jenkins Server]

Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/12033/
Java: 64bit/jdk1.9.0-ea-b54 -XX:-UseCompressedOops -XX:+UseConcMarkSweepGC

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([178897549DDEEF09:49B27529A1481345]: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:502)
        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 9390 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
 178897549DDEEF09-001/init-core-data-001
   [junit4]   2> 356346 T3761 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl 
(false) and clientAuth (false)
   [junit4]   2> 356346 T3761 oas.SolrTestCaseJ4.initCore ####initCore
   [junit4]   2> 356347 T3761 oasc.SolrResourceLoader.<init> new 
SolrResourceLoader for directory: 
'/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/'
   [junit4]   2> 356347 T3761 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> 356348 T3761 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> 356359 T3761 oasc.SolrConfig.refreshRequestParams current 
version of requestparams : -1
   [junit4]   2> 356361 T3761 oasc.SolrConfig.<init> Using Lucene MatchVersion: 
6.0.0
   [junit4]   2> 356365 T3761 oasc.SolrConfig.<init> Loaded SolrConfig: 
solrconfig-functionquery.xml
   [junit4]   2> 356365 T3761 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> 356367 T3761 oass.IndexSchema.readSchema [null] Schema 
name=example
   [junit4]   2> 356385 T3761 oass.IndexSchema.readSchema default search field 
in schema is text
   [junit4]   2> 356386 T3761 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 356387 T3761 oasc.SolrResourceLoader.locateSolrHome JNDI not 
configured for solr (NoInitialContextEx)
   [junit4]   2> 356387 T3761 oasc.SolrResourceLoader.locateSolrHome using 
system property solr.solr.home: 
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr
   [junit4]   2> 356390 T3761 oasc.SolrResourceLoader.<init> new 
SolrResourceLoader for directory: 
'/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/'
   [junit4]   2> 356397 T3761 oasc.CoreContainer.<init> New CoreContainer 
1602838087
   [junit4]   2> 356397 T3761 oasc.CoreContainer.load Loading cores into 
CoreContainer 
[instanceDir=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/]
   [junit4]   2> 356397 T3761 oasc.CoreContainer.load loading shared library: 
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/lib
   [junit4]   2> 356397 T3761 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> 356400 T3761 oashc.HttpShardHandlerFactory.getParameter 
Setting socketTimeout to: 600000
   [junit4]   2> 356400 T3761 oashc.HttpShardHandlerFactory.getParameter 
Setting urlScheme to: null
   [junit4]   2> 356400 T3761 oashc.HttpShardHandlerFactory.getParameter 
Setting connTimeout to: 60000
   [junit4]   2> 356400 T3761 oashc.HttpShardHandlerFactory.getParameter 
Setting maxConnectionsPerHost to: 20
   [junit4]   2> 356400 T3761 oashc.HttpShardHandlerFactory.getParameter 
Setting maxConnections to: 10000
   [junit4]   2> 356400 T3761 oashc.HttpShardHandlerFactory.getParameter 
Setting corePoolSize to: 0
   [junit4]   2> 356400 T3761 oashc.HttpShardHandlerFactory.getParameter 
Setting maximumPoolSize to: 2147483647
   [junit4]   2> 356400 T3761 oashc.HttpShardHandlerFactory.getParameter 
Setting maxThreadIdleTime to: 5
   [junit4]   2> 356400 T3761 oashc.HttpShardHandlerFactory.getParameter 
Setting sizeOfQueue to: -1
   [junit4]   2> 356401 T3761 oashc.HttpShardHandlerFactory.getParameter 
Setting fairnessPolicy to: false
   [junit4]   2> 356401 T3761 oashc.HttpShardHandlerFactory.getParameter 
Setting useRetries to: false
   [junit4]   2> 356401 T3761 oasu.UpdateShardHandler.<init> Creating 
UpdateShardHandler HTTP client with params: 
socketTimeout=30000&connTimeout=30000&retry=true
   [junit4]   2> 356401 T3761 oasl.LogWatcher.createWatcher SLF4J impl is 
org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 356401 T3761 oasl.LogWatcher.newRegisteredLogWatcher 
Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 356401 T3761 oasc.CoreContainer.load Node Name: testNode
   [junit4]   2> 356402 T3761 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
 178897549DDEEF09-001/init-core-data-001, shard=shard1}
   [junit4]   2> 356402 T3762 oasc.SolrResourceLoader.<init> new 
SolrResourceLoader for directory: 
'/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/'
   [junit4]   2> 356402 T3762 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> 356403 T3762 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> 356410 T3762 oasc.SolrConfig.refreshRequestParams current 
version of requestparams : -1
   [junit4]   2> 356412 T3762 oasc.SolrConfig.<init> Using Lucene MatchVersion: 
6.0.0
   [junit4]   2> 356415 T3762 oasc.SolrConfig.<init> Loaded SolrConfig: 
solrconfig-functionquery.xml
   [junit4]   2> 356415 T3762 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> 356417 T3762 oass.IndexSchema.readSchema [collection1] Schema 
name=example
   [junit4]   2> 356434 T3762 oass.IndexSchema.readSchema default search field 
in schema is text
   [junit4]   2> 356434 T3762 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 356436 T3762 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> 356436 T3762 oasc.SolrCore.initDirectoryFactory 
org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 356436 T3762 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
 178897549DDEEF09-001/init-core-data-001/
   [junit4]   2> 356436 T3762 oasc.SolrCore.<init> JMX monitoring not detected 
for core: collection1
   [junit4]   2> 356437 T3762 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
 178897549DDEEF09-001/init-core-data-001
   [junit4]   2> 356437 T3762 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
 178897549DDEEF09-001/init-core-data-001/index/
   [junit4]   2> 356437 T3762 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
 178897549DDEEF09-001/init-core-data-001/index' doesn't exist. Creating new 
index...
   [junit4]   2> 356437 T3762 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
 178897549DDEEF09-001/init-core-data-001/index
   [junit4]   2> 356437 T3762 oasu.RandomMergePolicy.<init> RandomMergePolicy 
wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: 
maxMergeAtOnce=10, maxMergeAtOnceExplicit=34, maxMergedSegmentMB=10.9814453125, 
floorSegmentMB=1.1533203125, forceMergeDeletesPctAllowed=0.26218543076557355, 
segmentsPerTier=35.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
   [junit4]   2> 356438 T3762 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@cb74d1c 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3ba1b085),segFN=segments_1,generation=1}
   [junit4]   2> 356441 T3762 oasc.SolrDeletionPolicy.updateCommits newest 
commit generation = 1
   [junit4]   2> 356443 T3762 oasc.SolrCore.loadUpdateProcessorChains no 
updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 356444 T3762 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 356444 T3762 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 356445 T3762 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 356445 T3762 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 356446 T3762 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> 356447 T3762 oasc.SolrCore.initStatsCache Using default 
statsCache cache: org.apache.solr.search.stats.LocalStatsCache
   [junit4]   2> 356447 T3762 oasu.CommitTracker.<init> Hard AutoCommit: 
disabled
   [junit4]   2> 356447 T3762 oasu.CommitTracker.<init> Soft AutoCommit: 
disabled
   [junit4]   2> 356448 T3762 oasu.RandomMergePolicy.<init> RandomMergePolicy 
wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: 
maxMergeAtOnce=38, maxMergeAtOnceExplicit=40, maxMergedSegmentMB=31.7041015625, 
floorSegmentMB=1.15234375, forceMergeDeletesPctAllowed=21.5974094431678, 
segmentsPerTier=23.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 356448 T3762 oasc.SolrDeletionPolicy.onInit 
SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@cb74d1c 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3ba1b085),segFN=segments_1,generation=1}
   [junit4]   2> 356448 T3762 oasc.SolrDeletionPolicy.updateCommits newest 
commit generation = 1
   [junit4]   2> 356448 T3762 oass.SolrIndexSearcher.<init> Opening 
Searcher@77719a56[collection1] main
   [junit4]   2> 356448 T3762 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> 356448 T3762 oasr.RestManager.init Initializing RestManager 
with initArgs: {}
   [junit4]   2> 356448 T3762 oasr.ManagedResourceStorage.load Reading 
_rest_managed.json using InMemoryStorage
   [junit4]   2> 356449 T3762 oasr.RestManager.init Initializing 0 registered 
ManagedResources
   [junit4]   2> 356449 T3762 oash.ReplicationHandler.inform Commits will be 
reserved for  10000
   [junit4]   2> 356449 T3763 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@77719a56[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 356449 T3762 oasc.CoreContainer.registerCore registering core: 
collection1
   [junit4]   2> 356450 T3761 oas.SolrTestCaseJ4.initCore ####initCore end
   [junit4]   2> 356451 T3761 oas.SolrTestCaseJ4.setUp ###Starting 
testBooleanFunctions
   [junit4]   2> ASYNC  NEW_CORE C487 name=collection1 
org.apache.solr.core.SolrCore@35cc3b0f
   [junit4]   2> 356452 T3761 C487 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[1]} 0 1
   [junit4]   2> 356453 T3761 C487 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[2]} 0 0
   [junit4]   2> 356453 T3761 C487 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 356455 T3761 C487 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@cb74d1c 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3ba1b085),segFN=segments_1,generation=1}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@cb74d1c 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3ba1b085),segFN=segments_2,generation=2}
   [junit4]   2> 356456 T3761 C487 oasc.SolrDeletionPolicy.updateCommits newest 
commit generation = 2
   [junit4]   2> 356457 T3761 C487 oass.SolrIndexSearcher.<init> Opening 
Searcher@334dbec0[collection1] main
   [junit4]   2> 356457 T3761 C487 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 356457 T3763 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@334dbec0[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.0.0):c2)))}
   [junit4]   2> 356457 T3761 C487 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 4
   [junit4]   2> 356458 T3761 C487 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> 356460 T3761 C487 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> 356462 T3761 C487 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=2 
   [junit4]   2> 356466 T3761 C487 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=2 
   [junit4]   2> 356468 T3761 C487 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> 356469 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=id:1&fl=t1:or(testfunc(true),true)&fl=t2:or(true,false)&fl=t3:or(false,true)&fl=f1:or(false,false)&wt=xml}
 hits=1 status=0 QTime=1 
   [junit4]   2> 356469 T3761 C487 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> 356470 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=id:1&fl=t:not(testfunc(false)),f:not(true)&wt=xml} hits=1 status=0 
QTime=0 
   [junit4]   2> 356472 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=id:1&fl=x:def(id,testfunc(123.0)),+y:def(foo_f,234.0)&wt=xml} hits=1 
status=0 QTime=2 
   [junit4]   2> 356473 T3761 C487 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> 356476 T3761 C487 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> 356476 T3761 oas.SolrTestCaseJ4.tearDown ###Ending 
testBooleanFunctions
   [junit4]   2> 356478 T3761 oas.SolrTestCaseJ4.setUp ###Starting testFunctions
   [junit4]   2> 356479 T3761 C487 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[100.0]} 0 1
   [junit4]   2> 356480 T3761 C487 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[-4.0]} 0 1
   [junit4]   2> 356480 T3761 C487 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[0.0]} 0 0
   [junit4]   2> 356480 T3761 C487 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[10.0]} 0 0
   [junit4]   2> 356481 T3761 C487 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[10.0]} 0 0
   [junit4]   2> 356481 T3761 C487 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 356483 T3761 C487 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@cb74d1c 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3ba1b085),segFN=segments_2,generation=2}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@cb74d1c 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3ba1b085),segFN=segments_3,generation=3}
   [junit4]   2> 356483 T3761 C487 oasc.SolrDeletionPolicy.updateCommits newest 
commit generation = 3
   [junit4]   2> 356483 T3761 C487 oass.SolrIndexSearcher.<init> Opening 
Searcher@52de5b2d[collection1] main
   [junit4]   2> 356483 T3761 C487 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 356483 T3763 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@52de5b2d[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.0.0):c2)
 Uninverting(_1(6.0.0):c5/1:delGen=1)))}
   [junit4]   2> 356484 T3761 C487 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 3
   [junit4]   2> 356484 T3761 C487 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[25.0]} 0 0
   [junit4]   2> 356485 T3761 C487 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[5.0]} 0 0
   [junit4]   2> 356485 T3761 C487 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[5.0]} 0 0
   [junit4]   2> 356485 T3761 C487 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 356487 T3761 C487 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@cb74d1c 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3ba1b085),segFN=segments_3,generation=3}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@cb74d1c 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3ba1b085),segFN=segments_4,generation=4}
   [junit4]   2> 356487 T3761 C487 oasc.SolrDeletionPolicy.updateCommits newest 
commit generation = 4
   [junit4]   2> 356487 T3761 C487 oass.SolrIndexSearcher.<init> Opening 
Searcher@2e29511e[collection1] main
   [junit4]   2> 356487 T3761 C487 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 356487 T3763 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@2e29511e[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.0.0):c2)
 Uninverting(_1(6.0.0):c5/1:delGen=1) Uninverting(_2(6.0.0):c3/1:delGen=1)))}
   [junit4]   2> 356488 T3761 C487 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 3
   [junit4]   2> 356488 T3761 C487 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[88.0]} 0 0
   [junit4]   2> 356488 T3761 C487 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 356489 T3761 C487 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@cb74d1c 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3ba1b085),segFN=segments_4,generation=4}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@cb74d1c 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3ba1b085),segFN=segments_5,generation=5}
   [junit4]   2> 356490 T3761 C487 oasc.SolrDeletionPolicy.updateCommits newest 
commit generation = 5
   [junit4]   2> 356490 T3761 C487 oass.SolrIndexSearcher.<init> Opening 
Searcher@eb23531[collection1] main
   [junit4]   2> 356490 T3761 C487 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 356490 T3763 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@eb23531[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.0.0):c2)
 Uninverting(_1(6.0.0):c5/1:delGen=1) Uninverting(_2(6.0.0):c3/1:delGen=1) 
Uninverting(_3(6.0.0):c1)))}
   [junit4]   2> 356491 T3761 C487 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 3
   [junit4]   2> 356492 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}foo_f&indent=on&fl=*,score&rows=100&wt=xml} hits=9 status=0 
QTime=1 
   [junit4]   2> 356492 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}1.414213&indent=on&fl=*,score&rows=100&wt=xml} hits=9 status=0 
QTime=0 
   [junit4]   2> 356493 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}-1.414213&indent=on&fl=*,score&rows=100&wt=xml} hits=9 
status=0 QTime=0 
   [junit4]   2> 356495 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}sum(foo_f,1)&indent=on&fl=*,score&rows=100&wt=xml} hits=9 
status=0 QTime=1 
   [junit4]   2> 356495 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}sum(foo_f,foo_f)&indent=on&fl=*,score&rows=100&wt=xml} hits=9 
status=0 QTime=0 
   [junit4]   2> 356496 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}sum(foo_f,foo_f,5)&indent=on&fl=*,score&rows=100&wt=xml} 
hits=9 status=0 QTime=0 
   [junit4]   2> 356497 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}sub(foo_f,1)&indent=on&fl=*,score&rows=100&wt=xml} hits=9 
status=0 QTime=1 
   [junit4]   2> 356497 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}product(foo_f,1)&indent=on&fl=*,score&rows=100&wt=xml} hits=9 
status=0 QTime=0 
   [junit4]   2> 356498 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}product(foo_f,-2,-4)&indent=on&fl=*,score&rows=100&wt=xml} 
hits=9 status=0 QTime=0 
   [junit4]   2> 356499 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}log(foo_f)&indent=on&fl=*,score&rows=100&wt=xml} hits=9 
status=0 QTime=1 
   [junit4]   2> 356500 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}sqrt(foo_f)&indent=on&fl=*,score&rows=100&wt=xml} hits=9 
status=0 QTime=0 
   [junit4]   2> 356502 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}abs(foo_f)&indent=on&fl=*,score&rows=100&wt=xml} hits=9 
status=0 QTime=1 
   [junit4]   2> 356503 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}pow(foo_f,foo_f)&indent=on&fl=*,score&rows=100&wt=xml} hits=9 
status=0 QTime=1 
   [junit4]   2> 356504 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}pow(foo_f,0.5)&indent=on&fl=*,score&rows=100&wt=xml} hits=9 
status=0 QTime=0 
   [junit4]   2> 356505 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}div(1,foo_f)&indent=on&fl=*,score&rows=100&wt=xml} hits=9 
status=0 QTime=0 
   [junit4]   2> 356505 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}div(1,1)&indent=on&fl=*,score&rows=100&wt=xml} hits=9 status=0 
QTime=0 
   [junit4]   2> 356506 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}sqrt(abs(foo_f))&indent=on&fl=*,score&rows=100&wt=xml} hits=9 
status=0 QTime=0 
   [junit4]   2> 356507 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}sqrt(sum(29,foo_f))&indent=on&fl=*,score&rows=100&wt=xml} 
hits=9 status=0 QTime=0 
   [junit4]   2> 356509 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}map(foo_f,0,0,500)&indent=on&fl=*,score&rows=100&wt=xml} 
hits=9 status=0 QTime=1 
   [junit4]   2> 356509 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}map(foo_f,-4,5,500)&indent=on&fl=*,score&rows=100&wt=xml} 
hits=9 status=0 QTime=0 
   [junit4]   2> 356510 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}map(foo_f,0,0,sum(foo_f,500))&indent=on&fl=*,score&rows=100&wt=xml}
 hits=9 status=0 QTime=0 
   [junit4]   2> 356511 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}map(foo_f,0,0,sum(foo_f,500),sum(foo_f,1))&indent=on&fl=*,score&rows=100&wt=xml}
 hits=9 status=0 QTime=0 
   [junit4]   2> 356512 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}map(foo_f,-4,5,sum(foo_f,1))&indent=on&fl=*,score&rows=100&wt=xml}
 hits=9 status=0 QTime=0 
   [junit4]   2> 356515 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}scale(foo_f,-1,1)&indent=on&fl=*,score&rows=100&wt=xml} hits=9 
status=0 QTime=2 
   [junit4]   2> 356516 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}scale(foo_f,-10,1000)&indent=on&fl=*,score&rows=100&wt=xml} 
hits=9 status=0 QTime=0 
   [junit4]   2> 356517 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}scale(log(foo_f),-1000,1000)&indent=on&fl=*,score&rows=100&wt=xml}
 hits=9 status=0 QTime=0 
   [junit4]   2> 356518 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}nvl(foo_f,1)&indent=on&fl=*,score&rows=100&wt=xml} hits=9 
status=0 QTime=0 
   [junit4]   2> 356518 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}nvl(sum(0,foo_f),1)&indent=on&fl=*,score&rows=100&wt=xml} 
hits=9 status=0 QTime=0 
   [junit4]   2> 356519 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}query({!func+v%3Dfoo_f})&indent=on&fl=*,score&rows=100&wt=xml} 
hits=9 status=0 QTime=0 
   [junit4]   2> 356520 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}query({!lucene+v%3D'foo_f:[*+TO+*]'},8)&indent=on&fl=*,score&rows=100&wt=xml}
 hits=9 status=0 QTime=0 
   [junit4]   2> 356520 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}sum(query({!func+v%3Dfoo_f},7.1),query({!func+v%3Dfoo_f}))&indent=on&fl=*,score&rows=100&wt=xml}
 hits=9 status=0 QTime=0 
   [junit4]   2> 356521 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={vv=foo_f&q={!func}query({!func+v%3D$vv})&indent=on&fl=*,score&rows=100&wt=xml}
 hits=9 status=0 QTime=0 
   [junit4]   2> 356522 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={vv={!func}foo_f&q={!func}query($vv)&indent=on&fl=*,score&rows=100&wt=xml}
 hits=9 status=0 QTime=0 
   [junit4]   2> 356522 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}sum(query($v1,5),query($v1,7))&indent=on&fl=*,score&v1=foo_f:[*+TO+*]&rows=100&wt=xml}
 hits=9 status=0 QTime=0 
   [junit4]   2> 356523 T3761 C487 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[100.0]} 0 0
   [junit4]   2> 356524 T3761 C487 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[100.0]} 0 0
   [junit4]   2> 356524 T3761 C487 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[-4.0]} 0 0
   [junit4]   2> 356524 T3761 C487 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[0.0]} 0 0
   [junit4]   2> 356525 T3761 C487 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[10.0]} 0 0
   [junit4]   2> 356525 T3761 C487 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[25.0]} 0 0
   [junit4]   2> 356525 T3761 C487 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[25.0]} 0 0
   [junit4]   2> 356526 T3761 C487 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[5.0]} 0 0
   [junit4]   2> 356526 T3761 C487 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[5.0]} 0 0
   [junit4]   2> 356526 T3761 C487 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 356528 T3761 C487 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@cb74d1c 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3ba1b085),segFN=segments_5,generation=5}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@cb74d1c 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3ba1b085),segFN=segments_6,generation=6}
   [junit4]   2> 356528 T3761 C487 oasc.SolrDeletionPolicy.updateCommits newest 
commit generation = 6
   [junit4]   2> 356528 T3761 C487 oass.SolrIndexSearcher.<init> Opening 
Searcher@15aab85e[collection1] main
   [junit4]   2> 356529 T3761 C487 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 356529 T3763 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@15aab85e[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.0.0):c2)
 Uninverting(_3(6.0.0):c1) Uninverting(_4(6.0.0):c9/3:delGen=1)))}
   [junit4]   2> 356529 T3761 C487 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 3
   [junit4]   2> 356529 T3761 C487 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[88.0]} 0 0
   [junit4]   2> 356530 T3761 C487 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[88.0]} 0 0
   [junit4]   2> 356530 T3761 C487 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 356531 T3761 C487 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@cb74d1c 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3ba1b085),segFN=segments_6,generation=6}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@cb74d1c 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3ba1b085),segFN=segments_7,generation=7}
   [junit4]   2> 356531 T3761 C487 oasc.SolrDeletionPolicy.updateCommits newest 
commit generation = 7
   [junit4]   2> 356532 T3761 C487 oass.SolrIndexSearcher.<init> Opening 
Searcher@2723341[collection1] main
   [junit4]   2> 356532 T3761 C487 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 356532 T3763 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@2723341[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.0.0):c2)
 Uninverting(_4(6.0.0):c9/3:delGen=1) Uninverting(_5(6.0.0):c2/1:delGen=1)))}
   [junit4]   2> 356532 T3761 C487 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 2
   [junit4]   2> 356533 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}foo_tf&indent=on&fl=*,score&rows=100&wt=xml} hits=9 status=0 
QTime=1 
   [junit4]   2> 356533 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}1.414213&indent=on&fl=*,score&rows=100&wt=xml} hits=9 status=0 
QTime=0 
   [junit4]   2> 356534 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}-1.414213&indent=on&fl=*,score&rows=100&wt=xml} hits=9 
status=0 QTime=0 
   [junit4]   2> 356534 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}sum(foo_tf,1)&indent=on&fl=*,score&rows=100&wt=xml} hits=9 
status=0 QTime=0 
   [junit4]   2> 356535 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}sum(foo_tf,foo_tf)&indent=on&fl=*,score&rows=100&wt=xml} 
hits=9 status=0 QTime=0 
   [junit4]   2> 356535 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}sum(foo_tf,foo_tf,5)&indent=on&fl=*,score&rows=100&wt=xml} 
hits=9 status=0 QTime=0 
   [junit4]   2> 356536 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}sub(foo_tf,1)&indent=on&fl=*,score&rows=100&wt=xml} hits=9 
status=0 QTime=0 
   [junit4]   2> 356536 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}product(foo_tf,1)&indent=on&fl=*,score&rows=100&wt=xml} hits=9 
status=0 QTime=0 
   [junit4]   2> 356537 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}product(foo_tf,-2,-4)&indent=on&fl=*,score&rows=100&wt=xml} 
hits=9 status=0 QTime=0 
   [junit4]   2> 356537 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}log(foo_tf)&indent=on&fl=*,score&rows=100&wt=xml} hits=9 
status=0 QTime=0 
   [junit4]   2> 356538 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}sqrt(foo_tf)&indent=on&fl=*,score&rows=100&wt=xml} hits=9 
status=0 QTime=0 
   [junit4]   2> 356539 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}abs(foo_tf)&indent=on&fl=*,score&rows=100&wt=xml} hits=9 
status=0 QTime=0 
   [junit4]   2> 356539 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}pow(foo_tf,foo_tf)&indent=on&fl=*,score&rows=100&wt=xml} 
hits=9 status=0 QTime=0 
   [junit4]   2> 356540 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}pow(foo_tf,0.5)&indent=on&fl=*,score&rows=100&wt=xml} hits=9 
status=0 QTime=0 
   [junit4]   2> 356541 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}div(1,foo_tf)&indent=on&fl=*,score&rows=100&wt=xml} hits=9 
status=0 QTime=0 
   [junit4]   2> 356542 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}div(1,1)&indent=on&fl=*,score&rows=100&wt=xml} hits=9 status=0 
QTime=1 
   [junit4]   2> 356542 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}sqrt(abs(foo_tf))&indent=on&fl=*,score&rows=100&wt=xml} hits=9 
status=0 QTime=0 
   [junit4]   2> 356543 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}sqrt(sum(29,foo_tf))&indent=on&fl=*,score&rows=100&wt=xml} 
hits=9 status=0 QTime=0 
   [junit4]   2> 356543 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}map(foo_tf,0,0,500)&indent=on&fl=*,score&rows=100&wt=xml} 
hits=9 status=0 QTime=0 
   [junit4]   2> 356544 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}map(foo_tf,-4,5,500)&indent=on&fl=*,score&rows=100&wt=xml} 
hits=9 status=0 QTime=0 
   [junit4]   2> 356545 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}map(foo_tf,0,0,sum(foo_tf,500))&indent=on&fl=*,score&rows=100&wt=xml}
 hits=9 status=0 QTime=0 
   [junit4]   2> 356546 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}map(foo_tf,0,0,sum(foo_tf,500),sum(foo_tf,1))&indent=on&fl=*,score&rows=100&wt=xml}
 hits=9 status=0 QTime=0 
   [junit4]   2> 356547 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}map(foo_tf,-4,5,sum(foo_tf,1))&indent=on&fl=*,score&rows=100&wt=xml}
 hits=9 status=0 QTime=0 
   [junit4]   2> 356548 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}scale(foo_tf,-1,1)&indent=on&fl=*,score&rows=100&wt=xml} 
hits=9 status=0 QTime=0 
   [junit4]   2> 356549 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}scale(foo_tf,-10,1000)&indent=on&fl=*,score&rows=100&wt=xml} 
hits=9 status=0 QTime=0 
   [junit4]   2> 356550 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}scale(log(foo_tf),-1000,1000)&indent=on&fl=*,score&rows=100&wt=xml}
 hits=9 status=0 QTime=0 
   [junit4]   2> 356550 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}nvl(foo_tf,1)&indent=on&fl=*,score&rows=100&wt=xml} hits=9 
status=0 QTime=0 
   [junit4]   2> 356551 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}nvl(sum(0,foo_tf),1)&indent=on&fl=*,score&rows=100&wt=xml} 
hits=9 status=0 QTime=0 
   [junit4]   2> 356552 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}query({!func+v%3Dfoo_tf})&indent=on&fl=*,score&rows=100&wt=xml}
 hits=9 status=0 QTime=0 
   [junit4]   2> 356553 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}query({!lucene+v%3D'foo_tf:[*+TO+*]'},8)&indent=on&fl=*,score&rows=100&wt=xml}
 hits=9 status=0 QTime=1 
   [junit4]   2> 356553 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}sum(query({!func+v%3Dfoo_tf},7.1),query({!func+v%3Dfoo_tf}))&indent=on&fl=*,score&rows=100&wt=xml}
 hits=9 status=0 QTime=0 
   [junit4]   2> 356554 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={vv=foo_tf&q={!func}query({!func+v%3D$vv})&indent=on&fl=*,score&rows=100&wt=xml}
 hits=9 status=0 QTime=0 
   [junit4]   2> 356554 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={vv={!func}foo_tf&q={!func}query($vv)&indent=on&fl=*,score&rows=100&wt=xml}
 hits=9 status=0 QTime=0 
   [junit4]   2> 356555 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}sum(query($v1,5),query($v1,7))&indent=on&fl=*,score&v1=foo_tf:[*+TO+*]&rows=100&wt=xml}
 hits=9 status=0 QTime=0 
   [junit4]   2> 356556 T3761 oas.SolrTestCaseJ4.tearDown ###Ending 
testFunctions
   [junit4]   2> 356558 T3761 oas.SolrTestCaseJ4.setUp ###Starting 
testExternalField
   [junit4]   2> 356558 T3761 C487 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[100.0]} 0 0
   [junit4]   2> 356558 T3761 C487 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[-4.0]} 0 0
   [junit4]   2> 356559 T3761 C487 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[-4.0]} 0 0
   [junit4]   2> 356559 T3761 C487 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[0.0]} 0 0
   [junit4]   2> 356559 T3761 C487 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[10.0]} 0 0
   [junit4]   2> 356560 T3761 C487 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[10.0]} 0 0
   [junit4]   2> 356560 T3761 C487 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[25.0]} 0 0
   [junit4]   2> 356560 T3761 C487 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 356562 T3761 C487 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@cb74d1c 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3ba1b085),segFN=segments_7,generation=7}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@cb74d1c 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3ba1b085),segFN=segments_8,generation=8}
   [junit4]   2> 356562 T3761 C487 oasc.SolrDeletionPolicy.updateCommits newest 
commit generation = 8
   [junit4]   2> 356562 T3761 C487 oass.SolrIndexSearcher.<init> Opening 
Searcher@5f011307[collection1] main
   [junit4]   2> 356562 T3761 C487 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 356562 T3763 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@5f011307[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.0.0):c2)
 Uninverting(_4(6.0.0):c9/8:delGen=2) Uninverting(_5(6.0.0):c2/1:delGen=1) 
Uninverting(_6(6.0.0):c7/2:delGen=1)))}
   [junit4]   2> 356563 T3761 C487 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 3
   [junit4]   2> 356564 T3761 C487 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[5.0]} 0 1
   [junit4]   2> 356564 T3761 C487 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[77.0]} 0 0
   [junit4]   2> 356564 T3761 C487 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[23.0]} 0 0
   [junit4]   2> 356564 T3761 C487 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 356566 T3761 C487 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@cb74d1c 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3ba1b085),segFN=segments_8,generation=8}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@cb74d1c 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3ba1b085),segFN=segments_9,generation=9}
   [junit4]   2> 356566 T3761 C487 oasc.SolrDeletionPolicy.updateCommits newest 
commit generation = 9
   [junit4]   2> 356566 T3761 C487 oass.SolrIndexSearcher.<init> Opening 
Searcher@c0600ed[collection1] main
   [junit4]   2> 356566 T3761 C487 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 356566 T3763 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@c0600ed[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.0.0):c2)
 Uninverting(_5(6.0.0):c2/1:delGen=1) Uninverting(_6(6.0.0):c7/2:delGen=1) 
Uninverting(_7(6.0.0):c3)))}
   [junit4]   2> 356567 T3761 C487 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 3
   [junit4]   2> 356567 T3761 C487 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[55.0]} 0 0
   [junit4]   2> 356567 T3761 C487 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[-78.0]} 0 0
   [junit4]   2> 356568 T3761 C487 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[-45.0]} 0 0
   [junit4]   2> 356568 T3761 C487 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[-24.0]} 0 0
   [junit4]   2> 356568 T3761 C487 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 356570 T3761 C487 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@cb74d1c 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3ba1b085),segFN=segments_9,generation=9}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@cb74d1c 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3ba1b085),segFN=segments_a,generation=10}
   [junit4]   2> 356570 T3761 C487 oasc.SolrDeletionPolicy.updateCommits newest 
commit generation = 10
   [junit4]   2> 356570 T3761 C487 oass.SolrIndexSearcher.<init> Opening 
Searcher@7bf48d31[collection1] main
   [junit4]   2> 356570 T3761 C487 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 356570 T3763 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@7bf48d31[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.0.0):c2)
 Uninverting(_5(6.0.0):c2/1:delGen=1) Uninverting(_6(6.0.0):c7/2:delGen=1) 
Uninverting(_7(6.0.0):c3) Uninverting(_8(6.0.0):c4)))}
   [junit4]   2> 356571 T3761 C487 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 3
   [junit4]   2> 356571 T3761 C487 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[63.0]} 0 0
   [junit4]   2> 356571 T3761 C487 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[78.0]} 0 0
   [junit4]   2> 356572 T3761 C487 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 356573 T3761 C487 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@cb74d1c 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3ba1b085),segFN=segments_a,generation=10}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@cb74d1c 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3ba1b085),segFN=segments_b,generation=11}
   [junit4]   2> 356573 T3761 C487 oasc.SolrDeletionPolicy.updateCommits newest 
commit generation = 11
   [junit4]   2> 356573 T3761 C487 oass.SolrIndexSearcher.<init> Opening 
Searcher@11743ae9[collection1] main
   [junit4]   2> 356574 T3761 C487 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 356574 T3763 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@11743ae9[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.0.0):c2)
 Uninverting(_5(6.0.0):c2/1:delGen=1) Uninverting(_6(6.0.0):c7/2:delGen=1) 
Uninverting(_7(6.0.0):c3) Uninverting(_8(6.0.0):c4) Uninverting(_9(6.0.0):c2)))}
   [junit4]   2> 356574 T3761 C487 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 2
   [junit4]   2> 356574 T3761 C487 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[94.0]} 0 0
   [junit4]   2> 356575 T3761 C487 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[94.0]} 0 0
   [junit4]   2> 356575 T3761 C487 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[22.0]} 0 0
   [junit4]   2> 356576 T3761 C487 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 356577 T3761 C487 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@cb74d1c 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3ba1b085),segFN=segments_b,generation=11}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@cb74d1c 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3ba1b085),segFN=segments_c,generation=12}
   [junit4]   2> 356577 T3761 C487 oasc.SolrDeletionPolicy.updateCommits newest 
commit generation = 12
   [junit4]   2> 356578 T3761 C487 oass.SolrIndexSearcher.<init> Opening 
Searcher@41f6cc24[collection1] main
   [junit4]   2> 356578 T3761 C487 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 356578 T3763 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@41f6cc24[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.0.0):c2)
 Uninverting(_5(6.0.0):c2/1:delGen=1) Uninverting(_6(6.0.0):c7/2:delGen=1) 
Uninverting(_7(6.0.0):c3) Uninverting(_8(6.0.0):c4) Uninverting(_9(6.0.0):c2) 
Uninverting(_a(6.0.0):c3/1:delGen=1)))}
   [junit4]   2> 356578 T3761 C487 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 2
   [junit4]   2> 356579 T3761 C487 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[34.0]} 0 1
   [junit4]   2> 356579 T3761 C487 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[54321.0]} 0 0
   [junit4]   2> 356579 T3761 C487 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[261.0]} 0 0
   [junit4]   2> 356580 T3761 C487 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[261.0]} 0 0
   [junit4]   2> 356580 T3761 C487 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[-627.0]} 0 0
   [junit4]   2> 356580 T3761 C487 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 356582 T3761 C487 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@cb74d1c 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3ba1b085),segFN=segments_c,generation=12}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@cb74d1c 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3ba1b085),segFN=segments_d,generation=13}
   [junit4]   2> 356582 T3761 C487 oasc.SolrDeletionPolicy.updateCommits newest 
commit generation = 13
   [junit4]   2> 356582 T3761 C487 oass.SolrIndexSearcher.<init> Opening 
Searcher@178ca27a[collection1] main
   [junit4]   2> 356582 T3761 C487 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 356582 T3763 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@178ca27a[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.0.0):c2)
 Uninverting(_5(6.0.0):c2/1:delGen=1) Uninverting(_6(6.0.0):c7/2:delGen=1) 
Uninverting(_7(6.0.0):c3) Uninverting(_8(6.0.0):c4) Uninverting(_9(6.0.0):c2) 
Uninverting(_a(6.0.0):c3/1:delGen=1) Uninverting(_b(6.0.0):c5/1:delGen=1)))}
   [junit4]   2> 356583 T3761 C487 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 3
   [junit4]   2> 356583 T3761 C487 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 356583 T3761 C487 oasu.DirectUpdateHandler2.commit No 
uncommitted changes. Skipping IW.commit.
   [junit4]   2> 356583 T3761 C487 oasc.SolrCore.openNewSearcher 
SolrIndexSearcher has not changed - not re-opening: 
org.apache.solr.search.SolrIndexSearcher
   [junit4]   2> 356584 T3761 C487 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 356584 T3761 C487 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 1
   [junit4]   2> 356590 T3761 C487 oassf.FileFloatSource.getFloats Loaded 
external value source external_foo_extf
   [junit4]   2> 356590 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}foo_extf&indent=on&fl=*,score&rows=100&wt=xml} hits=23 
status=0 QTime=6 
   [junit4]   2> 356591 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}log(foo_extf)&indent=on&fl=*,score&rows=100&wt=xml} hits=23 
status=0 QTime=0 
   [junit4]   2> 356592 T3761 C487 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}sqrt(foo_extf)&indent=on&fl=*,score&rows=100&wt=xml} hits=23 
status=0 QTime=0 
   [junit4]   2> 356592 T3761 C487 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 356592 T3761 C487 oasu.DirectUpdateHandler2.commit No 
uncommitted changes. Skipping IW.commit.
   [junit4]   2> 356593 T3761 C487 oasc.SolrCore.openNewSearcher 
SolrIndexSearcher has not changed - not re-opening: 
org.apache.solr.search.SolrIndexSearcher
   [junit4]   2> 356593 T3761 C487 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 356593 T3761 C487 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={=&wt=xml} {commit=} 0 1
   [junit4]   2> 356593 T3761 C487 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {} 0 0
   [junit4]   2> ASYNC  NEW_CORE C488 name=collection1 
org.apache.solr.core.SolrCore@35cc3b0f
   [junit4]   2> 356598 T3761 C488 oassf.FileFloatSource.getFloats Loaded 
external value source external_foo_extf
   [junit4]   2> 356598 T3761 C488 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}sqrt(foo_extf)&indent=on&fl=*,score&rows=100&wt=xml} hits=23 
status=0 QTime=1 
   [junit4]   2> 356599 T3761 C488 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 356599 T3761 C488 oasu.DirectUpdateHandler2.commit No 
uncommitted changes. Skipping IW.commit.
   [junit4]   2> 356599 T3761 C488 oasc.SolrCore.openNewSearcher 
SolrIndexSearcher has not changed - not re-opening: 
org.apache.solr.search.SolrIndexSearcher
   [junit4]   2> 356599 T3761 C488 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 356599 T3761 C488 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={=&wt=xml} {commit=} 0 1
   [junit4]   2> 356600 T3761 C488 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {} 0 1
   [junit4]   2> 356600 T3761 C488 oassf.FileFloatSource.getFloats Loaded 
external value source external_foo_extf
   [junit4]   2> 356600 T3761 C488 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}foo_extf&indent=on&fl=*,score&rows=100&wt=xml} hits=23 
status=0 QTime=0 
   [junit4]   2> 356604 T3761 C488 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 356604 T3761 C488 oasu.DirectUpdateHandler2.commit No 
uncommitted changes. Skipping IW.commit.
   [junit4]   2> 356604 T3761 C488 oasc.SolrCore.openNewSearcher 
SolrIndexSearcher has not changed - not re-opening: 
org.apache.solr.search.SolrIndexSearcher
   [junit4]   2> 356604 T3761 C488 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 356604 T3761 C488 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={=&wt=xml} {commit=} 0 0
   [junit4]   2> 356605 T3761 C488 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {} 0 0
   [junit4]   2> 356605 T3761 C488 oassf.FileFloatSource.getFloats Loaded 
external value source external_foo_extf
   [junit4]   2> 356606 T3761 C488 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}foo_extf&indent=on&fl=*,score&rows=100&wt=xml} hits=23 
status=0 QTime=1 
   [junit4]   2> 356609 T3761 C488 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 356609 T3761 C488 oasu.DirectUpdateHandler2.commit No 
uncommitted changes. Skipping IW.commit.
   [junit4]   2> 356610 T3761 C488 oasc.SolrCore.openNewSearcher 
SolrIndexSearcher has not changed - not re-opening: 
org.apache.solr.search.SolrIndexSearcher
   [junit4]   2> 356610 T3761 C488 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 356610 T3761 C488 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={=&wt=xml} {commit=} 0 1
   [junit4]   2> 356610 T3761 C488 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {} 0 0
   [junit4]   2> 356611 T3761 C488 oassf.FileFloatSource.getFloats Loaded 
external value source external_foo_extf
   [junit4]   2> 356611 T3761 C488 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}foo_extf&indent=on&fl=*,score&rows=100&wt=xml} hits=23 
status=0 QTime=1 
   [junit4]   2> 356615 T3761 C488 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 356615 T3761 C488 oasu.DirectUpdateHandler2.commit No 
uncommitted changes. Skipping IW.commit.
   [junit4]   2> 356615 T3761 C488 oasc.SolrCore.openNewSearcher 
SolrIndexSearcher has not changed - not re-opening: 
org.apache.solr.search.SolrIndexSearcher
   [junit4]   2> 356615 T3761 C488 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 356616 T3761 C488 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={=&wt=xml} {commit=} 0 1
   [junit4]   2> 356616 T3761 C488 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {} 0 0
   [junit4]   2> 356616 T3761 C488 oassf.FileFloatSource.getFloats Loaded 
external value source external_foo_extf
   [junit4]   2> 356617 T3761 C488 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}foo_extf&indent=on&fl=*,score&rows=100&wt=xml} hits=23 
status=0 QTime=1 
   [junit4]   2> 356620 T3761 C488 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 356620 T3761 C488 oasu.DirectUpdateHandler2.commit No 
uncommitted changes. Skipping IW.commit.
   [junit4]   2> 356620 T3761 C488 oasc.SolrCore.openNewSearcher 
SolrIndexSearcher has not changed - not re-opening: 
org.apache.solr.search.SolrIndexSearcher
   [junit4]   2> 356621 T3761 C488 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 356621 T3761 C488 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={=&wt=xml} {commit=} 0 1
   [junit4]   2> 356621 T3761 C488 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {} 0 0
   [junit4]   2> 356622 T3761 C488 oassf.FileFloatSource.getFloats Loaded 
external value source external_foo_extf
   [junit4]   2> 356622 T3761 C488 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}foo_extf&indent=on&fl=*,score&rows=100&wt=xml} hits=23 
status=0 QTime=1 
   [junit4]   2> 356625 T3761 C488 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 356626 T3761 C488 oasu.DirectUpdateHandler2.commit No 
uncommitted changes. Skipping IW.commit.
   [junit4]   2> 356626 T3761 C488 oasc.SolrCore.openNewSearcher 
SolrIndexSearcher has not changed - not re-opening: 
org.apache.solr.search.SolrIndexSearcher
   [junit4]   2> 356626 T3761 C488 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 356626 T3761 C488 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={=&wt=xml} {commit=} 0 1
   [junit4]   2> 356626 T3761 C488 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {} 0 0
   [junit4]   2> 356627 T3761 C488 oassf.FileFloatSource.getFloats Loaded 
external value source external_foo_extf
   [junit4]   2> 356627 T3761 C488 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}foo_extf&indent=on&fl=*,score&rows=100&wt=xml} hits=23 
status=0 QTime=0 
   [junit4]   2> 356631 T3761 C488 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 356631 T3761 C488 oasu.DirectUpdateHandler2.commit No 
uncommitted changes. Skipping IW.commit.
   [junit4]   2> 356631 T3761 C488 oasc.SolrCore.openNewSearcher 
SolrIndexSearcher has not changed - not re-opening: 
org.apache.solr.search.SolrIndexSearcher
   [junit4]   2> 356631 T3761 C488 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 356631 T3761 C488 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={=&wt=xml} {commit=} 0 0
   [junit4]   2> 356631 T3761 C488 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {} 0 0
   [junit4]   2> 356632 T3761 C488 oassf.FileFloatSource.getFloats Loaded 
external value source external_foo_extf
   [junit4]   2> 356632 T3761 C488 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}foo_extf&indent=on&fl=*,score&rows=100&wt=xml} hits=23 
status=0 QTime=0 
   [junit4]   2> 356636 T3761 C488 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 356636 T3761 C488 oasu.DirectUpdateHandler2.commit No 
uncommitted changes. Skipping IW.commit.
   [junit4]   2> 356636 T3761 C488 oasc.SolrCore.openNewSearcher 
SolrIndexSearcher has not changed - not re-opening: 
org.apache.solr.search.SolrIndexSearcher
   [junit4]   2> 356636 T3761 C488 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 356637 T3761 C488 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={=&wt=xml} {commit=} 0 1
   [junit4]   2> 356637 T3761 C488 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {} 0 0
   [junit4]   2> 356638 T3761 C488 oassf.FileFloatSource.getFloats Loaded 
external value source external_foo_extf
   [junit4]   2> 356638 T3761 C488 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}foo_extf&indent=on&fl=*,score&rows=100&wt=xml} hits=23 
status=0 QTime=1 
   [junit4]   2> 356641 T3761 C488 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 356642 T3761 C488 oasu.DirectUpdateHandler2.commit No 
uncommitted changes. Skipping IW.commit.
   [junit4]   2> 356642 T3761 C488 oasc.SolrCore.openNewSearcher 
SolrIndexSearcher has not changed - not re-opening: 
org.apache.solr.search.SolrIndexSearcher
   [junit4]   2> 356642 T3761 C488 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 356642 T3761 C488 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={=&wt=xml} {commit=} 0 1
   [junit4]   2> 356642 T3761 C488 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {} 0 0
   [junit4]   2> 356643 T3761 C488 oassf.FileFloatSource.getFloats Loaded 
external value source external_foo_extf
   [junit4]   2> 356643 T3761 C488 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}foo_extf&indent=on&fl=*,score&rows=100&wt=xml} hits=23 
status=0 QTime=0 
   [junit4]   2> 356647 T3761 C488 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 356647 T3761 C488 oasu.DirectUpdateHandler2.commit No 
uncommitted changes. Skipping IW.commit.
   [junit4]   2> 356648 T3761 C488 oasc.SolrCore.openNewSearcher 
SolrIndexSearcher has not changed - not re-opening: 
org.apache.solr.search.SolrIndexSearcher
   [junit4]   2> 356648 T3761 C488 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 356648 T3761 C488 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={=&wt=xml} {commit=} 0 1
   [junit4]   2> 356648 T3761 C488 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {} 0 0
   [junit4]   2> 356649 T3761 C488 oassf.FileFloatSource.getFloats Loaded 
external value source external_foo_extf
   [junit4]   2> 356649 T3761 C488 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}foo_extf&indent=on&fl=*,score&rows=100&wt=xml} hits=23 
status=0 QTime=0 
   [junit4]   2> 356652 T3761 oas.SolrTestCaseJ4.tearDown ###Ending 
testExternalField
   [junit4]   2> 356654 T3761 oas.SolrTestCaseJ4.setUp ###Starting 
testSortByFunc
   [junit4]   2> 356655 T3761 C488 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[1]} 0 0
   [junit4]   2> 356655 T3761 C488 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[2]} 0 0
   [junit4]   2> 356656 T3761 C488 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[3]} 0 0
   [junit4]   2> 356656 T3761 C488 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 356658 T3761 C488 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@cb74d1c 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3ba1b085),segFN=segments_d,generation=13}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@cb74d1c 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3ba1b085),segFN=segments_e,generation=14}
   [junit4]   2> 356659 T3761 C488 oasc.SolrDeletionPolicy.updateCommits newest 
commit generation = 14
   [junit4]   2> 356659 T3761 C488 oass.SolrIndexSearcher.<init> Opening 
Searcher@7a5e1188[collection1] main
   [junit4]   2> 356659 T3761 C488 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 356659 T3763 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@7a5e1188[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_5(6.0.0):c2/1:delGen=1)
 Uninverting(_6(6.0.0):c7/2:delGen=1) Uninverting(_7(6.0.0):c3) 
Uninverting(_8(6.0.0):c4) Uninverting(_9(6.0.0):c2) 
Uninverting(_a(6.0.0):c3/1:delGen=1) Uninverting(_b(6.0.0):c5/1:delGen=1) 
Uninverting(_c(6.0.0):c3)))}
   [junit4]   2> 356660 T3761 C488 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 4
   [junit4]   2> 356661 T3761 C488 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=id:[1+TO+3]&fl=x_i&sort=add(x_i,x_i)+desc&wt=xml} hits=3 status=0 
QTime=1 
   [junit4]   2> 356661 T3761 C488 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> 356662 T3761 C488 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=1 
   [junit4]   2> 356662 T3761 C488 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> 356662 T3761 C488 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> 356663 T3761 C488 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=id:[1+TO+3]&fl=x_i&sort={!key%3Dfoo}add(x_i,x_i)+desc,+const_s+asc&wt=xml}
 hits=3 status=0 QTime=0 
   [junit4]   2> 356663 T3761 C488 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> 356664 T3761 C488 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=1 
   [junit4]   2> 356664 T3761 C488 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=id:[1+TO+3]&fl=x_i&sort={!key%3Dbar+v%3D$s1}asc,const_s+asc,{!key%3Dfoo+v%3D$s2}desc&wt=xml&s1=add(3,4)&s2=add(x_i,5)}
 hits=3 status=0 QTime=0 
   [junit4]   2> 356665 T3761 C488 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=1 
   [junit4]   2> 356665 T3761 C488 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q=id:[1+TO+3]&fl=x_i&sort=x:x_i+desc&wt=xml} 
hits=3 status=0 QTime=0 
   [junit4]   2> 356665 T3761 C488 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> 356666 T3761 C488 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=0 
   [junit4]   2> 356667 T3761 C488 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=1 
   [junit4]   2> 356667 T3761 oas.SolrTestCaseJ4.tearDown ###Ending 
testSortByFunc
   [junit4]   2> 356669 T3761 oas.SolrTestCaseJ4.setUp ###Starting 
testExternalFieldValueSourceParser
   [junit4]   2> 356669 T3761 C488 oasu.DirectUpdateHandler2.deleteAll 
[collection1] REMOVING ALL DOCUMENTS FROM INDEX
   [junit4]   2> 356669 T3761 C488 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 0
   [junit4]   2> 356670 T3761 C488 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[100.0]} 0 0
   [junit4]   2> 356670 T3761 C488 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[-4.0]} 0 0
   [junit4]   2> 356670 T3761 C488 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 356672 T3761 C488 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@cb74d1c 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3ba1b085),segFN=segments_e,generation=14}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@cb74d1c 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3ba1b085),segFN=segments_f,generation=15}
   [junit4]   2> 356672 T3761 C488 oasc.SolrDeletionPolicy.updateCommits newest 
commit generation = 15
   [junit4]   2> 356673 T3761 C488 oass.SolrIndexSearcher.<init> Opening 
Searcher@47736387[collection1] main
   [junit4]   2> 356673 T3761 C488 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 356673 T3763 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@47736387[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_d(6.0.0):c2)))}
   [junit4]   2> 356673 T3761 C488 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 3
   [junit4]   2> 356674 T3761 C488 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[0.0]} 0 1
   [junit4]   2> 356674 T3761 C488 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 356675 T3761 C488 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@cb74d1c 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3ba1b085),segFN=segments_f,generation=15}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@cb74d1c 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3ba1b085),segFN=segments_g,generation=16}
   [junit4]   2> 356675 T3761 C488 oasc.SolrDeletionPolicy.updateCommits newest 
commit generation = 16
   [junit4]   2> 356675 T3761 C488 oass.SolrIndexSearcher.<init> Opening 
Searcher@684cb79c[collection1] main
   [junit4]   2> 356676 T3761 C488 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 356676 T3763 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@684cb79c[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_d(6.0.0):c2)
 Uninverting(_e(6.0.0):c1)))}
   [junit4]   2> 356676 T3761 C488 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 2
   [junit4]   2> 356676 T3761 C488 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[10.0]} 0 0
   [junit4]   2> 356677 T3761 C488 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[25.0]} 0 0
   [junit4]   2> 356677 T3761 C488 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[5.0]} 0 0
   [junit4]   2> 356677 T3761 C488 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[77.0]} 0 0
   [junit4]   2> 356678 T3761 C488 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[23.0]} 0 1
   [junit4]   2> 356678 T3761 C488 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[55.0]} 0 0
   [junit4]   2> 356678 T3761 C488 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[-78.0]} 0 0
   [junit4]   2> 356679 T3761 C488 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[-45.0]} 0 0
   [junit4]   2> 356679 T3761 C488 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[-45.0]} 0 0
   [junit4]   2> 356679 T3761 C488 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[-24.0]} 0 0
   [junit4]   2> 356680 T3761 C488 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[63.0]} 0 0
   [junit4]   2> 356680 T3761 C488 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[78.0]} 0 0
   [junit4]   2> 356680 T3761 C488 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 356682 T3761 C488 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@cb74d1c 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3ba1b085),segFN=segments_g,generation=16}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@cb74d1c 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3ba1b085),segFN=segments_h,generation=17}
   [junit4]   2> 356682 T3761 C488 oasc.SolrDeletionPolicy.updateCommits newest 
commit generation = 17
   [junit4]   2> 356682 T3761 C488 oass.SolrIndexSearcher.<init> Opening 
Searcher@86bae38[collection1] main
   [junit4]   2> 356682 T3761 C488 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 356682 T3763 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@86bae38[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_d(6.0.0):c2)
 Uninverting(_e(6.0.0):c1) Uninverting(_f(6.0.0):c12/1:delGen=1)))}
   [junit4]   2> 356683 T3761 C488 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 3
   [junit4]   2> 356683 T3761 C488 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[94.0]} 0 0
   [junit4]   2> 356684 T3761 C488 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[22.0]} 0 0
   [junit4]   2> 356684 T3761 C488 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[34.0]} 0 0
   [junit4]   2> 356684 T3761 C488 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[34.0]} 0 0
   [junit4]   2> 356685 T3761 C488 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[54321.0]} 0 0
   [junit4]   2> 356685 T3761 C488 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[261.0]} 0 0
   [junit4]   2> 356686 T3761 C488 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[261.0]} 0 1
   [junit4]   2> 356686 T3761 C488 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[-627.0]} 0 0
   [junit4]   2> 356686 T3761 C488 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[-627.0]} 0 0
   [junit4]   2> 356686 T3761 C488 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 356688 T3761 C488 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@cb74d1c 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3ba1b085),segFN=segments_h,generation=17}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@cb74d1c 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3ba1b085),segFN=segments_i,generation=18}
   [junit4]   2> 356688 T3761 C488 oasc.SolrDeletionPolicy.updateCommits newest 
commit generation = 18
   [junit4]   2> 356689 T3761 C488 oass.SolrIndexSearcher.<init> Opening 
Searcher@25389872[collection1] main
   [junit4]   2> 356689 T3761 C488 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 356689 T3763 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@25389872[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_d(6.0.0):c2)
 Uninverting(_e(6.0.0):c1) Uninverting(_f(6.0.0):c12/1:delGen=1) 
Uninverting(_g(6.0.0):c9/3:delGen=1)))}
   [junit4]   2> 356689 T3761 C488 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 3
   [junit4]   2> 356690 T3761 C488 oassf.FileFloatSource.getFloats Loaded 
external value source external_CoMpleX fieldName _extf
   [junit4]   2> 356690 T3761 C488 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=0 
   [junit4]   2> ASYNC  NEW_CORE C489 name=collection1 
org.apache.solr.core.SolrCore@35cc3b0f
   [junit4]   2> 356694 T3761 C489 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> 356695 T3761 C489 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> 356696 T3761 C489 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[10000]} 0 1
   [junit4]   2> 356696 T3761 C489 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 356697 T3761 C489 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@cb74d1c 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3ba1b085),segFN=segments_i,generation=18}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@cb74d1c 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3ba1b085),segFN=segments_j,generation=19}
   [junit4]   2> 356698 T3761 C489 oasc.SolrDeletionPolicy.updateCommits newest 
commit generation = 19
   [junit4]   2> 356698 T3761 C489 oass.SolrIndexSearcher.<init> Opening 
Searcher@4ad3ec64[collection1] main
   [junit4]   2> 356698 T3761 C489 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 356698 T3763 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@4ad3ec64[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_d(6.0.0):c2)
 Uninverting(_e(6.0.0):c1) Uninverting(_f(6.0.0):c12/1:delGen=1) 
Uninverting(_g(6.0.0):c9/3:delGen=1) Uninverting(_h(6.0.0):c1)))}
   [junit4]   2> 356698 T3761 C489 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 2
   [junit4]   2> 356699 T3761 C489 oassf.FileFloatSource.getFloats Loaded 
external value source external_CoMpleX fieldName _extf
   [junit4]   2> 356699 T3761 C489 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=0 
   [junit4]   2> 356700 T3761 oas.SolrTestCaseJ4.tearDown ###Ending 
testExternalFieldValueSourceParser
   [junit4]   2> 356701 T3761 oas.SolrTestCaseJ4.setUp ###Starting 
testFieldValueSourceParser
   [junit4]   2> 356702 T3761 C489 oasu.DirectUpdateHandler2.deleteAll 
[collection1] REMOVING ALL DOCUMENTS FROM INDEX
   [junit4]   2> 356702 T3761 C489 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 1
   [junit4]   2> 356702 T3761 C489 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[100.0]} 0 0
   [junit4]   2> 356703 T3761 C489 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[-4.0]} 0 0
   [junit4]   2> 356703 T3761 C489 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[0.0]} 0 0
   [junit4]   2> 356704 T3761 C489 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[0.0]} 0 0
   [junit4]   2> 356704 T3761 C489 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[10.0]} 0 0
   [junit4]   2> 356704 T3761 C489 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[25.0]} 0 0
   [junit4]   2> 356705 T3761 C489 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 356706 T3761 C489 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@cb74d1c 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3ba1b085),segFN=segments_j,generation=19}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@cb74d1c 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3ba1b085),segFN=segments_k,generation=20}
   [junit4]   2> 356706 T3761 C489 oasc.SolrDeletionPolicy.updateCommits newest 
commit generation = 20
   [junit4]   2> 356707 T3761 C489 oass.SolrIndexSearcher.<init> Opening 
Searcher@19563a06[collection1] main
   [junit4]   2> 356707 T3761 C489 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 356707 T3763 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@19563a06[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_i(6.0.0):c6/1:delGen=1)))}
   [junit4]   2> 356708 T3761 C489 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 3
   [junit4]   2> 356708 T3761 C489 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[5.0]} 0 0
   [junit4]   2> 356708 T3761 C489 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[77.0]} 0 0
   [junit4]   2> 356709 T3761 C489 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[1.0]} 0 0
   [junit4]   2> 356709 T3761 C489 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 356710 T3761 C489 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@cb74d1c 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3ba1b085),segFN=segments_k,generation=20}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@cb74d1c 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3ba1b085),segFN=segments_l,generation=21}
   [junit4]   2> 356711 T3761 C489 oasc.SolrDeletionPolicy.updateCommits newest 
commit generation = 21
   [junit4]   2> 356711 T3761 C489 oass.SolrIndexSearcher.<init> Opening 
Searcher@3d1f3173[collection1] main
   [junit4]   2> 356711 T3761 C489 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 356711 T3763 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@3d1f3173[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_i(6.0.0):c6/1:delGen=1)
 Uninverting(_j(6.0.0):c3)))}
   [junit4]   2> 356711 T3761 C489 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 2
   [junit4]   2> 356712 T3761 C489 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}field("CoMpleX+\"+fieldName+_f")&indent=on&fl=*,score&rows=100&wt=xml}
 hits=8 status=0 QTime=0 
   [junit4]   2> 356713 T3761 C489 oasc.SolrCore.execute [collection1] web

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

=1 status=0 QTime=0 
   [junit4]   2> 356878 T3761 C489 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> 356879 T3761 C489 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=id:1&fl=noval_if:if(no__vals____dt,42,-99)&fl=noval_def:def(no__vals____dt,-99)&fl=noval_not:not(no__vals____dt)&fl=noval_exists:exists(no__vals____dt)&wt=xml}
 hits=1 status=0 QTime=1 
   [junit4]   2> 356879 T3761 C489 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> ASYNC  NEW_CORE C490 name=collection1 
org.apache.solr.core.SolrCore@35cc3b0f
   [junit4]   2> 356883 T3761 C490 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=1 
   [junit4]   2> 356884 T3761 C490 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=id:1&fl=noval_if:if(no__vals____l,42,-99)&fl=noval_def:def(no__vals____l,-99)&fl=noval_not:not(no__vals____l)&fl=noval_exists:exists(no__vals____l)&wt=xml}
 hits=1 status=0 QTime=0 
   [junit4]   2> 356885 T3761 C490 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=1 
   [junit4]   2> 356885 T3761 C490 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> 356886 T3761 C490 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> 356887 T3761 C490 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=1 
   [junit4]   2> 356887 T3761 C490 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> 356888 T3761 C490 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=id:1&fl=noval_if:if(no__vals____td,42,-99)&fl=noval_def:def(no__vals____td,-99)&fl=noval_not:not(no__vals____td)&fl=noval_exists:exists(no__vals____td)&wt=xml}
 hits=1 status=0 QTime=0 
   [junit4]   2> 356889 T3761 oas.SolrTestCaseJ4.tearDown ###Ending 
testMissingFieldFunctionBehavior
   [junit4]   2> 356889 T3761 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> 356889 T3761 oasc.CoreContainer.shutdown Shutting down 
CoreContainer instance=1602838087
   [junit4]   2> 356889 T3761 oasc.SolrCore.close [collection1]  CLOSING 
SolrCore org.apache.solr.core.SolrCore@35cc3b0f
   [junit4]   2> 356889 T3761 oasu.DirectUpdateHandler2.close closing 
DirectUpdateHandler2{commits=47,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> 356890 T3761 oasu.SolrCoreState.decrefSolrCoreState Closing 
SolrCoreState
   [junit4]   2> 356890 T3761 oasu.DefaultSolrCoreState.closeIndexWriter 
SolrCoreState ref count has reached 0 - closing IndexWriter
   [junit4]   2> 356890 T3761 oasu.DefaultSolrCoreState.closeIndexWriter 
closing IndexWriter with IndexWriterCloser
   [junit4]   2> 356890 T3761 oasc.SolrCore.closeSearcher [collection1] Closing 
main searcher on request.
   [junit4]   2> 356890 T3761 oasc.CachingDirectoryFactory.close Closing 
MockDirectoryFactory - 2 directories currently being tracked
   [junit4]   2> 356890 T3761 oasc.CachingDirectoryFactory.closeCacheValue 
looking to close 
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.search.function.TestFunctionQuery
 178897549DDEEF09-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
 178897549DDEEF09-001/init-core-data-001;done=false>>]
   [junit4]   2> 356891 T3761 oasc.CachingDirectoryFactory.close Closing 
directory: 
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.search.function.TestFunctionQuery
 178897549DDEEF09-001/init-core-data-001
   [junit4]   2> 356891 T3761 oasc.CachingDirectoryFactory.closeCacheValue 
looking to close 
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.search.function.TestFunctionQuery
 178897549DDEEF09-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
 178897549DDEEF09-001/init-core-data-001/index;done=false>>]
   [junit4]   2> 356891 T3761 oasc.CachingDirectoryFactory.close Closing 
directory: 
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.search.function.TestFunctionQuery
 178897549DDEEF09-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
 178897549DDEEF09-001
   [junit4]   2> NOTE: test params are: codec=Asserting(Lucene50): 
{x_td=Lucene50(blocksize=128), const_s=Lucene50(blocksize=128), 
x_i=PostingsFormat(name=MockRandom), 1_s=FSTOrd50, 
a_tdt=PostingsFormat(name=MockRandom), eff_ti=Lucene50(blocksize=128), 
foo_s=PostingsFormat(name=MockRandom), x_s=BlockTreeOrds(blocksize=128), 
1-1_s=FSTOrd50, y_td=PostingsFormat(name=MockRandom), foo_tl=FSTOrd50, CoMpleX 
" fieldName _f=BlockTreeOrds(blocksize=128), 
foo_ti=BlockTreeOrds(blocksize=128), foo_tf=Lucene50(blocksize=128), 
b_tdt=Lucene50(blocksize=128), sfile_s=Lucene50(blocksize=128), 
x:x_i=BlockTreeOrds(blocksize=128), a_t=PostingsFormat(name=MockRandom), 
foo_d=Lucene50(blocksize=128), id=Lucene50(blocksize=128), text=FSTOrd50, 
yak_i=FSTOrd50, foo_f=FSTOrd50}, docValues:{}, 
sim=RandomSimilarityProvider(queryNorm=false,coord=yes): {}, locale=sk, 
timezone=EST
   [junit4]   2> NOTE: Linux 3.13.0-46-generic amd64/Oracle Corporation 
1.9.0-ea (64-bit)/cpus=12,threads=1,free=351359728,total=508887040
   [junit4]   2> NOTE: All tests run in this JVM: [RequestHandlersTest, 
TestExpandComponent, PingRequestHandlerTest, TestHighlightDedupGrouping, 
SaslZkACLProviderTest, TestStressLucene, HdfsDirectoryFactoryTest, 
SolrIndexConfigTest, TestStandardQParsers, TestMissingGroups, 
SimpleCollectionCreateDeleteTest, TestFreeTextSuggestions, 
HdfsBasicDistributedZkTest, TestSchemaSimilarityResource, 
TestManagedResourceStorage, TestDefaultStatsCache, TestFieldCollectionResource, 
TestPhraseSuggestions, TestSolrIndexConfig, SyncSliceTest, TestLazyCores, 
IndexSchemaTest, TestDFRSimilarityFactory, 
SharedFSAutoReplicaFailoverUtilsTest, SpatialHeatmapFacetsTest, 
TestTrackingShardHandlerFactory, TestReplicationHandler, FacetPivotSmallTest, 
DistributedIntervalFacetingTest, TestSolrConfigHandler, TestRandomDVFaceting, 
DistributedSuggestComponentTest, CachingDirectoryFactoryTest, 
FastVectorHighlighterTest, DistributedFacetPivotLargeTest, 
ChaosMonkeyNothingIsSafeTest, SchemaVersionSpecificBehaviorTest, 
TestIBSimilarityFactory, QueryResultKeyTest, TestCodecSupport, 
TestHdfsUpdateLog, TestDistributedMissingSort, HighlighterTest, 
TestArbitraryIndexDir, OutOfBoxZkACLAndCredentialsProvidersTest, TestCSVLoader, 
LeaderElectionIntegrationTest, ResponseHeaderTest, IndexBasedSpellCheckerTest, 
TestSimpleTrackingShardHandler, TestFunctionQuery]
   [junit4] Completed on J0 in 0.56s, 15 tests, 1 error <<< FAILURES!

[...truncated 960 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: 39 minutes 12 seconds
Build step 'Invoke Ant' marked build as failure
[description-setter] Description set: Java: 64bit/jdk1.9.0-ea-b54 
-XX:-UseCompressedOops -XX:+UseConcMarkSweepGC
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