[Dovecot] "Header is huge" in fts-solr

Valery V. Sedletski valerius at afterlogic.com
Tue Feb 5 15:58:14 EET 2013 

Hi, Timo and all!

I am trying to index mail in a test mailbox using fts_solr plugin for
full-text search. On most mailboxes, it works fine, but on some big
messages I get
warnings like the following, and then I get an Out of memory error from
Solr, then the indexer-worker process (or doveadm) crashes with "assertion
failed" error and the backtrace:

==========================================================
doveadm(valerius at test.afterlogic.com): Warning:
fts-solr(valerius at test.afterlogic.com): Mailbox gmail.com UID=48 header
size is huge
doveadm(valerius at test.afterlogic.com): Warning:
fts-solr(valerius at test.afterlogic.com): Mailbox gmail.com UID=49 header
size is huge
doveadm(valerius at test.afterlogic.com): Panic: file
../../../../src/plugins/fts-solr/solr-connection.c: line 548
(solr_connection_post_more): assertion failed: (maxfd >= 0)
doveadm(valerius at test.afterlogic.com): Error: Raw backtrace:
/usr/mailsuite/lib/dovecot/libdovecot.so.0(+0x58f04) [0x7fe8a908af04] ->
/usr/mailsuite/lib/dovecot/libdovecot.so.0(default_error_handler+0)
[0x7fe8a908af93] -> /usr/mailsuite/lib/dovecot/libdovecot.so.0(i_fatal+0)
[0x7fe8a908b274] ->
/usr/mailsuite/lib/dovecot/lib21_fts_solr_plugin.so(solr_connection_post_more+0x2d2)
[0x7fe8a75fe973] ->
/usr/mailsuite/lib/dovecot/lib21_fts_solr_plugin.so(+0x4d03)
[0x7fe8a75f9d03] ->
/usr/mailsuite/lib/dovecot/lib20_fts_plugin.so(fts_backend_update_build_more+0x77)
[0x7fe8a7c1d401] -> /usr/mailsuite/lib/dovecot/lib20_fts_plugin.so(+0x7fe2)
[0x7fe8a7c1dfe2] -> /usr/mailsuite/lib/dovecot/lib20_fts_plugin.so(+0x80d5)
[0x7fe8a7c1e0d5] -> /usr/mailsuite/lib/dovecot/lib20_fts_plugin.so(+0x89e4)
[0x7fe8a7c1e9e4] ->
/usr/mailsuite/lib/dovecot/lib20_fts_plugin.so(fts_build_mail+0x2b)
[0x7fe8a7c1ebf5] -> /usr/mailsuite/lib/dovecot/lib20_fts_plugin.so(+0xe7cf)
[0x7fe8a7c247cf] -> /usr/mailsuite/lib/dovecot/lib20_fts_plugin.so(+0xe8ba)
[0x7fe8a7c248ba] ->
/usr/mailsuite/lib/dovecot/libdovecot-storage.so.0(mail_precache+0x25)
[0x7fe8a9379bc9] -> /usr/mailsuite/bin/doveadm() [0x4139de] ->
/usr/mailsuite/bin/doveadm() [0x413c17] -> /usr/mailsuite/bin/doveadm()
[0x413f18] -> /usr/mailsuite/bin/doveadm() [0x40fea6] ->
/usr/mailsuite/bin/doveadm(doveadm_mail_single_user+0x154) [0x410069] ->
/usr/mailsuite/bin/doveadm() [0x41090a] ->
/usr/mailsuite/bin/doveadm(doveadm_mail_try_run+0xac) [0x410b81] ->
/usr/mailsuite/bin/doveadm(main+0x28d) [0x41a92c] ->
/lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xfd) [0x7fe8a8cc9ead] ->
/usr/mailsuite/bin/doveadm() [0x40f499]
==========================================================

