Cron.php not working unless repair schedulers and then only once

[doahh]

I have tried everything that I can think of including a full re-install of SuiteCRM and the database. I have added the following to the www-data crontab:

*    *    *    *    *     cd /storage/www/suitecrm; php -f cron.php > /dev/null 2>&1

I then setup a marketing campaign with a scheduler email with the emails being correctly added to the queue. I wait until the correct time but the queue is not cleared, the only error that ever appears in the log is:

 Query Failed: SELECT count(*) c FROM emails JOIN emails_text on emails.id = emails_text.email_idWHERE emails.deleted=0 AND emails.type NOT IN ('out', 'draft')
            AND emails.status NOT IN ('sent', 'draft') AND emails.id IN (SELECT eear.email_id FROM emails_email_addr_rel eearJOIN email_addr_bean_rel eabr ON eabr.email_address_id=eear.email_address_id AND eabr.bean_id = '1' AND eabr.bean_module = 'Users' WHERE eear.deleted=0) AND emails.status = 'unread': MySQL error 1064: You have an error in your SQL syntax; check the manual that corresponds to your MySQL server version for the right syntax to use near 'emails.deleted=0 AND emails.type NOT IN ('out', 'draft')
            AND emails.' at line 1
Mon Jun 12 13:34:09 2017 [7227][1][FATAL] emails_email_templates for emails_email_templates failed to load
Mon Jun 12 13:34:09 2017 [7227][1][FATAL] Failed to load relationship emails_email_templates while saving Emails
Mon Jun 12 13:35:50 2017 [4278][1][ERROR] convert: Conversion of 2017-06-12 13:45 13:30 from Y-m-d H:i to Y-m-d H:i:s failed

and I am not sure that is related to this issue. If I then go to:

Admin > Repair > Rebuild Schedulers

the scheduler will fire once and clear the queue. However, if I then try to send another campagin to a new list the scheduler will not fire again. It will only fire once for each repair that I do.

Any ideas?

[pgr]

You are hitting a known bug in version 7.9.

The 7.9.1 bugfix release is due today… it should solve your issue, let us know if the problems persist.

[doahh]

Thanks for the update, unfortunately it didn’t help to resolve the problem.

Using V7.9.1 I found that cron.php would never clear the queue. The suitecrm.log is empty and the sugarcrm.log file contains this directly after running the installation wizard:

Fri Jun 16 14:58:05 2017 [4989][-none-][FATAL]  Query Failed: SELECT id FROM aow_workflow WHERE aow_workflow.flow_module = 'ACLActions' AND aow_workflow.status = 'Active' AND (aow_workflow.run_when = 'Always' OR aow_workflow.run_when = 'On_Save' OR aow_workflow.run_when = 'Create') AND aow_workflow.deleted = 0 : MySQL error 1146: Table 'suitecrm.aow_workflow' doesn't exist
Fri Jun 16 14:58:08 2017 [4989][1][FATAL] ERROR: rmdir_recursive(): argument cache/themes/SuiteP/modules is not a file or a dir.

I then tried to use V7.8.5 and got exactly the same results as above.

Syslog contains:

Jun 16 15:16:01 ip-172-31-24-237 CRON[6840]: (www-data) CMD (cd /storage/www/suitecrm; php -f cron.php > /dev/null 2>&1)

so it looks like cron.php is being called correctly, it just doesn’t seem to do anything. I have checked that the system clock is correctly set.

Any suggestions?

[pgr]

Let’s focus on the 7.8.5 system, if that’s alright with you.

If you can login, navigate to Admin -> Repair and run a Quick Repair & Rebuild. Once this runs, scroll to the bottom of the page and if there are any SQL queries click ‘Execute’.

If the problem persists, please check upgradeWizard.log to see if there were errors installing. I once saw this error of the missing worklfow table, it was caused by the installer not fully completing installation due to php.ini limits (memory_size or max_execution_time).

And just to make sure about cron, can you post the output of this command on the SuiteCRM root directory?

ls -al

This will give me a quick look into your permissions to see how they match that user www-data you’re using for cron.

[doahh]

I ran the repair as you suggested and it went without errors. There were no SQL statements at the bottom to execute.

I did a clean install of V7.8.5 and before doing do I have modified the /etc/php/7.0/apache/php.ini file to use “memory_size = 256” and “max_execution_time = 60”. The sugarcrm.log file contained the same issue as previously mentioned.

I checked that the suitecrm database had the table aow_workflow:

mysql> desc aow_workflow;
+------------------+--------------+------+-----+---------+-------+
| Field            | Type         | Null | Key | Default | Extra |
+------------------+--------------+------+-----+---------+-------+
| id               | char(36)     | NO   | PRI | NULL    |       |
| name             | varchar(255) | YES  |     | NULL    |       |
| date_entered     | datetime     | YES  |     | NULL    |       |
| date_modified    | datetime     | YES  |     | NULL    |       |
| modified_user_id | char(36)     | YES  |     | NULL    |       |
| created_by       | char(36)     | YES  |     | NULL    |       |
| description      | text         | YES  |     | NULL    |       |
| deleted          | tinyint(1)   | YES  |     | 0       |       |
| assigned_user_id | char(36)     | YES  |     | NULL    |       |
| flow_module      | varchar(100) | YES  |     | NULL    |       |
| flow_run_on      | varchar(100) | YES  |     | 0       |       |
| status           | varchar(100) | YES  | MUL | Active  |       |
| run_when         | varchar(100) | YES  |     | Always  |       |
| multiple_runs    | tinyint(1)   | YES  |     | 0       |       |
+------------------+--------------+------+-----+---------+-------+
14 rows in set (0.00 sec)

and then executed the statement that failed:

 SELECT id FROM aow_workflow WHERE aow_workflow.flow_module = 'ACLActions' AND aow_workflow.status = 'Active' AND (aow_workflow.run_when = 'Always' OR aow_workflow.run_when = 'On_Save' OR aow_workflow.run_when = 'Create') AND aow_workflow.deleted = 0;
Empty set (0.00 sec)

All seems OK there albeit returning an empty result set.

the output of ls -al is:

