2025-08-06 16:06:42,642 - INFO - Domain Default found not creating 2025-08-06 16:06:42,789 - INFO - Project ctest-DisablePolicyEcmpIpv6-67518367 not found, creating it 2025-08-06 16:06:43,341 - INFO - Created Project:ctest-DisablePolicyEcmpIpv6-67518367, ID : 5ac72286-54a6-4fda-a7cd-d23b8ee100bd 2025-08-06 16:06:44,871 - INFO - ================================================================================ 2025-08-06 16:06:44,872 - INFO - STARTING TEST : test_ecmp_with_static_routes 2025-08-06 16:06:44,872 - INFO - TEST DESCRIPTION : Description: Verify disabling policy for ECMP routes with static routes on VM Steps: 1. launch 1 VN and launch 3 VMs in it. 2. create a static route for a new subnet prefix and add this on 2 VMIs. this will create 2 ECMP routes. 3. Disable the policy on all VMIs. 4. Now from 3rd VM send traffic to an IP from static route prefix 5. add new ECMP destinations and verify load is distributed to new destinations too 6. remove ECMP destinations and verify load is distributed to remaining destinations Pass criteria: 1. traffic should go through fine 2. flows should not be created 3. load should be distributed among ecmp routes. 2025-08-06 16:06:46,189 - DEBUG - Nothing to compare xmpp stats {'10.0.0.49': {'10.20.0.25': '0', '10.20.0.14': '0'}, '10.0.0.57': {'10.20.0.25': '0', '10.20.0.14': '0'}} with 2025-08-06 16:06:46,190 - INFO - Address family configured is dual 2025-08-06 16:06:46,190 - INFO - we are setting address family as v6 2025-08-06 16:06:46,190 - INFO - we are setting address family as v6 2025-08-06 16:06:46,190 - INFO - Initial checks done. Running the testcase now 2025-08-06 16:06:46,190 - INFO - 2025-08-06 16:06:46,215 - DEBUG - Services list from nova: [, , , ] 2025-08-06 16:06:46,215 - DEBUG - Hosts: {'nova': ['an-jenkins-deploy-platform-ansible-os-3763-1', 'an-jenkins-deploy-platform-ansible-os-3763-2']} 2025-08-06 16:06:46,885 - DEBUG - Response for create_network : {'network': {'id': '39e18760-d3e7-4bf7-9689-cf56ee171da4', 'name': 'ctest-vn-18413561', 'tenant_id': '5ac7228654a64fdaa7cdd23b8ee100bd', 'project_id': '5ac7228654a64fdaa7cdd23b8ee100bd', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-DisablePolicyEcmpIpv6-67518367', 'ctest-vn-18413561'], 'port_security_enabled': True, 'description': ''}} 2025-08-06 16:06:47,171 - DEBUG - Response for create_subnet : {'subnet': {'id': 'def68046-8aee-403c-b6dc-ace705f47f3a', 'name': '', 'tenant_id': '5ac7228654a64fdaa7cdd23b8ee100bd', 'network_id': '39e18760-d3e7-4bf7-9689-cf56ee171da4', 'ip_version': 6, 'cidr': '3a1e:2214:f427:dcc:e681:71b::/96', 'allocation_pools': [{'start': '3a1e:2214:f427:dcc:e681:71b:0:2', 'end': '3a1e:2214:f427:dcc:e681:71b:ffff:fffe'}], 'gateway_ip': '3a1e:2214:f427:dcc:e681:71b:0:1', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '3a1e:2214:f427:dcc:e681:71b:0:2', 'tags': [], 'project_id': '5ac7228654a64fdaa7cdd23b8ee100bd'}} 2025-08-06 16:06:47,437 - DEBUG - Response for create_subnet : {'subnet': {'id': '9717fa97-104a-43c5-b328-79ddd3f06f60', 'name': '', 'tenant_id': '5ac7228654a64fdaa7cdd23b8ee100bd', 'network_id': '39e18760-d3e7-4bf7-9689-cf56ee171da4', 'ip_version': 4, 'cidr': '30.66.173.64/26', 'allocation_pools': [{'start': '30.66.173.66', 'end': '30.66.173.126'}], 'gateway_ip': '30.66.173.65', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '30.66.173.66', 'tags': [], 'project_id': '5ac7228654a64fdaa7cdd23b8ee100bd'}} 2025-08-06 16:06:47,463 - INFO - Created VN ctest-vn-18413561 2025-08-06 16:06:47,476 - DEBUG - VN ctest-vn-18413561 UUID is 39e18760-d3e7-4bf7-9689-cf56ee171da4 2025-08-06 16:06:47,603 - DEBUG - Requesting: http://10.0.0.254:8082/domains 2025-08-06 16:06:47,938 - DEBUG - Requesting: http://10.0.0.254:8082/domains 2025-08-06 16:06:47,997 - DEBUG - Requesting: http://10.0.0.254:8082/domain/024378da-7408-4369-ac73-51fa8d4d8d77 2025-08-06 16:06:48,021 - DEBUG - Requesting: http://10.0.0.254:8082/project/5ac72286-54a6-4fda-a7cd-d23b8ee100bd 2025-08-06 16:06:48,150 - DEBUG - Requesting: http://10.0.0.254:8082/virtual-network/39e18760-d3e7-4bf7-9689-cf56ee171da4 2025-08-06 16:06:48,175 - DEBUG - Requesting: http://10.0.0.254:8082/virtual-network/39e18760-d3e7-4bf7-9689-cf56ee171da4 2025-08-06 16:06:48,195 - DEBUG - Requesting: http://10.0.0.254:8082/routing-instance/80eeca19-8118-4082-a99e-35ed8be16d22 2025-08-06 16:06:48,211 - DEBUG - Requesting: http://10.0.0.254:8082/routing-instance/80eeca19-8118-4082-a99e-35ed8be16d22 2025-08-06 16:06:48,223 - DEBUG - Requesting: http://10.0.0.254:8082/route-target/15f3fa02-29fd-4fe0-a8f2-dbae1fd2d743 2025-08-06 16:06:48,236 - DEBUG - Route Targets: ['target:64512:8000005'] 2025-08-06 16:06:48,237 - DEBUG - Requesting: http://10.0.0.254:8082/virtual-network/39e18760-d3e7-4bf7-9689-cf56ee171da4 2025-08-06 16:06:48,250 - DEBUG - Requesting: http://10.0.0.254:8082/routing-instance/80eeca19-8118-4082-a99e-35ed8be16d22 2025-08-06 16:06:48,270 - INFO - Verified VN network id 9 for VN 39e18760-d3e7-4bf7-9689-cf56ee171da4 2025-08-06 16:06:48,270 - INFO - Verifications in API Server for VN ctest-vn-18413561 passed 2025-08-06 16:06:48,270 - DEBUG - Requesting: http://10.0.0.254:8082/virtual-network/39e18760-d3e7-4bf7-9689-cf56ee171da4 2025-08-06 16:06:48,282 - DEBUG - Requesting: http://10.0.0.254:8082/routing-instance/80eeca19-8118-4082-a99e-35ed8be16d22 2025-08-06 16:06:48,291 - DEBUG - Requesting: http://10.0.0.254:8082/routing-instance/80eeca19-8118-4082-a99e-35ed8be16d22 2025-08-06 16:06:48,300 - DEBUG - Requesting: http://10.0.0.254:8082/route-target/15f3fa02-29fd-4fe0-a8f2-dbae1fd2d743 2025-08-06 16:06:48,319 - DEBUG - Control-node 10.0.0.254 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-DisablePolicyEcmpIpv6-67518367:ctest-vn-18413561', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-DisablePolicyEcmpIpv6-67518367', 'owner-access': '7', 'group': 'reader', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '4170763579863550967', 'uuid-lslong': '10847429149767179684'}, 'enable': 'true', 'created': '2025-08-06T16:06:46', 'last-modified': '2025-08-06T16:06:47', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:01.000331'} 2025-08-06 16:06:48,327 - DEBUG - Route Targets: ['target:64512:8000005'] 2025-08-06 16:06:48,334 - DEBUG - Control-node 10.0.0.38 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-DisablePolicyEcmpIpv6-67518367:ctest-vn-18413561', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-DisablePolicyEcmpIpv6-67518367', 'owner-access': '7', 'group': 'reader', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '4170763579863550967', 'uuid-lslong': '10847429149767179684'}, 'enable': 'true', 'created': '2025-08-06T16:06:46', 'last-modified': '2025-08-06T16:06:47', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:01.017514'} 2025-08-06 16:06:48,346 - DEBUG - Route Targets: ['target:64512:8000005'] 2025-08-06 16:06:48,353 - DEBUG - Control-node 10.0.0.48 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-DisablePolicyEcmpIpv6-67518367:ctest-vn-18413561', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-DisablePolicyEcmpIpv6-67518367', 'owner-access': '7', 'group': 'reader', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '4170763579863550967', 'uuid-lslong': '10847429149767179684'}, 'enable': 'true', 'created': '2025-08-06T16:06:46', 'last-modified': '2025-08-06T16:06:47', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:01.035739'} 2025-08-06 16:06:48,360 - DEBUG - Route Targets: ['target:64512:8000005'] 2025-08-06 16:06:48,360 - INFO - On all control nodes, Config, RI and RT verification for VN ctest-vn-18413561 passed 2025-08-06 16:06:48,361 - DEBUG - ====Verifying policy data for ctest-vn-18413561 in API_Server ====== 2025-08-06 16:06:48,361 - DEBUG - Requesting: http://10.0.0.254:8082/domains 2025-08-06 16:06:48,368 - DEBUG - Requesting: http://10.0.0.254:8082/domain/024378da-7408-4369-ac73-51fa8d4d8d77 2025-08-06 16:06:48,381 - DEBUG - Requesting: http://10.0.0.254:8082/project/5ac72286-54a6-4fda-a7cd-d23b8ee100bd 2025-08-06 16:06:48,475 - DEBUG - Requesting: http://10.0.0.254:8082/virtual-network/39e18760-d3e7-4bf7-9689-cf56ee171da4 2025-08-06 16:06:48,491 - DEBUG - =>VN ctest-vn-18413561 has no policy to be verified 2025-08-06 16:06:48,492 - DEBUG - Verifying the vn in opserver 2025-08-06 16:06:48,492 - DEBUG - Verifying the default-domain:ctest-DisablePolicyEcmpIpv6-67518367:ctest-vn-18413561 virtual network link through opserver 10.0.0.254 2025-08-06 16:06:48,492 - DEBUG - Requesting: http://10.0.0.254:8081/analytics/uves/virtual-networks 2025-08-06 16:06:48,800 - DEBUG - Requesting: http://10.0.0.254:8081/analytics/uves/virtual-networks 2025-08-06 16:06:48,877 - DEBUG - vn link and name as {'name': 'default-domain:ctest-DisablePolicyEcmpIpv6-67518367:ctest-vn-18413561', 'href': 'http://10.0.0.254:8081/analytics/uves/virtual-network/default-domain:ctest-DisablePolicyEcmpIpv6-67518367:ctest-vn-18413561?flat'} 2025-08-06 16:06:48,877 - DEBUG - Verifying the default-domain:ctest-DisablePolicyEcmpIpv6-67518367:ctest-vn-18413561 virtual network link through opserver 10.0.0.38 2025-08-06 16:06:48,877 - DEBUG - Requesting: http://10.0.0.38:8081/analytics/uves/virtual-networks 2025-08-06 16:06:49,190 - DEBUG - Requesting: http://10.0.0.38:8081/analytics/uves/virtual-networks 2025-08-06 16:06:49,255 - DEBUG - vn link and name as {'name': 'default-domain:ctest-DisablePolicyEcmpIpv6-67518367:ctest-vn-18413561', 'href': 'http://10.0.0.38:8081/analytics/uves/virtual-network/default-domain:ctest-DisablePolicyEcmpIpv6-67518367:ctest-vn-18413561?flat'} 2025-08-06 16:06:49,255 - DEBUG - Verifying the default-domain:ctest-DisablePolicyEcmpIpv6-67518367:ctest-vn-18413561 virtual network link through opserver 10.0.0.48 2025-08-06 16:06:49,255 - DEBUG - Requesting: http://10.0.0.48:8081/analytics/uves/virtual-networks 2025-08-06 16:06:49,568 - DEBUG - Requesting: http://10.0.0.48:8081/analytics/uves/virtual-networks 2025-08-06 16:06:49,631 - DEBUG - vn link and name as {'name': 'default-domain:ctest-DisablePolicyEcmpIpv6-67518367:ctest-vn-18413561', 'href': 'http://10.0.0.48:8081/analytics/uves/virtual-network/default-domain:ctest-DisablePolicyEcmpIpv6-67518367:ctest-vn-18413561?flat'} 2025-08-06 16:06:49,631 - INFO - Validated that VN default-domain:ctest-DisablePolicyEcmpIpv6-67518367:ctest-vn-18413561 is found in opserver 2025-08-06 16:06:49,655 - DEBUG - Do not have enough data to verify VN in agent 2025-08-06 16:06:49,671 - DEBUG - VRF ids for VN ctest-vn-18413561: {} 2025-08-06 16:06:49,671 - DEBUG - Hosts: {'nova': ['an-jenkins-deploy-platform-ansible-os-3763-1', 'an-jenkins-deploy-platform-ansible-os-3763-2']} 2025-08-06 16:06:50,892 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-3763-1), Zone: (nova:an-jenkins-deploy-platform-ansible-os-3763-1) 2025-08-06 16:06:50,892 - DEBUG - Hosts: {'nova': ['an-jenkins-deploy-platform-ansible-os-3763-1', 'an-jenkins-deploy-platform-ansible-os-3763-2']} 2025-08-06 16:06:52,290 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-3763-2), Zone: (nova:an-jenkins-deploy-platform-ansible-os-3763-2) 2025-08-06 16:06:53,665 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-3763-2), Zone: (nova:an-jenkins-deploy-platform-ansible-os-3763-2) 2025-08-06 16:06:53,665 - DEBUG - Hosts: {'nova': ['an-jenkins-deploy-platform-ansible-os-3763-1', 'an-jenkins-deploy-platform-ansible-os-3763-2']} 2025-08-06 16:06:55,084 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-3763-1), Zone: (nova:an-jenkins-deploy-platform-ansible-os-3763-1) 2025-08-06 16:06:55,085 - INFO - Waiting for VM ctest-DisablePolicyEcmpIpv6-67518367-71898721 to be up.. 2025-08-06 16:06:55,174 - DEBUG - VM is in ACTIVE state now 2025-08-06 16:06:55,174 - INFO - VM name : ctest-DisablePolicyEcmpIpv6-67518367-71898721 2025-08-06 16:06:55,269 - DEBUG - VM ctest-DisablePolicyEcmpIpv6-67518367-71898721 ID is 819d2d5b-264b-4efa-92d0-1496b169645c 2025-08-06 16:06:55,269 - DEBUG - VM ctest-DisablePolicyEcmpIpv6-67518367-71898721 launched on Node an-jenkins-deploy-platform-ansible-os-3763-2 2025-08-06 16:06:55,361 - DEBUG - Requesting: http://10.0.0.48:8082/virtual-machine/819d2d5b-264b-4efa-92d0-1496b169645c 2025-08-06 16:06:55,686 - DEBUG - Requesting: http://10.0.0.48:8082/virtual-machine/819d2d5b-264b-4efa-92d0-1496b169645c 2025-08-06 16:06:55,783 - DEBUG - Requesting: http://10.0.0.48:8082/virtual-machine-interface/9b44caa1-2305-45e1-aa4c-be7e829d519a 2025-08-06 16:06:59,073 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1001ms') 2025-08-06 16:06:59,073 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-DisablePolicyEcmpIpv6-67518367-71898721 failed! 2025-08-06 16:06:59,088 - DEBUG - Gateway for vn default-domain:ctest-DisablePolicyEcmpIpv6-67518367:ctest-vn-18413561 is 3a1e:2214:f427:dcc:e681:71b:0:1 and allocation pool is NOT set 2025-08-06 16:06:59,088 - DEBUG - Gateway for vn default-domain:ctest-DisablePolicyEcmpIpv6-67518367:ctest-vn-18413561 is 30.66.173.65 and allocation pool is NOT set 2025-08-06 16:07:03,169 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1004ms') 2025-08-06 16:07:03,169 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-DisablePolicyEcmpIpv6-67518367-71898721 failed! 2025-08-06 16:07:03,188 - DEBUG - Gateway for vn default-domain:ctest-DisablePolicyEcmpIpv6-67518367:ctest-vn-18413561 is 3a1e:2214:f427:dcc:e681:71b:0:1 and allocation pool is NOT set 2025-08-06 16:07:03,188 - DEBUG - Gateway for vn default-domain:ctest-DisablePolicyEcmpIpv6-67518367:ctest-vn-18413561 is 30.66.173.65 and allocation pool is NOT set 2025-08-06 16:07:07,294 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1032ms') 2025-08-06 16:07:07,294 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-DisablePolicyEcmpIpv6-67518367-71898721 failed! 2025-08-06 16:07:07,310 - DEBUG - Gateway for vn default-domain:ctest-DisablePolicyEcmpIpv6-67518367:ctest-vn-18413561 is 3a1e:2214:f427:dcc:e681:71b:0:1 and allocation pool is NOT set 2025-08-06 16:07:07,310 - DEBUG - Gateway for vn default-domain:ctest-DisablePolicyEcmpIpv6-67518367:ctest-vn-18413561 is 30.66.173.65 and allocation pool is NOT set 2025-08-06 16:07:11,395 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1004ms') 2025-08-06 16:07:11,395 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-DisablePolicyEcmpIpv6-67518367-71898721 failed! 2025-08-06 16:07:11,412 - DEBUG - Gateway for vn default-domain:ctest-DisablePolicyEcmpIpv6-67518367:ctest-vn-18413561 is 3a1e:2214:f427:dcc:e681:71b:0:1 and allocation pool is NOT set 2025-08-06 16:07:11,412 - DEBUG - Gateway for vn default-domain:ctest-DisablePolicyEcmpIpv6-67518367:ctest-vn-18413561 is 30.66.173.65 and allocation pool is NOT set 2025-08-06 16:07:15,487 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1007ms') 2025-08-06 16:07:15,487 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-DisablePolicyEcmpIpv6-67518367-71898721 failed! 2025-08-06 16:07:15,503 - DEBUG - Gateway for vn default-domain:ctest-DisablePolicyEcmpIpv6-67518367:ctest-vn-18413561 is 3a1e:2214:f427:dcc:e681:71b:0:1 and allocation pool is NOT set 2025-08-06 16:07:15,503 - DEBUG - Gateway for vn default-domain:ctest-DisablePolicyEcmpIpv6-67518367:ctest-vn-18413561 is 30.66.173.65 and allocation pool is NOT set 2025-08-06 16:07:19,617 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1032ms') 2025-08-06 16:07:19,617 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-DisablePolicyEcmpIpv6-67518367-71898721 failed! 2025-08-06 16:07:19,633 - DEBUG - Gateway for vn default-domain:ctest-DisablePolicyEcmpIpv6-67518367:ctest-vn-18413561 is 3a1e:2214:f427:dcc:e681:71b:0:1 and allocation pool is NOT set 2025-08-06 16:07:19,633 - DEBUG - Gateway for vn default-domain:ctest-DisablePolicyEcmpIpv6-67518367:ctest-vn-18413561 is 30.66.173.65 and allocation pool is NOT set 2025-08-06 16:07:23,708 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1014ms') 2025-08-06 16:07:23,708 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-DisablePolicyEcmpIpv6-67518367-71898721 failed! 2025-08-06 16:07:23,722 - DEBUG - Gateway for vn default-domain:ctest-DisablePolicyEcmpIpv6-67518367:ctest-vn-18413561 is 3a1e:2214:f427:dcc:e681:71b:0:1 and allocation pool is NOT set 2025-08-06 16:07:23,722 - DEBUG - Gateway for vn default-domain:ctest-DisablePolicyEcmpIpv6-67518367:ctest-vn-18413561 is 30.66.173.65 and allocation pool is NOT set 2025-08-06 16:07:27,809 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1021ms') 2025-08-06 16:07:27,809 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-DisablePolicyEcmpIpv6-67518367-71898721 failed! 2025-08-06 16:07:27,823 - DEBUG - Gateway for vn default-domain:ctest-DisablePolicyEcmpIpv6-67518367:ctest-vn-18413561 is 3a1e:2214:f427:dcc:e681:71b:0:1 and allocation pool is NOT set 2025-08-06 16:07:27,824 - DEBUG - Gateway for vn default-domain:ctest-DisablePolicyEcmpIpv6-67518367:ctest-vn-18413561 is 30.66.173.65 and allocation pool is NOT set 2025-08-06 16:07:31,903 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1013ms') 2025-08-06 16:07:31,903 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-DisablePolicyEcmpIpv6-67518367-71898721 failed! 2025-08-06 16:07:31,918 - DEBUG - Gateway for vn default-domain:ctest-DisablePolicyEcmpIpv6-67518367:ctest-vn-18413561 is 3a1e:2214:f427:dcc:e681:71b:0:1 and allocation pool is NOT set 2025-08-06 16:07:31,918 - DEBUG - Gateway for vn default-domain:ctest-DisablePolicyEcmpIpv6-67518367:ctest-vn-18413561 is 30.66.173.65 and allocation pool is NOT set 2025-08-06 16:07:36,002 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1018ms') 2025-08-06 16:07:36,002 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-DisablePolicyEcmpIpv6-67518367-71898721 failed! 2025-08-06 16:07:36,018 - DEBUG - Gateway for vn default-domain:ctest-DisablePolicyEcmpIpv6-67518367:ctest-vn-18413561 is 3a1e:2214:f427:dcc:e681:71b:0:1 and allocation pool is NOT set 2025-08-06 16:07:36,018 - DEBUG - Gateway for vn default-domain:ctest-DisablePolicyEcmpIpv6-67518367:ctest-vn-18413561 is 30.66.173.65 and allocation pool is NOT set 2025-08-06 16:07:40,094 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1009ms') 2025-08-06 16:07:40,094 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-DisablePolicyEcmpIpv6-67518367-71898721 failed! 2025-08-06 16:07:40,109 - DEBUG - Gateway for vn default-domain:ctest-DisablePolicyEcmpIpv6-67518367:ctest-vn-18413561 is 3a1e:2214:f427:dcc:e681:71b:0:1 and allocation pool is NOT set 2025-08-06 16:07:40,110 - DEBUG - Gateway for vn default-domain:ctest-DisablePolicyEcmpIpv6-67518367:ctest-vn-18413561 is 30.66.173.65 and allocation pool is NOT set 2025-08-06 16:07:44,194 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1018ms') 2025-08-06 16:07:44,194 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-DisablePolicyEcmpIpv6-67518367-71898721 failed! 2025-08-06 16:07:44,211 - DEBUG - Gateway for vn default-domain:ctest-DisablePolicyEcmpIpv6-67518367:ctest-vn-18413561 is 3a1e:2214:f427:dcc:e681:71b:0:1 and allocation pool is NOT set 2025-08-06 16:07:44,211 - DEBUG - Gateway for vn default-domain:ctest-DisablePolicyEcmpIpv6-67518367:ctest-vn-18413561 is 30.66.173.65 and allocation pool is NOT set 2025-08-06 16:07:48,289 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1012ms') 2025-08-06 16:07:48,289 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-DisablePolicyEcmpIpv6-67518367-71898721 failed! 2025-08-06 16:07:48,304 - DEBUG - Gateway for vn default-domain:ctest-DisablePolicyEcmpIpv6-67518367:ctest-vn-18413561 is 3a1e:2214:f427:dcc:e681:71b:0:1 and allocation pool is NOT set 2025-08-06 16:07:48,304 - DEBUG - Gateway for vn default-domain:ctest-DisablePolicyEcmpIpv6-67518367:ctest-vn-18413561 is 30.66.173.65 and allocation pool is NOT set 2025-08-06 16:07:52,387 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1016ms') 2025-08-06 16:07:52,387 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-DisablePolicyEcmpIpv6-67518367-71898721 failed! 2025-08-06 16:07:52,401 - DEBUG - Gateway for vn default-domain:ctest-DisablePolicyEcmpIpv6-67518367:ctest-vn-18413561 is 3a1e:2214:f427:dcc:e681:71b:0:1 and allocation pool is NOT set 2025-08-06 16:07:52,401 - DEBUG - Gateway for vn default-domain:ctest-DisablePolicyEcmpIpv6-67518367:ctest-vn-18413561 is 30.66.173.65 and allocation pool is NOT set 2025-08-06 16:07:56,481 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1014ms') 2025-08-06 16:07:56,481 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-DisablePolicyEcmpIpv6-67518367-71898721 failed! 2025-08-06 16:07:56,502 - DEBUG - Gateway for vn default-domain:ctest-DisablePolicyEcmpIpv6-67518367:ctest-vn-18413561 is 3a1e:2214:f427:dcc:e681:71b:0:1 and allocation pool is NOT set 2025-08-06 16:07:56,502 - DEBUG - Gateway for vn default-domain:ctest-DisablePolicyEcmpIpv6-67518367:ctest-vn-18413561 is 30.66.173.65 and allocation pool is NOT set 2025-08-06 16:08:00,573 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1010ms') 2025-08-06 16:08:00,573 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-DisablePolicyEcmpIpv6-67518367-71898721 failed! 2025-08-06 16:08:00,587 - DEBUG - Gateway for vn default-domain:ctest-DisablePolicyEcmpIpv6-67518367:ctest-vn-18413561 is 3a1e:2214:f427:dcc:e681:71b:0:1 and allocation pool is NOT set 2025-08-06 16:08:00,587 - DEBUG - Gateway for vn default-domain:ctest-DisablePolicyEcmpIpv6-67518367:ctest-vn-18413561 is 30.66.173.65 and allocation pool is NOT set 2025-08-06 16:08:04,672 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1023ms') 2025-08-06 16:08:04,672 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-DisablePolicyEcmpIpv6-67518367-71898721 failed! 2025-08-06 16:08:04,689 - DEBUG - Gateway for vn default-domain:ctest-DisablePolicyEcmpIpv6-67518367:ctest-vn-18413561 is 3a1e:2214:f427:dcc:e681:71b:0:1 and allocation pool is NOT set 2025-08-06 16:08:04,689 - DEBUG - Gateway for vn default-domain:ctest-DisablePolicyEcmpIpv6-67518367:ctest-vn-18413561 is 30.66.173.65 and allocation pool is NOT set 2025-08-06 16:08:06,758 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n64 bytes from 169.254.0.3: icmp_seq=1 ttl=63 time=7.08 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=0.754 ms\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1001ms\r\nrtt min/avg/max/mdev = 0.754/3.916/7.078/3.162 ms') 2025-08-06 16:08:06,758 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-DisablePolicyEcmpIpv6-67518367-71898721 passed 2025-08-06 16:08:06,883 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-06 16:08:06,883 - DEBUG - Waiting to SSH to VM ctest-DisablePolicyEcmpIpv6-67518367-71898721, IP 3a1e:2214:f427:dcc:e681:71b:0:4, Port 22 2025-08-06 16:08:06,949 - DEBUG - Error on ssh to ubuntu@169.254.0.3:22, result: /bin/bash: connect: Connection refused /bin/bash: line 1: /dev/tcp/169.254.0.3/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.3/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.3/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''} 2025-08-06 16:08:07,055 - DEBUG - VM ctest-DisablePolicyEcmpIpv6-67518367-71898721 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-06 16:08:12,056 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-06 16:08:12,056 - DEBUG - Waiting to SSH to VM ctest-DisablePolicyEcmpIpv6-67518367-71898721, IP 3a1e:2214:f427:dcc:e681:71b:0:4, Port 22 2025-08-06 16:08:12,136 - DEBUG - Error on ssh to ubuntu@169.254.0.3:22, result: /bin/bash: connect: Connection refused /bin/bash: line 1: /dev/tcp/169.254.0.3/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.3/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.3/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''} 2025-08-06 16:08:12,224 - DEBUG - VM ctest-DisablePolicyEcmpIpv6-67518367-71898721 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-06 16:08:17,226 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-06 16:08:17,226 - DEBUG - Waiting to SSH to VM ctest-DisablePolicyEcmpIpv6-67518367-71898721, IP 3a1e:2214:f427:dcc:e681:71b:0:4, Port 22 2025-08-06 16:08:17,298 - DEBUG - Error on ssh to ubuntu@169.254.0.3:22, result: /bin/bash: connect: Connection refused /bin/bash: line 1: /dev/tcp/169.254.0.3/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.3/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.3/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''} 2025-08-06 16:08:17,379 - DEBUG - VM ctest-DisablePolicyEcmpIpv6-67518367-71898721 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-06 16:08:22,379 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-06 16:08:22,380 - DEBUG - Waiting to SSH to VM ctest-DisablePolicyEcmpIpv6-67518367-71898721, IP 3a1e:2214:f427:dcc:e681:71b:0:4, Port 22 2025-08-06 16:08:22,456 - DEBUG - Error on ssh to ubuntu@169.254.0.3:22, result: /bin/bash: connect: Connection refused /bin/bash: line 1: /dev/tcp/169.254.0.3/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.3/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.3/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''} 2025-08-06 16:08:22,537 - DEBUG - VM ctest-DisablePolicyEcmpIpv6-67518367-71898721 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-06 16:08:27,538 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-06 16:08:27,538 - DEBUG - Waiting to SSH to VM ctest-DisablePolicyEcmpIpv6-67518367-71898721, IP 3a1e:2214:f427:dcc:e681:71b:0:4, Port 22 2025-08-06 16:08:27,606 - DEBUG - Error on ssh to ubuntu@169.254.0.3:22, result: /bin/bash: connect: Connection refused /bin/bash: line 1: /dev/tcp/169.254.0.3/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.3/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.3/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''} 2025-08-06 16:08:27,692 - DEBUG - VM ctest-DisablePolicyEcmpIpv6-67518367-71898721 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-06 16:08:32,692 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-06 16:08:32,692 - DEBUG - Waiting to SSH to VM ctest-DisablePolicyEcmpIpv6-67518367-71898721, IP 3a1e:2214:f427:dcc:e681:71b:0:4, Port 22 2025-08-06 16:08:32,761 - DEBUG - Error on ssh to ubuntu@169.254.0.3:22, result: /bin/bash: connect: Connection refused /bin/bash: line 1: /dev/tcp/169.254.0.3/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.3/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.3/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''} 2025-08-06 16:08:32,852 - DEBUG - VM ctest-DisablePolicyEcmpIpv6-67518367-71898721 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-06 16:08:37,853 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-06 16:08:37,853 - DEBUG - Waiting to SSH to VM ctest-DisablePolicyEcmpIpv6-67518367-71898721, IP 3a1e:2214:f427:dcc:e681:71b:0:4, Port 22 2025-08-06 16:08:37,922 - DEBUG - Error on ssh to ubuntu@169.254.0.3:22, result: /bin/bash: connect: Connection refused /bin/bash: line 1: /dev/tcp/169.254.0.3/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.3/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.3/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''} 2025-08-06 16:08:38,002 - DEBUG - VM ctest-DisablePolicyEcmpIpv6-67518367-71898721 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-06 16:08:43,003 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-06 16:08:43,003 - DEBUG - Waiting to SSH to VM ctest-DisablePolicyEcmpIpv6-67518367-71898721, IP 3a1e:2214:f427:dcc:e681:71b:0:4, Port 22 2025-08-06 16:08:43,070 - DEBUG - Error on ssh to ubuntu@169.254.0.3:22, result: /bin/bash: connect: Connection refused /bin/bash: line 1: /dev/tcp/169.254.0.3/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.3/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.3/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''} 2025-08-06 16:08:43,172 - DEBUG - VM ctest-DisablePolicyEcmpIpv6-67518367-71898721 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-06 16:08:48,173 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-06 16:08:48,173 - DEBUG - Waiting to SSH to VM ctest-DisablePolicyEcmpIpv6-67518367-71898721, IP 3a1e:2214:f427:dcc:e681:71b:0:4, Port 22 2025-08-06 16:08:48,345 - DEBUG - VM ctest-DisablePolicyEcmpIpv6-67518367-71898721 is ready for SSH connections 2025-08-06 16:08:48,346 - INFO - Waiting for VM ctest-DisablePolicyEcmpIpv6-67518367-57186457 to be up.. 2025-08-06 16:08:48,438 - DEBUG - VM is in ACTIVE state now 2025-08-06 16:08:48,438 - INFO - VM name : ctest-DisablePolicyEcmpIpv6-67518367-57186457 2025-08-06 16:08:48,521 - DEBUG - VM ctest-DisablePolicyEcmpIpv6-67518367-57186457 ID is 95fa44ac-120a-4720-9729-62e400b53751 2025-08-06 16:08:48,521 - DEBUG - VM ctest-DisablePolicyEcmpIpv6-67518367-57186457 launched on Node an-jenkins-deploy-platform-ansible-os-3763-2 2025-08-06 16:08:48,605 - DEBUG - Requesting: http://10.0.0.48:8082/virtual-machine/95fa44ac-120a-4720-9729-62e400b53751 2025-08-06 16:08:48,618 - DEBUG - Requesting: http://10.0.0.48:8082/virtual-machine-interface/950357cd-8c5a-4305-9971-5805bc0a35fc 2025-08-06 16:08:49,845 - DEBUG - (True, 'PING 169.254.0.4 (169.254.0.4) 56(84) bytes of data.\r\n64 bytes from 169.254.0.4: icmp_seq=1 ttl=63 time=2.60 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=3.68 ms\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1002ms\r\nrtt min/avg/max/mdev = 2.598/3.139/3.680/0.541 ms') 2025-08-06 16:08:49,845 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-DisablePolicyEcmpIpv6-67518367-57186457 passed 2025-08-06 16:08:49,960 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-06 16:08:49,961 - DEBUG - Waiting to SSH to VM ctest-DisablePolicyEcmpIpv6-67518367-57186457, IP 3a1e:2214:f427:dcc:e681:71b:0:5, Port 22 2025-08-06 16:08:50,146 - DEBUG - VM ctest-DisablePolicyEcmpIpv6-67518367-57186457 is ready for SSH connections 2025-08-06 16:08:50,146 - INFO - Waiting for VM ctest-DisablePolicyEcmpIpv6-67518367-25554796 to be up.. 2025-08-06 16:08:50,257 - DEBUG - VM is in ACTIVE state now 2025-08-06 16:08:50,257 - INFO - VM name : ctest-DisablePolicyEcmpIpv6-67518367-25554796 2025-08-06 16:08:50,336 - DEBUG - VM ctest-DisablePolicyEcmpIpv6-67518367-25554796 ID is 701100cc-1714-490d-8c09-aff44a552f3d 2025-08-06 16:08:50,336 - DEBUG - VM ctest-DisablePolicyEcmpIpv6-67518367-25554796 launched on Node an-jenkins-deploy-platform-ansible-os-3763-1 2025-08-06 16:08:50,421 - DEBUG - Requesting: http://10.0.0.48:8082/virtual-machine/701100cc-1714-490d-8c09-aff44a552f3d 2025-08-06 16:08:50,434 - DEBUG - Requesting: http://10.0.0.48:8082/virtual-machine-interface/3b2ac57b-13a1-47e2-bceb-f001c30cdbfd 2025-08-06 16:08:51,650 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n64 bytes from 169.254.0.3: icmp_seq=1 ttl=63 time=5.11 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=0.428 ms\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1001ms\r\nrtt min/avg/max/mdev = 0.428/2.768/5.108/2.340 ms') 2025-08-06 16:08:51,651 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-DisablePolicyEcmpIpv6-67518367-25554796 passed 2025-08-06 16:08:51,764 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-06 16:08:51,764 - DEBUG - Waiting to SSH to VM ctest-DisablePolicyEcmpIpv6-67518367-25554796, IP 3a1e:2214:f427:dcc:e681:71b:0:3, Port 22 2025-08-06 16:08:51,933 - DEBUG - VM ctest-DisablePolicyEcmpIpv6-67518367-25554796 is ready for SSH connections 2025-08-06 16:08:51,933 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-06 16:08:51,933 - DEBUG - Running remote_cmd, Cmd : ifconfig -a| grep 3a1e:2214:f427:dcc:e681:71b:0:4 -A2 -B4| grep -i 'hwaddr\|flags' | awk '{print $1}' | cut -d ':' -f 1, host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.57, gateway password: c0ntrail123 2025-08-06 16:08:51,933 - DEBUG - ifconfig -a| grep 3a1e:2214:f427:dcc:e681:71b:0:4 -A2 -B4| grep -i 'hwaddr\|flags' | awk '{print $1}' | cut -d ':' -f 1 2025-08-06 16:09:14,181 - DEBUG - eth0 2025-08-06 16:09:14,182 - DEBUG - Running remote_cmd, Cmd : sysctl net.ipv6.conf.eth0.accept_dad=0, host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.57, gateway password: c0ntrail123 2025-08-06 16:09:14,182 - DEBUG - sysctl net.ipv6.conf.eth0.accept_dad=0 2025-08-06 16:09:14,732 - DEBUG - net.ipv6.conf.eth0.accept_dad = 0 2025-08-06 16:09:14,986 - INFO - Created InterfaceRouteTable ['default-domain', 'ctest-DisablePolicyEcmpIpv6-67518367', 'ctest-intf-rtb-24144304'](UUID 0073a843-ce7e-4cd7-81ef-69b7e85ae088), prefixes : ['3576:4b9b:966f:7e96:26a3:c1c0::/96'] 2025-08-06 16:09:15,054 - INFO - Added intf route table 0073a843-ce7e-4cd7-81ef-69b7e85ae088 to port 9b44caa1-2305-45e1-aa4c-be7e829d519a 2025-08-06 16:09:15,054 - DEBUG - Running remote_cmd, Cmd : ifconfig -a| grep -i 'hwaddr\|flags' | awk '{print $1}' | cut -d ':' -f 1, host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.57, gateway password: c0ntrail123 2025-08-06 16:09:15,055 - DEBUG - ifconfig -a| grep -i 'hwaddr\|flags' | awk '{print $1}' | cut -d ':' -f 1 2025-08-06 16:09:15,546 - DEBUG - eth0 2025-08-06 16:09:15,546 - DEBUG - Running remote_cmd, Cmd : ifconfig eth0 inet6 add 3576:4b9b:966f:7e96:26a3:c1c0:1277:b78e, host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.57, gateway password: c0ntrail123 2025-08-06 16:09:15,546 - DEBUG - ifconfig eth0 inet6 add 3576:4b9b:966f:7e96:26a3:c1c0:1277:b78e 2025-08-06 16:09:16,107 - DEBUG - None 2025-08-06 16:09:16,107 - DEBUG - Running remote_cmd, Cmd : ifconfig -a, host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.57, gateway password: c0ntrail123 2025-08-06 16:09:16,107 - DEBUG - ifconfig -a 2025-08-06 16:09:16,686 - DEBUG - eth0 Link encap:Ethernet HWaddr 02:9b:44:ca:a1:23 inet addr:30.66.173.68 Bcast:30.66.173.127 Mask:255.255.255.192 inet6 addr: 3a1e:2214:f427:dcc:e681:71b:0:4/64 Scope:Global inet6 addr: 3576:4b9b:966f:7e96:26a3:c1c0:1277:b78e/128 Scope:Global inet6 addr: fe80::9b:44ff:feca:a123/64 Scope:Link UP BROADCAST RUNNING MULTICAST MTU:1500 Metric:1 RX packets:496 errors:0 dropped:0 overruns:0 frame:0 TX packets:376 errors:0 dropped:0 overruns:0 carrier:0 collisions:0 txqueuelen:1000 RX bytes:47655 (47.6 KB) TX bytes:34860 (34.8 KB) lo Link encap:Local Loopback inet addr:127.0.0.1 Mask:255.0.0.0 inet6 addr: ::1/128 Scope:Host UP LOOPBACK RUNNING MTU:16436 Metric:1 RX packets:0 errors:0 dropped:0 overruns:0 frame:0 TX packets:0 errors:0 dropped:0 overruns:0 carrier:0 collisions:0 txqueuelen:0 RX bytes:0 (0.0 B) TX bytes:0 (0.0 B) 2025-08-06 16:09:16,686 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-06 16:09:16,686 - DEBUG - Running remote_cmd, Cmd : ifconfig -a| grep 3a1e:2214:f427:dcc:e681:71b:0:5 -A2 -B4| grep -i 'hwaddr\|flags' | awk '{print $1}' | cut -d ':' -f 1, host_string: ubuntu@169.254.0.4, password: ubuntugateway: ubuntu@10.0.0.57, gateway password: c0ntrail123 2025-08-06 16:09:16,686 - DEBUG - ifconfig -a| grep 3a1e:2214:f427:dcc:e681:71b:0:5 -A2 -B4| grep -i 'hwaddr\|flags' | awk '{print $1}' | cut -d ':' -f 1 2025-08-06 16:09:59,800 - DEBUG - eth0 2025-08-06 16:09:59,801 - DEBUG - Running remote_cmd, Cmd : sysctl net.ipv6.conf.eth0.accept_dad=0, host_string: ubuntu@169.254.0.4, password: ubuntugateway: ubuntu@10.0.0.57, gateway password: c0ntrail123 2025-08-06 16:09:59,801 - DEBUG - sysctl net.ipv6.conf.eth0.accept_dad=0 2025-08-06 16:10:00,397 - DEBUG - net.ipv6.conf.eth0.accept_dad = 0 2025-08-06 16:10:00,610 - INFO - Created InterfaceRouteTable ['default-domain', 'ctest-DisablePolicyEcmpIpv6-67518367', 'ctest-intf-rtb-53257381'](UUID 6f1fb82a-25d4-47c7-81c2-77fdece15609), prefixes : ['3576:4b9b:966f:7e96:26a3:c1c0::/96'] 2025-08-06 16:10:00,678 - INFO - Added intf route table 6f1fb82a-25d4-47c7-81c2-77fdece15609 to port 950357cd-8c5a-4305-9971-5805bc0a35fc 2025-08-06 16:10:00,678 - DEBUG - Running remote_cmd, Cmd : ifconfig -a| grep -i 'hwaddr\|flags' | awk '{print $1}' | cut -d ':' -f 1, host_string: ubuntu@169.254.0.4, password: ubuntugateway: ubuntu@10.0.0.57, gateway password: c0ntrail123 2025-08-06 16:10:00,678 - DEBUG - ifconfig -a| grep -i 'hwaddr\|flags' | awk '{print $1}' | cut -d ':' -f 1 2025-08-06 16:10:01,214 - DEBUG - eth0 2025-08-06 16:10:01,214 - DEBUG - Running remote_cmd, Cmd : ifconfig eth0 inet6 add 3576:4b9b:966f:7e96:26a3:c1c0:1277:b78e, host_string: ubuntu@169.254.0.4, password: ubuntugateway: ubuntu@10.0.0.57, gateway password: c0ntrail123 2025-08-06 16:10:01,214 - DEBUG - ifconfig eth0 inet6 add 3576:4b9b:966f:7e96:26a3:c1c0:1277:b78e 2025-08-06 16:10:01,812 - DEBUG - None 2025-08-06 16:10:01,813 - DEBUG - Running remote_cmd, Cmd : ifconfig -a, host_string: ubuntu@169.254.0.4, password: ubuntugateway: ubuntu@10.0.0.57, gateway password: c0ntrail123 2025-08-06 16:10:01,813 - DEBUG - ifconfig -a 2025-08-06 16:10:02,432 - DEBUG - eth0 Link encap:Ethernet HWaddr 02:95:03:57:cd:8c inet addr:30.66.173.69 Bcast:30.66.173.127 Mask:255.255.255.192 inet6 addr: 3a1e:2214:f427:dcc:e681:71b:0:5/64 Scope:Global inet6 addr: 3576:4b9b:966f:7e96:26a3:c1c0:1277:b78e/128 Scope:Global inet6 addr: fe80::95:3ff:fe57:cd8c/64 Scope:Link UP BROADCAST RUNNING MULTICAST MTU:1500 Metric:1 RX packets:493 errors:0 dropped:0 overruns:0 frame:0 TX packets:429 errors:0 dropped:0 overruns:0 carrier:0 collisions:0 txqueuelen:1000 RX bytes:46709 (46.7 KB) TX bytes:38664 (38.6 KB) lo Link encap:Local Loopback inet addr:127.0.0.1 Mask:255.0.0.0 inet6 addr: ::1/128 Scope:Host UP LOOPBACK RUNNING MTU:16436 Metric:1 RX packets:0 errors:0 dropped:0 overruns:0 frame:0 TX packets:0 errors:0 dropped:0 overruns:0 carrier:0 collisions:0 txqueuelen:0 RX bytes:0 (0.0 B) TX bytes:0 (0.0 B) 2025-08-06 16:10:02,502 - INFO - Policy DISABLED on VMI 3b2ac57b-13a1-47e2-bceb-f001c30cdbfd 2025-08-06 16:10:02,582 - INFO - Policy DISABLED on VMI 9b44caa1-2305-45e1-aa4c-be7e829d519a 2025-08-06 16:10:02,650 - INFO - Policy DISABLED on VMI 950357cd-8c5a-4305-9971-5805bc0a35fc 2025-08-06 16:10:02,677 - INFO - ECMP routes found in agent 10.0.0.57, for prefix 3576:4b9b:966f:7e96:26a3:c1c0::/96 2025-08-06 16:10:02,677 - INFO - Tap interface tap9b44caa1-23 found in ecmp routes in agent 10.0.0.57 2025-08-06 16:10:02,677 - INFO - Tap interface tap950357cd-8c found in ecmp routes in agent 10.0.0.57 2025-08-06 16:10:02,696 - INFO - ECMP routes found in agent 10.0.0.57, for prefix 3576:4b9b:966f:7e96:26a3:c1c0::/96 2025-08-06 16:10:02,787 - DEBUG - Executing command: sudo tcpdump -nni tap9b44caa1-23 -U '(udp and src host 3a1e:2214:f427:dcc:e681:71b:0:3 and dst host 3576:4b9b:966f:7e96:26a3:c1c0:1277:b78e and dst port 11000)' -w /tmp/tap9b44caa1-23_ctest-random-88104739.pcap 2025-08-06 16:10:02,972 - DEBUG - Executing command: sudo tcpdump -nni tap950357cd-8c -U '(udp and src host 3a1e:2214:f427:dcc:e681:71b:0:3 and dst host 3576:4b9b:966f:7e96:26a3:c1c0:1277:b78e and dst port 11000)' -w /tmp/tap950357cd-8c_ctest-random-00078083.pcap 2025-08-06 16:10:03,080 - DEBUG - Running remote_cmd, Cmd : dd bs=100 count=1 if=/dev/zero of=icmp_error;nc -6 -q 2 -u -p 52158 3576:4b9b:966f:7e96:26a3:c1c0:1277:b78e 11000 < icmp_error, host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.49, gateway password: c0ntrail123 2025-08-06 16:10:03,080 - DEBUG - dd bs=100 count=1 if=/dev/zero of=icmp_error;nc -6 -q 2 -u -p 52158 3576:4b9b:966f:7e96:26a3:c1c0:1277:b78e 11000 < icmp_error 2025-08-06 16:10:46,037 - DEBUG - 1+0 records in 1+0 records out 100 bytes (100 B) copied, 0.00142304 s, 70.3 kB/s 2025-08-06 16:10:46,038 - DEBUG - Executing command: sudo tcpdump -nnr /tmp/tap9b44caa1-23_ctest-random-88104739.pcap | grep -c length 2025-08-06 16:10:46,058 - DEBUG - STDOUT: 1 2025-08-06 16:10:46,059 - DEBUG - STDERR: reading from file /tmp/tap9b44caa1-23_ctest-random-88104739.pcap, link-type EN10MB (Ethernet), snapshot length 262144 2025-08-06 16:10:46,059 - INFO - 1 packets are found in tcpdump output as expected 2025-08-06 16:10:46,059 - DEBUG - Executing command: sudo kill $(ps -ef|grep tcpdump | grep pcap| awk '{print $2}') 2025-08-06 16:10:48,102 - INFO - Tcpdump verification on VM 3a1e:2214:f427:dcc:e681:71b:0:4 passed 2025-08-06 16:10:48,475 - DEBUG - Forward and reverse flows for match {'sip': '3a1e:2214:f427:dcc:e681:71b:0:3', 'dip': '3576:4b9b:966f:7e96:26a3:c1c0:1277:b78e', 'sport': '52158', 'dport': '11000', 'proto': '17', 'vrf_id': '2'}: 0, 0 2025-08-06 16:10:48,477 - DEBUG - Flow verification PASSED on node: 10.0.0.57 for VMs - Sender: 3a1e:2214:f427:dcc:e681:71b:0:3, Receiver: 3576:4b9b:966f:7e96:26a3:c1c0:1277:b78e, Flow count expected: 0 0, got: 0 0 2025-08-06 16:10:48,477 - DEBUG - Executing command: sudo kill $(ps -ef|grep tcpdump | grep pcap| awk '{print $2}') 2025-08-06 16:10:50,489 - DEBUG - Executing command: sudo kill $(ps -ef|grep tcpdump | grep pcap| awk '{print $2}') 2025-08-06 16:10:52,900 - DEBUG - Forward and reverse flows for match {'sip': '3a1e:2214:f427:dcc:e681:71b:0:3', 'dip': '3576:4b9b:966f:7e96:26a3:c1c0:1277:b78e', 'sport': '52158', 'dport': '11000', 'proto': '17', 'vrf_id': '2'}: 0, 0 2025-08-06 16:10:52,901 - DEBUG - Flow verification PASSED on node: 10.0.0.49 for VMs - Sender: 3a1e:2214:f427:dcc:e681:71b:0:3, Receiver: 3576:4b9b:966f:7e96:26a3:c1c0:1277:b78e, Flow count expected: 0 0, got: 0 0 2025-08-06 16:10:52,901 - INFO - Traffic verification for ECMP passed 2025-08-06 16:10:52,901 - INFO - Waiting for VM ctest-DisablePolicyEcmpIpv6-67518367-33464430 to be up.. 2025-08-06 16:10:52,999 - DEBUG - VM is in ACTIVE state now 2025-08-06 16:10:52,999 - INFO - VM name : ctest-DisablePolicyEcmpIpv6-67518367-33464430 2025-08-06 16:10:53,080 - DEBUG - VM ctest-DisablePolicyEcmpIpv6-67518367-33464430 ID is d081af0d-c20e-4f12-8fb9-7f0491b449d2 2025-08-06 16:10:53,080 - DEBUG - VM ctest-DisablePolicyEcmpIpv6-67518367-33464430 launched on Node an-jenkins-deploy-platform-ansible-os-3763-1 2025-08-06 16:10:53,161 - DEBUG - Requesting: http://10.0.0.48:8082/virtual-machine/d081af0d-c20e-4f12-8fb9-7f0491b449d2 2025-08-06 16:10:53,172 - DEBUG - Requesting: http://10.0.0.48:8082/virtual-machine-interface/17de7b5e-5e0f-46a2-b450-6f34af58132d 2025-08-06 16:10:54,377 - DEBUG - (True, 'PING 169.254.0.4 (169.254.0.4) 56(84) bytes of data.\r\n64 bytes from 169.254.0.4: icmp_seq=1 ttl=63 time=3.16 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=0.533 ms\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1001ms\r\nrtt min/avg/max/mdev = 0.533/1.844/3.155/1.311 ms') 2025-08-06 16:10:54,378 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-DisablePolicyEcmpIpv6-67518367-33464430 passed 2025-08-06 16:10:54,492 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-06 16:10:54,493 - DEBUG - Waiting to SSH to VM ctest-DisablePolicyEcmpIpv6-67518367-33464430, IP 3a1e:2214:f427:dcc:e681:71b:0:6, Port 22 2025-08-06 16:10:54,661 - DEBUG - VM ctest-DisablePolicyEcmpIpv6-67518367-33464430 is ready for SSH connections 2025-08-06 16:10:54,730 - INFO - Policy DISABLED on VMI 17de7b5e-5e0f-46a2-b450-6f34af58132d 2025-08-06 16:10:54,730 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-06 16:10:54,730 - DEBUG - Running remote_cmd, Cmd : ifconfig -a| grep 3a1e:2214:f427:dcc:e681:71b:0:6 -A2 -B4| grep -i 'hwaddr\|flags' | awk '{print $1}' | cut -d ':' -f 1, host_string: ubuntu@169.254.0.4, password: ubuntugateway: ubuntu@10.0.0.49, gateway password: c0ntrail123 2025-08-06 16:10:54,730 - DEBUG - ifconfig -a| grep 3a1e:2214:f427:dcc:e681:71b:0:6 -A2 -B4| grep -i 'hwaddr\|flags' | awk '{print $1}' | cut -d ':' -f 1 2025-08-06 16:11:38,525 - DEBUG - eth0 2025-08-06 16:11:38,525 - DEBUG - Running remote_cmd, Cmd : sysctl net.ipv6.conf.eth0.accept_dad=0, host_string: ubuntu@169.254.0.4, password: ubuntugateway: ubuntu@10.0.0.49, gateway password: c0ntrail123 2025-08-06 16:11:38,525 - DEBUG - sysctl net.ipv6.conf.eth0.accept_dad=0 2025-08-06 16:11:39,135 - DEBUG - net.ipv6.conf.eth0.accept_dad = 0 2025-08-06 16:11:39,402 - INFO - Created InterfaceRouteTable ['default-domain', 'ctest-DisablePolicyEcmpIpv6-67518367', 'ctest-intf-rtb-04192970'](UUID d780a6e5-03bf-4d1f-85f4-f91e617682f2), prefixes : ['3576:4b9b:966f:7e96:26a3:c1c0::/96'] 2025-08-06 16:11:39,474 - INFO - Added intf route table d780a6e5-03bf-4d1f-85f4-f91e617682f2 to port 17de7b5e-5e0f-46a2-b450-6f34af58132d 2025-08-06 16:11:39,475 - DEBUG - Running remote_cmd, Cmd : ifconfig -a| grep -i 'hwaddr\|flags' | awk '{print $1}' | cut -d ':' -f 1, host_string: ubuntu@169.254.0.4, password: ubuntugateway: ubuntu@10.0.0.49, gateway password: c0ntrail123 2025-08-06 16:11:39,475 - DEBUG - ifconfig -a| grep -i 'hwaddr\|flags' | awk '{print $1}' | cut -d ':' -f 1 2025-08-06 16:11:39,942 - DEBUG - eth0 2025-08-06 16:11:39,942 - DEBUG - Running remote_cmd, Cmd : ifconfig eth0 inet6 add 3576:4b9b:966f:7e96:26a3:c1c0:1277:b78e, host_string: ubuntu@169.254.0.4, password: ubuntugateway: ubuntu@10.0.0.49, gateway password: c0ntrail123 2025-08-06 16:11:39,942 - DEBUG - ifconfig eth0 inet6 add 3576:4b9b:966f:7e96:26a3:c1c0:1277:b78e 2025-08-06 16:11:40,509 - DEBUG - None 2025-08-06 16:11:40,509 - DEBUG - Running remote_cmd, Cmd : ifconfig -a, host_string: ubuntu@169.254.0.4, password: ubuntugateway: ubuntu@10.0.0.49, gateway password: c0ntrail123 2025-08-06 16:11:40,509 - DEBUG - ifconfig -a 2025-08-06 16:11:41,066 - DEBUG - eth0 Link encap:Ethernet HWaddr 02:17:de:7b:5e:5e inet addr:30.66.173.70 Bcast:30.66.173.127 Mask:255.255.255.192 inet6 addr: 3576:4b9b:966f:7e96:26a3:c1c0:1277:b78e/128 Scope:Global inet6 addr: fe80::17:deff:fe7b:5e5e/64 Scope:Link inet6 addr: 3a1e:2214:f427:dcc:e681:71b:0:6/64 Scope:Global UP BROADCAST RUNNING MULTICAST MTU:1500 Metric:1 RX packets:594 errors:0 dropped:0 overruns:0 frame:0 TX packets:526 errors:0 dropped:0 overruns:0 carrier:0 collisions:0 txqueuelen:1000 RX bytes:52435 (52.4 KB) TX bytes:44466 (44.4 KB) lo Link encap:Local Loopback inet addr:127.0.0.1 Mask:255.0.0.0 inet6 addr: ::1/128 Scope:Host UP LOOPBACK RUNNING MTU:16436 Metric:1 RX packets:0 errors:0 dropped:0 overruns:0 frame:0 TX packets:0 errors:0 dropped:0 overruns:0 carrier:0 collisions:0 txqueuelen:0 RX bytes:0 (0.0 B) TX bytes:0 (0.0 B) 2025-08-06 16:11:41,066 - INFO - Deleting VM ctest-DisablePolicyEcmpIpv6-67518367-71898721 2025-08-06 16:11:41,206 - INFO - Removed intf route table 0073a843-ce7e-4cd7-81ef-69b7e85ae088 from port 9b44caa1-2305-45e1-aa4c-be7e829d519a 2025-08-06 16:11:41,242 - INFO - Deleted Interface route table 0073a843-ce7e-4cd7-81ef-69b7e85ae088 2025-08-06 16:11:41,259 - INFO - ECMP routes found in agent 10.0.0.57, for prefix 3576:4b9b:966f:7e96:26a3:c1c0::/96 2025-08-06 16:11:41,259 - INFO - Tap interface tap950357cd-8c found in ecmp routes in agent 10.0.0.57 2025-08-06 16:11:41,272 - INFO - ECMP routes found in agent 10.0.0.49, for prefix 3576:4b9b:966f:7e96:26a3:c1c0::/96 2025-08-06 16:11:41,272 - INFO - Tap interface tap17de7b5e-5e found in ecmp routes in agent 10.0.0.49 2025-08-06 16:11:41,354 - DEBUG - Executing command: sudo tcpdump -nni tap950357cd-8c -U '(udp and src host 3a1e:2214:f427:dcc:e681:71b:0:3 and dst host 3576:4b9b:966f:7e96:26a3:c1c0:1277:b78e and dst port 11000)' -w /tmp/tap950357cd-8c_ctest-random-18860576.pcap 2025-08-06 16:11:41,895 - DEBUG - Executing command: sudo tcpdump -nni tap17de7b5e-5e -U '(udp and src host 3a1e:2214:f427:dcc:e681:71b:0:3 and dst host 3576:4b9b:966f:7e96:26a3:c1c0:1277:b78e and dst port 11000)' -w /tmp/tap17de7b5e-5e_ctest-random-23391467.pcap 2025-08-06 16:11:42,428 - DEBUG - Running remote_cmd, Cmd : dd bs=100 count=1 if=/dev/zero of=icmp_error;nc -6 -q 2 -u -p 13005 3576:4b9b:966f:7e96:26a3:c1c0:1277:b78e 11000 < icmp_error, host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.49, gateway password: c0ntrail123 2025-08-06 16:11:42,428 - DEBUG - dd bs=100 count=1 if=/dev/zero of=icmp_error;nc -6 -q 2 -u -p 13005 3576:4b9b:966f:7e96:26a3:c1c0:1277:b78e 11000 < icmp_error 2025-08-06 16:11:45,020 - DEBUG - 1+0 records in 1+0 records out 100 bytes (100 B) copied, 0.00133963 s, 74.6 kB/s 2025-08-06 16:11:45,020 - DEBUG - Executing command: sudo tcpdump -nnr /tmp/tap950357cd-8c_ctest-random-18860576.pcap | grep -c length 2025-08-06 16:11:45,041 - DEBUG - STDOUT: 0 2025-08-06 16:11:45,041 - DEBUG - STDERR: reading from file /tmp/tap950357cd-8c_ctest-random-18860576.pcap, link-type EN10MB (Ethernet), snapshot length 262144 2025-08-06 16:11:45,041 - WARNING - No packets are found in tcpdump output file /tmp/tap950357cd-8c_ctest-random-18860576.pcap but expected some packets 2025-08-06 16:11:47,042 - DEBUG - Executing command: sudo tcpdump -nnr /tmp/tap950357cd-8c_ctest-random-18860576.pcap | grep -c length 2025-08-06 16:11:47,070 - DEBUG - STDOUT: 0 2025-08-06 16:11:47,070 - DEBUG - STDERR: reading from file /tmp/tap950357cd-8c_ctest-random-18860576.pcap, link-type EN10MB (Ethernet), snapshot length 262144 2025-08-06 16:11:47,070 - WARNING - No packets are found in tcpdump output file /tmp/tap950357cd-8c_ctest-random-18860576.pcap but expected some packets 2025-08-06 16:11:49,071 - DEBUG - Executing command: sudo tcpdump -nnr /tmp/tap950357cd-8c_ctest-random-18860576.pcap | grep -c length 2025-08-06 16:11:49,088 - DEBUG - STDOUT: 0 2025-08-06 16:11:49,088 - DEBUG - STDERR: reading from file /tmp/tap950357cd-8c_ctest-random-18860576.pcap, link-type EN10MB (Ethernet), snapshot length 262144 2025-08-06 16:11:49,088 - WARNING - No packets are found in tcpdump output file /tmp/tap950357cd-8c_ctest-random-18860576.pcap but expected some packets 2025-08-06 16:11:51,088 - DEBUG - Executing command: sudo tcpdump -nnr /tmp/tap950357cd-8c_ctest-random-18860576.pcap | grep -c length 2025-08-06 16:11:51,109 - DEBUG - STDOUT: 0 2025-08-06 16:11:51,109 - DEBUG - STDERR: reading from file /tmp/tap950357cd-8c_ctest-random-18860576.pcap, link-type EN10MB (Ethernet), snapshot length 262144 2025-08-06 16:11:51,109 - WARNING - No packets are found in tcpdump output file /tmp/tap950357cd-8c_ctest-random-18860576.pcap but expected some packets 2025-08-06 16:11:53,110 - DEBUG - Executing command: sudo tcpdump -nnr /tmp/tap950357cd-8c_ctest-random-18860576.pcap | grep -c length 2025-08-06 16:11:53,129 - DEBUG - STDOUT: 0 2025-08-06 16:11:53,129 - DEBUG - STDERR: reading from file /tmp/tap950357cd-8c_ctest-random-18860576.pcap, link-type EN10MB (Ethernet), snapshot length 262144 2025-08-06 16:11:53,129 - WARNING - No packets are found in tcpdump output file /tmp/tap950357cd-8c_ctest-random-18860576.pcap but expected some packets 2025-08-06 16:11:55,130 - DEBUG - Executing command: sudo tcpdump -nnr /tmp/tap950357cd-8c_ctest-random-18860576.pcap | grep -c length 2025-08-06 16:11:55,147 - DEBUG - STDOUT: 0 2025-08-06 16:11:55,147 - DEBUG - STDERR: reading from file /tmp/tap950357cd-8c_ctest-random-18860576.pcap, link-type EN10MB (Ethernet), snapshot length 262144 2025-08-06 16:11:55,147 - WARNING - No packets are found in tcpdump output file /tmp/tap950357cd-8c_ctest-random-18860576.pcap but expected some packets 2025-08-06 16:11:57,148 - DEBUG - Executing command: sudo tcpdump -nnr /tmp/tap950357cd-8c_ctest-random-18860576.pcap | grep -c length 2025-08-06 16:11:57,163 - DEBUG - STDOUT: 0 2025-08-06 16:11:57,164 - DEBUG - STDERR: reading from file /tmp/tap950357cd-8c_ctest-random-18860576.pcap, link-type EN10MB (Ethernet), snapshot length 262144 2025-08-06 16:11:57,164 - WARNING - No packets are found in tcpdump output file /tmp/tap950357cd-8c_ctest-random-18860576.pcap but expected some packets 2025-08-06 16:11:57,164 - DEBUG - Executing command: sudo tcpdump -nnr /tmp/tap17de7b5e-5e_ctest-random-23391467.pcap | grep -c length 2025-08-06 16:11:57,179 - DEBUG - STDOUT: 1 2025-08-06 16:11:57,179 - DEBUG - STDERR: reading from file /tmp/tap17de7b5e-5e_ctest-random-23391467.pcap, link-type EN10MB (Ethernet), snapshot length 262144 2025-08-06 16:11:57,180 - INFO - 1 packets are found in tcpdump output as expected 2025-08-06 16:11:57,180 - DEBUG - Executing command: sudo kill $(ps -ef|grep tcpdump | grep pcap| awk '{print $2}') 2025-08-06 16:11:59,225 - INFO - Tcpdump verification on VM 3a1e:2214:f427:dcc:e681:71b:0:6 passed 2025-08-06 16:11:59,625 - DEBUG - Forward and reverse flows for match {'sip': '3a1e:2214:f427:dcc:e681:71b:0:3', 'dip': '3576:4b9b:966f:7e96:26a3:c1c0:1277:b78e', 'sport': '13005', 'dport': '11000', 'proto': '17', 'vrf_id': '2'}: 0, 0 2025-08-06 16:11:59,625 - DEBUG - Flow verification PASSED on node: 10.0.0.49 for VMs - Sender: 3a1e:2214:f427:dcc:e681:71b:0:3, Receiver: 3576:4b9b:966f:7e96:26a3:c1c0:1277:b78e, Flow count expected: 0 0, got: 0 0 2025-08-06 16:11:59,625 - DEBUG - Executing command: sudo kill $(ps -ef|grep tcpdump | grep pcap| awk '{print $2}') 2025-08-06 16:12:01,634 - DEBUG - Executing command: sudo kill $(ps -ef|grep tcpdump | grep pcap| awk '{print $2}') 2025-08-06 16:12:04,021 - DEBUG - Forward and reverse flows for match {'sip': '3a1e:2214:f427:dcc:e681:71b:0:3', 'dip': '3576:4b9b:966f:7e96:26a3:c1c0:1277:b78e', 'sport': '13005', 'dport': '11000', 'proto': '17', 'vrf_id': '2'}: 0, 0 2025-08-06 16:12:04,021 - DEBUG - Flow verification PASSED on node: 10.0.0.49 for VMs - Sender: 3a1e:2214:f427:dcc:e681:71b:0:3, Receiver: 3576:4b9b:966f:7e96:26a3:c1c0:1277:b78e, Flow count expected: 0 0, got: 0 0 2025-08-06 16:12:04,021 - INFO - Traffic verification for ECMP passed 2025-08-06 16:12:04,022 - INFO - Deleting VM ctest-DisablePolicyEcmpIpv6-67518367-33464430 2025-08-06 16:12:04,227 - INFO - Removed intf route table d780a6e5-03bf-4d1f-85f4-f91e617682f2 from port 17de7b5e-5e0f-46a2-b450-6f34af58132d 2025-08-06 16:12:04,266 - INFO - Deleted Interface route table d780a6e5-03bf-4d1f-85f4-f91e617682f2 2025-08-06 16:12:04,267 - INFO - Deleting VM ctest-DisablePolicyEcmpIpv6-67518367-57186457 2025-08-06 16:12:04,422 - INFO - Removed intf route table 6f1fb82a-25d4-47c7-81c2-77fdece15609 from port 950357cd-8c5a-4305-9971-5805bc0a35fc 2025-08-06 16:12:04,460 - INFO - Deleted Interface route table 6f1fb82a-25d4-47c7-81c2-77fdece15609 2025-08-06 16:12:04,461 - INFO - Deleting VM ctest-DisablePolicyEcmpIpv6-67518367-25554796 2025-08-06 16:12:04,548 - INFO - Deleting VN ctest-vn-18413561 2025-08-06 16:12:04,653 - DEBUG - VN 39e18760-d3e7-4bf7-9689-cf56ee171da4 still in use: Unable to complete operation on network 39e18760-d3e7-4bf7-9689-cf56ee171da4. There are one or more ports still in use on the network. Neutron server returns request_ids: ['req-53e2573d-a426-48fa-9535-4cf27dfa6dc9'] 2025-08-06 16:12:04,653 - WARNING - Deleting VN ctest-vn-18413561 failed..Will retry 2025-08-06 16:12:06,841 - DEBUG - Response for deleting network () 2025-08-06 16:12:06,841 - DEBUG - Requesting: http://10.0.0.254:8082/routing-instance/80eeca19-8118-4082-a99e-35ed8be16d22 2025-08-06 16:12:06,914 - DEBUG - Response Code: 404 2025-08-06 16:12:06,914 - DEBUG - Requesting: http://10.0.0.254:8082/domains 2025-08-06 16:12:06,921 - DEBUG - Requesting: http://10.0.0.254:8082/domain/024378da-7408-4369-ac73-51fa8d4d8d77 2025-08-06 16:12:06,963 - DEBUG - Requesting: http://10.0.0.254:8082/project/5ac72286-54a6-4fda-a7cd-d23b8ee100bd 2025-08-06 16:12:07,070 - INFO - Validated that VN ctest-vn-18413561 is not found in API Server 2025-08-06 16:12:07,085 - DEBUG - VN ctest-vn-18413561 is not present in Agent 10.0.0.49 2025-08-06 16:12:07,103 - DEBUG - VN ctest-vn-18413561 is not present in Agent 10.0.0.57 2025-08-06 16:12:07,103 - INFO - Validated that VN ctest-vn-18413561 is not in any agent 2025-08-06 16:12:07,140 - INFO - Validated that Routing instances and Config db in Control-nodes does not have VN ctest-vn-18413561 info 2025-08-06 16:12:08,444 - DEBUG - No XMPP flaps were noticed during the test
2025-08-06 16:12:08,444 - INFO - END TEST : test_ecmp_with_static_routes : PASSED[0:05:24]
2025-08-06 16:12:08,444 - INFO - -------------------------------------------------------------------------------- 2025-08-06 16:12:09,248 - INFO - Deleted project: ctest-DisablePolicyEcmpIpv6-67518367, ID : 5ac72286-54a6-4fda-a7cd-d23b8ee100bd