Local lmtp proxy on backend server

Marc Roos M.Roos at f1-outsourcing.eu
Mon Dec 16 20:51:19 EET 2019 

 
I have tested also with lmtp.pl script to send a message directly to the 
lmtp port, to exclude a sendmail issue and also this email keeps being 
locally delivered. I tried with changing the userdb with default fields, 
also does not work. This forwarding between backend servers should work 
not?

Dec 16 21:02:56 svr1 dovecot: lmtp(test): Debug: Added userdb setting: 
plugin/host=svr2
Dec 16 21:02:56 svr1 dovecot: lmtp(test): Debug: Added userdb setting: 
plugin/proxy=y


-----Original Message-----
To: aki.tuomi; dovecot
Subject: RE: Local lmtp proxy on backend server

 

I am staring constantly at the same logs, this is what I get from 
dovecot[1]. Sendmail[2] is sending with test at svr1 maybe this overrides 
lmtp proxying? This is a test with a special-userdb passwd-file also 
having host=svr2

[1]
Dec 16 16:30:16 svr1 dovecot: lmtp(16466): Debug: none: root=, index=, 
indexpvt=, control=, inbox=, alt= Dec 16 16:30:16 svr1 dovecot: 
lmtp(16466): Connect from local Dec 16 16:30:16 svr1 dovecot: auth: 
Debug: master in: 
PASS#0111#011test#011service=lmtp
Dec 16 16:30:16 svr1 dovecot: auth: Debug: passwd(test): cache miss Dec 
16 16:30:16 svr1 dovecot: auth-worker(16468): Debug: Loading modules 
from directory: /usr/lib64/dovecot/auth Dec 16 16:30:16 svr1 dovecot: 
auth-worker(16468): Debug: Module loaded: 
/usr/lib64/dovecot/auth/lib20_auth_var_expand_crypt.so
Dec 16 16:30:16 svr1 dovecot: auth-worker(16468): Debug: Module loaded: 
/usr/lib64/dovecot/auth/libdriver_sqlite.so
Dec 16 16:30:16 svr1 dovecot: auth-worker(16468): Debug: passwd-file
/etc/dovecot/special-userdb: Read 1 users in 0 secs Dec 16 16:30:16 svr1 
dovecot: auth-worker(16468): Debug: passwd(test): 
lookup
Dec 16 16:30:16 svr1 dovecot: auth-worker(16468): passwd(test): invalid 
password field '*'
Dec 16 16:30:16 svr1 dovecot: auth: Debug: passdb out: NOTFOUND#0111 Dec 
16 16:30:16 svr1 dovecot: lmtp(16466): Debug: auth PASS input:
Dec 16 16:30:16 svr1 dovecot: lmtp(test): Debug: Loading modules from
directory: /usr/lib64/dovecot
Dec 16 16:30:16 svr1 dovecot: lmtp(test): Debug: Module loaded: 
/usr/lib64/dovecot/lib15_notify_plugin.so
Dec 16 16:30:16 svr1 dovecot: lmtp(test): Debug: Module loaded: 
/usr/lib64/dovecot/lib90_sieve_plugin.so
Dec 16 16:30:16 svr1 dovecot: lmtp(test): Debug: Module loaded: 
/usr/lib64/dovecot/libstorage_rbox_plugin.so
Dec 16 16:30:16 svr1 dovecot: auth: Debug: master in: 
USER#0112#011test#011service=lmtp
Dec 16 16:30:16 svr1 dovecot: auth: Debug: passwd-file(test): lookup: 
user=test file=/etc/dovecot/special-userdb Dec 16 16:30:16 svr1 dovecot: 
auth: Debug: userdb out: 
USER#0112#011test#011uid=8267#011gid=231#011home=/home/popusers/test
Dec 16 16:30:16 svr1 dovecot: lmtp(test): Debug: auth USER input: test
uid=8267 gid=231 home=/home/popusers/test Dec 16 16:30:16 svr1 dovecot: 
lmtp(16466, test): Debug: Effective uid=8267, gid=231, 
home=/home/popusers/test Dec 16 16:30:16 svr1 dovecot: lmtp(16466, 
test): Debug: Namespace inbox: 
type=private, prefix=, sep=/, inbox=yes, hidden=no, list=yes, 
subscriptions=yes location=rbox:~/rbox:INDEX=/home/popindex/test/index
Dec 16 16:30:16 svr1 dovecot: lmtp(16466, test): Debug: fs: 
root=/home/popusers/test/rbox, index=/home/popindex/test/index, 
indexpvt=, control=, inbox=, alt= Dec 16 16:30:16 svr1 dovecot: 
lmtp(test): Debug: sieve: Pigeonhole version 0.4.24 (124e06aa) 
initializing Dec 16 16:30:16 svr1 dovecot: lmtp(test): Debug: sieve: 
include: 
sieve_global is not set; it is currently not possible to include 
`:global' scripts.
Dec 16 16:30:16 svr1 dovecot: lmtp(test): Debug: +FIiFQij911SQAAAzJXYRg: 

sieve: file storage: Using active Sieve script path: 
/home/popusers/test/.dovecot.sieve
Dec 16 16:30:16 svr1 dovecot: lmtp(test): Debug: +FIiFQij911SQAAAzJXYRg: 

sieve: file storage: Using script storage path: 
/home/popusers/test/sieve
Dec 16 16:30:16 svr1 dovecot: lmtp(test): Debug: +FIiFQij911SQAAAzJXYRg: 

sieve: file storage: Relative path to sieve storage in active link: 
sieve/
Dec 16 16:30:16 svr1 dovecot: lmtp(test): Debug: +FIiFQij911SQAAAzJXYRg: 

sieve: file storage: Using Sieve script path: 
/home/popusers/test/.dovecot.sieve
Dec 16 16:30:16 svr1 dovecot: lmtp(test): Debug: +FIiFQij911SQAAAzJXYRg: 

sieve: file script: Opened script `managesieve' from 
`/home/popusers/test/.dovecot.sieve'
Dec 16 16:30:16 svr1 dovecot: lmtp(test): Debug: +FIiFQij911SQAAAzJXYRg: 

sieve: Using the following location for user's Sieve script: 
/home/popusers/test/.dovecot.sieve
Dec 16 16:30:16 svr1 dovecot: lmtp(test): Debug: Mailbox <lmtp DATA>: 
Opened mail UID=1 because: header Message-ID (Cache file is unusable) 
Dec 16 16:30:16 svr1 dovecot: lmtp(test): Debug: +FIiFQij911SQAAAzJXYRg: 

sieve: Opening script 1 of 1 from `/home/popusers/test/.dovecot.sieve'
Dec 16 16:30:16 svr1 dovecot: lmtp(test): Debug: +FIiFQij911SQAAAzJXYRg: 

