| Posted | Nick | Remark | |
|---|---|---|---|
| #openstack-nova - 2020-02-06 | |||
| 15:58:43 | dansmith | sean-k-mooney: devstack or devstack-gate? | |
| 15:59:23 | sean-k-mooney | bauzas: are you confusing me with an english man becasue as a irish eu citizen i coudl be offended by that. also irish <anything> usally meens add good wiskey | |
| 15:59:47 | sean-k-mooney | *irish <beverage or food item> | |
| 16:00:00 | sean-k-mooney | dansmith: devstack | |
| 16:00:15 | dansmith | sean-k-mooney: the other projects have git_clone calls in their modules | |
| 16:00:55 | sean-k-mooney | so in the gate they are disabled via a diffenert parmater | |
| 16:01:24 | mnaser | ok, i'm absolutely hitting a wall. nova list --all-tenants returns only 11 vms, but i have 1297 vm_state='ACTIVE' instances. instance_mappings are correct in nova_api | |
| 16:01:30 | sean-k-mooney | but the plugin interface specific was designed for devstack to do the clone of the pugin repo | |
| 16:01:34 | mnaser | i double checked the db creds inside nova_api.cell_mappings | |
| 16:01:49 | sean-k-mooney | anyway its not a big deal | |
| 16:02:08 | mnaser | the crazier thing is running something like placement heal allocations only returns 11 instances only, which that is doing objects.InstaceList.... | |
| 16:02:51 | mnaser | so its note even an API level problem, it's in the db layer (i assume objects.* API inside nova-manage commands talks directly to db, not via conductor?) | |
| 16:03:53 | dansmith | mnaser: nova-manage does not talk to conductor | |
| 16:04:08 | mnaser | ok, so that's what i thought as well | |
| 16:04:30 | sean-k-mooney | nova manage will try and get the db infor form your nova.conf | |
| 16:04:45 | sean-k-mooney | is it perhaps geting the wrong db info | |
| 16:04:46 | openstackgerrit | Stephen Finucane proposed openstack/nova master: Configure max-line-length to 88 https://review.opendev.org/706311 | |
| 16:05:26 | mnaser | i used the mysql client to use the same credentials in nova.conf and i see all the instances | |
| 16:05:48 | dansmith | mnaser: one non-cell0 cell? | |
| 16:05:53 | stephenfin | bauzas: thanks :) | |
| 16:05:58 | mnaser | yes, only one non-cell0 cell | |
| 16:06:11 | dansmith | mnaser: and the 11 instances you do see, are they from that cell or in cell0? | |
| 16:06:20 | bauzas | sean-k-mooney: I've been told that by an irish man in Grenoblre | |
| 16:06:29 | mnaser | i ddint check all of them but one of them is from that cell dansmith (aka inside `nova`) | |
| 16:07:00 | dansmith | mnaser: is it complete? meaning, it's not returned as a shell instance with no real state information? | |
| 16:07:09 | mnaser | oh good call | |
| 16:07:27 | mnaser | nova show brings even the user_data | |
| 16:07:36 | mnaser | so it sounds like its pulling it in from nova and not nova_api | |
| 16:07:42 | dansmith | that's not the same | |
| 16:07:53 | dansmith | when you see it in nova list, does it have vm_state? | |
| 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 | |