| Posted | Nick | Remark | |
|---|---|---|---|
| #openstack-nova - 2017-06-28 | |||
| 12:00:20 | ebbex | jaypipes: but then how come the select on the instances table _after_ nova-api has returned 202 on to the create instance call returns no match? | |
| 12:01:22 | jaypipes | ebbex: nova-api returns a 202 when it creates the *build request*. The build request is in the API database (top-level DB). The instances table is in the cell DB and is written to after scheduling has selected a target host (and therefore a target cell). | |
| 12:01:36 | jaypipes | ebbex: nova-api calls nova-conductor after passing a 202 back to the user. | |
| 12:01:42 | ebbex | jaypipes: there must be a race condition here, and even tho we are using galera, we (currently) send all of nova*'s sql connections to a single galera instance (trying to eliminate "slave-lag" problems) | |
| 12:02:23 | jaypipes | ebbex: nova-conductor then calls nova-scheduler, which selects the host and returns that selection back to the conductor, which then writes the instances record to the cell DB and sends the launch instance RPC call to the target compute host. | |
| 12:02:50 | jaypipes | ebbex: it's not a race condition. it's working as intended :) | |
| 12:03:15 | jaypipes | ebbex: the instances table of the cell DB will not have a record for the instance with that UUID until the scheduler selects a host. | |
| 12:03:31 | jaypipes | ebbex: the UUID you get back is the one from the build_requests table in the top-level API database. | |
| 12:04:26 | ebbex | jaypipes: but nova-api then serves a location with the 202 response that returns 404... hmm, that cant be intentional? | |
| 12:04:30 | jaypipes | ebbex: when the compute host is selected by the scheduler, the instances table in the cell database is written and the build_requests table entry is deleted (here: https://github.com/openstack/nova/blob/master/nova/conductor/manager.py#L986) | |
| 12:04:55 | artom | ebbex, what database are you looking in? | |
| 12:04:57 | jaypipes | ebbex: no. the location returned by nova-api *does* exist. | |
| 12:05:07 | ebbex | jaypipes: nope | |
| 12:05:39 | jaypipes | ebbex: execute list instances with an admin user. | |
| 12:05:56 | ebbex | jaypipes: so, after a post to /v2.1/servers, nova-api replies with 202 and location: http://nova-api/v2.1/servers/899d5996-a030-44ac-ad34-28d261255d2d | |
| 12:06:08 | jaypipes | ebbex: something is causing the build to go into an error state somewhere I suspect. | |
| 12:06:20 | jaypipes | ebbex: yes, that URI is valid. | |
| 12:06:36 | ebbex | jaypipes: that url is not valid until the instance is inserted into the instances table | |
| 12:06:43 | jaypipes | ebbex: no, that's not true. | |
| 12:06:46 | ebbex | and there you have your race condition | |
| 12:06:48 | jaypipes | ebbex: let me explain. | |
| 12:07:32 | ebbex | jaypipes: ok... atleast that is what we see here, a select ... where ...uuid= ... from instances .. returning no entries and nova-api returning us 404 | |
| 12:08:01 | jaypipes | ebbex: the information returned from the GET /servers/<UUID> will be information about the build request (flavor, image, the instance UUID, etc) *until the instances record in the cell DB has been written, in which case the build_requests table entry will be deleted* | |
| 12:08:35 | jaypipes | ebbex: where is your cell DB vs. your API db? | |
| 12:08:36 | ebbex | jaypipes: so what then causes the 404 from the GET servers/UUID? | |
| 12:08:51 | Dinesh_Bhor | artom: ok, ill try, thanks for the help | |
| 12:10:05 | jaypipes | ebbex: have you looked in your nova-conductor log for errors? | |
| 12:10:06 | ebbex | cell0 is nova_cell0, cell1 is nova, nova-api has nova_api and placement-api uses nova_api database. all on the same server. | |
| 12:10:22 | jaypipes | ebbex: I'm wondering perhaps if you're hitting this: https://github.com/openstack/nova/blob/master/nova/conductor/manager.py#L936 | |
| 12:11:00 | jaypipes | ebbex: have you checked all the logs for errors? anything in there? | |
| 12:11:50 | ebbex | We dont get any errors and the instance is started just fine | |
| 12:12:26 | ebbex | and if we do a server show after the server create has returned the 404 error, it is there | |
| 12:12:53 | jaypipes | ebbex: may I ask how you are creating the server? | |
| 12:12:57 | ebbex | so the problem only exists for small amount of time, but still causes throuble in openstackclient and what-not | |
| 12:13:22 | ebbex | server create --wait --image cirros.raw --flavor m1.small --nic net-id=network1 server1 | |
| 12:14:03 | jaypipes | ebbex: k, thank you. sounds like a bug indeed. would you mind creating a bug for this? | |
| 12:15:04 | sfinucan | sdague: comments left on the controversial ones | |
| 12:18:25 | ebbex | jaypipes: I do not see nova-api doing any other sql queries than the one against instances that returns empty | |
| 12:18:59 | jaypipes | ebbex: would you mind putting all of this into a bug report? | |
| 12:19:24 | ebbex | jaypipes: so if that you said earlier is correct, that is should also look in build_requests or whatever, it is not happening | |
| 12:19:38 | jaypipes | efried: lol. Deputy Dan :) | |
| 12:19:46 | efried | :) | |
| 12:21:38 | sdague | sfinucan: where is the blueprint for this, the blueprint link is broken | |
| 12:21:41 | jaypipes | ebbex: nova-api definitely is looking in build_requests. https://github.com/openstack/nova/blob/master/nova/compute/api.py#L2564 | |
| 12:22:06 | ebbex | jaypipes: how come I do not see the sql query in the tcpdump? | |
| 12:22:57 | openstackgerrit | Alex Xu proposed openstack/nova master: DNM: debug traits sync https://review.openstack.org/478495 | |
| 12:23:01 | alex_xu | jaypipes: reproduce same fail in the local, after adding some logs...the test successful now...even remove those logs | |
| 12:23:22 | alex_xu | jaypipes: ^ adding a log, then let see if they still reproducable in the gate | |
| 12:23:36 | jaypipes | alex_xu: k, ty sir | |
| 12:23:41 | jaypipes | ebbex: not sure :( | |
| 12:23:42 | alex_xu | np | |
| 12:24:00 | jaypipes | ebbex: what version of Nova are you on? | |
| 12:24:24 | ebbex | jaypipes: we are talking about "server show" here right, not "server list"? | |
| 12:24:28 | ebbex | ocata branch | |
| 12:25:01 | ebbex | jaypipes: because the line you refer to seems to be related to "server list" | |
| 12:26:22 | artom | ebbex, you said this is load balanced, right? What's the db setup like? | |
| 12:26:23 | jaypipes | ebbex: https://github.com/openstack/nova/blob/master/nova/compute/api.py#L2435 | |
| 12:26:31 | jaypipes | ebbex: same thing for show. | |
| 12:26:55 | ebbex | artom: it is not load-balanced any more, disabled to eliminate errors caused by this. | |
| 12:26:59 | jaypipes | ebbex: ooooh | |
| 12:27:20 | artom | ebbex, so everything on a single machine? | |
| 12:27:21 | jaypipes | ebbex: try setting the service version of nova-osapi_compute to 16. | |
| 12:27:58 | ebbex | ok.. lets try that | |
| 12:28:17 | jaypipes | ebbex: go into the API database's services table and update the version column to 16 for all services where the binary column is "nova-osapi_compute" | |
| 12:29:09 | jaypipes | ebbex: sorry, meant the cell1 db | |
| 12:29:12 | jaypipes | not the api db | |
| 12:32:09 | ebbex | hmm.. | |
| 12:33:08 | ebbex | there is no binary that has this name | |
| 12:33:30 | ebbex | also, nice to use a function name as a column name :) | |
| 12:34:05 | jaypipes | ebbex: yeah... :( | |
| 12:34:35 | jaypipes | ebbex: so I'm pretty sure this is the source of the bug: https://github.com/openstack/nova/blob/master/nova/compute/api.py#L2422 | |
| 12:34:53 | jaypipes | ebbex: or rather, that is the source of your woes... :) | |
| 12:35:14 | jaypipes | ebbex: either the service version being returned by the call here: https://github.com/openstack/nova/blob/master/nova/compute/api.py#L2417 | |
| 12:35:24 | jaypipes | is not >= 15 | |
| 12:35:34 | jaypipes | or you have cellsv1 set up, which I doubt :) | |
| 12:35:42 | ebbex | no cellsv1 | |
| 12:36:09 | ebbex | so where do I set the service_version if its not in the services table, and what can cause it to be there | |
| 12:36:21 | jaypipes | ebbex: can you try removing lines 2422-2424 from the code and retrying the scenario? | |
| 12:37:10 | jaypipes | ebbex: I'm thinking that "nova-osapi_compute" is wrong for existing installations maybe. Perhaps that should be "nova-api"? | |
| 12:37:23 | jaypipes | ebbex: what does this give you if you run it on the cell DB: | |
| 12:37:31 | ebbex | jaypipes: could I have bootstrapped something wrong with cellsv2? should there be an entry for nova-os-compute-api? | |
| 12:37:38 | jaypipes | SELECT binary, count(*) as c from services group by binary; | |
| 12:37:52 | jaypipes | ebbex: not sure, trying to find out :) | |
| 12:38:27 | ebbex | remember `binary` ;) | |
| 12:38:34 | jaypipes | heh, yes | |
| 12:38:46 | jaypipes | was just about to say that :) | |
| 12:38:53 | ebbex | | nova-compute | 2 | | |
| 12:38:53 | ebbex | | nova-conductor | 3 | | |
| 12:38:54 | ebbex | | nova-console | 3 | | |
| 12:38:54 | ebbex | | nova-consoleauth | 3 | | |
| 12:38:54 | ebbex | | nova-scheduler | 3 | | |
| 12:39:31 | jaypipes | is there a services table in the nova_api db? | |
| 12:39:39 | ebbex | nope. | |
| 12:39:49 | jaypipes | hmm.. | |
| 12:39:57 | jaypipes | I wonder why there's no entry for the api services... | |
| 12:41:52 | jaypipes | ebbex: I need to run out for a bit. I'm hoping dansmith will have some ideas when he gets online about this. | |
| 12:42:39 | ebbex | jaypipes: cool, thanks :) | |
| 12:45:07 | openstackgerrit | Alex Xu proposed openstack/nova master: Use plain routes list for images instead of stevedore https://review.openstack.org/478498 | |
| 12:45:08 | openstackgerrit | Alex Xu proposed openstack/nova master: Use plain routes list for image-metadata instead of stevedore https://review.openstack.org/478499 | |
| 12:45:49 | alex_xu | nova api meeting is in 15 mins at #openstack-meeting-4 | |