Run log

run.log

/System/Library/Java/JavaVirtualMachines/1.6.0.jdk/Contents/Home/bin/java -Didea.launcher.port=7534 -Didea.launcher.bin.path=/Applications/Cardea-IU-130.1365.app/bin -Dfile.encoding=UTF-8 -classpath /System/Library/Java/JavaVirtualMachines/1.6.0.jdk/Contents/Home/lib/deploy.jar:/System/Library/Java/JavaVirtualMachines/1.6.0.jdk/Contents/Home/lib/dt.jar:/System/Library/Java/JavaVirtualMachines/1.6.0.jdk/Contents/Home/lib/javaws.jar:/System/Library/Java/JavaVirtualMachines/1.6.0.jdk/Contents/Home/lib/jce.jar:/System/Library/Java/JavaVirtualMachines/1.6.0.jdk/Contents/Home/lib/jconsole.jar:/System/Library/Java/JavaVirtualMachines/1.6.0.jdk/Contents/Home/lib/management-agent.jar:/System/Library/Java/JavaVirtualMachines/1.6.0.jdk/Contents/Home/lib/plugin.jar:/System/Library/Java/JavaVirtualMachines/1.6.0.jdk/Contents/Home/lib/sa-jdi.jar:/System/Library/Java/JavaVirtualMachines/1.6.0.jdk/Contents/Classes/charsets.jar:/System/Library/Java/JavaVirtualMachines/1.6.0.jdk/Contents/Classes/classes.jar:/System/Library/Java/JavaVirtualMachines/1.6.0.jdk/Contents/Classes/jsse.jar:/System/Library/Java/JavaVirtualMachines/1.6.0.jdk/Contents/Classes/ui.jar:/System/Library/Java/JavaVirtualMachines/1.6.0.jdk/Contents/Home/lib/ext/apple_provider.jar:/System/Library/Java/JavaVirtualMachines/1.6.0.jdk/Contents/Home/lib/ext/dnsns.jar:/System/Library/Java/JavaVirtualMachines/1.6.0.jdk/Contents/Home/lib/ext/localedata.jar:/System/Library/Java/JavaVirtualMachines/1.6.0.jdk/Contents/Home/lib/ext/sunjce_provider.jar:/System/Library/Java/JavaVirtualMachines/1.6.0.jdk/Contents/Home/lib/ext/sunpkcs11.jar:/Users/delip/r/dataops/target/classes:/Users/delip/r/dataops/lib/jars/pig-0.11.1.jar:/Users/delip/r/dataops/lib/jars/guava-14.0.1.jar:/Users/delip/r/dataops/lib/jars/elephant-bird-pig-4.1.jar:/Users/delip/r/dataops/lib/jars/datafu-0.0.11-SNAPSHOT.jar:/Users/delip/r/dataops/lib/jars/elephant-bird-core-4.1.jar:/Users/delip/r/dataops/lib/jars/elephant-bird-lucene-4.1.jar:/Users/delip/r/dataops/lib/jars/elephant-bird-pig-lucene-4.1.jar:/Users/delip/.m2/repository/org/apache/solr/solr-core/4.4.0/solr-core-4.4.0.jar:/Users/delip/.m2/repository/org/apache/solr/solr-solrj/4.4.0/solr-solrj-4.4.0.jar:/Users/delip/.m2/repository/org/apache/zookeeper/zookeeper/3.4.5/zookeeper-3.4.5.jar:/Users/delip/.m2/repository/org/slf4j/slf4j-api/1.6.4/slf4j-api-1.6.4.jar:/Users/delip/.m2/repository/commons-io/commons-io/2.1/commons-io-2.1.jar:/Users/delip/.m2/repository/org/noggit/noggit/0.5/noggit-0.5.jar:/Users/delip/.m2/repository/org/apache/httpcomponents/httpclient/4.2.3/httpclient-4.2.3.jar:/Users/delip/.m2/repository/org/apache/httpcomponents/httpcore/4.3/httpcore-4.3.jar:/Users/delip/.m2/repository/commons-codec/commons-codec/1.7/commons-codec-1.7.jar:/Users/delip/.m2/repository/org/apache/httpcomponents/httpmime/4.2.3/httpmime-4.2.3.jar:/Users/delip/.m2/repository/org/codehaus/woodstox/wstx-asl/3.2.7/wstx-asl-3.2.7.jar:/Users/delip/.m2/repository/org/apache/lucene/lucene-core/4.4.0/lucene-core-4.4.0.jar:/Users/delip/.m2/repository/org/apache/lucene/lucene-codecs/4.4.0/lucene-codecs-4.4.0.jar:/Users/delip/.m2/repository/org/apache/lucene/lucene-analyzers-common/4.4.0/lucene-analyzers-common-4.4.0.jar:/Users/delip/.m2/repository/org/apache/lucene/lucene-analyzers-kuromoji/4.4.0/lucene-analyzers-kuromoji-4.4.0.jar:/Users/delip/.m2/repository/org/apache/lucene/lucene-analyzers-phonetic/4.4.0/lucene-analyzers-phonetic-4.4.0.jar:/Users/delip/.m2/repository/org/apache/lucene/lucene-highlighter/4.4.0/lucene-highlighter-4.4.0.jar:/Users/delip/.m2/repository/org/apache/lucene/lucene-memory/4.4.0/lucene-memory-4.4.0.jar:/Users/delip/.m2/repository/org/apache/lucene/lucene-queries/4.4.0/lucene-queries-4.4.0.jar:/Users/delip/.m2/repository/org/apache/lucene/lucene-misc/4.4.0/lucene-misc-4.4.0.jar:/Users/delip/.m2/repository/org/apache/lucene/lucene-queryparser/4.4.0/lucene-queryparser-4.4.0.jar:/Users/delip/.m2/repository/org/apache/lucene/lucene-spatial/4.4.0/lucene-spatial-4.4.0.jar:/Users/delip/.m2/repository/com/spatial4j/spatial4j/0.3/spatial4j-0.3.jar:/Users/delip/.m2/repository/org/apache/lucene/lucene-suggest/4.4.0/lucene-suggest-4.4.0.jar:/Users/delip/.m2/repository/org/apache/lucene/lucene-grouping/4.4.0/lucene-grouping-4.4.0.jar:/Users/delip/.m2/repository/com/googlecode/concurrentlinkedhashmap/concurrentlinkedhashmap-lru/1.2/concurrentlinkedhashmap-lru-1.2.jar:/Users/delip/.m2/repository/commons-cli/commons-cli/1.2/commons-cli-1.2.jar:/Users/delip/.m2/repository/commons-fileupload/commons-fileupload/1.2.1/commons-fileupload-1.2.1.jar:/Users/delip/.m2/repository/joda-time/joda-time/2.2/joda-time-2.2.jar:/Users/delip/.m2/repository/org/apache/hadoop/hadoop-annotations/2.0.5-alpha/hadoop-annotations-2.0.5-alpha.jar:/Users/delip/.m2/repository/org/apache/hadoop/hadoop-auth/2.0.5-alpha/hadoop-auth-2.0.5-alpha.jar:/Users/delip/.m2/repository/log4j/log4j/1.2.17/log4j-1.2.17.jar:/Users/delip/.m2/repository/org/slf4j/slf4j-log4j12/1.6.1/slf4j-log4j12-1.6.1.jar:/Users/delip/.m2/repository/org/apache/hadoop/hadoop-common/2.0.5-alpha/hadoop-common-2.0.5-alpha.jar:/Users/delip/.m2/repository/com/google/guava/guava/14.0.1/guava-14.0.1.jar:/Users/delip/.m2/repository/org/mortbay/jetty/jetty/6.1.26/jetty-6.1.26.jar:/Users/delip/.m2/repository/org/mortbay/jetty/jetty-util/6.1.26/jetty-util-6.1.26.jar:/Users/delip/.m2/repository/javax/servlet/jsp/jsp-api/2.1/jsp-api-2.1.jar:/Users/delip/.m2/repository/commons-lang/commons-lang/2.6/commons-lang-2.6.jar:/Users/delip/.m2/repository/commons-configuration/commons-configuration/1.6/commons-configuration-1.6.jar:/Users/delip/.m2/repository/commons-collections/commons-collections/3.2.1/commons-collections-3.2.1.jar:/Users/delip/.m2/repository/com/google/protobuf/protobuf-java/2.4.1/protobuf-java-2.4.1.jar:/Users/delip/.m2/repository/org/apache/hadoop/hadoop-hdfs/2.0.5-alpha/hadoop-hdfs-2.0.5-alpha.jar:/Users/delip/.m2/repository/org/restlet/jee/org.restlet/2.1.1/org.restlet-2.1.1.jar:/Users/delip/.m2/repository/org/restlet/jee/org.restlet.ext.servlet/2.1.1/org.restlet.ext.servlet-2.1.1.jar:/Users/delip/.m2/repository/javax/servlet/servlet-api/2.5/servlet-api-2.5.jar:/Users/delip/.m2/repository/com/twitter/elephantbird/elephant-bird-core/4.1/elephant-bird-core-4.1.jar:/Users/delip/.m2/repository/com/twitter/elephantbird/elephant-bird-hadoop-compat/4.1/elephant-bird-hadoop-compat-4.1.jar:/Users/delip/.m2/repository/org/apache/thrift/libthrift/0.9.0/libthrift-0.9.0.jar:/Users/delip/.m2/repository/com/googlecode/json-simple/json-simple/1.1/json-simple-1.1.jar:/Users/delip/.m2/repository/com/hadoop/gplcompression/hadoop-lzo/0.4.16/hadoop-lzo-0.4.16.jar:/Users/delip/.m2/repository/com/twitter/elephantbird/elephant-bird-pig/4.1/elephant-bird-pig-4.1.jar:/Users/delip/.m2/repository/org/mockito/mockito-all/1.9.5/mockito-all-1.9.5.jar:/Users/delip/.m2/repository/org/apache/pig/pig/0.11.1/pig-0.11.1.jar:/Users/delip/.m2/repository/xmlenc/xmlenc/0.52/xmlenc-0.52.jar:/Users/delip/.m2/repository/commons-httpclient/commons-httpclient/3.1/commons-httpclient-3.1.jar:/Users/delip/.m2/repository/commons-logging/commons-logging/1.0.4/commons-logging-1.0.4.jar:/Users/delip/.m2/repository/commons-net/commons-net/1.4.1/commons-net-1.4.1.jar:/Users/delip/.m2/repository/oro/oro/2.0.8/oro-2.0.8.jar:/Users/delip/.m2/repository/org/mortbay/jetty/servlet-api/2.5-20081211/servlet-api-2.5-20081211.jar:/Users/delip/.m2/repository/tomcat/jasper-runtime/5.5.12/jasper-runtime-5.5.12.jar:/Users/delip/.m2/repository/tomcat/jasper-compiler/5.5.12/jasper-compiler-5.5.12.jar:/Users/delip/.m2/repository/org/mortbay/jetty/jsp-api-2.1/6.1.14/jsp-api-2.1-6.1.14.jar:/Users/delip/.m2/repository/org/mortbay/jetty/servlet-api-2.5/6.1.14/servlet-api-2.5-6.1.14.jar:/Users/delip/.m2/repository/org/mortbay/jetty/jsp-2.1/6.1.14/jsp-2.1-6.1.14.jar:/Users/delip/.m2/repository/org/eclipse/jdt/core/3.1.1/core-3.1.1.jar:/Users/delip/.m2/repository/ant/ant/1.6.5/ant-1.6.5.jar:/Users/delip/.m2/repository/commons-el/commons-el/1.0/commons-el-1.0.jar:/Users/delip/.m2/repository/net/java/dev/jets3t/jets3t/0.7.1/jets3t-0.7.1.jar:/Users/delip/.m2/repository/net/sf/kosmosfs/kfs/0.3/kfs-0.3.jar:/Users/delip/.m2/repository/hsqldb/hsqldb/1.8.0.10/hsqldb-1.8.0.10.jar:/Users/delip/.m2/repository/org/apache/avro/avro/1.5.3/avro-1.5.3.jar:/Users/delip/.m2/repository/org/codehaus/jackson/jackson-mapper-asl/1.0.1/jackson-mapper-asl-1.0.1.jar:/Users/delip/.m2/repository/org/codehaus/jackson/jackson-core-asl/1.0.1/jackson-core-asl-1.0.1.jar:/Users/delip/.m2/repository/com/thoughtworks/paranamer/paranamer/2.3/paranamer-2.3.jar:/Users/delip/.m2/repository/org/xerial/snappy/snappy-java/1.0.3.2/snappy-java-1.0.3.2.jar:/Users/delip/.m2/repository/org/apache/hadoop/hadoop-core/1.0.3/hadoop-core-1.0.3.jar:/Users/delip/.m2/repository/org/apache/commons/commons-math/2.1/commons-math-2.1.jar:/Users/delip/.m2/repository/commons-digester/commons-digester/1.8/commons-digester-1.8.jar:/Users/delip/.m2/repository/commons-beanutils/commons-beanutils/1.7.0/commons-beanutils-1.7.0.jar:/Users/delip/.m2/repository/commons-beanutils/commons-beanutils-core/1.8.0/commons-beanutils-core-1.8.0.jar:/Users/delip/.m2/repository/org/jsoup/jsoup/1.7.2/jsoup-1.7.2.jar:/Applications/Cardea-IU-130.1365.app/lib/idea_rt.jar com.intellij.rt.execution.application.AppMain com.ravellaw.EmbeddedSolrExample
SLF4J: Class path contains multiple SLF4J bindings.
SLF4J: Found binding in [jar:file:/Users/delip/r/dataops/lib/jars/pig-0.11.1.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: Found binding in [jar:file:/Users/delip/.m2/repository/org/slf4j/slf4j-log4j12/1.6.1/slf4j-log4j12-1.6.1.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: See http://www.slf4j.org/codes.html#multiple_bindings for an explanation.
13/08/12 12:41:09 INFO core.SolrResourceLoader: new SolrResourceLoader for directory: 'sandbox/solr/'
13/08/12 12:41:09 INFO core.ConfigSolr: Loading container configuration from /Users/delip/r/dataops/sandbox/solr/solr.xml
13/08/12 12:41:09 INFO core.SolrCoreDiscoverer: Looking for cores in /Users/delip/r/dataops/sandbox/solr
13/08/12 12:41:09 INFO core.SolrCoreDiscoverer: Looking for cores in /Users/delip/r/dataops/sandbox/solr/bin
13/08/12 12:41:09 INFO core.SolrCoreDiscoverer: Discovered properties file /Users/delip/r/dataops/sandbox/solr/shakespeare/core.properties, adding to cores
13/08/12 12:41:09 INFO core.CoreContainer: New CoreContainer 1748234462
13/08/12 12:41:09 INFO core.CoreContainer: Loading cores into CoreContainer [instanceDir=sandbox/solr/]
13/08/12 12:41:09 INFO component.HttpShardHandlerFactory: Setting socketTimeout to: 0
13/08/12 12:41:09 INFO component.HttpShardHandlerFactory: Setting urlScheme to: http://
13/08/12 12:41:09 INFO component.HttpShardHandlerFactory: Setting connTimeout to: 0
13/08/12 12:41:09 INFO component.HttpShardHandlerFactory: Setting maxConnectionsPerHost to: 20
13/08/12 12:41:09 INFO component.HttpShardHandlerFactory: Setting corePoolSize to: 0
13/08/12 12:41:09 INFO component.HttpShardHandlerFactory: Setting maximumPoolSize to: 2147483647
13/08/12 12:41:09 INFO component.HttpShardHandlerFactory: Setting maxThreadIdleTime to: 5
13/08/12 12:41:09 INFO component.HttpShardHandlerFactory: Setting sizeOfQueue to: -1
13/08/12 12:41:09 INFO component.HttpShardHandlerFactory: Setting fairnessPolicy to: false
13/08/12 12:41:09 INFO impl.HttpClientUtil: Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
13/08/12 12:41:09 INFO logging.LogWatcher: Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
13/08/12 12:41:09 INFO core.CoreContainer: Creating SolrCore 'shakespeare' using instanceDir: /Users/delip/r/dataops/sandbox/solr/shakespeare
13/08/12 12:41:09 INFO core.SolrResourceLoader: new SolrResourceLoader for directory: '/Users/delip/r/dataops/sandbox/solr/shakespeare/'
13/08/12 12:41:09 INFO core.SolrConfig: Adding specified lib dirs to ClassLoader
13/08/12 12:41:09 WARN core.SolrResourceLoader: Can't find (or read) directory to add to classloader: ../../../contrib/extraction/lib (resolved as: /Users/delip/r/dataops/sandbox/solr/shakespeare/../../../contrib/extraction/lib).
13/08/12 12:41:09 WARN core.SolrResourceLoader: Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /Users/delip/r/dataops/sandbox/solr/shakespeare/../../../dist).
13/08/12 12:41:09 WARN core.SolrResourceLoader: Can't find (or read) directory to add to classloader: ../../../contrib/clustering/lib/ (resolved as: /Users/delip/r/dataops/sandbox/solr/shakespeare/../../../contrib/clustering/lib).
13/08/12 12:41:09 WARN core.SolrResourceLoader: Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /Users/delip/r/dataops/sandbox/solr/shakespeare/../../../dist).
13/08/12 12:41:09 WARN core.SolrResourceLoader: Can't find (or read) directory to add to classloader: ../../../contrib/langid/lib/ (resolved as: /Users/delip/r/dataops/sandbox/solr/shakespeare/../../../contrib/langid/lib).
13/08/12 12:41:09 WARN core.SolrResourceLoader: Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /Users/delip/r/dataops/sandbox/solr/shakespeare/../../../dist).
13/08/12 12:41:09 WARN core.SolrResourceLoader: Can't find (or read) directory to add to classloader: ../../../contrib/velocity/lib (resolved as: /Users/delip/r/dataops/sandbox/solr/shakespeare/../../../contrib/velocity/lib).
13/08/12 12:41:09 WARN core.SolrResourceLoader: Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /Users/delip/r/dataops/sandbox/solr/shakespeare/../../../dist).
13/08/12 12:41:10 INFO update.SolrIndexConfig: IndexWriter infoStream solr logging is enabled
13/08/12 12:41:10 INFO core.SolrConfig: Using Lucene MatchVersion: LUCENE_44
13/08/12 12:41:10 INFO core.Config: Loaded SolrConfig: solrconfig.xml
13/08/12 12:41:10 INFO schema.IndexSchema: Reading Solr Schema from schema.xml
13/08/12 12:41:10 INFO schema.IndexSchema: [shakespeare] Schema name=example
13/08/12 12:41:10 INFO schema.IndexSchema: unique key field: id
13/08/12 12:41:10 INFO schema.FileExchangeRateProvider: Reloading exchange rates from file currency.xml
13/08/12 12:41:10 INFO schema.FileExchangeRateProvider: Reloading exchange rates from file currency.xml
13/08/12 12:41:11 INFO core.SolrCore: solr.NRTCachingDirectoryFactory
13/08/12 12:41:11 INFO core.SolrCore: [shakespeare] Opening new SolrCore at /Users/delip/r/dataops/sandbox/solr/shakespeare/, dataDir=/Users/delip/r/dataops/sandbox/solr/shakespeare/data/
13/08/12 12:41:11 INFO core.JmxMonitoredMap: No JMX servers found, not exposing Solr information with JMX.
13/08/12 12:41:11 INFO core.SolrCore: [shakespeare] Added SolrEventListener for newSearcher: org.apache.solr.core.QuerySenderListener{queries=[]}
13/08/12 12:41:11 INFO core.SolrCore: [shakespeare] Added SolrEventListener for firstSearcher: org.apache.solr.core.QuerySenderListener{queries=[{q=static firstSearcher warming in solrconfig.xml}]}
13/08/12 12:41:11 INFO core.CachingDirectoryFactory: return new directory for /Users/delip/r/dataops/sandbox/solr/shakespeare/data
13/08/12 12:41:11 INFO core.SolrCore: New index directory detected: old=null new=/Users/delip/r/dataops/sandbox/solr/shakespeare/data/index/
13/08/12 12:41:11 WARN core.SolrCore: [shakespeare] Solr index directory '/Users/delip/r/dataops/sandbox/solr/shakespeare/data/index' doesn't exist. Creating new index...
13/08/12 12:41:11 INFO core.CachingDirectoryFactory: return new directory for /Users/delip/r/dataops/sandbox/solr/shakespeare/data/index
13/08/12 12:41:11 INFO update.LoggingInfoStream: [IFD][coreLoadExecutor-3-thread-1]: init: current segments file is "null"; deletionPolicy=org.apache.solr.core.IndexDeletionPolicyWrapper@3db158db
13/08/12 12:41:11 INFO update.LoggingInfoStream: [IFD][coreLoadExecutor-3-thread-1]: now checkpoint "" [0 segments ; isCommit = false]
13/08/12 12:41:11 INFO update.LoggingInfoStream: [IFD][coreLoadExecutor-3-thread-1]: 0 msec to checkpoint
13/08/12 12:41:11 INFO update.LoggingInfoStream: [IW][coreLoadExecutor-3-thread-1]: init: create=true
13/08/12 12:41:11 INFO update.LoggingInfoStream: [IW][coreLoadExecutor-3-thread-1]: 
dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/Users/delip/r/dataops/sandbox/solr/shakespeare/data/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@49f10a67; maxCacheMB=48.0 maxMergeSizeMB=4.0)
index=
version=4.4.0 1504776 - sarowe - 2013-07-19 02:53:42
matchVersion=LUCENE_44
analyzer=null
ramBufferSizeMB=100.0
maxBufferedDocs=-1
maxBufferedDeleteTerms=-1
mergedSegmentWarmer=null
readerTermsIndexDivisor=1
termIndexInterval=32
delPolicy=org.apache.solr.core.IndexDeletionPolicyWrapper
commit=null
openMode=CREATE
similarity=org.apache.lucene.search.similarities.DefaultSimilarity
mergeScheduler=ConcurrentMergeScheduler: maxThreadCount=1, maxMergeCount=2, mergeThreadPriority=-1
default WRITE_LOCK_TIMEOUT=1000
writeLockTimeout=1000
codec=Lucene42
infoStream=org.apache.solr.update.LoggingInfoStream
mergePolicy=[TieredMergePolicy: maxMergeAtOnce=10, maxMergeAtOnceExplicit=30, maxMergedSegmentMB=5120.0, floorSegmentMB=2.0, forceMergeDeletesPctAllowed=10.0, segmentsPerTier=10.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
indexerThreadPool=org.apache.lucene.index.ThreadAffinityDocumentsWriterThreadPool@7c6576d5
readerPooling=false
perThreadHardLimitMB=1945
useCompoundFile=false

13/08/12 12:41:11 INFO update.LoggingInfoStream: [IW][coreLoadExecutor-3-thread-1]: now flush at close waitForMerges=true
13/08/12 12:41:11 INFO update.LoggingInfoStream: [IW][coreLoadExecutor-3-thread-1]:   start flush: applyAllDeletes=true
13/08/12 12:41:11 INFO update.LoggingInfoStream: [IW][coreLoadExecutor-3-thread-1]:   index before flush 
13/08/12 12:41:11 INFO update.LoggingInfoStream: [DW][coreLoadExecutor-3-thread-1]: coreLoadExecutor-3-thread-1 startFullFlush
13/08/12 12:41:11 INFO update.LoggingInfoStream: [DW][coreLoadExecutor-3-thread-1]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
13/08/12 12:41:11 INFO update.LoggingInfoStream: [DW][coreLoadExecutor-3-thread-1]: coreLoadExecutor-3-thread-1 finishFullFlush success=true
13/08/12 12:41:11 INFO update.LoggingInfoStream: [IW][coreLoadExecutor-3-thread-1]: apply all deletes during flush
13/08/12 12:41:11 INFO update.LoggingInfoStream: [BD][coreLoadExecutor-3-thread-1]: prune sis=org.apache.lucene.index.SegmentInfos@4edc024a minGen=9223372036854775807 packetCount=0
13/08/12 12:41:11 INFO update.LoggingInfoStream: [CMS][coreLoadExecutor-3-thread-1]: now merge
13/08/12 12:41:11 INFO update.LoggingInfoStream: [CMS][coreLoadExecutor-3-thread-1]:   index: 
13/08/12 12:41:11 INFO update.LoggingInfoStream: [CMS][coreLoadExecutor-3-thread-1]:   no more merges pending; now return
13/08/12 12:41:11 INFO update.LoggingInfoStream: [IW][coreLoadExecutor-3-thread-1]: waitForMerges
13/08/12 12:41:11 INFO update.LoggingInfoStream: [IW][coreLoadExecutor-3-thread-1]: waitForMerges done
13/08/12 12:41:11 INFO update.LoggingInfoStream: [IW][coreLoadExecutor-3-thread-1]: now call final commit()
13/08/12 12:41:11 INFO update.LoggingInfoStream: [IW][coreLoadExecutor-3-thread-1]: commit: start
13/08/12 12:41:11 INFO update.LoggingInfoStream: [IW][coreLoadExecutor-3-thread-1]: commit: enter lock
13/08/12 12:41:11 INFO update.LoggingInfoStream: [IW][coreLoadExecutor-3-thread-1]: commit: now prepare
13/08/12 12:41:11 INFO update.LoggingInfoStream: [IW][coreLoadExecutor-3-thread-1]: prepareCommit: flush
13/08/12 12:41:11 INFO update.LoggingInfoStream: [IW][coreLoadExecutor-3-thread-1]:   index before flush 
13/08/12 12:41:11 INFO update.LoggingInfoStream: [DW][coreLoadExecutor-3-thread-1]: coreLoadExecutor-3-thread-1 startFullFlush
13/08/12 12:41:11 INFO update.LoggingInfoStream: [DW][coreLoadExecutor-3-thread-1]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
13/08/12 12:41:11 INFO update.LoggingInfoStream: [IW][coreLoadExecutor-3-thread-1]: apply all deletes during flush
13/08/12 12:41:11 INFO update.LoggingInfoStream: [BD][coreLoadExecutor-3-thread-1]: prune sis=org.apache.lucene.index.SegmentInfos@4edc024a minGen=9223372036854775807 packetCount=0
13/08/12 12:41:11 INFO update.LoggingInfoStream: [DW][coreLoadExecutor-3-thread-1]: coreLoadExecutor-3-thread-1 finishFullFlush success=true
13/08/12 12:41:11 INFO update.LoggingInfoStream: [IW][coreLoadExecutor-3-thread-1]: startCommit(): start
13/08/12 12:41:11 INFO update.LoggingInfoStream: [IW][coreLoadExecutor-3-thread-1]: startCommit index= changeCount=1
13/08/12 12:41:11 INFO update.LoggingInfoStream: [IW][coreLoadExecutor-3-thread-1]: done all syncs: []
13/08/12 12:41:11 INFO update.LoggingInfoStream: [IW][coreLoadExecutor-3-thread-1]: commit: pendingCommit != null
13/08/12 12:41:11 INFO update.LoggingInfoStream: [IW][coreLoadExecutor-3-thread-1]: commit: wrote segments file "segments_1"
13/08/12 12:41:11 INFO update.LoggingInfoStream: [IFD][coreLoadExecutor-3-thread-1]: now checkpoint "" [0 segments ; isCommit = true]
13/08/12 12:41:11 INFO core.SolrCore: SolrDeletionPolicy.onCommit: commits: num=1
  commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/Users/delip/r/dataops/sandbox/solr/shakespeare/data/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@49f10a67; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1}
