Build: http://jenkins.thetaphi.de/job/Lucene-Solr-5.x-Linux/11866/
Java: 32bit/jdk1.7.0_76 -client -XX:+UseParallelGC

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([EE346A9408D44397:B00E88E93442BFDB]: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:57)
        at 
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:606)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java: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 10029 lines...]
   [junit4] Suite: org.apache.solr.search.function.TestFunctionQuery
   [junit4]   2> Creating dataDir: 
/home/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.search.function.TestFunctionQuery
 EE346A9408D44397-001/init-core-data-001
   [junit4]   2> 784136 T6288 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl 
(false) and clientAuth (false)
   [junit4]   2> 784137 T6288 oas.SolrTestCaseJ4.initCore ####initCore
   [junit4]   2> 784137 T6288 oasc.SolrResourceLoader.<init> new 
SolrResourceLoader for directory: 
'/home/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/core/src/test-files/solr/collection1/'
   [junit4]   2> 784138 T6288 oasc.SolrResourceLoader.replaceClassLoader Adding 
'file:/home/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/core/src/test-files/solr/collection1/lib/classes/'
 to classloader
   [junit4]   2> 784138 T6288 oasc.SolrResourceLoader.replaceClassLoader Adding 
'file:/home/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/core/src/test-files/solr/collection1/lib/README'
 to classloader
   [junit4]   2> 784154 T6288 oasc.SolrConfig.refreshRequestParams current 
version of requestparams : -1
   [junit4]   2> 784163 T6288 oasc.SolrConfig.<init> Using Lucene MatchVersion: 
5.1.0
   [junit4]   2> 784186 T6288 oasc.SolrConfig.<init> Loaded SolrConfig: 
solrconfig-functionquery.xml
   [junit4]   2> 784187 T6288 oass.IndexSchema.readSchema Reading Solr Schema 
from 
/home/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/core/src/test-files/solr/collection1/conf/schema11.xml
   [junit4]   2> 784190 T6288 oass.IndexSchema.readSchema [null] Schema 
name=example
   [junit4]   2> 784254 T6288 oass.IndexSchema.readSchema default search field 
in schema is text
   [junit4]   2> 784256 T6288 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 784258 T6288 oasc.SolrResourceLoader.locateSolrHome JNDI not 
configured for solr (NoInitialContextEx)
   [junit4]   2> 784258 T6288 oasc.SolrResourceLoader.locateSolrHome using 
system property solr.solr.home: 
/home/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/core/src/test-files/solr
   [junit4]   2> 784258 T6288 oasc.SolrResourceLoader.<init> new 
SolrResourceLoader for directory: 
'/home/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/core/src/test-files/solr/'
   [junit4]   2> 784268 T6288 oasc.CoreContainer.<init> New CoreContainer 
24227803
   [junit4]   2> 784268 T6288 oasc.CoreContainer.load Loading cores into 
CoreContainer 
[instanceDir=/home/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/core/src/test-files/solr/]
   [junit4]   2> 784268 T6288 oasc.CoreContainer.load loading shared library: 
/home/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/core/src/test-files/solr/lib
   [junit4]   2> 784268 T6288 oasc.SolrResourceLoader.addToClassLoader WARN 
Can't find (or read) directory to add to classloader: lib (resolved as: 
/home/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/core/src/test-files/solr/lib).
   [junit4]   2> 784273 T6288 oashc.HttpShardHandlerFactory.getParameter 
Setting socketTimeout to: 600000
   [junit4]   2> 784273 T6288 oashc.HttpShardHandlerFactory.getParameter 
Setting urlScheme to: null
   [junit4]   2> 784273 T6288 oashc.HttpShardHandlerFactory.getParameter 
Setting connTimeout to: 60000
   [junit4]   2> 784273 T6288 oashc.HttpShardHandlerFactory.getParameter 
Setting maxConnectionsPerHost to: 20
   [junit4]   2> 784274 T6288 oashc.HttpShardHandlerFactory.getParameter 
Setting maxConnections to: 10000
   [junit4]   2> 784274 T6288 oashc.HttpShardHandlerFactory.getParameter 
Setting corePoolSize to: 0
   [junit4]   2> 784274 T6288 oashc.HttpShardHandlerFactory.getParameter 
Setting maximumPoolSize to: 2147483647
   [junit4]   2> 784274 T6288 oashc.HttpShardHandlerFactory.getParameter 
Setting maxThreadIdleTime to: 5
   [junit4]   2> 784274 T6288 oashc.HttpShardHandlerFactory.getParameter 
Setting sizeOfQueue to: -1
   [junit4]   2> 784275 T6288 oashc.HttpShardHandlerFactory.getParameter 
Setting fairnessPolicy to: false
   [junit4]   2> 784275 T6288 oashc.HttpShardHandlerFactory.getParameter 
Setting useRetries to: false
   [junit4]   2> 784275 T6288 oasu.UpdateShardHandler.<init> Creating 
UpdateShardHandler HTTP client with params: 
socketTimeout=30000&connTimeout=30000&retry=true
   [junit4]   2> 784275 T6288 oasl.LogWatcher.createWatcher SLF4J impl is 
org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 784275 T6288 oasl.LogWatcher.newRegisteredLogWatcher 
Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 784276 T6288 oasc.CoreContainer.load Node Name: testNode
   [junit4]   2> 784276 T6288 oasc.CoreDescriptor.<init> CORE DESCRIPTOR: 
{transient=false, collection=collection1, instanceDir=collection1, 
config=solrconfig-functionquery.xml, shard=shard1, schema=schema11.xml, 
loadOnStartup=true, 
dataDir=/home/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.search.function.TestFunctionQuery
 EE346A9408D44397-001/init-core-data-001, 
absoluteInstDir=/home/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/core/src/test-files/solr/collection1/,
 name=collection1}
   [junit4]   2> 784277 T6289 oasc.SolrResourceLoader.<init> new 
SolrResourceLoader for directory: 
'/home/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/core/src/test-files/solr/collection1/'
   [junit4]   2> 784277 T6289 oasc.SolrResourceLoader.replaceClassLoader Adding 
'file:/home/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/core/src/test-files/solr/collection1/lib/classes/'
 to classloader
   [junit4]   2> 784277 T6289 oasc.SolrResourceLoader.replaceClassLoader Adding 
'file:/home/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/core/src/test-files/solr/collection1/lib/README'
 to classloader
   [junit4]   2> 784291 T6289 oasc.SolrConfig.refreshRequestParams current 
version of requestparams : -1
   [junit4]   2> 784300 T6289 oasc.SolrConfig.<init> Using Lucene MatchVersion: 
5.1.0
   [junit4]   2> 784318 T6289 oasc.SolrConfig.<init> Loaded SolrConfig: 
solrconfig-functionquery.xml
   [junit4]   2> 784318 T6289 oass.IndexSchema.readSchema Reading Solr Schema 
from 
/home/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/core/src/test-files/solr/collection1/conf/schema11.xml
   [junit4]   2> 784322 T6289 oass.IndexSchema.readSchema [collection1] Schema 
name=example
   [junit4]   2> 784391 T6289 oass.IndexSchema.readSchema default search field 
in schema is text
   [junit4]   2> 784393 T6289 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 784395 T6289 oasc.CoreContainer.create Creating SolrCore 
'collection1' using configuration from instancedir 
/home/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/core/src/test-files/solr/collection1/
   [junit4]   2> 784395 T6289 oasc.SolrCore.initDirectoryFactory 
org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 784395 T6289 oasc.SolrCore.<init> [collection1] Opening new 
SolrCore at 
/home/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/core/src/test-files/solr/collection1/,
 
dataDir=/home/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.search.function.TestFunctionQuery
 EE346A9408D44397-001/init-core-data-001/
   [junit4]   2> 784395 T6289 oasc.SolrCore.<init> JMX monitoring not detected 
for core: collection1
   [junit4]   2> 784396 T6289 oasc.CachingDirectoryFactory.get return new 
directory for 
/home/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.search.function.TestFunctionQuery
 EE346A9408D44397-001/init-core-data-001
   [junit4]   2> 784396 T6289 oasc.SolrCore.getNewIndexDir New index directory 
detected: old=null 
new=/home/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.search.function.TestFunctionQuery
 EE346A9408D44397-001/init-core-data-001/index/
   [junit4]   2> 784396 T6289 oasc.SolrCore.initIndex WARN [collection1] Solr 
index directory 
'/home/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.search.function.TestFunctionQuery
 EE346A9408D44397-001/init-core-data-001/index' doesn't exist. Creating new 
index...
   [junit4]   2> 784396 T6289 oasc.CachingDirectoryFactory.get return new 
directory for 
/home/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.search.function.TestFunctionQuery
 EE346A9408D44397-001/init-core-data-001/index
   [junit4]   2> 784397 T6289 oasu.RandomMergePolicy.<init> RandomMergePolicy 
wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: 
maxMergeAtOnce=42, maxMergeAtOnceExplicit=37, maxMergedSegmentMB=41.333984375, 
floorSegmentMB=0.73828125, forceMergeDeletesPctAllowed=18.16564417327851, 
segmentsPerTier=50.0, maxCFSSegmentSizeMB=8.796093022207999E12, 
noCFSRatio=0.7930142088024849
   [junit4]   2> 784397 T6289 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@106c185 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@8b18d4),segFN=segments_1,generation=1}
   [junit4]   2> 784397 T6289 oasc.SolrDeletionPolicy.updateCommits newest 
commit generation = 1
   [junit4]   2> 784400 T6289 oasc.SolrCore.loadUpdateProcessorChains no 
updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 784401 T6289 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 784402 T6289 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 784403 T6289 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 784404 T6289 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 784406 T6289 oasc.RequestHandlers.initHandlersFromConfig 
Registered paths: 
/update/json/docs,/replication,/admin/logging,/admin/segments,/admin/plugins,/admin/ping,/admin/properties,/admin/system,/admin/file,/admin/threads,/admin/mbeans,/schema,/get,/reloadCache,standard,/config,/update/csv,/update,/update/json,/admin/luke
   [junit4]   2> 784407 T6289 oasc.SolrCore.initStatsCache Using default 
statsCache cache: org.apache.solr.search.stats.LocalStatsCache
   [junit4]   2> 784407 T6289 oasu.CommitTracker.<init> Hard AutoCommit: 
disabled
   [junit4]   2> 784407 T6289 oasu.CommitTracker.<init> Soft AutoCommit: 
disabled
   [junit4]   2> 784408 T6289 oasu.RandomMergePolicy.<init> RandomMergePolicy 
wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: 
maxMergeAtOnce=25, maxMergeAtOnceExplicit=48, maxMergedSegmentMB=68.5810546875, 
floorSegmentMB=1.4873046875, forceMergeDeletesPctAllowed=3.419653583777995, 
segmentsPerTier=24.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 784408 T6289 oasc.SolrDeletionPolicy.onInit 
SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@106c185 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@8b18d4),segFN=segments_1,generation=1}
   [junit4]   2> 784408 T6289 oasc.SolrDeletionPolicy.updateCommits newest 
commit generation = 1
   [junit4]   2> 784409 T6289 oass.SolrIndexSearcher.<init> Opening 
Searcher@7d71dd[collection1] main
   [junit4]   2> 784409 T6289 oasr.ManagedResourceStorage.newStorageIO WARN 
Cannot write to config directory 
/home/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/core/src/test-files/solr/collection1/conf;
 switching to use InMemory storage instead.
   [junit4]   2> 784409 T6289 oasr.RestManager.init Initializing RestManager 
with initArgs: {}
   [junit4]   2> 784409 T6289 oasr.ManagedResourceStorage.load Reading 
_rest_managed.json using InMemoryStorage
   [junit4]   2> 784409 T6289 oasr.RestManager.init Initializing 0 registered 
ManagedResources
   [junit4]   2> 784409 T6289 oash.ReplicationHandler.inform Commits will be 
reserved for  10000
   [junit4]   2> 784410 T6290 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@7d71dd[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 784410 T6289 oasc.CoreContainer.registerCore registering core: 
collection1
   [junit4]   2> 784411 T6288 oas.SolrTestCaseJ4.initCore ####initCore end
   [junit4]   2> 784413 T6288 oas.SolrTestCaseJ4.setUp ###Starting 
testBooleanFunctions
   [junit4]   2> ASYNC  NEW_CORE C911 name=collection1 
org.apache.solr.core.SolrCore@41ceb3
   [junit4]   2> 784414 T6288 C911 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[1]} 0 0
   [junit4]   2> 784416 T6288 C911 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[2]} 0 0
   [junit4]   2> 784417 T6288 C911 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 784418 T6288 C911 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@106c185 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@8b18d4),segFN=segments_1,generation=1}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@106c185 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@8b18d4),segFN=segments_2,generation=2}
   [junit4]   2> 784419 T6288 C911 oasc.SolrDeletionPolicy.updateCommits newest 
commit generation = 2
   [junit4]   2> 784419 T6288 C911 oass.SolrIndexSearcher.<init> Opening 
Searcher@6e8b4c[collection1] main
   [junit4]   2> 784420 T6288 C911 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 784420 T6290 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@6e8b4c[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(5.1.0):c2)))}
   [junit4]   2> 784420 T6288 C911 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 3
   [junit4]   2> 784421 T6288 C911 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> 784423 T6288 C911 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> 784425 T6288 C911 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=id:1&q1=text:hello&fl=t:exists(query($q1)),f:exists(query($q2))&wt=xml&q2=text:there}
 hits=1 status=0 QTime=1 
   [junit4]   2> 784427 T6288 C911 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=id:1&fl=a1:if(true,'A','B')&fl=b1:if(false,'A',testfunc('B'))&wt=xml} 
hits=1 status=0 QTime=0 
   [junit4]   2> 784429 T6288 C911 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> 784430 T6288 C911 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=id:1&fl=t1:or(testfunc(true),true)&fl=t2:or(true,false)&fl=t3:or(false,true)&fl=f1:or(false,false)&wt=xml}
 hits=1 status=0 QTime=0 
   [junit4]   2> 784430 T6288 C911 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> 784431 T6288 C911 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> 784434 T6288 C911 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=id:1&fl=x:def(id,testfunc(123.0)),+y:def(foo_f,234.0)&wt=xml} hits=1 
status=0 QTime=3 
   [junit4]   2> 784438 T6288 C911 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> 784438 T6288 C911 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> 784438 T6288 oas.SolrTestCaseJ4.tearDown ###Ending 
testBooleanFunctions
   [junit4]   2> 784441 T6288 oas.SolrTestCaseJ4.setUp ###Starting 
testPseudoFieldFunctions
   [junit4]   2> 784442 T6288 C911 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[1]} 0 1
   [junit4]   2> 784443 T6288 C911 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[2]} 0 0
   [junit4]   2> 784443 T6288 C911 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 784445 T6288 C911 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@106c185 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@8b18d4),segFN=segments_2,generation=2}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@106c185 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@8b18d4),segFN=segments_3,generation=3}
   [junit4]   2> 784445 T6288 C911 oasc.SolrDeletionPolicy.updateCommits newest 
commit generation = 3
   [junit4]   2> 784446 T6288 C911 oass.SolrIndexSearcher.<init> Opening 
Searcher@87e2e6[collection1] main
   [junit4]   2> 784446 T6288 C911 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 784446 T6290 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@87e2e6[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_1(5.1.0):c2)))}
   [junit4]   2> 784447 T6288 C911 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 4
   [junit4]   2> 784447 T6288 C911 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=id:1&fl=a:1,b:2.0,c:'X',d:{!func}foo_s,e:{!func}bar_s&wt=xml} hits=1 
status=0 QTime=0 
   [junit4]   2> 784448 T6288 oas.SolrTestCaseJ4.assertJQ ERROR query failed 
JSON validation. error=unexpected map keys [e] @ response/docs/[0]
   [junit4]   2>         expected =/response/docs/[0]=={'a':1, 
'b':2.0,'c':'X','d':'A'}
   [junit4]   2>         response = {
   [junit4]   2>          "responseHeader":{
   [junit4]   2>            "status":0,
   [junit4]   2>            "QTime":0},
   [junit4]   2>          "response":{"numFound":1,"start":0,"docs":[
   [junit4]   2>              {
   [junit4]   2>                "a":1,
   [junit4]   2>                "b":2.0,
   [junit4]   2>                "c":"X",
   [junit4]   2>                "d":"A",
   [junit4]   2>                "e":null}]
   [junit4]   2>          }}
   [junit4]   2>        
   [junit4]   2>         request = 
q=id:1&fl=a:1,b:2.0,c:'X',d:{!func}foo_s,e:{!func}bar_s&wt=xml
   [junit4]   2> 784448 T6288 oas.SolrTestCaseJ4.tearDown ###Ending 
testPseudoFieldFunctions
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=TestFunctionQuery 
-Dtests.method=testPseudoFieldFunctions -Dtests.seed=EE346A9408D44397 
-Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=lt_LT 
-Dtests.timezone=Australia/Adelaide -Dtests.asserts=true 
-Dtests.file.encoding=US-ASCII
   [junit4] ERROR   0.02s J1 | TestFunctionQuery.testPseudoFieldFunctions <<<
   [junit4]    > Throwable #1: java.lang.RuntimeException: unexpected map keys 
[e] @ response/docs/[0]
   [junit4]    >        at 
__randomizedtesting.SeedInfo.seed([EE346A9408D44397:B00E88E93442BFDB]:0)
   [junit4]    >        at 
org.apache.solr.SolrTestCaseJ4.assertJQ(SolrTestCaseJ4.java:882)
   [junit4]    >        at 
org.apache.solr.SolrTestCaseJ4.assertJQ(SolrTestCaseJ4.java:829)
   [junit4]    >        at 
org.apache.solr.search.function.TestFunctionQuery.testPseudoFieldFunctions(TestFunctionQuery.java:739)
   [junit4]    >        at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 784458 T6288 oas.SolrTestCaseJ4.setUp ###Starting 
testStrDistance
   [junit4]   2> 784459 T6288 C911 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[1]} 0 1
   [junit4]   2> 784460 T6288 C911 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 784461 T6288 C911 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@106c185 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@8b18d4),segFN=segments_3,generation=3}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@106c185 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@8b18d4),segFN=segments_4,generation=4}
   [junit4]   2> 784462 T6288 C911 oasc.SolrDeletionPolicy.updateCommits newest 
commit generation = 4
   [junit4]   2> 784462 T6288 C911 oass.SolrIndexSearcher.<init> Opening 
Searcher@1e0cc31[collection1] main
   [junit4]   2> 784462 T6288 C911 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 784462 T6290 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@1e0cc31[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_1(5.1.0):c2/1:delGen=1)
 Uninverting(_2(5.1.0):c1)))}
   [junit4]   2> 784463 T6288 C911 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 3
   [junit4]   2> 784465 T6288 C911 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}strdist(x_s,+'foit',+edit)&fq=id:1&fl=*,score&wt=xml} hits=1 
