Suddenly test emails failing with DATA END command failed

Running 3.5.3 since last April, but suddenly I’m getting a “Sent test mail to: xxx failed” after a pause (looks like a timeout, SMTP_TIMEOUT is set to 5). Log shows:
“Error sending email to … SMTP Error: data not accepted.SMTP server error: DATA END command failed”
regardless of the setting of the value used for PHPMAILER_SMTP_DEBUG. Interestingly the emails actually do come through OK! Same thing when I actually do a send to a small test group, tho it takes a while – again looks like it’s timing out on each address; and again the emails actually do come thru OK.

Sending email via any other means works without problems and AFAIK nothing’s changed on the server. From the PHPList log I see this error message first started appearing Feb 13 – 12 days ago(!!) – relating to sending system messages. So something happened before.

Any ideas on how to debug this, or work around?

Also I now see that when sending to my small test-group PHPList is convinced it did NOT send the messages, so it goes into a re-try loop, and sends them again, and again, and … I did stop processing, so it’s quit now.

When sending the test email (not a group send), the HTML version of the email comes thru, but not the plain text version (and I still get the test failed message).

@BaliDave Your hosting company might be able to see what is happening. It sounds like something has changed at their end.
Did the SMTP debug show anything useful? Otherwise I don’t think that either phplist or phpmailer can provide any information on the problem.

Where would I find the SMTP debug output? I was expecting it in the phpLIst log, but nothing changed. I tried both setting PHPMAILER_SMTP_DEBUG to 2 and 3 and didn’t see any difference in the log. Should I be looking elsewhere?

I’ll check with our hosting company. I’m on a dedicated server.
Thanks.

@BaliDave The debug is displayed on the same page at the top when you send a test message (not when sending a campaign by processing the queue).

That was where I first looked, but there’s nothing displayed there other than the failed message. Should values of 2 and 3 for PHPMAILER_SMTP_DEBUG be displaying more there? Attached are screenshots of the failed message and the config.php section as displayed under “Config” in the left side bar.

I am checking with my webhost provider.
Thanks

plistconfigdebug

Oops, found the debug info at the very top – sorry.

My webhost provider says nothing’s changed on the server – sigh. Here’s some condensed and mostly sanitized version of the debug info that a test email (testing, not from a group) generates – I threw out the bulk of the email contents. [BTW at my webhost provider’s suggestion, I switched to port 25 and turned of TLS in the config – same results tho.]

Any ideas?

