| Posted | Nick | Remark | |
|---|---|---|---|
| #openstack-nova - 2017-03-20 | |||
| 13:47:53 | EmilienM | jaypipes: hey, good morning. We're currently investigating a TripleO CI issue where fail to deploy the overcloud (nodes managed by ironic) since March 16th, so we're looking at commits in Nova and we found https://review.openstack.org/#/c/441544/ that might be related. If you want to see bug report: https://bugs.launchpad.net/tripleo/+bug/1674236 - thanks for looking | |
| 13:47:53 | openstack | Launchpad bug 1674236 in tripleo "CI / promotion: Nova isn't aware of the nodes that were registered with Ironic" [Critical,Triaged] | |
| 13:50:18 | openstackgerrit | Claudiu Belu proposed openstack/nova master: POC: tests: autospecs all the mock.patch usages https://review.openstack.org/447505 | |
| 13:52:37 | jaypipes | EmilienM: looking... | |
| 13:52:58 | EmilienM | some logs: http://logs.openstack.org/periodic/periodic-tripleo-ci-centos-7-ovb-nonha/12d034e/logs/undercloud/var/log/nova/nova-conductor.txt.gz#_2017-03-19_07_21_12_709 | |
| 13:53:43 | EmilienM | and http://logs.openstack.org/periodic/periodic-tripleo-ci-centos-7-ovb-nonha/12d034e/logs/undercloud/var/log/nova/nova-scheduler.txt.gz#_2017-03-19_07_19_34_158 | |
| 13:53:44 | sdague | jaypipes: I'm confused by your reviews on https://review.openstack.org/#/c/427901/ - as it's got a -1 with a change requested, then a +2 | |
| 13:54:32 | mriedem | sdague: because they talked about it in irc and didn't update the comments in the review | |
| 13:54:49 | jaypipes | sdague: yes, what mriedem said. | |
| 13:55:14 | mriedem | EmilienM: the compute logs are probably what is most interesting since that's where the resource tracker logs are | |
| 13:55:17 | mriedem | which feeds the scheduler | |
| 13:55:47 | dansmith | compute is feeding placement correctly | |
| 13:55:59 | dansmith | scheduler just never finds any compute nodes, AFAICT | |
| 13:56:10 | jroll | O_o | |
| 13:58:18 | jroll | oh, we don't take the old path if get_inventory() is implemented: https://github.com/openstack/nova/blob/master/nova/compute/resource_tracker.py#L754 | |
| 13:58:28 | mriedem | correct | |
| 13:58:32 | jroll | I bet we aren't registering the "capabilities" | |
| 13:58:33 | mriedem | i see this over and over in the compute logs | |
| 13:58:33 | mriedem | 2017-03-19 07:01:23.652 16870 ERROR nova.compute.manager [req-cf2991f8-9fe2-45db-95e2-8cfc8cee2edd - - - - -] No compute node record for host tripleo-centos-7-tripleo-test-cloud-rh1-7948745 | |
| 13:58:59 | dansmith | ah | |
| 13:59:12 | jroll | it wouldn't explain starting with 0 nodes, though | |
| 13:59:29 | dansmith | jroll: if we never create a computenode record though... | |
| 13:59:37 | dansmith | shouldn't this have broken our ironic job too? | |
| 13:59:51 | jroll | dansmith: right, I thought we did that either way | |
| 13:59:56 | mriedem | i thought the compute node record was created before this | |
| 14:00:05 | dansmith | ah yeah, you're right | |
| 14:00:15 | dansmith | L745 | |
| 14:00:18 | jroll | yeah | |
| 14:00:23 | dansmith | we've already got a CN there | |
| 14:00:50 | mriedem | yeah create it here if it doesn't exist https://github.com/openstack/nova/blob/66c3f0860b6d96500539b5e94856f9594d363da7/nova/compute/resource_tracker.py#L593 | |
| 14:00:51 | jaypipes | mriedem: it looks like it's taking approx 30 minutes for the Ironic nodes to register with Nova.. | |
| 14:01:02 | mriedem | update it here using get_inventory https://github.com/openstack/nova/blob/66c3f0860b6d96500539b5e94856f9594d363da7/nova/compute/resource_tracker.py#L642 | |
| 14:02:15 | EmilienM | CN = compute node? | |
| 14:02:19 | mriedem | yes | |
| 14:02:48 | edleafe | Scheduler meeting now running in #openstack-meeting-alt | |
| 14:03:16 | EmilienM | iiuc, you have one job that test Ironic: gate-tempest-dsvm-ironic-ipa-wholedisk-bios-agent_ipmitool-tinyipa-ubuntu-xenial-nv - am I right? | |
| 14:03:33 | jroll | +1 to what jaypipes said, I don't see the resource tracker even try to run until 07:10, that's odd | |
| 14:03:47 | jroll | EmilienM: yes, and then the entire ironic gate. we'd know by now if it broke ironic :) | |
| 14:04:15 | EmilienM | right, and I've looked at commits in Ironic since March 16th and I haven't found anything suspicious | |
| 14:04:24 | mriedem | one of the compute node records is created here http://logs.openstack.org/periodic/periodic-tripleo-ci-centos-7-ovb-nonha/12d034e/logs/undercloud/var/log/nova/nova-compute.txt.gz#_2017-03-19_07_10_44_256 | |
| 14:04:41 | jroll | EmilienM: I must ask, this is repeatable, right? | |
| 14:04:53 | EmilienM | jroll: yes, we have it for 3 days | |
| 14:05:00 | EmilienM | but nobody looked at it this weekend | |
| 14:05:02 | jroll | cool, the timing thing seemed weird | |
| 14:05:04 | EmilienM | (I was offline) | |
| 14:05:17 | jroll | I guess you're trying to boot an instance after it's created anyway | |
| 14:05:21 | jaypipes | mriedem: yes, and looking at the placement log, I see 3 PUTs for creating inventory successfully. | |
| 14:05:37 | jroll | EmilienM: what does your flavor look like? | |
| 14:05:44 | EmilienM | I can try a revert and Depends-On tripleo patch | |
| 14:05:50 | EmilienM | so I can tell if this patch broke us or not | |
| 14:06:01 | EmilienM | jroll: let me show you that | |
| 14:06:04 | EmilienM | jroll: gimme 2 min | |
| 14:06:15 | jroll | that would be good data, yeah | |
| 14:06:17 | jroll | EmilienM: thanks | |
| 14:07:47 | openstackgerrit | Emilien Macchi proposed openstack/nova master: DNM - Revert "virt: implement get_inventory() for Ironic" https://review.openstack.org/447512 | |
| 14:07:51 | mriedem | Using cache for node eca19329-b67f-46b5-8509-586491a15f17, age: 7.65818786621 _node_from_cache /usr/lib/python2.7/site-packages/nova/virt/ironic/driver.py:700 | |
| 14:08:06 | mriedem | is there a timer on the node cache in the ironic driver? | |
| 14:08:14 | jroll | it refreshes every resource tracker run | |
| 14:09:29 | mriedem | jroll: are you sure about that? | |
| 14:09:37 | mriedem | i don't see _node_from_cache refreshing | |
| 14:09:50 | mriedem | and get_available_resource only does if it doesn't exist | |
| 14:10:00 | jroll | mriedem: get_available_nodes | |
| 14:10:21 | jroll | ya https://github.com/openstack/nova/blob/master/nova/virt/ironic/driver.py#L604 | |
| 14:11:39 | EmilienM | jroll: I think the default flavor is 4096, 1, 40 | |
| 14:11:53 | mriedem | and get_available_nodes is called for every update_available_resource in the compute manager, which is on startup and every 60s | |
| 14:11:56 | jaypipes | mriedem: get_available_resource() is always called before get_inventory(), and get_available_resource() always refreshes the node cache: https://github.com/openstack/nova/blob/master/nova/virt/ironic/driver.py#L688 | |
| 14:12:07 | EmilienM | jroll: details here: http://logs.openstack.org/periodic/periodic-tripleo-ci-centos-7-ovb-nonha/12d034e/logs/undercloud/var/log/nova/nova-api.txt.gz#_2017-03-19_06_38_20_764 | |
| 14:12:21 | mriedem | jaypipes: get_available_resource does not always refresh the cache | |
| 14:12:21 | openstackgerrit | Rafael Folco proposed openstack/nova master: DELETE all inventory for a resource provider https://review.openstack.org/416669 | |
| 14:12:26 | mriedem | see the conditional block it's in | |
| 14:12:30 | mriedem | if not self.node_cache: | |
| 14:12:34 | mriedem | self._refresh_cache() | |
| 14:12:54 | jroll | EmilienM: okay, and we have Final resource view: name=eca19329-b67f-46b5-8509-586491a15f17 phys_ram=8192MB used_ram=0MB phys_disk=40GB used_disk=0GB total_vcpus=4 used_vcpus=0 pci_stats=[] | |
| 14:12:55 | jaypipes | mriedem: well, I mean it will always trigger a full pull of the node list if the node cache is empty. | |
| 14:13:00 | mriedem | anyway, looks like jroll is right and we refresh in get_available_nodes, which is called in each periodic in the manager | |
| 14:13:51 | dansmith | jroll: no, but what has changed? | |
| 14:14:16 | jaypipes | jroll: placement will return nodes that have enough RAM/VCPU/DISK | |
| 14:14:19 | jroll | dansmith: we now have ironic inventory in the placement engine | |
| 14:14:31 | jroll | right, that's what I thought, so this flavor should fit | |
| 14:14:32 | jaypipes | jroll: scheduler isn't yet requesting custom resource class | |
| 14:14:35 | dansmith | jroll: sure but we're not asking for it | |
| 14:15:14 | jroll | the scheduler isn't asking placement for resource providers that match the flavor's cpu/ram/disk? | |
| 14:15:22 | jroll | oh wait, that was already there | |
| 14:15:23 | jroll | blah | |
| 14:15:28 | dansmith | right | |
| 14:15:46 | mriedem | Hypervisor: VCPU information unavailable _report_hypervisor_resource_view /usr/lib/python2.7/site-packages/nova/compute/resource_tracker.py:676 | |
| 14:15:53 | mriedem | indicates the node is not available, right ^ ? | |
| 14:16:40 | jroll | mriedem: yeah, but later it figures things out: http://logs.openstack.org/periodic/periodic-tripleo-ci-centos-7-ovb-nonha/12d034e/logs/undercloud/var/log/nova/nova-compute.txt.gz#_2017-03-19_07_14_43_029 | |
| 14:16:51 | EmilienM | (in the meantime, we're testing the revert here: https://review.openstack.org/#/c/447514) | |
| 14:17:03 | jroll | log level filters here would be super useful, btw :P | |
| 14:17:34 | dansmith | jroll: yeah :( | |
| 14:17:41 | EmilienM | jroll: it's in our (long) todo | |
| 14:17:48 | dansmith | jaypipes: a scheduling decision looks like /resource_providers?stuff=stuff right? | |
| 14:17:49 | EmilienM | but yeah, I agree | |
| 14:17:51 | dansmith | jaypipes: in placement | |
| 14:17:58 | jaypipes | dansmith: yep. | |
| 14:18:05 | dansmith | jaypipes: I don't see a single one of those in placement's log | |
| 14:18:15 | jroll | I do | |
| 14:18:22 | jroll | GET /placement/resource_providers?resources=DISK_GB%3A40%2CMEMORY_MB%3A4096%2CVCPU%3A1 | |
| 14:18:23 | dansmith | I think we should be asking placement, then using that list of uuids to filter the compute_nodes list right? | |