Page MenuHomePhabricator

High queue utilization and mails are not being delivered
Closed, WontfixPublic

Assigned To
Authored By
unaiscusat
Jan 7 2015, 3:40 PM
Referenced Files
F263814: phpmailer.png
Jan 8 2015, 7:49 AM
F263417: current.png
Jan 7 2015, 5:36 PM
F263379: phab-daemon.png
Jan 7 2015, 3:40 PM
Subscribers

Description

Hi ,

Our phabricator instance is not delivering mails and its getting queued up

33

2608 Queued for Delivery T1273: Exchange mailing In-box API
22609 Queued for Delivery T1273: Exchange mailing In-box API
22610 Queued for Delivery T1273: Exchange mailing In-box API
22611 Queued for Delivery T838: Access and Sort Issues in Member Listing API
22612 Queued for Delivery T838: Access and Sort Issues in Member Listing API
22613 Queued for Delivery T838: Access and Sort Issues in Member Listing API
22614 Queued for Delivery T838: Access and Sort Issues in Member Listing API
22615 Queued for Delivery T838: Access and Sort Issues in Member Listing API
22616 Queued for Delivery T838: Access and Sort Issues in Member Listing API
22617 Queued for Delivery T806: Post Payment Pop up and Controller
22618 Queued for Delivery T806: Post Payment Pop up and Controller
22619 Queued for Delivery T806: Post Payment Pop up and Controller
22620 Queued for Delivery T806: Post Payment Pop up and Controller
22621 Queued for Delivery T806: Post Payment Pop up and Controller
22622 Queued for Delivery T806: Post Payment Pop up and Controller
22623 Queued for Delivery T806: Post Payment Pop up and Controller
22624 Queued for Delivery T806: Post Payment Pop up and Controller
22625 Queued for Delivery T806: Post Payment Pop up and Controller
22626 Queued for Delivery T806: Post Payment Pop up and Controller

The queue utilization was 450% yesterday and so I launched 8 more PhabricatorTaskmasterDaemon

Now the queue is around 100+ % . However mails are still being queued.

phab-daemon.png (786×1 px, 113 KB)

Event Timeline

unaiscusat assigned this task to epriestley.
unaiscusat raised the priority of this task from to High.
unaiscusat updated the task description. (Show Details)
unaiscusat added a subscriber: unaiscusat.
epriestley raised the priority of this task from High to Needs Triage.Jan 7 2015, 4:14 PM

Can you show me the output of:

phabricator/ $ ./bin/phd log

sure, here is the o/p of phabricator/ $ ./bin/phd log

