0

Our email messages are not delivered. We have done some debugging but have not found any issues. When we send an email using a simple test script PHPMailer reports success and the logs indicate the mail was accepted for delivery:

Message accepted for delivery

but nothing arrives at the receiving end, not to the inbox and not to the spam folder.

What are our debugging options?

We have the following in place

  • Postfix MTA installed and configured as per this guide
  • Have opened ports 25, 465 and 587 in UFW
  • Verified that we can connect to Gmail SMTP with telnet (with telnet -4 smtp.gmail.com 25)
  • A script that uses PHPMailer to send email with low level logging ($mail->SMTPDebug = 4;)

Here are sample logs in which we have changed identifying info with dummy details:

2019-03-15 16:19:42 Connection: opening to localhost:25, timeout=300, options=array()
2019-03-15 16:19:42 Connection: opened
2019-03-15 16:19:42 SMTP INBOUND: "220 example.com ESMTP Sendmail 8.14.4/8.14.4/Debian-4.1ubuntu1; Fri, 15 Mar 2019 17:19:42 +0100; (No UCE/UBE) logging access from: localhost(OK)-localhost [127.0.0.1]"
2019-03-15 16:19:42 SERVER -> CLIENT: 220 example.com ESMTP Sendmail 8.14.4/8.14.4/Debian-4.1ubuntu1; Fri, 15 Mar 2019 17:19:42 +0100; (No UCE/UBE) logging access from: localhost(OK)-localhost [127.0.0.1]
2019-03-15 16:19:42 CLIENT -> SERVER: EHLO example.com
2019-03-15 16:19:42 SMTP INBOUND: "250-example.com Hello localhost [127.0.0.1], pleased to meet you"
2019-03-15 16:19:42 SMTP INBOUND: "250-ENHANCEDSTATUSCODES"
2019-03-15 16:19:42 SMTP INBOUND: "250-PIPELINING"
2019-03-15 16:19:42 SMTP INBOUND: "250-EXPN"
2019-03-15 16:19:42 SMTP INBOUND: "250-VERB"
2019-03-15 16:19:42 SMTP INBOUND: "250-8BITMIME"
2019-03-15 16:19:42 SMTP INBOUND: "250-SIZE"
2019-03-15 16:19:42 SMTP INBOUND: "250-DSN"
2019-03-15 16:19:42 SMTP INBOUND: "250-ETRN"
2019-03-15 16:19:42 SMTP INBOUND: "250-AUTH DIGEST-MD5 CRAM-MD5"
2019-03-15 16:19:42 SMTP INBOUND: "250-DELIVERBY"
2019-03-15 16:19:42 SMTP INBOUND: "250 HELP"
2019-03-15 16:19:42 SERVER -> CLIENT: 250-example.com Hello localhost [127.0.0.1], pleased to meet you
                                      250-ENHANCEDSTATUSCODES
                                      250-PIPELINING
                                      250-EXPN
                                      250-VERB
                                      250-8BITMIME
                                      250-SIZE
                                      250-DSN
                                      250-ETRN
                                      250-AUTH DIGEST-MD5 CRAM-MD5
                                      250-DELIVERBY
                                      250 HELP
