Missing database migration for `active_slot_coeff` #1251

KtorZ · 2020-01-07T14:52:23Z

Context

We "recently" added the active_slot_coeff blockchain parameters to the checkpoint data. Yet, for database existing before the release, we have missed a migration..

Information	-
Version	v2019.12.16+
Platform	All
Installation	N/A

Steps to Reproduce

Create a wallet with a version prior to v2019.12.16
Stop the server
Start a server running on v2019.12.16+

Expected behavior

Wallets can be restored successfully

Actual behavior

The worker exits because of a failing migration.

SQLite3 returned ErrorConstraint while attempting to perform step: NOT NULL constraint failed: checkpoint_backup.active_slot_coeff

Resolution

Run manual migration to migrate databases with default values for missing field ==> Add a manual DB migration step for active_slot_coeff. #1266

QA

Correct behavior is visible from the logs:

[...]
[cardano-wallet.network:Info:22] [2020-01-18 17:01:00.96 UTC] Waiting for Jörmungandr to be ready on tcp/35027
[cardano-wallet.application:Info:22] [2020-01-18 17:01:00.97 UTC] Found existing wallet: c8416497faead398770a1ae14eb31a41683c8f67
[cardano-wallet.wallet-db:Notice:28] [2020-01-18 17:01:00.97 UTC] checkpoint table does not contain required field 'active_slot_coeff'. Adding this field with a default value of 1.0.
[...]
[cardano-wallet.wallet-engine:Info:28] [2020-01-18 17:01:00.99 UTC] c8416497: Applying blocks [1158224.6 ... 1158226.8]

How to reproduce the above:

Download v2019-12-13
Launch the server using integration config params
Create a wallet
Turn it off, and launch the server using latest master
Observe

On subsequent runs, nothing is logged, unless the severity is at least DEBUG

$ cardano-wallet launch ... --trace-wallet-db debug --log-level debug -- ... 
[...]
[cardano-wallet.wallet-db:Debug:28] [2020-01-18 17:02:06.23 UTC] checkpoint table already contains required field 'active_slot_coeff'.
[cardano-wallet.wallet-db:Debug:28] [2020-01-18 17:02:06.23 UTC] Running database action - Start
[cardano-wallet.wallet-db:Debug:28] [2020-01-18 17:02:06.23 UTC] Running database action - Finish
[cardano-wallet.wallet-db:Debug:28] [2020-01-18 17:02:06.23 UTC] No database migrations were necessary.

The text was updated successfully, but these errors were encountered:

jonathanknowles · 2020-01-08T07:19:44Z

Hi @KtorZ

What value should the migration provide, and how should it obtain this value?

The current values seem to be obtained by reading getActiveSlotCoefficient from the value obtained by calling getInitialBlockchainParameters (which is dependent on the Jormungandr backend). Can this value change between calls?

Is this parameter available at the point where we perform a DB migration, and should we use the current value, or a historical value instead?

(Inspecting the DB manually shows this value is currently 1.0.)

jonathanknowles · 2020-01-09T03:44:23Z

I tried to reproduce this with the following steps:

