The operation timed out while waiting for a lock

The operation timed out while waiting for a lock

by Gareth Jones -
Number of replies: 12

Hi,

"The operation timed out while waiting for a lock."

We get this error when anyone tries to open two particular courses. (Course IDs: 1718 & 2769)

 We upgraded from Moodle 3.5 to 3.7 last month, as well as moving from Ubuntu 16.04 to 18.04LTS. It's likely this issue has only starting happening since the update. No other issues have been noticed.

 Cron runs without any issues

  

I've tried the following:

Restarting the server

Tried to delete the courses via Moodle or via the CLI (using https://github.com/daparker26/moodle-cli-delete-courses), both fail.

Reapplying permissions to the moodledata directory (www-data:www-data, 700 on directory's, 600 on files)

Deleting the contents of moodledata/cache

Running the command: php admin/cli/purge_caches.php

Renaming the "moodledata/lock" directory & creating a new empty "lock" directory with appropriate  permissions.

Adding "$CFG->preventfilelocking = true" to config.php

 

I've done a fair bit of searching on here & google and am now properly out of ideas! Anyone able to help?

 

Version info:

Moodle: 2019052001.08

Release:  '3.7.1+ (Build: 20190823)'

OS: Ubuntu 1804.LTS

PHP: 7.2.19-0ubuntu0.18.04.2

Apache: 2.4.29

MySQL: 5.7.27-0ubuntu0.18.04.1 - (Ubuntu)

  

Thanks

Gareth

 

 

Debug output:

 

Debug info: core_modinfo/build_course_cache_1718

Error code: locktimeout

Stack trace:

•        line 618 of /lib/modinfolib.php: moodle_exception thrown

•        line 457 of /lib/modinfolib.php: call to course_modinfo::get_course_cache_lock()

•        line 418 of /lib/modinfolib.php: call to course_modinfo->__construct()

•        line 2169 of /lib/modinfolib.php: call to course_modinfo::instance()

•        line 163 of /mod/glossary/classes/local/concept_cache.php: call to get_fast_modinfo()

•        line 279 of /mod/glossary/classes/local/concept_cache.php: call to mod_glossary\local\concept_cache::get_course_concepts()

•        line 79 of /filter/glossary/filter.php: call to mod_glossary\local\concept_cache::get_concepts()

•        line 163 of /filter/glossary/filter.php: call to filter_glossary->get_all_concepts()

•        line 176 of /lib/filterlib.php: call to filter_glossary->filter()

•        line 232 of /lib/filterlib.php: call to filter_manager->apply_filter_chain()

•        line 1488 of /lib/weblib.php: call to filter_manager->filter_string()

•        line 464 of /mod/url/locallib.php: call to format_string()

•        line 109 of /mod/url/locallib.php: call to url_get_variable_values()

•        line 247 of /mod/url/lib.php: call to url_get_full_url()

•        line 465 of /course/lib.php: call to url_get_coursemodule_info()

•        line 671 of /lib/modinfolib.php: call to get_array_of_activities()

•        line 463 of /lib/modinfolib.php: call to course_modinfo::inner_build_course_cache()

•        line 418 of /lib/modinfolib.php: call to course_modinfo->__construct()

•        line 2169 of /lib/modinfolib.php: call to course_modinfo::instance()

•        line 163 of /mod/glossary/classes/local/concept_cache.php: call to get_fast_modinfo()

•        line 279 of /mod/glossary/classes/local/concept_cache.php: call to mod_glossary\local\concept_cache::get_course_concepts()

•        line 79 of /filter/glossary/filter.php: call to mod_glossary\local\concept_cache::get_concepts()

•        line 163 of /filter/glossary/filter.php: call to filter_glossary->get_all_concepts()

•        line 176 of /lib/filterlib.php: call to filter_glossary->filter()

•        line 232 of /lib/filterlib.php: call to filter_manager->apply_filter_chain()

•        line 1488 of /lib/weblib.php: call to filter_manager->filter_string()

•        line 282 of /calendar/renderer.php: call to format_string()

•        line 170 of /calendar/classes/external/calendar_upcoming_exporter.php: call to core_calendar_renderer->course_filter_selector()

•        line 139 of /calendar/classes/external/calendar_upcoming_exporter.php: call to core_calendar\external\calendar_upcoming_exporter->get_course_filter_selector()

•        line 125 of /lib/classes/external/exporter.php: call to core_calendar\external\calendar_upcoming_exporter->get_other_values()

•        line 3438 of /calendar/lib.php: call to core\external\exporter->export()

•        line 53 of /blocks/calendar_upcoming/block_calendar_upcoming.php: call to calendar_get_view()

•        line 321 of /blocks/moodleblock.class.php: call to block_calendar_upcoming->get_content()

•        line 230 of /blocks/moodleblock.class.php: call to block_base->formatted_contents()

•        line 1181 of /lib/blocklib.php: call to block_base->get_content_for_output()

•        line 1233 of /lib/blocklib.php: call to block_manager->create_block_contents()

•        line 374 of /lib/blocklib.php: call to block_manager->ensure_content_created()

•        line 3909 of /lib/outputrenderers.php: call to block_manager->region_has_content()

•        line 41 of /theme/fordson/layout/course.php: call to core_renderer->blocks()

•        line 1370 of /lib/outputrenderers.php: call to include()

•        line 1300 of /lib/outputrenderers.php: call to core_renderer->render_page_layout()

•        line 244 of /course/view.php: call to core_renderer->header()


Average of ratings: -
In reply to Gareth Jones

Re: The operation timed out while waiting for a lock

by Howard Miller -
Picture of Core developers Picture of Documentation writers Picture of Particularly helpful Moodlers Picture of Peer reviewers Picture of Plugin developers
Try (more as an experiment than anything) changing the lock factory to database locks.

The relevant settings are in config-dist.php. The table already exists.
Average of ratings: -
In reply to Gareth Jones

Re: The operation timed out while waiting for a lock

by Ken Task -
Picture of Particularly helpful Moodlers

In addition to or alternatives for 'experimenting' ...

Are you allowing different themes for courses?
See in the debug Fordson theme ... is that the latest/greatest?
and the debug lines point to glossary and calendar.

courses 1718 & 2769

Turn on editing, then see if you can't get to editing one of those courses directly via URL ...

https://yoursite/course/view.php?id=1718

or 2769

First line of debug ... build_course_cache_1718

mysql> select id,fullname,theme,cacherev from mdl_course where id=3;
you replace the '3' above with your course id's.

3.7 has default themes of boost and classic.

Could try setting the theme for 1718 to boost.

UPDATE mdl_course SET theme = 'boost' WHERE id = 1718;

Not sure where Fordson would put calendar, but ... boost -> right classic <-left.

The cacherev column is an epoch time stamp and when one makes a change to course, like theme, that is changed.

Strange error ... means exploring possible resolutions. :|

'SoS', Ken

Average of ratings: -
In reply to Ken Task

Re: The operation timed out while waiting for a lock

by Gareth Jones -
Thanks for the reply's.

As far as I'm aware we use a single theme through out Moodle.

I've just tried all of the following:
Updated Moodle & Fordon to the latest versions.
Set the lock factory to database locks (changes have now been reverted).
Changed the default theme to Boost & then to classic.
Turned on editing & browsed to the URL of the course.
Changed the theme for 1718 to Boost & then classic.

Unfortunately I've still got the same problem.

Could you please expand on the following: "Not sure where Fordson would put calendar, but ... boost -> right classic <-left."
I'm not sure what you would like me to try.

Many thanks

Gareth
Average of ratings: -
In reply to Gareth Jones

Re: The operation timed out while waiting for a lock

by Ken Task -
Picture of Particularly helpful Moodlers

Database locks might be too much for database.   Suggest changing that back.

Time to get nasty ... in your moodledata directory you will see a 'locks' directory.   It is safe to manually remove/delete it ... moodle will rebuild it upon next task or cron job run.

For that matter one can also manually remove contents of moodledata/cache moodledata/localcache and moodledata/sessions

They too will be rebuilt.

Also suggest clearing browser cache/cookies for the site.

Run your cron job after above ... cli would be best ... in moodlecode/admin/cli/ run php cron.php [ENTER]   Then hit site with browser.

Fingers crossed!

'SoS', Ken


Average of ratings: -
In reply to Ken Task

Re: The operation timed out while waiting for a lock

by Gareth Jones -
Ok I've just deleted all the directories above, recreated with the appropriate permissions.
Run cron without any issues.
Restarted apache & used a incognito/inPrivate browser session.

Still got the same problem sad

Appreciate the help though smile

Debug info seems to of changed a little:

Debug info: core_modinfo/build_course_cache_1718
Error code: locktimeout
Stack trace:
• line 618 of /lib/modinfolib.php: moodle_exception thrown
• line 457 of /lib/modinfolib.php: call to course_modinfo::get_course_cache_lock()
• line 418 of /lib/modinfolib.php: call to course_modinfo->__construct()
• line 2169 of /lib/modinfolib.php: call to course_modinfo::instance()
• line 163 of /mod/glossary/classes/local/concept_cache.php: call to get_fast_modinfo()
• line 279 of /mod/glossary/classes/local/concept_cache.php: call to mod_glossary\local\concept_cache::get_course_concepts()
• line 79 of /filter/glossary/filter.php: call to mod_glossary\local\concept_cache::get_concepts()
• line 163 of /filter/glossary/filter.php: call to filter_glossary->get_all_concepts()
• line 176 of /lib/filterlib.php: call to filter_glossary->filter()
• line 232 of /lib/filterlib.php: call to filter_manager->apply_filter_chain()
• line 1488 of /lib/weblib.php: call to filter_manager->filter_string()
• line 463 of /mod/url/locallib.php: call to format_string()
• line 109 of /mod/url/locallib.php: call to url_get_variable_values()
• line 247 of /mod/url/lib.php: call to url_get_full_url()
• line 465 of /course/lib.php: call to url_get_coursemodule_info()
• line 671 of /lib/modinfolib.php: call to get_array_of_activities()
• line 463 of /lib/modinfolib.php: call to course_modinfo::inner_build_course_cache()
• line 418 of /lib/modinfolib.php: call to course_modinfo->__construct()
• line 2169 of /lib/modinfolib.php: call to course_modinfo::instance()
• line 163 of /mod/glossary/classes/local/concept_cache.php: call to get_fast_modinfo()
• line 279 of /mod/glossary/classes/local/concept_cache.php: call to mod_glossary\local\concept_cache::get_course_concepts()
• line 79 of /filter/glossary/filter.php: call to mod_glossary\local\concept_cache::get_concepts()
• line 163 of /filter/glossary/filter.php: call to filter_glossary->get_all_concepts()
• line 176 of /lib/filterlib.php: call to filter_glossary->filter()
• line 232 of /lib/filterlib.php: call to filter_manager->apply_filter_chain()
• line 1488 of /lib/weblib.php: call to filter_manager->filter_string()
• line 1223 of /lib/pagelib.php: call to format_string()
line 240 of /course/view.php: call to moodle_page->set_title()

Debug info: core_modinfo/build_course_cache_1718
Error code: locktimeout
Stack trace:
• line 618 of /lib/modinfolib.php: moodle_exception thrown
• line 457 of /lib/modinfolib.php: call to course_modinfo::get_course_cache_lock()
• line 418 of /lib/modinfolib.php: call to course_modinfo->__construct()
• line 2169 of /lib/modinfolib.php: call to course_modinfo::instance()
• line 163 of /mod/glossary/classes/local/concept_cache.php: call to get_fast_modinfo()
• line 279 of /mod/glossary/classes/local/concept_cache.php: call to mod_glossary\local\concept_cache::get_course_concepts()
• line 79 of /filter/glossary/filter.php: call to mod_glossary\local\concept_cache::get_concepts()
• line 163 of /filter/glossary/filter.php: call to filter_glossary->get_all_concepts()
• line 176 of /lib/filterlib.php: call to filter_glossary->filter()
• line 232 of /lib/filterlib.php: call to filter_manager->apply_filter_chain()
• line 1488 of /lib/weblib.php: call to filter_manager->filter_string()
• line 463 of /mod/url/locallib.php: call to format_string()
• line 109 of /mod/url/locallib.php: call to url_get_variable_values()
• line 247 of /mod/url/lib.php: call to url_get_full_url()
• line 465 of /course/lib.php: call to url_get_coursemodule_info()
• line 671 of /lib/modinfolib.php: call to get_array_of_activities()
• line 463 of /lib/modinfolib.php: call to course_modinfo::inner_build_course_cache()
• line 418 of /lib/modinfolib.php: call to course_modinfo->__construct()
• line 2169 of /lib/modinfolib.php: call to course_modinfo::instance()
• line 163 of /mod/glossary/classes/local/concept_cache.php: call to get_fast_modinfo()
• line 279 of /mod/glossary/classes/local/concept_cache.php: call to mod_glossary\local\concept_cache::get_course_concepts()
• line 79 of /filter/glossary/filter.php: call to mod_glossary\local\concept_cache::get_concepts()
• line 163 of /filter/glossary/filter.php: call to filter_glossary->get_all_concepts()
• line 176 of /lib/filterlib.php: call to filter_glossary->filter()
• line 232 of /lib/filterlib.php: call to filter_manager->apply_filter_chain()
• line 1488 of /lib/weblib.php: call to filter_manager->filter_string()
• line 1223 of /lib/pagelib.php: call to format_string()
• line 2801 of /lib/outputrenderers.php: call to moodle_page->set_title()
• line 386 of /lib/setuplib.php: call to core_renderer->fatal_error()
line ? of unknownfile: call to default_exception_handler()


Thanks

Gareth
Average of ratings: -
In reply to Gareth Jones

Re: The operation timed out while waiting for a lock

by Ken Task -
Picture of Particularly helpful Moodlers

Guess ... looks to be an issue with glossary in one or both of those courses?  2 courses using same glossary?

select * from `mdl_glossary where course = 'oneoftroubledcourseids';

There are quite a few tables related to glossary ... might have to check all of them looking for things that aren't the same in other glossaries used in other courses.   :\

Sorry .. haven't run across this one so am attempting sluething without access .. which equates to 100% guess! :|

'SoS', Ken

Average of ratings: -
In reply to Ken Task

Re: The operation timed out while waiting for a lock

by Gareth Jones -
I'm happy trying out your guesses!

Interestingly theirs nothing in the glossary for 1718 & 2679. 3004 is a known working course, which also has nothing in glossary. Some courses do have glossary info, I've listed course 1372 below as an example.


mysql> select * from mdl_glossary where course = '1718';
Empty set (0.00 sec)

mysql> select * from mdl_glossary where course = '2769';
Empty set (0.00 sec)

mysql> select * from mdl_glossary where course = '3004';
Empty set (0.00 sec)

mysql> select * from mdl_glossary where course = '1372';
+-----+--------+----------------------------------------------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+-------------+------------------------+---------------+--------------+-------------+--------------+---------+---------------+----------------+-------------+-----------------+-----------------------+----------------+-----------+------------+---------+-------------+----------+-----------------+------------------+-------+-------------+--------------+-------------------+
| id | course | name | intro | introformat | allowduplicatedentries | displayformat | mainglossary | showspecial | showalphabet | showall | allowcomments | allowprintview | usedynalink | defaultapproval | approvaldisplayformat | globalglossary | entbypage | editalways | rsstype | rssarticles | assessed | assesstimestart | assesstimefinish | scale | timecreated | timemodified | completionentries |
+-----+--------+----------------------------------------------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+-------------+------------------------+---------------+--------------+-------------+--------------+---------+---------------+----------------+-------------+-----------------+-----------------------+----------------+-----------+------------+---------+-------------+----------+-----------------+------------------+-------+-------------+--------------+-------------------+
| 186 | 1372 | Glossary of Links to Useful Websites |

Glossaries are useful for explanation of terms, links to websites, images etc.

 

| 1 | 0 | dictionary | 0 | 1 | 1 | 1 | 1 | 1 | 1 | 0 | default | 0 | 10 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 1338407615 | 1350654796 | 0 |
| 187 | 1372 | Creative ideas for using the Moodle Glossary |

These ideas are from a list of ideas on a Moodle.org chat

| 1 | 0 | dictionary | 0 | 1 | 1 | 1 | 1 | 1 | 1 | 1 | default | 0 | 10 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 1350915892 | 1350915947 | 0 |
| 191 | 1372 | Technology Glossary |

Technology Glossary

| 1 | 0 | dictionary | 0 | 1 | 1 | 1 | 1 | 1 | 0 | 1 | default | 0 | 10 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 1350935246 | 1350936910 | 0 |
+-----+--------+----------------------------------------------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+-------------+------------------------+---------------+--------------+-------------+--------------+---------+---------------+----------------+-------------+-----------------+-----------------------+----------------+-----------+------------+---------+-------------+----------+-----------------+------------------+-------+-------------+--------------+-------------------+
3 rows in set (0.00 sec)

Thanks

Gareth
Average of ratings: -
In reply to Gareth Jones

Re: The operation timed out while waiting for a lock

by Ken Task -
Picture of Particularly helpful Moodlers

Hmmm ... may have sent you down a rabbit hole there ... sorry 'bout that.

Error ...

Debug info: core_modinfo/build_course_cache_1718
Error code: locktimeout

suggest an issue with building a course cache ... 1718? (guess)

In moodledata/cache/cachestore_file/default_application/
there is core_coursemodinfo
ls -ld core_coursemodinfo
Inside core_coursemodinfo one should see directories which appear to be caches
for each course.
On a system am using to trouble shoot your issue I have very few courses
and there are directories for some courses:

133-cache
134-cache
136-cache
1-3-cache
2-3-cache
5-3-cache
6-3-cache

Do you see a 1718-cache?

Suggest being very liberal with permissions on all directories in cache/cachestore_file/default_application

chmod ugo+rwx * -R

Am really out of guesses!

'SoS', Ken

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

Re: The operation timed out while waiting for a lock

by Gareth Jones -
The three character cache is short for 123x course ID.

So course 1716 belongs in directory 171-cache.

There is no 1718, inside of 171-cache. The user/group is currently www-data:www-data with 777 set (default), so nothing to change there.

All of the .cache files are named courseID-SomeKindOfID
EG:
1714-f972a21502094044288820dcf19e326e.cache
1716-f972a21502094044288820dcf19e326e.cache

So I manually created 1718-f972a21502094044288820dcf19e326e.cache & got a different error:
Coding error detected, it must be fixed by a programmer: Failed to unserialise data from file. Either failed to read, or failed to write.

I then copied the contents of 1714-f972a21502094044288820dcf19e326e.cache into 1718-f972a21502094044288820dcf19e326e.cache

THE COURSE LOADS!!!
The course has the correct title/header, but all the course information is for 1714 (obviously using the cache).
But is does now allow me to delete the courses. Amazing!

Moodle must of had some issue with creating the cache for those two courses, even though the permission is 777 - very odd.

We have a user that created the courses a few years back, that also had some other issues with opening other courses (as an admin we could open them fine), I've done some quick tests & the problem appears to be resolved. Will confirm with the user tomorrow.

Thanks so much for your help, I owe you a beer!

Gareth
Average of ratings: -
In reply to Gareth Jones

Re: The operation timed out while waiting for a lock

by Ken Task -
Picture of Particularly helpful Moodlers

Oh, no!   All I did was point ... you solved it ... and I might add very clever!

So ... community (those that might run into similar) owes you a beer!


'SoS', Ken

Average of ratings: -
In reply to Gareth Jones

Re: The operation timed out while waiting for a lock

by Marcos Gtz -

I had a similar problem. I tried delete temp and cache folders, also data/lock, but I got the same error.


The problem? 1 file inside "data/lock" was locking, maybe a process was locking that file

The solution? I restarted linux

Average of ratings: -