? Language Change bug PR-4.3-dev Pending

User tests: Successful: Unsuccessful:

avatar Fedik
Fedik
14 Aug 2023

Summary of Changes

Kind of a fix for failed upgrade that report success.
I have added error collector, the most messages are loged now.
Also updated the "complete" layout, now it will show a meesage about error instead of "success".

Note: it is just a work around. A proper fix require more coding/re-coding of upgrade process.

Main issue that all messages like

echo Text::sprintf('JLIB_DATABASE_ERROR_FUNCTION_FAILED', $e->getCode(), $e->getMessage()) . '<br>';

are lost, and after upgrade is finished, the complete upgrade page shows just a static "Success"
<?php echo Text::sprintf('COM_JOOMLAUPDATE_VIEW_COMPLETE_MESSAGE', '&#x200E;' . JVERSION); ?>

Testing Instructions

Download upgrade packge from the pr.
In joomla 3 in any Fields plugin add throw new Exception('Plugin test error'); in plugin constructor.
Run joomla upgrade, with manual upload of upgrade packge.

public function __construct(&$subject, $config)
{
  parent::__construct($subject, $config);
  throw new Exception('Error error, Fields plugin');
}

Addittionaly, try to add throw new Exception('Update test error'); in coupe of upgrade methods in administrator/components/com_admin/script.php

Actual result BEFORE applying this Pull Request

The finalise step will crash with messed up page.
Upgrade log reaport about "Files deleting blabla", but no error info.

Expected result AFTER applying this Pull Request

The finalise step are finished.The completion page show a message about unsuccessful update.
Upgrade log contains logs for error 'Plugin test error'.

avatar joomla-cms-bot joomla-cms-bot - change - 14 Aug 2023
Category Administration com_admin com_joomlaupdate
avatar Fedik Fedik - open - 14 Aug 2023
avatar Fedik Fedik - change - 14 Aug 2023
Status New Pending
avatar joomla-cms-bot joomla-cms-bot - change - 16 Aug 2023
Category Administration com_admin com_joomlaupdate Administration com_admin com_joomlaupdate Language & Strings Libraries
avatar Fedik Fedik - change - 16 Aug 2023
Labels Added: bug PR-4.3-dev
45b3ba8 16 Aug 2023 avatar Fedik phpcs
avatar Fedik Fedik - change - 16 Aug 2023
Labels Added: Language Change
avatar Fedik Fedik - change - 16 Aug 2023
The description was changed
avatar Fedik Fedik - edited - 16 Aug 2023
avatar Fedik Fedik - change - 16 Aug 2023
The description was changed
avatar Fedik Fedik - edited - 16 Aug 2023
avatar Fedik
Fedik - comment - 16 Aug 2023

Addittionaly, if we can get this joomla-framework/event#35 in, we also can debug/ignore a broken plugins while upgrade.

69a547c 16 Aug 2023 avatar Fedik phpcs
avatar Fedik Fedik - change - 16 Aug 2023
The description was changed
avatar Fedik Fedik - edited - 16 Aug 2023
avatar Fedik Fedik - change - 16 Aug 2023
The description was changed
avatar Fedik Fedik - edited - 16 Aug 2023
avatar richard67
richard67 - comment - 20 Aug 2023

I've made a few tests, and more will follow.

I've tested with updating from 4.3.1 stable so that there are some update SQL scripts to be executed.

For testing I have created custom update URLs and modified update packages based on the nightly build from today morning for the actual results without this PR applied, and the same based on the update package buit by Drone for this PR today.

Each of the packages has a modification to cause an error specific for the test. The modifications are described below for each test.

The links to the update packages and corresponding custom update site URLs are given below and will remain online for some time so other testers can use them, too.

Test 1: Cause database error in fixTemplateMode method of script.php so preflight fails with exception

Modification in the update packages in file "administrator/components/com_admin/script.php":

    protected function fixTemplateMode(): void
    {
        $db = Factory::getContainer()->get('DatabaseDriver');

        foreach (['atum', 'cassiopeia'] as $template) {
            $clientId = $template === 'atum' ? 1 : 0;
            $query    = $db->getQuery(true)
                ->update($db->quoteName('#__template_styles'))
                // Test PR #41367: Simulate database error
                // ->set($db->quoteName('inheritable') . ' = 1')
                ->set($db->quoteName('not_existing_column') . ' = 1')
                // Test PR #41367 end
                ->where($db->quoteName('template') . ' = ' . $db->quote($template))
                ->where($db->quoteName('client_id') . ' = ' . $clientId);

            try {
                $db->setQuery($query)->execute();
            } catch (Exception $e) {
                $this->collectError(__METHOD__, $e);
            }
        }
    }

This shall simulate any kind of database error happening at that place.

The above code is from the package with the PR applied, in the package without the PR it is done accordingly but of course without the changes from this PR.

Actual result without the PR applied

  • Custom update URL: obsolete link removed
  • Update package: obsolete link removed

Backend after the update:
test-1_actual-result

The "joomla_update.php" log file doesn't show anything special, i.e. no differences to the log from a normal update without errors beside of the time stamps, the update zip name and the user ID. All steps of the update have been processed.

Expected result with the PR applied

  • Custom update obsolete link removed
  • Update package: obsolete link removed

Backend after the update:
test-1_expected-result

The backend shows a page with is blank except of error messages or alerts, i.e. it is missing all backend menus and modules because using the system template.

