lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Policeman Jenkins Server <jenk...@thetaphi.de>
Subject [JENKINS] Lucene-Solr-trunk-Linux (32bit/ibm-j9-jdk7) - Build # 5434 - Failure!
Date Wed, 01 May 2013 09:11:47 GMT
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/5434/
Java: 32bit/ibm-j9-jdk7 

No tests ran.

Build Log:
[...truncated 9263 lines...]
[junit4:junit4] Suite: org.apache.solr.update.HardAutoCommitTest
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.174; org.apache.solr.SolrTestCaseJ4; ####initCore
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.176; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/'
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.177; org.apache.solr.core.SolrResourceLoader; Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/lib/README' to classloader
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.178; org.apache.solr.core.SolrResourceLoader; Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/lib/classes/' to classloader
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.209; org.apache.solr.core.SolrConfig; Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.245; org.apache.solr.core.SolrConfig; Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.245; org.apache.solr.schema.IndexSchema; Reading Solr Schema from schema.xml
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.250; org.apache.solr.schema.IndexSchema; Schema name=test
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.569; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.574; org.apache.solr.schema.IndexSchema; default search field in schema is text
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.580; org.apache.solr.schema.IndexSchema; unique key field: id
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.586; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.589; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.593; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> WARN  - 2013-05-01 08:55:08.593; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-05-01 08:55:08.594; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.594; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> WARN  - 2013-05-01 08:55:08.595; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-05-01 08:55:08.595; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.596; org.apache.solr.core.SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.596; org.apache.solr.core.SolrResourceLoader; using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.597; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.603; org.apache.solr.core.CoreContainer; New CoreContainer -94193311
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.630; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.631; org.apache.solr.core.SolrCore; [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-HardAutoCommitTest-1367398508175/
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.631; org.apache.solr.core.JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@40ec834f
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.632; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.633; org.apache.solr.core.CachingDirectoryFactory; return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-HardAutoCommitTest-1367398508175
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.633; org.apache.solr.core.SolrCore; New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-HardAutoCommitTest-1367398508175/index/
[junit4:junit4]   1> WARN  - 2013-05-01 08:55:08.634; org.apache.solr.core.SolrCore; [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-HardAutoCommitTest-1367398508175/index' doesn't exist. Creating new index...
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.634; org.apache.solr.core.CachingDirectoryFactory; return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-HardAutoCommitTest-1367398508175/index
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.636; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4]   1> 	commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@bf16d343 lockFactory=org.apache.lucene.store.NativeFSLockFactory@d861e42b)),segFN=segments_1,generation=1}
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.636; org.apache.solr.core.SolrDeletionPolicy; newest commit generation = 1
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.637; org.apache.solr.core.SolrCore; created xml: solr.XMLResponseWriter
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.638; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.639; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.639; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.640; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.641; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.641; org.apache.solr.core.RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.642; org.apache.solr.core.RequestHandlers; created /replication: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.642; org.apache.solr.core.RequestHandlers; created standard: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.643; org.apache.solr.core.RequestHandlers; created /get: solr.RealTimeGetHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.643; org.apache.solr.core.RequestHandlers; created dismax: solr.SearchHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.644; org.apache.solr.core.RequestHandlers; created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.644; org.apache.solr.core.RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.645; org.apache.solr.core.RequestHandlers; created defaults: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.645; org.apache.solr.core.RequestHandlers; adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.646; org.apache.solr.core.RequestHandlers; created lazy: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.646; org.apache.solr.core.RequestHandlers; created /update: solr.UpdateRequestHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.647; org.apache.solr.core.RequestHandlers; created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.647; org.apache.solr.core.RequestHandlers; created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.648; org.apache.solr.core.RequestHandlers; created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.648; org.apache.solr.core.RequestHandlers; created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.649; org.apache.solr.core.RequestHandlers; created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.649; org.apache.solr.core.RequestHandlers; created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.650; org.apache.solr.core.RequestHandlers; created mltrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.650; org.apache.solr.core.RequestHandlers; created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.651; org.apache.solr.core.RequestHandlers; created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.651; org.apache.solr.core.RequestHandlers; created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.653; org.apache.solr.handler.loader.XMLLoader; xsltCacheLifetimeSeconds=60
[junit4:junit4]   1> WARN  - 2013-05-01 08:55:08.654; org.apache.solr.core.SolrCore; solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   1> WARN  - 2013-05-01 08:55:08.656; org.apache.solr.core.SolrCore; adding ShowFileRequestHandler with hidden files: [SOLRCONFIG-MANAGED-SCHEMA.XML, BAD-SCHEMA-NOT-INDEXED-BUT-TF.XML, SCHEMA-REQUIRED-FIELDS.XML, BAD-SOLRCONFIG-MANAGED-SCHEMA-NAMED-SCHEMA.XML.XML, SOLRCONFIG-MASTER1-KEEPONEBACKUP.XML, SOLRCONFIG-PROPINJECT.XML, BAD-SCHEMA-NONTEXT-ANALYZER.XML, SCHEMA-BEHAVIOR.XML, SOLRCONFIG-PROPINJECT-INDEXDEFAULT.XML, STOP-2.TXT, SCHEMA11.XML, BAD-SCHEMA-UNIQUEKEY-USES-DEFAULT.XML, SCHEMA15.XML, BAD-SOLRCONFIG-UNEXPECTED-SCHEMA-ATTRIBUTE.XML, SOLRCONFIG-NATIVELOCK.XML, SCHEMA-SIM.XML, CONDITIONAL.UPDATEPROCESSOR.JS, SCHEMA-DOCVALUES.XML, SCHEMA-ID-AND-VERSION-FIELDS-ONLY.XML, BAD-SOLRCONFIG-MISSING-SCRIPTFILE.XML, SOLRCONFIG-SCRIPT-UPDATEPROCESSOR.XML, SOLRCONFIG-REPEATER.XML, BAD-SCHEMA-DOCVALUES-NOT-REQUIRED-NO-DEFAULT.XML, SOLRCONFIG-SPELLCHECKER.XML, SOLRCONFIG-NOCACHE.XML, SCHEMA-CHARFILTERS.XML, SOLRCONFIG-SOLCOREPROPERTIES.XML, SCHEMA-EFF.XML, SOLRCONFIG_CODEC.XML, SOLRCONFIG-MUTABLE-MANAGED-SCHEMA.XML, BAD-SCHEMA-EXTERNAL-FILEFIELD.XML, HYPHENATION.DTD, TRIVIAL.UPDATEPROCESSOR1.JS, SOLRCONFIG-MERGEPOLICY.XML, SOLRCONFIG-PHRASESUGGEST.XML, SOLRCONFIG-SLAVE1.XML, SOLRCONFIG-BASIC.XML, SCHEMA-LMJELINEKMERCER.XML, BAD-MP-SOLRCONFIG.XML, JASUGGEST.TXT, BAD-SCHEMA-DUP-FIELD.XML, BAD-SCHEMA-UNIQUEKEY-MULTIVALUED.XML, SOLRCONFIG-MASTER.XML, SOLRCONFIG-HIGHLIGHT.XML, SCHEMA-TFIDF.XML, SCHEMA-REPLICATION1.XML, STOPWITHBOM.TXT, SOLRCONFIG-ELEVATE.XML, SYNONYMS.TXT, SOLRCONFIG-QUERYSENDER.XML, SOLRCONFIG-COMPONENTS-NAME.XML, SOLRCONFIG-SNIPPET-PROCESSOR.XML, WDFTYPES.TXT, BAD-SCHEMA-CURRENCY-FT-OER-NORATES.XML, SOLRCONFIG-DELPOLICY1.XML, BAD_SOLRCONFIG.XML, BAD-SCHEMA-UNSUPPORTED-DOCVALUES.XML, HUNSPELL-TEST.DIC, SCHEMA-NUMERIC.XML, SCHEMA-LUCENEMATCHVERSION.XML, KEEP-2.TXT, SCHEMA-STOP-KEEP.XML, SCHEMA-IB.XML, STOP-SNOWBALL.TXT, SCHEMA-ONE-FIELD-NO-DYNAMIC-FIELD.XML, BAD-SCHEMA-MULTIPLE-ASTERISK-COPYFIELD-DEST-SHOULD-FAIL-TEST.XML, SCHEMA-DOCVALUESMULTI.XML, SOLRCONFIG-INDEXCONFIG.XML, SOLRCONFIG-SLAVE.XML, SCHEMA-CLASS-NAME-SHORTENING-ON-SERIALIZATION.XML, BAD-SCHEMA-NOT-INDEXED-BUT-NORMS.XML, STOPWORDSWRONGENCODING.TXT, BAD-SCHEMA-MISPLACED-ASTERISK-COPYFIELD-SOURCE-SHOULD-FAIL-TEST.XML, THROW.ERROR.ON.ADD.UPDATEPROCESSOR.JS, STOPTYPES-1.TXT, SOLRCONFIG-SPELLCHECKCOMPONENT.XML, REGEX-BOOST-PROCESSOR-TEST.TXT, SOLRCONFIG-MINIMAL.XML, SCHEMA-DOCVALUESFACETING.XML, SOLRCONFIG-TLOG.XML, COMPOUNDDICTIONARY.TXT, SOLRCONFIG-POSTINGSHIGHLIGHT.XML, DA_COMPOUNDDICTIONARY.TXT, SOLRCONFIG-TERMINDEX.XML, BAD-SOLRCONFIG-INVALID-SCRIPTFILE.XML, BAD-SCHEMA-NON-GLOB-COPYFIELD-SOURCE-MATCHING-NOTHING-SHOULD-FAIL-TEST.XML, SCHEMASURROUND.XML, OPEN-EXCHANGE-RATES.JSON, BAD-SCHEMA-DUP-FIELDTYPE.XML, PHRASESUGGEST.TXT, BAD-SCHEMA-CURRENCY-FT-MULTIVALUED.XML, SOLRCONFIG-MASTER2.XML, OLD_SYNONYMS.TXT, BAD-SCHEMA-UNIQUEKEY-IS-COPYFIELD-DEST.XML, SCHEMA-NOT-REQUIRED-UNIQUE-KEY.XML, BAD-SCHEMA-CODEC-GLOBAL-VS-FT-MISMATCH.XML, SCHEMA-LMDIRICHLET.XML, BAD-SCHEMA-NOT-INDEXED-BUT-POS.XML, SCHEMA-REVERSED.XML, BAD-SCHEMA-CURRENCY-MULTIVALUED.XML, SCHEMA-FOLDING.XML, SOLRCONFIG-CACHING.XML, MAPPING-ISOLATIN1ACCENT.TXT, BAD-CURRENCY.XML, ADDFIELDS.UPDATEPROCESSOR.JS, SCHEMA-BM25.XML, SOLRCONFIG-ENABLEPLUGIN.XML, STOP-1.TXT, BAD-SCHEMA-SWEETSPOT-BOTH-TF.XML, SCHEMA-REST.XML, MISSING.FUNCTIONS.UPDATEPROCESSOR.JS, SCHEMA12.XML, SOLRCONFIG-TRANSFORMERS.XML, SCHEMA-COPYFIELD-TEST.XML, BAD-SCHEMA-DUP-DYNAMICFIELD.XML, BAD-SCHEMA-SWEETSPOT-PARTIAL-BASELINE.XML, CURRENCY.XML, DA_UTF8.XML, FUZZYSUGGEST.TXT, SCHEMA-POSTINGSHIGHLIGHT.XML, MISSLEADING.EXTENSION.UPDATEPROCESSOR.JS.TXT, SOLRCONFIG-SOLR-749.XML, STOPWORDS.TXT, BAD-SCHEMA-BOGUS-ANALYSIS-PARAMETERS.XML, HUNSPELL-TEST.AFF, SOLRCONFIG-TLOG-MANAGED-SCHEMA.XML, SOLRCONFIG_PERF.XML, SCHEMA-SWEETSPOT.XML, SOLRCONFIG-SIMPLELOCK.XML, BAD-SCHEMA-MISPLACED-ASTERISK-COPYFIELD-DEST-SHOULD-FAIL-TEST.XML, SCHEMA-TINY.XML, BAD-SCHEMA-SWEETSPOT-PARTIAL-NORMS.XML, FRENCHARTICLES.TXT, SOLRCONFIG-LAZYWRITER.XML, SOLRCONFIG-RESPONSE-LOG-COMPONENT.XML, SCHEMA-REPLICATION2.XML, SCHEMA-SNIPPET-TYPE.XML, SCHEMA-SPATIAL.XML, BAD-SCHEMA-SWEETSPOT-PARTIAL-HYPERBOLIC.XML, SCHEMA-SPELLCHECKER.XML, SOLRCONFIG-XINCLUDE.XML, XSLT, SOLRCONFIG-WARMER.XML, SOLRCONFIG-DELPOLICY2.XML, KEEP-1.TXT, TRIVIAL.UPDATEPROCESSOR0.JS, BAD-SCHEMA-CURRENCY-DYNAMIC-MULTIVALUED.XML, SCHEMA-TRIE.XML, SOLRCONFIG-TLOG-MUTABLE-MANAGED-SCHEMA.XML, SCHEMA-BINARYFIELD.XML, SCHEMA-REST-LUCENE-MATCH-VERSION.XML, BAD-SCHEMA-OMIT-TF-BUT-NOT-POS.XML, BAD-SCHEMA-CURRENCY-FT-BOGUS-CODE-IN-XML.XML, SCHEMA-MINIMAL.XML, STOPTYPES-2.TXT, SCHEMA_CODEC.XML, STEMDICT.TXT, SCHEMA-SYNONYM-TOKENIZER.XML, ELEVATE.XML, SCHEMA-COLLATE.XML, PROTWORDS.TXT, SCHEMA-XINCLUDE.XML, SCHEMA-SNIPPET-FIELD.XML, SOLRCONFIG-REQHANDLER.INCL, SCHEMA-PHRASESUGGEST.XML, SCHEMA-DFR.XML, BAD-SCHEMA-ANALYZER-CLASS-AND-NESTED.XML, SOLRCONFIG-MASTER1.XML, SOLRCONFIG-FUNCTIONQUERY.XML, BAD-SOLRCONFIG-SCHEMA-MUTABLE-BUT-NOT-MANAGED.XML, SOLRCONFIG-MASTER3.XML, SOLRCONFIG-UPDATE-PROCESSOR-CHAINS.XML, SOLRCONFIG-ALTDIRECTORY.XML, BAD-SCHEMA-SIM-GLOBAL-VS-FT-MISMATCH.XML, SOLRCONFIG-QUERYSENDER-NOQUERY.XML, BAD-SCHEMA-MULTIPLE-ASTERISK-COPYFIELD-SOURCE-SHOULD-FAIL-TEST.XML, BAD-SOLRCONFIG-BOGUS-SCRIPTENGINE-NAME.XML, BAD-SCHEMA-CURRENCY-FT-BOGUS-DEFAULT-CODE.XML, BAD-SCHEMA-BOGUS-FIELD-PARAMETERS.XML]
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.657; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@442c4594 main
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.658; org.apache.solr.update.CommitTracker; Hard AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.658; org.apache.solr.update.CommitTracker; Soft AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.659; org.apache.solr.handler.component.SpellCheckComponent; Initializing spell checkers
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.663; org.apache.solr.spelling.DirectSolrSpellChecker; init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.680; org.apache.solr.core.SolrCore; [collection1] Registered new searcher Searcher@442c4594 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.683; org.apache.solr.core.CoreContainer; registering core: collection1
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.684; org.apache.solr.SolrTestCaseJ4; ####initCore end
[junit4:junit4]   2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-HardAutoCommitTest-1367398508175
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.687; org.apache.solr.SolrTestCaseJ4; ###Starting testCommitWithin
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.692; org.apache.solr.update.DirectUpdateHandler2; [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.693; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4]   1> 	commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@bf16d343 lockFactory=org.apache.lucene.store.NativeFSLockFactory@d861e42b)),segFN=segments_1,generation=1}
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.694; org.apache.solr.core.SolrDeletionPolicy; newest commit generation = 1
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.694; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 2
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.698; org.apache.solr.core.CoreContainer; Reloading SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.698; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/'
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.699; org.apache.solr.core.SolrResourceLoader; Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/lib/README' to classloader
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.699; org.apache.solr.core.SolrResourceLoader; Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/lib/classes/' to classloader
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.727; org.apache.solr.core.SolrConfig; Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.766; org.apache.solr.core.SolrConfig; Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.767; org.apache.solr.schema.IndexSchema; Reading Solr Schema from schema.xml
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:08.773; org.apache.solr.schema.IndexSchema; Schema name=test
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:09.080; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:09.085; org.apache.solr.schema.IndexSchema; default search field in schema is text
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:09.087; org.apache.solr.schema.IndexSchema; unique key field: id
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:09.093; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:09.096; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:09.100; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> WARN  - 2013-05-01 08:55:09.100; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-05-01 08:55:09.101; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:09.101; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> WARN  - 2013-05-01 08:55:09.102; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-05-01 08:55:09.102; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:09.103; org.apache.solr.core.SolrCore; [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-HardAutoCommitTest-1367398508175/
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:09.103; org.apache.solr.core.JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@40ec834f
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:09.104; org.apache.solr.core.SolrCore; New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-HardAutoCommitTest-1367398508175/index/
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:09.104; org.apache.solr.core.SolrCore; created xml: solr.XMLResponseWriter
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:09.106; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:09.106; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:09.107; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:09.107; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:09.108; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:09.109; org.apache.solr.core.RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:09.109; org.apache.solr.core.RequestHandlers; created /replication: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:09.110; org.apache.solr.core.RequestHandlers; created standard: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:09.110; org.apache.solr.core.RequestHandlers; created /get: solr.RealTimeGetHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:09.111; org.apache.solr.core.RequestHandlers; created dismax: solr.SearchHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:09.112; org.apache.solr.core.RequestHandlers; created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:09.112; org.apache.solr.core.RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:09.113; org.apache.solr.core.RequestHandlers; created defaults: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:09.113; org.apache.solr.core.RequestHandlers; adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:09.114; org.apache.solr.core.RequestHandlers; created lazy: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:09.114; org.apache.solr.core.RequestHandlers; created /update: solr.UpdateRequestHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:09.115; org.apache.solr.core.RequestHandlers; created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:09.116; org.apache.solr.core.RequestHandlers; created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:09.116; org.apache.solr.core.RequestHandlers; created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:09.117; org.apache.solr.core.RequestHandlers; created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:09.118; org.apache.solr.core.RequestHandlers; created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:09.118; org.apache.solr.core.RequestHandlers; created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:09.119; org.apache.solr.core.RequestHandlers; created mltrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:09.120; org.apache.solr.core.RequestHandlers; created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:09.120; org.apache.solr.core.RequestHandlers; created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:09.121; org.apache.solr.core.RequestHandlers; created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:09.122; org.apache.solr.handler.loader.XMLLoader; xsltCacheLifetimeSeconds=60
[junit4:junit4]   1> WARN  - 2013-05-01 08:55:09.124; org.apache.solr.core.SolrCore; solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   1> WARN  - 2013-05-01 08:55:09.125; org.apache.solr.core.SolrCore; adding ShowFileRequestHandler with hidden files: [SOLRCONFIG-MANAGED-SCHEMA.XML, BAD-SCHEMA-NOT-INDEXED-BUT-TF.XML, SCHEMA-REQUIRED-FIELDS.XML, BAD-SOLRCONFIG-MANAGED-SCHEMA-NAMED-SCHEMA.XML.XML, SOLRCONFIG-MASTER1-KEEPONEBACKUP.XML, SOLRCONFIG-PROPINJECT.XML, BAD-SCHEMA-NONTEXT-ANALYZER.XML, SCHEMA-BEHAVIOR.XML, SOLRCONFIG-PROPINJECT-INDEXDEFAULT.XML, STOP-2.TXT, SCHEMA11.XML, BAD-SCHEMA-UNIQUEKEY-USES-DEFAULT.XML, SCHEMA15.XML, BAD-SOLRCONFIG-UNEXPECTED-SCHEMA-ATTRIBUTE.XML, SOLRCONFIG-NATIVELOCK.XML, SCHEMA-SIM.XML, CONDITIONAL.UPDATEPROCESSOR.JS, SCHEMA-DOCVALUES.XML, SCHEMA-ID-AND-VERSION-FIELDS-ONLY.XML, BAD-SOLRCONFIG-MISSING-SCRIPTFILE.XML, SOLRCONFIG-SCRIPT-UPDATEPROCESSOR.XML, SOLRCONFIG-REPEATER.XML, BAD-SCHEMA-DOCVALUES-NOT-REQUIRED-NO-DEFAULT.XML, SOLRCONFIG-SPELLCHECKER.XML, SOLRCONFIG-NOCACHE.XML, SCHEMA-CHARFILTERS.XML, SOLRCONFIG-SOLCOREPROPERTIES.XML, SCHEMA-EFF.XML, SOLRCONFIG_CODEC.XML, SOLRCONFIG-MUTABLE-MANAGED-SCHEMA.XML, BAD-SCHEMA-EXTERNAL-FILEFIELD.XML, HYPHENATION.DTD, TRIVIAL.UPDATEPROCESSOR1.JS, SOLRCONFIG-MERGEPOLICY.XML, SOLRCONFIG-PHRASESUGGEST.XML, SOLRCONFIG-SLAVE1.XML, SOLRCONFIG-BASIC.XML, SCHEMA-LMJELINEKMERCER.XML, BAD-MP-SOLRCONFIG.XML, JASUGGEST.TXT, BAD-SCHEMA-DUP-FIELD.XML, BAD-SCHEMA-UNIQUEKEY-MULTIVALUED.XML, SOLRCONFIG-MASTER.XML, SOLRCONFIG-HIGHLIGHT.XML, SCHEMA-TFIDF.XML, SCHEMA-REPLICATION1.XML, STOPWITHBOM.TXT, SOLRCONFIG-ELEVATE.XML, SYNONYMS.TXT, SOLRCONFIG-QUERYSENDER.XML, SOLRCONFIG-COMPONENTS-NAME.XML, SOLRCONFIG-SNIPPET-PROCESSOR.XML, WDFTYPES.TXT, BAD-SCHEMA-CURRENCY-FT-OER-NORATES.XML, SOLRCONFIG-DELPOLICY1.XML, BAD_SOLRCONFIG.XML, BAD-SCHEMA-UNSUPPORTED-DOCVALUES.XML, HUNSPELL-TEST.DIC, SCHEMA-NUMERIC.XML, SCHEMA-LUCENEMATCHVERSION.XML, KEEP-2.TXT, SCHEMA-STOP-KEEP.XML, SCHEMA-IB.XML, STOP-SNOWBALL.TXT, SCHEMA-ONE-FIELD-NO-DYNAMIC-FIELD.XML, BAD-SCHEMA-MULTIPLE-ASTERISK-COPYFIELD-DEST-SHOULD-FAIL-TEST.XML, SCHEMA-DOCVALUESMULTI.XML, SOLRCONFIG-INDEXCONFIG.XML, SOLRCONFIG-SLAVE.XML, SCHEMA-CLASS-NAME-SHORTENING-ON-SERIALIZATION.XML, BAD-SCHEMA-NOT-INDEXED-BUT-NORMS.XML, STOPWORDSWRONGENCODING.TXT, BAD-SCHEMA-MISPLACED-ASTERISK-COPYFIELD-SOURCE-SHOULD-FAIL-TEST.XML, THROW.ERROR.ON.ADD.UPDATEPROCESSOR.JS, STOPTYPES-1.TXT, SOLRCONFIG-SPELLCHECKCOMPONENT.XML, REGEX-BOOST-PROCESSOR-TEST.TXT, SOLRCONFIG-MINIMAL.XML, SCHEMA-DOCVALUESFACETING.XML, SOLRCONFIG-TLOG.XML, COMPOUNDDICTIONARY.TXT, SOLRCONFIG-POSTINGSHIGHLIGHT.XML, DA_COMPOUNDDICTIONARY.TXT, SOLRCONFIG-TERMINDEX.XML, BAD-SOLRCONFIG-INVALID-SCRIPTFILE.XML, BAD-SCHEMA-NON-GLOB-COPYFIELD-SOURCE-MATCHING-NOTHING-SHOULD-FAIL-TEST.XML, SCHEMASURROUND.XML, OPEN-EXCHANGE-RATES.JSON, BAD-SCHEMA-DUP-FIELDTYPE.XML, PHRASESUGGEST.TXT, BAD-SCHEMA-CURRENCY-FT-MULTIVALUED.XML, SOLRCONFIG-MASTER2.XML, OLD_SYNONYMS.TXT, BAD-SCHEMA-UNIQUEKEY-IS-COPYFIELD-DEST.XML, SCHEMA-NOT-REQUIRED-UNIQUE-KEY.XML, BAD-SCHEMA-CODEC-GLOBAL-VS-FT-MISMATCH.XML, SCHEMA-LMDIRICHLET.XML, BAD-SCHEMA-NOT-INDEXED-BUT-POS.XML, SCHEMA-REVERSED.XML, BAD-SCHEMA-CURRENCY-MULTIVALUED.XML, SCHEMA-FOLDING.XML, SOLRCONFIG-CACHING.XML, MAPPING-ISOLATIN1ACCENT.TXT, BAD-CURRENCY.XML, ADDFIELDS.UPDATEPROCESSOR.JS, SCHEMA-BM25.XML, SOLRCONFIG-ENABLEPLUGIN.XML, STOP-1.TXT, BAD-SCHEMA-SWEETSPOT-BOTH-TF.XML, SCHEMA-REST.XML, MISSING.FUNCTIONS.UPDATEPROCESSOR.JS, SCHEMA12.XML, SOLRCONFIG-TRANSFORMERS.XML, SCHEMA-COPYFIELD-TEST.XML, BAD-SCHEMA-DUP-DYNAMICFIELD.XML, BAD-SCHEMA-SWEETSPOT-PARTIAL-BASELINE.XML, CURRENCY.XML, DA_UTF8.XML, FUZZYSUGGEST.TXT, SCHEMA-POSTINGSHIGHLIGHT.XML, MISSLEADING.EXTENSION.UPDATEPROCESSOR.JS.TXT, SOLRCONFIG-SOLR-749.XML, STOPWORDS.TXT, BAD-SCHEMA-BOGUS-ANALYSIS-PARAMETERS.XML, HUNSPELL-TEST.AFF, SOLRCONFIG-TLOG-MANAGED-SCHEMA.XML, SOLRCONFIG_PERF.XML, SCHEMA-SWEETSPOT.XML, SOLRCONFIG-SIMPLELOCK.XML, BAD-SCHEMA-MISPLACED-ASTERISK-COPYFIELD-DEST-SHOULD-FAIL-TEST.XML, SCHEMA-TINY.XML, BAD-SCHEMA-SWEETSPOT-PARTIAL-NORMS.XML, FRENCHARTICLES.TXT, SOLRCONFIG-LAZYWRITER.XML, SOLRCONFIG-RESPONSE-LOG-COMPONENT.XML, SCHEMA-REPLICATION2.XML, SCHEMA-SNIPPET-TYPE.XML, SCHEMA-SPATIAL.XML, BAD-SCHEMA-SWEETSPOT-PARTIAL-HYPERBOLIC.XML, SCHEMA-SPELLCHECKER.XML, SOLRCONFIG-XINCLUDE.XML, XSLT, SOLRCONFIG-WARMER.XML, SOLRCONFIG-DELPOLICY2.XML, KEEP-1.TXT, TRIVIAL.UPDATEPROCESSOR0.JS, BAD-SCHEMA-CURRENCY-DYNAMIC-MULTIVALUED.XML, SCHEMA-TRIE.XML, SOLRCONFIG-TLOG-MUTABLE-MANAGED-SCHEMA.XML, SCHEMA-BINARYFIELD.XML, SCHEMA-REST-LUCENE-MATCH-VERSION.XML, BAD-SCHEMA-OMIT-TF-BUT-NOT-POS.XML, BAD-SCHEMA-CURRENCY-FT-BOGUS-CODE-IN-XML.XML, SCHEMA-MINIMAL.XML, STOPTYPES-2.TXT, SCHEMA_CODEC.XML, STEMDICT.TXT, SCHEMA-SYNONYM-TOKENIZER.XML, ELEVATE.XML, SCHEMA-COLLATE.XML, PROTWORDS.TXT, SCHEMA-XINCLUDE.XML, SCHEMA-SNIPPET-FIELD.XML, SOLRCONFIG-REQHANDLER.INCL, SCHEMA-PHRASESUGGEST.XML, SCHEMA-DFR.XML, BAD-SCHEMA-ANALYZER-CLASS-AND-NESTED.XML, SOLRCONFIG-MASTER1.XML, SOLRCONFIG-FUNCTIONQUERY.XML, BAD-SOLRCONFIG-SCHEMA-MUTABLE-BUT-NOT-MANAGED.XML, SOLRCONFIG-MASTER3.XML, SOLRCONFIG-UPDATE-PROCESSOR-CHAINS.XML, SOLRCONFIG-ALTDIRECTORY.XML, BAD-SCHEMA-SIM-GLOBAL-VS-FT-MISMATCH.XML, SOLRCONFIG-QUERYSENDER-NOQUERY.XML, BAD-SCHEMA-MULTIPLE-ASTERISK-COPYFIELD-SOURCE-SHOULD-FAIL-TEST.XML, BAD-SOLRCONFIG-BOGUS-SCRIPTENGINE-NAME.XML, BAD-SCHEMA-CURRENCY-FT-BOGUS-DEFAULT-CODE.XML, BAD-SCHEMA-BOGUS-FIELD-PARAMETERS.XML]
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:09.127; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@f5ee7017 main
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:09.128; org.apache.solr.update.CommitTracker; Hard AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:09.128; org.apache.solr.update.CommitTracker; Soft AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:09.129; org.apache.solr.handler.component.SpellCheckComponent; Initializing spell checkers
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:09.130; org.apache.solr.spelling.DirectSolrSpellChecker; init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:09.137; org.apache.solr.core.SolrCore; [collection1] Registered new searcher Searcher@f5ee7017 main{StandardDirectoryReader(segments_1:2:nrt)}
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:09.142; org.apache.solr.update.DefaultSolrCoreState; Creating new IndexWriter...
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:09.143; org.apache.solr.update.DefaultSolrCoreState; Waiting until IndexWriter is unused... core=collection1
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:09.143; org.apache.solr.update.DefaultSolrCoreState; Closing old IndexWriter... core=collection1
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:09.144; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4]   1> 	commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@bf16d343 lockFactory=org.apache.lucene.store.NativeFSLockFactory@d861e42b)),segFN=segments_1,generation=1}
[junit4:junit4]   1> 	commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@bf16d343 lockFactory=org.apache.lucene.store.NativeFSLockFactory@d861e42b)),segFN=segments_2,generation=2}
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:09.144; org.apache.solr.core.SolrDeletionPolicy; newest commit generation = 2
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:09.145; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4]   1> 	commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@bf16d343 lockFactory=org.apache.lucene.store.NativeFSLockFactory@d861e42b)),segFN=segments_2,generation=2}
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:09.146; org.apache.solr.core.SolrDeletionPolicy; newest commit generation = 2
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:09.146; org.apache.solr.update.DefaultSolrCoreState; New IndexWriter is ready to be used.
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:09.147; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@48cddca6 main
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:09.147; org.apache.solr.core.CoreContainer; replacing core: collection1
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:09.148; org.apache.solr.core.SolrCore; [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@43cdc4c2
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:09.148; org.apache.solr.core.SolrCore; [collection1] Registered new searcher Searcher@48cddca6 main{StandardDirectoryReader(segments_2:2:nrt)}
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:09.152; org.apache.solr.update.DirectUpdateHandler2; closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=1,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=1,cumulative_errors=0}
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:09.153; org.apache.solr.core.SolrCore; [collection1] Closing main searcher on request.
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:10.273; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] {add=[529]} 0 1118
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:12.273; org.apache.solr.update.DirectUpdateHandler2; start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:12.275; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4]   1> 	commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@bf16d343 lockFactory=org.apache.lucene.store.NativeFSLockFactory@d861e42b)),segFN=segments_2,generation=2}
[junit4:junit4]   1> 	commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@bf16d343 lockFactory=org.apache.lucene.store.NativeFSLockFactory@d861e42b)),segFN=segments_3,generation=3}
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:12.275; org.apache.solr.core.SolrDeletionPolicy; newest commit generation = 3
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:12.276; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@6b2447a5 main
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:12.277; org.apache.solr.update.DirectUpdateHandler2; end_commit_flush
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:12.278; org.apache.solr.core.SolrCore; [collection1] Registered new searcher Searcher@6b2447a5 main{StandardDirectoryReader(segments_3:4:nrt _0(5.0):C1)}
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:12.452; org.apache.solr.core.SolrCore; [collection1] webapp=null path=null params={q=id:529&start=0&qt=standard&version=2.2&rows=20} hits=1 status=0 QTime=2178 
[junit4:junit4]   1> ERROR - 2013-05-01 08:55:12.481; org.apache.solr.SolrTestCaseJ4; REQUEST FAILED: xpath=//result[@numFound=0]
[junit4:junit4]   1> 	xml response was: <?xml version="1.0" encoding="UTF-8"?>
[junit4:junit4]   1> <response>
[junit4:junit4]   1> <lst name="responseHeader"><int name="status">0</int><int name="QTime">2178</int></lst><result name="response" numFound="1" start="0"><doc><int name="id">529</int><int name="range_facet_si">529</int><arr name="range_facet_l"><long>529</long></arr><arr name="range_facet_sl"><long>529</long></arr><arr name="field_t"><str>what's inside?</str></arr><arr name="subject"><str>info</str></arr><int name="intDefault">42</int><date name="timestamp">2013-05-01T08:55:10.272Z</date><arr name="multiDefault"><str>muLti-Default</str></arr></doc></result>
[junit4:junit4]   1> </response>
[junit4:junit4]   1> 
[junit4:junit4]   1> 	request was:q=id:529&start=0&qt=standard&version=2.2&rows=20
[junit4:junit4]   1> ERROR - 2013-05-01 08:55:12.484; org.apache.solr.common.SolrException; REQUEST FAILED: q=id:529&start=0&qt=standard&version=2.2&rows=20:java.lang.RuntimeException: REQUEST FAILED: xpath=//result[@numFound=0]
[junit4:junit4]   1> 	xml response was: <?xml version="1.0" encoding="UTF-8"?>
[junit4:junit4]   1> <response>
[junit4:junit4]   1> <lst name="responseHeader"><int name="status">0</int><int name="QTime">2178</int></lst><result name="response" numFound="1" start="0"><doc><int name="id">529</int><int name="range_facet_si">529</int><arr name="range_facet_l"><long>529</long></arr><arr name="range_facet_sl"><long>529</long></arr><arr name="field_t"><str>what's inside?</str></arr><arr name="subject"><str>info</str></arr><int name="intDefault">42</int><date name="timestamp">2013-05-01T08:55:10.272Z</date><arr name="multiDefault"><str>muLti-Default</str></arr></doc></result>
[junit4:junit4]   1> </response>
[junit4:junit4]   1> 
[junit4:junit4]   1> 	request was:q=id:529&start=0&qt=standard&version=2.2&rows=20
[junit4:junit4]   1> 	at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:518)
[junit4:junit4]   1> 	at org.apache.solr.update.HardAutoCommitTest.testCommitWithin(HardAutoCommitTest.java:79)
[junit4:junit4]   1> 	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4:junit4]   1> 	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:88)
[junit4:junit4]   1> 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:55)
[junit4:junit4]   1> 	at java.lang.reflect.Method.invoke(Method.java:613)
[junit4:junit4]   1> 	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
[junit4:junit4]   1> 	at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
[junit4:junit4]   1> 	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
[junit4:junit4]   1> 	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
[junit4:junit4]   1> 	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
[junit4:junit4]   1> 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
[junit4:junit4]   1> 	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
[junit4:junit4]   1> 	at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
[junit4:junit4]   1> 	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
[junit4:junit4]   1> 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
[junit4:junit4]   1> 	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
[junit4:junit4]   1> 	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
[junit4:junit4]   1> 	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4:junit4]   1> 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4]   1> 	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
[junit4:junit4]   1> 	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
[junit4:junit4]   1> 	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
[junit4:junit4]   1> 	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
[junit4:junit4]   1> 	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
[junit4:junit4]   1> 	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
[junit4:junit4]   1> 	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
[junit4:junit4]   1> 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4]   1> 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
[junit4:junit4]   1> 	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
[junit4:junit4]   1> 	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
[junit4:junit4]   1> 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
[junit4:junit4]   1> 	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4:junit4]   1> 	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4:junit4]   1> 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4]   1> 	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
[junit4:junit4]   1> 	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4:junit4]   1> 	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
[junit4:junit4]   1> 	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
[junit4:junit4]   1> 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4]   1> 	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
[junit4:junit4]   1> 	at java.lang.Thread.run(Thread.java:780)
[junit4:junit4]   1> 
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:12.485; org.apache.solr.SolrTestCaseJ4; ###Ending testCommitWithin
[junit4:junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=HardAutoCommitTest -Dtests.method=testCommitWithin -Dtests.seed=B531F494E47AA3D3 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=hr_HR -Dtests.timezone=Pacific/Palau -Dtests.file.encoding=UTF-8
[junit4:junit4] ERROR   3.82s J1 | HardAutoCommitTest.testCommitWithin <<<
[junit4:junit4]    > Throwable #1: java.lang.RuntimeException: Exception during query
[junit4:junit4]    > 	at __randomizedtesting.SeedInfo.seed([B531F494E47AA3D3:FE39BEC67544DC6]:0)
[junit4:junit4]    > 	at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:525)
[junit4:junit4]    > 	at org.apache.solr.update.HardAutoCommitTest.testCommitWithin(HardAutoCommitTest.java:79)
[junit4:junit4]    > 	at java.lang.Thread.run(Thread.java:780)
[junit4:junit4]    > Caused by: java.lang.RuntimeException: REQUEST FAILED: xpath=//result[@numFound=0]
[junit4:junit4]    > 	xml response was: <?xml version="1.0" encoding="UTF-8"?>
[junit4:junit4]    > <response>
[junit4:junit4]    > <lst name="responseHeader"><int name="status">0</int><int name="QTime">2178</int></lst><result name="response" numFound="1" start="0"><doc><int name="id">529</int><int name="range_facet_si">529</int><arr name="range_facet_l"><long>529</long></arr><arr name="range_facet_sl"><long>529</long></arr><arr name="field_t"><str>what's inside?</str></arr><arr name="subject"><str>info</str></arr><int name="intDefault">42</int><date name="timestamp">2013-05-01T08:55:10.272Z</date><arr name="multiDefault"><str>muLti-Default</str></arr></doc></result>
[junit4:junit4]    > </response>
[junit4:junit4]    > 	request was:q=id:529&start=0&qt=standard&version=2.2&rows=20
[junit4:junit4]    > 	at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:518)
[junit4:junit4]    > 	... 41 more
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:12.508; org.apache.solr.SolrTestCaseJ4; ###deleteCore
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:12.508; org.apache.solr.core.CoreContainer; Shutting down CoreContainer instance=-94193311
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:12.509; org.apache.solr.core.SolrCore; [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@4c38c1e0
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:12.516; org.apache.solr.update.DirectUpdateHandler2; closing DirectUpdateHandler2{commits=1,autocommits=1,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=1,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:12.517; org.apache.solr.update.SolrCoreState; Closing SolrCoreState
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:12.517; org.apache.solr.update.DefaultSolrCoreState; SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:12.517; org.apache.solr.update.DefaultSolrCoreState; closing IndexWriter with IndexWriterCloser
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:12.518; org.apache.solr.core.SolrCore; [collection1] Closing main searcher on request.
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:12.518; org.apache.solr.core.CachingDirectoryFactory; Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:12.519; org.apache.solr.core.CachingDirectoryFactory; looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-HardAutoCommitTest-1367398508175/index [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-HardAutoCommitTest-1367398508175/index;done=false>>]
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:12.519; org.apache.solr.core.CachingDirectoryFactory; Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-HardAutoCommitTest-1367398508175/index
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:12.520; org.apache.solr.core.CachingDirectoryFactory; looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-HardAutoCommitTest-1367398508175 [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-HardAutoCommitTest-1367398508175;done=false>>]
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:12.520; org.apache.solr.core.CachingDirectoryFactory; Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-HardAutoCommitTest-1367398508175
[junit4:junit4]   2> NOTE: test params are: codec=Lucene41, sim=RandomSimilarityProvider(queryNorm=true,coord=crazy): {}, locale=hr_HR, timezone=Pacific/Palau
[junit4:junit4]   2> NOTE: Linux 3.2.0-40-generic x86/IBM Corporation 1.7.0 (32-bit)/cpus=8,threads=1,free=76144112,total=164233216
[junit4:junit4]   2> NOTE: All tests run in this JVM: [SolrCoreCheckLockOnStartupTest, DebugComponentTest, TestFieldTypeResource, TestJmxIntegration, TestSolrXMLSerializer, TestZkChroot, CoreContainerCoreInitFailuresTest, SignatureUpdateProcessorFactoryTest, ShardRoutingCustomTest, TestDistributedGrouping, TestReload, TestRecovery, TestCodecSupport, URLClassifyProcessorTest, TestFieldResource, MultiTermTest, DocumentAnalysisRequestHandlerTest, FieldAnalysisRequestHandlerTest, TestOmitPositions, TestMergePolicyConfig, DisMaxRequestHandlerTest, SolrCmdDistributorTest, TestPostingsSolrHighlighter, QueryResultKeyTest, OpenExchangeRatesOrgProviderTest, TestDFRSimilarityFactory, BadIndexSchemaTest, TestAnalyzedSuggestions, StandardRequestHandlerTest, SpellCheckComponentTest, OutputWriterTest, SuggesterTSTTest, TestComponentsName, DocValuesMultiTest, NumericFieldsTest, CurrencyFieldXmlFileTest, TestLuceneMatchVersion, TestSchemaNameResource, AliasIntegrationTest, TestStressReorder, TestLazyCores, TestFiltering, ConvertedLegacyTest, TestCoreDiscovery, SimplePostToolTest, PathHierarchyTokenizerFactoryTest, TestDistributedSearch, TestQueryTypes, TestBM25SimilarityFactory, SolrPluginUtilsTest, TestUtils, HardAutoCommitTest]
[junit4:junit4] Completed on J1 in 4.38s, 1 test, 1 error <<< FAILURES!

[...truncated 27 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.BasicDistributedZk2Test
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.156; org.apache.solr.BaseDistributedSearchTestCase; Setting hostContext system property: /v/
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.160; org.apache.solr.SolrTestCaseJ4; ###Starting testDistribSearch
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.161; org.apache.solr.cloud.ZkTestServer; STARTING ZK TEST SERVER
[junit4:junit4]   1> client port:0.0.0.0/0.0.0.0:0
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.162; org.apache.solr.cloud.ZkTestServer$ZKServerMain; Starting server
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.262; org.apache.solr.cloud.ZkTestServer; start zk server on port:35537
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.264; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.325; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@7d79b600 name:ZooKeeperConnection Watcher:127.0.0.1:35537 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.325; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.326; org.apache.solr.common.cloud.SolrZkClient; makePath: /solr
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.334; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.336; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@eb334d6 name:ZooKeeperConnection Watcher:127.0.0.1:35537/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.337; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.338; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/collection1
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.344; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/collection1/shards
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.348; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/control_collection
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.352; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/control_collection/shards
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.358; org.apache.solr.cloud.AbstractZkTestCase; put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.359; org.apache.solr.common.cloud.SolrZkClient; makePath: /configs/conf1/solrconfig.xml
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.367; org.apache.solr.cloud.AbstractZkTestCase; put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.369; org.apache.solr.common.cloud.SolrZkClient; makePath: /configs/conf1/schema.xml
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.375; org.apache.solr.cloud.AbstractZkTestCase; put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.376; org.apache.solr.common.cloud.SolrZkClient; makePath: /configs/conf1/stopwords.txt
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.381; org.apache.solr.cloud.AbstractZkTestCase; put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.383; org.apache.solr.common.cloud.SolrZkClient; makePath: /configs/conf1/protwords.txt
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.388; org.apache.solr.cloud.AbstractZkTestCase; put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.389; org.apache.solr.common.cloud.SolrZkClient; makePath: /configs/conf1/currency.xml
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.394; org.apache.solr.cloud.AbstractZkTestCase; put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.396; org.apache.solr.common.cloud.SolrZkClient; makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.401; org.apache.solr.cloud.AbstractZkTestCase; put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.402; org.apache.solr.common.cloud.SolrZkClient; makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.407; org.apache.solr.cloud.AbstractZkTestCase; put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.409; org.apache.solr.common.cloud.SolrZkClient; makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.414; org.apache.solr.cloud.AbstractZkTestCase; put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.415; org.apache.solr.common.cloud.SolrZkClient; makePath: /configs/conf1/synonyms.txt
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.505; org.eclipse.jetty.server.Server; jetty-8.1.10.v20130312
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.508; org.eclipse.jetty.server.AbstractConnector; Started SelectChannelConnector@127.0.0.1:55186
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.509; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init()
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.509; org.apache.solr.core.SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.510; org.apache.solr.core.SolrResourceLoader; using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1367398527421
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.510; org.apache.solr.core.CoreContainer$Initializer; looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1367398527421/solr.xml
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.511; org.apache.solr.core.CoreContainer; New CoreContainer 1115747098
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.512; org.apache.solr.core.CoreContainer; Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1367398527421/'
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.512; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1367398527421/'
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.552; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting socketTimeout to: 120000
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.553; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting urlScheme to: http://
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.554; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting connTimeout to: 15000
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.555; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.555; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting corePoolSize to: 0
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.556; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 2147483647
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.557; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.558; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.559; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.560; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.565; org.apache.solr.core.CoreContainer; Registering Log Listener
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.566; org.apache.solr.core.ZkContainer; Zookeeper client=127.0.0.1:35537/solr
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.567; org.apache.solr.cloud.ZkController; zkHost includes chroot
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.568; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.569; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@fd39cc4c name:ZooKeeperConnection Watcher:127.0.0.1:35537 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.570; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.571; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.576; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.577; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@736cee30 name:ZooKeeperConnection Watcher:127.0.0.1:35537/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.577; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.579; org.apache.solr.common.cloud.SolrZkClient; makePath: /overseer/queue
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.581; org.apache.solr.common.cloud.SolrZkClient; makePath: /overseer/collection-queue-work
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.584; org.apache.solr.common.cloud.SolrZkClient; makePath: /live_nodes
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.585; org.apache.solr.cloud.ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:55186_v
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.586; org.apache.solr.common.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:55186_v
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.589; org.apache.solr.common.cloud.SolrZkClient; makePath: /overseer_elect/election
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.597; org.apache.solr.common.cloud.SolrZkClient; makePath: /overseer_elect/leader
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.601; org.apache.solr.cloud.Overseer; Overseer (id=89613829876285443-127.0.0.1:55186_v-n_0000000000) starting
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.606; org.apache.solr.common.cloud.SolrZkClient; makePath: /overseer/queue-work
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.613; org.apache.solr.cloud.OverseerCollectionProcessor; Process current queue of collection creations
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.614; org.apache.solr.common.cloud.SolrZkClient; makePath: /clusterstate.json
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.618; org.apache.solr.common.cloud.SolrZkClient; makePath: /aliases.json
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.622; org.apache.solr.common.cloud.ZkStateReader; Updating cluster state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.627; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Starting to work on the main queue
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.632; org.apache.solr.core.CoreContainer; Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1367398527421/collection1
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.632; org.apache.solr.cloud.ZkController; Check for collection zkNode:control_collection
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.634; org.apache.solr.cloud.ZkController; Collection zkNode exists
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.634; org.apache.solr.cloud.ZkController; Load collection config from:/collections/control_collection
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.637; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1367398527421/collection1/'
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.638; org.apache.solr.core.SolrResourceLoader; Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1367398527421/collection1/lib/README' to classloader
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.639; org.apache.solr.core.SolrResourceLoader; Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1367398527421/collection1/lib/classes/' to classloader
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.683; org.apache.solr.core.SolrConfig; Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.710; org.apache.solr.core.SolrConfig; Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.713; org.apache.solr.schema.IndexSchema; Reading Solr Schema from schema.xml
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.716; org.apache.solr.schema.IndexSchema; Schema name=test
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:27.998; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:28.003; org.apache.solr.schema.IndexSchema; default search field in schema is text
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:28.005; org.apache.solr.schema.IndexSchema; unique key field: id
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:28.024; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:28.029; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:28.037; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> WARN  - 2013-05-01 08:55:28.040; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-05-01 08:55:28.040; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:28.041; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> WARN  - 2013-05-01 08:55:28.044; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-05-01 08:55:28.045; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:28.045; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:28.046; org.apache.solr.core.SolrCore; [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1367398527421/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1367398527161/control/data/
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:28.047; org.apache.solr.core.JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@40ec834f
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:28.048; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:28.049; org.apache.solr.core.CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1367398527161/control/data
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:28.050; org.apache.solr.core.SolrCore; New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1367398527161/control/data/index/
[junit4:junit4]   1> WARN  - 2013-05-01 08:55:28.050; org.apache.solr.core.SolrCore; [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1367398527161/control/data/index' doesn't exist. Creating new index...
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:28.051; org.apache.solr.core.CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1367398527161/control/data/index
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:28.054; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@8d37dce5 lockFactory=org.apache.lucene.store.NativeFSLockFactory@312cd6d8),segFN=segments_1,generation=1}
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:28.055; org.apache.solr.core.SolrDeletionPolicy; newest commit generation = 1
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:28.058; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:28.059; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:28.060; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:28.061; org.apache.solr.core.RequestHandlers; created standard: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:28.062; org.apache.solr.core.RequestHandlers; created /get: solr.RealTimeGetHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:28.063; org.apache.solr.core.RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:28.063; org.apache.solr.core.RequestHandlers; created /replication: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:28.063; org.apache.solr.core.RequestHandlers; created /update: solr.UpdateRequestHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:28.064; org.apache.solr.core.RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:28.065; org.apache.solr.handler.loader.XMLLoader; xsltCacheLifetimeSeconds=60
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:28.067; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@176c5945 main
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:28.067; org.apache.solr.update.UpdateHandler; Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1367398527161/control/data/tlog
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:28.068; org.apache.solr.update.CommitTracker; Hard AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:28.068; org.apache.solr.update.CommitTracker; Soft AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:28.072; org.apache.solr.core.SolrCore; [collection1] Registered new searcher Searcher@176c5945 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:28.073; org.apache.solr.cloud.ZkController; publishing core=collection1 state=down
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:28.074; org.apache.solr.cloud.ZkController; numShards not found on descriptor - reading it from system property
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:29.133; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:29.135; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Update state numShards=1 message={
[junit4:junit4]   1>   "shard_state":"active",
[junit4:junit4]   1>   "base_url":"http://127.0.0.1:55186/v",
[junit4:junit4]   1>   "state":"down",
[junit4:junit4]   1>   "operation":"state",
[junit4:junit4]   1>   "core_node_name":null,
[junit4:junit4]   1>   "node_name":"127.0.0.1:55186_v",
[junit4:junit4]   1>   "numShards":"1",
[junit4:junit4]   1>   "shard_range":null,
[junit4:junit4]   1>   "roles":null,
[junit4:junit4]   1>   "collection":"control_collection",
[junit4:junit4]   1>   "shard":null,
[junit4:junit4]   1>   "core":"collection1"}
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:29.135; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Create collection control_collection with numShards 1
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:29.136; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Assigning new node to shard=shard1
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:29.143; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:30.076; org.apache.solr.core.CoreContainer; registering core: collection1
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:30.077; org.apache.solr.cloud.ZkController; Register replica - core:collection1 address:http://127.0.0.1:55186/v collection:control_collection shard:shard1
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:30.079; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/control_collection/leader_elect/shard1/election
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:30.092; org.apache.solr.cloud.ShardLeaderElectionContext; Running the leader process.
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:30.097; org.apache.solr.cloud.ShardLeaderElectionContext; Enough replicas found to continue.
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:30.098; org.apache.solr.cloud.ShardLeaderElectionContext; I may be the new leader - try and sync
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:30.098; org.apache.solr.cloud.SyncStrategy; Sync replicas to http://127.0.0.1:55186/v/collection1/
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:30.099; org.apache.solr.cloud.SyncStrategy; Sync Success - now sync replicas to me
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:30.100; org.apache.solr.cloud.SyncStrategy; http://127.0.0.1:55186/v/collection1/ has no replicas
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:30.100; org.apache.solr.cloud.ShardLeaderElectionContext; I am the new leader: http://127.0.0.1:55186/v/collection1/
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:30.101; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/control_collection/leaders/shard1
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:30.650; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:30.663; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:30.714; org.apache.solr.cloud.ZkController; We are http://127.0.0.1:55186/v/collection1/ and leader is http://127.0.0.1:55186/v/collection1/
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:30.715; org.apache.solr.cloud.ZkController; No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:55186/v
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:30.715; org.apache.solr.cloud.ZkController; I am the leader, no recovery necessary
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:30.716; org.apache.solr.cloud.ZkController; publishing core=collection1 state=active
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:30.717; org.apache.solr.cloud.ZkController; numShards not found on descriptor - reading it from system property
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:30.720; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:30.722; org.apache.solr.servlet.SolrDispatchFilter; user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:30.723; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init() done
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:30.725; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:30.733; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:30.736; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:30.738; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@be2011bc name:ZooKeeperConnection Watcher:127.0.0.1:35537/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:30.739; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:30.742; org.apache.solr.common.cloud.ZkStateReader; Updating cluster state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:30.744; org.apache.solr.cloud.ChaosMonkey; monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:30.831; org.eclipse.jetty.server.Server; jetty-8.1.10.v20130312
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:30.833; org.eclipse.jetty.server.AbstractConnector; Started SelectChannelConnector@127.0.0.1:39642
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:30.834; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init()
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:30.835; org.apache.solr.core.SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:30.835; org.apache.solr.core.SolrResourceLoader; using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1367398530745
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:30.836; org.apache.solr.core.CoreContainer$Initializer; looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1367398530745/solr.xml
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:30.837; org.apache.solr.core.CoreContainer; New CoreContainer 1759913369
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:30.837; org.apache.solr.core.CoreContainer; Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1367398530745/'
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:30.838; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1367398530745/'
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:30.886; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting socketTimeout to: 120000
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:30.887; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting urlScheme to: http://
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:30.888; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting connTimeout to: 15000
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:30.888; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:30.889; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting corePoolSize to: 0
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:30.889; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 2147483647
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:30.890; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:30.890; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:30.891; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:30.892; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:30.897; org.apache.solr.core.CoreContainer; Registering Log Listener
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:30.897; org.apache.solr.core.ZkContainer; Zookeeper client=127.0.0.1:35537/solr
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:30.898; org.apache.solr.cloud.ZkController; zkHost includes chroot
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:30.899; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:30.901; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@e4225a0d name:ZooKeeperConnection Watcher:127.0.0.1:35537 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:30.901; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:30.903; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:30.909; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:30.910; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@1972003 name:ZooKeeperConnection Watcher:127.0.0.1:35537/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:30.910; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:30.914; org.apache.solr.common.cloud.ZkStateReader; Updating cluster state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:31.919; org.apache.solr.cloud.ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:39642_v
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:31.922; org.apache.solr.common.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:39642_v
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:31.926; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:31.927; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (2)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:31.927; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (2)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:31.930; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (2)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:31.937; org.apache.solr.core.CoreContainer; Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1367398530745/collection1
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:31.938; org.apache.solr.cloud.ZkController; Check for collection zkNode:collection1
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:31.939; org.apache.solr.cloud.ZkController; Collection zkNode exists
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:31.939; org.apache.solr.cloud.ZkController; Load collection config from:/collections/collection1
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:31.942; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1367398530745/collection1/'
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:31.943; org.apache.solr.core.SolrResourceLoader; Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1367398530745/collection1/lib/README' to classloader
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:31.943; org.apache.solr.core.SolrResourceLoader; Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1367398530745/collection1/lib/classes/' to classloader
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:31.975; org.apache.solr.core.SolrConfig; Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:32.002; org.apache.solr.core.SolrConfig; Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:32.004; org.apache.solr.schema.IndexSchema; Reading Solr Schema from schema.xml
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:32.007; org.apache.solr.schema.IndexSchema; Schema name=test
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:32.170; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:32.171; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Update state numShards=1 message={
[junit4:junit4]   1>   "shard_state":"active",
[junit4:junit4]   1>   "base_url":"http://127.0.0.1:55186/v",
[junit4:junit4]   1>   "state":"active",
[junit4:junit4]   1>   "operation":"state",
[junit4:junit4]   1>   "core_node_name":"127.0.0.1:55186_v_collection1",
[junit4:junit4]   1>   "node_name":"127.0.0.1:55186_v",
[junit4:junit4]   1>   "numShards":"1",
[junit4:junit4]   1>   "shard_range":null,
[junit4:junit4]   1>   "roles":null,
[junit4:junit4]   1>   "collection":"control_collection",
[junit4:junit4]   1>   "shard":"shard1",
[junit4:junit4]   1>   "core":"collection1"}
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:32.174; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:32.174; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:32.174; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:32.316; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:32.321; org.apache.solr.schema.IndexSchema; default search field in schema is text
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:32.323; org.apache.solr.schema.IndexSchema; unique key field: id
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:32.338; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:32.346; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:32.350; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> WARN  - 2013-05-01 08:55:32.351; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-05-01 08:55:32.351; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:32.352; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> WARN  - 2013-05-01 08:55:32.353; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-05-01 08:55:32.353; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:32.354; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:32.354; org.apache.solr.core.SolrCore; [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1367398530745/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1367398527161/jetty1/
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:32.354; org.apache.solr.core.JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@40ec834f
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:32.355; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:32.356; org.apache.solr.core.CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1367398527161/jetty1
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:32.356; org.apache.solr.core.SolrCore; New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1367398527161/jetty1/index/
[junit4:junit4]   1> WARN  - 2013-05-01 08:55:32.356; org.apache.solr.core.SolrCore; [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1367398527161/jetty1/index' doesn't exist. Creating new index...
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:32.357; org.apache.solr.core.CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1367398527161/jetty1/index
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:32.358; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@c62adf4c lockFactory=org.apache.lucene.store.NativeFSLockFactory@3682e174),segFN=segments_1,generation=1}
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:32.358; org.apache.solr.core.SolrDeletionPolicy; newest commit generation = 1
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:32.360; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:32.360; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:32.361; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:32.361; org.apache.solr.core.RequestHandlers; created standard: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:32.362; org.apache.solr.core.RequestHandlers; created /get: solr.RealTimeGetHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:32.362; org.apache.solr.core.RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:32.362; org.apache.solr.core.RequestHandlers; created /replication: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:32.363; org.apache.solr.core.RequestHandlers; created /update: solr.UpdateRequestHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:32.363; org.apache.solr.core.RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:32.364; org.apache.solr.handler.loader.XMLLoader; xsltCacheLifetimeSeconds=60
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:32.366; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@7d1d7587 main
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:32.367; org.apache.solr.update.UpdateHandler; Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1367398527161/jetty1/tlog
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:32.368; org.apache.solr.update.CommitTracker; Hard AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:32.368; org.apache.solr.update.CommitTracker; Soft AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:32.371; org.apache.solr.core.SolrCore; [collection1] Registered new searcher Searcher@7d1d7587 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:32.372; org.apache.solr.cloud.ZkController; publishing core=collection1 state=down
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:32.372; org.apache.solr.cloud.ZkController; numShards not found on descriptor - reading it from system property
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:33.679; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:33.680; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Update state numShards=2 message={
[junit4:junit4]   1>   "shard_state":"active",
[junit4:junit4]   1>   "base_url":"http://127.0.0.1:39642/v",
[junit4:junit4]   1>   "state":"down",
[junit4:junit4]   1>   "operation":"state",
[junit4:junit4]   1>   "core_node_name":null,
[junit4:junit4]   1>   "node_name":"127.0.0.1:39642_v",
[junit4:junit4]   1>   "numShards":"2",
[junit4:junit4]   1>   "shard_range":null,
[junit4:junit4]   1>   "roles":null,
[junit4:junit4]   1>   "collection":"collection1",
[junit4:junit4]   1>   "shard":null,
[junit4:junit4]   1>   "core":"collection1"}
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:33.681; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Create collection collection1 with numShards 2
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:33.681; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Assigning new node to shard=shard1
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:33.687; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:33.687; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:33.687; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:34.374; org.apache.solr.core.CoreContainer; registering core: collection1
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:34.375; org.apache.solr.cloud.ZkController; Register replica - core:collection1 address:http://127.0.0.1:39642/v collection:collection1 shard:shard1
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:34.377; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:34.390; org.apache.solr.cloud.ShardLeaderElectionContext; Running the leader process.
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:34.395; org.apache.solr.cloud.ShardLeaderElectionContext; Enough replicas found to continue.
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:34.395; org.apache.solr.cloud.ShardLeaderElectionContext; I may be the new leader - try and sync
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:34.396; org.apache.solr.cloud.SyncStrategy; Sync replicas to http://127.0.0.1:39642/v/collection1/
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:34.397; org.apache.solr.cloud.SyncStrategy; Sync Success - now sync replicas to me
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:34.397; org.apache.solr.cloud.SyncStrategy; http://127.0.0.1:39642/v/collection1/ has no replicas
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:34.398; org.apache.solr.cloud.ShardLeaderElectionContext; I am the new leader: http://127.0.0.1:39642/v/collection1/
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:34.399; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/collection1/leaders/shard1
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:35.193; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:35.209; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:35.209; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:35.209; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:35.214; org.apache.solr.cloud.ZkController; We are http://127.0.0.1:39642/v/collection1/ and leader is http://127.0.0.1:39642/v/collection1/
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:35.215; org.apache.solr.cloud.ZkController; No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:39642/v
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:35.215; org.apache.solr.cloud.ZkController; I am the leader, no recovery necessary
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:35.216; org.apache.solr.cloud.ZkController; publishing core=collection1 state=active
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:35.217; org.apache.solr.cloud.ZkController; numShards not found on descriptor - reading it from system property
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:35.219; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:35.222; org.apache.solr.servlet.SolrDispatchFilter; user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:35.223; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init() done
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:35.224; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:35.317; org.eclipse.jetty.server.Server; jetty-8.1.10.v20130312
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:35.319; org.eclipse.jetty.server.AbstractConnector; Started SelectChannelConnector@127.0.0.1:49765
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:35.320; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init()
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:35.321; org.apache.solr.core.SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:35.321; org.apache.solr.core.SolrResourceLoader; using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1367398535234
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:35.322; org.apache.solr.core.CoreContainer$Initializer; looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1367398535234/solr.xml
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:35.322; org.apache.solr.core.CoreContainer; New CoreContainer -1100137124
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:35.323; org.apache.solr.core.CoreContainer; Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1367398535234/'
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:35.323; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1367398535234/'
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:35.360; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting socketTimeout to: 120000
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:35.360; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting urlScheme to: http://
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:35.361; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting connTimeout to: 15000
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:35.361; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:35.362; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting corePoolSize to: 0
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:35.363; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 2147483647
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:35.363; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:35.364; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:35.364; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:35.365; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:35.370; org.apache.solr.core.CoreContainer; Registering Log Listener
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:35.371; org.apache.solr.core.ZkContainer; Zookeeper client=127.0.0.1:35537/solr
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:35.372; org.apache.solr.cloud.ZkController; zkHost includes chroot
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:35.373; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:35.375; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@8a328da5 name:ZooKeeperConnection Watcher:127.0.0.1:35537 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:35.375; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:35.378; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:35.384; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:35.385; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@ab0fce8f name:ZooKeeperConnection Watcher:127.0.0.1:35537/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:35.386; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:35.392; org.apache.solr.common.cloud.ZkStateReader; Updating cluster state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:36.397; org.apache.solr.cloud.ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49765_v
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:36.399; org.apache.solr.common.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:49765_v
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:36.402; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:36.402; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:36.402; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (3)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:36.402; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:36.403; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (3)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:36.404; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (3)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:36.404; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (3)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:36.407; org.apache.solr.core.CoreContainer; Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1367398535234/collection1
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:36.407; org.apache.solr.cloud.ZkController; Check for collection zkNode:collection1
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:36.408; org.apache.solr.cloud.ZkController; Collection zkNode exists
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:36.408; org.apache.solr.cloud.ZkController; Load collection config from:/collections/collection1
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:36.410; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1367398535234/collection1/'
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:36.410; org.apache.solr.core.SolrResourceLoader; Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1367398535234/collection1/lib/README' to classloader
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:36.411; org.apache.solr.core.SolrResourceLoader; Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1367398535234/collection1/lib/classes/' to classloader
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:36.433; org.apache.solr.core.SolrConfig; Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:36.464; org.apache.solr.core.SolrConfig; Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:36.465; org.apache.solr.schema.IndexSchema; Reading Solr Schema from schema.xml
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:36.469; org.apache.solr.schema.IndexSchema; Schema name=test
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:36.727; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:36.728; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Update state numShards=2 message={
[junit4:junit4]   1>   "shard_state":"active",
[junit4:junit4]   1>   "base_url":"http://127.0.0.1:39642/v",
[junit4:junit4]   1>   "state":"active",
[junit4:junit4]   1>   "operation":"state",
[junit4:junit4]   1>   "core_node_name":"127.0.0.1:39642_v_collection1",
[junit4:junit4]   1>   "node_name":"127.0.0.1:39642_v",
[junit4:junit4]   1>   "numShards":"2",
[junit4:junit4]   1>   "shard_range":null,
[junit4:junit4]   1>   "roles":null,
[junit4:junit4]   1>   "collection":"collection1",
[junit4:junit4]   1>   "shard":"shard1",
[junit4:junit4]   1>   "core":"collection1"}
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:36.732; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:36.732; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:36.732; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:36.732; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:36.771; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:36.776; org.apache.solr.schema.IndexSchema; default search field in schema is text
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:36.779; org.apache.solr.schema.IndexSchema; unique key field: id
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:36.797; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:36.802; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:36.806; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> WARN  - 2013-05-01 08:55:36.808; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-05-01 08:55:36.808; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:36.809; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> WARN  - 2013-05-01 08:55:36.810; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-05-01 08:55:36.811; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:36.811; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:36.811; org.apache.solr.core.SolrCore; [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1367398535234/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1367398527161/jetty2/
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:36.812; org.apache.solr.core.JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@40ec834f
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:36.813; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:36.814; org.apache.solr.core.CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1367398527161/jetty2
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:36.814; org.apache.solr.core.SolrCore; New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1367398527161/jetty2/index/
[junit4:junit4]   1> WARN  - 2013-05-01 08:55:36.814; org.apache.solr.core.SolrCore; [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1367398527161/jetty2/index' doesn't exist. Creating new index...
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:36.815; org.apache.solr.core.CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1367398527161/jetty2/index
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:36.817; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@c5fc2c87 lockFactory=org.apache.lucene.store.NativeFSLockFactory@43c0d8fa),segFN=segments_1,generation=1}
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:36.817; org.apache.solr.core.SolrDeletionPolicy; newest commit generation = 1
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:36.820; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:36.820; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:36.821; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:36.822; org.apache.solr.core.RequestHandlers; created standard: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:36.822; org.apache.solr.core.RequestHandlers; created /get: solr.RealTimeGetHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:36.823; org.apache.solr.core.RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:36.823; org.apache.solr.core.RequestHandlers; created /replication: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:36.824; org.apache.solr.core.RequestHandlers; created /update: solr.UpdateRequestHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:36.824; org.apache.solr.core.RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:36.825; org.apache.solr.handler.loader.XMLLoader; xsltCacheLifetimeSeconds=60
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:36.827; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@78976739 main
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:36.827; org.apache.solr.update.UpdateHandler; Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1367398527161/jetty2/tlog
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:36.828; org.apache.solr.update.CommitTracker; Hard AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:36.829; org.apache.solr.update.CommitTracker; Soft AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:36.835; org.apache.solr.core.SolrCore; [collection1] Registered new searcher Searcher@78976739 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:36.838; org.apache.solr.cloud.ZkController; publishing core=collection1 state=down
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:36.838; org.apache.solr.cloud.ZkController; numShards not found on descriptor - reading it from system property
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:38.238; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:38.240; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Update state numShards=2 message={
[junit4:junit4]   1>   "shard_state":"active",
[junit4:junit4]   1>   "base_url":"http://127.0.0.1:49765/v",
[junit4:junit4]   1>   "state":"down",
[junit4:junit4]   1>   "operation":"state",
[junit4:junit4]   1>   "core_node_name":null,
[junit4:junit4]   1>   "node_name":"127.0.0.1:49765_v",
[junit4:junit4]   1>   "numShards":"2",
[junit4:junit4]   1>   "shard_range":null,
[junit4:junit4]   1>   "roles":null,
[junit4:junit4]   1>   "collection":"collection1",
[junit4:junit4]   1>   "shard":null,
[junit4:junit4]   1>   "core":"collection1"}
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:38.241; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Collection already exists with numShards=2
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:38.241; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Assigning new node to shard=shard2
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:38.250; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:38.250; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:38.250; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:38.250; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:38.841; org.apache.solr.core.CoreContainer; registering core: collection1
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:38.841; org.apache.solr.cloud.ZkController; Register replica - core:collection1 address:http://127.0.0.1:49765/v collection:collection1 shard:shard2
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:38.843; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/collection1/leader_elect/shard2/election
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:38.854; org.apache.solr.cloud.ShardLeaderElectionContext; Running the leader process.
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:38.859; org.apache.solr.cloud.ShardLeaderElectionContext; Enough replicas found to continue.
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:38.860; org.apache.solr.cloud.ShardLeaderElectionContext; I may be the new leader - try and sync
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:38.860; org.apache.solr.cloud.SyncStrategy; Sync replicas to http://127.0.0.1:49765/v/collection1/
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:38.861; org.apache.solr.cloud.SyncStrategy; Sync Success - now sync replicas to me
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:38.862; org.apache.solr.cloud.SyncStrategy; http://127.0.0.1:49765/v/collection1/ has no replicas
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:38.862; org.apache.solr.cloud.ShardLeaderElectionContext; I am the new leader: http://127.0.0.1:49765/v/collection1/
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:38.863; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/collection1/leaders/shard2
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:39.757; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:39.770; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:39.770; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:39.770; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:39.770; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:39.826; org.apache.solr.cloud.ZkController; We are http://127.0.0.1:49765/v/collection1/ and leader is http://127.0.0.1:49765/v/collection1/
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:39.827; org.apache.solr.cloud.ZkController; No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:49765/v
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:39.828; org.apache.solr.cloud.ZkController; I am the leader, no recovery necessary
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:39.828; org.apache.solr.cloud.ZkController; publishing core=collection1 state=active
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:39.829; org.apache.solr.cloud.ZkController; numShards not found on descriptor - reading it from system property
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:39.831; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:39.834; org.apache.solr.servlet.SolrDispatchFilter; user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:39.835; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init() done
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:39.836; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:39.924; org.eclipse.jetty.server.Server; jetty-8.1.10.v20130312
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:39.926; org.eclipse.jetty.server.AbstractConnector; Started SelectChannelConnector@127.0.0.1:42631
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:39.927; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init()
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:39.928; org.apache.solr.core.SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:39.928; org.apache.solr.core.SolrResourceLoader; using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1367398539845
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:39.929; org.apache.solr.core.CoreContainer$Initializer; looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1367398539845/solr.xml
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:39.929; org.apache.solr.core.CoreContainer; New CoreContainer 1820047441
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:39.930; org.apache.solr.core.CoreContainer; Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1367398539845/'
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:39.931; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1367398539845/'
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:39.969; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting socketTimeout to: 120000
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:39.969; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting urlScheme to: http://
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:39.970; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting connTimeout to: 15000
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:39.971; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:39.972; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting corePoolSize to: 0
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:39.972; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 2147483647
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:39.973; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:39.973; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:39.974; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:39.975; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:39.981; org.apache.solr.core.CoreContainer; Registering Log Listener
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:39.981; org.apache.solr.core.ZkContainer; Zookeeper client=127.0.0.1:35537/solr
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:39.982; org.apache.solr.cloud.ZkController; zkHost includes chroot
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:39.983; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:39.985; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@cd7eb6f8 name:ZooKeeperConnection Watcher:127.0.0.1:35537 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:39.986; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:39.987; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:39.992; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:39.994; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@8651862f name:ZooKeeperConnection Watcher:127.0.0.1:35537/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:39.994; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:40.000; org.apache.solr.common.cloud.ZkStateReader; Updating cluster state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:41.005; org.apache.solr.cloud.ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:42631_v
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:41.007; org.apache.solr.common.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:42631_v
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:41.009; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:41.009; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:41.009; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:41.010; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (4)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:41.009; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:41.011; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (4)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:41.012; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (4)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:41.012; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (4)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:41.012; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (4)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:41.015; org.apache.solr.core.CoreContainer; Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1367398539845/collection1
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:41.015; org.apache.solr.cloud.ZkController; Check for collection zkNode:collection1
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:41.016; org.apache.solr.cloud.ZkController; Collection zkNode exists
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:41.016; org.apache.solr.cloud.ZkController; Load collection config from:/collections/collection1
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:41.018; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1367398539845/collection1/'
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:41.018; org.apache.solr.core.SolrResourceLoader; Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1367398539845/collection1/lib/README' to classloader
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:41.019; org.apache.solr.core.SolrResourceLoader; Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1367398539845/collection1/lib/classes/' to classloader
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:41.043; org.apache.solr.core.SolrConfig; Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:41.071; org.apache.solr.core.SolrConfig; Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:41.073; org.apache.solr.schema.IndexSchema; Reading Solr Schema from schema.xml
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:41.077; org.apache.solr.schema.IndexSchema; Schema name=test
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:41.282; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:41.283; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Update state numShards=2 message={
[junit4:junit4]   1>   "shard_state":"active",
[junit4:junit4]   1>   "base_url":"http://127.0.0.1:49765/v",
[junit4:junit4]   1>   "state":"active",
[junit4:junit4]   1>   "operation":"state",
[junit4:junit4]   1>   "core_node_name":"127.0.0.1:49765_v_collection1",
[junit4:junit4]   1>   "node_name":"127.0.0.1:49765_v",
[junit4:junit4]   1>   "numShards":"2",
[junit4:junit4]   1>   "shard_range":null,
[junit4:junit4]   1>   "roles":null,
[junit4:junit4]   1>   "collection":"collection1",
[junit4:junit4]   1>   "shard":"shard2",
[junit4:junit4]   1>   "core":"collection1"}
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:41.288; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:41.288; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:41.288; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:41.288; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:41.288; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:41.374; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:41.379; org.apache.solr.schema.IndexSchema; default search field in schema is text
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:41.381; org.apache.solr.schema.IndexSchema; unique key field: id
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:41.400; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:41.407; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:41.415; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> WARN  - 2013-05-01 08:55:41.417; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-05-01 08:55:41.418; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:41.419; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> WARN  - 2013-05-01 08:55:41.421; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-05-01 08:55:41.422; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:41.423; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:41.424; org.apache.solr.core.SolrCore; [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1367398539845/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1367398527161/jetty3/
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:41.424; org.apache.solr.core.JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@40ec834f
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:41.426; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:41.427; org.apache.solr.core.CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1367398527161/jetty3
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:41.428; org.apache.solr.core.SolrCore; New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1367398527161/jetty3/index/
[junit4:junit4]   1> WARN  - 2013-05-01 08:55:41.428; org.apache.solr.core.SolrCore; [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1367398527161/jetty3/index' doesn't exist. Creating new index...
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:41.429; org.apache.solr.core.CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1367398527161/jetty3/index
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:41.432; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@61609b45 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6e269e64),segFN=segments_1,generation=1}
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:41.432; org.apache.solr.core.SolrDeletionPolicy; newest commit generation = 1
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:41.435; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:41.436; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:41.437; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:41.439; org.apache.solr.core.RequestHandlers; created standard: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:41.440; org.apache.solr.core.RequestHandlers; created /get: solr.RealTimeGetHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:41.440; org.apache.solr.core.RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:41.441; org.apache.solr.core.RequestHandlers; created /replication: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:41.442; org.apache.solr.core.RequestHandlers; created /update: solr.UpdateRequestHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:41.443; org.apache.solr.core.RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:41.444; org.apache.solr.handler.loader.XMLLoader; xsltCacheLifetimeSeconds=60
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:41.446; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@7d0c5 main
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:41.446; org.apache.solr.update.UpdateHandler; Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1367398527161/jetty3/tlog
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:41.447; org.apache.solr.update.CommitTracker; Hard AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:41.447; org.apache.solr.update.CommitTracker; Soft AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:41.451; org.apache.solr.core.SolrCore; [collection1] Registered new searcher Searcher@7d0c5 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:41.454; org.apache.solr.cloud.ZkController; publishing core=collection1 state=down
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:41.455; org.apache.solr.cloud.ZkController; numShards not found on descriptor - reading it from system property
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:42.794; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:42.796; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Update state numShards=2 message={
[junit4:junit4]   1>   "shard_state":"active",
[junit4:junit4]   1>   "base_url":"http://127.0.0.1:42631/v",
[junit4:junit4]   1>   "state":"down",
[junit4:junit4]   1>   "operation":"state",
[junit4:junit4]   1>   "core_node_name":null,
[junit4:junit4]   1>   "node_name":"127.0.0.1:42631_v",
[junit4:junit4]   1>   "numShards":"2",
[junit4:junit4]   1>   "shard_range":null,
[junit4:junit4]   1>   "roles":null,
[junit4:junit4]   1>   "collection":"collection1",
[junit4:junit4]   1>   "shard":null,
[junit4:junit4]   1>   "core":"collection1"}
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:42.796; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Collection already exists with numShards=2
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:42.797; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Assigning new node to shard=shard1
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:42.805; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:42.805; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:42.805; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:42.805; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:42.805; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:43.457; org.apache.solr.core.CoreContainer; registering core: collection1
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:43.458; org.apache.solr.cloud.ZkController; Register replica - core:collection1 address:http://127.0.0.1:42631/v collection:collection1 shard:shard1
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:43.464; org.apache.solr.cloud.ZkController; We are http://127.0.0.1:42631/v/collection1/ and leader is http://127.0.0.1:39642/v/collection1/
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:43.464; org.apache.solr.cloud.ZkController; No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:42631/v
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:43.464; org.apache.solr.cloud.ZkController; Core needs to recover:collection1
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:43.465; org.apache.solr.update.DefaultSolrCoreState; Running recovery - first canceling any ongoing recovery
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:43.465; org.apache.solr.cloud.RecoveryStrategy; Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:43.465; org.apache.solr.cloud.RecoveryStrategy; ###### startupVersions=[]
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:43.465; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:43.466; org.apache.solr.cloud.ZkController; publishing core=collection1 state=recovering
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:43.466; org.apache.solr.cloud.ZkController; numShards not found on descriptor - reading it from system property
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:43.467; org.apache.solr.servlet.SolrDispatchFilter; user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:43.468; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init() done
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:43.467; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:43.468; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:43.477; org.apache.solr.handler.admin.CoreAdminHandler; Going to wait for coreNodeName: 127.0.0.1:42631_v_collection1, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:43.557; org.eclipse.jetty.server.Server; jetty-8.1.10.v20130312
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:43.559; org.eclipse.jetty.server.AbstractConnector; Started SelectChannelConnector@127.0.0.1:53864
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:43.559; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init()
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:43.560; org.apache.solr.core.SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:43.561; org.apache.solr.core.SolrResourceLoader; using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1367398543478
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:43.561; org.apache.solr.core.CoreContainer$Initializer; looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1367398543478/solr.xml
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:43.562; org.apache.solr.core.CoreContainer; New CoreContainer 1707114960
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:43.562; org.apache.solr.core.CoreContainer; Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1367398543478/'
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:43.563; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1367398543478/'
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:43.599; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting socketTimeout to: 120000
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:43.599; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting urlScheme to: http://
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:43.600; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting connTimeout to: 15000
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:43.600; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:43.601; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting corePoolSize to: 0
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:43.601; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 2147483647
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:43.602; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:43.602; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:43.603; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:43.604; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:43.609; org.apache.solr.core.CoreContainer; Registering Log Listener
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:43.610; org.apache.solr.core.ZkContainer; Zookeeper client=127.0.0.1:35537/solr
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:43.611; org.apache.solr.cloud.ZkController; zkHost includes chroot
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:43.612; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:43.614; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@b5548224 name:ZooKeeperConnection Watcher:127.0.0.1:35537 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:43.614; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:43.617; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:43.627; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:43.629; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@d81e3bb5 name:ZooKeeperConnection Watcher:127.0.0.1:35537/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:43.630; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:43.637; org.apache.solr.common.cloud.ZkStateReader; Updating cluster state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:44.314; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:44.316; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Update state numShards=2 message={
[junit4:junit4]   1>   "shard_state":"active",
[junit4:junit4]   1>   "base_url":"http://127.0.0.1:42631/v",
[junit4:junit4]   1>   "state":"recovering",
[junit4:junit4]   1>   "operation":"state",
[junit4:junit4]   1>   "core_node_name":"127.0.0.1:42631_v_collection1",
[junit4:junit4]   1>   "node_name":"127.0.0.1:42631_v",
[junit4:junit4]   1>   "numShards":"2",
[junit4:junit4]   1>   "shard_range":null,
[junit4:junit4]   1>   "roles":null,
[junit4:junit4]   1>   "collection":"collection1",
[junit4:junit4]   1>   "shard":"shard1",
[junit4:junit4]   1>   "core":"collection1"}
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:44.324; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:44.324; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:44.324; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:44.324; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:44.324; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:44.324; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:44.478; org.apache.solr.handler.admin.CoreAdminHandler; Waited coreNodeName: 127.0.0.1:42631_v_collection1, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:44.479; org.apache.solr.servlet.SolrDispatchFilter; [admin] webapp=null path=/admin/cores params={state=recovering&onlyIfLeader=true&checkLive=true&action=PREPRECOVERY&version=2&coreNodeName=127.0.0.1:42631_v_collection1&wt=javabin&nodeName=127.0.0.1:42631_v&core=collection1} status=0 QTime=1002 
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:44.643; org.apache.solr.cloud.ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53864_v
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:44.646; org.apache.solr.common.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:53864_v
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:44.650; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:44.650; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:44.650; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:44.651; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (5)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:44.652; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (5)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:44.650; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:44.653; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:44.653; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:44.655; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (5)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:44.655; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (5)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:44.653; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (5)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:44.657; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (5)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:44.662; org.apache.solr.core.CoreContainer; Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1367398543478/collection1
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:44.663; org.apache.solr.cloud.ZkController; Check for collection zkNode:collection1
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:44.664; org.apache.solr.cloud.ZkController; Collection zkNode exists
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:44.665; org.apache.solr.cloud.ZkController; Load collection config from:/collections/collection1
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:44.667; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1367398543478/collection1/'
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:44.669; org.apache.solr.core.SolrResourceLoader; Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1367398543478/collection1/lib/README' to classloader
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:44.670; org.apache.solr.core.SolrResourceLoader; Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1367398543478/collection1/lib/classes/' to classloader
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:44.709; org.apache.solr.core.SolrConfig; Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:44.737; org.apache.solr.core.SolrConfig; Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:44.738; org.apache.solr.schema.IndexSchema; Reading Solr Schema from schema.xml
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:44.742; org.apache.solr.schema.IndexSchema; Schema name=test
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:45.037; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:45.041; org.apache.solr.schema.IndexSchema; default search field in schema is text
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:45.044; org.apache.solr.schema.IndexSchema; unique key field: id
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:45.061; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:45.066; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:45.070; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> WARN  - 2013-05-01 08:55:45.072; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-05-01 08:55:45.073; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:45.073; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> WARN  - 2013-05-01 08:55:45.075; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-05-01 08:55:45.075; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:45.076; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:45.077; org.apache.solr.core.SolrCore; [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1367398543478/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1367398527161/jetty4/
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:45.077; org.apache.solr.core.JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@40ec834f
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:45.078; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:45.079; org.apache.solr.core.CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1367398527161/jetty4
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:45.080; org.apache.solr.core.SolrCore; New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1367398527161/jetty4/index/
[junit4:junit4]   1> WARN  - 2013-05-01 08:55:45.081; org.apache.solr.core.SolrCore; [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1367398527161/jetty4/index' doesn't exist. Creating new index...
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:45.081; org.apache.solr.core.CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1367398527161/jetty4/index
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:45.083; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@b02d3478 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1837ea19),segFN=segments_1,generation=1}
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:45.084; org.apache.solr.core.SolrDeletionPolicy; newest commit generation = 1
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:45.085; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:45.086; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:45.087; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:45.087; org.apache.solr.core.RequestHandlers; created standard: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:45.088; org.apache.solr.core.RequestHandlers; created /get: solr.RealTimeGetHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:45.088; org.apache.solr.core.RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:45.088; org.apache.solr.core.RequestHandlers; created /replication: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:45.089; org.apache.solr.core.RequestHandlers; created /update: solr.UpdateRequestHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:45.089; org.apache.solr.core.RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:45.090; org.apache.solr.handler.loader.XMLLoader; xsltCacheLifetimeSeconds=60
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:45.092; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@3618e728 main
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:45.092; org.apache.solr.update.UpdateHandler; Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1367398527161/jetty4/tlog
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:45.093; org.apache.solr.update.CommitTracker; Hard AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:45.093; org.apache.solr.update.CommitTracker; Soft AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:45.100; org.apache.solr.core.SolrCore; [collection1] Registered new searcher Searcher@3618e728 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:45.102; org.apache.solr.cloud.ZkController; publishing core=collection1 state=down
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:45.103; org.apache.solr.cloud.ZkController; numShards not found on descriptor - reading it from system property
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:45.831; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:45.833; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Update state numShards=2 message={
[junit4:junit4]   1>   "shard_state":"active",
[junit4:junit4]   1>   "base_url":"http://127.0.0.1:53864/v",
[junit4:junit4]   1>   "state":"down",
[junit4:junit4]   1>   "operation":"state",
[junit4:junit4]   1>   "core_node_name":null,
[junit4:junit4]   1>   "node_name":"127.0.0.1:53864_v",
[junit4:junit4]   1>   "numShards":"2",
[junit4:junit4]   1>   "shard_range":null,
[junit4:junit4]   1>   "roles":null,
[junit4:junit4]   1>   "collection":"collection1",
[junit4:junit4]   1>   "shard":null,
[junit4:junit4]   1>   "core":"collection1"}
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:45.834; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Collection already exists with numShards=2
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:45.834; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Assigning new node to shard=shard2
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:45.844; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:45.844; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:45.844; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:45.844; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:45.844; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:45.844; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.106; org.apache.solr.core.CoreContainer; registering core: collection1
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.106; org.apache.solr.cloud.ZkController; Register replica - core:collection1 address:http://127.0.0.1:53864/v collection:collection1 shard:shard2
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.112; org.apache.solr.cloud.ZkController; We are http://127.0.0.1:53864/v/collection1/ and leader is http://127.0.0.1:49765/v/collection1/
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.113; org.apache.solr.cloud.ZkController; No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:53864/v
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.113; org.apache.solr.cloud.ZkController; Core needs to recover:collection1
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.114; org.apache.solr.update.DefaultSolrCoreState; Running recovery - first canceling any ongoing recovery
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.115; org.apache.solr.cloud.RecoveryStrategy; Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.115; org.apache.solr.cloud.RecoveryStrategy; ###### startupVersions=[]
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.116; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.116; org.apache.solr.cloud.ZkController; publishing core=collection1 state=recovering
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.117; org.apache.solr.cloud.ZkController; numShards not found on descriptor - reading it from system property
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.119; org.apache.solr.servlet.SolrDispatchFilter; user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.120; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init() done
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.119; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.121; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.132; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.132; org.apache.solr.handler.admin.CoreAdminHandler; Going to wait for coreNodeName: 127.0.0.1:53864_v_collection1, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.134; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.146; org.apache.solr.core.CoreContainer; Creating SolrCore 'onenodecollectioncore' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1367398530745/onenodecollectioncore
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.147; org.apache.solr.cloud.ZkController; Check for collection zkNode:onenodecollection
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.149; org.apache.solr.cloud.ZkController; Creating collection in ZooKeeper:onenodecollection
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.151; org.apache.solr.cloud.ZkController; Looking for collection configName
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.153; org.apache.solr.cloud.ZkController; Only one config set found in zk - using it:conf1
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.154; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/onenodecollection
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.159; org.apache.solr.cloud.ZkController; Load collection config from:/collections/onenodecollection
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.161; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1367398530745/onenodecollectioncore/'
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.196; org.apache.solr.core.SolrConfig; Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.224; org.apache.solr.core.SolrConfig; Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.226; org.apache.solr.schema.IndexSchema; Reading Solr Schema from schema.xml
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.230; org.apache.solr.schema.IndexSchema; Schema name=test
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.481; org.apache.solr.cloud.RecoveryStrategy; Attempting to PeerSync from http://127.0.0.1:39642/v/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.482; org.apache.solr.update.PeerSync; PeerSync: core=collection1 url=http://127.0.0.1:42631/v START replicas=[http://127.0.0.1:39642/v/collection1/] nUpdates=100
[junit4:junit4]   1> WARN  - 2013-05-01 08:55:46.482; org.apache.solr.update.PeerSync; no frame of reference to tell of we've missed updates
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.482; org.apache.solr.cloud.RecoveryStrategy; PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.482; org.apache.solr.cloud.RecoveryStrategy; Starting Replication Recovery. core=collection1
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.483; org.apache.solr.cloud.RecoveryStrategy; Begin buffering updates. core=collection1
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.483; org.apache.solr.update.UpdateLog; Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.483; org.apache.solr.cloud.RecoveryStrategy; Attempting to replicate from http://127.0.0.1:39642/v/collection1/. core=collection1
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.484; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.487; org.apache.solr.core.SolrCore; [collection1] webapp=/v path=/get params={getVersions=100&qt=/get&distrib=false&version=2&wt=javabin} status=0 QTime=0 
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.488; org.apache.solr.update.DirectUpdateHandler2; start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.490; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@c62adf4c lockFactory=org.apache.lucene.store.NativeFSLockFactory@3682e174),segFN=segments_1,generation=1}
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.491; org.apache.solr.core.SolrDeletionPolicy; newest commit generation = 1
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.491; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@c62adf4c lockFactory=org.apache.lucene.store.NativeFSLockFactory@3682e174),segFN=segments_1,generation=1}
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@c62adf4c lockFactory=org.apache.lucene.store.NativeFSLockFactory@3682e174),segFN=segments_2,generation=2}
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.492; org.apache.solr.core.SolrDeletionPolicy; newest commit generation = 2
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.493; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@381627d2 realtime
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.493; org.apache.solr.update.DirectUpdateHandler2; end_commit_flush
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.494; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/v path=/update params={softCommit=false&commit_end_point=true&commit=true&version=2&waitSearcher=true&wt=javabin&openSearcher=false} {commit=} 0 6
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.495; org.apache.solr.handler.ReplicationHandler; Commits will be reserved for  10000
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.495; org.apache.solr.handler.SnapPuller;  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.496; org.apache.solr.handler.ReplicationHandler; Commits will be reserved for  10000
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.497; org.apache.solr.core.SolrCore; [collection1] webapp=/v path=/replication params={qt=/replication&version=2&command=indexversion&wt=javabin} status=0 QTime=1 
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.498; org.apache.solr.handler.SnapPuller; Master's generation: 2
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.498; org.apache.solr.handler.SnapPuller; Slave's generation: 1
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.498; org.apache.solr.handler.SnapPuller; Starting replication process
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.500; org.apache.solr.core.SolrCore; [collection1] webapp=/v path=/replication params={qt=/replication&version=2&generation=2&command=filelist&wt=javabin} status=0 QTime=0 
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.501; org.apache.solr.handler.SnapPuller; Number of files in latest index in master: 1
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.501; org.apache.solr.core.CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1367398527161/jetty3/index.20130501152546501
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.502; org.apache.solr.handler.SnapPuller; Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@252ae225 lockFactory=org.apache.lucene.store.NativeFSLockFactory@7df10bee) fullCopy=false
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.503; org.apache.solr.core.SolrCore; [collection1] webapp=/v path=/replication params={checksum=true&qt=/replication&generation=2&command=filecontent&file=segments_2&wt=filestream} status=0 QTime=0 
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.504; org.apache.solr.handler.SnapPuller; Total time taken for download : 0 secs
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.505; org.apache.solr.update.DefaultSolrCoreState; Creating new IndexWriter...
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.505; org.apache.solr.update.DefaultSolrCoreState; Waiting until IndexWriter is unused... core=collection1
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.506; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onInit: commits: num=2
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@61609b45 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6e269e64),segFN=segments_1,generation=1}
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@61609b45 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6e269e64),segFN=segments_2,generation=2}
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.507; org.apache.solr.core.SolrDeletionPolicy; newest commit generation = 2
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.507; org.apache.solr.update.DefaultSolrCoreState; New IndexWriter is ready to be used.
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.508; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@afba233f main
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.509; org.apache.solr.core.SolrCore; [collection1] Registered new searcher Searcher@afba233f main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.509; org.apache.solr.core.CachingDirectoryFactory; looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1367398527161/jetty3/index.20130501152546501 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1367398527161/jetty3/index.20130501152546501;done=true>>]
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.509; org.apache.solr.core.CachingDirectoryFactory; Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1367398527161/jetty3/index.20130501152546501
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.510; org.apache.solr.core.CachingDirectoryFactory; Removing directory before core close: ./org.apache.solr.cloud.BasicDistributedZk2Test-1367398527161/jetty3/index.20130501152546501
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.510; org.apache.solr.cloud.RecoveryStrategy; No replay needed. core=collection1
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.510; org.apache.solr.cloud.RecoveryStrategy; Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.510; org.apache.solr.cloud.ZkController; publishing core=collection1 state=active
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.511; org.apache.solr.cloud.ZkController; numShards not found on descriptor - reading it from system property
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.512; org.apache.solr.cloud.RecoveryStrategy; Finished recovery process. core=collection1
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.540; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.545; org.apache.solr.schema.IndexSchema; default search field in schema is text
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.548; org.apache.solr.schema.IndexSchema; unique key field: id
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.563; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.571; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.579; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> WARN  - 2013-05-01 08:55:46.582; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-05-01 08:55:46.583; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.584; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> WARN  - 2013-05-01 08:55:46.587; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-05-01 08:55:46.588; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.590; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.591; org.apache.solr.core.SolrCore; [onenodecollectioncore] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1367398530745/onenodecollectioncore/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1367398527161/onenodecollection/
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.592; org.apache.solr.core.JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@40ec834f
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.593; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.596; org.apache.solr.core.CachingDirectoryFactory; return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1367398527161/onenodecollection
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.597; org.apache.solr.core.SolrCore; New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1367398527161/onenodecollection/index/
[junit4:junit4]   1> WARN  - 2013-05-01 08:55:46.598; org.apache.solr.core.SolrCore; [onenodecollectioncore] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1367398527161/onenodecollection/index' doesn't exist. Creating new index...
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.600; org.apache.solr.core.CachingDirectoryFactory; return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1367398527161/onenodecollection/index
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.603; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@46fa2b6 lockFactory=org.apache.lucene.store.NativeFSLockFactory@dedb1068),segFN=segments_1,generation=1}
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.604; org.apache.solr.core.SolrDeletionPolicy; newest commit generation = 1
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.608; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.608; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.609; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.610; org.apache.solr.core.RequestHandlers; created standard: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.610; org.apache.solr.core.RequestHandlers; created /get: solr.RealTimeGetHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.611; org.apache.solr.core.RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.611; org.apache.solr.core.RequestHandlers; created /replication: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.612; org.apache.solr.core.RequestHandlers; created /update: solr.UpdateRequestHandler
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.613; org.apache.solr.core.RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.614; org.apache.solr.handler.loader.XMLLoader; xsltCacheLifetimeSeconds=60
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.616; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@4b33bfb7 main
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.617; org.apache.solr.update.UpdateHandler; Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1367398527161/onenodecollection/tlog
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.618; org.apache.solr.update.CommitTracker; Hard AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.619; org.apache.solr.update.CommitTracker; Soft AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.623; org.apache.solr.core.SolrCore; [onenodecollectioncore] Registered new searcher Searcher@4b33bfb7 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:46.625; org.apache.solr.cloud.ZkController; publishing core=onenodecollectioncore state=down
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:47.353; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:47.355; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Update state numShards=2 message={
[junit4:junit4]   1>   "shard_state":"active",
[junit4:junit4]   1>   "base_url":"http://127.0.0.1:53864/v",
[junit4:junit4]   1>   "state":"recovering",
[junit4:junit4]   1>   "operation":"state",
[junit4:junit4]   1>   "core_node_name":"127.0.0.1:53864_v_collection1",
[junit4:junit4]   1>   "node_name":"127.0.0.1:53864_v",
[junit4:junit4]   1>   "numShards":"2",
[junit4:junit4]   1>   "shard_range":null,
[junit4:junit4]   1>   "roles":null,
[junit4:junit4]   1>   "collection":"collection1",
[junit4:junit4]   1>   "shard":"shard2",
[junit4:junit4]   1>   "core":"collection1"}
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:47.362; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Update state numShards=2 message={
[junit4:junit4]   1>   "shard_state":"active",
[junit4:junit4]   1>   "base_url":"http://127.0.0.1:42631/v",
[junit4:junit4]   1>   "state":"active",
[junit4:junit4]   1>   "operation":"state",
[junit4:junit4]   1>   "core_node_name":"127.0.0.1:42631_v_collection1",
[junit4:junit4]   1>   "node_name":"127.0.0.1:42631_v",
[junit4:junit4]   1>   "numShards":"2",
[junit4:junit4]   1>   "shard_range":null,
[junit4:junit4]   1>   "roles":null,
[junit4:junit4]   1>   "collection":"collection1",
[junit4:junit4]   1>   "shard":"shard1",
[junit4:junit4]   1>   "core":"collection1"}
[junit4:junit4]   1> INFO  - 2013-05-01 

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

