Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/12031/
Java: 32bit/jdk1.9.0-ea-b54 -server -XX:+UseG1GC

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

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

Stack Trace:
java.lang.RuntimeException: unexpected map keys [e] @ response/docs/[0]
        at 
__randomizedtesting.SeedInfo.seed([881611D4DD76A4CE:D62CF3A9E1E05882]:0)
        at org.apache.solr.SolrTestCaseJ4.assertJQ(SolrTestCaseJ4.java:882)
        at org.apache.solr.SolrTestCaseJ4.assertJQ(SolrTestCaseJ4.java:829)
        at 
org.apache.solr.search.function.TestFunctionQuery.testPseudoFieldFunctions(TestFunctionQuery.java:739)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at 
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at 
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:502)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1627)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:836)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:872)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:886)
        at 
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
        at 
org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
        at 
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
        at 
org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
        at 
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
        at 
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
        at 
com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798)
        at 
com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:845)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:747)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:781)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:792)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
        at 
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
        at 
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
        at 
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:54)
        at 
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
        at 
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
        at 
org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
        at java.lang.Thread.run(Thread.java:745)




Build Log:
[...truncated 9798 lines...]
   [junit4] Suite: org.apache.solr.search.function.TestFunctionQuery
   [junit4]   2> Creating dataDir: 
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.search.function.TestFunctionQuery
 881611D4DD76A4CE-001/init-core-data-001
   [junit4]   2> 621158 T6262 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl 
(false) and clientAuth (false)
   [junit4]   2> 621159 T6262 oas.SolrTestCaseJ4.initCore ####initCore
   [junit4]   2> 621159 T6262 oasc.SolrResourceLoader.<init> new 
SolrResourceLoader for directory: 
'/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/'
   [junit4]   2> 621159 T6262 oasc.SolrResourceLoader.replaceClassLoader Adding 
'file:/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/lib/classes/'
 to classloader
   [junit4]   2> 621160 T6262 oasc.SolrResourceLoader.replaceClassLoader Adding 
'file:/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/lib/README'
 to classloader
   [junit4]   2> 621178 T6262 oasc.SolrConfig.refreshRequestParams current 
version of requestparams : -1
   [junit4]   2> 621181 T6262 oasc.SolrConfig.<init> Using Lucene MatchVersion: 
6.0.0
   [junit4]   2> 621185 T6262 oasc.SolrConfig.<init> Loaded SolrConfig: 
solrconfig-functionquery.xml
   [junit4]   2> 621186 T6262 oass.IndexSchema.readSchema Reading Solr Schema 
from 
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/schema11.xml
   [junit4]   2> 621189 T6262 oass.IndexSchema.readSchema [null] Schema 
name=example
   [junit4]   2> 621216 T6262 oass.IndexSchema.readSchema default search field 
in schema is text
   [junit4]   2> 621217 T6262 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 621220 T6262 oasc.SolrResourceLoader.locateSolrHome JNDI not 
configured for solr (NoInitialContextEx)
   [junit4]   2> 621220 T6262 oasc.SolrResourceLoader.locateSolrHome using 
system property solr.solr.home: 
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr
   [junit4]   2> 621220 T6262 oasc.SolrResourceLoader.<init> new 
SolrResourceLoader for directory: 
'/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/'
   [junit4]   2> 621230 T6262 oasc.CoreContainer.<init> New CoreContainer 
20600411
   [junit4]   2> 621231 T6262 oasc.CoreContainer.load Loading cores into 
CoreContainer 
[instanceDir=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/]
   [junit4]   2> 621231 T6262 oasc.CoreContainer.load loading shared library: 
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/lib
   [junit4]   2> 621232 T6262 oasc.SolrResourceLoader.addToClassLoader WARN 
Can't find (or read) directory to add to classloader: lib (resolved as: 
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/lib).
   [junit4]   2> 621237 T6262 oashc.HttpShardHandlerFactory.getParameter 
Setting socketTimeout to: 600000
   [junit4]   2> 621238 T6262 oashc.HttpShardHandlerFactory.getParameter 
Setting urlScheme to: null
   [junit4]   2> 621238 T6262 oashc.HttpShardHandlerFactory.getParameter 
Setting connTimeout to: 60000
   [junit4]   2> 621238 T6262 oashc.HttpShardHandlerFactory.getParameter 
Setting maxConnectionsPerHost to: 20
   [junit4]   2> 621238 T6262 oashc.HttpShardHandlerFactory.getParameter 
Setting maxConnections to: 10000
   [junit4]   2> 621238 T6262 oashc.HttpShardHandlerFactory.getParameter 
Setting corePoolSize to: 0
   [junit4]   2> 621239 T6262 oashc.HttpShardHandlerFactory.getParameter 
Setting maximumPoolSize to: 2147483647
   [junit4]   2> 621239 T6262 oashc.HttpShardHandlerFactory.getParameter 
Setting maxThreadIdleTime to: 5
   [junit4]   2> 621239 T6262 oashc.HttpShardHandlerFactory.getParameter 
Setting sizeOfQueue to: -1
   [junit4]   2> 621240 T6262 oashc.HttpShardHandlerFactory.getParameter 
Setting fairnessPolicy to: false
   [junit4]   2> 621240 T6262 oashc.HttpShardHandlerFactory.getParameter 
Setting useRetries to: false
   [junit4]   2> 621240 T6262 oasu.UpdateShardHandler.<init> Creating 
UpdateShardHandler HTTP client with params: 
socketTimeout=30000&connTimeout=30000&retry=true
   [junit4]   2> 621241 T6262 oasl.LogWatcher.createWatcher SLF4J impl is 
org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 621241 T6262 oasl.LogWatcher.newRegisteredLogWatcher 
Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 621241 T6262 oasc.CoreContainer.load Node Name: testNode
   [junit4]   2> 621242 T6262 oasc.CoreDescriptor.<init> CORE DESCRIPTOR: 
{name=collection1, config=solrconfig-functionquery.xml, transient=false, 
schema=schema11.xml, loadOnStartup=true, instanceDir=collection1, 
collection=collection1, 
absoluteInstDir=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/,
 
dataDir=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.search.function.TestFunctionQuery
 881611D4DD76A4CE-001/init-core-data-001, shard=shard1}
   [junit4]   2> 621243 T6263 oasc.SolrResourceLoader.<init> new 
SolrResourceLoader for directory: 
'/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/'
   [junit4]   2> 621243 T6263 oasc.SolrResourceLoader.replaceClassLoader Adding 
'file:/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/lib/classes/'
 to classloader
   [junit4]   2> 621244 T6263 oasc.SolrResourceLoader.replaceClassLoader Adding 
'file:/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/lib/README'
 to classloader
   [junit4]   2> 621255 T6263 oasc.SolrConfig.refreshRequestParams current 
version of requestparams : -1
   [junit4]   2> 621256 T6263 oasc.SolrConfig.<init> Using Lucene MatchVersion: 
6.0.0
   [junit4]   2> 621259 T6263 oasc.SolrConfig.<init> Loaded SolrConfig: 
solrconfig-functionquery.xml
   [junit4]   2> 621260 T6263 oass.IndexSchema.readSchema Reading Solr Schema 
from 
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/schema11.xml
   [junit4]   2> 621262 T6263 oass.IndexSchema.readSchema [collection1] Schema 
name=example
   [junit4]   2> 621290 T6263 oass.IndexSchema.readSchema default search field 
in schema is text
   [junit4]   2> 621290 T6263 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 621292 T6263 oasc.CoreContainer.create Creating SolrCore 
'collection1' using configuration from instancedir 
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/
   [junit4]   2> 621292 T6263 oasc.SolrCore.initDirectoryFactory 
org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 621293 T6263 oasc.SolrCore.<init> [collection1] Opening new 
SolrCore at 
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/,
 
dataDir=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.search.function.TestFunctionQuery
 881611D4DD76A4CE-001/init-core-data-001/
   [junit4]   2> 621293 T6263 oasc.SolrCore.<init> JMX monitoring not detected 
for core: collection1
   [junit4]   2> 621293 T6263 oasc.CachingDirectoryFactory.get return new 
directory for 
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.search.function.TestFunctionQuery
 881611D4DD76A4CE-001/init-core-data-001
   [junit4]   2> 621293 T6263 oasc.SolrCore.getNewIndexDir New index directory 
detected: old=null 
new=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.search.function.TestFunctionQuery
 881611D4DD76A4CE-001/init-core-data-001/index/
   [junit4]   2> 621293 T6263 oasc.SolrCore.initIndex WARN [collection1] Solr 
index directory 
'/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.search.function.TestFunctionQuery
 881611D4DD76A4CE-001/init-core-data-001/index' doesn't exist. Creating new 
index...
   [junit4]   2> 621294 T6263 oasc.CachingDirectoryFactory.get return new 
