fix(sqlite): Prevent the execution of 'migrate' script if user_version==0 #2031

Ivansete-status · 2023-09-13T14:45:35Z

Description

Given a nwaku node with Store-SQLite mounted, it will try to apply a migration script because the user_version present in the SQLite file is 0, whereas the expected version is 7.

Changes

Avoid migrate the SQLite schema if the user_version == 0 and the # of columns in PK is 3. In this case, we also enforce the SchemaVersion 7.

How to replicate the issue:

In order to replicate the issue, the node should have a certain amount of messages stored in the database.

Use the next command, tailored by @vpavlin, to start the node, but change the docker image each time:

docker run -it --rm -v $PWD/data:/data:z XXXdocker-imageXXX --relay --store --store-message-db-url=sqlite:///data/wakustore.sqlite3 --log-level=DEBUG --dns-discovery=true --dns-discovery-url=enrtree://AOGECG2SPND25EEFMAJ5WF3KSGJNSGV356DSTL2YVLLZWIV6SAYBM@prod.waku.nodes.status.im --discv5-discovery=true --discv5-udp-port=9005 --discv5-enr-auto-update=True

Start the node with: statusteam/nim-waku:v0.17.0. This will start normally.
Start the node with: statusteam/nim-waku:v0.19.0. The node fails to start with the message: "failed to setup archive driver: failed to execute migration scripts: failed to execute migration statement".

How to validate the fix:

Start the node with: statusteam/nim-waku:v0.17.0. This will start normally.
Start the node with: quay.io/wakuorg/nwaku-pr:2031. This will start normally, and the next message should appear: "We found user_version 0 but the database schema reflects the user_version 7".
Start the node with: statusteam/nim-waku:v0.19.0. This will start normally.

Issue

closes #2027

github-actions · 2023-09-13T14:53:03Z

You can find the image built from this PR at

quay.io/wakuorg/nwaku-pr:2031

Built from 54bdf98

jm-clius · 2023-09-13T15:32:25Z

Not sure I follow this fix - why would we consider nodes with user_version=0 to be up to date? How will we update their schemas in future? And do we know why the user_version would have been reset to 0 at all? If we know why this would have happened, I would imagine a temporary fix script is that for such nodes the user_version should be set to the latest target_version and migration skipped.

vpavlin · 2023-09-13T15:35:53Z

I am not sure how to reproduce the original issue - I ran

docker run -it --rm -v $PWD/data:/data:z statusteam/nim-waku:v0.17.0 --relay=true --store=true --store-message-db-url=sqlite:///data/wakustore.sqlite3

then

docker run -it --rm -v $PWD/data:/data:z statusteam/nim-waku:v0.19.0 --relay=true --store=true --store-message-db-url=sqlite:///data/wakustore.sqlite3

And I get

INF 2023-09-13 15:33:51.702+00:00 database schema is outdated                topics="sqlite" tid=1 file=db_sqlite.nim:444 userVersion=0 targetVersion=7

In both executions, but no errors

vpavlin · 2023-09-13T15:52:13Z

Ok, reproduced it - it needs some messages in the db (which makes sense, since it is caused by some constraint change)

docker run -it --rm -v $PWD/data:/data:z statusteam/nim-waku:v0.17.0 --relay --store --store-message-db-url=sqlite:///data/wakustore.sqlite3 --log-level=DEBUG --dns-discovery=true --dns-discovery-url=enrtree://AOGECG2SPND25EEFMAJ5WF3KSGJNSGV356DSTL2YVLLZWIV6SAYBM@prod.waku.nodes.status.im --discv5-discovery=true --discv5-udp-port=9005 --discv5-enr-auto-update=True

wait to get messages in (or send your own non-ephemeral messages..)

THen I got