And Solr log, at the same time:
==========================================================
2013-02-01 18:03:53.342:INFO::Logging to STDERR via
org.mortbay.log.StdErrLog
2013-02-01 18:03:53.425:INFO::jetty-6.1-SNAPSHOT
01.02.2013 18:03:53 org.apache.solr.core.SolrResourceLoader locateSolrHome
INFO: JNDI not configured for solr (NoInitialContextEx)
01.02.2013 18:03:53 org.apache.solr.core.SolrResourceLoader locateSolrHome
INFO: solr home defaulted to 'solr/' (could not find system property or
JNDI)
01.02.2013 18:03:53 org.apache.solr.core.SolrResourceLoader 
INFO: new SolrResourceLoader for deduced Solr Home: 'solr/'
01.02.2013 18:03:53 org.apache.solr.servlet.SolrDispatchFilter init
INFO: SolrDispatchFilter.init()
01.02.2013 18:03:53 org.apache.solr.core.SolrResourceLoader locateSolrHome
INFO: JNDI not configured for solr (NoInitialContextEx)
01.02.2013 18:03:53 org.apache.solr.core.SolrResourceLoader locateSolrHome
INFO: solr home defaulted to 'solr/' (could not find system property or
JNDI)
01.02.2013 18:03:53 org.apache.solr.core.CoreContainerSInitializer
initialize
INFO: looking for solr.xml:
/home/valerius/apache-solr-3.6.2/example/solr/solr.xml
01.02.2013 18:03:53 org.apache.solr.core.CoreContainer load
INFO: Loading CoreContainer using Solr Home: 'solr/'
01.02.2013 18:03:53 org.apache.solr.core.SolrResourceLoader 
INFO: new SolrResourceLoader for directory: 'solr/'
01.02.2013 18:03:53 org.apache.solr.core.CoreContainer create
INFO: Creating SolrCore '' using instanceDir: solr/.
01.02.2013 18:03:53 org.apache.solr.core.SolrResourceLoader 
INFO: new SolrResourceLoader for directory: 'solr/./'
01.02.2013 18:03:53 org.apache.solr.core.SolrConfig initLibs
INFO: Adding specified lib dirs to ClassLoader
01.02.2013 18:03:53 org.apache.solr.core.SolrResourceLoader
replaceClassLoader
INFO: Adding
'file:/home/valerius/apache-solr-3.6.2/dist/apache-solr-cell-3.6.2.jar' to
classloader
01.02.2013 18:03:53 org.apache.solr.core.SolrResourceLoader
replaceClassLoader
INFO: Adding
'file:/home/valerius/apache-solr-3.6.2/contrib/extraction/lib/poi-ooxml-3.8-beta4.jar'
to classloader
01.02.2013 18:03:53 org.apache.solr.core.SolrResourceLoader
replaceClassLoader
INFO: Adding
'file:/home/valerius/apache-solr-3.6.2/contrib/extraction/lib/jdom-1.0.jar'
to classloader
01.02.2013 18:03:53 org.apache.solr.core.SolrResourceLoader
replaceClassLoader
INFO: Adding
'file:/home/valerius/apache-solr-3.6.2/contrib/extraction/lib/bcprov-jdk15-1.45.jar'
to classloader
01.02.2013 18:03:53 org.apache.solr.core.SolrResourceLoader
replaceClassLoader
INFO: Adding
'file:/home/valerius/apache-solr-3.6.2/contrib/extraction/lib/xmlbeans-2.3.0.jar'
to classloader
01.02.2013 18:03:53 org.apache.solr.core.SolrResourceLoader
replaceClassLoader
INFO: Adding
'file:/home/valerius/apache-solr-3.6.2/contrib/extraction/lib/boilerpipe-1.1.0.jar'
to classloader
01.02.2013 18:03:53 org.apache.solr.core.SolrResourceLoader
replaceClassLoader
INFO: Adding
'file:/home/valerius/apache-solr-3.6.2/contrib/extraction/lib/xercesImpl-2.8.1.jar'
to classloader
01.02.2013 18:03:53 org.apache.solr.core.SolrResourceLoader
replaceClassLoader
INFO: Adding
'file:/home/valerius/apache-solr-3.6.2/contrib/extraction/lib/tika-core-1.0.jar'
to classloader
01.02.2013 18:03:53 org.apache.solr.core.SolrResourceLoader
replaceClassLoader
INFO: Adding
'file:/home/valerius/apache-solr-3.6.2/contrib/extraction/lib/metadata-extractor-2.4.0-beta-1.jar'
to classloader
01.02.2013 18:03:53 org.apache.solr.core.SolrResourceLoader
replaceClassLoader
INFO: Adding
'file:/home/valerius/apache-solr-3.6.2/contrib/extraction/lib/apache-mime4j-core-0.7.jar'
to classloader
01.02.2013 18:03:53 org.apache.solr.core.SolrResourceLoader
replaceClassLoader
INFO: Adding
'file:/home/valerius/apache-solr-3.6.2/contrib/extraction/lib/fontbox-1.6.0.jar'
to classloader
01.02.2013 18:03:53 org.apache.solr.core.SolrResourceLoader
replaceClassLoader
INFO: Adding
'file:/home/valerius/apache-solr-3.6.2/contrib/extraction/lib/pdfbox-1.6.0.jar'
to classloader
01.02.2013 18:03:53 org.apache.solr.core.SolrResourceLoader
replaceClassLoader
INFO: Adding
'file:/home/valerius/apache-solr-3.6.2/contrib/extraction/lib/dom4j-1.6.1.jar'
to classloader
01.02.2013 18:03:53 org.apache.solr.core.SolrResourceLoader
replaceClassLoader
INFO: Adding
'file:/home/valerius/apache-solr-3.6.2/contrib/extraction/lib/asm-3.1.jar'
to classloader
01.02.2013 18:03:53 org.apache.solr.core.SolrResourceLoader
replaceClassLoader
INFO: Adding
'file:/home/valerius/apache-solr-3.6.2/contrib/extraction/lib/jempbox-1.6.0.jar'
to classloader
01.02.2013 18:03:53 org.apache.solr.core.SolrResourceLoader
replaceClassLoader
INFO: Adding
'file:/home/valerius/apache-solr-3.6.2/contrib/extraction/lib/poi-ooxml-schemas-3.8-beta4.jar'
to classloader
01.02.2013 18:03:53 org.apache.solr.core.SolrResourceLoader
replaceClassLoader
INFO: Adding
'file:/home/valerius/apache-solr-3.6.2/contrib/extraction/lib/rome-0.9.jar'
to classloader
01.02.2013 18:03:53 org.apache.solr.core.SolrResourceLoader
replaceClassLoader
INFO: Adding
'file:/home/valerius/apache-solr-3.6.2/contrib/extraction/lib/bcmail-jdk15-1.45.jar'
to classloader
01.02.2013 18:03:53 org.apache.solr.core.SolrResourceLoader
replaceClassLoader
INFO: Adding
'file:/home/valerius/apache-solr-3.6.2/contrib/extraction/lib/tagsoup-1.2.1.jar'
to classloader
01.02.2013 18:03:53 org.apache.solr.core.SolrResourceLoader
replaceClassLoader
INFO: Adding
'file:/home/valerius/apache-solr-3.6.2/contrib/extraction/lib/icu4j-4.8.1.1.jar'
to classloader
01.02.2013 18:03:53 org.apache.solr.core.SolrResourceLoader
replaceClassLoader
INFO: Adding
'file:/home/valerius/apache-solr-3.6.2/contrib/extraction/lib/poi-3.8-beta4.jar'
to classloader
01.02.2013 18:03:53 org.apache.solr.core.SolrResourceLoader
replaceClassLoader
INFO: Adding
'file:/home/valerius/apache-solr-3.6.2/contrib/extraction/lib/tika-parsers-1.0.jar'
to classloader
01.02.2013 18:03:53 org.apache.solr.core.SolrResourceLoader
replaceClassLoader
INFO: Adding
'file:/home/valerius/apache-solr-3.6.2/contrib/extraction/lib/poi-scratchpad-3.8-beta4.jar'
to classloader
01.02.2013 18:03:53 org.apache.solr.core.SolrResourceLoader
replaceClassLoader
INFO: Adding
'file:/home/valerius/apache-solr-3.6.2/contrib/extraction/lib/commons-compress-1.3.jar'
to classloader
01.02.2013 18:03:53 org.apache.solr.core.SolrResourceLoader
replaceClassLoader
INFO: Adding
'file:/home/valerius/apache-solr-3.6.2/contrib/extraction/lib/xml-apis-1.0.b2.jar'
to classloader
01.02.2013 18:03:53 org.apache.solr.core.SolrResourceLoader
replaceClassLoader
INFO: Adding
'file:/home/valerius/apache-solr-3.6.2/contrib/extraction/lib/apache-mime4j-dom-0.7.jar'
to classloader
01.02.2013 18:03:53 org.apache.solr.core.SolrResourceLoader
replaceClassLoader
INFO: Adding
'file:/home/valerius/apache-solr-3.6.2/dist/apache-solr-clustering-3.6.2.jar'
to classloader
01.02.2013 18:03:53 org.apache.solr.core.SolrResourceLoader
replaceClassLoader
INFO: Adding
'file:/home/valerius/apache-solr-3.6.2/contrib/clustering/lib/jackson-mapper-asl-1.7.4.jar'
to classloader
01.02.2013 18:03:53 org.apache.solr.core.SolrResourceLoader
replaceClassLoader
INFO: Adding
'file:/home/valerius/apache-solr-3.6.2/contrib/clustering/lib/mahout-collections-0.3.jar'
to classloader
01.02.2013 18:03:53 org.apache.solr.core.SolrResourceLoader
replaceClassLoader
INFO: Adding
'file:/home/valerius/apache-solr-3.6.2/contrib/clustering/lib/mahout-math-0.3.jar'
to classloader
01.02.2013 18:03:53 org.apache.solr.core.SolrResourceLoader
replaceClassLoader
INFO: Adding
'file:/home/valerius/apache-solr-3.6.2/contrib/clustering/lib/hppc-0.3.4-jdk15.jar'
to classloader
01.02.2013 18:03:53 org.apache.solr.core.SolrResourceLoader
replaceClassLoader
INFO: Adding
'file:/home/valerius/apache-solr-3.6.2/contrib/clustering/lib/carrot2-core-3.5.0.1.jar'
to classloader
01.02.2013 18:03:53 org.apache.solr.core.SolrResourceLoader
replaceClassLoader
INFO: Adding
'file:/home/valerius/apache-solr-3.6.2/contrib/clustering/lib/jackson-core-asl-1.7.4.jar'
to classloader
01.02.2013 18:03:53 org.apache.solr.core.SolrResourceLoader
replaceClassLoader
INFO: Adding
'file:/home/valerius/apache-solr-3.6.2/contrib/clustering/lib/simple-xml-2.4.1.jar'
to classloader
01.02.2013 18:03:53 org.apache.solr.core.SolrResourceLoader
replaceClassLoader
INFO: Adding
'file:/home/valerius/apache-solr-3.6.2/dist/apache-solr-dataimporthandler-3.6.2.jar'
to classloader
01.02.2013 18:03:53 org.apache.solr.core.SolrResourceLoader
replaceClassLoader
INFO: Adding
'file:/home/valerius/apache-solr-3.6.2/contrib/dataimporthandler/lib/mail-1.4.1.jar'
to classloader
01.02.2013 18:03:53 org.apache.solr.core.SolrResourceLoader
replaceClassLoader
INFO: Adding
'file:/home/valerius/apache-solr-3.6.2/contrib/dataimporthandler/lib/activation-1.1.jar'
to classloader
01.02.2013 18:03:53 org.apache.solr.core.SolrResourceLoader
replaceClassLoader
INFO: Adding
'file:/home/valerius/apache-solr-3.6.2/dist/apache-solr-langid-3.6.2.jar'
to classloader
01.02.2013 18:03:53 org.apache.solr.core.SolrResourceLoader
replaceClassLoader
INFO: Adding
'file:/home/valerius/apache-solr-3.6.2/contrib/langid/lib/langdetect-1.1-20120112.jar'
to classloader
01.02.2013 18:03:53 org.apache.solr.core.SolrResourceLoader
replaceClassLoader
INFO: Adding
'file:/home/valerius/apache-solr-3.6.2/contrib/langid/lib/jsonic-1.2.7.jar'
to classloader
01.02.2013 18:03:53 org.apache.solr.core.SolrResourceLoader
replaceClassLoader
INFO: Adding
'file:/home/valerius/apache-solr-3.6.2/dist/apache-solr-velocity-3.6.2.jar'
to classloader
01.02.2013 18:03:53 org.apache.solr.core.SolrResourceLoader
replaceClassLoader
INFO: Adding
'file:/home/valerius/apache-solr-3.6.2/contrib/velocity/lib/velocity-1.6.4.jar'
to classloader
01.02.2013 18:03:53 org.apache.solr.core.SolrResourceLoader
replaceClassLoader
INFO: Adding
'file:/home/valerius/apache-solr-3.6.2/contrib/velocity/lib/commons-collections-3.2.1.jar'
to classloader
01.02.2013 18:03:53 org.apache.solr.core.SolrResourceLoader
replaceClassLoader
INFO: Adding
'file:/home/valerius/apache-solr-3.6.2/contrib/velocity/lib/commons-beanutils-1.7.0.jar'
to classloader
01.02.2013 18:03:53 org.apache.solr.core.SolrResourceLoader
replaceClassLoader
INFO: Adding
'file:/home/valerius/apache-solr-3.6.2/contrib/velocity/lib/velocity-tools-2.0.jar'
to classloader
01.02.2013 18:03:53 org.apache.solr.core.SolrConfig 
INFO: Using Lucene MatchVersion: LUCENE_36
01.02.2013 18:03:54 org.apache.solr.core.SolrConfig 
INFO: Loaded SolrConfig: solrconfig.xml
01.02.2013 18:03:54 org.apache.solr.schema.IndexSchema readSchema
INFO: Reading Solr Schema
01.02.2013 18:03:54 org.apache.solr.schema.IndexSchema readSchema
INFO: Schema name=dovecot
01.02.2013 18:03:54 org.apache.solr.util.plugin.AbstractPluginLoader load
INFO: created string: org.apache.solr.schema.StrField
01.02.2013 18:03:54 org.apache.solr.util.plugin.AbstractPluginLoader load
INFO: created long: org.apache.solr.schema.LongField
01.02.2013 18:03:54 org.apache.solr.util.plugin.AbstractPluginLoader load
INFO: created slong: org.apache.solr.schema.SortableLongField
01.02.2013 18:03:54 org.apache.solr.util.plugin.AbstractPluginLoader load
INFO: created float: org.apache.solr.schema.FloatField
01.02.2013 18:03:54 org.apache.solr.util.plugin.AbstractPluginLoader load
INFO: created boolean: org.apache.solr.schema.BoolField
01.02.2013 18:03:54 org.apache.solr.util.plugin.AbstractPluginLoader load
INFO: created : org.apache.solr.analysis.WhitespaceTokenizerFactory
01.02.2013 18:03:54 org.apache.solr.util.plugin.AbstractPluginLoader load
INFO: created : org.apache.solr.analysis.SynonymFilterFactory
01.02.2013 18:03:54 org.apache.solr.util.plugin.AbstractPluginLoader load
INFO: created : org.apache.solr.analysis.StopFilterFactory
01.02.2013 18:03:54 org.apache.solr.util.plugin.AbstractPluginLoader load
INFO: created : org.apache.solr.analysis.WordDelimiterFilterFactory
01.02.2013 18:03:54 org.apache.solr.util.plugin.AbstractPluginLoader load
INFO: created : org.apache.solr.analysis.LowerCaseFilterFactory
01.02.2013 18:03:54 org.apache.solr.util.plugin.AbstractPluginLoader load
INFO: created : org.apache.solr.analysis.SnowballPorterFilterFactory
01.02.2013 18:03:54 org.apache.solr.util.plugin.AbstractPluginLoader load
INFO: created : org.apache.solr.analysis.RemoveDuplicatesTokenFilterFactory
01.02.2013 18:03:54 org.apache.solr.util.plugin.AbstractPluginLoader load
INFO: created : org.apache.solr.analysis.WhitespaceTokenizerFactory
01.02.2013 18:03:54 org.apache.solr.util.plugin.AbstractPluginLoader load
INFO: created : org.apache.solr.analysis.StopFilterFactory
01.02.2013 18:03:54 org.apache.solr.util.plugin.AbstractPluginLoader load
INFO: created : org.apache.solr.analysis.WordDelimiterFilterFactory
01.02.2013 18:03:54 org.apache.solr.util.plugin.AbstractPluginLoader load
INFO: created : org.apache.solr.analysis.LowerCaseFilterFactory
01.02.2013 18:03:54 org.apache.solr.util.plugin.AbstractPluginLoader load
INFO: created : org.apache.solr.analysis.SnowballPorterFilterFactory
01.02.2013 18:03:54 org.apache.solr.util.plugin.AbstractPluginLoader load
INFO: created : org.apache.solr.analysis.NGramFilterFactory
01.02.2013 18:03:54 org.apache.solr.util.plugin.AbstractPluginLoader load
INFO: created : org.apache.solr.analysis.RemoveDuplicatesTokenFilterFactory
01.02.2013 18:03:54 org.apache.solr.util.plugin.AbstractPluginLoader load
INFO: created text: org.apache.solr.schema.TextField
01.02.2013 18:03:54 org.apache.solr.schema.IndexSchema readSchema
INFO: default search field in schema is body
01.02.2013 18:03:54 org.apache.solr.schema.IndexSchema readSchema
INFO: query parser default operator is AND
01.02.2013 18:03:54 org.apache.solr.schema.IndexSchema readSchema
INFO: unique key field: id
01.02.2013 18:03:54 org.apache.solr.core.SolrCore 
INFO: [] Opening new SolrCore at solr/./, dataDir=solr/./data/
01.02.2013 18:03:54 org.apache.solr.core.JmxMonitoredMap 
INFO: JMX monitoring is enabled. Adding Solr mbeans to JMX Server:
com.sun.jmx.mbeanserver.JmxMBeanServer at 27b4c1d7
01.02.2013 18:03:54 org.apache.solr.core.SolrCore initListeners
INFO: [] Added SolrEventListener for newSearcher:
org.apache.solr.core.QuerySenderListener{queries=[]}
01.02.2013 18:03:54 org.apache.solr.core.SolrCore initListeners
INFO: [] Added SolrEventListener for firstSearcher:
org.apache.solr.core.QuerySenderListener{queries=[{q=static firstSearcher
warming in solrconfig.xml}]}
01.02.2013 18:03:54 org.apache.solr.core.SolrCore initWriters
INFO: created json: solr.JSONResponseWriter
01.02.2013 18:03:54 org.apache.solr.core.SolrCore initWriters
INFO: adding lazy queryResponseWriter: solr.VelocityResponseWriter
01.02.2013 18:03:54 org.apache.solr.core.SolrCore initWriters
INFO: created velocity: solr.VelocityResponseWriter
01.02.2013 18:03:54 org.apache.solr.core.SolrCore initWriters
INFO: created xslt: solr.XSLTResponseWriter
01.02.2013 18:03:54 org.apache.solr.response.XSLTResponseWriter init
INFO: xsltCacheLifetimeSeconds=5
01.02.2013 18:03:54 org.apache.solr.core.RequestHandlers
initHandlersFromConfig
INFO: created /select: solr.SearchHandler
01.02.2013 18:03:54 org.apache.solr.core.RequestHandlers
initHandlersFromConfig
INFO: created /browse: solr.SearchHandler
01.02.2013 18:03:54 org.apache.solr.core.RequestHandlers
initHandlersFromConfig
INFO: created /update: solr.XmlUpdateRequestHandler
01.02.2013 18:03:54 org.apache.solr.core.RequestHandlers
initHandlersFromConfig
INFO: created /update/javabin: solr.BinaryUpdateRequestHandler
01.02.2013 18:03:54 org.apache.solr.core.RequestHandlers
initHandlersFromConfig
INFO: adding lazy requestHandler: solr.CSVRequestHandler
01.02.2013 18:03:54 org.apache.solr.core.RequestHandlers
initHandlersFromConfig
INFO: created /update/csv: solr.CSVRequestHandler
01.02.2013 18:03:54 org.apache.solr.core.RequestHandlers
initHandlersFromConfig
INFO: adding lazy requestHandler: solr.JsonUpdateRequestHandler
01.02.2013 18:03:54 org.apache.solr.core.RequestHandlers
initHandlersFromConfig
INFO: created /update/json: solr.JsonUpdateRequestHandler
01.02.2013 18:03:54 org.apache.solr.core.RequestHandlers
initHandlersFromConfig
INFO: adding lazy requestHandler: solr.extraction.ExtractingRequestHandler
01.02.2013 18:03:54 org.apache.solr.core.RequestHandlers
initHandlersFromConfig
INFO: created /update/extract: solr.extraction.ExtractingRequestHandler
01.02.2013 18:03:54 org.apache.solr.core.RequestHandlers
initHandlersFromConfig
INFO: adding lazy requestHandler: solr.XsltUpdateRequestHandler
01.02.2013 18:03:54 org.apache.solr.core.RequestHandlers
initHandlersFromConfig
INFO: created /update/xslt: solr.XsltUpdateRequestHandler
01.02.2013 18:03:54 org.apache.solr.core.RequestHandlers
initHandlersFromConfig
INFO: adding lazy requestHandler: solr.FieldAnalysisRequestHandler
01.02.2013 18:03:54 org.apache.solr.core.RequestHandlers
initHandlersFromConfig
INFO: created /analysis/field: solr.FieldAnalysisRequestHandler
01.02.2013 18:03:54 org.apache.solr.core.RequestHandlers
initHandlersFromConfig
INFO: adding lazy requestHandler: solr.DocumentAnalysisRequestHandler
01.02.2013 18:03:54 org.apache.solr.core.RequestHandlers
initHandlersFromConfig
INFO: created /analysis/document: solr.DocumentAnalysisRequestHandler
01.02.2013 18:03:54 org.apache.solr.core.RequestHandlers
initHandlersFromConfig
INFO: created /admin/: solr.admin.AdminHandlers
01.02.2013 18:03:54 org.apache.solr.core.RequestHandlers
initHandlersFromConfig
INFO: created /admin/ping: solr.PingRequestHandler
01.02.2013 18:03:54 org.apache.solr.core.RequestHandlers
initHandlersFromConfig
INFO: created /debug/dump: solr.DumpRequestHandler
01.02.2013 18:03:54 org.apache.solr.core.RequestHandlers
initHandlersFromConfig
INFO: adding lazy requestHandler: solr.SearchHandler
01.02.2013 18:03:54 org.apache.solr.core.RequestHandlers
initHandlersFromConfig
INFO: created /spell: solr.SearchHandler
01.02.2013 18:03:54 org.apache.solr.core.RequestHandlers
initHandlersFromConfig
INFO: adding lazy requestHandler: solr.SearchHandler
01.02.2013 18:03:54 org.apache.solr.core.RequestHandlers
initHandlersFromConfig
INFO: created /tvrh: solr.SearchHandler
01.02.2013 18:03:54 org.apache.solr.core.RequestHandlers
initHandlersFromConfig
INFO: adding lazy requestHandler: solr.SearchHandler
01.02.2013 18:03:54 org.apache.solr.core.RequestHandlers
initHandlersFromConfig
INFO: created /terms: solr.SearchHandler
01.02.2013 18:03:54 org.apache.solr.core.RequestHandlers
initHandlersFromConfig
INFO: adding lazy requestHandler: solr.SearchHandler
01.02.2013 18:03:54 org.apache.solr.core.RequestHandlers
initHandlersFromConfig
INFO: created /elevate: solr.SearchHandler
01.02.2013 18:03:54 org.apache.solr.search.SolrIndexSearcher 
INFO: Opening Searcher at 5c29ea31 main
01.02.2013 18:03:54 org.apache.solr.update.CommitTracker 
INFO: commitTracker AutoCommit: disabled
01.02.2013 18:03:54 org.apache.solr.handler.component.SpellCheckComponent
inform
INFO: Initializing spell checkers
01.02.2013 18:03:54 org.apache.solr.handler.component.SpellCheckComponent
inform
INFO: No queryConverter defined, using default converter
01.02.2013 18:03:54
org.apache.solr.handler.component.QueryElevationComponent inform
INFO: Loading QueryElevation from:
/home/valerius/apache-solr-3.6.2/example/solr/./conf/elevate.xml
01.02.2013 18:03:54 org.apache.solr.handler.component.SearchHandler inform
INFO: Adding 
component:org.apache.solr.handler.component.QueryComponent at 4d16318b
01.02.2013 18:03:54 org.apache.solr.handler.component.SearchHandler inform
INFO: Adding 
component:org.apache.solr.handler.component.FacetComponent at 6c0ec436
01.02.2013 18:03:54 org.apache.solr.handler.component.SearchHandler inform
INFO: Adding 
component:org.apache.solr.handler.component.MoreLikeThisComponent at 3d73eca6
01.02.2013 18:03:54 org.apache.solr.handler.component.SearchHandler inform
INFO: Adding 
component:org.apache.solr.handler.component.HighlightComponent at 5b5a5cf
01.02.2013 18:03:54 org.apache.solr.handler.component.SearchHandler inform
INFO: Adding 
component:org.apache.solr.handler.component.StatsComponent at 5898bbf6
01.02.2013 18:03:54 org.apache.solr.handler.component.SearchHandler inform
INFO: Adding  debug
component:org.apache.solr.handler.component.DebugComponent at 135c40eb
01.02.2013 18:03:54
org.apache.solr.handler.component.HttpShardHandlerFactory getParameter
INFO: Setting socketTimeout to: 0
01.02.2013 18:03:54
org.apache.solr.handler.component.HttpShardHandlerFactory getParameter
INFO: Setting urlScheme to: http://
01.02.2013 18:03:54
org.apache.solr.handler.component.HttpShardHandlerFactory getParameter
INFO: Setting connTimeout to: 0
01.02.2013 18:03:54
org.apache.solr.handler.component.HttpShardHandlerFactory getParameter
INFO: Setting maxConnectionsPerHost to: 20
01.02.2013 18:03:54
org.apache.solr.handler.component.HttpShardHandlerFactory getParameter
INFO: Setting corePoolSize to: 0
01.02.2013 18:03:54
org.apache.solr.handler.component.HttpShardHandlerFactory getParameter
INFO: Setting maximumPoolSize to: 2147483647
01.02.2013 18:03:54
org.apache.solr.handler.component.HttpShardHandlerFactory getParameter
INFO: Setting maxThreadIdleTime to: 5
01.02.2013 18:03:54
org.apache.solr.handler.component.HttpShardHandlerFactory getParameter
INFO: Setting sizeOfQueue to: -1
01.02.2013 18:03:54
org.apache.solr.handler.component.HttpShardHandlerFactory getParameter
INFO: Setting fairnessPolicy to: false
01.02.2013 18:03:54 org.apache.solr.handler.component.SearchHandler inform
INFO: Adding 
component:org.apache.solr.handler.component.QueryComponent at 4d16318b
01.02.2013 18:03:54 org.apache.solr.handler.component.SearchHandler inform
INFO: Adding 
component:org.apache.solr.handler.component.FacetComponent at 6c0ec436
01.02.2013 18:03:54 org.apache.solr.handler.component.SearchHandler inform
INFO: Adding 
component:org.apache.solr.handler.component.MoreLikeThisComponent at 3d73eca6
01.02.2013 18:03:54 org.apache.solr.handler.component.SearchHandler inform
INFO: Adding 
component:org.apache.solr.handler.component.HighlightComponent at 5b5a5cf
01.02.2013 18:03:54 org.apache.solr.handler.component.SearchHandler inform
INFO: Adding 
component:org.apache.solr.handler.component.StatsComponent at 5898bbf6
01.02.2013 18:03:54 org.apache.solr.handler.component.SearchHandler inform
INFO: Adding 
component:org.apache.solr.handler.component.SpellCheckComponent at 18f2225f
01.02.2013 18:03:54 org.apache.solr.handler.component.SearchHandler inform
INFO: Adding  debug
component:org.apache.solr.handler.component.DebugComponent at 135c40eb
01.02.2013 18:03:54
org.apache.solr.handler.component.HttpShardHandlerFactory getParameter
INFO: Setting socketTimeout to: 0
01.02.2013 18:03:54
org.apache.solr.handler.component.HttpShardHandlerFactory getParameter
INFO: Setting urlScheme to: http://
01.02.2013 18:03:54
org.apache.solr.handler.component.HttpShardHandlerFactory getParameter
INFO: Setting connTimeout to: 0
01.02.2013 18:03:54
org.apache.solr.handler.component.HttpShardHandlerFactory getParameter
INFO: Setting maxConnectionsPerHost to: 20
01.02.2013 18:03:54
org.apache.solr.handler.component.HttpShardHandlerFactory getParameter
INFO: Setting corePoolSize to: 0
01.02.2013 18:03:54
org.apache.solr.handler.component.HttpShardHandlerFactory getParameter
INFO: Setting maximumPoolSize to: 2147483647
01.02.2013 18:03:54
org.apache.solr.handler.component.HttpShardHandlerFactory getParameter
INFO: Setting maxThreadIdleTime to: 5
01.02.2013 18:03:54
org.apache.solr.handler.component.HttpShardHandlerFactory getParameter
INFO: Setting sizeOfQueue to: -1
01.02.2013 18:03:54
org.apache.solr.handler.component.HttpShardHandlerFactory getParameter
INFO: Setting fairnessPolicy to: false
01.02.2013 18:03:54 org.apache.solr.core.QuerySenderListener newSearcher
INFO: QuerySenderListener sending requests to Searcher at 5c29ea31 main
01.02.2013 18:03:54 org.apache.solr.core.CoreContainer register
INFO: registering core: 
01.02.2013 18:03:54 org.apache.solr.servlet.SolrDispatchFilter init
INFO: user.dir=/home/valerius/apache-solr-3.6.2/example
01.02.2013 18:03:54 org.apache.solr.servlet.SolrDispatchFilter init
INFO: SolrDispatchFilter.init() done
01.02.2013 18:03:54 org.apache.solr.common.SolrException log
SEVERE: org.apache.solr.common.SolrException: undefined field text
    at