Blockquote
Connection: opening to ourserver.org:25, timeout=5, options=array ()
Connection: opened
SERVER → CLIENT: 220-ourserver.org ESMTP Exim 4.94 #2 Fri, 26 Feb 2021 01:52:21 -0500 220-We do not authorize the use of this system to transport unsolicited, 220 and/or bulk e-mail.
CLIENT → SERVER: EHLO xyz.org
SERVER → CLIENT: 250-ourserver.org Hello xyz.org [99.333.999.204]250-SIZE 52428800250-8BITMIME250-PIPELINING250-X_PIPE_CONNECT250-AUTH PLAIN LOGIN250-STARTTLS250 HELP
CLIENT → SERVER: STARTTLS
SERVER → CLIENT: 220 TLS go ahead
CLIENT → SERVER: EHLO xyz.org
SERVER → CLIENT: 250-ourserver.org Hello xyz.org [99.333.999.204]250-SIZE 52428800250-8BITMIME250-PIPELINING250-X_PIPE_CONNECT250-AUTH PLAIN LOGIN250 HELP
CLIENT → SERVER: AUTH LOGIN
SERVER → CLIENT: 334 VXNlcm5hbWU6
CLIENT → SERVER: bWFpbGRpc3RAdW5kZXJjdXJyZW50Lm9yZw==
SERVER → CLIENT: 334 UGFzc3dvcmQ6
CLIENT → SERVER: bkV3RipAa2dQd0QhI0A=
SERVER → CLIENT: 235 Authentication succeeded
CLIENT → SERVER: MAIL FROM:plmailer@xyz.org
SERVER → CLIENT: 250 OK
CLIENT → SERVER: RCPT TO:user1@xyz.org
SERVER → CLIENT: 250 Accepted
CLIENT → SERVER: DATA
SERVER → CLIENT: 354 Enter message, ending with “.” on a line by itself
CLIENT → SERVER: Received: from unassigned.psychz.net [104.149.68.126] by www.xyz.org with HTTP; Fri, 26 Feb 2021 01:52:21 -0500
CLIENT → SERVER: Date: Fri, 26 Feb 2021 01:52:21 -0500
CLIENT → SERVER: To: user1@xyz.org
CLIENT → SERVER: From: UC by BD maildist@xyz.org
CLIENT → SERVER: Subject: Testing – ignore
CLIENT → SERVER: Message-ID: 1c218c02c122a681b1ffd035ea458440@xyz.org
CLIENT → SERVER: X-phpList-version: 3.5.3
CLIENT → SERVER: X-MessageID: 782
CLIENT → SERVER: X-ListMember: user1@xyz.org
CLIENT → SERVER: Precedence: bulk
CLIENT → SERVER: List-Help: https://www.xyz.org/elist/?p=preferences&uid=15e0a6090025d3cc78ce32a9a9806790
CLIENT → SERVER: List-Unsubscribe: https://www.xyz.org/elist/?p=unsubscribe&uid=15e0a6090025d3cc78ce32a9a9806790&jo=1
CLIENT → SERVER: List-Unsubscribe-Post: List-Unsubscribe=One-Click
CLIENT → SERVER: List-Subscribe: https://www.xyz.org/elist/?p=subscribe
CLIENT → SERVER: List-Owner: mailto:user1@xyz.org
CLIENT → SERVER: MIME-Version: 1.0
CLIENT → SERVER: Content-Type: multipart/alternative;
CLIENT → SERVER: boundary=“b1_1c218c02c122a681b1ffd035ea458440”
CLIENT → SERVER:
CLIENT → SERVER: This is a multi-part message in MIME format.
CLIENT → SERVER:
CLIENT → SERVER: --b1_1c218c02c122a681b1ffd035ea458440
CLIENT → SERVER: Content-Type: text/plain; charset=UTF-8
CLIENT → SERVER: Content-Transfer-Encoding: quoted-printable
CLIENT → SERVER:
CLIENT → SERVER: Just a test
CLIENT → SERVER: ignore it
CLIENT → SERVER:
CLIENT → SERVER:
CLIENT → SERVER:
CLIENT → SERVER:
CLIENT → SERVER: – powered by phpList, www.phplist.com –
CLIENT → SERVER:
CLIENT → SERVER:
CLIENT → SERVER:
CLIENT → SERVER: --b1_1c218c02c122a681b1ffd035ea458440
CLIENT → SERVER: Content-Type: multipart/related;
CLIENT → SERVER: boundary=“b2_1c218c02c122a681b1ffd035ea458440”
CLIENT → SERVER:
CLIENT → SERVER: --b2_1c218c02c122a681b1ffd035ea458440
CLIENT → SERVER: Content-Type: text/html; charset=UTF-8
CLIENT → SERVER: Content-Transfer-Encoding: quoted-printable
CLIENT → SERVER:
CLIENT → SERVER: =0A <meta content=3D"text/html;charset=3DUTF-8" http-equ=
CLIENT → SERVER: iv=3D"Content-Type">=0A <meta content=3D"width=3Ddevice-width"/>=0A =
CLIENT → SERVER:
CLIENT → SERVER:
CLIENT → SERVER: <p align=3D"center" style=3D"padding-top:6px;“><img alt=3D"discarded masks”=
CLIENT → SERVER: height=3D"225" src=3D"https://www.xyz.org/UCnow/images/discarded-=
CLIENT → SERVER: masks-2020.jpg" style=3D"max-width:100%;height:auto;" vspace=3D"10" width=
CLIENT → SERVER: =3D"600" />


CLIENT → SERVER:
CLIENT → SERVER: <p style=3D"font-family:Arial, Helvetica, sans-serif;font-size:14px; paddin=
CLIENT → SERVER: g-top:6px;“><span style=3D"color:#000000; padding-right:2px;”>Why D=