directory for 
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.search.function.TestFunctionQuery
 881611D4DD76A4CE-001/init-core-data-001/index
   [junit4]   2> 621294 T6263 oasu.RandomMergePolicy.<init> RandomMergePolicy 
wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: 
minMergeSize=1000, mergeFactor=33, maxMergeSize=9223372036854775807, 
maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, 
maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, 
noCFSRatio=0.0]
   [junit4]   2> 621294 T6263 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@c08bbc 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1f60cae),segFN=segments_1,generation=1}
   [junit4]   2> 621295 T6263 oasc.SolrDeletionPolicy.updateCommits newest 
commit generation = 1
   [junit4]   2> 621296 T6263 oasc.SolrCore.loadUpdateProcessorChains no 
updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 621298 T6263 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 621298 T6263 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 621299 T6263 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 621299 T6263 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 621301 T6263 oasc.RequestHandlers.initHandlersFromConfig 
Registered paths: 
/admin/mbeans,standard,/update/csv,/update/json/docs,/admin/luke,/admin/segments,/get,/admin/system,/replication,/admin/properties,/reloadCache,/config,/schema,/admin/plugins,/admin/logging,/update/json,/admin/threads,/admin/ping,/update,/admin/file
   [junit4]   2> 621301 T6263 oasc.SolrCore.initStatsCache Using default 
statsCache cache: org.apache.solr.search.stats.LocalStatsCache
   [junit4]   2> 621302 T6263 oasu.CommitTracker.<init> Hard AutoCommit: 
disabled
   [junit4]   2> 621302 T6263 oasu.CommitTracker.<init> Soft AutoCommit: 
disabled
   [junit4]   2> 621302 T6263 oasu.RandomMergePolicy.<init> RandomMergePolicy 
wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: 
maxMergeAtOnce=22, maxMergeAtOnceExplicit=32, maxMergedSegmentMB=87.4716796875, 
floorSegmentMB=1.3017578125, forceMergeDeletesPctAllowed=21.04605392526762, 
segmentsPerTier=18.0, maxCFSSegmentSizeMB=8.796093022207999E12, 
noCFSRatio=0.8029962020866077
   [junit4]   2> 621302 T6263 oasc.SolrDeletionPolicy.onInit 
SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@c08bbc 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1f60cae),segFN=segments_1,generation=1}
   [junit4]   2> 621302 T6263 oasc.SolrDeletionPolicy.updateCommits newest 
commit generation = 1
   [junit4]   2> 621303 T6263 oass.SolrIndexSearcher.<init> Opening 
Searcher@1dd3214[collection1] main
   [junit4]   2> 621303 T6263 oasr.ManagedResourceStorage.newStorageIO WARN 
Cannot write to config directory 
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf;
 switching to use InMemory storage instead.
   [junit4]   2> 621303 T6263 oasr.RestManager.init Initializing RestManager 
with initArgs: {}
   [junit4]   2> 621304 T6263 oasr.ManagedResourceStorage.load Reading 
_rest_managed.json using InMemoryStorage
   [junit4]   2> 621304 T6263 oasr.RestManager.init Initializing 0 registered 
ManagedResources
   [junit4]   2> 621304 T6263 oash.ReplicationHandler.inform Commits will be 
reserved for  10000
   [junit4]   2> 621304 T6263 oasc.CoreContainer.registerCore registering core: 
collection1
   [junit4]   2> 621304 T6264 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@1dd3214[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 621305 T6262 oas.SolrTestCaseJ4.initCore ####initCore end
   [junit4]   2> 621307 T6262 oas.SolrTestCaseJ4.setUp ###Starting 
testExternalFieldValueSourceParser
   [junit4]   2> ASYNC  NEW_CORE C2493 name=collection1 
org.apache.solr.core.SolrCore@f1266b
   [junit4]   2> 621308 T6262 C2493 oasu.DirectUpdateHandler2.deleteAll 
[collection1] REMOVING ALL DOCUMENTS FROM INDEX
   [junit4]   2> 621308 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 0
   [junit4]   2> 621310 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[100.0]} 0 1
   [junit4]   2> 621310 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[-4.0]} 0 0
   [junit4]   2> 621311 T6262 C2493 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 621312 T6262 C2493 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@c08bbc 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1f60cae),segFN=segments_1,generation=1}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@c08bbc 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1f60cae),segFN=segments_2,generation=2}
   [junit4]   2> 621313 T6262 C2493 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 2
   [junit4]   2> 621314 T6262 C2493 oass.SolrIndexSearcher.<init> Opening 
Searcher@4bfd98[collection1] main
   [junit4]   2> 621314 T6262 C2493 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 621314 T6264 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@4bfd98[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.0.0):C2)))}
   [junit4]   2> 621315 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 4
   [junit4]   2> 621315 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[0.0]} 0 0
   [junit4]   2> 621316 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[10.0]} 0 0
   [junit4]   2> 621316 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[25.0]} 0 0
   [junit4]   2> 621316 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[5.0]} 0 0
   [junit4]   2> 621317 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[77.0]} 0 0
   [junit4]   2> 621317 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[23.0]} 0 0
   [junit4]   2> 621318 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[55.0]} 0 1
   [junit4]   2> 621318 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[55.0]} 0 0
   [junit4]   2> 621318 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[-78.0]} 0 0
   [junit4]   2> 621319 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[-45.0]} 0 0
   [junit4]   2> 621319 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[-24.0]} 0 0
   [junit4]   2> 621319 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[-24.0]} 0 0
   [junit4]   2> 621320 T6262 C2493 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 621321 T6262 C2493 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@c08bbc 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1f60cae),segFN=segments_2,generation=2}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@c08bbc 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1f60cae),segFN=segments_3,generation=3}
   [junit4]   2> 621322 T6262 C2493 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 3
   [junit4]   2> 621322 T6262 C2493 oass.SolrIndexSearcher.<init> Opening 
Searcher@9df3d8[collection1] main
   [junit4]   2> 621322 T6262 C2493 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 621323 T6264 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@9df3d8[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.0.0):C2)
 Uninverting(_1(6.0.0):C12/2:delGen=1)))}
   [junit4]   2> 621324 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 4
   [junit4]   2> 621324 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[63.0]} 0 0
   [junit4]   2> 621325 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[78.0]} 0 0
   [junit4]   2> 621325 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[94.0]} 0 0
   [junit4]   2> 621325 T6262 C2493 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 621327 T6262 C2493 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@c08bbc 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1f60cae),segFN=segments_3,generation=3}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@c08bbc 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1f60cae),segFN=segments_4,generation=4}
   [junit4]   2> 621327 T6262 C2493 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 4
   [junit4]   2> 621328 T6262 C2493 oass.SolrIndexSearcher.<init> Opening 
Searcher@b6f58[collection1] main
   [junit4]   2> 621328 T6262 C2493 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 621328 T6264 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@b6f58[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.0.0):C2)
 Uninverting(_1(6.0.0):C12/2:delGen=1) Uninverting(_2(6.0.0):C3)))}
   [junit4]   2> 621329 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 4
   [junit4]   2> 621329 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[22.0]} 0 0
   [junit4]   2> 621330 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[34.0]} 0 0
   [junit4]   2> 621330 T6262 C2493 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 621332 T6262 C2493 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@c08bbc 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1f60cae),segFN=segments_4,generation=4}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@c08bbc 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1f60cae),segFN=segments_5,generation=5}
   [junit4]   2> 621333 T6262 C2493 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 5
   [junit4]   2> 621333 T6262 C2493 oass.SolrIndexSearcher.<init> Opening 
Searcher@e18c58[collection1] main
   [junit4]   2> 621334 T6262 C2493 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 621334 T6264 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@e18c58[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.0.0):C2)
 Uninverting(_1(6.0.0):C12/2:delGen=1) Uninverting(_2(6.0.0):C3) 
Uninverting(_3(6.0.0):C2)))}
   [junit4]   2> 621334 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 4
   [junit4]   2> 621335 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[54321.0]} 0 0
   [junit4]   2> 621335 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[261.0]} 0 0
   [junit4]   2> 621336 T6262 C2493 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 621338 T6262 C2493 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@c08bbc 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1f60cae),segFN=segments_5,generation=5}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@c08bbc 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1f60cae),segFN=segments_6,generation=6}
   [junit4]   2> 621338 T6262 C2493 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 6
   [junit4]   2> 621339 T6262 C2493 oass.SolrIndexSearcher.<init> Opening 
Searcher@2ea8e5[collection1] main
   [junit4]   2> 621339 T6262 C2493 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 621339 T6264 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@2ea8e5[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.0.0):C2)
 Uninverting(_1(6.0.0):C12/2:delGen=1) Uninverting(_2(6.0.0):C3) 