Daemon 373 STDE [Wed, 07 Jan 2015 22:36:29 +0530] #7 PhabricatorWorkerActiveTask::executeTask() called at [<phabricator>/src/infrastructure/daemon/workers/PhabricatorTaskmasterDaemon.php:19]
Daemon 373 STDE [Wed, 07 Jan 2015 22:36:29 +0530] #8 PhabricatorTaskmasterDaemon::run() called at [<phutil>/src/daemon/PhutilDaemon.php:91]
Daemon 373 STDE [Wed, 07 Jan 2015 22:36:29 +0530] #9 PhutilDaemon::execute() called at [<phutil>/scripts/daemon/exec/exec_daemon.php:111]
Daemon 373 FAIL [Wed, 07 Jan 2015 22:36:29 +0530] (255) Process exited with error 255.
Daemon 373 WAIT [Wed, 07 Jan 2015 22:36:29 +0530] Waiting to restart process.
Daemon 372 STDE [Wed, 07 Jan 2015 22:36:29 +0530] PHP Warning: Module 'memcache' already loaded in Unknown on line 0
Daemon 372 STDE [Wed, 07 Jan 2015 22:36:29 +0530] PHP Warning: Module 'memcached' already loaded in Unknown on line 0
Daemon 369 INIT [Wed, 07 Jan 2015 22:36:29 +0530] Starting process.
Daemon 370 STDE [Wed, 07 Jan 2015 22:36:29 +0530] PHP Warning: Module 'memcache' already loaded in Unknown on line 0
Daemon 370 STDE [Wed, 07 Jan 2015 22:36:29 +0530] PHP Warning: Module 'memcached' already loaded in Unknown on line 0
Daemon 371 STDE [Wed, 07 Jan 2015 22:36:30 +0530] [2015-01-07 22:36:30] EXCEPTION: (PhutilProxyException) Error while executing task ID 54536 from queue. {>} (phpmailerException) SMTP Error: Could not authenticate. at [<phabricator>/externals/phpmailer/class.phpmailer.php:798]
Daemon 371 STDE [Wed, 07 Jan 2015 22:36:30 +0530] #0 PHPMailer::SmtpConnect() called at [<phabricator>/externals/phpmailer/class.phpmailer.php:689]
Daemon 371 STDE [Wed, 07 Jan 2015 22:36:30 +0530] #1 PHPMailer::SmtpSend(string, string) called at [<phabricator>/externals/phpmailer/class.phpmailer.php:576]
Daemon 371 STDE [Wed, 07 Jan 2015 22:36:30 +0530] #2 PHPMailer::Send() called at [<phabricator>/src/applications/metamta/adapter/PhabricatorMailImplementationPHPMailerAdapter.php:118]
Daemon 371 STDE [Wed, 07 Jan 2015 22:36:30 +0530] #3 PhabricatorMailImplementationPHPMailerAdapter::send() called at [<phabricator>/src/applications/metamta/storage/PhabricatorMetaMTAMail.php:674]
Daemon 371 STDE [Wed, 07 Jan 2015 22:36:30 +0530] #4 PhabricatorMetaMTAMail::sendNow() called at [<phabricator>/src/applications/metamta/PhabricatorMetaMTAWorker.php:26]
Daemon 371 STDE [Wed, 07 Jan 2015 22:36:30 +0530] #5 PhabricatorMetaMTAWorker::doWork() called at [<phabricator>/src/infrastructure/daemon/workers/PhabricatorWorker.php:91]
Daemon 371 STDE [Wed, 07 Jan 2015 22:36:30 +0530] #6 PhabricatorWorker::executeTask() called at [<phabricator>/src/infrastructure/daemon/workers/storage/PhabricatorWorkerActiveTask.php:156]
Daemon 371 STDE [Wed, 07 Jan 2015 22:36:30 +0530] #7 PhabricatorWorkerActiveTask::executeTask() called at [<phabricator>/src/infrastructure/daemon/workers/PhabricatorTaskmasterDaemon.php:19]
Daemon 371 STDE [Wed, 07 Jan 2015 22:36:30 +0530] #8 PhabricatorTaskmasterDaemon::run() called at [<phutil>/src/daemon/PhutilDaemon.php:91]
Daemon 371 STDE [Wed, 07 Jan 2015 22:36:30 +0530] #9 PhutilDaemon::execute() called at [<phutil>/scripts/daemon/exec/exec_daemon.php:111]
Daemon 369 STDE [Wed, 07 Jan 2015 22:36:30 +0530] PHP Warning: Module 'memcache' already loaded in Unknown on line 0
Daemon 369 STDE [Wed, 07 Jan 2015 22:36:30 +0530] PHP Warning: Module 'memcached' already loaded in Unknown on line 0
Daemon 371 FAIL [Wed, 07 Jan 2015 22:36:30 +0530] (255) Process exited with error 255.
Daemon 371 WAIT [Wed, 07 Jan 2015 22:36:30 +0530] Waiting to restart process.
Daemon 374 INIT [Wed, 07 Jan 2015 22:36:31 +0530] Starting process.
Daemon 370 STDE [Wed, 07 Jan 2015 22:36:31 +0530] [2015-01-07 22:36:31] EXCEPTION: (PhutilProxyException) Error while executing task ID 54521 from queue. {>} (phpmailerException) SMTP Error: Could not authenticate. at [<phabricator>/externals/phpmailer/class.phpmailer.php:798]

