Errors on DB schema update after version upgrade

SiRichards2049 · March 17, 2023, 4:54pm

I am getting SQL errors after updating passbolt.

Centos 7
Passbolt 3.12.0
MariaDB 10.8
nginx/1.23.3
PHP 8.0

Healthcheck fail (DB Schema out of date)

root@192.168.1.15:/var/www/html/passbolt# sudo su -s /bin/bash -c “/var/www/html/passbolt/bin/cake migrations migrate --no-lock” nginx
PHP Warning: Module “gnupg” is already loaded in Unknown on line 0
using migration paths

/var/www/html/passbolt/config/Migrations
using seed paths
/var/www/html/passbolt/config/Seeds
using environment default
using adapter mysql
using database passbolt
ordering by creation time

== 20220809190030 V372ImproveFoldersRelationsIndexesAddItemsToUserTreePerformance: migrating
PDOException: SQLSTATE[42000]: Syntax error or access violation: 1280 Incorrect index name ‘foreign_id’ in /var/www/html/passbolt/vendor/robmorgan/phinx/src/Phinx/Db/Adapter/PdoAdapter.php:193
Stack trace:
#0 /var/www/html/passbolt/vendor/robmorgan/phinx/src/Phinx/Db/Adapter/PdoAdapter.php(193): PDO->exec(‘ALTER TABLE fo...') #1 /var/www/html/passbolt/vendor/robmorgan/phinx/src/Phinx/Db/Util/AlterInstructions.php(108): Phinx\Db\Adapter\PdoAdapter->execute('ALTER TABLE fo…’)
#2 /var/www/html/passbolt/vendor/robmorgan/phinx/src/Phinx/Db/Adapter/PdoAdapter.php(611): Phinx\Db\Util\AlterInstructions->execute(‘ALTER TABLE `fo…’, Array)
#3 /var/www/html/passbolt/vendor/robmorgan/phinx/src/Phinx/Db/Adapter/PdoAdapter.php(972): Phinx\Db\Adapter\PdoAdapter->executeAlterSteps(‘folders_relatio…’, Object(Phinx\Db\Util\AlterInstructions))
#4 /var/www/html/passbolt/vendor/robmorgan/phinx/src/Phinx/Db/Adapter/AdapterWrapper.php(484): Phinx\Db\Adapter\PdoAdapter->executeActions(Object(Phinx\Db\Table\Table), Array)
#5 /var/www/html/passbolt/vendor/robmorgan/phinx/src/Phinx/Db/Adapter/TimedOutputAdapter.php(420): Phinx\Db\Adapter\AdapterWrapper->executeActions(Object(Phinx\Db\Table\Table), Array)
#6 /var/www/html/passbolt/vendor/robmorgan/phinx/src/Phinx/Db/Adapter/AdapterWrapper.php(484): Phinx\Db\Adapter\TimedOutputAdapter->executeActions(Object(Phinx\Db\Table\Table), Array)
#7 /var/www/html/passbolt/vendor/robmorgan/phinx/src/Phinx/Db/Plan/Plan.php(151): Phinx\Db\Adapter\AdapterWrapper->executeActions(Object(Phinx\Db\Table\Table), Array)
#8 /var/www/html/passbolt/vendor/robmorgan/phinx/src/Phinx/Db/Table.php(715): Phinx\Db\Plan\Plan->execute(Object(Migrations\CakeAdapter))
#9 /var/www/html/passbolt/vendor/robmorgan/phinx/src/Phinx/Db/Table.php(623): Phinx\Db\Table->executeActions(true)
#10 /var/www/html/passbolt/vendor/cakephp/migrations/src/Table.php(152): Phinx\Db\Table->update()
#11 /var/www/html/passbolt/vendor/robmorgan/phinx/src/Phinx/Db/Table.php(682): Migrations\Table->update()
#12 /var/www/html/passbolt/config/Migrations/20220809190030_V372ImproveFoldersRelationsIndexesAddItemsToUserTreePerformance.php(41): Phinx\Db\Table->save()
#13 /var/www/html/passbolt/vendor/robmorgan/phinx/src/Phinx/Migration/Manager/Environment.php(111): V372ImproveFoldersRelationsIndexesAddItemsToUserTreePerformance->up()
#14 /var/www/html/passbolt/vendor/robmorgan/phinx/src/Phinx/Migration/Manager.php(385): Phinx\Migration\Manager\Environment->executeMigration(Object(V372ImproveFoldersRelationsIndexesAddItemsToUserTreePerformance), ‘up’, false)
#15 /var/www/html/passbolt/vendor/robmorgan/phinx/src/Phinx/Migration/Manager.php(359): Phinx\Migration\Manager->executeMigration(‘default’, Object(V372ImproveFoldersRelationsIndexesAddItemsToUserTreePerformance), ‘up’, false)
#16 /var/www/html/passbolt/vendor/robmorgan/phinx/src/Phinx/Console/Command/Migrate.php(124): Phinx\Migration\Manager->migrate(‘default’, 20230308124720, false)
#17 /var/www/html/passbolt/vendor/cakephp/migrations/src/Command/Phinx/CommandTrait.php(37): Phinx\Console\Command\Migrate->execute(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#18 /var/www/html/passbolt/vendor/cakephp/migrations/src/Command/Phinx/Migrate.php(85): Migrations\Command\Phinx\Migrate->parentExecute(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#19 /var/www/html/passbolt/vendor/symfony/console/Command/Command.php(298): Migrations\Command\Phinx\Migrate->execute(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#20 /var/www/html/passbolt/vendor/symfony/console/Application.php(1040): Symfony\Component\Console\Command\Command->run(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#21 /var/www/html/passbolt/vendor/symfony/console/Application.php(301): Symfony\Component\Console\Application->doRunCommand(Object(Migrations\Command\Phinx\Migrate), Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#22 /var/www/html/passbolt/vendor/symfony/console/Application.php(171): Symfony\Component\Console\Application->doRun(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#23 /var/www/html/passbolt/vendor/cakephp/migrations/src/Command/MigrationsCommand.php(126): Symfony\Component\Console\Application->run(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#24 /var/www/html/passbolt/vendor/cakephp/cakephp/src/Console/BaseCommand.php(179): Migrations\Command\MigrationsCommand->execute(Object(Cake\Console\Arguments), Object(Cake\Console\ConsoleIo))
#25 /var/www/html/passbolt/vendor/cakephp/migrations/src/Command/MigrationsCommand.php(198): Cake\Console\BaseCommand->run(Array, Object(Cake\Console\ConsoleIo))
#26 /var/www/html/passbolt/vendor/cakephp/cakephp/src/Console/CommandRunner.php(334): Migrations\Command\MigrationsCommand->run(Array, Object(Cake\Console\ConsoleIo))
#27 /var/www/html/passbolt/vendor/cakephp/cakephp/src/Console/CommandRunner.php(172): Cake\Console\CommandRunner->runCommand(Object(Migrations\Command\MigrationsMigrateCommand), Array, Object(Cake\Console\ConsoleIo))
#28 /var/www/html/passbolt/bin/cake.php(12): Cake\Console\CommandRunner->run(Array)
#29 {main}