Uninverting(_3(6.0.0):C2) Uninverting(_4(6.0.0):C2)))}
   [junit4]   2> 621340 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 4
   [junit4]   2> 621340 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[-627.0]} 0 0
   [junit4]   2> 621341 T6262 C2493 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 621343 T6262 C2493 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@c08bbc 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1f60cae),segFN=segments_6,generation=6}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@c08bbc 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1f60cae),segFN=segments_7,generation=7}
   [junit4]   2> 621343 T6262 C2493 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 7
   [junit4]   2> 621344 T6262 C2493 oass.SolrIndexSearcher.<init> Opening 
Searcher@12a34bf[collection1] main
   [junit4]   2> 621344 T6262 C2493 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 621344 T6264 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@12a34bf[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.0.0):C2)
 Uninverting(_1(6.0.0):C12/2:delGen=1) Uninverting(_2(6.0.0):C3) 
Uninverting(_3(6.0.0):C2) Uninverting(_4(6.0.0):C2) Uninverting(_5(6.0.0):C1)))}
   [junit4]   2> 621345 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 4
   [junit4]   2> 621345 T6262 C2493 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 621345 T6262 C2493 oasu.DirectUpdateHandler2.commit No 
uncommitted changes. Skipping IW.commit.
   [junit4]   2> 621346 T6262 C2493 oasc.SolrCore.openNewSearcher 
SolrIndexSearcher has not changed - not re-opening: 
org.apache.solr.search.SolrIndexSearcher
   [junit4]   2> 621346 T6262 C2493 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 621346 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 1
   [junit4]   2> 621352 T6262 C2493 oassf.FileFloatSource.getFloats Loaded 
external value source external_CoMpleX fieldName _extf
   [junit4]   2> 621353 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}field("CoMpleX+fieldName+_extf")&indent=on&fl=*,score&rows=100&wt=xml}
 hits=20 status=0 QTime=6 
   [junit4]   2> 621356 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}log(field("CoMpleX+fieldName+_extf"))&indent=on&fl=*,score&rows=100&wt=xml}
 hits=20 status=0 QTime=1 
   [junit4]   2> 621356 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}sqrt(field("CoMpleX+fieldName+_extf"))&indent=on&fl=*,score&rows=100&wt=xml}
 hits=20 status=0 QTime=0 
   [junit4]   2> 621357 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[10000]} 0 0
   [junit4]   2> 621358 T6262 C2493 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 621360 T6262 C2493 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@c08bbc 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1f60cae),segFN=segments_7,generation=7}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@c08bbc 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1f60cae),segFN=segments_8,generation=8}
   [junit4]   2> 621361 T6262 C2493 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 8
   [junit4]   2> 621361 T6262 C2493 oass.SolrIndexSearcher.<init> Opening 
Searcher@ef0f7c[collection1] main
   [junit4]   2> 621361 T6262 C2493 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 621361 T6264 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@ef0f7c[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.0.0):C2)
 Uninverting(_1(6.0.0):C12/2:delGen=1) Uninverting(_2(6.0.0):C3) 
Uninverting(_3(6.0.0):C2) Uninverting(_4(6.0.0):C2) Uninverting(_5(6.0.0):C1) 
Uninverting(_6(6.0.0):C1)))}
   [junit4]   2> 621362 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 4
   [junit4]   2> 621363 T6262 C2493 oassf.FileFloatSource.getFloats Loaded 
external value source external_CoMpleX fieldName _extf
   [junit4]   2> 621364 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}sqrt(field("CoMpleX+fieldName+_extf"))&indent=on&fl=*,score&rows=100&wt=xml}
 hits=21 status=0 QTime=1 
   [junit4]   2> 621364 T6262 oas.SolrTestCaseJ4.tearDown ###Ending 
testExternalFieldValueSourceParser
   [junit4]   2> 621367 T6262 oas.SolrTestCaseJ4.setUp ###Starting 
testExternalFileFieldStringKeys
   [junit4]   2> 621367 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[991]} 0 0
   [junit4]   2> 621368 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[992]} 0 0
   [junit4]   2> 621368 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[993]} 0 0
   [junit4]   2> 621369 T6262 C2493 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 621371 T6262 C2493 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@c08bbc 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1f60cae),segFN=segments_8,generation=8}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@c08bbc 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1f60cae),segFN=segments_9,generation=9}
   [junit4]   2> 621372 T6262 C2493 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 9
   [junit4]   2> 621372 T6262 C2493 oass.SolrIndexSearcher.<init> Opening 
Searcher@dcfc8c[collection1] main
   [junit4]   2> 621373 T6262 C2493 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 621373 T6264 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@dcfc8c[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.0.0):C2)
 Uninverting(_1(6.0.0):C12/2:delGen=1) Uninverting(_2(6.0.0):C3) 
Uninverting(_3(6.0.0):C2) Uninverting(_4(6.0.0):C2) Uninverting(_5(6.0.0):C1) 
Uninverting(_6(6.0.0):C1) Uninverting(_7(6.0.0):C3)))}
   [junit4]   2> 621373 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 5
   [junit4]   2> 621374 T6262 C2493 oassf.FileFloatSource.getFloats Loaded 
external value source external_foo_extfs
   [junit4]   2> 621374 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}foo_extfs&indent=on&fl=*,score&rows=100&wt=xml} hits=24 
status=0 QTime=0 
   [junit4]   2> 621376 T6262 oas.SolrTestCaseJ4.tearDown ###Ending 
testExternalFileFieldStringKeys
   [junit4]   2> 621378 T6262 oas.SolrTestCaseJ4.setUp ###Starting 
testExternalField
   [junit4]   2> 621378 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[100.0]} 0 0
   [junit4]   2> 621379 T6262 C2493 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 621382 T6262 C2493 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@c08bbc 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1f60cae),segFN=segments_9,generation=9}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@c08bbc 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1f60cae),segFN=segments_a,generation=10}
   [junit4]   2> 621382 T6262 C2493 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 10
   [junit4]   2> 621383 T6262 C2493 oass.SolrIndexSearcher.<init> Opening 
Searcher@ed347a[collection1] main
   [junit4]   2> 621384 T6262 C2493 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 621384 T6264 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@ed347a[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.0.0):C2/1:delGen=1)
 Uninverting(_1(6.0.0):C12/2:delGen=1) Uninverting(_2(6.0.0):C3) 
Uninverting(_3(6.0.0):C2) Uninverting(_4(6.0.0):C2) Uninverting(_5(6.0.0):C1) 
Uninverting(_6(6.0.0):C1) Uninverting(_7(6.0.0):C3) Uninverting(_8(6.0.0):C1)))}
   [junit4]   2> 621385 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 7
   [junit4]   2> 621385 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[-4.0]} 0 0
   [junit4]   2> 621386 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[0.0]} 0 0
   [junit4]   2> 621386 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[10.0]} 0 0
   [junit4]   2> 621387 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[25.0]} 0 0
   [junit4]   2> 621388 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[5.0]} 0 0
   [junit4]   2> 621388 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[77.0]} 0 0
   [junit4]   2> 621389 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[77.0]} 0 0
   [junit4]   2> 621389 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[23.0]} 0 0
   [junit4]   2> 621390 T6262 C2493 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 621394 T6262 C2493 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@c08bbc 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1f60cae),segFN=segments_a,generation=10}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@c08bbc 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1f60cae),segFN=segments_b,generation=11}
   [junit4]   2> 621394 T6262 C2493 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 11
   [junit4]   2> 621395 T6262 C2493 oass.SolrIndexSearcher.<init> Opening 
Searcher@4034ba[collection1] main
   [junit4]   2> 621395 T6262 C2493 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 621395 T6264 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@4034ba[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_1(6.0.0):C12/8:delGen=2)
 Uninverting(_2(6.0.0):C3) Uninverting(_3(6.0.0):C2) Uninverting(_4(6.0.0):C2) 
Uninverting(_5(6.0.0):C1) Uninverting(_6(6.0.0):C1) Uninverting(_7(6.0.0):C3) 
Uninverting(_8(6.0.0):C1) Uninverting(_9(6.0.0):C8/1:delGen=1)))}
   [junit4]   2> 621396 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 7
   [junit4]   2> 621397 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[55.0]} 0 1
   [junit4]   2> 621397 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[-78.0]} 0 0
   [junit4]   2> 621398 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[-78.0]} 0 1
   [junit4]   2> 621398 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[-45.0]} 0 0
   [junit4]   2> 621398 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[-24.0]} 0 0
   [junit4]   2> 621399 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[63.0]} 0 0
   [junit4]   2> 621399 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[78.0]} 0 0
   [junit4]   2> 621399 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[78.0]} 0 0
   [junit4]   2> 621400 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[94.0]} 0 0
   [junit4]   2> 621400 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[22.0]} 0 0
   [junit4]   2> 621401 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[34.0]} 0 0
   [junit4]   2> 621401 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[34.0]} 0 0
   [junit4]   2> 621401 T6262 C2493 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 621404 T6262 C2493 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@c08bbc 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1f60cae),segFN=segments_b,generation=11}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@c08bbc 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1f60cae),segFN=segments_c,generation=12}
   [junit4]   2> 621405 T6262 C2493 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 12
   [junit4]   2> 621405 T6262 C2493 oass.SolrIndexSearcher.<init> Opening 
