Troubleshooting lengthy cron-runs (2 hours, not resource limited, big database)

[RMBLR]

Problem: Cron takes forever, sometimes doesn't complete.

Output from:

php -q /path/to/whmcs/crons/cron.php all -F -vvv

 

WHMCS Automation Task Utility: all
==================================

 Daily Cron Automation Mode

Queuing Tasks
-------------

 Force run any tasks: ignore "in progress" and "is due"
 Task queues ready

Executing Application Queue
---------------------------

  0/34 [░░░░░░░░░░░░░░░░░░░░░░░░░░░░]   0% < 1 sec/< 1 sec 28.0 MiB 
 Currency Exchange Rates
  1/34 [░░░░░░░░░░░░░░░░░░░░░░░░░░░░]   2% < 1 sec/< 1 sec 28.0 MiB 
 Product Pricing Updates
  2/34 [▓░░░░░░░░░░░░░░░░░░░░░░░░░░░]   5% 3 secs/51 secs 28.0 MiB 
 Tenant Usage Metrics
  3/34 [▓▓░░░░░░░░░░░░░░░░░░░░░░░░░░]   8% 52 secs/9 mins 30.0 MiB 
 Invoices
  4/34 [▓▓▓░░░░░░░░░░░░░░░░░░░░░░░░░]  11% 52 secs/7 mins 30.0 MiB 
 Late Fees
  5/34 [▓▓▓▓░░░░░░░░░░░░░░░░░░░░░░░░]  14% 52 secs/5 mins 30.0 MiB 
 Credit Card Charges
  6/34 [▓▓▓▓░░░░░░░░░░░░░░░░░░░░░░░░]  17% 2 mins/12 mins 70.5 MiB 
 Invoice & Overdue Reminders
  7/34 [▓▓▓▓▓░░░░░░░░░░░░░░░░░░░░░░░]  20% 2 mins/10 mins 74.5 MiB 
 Domain Renewal Notices
  8/34 [▓▓▓▓▓▓░░░░░░░░░░░░░░░░░░░░░░]  23% 2 mins/9 mins 74.5 MiB 
 Cancellation Requests
  9/34 [▓▓▓▓▓▓▓░░░░░░░░░░░░░░░░░░░░░]  26% 2 mins/8 mins 74.5 MiB 
 Overdue Suspensions
 10/34 [▓▓▓▓▓▓▓▓░░░░░░░░░░░░░░░░░░░░]  29% 2 mins/8 mins 74.5 MiB 
 Overdue Terminations
 11/34 [▓▓▓▓▓▓▓▓▓░░░░░░░░░░░░░░░░░░░]  32% 2 mins/7 mins 74.5 MiB 
 Fixed Term Terminations
 12/34 [▓▓▓▓▓▓▓▓▓░░░░░░░░░░░░░░░░░░░]  35% 2 mins/6 mins 74.5 MiB 
 Inactive Tickets
 13/34 [▓▓▓▓▓▓▓▓▓▓░░░░░░░░░░░░░░░░░░]  38% 2 mins/6 mins 74.5 MiB 
 Prune Ticket Attachments
 14/34 [▓▓▓▓▓▓▓▓▓▓▓░░░░░░░░░░░░░░░░░]  41% 2 mins/5 mins 74.5 MiB 
 Delayed Affiliate Commissions
 15/34 [▓▓▓▓▓▓▓▓▓▓▓▓░░░░░░░░░░░░░░░░]  44% 2 mins/5 mins 74.5 MiB 
 Affiliate Reports
 16/34 [▓▓▓▓▓▓▓▓▓▓▓▓▓░░░░░░░░░░░░░░░]  47% 2 mins/5 mins 74.5 MiB 
 Process Email Queue
 17/34 [▓▓▓▓▓▓▓▓▓▓▓▓▓▓░░░░░░░░░░░░░░]  50% 2 mins/4 mins 74.5 MiB 
 Email Marketer Rules
 18/34 [▓▓▓▓▓▓▓▓▓▓▓▓▓▓░░░░░░░░░░░░░░]  52% 2 mins/4 mins 74.5 MiB 
 Process Email Campaigns
 19/34 [▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓░░░░░░░░░░░░░]  55% 2 mins/4 mins 74.5 MiB 
 Credit Card Expiry Notices
 20/34 [▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓░░░░░░░░░░░░]  58% 2 mins/4 mins 74.5 MiB 
 SSL Sync
 21/34 [▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓░░░░░░░░░░░]  61% 3 mins/5 mins 74.5 MiB 
 Server Usage Stats
 22/34 [▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓░░░░░░░░░░]  64% 4 mins/7 mins 74.5 MiB 
 Overage Billing Charges
 23/34 [▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓░░░░░░░░░░]  67% 4 mins/7 mins 74.5 MiB 
 Client Status Update
 24/34 [▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓░░░░░░░░░]  70% 4 mins/6 mins 74.5 MiB 
 Domain Expiry
 25/34 [▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓░░░░░░░░]  73% 4 mins/6 mins 74.5 MiB 
 Ticket Escalation Rules
 26/34 [▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓░░░░░░░]  76% 4 mins/6 mins 74.5 MiB 
 Data Retention Pruning
 27/34 [▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓░░░░░░]  79% 4 mins/6 mins 74.5 MiB 
 SSL Certificate Reissues
 28/34 [▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓░░░░░]  82% 4 mins/5 mins 74.5 MiB 
 Update Server Usage
 29/34 [▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓░░░░░]  85% 4 mins/5 mins 74.5 MiB 
 Update Server Meta Data
 30/34 [▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓░░░░]  88% 4 mins/5 mins 74.5 MiB 
 WHMCS Updates
 31/34 [▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓░░░]  91% 4 mins/5 mins 76.5 MiB 
 Run Jobs Queue
 32/34 [▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓░░]  94% 4 mins/5 mins 76.5 MiB 
 Domain Transfer Status Synchronisation
 33/34 [▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓░]  97% 4 mins/5 mins 76.5 MiB 
 Domain Status Synchronisation
 34/34 [▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓] 100% 5 mins/5 mins 76.5 MiB


 Sending Daily Cron Digest email

