Updating a plugin takes several hours

Updating a plugin takes several hours

by Dácil Blanco Francisco -
Number of replies: 16
Hi, In moodle 4.1.4 with php 8.1 when I update a plugin via command line it takes several hours, before it took minutes.

I have checked Server -> Environment and everything is fine.


If I do a strace to see what the process is doing I see the following, for example:

access("/var/www2/medusa/evagd/test_evagd/lib/editor/tinymce/plugins/moodlemedia/db/caches.php", F_OK) = -1 ENOENT (No such file or directory)
access("/var/www2/medusa/evagd/test_evagd/lib/editor/tinymce/plugins/moodlenolink/db/caches.php", F_OK) = -1 ENOENT (No such file or directory)
access("/var/www2/medusa/evagd/test_evagd/lib/editor/tinymce/plugins/pdw/db/caches.php", F_OK) = -1 ENOENT (No such file or directory)
access("/var/www2/medusa/evagd/test_evagd/lib/editor/tinymce/plugins/recordrtc/db/caches.php", F_OK) = -1 ENOENT (No such file or directory)
access("/var/www2/medusa/evagd/test_evagd/lib/editor/tinymce/plugins/spellchecker/db/caches.php", F_OK) = -1 ENOENT (No such file or directory)
access("/var/www2/medusa/evagd/test_evagd/lib/editor/tinymce/plugins/tiny_mce_wiris/db/caches.php", F_OK) = -1 ENOENT (No such file or directory)
access("/var/www2/medusa/evagd/test_evagd/lib/editor/tinymce/plugins/wrap/db/caches.php", F_OK) = -1 ENOENT (No such file or directory)
access("/var/www2/medusa/evagd/test_evagd/admin/tool/log/store/database/db/caches.php", F_OK) = -1 ENOENT (No such file or directory)
access("/var/www2/medusa/evagd/test_evagd/admin/tool/log/store/legacy/db/caches.php", F_OK) = -1 ENOENT (No such file or directory)
access("/var/www2/medusa/evagd/test_evagd/admin/tool/log/store/standard/db/caches.php", F_OK) = -1 ENOENT (No such file or directory)
access("/var/www2/medusa/evagd/test_evagd/lib/db/caches.php", F_OK) = 0
openat(AT_FDCWD, "/var/www2/medusa/evagd/test_evagd/lib/db/caches.php", O_RDONLY) = 7
fstat(7, {st_mode=S_IFREG|0755, st_size=20316, ...}) = 0
read(7, "<?php\n// This file is part of Mo"..., 20316) = 20316
close(7)                                = 0
access("/var/www2/medusa/evagd/test_evagd/availability/condition/completion/db/caches.php", F_OK) = 0
openat(AT_FDCWD, "/var/www2/medusa/evagd/test_evagd/availability/condition/completion/db/caches.php", O_RDONLY) = 7
fstat(7, {st_mode=S_IFREG|0755, st_size=1174, ...}) = 0
read(7, "<?php\n// This file is part of Mo"..., 1174) = 1174
close(7)                                = 0
access("/var/www2/medusa/evagd/test_evagd/availability/condition/grade/db/caches.php", F_OK) = 0
openat(AT_FDCWD, "/var/www2/medusa/evagd/test_evagd/availability/condition/grade/db/caches.php", O_RDONLY) = 7
fstat(7, {st_mode=S_IFREG|0755, st_size=1518, ...}) = 0
read(7, "<?php\n// This file is part of Mo"..., 1518) = 1518

Can you help me?
Average of ratings: -
In reply to Dácil Blanco Francisco

Re: Updating a plugin takes several hours

by Marcus Green -
Picture of Core developers Picture of Particularly helpful Moodlers Picture of Plugin developers Picture of Testers
What is the plugin?
Average of ratings: -
In reply to Marcus Green

Re: Updating a plugin takes several hours

by Dácil Blanco Francisco -
Hi. 

This happens with any plugin. Both installing and removing plugins 

Average of ratings: -
In reply to Dácil Blanco Francisco

Re: Updating a plugin takes several hours

by Ken Task -
Picture of Particularly helpful Moodlers
You must have a large site!!!
Load balanced?   What's overall setup?

