[Dovecot] "Header is huge" in fts-solr
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 =
On 5.2.2013, at 15.58, Valery V. Sedletski valerius@afterlogic.com wrote:
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
I'm not sure why Solr would become out of memory. If it handles huge message bodies then I don't really see why it couldn't handle huge headers..
doveadm(valerius@test.afterlogic.com): Panic: file ../../../../src/plugins/fts-solr/solr-connection.c: line 548 (solr_connection_post_more): assertion failed: (maxfd >= 0)
This is hopefully fixed by v2.2, which uses its own lib-http instead of libcurl (which I'm apparently not using correctly).
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 don't know about that one.
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.
Yes.
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 ".
Is it really a message with huge header? Also MIME headers are counted as headers.
Anyway, http://hg.dovecot.org/dovecot-2.1/rev/0a932ba1f01f hopefully helps?
participants (2)
-
Timo Sirainen
-
Valery V. Sedletski