remy · March 17, 2023, 5:22pm

Hello @SiRichards2049,

Can you answer the following to help us understand the problem:

Which version you where upgrading from?
Did you by any chance alter the database schema manually prior running the migration? Like dropped some index already for some performance optimization?
Can you run a the following SQL query for us:

describe folders_relations;
show index from folders_relations;

We’re investigating on our side, trying to reproduce the issue.
Cheers,

SiRichards2049 · March 17, 2023, 5:27pm

Hi Remy,

I will check the logs… i’m pretty sure if was 3 releases behind.
No DB changes had been made
Your output is as follows:

Welcome to the MariaDB monitor. Commands end with ; or \g.
Your MariaDB connection id is 86
Server version: 5.5.60-MariaDB-wsrep MariaDB Server, wsrep_25.23.r9949137
Copyright (c) 2000, 2018, Oracle, MariaDB Corporation Ab and others.
Type ‘help;’ or ‘\h’ for help. Type ‘\c’ to clear the current input statement.

MariaDB [(none)]> use passbolt;
Reading table information for completion of table and column names
You can turn off this feature to get a quicker startup with -A

Database changed
MariaDB [passbolt]> describe folders_relations;
±-----------------±------------±-----±----±--------±------+
| Field | Type | Null | Key | Default | Extra |
±-----------------±------------±-----±----±--------±------+
| id | char(36) | NO | PRI | NULL | |
| foreign_model | varchar(30) | NO | MUL | NULL | |
| foreign_id | char(36) | NO | MUL | NULL | |
| user_id | char(36) | NO | MUL | NULL | |
| folder_parent_id | char(36) | YES | MUL | NULL | |
| created | datetime | NO | | NULL | |
| modified | datetime | NO | | NULL | |
±-----------------±------------±-----±----±--------±------+
7 rows in set (0.001 sec)