2019-03-15 16:19:42 CLIENT -> SERVER: MAIL FROM:<info@example.com>
2019-03-15 16:19:42 SMTP INBOUND: "250 2.1.0 <info@example.com>... Sender ok"
2019-03-15 16:19:42 SERVER -> CLIENT: 250 2.1.0 <info@example.com>... Sender ok
2019-03-15 16:19:42 CLIENT -> SERVER: RCPT TO:<john.doe@gmail.com>
2019-03-15 16:19:42 SMTP INBOUND: "250 2.1.5 <john.doe@gmail.com>... Recipient ok
"2019-03-15 16:19:42    SERVER -> CLIENT: 250 2.1.5 <john.doe@gmail.com>... Recipient ok
2019-03-15 16:19:42 CLIENT -> SERVER: DATA
2019-03-15 16:19:42 SMTP INBOUND: "354 Enter mail, end with "." on a line by itself"
2019-03-15 16:19:42 SERVER -> CLIENT: 354 Enter mail, end with "." on a line by itself
2019-03-15 16:19:42 CLIENT -> SERVER: Date: Fri, 15 Mar 2019 17:19:42 +0100
2019-03-15 16:19:42 CLIENT -> SERVER: To: john.doe@gmail.com
2019-03-15 16:19:42 CLIENT -> SERVER: From: info@example.com
2019-03-15 16:19:42 CLIENT -> SERVER: Subject: Test Email
2019-03-15 16:19:42 CLIENT -> SERVER: Message-ID: <LQM2kBXgDboENNfZCiZXl5DTCXJgino6kLi9Ham0@example.com>
2019-03-15 16:19:42 CLIENT -> SERVER: X-Mailer: PHPMailer 6.0.5 (https://github.com/PHPMailer/PHPMailer)
2019-03-15 16:19:42 CLIENT -> SERVER: MIME-Version: 1.0
2019-03-15 16:19:42 CLIENT -> SERVER: Content-Type: text/html; charset=iso-8859-1
2019-03-15 16:19:42 CLIENT -> SERVER:
2019-03-15 16:19:42 CLIENT -> SERVER: The body of the test email.
2019-03-15 16:19:42 CLIENT -> SERVER:
2019-03-15 16:19:42 CLIENT -> SERVER: .
2019-03-15 16:19:42 SMTP INBOUND: "250 2.0.0 x2FGJgcR016911 Message accepted for delivery"
2019-03-15 16:19:42 SERVER -> CLIENT: 250 2.0.0 x2FGJgcR016911 Message accepted for delivery
2019-03-15 16:19:42 CLIENT -> SERVER: QUIT
2019-03-15 16:19:42 SMTP INBOUND: "221 2.0.0 example.com closing connection"
2019-03-15 16:19:42 SERVER -> CLIENT: 221 2.0.0 example.com closing connection
2019-03-15 16:19:42 Connection: closed

Update
The log, /var/log/mail.log, is very long (more than 400KB), however I searched in it for lines containing x2FGJgcR016911 as it looks like some kind of hash and is present in my sample logs above. I found these four lines (again having identifying info in them glossed over):

Mar 15 17:19:43 m1-production sm-mta[16913]: x2FGJgcR016911: to=<john.doe@gmail.com>, delay=00:00:01, xdelay=00:00:01, mailer=esmtp, pri=120332, relay=gmail-smtp-in.l.google.com. [74.125.140.26], dsn=5.0.0, stat=Service unavailable
Mar 15 17:19:43 m1-production sm-mta[16913]: x2FGJgcR016911: to=<info@example.com>, delay=00:00:01, mailer=local, pri=120332, dsn=5.1.1, stat=User unknown
Mar 15 17:19:43 m1-production sm-mta[16913]: x2FGJgcR016911: to=postmaster, delay=00:00:01, mailer=local, pri=120332, dsn=5.1.1, stat=User unknown
Mar 15 17:19:43 m1-production sm-mta[16913]: x2FGJgcR016911: x2FGJhcR016913: postmaster notify: User unknown

Update 2
The logs as interpreted by @MichaelHampton show a double bounce. Here are the additional lines related to the second bounce:

Mar 15 17:19:43 m1-production sm-mta[16913]: x2FGJhcR016913: to=MAILER-DAEMON, delay=00:00:00, mailer=local, pri=0, dsn=5.1.1, stat=User unknown
Mar 15 17:19:43 m1-production sm-mta[16913]: x2FGJhcR016913: to=postmaster, delay=00:00:00, mailer=local, pri=0, dsn=5.1.1, stat=User unknown
Mar 15 17:19:43 m1-production sm-mta[16913]: x2FGJhcR016913: x2FGJhcS016913: return to sender: User unknown
Mar 15 17:19:43 m1-production sm-mta[16913]: x2FGJhcS016913: to=MAILER-DAEMON, delay=00:00:00, mailer=local, pri=0, dsn=5.1.1, stat=User unknown
Mar 15 17:19:43 m1-production sm-mta[16913]: x2FGJhcR016913: Saved message in /var/lib/sendmail/dead.letter
Improve this question
7
  • Please show the relevant mail.log entries. The log from PHPMailer doesn't tell us anything.
    – Michael Hampton
    Mar 17, 2019 at 19:51
  • @MichaelHampton I will locate the logs and add what I find in there. Thanks for the clue!
    – Majid Fouladpour
    Mar 17, 2019 at 19:53
  • Your transcript shows communication with sendmail. You claim your MTA is postfix. You probably have both installed, and right now, sendmail is occupying port 25.
    – anx
    Mar 17, 2019 at 20:15
  • @anx so I should somehow shut down or disable sendmail? Would that cue postfix to step up to being the acting MTA? And do the logs I just added provide more insight as to what the cause is?
    – Majid Fouladpour
    Mar 17, 2019 at 20:19
  • Looks like Google rejected the message. You'll need to read the bounce message to find out why. But the log shows that the bounce also bounced (because info@ is not a known email address to your system). This is a double bounce. So the double bounce has gone to postmaster. Look up the second message ID given in the log entry to find out what happened to that message.
    – Michael Hampton
    Mar 17, 2019 at 20:23

1 Answer 1

Reset to default
2

If you use postfix it is recommended to remove sendmail

sudo apt remove --purge sendmail

or in Red Hat family (CentOS, Fedora etc.)

sudo yum remove sendmail

Eventually if you do not want to remove sendmail, just use this:

sudo systemctl stop sendmail

sudo systemctl disable sendmail

sudo systemctl mask --now sendmail

Option umask and enable and start can revert back the state.

Improve this answer
8
  • I will do that. There seems to be other issues as well as pointed n the comments. All in all, this is progress; thanks!
    – Majid Fouladpour
    Mar 17, 2019 at 20:27
  • Here is what I got. I have a fear of fat-fingering and messing things up. This is the production server. sudo apt remove --purge sendmail Reading package lists... Done Building dependency tree Reading state information... Done Package 'sendmail' is not installed, so not removed The following packages were automatically installed and are no longer required: m4 sendmail-base sendmail-cf sensible-mda Use 'apt-get autoremove' to remove them. 0 upgraded, 0 newly installed, 0 to remove and 266 not upgraded.
    – Majid Fouladpour
    Mar 17, 2019 at 20:30
  • apt-get autoremove as suggested.
    – Sysadmin
    Mar 17, 2019 at 20:50
  • Check what listens on port 25 netstat -tulpn or sudo lsof -PiTCP -sTCP:LISTEN
    – Sysadmin
    Mar 17, 2019 at 21:17
  • sendmail- 1246 root 3u IPv4 13584 0t0 TCP localhost:25 (LISTEN) sendmail- 1246 root 5u IPv4 13585 0t0 TCP localhost:587 (LISTEN) This apparently re-spawns because those two lines persist even after doing sudo service sendmail stop
    – Majid Fouladpour
    Mar 17, 2019 at 21:26

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.