13/08/12 12:41:11 INFO core.SolrCore: newest commit generation = 1
13/08/12 12:41:11 INFO update.LoggingInfoStream: [IFD][coreLoadExecutor-3-thread-1]: 2 msec to checkpoint
13/08/12 12:41:11 INFO update.LoggingInfoStream: [IW][coreLoadExecutor-3-thread-1]: commit: done
13/08/12 12:41:11 INFO update.LoggingInfoStream: [IW][coreLoadExecutor-3-thread-1]: at close: 
13/08/12 12:41:11 INFO core.SolrCore: created json: solr.JSONResponseWriter
13/08/12 12:41:11 INFO core.SolrCore: adding lazy queryResponseWriter: solr.VelocityResponseWriter
13/08/12 12:41:11 INFO core.SolrCore: created velocity: solr.VelocityResponseWriter
13/08/12 12:41:11 INFO core.SolrCore: created xslt: solr.XSLTResponseWriter
13/08/12 12:41:11 INFO response.XSLTResponseWriter: xsltCacheLifetimeSeconds=5
13/08/12 12:41:11 INFO core.RequestHandlers: created /select: solr.SearchHandler
13/08/12 12:41:11 INFO core.RequestHandlers: created /query: solr.SearchHandler
13/08/12 12:41:11 INFO core.RequestHandlers: created /get: solr.RealTimeGetHandler
13/08/12 12:41:11 INFO core.RequestHandlers: created /browse: solr.SearchHandler
13/08/12 12:41:11 INFO core.RequestHandlers: created /update: solr.UpdateRequestHandler
13/08/12 12:41:11 INFO core.RequestHandlers: created /update/json: solr.JsonUpdateRequestHandler
13/08/12 12:41:11 INFO core.RequestHandlers: created /update/csv: solr.CSVRequestHandler
13/08/12 12:41:11 INFO core.RequestHandlers: adding lazy requestHandler: solr.extraction.ExtractingRequestHandler
13/08/12 12:41:11 INFO core.RequestHandlers: created /update/extract: solr.extraction.ExtractingRequestHandler
13/08/12 12:41:11 INFO core.RequestHandlers: adding lazy requestHandler: solr.FieldAnalysisRequestHandler
13/08/12 12:41:11 INFO core.RequestHandlers: created /analysis/field: solr.FieldAnalysisRequestHandler
13/08/12 12:41:11 INFO core.RequestHandlers: adding lazy requestHandler: solr.DocumentAnalysisRequestHandler
13/08/12 12:41:11 INFO core.RequestHandlers: created /analysis/document: solr.DocumentAnalysisRequestHandler
13/08/12 12:41:11 INFO core.RequestHandlers: created /admin/: solr.admin.AdminHandlers
13/08/12 12:41:11 INFO core.RequestHandlers: created /admin/ping: solr.PingRequestHandler
13/08/12 12:41:11 INFO core.RequestHandlers: created /debug/dump: solr.DumpRequestHandler
13/08/12 12:41:11 INFO core.RequestHandlers: created /replication: solr.ReplicationHandler
13/08/12 12:41:11 INFO core.RequestHandlers: adding lazy requestHandler: solr.SearchHandler
13/08/12 12:41:11 INFO core.RequestHandlers: created /spell: solr.SearchHandler
13/08/12 12:41:11 INFO core.RequestHandlers: adding lazy requestHandler: solr.SearchHandler
13/08/12 12:41:11 INFO core.RequestHandlers: created /tvrh: solr.SearchHandler
13/08/12 12:41:11 INFO core.RequestHandlers: adding lazy requestHandler: solr.SearchHandler
13/08/12 12:41:11 INFO core.RequestHandlers: created /terms: solr.SearchHandler
13/08/12 12:41:11 INFO core.RequestHandlers: adding lazy requestHandler: solr.SearchHandler
13/08/12 12:41:11 INFO core.RequestHandlers: created /elevate: solr.SearchHandler
13/08/12 12:41:11 INFO loader.XMLLoader: xsltCacheLifetimeSeconds=60
13/08/12 12:41:11 INFO loader.XMLLoader: xsltCacheLifetimeSeconds=60
13/08/12 12:41:11 INFO loader.XMLLoader: xsltCacheLifetimeSeconds=60
13/08/12 12:41:11 INFO search.SolrIndexSearcher: Opening Searcher@51017ca1 main
13/08/12 12:41:11 INFO core.SolrCore: Hard AutoCommit: if uncommited for 15000ms; 
13/08/12 12:41:11 INFO core.SolrCore: Soft AutoCommit: disabled
13/08/12 12:41:11 INFO component.SpellCheckComponent: Initializing spell checkers
13/08/12 12:41:11 INFO spelling.DirectSolrSpellChecker: init: {name=default,field=text,classname=solr.DirectSolrSpellChecker,distanceMeasure=internal,accuracy=0.5,maxEdits=2,minPrefix=1,maxInspections=5,minQueryLength=4,maxQueryFrequency=0.01}
13/08/12 12:41:11 INFO component.SpellCheckComponent: No queryConverter defined, using default converter
13/08/12 12:41:11 INFO component.QueryElevationComponent: Loading QueryElevation from: /Users/delip/r/dataops/sandbox/solr/shakespeare/conf/elevate.xml
13/08/12 12:41:11 INFO handler.ReplicationHandler: Commits will be reserved for  10000
13/08/12 12:41:11 INFO core.SolrCore: QuerySenderListener sending requests to Searcher@51017ca1 main{StandardDirectoryReader(segments_1:1)}
13/08/12 12:41:11 INFO core.CoreContainer: registering core: shakespeare
>>> shakespeare
13/08/12 12:41:11 INFO core.SolrCore: [shakespeare] webapp=null path=null params={event=firstSearcher&q=static+firstSearcher+warming+in+solrconfig.xml&distrib=false} hits=0 status=0 QTime=62 
13/08/12 12:41:11 INFO core.SolrCore: QuerySenderListener done.
13/08/12 12:41:11 INFO component.SpellCheckComponent: Loading spell index for spellchecker: default
13/08/12 12:41:11 INFO component.SpellCheckComponent: Loading spell index for spellchecker: wordbreak
13/08/12 12:41:11 INFO core.SolrCore: [shakespeare] Registered new searcher Searcher@51017ca1 main{StandardDirectoryReader(segments_1:1)}
13/08/12 12:41:11 INFO update.LoggingInfoStream: [IFD][main]: init: current segments file is "segments_1"; deletionPolicy=org.apache.solr.core.IndexDeletionPolicyWrapper@3db158db
13/08/12 12:41:11 INFO update.LoggingInfoStream: [IFD][main]: init: load commit "segments_1"
13/08/12 12:41:11 INFO core.SolrCore: SolrDeletionPolicy.onInit: commits: num=1
	commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/Users/delip/r/dataops/sandbox/solr/shakespeare/data/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@49f10a67; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1}