Reloading the page doesn't change that.

Only using the "back" button of the browser 2 times or more or changing the URL in the browser's URL field e.g. to administrator/index.php without any options brings us back to the administrator template.

The "joomla_update.php" log file shows 2 errors as the error happens 2 times, one time for each core template. All steps of the update have been processed. See here the comparison, left side = with PR applied, right side = without PR applied:
compare-update-log_test-1_expected-to-actual

Test 2: Let preflight method of script.php fail e.g. due to broken manifest cache and return false.

Modification in the update packages in file "administrator/components/com_admin/script.php":

    public function preflight($action, $installer)
    {
        if ($action === 'update') {
            // Get the version we are updating from
            /* Test PR 41367: Simulate missing or broken manifest
            if (!empty($installer->extension->manifest_cache)) {
                $manifestValues = json_decode($installer->extension->manifest_cache, true);

                if (array_key_exists('version', $manifestValues)) {
                    $this->fromVersion = $manifestValues['version'];

                    // Ensure templates are moved to the correct mode
                    $this->fixTemplateMode();

                    return true;
                }
            }
            Test PR 41367 end */

            return false;
        }

        return true;
    }

This shall simulate the preflight method failing due to a missing or incomplete manifest cache.

Actual result without the PR applied

  • Custom update URL: obsolete link removed
  • Update package: obsolete link removed

Backend after the update:
test-2_actual-result

The backend shows an alert with an unspecific warning.

The "joomla_update.php" log file shows no warning or error. But compared to the log file from a successful update you can see that the SQL update scripts have not been run. See following comparison, left side = log from this test without PR applied, right side = log from a successful update:
compare-update-log_test-2_actual-to-no-error

Expected result with the PR applied

  • Custom update URL: obsolete link removed
  • Update package: obsolete link removed

Backend after the update:
test-2_expected-result

The backend shows a page with is blank except of error messages or alerts, i.e. it is missing all backend menus and modules because using the system template.

Reloading the page doesn't change that except of closing the yellow alert, which is the same as shown without this PR applied.

Only using the "back" button of the browser 2 times or more or changing the URL in the browser's URL field e.g. to administrator/index.php without any options brings us back to the administrator template.

The "joomla_update.php" log file shows 1 error and 1 warning. Same as without the PR applied, the SQL update scripts have been not processed. See here the comparison, left side = with PR applied, right side = without PR applied:
compare-update-log_test-2_expected-to-actual

Test 3: Cause an SQL error in an update SQL script (new script 4.3.4-2023-08-20.sql).

New update SQL scripts "4.3.4-2023-08-20.sql" with an erroneous SQL statement in the update packages.

This shall simulate any kind of SQL or database error during the SQL updates.

Actual result without the PR applied

  • Custom update URL: obsolete link removed
  • Update package: obsolete link removed

Backend after the update:
test-3_actual-result

The backend shows an alert about the SQL error.

The "joomla_update.php" log file shows the SQL error and reports the incomplete SQL updates.

Expected result with the PR applied

  • Custom update URL: obsolete link removed
  • Update package: obsolete link removed

Backend after the update:
test-3_expected-result

The backend shows a page with is blank except of error messages or alerts, i.e. it is missing all backend menus and modules because using the system template.

Reloading the page doesn't change that except of closing the yellow alert, which is the same as shown without this PR applied.

Only using the "back" button of the browser 2 times or more or changing the URL in the browser's URL field e.g. to administrator/index.php without any options brings us back to the administrator template.

The "joomla_update.php" log file shows 1 warning and 1 error, but they are some kind of redundant to the logs reported already without the PR applied and which are still there when the PR is applied. See here the comparison, left side = with PR applied, right side = without PR applied:
compare-update-log_test-3_expected-to-actual

Summary

In Test 1, without this PR, neither the backend nor the update log file show anything about the error, while with this PR both do.

For Test 2 the same applies as for Test 1, except that without the PR you can see in the update log file that the SQL updates have not been executed if you are an expert on database update.

My thoughts:

  1. I'm not sure if it's a good idea to always use the system template, except if we can extend it by a link to the administrator/index.php without any options, so we navigate to the home dashboard.
  2. The logs in test 3 added by this PR seem to be redundant, but that might not be the case in every scenario, so I am ok with them. @Fedik But maybe you want to change something there since it seems that SQL errors in the update SQL scripts are already handled well without your PR.

@Fedik More tests will follow sooner or later, but maybe you want to change something after these first results, so I will wait a bit for your feedback.

avatar Fedik
Fedik - comment - 20 Aug 2023

@richard67 thanks, that a huge test ;)

I'm not sure if it's a good idea to always use the system template

This is in purpose, to increase a chance to see the result page of failed upgrade.
And to avoid modules rendering, in case some SQL fail to update one of them. Example fail of upgrade #__menu schema will lead to crash of the menu module.

The logs in test 3 added by this PR seem to be redundant,

I just replaced all echo to do log. However existing log to jerror category produce a message.
I tried to minimise changes in behavior. I would keep it as it is for 4.x.

It still would need a proper refactoring of whole upgrade code, there many strange pieces.
The upgrade process managed to survive all the way from Joomla 1.6 😄

Did you tried to test CLI update?

UPD. I will try to add "Dashboard button", or something like that.

avatar richard67
richard67 - comment - 20 Aug 2023

Did you tried to test CLI update?