INF 2023-09-13 15:47:54.442+00:00 database schema is outdated                topics="sqlite" tid=1 file=db_sqlite.nim:444 userVersion=0 targetVersion=7
DBG 2023-09-13 15:47:54.442+00:00 executing migration statement              topics="sqlite" tid=1 file=db_sqlite.nim:461 statement="CREATE TABLE IF NOT EXISTS  Message(\n        id BLOB PRIMARY KEY,\n        timestamp INTEGER NOT NULL,\n        contentTopic BLOB NOT NULL,\n        pubsubTopic BLOB NOT NULL,\n        payload BLOB,\n        version INTEGER NOT NULL\n    ) WITHOUT ROWID;"
DBG 2023-09-13 15:47:54.442+00:00 migration statement executed succesfully   topics="sqlite" tid=1 file=db_sqlite.nim:468 statement="CREATE TABLE IF NOT EXISTS  Message(\n        id BLOB PRIMARY KEY,\n        timestamp INTEGER NOT NULL,\n        contentTopic BLOB NOT NULL,\n        pubsubTopic BLOB NOT NULL,\n        payload BLOB,\n        version INTEGER NOT NULL\n    ) WITHOUT ROWID;"
DBG 2023-09-13 15:47:54.442+00:00 executing migration statement              topics="sqlite" tid=1 file=db_sqlite.nim:461 statement="CREATE TABLE IF NOT EXISTS Message_backup (\n        id BLOB PRIMARY KEY,\n        timestamp INTEGER NOT NULL,\n        contentTopic BLOB NOT NULL,\n        pubsubTopic BLOB NOT NULL,\n        payload BLOB,\n        version INTEGER NOT NULL\n    ) WITHOUT ROWID;"
DBG 2023-09-13 15:47:54.454+00:00 migration statement executed succesfully   topics="sqlite" tid=1 file=db_sqlite.nim:468 statement="CREATE TABLE IF NOT EXISTS Message_backup (\n        id BLOB PRIMARY KEY,\n        timestamp INTEGER NOT NULL,\n        contentTopic BLOB NOT NULL,\n        pubsubTopic BLOB NOT NULL,\n        payload BLOB,\n        version INTEGER NOT NULL\n    ) WITHOUT ROWID;"
DBG 2023-09-13 15:47:54.455+00:00 executing migration statement              topics="sqlite" tid=1 file=db_sqlite.nim:461 statement="INSERT INTO Message_backup SELECT id, timestamp, contentTopic, pubsubTopic, payload, version FROM Message;"
ERR 2023-09-13 15:47:54.468+00:00 failed to execute migration statement      topics="sqlite" tid=1 file=db_sqlite.nim:465 statement="INSERT INTO Message_backup SELECT id, timestamp, contentTopic, pubsubTopic, payload, version FROM Message;" error="constraint failed"
ERR 2023-09-13 15:47:54.468+00:00 4/7 Mounting protocols failed              topics="wakunode main" tid=1 file=wakunode2.nim:85 error="failed to setup archive driver: failed to execute migration scripts: failed to execute migration statement"

Ivansete-status · 2023-09-13T15:59:26Z

Thanks for the comments!
Yes, this is a workaround that doesn't fix the actual problem. The way how @vpavlin runs it makes it to properly run the migration scripts. But, if it runs from a docker compose, then it can't find the migration scripts and crashes.

I will look for a better solution. This cannot be merged indeed.

vpavlin · 2023-09-13T16:01:32Z

No, I do not agree, it is actually executing migrations and failing to insert messages from Message table into Message_backup table for some reason (some constraint is failing - PK, NULL, unique index?) But it does not say what kind of constraint

Ivansete-status · 2023-09-13T16:05:40Z

Okay I see, in my case I saw that the migration scripts are being run properly, having the table empty:

