| Posted | Nick | Remark | |
|---|---|---|---|
| #openstack-nova - 2021-05-11 | |||
| 16:01:33 | ignaziocassano | 18:00:49.552325 ARP, Request who-has 10.138.209.47 (Broadcast) tell 10.138.209.1, length 46 | |
| 16:01:34 | ignaziocassano | 18:00:49.855902 IP6 :: > ff02::16: HBH ICMP6, multicast listener report v2, 1 group record(s), length 28 | |
| 16:01:34 | ignaziocassano | 18:00:49.556230 ARP, Request who-has 10.138.209.48 (Broadcast) tell 10.138.209.1, length 46 | |
| 16:01:34 | ignaziocassano | 18:00:49.855902 IP6 :: > ff02::16: HBH ICMP6, multicast listener report v2, 1 group record(s), length 28 | |
| 16:01:34 | ignaziocassano | 18:00:49.556230 ARP, Request who-has 10.138.209.48 (Broadcast) tell 10.138.209.1, length 46 | |
| 16:01:35 | ignaziocassano | 18:00:50.009117 IP6 fe80::fc16:3eff:fe6b:8bee > ff02::2: ICMP6, router solicitation, length 16 | |
| 16:01:35 | ignaziocassano | 18:00:50.009075 IP6 fe80::fc16:3eff:fe6b:8bee > ff02::16: HBH ICMP6, multicast listener report v2, 1 group record(s), length 28 | |
| 16:01:35 | ignaziocassano | 18:00:50.009117 IP6 fe80::fc16:3eff:fe6b:8bee > ff02::2: ICMP6, router solicitation, length 16 | |
| 16:01:35 | ignaziocassano | 18:00:50.009075 IP6 fe80::fc16:3eff:fe6b:8bee > ff02::16: HBH ICMP6, multicast listener report v2, 1 group record(s), length 28 | |
| 16:01:36 | ignaziocassano | 18:00:50.285607 ARP, Reverse Request who-is fa:16:3e:6b:8b:ee (oui Unknown) tell fa:16:3e:6b:8b:ee (oui Unknown), length 46 | |
| 16:01:36 | ignaziocassano | 18:00:50.265259 ARP, Reverse Request who-is fa:16:3e:6b:8b:ee (oui Unknown) tell fa:16:3e:6b:8b:ee (oui Unknown), length 46 | |
| 16:01:36 | ignaziocassano | 18:00:50.285607 ARP, Reverse Request who-is fa:16:3e:6b:8b:ee (oui Unknown) tell fa:16:3e:6b:8b:ee (oui Unknown), length 46 | |
| 16:01:36 | ignaziocassano | 18:00:50.265259 ARP, Reverse Request who-is fa:16:3e:6b:8b:ee (oui Unknown) tell fa:16:3e:6b:8b:ee (oui Unknown), length 46 | |
| 16:01:37 | ignaziocassano | 18:00:50.294153 IP6 fe80::f816:3eff:fe6b:8bee > ff02::1: ICMP6, neighbor advertisement, tgt is fe80::f816:3eff:fe6b:8bee, length 32 | |
| 16:01:37 | ignaziocassano | 18:00:50.293932 ARP, Request who-has 10.138.248.68 tell 10.138.248.68, length 28 | |
| 16:01:37 | ignaziocassano | 18:00:50.294153 IP6 fe80::f816:3eff:fe6b:8bee > ff02::1: ICMP6, neighbor advertisement, tgt is fe80::f816:3eff:fe6b:8bee, length 32 | |
| 16:01:37 | ignaziocassano | 18:00:50.293932 ARP, Request who-has 10.138.248.68 tell 10.138.248.68, length 28 | |
| 16:01:38 | ignaziocassano | 18:00:50.344397 IP6 fe80::f816:3eff:fe6b:8bee > ff02::1: ICMP6, neighbor advertisement, tgt is fe80::f816:3eff:fe6b:8bee, length 32 | |
| 16:01:38 | ignaziocassano | 18:00:50.344367 ARP, Request who-has 10.138.248.68 tell 10.138.248.68, length 28 | |
| 16:01:38 | ignaziocassano | 18:00:50.344397 IP6 fe80::f816:3eff:fe6b:8bee > ff02::1: ICMP6, neighbor advertisement, tgt is fe80::f816:3eff:fe6b:8bee, length 32 | |
| 16:01:38 | ignaziocassano | 18:00:50.344367 ARP, Request who-has 10.138.248.68 tell 10.138.248.68, length 28 | |
| 16:01:39 | ignaziocassano | 18:00:50.494425 ARP, Request who-has 10.138.248.68 tell 10.138.248.68, length 28 | |
| 16:01:39 | ignaziocassano | 18:00:50.435854 ARP, Reverse Request who-is fa:16:3e:6b:8b:ee (oui Unknown) tell fa:16:3e:6b:8b:ee (oui Unknown), length 46 | |
| 16:01:39 | ignaziocassano | 18:00:50.494425 ARP, Request who-has 10.138.248.68 tell 10.138.248.68, length 28 | |
| 16:01:39 | ignaziocassano | 18:00:50.435854 ARP, Reverse Request who-is fa:16:3e:6b:8b:ee (oui Unknown) tell fa:16:3e:6b:8b:ee (oui Unknown), length 46 | |
| 16:01:40 | ignaziocassano | 18:00:50.494456 IP6 fe80::f816:3eff:fe6b:8bee > ff02::1: ICMP6, neighbor advertisement, tgt is fe80::f816:3eff:fe6b:8bee, length 32 | |
| 16:01:40 | ignaziocassano | 18:00:50.494456 IP6 fe80::f816:3eff:fe6b:8bee > ff02::1: ICMP6, neighbor advertisement, tgt is fe80::f816:3eff:fe6b:8bee, length 32 | |
| 16:02:13 | ignaziocassano | the above is on destination node | |
| 16:02:13 | ignaziocassano | the above is on destination node | |
| 16:02:59 | sean-k-mooney | so the Reverse Request who-is fa:16:3e:6b:8b:ee (oui Unknown) tell fa:16:3e:6b:8b:ee | |
| 16:02:59 | sean-k-mooney | so the Reverse Request who-is fa:16:3e:6b:8b:ee (oui Unknown) tell fa:16:3e:6b:8b:ee | |
| 16:03:07 | sean-k-mooney | i think was the RARP packet | |
| 16:03:07 | sean-k-mooney | i think was the RARP packet | |
| 16:04:00 | sean-k-mooney | so the question is has the ovs agent finished installing the openflow rules wehn that was sent and did tha tpacket also get sent on the physical network correnctly encapsulated | |
| 16:04:00 | sean-k-mooney | so the question is has the ovs agent finished installing the openflow rules wehn that was sent and did tha tpacket also get sent on the physical network correnctly encapsulated | |
| 16:05:04 | sean-k-mooney | ignaziocassano: can you confirm that fa:16:3e:6b:8b:ee is the vms mac address | |
| 16:05:04 | sean-k-mooney | ignaziocassano: can you confirm that fa:16:3e:6b:8b:ee is the vms mac address | |
| 16:06:00 | ignaziocassano | fa:16:3e:6b:8b:ee ues | |
| 16:06:04 | ignaziocassano | fa:16:3e:6b:8b:ee ues | |
| 16:06:04 | ignaziocassano | fa:16:3e:6b:8b:ee ues | |
| 16:06:09 | sean-k-mooney | ignaziocassano: by the way longer message like logs are best shared using http://paste.openstack.org/ | |
| 16:06:09 | sean-k-mooney | ignaziocassano: by the way longer message like logs are best shared using http://paste.openstack.org/ | |
| 16:06:11 | ignaziocassano | fa:16:3e:6b:8b:ee yes it is | |
| 16:06:11 | ignaziocassano | fa:16:3e:6b:8b:ee yes it is | |
| 16:06:15 | sean-k-mooney | :) | |
| 16:06:45 | sean-k-mooney | cool so we can see that the RARP packets are sent but we need to look at the timestamp and compore that to the neutron agent logs | |
| 16:06:45 | sean-k-mooney | cool so we can see that the RARP packets are sent but we need to look at the timestamp and compore that to the neutron agent logs | |
| 16:07:38 | ignaziocassano | do you want I send on paste.openstack.org the openvswitch agent log related to destination node ? | |
| 16:07:38 | ignaziocassano | do you want I send on paste.openstack.org the openvswitch agent log related to destination node ? | |
| 16:11:14 | ignaziocassano | sean-k-mooney which logs do you need ? | |
| 16:11:14 | ignaziocassano | sean-k-mooney which logs do you need ? | |
| 16:11:30 | ignaziocassano | I have 3 controllers and 2 compute nodes | |
| 16:11:30 | ignaziocassano | I have 3 controllers and 2 compute nodes | |
| 16:14:52 | sean-k-mooney | ignaziocassano: if you have a subset of the log for the time perod whne it booted say a 2-5 minute span around 18:00:49 | |
| 16:14:52 | sean-k-mooney | ignaziocassano: if you have a subset of the log for the time perod whne it booted say a 2-5 minute span around 18:00:49 | |
| 16:15:07 | sean-k-mooney | the we coudl take a look | |
| 16:15:07 | sean-k-mooney | the we coudl take a look | |
| 16:17:02 | ignaziocassano | Paste #52iiZxCu2PRtXAhf318N | |
| 16:17:02 | ignaziocassano | Paste #52iiZxCu2PRtXAhf318N | |
| 16:17:33 | ignaziocassano | is the dhacpagent log | |
| 16:17:33 | ignaziocassano | is the dhacpagent log | |
| 16:18:41 | ignaziocassano | sorry | |
| 16:18:41 | ignaziocassano | sorry | |
| 16:18:46 | ignaziocassano | http://paste.openstack.org/show/52iiZxCu2PRtXAhf318N/ | |
| 16:18:46 | ignaziocassano | http://paste.openstack.org/show/52iiZxCu2PRtXAhf318N/ | |
| 16:19:51 | sean-k-mooney | can you do the same thing for the ovs l2 agent log, actully it might be better to grep by the port uuid or tap name | |
| 16:19:51 | sean-k-mooney | can you do the same thing for the ovs l2 agent log, actully it might be better to grep by the port uuid or tap name | |
| 16:20:30 | sean-k-mooney | e.g. grep -i -E "tap11fdfb84-4a|fa:16:3e:6b:8b:ee|<port uuid>" | |
| 16:20:30 | sean-k-mooney | e.g. grep -i -E "tap11fdfb84-4a|fa:16:3e:6b:8b:ee|<port uuid>" | |
| 16:21:29 | sean-k-mooney | what im looking for specificly is the l2 agent in debug mode logs when ports are added to ovs and when the prot is "treated" | |
| 16:21:29 | sean-k-mooney | what im looking for specificly is the l2 agent in debug mode logs when ports are added to ovs and when the prot is "treated" | |
| 16:21:54 | sean-k-mooney | which means it has configured ovs to handel data form the port | |
| 16:21:54 | sean-k-mooney | which means it has configured ovs to handel data form the port | |
| 16:22:14 | ignaziocassano | http://paste.openstack.org/show/805250/ | |
| 16:22:14 | ignaziocassano | http://paste.openstack.org/show/805250/ | |
| 16:23:27 | sean-k-mooney | hum i guess its only logged in dbug mode i assume you dont have this in debug | |
| 16:23:27 | sean-k-mooney | hum i guess its only logged in dbug mode i assume you dont have this in debug | |
| 16:24:27 | ignaziocassano | unfortunately it is not in debug mode | |
| 16:24:27 | ignaziocassano | unfortunately it is not in debug mode | |
| 16:25:17 | sean-k-mooney | ok | |
| 16:26:01 | sean-k-mooney | ignaziocassano: i was trying to see if any of the logs form https://github.com/openstack/neutron/blob/master/neutron/plugins/ml2/drivers/openvswitch/agent/ovs_neutron_agent.py#L1793 would be printed but the ones i wanted i think are debug only | |
| 16:26:01 | sean-k-mooney | ignaziocassano: i was trying to see if any of the logs form https://github.com/openstack/neutron/blob/master/neutron/plugins/ml2/drivers/openvswitch/agent/ovs_neutron_agent.py#L1793 would be printed but the ones i wanted i think are debug only | |
| 16:26:58 | sean-k-mooney | ignaziocassano: i belive the log we were seeing before was https://github.com/openstack/neutron/blob/a12d9e41fdaf16dfefc7fe30e6198984a7588036/neutron/plugins/ml2/drivers/openvswitch/agent/ovs_neutron_agent.py#L1936 | |
| 16:26:58 | sean-k-mooney | ignaziocassano: i belive the log we were seeing before was https://github.com/openstack/neutron/blob/a12d9e41fdaf16dfefc7fe30e6198984a7588036/neutron/plugins/ml2/drivers/openvswitch/agent/ovs_neutron_agent.py#L1936 | |
| 16:28:06 | sean-k-mooney | both of those logs are at 18:00:52.542 and 18:00:54.541 | |
| 16:28:06 | sean-k-mooney | both of those logs are at 18:00:52.542 and 18:00:54.541 | |
| 16:28:15 | sean-k-mooney | which is after teh RARP packets were sent | |
| 16:28:15 | sean-k-mooney | which is after teh RARP packets were sent | |
| 16:29:03 | sean-k-mooney | that is implying you are currntly hitting the race | |
| 16:29:03 | ignaziocassano | So, what can I do to help ? | |
| 16:29:03 | sean-k-mooney | that is implying you are currntly hitting the race | |
| 16:29:03 | ignaziocassano | So, what can I do to help ? | |
| 16:29:42 | sean-k-mooney | the last log in the dhcp agent was at 18:00:48.400 | |
| 16:29:42 | sean-k-mooney | the last log in the dhcp agent was at 18:00:48.400 | |
| 16:29:53 | sean-k-mooney | right before the vm started on the dest | |
| 16:29:53 | sean-k-mooney | right before the vm started on the dest | |
| 16:30:18 | sean-k-mooney | ignaziocassano: so it does look like if the dhcp race is fixed then it would fix your issue | |
| 16:30:18 | sean-k-mooney | ignaziocassano: so it does look like if the dhcp race is fixed then it would fix your issue | |
| 16:30:47 | sean-k-mooney | ignaziocassano: so i think we just need to wait for rodolfo to finish backporting that patch to train | |
| 16:30:47 | sean-k-mooney | ignaziocassano: so i think we just need to wait for rodolfo to finish backporting that patch to train | |