status=0 QTime=1 
   [junit4]   2> 784466 T6288 C911 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}strdist(x_s,+'foit',+jw)&fq=id:1&fl=*,score&wt=xml} hits=1 
status=0 QTime=0 
   [junit4]   2> 784468 T6288 C911 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}strdist(x_s,+'foit',+ngram,+2)&fq=id:1&fl=*,score&wt=xml} 
hits=1 status=0 QTime=1 
   [junit4]   2> 784469 T6288 C911 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=id:1&fl=good:strdist(x_s,+'toil',+edit)&fl=bad1:strdist(missing1_s,+missing2_s,+edit)&fl=bad2:strdist(missing1_s,+'something',+edit)&fl=bad3:strdist(missing1_s,+x_s,+edit)&wt=xml}
 hits=1 status=0 QTime=0 
   [junit4]   2> 784470 T6288 C911 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}strdist(missing1_s,+missing2_s,+edit)&fq=id:1&fl=score&wt=xml} 
hits=1 status=0 QTime=0 
   [junit4]   2> 784471 T6288 C911 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}strdist(missing1_s,+x_s,+edit)&fq=id:1&fl=score&wt=xml} hits=1 
status=0 QTime=0 
   [junit4]   2> 784472 T6288 C911 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}strdist(missing1_s,+'const',+edit)&fq=id:1&fl=score&wt=xml} 
hits=1 status=0 QTime=0 
   [junit4]   2> 784472 T6288 oas.SolrTestCaseJ4.tearDown ###Ending 
testStrDistance
   [junit4]   2> 784475 T6288 oas.SolrTestCaseJ4.setUp ###Starting 
testExternalFileFieldStringKeys
   [junit4]   2> 784475 T6288 C911 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[991]} 0 0
   [junit4]   2> 784476 T6288 C911 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[992]} 0 0
   [junit4]   2> 784477 T6288 C911 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[993]} 0 0
   [junit4]   2> 784477 T6288 C911 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 784479 T6288 C911 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@106c185 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@8b18d4),segFN=segments_4,generation=4}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@106c185 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@8b18d4),segFN=segments_5,generation=5}
   [junit4]   2> 784479 T6288 C911 oasc.SolrDeletionPolicy.updateCommits newest 
commit generation = 5
   [junit4]   2> 784480 T6288 C911 oass.SolrIndexSearcher.<init> Opening 
Searcher@166c3d7[collection1] main
   [junit4]   2> 784480 T6288 C911 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 784480 T6290 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@166c3d7[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_1(5.1.0):c2/1:delGen=1)
 Uninverting(_2(5.1.0):c1) Uninverting(_3(5.1.0):c3)))}
   [junit4]   2> 784480 T6288 C911 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 3
   [junit4]   2> 784486 T6288 C911 oassf.FileFloatSource.getFloats Loaded 
external value source external_foo_extfs
   [junit4]   2> 784486 T6288 C911 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}foo_extfs&rows=100&fl=*,score&wt=xml&indent=on} hits=5 
status=0 QTime=5 
   [junit4]   2> 784488 T6288 oas.SolrTestCaseJ4.tearDown ###Ending 
testExternalFileFieldStringKeys
   [junit4]   2> 784490 T6288 oas.SolrTestCaseJ4.setUp ###Starting 
testExternalField
   [junit4]   2> 784491 T6288 C911 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[100.0]} 0 0
   [junit4]   2> 784492 T6288 C911 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[-4.0]} 0 0
   [junit4]   2> 784492 T6288 C911 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[0.0]} 0 0
   [junit4]   2> 784493 T6288 C911 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 784495 T6288 C911 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@106c185 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@8b18d4),segFN=segments_5,generation=5}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@106c185 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@8b18d4),segFN=segments_6,generation=6}
   [junit4]   2> 784495 T6288 C911 oasc.SolrDeletionPolicy.updateCommits newest 
commit generation = 6
   [junit4]   2> 784495 T6288 C911 oass.SolrIndexSearcher.<init> Opening 
Searcher@916984[collection1] main
   [junit4]   2> 784496 T6288 C911 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 784496 T6290 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@916984[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_1(5.1.0):c2/1:delGen=1)
 Uninverting(_2(5.1.0):c1) Uninverting(_3(5.1.0):c3) 
Uninverting(_4(5.1.0):c3)))}
   [junit4]   2> 784496 T6288 C911 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 3
   [junit4]   2> 784497 T6288 C911 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[10.0]} 0 0
   [junit4]   2> 784497 T6288 C911 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[10.0]} 0 0
   [junit4]   2> 784498 T6288 C911 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[25.0]} 0 0
   [junit4]   2> 784499 T6288 C911 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 784501 T6288 C911 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@106c185 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@8b18d4),segFN=segments_6,generation=6}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@106c185 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@8b18d4),segFN=segments_7,generation=7}
   [junit4]   2> 784501 T6288 C911 oasc.SolrDeletionPolicy.updateCommits newest 
commit generation = 7
   [junit4]   2> 784501 T6288 C911 oass.SolrIndexSearcher.<init> Opening 
Searcher@1522631[collection1] main
   [junit4]   2> 784502 T6288 C911 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 784502 T6290 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@1522631[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_1(5.1.0):c2/1:delGen=1)
 Uninverting(_2(5.1.0):c1) Uninverting(_3(5.1.0):c3) Uninverting(_4(5.1.0):c3) 
Uninverting(_5(5.1.0):c3/1:delGen=1)))}
   [junit4]   2> 784502 T6288 C911 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 3
   [junit4]   2> 784503 T6288 C911 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[5.0]} 0 0
   [junit4]   2> 784504 T6288 C911 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[77.0]} 0 0
   [junit4]   2> 784504 T6288 C911 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[23.0]} 0 0
   [junit4]   2> 784505 T6288 C911 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[55.0]} 0 0
   [junit4]   2> 784506 T6288 C911 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 784507 T6288 C911 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@106c185 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@8b18d4),segFN=segments_7,generation=7}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@106c185 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@8b18d4),segFN=segments_8,generation=8}
   [junit4]   2> 784507 T6288 C911 oasc.SolrDeletionPolicy.updateCommits newest 
commit generation = 8
   [junit4]   2> 784508 T6288 C911 oass.SolrIndexSearcher.<init> Opening 
Searcher@776c12[collection1] main
   [junit4]   2> 784508 T6288 C911 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 784508 T6290 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@776c12[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_1(5.1.0):c2/1:delGen=1)
 Uninverting(_2(5.1.0):c1) Uninverting(_3(5.1.0):c3) Uninverting(_4(5.1.0):c3) 
Uninverting(_5(5.1.0):c3/1:delGen=1) Uninverting(_6(5.1.0):c4)))}
   [junit4]   2> 784509 T6288 C911 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 3
   [junit4]   2> 784509 T6288 C911 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[-78.0]} 0 0
   [junit4]   2> 784510 T6288 C911 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[-45.0]} 0 0
   [junit4]   2> 784511 T6288 C911 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[-24.0]} 0 0
   [junit4]   2> 784512 T6288 C911 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[63.0]} 0 0
   [junit4]   2> 784512 T6288 C911 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[78.0]} 0 0
   [junit4]   2> 784513 T6288 C911 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[94.0]} 0 0
   [junit4]   2> 784514 T6288 C911 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 784515 T6288 C911 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@106c185 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@8b18d4),segFN=segments_8,generation=8}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@106c185 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@8b18d4),segFN=segments_9,generation=9}
   [junit4]   2> 784516 T6288 C911 oasc.SolrDeletionPolicy.updateCommits newest 
commit generation = 9
   [junit4]   2> 784516 T6288 C911 oass.SolrIndexSearcher.<init> Opening 
Searcher@162c1a7[collection1] main
   [junit4]   2> 784517 T6288 C911 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 784517 T6290 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@162c1a7[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_1(5.1.0):c2/1:delGen=1)
 Uninverting(_2(5.1.0):c1) Uninverting(_3(5.1.0):c3) Uninverting(_4(5.1.0):c3) 
Uninverting(_5(5.1.0):c3/1:delGen=1) Uninverting(_6(5.1.0):c4) 
Uninverting(_7(5.1.0):c6)))}
   [junit4]   2> 784517 T6288 C911 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 3
   [junit4]   2> 784518 T6288 C911 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[22.0]} 0 0
   [junit4]   2> 784519 T6288 C911 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[34.0]} 0 0
   [junit4]   2> 784519 T6288 C911 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[54321.0]} 0 0
   [junit4]   2> 784520 T6288 C911 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[261.0]} 0 0
   [junit4]   2> 784521 T6288 C911 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[-627.0]} 0 0
   [junit4]   2> 784521 T6288 C911 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 784523 T6288 C911 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@106c185 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@8b18d4),segFN=segments_9,generation=9}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@106c185 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@8b18d4),segFN=segments_a,generation=10}
   [junit4]   2> 784523 T6288 C911 oasc.SolrDeletionPolicy.updateCommits newest 
commit generation = 10
   [junit4]   2> 784524 T6288 C911 oass.SolrIndexSearcher.<init> Opening 
Searcher@fc5e10[collection1] main
   [junit4]   2> 784524 T6288 C911 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 784524 T6290 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@fc5e10[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_1(5.1.0):c2/1:delGen=1)
 Uninverting(_2(5.1.0):c1) Uninverting(_3(5.1.0):c3) Uninverting(_4(5.1.0):c3) 
