search

studentquiz / moodle-mod_studentquiz

Moodle-Plugin
GNU General Public License v3.0
38 stars 37 forks source link

[v5.1.0] Database error when upgrading from v4.5.0 to v5.1.0 #447

Open danowar2k opened 1 year ago

danowar2k commented 1 year ago

This came up during an upgrade:

Debug-Info:  FEHLER: NULL-Wert in Spalte »questionid« von Relation »m_studentquiz_state_history« verletzt Not-Null-Constraint
DETAIL: Fehlgeschlagene Zeile enthält (1, null, 18182, 2, 1569395230).
INSERT INTO m_studentquiz_state_history (userid,state,timecreated) VALUES($1,$2,$3) RETURNING id
[array (
'userid' => 18182,
'state' => 2,
'timecreated' => 1569395230,
)]
Error code: dmlwriteexception×Diese Systemnachricht ablehnen
Stack trace: 
line 497 of /lib/dml/moodle_database.php: dml_write_exception thrown
line 293 of /lib/dml/moodle_read_slave_trait.php: call to moodle_database->query_end()
line 341 of /lib/dml/pgsql_native_moodle_database.php: call to pgsql_native_moodle_database->read_slave_query_end()
line 1132 of /lib/dml/pgsql_native_moodle_database.php: call to pgsql_native_moodle_database->query_end()
line 1180 of /lib/dml/pgsql_native_moodle_database.php: call to pgsql_native_moodle_database->insert_record_raw()
line 595 of /mod/studentquiz/classes/utils.php: call to pgsql_native_moodle_database->insert_record()
line 923 of /mod/studentquiz/db/upgrade.php: call to mod_studentquiz\utils::question_save_action()
line 934 of /lib/upgradelib.php: call to xmldb_studentquiz_upgrade()
line 677 of /lib/upgradelib.php: call to upgrade_plugins_modules()
line 1953 of /lib/upgradelib.php: call to upgrade_plugins()
line 721 of /admin/index.php: call to upgrade_noncore()

Reloading the upgrade page led to studentquiz finishing the upgrade, which surprised us. I thought we would get the same error again, because of rollbacked transactions (we're using Postgres).

The underlying Moodle instance had previously been upgraded from 3.11.11 to 4.1.1, but mod_studentquiz had been left at v4.5.0 until we separately updated the plugin.

The cause looks to be around here: https://github.com/studentquiz/moodle-mod_studentquiz/blob/main/db/upgrade.php#L887-L938.

A questionid from studentquiz_question is NULL ? That's strange, shouldn't happen...?

timhunt commented 1 year ago

The fact that a reaload works surprises me too. ...

Ah! the code that gave the error was inside an if (!$dbman->table_exists($table)) { and when you reload, the table will exist, so it will skip that bit of hte upgrade, which will leave your system in a bad state.

Was this a test server? Can you restore your backup and try the upgrade again? (perhaps after adding some debugging output, to work out how that column could be null. That still seems impossible to me.)

(The checks under System administration > Development > XMLDB editor, do any of those check that the column NOT NULL in your database, acutally match what it is supposed to be? Or, could you manually check the structure of the studentquiz_question matches what it should be?)

danowar2k commented 1 year ago

Sadly, the system was both a test server with "uncritical data" and I didn't do a backup beforehand because it didn't matter to us very much. But I can try and check with our database admins, they should be able to produce a database backup from the last 24 hours...

danowar2k commented 1 year ago

So the creation of tables is done atomically and in a transaction? Well, shouldn't the "creating table" code not be separate from the "massage old data to new way of thinking" stuff?

timhunt commented 1 year ago

Postgres can do DML statements (like create table) in transactnios, but most other DB can't.

Yes, the upgrade blocks should be separate.

danowar2k commented 1 year ago

I added a PR which doesn't fix the NULL problem, but should at least prevent further resulting data inconsistencies.

danowar2k commented 1 year ago

Aside: js files seem to be stale...

danowar2k commented 1 year ago

We've restored the database via WAL log and just didn't update the plugin for now.

Looking at the contents of studentquiz_question, I can't seem to find a NULL entry. Strange...

EDIT: At least I found the record that possibly was referenced avobe:

questionid;state;createdby;timecreated "987";"1";"18182";"1569395230"

danowar2k commented 1 year ago

Debugged it. The cause is:

That field is only added here: https://github.com/studentquiz/moodle-mod_studentquiz/blob/main/db/upgrade.php#L1118 and populated with the content of questionid here: https://github.com/studentquiz/moodle-mod_studentquiz/blob/a07f09a76977f8e43a829e0241851e8ac9a2c1c2/db/upgrade.php#L1414-L1418 and the old field is finally dropped here: https://github.com/studentquiz/moodle-mod_studentquiz/blob/main/db/upgrade.php#L1620

But of course, if one uses the constantly evolving code in the upgrade procedure, this was bound to happen sometime. I gotta remember that for my plugins: "Do not use 'normal' API in plugin updates"...

EDIT: I'll do a PR for this, too...will replace the utils function with creating "at the time correct" data objects...

danowar2k commented 1 year ago

Here's a workaround for anyone looking to update in the meantime. The v4.5.0 tag officially is 2021071300. The change is done at 2021102502. The next tag that includes that change is v4.6.0 .

So one can update from v4.5.0 to v4.6.0 (the API is still consistent there), and then update from v4.6.0 to v5.1.0.

danowar2k commented 1 year ago

Okay, I just updated the existing PR with a second commit that doesn't use the utils method anymore.

timhunt commented 1 year ago

Sorry that I am ingoring your! This turned into a very busy week, and I just have not had time. Thank you for continuing to work on this, and I hope I will have time to look next week.

danowar2k commented 1 year ago

No worries. I think I'm done, though.

danowar2k commented 1 year ago

Any progress here?

eligorio commented 1 year ago

In order to be able to upgrade to version 2022122200 i did the below image edits. It is not optimal. Is there other workaround?

I did this because of message.

!!! Erro ao gravar na base de dados !!! !! Subquery returns more than 1 row UPDATE mdl_studentquiz_rate SET studentquizquestionid = ( SELECT id FROM mdl_studentquiz_question WHERE questionid = mdl_studentquiz_rate.questionid )

[array ( )] Error code: dmlwriteexception !!

image

sennewood commented 1 year ago

This error also occurs with plugin version v4.7.1 (2022052401).

danowar2k commented 9 months ago

Ran into this problem again when upgrading another instance of ours. @timhunt Can't you at least merge the code that splits table creation from data migration to make the error reproducible and the database inconsistency a smaller problem?

timhunt commented 9 months ago

Merge it into which branch?

danowar2k commented 9 months ago

By the way, applying the fix above to a non-upgraded Moodle removed the error when upgrading.

Merge it into which branch?

Um, I'd gather "main"? The commits don't introduce new features but slightly alter the upgrade procedure to split the studentquiz_state_history table creation and data migration to it, so that could IMHO just be merged to at least prevent data inconsistencies.

The second commit replaces the utils::question_save_action calls with what was at that point in time the function body. This way the upgrade flow is maintained and nothing in this flow has been functionally changed.

Do you need me to do further tests to be able to determine whether this PR can be used?