MariaDB [passbolt]> show index from folders_relations;
±------------------±-----------±-----------------±-------------±-----------------±----------±------------±---------±-------±-----±-----------±--------±--------------+
| Table | Non_unique | Key_name | Seq_in_index | Column_name | Collation | Cardinality | Sub_part | Packed | Null | Index_type | Comment | Index_comment |
±------------------±-----------±-----------------±-------------±-----------------±----------±------------±---------±-------±-----±-----------±--------±--------------+
| folders_relations | 0 | PRIMARY | 1 | id | A | 2377 | NULL | NULL | | BTREE | | |
| folders_relations | 1 | foreign_model | 1 | foreign_model | A | 2 | NULL | NULL | | BTREE | | |
| folders_relations | 1 | user_id | 1 | user_id | A | 18 | NULL | NULL | | BTREE | | |
| folders_relations | 1 | foreign_id | 1 | foreign_id | A | 1188 | NULL | NULL | | BTREE | | |
| folders_relations | 1 | folder_parent_id | 1 | folder_parent_id | A | 2 | NULL | NULL | YES | BTREE | | |
| folders_relations | 1 | foreign_id_2 | 1 | foreign_id | A | 792 | NULL | NULL | | BTREE | | |
| folders_relations | 1 | foreign_id_2 | 2 | folder_parent_id | A | 792 | NULL | NULL | YES | BTREE | | |
| folders_relations | 1 | foreign_model_2 | 1 | foreign_model | A | 2 | NULL | NULL | | BTREE | | |
| folders_relations | 1 | foreign_model_2 | 2 | foreign_id | A | 1188 | NULL | NULL | | BTREE | | |
| folders_relations | 1 | foreign_model_2 | 3 | user_id | A | 2377 | NULL | NULL | | BTREE | | |
| folders_relations | 1 | user_id_2 | 1 | user_id | A | 36 | NULL | NULL | | BTREE | | |
| folders_relations | 1 | user_id_2 | 2 | foreign_id | A | 2377 | NULL | NULL | | BTREE | | |
±------------------±-----------±-----------------±-------------±-----------------±----------±------------±---------±-------±-----±-----------±--------±--------------+
12 rows in set (0.022 sec)

SiRichards2049 · March 17, 2023, 5:31pm

Easier to read

cedric · March 17, 2023, 5:47pm

Thanks for the additional information. We are still trying to reproduce without any luck as of now. But the index might be corrupted. Can you try to remove it and add it again manually prior to executing the migrations again:

drop index foreign_id on folders_relations;
create index foreign_id  on folders_relations (foreign_id);

remy · March 17, 2023, 5:54pm

@SiRichards2049 can you confirm on which edition you are CE or PRO? Also did you ever switch from one version to the other?

cedric · March 17, 2023, 6:14pm

@SiRichards2049

@clayton already solved this weird issue in the past

INSERT INTO `phinxlog` VALUES (20220809190030,'V372ImproveFoldersRelationsIndexesAddItemsToUserTreePerformance','2023-03-17 19:10:00','2023-03-17 19:10:00',0);
DROP INDEX foreign_id ON folders_relations;
DROP INDEX foreign_id_2 ON folders_relations;
CREATE INDEX foreign_id ON folders_relations (foreign_id, folder_parent_id, created);