13/08/12 12:41:11 INFO core.SolrCore: newest commit generation = 1
13/08/12 12:41:11 INFO update.LoggingInfoStream: [IFD][main]: now checkpoint "" [0 segments ; isCommit = false]
13/08/12 12:41:11 INFO update.LoggingInfoStream: [IFD][main]: 0 msec to checkpoint
13/08/12 12:41:11 INFO update.LoggingInfoStream: [IW][main]: init: create=false
13/08/12 12:41:11 INFO update.LoggingInfoStream: [IW][main]: 
dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/Users/delip/r/dataops/sandbox/solr/shakespeare/data/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@49f10a67; maxCacheMB=48.0 maxMergeSizeMB=4.0)
index=
version=4.4.0 1504776 - sarowe - 2013-07-19 02:53:42
matchVersion=LUCENE_44
analyzer=null
ramBufferSizeMB=100.0
maxBufferedDocs=-1
maxBufferedDeleteTerms=-1
mergedSegmentWarmer=null
readerTermsIndexDivisor=1
termIndexInterval=32
delPolicy=org.apache.solr.core.IndexDeletionPolicyWrapper
commit=null
openMode=APPEND
similarity=org.apache.lucene.search.similarities.DefaultSimilarity
mergeScheduler=ConcurrentMergeScheduler: maxThreadCount=1, maxMergeCount=2, mergeThreadPriority=-1
default WRITE_LOCK_TIMEOUT=1000
writeLockTimeout=1000
codec=Lucene42
infoStream=org.apache.solr.update.LoggingInfoStream
mergePolicy=[TieredMergePolicy: maxMergeAtOnce=10, maxMergeAtOnceExplicit=30, maxMergedSegmentMB=5120.0, floorSegmentMB=2.0, forceMergeDeletesPctAllowed=10.0, segmentsPerTier=10.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
indexerThreadPool=org.apache.lucene.index.ThreadAffinityDocumentsWriterThreadPool@1a3526cf
readerPooling=false
perThreadHardLimitMB=1945
useCompoundFile=false

13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[1542303677 (1443193391957409792)]} 0 82
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773779 (1443193391996207104)]} 0 2
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[390118013 (1443193391999352832)]} 0 3
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[390118014 (1443193392003547136)]} 0 3
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[390118015 (1443193392006692864)]} 0 2
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[390118016 (1443193392009838592)]} 0 3
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[390118017 (1443193392012984320)]} 0 3
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[390118018 (1443193392017178624)]} 0 3
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[390118019 (1443193392022421504)]} 0 3
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[390118020 (1443193392026615808)]} 0 3
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[390118021 (1443193392029761536)]} 0 3
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[390118022 (1443193392033955840)]} 0 3
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773780 (1443193392038150144)]} 0 3
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[390118044 (1443193392042344448)]} 0 4
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[390118045 (1443193392046538752)]} 0 3
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[390118046 (1443193392050733056)]} 0 4
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[390118047 (1443193392054927360)]} 0 3
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[390118048 (1443193392059121664)]} 0 3
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[390118049 (1443193392063315968)]} 0 4
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[390118050 (1443193392067510272)]} 0 3
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[390118051 (1443193392070656000)]} 0 2
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[390118052 (1443193392073801728)]} 0 2
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[390118053 (1443193392077996032)]} 0 3
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773781 (1443193392081141760)]} 0 3
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[390118075 (1443193392085336064)]} 0 4
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[390118076 (1443193392088481792)]} 0 10
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[390118077 (1443193392100016128)]} 0 2
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[390118078 (1443193392101064704)]} 0 2
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[390118079 (1443193392104210432)]} 0 3
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[390118080 (1443193392107356160)]} 0 2
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[390118081 (1443193392110501888)]} 0 2
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[390118082 (1443193392112599040)]} 0 2
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[390118083 (1443193392114696192)]} 0 2
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[390118084 (1443193392117841920)]} 0 2
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773782 (1443193392119939072)]} 0 2
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[390118106 (1443193392123084800)]} 0 2
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[390118107 (1443193392126230528)]} 0 2
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[390118108 (1443193392128327680)]} 0 1
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[390118109 (1443193392130424832)]} 0 1
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[390118110 (1443193392132521984)]} 0 1
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[390118111 (1443193392134619136)]} 0 2
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[390118112 (1443193392136716288)]} 0 2
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[390118113 (1443193392138813440)]} 0 2
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[390118114 (1443193392140910592)]} 0 2
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[390118115 (1443193392143007744)]} 0 2
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773783 (1443193392145104896)]} 0 2
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[390118137 (1443193392147202048)]} 0 1
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[390118138 (1443193392149299200)]} 0 2
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[390118139 (1443193392151396352)]} 0 2
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[390118140 (1443193392153493504)]} 0 2
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[390118141 (1443193392156639232)]} 0 2
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[390118142 (1443193392159784960)]} 0 8
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[390118143 (1443193392168173568)]} 0 2
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[390118144 (1443193392169222144)]} 0 2
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[390118145 (1443193392171319296)]} 0 1
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[390118146 (1443193392173416448)]} 0 1
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773784 (1443193392175513600)]} 0 1
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[390118168 (1443193392177610752)]} 0 1
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[390118169 (1443193392179707904)]} 0 2
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[390118170 (1443193392181805056)]} 0 2
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[390118171 (1443193392184950784)]} 0 1
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[390118172 (1443193392187047936)]} 0 2
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773785 (1443193392190193664)]} 0 2
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773786 (1443193392192290816)]} 0 3
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773787 (1443193392195436544)]} 0 2
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773788 (1443193392197533696)]} 0 1
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[1542303678 (1443193392199630848)]} 0 2
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773810 (1443193392201728000)]} 0 2
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773811 (1443193392203825152)]} 0 1
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773812 (1443193392204873728)]} 0 1
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773813 (1443193392206970880)]} 0 1
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773814 (1443193392208019456)]} 0 2
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773815 (1443193392210116608)]} 0 1
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773816 (1443193392212213760)]} 0 2
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773817 (1443193392215359488)]} 0 3
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773818 (1443193392218505216)]} 0 2
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773819 (1443193392220602368)]} 0 2
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[1542303679 (1443193392223748096)]} 0 11
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773841 (1443193392236331008)]} 0 2
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773842 (1443193392239476736)]} 0 2
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773843 (1443193392240525312)]} 0 2
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773844 (1443193392242622464)]} 0 2
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773845 (1443193392245768192)]} 0 2
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773846 (1443193392247865344)]} 0 2
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773847 (1443193392251011072)]} 0 2
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773848 (1443193392253108224)]} 0 2
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773849 (1443193392256253952)]} 0 2
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773850 (1443193392259399680)]} 0 1
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[1542303680 (1443193392261496832)]} 0 2
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773872 (1443193392264642560)]} 0 2
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773873 (1443193392266739712)]} 0 2
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773874 (1443193392269885440)]} 0 2
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773875 (1443193392273031168)]} 0 2
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773876 (1443193392276176896)]} 0 2
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773877 (1443193392278274048)]} 0 2
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773878 (1443193392280371200)]} 0 1
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773879 (1443193392282468352)]} 0 1
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773880 (1443193392284565504)]} 0 1
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773881 (1443193392287711232)]} 0 2
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[1542303681 (1443193392289808384)]} 0 1
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773903 (1443193392292954112)]} 0 2
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773904 (1443193392295051264)]} 0 1
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773905 (1443193392297148416)]} 0 1
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773906 (1443193392299245568)]} 0 1
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773907 (1443193392301342720)]} 0 2
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773908 (1443193392304488448)]} 0 2
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773909 (1443193392306585600)]} 0 2
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773910 (1443193392308682752)]} 0 2
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773911 (1443193392310779904)]} 0 1
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773912 (1443193392312877056)]} 0 1
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[1542303682 (1443193392314974208)]} 0 2
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773934 (1443193392317071360)]} 0 1
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773935 (1443193392320217088)]} 0 2
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773936 (1443193392322314240)]} 0 1
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773937 (1443193392324411392)]} 0 1
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773938 (1443193392326508544)]} 0 1
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773939 (1443193392328605696)]} 0 1
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773940 (1443193392330702848)]} 0 1
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773941 (1443193392332800000)]} 0 1
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773942 (1443193392334897152)]} 0 1
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773943 (1443193392336994304)]} 0 1
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[1542303683 (1443193392339091456)]} 0 2
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773965 (1443193392340140032)]} 0 1
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773966 (1443193392342237184)]} 0 1
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773967 (1443193392343285760)]} 0 1
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773968 (1443193392345382912)]} 0 1
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773969 (1443193392346431488)]} 0 0
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773970 (1443193392348528640)]} 0 1
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773971 (1443193392349577216)]} 0 1
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773972 (1443193392350625792)]} 0 1
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773973 (1443193392352722944)]} 0 1
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773974 (1443193392354820096)]} 0 1
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[1542303684 (1443193392356917248)]} 0 1
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773996 (1443193392357965824)]} 0 1
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773997 (1443193392360062976)]} 0 2
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773998 (1443193392361111552)]} 0 1
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566773999 (1443193392363208704)]} 0 1
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566774000 (1443193392365305856)]} 0 2
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566774001 (1443193392367403008)]} 0 1
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566774002 (1443193392368451584)]} 0 1
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566774003 (1443193392371597312)]} 0 1
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566774004 (1443193392372645888)]} 0 1
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566774005 (1443193392374743040)]} 0 1
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[1542303685 (1443193392376840192)]} 0 1
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566774027 (1443193392377888768)]} 0 1
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566774028 (1443193392378937344)]} 0 1
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566774029 (1443193392381034496)]} 0 0
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566774030 (1443193392382083072)]} 0 1
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566774031 (1443193392384180224)]} 0 1
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566774032 (1443193392385228800)]} 0 0
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566774033 (1443193392386277376)]} 0 1
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566774034 (1443193392387325952)]} 0 1
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566774035 (1443193392389423104)]} 0 1
13/08/12 12:41:11 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={} {add=[566774036 (1443193392391520256)]} 0 2
13/08/12 12:41:11 INFO update.UpdateHandler: start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
13/08/12 12:41:11 INFO update.LoggingInfoStream: [IW][main]: commit: start
13/08/12 12:41:11 INFO update.LoggingInfoStream: [IW][main]: commit: enter lock
13/08/12 12:41:11 INFO update.LoggingInfoStream: [IW][main]: commit: now prepare
13/08/12 12:41:11 INFO update.LoggingInfoStream: [IW][main]: prepareCommit: flush
13/08/12 12:41:11 INFO update.LoggingInfoStream: [IW][main]:   index before flush 
13/08/12 12:41:11 INFO update.LoggingInfoStream: [DW][main]: main startFullFlush
13/08/12 12:41:11 INFO update.LoggingInfoStream: [DW][main]: anyChanges? numDocsInRam=154 deletes=true hasTickets:false pendingChangesInFullFlush: false
13/08/12 12:41:11 INFO update.LoggingInfoStream: [DWFC][main]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0 153 deleted terms (unique count=153) bytesUsed=26477, segment=_0, aborting=false, numDocsInRAM=154, deleteQueue=DWDQ: [ generation: 0 ]]
13/08/12 12:41:11 INFO update.LoggingInfoStream: [DWPT][main]: flush postings as segment _0 numDocs=154
13/08/12 12:41:12 INFO update.LoggingInfoStream: [DWPT][main]: new segment has 0 deleted docs
13/08/12 12:41:12 INFO update.LoggingInfoStream: [DWPT][main]: new segment has no vectors; norms; no docValues; prox; freqs
13/08/12 12:41:12 INFO update.LoggingInfoStream: [DWPT][main]: flushedFiles=[_0.fnm, _0_Lucene41_0.doc, _0_Lucene41_0.pos, _0.nvd, _0.fdx, _0.nvm, _0_Lucene41_0.tim, _0_Lucene41_0.tip, _0.fdt]
13/08/12 12:41:12 INFO update.LoggingInfoStream: [DWPT][main]: flushed codec=Lucene42
13/08/12 12:41:12 INFO update.LoggingInfoStream: [DWPT][main]: flushed: segment=_0 ramUsed=0.329 MB newFlushedSize(includes docstores)=0.132 MB docs/MB=1,171.092
13/08/12 12:41:12 INFO update.LoggingInfoStream: [DW][main]: publishFlushedSegment seg-private deletes=null
13/08/12 12:41:12 INFO update.LoggingInfoStream: [IW][main]: publishFlushedSegment
13/08/12 12:41:12 INFO update.LoggingInfoStream: [BD][main]: push deletes  154 deleted terms (unique count=154) bytesUsed=1024 delGen=1 packetCount=1 totBytesUsed=1024
13/08/12 12:41:12 INFO update.LoggingInfoStream: [IW][main]: publish sets newSegment delGen=2 seg=_0(4.4):C154
13/08/12 12:41:12 INFO update.LoggingInfoStream: [IFD][main]: now checkpoint "_0(4.4):C154" [1 segments ; isCommit = false]
13/08/12 12:41:12 INFO update.LoggingInfoStream: [IFD][main]: 0 msec to checkpoint
13/08/12 12:41:12 INFO update.LoggingInfoStream: [IW][main]: apply all deletes during flush
13/08/12 12:41:12 INFO update.LoggingInfoStream: [BD][main]: applyDeletes: infos=[_0(4.4):C154] packetCount=1
13/08/12 12:41:12 INFO update.LoggingInfoStream: [BD][main]: applyDeletes took 0 msec
13/08/12 12:41:12 INFO update.LoggingInfoStream: [BD][main]: prune sis=org.apache.lucene.index.SegmentInfos@38666d83 minGen=3 packetCount=1
13/08/12 12:41:12 INFO update.LoggingInfoStream: [BD][main]: pruneDeletes: prune 1 packets; 0 packets remain
13/08/12 12:41:12 INFO update.LoggingInfoStream: [DW][main]: main finishFullFlush success=true
13/08/12 12:41:12 INFO update.LoggingInfoStream: [TMP][main]: findMerges: 1 segments
13/08/12 12:41:12 INFO update.LoggingInfoStream: [TMP][main]:   seg=_0(4.4):C154 size=0.131 MB [floored]
13/08/12 12:41:12 INFO update.LoggingInfoStream: [TMP][main]:   allowedSegmentCount=1 vs count=1 (eligible count=1) tooBigCount=0
13/08/12 12:41:12 INFO update.LoggingInfoStream: [CMS][main]: now merge
13/08/12 12:41:12 INFO update.LoggingInfoStream: [CMS][main]:   index: _0(4.4):C154
13/08/12 12:41:12 INFO update.LoggingInfoStream: [CMS][main]:   no more merges pending; now return
13/08/12 12:41:12 INFO update.LoggingInfoStream: [IW][main]: startCommit(): start
13/08/12 12:41:12 INFO update.LoggingInfoStream: [IW][main]: startCommit index=_0(4.4):C154 changeCount=3
13/08/12 12:41:12 INFO update.LoggingInfoStream: [IW][main]: done all syncs: [_0.fnm, _0_Lucene41_0.doc, _0_Lucene41_0.pos, _0.nvd, _0.fdx, _0.si, _0.nvm, _0_Lucene41_0.tim, _0.fdt, _0_Lucene41_0.tip]
13/08/12 12:41:12 INFO update.LoggingInfoStream: [IW][main]: commit: pendingCommit != null
13/08/12 12:41:12 INFO update.LoggingInfoStream: [IW][main]: commit: wrote segments file "segments_2"
13/08/12 12:41:12 INFO update.LoggingInfoStream: [IFD][main]: now checkpoint "_0(4.4):C154" [1 segments ; isCommit = true]
13/08/12 12:41:12 INFO core.SolrCore: SolrDeletionPolicy.onCommit: commits: num=2
	commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/Users/delip/r/dataops/sandbox/solr/shakespeare/data/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@49f10a67; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1}
	commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/Users/delip/r/dataops/sandbox/solr/shakespeare/data/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@49f10a67; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2}