INF 2023-09-13 15:50:54.911+00:00 database schema is outdated                topics="sqlite" tid=1 file=db_sqlite.nim:444 userVersion=0 targetVersion=7
DBG 2023-09-13 15:50:54.911+00:00 executing migration statement              topics="sqlite" tid=1 file=db_sqlite.nim:461 statement="CREATE TABLE IF NOT EXISTS  Message(\n        id BLOB PRIMARY KEY,\n        timestamp INTEGER NOT NULL,\n        contentTopic BLOB NOT NULL,\n        pubsubTopic BLOB NOT NULL,\n        payload BLOB,\n        version INTEGER NOT NULL\n    ) WITHOUT ROWID;"
DBG 2023-09-13 15:50:54.911+00:00 migration statement executed succesfully   topics="sqlite" tid=1 file=db_sqlite.nim:468 statement="CREATE TABLE IF NOT EXISTS  Message(\n        id BLOB PRIMARY KEY,\n        timestamp INTEGER NOT NULL,\n        contentTopic BLOB NOT NULL,\n        pubsubTopic BLOB NOT NULL,\n        payload BLOB,\n        version INTEGER NOT NULL\n    ) WITHOUT ROWID;"
DBG 2023-09-13 15:50:54.911+00:00 executing migration statement              topics="sqlite" tid=1 file=db_sqlite.nim:461 statement="CREATE TABLE IF NOT EXISTS Message_backup (\n        id BLOB PRIMARY KEY,\n        timestamp INTEGER NOT NULL,\n        contentTopic BLOB NOT NULL,\n        pubsubTopic BLOB NOT NULL,\n        payload BLOB,\n        version INTEGER NOT NULL\n    ) WITHOUT ROWID;"
DBG 2023-09-13 15:50:54.921+00:00 migration statement executed succesfully   topics="sqlite" tid=1 file=db_sqlite.nim:468 statement="CREATE TABLE IF NOT EXISTS Message_backup (\n        id BLOB PRIMARY KEY,\n        timestamp INTEGER NOT NULL,\n        contentTopic BLOB NOT NULL,\n        pubsubTopic BLOB NOT NULL,\n        payload BLOB,\n        version INTEGER NOT NULL\n    ) WITHOUT ROWID;"
DBG 2023-09-13 15:50:54.921+00:00 executing migration statement              topics="sqlite" tid=1 file=db_sqlite.nim:461 statement="INSERT INTO Message_backup SELECT id, timestamp, contentTopic, pubsubTopic, payload, version FROM Message;"
DBG 2023-09-13 15:50:54.921+00:00 migration statement executed succesfully   topics="sqlite" tid=1 file=db_sqlite.nim:468 statement="INSERT INTO Message_backup SELECT id, timestamp, contentTopic, pubsubTopic, payload, version FROM Message;"
DBG 2023-09-13 15:50:54.921+00:00 executing migration statement              topics="sqlite" tid=1 file=db_sqlite.nim:461 statement="DROP TABLE Message;"
DBG 2023-09-13 15:50:54.923+00:00 migration statement executed succesfully   topics="sqlite" tid=1 file=db_sqlite.nim:468 statement="DROP TABLE Message;"
DBG 2023-09-13 15:50:54.923+00:00 executing migration statement              topics="sqlite" tid=1 file=db_sqlite.nim:461 statement="CREATE TABLE IF NOT EXISTS Message(\n        id BLOB PRIMARY KEY,\n        receiverTimestamp REAL NOT NULL,\n        contentTopic BLOB NOT NULL,\n        pubsubTopic BLOB NOT NULL,\n        payload BLOB,\n        version INTEGER NOT NULL,\n        senderTimestamp REAL NOT NULL\n    ) WITHOUT ROWID;"
DBG 2023-09-13 15:50:54.924+00:00 migration statement executed succesfully   topics="sqlite" tid=1 file=db_sqlite.nim:468 statement="CREATE TABLE IF NOT EXISTS Message(\n        id BLOB PRIMARY KEY,\n        receiverTimestamp REAL NOT NULL,\n        contentTopic BLOB NOT NULL,\n        pubsubTopic BLOB NOT NULL,\n        payload BLOB,\n        version INTEGER NOT NULL,\n        senderTimestamp REAL NOT NULL\n    ) WITHOUT ROWID;"
DBG 2023-09-13 15:50:54.924+00:00 executing migration statement              topics="sqlite" tid=1 file=db_sqlite.nim:461 statement="INSERT INTO Message (id, receiverTimestamp, contentTopic, pubsubTopic, payload, version, senderTimestamp)\n    SELECT id, timestamp, contentTopic, pubsubTopic, payload, version, 0\n    FROM Message_backup;"
DBG 2023-09-13 15:50:54.924+00:00 migration statement executed succesfully   topics="sqlite" tid=1 file=db_sqlite.nim:468 statement="INSERT INTO Message (id, receiverTimestamp, contentTopic, pubsubTopic, payload, version, senderTimestamp)\n    SELECT id, timestamp, contentTopic, pubsubTopic, payload, version, 0\n    FROM Message_backup;"
DBG 2023-09-13 15:50:54.924+00:00 executing migration statement              topics="sqlite" tid=1 file=db_sqlite.nim:461 statement="DROP TABLE Message_backup;"
DBG 2023-09-13 15:50:54.925+00:00 migration statement executed succesfully   topics="sqlite" tid=1 file=db_sqlite.nim:468 statement="DROP TABLE Message_backup;"
DBG 2023-09-13 15:50:54.925+00:00 executing migration statement              topics="sqlite" tid=1 file=db_sqlite.nim:461 statement="CREATE TABLE IF NOT EXISTS Message_backup (\n        id BLOB PRIMARY KEY,\n        receiverTimestamp REAL NOT NULL,\n        contentTopic BLOB NOT NULL,\n        pubsubTopic BLOB NOT NULL,\n        payload BLOB,\n        version INTEGER NOT NULL,\n        senderTimestamp REAL NOT NULL\n    ) WITHOUT ROWID;"
DBG 2023-09-13 15:50:54.926+00:00 migration statement executed succesfully   topics="sqlite" tid=1 file=db_sqlite.nim:468 statement="CREATE TABLE IF NOT EXISTS Message_backup (\n        id BLOB PRIMARY KEY,\n        receiverTimestamp REAL NOT NULL,\n        contentTopic BLOB NOT NULL,\n        pubsubTopic BLOB NOT NULL,\n        payload BLOB,\n        version INTEGER NOT NULL,\n        senderTimestamp REAL NOT NULL\n    ) WITHOUT ROWID;"
DBG 2023-09-13 15:50:54.926+00:00 executing migration statement              topics="sqlite" tid=1 file=db_sqlite.nim:461 statement="INSERT INTO Message_backup SELECT id, receiverTimestamp, contentTopic, pubsubTopic, payload, version, senderTimestamp FROM Message;"
DBG 2023-09-13 15:50:54.926+00:00 migration statement executed succesfully   topics="sqlite" tid=1 file=db_sqlite.nim:468 statement="INSERT INTO Message_backup SELECT id, receiverTimestamp, contentTopic, pubsubTopic, payload, version, senderTimestamp FROM Message;"
DBG 2023-09-13 15:50:54.926+00:00 executing migration statement              topics="sqlite" tid=1 file=db_sqlite.nim:461 statement="DROP TABLE Message;"
DBG 2023-09-13 15:50:54.927+00:00 migration statement executed succesfully   topics="sqlite" tid=1 file=db_sqlite.nim:468 statement="DROP TABLE Message;"
DBG 2023-09-13 15:50:54.927+00:00 executing migration statement              topics="sqlite" tid=1 file=db_sqlite.nim:461 statement="CREATE TABLE IF NOT EXISTS Message(\n        id BLOB PRIMARY KEY,\n        receiverTimestamp INTEGER NOT NULL,\n        contentTopic BLOB NOT NULL,\n        pubsubTopic BLOB NOT NULL,\n        payload BLOB,\n        version INTEGER NOT NULL,\n        senderTimestamp INTEGER NOT NULL\n    ) WITHOUT ROWID;"
DBG 2023-09-13 15:50:54.928+00:00 migration statement executed succesfully   topics="sqlite" tid=1 file=db_sqlite.nim:468 statement="CREATE TABLE IF NOT EXISTS Message(\n        id BLOB PRIMARY KEY,\n        receiverTimestamp INTEGER NOT NULL,\n        contentTopic BLOB NOT NULL,\n        pubsubTopic BLOB NOT NULL,\n        payload BLOB,\n        version INTEGER NOT NULL,\n        senderTimestamp INTEGER NOT NULL\n    ) WITHOUT ROWID;"
DBG 2023-09-13 15:50:54.928+00:00 executing migration statement              topics="sqlite" tid=1 file=db_sqlite.nim:461 statement="INSERT INTO Message (id, receiverTimestamp, contentTopic, pubsubTopic, payload, version, senderTimestamp)\n    SELECT id, CAST(receiverTimestamp*1000000000 AS INTEGER), contentTopic, pubsubTopic, payload, version, CAST(senderTimestamp*1000000000 AS INTEGER)\n    FROM Message_backup;"
DBG 2023-09-13 15:50:54.928+00:00 migration statement executed succesfully   topics="sqlite" tid=1 file=db_sqlite.nim:468 statement="INSERT INTO Message (id, receiverTimestamp, contentTopic, pubsubTopic, payload, version, senderTimestamp)\n    SELECT id, CAST(receiverTimestamp*1000000000 AS INTEGER), contentTopic, pubsubTopic, payload, version, CAST(senderTimestamp*1000000000 AS INTEGER)\n    FROM Message_backup;"
DBG 2023-09-13 15:50:54.928+00:00 executing migration statement              topics="sqlite" tid=1 file=db_sqlite.nim:461 statement="DROP TABLE Message_backup;"
DBG 2023-09-13 15:50:54.928+00:00 migration statement executed succesfully   topics="sqlite" tid=1 file=db_sqlite.nim:468 statement="DROP TABLE Message_backup;"
DBG 2023-09-13 15:50:54.928+00:00 executing migration statement              topics="sqlite" tid=1 file=db_sqlite.nim:461 statement="ALTER TABLE Message RENAME TO Message_backup;"
DBG 2023-09-13 15:50:54.930+00:00 migration statement executed succesfully   topics="sqlite" tid=1 file=db_sqlite.nim:468 statement="ALTER TABLE Message RENAME TO Message_backup;"
DBG 2023-09-13 15:50:54.931+00:00 executing migration statement              topics="sqlite" tid=1 file=db_sqlite.nim:461 statement="CREATE TABLE IF NOT EXISTS Message(\n        id BLOB,\n        receiverTimestamp INTEGER NOT NULL,\n        contentTopic BLOB NOT NULL,\n        pubsubTopic BLOB NOT NULL,\n        payload BLOB,\n        version INTEGER NOT NULL,\n        senderTimestamp INTEGER NOT NULL,\n        CONSTRAINT messageIndex PRIMARY KEY (senderTimestamp, id, pubsubTopic)\n    ) WITHOUT ROWID;"
DBG 2023-09-13 15:50:54.932+00:00 migration statement executed succesfully   topics="sqlite" tid=1 file=db_sqlite.nim:468 statement="CREATE TABLE IF NOT EXISTS Message(\n        id BLOB,\n        receiverTimestamp INTEGER NOT NULL,\n        contentTopic BLOB NOT NULL,\n        pubsubTopic BLOB NOT NULL,\n        payload BLOB,\n        version INTEGER NOT NULL,\n        senderTimestamp INTEGER NOT NULL,\n        CONSTRAINT messageIndex PRIMARY KEY (senderTimestamp, id, pubsubTopic)\n    ) WITHOUT ROWID;"
DBG 2023-09-13 15:50:54.932+00:00 executing migration statement              topics="sqlite" tid=1 file=db_sqlite.nim:461 statement="INSERT INTO Message\n    SELECT *\n    FROM Message_backup;"
DBG 2023-09-13 15:50:54.932+00:00 migration statement executed succesfully   topics="sqlite" tid=1 file=db_sqlite.nim:468 statement="INSERT INTO Message\n    SELECT *\n    FROM Message_backup;"
DBG 2023-09-13 15:50:54.932+00:00 executing migration statement              topics="sqlite" tid=1 file=db_sqlite.nim:461 statement="DROP TABLE Message_backup;"
DBG 2023-09-13 15:50:54.933+00:00 migration statement executed succesfully   topics="sqlite" tid=1 file=db_sqlite.nim:468 statement="DROP TABLE Message_backup;"
DBG 2023-09-13 15:50:54.933+00:00 executing migration statement              topics="sqlite" tid=1 file=db_sqlite.nim:461 statement="CREATE INDEX IF NOT EXISTS i_msg ON Message (contentTopic, pubsubTopic, senderTimestamp, id);"
DBG 2023-09-13 15:50:54.934+00:00 migration statement executed succesfully   topics="sqlite" tid=1 file=db_sqlite.nim:468 statement="CREATE INDEX IF NOT EXISTS i_msg ON Message (contentTopic, pubsubTopic, senderTimestamp, id);"
DBG 2023-09-13 15:50:54.934+00:00 executing migration statement              topics="sqlite" tid=1 file=db_sqlite.nim:461 statement="ALTER TABLE message RENAME COLUMN receiverTimestamp TO storedAt;"
DBG 2023-09-13 15:50:54.936+00:00 migration statement executed succesfully   topics="sqlite" tid=1 file=db_sqlite.nim:468 statement="ALTER TABLE message RENAME COLUMN receiverTimestamp TO storedAt;"
DBG 2023-09-13 15:50:54.937+00:00 executing migration statement              topics="sqlite" tid=1 file=db_sqlite.nim:461 statement="DROP INDEX IF EXISTS i_msg;"
DBG 2023-09-13 15:50:54.938+00:00 migration statement executed succesfully   topics="sqlite" tid=1 file=db_sqlite.nim:468 statement="DROP INDEX IF EXISTS i_msg;"
DBG 2023-09-13 15:50:54.938+00:00 executing migration statement              topics="sqlite" tid=1 file=db_sqlite.nim:461 statement="CREATE INDEX IF NOT EXISTS i_query ON message (contentTopic, pubsubTopic, storedAt, id);"
DBG 2023-09-13 15:50:54.938+00:00 migration statement executed succesfully   topics="sqlite" tid=1 file=db_sqlite.nim:468 statement="CREATE INDEX IF NOT EXISTS i_query ON message (contentTopic, pubsubTopic, storedAt, id);"
DBG 2023-09-13 15:50:54.939+00:00 executing migration statement              topics="sqlite" tid=1 file=db_sqlite.nim:461 statement="DROP INDEX IF EXISTS i_rt;"
DBG 2023-09-13 15:50:54.939+00:00 migration statement executed succesfully   topics="sqlite" tid=1 file=db_sqlite.nim:468 statement="DROP INDEX IF EXISTS i_rt;"
DBG 2023-09-13 15:50:54.939+00:00 executing migration statement              topics="sqlite" tid=1 file=db_sqlite.nim:461 statement="CREATE INDEX IF NOT EXISTS i_ts ON message (storedAt);"
DBG 2023-09-13 15:50:54.939+00:00 migration statement executed succesfully   topics="sqlite" tid=1 file=db_sqlite.nim:468 statement="CREATE INDEX IF NOT EXISTS i_ts ON message (storedAt);"
DBG 2023-09-13 15:50:54.939+00:00 executing migration statement              topics="sqlite" tid=1 file=db_sqlite.nim:461 statement="ALTER TABLE message RENAME TO message_backup;"
DBG 2023-09-13 15:50:54.942+00:00 migration statement executed succesfully   topics="sqlite" tid=1 file=db_sqlite.nim:468 statement="ALTER TABLE message RENAME TO message_backup;"
DBG 2023-09-13 15:50:54.942+00:00 executing migration statement              topics="sqlite" tid=1 file=db_sqlite.nim:461 statement="CREATE TABLE IF NOT EXISTS message(\n  pubsubTopic BLOB NOT NULL,\n  contentTopic BLOB NOT NULL,\n  payload BLOB,\n  version INTEGER NOT NULL,\n  timestamp INTEGER NOT NULL,\n  id BLOB,\n  storedAt INTEGER NOT NULL,\n  CONSTRAINT messageIndex PRIMARY KEY (storedAt, id, pubsubTopic)\n) WITHOUT ROWID;"
DBG 2023-09-13 15:50:54.943+00:00 migration statement executed succesfully   topics="sqlite" tid=1 file=db_sqlite.nim:468 statement="CREATE TABLE IF NOT EXISTS message(\n  pubsubTopic BLOB NOT NULL,\n  contentTopic BLOB NOT NULL,\n  payload BLOB,\n  version INTEGER NOT NULL,\n  timestamp INTEGER NOT NULL,\n  id BLOB,\n  storedAt INTEGER NOT NULL,\n  CONSTRAINT messageIndex PRIMARY KEY (storedAt, id, pubsubTopic)\n) WITHOUT ROWID;"
DBG 2023-09-13 15:50:54.943+00:00 executing migration statement              topics="sqlite" tid=1 file=db_sqlite.nim:461 statement="INSERT OR IGNORE INTO message(pubsubTopic, contentTopic, payload, version, timestamp, id, storedAt)\n  SELECT pubsubTopic, contentTopic, payload, version, senderTimestamp, id, storedAt\n  FROM message_backup;"
DBG 2023-09-13 15:50:54.943+00:00 migration statement executed succesfully   topics="sqlite" tid=1 file=db_sqlite.nim:468 statement="INSERT OR IGNORE INTO message(pubsubTopic, contentTopic, payload, version, timestamp, id, storedAt)\n  SELECT pubsubTopic, contentTopic, payload, version, senderTimestamp, id, storedAt\n  FROM message_backup;"
DBG 2023-09-13 15:50:54.943+00:00 executing migration statement              topics="sqlite" tid=1 file=db_sqlite.nim:461 statement="DROP TABLE message_backup;"
DBG 2023-09-13 15:50:54.944+00:00 migration statement executed succesfully   topics="sqlite" tid=1 file=db_sqlite.nim:468 statement="DROP TABLE message_backup;"
DBG 2023-09-13 15:50:54.945+00:00 database user_version updated              topics="sqlite" tid=1 file=db_sqlite.nim:473 userVersion=7
DBG 2023-09-13 15:50:54.945+00:00 finished message store's sqlite database migration topics="waku archive migration" tid=1 file=migrations.nim:37