CLIENT → SERVER:
=0A<p class=3D"poweredby" style=3D"text-align:center"><a href=3D"http=
CLIENT → SERVER: s://www.phplist.com/poweredby?utm_content=3DHTML" title=3D"visit the phpLi=
CLIENT → SERVER: st website" ><img src=3D"cid:1c57533e73db16e6ab3a1ced7e3fc347" title=3D"pow=
CLIENT → SERVER: ered by phpList version 3.5.3, © phpList ltd" alt=3D"powered by phpLis=
CLIENT → SERVER: t 3.5.3, © phpList ltd" border=3D"0" />

<img src=3D"https://www=
CLIENT → SERVER: …xyz.org/elist/ut.php?u=3D15e0a6090025d3cc78ce32a9a9806790&m=
CLIENT → SERVER: =3D782" width=3D"1" height=3D"1" border=3D"0" alt=3D"" />
CLIENT → SERVER:
CLIENT → SERVER: --b2_1c218c02c122a681b1ffd035ea458440
CLIENT → SERVER: Content-Type: image/png; name=“powerphplist.png”
CLIENT → SERVER: Content-Transfer-Encoding: base64
CLIENT → SERVER: Content-ID: <1c57533e73db16e6ab3a1ced7e3fc347>
CLIENT → SERVER: Content-Disposition: inline; filename=powerphplist.png
CLIENT → SERVER:
CLIENT → SERVER: iVBORw0KGgoAAAANSUhEUgAAAEsAAAAhCAYAAACRIVbWAAAABHNCSVQICAgIfAhkiAAAAAlwSFlz


CLIENT → SERVER: RK5CYII=
CLIENT → SERVER:
CLIENT → SERVER:
CLIENT → SERVER: --b2_1c218c02c122a681b1ffd035ea458440–
CLIENT → SERVER:
CLIENT → SERVER:
CLIENT → SERVER: --b1_1c218c02c122a681b1ffd035ea458440–
CLIENT → SERVER:
CLIENT → SERVER: .
SERVER → CLIENT:
SMTP ERROR: DATA END command failed:
SMTP Error: data not accepted.
CLIENT → SERVER: QUIT
SERVER → CLIENT: 250 OK id=1lFWz7-0008Rf-Ny
SMTP ERROR: QUIT command failed: 250 OK id=1lFWz7-0008Rf-Ny
Connection: closed

@BaliDave “SMTP Error: data not accepted.” might mean there is something wrong with the content of the email or the headers. Are you using a valid From address and valid bounces address?

Yes, nothing’s changed there for years… And since we get the HTML version of the test email, that seems to indicate all’s OK with those addresses. Any other ways to debug this?

Here’s a sanitized version of the header of the HTML test email that I received, and all seems to look OK:

