- dovecot - dovecot.org

[Dovecot] patch to fix binary attachment indexing
by Mike Abbott 22 Feb '13

22 Feb '13

FTS indexing of binary attachments is broken in dovecot-2.1.15: the binary data which fts_build_mail_real() sends to fts_build_body_block() (which sends it to fts_backend_update_build_more()) is garbled. This patch ungarbles it but I’m not positive it’s the best fix. --- dovecot-2.1.15/src/plugins/fts/fts-build-mail.c 2012-11-27 02:07:27.000000000 -0600 +++ dovecot/src/plugins/fts/fts-build-mail.c 2013-02-21 19:48:15.000000000 -0600 @@ -178,7 +178,8 @@ *binary_body_r = TRUE; key.type = FTS_BACKEND_BUILD_KEY_BODY_PART_BINARY; } - if (ctx->body_parser == NULL) + if (ctx->body_parser == NULL && + key.type != FTS_BACKEND_BUILD_KEY_BODY_PART_BINARY) ctx->body_parser = fts_parser_text_init(); key.body_content_type = content_type; key.body_content_disposition = ctx->content_disposition;

2 2

[Dovecot] error running indexer-worker as non-root user
by Mike Abbott 22 Feb '13

22 Feb '13

Using dovecot-2.1.15 if I run indexer-worker as a non-root user it fails with an error: Feb 11 13:06:47 indexer-worker: Error: user foobar: Error reading configuration: net_connect_unix(/var/run/dovecot/config) failed: Permission denied This is what I added to 10-master.conf: service indexer-worker { user = _dovecot } The wiki says it should work: <http://wiki2.dovecot.org/Services> indexer-worker [...] • user=root, but the privileges are (temporarily) dropped to the mail user's privileges after userdb lookup. If only a single UID is used, user can be set to the mail UID for higher security, because the process can't gain root privileges anymore. And the code says it should work: <src/indexer/indexer-worker.c> static void drop_privileges(void) { [...] if (set.uid != 0) { /* open config connection before dropping privileges */ Of course the config socket is locked down as it should be: srw------- 1 root daemon 0 Feb 11 13:06 /var/run/dovecot/config Here's where the error comes from: 2 libdovecot.0.dylib 0x00000001019612a0 master_service_settings_read + 2168 3 libdovecot.0.dylib 0x000000010196193e master_service_settings_cache_read + 294 4 libdovecot-storage.0.dylib 0x000000010185d9ad mail_storage_service_read_settings + 510 5 libdovecot-storage.0.dylib 0x000000010185da5d mail_storage_service_lookup + 96 6 libdovecot-storage.0.dylib 0x000000010185f06a mail_storage_service_lookup_next + 42 7 indexer-worker 0x00000001018101a1 master_connection_input + 335 8 libdovecot.0.dylib 0x0000000101972455 io_loop_call_io + 46 9 libdovecot.0.dylib 0x000000010197343e io_loop_handler_run + 214 10 libdovecot.0.dylib 0x0000000101972600 io_loop_run + 77 11 libdovecot.0.dylib 0x00000001019601ef master_service_run + 24 12 indexer-worker 0x000000010180ff17 main + 490 13 libdyld.dylib 0x00007fff89d2f7b5 start + 1 Is this a bug or am I configuring it incorrectly? Thanks.

2 2

[Dovecot] Userdb passwd and 'nologin' users
by Ben Morrow 22 Feb '13

22 Feb '13

I am running Dovecot with system users (userdb passwd), but some of those users don't have shell accounts on the IMAP server so their shell on that machine is set to /usr/sbin/nologin. Currently I am using maildirs and this is not a problem, but I am in the process of switching to dbox which means I will need a cronjob running 'doveadm purge -A'. During testing I found that those users with a 'nologin' shell are not included in the list returned by the userdb iterator, and that the iterator doesn't honour the first/last_valid_uid settings. This inconsistency seems undesirable, so the attached patch - makes lookup perform the same checks as iteration, - makes the 'nologin' check configurable, - adds a new optional check that the user owns their home directory. The last check was the one performed by qmail, and seems to me to be a more reliable 'is this a real user' check than a nologin shell. If this patch is applied, the release notes for the next release should probably mention that system users with a 'nologin' shell will no longer be allowed to log in to IMAP until the 'auth_check_nologin' setting is changed from true to false. Also, there seem to be two first/last_valid_uid settings: first_valid_uid itself, which is honoured by the storage subsystem, and auth_first_valid_uid, which is honoured by the 'passwd' userdb. Is this intentional? Ben

3 5

[Dovecot] "Header is huge" in fts-solr
by Valery V. Sedletski 22 Feb '13