Executing System Queue
----------------------

 4/4 [▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓] 100%  2 hrs/2 hrs  88.5 MiB

IMAP connection failed: PhpImap\Exceptions\ConnectionException: ["[CLOSED] IMAP connection broken (server response)"] in /path/to/whmcs/modules/addons/abusemanagerpro/includes/phpimap/vendor/php-imap/php-imap/src/PhpImap/Imap.php:712
Stack trace:
#0 /path/to/whmcs/modules/addons/abusemanagerpro/includes/phpimap/vendor/php-imap/php-imap/src/PhpImap/Mailbox.php(1725): PhpImap\Imap::open()
#1 /path/to/whmcs/modules/addons/abusemanagerpro/includes/phpimap/vendor/php-imap/php-imap/src/PhpImap/Mailbox.php(1686): PhpImap\Mailbox->initImapStream()
#2 /path/to/whmcsmodules/addons/abusemanagerpro/includes/phpimap/vendor/php-imap/php-imap/src/PhpImap/Mailbox.php(469): PhpImap\Mailbox->initImapStreamWithRetry()
#3 /path/to/whmcs/modules/addons/abusemanagerpro/includes/phpimap/vendor/php-imap/php-imap/src/PhpImap/Mailbox.php(664): PhpImap\Mailbox->getImapStream()
#4 /path/to/whmcs/public_html/modules/addons/abusemanagerpro/hooks.php(0): PhpImap\Mailbox->searchMailbox()
#5 [internal function]: hook_abusemanagerpro_fetchimap()
#6 /path/to/whmcs/vendor/whmcs/whmcs-foundation/lib/Hook/Manager.php(0): call_user_func()
#7 /path/to/whmcs/vendor/illuminate/support/Facades/Facade.php(261): WHMCS\Hook\Manager->run()
#8 /path/to/whmcs/includes/functions.php(0): Illuminate\Support\Facades\Facade::__callStatic()
#9 /path/to/whmcs/vendor/whmcs/whmcs-foundation/lib/Cron/Console/Command/AbstractCronCommand.php(0): run_hook()
#10 /path/to/whmcs/vendor/whmcs/whmcs-foundation/lib/Cron/Console/Command/AbstractCronCommand.php(0): WHMCS\Cron\Console\Command\AbstractCronCommand->tearDown()
#11 /path/to/whmcs/vendor/symfony/console/Command/Command.php(298): WHMCS\Cron\Console\Command\AbstractCronCommand->execute()
#12 /path/to/whmcs/vendor/symfony/console/Application.php(1028): Symfony\Component\Console\Command\Command->run()
#13 /path/to/whmcs/vendor/symfony/console/Application.php(299): Symfony\Component\Console\Application->doRunCommand()
#14 /path/to/whmcs/vendor/symfony/console/Application.php(171): Symfony\Component\Console\Application->doRun()
#15 /path/to/whmcs/public_html/crons/cron.php(0): Symfony\Component\Console\Application->run()

 