No, not yet. Meanwhile I have updated my custom update URLs so they can also be used for updating from 3.10.12. Will provide more test in the next days.

avatar HLeithner HLeithner - change - 20 Aug 2023
Title
Work around a successful upgrade with silent errors
[4.3] Work around a successful upgrade with silent errors
avatar HLeithner HLeithner - edited - 20 Aug 2023
avatar Fedik
Fedik - comment - 22 Aug 2023

I have added "back button", and changed message to be more helpfull.
Screenshot 2023-08-22_20-13-43

@brianteeman please check the message text, thanks!

ec04fcf 22 Aug 2023 avatar Fedik phpcs
2af0bec 22 Aug 2023 avatar Fedik logs
avatar brianteeman
brianteeman - comment - 22 Aug 2023

the english is fine if thats the message you want to say. i have no opinion on that

avatar Fedik
Fedik - comment - 23 Aug 2023

I have added a test for logging before download/upload.
This will work for future updates 4+, but 3 => 4 still will fail when log is not writable.

avatar richard67
richard67 - comment - 25 Aug 2023

@Fedik In the testing instructions you wrote:

In joomla 3 in any Fields plugin add throw new Exception('Plugin test error'); in plugin constructor.

But on a 3.10.12, none of the fields plugins has a constructor. Did you mean we should add a constructor with that code?

Or could we also modify e.g. a content plugin which has already a constructor?

avatar Fedik
Fedik - comment - 25 Aug 2023

Yes, I meant "add" :)
Here a code for copy/paste:

public function __construct(&$subject, $config)
{
  parent::__construct($subject, $config);
  throw new Exception('Error error, Fields plugin');
}

Added to description.

Or could we also modify e.g. a content plugin which has already a constructor?

No, the content plugin not loaded while upgrade, I already tested.

avatar Fedik Fedik - change - 25 Aug 2023
The description was changed
avatar Fedik Fedik - edited - 25 Aug 2023
avatar richard67
richard67 - comment - 27 Aug 2023

@Fedik I've tried the thing with the constructor of a core field plugin, but that doesn't cause an error. I think it's because the core plugin is updated with the CMS update. I've tested with that constructor in file plugins/fields/calendar/calendar.php inside the class at the top. The file is removed due to the changed plugin structure, but that happens after the repeatable fields plugin migration where I expect the error to happen. But I think the fields component is already the updated one and so loads the new, updated plugin file without the error.

Can it be that it needs a 3rd party plugin for this test?

avatar Fedik
Fedik - comment - 27 Aug 2023

The file is removed due to the changed plugin structure,

This is the reason, the files removed by administrator/components/com_joomlaupdate/restore_finalisation.php

avatar richard67
richard67 - comment - 27 Aug 2023

@Fedik I have just created an installable broken fields plugin zip which can be installed on 3.10: https://test5.richard-fath.de/plg_fields_brokentest.zip . Will test soon.

avatar richard67
richard67 - comment - 27 Aug 2023

@Fedik Hmm, seems something's missing. The plugin which I've created (see link in my previous comment) also doesn't create any error when being installed and then enabled on 3.10 before the update.

avatar Fedik
Fedik - comment - 27 Aug 2023

try this:
ttest.zip

avatar Fedik
Fedik - comment - 27 Aug 2023

Your plugin have wrong class name PlgFieldsCalendar should be PlgFieldsBrokentest

avatar richard67
richard67 - comment - 27 Aug 2023

Ouch

avatar richard67
richard67 - comment - 27 Aug 2023

@Fedik With your package I also don't get an error. Can it be that it needs to create a field based on this plugin before updating?

avatar Fedik
Fedik - comment - 27 Aug 2023

Should work, I have tested with it many times,
did you enabled the plugin after installation? 😉

avatar Fedik
Fedik - comment - 27 Aug 2023

Ah, make sure you have at least 1 repeatable field created. I totaly forgot it.

avatar richard67
richard67 - comment - 27 Aug 2023

Should work, I have tested with it many times, did you enabled the plugin after installation? 😉

@Fedik Yes, I enabled it.

avatar richard67
richard67 - comment - 27 Aug 2023

Ah, make sure you have at least 1 repeatable field created

That's it! Thanks.

avatar Fedik
Fedik - comment - 27 Aug 2023

Also make 1 article that use this field

avatar richard67
richard67 - comment - 27 Aug 2023

Now I can reproduce the error. It needs to process in following order:

  1. On 3.10.12 create a repeatable field for articles and use it in an article.
  2. Install the bad fields plugin.
  3. Enable the bad fields plugin.
  4. Do the core update.
  5. Check in database in the fields table that the repeatable field has not been converted.
avatar Fedik
Fedik - comment - 9 Sep 2023

The same changes for 5.0 branch is there #41690

avatar richard67
richard67 - comment - 10 Sep 2023

Here are my detailed test results of 9 tests which I've made in order of their occurrence in the execution flow of the update steps.

For some of the tests I have created custom update URLs and modified update packages based on the nightly build from yesterday morning for the actual results without this PR applied, and the same based on the update package built by Drone for this PR yesterday.

The links to the update packages and corresponding custom update site URLs are given below and will remain online for some time so other testers can use them, too.

Test 1: Normal update from 3.10.12 or 4.3.1 without any errors