Uninverting(_5(5.1.0):c3/1:delGen=1) Uninverting(_6(5.1.0):c4) 
Uninverting(_7(5.1.0):c6) Uninverting(_8(5.1.0):c5)))}
   [junit4]   2> 784524 T6288 C911 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 3
   [junit4]   2> 784525 T6288 C911 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 784525 T6288 C911 oasu.DirectUpdateHandler2.commit No 
uncommitted changes. Skipping IW.commit.
   [junit4]   2> 784526 T6288 C911 oasc.SolrCore.openNewSearcher 
SolrIndexSearcher has not changed - not re-opening: 
org.apache.solr.search.SolrIndexSearcher
   [junit4]   2> 784526 T6288 C911 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 784526 T6288 C911 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 1
   [junit4]   2> 784527 T6288 C911 oassf.FileFloatSource.getFloats Loaded 
external value source external_foo_extf
   [junit4]   2> 784528 T6288 C911 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}foo_extf&rows=100&fl=*,score&wt=xml&indent=on} hits=25 
status=0 QTime=1 
   [junit4]   2> 784532 T6288 C911 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}log(foo_extf)&rows=100&fl=*,score&wt=xml&indent=on} hits=25 
status=0 QTime=1 
   [junit4]   2> 784532 T6288 C911 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}sqrt(foo_extf)&rows=100&fl=*,score&wt=xml&indent=on} hits=25 
status=0 QTime=0 
   [junit4]   2> 784533 T6288 C911 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 784533 T6288 C911 oasu.DirectUpdateHandler2.commit No 
uncommitted changes. Skipping IW.commit.
   [junit4]   2> 784533 T6288 C911 oasc.SolrCore.openNewSearcher 
SolrIndexSearcher has not changed - not re-opening: 
org.apache.solr.search.SolrIndexSearcher
   [junit4]   2> 784534 T6288 C911 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 784534 T6288 C911 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={wt=xml&=} {commit=} 0 1
   [junit4]   2> 784534 T6288 C911 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {} 0 0
   [junit4]   2> 784535 T6288 C911 oassf.FileFloatSource.getFloats Loaded 
external value source external_foo_extf
   [junit4]   2> 784535 T6288 C911 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}sqrt(foo_extf)&rows=100&fl=*,score&wt=xml&indent=on} hits=25 
status=0 QTime=0 
   [junit4]   2> 784536 T6288 C911 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 784536 T6288 C911 oasu.DirectUpdateHandler2.commit No 
uncommitted changes. Skipping IW.commit.
   [junit4]   2> 784536 T6288 C911 oasc.SolrCore.openNewSearcher 
SolrIndexSearcher has not changed - not re-opening: 
org.apache.solr.search.SolrIndexSearcher
   [junit4]   2> 784537 T6288 C911 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 784537 T6288 C911 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={wt=xml&=} {commit=} 0 1
   [junit4]   2> 784537 T6288 C911 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {} 0 0
   [junit4]   2> 784538 T6288 C911 oassf.FileFloatSource.getFloats Loaded 
external value source external_foo_extf
   [junit4]   2> 784538 T6288 C911 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}foo_extf&rows=100&fl=*,score&wt=xml&indent=on} hits=25 
status=0 QTime=0 
   [junit4]   2> 784549 T6288 C911 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 784549 T6288 C911 oasu.DirectUpdateHandler2.commit No 
uncommitted changes. Skipping IW.commit.
   [junit4]   2> 784549 T6288 C911 oasc.SolrCore.openNewSearcher 
SolrIndexSearcher has not changed - not re-opening: 
org.apache.solr.search.SolrIndexSearcher
   [junit4]   2> 784550 T6288 C911 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 784550 T6288 C911 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={wt=xml&=} {commit=} 0 1
   [junit4]   2> 784550 T6288 C911 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {} 0 0
   [junit4]   2> 784551 T6288 C911 oassf.FileFloatSource.getFloats Loaded 
external value source external_foo_extf
   [junit4]   2> 784552 T6288 C911 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}foo_extf&rows=100&fl=*,score&wt=xml&indent=on} hits=25 
status=0 QTime=1 
   [junit4]   2> 784562 T6288 C911 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 784562 T6288 C911 oasu.DirectUpdateHandler2.commit No 
uncommitted changes. Skipping IW.commit.
   [junit4]   2> 784562 T6288 C911 oasc.SolrCore.openNewSearcher 
SolrIndexSearcher has not changed - not re-opening: 
org.apache.solr.search.SolrIndexSearcher
   [junit4]   2> 784562 T6288 C911 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 784563 T6288 C911 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={wt=xml&=} {commit=} 0 1
   [junit4]   2> 784563 T6288 C911 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {} 0 0
   [junit4]   2> 784564 T6288 C911 oassf.FileFloatSource.getFloats Loaded 
external value source external_foo_extf
   [junit4]   2> 784564 T6288 C911 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}foo_extf&rows=100&fl=*,score&wt=xml&indent=on} hits=25 
status=0 QTime=0 
   [junit4]   2> 784574 T6288 C911 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 784575 T6288 C911 oasu.DirectUpdateHandler2.commit No 
uncommitted changes. Skipping IW.commit.
   [junit4]   2> 784575 T6288 C911 oasc.SolrCore.openNewSearcher 
SolrIndexSearcher has not changed - not re-opening: 
org.apache.solr.search.SolrIndexSearcher
   [junit4]   2> 784575 T6288 C911 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 784575 T6288 C911 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={wt=xml&=} {commit=} 0 1
   [junit4]   2> 784576 T6288 C911 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {} 0 0
   [junit4]   2> 784577 T6288 C911 oassf.FileFloatSource.getFloats Loaded 
external value source external_foo_extf
   [junit4]   2> 784577 T6288 C911 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}foo_extf&rows=100&fl=*,score&wt=xml&indent=on} hits=25 
status=0 QTime=1 
   [junit4]   2> 784587 T6288 C911 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 784588 T6288 C911 oasu.DirectUpdateHandler2.commit No 
uncommitted changes. Skipping IW.commit.
   [junit4]   2> 784588 T6288 C911 oasc.SolrCore.openNewSearcher 
SolrIndexSearcher has not changed - not re-opening: 
org.apache.solr.search.SolrIndexSearcher
   [junit4]   2> 784588 T6288 C911 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 784588 T6288 C911 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={wt=xml&=} {commit=} 0 1
   [junit4]   2> 784588 T6288 C911 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {} 0 0
   [junit4]   2> 784590 T6288 C911 oassf.FileFloatSource.getFloats Loaded 
external value source external_foo_extf
   [junit4]   2> 784590 T6288 C911 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}foo_extf&rows=100&fl=*,score&wt=xml&indent=on} hits=25 
status=0 QTime=1 
   [junit4]   2> 784600 T6288 C911 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 784600 T6288 C911 oasu.DirectUpdateHandler2.commit No 
uncommitted changes. Skipping IW.commit.
   [junit4]   2> 784601 T6288 C911 oasc.SolrCore.openNewSearcher 
SolrIndexSearcher has not changed - not re-opening: 
org.apache.solr.search.SolrIndexSearcher
   [junit4]   2> 784601 T6288 C911 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 784601 T6288 C911 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={wt=xml&=} {commit=} 0 1
   [junit4]   2> 784601 T6288 C911 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {} 0 0
   [junit4]   2> 784602 T6288 C911 oassf.FileFloatSource.getFloats Loaded 
external value source external_foo_extf
   [junit4]   2> 784603 T6288 C911 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}foo_extf&rows=100&fl=*,score&wt=xml&indent=on} hits=25 
status=0 QTime=1 
   [junit4]   2> 784625 T6288 C911 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 784626 T6288 C911 oasu.DirectUpdateHandler2.commit No 
uncommitted changes. Skipping IW.commit.
   [junit4]   2> 784627 T6288 C911 oasc.SolrCore.openNewSearcher 
SolrIndexSearcher has not changed - not re-opening: 
org.apache.solr.search.SolrIndexSearcher
   [junit4]   2> 784627 T6288 C911 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 784627 T6288 C911 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={wt=xml&=} {commit=} 0 2
   [junit4]   2> 784628 T6288 C911 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {} 0 1
   [junit4]   2> 784629 T6288 C911 oassf.FileFloatSource.getFloats Loaded 
external value source external_foo_extf
   [junit4]   2> 784629 T6288 C911 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}foo_extf&rows=100&fl=*,score&wt=xml&indent=on} hits=25 
status=0 QTime=0 
   [junit4]   2> 784682 T6288 C911 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 784682 T6288 C911 oasu.DirectUpdateHandler2.commit No 
uncommitted changes. Skipping IW.commit.
   [junit4]   2> 784683 T6288 C911 oasc.SolrCore.openNewSearcher 
SolrIndexSearcher has not changed - not re-opening: 
org.apache.solr.search.SolrIndexSearcher
   [junit4]   2> 784683 T6288 C911 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 784683 T6288 C911 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={wt=xml&=} {commit=} 0 1
   [junit4]   2> 784683 T6288 C911 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {} 0 0
   [junit4]   2> 784684 T6288 C911 oassf.FileFloatSource.getFloats Loaded 
external value source external_foo_extf
   [junit4]   2> 784685 T6288 C911 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}foo_extf&rows=100&fl=*,score&wt=xml&indent=on} hits=25 
status=0 QTime=1 
   [junit4]   2> 784695 T6288 C911 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 784695 T6288 C911 oasu.DirectUpdateHandler2.commit No 
uncommitted changes. Skipping IW.commit.
   [junit4]   2> 784696 T6288 C911 oasc.SolrCore.openNewSearcher 
