| Posted | Nick | Remark | |
|---|---|---|---|
| #openstack-nova - 2017-07-25 | |||
| 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 | sdague | dansmith: yeh | |
| 20:34:32 | mriedem | which should then do the init compute node stuff | |
| 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 | e_tracker.py:609}} | |
| 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: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 | |
| 20:56:24 | mriedem | right when we start the n-cpu service, and the service is launched, that's all async | |
| 20:56:31 | sdague | mriedem: it's not async | |
| 20:56:38 | jangutter | mriedem, jaypipes: should I assert on exception.NovaException or exception.InternalError at https://review.openstack.org/#/c/486426/6/nova/tests/unit/virt/libvirt/test_vif.py@1616 | |
| 20:56:49 | sdague | it's that it's not ready for 25 - 30 seconds after start | |
| 20:57:00 | sdague | and, there is no /health to know that | |
| 20:57:19 | sdague | we poll api processes that we start to know they are ready before we move on | |
| 20:57:26 | sdague | but there isn't a direct interface for that | |
| 20:57:34 | mriedem | right i meant https://github.com/openstack/nova/blob/master/nova/service.py#L138 | |
| 20:57:47 | mriedem | which is what calls compute manager pre_start_hook that sets this all up | |
| 20:58:09 | sdague | mriedem: ok, before I leave, I want to make sure we get this question clear :) | |
| 20:58:30 | sdague | systemd is starting things, and it's running as parent process as soon as python exec happens | |
| 20:59:00 | mriedem | i guess i was thinking about like sysv init scripts and services, | |
| 20:59:05 | mriedem | where you can run service nova-compute status | |
| 20:59:08 | mriedem | and see if it's started or not | |
| 20:59:19 | sdague | sure, but all that tells you is if the process is running | |
| 20:59:25 | sdague | the process is running | |
| 20:59:38 | sdague | eventually the process is ready | |
| 20:59:42 | mriedem | but can't the start routine block until it's actually started or crashed? | |
| 20:59:51 | sdague | it is started | |
| 20:59:58 | sdague | the process is running | |
| 21:00:27 | sdague | how does anything external know if a process is ready other than pid existing? | |
| 21:00:31 | mriedem | ok, well this is all latent stuff and shouldn't block https://review.openstack.org/#/c/477556/ | |
| 21:00:35 | mriedem | so can we get that in? | |
| 21:00:54 | mriedem | like, this behavior goes back to ocata | |
| 21:01:04 | sdague | https://www.freedesktop.org/software/systemd/man/systemd-notify.html if you want deeper state interaction between process and systemd | |
| 21:01:34 | sdague | mriedem: the neutron folks are currently borked? | |
| 21:01:39 | mriedem | no | |
| 21:01:49 | mriedem | the dvr-ha multinode job is non-voting and in the experimental queue | |
| 21:01:54 | sdague | ok | |
| 21:01:55 | mriedem | i've already talked to haleyb about it | |
| 21:02:07 | sdague | if they are cool with it, that's fine | |
| 21:02:44 | sdague | I'll try to get this wait call in place | |
| 21:02:52 | sdague | I just appoved the fleet patch | |
| 21:03:01 | mriedem | ok | |
| 21:03:13 | sdague | this other thing takes a while to run, so off for the night, we'll see what it looks like in the morning | |
| 21:06:21 | openstackgerrit | Matt Riedemann proposed openstack/nova master: Remove redundant free_vcpus logging in _report_hypervisor_resource_view https://review.openstack.org/487216 | |
| 21:11:28 | jangutter | mriedem, jaypipes: should I assert on exception.NovaException or exception.InternalError at https://review.openstack.org/#/c/486426/6/nova/tests/unit/virt/libvirt/test_vif.py@1616 | |
| 21:14:01 | mriedem | internal error | |
| 21:14:17 | mriedem | you should assert the thing being raised | |