06 August 2024, 2:31

We have upgraded to 24.04 and we notice these remarks at our cron on the admin overview page:

Obliviously, some cron task are not running correctly or take a long time. But how do we start fixing this issue? We were running a cronjob every minute, but my guess is that it's not finished within one minute.

So now I have set it to run every 5 minutes. Let's see if that makes a difference, but suggestions are very welcome.

06 August 2024, 9:11

Hi Richard,

Robert's first response in this forum post may help with your debugging: https://mahara.org/interaction/forum/topic.php?id=7529

Following on, in your database table cron is a list of cron tasks. When a cron task gets broken, an entry is added to the config table starting with _cron_lock<cron task>.

The first step to re-triggering these broken tasks, is to delete the lock entry from the config table and set their matching nextrun value in the cron table to a sooner time so you can debug it.

Kind regards,

Doris

24 August 2024, 1:19

Thanks, I read the specific thread.

OK, so I deleted the _cron entries in my config table. Then I ran the cron again.

Cronlog says this error:

Content-type: text/html; charset=UTF-8
Cache-Control: private, must-revalidate, pre-check=0, post-check=0, max-age=0
Expires: Sun, 02 Feb 1986 00:00:00 GMT
Pragma: no-cache
X-XSS-Protection: 1; mode=block
X-Content-Type-Options: nosniff
X-Permitted-Cross-Domain-Policies: master-only
Strict-Transport-Security: max-age=63072000
Content-Security-Policy: frame-ancestors 'self'
X-Frame-Options: SAMEORIGIN

A nonrecoverable error occurred. This probably means you have encountered a bug in the systemContent-type: text/html; charset=UTF-8
Cache-Control: private, must-revalidate, pre-check=0, post-check=0, max-age=0
Expires: Sun, 02 Feb 1986 00:00:00 GMT
Pragma: no-cache
X-XSS-Protection: 1; mode=block
X-Content-Type-Options: nosniff
X-Permitted-Cross-Domain-Policies: master-only
Strict-Transport-Security: max-age=63072000
Content-Security-Policy: frame-ancestors 'self'
X-Frame-Options: SAMEORIGIN

A nonrecoverable error occurred. This probably means you have encountered a bug in the systemStatus: 500 Internal Server Error
Content-type: text/html; charset=UTF-8
Cache-Control: private, must-revalidate, pre-check=0, post-check=0, max-age=0
Expires: Sun, 02 Feb 1986 00:00:00 GMT
Pragma: no-cache
X-XSS-Protection: 1; mode=block
X-Content-Type-Options: nosniff
X-Permitted-Cross-Domain-Policies: master-only
Strict-Transport-Security: max-age=63072000
Content-Security-Policy: frame-ancestors 'self'
X-Frame-Options: SAMEORIGIN

So basically a 500 internal server error.

Also, the cron in the admin overview pages says this:

Slow running cron tasks:
core_activity_process_queue
core_auth_handle_account_expiries
module_lti_advantage_lti_advantage_get_members_cron

The account expires cron could be disabled as we only use an external login system. How do I disable that one? Couldn't find that option in the database table cron

The other two... any idea why they are failing and what they are doing? What does core_activity_process_queue do?

The get lti-get members also is interesting to me. I think I can disable that one as well, as we use webservices to populate our groups.

24 August 2024, 1:25

php error log looks familiar:

[23-Aug-2024 15:23:02 Europe/Amsterdam] [WAR] 42 (auth/session.php:456) session_start(): Session cannot be started after headers have already been sent
[23-Aug-2024 15:23:02 Europe/Amsterdam] Call stack (most recent first):
[23-Aug-2024 15:23:02 Europe/Amsterdam]   * log_message(string(size 79), integer, true, true, string(size 44), integer) at /home/portfolio/public_html/lib/errors.php:522
[23-Aug-2024 15:23:02 Europe/Amsterdam]   * error(integer, string(size 79), string(size 44), integer) at Unknown:0
[23-Aug-2024 15:23:02 Europe/Amsterdam]   * session_start() at /home/portfolio/public_html/auth/session.php:456
[23-Aug-2024 15:23:02 Europe/Amsterdam]   * Session->ensure_session() at /home/portfolio/public_html/auth/session.php:248
[23-Aug-2024 15:23:02 Europe/Amsterdam]   * Session->set(string(size 14), integer) at /home/portfolio/public_html/auth/user.php:2336
[23-Aug-2024 15:23:02 Europe/Amsterdam]   * LiveUser->set(string(size 9), integer) at /home/portfolio/public_html/auth/user.php:2145
[23-Aug-2024 15:23:02 Europe/Amsterdam]   * LiveUser->logout() at /home/portfolio/public_html/webservice/lib.php:1572
[23-Aug-2024 15:23:02 Europe/Amsterdam]   * WebserviceBaseServer->session_cleanup() at /home/portfolio/public_html/webservice/lib.php:1509
[23-Aug-2024 15:23:02 Europe/Amsterdam]   * WebserviceBaseServer->run() at /home/portfolio/public_html/webservice/rest/server.php:74
[23-Aug-2024 15:23:02 Europe/Amsterdam] 