22 Feb '13

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(a)test.afterlogic.com): Warning: fts-solr(valerius(a)test.afterlogic.com): Mailbox gmail.com UID=48 header size is huge doveadm(valerius(a)test.afterlogic.com): Warning: fts-solr(valerius(a)test.afterlogic.com): Mailbox gmail.com UID=49 header size is huge doveadm(valerius(a)test.afterlogic.com): Panic: file ../../../../src/plugins/fts-solr/solr-connection.c: line 548 (solr_connection_post_more): assertion failed: (maxfd >= 0) doveadm(valerius(a)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(a)test.afterlogic.com, 48/5cc6513b4dc6de5093660000b304ded5/valerius(a)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 =

2 1

[Dovecot] Errors with doveadm when using checkpassword
by Andy Dills 22 Feb '13

22 Feb '13

We have a checkpassword authentication with mysql pre-fetch for the userdb lookups. When trying to do: doveadm search -u andytest(a)xecu.net mailbox Trash DELETED I get: doveadm(andytest(a)xecu.net): Error: user andytest(a)xecu.net: Auth PASS lookup failed doveadm(andytest(a)xecu.net): Fatal: /var/run/dovecot/auth-userdb: passdb lookup failed (to see if user is proxied, because doveadm_proxy_port is set) And I see this in the logs: Feb 4 12:02:04 mail-out01 dovecot: auth: Error: userdb-checkpassword(andytest(a)xecu.net): Child 12591 exited with status 1 I'm not surprised the checkpassword lookup is failing; the password isn't being supplied. Shouldn't it just be doing the prefetch lookup instead, like the lmtp service? Andy --- Andy Dills Xecunet, Inc. www.xecu.net 301-682-9972 ---

2 6

[Dovecot] fts_solr search in subfolders?
by Frederic Biermann 22 Feb '13

22 Feb '13

Hello, i am using dovecot 2.1.x with Solr 4.x and it is all working fine. Search in current selected folder is extremly fast. But i want to ask if it is possible that i have selected inbox, setup a search and get results from subfolders. This is not working for me. I have to select the subfolder and then i get results. Is there any solution to fix this? best regards lexusburn

3 4

[Dovecot] Connection leak in sqlpool for ACL Dict Postgres in v2.1.15 (14907:b96df105ec55) and v2.2.beta1 (15857:07dfd4391d22)
by Steffen Kaiser 22 Feb '13

22 Feb '13

-----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1 Hi, I'm using a postgres dict for ACL, when when use deleteacl or setacl I get a "not connected" error and (v2.2) Panic: file driver-pgsql.c: line 84 (driver_pgsql_set_state): assertion failed: (state == SQL_DB_STATE_BUSY || db->cur_result == NULL) and a rawdump eventually. You can trigger the error with the "dict" socket easily: while true; do ( echo -en "H2\t0\t0\t\tacl\nI1\tshared/shared-boxes/\n" sleep 1 ) | socat - unix:/var/run/dovecot2.2/dict done I interprete H2-I1..-bang.log.gz (logged with v2.1) so, that each time the ACL dict is iterated, driver_sqlpool_query_s() is executed two times, once for user_shares and once for anyone_shares. I guess that the user_shares one is never finished, so that the sqlpool keeps that slot in "busy" state until timeout. The information about the slots of the log lines 0x9886d0 1. state=3 to_recon=(nil) ready=0 |driver_sqlpool_query_s end is generated by: conns = array_get(&db->all_connections, &count); for (i = 0; i < count; i++) { struct sql_db *conndb = conns[i].db; i_info("SKA: POOL: [%u] %p %u. state=%u to_recon=%p ready=%u |%s", getpid(), db, i, conndb->state, conndb->to_reconnect, SQL_DB_IS_READY(conndb)? 1: 0, msg); } msg is the function, where that log function is called from, e.g. at the end of driver_sqlpool_query_s() in this case, which is right before the return. When the user_shares query ends in driver_sqlpool_query_s(), one additional slot of the sqlpool is in state 3, at the end of driver_sqlpool_query_s() of the anyone_shares query there are two slots in state 3. When the next I1 command triggers the next iteration, there is one slot still in state 3 at the start of driver_sqlpool_query_s(), which seems to be the slot used for the user_shares query of the previous I1 command. It looks like that the user_shares query has not been "finished" correctly and is left open. The assert() panics, because db->cur_result is != NULL. When all slots in the pool have been used up, the sqlpool enters "not connected" state and all dict connections fail with this error now. Then the assert causes the dict to die eventually, I guess, because of a timeout. The quota dict seems to not trigger that behaviour, because it uses the "L" (lookup) command, but when the sqlpool is in "not connected" state, these commands fail, too. Attached you'll find the config and log file. Kind regards, - -- Steffen Kaiser -----BEGIN PGP SIGNATURE----- Version: GnuPG v1.4.11 (GNU/Linux) iQEVAwUBUSTYgF3r2wJMiz2NAQLCGggAqcAThH8/phYIGxnkjEt3ECGBabCvDO72 L28rjvaakFffy5jmhrLrcV2b765W9XsZ/bhNOhfkQADAf8oCU9Z5q4h7wG+ZnoMj 4sd1Zax7wU/8idmrF1esSYAfZ1kCVq/ySHY7zs8stoWcpiUk6uQMN4ynYS7c3kxJ yaOWz31s0r4pS8muktq9qCwjlCXDjTigIiPbw9X5qpJ8hnvJq9Xv/BfW5uf1xKKK BXNB+HrQYrOA6VD3KCjteZhaquQFd18B9b35WkBH77thwSbaN1/R4zy8CLLpZOkS 5ss5K/doPitCunGRcNiVD8srgUU6Po7Zv0akBmE1XUfBKkn6JUILDQ== =VpqF -----END PGP SIGNATURE----- = Mailscanner Information [FB02] == Rename Filename At least one attachement has been renamed to overcome a potential filename attack. Right-click on the item and select SaveAs, in order to save the file with its original name. Mindestens ein Anhang wurde umbenannt, um eine potentielle Attacke mit unleserlichen Dateinamen zu verhinden. Um ihn mit seinem orginialen Namen zu speichern, klicken Sie rechts auf den Anhang und wählen SaveAs. See FAQ [http://www5.inf.fh-bonn-rhein-sieg.de/FAQ/mail/scan/] for more information. NewName |OldName ------------------+------------------- H2-I1.-bang.log.gz|H2-I1..-bang.log.gz -- This information was created by the mailscanner automatically. No human interferred with the process.

2 3

[Dovecot] Dovecot 2.2. proxy_maybe and twice SSL connections
by Evgeny Basov 22 Feb '13

22 Feb '13

Hello. 1. I have two identically hosts 2. I have set up replication between two hosts 3. I have 'Y' AS proxy_maybe in password_query. 4. password_query returns one of this one hosts 5. I set this parameters in dovecot config: disable_plaintext_auth = yes ssl = yes auth_mechanisms = plain login for enforce use encrypted connections by client programs. When the client connects to host imap2 directly, connection is encrypted, it is good. | client | ---- (1) ----> |imap2 (proxy_maybe='y', host = imap2)| And when the client connects to another host, I have (1) and (2) connections are encrypted | client | ---- (1) ----> |imap1 (proxy_maybe='y', host = imap2)| ---- (2) ----> |imap2| but need only (1). How do I have desired behavior? Is it possible?

3 5

[Dovecot] Using different auth_default_realm on multiple sockets with postfix. Is it possible?
by Gábor Lénárt 22 Feb '13

22 Feb '13

Hi, I have more postfix smtpd instances (via master.cf) listening on different ports, and the FW passes the inbound mail submit connections to the right port. The problem: it seems postfix is not able to append "default realm" and I need to set different values for the instances. As far as I see, it's not possible as postfix only passes the base64 encoded string from the user to the dovecot auth service (as I'm using dovecot for sasl authentication). We're talking about PLAIN and LOGIN methods. In the other hand, dovecot is happily append "realm" with auth_default_realm. It works (which does not with postfix) but again: I need more defaults. I wouldn't like to run multiple instances of dovecot (just for having a single setting be different), so I've tried similar solutions: service auth { unix_listener /var/spool/postfix/private/auth-dom1 { group = postfix mode = 0660 user = postfix } auth_default_realm = domain1.com } And the same for /var/spool/postfix/private/auth-dom2 with domain2.com. I thought then I could use postfix's master.cf to give different auth socket (like /var/spool/postfix/private/auth-dom1 and auth-dom2) with smtpd_sasl_path postfix parameter. However it seems dovecot finds auth_default_realm invalid unless it's used in the global scope of the configuration. It's dovecot 2.0.19 (in Ubuntu 12.04 LTS). Is it possible at all, what I would like to do? Maybe with newer dovecot, or can you suggest me some other solution? Any feedback is welcomed and thanked. Thanks, - Gábor

2 1

[Dovecot] Errors after enable vnd.dovecot.duplicate
by Alessio Cecchi 22 Feb '13

22 Feb '13

Hi, on dovecot 2.1.14 and pigeonhole-0.3.3 after creating a default.sieve like this: require ["vnd.dovecot.duplicate", "fileinto", "mailbox"]; if duplicate { fileinto "Trash"; } I have two strange errors, one is many of this error in lda.log: Feb 19 14:43:17 lda(info(a)domain.com): Error: file_dotlock_create(/home/vpopmail/domains/domain.com/info/.dovecot.lda-dup… failed: Resource temporarily unavailable Feb 19 14:43:43 lda(info(a)domain.com): Error: file_dotlock_create(/home/vpopmail/domains/domain.com/info/.dovecot.lda-dup… failed: Resource temporarily unavailable Feb 19 14:44:29 lda(info(a)domain.com): Error: rename(/home/vpopmail/domains/domain.com/info/.dovecot.lda-dupes.lock, /home/vpopmail/domains/domain.com/info/.dovecot.lda-dupes) failed: No such file or directory Feb 19 14:44:29 lda(info(a)domain.com): Error: file_dotlock_replace(/home/vpopmail/domains/domain.com/info/.dovecot.lda-du… failed: No such file or directory Note that my mailboxes are store on NFS. This happens for many accounts. Another error is that some messages have not Message-ID in lda.log and when this happens emails are treated as duplicate: # grep "msgid=: stored" /var/log/dovecot/lda.log Feb 18 08:02:13 lda(info(a)domain.com): Info: sieve: msgid=: stored mail into mailbox 'INBOX' Feb 18 09:37:06 lda(info(a)domain.com): Info: sieve: msgid=: stored mail into mailbox 'Trash' Feb 18 10:29:37 lda(cracigna(a)domain.com): Info: sieve: msgid=: stored mail into mailbox 'Trash' Feb 18 11:38:00 lda(info(a)domain.com): Info: sieve: msgid=: stored mail into mailbox 'Trash' Feb 18 12:09:22 lda(info(a)domain.com): Info: sieve: msgid=: stored mail into mailbox 'Trash' Feb 18 16:10:52 lda(info(a)domain.com): Info: sieve: msgid=: stored mail into mailbox 'Trash' Feb 19 14:18:19 lda(cracigna(a)domain.com): Info: sieve: msgid=: stored mail into mailbox 'Trash' Feb 19 14:24:21 lda(panizzon(a)domain.com): Info: sieve: msgid=: stored mail into mailbox 'INBOX' After some investigations this emails are sent all from the same user with a Lotus Domino Server. Can these errors be solved? My dovecot configuration: # 2.1.14: /usr/local/dovecot-2.1/etc/dovecot/dovecot.conf # OS: Linux 2.6.32-5-amd64 x86_64 Debian 6.0.6 auth_cache_size = 512 k auth_worker_max_count = 60 default_login_user = nobody dict { acl = mysql:/usr/local/dovecot-2.1/etc/dovecot/dovecot-share-folder.conf expire = mysql:/usr/local/dovecot-2.1/etc/dovecot/dovecot-dict-sql.conf.ext } disable_plaintext_auth = no dotlock_use_excl = no first_valid_gid = 89 first_valid_uid = 89 last_valid_gid = 89 last_valid_uid = 89 lda_mailbox_autocreate = yes lda_mailbox_autosubscribe = yes log_path = /var/log/dovecot/dovecot.log mail_fsync = always mail_location = maildir:~/Maildir mail_nfs_index = yes mail_nfs_storage = yes mail_plugins = quota acl zlib expire maildir_very_dirty_syncs = yes 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 vnd.dovecot.duplicate mmap_disable = yes namespace { list = children location = maildir:%%h/Maildir:INDEX=~/Maildir/shared/%%u prefix = shared/%%n/ separator = / subscriptions = no type = shared } namespace inbox { inbox = yes location = mailbox Drafts { auto = subscribe special_use = \Drafts } mailbox Sent { auto = subscribe special_use = \Sent } mailbox Spam { auto = subscribe special_use = \Junk } mailbox Trash { auto = subscribe special_use = \Trash } prefix = separator = / } passdb { args = cache_key=%s%u webmail=192.168.13.215 driver = vpopmail } plugin { acl = vfile:/usr/local/dovecot-2.1/etc/dovecot/global-acls:cache_secs=300 acl_shared_dict = proxy::acl expire = Trash expire2 = Spam expire_dict = proxy::expire quota = maildir:UserQuota quota_rule2 = Trash:storage=+100M quota_warning = storage=95%% quota-warning 95 %u quota_warning2 = storage=80%% quota-warning 80 %u sieve = ~/.dovecot.sieve sieve_default = /usr/local/dovecot-2.1/etc/dovecot/sieve/default.sieve sieve_dir = ~/sieve sieve_extensions = +vnd.dovecot.duplicate } protocols = imap pop3 sieve service auth { unix_listener auth-userdb { group = vchkpw mode = 0660 user = vpopmail } } service dict { unix_listener dict { group = vchkpw mode = 0660 user = vpopmail } } service imap-login { service_count = 0 } service managesieve-login { inet_listener sieve { port = 4190 } } service pop3-login { service_count = 0 } service quota-warning { executable = script /usr/local/dovecot-2.1/etc/dovecot/scripts/quota-warning.sh unix_listener quota-warning { user = vpopmail } user = vpopmail } ssl_cert = </usr/local/dovecot-2.1/etc/ssl/wildcard.pem ssl_key = </usr/local/dovecot-2.1/etc/ssl/wildcard.key submission_host = localhost userdb { args = quota_template=quota_rule=*:backend=%q driver = vpopmail } protocol lda { log_path = /var/log/dovecot/lda.log mail_plugins = quota acl zlib expire sieve } protocol imap { imap_client_workarounds = delay-newmail tb-extra-mailbox-sep tb-lsub-flags imap_idle_notify_interval = 29 mins mail_max_userip_connections = 18 mail_plugins = quota acl zlib expire imap_quota imap_acl } protocol sieve { mail_max_userip_connections = 10 } protocol pop3 { mail_max_userip_connections = 5 pop3_client_workarounds = outlook-no-nuls oe-ns-eoh } Thanks -- Alessio Cecchi is: @ ILS -> http://www.linux.it/~alessice/ on LinkedIn -> http://www.linkedin.com/in/alessice Assistenza Sistemi GNU/Linux -> http://www.cecchi.biz/ @ PLUG -> ex-Presidente, adesso senatore a vita, http://www.prato.linux.it

3 4

[Dovecot] Full-text search
by Valery V. Sedletski 22 Feb '13

22 Feb '13

Hi all I discovered that the full-text search (fts) plugin can work without SQUAT/LUCENE/SOLR backend. I.e., Dovecot creates separate indexes for header search in files dovecot.index and dovecot.index.cache. Even, the search by headers is fast enough, and can search for phrases. Also, it seems that this buillt-in search is faster than Solr-based search. But if I enable the Solr backend (fts_solr), then the FTS generic plugin built-in search becomes disabled. But, Solr-based Full-text search is faster if search inside message bodies. Also, it appears that the built-in search inside message bodies works too, but very slow (it seems that is because it is dumb file-based search and does not use indexes at all) So, my question is: is it possible to combine the built-in search with Solr or Lucene plugin-based search so that the first one searches by headers, and the second one works by bodies? This could make the advantages of both search methods combined. WBR, valery

2 1

[Dovecot] LDA misbehavior?
by Eugene Paskevich 22 Feb '13

22 Feb '13

Hello, Could somebody please give me a hint on what might be going wrong? Feb 21 16:33:07 hopper dovecot: lda(eugene): Panic: file mail-storage.c: line 1757 (mailbox_transaction_commit_get_changes): assertion failed: (ret < 0 || seq_range_count(&changes_r->saved_uids) == save_count) Feb 21 16:33:07 hopper dovecot: lda(eugene): Error: Raw backtrace: /usr/lib/dovecot/libdovecot.so.0(+0x6019a) [0x7f38e5ef619a] -> /usr/lib/dovecot/ibdovecot.s o.0(i_syslog_fatal_handler+0x2b) [0x7f38e5ef621b] -> /usr/lib/dovecot/libdovecot.so.0(i_fatal+0) [0x7f38e5eb81f4] -> /usr/lib/dovecot/libdovecot-storage.so.0(+0x7c0de) [0x7f38e61cd0de] -> /usr/lib/dovecot/libdovecot-lda.so.0(mail_deliver_save+0x1b2) [0x7f38e6469d62] -> /usr/lib/dovecot/libdovecot-lda.so.0(mail_deliver+0xe3) [0x7f38e646a113] -> /usr/lib/dovecot/dovecot-lda(main+0x38a) [0x40295a] -> /lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xfd) [0x7f38e5b2aead] -> /usr/lib/dovecot/dovecot-lda() [0x4031e1] Feb 21 16:33:07 hopper exim[10094]: 1U8XCf-0002Za-4s ** eugene(a)hopper.volia.net <root(a)hopper.volia.net> R=local_user T=dovecot_delivery: Child process of dovecot_delivery transport (running command "/usr/lib/dovecot/dovecot-lda -f $sender_address -a $original_local_part@$original_domain") was terminated by signal 6 (Aborted) Feb 21 16:33:07 hopper exim[10094]: 1U8XCf-0002Za-4s Frozen (delivery error message) It started a couple of days ago. Triggered by the mass delivery. E.g. by for i in {1..50}; do { mail -s "test $i" eugene(a)hopper.volia.net <<< "Try $i" & }; done I suspected that sieve might cause that, but disabling it gave nothing. Current root@hopper[pts/0]:/etc/dovecot> doveconf -n # 2.2.beta1 (808a64899e8a): /etc/dovecot/dovecot.conf # OS: Linux 3.2.0-4-amd64 x86_64 Debian 7.0 mail_location = maildir:~/Maildir namespace inbox { inbox = yes location = mailbox Drafts { special_use = \Drafts } mailbox Junk { special_use = \Junk } mailbox Sent { special_use = \Sent } mailbox "Sent Messages" { special_use = \Sent } mailbox Trash { special_use = \Trash } prefix = } passdb { driver = pam } postmaster_address = hopper(a)volia.net protocols = imap service imap-login { inet_listener imap { port = 143 } inet_listener imap2 { port = 1357 } } ssl_cert = </etc/dovecot/dovecot.pem ssl_key = </etc/dovecot/private/dovecot.pem userdb { driver = passwd } Is there any other info I could provide? -- Eugene Paskevich | *==)----------- | Plug me into eugene(a)raptor.kiev.ua | -----------(==* | The Matrix

2 1

[Dovecot] Bug: empty m-files
by Peer Heinlein 22 Feb '13

22 Feb '13

Having an empty m-File, doveadm force-resync isn't able to detect and repair this: -rw------- 1 vmail vmail 4948043 8. Jan 20:32 m.634 -rw------- 1 vmail vmail 5237411 8. Jan 20:32 m.635 -rw------- 1 vmail vmail 0 9. Jan 16:23 m.636 mail1:~ # doveadm force-resync -u user mailbox INBOX doveadm(user): Warning: fscking index file /vmail/example.com/user//mdbox/storage/dovecot.map.index doveadm(user): Warning: mdbox /vmail/example.com/user//mdbox/storage: rebuilding indexes doveadm(user): Error: Corrupted dbox file /vmail/example.com/user//mdbox/storage/m.636 (around offset=0): EOF while reading file header doveadm(user): Error: mdbox rebuild: Failed to fix file /vmail/example.com/user//mdbox/storage/m.636 doveadm(user): Error: mdbox /vmail/example.com/user//mdbox/storage: Duplicate GUID 2cafdd2f0224ec50773c0000085c1439 in m.627:16 and m.638:16 Peer -- Heinlein Support GmbH Schwedter Str. 8/9b, 10119 Berlin http://www.heinlein-support.de Tel: 030 / 405051-42 Fax: 030 / 405051-19 Zwangsangaben lt. §35a GmbHG: HRB 93818 B / Amtsgericht Berlin-Charlottenburg, Geschäftsführer: Peer Heinlein -- Sitz: Berlin

2 1

[Dovecot] Crash in dsync [dovecot 2.1.7]
by Joe Beaubien 22 Feb '13

22 Feb '13

Just taught i'd report this crash while running the ofllowing command: 19748 Aborted (core dumped) $DSYNC_BINARY -f -u document backup mdbox:$LOCAL_BACKUP_PATH/emails/document >> $LOG_FILE 2>&1 Here is the traceback I got: dsync(document): Error: Mailbox INBOX/Julie: Corrupted index, uidvalidity=0 dsync(document): Warning: mdbox /backup_hdd/current/emails/document/storage: rebuilding indexes dsync(document): Panic: file mdbox-storage-rebuild.c: line 66 (mdbox_storage_rebuild_init): assertion failed: (!storage->rebuilding_storage) dsync(document): Error: Raw backtrace: /opt/dovecot-2.1.7/lib/dovecot/libdovecot.so.0(+0x4203a) [0x7faa3bbde03a] -> /opt/dovecot-2.1.7/lib/dovecot/libdovecot.so.0(default_fatal_handler+0x2a) [0x7faa3bbde0fa] -> /opt/dovecot-2.1.7/lib/dovecot/libdovecot.so.0(i_fatal+0) [0x7faa3bbb53f0] -> /opt/dovecot-2.1.7/lib/dovecot/libdovecot-storage.so.0(mdbox_storage_rebuild_in_context+0x117e) [0x7faa3be656de] -> /opt/dovecot-2.1.7/lib/dovecot/libdovecot-storage.so.0(mdbox_sync_begin+0x23a) [0x7faa3be62b1a] -> /opt/dovecot-2.1.7/lib/dovecot/libdovecot-storage.so.0(mdbox_sync+0x33) [0x7faa3be630f3] -> /opt/dovecot-2.1.7/lib/dovecot/libdovecot-storage.so.0(mdbox_storage_sync_init+0x7e) [0x7faa3be631be] -> /opt/dovecot-2.1.7/lib/dovecot/libdovecot-storage.so.0(mailbox_sync_init+0x31) [0x7faa3bea2871] -> /opt/dovecot-2.1.7/lib/dovecot/libdovecot-storage.so.0(mailbox_sync+0x27) [0x7faa3bea2997] -> /opt/dovecot-2.1.7/lib/dovecot/libdovecot-storage.so.0(mailbox_mark_index_deleted+0x9b) [0x7faa3bea3aeb] -> /opt/dovecot-2.1.7/lib/dovecot/libdovecot-storage.so.0(mailbox_open+0x85) [0x7faa3bea3a25] -> /opt/dovecot-2.1.7/lib/dovecot/libdovecot-storage.so.0(mdbox_storage_rebuild_in_context+0xb7b) [0x7faa3be650db] -> /opt/dovecot-2.1.7/lib/dovecot/libdovecot-storage.so.0(mdbox_sync_begin+0x23a) [0x7faa3be62b1a] -> /opt/dovecot-2.1.7/lib/dovecot/libdovecot-storage.so.0(mdbox_sync+0x33) [0x7faa3be630f3] -> /opt/dovecot-2.1.7/lib/dovecot/libdovecot-storage.so.0(mdbox_storage_sync_init+0x7e) [0x7faa3be631be] -> /opt/dovecot-2.1.7/lib/dovecot/libdovecot-storage.so.0(mailbox_sync_init+0x31) [0x7faa3bea2871] -> /opt/dovecot-2.1.7/lib/dovecot/libdovecot-storage.so.0(mailbox_sync+0x27) [0x7faa3bea2997] -> /opt/dovecot-2.1.7/lib/dovecot/libdovecot-storage.so.0(index_storage_get_status+0x8a) [0x7faa3bec47da] -> /opt/dovecot/lib/dovecot/lib20_fts_plugin.so(+0xc002) [0x7faa3a775002] -> /opt/dovecot/bin/dsync() [0x42bf9a] -> /opt/dovecot/bin/dsync(dsync_worker_mailbox_iter_next+0x29) [0x428eb9] -> /opt/dovecot/bin/dsync() [0x423bfe] -> /opt/dovecot/bin/dsync(dsync_brain_sync+0x832) [0x4233a2] -> /opt/dovecot/bin/dsync(dsync_brain_sync_all+0x18) [0x423ee8] -> /opt/dovecot/bin/dsync() [0x420f36] -> /opt/dovecot/bin/dsync() [0x4215b2] -> /opt/dovecot/bin/dsync() [0x40e798] -> /opt/dovecot/bin/dsync() [0x40f1ea]

2 1

[Dovecot] Problem with managesieve proxy
by Lance A. Brown 22 Feb '13

22 Feb '13

Hi folks, I'm setting up a new dovecot email service and have a proxy server running in front of it to facilitate migrating users from my very old UW-IMAP-based mail server to the new one. I have a mysql proxy table that directs inbound IMAP and LMTP connections to the correct server, works great. Managesieve connections are not working through the proxy using either with the sieverules plugin for RoundCube or the Sieve plugin for Thunderbird. If I point them directly at the actual dovecot server everything works fine, so I must have something wrong in my proxy setup. This is what I get in the maillogs when I try to connect to the managesieve proxy: PROXY machine: Feb 21 16:16:38 sortie dovecot: managesieve-login: Error: proxy: Remote x.y.z.110:4190 disconnected: Connection closed (state=0, duration=0s): user=<brown>, method=PLAIN, rip=x.y.z.83, lip=x.y.z.109, TLS, session=<0jUal0LWswCYAxZT> Feb 21 16:16:38 sortie dovecot: managesieve-login: Disconnected (internal failure, 1 succesful auths): user=<brown>, method=PLAIN, rip=x.y.z.83, lip=x.y.z.109, TLS, session=<0jUal0LWswCYAxZT> SERVER machine: Feb 21 16:16:38 postie dovecot: managesieve-login: Disconnected: Too many invalid commands. (no auth attempts in 0 secs): user=<>, rip=x.y.z.109, lip=x.y.z.110, session=<REgal0LWnQCYAxZt> Output of a 'tcpdump -A' is attached as well if needed. x.y.z.83 - Roundcube webmail server x.y.z.109 - PROXY x.y.z.110 - SERVER If I turn off TLS all-around I get an error in the roundcube log that says: [20-Feb-2013 23:02:27] No supported authentication method found. The server supports these methods: , but we want to use: PLAIN (): [20-Feb-2013 23:02:27] Not currently in AUTHORISATION state (1): I am using Pigeonhole 0.3.3 on both proxy and server. Dovecot configurations for the proxy and server are attached below. Here are the SQL files referenced in the proxy configs. Long lines broke for readability. /etc/dovecot/dovecot-sql.conf.ext driver = mysql connect = host=localhost dbname=dovecot user=dovecot password=XXX password_query = SELECT NULL AS password, 'any-cert' as 'ssl', \ 'Y' as nopassword, host, user as destuser, \ 'Y' AS proxy \ FROM proxy WHERE user = '%u' /etc/dovecot/dovecot-sql-lmtp.conf.ext driver = mysql connect = host=localhost dbname=dovecot user=dovecot password=XXX password_query = SELECT NULL AS password, 'any-cert' as 'ssl', \ 'Y' as nopassword, host, user as destuser, 'Y' AS proxy \ FROM proxy WHERE user = '%n' The proxy DB table looks like this: - -- Table structure for table `proxy` -- CREATE TABLE IF NOT EXISTS `proxy` ( `id` int(11) NOT NULL AUTO_INCREMENT, `user` varchar(255) NOT NULL, `email` varchar(64) NOT NULL, `host` varchar(16) DEFAULT NULL, PRIMARY KEY (`id`), UNIQUE KEY `user_index` (`user`) ) ENGINE=MyISAM DEFAULT CHARSET=latin1 AUTO_INCREMENT=379 ; -- -- Dumping data for table `proxy` -- INSERT INTO `proxy` (`id`, `user`, `email`, `host`) VALUES (1, 'brown', '', 'x.y.z.110'), (2, 'fizgig', '', 'x.r.z.15'), 110 is the new dovecot IMAP server, 15 is the old UW-IMAP server. Any advice on getting managesieve proxy running would be greatly appreciated. Thanks, --[Lance] -- GPG Fingerprint: 409B A409 A38D 92BF 15D9 6EEE 9A82 F2AC 69AC 07B9 CACert.org Assurer

1 1

[Dovecot] Dovecot list archives not updating
by Mark Sapiro 22 Feb '13

22 Feb '13

The February archive indexes of this list haven't been updating since Feb 8. The text file at <http://dovecot.org/pipermail/dovecot/2013-February.txt> appears to be up to date with all posts, but the index pages at <http://dovecot.org/pipermail/dovecot/2013-February/thread.html>, <http://dovecot.org/pipermail/dovecot/2013-February/subject.html>, <http://dovecot.org/pipermail/dovecot/2013-February/author.html> and <http://dovecot.org/pipermail/dovecot/2013-February/date.html> have no posts after the one at <http://dovecot.org/pipermail/dovecot/2013-February/071213.html> from Fri Feb 8 16:31:49 EET 2013. Subsequent posts appear to not have individual HTML pages either as URLs <http://dovecot.org/pipermail/dovecot/2013-February/071214.html> and <http://dovecot.org/pipermail/dovecot/2013-February/071215.html> return 404 errors. I suspect there is a permissions issue starting soon after Fri Feb 8 16:31:49 EET 2013 and that Mailman's error log has lots of tracebacks from this. If that is the case, the messages were probably all shunted and running Mailman's bin/unshunt after fixing the underlying issue and also making sure that any messages older than Fri Feb 8 16:31:49 EET 2013 in Mailman's 'shunt' queue that should not also be reprocessed are removed. -- Mark Sapiro <mark(a)msapiro.net> The highway is for gamblers, San Francisco Bay Area, California better use your sense - B. Dylan

1 0

[Dovecot] Public folders and dsync replication Dovecot v2.1.7
by Steve Brown 21 Feb '13

21 Feb '13

Dear all I have a few public folders setup and working fine, and one such public folder is 'Public/General'. I'm trying to sort dsync replication out to another server and notice that the system log is full of error messages similar to: dovecot: doveadm: Error: dsync-remote(username: Error: Can't update subscription Pu blic/General: Invalid mailbox name The replication setup is basically as per the v2 wiki. It seems that when a mail client subscribes to a public folder, the folder name is put into '~/Maildir/subscriptions' and this seems to be the cause of the error during replication. The mails are not synchronised to the other server. Public namespace is: namespace { type = public separator = / prefix = Public/ location = maildir:/home/shared/public subscriptions = no list = yes } Hopefully somebody can send the clue bus over? Steve -- Steve Brown Operations Manager Connection Services Ltd +44 (0)1189 711 765 Direct +44 (0)870 751 7571 Fax www.connectionservices.com www.hotspot-directory.com

3 2

Re: [Dovecot] Dovecot LDA LDAP lookups on samba4 server ends very often in timeouts (Christian Wiese)
by Marco Carcano 21 Feb '13

21 Feb '13

Dear Christian thank you very much - you got it at the very first shot: modified /etc/ openldap/ldap.conf adding REFERRALS off en everything works without issues now many thanks Marco Carcano

1 0

[Dovecot] Dovecot LDA LDAP lookups on samba4 server ends very often in timeouts
by marco＠carcano.ch 20 Feb '13

20 Feb '13

I hope that someone will be so kind to help me into solving this really strange thing (don't know if it is a bug or not) I have a samba4 server and want to use postfix+dovecot - dovecot version is 2.0.11 as for the postfix side everything is OK (all the LDAP lookups works without any error, tested also manually with postmap -q) the real pain is with dovecot deliver: it seems that sometimes lda tries to lookup to the LDPA (samba 4) server, got a reply, an then report(after 2 minutes) a lookup timeout error the really strange thing is that (very seldom) lda works, but most of the times I got the timeout error. The strange thing is that if I use ldapsearch I never got timeout neither late replies, and even postfix performs its lookups without any issue it seems something related to lda itself (I do not know if I have a wrong configuration, but I think this is not a configuration issue, otherwise it should not work at all) here are the information logged when it does not work - after this log you will find the one when I got the failure (if needed I can provide a .pcap file too) (trailing and leading spaces of AT charcater has been added by me) ############################## FAULTY DELIVER LOG ############################################# Feb 20 12:20:50 sng02 postfix/smtpd[8928]: connect from localhost[127.0.0.1] Feb 20 12:21:14 sng02 postfix/smtpd[8928]: A38D4407F5: client=localhost[127.0.0.1] Feb 20 12:21:20 sng02 postfix/cleanup[8891]: A38D4407F5: warning: header Subject: prova from localhost[127.0.0.1]; from=<marco @ senderdomain.tld> to=<mac @ mydomain.com> proto=SMTP helo=<senderdomain.tld> Feb 20 12:21:20 sng02 postfix/cleanup[8891]: A38D4407F5: message-id=<20130220112114.A38D4407F5 @ srv01.mydomain.local> Feb 20 12:21:20 sng02 postfix/qmgr[8889]: A38D4407F5: from=<marco @ senderdomain.tld>, size=371, nrcpt=1 (queue active) Feb 20 12:21:20 sng02 dovecot: lda: Debug: Loading modules from directory: /usr/lib64/dovecot Feb 20 12:21:20 sng02 dovecot: lda: Debug: Module loaded: /usr/lib64/dovecot/lib10_quota_plugin.so Feb 20 12:21:20 sng02 dovecot: lda: Debug: Module loaded: /usr/lib64/dovecot/lib20_expire_plugin.so Feb 20 12:21:20 sng02 dovecot: lda: Debug: Module loaded: /usr/lib64/dovecot/lib90_sieve_plugin.so Feb 20 12:21:20 sng02 dovecot: auth: Debug: Loading modules from directory: /usr/lib64/dovecot/auth Feb 20 12:21:20 sng02 dovecot: auth: Debug: Module loaded: /usr/lib64/dovecot/auth/libauthdb_ldap.so Feb 20 12:21:20 sng02 dovecot: auth: Debug: Module loaded: /usr/lib64/dovecot/auth/libdriver_mysql.so Feb 20 12:21:20 sng02 dovecot: auth: Debug: Module loaded: /usr/lib64/dovecot/auth/libdriver_pgsql.so Feb 20 12:21:20 sng02 dovecot: auth: Debug: Module loaded: /usr/lib64/dovecot/auth/libdriver_sqlite.so Feb 20 12:21:20 sng02 dovecot: auth: Debug: Module loaded: /usr/lib64/dovecot/auth/libmech_gssapi.so Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_bind Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_simple_bind Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_sasl_bind Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_send_initial_request Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_new_connection 1 1 0 Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_int_open_connection Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_connect_to_host: TCP localhost:389 Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_new_socket: 16 Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_prepare_socket: 16 Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_connect_to_host: Trying ::1 389 Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_pvt_connect: fd: 16 tm: -1 async: 0 Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_open_defconn: successful Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_send_server_request Feb 20 12:21:20 sng02 dovecot: auth: Debug: master in: USER#0111#011marco.carcano#011service=lda Feb 20 12:21:20 sng02 dovecot: auth: Debug: password(marco.carcano): passdb doesn't support credential lookups Feb 20 12:21:20 sng02 dovecot: auth: Error: static(marco.carcano): passdb doesn't support lookups, can't verify user's existence Feb 20 12:21:20 sng02 dovecot: auth: Debug: ldap(marco.carcano): user search: base=DC=mydomain,DC=local scope=subtree filter=(sAMAccountname=marco.carcano) fields=Mailbox,dovecotMailQuota Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_result ld 0x6cba60 msgid -1 Feb 20 12:21:20 sng02 dovecot: auth: Error: wait4msg ld 0x6cba60 msgid -1 (timeout 0 usec) Feb 20 12:21:20 sng02 dovecot: auth: Error: wait4msg continue ld 0x6cba60 msgid -1 all 0 Feb 20 12:21:20 sng02 dovecot: auth: Error: ** ld 0x6cba60 Connections: Feb 20 12:21:20 sng02 dovecot: auth: Error: * host: localhost port: 389 (default) Feb 20 12:21:20 sng02 dovecot: auth: Error: refcnt: 2 status: Connected Feb 20 12:21:20 sng02 dovecot: auth: Error: last used: Wed Feb 20 12:21:20 2013 Feb 20 12:21:20 sng02 dovecot: auth: Error: Feb 20 12:21:20 sng02 dovecot: auth: Error: Feb 20 12:21:20 sng02 dovecot: auth: Error: ** ld 0x6cba60 Outstanding Requests: Feb 20 12:21:20 sng02 dovecot: auth: Error: * msgid 1, origid 1, status InProgress Feb 20 12:21:20 sng02 dovecot: auth: Error: outstanding referrals 0, parent count 0 Feb 20 12:21:20 sng02 dovecot: auth: Error: ld 0x6cba60 request count 1 (abandoned 0) Feb 20 12:21:20 sng02 dovecot: auth: Error: ** ld 0x6cba60 Response Queue: Feb 20 12:21:20 sng02 dovecot: auth: Error: Empty Feb 20 12:21:20 sng02 dovecot: auth: Error: ld 0x6cba60 response count 0 Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_chkResponseList ld 0x6cba60 msgid -1 all 0 Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_chkResponseList returns ld 0x6cba60 NULL Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_int_select Feb 20 12:21:20 sng02 dovecot: auth: Error: read1msg: ld 0x6cba60 msgid -1 all 0 Feb 20 12:21:20 sng02 dovecot: auth: Error: read1msg: ld 0x6cba60 msgid 1 message type bind Feb 20 12:21:20 sng02 dovecot: auth: Error: read1msg: ld 0x6cba60 0 new referrals Feb 20 12:21:20 sng02 dovecot: auth: Error: read1msg: mark request completed, ld 0x6cba60 msgid 1 Feb 20 12:21:20 sng02 dovecot: auth: Error: request done: ld 0x6cba60 msgid 1 Feb 20 12:21:20 sng02 dovecot: auth: Error: res_errno: 0, res_error: <>, res_matched: <> Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_free_request (origid 1, msgid 1) Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_parse_result Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_search Feb 20 12:21:20 sng02 dovecot: auth: Error: put_filter: "(sAMAccountname=marco.carcano)" Feb 20 12:21:20 sng02 dovecot: auth: Error: put_filter: simple Feb 20 12:21:20 sng02 dovecot: auth: Error: put_simple_filter: "sAMAccountname=marco.carcano" Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_send_initial_request Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_send_server_request Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_msgfree Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_result ld 0x6cba60 msgid -1 Feb 20 12:21:20 sng02 dovecot: auth: Error: wait4msg ld 0x6cba60 msgid -1 (timeout 0 usec) Feb 20 12:21:20 sng02 dovecot: auth: Error: wait4msg continue ld 0x6cba60 msgid -1 all 0 Feb 20 12:21:20 sng02 dovecot: auth: Error: ** ld 0x6cba60 Connections: Feb 20 12:21:20 sng02 dovecot: auth: Error: * host: localhost port: 389 (default) Feb 20 12:21:20 sng02 dovecot: auth: Error: refcnt: 2 status: Connected Feb 20 12:21:20 sng02 dovecot: auth: Error: last used: Wed Feb 20 12:21:20 2013 Feb 20 12:21:20 sng02 dovecot: auth: Error: Feb 20 12:21:20 sng02 dovecot: auth: Error: Feb 20 12:21:20 sng02 dovecot: auth: Error: ** ld 0x6cba60 Outstanding Requests: Feb 20 12:21:20 sng02 dovecot: auth: Error: * msgid 2, origid 2, status InProgress Feb 20 12:21:20 sng02 dovecot: auth: Error: outstanding referrals 0, parent count 0 Feb 20 12:21:20 sng02 dovecot: auth: Error: ld 0x6cba60 request count 1 (abandoned 0) Feb 20 12:21:20 sng02 dovecot: auth: Error: ** ld 0x6cba60 Response Queue: Feb 20 12:21:20 sng02 dovecot: auth: Error: Empty Feb 20 12:21:20 sng02 dovecot: auth: Error: ld 0x6cba60 response count 0 Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_chkResponseList ld 0x6cba60 msgid -1 all 0 Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_chkResponseList returns ld 0x6cba60 NULL Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_int_select Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_result ld 0x6cba60 msgid -1 Feb 20 12:21:20 sng02 dovecot: auth: Error: wait4msg ld 0x6cba60 msgid -1 (timeout 0 usec) Feb 20 12:21:20 sng02 dovecot: auth: Error: wait4msg continue ld 0x6cba60 msgid -1 all 0 Feb 20 12:21:20 sng02 dovecot: auth: Error: ** ld 0x6cba60 Connections: Feb 20 12:21:20 sng02 dovecot: auth: Error: * host: localhost port: 389 (default) Feb 20 12:21:20 sng02 dovecot: auth: Error: refcnt: 2 status: Connected Feb 20 12:21:20 sng02 dovecot: auth: Error: last used: Wed Feb 20 12:21:20 2013 Feb 20 12:21:20 sng02 dovecot: auth: Error: Feb 20 12:21:20 sng02 dovecot: auth: Error: Feb 20 12:21:20 sng02 dovecot: auth: Error: ** ld 0x6cba60 Outstanding Requests: Feb 20 12:21:20 sng02 dovecot: auth: Error: * msgid 2, origid 2, status InProgress Feb 20 12:21:20 sng02 dovecot: auth: Error: outstanding referrals 0, parent count 0 Feb 20 12:21:20 sng02 dovecot: auth: Error: ld 0x6cba60 request count 1 (abandoned 0) Feb 20 12:21:20 sng02 dovecot: auth: Error: ** ld 0x6cba60 Response Queue: Feb 20 12:21:20 sng02 dovecot: auth: Error: Empty Feb 20 12:21:20 sng02 dovecot: auth: Error: ld 0x6cba60 response count 0 Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_chkResponseList ld 0x6cba60 msgid -1 all 0 Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_chkResponseList returns ld 0x6cba60 NULL Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_int_select Feb 20 12:21:20 sng02 dovecot: auth: Error: read1msg: ld 0x6cba60 msgid -1 all 0 Feb 20 12:21:20 sng02 dovecot: auth: Error: read1msg: ld 0x6cba60 msgid 2 message type search-entry Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_first_attribute Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_get_values Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_next_attribute Feb 20 12:21:20 sng02 dovecot: auth: Debug: ldap(marco.carcano): result: dovecotMailQuota(quota_rule=%$)=*:storage=8192M Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_msgfree Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_result ld 0x6cba60 msgid -1 Feb 20 12:21:20 sng02 dovecot: auth: Error: wait4msg ld 0x6cba60 msgid -1 (timeout 0 usec) Feb 20 12:21:20 sng02 dovecot: auth: Error: wait4msg continue ld 0x6cba60 msgid -1 all 0 Feb 20 12:21:20 sng02 dovecot: auth: Error: ** ld 0x6cba60 Connections: Feb 20 12:21:20 sng02 dovecot: auth: Error: * host: localhost port: 389 (default) Feb 20 12:21:20 sng02 dovecot: auth: Error: refcnt: 2 status: Connected Feb 20 12:21:20 sng02 dovecot: auth: Error: last used: Wed Feb 20 12:21:20 2013 Feb 20 12:21:20 sng02 dovecot: auth: Error: Feb 20 12:21:20 sng02 dovecot: auth: Error: Feb 20 12:21:20 sng02 dovecot: auth: Error: ** ld 0x6cba60 Outstanding Requests: Feb 20 12:21:20 sng02 dovecot: auth: Error: * msgid 2, origid 2, status InProgress Feb 20 12:21:20 sng02 dovecot: auth: Error: outstanding referrals 0, parent count 0 Feb 20 12:21:20 sng02 dovecot: auth: Error: ld 0x6cba60 request count 1 (abandoned 0) Feb 20 12:21:20 sng02 dovecot: auth: Error: ** ld 0x6cba60 Response Queue: Feb 20 12:21:20 sng02 dovecot: auth: Error: Empty Feb 20 12:21:20 sng02 dovecot: auth: Error: ld 0x6cba60 response count 0 Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_chkResponseList ld 0x6cba60 msgid -1 all 0 Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_chkResponseList returns ld 0x6cba60 NULL Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_int_select Feb 20 12:21:20 sng02 dovecot: auth: Error: read1msg: ld 0x6cba60 msgid -1 all 0 Feb 20 12:21:20 sng02 dovecot: auth: Error: read1msg: ld 0x6cba60 msgid 2 message type search-reference Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_chase_v3referrals Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_url_parse_ext(ldap://mydomain.local/CN=Configuration,DC=mydomain,DC=local) Feb 20 12:21:20 sng02 dovecot: auth: Error: re_encode_request: new msgid 3, new dn <CN=Configuration,DC=mydomain,DC=local> Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_chase_v3referral: msgid 2, url "ldap://mydomain.local/CN=Configuration,DC=mydomain,DC=local" Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_send_server_request Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_new_connection 0 1 1 Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_int_open_connection Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_connect_to_host: TCP mydomain.local:389 Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_new_socket: 18 Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_prepare_socket: 18 Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_connect_to_host: Trying 192.168.32.2:389 Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_pvt_connect: fd: 18 tm: -1 async: 0 Feb 20 12:21:20 sng02 dovecot: auth: Error: anonymous rebind via ldap_sasl_bind("") Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_sasl_bind Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_send_initial_request Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_send_server_request Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_result ld 0x6cba60 msgid 4 Feb 20 12:21:20 sng02 dovecot: auth: Error: wait4msg ld 0x6cba60 msgid 4 (timeout 100000 usec) Feb 20 12:21:20 sng02 dovecot: auth: Error: wait4msg continue ld 0x6cba60 msgid 4 all 1 Feb 20 12:21:20 sng02 dovecot: auth: Error: ** ld 0x6cba60 Connections: Feb 20 12:21:20 sng02 dovecot: auth: Error: * host: mydomain.local port: 0 Feb 20 12:21:20 sng02 dovecot: auth: Error: refcnt: 2 status: Connected Feb 20 12:21:20 sng02 dovecot: auth: Error: last used: Wed Feb 20 12:21:20 2013 Feb 20 12:21:20 sng02 dovecot: auth: Error: rebind in progress Feb 20 12:21:20 sng02 dovecot: auth: Error: queue is empty Feb 20 12:21:20 sng02 dovecot: auth: Error: Feb 20 12:21:20 sng02 dovecot: auth: Error: * host: localhost port: 389 (default) Feb 20 12:21:20 sng02 dovecot: auth: Error: refcnt: 3 status: Connected Feb 20 12:21:20 sng02 dovecot: auth: Error: last used: Wed Feb 20 12:21:20 2013 Feb 20 12:21:20 sng02 dovecot: auth: Error: Feb 20 12:21:20 sng02 dovecot: auth: Error: Feb 20 12:21:20 sng02 dovecot: auth: Error: ** ld 0x6cba60 Outstanding Requests: Feb 20 12:21:20 sng02 dovecot: auth: Error: * msgid 4, origid 4, status InProgress Feb 20 12:21:20 sng02 dovecot: auth: Error: outstanding referrals 0, parent count 0 Feb 20 12:21:20 sng02 dovecot: auth: Error: * msgid 2, origid 2, status InProgress Feb 20 12:21:20 sng02 dovecot: auth: Error: outstanding referrals 1, parent count 0 Feb 20 12:21:20 sng02 dovecot: auth: Error: ld 0x6cba60 request count 2 (abandoned 0) Feb 20 12:21:20 sng02 dovecot: auth: Error: ** ld 0x6cba60 Response Queue: Feb 20 12:21:20 sng02 dovecot: auth: Error: Empty Feb 20 12:21:20 sng02 dovecot: auth: Error: ld 0x6cba60 response count 0 Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_chkResponseList ld 0x6cba60 msgid 4 all 1 Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_chkResponseList returns ld 0x6cba60 NULL Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_int_select Feb 20 12:21:20 sng02 dovecot: auth: Error: read1msg: ld 0x6cba60 msgid 4 all 1 Feb 20 12:21:20 sng02 dovecot: auth: Error: read1msg: ld 0x6cba60 msgid 2 message type search-result Feb 20 12:21:20 sng02 dovecot: auth: Error: read1msg: ld 0x6cba60 0 new referrals Feb 20 12:21:20 sng02 dovecot: auth: Error: read1msg: mark request completed, ld 0x6cba60 msgid 2 Feb 20 12:21:20 sng02 dovecot: auth: Error: wait4msg ld 0x6cba60 0 s 99952 us to go Feb 20 12:21:20 sng02 dovecot: auth: Error: wait4msg continue ld 0x6cba60 msgid 4 all 1 Feb 20 12:21:20 sng02 dovecot: auth: Error: ** ld 0x6cba60 Connections: Feb 20 12:21:20 sng02 dovecot: auth: Error: * host: mydomain.local port: 0 Feb 20 12:21:20 sng02 dovecot: auth: Error: refcnt: 2 status: Connected Feb 20 12:21:20 sng02 dovecot: auth: Error: last used: Wed Feb 20 12:21:20 2013 Feb 20 12:21:20 sng02 dovecot: auth: Error: rebind in progress Feb 20 12:21:20 sng02 dovecot: auth: Error: queue is empty Feb 20 12:21:20 sng02 dovecot: auth: Error: Feb 20 12:21:20 sng02 dovecot: auth: Error: * host: localhost port: 389 (default) Feb 20 12:21:20 sng02 dovecot: auth: Error: refcnt: 2 status: Connected Feb 20 12:21:20 sng02 dovecot: auth: Error: last used: Wed Feb 20 12:21:20 2013 Feb 20 12:21:20 sng02 dovecot: auth: Error: Feb 20 12:21:20 sng02 dovecot: auth: Error: Feb 20 12:21:20 sng02 dovecot: auth: Error: ** ld 0x6cba60 Outstanding Requests: Feb 20 12:21:20 sng02 dovecot: auth: Error: * msgid 4, origid 4, status InProgress Feb 20 12:21:20 sng02 dovecot: auth: Error: outstanding referrals 0, parent count 0 Feb 20 12:21:20 sng02 dovecot: auth: Error: * msgid 2, origid 2, status RequestCompleted Feb 20 12:21:20 sng02 dovecot: auth: Error: outstanding referrals 1, parent count 0 Feb 20 12:21:20 sng02 dovecot: auth: Error: ld 0x6cba60 request count 2 (abandoned 0) Feb 20 12:21:20 sng02 dovecot: auth: Error: ** ld 0x6cba60 Response Queue: Feb 20 12:21:20 sng02 dovecot: auth: Error: Empty Feb 20 12:21:20 sng02 dovecot: auth: Error: ld 0x6cba60 response count 0 Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_chkResponseList ld 0x6cba60 msgid 4 all 1 Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_chkResponseList returns ld 0x6cba60 NULL Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_int_select Feb 20 12:21:20 sng02 dovecot: auth: Error: read1msg: ld 0x6cba60 msgid 4 all 1 Feb 20 12:21:20 sng02 dovecot: auth: Error: read1msg: ld 0x6cba60 msgid 4 message type bind Feb 20 12:21:20 sng02 dovecot: auth: Error: read1msg: ld 0x6cba60 0 new referrals Feb 20 12:21:20 sng02 dovecot: auth: Error: read1msg: mark request completed, ld 0x6cba60 msgid 4 Feb 20 12:21:22 sng02 postfix/smtpd[8928]: disconnect from localhost[127.0.0.1] Feb 20 12:23:55 sng02 dovecot: lda: Error: userdb lookup(marco.carcano): Request timed out Feb 20 12:23:55 sng02 dovecot: lda: Fatal: Internal error occurred. Refer to server log for more information. Feb 20 12:23:56 sng02 postfix/pipe[8897]: A38D4407F5: to=<marco.carcano @ mydomain.local>, orig_to=<mac @ mydomain.com>, relay=dovecot, delay=171, delays=16/0.01/0/155, dsn=4.3.0, status=deferred (temporary failure) Feb 20 12:24:10 sng02 dovecot: master: Warning: Killed with signal 15 (by pid=8946 uid=0 code=kill) Feb 20 12:24:10 sng02 dovecot: auth: ldap(marco.carcano): Shutting down Feb 20 12:24:10 sng02 dovecot: auth: Debug: master out: FAIL#0111 Feb 20 12:24:10 sng02 dovecot: auth: Error: ldap_unbind Feb 20 12:24:10 sng02 dovecot: auth: Error: ldap_free_request (origid 2, msgid 3) Feb 20 12:24:10 sng02 dovecot: auth: Error: ldap_free_request (origid 2, msgid 2) Feb 20 12:24:10 sng02 dovecot: auth: Error: ldap_free_connection 1 1 Feb 20 12:24:10 sng02 dovecot: auth: Error: ldap_send_unbind Feb 20 12:24:10 sng02 dovecot: auth: Error: ldap_free_connection: actually freed Feb 20 12:24:10 sng02 dovecot: auth: Error: ldap_free_connection 1 1 Feb 20 12:24:10 sng02 dovecot: auth: Error: ldap_send_unbind Feb 20 12:24:10 sng02 dovecot: auth: Error: ldap_free_connection: actually freed Feb 20 12:24:18 sng02 postfix/postfix-script[8962]: stopping the Postfix mail system Feb 20 12:24:18 sng02 postfix/master[8886]: terminating on signal 15 ############################## END OF FAULTY DELIVER LOG ############################################# I'll add the log of a succefully delivered message in another mail (otherwise I exceed message size limit of the list)

2 1

Re: [Dovecot] Dovecot LDA LDAP lookups on samba4 server ends very often in timeouts
by marco＠carcano.ch 20 Feb '13

20 Feb '13

just to complete the informations of this thread, here is the log of a mail delivered succesfully (trailing and leading spaces of AT charcater has been added by me) ############################## MAIL SUCCEFFULLY DELIVERED LOG ############################################# Feb 19 17:41:01 sng02 postfix/smtpd[4006]: connect from localhost[127.0.0.1] Feb 19 17:41:28 sng02 postfix/smtpd[4006]: 95659407F5: client=localhost[127.0.0.1] Feb 19 17:41:36 sng02 postfix/cleanup[4011]: 95659407F5: warning: header Subject: prova from localhost[127.0.0.1]; from=<marco @ senderdomain.tld> to=<mac @ mydomain.com> proto=SMTP helo=<senderdomain.tld> Feb 19 17:41:36 sng02 postfix/cleanup[4011]: 95659407F5: message-id=<20130219164128.95659407F5 @ srv01.mydomain.local> Feb 19 17:41:36 sng02 postfix/qmgr[3992]: 95659407F5: from=<marco @ senderdomain.tld>, size=371, nrcpt=1 (queue active) Feb 19 17:41:36 sng02 dovecot: lda: Debug: Loading modules from directory: /usr/lib64/dovecot Feb 19 17:41:36 sng02 dovecot: lda: Debug: Module loaded: /usr/lib64/dovecot/lib10_quota_plugin.so Feb 19 17:41:36 sng02 dovecot: lda: Debug: Module loaded: /usr/lib64/dovecot/lib20_expire_plugin.so Feb 19 17:41:36 sng02 dovecot: lda: Debug: Module loaded: /usr/lib64/dovecot/lib90_sieve_plugin.so Feb 19 17:41:36 sng02 dovecot: auth: Debug: master in: USER#0111#011marco.carcano#011service=lda Feb 19 17:41:36 sng02 dovecot: auth: Debug: password(marco.carcano): passdb doesn't support credential lookups Feb 19 17:41:36 sng02 dovecot: auth: Error: static(marco.carcano): passdb doesn't support lookups, can't verify user's existence Feb 19 17:41:36 sng02 dovecot: auth: Debug: ldap(marco.carcano): user search: base=DC=mydomain,DC=local scope=subtree filter=(sAMAccountname=marco.carcano) fields=Mailbox,dovecotMailQuota Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap(marco.carcano): Connection appears to be hanging, reconnecting Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_unbind Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_free_request (origid 2, msgid 3) Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_free_request (origid 2, msgid 2) Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_free_connection 1 1 Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_send_unbind Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_free_connection: actually freed Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_free_connection 1 1 Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_send_unbind Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_free_connection: actually freed Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_create Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_bind Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_simple_bind Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_sasl_bind Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_send_initial_request Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_new_connection 1 1 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_int_open_connection Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_connect_to_host: TCP localhost:389 Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_new_socket: 16 Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_prepare_socket: 16 Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_connect_to_host: Trying ::1 389 Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_pvt_connect: fd: 16 tm: -1 async: 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_open_defconn: successful Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_send_server_request Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_result ld 0x666a60 msgid -1 Feb 19 17:41:36 sng02 dovecot: auth: Error: wait4msg ld 0x666a60 msgid -1 (timeout 0 usec) Feb 19 17:41:36 sng02 dovecot: auth: Error: wait4msg continue ld 0x666a60 msgid -1 all 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: ** ld 0x666a60 Connections: Feb 19 17:41:36 sng02 dovecot: auth: Error: * host: localhost port: 389 (default) Feb 19 17:41:36 sng02 dovecot: auth: Error: refcnt: 2 status: Connected Feb 19 17:41:36 sng02 dovecot: auth: Error: last used: Tue Feb 19 17:41:36 2013 Feb 19 17:41:36 sng02 dovecot: auth: Error: Feb 19 17:41:36 sng02 dovecot: auth: Error: Feb 19 17:41:36 sng02 dovecot: auth: Error: ** ld 0x666a60 Outstanding Requests: Feb 19 17:41:36 sng02 dovecot: auth: Error: * msgid 1, origid 1, status InProgress Feb 19 17:41:36 sng02 dovecot: auth: Error: outstanding referrals 0, parent count 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: ld 0x666a60 request count 1 (abandoned 0) Feb 19 17:41:36 sng02 dovecot: auth: Error: ** ld 0x666a60 Response Queue: Feb 19 17:41:36 sng02 dovecot: auth: Error: Empty Feb 19 17:41:36 sng02 dovecot: auth: Error: ld 0x666a60 response count 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_chkResponseList ld 0x666a60 msgid -1 all 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_chkResponseList returns ld 0x666a60 NULL Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_int_select Feb 19 17:41:36 sng02 dovecot: auth: Error: read1msg: ld 0x666a60 msgid -1 all 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: read1msg: ld 0x666a60 msgid 1 message type bind Feb 19 17:41:36 sng02 dovecot: auth: Error: read1msg: ld 0x666a60 0 new referrals Feb 19 17:41:36 sng02 dovecot: auth: Error: read1msg: mark request completed, ld 0x666a60 msgid 1 Feb 19 17:41:36 sng02 dovecot: auth: Error: request done: ld 0x666a60 msgid 1 Feb 19 17:41:36 sng02 dovecot: auth: Error: res_errno: 0, res_error: <>, res_matched: <> Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_free_request (origid 1, msgid 1) Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_parse_result Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_search Feb 19 17:41:36 sng02 dovecot: auth: Error: put_filter: "(sAMAccountname=marco.carcano)" Feb 19 17:41:36 sng02 dovecot: auth: Error: put_filter: simple Feb 19 17:41:36 sng02 dovecot: auth: Error: put_simple_filter: "sAMAccountname=marco.carcano" Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_send_initial_request Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_send_server_request Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_search Feb 19 17:41:36 sng02 dovecot: auth: Error: put_filter: "(sAMAccountname=marco.carcano)" Feb 19 17:41:36 sng02 dovecot: auth: Error: put_filter: simple Feb 19 17:41:36 sng02 dovecot: auth: Error: put_simple_filter: "sAMAccountname=marco.carcano" Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_send_initial_request Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_send_server_request Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_msgfree Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_result ld 0x666a60 msgid -1 Feb 19 17:41:36 sng02 dovecot: auth: Error: wait4msg ld 0x666a60 msgid -1 (timeout 0 usec) Feb 19 17:41:36 sng02 dovecot: auth: Error: wait4msg continue ld 0x666a60 msgid -1 all 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: ** ld 0x666a60 Connections: Feb 19 17:41:36 sng02 dovecot: auth: Error: * host: localhost port: 389 (default) Feb 19 17:41:36 sng02 dovecot: auth: Error: refcnt: 3 status: Connected Feb 19 17:41:36 sng02 dovecot: auth: Error: last used: Tue Feb 19 17:41:36 2013 Feb 19 17:41:36 sng02 dovecot: auth: Error: Feb 19 17:41:36 sng02 dovecot: auth: Error: Feb 19 17:41:36 sng02 dovecot: auth: Error: ** ld 0x666a60 Outstanding Requests: Feb 19 17:41:36 sng02 dovecot: auth: Error: * msgid 3, origid 3, status InProgress Feb 19 17:41:36 sng02 dovecot: auth: Error: outstanding referrals 0, parent count 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: * msgid 2, origid 2, status InProgress Feb 19 17:41:36 sng02 dovecot: auth: Error: outstanding referrals 0, parent count 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: ld 0x666a60 request count 2 (abandoned 0) Feb 19 17:41:36 sng02 dovecot: auth: Error: ** ld 0x666a60 Response Queue: Feb 19 17:41:36 sng02 dovecot: auth: Error: Empty Feb 19 17:41:36 sng02 dovecot: auth: Error: ld 0x666a60 response count 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_chkResponseList ld 0x666a60 msgid -1 all 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_chkResponseList returns ld 0x666a60 NULL Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_int_select Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_result ld 0x666a60 msgid -1 Feb 19 17:41:36 sng02 dovecot: auth: Error: wait4msg ld 0x666a60 msgid -1 (timeout 0 usec) Feb 19 17:41:36 sng02 dovecot: auth: Error: wait4msg continue ld 0x666a60 msgid -1 all 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: ** ld 0x666a60 Connections: Feb 19 17:41:36 sng02 dovecot: auth: Error: * host: localhost port: 389 (default) Feb 19 17:41:36 sng02 dovecot: auth: Error: refcnt: 3 status: Connected Feb 19 17:41:36 sng02 dovecot: auth: Error: last used: Tue Feb 19 17:41:36 2013 Feb 19 17:41:36 sng02 dovecot: auth: Error: Feb 19 17:41:36 sng02 dovecot: auth: Error: Feb 19 17:41:36 sng02 dovecot: auth: Error: ** ld 0x666a60 Outstanding Requests: Feb 19 17:41:36 sng02 dovecot: auth: Error: * msgid 3, origid 3, status InProgress Feb 19 17:41:36 sng02 dovecot: auth: Error: outstanding referrals 0, parent count 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: * msgid 2, origid 2, status InProgress Feb 19 17:41:36 sng02 dovecot: auth: Error: outstanding referrals 0, parent count 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: ld 0x666a60 request count 2 (abandoned 0) Feb 19 17:41:36 sng02 dovecot: auth: Error: ** ld 0x666a60 Response Queue: Feb 19 17:41:36 sng02 dovecot: auth: Error: Empty Feb 19 17:41:36 sng02 dovecot: auth: Error: ld 0x666a60 response count 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_chkResponseList ld 0x666a60 msgid -1 all 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_chkResponseList returns ld 0x666a60 NULL Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_int_select Feb 19 17:41:36 sng02 dovecot: auth: Error: read1msg: ld 0x666a60 msgid -1 all 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: read1msg: ld 0x666a60 msgid 2 message type search-entry Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_msgfree Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_result ld 0x666a60 msgid -1 Feb 19 17:41:36 sng02 dovecot: auth: Error: wait4msg ld 0x666a60 msgid -1 (timeout 0 usec) Feb 19 17:41:36 sng02 dovecot: auth: Error: wait4msg continue ld 0x666a60 msgid -1 all 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: ** ld 0x666a60 Connections: Feb 19 17:41:36 sng02 dovecot: auth: Error: * host: localhost port: 389 (default) Feb 19 17:41:36 sng02 dovecot: auth: Error: refcnt: 3 status: Connected Feb 19 17:41:36 sng02 dovecot: auth: Error: last used: Tue Feb 19 17:41:36 2013 Feb 19 17:41:36 sng02 dovecot: auth: Error: Feb 19 17:41:36 sng02 dovecot: auth: Error: Feb 19 17:41:36 sng02 dovecot: auth: Error: ** ld 0x666a60 Outstanding Requests: Feb 19 17:41:36 sng02 dovecot: auth: Error: * msgid 3, origid 3, status InProgress Feb 19 17:41:36 sng02 dovecot: auth: Error: outstanding referrals 0, parent count 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: * msgid 2, origid 2, status InProgress Feb 19 17:41:36 sng02 dovecot: auth: Error: outstanding referrals 0, parent count 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: ld 0x666a60 request count 2 (abandoned 0) Feb 19 17:41:36 sng02 dovecot: auth: Error: ** ld 0x666a60 Response Queue: Feb 19 17:41:36 sng02 dovecot: auth: Error: Empty Feb 19 17:41:36 sng02 dovecot: auth: Error: ld 0x666a60 response count 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_chkResponseList ld 0x666a60 msgid -1 all 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_chkResponseList returns ld 0x666a60 NULL Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_int_select Feb 19 17:41:36 sng02 dovecot: auth: Error: read1msg: ld 0x666a60 msgid -1 all 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: read1msg: ld 0x666a60 msgid 2 message type search-reference Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_chase_v3referrals Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_url_parse_ext(ldap://mydomain.local/CN=Configuration,DC=mydomain,DC=local) Feb 19 17:41:36 sng02 dovecot: auth: Error: re_encode_request: new msgid 4, new dn <CN=Configuration,DC=mydomain,DC=local> Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_chase_v3referral: msgid 2, url "ldap://mydomain.local/CN=Configuration,DC=mydomain,DC=local" Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_send_server_request Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_new_connection 0 1 1 Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_int_open_connection Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_connect_to_host: TCP mydomain.local:389 Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_new_socket: 18 Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_prepare_socket: 18 Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_connect_to_host: Trying 192.168.32.2:389 Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_pvt_connect: fd: 18 tm: -1 async: 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: anonymous rebind via ldap_sasl_bind("") Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_sasl_bind Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_send_initial_request Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_send_server_request Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_result ld 0x666a60 msgid 5 Feb 19 17:41:36 sng02 dovecot: auth: Error: wait4msg ld 0x666a60 msgid 5 (timeout 100000 usec) Feb 19 17:41:36 sng02 dovecot: auth: Error: wait4msg continue ld 0x666a60 msgid 5 all 1 Feb 19 17:41:36 sng02 dovecot: auth: Error: ** ld 0x666a60 Connections: Feb 19 17:41:36 sng02 dovecot: auth: Error: * host: mydomain.local port: 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: refcnt: 2 status: Connected Feb 19 17:41:36 sng02 dovecot: auth: Error: last used: Tue Feb 19 17:41:36 2013 Feb 19 17:41:36 sng02 dovecot: auth: Error: rebind in progress Feb 19 17:41:36 sng02 dovecot: auth: Error: queue is empty Feb 19 17:41:36 sng02 dovecot: auth: Error: Feb 19 17:41:36 sng02 dovecot: auth: Error: * host: localhost port: 389 (default) Feb 19 17:41:36 sng02 dovecot: auth: Error: refcnt: 4 status: Connected Feb 19 17:41:36 sng02 dovecot: auth: Error: last used: Tue Feb 19 17:41:36 2013 Feb 19 17:41:36 sng02 dovecot: auth: Error: Feb 19 17:41:36 sng02 dovecot: auth: Error: Feb 19 17:41:36 sng02 dovecot: auth: Error: ** ld 0x666a60 Outstanding Requests: Feb 19 17:41:36 sng02 dovecot: auth: Error: * msgid 5, origid 5, status InProgress Feb 19 17:41:36 sng02 dovecot: auth: Error: outstanding referrals 0, parent count 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: * msgid 3, origid 3, status InProgress Feb 19 17:41:36 sng02 dovecot: auth: Error: outstanding referrals 0, parent count 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: * msgid 2, origid 2, status InProgress Feb 19 17:41:36 sng02 dovecot: auth: Error: outstanding referrals 1, parent count 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: ld 0x666a60 request count 3 (abandoned 0) Feb 19 17:41:36 sng02 dovecot: auth: Error: ** ld 0x666a60 Response Queue: Feb 19 17:41:36 sng02 dovecot: auth: Error: Empty Feb 19 17:41:36 sng02 dovecot: auth: Error: ld 0x666a60 response count 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_chkResponseList ld 0x666a60 msgid 5 all 1 Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_chkResponseList returns ld 0x666a60 NULL Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_int_select Feb 19 17:41:36 sng02 dovecot: auth: Error: read1msg: ld 0x666a60 msgid 5 all 1 Feb 19 17:41:36 sng02 dovecot: auth: Error: read1msg: ld 0x666a60 msgid 2 message type search-result Feb 19 17:41:36 sng02 dovecot: auth: Error: read1msg: ld 0x666a60 0 new referrals Feb 19 17:41:36 sng02 dovecot: auth: Error: read1msg: mark request completed, ld 0x666a60 msgid 2 Feb 19 17:41:36 sng02 dovecot: auth: Error: wait4msg ld 0x666a60 0 s 99954 us to go Feb 19 17:41:36 sng02 dovecot: auth: Error: wait4msg continue ld 0x666a60 msgid 5 all 1 Feb 19 17:41:36 sng02 dovecot: auth: Error: ** ld 0x666a60 Connections: Feb 19 17:41:36 sng02 dovecot: auth: Error: * host: mydomain.local port: 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: refcnt: 2 status: Connected Feb 19 17:41:36 sng02 dovecot: auth: Error: last used: Tue Feb 19 17:41:36 2013 Feb 19 17:41:36 sng02 dovecot: auth: Error: rebind in progress Feb 19 17:41:36 sng02 dovecot: auth: Error: queue is empty Feb 19 17:41:36 sng02 dovecot: auth: Error: Feb 19 17:41:36 sng02 dovecot: auth: Error: * host: localhost port: 389 (default) Feb 19 17:41:36 sng02 dovecot: auth: Error: refcnt: 3 status: Connected Feb 19 17:41:36 sng02 dovecot: auth: Error: last used: Tue Feb 19 17:41:36 2013 Feb 19 17:41:36 sng02 dovecot: auth: Error: Feb 19 17:41:36 sng02 dovecot: auth: Error: Feb 19 17:41:36 sng02 dovecot: auth: Error: ** ld 0x666a60 Outstanding Requests: Feb 19 17:41:36 sng02 dovecot: lda: Debug: auth input: marco.carcano quota_rule=*:storage=8192M Feb 19 17:41:36 sng02 dovecot: lda: Debug: Added userdb setting: plugin/quota_rule=*:storage=8192M Feb 19 17:41:36 sng02 dovecot: lda(marco.carcano): Debug: Effective uid=8, gid=12, home= Feb 19 17:41:36 sng02 dovecot: lda(marco.carcano): Debug: Quota root: name=User quota backend=maildir args= Feb 19 17:41:36 sng02 dovecot: lda(marco.carcano): Debug: Quota rule: root=User quota mailbox=* bytes=8589934592 messages=0 Feb 19 17:41:36 sng02 dovecot: lda(marco.carcano): Debug: Quota rule: root=User quota mailbox=Trash bytes=+104857600 messages=0 Feb 19 17:41:36 sng02 dovecot: lda(marco.carcano): Debug: Quota warning: bytes=8160437862 (95%) messages=0 reverse=no command=quota-warning 95 marco.carcano Feb 19 17:41:36 sng02 dovecot: lda(marco.carcano): Debug: Quota warning: bytes=7301444403 (85%) messages=0 reverse=no command=quota-warning 85 marco.carcano Feb 19 17:41:36 sng02 dovecot: lda(marco.carcano): Debug: Quota warning: bytes=6442450944 (75%) messages=0 reverse=no command=quota-warning 75 marco.carcano Feb 19 17:41:36 sng02 dovecot: lda(marco.carcano): Debug: Quota root: name=Shared quota backend=maildir args=ns=Public/ Feb 19 17:41:36 sng02 dovecot: lda(marco.carcano): Debug: Quota rule: root=Shared quota mailbox=* bytes=20971520000 messages=0 Feb 19 17:41:36 sng02 dovecot: lda: Error: user marco.carcano: Auth USER lookup failed Feb 19 17:41:36 sng02 dovecot: lda: Debug: auth input: Feb 19 17:41:36 sng02 dovecot: lda: Fatal: Internal error occurred. Refer to server log for more information. Feb 19 17:41:36 sng02 dovecot: lda(marco.carcano): Debug: Namespace : type=private, prefix=, sep=/, inbox=yes, hidden=no, list=yes, subscriptions=yes location=maildir:/home/mailboxstore/marco.carcano/Maildir Feb 19 17:41:36 sng02 dovecot: lda(marco.carcano): Debug: maildir++: root=/home/mailboxstore/marco.carcano/Maildir, index=, control=, inbox=/home/mailboxstore/marco.carcano/Maildir Feb 19 17:41:36 sng02 dovecot: lda(marco.carcano): Debug: Namespace : type=shared, prefix=shared/%u/, sep=/, inbox=no, hidden=no, list=children, subscriptions=no location=maildir:/home/mailboxstore/%Lu/Maildir:INDEX=/home/mailboxstore/marco.carcano/Maildir/shared/%Lu Feb 19 17:41:36 sng02 dovecot: lda(marco.carcano): Debug: shared: root=/var/run/dovecot, index=, control=, inbox= Feb 19 17:41:36 sng02 dovecot: lda(marco.carcano): Debug: Namespace : type=public, prefix=Public/, sep=/, inbox=no, hidden=no, list=yes, subscriptions=no location=maildir:/home/mailboxstore/public Feb 19 17:41:36 sng02 dovecot: lda(marco.carcano): Debug: maildir++: root=/home/mailboxstore/public, index=, control=, inbox= Feb 19 17:41:36 sng02 dovecot: lda(marco.carcano): Debug: expire: No expire setting - plugin disabled Feb 19 17:41:36 sng02 dovecot: lda(marco.carcano): Debug: Quota root: name=User quota backend=maildir args= Feb 19 17:41:36 sng02 dovecot: lda(marco.carcano): Debug: Quota rule: root=User quota mailbox=* bytes=1073741824 messages=0 Feb 19 17:41:36 sng02 dovecot: lda(marco.carcano): Debug: Quota rule: root=User quota mailbox=Trash bytes=+104857600 messages=0 Feb 19 17:41:36 sng02 dovecot: lda(marco.carcano): Debug: Quota warning: bytes=1020054732 (95%) messages=0 reverse=no command=quota-warning 95 marco.carcano Feb 19 17:41:36 sng02 dovecot: lda(marco.carcano): Debug: Quota warning: bytes=912680550 (85%) messages=0 reverse=no command=quota-warning 85 marco.carcano Feb 19 17:41:36 sng02 dovecot: lda(marco.carcano): Debug: Quota warning: bytes=805306368 (75%) messages=0 reverse=no command=quota-warning 75 marco.carcano Feb 19 17:41:36 sng02 dovecot: lda(marco.carcano): Debug: Quota root: name=Shared quota backend=maildir args=ns=Public/ Feb 19 17:41:36 sng02 dovecot: lda(marco.carcano): Debug: Quota rule: root=Shared quota mailbox=* bytes=20971520000 messages=0 Feb 19 17:41:36 sng02 dovecot: lda(marco.carcano): Debug: none: root=, index=, control=, inbox= Feb 19 17:41:36 sng02 dovecot: lda(marco.carcano): Error: User marco.carcano doesn't have home dir set, disabling duplicate database Feb 19 17:41:36 sng02 dovecot: lda(marco.carcano): Debug: sieve: user's script path /home/mailboxstore/marco.carcano/.dovecot.sieve doesn't exist (using global script path in stead) Feb 19 17:41:36 sng02 dovecot: lda(marco.carcano): Debug: sieve: user has no valid personal script Feb 19 17:41:36 sng02 dovecot: lda(marco.carcano): Debug: sieve: no scripts to execute: reverting to default delivery. Feb 19 17:41:36 sng02 postfix/pipe[3995]: 7D9AE407E7: to=<marco.carcano @ mydomain.local>, orig_to=<mac @ mydomain.com>, relay=dovecot, delay=17102, delays=17034/0.05/0/68, dsn=4.3.0, status=deferred (temporary failure) Feb 19 17:41:36 sng02 dovecot: lda(marco.carcano): msgid=<20130219164128.95659407F5 @ srv01.mydomain.local>: saved mail to INBOX Feb 19 17:41:36 sng02 postfix/pipe[4013]: 95659407F5: to=<marco.carcano @ mydomain.local>, orig_to=<mac @ mydomain.com>, relay=dovecot, delay=22, delays=22/0.02/0/0.14, dsn=2.0.0, status=sent (delivered via dovecot service) Feb 19 17:41:36 sng02 postfix/qmgr[3992]: 95659407F5: removed Feb 19 17:41:38 sng02 postfix/smtpd[4006]: disconnect from localhost[127.0.0.1] ############################## END OF MAIL SUCCEFFULLY DELIVERED LOG #############################################

1 0

[Dovecot] Changin password in LDAP
by Arto Saraniva 20 Feb '13

20 Feb '13

We are using now dovecot 2.0.21 with open-ldap, but this situations has already taken a quite long time. When user changes the password, we have to reload dovecot every time, otherwise the change is ignored and dovecot sees only the old password. Any ideas where the problem might exist? Conf: # 2.0.21: /etc/dovecot/dovecot.conf # OS: Linux 2.6.18-308.24.1.el5 i686 CentOS release 5.9 (Final) auth_cache_size = 100 M auth_mechanisms = plain login auth_verbose = yes default_process_limit = 5000 disable_plaintext_auth = no info_log_path = /var/log/dovecot.log mail_location = maildir:~/Maildir:INDEX=/var/spool/indexes/%u 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 mbox_write_locks = fcntl passdb { args = /etc/dovecot/dovecot-ldap.conf.ext driver = ldap } plugin { quota = maildir:User Quota sieve = ~/.dovecot.sieve sieve_dir = ~/sieve } postmaster_address = postmaster(a)artio.net service auth { unix_listener /var/spool/postfix/private/auth { mode = 0666 } } service imap-login { service_count = 0 } service imap-postlogin { executable = script-login /usr/local/sbin/dovecot-postscript-imap user = root } service imap { executable = imap imap-postlogin } service pop3-postlogin { executable = script-login /usr/local/sbin/dovecot-postscript-pop3 user = root } service pop3 { executable = pop3 pop3-postlogin } ssl_ca = </usr/share/ssl/certs/mail_artio_net-2012-geotrust.ca ssl_cert = </usr/share/ssl/certs/mail_artio_net-2012-geotrust.crt ssl_key = </usr/share/ssl/private/mail_artio_net-2012-geotrust.key userdb { args = /etc/dovecot/dovecot-ldap.conf.ext driver = ldap } protocol lda { mail_plugins = sieve quota } protocol imap { mail_max_userip_connections = 50 mail_plugins = quota imap_quota } protocol pop3 { mail_plugins = quota pop3_uidl_format = %08Xu%08Xv } Dovecot-ldap.conf: # NOTE: We don't support "authentication binds", so you'll have to give # dovecot-auth read access to userPassword field in LDAP server. With OpenLDAP # this is done by modifying /etc/ldap/slapd.conf. There should already be # something like this: # access to attribute=userPassword # by dn="<dovecot's dn>" read # add this # by anonymous auth # by self write # by * none # Space separated list of LDAP hosts to use. host:port is allowed too. #hosts = hosts = 123.123.123.123 123.123.123.124 # Distinguished Name - the username used to login to the LDAP server #dn = # Password for LDAP server #dnpass = # LDAP protocol version to use. Likely 2 or 3. ldap_version = 3 # LDAP base #base = uid=someone, dc=foo, dc=bar, dc=org base = dc=artio,dc=net # Dereference: never, searching, finding, always deref = never # Search scope: base, onelevel, subtree scope = subtree # User attributes in order: # Virtual user name (user@domain) # Home directory # MAIL environment # System user name (for getting user's groups from /etc/group) # - For virtual users you don't want to use this, so this defaults to none. # System UID # System GID #user_attrs = uid,homeDirectory,,,uidNumber,gidNumber # user_attrs = homeDirectory=home,uidNumber=uid,gidNumber=gid # user_attrs = cn,homeDirectory,,uid,uidNumber,gidNumber #user_attrs = homeDirectory=home,uidNumber=uid,gidNumber=gid user_attrs = homeDirectory=home,uidNumber=uid,gidNumber=gid,artioMailQuotaSize=quota_rule=*:storage=%$M # Filter for user lookup. Some variables can be used: # %u - username # %n - user part in user@domain, same as %u if there's no domain # %d - domain part in user@domain, empty if user there's no domain #user_filter = (&(objectClass=posixAccount)(uid=%u)) user_filter = (&(objectClass=posixAccount)(|(uid=%u)(mail=%u))) # Password checking attributes in order: # Virtual user name (user@domain) # Password, may optionally start with {type}, eg. {crypt} #pass_attrs = uid,userPassword # pass_attrs = cn,userPassword pass_attrs = uid=user, userPassword=password # Filter for password lookups #pass_filter = (&(objectClass=posixAccount)(uid=%u)) pass_filter = (&(objectClass=posixAccount)(|(uid=%u)(mail=%u))) # Default password scheme. "{scheme}" before password overrides this. # Currently supported schemes include PLAIN, PLAIN-MD5, DIGEST-MD5, CRYPT #default_pass_scheme = CRYPT default_pass_scheme = CRYPT # You can use same UID and GID for all user accounts if you really want to. # If the UID/GID is still found from LDAP reply, it overrides these values. #user_global_uid = #user_global_gid = Pam: /etc/pam.d/dovecot #%PAM-1.0 auth required pam_nologin.so auth include system-auth account include system-auth session include system-auth

1 0

[Dovecot] Dovecot 2 + Quota - CentOS 6.3
by drum.lucas＠gmail.com 20 Feb '13

20 Feb '13

Hello, I've a postfix+postfixadmin+mysql server+roundcubemail centos 6 mail server. My question is as follows: In postfixadmin it's possible that he show me how the mailbox is full. Show this information is dovecot service? What is the purpose of quota in dovecot? Thanks! *Lucas Possamai *

2 1

[Dovecot] 1.x with mbox files to 2.x with mdbox, I think?
by Ken A 20 Feb '13

20 Feb '13

Hi, I have a couple questions about migrating from 1.x to 2.x I'm needing to support larger mailbox sizes and mdbox seems like the right format to use to get larger size boxes and maintain, or possibly even increase speed. Is that correct? Am I correct that the best way to accomplish this migration is to copy the mboxes over to the new server and then use dsync to convert them to mdbox? Thanks for your thoughts! Ken -- Ken Anderson Pacific Internet - http://www.pacific.net Latest Pacific.Net Status - http://twitter.com/pacnetstatus

1 0

[Dovecot] Ping re: error running indexer-worker as non-root user
by Mike Abbott 19 Feb '13

19 Feb '13

Any hints about the issue I wrote about on Feb. 11? http://markmail.org/message/6g7itsu2u3fdnfkd Thanks.

1 0

[Dovecot] Dovecot-2.1.14 - pop3 processes always hangs forever - another follow-up
by Axel Luttgens 19 Feb '13

19 Feb '13

Hello, With the same basic configs as in my previous messages, I tried with the maildir format instead of the mbox format. That is, in both cases ("virtual" uids/gids vs a single "real" uid/gid), doveconf -n shows: mail_location = maildir:~/maildir instead of: mail_location = mbox:~/mboxes:INBOX=~/mboxes/inbox Here too, with "virtual" uids/gids, connections thru pop hang forever, while imap connections behave flawlessly. And with a single "real" uid/gid, connections thru both pop and imap behave as expected. As a result, it could be inferred that the problems I am encountering with pop connections do not depend on the mailbox format in use, and that they are entirely related to "virtual" uids/gids. To recap: with this very basic config # 2.1.14: /_ETC/dovecot/dovecot.conf # OS: Darwin 12.2.1 x86_64 auth_verbose = yes disable_plaintext_auth = no mail_debug = yes mail_location = mbox:~/mboxes:INBOX=~/mboxes/inbox passdb { args = /_ETC/dovecot/db.conf driver = sql } ssl = no userdb { driver = prefetch } a pop connection hangs forever after the pass command $ telnet 127.0.0.1 110 Trying 127.0.0.1... Connected to localhost. Escape character is '^]'. +OK Dovecot ready. user user2 +OK pass pass2 and the log shows (here, when the user connects for the first time) dovecot[2997]: pop3-login: Login: user=<user2>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, mpid=3113, secured, session=<GTOlMjfV3gB/AAAB> dovecot[2997]: pop3(user2): Debug: Effective uid=100003, gid=100003, home=/_Data/Mailstores/100003 dovecot[2997]: pop3(user2): Debug: Home dir not found: /_Data/Mailstores/100003 dovecot[2997]: pop3(user2): Debug: fs: root=/_Data/Mailstores/100003/mboxes, index=, control=, inbox=/_Data/Mailstores/100003/mboxes/inbox, alt= dovecot[2997]: pop3(user2): Debug: Namespace : /_Data/Mailstores/100003/mboxes doesn't exist yet, using default permissions dovecot[2997]: pop3(user2): Debug: Namespace : Using permissions from /_Data/Mailstores/100003/mboxes: mode=0700 gid=-1 dovecot[2997]: pop3(user2): Debug: Namespace : /_Data/Mailstores/100003/mboxes/inbox doesn't exist yet, using default permissions dovecot[2997]: pop3(user2): Debug: Namespace : Using permissions from /_Data/Mailstores/100003/mboxes: mode=0700 gid=-1 dovecot[2997]: pop3(user2): Debug: Namespace : /_Data/Mailstores/100003/mboxes/inbox doesn't exist yet, using default permissions dovecot[2997]: pop3(user2): Debug: Namespace : Using permissions from /_Data/Mailstores/100003/mboxes: mode=0700 gid=-1 With exactly the same config, imap connections are fully functional. Does someone have an explanation? TIA, Axel

2 11