total 1420
drwxr-xr-x  17 www-data www-data   4096 Jun 16 16:39 .
drwxrwxr-x  10 root     www-data   4096 Jun 16 16:32 ..
drwxrwxr-x  15 www-data www-data   4096 Jun 16 16:40 cache
-rwxr-xr-x   1 www-data www-data   3590 Jun 15 11:44 campaign_tracker.php
-rwxr-xr-x   1 www-data www-data    462 Jun 15 11:44 composer.json
-rwxr-xr-x   1 www-data www-data  17908 Jun 15 11:44 composer.lock
-rwxrwxr-x   1 www-data www-data    573 Jun 16 16:41 config_override.php
-rwxr-xr-x   1 www-data www-data  10126 Jun 16 16:39 config.php
-rwxr-xr-x   1 www-data www-data   5052 Jun 15 11:44 cron.php
-rwxr-xr-x   1 www-data www-data   2446 Jun 15 11:44 crossdomain.xml
drwxrwxr-x   8 www-data www-data   4096 Jun 16 16:39 custom
drwxrwxr-x   3 www-data www-data   4096 Jun 15 11:44 data
-rwxr-xr-x   1 www-data www-data   2388 Jun 15 11:44 dictionary.php
-rwxr-xr-x   1 www-data www-data  12541 Jun 15 11:44 download.php
-rwxr-xr-x   1 www-data www-data   2392 Jun 15 11:44 emailmandelivery.php
-rwxr-xr-x   1 www-data www-data   4912 Jun 15 11:44 export.php
-rwxr-xr-x   1 www-data www-data 967627 Jun 15 11:44 files.md5
-rwxr-xr-x   1 www-data www-data   2811 Jun 15 11:44 HandleAjaxCall.php
-rw-r--r--   1 www-data www-data   1373 Jun 16 16:39 .htaccess
-rwxr-xr-x   1 www-data www-data   2371 Jun 15 11:44 ical_server.php
drwxr-xr-x  56 www-data www-data   4096 Jun 15 11:44 include
-rwxr-xr-x   1 www-data www-data   2374 Jun 15 11:44 index.php
drwxr-xr-x   6 www-data www-data   4096 Jun 16 16:39 install
-rw-r--r--   1 www-data www-data  17922 Jun 16 16:39 install.log
-rwxr-xr-x   1 www-data www-data  32077 Jun 15 11:44 install.php
-rwxr-xr-x   1 www-data www-data  13373 Jun 15 11:44 json_server.php
drwxr-xr-x   3 www-data www-data   4096 Jun 15 11:44 jssource
-rwxr-xr-x   1 www-data www-data  34539 Jun 15 11:44 LICENSE.txt
-rwxr-xr-x   1 www-data www-data   2313 Jun 15 11:44 log_file_restricted.html
-rwxr-xr-x   1 www-data www-data   2376 Jun 15 11:44 maintenance.php
drwxr-xr-x   2 www-data www-data   4096 Jun 15 11:44 metadata
drwxr-xr-x   3 www-data www-data   4096 Jun 15 11:44 ModuleInstall
drwxrwxr-x 112 www-data www-data   4096 Jun 15 11:44 modules
-rwxr-xr-x   1 www-data www-data   2890 Jun 15 11:44 pdf.php
-rwxr-xr-x   1 www-data www-data    306 Jun 15 11:44 php_version.php
-rwxr-xr-x   1 www-data www-data   2659 Jun 15 11:44 README.md
-rwxr-xr-x   1 www-data www-data     73 Jun 15 11:44 robots.txt
-rwxr-xr-x   1 www-data www-data   3588 Jun 15 11:44 run_job.php
drwxr-xr-x  11 www-data www-data   4096 Jun 15 11:44 service
drwxr-xr-x   2 www-data www-data   4096 Jun 15 11:44 soap
-rwxr-xr-x   1 www-data www-data   4091 Jun 15 11:44 soap.php
-rw-r--r--   1 www-data www-data 124046 Jun 16 16:39 sugarcrm.log
-rwxr-xr-x   1 www-data www-data   5327 Jun 15 11:44 SugarSecurity.php
-rwxr-xr-x   1 www-data www-data    154 Jun 15 11:44 sugar_version.json
-rwxr-xr-x   1 www-data www-data   2263 Jun 15 11:44 sugar_version.php
-rw-r--r--   1 www-data www-data    705 Jun 16 16:49 suitecrm.log
-rwxr-xr-x   1 www-data www-data    168 Jun 15 11:44 suitecrm_version.php
drwxrwxr-x   6 www-data www-data   4096 Jun 15 11:44 themes
-rwxr-xr-x   1 www-data www-data   5843 Jun 15 11:44 TreeData.php
drwxrwxr-x   2 www-data www-data   4096 Jun 16 16:39 upload
-rwxr-xr-x   1 www-data www-data   2707 Jun 15 11:44 vcal_server.php
-rwxr-xr-x   1 www-data www-data   2980 Jun 15 11:44 vCard.php
drwxr-xr-x   2 www-data www-data   4096 Jun 15 11:44 XTemplate
drwxr-xr-x   8 www-data www-data   4096 Jun 15 11:44 Zend

I did the Quick Repair & Rebuild as you suggested but it didn’t help.

The only addition to the suitecrm.log is:

Fri Jun 16 16:49:44 2017 [17937][1][FATAL] ERROR: rmdir_recursive(): argument cache/themes/SuiteR/modules is not a file or a dir.

The issue still persists and so I would welcome any further suggestions…

[pgr]

Maybe just reset your permissions running these commands from your SuiteCRM directory:

    sudo chown -R www-data:www-data .
    sudo chmod -R 755 .
    sudo chmod -R 775 cache custom modules themes data upload config_override.php 

Also make sure in config.php you have something like this:

  array (
    'dir_mode' => 1517,
    'file_mode' => 420,
    'user' => 'www-data',
    'group' => 'www-data',
  ),

Also try deleting (or make a backup and rename it) the entire cache/themes folder. It will get recreated.

[doahh]

I reset the permissions as suggested.

My config.php file had:

'dir_mode' => 1528,
'file_mode' => 493,
'user' => '',
'group' => '',

I changed it to be the same as your example.

I renamed the cache and themes folders but only the cache folder was re-created and so I put the themes folder back.

Unfortunately, still no success.

[pgr]

I heard that removing the entire cache folder is not good. Put back your older version, and just delete cache/themes. After a Repair it should be there again. At least I tried that a few days ago and it worked well…

I don’t have more ideas for the rest… let me sleep on it…

[pgr]

I just re-read the thread and I realized you still haven’t looked in upgradeWizard.log. I’d really like to check that your upgrade completed successfully.

[doahh]

Thanks for checking back.

I put the cache folder back as you suggested and have jest deleted the cache/themes folder.

I didn’t do an upgrade as I am a first time user of SuiteCRM. I just did a fresh install as it seemed like it was safer and I didn’t have much to lose. Hence there is no upgradeWizard.log file.

[pgr]

Sorry, please check install.log then.

[doahh]

This is the install.log. I’m not ure if the following is a problem:

installerHook: Could not find custom/install/install_hooks.php

Full install.log:

