2025-08-11 12:23:11,622 - INFO - Domain Default found not creating 2025-08-11 12:23:11,754 - INFO - Project ctest-TestBGPaaSlocalAS-99316886 not found, creating it 2025-08-11 12:23:12,284 - INFO - Created Project:ctest-TestBGPaaSlocalAS-99316886, ID : b08a46dc-5b1a-4411-aa1d-ba8a952b9f1c 2025-08-11 12:23:13,716 - DEBUG - Services list from nova: [, , , ] 2025-08-11 12:23:13,716 - DEBUG - Hosts: {'nova': ['an-jenkins-deploy-platform-ansible-os-3803-2', 'an-jenkins-deploy-platform-ansible-os-3803-1']} 2025-08-11 12:23:13,718 - INFO - ================================================================================ 2025-08-11 12:23:13,718 - INFO - STARTING TEST : test_basic_bgpaas_local_as 2025-08-11 12:23:13,718 - INFO - TEST DESCRIPTION : 1. Create a bgpaas vm. Configure same local-as on vm and contrail side. 2. Make sure BGP with vm comes up. 2025-08-11 12:23:14,972 - DEBUG - Skipping xmpp flap check 2025-08-11 12:23:14,972 - INFO - Initial checks done. Running the testcase now 2025-08-11 12:23:14,972 - INFO - 2025-08-11 12:23:15,645 - DEBUG - Response for create_network : {'network': {'id': 'd39a5409-62c2-42ae-b97a-91d2bbb31210', 'name': 'ctest-bgpaas_vn-66921930', 'tenant_id': 'b08a46dc5b1a4411aa1dba8a952b9f1c', 'project_id': 'b08a46dc5b1a4411aa1dba8a952b9f1c', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestBGPaaSlocalAS-99316886', 'ctest-bgpaas_vn-66921930'], 'port_security_enabled': True, 'description': ''}} 2025-08-11 12:23:15,946 - DEBUG - Response for create_subnet : {'subnet': {'id': '7feb4a73-03e7-4c80-aef0-362be78a9941', 'name': '', 'tenant_id': 'b08a46dc5b1a4411aa1dba8a952b9f1c', 'network_id': 'd39a5409-62c2-42ae-b97a-91d2bbb31210', 'ip_version': 4, 'cidr': '130.31.167.192/26', 'allocation_pools': [{'start': '130.31.167.194', 'end': '130.31.167.254'}], 'gateway_ip': '130.31.167.193', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '130.31.167.194', 'tags': [], 'project_id': 'b08a46dc5b1a4411aa1dba8a952b9f1c'}} 2025-08-11 12:23:15,967 - INFO - Created VN ctest-bgpaas_vn-66921930 2025-08-11 12:23:15,977 - DEBUG - VN ctest-bgpaas_vn-66921930 UUID is d39a5409-62c2-42ae-b97a-91d2bbb31210 2025-08-11 12:23:17,092 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-3803-2), Zone: (nova:an-jenkins-deploy-platform-ansible-os-3803-2) 2025-08-11 12:23:17,172 - DEBUG - Image by name ubuntu-bird not found 2025-08-11 12:23:17,172 - DEBUG - Installing image ubuntu-bird 2025-08-11 12:23:17,172 - 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-08-11 12:23:17,173 - DEBUG - Image build path http://nexus.opensdn.io/repository///images/converts//ubuntu-bird.vmdk.gz 2025-08-11 12:23:17,174 - DEBUG - Download image from web http://nexus.opensdn.io/repository///images/converts//ubuntu-bird.vmdk.gz 2025-08-11 12:23:17,184 - 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-08-11 12:23:19,781 - DEBUG - Image has been downloaded to /contrail-test/images/ubuntu-bird.vmdk.gz 2025-08-11 12:23:19,781 - DEBUG - Unzip image 2025-08-11 12:23:19,781 - DEBUG - Image download (local=True) (proxy=None): Execute cmd: gunzip -f /contrail-test/images/ubuntu-bird.vmdk.gz 2025-08-11 12:23:30,098 - DEBUG - Try to create image in user context 2025-08-11 12:23:36,981 - DEBUG - Image has been created in user context 2025-08-11 12:23:36,981 - DEBUG - Image download (local=True) (proxy=None): Execute cmd: rm -f /contrail-test/images/ubuntu-bird.vmdk 2025-08-11 12:23:37,143 - DEBUG - Downloaded image has been removed 2025-08-11 12:23:37,160 - DEBUG - Uploaded image status = active 2025-08-11 12:23:38,157 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-3803-1), Zone: (nova:an-jenkins-deploy-platform-ansible-os-3803-1) 2025-08-11 12:23:38,157 - INFO - Waiting for VM test_vm to be up.. 2025-08-11 12:23:38,232 - DEBUG - VM is in ACTIVE state now 2025-08-11 12:23:38,232 - INFO - VM name : test_vm 2025-08-11 12:23:38,313 - DEBUG - VM test_vm ID is 587d8a7a-6032-4f37-93c4-4d5b7d3d3278 2025-08-11 12:23:38,339 - DEBUG - VM test_vm launched on Node an-jenkins-deploy-platform-ansible-os-3803-2 2025-08-11 12:23:38,426 - DEBUG - Requesting: http://10.0.0.22:8082/virtual-machine/587d8a7a-6032-4f37-93c4-4d5b7d3d3278 2025-08-11 12:23:38,825 - DEBUG - Requesting: http://10.0.0.22:8082/virtual-machine/587d8a7a-6032-4f37-93c4-4d5b7d3d3278 2025-08-11 12:23:38,859 - DEBUG - Requesting: http://10.0.0.22:8082/virtual-machine-interface/a39e79c7-0903-4ec2-b8cc-00d17ad6cb68 2025-08-11 12:23:40,080 - 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.36 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=3.65 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 = 2.359/3.002/3.645/0.643 ms') 2025-08-11 12:23:40,081 - INFO - Ping to Metadata IP 169.254.0.3 of VM test_vm passed 2025-08-11 12:23:40,202 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-11 12:23:40,202 - DEBUG - Waiting to SSH to VM test_vm, IP 130.31.167.195, Port 22 2025-08-11 12:23:40,260 - DEBUG - Error on ssh to cirros@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 12:23:40,356 - DEBUG - VM test_vm is NOT ready for SSH connections, VM status: ACTIVE 2025-08-11 12:23:45,357 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-11 12:23:45,357 - DEBUG - Waiting to SSH to VM test_vm, IP 130.31.167.195, Port 22 2025-08-11 12:23:45,519 - DEBUG - VM test_vm is ready for SSH connections 2025-08-11 12:23:45,519 - INFO - Waiting for VM bgpaas_vm1 to be up.. 2025-08-11 12:23:45,593 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2025-08-11 12:23:50,665 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2025-08-11 12:23:55,738 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2025-08-11 12:24:00,807 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2025-08-11 12:24:05,874 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2025-08-11 12:24:10,950 - DEBUG - VM is in ACTIVE state now 2025-08-11 12:24:10,950 - INFO - VM name : bgpaas_vm1 2025-08-11 12:24:11,016 - DEBUG - VM bgpaas_vm1 ID is 7b51d54a-027f-47d8-bba8-3ab8e06dc0f1 2025-08-11 12:24:11,017 - DEBUG - VM bgpaas_vm1 launched on Node an-jenkins-deploy-platform-ansible-os-3803-1 2025-08-11 12:24:11,083 - DEBUG - Requesting: http://10.0.0.22:8082/virtual-machine/7b51d54a-027f-47d8-bba8-3ab8e06dc0f1 2025-08-11 12:24:11,092 - DEBUG - Requesting: http://10.0.0.22:8082/virtual-machine-interface/5da0fdcb-54fb-431e-b32d-e24ec060840a 2025-08-11 12:24:14,296 - 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 1005ms') 2025-08-11 12:24:14,296 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM bgpaas_vm1 failed! 2025-08-11 12:24:14,310 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaaSlocalAS-99316886:ctest-bgpaas_vn-66921930 is 130.31.167.193 and allocation pool is NOT set 2025-08-11 12:24:18,392 - 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 1027ms') 2025-08-11 12:24:18,392 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM bgpaas_vm1 failed! 2025-08-11 12:24:18,407 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaaSlocalAS-99316886:ctest-bgpaas_vn-66921930 is 130.31.167.193 and allocation pool is NOT set 2025-08-11 12:24:22,485 - 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') 2025-08-11 12:24:22,485 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM bgpaas_vm1 failed! 2025-08-11 12:24:22,498 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaaSlocalAS-99316886:ctest-bgpaas_vn-66921930 is 130.31.167.193 and allocation pool is NOT set 2025-08-11 12:24:26,587 - 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 1027ms') 2025-08-11 12:24:26,587 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM bgpaas_vm1 failed! 2025-08-11 12:24:26,600 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaaSlocalAS-99316886:ctest-bgpaas_vn-66921930 is 130.31.167.193 and allocation pool is NOT set 2025-08-11 12:24:30,678 - 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 12:24:30,678 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM bgpaas_vm1 failed! 2025-08-11 12:24:30,691 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaaSlocalAS-99316886:ctest-bgpaas_vn-66921930 is 130.31.167.193 and allocation pool is NOT set 2025-08-11 12:24:34,775 - 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-08-11 12:24:34,775 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM bgpaas_vm1 failed! 2025-08-11 12:24:34,788 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaaSlocalAS-99316886:ctest-bgpaas_vn-66921930 is 130.31.167.193 and allocation pool is NOT set 2025-08-11 12:24:38,879 - 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 1027ms') 2025-08-11 12:24:38,879 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM bgpaas_vm1 failed! 2025-08-11 12:24:38,892 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaaSlocalAS-99316886:ctest-bgpaas_vn-66921930 is 130.31.167.193 and allocation pool is NOT set 2025-08-11 12:24:42,972 - 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-08-11 12:24:42,972 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM bgpaas_vm1 failed! 2025-08-11 12:24:42,986 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaaSlocalAS-99316886:ctest-bgpaas_vn-66921930 is 130.31.167.193 and allocation pool is NOT set 2025-08-11 12:24:47,068 - 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-08-11 12:24:47,068 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM bgpaas_vm1 failed! 2025-08-11 12:24:47,093 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaaSlocalAS-99316886:ctest-bgpaas_vn-66921930 is 130.31.167.193 and allocation pool is NOT set 2025-08-11 12:24:51,167 - 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-08-11 12:24:51,167 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM bgpaas_vm1 failed! 2025-08-11 12:24:51,186 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaaSlocalAS-99316886:ctest-bgpaas_vn-66921930 is 130.31.167.193 and allocation pool is NOT set 2025-08-11 12:24:55,264 - 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-08-11 12:24:55,264 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM bgpaas_vm1 failed! 2025-08-11 12:24:55,278 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaaSlocalAS-99316886:ctest-bgpaas_vn-66921930 is 130.31.167.193 and allocation pool is NOT set 2025-08-11 12:24:59,356 - 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') 2025-08-11 12:24:59,356 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM bgpaas_vm1 failed! 2025-08-11 12:24:59,369 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaaSlocalAS-99316886:ctest-bgpaas_vn-66921930 is 130.31.167.193 and allocation pool is NOT set 2025-08-11 12:25:03,448 - 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 12:25:03,448 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM bgpaas_vm1 failed! 2025-08-11 12:25:03,462 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaaSlocalAS-99316886:ctest-bgpaas_vn-66921930 is 130.31.167.193 and allocation pool is NOT set 2025-08-11 12:25:07,546 - 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=2 ttl=63 time=2.07 ms\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 1 received, 50% packet loss, time 1024ms\r\nrtt min/avg/max/mdev = 2.067/2.067/2.067/0.000 ms') 2025-08-11 12:25:07,546 - INFO - Ping to Metadata IP 169.254.0.3 of VM bgpaas_vm1 passed 2025-08-11 12:25:07,656 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-11 12:25:07,656 - DEBUG - Waiting to SSH to VM bgpaas_vm1, IP 130.31.167.196, Port 22 2025-08-11 12:25:07,714 - 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 12:25:07,812 - DEBUG - VM bgpaas_vm1 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-11 12:25:12,813 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-11 12:25:12,813 - DEBUG - Waiting to SSH to VM bgpaas_vm1, IP 130.31.167.196, Port 22 2025-08-11 12:25:12,883 - 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 12:25:12,961 - DEBUG - VM bgpaas_vm1 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-11 12:25:17,962 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-11 12:25:17,962 - DEBUG - Waiting to SSH to VM bgpaas_vm1, IP 130.31.167.196, Port 22 2025-08-11 12:25:18,018 - 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 12:25:18,091 - DEBUG - VM bgpaas_vm1 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-11 12:25:23,092 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-11 12:25:23,092 - DEBUG - Waiting to SSH to VM bgpaas_vm1, IP 130.31.167.196, Port 22 2025-08-11 12:25:23,149 - 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 12:25:23,233 - DEBUG - VM bgpaas_vm1 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-11 12:25:28,233 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-11 12:25:28,233 - DEBUG - Waiting to SSH to VM bgpaas_vm1, IP 130.31.167.196, Port 22 2025-08-11 12:25:28,289 - 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 12:25:28,371 - DEBUG - VM bgpaas_vm1 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-11 12:25:33,371 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-11 12:25:33,371 - DEBUG - Waiting to SSH to VM bgpaas_vm1, IP 130.31.167.196, Port 22 2025-08-11 12:25:33,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 12:25:33,505 - DEBUG - VM bgpaas_vm1 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-11 12:25:38,506 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-11 12:25:38,506 - DEBUG - Waiting to SSH to VM bgpaas_vm1, IP 130.31.167.196, Port 22 2025-08-11 12:25:38,562 - 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 12:25:38,649 - DEBUG - VM bgpaas_vm1 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-11 12:25:43,650 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-11 12:25:43,650 - DEBUG - Waiting to SSH to VM bgpaas_vm1, IP 130.31.167.196, Port 22 2025-08-11 12:25:43,716 - 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 12:25:43,784 - DEBUG - VM bgpaas_vm1 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-11 12:25:48,784 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-11 12:25:48,785 - DEBUG - Waiting to SSH to VM bgpaas_vm1, IP 130.31.167.196, Port 22 2025-08-11 12:25:48,942 - DEBUG - VM bgpaas_vm1 is ready for SSH connections 2025-08-11 12:25:48,942 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-11 12:25:48,948 - INFO - Creating BGPaaS ctest-TestBGPaaSlocalAS-99316886-83099241 2025-08-11 12:25:49,044 - INFO - BGPaaS: ctest-TestBGPaaSlocalAS-99316886-83099241(9d5602be-5ed3-49d6-831f-2a86209665db) 2025-08-11 12:25:49,044 - DEBUG - Requesting: http://10.0.0.56:8082/bgp-as-a-service/9d5602be-5ed3-49d6-831f-2a86209665db 2025-08-11 12:25:49,354 - DEBUG - Requesting: http://10.0.0.56:8082/bgp-as-a-service/9d5602be-5ed3-49d6-831f-2a86209665db 2025-08-11 12:25:49,384 - INFO - verify_in_api_server passed for BGPaaS obj 9d5602be-5ed3-49d6-831f-2a86209665db 2025-08-11 12:25:49,384 - INFO - BGPaaS(9d5602be-5ed3-49d6-831f-2a86209665db): verify_on_setup passed 2025-08-11 12:25:49,384 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-11 12:25:49,384 - DEBUG - Waiting to SSH to VM bgpaas_vm1, IP 130.31.167.196, Port 22 2025-08-11 12:25:49,538 - DEBUG - VM bgpaas_vm1 is ready for SSH connections 2025-08-11 12:25:49,538 - INFO - Attaching VMI 5da0fdcb-54fb-431e-b32d-e24ec060840a to BGPaaS 9d5602be-5ed3-49d6-831f-2a86209665db 2025-08-11 12:25:49,612 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-11 12:25:49,612 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-11 12:25:49,722 - INFO - Configuring BGP on the bird 2025-08-11 12:25:49,722 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-11 12:25:49,722 - DEBUG - Waiting to SSH to VM bgpaas_vm1, IP 130.31.167.196, Port 22 2025-08-11 12:25:49,877 - DEBUG - VM bgpaas_vm1 is ready for SSH connections 2025-08-11 12:25:49,878 - INFO - Configuring BGP on bgpaas_vm1 2025-08-11 12:25:49,878 - 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 130.31.167.196; protocol bgp bgp_1{ local as 64500; neighbor 130.31.167.193 as 738; export where source = RTS_STATIC; export all; multihop; #export all; hold time 90; bfd on; source address 130.31.167.196; } protocol bfd { neighbor 130.31.167.193 local 130.31.167.196 multihop on; } EOS , host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.19, gateway password: c0ntrail123 2025-08-11 12:25:49,878 - 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 130.31.167.196; protocol bgp bgp_1{ local as 64500; neighbor 130.31.167.193 as 738; export where source = RTS_STATIC; export all; multihop; #export all; hold time 90; bfd on; source address 130.31.167.196; } protocol bfd { neighbor 130.31.167.193 local 130.31.167.196 multihop on; } EOS 2025-08-11 12:26:03,369 - DEBUG - None 2025-08-11 12:26:03,369 - 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 130.31.167.196; protocol bgp bgp_1{ local as 64500; neighbor 130.31.167.193 as 738; export where source = RTS_STATIC; export all; multihop; #export all; hold time 90; bfd on; source address 130.31.167.196; } protocol bfd { neighbor 130.31.167.193 local 130.31.167.196 multihop on; } EOS , host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.19, gateway password: c0ntrail123 2025-08-11 12:26:03,369 - 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 130.31.167.196; protocol bgp bgp_1{ local as 64500; neighbor 130.31.167.193 as 738; export where source = RTS_STATIC; export all; multihop; #export all; hold time 90; bfd on; source address 130.31.167.196; } protocol bfd { neighbor 130.31.167.193 local 130.31.167.196 multihop on; } EOS 2025-08-11 12:26:04,187 - DEBUG - None 2025-08-11 12:26:04,187 - DEBUG - Running remote_cmd, Cmd : service bird restart, host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.19, gateway password: c0ntrail123 2025-08-11 12:26:04,187 - DEBUG - service bird restart 2025-08-11 12:26:06,852 - DEBUG - bird stop/waiting bird start/running, process 1472 2025-08-11 12:26:06,868 - DEBUG - Requesting: http://10.20.0.17:8083/Snh_BgpNeighborReq?domain=&ip_address= 2025-08-11 12:26:06,894 - DEBUG - Requesting: http://10.20.0.25:8083/Snh_BgpNeighborReq?domain=&ip_address= 2025-08-11 12:26:12,937 - DEBUG - Requesting: http://10.20.0.17:8083/Snh_BgpNeighborReq?domain=&ip_address= 2025-08-11 12:26:12,950 - INFO - BGPaaS session seen in control-node 10.20.0.17 2025-08-11 12:26:12,951 - DEBUG - Requesting: http://10.20.0.25:8083/Snh_BgpNeighborReq?domain=&ip_address= 2025-08-11 12:26:18,103 - INFO - Detaching VMI 5da0fdcb-54fb-431e-b32d-e24ec060840a from BGPaaS 9d5602be-5ed3-49d6-831f-2a86209665db 2025-08-11 12:26:18,172 - INFO - Deleting BGPaaS ctest-TestBGPaaSlocalAS-99316886-83099241(9d5602be-5ed3-49d6-831f-2a86209665db) 2025-08-11 12:26:18,220 - DEBUG - Requesting: http://10.0.0.56:8082/bgp-as-a-service/9d5602be-5ed3-49d6-831f-2a86209665db 2025-08-11 12:26:18,228 - DEBUG - Response Code: 404 2025-08-11 12:26:18,228 - DEBUG - BGPaaS: 9d5602be-5ed3-49d6-831f-2a86209665db deleted from api server 2025-08-11 12:26:18,228 - INFO - BGPaaS(9d5602be-5ed3-49d6-831f-2a86209665db): verify_on_cleanup passed 2025-08-11 12:26:18,228 - INFO - Deleting VM bgpaas_vm1 2025-08-11 12:26:18,316 - INFO - Deleting VM test_vm 2025-08-11 12:26:18,383 - INFO - Deleting VN ctest-bgpaas_vn-66921930 2025-08-11 12:26:18,419 - DEBUG - VN d39a5409-62c2-42ae-b97a-91d2bbb31210 still in use: Unable to complete operation on network d39a5409-62c2-42ae-b97a-91d2bbb31210. There are one or more ports still in use on the network. Neutron server returns request_ids: ['req-2159dd0f-fb0b-4b5f-a85c-7a32a5432649'] 2025-08-11 12:26:18,419 - WARNING - Deleting VN ctest-bgpaas_vn-66921930 failed..Will retry 2025-08-11 12:26:20,624 - DEBUG - Response for deleting network () 2025-08-11 12:26:21,875 - DEBUG - Skipping xmpp flap check
2025-08-11 12:26:21,875 - INFO - END TEST : test_basic_bgpaas_local_as : PASSED[0:03:08]
2025-08-11 12:26:21,876 - INFO - -------------------------------------------------------------------------------- 2025-08-11 12:26:22,526 - INFO - Deleted project: ctest-TestBGPaaSlocalAS-99316886, ID : b08a46dc-5b1a-4411-aa1d-ba8a952b9f1c 2025-08-11 12:29:23,864 - DEBUG - Requesting: http://10.20.0.17:8083/Snh_BgpNeighborReq?domain=&ip_address= 2025-08-11 12:29:29,879 - DEBUG - Requesting: http://10.20.0.17:8083/Snh_BgpNeighborReq?domain=&ip_address= 2025-08-11 12:29:44,615 - DEBUG - Requesting: http://10.20.0.25:8083/Snh_BgpNeighborReq?domain=&ip_address= 2025-08-11 12:29:50,633 - DEBUG - Requesting: http://10.20.0.25:8083/Snh_BgpNeighborReq?domain=&ip_address= 2025-08-11 12:30:12,953 - DEBUG - Requesting: http://10.20.0.17:8083/Snh_BgpNeighborReq?domain=&ip_address= 2025-08-11 12:30:18,966 - DEBUG - Requesting: http://10.20.0.17:8083/Snh_BgpNeighborReq?domain=&ip_address= 2025-08-11 12:32:53,655 - DEBUG - Requesting: http://10.20.0.17:8083/Snh_BgpNeighborReq?domain=&ip_address= 2025-08-11 12:32:59,668 - DEBUG - Requesting: http://10.20.0.17:8083/Snh_BgpNeighborReq?domain=&ip_address= 2025-08-11 12:32:59,701 - DEBUG - Requesting: http://10.20.0.17:8083/Snh_BgpNeighborReq?domain=&ip_address= 2025-08-11 12:33:05,712 - DEBUG - Requesting: http://10.20.0.17:8083/Snh_BgpNeighborReq?domain=&ip_address= 2025-08-11 12:33:23,169 - DEBUG - Requesting: http://10.20.0.17:8083/Snh_BgpNeighborReq?domain=&ip_address= 2025-08-11 12:33:23,200 - DEBUG - Requesting: http://10.20.0.17:8083/Snh_BgpNeighborReq?domain=&ip_address=