Blockquote
From - Thu Feb 25 16:18:55 2021
X-Account-Key: account29
X-UIDL: UID415687-1163413335
X-Mozilla-Status: 0001
X-Mozilla-Status2: 00000000
X-Mozilla-Keys:
Return-Path: plmailer@xyz.org
Received: from ourserver.org
by ourserver.org with LMTP
id 6JAaF+ZcN2DnJwAAN0Vm6A
(envelope-from plmailer@xyz.org); Thu, 25 Feb 2021 03:16:38 -0500
Return-path: plmailer@xyz.org
Envelope-to: TestDSESF1@xyz.org
Delivery-date: Thu, 25 Feb 2021 03:16:38 -0500
Received: from [99.333.999.204] (port=47858 helo=xyz.org)
by ourserver.org with esmtpsa (TLS1.2) tls TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256
(Exim 4.94)
(envelope-from plmailer@xyz.org)
id 1lFBoy-0003FO-Vc
for TestDSESF1@xyz.org; Thu, 25 Feb 2021 03:16:29 -0500
Received: from unassigned.psychz.net [104.149.68.119] by www.xyz.org with HTTP; Thu, 25 Feb 2021 03:16:26 -0500
Date: Thu, 25 Feb 2021 03:16:28 -0500
To: TestDSESF1@xyz.org
From: & by BD maildist@xyz.org
Subject: Turtles in Trouble & American Underwater Photography Winner
Message-ID: f1d50afd8ac0dd6bc5097e68efd1d471@xyz.org
X-phpList-version: 3.5.3
X-MessageID: 779
X-ListMember: TestDSESF1@xyz.org
Precedence: bulk
List-Help: https://www.xyz.org/elist/?p=preferences&uid=0cf5e7fbdbaff0146c1a8271550322a5
List-Unsubscribe: https://www.xyz.org/elist/?p=unsubscribe&uid=0cf5e7fbdbaff0146c1a8271550322a5&jo=1
List-Unsubscribe-Post: List-Unsubscribe=One-Click
List-Subscribe: https://www.xyz.org/elist/?p=subscribe
List-Owner: mailto:user1@xyz.org
MIME-Version: 1.0
Content-Type: multipart/alternative;
boundary=“b1_f1d50afd8ac0dd6bc5097e68efd1d471”
X-ScubaDivers-MailScanner-Information: Please contact the ISP for more information
X-ScubaDivers-MailScanner-ID: 1lFBoy-0003FO-Vc
X-ScubaDivers-MailScanner: Found to be clean
X-ScubaDivers-MailScanner-SpamCheck: spam, SpamAssassin (not cached,
score=7.264, required 5, ALL_TRUSTED -1.00, BAYES_99 5.00,
BAYES_999 1.00, HTML_MESSAGE 0.00, KAM_DMARC_NONE 0.25,
KAM_DMARC_STATUS 0.01, KAM_SHORT 0.00, LOTS_OF_MONEY 0.00,
TO_NO_BRKTS_HTML_IMG 2.00, URIBL_BLOCKED 0.00)
X-ScubaDivers-MailScanner-SpamScore: sssssss
X-ScubaDivers-MailScanner-From: plmailer@xyz.org

And the contents of the text part of this testing email was just:

Blockquote
Just a test
ignore it

I just tried sending test emails using other domains on our server (dedicated, not shared) with their own phplist installations. Two out of three failed in the same way, all with diff versions of phpList. Failed ones were running 3.5.2 and 3.2.0 (phplist not used there anymore),. while a 3.5.1 version succeeded (!) Neither the 3.5.2 nor 3.5.1 versions even have a plain text component for the message.

So anyhow I’m not detecting a pattern here – any ideas? I’ll try upgrading at least one of the failed ones to see if that helps.

OK, so I upgraded the 3.5.2 domain-phplist to 3.6.1 to see if that would help. And voila, the test email succeeded, and I received it – no errors.

So then to be sure all’s OK, I try to send a bogus message to a small subscriber list w 3 emails. Via Segment I use the Calculate and it shows all 3 as showing up. I then Finish and Process, and get an All done message, but no indication of anything being sent. Sure enough nothing was sent – not received by my server, no processing report, nothing in the Log of Events, … It’s like there were zero emails on the list. I tried again adding another email, and same thing. SMTP debug set to 3 give me no output when I’m sending to the group, either on that page or in the Log of Events.

Any ideas to further debug? And why is 3.6.1 behaving so differently from 3.5.2?

This part of the smtp debug is showing what is going wrong. phplist uses the phpmailer package to send emails.

phpmailer sends the “end of data” command, a dot character but appears to read an empty response which it treats as failure.
It then sends a QUIT command and reads what looks to be the actual response to the end of data command “250 OK” which is an invalid response to the QUIT command.
I think that you can increase the debug level to get more output. That output can be a bit confusing but might confirm this idea.

phplist now uses phpmailer release 6. Your earlier version of phplist, 3.5.3, would have been using phpmailer 5 by default, so there are code differences.

THanks. Here’s what I get at the end with debug set to 4

Blockquote
CLIENT → SERVER: --b1_5041fd9122cf2cc9995ee96f58bc3304–
CLIENT → SERVER:
CLIENT → SERVER: .
SMTP → get_lines(): $data is “”
SMTP → get_lines(): $str is “”
SMTP → get_lines(): timed-out (5 sec)
SERVER → CLIENT:
SMTP ERROR: DATA END command failed:
SMTP Error: data not accepted.
CLIENT → SERVER: QUIT
SMTP → get_lines(): $data is “”
SMTP → get_lines(): $str is “250 OK id=1lFtHm-000107-7v”
SERVER → CLIENT: 250 OK id=1lFtHm-000107-7v
SMTP ERROR: QUIT command failed: 250 OK id=1lFtHm-000107-7v
Connection: closed

