postfix doesn't deliver mail through dagent

AnotherAndy

@gduran
my output is:
tcp6 0 0 :::2003 :::* LISTEN 0 4017973 7873/kopano-dagen
so just use the telnet commands to try if you can reach port 2003 by 127.0.0.1

result must be:
telnet 127.0.0.1 2003
Trying 127.0.0.1…
Connected to 127.0.0.1.
Escape character is ‘^]’.
220 2.1.5 LMTP server is ready

br
Andreas

gduran

@anotherandy
Hi Andreas,
I have changes the configs: Postfix now virtual_transport = lmtp:127.0.0.1:2003
kopano-dagent lmtp_listen = 127.0.0.1:2003

telnet results:
Trying 127.0.0.1…
Connected to 127.0.0.1.
Escape character is ‘^]’.
220 2.1.5 LMTP server is ready

But no luck, mail is still being dropped in the local mailbox.
br
Gerrit

AnotherAndy

@gduran
so we have to search for the error on the postfix service.
How do you choose the users? with and openldap oder mysql table?
br

gduran

@anotherandy

Using postfix with openldap.
I added the -v like you said and that results in a lot of entries in the mail.log but is to long to post.

bg
Gerrit

fbartels

@gduran Please post your complete postfix configuration.

gduran

@fbartels
Hi Felix,
This forum does not accept because it seems to be too large…
So how do I do that?

AnotherAndy

@gduran
I was thinking about your problem again. Do you have a development or testing environment? Did your postfix-ldap work there?
Just a thought - did you install the postfix-ldap package?
br
Andreas

gduran

@anotherandy

Hi Andreas,
Meanwhile I’ve rolled back and the ‘old’ server is in place again.
Yes everything required has been installed.
I do see some strange anomalies in the mail log which while comparing with the log from the ‘old server’ where I’ve added the -v key as well to the master.cf.
I now suspect it has something to do with the postfix version in use on the new server being 3.4.13 while 3.3.0 running on the ‘old server’.
bg
Gerrit

fbartels

@gduran said in postfix doesn't deliver mail through dagent:

So how do I do that?

You could for example use https://gist.github.com/

gduran

@fbartels
Hi Felix,
I’ve compared the mail.log’s from both the working “old server” and “new server” and I will just include the most obvious part where it is clear that postfix is messing around with mail headers.
As you can see I make use of an external anti spam party and postfix is replacing the intended e-mail addresses (sender’s as well recipient’s) with something composed from the spam service. No wonder that no match is being found while consulting ldap as ldap searches using a non existing address. Somehow after not finding a match it still remembers the intended e-mail addresses as the e-mail is properly delivered to the local mailbox (???).
Here is an extract of the log file with comments between brackets of the differences between the mail log on the “old server”.