Searcher@145a375[collection1] main
   [junit4]   2> 621406 T6262 C2493 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 621406 T6264 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@145a375[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_4(6.0.0):C2)
 Uninverting(_5(6.0.0):C1) Uninverting(_6(6.0.0):C1) Uninverting(_7(6.0.0):C3) 
Uninverting(_8(6.0.0):C1) Uninverting(_9(6.0.0):C8/1:delGen=1) 
Uninverting(_a(6.0.0):C12/3:delGen=1)))}
   [junit4]   2> 621407 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 6
   [junit4]   2> 621408 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[54321.0]} 0 0
   [junit4]   2> 621408 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[54321.0]} 0 0
   [junit4]   2> 621409 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[261.0]} 0 0
   [junit4]   2> 621409 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[-627.0]} 0 0
   [junit4]   2> 621410 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[-627.0]} 0 1
   [junit4]   2> 621410 T6262 C2493 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 621413 T6262 C2493 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@c08bbc 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1f60cae),segFN=segments_c,generation=12}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@c08bbc 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1f60cae),segFN=segments_d,generation=13}
   [junit4]   2> 621413 T6262 C2493 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 13
   [junit4]   2> 621413 T6262 C2493 oass.SolrIndexSearcher.<init> Opening 
Searcher@14f5b10[collection1] main
   [junit4]   2> 621414 T6262 C2493 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 621414 T6264 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@14f5b10[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_6(6.0.0):C1)
 Uninverting(_7(6.0.0):C3) Uninverting(_8(6.0.0):C1) 
Uninverting(_9(6.0.0):C8/1:delGen=1) Uninverting(_a(6.0.0):C12/3:delGen=1) 
Uninverting(_b(6.0.0):C5/2:delGen=1)))}
   [junit4]   2> 621414 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 4
   [junit4]   2> 621416 T6262 C2493 oassf.FileFloatSource.getFloats Loaded 
external value source external_foo_extf
   [junit4]   2> 621416 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}foo_extf&indent=on&fl=*,score&rows=100&wt=xml} hits=24 
status=0 QTime=1 
   [junit4]   2> 621418 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}log(foo_extf)&indent=on&fl=*,score&rows=100&wt=xml} hits=24 
status=0 QTime=0 
   [junit4]   2> 621418 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}sqrt(foo_extf)&indent=on&fl=*,score&rows=100&wt=xml} hits=24 
status=0 QTime=0 
   [junit4]   2> 621419 T6262 C2493 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 621420 T6262 C2493 oasu.DirectUpdateHandler2.commit No 
uncommitted changes. Skipping IW.commit.
   [junit4]   2> 621420 T6262 C2493 oasc.SolrCore.openNewSearcher 
SolrIndexSearcher has not changed - not re-opening: 
org.apache.solr.search.SolrIndexSearcher
   [junit4]   2> 621420 T6262 C2493 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 621420 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={=&wt=xml} {commit=} 0 1
   [junit4]   2> 621421 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {} 0 0
   [junit4]   2> 621422 T6262 C2493 oassf.FileFloatSource.getFloats Loaded 
external value source external_foo_extf
   [junit4]   2> 621422 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}sqrt(foo_extf)&indent=on&fl=*,score&rows=100&wt=xml} hits=24 
status=0 QTime=1 
   [junit4]   2> 621423 T6262 C2493 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 621424 T6262 C2493 oasu.DirectUpdateHandler2.commit No 
uncommitted changes. Skipping IW.commit.
   [junit4]   2> 621425 T6262 C2493 oasc.SolrCore.openNewSearcher 
SolrIndexSearcher has not changed - not re-opening: 
org.apache.solr.search.SolrIndexSearcher
   [junit4]   2> 621425 T6262 C2493 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 621425 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={=&wt=xml} {commit=} 0 2
   [junit4]   2> 621426 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {} 0 0
   [junit4]   2> 621427 T6262 C2493 oassf.FileFloatSource.getFloats Loaded 
external value source external_foo_extf
   [junit4]   2> 621428 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}foo_extf&indent=on&fl=*,score&rows=100&wt=xml} hits=24 
status=0 QTime=1 
   [junit4]   2> 621435 T6262 C2493 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 621436 T6262 C2493 oasu.DirectUpdateHandler2.commit No 
uncommitted changes. Skipping IW.commit.
   [junit4]   2> 621436 T6262 C2493 oasc.SolrCore.openNewSearcher 
SolrIndexSearcher has not changed - not re-opening: 
org.apache.solr.search.SolrIndexSearcher
   [junit4]   2> 621437 T6262 C2493 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 621437 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={=&wt=xml} {commit=} 0 2
   [junit4]   2> 621437 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {} 0 0
   [junit4]   2> 621439 T6262 C2493 oassf.FileFloatSource.getFloats Loaded 
external value source external_foo_extf
   [junit4]   2> 621439 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}foo_extf&indent=on&fl=*,score&rows=100&wt=xml} hits=24 
status=0 QTime=1 
   [junit4]   2> 621446 T6262 C2493 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 621447 T6262 C2493 oasu.DirectUpdateHandler2.commit No 
uncommitted changes. Skipping IW.commit.
   [junit4]   2> 621448 T6262 C2493 oasc.SolrCore.openNewSearcher 
SolrIndexSearcher has not changed - not re-opening: 
org.apache.solr.search.SolrIndexSearcher
   [junit4]   2> 621448 T6262 C2493 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 621448 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={=&wt=xml} {commit=} 0 2
   [junit4]   2> 621449 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {} 0 0
   [junit4]   2> 621450 T6262 C2493 oassf.FileFloatSource.getFloats Loaded 
external value source external_foo_extf
   [junit4]   2> 621450 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}foo_extf&indent=on&fl=*,score&rows=100&wt=xml} hits=24 
status=0 QTime=1 
   [junit4]   2> 621454 T6262 C2493 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 621455 T6262 C2493 oasu.DirectUpdateHandler2.commit No 
uncommitted changes. Skipping IW.commit.
   [junit4]   2> 621455 T6262 C2493 oasc.SolrCore.openNewSearcher 
SolrIndexSearcher has not changed - not re-opening: 
org.apache.solr.search.SolrIndexSearcher
   [junit4]   2> 621455 T6262 C2493 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 621455 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={=&wt=xml} {commit=} 0 1
   [junit4]   2> 621456 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {} 0 0
   [junit4]   2> 621457 T6262 C2493 oassf.FileFloatSource.getFloats Loaded 
external value source external_foo_extf
   [junit4]   2> 621457 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}foo_extf&indent=on&fl=*,score&rows=100&wt=xml} hits=24 
status=0 QTime=1 
   [junit4]   2> 621461 T6262 C2493 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 621461 T6262 C2493 oasu.DirectUpdateHandler2.commit No 
uncommitted changes. Skipping IW.commit.
   [junit4]   2> 621461 T6262 C2493 oasc.SolrCore.openNewSearcher 
SolrIndexSearcher has not changed - not re-opening: 
org.apache.solr.search.SolrIndexSearcher
   [junit4]   2> 621461 T6262 C2493 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 621462 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={=&wt=xml} {commit=} 0 2
   [junit4]   2> 621462 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {} 0 0
   [junit4]   2> 621463 T6262 C2493 oassf.FileFloatSource.getFloats Loaded 
external value source external_foo_extf
   [junit4]   2> 621463 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}foo_extf&indent=on&fl=*,score&rows=100&wt=xml} hits=24 
status=0 QTime=1 
   [junit4]   2> 621467 T6262 C2493 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 621468 T6262 C2493 oasu.DirectUpdateHandler2.commit No 
uncommitted changes. Skipping IW.commit.
   [junit4]   2> 621468 T6262 C2493 oasc.SolrCore.openNewSearcher 
SolrIndexSearcher has not changed - not re-opening: 
org.apache.solr.search.SolrIndexSearcher
   [junit4]   2> 621468 T6262 C2493 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 621469 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={=&wt=xml} {commit=} 0 2
   [junit4]   2> 621469 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {} 0 0
   [junit4]   2> 621470 T6262 C2493 oassf.FileFloatSource.getFloats Loaded 
external value source external_foo_extf
   [junit4]   2> 621470 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}foo_extf&indent=on&fl=*,score&rows=100&wt=xml} hits=24 
status=0 QTime=1 
   [junit4]   2> 621474 T6262 C2493 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 621475 T6262 C2493 oasu.DirectUpdateHandler2.commit No 
uncommitted changes. Skipping IW.commit.
   [junit4]   2> 621475 T6262 C2493 oasc.SolrCore.openNewSearcher 
SolrIndexSearcher has not changed - not re-opening: 
org.apache.solr.search.SolrIndexSearcher
   [junit4]   2> 621476 T6262 C2493 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 621476 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={=&wt=xml} {commit=} 0 2
   [junit4]   2> 621476 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {} 0 0
   [junit4]   2> 621477 T6262 C2493 oassf.FileFloatSource.getFloats Loaded 