SiRichards2049 · March 17, 2023, 6:40pm

Magic !!!

Worked and thank you all for the fantastic fast help so late on a friday !

[PASS] The database schema up to date.

remy · March 17, 2023, 10:54pm

Please let us know if you (as everyone else) experience this issue also, we’re keen to get to the bottom of this and why it is happening.

garrett · March 18, 2023, 4:01am

There was a fix in phinx related to this issue - it appears the column-name only approach was problematic when there was a one-column index overlapping with a multi-column index and they were being removed. The problem resulted in the wrong index being removed (or both being removed).

In our case the theory would be that by removing the multiple column index first, there is no foreign_id index remaining. Then, it tries to remove the missing index and throws and error.

Their individual tests includes the following (dropping):

single column index
multiple column index
index with name specified, but dropping it by column name
multiple column index with name specified
don’t drop multiple column index when dropping single column *
don’t drop multiple column index with name specified when dropping single column *

The ones with (*) are related and it seems they favor dropping a single column index first. They don’t test dropping a multi-column first.

If index names are not being used, maybe instead of:

    public function up()
    {
        $this->table('folders_relations')
            /*
             * Will be replaced by the following index: "foreign_id", "folder_parent_id", "created"
             */
            ->removeIndex([
                'foreign_id',
                'folder_parent_id',
            ])
            /*
             * Single index decreases performance as it might be picked by the mysql optimizer instead of another
             * combined index which could do a better job.
             */
            ->removeIndex([
                'foreign_id'
            ])
            /*
             * Improves the performance of the queries which retrieve information relative to the potential folders
             * relations changes to apply to a user tree while adding new items to this same user tree.
             */
            ->addIndex([
                'foreign_id',
                'folder_parent_id',
                'created',
            ])
            ->save();

…it would work better with:

    public function up()
    {
        $this->table('folders_relations')
            /*
             * Single index decreases performance as it might be picked by the mysql optimizer instead of another
             * combined index which could do a better job.
             */
            ->removeIndex([
                'foreign_id'
            ])
            /*
             * Will be replaced by the following index: "foreign_id", "folder_parent_id", "created"
             */
            ->removeIndex([
                'foreign_id',
                'folder_parent_id',
            ])
            /*
             * Improves the performance of the queries which retrieve information relative to the potential folders
             * relations changes to apply to a user tree while adding new items to this same user tree.
             */
            ->addIndex([
                'foreign_id',
                'folder_parent_id',
                'created',
            ])
            ->save();

As to why it’s not failing with all users, maybe it is because of the order of the indices and phinx doesn’t handle it well or consistently. I didn’t dig into their source code to see more.

Related issues:

github.com/cakephp/phinx

addIndex and removeIndex do not behave as expected (MySQL)

opened 06:14PM - 10 Feb 14 UTC

closed 12:32AM - 09 May 20 UTC

smallhadroncollider

bug

I used `addIndex` to, I thought, setup a multi-column index: ``` $table->addInd…ex(array('dealership_id', 'dealership_name_id'), array('unique' => true)) ``` Later I wanted to remove it, so I tried: ``` $table->removeIndex(array('dealership_id', 'dealership_name_id')) ``` But because the `dealership_id` column had a foreign-key restraint it caused an error as it tried to delete the `dealership_id` index for the foreign key, not the multi-column index (I thought) I'd setup. Didn't seem to be a way to get Phinx to remove this index. Maybe I've misunderstood the syntax for `addIndex` and I wasn't setting up a multi-column index? Or maybe the `removeIndex` method has a bug.

Test function testDropIndex()
phinx/MysqlAdapterTest.php at eccc64b53e585608da8ac073a2a4728447e6d98b · cakephp/phinx · GitHub

cedric · April 3, 2023, 1:39pm

Thanks for the follow-up on it @garrett.
We’ll see to squeeze it with the coming releases.

garrett · April 3, 2023, 2:42pm

@cedric Wow so you guys were able to find/confirm what was causing it?