2026-06-05 17:13:58,963 - INFO - Domain Default found not creating
2026-06-05 17:13:59,119 - INFO - Project ctest-TestQos-05544023 not found, creating it
2026-06-05 17:13:59,686 - INFO - Created Project:ctest-TestQos-05544023, ID : 6067ffdf-83ef-4e19-9028-db657c574b00
2026-06-05 17:14:03,299 - DEBUG - Response for create_network : {'network': {'id': 'f25edc2d-c266-4ec5-87e0-26e51999585e', 'name': 'ctest-vn-04906482', 'tenant_id': '6067ffdf83ef4e199028db657c574b00', 'project_id': '6067ffdf83ef4e199028db657c574b00', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestQos-05544023', 'ctest-vn-04906482'], 'port_security_enabled': True, 'description': ''}}
2026-06-05 17:14:03,587 - DEBUG - Response for create_subnet : {'subnet': {'id': 'f8dfad09-d877-43fb-8a8e-bf1803cd2395', 'name': '', 'tenant_id': '6067ffdf83ef4e199028db657c574b00', 'network_id': 'f25edc2d-c266-4ec5-87e0-26e51999585e', 'ip_version': 4, 'cidr': '46.236.215.128/26', 'allocation_pools': [{'start': '46.236.215.130', 'end': '46.236.215.190'}], 'gateway_ip': '46.236.215.129', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '46.236.215.130', 'tags': [], 'project_id': '6067ffdf83ef4e199028db657c574b00'}}
2026-06-05 17:14:03,830 - DEBUG - Response for create_subnet : {'subnet': {'id': '5d088063-9196-4e9b-95f2-d9eaf981c557', 'name': '', 'tenant_id': '6067ffdf83ef4e199028db657c574b00', 'network_id': 'f25edc2d-c266-4ec5-87e0-26e51999585e', 'ip_version': 6, 'cidr': '33f0:7896:5678:cf9:e709:9151::/96', 'allocation_pools': [{'start': '33f0:7896:5678:cf9:e709:9151:0:2', 'end': '33f0:7896:5678:cf9:e709:9151:ffff:fffe'}], 'gateway_ip': '33f0:7896:5678:cf9:e709:9151:0:1', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '33f0:7896:5678:cf9:e709:9151:0:2', 'tags': [], 'project_id': '6067ffdf83ef4e199028db657c574b00'}}
2026-06-05 17:14:03,859 - INFO - Created VN ctest-vn-04906482
2026-06-05 17:14:03,872 - DEBUG - VN ctest-vn-04906482 UUID is f25edc2d-c266-4ec5-87e0-26e51999585e
2026-06-05 17:14:04,302 - DEBUG - Response for create_network : {'network': {'id': '509c1937-5729-4e25-bf54-0d5db9cff8f4', 'name': 'ctest-vn-70153609', 'tenant_id': '6067ffdf83ef4e199028db657c574b00', 'project_id': '6067ffdf83ef4e199028db657c574b00', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestQos-05544023', 'ctest-vn-70153609'], 'port_security_enabled': True, 'description': ''}}
2026-06-05 17:14:04,539 - DEBUG - Response for create_subnet : {'subnet': {'id': '6a20ec79-1bcf-4b7a-a1a9-099ecb34aa36', 'name': '', 'tenant_id': '6067ffdf83ef4e199028db657c574b00', 'network_id': '509c1937-5729-4e25-bf54-0d5db9cff8f4', 'ip_version': 4, 'cidr': '32.6.24.64/26', 'allocation_pools': [{'start': '32.6.24.66', 'end': '32.6.24.126'}], 'gateway_ip': '32.6.24.65', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '32.6.24.66', 'tags': [], 'project_id': '6067ffdf83ef4e199028db657c574b00'}}
2026-06-05 17:14:04,725 - DEBUG - Response for create_subnet : {'subnet': {'id': '35e6631c-a8f9-4431-ba4b-ac19d79d4e88', 'name': '', 'tenant_id': '6067ffdf83ef4e199028db657c574b00', 'network_id': '509c1937-5729-4e25-bf54-0d5db9cff8f4', 'ip_version': 6, 'cidr': '2554:b829:258a:b371:55c4:36ec::/96', 'allocation_pools': [{'start': '2554:b829:258a:b371:55c4:36ec:0:2', 'end': '2554:b829:258a:b371:55c4:36ec:ffff:fffe'}], 'gateway_ip': '2554:b829:258a:b371:55c4:36ec:0:1', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '2554:b829:258a:b371:55c4:36ec:0:2', 'tags': [], 'project_id': '6067ffdf83ef4e199028db657c574b00'}}
2026-06-05 17:14:04,753 - INFO - Created VN ctest-vn-70153609
2026-06-05 17:14:04,764 - DEBUG - VN ctest-vn-70153609 UUID is 509c1937-5729-4e25-bf54-0d5db9cff8f4
2026-06-05 17:14:04,936 - DEBUG - Services list from nova: [, , , ]
2026-06-05 17:14:06,164 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-5896-1), Zone: (nova:an-jenkins-deploy-platform-ansible-os-5896-1)
2026-06-05 17:14:07,557 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-5896-2), Zone: (nova:an-jenkins-deploy-platform-ansible-os-5896-2)
2026-06-05 17:14:09,000 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-5896-2), Zone: (nova:an-jenkins-deploy-platform-ansible-os-5896-2)
2026-06-05 17:14:09,000 - INFO - Waiting for VM ctest-TestQos-05544023-03079820 to be up..
2026-06-05 17:14:09,099 - DEBUG - VM is in ACTIVE state now
2026-06-05 17:14:09,099 - INFO - VM name : ctest-TestQos-05544023-03079820
2026-06-05 17:14:09,186 - DEBUG - VM ctest-TestQos-05544023-03079820 ID is 69d840e8-a779-4e8d-8e67-9e2810b1d2c3
2026-06-05 17:14:09,213 - DEBUG - VM ctest-TestQos-05544023-03079820 launched on Node an-jenkins-deploy-platform-ansible-os-5896-1
2026-06-05 17:14:09,301 - DEBUG - Requesting: http://10.0.0.38:8082/virtual-machine/69d840e8-a779-4e8d-8e67-9e2810b1d2c3
2026-06-05 17:14:09,757 - DEBUG - Requesting: http://10.0.0.38:8082/virtual-machine/69d840e8-a779-4e8d-8e67-9e2810b1d2c3
2026-06-05 17:14:09,798 - DEBUG - Requesting: http://10.0.0.38:8082/virtual-machine-interface/eba51dad-9bf0-4741-938b-3bda0221288c
2026-06-05 17:14:12,981 - 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-06-05 17:14:12,981 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestQos-05544023-03079820 failed!
2026-06-05 17:14:12,997 - DEBUG - Gateway for vn default-domain:ctest-TestQos-05544023:ctest-vn-04906482 is 46.236.215.129 and allocation pool is NOT set
2026-06-05 17:14:12,997 - DEBUG - Gateway for vn default-domain:ctest-TestQos-05544023:ctest-vn-04906482 is 33f0:7896:5678:cf9:e709:9151:0:1 and allocation pool is NOT set
2026-06-05 17:14:17,083 - 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 1022ms')
2026-06-05 17:14:17,083 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestQos-05544023-03079820 failed!
2026-06-05 17:14:17,098 - DEBUG - Gateway for vn default-domain:ctest-TestQos-05544023:ctest-vn-04906482 is 46.236.215.129 and allocation pool is NOT set
2026-06-05 17:14:17,098 - DEBUG - Gateway for vn default-domain:ctest-TestQos-05544023:ctest-vn-04906482 is 33f0:7896:5678:cf9:e709:9151:0:1 and allocation pool is NOT set
2026-06-05 17:14:21,175 - 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')
2026-06-05 17:14:21,176 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestQos-05544023-03079820 failed!
2026-06-05 17:14:21,190 - DEBUG - Gateway for vn default-domain:ctest-TestQos-05544023:ctest-vn-04906482 is 46.236.215.129 and allocation pool is NOT set
2026-06-05 17:14:21,190 - DEBUG - Gateway for vn default-domain:ctest-TestQos-05544023:ctest-vn-04906482 is 33f0:7896:5678:cf9:e709:9151:0:1 and allocation pool is NOT set
2026-06-05 17:14:25,277 - 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 1017ms')
2026-06-05 17:14:25,277 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestQos-05544023-03079820 failed!
2026-06-05 17:14:25,291 - DEBUG - Gateway for vn default-domain:ctest-TestQos-05544023:ctest-vn-04906482 is 46.236.215.129 and allocation pool is NOT set
2026-06-05 17:14:25,291 - DEBUG - Gateway for vn default-domain:ctest-TestQos-05544023:ctest-vn-04906482 is 33f0:7896:5678:cf9:e709:9151:0:1 and allocation pool is NOT set
2026-06-05 17:14:29,371 - 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 1020ms')
2026-06-05 17:14:29,372 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestQos-05544023-03079820 failed!
2026-06-05 17:14:29,389 - DEBUG - Gateway for vn default-domain:ctest-TestQos-05544023:ctest-vn-04906482 is 46.236.215.129 and allocation pool is NOT set
2026-06-05 17:14:29,389 - DEBUG - Gateway for vn default-domain:ctest-TestQos-05544023:ctest-vn-04906482 is 33f0:7896:5678:cf9:e709:9151:0:1 and allocation pool is NOT set
2026-06-05 17:14:33,469 - 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-06-05 17:14:33,469 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestQos-05544023-03079820 failed!
2026-06-05 17:14:33,483 - DEBUG - Gateway for vn default-domain:ctest-TestQos-05544023:ctest-vn-04906482 is 46.236.215.129 and allocation pool is NOT set
2026-06-05 17:14:33,483 - DEBUG - Gateway for vn default-domain:ctest-TestQos-05544023:ctest-vn-04906482 is 33f0:7896:5678:cf9:e709:9151:0:1 and allocation pool is NOT set
2026-06-05 17:14:37,566 - 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-06-05 17:14:37,566 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestQos-05544023-03079820 failed!
2026-06-05 17:14:37,580 - DEBUG - Gateway for vn default-domain:ctest-TestQos-05544023:ctest-vn-04906482 is 46.236.215.129 and allocation pool is NOT set
2026-06-05 17:14:37,580 - DEBUG - Gateway for vn default-domain:ctest-TestQos-05544023:ctest-vn-04906482 is 33f0:7896:5678:cf9:e709:9151:0:1 and allocation pool is NOT set
2026-06-05 17:14:41,658 - 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')
2026-06-05 17:14:41,658 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestQos-05544023-03079820 failed!
2026-06-05 17:14:41,675 - DEBUG - Gateway for vn default-domain:ctest-TestQos-05544023:ctest-vn-04906482 is 46.236.215.129 and allocation pool is NOT set
2026-06-05 17:14:41,675 - DEBUG - Gateway for vn default-domain:ctest-TestQos-05544023:ctest-vn-04906482 is 33f0:7896:5678:cf9:e709:9151:0:1 and allocation pool is NOT set
2026-06-05 17:14:45,751 - 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-06-05 17:14:45,751 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestQos-05544023-03079820 failed!
2026-06-05 17:14:45,765 - DEBUG - Gateway for vn default-domain:ctest-TestQos-05544023:ctest-vn-04906482 is 46.236.215.129 and allocation pool is NOT set
2026-06-05 17:14:45,765 - DEBUG - Gateway for vn default-domain:ctest-TestQos-05544023:ctest-vn-04906482 is 33f0:7896:5678:cf9:e709:9151:0:1 and allocation pool is NOT set
2026-06-05 17:14:49,853 - 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 1022ms')
2026-06-05 17:14:49,853 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestQos-05544023-03079820 failed!
2026-06-05 17:14:49,869 - DEBUG - Gateway for vn default-domain:ctest-TestQos-05544023:ctest-vn-04906482 is 46.236.215.129 and allocation pool is NOT set
2026-06-05 17:14:49,869 - DEBUG - Gateway for vn default-domain:ctest-TestQos-05544023:ctest-vn-04906482 is 33f0:7896:5678:cf9:e709:9151:0:1 and allocation pool is NOT set
2026-06-05 17:14:51,939 - 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.84 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=3.74 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.736/5.789/7.842/2.053 ms')
2026-06-05 17:14:51,939 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-TestQos-05544023-03079820 passed
2026-06-05 17:14:52,007 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-06-05 17:14:52,008 - DEBUG - Waiting to SSH to VM ctest-TestQos-05544023-03079820, IP 46.236.215.131, Port 22
2026-06-05 17:14:52,075 - 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-06-05 17:14:52,181 - DEBUG - VM ctest-TestQos-05544023-03079820 is NOT ready for SSH connections, VM status: ACTIVE
2026-06-05 17:14:57,181 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-06-05 17:14:57,181 - DEBUG - Waiting to SSH to VM ctest-TestQos-05544023-03079820, IP 46.236.215.131, Port 22
2026-06-05 17:14:57,250 - 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-06-05 17:14:57,345 - DEBUG - VM ctest-TestQos-05544023-03079820 is NOT ready for SSH connections, VM status: ACTIVE
2026-06-05 17:15:02,346 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-06-05 17:15:02,346 - DEBUG - Waiting to SSH to VM ctest-TestQos-05544023-03079820, IP 46.236.215.131, Port 22
2026-06-05 17:15:02,404 - 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-06-05 17:15:02,501 - DEBUG - VM ctest-TestQos-05544023-03079820 is NOT ready for SSH connections, VM status: ACTIVE
2026-06-05 17:15:07,502 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-06-05 17:15:07,502 - DEBUG - Waiting to SSH to VM ctest-TestQos-05544023-03079820, IP 46.236.215.131, Port 22
2026-06-05 17:15:07,580 - 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-06-05 17:15:07,672 - DEBUG - VM ctest-TestQos-05544023-03079820 is NOT ready for SSH connections, VM status: ACTIVE
2026-06-05 17:15:12,672 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-06-05 17:15:12,672 - DEBUG - Waiting to SSH to VM ctest-TestQos-05544023-03079820, IP 46.236.215.131, Port 22
2026-06-05 17:15:12,838 - DEBUG - VM ctest-TestQos-05544023-03079820 is ready for SSH connections
2026-06-05 17:15:12,838 - INFO - Waiting for VM ctest-TestQos-05544023-43743037 to be up..
2026-06-05 17:15:12,930 - DEBUG - VM is in ACTIVE state now
2026-06-05 17:15:12,930 - INFO - VM name : ctest-TestQos-05544023-43743037
2026-06-05 17:15:13,016 - DEBUG - VM ctest-TestQos-05544023-43743037 ID is 08072280-ab9f-4059-af2d-664fcd04dd87
2026-06-05 17:15:13,016 - DEBUG - VM ctest-TestQos-05544023-43743037 launched on Node an-jenkins-deploy-platform-ansible-os-5896-2
2026-06-05 17:15:13,095 - DEBUG - Requesting: http://10.0.0.38:8082/virtual-machine/08072280-ab9f-4059-af2d-664fcd04dd87
2026-06-05 17:15:13,105 - DEBUG - Requesting: http://10.0.0.38:8082/virtual-machine-interface/c6a49d35-ed85-4502-bdbd-315acfb2644b
2026-06-05 17:15:14,273 - 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.66 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=3.01 ms\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1002ms\r\nrtt min/avg/max/mdev = 3.013/3.334/3.655/0.321 ms')
2026-06-05 17:15:14,273 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-TestQos-05544023-43743037 passed
2026-06-05 17:15:14,349 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-06-05 17:15:14,350 - DEBUG - Waiting to SSH to VM ctest-TestQos-05544023-43743037, IP 46.236.215.132, Port 22
2026-06-05 17:15:14,417 - 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-06-05 17:15:14,508 - DEBUG - VM ctest-TestQos-05544023-43743037 is NOT ready for SSH connections, VM status: ACTIVE
2026-06-05 17:15:19,509 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-06-05 17:15:19,509 - DEBUG - Waiting to SSH to VM ctest-TestQos-05544023-43743037, IP 46.236.215.132, Port 22
2026-06-05 17:15:19,577 - 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-06-05 17:15:19,673 - DEBUG - VM ctest-TestQos-05544023-43743037 is NOT ready for SSH connections, VM status: ACTIVE
2026-06-05 17:15:24,674 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-06-05 17:15:24,674 - DEBUG - Waiting to SSH to VM ctest-TestQos-05544023-43743037, IP 46.236.215.132, Port 22
2026-06-05 17:15:24,740 - 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-06-05 17:15:24,841 - DEBUG - VM ctest-TestQos-05544023-43743037 is NOT ready for SSH connections, VM status: ACTIVE
2026-06-05 17:15:29,841 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-06-05 17:15:29,841 - DEBUG - Waiting to SSH to VM ctest-TestQos-05544023-43743037, IP 46.236.215.132, Port 22
2026-06-05 17:15:30,013 - DEBUG - VM ctest-TestQos-05544023-43743037 is ready for SSH connections
2026-06-05 17:15:30,013 - INFO - Waiting for VM ctest-TestQos-05544023-33760436 to be up..
2026-06-05 17:15:30,093 - DEBUG - VM is in ACTIVE state now
2026-06-05 17:15:30,093 - INFO - VM name : ctest-TestQos-05544023-33760436
2026-06-05 17:15:30,172 - DEBUG - VM ctest-TestQos-05544023-33760436 ID is 83e2f710-423f-43f2-a332-25bd2ee70d2f
2026-06-05 17:15:30,172 - DEBUG - VM ctest-TestQos-05544023-33760436 launched on Node an-jenkins-deploy-platform-ansible-os-5896-2
2026-06-05 17:15:30,258 - DEBUG - Requesting: http://10.0.0.38:8082/virtual-machine/83e2f710-423f-43f2-a332-25bd2ee70d2f
2026-06-05 17:15:30,271 - DEBUG - Requesting: http://10.0.0.38:8082/virtual-machine-interface/ea2b4c4d-a3a8-4a12-826e-2ff1670ce263
2026-06-05 17:15:31,452 - 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=4.92 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=0.615 ms\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1000ms\r\nrtt min/avg/max/mdev = 0.615/2.767/4.920/2.152 ms')
2026-06-05 17:15:31,452 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-TestQos-05544023-33760436 passed
2026-06-05 17:15:31,524 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-06-05 17:15:31,524 - DEBUG - Waiting to SSH to VM ctest-TestQos-05544023-33760436, IP 32.6.24.67, Port 22
2026-06-05 17:15:31,686 - DEBUG - VM ctest-TestQos-05544023-33760436 is ready for SSH connections
2026-06-05 17:15:31,689 - INFO - ================================================================================
2026-06-05 17:15:31,689 - INFO - STARTING TEST : test_qos_remark_dscp_on_vmi
2026-06-05 17:15:31,689 - 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-06-05 17:15:32,970 - DEBUG - Nothing to compare xmpp stats {'10.0.0.27': {'10.20.0.14': '0', '10.20.0.129': '0'}, '10.0.0.19': {'10.20.0.18': '0', '10.20.0.14': '0'}} with
2026-06-05 17:15:32,970 - INFO - Initial checks done. Running the testcase now
2026-06-05 17:15:32,970 - INFO -
2026-06-05 17:15:32,978 - DEBUG - FC Dict is {'fc_id': 0, 'dscp': 10, 'dot1p': 1, 'exp': 1, 'connections': }
2026-06-05 17:15:33,255 - INFO - Created FC ['default-global-system-config', 'default-global-qos-config', 'ctest-fc-57344486'], UUID 43500002-113d-4813-8e27-5844e084da2b
2026-06-05 17:15:33,595 - INFO - Created QosConfig ['default-domain', 'ctest-TestQos-05544023', 'ctest-qos_config-17214243'], UUID: b8d45831-d603-4b5a-90da-04afcf1249e5
2026-06-05 17:15:33,647 - INFO - Applying qos-config on VM eba51dad-9bf0-4741-938b-3bda0221288c
2026-06-05 17:15:33,917 - DEBUG - VM is in ACTIVE state now
2026-06-05 17:15:34,171 - DEBUG - Requesting: http://10.0.0.38:8082/virtual-machine/69d840e8-a779-4e8d-8e67-9e2810b1d2c3
2026-06-05 17:15:34,179 - DEBUG - Requesting: http://10.0.0.38:8082/virtual-machine-interface/eba51dad-9bf0-4741-938b-3bda0221288c
2026-06-05 17:15:34,193 - DEBUG - Requesting: http://10.0.0.38:8082/instance-ip/1c637677-f318-4227-8851-dd520038759a
2026-06-05 17:15:34,208 - DEBUG - Requesting: http://10.0.0.38:8082/instance-ip/472a32a7-a498-45d3-b37d-0fab28f40604
2026-06-05 17:15:34,396 - DEBUG - VM is in ACTIVE state now
2026-06-05 17:15:34,611 - DEBUG - Requesting: http://10.0.0.38:8082/virtual-machine/08072280-ab9f-4059-af2d-664fcd04dd87
2026-06-05 17:15:34,618 - DEBUG - Requesting: http://10.0.0.38:8082/virtual-machine-interface/c6a49d35-ed85-4502-bdbd-315acfb2644b
2026-06-05 17:15:34,628 - DEBUG - Requesting: http://10.0.0.38:8082/instance-ip/03b6f661-0603-40b0-9cf1-169f99fb0ecf
2026-06-05 17:15:34,639 - DEBUG - Requesting: http://10.0.0.38:8082/instance-ip/8564636d-36e7-4663-980a-683e2342c11c
2026-06-05 17:15:34,669 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-06-05 17:15:34,669 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-06-05 17:15:34,669 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-06-05 17:15:34,669 - INFO - Starting hping3 on ctest-TestQos-05544023-03079820, args: --destport 20000 --baseport 10000 --count 20000 --interval 1 --udp --tos 4 --keep --numeric
2026-06-05 17:15:34,669 - DEBUG - Hping3 cmd : hping3 --destport 20000 --baseport 10000 --count 20000 --interval 1 --udp --tos 4 --keep --numeric 46.236.215.132 1>/tmp/hping_ctest-random-06438616.log 2>/tmp/hping_ctest-random-06438616.result
2026-06-05 17:15:34,669 - DEBUG - Running remote_cmd, Cmd : hping3 --destport 20000 --baseport 10000 --count 20000 --interval 1 --udp --tos 4 --keep --numeric 46.236.215.132 1>/tmp/hping_ctest-random-06438616.log 2>/tmp/hping_ctest-random-06438616.result, host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.27, gateway password: c0ntrail123
2026-06-05 17:15:34,669 - DEBUG - nohup hping3 --destport 20000 --baseport 10000 --count 20000 --interval 1 --udp --tos 4 --keep --numeric 46.236.215.132 1>/tmp/hping_ctest-random-06438616.log 2>/tmp/hping_ctest-random-06438616.result & echo $! > /tmp/hping_ctest-random-06438616.pid
2026-06-05 17:15:43,191 - DEBUG - None
2026-06-05 17:15:48,365 - DEBUG - Forward flow: {'index': '417260', 'rflow': '63908', 'sip': '46.236.215.131', 'sport': '10000', 'dip': '46.236.215.132', 'dport': '20000', 'proto': '17', 'vrf_id': '2', 'action': 'FORWARD', 'flags': ' ACTIVE | RFLOW_VALID ', 'd_vrf_id': '0', 'bytes': '210', 'pkts': '5', 'insight': '0', 'nhid': '31', 'underlay_udp_sport': '65342', 'ttl': '0', 'qos_id': '0', 'gen_id': '1', 'tcp_seq': '0', 'oflow_bytes': '0', 'oflow_packets': '0', 'underlay_gw_index': '-1'}
2026-06-05 17:15:48,366 - DEBUG - Reverse flow: {'index': '63908', 'rflow': '417260', 'sip': '46.236.215.132', 'sport': '20000', 'dip': '46.236.215.131', 'dport': '10000', 'proto': '17', 'vrf_id': '2', 'action': 'FORWARD', 'flags': ' ACTIVE | RFLOW_VALID ', 'd_vrf_id': '0', 'bytes': '350', 'pkts': '5', 'insight': '0', 'nhid': '31', 'underlay_udp_sport': '59635', 'ttl': '0', 'qos_id': '0', 'gen_id': '1', 'tcp_seq': '0', 'oflow_bytes': '0', 'oflow_packets': '0', 'underlay_gw_index': '-1'}
2026-06-05 17:15:48,366 - DEBUG - The filter pattern is ['udp', 'and', 'src port 65342']
2026-06-05 17:15:48,366 - DEBUG - The filter string is '(udp and src port 65342)'
2026-06-05 17:15:48,447 - DEBUG - Executing command: sudo tcpdump -nni ens6 -U -vvxx '(udp and src port 65342)' -w /tmp/ens6_ctest-random-96768812.pcap
2026-06-05 17:15:53,537 - DEBUG - Executing command: sudo kill $(ps -ef|grep tcpdump | grep pcap| awk '{print $2}')
2026-06-05 17:15:55,540 - DEBUG - Ensuring hping3 instance with result file /tmp/hping_ctest-random-06438616.result on ctest-TestQos-05544023-03079820 is stopped
2026-06-05 17:15:55,540 - DEBUG - Running remote_cmd, Cmd : cat /tmp/hping_ctest-random-06438616.pid | xargs kill , host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.27, gateway password: c0ntrail123
2026-06-05 17:15:55,540 - DEBUG - cat /tmp/hping_ctest-random-06438616.pid | xargs kill
2026-06-05 17:15:56,353 - DEBUG - None
2026-06-05 17:15:56,353 - DEBUG - Running remote_cmd, Cmd : cat /tmp/hping_ctest-random-06438616.result, host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.27, gateway password: c0ntrail123
2026-06-05 17:15:56,353 - DEBUG - cat /tmp/hping_ctest-random-06438616.result
2026-06-05 17:15:56,713 - DEBUG - --- 46.236.215.132 hping statistic ---
13 packets transmitted, 13 packets received, 0% packet loss
round-trip min/avg/max = 16.5/6020.5/12022.2 ms
2026-06-05 17:15:56,713 - DEBUG - Running remote_cmd, Cmd : cat /tmp/hping_ctest-random-06438616.log, host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.27, gateway password: c0ntrail123
2026-06-05 17:15:56,713 - DEBUG - cat /tmp/hping_ctest-random-06438616.log
2026-06-05 17:15:57,057 - DEBUG - HPING 46.236.215.132 (eth0 46.236.215.132): udp mode set, 28 headers + 0 data bytes
ICMP Port Unreachable from ip=46.236.215.132
status=0 port=10000 seq=0
ICMP Port Unreachable from ip=46.236.215.132
status=1 port=10000 seq=0
ICMP Port Unreachable from ip=46.236.215.132
status=1 port=10000 seq=0
ICMP Port Unreachable from ip=46.236.215.132
status=1 port=10000 seq=0
ICMP Port Unreachable from ip=46.236.215.132
status=1 port=10000 seq=0
ICMP Port Unreachable from ip=46.236.215.132
status=1 port=10000 seq=0
ICMP Port Unreachable from ip=46.236.215.132
status=1 port=10000 seq=0
ICMP Port Unreachable from ip=46.236.215.132
status=1 port=10000 seq=0
ICMP Port Unreachable from ip=46.236.215.132
status=1 port=10000 seq=0
ICMP Port Unreachable from ip=46.236.215.132
status=1 port=10000 seq=0
ICMP Port Unreachable from ip=46.236.215.132
status=1 port=10000 seq=0
ICMP Port Unreachable from ip=46.236.215.132
status=1 port=10000 seq=0
ICMP Port Unreachable from ip=46.236.215.132
status=1 port=10000 seq=0
2026-06-05 17:15:57,058 - DEBUG - Hping3 stats: {'sent': '13', 'received': '13', 'loss': '0', 'rtt_min': '16.5', 'rtt_avg': '6020.5', 'rtt_max': '12022.2'}
2026-06-05 17:15:57,058 - DEBUG - Executing command: sudo tcpdump -nnr /tmp/ens6_ctest-random-96768812.pcap | wc -l
2026-06-05 17:15:57,073 - DEBUG - STDOUT: 16
2026-06-05 17:15:57,073 - DEBUG - STDERR: reading from file /tmp/ens6_ctest-random-96768812.pcap, link-type EN10MB (Ethernet), snapshot length 262144
2026-06-05 17:15:57,073 - DEBUG - 16 packets are found in tcpdump output file /tmp/ens6_ctest-random-96768812.pcap but expected 1, which is fine
2026-06-05 17:15:57,073 - INFO - 16 packets are found in tcpdump output as expected
2026-06-05 17:15:57,073 - DEBUG - Executing command: sudo kill $(ps -ef|grep tcpdump | grep pcap| awk '{print $2}')
2026-06-05 17:15:59,135 - DEBUG - ['/contrail-test/ens6_ctest-random-96768812.pcap']
2026-06-05 17:15:59,136 - DEBUG - Verifying for packet number 0
2026-06-05 17:15:59,136 - DEBUG - Validated DSCP marking of 10
2026-06-05 17:15:59,136 - DEBUG - Verifying for packet number 1
2026-06-05 17:15:59,136 - DEBUG - Validated DSCP marking of 10
2026-06-05 17:15:59,136 - DEBUG - Verifying for packet number 2
2026-06-05 17:15:59,136 - DEBUG - Validated DSCP marking of 10
2026-06-05 17:15:59,136 - DEBUG - Verifying for packet number 3
2026-06-05 17:15:59,136 - DEBUG - Validated DSCP marking of 10
2026-06-05 17:15:59,136 - INFO - Packet QoS marking validation passed
2026-06-05 17:15:59,136 - DEBUG - Executing command: sudo tcpdump -nnr /tmp/ens6_ctest-random-96768812.pcap | wc -l
2026-06-05 17:15:59,150 - DEBUG - STDOUT: 16
2026-06-05 17:15:59,150 - DEBUG - STDERR: reading from file /tmp/ens6_ctest-random-96768812.pcap, link-type EN10MB (Ethernet), snapshot length 262144
2026-06-05 17:15:59,150 - DEBUG - 16 packets are found in tcpdump output file /tmp/ens6_ctest-random-96768812.pcap but expected 1, which is fine
2026-06-05 17:15:59,150 - INFO - 16 packets are found in tcpdump output as expected
2026-06-05 17:15:59,150 - DEBUG - Executing command: sudo kill $(ps -ef|grep tcpdump | grep pcap| awk '{print $2}')
2026-06-05 17:16:01,204 - DEBUG - ['/contrail-test/ens6_ctest-random-96768812.pcap']
2026-06-05 17:16:01,204 - DEBUG - Verifying for packet number 0
2026-06-05 17:16:01,204 - DEBUG - Interface ens6 does not seem to be a tagged intf. Skipping dot1p check
2026-06-05 17:16:01,204 - DEBUG - Verifying for packet number 1
2026-06-05 17:16:01,204 - DEBUG - Interface ens6 does not seem to be a tagged intf. Skipping dot1p check
2026-06-05 17:16:01,204 - DEBUG - Verifying for packet number 2
2026-06-05 17:16:01,204 - DEBUG - Interface ens6 does not seem to be a tagged intf. Skipping dot1p check
2026-06-05 17:16:01,204 - DEBUG - Verifying for packet number 3
2026-06-05 17:16:01,204 - DEBUG - Interface ens6 does not seem to be a tagged intf. Skipping dot1p check
2026-06-05 17:16:01,204 - INFO - Packet QoS marking validation passed
2026-06-05 17:16:01,314 - INFO - Removing qos-config on VM eba51dad-9bf0-4741-938b-3bda0221288c
2026-06-05 17:16:01,387 - INFO - Deleting Qos config ['default-domain', 'ctest-TestQos-05544023', 'ctest-qos_config-17214243'], UUID: b8d45831-d603-4b5a-90da-04afcf1249e5
2026-06-05 17:16:01,475 - INFO - Deleting FC ['default-global-system-config', 'default-global-qos-config', 'ctest-fc-57344486'], UUID: 43500002-113d-4813-8e27-5844e084da2b
2026-06-05 17:16:02,830 - DEBUG - No XMPP flaps were noticed during the test
2026-06-05 17:16:02,830 - INFO - --------------------------------------------------------------------------------
2026-06-05 17:16:02,836 - INFO - Deleting VM ctest-TestQos-05544023-33760436
2026-06-05 17:16:02,924 - INFO - Deleting VM ctest-TestQos-05544023-43743037
2026-06-05 17:16:03,034 - INFO - Deleting VM ctest-TestQos-05544023-03079820
2026-06-05 17:16:03,109 - INFO - Deleting VN ctest-vn-70153609
2026-06-05 17:16:03,179 - DEBUG - VN 509c1937-5729-4e25-bf54-0d5db9cff8f4 still in use: Unable to complete operation on network 509c1937-5729-4e25-bf54-0d5db9cff8f4. There are one or more ports still in use on the network.
Neutron server returns request_ids: ['req-149d10c2-d675-4596-af42-bc59a06b66ed']
2026-06-05 17:16:03,179 - WARNING - Deleting VN ctest-vn-70153609 failed..Will retry
2026-06-05 17:16:05,358 - DEBUG - Response for deleting network ()
2026-06-05 17:16:05,359 - INFO - Deleting VN ctest-vn-04906482
2026-06-05 17:16:05,611 - DEBUG - Response for deleting network ()
2026-06-05 17:16:06,421 - INFO - Deleted project: ctest-TestQos-05544023, ID : 6067ffdf-83ef-4e19-9028-db657c574b00