external value source external_foo_extf
   [junit4]   2> 621478 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}foo_extf&indent=on&fl=*,score&rows=100&wt=xml} hits=24 
status=0 QTime=1 
   [junit4]   2> 621481 T6262 C2493 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 621482 T6262 C2493 oasu.DirectUpdateHandler2.commit No 
uncommitted changes. Skipping IW.commit.
   [junit4]   2> 621482 T6262 C2493 oasc.SolrCore.openNewSearcher 
SolrIndexSearcher has not changed - not re-opening: 
org.apache.solr.search.SolrIndexSearcher
   [junit4]   2> 621482 T6262 C2493 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 621483 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={=&wt=xml} {commit=} 0 2
   [junit4]   2> 621483 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {} 0 0
   [junit4]   2> 621484 T6262 C2493 oassf.FileFloatSource.getFloats Loaded 
external value source external_foo_extf
   [junit4]   2> 621484 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}foo_extf&indent=on&fl=*,score&rows=100&wt=xml} hits=24 
status=0 QTime=1 
   [junit4]   2> 621488 T6262 C2493 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 621489 T6262 C2493 oasu.DirectUpdateHandler2.commit No 
uncommitted changes. Skipping IW.commit.
   [junit4]   2> 621489 T6262 C2493 oasc.SolrCore.openNewSearcher 
SolrIndexSearcher has not changed - not re-opening: 
org.apache.solr.search.SolrIndexSearcher
   [junit4]   2> 621489 T6262 C2493 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 621489 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={=&wt=xml} {commit=} 0 1
   [junit4]   2> 621490 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {} 0 0
   [junit4]   2> 621491 T6262 C2493 oassf.FileFloatSource.getFloats Loaded 
external value source external_foo_extf
   [junit4]   2> 621491 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}foo_extf&indent=on&fl=*,score&rows=100&wt=xml} hits=24 
status=0 QTime=1 
   [junit4]   2> 621495 T6262 C2493 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 621495 T6262 C2493 oasu.DirectUpdateHandler2.commit No 
uncommitted changes. Skipping IW.commit.
   [junit4]   2> 621496 T6262 C2493 oasc.SolrCore.openNewSearcher 
SolrIndexSearcher has not changed - not re-opening: 
org.apache.solr.search.SolrIndexSearcher
   [junit4]   2> 621496 T6262 C2493 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 621496 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={=&wt=xml} {commit=} 0 1
   [junit4]   2> 621497 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {} 0 0
   [junit4]   2> 621498 T6262 C2493 oassf.FileFloatSource.getFloats Loaded 
external value source external_foo_extf
   [junit4]   2> 621498 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}foo_extf&indent=on&fl=*,score&rows=100&wt=xml} hits=24 
status=0 QTime=1 
   [junit4]   2> 621501 T6262 oas.SolrTestCaseJ4.tearDown ###Ending 
testExternalField
   [junit4]   2> 621504 T6262 oas.SolrTestCaseJ4.setUp ###Starting 
testPseudoFieldFunctions
   [junit4]   2> 621505 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[1]} 0 1
   [junit4]   2> 621506 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[2]} 0 1
   [junit4]   2> 621506 T6262 C2493 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 621509 T6262 C2493 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@c08bbc 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1f60cae),segFN=segments_d,generation=13}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@c08bbc 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1f60cae),segFN=segments_e,generation=14}
   [junit4]   2> 621510 T6262 C2493 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 14
   [junit4]   2> 621511 T6262 C2493 oass.SolrIndexSearcher.<init> Opening 
Searcher@1c5e2c5[collection1] main
   [junit4]   2> 621516 T6262 C2493 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 621516 T6264 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@1c5e2c5[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_6(6.0.0):C1)
 Uninverting(_7(6.0.0):C3) Uninverting(_8(6.0.0):C1) 
Uninverting(_9(6.0.0):C8/1:delGen=1) Uninverting(_a(6.0.0):C12/3:delGen=1) 
Uninverting(_b(6.0.0):C5/2:delGen=1) Uninverting(_c(6.0.0):C2)))}
   [junit4]   2> 621517 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 11
   [junit4]   2> 621521 T6262 C2493 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=3 
   [junit4]   2> 621523 T6262 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":3},
   [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> 621524 T6262 oas.SolrTestCaseJ4.tearDown ###Ending 
testPseudoFieldFunctions
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=TestFunctionQuery 
-Dtests.method=testPseudoFieldFunctions -Dtests.seed=881611D4DD76A4CE 
-Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=ca_ES 
-Dtests.timezone=Asia/Seoul -Dtests.asserts=true -Dtests.file.encoding=US-ASCII
   [junit4] ERROR   0.03s J0 | TestFunctionQuery.testPseudoFieldFunctions <<<
   [junit4]    > Throwable #1: java.lang.RuntimeException: unexpected map keys 
[e] @ response/docs/[0]
   [junit4]    >        at 
__randomizedtesting.SeedInfo.seed([881611D4DD76A4CE:D62CF3A9E1E05882]: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> 621529 T6262 oas.SolrTestCaseJ4.setUp ###Starting testFuncs
   [junit4]   2> 621529 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[1]} 0 0
   [junit4]   2> 621530 T6262 C2493 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 621532 T6262 C2493 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@c08bbc 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1f60cae),segFN=segments_e,generation=14}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@c08bbc 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1f60cae),segFN=segments_f,generation=15}
   [junit4]   2> 621533 T6262 C2493 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 15
   [junit4]   2> 621533 T6262 C2493 oass.SolrIndexSearcher.<init> Opening 
Searcher@1d1ef25[collection1] main
   [junit4]   2> 621534 T6262 C2493 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 621534 T6264 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@1d1ef25[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_6(6.0.0):C1)
 Uninverting(_7(6.0.0):C3) Uninverting(_8(6.0.0):C1) 
Uninverting(_9(6.0.0):C8/1:delGen=1) Uninverting(_a(6.0.0):C12/3:delGen=1) 
Uninverting(_b(6.0.0):C5/2:delGen=1) Uninverting(_c(6.0.0):C2/1:delGen=1) 
Uninverting(_d(6.0.0):C1)))}
   [junit4]   2> 621534 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 4
   [junit4]   2> 621535 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q=1.0&defType=func&fl=*,score&fq=id:1&wt=xml} 
hits=1 status=0 QTime=0 
   [junit4]   2> 621536 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q=e()&defType=func&fl=*,score&fq=id:1&wt=xml} 
hits=1 status=0 QTime=0 
   [junit4]   2> 621537 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q=pi()&defType=func&fl=*,score&fq=id:1&wt=xml} 
hits=1 status=0 QTime=1 
   [junit4]   2> 621537 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=add(2,3)&defType=func&fl=*,score&fq=id:1&wt=xml} hits=1 status=0 
QTime=0 
   [junit4]   2> 621538 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=mul(2,3)&defType=func&fl=*,score&fq=id:1&wt=xml} hits=1 status=0 
QTime=0 
   [junit4]   2> 621538 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q=rad(45)&defType=func&fl=*,score&fq=id:1&wt=xml} 
hits=1 status=0 QTime=0 
   [junit4]   2> 621539 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q=deg(.5)&defType=func&fl=*,score&fq=id:1&wt=xml} 
hits=1 status=0 QTime=0 
   [junit4]   2> 621540 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q=sqrt(9)&defType=func&fl=*,score&fq=id:1&wt=xml} 
hits=1 status=0 QTime=0 
   [junit4]   2> 621541 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q=cbrt(8)&defType=func&fl=*,score&fq=id:1&wt=xml} 
hits=1 status=0 QTime=1 
   [junit4]   2> 621541 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=max(0,1)&defType=func&fl=*,score&fq=id:1&wt=xml} hits=1 status=0 
QTime=0 
   [junit4]   2> 621542 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=max(10,3,8,7,5,4)&defType=func&fl=*,score&fq=id:1&wt=xml} hits=1 
status=0 QTime=0 
   [junit4]   2> 621543 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=min(0,1)&defType=func&fl=*,score&fq=id:1&wt=xml} hits=1 status=0 
QTime=1 
   [junit4]   2> 621543 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=min(10,3,8,7,5,4)&defType=func&fl=*,score&fq=id:1&wt=xml} hits=1 
status=0 QTime=0 
   [junit4]   2> 621544 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=log(100)&defType=func&fl=*,score&fq=id:1&wt=xml} hits=1 status=0 
QTime=0 
   [junit4]   2> 621544 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q=ln(3)&defType=func&fl=*,score&fq=id:1&wt=xml} 
hits=1 status=0 QTime=0 
   [junit4]   2> 621545 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q=exp(1)&defType=func&fl=*,score&fq=id:1&wt=xml} 