2017-06-16 15:33:52...installerHook: Could not find custom/install/install_hooks.php
2017-06-16 15:33:56...Begin System Check Process *************
2017-06-16 15:33:56...XML Parsing Support Found
2017-06-16 15:33:56...MBString Support Found
2017-06-16 15:33:56...ZIP Support Found
2017-06-16 15:33:56.../custom directory and subdirectory check passed
2017-06-16 15:33:56...cache directory and subdirectory check passed
2017-06-16 15:33:56.../module  directory and subdirectory check passed
2017-06-16 15:33:56.../upload directory check passed
2017-06-16 15:33:56.../zip check passed
2017-06-16 15:33:56...PCRE version check passed
2017-06-16 15:33:56...installerHook: Could not find custom/install/install_hooks.php
2017-06-16 15:33:56...php.ini location found. /etc/php/7.0/apache2/php.ini
2017-06-16 15:33:56...Outputting HTML for System check
2017-06-16 15:33:56...No Errors were found *************
2017-06-16 15:33:56...installerHook: Could not find custom/install/install_hooks.php
2017-06-16 15:37:13...installerHook: Could not find custom/install/install_hooks.php
2017-06-16 15:37:18...installerHook: Could not find custom/install/install_hooks.php
2017-06-16 15:39:18...Begin DB Check Process *************
2017-06-16 15:39:18...testing with mysql:mysqli
2017-06-16 15:39:18...Basic form info is valid, continuing Process.
2017-06-16 15:39:18...Testing user account...
2017-06-16 15:39:18...Connection made using  host: localhost, usr: suitecrm
2017-06-16 15:39:18...SUCCESS:: no errors detected!
2017-06-16 15:39:18...End DB Check Process *************
2017-06-16 15:39:18...installerHook: Could not find custom/install/install_hooks.php
2017-06-16 15:39:18...calling handleSugarConfig()
2017-06-16 15:39:18...calling handleHtaccess()
2017-06-16 15:39:18...calling handleDbCreateDatabase()
2017-06-16 15:39:18...looping through all the Beans and create their tables
2017-06-16 15:39:18...processing table acl_actions
2017-06-16 15:39:18...creating table acl_actions
2017-06-16 15:39:18...creating Relationship Meta for ACLAction
2017-06-16 15:39:18...processing table acl_roles
2017-06-16 15:39:18...creating table acl_roles
2017-06-16 15:39:18...creating Relationship Meta for ACLRole
2017-06-16 15:39:18...processing table relationships
2017-06-16 15:39:18...creating table relationships
2017-06-16 15:39:18...creating Relationship Meta for Relationship
2017-06-16 15:39:18...processing table leads
2017-06-16 15:39:18...creating table leads
2017-06-16 15:39:18...creating Relationship Meta for Lead
2017-06-16 15:39:18...processing table cases
2017-06-16 15:39:18...creating table cases
2017-06-16 15:39:18...creating Relationship Meta for Case
2017-06-16 15:39:18...processing table bugs
2017-06-16 15:39:18...creating table bugs
2017-06-16 15:39:18...creating Relationship Meta for Bug
2017-06-16 15:39:18...processing table users
2017-06-16 15:39:18...creating table users
2017-06-16 15:39:18...creating Relationship Meta for User
2017-06-16 15:39:18...processing table campaign_log
2017-06-16 15:39:18...creating table campaign_log
2017-06-16 15:39:18...creating Relationship Meta for CampaignLog
2017-06-16 15:39:18...processing table project
2017-06-16 15:39:18...creating table project
2017-06-16 15:39:18...creating Relationship Meta for Project
2017-06-16 15:39:18...processing table project_task
2017-06-16 15:39:18...creating table project_task
2017-06-16 15:39:18...creating Relationship Meta for ProjectTask
2017-06-16 15:39:18...processing table campaigns
2017-06-16 15:39:18...creating table campaigns
2017-06-16 15:39:18...creating Relationship Meta for Campaign
2017-06-16 15:39:18...processing table prospect_lists
2017-06-16 15:39:18...creating table prospect_lists
2017-06-16 15:39:18...creating Relationship Meta for ProspectList
2017-06-16 15:39:18...processing table prospects
2017-06-16 15:39:18...creating table prospects
2017-06-16 15:39:18...creating Relationship Meta for Prospect
2017-06-16 15:39:18...processing table email_marketing
2017-06-16 15:39:18...creating table email_marketing
2017-06-16 15:39:18...creating Relationship Meta for EmailMarketing
2017-06-16 15:39:18...processing table campaign_trkrs
2017-06-16 15:39:18...creating table campaign_trkrs
2017-06-16 15:39:18...creating Relationship Meta for CampaignTracker
2017-06-16 15:39:18...processing table releases
2017-06-16 15:39:18...creating table releases
2017-06-16 15:39:18...creating Relationship Meta for Release
2017-06-16 15:39:18...processing table emailman
2017-06-16 15:39:18...creating table emailman
2017-06-16 15:39:18...creating Relationship Meta for EmailMan
2017-06-16 15:39:18...processing table schedulers
2017-06-16 15:39:18...creating table schedulers
2017-06-16 15:39:18...creating Relationship Meta for Scheduler
2017-06-16 15:39:18...processing table job_queue
2017-06-16 15:39:18...creating table job_queue
2017-06-16 15:39:18...creating Relationship Meta for SchedulersJob
2017-06-16 15:39:18...processing table contacts
2017-06-16 15:39:18...creating table contacts
2017-06-16 15:39:18...creating Relationship Meta for Contact
2017-06-16 15:39:18...processing table accounts
2017-06-16 15:39:18...creating table accounts
2017-06-16 15:39:18...creating Relationship Meta for Account
2017-06-16 15:39:18...processing table opportunities
2017-06-16 15:39:19...creating table opportunities
2017-06-16 15:39:19...creating Relationship Meta for Opportunity
2017-06-16 15:39:19...processing table email_templates
2017-06-16 15:39:19...creating table email_templates
2017-06-16 15:39:19...creating Relationship Meta for EmailTemplate
2017-06-16 15:39:19...processing table notes
2017-06-16 15:39:19...creating table notes
2017-06-16 15:39:19...creating Relationship Meta for Note
2017-06-16 15:39:19...processing table calls
2017-06-16 15:39:19...creating table calls
2017-06-16 15:39:19...creating Relationship Meta for Call
2017-06-16 15:39:19...processing table emails
2017-06-16 15:39:19...creating table emails
2017-06-16 15:39:19...creating Relationship Meta for Email
2017-06-16 15:39:19...processing table meetings
2017-06-16 15:39:19...creating table meetings
2017-06-16 15:39:19...creating Relationship Meta for Meeting
2017-06-16 15:39:19...processing table tasks
2017-06-16 15:39:19...creating table tasks
2017-06-16 15:39:19...creating Relationship Meta for Task
2017-06-16 15:39:19...processing table users
2017-06-16 15:39:19...processing table users
2017-06-16 15:39:19...processing table currencies
2017-06-16 15:39:19...creating table currencies
2017-06-16 15:39:19...creating Relationship Meta for Currency
2017-06-16 15:39:19...processing table tracker
2017-06-16 15:39:19...creating table tracker
2017-06-16 15:39:19...creating Relationship Meta for Tracker
2017-06-16 15:39:19...processing table import_maps
2017-06-16 15:39:19...creating table import_maps
2017-06-16 15:39:19...creating Relationship Meta for ImportMap
2017-06-16 15:39:19...processing table users_last_import
2017-06-16 15:39:19...creating table users_last_import
2017-06-16 15:39:19...creating Relationship Meta for UsersLastImport
2017-06-16 15:39:19...processing table config
2017-06-16 15:39:19...creating table config
2017-06-16 15:39:19...creating Relationship Meta for Administration
2017-06-16 15:39:19...processing table upgrade_history
2017-06-16 15:39:19...creating table upgrade_history
2017-06-16 15:39:19...creating Relationship Meta for UpgradeHistory
2017-06-16 15:39:19...processing table vcals
2017-06-16 15:39:19...creating table vcals
2017-06-16 15:39:19...creating Relationship Meta for vCal
2017-06-16 15:39:19...processing table alerts
2017-06-16 15:39:19...creating table alerts
2017-06-16 15:39:19...creating Relationship Meta for Alert
2017-06-16 15:39:19...processing table roles
2017-06-16 15:39:19...creating table roles
2017-06-16 15:39:19...creating Relationship Meta for Role
2017-06-16 15:39:19...processing table documents
2017-06-16 15:39:19...creating table documents
2017-06-16 15:39:19...creating Relationship Meta for Document
2017-06-16 15:39:19...processing table document_revisions
2017-06-16 15:39:19...creating table document_revisions
2017-06-16 15:39:19...creating Relationship Meta for DocumentRevision
2017-06-16 15:39:19...processing table fields_meta_data
2017-06-16 15:39:19...creating table fields_meta_data
2017-06-16 15:39:19...creating Relationship Meta for FieldsMetaData
2017-06-16 15:39:19...processing table inbound_email
2017-06-16 15:39:19...creating table inbound_email
2017-06-16 15:39:19...creating Relationship Meta for InboundEmail
2017-06-16 15:39:19...processing table saved_search
2017-06-16 15:39:19...creating table saved_search
2017-06-16 15:39:19...creating Relationship Meta for SavedSearch
2017-06-16 15:39:19...processing table user_preferences
2017-06-16 15:39:19...creating table user_preferences
2017-06-16 15:39:19...creating Relationship Meta for UserPreference
2017-06-16 15:39:19...processing table
2017-06-16 15:39:19...processing table email_addresses
2017-06-16 15:39:19...creating table email_addresses
2017-06-16 15:39:19...creating Relationship Meta for EmailAddress
2017-06-16 15:39:19...processing table emails_text
2017-06-16 15:39:19...creating table emails_text
2017-06-16 15:39:19...creating Relationship Meta for EmailText
2017-06-16 15:39:19...processing table spots
2017-06-16 15:39:19...creating table spots
2017-06-16 15:39:19...creating Relationship Meta for Spots
2017-06-16 15:39:19...processing table aobh_businesshours
2017-06-16 15:39:19...creating table aobh_businesshours
2017-06-16 15:39:19...creating Relationship Meta for AOBH_BusinessHours
2017-06-16 15:39:19...processing table sugarfeed
2017-06-16 15:39:19...creating table sugarfeed
2017-06-16 15:39:19...creating Relationship Meta for SugarFeed
2017-06-16 15:39:19...processing table eapm
2017-06-16 15:39:19...creating table eapm
2017-06-16 15:39:19...creating Relationship Meta for EAPM
2017-06-16 15:39:19...processing table oauth_consumer
2017-06-16 15:39:19...creating table oauth_consumer
2017-06-16 15:39:19...creating Relationship Meta for OAuthKey
2017-06-16 15:39:19...processing table oauth_tokens
2017-06-16 15:39:19...creating table oauth_tokens
2017-06-16 15:39:19...creating Relationship Meta for OAuthToken
2017-06-16 15:39:19...processing table am_projecttemplates
2017-06-16 15:39:19...creating table am_projecttemplates
2017-06-16 15:39:19...creating Relationship Meta for AM_ProjectTemplates
2017-06-16 15:39:19...processing table am_tasktemplates
2017-06-16 15:39:19...creating table am_tasktemplates
2017-06-16 15:39:19...creating Relationship Meta for AM_TaskTemplates
2017-06-16 15:39:19...processing table favorites
2017-06-16 15:39:19...creating table favorites
2017-06-16 15:39:19...creating Relationship Meta for Favorites
2017-06-16 15:39:19...processing table aok_knowledge_base_categories
2017-06-16 15:39:19...creating table aok_knowledge_base_categories
2017-06-16 15:39:19...creating Relationship Meta for AOK_Knowledge_Base_Categories
2017-06-16 15:39:19...processing table aok_knowledgebase
2017-06-16 15:39:19...creating table aok_knowledgebase
2017-06-16 15:39:19...creating Relationship Meta for AOK_KnowledgeBase
2017-06-16 15:39:19...processing table reminders
2017-06-16 15:39:19...creating table reminders
2017-06-16 15:39:19...creating Relationship Meta for Reminder
2017-06-16 15:39:19...processing table reminders_invitees
2017-06-16 15:39:19...creating table reminders_invitees
2017-06-16 15:39:19...creating Relationship Meta for Reminder_Invitee
2017-06-16 15:39:19...processing table fp_events
2017-06-16 15:39:19...creating table fp_events
2017-06-16 15:39:19...creating Relationship Meta for FP_events
2017-06-16 15:39:19...processing table fp_event_locations
2017-06-16 15:39:19...creating table fp_event_locations
2017-06-16 15:39:19...creating Relationship Meta for FP_Event_Locations
2017-06-16 15:39:19...processing table aod_indexevent
2017-06-16 15:39:19...creating table aod_indexevent
2017-06-16 15:39:19...creating Relationship Meta for AOD_IndexEvent
2017-06-16 15:39:19...processing table aod_index
2017-06-16 15:39:19...creating table aod_index
2017-06-16 15:39:19...creating Relationship Meta for AOD_Index
2017-06-16 15:39:19...processing table aop_case_events
2017-06-16 15:39:19...creating table aop_case_events
2017-06-16 15:39:19...creating Relationship Meta for AOP_Case_Events
2017-06-16 15:39:19...processing table aop_case_updates
2017-06-16 15:39:19...creating table aop_case_updates
2017-06-16 15:39:19...creating Relationship Meta for AOP_Case_Updates
2017-06-16 15:39:19...processing table aor_reports
2017-06-16 15:39:20...creating table aor_reports
2017-06-16 15:39:20...creating Relationship Meta for AOR_Report
2017-06-16 15:39:20...processing table aor_fields
2017-06-16 15:39:20...creating table aor_fields
2017-06-16 15:39:20...creating Relationship Meta for AOR_Field
2017-06-16 15:39:20...processing table aor_charts
2017-06-16 15:39:20...creating table aor_charts
2017-06-16 15:39:20...creating Relationship Meta for AOR_Chart
2017-06-16 15:39:20...processing table aor_conditions
2017-06-16 15:39:20...creating table aor_conditions
2017-06-16 15:39:20...creating Relationship Meta for AOR_Condition
2017-06-16 15:39:20...processing table aor_scheduled_reports
2017-06-16 15:39:20...creating table aor_scheduled_reports
2017-06-16 15:39:20...creating Relationship Meta for AOR_Scheduled_Reports
2017-06-16 15:39:20...processing table aos_contracts
2017-06-16 15:39:20...creating table aos_contracts
2017-06-16 15:39:20...creating Relationship Meta for AOS_Contracts
2017-06-16 15:39:20...processing table aos_invoices
2017-06-16 15:39:20...creating table aos_invoices
2017-06-16 15:39:20...creating Relationship Meta for AOS_Invoices
2017-06-16 15:39:20...processing table aos_pdf_templates
2017-06-16 15:39:20...creating table aos_pdf_templates
2017-06-16 15:39:20...creating Relationship Meta for AOS_PDF_Templates
2017-06-16 15:39:20...processing table aos_product_categories
2017-06-16 15:39:20...creating table aos_product_categories
2017-06-16 15:39:20...creating Relationship Meta for AOS_Product_Categories
2017-06-16 15:39:20...processing table aos_products
2017-06-16 15:39:20...creating table aos_products
2017-06-16 15:39:20...creating Relationship Meta for AOS_Products
2017-06-16 15:39:20...processing table aos_products_quotes
2017-06-16 15:39:20...creating table aos_products_quotes
2017-06-16 15:39:20...creating Relationship Meta for AOS_Products_Quotes
2017-06-16 15:39:20...processing table aos_line_item_groups
2017-06-16 15:39:20...creating table aos_line_item_groups
2017-06-16 15:39:20...creating Relationship Meta for AOS_Line_Item_Groups
2017-06-16 15:39:20...processing table aos_quotes
2017-06-16 15:39:20...creating table aos_quotes
2017-06-16 15:39:20...creating Relationship Meta for AOS_Quotes
2017-06-16 15:39:20...processing table aow_actions
2017-06-16 15:39:20...creating table aow_actions
2017-06-16 15:39:20...creating Relationship Meta for AOW_Action
2017-06-16 15:39:20...processing table aow_workflow
2017-06-16 15:39:20...creating table aow_workflow
2017-06-16 15:39:20...creating Relationship Meta for AOW_WorkFlow
2017-06-16 15:39:20...processing table aow_processed
2017-06-16 15:39:20...creating table aow_processed
2017-06-16 15:39:20...creating Relationship Meta for AOW_Processed
2017-06-16 15:39:20...processing table aow_conditions
2017-06-16 15:39:20...creating table aow_conditions
2017-06-16 15:39:20...creating Relationship Meta for AOW_Condition
2017-06-16 15:39:20...processing table jjwg_maps
2017-06-16 15:39:20...creating table jjwg_maps
2017-06-16 15:39:20...creating Relationship Meta for jjwg_Maps
2017-06-16 15:39:20...processing table jjwg_markers
2017-06-16 15:39:20...creating table jjwg_markers
2017-06-16 15:39:20...creating Relationship Meta for jjwg_Markers
2017-06-16 15:39:20...processing table jjwg_areas
2017-06-16 15:39:20...creating table jjwg_areas
2017-06-16 15:39:20...creating Relationship Meta for jjwg_Areas
2017-06-16 15:39:20...processing table jjwg_address_cache
2017-06-16 15:39:20...creating table jjwg_address_cache
2017-06-16 15:39:20...creating Relationship Meta for jjwg_Address_Cache
2017-06-16 15:39:20...processing table calls_reschedule
2017-06-16 15:39:20...creating table calls_reschedule
2017-06-16 15:39:20...creating Relationship Meta for Calls_Reschedule
2017-06-16 15:39:20...processing table securitygroups
2017-06-16 15:39:20...creating table securitygroups
2017-06-16 15:39:20...creating Relationship Meta for SecurityGroup
2017-06-16 15:39:20...processing table outbound_email
2017-06-16 15:39:20...creating table outbound_email
2017-06-16 15:39:20...creating Relationship Meta for OutboundEmailAccounts
2017-06-16 15:39:20...processing table templatesectionline
2017-06-16 15:39:20...creating table templatesectionline
2017-06-16 15:39:20...creating Relationship Meta for TemplateSectionLine
2017-06-16 15:39:21...Begin creating Defaults
2017-06-16 15:39:21...insert defaults into config table
2017-06-16 15:39:21...Creating default users
2017-06-16 15:39:21...Creating default scheduler jobs
2017-06-16 15:39:21...Enable SugarFeeds
2017-06-16 15:39:21...Installation has completed *********
2017-06-16 15:39:23...populating the db with seed data
2017-06-16 15:39:23...Save configuration settings..
2017-06-16 15:39:23...save locale
2017-06-16 15:39:23...new Administration
2017-06-16 15:39:23...retrieveSettings
2017-06-16 15:39:23...AdminWizard OFF
2017-06-16 15:39:23...saveConfig
2017-06-16 15:39:23...new Configurator
2017-06-16 15:39:23...populateFromPost
2017-06-16 15:39:23...handleOverride
2017-06-16 15:39:23...addCronAllowedUser
2017-06-16 15:39:23...saveConfig
2017-06-16 15:39:23...new Currency
2017-06-16 15:39:23...retrieve
2017-06-16 15:39:23...DBG: save currency
2017-06-16 15:39:23...Save user settings..
2017-06-16 15:39:23...DBG: SugarThemeRegistry::getDefault
2017-06-16 15:39:23...DBG: require modules/Users/Save.php