jm-clius · 2023-09-13T16:10:16Z

Right, so this may have been caused by a migration that was interrupted? One impact is that potentially there might now be inconsistent schemas on upgraded nodes (since the migration failed) and a temporary backup tables that were never deleted. The fix would be to ensure that the migration is fixed and that impacted nodes can properly "get themselves out of the situation"?

vpavlin · 2023-09-13T16:12:43Z

Migration 00004_extendPrimaryKey "broke it"

Because it changes the PK to also inclide senderTimestamp, so when the user_version is wrong and the migrations try to re-run from scratch, since the 00004 already happened, the older migrations could have duplicates for the old PK (which was only id column) - we can have same id accross multiple messages after 00004 is applied since the PK consists of multiple columns

So if the user_version is 0, nwaku re-runs all the migrations and migration script 00002 will fail because some rows may have conflicting id values

So the real issue is really actually missing user_version which breaks the whole migration process (and forces nwaku to start from scratch, although the DB is already past that point)

vpavlin · 2023-09-13T16:16:46Z

My proposal would to

check the user_version and if it is 0, then we are starting from scratch, or it is highly probably the screwed up v0.17.0 release
Analyze the schema and decide if it actually matches 0.17.0
If it does match, set the user_version in the DB

Execute all the above before migrations kick in, so when they do, we actually go from the right schema version