SolrIndexSearcher has not changed - not re-opening: 
org.apache.solr.search.SolrIndexSearcher
   [junit4]   2> 784696 T6288 C911 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 784696 T6288 C911 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={wt=xml&=} {commit=} 0 1
   [junit4]   2> 784696 T6288 C911 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {} 0 0
   [junit4]   2> 784697 T6288 C911 oassf.FileFloatSource.getFloats Loaded 
external value source external_foo_extf
   [junit4]   2> 784698 T6288 C911 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}foo_extf&rows=100&fl=*,score&wt=xml&indent=on} hits=25 
status=0 QTime=1 
   [junit4]   2> 784708 T6288 C911 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 784708 T6288 C911 oasu.DirectUpdateHandler2.commit No 
uncommitted changes. Skipping IW.commit.
   [junit4]   2> 784709 T6288 C911 oasc.SolrCore.openNewSearcher 
SolrIndexSearcher has not changed - not re-opening: 
org.apache.solr.search.SolrIndexSearcher
   [junit4]   2> 784709 T6288 C911 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 784709 T6288 C911 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={wt=xml&=} {commit=} 0 1
   [junit4]   2> 784709 T6288 C911 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {} 0 0
   [junit4]   2> 784711 T6288 C911 oassf.FileFloatSource.getFloats Loaded 
external value source external_foo_extf
   [junit4]   2> 784711 T6288 C911 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}foo_extf&rows=100&fl=*,score&wt=xml&indent=on} hits=25 
status=0 QTime=1 
   [junit4]   2> 784725 T6288 oas.SolrTestCaseJ4.tearDown ###Ending 
testExternalField
   [junit4]   2> 784728 T6288 oas.SolrTestCaseJ4.setUp ###Starting 
testFieldValueSourceParser
   [junit4]   2> ASYNC  NEW_CORE C912 name=collection1 
org.apache.solr.core.SolrCore@41ceb3
   [junit4]   2> 784728 T6288 C912 oasu.DirectUpdateHandler2.deleteAll 
[collection1] REMOVING ALL DOCUMENTS FROM INDEX
   [junit4]   2> 784729 T6288 C912 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 1
   [junit4]   2> 784730 T6288 C912 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[100.0]} 0 1
   [junit4]   2> 784730 T6288 C912 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[100.0]} 0 0
   [junit4]   2> 784731 T6288 C912 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 784732 T6288 C912 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@106c185 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@8b18d4),segFN=segments_a,generation=10}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@106c185 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@8b18d4),segFN=segments_b,generation=11}
   [junit4]   2> 784733 T6288 C912 oasc.SolrDeletionPolicy.updateCommits newest 
commit generation = 11
   [junit4]   2> 784733 T6288 C912 oass.SolrIndexSearcher.<init> Opening 
Searcher@1098318[collection1] main
   [junit4]   2> 784734 T6288 C912 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 784734 T6290 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@1098318[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_9(5.1.0):c2/1:delGen=1)))}
   [junit4]   2> 784734 T6288 C912 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 3
   [junit4]   2> 784735 T6288 C912 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[-4.0]} 0 0
   [junit4]   2> 784736 T6288 C912 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[0.0]} 0 0
   [junit4]   2> 784737 T6288 C912 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[10.0]} 0 1
   [junit4]   2> 784737 T6288 C912 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[25.0]} 0 0
   [junit4]   2> 784738 T6288 C912 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[5.0]} 0 0
   [junit4]   2> 784739 T6288 C912 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[77.0]} 0 0
   [junit4]   2> 784739 T6288 C912 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[77.0]} 0 0
   [junit4]   2> 784740 T6288 C912 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[1.0]} 0 0
   [junit4]   2> 784741 T6288 C912 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 784743 T6288 C912 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@106c185 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@8b18d4),segFN=segments_b,generation=11}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@106c185 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@8b18d4),segFN=segments_c,generation=12}
   [junit4]   2> 784743 T6288 C912 oasc.SolrDeletionPolicy.updateCommits newest 
commit generation = 12
   [junit4]   2> 784743 T6288 C912 oass.SolrIndexSearcher.<init> Opening 
Searcher@5210b[collection1] main
   [junit4]   2> 784744 T6288 C912 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 784744 T6290 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@5210b[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_9(5.1.0):c2/1:delGen=1)
 Uninverting(_a(5.1.0):c8/1:delGen=1)))}
   [junit4]   2> 784744 T6288 C912 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 3
   [junit4]   2> 784745 T6288 C912 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}field("CoMpleX+\"+fieldName+_f")&rows=100&fl=*,score&wt=xml&indent=on}
 hits=8 status=0 QTime=0 
   [junit4]   2> 784749 T6288 C912 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}sqrt(field("CoMpleX+\"+fieldName+_f"))&rows=100&fl=*,score&wt=xml&indent=on}
 hits=8 status=0 QTime=0 
   [junit4]   2> 784751 T6288 C912 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}log(field("CoMpleX+\"+fieldName+_f"))&rows=100&fl=*,score&wt=xml&indent=on}
 hits=8 status=0 QTime=0 
   [junit4]   2> 784752 T6288 oas.SolrTestCaseJ4.tearDown ###Ending 
testFieldValueSourceParser
   [junit4]   2> 784755 T6288 oas.SolrTestCaseJ4.setUp ###Starting 
testMissingFieldFunctionBehavior
   [junit4]   2> 784755 T6288 C912 oasu.DirectUpdateHandler2.deleteAll 
[collection1] REMOVING ALL DOCUMENTS FROM INDEX
   [junit4]   2> 784755 T6288 C912 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 0
   [junit4]   2> 784756 T6288 C912 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[1]} 0 0
   [junit4]   2> 784757 T6288 C912 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 784758 T6288 C912 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@106c185 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@8b18d4),segFN=segments_c,generation=12}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@106c185 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@8b18d4),segFN=segments_d,generation=13}
   [junit4]   2> 784758 T6288 C912 oasc.SolrDeletionPolicy.updateCommits newest 
commit generation = 13
   [junit4]   2> 784759 T6288 C912 oass.SolrIndexSearcher.<init> Opening 
Searcher@9d1868[collection1] main
   [junit4]   2> 784759 T6288 C912 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 784759 T6290 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@9d1868[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_b(5.1.0):c1)))}
   [junit4]   2> 784760 T6288 C912 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 3
   [junit4]   2> 784760 T6288 C912 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=id:1&fl=noval_if:if(no__vals____s,42,-99)&fl=noval_def:def(no__vals____s,-99)&fl=noval_not:not(no__vals____s)&fl=noval_exists:exists(no__vals____s)&wt=xml}
 hits=1 status=0 QTime=0 
   [junit4]   2> 784762 T6288 C912 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> 784765 T6288 C912 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=id:1&fl=noval_if:if(no__vals____dt,42,-99)&fl=noval_def:def(no__vals____dt,-99)&fl=noval_not:not(no__vals____dt)&fl=noval_exists:exists(no__vals____dt)&wt=xml}
 hits=1 status=0 QTime=0 
   [junit4]   2> 784767 T6288 C912 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> 784769 T6288 C912 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=id:1&fl=noval_if:if(no__vals____i,42,-99)&fl=noval_def:def(no__vals____i,-99)&fl=noval_not:not(no__vals____i)&fl=noval_exists:exists(no__vals____i)&wt=xml}
 hits=1 status=0 QTime=0 
   [junit4]   2> 784771 T6288 C912 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=id:1&fl=noval_if:if(no__vals____l,42,-99)&fl=noval_def:def(no__vals____l,-99)&fl=noval_not:not(no__vals____l)&fl=noval_exists:exists(no__vals____l)&wt=xml}
 hits=1 status=0 QTime=1 
   [junit4]   2> 784773 T6288 C912 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> 784774 T6288 C912 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> 784777 T6288 C912 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> 784779 T6288 C912 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=id:1&fl=noval_if:if(no__vals____tl,42,-99)&fl=noval_def:def(no__vals____tl,-99)&fl=noval_not:not(no__vals____tl)&fl=noval_exists:exists(no__vals____tl)&wt=xml}
 hits=1 status=0 QTime=0 
   [junit4]   2> 784781 T6288 C912 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> 784783 T6288 C912 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=id:1&fl=noval_if:if(no__vals____td,42,-99)&fl=noval_def:def(no__vals____td,-99)&fl=noval_not:not(no__vals____td)&fl=noval_exists:exists(no__vals____td)&wt=xml}
 hits=1 status=0 QTime=1 
   [junit4]   2> 784785 T6288 oas.SolrTestCaseJ4.tearDown ###Ending 
testMissingFieldFunctionBehavior
   [junit4]   2> 784787 T6288 oas.SolrTestCaseJ4.setUp ###Starting testGeneral
   [junit4]   2> 784788 T6288 C912 oasu.DirectUpdateHandler2.deleteAll 
[collection1] REMOVING ALL DOCUMENTS FROM INDEX
   [junit4]   2> 784788 T6288 C912 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 1
   [junit4]   2> 784789 T6288 C912 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[1]} 0 0
   [junit4]   2> 784790 T6288 C912 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[2]} 0 0
   [junit4]   2> 784790 T6288 C912 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 784792 T6288 C912 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@106c185 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@8b18d4),segFN=segments_d,generation=13}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@106c185 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@8b18d4),segFN=segments_e,generation=14}
   [junit4]   2> 784792 T6288 C912 oasc.SolrDeletionPolicy.updateCommits newest 
commit generation = 14
   [junit4]   2> 784793 T6288 C912 oass.SolrIndexSearcher.<init> Opening 
