postfix filter lmtp

Discussion in 'General' started by ptroms, Jun 1, 2021.

Tags:
Page 1 of 2
  1. ptroms

    ptroms Member

    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?
     
    Last edited: Jun 4, 2021
    ptroms, Jun 1, 2021
    #1
  2. till

    till Super Moderator Staff Member ISPConfig Developer

    What kind of mail setup do you use?
     
    till, Jun 1, 2021
    #2
  3. ptroms

    ptroms Member

    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.
     
    ptroms, Jun 1, 2021
    #3
  4. Jesse Norell

    Jesse Norell Well-Known Member Staff Member Howtoforge Staff

    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.
     
    Jesse Norell, Jun 1, 2021
    #4
  5. ptroms

    ptroms Member

    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.
     
    ptroms, Jun 3, 2021
    #5
  6. ptroms

    ptroms Member

    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.
     
    Last edited: Jun 4, 2021
    ptroms, Jun 4, 2021
    #6
  7. Taleman

    Taleman Well-Known Member HowtoForge Supporter

    It says
    Code:
    Sender address triggers FILTER
    Add sender address to postfix whitelist in ISPConfig Panel, EMail | Global Filters | Postfix Whitelist as type Sender.
     
    Taleman, Jun 4, 2021
    #7
  8. ptroms

    ptroms Member

    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
     
    Last edited: Jun 4, 2021
    ptroms, Jun 4, 2021
    #8
  9. Jesse Norell

    Jesse Norell Well-Known Member Staff Member Howtoforge Staff

    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.
     
    Jesse Norell, Jun 4, 2021
    #9
  10. ptroms

    ptroms Member

    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?
     
    Last edited: Jun 4, 2021
    ptroms, Jun 4, 2021
    #10
  11. Jesse Norell

    Jesse Norell Well-Known Member Staff Member Howtoforge Staff

    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.
     
    Jesse Norell, Jun 5, 2021
    #11
  12. ptroms

    ptroms Member

    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?
     
    ptroms, Jun 7, 2021
    #12
  13. Jesse Norell

    Jesse Norell Well-Known Member Staff Member Howtoforge Staff

    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.
     
    Jesse Norell, Jun 7, 2021
    #13
  14. ptroms

    ptroms Member

    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]
     
    ptroms, Jun 7, 2021
    #14
  15. Jesse Norell

    Jesse Norell Well-Known Member Staff Member Howtoforge Staff

    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.
     
    Jesse Norell, Jun 7, 2021
    #15
  16. ptroms

    ptroms Member

    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?
     
    ptroms, Jun 9, 2021
    #16
  17. Jesse Norell

    Jesse Norell Well-Known Member Staff Member Howtoforge Staff

    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).
     
    Jesse Norell, Jun 9, 2021
    #17
  18. ptroms

    ptroms Member

    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
     
    ptroms, Jun 9, 2021
    #18
  19. Jesse Norell

    Jesse Norell Well-Known Member Staff Member Howtoforge Staff

    Stop amavis (which is what is using the ports already), then start postfix.
     
    Jesse Norell, Jun 9, 2021
    #19
  20. ptroms

    ptroms Member

    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
     
    Last edited: Jun 9, 2021
    ptroms, Jun 9, 2021
    #20
Page 1 of 2

Share This Page