THen keep this workaround in for a few releases to make sure people have enough time to migrate from 0.17.0 and then remove the check

WDYT?

Ivansete-status · 2023-09-13T16:33:36Z

My proposal would to ...

I like the idea of checking the current schema, as you mentioned to me on Discord, and if the PK has three columns, then we assume that the version is 7, and we write 7 to the user_version, and skip the migration procedure.

Ivansete-status · 2023-09-13T16:37:41Z

Btw, the schema version was set to 7 in the next commit: 4509f4f

And therefore, started to be present from the nwaku 0.13.0.

…sion==0" This reverts commit 605b04e.

…mary key

Ivansete-status · 2023-09-13T18:08:51Z

Not sure I follow this fix - why would we consider nodes with user_version=0 to be up to date? How will we update their schemas in future? And do we know why the user_version would have been reset to 0 at all? If we know why this would have happened, I would imagine a temporary fix script is that for such nodes the user_version should be set to the latest target_version and migration skipped.

The main issue is that, when starting a node from scratch with for example 0.17.0, it doesn't set the SchemaVersion at all, although it is creating a database whose scheme reflects the expectations for version 7.

In the PR I'm applying @vpavlin's suggestion: if user_version == 0 && num_columns_in_PK == 3, then enforce SchemaVersion (user_version) to 7 within the database, and that fixes the database itself and then, a 0.19.0 version can start correctly.