Searcher@38c1ef[collection1] main
   [junit4]   2> 784793 T6288 C912 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 784793 T6290 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@38c1ef[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_c(5.1.0):c2)))}
   [junit4]   2> 784794 T6288 C912 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 4
   [junit4]   2> 784794 T6288 C912 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[3]} 0 0
   [junit4]   2> 784795 T6288 C912 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[4]} 0 0
   [junit4]   2> 784796 T6288 C912 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 784797 T6288 C912 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@106c185 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@8b18d4),segFN=segments_e,generation=14}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@106c185 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@8b18d4),segFN=segments_f,generation=15}
   [junit4]   2> 784797 T6288 C912 oasc.SolrDeletionPolicy.updateCommits newest 
commit generation = 15
   [junit4]   2> 784798 T6288 C912 oass.SolrIndexSearcher.<init> Opening 
Searcher@b355cf[collection1] main
   [junit4]   2> 784798 T6288 C912 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 784798 T6290 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@b355cf[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_c(5.1.0):c2)
 Uninverting(_d(5.1.0):c2)))}
   [junit4]   2> 784799 T6288 C912 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 3
   [junit4]   2> 784799 T6288 C912 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[5]} 0 0
   [junit4]   2> 784800 T6288 C912 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[6]} 0 0
   [junit4]   2> 784801 T6288 C912 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 784802 T6288 C912 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@106c185 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@8b18d4),segFN=segments_f,generation=15}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@106c185 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@8b18d4),segFN=segments_g,generation=16}
   [junit4]   2> 784802 T6288 C912 oasc.SolrDeletionPolicy.updateCommits newest 
commit generation = 16
   [junit4]   2> 784803 T6288 C912 oass.SolrIndexSearcher.<init> Opening 
Searcher@5a8b7e[collection1] main
   [junit4]   2> 784803 T6288 C912 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 784803 T6290 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@5a8b7e[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_c(5.1.0):c2)
 Uninverting(_d(5.1.0):c2) Uninverting(_e(5.1.0):c2)))}
   [junit4]   2> 784804 T6288 C912 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 3
   [junit4]   2> 784806 T6288 C912 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q={!func}numdocs()&fq=id:6&fl=*,score&wt=xml} 
hits=1 status=0 QTime=1 
   [junit4]   2> 784807 T6288 C912 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q={!func}maxdoc()&fq=id:6&fl=*,score&wt=xml} 
hits=1 status=0 QTime=0 
   [junit4]   2> 784809 T6288 C912 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}docfreq(a_t,cow)&fq=id:6&fl=*,score&wt=xml} hits=1 status=0 
QTime=1 
   [junit4]   2> 784809 T6288 C912 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}docfreq('a_t','cow')&fq=id:6&fl=*,score&wt=xml} hits=1 
status=0 QTime=0 
   [junit4]   2> 784810 T6288 C912 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={field=a_t&q={!func}docfreq($field,$value)&value=cow&fq=id:6&fl=*,score&wt=xml}
 hits=1 status=0 QTime=0 
   [junit4]   2> 784813 T6288 C912 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}termfreq(a_t,cow)&fq=id:6&fl=*,score&wt=xml} hits=1 status=0 
QTime=2 
   [junit4]   2> 784814 T6288 C912 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}termfreq(nofield_t,cow)&fq=id:6&fl=*,score&wt=xml} hits=1 
status=0 QTime=0 
   [junit4]   2> 784815 T6288 C912 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}docfreq(nofield_t,cow)&fq=id:6&fl=*,score&wt=xml} hits=1 
status=0 QTime=0 
   [junit4]   2> 784817 T6288 C912 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}idf(nofield_t,cow)&fq=id:6&fl=*,score&wt=xml} hits=1 status=0 
QTime=2 
   [junit4]   2> 784819 T6288 C912 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}tf(nofield_t,cow)&fq=id:6&fl=*,score&wt=xml} hits=1 status=0 
QTime=2 
   [junit4]   2> 784820 T6288 C912 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q={!func}idf(a_t,cow)&fq=id:6&fl=*,score&wt=xml} 
hits=1 status=0 QTime=0 
   [junit4]   2> 784821 T6288 C912 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q={!func}tf(a_t,cow)&fq=id:6&fl=*,score&wt=xml} 
hits=1 status=0 QTime=0 
   [junit4]   2> 784823 T6288 C912 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q={!func}norm(a_t)&fq=id:2&fl=*,score&wt=xml} 
hits=1 status=0 QTime=1 
   [junit4]   2> 784829 T6288 C912 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q={!func}ord(id)&fq=id:6&fl=*,score&wt=xml} 
hits=1 status=0 QTime=5 
   [junit4]   2> 784830 T6288 C912 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q={!func}top(ord(id))&fq=id:6&fl=*,score&wt=xml} 
hits=1 status=0 QTime=0 
   [junit4]   2> 784832 T6288 C912 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q={!func}rord(id)&fq=id:1&fl=*,score&wt=xml} 
hits=1 status=0 QTime=1 
   [junit4]   2> 784833 T6288 C912 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q={!func}top(rord(id))&fq=id:1&fl=*,score&wt=xml} 
hits=1 status=0 QTime=0 
   [junit4]   2> 784834 T6288 C912 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}ms(a_tdt,b_tdt)&fq=id:1&fl=*,score&wt=xml} hits=1 status=0 
QTime=1 
   [junit4]   2> 784835 T6288 C912 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}ms(b_tdt,a_tdt)&fq=id:1&fl=*,score&wt=xml} hits=1 status=0 
QTime=0 
   [junit4]   2> 784836 T6288 C912 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}ms(2009-08-31T12:10:10.125Z,2009-08-31T12:10:10.124Z)&fq=id:1&fl=*,score&wt=xml}
 hits=1 status=0 QTime=1 
   [junit4]   2> 784836 T6288 C912 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}ms(2009-08-31T12:10:10.124Z,a_tdt)&fq=id:1&fl=*,score&wt=xml} 
hits=1 status=0 QTime=0 
   [junit4]   2> 784837 T6288 C912 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}ms(2009-08-31T12:10:10.125Z,b_tdt)&fq=id:1&fl=*,score&wt=xml} 
hits=1 status=0 QTime=0 
   [junit4]   2> 784838 T6288 C912 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}ms(2009-08-31T12:10:10.125Z/SECOND,2009-08-31T12:10:10.124Z/SECOND)&fq=id:1&fl=*,score&wt=xml}
 hits=1 status=0 QTime=0 
   [junit4]   2> 784839 T6288 C912 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q={!func}ms(NOW)&fl=*,score&NOW=1000&wt=xml} 
hits=6 status=0 QTime=0 
   [junit4]   2> 784840 T6288 C912 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[100]} 0 0
   [junit4]   2> 784841 T6288 C912 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[101]} 0 0
   [junit4]   2> 784842 T6288 C912 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[102]} 0 0
   [junit4]   2> 784842 T6288 C912 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[103]} 0 0
   [junit4]   2> 784843 T6288 C912 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[104]} 0 0
   [junit4]   2> 784844 T6288 C912 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[105]} 0 0
   [junit4]   2> 784845 T6288 C912 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[106]} 0 1
   [junit4]   2> 784845 T6288 C912 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[107]} 0 0
   [junit4]   2> 784846 T6288 C912 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[108]} 0 0
   [junit4]   2> 784847 T6288 C912 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[109]} 0 0
   [junit4]   2> 784847 T6288 C912 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[110]} 0 0
   [junit4]   2> 784848 T6288 C912 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[111]} 0 0
   [junit4]   2> 784849 T6288 C912 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 784851 T6288 C912 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@106c185 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@8b18d4),segFN=segments_g,generation=16}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@106c185 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@8b18d4),segFN=segments_h,generation=17}
   [junit4]   2> 784851 T6288 C912 oasc.SolrDeletionPolicy.updateCommits newest 
commit generation = 17
   [junit4]   2> 784851 T6288 C912 oass.SolrIndexSearcher.<init> Opening 
Searcher@1e8135a[collection1] main
   [junit4]   2> 784852 T6288 C912 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 784852 T6290 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@1e8135a[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_c(5.1.0):c2)
 Uninverting(_d(5.1.0):c2) Uninverting(_e(5.1.0):c2) 
Uninverting(_f(5.1.0):c12)))}
   [junit4]   2> 784852 T6288 C912 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 4
   [junit4]   2> 784853 T6288 C912 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[120]} 0 0
   [junit4]   2> 784854 T6288 C912 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[121]} 0 0
   [junit4]   2> 784854 T6288 C912 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 784856 T6288 C912 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@106c185 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@8b18d4),segFN=segments_h,generation=17}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@106c185 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@8b18d4),segFN=segments_i,generation=18}
   [junit4]   2> 784856 T6288 C912 oasc.SolrDeletionPolicy.updateCommits newest 
commit generation = 18
   [junit4]   2> 784857 T6288 C912 oass.SolrIndexSearcher.<init> Opening 
Searcher@162feea[collection1] main
   [junit4]   2> 784857 T6288 C912 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 784857 T6290 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@162feea[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_c(5.1.0):c2)
 Uninverting(_d(5.1.0):c2) Uninverting(_e(5.1.0):c2) Uninverting(_f(5.1.0):c12) 
Uninverting(_g(5.1.0):c2)))}
   [junit4]   2> 784858 T6288 C912 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 4
   [junit4]   2> 784859 T6288 C912 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}query($qq)&fq=id:120&fl=*,score&wt=xml&qq=text:batman} hits=1 
status=0 QTime=1 
   [junit4]   2> 784860 T6288 C912 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}query($qq)&fq=id:120&fl=*,score&wt=xml&qq=text:superman} 
