| Posted | Nick | Remark | |
|---|---|---|---|
| #openstack-nova - 2020-02-06 | |||
| 16:07:57 | mnaser | yes | |
| 16:08:02 | dansmith | of active/ | |
| 16:08:05 | mnaser | yep | |
| 16:08:24 | mnaser | and those instances were all created post upgrade so its almost like the db just like.. only started reading specific records | |
| 16:08:37 | mnaser | now to note this is a s=>t upgrade, but those have been pretty smooth : | |
| 16:09:12 | dansmith | so I think you can rule out cells, cell_mappings, instance_mapping related issues | |
| 16:09:44 | mnaser | well to me the weird thing is how objects.InstanceList which is called inside heal placement allocation.. only sees those 11 instances | |
| 16:10:03 | mnaser | yet hypervisors are happily complaining like "66 vms on host but 65 in db" and things like that still happen | |
| 16:10:10 | dansmith | yep, another reason I think you can rule out the cell infrastructure | |
| 16:10:33 | mnaser | and if i hit a "Show" on a specific instance, i can retrieve it (just found out) | |
| 16:10:40 | mnaser | even if i dont see it listed | |
| 16:11:31 | mnaser | oh wth | |
| 16:11:31 | dansmith | show finds instances in a pretty different way, | |
| 16:11:32 | dansmith | but it also means that instance_mappings is correct | |
| 16:11:37 | mnaser | it looks like a db migration has failed | |
| 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 | |