2025-08-04 03:46:10,344 - INFO - Domain Default found not creating
2025-08-04 03:46:10,507 - INFO - Project ctest-TestSubInterfaces-56426898 not found, creating it
2025-08-04 03:46:11,056 - INFO - Created Project:ctest-TestSubInterfaces-56426898, ID : 6e28ef5e-f074-48e7-8b7c-8b7a4f3a26e7
2025-08-04 03:46:13,377 - DEBUG - Response for create_network : {'network': {'id': 'b6b6ca40-7d97-4c1b-9225-80038f57d686', 'name': 'ctest-vn-89773559', 'tenant_id': '6e28ef5ef07448e78b7c8b7a4f3a26e7', 'project_id': '6e28ef5ef07448e78b7c8b7a4f3a26e7', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestSubInterfaces-56426898', 'ctest-vn-89773559'], 'port_security_enabled': True, 'description': ''}}
2025-08-04 03:46:13,676 - DEBUG - Response for create_subnet : {'subnet': {'id': '0086d794-4300-423d-b8c4-a32c2163af53', 'name': '', 'tenant_id': '6e28ef5ef07448e78b7c8b7a4f3a26e7', 'network_id': 'b6b6ca40-7d97-4c1b-9225-80038f57d686', 'ip_version': 4, 'cidr': '133.151.89.64/26', 'allocation_pools': [{'start': '133.151.89.66', 'end': '133.151.89.126'}], 'gateway_ip': '133.151.89.65', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '133.151.89.66', 'tags': [], 'project_id': '6e28ef5ef07448e78b7c8b7a4f3a26e7'}}
2025-08-04 03:46:13,698 - INFO - Created VN ctest-vn-89773559
2025-08-04 03:46:13,717 - DEBUG - VN ctest-vn-89773559 UUID is b6b6ca40-7d97-4c1b-9225-80038f57d686
2025-08-04 03:46:14,110 - DEBUG - Response for create_network : {'network': {'id': '0f5fe5bb-a283-42e5-8fe2-973fb60cbf4b', 'name': 'ctest-vn-67779414', 'tenant_id': '6e28ef5ef07448e78b7c8b7a4f3a26e7', 'project_id': '6e28ef5ef07448e78b7c8b7a4f3a26e7', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestSubInterfaces-56426898', 'ctest-vn-67779414'], 'port_security_enabled': True, 'description': ''}}
2025-08-04 03:46:14,336 - DEBUG - Response for create_subnet : {'subnet': {'id': '71ebb46c-5080-4c48-bfba-fbe538f3f4e6', 'name': '', 'tenant_id': '6e28ef5ef07448e78b7c8b7a4f3a26e7', 'network_id': '0f5fe5bb-a283-42e5-8fe2-973fb60cbf4b', 'ip_version': 4, 'cidr': '145.15.207.64/26', 'allocation_pools': [{'start': '145.15.207.66', 'end': '145.15.207.126'}], 'gateway_ip': '145.15.207.65', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '145.15.207.66', 'tags': [], 'project_id': '6e28ef5ef07448e78b7c8b7a4f3a26e7'}}
2025-08-04 03:46:14,360 - INFO - Created VN ctest-vn-67779414
2025-08-04 03:46:14,375 - DEBUG - VN ctest-vn-67779414 UUID is 0f5fe5bb-a283-42e5-8fe2-973fb60cbf4b
2025-08-04 03:46:14,763 - DEBUG - Response for create_network : {'network': {'id': 'b1036cfb-5066-456c-b91f-1dd7a2952be7', 'name': 'ctest-vn-50447992', 'tenant_id': '6e28ef5ef07448e78b7c8b7a4f3a26e7', 'project_id': '6e28ef5ef07448e78b7c8b7a4f3a26e7', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestSubInterfaces-56426898', 'ctest-vn-50447992'], 'port_security_enabled': True, 'description': ''}}
2025-08-04 03:46:15,046 - DEBUG - Response for create_subnet : {'subnet': {'id': 'fad26713-e078-4146-8f4d-513c5a9e5d23', 'name': '', 'tenant_id': '6e28ef5ef07448e78b7c8b7a4f3a26e7', 'network_id': 'b1036cfb-5066-456c-b91f-1dd7a2952be7', 'ip_version': 4, 'cidr': '25.155.110.0/26', 'allocation_pools': [{'start': '25.155.110.2', 'end': '25.155.110.62'}], 'gateway_ip': '25.155.110.1', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '25.155.110.2', 'tags': [], 'project_id': '6e28ef5ef07448e78b7c8b7a4f3a26e7'}}
2025-08-04 03:46:15,071 - INFO - Created VN ctest-vn-50447992
2025-08-04 03:46:15,086 - DEBUG - VN ctest-vn-50447992 UUID is b1036cfb-5066-456c-b91f-1dd7a2952be7
2025-08-04 03:46:15,194 - DEBUG - Read virtual machine interface {'fq_name': ['default-domain', 'ctest-TestSubInterfaces-56426898', 'ctest-vmi-92273867']}
2025-08-04 03:46:15,498 - DEBUG - Response for create_port : {'port': {'name': 'ctest-vmi-92273867', 'id': '24d27082-d39d-4cb6-b40f-9968375d79b1', 'tenant_id': '6e28ef5ef07448e78b7c8b7a4f3a26e7', 'network_id': '0f5fe5bb-a283-42e5-8fe2-973fb60cbf4b', 'mac_address': '02:24:d2:70:82:d3', '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': '145.15.207.67', 'subnet_id': '71ebb46c-5080-4c48-bfba-fbe538f3f4e6'}], 'security_groups': ['5c6bb6bd-a233-4a75-83f7-a821c4c5dc4e'], 'admin_state_up': True, 'device_id': '', 'device_owner': '', 'status': 'DOWN', 'port_security_enabled': True, 'description': '', 'project_id': '6e28ef5ef07448e78b7c8b7a4f3a26e7'}}
2025-08-04 03:46:15,498 - DEBUG - Created port 24d27082-d39d-4cb6-b40f-9968375d79b1
2025-08-04 03:46:15,587 - DEBUG - Read virtual machine interface {'fq_name': ['default-domain', 'ctest-TestSubInterfaces-56426898', 'ctest-vmi-29478448']}
2025-08-04 03:46:16,096 - DEBUG - Created port 5881dbdb-fdd2-4f50-b95e-93a197254ee7
2025-08-04 03:46:16,220 - DEBUG - Read virtual machine interface {'fq_name': ['default-domain', 'ctest-TestSubInterfaces-56426898', 'ctest-vmi-26144278']}
2025-08-04 03:46:16,561 - DEBUG - Response for create_port : {'port': {'name': 'ctest-vmi-26144278', 'id': 'f80db8bb-d922-4954-9853-29fa5f47f226', 'tenant_id': '6e28ef5ef07448e78b7c8b7a4f3a26e7', 'network_id': '0f5fe5bb-a283-42e5-8fe2-973fb60cbf4b', 'mac_address': '02:f8:0d:b8:bb:d9', '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': '145.15.207.68', 'subnet_id': '71ebb46c-5080-4c48-bfba-fbe538f3f4e6'}], 'security_groups': ['5c6bb6bd-a233-4a75-83f7-a821c4c5dc4e'], 'admin_state_up': True, 'device_id': '', 'device_owner': '', 'status': 'DOWN', 'port_security_enabled': True, 'description': '', 'project_id': '6e28ef5ef07448e78b7c8b7a4f3a26e7'}}
2025-08-04 03:46:16,561 - DEBUG - Created port f80db8bb-d922-4954-9853-29fa5f47f226
2025-08-04 03:46:16,637 - DEBUG - Read virtual machine interface {'fq_name': ['default-domain', 'ctest-TestSubInterfaces-56426898', 'ctest-vmi-08892965']}
2025-08-04 03:46:17,112 - DEBUG - Created port fa94f8e3-5c73-41f3-8dd4-7ee76b6134bc
2025-08-04 03:46:17,240 - DEBUG - Read virtual machine interface {'fq_name': ['default-domain', 'ctest-TestSubInterfaces-56426898', 'ctest-vmi-36217005']}
2025-08-04 03:46:17,604 - DEBUG - Response for create_port : {'port': {'name': 'ctest-vmi-36217005', 'id': '90495981-3924-408a-aeeb-273c8cab2c1e', 'tenant_id': '6e28ef5ef07448e78b7c8b7a4f3a26e7', 'network_id': '0f5fe5bb-a283-42e5-8fe2-973fb60cbf4b', 'mac_address': '02:90:49:59:81:39', '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': '145.15.207.69', 'subnet_id': '71ebb46c-5080-4c48-bfba-fbe538f3f4e6'}], 'security_groups': ['5c6bb6bd-a233-4a75-83f7-a821c4c5dc4e'], 'admin_state_up': True, 'device_id': '', 'device_owner': '', 'status': 'DOWN', 'port_security_enabled': True, 'description': '', 'project_id': '6e28ef5ef07448e78b7c8b7a4f3a26e7'}}
2025-08-04 03:46:17,604 - DEBUG - Created port 90495981-3924-408a-aeeb-273c8cab2c1e
2025-08-04 03:46:17,685 - DEBUG - Read virtual machine interface {'fq_name': ['default-domain', 'ctest-TestSubInterfaces-56426898', 'ctest-vmi-01774649']}
2025-08-04 03:46:18,188 - DEBUG - Created port dfa93ad9-eb60-4d1b-a555-221ccadda2b2
2025-08-04 03:46:18,308 - INFO - ================================================================================
2025-08-04 03:46:18,308 - INFO - STARTING TEST : test_vlan_interface_2
2025-08-04 03:46:18,308 - INFO - TEST DESCRIPTION :
Test ping/hping between tagged-untagged vmis across VNs
2025-08-04 03:46:19,587 - DEBUG - Nothing to compare xmpp stats {'10.0.0.41': {'10.20.0.18': '0', '10.20.0.129': '0'}, '10.0.0.57': {'10.20.0.193': '0', '10.20.0.18': '0'}} with
2025-08-04 03:46:19,587 - INFO - Initial checks done. Running the testcase now
2025-08-04 03:46:19,587 - INFO -
2025-08-04 03:46:19,664 - DEBUG - Services list from nova: [, , , ]
2025-08-04 03:46:20,244 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-3750-2), Zone: (nova:an-jenkins-deploy-platform-ansible-os-3750-2)
2025-08-04 03:46:21,514 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-3750-1), Zone: (nova:an-jenkins-deploy-platform-ansible-os-3750-1)
2025-08-04 03:46:22,277 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-3750-2), Zone: (nova:an-jenkins-deploy-platform-ansible-os-3750-2)
2025-08-04 03:46:22,436 - INFO - Adding interface with subnet_id 0086d794-4300-423d-b8c4-a32c2163af53, port_id None to router 1cf52d2e-9b1d-41d8-9881-40529533721c
2025-08-04 03:46:22,898 - INFO - Adding interface with subnet_id fad26713-e078-4146-8f4d-513c5a9e5d23, port_id None to router 1cf52d2e-9b1d-41d8-9881-40529533721c
2025-08-04 03:46:23,387 - INFO - Waiting for VM ctest-TestSubInterfaces-56426898-53133123 to be up..
2025-08-04 03:46:23,527 - DEBUG - VM is in ACTIVE state now
2025-08-04 03:46:23,527 - INFO - VM name : ctest-TestSubInterfaces-56426898-53133123
2025-08-04 03:46:23,616 - DEBUG - VM ctest-TestSubInterfaces-56426898-53133123 ID is 0afd1fb2-4c60-43f0-9937-7260f982a4cf
2025-08-04 03:46:23,644 - DEBUG - VM ctest-TestSubInterfaces-56426898-53133123 launched on Node an-jenkins-deploy-platform-ansible-os-3750-2
2025-08-04 03:46:23,747 - DEBUG - Requesting: http://10.0.0.61:8082/virtual-machine/0afd1fb2-4c60-43f0-9937-7260f982a4cf
2025-08-04 03:46:24,058 - DEBUG - Requesting: http://10.0.0.61:8082/virtual-machine/0afd1fb2-4c60-43f0-9937-7260f982a4cf
2025-08-04 03:46:24,097 - DEBUG - Requesting: http://10.0.0.61:8082/virtual-machine-interface/24d27082-d39d-4cb6-b40f-9968375d79b1
2025-08-04 03:46:27,355 - 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-04 03:46:27,355 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestSubInterfaces-56426898-53133123 failed!
2025-08-04 03:46:27,373 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-56426898:ctest-vn-67779414 is 145.15.207.65 and allocation pool is NOT set
2025-08-04 03:46:31,456 - 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-04 03:46:31,456 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestSubInterfaces-56426898-53133123 failed!
2025-08-04 03:46:31,472 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-56426898:ctest-vn-67779414 is 145.15.207.65 and allocation pool is NOT set
2025-08-04 03:46:35,546 - 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-08-04 03:46:35,546 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestSubInterfaces-56426898-53133123 failed!
2025-08-04 03:46:35,569 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-56426898:ctest-vn-67779414 is 145.15.207.65 and allocation pool is NOT set
2025-08-04 03:46:39,651 - 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 1019ms')
2025-08-04 03:46:39,651 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestSubInterfaces-56426898-53133123 failed!
2025-08-04 03:46:39,670 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-56426898:ctest-vn-67779414 is 145.15.207.65 and allocation pool is NOT set
2025-08-04 03:46:43,748 - 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-08-04 03:46:43,748 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestSubInterfaces-56426898-53133123 failed!
2025-08-04 03:46:43,771 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-56426898:ctest-vn-67779414 is 145.15.207.65 and allocation pool is NOT set
2025-08-04 03:46:47,841 - 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 1008ms')
2025-08-04 03:46:47,841 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestSubInterfaces-56426898-53133123 failed!
2025-08-04 03:46:47,859 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-56426898:ctest-vn-67779414 is 145.15.207.65 and allocation pool is NOT set
2025-08-04 03:46:51,938 - 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-08-04 03:46:51,938 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestSubInterfaces-56426898-53133123 failed!
2025-08-04 03:46:51,958 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-56426898:ctest-vn-67779414 is 145.15.207.65 and allocation pool is NOT set
2025-08-04 03:46:56,038 - 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-08-04 03:46:56,038 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestSubInterfaces-56426898-53133123 failed!
2025-08-04 03:46:56,057 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-56426898:ctest-vn-67779414 is 145.15.207.65 and allocation pool is NOT set
2025-08-04 03:47:00,131 - 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-04 03:47:00,131 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestSubInterfaces-56426898-53133123 failed!
2025-08-04 03:47:00,150 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-56426898:ctest-vn-67779414 is 145.15.207.65 and allocation pool is NOT set
2025-08-04 03:47:04,239 - 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-08-04 03:47:04,240 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestSubInterfaces-56426898-53133123 failed!
2025-08-04 03:47:04,262 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-56426898:ctest-vn-67779414 is 145.15.207.65 and allocation pool is NOT set
2025-08-04 03:47:08,349 - 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=2 ttl=63 time=11.8 ms\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 1 received, 50% packet loss, time 1026ms\r\nrtt min/avg/max/mdev = 11.763/11.763/11.763/0.000 ms')
2025-08-04 03:47:08,349 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-TestSubInterfaces-56426898-53133123 passed
2025-08-04 03:47:08,470 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-04 03:47:08,470 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-56426898-53133123, IP 145.15.207.67, Port 22
2025-08-04 03:47:08,549 - 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-04 03:47:08,654 - DEBUG - VM ctest-TestSubInterfaces-56426898-53133123 is NOT ready for SSH connections, VM status: ACTIVE
2025-08-04 03:47:13,655 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-04 03:47:13,655 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-56426898-53133123, IP 145.15.207.67, Port 22
2025-08-04 03:47:13,712 - 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-04 03:47:13,828 - DEBUG - VM ctest-TestSubInterfaces-56426898-53133123 is NOT ready for SSH connections, VM status: ACTIVE
2025-08-04 03:47:18,828 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-04 03:47:18,828 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-56426898-53133123, IP 145.15.207.67, Port 22
2025-08-04 03:47:18,895 - 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-04 03:47:18,993 - DEBUG - VM ctest-TestSubInterfaces-56426898-53133123 is NOT ready for SSH connections, VM status: ACTIVE
2025-08-04 03:47:23,994 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-04 03:47:23,994 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-56426898-53133123, IP 145.15.207.67, Port 22
2025-08-04 03:47:24,063 - 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-04 03:47:24,186 - DEBUG - VM ctest-TestSubInterfaces-56426898-53133123 is NOT ready for SSH connections, VM status: ACTIVE
2025-08-04 03:47:29,187 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-04 03:47:29,187 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-56426898-53133123, IP 145.15.207.67, Port 22
2025-08-04 03:47:29,348 - DEBUG - VM ctest-TestSubInterfaces-56426898-53133123 is ready for SSH connections
2025-08-04 03:47:29,348 - INFO - Waiting for VM ctest-TestSubInterfaces-56426898-15238480 to be up..
2025-08-04 03:47:29,461 - DEBUG - VM is in ACTIVE state now
2025-08-04 03:47:29,461 - INFO - VM name : ctest-TestSubInterfaces-56426898-15238480
2025-08-04 03:47:29,550 - DEBUG - VM ctest-TestSubInterfaces-56426898-15238480 ID is 37b411e9-d789-47d5-8940-4e0757e1976d
2025-08-04 03:47:29,550 - DEBUG - VM ctest-TestSubInterfaces-56426898-15238480 launched on Node an-jenkins-deploy-platform-ansible-os-3750-1
2025-08-04 03:47:29,647 - DEBUG - Requesting: http://10.0.0.61:8082/virtual-machine/37b411e9-d789-47d5-8940-4e0757e1976d
2025-08-04 03:47:29,661 - DEBUG - Requesting: http://10.0.0.61:8082/virtual-machine-interface/e51582a1-7cb1-4363-93c4-133a104b8be5
2025-08-04 03:47:30,897 - 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.17 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=3.51 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 = 3.509/5.337/7.166/1.828 ms')
2025-08-04 03:47:30,898 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-TestSubInterfaces-56426898-15238480 passed
2025-08-04 03:47:31,028 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-04 03:47:31,028 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-56426898-15238480, IP 25.155.110.4, Port 22
2025-08-04 03:47:31,200 - DEBUG - VM ctest-TestSubInterfaces-56426898-15238480 is ready for SSH connections
2025-08-04 03:47:31,200 - INFO - Waiting for VM ctest-TestSubInterfaces-56426898-53568411 to be up..
2025-08-04 03:47:31,299 - DEBUG - VM is in ACTIVE state now
2025-08-04 03:47:31,300 - INFO - VM name : ctest-TestSubInterfaces-56426898-53568411
2025-08-04 03:47:31,408 - DEBUG - VM ctest-TestSubInterfaces-56426898-53568411 ID is 1ceaf472-ec41-4f44-adfe-d75e07efe826
2025-08-04 03:47:31,408 - DEBUG - VM ctest-TestSubInterfaces-56426898-53568411 launched on Node an-jenkins-deploy-platform-ansible-os-3750-2
2025-08-04 03:47:31,526 - DEBUG - Requesting: http://10.0.0.61:8082/virtual-machine/1ceaf472-ec41-4f44-adfe-d75e07efe826
2025-08-04 03:47:31,540 - DEBUG - Requesting: http://10.0.0.61:8082/virtual-machine-interface/90495981-3924-408a-aeeb-273c8cab2c1e
2025-08-04 03:47:32,790 - DEBUG - (True, 'PING 169.254.0.5 (169.254.0.5) 56(84) bytes of data.\r\n64 bytes from 169.254.0.5: icmp_seq=1 ttl=63 time=2.99 ms\r\n64 bytes from 169.254.0.5: icmp_seq=2 ttl=63 time=0.352 ms\r\n\r\n--- 169.254.0.5 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1001ms\r\nrtt min/avg/max/mdev = 0.352/1.671/2.990/1.319 ms')
2025-08-04 03:47:32,791 - INFO - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-56426898-53568411 passed
2025-08-04 03:47:32,924 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-04 03:47:32,924 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-56426898-53568411, IP 145.15.207.69, Port 22
2025-08-04 03:47:33,091 - DEBUG - VM ctest-TestSubInterfaces-56426898-53568411 is ready for SSH connections
2025-08-04 03:47:33,091 - DEBUG - Running remote_cmd, Cmd : ifconfig -a| grep 133.151.89.67 -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-04 03:47:33,092 - DEBUG - ifconfig -a| grep 133.151.89.67 -A2 -B4| grep -i 'hwaddr\|flags' | awk '{print $1}' | cut -d ':' -f 1
2025-08-04 03:47:50,795 - DEBUG - None
2025-08-04 03:47:55,795 - DEBUG - Running remote_cmd, Cmd : ifconfig -a| grep 133.151.89.67 -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-04 03:47:55,796 - DEBUG - ifconfig -a| grep 133.151.89.67 -A2 -B4| grep -i 'hwaddr\|flags' | awk '{print $1}' | cut -d ':' -f 1
2025-08-04 03:47:57,201 - DEBUG - None
2025-08-04 03:48:02,202 - DEBUG - Running remote_cmd, Cmd : ifconfig -a| grep 133.151.89.67 -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-04 03:48:02,203 - DEBUG - ifconfig -a| grep 133.151.89.67 -A2 -B4| grep -i 'hwaddr\|flags' | awk '{print $1}' | cut -d ':' -f 1
2025-08-04 03:48:03,708 - DEBUG - eth0.100
2025-08-04 03:48:03,709 - INFO - Interface eth0.100 is found on VM 0afd1fb2-4c60-43f0-9937-7260f982a4cf
2025-08-04 03:48:03,709 - DEBUG - Running remote_cmd, Cmd : ifconfig -a| grep 25.155.110.3 -A2 -B4| grep -i 'hwaddr\|flags' | awk '{print $1}' | cut -d ':' -f 1, host_string: ubuntu@169.254.0.5, password: ubuntugateway: ubuntu@10.0.0.57, gateway password: c0ntrail123
2025-08-04 03:48:03,709 - DEBUG - ifconfig -a| grep 25.155.110.3 -A2 -B4| grep -i 'hwaddr\|flags' | awk '{print $1}' | cut -d ':' -f 1
2025-08-04 03:48:40,280 - DEBUG - eth0.100
2025-08-04 03:48:40,280 - INFO - Interface eth0.100 is found on VM 1ceaf472-ec41-4f44-adfe-d75e07efe826
2025-08-04 03:48:40,280 - DEBUG - Running remote_cmd, Cmd : route add -net 25.155.110.0/26 dev eth0.100, host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.57, gateway password: c0ntrail123
2025-08-04 03:48:40,280 - DEBUG - route add -net 25.155.110.0/26 dev eth0.100
2025-08-04 03:48:40,783 - DEBUG - None
2025-08-04 03:48:40,783 - DEBUG - Running remote_cmd, Cmd : route add -net 133.151.89.64/26 dev eth0.100, host_string: ubuntu@169.254.0.5, password: ubuntugateway: ubuntu@10.0.0.57, gateway password: c0ntrail123
2025-08-04 03:48:40,783 - DEBUG - route add -net 133.151.89.64/26 dev eth0.100
2025-08-04 03:48:41,299 - DEBUG - None
2025-08-04 03:48:41,300 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-04 03:48:41,300 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 25.155.110.4, host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.57, gateway password: c0ntrail123
2025-08-04 03:48:41,300 - DEBUG - ping -s 56 -c 3 -W 1 25.155.110.4
2025-08-04 03:48:43,756 - DEBUG - PING 25.155.110.4 (25.155.110.4) 56(84) bytes of data.
64 bytes from 25.155.110.4: icmp_req=1 ttl=63 time=8.45 ms
64 bytes from 25.155.110.4: icmp_req=2 ttl=63 time=1.67 ms
64 bytes from 25.155.110.4: icmp_req=3 ttl=63 time=1.03 ms
--- 25.155.110.4 ping statistics ---
3 packets transmitted, 3 received, 0% packet loss, time 2005ms
rtt min/avg/max/mdev = 1.032/3.718/8.450/3.356 ms
2025-08-04 03:48:43,756 - INFO - Ping to IP 25.155.110.4 from VM ctest-TestSubInterfaces-56426898-53133123 passed
2025-08-04 03:48:43,756 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 25.155.110.3, host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.57, gateway password: c0ntrail123
2025-08-04 03:48:43,756 - DEBUG - ping -s 56 -c 3 -W 1 25.155.110.3
2025-08-04 03:48:46,230 - DEBUG - PING 25.155.110.3 (25.155.110.3) 56(84) bytes of data.
64 bytes from 25.155.110.3: icmp_req=1 ttl=63 time=18.6 ms
64 bytes from 25.155.110.3: icmp_req=2 ttl=63 time=0.858 ms
64 bytes from 25.155.110.3: icmp_req=3 ttl=63 time=0.772 ms
--- 25.155.110.3 ping statistics ---
3 packets transmitted, 3 received, 0% packet loss, time 2003ms
rtt min/avg/max/mdev = 0.772/6.745/18.606/8.387 ms
2025-08-04 03:48:46,230 - INFO - Ping to IP 25.155.110.3 from VM ctest-TestSubInterfaces-56426898-53133123 passed
2025-08-04 03:48:46,230 - INFO - Deleting interface with subnet_id fad26713-e078-4146-8f4d-513c5a9e5d23, port_id None from router 1cf52d2e-9b1d-41d8-9881-40529533721c
2025-08-04 03:48:46,467 - INFO - Deleting interface with subnet_id 0086d794-4300-423d-b8c4-a32c2163af53, port_id None from router 1cf52d2e-9b1d-41d8-9881-40529533721c
2025-08-04 03:48:46,765 - INFO - Detaching port 90495981-3924-408a-aeeb-273c8cab2c1e from VM ctest-TestSubInterfaces-56426898-53568411
2025-08-04 03:48:46,828 - INFO - Deleting VM ctest-TestSubInterfaces-56426898-53568411
2025-08-04 03:48:46,932 - INFO - Deleting VM ctest-TestSubInterfaces-56426898-15238480
2025-08-04 03:48:47,017 - INFO - Detaching port 24d27082-d39d-4cb6-b40f-9968375d79b1 from VM ctest-TestSubInterfaces-56426898-53133123
2025-08-04 03:48:47,054 - INFO - Deleting VM ctest-TestSubInterfaces-56426898-53133123
2025-08-04 03:48:48,427 - DEBUG - No XMPP flaps were noticed during the test
2025-08-04 03:48:48,427 - INFO - END TEST : test_vlan_interface_2 : PASSED[0:02:30]
2025-08-04 03:48:48,427 - INFO - --------------------------------------------------------------------------------
2025-08-04 03:48:48,549 - INFO - Deleted port dfa93ad9-eb60-4d1b-a555-221ccadda2b2
2025-08-04 03:48:48,774 - DEBUG - Response for delete_port : ()
2025-08-04 03:48:48,774 - INFO - Deleted port 90495981-3924-408a-aeeb-273c8cab2c1e
2025-08-04 03:48:48,910 - INFO - Deleted port fa94f8e3-5c73-41f3-8dd4-7ee76b6134bc
2025-08-04 03:48:49,077 - DEBUG - Response for delete_port : ()
2025-08-04 03:48:49,077 - INFO - Deleted port f80db8bb-d922-4954-9853-29fa5f47f226
2025-08-04 03:48:49,207 - INFO - Deleted port 5881dbdb-fdd2-4f50-b95e-93a197254ee7
2025-08-04 03:48:49,443 - DEBUG - Response for delete_port : ()
2025-08-04 03:48:49,443 - INFO - Deleted port 24d27082-d39d-4cb6-b40f-9968375d79b1
2025-08-04 03:48:49,443 - INFO - Deleting VN ctest-vn-50447992
2025-08-04 03:48:49,607 - DEBUG - Response for deleting network ()
2025-08-04 03:48:49,607 - INFO - Deleting VN ctest-vn-67779414
2025-08-04 03:48:49,792 - DEBUG - Response for deleting network ()
2025-08-04 03:48:49,792 - INFO - Deleting VN ctest-vn-89773559
2025-08-04 03:48:49,974 - DEBUG - Response for deleting network ()
2025-08-04 03:48:51,342 - INFO - Deleted project: ctest-TestSubInterfaces-56426898, ID : 6e28ef5e-f074-48e7-8b7c-8b7a4f3a26e7