2026-05-28 00:30:05,109 - INFO - Domain Default found not creating
2026-05-28 00:30:05,408 - INFO - Project ctest-TestQos-21636122 not found, creating it
2026-05-28 00:30:06,113 - INFO - Created Project:ctest-TestQos-21636122, ID : 81ee9689-070d-4538-81e2-b6f434e67ceb
2026-05-28 00:30:09,567 - DEBUG - Response for create_network : {'network': {'id': '1a0b2512-e3f3-4bfe-87b5-8227ce90732f', 'name': 'ctest-vn-71403495', 'tenant_id': '81ee9689070d453881e2b6f434e67ceb', 'project_id': '81ee9689070d453881e2b6f434e67ceb', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestQos-21636122', 'ctest-vn-71403495'], 'port_security_enabled': True, 'description': ''}}
2026-05-28 00:30:09,939 - DEBUG - Response for create_subnet : {'subnet': {'id': '2c9fa57c-9ac1-430f-a4f4-0b9900428c32', 'name': '', 'tenant_id': '81ee9689070d453881e2b6f434e67ceb', 'network_id': '1a0b2512-e3f3-4bfe-87b5-8227ce90732f', 'ip_version': 4, 'cidr': '111.163.50.64/26', 'allocation_pools': [{'start': '111.163.50.66', 'end': '111.163.50.126'}], 'gateway_ip': '111.163.50.65', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '111.163.50.66', 'tags': [], 'project_id': '81ee9689070d453881e2b6f434e67ceb'}}
2026-05-28 00:30:10,189 - DEBUG - Response for create_subnet : {'subnet': {'id': 'dd67b5e8-6575-4610-9eac-fa1288d1154c', 'name': '', 'tenant_id': '81ee9689070d453881e2b6f434e67ceb', 'network_id': '1a0b2512-e3f3-4bfe-87b5-8227ce90732f', 'ip_version': 6, 'cidr': '25dd:5445:3f85:8d93:f965:eecb::/96', 'allocation_pools': [{'start': '25dd:5445:3f85:8d93:f965:eecb:0:2', 'end': '25dd:5445:3f85:8d93:f965:eecb:ffff:fffe'}], 'gateway_ip': '25dd:5445:3f85:8d93:f965:eecb:0:1', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '25dd:5445:3f85:8d93:f965:eecb:0:2', 'tags': [], 'project_id': '81ee9689070d453881e2b6f434e67ceb'}}
2026-05-28 00:30:10,232 - INFO - Created VN ctest-vn-71403495
2026-05-28 00:30:10,253 - DEBUG - VN ctest-vn-71403495 UUID is 1a0b2512-e3f3-4bfe-87b5-8227ce90732f
2026-05-28 00:30:10,843 - DEBUG - Response for create_network : {'network': {'id': '1c0643fd-7d2f-4812-a44b-f0c741583b89', 'name': 'ctest-vn-34842345', 'tenant_id': '81ee9689070d453881e2b6f434e67ceb', 'project_id': '81ee9689070d453881e2b6f434e67ceb', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestQos-21636122', 'ctest-vn-34842345'], 'port_security_enabled': True, 'description': ''}}
2026-05-28 00:30:11,126 - DEBUG - Response for create_subnet : {'subnet': {'id': 'ddc8a6c7-babb-4787-8071-9f1e54de6beb', 'name': '', 'tenant_id': '81ee9689070d453881e2b6f434e67ceb', 'network_id': '1c0643fd-7d2f-4812-a44b-f0c741583b89', 'ip_version': 4, 'cidr': '84.56.26.0/26', 'allocation_pools': [{'start': '84.56.26.2', 'end': '84.56.26.62'}], 'gateway_ip': '84.56.26.1', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '84.56.26.2', 'tags': [], 'project_id': '81ee9689070d453881e2b6f434e67ceb'}}
2026-05-28 00:30:11,410 - DEBUG - Response for create_subnet : {'subnet': {'id': '9109ded4-0d49-4e2e-b05b-8356fcb9bed7', 'name': '', 'tenant_id': '81ee9689070d453881e2b6f434e67ceb', 'network_id': '1c0643fd-7d2f-4812-a44b-f0c741583b89', 'ip_version': 6, 'cidr': '3acf:33a0:bc5a:bb2c:28f2:976d::/96', 'allocation_pools': [{'start': '3acf:33a0:bc5a:bb2c:28f2:976d:0:2', 'end': '3acf:33a0:bc5a:bb2c:28f2:976d:ffff:fffe'}], 'gateway_ip': '3acf:33a0:bc5a:bb2c:28f2:976d:0:1', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '3acf:33a0:bc5a:bb2c:28f2:976d:0:2', 'tags': [], 'project_id': '81ee9689070d453881e2b6f434e67ceb'}}
2026-05-28 00:30:11,448 - INFO - Created VN ctest-vn-34842345
2026-05-28 00:30:11,466 - DEBUG - VN ctest-vn-34842345 UUID is 1c0643fd-7d2f-4812-a44b-f0c741583b89
2026-05-28 00:30:11,717 - DEBUG - Services list from nova: [, , , ]
2026-05-28 00:30:13,351 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-5836-1), Zone: (nova:an-jenkins-deploy-platform-ansible-os-5836-1)
2026-05-28 00:30:15,590 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-5836-2), Zone: (nova:an-jenkins-deploy-platform-ansible-os-5836-2)
2026-05-28 00:30:17,778 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-5836-2), Zone: (nova:an-jenkins-deploy-platform-ansible-os-5836-2)
2026-05-28 00:30:17,778 - INFO - Waiting for VM ctest-TestQos-21636122-10964073 to be up..
2026-05-28 00:30:17,922 - DEBUG - VM is in ACTIVE state now
2026-05-28 00:30:17,922 - INFO - VM name : ctest-TestQos-21636122-10964073
2026-05-28 00:30:18,070 - DEBUG - VM ctest-TestQos-21636122-10964073 ID is 22b0ded8-b229-461d-88e1-503599e9d61d
2026-05-28 00:30:18,115 - DEBUG - VM ctest-TestQos-21636122-10964073 launched on Node an-jenkins-deploy-platform-ansible-os-5836-1
2026-05-28 00:30:18,254 - DEBUG - Requesting: http://10.0.0.22:8082/virtual-machine/22b0ded8-b229-461d-88e1-503599e9d61d
2026-05-28 00:30:18,825 - DEBUG - Requesting: http://10.0.0.22:8082/virtual-machine/22b0ded8-b229-461d-88e1-503599e9d61d
2026-05-28 00:30:18,892 - DEBUG - Requesting: http://10.0.0.22:8082/virtual-machine-interface/2a5add28-61f4-4423-86e0-c222212e85d1
2026-05-28 00:30:22,110 - 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')
2026-05-28 00:30:22,111 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestQos-21636122-10964073 failed!
2026-05-28 00:30:22,132 - DEBUG - Gateway for vn default-domain:ctest-TestQos-21636122:ctest-vn-71403495 is 111.163.50.65 and allocation pool is NOT set
2026-05-28 00:30:22,132 - DEBUG - Gateway for vn default-domain:ctest-TestQos-21636122:ctest-vn-71403495 is 25dd:5445:3f85:8d93:f965:eecb:0:1 and allocation pool is NOT set
2026-05-28 00:30:26,211 - 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')
2026-05-28 00:30:26,211 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestQos-21636122-10964073 failed!
2026-05-28 00:30:26,237 - DEBUG - Gateway for vn default-domain:ctest-TestQos-21636122:ctest-vn-71403495 is 111.163.50.65 and allocation pool is NOT set
2026-05-28 00:30:26,237 - DEBUG - Gateway for vn default-domain:ctest-TestQos-21636122:ctest-vn-71403495 is 25dd:5445:3f85:8d93:f965:eecb:0:1 and allocation pool is NOT set
2026-05-28 00:30:30,309 - 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 1006ms')
2026-05-28 00:30:30,309 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestQos-21636122-10964073 failed!
2026-05-28 00:30:30,331 - DEBUG - Gateway for vn default-domain:ctest-TestQos-21636122:ctest-vn-71403495 is 111.163.50.65 and allocation pool is NOT set
2026-05-28 00:30:30,331 - DEBUG - Gateway for vn default-domain:ctest-TestQos-21636122:ctest-vn-71403495 is 25dd:5445:3f85:8d93:f965:eecb:0:1 and allocation pool is NOT set
2026-05-28 00:30:34,404 - 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')
2026-05-28 00:30:34,404 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestQos-21636122-10964073 failed!
2026-05-28 00:30:34,422 - DEBUG - Gateway for vn default-domain:ctest-TestQos-21636122:ctest-vn-71403495 is 111.163.50.65 and allocation pool is NOT set
2026-05-28 00:30:34,422 - DEBUG - Gateway for vn default-domain:ctest-TestQos-21636122:ctest-vn-71403495 is 25dd:5445:3f85:8d93:f965:eecb:0:1 and allocation pool is NOT set
2026-05-28 00:30:38,497 - 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')
2026-05-28 00:30:38,498 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestQos-21636122-10964073 failed!
2026-05-28 00:30:38,517 - DEBUG - Gateway for vn default-domain:ctest-TestQos-21636122:ctest-vn-71403495 is 111.163.50.65 and allocation pool is NOT set
2026-05-28 00:30:38,517 - DEBUG - Gateway for vn default-domain:ctest-TestQos-21636122:ctest-vn-71403495 is 25dd:5445:3f85:8d93:f965:eecb:0:1 and allocation pool is NOT set
2026-05-28 00:30:42,597 - 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')
2026-05-28 00:30:42,597 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestQos-21636122-10964073 failed!
2026-05-28 00:30:42,615 - DEBUG - Gateway for vn default-domain:ctest-TestQos-21636122:ctest-vn-71403495 is 111.163.50.65 and allocation pool is NOT set
2026-05-28 00:30:42,616 - DEBUG - Gateway for vn default-domain:ctest-TestQos-21636122:ctest-vn-71403495 is 25dd:5445:3f85:8d93:f965:eecb:0:1 and allocation pool is NOT set
2026-05-28 00:30:46,691 - 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')
2026-05-28 00:30:46,691 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestQos-21636122-10964073 failed!
2026-05-28 00:30:46,712 - DEBUG - Gateway for vn default-domain:ctest-TestQos-21636122:ctest-vn-71403495 is 111.163.50.65 and allocation pool is NOT set
2026-05-28 00:30:46,713 - DEBUG - Gateway for vn default-domain:ctest-TestQos-21636122:ctest-vn-71403495 is 25dd:5445:3f85:8d93:f965:eecb:0:1 and allocation pool is NOT set
2026-05-28 00:30:50,790 - 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 1006ms')
2026-05-28 00:30:50,791 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestQos-21636122-10964073 failed!
2026-05-28 00:30:50,815 - DEBUG - Gateway for vn default-domain:ctest-TestQos-21636122:ctest-vn-71403495 is 111.163.50.65 and allocation pool is NOT set
2026-05-28 00:30:50,815 - DEBUG - Gateway for vn default-domain:ctest-TestQos-21636122:ctest-vn-71403495 is 25dd:5445:3f85:8d93:f965:eecb:0:1 and allocation pool is NOT set
2026-05-28 00:30:54,911 - 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 1028ms')
2026-05-28 00:30:54,911 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestQos-21636122-10964073 failed!
2026-05-28 00:30:54,933 - DEBUG - Gateway for vn default-domain:ctest-TestQos-21636122:ctest-vn-71403495 is 111.163.50.65 and allocation pool is NOT set
2026-05-28 00:30:54,933 - DEBUG - Gateway for vn default-domain:ctest-TestQos-21636122:ctest-vn-71403495 is 25dd:5445:3f85:8d93:f965:eecb:0:1 and allocation pool is NOT set
2026-05-28 00:30:59,019 - 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')
2026-05-28 00:30:59,019 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestQos-21636122-10964073 failed!
2026-05-28 00:30:59,039 - DEBUG - Gateway for vn default-domain:ctest-TestQos-21636122:ctest-vn-71403495 is 111.163.50.65 and allocation pool is NOT set
2026-05-28 00:30:59,039 - DEBUG - Gateway for vn default-domain:ctest-TestQos-21636122:ctest-vn-71403495 is 25dd:5445:3f85:8d93:f965:eecb:0:1 and allocation pool is NOT set
2026-05-28 00:31:01,117 - 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=9.00 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=0.993 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.993/4.995/8.998/4.002 ms')
2026-05-28 00:31:01,117 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-TestQos-21636122-10964073 passed
2026-05-28 00:31:01,208 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-05-28 00:31:01,208 - DEBUG - Waiting to SSH to VM ctest-TestQos-21636122-10964073, IP 111.163.50.67, Port 22
2026-05-28 00:31:01,279 - 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': ''}
2026-05-28 00:31:01,406 - DEBUG - VM ctest-TestQos-21636122-10964073 is NOT ready for SSH connections, VM status: ACTIVE
2026-05-28 00:31:06,406 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-05-28 00:31:06,406 - DEBUG - Waiting to SSH to VM ctest-TestQos-21636122-10964073, IP 111.163.50.67, Port 22
2026-05-28 00:31:06,474 - 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': ''}
2026-05-28 00:31:06,613 - DEBUG - VM ctest-TestQos-21636122-10964073 is NOT ready for SSH connections, VM status: ACTIVE
2026-05-28 00:31:11,614 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-05-28 00:31:11,615 - DEBUG - Waiting to SSH to VM ctest-TestQos-21636122-10964073, IP 111.163.50.67, Port 22
2026-05-28 00:31:11,686 - 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': ''}
2026-05-28 00:31:11,825 - DEBUG - VM ctest-TestQos-21636122-10964073 is NOT ready for SSH connections, VM status: ACTIVE
2026-05-28 00:31:16,826 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-05-28 00:31:16,826 - DEBUG - Waiting to SSH to VM ctest-TestQos-21636122-10964073, IP 111.163.50.67, Port 22
2026-05-28 00:31:16,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': ''}
2026-05-28 00:31:17,013 - DEBUG - VM ctest-TestQos-21636122-10964073 is NOT ready for SSH connections, VM status: ACTIVE
2026-05-28 00:31:22,014 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-05-28 00:31:22,014 - DEBUG - Waiting to SSH to VM ctest-TestQos-21636122-10964073, IP 111.163.50.67, Port 22
2026-05-28 00:31:22,077 - 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': ''}
2026-05-28 00:31:22,215 - DEBUG - VM ctest-TestQos-21636122-10964073 is NOT ready for SSH connections, VM status: ACTIVE
2026-05-28 00:31:27,216 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-05-28 00:31:27,216 - DEBUG - Waiting to SSH to VM ctest-TestQos-21636122-10964073, IP 111.163.50.67, Port 22
2026-05-28 00:31:27,396 - DEBUG - VM ctest-TestQos-21636122-10964073 is ready for SSH connections
2026-05-28 00:31:27,396 - INFO - Waiting for VM ctest-TestQos-21636122-45633543 to be up..
2026-05-28 00:31:27,516 - DEBUG - VM is in ACTIVE state now
2026-05-28 00:31:27,516 - INFO - VM name : ctest-TestQos-21636122-45633543
2026-05-28 00:31:27,641 - DEBUG - VM ctest-TestQos-21636122-45633543 ID is 7cdaba97-c5b0-4c3d-a6c3-6f1fe303e45b
2026-05-28 00:31:27,641 - DEBUG - VM ctest-TestQos-21636122-45633543 launched on Node an-jenkins-deploy-platform-ansible-os-5836-2
2026-05-28 00:31:27,777 - DEBUG - Requesting: http://10.0.0.22:8082/virtual-machine/7cdaba97-c5b0-4c3d-a6c3-6f1fe303e45b
2026-05-28 00:31:27,795 - DEBUG - Requesting: http://10.0.0.22:8082/virtual-machine-interface/c32f502a-84a4-4811-8139-7d48eb0be1cd
2026-05-28 00:31:28,997 - 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=4.76 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=0.481 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 = 0.481/2.619/4.757/2.138 ms')
2026-05-28 00:31:28,997 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-TestQos-21636122-45633543 passed
2026-05-28 00:31:29,078 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-05-28 00:31:29,078 - DEBUG - Waiting to SSH to VM ctest-TestQos-21636122-45633543, IP 111.163.50.68, Port 22
2026-05-28 00:31:29,147 - 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': ''}
2026-05-28 00:31:29,310 - DEBUG - VM ctest-TestQos-21636122-45633543 is NOT ready for SSH connections, VM status: ACTIVE
2026-05-28 00:31:34,311 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-05-28 00:31:34,311 - DEBUG - Waiting to SSH to VM ctest-TestQos-21636122-45633543, IP 111.163.50.68, Port 22
2026-05-28 00:31:34,378 - 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': ''}
2026-05-28 00:31:34,505 - DEBUG - VM ctest-TestQos-21636122-45633543 is NOT ready for SSH connections, VM status: ACTIVE
2026-05-28 00:31:39,505 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-05-28 00:31:39,506 - DEBUG - Waiting to SSH to VM ctest-TestQos-21636122-45633543, IP 111.163.50.68, Port 22
2026-05-28 00:31:39,682 - DEBUG - VM ctest-TestQos-21636122-45633543 is ready for SSH connections
2026-05-28 00:31:39,683 - INFO - Waiting for VM ctest-TestQos-21636122-29048650 to be up..
2026-05-28 00:31:39,798 - DEBUG - VM is in ACTIVE state now
2026-05-28 00:31:39,798 - INFO - VM name : ctest-TestQos-21636122-29048650
2026-05-28 00:31:39,927 - DEBUG - VM ctest-TestQos-21636122-29048650 ID is 49f7b173-93a7-4100-a321-6f4aaf10c374
2026-05-28 00:31:39,928 - DEBUG - VM ctest-TestQos-21636122-29048650 launched on Node an-jenkins-deploy-platform-ansible-os-5836-2
2026-05-28 00:31:40,073 - DEBUG - Requesting: http://10.0.0.22:8082/virtual-machine/49f7b173-93a7-4100-a321-6f4aaf10c374
2026-05-28 00:31:40,093 - DEBUG - Requesting: http://10.0.0.22:8082/virtual-machine-interface/b0db9dd1-d3e6-4ccd-89cd-47c9c0e36203
2026-05-28 00:31:41,293 - 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.52 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=1.45 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 = 1.451/2.485/3.519/1.034 ms')
2026-05-28 00:31:41,293 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-TestQos-21636122-29048650 passed
2026-05-28 00:31:41,381 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-05-28 00:31:41,381 - DEBUG - Waiting to SSH to VM ctest-TestQos-21636122-29048650, IP 84.56.26.3, Port 22
2026-05-28 00:31:41,554 - DEBUG - VM ctest-TestQos-21636122-29048650 is ready for SSH connections
2026-05-28 00:31:41,559 - INFO - ================================================================================
2026-05-28 00:31:41,559 - INFO - STARTING TEST : test_qos_remark_dscp_on_vmi
2026-05-28 00:31:41,559 - INFO - TEST DESCRIPTION : Create a qos config for remarking DSCP 1 to 10
Have VMs A, B
Apply the qos config to VM A
Validate that packets from A to B have DSCP marked correctly
2026-05-28 00:31:42,926 - DEBUG - Nothing to compare xmpp stats {'10.0.0.19': {'10.20.0.254': '0', '10.20.0.14': '0'}, '10.0.0.129': {'10.20.0.254': '0', '10.20.0.14': '0'}} with
2026-05-28 00:31:42,926 - INFO - Initial checks done. Running the testcase now
2026-05-28 00:31:42,927 - INFO -
2026-05-28 00:31:42,935 - DEBUG - FC Dict is {'fc_id': 0, 'dscp': 10, 'dot1p': 1, 'exp': 1, 'connections': }
2026-05-28 00:31:43,239 - INFO - Created FC ['default-global-system-config', 'default-global-qos-config', 'ctest-fc-19887518'], UUID 8e1de01d-2b73-4f4e-bb58-4c6e0fc9d30e
2026-05-28 00:31:43,651 - INFO - Created QosConfig ['default-domain', 'ctest-TestQos-21636122', 'ctest-qos_config-52385910'], UUID: db5a72f8-e708-42c8-9041-c9a474aadaf8
2026-05-28 00:31:43,703 - INFO - Applying qos-config on VM 2a5add28-61f4-4423-86e0-c222212e85d1
2026-05-28 00:31:44,063 - DEBUG - VM is in ACTIVE state now
2026-05-28 00:31:44,387 - DEBUG - Requesting: http://10.0.0.22:8082/virtual-machine/22b0ded8-b229-461d-88e1-503599e9d61d
2026-05-28 00:31:44,399 - DEBUG - Requesting: http://10.0.0.22:8082/virtual-machine-interface/2a5add28-61f4-4423-86e0-c222212e85d1
2026-05-28 00:31:44,414 - DEBUG - Requesting: http://10.0.0.22:8082/instance-ip/a6158717-bbea-401f-b877-299bd89ddb66
2026-05-28 00:31:44,430 - DEBUG - Requesting: http://10.0.0.22:8082/instance-ip/d4511b12-3589-4900-bdad-7ffdba258cc2
2026-05-28 00:31:44,713 - DEBUG - VM is in ACTIVE state now
2026-05-28 00:31:45,100 - DEBUG - Requesting: http://10.0.0.22:8082/virtual-machine/7cdaba97-c5b0-4c3d-a6c3-6f1fe303e45b
2026-05-28 00:31:45,111 - DEBUG - Requesting: http://10.0.0.22:8082/virtual-machine-interface/c32f502a-84a4-4811-8139-7d48eb0be1cd
2026-05-28 00:31:45,126 - DEBUG - Requesting: http://10.0.0.22:8082/instance-ip/4b7efb6b-885d-4431-a030-48b43cb48765
2026-05-28 00:31:45,142 - DEBUG - Requesting: http://10.0.0.22:8082/instance-ip/4f398860-7530-4717-b9f0-29e4cfa5ed76
2026-05-28 00:31:45,185 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-05-28 00:31:45,186 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-05-28 00:31:45,186 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-05-28 00:31:45,186 - INFO - Starting hping3 on ctest-TestQos-21636122-10964073, args: --destport 20000 --baseport 10000 --count 20000 --interval 1 --udp --tos 4 --keep --numeric
2026-05-28 00:31:45,186 - DEBUG - Hping3 cmd : hping3 --destport 20000 --baseport 10000 --count 20000 --interval 1 --udp --tos 4 --keep --numeric 111.163.50.68 1>/tmp/hping_ctest-random-80469884.log 2>/tmp/hping_ctest-random-80469884.result
2026-05-28 00:31:45,186 - DEBUG - Running remote_cmd, Cmd : hping3 --destport 20000 --baseport 10000 --count 20000 --interval 1 --udp --tos 4 --keep --numeric 111.163.50.68 1>/tmp/hping_ctest-random-80469884.log 2>/tmp/hping_ctest-random-80469884.result, host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.19, gateway password: c0ntrail123
2026-05-28 00:31:45,186 - DEBUG - nohup hping3 --destport 20000 --baseport 10000 --count 20000 --interval 1 --udp --tos 4 --keep --numeric 111.163.50.68 1>/tmp/hping_ctest-random-80469884.log 2>/tmp/hping_ctest-random-80469884.result & echo $! > /tmp/hping_ctest-random-80469884.pid
2026-05-28 00:31:55,397 - DEBUG - None
2026-05-28 00:32:00,686 - DEBUG - Forward flow: {'index': '188720', 'rflow': '479472', 'sip': '111.163.50.67', 'sport': '10000', 'dip': '111.163.50.68', 'dport': '20000', 'proto': '17', 'vrf_id': '2', 'action': 'FORWARD', 'flags': ' ACTIVE | RFLOW_VALID ', 'd_vrf_id': '0', 'bytes': '210', 'pkts': '5', 'insight': '0', 'nhid': '30', 'underlay_udp_sport': '65141', 'ttl': '0', 'qos_id': '0', 'gen_id': '1', 'tcp_seq': '0', 'oflow_bytes': '0', 'oflow_packets': '0', 'underlay_gw_index': '-1'}
2026-05-28 00:32:00,688 - DEBUG - Reverse flow: {'index': '479472', 'rflow': '188720', 'sip': '111.163.50.68', 'sport': '20000', 'dip': '111.163.50.67', 'dport': '10000', 'proto': '17', 'vrf_id': '2', 'action': 'FORWARD', 'flags': ' ACTIVE | RFLOW_VALID ', 'd_vrf_id': '0', 'bytes': '420', 'pkts': '6', 'insight': '0', 'nhid': '30', 'underlay_udp_sport': '51603', 'ttl': '0', 'qos_id': '0', 'gen_id': '1', 'tcp_seq': '0', 'oflow_bytes': '0', 'oflow_packets': '0', 'underlay_gw_index': '-1'}
2026-05-28 00:32:00,688 - DEBUG - The filter pattern is ['udp', 'and', 'src port 65141']
2026-05-28 00:32:00,688 - DEBUG - The filter string is '(udp and src port 65141)'
2026-05-28 00:32:00,784 - DEBUG - Executing command: sudo tcpdump -nni ens6 -U -vvxx '(udp and src port 65141)' -w /tmp/ens6_ctest-random-26849708.pcap
2026-05-28 00:32:05,911 - DEBUG - Executing command: sudo kill $(ps -ef|grep tcpdump | grep pcap| awk '{print $2}')
2026-05-28 00:32:07,916 - DEBUG - Ensuring hping3 instance with result file /tmp/hping_ctest-random-80469884.result on ctest-TestQos-21636122-10964073 is stopped
2026-05-28 00:32:07,916 - DEBUG - Running remote_cmd, Cmd : cat /tmp/hping_ctest-random-80469884.pid | xargs kill , host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.19, gateway password: c0ntrail123
2026-05-28 00:32:07,916 - DEBUG - cat /tmp/hping_ctest-random-80469884.pid | xargs kill
2026-05-28 00:32:08,903 - DEBUG - None
2026-05-28 00:32:08,903 - DEBUG - Running remote_cmd, Cmd : cat /tmp/hping_ctest-random-80469884.result, host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.19, gateway password: c0ntrail123
2026-05-28 00:32:08,903 - DEBUG - cat /tmp/hping_ctest-random-80469884.result
2026-05-28 00:32:09,291 - DEBUG - --- 111.163.50.68 hping statistic ---
14 packets transmitted, 14 packets received, 0% packet loss
round-trip min/avg/max = 14.4/6522.6/13030.2 ms
2026-05-28 00:32:09,291 - DEBUG - Running remote_cmd, Cmd : cat /tmp/hping_ctest-random-80469884.log, host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.19, gateway password: c0ntrail123
2026-05-28 00:32:09,291 - DEBUG - cat /tmp/hping_ctest-random-80469884.log
2026-05-28 00:32:09,634 - DEBUG - HPING 111.163.50.68 (eth0 111.163.50.68): udp mode set, 28 headers + 0 data bytes
ICMP Port Unreachable from ip=111.163.50.68
status=0 port=10000 seq=0
ICMP Port Unreachable from ip=111.163.50.68
status=1 port=10000 seq=0
ICMP Port Unreachable from ip=111.163.50.68
status=1 port=10000 seq=0
ICMP Port Unreachable from ip=111.163.50.68
status=1 port=10000 seq=0
ICMP Port Unreachable from ip=111.163.50.68
status=1 port=10000 seq=0
ICMP Port Unreachable from ip=111.163.50.68
status=1 port=10000 seq=0
ICMP Port Unreachable from ip=111.163.50.68
status=1 port=10000 seq=0
ICMP Port Unreachable from ip=111.163.50.68
status=1 port=10000 seq=0
ICMP Port Unreachable from ip=111.163.50.68
status=1 port=10000 seq=0
ICMP Port Unreachable from ip=111.163.50.68
status=1 port=10000 seq=0
ICMP Port Unreachable from ip=111.163.50.68
status=1 port=10000 seq=0
ICMP Port Unreachable from ip=111.163.50.68
status=1 port=10000 seq=0
ICMP Port Unreachable from ip=111.163.50.68
status=1 port=10000 seq=0
ICMP Port Unreachable from ip=111.163.50.68
status=1 port=10000 seq=0
2026-05-28 00:32:09,635 - DEBUG - Hping3 stats: {'sent': '14', 'received': '14', 'loss': '0', 'rtt_min': '14.4', 'rtt_avg': '6522.6', 'rtt_max': '13030.2'}
2026-05-28 00:32:09,635 - DEBUG - Executing command: sudo tcpdump -nnr /tmp/ens6_ctest-random-26849708.pcap | wc -l
2026-05-28 00:32:09,663 - DEBUG - STDOUT: 16
2026-05-28 00:32:09,664 - DEBUG - STDERR: reading from file /tmp/ens6_ctest-random-26849708.pcap, link-type EN10MB (Ethernet), snapshot length 262144
2026-05-28 00:32:09,664 - DEBUG - 16 packets are found in tcpdump output file /tmp/ens6_ctest-random-26849708.pcap but expected 1, which is fine
2026-05-28 00:32:09,664 - INFO - 16 packets are found in tcpdump output as expected
2026-05-28 00:32:09,664 - DEBUG - Executing command: sudo kill $(ps -ef|grep tcpdump | grep pcap| awk '{print $2}')
2026-05-28 00:32:11,736 - DEBUG - ['/contrail-test/ens6_ctest-random-26849708.pcap']
2026-05-28 00:32:11,737 - DEBUG - Verifying for packet number 0
2026-05-28 00:32:11,737 - DEBUG - Validated DSCP marking of 10
2026-05-28 00:32:11,737 - DEBUG - Verifying for packet number 1
2026-05-28 00:32:11,737 - DEBUG - Validated DSCP marking of 10
2026-05-28 00:32:11,737 - DEBUG - Verifying for packet number 2
2026-05-28 00:32:11,737 - DEBUG - Validated DSCP marking of 10
2026-05-28 00:32:11,737 - DEBUG - Verifying for packet number 3
2026-05-28 00:32:11,737 - DEBUG - Validated DSCP marking of 10
2026-05-28 00:32:11,737 - INFO - Packet QoS marking validation passed
2026-05-28 00:32:11,737 - DEBUG - Executing command: sudo tcpdump -nnr /tmp/ens6_ctest-random-26849708.pcap | wc -l
2026-05-28 00:32:11,757 - DEBUG - STDOUT: 16
2026-05-28 00:32:11,758 - DEBUG - STDERR: reading from file /tmp/ens6_ctest-random-26849708.pcap, link-type EN10MB (Ethernet), snapshot length 262144
2026-05-28 00:32:11,758 - DEBUG - 16 packets are found in tcpdump output file /tmp/ens6_ctest-random-26849708.pcap but expected 1, which is fine
2026-05-28 00:32:11,758 - INFO - 16 packets are found in tcpdump output as expected
2026-05-28 00:32:11,758 - DEBUG - Executing command: sudo kill $(ps -ef|grep tcpdump | grep pcap| awk '{print $2}')
2026-05-28 00:32:13,821 - DEBUG - ['/contrail-test/ens6_ctest-random-26849708.pcap']
2026-05-28 00:32:13,821 - DEBUG - Verifying for packet number 0
2026-05-28 00:32:13,821 - DEBUG - Interface ens6 does not seem to be a tagged intf. Skipping dot1p check
2026-05-28 00:32:13,821 - DEBUG - Verifying for packet number 1
2026-05-28 00:32:13,821 - DEBUG - Interface ens6 does not seem to be a tagged intf. Skipping dot1p check
2026-05-28 00:32:13,821 - DEBUG - Verifying for packet number 2
2026-05-28 00:32:13,821 - DEBUG - Interface ens6 does not seem to be a tagged intf. Skipping dot1p check
2026-05-28 00:32:13,821 - DEBUG - Verifying for packet number 3
2026-05-28 00:32:13,821 - DEBUG - Interface ens6 does not seem to be a tagged intf. Skipping dot1p check
2026-05-28 00:32:13,821 - INFO - Packet QoS marking validation passed
2026-05-28 00:32:13,931 - INFO - Removing qos-config on VM 2a5add28-61f4-4423-86e0-c222212e85d1
2026-05-28 00:32:14,011 - INFO - Deleting Qos config ['default-domain', 'ctest-TestQos-21636122', 'ctest-qos_config-52385910'], UUID: db5a72f8-e708-42c8-9041-c9a474aadaf8
2026-05-28 00:32:14,107 - INFO - Deleting FC ['default-global-system-config', 'default-global-qos-config', 'ctest-fc-19887518'], UUID: 8e1de01d-2b73-4f4e-bb58-4c6e0fc9d30e
2026-05-28 00:32:15,489 - DEBUG - No XMPP flaps were noticed during the test
2026-05-28 00:32:15,490 - INFO - --------------------------------------------------------------------------------
2026-05-28 00:32:15,493 - INFO - Deleting VM ctest-TestQos-21636122-29048650
2026-05-28 00:32:15,615 - INFO - Deleting VM ctest-TestQos-21636122-45633543
2026-05-28 00:32:15,746 - INFO - Deleting VM ctest-TestQos-21636122-10964073
2026-05-28 00:32:15,844 - INFO - Deleting VN ctest-vn-34842345
2026-05-28 00:32:15,911 - DEBUG - VN 1c0643fd-7d2f-4812-a44b-f0c741583b89 still in use: Unable to complete operation on network 1c0643fd-7d2f-4812-a44b-f0c741583b89. There are one or more ports still in use on the network.
Neutron server returns request_ids: ['req-2515d417-c5ff-43bc-b7d9-4cb090371e4d']
2026-05-28 00:32:15,911 - WARNING - Deleting VN ctest-vn-34842345 failed..Will retry
2026-05-28 00:32:18,136 - DEBUG - Response for deleting network ()
2026-05-28 00:32:18,136 - INFO - Deleting VN ctest-vn-71403495
2026-05-28 00:32:18,422 - DEBUG - Response for deleting network ()
2026-05-28 00:32:19,457 - INFO - Deleted project: ctest-TestQos-21636122, ID : 81ee9689-070d-4538-81e2-b6f434e67ceb