2025-07-31 02:37:56,255 - INFO - Domain Default found not creating 2025-07-31 02:37:56,470 - INFO - Project ctest-TestBGPaaS-53610747 not found, creating it 2025-07-31 02:37:57,048 - INFO - Created Project:ctest-TestBGPaaS-53610747, ID : ff3f6a15-d569-40a4-8988-6af8e3adb889 2025-07-31 02:37:58,682 - INFO - Using existing project ['default-domain', 'admin'](2761afbf-24b2-4f6f-abe2-e910af9609e1) 2025-07-31 02:37:59,538 - INFO - Adding rules to the default security group in Project admin 2025-07-31 02:37:59,926 - DEBUG - Services list from nova: [, , , ] 2025-07-31 02:37:59,926 - DEBUG - Hosts: {'nova': ['an-jenkins-deploy-platform-ansible-os-3732-1', 'an-jenkins-deploy-platform-ansible-os-3732-2']} 2025-07-31 02:37:59,928 - INFO - ================================================================================ 2025-07-31 02:37:59,928 - INFO - STARTING TEST : test_bgpaas_basic 2025-07-31 02:37:59,928 - INFO - TEST DESCRIPTION : 1. Create a BGPaaS object with shared attribute, IP address and ASN. 2. Launch a VM which will act as the BGPaaS client. 3. Configure BFDoBGPaaS on it. 4. Verify BGP and BFD sessions over it come up fine. Maintainer: ganeshahv@juniper.net 2025-07-31 02:38:00,605 - DEBUG - Nothing to compare xmpp stats {'10.0.0.27': {'10.20.0.193': '0', '10.20.0.18': '0'}, '10.0.0.57': {'10.20.0.18': '0', '10.20.0.193': '0'}} with 2025-07-31 02:38:00,605 - INFO - Initial checks done. Running the testcase now 2025-07-31 02:38:00,605 - INFO - 2025-07-31 02:38:01,504 - DEBUG - Response for create_network : {'network': {'id': 'e7be9a04-1441-415f-95d3-4bfa63581220', 'name': 'ctest-bgpaas_vn-44387333', 'tenant_id': 'ff3f6a15d56940a489886af8e3adb889', 'project_id': 'ff3f6a15d56940a489886af8e3adb889', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestBGPaaS-53610747', 'ctest-bgpaas_vn-44387333'], 'port_security_enabled': True, 'description': ''}} 2025-07-31 02:38:01,847 - DEBUG - Response for create_subnet : {'subnet': {'id': 'da0872f7-24c0-4542-ab31-c6926edf4e71', 'name': '', 'tenant_id': 'ff3f6a15d56940a489886af8e3adb889', 'network_id': 'e7be9a04-1441-415f-95d3-4bfa63581220', 'ip_version': 4, 'cidr': '1.145.231.128/26', 'allocation_pools': [{'start': '1.145.231.130', 'end': '1.145.231.190'}], 'gateway_ip': '1.145.231.129', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '1.145.231.130', 'tags': [], 'project_id': 'ff3f6a15d56940a489886af8e3adb889'}} 2025-07-31 02:38:01,870 - INFO - Created VN ctest-bgpaas_vn-44387333 2025-07-31 02:38:01,885 - DEBUG - VN ctest-bgpaas_vn-44387333 UUID is e7be9a04-1441-415f-95d3-4bfa63581220 2025-07-31 02:38:02,032 - DEBUG - Image by name ubuntu-bird not found 2025-07-31 02:38:02,032 - DEBUG - Installing image ubuntu-bird 2025-07-31 02:38:02,032 - DEBUG - Image info {'name': 'ubuntu-bird.vmdk.gz', 'webserver': '', 'location': '/images/converts/', 'username': 'ubuntu', 'password': 'ubuntu', 'type': 'os', 'flavor': 'contrail_flavor_small', 'params': '--container-format bare --disk-format vmdk --property vmware_disktype="sparse" --property vmware_adaptertype="ide" --property hw_scsi_model=virtio-scsi --property hw_disk_bus_model=virtio-scsi --property hw_disk_bus=virtio', 'name_docker': 'phusion-baseimage-enablesshd'} 2025-07-31 02:38:02,033 - DEBUG - Image build path http://nexus.opensdn.io/repository///images/converts//ubuntu-bird.vmdk.gz 2025-07-31 02:38:02,033 - DEBUG - Download image from web http://nexus.opensdn.io/repository///images/converts//ubuntu-bird.vmdk.gz 2025-07-31 02:38:02,042 - DEBUG - Image download (local=True) (proxy=None): Execute cmd: wget -nv http://nexus.opensdn.io/repository///images/converts//ubuntu-bird.vmdk.gz -O /contrail-test/images/ubuntu-bird.vmdk.gz 2025-07-31 02:38:04,711 - DEBUG - Image has been downloaded to /contrail-test/images/ubuntu-bird.vmdk.gz 2025-07-31 02:38:04,713 - DEBUG - Unzip image 2025-07-31 02:38:04,713 - DEBUG - Image download (local=True) (proxy=None): Execute cmd: gunzip -f /contrail-test/images/ubuntu-bird.vmdk.gz 2025-07-31 02:38:14,758 - DEBUG - Try to create image in user context 2025-07-31 02:38:22,717 - DEBUG - Image has been created in user context 2025-07-31 02:38:22,718 - DEBUG - Image download (local=True) (proxy=None): Execute cmd: rm -f /contrail-test/images/ubuntu-bird.vmdk 2025-07-31 02:38:22,902 - DEBUG - Downloaded image has been removed 2025-07-31 02:38:22,931 - DEBUG - Uploaded image status = active 2025-07-31 02:38:24,352 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-3732-1), Zone: (nova:an-jenkins-deploy-platform-ansible-os-3732-1) 2025-07-31 02:38:24,352 - INFO - Waiting for VM bgpaas_vm1 to be up.. 2025-07-31 02:38:24,415 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2025-07-31 02:38:29,592 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2025-07-31 02:38:34,728 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2025-07-31 02:38:39,858 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2025-07-31 02:38:45,066 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2025-07-31 02:38:50,261 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2025-07-31 02:38:55,398 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2025-07-31 02:39:00,500 - DEBUG - VM is in ACTIVE state now 2025-07-31 02:39:00,500 - INFO - VM name : bgpaas_vm1 2025-07-31 02:39:00,713 - DEBUG - VM bgpaas_vm1 ID is f5cc9633-3e95-4e71-9822-56c6a21b22a9 2025-07-31 02:39:00,736 - DEBUG - VM bgpaas_vm1 launched on Node an-jenkins-deploy-platform-ansible-os-3732-1 2025-07-31 02:39:00,826 - DEBUG - Requesting: http://10.0.0.61:8082/virtual-machine/f5cc9633-3e95-4e71-9822-56c6a21b22a9 2025-07-31 02:39:01,123 - DEBUG - Requesting: http://10.0.0.61:8082/virtual-machine/f5cc9633-3e95-4e71-9822-56c6a21b22a9 2025-07-31 02:39:01,160 - DEBUG - Requesting: http://10.0.0.61:8082/virtual-machine-interface/20b52fea-eed6-4bc5-b485-aa5863b1b375 2025-07-31 02:39:04,363 - 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') 2025-07-31 02:39:04,363 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM bgpaas_vm1 failed! 2025-07-31 02:39:04,386 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaaS-53610747:ctest-bgpaas_vn-44387333 is 1.145.231.129 and allocation pool is NOT set 2025-07-31 02:39:08,423 - 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 1012ms') 2025-07-31 02:39:08,424 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM bgpaas_vm1 failed! 2025-07-31 02:39:08,450 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaaS-53610747:ctest-bgpaas_vn-44387333 is 1.145.231.129 and allocation pool is NOT set 2025-07-31 02:39:12,483 - 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') 2025-07-31 02:39:12,484 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM bgpaas_vm1 failed! 2025-07-31 02:39:12,503 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaaS-53610747:ctest-bgpaas_vn-44387333 is 1.145.231.129 and allocation pool is NOT set 2025-07-31 02:39:16,556 - 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 1025ms') 2025-07-31 02:39:16,557 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM bgpaas_vm1 failed! 2025-07-31 02:39:16,584 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaaS-53610747:ctest-bgpaas_vn-44387333 is 1.145.231.129 and allocation pool is NOT set 2025-07-31 02:39:20,619 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1008ms') 2025-07-31 02:39:20,620 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM bgpaas_vm1 failed! 2025-07-31 02:39:20,651 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaaS-53610747:ctest-bgpaas_vn-44387333 is 1.145.231.129 and allocation pool is NOT set 2025-07-31 02:39:24,675 - 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') 2025-07-31 02:39:24,675 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM bgpaas_vm1 failed! 2025-07-31 02:39:24,692 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaaS-53610747:ctest-bgpaas_vn-44387333 is 1.145.231.129 and allocation pool is NOT set 2025-07-31 02:39:28,748 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1024ms') 2025-07-31 02:39:28,749 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM bgpaas_vm1 failed! 2025-07-31 02:39:28,774 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaaS-53610747:ctest-bgpaas_vn-44387333 is 1.145.231.129 and allocation pool is NOT set 2025-07-31 02:39:32,811 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1011ms') 2025-07-31 02:39:32,811 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM bgpaas_vm1 failed! 2025-07-31 02:39:32,838 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaaS-53610747:ctest-bgpaas_vn-44387333 is 1.145.231.129 and allocation pool is NOT set 2025-07-31 02:39:36,875 - 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 1012ms') 2025-07-31 02:39:36,876 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM bgpaas_vm1 failed! 2025-07-31 02:39:36,901 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaaS-53610747:ctest-bgpaas_vn-44387333 is 1.145.231.129 and allocation pool is NOT set 2025-07-31 02:39:40,938 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1015ms') 2025-07-31 02:39:40,939 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM bgpaas_vm1 failed! 2025-07-31 02:39:40,968 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaaS-53610747:ctest-bgpaas_vn-44387333 is 1.145.231.129 and allocation pool is NOT set 2025-07-31 02:39:45,001 - 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') 2025-07-31 02:39:45,002 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM bgpaas_vm1 failed! 2025-07-31 02:39:45,029 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaaS-53610747:ctest-bgpaas_vn-44387333 is 1.145.231.129 and allocation pool is NOT set 2025-07-31 02:39:49,061 - 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') 2025-07-31 02:39:49,061 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM bgpaas_vm1 failed! 2025-07-31 02:39:49,084 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaaS-53610747:ctest-bgpaas_vn-44387333 is 1.145.231.129 and allocation pool is NOT set 2025-07-31 02:39:53,125 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1023ms') 2025-07-31 02:39:53,126 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM bgpaas_vm1 failed! 2025-07-31 02:39:53,154 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaaS-53610747:ctest-bgpaas_vn-44387333 is 1.145.231.129 and allocation pool is NOT set 2025-07-31 02:39:57,190 - 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 1012ms') 2025-07-31 02:39:57,191 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM bgpaas_vm1 failed! 2025-07-31 02:39:57,216 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaaS-53610747:ctest-bgpaas_vn-44387333 is 1.145.231.129 and allocation pool is NOT set 2025-07-31 02:40:01,255 - 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') 2025-07-31 02:40:01,255 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM bgpaas_vm1 failed! 2025-07-31 02:40:01,275 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaaS-53610747:ctest-bgpaas_vn-44387333 is 1.145.231.129 and allocation pool is NOT set 2025-07-31 02:40:05,315 - 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-07-31 02:40:05,315 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM bgpaas_vm1 failed! 2025-07-31 02:40:05,335 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaaS-53610747:ctest-bgpaas_vn-44387333 is 1.145.231.129 and allocation pool is NOT set 2025-07-31 02:40:09,388 - 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 1025ms') 2025-07-31 02:40:09,389 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM bgpaas_vm1 failed! 2025-07-31 02:40:09,413 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaaS-53610747:ctest-bgpaas_vn-44387333 is 1.145.231.129 and allocation pool is NOT set 2025-07-31 02:40:11,436 - 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=1.68 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=1.25 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 = 1.250/1.463/1.676/0.213 ms') 2025-07-31 02:40:11,436 - INFO - Ping to Metadata IP 169.254.0.3 of VM bgpaas_vm1 passed 2025-07-31 02:40:11,575 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-07-31 02:40:11,575 - DEBUG - Waiting to SSH to VM bgpaas_vm1, IP 1.145.231.131, Port 22 2025-07-31 02:40:11,600 - 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-07-31 02:40:11,718 - DEBUG - VM bgpaas_vm1 is NOT ready for SSH connections, VM status: ACTIVE 2025-07-31 02:40:16,718 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-07-31 02:40:16,719 - DEBUG - Waiting to SSH to VM bgpaas_vm1, IP 1.145.231.131, Port 22 2025-07-31 02:40:16,749 - 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-07-31 02:40:16,909 - DEBUG - VM bgpaas_vm1 is NOT ready for SSH connections, VM status: ACTIVE 2025-07-31 02:40:21,910 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-07-31 02:40:21,911 - DEBUG - Waiting to SSH to VM bgpaas_vm1, IP 1.145.231.131, Port 22 2025-07-31 02:40:21,938 - 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-07-31 02:40:22,039 - DEBUG - VM bgpaas_vm1 is NOT ready for SSH connections, VM status: ACTIVE 2025-07-31 02:40:27,040 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-07-31 02:40:27,041 - DEBUG - Waiting to SSH to VM bgpaas_vm1, IP 1.145.231.131, Port 22 2025-07-31 02:40:27,069 - 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-07-31 02:40:27,256 - DEBUG - VM bgpaas_vm1 is NOT ready for SSH connections, VM status: ACTIVE 2025-07-31 02:40:32,257 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-07-31 02:40:32,258 - DEBUG - Waiting to SSH to VM bgpaas_vm1, IP 1.145.231.131, Port 22 2025-07-31 02:40:32,286 - 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-07-31 02:40:32,460 - DEBUG - VM bgpaas_vm1 is NOT ready for SSH connections, VM status: ACTIVE 2025-07-31 02:40:37,462 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-07-31 02:40:37,462 - DEBUG - Waiting to SSH to VM bgpaas_vm1, IP 1.145.231.131, Port 22 2025-07-31 02:40:37,491 - 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-07-31 02:40:37,668 - DEBUG - VM bgpaas_vm1 is NOT ready for SSH connections, VM status: ACTIVE 2025-07-31 02:40:42,669 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-07-31 02:40:42,670 - DEBUG - Waiting to SSH to VM bgpaas_vm1, IP 1.145.231.131, Port 22 2025-07-31 02:40:42,698 - 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-07-31 02:40:42,919 - DEBUG - VM bgpaas_vm1 is NOT ready for SSH connections, VM status: ACTIVE 2025-07-31 02:40:47,921 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-07-31 02:40:47,921 - DEBUG - Waiting to SSH to VM bgpaas_vm1, IP 1.145.231.131, Port 22 2025-07-31 02:40:47,948 - 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-07-31 02:40:48,096 - DEBUG - VM bgpaas_vm1 is NOT ready for SSH connections, VM status: ACTIVE 2025-07-31 02:40:53,097 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-07-31 02:40:53,098 - DEBUG - Waiting to SSH to VM bgpaas_vm1, IP 1.145.231.131, Port 22 2025-07-31 02:40:53,114 - 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-07-31 02:40:53,247 - DEBUG - VM bgpaas_vm1 is NOT ready for SSH connections, VM status: ACTIVE 2025-07-31 02:40:58,248 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-07-31 02:40:58,248 - DEBUG - Waiting to SSH to VM bgpaas_vm1, IP 1.145.231.131, Port 22 2025-07-31 02:40:58,338 - DEBUG - VM bgpaas_vm1 is ready for SSH connections 2025-07-31 02:40:58,338 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-07-31 02:40:58,525 - INFO - Creating BGPaaS ctest-TestBGPaaS-53610747-62209076 2025-07-31 02:40:58,605 - INFO - BGPaaS: ctest-TestBGPaaS-53610747-62209076(d29cf255-906b-49ed-9fc3-6ec126c4e662) 2025-07-31 02:40:58,605 - DEBUG - Requesting: http://10.0.0.41:8082/bgp-as-a-service/d29cf255-906b-49ed-9fc3-6ec126c4e662 2025-07-31 02:40:58,922 - DEBUG - Requesting: http://10.0.0.41:8082/bgp-as-a-service/d29cf255-906b-49ed-9fc3-6ec126c4e662 2025-07-31 02:40:58,966 - INFO - verify_in_api_server passed for BGPaaS obj d29cf255-906b-49ed-9fc3-6ec126c4e662 2025-07-31 02:40:58,966 - INFO - BGPaaS(d29cf255-906b-49ed-9fc3-6ec126c4e662): verify_on_setup passed 2025-07-31 02:40:58,967 - INFO - We will configure BGP on the VM 2025-07-31 02:40:58,968 - INFO - Configuring BGP on bgpaas_vm1 2025-07-31 02:40:58,968 - DEBUG - Running remote_cmd, Cmd : cat > /etc/bird/bird.conf << EOS protocol device { scan time 10; # Scan interfaces every 10 seconds } protocol kernel { persist; # Don't remove routes on bird shutdown scan time 20; # Scan kernel routing table every 20 seconds import all; # Default is import all #export all; # Default is export none } protocol direct { interface "eth*"; } router id 1.145.231.131; protocol bgp bgp_1{ local as 64500; neighbor 1.145.231.129 as 64512; export where source = RTS_STATIC; export all; multihop; #export all; hold time 90; bfd on; source address 1.145.231.131; } protocol bfd { neighbor 1.145.231.129 local 1.145.231.131 multihop on; } EOS , host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.27, gateway password: c0ntrail123 2025-07-31 02:40:58,969 - DEBUG - cat > /etc/bird/bird.conf << EOS protocol device { scan time 10; # Scan interfaces every 10 seconds } protocol kernel { persist; # Don't remove routes on bird shutdown scan time 20; # Scan kernel routing table every 20 seconds import all; # Default is import all #export all; # Default is export none } protocol direct { interface "eth*"; } router id 1.145.231.131; protocol bgp bgp_1{ local as 64500; neighbor 1.145.231.129 as 64512; export where source = RTS_STATIC; export all; multihop; #export all; hold time 90; bfd on; source address 1.145.231.131; } protocol bfd { neighbor 1.145.231.129 local 1.145.231.131 multihop on; } EOS 2025-07-31 02:41:16,697 - DEBUG - None 2025-07-31 02:41:16,697 - DEBUG - Running remote_cmd, Cmd : cat > /etc/bird/bird.conf << EOS protocol device { scan time 10; # Scan interfaces every 10 seconds } protocol kernel { persist; # Don't remove routes on bird shutdown scan time 20; # Scan kernel routing table every 20 seconds import all; # Default is import all #export all; # Default is export none } protocol direct { interface "eth*"; } router id 1.145.231.131; protocol bgp bgp_1{ local as 64500; neighbor 1.145.231.129 as 64512; export where source = RTS_STATIC; export all; multihop; #export all; hold time 90; bfd on; source address 1.145.231.131; } protocol bfd { neighbor 1.145.231.129 local 1.145.231.131 multihop on; } EOS , host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.27, gateway password: c0ntrail123 2025-07-31 02:41:16,697 - DEBUG - cat > /etc/bird/bird.conf << EOS protocol device { scan time 10; # Scan interfaces every 10 seconds } protocol kernel { persist; # Don't remove routes on bird shutdown scan time 20; # Scan kernel routing table every 20 seconds import all; # Default is import all #export all; # Default is export none } protocol direct { interface "eth*"; } router id 1.145.231.131; protocol bgp bgp_1{ local as 64500; neighbor 1.145.231.129 as 64512; export where source = RTS_STATIC; export all; multihop; #export all; hold time 90; bfd on; source address 1.145.231.131; } protocol bfd { neighbor 1.145.231.129 local 1.145.231.131 multihop on; } EOS 2025-07-31 02:41:17,880 - DEBUG - None 2025-07-31 02:41:17,881 - DEBUG - Running remote_cmd, Cmd : service bird restart, host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.27, gateway password: c0ntrail123 2025-07-31 02:41:17,881 - DEBUG - service bird restart 2025-07-31 02:41:21,258 - DEBUG - bird stop/waiting bird start/running, process 1426 2025-07-31 02:41:21,259 - INFO - Attaching the VMI to the BGPaaS object 2025-07-31 02:41:21,260 - INFO - Attaching VMI 20b52fea-eed6-4bc5-b485-aa5863b1b375 to BGPaaS d29cf255-906b-49ed-9fc3-6ec126c4e662 2025-07-31 02:41:21,413 - INFO - Creating Health Check ctest-TestBGPaaS-53610747-74159827 2025-07-31 02:41:21,517 - INFO - Health Check: ctest-TestBGPaaS-53610747-74159827(faa4f0a4-f409-4187-8d2d-dc6895859820), type BFD 2025-07-31 02:41:21,517 - DEBUG - Requesting: http://10.0.0.41:8082/service-health-check/faa4f0a4-f409-4187-8d2d-dc6895859820 2025-07-31 02:41:21,534 - INFO - verify_in_api_server passed for HC obj faa4f0a4-f409-4187-8d2d-dc6895859820 2025-07-31 02:41:21,535 - INFO - Health Check(faa4f0a4-f409-4187-8d2d-dc6895859820): verify_on_setup passed 2025-07-31 02:41:21,535 - INFO - Attaching HC faa4f0a4-f409-4187-8d2d-dc6895859820 to BGPaaS d29cf255-906b-49ed-9fc3-6ec126c4e662 2025-07-31 02:41:21,665 - INFO - Check HC obj faa4f0a4-f409-4187-8d2d-dc6895859820 on agent 10.0.0.27 2025-07-31 02:41:21,673 - INFO - verify_in_agent passed for HC obj faa4f0a4-f409-4187-8d2d-dc6895859820 2025-07-31 02:41:21,688 - DEBUG - Requesting: http://10.20.0.193:8083/Snh_BgpNeighborReq?domain=&ip_address= 2025-07-31 02:41:21,709 - DEBUG - Requesting: http://10.20.0.18:8083/Snh_BgpNeighborReq?domain=&ip_address= 2025-07-31 02:41:27,758 - DEBUG - Requesting: http://10.20.0.193:8083/Snh_BgpNeighborReq?domain=&ip_address= 2025-07-31 02:41:27,794 - DEBUG - Requesting: http://10.20.0.18:8083/Snh_BgpNeighborReq?domain=&ip_address= 2025-07-31 02:41:33,861 - DEBUG - Requesting: http://10.20.0.193:8083/Snh_BgpNeighborReq?domain=&ip_address= 2025-07-31 02:41:33,894 - DEBUG - Requesting: http://10.20.0.18:8083/Snh_BgpNeighborReq?domain=&ip_address= 2025-07-31 02:41:39,952 - DEBUG - Requesting: http://10.20.0.193:8083/Snh_BgpNeighborReq?domain=&ip_address= 2025-07-31 02:41:39,977 - DEBUG - Requesting: http://10.20.0.18:8083/Snh_BgpNeighborReq?domain=&ip_address= 2025-07-31 02:41:46,025 - DEBUG - Requesting: http://10.20.0.193:8083/Snh_BgpNeighborReq?domain=&ip_address= 2025-07-31 02:41:46,044 - DEBUG - Requesting: http://10.20.0.18:8083/Snh_BgpNeighborReq?domain=&ip_address= 2025-07-31 02:41:52,107 - DEBUG - Requesting: http://10.20.0.193:8083/Snh_BgpNeighborReq?domain=&ip_address= 2025-07-31 02:41:52,137 - DEBUG - Requesting: http://10.20.0.18:8083/Snh_BgpNeighborReq?domain=&ip_address= 2025-07-31 02:41:58,185 - DEBUG - Requesting: http://10.20.0.193:8083/Snh_BgpNeighborReq?domain=&ip_address= 2025-07-31 02:41:58,207 - DEBUG - Requesting: http://10.20.0.18:8083/Snh_BgpNeighborReq?domain=&ip_address= 2025-07-31 02:42:04,259 - DEBUG - Requesting: http://10.20.0.193:8083/Snh_BgpNeighborReq?domain=&ip_address= 2025-07-31 02:42:04,281 - DEBUG - Requesting: http://10.20.0.18:8083/Snh_BgpNeighborReq?domain=&ip_address= 2025-07-31 02:42:10,320 - DEBUG - Requesting: http://10.20.0.193:8083/Snh_BgpNeighborReq?domain=&ip_address= 2025-07-31 02:42:10,340 - DEBUG - Requesting: http://10.20.0.18:8083/Snh_BgpNeighborReq?domain=&ip_address= 2025-07-31 02:42:16,394 - DEBUG - Requesting: http://10.20.0.193:8083/Snh_BgpNeighborReq?domain=&ip_address= 2025-07-31 02:42:16,426 - DEBUG - Requesting: http://10.20.0.18:8083/Snh_BgpNeighborReq?domain=&ip_address= 2025-07-31 02:42:22,475 - DEBUG - Requesting: http://10.20.0.193:8083/Snh_BgpNeighborReq?domain=&ip_address= 2025-07-31 02:42:22,508 - DEBUG - Requesting: http://10.20.0.18:8083/Snh_BgpNeighborReq?domain=&ip_address= 2025-07-31 02:42:22,540 - INFO - Detaching HC faa4f0a4-f409-4187-8d2d-dc6895859820 from BGPaaS d29cf255-906b-49ed-9fc3-6ec126c4e662 2025-07-31 02:42:22,665 - INFO - Deleting Health Check ctest-TestBGPaaS-53610747-74159827(faa4f0a4-f409-4187-8d2d-dc6895859820) 2025-07-31 02:42:22,722 - DEBUG - Requesting: http://10.0.0.41:8082/service-health-check/faa4f0a4-f409-4187-8d2d-dc6895859820 2025-07-31 02:42:22,735 - DEBUG - Response Code: 404 2025-07-31 02:42:22,735 - DEBUG - HC: faa4f0a4-f409-4187-8d2d-dc6895859820 deleted from api server 2025-07-31 02:42:22,735 - INFO - Health Check(faa4f0a4-f409-4187-8d2d-dc6895859820): verify_on_cleanup passed 2025-07-31 02:42:22,735 - INFO - Detaching VMI 20b52fea-eed6-4bc5-b485-aa5863b1b375 from BGPaaS d29cf255-906b-49ed-9fc3-6ec126c4e662 2025-07-31 02:42:22,813 - INFO - Deleting BGPaaS ctest-TestBGPaaS-53610747-62209076(d29cf255-906b-49ed-9fc3-6ec126c4e662) 2025-07-31 02:42:22,858 - DEBUG - Requesting: http://10.0.0.41:8082/bgp-as-a-service/d29cf255-906b-49ed-9fc3-6ec126c4e662 2025-07-31 02:42:22,866 - DEBUG - Response Code: 404 2025-07-31 02:42:22,866 - DEBUG - BGPaaS: d29cf255-906b-49ed-9fc3-6ec126c4e662 deleted from api server 2025-07-31 02:42:22,866 - INFO - BGPaaS(d29cf255-906b-49ed-9fc3-6ec126c4e662): verify_on_cleanup passed 2025-07-31 02:42:22,866 - INFO - Deleting VM bgpaas_vm1 2025-07-31 02:42:22,941 - INFO - Deleting VN ctest-bgpaas_vn-44387333 2025-07-31 02:42:22,986 - DEBUG - VN e7be9a04-1441-415f-95d3-4bfa63581220 still in use: Unable to complete operation on network e7be9a04-1441-415f-95d3-4bfa63581220. There are one or more ports still in use on the network. Neutron server returns request_ids: ['req-afca4878-170c-4ed2-9d84-7eedc84e36a8'] 2025-07-31 02:42:22,986 - WARNING - Deleting VN ctest-bgpaas_vn-44387333 failed..Will retry 2025-07-31 02:42:25,274 - DEBUG - Response for deleting network () 2025-07-31 02:42:26,583 - ERROR - AssertionError Python 3.6.8: /usr/bin/python3 Thu Jul 31 02:42:22 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/scripts/bgpaas/test_bgpaas.py in test_bgpaas_basic(self=) 1576 Maintainer: ganeshahv@juniper.net 1577 ''' 1578 self.bgpaas_basic_common(attach_to='bgpaas') 1579 # end test_bgpaas_basic 1580 self = self.bgpaas_basic_common = > attach_to undefined /contrail-test/scripts/bgpaas/test_bgpaas.py in bgpaas_basic_common(self=, attach_to='bgpaas') 1616 shc_fixture.verify_in_agent(agent) 1617 assert bgpaas_fixture.verify_in_control_node( 1618 bgpaas_vm), 'BGPaaS Session not seen in the control-node' 1619 assert self.verify_bfd_packets( 1620 bgpaas_vm, vn_fixture), 'Multihop BFD packets not seen over the BGPaaS interface' bgpaas_vm = AssertionError: BGPaaS Session not seen in the control-node __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 = ('BGPaaS Session not seen in the control-node',) 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/scripts/bgpaas/test_bgpaas.py", line 1578, in test_bgpaas_basic self.bgpaas_basic_common(attach_to='bgpaas') File "/contrail-test/scripts/bgpaas/test_bgpaas.py", line 1618, in bgpaas_basic_common bgpaas_vm), 'BGPaaS Session not seen in the control-node' AssertionError: BGPaaS Session not seen in the control-node 2025-07-31 02:42:26,603 - DEBUG - No XMPP flaps were noticed during the test 2025-07-31 02:42:26,603 - INFO -
2025-07-31 02:42:26,603 - INFO - END TEST : test_bgpaas_basic : FAILED[0:04:27]
2025-07-31 02:42:26,603 - INFO - -------------------------------------------------------------------------------- 2025-07-31 02:42:27,556 - INFO - Deleted project: ctest-TestBGPaaS-53610747, ID : ff3f6a15-d569-40a4-8988-6af8e3adb889 2025-07-31 03:59:01,833 - DEBUG - Requesting: http://10.20.0.193:8083/Snh_ShowRouteReq?x=default-domain:ctest-TestRP-39012225:ctest-bgpaas_vn-97982857:ctest-bgpaas_vn-97982857.inet.0 2025-07-31 03:59:01,853 - DEBUG - Requesting: http://10.20.0.18:8083/Snh_ShowRouteReq?x=default-domain:ctest-TestRP-39012225:ctest-bgpaas_vn-97982857:ctest-bgpaas_vn-97982857.inet.0 2025-07-31 03:59:30,017 - DEBUG - Requesting: http://10.20.0.193:8083/Snh_ShowRouteReq?x=default-domain:ctest-TestRP-39012225:ctest-bgpaas_vn-82065573:ctest-bgpaas_vn-82065573.inet.0 2025-07-31 03:59:30,037 - DEBUG - Requesting: http://10.20.0.18:8083/Snh_ShowRouteReq?x=default-domain:ctest-TestRP-39012225:ctest-bgpaas_vn-82065573:ctest-bgpaas_vn-82065573.inet.0 2025-07-31 03:59:34,088 - DEBUG - Requesting: http://10.20.0.193:8083/Snh_ShowRouteReq?x=default-domain:ctest-TestRP-39012225:ctest-bgpaas_vn-82065573:ctest-bgpaas_vn-82065573.inet.0 2025-07-31 03:59:34,106 - DEBUG - Requesting: http://10.20.0.18:8083/Snh_ShowRouteReq?x=default-domain:ctest-TestRP-39012225:ctest-bgpaas_vn-82065573:ctest-bgpaas_vn-82065573.inet.0 2025-07-31 03:59:58,361 - DEBUG - Requesting: http://10.20.0.193:8083/Snh_ShowRouteReq?x=default-domain:ctest-TestRP-39012225:ctest-bgpaas_vn-21774929:ctest-bgpaas_vn-21774929.inet.0 2025-07-31 03:59:58,384 - DEBUG - Requesting: http://10.20.0.18:8083/Snh_ShowRouteReq?x=default-domain:ctest-TestRP-39012225:ctest-bgpaas_vn-21774929:ctest-bgpaas_vn-21774929.inet.0