Daemon 370 STDE [Wed, 07 Jan 2015 22:36:31 +0530] #0 PHPMailer::SmtpConnect() called at [<phabricator>/externals/phpmailer/class.phpmailer.php:689]
Daemon 370 STDE [Wed, 07 Jan 2015 22:36:31 +0530] #1 PHPMailer::SmtpSend(string, string) called at [<phabricator>/externals/phpmailer/class.phpmailer.php:576]
Daemon 370 STDE [Wed, 07 Jan 2015 22:36:31 +0530] #2 PHPMailer::Send() called at [<phabricator>/src/applications/metamta/adapter/PhabricatorMailImplementationPHPMailerAdapter.php:118]
Daemon 370 STDE [Wed, 07 Jan 2015 22:36:31 +0530] #3 PhabricatorMailImplementationPHPMailerAdapter::send() called at [<phabricator>/src/applications/metamta/storage/PhabricatorMetaMTAMail.php:674]
Daemon 370 STDE [Wed, 07 Jan 2015 22:36:31 +0530] #4 PhabricatorMetaMTAMail::sendNow() called at [<phabricator>/src/applications/metamta/PhabricatorMetaMTAWorker.php:26]
Daemon 370 STDE [Wed, 07 Jan 2015 22:36:31 +0530] #5 PhabricatorMetaMTAWorker::doWork() called at [<phabricator>/src/infrastructure/daemon/workers/PhabricatorWorker.php:91]
Daemon 370 STDE [Wed, 07 Jan 2015 22:36:31 +0530] #6 PhabricatorWorker::executeTask() called at [<phabricator>/src/infrastructure/daemon/workers/storage/PhabricatorWorkerActiveTask.php:156]
Daemon 370 STDE [Wed, 07 Jan 2015 22:36:31 +0530] #7 PhabricatorWorkerActiveTask::executeTask() called at [<phabricator>/src/infrastructure/daemon/workers/PhabricatorTaskmasterDaemon.php:19]
Daemon 370 STDE [Wed, 07 Jan 2015 22:36:31 +0530] #8 PhabricatorTaskmasterDaemon::run() called at [<phutil>/src/daemon/PhutilDaemon.php:91]
Daemon 370 STDE [Wed, 07 Jan 2015 22:36:31 +0530] #9 PhutilDaemon::execute() called at [<phutil>/scripts/daemon/exec/exec_daemon.php:111]
Daemon 370 FAIL [Wed, 07 Jan 2015 22:36:31 +0530] (255) Process exited with error 255.
Daemon 370 WAIT [Wed, 07 Jan 2015 22:36:31 +0530] Waiting to restart process.
Daemon 374 STDE [Wed, 07 Jan 2015 22:36:32 +0530] PHP Warning: Module 'memcache' already loaded in Unknown on line 0
Daemon 374 STDE [Wed, 07 Jan 2015 22:36:32 +0530] PHP Warning: Module 'memcached' already loaded in Unknown on line 0
Daemon 365 INIT [Wed, 07 Jan 2015 22:36:32 +0530] Starting process.
Daemon 363 STDE [Wed, 07 Jan 2015 22:36:32 +0530] [2015-01-07 22:36:31] PHLOG: 'Unexpected output while updating repository "rEKALOKAM": PHP Warning: Module 'memcache' already loaded in Unknown on line 0
Daemon 363 STDE [Wed, 07 Jan 2015 22:36:32 +0530] PHP Warning: Module 'memcached' already loaded in Unknown on line 0
Daemon 363 STDE [Wed, 07 Jan 2015 22:36:32 +0530] ' at [/var/www/phab/phabricator/src/applications/repository/daemon/PhabricatorRepositoryPullLocalDaemon.php:345]
Daemon 363 STDE [Wed, 07 Jan 2015 22:36:32 +0530] #0 phlog(string) called at [<phabricator>/src/applications/repository/daemon/PhabricatorRepositoryPullLocalDaemon.php:345]
Daemon 363 STDE [Wed, 07 Jan 2015 22:36:32 +0530] #1 PhabricatorRepositoryPullLocalDaemon::resolveUpdateFuture(PhabricatorRepository, ExecFuture, integer) called at [<phabricator>/src/applications/repository/daemon/PhabricatorRepositoryPullLocalDaemon.php:198]
Daemon 363 STDE [Wed, 07 Jan 2015 22:36:32 +0530] #2 PhabricatorRepositoryPullLocalDaemon::run() called at [<phutil>/src/daemon/PhutilDaemon.php:91]
Daemon 363 STDE [Wed, 07 Jan 2015 22:36:32 +0530] #3 PhutilDaemon::execute() called at [<phutil>/scripts/daemon/exec/exec_daemon.php:111]
Daemon 369 STDE [Wed, 07 Jan 2015 22:36:32 +0530] [2015-01-07 22:36:32] EXCEPTION: (PhutilProxyException) Error while executing task ID 54525 from queue. {>} (phpmailerException) SMTP Error: Could not authenticate. at [<phabricator>/externals/phpmailer/class.phpmailer.php:798]
Daemon 369 STDE [Wed, 07 Jan 2015 22:36:32 +0530] #0 PHPMailer::SmtpConnect() called at [<phabricator>/externals/phpmailer/class.phpmailer.php:689]
Daemon 369 STDE [Wed, 07 Jan 2015 22:36:32 +0530] #1 PHPMailer::SmtpSend(string, string) called at [<phabricator>/externals/phpmailer/class.phpmailer.php:576]
Daemon 369 STDE [Wed, 07 Jan 2015 22:36:32 +0530] #2 PHPMailer::Send() called at [<phabricator>/src/applications/metamta/adapter/PhabricatorMailImplementationPHPMailerAdapter.php:118]
Daemon 369 STDE [Wed, 07 Jan 2015 22:36:32 +0530] #3 PhabricatorMailImplementationPHPMailerAdapter::send() called at [<phabricator>/src/applications/metamta/storage/PhabricatorMetaMTAMail.php:674]
Daemon 369 STDE [Wed, 07 Jan 2015 22:36:32 +0530] #4 PhabricatorMetaMTAMail::sendNow() called at [<phabricator>/src/applications/metamta/PhabricatorMetaMTAWorker.php:26]
Daemon 369 STDE [Wed, 07 Jan 2015 22:36:32 +0530] #5 PhabricatorMetaMTAWorker::doWork() called at [<phabricator>/src/infrastructure/daemon/workers/PhabricatorWorker.php:91]
Daemon 369 STDE [Wed, 07 Jan 2015 22:36:32 +0530] #6 PhabricatorWorker::executeTask() called at [<phabricator>/src/infrastructure/daemon/workers/storage/PhabricatorWorkerActiveTask.php:156]
Daemon 369 STDE [Wed, 07 Jan 2015 22:36:32 +0530] #7 PhabricatorWorkerActiveTask::executeTask() called at [<phabricator>/src/infrastructure/daemon/workers/PhabricatorTaskmasterDaemon.php:19]
Daemon 369 STDE [Wed, 07 Jan 2015 22:36:32 +0530] #8 PhabricatorTaskmasterDaemon::run() called at [<phutil>/src/daemon/PhutilDaemon.php:91]
Daemon 369 STDE [Wed, 07 Jan 2015 22:36:32 +0530] #9 PhutilDaemon::execute() called at [<phutil>/scripts/daemon/exec/exec_daemon.php:111]
Daemon 369 FAIL [Wed, 07 Jan 2015 22:36:32 +0530] (255) Process exited with error 255.
Daemon 369 WAIT [Wed, 07 Jan 2015 22:36:32 +0530] Waiting to restart process.
Daemon 365 STDE [Wed, 07 Jan 2015 22:36:33 +0530] PHP Warning: Module 'memcache' already loaded in Unknown on line 0
Daemon 365 STDE [Wed, 07 Jan 2015 22:36:33 +0530] PHP Warning: Module 'memcached' already loaded in Unknown on line 0
Daemon 367 INIT [Wed, 07 Jan 2015 22:36:33 +0530] Starting process.
Daemon 373 INIT [Wed, 07 Jan 2015 22:36:34 +0530] Starting process.
Daemon 367 STDE [Wed, 07 Jan 2015 22:36:34 +0530] PHP Warning: Module 'memcache' already loaded in Unknown on line 0
Daemon 367 STDE [Wed, 07 Jan 2015 22:36:34 +0530] PHP Warning: Module 'memcached' already loaded in Unknown on line 0
Daemon 373 STDE [Wed, 07 Jan 2015 22:36:35 +0530] PHP Warning: Module 'memcache' already loaded in Unknown on line 0
Daemon 373 STDE [Wed, 07 Jan 2015 22:36:35 +0530] PHP Warning: Module 'memcached' already loaded in Unknown on line 0
Daemon 371 INIT [Wed, 07 Jan 2015 22:36:35 +0530] Starting process.
Daemon 363 STDE [Wed, 07 Jan 2015 22:36:35 +0530] [2015-01-07 22:36:35] PHLOG: 'Unexpected output while updating repository "rINNOVA": PHP Warning: Module 'memcache' already loaded in Unknown on line 0
Daemon 363 STDE [Wed, 07 Jan 2015 22:36:35 +0530] PHP Warning: Module 'memcached' already loaded in Unknown on line 0
Daemon 363 STDE [Wed, 07 Jan 2015 22:36:35 +0530] ' at [/var/www/phab/phabricator/src/applications/repository/daemon/PhabricatorRepositoryPullLocalDaemon.php:345]
Daemon 363 STDE [Wed, 07 Jan 2015 22:36:35 +0530] #0 phlog(string) called at [<phabricator>/src/applications/repository/daemon/PhabricatorRepositoryPullLocalDaemon.php:345]
Daemon 363 STDE [Wed, 07 Jan 2015 22:36:35 +0530] #1 PhabricatorRepositoryPullLocalDaemon::resolveUpdateFuture(PhabricatorRepository, ExecFuture, integer) called at [<phabricator>/src/applications/repository/daemon/PhabricatorRepositoryPullLocalDaemon.php:198]
Daemon 363 STDE [Wed, 07 Jan 2015 22:36:35 +0530] #2 PhabricatorRepositoryPullLocalDaemon::run() called at [<phutil>/src/daemon/PhutilDaemon.php:91]
Daemon 363 STDE [Wed, 07 Jan 2015 22:36:35 +0530] #3 PhutilDaemon::execute() called at [<phutil>/scripts/daemon/exec/exec_daemon.php:111]
Daemon 370 INIT [Wed, 07 Jan 2015 22:36:36 +0530] Starting process.
Daemon 371 STDE [Wed, 07 Jan 2015 22:36:36 +0530] PHP Warning: Module 'memcache' already loaded in Unknown on line 0
Daemon 371 STDE [Wed, 07 Jan 2015 22:36:36 +0530] PHP Warning: Module 'memcached' already loaded in Unknown on line 0
Daemon 363 STDE [Wed, 07 Jan 2015 22:36:36 +0530] [2015-01-07 22:36:36] PHLOG: 'Unexpected output while updating repository "rVBP": PHP Warning: Module 'memcache' already loaded in Unknown on line 0
Daemon 363 STDE [Wed, 07 Jan 2015 22:36:36 +0530] PHP Warning: Module 'memcached' already loaded in Unknown on line 0
Daemon 363 STDE [Wed, 07 Jan 2015 22:36:36 +0530] ' at [/var/www/phab/phabricator/src/applications/repository/daemon/PhabricatorRepositoryPullLocalDaemon.php:345]
Daemon 363 STDE [Wed, 07 Jan 2015 22:36:36 +0530] #0 phlog(string) called at [<phabricator>/src/applications/repository/daemon/PhabricatorRepositoryPullLocalDaemon.php:345]
Daemon 363 STDE [Wed, 07 Jan 2015 22:36:36 +0530] #1 PhabricatorRepositoryPullLocalDaemon::resolveUpdateFuture(PhabricatorRepository, ExecFuture, integer) called at [<phabricator>/src/applications/repository/daemon/PhabricatorRepositoryPullLocalDaemon.php:198]
Daemon 363 STDE [Wed, 07 Jan 2015 22:36:36 +0530] #2 PhabricatorRepositoryPullLocalDaemon::run() called at [<phutil>/src/daemon/PhutilDaemon.php:91]
Daemon 363 STDE [Wed, 07 Jan 2015 22:36:36 +0530] #3 PhutilDaemon::execute() called at [<phutil>/scripts/daemon/exec/exec_daemon.php:111]
Daemon 370 STDE [Wed, 07 Jan 2015 22:36:37 +0530] PHP Warning: Module 'memcache' already loaded in Unknown on line 0
Daemon 370 STDE [Wed, 07 Jan 2015 22:36:37 +0530] PHP Warning: Module 'memcached' already loaded in Unknown on line 0
Daemon 363 STDE [Wed, 07 Jan 2015 22:36:37 +0530] [2015-01-07 22:36:36] PHLOG: 'Unexpected output while updating repository "rSOCCERAPP": PHP Warning: Module 'memcache' already loaded in Unknown on line 0
Daemon 363 STDE [Wed, 07 Jan 2015 22:36:37 +0530] PHP Warning: Module 'memcached' already loaded in Unknown on line 0
Daemon 363 STDE [Wed, 07 Jan 2015 22:36:37 +0530] ' at [/var/www/phab/phabricator/src/applications/repository/daemon/PhabricatorRepositoryPullLocalDaemon.php:345]
Daemon 363 STDE [Wed, 07 Jan 2015 22:36:37 +0530] #0 phlog(string) called at [<phabricator>/src/applications/repository/daemon/PhabricatorRepositoryPullLocalDaemon.php:345]
Daemon 363 STDE [Wed, 07 Jan 2015 22:36:37 +0530] #1 PhabricatorRepositoryPullLocalDaemon::resolveUpdateFuture(PhabricatorRepository, ExecFuture, integer) called at [<phabricator>/src/applications/repository/daemon/PhabricatorRepositoryPullLocalDaemon.php:198]
Daemon 363 STDE [Wed, 07 Jan 2015 22:36:37 +0530] #2 PhabricatorRepositoryPullLocalDaemon::run() called at [<phutil>/src/daemon/PhutilDaemon.php:91]
Daemon 363 STDE [Wed, 07 Jan 2015 22:36:37 +0530] #3 PhutilDaemon::execute() called at [<phutil>/scripts/daemon/exec/exec_daemon.php:111]
Daemon 369 INIT [Wed, 07 Jan 2015 22:36:37 +0530] Starting process.
Daemon 369 STDE [Wed, 07 Jan 2015 22:36:38 +0530] PHP Warning: Module 'memcache' already loaded in Unknown on line 0
Daemon 369 STDE [Wed, 07 Jan 2015 22:36:38 +0530] PHP Warning: Module 'memcached' already loaded in Unknown on line 0