Build release v2019-12-13 (the release prior to v2019-12-16).
Start the server (with launch) and create a wallet.
Shut down the server.
Build e135938 (the current tip of master)
Start the server (with `launch).

I get the following pool_owner_index error, which is slightly different from the error reported in this issue:

[cardano-wallet:Debug:22] [2020-01-09 03:15:00.49 UTC] Using connection string: /home/jsk/.local/share/cardano-wallet/jormungandr/testnet/wallets/stake-pools.sqlite
[cardano-wallet.query:Debug:22] [2020-01-09 03:15:00.49 UTC] CREATE TEMP TABLE "pool_owner_backup"("pool_id" VARCHAR NOT NULL,"pool_owner" VARCHAR NOT NULL,"pool_owner_index" INTEGER
 NOT NULL, PRIMARY KEY ("pool_id","pool_owner","pool_owner_index"))
[cardano-wallet.query:Debug:22] [2020-01-09 03:15:00.49 UTC] INSERT INTO "pool_owner_backup"("pool_id","pool_owner") SELECT "pool_id","pool_owner" FROM "pool_owner"
SQLite3 returned ErrorConstraint while attempting to perform step: NOT NULL constraint failed: pool_owner_backup.pool_owner_index
[cardano-wallet:Debug:4] [2020-01-09 03:15:00.49 UTC] Logging shutdown.
cardano-wallet-jormungandr: SQLite3 returned ErrorConstraint while attempting to perform step: NOT NULL constraint failed: pool_owner_backup.pool_owner_index

I'll try to reproduce with an earlier version (v2019-12-16), and see if I can replicate the same error reported in this issue.

jonathanknowles · 2020-01-09T03:51:51Z

Just tried with v2019-12-13 --> v2019-12-16, and got the same pool_owner_index error on startup:

[cardano-wallet:Debug:22] [2020-01-09 03:50:23.50 UTC] Using connection string: /home/jsk/.local/share/cardano-wallet/jormungandr/testnet/wallets/stake-pools.sqlite
[cardano-wallet.query:Debug:22] [2020-01-09 03:50:23.51 UTC] CREATE TEMP TABLE "pool_owner_backup"("pool_id" VARCHAR NOT NULL,"pool_owner" VARCHAR NOT NULL,"pool_owner_index" INTEGER NOT NULL, PRIMARY KEY ("pool_id","pool_owner","pool_owner_index"))
[cardano-wallet.query:Debug:22] [2020-01-09 03:50:23.51 UTC] INSERT INTO "pool_owner_backup"("pool_id","pool_owner") SELECT "pool_id","pool_owner" FROM "pool_owner"
SQLite3 returned ErrorConstraint while attempting to perform step: NOT NULL constraint failed: pool_owner_backup.pool_owner_index
[cardano-wallet:Debug:4] [2020-01-09 03:50:23.51 UTC] Logging shutdown.
cardano-wallet-jormungandr: SQLite3 returned ErrorConstraint while attempting to perform step: NOT NULL constraint failed: pool_owner_backup.pool_owner_index

jonathanknowles · 2020-01-09T04:14:14Z

Okay. I can finally reproduce the bug described in this issue, but only after performing the following steps:

Build release v2019-12-13 (the release prior to v2019-12-16).
Start the server (with launch) and create a wallet.
Shut down the server.
Delete the file ~/.local/share/cardano-wallet/jormungandr/testnet/wallets/stake-pools.sqlite.
Build release v2019-12-16.
Start the server (with launch).

Then we see:

SQLite3 returned ErrorConstraint while attempting to perform step: NOT NULL constraint failed: checkpoint_backup.active_slot_coeff
[cardano-wallet.worker:Error:28] [2020-01-09 04:13:50.61 UTC] bf04d83b: Worker has exited unexpectedly: SQLite3 returned ErrorConstraint while attempting to perform step: NOT NULL constraint failed: checkpoint_backup.active_slot_coeff

jonathanknowles · 2020-01-09T06:08:54Z

@KtorZ Should we create a separate bug report for #1251 (comment)?

It's trivial to work around (by deleting ~/.local/share/cardano-wallet/jormungandr/testnet/wallets/stake-pools.sqlite and restarting), but perhaps it is something that we should handle automatically, instead of asking users to delete files manually.

KtorZ · 2020-01-09T09:21:05Z

@jonathanknowles This was a known issue taken care of by #1177. The pool database will "migrate" itself automatically but that's only since v2019.12.23 (or exactly, a few commits after v2019.12.16).

KtorZ · 2020-01-09T09:21:56Z

So, in order to reproduce the bug above, it's probably best to go from v2019.12.13 to v2019.12.23 (or simply current master) such that the pool db migration error is handled, and remains only the active_slot_coeff one.

jonathanknowles · 2020-01-13T03:21:01Z

So, in order to reproduce the bug above, it's probably best to go from v2019.12.13 to v2019.12.23 (or simply current master) such that the pool db migration error is handled, and remains only the active_slot_coeff one.

@KtorZ Unfortunately this doesn't appear to be working.

Going from v2019-12-13 (f3576be) to the current master (10b5512) still results in an NOT NULL constraint failed: pool_owner_backup.pool_owner_index error:

jsk@neon:~/projects/input-output-hk/cardano-wallet$ stack exec cardano-wallet-jormungandr -- launch --genesis-block lib/jormungandr/test/data/jormungandr/block0.bin
[cardano-wallet:Info:4] [2020-01-13 03:17:06.42 UTC] Using directory: /home/jsk/.local/share/cardano-wallet/jormungandr/testnet
[cardano-wallet:Info:4] [2020-01-13 03:17:06.42 UTC] Using directory: /home/jsk/.local/share/cardano-wallet/jormungandr/testnet/wallets
[cardano-wallet:Info:4] [2020-01-13 03:17:06.42 UTC] Running as v2020.1.7 (git revision: 10b5512222e09ef788dcea82628113add4291460)
[cardano-wallet.application:Info:4] [2020-01-13 03:17:06.42 UTC] Wallet backend server starting...
[cardano-wallet.application:Info:4] [2020-01-13 03:17:06.42 UTC] Node is Jörmungandr on testnet
[cardano-wallet.daedalus-ipc:Info:17] [2020-01-13 03:17:06.42 UTC] Daedalus IPC is not enabled.
[cardano-wallet.network:Notice:18] [2020-01-13 03:17:06.44 UTC] Starting process jormungandr
     --genesis-block lib/jormungandr/test/data/jormungandr/block0.bin
     --rest-listen 127.0.0.1:35759
     --storage /home/jsk/.local/share/cardano-wallet/jormungandr/testnet/chain

[cardano-wallet.network:Info:18] [2020-01-13 03:17:06.44 UTC] [jormungandr.17209] Process started
Jan 13 03:17:06.451 INFO Starting jormungandr 0.8.5 (, release, linux [x86_64]) - [rustc 1.38.0 (625451e37 2019-09-23)], task: init
Jan 13 03:17:06.451 WARN Node started without path to the stored secret keys (not a stake pool or a BFT leader), task: init
Jan 13 03:17:06.452 INFO storing blockchain in '"/home/jsk/.local/share/cardano-wallet/jormungandr/testnet/chain/blocks.sqlite"', task: init
Jan 13 03:17:06.493 WARN No trusted peers joinable to bootstrap the network, task: bootstrap
[cardano-wallet.network:Info:22] [2020-01-13 03:17:07.45 UTC] Waiting for Jörmungandr to be ready on tcp/35759
[cardano-wallet.network:Info:22] [2020-01-13 03:17:07.45 UTC] Jörmungandr is ready.
cardano-wallet-jormungandr: SQLite3 returned ErrorConstraint while attempting to perform step: NOT NULL constraint failed: pool_owner_backup.pool_owner_index

But as pointed out in #1251 (comment), I can work around this issue by deleting ~/.local/share/cardano-wallet/jormungandr/testnet/wallets/stake-pools.sqlite and restarting, and only then do I see the following error:

wallet.application:Info:22] [2020-01-13 03:20:19.70 UTC] Found existing wallet: b15b1cc1109485096c779c3605a7e22e71654fb9
[cardano-wallet.wallet-engine:Info:28] [2020-01-13 03:20:19.70 UTC] b15b1cc1: Worker has exited unexpectedly: SQLite3 returned ErrorConstraint while attempting to perform step: NOT N
ULL constraint failed: checkpoint_backup.active_slot_coeff

KtorZ · 2020-01-13T14:24:37Z

@jonathanknowles indeed :o !
I thought it was an occurence of #1200 but, it is yet something else. See #1261

Fell-x27 · 2020-01-13T22:23:05Z

I'm afraid there is one more trouble. Don't know why, but sometimes in the end of an epoch cardanoWallet pools worker may just stuck and remove the database with no any actions after. But it recreates this after manually restart. I cant reproduce it by my wish, so didnt open an issue. Prolly its related with something from this thread.

jonathanknowles · 2020-01-14T07:57:40Z

Hi @KtorZ

@rvl and I had a discussion about this issue earlier today. We came up with two potential solutions:

Solution 1: Remove the field

Change the code so that it gets the activeSlotCoefficient value from the (initial) result of calling getInitialBlockchainParameters on the backend node (e.g., Jörmungandr) rather than reading it from the checkpoint table.
Remove the active_slot_coeff field from the checkpoint table schema definition inCardano.Wallet.DB.Sqlite.TH.
Change newDBLayer so that immediately after calling startSqliteBackend, we check whether the checkpoint table has an active_slot_coeff field.
If the field IS present, we:
- issue a query to delete this field from the table;
- continue with startup as normal.

Solution 2: Keep the field

Change newDBLayer so that after calling startSqliteBackend, we check whether the checkpoint table has the active_slot_coeff field.
If the field is NOT present, we:
- issue a query to delete all rows from the checkpoint table (since they don't have a value for this field, and we can't assume a particular default value);
- issue a query to add the active_slot_coeff field;
- continue with startup as normal.

@KtorZ From the above options, do you have a strong preference for how we solve this issue?

Thanks!

1261: widen 'isMigrationError' to catch constraint errors r=KtorZ a=KtorZ # Issue Number  #1251 # Overview  On start-up, we run persistent migrations and in case of migration issues, we execute some particular handling (e.g. the pool db resets itself). Yet, we failed at catching migration issues coming from constraints introduced later and that can't be satisfied on already existing data. This commit fixes it. Before ====== ``` [cardano-wallet.network:Info:22] Jörmungandr is ready. cardano-wallet-jormungandr: SQLite3 returned ErrorConstraint while attempting to perform step: NOT NULL constraint failed: pool_owner_backup.pool_owner_index (exiting with an error code) ``` After ===== ``` [cardano-wallet.network:Info:22] Jörmungandr is ready. [cardano-wallet.stake-pool-db:Error:22] Failed to migrate the database: : NOT NULL constraint failed: pool_owner_backup.pool_owner_index [cardano-wallet.stake-pool-db:Notice:22] Non backward compatible database found. Removing old database and re-creating it from scratch. Ignore the previous error. [cardano-wallet.stake-pool-db:Notice:22] 1 migrations were applied to the database. (... and continuing as normal) ``` # Comments   Co-authored-by: KtorZ <matthias.benkort@gmail.com>

KtorZ · 2020-01-14T09:48:27Z

@Fell-x27 if you'd like to open an issue describing what you saw (logs are especially useful in that case), please do 🙏

@jonathanknowles Solution 1 is not going to be an option I am afraid. The active_slot_coefficient belongs to the realm of updatable protocol parameters. Thus, even though reading it from the genesis block would work as an immediate fix, we would have to re-introduce it to be tracked alongside checkpoint anyway.

Solution 2 works better if I understand correctly what the approach would be. Incidentally, I just discussed with Daedalus something suggested by a user earlier in a GH ticket: the ability to force-resync a wallet. This would be pretty handy at this level here, forcing to drop every checkpoints in the database (but the genesis one) and, resync.
The main problem with doing this for the migration is that we would have to also drop the genesis checkpoint here, because it also contains the active slot coefficient. This checkpoint can however be replaced easily without loss of user-data (which are stored in a separate table).

1266: Add a manual DB migration step for `active_slot_coeff`. r=KtorZ a=jonathanknowles # Issue Number #1251 # Overview This PR: - [x] Adds the ability to perform manual DB migration actions after connecting to a SQLite database. - [x] Uses this ability to detect whether or not the `active_slot_coeff` field is present in the `checkpoint` table. - [x] Adds the `active_slot_coeff` field manually, if it was not present already, using a default value that is passed down from the network layer. - [ ] Figure out the cause of repeated log entries of the form: ```hs [cardano-wallet.wallet-engine:Info:29] [2020-01-16 09:05:14.78 UTC] e834cdb3: Try rolling back to 0.0 [cardano-wallet.wallet-engine:Info:29] [2020-01-16 09:05:14.78 UTC] e834cdb3: Rolled back to 0.0 ``` # Comments Co-authored-by: Jonathan Knowles <jonathan.knowles@iohk.io> Co-authored-by: KtorZ <matthias.benkort@gmail.com>

piotr-iohk · 2020-01-20T09:54:56Z

OK. migration from 2019-12-13 to recent master works fine now. I suppose. Wallet is operational and works fine after migration.

[cardano-wallet.pools-db:Error:22] [2020-01-20 09:36:33.35 UTC] Failed to migrate the database: : NOT NULL constraint failed: pool_owner_backup.pool_owner_index
[cardano-wallet.pools-db:Notice:22] [2020-01-20 09:36:33.35 UTC] Non backward compatible database found. Removing old database and re-creating it from scratch. Ignore the previous error.

piotr-iohk · 2020-01-20T09:55:12Z

Automated migration tests are passing -> https://buildkite.com/input-output-hk/cardano-wallet-nightly/builds/371#e64aa5e1-faf7-4ae5-be57-eade6c91f32d

KtorZ added the BUG:CONFIRMED label Jan 7, 2020

KtorZ mentioned this issue Jan 7, 2020

Missed UTXO #1230

Closed

KtorZ mentioned this issue Jan 13, 2020

widen 'isMigrationError' to catch constraint errors #1261

Merged

jonathanknowles mentioned this issue Jan 15, 2020

Add a manual DB migration step for active_slot_coeff. #1266

Merged

4 tasks

rvl mentioned this issue Jan 16, 2020

Add database migration test #1190

Merged

KtorZ assigned jonathanknowles Jan 16, 2020

piotr-iohk closed this as completed Jan 20, 2020

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Missing database migration for `active_slot_coeff` #1251

Missing database migration for `active_slot_coeff` #1251

KtorZ commented Jan 7, 2020 •

edited

Loading

jonathanknowles commented Jan 8, 2020

jonathanknowles commented Jan 9, 2020 •

edited

Loading

jonathanknowles commented Jan 9, 2020 •

edited

Loading

jonathanknowles commented Jan 9, 2020 •

edited

Loading

jonathanknowles commented Jan 9, 2020 •

edited

Loading

KtorZ commented Jan 9, 2020

KtorZ commented Jan 9, 2020 •

edited

Loading

jonathanknowles commented Jan 13, 2020 •

edited

Loading

KtorZ commented Jan 13, 2020

Fell-x27 commented Jan 13, 2020 •

edited

Loading

jonathanknowles commented Jan 14, 2020 •

edited

Loading

KtorZ commented Jan 14, 2020

piotr-iohk commented Jan 20, 2020

piotr-iohk commented Jan 20, 2020

Missing database migration for active_slot_coeff #1251

Missing database migration for active_slot_coeff #1251

Comments

KtorZ commented Jan 7, 2020 • edited Loading

Context

Steps to Reproduce

Expected behavior

Actual behavior

Resolution

QA

jonathanknowles commented Jan 8, 2020

jonathanknowles commented Jan 9, 2020 • edited Loading

jonathanknowles commented Jan 9, 2020 • edited Loading

jonathanknowles commented Jan 9, 2020 • edited Loading

jonathanknowles commented Jan 9, 2020 • edited Loading

KtorZ commented Jan 9, 2020

KtorZ commented Jan 9, 2020 • edited Loading

jonathanknowles commented Jan 13, 2020 • edited Loading

KtorZ commented Jan 13, 2020

Fell-x27 commented Jan 13, 2020 • edited Loading

jonathanknowles commented Jan 14, 2020 • edited Loading

Solution 1: Remove the field

Solution 2: Keep the field

KtorZ commented Jan 14, 2020

piotr-iohk commented Jan 20, 2020

piotr-iohk commented Jan 20, 2020

Missing database migration for `active_slot_coeff` #1251

Missing database migration for `active_slot_coeff` #1251

KtorZ commented Jan 7, 2020 •

edited

Loading

jonathanknowles commented Jan 9, 2020 •

edited

Loading

jonathanknowles commented Jan 9, 2020 •

edited

Loading

jonathanknowles commented Jan 9, 2020 •

edited

Loading

jonathanknowles commented Jan 9, 2020 •

edited

Loading

KtorZ commented Jan 9, 2020 •

edited

Loading

jonathanknowles commented Jan 13, 2020 •

edited

Loading

Fell-x27 commented Jan 13, 2020 •

edited

Loading

jonathanknowles commented Jan 14, 2020 •

edited

Loading