At tail end of upgrade.php it reports:
== Setting new default values ==

In a small (compared to yours) site with only a few addons,
that's 655 settings.

And mine pauses for quite a few seconds doing that last bit.

How many for your server?
cd /path/to/code/admin/cli/
php cfg.php > allsettings.txt
wc -l allsettings.txt

Cron job is basically halted (can't run cron when in maintenance mode).  Wonder if you server has a lot of backed up adhoc task?

'SoS', Ken

Average of ratings: -
In reply to Ken Task

Re: Updating a plugin takes several hours

by Dácil Blanco Francisco -
Hello.
In production I have the moodle balanced, I have cloned the moodle in preproduction (I only have it on a single server, not balanced) and the behavior is the same.

If I run:
php cfg.php > allsettings.txt
wc -l allsettings.txt -> 842

I run the cron from another server and it works correctly, I don't have many adhoc tasks.
Average of ratings: -
In reply to Dácil Blanco Francisco

Re: Updating a plugin takes several hours

by Ken Task -
Picture of Particularly helpful Moodlers
You've not mentioned your DB ... on a dedicated server I would imagine - all nodes in the LB point to it.   That means there is networking involved.

How about your clone/testing ... dedicated DB still or is the clone pointed to another dedicated DB server?  Depending, could be some networking involved there also.

Dunno for a fact, but, your bottle neck here might be the networking involved.   In mysql config (you've not mentioned DB engine so this might not apply exactly), there is a parameter for skipping network - and config of code server points to an IP address ... not FQDN of dedicated server.
If that parameter not set to skip, DB server does a DNS lookup on every access to it to determine if the request is coming from an allowed networked client.

Above is total guess, but might be worth pursuing some investigations related to networking between code server, DB server. smile

'SoS', Ken

Average of ratings: -
In reply to Dácil Blanco Francisco

Re: Updating a plugin takes several hours

by Ken Task -
Picture of Particularly helpful Moodlers
Not sure this helps but ...

In looking up what ENOENT meant ...

ENOENT. This error is a straightforward one. It means "Error No Entity" and is raised when a specified path (file or directory) does not exist in the filesystem. It is most commonly encountered when performing an operation with the fs module or running a script that expects a specific directory structure.


I see several lines that refer to tinymce editor and the plugins for that editor.
Also see you have 3rd party WIRIS installed?

I have a 4.1.6+ with WIRIS add-on installed.
Going to notifications for site now gives this warning:

MathType for TinyMCE (legacy) is not supported in Moodle 4.2 or higher, you must uninstall the plugin located on "./lib/editor/tinymce/plugins/tiny_mce_wiris" and install the MathType plugin for TinyMCE 6

Clue/hints?

'SoS', Ken

Average of ratings: -
In reply to Ken Task

Re: Updating a plugin takes several hours

by Dácil Blanco Francisco -
Thank you for your help.

The text I added is only a part of what I see in the upgrade process that is running.
I do a strace -p pid to see what is happening since it takes several hours and does not finish sad
I have redis installed and configured but I do not know what is causing this slowness when running php admin/cli/upgrade.php

It used to finish in 10 minutes but now it takes hours.
Average of ratings: -
In reply to Dácil Blanco Francisco

Re: Updating a plugin takes several hours

by Mark Sharp -
Picture of Core developers Picture of Particularly helpful Moodlers Picture of Plugin developers
In your updated code have the file permissions changed? Does the user you're running the code as have access to the files. Usually 644 for files and 755 for folders.
Are there any new plugins in your updated code? Are they doing anything funky?
Average of ratings: -
In reply to Mark Sharp

Re: Updating a plugin takes several hours

by Dácil Blanco Francisco -
Hello.
The permissions if they are the ones you indicate 755. If with the user that I am doing the upgrade I have permissions to access those files.
I am not doing anything weird, this happens to me with version 4.1.4 and only in this moodle in others with the same version of moodle and php, I do not have this problem.
Average of ratings: -
In reply to Dácil Blanco Francisco

Ri: Re: Updating a plugin takes several hours

by Sergio Rabellino -
Picture of Particularly helpful Moodlers Picture of Plugin developers
If you experience a long time to do a task without having your server busy (e.g. cpu load low, database load low) then ask yourself about locking: IMHO this is the most probable cause of wasting time.
During an upgrade, many locks are done at various levels, if the lock procedure has to wait for dead locks (note the space between the two terms), you'll wait until a timeout occurs. Repeat this many times and your total time will increase fastly to the order of minutes.
In my personal experience, a plugin update it's a matter of a bunch of seconds, even with 50000 people in the user list, for me it's not a matter of how big is your moodle.
Average of ratings: -
In reply to Dácil Blanco Francisco

Re: Updating a plugin takes several hours

by Ken Task -
Picture of Particularly helpful Moodlers
How do you acquire core code?
Do you use git?

If so, version 4.1 is now 4.1.6+.

Your current version of moodle is barely above the minimum to be compat with php 8.1.

That's according to:
The row for 4.1.

No need to put your test environment in maintainence mode ... although that wouldn't be a bad idea as cron won't run under maintenance mode.

So suggest trying this if code acquired via git:
cd /path/to/moodlecode/
php admin/cli/maintenance.php --enable
git pull
php admin/cli/upgrade.php
php admin/cli/maintenance.php --enable

Above will do core only ... no addons.

IF that also takes hours ... it shouldn't.
What's left to investigate?
Suggest DB.

'SoS', Ken

Average of ratings: -
In reply to Ken Task

Re: Updating a plugin takes several hours

by Maria Silva -

Hi Ken,

Thanks for the heads-up and the detailed instructions! 👍

I'll definitely give the upgrade a go using the steps you provided. I appreciate your assistance and will keep an eye on the process. 

Average of ratings: -
In reply to Ken Task

Re: Updating a plugin takes several hours

by Dácil Blanco Francisco -
Hi!
I have been testing and I have removed all the themes I had installed in moodle, I had 10 themes added (theme_academi, theme_adaptable, theme_eguru, theme_klass, theme_lambda, theme_moove, theme_snap, theme_trending, theme_classic, theme_boost updated for moodle 4.1).

I have left only the default Moodle Themes. With this the update of a plugin doesn't take 2 minutes.

I reinstalled all the themes and the same problem occurred again.

I left only 5 themes installed and the update of a plugin takes 11 minutes.

Is this logical?
Average of ratings: -
In reply to Dácil Blanco Francisco

Ri: Re: Updating a plugin takes several hours

by Sergio Rabellino -
Picture of Particularly helpful Moodlers Picture of Plugin developers
My suggestion is to add and test one theme at a time, maybe one (and maybe only one) does some strange and long things. The number of theme itself never was an issue at my knowledge.
Average of ratings: -
In reply to Sergio Rabellino

Re: Ri: Re: Updating a plugin takes several hours

by Dácil Blanco Francisco -
Hello, I have found the problem.
Currently, with 8 themes installed in my moodle, if I update a plugin it takes 65 minutes. If I remove the academi theme and update a plugin it takes 9 minutes. I have the academi theme version (v4.3 2023102400), if I look at the version.php file I see the following:
$plugin->version = 2023102400; // This component release level.
$plugin->maturity = MATURITY_STABLE; // This version's maturity level.
$plugin->release = 'v4.3'; // This version's release version.
$plugin->requires = 2022041200; // This version's moodle require release.
$plugin->component = 'theme_academi'; // This component type_name.
$plugin->dependencies = [
'theme_boost' => 2022041900, // This version depended the component and its require release.
];

But in moodle 4.1 the theme boost version is 2022111800, which is lower than required. I think this theme is not compatible with moodle 4.1 although it appears as such in moodle repositories.
Average of ratings: Useful (1)
In reply to Dácil Blanco Francisco

Re: Updating a plugin takes several hours

by Ken Task -
Picture of Particularly helpful Moodlers
+1 to what Sergio said!

'Logical' ... now there is a term ... there's 'human logic' and then there is 'server logc' ... are they the same? :|

As a general rule, I'd pick function (how well it works) over form (how it looks).
There are some themes which are 'heavier' on processing than others.
And there are some that just don't function well with mobile either!
My 2 cents of course! smile
'SoS', Ken


Average of ratings: -