2025-10-17 22:45:35,519 - INFO - Reading existing Domain with UUID c2fab7b5-42f0-4b0e-a131-4c62931bf465
2025-10-17 22:45:35,531 - INFO - Using existing domain ['admin_domain'](c2fab7b5-42f0-4b0e-a131-4c62931bf465)
2025-10-17 22:45:35,772 - INFO - Project ctest-TestPorts-87949552 not found, creating it
2025-10-17 22:45:36,309 - INFO - Created Project:ctest-TestPorts-87949552, ID : 7c01088a-064d-4146-b420-c054c55d21d0 
2025-10-17 22:45:38,061 - INFO - ================================================================================
2025-10-17 22:45:38,061 - INFO - STARTING TEST    : test_ports_bindings
2025-10-17 22:45:38,062 - INFO - TEST DESCRIPTION : 
        Verify that we are able to create a port with custom port bindings
        Steps:
            1) Create Port with Port bindings profile set to {'foo': 'bar'}
            2) Retrieve and verify the same is set
        
2025-10-17 22:45:38,476 - DEBUG - Nothing to compare xmpp stats {'10.0.0.131': {'10.0.0.131': '0'}} with
2025-10-17 22:45:38,476 - INFO - Initial checks done. Running the testcase now
2025-10-17 22:45:38,476 - INFO - 
2025-10-17 22:45:39,223 - DEBUG - Response for create_network : {'network': {'id': '35dd2d7b-0695-4c72-b1a5-036c4cd9efe9', 'name': 'ctest-vn-11349320', 'tenant_id': '7c01088a064d4146b420c054c55d21d0', 'project_id': '7c01088a064d4146b420c054c55d21d0', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['admin_domain', 'ctest-TestPorts-87949552', 'ctest-vn-11349320'], 'port_security_enabled': True, 'description': '', 'created_at': None, 'updated_at': None}}
2025-10-17 22:45:39,495 - DEBUG - Response for create_subnet : {'subnet': {'id': '64160ed8-95cf-4d26-acd8-87a96f293e94', 'name': '', 'tenant_id': '7c01088a064d4146b420c054c55d21d0', 'network_id': '35dd2d7b-0695-4c72-b1a5-036c4cd9efe9', 'ip_version': 4, 'cidr': '218.104.219.192/26', 'allocation_pools': [{'start': '218.104.219.194', 'end': '218.104.219.254'}], 'gateway_ip': '218.104.219.193', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'created_at': '2025-10-17T22:45:39.386164', 'updated_at': '2025-10-17T22:45:39.386164', 'dns_server_address': '218.104.219.194', 'tags': [], 'project_id': '7c01088a064d4146b420c054c55d21d0'}}
2025-10-17 22:45:39,557 - INFO - Created VN ctest-vn-11349320
2025-10-17 22:45:39,615 - DEBUG - VN ctest-vn-11349320 UUID is 35dd2d7b-0695-4c72-b1a5-036c4cd9efe9
2025-10-17 22:45:39,825 - DEBUG - Read virtual machine interface {'fq_name': ['admin_domain', 'ctest-TestPorts-87949552', 'ctest-vmi-22004664']}
2025-10-17 22:45:40,156 - DEBUG - Response for create_port : {'port': {'name': 'ctest-vmi-22004664', 'id': 'dc67ccf6-aeaa-49b0-b72c-3444b03d6d98', 'tenant_id': '7c01088a064d4146b420c054c55d21d0', 'network_id': '35dd2d7b-0695-4c72-b1a5-036c4cd9efe9', 'mac_address': '02:dc:67:cc:f6:ae', 'binding:profile': {'foo': 'bar'}, 'binding:vnic_type': 'normal', 'binding:vif_details': {'port_filter': True}, 'binding:vif_type': 'unbound', 'binding:host_id': None, 'allowed_address_pairs': [], 'fixed_ips': [{'ip_address': '218.104.219.195', 'subnet_id': '64160ed8-95cf-4d26-acd8-87a96f293e94'}], 'security_groups': ['ed6536c6-390e-4bc9-b540-ce418cf055f3'], 'admin_state_up': True, 'device_id': '', 'device_owner': '', 'status': 'DOWN', 'port_security_enabled': True, 'description': '', 'created_at': '2025-10-17T22:45:39.952010', 'updated_at': '2025-10-17T22:45:40.021146', 'project_id': '7c01088a064d4146b420c054c55d21d0'}}
2025-10-17 22:45:40,156 - DEBUG - Created port dc67ccf6-aeaa-49b0-b72c-3444b03d6d98
2025-10-17 22:45:40,270 - DEBUG - Requesting: https://10.0.0.131:8082/virtual-machine-interface/dc67ccf6-aeaa-49b0-b72c-3444b03d6d98
2025-10-17 22:45:40,611 - DEBUG - Requesting: https://10.0.0.131:8082/virtual-machine-interface/dc67ccf6-aeaa-49b0-b72c-3444b03d6d98
2025-10-17 22:45:40,700 - INFO - VMI dc67ccf6-aeaa-49b0-b72c-3444b03d6d98 verification in API Server passed
2025-10-17 22:45:40,881 - DEBUG - Response for delete_port : ()
2025-10-17 22:45:40,881 - INFO - Deleted port dc67ccf6-aeaa-49b0-b72c-3444b03d6d98
2025-10-17 22:45:40,882 - INFO - Deleting VN ctest-vn-11349320 
2025-10-17 22:45:41,096 - DEBUG - Response for deleting network ()
2025-10-17 22:45:41,492 - DEBUG - No XMPP flaps were noticed during the test
2025-10-17 22:45:41,492 - INFO - END TEST : test_ports_bindings : PASSED[0:00:03]
2025-10-17 22:45:41,492 - INFO - --------------------------------------------------------------------------------
2025-10-17 22:45:41,495 - INFO - ================================================================================
2025-10-17 22:45:41,495 - INFO - STARTING TEST    : test_ports_specific_subnet_ip
2025-10-17 22:45:41,495 - INFO - TEST DESCRIPTION : Create ports with specific Subnet and IP
        Create two ports in a VN with 2 subnets and specific IPs
        Attach to two VMs
        Ping between them should pass
        