Ok, so line items 0-5 seem easy to fix and I've since corrected that issue. A plugin (Abuse Manager Pro) had some incorrect IMAP details but we're not piping emails in from our abuse inbox anyway so I just disabled that function.

 

Line items 6-15, however, are less obvious to me. I searched for a few of them and couldn't find anything specific.

 

Our database is quite large, at 2GB or so... I do prune and clean it up regularly. Not sure what can really be done there since it needs dumped and backed up each day. I just ran system cleanup and pruned it, as well as optimized it and still:

 

Total Tables: 184 - Total Rows: 1561066 - Total Size: 1907888 KB

 

The box hosting our WHMCS install isn't constrained by resource limits nor are any resource limits being hit, other than 100% CPU utilization of a single CPU core when the database is being dumped but other than that, normal CPU usage (all cores combined) average at about 5-10% usage. Not sure if something can be optimized to make the DB perform better. Hardware wise, it's not an issue.

Some PHP stuff:

PHP 8.1.19 (cli) (built: Jul  6 2023 23:08:27) (NTS)
Copyright (c) The PHP Group
Zend Engine v4.1.19, Copyright (c) Zend Technologies
    with the ionCube PHP Loader v12.0.4, Copyright (c) 2002-2022, by ionCube Ltd.

 

php -ini | grep "memory_limit"
memory_limit => 4096M => 4096M

 

php -ini | grep "max_execution_time"
max_execution_time => 0 => 0

 

Date/Time also match from the server and my WHMCS install (EST)

I have already read:

https://help.whmcs.com/m/automation/l/1277110-resolving-a-cron-invocation-frequency-warning

https://docs.whmcs.com/System_Cleanup

https://help.whmcs.com/m/automation/l/683269-advanced-cron-troubleshooting

 

Any thoughts? Pointers? I'm mainly concerned about the items listed 5-15 in the output of the manual cron run earlier.

Thanks!

[RMBLR]

Seems like the database is still massive after pruning the last six months of emails as well.

tblemails	19504	1598240 KB

Before I pruned them, tblemails was 1597216 KB, so somehow removing the last six months of emails INCREASED the size of the database? Doesn't make sense to me.

 

[Evolve Web Hosting]

I've never used Abuse Manager Pro but when I look at the error message, it seems that the Addon module as a whole may be causing the issue. Lines 6 - 15 is just the stack trace to show where it ultimately fails but it's originally created by Abuse Manager Pro. Is the module updated for your version of WHMCS?

Are you able to disable the module completely and test again? I also wonder what would happen if you backup the database table with the emails and then empty it or atleast prune what you can from it.

This won't fix the error above but it would help the overall cron time to skip certain functions to prevent them from running if you aren't using them. For example, we got rid of the SSL Monitoring so we skip that command and don't run it. https://docs.whmcs.com/Crons