Cron errors, but what's triggering them?

JulianHarmer · 4 July 2018 17:16

Hi All,

I’m getting 2 main errors on my system, loads of cron errors and a few subpanel errors. I’d like to tackle the cron errors first, as there are so many of them.

Can you suggest which log files I should start looking at. Here’s the main system log, or part of it.

Thanks

Wed Jul 4 17:32:02 2018 [14653][1][FATAL] Job 2aa14dbe-0daa-6ae0-1afa-5b3cf6261779 (Run Report Generation Scheduled Tasks) failed in CRON run
Wed Jul 4 17:33:01 2018 [14658][1][FATAL] Job 6f96fec3-8122-7f0c-f32a-5b3cf6aa8b3e (Run Report Generation Scheduled Tasks) failed in CRON run
Wed Jul 4 17:34:01 2018 [14663][1][FATAL] Job ce481094-6b4c-25d4-4fd0-5b3cf6a6a4ad (Run Report Generation Scheduled Tasks) failed in CRON run
Wed Jul 4 17:35:02 2018 [14668][1][FATAL] Job 25f0c007-af7b-2631-f1b6-5b3cf7c62926 (Run Report Generation Scheduled Tasks) failed in CRON run
Wed Jul 4 17:36:01 2018 [14674][1][FATAL] Job 88947a0e-cd8d-36c7-fe41-5b3cf7831935 (Run Report Generation Scheduled Tasks) failed in CRON run
Wed Jul 4 17:37:02 2018 [14679][1][FATAL] Job cd68aa35-08da-ee57-b5bb-5b3cf7eb6650 (Run Report Generation Scheduled Tasks) failed in CRON run
Wed Jul 4 17:38:01 2018 [14684][1][FATAL] Job 37e3111b-5a87-3cca-f5c4-5b3cf7a0b569 (Run Report Generation Scheduled Tasks) failed in CRON run
Wed Jul 4 17:39:01 2018 [14691][1][FATAL] Job 8c31235c-70e8-1c7d-0c34-5b3cf8adc7a8 (Run Report Generation Scheduled Tasks) failed in CRON run
Wed Jul 4 17:40:02 2018 [14738][1][FATAL] Job ee109535-cba8-27dd-557b-5b3cf8e681d5 (Run Report Generation Scheduled Tasks) failed in CRON run
Wed Jul 4 17:41:01 2018 [14762][1][FATAL] Job 3dcc6b90-d654-446d-f3e9-5b3cf8d2738b (Run Report Generation Scheduled Tasks) failed in CRON run
Wed Jul 4 17:42:02 2018 [14768][1][FATAL] Job 6bab0f65-7260-481b-d548-5b3cf88ff575 (Run Report Generation Scheduled Tasks) failed in CRON run
Wed Jul 4 17:43:01 2018 [14773][1][FATAL] Job 3e18b441-7695-67eb-15f5-5b3cf9218883 (Run Report Generation Scheduled Tasks) failed in CRON run
Wed Jul 4 17:44:01 2018 [14778][1][FATAL] Job a5ec1407-9e60-dcbc-a954-5b3cf912ae18 (Run Report Generation Scheduled Tasks) failed in CRON run
Wed Jul 4 17:45:02 2018 [14783][1][FATAL] Job e97ce875-500a-c7b3-f439-5b3cf98064da (Run Report Generation Scheduled Tasks) failed in CRON run
Wed Jul 4 17:46:01 2018 [14789][1][FATAL] Job 5acec61c-2244-9d45-8aa2-5b3cf9e1a29c (Run Report Generation Scheduled Tasks) failed in CRON run
Wed Jul 4 17:47:01 2018 [14794][1][FATAL] Job a38bbe3a-e0a4-dca4-4a8d-5b3cfa906b40 (Run Report Generation Scheduled Tasks) failed in CRON run
Wed Jul 4 17:48:02 2018 [14799][1][FATAL] Job b87b0c0d-a353-2b78-b43c-5b3cfab76d00 (Run Report Generation Scheduled Tasks) failed in CRON run

pgr · 4 July 2018 17:31

If you look also at php_errors.log (or whatever your web server log is called) you can cross the information. For example, youmight have a PHP error for each of those CRON errors, saying why the job failed.

Are you using Scheduled Reports? If not, you can simply turn off that job. If you are, you can try deleting existing Reports to see if any one of them is causing the errors.