org.apache.solr.schema.IndexSchema.getDynamicFieldType(IndexSchema.java:1330)
    at
org.apache.solr.schema.IndexSchemaSSolrQueryAnalyzer.getAnalyzer(IndexSchema.java:408)
    at
org.apache.solr.schema.IndexSchemaSSolrIndexAnalyzer.reusableTokenStream(IndexSchema.java:383)
    at
org.apache.lucene.queryParser.QueryParser.getFieldQuery(QueryParser.java:574)
    at
org.apache.solr.search.SolrQueryParser.getFieldQuery(SolrQueryParser.java:206)
    at
org.apache.lucene.queryParser.QueryParser.Term(QueryParser.java:1436)
    at
org.apache.lucene.queryParser.QueryParser.Clause(QueryParser.java:1319)
    at
org.apache.lucene.queryParser.QueryParser.Query(QueryParser.java:1245)
    at
org.apache.lucene.queryParser.QueryParser.TopLevelQuery(QueryParser.java:1234)
    at
org.apache.lucene.queryParser.QueryParser.parse(QueryParser.java:206)
    at
org.apache.solr.search.LuceneQParser.parse(LuceneQParserPlugin.java:79)
    at org.apache.solr.search.QParser.getQuery(QParser.java:143)
    at
org.apache.solr.handler.component.QueryComponent.prepare(QueryComponent.java:105)
    at