hits=1 status=0 QTime=0 
   [junit4]   2> 784861 T6288 C912 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!frange+l%3D1+u%3D10}query($qq)&fq=id:120&fl=*,score&wt=xml&qq=text:superman}
 hits=1 status=0 QTime=0 
   [junit4]   2> 784863 T6288 C912 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}sub(div(sum(0.0,product(1,query($qq))),1),0)&fq=id:120&fl=*,score&wt=xml&qq=text:batman}
 hits=1 status=0 QTime=1 
   [junit4]   2> 784864 T6288 C912 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}sub(div(sum(0.0,product(1,query($qq))),1),0)&fq=id:120&fl=*,score&wt=xml&qq=text:superman}
 hits=1 status=0 QTime=1 
   [junit4]   2> 784865 T6288 C912 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}add($v1,$v2)&v3=2&fq=id:1&fl=*,score&v2=1&wt=xml&v4=5&v1=add($v3,$v4)}
 hits=1 status=0 QTime=1 
   [junit4]   2> 784868 T6288 C912 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}dist(2,vector(1,1),$pt)&fq=id:1&fl=*,score&wt=xml&pt=3,1} 
hits=1 status=0 QTime=3 
   [junit4]   2> 784870 T6288 C912 oasc.SolrException.log Ignoring exception 
matching ignore_exception
   [junit4]   2> 784870 T6288 C912 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}10+wow+dude+ignore_exception&fl=*,score&wt=xml} status=400 
QTime=1 
   [junit4]   2> 784870 T6288 oasc.SolrException.log Ignoring exception 
matching ignore_exception
   [junit4]   2> 784871 T6288 C912 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=*:*&fq=id:120+OR+id:121&wt=xml&qq=text:(batman+OR+superman)&sortfunc=query($qq)&sort={!func+v%3D$sortfunc}+desc}
 hits=2 status=0 QTime=1 
   [junit4]   2> 784872 T6288 oas.SolrTestCaseJ4.tearDown ###Ending testGeneral
   [junit4]   2> 784883 T6288 oas.SolrTestCaseJ4.setUp ###Starting 
testTotalTermFreq
   [junit4]   2> 784883 T6288 C912 oasu.DirectUpdateHandler2.deleteAll 
[collection1] REMOVING ALL DOCUMENTS FROM INDEX
   [junit4]   2> 784884 T6288 C912 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 1
   [junit4]   2> 784885 T6288 C912 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[1]} 0 1
   [junit4]   2> 784885 T6288 C912 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[2]} 0 0
   [junit4]   2> 784886 T6288 C912 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 784887 T6288 C912 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@106c185 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@8b18d4),segFN=segments_i,generation=18}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@106c185 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@8b18d4),segFN=segments_j,generation=19}
   [junit4]   2> 784888 T6288 C912 oasc.SolrDeletionPolicy.updateCommits newest 
commit generation = 19
   [junit4]   2> 784888 T6288 C912 oass.SolrIndexSearcher.<init> Opening 
Searcher@379e63[collection1] main
   [junit4]   2> 784889 T6288 C912 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 784889 T6290 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@379e63[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_h(5.1.0):c2)))}
   [junit4]   2> 784889 T6288 C912 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 3
   [junit4]   2> 784890 T6288 C912 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[3]} 0 0
   [junit4]   2> 784891 T6288 C912 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[4]} 0 0
   [junit4]   2> 784892 T6288 C912 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 784893 T6288 C912 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@106c185 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@8b18d4),segFN=segments_j,generation=19}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@106c185 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@8b18d4),segFN=segments_k,generation=20}
   [junit4]   2> 784893 T6288 C912 oasc.SolrDeletionPolicy.updateCommits newest 
commit generation = 20
   [junit4]   2> 784894 T6288 C912 oass.SolrIndexSearcher.<init> Opening 
Searcher@4e00a1[collection1] main
   [junit4]   2> 784894 T6288 C912 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 784894 T6290 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@4e00a1[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_h(5.1.0):c2)
 Uninverting(_i(5.1.0):c2)))}
   [junit4]   2> 784894 T6288 C912 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 2
   [junit4]   2> 784895 T6288 C912 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[5]} 0 0
   [junit4]   2> 784896 T6288 C912 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[6]} 0 0
   [junit4]   2> 784897 T6288 C912 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 784899 T6288 C912 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@106c185 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@8b18d4),segFN=segments_k,generation=20}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@106c185 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@8b18d4),segFN=segments_l,generation=21}
   [junit4]   2> 784899 T6288 C912 oasc.SolrDeletionPolicy.updateCommits newest 
commit generation = 21
   [junit4]   2> 784900 T6288 C912 oass.SolrIndexSearcher.<init> Opening 
Searcher@f8bfae[collection1] main
   [junit4]   2> 784900 T6288 C912 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 784900 T6290 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@f8bfae[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_h(5.1.0):c2)
 Uninverting(_i(5.1.0):c2) Uninverting(_j(5.1.0):c2)))}
   [junit4]   2> 784901 T6288 C912 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 4
   [junit4]   2> 784903 T6288 C912 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}totaltermfreq('a_t','cow')&fq=id:6&fl=*,score&wt=xml} hits=1 
status=0 QTime=1 
   [junit4]   2> 784904 T6288 C912 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}ttf(a_t,'cow')&fq=id:6&fl=*,score&wt=xml} hits=1 status=0 
QTime=0 
   [junit4]   2> 784906 T6288 C912 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}sumtotaltermfreq('a_t')&fq=id:6&fl=*,score&wt=xml} hits=1 
status=0 QTime=1 
   [junit4]   2> 784907 T6288 C912 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q={!func}sttf(a_t)&fq=id:6&fl=*,score&wt=xml} 
hits=1 status=0 QTime=0 
   [junit4]   2> 784908 T6288 oas.SolrTestCaseJ4.tearDown ###Ending 
testTotalTermFreq
   [junit4]   2> 784911 T6288 oas.SolrTestCaseJ4.setUp ###Starting testFunctions
   [junit4]   2> 784911 T6288 C912 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[100.0]} 0 0
   [junit4]   2> 784912 T6288 C912 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[-4.0]} 0 0
   [junit4]   2> 784913 T6288 C912 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[0.0]} 0 0
   [junit4]   2> 784914 T6288 C912 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[10.0]} 0 0
   [junit4]   2> 784915 T6288 C912 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[25.0]} 0 0
   [junit4]   2> 784915 T6288 C912 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[5.0]} 0 0
   [junit4]   2> 784916 T6288 C912 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 784918 T6288 C912 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@106c185 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@8b18d4),segFN=segments_l,generation=21}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@106c185 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@8b18d4),segFN=segments_m,generation=22}
   [junit4]   2> 784918 T6288 C912 oasc.SolrDeletionPolicy.updateCommits newest 
commit generation = 22
   [junit4]   2> 784919 T6288 C912 oass.SolrIndexSearcher.<init> Opening 
Searcher@770c3c[collection1] main
   [junit4]   2> 784919 T6288 C912 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 784919 T6290 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@770c3c[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_h(5.1.0):c2)
 Uninverting(_i(5.1.0):c2) Uninverting(_j(5.1.0):c2/1:delGen=1) 
Uninverting(_k(5.1.0):c6)))}
   [junit4]   2> 784920 T6288 C912 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 4
   [junit4]   2> 784920 T6288 C912 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[88.0]} 0 0
   [junit4]   2> 784921 T6288 C912 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 784923 T6288 C912 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@106c185 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@8b18d4),segFN=segments_m,generation=22}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@106c185 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@8b18d4),segFN=segments_n,generation=23}
   [junit4]   2> 784923 T6288 C912 oasc.SolrDeletionPolicy.updateCommits newest 
commit generation = 23
   [junit4]   2> 784923 T6288 C912 oass.SolrIndexSearcher.<init> Opening 
Searcher@156fb43[collection1] main
   [junit4]   2> 784924 T6288 C912 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 784924 T6290 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@156fb43[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_h(5.1.0):c2)
 Uninverting(_i(5.1.0):c2) Uninverting(_j(5.1.0):c2/1:delGen=1) 
Uninverting(_k(5.1.0):c6) Uninverting(_l(5.1.0):c1)))}
   [junit4]   2> 784924 T6288 C912 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 3
   [junit4]   2> 784925 T6288 C912 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}foo_f&rows=100&fl=*,score&wt=xml&indent=on} hits=12 status=0 
QTime=0 
   [junit4]   2> 784926 T6288 C912 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}1.414213&rows=100&fl=*,score&wt=xml&indent=on} hits=12 
status=0 QTime=0 
   [junit4]   2> 784927 T6288 C912 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}-1.414213&rows=100&fl=*,score&wt=xml&indent=on} hits=12 
status=0 QTime=0 
   [junit4]   2> 784928 T6288 C912 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}sum(foo_f,1)&rows=100&fl=*,score&wt=xml&indent=on} hits=12 
status=0 QTime=0 
   [junit4]   2> 784929 T6288 C912 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q={!func}sum(foo_f

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

fType=func&fq=id:1&fl=*,score&wt=xml} hits=1 status=0 QTime=0 
   [junit4]   2> 785179 T6288 C913 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=asin(.5)&defType=func&fq=id:1&fl=*,score&wt=xml} hits=1 status=0 
QTime=0 
   [junit4]   2> 785180 T6288 C913 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=acos(.5)&defType=func&fq=id:1&fl=*,score&wt=xml} hits=1 status=0 
QTime=0 
   [junit4]   2> 785181 T6288 C913 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=atan(.5)&defType=func&fq=id:1&fl=*,score&wt=xml} hits=1 status=0 