This test doesn't require changes for testing on the update packages, but I have created custom update URLs for unmodified update packages as of yesterday for easier comparison of the logs with the results from other tests.

  1. Make sure there is no file "administrator/logs/joomla_update.php".
  2. Update from 3.10.12 or 4.3.1 to the latest 4.3 nightly build.
  3. Save file "administrator/logs/joomla_update.php" for later comparison.
  4. Repeat steps 1 to 3, but in thep 2 update to the package or custom update URL created by Drone for this PR.
  5. Compare the files saved in step 3.

Afther the test, keep the files saved in step 3 for later comparison with the file from later tests.

Actual result without the PR applied

Update succeeds without any error.

Expected result with the PR applied

Update succeeds without any error.

Update logs without PR and with PR differ only by timestamps, package name and user ID.

Test 2: Update from 4.3-dev to 4.4-dev with log folder not writable

This test doesn't require any modified update packages and custom update URLs.

  1. For the actual result, use an installation of a current 4.3-dev or nightly build. For the expected result, use a 4.3-dev installation which has this PR applied.
  2. Make sure there is no file "administrator/logs/joomla_update.php".
  3. Change ownership and permissions of folder "administrator/logs" so that it's not writeable for the webserver user and the permissons can't be changed by that user. On Linux in the Joomla root folder:
sudo chown root:root administrator/logs
sudo chmod 644 administrator/logs
  1. Update to the latest 4.4-dev nightly build.

For reverting the changes from step 3 after the test, do on Linux (use different user or group than "www-data" depending on your server):

sudo chown www-data:www-data administrator/logs
chmod 775 administrator/logs
  1. Check e.g. with phpMyAdmin in your database if the 4.4 update SQL script https://github.com/joomla/joomla-cms/blob/4.4-dev/administrator/components/com_admin/sql/updates/mysql/4.4.0-2023-05-08.sql has run. Replace the #__ by your table prefix.
SELECT * FROM `#__extensions` WHERE `name` = 'plg_quickicon_eos';

Actual result without the PR applied

The update seems to run all steps, at least you can see for a short moment that it runs the last cleanup step.

But then it ends with an error:
test-2_actual-result

When you use the "Return to Dashboard" button, the backend seems to be ok.

But the 4.4 update SQL script has not run. The plg_quickicon_eos record has not been inserted into the #__extensions table.

As there is no logfile from the update, the user doesn't know about that.

When 4.4-dev will have more update SQL scripts which are not run, the backend might not be usable or the site might be broken, depending on the lost SQL changes.

Expected result with the PR applied

The update is not started, and an appropriate error message is shown:
test-2_expected-result

Test 3: Cause database error in fixTemplateMode method of script.php so preflight fails with exception

Modification in the update packages in file "administrator/components/com_admin/script.php":

    protected function fixTemplateMode(): void
    {
        $db = Factory::getContainer()->get('DatabaseDriver');

        foreach (['atum', 'cassiopeia'] as $template) {
            $clientId = $template === 'atum' ? 1 : 0;
            $query    = $db->getQuery(true)
                ->update($db->quoteName('#__template_styles'))
                // Test PR #41367: Simulate database error
                // ->set($db->quoteName('inheritable') . ' = 1')
                ->set($db->quoteName('not_existing_column') . ' = 1')
                // Test PR #41367 end
                ->where($db->quoteName('template') . ' = ' . $db->quote($template))
                ->where($db->quoteName('client_id') . ' = ' . $clientId);

            try {
                $db->setQuery($query)->execute();
            } catch (Exception $e) {
                $this->collectError(__METHOD__, $e);
            }
        }
    }

This shall simulate any kind of database error happening at that place.

The above code is from the package with the PR applied, in the package without the PR it is done accordingly but of course without the changes from this PR.

Actual result without the PR applied

The update succeeds. The postflight has run so the Contacts and Smart Search submenus are complete in the administrator menu.

test-3_actual-result_from-3 10 12

The backend seems to work. But the failed fixTemplateMode could cause issues with the template manager.

The "joomla_update.php" log file doesn't show anything special, it differs only by timestamps, user ID and package name compared with the one from Test 1.

All steps of the update have been processed.

Expected result with the PR applied

The backend shows a page with is blank except of error messages or alerts and a button to go back to the dashboard.
test-3_expected-result_from-3 10 12

Using that button brings us back to the administrator template.

The postflight has run so the Contacts and Smart Search submenus are complete in the administrator menu.
test-3_expected-result_from-3 10 12-after-back-to-dashboard

The backend seems to work. But the failed fixTemplateMode could cause issues with the template manager.

The "joomla_update.php" log file shows 2 errors as the error happens 2 times, one time for each core template.

2023-09-10T08:05:41+00:00	INFO 192.168.98.1	update	Update started by user Super User (701). Old version is 3.10.12.
2023-09-10T08:05:41+00:00	INFO 192.168.98.1	update	Downloading update file from https://test5.richard-fath.de/Joomla_4.3.5-dev+pr.41367-Development-Update_Package_2023-09-09_test-3.zip.
2023-09-10T08:05:44+00:00	INFO 192.168.98.1	update	File Joomla_4.3.5-dev+pr.41367-Development-Update_Package_2023-09-09_test-3.zip downloaded.
2023-09-10T08:05:44+00:00	INFO 192.168.98.1	update	Starting installation of new version.
2023-09-10T08:05:47+00:00	INFO 192.168.98.1	update	Finalising installation.
2023-09-10T08:05:47+00:00	ERROR 192.168.98.1	update	An error has occurred while running "JoomlaInstallerScript::fixTemplateMode". Code: 1054. Message: Unknown column 'not_existing_column' in 'field list'.
2023-09-10T08:05:47+00:00	ERROR 192.168.98.1	update	An error has occurred while running "JoomlaInstallerScript::fixTemplateMode". Code: 1054. Message: Unknown column 'not_existing_column' in 'field list'.
2023-09-10T08:05:47+00:00	INFO 192.168.98.1	update	Start of SQL updates.
...