JulianHarmer · 4 July 2018 19:02

I’ve been trying to upload the error.log file, I’ve tried dragging the file to the add file, but can’t seem to get it going, so here’s the dropbox link to the file https://www.dropbox.com/s/29taq89y0ms1hh3/error.zip?dl=0

There’s 14 log files in the /var/log/apache2 area.

root@suitecrm-collie:/var/log/apache2# ls -l
total 63628
-rw-r----- 1 root adm 1604167 Jul 4 19:59 access.log
-rw-r----- 1 root adm 1022146 Jul 4 05:17 access.log.1
-rw-r----- 1 root adm 6034 Jun 25 05:40 access.log.10.gz
-rw-r----- 1 root adm 3676 Jun 24 06:14 access.log.11.gz
-rw-r----- 1 root adm 6145 Jun 23 06:13 access.log.12.gz
-rw-r----- 1 root adm 3948 Jun 22 05:59 access.log.13.gz
-rw-r----- 1 root adm 8709 Jun 21 04:11 access.log.14.gz
-rw-r----- 1 root adm 42449 Jul 3 06:11 access.log.2.gz
-rw-r----- 1 root adm 4055 Jul 2 05:06 access.log.3.gz
-rw-r----- 1 root adm 3773 Jul 1 05:56 access.log.4.gz
-rw-r----- 1 root adm 5297 Jun 30 05:34 access.log.5.gz
-rw-r----- 1 root adm 5511 Jun 29 06:22 access.log.6.gz
-rw-r----- 1 root adm 9957 Jun 28 06:24 access.log.7.gz
-rw-r----- 1 root adm 8918 Jun 27 06:17 access.log.8.gz
-rw-r----- 1 root adm 6567 Jun 26 06:02 access.log.9.gz
-rw-r----- 1 root adm 27303033 Jul 4 19:24 error.log
-rw-r----- 1 root adm 33502389 Jul 4 06:25 error.log.1
-rw-r----- 1 root adm 427 Jun 25 06:25 error.log.10.gz
-rw-r----- 1 root adm 557 Jun 24 06:25 error.log.11.gz
-rw-r----- 1 root adm 753 Jun 23 06:25 error.log.12.gz
-rw-r----- 1 root adm 340 Jun 22 06:25 error.log.13.gz
-rw-r----- 1 root adm 28610 Jun 21 06:25 error.log.14.gz
-rw-r----- 1 root adm 1413898 Jul 3 06:25 error.log.2.gz
-rw-r----- 1 root adm 719 Jul 2 06:25 error.log.3.gz
-rw-r----- 1 root adm 561 Jul 1 06:25 error.log.4.gz
-rw-r----- 1 root adm 595 Jun 30 06:25 error.log.5.gz
-rw-r----- 1 root adm 337 Jun 29 06:25 error.log.6.gz
-rw-r----- 1 root adm 459 Jun 28 06:25 error.log.7.gz
-rw-r----- 1 root adm 41213 Jun 27 06:25 error.log.8.gz
-rw-r----- 1 root adm 33938 Jun 26 06:25 error.log.9.gz
-rw-r----- 1 root adm 0 Jan 24 19:42 other_vhosts_access.log

Now I’m concerned as there are way too many log files. The machine was a fresh install. it only runs SuiteCRM.

Any suggestions?

pgr · 5 July 2018 09:39

About the log rotation scheme, that’s basic Apache configuration, has nothing to do with SuiteCRM. Google for how-to’s, you will find many.

Examining your log, I think it’s worth starting by fixing this frequent warning

Declaration of MyEmailsDashlet::process() should be compatible with DashletGeneric::process($lvsParams = Array, $id = NULL) in /var/www/html/suitecrm/modules/Emails/Dashlets/MyEmailsDashlet/MyEmailsDashlet.php on line 48, referer: http://193.37.226.213/suitecrm/index.php?action=ajaxui

Which version of SuiteCRM are you running? Can you make this line here

https://github.com/salesagility/SuiteCRM/blob/master/modules/Emails/Dashlets/MyEmailsDashlet/MyEmailsDashlet.php#L81

the same as in that version, adding the parameters if they’re missing?

JulianHarmer · 5 July 2018 09:51

I’m using