org.apache.solr.handler.component.SearchHandler.handleRequestBody(SearchHandler.java:165)
    at
org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:129)
    at org.apache.solr.core.SolrCore.execute(SolrCore.java:1376)
    at
org.apache.solr.core.QuerySenderListener.newSearcher(QuerySenderListener.java:59)
    at org.apache.solr.core.SolrCoreS3.call(SolrCore.java:1182)
    at java.util.concurrent.FutureTaskSSync.innerRun(FutureTask.java:334)
    at java.util.concurrent.FutureTask.run(FutureTask.java:166)
    at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
    at
java.util.concurrent.ThreadPoolExecutorSWorker.run(ThreadPoolExecutor.java:603)
    at java.lang.Thread.run(Thread.java:679)

01.02.2013 18:03:54 org.apache.solr.core.SolrCore execute
INFO: [] webapp=null path=null
params={event=firstSearcher&q=static+firstSearcher+warming+in+solrconfig.xml}
status=400 QTime=22 
01.02.2013 18:03:54 org.apache.solr.core.QuerySenderListener newSearcher
INFO: QuerySenderListener done.
01.02.2013 18:03:54
org.apache.solr.handler.component.SpellCheckComponentSSpellCheckerListener
newSearcher
INFO: Loading spell index for spellchecker: default
01.02.2013 18:03:54 org.apache.solr.core.SolrCore registerSearcher
INFO: [] Registered new searcher Searcher at 5c29ea31 main
01.02.2013 18:03:54 org.apache.solr.servlet.SolrServlet init
INFO: SolrServlet.init()
01.02.2013 18:03:54 org.apache.solr.core.SolrResourceLoader locateSolrHome
INFO: JNDI not configured for solr (NoInitialContextEx)
01.02.2013 18:03:54 org.apache.solr.core.SolrResourceLoader locateSolrHome
INFO: solr home defaulted to 'solr/' (could not find system property or
JNDI)
01.02.2013 18:03:54 org.apache.solr.servlet.SolrServlet init
INFO: SolrServlet.init() done
01.02.2013 18:03:54 org.apache.solr.core.SolrResourceLoader locateSolrHome
INFO: JNDI not configured for solr (NoInitialContextEx)
01.02.2013 18:03:54 org.apache.solr.core.SolrResourceLoader locateSolrHome
INFO: solr home defaulted to 'solr/' (could not find system property or
JNDI)
01.02.2013 18:03:54 org.apache.solr.servlet.SolrUpdateServlet init
INFO: SolrUpdateServlet.init() done
2013-02-01 18:03:54.449:INFO::Started SocketConnector at 0.0.0.0:8983
01.02.2013 18:04:40 org.apache.solr.core.SolrDeletionPolicy onInit
INFO: SolrDeletionPolicy.onInit: commits:num=1
   
