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

5 Feb 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@test.afterlogic.com): Warning:
fts-solr(valerius@test.afterlogic.com): Mailbox gmail.com UID=48 header
size is huge
doveadm(valerius@test.afterlogic.com): Warning:
fts-solr(valerius@test.afterlogic.com): Mailbox gmail.com UID=49 header
size is huge
doveadm(valerius@test.afterlogic.com): Panic: file
../../../../src/plugins/fts-solr/solr-connection.c: line 548
(solr_connection_post_more): assertion failed: (maxfd >= 0)
doveadm(valerius@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@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@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@4d16318b
01.02.2013 18:03:54 org.apache.solr.handler.component.SearchHandler inform
INFO: Adding
component:org.apache.solr.handler.component.FacetComponent@6c0ec436
01.02.2013 18:03:54 org.apache.solr.handler.component.SearchHandler inform
INFO: Adding
component:org.apache.solr.handler.component.MoreLikeThisComponent@3d73eca6
01.02.2013 18:03:54 org.apache.solr.handler.component.SearchHandler inform
INFO: Adding
component:org.apache.solr.handler.component.HighlightComponent@5b5a5cf
01.02.2013 18:03:54 org.apache.solr.handler.component.SearchHandler inform
INFO: Adding
component:org.apache.solr.handler.component.StatsComponent@5898bbf6
01.02.2013 18:03:54 org.apache.solr.handler.component.SearchHandler inform
INFO: Adding  debug
component:org.apache.solr.handler.component.DebugComponent@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@4d16318b
01.02.2013 18:03:54 org.apache.solr.handler.component.SearchHandler inform
INFO: Adding
component:org.apache.solr.handler.component.FacetComponent@6c0ec436
01.02.2013 18:03:54 org.apache.solr.handler.component.SearchHandler inform
INFO: Adding
component:org.apache.solr.handler.component.MoreLikeThisComponent@3d73eca6
01.02.2013 18:03:54 org.apache.solr.handler.component.SearchHandler inform
INFO: Adding
component:org.apache.solr.handler.component.HighlightComponent@5b5a5cf
01.02.2013 18:03:54 org.apache.solr.handler.component.SearchHandler inform
INFO: Adding
component:org.apache.solr.handler.component.StatsComponent@5898bbf6
01.02.2013 18:03:54 org.apache.solr.handler.component.SearchHandler inform
INFO: Adding
component:org.apache.solr.handler.component.SpellCheckComponent@18f2225f
01.02.2013 18:03:54 org.apache.solr.handler.component.SearchHandler inform
INFO: Adding  debug
component:org.apache.solr.handler.component.DebugComponent@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@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@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@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@test.afterlogic.com,
48/5cc6513b4dc6de5093660000b304ded5/valerius@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@0.0.0.0:8983
2013-02-01 18:05:42.596:INFO::Graceful shutdown
org.mortbay.jetty.webapp.WebAppContext@5484ff20{/solr,file:/home/valerius/apache-solr-3.6.2/example/webapps/solr.war}
2013-02-01 18:05:43.596:INFO::Stopped SocketConnector@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 =

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

Valery V. Sedletski

And Solr log, at the same time:

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

I use Dovecot version 2.1.13. My doveconf -n :