course_delete_modules task taking too many time

course_delete_modules task taking too many time

by Osvaldo Canato -
Number of replies: 15

Hello!

For some reason our mdl_task_adhoc acumulated around 20,000 entries which the first 2,000 entries being the course_delete modules tasks.

The problem is that these course_delete_modules entries are taking too many time to be completed, blocking other important tasks to be done, like course_backup_task and send_user_notification.

So my question is what could be wrong if I simple delete some course_delete_modules entries from mdl_task_adhoc.

On the other hand, is there any way to change the order of the entries in mdl_task_adhoc?

We are using moodle 3.10.

Any help?

Osvaldo

 


 

Average of ratings: -
In reply to Osvaldo Canato

Re: course_delete_modules task taking too many time

by Ken Task -
Picture of Particularly helpful Moodlers

Sounds like your site has become victum to recycle bin.

Go to: your site/admin/settings.php?section=tool_recyclebin

Item lifetime is set to 1 week by default.   Change that to 1 minute.
Auto Hide uncheck.  Recyclebin will show in all course admin menus then and you can
see what's in there.

Ad-hoc task are jobs that cron job didn't finish ... when something is deleted
(course module) a recylebin backup is made ... that could be something massive ...
like an assignment for 600 + users who submitted a video.

Evidence this is happening ...

look in moodledata/temp/backup/ you might find backups that failed ... taking too long to create the recyclebin backup of something large.

Query your mdl_files table to see if there are .mbz filenames and what component they belong too.