commit{dir=/home/valerius/apache-solr-3.6.2/example/solr/data/index,segFN=segments_1,version=1359741540635,generation=1,filenames=[segments_1]
01.02.2013 18:04:40 org.apache.solr.core.SolrDeletionPolicy updateCommits
INFO: newest commit = 1359741540635
01.02.2013 18:05:05 org.apache.solr.update.processor.LogUpdateProcessor
finish
INFO:
{add=[1/5cc6513b4dc6de5093660000b304ded5/valerius at test.afterlogic.com,
48/5cc6513b4dc6de5093660000b304ded5/valerius at test.afterlogic.com]} 0 24629
01.02.2013 18:05:05 org.apache.solr.common.SolrException log
SEVERE: java.lang.OutOfMemoryError: Java heap space
    at
org.apache.lucene.index.FreqProxTermsWriterPerFieldSFreqProxPostingsArray.(FreqProxTermsWriterPerField.java:193)
    at
org.apache.lucene.index.FreqProxTermsWriterPerFieldSFreqProxPostingsArray.newInstance(FreqProxTermsWriterPerField.java:204)
    at
org.apache.lucene.index.ParallelPostingsArray.grow(ParallelPostingsArray.java:48)
    at
org.apache.lucene.index.TermsHashPerField.growParallelPostingsArray(TermsHashPerField.java:157)
    at
org.apache.lucene.index.TermsHashPerField.add(TermsHashPerField.java:460)
    at
org.apache.lucene.index.DocInverterPerField.processFields(DocInverterPerField.java:189)
    at
org.apache.lucene.index.DocFieldProcessorPerThread.processDocument(DocFieldProcessorPerThread.java:278)
    at
org.apache.lucene.index.DocumentsWriter.updateDocument(DocumentsWriter.java:766)
    at
org.apache.lucene.index.IndexWriter.updateDocument(IndexWriter.java:2328)
    at
org.apache.lucene.index.IndexWriter.updateDocument(IndexWriter.java:2300)
    at
org.apache.solr.update.DirectUpdateHandler2.addDoc(DirectUpdateHandler2.java:240)
    at
org.apache.solr.update.processor.RunUpdateProcessor.processAdd(RunUpdateProcessorFactory.java:61)
    at
org.apache.solr.update.processor.LogUpdateProcessor.processAdd(LogUpdateProcessorFactory.java:115)
    at org.apache.solr.handler.XMLLoader.processUpdate(XMLLoader.java:157)
    at org.apache.solr.handler.XMLLoader.load(XMLLoader.java:79)
    at
org.apache.solr.handler.ContentStreamHandlerBase.handleRequestBody(ContentStreamHandlerBase.java:58)
    at
org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:129)
    at org.apache.solr.core.SolrCore.execute(SolrCore.java:1376)
    at