[pgr]

Is your MySQL database named exactly ‘suitecrm’ ?

Do you still see an error about cache in suitecrm.log?

If you increase the log level to DEBUG, can you get extra clues about what’s wrong with cron?

[doahh]

Yes, the database is named suitecrm.

After upping the level to debug the SuiteCRM log (attached) contains the following after a call to cron (but no necessarily related to cron):

Fri Jun 16 16:39:54 2017 [16982][1][b][FATAL] SugarPHPMailer encountered an error: An outgoing mail server is not configured to send emails. Please configure an outgoing mail server or select an outgoing mail server for the mail account that you are using in Settings >> Mail Account.[/b]
Fri Jun 16 16:39:54 2017 [16982][1][FATAL] SugarPHPMailer encountered an error: SMTP connect() failed. https://github.com/PHPMailer/PHPMailer/wiki/Troubleshooting
Fri Jun 16 16:49:44 2017 [17937][1][[b]FATAL] ERROR: rmdir_recursive(): argument cache/themes/SuiteR/modules is not a file or a dir.[/b]
Fri Jun 16 16:49:44 2017 [17937][1][FATAL] ERROR: rmdir_recursive(): argument cache/themes/Suite7/modules is not a file or a dir.
Sun Jun 18 12:03:02 2017 [26236][1][b][DEBUG] SugarBean.load_relationships, Error Loading relationship (assigned_user_id)[/b]
Sun Jun 18 12:03:02 2017 [26236][1][INFO] Query:UPDATE job_queue
                                        SET `assigned_user_id`='1',`name`='Process Workflow Tasks',`date_modified`='2017-06-18 11:03:02',`scheduler_id`='53c5567e-1136-3de0-d39b-5943fb40c924',`execute_time`='2017-06-18 11:03:00',`status`='done',`resolution`='success',`message`='Warning [2]:[b] Invalid argument supplied for foreach() in /storage/www/suitecrm/modules/AOW_WorkFlow/AOW_WorkFlow.php on line 124\n',`target`='function::processAOW_Workflow',`data`=NULL,`requeue`=0,`retry_count`=NULL,`failure_count`=NULL,`job_delay`=0,`client`='CRON14b87127b43138534880f2310a66c966:26236',`percent_complete`=NULL
                                         WHERE  job_queue.id = '14bd91ef-4a4b-d4f5-dcfa-59465d6970cc' AND deleted=0[/b]
