Uploaded image for project: 'Moodle'
  1. Moodle
  2. MDL-70137

MUC config can become corrupt in certain cases

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: Closed
    • Priority: Blocker
    • Resolution: Fixed
    • Affects Version/s: 3.8.5, 3.9.2, 3.10
    • Fix Version/s: 3.8.6, 3.9.3
    • Component/s: Caching
    • Labels:
    • Testing Instructions:
      Hide

      This is an extremely difficult one to test
      I would recommend running the tests through before applying the patch to understand the issue as a whole.

      Testing before patch

      1. Open a new terminal window and tail the Apache error log. You will need a command like:

        tail -F /var/log/www/error.log
        

      2. Open another new terminal window and navigate to the moodledata directory.
      3. Tail the MUC configuration file:

        tail -F muc/config.php
        

        Note: Use the -F not a lowercase!!

      4. Open two windows in different browsers
      5. Log in as admin to both
      6. In the first one, open the address bar and type http://pathtomoodle/admin/index.php but DO NOT VISIT YET
      7. Copy the URL into the address bar of the second window
      8. Apply the pre-70137.patch file:

        git am pre-70137.patch
        

      9. Keep an eye on your apache error log
      10. In the first browser visit the link
      11. Watch in the error log until it says "LOAD THE OTHER BROWSER TAB NOW!!!"
      12. Immediately visit the link in the second browser
      13. Watch in the error log until it says "LOAD THE OTHER BROWSER TAB NOW!!!"
        1. Confirm that you see see "It has a size of 0" in the output
      14. Open the muc/config.php and jump to the bottom
        1. Note: the locks array is empty
      15. Reset your git repo to get rid of the testing commit

        git reset --hard HEAD~
        

      16. Refresh the admin/index.php in one of the browsers
        1. Enjoy the errors you see
      17. To tidy up, just remove the muc/config.php file
      18. Refresh the admin/index.php in one of the browsers
      19. No errors now

      Testing after applying the patch

      1. Open a new terminal window and tail the Apache error log. You will need a command like:

        tail -F /var/log/www/error.log
        

      2. Open another new terminal window and navigate to the moodledata directory.
      3. Tail the MUC configuration file:

        tail -F muc/config.php
        

        Note: Use the -F not a lowercase!!

      4. Open two windows in different browsers
      5. Log in as admin to both
      6. In the first one, open the address bar and type http://pathtomoodle/admin/index.php but DO NOT VISIT YET
      7. Copy the URL into the address bar of the second window
      8. Apply the post-70137.patch file:

        git am post-70137.patch
        

      9. Keep an eye on your apache error log
      10. In the first browser visit the link
      11. Watch in the error log until it says "LOAD THE OTHER BROWSER TAB NOW!!!"
      12. Immediately visit the link in the second browser
      13. Watch in the error log until it says "LOAD THE OTHER BROWSER TAB NOW!!!"
        1. Confirm that you see see "It has a size of 6" in the output
      14. Open the muc/config.php and jump to the bottom
        1. Note: the locks array now has content
      15. Reset your git repo to get rid of the testing commit

        git reset --hard HEAD~
        

      16. Refresh the admin/index.php in one of the browsers
        1. Confirm you had no errors
      Show
      This is an extremely difficult one to test I would recommend running the tests through before applying the patch to understand the issue as a whole. Testing before patch Open a new terminal window and tail the Apache error log. You will need a command like: tail -F /var/log/www/error.log Open another new terminal window and navigate to the moodledata directory. Tail the MUC configuration file: tail -F muc/config.php Note: Use the -F not a lowercase!! Open two windows in different browsers Log in as admin to both In the first one, open the address bar and type http://pathtomoodle/admin/index.php but DO NOT VISIT YET Copy the URL into the address bar of the second window Apply the pre-70137.patch file: git am pre-70137.patch Keep an eye on your apache error log In the first browser visit the link Watch in the error log until it says " LOAD THE OTHER BROWSER TAB NOW!!! " Immediately visit the link in the second browser Watch in the error log until it says " LOAD THE OTHER BROWSER TAB NOW!!! " Confirm that you see see " It has a size of 0 " in the output Open the muc/config.php and jump to the bottom Note: the locks array is empty Reset your git repo to get rid of the testing commit git reset --hard HEAD~ Refresh the admin/index.php in one of the browsers Enjoy the errors you see To tidy up, just remove the muc/config.php file Refresh the admin/index.php in one of the browsers No errors now Testing after applying the patch Open a new terminal window and tail the Apache error log. You will need a command like: tail -F /var/log/www/error.log Open another new terminal window and navigate to the moodledata directory. Tail the MUC configuration file: tail -F muc/config.php Note: Use the -F not a lowercase!! Open two windows in different browsers Log in as admin to both In the first one, open the address bar and type http://pathtomoodle/admin/index.php but DO NOT VISIT YET Copy the URL into the address bar of the second window Apply the post-70137.patch file: git am post-70137.patch Keep an eye on your apache error log In the first browser visit the link Watch in the error log until it says " LOAD THE OTHER BROWSER TAB NOW!!! " Immediately visit the link in the second browser Watch in the error log until it says " LOAD THE OTHER BROWSER TAB NOW!!! " Confirm that you see see " It has a size of 6 " in the output Open the muc/config.php and jump to the bottom Note: the locks array now has content Reset your git repo to get rid of the testing commit git reset --hard HEAD~ Refresh the admin/index.php in one of the browsers Confirm you had no errors
    • Affected Branches:
      MOODLE_310_STABLE, MOODLE_38_STABLE, MOODLE_39_STABLE
    • Fixed Branches:
      MOODLE_38_STABLE, MOODLE_39_STABLE
    • Pull 3.9 Branch:
      MDL-70137-39-2
    • Pull 3.10 Branch:
      MDL-70137-310-2
    • Pull Master Branch:
      MDL-70137-master-2

      Description

      See notes on MDLQA-15383 and MDL-51111. Summary below:

      From David Mudrák (@mudrd8mz)

      Everything went well with the upgrade up until 1 minute and 10 seconds when it failed with:

      ++ Success (0.43 seconds) ++
      -->auth_ldap
      ++ Success (0.45 seconds) ++
      -->enrol_fee
      ++ Success ++
      -->enrol_self
      Default exception handler: Unable to save the cache config to file. Debug: Unable to open the cache config file.
      Error code: ex_configcannotsave
      * line 115 of /cache/locallib.php: cache_exception thrown
      * line 578 of /cache/locallib.php: call to cache_config_writer->config_save()
      * line 505 of /cache/locallib.php: call to cache_config_writer->write_definitions_to_cache()
      * line 458 of /cache/classes/factory.php: call to cache_config_writer::update_definitions()
      * line 218 of /cache/disabledlib.php: call to cache_factory->create_definition()
      * line 254 of /cache/disabledlib.php: call to cache_factory_disabled->create_definition()
      * line 182 of /cache/classes/loaders.php: call to cache_factory_disabled->create_cache_from_definition()
      * line 273 of /lib/accesslib.php: call to cache::make()
      * line 1433 of /lib/accesslib.php: call to accesslib_clear_role_cache()
      * line 1203 of /lib/accesslib.php: call to assign_capability()
      * line 2343 of /lib/accesslib.php: call to assign_legacy_capabilities()
      * line 709 of /lib/upgradelib.php: call to update_capabilities()
      * line 1922 of /lib/upgradelib.php: call to upgrade_plugins()
      * line 193 of /admin/cli/upgrade.php: call to upgrade_noncore()
       
      !!! Unable to save the cache config to file. !!!
      !! Unable to open the cache config file.
      Error code: ex_configcannotsave !!
      !! Stack trace: * line 115 of /cache/locallib.php: cache_exception thrown
      * line 578 of /cache/locallib.php: call to cache_config_writer->config_save()
      * line 505 of /cache/locallib.php: call to cache_config_writer->write_definitions_to_cache()
      * line 458 of /cache/classes/factory.php: call to cache_config_writer::update_definitions()
      * line 218 of /cache/disabledlib.php: call to cache_factory->create_definition()
      * line 254 of /cache/disabledlib.php: call to cache_factory_disabled->create_definition()
      * line 182 of /cache/classes/loaders.php: call to cache_factory_disabled->create_cache_from_definition()
      * line 273 of /lib/accesslib.php: call to cache::make()
      * line 1433 of /lib/accesslib.php: call to accesslib_clear_role_cache()
      * line 1203 of /lib/accesslib.php: call to assign_capability()
      * line 2343 of /lib/accesslib.php: call to assign_legacy_capabilities()
      * line 709 of /lib/upgradelib.php: call to update_capabilities()
      * line 1922 of /lib/upgradelib.php: call to upgrade_plugins()
      * line 193 of /admin/cli/upgrade.php: call to upgrade_noncore()
       !!
       
      real    1m10.455s
      user    0m1.764s
      sys     0m1.228
      

      I tried to simply re-run the upgrade with eventually finished after another 2m40sec.

      However, during the post-upgrade check I noticed that the MUC config file was rewritten and all our caching configuration was lost. There was no store configured, nothing.

      Luckily for us, we had a relatively fresh backup of the config file so we were able to recover this time.

      But I suspect there went something wrong during the upgrade when the disabled caching tried to write the MUC config.php

      Marking this as Failed to raise attention to it. Sorry and thank you.

      Then

      The problem persists. As reported by Helen Foster in MDLSITE-6271 - when we visit admin/index.php we still get a set of messages like:

      Your cache configuration file is out of date and needs to be refreshed.
       
          line 93 of /cache/locallib.php: call to debugging()
          line 578 of /cache/locallib.php: call to cache_config_writer->config_save()
          line 505 of /cache/locallib.php: call to cache_config_writer->write_definitions_to_cache()
          line 458 of /cache/classes/factory.php: call to cache_config_writer::update_definitions()
          line 218 of /cache/disabledlib.php: call to cache_factory->create_definition()
          line 254 of /cache/disabledlib.php: call to cache_factory_disabled->create_definition()
          line 182 of /cache/classes/loaders.php: call to cache_factory_disabled->create_cache_from_definition()
          line 75 of /lib/classes/string_manager_standard.php: call to cache::make()
          line 7304 of /lib/moodlelib.php: call to core_string_manager_standard->__construct()
          line 7432 of /lib/moodlelib.php: call to get_string_manager()
          line 8286 of /lib/moodlelib.php: call to get_string()
          line 8306 of /lib/moodlelib.php: call to moodle_getlocale()
          line 904 of /lib/setup.php: call to moodle_setlocale()
          line 172 of /config.php: call to require_once()
          line 88 of /admin/index.php: call to require()
       
      Your cache configuration file is out of date and needs to be refreshed.
       
          line 93 of /cache/locallib.php: call to debugging()
          line 578 of /cache/locallib.php: call to cache_config_writer->config_save()
          line 505 of /cache/locallib.php: call to cache_config_writer->write_definitions_to_cache()
          line 458 of /cache/classes/factory.php: call to cache_config_writer::update_definitions()
          line 218 of /cache/disabledlib.php: call to cache_factory->create_definition()
          line 254 of /cache/disabledlib.php: call to cache_factory_disabled->create_definition()
          line 182 of /cache/classes/loaders.php: call to cache_factory_disabled->create_cache_from_definition()
          line 2541 of /lib/accesslib.php: call to cache::make()
          line 2525 of /lib/accesslib.php: call to get_all_capabilities()
          line 452 of /lib/accesslib.php: call to get_capability_info()
          line 772 of /admin/index.php: call to has_capability()
      

      followed by "Error - Unable to save the cache config to file."

      He notes that preventing the config_writer from saving the file if cache is disabled and there is a file addresses these issues.

        Attachments

        1. muc-config.php-correct
          28 kB
        2. muc-config.php-empty
          18 kB
        3. muc-config.php-empty-with-sharing-options
          24 kB
        4. muc-config.php-wo-sharingoptions
          25 kB
        5. post-70137.patch
          3 kB
        6. pre-70137.patch
          3 kB
        7. screenshot-1.png
          screenshot-1.png
          38 kB

          Issue Links

            Activity

              People

              Assignee:
              dobedobedoh Andrew Lyons
              Reporter:
              dobedobedoh Andrew Lyons
              Peer reviewer:
              Eloy Lafuente (stronk7) Eloy Lafuente (stronk7)
              Integrator:
              Víctor Déniz Falcón Víctor Déniz Falcón
              Tester:
              Víctor Déniz Falcón Víctor Déniz Falcón
              Participants:
              Component watchers:
              Matteo Scaramuccia, Amaia Anabitarte, Carlos Escobedo, Ferran Recio, Ilya Tregubov, Sara Arjona (@sarjona)
              Votes:
              1 Vote for this issue
              Watchers:
              9 Start watching this issue

                Dates

                Created:
                Updated:
                Resolved:
                Fix Release Date:
                9/Nov/20

                  Time Tracking

                  Estimated:
                  Original Estimate - Not Specified
                  Not Specified
                  Remaining:
                  Remaining Estimate - 0 minutes
                  0m
                  Logged:
                  Time Spent - 1 day, 4 hours, 30 minutes
                  1d 4h 30m