hits=1 status=0 QTime=0 
   [junit4]   2> 621546 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q=sin(.5)&defType=func&fl=*,score&fq=id:1&wt=xml} 
hits=1 status=0 QTime=1 
   [junit4]   2> 621546 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q=cos(.5)&defType=func&fl=*,score&fq=id:1&wt=xml} 
hits=1 status=0 QTime=0 
   [junit4]   2> 621547 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q=tan(.5)&defType=func&fl=*,score&fq=id:1&wt=xml} 
hits=1 status=0 QTime=0 
   [junit4]   2> 621547 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=asin(.5)&defType=func&fl=*,score&fq=id:1&wt=xml} hits=1 status=0 
QTime=0 
   [junit4]   2> 621548 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=acos(.5)&defType=func&fl=*,score&fq=id:1&wt=xml} hits=1 status=0 
QTime=0 
   [junit4]   2> 621549 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=atan(.5)&defType=func&fl=*,score&fq=id:1&wt=xml} hits=1 status=0 
QTime=1 
   [junit4]   2> 621549 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=sinh(.5)&defType=func&fl=*,score&fq=id:1&wt=xml} hits=1 status=0 
QTime=0 
   [junit4]   2> 621550 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=cosh(.5)&defType=func&fl=*,score&fq=id:1&wt=xml} hits=1 status=0 
QTime=0 
   [junit4]   2> 621551 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=tanh(.5)&defType=func&fl=*,score&fq=id:1&wt=xml} hits=1 status=0 
QTime=1 
   [junit4]   2> 621552 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=ceil(2.3)&defType=func&fl=*,score&fq=id:1&wt=xml} hits=1 status=0 
QTime=1 
   [junit4]   2> 621552 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=floor(2.3)&defType=func&fl=*,score&fq=id:1&wt=xml} hits=1 status=0 
QTime=0 
   [junit4]   2> 621553 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=rint(2.3)&defType=func&fl=*,score&fq=id:1&wt=xml} hits=1 status=0 
QTime=1 
   [junit4]   2> 621554 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=pow(2,0.5)&defType=func&fl=*,score&fq=id:1&wt=xml} hits=1 status=0 
QTime=1 
   [junit4]   2> 621555 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=hypot(3,4)&defType=func&fl=*,score&fq=id:1&wt=xml} hits=1 status=0 
QTime=1 
   [junit4]   2> 621555 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=atan2(.25,.5)&defType=func&fl=*,score&fq=id:1&wt=xml} hits=1 status=0 
QTime=0 
   [junit4]   2> 621556 T6262 oas.SolrTestCaseJ4.tearDown ###Ending testFuncs
   [junit4]   2> 621559 T6262 oas.SolrTestCaseJ4.setUp ###Starting 
testTotalTermFreq
   [junit4]   2> 621560 T6262 C2493 oasu.DirectUpdateHandler2.deleteAll 
[collection1] REMOVING ALL DOCUMENTS FROM INDEX
   [junit4]   2> 621560 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 1
   [junit4]   2> 621561 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[1]} 0 0
   [junit4]   2> 621562 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[2]} 0 0
   [junit4]   2> 621563 T6262 C2493 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 621565 T6262 C2493 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@c08bbc 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1f60cae),segFN=segments_f,generation=15}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@c08bbc 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1f60cae),segFN=segments_g,generation=16}
   [junit4]   2> 621565 T6262 C2493 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 16
   [junit4]   2> 621567 T6262 C2493 oass.SolrIndexSearcher.<init> Opening 
Searcher@17e3b75[collection1] main
   [junit4]   2> 621567 T6262 C2493 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 621567 T6264 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@17e3b75[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_e(6.0.0):C2)))}
   [junit4]   2> 621568 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 5
   [junit4]   2> 621569 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[3]} 0 0
   [junit4]   2> 621569 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[4]} 0 0
   [junit4]   2> 621570 T6262 C2493 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 621571 T6262 C2493 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@c08bbc 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1f60cae),segFN=segments_g,generation=16}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@c08bbc 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1f60cae),segFN=segments_h,generation=17}
   [junit4]   2> 621572 T6262 C2493 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 17
   [junit4]   2> 621572 T6262 C2493 oass.SolrIndexSearcher.<init> Opening 
Searcher@1e934e8[collection1] main
   [junit4]   2> 621573 T6262 C2493 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 621573 T6264 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@1e934e8[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_e(6.0.0):C2)
 Uninverting(_f(6.0.0):C2)))}
   [junit4]   2> 621573 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 3
   [junit4]   2> 621574 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[5]} 0 1
   [junit4]   2> 621574 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[6]} 0 0
   [junit4]   2> 621574 T6262 C2493 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 621577 T6262 C2493 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@c08bbc 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1f60cae),segFN=segments_h,generation=17}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@c08bbc 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1f60cae),segFN=segments_i,generation=18}
   [junit4]   2> 621577 T6262 C2493 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 18
   [junit4]   2> 621577 T6262 C2493 oass.SolrIndexSearcher.<init> Opening 
Searcher@224f65[collection1] main
   [junit4]   2> 621578 T6262 C2493 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 621578 T6264 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@224f65[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_e(6.0.0):C2)
 Uninverting(_f(6.0.0):C2) Uninverting(_g(6.0.0):C2)))}
   [junit4]   2> 621578 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 4
   [junit4]   2> 621581 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}totaltermfreq('a_t','cow')&fl=*,score&fq=id:6&wt=xml} hits=1 
status=0 QTime=2 
   [junit4]   2> 621582 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}ttf(a_t,'cow')&fl=*,score&fq=id:6&wt=xml} hits=1 status=0 
QTime=0 
   [junit4]   2> 621584 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}sumtotaltermfreq('a_t')&fl=*,score&fq=id:6&wt=xml} hits=1 
status=0 QTime=1 
   [junit4]   2> 621585 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q={!func}sttf(a_t)&fl=*,score&fq=id:6&wt=xml} 
hits=1 status=0 QTime=1 
   [junit4]   2> 621585 T6262 oas.SolrTestCaseJ4.tearDown ###Ending 
testTotalTermFreq
   [junit4]   2> 621587 T6262 oas.SolrTestCaseJ4.setUp ###Starting 
testStrDistance
   [junit4]   2> 621588 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[1]} 0 0
   [junit4]   2> 621588 T6262 C2493 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 621591 T6262 C2493 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@c08bbc 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1f60cae),segFN=segments_i,generation=18}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@c08bbc 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1f60cae),segFN=segments_j,generation=19}
   [junit4]   2> 621591 T6262 C2493 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 19
   [junit4]   2> 621592 T6262 C2493 oass.SolrIndexSearcher.<init> Opening 
Searcher@3a28aa[collection1] main
   [junit4]   2> 621592 T6262 C2493 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 621592 T6264 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@3a28aa[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_e(6.0.0):C2/1:delGen=1)
 Uninverting(_f(6.0.0):C2) Uninverting(_g(6.0.0):C2) 
Uninverting(_h(6.0.0):C1)))}
   [junit4]   2> 621593 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 5
   [junit4]   2> 621595 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}strdist(x_s,+'foit',+edit)&fl=*,score&fq=id:1&wt=xml} hits=1 
status=0 QTime=2 
   [junit4]   2> 621596 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}strdist(x_s,+'foit',+jw)&fl=*,score&fq=id:1&wt=xml} hits=1 
status=0 QTime=1 
   [junit4]   2> 621597 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}strdist(x_s,+'foit',+ngram,+2)&fl=*,score&fq=id:1&wt=xml} 
hits=1 status=0 QTime=1 
   [junit4]   2> 621598 T6262 C2493 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> 621600 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}strdist(missing1_s,+missing2_s,+edit)&fl=score&fq=id:1&wt=xml} 
hits=1 status=0 QTime=1 
   [junit4]   2> 621601 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}strdist(missing1_s,+x_s,+edit)&fl=score&fq=id:1&wt=xml} hits=1 
status=0 QTime=1 
   [junit4]   2> 621602 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}strdist(missing1_s,+'const',+edit)&fl=score&fq=id:1&wt=xml} 
hits=1 status=0 QTime=1 
   [junit4]   2> 621602 T6262 oas.SolrTestCaseJ4.tearDown ###Ending 
testStrDistance
   [junit4]   2> 621605 T6262 oas.SolrTestCaseJ4.setUp ###Starting testGeneral
   [junit4]   2> 621606 T6262 C2493 oasu.DirectUpdateHandler2.deleteAll 
[collection1] REMOVING ALL DOCUMENTS FROM INDEX
   [junit4]   2> 621606 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 0
   [junit4]   2> 621607 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[1]} 0 0
   [junit4]   2> 621608 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[2]} 0 1
   [junit4]   2> 621608 T6262 C2493 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 621609 T6262 C2493 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@c08bbc 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1f60cae),segFN=segments_j,generation=19}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@c08bbc 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1f60cae),segFN=segments_k,generation=20}
   [junit4]   2> 621610 T6262 C2493 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 20
   [junit4]   2> 621610 T6262 C2493 oass.SolrIndexSearcher.<init> Opening 