Ivansete-status · 2023-09-13T18:39:42Z

🔔 The migration problem started to occur in version 0.14.0. In other words, the node started with SchemaVersion 7 (three columns in PK) but didn't set the user_version to 7 because the "migration" scripts didn't kick off.

The reason why the migration scripts didn't start is because the migration.nim file was moved to a deeper folder but the relative path was not updated. That can be seen by looking for "migrations.nim" in https://github.com/waku-org/nwaku/compare/v0.13.0..v0.14.0

vpavlin · 2023-09-14T08:26:00Z

waku/waku_archive/driver/sqlite_driver/migrations.nim

+    info "We found user_version 0 but the database schema reflects the user_version 7"
+    ## Force the correct schema version
+    ? db.setUserVersion( 7 )
+    return ok()


What happens in case where

User is running v0.17.0

We update schema in v0.21.0

User updates to v0.21.0

IIUC the user_version gets set to 7 and then migrate proc returns and the migration does not happen - which is wrong - right? IMO the migration should continue with corrected user_version

Good point!
In this case, the migration should not happen because the database is using the schema version 7 (three columns in PK) but the user_version value was 0.

If we update the schema in 0.21.0 we will need to revisit this logic of course. In fact, I think we need to modify this logic the next time we modify the schema somehow.

jm-clius