13/08/12 12:41:12 INFO core.SolrCore: newest commit generation = 2
13/08/12 12:41:12 INFO update.LoggingInfoStream: [IFD][main]: deleteCommits: now decRef commit "segments_1"
13/08/12 12:41:12 INFO update.LoggingInfoStream: [IFD][main]: delete "segments_1"
13/08/12 12:41:12 INFO update.LoggingInfoStream: [IFD][main]: 0 msec to checkpoint
13/08/12 12:41:12 INFO update.LoggingInfoStream: [IW][main]: commit: done
13/08/12 12:41:12 INFO update.LoggingInfoStream: [IW][main]: flush at getReader
13/08/12 12:41:12 INFO update.LoggingInfoStream: [DW][main]: main startFullFlush
13/08/12 12:41:12 INFO update.LoggingInfoStream: [DW][main]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
13/08/12 12:41:12 INFO update.LoggingInfoStream: [DWFC][main]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=null, aborting=false, numDocsInRAM=0, deleteQueue=DWDQ: [ generation: 1 ]]
13/08/12 12:41:12 INFO update.LoggingInfoStream: [IW][main]: apply all deletes during flush
13/08/12 12:41:12 INFO update.LoggingInfoStream: [BD][main]: applyDeletes: no deletes; skipping
13/08/12 12:41:12 INFO update.LoggingInfoStream: [BD][main]: prune sis=org.apache.lucene.index.SegmentInfos@38666d83 minGen=3 packetCount=0
13/08/12 12:41:12 INFO update.LoggingInfoStream: [IW][main]: return reader version=3 reader=StandardDirectoryReader(segments_2:3:nrt _0(4.4):C154)
13/08/12 12:41:12 INFO update.LoggingInfoStream: [DW][main]: main finishFullFlush success=true
13/08/12 12:41:12 INFO update.LoggingInfoStream: [IW][main]: getReader took 29 msec
13/08/12 12:41:12 INFO search.SolrIndexSearcher: Opening Searcher@6885b670 main
13/08/12 12:41:12 INFO update.UpdateHandler: end_commit_flush
13/08/12 12:41:12 INFO core.SolrCore: QuerySenderListener sending requests to Searcher@6885b670 main{StandardDirectoryReader(segments_2:3:nrt _0(4.4):C154)}
13/08/12 12:41:12 INFO core.SolrCore: QuerySenderListener done.
13/08/12 12:41:12 INFO core.SolrCore: [shakespeare] Registered new searcher Searcher@6885b670 main{StandardDirectoryReader(segments_2:3:nrt _0(4.4):C154)}
13/08/12 12:41:12 INFO processor.LogUpdateProcessor: [shakespeare] webapp=null path=/update params={commit=true&softCommit=false&waitSearcher=true} {commit=} 0 289
13/08/12 12:41:17 INFO core.CoreContainer: Shutting down CoreContainer instance=1748234462
13/08/12 12:41:17 INFO core.SolrCore: [shakespeare]  CLOSING SolrCore org.apache.solr.core.SolrCore@3ea86d12
13/08/12 12:41:17 INFO update.UpdateHandler: closing DirectUpdateHandler2{commits=1,autocommit maxTime=15000ms,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=154,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
13/08/12 12:41:17 INFO update.SolrCoreState: Closing SolrCoreState
13/08/12 12:41:17 INFO update.DefaultSolrCoreState: SolrCoreState ref count has reached 0 - closing IndexWriter
13/08/12 12:41:17 INFO update.DefaultSolrCoreState: closing IndexWriter with IndexWriterCloser
13/08/12 12:41:17 INFO update.LoggingInfoStream: [IW][main]: now flush at close waitForMerges=true
13/08/12 12:41:17 INFO update.LoggingInfoStream: [IW][main]:   start flush: applyAllDeletes=true
13/08/12 12:41:17 INFO update.LoggingInfoStream: [IW][main]:   index before flush _0(4.4):C154
13/08/12 12:41:17 INFO update.LoggingInfoStream: [DW][main]: main startFullFlush
13/08/12 12:41:17 INFO update.LoggingInfoStream: [DW][main]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
13/08/12 12:41:17 INFO update.LoggingInfoStream: [DWFC][main]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=null, aborting=false, numDocsInRAM=0, deleteQueue=DWDQ: [ generation: 2 ]]
13/08/12 12:41:17 INFO update.LoggingInfoStream: [DW][main]: main finishFullFlush success=true
13/08/12 12:41:17 INFO update.LoggingInfoStream: [IW][main]: apply all deletes during flush
13/08/12 12:41:17 INFO update.LoggingInfoStream: [BD][main]: applyDeletes: no deletes; skipping
13/08/12 12:41:17 INFO update.LoggingInfoStream: [BD][main]: prune sis=org.apache.lucene.index.SegmentInfos@38666d83 minGen=3 packetCount=0
13/08/12 12:41:17 INFO update.LoggingInfoStream: [CMS][main]: now merge
13/08/12 12:41:17 INFO update.LoggingInfoStream: [CMS][main]:   index: _0(4.4):C154
13/08/12 12:41:17 INFO update.LoggingInfoStream: [CMS][main]:   no more merges pending; now return
13/08/12 12:41:17 INFO update.LoggingInfoStream: [IW][main]: waitForMerges
13/08/12 12:41:17 INFO update.LoggingInfoStream: [IW][main]: waitForMerges done
13/08/12 12:41:17 INFO update.LoggingInfoStream: [IW][main]: now call final commit()
13/08/12 12:41:17 INFO update.LoggingInfoStream: [IW][main]: commit: start
13/08/12 12:41:17 INFO update.LoggingInfoStream: [IW][main]: commit: enter lock
13/08/12 12:41:17 INFO update.LoggingInfoStream: [IW][main]: commit: now prepare
13/08/12 12:41:17 INFO update.LoggingInfoStream: [IW][main]: prepareCommit: flush
13/08/12 12:41:17 INFO update.LoggingInfoStream: [IW][main]:   index before flush _0(4.4):C154
13/08/12 12:41:17 INFO update.LoggingInfoStream: [DW][main]: main startFullFlush
13/08/12 12:41:17 INFO update.LoggingInfoStream: [DW][main]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
13/08/12 12:41:17 INFO update.LoggingInfoStream: [IW][main]: apply all deletes during flush
13/08/12 12:41:17 INFO update.LoggingInfoStream: [BD][main]: applyDeletes: no deletes; skipping
13/08/12 12:41:17 INFO update.LoggingInfoStream: [BD][main]: prune sis=org.apache.lucene.index.SegmentInfos@38666d83 minGen=3 packetCount=0
13/08/12 12:41:17 INFO update.LoggingInfoStream: [DW][main]: main finishFullFlush success=true
13/08/12 12:41:17 INFO update.LoggingInfoStream: [IW][main]: startCommit(): start
13/08/12 12:41:17 INFO update.LoggingInfoStream: [IW][main]:   skip startCommit(): no changes pending
13/08/12 12:41:17 INFO update.LoggingInfoStream: [IW][main]: commit: pendingCommit == null; skip
13/08/12 12:41:17 INFO update.LoggingInfoStream: [IW][main]: commit: done
13/08/12 12:41:17 INFO update.LoggingInfoStream: [IW][main]: at close: _0(4.4):C154
13/08/12 12:41:17 INFO core.SolrCore: [shakespeare] Closing main searcher on request.
13/08/12 12:41:17 INFO core.CachingDirectoryFactory: Closing NRTCachingDirectoryFactory - 2 directories currently being tracked
13/08/12 12:41:17 INFO core.CachingDirectoryFactory: looking to close /Users/delip/r/dataops/sandbox/solr/shakespeare/data [CachedDir<<refCount=0;path=/Users/delip/r/dataops/sandbox/solr/shakespeare/data;done=false>>]
13/08/12 12:41:17 INFO core.CachingDirectoryFactory: Closing directory: /Users/delip/r/dataops/sandbox/solr/shakespeare/data
13/08/12 12:41:17 INFO core.CachingDirectoryFactory: looking to close /Users/delip/r/dataops/sandbox/solr/shakespeare/data/index [CachedDir<<refCount=0;path=/Users/delip/r/dataops/sandbox/solr/shakespeare/data/index;done=false>>]
13/08/12 12:41:17 INFO core.CachingDirectoryFactory: Closing directory: /Users/delip/r/dataops/sandbox/solr/shakespeare/data/index
13/08/12 12:41:17 INFO core.CoreContainer: Shutting down CoreContainer instance=1748234462
13/08/12 12:41:17 INFO core.SolrResourceLoader: new SolrResourceLoader for directory: 'sandbox/solr/'
13/08/12 12:41:17 INFO core.ConfigSolr: Loading container configuration from /Users/delip/r/dataops/sandbox/solr/solr.xml
13/08/12 12:41:17 INFO core.SolrCoreDiscoverer: Looking for cores in /Users/delip/r/dataops/sandbox/solr
13/08/12 12:41:17 INFO core.SolrCoreDiscoverer: Looking for cores in /Users/delip/r/dataops/sandbox/solr/bin
13/08/12 12:41:17 INFO core.SolrCoreDiscoverer: Discovered properties file /Users/delip/r/dataops/sandbox/solr/shakespeare/core.properties, adding to cores
13/08/12 12:41:17 INFO core.CoreContainer: New CoreContainer 1465333984
13/08/12 12:41:17 INFO core.CoreContainer: Loading cores into CoreContainer [instanceDir=sandbox/solr/]
13/08/12 12:41:17 INFO component.HttpShardHandlerFactory: Setting socketTimeout to: 0
13/08/12 12:41:17 INFO component.HttpShardHandlerFactory: Setting urlScheme to: http://
13/08/12 12:41:17 INFO component.HttpShardHandlerFactory: Setting connTimeout to: 0
13/08/12 12:41:17 INFO component.HttpShardHandlerFactory: Setting maxConnectionsPerHost to: 20
13/08/12 12:41:17 INFO component.HttpShardHandlerFactory: Setting corePoolSize to: 0
13/08/12 12:41:17 INFO component.HttpShardHandlerFactory: Setting maximumPoolSize to: 2147483647
13/08/12 12:41:17 INFO component.HttpShardHandlerFactory: Setting maxThreadIdleTime to: 5
13/08/12 12:41:17 INFO component.HttpShardHandlerFactory: Setting sizeOfQueue to: -1
13/08/12 12:41:17 INFO component.HttpShardHandlerFactory: Setting fairnessPolicy to: false
13/08/12 12:41:17 INFO impl.HttpClientUtil: Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
13/08/12 12:41:17 INFO logging.LogWatcher: Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
13/08/12 12:41:17 INFO core.CoreContainer: Creating SolrCore 'shakespeare' using instanceDir: /Users/delip/r/dataops/sandbox/solr/shakespeare
13/08/12 12:41:17 INFO core.SolrResourceLoader: new SolrResourceLoader for directory: '/Users/delip/r/dataops/sandbox/solr/shakespeare/'
13/08/12 12:41:17 INFO core.SolrConfig: Adding specified lib dirs to ClassLoader
13/08/12 12:41:17 WARN core.SolrResourceLoader: Can't find (or read) directory to add to classloader: ../../../contrib/extraction/lib (resolved as: /Users/delip/r/dataops/sandbox/solr/shakespeare/../../../contrib/extraction/lib).
13/08/12 12:41:17 WARN core.SolrResourceLoader: Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /Users/delip/r/dataops/sandbox/solr/shakespeare/../../../dist).
13/08/12 12:41:17 WARN core.SolrResourceLoader: Can't find (or read) directory to add to classloader: ../../../contrib/clustering/lib/ (resolved as: /Users/delip/r/dataops/sandbox/solr/shakespeare/../../../contrib/clustering/lib).
13/08/12 12:41:17 WARN core.SolrResourceLoader: Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /Users/delip/r/dataops/sandbox/solr/shakespeare/../../../dist).
13/08/12 12:41:17 WARN core.SolrResourceLoader: Can't find (or read) directory to add to classloader: ../../../contrib/langid/lib/ (resolved as: /Users/delip/r/dataops/sandbox/solr/shakespeare/../../../contrib/langid/lib).
13/08/12 12:41:17 WARN core.SolrResourceLoader: Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /Users/delip/r/dataops/sandbox/solr/shakespeare/../../../dist).
13/08/12 12:41:17 WARN core.SolrResourceLoader: Can't find (or read) directory to add to classloader: ../../../contrib/velocity/lib (resolved as: /Users/delip/r/dataops/sandbox/solr/shakespeare/../../../contrib/velocity/lib).
13/08/12 12:41:17 WARN core.SolrResourceLoader: Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /Users/delip/r/dataops/sandbox/solr/shakespeare/../../../dist).
13/08/12 12:41:17 INFO update.SolrIndexConfig: IndexWriter infoStream solr logging is enabled
13/08/12 12:41:17 INFO core.SolrConfig: Using Lucene MatchVersion: LUCENE_44
13/08/12 12:41:17 INFO core.Config: Loaded SolrConfig: solrconfig.xml
13/08/12 12:41:17 INFO schema.IndexSchema: Reading Solr Schema from schema.xml
13/08/12 12:41:17 INFO schema.IndexSchema: [shakespeare] Schema name=example
13/08/12 12:41:17 INFO schema.IndexSchema: unique key field: id
13/08/12 12:41:17 INFO schema.FileExchangeRateProvider: Reloading exchange rates from file currency.xml
13/08/12 12:41:17 INFO schema.FileExchangeRateProvider: Reloading exchange rates from file currency.xml
13/08/12 12:41:17 INFO core.SolrCore: solr.NRTCachingDirectoryFactory
13/08/12 12:41:17 INFO core.SolrCore: [shakespeare] Opening new SolrCore at /Users/delip/r/dataops/sandbox/solr/shakespeare/, dataDir=/Users/delip/r/dataops/sandbox/solr/shakespeare/data/
13/08/12 12:41:17 INFO core.JmxMonitoredMap: No JMX servers found, not exposing Solr information with JMX.
13/08/12 12:41:17 INFO core.SolrCore: [shakespeare] Added SolrEventListener for newSearcher: org.apache.solr.core.QuerySenderListener{queries=[]}
13/08/12 12:41:17 INFO core.SolrCore: [shakespeare] Added SolrEventListener for firstSearcher: org.apache.solr.core.QuerySenderListener{queries=[{q=static firstSearcher warming in solrconfig.xml}]}
13/08/12 12:41:17 INFO core.CachingDirectoryFactory: return new directory for /Users/delip/r/dataops/sandbox/solr/shakespeare/data
13/08/12 12:41:17 INFO core.SolrCore: New index directory detected: old=null new=/Users/delip/r/dataops/sandbox/solr/shakespeare/data/index/
13/08/12 12:41:17 INFO core.SolrCore: created json: solr.JSONResponseWriter
13/08/12 12:41:17 INFO core.SolrCore: adding lazy queryResponseWriter: solr.VelocityResponseWriter
13/08/12 12:41:17 INFO core.SolrCore: created velocity: solr.VelocityResponseWriter
13/08/12 12:41:17 INFO core.SolrCore: created xslt: solr.XSLTResponseWriter
13/08/12 12:41:17 INFO response.XSLTResponseWriter: xsltCacheLifetimeSeconds=5
13/08/12 12:41:17 INFO core.RequestHandlers: created /select: solr.SearchHandler
13/08/12 12:41:17 INFO core.RequestHandlers: created /query: solr.SearchHandler
13/08/12 12:41:17 INFO core.RequestHandlers: created /get: solr.RealTimeGetHandler
13/08/12 12:41:17 INFO core.RequestHandlers: created /browse: solr.SearchHandler
13/08/12 12:41:17 INFO core.RequestHandlers: created /update: solr.UpdateRequestHandler
13/08/12 12:41:17 INFO core.RequestHandlers: created /update/json: solr.JsonUpdateRequestHandler
13/08/12 12:41:17 INFO core.RequestHandlers: created /update/csv: solr.CSVRequestHandler
13/08/12 12:41:17 INFO core.RequestHandlers: adding lazy requestHandler: solr.extraction.ExtractingRequestHandler
13/08/12 12:41:17 INFO core.RequestHandlers: created /update/extract: solr.extraction.ExtractingRequestHandler
13/08/12 12:41:17 INFO core.RequestHandlers: adding lazy requestHandler: solr.FieldAnalysisRequestHandler
13/08/12 12:41:17 INFO core.RequestHandlers: created /analysis/field: solr.FieldAnalysisRequestHandler
13/08/12 12:41:17 INFO core.RequestHandlers: adding lazy requestHandler: solr.DocumentAnalysisRequestHandler
13/08/12 12:41:17 INFO core.RequestHandlers: created /analysis/document: solr.DocumentAnalysisRequestHandler
13/08/12 12:41:17 INFO core.RequestHandlers: created /admin/: solr.admin.AdminHandlers
13/08/12 12:41:17 INFO core.RequestHandlers: created /admin/ping: solr.PingRequestHandler
13/08/12 12:41:17 INFO core.RequestHandlers: created /debug/dump: solr.DumpRequestHandler
13/08/12 12:41:17 INFO core.RequestHandlers: created /replication: solr.ReplicationHandler
13/08/12 12:41:17 INFO core.RequestHandlers: adding lazy requestHandler: solr.SearchHandler
13/08/12 12:41:17 INFO core.RequestHandlers: created /spell: solr.SearchHandler
13/08/12 12:41:17 INFO core.RequestHandlers: adding lazy requestHandler: solr.SearchHandler
13/08/12 12:41:17 INFO core.RequestHandlers: created /tvrh: solr.SearchHandler
13/08/12 12:41:17 INFO core.RequestHandlers: adding lazy requestHandler: solr.SearchHandler
13/08/12 12:41:17 INFO core.RequestHandlers: created /terms: solr.SearchHandler
13/08/12 12:41:17 INFO core.RequestHandlers: adding lazy requestHandler: solr.SearchHandler
13/08/12 12:41:17 INFO core.RequestHandlers: created /elevate: solr.SearchHandler
13/08/12 12:41:17 INFO loader.XMLLoader: xsltCacheLifetimeSeconds=60
13/08/12 12:41:17 INFO loader.XMLLoader: xsltCacheLifetimeSeconds=60
13/08/12 12:41:17 INFO loader.XMLLoader: xsltCacheLifetimeSeconds=60
13/08/12 12:41:17 INFO core.CachingDirectoryFactory: return new directory for /Users/delip/r/dataops/sandbox/solr/shakespeare/data/index
13/08/12 12:41:17 INFO search.SolrIndexSearcher: Opening Searcher@4838462a main
13/08/12 12:41:17 INFO core.SolrCore: Hard AutoCommit: if uncommited for 15000ms; 
13/08/12 12:41:17 INFO core.SolrCore: Soft AutoCommit: disabled
13/08/12 12:41:17 INFO component.SpellCheckComponent: Initializing spell checkers
13/08/12 12:41:17 INFO spelling.DirectSolrSpellChecker: init: {name=default,field=text,classname=solr.DirectSolrSpellChecker,distanceMeasure=internal,accuracy=0.5,maxEdits=2,minPrefix=1,maxInspections=5,minQueryLength=4,maxQueryFrequency=0.01}
13/08/12 12:41:17 INFO component.SpellCheckComponent: No queryConverter defined, using default converter
13/08/12 12:41:17 INFO component.QueryElevationComponent: Loading QueryElevation from: /Users/delip/r/dataops/sandbox/solr/shakespeare/conf/elevate.xml
13/08/12 12:41:17 INFO handler.ReplicationHandler: Commits will be reserved for  10000
13/08/12 12:41:17 INFO core.SolrCore: QuerySenderListener sending requests to Searcher@4838462a main{StandardDirectoryReader(segments_2:3 _0(4.4):C154)}
13/08/12 12:41:17 INFO core.CoreContainer: registering core: shakespeare
13/08/12 12:41:17 INFO core.SolrCore: [shakespeare] webapp=null path=null params={event=firstSearcher&q=static+firstSearcher+warming+in+solrconfig.xml&distrib=false} hits=140 status=0 QTime=17 
13/08/12 12:41:17 INFO core.SolrCore: QuerySenderListener done.
13/08/12 12:41:17 INFO component.SpellCheckComponent: Loading spell index for spellchecker: default
13/08/12 12:41:17 INFO component.SpellCheckComponent: Loading spell index for spellchecker: wordbreak
13/08/12 12:41:17 INFO core.SolrCore: [shakespeare] Registered new searcher Searcher@4838462a main{StandardDirectoryReader(segments_2:3 _0(4.4):C154)}
13/08/12 12:41:17 INFO core.SolrCore: [shakespeare] webapp=null path=/select params={*:*=} hits=0 status=0 QTime=21