24 August 2024, 1:34

24 August 2024, 1:43

Found an extra error.log in maharadata:

[INF] 7a (lib/cron.php:55) ---------- cron running Fri, 23 Aug 2024 15:43:54 +0200 ----------
[INF] 7a (lib/cron.php:114) Running PluginModuleLti_advantage::lti_advantage_get_members_cron
[DBG] 7a (module/lti_advantage/lib.php:972) lti_advantage_get_members_cron
[WAR] 7a (module/lti_advantage/lib/lti-1-3-php-library/lti/LTI_Service_Connector.php:59) Trying to access array offset on value of type null
Call stack (most recent first):
  * log_message(string(size 51), integer, true, true, string(size 102), integer) at /home/portfolio/public_html/lib/errors.php:522
  * error(integer, string(size 51), string(size 102), integer) at /home/portfolio/public_html/module/lti_advantage/lib/lti-1-3-php-library/lti/LTI_Service_Connector.php:59
  * IMSGlobal\LTI\LTI_Service_Connector->get_access_token(array(size 1)) at /home/portfolio/public_html/module/lti_advantage/lib/lti-1-3-php-library/lti/LTI_Service_Connector.php:65
  * IMSGlobal\LTI\LTI_Service_Connector->make_service_request(array(size 1), string(size 3), string(size 83), null, null, string(size 56)) at /home/portfolio/public_html/module/lti_advantage/lib/lti-1-3-php-library/lti/LTI_Names_Roles_Provisioning_Service.php:27
  * IMSGlobal\LTI\LTI_Names_Roles_Provisioning_Service->get_members() at /home/portfolio/public_html/module/lti_advantage/lib.php:1005
  * PluginModuleLti_advantage::lti_advantage_get_members_cron() at /home/portfolio/public_html/lib/cron.php:122

[WAR] 7a (module/lti_advantage/lib/lti-1-3-php-library/lti/LTI_Names_Roles_Provisioning_Service.php:30) Undefined array key "members"
Call stack (most recent first):
  * log_message(string(size 29), integer, true, true, string(size 117), integer) at /home/portfolio/public_html/lib/errors.php:522
  * error(integer, string(size 29), string(size 117), integer) at /home/portfolio/public_html/module/lti_advantage/lib/lti-1-3-php-library/lti/LTI_Names_Roles_Provisioning_Service.php:30
  * IMSGlobal\LTI\LTI_Names_Roles_Provisioning_Service->get_members() at /home/portfolio/public_html/module/lti_advantage/lib.php:1005
  * PluginModuleLti_advantage::lti_advantage_get_members_cron() at /home/portfolio/public_html/lib/cron.php:122

[WAR] 7a (lib/errors.php:537) [TypeError]: array_merge(): Argument #2 must be of type array, null given at /home/portfolio/public_html/module/lti_advantage/lib/lti-1-3-php-library/lti/LTI_Names_Roles_Provisioning_Service.php:30
Call stack (most recent first):
  * exception(object(TypeError)) at Unknown:0

24 August 2024, 2:15

I emptied this table `activity_queue` that had over 9000 records and now cron seems to run OK.

Only problem now seems to be the LTI Advantage: _cron_lock_module_lti_advantage_lti_advantage_get_members_cron

26 August 2024, 9:22

Hi Richard,

I've not seen that LTI_Advantage error before. Are you able to make a small adjustment to your code to see why your LTI_Advantage cron is failing?

In the file module/lti_advantage/lib/lti-1-3-php-library/lti/LTI_Service_Connector.php on line 56 can you change:

$token_data = json_decode($resp, true);

To

$token_data = json_decode($resp, true); error_log(print_r($token, true));

and see what errors you get in your error log about the response for the getting access token.

Cheers

Robert

26 August 2024, 18:34

Just checked, the errors are all gone after emptying the activity_queue table.

I must say that I disabled some cron-tasks, they are useless to us. For example account expiry, reset password mails, etc.

I think I also disabled the lti_advantage cron task. What did that do?

05 September 2024, 16:41

Hi Richard,

I believe that this cron runs once a day if LTI Advantage is used to check if there has been a change in group membership when a group was created via LTI 1.3 Advantage.

Cheers

Kristina