I have been seeing few email regularly bouncing away based on following log: Code: Jun 1 04:48:39 ups postfix/smtpd[20916]: NOQUEUE: filter: RCPT from mta2.christrevealed.com[168.235.235.62]: <[email protected]>: Sender address triggers FILTER lmtp:[127.0.0.1]:10026; from=<[email protected]> to=<[email protected]> proto=ESMTP helo=<mta2.christrevealed.com> Jun 1 04:48:39 ups postfix/smtpd[20916]: NOQUEUE: filter: RCPT from mta2.christrevealed.com[168.235.235.62]: <[email protected]>: Sender address triggers FILTER lmtp:[127.0.0.1]:10024; from=<[email protected]> to=<[email protected]> proto=ESMTP helo=<mta2.christrevealed.com> Jun 1 04:48:39 ups postfix/smtpd[20916]: 507768C3E13: client=mta2.christrevealed.com[168.235.235.62] I am guessing it is corresponding with an content filer in main.cf ... content_filter = lmtp:[127.0.0.1]:10024 ... shall I just simply commented out, or is any way around it?
Thank you for early reply. I would say the default one. I haven't touched postfix conf for sometime. Recently I have updated ispconfig to the ver 3.2.4 and spotted the log.
I'll move your post to the relevant ISPConfig topic. The logs you posted don't show any 'reject', just that content filter was set to port 10026, then updated to port 10024, which is normal/correct for external email. If that's one of your users trying to send, they forgot to use authentication. If that's an external user sending to you, keep reading further in the mail log to see what happened.
Right. Following closely inspections I need to admin that postfix works in flying colors and the lmtp filter does block from time to time some emails form auto respond sites, such us "password restore" functions, but mostly blocking junk mails.
I am afraid it occasionally blocking important email such as booking tickets: Code: Jun 4 08:20:08 ups postfix/smtpd[2096]: connect from origin1-mail.easyjet.com[213.174.196.41] Jun 4 08:20:08 ups postfix/smtpd[2096]: NOQUEUE: filter: RCPT from origin1-mail.easyjet.com[213.174.196.41]: <[email protected]>: Sender address triggers FILTER lmtp:[127.0.0.1]:10026; from=<[email protected]> to=<[email protected]> proto=ESMTP helo=<origin1-mail.easyjet.com> Jun 4 08:20:08 ups postfix/smtpd[2096]: NOQUEUE: filter: RCPT from origin1-mail.easyjet.com[213.174.196.41]: <[email protected]>: Sender address triggers FILTER lmtp:[127.0.0.1]:10024; from=<[email protected]> to=<[email protected]> proto=ESMTP helo=<origin1-mail.easyjet.com> Jun 4 08:20:08 ups postfix/smtpd[2096]: 78D448C3EA5: client=origin1-mail.easyjet.com[213.174.196.41] Any help appreciate.
It says Code: Sender address triggers FILTER Add sender address to postfix whitelist in ISPConfig Panel, EMail | Global Filters | Postfix Whitelist as type Sender.
I am afraid it didn't help, but the log looks different. Code: Jun 4 13:43:06 ups postfix/smtpd[19871]: connect from mail.tsohost.co.uk[195.62.28.191] Jun 4 13:43:07 ups postfix/smtpd[19871]: 349C18C11B0: client=mail.tsohost.co.uk[195.62.28.191] Mail queue empty, no sign of any errors and warm logs. And then after around 5 min comes up this: Code: Jun 4 13:48:07 ups postfix/smtpd[19871]: timeout after DATA (0 bytes) from mail.tsohost.co.uk[195.62.28.191] Jun 4 13:48:07 ups postfix/smtpd[19871]: disconnect from mail.tsohost.co.uk[195.62.28.191] ehlo=1 mail=1 rcpt=1 data=0/1 commands=3/4 Interesting
Those logs show the message was received and will be sent to amavis for filtering, keep reading the logs to see what happened with it after that. That one indicates the other end did not complete the smtp conversation, but timed out after sending the DATA command.
Well. Amavis is loaded Code: Loaded: loaded (/etc/init.d/amavis; generated) Active: active (running) since Fri 2021-06-04 19:25:15 BST; 20min ago Docs: man:systemd-sysv-generator(8) Process: 6643 ExecStart=/etc/init.d/amavis start (code=exited, status=0/SUCCESS) Tasks: 3 (limit: 4915) Memory: 167.9M CGroup: /system.slice/amavis.service ââ6659 /usr/sbin/amavisd-new (master) ââ6677 /usr/sbin/amavisd-new (ch1-avail) ââ6678 /usr/sbin/amavisd-new (virgin child) Jun 04 19:25:15 ups systemd[1]: Started LSB: Starts amavisd-new mailfilter. Jun 04 19:25:15 ups amavis[6659]: No ext program for .rpm, tried: rpm2cpio.pl, rpm2cpio Jun 04 19:25:15 ups amavis[6659]: No ext program for .zoo, tried: zoo Jun 04 19:25:15 ups amavis[6659]: No ext program for .doc, tried: ripole Jun 04 19:25:15 ups amavis[6659]: No decoder for .F Jun 04 19:25:15 ups amavis[6659]: No decoder for .doc Jun 04 19:25:15 ups amavis[6659]: No decoder for .zoo Jun 04 19:25:15 ups amavis[6659]: Using primary internal av scanner code for ClamAV-clamd Jun 04 19:25:15 ups amavis[6659]: Found secondary av scanner ClamAV-clamscan at /usr/bin/clamscan File /etc/amavis/conf.d/50-user contains details: Code: # Enable Logging $DO_SYSLOG = 1; $LOGFILE = "/var/log/amavis.log"; # (defaults to empty, no log) But no log file. Ok I got that, but how to trace the filter error?
I'm reading on a smartphone so might overlook something, but I don't believe there was an error. The other end did not complete the smtp transaction, you can't tell from your logs why that happened. If you had another server to send from you could see both sides of the conversation, or post your actual server name and someone else could test.
Terrible. Is a way to disable the lmtp filter in some sort of way and enable one bit of that time and see what is blocking it?
You could temporarily stop amavisd-new, then edit /etc/postfix/master.cf to copy the entries for ports 10025 and 10027 to listen on 10024 and 10026 as well, then postfix will simply pass the message to the downstream smtpd and bypass amavis. Or you can edit /etc/postfix/main.cf to remove the 'tag_as_*.re' maps from smtpd_sender_restrictions and comment out content_filter, which will then queue the message for delivery directly. If that solves your problem, it probably lies in amavis, and you would want to increase logging there; if it doesn't, the problem is likely in postfix, and you can enable debugging there.
Well I Couldn't bypass amavis, even more I tried temporary override domain/IP address of the sender as a whitelist/my networks. the lmtp filer blocks it. None of it works. As you can see on the log the filter struck right away when the connection form the sender is established. Code: Jun 7 22:27:43 ups postfix/smtpd[24056]: connect from mail.tsohost.co.uk[195.62.28.191] Jun 7 22:27:43 ups postfix/smtpd[24056]: NOQUEUE: filter: RCPT from mail.tsohost.co.uk[195.62.28.191]: <[email protected]>: Sender address triggers FILTER lmtp:[127.0.0.1]:10026; from=<[email protected]> to=<[email protected]> proto=ESMTP helo=<mail.tsohost.co.uk> Jun 7 22:27:43 ups postfix/smtpd[24056]: NOQUEUE: filter: RCPT from mail.tsohost.co.uk[195.62.28.191]: <[email protected]>: Sender address triggers FILTER lmtp:[127.0.0.1]:10024; from=<[email protected]> to=<[email protected]> proto=ESMTP helo=<mail.tsohost.co.uk> Jun 7 22:27:43 ups postfix/smtpd[24056]: 5D1738C34A0: client=mail.tsohost.co.uk[195.62.28.191]
I mentioned 2 ways to do so, which did you try? What do your config changes look like? Maybe you just need to restart postfix after making your changes? Your logs in that same post #14 indicate neither of those changes is in effect, the sender domain is not whitelisted, and the server's ip is not in mynetworks at the time those logs were made. That could be true, but there is no indication whatsoever of that in any of the logs you have posted. What I see is the correct content_filter was set for a message from an external sender. You did not post subsequent logs which would show the disposition of that smtp session.
Bypassing amavis: The first solution reporting the ports 10025 10027 to 10024 and 10026 but the system dies. The other way I am no sure what 'tag_as_*.re' means, so I just ended up nowhere. Also I have increase amavis log to 5 and didn't help to provide any additional info regarding the problem. I am just curious any mail that lands into the server does hit the lmtp filter twice. First port 10026 and then 10024, regardless of the future respond. Is that normal?
I'm not sure what you mean by "reporting the ports", but you should copy the entire 10025 entry and change it to port 10024, and likewise copy the entire 10027 entry and change it to port 10026, then reload postfix. Edit /etc/postfix/main.cf and change Code: smtpd_sender_restrictions = check_sender_access proxy:mysql:/etc/postfix/mysql-virtual_sender.cf, reject_authenticated_sender_login_mismatch, check_sender_access regexp:/etc/postfix/tag_as_originating.re, permit_mynetworks,reject_sender_login_mismatch,, permit_sasl_authenticated, reject_non_fqdn_sender, reject_unlisted_sender, check_sender_access regexp:/etc/postfix/tag_as_foreign.re to Code: smtpd_sender_restrictions = check_sender_access proxy:mysql:/etc/postfix/mysql-virtual_sender.cf, reject_authenticated_sender_login_mismatch, permit_mynetworks,reject_sender_login_mismatch,, permit_sasl_authenticated, reject_non_fqdn_sender, reject_unlisted_sender Then reload postfix. Perhaps the mail isn't even making it to amavis. Most of the logs you posted do not indicate what happened to the message; the one exception shows that the client timed out after the DATA command, meaning the message was never sent/completed, so it would not have been filtered by amavis. It doesn't get filtered twice, at first the port 10026 filter is set, then later that is changed to 10024. It seems like it's probably not being sent to amavis at all, or at least there's no indication of that so far. Yes, that's how the content_filter is set (in smtpd_sender_restrictions).
In therms of the "reporting the ports" it was typo error should be repoint. After changes and restarting I have got this. Code: Jun 9 18:32:12 ups postfix/master[5884]: fatal: bind 127.0.0.1 port 10024: Address already in use Jun 9 18:32:13 ups postfix/master[5883]: fatal: daemon initialization failure Jun 9 18:32:14 ups postfix/postfix-script[5885]: fatal: mail system startup failed Jun 9 18:35:01 ups postfix/postqueue[6004]: warning: Mail system is down -- accessing queue directly I am afraid the system dies
I have done it, also I sent an email form outside that always works and I have got this: Code: Jun 9 18:53:04 ups postfix/lmtp[8218]: 396188C3866: to=<[email protected]>, relay=127.0.0.1[127.0.0.1]:10024, delay=4.3, delays=4.2/0.01/0.02/0, dsn=5.5.2, status=bounced (host 127.0.0.1[127.0.0.1] refused to talk to me: 502 5.5.2 Error: command not recognized) And is bounce back to the sender as undelivered, also local emails are undelivered. The undelivered emails have the same error. Code: <[email protected]>: host 127.0.0.1[127.0.0.1] refused to talk to me: 502 5.5.2 Error: command not recognized
