Hi all!
I am a long-time dovecot user/admin on my home server, but only recently
tried to configure replication. Everything seems to work except sieve
scripts replication. When I upload new one on the server A, it does not
replicate to server B, even if it seemingly tries to, according to debug
logs. The log antry says: Replication requested by
'sieve_storage_sync_transaction_begin', priority=1 on server A, but
nothing like that on server B. Server B logs show that server A is
connecting to doveadm service but little else. Any ideas what could be
wrong?
Please see the logs below. Users and domains have been anonymized.
----- Upload -------------
$ sieve-connect -s serverA.mydomain.example -p sieve -u user at mydomain.example
--notlsverify
Sieve/IMAP Password:
ReadLine support enabled.> put lists
> put autosave
----- Server A log -------
Aug 18 16:05:49 serverA dovecot[60776]: managesieve-login: Login: user=<user
at mydomain.example>, method=PLAIN, rip=<redacted>,
lip=<redacted>, mpid=35651, TLS, session=<Qw4fYiet/uEKKCgK>
Aug 18 16:05:49 serverA dovecot[60776]: managesieve(user at
mydomain.example)<35651><Qw4fYiet/uEKKCgK>: Debug: Loading modules
from directory: /usr/lib/dovecot/modules
Aug 18 16:05:49 serverA dovecot[60776]: managesieve(user at
mydomain.example)<35651><Qw4fYiet/uEKKCgK>: Debug: Module loaded:
/usr/lib/dovecot/modules/lib15_notify_plugin.so
Aug 18 16:05:49 serverA dovecot[60776]: managesieve(user at
mydomain.example)<35651><Qw4fYiet/uEKKCgK>: Debug: Module loaded:
/usr/lib/dovecot/modules/lib20_replication_plugin.so
Aug 18 16:05:49 serverA dovecot[60776]: managesieve(user at
mydomain.example)<35651><Qw4fYiet/uEKKCgK>: Debug: Effective
uid=113, gid=122, home=/var/vmail/user at mydomain.example
Aug 18 16:05:49 serverA dovecot[60776]: managesieve(user at
mydomain.example)<35651><Qw4fYiet/uEKKCgK>: Debug: Namespace inbox:
type=private, prefix=, sep=, inbox=yes, hidden=no, list=yes, subscriptions=yes
location=maildir:~/mail:LAYOUT=fs:DIRNAME=.MailDir:UTF-8
Aug 18 16:05:49 serverA dovecot[60776]: managesieve(user at
mydomain.example)<35651><Qw4fYiet/uEKKCgK>: Debug: fs:
root=/var/vmail/user at mydomain.example/mail, index=, indexpvt=, control=,
inbox=, altAug 18 16:05:49 serverA dovecot[60776]: managesieve(user at
mydomain.example)<35651><Qw4fYiet/uEKKCgK>: Debug: sieve: Pigeonhole
version 0.5.4 () initializing
Aug 18 16:05:49 serverA dovecot[60776]: managesieve(user at
mydomain.example)<35651><Qw4fYiet/uEKKCgK>: Debug: sieve: include:
sieve_global is not set; it is currently not possible to include `:global'
scripts.
Aug 18 16:05:49 serverA dovecot[60776]: managesieve(user at
mydomain.example)<35651><Qw4fYiet/uEKKCgK>: Debug: sieve: file
storage: Using active Sieve script path: /var/vmail/user at
mydomain.example/.sieve
Aug 18 16:05:49 serverA dovecot[60776]: managesieve(user at
mydomain.example)<35651><Qw4fYiet/uEKKCgK>: Debug: sieve: file
storage: Using script storage path: /var/vmail/user at mydomain.example/sieve
Aug 18 16:05:49 serverA dovecot[60776]: managesieve(user at
mydomain.example)<35651><Qw4fYiet/uEKKCgK>: Debug: sieve: file
storage: Using permissions from /var/vmail/user at mydomain.example/sieve:
mode=0700 gid=-1
Aug 18 16:05:49 serverA dovecot[60776]: managesieve(user at
mydomain.example)<35651><Qw4fYiet/uEKKCgK>: Debug: sieve: file
storage: Relative path to sieve storage in active link: sieve/
Aug 18 16:05:49 serverA dovecot[60776]: managesieve(user at
mydomain.example)<35651><Qw4fYiet/uEKKCgK>: Debug: sieve: file
storage: sync: Synchronization active
Aug 18 16:05:54 serverA dovecot[60776]: managesieve(user at
mydomain.example)<35651><Qw4fYiet/uEKKCgK>: Debug: sieve: file
storage: Using Sieve script path: /var/vmail/user at
mydomain.example/sieve/tmp/lists_1597759554.M792097P35651.serverA.mydomain.example.sieve
Aug 18 16:05:54 serverA dovecot[60776]: managesieve(user at
mydomain.example)<35651><Qw4fYiet/uEKKCgK>: Debug: sieve: file
script: Opened script `lists' from `/var/vmail/user at
mydomain.example/sieve/tmp/lists_1597759554.M792097P35651.serverA.mydomain.example.sieve'
Aug 18 16:05:54 serverA dovecot[60776]: managesieve(user at
mydomain.example)<35651><Qw4fYiet/uEKKCgK>: Debug: replication:
Replication requested by 'sieve_storage_sync_transaction_begin',
priority=1
Aug 18 16:05:55 serverA dovecot[60776]: doveadm(user at mydomain.example):
Debug: auth PASS input: user=user at mydomain.example
Aug 18 16:05:55 serverA dovecot[60776]: doveadm(user at
mydomain.example)<35652><>: Debug: auth USER input: user at
mydomain.example uid=113 gid=122 home=/var/vmail/user at mydomain.example
Aug 18 16:05:55 serverA dovecot[60776]: doveadm(user at mydomain.example):
Debug: remote(serverB.mydomain.example): auth PASS input: user=user at
mydomain.example
Aug 18 16:05:55 serverA dovecot[60776]: doveadm(user at mydomain.example):
Debug: remote(serverB.mydomain.example): auth USER input: user at
mydomain.example uid=113 gid=122 home=/var/vmail/user at mydomain.example
Aug 18 16:05:55 serverA dovecot[60776]: doveadm(user at mydomain.example):
Debug: remote(serverB.mydomain.example): Effective uid=113, gid=122,
home=/var/vmail/user at mydomain.example
Aug 18 16:05:55 serverA dovecot[60776]: doveadm(user at mydomain.example):
Debug: remote(serverB.mydomain.example): Namespace inbox: type=private, prefix=,
sep=, inbox=yes, hidden=no, list=yes, subscriptions=yes
location=maildir:~/mail:LAYOUT=fs:DIRNAME=.MailDir:UTF-8
Aug 18 16:05:55 serverA dovecot[60776]: doveadm(user at mydomain.example):
Debug: remote(serverB.mydomain.example): fs: root=/var/vmail/user at
mydomain.example/mail, index=, indexpvt=, control=, inbox=, altAug 18 16:05:55
serverA dovecot[60776]: doveadm(user at mydomain.example): Debug: Effective
uid=113, gid=122, home=/var/vmail/user at mydomain.example
Aug 18 16:05:55 serverA dovecot[60776]: doveadm(user at mydomain.example):
Debug: Namespace inbox: type=private, prefix=, sep=, inbox=yes, hidden=no,
list=yes, subscriptions=yes
location=maildir:~/mail:LAYOUT=fs:DIRNAME=.MailDir:UTF-8
Aug 18 16:05:55 serverA dovecot[60776]: doveadm(user at mydomain.example):
Debug: fs: root=/var/vmail/user at mydomain.example/mail, index=, indexpvt=,
control=, inbox=, altAug 18 16:05:55 serverA dovecot[60776]: doveadm(user at
mydomain.example): Debug: Namespace : Using permissions from /var/vmail/user at
mydomain.example/mail: mode=0700 gid=default
Aug 18 16:05:58 serverA dovecot[60776]: managesieve(user at
mydomain.example)<35651><Qw4fYiet/uEKKCgK>: Debug: sieve: file
storage: Using Sieve script path: /var/vmail/user at
mydomain.example/sieve/tmp/autosave_1597759558.M923011P35651.serverA.mydomain.example.sieve
Aug 18 16:05:58 serverA dovecot[60776]: managesieve(user at
mydomain.example)<35651><Qw4fYiet/uEKKCgK>: Debug: sieve: file
script: Opened script `autosave' from `/var/vmail/user at
mydomain.example/sieve/tmp/autosave_1597759558.M923011P35651.serverA.mydomain.example.sieve'
Aug 18 16:05:58 serverA dovecot[60776]: managesieve(user at
mydomain.example)<35651><Qw4fYiet/uEKKCgK>: Debug: replication:
Replication requested by 'sieve_storage_sync_transaction_begin',
priority=1
Aug 18 16:05:59 serverA dovecot[60776]: doveadm(user at mydomain.example):
Debug: auth PASS input: user=user at mydomain.example
Aug 18 16:05:59 serverA dovecot[60776]: doveadm(user at
mydomain.example)<35653><>: Debug: auth USER input: user at
mydomain.example uid=113 gid=122 home=/var/vmail/user at mydomain.example
Aug 18 16:05:59 serverA dovecot[60776]: doveadm(user at mydomain.example):
Debug: remote(serverB.mydomain.example): auth PASS input: user=user at
mydomain.example
Aug 18 16:05:59 serverA dovecot[60776]: doveadm(user at mydomain.example):
Debug: remote(serverB.mydomain.example): auth USER input: user at
mydomain.example uid=113 gid=122 home=/var/vmail/user at mydomain.example
Aug 18 16:05:59 serverA dovecot[60776]: doveadm(user at mydomain.example):
Debug: remote(serverB.mydomain.example): Effective uid=113, gid=122,
home=/var/vmail/user at mydomain.example
Aug 18 16:05:59 serverA dovecot[60776]: doveadm(user at mydomain.example):
Debug: remote(serverB.mydomain.example): Namespace inbox: type=private, prefix=,
sep=, inbox=yes, hidden=no, list=yes, subscriptions=yes
location=maildir:~/mail:LAYOUT=fs:DIRNAME=.MailDir:UTF-8
Aug 18 16:05:59 serverA dovecot[60776]: doveadm(user at mydomain.example):
Debug: remote(serverB.mydomain.example): fs: root=/var/vmail/user at
mydomain.example/mail, index=, indexpvt=, control=, inbox=, altAug 18 16:05:59
serverA dovecot[60776]: doveadm(user at mydomain.example): Debug: Effective
uid=113, gid=122, home=/var/vmail/user at mydomain.example
Aug 18 16:05:59 serverA dovecot[60776]: doveadm(user at mydomain.example):
Debug: Namespace inbox: type=private, prefix=, sep=, inbox=yes, hidden=no,
list=yes, subscriptions=yes
location=maildir:~/mail:LAYOUT=fs:DIRNAME=.MailDir:UTF-8
Aug 18 16:05:59 serverA dovecot[60776]: doveadm(user at mydomain.example):
Debug: fs: root=/var/vmail/user at mydomain.example/mail, index=, indexpvt=,
control=, inbox=, altAug 18 16:05:59 serverA dovecot[60776]: doveadm(user at
mydomain.example): Debug: Namespace : Using permissions from /var/vmail/user at
mydomain.example/mail: mode=0700 gid=default
Aug 18 16:06:00 serverA dovecot[60776]: managesieve(user at
mydomain.example)<35651><Qw4fYiet/uEKKCgK>: Disconnected: Logged out
bytes=3748/95
----- Server B log -------
Aug 18 16:05:55 serverB dovecot[30215]: doveadm: Debug: auth PASS input:
user=user at mydomain.example
Aug 18 16:05:55 serverB dovecot[30215]: doveadm: Debug: auth USER input: user at
mydomain.example uid=113 gid=122 home=/var/vmail/user at mydomain.example
Aug 18 16:05:55 serverB dovecot[30215]: doveadm: Debug: Effective uid=113,
gid=122, home=/var/vmail/user at mydomain.example
Aug 18 16:05:55 serverB dovecot[30215]: doveadm: Debug: Namespace inbox:
type=private, prefix=, sep=, inbox=yes, hidden=no, list=yes, subscriptions=yes
location=maildir:~/mail:LAYOUT=fs:DIRNAME=.MailDir:UTF-8
Aug 18 16:05:55 serverB dovecot[30215]: doveadm: Debug: fs: root=/var/vmail/user
at mydomain.example/mail, index=, indexpvt=, control=, inbox=, altAug 18
16:05:55 serverB dovecot[30215]: doveadm: Debug: Namespace : Using permissions
from /var/vmail/user at mydomain.example/mail: mode=0700 gid=default
Aug 18 16:05:59 serverB dovecot[30215]: doveadm: Debug: auth PASS input:
user=user at mydomain.example
Aug 18 16:05:59 serverB dovecot[30215]: doveadm: Debug: auth USER input: user at
mydomain.example uid=113 gid=122 home=/var/vmail/user at mydomain.example
Aug 18 16:05:59 serverB dovecot[30215]: doveadm: Debug: Effective uid=113,
gid=122, home=/var/vmail/user at mydomain.example
Aug 18 16:05:59 serverB dovecot[30215]: doveadm: Debug: Namespace inbox:
type=private, prefix=, sep=, inbox=yes, hidden=no, list=yes, subscriptions=yes
location=maildir:~/mail:LAYOUT=fs:DIRNAME=.MailDir:UTF-8
Aug 18 16:05:59 serverB dovecot[30215]: doveadm: Debug: fs: root=/var/vmail/user
at mydomain.example/mail, index=, indexpvt=, control=, inbox=, altAug 18
16:05:59 serverB dovecot[30215]: doveadm: Debug: Namespace : Using permissions
from /var/vmail/user at mydomain.example/mail: mode=0700 gid=default
----- doveconf -n -------
# 2.3.4.1 (f79e8e7e4): /etc/dovecot/dovecot.conf
# Pigeonhole version 0.5.4 ()
# OS: Linux 4.19.0-8-amd64 x86_64 Debian 10.4
# Hostname: serverA.mydomain.example
auth_failure_delay = 3 secs
auth_verbose = yes
auth_worker_max_count = 5
deliver_log_format = msgid=%m; from=%f: %$
disable_plaintext_auth = no
doveadm_password = # hidden, use -P to show it
doveadm_port = 4551
first_valid_uid = 100
login_greeting = <redacted>
mail_attribute_dict = file:mail/dovecot-attributes
mail_debug = yes
mail_location = maildir:~/mail:LAYOUT=fs:DIRNAME=.MailDir:UTF-8
mail_plugins = " notify replication"
mail_privileged_group = 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 editheader vnd.dovecot.debug
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 {
args = /etc/dovecot/dovecot-sql.conf.ext.local
driver = sql
}
plugin {
mail_replica = tcp:serverB.mydomain.example
sieve = ~/.sieve
sieve_dir = ~/sieve
sieve_extensions = +vnd.dovecot.debug +editheader
sieve_user_log = ~/log/sieve.log
}
pop3_fast_size_lookups = yes
pop3_lock_session = yes
pop3_no_flag_updates = yes
pop3_save_uidl = yes
protocols = " imap lmtp sieve pop3"
replication_max_conns = 5
service aggregator {
fifo_listener replication-notify-fifo {
group = root
mode = 0660
user = vmail
}
unix_listener replication-notify {
group = root
mode = 0660
user = vmail
}
}
service auth-worker {
chroot = /etc/dovecot/db
process_limit = 10
unix_listener auth-worker {
mode = 0600
user = doveauth
}
user = doveauth
}
service auth {
client_limit = 64
inet_listener sasl {
address = serverA.mydomain.example
port = 9192
}
unix_listener auth-userdb {
group = vmail
mode = 0660
user = doveauth
}
user = doveauth
}
service dict-async {
protocol = none
}
service dict {
protocol = none
}
service director {
protocol = none
}
service doveadm {
inet_listener doveadm {
address = serverA.mydomain.example
port = 4551
}
}
service imap-hibernate {
protocol = none
}
service imap-login {
inet_listener imap {
address = serverA.mydomain.example
port = 143
}
process_limit = 25
service_count = 1
}
service imap-urlauth-login {
protocol = none
}
service imap-urlauth-worker {
protocol = none
}
service imap-urlauth {
protocol = none
}
service imap {
chroot = /var/vmail
client_limit = 15
process_limit = 25
service_count = 32
user = vmail
}
service indexer-worker {
process_limit = 3
user = vmail
}
service indexer {
chroot = $base_dir
}
service lmtp {
client_limit = 1
extra_groups group = vmail
inet_listener lmtp {
address = serverA.mydomain.example
port = 2306
}
process_limit = 5
user = vmail
}
service log {
user = $default_internal_user
}
service managesieve-login {
inet_listener sieve {
address = serverA.mydomain.example
port = 4190
}
process_limit = 3
service_count = 1
}
service managesieve {
chroot = /var/vmail
process_limit = 3
service_count = 1
user = vmail
}
service pop3-login {
inet_listener pop3 {
port = 0
}
process_limit = 3
service_count = 1
}
service pop3 {
chroot = /var/vmail
process_limit = 3
service_count = 1
user = vmail
}
service replicator {
unix_listener replicator-doveadm {
group = root
mode = 0600
user = vmail
}
}
service submission-login {
protocol = none
}
service tcpwrap {
protocol = none
}
ssl_cert = </etc/dovecot/private/dovecot.pem
ssl_client_ca_dir = /etc/ssl/certs
ssl_dh = # hidden, use -P to show it
ssl_key = # hidden, use -P to show it
userdb {
args = /etc/dovecot/dovecot-sql.conf.ext.local
driver = sql
}
valid_chroot_dirs = /var/vmail /etc/dovecot/db
verbose_proctitle = yes
protocol lmtp {
mail_plugins = " notify replication sieve"
}
protocol imap {
imap_metadata = yes
}
--
Piotr "Malgond" Auksztulewicz firstname at
lastname.net