30 June 2021, 22:44

Hi all. 

        I was hoping someone could help me with a small issue with the mahara crons not running, Ive just installed mahara from GIT repo and our version of mahara is: 

The site was setup with no problems at all, setup the site, the database the apache conf and our mahara instance is up and running with no issues other than the crons are not running. so when running the cron (either from the crontab or manually running "php /var/www/mahara/htdocs/lib/cron.php") I get the following error: 

# php /var/www/mahara/htdocs/lib/cron.php
[INF] ef (lib/cron.php:55) ---------- cron running Tue, 29 Jun 2021 14:29:26 +0100 ----------
[INF] ef (lib/cron.php:114) Running PluginAuthSaml::auth_saml_refresh_cron
[INF] ef (lib/cron.php:114) Running PluginSearchElasticsearch::cron
[INF] ef (lib/cron.php:114) Running PluginBlocktypeExternalfeed::refresh_feeds
[INF] ef (lib/cron.php:136) Skipping: No need to run PluginInteractionForum::interaction_forum_new_post
[INF] ef (lib/cron.php:193) Running core cron collection_rollover
[WAR] ef (lib/errors.php:530) [Error]: Call to undefined function collection_rollover() at /var/www/mahara/htdocs/lib/cron.php:201
Call stack (most recent first):
  * exception() at Unknown:0

A nonrecoverable error occurred. This probably means you have encountered a bug in the system

Poking around on the forms I checked the database and there is a DB lock 

mahara=# SELECT * FROM config WHERE field LIKE '\_cron%';
                field                |   value
-------------------------------------+------------
 _cron_lock_core_collection_rollover | 1624973366
(1 row)

deleteing the lock and re-running the cron just results in the same error and the same DB lock, Which i suppose makes sense if the collection rollover is failing then there probably is a DB lock for it, 

In my config.php file for mahara i have logged set to:  

$cfg->log_file = '/var/www/mahara/maharadata/error.log';

and logging levels set to: 

$cfg->error_reporting = E_ALL & ~E_STRICT;

but that file doesnt get updated with any kind of errors which is even stranger. I checked the syslog in /var/log and it does show the cron.php being run but nothing else after that.

Id be extremely grateful if anyone could point me in the right direction as to why im getting the error: Call to undefined function collection_rollover()   means when running the cron as its not in the logs. 

Cheers 

Anthony 

01 July 2021, 22:25

Hello Anthony,

I'm afraid I don't have an answer for you, I'm just here to say I'm having a similar issue ... I'm running Mahara 21.04.1

The core_collection_rollover cron job is also showing as 'long-running' for me too, like yourself I've tried deleting the row in the DB but on each cron run it returns. - 'Cron is not running' is being displayed under 'Reports', no errors in the logs, site seemingly working fine otherwise.

I also have another strange issue that's been slowly driving me insane in my attempts to troubleshoot it, my cron process seems to start off in one timezone and complete in another, everything is set to Europe/London, when the cron starts it states the correct time (+0100) but as it progresses any other logged times are all an hour behind, including the cron finished time (+0000).

[INF] 91 (lib/cron.php:55) ---------- cron running Thu, 01 Jul 2021 11:07:01 +0100 ----------
[INF] 91 (lib/cron.php:114) Running PluginAuthSaml::auth_saml_refresh_cron
Jul 01 11:07:01 ssphp-https://maharatest INFO [CL1be6067c] Mahara [metarefresh]: Executing set [remote-idp]
Jul 01 11:07:01 ssphp-https://maharatest DEBUG [CL1be6067c] cron [metarefresh]: In set [remote-idp] loading source [https://login.microsoftonline.com/iveremovedtheguidhere/federationmetadata/2007-06/federationmetadata.xml?appid=iveremovedtheappidhere]
Jul 01 11:07:01 ssphp-https://maharatest DEBUG [CL1be6067c] Downloaded fresh copy
Jul 01 11:07:01 ssphp-https://maharatest DEBUG [CL1be6067c] Writing: /media/data-drive/maharatestsite.domainname.ac.uk/metadata/refresh/saml20-idp-remote.php
[INF] 91 (lib/cron.php:568) Skipping long-running cron job core_collection_rollover (Thu, 01 Jul 2021 09:16:01 +0000).
[INF] 91 (lib/cron.php:235) ---------- cron finished Thu, 01 Jul 2021 10:07:01 +0000 ----------

The timezone issue seems to be something to do with the remote-idp jobs, when they don't run everything seems to be fine, I can only assume those jobs are receiving UTC from the IDP which then skews the cron log times.

[INF] 24 (lib/cron.php:55) ---------- cron running Thu, 01 Jul 2021 11:21:01 +0100 ----------
[INF] 24 (lib/cron.php:568) Skipping long-running cron job auth_saml_auth_saml_refresh_cron (Thu, 01 Jul 2021 11:21:01 +0100).
[INF] 24 (lib/cron.php:568) Skipping long-running cron job core_collection_rollover (Thu, 01 Jul 2021 10:16:01 +0100).
[INF] 24 (lib/cron.php:193) Running core cron portfolio_auto_copy
[INF] 24 (lib/cron.php:193) Running core cron check_imap_for_bounces
[INF] 24 (lib/cron.php:193) Running core cron watchlist_process_notifications
[INF] 24 (lib/cron.php:235) ---------- cron finished Thu, 01 Jul 2021 11:21:01 +0100 ----------

All the best,

Ben

02 July 2021, 1:16

Hi Ben 

          This is sorted for us now. Were using mahara installed from git there was an update yesterday to the repos to fix this issue. Im a new member so it wont let me post the URL to the mahara git repo but ive attached it in a text file here now so you can see the release note. 

I just did a git pull, a DB upgrade and then deleted the locks on the CRON table above and then the crons are now running for me fine. If you arent on git you may need to grab the latest version of mahara from source and install the update. 

Regards

Anthony

02 July 2021, 10:18

Hi,

Yes, there was a coding issue that was spotted yesterday by another user and a patch was created to fix this problem

https://reviews.mahara.org/#/c/11838/

Applying the patch will fix the problem.

But if your site can't apply the patch and if you can't wait for next minor point release then you can run these commands in the DB to fix:

 UPDATE cron SET callfunction = 'unlock_collections_by_rollover' WHERE callfunction = 'collection_rollover';

 DELETE FROM config WHERE field LIKE '\_%';

The delete command removes all the cron locks that begin with an underscore;

As for the cron run having an end time before start time I've not seen that before so will look into it

Cheers

Robert