2025-10-17 22:45:41,888 - DEBUG - Nothing to compare xmpp stats {'10.0.0.131': {'10.0.0.131': '0'}} with
2025-10-17 22:45:41,888 - INFO - Initial checks done. Running the testcase now
2025-10-17 22:45:41,888 - INFO - 
2025-10-17 22:45:42,192 - DEBUG - Response for create_network : {'network': {'id': 'ec7e87b7-9e9d-4be9-a5e8-ddcc1cb91401', 'name': 'ctest-vn1-52446069', 'tenant_id': '7c01088a064d4146b420c054c55d21d0', 'project_id': '7c01088a064d4146b420c054c55d21d0', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['admin_domain', 'ctest-TestPorts-87949552', 'ctest-vn1-52446069'], 'port_security_enabled': True, 'description': '', 'created_at': None, 'updated_at': None}}
2025-10-17 22:45:42,488 - DEBUG - Response for create_subnet : {'subnet': {'id': '873340e9-a78e-4e26-a61f-a591db84ee70', 'name': '', 'tenant_id': '7c01088a064d4146b420c054c55d21d0', 'network_id': 'ec7e87b7-9e9d-4be9-a5e8-ddcc1cb91401', 'ip_version': 4, 'cidr': '184.58.233.128/26', 'allocation_pools': [{'start': '184.58.233.130', 'end': '184.58.233.190'}], 'gateway_ip': '184.58.233.129', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'created_at': '2025-10-17T22:45:42.331885', 'updated_at': '2025-10-17T22:45:42.331885', 'dns_server_address': '184.58.233.130', 'tags': [], 'project_id': '7c01088a064d4146b420c054c55d21d0'}}
2025-10-17 22:45:42,726 - DEBUG - Response for create_subnet : {'subnet': {'id': 'daf473a1-a412-45d7-833b-3248d3b584f1', 'name': '', 'tenant_id': '7c01088a064d4146b420c054c55d21d0', 'network_id': 'ec7e87b7-9e9d-4be9-a5e8-ddcc1cb91401', 'ip_version': 4, 'cidr': '221.246.33.64/26', 'allocation_pools': [{'start': '221.246.33.66', 'end': '221.246.33.126'}], 'gateway_ip': '221.246.33.65', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'created_at': '2025-10-17T22:45:42.612749', 'updated_at': '2025-10-17T22:45:42.612749', 'dns_server_address': '221.246.33.66', 'tags': [], 'project_id': '7c01088a064d4146b420c054c55d21d0'}}
2025-10-17 22:45:42,797 - INFO - Created VN ctest-vn1-52446069
2025-10-17 22:45:42,859 - DEBUG - VN ctest-vn1-52446069 UUID is ec7e87b7-9e9d-4be9-a5e8-ddcc1cb91401
2025-10-17 22:45:43,425 - DEBUG - Response for create_port : {'port': {'name': 'fc823e04-b78a-44dc-a9f2-983ef6886e36', 'id': 'fc823e04-b78a-44dc-a9f2-983ef6886e36', 'tenant_id': '7c01088a064d4146b420c054c55d21d0', 'network_id': 'ec7e87b7-9e9d-4be9-a5e8-ddcc1cb91401', 'mac_address': '02:fc:82:3e:04:b7', 'binding:vnic_type': 'normal', 'binding:vif_details': {'port_filter': True}, 'binding:vif_type': 'unbound', 'binding:host_id': None, 'allowed_address_pairs': [], 'fixed_ips': [{'ip_address': '184.58.233.133', 'subnet_id': '873340e9-a78e-4e26-a61f-a591db84ee70'}], 'security_groups': ['ed6536c6-390e-4bc9-b540-ce418cf055f3'], 'admin_state_up': True, 'device_id': '', 'device_owner': '', 'status': 'DOWN', 'port_security_enabled': True, 'description': '', 'created_at': '2025-10-17T22:45:43.231685', 'updated_at': '2025-10-17T22:45:43.308624', 'project_id': '7c01088a064d4146b420c054c55d21d0'}}
2025-10-17 22:45:43,697 - DEBUG - Response for create_port : {'port': {'name': 'e4fb47c4-722d-42c1-b938-2768ba253efa', 'id': 'e4fb47c4-722d-42c1-b938-2768ba253efa', 'tenant_id': '7c01088a064d4146b420c054c55d21d0', 'network_id': 'ec7e87b7-9e9d-4be9-a5e8-ddcc1cb91401', 'mac_address': '02:e4:fb:47:c4:72', 'binding:vnic_type': 'normal', 'binding:vif_details': {'port_filter': True}, 'binding:vif_type': 'unbound', 'binding:host_id': None, 'allowed_address_pairs': [], 'fixed_ips': [{'ip_address': '221.246.33.69', 'subnet_id': 'daf473a1-a412-45d7-833b-3248d3b584f1'}], 'security_groups': ['ed6536c6-390e-4bc9-b540-ce418cf055f3'], 'admin_state_up': True, 'device_id': '', 'device_owner': '', 'status': 'DOWN', 'port_security_enabled': True, 'description': '', 'created_at': '2025-10-17T22:45:43.500509', 'updated_at': '2025-10-17T22:45:43.571724', 'project_id': '7c01088a064d4146b420c054c55d21d0'}}
2025-10-17 22:45:43,820 - DEBUG - Services list from nova: [, , ]
2025-10-17 22:45:44,698 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-juju-os-595-1), Zone: (nova:cn-jenkins-deploy-platform-juju-os-595-1)
2025-10-17 22:45:45,555 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-juju-os-595-1), Zone: (nova:cn-jenkins-deploy-platform-juju-os-595-1)
2025-10-17 22:45:45,556 - INFO - Waiting for VM ctest-vn1-vm1-80950477 to be up..
2025-10-17 22:45:45,660 - DEBUG - VM  is still in BUILD state, Expected: ACTIVE
2025-10-17 22:45:50,808 - DEBUG - VM  is in ACTIVE state now
2025-10-17 22:45:50,808 - INFO - VM name : ctest-vn1-vm1-80950477
2025-10-17 22:45:50,953 - DEBUG - VM ctest-vn1-vm1-80950477 ID is 93c74f6a-f583-4b5b-bd54-f0ea203b5869
2025-10-17 22:45:50,990 - DEBUG - VM ctest-vn1-vm1-80950477 launched on Node cn-jenkins-deploy-platform-juju-os-595-1
2025-10-17 22:45:51,141 - DEBUG - Requesting: https://10.0.0.131:8082/virtual-machine/93c74f6a-f583-4b5b-bd54-f0ea203b5869
2025-10-17 22:45:51,204 - DEBUG - Requesting: https://10.0.0.131:8082/virtual-machine-interface/fc823e04-b78a-44dc-a9f2-983ef6886e36
2025-10-17 22:45:54,686 - 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 1011ms')
2025-10-17 22:45:54,686 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-80950477 failed!
2025-10-17 22:45:54,743 - DEBUG - Gateway for vn admin_domain:ctest-TestPorts-87949552:ctest-vn1-52446069 is 184.58.233.129 and allocation pool is NOT set
2025-10-17 22:45:54,743 - DEBUG - Gateway for vn admin_domain:ctest-TestPorts-87949552:ctest-vn1-52446069 is 221.246.33.65 and allocation pool is NOT set
2025-10-17 22:45:58,847 - 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 1015ms')
2025-10-17 22:45:58,847 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-80950477 failed!
2025-10-17 22:45:58,903 - DEBUG - Gateway for vn admin_domain:ctest-TestPorts-87949552:ctest-vn1-52446069 is 184.58.233.129 and allocation pool is NOT set
2025-10-17 22:45:58,904 - DEBUG - Gateway for vn admin_domain:ctest-TestPorts-87949552:ctest-vn1-52446069 is 221.246.33.65 and allocation pool is NOT set
2025-10-17 22:46:00,995 - 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.62 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=1.01 ms\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1002ms\r\nrtt min/avg/max/mdev = 1.007/4.311/7.616/3.304 ms')
2025-10-17 22:46:00,996 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-80950477 passed
2025-10-17 22:46:01,162 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-17 22:46:01,163 - DEBUG - Waiting to SSH to VM ctest-vn1-vm1-80950477, IP 184.58.233.133, Port 22
2025-10-17 22:46:01,385 - DEBUG - VM ctest-vn1-vm1-80950477 is ready for SSH connections
2025-10-17 22:46:01,385 - INFO - Waiting for VM ctest-vn1-vm2-99668729 to be up..
2025-10-17 22:46:01,537 - DEBUG - VM  is in ACTIVE state now
2025-10-17 22:46:01,538 - INFO - VM name : ctest-vn1-vm2-99668729
2025-10-17 22:46:01,694 - DEBUG - VM ctest-vn1-vm2-99668729 ID is a78ae3e2-f7a6-43c1-80f5-ac02988dddef
2025-10-17 22:46:01,694 - DEBUG - VM ctest-vn1-vm2-99668729 launched on Node cn-jenkins-deploy-platform-juju-os-595-1
2025-10-17 22:46:01,835 - DEBUG - Requesting: https://10.0.0.131:8082/virtual-machine/a78ae3e2-f7a6-43c1-80f5-ac02988dddef
2025-10-17 22:46:01,891 - DEBUG - Requesting: https://10.0.0.131:8082/virtual-machine-interface/e4fb47c4-722d-42c1-b938-2768ba253efa
2025-10-17 22:46:03,367 - 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.29 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=0.541 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.541/1.916/3.291/1.375 ms')
2025-10-17 22:46:03,368 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-vn1-vm2-99668729 passed
2025-10-17 22:46:03,527 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-17 22:46:03,527 - DEBUG - Waiting to SSH to VM ctest-vn1-vm2-99668729, IP 221.246.33.69, Port 22
2025-10-17 22:46:03,741 - DEBUG - VM ctest-vn1-vm2-99668729 is ready for SSH connections
2025-10-17 22:46:03,741 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-17 22:46:03,741 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-17 22:46:03,741 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-17 22:46:03,741 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1  184.58.233.133, host_string: cirros@169.254.0.4, password: cubswin:)gateway: ubuntu@10.0.0.131, gateway password: c0ntrail123
2025-10-17 22:46:03,741 - DEBUG - ping -s 56 -c 3 -W 1  184.58.233.133
2025-10-17 22:46:06,788 - DEBUG - PING 184.58.233.133 (184.58.233.133): 56 data bytes
64 bytes from 184.58.233.133: seq=0 ttl=63 time=3.909 ms
64 bytes from 184.58.233.133: seq=1 ttl=63 time=1.218 ms
64 bytes from 184.58.233.133: seq=2 ttl=63 time=1.400 ms
--- 184.58.233.133 ping statistics ---
3 packets transmitted, 3 packets received, 0% packet loss
round-trip min/avg/max = 1.218/2.175/3.909 ms
2025-10-17 22:46:06,788 - INFO - Ping to IP 184.58.233.133 from VM ctest-vn1-vm2-99668729 passed
2025-10-17 22:46:06,788 - INFO - Detaching port e4fb47c4-722d-42c1-b938-2768ba253efa from VM ctest-vn1-vm2-99668729
2025-10-17 22:46:06,992 - INFO - Deleting VM ctest-vn1-vm2-99668729
2025-10-17 22:46:07,163 - INFO - Detaching port fc823e04-b78a-44dc-a9f2-983ef6886e36 from VM ctest-vn1-vm1-80950477
2025-10-17 22:46:07,247 - INFO - Deleting VM ctest-vn1-vm1-80950477
2025-10-17 22:46:07,690 - DEBUG - Response for delete_port : ()
2025-10-17 22:46:07,989 - DEBUG - Response for delete_port : ()
2025-10-17 22:46:07,989 - INFO - Deleting VN ctest-vn1-52446069 
2025-10-17 22:46:08,210 - DEBUG - Response for deleting network ()
2025-10-17 22:46:08,599 - DEBUG - No XMPP flaps were noticed during the test
2025-10-17 22:46:08,600 - INFO - END TEST : test_ports_specific_subnet_ip : PASSED[0:00:27]
2025-10-17 22:46:08,600 - INFO - --------------------------------------------------------------------------------
2025-10-17 22:46:09,629 - INFO - Deleted project: ctest-TestPorts-87949552, ID : 7c01088a-064d-4146-b420-c054c55d21d0