Besides this, it differs only by timestamps, user ID and package name compared with the one from Test 1, i.e. all steps of the update have been processed.

Test 4: Let preflight method of script.php fail e.g. due to broken manifest cache and return false.

Modification in the update packages in file "administrator/components/com_admin/script.php":

    public function preflight($action, $installer)
    {
        if ($action === 'update') {
            // Get the version we are updating from
            /* Test PR 41367: Simulate missing or broken manifest
            if (!empty($installer->extension->manifest_cache)) {
                $manifestValues = json_decode($installer->extension->manifest_cache, true);

                if (array_key_exists('version', $manifestValues)) {
                    $this->fromVersion = $manifestValues['version'];

                    // Ensure templates are moved to the correct mode
                    $this->fixTemplateMode();

                    return true;
                }
            }
            Test PR 41367 end */

            return false;
        }

        return true;
    }

This shall simulate the preflight method failing due to a missing or incomplete manifest cache.

Actual result without the PR applied

The "joomla_update.php" log file shows no warning or error. But compared to the log file from a successful update you can see that the SQL update scripts have not been run.

See following comparison for updating from 4.3.1, left side = log from this test without PR applied, right side = log from a successful update:
test-4_actual-result_from-4 3 1-logfile-compare

Depending on the version from which the update has been made, there are many SQL changes lost or only a few.

After updating from 3.10.12, the backend is completely broken:
test-4_actual-result_from-3 10 12

After updating from 4.3.1, the backend looks ok:
test-4_actual-result_from-4 3 1

In both cases an unspecific warning about a custom install routine failure is shown.

Expected result with the PR applied

Same as without the PR applied, the SQL update scripts have been not processed.

But this time the "joomla_update.php" log file shows 1 error and 1 warning.

See here the comparison, left side = with PR applied, right side = without PR applied:
test-4_expected-result_from-4 3 1-logfile-compare

Backend after update from 3.10.12:
test-4_expected-result_from-3 10 12

Backend after update from 4.3.1:
test-4_expected-result_from-4 3 1

Test 5: Cause an SQL error in an update SQL script (new script 4.3.4-2023-08-20.sql).

New update SQL scripts "4.3.4-2023-08-20.sql" with an erroneous SQL statement in the update packages.

This shall simulate any kind of SQL or database error during the SQL updates.

Actual result without the PR applied

The backend shows an alert about the SQL error.

Besides this, the backend works because the SQL error happened at the very end, but if it happens early, the backend might be broken.

Depending on the kind of error and backend template this might result in the error messages not being shown.
test-5_actual-result_from-3 10 12

The "joomla_update.php" log file shows the SQL error and reports the incomplete SQL updates:

...
2023-09-10T09:23:07+00:00	INFO 192.168.98.1	update	Ran query from file 4.3.4-2023-08-20. Query text: UPDATE `#__extensions`    SET `not_existing_column` = 'blabla'  WHERE `name` = '.
2023-09-10T09:23:07+00:00	INFO 192.168.98.1	update	JInstaller: :Install: Error SQL Unknown column 'not_existing_column' in 'field list'
2023-09-10T09:23:07+00:00	INFO 192.168.98.1	update	End of SQL updates - INCOMPLETE.
2023-09-10T09:23:07+00:00	INFO 192.168.98.1	update	Cleaning up after installation.
2023-09-10T09:23:07+00:00	INFO 192.168.98.1	update	Update to version 4.3.5-dev is complete.

Expected result with the PR applied

Backend after the update from 3.10.12:
test-5_expected-result_from-3 10 12

After using the "Return to Dashboard" button, the backend works because the SQL error happened at the very end, but if it happens early, the backend might be broken.

Using the system template here makes sure that we can see the error messages.

The "joomla_update.php" log file shows 1 warning and 1 error in addition to the logs reported already without the PR applied.

But the new logs have levels "WARNING" and "ERROR" while the old ones have "INFO" so that is an improvement when someone searches for error or warning.

...
2023-09-10T09:26:48+00:00	INFO 192.168.98.1	update	Ran query from file 4.3.4-2023-08-20. Query text: UPDATE `#__extensions`    SET `not_existing_column` = 'blabla'  WHERE `name` = '.
2023-09-10T09:26:48+00:00	INFO 192.168.98.1	update	JInstaller: :Install: Error SQL Unknown column 'not_existing_column' in 'field list'
2023-09-10T09:26:48+00:00	INFO 192.168.98.1	update	End of SQL updates - INCOMPLETE.
2023-09-10T09:26:48+00:00	WARNING 192.168.98.1	jerror	JInstaller: :Install: Error SQL Unknown column 'not_existing_column' in 'field list'
2023-09-10T09:26:48+00:00	ERROR 192.168.98.1	update	An error has occurred while running "installer::parseSchemaUpdates". Code: 0. Message: installer::parseSchemaUpdates finished with "false" result..
2023-09-10T09:26:48+00:00	INFO 192.168.98.1	update	Cleaning up after installation.
2023-09-10T09:26:48+00:00	INFO 192.168.98.1	update	Update to version 4.3.5-dev+pr.41367 is complete.

