kfx
2018-Apr-17 12:18 UTC
Bug: Dovecot index loosing sync with FTS despite "fts_autoindex = yes"
dovecot 2.2.34 solr 7.2 I only see new messages after typing on the server "doveadm fts rescan -u username" though I've followed the wiki and added "fts_autoindex yes" in 90-plugin.conf . Subsequent search for the same pattern always gives the same result, ignoring new emails with that particular pattern. Solr is working correctly and the correct search results comes immediately (whatever the searched word) after a "doveadm fts rescan" # doveconf | grep fts mail_plugins = " quota stats fts fts_solr" ? fts = solr ? fts_autoindex = yes ? fts_solr = url=http://localhost:8983/solr/dovecot/ [POP]? mail_plugins = " quota stats fts fts_solr sieve virtual" [IMAP]? mail_plugins = " quota stats fts fts_solr imap_quota virtual imap_stats"
kadafax at gmail.com
2018-Apr-17 20:01 UTC
Bug: Dovecot index loosing sync with FTS despite "fts_autoindex = yes"
Le 17/04/2018 ? 14:18, kfx a ?crit?:> dovecot 2.2.34 > solr 7.2 > > I only see new messages after typing on the server "doveadm fts rescan > -u username" though I've followed the wiki and added "fts_autoindex > yes" in 90-plugin.conf . Subsequent search for the same pattern always > gives the same result, ignoring new emails with that particular pattern. > Solr is working correctly and the correct search results comes > immediately (whatever the searched word) after a "doveadm fts rescan" > > # doveconf | grep fts > mail_plugins = " quota stats fts fts_solr" > ? fts = solr > ? fts_autoindex = yes > ? fts_solr = url=http://localhost:8983/solr/dovecot/ > [POP]? mail_plugins = " quota stats fts fts_solr sieve virtual" > [IMAP]? mail_plugins = " quota stats fts fts_solr imap_quota virtual > imap_stats" > > > >Here are some debug logs from a search (responding with incorrect - or old - results, as new emails have arrived, containing the same "MySearchPattern" pattern). This leads me to a problem on the dovecot side. Only a "doveadm fts rescan -u username" can solve this situation, so should I add a cronjob for it ? It defeats the purpose of solr as the first search after is really slow (but correct). Here are the logs, please tell me if I should provide more info, and thanks for any help: Apr 17 21:44:56 imap(MyUsername): Debug: http-client: host localhost: Host created Apr 17 21:44:56 imap(MyUsername): Debug: http-client: host localhost: DNS lookup successful; got 2 IPs Apr 17 21:44:56 imap(MyUsername): Debug: http-client: peer [::1]:8983: Peer created Apr 17 21:44:56 imap(MyUsername): Debug: http-client: queue http://localhost:8983: Setting up connection to [::1]:8983 (1 requests pending) Apr 17 21:44:56 imap(MyUsername): Debug: http-client: peer [::1]:8983: Linked queue http://localhost:8983 (1 queues linked) Apr 17 21:44:56 imap(MyUsername): Debug: http-client: queue http://localhost:8983: Started new connection to [::1]:8983 Apr 17 21:44:56 imap(MyUsername): Debug: http-client: request [Req1: GET http://localhost:8983/solr/dovecot/select?fl=uid,score&rows=25495&sort=uid+asc&q=%7b!lucene+q.op%3dAND%7d(hdr:MySearchPattern+OR+body:MySearchPattern)&fq=%2Bbox:e09cce0283e8695ab760000002deed92+%2Buser:MyUsername]: Submitted Apr 17 21:44:56 imap(MyUsername): Debug: http-client: Waiting for 1 requests to finish Apr 17 21:44:56 imap(MyUsername): Debug: http-client: peer [::1]:8983: Creating 1 new connections to handle requests (already 0 usable, connecting to 0, closing 0) Apr 17 21:44:56 imap(MyUsername): Debug: http-client: peer [::1]:8983: Making new connection 1 of 1 Apr 17 21:44:56 imap(MyUsername): Debug: http-client: conn [::1]:8983 [0]: HTTP connection created (1 parallel connections exist) Apr 17 21:44:56 imap(MyUsername): Debug: http-client: conn [::1]:8983 [0]: Connected Apr 17 21:44:56 imap(MyUsername): Debug: http-client: conn [::1]:8983 [0]: Ready for requests Apr 17 21:44:56 imap(MyUsername): Debug: http-client: peer [::1]:8983: Successfully connected (connections=1) Apr 17 21:44:56 imap(MyUsername): Debug: http-client: peer [::1]:8983: Using 1 idle connections to handle 1 requests (1 total connections ready) Apr 17 21:44:56 imap(MyUsername): Debug: http-client: queue http://localhost:8983: Connection to peer [::1]:8983 claimed request [Req1: GET http://localhost:8983/solr/dovecot/select?fl=uid,score&rows=25495&sort=uid+asc&q=%7b!lucene+q.op%3dAND%7d(hdr:MySearchPattern+OR+body:MySearchPattern)&fq=%2Bbox:e09cce0283e8695ab760000002deed92+%2Buser:MyUsername] Apr 17 21:44:56 imap(MyUsername): Debug: http-client: conn [::1]:8983 [0]: Claimed request [Req1: GET http://localhost:8983/solr/dovecot/select?fl=uid,score&rows=25495&sort=uid+asc&q=%7b!lucene+q.op%3dAND%7d(hdr:MySearchPattern+OR+body:MySearchPattern)&fq=%2Bbox:e09cce0283e8695ab760000002deed92+%2Buser:MyUsername] Apr 17 21:44:56 imap(MyUsername): Debug: http-client: request [Req1: GET http://localhost:8983/solr/dovecot/select?fl=uid,score&rows=25495&sort=uid+asc&q=%7b!lucene+q.op%3dAND%7d(hdr:MySearchPattern+OR+body:MySearchPattern)&fq=%2Bbox:e09cce0283e8695ab760000002deed92+%2Buser:MyUsername]: Sent header Apr 17 21:44:56 imap(MyUsername): Debug: http-client: peer [::1]:8983: No more requests to service for this peer (1 connections exist) Apr 17 21:44:56 imap(MyUsername): Debug: http-client: conn [::1]:8983 [0]: Got 200 response for request [Req1: GET http://localhost:8983/solr/dovecot/select?fl=uid,score&rows=25495&sort=uid+asc&q=%7b!lucene+q.op%3dAND%7d(hdr:MySearchPattern+OR+body:MySearchPattern)&fq=%2Bbox:e09cce0283e8695ab760000002deed92+%2Buser:MyUsername] (took 109 ms + 23 ms in queue) Apr 17 21:44:56 imap(MyUsername): Debug: http-client: conn [::1]:8983 [0]: Response payload stream destroyed (0 ms after initial response) Apr 17 21:44:56 imap(MyUsername): Debug: http-client: request [Req1: GET http://localhost:8983/solr/dovecot/select?fl=uid,score&rows=25495&sort=uid+asc&q=%7b!lucene+q.op%3dAND%7d(hdr:MySearchPattern+OR+body:MySearchPattern)&fq=%2Bbox:e09cce0283e8695ab760000002deed92+%2Buser:MyUsername]: Finished Apr 17 21:44:56 imap(MyUsername): Debug: http-client: queue http://localhost:8983: Dropping request [Req1: GET http://localhost:8983/solr/dovecot/select?fl=uid,score&rows=25495&sort=uid+asc&q=%7b!lucene+q.op%3dAND%7d(hdr:MySearchPattern+OR+body:MySearchPattern)&fq=%2Bbox:e09cce0283e8695ab760000002deed92+%2Buser:MyUsername] Apr 17 21:44:56 imap(MyUsername): Debug: http-client: host localhost: Host is idle (timeout = 1799867 msecs) Apr 17 21:44:56 imap(MyUsername): Debug: http-client: request [Req1: GET http://localhost:8983/solr/dovecot/select?fl=uid,score&rows=25495&sort=uid+asc&q=%7b!lucene+q.op%3dAND%7d(hdr:MySearchPattern+OR+body:MySearchPattern)&fq=%2Bbox:e09cce0283e8695ab760000002deed92+%2Buser:MyUsername]: Free (requests left=1) Apr 17 21:44:56 imap(MyUsername): Debug: http-client: All requests finished Apr 17 21:44:56 imap(MyUsername): Debug: http-client: peer [::1]:8983: No requests to service for this peer (1 connections exist) Apr 17 21:44:56 imap(MyUsername): Debug: http-client: conn [::1]:8983 [0]: No more requests queued; going idle (timeout = 5000 msecs)
kadafax at gmail.com
2018-Apr-19 08:30 UTC
Bug: Dovecot index loosing sync with FTS despite "fts_autoindex = yes"
I think I'm progressing: if I create a brand new user, send her an email, it will not be indexed right away. I need to doveadm rescan / index the Inbox before. At the end of this email, a dovecot's debug log snipset (grep'ed on this user). In it I can read: "Debug: fts: Indexes disabled for namespace '' Can this be a problem ? Thanks doveconf -n output: # 2.2.34 (874deae): /usr/local/etc/dovecot/dovecot.conf # Pigeonhole version 0.4.22 (22940fb7) # OS: Linux 3.10.0-693.17.1.el7.x86_64 x86_64 CentOS Linux release 7.4.1708 (Core)? ext4 # Hostname: mailServer.myDomain auth_master_user_separator = * auth_socket_path = /var/run/dovecot/auth-userdb auth_username_chars abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ01234567890.-_@* auth_verbose = yes base_dir = /var/run/dovecot/ debug_log_path = /var/log/dovecot-debug.log default_client_limit = 5120 default_process_limit = 1024 default_vsz_limit = 2 G hostname = myDomain info_log_path = /var/log/dovecot.log lda_mailbox_autocreate = yes lda_mailbox_autosubscribe = yes listen = * log_path = /var/log/dovecot-error.log login_greeting = Welcome login_log_format_elements = user=<%u> method=%m rip=%r lip=%l mpid=%e %c mail_gid = vmail mail_location = maildir:/var/vmail/%Ln mail_plugins = " quota stats fts fts_solr" mail_uid = vmail 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 index ihave duplicate mime foreverypart extracttext namespace { ? inbox = yes ? location = maildir:/var/vmail/%Ln ? mailbox Drafts { ??? auto = subscribe ??? special_use = \Drafts ? } ? mailbox Sent { ??? auto = subscribe ??? special_use = \Sent ? } ? mailbox "Sent Messages" { ??? special_use = \Sent ? } ? mailbox Trash { ??? auto = subscribe ??? special_use = \Trash ? } ? prefix ? type = private } passdb { ? args = /usr/local/etc/dovecot/deny-users ? deny = yes ? driver = passwd-file } passdb { ? args = /usr/local/etc/dovecot/master-users ? driver = passwd-file ? master = yes } passdb { ? args = /usr/local/etc/dovecot/dovecot-ldap.conf.ext ? driver = ldap } plugin { ? fts = solr ? fts_autoindex = yes ? fts_solr = url=http://localhost:8983/solr/dovecot/ break-imap-search ? quota = maildir:User quota ? quota_rule = *:storage=20GB ? quota_rule2 = Trash:storage=+200M ? quota_warning = storage=95%% quota-warning 95 %u ? quota_warning2 = storage=80%% quota-warning 80 %u ? sieve = /var/sieve-scripts/%Ln.sieve ? sieve_dir = /var/vmail/%Ln/home/sieve ? stats_command_min_time = 1 mins ? stats_domain_min_time = 12 hours ? stats_ip_min_time = 12 hours ? stats_memory_limit = 16 M ? stats_refresh = 30 secs ? stats_session_min_time = 15 mins ? stats_track_cmds = yes ? stats_user_min_time = 1 hours } postmaster_address = postmaster at myDomain protocols = imap pop3 sieve sieve service auth-worker { ? user = root } service auth { ? unix_listener /var/spool/postfix/private/auth { ??? mode = 0777 ??? user = vmail ? } } service imap-login { ? inet_listener imaps { ??? port = 993 ??? ssl = yes ? } ? process_min_avail = 10 } service imap { ? process_limit = 2128 } service managesieve-login { ? inet_listener sieve { ??? port = 4190 ? } } service pop3-login { ? inet_listener pop3s { ??? port = 995 ??? ssl = yes ? } } service quota-warning { ? executable = script /usr/local/bin/quota-warning.sh ? user = nobody } service stats { ? fifo_listener stats-mail { ??? mode = 0600 ??? user = vmail ? } } ssl_cert = </etc/letsencrypt/live/mailServer.myDomain/fullchain.pem ssl_key =? # hidden, use -P to show it userdb { ? args = /usr/local/etc/dovecot/dovecot-ldap-userdb.conf.ext ? driver = ldap ? override_fields = uid=vmail gid=vmail home=/var/vmail/%Ln/home } verbose_proctitle = yes protocol lda { ? mail_plugins = " quota stats fts fts_solr sieve virtual" } protocol imap { ? mail_max_userip_connections = 20 ? mail_plugins = " quota stats fts fts_solr imap_quota virtual imap_stats" } protocol sieve { ? mail_max_userip_connections = 20 } DEBUG LOG: Apr 19 10:23:26 lda(NewUser at myDomain): Debug: Loading modules from directory: /usr/local/lib/dovecot Apr 19 10:23:26 lda(NewUser at myDomain): Debug: Module loaded: /usr/local/lib/dovecot/lib10_quota_plugin.so Apr 19 10:23:26 lda(NewUser at myDomain): Debug: Module loaded: /usr/local/lib/dovecot/lib20_fts_plugin.so Apr 19 10:23:26 lda(NewUser at myDomain): Debug: Module loaded: /usr/local/lib/dovecot/lib20_virtual_plugin.so Apr 19 10:23:26 lda(NewUser at myDomain): Debug: Module loaded: /usr/local/lib/dovecot/lib21_fts_solr_plugin.so Apr 19 10:23:26 lda(NewUser at myDomain): Debug: Module loaded: /usr/local/lib/dovecot/lib90_sieve_plugin.so Apr 19 10:23:26 lda(NewUser at myDomain): Debug: Module loaded: /usr/local/lib/dovecot/lib90_stats_plugin.so Apr 19 10:23:26 lda(NewUser at myDomain): Debug: auth USER input: NewUser at myDomain uid=992 gid=989 home=/var/vmail/NewUser/home Apr 19 10:23:26 lda(NewUser at myDomain): Debug: Effective uid=992, gid=989, home=/var/vmail/NewUser/home Apr 19 10:23:26 lda(NewUser at myDomain): Debug: Quota root: name=User quota backend=maildir argsApr 19 10:23:26 lda(NewUser at myDomain): Debug: Quota rule: root=User quota mailbox=* bytes=21474836480 messages=0 Apr 19 10:23:26 lda(NewUser at myDomain): Debug: Quota rule: root=User quota mailbox=Trash bytes=+209715200 messages=0 Apr 19 10:23:26 lda(NewUser at myDomain): Debug: Quota warning: bytes=20401094656 (95%) messages=0 reverse=no command=quota-warning 95 NewUser at myDomain Apr 19 10:23:26 lda(NewUser at myDomain): Debug: Quota warning: bytes=17179869184 (80%) messages=0 reverse=no command=quota-warning 80 NewUser at myDomain Apr 19 10:23:26 lda(NewUser at myDomain): Debug: Quota grace: root=User quota bytes=2147483648 (10%) Apr 19 10:23:26 lda(NewUser at myDomain): Debug: Namespace : type=private, prefix=, sep=, inbox=yes, hidden=no, list=yes, subscriptions=yes location=maildir:/var/vmail/NewUser Apr 19 10:23:26 lda(NewUser at myDomain): Debug: maildir++: root=/var/vmail/NewUser, index=, indexpvt=, control=, inbox=/var/vmail/NewUser, altApr 19 10:23:26 lda(NewUser at myDomain): Debug: quota: quota_over_flag check: quota_over_script unset - skipping Apr 19 10:23:26 lda(NewUser at myDomain): Debug: Quota root: name=User quota backend=maildir argsApr 19 10:23:26 lda(NewUser at myDomain): Debug: Quota rule: root=User quota mailbox=* bytes=21474836480 messages=0 Apr 19 10:23:26 lda(NewUser at myDomain): Debug: Quota rule: root=User quota mailbox=Trash bytes=+209715200 messages=0 Apr 19 10:23:26 lda(NewUser at myDomain): Debug: Quota warning: bytes=20401094656 (95%) messages=0 reverse=no command=quota-warning 95 raw mail user Apr 19 10:23:26 lda(NewUser at myDomain): Debug: Quota warning: bytes=17179869184 (80%) messages=0 reverse=no command=quota-warning 80 raw mail user Apr 19 10:23:26 lda(NewUser at myDomain): Debug: Quota grace: root=User quota bytes=2147483648 (10%) Apr 19 10:23:26 lda(NewUser at myDomain): Debug: none: root=, index=, indexpvt=, control=, inbox=, altApr 19 10:23:26 lda(NewUser at myDomain): Debug: fts: Indexes disabled for namespace '' Apr 19 10:23:26 lda(NewUser at myDomain): Debug: quota: quota_over_flag check: quota_over_script unset - skipping Apr 19 10:23:26 lda(NewUser at myDomain): Debug: Destination address: NewUser at myDomain (source: -a parameter) Apr 19 10:23:26 lda(NewUser at myDomain): Debug: sieve: Pigeonhole version 0.4.22 (22940fb7) initializing Apr 19 10:23:26 lda(NewUser at myDomain): Debug: sieve: include: sieve_global is not set; it is currently not possible to include `:global' scripts. Apr 19 10:23:26 lda(NewUser at myDomain): Debug: sieve: file storage: Storage path `/var/vmail/NewUser/home/sieve' not found Apr 19 10:23:26 lda(NewUser at myDomain): Debug: sieve: file storage: Using Sieve script path: /var/sieve-scripts/NewUser.sieve Apr 19 10:23:26 lda(NewUser at myDomain): Debug: sieve: file storage: Storage path `/var/sieve-scripts/NewUser.sieve' not found Apr 19 10:23:26 lda(NewUser at myDomain): Debug: sieve: storage: No default script location configured Apr 19 10:23:26 lda(NewUser at myDomain): Debug: sieve: User has no personal script Apr 19 10:23:26 lda(NewUser at myDomain): Debug: sieve: No scripts to execute: reverting to default delivery. Apr 19 10:23:26 lda(NewUser at myDomain): Debug: INBOX: Mailbox opened because: lib-lda delivery Apr 19 10:23:26 lda(NewUser at myDomain): Debug: Mailbox stdin: Opened mail UID=1 because: copying Apr 19 10:23:26 indexer-worker(NewUser at myDomain): Debug: auth USER input: NewUser at myDomain uid=992 gid=989 home=/var/vmail/NewUser/home Apr 19 10:23:26 indexer-worker(NewUser at myDomain): Debug: Effective uid=992, gid=989, home=/var/vmail/NewUser/home Apr 19 10:23:26 indexer-worker(NewUser at myDomain): Debug: Quota root: name=User quota backend=maildir argsApr 19 10:23:26 indexer-worker(NewUser at myDomain): Debug: Quota rule: root=User quota mailbox=* bytes=21474836480 messages=0 Apr 19 10:23:26 indexer-worker(NewUser at myDomain): Debug: Quota rule: root=User quota mailbox=Trash bytes=+209715200 messages=0 Apr 19 10:23:26 indexer-worker(NewUser at myDomain): Debug: Quota warning: bytes=20401094656 (95%) messages=0 reverse=no command=quota-warning 95 NewUser at myDomain Apr 19 10:23:26 indexer-worker(NewUser at myDomain): Debug: Quota warning: bytes=17179869184 (80%) messages=0 reverse=no command=quota-warning 80 NewUser at myDomain Apr 19 10:23:26 indexer-worker(NewUser at myDomain): Debug: Quota grace: root=User quota bytes=2147483648 (10%) Apr 19 10:23:26 indexer-worker(NewUser at myDomain): Debug: Namespace : type=private, prefix=, sep=, inbox=yes, hidden=no, list=yes, subscriptions=yes location=maildir:/var/vmail/NewUser Apr 19 10:23:26 indexer-worker(NewUser at myDomain): Debug: maildir++: root=/var/vmail/NewUser, index=, indexpvt=, control=, inbox=/var/vmail/NewUser, altApr 19 10:23:26 indexer-worker(NewUser at myDomain): Debug: quota: quota_over_flag check: quota_over_script unset - skipping Apr 19 10:23:26 indexer-worker(NewUser at myDomain): Debug: INBOX: Mailbox opened because: indexing Apr 19 10:23:26 indexer-worker(NewUser at myDomain): Debug: Mailbox INBOX: Opened mail UID=6 because: prefetch Apr 19 10:23:26 indexer-worker(NewUser at myDomain): Debug: Mailbox INBOX: Opened mail UID=6 because: access Apr 19 10:23:26 indexer-worker(NewUser at myDomain): Debug: Mailbox INBOX: Opened mail UID=6 because: fts indexing Apr 19 10:23:50 imap(NewUser): Debug: Loading modules from directory: /usr/local/lib/dovecot Apr 19 10:23:50 imap(NewUser): Debug: Module loaded: /usr/local/lib/dovecot/lib10_quota_plugin.so Apr 19 10:23:50 imap(NewUser): Debug: Module loaded: /usr/local/lib/dovecot/lib11_imap_quota_plugin.so Apr 19 10:23:50 imap(NewUser): Debug: Module loaded: /usr/local/lib/dovecot/lib20_fts_plugin.so Apr 19 10:23:50 imap(NewUser): Debug: Module loaded: /usr/local/lib/dovecot/lib20_virtual_plugin.so Apr 19 10:23:50 imap(NewUser): Debug: Module loaded: /usr/local/lib/dovecot/lib21_fts_solr_plugin.so Apr 19 10:23:50 imap(NewUser): Debug: Module loaded: /usr/local/lib/dovecot/lib90_stats_plugin.so Apr 19 10:23:50 imap(NewUser): Debug: Module loaded: /usr/local/lib/dovecot/lib95_imap_stats_plugin.so Apr 19 10:23:50 imap(NewUser): Debug: Effective uid=992, gid=989, home=/var/vmail/NewUser/home Apr 19 10:23:50 imap(NewUser): Debug: Quota root: name=User quota backend=maildir argsApr 19 10:23:50 imap(NewUser): Debug: Quota rule: root=User quota mailbox=* bytes=21474836480 messages=0 Apr 19 10:23:50 imap(NewUser): Debug: Quota rule: root=User quota mailbox=Trash bytes=+209715200 messages=0 Apr 19 10:23:50 imap(NewUser): Debug: Quota warning: bytes=20401094656 (95%) messages=0 reverse=no command=quota-warning 95 NewUser Apr 19 10:23:50 imap(NewUser): Debug: Quota warning: bytes=17179869184 (80%) messages=0 reverse=no command=quota-warning 80 NewUser Apr 19 10:23:50 imap(NewUser): Debug: Quota grace: root=User quota bytes=2147483648 (10%) Apr 19 10:23:50 imap(NewUser): Debug: Namespace : type=private, prefix=, sep=, inbox=yes, hidden=no, list=yes, subscriptions=yes location=maildir:/var/vmail/NewUser Apr 19 10:23:50 imap(NewUser): Debug: maildir++: root=/var/vmail/NewUser, index=, indexpvt=, control=, inbox=/var/vmail/NewUser, altApr 19 10:23:50 imap(NewUser): Debug: quota: quota_over_flag check: quota_over_script unset - skipping Apr 19 10:23:50 imap(NewUser): Debug: INBOX: Mailbox opened because: SELECT Apr 19 10:23:52 imap(NewUser): Debug: Loading modules from directory: /usr/local/lib/dovecot Apr 19 10:23:52 imap(NewUser): Debug: Module loaded: /usr/local/lib/dovecot/lib10_quota_plugin.so Apr 19 10:23:52 imap(NewUser): Debug: Module loaded: /usr/local/lib/dovecot/lib11_imap_quota_plugin.so Apr 19 10:23:52 imap(NewUser): Debug: Module loaded: /usr/local/lib/dovecot/lib20_fts_plugin.so Apr 19 10:23:52 imap(NewUser): Debug: Module loaded: /usr/local/lib/dovecot/lib20_virtual_plugin.so Apr 19 10:23:52 imap(NewUser): Debug: Module loaded: /usr/local/lib/dovecot/lib21_fts_solr_plugin.so Apr 19 10:23:52 imap(NewUser): Debug: Module loaded: /usr/local/lib/dovecot/lib90_stats_plugin.so Apr 19 10:23:52 imap(NewUser): Debug: Module loaded: /usr/local/lib/dovecot/lib95_imap_stats_plugin.so Apr 19 10:23:52 imap(NewUser): Debug: Effective uid=992, gid=989, home=/var/vmail/NewUser/home Apr 19 10:23:52 imap(NewUser): Debug: Quota root: name=User quota backend=maildir argsApr 19 10:23:52 imap(NewUser): Debug: Quota rule: root=User quota mailbox=* bytes=21474836480 messages=0 Apr 19 10:23:52 imap(NewUser): Debug: Quota rule: root=User quota mailbox=Trash bytes=+209715200 messages=0 Apr 19 10:23:52 imap(NewUser): Debug: Quota warning: bytes=20401094656 (95%) messages=0 reverse=no command=quota-warning 95 NewUser Apr 19 10:23:52 imap(NewUser): Debug: Quota warning: bytes=17179869184 (80%) messages=0 reverse=no command=quota-warning 80 NewUser Apr 19 10:23:52 imap(NewUser): Debug: Quota grace: root=User quota bytes=2147483648 (10%) Apr 19 10:23:52 imap(NewUser): Debug: Namespace : type=private, prefix=, sep=, inbox=yes, hidden=no, list=yes, subscriptions=yes location=maildir:/var/vmail/NewUser Apr 19 10:23:52 imap(NewUser): Debug: maildir++: root=/var/vmail/NewUser, index=, indexpvt=, control=, inbox=/var/vmail/NewUser, altApr 19 10:23:52 imap(NewUser): Debug: quota: quota_over_flag check: quota_over_script unset - skipping Apr 19 10:23:52 imap(NewUser): Debug: INBOX: Mailbox opened because: STATUS Apr 19 10:23:52 imap(NewUser): Debug: INBOX: Mailbox opened because: SELECT Apr 19 10:23:53 imap(NewUser): Debug: Loading modules from directory: /usr/local/lib/dovecot Apr 19 10:23:53 imap(NewUser): Debug: Module loaded: /usr/local/lib/dovecot/lib10_quota_plugin.so Apr 19 10:23:53 imap(NewUser): Debug: Module loaded: /usr/local/lib/dovecot/lib11_imap_quota_plugin.so Apr 19 10:23:53 imap(NewUser): Debug: Module loaded: /usr/local/lib/dovecot/lib20_fts_plugin.so Apr 19 10:23:53 imap(NewUser): Debug: Module loaded: /usr/local/lib/dovecot/lib20_virtual_plugin.so Apr 19 10:23:53 imap(NewUser): Debug: Module loaded: /usr/local/lib/dovecot/lib21_fts_solr_plugin.so Apr 19 10:23:53 imap(NewUser): Debug: Module loaded: /usr/local/lib/dovecot/lib90_stats_plugin.so Apr 19 10:23:53 imap(NewUser): Debug: Module loaded: /usr/local/lib/dovecot/lib95_imap_stats_plugin.so Apr 19 10:23:53 imap(NewUser): Debug: Effective uid=992, gid=989, home=/var/vmail/NewUser/home Apr 19 10:23:53 imap(NewUser): Debug: Quota root: name=User quota backend=maildir argsApr 19 10:23:53 imap(NewUser): Debug: Quota rule: root=User quota mailbox=* bytes=21474836480 messages=0 Apr 19 10:23:53 imap(NewUser): Debug: Quota rule: root=User quota mailbox=Trash bytes=+209715200 messages=0 Apr 19 10:23:53 imap(NewUser): Debug: Quota warning: bytes=20401094656 (95%) messages=0 reverse=no command=quota-warning 95 NewUser Apr 19 10:23:53 imap(NewUser): Debug: Quota warning: bytes=17179869184 (80%) messages=0 reverse=no command=quota-warning 80 NewUser Apr 19 10:23:53 imap(NewUser): Debug: Quota grace: root=User quota bytes=2147483648 (10%) Apr 19 10:23:53 imap(NewUser): Debug: Namespace : type=private, prefix=, sep=, inbox=yes, hidden=no, list=yes, subscriptions=yes location=maildir:/var/vmail/NewUser Apr 19 10:23:53 imap(NewUser): Debug: maildir++: root=/var/vmail/NewUser, index=, indexpvt=, control=, inbox=/var/vmail/NewUser, altApr 19 10:23:53 imap(NewUser): Debug: quota: quota_over_flag check: quota_over_script unset - skipping Apr 19 10:23:53 imap(NewUser): Debug: INBOX: Mailbox opened because: SELECT Apr 19 10:23:53 imap(NewUser): Debug: Mailbox INBOX: Opened mail UID=3 because: prefetch Apr 19 10:23:53 imap(NewUser): Debug: Mailbox INBOX: Opened mail UID=3 because: access Apr 19 10:23:53 imap(NewUser): Debug: Mailbox INBOX: Opened mail UID=3 because: MIME part Apr 19 10:23:54 imap(NewUser): Debug: Loading modules from directory: /usr/local/lib/dovecot Apr 19 10:23:54 imap(NewUser): Debug: Module loaded: /usr/local/lib/dovecot/lib10_quota_plugin.so Apr 19 10:23:54 imap(NewUser): Debug: Module loaded: /usr/local/lib/dovecot/lib11_imap_quota_plugin.so Apr 19 10:23:54 imap(NewUser): Debug: Module loaded: /usr/local/lib/dovecot/lib20_fts_plugin.so Apr 19 10:23:54 imap(NewUser): Debug: Module loaded: /usr/local/lib/dovecot/lib20_virtual_plugin.so Apr 19 10:23:54 imap(NewUser): Debug: Module loaded: /usr/local/lib/dovecot/lib21_fts_solr_plugin.so Apr 19 10:23:54 imap(NewUser): Debug: Module loaded: /usr/local/lib/dovecot/lib90_stats_plugin.so Apr 19 10:23:54 imap(NewUser): Debug: Module loaded: /usr/local/lib/dovecot/lib95_imap_stats_plugin.so Apr 19 10:23:54 imap(NewUser): Debug: Effective uid=992, gid=989, home=/var/vmail/NewUser/home Apr 19 10:23:54 imap(NewUser): Debug: Quota root: name=User quota backend=maildir argsApr 19 10:23:54 imap(NewUser): Debug: Quota rule: root=User quota mailbox=* bytes=21474836480 messages=0 Apr 19 10:23:54 imap(NewUser): Debug: Quota rule: root=User quota mailbox=Trash bytes=+209715200 messages=0 Apr 19 10:23:54 imap(NewUser): Debug: Quota warning: bytes=20401094656 (95%) messages=0 reverse=no command=quota-warning 95 NewUser Apr 19 10:23:54 imap(NewUser): Debug: Quota warning: bytes=17179869184 (80%) messages=0 reverse=no command=quota-warning 80 NewUser Apr 19 10:23:54 imap(NewUser): Debug: Quota grace: root=User quota bytes=2147483648 (10%) Apr 19 10:23:54 imap(NewUser): Debug: Namespace : type=private, prefix=, sep=, inbox=yes, hidden=no, list=yes, subscriptions=yes location=maildir:/var/vmail/NewUser Apr 19 10:23:54 imap(NewUser): Debug: maildir++: root=/var/vmail/NewUser, index=, indexpvt=, control=, inbox=/var/vmail/NewUser, altApr 19 10:23:54 imap(NewUser): Debug: quota: quota_over_flag check: quota_over_script unset - skipping Apr 19 10:23:54 imap(NewUser): Debug: INBOX: Mailbox opened because: SELECT Apr 19 10:23:54 imap(NewUser): Debug: Mailbox INBOX: Opened mail UID=4 because: prefetch Apr 19 10:23:54 imap(NewUser): Debug: Mailbox INBOX: Opened mail UID=4 because: access Apr 19 10:23:54 imap(NewUser): Debug: Mailbox INBOX: Opened mail UID=4 because: MIME part Apr 19 10:23:55 imap(NewUser): Debug: Loading modules from directory: /usr/local/lib/dovecot Apr 19 10:23:55 imap(NewUser): Debug: Module loaded: /usr/local/lib/dovecot/lib10_quota_plugin.so Apr 19 10:23:55 imap(NewUser): Debug: Module loaded: /usr/local/lib/dovecot/lib11_imap_quota_plugin.so Apr 19 10:23:55 imap(NewUser): Debug: Module loaded: /usr/local/lib/dovecot/lib20_fts_plugin.so Apr 19 10:23:55 imap(NewUser): Debug: Module loaded: /usr/local/lib/dovecot/lib20_virtual_plugin.so Apr 19 10:23:55 imap(NewUser): Debug: Module loaded: /usr/local/lib/dovecot/lib21_fts_solr_plugin.so Apr 19 10:23:55 imap(NewUser): Debug: Module loaded: /usr/local/lib/dovecot/lib90_stats_plugin.so Apr 19 10:23:55 imap(NewUser): Debug: Module loaded: /usr/local/lib/dovecot/lib95_imap_stats_plugin.so Apr 19 10:23:55 imap(NewUser): Debug: Effective uid=992, gid=989, home=/var/vmail/NewUser/home Apr 19 10:23:55 imap(NewUser): Debug: Quota root: name=User quota backend=maildir argsApr 19 10:23:55 imap(NewUser): Debug: Quota rule: root=User quota mailbox=* bytes=21474836480 messages=0 Apr 19 10:23:55 imap(NewUser): Debug: Quota rule: root=User quota mailbox=Trash bytes=+209715200 messages=0 Apr 19 10:23:55 imap(NewUser): Debug: Quota warning: bytes=20401094656 (95%) messages=0 reverse=no command=quota-warning 95 NewUser Apr 19 10:23:55 imap(NewUser): Debug: Quota warning: bytes=17179869184 (80%) messages=0 reverse=no command=quota-warning 80 NewUser Apr 19 10:23:55 imap(NewUser): Debug: Quota grace: root=User quota bytes=2147483648 (10%) Apr 19 10:23:55 imap(NewUser): Debug: Namespace : type=private, prefix=, sep=, inbox=yes, hidden=no, list=yes, subscriptions=yes location=maildir:/var/vmail/NewUser Apr 19 10:23:55 imap(NewUser): Debug: maildir++: root=/var/vmail/NewUser, index=, indexpvt=, control=, inbox=/var/vmail/NewUser, altApr 19 10:23:55 imap(NewUser): Debug: quota: quota_over_flag check: quota_over_script unset - skipping Apr 19 10:23:55 imap(NewUser): Debug: INBOX: Mailbox opened because: SELECT Apr 19 10:23:55 imap(NewUser): Debug: Mailbox INBOX: Opened mail UID=5 because: prefetch Apr 19 10:23:55 imap(NewUser): Debug: Mailbox INBOX: Opened mail UID=5 because: access Apr 19 10:23:55 imap(NewUser): Debug: Mailbox INBOX: Opened mail UID=5 because: MIME part Apr 19 10:23:55 imap(NewUser): Debug: Loading modules from directory: /usr/local/lib/dovecot Apr 19 10:23:55 imap(NewUser): Debug: Module loaded: /usr/local/lib/dovecot/lib10_quota_plugin.so Apr 19 10:23:55 imap(NewUser): Debug: Module loaded: /usr/local/lib/dovecot/lib11_imap_quota_plugin.so Apr 19 10:23:55 imap(NewUser): Debug: Module loaded: /usr/local/lib/dovecot/lib20_fts_plugin.so Apr 19 10:23:55 imap(NewUser): Debug: Module loaded: /usr/local/lib/dovecot/lib20_virtual_plugin.so Apr 19 10:23:55 imap(NewUser): Debug: Module loaded: /usr/local/lib/dovecot/lib21_fts_solr_plugin.so Apr 19 10:23:55 imap(NewUser): Debug: Module loaded: /usr/local/lib/dovecot/lib90_stats_plugin.so Apr 19 10:23:55 imap(NewUser): Debug: Module loaded: /usr/local/lib/dovecot/lib95_imap_stats_plugin.so Apr 19 10:23:55 imap(NewUser): Debug: Effective uid=992, gid=989, home=/var/vmail/NewUser/home Apr 19 10:23:55 imap(NewUser): Debug: Quota root: name=User quota backend=maildir argsApr 19 10:23:55 imap(NewUser): Debug: Quota rule: root=User quota mailbox=* bytes=21474836480 messages=0 Apr 19 10:23:55 imap(NewUser): Debug: Quota rule: root=User quota mailbox=Trash bytes=+209715200 messages=0 Apr 19 10:23:55 imap(NewUser): Debug: Quota warning: bytes=20401094656 (95%) messages=0 reverse=no command=quota-warning 95 NewUser Apr 19 10:23:55 imap(NewUser): Debug: Quota warning: bytes=17179869184 (80%) messages=0 reverse=no command=quota-warning 80 NewUser Apr 19 10:23:55 imap(NewUser): Debug: Quota grace: root=User quota bytes=2147483648 (10%) Apr 19 10:23:55 imap(NewUser): Debug: Namespace : type=private, prefix=, sep=, inbox=yes, hidden=no, list=yes, subscriptions=yes location=maildir:/var/vmail/NewUser Apr 19 10:23:55 imap(NewUser): Debug: maildir++: root=/var/vmail/NewUser, index=, indexpvt=, control=, inbox=/var/vmail/NewUser, altApr 19 10:23:55 imap(NewUser): Debug: quota: quota_over_flag check: quota_over_script unset - skipping Apr 19 10:23:55 imap(NewUser): Debug: INBOX: Mailbox opened because: SELECT Apr 19 10:23:55 imap(NewUser): Debug: Mailbox INBOX: Opened mail UID=6 because: prefetch Apr 19 10:23:55 imap(NewUser): Debug: Mailbox INBOX: Opened mail UID=6 because: access Apr 19 10:23:55 imap(NewUser): Debug: Mailbox INBOX: Opened mail UID=6 because: MIME part Apr 19 10:23:57 imap(NewUser): Debug: Loading modules from directory: /usr/local/lib/dovecot Apr 19 10:23:57 imap(NewUser): Debug: Module loaded: /usr/local/lib/dovecot/lib10_quota_plugin.so Apr 19 10:23:57 imap(NewUser): Debug: Module loaded: /usr/local/lib/dovecot/lib11_imap_quota_plugin.so Apr 19 10:23:57 imap(NewUser): Debug: Module loaded: /usr/local/lib/dovecot/lib20_fts_plugin.so Apr 19 10:23:57 imap(NewUser): Debug: Module loaded: /usr/local/lib/dovecot/lib20_virtual_plugin.so Apr 19 10:23:57 imap(NewUser): Debug: Module loaded: /usr/local/lib/dovecot/lib21_fts_solr_plugin.so Apr 19 10:23:57 imap(NewUser): Debug: Module loaded: /usr/local/lib/dovecot/lib90_stats_plugin.so Apr 19 10:23:57 imap(NewUser): Debug: Module loaded: /usr/local/lib/dovecot/lib95_imap_stats_plugin.so Apr 19 10:23:57 imap(NewUser): Debug: Effective uid=992, gid=989, home=/var/vmail/NewUser/home Apr 19 10:23:57 imap(NewUser): Debug: Quota root: name=User quota backend=maildir argsApr 19 10:23:57 imap(NewUser): Debug: Quota rule: root=User quota mailbox=* bytes=21474836480 messages=0 Apr 19 10:23:57 imap(NewUser): Debug: Quota rule: root=User quota mailbox=Trash bytes=+209715200 messages=0 Apr 19 10:23:57 imap(NewUser): Debug: Quota warning: bytes=20401094656 (95%) messages=0 reverse=no command=quota-warning 95 NewUser Apr 19 10:23:57 imap(NewUser): Debug: Quota warning: bytes=17179869184 (80%) messages=0 reverse=no command=quota-warning 80 NewUser Apr 19 10:23:57 imap(NewUser): Debug: Quota grace: root=User quota bytes=2147483648 (10%) Apr 19 10:23:57 imap(NewUser): Debug: Namespace : type=private, prefix=, sep=, inbox=yes, hidden=no, list=yes, subscriptions=yes location=maildir:/var/vmail/NewUser Apr 19 10:23:57 imap(NewUser): Debug: maildir++: root=/var/vmail/NewUser, index=, indexpvt=, control=, inbox=/var/vmail/NewUser, altApr 19 10:23:57 imap(NewUser): Debug: quota: quota_over_flag check: quota_over_script unset - skipping Apr 19 10:23:57 imap(NewUser): Debug: INBOX: Mailbox opened because: STATUS Apr 19 10:23:57 imap(NewUser): Debug: INBOX: Mailbox opened because: SELECT Apr 19 10:23:59 imap(NewUser): Debug: Loading modules from directory: /usr/local/lib/dovecot Apr 19 10:23:59 imap(NewUser): Debug: Module loaded: /usr/local/lib/dovecot/lib10_quota_plugin.so Apr 19 10:23:59 imap(NewUser): Debug: Module loaded: /usr/local/lib/dovecot/lib11_imap_quota_plugin.so Apr 19 10:23:59 imap(NewUser): Debug: Module loaded: /usr/local/lib/dovecot/lib20_fts_plugin.so Apr 19 10:23:59 imap(NewUser): Debug: Module loaded: /usr/local/lib/dovecot/lib20_virtual_plugin.so Apr 19 10:23:59 imap(NewUser): Debug: Module loaded: /usr/local/lib/dovecot/lib21_fts_solr_plugin.so Apr 19 10:23:59 imap(NewUser): Debug: Module loaded: /usr/local/lib/dovecot/lib90_stats_plugin.so Apr 19 10:23:59 imap(NewUser): Debug: Module loaded: /usr/local/lib/dovecot/lib95_imap_stats_plugin.so Apr 19 10:23:59 imap(NewUser): Debug: Effective uid=992, gid=989, home=/var/vmail/NewUser/home Apr 19 10:23:59 imap(NewUser): Debug: Quota root: name=User quota backend=maildir argsApr 19 10:23:59 imap(NewUser): Debug: Quota rule: root=User quota mailbox=* bytes=21474836480 messages=0 Apr 19 10:23:59 imap(NewUser): Debug: Quota rule: root=User quota mailbox=Trash bytes=+209715200 messages=0 Apr 19 10:23:59 imap(NewUser): Debug: Quota warning: bytes=20401094656 (95%) messages=0 reverse=no command=quota-warning 95 NewUser Apr 19 10:23:59 imap(NewUser): Debug: Quota warning: bytes=17179869184 (80%) messages=0 reverse=no command=quota-warning 80 NewUser Apr 19 10:23:59 imap(NewUser): Debug: Quota grace: root=User quota bytes=2147483648 (10%) Apr 19 10:23:59 imap(NewUser): Debug: Namespace : type=private, prefix=, sep=, inbox=yes, hidden=no, list=yes, subscriptions=yes location=maildir:/var/vmail/NewUser Apr 19 10:23:59 imap(NewUser): Debug: maildir++: root=/var/vmail/NewUser, index=, indexpvt=, control=, inbox=/var/vmail/NewUser, altApr 19 10:23:59 imap(NewUser): Debug: quota: quota_over_flag check: quota_over_script unset - skipping Apr 19 10:23:59 imap(NewUser): Debug: INBOX: Mailbox opened because: SELECT Apr 19 10:24:07 imap(NewUser): Debug: Loading modules from directory: /usr/local/lib/dovecot Apr 19 10:24:07 imap(NewUser): Debug: Module loaded: /usr/local/lib/dovecot/lib10_quota_plugin.so Apr 19 10:24:07 imap(NewUser): Debug: Module loaded: /usr/local/lib/dovecot/lib11_imap_quota_plugin.so Apr 19 10:24:07 imap(NewUser): Debug: Module loaded: /usr/local/lib/dovecot/lib20_fts_plugin.so Apr 19 10:24:07 imap(NewUser): Debug: Module loaded: /usr/local/lib/dovecot/lib20_virtual_plugin.so Apr 19 10:24:07 imap(NewUser): Debug: Module loaded: /usr/local/lib/dovecot/lib21_fts_solr_plugin.so Apr 19 10:24:07 imap(NewUser): Debug: Module loaded: /usr/local/lib/dovecot/lib90_stats_plugin.so Apr 19 10:24:07 imap(NewUser): Debug: Module loaded: /usr/local/lib/dovecot/lib95_imap_stats_plugin.so Apr 19 10:24:07 imap(NewUser): Debug: Effective uid=992, gid=989, home=/var/vmail/NewUser/home Apr 19 10:24:07 imap(NewUser): Debug: Quota root: name=User quota backend=maildir argsApr 19 10:24:07 imap(NewUser): Debug: Quota rule: root=User quota mailbox=* bytes=21474836480 messages=0 Apr 19 10:24:07 imap(NewUser): Debug: Quota rule: root=User quota mailbox=Trash bytes=+209715200 messages=0 Apr 19 10:24:07 imap(NewUser): Debug: Quota warning: bytes=20401094656 (95%) messages=0 reverse=no command=quota-warning 95 NewUser Apr 19 10:24:07 imap(NewUser): Debug: Quota warning: bytes=17179869184 (80%) messages=0 reverse=no command=quota-warning 80 NewUser Apr 19 10:24:07 imap(NewUser): Debug: Quota grace: root=User quota bytes=2147483648 (10%) Apr 19 10:24:07 imap(NewUser): Debug: Namespace : type=private, prefix=, sep=, inbox=yes, hidden=no, list=yes, subscriptions=yes location=maildir:/var/vmail/NewUser Apr 19 10:24:07 imap(NewUser): Debug: maildir++: root=/var/vmail/NewUser, index=, indexpvt=, control=, inbox=/var/vmail/NewUser, altApr 19 10:24:07 imap(NewUser): Debug: quota: quota_over_flag check: quota_over_script unset - skipping Apr 19 10:24:07 imap(NewUser): Debug: INBOX: Mailbox opened because: STATUS Apr 19 10:24:07 imap(NewUser): Debug: INBOX: Mailbox opened because: SELECT