ecollectioncore/update
[junit4:junit4]    > 	at __randomizedtesting.SeedInfo.seed([B531F494E47AA3D3:34D77A8C9325C3EF]:0)
[junit4:junit4]    > 	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:385)
[junit4:junit4]    > 	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
[junit4:junit4]    > 	at org.apache.solr.client.solrj.request.AbstractUpdateRequest.process(AbstractUpdateRequest.java:117)
[junit4:junit4]    > 	at org.apache.solr.client.solrj.SolrServer.add(SolrServer.java:116)
[junit4:junit4]    > 	at org.apache.solr.client.solrj.SolrServer.add(SolrServer.java:102)
[junit4:junit4]    > 	at org.apache.solr.cloud.BasicDistributedZk2Test.testNodeWithoutCollectionForwarding(BasicDistributedZk2Test.java:197)
[junit4:junit4]    > 	at org.apache.solr.cloud.BasicDistributedZk2Test.doTest(BasicDistributedZk2Test.java:89)
[junit4:junit4]    > 	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:815)
[junit4:junit4]    > 	at java.lang.Thread.run(Thread.java:780)
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:59.560; org.apache.solr.SolrTestCaseJ4; ###deleteCore
[junit4:junit4]   2> 32408 T1202 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 4 leaked thread(s).
[junit4:junit4]   1> WARN  - 2013-05-01 08:55:59.685; org.apache.solr.common.cloud.ZkStateReader$3; ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   1> INFO  - 2013-05-01 08:55:59.685; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   1> WARN  - 2013-05-01 08:55:59.686; org.apache.solr.common.cloud.ZkStateReader$2; ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   1> WARN  - 2013-05-01 08:56:00.774; org.apache.solr.common.cloud.ZkStateReader$3; ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   1> INFO  - 2013-05-01 08:56:00.774; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
[junit4:junit4]   1> WARN  - 2013-05-01 08:56:00.774; org.apache.solr.common.cloud.ZkStateReader$2; ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> NOTE: test params are: codec=Lucene40, sim=RandomSimilarityProvider(queryNorm=false,coord=no): {}, locale=iw, timezone=Indian/Cocos
[junit4:junit4]   2> NOTE: Linux 3.2.0-40-generic x86/IBM Corporation 1.7.0 (32-bit)/cpus=8,threads=3,free=34892816,total=170983424
[junit4:junit4]   2> NOTE: All tests run in this JVM: [SolrCoreCheckLockOnStartupTest, DebugComponentTest, TestFieldTypeResource, TestJmxIntegration, TestSolrXMLSerializer, TestZkChroot, CoreContainerCoreInitFailuresTest, SignatureUpdateProcessorFactoryTest, ShardRoutingCustomTest, TestDistributedGrouping, TestReload, TestRecovery, TestCodecSupport, URLClassifyProcessorTest, TestFieldResource, MultiTermTest, DocumentAnalysisRequestHandlerTest, FieldAnalysisRequestHandlerTest, TestOmitPositions, TestMergePolicyConfig, DisMaxRequestHandlerTest, SolrCmdDistributorTest, TestPostingsSolrHighlighter, QueryResultKeyTest, OpenExchangeRatesOrgProviderTest, TestDFRSimilarityFactory, BadIndexSchemaTest, TestAnalyzedSuggestions, StandardRequestHandlerTest, SpellCheckComponentTest, OutputWriterTest, SuggesterTSTTest, TestComponentsName, DocValuesMultiTest, NumericFieldsTest, CurrencyFieldXmlFileTest, TestLuceneMatchVersion, TestSchemaNameResource, AliasIntegrationTest, TestStressReorder, TestLazyCores, TestFiltering, ConvertedLegacyTest, TestCoreDiscovery, SimplePostToolTest, PathHierarchyTokenizerFactoryTest, TestDistributedSearch, TestQueryTypes, TestBM25SimilarityFactory, SolrPluginUtilsTest, TestUtils, HardAutoCommitTest, IndexReaderFactoryTest, IndexBasedSpellCheckerTest, TestSolr4Spatial, RequiredFieldsTest, TestMultiCoreConfBootstrap, BasicDistributedZk2Test]
[junit4:junit4] Completed on J1 in 33.69s, 1 test, 1 error <<< FAILURES!