Sun Jun 18 12:03:02 2017 [26236][1][b][DEBUG] SugarBean.load_relationships, Error Loading relationship (aor_scheduled_reports_aor_reports)[/b]

I don’t see any errors about cache.

I could not find a Settings >> Mail Account. to add email configuration into and this error is from a couple of days ago and I assume occurred during the early install. I have email configured in:

Email settings
Inbound email (bounce handler)
Outbound email accounts has a system entry

and the following was found in suitecrm.log regarding schedulers:

Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] --------------------------------------------> at cron.php <--------------------------------------------
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] Using SugarCronJobs as CRON driver
Sun Jun 18 12:03:02 2017 [26236][1][INFO] Query:SELECT id FROM job_queue WHERE status='running' AND date_modified <= '2017-06-17 11:03:02'
Sun Jun 18 12:03:02 2017 [26236][1][INFO] Query Execution Time:0.00024890899658203
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] get_full_list:  order_by = '' and where = 'schedulers.status='Active' AND NOT EXISTS(SELECT id FROM job_queue WHERE scheduler_id=schedulers.id AND status!='done')'
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] SugarBean[Scheduler].load_relationships, Loading relationship (created_by_link).
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] SugarBean[Scheduler].load_relationships, Loading relationship (modified_user_link).
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list_query: query is  SELECT  schedulers.*  , jt0.user_name created_by_name , jt0.created_by created_by_name_owner  , 'Users' created_by_name_mod , jt1.user_name modified_by_name , jt1.created_by modified_by_name_owner  , 'Users' modified_by_name_mod FROM schedulers   LEFT JOIN  users jt0 ON jt0.id=schedulers.created_by AND jt0.deleted=0
 AND jt0.deleted=0  LEFT JOIN  users jt1 ON schedulers.modified_user_id=jt1.id AND jt1.deleted=0

 AND jt1.deleted=0 where (schedulers.status='Active' AND NOT EXISTS(SELECT id FROM job_queue WHERE scheduler_id=schedulers.id AND status!='done')) AND schedulers.deleted=0
Sun Jun 18 12:03:02 2017 [26236][1][INFO] Query: SELECT  schedulers.*  , jt0.user_name created_by_name , jt0.created_by created_by_name_owner  , 'Users' created_by_name_mod , jt1.user_name modified_by_name , jt1.created_by modified_by_name_owner  , 'Users' modified_by_name_mod FROM schedulers   LEFT JOIN  users jt0 ON jt0.id=schedulers.created_by AND jt0.deleted=0
 AND jt0.deleted=0  LEFT JOIN  users jt1 ON schedulers.modified_user_id=jt1.id AND jt1.deleted=0

 AND jt1.deleted=0 where (schedulers.status='Active' AND NOT EXISTS(SELECT id FROM job_queue WHERE scheduler_id=schedulers.id AND status!='done')) AND schedulers.deleted=0