Version 7.8.17
Sugar Version 6.5.25 (Build 344)

I’ve replaced the line with

function process($lvsParams = array(), $id = null) {

You were correct. there were no variables defined. I’ll reboot it an see what happens. Oh I did take a backup first

Thanks

JulianHarmer · 5 July 2018 13:36

I’ve rebooted it nothing seems broken, but then it didn’t before. Here’s the link to the erorlog after the edit and reboot, and the altered php file

https://www.dropbox.com/s/bl4pvonezx5pr8x/error-afteredit.zip?dl=0

Thank you very much for your help. If theis is ok, I guess something else is causing the cron errors.

If my php file was not complete, does that meaneveryone has this problem?

Thanks

pgr · 5 July 2018 17:22

That fix is already in more recent versions of SuiteCRM (the link I gave you was to the code of 7.10.7), for some reason it is not included in your version (I guess it should be because it’s LTS).

I don’t have time now to examine your full logs. If you still have the cron errors try looking into Scheduled Reports and test them from there to see if they work well.

JulianHarmer · 6 July 2018 09:54

I’ve just realised, non of the pop up alers for reminders work. Surely they must be cron based, Could that be the cause? How do I verify it?

Thanks

Julian

pgr · 6 July 2018 11:01

You can go in Admin / Schedulers and check each job individually.

There’s one for Reminders, and one for Scheduled Reports. See “last ran successfully” property. (also check if the timezone looks right on those times).

Maybe (just maybe) a FATAL error on one job is preventing the other jobs from running. You can try disabling the Scheduled reports job to see if the others run.

JulianHarmer · 6 July 2018 15:03

The email scheduler is run quite frequently, but the scheduled report says

Job Name: Run Report Generation Scheduled Tasks
Status: Active
Date & Time Start: 01/01/2015 12:00
Active From: Always
Date & Time End: Active To: Always
Last Successful Run: Never
Interval: As often as possible.
Execute If Missed: Job:
function::aorRunScheduledReports
Date Created:
03/21/2018 17:19 by Administrator
Date Modified:
07/06/2018 16:01 by Administrator

So it looks like this has probelms, what would you recommend?

Thanks

Julian

pgr · 6 July 2018 16:10

It makes sense that it does’t run correctly, because it’s leaving FATALs in the logs.

As I wrote above, either disable the job if you don’t need it, or try to go in the Scheduled Reports module an delete individual Reports until you find out which one is causing the error.

JulianHarmer · 10 July 2018 13:12

I turned off “Run Report Generation Scheduled Tasks” and the relevant cron errors went away. Half way there.

I deleted the report and turned reporting back on, and the errors have reoccurred.

Even thought the report runs, and produced valid results, the reporting module is faulty in some way.

Are there any know problems with the reporting module in my version? Can I opy a known good copy of the rporting module over and see if the problems go?

Any suggestions?

Thanks

JulianHarmer · 10 July 2018 16:59

I wonder if the fact the reminder pop ups don’t work is related. I assumed this was a browser issue, but in retrospect I wonder if they’re related.

HMm

pgr · 11 July 2018 11:36

Getting the reminders to work sometimes has additional challenges (like timezones in CLI PHP). But you can start by checking if “Run email reminder Notifications” is running successfully. I think the other reminders (on-screen) also depend on this (not sure though).

I find it weird that we can’t figure out your Reports problem better. We should be getting specific errors wither in suitecrm.log or php_errors.log when a specific report fails… it’s hard to troubleshoot from a distance, without information…

JulianHarmer · 11 July 2018 16:44

Thanks for that, I have the email reminders working, it’s the pop up ones that seem to be failing, but I’d rather leave that till the Cron issue is fixed.

I’ve zipped up the
/var/log/apache2/error.log and /var/www/html/suitecrm/suitecrm.log files in to https://www.dropbox.com/s/6y28t7k4h5t1cmz/suitecrm.zip?dl=0

Are there any other files of other information that would be of use I could put up?

There are loads of cron errors in suitecrm, what does the identifier linke or reference to ?

Thanks again

pgr · 11 July 2018 19:10

Ok, I don’t normally analyze full logs people send me, but I did have a look at yours and this is my advice

clear old stuff from your logs, they’re getting big and hard to manage in a text editor
in Admin / System settings, increase your log level to Debug. Now, after a minute, you should have the same Job failed Fatal error, but you also have a bunch of messages before giving you clues into what SuiteCRM was trying to do when it failed.
in error.log you have messages that might explain why reminders aren’t working - but as you said, let’s leave that for later

JulianHarmer · 11 July 2018 19:58

I’ve had a look at the log, after cleaning it up. Bear in mind I’m not a programmer or developer. but I think the version of PHP may be incompatible, from

Wed Jul 11 20:39:02 2018 [1364][1][DEPRECATED] Formatting correction: SchedulersJobs->failure_count had formatting automatically corrected. This will be removed in the future, please upgrade your external code
Wed Jul 11 20:39:02 2018 [1364][1][DEBUG] Hook called: SchedulersJobs::before_save
[color=#ff0000]Wed Jul 11 20:39:02 2018 [1364][1][DEPRECATED] SugarBean.php: preprocess_fields_on_save() is deprecated[/color]
Wed Jul 11 20:39:02 2018 [1364][1][INFO] Query:UPDATE job_queue
SET assigned_user_id=‘1’,name=‘Run Report Generation Scheduled Tasks’,date_modified=‘2018-07-11 19:39:01’,scheduler_id=‘8a8367f2-3503-68ac-4c3e-5ab2943d2a88’,execute_time=‘2018-07-11 19:39:00’,status=‘done’,resolution=‘failure’,message=‘Unexpected failure, please check PHP logs and suitecrm.log\n’,target=‘function::aorRunScheduledReports’,data=NULL,requeue=0,retry_count=NULL,failure_count=1,job_delay=0,client=‘CRON00a00c65aa19870da6b1b6a14ee132df:1364’,percent_complete=NULL
WHERE job_queue.id = ‘7fb4a2d6-18b5-8912-a1bd-5b465ce6f1fe’ AND deleted=0
Wed Jul 11 20:39:02 2018 [1364][1][INFO] Query Execution Time:0.0084750652313232
Wed Jul 11 20:39:02 2018 [1364][1][DEBUG] SecuritySuite: Get SecuritySuite Enabled Modules: SELECT lhs_module, rhs_module FROM relationships WHERE deleted=0 AND (lhs_module = ‘SecurityGroups’ OR rhs_module=‘SecurityGroups’)
Wed Jul 11 20:39:02 2018 [1364][1][INFO] Query:SELECT lhs_module, rhs_module FROM relationships WHERE deleted=0 AND (lhs_module = ‘SecurityGroups’ OR rhs_module=‘SecurityGroups’)
Wed Jul 11 20:39:02 2018 [1364][1][INFO] Query Execution Time:0.00035405158996582
Wed Jul 11 20:39:02 2018 [1364][1][DEBUG] Hook called: SchedulersJobs::after_save
Wed Jul 11 20:39:02 2018 [1364][1][DEBUG] Creating new instance of hook class AOD_LogicHooks without parameters
Wed Jul 11 20:39:02 2018 [1364][1][DEBUG] Creating new instance of hook class AssignGroups without parameters
Wed Jul 11 20:39:02 2018 [1364][1][DEBUG] Creating new instance of hook class AOW_WorkFlow without parameters

I’ve put the full log here https://www.dropbox.com/s/nfp7bk9q4xlnquw/suitecrm-debug.zip?dl=0

What do you think?

Thanks

pgr · 11 July 2018 21:42

99.9% of INFO, DEBUG and DEPRECATED messages are to be ignored. It takes a while to get used to the messages and learn to ignore them

Your PHP is compatible if it obeys the Compatibility Matrix:

https://docs.suitecrm.com/admin/compatibility-matrix/

Those “deprecated” messages are just warnings for the future. The SuiteCRM team will take care of those whenever they’re approaching the moment to drop compatibility with the older versions.

I’ll try to look for more clues in your logs tomorrow.

pgr · 12 July 2018 17:00

Sorry, I can’t get anything significant from your debug log.

How many Reports to you have in the Reports module? Do they all run successfully, when running them directly from that module?

And how many Scheduled Reports do you have? Can you try deleting them all?

LordWolfer · 26 March 2020 12:39

hello Mr. pgr,
I seen that you helped many people plz help me too
actully whenever i running cron.php using task schedular it’s showing error bad data passed in; return to homepage.

I’ll wait for your reply.

Thanks