2026-05-04 03:12:25,063 - INFO - Domain Default found not creating
2026-05-04 03:12:25,261 - INFO - Project ctest-TestQos-26710554 not found, creating it
2026-05-04 03:12:25,866 - INFO - Created Project:ctest-TestQos-26710554, ID : 90ec7c2c-20a9-4769-b84d-3d3b48ff8371
2026-05-04 03:12:28,402 - DEBUG - Response for create_network : {'network': {'id': 'aac50645-8874-430b-98ae-dfb4b7cf46e6', 'name': 'ctest-vn-80516996', 'tenant_id': '90ec7c2c20a94769b84d3d3b48ff8371', 'project_id': '90ec7c2c20a94769b84d3d3b48ff8371', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestQos-26710554', 'ctest-vn-80516996'], 'port_security_enabled': True, 'description': ''}}
2026-05-04 03:12:28,714 - DEBUG - Response for create_subnet : {'subnet': {'id': '26ca20a6-57a3-4a87-876e-ccc3b3140dd9', 'name': '', 'tenant_id': '90ec7c2c20a94769b84d3d3b48ff8371', 'network_id': 'aac50645-8874-430b-98ae-dfb4b7cf46e6', 'ip_version': 4, 'cidr': '43.249.8.192/26', 'allocation_pools': [{'start': '43.249.8.194', 'end': '43.249.8.254'}], 'gateway_ip': '43.249.8.193', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '43.249.8.194', 'tags': [], 'project_id': '90ec7c2c20a94769b84d3d3b48ff8371'}}
2026-05-04 03:12:28,968 - DEBUG - Response for create_subnet : {'subnet': {'id': '5d21c727-31cf-4d52-92fe-38c3e2dddf07', 'name': '', 'tenant_id': '90ec7c2c20a94769b84d3d3b48ff8371', 'network_id': 'aac50645-8874-430b-98ae-dfb4b7cf46e6', 'ip_version': 6, 'cidr': '27b1:6c56:4924:35ae:5548:db5::/96', 'allocation_pools': [{'start': '27b1:6c56:4924:35ae:5548:db5:0:2', 'end': '27b1:6c56:4924:35ae:5548:db5:ffff:fffe'}], 'gateway_ip': '27b1:6c56:4924:35ae:5548:db5:0:1', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '27b1:6c56:4924:35ae:5548:db5:0:2', 'tags': [], 'project_id': '90ec7c2c20a94769b84d3d3b48ff8371'}}
2026-05-04 03:12:28,995 - INFO - Created VN ctest-vn-80516996
2026-05-04 03:12:29,007 - DEBUG - VN ctest-vn-80516996 UUID is aac50645-8874-430b-98ae-dfb4b7cf46e6
2026-05-04 03:12:29,418 - DEBUG - Response for create_network : {'network': {'id': '6c683d5e-607f-45b8-b858-c89def2cf668', 'name': 'ctest-vn-21198076', 'tenant_id': '90ec7c2c20a94769b84d3d3b48ff8371', 'project_id': '90ec7c2c20a94769b84d3d3b48ff8371', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestQos-26710554', 'ctest-vn-21198076'], 'port_security_enabled': True, 'description': ''}}
2026-05-04 03:12:29,676 - DEBUG - Response for create_subnet : {'subnet': {'id': 'b84d5d16-cebd-48fa-aa41-0aa089dfffcc', 'name': '', 'tenant_id': '90ec7c2c20a94769b84d3d3b48ff8371', 'network_id': '6c683d5e-607f-45b8-b858-c89def2cf668', 'ip_version': 4, 'cidr': '42.210.214.128/26', 'allocation_pools': [{'start': '42.210.214.130', 'end': '42.210.214.190'}], 'gateway_ip': '42.210.214.129', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '42.210.214.130', 'tags': [], 'project_id': '90ec7c2c20a94769b84d3d3b48ff8371'}}
2026-05-04 03:12:30,005 - DEBUG - Response for create_subnet : {'subnet': {'id': 'c40b2d91-337b-4e47-bb14-0d266e8a8fd3', 'name': '', 'tenant_id': '90ec7c2c20a94769b84d3d3b48ff8371', 'network_id': '6c683d5e-607f-45b8-b858-c89def2cf668', 'ip_version': 6, 'cidr': '2118:4c22:b8b1:88d7:edc3:410a::/96', 'allocation_pools': [{'start': '2118:4c22:b8b1:88d7:edc3:410a:0:2', 'end': '2118:4c22:b8b1:88d7:edc3:410a:ffff:fffe'}], 'gateway_ip': '2118:4c22:b8b1:88d7:edc3:410a:0:1', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '2118:4c22:b8b1:88d7:edc3:410a:0:2', 'tags': [], 'project_id': '90ec7c2c20a94769b84d3d3b48ff8371'}}
2026-05-04 03:12:30,035 - INFO - Created VN ctest-vn-21198076
2026-05-04 03:12:30,047 - DEBUG - VN ctest-vn-21198076 UUID is 6c683d5e-607f-45b8-b858-c89def2cf668
2026-05-04 03:12:30,227 - DEBUG - Services list from nova: [, , , ]
2026-05-04 03:12:31,409 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-5740-1), Zone: (nova:an-jenkins-deploy-platform-ansible-os-5740-1)
2026-05-04 03:12:32,771 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-5740-2), Zone: (nova:an-jenkins-deploy-platform-ansible-os-5740-2)
2026-05-04 03:12:34,307 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-5740-2), Zone: (nova:an-jenkins-deploy-platform-ansible-os-5740-2)
2026-05-04 03:12:34,307 - INFO - Waiting for VM ctest-TestQos-26710554-42822299 to be up..
2026-05-04 03:12:34,416 - DEBUG - VM is in ACTIVE state now
2026-05-04 03:12:34,416 - INFO - VM name : ctest-TestQos-26710554-42822299
2026-05-04 03:12:34,523 - DEBUG - VM ctest-TestQos-26710554-42822299 ID is cba0dfb6-d7c5-44a5-a3eb-ecd246969821
2026-05-04 03:12:34,558 - DEBUG - VM ctest-TestQos-26710554-42822299 launched on Node an-jenkins-deploy-platform-ansible-os-5740-1
2026-05-04 03:12:34,671 - DEBUG - Requesting: http://10.0.0.249:8082/virtual-machine/cba0dfb6-d7c5-44a5-a3eb-ecd246969821
2026-05-04 03:12:35,131 - DEBUG - Requesting: http://10.0.0.249:8082/virtual-machine/cba0dfb6-d7c5-44a5-a3eb-ecd246969821
2026-05-04 03:12:35,193 - DEBUG - Requesting: http://10.0.0.249:8082/virtual-machine-interface/0d55bfc2-0792-4cc1-95f5-c3399d92fe7f
2026-05-04 03:12:38,379 - 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 1002ms')
2026-05-04 03:12:38,379 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestQos-26710554-42822299 failed!
2026-05-04 03:12:38,402 - DEBUG - Gateway for vn default-domain:ctest-TestQos-26710554:ctest-vn-80516996 is 43.249.8.193 and allocation pool is NOT set
2026-05-04 03:12:38,402 - DEBUG - Gateway for vn default-domain:ctest-TestQos-26710554:ctest-vn-80516996 is 27b1:6c56:4924:35ae:5548:db5:0:1 and allocation pool is NOT set
2026-05-04 03:12:42,481 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1013ms')
2026-05-04 03:12:42,481 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestQos-26710554-42822299 failed!
2026-05-04 03:12:42,501 - DEBUG - Gateway for vn default-domain:ctest-TestQos-26710554:ctest-vn-80516996 is 43.249.8.193 and allocation pool is NOT set
2026-05-04 03:12:42,501 - DEBUG - Gateway for vn default-domain:ctest-TestQos-26710554:ctest-vn-80516996 is 27b1:6c56:4924:35ae:5548:db5:0:1 and allocation pool is NOT set
2026-05-04 03:12:46,573 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1009ms')
2026-05-04 03:12:46,573 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestQos-26710554-42822299 failed!
2026-05-04 03:12:46,590 - DEBUG - Gateway for vn default-domain:ctest-TestQos-26710554:ctest-vn-80516996 is 43.249.8.193 and allocation pool is NOT set
2026-05-04 03:12:46,590 - DEBUG - Gateway for vn default-domain:ctest-TestQos-26710554:ctest-vn-80516996 is 27b1:6c56:4924:35ae:5548:db5:0:1 and allocation pool is NOT set
2026-05-04 03:12:50,674 - 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')
2026-05-04 03:12:50,674 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestQos-26710554-42822299 failed!
2026-05-04 03:12:50,691 - DEBUG - Gateway for vn default-domain:ctest-TestQos-26710554:ctest-vn-80516996 is 43.249.8.193 and allocation pool is NOT set
2026-05-04 03:12:50,691 - DEBUG - Gateway for vn default-domain:ctest-TestQos-26710554:ctest-vn-80516996 is 27b1:6c56:4924:35ae:5548:db5:0:1 and allocation pool is NOT set
2026-05-04 03:12:54,772 - 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-04 03:12:54,772 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestQos-26710554-42822299 failed!
2026-05-04 03:12:54,790 - DEBUG - Gateway for vn default-domain:ctest-TestQos-26710554:ctest-vn-80516996 is 43.249.8.193 and allocation pool is NOT set
2026-05-04 03:12:54,790 - DEBUG - Gateway for vn default-domain:ctest-TestQos-26710554:ctest-vn-80516996 is 27b1:6c56:4924:35ae:5548:db5:0:1 and allocation pool is NOT set
2026-05-04 03:12:58,867 - 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-04 03:12:58,867 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestQos-26710554-42822299 failed!
2026-05-04 03:12:58,883 - DEBUG - Gateway for vn default-domain:ctest-TestQos-26710554:ctest-vn-80516996 is 43.249.8.193 and allocation pool is NOT set
2026-05-04 03:12:58,884 - DEBUG - Gateway for vn default-domain:ctest-TestQos-26710554:ctest-vn-80516996 is 27b1:6c56:4924:35ae:5548:db5:0:1 and allocation pool is NOT set
2026-05-04 03:13:02,965 - 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-04 03:13:02,965 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestQos-26710554-42822299 failed!
2026-05-04 03:13:02,983 - DEBUG - Gateway for vn default-domain:ctest-TestQos-26710554:ctest-vn-80516996 is 43.249.8.193 and allocation pool is NOT set
2026-05-04 03:13:02,983 - DEBUG - Gateway for vn default-domain:ctest-TestQos-26710554:ctest-vn-80516996 is 27b1:6c56:4924:35ae:5548:db5:0:1 and allocation pool is NOT set
2026-05-04 03:13:07,057 - 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')
2026-05-04 03:13:07,058 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestQos-26710554-42822299 failed!
2026-05-04 03:13:07,079 - DEBUG - Gateway for vn default-domain:ctest-TestQos-26710554:ctest-vn-80516996 is 43.249.8.193 and allocation pool is NOT set
2026-05-04 03:13:07,079 - DEBUG - Gateway for vn default-domain:ctest-TestQos-26710554:ctest-vn-80516996 is 27b1:6c56:4924:35ae:5548:db5:0:1 and allocation pool is NOT set
2026-05-04 03:13:11,153 - 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-04 03:13:11,153 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestQos-26710554-42822299 failed!
2026-05-04 03:13:11,170 - DEBUG - Gateway for vn default-domain:ctest-TestQos-26710554:ctest-vn-80516996 is 43.249.8.193 and allocation pool is NOT set
2026-05-04 03:13:11,171 - DEBUG - Gateway for vn default-domain:ctest-TestQos-26710554:ctest-vn-80516996 is 27b1:6c56:4924:35ae:5548:db5:0:1 and allocation pool is NOT set
2026-05-04 03:13:13,234 - 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=6.45 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=4.56 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 = 4.563/5.504/6.445/0.941 ms')
2026-05-04 03:13:13,234 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-TestQos-26710554-42822299 passed
2026-05-04 03:13:13,307 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-05-04 03:13:13,307 - DEBUG - Waiting to SSH to VM ctest-TestQos-26710554-42822299, IP 43.249.8.195, Port 22
2026-05-04 03:13:13,364 - 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-04 03:13:13,475 - DEBUG - VM ctest-TestQos-26710554-42822299 is NOT ready for SSH connections, VM status: ACTIVE
2026-05-04 03:13:18,476 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-05-04 03:13:18,476 - DEBUG - Waiting to SSH to VM ctest-TestQos-26710554-42822299, IP 43.249.8.195, Port 22
2026-05-04 03:13:18,545 - 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-04 03:13:18,647 - DEBUG - VM ctest-TestQos-26710554-42822299 is NOT ready for SSH connections, VM status: ACTIVE
2026-05-04 03:13:23,648 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-05-04 03:13:23,649 - DEBUG - Waiting to SSH to VM ctest-TestQos-26710554-42822299, IP 43.249.8.195, Port 22
2026-05-04 03:13:23,719 - 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-04 03:13:23,850 - DEBUG - VM ctest-TestQos-26710554-42822299 is NOT ready for SSH connections, VM status: ACTIVE
2026-05-04 03:13:28,852 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-05-04 03:13:28,852 - DEBUG - Waiting to SSH to VM ctest-TestQos-26710554-42822299, IP 43.249.8.195, Port 22
2026-05-04 03:13:28,921 - 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-04 03:13:29,020 - DEBUG - VM ctest-TestQos-26710554-42822299 is NOT ready for SSH connections, VM status: ACTIVE
2026-05-04 03:13:34,021 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-05-04 03:13:34,021 - DEBUG - Waiting to SSH to VM ctest-TestQos-26710554-42822299, IP 43.249.8.195, Port 22
2026-05-04 03:13:34,194 - DEBUG - VM ctest-TestQos-26710554-42822299 is ready for SSH connections
2026-05-04 03:13:34,194 - INFO - Waiting for VM ctest-TestQos-26710554-39350754 to be up..
2026-05-04 03:13:34,305 - DEBUG - VM is in ACTIVE state now
2026-05-04 03:13:34,305 - INFO - VM name : ctest-TestQos-26710554-39350754
2026-05-04 03:13:34,409 - DEBUG - VM ctest-TestQos-26710554-39350754 ID is 73f81ff7-5597-4fc4-a9fc-6befc5d7b904
2026-05-04 03:13:34,409 - DEBUG - VM ctest-TestQos-26710554-39350754 launched on Node an-jenkins-deploy-platform-ansible-os-5740-2
2026-05-04 03:13:34,515 - DEBUG - Requesting: http://10.0.0.249:8082/virtual-machine/73f81ff7-5597-4fc4-a9fc-6befc5d7b904
2026-05-04 03:13:34,527 - DEBUG - Requesting: http://10.0.0.249:8082/virtual-machine-interface/89b5302a-f8bb-4872-bbe6-ed43f4af0597
2026-05-04 03:13:35,712 - 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=3.86 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=0.651 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.651/2.256/3.862/1.605 ms')
2026-05-04 03:13:35,713 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-TestQos-26710554-39350754 passed
2026-05-04 03:13:35,788 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-05-04 03:13:35,788 - DEBUG - Waiting to SSH to VM ctest-TestQos-26710554-39350754, IP 43.249.8.196, Port 22
2026-05-04 03:13:35,857 - 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-04 03:13:35,963 - DEBUG - VM ctest-TestQos-26710554-39350754 is NOT ready for SSH connections, VM status: ACTIVE
2026-05-04 03:13:40,964 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-05-04 03:13:40,964 - DEBUG - Waiting to SSH to VM ctest-TestQos-26710554-39350754, IP 43.249.8.196, Port 22
2026-05-04 03:13:41,037 - 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-04 03:13:41,136 - DEBUG - VM ctest-TestQos-26710554-39350754 is NOT ready for SSH connections, VM status: ACTIVE
2026-05-04 03:13:46,137 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-05-04 03:13:46,137 - DEBUG - Waiting to SSH to VM ctest-TestQos-26710554-39350754, IP 43.249.8.196, Port 22
2026-05-04 03:13:46,218 - 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-04 03:13:46,398 - DEBUG - VM ctest-TestQos-26710554-39350754 is NOT ready for SSH connections, VM status: ACTIVE
2026-05-04 03:13:51,398 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-05-04 03:13:51,399 - DEBUG - Waiting to SSH to VM ctest-TestQos-26710554-39350754, IP 43.249.8.196, Port 22
2026-05-04 03:13:51,463 - 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-04 03:13:51,590 - DEBUG - VM ctest-TestQos-26710554-39350754 is NOT ready for SSH connections, VM status: ACTIVE
2026-05-04 03:13:56,590 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-05-04 03:13:56,590 - DEBUG - Waiting to SSH to VM ctest-TestQos-26710554-39350754, IP 43.249.8.196, Port 22
2026-05-04 03:13:56,747 - DEBUG - VM ctest-TestQos-26710554-39350754 is ready for SSH connections
2026-05-04 03:13:56,747 - INFO - Waiting for VM ctest-TestQos-26710554-09546661 to be up..
2026-05-04 03:13:56,847 - DEBUG - VM is in ACTIVE state now
2026-05-04 03:13:56,847 - INFO - VM name : ctest-TestQos-26710554-09546661
2026-05-04 03:13:56,947 - DEBUG - VM ctest-TestQos-26710554-09546661 ID is 267b1514-70b1-4a9a-99da-fe722e8856b6
2026-05-04 03:13:56,947 - DEBUG - VM ctest-TestQos-26710554-09546661 launched on Node an-jenkins-deploy-platform-ansible-os-5740-2
2026-05-04 03:13:57,047 - DEBUG - Requesting: http://10.0.0.249:8082/virtual-machine/267b1514-70b1-4a9a-99da-fe722e8856b6
2026-05-04 03:13:57,059 - DEBUG - Requesting: http://10.0.0.249:8082/virtual-machine-interface/292b4ed0-970a-4577-80af-5bd7f7be0427
2026-05-04 03:13:58,240 - 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.30 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=0.826 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.826/2.063/3.301/1.237 ms')
2026-05-04 03:13:58,241 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-TestQos-26710554-09546661 passed
2026-05-04 03:13:58,320 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-05-04 03:13:58,321 - DEBUG - Waiting to SSH to VM ctest-TestQos-26710554-09546661, IP 42.210.214.131, Port 22
2026-05-04 03:13:58,486 - DEBUG - VM ctest-TestQos-26710554-09546661 is ready for SSH connections
2026-05-04 03:13:58,489 - INFO - ================================================================================
2026-05-04 03:13:58,489 - INFO - STARTING TEST : test_qos_remark_dscp_on_vmi
2026-05-04 03:13:58,489 - 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-04 03:13:59,803 - DEBUG - Nothing to compare xmpp stats {'10.0.0.41': {'10.20.0.193': '0', '10.20.0.129': '0'}, '10.0.0.141': {'10.20.0.18': '0', '10.20.0.193': '0'}} with
2026-05-04 03:13:59,803 - INFO - Initial checks done. Running the testcase now
2026-05-04 03:13:59,804 - INFO -
2026-05-04 03:13:59,811 - DEBUG - FC Dict is {'fc_id': 0, 'dscp': 10, 'dot1p': 1, 'exp': 1, 'connections': }
2026-05-04 03:14:00,094 - INFO - Created FC ['default-global-system-config', 'default-global-qos-config', 'ctest-fc-39597439'], UUID aba44a79-42b9-456d-aa50-ea67212af81d
2026-05-04 03:14:00,474 - INFO - Created QosConfig ['default-domain', 'ctest-TestQos-26710554', 'ctest-qos_config-88581014'], UUID: ec51f46d-d236-4d97-addb-28c7dfd8a1b4
2026-05-04 03:14:00,526 - INFO - Applying qos-config on VM 0d55bfc2-0792-4cc1-95f5-c3399d92fe7f
2026-05-04 03:14:00,830 - DEBUG - VM is in ACTIVE state now
2026-05-04 03:14:01,129 - DEBUG - Requesting: http://10.0.0.249:8082/virtual-machine/cba0dfb6-d7c5-44a5-a3eb-ecd246969821
2026-05-04 03:14:01,142 - DEBUG - Requesting: http://10.0.0.249:8082/virtual-machine-interface/0d55bfc2-0792-4cc1-95f5-c3399d92fe7f
2026-05-04 03:14:01,157 - DEBUG - Requesting: http://10.0.0.249:8082/instance-ip/6b3ae498-a5e8-4c70-a98b-e3a9c2c4ba57
2026-05-04 03:14:01,174 - DEBUG - Requesting: http://10.0.0.249:8082/instance-ip/89730433-e592-46cb-916d-13e191a72c28
2026-05-04 03:14:01,465 - DEBUG - VM is in ACTIVE state now
2026-05-04 03:14:01,772 - DEBUG - Requesting: http://10.0.0.249:8082/virtual-machine/73f81ff7-5597-4fc4-a9fc-6befc5d7b904
2026-05-04 03:14:01,783 - DEBUG - Requesting: http://10.0.0.249:8082/virtual-machine-interface/89b5302a-f8bb-4872-bbe6-ed43f4af0597
2026-05-04 03:14:01,797 - DEBUG - Requesting: http://10.0.0.249:8082/instance-ip/5b0457ec-d90f-4438-b200-cbf299fffd57
2026-05-04 03:14:01,812 - DEBUG - Requesting: http://10.0.0.249:8082/instance-ip/89d5f1f9-e3ea-4b8a-bdd3-357402642eb0
2026-05-04 03:14:01,853 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-05-04 03:14:01,853 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-05-04 03:14:01,853 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-05-04 03:14:01,853 - INFO - Starting hping3 on ctest-TestQos-26710554-42822299, args: --destport 20000 --baseport 10000 --count 20000 --interval 1 --udp --tos 4 --keep --numeric
2026-05-04 03:14:01,853 - DEBUG - Hping3 cmd : hping3 --destport 20000 --baseport 10000 --count 20000 --interval 1 --udp --tos 4 --keep --numeric 43.249.8.196 1>/tmp/hping_ctest-random-99452652.log 2>/tmp/hping_ctest-random-99452652.result
2026-05-04 03:14:01,853 - DEBUG - Running remote_cmd, Cmd : hping3 --destport 20000 --baseport 10000 --count 20000 --interval 1 --udp --tos 4 --keep --numeric 43.249.8.196 1>/tmp/hping_ctest-random-99452652.log 2>/tmp/hping_ctest-random-99452652.result, host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.41, gateway password: c0ntrail123
2026-05-04 03:14:01,854 - DEBUG - nohup hping3 --destport 20000 --baseport 10000 --count 20000 --interval 1 --udp --tos 4 --keep --numeric 43.249.8.196 1>/tmp/hping_ctest-random-99452652.log 2>/tmp/hping_ctest-random-99452652.result & echo $! > /tmp/hping_ctest-random-99452652.pid
2026-05-04 03:14:44,129 - DEBUG - None
2026-05-04 03:14:49,333 - DEBUG - Forward flow: {'index': '384036', 'rflow': '115684', 'sip': '43.249.8.195', 'sport': '10000', 'dip': '43.249.8.196', 'dport': '20000', 'proto': '17', 'vrf_id': '2', 'action': 'FORWARD', 'flags': ' ACTIVE | RFLOW_VALID ', 'd_vrf_id': '0', 'bytes': '252', 'pkts': '6', 'insight': '0', 'nhid': '30', 'underlay_udp_sport': '56518', 'ttl': '0', 'qos_id': '0', 'gen_id': '1', 'tcp_seq': '0', 'oflow_bytes': '0', 'oflow_packets': '0', 'underlay_gw_index': '-1'}
2026-05-04 03:14:49,334 - DEBUG - Reverse flow: {'index': '115684', 'rflow': '384036', 'sip': '43.249.8.196', 'sport': '20000', 'dip': '43.249.8.195', 'dport': '10000', 'proto': '17', 'vrf_id': '2', 'action': 'FORWARD', 'flags': ' ACTIVE | RFLOW_VALID ', 'd_vrf_id': '0', 'bytes': '350', 'pkts': '5', 'insight': '0', 'nhid': '30', 'underlay_udp_sport': '59677', 'ttl': '0', 'qos_id': '0', 'gen_id': '1', 'tcp_seq': '0', 'oflow_bytes': '0', 'oflow_packets': '0', 'underlay_gw_index': '-1'}
2026-05-04 03:14:49,334 - DEBUG - The filter pattern is ['udp', 'and', 'src port 56518']
2026-05-04 03:14:49,334 - DEBUG - The filter string is '(udp and src port 56518)'
2026-05-04 03:14:49,425 - DEBUG - Executing command: sudo tcpdump -nni ens6 -U -vvxx '(udp and src port 56518)' -w /tmp/ens6_ctest-random-87140735.pcap
2026-05-04 03:14:54,515 - DEBUG - Executing command: sudo kill $(ps -ef|grep tcpdump | grep pcap| awk '{print $2}')
2026-05-04 03:14:56,518 - DEBUG - Ensuring hping3 instance with result file /tmp/hping_ctest-random-99452652.result on ctest-TestQos-26710554-42822299 is stopped
2026-05-04 03:14:56,518 - DEBUG - Running remote_cmd, Cmd : cat /tmp/hping_ctest-random-99452652.pid | xargs kill , host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.41, gateway password: c0ntrail123
2026-05-04 03:14:56,519 - DEBUG - cat /tmp/hping_ctest-random-99452652.pid | xargs kill
2026-05-04 03:14:57,377 - DEBUG - None
2026-05-04 03:14:57,378 - DEBUG - Running remote_cmd, Cmd : cat /tmp/hping_ctest-random-99452652.result, host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.41, gateway password: c0ntrail123
2026-05-04 03:14:57,378 - DEBUG - cat /tmp/hping_ctest-random-99452652.result
2026-05-04 03:14:57,707 - DEBUG - --- 43.249.8.196 hping statistic ---
14 packets transmitted, 14 packets received, 0% packet loss
round-trip min/avg/max = 12.4/6512.5/13017.9 ms
2026-05-04 03:14:57,707 - DEBUG - Running remote_cmd, Cmd : cat /tmp/hping_ctest-random-99452652.log, host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.41, gateway password: c0ntrail123
2026-05-04 03:14:57,708 - DEBUG - cat /tmp/hping_ctest-random-99452652.log
2026-05-04 03:14:58,077 - DEBUG - HPING 43.249.8.196 (eth0 43.249.8.196): udp mode set, 28 headers + 0 data bytes
ICMP Port Unreachable from ip=43.249.8.196
status=0 port=10000 seq=0
ICMP Port Unreachable from ip=43.249.8.196
status=1 port=10000 seq=0
ICMP Port Unreachable from ip=43.249.8.196
status=1 port=10000 seq=0
ICMP Port Unreachable from ip=43.249.8.196
status=1 port=10000 seq=0
ICMP Port Unreachable from ip=43.249.8.196
status=1 port=10000 seq=0
ICMP Port Unreachable from ip=43.249.8.196
status=1 port=10000 seq=0
ICMP Port Unreachable from ip=43.249.8.196
status=1 port=10000 seq=0
ICMP Port Unreachable from ip=43.249.8.196
status=1 port=10000 seq=0
ICMP Port Unreachable from ip=43.249.8.196
status=1 port=10000 seq=0
ICMP Port Unreachable from ip=43.249.8.196
status=1 port=10000 seq=0
ICMP Port Unreachable from ip=43.249.8.196
status=1 port=10000 seq=0
ICMP Port Unreachable from ip=43.249.8.196
status=1 port=10000 seq=0
ICMP Port Unreachable from ip=43.249.8.196
status=1 port=10000 seq=0
ICMP Port Unreachable from ip=43.249.8.196
status=1 port=10000 seq=0
2026-05-04 03:14:58,077 - DEBUG - Hping3 stats: {'sent': '14', 'received': '14', 'loss': '0', 'rtt_min': '12.4', 'rtt_avg': '6512.5', 'rtt_max': '13017.9'}
2026-05-04 03:14:58,078 - DEBUG - Executing command: sudo tcpdump -nnr /tmp/ens6_ctest-random-87140735.pcap | wc -l
2026-05-04 03:14:58,096 - DEBUG - STDOUT: 16
2026-05-04 03:14:58,096 - DEBUG - STDERR: reading from file /tmp/ens6_ctest-random-87140735.pcap, link-type EN10MB (Ethernet), snapshot length 262144
2026-05-04 03:14:58,096 - DEBUG - 16 packets are found in tcpdump output file /tmp/ens6_ctest-random-87140735.pcap but expected 1, which is fine
2026-05-04 03:14:58,096 - INFO - 16 packets are found in tcpdump output as expected
2026-05-04 03:14:58,097 - DEBUG - Executing command: sudo kill $(ps -ef|grep tcpdump | grep pcap| awk '{print $2}')
2026-05-04 03:15:00,164 - DEBUG - ['/contrail-test/ens6_ctest-random-87140735.pcap']
2026-05-04 03:15:00,165 - DEBUG - Verifying for packet number 0
2026-05-04 03:15:00,165 - DEBUG - Validated DSCP marking of 10
2026-05-04 03:15:00,165 - DEBUG - Verifying for packet number 1
2026-05-04 03:15:00,165 - DEBUG - Validated DSCP marking of 10
2026-05-04 03:15:00,165 - DEBUG - Verifying for packet number 2
2026-05-04 03:15:00,165 - DEBUG - Validated DSCP marking of 10
2026-05-04 03:15:00,165 - DEBUG - Verifying for packet number 3
2026-05-04 03:15:00,165 - DEBUG - Validated DSCP marking of 10
2026-05-04 03:15:00,165 - INFO - Packet QoS marking validation passed
2026-05-04 03:15:00,166 - DEBUG - Executing command: sudo tcpdump -nnr /tmp/ens6_ctest-random-87140735.pcap | wc -l
2026-05-04 03:15:00,183 - DEBUG - STDOUT: 16
2026-05-04 03:15:00,183 - DEBUG - STDERR: reading from file /tmp/ens6_ctest-random-87140735.pcap, link-type EN10MB (Ethernet), snapshot length 262144
2026-05-04 03:15:00,183 - DEBUG - 16 packets are found in tcpdump output file /tmp/ens6_ctest-random-87140735.pcap but expected 1, which is fine
2026-05-04 03:15:00,183 - INFO - 16 packets are found in tcpdump output as expected
2026-05-04 03:15:00,183 - DEBUG - Executing command: sudo kill $(ps -ef|grep tcpdump | grep pcap| awk '{print $2}')
2026-05-04 03:15:02,250 - DEBUG - ['/contrail-test/ens6_ctest-random-87140735.pcap']
2026-05-04 03:15:02,250 - DEBUG - Verifying for packet number 0
2026-05-04 03:15:02,250 - DEBUG - Interface ens6 does not seem to be a tagged intf. Skipping dot1p check
2026-05-04 03:15:02,250 - DEBUG - Verifying for packet number 1
2026-05-04 03:15:02,251 - DEBUG - Interface ens6 does not seem to be a tagged intf. Skipping dot1p check
2026-05-04 03:15:02,251 - DEBUG - Verifying for packet number 2
2026-05-04 03:15:02,251 - DEBUG - Interface ens6 does not seem to be a tagged intf. Skipping dot1p check
2026-05-04 03:15:02,251 - DEBUG - Verifying for packet number 3
2026-05-04 03:15:02,251 - DEBUG - Interface ens6 does not seem to be a tagged intf. Skipping dot1p check
2026-05-04 03:15:02,251 - INFO - Packet QoS marking validation passed
2026-05-04 03:15:02,372 - INFO - Removing qos-config on VM 0d55bfc2-0792-4cc1-95f5-c3399d92fe7f
2026-05-04 03:15:02,450 - INFO - Deleting Qos config ['default-domain', 'ctest-TestQos-26710554', 'ctest-qos_config-88581014'], UUID: ec51f46d-d236-4d97-addb-28c7dfd8a1b4
2026-05-04 03:15:02,557 - INFO - Deleting FC ['default-global-system-config', 'default-global-qos-config', 'ctest-fc-39597439'], UUID: aba44a79-42b9-456d-aa50-ea67212af81d
2026-05-04 03:15:03,903 - DEBUG - No XMPP flaps were noticed during the test
2026-05-04 03:15:03,904 - INFO - --------------------------------------------------------------------------------
2026-05-04 03:15:03,906 - INFO - Deleting VM ctest-TestQos-26710554-09546661
2026-05-04 03:15:04,014 - INFO - Deleting VM ctest-TestQos-26710554-39350754
2026-05-04 03:15:04,111 - INFO - Deleting VM ctest-TestQos-26710554-42822299
2026-05-04 03:15:04,205 - INFO - Deleting VN ctest-vn-21198076
2026-05-04 03:15:04,262 - DEBUG - VN 6c683d5e-607f-45b8-b858-c89def2cf668 still in use: Unable to complete operation on network 6c683d5e-607f-45b8-b858-c89def2cf668. There are one or more ports still in use on the network.
Neutron server returns request_ids: ['req-8a82f75f-2deb-4456-a44c-70c97699f668']
2026-05-04 03:15:04,262 - WARNING - Deleting VN ctest-vn-21198076 failed..Will retry
2026-05-04 03:15:06,573 - DEBUG - Response for deleting network ()
2026-05-04 03:15:06,573 - INFO - Deleting VN ctest-vn-80516996
2026-05-04 03:15:06,865 - DEBUG - Response for deleting network ()
2026-05-04 03:15:07,712 - INFO - Deleted project: ctest-TestQos-26710554, ID : 90ec7c2c-20a9-4769-b84d-3d3b48ff8371