[...truncated 595 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:378: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:371: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:181: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:437: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1240: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:884: There were test failures: 293 suites, 1219 tests, 2 errors, 14 ignored (8 assumptions)

Total time: 38 minutes 49 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/ibm-j9-jdk7 
Archiving artifacts
Recording test results
ERROR: Failed to archive test reports
hudson.util.IOException2: Failed to read /var/lib/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/build/core/test/TEST-org.apache.lucene.index.Test2BTerms.xml
	at hudson.tasks.junit.TestResult.parse(TestResult.java:284)
	at hudson.tasks.junit.TestResult.parsePossiblyEmpty(TestResult.java:223)
	at hudson.tasks.junit.TestResult.parse(TestResult.java:158)
	at hudson.tasks.junit.TestResult.parse(TestResult.java:141)
	at hudson.tasks.junit.TestResult.<init>(TestResult.java:117)
	at hudson.tasks.junit.JUnitParser$ParseResultCallable.invoke(JUnitParser.java:117)
	at hudson.tasks.junit.JUnitParser$ParseResultCallable.invoke(JUnitParser.java:90)
	at hudson.FilePath.act(FilePath.java:904)
	at hudson.FilePath.act(FilePath.java:877)
	at hudson.tasks.junit.JUnitParser.parse(JUnitParser.java:87)
	at hudson.tasks.junit.JUnitResultArchiver.parse(JUnitResultArchiver.java:121)
	at hudson.tasks.junit.JUnitResultArchiver.perform(JUnitResultArchiver.java:133)
	at hudson.tasks.BuildStepMonitor$1.perform(BuildStepMonitor.java:19)
	at hudson.model.AbstractBuild$AbstractBuildExecution.perform(AbstractBuild.java:804)
	at hudson.model.AbstractBuild$AbstractBuildExecution.performAllBuildSteps(AbstractBuild.java:776)
	at hudson.model.Build$BuildExecution.post2(Build.java:183)
	at hudson.model.AbstractBuild$AbstractBuildExecution.post(AbstractBuild.java:726)
	at hudson.model.Run.execute(Run.java:1600)
	at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:46)
	at hudson.model.ResourceController.execute(ResourceController.java:88)
	at hudson.model.Executor.run(Executor.java:237)
