Has anyone experienced this before? The scheduler works no problem, it even runs “Run Scheduled Report Generation Task” and it completes with no error. When I go to scheduled reports, it says “Last Run: Never”
I cannot find any issues in the logs. Where should I look to try to fix this?
Do you have your timezone set correctly in two places?
And what schedule are you using (monthly, advanced, what time, etc)? Can you play with different schedule options and see if any of them works?
I am using identically php.ini for cron job and webserver. My cronjob works like this:
5 * * * * cd /var/www/suitecrm && /usr/bin/php -c /etc/php5/apache2/php.ini -f cron.php 2>&1
I am using daily and set it for 00:00:00 and 12:00:00 and it has been 12 hours and i have not received any report and still it says Last Run: Never
Maybe try temporarily changing that to
5 * * * * cd /var/www/suitecrm && /usr/bin/php -c /etc/php5/apache2/php.ini -f cron.php >suitecrm.log 2>&1To see if you get something more in the logs. Also you could increase your log level in Admin/System settings.
And maybe try different schedules, the difficulty might be with the schedule condition, I don’t know…
Oh of course. I’ll change it now and force cron to run and update as soon as I get more logs.
Adding the line to cron does not print anything so I’m assuming there are no errors or output whatsoever.
The log level in SuiteCRM was INFO, I changed it to DEBUG and am waiting for it to run the scheduled job. It’s currently queued. If I look at past successful Generate Scheduled Report Logs, there is very little info. I see it running the query for my scheduled report but nothing happens. Here are the logs for the last successful run on log level INFO
Fri May 26 19:15:02 2017 [14285][1][INFO] Query:UPDATE job_queue
SET assigned_user_id=‘1’,name=‘Run Report Generation Scheduled Tasks’,date_modified=‘2017-05-26 19:15:02’,scheduler_id=‘571061fd-6a6b-eb15-bda8-592748185c4d’,execute_time=‘2017-05-26 19:05:00’,status=‘running’,resolution=‘queued’,message=NULL,target=‘function::aorRunScheduledReports’,data=NULL,requeue=0,retry_count=NULL,failure_count=NULL,job_delay=0,client=‘CRONd2b5328519df7a0599fc4d366a09be41:14285’,percent_complete=NULL
Fri May 26 19:15:02 2017 [14285][1][INFO] Query Execution Time:0.0022068023681641
Fri May 26 19:15:02 2017 [14285][1][INFO] Query:SELECT lhs_module, rhs_module FROM relationships WHERE deleted=0 AND (lhs_module = ‘SecurityGroups’ OR rhs_module=‘SecurityGroups’)
Fri May 26 19:15:02 2017 [14285][1][INFO] Query Execution Time:4.4822692871094E-5
Fri May 26 19:15:02 2017 [14285][1][INFO] Query:SELECT id FROM aow_workflow WHERE aow_workflow.flow_module = ‘SchedulersJobs’ 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
Fri May 26 19:15:02 2017 [14285][1][INFO] Query Execution Time:4.1961669921875E-5
Fri May 26 19:15:02 2017 [14285][1][INFO] Custom add jobs here loaded
Fri May 26 19:15:02 2017 [14285][1][INFO] Query:SELECT users.* FROM users WHERE users.id = ‘1’ AND users.deleted=0 LIMIT 0,1
Fri May 26 19:15:02 2017 [14285][1][INFO] Query Execution Time:5.5074691772461E-5
Fri May 26 19:15:02 2017 [14285][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
Fri May 26 19:15:02 2017 [14285][1][INFO] Query Execution Time:4.1961669921875E-5
Fri May 26 19:15:02 2017 [14285][1][INFO] Query:SELECT ea.email_address, ea.email_address_caps, ea.invalid_email, ea.opt_out, ea.date_created, ea.date_modified,
Fri May 26 19:15:02 2017 [14285][1][INFO] Query Execution Time:6.5803527832031E-5
Fri May 26 19:15:02 2017 [14285][1][INFO] Query: SELECT aor_scheduled_reports.* , jt0.user_name modified_by_name , jt0.created_by modified_by_name_owner , ‘Users’ modified_by_name_mod , jt1.user_name created_by_name , jt1.created_by created_by_name_owner , ‘Users’ created_by_name_mod FROM aor_scheduled_reports LEFT JOIN users jt0 ON aor_scheduled_reports.modified_user_id=jt0.id AND jt0.deleted=0
Fri May 26 19:15:02 2017 [14285][1][INFO] Query Execution Time:0.00029301643371582
Fri May 26 19:15:02 2017 [14285][1][INFO] Resolving job df66066c-875d-57c8-5f33-59287ca13da5 as success:
Fri May 26 19:15:02 2017 [14285][1][DEPRECATED] SugarBean.php: preprocess_fields_on_save() is deprecated
Fri May 26 19:15:02 2017 [14285][1][INFO] Query:UPDATE job_queue
SET assigned_user_id=‘1’,name=‘Run Report Generation Scheduled Tasks’,date_modified=‘2017-05-26 19:15:02’,scheduler_id=‘571061fd-6a6b-eb15-bda8-592748185c4d’,execute_time=‘2017-05-26 19:05:00’,status=‘done’,resolution=‘success’,message=NULL,target=‘function::aorRunScheduledReports’,data=NULL,requeue=0,retry_count=NULL,failure_count=NULL,job_delay=0,client=‘CRONd2b5328519df7a0599fc4d366a09be41:14285’,percent_complete=NULL
Maybe check php_errors.log (or whatever your Web server log is called), there could be some clues there…
I got it working. It seemed to have something to do with my cron job running once per hour and the time the reports were scheduled. i traced it in the code to the function that checks if the report is due. For some reason it would never count it is due. Comments in the code for the function isDue() say it should be called every minute and I was calling it once an hour at minute 5. Changing the scheduled report to Advanced with period * * * * * works. Still testing specific times.
Referenced Files:
Ah, I should have spotted that! You have
5 * * * *
which means run at minute 5 every hour, and I was reading it in my mind as if you had
*/5 * * * *
which means run every five minutes!
You should really keep it every minute, or every 2 or 3 minutes. That’s the way it’s designed (and tested) to work…