2025-09-18 10:17:47,574 - INFO - Domain Default found not creating 2025-09-18 10:17:47,708 - INFO - Project ctest-TestRoutersBasic-21841297 not found, creating it 2025-09-18 10:17:48,131 - INFO - Created Project:ctest-TestRoutersBasic-21841297, ID : 642639ac-fb4a-4d10-a711-5f6ffdb9bd54 2025-09-18 10:17:49,566 - INFO - ================================================================================ 2025-09-18 10:17:49,566 - INFO - STARTING TEST : test_basic_snat_behavior_without_external_connectivity 2025-09-18 10:17:49,566 - INFO - TEST DESCRIPTION : Create an external network, a router set router-gateway to external network launch a private network and attach it to router validate left vm pinging right vm through Snat 2025-09-18 10:17:49,693 - DEBUG - Nothing to compare xmpp stats {'10.0.0.254': {'10.20.0.17': '0'}} with 2025-09-18 10:17:49,694 - INFO - Initial checks done. Running the testcase now 2025-09-18 10:17:49,694 - INFO - 2025-09-18 10:17:50,380 - INFO - Default SG to be edited for allow all on project: ctest-TestRoutersBasic-21841297 2025-09-18 10:17:50,476 - INFO - Adding rules to the default security group in Project ctest-TestRoutersBasic-21841297 2025-09-18 10:17:50,787 - DEBUG - Reading firewall policy {'fq_name': ['default-domain', 'ctest-TestRoutersBasic-21841297', 'default']} 2025-09-18 10:17:51,057 - DEBUG - Response for create_network : {'network': {'id': 'e8050606-a9ca-4e44-8902-fb5389af3c52', 'name': 'ctest-vn-56871141', 'tenant_id': '642639acfb4a4d10a7115f6ffdb9bd54', 'project_id': '642639acfb4a4d10a7115f6ffdb9bd54', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRoutersBasic-21841297', 'ctest-vn-56871141'], 'port_security_enabled': True, 'description': ''}} 2025-09-18 10:17:51,253 - DEBUG - Response for create_subnet : {'subnet': {'id': '0062b8f3-a51b-4beb-808a-ad5e98351ac2', 'name': '', 'tenant_id': '642639acfb4a4d10a7115f6ffdb9bd54', 'network_id': 'e8050606-a9ca-4e44-8902-fb5389af3c52', 'ip_version': 4, 'cidr': '173.89.84.192/26', 'allocation_pools': [{'start': '173.89.84.194', 'end': '173.89.84.254'}], 'gateway_ip': '173.89.84.193', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '173.89.84.194', 'tags': [], 'project_id': '642639acfb4a4d10a7115f6ffdb9bd54'}} 2025-09-18 10:17:51,269 - INFO - Created VN ctest-vn-56871141 2025-09-18 10:17:51,320 - DEBUG - VN ctest-vn-56871141 UUID is e8050606-a9ca-4e44-8902-fb5389af3c52 2025-09-18 10:17:51,647 - DEBUG - Response for create_network : {'network': {'id': '2129a703-9d8f-487c-9bef-634548d7603e', 'name': 'ctest-ext_vn-48343516', 'tenant_id': '642639acfb4a4d10a7115f6ffdb9bd54', 'project_id': '642639acfb4a4d10a7115f6ffdb9bd54', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': True, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRoutersBasic-21841297', 'ctest-ext_vn-48343516'], 'port_security_enabled': True, 'description': ''}} 2025-09-18 10:17:51,787 - DEBUG - Response for create_subnet : {'subnet': {'id': '6581315d-1c45-4da9-9622-2fe61edb4ac5', 'name': '', 'tenant_id': '642639acfb4a4d10a7115f6ffdb9bd54', 'network_id': '2129a703-9d8f-487c-9bef-634548d7603e', 'ip_version': 4, 'cidr': '109.203.113.0/26', 'allocation_pools': [{'start': '109.203.113.2', 'end': '109.203.113.62'}], 'gateway_ip': '109.203.113.1', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '109.203.113.2', 'tags': [], 'project_id': '642639acfb4a4d10a7115f6ffdb9bd54'}} 2025-09-18 10:17:51,803 - INFO - Created VN ctest-ext_vn-48343516 2025-09-18 10:17:51,855 - DEBUG - VN ctest-ext_vn-48343516 UUID is 2129a703-9d8f-487c-9bef-634548d7603e 2025-09-18 10:17:52,096 - DEBUG - Services list from nova: [, , ] 2025-09-18 10:17:53,092 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-4136-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-4136-1) 2025-09-18 10:17:54,235 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-4136-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-4136-1) 2025-09-18 10:17:54,291 - INFO - Setting gateway for router ad0c0081-3188-430c-a206-1fc95718fc91 to network 2129a703-9d8f-487c-9bef-634548d7603e 2025-09-18 10:17:54,346 - INFO - Adding interface with subnet_id 0062b8f3-a51b-4beb-808a-ad5e98351ac2, port_id None to router ad0c0081-3188-430c-a206-1fc95718fc91 2025-09-18 10:17:54,660 - INFO - Waiting for VM ctest-TestRoutersBasic-21841297-80748014 to be up.. 2025-09-18 10:17:54,776 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2025-09-18 10:17:59,829 - DEBUG - VM is in ERROR state now 2025-09-18 10:17:59,829 - ERROR - VM in error state. 2025-09-18 10:17:59,829 - ERROR - VM is not in ACTIVE state 2025-09-18 10:17:59,905 - ERROR - Fatal Nova Exception while getting VM detail 2025-09-18 10:17:59,905 - DEBUG - None 2025-09-18 10:17:59,905 - INFO - Waiting for VM ctest-TestRoutersBasic-21841297-16657783 to be up.. 2025-09-18 10:17:59,964 - DEBUG - VM is in ERROR state now 2025-09-18 10:17:59,964 - ERROR - VM in error state. 2025-09-18 10:17:59,964 - ERROR - VM is not in ACTIVE state 2025-09-18 10:18:00,051 - ERROR - Fatal Nova Exception while getting VM detail 2025-09-18 10:18:00,051 - DEBUG - None 2025-09-18 10:18:00,051 - INFO - VM name : ctest-TestRoutersBasic-21841297-16657783 2025-09-18 10:18:00,107 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:18:05,159 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:18:10,211 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:18:15,266 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:18:20,324 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:18:25,380 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:18:25,380 - ERROR - VM 2af52312-7625-47aa-8b49-071357bbf61d is not launched yet 2025-09-18 10:18:27,381 - INFO - VM name : ctest-TestRoutersBasic-21841297-16657783 2025-09-18 10:18:27,436 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:18:32,492 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:18:37,551 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:18:42,602 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:18:47,660 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:18:52,717 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:18:52,717 - ERROR - VM 2af52312-7625-47aa-8b49-071357bbf61d is not launched yet 2025-09-18 10:18:54,717 - INFO - VM name : ctest-TestRoutersBasic-21841297-16657783 2025-09-18 10:18:54,782 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:18:59,839 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:19:04,898 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:19:09,952 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:19:15,007 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:19:20,068 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:19:20,068 - ERROR - VM 2af52312-7625-47aa-8b49-071357bbf61d is not launched yet 2025-09-18 10:19:22,068 - INFO - VM name : ctest-TestRoutersBasic-21841297-16657783 2025-09-18 10:19:22,122 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:19:27,175 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:19:32,230 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:19:37,287 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:19:42,340 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:19:47,394 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:19:47,394 - ERROR - VM 2af52312-7625-47aa-8b49-071357bbf61d is not launched yet 2025-09-18 10:19:49,394 - INFO - VM name : ctest-TestRoutersBasic-21841297-16657783 2025-09-18 10:19:49,448 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:19:54,500 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:19:59,551 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:20:04,611 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:20:09,680 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:20:14,742 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:20:14,742 - ERROR - VM 2af52312-7625-47aa-8b49-071357bbf61d is not launched yet 2025-09-18 10:20:16,743 - INFO - VM name : ctest-TestRoutersBasic-21841297-16657783 2025-09-18 10:20:16,799 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:20:21,855 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:20:26,907 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:20:31,961 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:20:37,019 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:20:42,073 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:20:42,074 - ERROR - VM 2af52312-7625-47aa-8b49-071357bbf61d is not launched yet 2025-09-18 10:20:42,075 - INFO - VM name : ctest-TestRoutersBasic-21841297-16657783 2025-09-18 10:20:42,138 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:20:47,190 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:20:52,242 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:20:57,293 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:21:02,352 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:21:07,411 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:21:07,411 - ERROR - VM 2af52312-7625-47aa-8b49-071357bbf61d is not launched yet 2025-09-18 10:21:09,411 - INFO - VM name : ctest-TestRoutersBasic-21841297-16657783 2025-09-18 10:21:09,463 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:21:14,522 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:21:19,582 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:21:24,637 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:21:29,693 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:21:34,747 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:21:34,747 - ERROR - VM 2af52312-7625-47aa-8b49-071357bbf61d is not launched yet 2025-09-18 10:21:36,747 - INFO - VM name : ctest-TestRoutersBasic-21841297-16657783 2025-09-18 10:21:36,797 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:21:41,881 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:21:46,944 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:21:51,994 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:21:57,049 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:22:02,105 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:22:02,105 - ERROR - VM 2af52312-7625-47aa-8b49-071357bbf61d is not launched yet 2025-09-18 10:22:04,105 - INFO - VM name : ctest-TestRoutersBasic-21841297-16657783 2025-09-18 10:22:04,171 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:22:09,226 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:22:14,280 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:22:19,335 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:22:24,393 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:22:29,450 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:22:29,450 - ERROR - VM 2af52312-7625-47aa-8b49-071357bbf61d is not launched yet 2025-09-18 10:22:31,450 - INFO - VM name : ctest-TestRoutersBasic-21841297-16657783 2025-09-18 10:22:31,507 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:22:36,582 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:22:41,641 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:22:46,697 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:22:51,795 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:22:56,848 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:22:56,848 - ERROR - VM 2af52312-7625-47aa-8b49-071357bbf61d is not launched yet 2025-09-18 10:22:58,848 - INFO - VM name : ctest-TestRoutersBasic-21841297-16657783 2025-09-18 10:22:58,908 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:23:03,963 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:23:09,018 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:23:14,078 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:23:19,134 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:23:24,193 - DEBUG - VM ctest-TestRoutersBasic-21841297-16657783 : Status=ERROR, Addresses : {} 2025-09-18 10:23:24,193 - ERROR - VM 2af52312-7625-47aa-8b49-071357bbf61d is not launched yet 2025-09-18 10:23:24,193 - INFO - Deleting interface with subnet_id 0062b8f3-a51b-4beb-808a-ad5e98351ac2, port_id None from router ad0c0081-3188-430c-a206-1fc95718fc91 2025-09-18 10:23:24,392 - INFO - Skip interface_detach for VM ctest-TestRoutersBasic-21841297-16657783 in state ERROR 2025-09-18 10:23:24,392 - INFO - Deleting VM ctest-TestRoutersBasic-21841297-16657783 2025-09-18 10:23:24,410 - ERROR - VM ctest-TestRoutersBasic-21841297-16657783 has failed to come up 2025-09-18 10:23:24,410 - ERROR - Fault seen in nova show is: {'code': 500, 'created': '2025-09-18T10:17:55Z', 'message': "Failure running os_vif plugin plug method: Failed to plug VIF VIFGeneric(active=True,address=02:8a:8b:21:08:4b,has_traffic_filtering=True,id=8a8b2108-4b64-4591-9752-9340bea51351,network=Network(2129a703-9d8f-487c-9bef-634548d7603e),plugin='vrouter',port_p", 'details': 'Traceback (most recent call last):\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/os_vif/__init__.py", line 77, in plug\n plugin.plug(vif, instance_info)\n File "/opt/plugin/site-packages/vif_plug_vrouter/vrouter.py", line 271, in plug\n self._vrouter_port_add(instance_info, vif)\n File "/opt/plugin/site-packages/vif_plug_vrouter/vrouter.py", line 263, in _vrouter_port_add\n vhostuser_socket, vhostuser_mode)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/oslo_privsep/priv_context.py", line 272, in _wrap\n r_call_timeout)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/oslo_privsep/daemon.py", line 215, in remote_call\n raise exc_type(*result[2])\nvif_plug_vrouter.exception.VrouterPortControlError: Error during the call to vrouter-port-control: (\'vrouter-port-control\', \'--oper=add\', \'--uuid=8a8b2108-4b64-4591-9752-9340bea51351\', \'--instance_uuid=2af52312-7625-47aa-8b49-071357bbf61d\', \'--vn_uuid=2129a703-9d8f-487c-9bef-634548d7603e\', \'--vm_project_uuid=642639acfb4a4d10a7115f6ffdb9bd54\', \'--ip_address=109.203.113.3\', \'--ipv6_address=None\', \'--vm_name=ctest-TestRoutersBasic-21841297-16657783\', \'--mac=02:8a:8b:21:08:4b\', \'--tap_name=tap8a8b2108-4b\', \'--port_type=NovaVMPort\', \'--tx_vlan_id=-1\', \'--rx_vlan_id=-1\')\n\nDuring handling of the above exception, another exception occurred:\n\nTraceback (most recent call last):\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/virt/libvirt/vif.py", line 699, in _plug_os_vif\n os_vif.plug(vif, instance_info)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/os_vif/__init__.py", line 82, in plug\n raise os_vif.exception.PlugException(vif=vif, err=err)\nos_vif.exception.PlugException: Failed to plug VIF VIFGeneric(active=True,address=02:8a:8b:21:08:4b,has_traffic_filtering=True,id=8a8b2108-4b64-4591-9752-9340bea51351,network=Network(2129a703-9d8f-487c-9bef-634548d7603e),plugin=\'vrouter\',port_profile=,preserve_on_delete=False,vif_name=\'tap8a8b2108-4b\'). Got error: Error during the call to vrouter-port-control: (\'vrouter-port-control\', \'--oper=add\', \'--uuid=8a8b2108-4b64-4591-9752-9340bea51351\', \'--instance_uuid=2af52312-7625-47aa-8b49-071357bbf61d\', \'--vn_uuid=2129a703-9d8f-487c-9bef-634548d7603e\', \'--vm_project_uuid=642639acfb4a4d10a7115f6ffdb9bd54\', \'--ip_address=109.203.113.3\', \'--ipv6_address=None\', \'--vm_name=ctest-TestRoutersBasic-21841297-16657783\', \'--mac=02:8a:8b:21:08:4b\', \'--tap_name=tap8a8b2108-4b\', \'--port_type=NovaVMPort\', \'--tx_vlan_id=-1\', \'--rx_vlan_id=-1\')\n\nDuring handling of the above exception, another exception occurred:\n\nTraceback (most recent call last):\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/compute/manager.py", line 2521, in _build_and_run_instance\n accel_info=accel_info)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/virt/libvirt/driver.py", line 4339, in spawn\n cleanup_instance_disks=created_disks)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/virt/libvirt/driver.py", line 7523, in _create_guest_with_network\n cleanup_instance_disks=cleanup_instance_disks)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/oslo_utils/excutils.py", line 227, in __exit__\n self.force_reraise()\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/oslo_utils/excutils.py", line 200, in force_reraise\n raise self.value\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/virt/libvirt/driver.py", line 7492, in _create_guest_with_network\n self.plug_vifs(instance, network_info)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/virt/libvirt/driver.py", line 1386, in plug_vifs\n self.vif_driver.plug(instance, vif)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/virt/libvirt/vif.py", line 723, in plug\n self._plug_os_vif(instance, vif_obj)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/virt/libvirt/vif.py", line 703, in _plug_os_vif\n raise exception.InternalError(msg)\nnova.exception.InternalError: Failure running os_vif plugin plug method: Failed to plug VIF VIFGeneric(active=True,address=02:8a:8b:21:08:4b,has_traffic_filtering=True,id=8a8b2108-4b64-4591-9752-9340bea51351,network=Network(2129a703-9d8f-487c-9bef-634548d7603e),plugin=\'vrouter\',port_profile=,preserve_on_delete=False,vif_name=\'tap8a8b2108-4b\'). Got error: Error during the call to vrouter-port-control: (\'vrouter-port-control\', \'--oper=add\', \'--uuid=8a8b2108-4b64-4591-9752-9340bea51351\', \'--instance_uuid=2af52312-7625-47aa-8b49-071357bbf61d\', \'--vn_uuid=2129a703-9d8f-487c-9bef-634548d7603e\', \'--vm_project_uuid=642639acfb4a4d10a7115f6ffdb9bd54\', \'--ip_address=109.203.113.3\', \'--ipv6_address=None\', \'--vm_name=ctest-TestRoutersBasic-21841297-16657783\', \'--mac=02:8a:8b:21:08:4b\', \'--tap_name=tap8a8b2108-4b\', \'--port_type=NovaVMPort\', \'--tx_vlan_id=-1\', \'--rx_vlan_id=-1\')\n\nDuring handling of the above exception, another exception occurred:\n\nTraceback (most recent call last):\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/compute/manager.py", line 2337, in _do_build_and_run_instance\n filter_properties, request_spec, accel_uuids)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/compute/manager.py", line 2625, in _build_and_run_instance\n instance_uuid=instance.uuid, reason=str(e))\nnova.exception.RescheduledException: Build of instance 2af52312-7625-47aa-8b49-071357bbf61d was re-scheduled: Failure running os_vif plugin plug method: Failed to plug VIF VIFGeneric(active=True,address=02:8a:8b:21:08:4b,has_traffic_filtering=True,id=8a8b2108-4b64-4591-9752-9340bea51351,network=Network(2129a703-9d8f-487c-9bef-634548d7603e),plugin=\'vrouter\',port_profile=,preserve_on_delete=False,vif_name=\'tap8a8b2108-4b\'). Got error: Error during the call to vrouter-port-control: (\'vrouter-port-control\', \'--oper=add\', \'--uuid=8a8b2108-4b64-4591-9752-9340bea51351\', \'--instance_uuid=2af52312-7625-47aa-8b49-071357bbf61d\', \'--vn_uuid=2129a703-9d8f-487c-9bef-634548d7603e\', \'--vm_project_uuid=642639acfb4a4d10a7115f6ffdb9bd54\', \'--ip_address=109.203.113.3\', \'--ipv6_address=None\', \'--vm_name=ctest-TestRoutersBasic-21841297-16657783\', \'--mac=02:8a:8b:21:08:4b\', \'--tap_name=tap8a8b2108-4b\', \'--port_type=NovaVMPort\', \'--tx_vlan_id=-1\', \'--rx_vlan_id=-1\')\n'} 2025-09-18 10:23:24,411 - INFO - Skip interface_detach for VM ctest-TestRoutersBasic-21841297-80748014 in state ERROR 2025-09-18 10:23:24,411 - INFO - Deleting VM ctest-TestRoutersBasic-21841297-80748014 2025-09-18 10:23:24,411 - ERROR - VM ctest-TestRoutersBasic-21841297-80748014 has failed to come up 2025-09-18 10:23:24,411 - ERROR - Fault seen in nova show is: {'code': 500, 'created': '2025-09-18T10:17:55Z', 'message': "Failure running os_vif plugin plug method: Failed to plug VIF VIFGeneric(active=True,address=02:28:59:98:9b:8d,has_traffic_filtering=True,id=2859989b-8dfe-4798-9f09-64ad824d507d,network=Network(e8050606-a9ca-4e44-8902-fb5389af3c52),plugin='vrouter',port_p", 'details': 'Traceback (most recent call last):\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/os_vif/__init__.py", line 77, in plug\n plugin.plug(vif, instance_info)\n File "/opt/plugin/site-packages/vif_plug_vrouter/vrouter.py", line 271, in plug\n self._vrouter_port_add(instance_info, vif)\n File "/opt/plugin/site-packages/vif_plug_vrouter/vrouter.py", line 263, in _vrouter_port_add\n vhostuser_socket, vhostuser_mode)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/oslo_privsep/priv_context.py", line 272, in _wrap\n r_call_timeout)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/oslo_privsep/daemon.py", line 215, in remote_call\n raise exc_type(*result[2])\nvif_plug_vrouter.exception.VrouterPortControlError: Error during the call to vrouter-port-control: (\'vrouter-port-control\', \'--oper=add\', \'--uuid=2859989b-8dfe-4798-9f09-64ad824d507d\', \'--instance_uuid=971bfd39-7c72-44c5-a60f-45d354db0ed2\', \'--vn_uuid=e8050606-a9ca-4e44-8902-fb5389af3c52\', \'--vm_project_uuid=642639acfb4a4d10a7115f6ffdb9bd54\', \'--ip_address=173.89.84.195\', \'--ipv6_address=None\', \'--vm_name=ctest-TestRoutersBasic-21841297-80748014\', \'--mac=02:28:59:98:9b:8d\', \'--tap_name=tap2859989b-8d\', \'--port_type=NovaVMPort\', \'--tx_vlan_id=-1\', \'--rx_vlan_id=-1\')\n\nDuring handling of the above exception, another exception occurred:\n\nTraceback (most recent call last):\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/virt/libvirt/vif.py", line 699, in _plug_os_vif\n os_vif.plug(vif, instance_info)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/os_vif/__init__.py", line 82, in plug\n raise os_vif.exception.PlugException(vif=vif, err=err)\nos_vif.exception.PlugException: Failed to plug VIF VIFGeneric(active=True,address=02:28:59:98:9b:8d,has_traffic_filtering=True,id=2859989b-8dfe-4798-9f09-64ad824d507d,network=Network(e8050606-a9ca-4e44-8902-fb5389af3c52),plugin=\'vrouter\',port_profile=,preserve_on_delete=False,vif_name=\'tap2859989b-8d\'). Got error: Error during the call to vrouter-port-control: (\'vrouter-port-control\', \'--oper=add\', \'--uuid=2859989b-8dfe-4798-9f09-64ad824d507d\', \'--instance_uuid=971bfd39-7c72-44c5-a60f-45d354db0ed2\', \'--vn_uuid=e8050606-a9ca-4e44-8902-fb5389af3c52\', \'--vm_project_uuid=642639acfb4a4d10a7115f6ffdb9bd54\', \'--ip_address=173.89.84.195\', \'--ipv6_address=None\', \'--vm_name=ctest-TestRoutersBasic-21841297-80748014\', \'--mac=02:28:59:98:9b:8d\', \'--tap_name=tap2859989b-8d\', \'--port_type=NovaVMPort\', \'--tx_vlan_id=-1\', \'--rx_vlan_id=-1\')\n\nDuring handling of the above exception, another exception occurred:\n\nTraceback (most recent call last):\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/compute/manager.py", line 2521, in _build_and_run_instance\n accel_info=accel_info)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/virt/libvirt/driver.py", line 4339, in spawn\n cleanup_instance_disks=created_disks)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/virt/libvirt/driver.py", line 7523, in _create_guest_with_network\n cleanup_instance_disks=cleanup_instance_disks)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/oslo_utils/excutils.py", line 227, in __exit__\n self.force_reraise()\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/oslo_utils/excutils.py", line 200, in force_reraise\n raise self.value\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/virt/libvirt/driver.py", line 7492, in _create_guest_with_network\n self.plug_vifs(instance, network_info)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/virt/libvirt/driver.py", line 1386, in plug_vifs\n self.vif_driver.plug(instance, vif)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/virt/libvirt/vif.py", line 723, in plug\n self._plug_os_vif(instance, vif_obj)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/virt/libvirt/vif.py", line 703, in _plug_os_vif\n raise exception.InternalError(msg)\nnova.exception.InternalError: Failure running os_vif plugin plug method: Failed to plug VIF VIFGeneric(active=True,address=02:28:59:98:9b:8d,has_traffic_filtering=True,id=2859989b-8dfe-4798-9f09-64ad824d507d,network=Network(e8050606-a9ca-4e44-8902-fb5389af3c52),plugin=\'vrouter\',port_profile=,preserve_on_delete=False,vif_name=\'tap2859989b-8d\'). Got error: Error during the call to vrouter-port-control: (\'vrouter-port-control\', \'--oper=add\', \'--uuid=2859989b-8dfe-4798-9f09-64ad824d507d\', \'--instance_uuid=971bfd39-7c72-44c5-a60f-45d354db0ed2\', \'--vn_uuid=e8050606-a9ca-4e44-8902-fb5389af3c52\', \'--vm_project_uuid=642639acfb4a4d10a7115f6ffdb9bd54\', \'--ip_address=173.89.84.195\', \'--ipv6_address=None\', \'--vm_name=ctest-TestRoutersBasic-21841297-80748014\', \'--mac=02:28:59:98:9b:8d\', \'--tap_name=tap2859989b-8d\', \'--port_type=NovaVMPort\', \'--tx_vlan_id=-1\', \'--rx_vlan_id=-1\')\n\nDuring handling of the above exception, another exception occurred:\n\nTraceback (most recent call last):\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/compute/manager.py", line 2337, in _do_build_and_run_instance\n filter_properties, request_spec, accel_uuids)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/compute/manager.py", line 2625, in _build_and_run_instance\n instance_uuid=instance.uuid, reason=str(e))\nnova.exception.RescheduledException: Build of instance 971bfd39-7c72-44c5-a60f-45d354db0ed2 was re-scheduled: Failure running os_vif plugin plug method: Failed to plug VIF VIFGeneric(active=True,address=02:28:59:98:9b:8d,has_traffic_filtering=True,id=2859989b-8dfe-4798-9f09-64ad824d507d,network=Network(e8050606-a9ca-4e44-8902-fb5389af3c52),plugin=\'vrouter\',port_profile=,preserve_on_delete=False,vif_name=\'tap2859989b-8d\'). Got error: Error during the call to vrouter-port-control: (\'vrouter-port-control\', \'--oper=add\', \'--uuid=2859989b-8dfe-4798-9f09-64ad824d507d\', \'--instance_uuid=971bfd39-7c72-44c5-a60f-45d354db0ed2\', \'--vn_uuid=e8050606-a9ca-4e44-8902-fb5389af3c52\', \'--vm_project_uuid=642639acfb4a4d10a7115f6ffdb9bd54\', \'--ip_address=173.89.84.195\', \'--ipv6_address=None\', \'--vm_name=ctest-TestRoutersBasic-21841297-80748014\', \'--mac=02:28:59:98:9b:8d\', \'--tap_name=tap2859989b-8d\', \'--port_type=NovaVMPort\', \'--tx_vlan_id=-1\', \'--rx_vlan_id=-1\')\n'} 2025-09-18 10:23:24,411 - INFO - Deleting VN ctest-ext_vn-48343516 2025-09-18 10:23:24,466 - DEBUG - VN 2129a703-9d8f-487c-9bef-634548d7603e still in use: Unable to complete operation on network 2129a703-9d8f-487c-9bef-634548d7603e. There are one or more ports still in use on the network. Neutron server returns request_ids: ['req-e8fb6be6-f289-411f-b1d2-dc9dbcc1055e'] 2025-09-18 10:23:24,466 - WARNING - Deleting VN ctest-ext_vn-48343516 failed..Will retry 2025-09-18 10:23:26,562 - DEBUG - Response for deleting network () 2025-09-18 10:23:26,562 - INFO - Deleting VN ctest-vn-56871141 2025-09-18 10:23:26,665 - DEBUG - Response for deleting network () 2025-09-18 10:23:26,784 - ERROR -
Traceback (most recent call last):
  File "/contrail-test/tcutils/wrappers.py", line 80, in wrapper
    result = function(self, *args, **kwargs)
  File "/contrail-test/scripts/neutron/test_routers_basic.py", line 52, in test_basic_snat_behavior_without_external_connectivity
    vm2_fixture.vm_ip), 'Ping from vm_left to vm_right through snat failed'
  File "/contrail-test/fixtures/vm_test.py", line 354, in vm_ip
    assert self.verify_vm_launched()
AssertionError
2025-09-18 10:23:26,789 - DEBUG - No XMPP flaps were noticed during the test 2025-09-18 10:23:26,789 - INFO -
2025-09-18 10:23:26,790 - INFO - END TEST : test_basic_snat_behavior_without_external_connectivity : FAILED[0:05:37]
2025-09-18 10:23:26,790 - INFO - -------------------------------------------------------------------------------- 2025-09-18 10:23:27,471 - INFO - Deleted project: ctest-TestRoutersBasic-21841297, ID : 642639ac-fb4a-4d10-a711-5f6ffdb9bd54