QTime=1 
   [junit4]   2> 785182 T6288 C913 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=sinh(.5)&defType=func&fq=id:1&fl=*,score&wt=xml} hits=1 status=0 
QTime=1 
   [junit4]   2> 785183 T6288 C913 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=cosh(.5)&defType=func&fq=id:1&fl=*,score&wt=xml} hits=1 status=0 
QTime=1 
   [junit4]   2> 785184 T6288 C913 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=tanh(.5)&defType=func&fq=id:1&fl=*,score&wt=xml} hits=1 status=0 
QTime=1 
   [junit4]   2> 785184 T6288 C913 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=ceil(2.3)&defType=func&fq=id:1&fl=*,score&wt=xml} hits=1 status=0 
QTime=0 
   [junit4]   2> 785185 T6288 C913 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=floor(2.3)&defType=func&fq=id:1&fl=*,score&wt=xml} hits=1 status=0 
QTime=0 
   [junit4]   2> 785186 T6288 C913 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=rint(2.3)&defType=func&fq=id:1&fl=*,score&wt=xml} hits=1 status=0 
QTime=0 
   [junit4]   2> 785187 T6288 C913 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=pow(2,0.5)&defType=func&fq=id:1&fl=*,score&wt=xml} hits=1 status=0 
QTime=0 
   [junit4]   2> 785188 T6288 C913 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=hypot(3,4)&defType=func&fq=id:1&fl=*,score&wt=xml} hits=1 status=0 
QTime=0 
   [junit4]   2> 785189 T6288 C913 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=atan2(.25,.5)&defType=func&fq=id:1&fl=*,score&wt=xml} hits=1 status=0 
QTime=0 
   [junit4]   2> 785190 T6288 oas.SolrTestCaseJ4.tearDown ###Ending testFuncs
   [junit4]   2> 785190 T6288 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> 785190 T6288 oasc.CoreContainer.shutdown Shutting down 
CoreContainer instance=24227803
   [junit4]   2> 785191 T6288 oasc.SolrCore.close [collection1]  CLOSING 
SolrCore org.apache.solr.core.SolrCore@41ceb3
   [junit4]   2> 785191 T6288 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=117,cumulative_deletesById=0,cumulative_deletesByQuery=5,cumulative_errors=0}
   [junit4]   2> 785191 T6288 oasu.SolrCoreState.decrefSolrCoreState Closing 
SolrCoreState
   [junit4]   2> 785191 T6288 oasu.DefaultSolrCoreState.closeIndexWriter 
SolrCoreState ref count has reached 0 - closing IndexWriter
   [junit4]   2> 785191 T6288 oasu.DefaultSolrCoreState.closeIndexWriter 
closing IndexWriter with IndexWriterCloser
   [junit4]   2> 785192 T6288 oasc.SolrCore.closeSearcher [collection1] Closing 
main searcher on request.
   [junit4]   2> 785192 T6288 oasc.CachingDirectoryFactory.close Closing 
MockDirectoryFactory - 2 directories currently being tracked
   [junit4]   2> 785192 T6288 oasc.CachingDirectoryFactory.closeCacheValue 
looking to close 
/home/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.search.function.TestFunctionQuery
 EE346A9408D44397-001/init-core-data-001 
[CachedDir<<refCount=0;path=/home/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.search.function.TestFunctionQuery
 EE346A9408D44397-001/init-core-data-001;done=false>>]
   [junit4]   2> 785192 T6288 oasc.CachingDirectoryFactory.close Closing 
directory: 
/home/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.search.function.TestFunctionQuery
 EE346A9408D44397-001/init-core-data-001
   [junit4]   2> 785193 T6288 oasc.CachingDirectoryFactory.closeCacheValue 
looking to close 
/home/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.search.function.TestFunctionQuery
 EE346A9408D44397-001/init-core-data-001/index 
[CachedDir<<refCount=0;path=/home/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.search.function.TestFunctionQuery
 EE346A9408D44397-001/init-core-data-001/index;done=false>>]
   [junit4]   2> 785193 T6288 oasc.CachingDirectoryFactory.close Closing 
directory: 
/home/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.search.function.TestFunctionQuery
 EE346A9408D44397-001/init-core-data-001/index
   [junit4]   2> NOTE: leaving temporary files on disk at: 
/home/jenkins/workspace/Lucene-Solr-5.x-Linux/solr/build/solr-core/test/J1/temp/solr.search.function.TestFunctionQuery
 EE346A9408D44397-001
   [junit4]   2> NOTE: test params are: codec=Asserting(Lucene50): 
{text=PostingsFormat(name=MockRandom), foo_s=PostingsFormat(name=Memory 
doPackFST= false), b_tdt=PostingsFormat(name=Memory doPackFST= true), 
const_s=PostingsFormat(name=Memory doPackFST= true), 
eff_ti=PostingsFormat(name=MockRandom), foo_ti=PostingsFormat(name=Memory 
doPackFST= false), x_s=BlockTreeOrds(blocksize=128), 
foo_tf=PostingsFormat(name=MockRandom), CoMpleX " fieldName 
_f=BlockTreeOrds(blocksize=128), 1-1_s=PostingsFormat(name=MockRandom), 
foo_tl=PostingsFormat(name=Memory doPackFST= true), 
id=PostingsFormat(name=Memory doPackFST= true), x_i=PostingsFormat(name=Memory 
doPackFST= false), foo_f=PostingsFormat(name=MockRandom), 
foo_d=PostingsFormat(name=Memory doPackFST= true), 
a_tdt=PostingsFormat(name=Memory doPackFST= false), 
y_td=PostingsFormat(name=Memory doPackFST= false), 
sfile_s=PostingsFormat(name=Memory doPackFST= true), 
1_s=PostingsFormat(name=MockRandom), x_td=PostingsFormat(name=Memory doPackFST= 
true), a_t=PostingsFormat(name=Memory doPackFST= false), 
x:x_i=BlockTreeOrds(blocksize=128), yak_i=PostingsFormat(name=MockRandom)}, 
docValues:{}, sim=RandomSimilarityProvider(queryNorm=true,coord=crazy): {}, 
locale=lt_LT, timezone=Australia/Adelaide
   [junit4]   2> NOTE: Linux 3.13.0-46-generic i386/Oracle Corporation 1.7.0_76 
(32-bit)/cpus=12,threads=1,free=159466096,total=288620544
   [junit4]   2> NOTE: All tests run in this JVM: [TestCharFilters, 
OpenCloseCoreStressTest, TestLeaderElectionZkExpiry, ChaosMonkeySafeLeaderTest, 
TestLFUCache, ExternalCollectionsTest, DistributedQueueTest, 
HdfsBasicDistributedZkTest, FieldMutatingUpdateProcessorTest, 
WordBreakSolrSpellCheckerTest, TestFuzzyAnalyzedSuggestions, DeleteShardTest, 
CacheHeaderTest, TestCollectionAPI, TestFieldResource, ZkCLITest, 
AnalysisErrorHandlingTest, DistanceUnitsTest, TestLRUCache, TestFastWriter, 
QueryResultKeyTest, SpellCheckComponentTest, CursorMarkTest, 
ShardRoutingCustomTest, DistributedTermsComponentTest, TestSolrCoreProperties, 
TestManagedResource, DistributedExpandComponentTest, DirectSolrConnectionTest, 
TestCoreContainer, TestMaxScoreQueryParser, TestDistributedMissingSort, 
LeaderInitiatedRecoveryOnCommitTest, ZkControllerTest, TestPivotHelperCode, 
DistributedIntervalFacetingTest, ZkSolrClientTest, 
DocumentAnalysisRequestHandlerTest, ConvertedLegacyTest, SliceStateTest, 
TestClusterStateMutator, StatelessScriptUpdateProcessorFactoryTest, 
IndexSchemaRuntimeFieldTest, HdfsSyncSliceTest, SpellPossibilityIteratorTest, 
TestFastLRUCache, JSONWriterTest, TestSchemaResource, EnumFieldTest, 
TestComponentsName, TestSimpleQParserPlugin, PreAnalyzedFieldTest, 
ScriptEngineTest, TestStressVersions, TestReplicaProperties, 
TestUniqueKeyFieldResource, ClusterStateUpdateTest, TestSolrDeletionPolicy2, 
TestHdfsUpdateLog, TestExpandComponent, MergeStrategyTest, CopyFieldTest, 
SuggesterTSTTest, SolrCmdDistributorTest, TestRebalanceLeaders, 
FacetPivotSmallTest, MigrateRouteKeyTest, TestInitParams, ReturnFieldsTest, 
TestExceedMaxTermLength, CurrencyFieldOpenExchangeTest, 
DistributedQueryComponentOptimizationTest, JsonLoaderTest, 
TestAtomicUpdateErrorCases, TestOmitPositions, TestManagedStopFilterFactory, 
TestNonDefinedSimilarityFactory, CollectionsAPIDistributedZkTest, OverseerTest, 
ShardRoutingTest, TestRandomDVFaceting, AutoCommitTest, 
TestDistributedGrouping, DistributedSpellCheckComponentTest, TestRealTimeGet, 
SolrCoreTest, QueryElevationComponentTest, TestSort, TestFunctionQuery]
   [junit4] Completed on J1 in 1.08s, 15 tests, 1 error <<< FAILURES!

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

Total time: 47 minutes 36 seconds
Build step 'Invoke Ant' marked build as failure
[description-setter] Description set: Java: 32bit/jdk1.7.0_76 -client 
-XX:+UseParallelGC
Archiving artifacts
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any


---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]

Reply via email to