| Posted | Nick | Remark | |
|---|---|---|---|
| #openstack-nova - 2017-06-06 | |||
| 18:47:52 | mriedem | they do | |
| 18:48:04 | mriedem | and hotdish! | |
| 18:49:14 | mriedem | sdague: so it's req-5b3770c1-d332-4875-8933-97de8a9890b4 right? | |
| 18:50:46 | sdague | I actually think it's req-f0668b70-fac7-4dae-b3b3-afba6c36ec77 | |
| 18:51:09 | sdague | one sec, I just closed all my tabs | |
| 18:51:42 | sdague | yeh req-f0668b70-fac7-4dae-b3b3-afba6c36ec77 is the rebuild | |
| 18:51:49 | sdague | http://logs.openstack.org/82/471082/1/check/gate-novaclient-dsvm-functional-neutron-ubuntu-xenial/68a19f4/logs/screen-n-api.txt.gz#_Jun_06_17_35_38_992164 | |
| 18:52:01 | mriedem | sdague: http://logs.openstack.org/82/471082/1/gate/gate-novaclient-dsvm-functional-neutron-ubuntu-xenial/796acb7/logs/screen-n-cpu.txt.gz#_Jun_06_13_14_02_210879 | |
| 18:52:09 | mriedem | i'm looking at the gate queue job | |
| 18:52:11 | mriedem | you're looking at check | |
| 18:52:12 | mriedem | :) | |
| 18:53:01 | openstackgerrit | Merged openstack/nova master: Send request_id on glance calls https://review.openstack.org/467242 | |
| 18:53:10 | sdague | mriedem: ah, sure :) | |
| 18:55:04 | openstackgerrit | Merged openstack/nova master: Sync os-traits to Traits database table https://review.openstack.org/469578 | |
| 18:55:28 | mriedem | Jun 06 13:14:02.594292 ubuntu-xenial-infracloud-chocolate-9158824 nova-compute[20994]: DEBUG nova.virt.libvirt.driver [None req-5b3770c1-d332-4875-8933-97de8a9890b4 admin admin] [instance: 573258a4-9416-4e13-a765-7c90683f3526] Shutting down instance from state 1: NotImplementedError {{(pid=20994) _clean_shutdown /opt/stack/new/nova/nova/virt/libvirt/driver.py:2524}} | |
| 18:55:28 | mriedem | this is a weird message | |
| 18:55:40 | openstackgerrit | Merged openstack/nova master: Use VIR_DOMAIN_BLOCK_REBASE_COPY_DEV when rebasing https://review.openstack.org/465205 | |
| 18:57:39 | artom | mriedem, looks like something doesn't implement get_power_states | |
| 18:58:13 | mriedem | or it's something in a repr | |
| 18:58:47 | artom | That... would make more sense | |
| 18:58:48 | mriedem | it should be a InstancePowerState object | |
| 19:00:48 | mriedem | weird, ": NotImplementedError" shows up a lot in the logs | |
| 19:00:55 | mriedem | http://logs.openstack.org/82/471082/1/gate/gate-novaclient-dsvm-functional-neutron-ubuntu-xenial/796acb7/logs/screen-n-cpu.txt.gz | |
| 19:01:13 | mriedem | maybe it's something in oslo.log? | |
| 19:01:48 | mriedem | sdague: wasn't there something done with oslo.log recently to put extra metadata in messages or something? | |
| 19:02:58 | mriedem | this error summary stuff | |
| 19:03:26 | mriedem | + error." | |
| 19:03:26 | mriedem | "If the log format string - does not include ``%(error_summary)s`` it will be appended to the end + does not include ``%(error_summary)s`` the error summary will be - of the line automatically, only if there is an error. + appended to the end of the line automatically, only if there is an | |
| 19:03:49 | sdague | yeh, the NotImplementedError stuff is bleeding through there, that's going to need to be a dhellman ask | |
| 19:04:03 | sdague | that was only supposed to happen if we were in an active exception block | |
| 19:04:40 | mriedem | i'm pinging him in -oslo | |
| 19:04:44 | sdague | I think that's irrelevant and just bleed over because that was the last exception thrown | |
| 19:04:47 | clarkb | not to interrupt but looks like the nova python35 job is failing a lot and reseting things in the gate? | |
| 19:05:04 | sdague | clarkb: not really | |
| 19:05:11 | clarkb | http://logs.openstack.org/71/465171/11/gate/gate-nova-python35/2fcc59a/console.html#_2017-06-06_14_57_13_022429 and http://logs.openstack.org/89/418489/10/gate/gate-nova-tox-functional-py35-ubuntu-xenial/51b5776/console.html#_2017-06-06_13_35_33_574055 appear to be two different classes of error | |
| 19:05:30 | sdague | clarkb: there was one bad patch, and because the gate was taking a long time and other things were running a lot, it managed to run and fail a lot in the gate | |
| 19:05:35 | clarkb | gotcha | |
| 19:05:51 | sdague | this is the params one? | |
| 19:06:02 | sdague | man, the log server seems slow today | |
| 19:06:19 | mriedem | i blame systemd | |
| 19:06:26 | mriedem | er journald :) | |
| 19:06:30 | mriedem | somethingd | |
| 19:06:32 | sdague | yeh, the wrong params to __init__ was just a patch with out of date tests | |
| 19:06:33 | clarkb | sdague: mriedem its less that the log server is slow and that its a 12MB html file | |
| 19:06:44 | clarkb | sdague: the second one is a different error fwiw | |
| 19:06:50 | mriedem | i kid | |
| 19:07:45 | sdague | clarkb: it's actually the same thing | |
| 19:08:00 | sdague | https://review.openstack.org/#/c/418489/ needs work | |
| 19:08:08 | sdague | stuff was probably behind it and failing | |
| 19:09:44 | mriedem | here is the oslo.log bug https://bugs.launchpad.net/oslo.log/+bug/1696213 | |
| 19:09:45 | openstack | Launchpad bug 1696213 in oslo.log "error summary formatter is putting ": NotImplementedError" in non-error log messages" [Undecided,New] | |
| 19:10:03 | mriedem | back to this rebuild failure | |
| 19:14:44 | mriedem | http://logs.openstack.org/82/471082/1/gate/gate-novaclient-dsvm-functional-neutron-ubuntu-xenial/796acb7/logs/screen-n-cpu.txt.gz#_Jun_06_13_19_17_300332 | |
| 19:14:44 | mriedem | sdague: i see the problem | |
| 19:14:49 | mriedem | vif plugging callback timeout | |
| 19:14:50 | mriedem | during rebuild | |
| 19:14:53 | mriedem | so the instance never goes active | |
| 19:15:26 | mriedem | which someone from heat reported a rebuild bug about vif plug timeouts recently | |
| 19:16:05 | openstack | Launchpad bug 1694371 in OpenStack Compute (nova) "test_stack_snapshot_restore failing intermittently" [Undecided,New] | |
| 19:16:05 | mriedem | https://bugs.launchpad.net/nova/+bug/1694371 | |
| 19:17:54 | openstack | Launchpad bug 1694371 in OpenStack Compute (nova) "Timeout while waiting for network-vif-plugged event during server rebuild" [Undecided,New] | |
| 19:17:54 | mriedem | kevinbenton: we probably need some help from the neutron side here https://bugs.launchpad.net/nova/+bug/1694371 | |
| 19:18:06 | mriedem | kevinbenton: seeing rebuild tests timeout waiting for vif plugged events from neutron | |
| 19:22:19 | mriedem | dansmith: does it make sense to do anything in nova.objects.Instance.mutated_migration_context if there is no self.migration_context? | |
| 19:22:31 | mriedem | because we're lazy-loading 3 fields in there just to do nothing | |
| 19:23:03 | dansmith | um | |
| 19:23:11 | mriedem | i'm seeing this during a rebuild | |
| 19:23:13 | mriedem | where we're not migrating | |
| 19:23:21 | mriedem | but the rebuild code also handles evacuate, which is the migration | |
| 19:23:42 | mriedem | but it loos like we end up lazy-loading numa_topology, pci_requests and pci_devices one after another just to ultimately do nothing | |
| 19:24:48 | dansmith | yeah I guess not.. you see that debug log warning that there's no context too I guess? | |
| 19:25:27 | mriedem | http://logs.openstack.org/82/471082/1/gate/gate-novaclient-dsvm-functional-neutron-ubuntu-xenial/796acb7/logs/screen-n-cpu.txt.gz#_Jun_06_13_14_02_547424 | |
| 19:25:31 | mriedem | yup | |
| 19:25:32 | cfriesen_ | mriedem: if you're not actually migrating I think it'd be safe to bypass the mutated_migration_context | |
| 19:25:35 | mriedem | see the next 4 there | |
| 19:25:45 | mriedem | it lazy-loads 3 fields, and then says "you're dumb" | |
| 19:26:19 | mriedem | and i believe each lazy-load on those fields is going to be a full pull from the db via conductor... | |
| 19:27:58 | kevinbenton | mriedem: in a rebuild what does nova tell neutron? | |
| 19:28:06 | kevinbenton | mriedem: because the host_id doesn't change, right? | |
| 19:28:48 | cfriesen_ | mriedem: can a rebuild end up picking a new host? | |
| 19:29:46 | cfriesen_ | (when we're not doing an evacuate, I mean) | |
| 19:30:23 | mriedem | cfriesen_: kevinbenton: no, same host | |
| 19:30:35 | cfriesen_ | mriedem:, right, we specify the host in that case | |
| 19:30:39 | mriedem | kevinbenton: so my theory is neutron is not sending the event maybe because the host doesn't change | |
| 19:30:57 | mriedem | but i'd think that would be 100% fail | |
| 19:31:28 | mriedem | so i wonder if we're hitting a race where neutron is queueing notifications and thinks it already told nova something about a given port | |
| 19:32:29 | kevinbenton | mriedem: we did have a recent change on the neutron side that reduced some port status changes when they weren't needed | |
| 19:32:58 | kevinbenton | mriedem: so it's possible that there is a race that was being covered by side effects from that before | |
| 19:33:35 | kevinbenton | mriedem: do you have a set of logs from one of these failures? | |
| 19:35:25 | mriedem | kevinbenton: yeah that bug linked above has a log dive from me | |
| 19:35:30 | mriedem | showing where things happen on the nova side | |
| 19:37:43 | efried | sdague Can you please help me understand whether/how global_request_id affordance is needed in https://review.openstack.org/#/c/412634/28/nova/image/glance.py ? | |
| 19:38:25 | efried | I'm kinda hoping it's implicitly part of the ksa session... | |
| 19:38:45 | efried | ...or auth | |
| 19:40:38 | efried | ...because of the context | |
| 19:49:39 | openstackgerrit | Eric Fried proposed openstack/nova master: Adopts keystoneauth with glance client. https://review.openstack.org/412634 | |
| 19:49:50 | openstackgerrit | Eric Fried proposed openstack/nova master: Add service_token for nova-glance interaction https://review.openstack.org/419662 | |
| 19:51:26 | sdague | efried: it's not implicit | |
| 19:52:08 | efried | sdague So I need to add the header explicitly? | |
| 19:52:08 | sdague | efried: it's a single parameter to pass | |