Sun Jun 18 12:03:02 2017 [26236][1][INFO] Query Execution Time:0.00045299530029297
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list_query: result is mysqli_result Object
(
    [current_field] => 0
    [field_count] => 22
    [lengths] => 
    [num_rows] => 12
    [type] => 0
)

Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(53c5567e-1136-3de0-d39b-5943fb40c924): id = 53c5567e-1136-3de0-d39b-5943fb40c924
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(53c5567e-1136-3de0-d39b-5943fb40c924): deleted = 0
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(53c5567e-1136-3de0-d39b-5943fb40c924): date_entered = 2017-06-16 15:39:18
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(53c5567e-1136-3de0-d39b-5943fb40c924): date_modified = 2017-06-16 15:39:18
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(53c5567e-1136-3de0-d39b-5943fb40c924): created_by = 1
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(53c5567e-1136-3de0-d39b-5943fb40c924): created_by_name = gavin
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(53c5567e-1136-3de0-d39b-5943fb40c924): modified_user_id = 1
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(53c5567e-1136-3de0-d39b-5943fb40c924): modified_by_name = gavin
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(53c5567e-1136-3de0-d39b-5943fb40c924): name = Process Workflow Tasks
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(53c5567e-1136-3de0-d39b-5943fb40c924): job = function::processAOW_Workflow
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(53c5567e-1136-3de0-d39b-5943fb40c924): date_time_start = 2015-01-01 13:45:01
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(53c5567e-1136-3de0-d39b-5943fb40c924): job_interval = *::*::*::*::*
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(53c5567e-1136-3de0-d39b-5943fb40c924): last_run = 2017-06-18 11:02:01
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(53c5567e-1136-3de0-d39b-5943fb40c924): status = Active
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(53c5567e-1136-3de0-d39b-5943fb40c924): catch_up = 1
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] Hook called: Schedulers::process_record
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(54831814-aba5-1b4a-2dc6-5943fbfd410a): id = 54831814-aba5-1b4a-2dc6-5943fbfd410a
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(54831814-aba5-1b4a-2dc6-5943fbfd410a): deleted = 0
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(54831814-aba5-1b4a-2dc6-5943fbfd410a): date_entered = 2017-06-16 15:39:18
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(54831814-aba5-1b4a-2dc6-5943fbfd410a): date_modified = 2017-06-16 15:39:18
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(54831814-aba5-1b4a-2dc6-5943fbfd410a): created_by = 1
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(54831814-aba5-1b4a-2dc6-5943fbfd410a): created_by_name = gavin
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(54831814-aba5-1b4a-2dc6-5943fbfd410a): modified_user_id = 1
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(54831814-aba5-1b4a-2dc6-5943fbfd410a): modified_by_name = gavin
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(54831814-aba5-1b4a-2dc6-5943fbfd410a): name = Run Report Generation Scheduled Tasks
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(54831814-aba5-1b4a-2dc6-5943fbfd410a): job = function::aorRunScheduledReports
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(54831814-aba5-1b4a-2dc6-5943fbfd410a): date_time_start = 2015-01-01 10:00:01
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(54831814-aba5-1b4a-2dc6-5943fbfd410a): job_interval = *::*::*::*::*
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(54831814-aba5-1b4a-2dc6-5943fbfd410a): last_run = 2017-06-18 11:02:01
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(54831814-aba5-1b4a-2dc6-5943fbfd410a): status = Active
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(54831814-aba5-1b4a-2dc6-5943fbfd410a): catch_up = 1
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] Hook called: Schedulers::process_record
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(56cead4e-821e-f618-c5a2-5943fb7be418): id = 56cead4e-821e-f618-c5a2-5943fb7be418
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(56cead4e-821e-f618-c5a2-5943fb7be418): deleted = 0
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(56cead4e-821e-f618-c5a2-5943fb7be418): date_entered = 2017-06-16 15:39:18
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(56cead4e-821e-f618-c5a2-5943fb7be418): date_modified = 2017-06-16 15:39:18
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(56cead4e-821e-f618-c5a2-5943fb7be418): created_by = 1
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(56cead4e-821e-f618-c5a2-5943fb7be418): created_by_name = gavin
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(56cead4e-821e-f618-c5a2-5943fb7be418): modified_user_id = 1
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(56cead4e-821e-f618-c5a2-5943fb7be418): modified_by_name = gavin
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(56cead4e-821e-f618-c5a2-5943fb7be418): name = Prune Tracker Tables
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(56cead4e-821e-f618-c5a2-5943fb7be418): job = function::trimTracker
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(56cead4e-821e-f618-c5a2-5943fb7be418): date_time_start = 2015-01-01 12:30:01
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(56cead4e-821e-f618-c5a2-5943fb7be418): job_interval = 0::2::1::*::*
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(56cead4e-821e-f618-c5a2-5943fb7be418): status = Active
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(56cead4e-821e-f618-c5a2-5943fb7be418): catch_up = 1
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] Hook called: Schedulers::process_record
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(578fb2eb-1f72-83cb-2c0b-5943fb3177fa): id = 578fb2eb-1f72-83cb-2c0b-5943fb3177fa
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(578fb2eb-1f72-83cb-2c0b-5943fb3177fa): deleted = 0
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(578fb2eb-1f72-83cb-2c0b-5943fb3177fa): date_entered = 2017-06-16 15:39:18
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(578fb2eb-1f72-83cb-2c0b-5943fb3177fa): date_modified = 2017-06-16 15:39:18
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(578fb2eb-1f72-83cb-2c0b-5943fb3177fa): created_by = 1
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(578fb2eb-1f72-83cb-2c0b-5943fb3177fa): created_by_name = gavin
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(578fb2eb-1f72-83cb-2c0b-5943fb3177fa): modified_user_id = 1
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(578fb2eb-1f72-83cb-2c0b-5943fb3177fa): modified_by_name = gavin
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(578fb2eb-1f72-83cb-2c0b-5943fb3177fa): name = Check Inbound Mailboxes
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(578fb2eb-1f72-83cb-2c0b-5943fb3177fa): job = function::pollMonitoredInboxesAOP
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(578fb2eb-1f72-83cb-2c0b-5943fb3177fa): date_time_start = 2015-01-01 19:00:01
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(578fb2eb-1f72-83cb-2c0b-5943fb3177fa): job_interval = *::*::*::*::*
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(578fb2eb-1f72-83cb-2c0b-5943fb3177fa): last_run = 2017-06-18 11:02:01
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(578fb2eb-1f72-83cb-2c0b-5943fb3177fa): status = Active
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(578fb2eb-1f72-83cb-2c0b-5943fb3177fa): catch_up = 0
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] Hook called: Schedulers::process_record
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5835a9ad-e7d5-d0fa-e22a-5943fbb58962): id = 5835a9ad-e7d5-d0fa-e22a-5943fbb58962
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5835a9ad-e7d5-d0fa-e22a-5943fbb58962): deleted = 0
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5835a9ad-e7d5-d0fa-e22a-5943fbb58962): date_entered = 2017-06-16 15:39:18
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5835a9ad-e7d5-d0fa-e22a-5943fbb58962): date_modified = 2017-06-16 15:39:18
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5835a9ad-e7d5-d0fa-e22a-5943fbb58962): created_by = 1
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5835a9ad-e7d5-d0fa-e22a-5943fbb58962): created_by_name = gavin
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5835a9ad-e7d5-d0fa-e22a-5943fbb58962): modified_user_id = 1
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5835a9ad-e7d5-d0fa-e22a-5943fbb58962): modified_by_name = gavin
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5835a9ad-e7d5-d0fa-e22a-5943fbb58962): name = Run Nightly Process Bounced Campaign Emails
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5835a9ad-e7d5-d0fa-e22a-5943fbb58962): job = function::pollMonitoredInboxesForBouncedCampaignEmails
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5835a9ad-e7d5-d0fa-e22a-5943fbb58962): date_time_start = 2015-01-01 06:00:01
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5835a9ad-e7d5-d0fa-e22a-5943fbb58962): job_interval = 0::2-6::*::*::*
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5835a9ad-e7d5-d0fa-e22a-5943fbb58962): last_run = 2017-06-18 05:00:01
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5835a9ad-e7d5-d0fa-e22a-5943fbb58962): status = Active
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5835a9ad-e7d5-d0fa-e22a-5943fbb58962): catch_up = 1
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] Hook called: Schedulers::process_record
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(58d9f806-6d43-3ff8-04b6-5943fb992118): id = 58d9f806-6d43-3ff8-04b6-5943fb992118
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(58d9f806-6d43-3ff8-04b6-5943fb992118): deleted = 0
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(58d9f806-6d43-3ff8-04b6-5943fb992118): date_entered = 2017-06-16 15:39:18
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(58d9f806-6d43-3ff8-04b6-5943fb992118): date_modified = 2017-06-16 15:39:18
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(58d9f806-6d43-3ff8-04b6-5943fb992118): created_by = 1
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(58d9f806-6d43-3ff8-04b6-5943fb992118): created_by_name = gavin
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(58d9f806-6d43-3ff8-04b6-5943fb992118): modified_user_id = 1
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(58d9f806-6d43-3ff8-04b6-5943fb992118): modified_by_name = gavin
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(58d9f806-6d43-3ff8-04b6-5943fb992118): name = Run Nightly Mass Email Campaigns
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(58d9f806-6d43-3ff8-04b6-5943fb992118): job = function::runMassEmailCampaign
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(58d9f806-6d43-3ff8-04b6-5943fb992118): date_time_start = 2015-01-01 19:30:01
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(58d9f806-6d43-3ff8-04b6-5943fb992118): job_interval = 0::2-6::*::*::*
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(58d9f806-6d43-3ff8-04b6-5943fb992118): last_run = 2017-06-18 05:00:01
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(58d9f806-6d43-3ff8-04b6-5943fb992118): status = Active
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(58d9f806-6d43-3ff8-04b6-5943fb992118): catch_up = 1
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] Hook called: Schedulers::process_record
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(59bdefe0-b740-510e-e290-5943fbe50ae7): id = 59bdefe0-b740-510e-e290-5943fbe50ae7
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(59bdefe0-b740-510e-e290-5943fbe50ae7): deleted = 0
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(59bdefe0-b740-510e-e290-5943fbe50ae7): date_entered = 2017-06-16 15:39:18
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(59bdefe0-b740-510e-e290-5943fbe50ae7): date_modified = 2017-06-16 15:39:18
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(59bdefe0-b740-510e-e290-5943fbe50ae7): created_by = 1
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(59bdefe0-b740-510e-e290-5943fbe50ae7): created_by_name = gavin
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(59bdefe0-b740-510e-e290-5943fbe50ae7): modified_user_id = 1
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(59bdefe0-b740-510e-e290-5943fbe50ae7): modified_by_name = gavin
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(59bdefe0-b740-510e-e290-5943fbe50ae7): name = Perform Lucene Index
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(59bdefe0-b740-510e-e290-5943fbe50ae7): job = function::aodIndexUnindexed
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(59bdefe0-b740-510e-e290-5943fbe50ae7): date_time_start = 2015-01-01 18:00:01
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(59bdefe0-b740-510e-e290-5943fbe50ae7): job_interval = 0::0::*::*::*
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(59bdefe0-b740-510e-e290-5943fbe50ae7): last_run = 2017-06-17 23:00:01
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(59bdefe0-b740-510e-e290-5943fbe50ae7): status = Active
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(59bdefe0-b740-510e-e290-5943fbe50ae7): catch_up = 0
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] Hook called: Schedulers::process_record
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5a0ef5b7-475c-ee0d-48bd-5943fb389890): id = 5a0ef5b7-475c-ee0d-48bd-5943fb389890
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5a0ef5b7-475c-ee0d-48bd-5943fb389890): deleted = 0
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5a0ef5b7-475c-ee0d-48bd-5943fb389890): date_entered = 2017-06-16 15:39:18
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5a0ef5b7-475c-ee0d-48bd-5943fb389890): date_modified = 2017-06-16 15:39:18
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5a0ef5b7-475c-ee0d-48bd-5943fb389890): created_by = 1
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5a0ef5b7-475c-ee0d-48bd-5943fb389890): created_by_name = gavin
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5a0ef5b7-475c-ee0d-48bd-5943fb389890): modified_user_id = 1
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5a0ef5b7-475c-ee0d-48bd-5943fb389890): modified_by_name = gavin
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5a0ef5b7-475c-ee0d-48bd-5943fb389890): name = Optimise AOD Index
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5a0ef5b7-475c-ee0d-48bd-5943fb389890): job = function::aodOptimiseIndex
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5a0ef5b7-475c-ee0d-48bd-5943fb389890): date_time_start = 2015-01-01 09:00:01
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5a0ef5b7-475c-ee0d-48bd-5943fb389890): job_interval = 0::*/3::*::*::*
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5a0ef5b7-475c-ee0d-48bd-5943fb389890): last_run = 2017-06-18 11:00:02
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5a0ef5b7-475c-ee0d-48bd-5943fb389890): status = Active
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5a0ef5b7-475c-ee0d-48bd-5943fb389890): catch_up = 0
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] Hook called: Schedulers::process_record
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5ab6ae31-62b8-0bd9-09fe-5943fbc2c3c0): id = 5ab6ae31-62b8-0bd9-09fe-5943fbc2c3c0
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5ab6ae31-62b8-0bd9-09fe-5943fbc2c3c0): deleted = 0
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5ab6ae31-62b8-0bd9-09fe-5943fbc2c3c0): date_entered = 2017-06-16 15:39:18
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5ab6ae31-62b8-0bd9-09fe-5943fbc2c3c0): date_modified = 2017-06-16 15:39:18
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5ab6ae31-62b8-0bd9-09fe-5943fbc2c3c0): created_by = 1
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5ab6ae31-62b8-0bd9-09fe-5943fbc2c3c0): created_by_name = gavin
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5ab6ae31-62b8-0bd9-09fe-5943fbc2c3c0): modified_user_id = 1
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5ab6ae31-62b8-0bd9-09fe-5943fbc2c3c0): modified_by_name = gavin
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5ab6ae31-62b8-0bd9-09fe-5943fbc2c3c0): name = Run Email Reminder Notifications
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5ab6ae31-62b8-0bd9-09fe-5943fbc2c3c0): job = function::sendEmailReminders
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5ab6ae31-62b8-0bd9-09fe-5943fbc2c3c0): date_time_start = 2015-01-01 17:30:01
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5ab6ae31-62b8-0bd9-09fe-5943fbc2c3c0): job_interval = *::*::*::*::*
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5ab6ae31-62b8-0bd9-09fe-5943fbc2c3c0): last_run = 2017-06-18 11:02:01
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5ab6ae31-62b8-0bd9-09fe-5943fbc2c3c0): status = Active
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5ab6ae31-62b8-0bd9-09fe-5943fbc2c3c0): catch_up = 0
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] Hook called: Schedulers::process_record
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5b02da69-f50c-596f-a51c-5943fbda2a51): id = 5b02da69-f50c-596f-a51c-5943fbda2a51
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5b02da69-f50c-596f-a51c-5943fbda2a51): deleted = 0
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5b02da69-f50c-596f-a51c-5943fbda2a51): date_entered = 2017-06-16 15:39:18
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5b02da69-f50c-596f-a51c-5943fbda2a51): date_modified = 2017-06-16 15:39:18
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5b02da69-f50c-596f-a51c-5943fbda2a51): created_by = 1
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5b02da69-f50c-596f-a51c-5943fbda2a51): created_by_name = gavin
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5b02da69-f50c-596f-a51c-5943fbda2a51): modified_user_id = 1
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5b02da69-f50c-596f-a51c-5943fbda2a51): modified_by_name = gavin
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5b02da69-f50c-596f-a51c-5943fbda2a51): name = Clean Jobs Queue
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5b02da69-f50c-596f-a51c-5943fbda2a51): job = function::cleanJobQueue
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5b02da69-f50c-596f-a51c-5943fbda2a51): date_time_start = 2015-01-01 15:15:01
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5b02da69-f50c-596f-a51c-5943fbda2a51): job_interval = 0::5::*::*::*
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5b02da69-f50c-596f-a51c-5943fbda2a51): last_run = 2017-06-18 04:00:01
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5b02da69-f50c-596f-a51c-5943fbda2a51): status = Active
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5b02da69-f50c-596f-a51c-5943fbda2a51): catch_up = 0
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] Hook called: Schedulers::process_record
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5b96c12c-690d-2a82-48d4-5943fb52b386): id = 5b96c12c-690d-2a82-48d4-5943fb52b386
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5b96c12c-690d-2a82-48d4-5943fb52b386): deleted = 0
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5b96c12c-690d-2a82-48d4-5943fb52b386): date_entered = 2017-06-16 15:39:18
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5b96c12c-690d-2a82-48d4-5943fb52b386): date_modified = 2017-06-16 15:39:18
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5b96c12c-690d-2a82-48d4-5943fb52b386): created_by = 1
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5b96c12c-690d-2a82-48d4-5943fb52b386): created_by_name = gavin
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5b96c12c-690d-2a82-48d4-5943fb52b386): modified_user_id = 1
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5b96c12c-690d-2a82-48d4-5943fb52b386): modified_by_name = gavin
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5b96c12c-690d-2a82-48d4-5943fb52b386): name = Removal of documents from filesystem
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5b96c12c-690d-2a82-48d4-5943fb52b386): job = function::removeDocumentsFromFS
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5b96c12c-690d-2a82-48d4-5943fb52b386): date_time_start = 2015-01-01 13:30:01
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5b96c12c-690d-2a82-48d4-5943fb52b386): job_interval = 0::3::1::*::*
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5b96c12c-690d-2a82-48d4-5943fb52b386): status = Active
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5b96c12c-690d-2a82-48d4-5943fb52b386): catch_up = 0
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] Hook called: Schedulers::process_record
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5beded22-0422-b87f-4d57-5943fb74a86b): id = 5beded22-0422-b87f-4d57-5943fb74a86b
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5beded22-0422-b87f-4d57-5943fb74a86b): deleted = 0
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5beded22-0422-b87f-4d57-5943fb74a86b): date_entered = 2017-06-16 15:39:18
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5beded22-0422-b87f-4d57-5943fb74a86b): date_modified = 2017-06-16 15:39:18
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5beded22-0422-b87f-4d57-5943fb74a86b): created_by = 1
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5beded22-0422-b87f-4d57-5943fb74a86b): created_by_name = gavin
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5beded22-0422-b87f-4d57-5943fb74a86b): modified_user_id = 1
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5beded22-0422-b87f-4d57-5943fb74a86b): modified_by_name = gavin
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5beded22-0422-b87f-4d57-5943fb74a86b): name = Prune SuiteCRM Feed Tables
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5beded22-0422-b87f-4d57-5943fb74a86b): job = function::trimSugarFeeds
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5beded22-0422-b87f-4d57-5943fb74a86b): date_time_start = 2015-01-01 09:30:01
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5beded22-0422-b87f-4d57-5943fb74a86b): job_interval = 0::2::1::*::*
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5beded22-0422-b87f-4d57-5943fb74a86b): status = Active
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] process_full_list: Scheduler(5beded22-0422-b87f-4d57-5943fb74a86b): catch_up = 1
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] Hook called: Schedulers::process_record
Sun Jun 18 12:03:02 2017 [26236][1][INFO] -----> Scheduler found [ 12 ] ACTIVE jobs
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] ----->Schedulers->deriveDBDateTimes() got an object of type: Scheduler
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] ----->got * day
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] ----->got * months
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] ----->got * dates
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] ----->got * hours
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] ----->got * mins
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] Constraints: start: 2015-01-01 13:45:01 from: 1970-01-01 00:00:00 end: 2017-06-19 11:03:03 to: 2017-06-19 11:03:03 now: 2017-06-18 11:03:02
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] ----->Scheduler found valid job (Process Workflow Tasks) for time GMT(2017-06-18 11:03:00)
Sun Jun 18 12:03:02 2017 [26236][1][INFO] Get One: |SELECT id FROM users WHERE id = '1' AND is_admin = 1 AND deleted = 0 AND status = 'Active'|
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] Limit Query:SELECT id FROM users WHERE id = '1' AND is_admin = 1 AND deleted = 0 AND status = 'Active' Start: 0 count: 1
Sun Jun 18 12:03:02 2017 [26236][1][INFO] Query:SELECT id FROM users WHERE id = '1' AND is_admin = 1 AND deleted = 0 AND status = 'Active' LIMIT 0,1
Sun Jun 18 12:03:02 2017 [26236][1][INFO] Query Execution Time:7.1048736572266E-5
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] Hook called: Users::before_retrieve
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] Retrieve User : SELECT users.* FROM users  WHERE users.id = '1' AND users.deleted=0
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] Limit Query:SELECT users.* FROM users  WHERE users.id = '1' AND users.deleted=0 Start: 0 count: 1
Sun Jun 18 12:03:02 2017 [26236][1][INFO] Query:SELECT users.* FROM users  WHERE users.id = '1' AND users.deleted=0 LIMIT 0,1
Sun Jun 18 12:03:02 2017 [26236][1][INFO] Query Execution Time:5.0067901611328E-5
Sun Jun 18 12:03:02 2017 [26236][1][INFO] Query:SELECT u1.first_name, u1.last_name from users  u1, users  u2 where u1.id = u2.reports_to_id AND u2.id = '1' and u1.deleted=0
Sun Jun 18 12:03:02 2017 [26236][1][INFO] Query Execution Time:4.1007995605469E-5
Sun Jun 18 12:03:02 2017 [26236][1][DEBUG] SugarBean[User].load_relationships, Loading relationship (reports_to_link).
Sun Jun 18 12:03:02 2017 [26236][1][INFO] Query:SELECT ea.email_address, ea.email_address_caps, ea.invalid_email, ea.opt_out, ea.date_created, ea.date_modified,
                ear.id, ear.email_address_id, ear.bean_id, ear.bean_module, ear.primary_address, ear.reply_to_address, ear.deleted
                FROM email_addresses ea LEFT JOIN email_addr_bean_rel ear ON ea.id = ear.email_address_id
                WHERE ear.bean_module = 'Users'
                AND ear.bean_id = '1'
                AND ear.deleted = 0
                ORDER BY ear.reply_to_address, ear.primary_address DESC