org.apache.solr.servlet.SolrDispatchFilter.execute(SolrDispatchFilter.java:365)
    at
org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:260)
    at
org.mortbay.jetty.servlet.ServletHandlerSCachedChain.doFilter(ServletHandler.java:1212)
    at
org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:399)
    at
org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.java:216)
    at
org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:182)
    at
org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:766)
    at
org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.java:450)
    at
org.mortbay.jetty.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:230)
    at
org.mortbay.jetty.handler.HandlerCollection.handle(HandlerCollection.java:114)
    at
org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152)
    at org.mortbay.jetty.Server.handle(Server.java:326)
    at
org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:542)
    at
org.mortbay.jetty.HttpConnectionSRequestHandler.content(HttpConnection.java:945)

2013-02-01 18:05:42.595:INFO::Shutdown hook executing
2013-02-01 18:05:42.596:INFO::Graceful shutdown
SocketConnector at 0.0.0.0:8983
2013-02-01 18:05:42.596:INFO::Graceful shutdown
org.mortbay.jetty.webapp.WebAppContext at 5484ff20{/solr,file:/home/valerius/apache-solr-3.6.2/example/webapps/solr.war}
2013-02-01 18:05:43.596:INFO::Stopped SocketConnector at 0.0.0.0:8983
2013-02-01 18:05:43.784:INFO::Shutdown hook complete
==========================================================

