| Posted | Nick | Remark | |
|---|---|---|---|
| #openstack-nova - 2017-07-25 | |||
| 19:34:00 | mriedem | it's just a latent thing we aren't handling well in our infra | |
| 19:34:00 | dansmith | mriedem: do these graphs do anything for you? http://docs-draft.openstack.org/83/487183/1/check/gate-nova-docs-ubuntu-xenial/ef53873//doc/build/html/user/cellsv2_layout.html | |
| 19:34:01 | dansmith | mostly the second one | |
| 19:34:11 | dansmith | okay | |
| 19:34:44 | openstackgerrit | Ildiko Vancsa proposed openstack/nova master: Translate the return value of attachment_create and _update https://review.openstack.org/486194 | |
| 19:35:10 | mriedem | dansmith: looks pretty good | |
| 19:35:38 | mriedem | the first graph is kind of a webby mess | |
| 19:35:40 | dansmith | wish I could fix a few visual aberrations on it, but it took a lot of screwing around to make it look this good | |
| 19:36:11 | dansmith | I spent less time on the first one I can muck some more | |
| 19:40:06 | sdague | mriedem: ok, so have you confirmed if the 3 node is voting yet? | |
| 19:40:10 | openstackgerrit | Moshe Levi proposed openstack/nova master: hardware offload support for openvswitch https://review.openstack.org/398265 | |
| 19:40:42 | sdague | mriedem: I thought we were doing discover hosts at the end of the d-g run? | |
| 19:41:55 | mriedem | sdague: we are, | |
| 19:42:07 | mriedem | but the compute node getting created is asynchronous to that | |
| 19:42:18 | mriedem | the 3-node job could be slowing down the controller services just enough to hit the latent window | |
| 19:42:36 | sdague | because the startup of nova-compute takes that long? | |
| 19:43:14 | sdague | so the race is that nova-compute service start doesn't make it to the db before discover hosts runs? | |
| 19:44:59 | mriedem | yes | |
| 19:45:19 | mriedem | +1 on https://review.openstack.org/#/c/477556/ and my debug notes are all in there | |
| 19:46:36 | sdague | so... related, what's the deal with the stack trace here - http://logs.openstack.org/56/477556/5/experimental/gate-tempest-dsvm-neutron-dvr-ha-multinode-full-ubuntu-xenial-nv/432c235/logs/subnode-3/screen-n-cpu.txt.gz#_Jul_25_15_06_55_309283 | |
| 19:47:23 | mriedem | that's the thing where the libvirt starts up and tries to enable itself | |
| 19:47:54 | sdague | ok, so we're going to stacktrace on every clean start | |
| 19:48:06 | mriedem | https://github.com/openstack/nova/blob/master/nova/virt/libvirt/driver.py#L3563 | |
| 19:48:09 | mriedem | sdague: that's been around | |
| 19:48:11 | mriedem | it's not a result of this change | |
| 19:48:19 | sdague | mriedem: sure | |
| 19:48:23 | sdague | it's just not good | |
| 19:48:37 | mriedem | yeah, i don't like it either | |
| 19:48:42 | sdague | ok, http://logs.openstack.org/56/477556/5/experimental/gate-tempest-dsvm-neutron-dvr-ha-multinode-full-ubuntu-xenial-nv/432c235/logs/subnode-3/screen-n-cpu.txt.gz#_Jul_25_15_07_02_323379 is where the compute node is built, that's about 7 seconds later | |
| 19:48:54 | mriedem | yes | |
| 19:49:51 | mriedem | i'm not sure why these stacktrace | |
| 19:50:21 | mriedem | i guess because of https://github.com/openstack/nova/blob/master/nova/virt/libvirt/driver.py#L3567 ? | |
| 19:50:33 | mriedem | so it hits the generic Exception block as ComputeHostNotFound_Remote? | |
| 19:50:39 | openstackgerrit | Dan Smith proposed openstack/nova master: [WIP] Add some more cellsv2 doc goodness https://review.openstack.org/487183 | |
| 19:52:56 | sdague | mriedem: yeh | |
| 19:59:42 | sdague | mriedem: do we have a way of telling that nova-compute is ready. Is that resource tracker at 07_02 the event we need? | |
| 20:00:26 | openstackgerrit | Merged openstack/nova master: API ref: associate floating IP requires Active status https://review.openstack.org/363642 | |
| 20:00:48 | sdague | I'm trying to think about who should wait for what to get us there. Is there something we could tell from the subnode easily about it being ready so we knew we were in the clear when stack.sh finished? | |
| 20:01:18 | mriedem | sdague: our docs tell you to run 'nova service-list --binary nova-compute' and make sure the compute shows up before you run discover_hosts | |
| 20:02:37 | mriedem | because that API iterates all cells and gathers up the services running in them | |
| 20:02:42 | mriedem | so the host mapping isn't required for that | |
| 20:03:24 | sdague | so we could put a flag in to wait for compute | |
| 20:03:29 | sdague | and run: nova service-list --host `hostname` --binary nova-compute | |
| 20:03:43 | sdague | on the child until it is true? | |
| 20:08:00 | dansmith | not on the child, on the main node | |
| 20:08:41 | mriedem | right we run discover_hosts from the primary | |
| 20:08:48 | mriedem | b/c it needs to get to the api db to find the cell mappings | |
| 20:08:58 | mriedem | and the compute nodes don't have access to that | |
| 20:09:00 | dansmith | well and you need the main node to do the waiting | |
| 20:09:16 | dansmith | because it's going to run tests that need to wait until all the nodes are up | |
| 20:10:52 | mriedem | this is what i see for the 'host is not mapped to any cell' failures in voting jobs | |
| 20:10:57 | mriedem | http://logstash.openstack.org/#dashboard/file/logstash.json?query=message%3A%5C%22Host%5C%22%20AND%20message%3A%5C%22is%20not%20mapped%20to%20any%20cell%5C%22%20AND%20tags%3A%5C%22console%5C%22%20AND%20voting%3A1%20AND%20build_status%3A%5C%22FAILURE%5C%22&from=7d | |
| 20:11:24 | mriedem | they are all grenade multinode jobs | |
| 20:12:34 | openstackgerrit | Dan Smith proposed openstack/nova master: Add some more cellsv2 doc goodness https://review.openstack.org/487183 | |
| 20:26:01 | sdague | dansmith: if the child doesn't return until n-cpu has checked in, that also works, right? | |
| 20:26:16 | sdague | basically make stack.sh synchronous on nova-compute being up | |
| 20:27:31 | dansmith | sdague: by child you mean the subnode right? | |
| 20:32:27 | mriedem | right so there are two places you could do that in the ComputeManager, | |
| 20:32:29 | mriedem | 1. init_host() | |
| 20:32:33 | mriedem | 2. pre_start_hook() | |
| 20:32:38 | mriedem | the latter already tries to get the compute node | |
| 20:32:46 | mriedem | *post_start_hook() i mean | |
| 20:33:07 | mriedem | damn, sorry, no i meant pre_start_hook | |
| 20:33:51 | mriedem | i did think that pre_start_hook should do it | |
| 20:34:00 | mriedem | because it calls update_available_resource_for_node | |
| 20:34:11 | mriedem | which calls rt.update_available_resource | |
| 20:34:32 | mriedem | which should then do the init compute node stuff | |
| 20:34:32 | sdague | dansmith: yeh | |
| 20:34:44 | mriedem | so i'm not entirely sure why that doesn't happen in the pre_start_hook phase | |
| 20:35:57 | sdague | mriedem: are you sure it didn't? | |
| 20:37:51 | mriedem | i'm not sure no | |
| 20:37:52 | mriedem | i can dig | |
| 20:38:06 | mriedem | my shovel is going to be pretty gd blunt after the end of this day | |
| 20:38:15 | sdague | mriedem: I was assuming that virt driver init host just took that long to start | |
| 20:38:28 | mriedem | the virt driver init_host doesn't do much | |
| 20:38:44 | mriedem | at least for the libvirt driver, it registers event listeners and connects to libvirt | |
| 20:39:11 | mriedem | ok so this is a subnode starting up | |
| 20:39:12 | mriedem | http://logs.openstack.org/79/487179/1/check/gate-tempest-dsvm-neutron-multinode-full-ubuntu-xenial-nv/1dd9db5/logs/subnode-2/screen-n-cpu.txt.gz#_Jul_25_19_30_42_125360 | |
| 20:39:16 | mriedem | Jul 25 19:30:42.125360 ubuntu-xenial-2-node-osic-cloud1-disk-10073644-745537 nova-compute[711]: INFO nova.service [-] Starting compute node (version 16.0.0) | |
| 20:39:30 | mriedem | that's in nova.service.Service.start() | |
| 20:40:15 | mriedem | then you see the libvirt event stuff | |
| 20:41:03 | mriedem | then you see this from the libvirt driver http://logs.openstack.org/79/487179/1/check/gate-tempest-dsvm-neutron-multinode-full-ubuntu-xenial-nv/1dd9db5/logs/subnode-2/screen-n-cpu.txt.gz#_Jul_25_19_30_42_150823 | |
| 20:41:10 | mriedem | because the compute node doesn't exist yet | |
| 20:41:41 | mriedem | then you see this in the compute manager http://logs.openstack.org/79/487179/1/check/gate-tempest-dsvm-neutron-multinode-full-ubuntu-xenial-nv/1dd9db5/logs/subnode-2/screen-n-cpu.txt.gz#_Jul_25_19_30_44_394800 | |
| 20:41:49 | mriedem | which is from _get_compute_nodes_in_db | |
| 20:43:18 | mriedem | i'm not sure why that traces | |
| 20:43:58 | mriedem | that warning is here https://github.com/openstack/nova/blob/master/nova/compute/manager.py#L6627 | |
| 20:47:28 | mriedem | anyway then we call the resource tracker https://github.com/openstack/nova/blob/master/nova/compute/manager.py#L6602 | |
| 20:47:44 | mriedem | http://logs.openstack.org/79/487179/1/check/gate-tempest-dsvm-neutron-multinode-full-ubuntu-xenial-nv/1dd9db5/logs/subnode-2/screen-n-cpu.txt.gz#_Jul_25_19_30_44_399281 | |
| 20:47:52 | mriedem | Jul 25 19:30:44.399281 ubuntu-xenial-2-node-osic-cloud1-disk-10073644-745537 nova-compute[711]: DEBUG nova.compute.resource_tracker [None req-9286123e-31d0-45c4-a951-fe1e3947db00 None None] Auditing locally available compute resources for ubuntu-xenial-2-node-osic-cloud1-disk-10073644-745537 (node: ubuntu-xenial-2-node-osic-cloud1-disk-10073644-745537) {{(pid=711) update_available_resource /opt/stack/new/nova/nova/compute/res | |
| 20:47:52 | mriedem | e_tracker.py:609}} | |
| 20:49:41 | mriedem | then we should get in here https://github.com/openstack/nova/blob/master/nova/compute/resource_tracker.py#L488 | |
| 20:50:43 | mriedem | and we'll hit this https://github.com/openstack/nova/blob/master/nova/compute/resource_tracker.py#L709 | |
| 20:50:57 | mriedem | http://logs.openstack.org/79/487179/1/check/gate-tempest-dsvm-neutron-multinode-full-ubuntu-xenial-nv/1dd9db5/logs/subnode-2/screen-n-cpu.txt.gz#_Jul_25_19_30_44_441734 | |
| 20:51:39 | mriedem | and so we'll create the compute node record here https://github.com/openstack/nova/blob/master/nova/compute/resource_tracker.py#L531 | |
| 20:51:58 | mriedem | http://logs.openstack.org/79/487179/1/check/gate-tempest-dsvm-neutron-multinode-full-ubuntu-xenial-nv/1dd9db5/logs/subnode-2/screen-n-cpu.txt.gz#_Jul_25_19_30_44_459686 | |
| 20:52:27 | mriedem | sdague: but does systemd wait or does it just launch off the service start and not block on it? | |
| 20:52:50 | sdague | mriedem: define wait | |
| 20:55:20 | sdague | mriedem: we're starting in the foreground, it's tracking the parent process, but the issue is it's much later that things are ready | |
| 20:56:21 | sdague | anyway, I need to work on dinner, I've got this half assed patch running locally, if it works I'll push it | |