Apr  5 18:19:08 server1 postfix/smtpd[46477]: > mx68.antispamcloud.com[212.32.233.198]: 250-server1.[mydomain].com
Apr  5 18:19:08 server1 postfix/smtpd[46477]: > mx68.antispamcloud.com[212.32.233.198]: 250-PIPELINING
Apr  5 18:19:08 server1 postfix/smtpd[46477]: > mx68.antispamcloud.com[212.32.233.198]: 250-SIZE 20480000
Apr  5 18:19:08 server1 postfix/smtpd[46477]: > mx68.antispamcloud.com[212.32.233.198]: 250-VRFY
Apr  5 18:19:08 server1 postfix/smtpd[46477]: > mx68.antispamcloud.com[212.32.233.198]: 250-ETRN
Apr  5 18:19:08 server1 postfix/smtpd[46477]: > mx68.antispamcloud.com[212.32.233.198]: 250-AUTH DIGEST-MD5 NTLM CRAM-MD5 PLAIN LOGIN
Apr  5 18:19:08 server1 postfix/smtpd[46477]: > mx68.antispamcloud.com[212.32.233.198]: 250-AUTH=DIGEST-MD5 NTLM CRAM-MD5 PLAIN LOGIN
Apr  5 18:19:08 server1 postfix/smtpd[46477]: > mx68.antispamcloud.com[212.32.233.198]: 250-ENHANCEDSTATUSCODES
Apr  5 18:19:08 server1 postfix/smtpd[46477]: > mx68.antispamcloud.com[212.32.233.198]: 250-8BITMIME
Apr  5 18:19:08 server1 postfix/smtpd[46477]: > mx68.antispamcloud.com[212.32.233.198]: 250-DSN
Apr  5 18:19:08 server1 postfix/smtpd[46477]: > mx68.antispamcloud.com[212.32.233.198]: 250-SMTPUTF8
Apr  5 18:19:08 server1 postfix/smtpd[46477]: > mx68.antispamcloud.com[212.32.233.198]: 250 CHUNKING
Apr  5 18:19:08 server1 postfix/smtpd[46477]: < mx68.antispamcloud.com[212.32.233.198]: MAIL FROM:<> [here mail address sender missing???]
Apr  5 18:19:08 server1 postfix/smtpd[46477]: extract_addr: input: <> [here mail address sender missing???]
Apr  5 18:19:08 server1 postfix/smtpd[46477]: smtpd_check_addr: addr= [here mail address sender missing???]
Apr  5 18:19:08 server1 postfix/smtpd[46477]: extract_addr: in: <>, result: [here mail address sender missing???]
Apr  5 18:19:08 server1 postfix/smtpd[46477]: connect to subsystem private/rewrite
Apr  5 18:19:08 server1 postfix/smtpd[46477]: send attr request = rewrite
Apr  5 18:19:08 server1 postfix/smtpd[46477]: send attr rule = local
Apr  5 18:19:08 server1 postfix/smtpd[46477]: send attr address = double-bounce [in 'old server' log = ""]
Apr  5 18:19:08 server1 postfix/smtpd[46477]: private/rewrite socket: wanted attribute: flags
Apr  5 18:19:08 server1 postfix/smtpd[46477]: input attribute name: flags
Apr  5 18:19:08 server1 postfix/smtpd[46477]: input attribute value: 0
Apr  5 18:19:08 server1 postfix/smtpd[46477]: private/rewrite socket: wanted attribute: address
Apr  5 18:19:08 server1 postfix/smtpd[46477]: input attribute name: address
Apr  5 18:19:08 server1 postfix/smtpd[46477]: input attribute value: double-bounce@server1 [in 'old server' log = ""]
Apr  5 18:19:08 server1 postfix/smtpd[46477]: private/rewrite socket: wanted attribute: (list terminator)
Apr  5 18:19:08 server1 postfix/smtpd[46477]: input attribute name: (end)
Apr  5 18:19:08 server1 postfix/smtpd[46477]: rewrite_clnt: local: double-bounce -> double-bounce@server1 [in 'old server' log = "" -> ""]
Apr  5 18:19:08 server1 postfix/smtpd[46477]: smtpd_check_rewrite: trying: permit_inet_interfaces
Apr  5 18:19:08 server1 postfix/smtpd[46477]: permit_inet_interfaces: mx68.antispamcloud.com 212.32.233.198
Apr  5 18:19:08 server1 postfix/smtpd[46477]: fsspace: .: block size 4096, blocks free 56667460
Apr  5 18:19:08 server1 postfix/smtpd[46477]: smtpd_check_queue: blocks 4096 avail 56667460 min_free 0 msg_size_limit 20480000
Apr  5 18:19:08 server1 postfix/smtpd[46477]: > mx68.antispamcloud.com[212.32.233.198]: 250 2.1.0 Ok
Apr  5 18:19:08 server1 postfix/smtpd[46477]: < mx68.antispamcloud.com[212.32.233.198]: RCPT TO:<mx68.antispamcloud.com-1617639548-testing@[mydomain].com> [should be RCPT TO: recipient e-mail address]
Apr  5 18:19:08 server1 postfix/smtpd[46477]: extract_addr: input: <mx68.antispamcloud.com-1617639548-testing@[mydomain].com> [should be recipient e-mail address]
Apr  5 18:19:08 server1 postfix/smtpd[46477]: smtpd_check_addr: addr=mx68.antispamcloud.com-1617639548-testing@[mydomain].com [should be recipient e-mail address]
Apr  5 18:19:08 server1 postfix/smtpd[46477]: send attr request = rewrite
Apr  5 18:19:08 server1 postfix/smtpd[46477]: send attr rule = local
Apr  5 18:19:08 server1 postfix/smtpd[46477]: send attr address = "" [should be senders e-mail address]
Apr  5 18:19:08 server1 postfix/smtpd[46477]: private/rewrite socket: wanted attribute: flags
Apr  5 18:19:08 server1 postfix/smtpd[46477]: input attribute name: flags
Apr  5 18:19:08 server1 postfix/smtpd[46477]: input attribute value: 0
Apr  5 18:19:08 server1 postfix/smtpd[46477]: private/rewrite socket: wanted attribute: address
Apr  5 18:19:08 server1 postfix/smtpd[46477]: input attribute name: address
Apr  5 18:19:08 server1 postfix/smtpd[46477]: input attribute value: "" [should be senders e-mail address]
Apr  5 18:19:08 server1 postfix/smtpd[46477]: private/rewrite socket: wanted attribute: (list terminator)
Apr  5 18:19:08 server1 postfix/smtpd[46477]: input attribute name: (end)
Apr  5 18:19:08 server1 postfix/smtpd[46477]: rewrite_clnt: local: "" -> "" [should be sender mail addr -> sender mail addr]
Apr  5 18:19:08 server1 postfix/smtpd[46477]: send attr request = rewrite [should be resolve]
Apr  5 18:19:08 server1 postfix/smtpd[46477]: send attr rule = local [entry not in log 'old server]
						[instead: send attr sender = senders email address
Apr  5 18:19:08 server1 postfix/smtpd[46477]: send attr address = mx68.antispamcloud.com-1617639548-testing@[mydomain].com [should be recipient e-mail address]
Apr  5 18:19:08 server1 postfix/smtpd[46477]: private/rewrite socket: wanted attribute: flags
Apr  5 18:19:08 server1 postfix/smtpd[46477]: input attribute name: flags
Apr  5 18:19:08 server1 postfix/smtpd[46477]: input attribute value: 0
Apr  5 18:19:08 server1 postfix/smtpd[46477]: private/rewrite socket: wanted attribute: address [should be transport]
Apr  5 18:19:08 server1 postfix/smtpd[46477]: input attribute name: address [should be transport]
						missing: input attribute name: transport
							input attribute value: lmtp
							private/rewrite socket: wanted attribute: nexthop
							input attribute name: nexthop
							input attribute value: unix:/kopano/dagent.sock
							private/rewrite socket: wanted attribute: recipient
							input attribute name: recipient
Apr  5 18:19:08 server1 postfix/smtpd[46477]: input attribute value: mx68.antispamcloud.com-1617639548-testing@[mydomain].com [should be recipient email address]
Apr  5 18:19:08 server1 postfix/smtpd[46477]: private/rewrite socket: wanted attribute: (list terminator) [should be flags]
Apr  5 18:19:08 server1 postfix/smtpd[46477]: input attribute name: (end) [should be recipient]
Apr  5 18:19:08 server1 postfix/smtpd[46477]: rewrite_clnt: local: mx68.antispamcloud.com-1617639548-testing@[mydomain].com -> mx68.antispamcloud.com-1617639548-testing@[mydomain].com
Apr  5 18:19:08 server1 postfix/smtpd[46477]: send attr request = resolve
Apr  5 18:19:08 server1 postfix/smtpd[46477]: send attr sender = 
Apr  5 18:19:08 server1 postfix/smtpd[46477]: send attr address = mx68.antispamcloud.com-1617639548-testing@[mydomain].com
Apr  5 18:19:08 server1 postfix/trivial-rewrite[46480]: warning: do not list domain [mydomain].com in BOTH mydestination and virtual_mailbox_domains
Apr  5 18:19:08 server1 postfix/smtpd[46477]: private/rewrite socket: wanted attribute: flags
Apr  5 18:19:08 server1 postfix/smtpd[46477]: input attribute name: flags
Apr  5 18:19:08 server1 postfix/smtpd[46477]: input attribute value: 0
Apr  5 18:19:08 server1 postfix/smtpd[46477]: private/rewrite socket: wanted attribute: transport
Apr  5 18:19:08 server1 postfix/smtpd[46477]: input attribute name: transport
Apr  5 18:19:08 server1 postfix/smtpd[46477]: input attribute value: local
Apr  5 18:19:08 server1 postfix/smtpd[46477]: private/rewrite socket: wanted attribute: nexthop
Apr  5 18:19:08 server1 postfix/smtpd[46477]: input attribute name: nexthop
Apr  5 18:19:08 server1 postfix/smtpd[46477]: input attribute value: server1.[mydomain].com
Apr  5 18:19:08 server1 postfix/smtpd[46477]: private/rewrite socket: wanted attribute: recipient
Apr  5 18:19:08 server1 postfix/smtpd[46477]: input attribute name: recipient
Apr  5 18:19:08 server1 postfix/smtpd[46477]: input attribute value: mx68.antispamcloud.com-1617639548-testing@[mydomain].com
Apr  5 18:19:08 server1 postfix/smtpd[46477]: private/rewrite socket: wanted attribute: flags
Apr  5 18:19:08 server1 postfix/smtpd[46477]: input attribute name: flags
Apr  5 18:19:08 server1 postfix/smtpd[46477]: input attribute value: 256
Apr  5 18:19:08 server1 postfix/smtpd[46477]: private/rewrite socket: wanted attribute: (list terminator)
Apr  5 18:19:08 server1 postfix/smtpd[46477]: input attribute name: (end)
Apr  5 18:19:08 server1 postfix/smtpd[46477]: resolve_clnt: `' -> `mx68.antispamcloud.com-1617639548-testing@[mydomain].com' -> transp=`local' host=`server1.[mydomain].com' rcpt=`mx68.antispamcloud.com-1617639548-testing@[mydomain].com' flags= class=local [should be senders email address -> recipient email address]
Apr  5 18:19:08 server1 postfix/smtpd[46477]: ctable_locate: install entry key ?mx68.antispamcloud.com-1617639548-testing@[mydomain].com [should be senders email address->recipient email address -> transp='lmtp'host='unix:/kopano/dagent.sock' rcpt='recipient email address' flags= class=virtual]
						missing:
							ctable_locate: install entry key senders address?recipient address
Apr  5 18:19:08 server1 postfix/smtpd[46477]: extract_addr: in: <mx68.antispamcloud.com-1617639548-testing@[mydomain].com>, result: mx68.antispamcloud.com-1617639548-testing@[mydomain].com [ should be both recipient address]
Apr  5 18:19:08 server1 postfix/smtpd[46477]: >>> START Recipient address RESTRICTIONS <<<```

gduran

This post is deleted!

gduran

@gduran said in postfix doesn't deliver mail through dagent:

@fbartels
Hi Felix,
New insights: I just figured out that for some reason the ldap-users search fails but after creating a KopanoAliasses entry with the same address as in the mail entry in LDAP it is properly resolved by postfix and delivers to Kopano Dagent through lmtp.
So now I need to understand why the ldap-users search fails…
First I’ve downgraded postfix and used the same postfix config as on the ‘old server’ but bumped into the same result. Than I tried adding the KopanoAliasses and than it worked. Next I upgraded postfix back to 3.4.13 and it still worked. Any idea what to look for why postfix cannot resolve the query_filter = (&(objectClass=posixAccount)(mail=%s))?

postmap -vq [username]@[mydomain].com ldap:/etc/postfix/ldap-users.cf does resolve properly and is returning the right e-mail address(???).

gduran

@fbartels
Hi Felix,
Not sure if there’s no response anymore because this may be considered as a postfix problem.
If so than please let me know.
Anyway, I’ve spend days now to examine what possibly goes wrong. I’ve compared both the working and non-working log line by line (close to 700 lines(!!!)). Stripped the first couple of columns (date stamp etc) to make it more easy to compare using WinMerge.
Two things were noticed.

there no attempt to connect to lmtp as where in the working log I read {rcpt_host}=unix:/kopano/dagent.sock {rcpt_mailer}=lmtp. Obviously it’s properly defined in main.cf. As I’m sending e-mails to myself postfix is able to resolve in the end as I’m known as a user on this machine and thus dropping the mail in the local mailbox.
I compared the ldap connections made. At first postfix is testing ldap if it can connect . First the virtual_alias_maps followed by the virtual_mailbox_maps (ldap:/etc/postfix/ldap-users.cf). Further on in the non-working log it only consults the virtual_alias_maps but NOT the ldap:/etc/postfix/ldap-users.cf. On the working machine it is clear that during the second stage it does consult ldap:/etc/postfix/ldap-users.cf and can resolve.
To exclude any wrong interpretation I did remove and purged postfix as wel as openldap, build them anew and started to test with a bare minimum of settings. I only added the lmtp directive and virtual_mailbox_maps = ldap:/etc/postfix/ldap-users.cf. Still the same behaviour: No connection to lmtp and although it connects to ldap it does not perform a search.
What now coach???

fbartels

@gduran said in postfix doesn't deliver mail through dagent:

Not sure if there’s no response anymore because this may be considered as a postfix problem.

No, mostly because i am on holiday ;-)

@gduran said in postfix doesn't deliver mail through dagent:

What now coach???

You still did not post your postfix configuration. My working theory is that you have a typo in your virtual_ definitions somewhere and therefore he does not use the *_transport definition you expect.

gduran

@fbartels
Hi Felix,
Thanks a lot!!!
One directive was indeed missing:
virtual_mailbox_domains = [example.com]
Once defined it worked like charm.
Although, not understanding as to why this directive is necessary and how that is related to the ldap search and lmpt failure but it’s running now.
Thanks again and have a nice holiday!!!