| Posted | Nick | Remark | |
|---|---|---|---|
| #openstack-nova - 2018-06-21 | |||
| 19:36:32 | SpamapS | so that's where we've been trying to find what tells neutron to try that. | |
| 19:36:56 | dansmith | looks like it's in os-vif now, as I don't see (in paths that take os-vif) where we do it in nova anymore | |
| 19:37:49 | dansmith | https://github.com/openstack/nova/blob/master/nova/virt/libvirt/driver.py#L5604-L5607 | |
| 19:37:58 | dansmith | that context won't return until the event is received | |
| 19:38:09 | SpamapS | correct | |
| 19:38:10 | dansmith | so we start the context, do something that will trigger the event, and on __exit__ we wait for the event | |
| 19:38:11 | SpamapS | we're timing out there | |
| 19:39:02 | SpamapS | dansmith: and that do something is..... | |
| 19:39:17 | dansmith | plug | |
| 19:42:03 | SpamapS | dansmith: right, I see that, but how does neutron find out that you plugged? | |
| 19:42:29 | dansmith | I'm looking through os-vif now | |
| 19:42:36 | SpamapS | I had thought it was something like, nova-compute calls os_vif.<plugin>.plug(things) and then sends some kind of message to the conductors to say "we plugged!" and the conductors call neutron. | |
| 19:42:46 | dansmith | no | |
| 19:43:40 | dansmith | I dunno, I don't really see os-vif calling neutron anywhere | |
| 19:43:52 | SpamapS | nor do I | |
| 19:44:37 | SpamapS | only nova.network.neutronv2 calls neutron AFAICT | |
| 19:45:13 | dansmith | well, that's our interface for it of course | |
| 19:46:49 | SpamapS | IIRC, network-vif-plugged is sent when a port goes from DOWN -> ACTIVE | |
| 19:47:01 | SpamapS | and the neutron agent does that transition (we're using linuxbridge) | |
| 19:47:15 | SpamapS | so then I'm looking for what tells the neutron agent to do *that* | |
| 19:50:10 | jroll | doesn't that happen when the 'host' is sent in the portbinding part of the port body? (whether during port create or update | |
| 19:52:03 | jroll | which I guess would be here: https://github.com/openstack/nova/blob/master/nova/network/neutronv2/api.py#L1072 | |
| 19:53:09 | SpamapS | right, I think that triggers binding | |
| 19:53:32 | dansmith | the key is, we can't do it until we've created the tap or whatever type of interface | |
| 19:53:49 | dansmith | which is why this interlock exists | |
| 19:54:38 | SpamapS | the tap happens | |
| 19:55:36 | SpamapS | so, IIRC, nova-compute doesn't call that, nova-conductor calls that | |
| 19:55:47 | dansmith | nova conductor calls what? | |
| 19:55:53 | dansmith | bind? | |
| 19:56:21 | SpamapS | well I mean, nova-conductor is the only one making calls to the neutron API | |
| 19:56:38 | dansmith | no, that's definitely not true | |
| 19:56:39 | jroll | _update_ports_for_instance is called by allocate_for_instance, which was in nova-compute last I checked | |
| 19:56:48 | dansmith | right | |
| 19:57:20 | dansmith | but, the thing that triggers this plug event has to happen within that context or we could miss it | |
| 19:57:21 | SpamapS | ah ok | |
| 19:57:56 | SpamapS | so, the port gets a binding_host_id, but does not get status set to ACTIVE | |
| 19:58:29 | jroll | sounds like something is failing in neutron, then | |
| 19:59:01 | dansmith | could be that, but neutron is supposed to indicate failure to us if it does | |
| 19:59:20 | jroll | or locking up in neutron, I guess :) | |
| 19:59:36 | dansmith | or neutron is sending it and it's not hitting nova-api, which is fairly common | |
| 19:59:57 | jroll | neutron sets the port to ACTIVE, no? | |
| 20:00:01 | SpamapS | network-vif-plugged will not be sent until ACTIVE | |
| 20:00:10 | SpamapS | agents make ports ACTIVE AFAICT | |
| 20:02:15 | dansmith | SpamapS: which version is this again? and specifically which version of os-vif? | |
| 20:02:32 | SpamapS | Pike | |
| 20:02:34 | dansmith | IIRC, ovs used to be the only one that supported events at all, | |
| 20:02:40 | dansmith | oh okay, that's new enough I think | |
| 20:02:48 | dansmith | are you sure these events were coming in before? | |
| 20:03:01 | SpamapS | os-vif==1.7.0 | |
| 20:03:01 | dansmith | and that you haven't just flipped vif-plugging-is-fatal recently or something? | |
| 20:03:10 | SpamapS | yes they were coming in | |
| 20:03:21 | dansmith | neutron will log when it sends the events, IIRC as they are batched, | |
| 20:03:29 | dansmith | so can you see it doing stuff to generate those? | |
| 20:04:08 | SpamapS | we did a deploy which mostly didn't change much, just some external things, and everything stopped working. We saw this once before when we had a badly configured cell that had the top level rmq's as the transport_url, and deleting that cell, and restarting everything fixed that.. but now.. stuck. | |
| 20:04:42 | SpamapS | Which is why I'm trying to figure out if nova-compute<->nova-conductor comms fail are causing the issue. | |
| 20:04:59 | SpamapS | neutron is not logging trying to send network-vif-plugged | |
| 20:05:09 | SpamapS | which is not a surprise because the ports are not going ACTIVE | |
| 20:05:16 | dansmith | a conductor or compute with a badly-configured transport_url in the config would prevent them from talking to other services in their cell | |
| 20:05:20 | SpamapS | I presume that is because whatever triggers the agent to make them active is not happening. | |
| 20:05:30 | dansmith | for events, nova-api looks up the cell of the instance and fires the event direct to the compute via its mq | |
| 20:06:44 | SpamapS | We've doubled checked all the config files, which didn't change anyway, they're all talking to the right rabbits. | |
| 20:06:46 | SpamapS | And the cells are fixed now | |
| 20:07:11 | SpamapS | just worried that something is stuck somewhere that is making a service still send events meant for cell-rabbit to top-level-rabbit. | |
| 20:07:36 | SpamapS | but neutron isn't really "cell aware" so I still suspect nova | |
| 20:07:53 | SpamapS | and can't seem to find the thing that nova does to tell neutron to activate a port | |
| 20:08:16 | dansmith | so, having looked through all the plug path stuff just now, | |
| 20:08:41 | dansmith | the only thing I can think of is if we create the tap, name it as we were told, and neutron agent on the compute notices that it got created, adds it to the bridge, and then fires the event | |
| 20:09:29 | dansmith | I thought we specifically called to neutron to tell it it was ready, but maybe we don't | |
| 20:09:35 | SpamapS | I think we do too | |
| 20:10:43 | dansmith | well, the plug path for linux bridge is pretty darn simple | |
| 20:11:22 | SpamapS | yeah, neutron even reports that it doesn't have to do anything when it gets triggered.. | |
| 20:11:23 | SpamapS | when things are working | |
| 20:12:02 | dansmith | there is a neutron agent running on that box at the time, right/ | |
| 20:12:18 | dansmith | and not in a container in such a way that it can't see the interfaces nova would create? | |
| 20:13:12 | SpamapS | yes the agent is running | |
| 20:13:22 | SpamapS | and they share a netns (deployed with kolla-ansible) | |
| 20:13:31 | SpamapS | they actually don't even have a netns | |
| 20:13:34 | SpamapS | they're on the host's networking | |
| 20:15:59 | dansmith | from looking through the agent (for the first time ever) it surely looks like it's just polling for new interfaces to pop up | |
| 20:18:49 | SpamapS | dansmith: I can verify that brctl show from inside the agent shows the taps | |
| 20:20:36 | openstackgerrit | Brianna Poulos proposed openstack/python-novaclient master: Fix trusted-image-certificate-id help text https://review.openstack.org/576555 | |
| 20:23:25 | dansmith | yeah, so the agent runs a loop, | |
| 20:23:46 | dansmith | each time through it looks for new interfaces, calls process_network_devices(), which goes through each new one, ends up at plug_interface(), etc, etc | |
| 20:24:16 | dansmith | so I think we create a properly-named tap, it notices, does the plug into the bridge and the wiring and then emits the notification | |
| 20:24:39 | dansmith | which explains why I can't find any calls to neutron in the critical path while we're waiting | |
| 20:26:05 | SpamapS | dansmith: makes sense I 'spose | |
| 20:27:00 | dansmith | looks like with debug on, | |
| 20:27:12 | dansmith | the agent should log "Agent loop found changes!" and then the device info it found | |
| 20:27:23 | dansmith | do you see that happen once nova has created the taps? | |
| 20:28:24 | dansmith | this: https://github.com/openstack/neutron/blob/master/neutron/plugins/ml2/drivers/agent/_common_agent.py#L453-L453 | |
| 20:30:38 | SpamapS | dansmith: right, we never get Agent loop found changes | |
| 20:30:45 | SpamapS | stracing now to see why | |
| 20:33:49 | dansmith | got confirmation from someone who would know that "plug" communication between neutron and nova just involves creating the interface | |
| 20:36:30 | SpamapS | k | |
| 20:36:55 | SpamapS | well I can see the taps from the linuxbridge container | |
| 20:37:07 | SpamapS | but I never see the agent actually polling brctl or ip or anything | |
| 20:37:39 | dansmith | well, it may use iproute directly | |
| 20:37:49 | dansmith | which would strace out as a socket(AF_NETLINK,...) early on | |
| 20:37:59 | SpamapS | "or ip" was my vague reference to iproute | |
| 20:38:07 | SpamapS | but .. oh that? | |