C0D3D3V/Moodle-DL

Unable to lock cache on Moodle v4

nhpf opened this issue · 4 comments

nhpf commented

Description of the bug

When I try to perform a clean run of moodle-dl I get the following output:

Downloading account information
Moodle cookie has expired, an attempt is made to generate a new cookie.
Loaded all databases
Loaded all pages
The following error occurred during execution:
The Moodle System rejected the Request. Details: moodle_exception (Error code: ex_unabletolock, Message: Unable to lock cache.)

Steps to reproduce the issue

Start with an empty environment and run the following commands:

python -m venv venv && source venv/bin/activate
pip install moodle-dl
moodle-dl --init --sso  # Whitelist all courses
moodle-dl

Possible Fix

I tried renewing the token with moodle-dl -nt --sso but after updating the token I still get the same error.
In the past semester my university used Moodle version 3.9.12, but since the upgrade to Moodle version 4.x I haven't been able to download anything with moodle-dl. This may be the cause of the problem.

Technical details

  • OS: Arch Linux
  • Moodle-DL Version 2.3.2.0
  • Moodle Version 4.1.4

By the way, thank you @C0D3D3V, moodle-dl has been a huge time saver for me in the last few years!

C0D3D3V commented

You are welcome ❤
If you run moodle-dl with the verbose option you should maybe see on what request your Moodle Platform can not lock its cache. Depending on that, maybe its a known error because I need to update the API request (for that new Moodle Version) or your Moodle Administrator has to fix it on his side.
Please send me the verbose log.

nhpf commented

Hi @C0D3D3V, the error occurred in this line of main.py, perhaps it is a 4xx error.

Click here to expand the full moodle.dl --verbose output.