Looks like it’s not picking up the “.” . Maybe a character encoding issue? Or ???

@BaliDave You appear to be using phpmailer release 5 which is not supported now. Upgrading to the latest release of phplist will ensure that you use phpmailer 6 as that is now the default.

The reading of the response appears to be timing-out

SMTP -> get_lines(): timed-out (5 sec)

Did you notice a 5s delay when sending a test message? You could try increasing that timeout value to see whether it makes any difference by adding this to the config.php file

define('SMTP_TIMEOUT', 10);

I have just noticed that the code handling time-outs has been reworked in phpmailer 6 so you should really use that.

A similar problem was reported two years ago. The developers thought that they had fixed it then

OK, great (!), progress! THANKS!: After changing timeout to 10, test email worked (tho much slower than before), and I did manage (still using 3.5.3 & PHPMaile 5 AFAIK) to send to a small group. BUT, it took over a minute to send to a 6 member list (here’s the report):

The following events occured while processing the message queue:

[Sat 27 Feb 2021 04:40] [104.149.68.126] Started
[Sat 27 Feb 2021 04:40] [104.149.68.126] Sending in batches of 10 emails
[Sat 27 Feb 2021 04:40] [104.149.68.126] Processing has started,
[Sat 27 Feb 2021 04:40] [104.149.68.126] One campaign to process.
[Sat 27 Feb 2021 04:40] [104.149.68.126] Please leave this window open.
phpList will process your queue until all messages have been sent. This may
take a while
[Sat 27 Feb 2021 04:40] [104.149.68.126] Report of processing will be sent
by email
[Sat 27 Feb 2021 04:40] [104.149.68.126] Processing campaign 782
[Sat 27 Feb 2021 04:40] [104.149.68.126] Looking for subscribers
[Sat 27 Feb 2021 04:40] [104.149.68.126] Found them: 6 to process
[Sat 27 Feb 2021 04:41] [104.149.68.126] Processed 6 out of 6 subscribers
[Sat 27 Feb 2021 04:41] [104.149.68.126] It took 1 minutes 01 seconds to
send this message
[Sat 27 Feb 2021 04:41] [104.149.68.126] Script stage: 5
[Sat 27 Feb 2021 04:41] [104.149.68.126] 6 messages sent in 70.17 seconds
(307 msgs/hr)

So a few questions:

  1. Any idea why the tmeout allowance has to be so much now? I never had this problem before and our server load is much lower now than before. And no one else is apparently reporting such behavior.
  2. Is this going to be as slow as it looks, or is this just start-up overhead? We have 40k subs we’re ready to send to, and that usually takes about 4-5 hours.
  3. Will going to 3.6.1 with timeout set to 10, and using PHPMAILER6, likely work OK? At least be reasonably fast? I don’t want to move now if it’s going to be very slow.

Anyhow again MANY thanks for working thru this with me (I’ve been getting balder the past 2 days). I’m hoping for some more good news on this.
:slight_smile: :+1: :

@BaliDave Please test this with phpmailer 6. I don’t see why it would be any slower than phpmailer 5, and as I said the timeout processing was changed significantly.

As an alternative, are you able to not use an SMTP server and send through the local mail server instead. You can comment out the line in config.php for PHPMAILERHOST to try that.

@BaliDave Also I noticed that your server is using Exim 4.94

Received: from [99.333.999.204] (port=47858 [helo=xyz.org](http://helo=xyz.org))
by [ourserver.org](http://ourserver.org) with esmtpsa (TLS1.2) tls TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256
(Exim 4.94)

I found a report of a similar problem


You could show that to the hosting company or system admin. The solution appeared to be to revert to Exim 4.93

@duncanc OK, that is making sense now. I reported it to our webhost and will try to get them to roll back to 4.93. And yes, we’re on Centos 7.9. And I’ll upgrade to 3.6.1 in the meantime with timeout set to 10. Hopefully soon I’ll be able to send emails at a reasonable speed. I’ll report back when I get more info and make some progress.

Again many thanks for your great support – nice to see the light now.