Sun Jun 18 12:03:02 2017 [26236][1][INFO] Query Execution Time:4.8160552978516E-5

[doahh]

Sorry, I didin’t seem to be able to attach the log file as mentioned previously. The ‘Add file’ button doen’t respond in either Firefox, Chrome or IE.

[pgr]

Yeah, there is something wrong with the “Add file” thing here on these forums (only happens for some people). You can use public services like Pasteboard for screenshots or Pastebin for text.

I’m not seeing any clues in your logs, and I’m running out of ideas…

You said that
Admin > Repair > Rebuild Schedulers
fixes your problem for a single run. Do you get any messages in the logs during that operation, that might indicate exactly what it fixed?

[doahh]

I don’t seem to be able to get it working even for a single run now when attempting to rebuild the schedulers. Maybe that was only working in the 7.9.1 build and not 7.8.5.

For this log file I:

1. Rebuild the schedulers
2. I scheduled the emails to be sent at 16:45pm.
3. Cleared the log file at 16:43pm so that I have only trapped one minute before the scheduled time

I have copied the log file up to:

https://pastebin.com/ZTUxdULP

but the only things that I can see are:

SugarBean.load_relationships, Error Loading relationship (assigned_user_id)
SugarBean.load_relationships, Error Loading relationship (aor_scheduled_reports_aor_reports)

