dsync: expunge from pop3 does not replicate

Jakub Lánský jakub at lansky.biz
Thu Jul 26 12:03:53 EEST 2018


Yes, it should incoming mail to inbox, where replication was requested
(and mail was replicated succesfully, of course). After expunge via
POP3, replication was not called at all. (It doesn't happens on IMAP
connections, if I didn't mentioned in previous message)

Log:

Jul 26 10:54:11 mda11 dovecot: lmtp(jakub@***)<339><mMJrGzOMWVtTAQAALagawQ>: Debug: INBOX: Mailbox opened because: lib-lda delivery
Jul 26 10:54:11 mda11 dovecot: lmtp(jakub@***)<339><mMJrGzOMWVtTAQAALagawQ>: Debug: Mailbox <lmtp DATA local>: Opened mail UID=1 because: copying
Jul 26 10:54:11 mda11 dovecot: lmtp(jakub@***)<339><mMJrGzOMWVtTAQAALagawQ>: Debug: replication: Replication requested by 'mail_deliver_save', priority=2
Jul 26 10:54:11 mda11 dovecot: lmtp(jakub@***)<339><mMJrGzOMWVtTAQAALagawQ>: <20180726105407.7b9cbf8d at muffycake> lenny@***/lenny@*** pop3 test mail #2 -> lenny@*** 2651: saved mail to INBOX
Jul 26 10:54:11 mda11 dovecot: doveadm(jakub@***)<2172><>: Debug: auth USER input: jakub@*** uid=65534 quota_rule=*:bytes=3221225472 quota_rule2=*:messages=0
Jul 26 10:54:11 mda11 dovecot: doveadm(jakub@***)<2172><>: Debug: Added userdb setting: plugin/quota_rule=*:bytes=3221225472
Jul 26 10:54:11 mda11 dovecot: doveadm(jakub@***)<2172><>: Debug: Added userdb setting: plugin/quota_rule2=*:messages=0
Jul 26 10:54:11 mda11 dovecot: doveadm(jakub@***): Debug: remote(10.3.13.52:54321): auth USER input: jakub@*** uid=65534 quota_rule=*:bytes=3221225472 quota_rule2=*:messages=0
Jul 26 10:54:11 mda11 dovecot: doveadm(jakub@***): Debug: remote(10.3.13.52:54321): Added userdb setting: plugin/quota_rule=*:bytes=3221225472
Jul 26 10:54:11 mda11 dovecot: doveadm(jakub@***): Debug: remote(10.3.13.52:54321): Added userdb setting: plugin/quota_rule2=*:messages=0
Jul 26 10:54:11 mda11 dovecot: doveadm(jakub@***): Debug: remote(10.3.13.52:54321): Effective uid=65534, gid=65534, home=/datastore/maildir/***/jakub
Jul 26 10:54:11 mda11 dovecot: doveadm(jakub@***): Debug: remote(10.3.13.52:54321): Quota root: name=User quota backend=dict args=:proxy::sqlquota
Jul 26 10:54:11 mda11 dovecot: doveadm(jakub@***): Debug: remote(10.3.13.52:54321): Quota rule: root=User quota mailbox=* bytes=3221225472 messages=0
Jul 26 10:54:11 mda11 dovecot: doveadm(jakub@***): Debug: remote(10.3.13.52:54321): Quota rule: root=User quota mailbox=* bytes=3221225472 messages=0
Jul 26 10:54:11 mda11 dovecot: doveadm(jakub@***): Debug: remote(10.3.13.52:54321): Quota warning: bytes=3060164198 (95%) messages=0 reverse=no command=quota-warning 95 jakub@*** *** size
Jul 26 10:54:11 mda11 dovecot: doveadm(jakub@***): Debug: remote(10.3.13.52:54321): Quota warning: bytes=0 messages=0 (95%) reverse=no command=quota-warning 95 jakub@*** *** count
Jul 26 10:54:11 mda11 dovecot: doveadm(jakub@***): Debug: remote(10.3.13.52:54321): Quota grace: root=User quota bytes=1610612736 (50%)
Jul 26 10:54:11 mda11 dovecot: doveadm(jakub@***): Debug: remote(10.3.13.52:54321): dict quota: user=jakub@***, uri=proxy::sqlquota, noenforcing=0
Jul 26 10:54:11 mda11 dovecot: doveadm(jakub@***): Debug: remote(10.3.13.52:54321): Namespace inbox: type=private, prefix=, sep=, inbox=yes, hidden=no, list=yes, subscriptions=yes location=maildir:~/
Jul 26 10:54:11 mda11 dovecot: doveadm(jakub@***): Debug: remote(10.3.13.52:54321): maildir++: root=/datastore/maildir/***/jakub, index=, indexpvt=, control=, inbox=/datastore/maildir/***/jakub, alt=
Jul 26 10:54:11 mda11 dovecot: doveadm(jakub@***): Debug: remote(10.3.13.52:54321): quota: quota_over_flag check: quota_over_script unset - skipping
Jul 26 10:54:11 mda11 dovecot: doveadm(jakub@***): Debug: Effective uid=65534, gid=65534, home=/datastore/maildir/***/jakub
Jul 26 10:54:11 mda11 dovecot: doveadm(jakub@***): Debug: Quota root: name=User quota backend=dict args=:proxy::sqlquota
Jul 26 10:54:11 mda11 dovecot: doveadm(jakub@***): Debug: Quota rule: root=User quota mailbox=* bytes=3221225472 messages=0
Jul 26 10:54:11 mda11 dovecot: doveadm(jakub@***): Debug: Quota rule: root=User quota mailbox=* bytes=3221225472 messages=0
Jul 26 10:54:11 mda11 dovecot: doveadm(jakub@***): Debug: Quota warning: bytes=3060164198 (95%) messages=0 reverse=no command=quota-warning 95 jakub@*** *** size
Jul 26 10:54:11 mda11 dovecot: doveadm(jakub@***): Debug: Quota warning: bytes=0 messages=0 (95%) reverse=no command=quota-warning 95 jakub@*** *** count
Jul 26 10:54:11 mda11 dovecot: doveadm(jakub@***): Debug: Quota grace: root=User quota bytes=1610612736 (50%)
Jul 26 10:54:11 mda11 dovecot: doveadm(jakub@***): Debug: dict quota: user=jakub@***, uri=proxy::sqlquota, noenforcing=0
Jul 26 10:54:11 mda11 dovecot: doveadm(jakub@***): Debug: Namespace inbox: type=private, prefix=, sep=, inbox=yes, hidden=no, list=yes, subscriptions=yes location=maildir:~/
Jul 26 10:54:11 mda11 dovecot: doveadm(jakub@***): Debug: maildir++: root=/datastore/maildir/***/jakub, index=, indexpvt=, control=, inbox=/datastore/maildir/***/jakub, alt=
Jul 26 10:54:11 mda11 dovecot: doveadm(jakub@***): Debug: quota: quota_over_flag check: quota_over_script unset - skipping
Jul 26 10:54:11 mda11 dovecot: doveadm(jakub@***): Debug: Namespace : Using permissions from /datastore/maildir/***/jakub: mode=0700 gid=default
Jul 26 10:54:11 mda11 dovecot: dsync-local(jakub@***)<uoLWIzOMWVt8CAAALagawQ>: Debug: Mailbox INBOX: Opened mail UID=18 because: prefetch
Jul 26 10:54:11 mda11 dovecot: dsync-local(jakub@***)<uoLWIzOMWVt8CAAALagawQ>: Debug: Mailbox INBOX: Opened mail UID=18 because: access
Jul 26 10:54:11 mda11 dovecot: dsync-local(jakub@***)<uoLWIzOMWVt8CAAALagawQ>: Debug: Mailbox INBOX: Opened mail UID=18 because: mail stream
Jul 26 10:55:28 mda11 dovecot: pop3-login: Login: user=<jakub@***>, method=PLAIN, rip=XXX, lip=XXX, mpid=3245, TLS
Jul 26 10:55:28 mda11 dovecot: pop3(jakub@***)<3245><ZLsWJ+Nx4J8qAB7QADwAAAAAAAAAAL7v>: Debug: Loading modules from directory: /usr/lib/dovecot/modules
Jul 26 10:55:28 mda11 dovecot: pop3(jakub@***)<3245><ZLsWJ+Nx4J8qAB7QADwAAAAAAAAAAL7v>: Debug: Module loaded: /usr/lib/dovecot/modules/lib10_quota_plugin.so
Jul 26 10:55:28 mda11 dovecot: pop3(jakub@***)<3245><ZLsWJ+Nx4J8qAB7QADwAAAAAAAAAAL7v>: Debug: Module loaded: /usr/lib/dovecot/modules/lib15_notify_plugin.so
Jul 26 10:55:28 mda11 dovecot: pop3(jakub@***)<3245><ZLsWJ+Nx4J8qAB7QADwAAAAAAAAAAL7v>: Debug: Module loaded: /usr/lib/dovecot/modules/lib20_mail_log_plugin.so
Jul 26 10:55:28 mda11 dovecot: pop3(jakub@***)<3245><ZLsWJ+Nx4J8qAB7QADwAAAAAAAAAAL7v>: Debug: Module loaded: /usr/lib/dovecot/modules/lib20_replication_plugin.so
Jul 26 10:55:28 mda11 dovecot: pop3(jakub@***)<3245><ZLsWJ+Nx4J8qAB7QADwAAAAAAAAAAL7v>: Debug: Module loaded: /usr/lib/dovecot/modules/lib90_old_stats_plugin.so
Jul 26 10:55:28 mda11 dovecot: pop3(jakub@***)<3245><ZLsWJ+Nx4J8qAB7QADwAAAAAAAAAAL7v>: Debug: Added userdb setting: plugin/quota_rule=*:bytes=3221225472
Jul 26 10:55:28 mda11 dovecot: pop3(jakub@***)<3245><ZLsWJ+Nx4J8qAB7QADwAAAAAAAAAAL7v>: Debug: Added userdb setting: plugin/quota_rule2=*:messages=0
Jul 26 10:55:28 mda11 dovecot: pop3(jakub@***)<3245><ZLsWJ+Nx4J8qAB7QADwAAAAAAAAAAL7v>: Debug: Effective uid=65534, gid=65534, home=/datastore/maildir/***/jakub
Jul 26 10:55:28 mda11 dovecot: pop3(jakub@***)<3245><ZLsWJ+Nx4J8qAB7QADwAAAAAAAAAAL7v>: Debug: Quota root: name=User quota backend=dict args=:proxy::sqlquota
Jul 26 10:55:28 mda11 dovecot: pop3(jakub@***)<3245><ZLsWJ+Nx4J8qAB7QADwAAAAAAAAAAL7v>: Debug: Quota rule: root=User quota mailbox=* bytes=3221225472 messages=0
Jul 26 10:55:28 mda11 dovecot: pop3(jakub@***)<3245><ZLsWJ+Nx4J8qAB7QADwAAAAAAAAAAL7v>: Debug: Quota rule: root=User quota mailbox=* bytes=3221225472 messages=0
Jul 26 10:55:28 mda11 dovecot: pop3(jakub@***)<3245><ZLsWJ+Nx4J8qAB7QADwAAAAAAAAAAL7v>: Debug: Quota warning: bytes=3060164198 (95%) messages=0 reverse=no command=quota-warning 95 jakub@*** *** size
Jul 26 10:55:28 mda11 dovecot: pop3(jakub@***)<3245><ZLsWJ+Nx4J8qAB7QADwAAAAAAAAAAL7v>: Debug: Quota warning: bytes=0 messages=0 (95%) reverse=no command=quota-warning 95 jakub@*** *** count
Jul 26 10:55:28 mda11 dovecot: pop3(jakub@***)<3245><ZLsWJ+Nx4J8qAB7QADwAAAAAAAAAAL7v>: Debug: Quota grace: root=User quota bytes=1610612736 (50%)
Jul 26 10:55:28 mda11 dovecot: pop3(jakub@***)<3245><ZLsWJ+Nx4J8qAB7QADwAAAAAAAAAAL7v>: Debug: dict quota: user=jakub@***, uri=proxy::sqlquota, noenforcing=0
Jul 26 10:55:28 mda11 dovecot: pop3(jakub@***)<3245><ZLsWJ+Nx4J8qAB7QADwAAAAAAAAAAL7v>: Debug: Namespace inbox: type=private, prefix=, sep=, inbox=yes, hidden=no, list=yes, subscriptions=yes location=maildir:
~/
Jul 26 10:55:28 mda11 dovecot: pop3(jakub@***)<3245><ZLsWJ+Nx4J8qAB7QADwAAAAAAAAAAL7v>: Debug: maildir++: root=/datastore/maildir/***/jakub, index=, indexpvt=, control=, inbox=/datastore/maildir/***/jak
ub, alt=
Jul 26 10:55:28 mda11 dovecot: pop3(jakub@***)<3245><ZLsWJ+Nx4J8qAB7QADwAAAAAAAAAAL7v>: Debug: quota: quota_over_flag check: quota_over_script unset - skipping
Jul 26 10:55:28 mda11 dovecot: pop3(jakub@***)<3245><ZLsWJ+Nx4J8qAB7QADwAAAAAAAAAAL7v>: Debug: INBOX: Mailbox opened because: POP3 INBOX
Jul 26 10:55:33 mda11 dovecot: pop3(jakub@***)<3245><ZLsWJ+Nx4J8qAB7QADwAAAAAAAAAAL7v>: expunge: box=INBOX, msgid=<20180726105407.7b9cbf8d at muffycake>, size=2651, from=Lenny <lenny@***>, subject=pop3 te
st mail #2
Jul 26 10:55:33 mda11 dovecot: pop3(jakub@***)<3245><ZLsWJ+Nx4J8qAB7QADwAAAAAAAAAAL7v>: Disconnected: Logged out top=0/0, retr=0/0, del=1/1, size=2718
-- 
Jakub Lánský

IT administration/support technician
jakub at lansky.biz
GSM: +420776172737
Jabber/GTalk: lenny at blesmrt.net

-------- Původní zpráva --------
Od: Aki Tuomi <aki.tuomi at dovecot.fi>
Komu: Jakub Lánský <jakub at lansky.biz>, dovecot at dovecot.org
Předmět: Re: dsync: expunge from pop3 does not replicate
Datum: Thu, 26 Jul 2018 08:46:57 +0300

Can you try enabling mail_debug=yes, perform a pop3 session and provide
logs?

Aki


On 25.07.2018 15:53, Jakub Lánský wrote:
> Here is it
> 
> # 2.3.2.1 (0719df592): /etc/dovecot/dovecot.conf
> # Pigeonhole version 0.5.2 (5d6d7c92)
> # OS: Linux 4.4.0-112-generic x86_64 Ubuntu 16.04.4 LTS 
> # Hostname: mda22
> auth_cache_negative_ttl = 2 secs
> auth_cache_size = 16 M
> auth_cache_ttl = 1 mins
> auth_master_user_separator = /
> auth_mechanisms = plain login
> auth_verbose = yes
> default_client_limit = 2000
> default_process_limit = 2000
> default_vsz_limit = 16894 M
> deliver_log_format = %m %f/%e %s -> %e %p: %$
> dict {
>   sqlquota = mysql:/etc/dovecot/dovecot-dict-sql.conf.ext
>   sqlsieve = mysql:/etc/dovecot/dovecot-dict-sqlsieve.conf.ext
> }
> disable_plaintext_auth = no
> doveadm_password =  # hidden, use -P to show it
> imap_client_workarounds = delay-newmail tb-extra-mailbox-sep tb-lsub-
> flags
> lda_mailbox_autocreate = yes
> lda_mailbox_autosubscribe = yes
> lmtp_rcpt_check_quota = yes
> login_log_format_elements = user=<%u> method=%m rip=%r lip=%l mpid=%e
> %c
> login_trusted_networks = 10.3.13.0/24 10.3.14.0/24
> mail_gid = nogroup
> mail_home = /datastore/maildir/%d/%n
> mail_location = maildir:~/
> mail_plugins = " quota mail_log notify old_stats replication"
> mail_uid = nobody
> maildir_copy_with_hardlinks = no
> 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 {
>   inbox = yes
>   location = 
>   mailbox Archive {
>     auto = subscribe
>     special_use = \Archive
>   }
>   mailbox Drafts {
>     auto = subscribe
>     special_use = \Drafts
>   }
>   mailbox Inbox {
>     auto = subscribe
>   }
>   mailbox Junk {
>     auto = subscribe
>     special_use = \Junk
>   }
>   mailbox Sent {
>     auto = subscribe
>     special_use = \Sent
>   }
>   mailbox Trash {
>     auto = subscribe
>     special_use = \Trash
>   }
>   prefix = 
>   subscriptions = yes
>   type = private
> }
> passdb {
>   args = /etc/dovecot/master-users
>   driver = passwd-file
>   master = yes
>   pass = yes
> }
> passdb {
>   args = /etc/dovecot/dovecot-sql.conf.ext
>   driver = sql
> }
> plugin {
>   mail_log_events = delete undelete expunge copy mailbox_delete
> mailbox_rename
>   mail_log_fields = box msgid from subject size
>   mail_replica = tcp:10.3.13.51:54321
>   old_stats_command_min_time = 1 mins
>   old_stats_domain_min_time = 12 hours
>   old_stats_ip_min_time = 12 hours
>   old_stats_memory_limit = 16 M
>   old_stats_refresh = 30 secs
>   old_stats_session_min_time = 15 mins
>   old_stats_track_cmds = yes
>   old_stats_user_min_time = 1 hours
>   quota = dict:User quota::proxy::sqlquota
>   quota_exceeded_message = Storage quota for this account has been
> exceeded, please try again later.
>   quota_grace = 50%%
>   quota_warning = storage=95%% quota-warning 95 %u %d size
>   quota_warning2 = messages=95%% quota-warning 95 %u %d count
>   recipient_delimiter = +
>   sieve =
> file:/datastore/sieve/%d/%n/;active=/datastore/sieve/%d/%n/active.sie
> ve
>   sieve_before =
> dict:proxy::sqlsieve;name=before_inbox_forward;bindir=/datastore/siev
> e/%d/%n/
>   sieve_max_actions = 32
>   sieve_max_redirects = 50
>   sieve_max_script_size = 1M
>   sieve_redirect_envelope_from = recipient
>   sieve_user_log = /datastore/sieve/%d/%n/.sieve.log
> }
> pop3_client_workarounds = outlook-no-nuls oe-ns-eoh
> pop3_reuse_xuidl = yes
> pop3_save_uidl = yes
> protocols = " imap lmtp sieve pop3 sieve"
> replication_max_conns = 100
> service aggregator {
>   fifo_listener replication-notify-fifo {
>     mode = 0666
>     user = nobody
>   }
>   unix_listener replication-notify {
>     mode = 0666
>     user = nobody
>   }
> }
> service auth {
>   inet_listener {
>     port = 12345
>     ssl = yes
>   }
> }
> service dict {
>   unix_listener dict {
>     group = nogroup
>     user = nobody
>   }
> }
> service doveadm {
>   inet_listener {
>     port = 54321
>     ssl = no
>   }
> }
> service imap-login {
>   process_limit = 32
>   process_min_avail = 8
>   service_count = 0
> }
> service imap {
>   process_limit = 16384
> }
> service lmtp {
>   executable = lmtp -L
>   inet_listener lmtp {
>     port = 24
>     ssl = no
>   }
>   process_min_avail = 5
> }
> service managesieve-login {
>   inet_listener sieve {
>     port = 4190
>   }
>   process_min_avail = 2
>   service_count = 1
>   vsz_limit = 196 M
> }
> service managesieve {
>   process_limit = 2048
> }
> service old-stats {
>   fifo_listener old-stats-mail {
>     mode = 0666
>     user = nobody
>   }
>   inet_listener {
>     address = 127.0.0.1
>     port = 24242
>   }
> }
> service pop3 {
>   process_limit = 2048
> }
> service quota-warning {
>   executable = script /etc/dovecot/quota-warning.sh
>   unix_listener quota-warning {
>     mode = 0666
>     user = nobody
>   }
>   user = nobody
> }
> service replicator {
>   process_min_avail = 1
>   unix_listener replicator-doveadm {
>     mode = 0666
>     user = nobody
>   }
> }
> service stats {
>   idle_kill = 5 mins
>   unix_listener stats-reader {
>     group = nogroup
>     mode = 0666
>     user = nobody
>   }
>   unix_listener stats-writer {
>     group = nogroup
>     mode = 0666
>     user = nobody
>   }
> }
> ssl_cert = </etc/dovecot/private/mda.vshosting.cloud/fullchain.pem
> ssl_dh =  # hidden, use -P to show it
> ssl_key =  # hidden, use -P to show it
> ssl_prefer_server_ciphers = yes
> submission_host = 10.3.14.30:587
> userdb {
>   args = /etc/dovecot/dovecot-sql.conf.ext
>   driver = sql
> }
> protocol lmtp {
>   mail_plugins = " quota mail_log notify old_stats replication sieve"
> }
> protocol lda {
>   mail_plugins = " quota mail_log notify old_stats replication sieve"
> }
> protocol imap {
>   mail_max_userip_connections = 50
>   mail_plugins = " quota mail_log notify old_stats replication
> imap_quota imap_old_stats"
> }
> protocol sieve {
>   managesieve_max_line_length = 65536
> }
> protocol pop3 {
>   mail_max_userip_connections = 50
> }
> 
> 
> 





More information about the dovecot mailing list