Approving, as it seems like this will indeed fix the immediate issue. What bothers me though is that the CREATE script will still create a DB now with user_version 0 and this logic just updates it to 7? I think the CREATE script itself should set the user_version to the correct schema number.

Ivansete-status · 2023-09-14T11:09:44Z

Thanks so much indeed for the feedback and comments guys!

I recently applied a better approach, advised by @vpavlin, and we aim to have a future-proof solution.

We'd need to keep this workaround during 10 version (?)

I'll elaborate more on the actual problem in the related issue

vpavlin · 2023-09-14T11:33:28Z

Approving, as it seems like this will indeed fix the immediate issue. What bothers me though is that the CREATE script will still create a DB now with user_version 0 and this logic just updates it to 7? I think the CREATE script itself should set the user_version to the correct schema number.

Ah, you are right, I haven't realized - if the DB is initialized from scratch, it will have user_version = 0, only if it got migrated it will have 7, so we should set the user_verion on init of the DB, which should prevent future issues with this

vpavlin

Tested the upgrade from "broken" v0.17.0 instance to this PR and it worked.

I think we are ok even if we merge it like this, but we need to resolve the cause (which seems to be not setting user_version on DB init) soon-ish

…cedure is not started (#2031)

sqlite: Prevent the execution of 'migrate' script if user_version==0

605b04e

Ivansete-status self-assigned this Sep 13, 2023

Ivansete-status marked this pull request as ready for review September 13, 2023 15:27

Ivansete-status requested review from vpavlin, SionoiS, jm-clius and NagyZoltanPeter September 13, 2023 15:28

Revert "sqlite: Prevent the execution of 'migrate' script if user_ver…

5ec025b

…sion==0" This reverts commit 605b04e.

Ivansete-status removed request for vpavlin, SionoiS, jm-clius and NagyZoltanPeter September 13, 2023 16:42

Ivansete-status added 2 commits September 13, 2023 19:29

sqlite: Enforcing SchemaVersion 7 if we find three columns in the pri…

60f256f

…mary key

migrations.nim: adding missing import

a98e0bc

Ivansete-status requested review from vpavlin, SionoiS and jm-clius September 13, 2023 18:10

Ivansete-status requested a review from NagyZoltanPeter September 13, 2023 18:10

migrations.nim: Correct error message

3379a4e

vpavlin reviewed Sep 14, 2023

View reviewed changes

jm-clius approved these changes Sep 14, 2023

View reviewed changes

migrations: Better approach to enhance the 'user_version==0' issue

3fb0d0a

vpavlin mentioned this pull request Sep 14, 2023

chore(rln-relay): logs, updated submodule, leaves_set metric #2024

Merged

3 tasks

vpavlin approved these changes Sep 14, 2023

View reviewed changes

Ivansete-status merged commit aa3e1a6 into master Sep 14, 2023
16 checks passed

Ivansete-status deleted the fix-user-version-migrate-sqlite branch September 14, 2023 12:12

vpavlin pushed a commit that referenced this pull request Sep 14, 2023

fix(sqlite): Properly set user_version to 7 so that the migration pro…

638ff31

…cedure is not started (#2031)

vpavlin mentioned this pull request Sep 14, 2023

bug: DB user_version is not set on database init #2036

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

fix(sqlite): Prevent the execution of 'migrate' script if user_version==0 #2031

fix(sqlite): Prevent the execution of 'migrate' script if user_version==0 #2031

Ivansete-status commented Sep 13, 2023 •

edited

Loading

github-actions bot commented Sep 13, 2023 •

edited

Loading

jm-clius commented Sep 13, 2023

vpavlin commented Sep 13, 2023

vpavlin commented Sep 13, 2023

Ivansete-status commented Sep 13, 2023

vpavlin commented Sep 13, 2023

Ivansete-status commented Sep 13, 2023

jm-clius commented Sep 13, 2023

vpavlin commented Sep 13, 2023

vpavlin commented Sep 13, 2023 •

edited

Loading

Ivansete-status commented Sep 13, 2023

Ivansete-status commented Sep 13, 2023

Ivansete-status commented Sep 13, 2023

Ivansete-status commented Sep 13, 2023

vpavlin Sep 14, 2023

Ivansete-status Sep 14, 2023

jm-clius left a comment

Ivansete-status commented Sep 14, 2023

vpavlin commented Sep 14, 2023

vpavlin left a comment

fix(sqlite): Prevent the execution of 'migrate' script if user_version==0 #2031

fix(sqlite): Prevent the execution of 'migrate' script if user_version==0 #2031

Conversation

Ivansete-status commented Sep 13, 2023 • edited Loading

Description

Changes

How to replicate the issue:

How to validate the fix:

Issue

github-actions bot commented Sep 13, 2023 • edited Loading

jm-clius commented Sep 13, 2023

vpavlin commented Sep 13, 2023

vpavlin commented Sep 13, 2023

Ivansete-status commented Sep 13, 2023

vpavlin commented Sep 13, 2023

Ivansete-status commented Sep 13, 2023

jm-clius commented Sep 13, 2023

vpavlin commented Sep 13, 2023

vpavlin commented Sep 13, 2023 • edited Loading

Ivansete-status commented Sep 13, 2023

Ivansete-status commented Sep 13, 2023

Ivansete-status commented Sep 13, 2023

Ivansete-status commented Sep 13, 2023

vpavlin Sep 14, 2023

Choose a reason for hiding this comment

Ivansete-status Sep 14, 2023

Choose a reason for hiding this comment

jm-clius left a comment

Choose a reason for hiding this comment

Ivansete-status commented Sep 14, 2023

vpavlin commented Sep 14, 2023

vpavlin left a comment

Choose a reason for hiding this comment

Ivansete-status commented Sep 13, 2023 •

edited

Loading

github-actions bot commented Sep 13, 2023 •

edited

Loading

vpavlin commented Sep 13, 2023 •

edited

Loading