Test 6: A bad 3rd party fields plugin throws an exception in its constructor

Only relevant when updating from 3.10.12.

This test doesn't require changes for testing on the update packages, but you can use the unmodified packages and custom update URLs from Test 1.

The order of processing of the following steps is important.

  1. On 3.10.12, create a repeatable field for articles and use it in an article.
  2. Download and install the following test plugin: https://test5.richard-fath.de/ttest.zip .
  3. Enable the plugin installed in the previous step.
  4. Update to the unpatched 4.3-dev nightly build for the actual result, or to the patched package created by drone for this PR for the expected result.

Actual result without the PR applied

The backend looks broken (no CSS) and shows an error message;
test-6_actual-result_from-3 10 12

After page reload, the backend look ok but still shows that error:
test-6_actual-result_from-3 10 12-after-page-reload

After using the "Return to Dashoard" button, the backend looks ok and seems to work, but when you check the admin menu for the Contacts and Smart Search submenus you will see that they are missing:
test-6_actual-result_from-3 10 12-after-return to-dashboard-expand-menu

And when you check the #__fields table in database, the repeatable field has not been converted to a subform field, so the postflight has not run:
test-6_actual-result_from-3 10 12-db-repeatable-field-not-migrated

The update log doesn't show any error. However, it's missing the "Cleaning up after installation" step, and it seems the "Update" method of script.php (or the finalisation step with the database update) has run a 2nd time because there is a 2nd log "Finalising installation", and start and end of SQL updates are logged again, but no updates have run because the schema version was already ok.

See following comparison, left side = log from this test without PR applied, right side = log from a successful update:
test-6_actual-result_from-3 10 12-logfile-compare

Expected result with the PR applied

Backend after the update:
test-6_expected-result_from-3 10 12

After using the "Return to Dashoard" button, the same applies as without this PR.

The update log shows a clear error message, the "update" method of script.php has not run a 2nd time.

See here the comparison, left side = with PR applied, right side = without PR applied:
test-6_expected-result_from-3 10 12-logfile-compare

Test 7: Cause refreshManifestCache failing for a core extension due to not existing manifext xml file in the updateManifestCaches method in script.php.

Modification in the update packages in file "administrator/components/com_admin/script.php" in method "updateManifestCaches":

...
        // Test PR #41367: Let refreshManifestCache return false due to not existing extension
        $badExtension = new stdClass();
        $badExtension->extension_id = -1;
        $extensions[] = $badExtension;
        // Test PR #41367 end

        foreach ($extensions as $extension) {
            if (!$installer->refreshManifestCache($extension->extension_id)) {
                $this->collectError(
                    __METHOD__,
                    new \Exception(Text::sprintf('FILES_JOOMLA_ERROR_MANIFEST', $extension->type, $extension->element, $extension->name, $extension->client_id))
                );
            }
        }
    }

This shall simulate bad extension data causing the installer's refreshManifestCache to fail.

Actual result without the PR applied

The backend shows an unspecific warning "Failed to load extension details".
test-7_actual-result_from-3 10 12

Besides this, the backend seems to work ok.

The update log doesn't show any difference compared to a successful update e.g. from Test 1 besides timestamps, user ID and package name, i.e. there is no error shown in the log.

Expected result with the PR applied

Backend after the update:
test-7_expected-result_from-3 10 12

The language string of the error from the installer has not been translated.

Besides this, the backend seems to work ok after using the "Return to Dashboard" button.

The update log shows a warning and an error:

...
2023-09-10T11:14:50+00:00	INFO 192.168.98.1	update	Ran query from file 4.3.2-2023-05-20. Query text: ALTER TABLE `#__user_mfa` ADD COLUMN `last_try` datetime ;.
2023-09-10T11:14:50+00:00	INFO 192.168.98.1	update	End of SQL updates.
2023-09-10T11:14:50+00:00	INFO 192.168.98.1	update	Deleting removed files and folders.
2023-09-10T11:14:51+00:00	WARNING 192.168.98.1	jerror	Failed to load extension details.
2023-09-10T11:14:51+00:00	ERROR 192.168.98.1	update	An error has occurred while running "JoomlaInstallerScript::updateManifestCaches". Code: 0. Message: FILES_JOOMLA_ERROR_MANIFEST.
2023-09-10T11:14:51+00:00	INFO 192.168.98.1	update	Cleaning up after installation.
2023-09-10T11:14:51+00:00	INFO 192.168.98.1	update	Update to version 4.3.5-dev+pr.41367 is complete.

Test 8: Only relevant when updating from 3.10.12.Cause database error in postflight method of script.php so postflight fails with exception.

