Slow Send Rate on AWS EC2 Instance

phpList is sending very slowly for some reason. I don’t have any throttle settings in my config.php and in the past, e-mails are sent quite quickly. Below is the message the queue is showing between each e-mail:

It took 10.2256600000 seconds to send

I’m also receiving a bunch of e-mail like this:

The following events occured while processing the message queue: 
[Mon 3 Jul 2023 17:22] [172.56.93.57] This batch will be 998 emails, 
because in the last 30 seconds 2 emails were sent 
[Mon 3 Jul 2023 17:22] [172.56.93.57] select id from phplist_message 
where status not in ("draft", "sent", "prepared", "suspended") and 
embargo <= now() order by entered limit 5 [Mon 3 Jul 2023 17:22] [172.56.93.57] 
User select query select distinct [u.id](http://u.id/) from phplist_listuser 
as listuser inner join phplist_user_user as u ON [u.id](http://u.id/) = listuser.userid inner join phplist_listmessage as listmessage ON listuser.listid = listmessage.listid 
left join phplist_usermessage as um ON (um.messageid = 18 and
um.userid = listuser.userid) where listmessage.messageid = 18 and 
listmessage.listid = listuser.listid and [u.id](http://u.id/) = listuser.userid and um.userid
IS NULL and u.confirmed and !u.blacklisted and !u.disabled 
[Mon 3 Jul 2023 17:22] [172.56.93.57]

Here is a copy of my config.php:

<?php

/*

* ==============================================================================================================
*
*
* The minimum requirements to get phpList working are in this file.
* If you are interested in tweaking more options, check out the config_extended.php file
* or visit http://resources.phplist.com/system/config
*
* ** NOTE: To use options from config_extended.php, you need to copy them to this file **
*
==============================================================================================================

*/
//error logging
define('VERBOSE', true);

// what is your Mysql database server hostname
$database_host = '127.0.0.1:3306';

// what is the name of the database we are using
$database_name = 'bitnami_phplist';

// what user has access to this database
$database_user = '* removed *';

// and what is the password to login to control the database
$database_password = '* removed *';

// if you have an SMTP server, set it here. Otherwise it will use the normal php mail() function
//# if your SMTP server is called "smtp.mydomain.com" you enter this below like this:
//#
//#     define("PHPMAILERHOST",'smtp.mydomain.com');

//define('PHPMAILERHOST', 'localhost');
//define('PHPMAILERPORT',2500);
//define('PHPMAILER_SECURE',false);
define("PHPMAILERHOST",'smtp.sendgrid.net');
$phpmailer_smtpuser = '* removed *';
$phpmailer_smtppassword = '* removed *';
define('PHPMAILERPORT','465');
define('PHPMAILER_SECURE','ssl');


// if TEST is set to 1 (not 0) it will not actually send ANY messages, but display what it would have sent
// this is here, to make sure you edited the config file and mails are not sent "accidentally"
// on unmanaged systems

define('TEST', 0);
/*

==============================================================================================================
*
* Settings for handling bounces
*
* This section is OPTIONAL, and not necessary to send out mailings, but it is highly recommended to correctly
* set up bounce processing. Without processing of bounces your system will end up sending large amounts of
* unnecessary messages, which overloads your own server, the receiving servers and internet traffic as a whole
*
==============================================================================================================

*/

// Message envelope.

// This is the address that most bounces will be delivered to
// Your should make this an address that no PERSON reads
// but a mailbox that phpList can empty every so often, to process the bounces

// $message_envelope = 'listbounces@yourdomain';

// Handling bounces. Check README.bounces for more info
// This can be 'pop' or 'mbox'
$bounce_protocol = 'pop';

// set this to 0, if you set up a cron to download bounces regularly by using the
// commandline option. If this is 0, users cannot run the page from the web
// frontend. Read README.commandline to find out how to set it up on the
// commandline
define('MANUALLY_PROCESS_BOUNCES', 1);

// when the protocol is pop, specify these three
$bounce_mailbox_host = 'localhost';
$bounce_mailbox_user = '* removed *';
$bounce_mailbox_password = '* removed *';

// the "port" is the remote port of the connection to retrieve the emails
// the default should be fine but if it doesn't work, you can try the second
// one. To do that, add a # before the first line and take off the one before the
// second line
$bounce_mailbox_port = '110/pop3/notls';
//$bounce_mailbox_port = "110/pop3";

// it's getting more common to have secure connections, in which case you probably want to use
//$bounce_mailbox_port = "995/pop3/ssl/novalidate-cert";

// when the protocol is mbox specify this one
// it needs to be a local file in mbox format, accessible to your webserver user
$bounce_mailbox = '/var/mail/listbounces';

// set this to 0 if you want to keep your messages in the mailbox. this is potentially
// a problem, because bounces will be counted multiple times, so only do this if you are
// testing things.
$bounce_mailbox_purge = 1;

// set this to 0 if you want to keep unprocessed messages in the mailbox. Unprocessed
// messages are messages that could not be matched with a user in the system
// messages are still downloaded into phpList, so it is safe to delete them from
// the mailbox and view them in phpList
$bounce_mailbox_purge_unprocessed = 1;

// how many bounces in a row need to have occurred for a user to be marked unconfirmed
$bounce_unsubscribe_threshold = 5;

// choose the hash method for password
// check the extended config for more info
// in most cases, it is fine to leave this as it is
define('HASH_ALGO', 'sha256');
$pageroot = '/';
// SMTP settings
// $phpmailer_smtpuser = '';
// $phpmailer_smtppassword = '';
// define('PHPMAILERPORT', '25');
// define('PHPMAILER_SECURE', '');

@daflores63 Look on the event log page. Because you have enabled VERBOSE you should be able to see which part of the processing is taking the long time.

I see this set of events over and over (I have replaced the actual email addresses with xxxxxxxxxxxxxx)

69885	3 July 2023 20:28:45	Finished this run
Page: pageaction
  
69884	3 July 2023 20:28:45	6 messages sent in 61.57 seconds (350 msgs/hr)
Page: pageaction
  
69883	3 July 2023 20:28:45	Processed 6 out of 149 subscribers
Page: pageaction
  
69882	3 July 2023 20:28:45	It took 10.2002210000 seconds to send
Page: pageaction
  
69881	3 July 2023 20:28:34	Sending 18 to xxxxxxxxxxxxxx
Page: pageaction
  
69880	3 July 2023 20:28:34	It took 10.3957670000 seconds to send
Page: pageaction
  
69879	3 July 2023 20:28:24	Sending 18 to xxxxxxxxxxxxxx
Page: pageaction
  
69878	3 July 2023 20:28:24	It took 10.2158770000 seconds to send
Page: pageaction
  
69877	3 July 2023 20:28:14	Sending 18 to xxxxxxxxxxxxxx
Page: pageaction
  
69876	3 July 2023 20:28:14	It took 10.2237690000 seconds to send
Page: pageaction
  
69875	3 July 2023 20:28:04	Sending 18 to xxxxxxxxxxxxxx
Page: pageaction
  
69874	3 July 2023 20:28:04	It took 10.2222030000 seconds to send
Page: pageaction
  
69873	3 July 2023 20:27:53	Sending 18 to xxxxxxxxxxxxxx
Page: pageaction
  
69872	3 July 2023 20:27:53	It took 10.2242710000 seconds to send
Page: pageaction
  
69871	3 July 2023 20:27:43	Sending 18 to xxxxxxxxxxxxxx
Page: pageaction
  
69870	3 July 2023 20:27:43	User select query select distinct u.id from phplist_listuser
as listuser inner join phplist_user_user as u ON u.id = listuser.userid inner
join phplist_listmessage as listmessage ON listuser.listid = listmessage.listid 
left join phplist_usermessage as um ON (um.messageid = 18 and um.userid = 
listuser.userid) where listmessage.messageid = 18 and 
listmessage.listid = listuser.listid and u.id = listuser.userid and um.userid IS NULL 
and u.confirmed and !u.blacklisted and !u.disabled
Page: pageaction
  
69869	3 July 2023 20:27:43	select id from phplist_message where status not 
in ("draft", "sent", "prepared", "suspended") and embargo

Page: pageaction
  
69868	3 July 2023 20:27:43	Maximum time for queue processing: 60
Page: pageaction
  
69867	3 July 2023 20:27:43	Less than batch size were sent, so reloading imminently

@daflores63 The 10s is the time for phplist to build the email then send it. I don’t know whether SendGrid can delay the sending in some way.
Is phplist fetching remote content for the email, such as sending a web page or using a RSS feed?

You could try the SendGrid plugin that uses the SendGrid API to send emails to see whether that is also slow.

@duncanc thanks, that’s a good idea to try the SendGrid API. As for the content, no it’s an HTML e-mail built within phplist using CKeditor and the simple responsive template. Do you think it could be the AWS EC2 instance or something like a memory leak on v3.6.13?

@daflores63 Does sending a test email take a similar time? If you enable SMTP debug then that might show whether it is the SMTP sending taking the time. Add this setting to config.php

define('PHPMAILER_SMTP_DEBUG', 2);

then send a test email on the Compose page. The debug output is then shown at the top of the page.

Judging by the timestamps, it appears instantaneous. Do you see anything concerning? The output was too long so I linked it here… https://drive.google.com/file/d/1kjiqJycXdglTutilKK0a2L4kjT-gAcSa/view?usp=sharing

@daflores63 This doesn’t seem to make sense. The event log lines are reporting the time taken to execute this code in file admin/actions/processqueue.php

if (VERBOSE) {
    processQueueOutput(s('Sending').' '.$messageid.' '.s('to').' '.$useremail);
}
$emailSentTimer = new timer();
++$counters['batch_count'];
$success = sendEmail($messageid, $useremail, $userhash,
    $htmlpref); // $rssitems Obsolete by rssmanager plugin
if (!$success) {
    ++$counters['sendemail returned false total'];
    ++$counters['sendemail returned false'];
} else {
    $counters['sendemail returned false'] = 0;
}
if ($counters['sendemail returned false'] > 10) {
    foreach ($GLOBALS['plugins'] as $pluginname => $plugin) {
        $plugin->processError(s('Warning: a lot of errors while sending campaign %d',
            $messageid));
    }
}

if (VERBOSE) {
    processQueueOutput(s('It took').' '.$emailSentTimer->elapsed(1).' '.s('seconds to send'));
}

There are no delays there, nor in the function which is called, sendEmail()
Check that there hasn’t been a change to the code in that file.

There does not appear to be any changes in the code. I have also changed to the SendGrid API, it’s still taking 10 seconds between e-mails. Do you think it could be AWS is throttling me?

Here is a link to a copy of the production processqueue.php file. https://drive.google.com/file/d/1rsvKAwGq8NdPcR6fxm3kpycy9AXnobFE/view?usp=sharing

@daflores63 It is odd that sending a test email was immediate but processing the queue has a 10s delay for each email for both SMTP and using the API.

If you continue to use the API wilth the SendGrid plugin then you can enable curl logging by modifying this line in file SendGridPlugin.php. It should be line 105

        $this->mailSender = new MailSender($client, false, 1, false, false, true);

to

        $this->mailSender = new MailSender($client, false, 1, false, true, true);

Then the plugin will enable curl verbose output and write that to a file curl.log in the directory identified by the $tmpdir variable in config.php. Not sure exactly what information that shows but might show timings.

Thanks for your continued help. I enabled logging on the SendGrid API plugin but the file create (curl_2023-07-10.log) was empty.

@daflores63 I tried that myself but the curl output wasn’t very useful in trying to understand why this problem is happening.

All I can suggest is adding debug code to phplist to try to see which section is causing the delay of 10s. Would you be able to give me access to your web server to be able to modify some files?

Can we do a screen-sharing session?

@daflores63 First just try changes in these two files to add further output of the time taken

Replace two files in the admin directory and PHPMailer.php in the admin/PHPMailer6/src directory. Then there should be further event log records giving the elapsed time taken to send each email.

smtpSend() took 0.0580760000
send() took 0.0941340000
compatSend() took 0.1001350000

@duncanc I replaced the files and ran a small batch, here is the output to the event log…

## Events

|Events|Date|Message|
| --- | --- | --- |
|76335|11 July 2023 18:37:15|select id from phplist_message where status not in ("draft", "sent", "prepared", "suspended") and embargo|
|Page: pageaction||
|76334|11 July 2023 18:37:15|Maximum time for queue processing: 60|
|Page: pageaction||
|76333|11 July 2023 18:37:14|Less than batch size were sent, so reloading imminently|
|Page: pageaction||
|76332|11 July 2023 18:37:14|send() took 0.0582360000|
|Page: pageaction||
|76331|11 July 2023 18:37:04|Finished this run|
|Page: pageaction||
|76330|11 July 2023 18:37:04|4 messages sent in 60.90 seconds (236 msgs/hr)|
|Page: pageaction||
|76329|11 July 2023 18:37:04|It took 40 seconds to send this message|
|Page: pageaction||
|76328|11 July 2023 18:37:04|send() took 0.0625500000|
|Page: pageaction||
|76327|11 July 2023 18:36:54|Processed 4 out of 4 subscribers|
|Page: pageaction||
|76326|11 July 2023 18:36:54|It took 10.0804070000 seconds to send|
|Page: pageaction||
|76325|11 July 2023 18:36:54|compatSend() took 0.0652830000|
|Page: pageaction||
|76324|11 July 2023 18:36:54|send() took 0.0636800000|
|Page: pageaction||
|76323|11 July 2023 18:36:44|Sending 23 to daflores@rhhaonline.com|
|Page: pageaction||
|76322|11 July 2023 18:36:44|It took 10.0791760000 seconds to send|
|Page: pageaction||
|76321|11 July 2023 18:36:44|compatSend() took 0.0641600000|
|Page: pageaction||
|76320|11 July 2023 18:36:44|send() took 0.0627090000|
|Page: pageaction||
|76319|11 July 2023 18:36:34|Sending 23 to daflores1@yahoo.com|
|Page: pageaction||
|76318|11 July 2023 18:36:34|It took 10.0757340000 seconds to send|
|Page: pageaction||
|76317|11 July 2023 18:36:34|compatSend() took 0.0603810000|
|Page: pageaction||
|76316|11 July 2023 18:36:34|send() took 0.0587000000|
|Page: pageaction||
|76315|11 July 2023 18:36:24|Sending 23 to daflores@dfconsults.com|
|Page: pageaction||
|76314|11 July 2023 18:36:24|It took 10.0888440000 seconds to send|
|Page: pageaction||
|76313|11 July 2023 18:36:24|compatSend() took 0.0591340000|
|Page: pageaction||
|76312|11 July 2023 18:36:24|send() took 0.0576430000|
|Page: pageaction||
|76311|11 July 2023 18:36:14|Sending 23 to daflores63@gmail.com|
|Page: pageaction||
|76310|11 July 2023 18:36:14|Found them: 4 to process|
|Page: pageaction||
|76309|11 July 2023 18:36:14|User select query select distinct u.id from phplist_listuser as listuser inner join phplist_user_user as u ON u.id = listuser.userid inner join phplist_listmessage as listmessage ON listuser.listid = listmessage.listid left join phplist_usermessage as um ON (um.messageid = 23 and um.userid = listuser.userid) where listmessage.messageid = 23 and listmessage.listid = listuser.listid and u.id = listuser.userid and um.userid IS NULL and u.confirmed and !u.blacklisted and !u.disabled|
|Page: pageaction||
|76308|11 July 2023 18:36:14|Looking for subscribers|
|Page: pageaction||
|76307|11 July 2023 18:36:14|Processing campaign 23|
|Page: pageaction||
|76306|11 July 2023 18:36:14|send() took 0.3696900000|
|Page: pageaction||
|76305|11 July 2023 18:36:03|sending of this campaign will stop, if it is still going in 7 days 23 hours 59 mins 57 seconds|
|Page: pageaction||
|76304|11 July 2023 18:36:03|Report of processing will be sent by email|
|Page: pageaction||
|76303|11 July 2023 18:36:03|Please leave this window open. phpList will process your queue until all messages have been sent. This may take a while|
|Page: pageaction||
|76302|11 July 2023 18:36:03|One campaign to process.|
|Page: pageaction||
|76301|11 July 2023 18:36:03|Processing has started,|
|Page: pageaction||
|76300|11 July 2023 18:36:03|select id from phplist_message where status not in ("draft", "sent", "prepared", "suspended") and embargo|
|Page: pageaction||
|76299|11 July 2023 18:36:03|Maximum time for queue processing: 60|
|Page: pageaction||
|76298|11 July 2023 18:36:03|Giving a Unique ID to 1 subscribers, this may take a while|
|Page: pageaction||
|76297|11 July 2023 18:31:25|fetched https://www.phplist.com/downloadnews//3.6.13-en-index.txt status 404|
|Page: home||
|76296|11 July 2023 18:31:25|https://www.phplist.com/downloadnews//3.6.13-en-index.txt fetching with curl|
|Page: home||

@daflores63 Do you have any plugins enabled?

@duncanc I do: CKEditorPlugin, CommonPlugin, Recaptcha Plugin, and SendGridPlugin.

@daflores63 I have modified sendemaillib.php in the zip file. Can you replace that file, then run again?
files.zip (59.7 KB)

Done. Here is the event log output…

pre compatSend() seems to be the culprit, what is that?

|Events|Date|Message|
| --- | --- | --- |
|76386|11 July 2023 21:11:56|select id from phplist_message where status not in ("draft", "sent", "prepared", "suspended") and embargo|
|Page: pageaction||
|76385|11 July 2023 21:11:56|Maximum time for queue processing: 60|
|Page: pageaction||
|76384|11 July 2023 21:11:55|Less than batch size were sent, so reloading imminently|
|Page: pageaction||
|76383|11 July 2023 21:11:55|send() took 0.0472700000|
|Page: pageaction||
|76382|11 July 2023 21:11:45|Finished this run|
|Page: pageaction||
|76381|11 July 2023 21:11:45|4 messages sent in 60.72 seconds (237 msgs/hr)|
|Page: pageaction||
|76380|11 July 2023 21:11:45|It took 40 seconds to send this message|
|Page: pageaction||
|76379|11 July 2023 21:11:45|send() took 0.0477160000|
|Page: pageaction||
|76378|11 July 2023 21:11:35|Processed 4 out of 4 subscribers|
|Page: pageaction||
|76377|11 July 2023 21:11:35|It took 10.0671680000 seconds to send|
|Page: pageaction||
|76376|11 July 2023 21:11:35|post compatSend() took 0.0007820000|
|Page: pageaction||
|76375|11 July 2023 21:11:35|compatSend() took 0.0491740000|
|Page: pageaction||
|76374|11 July 2023 21:11:35|send() took 0.0474210000|
|Page: pageaction||
|76373|11 July 2023 21:11:35|pre compatSend() took 10.0124810000|
|Page: pageaction||
|76372|11 July 2023 21:11:25|Sending 24 to daflores@rhhaonline.com|
|Page: pageaction||
|76371|11 July 2023 21:11:25|It took 10.0686150000 seconds to send|
|Page: pageaction||
|76370|11 July 2023 21:11:25|post compatSend() took 0.0008630000|
|Page: pageaction||
|76369|11 July 2023 21:11:25|compatSend() took 0.0504910000|
|Page: pageaction||
|76368|11 July 2023 21:11:25|send() took 0.0486680000|
|Page: pageaction||
|76367|11 July 2023 21:11:25|pre compatSend() took 10.0126250000|
|Page: pageaction||
|76366|11 July 2023 21:11:15|Sending 24 to daflores1@yahoo.com|
|Page: pageaction||
|76365|11 July 2023 21:11:15|It took 10.0686410000 seconds to send|
|Page: pageaction||
|76364|11 July 2023 21:11:15|post compatSend() took 0.0006470000|
|Page: pageaction||
|76363|11 July 2023 21:11:15|compatSend() took 0.0500440000|
|Page: pageaction||
|76362|11 July 2023 21:11:15|send() took 0.0479160000|
|Page: pageaction||
|76361|11 July 2023 21:11:15|pre compatSend() took 10.0126910000|
|Page: pageaction||
|76360|11 July 2023 21:11:05|Sending 24 to daflores@dfconsults.com|
|Page: pageaction||
|76359|11 July 2023 21:11:05|It took 10.0852550000 seconds to send|
|Page: pageaction||
|76358|11 July 2023 21:11:05|post compatSend() took 0.0007390000|
|Page: pageaction||
|76357|11 July 2023 21:11:05|compatSend() took 0.0503730000|
|Page: pageaction||
|76356|11 July 2023 21:11:05|send() took 0.0484290000|
|Page: pageaction||
|76355|11 July 2023 21:11:05|pre compatSend() took 10.0283230000|
|Page: pageaction||
|76354|11 July 2023 21:10:55|Sending 24 to daflores63@gmail.com|
|Page: pageaction||
|76353|11 July 2023 21:10:55|Found them: 4 to process|
|Page: pageaction||
|76352|11 July 2023 21:10:55|User select query select distinct u.id from phplist_listuser as listuser inner join phplist_user_user as u ON u.id = listuser.userid inner join phplist_listmessage as listmessage ON listuser.listid = listmessage.listid left join phplist_usermessage as um ON (um.messageid = 24 and um.userid = listuser.userid) where listmessage.messageid = 24 and listmessage.listid = listuser.listid and u.id = listuser.userid and um.userid IS NULL and u.confirmed and !u.blacklisted and !u.disabled|
|Page: pageaction||
|76351|11 July 2023 21:10:55|Looking for subscribers|
|Page: pageaction||
|76350|11 July 2023 21:10:55|Processing campaign 24|
|Page: pageaction||
|76349|11 July 2023 21:10:55|send() took 0.2590800000|
|Page: pageaction||
|76348|11 July 2023 21:10:45|sending of this campaign will stop, if it is still going in 7 days 22 hours 49 mins 15 seconds|
|Page: pageaction||
|76347|11 July 2023 21:10:45|Report of processing will be sent by email|
|Page: pageaction||
|76346|11 July 2023 21:10:45|Please leave this window open. phpList will process your queue until all messages have been sent. This may take a while|
|Page: pageaction||
|76345|11 July 2023 21:10:45|One campaign to process.|
|Page: pageaction||
|76344|11 July 2023 21:10:45|Processing has started,|
|Page: pageaction||
|76343|11 July 2023 21:10:45|select id from phplist_message where status not in ("draft", "sent", "prepared", "suspended") and embargo|
|Page: pageaction||
|76342|11 July 2023 21:10:45|Maximum time for queue processing: 60|
|Page: pageaction||

Thanks. This narrows down where the 10s is happening, in function sendEmail() when the email is being constructed. I will take a closer look at that.

@daflores63 I couldn’t see anything obvious so have added a lot more debug statements to the file sendemaillib.php in the zip file
files.zip (59.9 KB)

Also, just to rule it out being the cause, can you disable click tracking?