2023-09-20 09:25:37 DEBUG {main} moodle-dl version: 2.3.2.0
2023-09-20 09:25:37 DEBUG {main} python version: 3.11.5
2023-09-20 09:25:37 DEBUG {main} Is ffmpeg available: True
2023-09-20 09:25:37 DEBUG {main} Checking for changes for the configured Moodle-Account....
2023-09-20 09:25:37 DEBUG {database} Database Version: 5
2023-09-20 09:25:37 DEBUG {selector_events} Using selector: EpollSelector
2023-09-20 09:25:37 DEBUG {moodle_service} Fetching current Moodle state...
2023-09-20 09:25:37 INFO {moodle_service} Downloading account information
2023-09-20 09:25:37 DEBUG {connectionpool} Starting new HTTPS connection (1): MY_UNI_WEBSITE.com:443
2023-09-20 09:25:37 DEBUG {connectionpool} https://MY_UNI_WEBSITE.com:443 "POST /webservice/rest/server.php?moodlewsrestformat=json&wsfunction=core_webservice_get_site_info HTTP/1.1" 200 None
2023-09-20 09:25:37 DEBUG {moodle_service} Detected moodle version: 2022112804
2023-09-20 09:25:37 DEBUG {connectionpool} Starting new HTTPS connection (1): MY_UNI_WEBSITE.com:443
2023-09-20 09:25:38 DEBUG {connectionpool} https://MY_UNI_WEBSITE.com:443 "POST /webservice/rest/server.php?moodlewsrestformat=json&wsfunction=core_enrol_get_users_courses HTTP/1.1" 200 None
2023-09-20 09:25:38 INFO {common} Loaded all pages
2023-09-20 09:25:38 INFO {common} Loaded all databases
2023-09-20 09:25:38 INFO {common} Loaded all lessons
2023-09-20 09:25:38 DEBUG {request_helper} Details about the failed request:
URL: https://MY_UNI_WEBSITE.com/webservice/rest/server.php?moodlewsrestformat=json&wsfunction=mod_folder_get_folders_by_courses
Body: {'moodlewssettingfilter': 'true', 'moodlewssettingfileurl': 'true', 'courseids': {'0': 5629, '1': 5065, '2': 5833, '3': 6130, '4': 5513}, 'wsfunction': 'mod_folder_get_folders_by_courses', 'wstoken': 'censored'}
2023-09-20 09:25:38 DEBUG {request_helper} Details about the failed request:
URL: https://MY_UNI_WEBSITE.com/webservice/rest/server.php?moodlewsrestformat=json&wsfunction=mod_quiz_get_quizzes_by_courses
Body: {'moodlewssettingfilter': 'true', 'moodlewssettingfileurl': 'true', 'courseids': {'0': 5629, '1': 5065, '2': 5833, '3': 6130, '4': 5513}, 'wsfunction': 'mod_quiz_get_quizzes_by_courses', 'wstoken': 'censored'}
The following error occurred during execution:
The Moodle System rejected the Request. Details: moodle_exception (Error code: ex_unabletolock, Message: Unable to lock cache.)
2023-09-20 09:25:38 DEBUG {mail_service} Mail-Notifications not configured, skipping.
2023-09-20 09:25:38 DEBUG {telegram_service} Telegram-Notifications not configured, skipping.
2023-09-20 09:25:38 DEBUG {xmpp_service} XMPP-Notifications not configured, skipping.
2023-09-20 09:25:38 ERROR {main} Traceback (most recent call last):
File "/home/nick/.local/pipx/venvs/moodle-dl/lib64/python3.11/site-packages/moodle_dl/main.py", line 536, in main
choose_task(config, opts)
File "/home/nick/.local/pipx/venvs/moodle-dl/lib64/python3.11/site-packages/moodle_dl/main.py", line 68, in choose_task
run_main(config, opts)
File "/home/nick/.local/pipx/venvs/moodle-dl/lib64/python3.11/site-packages/moodle_dl/main.py", line 136, in run_main
raise base_err
File "/home/nick/.local/pipx/venvs/moodle-dl/lib64/python3.11/site-packages/moodle_dl/main.py", line 95, in run_main
changed_courses = asyncio.run(moodle.fetch_state(database))
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/lib64/python3.11/asyncio/runners.py", line 190, in run
return runner.run(main)
^^^^^^^^^^^^^^^^
File "/usr/lib64/python3.11/asyncio/runners.py", line 118, in run
return self._loop.run_until_complete(task)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
❯ moodle-dl --verbose
2023-09-20 09:36:08 DEBUG {main} moodle-dl version: 2.3.2.0
2023-09-20 09:36:08 DEBUG {main} python version: 3.11.5
2023-09-20 09:36:08 DEBUG {main} Is ffmpeg available: True
2023-09-20 09:36:08 DEBUG {main} Checking for changes for the configured Moodle-Account....
2023-09-20 09:36:08 DEBUG {database} Database Version: 5
2023-09-20 09:36:08 DEBUG {selector_events} Using selector: EpollSelector
2023-09-20 09:36:08 DEBUG {moodle_service} Fetching current Moodle state...
2023-09-20 09:36:08 INFO {moodle_service} Downloading account information
2023-09-20 09:36:08 DEBUG {connectionpool} Starting new HTTPS connection (1): MY_UNI_WEBSITE.com:443
2023-09-20 09:36:09 DEBUG {connectionpool} https://MY_UNI_WEBSITE.com:443 "POST /webservice/rest/server.php?moodlewsrestformat=json&wsfunction=core_webservice_get_site_info HTTP/1.1" 200 None
2023-09-20 09:36:09 DEBUG {moodle_service} Detected moodle version: 2022112804
2023-09-20 09:36:09 DEBUG {connectionpool} Starting new HTTPS connection (1): MY_UNI_WEBSITE.com:443
2023-09-20 09:36:11 DEBUG {connectionpool} https://MY_UNI_WEBSITE.com:443 "POST /webservice/rest/server.php?moodlewsrestformat=json&wsfunction=core_enrol_get_users_courses HTTP/1.1" 200 None
2023-09-20 09:36:11 DEBUG {request_helper} Details about the failed request:
URL: https://MY_UNI_WEBSITE.com/webservice/rest/server.php?moodlewsrestformat=json&wsfunction=mod_folder_get_folders_by_courses
Body: {'moodlewssettingfilter': 'true', 'moodlewssettingfileurl': 'true', 'courseids': {'0': 5629, '1': 5065, '2': 5833, '3': 6130, '4': 5513}, 'wsfunction': 'mod_folder_get_folders_by_courses', 'wstoken': 'censored'}
The following error occurred during execution:
The Moodle System rejected the Request. Details: moodle_exception (Error code: ex_unabletolock, Message: Unable to lock cache.)
2023-09-20 09:36:11 DEBUG {mail_service} Mail-Notifications not configured, skipping.
2023-09-20 09:36:11 DEBUG {telegram_service} Telegram-Notifications not configured, skipping.
2023-09-20 09:36:11 DEBUG {xmpp_service} XMPP-Notifications not configured, skipping.
2023-09-20 09:36:11 ERROR {main} Traceback (most recent call last):
File "/home/nick/.local/pipx/venvs/moodle-dl/lib64/python3.11/site-packages/moodle_dl/main.py", line 536, in main
choose_task(config, opts)
File "/home/nick/.local/pipx/venvs/moodle-dl/lib64/python3.11/site-packages/moodle_dl/main.py", line 68, in choose_task
run_main(config, opts)
File "/home/nick/.local/pipx/venvs/moodle-dl/lib64/python3.11/site-packages/moodle_dl/main.py", line 136, in run_main
raise base_err
File "/home/nick/.local/pipx/venvs/moodle-dl/lib64/python3.11/site-packages/moodle_dl/main.py", line 95, in run_main
changed_courses = asyncio.run(moodle.fetch_state(database))
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/lib64/python3.11/asyncio/runners.py", line 190, in run
return runner.run(main)
^^^^^^^^^^^^^^^^
File "/usr/lib64/python3.11/asyncio/runners.py", line 118, in run
return self._loop.run_until_complete(task)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/lib64/python3.11/asyncio/base_events.py", line 653, in run_until_complete
return future.result()
^^^^^^^^^^^^^^^
File "/home/nick/.local/pipx/venvs/moodle-dl/lib64/python3.11/site-packages/moodle_dl/moodle/moodle_service.py", line 116, in fetch_state
fetched_mods_files = await fetch_mods_files(mods, courses)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/home/nick/.local/pipx/venvs/moodle-dl/lib64/python3.11/site-packages/moodle_dl/moodle/mods/init.py", line 40, in fetch_mods_files
mods_results = await asyncio.gather(*[mod.fetch_mod_entries(courses_to_load) for mod in mods_to_fetch])
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/home/nick/.local/pipx/venvs/moodle-dl/lib64/python3.11/site-packages/moodle_dl/moodle/mods/common.py", line 57, in fetch_mod_entries
result = await self.real_fetch_mod_entries(courses)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/home/nick/.local/pipx/venvs/moodle-dl/lib64/python3.11/site-packages/moodle_dl/moodle/mods/folder.py", line 20, in real_fetch_mod_entries
await self.client.async_post(
File "/home/nick/.local/pipx/venvs/moodle-dl/lib64/python3.11/site-packages/moodle_dl/moodle/request_helper.py", line 141, in async_post
self.check_json_for_moodle_error(resp_json, url, data)
File "/home/nick/.local/pipx/venvs/moodle-dl/lib64/python3.11/site-packages/moodle_dl/moodle/request_helper.py", line 325, in check_json_for_moodle_error
raise RequestRejectedError(
moodle_dl.moodle.request_helper.RequestRejectedError: The Moodle System rejected the Request. Details: moodle_exception (Error code: ex_unabletolock, Message: Unable to lock cache.)

nhpf commented

UPDATE: moodle-dl started working again ou of the blue. I didn't change anything, so it probably was a configuration issue in my university's website.

C0D3D3V commented

Nice :) Thats what I thought. Because in your log the error happened on two different API Requests it was very likely that your Moodle Platform was wrongly configured.

  • 👍1