| Posted | Nick | Remark | |
|---|---|---|---|
| #openstack-nova - 2020-02-06 | |||
| 16:11:46 | mnaser | ..but it somehow KEPT going with the migrations? | |
| 16:11:54 | dansmith | what migration failed? | |
| 16:12:12 | mnaser | http://paste.openstack.org/show/789229/ | |
| 16:12:39 | dansmith | wow, that's interesting | |
| 16:12:43 | mnaser | dansmith: pastebin.com sounds like it only contains leaks of *stuff* | |
| 16:12:48 | mnaser | let me look at what migration is that | |
| 16:13:04 | mnaser | so i think it failed but the version was bumped | |
| 16:13:05 | dansmith | "add instances hidden" | |
| 16:13:06 | mnaser | and then it kept going after | |
| 16:13:10 | dansmith | yeah, that'd do it | |
| 16:13:38 | dansmith | although, it doesn't use server_default so it's a little weird | |
| 16:13:54 | dansmith | mnaser: does your instances table have a "hidden" column? | |
| 16:14:18 | mnaser | https://github.com/openstack/nova/blob/master/nova/db/sqlalchemy/migrate_repo/versions/399_add_instances_hidden.py <- for whoever is following and my notes | |
| 16:14:22 | mnaser | yes i'm checking that now | |
| 16:14:23 | dansmith | right | |
| 16:14:38 | mnaser | i am gonna assume | |
| 16:14:40 | mnaser | it does | |
| 16:14:41 | dansmith | the thing is that default is not server_default, so I would expect you're not missing that | |
| 16:14:51 | mnaser | tahts probably why new instances are ok | |
| 16:14:51 | dansmith | mnaser: you're assuming or you checked? | |
| 16:14:52 | mnaser | and old ones are not | |
| 16:14:56 | mnaser | (iam going to check now) | |
| 16:15:05 | mnaser | but that might make sense as to why the new instances (11) show up | |
| 16:15:16 | dansmith | hidden defaults to false on the code side, which means if it exists, they should all default to hidden=False, | |
| 16:15:22 | dansmith | and if it didn't exist, you should be getting query errors | |
| 16:15:24 | mnaser | | hidden | tinyint(1) | YES | | NULL | | | |
| 16:15:49 | dansmith | I think that's the right schema | |
| 16:15:55 | mnaser | there is 57 instances with hidden=0 | |
| 16:15:57 | mnaser | and the rest are null. | |
| 16:16:11 | mnaser | id be update instances set hidden=0; would fix it | |
| 16:16:20 | dansmith | right, and those NULLs should be presumed =False by the python side | |
| 16:16:26 | dansmith | well, | |
| 16:16:43 | dansmith | maybe to get you out of the jam, but... that's not what *should* be happening | |
| 16:17:04 | mnaser | right yeah, you're right, hidden being null should default to false | |
| 16:17:09 | mnaser | let me get out of my jam and i will look at the code | |
| 16:17:43 | dansmith | oooh, | |
| 16:17:46 | dansmith | this might be a bug | |
| 16:17:48 | dansmith | a really bad one | |
| 16:18:01 | dansmith | let it be known that mriedem may have made a mistake | |
| 16:18:23 | mnaser | he left us with a fun one :( | |
| 16:18:39 | dansmith | it's not a hard fix | |
| 16:19:23 | dansmith | mnaser: is this the first s->t upgrade for you? | |
| 16:19:31 | mnaser | dansmith: no, and i didnt hit the first time | |
| 16:19:35 | mnaser | but i also dont think i hit that db migration issue that time too | |
| 16:19:43 | dansmith | oh, hrm | |
| 16:19:56 | dansmith | the db migration doesn't seem to have left the schema incorrect though | |
| 16:21:15 | mriedem | fake news | |
| 16:21:19 | mnaser | lol | |
| 16:21:31 | mnaser | dansmith: i think it acutally tried to do an update and set things hidden=0 | |
| 16:21:35 | dansmith | mnaser: can you compare that bit of schema to one of your other clusters, and also look at the hidden values on those instances/ | |
| 16:21:39 | mnaser | (this is a much bigger cloud) | |
| 16:21:46 | mnaser | and my stupid update instances set hidden=0 gave me this | |
| 16:21:50 | mnaser | ERROR 1180 (HY000): Got error 90 "Message too long" during COMMIT | |
| 16:21:58 | dansmith | mnaser: okay it shouldn't be doing that | |
| 16:21:59 | mnaser | so its almost like once it does the schema update, it bumps the version, and then tries to backfill default values | |
| 16:22:08 | mnaser | let me check the value of hidden in the other train deployemnt | |
| 16:22:11 | dansmith | yeah, that's not the intent of that migration for sure | |
| 16:22:13 | openstackgerrit | Merged openstack/nova-specs master: FUP: Fixed the invalid index in References https://review.opendev.org/705933 | |
| 16:23:03 | dansmith | maybe in some situations sqla-migrate actually tries to patch up data for you on existing tables, which is a real problem | |
| 16:23:18 | mnaser | ok yeah | |
| 16:23:26 | mnaser | the other deployment has hidden=0 for every single record | |
| 16:23:30 | dansmith | and if so, this is a good example of why we don't do data transformation (intentionally) in schema migrations | |
| 16:23:31 | dansmith | okay damn | |
| 16:23:57 | dansmith | so we need to change that migration retroactively, and patch the load code to properly interpret the null as the default (which sqla does not do with default=) | |
| 16:24:10 | mnaser | so i think what happened is: schema updated and column added, db version bumped, backfill values to 0 | |
| 16:24:22 | mnaser | and then i failed in the backfill, so the next run it just started from the next migration | |
| 16:24:25 | dansmith | yeah, and on your big cloud, that timed out | |
| 16:24:39 | dansmith | yeah, probably because the backfill wasn't technically a schema fail | |
| 16:24:41 | dansmith | which is also scary | |
| 16:25:18 | mnaser | i think your theory is best | |
| 16:25:23 | mnaser | s/theory/solution/ | |
| 16:25:23 | openstackgerrit | Stephen Finucane proposed openstack/nova master: objects: Add MigrationTypeField https://review.opendev.org/706013 | |
| 16:25:24 | dansmith | mnaser: can you file a bug for me to write this up against? | |
| 16:25:39 | mnaser | sure | |
| 16:25:47 | dansmith | thanks | |
| 16:26:57 | mriedem | fwiw i count 5 non-api db schema migrations that add a new boolean column with default=False, | |
| 16:27:05 | dansmith | mriedem: yup | |
| 16:27:12 | mriedem | if it's actually backfilling, then maybe just not an issue for those b/c they are smaller tables | |
| 16:27:13 | dansmith | mriedem: we've been doing this without realizing | |
| 16:27:17 | dansmith | yu[ | |
| 16:27:22 | dansmith | will need a poison test too | |
| 16:27:29 | dansmith | like the others I have for alter operations | |
| 16:29:23 | mriedem | i sort of remember this discussion with jaypipes on https://review.opendev.org/#/c/557958/ | |
| 16:29:26 | mriedem | which uses server_default | |
| 16:30:09 | dansmith | I guess server_default would be one option, but it involves another schema change which I think is less good since we have to backport this | |
| 16:34:30 | mriedem | https://docs.sqlalchemy.org/en/13/core/metadata.html#sqlalchemy.schema.Column.params.default | |
| 16:34:41 | mriedem | "which will be invoked upon insert if this column is otherwise not specified in the VALUES clause of the insert" | |
| 16:34:45 | mriedem | didn't realize it would backfill though | |
| 16:35:03 | dansmith | right, I always assume it fills on read too, but just insert | |
| 16:35:07 | mriedem | https://docs.sqlalchemy.org/en/13/core/metadata.html#sqlalchemy.schema.Column.params.server_default - "A FetchedValue instance, str, Unicode or text() construct representing the DDL DEFAULT value for the column." | |
| 16:35:23 | mriedem | so yeah, i guess never use default in migrations | |
| 16:35:31 | dansmith | right | |
| 16:35:39 | mriedem | but is default in the models OK? | |
| 16:35:40 | mriedem | i thought it was | |
| 16:36:00 | dansmith | it is,m | |
| 16:36:10 | mriedem | mnaser: just purge your db :) | |
| 16:36:13 | dansmith | and I just tested that the model sync test does not fail you for having default on the column and not the migration | |
| 16:36:31 | mnaser | mriedem: you're not wrong | |
| 16:36:36 | mnaser | dansmith: https://bugs.launchpad.net/nova/+bug/1862205 | |
| 16:36:36 | openstack | Launchpad bug 1862205 in OpenStack Compute (nova) "Instances not visible when hidden=NULL" [Undecided,New] | |