Had an issue with this very thing recently and had to use the command line  with nohang up to run the adoc_task php script in admin/cli/ as well as set the lifetime to 1 second in order to get adhoc_task to finish and gain control over what appeared to  be a 'ghost' ... run-away - auto backup (which it wasn't).

If you have command line access, to go code/admin/cli/ and continually run the adoc_task.php script.

Issuing with no options will display the help:

[root@server cli]# php adhoc_task.php
Ad hoc cron tasks.

Options:
 -h, --help                Print out this help
     --showsql             Show sql queries before they are executed
     --showdebugging       Show developer level debugging information
 -e, --execute             Run all queued adhoc tasks
 -k, --keep-alive=N        Keep this script alive for N seconds and poll for new adhoc tasks
 -i  --ignorelimits        Ignore task_adhoc_concurrency_limit and task_adhoc_max_runtime limits
 -f, --force               Run even if cron is disabled

'SoS', Ken


Average of ratings: Useful (2)
In reply to Ken Task

Re: course_delete_modules task taking too many time

by Osvaldo Canato -
Thanks a lot for the reply, Ken!

The problem seems that my adhoc tasks are frozen in the first entries related to a course id 3714 and modules id 16 (quiz activity), 12 (label) and 1 (assign).

As an example, here is the customdata of the first line:

{"cms":[{"id":"151344","course":"3714","module":"16","instance":"6248","section":"41351","idnumber":"","added":"1604932668","score":"0","indent":"0","visible":"1","visibleoncoursepage":"1","visibleold":"1","groupmode":"0","groupingid":"0","completion":"0","completiongradeitemnumber":null,"completionview":"0","completionexpected":"0","showdescription":"0","availability":null,"deletioninprogress":"1"}],"userid":"459","realuserid":"459"}

Every time I run adhoc_task.php (yes, I can run it by comandline), results in a "PHP Fatal error: Allowed memory size of 4294967296 bytes exhausted".

But I have already tried to increase the memory limit even to 7GB per config.php ($CFG->extramemorylimit = '7168;) and it seems that the query only wastes more time, killing when the memory runs out.

Because of these things I was asking if I could delete those first entries (or change nextruntime to a future time) so that other lines could be executed and see what happens.

And ok, I adjusted the lifetime to 1 second.

Thanks in advance!

Osvaldo
Average of ratings: -
In reply to Osvaldo Canato

Re: course_delete_modules task taking too many time

by Ken Task -
Picture of Particularly helpful Moodlers

Did you:

purge caches after switching to boost?

check moodledata/temp/backup/xxxxxx/ for evidence of a failed recyclebin backup?   Did you remove what was there?  How large were the .xml files (especially the questions.xml)?

extra memory is already set to 512M by default:

[root@sos cli]# php cfg.php |grep extramemorylimit
extramemorylimit    512M

Note that has a designator 'M' at the end.extra memory is already set to 512M by default:

PHP error can't allocate more memory (value shown is 4 Gig?)  Can't get blood out of  a turnip.

While you could set nextrun time to future, you will be visiting this again and problem has not been resolved.

The CLI script is a background process and in my case (maybe yours also) never finished, so I got nasty:

nohup php adhoc_task.php -e &

nohup = no hang up ... run forever (can kill -9 the pid however)

& at the end allows you to watch the .out file in realtime:

tail -f ./nohup.out

If hanging on questions remember you are dealing with the entire questionbank ... lots of processing there.

Also, one can watch the build of the recyclebin backup in moodledata/temp/backup/xxxxx/ by cd into that directory and issuing:

watch "ls -l"

Pay attention to size of questions.xml file.

Good luck!

'SoS', Ken

Average of ratings: -
In reply to Ken Task

Re: course_delete_modules task taking too many time

by Osvaldo Canato -
Hello!

Yes, I purged caches, looked for error in moodledata/temp/backup/ ... no problem found nowhere.

The only way I could imagine to go on was excluding or postpone the stucked entries.

So, at least for now I decided to postpone and once that was done, tasks finally started to run.

Now I will have to decide what to do with the 26 blocked entries. It is curious: they are all related to 2 courses by the same teacher. It seems that there is a problem with some files that he tried repeatedly to put into activities. The fact is that these entries seem impossible to perform. Yes, I said it right ... even 7GB is not enough for these entries and I can't give more than that amount of memory!

Thanks a lot!

Osvaldo
Average of ratings: -
In reply to Osvaldo Canato

Re: course_delete_modules task taking too many time

by Ken Task -
Picture of Particularly helpful Moodlers

What do 'the 26 blocked entries' look like?  Maybe you could dump those rows to a text file and attach here?

What was the size of files this teacher repeadly tied to put into activities?

And the mdl_files table had no rows tagged as recyclebin backups?  (now that you have set keep for 1 minute, hard to catch those rows).

'SoS', Ken



Average of ratings: -
In reply to Ken Task

Re: course_delete_modules task taking too many time

by Osvaldo Canato -

Hi, Ken!

Okay, attached a file with all those 26 entries.

Actually, not all of these entries are linked to a file, but for those that have a file listed in mdl_files (13 entries marked yellow in the attached file) the files are about 2 MB in size.

And the mdl_files table does have a few rows marked as recyclebin backups, but linked to user ID 2, which is the administrator user.

That's it!

Osvaldo

Average of ratings: -
In reply to Osvaldo Canato

Re: course_delete_modules task taking too many time

by Ken Task -
Picture of Particularly helpful Moodlers

User id 2 (the initial admin user) is the user under which the adhoc_task would run ... that is normal.   The teacher ID number, once having deleted a module from a course is no longer in the picture ... deletion now turned over to cron/adhoc_task (que in this case).

Is the course still available?

Go into it ... go to grade book and see if there is a 'pending deletion' at the bottom.

You've not shared server setup specs ... like total memory + if DB server on same machine (localhost) as well as how one is running web service + how memory is allocated to web service, mysql (assuming it is mysql) etc.

Fact that your attempts to use a moodle config to use more memory and it fails with 'tired to allocate' and shows a value, kinda indicates server can't ... not enough resources (memory).

So what does the 'top' or the 'top' command show for server specs (memory wise)? (previous reference to 'can't get blood out of a turnip').

'SoS', Ken



Average of ratings: -
In reply to Ken Task

Re: course_delete_modules task taking too many time

by Ken Task -
Picture of Particularly helpful Moodlers

If no top from top, what does 'free' show?

Kinda off topic but related ... with site in maintenance mode, cli cron cannot run ... and that also means adhoc_task.php cannot run.

Would think that's faulty logic!!!   Situation like this keeping all users out and from doing anything until cron jobs and adhoc_task finish would be desired!!!

'SoS'. Ken


Average of ratings: -
In reply to Ken Task

Re: course_delete_modules task taking too many time

by Osvaldo Canato -
Ok, Ken!

Right on target! Yes, both courses are still available and have the "pending deletion" message!  And sure related to that these 2 courses did not completed their backup. So, what to do now?

The server data:

  • Machine total memory: 32 GB
  • 8 CPUs
  • DB server on the same machine of system (linux centos 7)
  • DB with 33 GB size
  • innodb_buffer_pool_size = 8GB
  • innodb_log_file_size = 1GB
  • Moodledata with 360 GB (46% of disc ... separated from the system, but in the same virtual machine)
  • what top says: KiB Mem : 32779832 total,  6358024 free, 12177916 used, 14243892 buff/cache; load average: 6,89, 8,34, 8,89

So, in no busy hours, I can put more memory to extramemorylimit in config.php; the problem is that i des not seems that will solve the problem. Maybe, am I wrong?

Thanks a lot!

Osvaldo

Average of ratings: -
In reply to Osvaldo Canato

Re: course_delete_modules task taking too many time

by Ken Task -
Picture of Particularly helpful Moodlers

That sounds pretty close to the problem faced by another poster .... even server specs about the same.

So ... set recyclebin settings to the quickest/lowest time to keep.   The recyclebin backups will still have to be created, but with the lowest/quickest times, they don't get stored in moodledata/filedir/ (where it is difficult to find and get rid of them) they will eventually end up in moodledata/trashdir/ where you can manually delete with no ill affects.

Now the trick is to get the adhoc_task.php script to run until completed.

First, set back down to sane levels what you tweaked upwards.  Server I was working with had no such tweaks upwards.

Have to be willing to issue  a nohup command and let it run ... yes, site will slow down ... but ... you don't have any choice.   Unfortunately, you cannot put site in maintenance mode ... adhoc_task.php won't run in maintenance mode (flaw in logic with this issue - can't fix). 

From code/admin/cli/ where you can see the adhoc_task.php script, issue:

nohup php adhoc_task.php -e &

nohup means no hang up.

php adhoc_task.php -e means execute

the & on the end puts the command in a background process - redirects output of command to a nohup.out log file *and* (more importantly) allows your ssh session freedom to move to moodledata/temp/backup/ and watch the recyclebin backup being built.

And (gulp) you have to let that run ... you can exit your ssh access and the nohup command will continue to run.    Go have a cold one ... catch some zzzz's ... then log back in via ssh and see if the nohup process still running ... if it is ... logout ... go have some more cold ones ... catch more zzzzz's etc.

Good luck!

'SoS', Ken




Average of ratings: -
In reply to Ken Task

Re: course_delete_modules task taking too many time

by Osvaldo Canato -
Hi, Ken!

Your tips were great and after two weeks of work, the problem is almost completely solved.

In my case, I had to work with those 26 blocked entries "line by line", freeing up 8 to 10GB of memory (extramemorylimit in config.php) so that they could be completed.

But, as I only have 32 GB for the entire virtual machine, I had to disable the cron, increase the task runtime (task_adhoc_max_runtime) to 12h and change the nextruntime values ​​of those lines (in mdl_task_adhoc) so that I am sure that only they would be running by command "nohup php adhoc_task.php -e &".

To not disturb users, I only could run the tasks during all night long or weekend.

Looking at the temporary backup folders built while the tasks is running, I realized that the whole problem may be related to badges. I say this because the badges.xml files (inside that temporay backup folders) can exceed 8GB!

Knowing this, I investigated the mdl.badges table and found tens of thousand identical lines related to those two courses of that same teacher.

Then i visited that 2 courses badges pages (https://mysite/badges/view.php?type=2&id=XXX) and what I find is a blank page.  

With this new information, would you be able to imagine the cause of the problem?
Average of ratings: Useful (1)
In reply to Osvaldo Canato

Re: course_delete_modules task taking too many time

by Osvaldo Canato -
Some more information:

That tens of thousands of mdl_badges lines are actually identical, even in their "timecreated" and "timemodified" values.

And all they have the valor "0" in "status" field.

So, reading Floyd post (https://moodle.org/mod/forum/discuss.php?d=347389) that is related to a inactive badge (cannot be earned and has not been awarded).

So, what if I delete all this entries?
Average of ratings: -
In reply to Osvaldo Canato

Re: course_delete_modules task taking too many time

by Ken Task -
Picture of Particularly helpful Moodlers

"With this new information, would you be able to imagine the cause of the problem?"

Am not capable of 'Vulcun Mind Melds', so I cannot 'imagine the cause'.

Never had the issue so following is 100% guess ..

1. Can you change the status of the badge awarding via DB?

2. In the table for the badges, is there a contenthash column? (which is supposed to be the location and filename in the sea of files of moodledata/filedir/

Both above are not 'standard' way of fixing things and should be done only on one reference to a badge.   Then checked to see if there has been any un-anticipated problem cause by actions.

In the case of #2 above ... let's say the contenthash column exist and shows something like:

t4nasdopirewgasdhsefjsrf

cd moodledata/filedir/

find ./ -name t4nasdopirewgasdhsefjsrf

Last command will grind away - lots of files to look through so be patient.

IF not found, one could create a 0 byte file as a 'placeholder'.

touch moodledata/filedir/t4/na/t4nasdopirewgasdhsefjsrf

If the t4 directory doesn't exist, manually create it as well as subdirectory of na as in the example given.

change own apache:apache moodledata/filedir/t4/ -R

chmod ugo+rwx moodledata/filedir/t4/ -R (liberal permissions ok in this case)

Now there is something in moodledata/filedir/ that matches the meta data in the DB.

With that there now the course_delete_modules should be able to find something to delete!

Above, is, like I said ... 100% guess!

Good luck!

'SoS', Ken


Average of ratings: -
In reply to Ken Task

Re: course_delete_modules task taking too many time

by Osvaldo Canato -
Hello, Ken!

Just to tell you how the story ended!

In short, the only way I found solving the problem was having courage and deleting all entries related to that badges in two database tables, mdl_badge and mdl_files. After that, I also deleted the files listed in moodledata / filedir.

Interestingly, there were only 3 small files related to millions of entries in this table from two databases. No, I'm not kidding ... millions !!!

After deleting all of this, cron started to run nicelly again!

Wishing you a happy new year,

Osvaldo
Average of ratings: Useful (1)
In reply to Osvaldo Canato

Re: course_delete_modules task taking too many time

by Ken Task -
Picture of Particularly helpful Moodlers

Thanks for reporting back what you did to resolve.

With badges what you've described would make sense ... badge is just an image so the badges awarded users would really be the same files.

So that course that had that badge to be awarded to users in it must have had a lot of users in it.   Deletion/removal of that badge from the course could result in moodle grinding to a halt on a cron process which could have also been qued up in adhoc task (jobs not yet completed) for deleting the 'module' (which was the badge).

Using that badge in any other course?   OR any other course using the same badge?

Again ... congrats on solving ... now you can enjoy your New Year's celeb without that hanging over your head for the 1st project of the new year! smile

'SoS', Ken


Average of ratings: Useful (1)