Earlier  
Later
New Search
Posted Nick Remark
#openstack-nova - 2018-12-11
20:41:40 mriedem but yeah my guess is since vendordata_jsonfile_path isn't set in nova.conf on nova-compute it's just not serving anything up
20:49:53 codyhill mriedem: Thanks for your help. I’ll give this a shot. (I’m in a meeting right now) But i’ll report my findings in about an hour.
20:50:18 mriedem good luck
20:55:02 openstackgerrit Merged openstack/nova stable/queens: Move the nova-next job in-tree and update it https://review.openstack.org/620777
20:55:09 openstackgerrit Merged openstack/nova stable/queens: Test websocketproxy with TLS in the nova-next job https://review.openstack.org/620776
20:55:15 openstackgerrit Merged openstack/nova stable/queens: Make the nova-next job voting and gating https://review.openstack.org/620888
21:08:23 openstackgerrit Matt Riedemann proposed openstack/nova master: DNM: debug old compute API service version lookup https://review.openstack.org/624438
21:25:53 melwitt mriedem: I noticed you have commented "recheck slow node" on some patches and was wondering, are you categorizing a failure to boot due to a timeout waiting for network-vif-plugged as that? example: http://logs.openstack.org/35/575735/4/gate/tempest-slow/7e5803b/controller/logs/screen-n-cpu.txt.gz#_Dec_11_16_33_46_458364
21:26:20 mriedem network-vif-plugged takes about 5 seconds
21:26:35 mriedem so if we timeout because we ddn't get that after 5 minutes, we likely screwed up somewhere
21:26:47 mriedem and rax isn't the slow nodes
21:26:57 melwitt ok
21:27:36 melwitt I'll check if neutron sent it. if so, we probably have another race or issue where we get the event before we start waiting or something
21:28:19 mriedem note 2 seconds before that a vif is unplugged http://logs.openstack.org/35/575735/4/gate/tempest-slow/7e5803b/controller/logs/screen-n-cpu.txt.gz#_Dec_11_16_33_44_406723
21:29:13 mriedem there are a bunch of unplugged vif messages for that same request
21:29:37 mriedem this is the timeout waiting for network-vif-plugged
21:29:37 mriedem http://logs.openstack.org/35/575735/4/gate/tempest-slow/7e5803b/controller/logs/screen-n-cpu.txt.gz#_Dec_11_16_33_43_583022
21:29:45 melwitt yeah, I saw that. I thought maybe it's some cleanup it does in response to the timeout (the _cleanup_failed_start routine)
21:30:14 melwitt unplugs all the vifs and then raises VirtualInterfaceCreateException
21:30:26 mriedem looks like this is the first plug
21:30:26 mriedem http://logs.openstack.org/35/575735/4/gate/tempest-slow/7e5803b/controller/logs/screen-n-cpu.txt.gz#_Dec_11_16_28_41_912716
21:30:32 mriedem which is 5 minutes before
21:31:02 mriedem likely yes, spawn() times out, unplugs vifs, meanwhile tempest is also timing out and destroying the instance concurrently which is doing its own unplugs
21:31:56 mriedem jesus does that test really plug 7 ports to the same vm?
21:32:05 mriedem Dec 11 16:33:43.583022 ubuntu-xenial-rax-iad-0001127841 nova-compute[368]: WARNING nova.virt.libvirt.driver [None req-8a094b29-c0e9-445c-848e-3c827f681858 tempest-TaggedBootDevicesTest-731133270 tempest-TaggedBootDevicesTest-731133270] [instance: 01e6b7fe-bfa0-4d51-bcdf-03e65971ed74] Timeout waiting for [('network-vif-plugged', u'c1777114-78f7-4533-8725-d01139d29c02'), ('network-vif-plugged', u'caade525-9701-47b4-a5d1-bc11076
21:32:05 mriedem 5'), ('network-vif-plugged', u'a5b3eb7e-696c-4870-abf1-b3ee43545dbe'), ('network-vif-plugged', u'ede8a324-5ed5-4737-bf6c-1b2f21b4f090'), ('network-vif-plugged', u'99e00244-9a75-4a25-9742-5c67b86ba0b2'), ('network-vif-plugged', u'11c3d630-37f4-4fd3-ba88-8355f7253ea6'), ('network-vif-plugged', u'05bb2644-68b1-4f07-a44e-f2277b444792')] for instance with vm_state building and task_state spawning.: Timeout: 300 seconds
21:32:42 mriedem Dec 11 16:28:45.973940 ubuntu-xenial-rax-iad-0001127841 nova-compute[368]: DEBUG nova.compute.manager [req-9fb4fde1-0cb0-4896-b0c3-5f8535a0fbd1 req-17f33770-c6cf-4fef-ade4-72fab2d05def service nova] [instance: 01e6b7fe-bfa0-4d51-bcdf-03e65971ed74] Processing event network-vif-plugged-caade525-9701-47b4-a5d1-bc11076c47f5 {{(pid=368) _process_instance_event /opt/stack/nova/nova/compute/manager.py:7952}}
21:33:02 melwitt I wasn't sure, I'm not that familiar with the tagged devices test. I didn't get that far yet
21:33:18 mriedem artom wrote it
21:33:19 mriedem Dec 11 16:28:48.063359 ubuntu-xenial-rax-iad-0001127841 nova-compute[368]: DEBUG nova.compute.manager [req-4f071ef5-d1a5-4cfb-820b-2d562666e534 req-86897002-4096-4477-a6ae-19515f45c40f service nova] [instance: 01e6b7fe-bfa0-4d51-bcdf-03e65971ed74] Processing event network-vif-plugged-a5b3eb7e-696c-4870-abf1-b3ee43545dbe {{(pid=368) _process_instance_event /opt/stack/nova/nova/compute/manager.py:7952}}
21:33:34 mriedem Dec 11 16:28:48.059696 ubuntu-xenial-rax-iad-0001127841 nova-compute[368]: DEBUG nova.compute.manager [req-4f071ef5-d1a5-4cfb-820b-2d562666e534 req-86897002-4096-4477-a6ae-19515f45c40f service nova] [instance: 01e6b7fe-bfa0-4d51-bcdf-03e65971ed74] Processing event network-vif-plugged-ede8a324-5ed5-4737-bf6c-1b2f21b4f090 {{(pid=368) _process_instance_event /opt/stack/nova/nova/compute/manager.py:7952}}
21:33:47 mriedem Dec 11 16:28:48.061523 ubuntu-xenial-rax-iad-0001127841 nova-compute[368]: DEBUG nova.compute.manager [req-4f071ef5-d1a5-4cfb-820b-2d562666e534 req-86897002-4096-4477-a6ae-19515f45c40f service nova] [instance: 01e6b7fe-bfa0-4d51-bcdf-03e65971ed74] Processing event network-vif-plugged-99e00244-9a75-4a25-9742-5c67b86ba0b2 {{(pid=368) _process_instance_event /opt/stack/nova/nova/compute/manager.py:7952}}
21:33:59 mriedem Dec 11 16:28:48.055772 ubuntu-xenial-rax-iad-0001127841 nova-compute[368]: DEBUG nova.compute.manager [req-4f071ef5-d1a5-4cfb-820b-2d562666e534 req-86897002-4096-4477-a6ae-19515f45c40f service nova] [instance: 01e6b7fe-bfa0-4d51-bcdf-03e65971ed74] Processing event network-vif-plugged-11c3d630-37f4-4fd3-ba88-8355f7253ea6 {{(pid=368) _process_instance_event /opt/stack/nova/nova/compute/manager.py:7952}}
21:34:11 mriedem Dec 11 16:28:48.057381 ubuntu-xenial-rax-iad-0001127841 nova-compute[368]: DEBUG nova.compute.manager [req-4f071ef5-d1a5-4cfb-820b-2d562666e534 req-86897002-4096-4477-a6ae-19515f45c40f service nova] [instance: 01e6b7fe-bfa0-4d51-bcdf-03e65971ed74] Processing event network-vif-plugged-05bb2644-68b1-4f07-a44e-f2277b444792 {{(pid=368) _process_instance_event /opt/stack/nova/nova/compute/manager.py:7952}}
21:34:14 mriedem looks like we got 6 of 7
21:34:45 mriedem c1777114-78f7-4533-8725-d01139d29c02 was the missing port event
21:36:21 melwitt that's a lot of ports
21:37:49 mriedem not for cfriesen
21:37:55 melwitt haha
21:38:03 mriedem cfriesen eats that many ports for f'ing breakfast
21:38:43 cfriesen Kellog's Port Loops...breakfast of champions.
21:42:59 openstackgerrit Matt Riedemann proposed openstack/nova master: Remove GROUP BY clause from CellMapping.get_by_project_id https://review.openstack.org/619061
21:43:03 mriedem zzzeek: ^ updated to remove that GROUP BY, i'm doing the grouping in python - thanks for the mysql mode note on that
21:46:05 melwitt yup, only 6 network-vif-plugged events sent in the neutron service log matching 'network-vif-plugged', u'server_uuid': u'01e6b7fe-bfa0-4d51-bcdf-03e65971ed74
21:47:02 mriedem http://logstash.openstack.org/#dashboard/file/logstash.json?query=message%3A%5C%22TaggedBootDevicesTest%5C%22%20AND%20message%3A%5C%22Timeout%20waiting%20for%20%5B('network-vif-plugged'%5C%22%20AND%20tags%3A%5C%22screen-n-cpu.txt%5C%22&from=7d fwiw only hits on that one change
21:47:09 mriedem so maybe it just got really really unlucky
21:47:20 melwitt only event I find related to that port is:
21:47:22 melwitt Dec 11 16:28:19.663912 ubuntu-xenial-rax-iad-0001127841 neutron-server[23986]: INFO neutron.notifiers.nova [-] Nova event response: {u'status': u'completed', u'tag': u'c1777114-78f7-4533-8725-d01139d29c02', u'name': u'network-changed', u'server_uuid': u'01e6b7fe-bfa0-4d51-bcdf-03e65971ed74', u'code': 200}
21:48:26 melwitt I feel like I've seen that before, where network-changed can happen instead of network-vif-plugged. I can't remember why/how
21:51:43 mriedem hmm, not sure, sean-k-mooney might remember the different cases in which those events are sent
21:52:20 mriedem but neutron might be doing something like, oh we're already going to send the network-changed event for this port, so don't also send it for network-vif-plugged,
21:52:28 mriedem maybe the events are queued up by port_id and it gets overwritten
21:52:52 melwitt yeah, could be. I'll try to remember to pick sean-k-mooney's brain about it later
21:53:31 melwitt thanks for the help in looking at it
22:10:32 openstackgerrit Matt Riedemann proposed openstack/nova master: Lazy-load SchedulerReportClient from API and drop _create_client lock https://review.openstack.org/623246
22:10:32 openstackgerrit Matt Riedemann proposed openstack/nova master: DRY up SchedulerReportClient init https://review.openstack.org/623247
22:10:35 mriedem is jay done for the year?
22:11:30 codyhill mriedem: Worked! I wish I could use Metadata service for this. But it looks like that is a bug between cloud-init and ironic. But with config-drive… This works for me! Thanks for the help!
22:11:48 mriedem codyhill: cool
22:12:05 mriedem maybe we should update the docs somewhere to mention that you need to set the config on nova-compute if you're using config drive...
22:12:57 mriedem codyhill: any suggestions there ^ to help others from beating their heads?
22:49:36 openstackgerrit Matt Riedemann proposed openstack/nova master: Cleanup vendordata docs https://review.openstack.org/624518
22:50:15 melwitt mriedem: he's attending the oath techpulse conference this week, says penick
22:50:19 openstackgerrit Matt Riedemann proposed openstack/nova master: Cleanup vendordata docs https://review.openstack.org/624518
22:50:20 mriedem codyhill: ^
22:50:35 mriedem oh great, techpulse
22:50:43 mriedem we're flatlining here
22:54:07 melwitt when I test fails for ssh timeout and says this:
22:54:09 melwitt tempest.lib.exceptions.SSHTimeout: Connection to the 172.24.5.148 via SSH timed out.
22:54:09 melwitt User: cirros, Password: O0*bEQwoQf2_bEu
22:54:45 melwitt does that really mean it used that password to login to cirros? because that's not the usual password it says it will be "login as 'cirros' user. default password: 'cubswin:)'. use 'sudo' for root."
22:57:36 melwitt because that should never work I don't think
23:09:30 melwitt oh, it doesn't use password "Creating ssh connection to '172.24.5.148:22' as 'cirros' with public key authentication"
23:11:20 mriedem note infra is dealing with a cirros issue where ssh fails b/c networking isn't setup in the guest b/c config drive is too small
23:11:43 mriedem https://bugs.launchpad.net/openstack-gate/+bug/1808010
23:11:43 openstack Launchpad bug 1808010 in OpenStack-Gate "Tempest cirros boots fail due to lack of disk space" [Undecided,New]
23:12:24 melwitt clicky
23:16:18 melwitt looks like that's the culprit. I don't see the "no space left" messages but I do see "WARN: failed: route add -net "0.0.0.0/0" gw "10.1.0.1""
23:18:02 melwitt so I guess it's not the same but has the same failure to add the route
23:35:32 melwitt added a comment to lp
#openstack-nova - 2018-12-12
00:40:20 openstackgerrit Merged openstack/nova master: Fix typo https://review.openstack.org/624442
00:52:25 mriedem dansmith: i think i've figured out why we're getting that ocata api service version warning in the logs - https://review.openstack.org/#/c/624438/ - something is re-entering _get_instance with a cell1-targeted context, so it's failing to find any nova-osapi_compute services in the cell1 db (as expected), i'm just not sure where the re-entry is coming from.
00:56:20 mriedem and that's why we don't get a 404 from the Instance.get_by_uuid call because the context is already targeted
01:04:21 openstackgerrit Matt Riedemann proposed openstack/nova master: DNM: add debug logging for bug 1807723 https://review.openstack.org/624181
01:04:21 openstack bug 1807723 in tempest "test_volume_swap_with_multiattach intermittently fails during cleanup" [High,In progress] https://launchpad.net/bugs/1807723 - Assigned to Matt Riedemann (mriedem)
01:14:04 openstackgerrit Matt Riedemann proposed openstack/nova master: DNM: debug old compute API service version lookup https://review.openstack.org/624438
02:13:25 openstackgerrit Yikun Jiang proposed openstack/nova master: Add live migration timeout action https://review.openstack.org/619143
02:41:49 openstackgerrit Yikun Jiang proposed openstack/nova master: Add live migration timeout action https://review.openstack.org/619143
03:26:41 openstackgerrit Yikun Jiang proposed openstack/nova master: Remove live_migration_progress_timeout config https://review.openstack.org/619142
03:35:45 openstackgerrit Merged openstack/nova master: Only warn about not having computes nodes once in rpcapi https://review.openstack.org/623282
03:58:19 openstackgerrit Merged openstack/nova master: Handle tags in _bury_in_cell0 https://review.openstack.org/621856
07:09:10 openstackgerrit Michael Still proposed openstack/nova master: Imagebackend should call processutils.execute directly. https://review.openstack.org/619704
07:09:11 openstackgerrit Michael Still proposed openstack/nova master: Remove final users of utils.execute() in libvirt. https://review.openstack.org/619705
07:09:11 openstackgerrit Michael Still proposed openstack/nova master: Remove the final user of utils.execute() from virt.images https://review.openstack.org/620007
07:09:12 openstackgerrit Michael Still proposed openstack/nova master: Remove utils.execute() from the hyperv driver. https://review.openstack.org/620008
07:09:12 openstackgerrit Michael Still proposed openstack/nova master: Remove utils.execute() from virt.disk.api. https://review.openstack.org/620009
07:09:13 openstackgerrit Michael Still proposed openstack/nova master: Move a generic bridge helper to a linux_net privsep file. https://review.openstack.org/620010
07:09:13 openstackgerrit Michael Still proposed openstack/nova master: Move bridge creation to privsep. https://review.openstack.org/620180
07:09:14 openstackgerrit Michael Still proposed openstack/nova master: Move some linux network helpers to use privsep. https://review.openstack.org/621398
07:09:14 openstackgerrit Michael Still proposed openstack/nova master: Move simple execute call to processutils. https://review.openstack.org/621527

Earlier   Later