Caused by: org.dom4j.DocumentException: Error on line 3 of document file:///var/lib/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/build/core/test/TEST-org.apache.lucene.index.Test2BTerms.xml : Element type "testsuite" must be followed by either attribute specifications, ">" or "/>". Nested exception: Element type "testsuite" must be followed by either attribute specifications, ">" or "/>".
	at org.dom4j.io.SAXReader.read(SAXReader.java:482)
	at org.dom4j.io.SAXReader.read(SAXReader.java:264)
	at hudson.tasks.junit.SuiteResult.parse(SuiteResult.java:129)
	at hudson.tasks.junit.TestResult.parse(TestResult.java:267)
	... 20 more
Caused by: org.xml.sax.SAXParseException; systemId: file:///var/lib/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/build/core/test/TEST-org.apache.lucene.index.Test2BTerms.xml; lineNumber: 3; columnNumber: 4; Element type "testsuite" must be followed by either attribute specifications, ">" or "/>".
	at com.sun.org.apache.xerces.internal.util.ErrorHandlerWrapper.createSAXParseException(ErrorHandlerWrapper.java:198)
	at com.sun.org.apache.xerces.internal.util.ErrorHandlerWrapper.fatalError(ErrorHandlerWrapper.java:177)
	at com.sun.org.apache.xerces.internal.impl.XMLErrorReporter.reportError(XMLErrorReporter.java:441)
	at com.sun.org.apache.xerces.internal.impl.XMLErrorReporter.reportError(XMLErrorReporter.java:368)
	at com.sun.org.apache.xerces.internal.impl.XMLScanner.reportFatalError(XMLScanner.java:1388)
	at com.sun.org.apache.xerces.internal.impl.XMLDocumentFragmentScannerImpl.seekCloseOfStartTag(XMLDocumentFragmentScannerImpl.java:1355)
	at com.sun.org.apache.xerces.internal.impl.XMLNSDocumentScannerImpl.scanStartElement(XMLNSDocumentScannerImpl.java:261)
	at com.sun.org.apache.xerces.internal.impl.XMLNSDocumentScannerImpl$NSContentDriver.scanRootElementHook(XMLNSDocumentScannerImpl.java:602)
	at com.sun.org.apache.xerces.internal.impl.XMLDocumentFragmentScannerImpl$FragmentContentDriver.next(XMLDocumentFragmentScannerImpl.java:3065)
	at com.sun.org.apache.xerces.internal.impl.XMLDocumentScannerImpl$PrologDriver.next(XMLDocumentScannerImpl.java:881)
	at com.sun.org.apache.xerces.internal.impl.XMLDocumentScannerImpl.next(XMLDocumentScannerImpl.java:607)
	at com.sun.org.apache.xerces.internal.impl.XMLNSDocumentScannerImpl.next(XMLNSDocumentScannerImpl.java:116)
	at com.sun.org.apache.xerces.internal.impl.XMLDocumentFragmentScannerImpl.scanDocument(XMLDocumentFragmentScannerImpl.java:489)
	at com.sun.org.apache.xerces.internal.parsers.XML11Configuration.parse(XML11Configuration.java:835)
	at com.sun.org.apache.xerces.internal.parsers.XML11Configuration.parse(XML11Configuration.java:764)
	at com.sun.org.apache.xerces.internal.parsers.XMLParser.parse(XMLParser.java:123)
	at com.sun.org.apache.xerces.internal.parsers.AbstractSAXParser.parse(AbstractSAXParser.java:1210)
	at com.sun.org.apache.xerces.internal.jaxp.SAXParserImpl$JAXPSAXParser.parse(SAXParserImpl.java:568)
	at org.dom4j.io.SAXReader.read(SAXReader.java:465)
	... 23 more
Email was triggered for: Failure
Sending email for trigger: Failure



Mime
View raw message