Searcher@103f63c[collection1] main
   [junit4]   2> 621611 T6262 C2493 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 621611 T6264 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@103f63c[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_i(6.0.0):C2)))}
   [junit4]   2> 621612 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 4
   [junit4]   2> 621613 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[3]} 0 1
   [junit4]   2> 621613 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[4]} 0 0
   [junit4]   2> 621613 T6262 C2493 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 621615 T6262 C2493 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@c08bbc 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1f60cae),segFN=segments_k,generation=20}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@c08bbc 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1f60cae),segFN=segments_l,generation=21}
   [junit4]   2> 621616 T6262 C2493 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 21
   [junit4]   2> 621616 T6262 C2493 oass.SolrIndexSearcher.<init> Opening 
Searcher@1b3f8d1[collection1] main
   [junit4]   2> 621616 T6262 C2493 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 621617 T6264 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@1b3f8d1[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_i(6.0.0):C2)
 Uninverting(_j(6.0.0):C2)))}
   [junit4]   2> 621617 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 4
   [junit4]   2> 621618 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[5]} 0 1
   [junit4]   2> 621618 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[6]} 0 0
   [junit4]   2> 621619 T6262 C2493 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 621621 T6262 C2493 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@c08bbc 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1f60cae),segFN=segments_l,generation=21}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@c08bbc 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1f60cae),segFN=segments_m,generation=22}
   [junit4]   2> 621621 T6262 C2493 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 22
   [junit4]   2> 621622 T6262 C2493 oass.SolrIndexSearcher.<init> Opening 
Searcher@1b5dece[collection1] main
   [junit4]   2> 621622 T6262 C2493 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 621622 T6264 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@1b5dece[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_i(6.0.0):C2)
 Uninverting(_j(6.0.0):C2) Uninverting(_k(6.0.0):C2)))}
   [junit4]   2> 621623 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 4
   [junit4]   2> 621625 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q={!func}numdocs()&fl=*,score&fq=id:6&wt=xml} 
hits=1 status=0 QTime=2 
   [junit4]   2> 621626 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q={!func}maxdoc()&fl=*,score&fq=id:6&wt=xml} 
hits=1 status=0 QTime=1 
   [junit4]   2> 621627 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}docfreq(a_t,cow)&fl=*,score&fq=id:6&wt=xml} hits=1 status=0 
QTime=1 
   [junit4]   2> 621628 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}docfreq('a_t','cow')&fl=*,score&fq=id:6&wt=xml} hits=1 
status=0 QTime=1 
   [junit4]   2> 621628 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}docfreq($field,$value)&field=a_t&fl=*,score&fq=id:6&value=cow&wt=xml}
 hits=1 status=0 QTime=0 
   [junit4]   2> 621631 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}termfreq(a_t,cow)&fl=*,score&fq=id:6&wt=xml} hits=1 status=0 
QTime=2 
   [junit4]   2> 621632 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}termfreq(nofield_t,cow)&fl=*,score&fq=id:6&wt=xml} hits=1 
status=0 QTime=1 
   [junit4]   2> 621633 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}docfreq(nofield_t,cow)&fl=*,score&fq=id:6&wt=xml} hits=1 
status=0 QTime=1 
   [junit4]   2> 621634 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}idf(nofield_t,cow)&fl=*,score&fq=id:6&wt=xml} hits=1 status=0 
QTime=1 
   [junit4]   2> 621637 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}tf(nofield_t,cow)&fl=*,score&fq=id:6&wt=xml} hits=1 status=0 
QTime=2 
   [junit4]   2> 621638 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q={!func}idf(a_t,cow)&fl=*,score&fq=id:6&wt=xml} 
hits=1 status=0 QTime=0 
   [junit4]   2> 621639 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q={!func}tf(a_t,cow)&fl=*,score&fq=id:6&wt=xml} 
hits=1 status=0 QTime=0 
   [junit4]   2> 621641 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q={!func}norm(a_t)&fl=*,score&fq=id:2&wt=xml} 
hits=1 status=0 QTime=2 
   [junit4]   2> 621642 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q={!func}ord(id)&fl=*,score&fq=id:6&wt=xml} 
hits=1 status=0 QTime=1 
   [junit4]   2> 621643 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q={!func}top(ord(id))&fl=*,score&fq=id:6&wt=xml} 
hits=1 status=0 QTime=1 
   [junit4]   2> 621644 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q={!func}rord(id)&fl=*,score&fq=id:1&wt=xml} 
hits=1 status=0 QTime=1 
   [junit4]   2> 621645 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null params={q={!func}top(rord(id))&fl=*,score&fq=id:1&wt=xml} 
hits=1 status=0 QTime=1 
   [junit4]   2> 621646 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}ms(a_tdt,b_tdt)&fl=*,score&fq=id:1&wt=xml} hits=1 status=0 
QTime=1 
   [junit4]   2> 621647 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}ms(b_tdt,a_tdt)&fl=*,score&fq=id:1&wt=xml} hits=1 status=0 
QTime=1 
   [junit4]   2> 621647 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}ms(2009-08-31T12:10:10.125Z,2009-08-31T12:10:10.124Z)&fl=*,score&fq=id:1&wt=xml}
 hits=1 status=0 QTime=0 
   [junit4]   2> 621648 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}ms(2009-08-31T12:10:10.124Z,a_tdt)&fl=*,score&fq=id:1&wt=xml} 
hits=1 status=0 QTime=0 
   [junit4]   2> 621649 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}ms(2009-08-31T12:10:10.125Z,b_tdt)&fl=*,score&fq=id:1&wt=xml} 
hits=1 status=0 QTime=1 
   [junit4]   2> 621649 T6262 C2493 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q={!func}ms(2009-08-31T12:10:10.125Z/SECOND,2009-08-31T12:10:10.124Z/SECOND)&fl=*,score&fq=id:1&wt=xml}
 hits=1 status=0 QTime=0 
   [junit4]   2> 621650 T6262 C2493 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> 621651 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[100]} 0 1
   [junit4]   2> 621651 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[101]} 0 0
   [junit4]   2> 621651 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[102]} 0 0
   [junit4]   2> 621652 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[103]} 0 0
   [junit4]   2> 621652 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[104]} 0 0
   [junit4]   2> 621653 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[105]} 0 0
   [junit4]   2> 621653 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[106]} 0 0
   [junit4]   2> 621654 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[107]} 0 1
   [junit4]   2> 621654 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[108]} 0 0
   [junit4]   2> 621654 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[109]} 0 0
   [junit4]   2> 621655 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[110]} 0 0
   [junit4]   2> 621655 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[111]} 0 0
   [junit4]   2> 621655 T6262 C2493 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 621658 T6262 C2493 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@c08bbc 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1f60cae),segFN=segments_m,generation=22}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@c08bbc 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1f60cae),segFN=segments_n,generation=23}
   [junit4]   2> 621658 T6262 C2493 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 23
   [junit4]   2> 621659 T6262 C2493 oass.SolrIndexSearcher.<init> Opening 
Searcher@5a85bc[collection1] main
   [junit4]   2> 621659 T6262 C2493 oasu.DirectUpdateHandler2.commit 
end_commit_flush
   [junit4]   2> 621660 T6264 oasc.SolrCore.registerSearcher [collection1] 
Registered new searcher Searcher@5a85bc[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_i(6.0.0):C2)
 Uninverting(_j(6.0.0):C2) Uninverting(_k(6.0.0):C2) 
Uninverting(_l(6.0.0):C12)))}
   [junit4]   2> 621660 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {commit=} 0 5
   [junit4]   2> 621661 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[120]} 0 0
   [junit4]   2> 621661 T6262 C2493 oasup.LogUpdateProcessor.finish 
[collection1] webapp=null path=null params={} {add=[121]} 0 0
   [junit4]   2> 621662 T6262 C2493 oasu.DirectUpdateHandler2.commit start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 621664 T6262 C2493 oasc.SolrDeletionPolicy.onCommit 
SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@c08bbc 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1f60cae),segFN=segments_n,generation=23}
   [junit4]   2>                
commit{dir=MockDirectoryWrapper(RAMDirectory@c08bbc 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1f60cae),segFN=segments_o,generation=24}
   [junit4]   2> 621665 T6262 C2493 oasc.SolrDeletionPolicy.updateCommits 
