The above is a description of an error in a Python program. Here is
the original traceback:
Traceback (most recent call last):
File "/contrail-test/tcutils/wrappers.py", line 80, in wrapper
result = function(self, *args, **kwargs)
File "/contrail-test/scripts/dsnat/test_dsnat.py", line 326, in test_dsnat_bug_1749695
'Ping to external IP failed with allow-any-policy')
AssertionError: Ping to external IP failed with allow-any-policy
2025-08-11 02:19:26,967 - DEBUG - No XMPP flaps were noticed during the test
2025-08-11 02:19:26,967 - INFO -
2025-08-11 02:19:26,968 - INFO - END TEST : test_dsnat_bug_1749695 : FAILED[0:04:11]
2025-08-11 02:19:26,968 - INFO - --------------------------------------------------------------------------------
2025-08-11 02:19:28,394 - INFO - Deleted project: ctest-TestDSNAT-09942130, ID : 9bb3950b-2ec0-41c8-80ff-2c56d9929668
2025-08-11 03:49:43,546 - INFO - Domain Default found not creating
2025-08-11 03:49:43,698 - INFO - Project ctest-TestDSNAT-81723129 not found, creating it
2025-08-11 03:49:44,245 - INFO - Created Project:ctest-TestDSNAT-81723129, ID : cd6f99a9-3bc0-4983-9dcb-7cdef1ff3aa4
2025-08-11 03:49:45,711 - DEBUG - Services list from nova: [, , , ]
2025-08-11 03:49:45,711 - DEBUG - Hosts: {'nova': ['an-jenkins-deploy-platform-ansible-os-3794-2', 'an-jenkins-deploy-platform-ansible-os-3794-1']}
2025-08-11 03:49:45,711 - INFO - ================================================================================
2025-08-11 03:49:45,711 - INFO - STARTING TEST : test_dsnat_tcp_basic
2025-08-11 03:49:45,711 - INFO - TEST DESCRIPTION :
Configure TCP port translation pool
send TCP traffic from the VM to the fabric IP
Verify the Port address translation happened and the
port being used in the range of configured
2025-08-11 03:49:46,953 - DEBUG - Skipping xmpp flap check
2025-08-11 03:49:46,953 - INFO - Initial checks done. Running the testcase now
2025-08-11 03:49:46,953 - INFO -
2025-08-11 03:49:47,427 - INFO - Create VN, enable FABRIC SNAT and verify its routing instance
2025-08-11 03:49:47,739 - DEBUG - Response for create_network : {'network': {'id': '585a7073-d134-416e-acb8-878ed2ae3dbf', 'name': 'ctest-dsnat_vn-96001968', 'tenant_id': 'cd6f99a93bc049839dcb7cdef1ff3aa4', 'project_id': 'cd6f99a93bc049839dcb7cdef1ff3aa4', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestDSNAT-81723129', 'ctest-dsnat_vn-96001968'], 'port_security_enabled': True, 'description': ''}}
2025-08-11 03:49:47,959 - DEBUG - Response for create_subnet : {'subnet': {'id': 'c073df34-1747-488c-8fad-9d9ae35ce852', 'name': '', 'tenant_id': 'cd6f99a93bc049839dcb7cdef1ff3aa4', 'network_id': '585a7073-d134-416e-acb8-878ed2ae3dbf', 'ip_version': 4, 'cidr': '184.40.1.64/26', 'allocation_pools': [{'start': '184.40.1.66', 'end': '184.40.1.126'}], 'gateway_ip': '184.40.1.65', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '184.40.1.66', 'tags': [], 'project_id': 'cd6f99a93bc049839dcb7cdef1ff3aa4'}}
2025-08-11 03:49:47,981 - INFO - Created VN ctest-dsnat_vn-96001968
2025-08-11 03:49:47,994 - DEBUG - VN ctest-dsnat_vn-96001968 UUID is 585a7073-d134-416e-acb8-878ed2ae3dbf
2025-08-11 03:49:48,167 - DEBUG - Requesting: http://10.0.0.23:8082/virtual-network/585a7073-d134-416e-acb8-878ed2ae3dbf
2025-08-11 03:49:48,455 - DEBUG - Requesting: http://10.0.0.23:8082/virtual-network/585a7073-d134-416e-acb8-878ed2ae3dbf
2025-08-11 03:49:48,488 - DEBUG - Requesting: http://10.0.0.23:8082/routing-instance/ae6c1917-09b3-4703-b413-236abf12e1cd
2025-08-11 03:49:49,554 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-3794-1), Zone: (nova:an-jenkins-deploy-platform-ansible-os-3794-1)
2025-08-11 03:49:50,812 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-3794-2), Zone: (nova:an-jenkins-deploy-platform-ansible-os-3794-2)
2025-08-11 03:49:50,812 - INFO - Waiting for VM ctest-dsnat-vm1-43621446 to be up..
2025-08-11 03:49:50,894 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2025-08-11 03:49:55,975 - DEBUG - VM is in ACTIVE state now
2025-08-11 03:49:55,975 - INFO - VM name : ctest-dsnat-vm1-43621446
2025-08-11 03:49:56,045 - DEBUG - VM ctest-dsnat-vm1-43621446 ID is 7e21be76-11f7-4672-a841-d79fd0dded6c
2025-08-11 03:49:56,067 - DEBUG - VM ctest-dsnat-vm1-43621446 launched on Node an-jenkins-deploy-platform-ansible-os-3794-1
2025-08-11 03:49:56,151 - DEBUG - Requesting: http://10.0.0.141:8082/virtual-machine/7e21be76-11f7-4672-a841-d79fd0dded6c
2025-08-11 03:49:56,441 - DEBUG - Requesting: http://10.0.0.141:8082/virtual-machine/7e21be76-11f7-4672-a841-d79fd0dded6c
2025-08-11 03:49:56,470 - DEBUG - Requesting: http://10.0.0.141:8082/virtual-machine-interface/da2a03a2-22c8-4449-a1c1-418b2a60ebb9
2025-08-11 03:49:59,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 1031ms')
2025-08-11 03:49:59,658 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-dsnat-vm1-43621446 failed!
2025-08-11 03:49:59,674 - DEBUG - Gateway for vn default-domain:ctest-TestDSNAT-81723129:ctest-dsnat_vn-96001968 is 184.40.1.65 and allocation pool is NOT set
2025-08-11 03:50:03,745 - 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')
2025-08-11 03:50:03,745 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-dsnat-vm1-43621446 failed!
2025-08-11 03:50:03,759 - DEBUG - Gateway for vn default-domain:ctest-TestDSNAT-81723129:ctest-dsnat_vn-96001968 is 184.40.1.65 and allocation pool is NOT set
2025-08-11 03:50:07,847 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1026ms')
2025-08-11 03:50:07,847 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-dsnat-vm1-43621446 failed!
2025-08-11 03:50:07,862 - DEBUG - Gateway for vn default-domain:ctest-TestDSNAT-81723129:ctest-dsnat_vn-96001968 is 184.40.1.65 and allocation pool is NOT set
2025-08-11 03:50:11,943 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1018ms')
2025-08-11 03:50:11,943 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-dsnat-vm1-43621446 failed!
2025-08-11 03:50:11,958 - DEBUG - Gateway for vn default-domain:ctest-TestDSNAT-81723129:ctest-dsnat_vn-96001968 is 184.40.1.65 and allocation pool is NOT set
2025-08-11 03:50:16,033 - 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')
2025-08-11 03:50:16,033 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-dsnat-vm1-43621446 failed!
2025-08-11 03:50:16,047 - DEBUG - Gateway for vn default-domain:ctest-TestDSNAT-81723129:ctest-dsnat_vn-96001968 is 184.40.1.65 and allocation pool is NOT set
2025-08-11 03:50:20,133 - 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 1024ms')
2025-08-11 03:50:20,133 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-dsnat-vm1-43621446 failed!
2025-08-11 03:50:20,148 - DEBUG - Gateway for vn default-domain:ctest-TestDSNAT-81723129:ctest-dsnat_vn-96001968 is 184.40.1.65 and allocation pool is NOT set
2025-08-11 03:50:24,230 - 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')
2025-08-11 03:50:24,230 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-dsnat-vm1-43621446 failed!
2025-08-11 03:50:24,243 - DEBUG - Gateway for vn default-domain:ctest-TestDSNAT-81723129:ctest-dsnat_vn-96001968 is 184.40.1.65 and allocation pool is NOT set
2025-08-11 03:50:26,311 - 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=5.77 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=2.98 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 = 2.983/4.376/5.769/1.393 ms')
2025-08-11 03:50:26,311 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-dsnat-vm1-43621446 passed
2025-08-11 03:50:26,385 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-11 03:50:26,385 - DEBUG - Waiting to SSH to VM ctest-dsnat-vm1-43621446, IP 184.40.1.67, Port 22
2025-08-11 03:50:26,440 - DEBUG - Error on ssh to ubuntu@169.254.0.3:22, result: /bin/bash: connect: Connection refused
/bin/bash: line 1: /dev/tcp/169.254.0.3/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.3/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.3/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''}
2025-08-11 03:50:26,551 - DEBUG - VM ctest-dsnat-vm1-43621446 is NOT ready for SSH connections, VM status: ACTIVE
2025-08-11 03:50:31,552 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-11 03:50:31,552 - DEBUG - Waiting to SSH to VM ctest-dsnat-vm1-43621446, IP 184.40.1.67, Port 22
2025-08-11 03:50:31,608 - DEBUG - Error on ssh to ubuntu@169.254.0.3:22, result: /bin/bash: connect: Connection refused
/bin/bash: line 1: /dev/tcp/169.254.0.3/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.3/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.3/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''}
2025-08-11 03:50:31,690 - DEBUG - VM ctest-dsnat-vm1-43621446 is NOT ready for SSH connections, VM status: ACTIVE
2025-08-11 03:50:36,690 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-11 03:50:36,691 - DEBUG - Waiting to SSH to VM ctest-dsnat-vm1-43621446, IP 184.40.1.67, Port 22
2025-08-11 03:50:36,747 - DEBUG - Error on ssh to ubuntu@169.254.0.3:22, result: /bin/bash: connect: Connection refused
/bin/bash: line 1: /dev/tcp/169.254.0.3/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.3/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.3/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''}
2025-08-11 03:50:36,822 - DEBUG - VM ctest-dsnat-vm1-43621446 is NOT ready for SSH connections, VM status: ACTIVE
2025-08-11 03:50:41,823 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-11 03:50:41,823 - DEBUG - Waiting to SSH to VM ctest-dsnat-vm1-43621446, IP 184.40.1.67, Port 22
2025-08-11 03:50:41,880 - DEBUG - Error on ssh to ubuntu@169.254.0.3:22, result: /bin/bash: connect: Connection refused
/bin/bash: line 1: /dev/tcp/169.254.0.3/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.3/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.3/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''}
2025-08-11 03:50:41,999 - DEBUG - VM ctest-dsnat-vm1-43621446 is NOT ready for SSH connections, VM status: ACTIVE
2025-08-11 03:50:47,000 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-11 03:50:47,001 - DEBUG - Waiting to SSH to VM ctest-dsnat-vm1-43621446, IP 184.40.1.67, Port 22
2025-08-11 03:50:47,156 - DEBUG - VM ctest-dsnat-vm1-43621446 is ready for SSH connections
2025-08-11 03:50:47,156 - INFO - Waiting for VM ctest-dsnat-vm2-43406689 to be up..
2025-08-11 03:50:47,241 - DEBUG - VM is in ACTIVE state now
2025-08-11 03:50:47,241 - INFO - VM name : ctest-dsnat-vm2-43406689
2025-08-11 03:50:47,327 - DEBUG - VM ctest-dsnat-vm2-43406689 ID is 8b723780-e0bc-47b3-9b9b-d4e20cdaf5b2
2025-08-11 03:50:47,328 - DEBUG - VM ctest-dsnat-vm2-43406689 launched on Node an-jenkins-deploy-platform-ansible-os-3794-2
2025-08-11 03:50:47,414 - DEBUG - Requesting: http://10.0.0.141:8082/virtual-machine/8b723780-e0bc-47b3-9b9b-d4e20cdaf5b2
2025-08-11 03:50:47,424 - DEBUG - Requesting: http://10.0.0.141:8082/virtual-machine-interface/8f0e36d1-4806-441c-bc07-8dbd2fce68a5
2025-08-11 03:50:48,586 - 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=2.99 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=1.92 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 = 1.916/2.450/2.985/0.534 ms')
2025-08-11 03:50:48,587 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-dsnat-vm2-43406689 passed
2025-08-11 03:50:48,667 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-11 03:50:48,667 - DEBUG - Waiting to SSH to VM ctest-dsnat-vm2-43406689, IP 184.40.1.68, Port 22
2025-08-11 03:50:48,835 - DEBUG - VM ctest-dsnat-vm2-43406689 is ready for SSH connections
2025-08-11 03:50:48,935 - DEBUG - command output is cat: /tmp/iperf_server_ctest-random-03656435.pid: No such file or directory
kill: usage: kill [-s sigspec | -n signum | -sigspec] pid | jobspec ... or kill -l [sigspec]
2025-08-11 03:50:49,050 - DEBUG - command output is
2025-08-11 03:50:49,050 - INFO - Starting Iperf3 on ctest-dsnat-vm1-43621446, args: --port 6201 --length 1048576 --time 10
2025-08-11 03:50:49,050 - DEBUG - Iperf3 cmd : iperf3 -c 10.20.0.201 --port 6201 --length 1048576 --time 10 1>/tmp/iper3_ctest-random-03656435.log 2>/tmp/iper3_ctest-random-03656435.result
2025-08-11 03:50:49,050 - INFO - Excecuting cmds, ['iperf3 -s --port 6201 1>/tmp/iper3_ctest-random-03656435.log 2>/tmp/iper3_ctest-random-03656435.result'], on server 10.0.0.65
2025-08-11 03:50:49,147 - DEBUG - command output is ['']
2025-08-11 03:50:49,147 - DEBUG - Running remote_cmd, Cmd : iperf3 -c 10.20.0.201 --port 6201 --length 1048576 --time 10 1>/tmp/iper3_ctest-random-03656435.log 2>/tmp/iper3_ctest-random-03656435.result, host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.57, gateway password: c0ntrail123
2025-08-11 03:50:49,147 - DEBUG - nohup iperf3 -c 10.20.0.201 --port 6201 --length 1048576 --time 10 1>/tmp/iper3_ctest-random-03656435.log 2>/tmp/iper3_ctest-random-03656435.result & echo $! > /tmp/iperf_client_ctest-random-03656435.pid
2025-08-11 03:51:03,898 - DEBUG - None
2025-08-11 03:51:07,142 - DEBUG - Returns multiple flows, [], matching flow data as list of tuples
2025-08-11 03:51:07,211 - DEBUG - command output is /bin/bash: line 1: kill: (60004) - No such process
2025-08-11 03:51:07,310 - DEBUG - command output is
2025-08-11 03:51:07,310 - INFO - Nat port being used for the flow is []
2025-08-11 03:51:12,379 - DEBUG - command output is /bin/bash: line 1: kill: (60004) - No such process
2025-08-11 03:51:12,494 - DEBUG - command output is
2025-08-11 03:51:12,494 - INFO - Starting Iperf3 on ctest-dsnat-vm1-43621446, args: --port 6201 --length 1048576 --time 10
2025-08-11 03:51:12,494 - DEBUG - Iperf3 cmd : iperf3 -c 10.20.0.201 --port 6201 --length 1048576 --time 10 1>/tmp/iper3_ctest-random-03656435.log 2>/tmp/iper3_ctest-random-03656435.result
2025-08-11 03:51:12,494 - INFO - Excecuting cmds, ['iperf3 -s --port 6201 1>/tmp/iper3_ctest-random-03656435.log 2>/tmp/iper3_ctest-random-03656435.result'], on server 10.0.0.65
2025-08-11 03:51:12,595 - DEBUG - command output is ['']
2025-08-11 03:51:12,595 - DEBUG - Running remote_cmd, Cmd : iperf3 -c 10.20.0.201 --port 6201 --length 1048576 --time 10 1>/tmp/iper3_ctest-random-03656435.log 2>/tmp/iper3_ctest-random-03656435.result, host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.57, gateway password: c0ntrail123
2025-08-11 03:51:12,595 - DEBUG - nohup iperf3 -c 10.20.0.201 --port 6201 --length 1048576 --time 10 1>/tmp/iper3_ctest-random-03656435.log 2>/tmp/iper3_ctest-random-03656435.result & echo $! > /tmp/iperf_client_ctest-random-03656435.pid
2025-08-11 03:51:12,987 - DEBUG - None
2025-08-11 03:51:16,229 - DEBUG - Returns multiple flows, [], matching flow data as list of tuples
2025-08-11 03:51:16,295 - DEBUG - command output is /bin/bash: line 1: kill: (60096) - No such process
2025-08-11 03:51:16,399 - DEBUG - command output is
2025-08-11 03:51:16,399 - INFO - Nat port being used for the flow is []
2025-08-11 03:51:21,468 - DEBUG - command output is /bin/bash: line 1: kill: (60096) - No such process
2025-08-11 03:51:21,571 - DEBUG - command output is
2025-08-11 03:51:21,571 - INFO - Starting Iperf3 on ctest-dsnat-vm1-43621446, args: --port 6201 --length 1048576 --time 10
2025-08-11 03:51:21,571 - DEBUG - Iperf3 cmd : iperf3 -c 10.20.0.201 --port 6201 --length 1048576 --time 10 1>/tmp/iper3_ctest-random-03656435.log 2>/tmp/iper3_ctest-random-03656435.result
2025-08-11 03:51:21,571 - INFO - Excecuting cmds, ['iperf3 -s --port 6201 1>/tmp/iper3_ctest-random-03656435.log 2>/tmp/iper3_ctest-random-03656435.result'], on server 10.0.0.65
2025-08-11 03:51:21,679 - DEBUG - command output is ['']
2025-08-11 03:51:21,679 - DEBUG - Running remote_cmd, Cmd : iperf3 -c 10.20.0.201 --port 6201 --length 1048576 --time 10 1>/tmp/iper3_ctest-random-03656435.log 2>/tmp/iper3_ctest-random-03656435.result, host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.57, gateway password: c0ntrail123
2025-08-11 03:51:21,679 - DEBUG - nohup iperf3 -c 10.20.0.201 --port 6201 --length 1048576 --time 10 1>/tmp/iper3_ctest-random-03656435.log 2>/tmp/iper3_ctest-random-03656435.result & echo $! > /tmp/iperf_client_ctest-random-03656435.pid
2025-08-11 03:51:22,091 - DEBUG - None
2025-08-11 03:51:25,397 - DEBUG - Returns multiple flows, [], matching flow data as list of tuples
2025-08-11 03:51:25,464 - DEBUG - command output is /bin/bash: line 1: kill: (60169) - No such process
2025-08-11 03:51:25,567 - DEBUG - command output is
2025-08-11 03:51:25,567 - INFO - Nat port being used for the flow is []
2025-08-11 03:51:30,635 - DEBUG - command output is /bin/bash: line 1: kill: (60169) - No such process
2025-08-11 03:51:30,738 - DEBUG - command output is
2025-08-11 03:51:30,738 - INFO - Starting Iperf3 on ctest-dsnat-vm1-43621446, args: --port 6201 --length 1048576 --time 10
2025-08-11 03:51:30,739 - DEBUG - Iperf3 cmd : iperf3 -c 10.20.0.201 --port 6201 --length 1048576 --time 10 1>/tmp/iper3_ctest-random-03656435.log 2>/tmp/iper3_ctest-random-03656435.result
2025-08-11 03:51:30,739 - INFO - Excecuting cmds, ['iperf3 -s --port 6201 1>/tmp/iper3_ctest-random-03656435.log 2>/tmp/iper3_ctest-random-03656435.result'], on server 10.0.0.65
2025-08-11 03:51:30,847 - DEBUG - command output is ['']
2025-08-11 03:51:30,848 - DEBUG - Running remote_cmd, Cmd : iperf3 -c 10.20.0.201 --port 6201 --length 1048576 --time 10 1>/tmp/iper3_ctest-random-03656435.log 2>/tmp/iper3_ctest-random-03656435.result, host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.57, gateway password: c0ntrail123
2025-08-11 03:51:30,848 - DEBUG - nohup iperf3 -c 10.20.0.201 --port 6201 --length 1048576 --time 10 1>/tmp/iper3_ctest-random-03656435.log 2>/tmp/iper3_ctest-random-03656435.result & echo $! > /tmp/iperf_client_ctest-random-03656435.pid
2025-08-11 03:51:31,238 - DEBUG - None
2025-08-11 03:51:34,511 - DEBUG - Returns multiple flows, [], matching flow data as list of tuples
2025-08-11 03:51:34,579 - DEBUG - command output is /bin/bash: line 1: kill: (60332) - No such process
2025-08-11 03:51:34,680 - DEBUG - command output is
2025-08-11 03:51:34,680 - INFO - Nat port being used for the flow is []
2025-08-11 03:51:39,752 - DEBUG - command output is /bin/bash: line 1: kill: (60332) - No such process
2025-08-11 03:51:39,852 - DEBUG - command output is
2025-08-11 03:51:39,852 - INFO - Starting Iperf3 on ctest-dsnat-vm1-43621446, args: --port 6201 --length 1048576 --time 10
2025-08-11 03:51:39,852 - DEBUG - Iperf3 cmd : iperf3 -c 10.20.0.201 --port 6201 --length 1048576 --time 10 1>/tmp/iper3_ctest-random-03656435.log 2>/tmp/iper3_ctest-random-03656435.result
2025-08-11 03:51:39,852 - INFO - Excecuting cmds, ['iperf3 -s --port 6201 1>/tmp/iper3_ctest-random-03656435.log 2>/tmp/iper3_ctest-random-03656435.result'], on server 10.0.0.65
2025-08-11 03:51:39,960 - DEBUG - command output is ['']
2025-08-11 03:51:39,961 - DEBUG - Running remote_cmd, Cmd : iperf3 -c 10.20.0.201 --port 6201 --length 1048576 --time 10 1>/tmp/iper3_ctest-random-03656435.log 2>/tmp/iper3_ctest-random-03656435.result, host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.57, gateway password: c0ntrail123
2025-08-11 03:51:39,961 - DEBUG - nohup iperf3 -c 10.20.0.201 --port 6201 --length 1048576 --time 10 1>/tmp/iper3_ctest-random-03656435.log 2>/tmp/iper3_ctest-random-03656435.result & echo $! > /tmp/iperf_client_ctest-random-03656435.pid
2025-08-11 03:51:40,370 - DEBUG - None
2025-08-11 03:51:43,630 - DEBUG - Returns multiple flows, [], matching flow data as list of tuples
2025-08-11 03:51:43,699 - DEBUG - command output is /bin/bash: line 1: kill: (60371) - No such process
2025-08-11 03:51:43,804 - DEBUG - command output is
2025-08-11 03:51:43,804 - INFO - Nat port being used for the flow is []
2025-08-11 03:51:48,872 - DEBUG - command output is /bin/bash: line 1: kill: (60371) - No such process
2025-08-11 03:51:48,979 - DEBUG - command output is
2025-08-11 03:51:48,979 - INFO - Starting Iperf3 on ctest-dsnat-vm1-43621446, args: --port 6201 --length 1048576 --time 10
2025-08-11 03:51:48,979 - DEBUG - Iperf3 cmd : iperf3 -c 10.20.0.201 --port 6201 --length 1048576 --time 10 1>/tmp/iper3_ctest-random-03656435.log 2>/tmp/iper3_ctest-random-03656435.result
2025-08-11 03:51:48,979 - INFO - Excecuting cmds, ['iperf3 -s --port 6201 1>/tmp/iper3_ctest-random-03656435.log 2>/tmp/iper3_ctest-random-03656435.result'], on server 10.0.0.65
2025-08-11 03:51:49,087 - DEBUG - command output is ['']
2025-08-11 03:51:49,087 - DEBUG - Running remote_cmd, Cmd : iperf3 -c 10.20.0.201 --port 6201 --length 1048576 --time 10 1>/tmp/iper3_ctest-random-03656435.log 2>/tmp/iper3_ctest-random-03656435.result, host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.57, gateway password: c0ntrail123
2025-08-11 03:51:49,087 - DEBUG - nohup iperf3 -c 10.20.0.201 --port 6201 --length 1048576 --time 10 1>/tmp/iper3_ctest-random-03656435.log 2>/tmp/iper3_ctest-random-03656435.result & echo $! > /tmp/iperf_client_ctest-random-03656435.pid
2025-08-11 03:51:49,488 - DEBUG - None
2025-08-11 03:51:52,735 - DEBUG - Returns multiple flows, [], matching flow data as list of tuples
2025-08-11 03:51:52,803 - DEBUG - command output is /bin/bash: line 1: kill: (60430) - No such process
2025-08-11 03:51:52,907 - DEBUG - command output is
2025-08-11 03:51:52,907 - INFO - Nat port being used for the flow is []
2025-08-11 03:51:53,019 - DEBUG - command output is /bin/bash: line 1: kill: (60430) - No such process
2025-08-11 03:51:53,119 - DEBUG - command output is
2025-08-11 03:51:53,119 - INFO - Deleting VM ctest-dsnat-vm2-43406689
2025-08-11 03:51:53,178 - INFO - Deleting VM ctest-dsnat-vm1-43621446
2025-08-11 03:51:53,237 - INFO - Deleting VN ctest-dsnat_vn-96001968
2025-08-11 03:51:53,272 - DEBUG - VN 585a7073-d134-416e-acb8-878ed2ae3dbf still in use: Unable to complete operation on network 585a7073-d134-416e-acb8-878ed2ae3dbf. There are one or more ports still in use on the network.
Neutron server returns request_ids: ['req-19bd50ca-d967-449f-901e-810abfe4efc8']
2025-08-11 03:51:53,273 - WARNING - Deleting VN ctest-dsnat_vn-96001968 failed..Will retry
2025-08-11 03:51:55,447 - DEBUG - Response for deleting network ()
2025-08-11 03:51:56,708 - ERROR - AssertionError
Python 3.6.8: /usr/bin/python3
Mon Aug 11 03:51:52 2025
A problem occurred in a Python script. Here is the sequence of
function calls leading up to the error, in the order they occurred.
/contrail-test/tcutils/wrappers.py in wrapper(self=, *args=(), **kwargs={})
78 log.info('Initial checks done. Running the testcase now')
79 log.info('')
80 result = function(self, *args, **kwargs)
81 if self.inputs.upgrade:
82 pid = os.getpid()
result = None
function =
self =
args = ()
kwargs = {}
/contrail-test/serial_scripts/dsnat/test_dsnat.py in test_dsnat_tcp_basic(self=)
108 self.iperf = None
109
110 assert self.verify_flow_with_port(vm1_fixture, vm2_fixture, port_range, **traffic)
111
112 @preposttest_wrapper
self =
self.verify_flow_with_port = .deco_retry.....test_dsnat_tcp_basic[sanity] id=0x7f77497b5748>>
vm1_fixture =
vm2_fixture =
port_range = [65000, 65001, 65002, 65003, 65004, 65005, 65006, 65007, 65008, 65009]
traffic = {'port': 6201, 'udp': False}
AssertionError:
__cause__ = None
__class__ =
__context__ = None
__delattr__ =
__dict__ = {}
__dir__ =
__doc__ = 'Assertion failed.'
__eq__ =
__format__ =
__ge__ =
__getattribute__ =
__gt__ =
__hash__ =
__init__ =
__init_subclass__ =
__le__ =
__lt__ =
__ne__ =
__new__ =
__reduce__ =
__reduce_ex__ =
__repr__ =
__setattr__ =
__setstate__ =
__sizeof__ =
__str__ =
__subclasshook__ =
__suppress_context__ = False
__traceback__ =
args = ()
with_traceback =
The above is a description of an error in a Python program. Here is
the original traceback:
Traceback (most recent call last):
File "/contrail-test/tcutils/wrappers.py", line 80, in wrapper
result = function(self, *args, **kwargs)
File "/contrail-test/serial_scripts/dsnat/test_dsnat.py", line 110, in test_dsnat_tcp_basic
assert self.verify_flow_with_port(vm1_fixture, vm2_fixture, port_range, **traffic)
AssertionError
2025-08-11 03:51:56,709 - DEBUG - Skipping xmpp flap check
2025-08-11 03:51:56,709 - INFO -
2025-08-11 03:51:56,709 - INFO - END TEST : test_dsnat_tcp_basic : FAILED[0:02:11]
2025-08-11 03:51:56,709 - INFO - --------------------------------------------------------------------------------
2025-08-11 03:51:57,384 - INFO - Deleted project: ctest-TestDSNAT-81723129, ID : cd6f99a9-3bc0-4983-9dcb-7cdef1ff3aa4