Modification in the update packages in file "administrator/components/com_admin/script.php" in method "postflight":

    public function postflight($action, $installer)
    {
...
        foreach ($menuItems as $menuItem) {
...

            // Test PR 41367: Return false due to an error
            return false;
        }
...

This shall simulate anything going wrong with one of the previous statements, so false is returned.

Actual result without the PR applied

The update seems to succeed, i.e. no error shown in backend.

The update log doesn't show any difference compared to a successful update e.g. from Test 1 besides timestamps, user ID and package name, i.e. there is no error shown in the log.

However, there might be errors shown when the error is not just simulated by returning false but a real error happens in one of the called methods.

Expected result with the PR applied

The result is the same as for the actual result without this PR: The update seems to succeed, i.e. no error shown in backend.
The update log doesn't show any difference compared to a successful update e.g. from Test 1 besides timestamps, user ID and package name, i.e. there is no error shown in the log. However, there might be errors shown when the error is not just simulated by returning false but a real error happens in one of the called methods.

Maybe the update model should check the return code of the postflight step, which it currently seems not to do, but that's outside the scope of this PR here.

Test 9: Only relevant when updating from 3.10.12.Let postflight method of script.php return false due to an error.

Modification in the update packages in file "administrator/components/com_admin/script.php" in method "postflight":

    public function postflight($action, $installer)
    {
...
        // Test PR 41367: Raise an exception due to an error
        throw new Exception('ERROR Exception in postflight method.');

        return true;
    }

This shall simulate any of the previous statements throwing an exception.

Actual result without the PR applied

After the update, the page looks broken (css):
test-9_actual-result_from-3 10 12

However, after a page reload, the backend seems ok:
test-9_actual-result_from-3 10 12-after-page-reload

In the log file there is no error message compared to the log from a normal update, e.g. from Test 1. But it seems that the "Update" method of script.php (or the finalisation step with the database update) has run a 2nd time.

See following comparison, left side = log from this test without PR applied, right side = log from a successful update:
test-9_actual-result_from-3 10 12-logfile-compare

Expected result with the PR applied

Backend after the update:
test-9_expected-result_from-3 10 12

After using the "Return to Dashoard" button the backend seems ok.

The update log shows a clear error message, the "update" method of script.php has not run a 2nd time.

See here the comparison, left side = with PR applied, right side = without PR applied:
test-9_expected-result_from-3 10 12-logfile-compare

Conclusion

The PR makes sure that errors become visible which before were completely hidden or not clear enough.

When the logs folder is not writeable, the update is not started, which is done without this PR and can result in a broken site.

avatar richard67
richard67 - comment - 10 Sep 2023

Up to now 7 of 9 tests were successful for me, the other 2 I haven't performed yet. I will update the results soon in my previous comment.

avatar Fedik
Fedik - comment - 10 Sep 2023

@richard67 That a huge work, thank you Richard!

I have to look on untranslated FILES_JOOMLA_ERROR_MANIFEST.

avatar richard67
richard67 - comment - 10 Sep 2023

@richard67 That a huge work, thank you Richard!

I have to look on untranslated FILES_JOOMLA_ERROR_MANIFEST.

@Fedik Maybe better do that with a new, separate PR.

avatar Fedik
Fedik - comment - 10 Sep 2023

I think I juts replace it to fixed text. this should not require extra test, or what do you think?
It comes from files_joomla.sys.in, no idea what is it and how it suposed to be loaded.

I thinking to add "file" and "line" to the log message, as I see from test result it maybe helpfull.
What do you think?

avatar Fedik
Fedik - comment - 10 Sep 2023

Okay, will do in another PR

avatar richard67
richard67 - comment - 10 Sep 2023

I thinking to add "file" and "line" to the log message, as I see from test result it maybe helpfull.
What do you think?

@Fedik Good idea, but maybe also better with a new follow-up PR after this one. I wanna finish my tests and their descriptions, and then will try to find a 2nd tester.

avatar richard67 richard67 - test_item - 10 Sep 2023 - Tested successfully
avatar richard67
richard67 - comment - 10 Sep 2023

I have tested this item ✅ successfully on bec0115

Detailed results of all my tests can be found in my previous comment here: #41367 (comment)

The comment contains also links to packages which I've created to produce the diverse errors, and links to corresponding custom update site URLs, so other testers can use them.


This comment was created with the J!Tracker Application at issues.joomla.org/tracker/joomla-cms/41367.

avatar richard67 richard67 - alter_testresult - 10 Sep 2023 - richard67: Tested successfully
avatar Fedik
Fedik - comment - 11 Sep 2023

I think these also pretty useless

if ($suppressOutput === false && count($status['folders_errors'])) {
echo implode('<br>', $status['folders_errors']);
}
if ($suppressOutput === false && count($status['files_errors'])) {
echo implode('<br>', $status['files_errors']);

Curentlly I skipped it. But as I see, they also should be untranslated:

$status['files_errors'][] = Text::sprintf('FILES_JOOMLA_ERROR_FILE_FOLDER', $file);

$status['folders_errors'][] = Text::sprintf('FILES_JOOMLA_ERROR_FILE_FOLDER', $folder);

Does it make sense to add them to log by default? and ignore $suppressOutput variable.
It probably also for another PR.

avatar richard67
richard67 - comment - 11 Sep 2023

Does it make sense to add them to log by default?

I think it could make sense, but it needs to be tested.

and ignore $suppressOutput variable.

Why ignore it? The default value of that parameter is false, and in administrator/components/com_joomlaupdate/finalisation.php and administrator/components/com_admin/script.php in the update method we call deleteUnexistingFiles without that parameter. Only in libraries/src/Console/RemoveOldFilesCommand.php is a call with the parameter set to true. So I think we can keep that condition as it is, we just have to use the result which we currently don't do.

avatar Fedik
Fedik - comment - 11 Sep 2023

Why ignore it?

To fully eliminate any echo from script.php.
Also it does not make any sense to me, maybe it was used in past, but currently I cannot find any.

Yeah, can also be both, echo and log, for now.

avatar obuisard
obuisard - comment - 12 Sep 2023

Tests done on a Windows 11 system, Firefox browser, local Bearsampp server running Apache 2.4.55 PHP 8.0.28 MySQL 8.0.32.
Following results are once the PR is applied.

Test 1 OK

Test 2 OK

Test 3 the update never ends, it stays stuck on 'The update is finalising'. I tried to update the modified package (created by Richard https://test5.richard-fath.de/Joomla_4.3.5-dev+pr.41367-Development-Update_Package_2023-09-09_test-3.zip), I just can't get it to finish. It just hangs.
Server error log:
PHP Warning: Uncaught Joomla\\Database\\Exception\\PrepareStatementFailureException: Unknown column 'not_existing_column' in 'field list' in E:\\bearsampp\\www\\MyWork_3_latest\\libraries\\vendor\\joomla\\database\\src\\Mysqli\\MysqliStatement.php:141

Test 3 OK under PHP 7.4.33

Test 4 OK

Test 5 OK

Test 6 update never ends, stays at 90.8%
Last 3 lines in joomla_update.php:

2023-09-12T02:02:18+00:00	INFO 127.0.0.1	update	End of SQL updates.
2023-09-12T02:02:18+00:00	INFO 127.0.0.1	update	Deleting removed files and folders.
2023-09-12T02:02:22+00:00	WARNING 127.0.0.1	jerror	Failed to load extension details.

Test 6 OK under PHP 7.4.33 That is a great one because it gives very useful feedback.

Test 7 update never ends, stays at 90.8%
PHP Warning: Undefined property: stdClass::$type in E:\bearsampp\www\MyWork_3_latest\administrator\components\com_admin\script.php on line 643

Last 3 lines in joomla_update.php:

2023-09-12T02:29:03+00:00	INFO 127.0.0.1	update	End of SQL updates.
2023-09-12T02:29:04+00:00	INFO 127.0.0.1	update	Deleting removed files and folders.
2023-09-12T02:29:10+00:00	WARNING 127.0.0.1	jerror	Failed to load extension details.

Test 7 OK under PHP 7.4.33

Test 8 OK

Test 9 update never ends, stays at 90.8%, then:
image

Last 2 lines in joomla_update.php:

2023-09-12T02:49:59+00:00	INFO 127.0.0.1	update	End of SQL updates.
2023-09-12T02:49:59+00:00	INFO 127.0.0.1	update	Deleting removed files and folders.

Test 9 OK under PHP 7.4.33

Thank you, Richard @richard67, for providing all these sample files and test directions, It was invaluable.

avatar richard67
richard67 - comment - 12 Sep 2023

@obuisard Regarding the stuck and never ending tests: Which Version have you updated from? Have you used the MySQLi or the MySQL (PDO) driver? And how long have you waited? The error with undefined property for stdClass in test 7 could be caused by the error which I have added.

avatar richard67
richard67 - comment - 12 Sep 2023

@obuisard Ah i know why it fails for you: error reporting and maybe debug on? Please try with standard error reporting and without debug, anything else breaks on php 8 when updating from 3.10.12, also without this PR applied.

avatar obuisard
obuisard - comment - 12 Sep 2023

@obuisard Ah i know why it fails for you: error reporting and maybe debug on? Please try with standard error reporting and without debug, anything else breaks on php 8 when updating from 3.10.12, also without this PR applied.

Oh! I did not think that debug would mess it up. I will retry the failed tests.

avatar obuisard
obuisard - comment - 12 Sep 2023

@obuisard Regarding the stuck and never ending tests: Which Version have you updated from? Have you used the MySQLi or the MySQL (PDO) driver? And how long have you waited? The error with undefined property for stdClass in test 7 could be caused by the error which I have added.

Updated from 3.10.12 in most cases, sometimes from 4.3.4 when tests did not require 3.10.12. Using MySQLi.
Waited a long time, sometimes (launching - taking a shower - still running :-) )

avatar obuisard obuisard - test_item - 12 Sep 2023 - Tested successfully
avatar obuisard
obuisard - comment - 12 Sep 2023

I have tested this item ✅ successfully on ba11ab4

I have gotten satisfactory results for all tests 1 thru 9.
Initial failed tests happened under PHP 8.0.28, probably a problem of configuration. Time outs may happen on user systems as well, which cannot be prevented.


This comment was created with the J!Tracker Application at issues.joomla.org/tracker/joomla-cms/41367.

avatar richard67 richard67 - change - 12 Sep 2023
Status Pending Ready to Commit
avatar richard67
richard67 - comment - 12 Sep 2023

RTC


This comment was created with the J!Tracker Application at issues.joomla.org/tracker/joomla-cms/41367.

avatar HLeithner HLeithner - change - 13 Sep 2023
Labels Added: ?
avatar HLeithner HLeithner - close - 13 Sep 2023
avatar HLeithner HLeithner - merge - 13 Sep 2023
avatar HLeithner HLeithner - change - 13 Sep 2023
Status Ready to Commit Fixed in Code Base
Closed_Date 0000-00-00 00:00:00 2023-09-13 08:20:42
Closed_By HLeithner

Add a Comment

Login with GitHub to post a comment