newest commit generation = 24
   [junit4]   2> 621665 T6262 

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

 
   [junit4]   2> 621919 T6262 C2494 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=id:1&fl=noval_if:if(no__vals____i,42,-99)&fl=noval_def:def(no__vals____i,-99)&fl=noval_not:not(no__vals____i)&fl=noval_exists:exists(no__vals____i)&wt=xml}
 hits=1 status=0 QTime=1 
   [junit4]   2> 621920 T6262 C2494 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=id:1&fl=noval_if:if(no__vals____l,42,-99)&fl=noval_def:def(no__vals____l,-99)&fl=noval_not:not(no__vals____l)&fl=noval_exists:exists(no__vals____l)&wt=xml}
 hits=1 status=0 QTime=0 
   [junit4]   2> 621921 T6262 C2494 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=id:1&fl=noval_if:if(no__vals____f,42,-99)&fl=noval_def:def(no__vals____f,-99)&fl=noval_not:not(no__vals____f)&fl=noval_exists:exists(no__vals____f)&wt=xml}
 hits=1 status=0 QTime=0 
   [junit4]   2> 621922 T6262 C2494 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> 621923 T6262 C2494 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> 621924 T6262 C2494 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> 621925 T6262 C2494 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> 621926 T6262 C2494 oasc.SolrCore.execute [collection1] 
webapp=null path=null 
params={q=id:1&fl=noval_if:if(no__vals____td,42,-99)&fl=noval_def:def(no__vals____td,-99)&fl=noval_not:not(no__vals____td)&fl=noval_exists:exists(no__vals____td)&wt=xml}
 hits=1 status=0 QTime=0 
   [junit4]   2> 621927 T6262 oas.SolrTestCaseJ4.tearDown ###Ending 
testMissingFieldFunctionBehavior
   [junit4]   2> 621928 T6262 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> 621928 T6262 oasc.CoreContainer.shutdown Shutting down 
CoreContainer instance=20600411
   [junit4]   2> 621929 T6262 oasc.SolrCore.close [collection1]  CLOSING 
SolrCore org.apache.solr.core.SolrCore@f1266b
   [junit4]   2> 621929 T6262 oasu.DirectUpdateHandler2.close closing 
DirectUpdateHandler2{commits=49,autocommits=0,soft 
autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=122,cumulative_deletesById=0,cumulative_deletesByQuery=5,cumulative_errors=0}
   [junit4]   2> 621929 T6262 oasu.SolrCoreState.decrefSolrCoreState Closing 
SolrCoreState
   [junit4]   2> 621930 T6262 oasu.DefaultSolrCoreState.closeIndexWriter 
SolrCoreState ref count has reached 0 - closing IndexWriter
   [junit4]   2> 621930 T6262 oasu.DefaultSolrCoreState.closeIndexWriter 
closing IndexWriter with IndexWriterCloser
   [junit4]   2> 621930 T6262 oasc.SolrCore.closeSearcher [collection1] Closing 
main searcher on request.
   [junit4]   2> 621931 T6262 oasc.CachingDirectoryFactory.close Closing 
MockDirectoryFactory - 2 directories currently being tracked
   [junit4]   2> 621931 T6262 oasc.CachingDirectoryFactory.closeCacheValue 
looking to close 
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.search.function.TestFunctionQuery
 881611D4DD76A4CE-001/init-core-data-001/index 
[CachedDir<<refCount=0;path=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.search.function.TestFunctionQuery
 881611D4DD76A4CE-001/init-core-data-001/index;done=false>>]
   [junit4]   2> 621931 T6262 oasc.CachingDirectoryFactory.close Closing 
directory: 
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.search.function.TestFunctionQuery
 881611D4DD76A4CE-001/init-core-data-001/index
   [junit4]   2> 621932 T6262 oasc.CachingDirectoryFactory.closeCacheValue 
looking to close 
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.search.function.TestFunctionQuery
 881611D4DD76A4CE-001/init-core-data-001 
[CachedDir<<refCount=0;path=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.search.function.TestFunctionQuery
 881611D4DD76A4CE-001/init-core-data-001;done=false>>]
   [junit4]   2> 621932 T6262 oasc.CachingDirectoryFactory.close Closing 
directory: 
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.search.function.TestFunctionQuery
 881611D4DD76A4CE-001/init-core-data-001
   [junit4]   2> NOTE: leaving temporary files on disk at: 
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.search.function.TestFunctionQuery
 881611D4DD76A4CE-001
   [junit4]   2> NOTE: test params are: codec=Asserting(Lucene50): 
{x_td=PostingsFormat(name=LuceneVarGapDocFreqInterval), 
const_s=PostingsFormat(name=LuceneVarGapDocFreqInterval), 
x_i=PostingsFormat(name=LuceneFixedGap), 
a_tdt=PostingsFormat(name=LuceneFixedGap), 1_s=Lucene50(blocksize=128), 
eff_ti=PostingsFormat(name=LuceneVarGapDocFreqInterval), 
foo_s=PostingsFormat(name=LuceneFixedGap), x_s=BlockTreeOrds(blocksize=128), 
y_td=PostingsFormat(name=LuceneFixedGap), 1-1_s=Lucene50(blocksize=128), 
CoMpleX " fieldName _f=BlockTreeOrds(blocksize=128), 
foo_tl=Lucene50(blocksize=128), foo_ti=BlockTreeOrds(blocksize=128), 
foo_tf=PostingsFormat(name=LuceneVarGapDocFreqInterval), 
sfile_s=PostingsFormat(name=LuceneVarGapDocFreqInterval), 
b_tdt=PostingsFormat(name=LuceneVarGapDocFreqInterval), 
a_t=PostingsFormat(name=LuceneFixedGap), x:x_i=BlockTreeOrds(blocksize=128), 
foo_d=PostingsFormat(name=LuceneVarGapDocFreqInterval), 
id=PostingsFormat(name=LuceneVarGapDocFreqInterval), 
text=Lucene50(blocksize=128), yak_i=Lucene50(blocksize=128), 
foo_f=Lucene50(blocksize=128)}, docValues:{}, sim=DefaultSimilarity, 
locale=ca_ES, timezone=Asia/Seoul
   [junit4]   2> NOTE: Linux 3.13.0-46-generic i386/Oracle Corporation 1.9.0-ea 
(32-bit)/cpus=12,threads=1,free=189674800,total=536870912
   [junit4]   2> NOTE: All tests run in this JVM: [TestConfigReload, 
ResponseHeaderTest, TestBinaryField, EnumFieldTest, TestRawResponseWriter, 
QueryResultKeyTest, SuggesterFSTTest, URLClassifyProcessorTest, 
DeleteShardTest, TestDocumentBuilder, TestDynamicFieldResource, 
TestReversedWildcardFilterFactory, OverseerStatusTest, DateFieldTest, 
DistributedSuggestComponentTest, SuggestComponentTest, HdfsSyncSliceTest, 
TestWordDelimiterFilterFactory, MBeansHandlerTest, TestSolr4Spatial, 
PrimitiveFieldTypeTest, ZkNodePropsTest, TestSolrIndexConfig, 
TestExpandComponent, CSVRequestHandlerTest, ClusterStateTest, TestJoin, 
TestRemoteStreaming, HighlighterTest, TestReloadAndDeleteDocs, 
TestSweetSpotSimilarityFactory, TestReplicationHandler, BasicDistributedZkTest, 
TestPostingsSolrHighlighter, DefaultValueUpdateProcessorTest, 
TestHdfsUpdateLog, DateMathParserTest, TestJmxIntegration, SolrCoreTest, 
TestNonDefinedSimilarityFactory, DistributedFacetPivotLargeTest, 
StandardRequestHandlerTest, DistributedSpellCheckComponentTest, 
TestInfoStreamLogging, CachingDirectoryFactoryTest, TestDFRSimilarityFactory, 
TestStressLucene, TestSolrConfigHandler, TestCSVLoader, 
QueryElevationComponentTest, TestIndexingPerformance, HighlighterConfigTest, 
TestMissingGroups, TestCloudManagedSchemaConcurrent, SimplePostToolTest, 
TestSchemaSimilarityResource, LeaderFailoverAfterPartitionTest, 
TestStandardQParsers, FastVectorHighlighterTest, 
TestManagedSynonymFilterFactory, SuggesterWFSTTest, TestManagedResourceStorage, 
SegmentsInfoRequestHandlerTest, LeaderInitiatedRecoveryOnCommitTest, 
SolrIndexConfigTest, TestDynamicFieldCollectionResource, 
TestClassNameShortening, MultiTermTest, TestCollapseQParserPlugin, 
PingRequestHandlerTest, TestSimpleTrackingShardHandler, 
HdfsBasicDistributedZkTest, IndexBasedSpellCheckerTest, ChangedSchemaMergeTest, 
RequestLoggingTest, TestRealTimeGet, LeaderElectionIntegrationTest, 
LeaderElectionTest, TestDistributedGrouping, TestFaceting, TestRecovery, 
TestStressVersions, TestRangeQuery, ConvertedLegacyTest, TestFunctionQuery]
   [junit4] Completed on J0 in 0.80s, 15 tests, 1 error <<< FAILURES!

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

Total time: 47 minutes 17 seconds
Build step 'Invoke Ant' marked build as failure
[description-setter] Description set: Java: 32bit/jdk1.9.0-ea-b54 -server 
-XX:+UseG1GC
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