sieve: Loading script /home/popusers/test/.dovecot.sieve
Dec 16 16:30:16 svr1 dovecot: lmtp(test): Debug: +FIiFQij911SQAAAzJXYRg: 

sieve: Script binary /home/popusers/test/.dovecot.svbin successfully 
loaded Dec 16 16:30:16 svr1 dovecot: lmtp(test): Debug: 
+FIiFQij911SQAAAzJXYRg: 
sieve: binary save: not saving binary
/home/popusers/test/.dovecot.svbin, because it is already stored Dec 16 
16:30:16 svr1 dovecot: lmtp(test): Debug: +FIiFQij911SQAAAzJXYRg: 
sieve: Executing script from `/home/popusers/test/.dovecot.svbin'
Dec 16 16:30:16 svr1 dovecot: lmtp(test): Debug: INBOX: Mailbox opened
because: lib-lda delivery
Dec 16 16:30:16 svr1 dovecot: lmtp(test): Debug: Mailbox <lmtp DATA>: 
Opened mail UID=1 because: copying
Dec 16 16:30:16 svr1 dovecot: lmtp(test): +FIiFQij911SQAAAzJXYRg: sieve: 

msgid=<201912161530.xBGFUF9A016463 at svr1.roosit.eu>: stored mail into 
mailbox 'INBOX'
Dec 16 16:30:16 svr1 dovecot: lmtp(16466): Disconnect from local: 
Successful quit

[2]
Dec 16 16:30:16 svr1 sendmail[16464]: xBGFUGm7016464: --- 250-PIPELINING 
Dec 16 16:30:16 svr1 sendmail[16464]: xBGFUGm7016464: --- 250-8BITMIME 
Dec 16 16:30:16 svr1 sendmail[16464]: xBGFUGm7016464: --- 250-SIZE 
52428800 Dec 16 16:30:16 svr1 sendmail[16464]: xBGFUGm7016464: --- 
250-DSN Dec 16 16:30:16 svr1 sendmail[16464]: xBGFUGm7016464: --- 
250-ETRN Dec 16 16:30:16 svr1 sendmail[16464]: xBGFUGm7016464: --- 
250-AUTH LOGIN PLAIN Dec 16 16:30:16 svr1 sendmail[16464]: 
xBGFUGm7016464: --- 250-DELIVERBY Dec 16 16:30:16 svr1 sendmail[16464]: 
xBGFUGm7016464: --- 250 HELP Dec 16 16:30:16 svr1 sendmail[16464]: 
xBGFUGm7016464: <-- MAIL From:<root at svr1.xxxxx.xxx> SIZE=216 
AUTH=root at svr1.xxxxx.xxx Dec 16 16:30:16 svr1 sendmail[16464]: 
ruleset=trust_auth, arg1=root at svr1.xxxxx.xxx, relay=localhost 
[127.0.0.1], reject=550 5.7.1 <root at svr1.xxxxx.xxx>... not authenticated 
Dec 16 16:30:16 svr1 sendmail[16464]: xBGFUGm7016464: --- 250 2.1.0 
<root at svr1.xxxxx.xxx>... Sender ok Dec 16 16:30:16 svr1 sendmail[16464]: 
xBGFUGm7016464: <-- RCPT To:<test at svr1.xxxxx.xxx> Dec 16 16:30:16 svr1 
sendmail[16464]: xBGFUGm7016464: --- 250 2.1.5 <test at svr1.xxxxx.xxx>... 
Recipient ok Dec 16 16:30:16 svr1 sendmail[16464]: xBGFUGm7016464: <-- 
DATA Dec 16 16:30:16 svr1 sendmail[16464]: xBGFUGm7016464: --- 354 Enter 
mail, end with "." on a line by itself Dec 16 16:30:16 svr1 
sendmail[16464]: STARTTLS=read, info: fds=11/4,
err=2
Dec 16 16:30:16 svr1 sendmail[16464]: xBGFUGm7016464: 
from=<root at svr1.xxxxx.xxx>, size=467, class=0, nrcpts=1, 
msgid=<201912161530.xBGFUF9A016463 at svr1.xxxxx.xxx>, proto=ESMTP, 
daemon=MTA, relay=localhost [127.0.0.1] Dec 16 16:30:16 svr1 
sendmail[16464]: xBGFUGm7016464: --- 250 2.0.0
xBGFUGm7016464 Message accepted for delivery Dec 16 16:30:16 svr1 
sendmail[16463]: xBGFUF9A016463: to=test, ctladdr=root (0/0), 
delay=00:00:01, xdelay=00:00:00, mailer=relay, pri=30216, 
relay=[127.0.0.1] [127.0.0.1], dsn=2.0.0, stat=Sent
(xBGFUGm7016464 Message accepted for delivery) Dec 16 16:30:16 svr1 
sendmail[16464]: STARTTLS=read, info: fds=11/4,
err=2
Dec 16 16:30:16 svr1 sendmail[16464]: xBGFUGm8016464: <-- QUIT Dec 16 
16:30:16 svr1 sendmail[16464]: xBGFUGm8016464: --- 221 2.0.0 
svr1.xxxxx.xxx closing connection Dec 16 16:30:16 svr1 sendmail[16465]: 
last message repeated 2 times Dec 16 16:30:16 svr1 sendmail[16465]: 
xBGFUGm7016464: 
to=<test at svr1.xxxxx.xxx>, ctladdr=<root at svr1.xxxxx.xxx> (0/0), 
delay=00:00:00, xdelay=00:00:00, mailer=local, pri=30753, 
relay=localhost, dsn=2.0.0, stat=Sent Dec 16 16:30:16 svr1 
sendmail[16465]: xBGFUGm7016464: done; delay=00:00:00, ntries=1


-----Original Message-----
To: aki.tuomi; dovecot
Subject: RE: Local lmtp proxy on backend server


Hi Aki,

If I adapt this configuration on svr1 like this[0], should the mail not 
be delivered at svr2 passdb {
  driver = pam
  # [session=yes] [setcred=yes] [failure_show_msg=yes] 
[max_requests=<n>]
  # [cache_key=<key>] [<service name>]
  #args = dovecot
  default_fields = proxy=y host=svr2
}
passdb {
  driver = passwd
  skip = authenticated
  default_fields = proxy=y host=svr2
}


 

-----Original Message-----
From: Aki Tuomi [mailto:aki.tuomi at open-xchange.com]
Sent: 16 December 2019 06:22
To: Marc Roos; dovecot
Subject: Re: Local lmtp proxy on backend server


	On 15/12/2019 23:09 Marc Roos < m.roos at f1-outsourcing.eu> wrote: 


	I receive a local mail when I do a 'mail test' on a backend svr1 
with 
	this[0] configuration. However when I just add only one 
configuration 
	change 'lmtp_proxy = yes' I am getting these errors[1]. I would 
expect 
	this email to still be delivered locally, should this be working or 


do I 
	misunderstand the lmtp proxy functionality? 


	[0] 
	passdb { 
	args = 
	auth_verbose = default 
	default_fields = proxy=y host=svr1 
	deny = no 
	driver = pam 


	[1] 
	Dec 15 23:28:48 svr1 dovecot: lmtp(9270): Debug: none: root=, 
index=, 
	indexpvt=, control=, inbox=, alt= 
	Dec 15 23:28:48 svr1 dovecot: lmtp(9270): Connect from local 
	Dec 15 23:28:48 svr1 dovecot: auth: Debug: master in: 
	PASS#0111#011test#011service=lmtp 
	Dec 15 23:28:48 svr1 dovecot: auth: Debug: pam(test): passdb 
doesn't 
	support credential lookups 
	Dec 15 23:28:48 svr1 dovecot: auth: Debug: passdb out: 
	FAIL#0111#011reason=Configured passdbs don't support credentials 
lookups 
	Dec 15 23:28:48 svr1 dovecot: lmtp(9270): Debug: user test: Auth 
PASS 
	lookup returned temporary failure: reason=Configured passdbs don't 
	support credentials lookups 
	Dec 15 23:28:48 svr1 dovecot: lmtp(9270): Debug: auth PASS input: 
	reason=Configured passdbs don't support credentials lookups 


	dovecot-pigeonhole-2.2.36-3.el7_7.1.x86_64 
	dovecot-2.2.36-3.el7_7.1.x86_64 


PAM does not support looking up users, so you cannot use it for LMTP 
proxying. Try adding 

passdb {
  driver = passwd
  skip = authenticated
} 

after PAM block. 
---
Aki Tuomi

More information about the dovecot mailing list