Daemon 370 STDE [Wed, 07 Jan 2015 22:36:31 +0530] [2015-01-07 22:36:31] EXCEPTION: (PhutilProxyException) Error while executing task ID 54521 from queue. {>} (phpmailerException) SMTP Error: Could not authenticate. at [<phabricator>/externals/phpmailer/class.phpmailer.php:798]

SMTP is not configured correctly, or you have some other error with your SMTP server.

You have at least one error in your configuration:

phpmailer.smtp-protocol: set to tls or ssl if necessary. Use ssl for Gmail.

https://secure.phabricator.com/book/phabricator/article/configuring_outbound_email/

I have configured it to use SSL over port 465. One mail got delivered yesterday using this configuration.

Here is my current configuration -

current.png (618×1 px, 62 KB)

This is a configuration issue that we can't reproduce.

https://secure.phabricator.com/book/phabcontrib/article/bug_reports/#unreproducible-problems

If you can't get SMTP working, you could try using another mailer as a workaround.

Thanks for your patience.

I have upgraded phabricator to resolve this issue. I have 2 configuration issues then -

  1. Daemons are running as the wrong user
  2. Daemons and Web Have Different Config

I did restarted phd several times and no hope, the set up issues are still there.

Also when open web console of config - phpmailer its showing the following error -

phpmailer.png (326×796 px, 26 KB)

update -

When I ignored these two issues, the issue nr 1 - "Daemons are running as the wrong user" got resolved.

Thanks !!!for this - https://github.com/phacility/phabricator/blob/master/resources/celerity/map.php.

Now there is only one issue after upgradation - The set up issue ;

Daemons and Web Have Different Config (restarted several times)

unaiscusat changed the task status from Resolved to Wontfix.