So, it seems that Dovecot tries to parse messages in the mailbox, and can't
correctly determine where the message header ends. So, it thinks that the
message header is big, and passes very big data to Solr. When trying to
index it, Solr exhausts the available memory (though, I have 8 Gb of RAM on
my machine, and java eats more than 2 Gb when indexing). Then connections
to Solr get closed, and maxfd is invalid, hence the assertion is failed.

Note also the following error

==========================================================
SEVERE: org.apache.solr.common.SolrException: undefined field text
==========================================================

before an out of memory error.

I also tried to tweak the decode2text.sh script to ignore all attachments
bigger than 1 Mb (just test if the file is bigger than 1 Mb, and if so,
return "1"). This won't help. As I understood, this is because of big
header, so attachments doesn't matter.

I separated the set of messages which cause this error (by their UID's).
So, I can give them as a testcase, the size of them all in archive is about
40 Mb. The error can be reproduced if put all these messages into an empty
mailbox, and do reindexing, via IMAP search, or via "doveadm index -u  ".

I use Dovecot version 2.1.13. My doveconf -n :
==========================================================
# 2.1.13: /usr/mailsuite/etc/dovecot/dovecot.conf
# OS: Linux 2.6.32-5-amd64 x86_64 Debian wheezy/sid ext4
auth_debug = yes
auth_debug_passwords = yes
auth_default_realm = test.afterlogic.com
auth_mechanisms = plain login
auth_socket_path = /usr/mailsuite/var/run/dovecot/auth-master
base_dir = /usr/mailsuite/var/run/dovecot/
debug_log_path = /usr/mailsuite/var/log/dovecot/debug.log
default_internal_user = exim
dict {
  domainquotadict =
mysql:/usr/mailsuite/etc/dovecot/dovecot-domain-quota-dict.conf
  realmquotadict =
mysql:/usr/mailsuite/etc/dovecot/dovecot-realm-quota-dict.conf
  userquotadict =
mysql:/usr/mailsuite/etc/dovecot/dovecot-user-quota-dict.conf
}
disable_plaintext_auth = no
info_log_path = /usr/mailsuite/var/log/dovecot/info.log
lda_mailbox_autocreate = yes
lda_mailbox_autosubscribe = yes
log_path = /usr/mailsuite/var/log/dovecot/dovecot.log
log_timestamp = "%Y-%m-%d %H:%M:%S "
mail_debug = yes
mail_gid = exim
mail_home = /usr/mailsuite/data/settings/%d/%n
mail_location = maildir:/usr/mailsuite/data/%d/%n
mail_plugins = listescape fts fts_solr virtual
mail_uid = exim
managesieve_notify_capability = mailto
managesieve_sieve_capability = fileinto reject envelope encoded-character
vacation subaddress comparator-i;ascii-numeric relational regex imap4flags
copy include variables body enotify environment mailbox date ihave spamtest
spamtestplus
mbox_write_locks = fcntl
namespace {
  inbox = yes
  location = maildir:/usr/mailsuite/data/%d/%n
  prefix = 
  separator = /
  type = private
}
namespace {
  hidden = yes
  inbox = no
  list = no
  location =
virtual:/usr/mailsuite/data/virtual/:LAYOUT=maildir++:INDEX=/usr/mailsuite/data/indexes/
  prefix = All/
  separator = /
  type = private
}
passdb {
  args = /usr/mailsuite/etc/dovecot/dovecot-sql.conf
  driver = sql
}
passdb {
  args = /usr/mailsuite/etc/dovecot/dovecot-sql.conf
  driver = sql
}
plugin {
  antispam_allow_append_to_spam = no
  antispam_backend = mailtrain
  antispam_mail_notspam = --ham
  antispam_mail_sendmail = /usr/mailsuite/scripts/sa-learn-pipe.sh
  antispam_mail_spam = --spam
  antispam_mail_tmpdir = /tmp
  antispam_signature = X-Spam-Flag
  antispam_signature_missing = error
  antispam_spam = SPAM
  antispam_spam_pattern = SPAM
  antispam_spam_pattern_ignorecase = SPAM
  antispam_trash = trash;Trash;Deleted Items; Deleted Messages
  antispam_trash_pattern = trash;Trash;Deleted *
  antispam_trash_pattern_ignorecase = trash;Deleted *
  antispam_unsure = 
  antispam_unsure_pattern = 
  antispam_unsure_pattern_ignorecase = 
  fts = solr
  fts_decoder = decode2text
  fts_solr = break-imap-search url=http://localhost:8983/solr/
  quota = dict:User quota::proxy::userquotadict
  quota2 = dict::%d:proxy::domainquotadict
  quota_rule = *:storage=100G
  quota_rule2 = Trash:storage=+20%%
  quota_rule3 = Spam:ignore
  quota_warning = storage=99%% quota-warning user 99 %d %n
  quota_warning2 = storage=95%% quota-warning user 95 %d %n
  quota_warning3 = storage=80%% quota-warning user 80 %d %n
  sieve = /usr/mailsuite/data/%d/%n/sieve.sieve
  sieve_before = /usr/mailsuite/etc/sieve/system.sieve
  sieve_dir = /usr/mailsuite/data/%d/%n/filters/
  sieve_extensions = +spamtest +spamtestplus +relational
+comparator-i;ascii-numeric
  sieve_global_dir = /usr/mailsuite/etc/sieve/
}
protocols = imap pop3 lmtp sieve
sendmail_path = /usr/mailsuite/bin/sendmail
service auth {
  unix_listener auth-client {
    group = exim
    mode = 0666
    user = exim
  }
  unix_listener auth-master {
    group = exim
    mode = 0666
    user = exim
  }
  user = Sdefault_internal_user
}
service decode2text {
  executable = script /usr/mailsuite/libexec/dovecot/decode2text.sh
  unix_listener decode2text {
    mode = 0666
  }
  user = exim
}
service dict {
  unix_listener dict {
    group = exim
    mode = 0600
    user = exim
  }
}
service imap-login {
  inet_listener imap {
    port = 143
  }
}
service imap-postlogin {
  executable = script-login /usr/mailsuite/scripts/dovecot-postlogin.sh
  user = root
}
service imap {
  executable = imap imap-postlogin
}
service indexer-worker {
  user = root
  vsz_limit = 768 M
}
service managesieve-login {
  inet_listener sieve {
    port = 4190
  }
  inet_listener sieve_deprecated {
    port = 2000
  }
  service_count = 1
  vsz_limit = 64 M
}
service quota-warning {
  executable = script /usr/mailsuite/scripts/send_mail_warnquota.sh
  unix_listener quota-warning {
    user = exim
  }
  user = exim
}
ssl_cert =

More information about the dovecot mailing list