Thanks for the suggestions. I guess it looks like I am approaching the end of what can be looked at.

[pgr]

Those are not really errors, they are “DEBUG” messages so it’s probably nothing important.

If you go into Admin/Email Queue, you can order the campaign to send the emails immediately without depending on any cron jobs. This could be a nice test to see if the actual emails work. You could also get better messages in your logs.

Apart from that, if you are a developer you can tr you to debug the code, stepping through each command until you reach exactly the source of the problem… that’s one of the beauties of open-source, it’s all visible.

[doahh]

I can correctly send emails by using the Admin > Email Queue, it is just cron that is currently a problem.

I’ll see if I can find time sometime to look into debugging the cron.php file but my PHP is remarkably below par so I think I am unlikely to be successful!

Thanks for all the suggestions, much appreciated.

[doahh]

Seems like I have it working, and it is just the (to my mind) odd way that scheduling works. It seems that:

1. crontab entry is needed to trigger the cron.php script. I assume because PHP has no way to start an independent thread;
2. The bundled scheduler Mass nightly email campaign needs to be changed to run at times other than 2-5am. I have set it to run every 15 minutes as that is the divisions that are available when selecting the campaign email time;
3. The campaign send time and the Mass nightly email campaign both need to have passed through their scheduled time (which they now do as they are both on the 15 minute time) or the email won’t be sent.

Hopefully if I send out a large mail campaign that takes longer than 15 minutes I won’t run into problems with two schedulers running at the same time!