2026-01-26 03:29:20,428 - INFO - Domain Default found not creating 2026-01-26 03:29:20,635 - INFO - Project ctest-TestBGPaasZone-86699219 not found, creating it 2026-01-26 03:29:21,277 - INFO - Created Project:ctest-TestBGPaasZone-86699219, ID : dc0ec732-8a67-4a89-811e-fed8a6793120 2026-01-26 03:29:22,909 - DEBUG - Services list from nova: [, , , ] 2026-01-26 03:29:22,909 - DEBUG - Hosts: {'nova': ['an-jenkins-deploy-platform-ansible-os-5076-1', 'an-jenkins-deploy-platform-ansible-os-5076-2']} 2026-01-26 03:29:22,911 - INFO - ================================================================================ 2026-01-26 03:29:22,911 - INFO - STARTING TEST : test_bgp_control_node_zone 2026-01-26 03:29:24,158 - DEBUG - Skipping xmpp flap check 2026-01-26 03:29:24,158 - INFO - Initial checks done. Running the testcase now 2026-01-26 03:29:24,158 - INFO - 2026-01-26 03:29:24,158 - INFO - executing bgp_control_zone test 2026-01-26 03:29:24,858 - DEBUG - Response for create_network : {'network': {'id': '5454c027-9345-4520-8949-d388322104bd', 'name': 'ctest-cnz_vn-02014070', 'tenant_id': 'dc0ec7328a674a89811efed8a6793120', 'project_id': 'dc0ec7328a674a89811efed8a6793120', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestBGPaasZone-86699219', 'ctest-cnz_vn-02014070'], 'port_security_enabled': True, 'description': ''}} 2026-01-26 03:29:25,140 - DEBUG - Response for create_subnet : {'subnet': {'id': 'cb31d8b5-4c2b-4870-aa42-1956cd9c14a9', 'name': '', 'tenant_id': 'dc0ec7328a674a89811efed8a6793120', 'network_id': '5454c027-9345-4520-8949-d388322104bd', 'ip_version': 4, 'cidr': '70.60.128.64/26', 'allocation_pools': [{'start': '70.60.128.66', 'end': '70.60.128.126'}], 'gateway_ip': '70.60.128.65', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '70.60.128.66', 'tags': [], 'project_id': 'dc0ec7328a674a89811efed8a6793120'}} 2026-01-26 03:29:25,160 - INFO - Created VN ctest-cnz_vn-02014070 2026-01-26 03:29:25,175 - DEBUG - VN ctest-cnz_vn-02014070 UUID is 5454c027-9345-4520-8949-d388322104bd 2026-01-26 03:29:26,646 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-5076-1), Zone: (nova:an-jenkins-deploy-platform-ansible-os-5076-1) 2026-01-26 03:29:28,326 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-5076-2), Zone: (nova:an-jenkins-deploy-platform-ansible-os-5076-2) 2026-01-26 03:29:30,217 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-5076-1), Zone: (nova:an-jenkins-deploy-platform-ansible-os-5076-1) 2026-01-26 03:29:30,218 - INFO - Waiting for VM ctest-TestBGPaasZone-86699219-42214563 to be up.. 2026-01-26 03:29:30,347 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-01-26 03:29:35,483 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-01-26 03:29:40,564 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-01-26 03:29:45,644 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-01-26 03:29:50,748 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-01-26 03:29:55,840 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-01-26 03:30:00,938 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-01-26 03:30:06,042 - DEBUG - VM is in ACTIVE state now 2026-01-26 03:30:06,042 - INFO - VM name : ctest-TestBGPaasZone-86699219-42214563 2026-01-26 03:30:06,122 - DEBUG - VM ctest-TestBGPaasZone-86699219-42214563 ID is a1fb13f9-f3d2-446a-92da-3c90c8fa79ed 2026-01-26 03:30:06,145 - DEBUG - VM ctest-TestBGPaasZone-86699219-42214563 launched on Node an-jenkins-deploy-platform-ansible-os-5076-1 2026-01-26 03:30:06,228 - DEBUG - Requesting: http://10.0.0.240:8082/virtual-machine/a1fb13f9-f3d2-446a-92da-3c90c8fa79ed 2026-01-26 03:30:06,530 - DEBUG - Requesting: http://10.0.0.240:8082/virtual-machine/a1fb13f9-f3d2-446a-92da-3c90c8fa79ed 2026-01-26 03:30:06,565 - DEBUG - Requesting: http://10.0.0.240:8082/virtual-machine-interface/d5c6901d-8ddd-415c-9ece-4dc146877ed2 2026-01-26 03:30:09,739 - DEBUG - (True, 'PING 169.254.0.7 (169.254.0.7) 56(84) bytes of data.\r\n\r\n--- 169.254.0.7 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1015ms') 2026-01-26 03:30:09,740 - DEBUG - Ping to Metadata IP 169.254.0.7 of VM ctest-TestBGPaasZone-86699219-42214563 failed! 2026-01-26 03:30:09,755 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaasZone-86699219:ctest-cnz_vn-02014070 is 70.60.128.65 and allocation pool is NOT set 2026-01-26 03:30:13,837 - DEBUG - (True, 'PING 169.254.0.7 (169.254.0.7) 56(84) bytes of data.\r\n\r\n--- 169.254.0.7 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1021ms') 2026-01-26 03:30:13,837 - DEBUG - Ping to Metadata IP 169.254.0.7 of VM ctest-TestBGPaasZone-86699219-42214563 failed! 2026-01-26 03:30:13,853 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaasZone-86699219:ctest-cnz_vn-02014070 is 70.60.128.65 and allocation pool is NOT set 2026-01-26 03:30:17,930 - DEBUG - (True, 'PING 169.254.0.7 (169.254.0.7) 56(84) bytes of data.\r\n\r\n--- 169.254.0.7 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1018ms') 2026-01-26 03:30:17,930 - DEBUG - Ping to Metadata IP 169.254.0.7 of VM ctest-TestBGPaasZone-86699219-42214563 failed! 2026-01-26 03:30:17,944 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaasZone-86699219:ctest-cnz_vn-02014070 is 70.60.128.65 and allocation pool is NOT set 2026-01-26 03:30:22,032 - DEBUG - (True, 'PING 169.254.0.7 (169.254.0.7) 56(84) bytes of data.\r\n\r\n--- 169.254.0.7 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1017ms') 2026-01-26 03:30:22,032 - DEBUG - Ping to Metadata IP 169.254.0.7 of VM ctest-TestBGPaasZone-86699219-42214563 failed! 2026-01-26 03:30:22,048 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaasZone-86699219:ctest-cnz_vn-02014070 is 70.60.128.65 and allocation pool is NOT set 2026-01-26 03:30:26,129 - DEBUG - (True, 'PING 169.254.0.7 (169.254.0.7) 56(84) bytes of data.\r\n\r\n--- 169.254.0.7 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1015ms') 2026-01-26 03:30:26,129 - DEBUG - Ping to Metadata IP 169.254.0.7 of VM ctest-TestBGPaasZone-86699219-42214563 failed! 2026-01-26 03:30:26,143 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaasZone-86699219:ctest-cnz_vn-02014070 is 70.60.128.65 and allocation pool is NOT set 2026-01-26 03:30:30,217 - DEBUG - (True, 'PING 169.254.0.7 (169.254.0.7) 56(84) bytes of data.\r\n\r\n--- 169.254.0.7 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1015ms') 2026-01-26 03:30:30,217 - DEBUG - Ping to Metadata IP 169.254.0.7 of VM ctest-TestBGPaasZone-86699219-42214563 failed! 2026-01-26 03:30:30,231 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaasZone-86699219:ctest-cnz_vn-02014070 is 70.60.128.65 and allocation pool is NOT set 2026-01-26 03:30:34,317 - DEBUG - (True, 'PING 169.254.0.7 (169.254.0.7) 56(84) bytes of data.\r\n\r\n--- 169.254.0.7 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1023ms') 2026-01-26 03:30:34,317 - DEBUG - Ping to Metadata IP 169.254.0.7 of VM ctest-TestBGPaasZone-86699219-42214563 failed! 2026-01-26 03:30:34,335 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaasZone-86699219:ctest-cnz_vn-02014070 is 70.60.128.65 and allocation pool is NOT set 2026-01-26 03:30:38,417 - DEBUG - (True, 'PING 169.254.0.7 (169.254.0.7) 56(84) bytes of data.\r\n\r\n--- 169.254.0.7 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1014ms') 2026-01-26 03:30:38,417 - DEBUG - Ping to Metadata IP 169.254.0.7 of VM ctest-TestBGPaasZone-86699219-42214563 failed! 2026-01-26 03:30:38,431 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaasZone-86699219:ctest-cnz_vn-02014070 is 70.60.128.65 and allocation pool is NOT set 2026-01-26 03:30:42,508 - DEBUG - (True, 'PING 169.254.0.7 (169.254.0.7) 56(84) bytes of data.\r\n\r\n--- 169.254.0.7 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1013ms') 2026-01-26 03:30:42,508 - DEBUG - Ping to Metadata IP 169.254.0.7 of VM ctest-TestBGPaasZone-86699219-42214563 failed! 2026-01-26 03:30:42,523 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaasZone-86699219:ctest-cnz_vn-02014070 is 70.60.128.65 and allocation pool is NOT set 2026-01-26 03:30:46,608 - DEBUG - (True, 'PING 169.254.0.7 (169.254.0.7) 56(84) bytes of data.\r\n\r\n--- 169.254.0.7 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1014ms') 2026-01-26 03:30:46,608 - DEBUG - Ping to Metadata IP 169.254.0.7 of VM ctest-TestBGPaasZone-86699219-42214563 failed! 2026-01-26 03:30:46,624 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaasZone-86699219:ctest-cnz_vn-02014070 is 70.60.128.65 and allocation pool is NOT set 2026-01-26 03:30:50,700 - DEBUG - (True, 'PING 169.254.0.7 (169.254.0.7) 56(84) bytes of data.\r\n\r\n--- 169.254.0.7 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1005ms') 2026-01-26 03:30:50,700 - DEBUG - Ping to Metadata IP 169.254.0.7 of VM ctest-TestBGPaasZone-86699219-42214563 failed! 2026-01-26 03:30:50,715 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaasZone-86699219:ctest-cnz_vn-02014070 is 70.60.128.65 and allocation pool is NOT set 2026-01-26 03:30:54,795 - DEBUG - (True, 'PING 169.254.0.7 (169.254.0.7) 56(84) bytes of data.\r\n\r\n--- 169.254.0.7 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1018ms') 2026-01-26 03:30:54,796 - DEBUG - Ping to Metadata IP 169.254.0.7 of VM ctest-TestBGPaasZone-86699219-42214563 failed! 2026-01-26 03:30:54,816 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaasZone-86699219:ctest-cnz_vn-02014070 is 70.60.128.65 and allocation pool is NOT set 2026-01-26 03:30:58,896 - DEBUG - (True, 'PING 169.254.0.7 (169.254.0.7) 56(84) bytes of data.\r\n\r\n--- 169.254.0.7 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1015ms') 2026-01-26 03:30:58,896 - DEBUG - Ping to Metadata IP 169.254.0.7 of VM ctest-TestBGPaasZone-86699219-42214563 failed! 2026-01-26 03:30:58,913 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaasZone-86699219:ctest-cnz_vn-02014070 is 70.60.128.65 and allocation pool is NOT set 2026-01-26 03:31:02,988 - DEBUG - (True, 'PING 169.254.0.7 (169.254.0.7) 56(84) bytes of data.\r\n\r\n--- 169.254.0.7 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1015ms') 2026-01-26 03:31:02,988 - DEBUG - Ping to Metadata IP 169.254.0.7 of VM ctest-TestBGPaasZone-86699219-42214563 failed! 2026-01-26 03:31:03,003 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaasZone-86699219:ctest-cnz_vn-02014070 is 70.60.128.65 and allocation pool is NOT set 2026-01-26 03:31:07,086 - DEBUG - (True, 'PING 169.254.0.7 (169.254.0.7) 56(84) bytes of data.\r\n\r\n--- 169.254.0.7 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1019ms') 2026-01-26 03:31:07,086 - DEBUG - Ping to Metadata IP 169.254.0.7 of VM ctest-TestBGPaasZone-86699219-42214563 failed! 2026-01-26 03:31:07,101 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaasZone-86699219:ctest-cnz_vn-02014070 is 70.60.128.65 and allocation pool is NOT set 2026-01-26 03:31:11,183 - DEBUG - (True, 'PING 169.254.0.7 (169.254.0.7) 56(84) bytes of data.\r\n\r\n--- 169.254.0.7 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1018ms') 2026-01-26 03:31:11,183 - DEBUG - Ping to Metadata IP 169.254.0.7 of VM ctest-TestBGPaasZone-86699219-42214563 failed! 2026-01-26 03:31:11,197 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaasZone-86699219:ctest-cnz_vn-02014070 is 70.60.128.65 and allocation pool is NOT set 2026-01-26 03:31:15,272 - DEBUG - (True, 'PING 169.254.0.7 (169.254.0.7) 56(84) bytes of data.\r\n\r\n--- 169.254.0.7 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1018ms') 2026-01-26 03:31:15,273 - DEBUG - Ping to Metadata IP 169.254.0.7 of VM ctest-TestBGPaasZone-86699219-42214563 failed! 2026-01-26 03:31:15,288 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaasZone-86699219:ctest-cnz_vn-02014070 is 70.60.128.65 and allocation pool is NOT set 2026-01-26 03:31:19,375 - DEBUG - (True, 'PING 169.254.0.7 (169.254.0.7) 56(84) bytes of data.\r\n\r\n--- 169.254.0.7 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1000ms') 2026-01-26 03:31:19,375 - DEBUG - Ping to Metadata IP 169.254.0.7 of VM ctest-TestBGPaasZone-86699219-42214563 failed! 2026-01-26 03:31:19,391 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaasZone-86699219:ctest-cnz_vn-02014070 is 70.60.128.65 and allocation pool is NOT set 2026-01-26 03:31:23,498 - DEBUG - (True, 'PING 169.254.0.7 (169.254.0.7) 56(84) bytes of data.\r\n\r\n--- 169.254.0.7 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1024ms') 2026-01-26 03:31:23,498 - DEBUG - Ping to Metadata IP 169.254.0.7 of VM ctest-TestBGPaasZone-86699219-42214563 failed! 2026-01-26 03:31:23,512 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaasZone-86699219:ctest-cnz_vn-02014070 is 70.60.128.65 and allocation pool is NOT set 2026-01-26 03:31:27,601 - DEBUG - (True, 'PING 169.254.0.7 (169.254.0.7) 56(84) bytes of data.\r\n\r\n--- 169.254.0.7 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1022ms') 2026-01-26 03:31:27,601 - DEBUG - Ping to Metadata IP 169.254.0.7 of VM ctest-TestBGPaasZone-86699219-42214563 failed! 2026-01-26 03:31:27,615 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaasZone-86699219:ctest-cnz_vn-02014070 is 70.60.128.65 and allocation pool is NOT set 2026-01-26 03:31:31,689 - DEBUG - (True, 'PING 169.254.0.7 (169.254.0.7) 56(84) bytes of data.\r\n64 bytes from 169.254.0.7: icmp_seq=2 ttl=63 time=4.89 ms\r\n\r\n--- 169.254.0.7 ping statistics ---\r\n2 packets transmitted, 1 received, 50% packet loss, time 1014ms\r\nrtt min/avg/max/mdev = 4.894/4.894/4.894/0.000 ms') 2026-01-26 03:31:31,689 - INFO - Ping to Metadata IP 169.254.0.7 of VM ctest-TestBGPaasZone-86699219-42214563 passed 2026-01-26 03:31:31,758 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:31:31,758 - DEBUG - Waiting to SSH to VM ctest-TestBGPaasZone-86699219-42214563, IP 70.60.128.67, Port 22 2026-01-26 03:31:31,829 - DEBUG - Error on ssh to ubuntu@169.254.0.7:22, result: /bin/bash: connect: Connection refused /bin/bash: line 1: /dev/tcp/169.254.0.7/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.7/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.7/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''} 2026-01-26 03:31:31,931 - DEBUG - VM ctest-TestBGPaasZone-86699219-42214563 is NOT ready for SSH connections, VM status: ACTIVE 2026-01-26 03:31:36,932 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:31:36,932 - DEBUG - Waiting to SSH to VM ctest-TestBGPaasZone-86699219-42214563, IP 70.60.128.67, Port 22 2026-01-26 03:31:37,000 - DEBUG - Error on ssh to ubuntu@169.254.0.7:22, result: /bin/bash: connect: Connection refused /bin/bash: line 1: /dev/tcp/169.254.0.7/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.7/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.7/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''} 2026-01-26 03:31:37,095 - DEBUG - VM ctest-TestBGPaasZone-86699219-42214563 is NOT ready for SSH connections, VM status: ACTIVE 2026-01-26 03:31:42,095 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:31:42,095 - DEBUG - Waiting to SSH to VM ctest-TestBGPaasZone-86699219-42214563, IP 70.60.128.67, Port 22 2026-01-26 03:31:42,164 - DEBUG - Error on ssh to ubuntu@169.254.0.7:22, result: /bin/bash: connect: Connection refused /bin/bash: line 1: /dev/tcp/169.254.0.7/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.7/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.7/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''} 2026-01-26 03:31:42,258 - DEBUG - VM ctest-TestBGPaasZone-86699219-42214563 is NOT ready for SSH connections, VM status: ACTIVE 2026-01-26 03:31:47,258 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:31:47,259 - DEBUG - Waiting to SSH to VM ctest-TestBGPaasZone-86699219-42214563, IP 70.60.128.67, Port 22 2026-01-26 03:31:47,318 - DEBUG - Error on ssh to ubuntu@169.254.0.7:22, result: /bin/bash: connect: Connection refused /bin/bash: line 1: /dev/tcp/169.254.0.7/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.7/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.7/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''} 2026-01-26 03:31:47,404 - DEBUG - VM ctest-TestBGPaasZone-86699219-42214563 is NOT ready for SSH connections, VM status: ACTIVE 2026-01-26 03:31:52,405 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:31:52,405 - DEBUG - Waiting to SSH to VM ctest-TestBGPaasZone-86699219-42214563, IP 70.60.128.67, Port 22 2026-01-26 03:31:52,472 - DEBUG - Error on ssh to ubuntu@169.254.0.7:22, result: /bin/bash: connect: Connection refused /bin/bash: line 1: /dev/tcp/169.254.0.7/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.7/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.7/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''} 2026-01-26 03:31:52,561 - DEBUG - VM ctest-TestBGPaasZone-86699219-42214563 is NOT ready for SSH connections, VM status: ACTIVE 2026-01-26 03:31:57,562 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:31:57,563 - DEBUG - Waiting to SSH to VM ctest-TestBGPaasZone-86699219-42214563, IP 70.60.128.67, Port 22 2026-01-26 03:31:57,629 - DEBUG - Error on ssh to ubuntu@169.254.0.7:22, result: /bin/bash: connect: Connection refused /bin/bash: line 1: /dev/tcp/169.254.0.7/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.7/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.7/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''} 2026-01-26 03:31:57,713 - DEBUG - VM ctest-TestBGPaasZone-86699219-42214563 is NOT ready for SSH connections, VM status: ACTIVE 2026-01-26 03:32:02,713 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:32:02,713 - DEBUG - Waiting to SSH to VM ctest-TestBGPaasZone-86699219-42214563, IP 70.60.128.67, Port 22 2026-01-26 03:32:02,781 - DEBUG - Error on ssh to ubuntu@169.254.0.7:22, result: /bin/bash: connect: Connection refused /bin/bash: line 1: /dev/tcp/169.254.0.7/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.7/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.7/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''} 2026-01-26 03:32:02,886 - DEBUG - VM ctest-TestBGPaasZone-86699219-42214563 is NOT ready for SSH connections, VM status: ACTIVE 2026-01-26 03:32:07,886 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:32:07,886 - DEBUG - Waiting to SSH to VM ctest-TestBGPaasZone-86699219-42214563, IP 70.60.128.67, Port 22 2026-01-26 03:32:07,942 - DEBUG - Error on ssh to ubuntu@169.254.0.7:22, result: /bin/bash: connect: Connection refused /bin/bash: line 1: /dev/tcp/169.254.0.7/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.7/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.7/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''} 2026-01-26 03:32:08,031 - DEBUG - VM ctest-TestBGPaasZone-86699219-42214563 is NOT ready for SSH connections, VM status: ACTIVE 2026-01-26 03:32:13,032 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:32:13,033 - DEBUG - Waiting to SSH to VM ctest-TestBGPaasZone-86699219-42214563, IP 70.60.128.67, Port 22 2026-01-26 03:32:13,100 - DEBUG - Error on ssh to ubuntu@169.254.0.7:22, result: /bin/bash: connect: Connection refused /bin/bash: line 1: /dev/tcp/169.254.0.7/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.7/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.7/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''} 2026-01-26 03:32:13,181 - DEBUG - VM ctest-TestBGPaasZone-86699219-42214563 is NOT ready for SSH connections, VM status: ACTIVE 2026-01-26 03:32:18,182 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:32:18,182 - DEBUG - Waiting to SSH to VM ctest-TestBGPaasZone-86699219-42214563, IP 70.60.128.67, Port 22 2026-01-26 03:32:18,237 - DEBUG - Error on ssh to ubuntu@169.254.0.7:22, result: /bin/bash: connect: Connection refused /bin/bash: line 1: /dev/tcp/169.254.0.7/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.7/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.7/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''} 2026-01-26 03:32:18,328 - DEBUG - VM ctest-TestBGPaasZone-86699219-42214563 is NOT ready for SSH connections, VM status: ACTIVE 2026-01-26 03:32:23,329 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:32:23,329 - DEBUG - Waiting to SSH to VM ctest-TestBGPaasZone-86699219-42214563, IP 70.60.128.67, Port 22 2026-01-26 03:32:23,407 - DEBUG - Error on ssh to ubuntu@169.254.0.7:22, result: /bin/bash: connect: Connection refused /bin/bash: line 1: /dev/tcp/169.254.0.7/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.7/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.7/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''} 2026-01-26 03:32:23,496 - DEBUG - VM ctest-TestBGPaasZone-86699219-42214563 is NOT ready for SSH connections, VM status: ACTIVE 2026-01-26 03:32:28,497 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:32:28,497 - DEBUG - Waiting to SSH to VM ctest-TestBGPaasZone-86699219-42214563, IP 70.60.128.67, Port 22 2026-01-26 03:32:28,676 - DEBUG - VM ctest-TestBGPaasZone-86699219-42214563 is ready for SSH connections 2026-01-26 03:32:28,676 - INFO - Waiting for VM ctest-TestBGPaasZone-86699219-12600266 to be up.. 2026-01-26 03:32:28,776 - DEBUG - VM is in ACTIVE state now 2026-01-26 03:32:28,776 - INFO - VM name : ctest-TestBGPaasZone-86699219-12600266 2026-01-26 03:32:28,872 - DEBUG - VM ctest-TestBGPaasZone-86699219-12600266 ID is 4f8facca-56bf-4a0f-acff-a3d7c7c07ed1 2026-01-26 03:32:28,873 - DEBUG - VM ctest-TestBGPaasZone-86699219-12600266 launched on Node an-jenkins-deploy-platform-ansible-os-5076-2 2026-01-26 03:32:28,953 - DEBUG - Requesting: http://10.0.0.240:8082/virtual-machine/4f8facca-56bf-4a0f-acff-a3d7c7c07ed1 2026-01-26 03:32:28,963 - DEBUG - Requesting: http://10.0.0.240:8082/virtual-machine-interface/914a1b1c-1e65-4b8c-8947-4775478948f5 2026-01-26 03:32:30,122 - 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=4.31 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=0.516 ms\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1002ms\r\nrtt min/avg/max/mdev = 0.516/2.413/4.310/1.897 ms') 2026-01-26 03:32:30,122 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-TestBGPaasZone-86699219-12600266 passed 2026-01-26 03:32:30,193 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:32:30,193 - DEBUG - Waiting to SSH to VM ctest-TestBGPaasZone-86699219-12600266, IP 70.60.128.68, Port 22 2026-01-26 03:32:30,350 - DEBUG - VM ctest-TestBGPaasZone-86699219-12600266 is ready for SSH connections 2026-01-26 03:32:30,350 - INFO - Waiting for VM ctest-TestBGPaasZone-86699219-91824582 to be up.. 2026-01-26 03:32:30,426 - DEBUG - VM is in ACTIVE state now 2026-01-26 03:32:30,427 - INFO - VM name : ctest-TestBGPaasZone-86699219-91824582 2026-01-26 03:32:30,511 - DEBUG - VM ctest-TestBGPaasZone-86699219-91824582 ID is cbb9e5e4-e48f-4045-a95d-1727a62d1ec7 2026-01-26 03:32:30,511 - DEBUG - VM ctest-TestBGPaasZone-86699219-91824582 launched on Node an-jenkins-deploy-platform-ansible-os-5076-1 2026-01-26 03:32:30,592 - DEBUG - Requesting: http://10.0.0.240:8082/virtual-machine/cbb9e5e4-e48f-4045-a95d-1727a62d1ec7 2026-01-26 03:32:30,601 - DEBUG - Requesting: http://10.0.0.240:8082/virtual-machine-interface/a48e5232-55c9-43a3-aeb0-6061f6f5a843 2026-01-26 03:32:31,767 - DEBUG - (True, 'PING 169.254.0.8 (169.254.0.8) 56(84) bytes of data.\r\n64 bytes from 169.254.0.8: icmp_seq=1 ttl=63 time=4.23 ms\r\n64 bytes from 169.254.0.8: icmp_seq=2 ttl=63 time=2.55 ms\r\n\r\n--- 169.254.0.8 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1001ms\r\nrtt min/avg/max/mdev = 2.546/3.389/4.233/0.843 ms') 2026-01-26 03:32:31,768 - INFO - Ping to Metadata IP 169.254.0.8 of VM ctest-TestBGPaasZone-86699219-91824582 passed 2026-01-26 03:32:31,841 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:32:31,841 - DEBUG - Waiting to SSH to VM ctest-TestBGPaasZone-86699219-91824582, IP 70.60.128.69, Port 22 2026-01-26 03:32:32,017 - DEBUG - VM ctest-TestBGPaasZone-86699219-91824582 is ready for SSH connections 2026-01-26 03:32:32,156 - INFO - Created control node zone ctest-test-zone-21896135(6192a7c6-4eb4-41fb-937d-b2fe5d5d1906) 2026-01-26 03:32:32,512 - INFO - Created control node zone ctest-test-zone-16431106(d5577e04-d92c-4305-a853-fa1bd30e9cba) 2026-01-26 03:32:32,872 - INFO - Created control node zone ctest-test-zone-49737311(0edf9911-57b3-4148-b699-4283c8f1699b) 2026-01-26 03:32:33,156 - INFO - Creating BGPaaS ctest-TestBGPaasZone-86699219-11980083 2026-01-26 03:32:33,236 - INFO - BGPaaS: ctest-TestBGPaasZone-86699219-11980083(a6ecae7b-de6c-4894-ab6e-24fd3f04d8cc) 2026-01-26 03:32:33,236 - DEBUG - Requesting: http://10.0.0.141:8082/bgp-as-a-service/a6ecae7b-de6c-4894-ab6e-24fd3f04d8cc 2026-01-26 03:32:33,537 - DEBUG - Requesting: http://10.0.0.141:8082/bgp-as-a-service/a6ecae7b-de6c-4894-ab6e-24fd3f04d8cc 2026-01-26 03:32:33,578 - INFO - verify_in_api_server passed for BGPaaS obj a6ecae7b-de6c-4894-ab6e-24fd3f04d8cc 2026-01-26 03:32:33,578 - INFO - BGPaaS(a6ecae7b-de6c-4894-ab6e-24fd3f04d8cc): verify_on_setup passed 2026-01-26 03:32:33,578 - INFO - We will configure BGP on the VM 2026-01-26 03:32:33,832 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:32:33,832 - INFO - Configuring BGP on ctest-TestBGPaasZone-86699219-42214563 2026-01-26 03:32:33,833 - 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 70.60.128.67; protocol bgp bgp_1{ local as 65000; neighbor 70.60.128.65 as 64512; export where source = RTS_STATIC; export all; multihop; #export all; hold time 90; bfd on; source address 70.60.128.67; } protocol bfd { neighbor 70.60.128.65 local 70.60.128.67 multihop on; } EOS , host_string: ubuntu@169.254.0.7, password: ubuntugateway: ubuntu@10.0.0.65, gateway password: c0ntrail123 2026-01-26 03:32:33,833 - 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 70.60.128.67; protocol bgp bgp_1{ local as 65000; neighbor 70.60.128.65 as 64512; export where source = RTS_STATIC; export all; multihop; #export all; hold time 90; bfd on; source address 70.60.128.67; } protocol bfd { neighbor 70.60.128.65 local 70.60.128.67 multihop on; } EOS 2026-01-26 03:32:48,734 - DEBUG - None 2026-01-26 03:32:48,734 - 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 70.60.128.67; protocol bgp bgp_1{ local as 65000; neighbor 70.60.128.65 as 64512; export where source = RTS_STATIC; export all; multihop; #export all; hold time 90; bfd on; source address 70.60.128.67; } protocol bfd { neighbor 70.60.128.65 local 70.60.128.67 multihop on; } EOS , host_string: ubuntu@169.254.0.7, password: ubuntugateway: ubuntu@10.0.0.65, gateway password: c0ntrail123 2026-01-26 03:32:48,734 - 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 70.60.128.67; protocol bgp bgp_1{ local as 65000; neighbor 70.60.128.65 as 64512; export where source = RTS_STATIC; export all; multihop; #export all; hold time 90; bfd on; source address 70.60.128.67; } protocol bfd { neighbor 70.60.128.65 local 70.60.128.67 multihop on; } EOS 2026-01-26 03:32:49,681 - DEBUG - None 2026-01-26 03:32:49,681 - DEBUG - Running remote_cmd, Cmd : service bird restart, host_string: ubuntu@169.254.0.7, password: ubuntugateway: ubuntu@10.0.0.65, gateway password: c0ntrail123 2026-01-26 03:32:49,682 - DEBUG - service bird restart 2026-01-26 03:32:53,109 - DEBUG - bird stop/waiting bird start/running, process 1437 2026-01-26 03:32:53,109 - INFO - Attaching VMI d5c6901d-8ddd-415c-9ece-4dc146877ed2 to BGPaaS a6ecae7b-de6c-4894-ab6e-24fd3f04d8cc 2026-01-26 03:32:53,188 - INFO - Attaching the VMI a1fb13f9-f3d2-446a-92da-3c90c8fa79ed to the BGPaaS a6ecae7b-de6c-4894-ab6e-24fd3f04d8cc object 2026-01-26 03:32:53,189 - DEBUG - Running remote_cmd, Cmd : sudo ip addr add 70.60.128.84 dev eth0, host_string: ubuntu@169.254.0.7, password: ubuntugateway: ubuntu@10.0.0.65, gateway password: c0ntrail123 2026-01-26 03:32:53,189 - DEBUG - sudo ip addr add 70.60.128.84 dev eth0 2026-01-26 03:32:54,676 - DEBUG - None 2026-01-26 03:32:54,740 - INFO - Creating BGPaaS ctest-TestBGPaasZone-86699219-20735073 2026-01-26 03:32:54,820 - INFO - BGPaaS: ctest-TestBGPaasZone-86699219-20735073(9b2c13c3-7f02-4a31-9b6f-9f42da31b086) 2026-01-26 03:32:54,820 - DEBUG - Requesting: http://10.0.0.141:8082/bgp-as-a-service/9b2c13c3-7f02-4a31-9b6f-9f42da31b086 2026-01-26 03:32:54,834 - INFO - verify_in_api_server passed for BGPaaS obj 9b2c13c3-7f02-4a31-9b6f-9f42da31b086 2026-01-26 03:32:54,834 - INFO - BGPaaS(9b2c13c3-7f02-4a31-9b6f-9f42da31b086): verify_on_setup passed 2026-01-26 03:32:54,834 - INFO - We will configure BGP on the VM 2026-01-26 03:32:55,096 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:32:55,096 - INFO - Configuring BGP on ctest-TestBGPaasZone-86699219-12600266 2026-01-26 03:32:55,097 - 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 70.60.128.68; protocol bgp bgp_1{ local as 65000; neighbor 70.60.128.66 as 64512; export where source = RTS_STATIC; export all; multihop; #export all; hold time 90; bfd on; source address 70.60.128.68; } protocol bfd { neighbor 70.60.128.66 local 70.60.128.68 multihop on; } EOS , host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.130, gateway password: c0ntrail123 2026-01-26 03:32:55,097 - 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 70.60.128.68; protocol bgp bgp_1{ local as 65000; neighbor 70.60.128.66 as 64512; export where source = RTS_STATIC; export all; multihop; #export all; hold time 90; bfd on; source address 70.60.128.68; } protocol bfd { neighbor 70.60.128.66 local 70.60.128.68 multihop on; } EOS 2026-01-26 03:33:00,572 - DEBUG - None 2026-01-26 03:33:00,572 - 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 70.60.128.68; protocol bgp bgp_1{ local as 65000; neighbor 70.60.128.66 as 64512; export where source = RTS_STATIC; export all; multihop; #export all; hold time 90; bfd on; source address 70.60.128.68; } protocol bfd { neighbor 70.60.128.66 local 70.60.128.68 multihop on; } EOS , host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.130, gateway password: c0ntrail123 2026-01-26 03:33:00,572 - 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 70.60.128.68; protocol bgp bgp_1{ local as 65000; neighbor 70.60.128.66 as 64512; export where source = RTS_STATIC; export all; multihop; #export all; hold time 90; bfd on; source address 70.60.128.68; } protocol bfd { neighbor 70.60.128.66 local 70.60.128.68 multihop on; } EOS 2026-01-26 03:33:01,222 - DEBUG - None 2026-01-26 03:33:01,222 - DEBUG - Running remote_cmd, Cmd : service bird restart, host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.130, gateway password: c0ntrail123 2026-01-26 03:33:01,222 - DEBUG - service bird restart 2026-01-26 03:33:02,996 - DEBUG - bird stop/waiting bird start/running, process 1433 2026-01-26 03:33:02,996 - INFO - Attaching VMI 914a1b1c-1e65-4b8c-8947-4775478948f5 to BGPaaS 9b2c13c3-7f02-4a31-9b6f-9f42da31b086 2026-01-26 03:33:03,072 - INFO - Attaching the VMI 4f8facca-56bf-4a0f-acff-a3d7c7c07ed1 to the BGPaaS 9b2c13c3-7f02-4a31-9b6f-9f42da31b086 object 2026-01-26 03:33:03,072 - DEBUG - Running remote_cmd, Cmd : sudo ip addr add 70.60.128.84 dev eth0, host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.130, gateway password: c0ntrail123 2026-01-26 03:33:03,072 - DEBUG - sudo ip addr add 70.60.128.84 dev eth0 2026-01-26 03:33:03,748 - DEBUG - None 2026-01-26 03:33:03,748 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:33:03,771 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:33:09,788 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:33:15,803 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:33:21,819 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:33:27,836 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:33:33,853 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:33:39,869 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:33:45,882 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:33:51,896 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:33:57,910 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:34:03,930 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:34:03,932 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:34:03,932 - INFO - primary peer not 70.60.128.67 established to the bgp_router ['10.20.0.25'] 2026-01-26 03:34:08,933 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:34:08,946 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:34:14,958 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:34:20,972 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:34:26,990 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:34:33,005 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:34:39,020 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:34:45,036 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:34:51,051 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:34:57,066 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:35:03,081 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:35:09,095 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:35:09,096 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:35:09,096 - INFO - primary peer not 70.60.128.67 established to the bgp_router ['10.20.0.25'] 2026-01-26 03:35:14,097 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:35:14,111 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:35:20,126 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:35:26,142 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:35:32,158 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:35:38,173 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:35:44,188 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:35:50,204 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:35:56,219 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:36:02,235 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:36:08,249 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:36:14,265 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:36:14,266 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:36:14,266 - INFO - primary peer not 70.60.128.67 established to the bgp_router ['10.20.0.25'] 2026-01-26 03:36:19,267 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:36:19,284 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:36:25,300 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:36:31,315 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:36:37,329 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:36:43,343 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:36:49,357 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:36:55,372 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:37:01,391 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:37:07,405 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:37:13,419 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:37:19,434 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:37:19,434 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:37:19,434 - INFO - primary peer not 70.60.128.67 established to the bgp_router ['10.20.0.25'] 2026-01-26 03:37:24,436 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:37:24,450 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:37:30,469 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:37:36,484 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:37:42,500 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:37:48,516 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:37:54,533 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:38:00,547 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:38:06,562 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:38:12,576 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:38:18,591 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:38:24,604 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:38:24,604 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:38:24,604 - INFO - primary peer not 70.60.128.67 established to the bgp_router ['10.20.0.25'] 2026-01-26 03:38:29,605 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:38:29,618 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:38:35,635 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:38:41,651 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:38:47,666 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:38:53,681 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:38:59,697 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:39:05,711 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:39:11,729 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:39:17,744 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:39:23,758 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:39:29,773 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:39:29,773 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:39:29,773 - INFO - primary peer not 70.60.128.67 established to the bgp_router ['10.20.0.25'] 2026-01-26 03:39:34,774 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:39:34,793 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:39:40,807 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:39:46,823 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:39:52,839 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:39:58,855 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:40:04,870 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:40:10,884 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:40:16,898 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:40:22,912 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:40:28,926 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:40:34,943 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:40:34,943 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:40:34,943 - INFO - primary peer not 70.60.128.67 established to the bgp_router ['10.20.0.25'] 2026-01-26 03:40:39,944 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:40:39,962 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:40:45,978 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:40:51,994 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:40:58,009 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:41:04,025 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:41:10,040 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:41:16,054 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:41:22,068 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:41:28,082 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:41:34,103 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:41:40,118 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:41:40,118 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:41:40,118 - INFO - primary peer not 70.60.128.67 established to the bgp_router ['10.20.0.25'] 2026-01-26 03:41:45,119 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:41:45,135 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:41:51,155 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:41:57,170 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:42:03,185 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:42:09,199 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:42:15,214 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:42:21,232 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:42:27,248 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:42:33,265 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:42:39,281 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:42:45,298 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:42:45,298 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:42:45,298 - INFO - primary peer not 70.60.128.67 established to the bgp_router ['10.20.0.25'] 2026-01-26 03:42:50,299 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:42:50,313 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:42:56,329 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:43:02,344 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:43:08,362 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:43:14,377 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:43:20,392 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:43:26,408 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:43:32,422 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:43:38,441 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:43:44,460 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:43:50,476 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:43:50,477 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:43:50,477 - INFO - primary peer not 70.60.128.67 established to the bgp_router ['10.20.0.25'] 2026-01-26 03:43:55,478 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:43:55,492 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:44:01,509 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:44:07,523 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:44:13,537 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:44:19,552 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:44:25,565 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:44:31,579 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:44:37,593 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:44:43,612 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:44:49,627 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:44:55,642 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:44:55,642 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:44:55,642 - INFO - primary peer not 70.60.128.67 established to the bgp_router ['10.20.0.25'] 2026-01-26 03:44:55,646 - INFO - Detaching VMI 914a1b1c-1e65-4b8c-8947-4775478948f5 from BGPaaS 9b2c13c3-7f02-4a31-9b6f-9f42da31b086 2026-01-26 03:44:55,800 - INFO - Deleting BGPaaS ctest-TestBGPaasZone-86699219-20735073(9b2c13c3-7f02-4a31-9b6f-9f42da31b086) 2026-01-26 03:44:55,840 - DEBUG - Requesting: http://10.0.0.141:8082/bgp-as-a-service/9b2c13c3-7f02-4a31-9b6f-9f42da31b086 2026-01-26 03:44:55,875 - DEBUG - Response Code: 404 2026-01-26 03:44:55,875 - DEBUG - BGPaaS: 9b2c13c3-7f02-4a31-9b6f-9f42da31b086 deleted from api server 2026-01-26 03:44:55,875 - INFO - BGPaaS(9b2c13c3-7f02-4a31-9b6f-9f42da31b086): verify_on_cleanup passed 2026-01-26 03:44:55,876 - INFO - Detaching VMI d5c6901d-8ddd-415c-9ece-4dc146877ed2 from BGPaaS a6ecae7b-de6c-4894-ab6e-24fd3f04d8cc 2026-01-26 03:44:55,956 - INFO - Deleting BGPaaS ctest-TestBGPaasZone-86699219-11980083(a6ecae7b-de6c-4894-ab6e-24fd3f04d8cc) 2026-01-26 03:44:56,011 - DEBUG - Requesting: http://10.0.0.141:8082/bgp-as-a-service/a6ecae7b-de6c-4894-ab6e-24fd3f04d8cc 2026-01-26 03:44:56,017 - DEBUG - Response Code: 404 2026-01-26 03:44:56,017 - DEBUG - BGPaaS: a6ecae7b-de6c-4894-ab6e-24fd3f04d8cc deleted from api server 2026-01-26 03:44:56,017 - INFO - BGPaaS(a6ecae7b-de6c-4894-ab6e-24fd3f04d8cc): verify_on_cleanup passed 2026-01-26 03:44:56,017 - INFO - Deleting Control node zone ctest-test-zone-49737311(0edf9911-57b3-4148-b699-4283c8f1699b) 2026-01-26 03:44:56,168 - INFO - Deleting Control node zone ctest-test-zone-16431106(d5577e04-d92c-4305-a853-fa1bd30e9cba) 2026-01-26 03:44:56,320 - INFO - Deleting Control node zone ctest-test-zone-21896135(6192a7c6-4eb4-41fb-937d-b2fe5d5d1906) 2026-01-26 03:44:56,477 - INFO - Deleting VM ctest-TestBGPaasZone-86699219-91824582 2026-01-26 03:44:56,573 - INFO - Deleting VM ctest-TestBGPaasZone-86699219-12600266 2026-01-26 03:44:56,640 - INFO - Deleting VM ctest-TestBGPaasZone-86699219-42214563 2026-01-26 03:44:56,722 - INFO - Deleting VN ctest-cnz_vn-02014070 2026-01-26 03:44:56,818 - DEBUG - VN 5454c027-9345-4520-8949-d388322104bd still in use: Unable to complete operation on network 5454c027-9345-4520-8949-d388322104bd. There are one or more ports still in use on the network. Neutron server returns request_ids: ['req-07c18b94-bdfc-4c1e-bbcb-e3f881b1232e'] 2026-01-26 03:44:56,818 - WARNING - Deleting VN ctest-cnz_vn-02014070 failed..Will retry 2026-01-26 03:44:58,992 - DEBUG - Response for deleting network () 2026-01-26 03:45:00,278 - ERROR - AssertionError Python 3.9.21: /usr/bin/python3 Mon Jan 26 03:44:55 2026 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/bgpaas/test_bgpaas_zone.py in test_bgp_control_node_zone(self=) 57 cnt = 0 58 self.logger.info('executing bgp_control_zone test') 59 assert self.basic_control_node_zone_setup() 60 # update control node zone with different bgp routers 61 self.update_control_node_zones(self.cnzs) self = self.basic_control_node_zone_setup = > /contrail-test/serial_scripts/bgpaas/test_bgpaas_zone.py in basic_control_node_zone_setup(self=, ctrl_zone=None) 46 self.vn,self.vms[1],self.local_as,self.vip,ctrl_zone)) 47 for vm in self.vms: 48 assert self.verify_bgpaas_in_control_nodes_and_agent(self.bgpaas_fixtures[cnt],vm) 49 cnt += 1 50 msg = 'ping from %s to %s failed'%(self.client_vm.name, self.vip) self = self.verify_bgpaas_in_control_nodes_and_agent = .deco_retry....bgp_control_node_zone[sanity] id=0x7fa9f6d0d5e0>> self.bgpaas_fixtures = [, ] cnt = 0 vm = 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/bgpaas/test_bgpaas_zone.py", line 59, in test_bgp_control_node_zone assert self.basic_control_node_zone_setup() File "/contrail-test/serial_scripts/bgpaas/test_bgpaas_zone.py", line 48, in basic_control_node_zone_setup assert self.verify_bgpaas_in_control_nodes_and_agent(self.bgpaas_fixtures[cnt],vm) AssertionError 2026-01-26 03:45:00,279 - DEBUG - Skipping xmpp flap check 2026-01-26 03:45:00,280 - INFO -

2026-01-26 03:45:00,280 - INFO - END TEST : test_bgp_control_node_zone : FAILED[0:15:38]

2026-01-26 03:45:00,280 - INFO - -------------------------------------------------------------------------------- 2026-01-26 03:45:00,283 - INFO - ================================================================================ 2026-01-26 03:45:00,283 - INFO - STARTING TEST : test_bgp_control_node_zones_from_single_vnf 2026-01-26 03:45:01,574 - DEBUG - Skipping xmpp flap check 2026-01-26 03:45:01,574 - INFO - Initial checks done. Running the testcase now 2026-01-26 03:45:01,574 - INFO - 2026-01-26 03:45:01,574 - INFO - executing bgp_control_zone agent restart test 2026-01-26 03:45:01,920 - DEBUG - Response for create_network : {'network': {'id': '3d1cef5f-0053-4f94-b786-9b742288d54e', 'name': 'ctest-cnz_vn-19149423', 'tenant_id': 'dc0ec7328a674a89811efed8a6793120', 'project_id': 'dc0ec7328a674a89811efed8a6793120', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestBGPaasZone-86699219', 'ctest-cnz_vn-19149423'], 'port_security_enabled': True, 'description': ''}} 2026-01-26 03:45:02,131 - DEBUG - Response for create_subnet : {'subnet': {'id': '630b5354-ab84-424f-887e-d5408a707aa1', 'name': '', 'tenant_id': 'dc0ec7328a674a89811efed8a6793120', 'network_id': '3d1cef5f-0053-4f94-b786-9b742288d54e', 'ip_version': 4, 'cidr': '146.41.165.0/26', 'allocation_pools': [{'start': '146.41.165.2', 'end': '146.41.165.62'}], 'gateway_ip': '146.41.165.1', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '146.41.165.2', 'tags': [], 'project_id': 'dc0ec7328a674a89811efed8a6793120'}} 2026-01-26 03:45:02,157 - INFO - Created VN ctest-cnz_vn-19149423 2026-01-26 03:45:02,173 - DEBUG - VN ctest-cnz_vn-19149423 UUID is 3d1cef5f-0053-4f94-b786-9b742288d54e 2026-01-26 03:45:03,762 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-5076-2), Zone: (nova:an-jenkins-deploy-platform-ansible-os-5076-2) 2026-01-26 03:45:05,260 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-5076-1), Zone: (nova:an-jenkins-deploy-platform-ansible-os-5076-1) 2026-01-26 03:45:06,826 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-5076-2), Zone: (nova:an-jenkins-deploy-platform-ansible-os-5076-2) 2026-01-26 03:45:06,826 - INFO - Waiting for VM ctest-TestBGPaasZone-86699219-32619934 to be up.. 2026-01-26 03:45:06,922 - DEBUG - VM is in ACTIVE state now 2026-01-26 03:45:06,922 - INFO - VM name : ctest-TestBGPaasZone-86699219-32619934 2026-01-26 03:45:07,040 - DEBUG - VM ctest-TestBGPaasZone-86699219-32619934 ID is 2176cab0-a621-4a70-bf71-729138832805 2026-01-26 03:45:07,040 - DEBUG - VM ctest-TestBGPaasZone-86699219-32619934 launched on Node an-jenkins-deploy-platform-ansible-os-5076-2 2026-01-26 03:45:07,123 - DEBUG - Requesting: http://10.0.0.240:8082/virtual-machine/2176cab0-a621-4a70-bf71-729138832805 2026-01-26 03:45:07,165 - DEBUG - Requesting: http://10.0.0.240:8082/virtual-machine-interface/b885a212-837b-4f15-b720-84e49f33165b 2026-01-26 03:45:10,366 - 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') 2026-01-26 03:45:10,366 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestBGPaasZone-86699219-32619934 failed! 2026-01-26 03:45:10,382 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaasZone-86699219:ctest-cnz_vn-19149423 is 146.41.165.1 and allocation pool is NOT set 2026-01-26 03:45:14,464 - 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') 2026-01-26 03:45:14,464 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestBGPaasZone-86699219-32619934 failed! 2026-01-26 03:45:14,480 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaasZone-86699219:ctest-cnz_vn-19149423 is 146.41.165.1 and allocation pool is NOT set 2026-01-26 03:45:18,557 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1014ms') 2026-01-26 03:45:18,557 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestBGPaasZone-86699219-32619934 failed! 2026-01-26 03:45:18,574 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaasZone-86699219:ctest-cnz_vn-19149423 is 146.41.165.1 and allocation pool is NOT set 2026-01-26 03:45:22,655 - 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-01-26 03:45:22,655 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestBGPaasZone-86699219-32619934 failed! 2026-01-26 03:45:22,671 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaasZone-86699219:ctest-cnz_vn-19149423 is 146.41.165.1 and allocation pool is NOT set 2026-01-26 03:45:26,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 1014ms') 2026-01-26 03:45:26,751 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestBGPaasZone-86699219-32619934 failed! 2026-01-26 03:45:26,765 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaasZone-86699219:ctest-cnz_vn-19149423 is 146.41.165.1 and allocation pool is NOT set 2026-01-26 03:45:30,845 - 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') 2026-01-26 03:45:30,846 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestBGPaasZone-86699219-32619934 failed! 2026-01-26 03:45:30,862 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaasZone-86699219:ctest-cnz_vn-19149423 is 146.41.165.1 and allocation pool is NOT set 2026-01-26 03:45:34,941 - 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-01-26 03:45:34,941 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestBGPaasZone-86699219-32619934 failed! 2026-01-26 03:45:34,957 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaasZone-86699219:ctest-cnz_vn-19149423 is 146.41.165.1 and allocation pool is NOT set 2026-01-26 03:45:39,034 - 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-01-26 03:45:39,034 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestBGPaasZone-86699219-32619934 failed! 2026-01-26 03:45:39,049 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaasZone-86699219:ctest-cnz_vn-19149423 is 146.41.165.1 and allocation pool is NOT set 2026-01-26 03:45:43,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 1023ms') 2026-01-26 03:45:43,134 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestBGPaasZone-86699219-32619934 failed! 2026-01-26 03:45:43,149 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaasZone-86699219:ctest-cnz_vn-19149423 is 146.41.165.1 and allocation pool is NOT set 2026-01-26 03:45:47,233 - 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-01-26 03:45:47,233 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestBGPaasZone-86699219-32619934 failed! 2026-01-26 03:45:47,246 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaasZone-86699219:ctest-cnz_vn-19149423 is 146.41.165.1 and allocation pool is NOT set 2026-01-26 03:45:51,331 - 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-01-26 03:45:51,331 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestBGPaasZone-86699219-32619934 failed! 2026-01-26 03:45:51,349 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaasZone-86699219:ctest-cnz_vn-19149423 is 146.41.165.1 and allocation pool is NOT set 2026-01-26 03:45:55,415 - 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') 2026-01-26 03:45:55,415 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestBGPaasZone-86699219-32619934 failed! 2026-01-26 03:45:55,430 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaasZone-86699219:ctest-cnz_vn-19149423 is 146.41.165.1 and allocation pool is NOT set 2026-01-26 03:45:59,516 - 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') 2026-01-26 03:45:59,516 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestBGPaasZone-86699219-32619934 failed! 2026-01-26 03:45:59,536 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaasZone-86699219:ctest-cnz_vn-19149423 is 146.41.165.1 and allocation pool is NOT set 2026-01-26 03:46:03,613 - 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-01-26 03:46:03,613 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestBGPaasZone-86699219-32619934 failed! 2026-01-26 03:46:03,628 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaasZone-86699219:ctest-cnz_vn-19149423 is 146.41.165.1 and allocation pool is NOT set 2026-01-26 03:46:07,703 - 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-01-26 03:46:07,704 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestBGPaasZone-86699219-32619934 failed! 2026-01-26 03:46:07,719 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaasZone-86699219:ctest-cnz_vn-19149423 is 146.41.165.1 and allocation pool is NOT set 2026-01-26 03:46:11,805 - 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 1021ms') 2026-01-26 03:46:11,805 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestBGPaasZone-86699219-32619934 failed! 2026-01-26 03:46:11,819 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaasZone-86699219:ctest-cnz_vn-19149423 is 146.41.165.1 and allocation pool is NOT set 2026-01-26 03:46:15,904 - 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') 2026-01-26 03:46:15,904 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestBGPaasZone-86699219-32619934 failed! 2026-01-26 03:46:15,919 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaasZone-86699219:ctest-cnz_vn-19149423 is 146.41.165.1 and allocation pool is NOT set 2026-01-26 03:46:20,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 1019ms') 2026-01-26 03:46:20,001 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestBGPaasZone-86699219-32619934 failed! 2026-01-26 03:46:20,020 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaasZone-86699219:ctest-cnz_vn-19149423 is 146.41.165.1 and allocation pool is NOT set 2026-01-26 03:46:24,091 - 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') 2026-01-26 03:46:24,091 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestBGPaasZone-86699219-32619934 failed! 2026-01-26 03:46:24,108 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaasZone-86699219:ctest-cnz_vn-19149423 is 146.41.165.1 and allocation pool is NOT set 2026-01-26 03:46:26,171 - 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.96 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=1.81 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.808/2.385/2.963/0.577 ms') 2026-01-26 03:46:26,171 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-TestBGPaasZone-86699219-32619934 passed 2026-01-26 03:46:26,241 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:46:26,242 - DEBUG - Waiting to SSH to VM ctest-TestBGPaasZone-86699219-32619934, IP 146.41.165.3, Port 22 2026-01-26 03:46:26,309 - 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-01-26 03:46:26,396 - DEBUG - VM ctest-TestBGPaasZone-86699219-32619934 is NOT ready for SSH connections, VM status: ACTIVE 2026-01-26 03:46:31,397 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:46:31,397 - DEBUG - Waiting to SSH to VM ctest-TestBGPaasZone-86699219-32619934, IP 146.41.165.3, Port 22 2026-01-26 03:46:31,464 - 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-01-26 03:46:31,546 - DEBUG - VM ctest-TestBGPaasZone-86699219-32619934 is NOT ready for SSH connections, VM status: ACTIVE 2026-01-26 03:46:36,547 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:46:36,547 - DEBUG - Waiting to SSH to VM ctest-TestBGPaasZone-86699219-32619934, IP 146.41.165.3, Port 22 2026-01-26 03:46:36,603 - 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-01-26 03:46:36,698 - DEBUG - VM ctest-TestBGPaasZone-86699219-32619934 is NOT ready for SSH connections, VM status: ACTIVE 2026-01-26 03:46:41,699 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:46:41,699 - DEBUG - Waiting to SSH to VM ctest-TestBGPaasZone-86699219-32619934, IP 146.41.165.3, Port 22 2026-01-26 03:46:41,764 - 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-01-26 03:46:41,846 - DEBUG - VM ctest-TestBGPaasZone-86699219-32619934 is NOT ready for SSH connections, VM status: ACTIVE 2026-01-26 03:46:46,847 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:46:46,847 - DEBUG - Waiting to SSH to VM ctest-TestBGPaasZone-86699219-32619934, IP 146.41.165.3, Port 22 2026-01-26 03:46:46,916 - 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-01-26 03:46:47,003 - DEBUG - VM ctest-TestBGPaasZone-86699219-32619934 is NOT ready for SSH connections, VM status: ACTIVE 2026-01-26 03:46:52,003 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:46:52,003 - DEBUG - Waiting to SSH to VM ctest-TestBGPaasZone-86699219-32619934, IP 146.41.165.3, Port 22 2026-01-26 03:46:52,072 - 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-01-26 03:46:52,165 - DEBUG - VM ctest-TestBGPaasZone-86699219-32619934 is NOT ready for SSH connections, VM status: ACTIVE 2026-01-26 03:46:57,166 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:46:57,166 - DEBUG - Waiting to SSH to VM ctest-TestBGPaasZone-86699219-32619934, IP 146.41.165.3, Port 22 2026-01-26 03:46:57,222 - 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-01-26 03:46:57,321 - DEBUG - VM ctest-TestBGPaasZone-86699219-32619934 is NOT ready for SSH connections, VM status: ACTIVE 2026-01-26 03:47:02,322 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:47:02,322 - DEBUG - Waiting to SSH to VM ctest-TestBGPaasZone-86699219-32619934, IP 146.41.165.3, Port 22 2026-01-26 03:47:02,390 - 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-01-26 03:47:02,479 - DEBUG - VM ctest-TestBGPaasZone-86699219-32619934 is NOT ready for SSH connections, VM status: ACTIVE 2026-01-26 03:47:07,480 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:47:07,480 - DEBUG - Waiting to SSH to VM ctest-TestBGPaasZone-86699219-32619934, IP 146.41.165.3, Port 22 2026-01-26 03:47:07,538 - 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-01-26 03:47:07,619 - DEBUG - VM ctest-TestBGPaasZone-86699219-32619934 is NOT ready for SSH connections, VM status: ACTIVE 2026-01-26 03:47:12,619 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:47:12,619 - DEBUG - Waiting to SSH to VM ctest-TestBGPaasZone-86699219-32619934, IP 146.41.165.3, Port 22 2026-01-26 03:47:12,678 - 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-01-26 03:47:12,771 - DEBUG - VM ctest-TestBGPaasZone-86699219-32619934 is NOT ready for SSH connections, VM status: ACTIVE 2026-01-26 03:47:17,771 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:47:17,772 - DEBUG - Waiting to SSH to VM ctest-TestBGPaasZone-86699219-32619934, IP 146.41.165.3, Port 22 2026-01-26 03:47:17,941 - DEBUG - VM ctest-TestBGPaasZone-86699219-32619934 is ready for SSH connections 2026-01-26 03:47:17,941 - INFO - Waiting for VM ctest-TestBGPaasZone-86699219-16037342 to be up.. 2026-01-26 03:47:18,038 - DEBUG - VM is in ACTIVE state now 2026-01-26 03:47:18,038 - INFO - VM name : ctest-TestBGPaasZone-86699219-16037342 2026-01-26 03:47:18,125 - DEBUG - VM ctest-TestBGPaasZone-86699219-16037342 ID is 316071f0-f54e-472e-9865-7aee021a9678 2026-01-26 03:47:18,125 - DEBUG - VM ctest-TestBGPaasZone-86699219-16037342 launched on Node an-jenkins-deploy-platform-ansible-os-5076-1 2026-01-26 03:47:18,211 - DEBUG - Requesting: http://10.0.0.240:8082/virtual-machine/316071f0-f54e-472e-9865-7aee021a9678 2026-01-26 03:47:18,221 - DEBUG - Requesting: http://10.0.0.240:8082/virtual-machine-interface/f0b5a538-6484-44ac-a97c-f72157c0a050 2026-01-26 03:47:21,384 - DEBUG - (True, 'PING 169.254.0.7 (169.254.0.7) 56(84) bytes of data.\r\n\r\n--- 169.254.0.7 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1002ms') 2026-01-26 03:47:21,384 - DEBUG - Ping to Metadata IP 169.254.0.7 of VM ctest-TestBGPaasZone-86699219-16037342 failed! 2026-01-26 03:47:21,407 - DEBUG - Gateway for vn default-domain:ctest-TestBGPaasZone-86699219:ctest-cnz_vn-19149423 is 146.41.165.1 and allocation pool is NOT set 2026-01-26 03:47:23,468 - DEBUG - (True, 'PING 169.254.0.7 (169.254.0.7) 56(84) bytes of data.\r\n64 bytes from 169.254.0.7: icmp_seq=1 ttl=63 time=5.60 ms\r\n64 bytes from 169.254.0.7: icmp_seq=2 ttl=63 time=0.431 ms\r\n\r\n--- 169.254.0.7 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1001ms\r\nrtt min/avg/max/mdev = 0.431/3.014/5.598/2.583 ms') 2026-01-26 03:47:23,468 - INFO - Ping to Metadata IP 169.254.0.7 of VM ctest-TestBGPaasZone-86699219-16037342 passed 2026-01-26 03:47:23,561 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:47:23,561 - DEBUG - Waiting to SSH to VM ctest-TestBGPaasZone-86699219-16037342, IP 146.41.165.4, Port 22 2026-01-26 03:47:23,733 - DEBUG - VM ctest-TestBGPaasZone-86699219-16037342 is ready for SSH connections 2026-01-26 03:47:23,733 - INFO - Waiting for VM ctest-TestBGPaasZone-86699219-34411818 to be up.. 2026-01-26 03:47:23,824 - DEBUG - VM is in ACTIVE state now 2026-01-26 03:47:23,824 - INFO - VM name : ctest-TestBGPaasZone-86699219-34411818 2026-01-26 03:47:23,914 - DEBUG - VM ctest-TestBGPaasZone-86699219-34411818 ID is 0a1adb69-b812-41bc-816e-dbe40d53afee 2026-01-26 03:47:23,915 - DEBUG - VM ctest-TestBGPaasZone-86699219-34411818 launched on Node an-jenkins-deploy-platform-ansible-os-5076-2 2026-01-26 03:47:24,020 - DEBUG - Requesting: http://10.0.0.240:8082/virtual-machine/0a1adb69-b812-41bc-816e-dbe40d53afee 2026-01-26 03:47:24,032 - DEBUG - Requesting: http://10.0.0.240:8082/virtual-machine-interface/899b0e19-38b4-4765-acc0-cae233f9b6b5 2026-01-26 03:47:25,198 - 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.80 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=3.12 ms\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1002ms\r\nrtt min/avg/max/mdev = 3.120/3.957/4.795/0.837 ms') 2026-01-26 03:47:25,199 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-TestBGPaasZone-86699219-34411818 passed 2026-01-26 03:47:25,269 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:47:25,269 - DEBUG - Waiting to SSH to VM ctest-TestBGPaasZone-86699219-34411818, IP 146.41.165.5, Port 22 2026-01-26 03:47:25,337 - DEBUG - Error on ssh to ubuntu@169.254.0.4:22, result: /bin/bash: connect: Connection refused /bin/bash: line 1: /dev/tcp/169.254.0.4/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.4/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.4/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''} 2026-01-26 03:47:25,422 - DEBUG - VM ctest-TestBGPaasZone-86699219-34411818 is NOT ready for SSH connections, VM status: ACTIVE 2026-01-26 03:47:30,423 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:47:30,423 - DEBUG - Waiting to SSH to VM ctest-TestBGPaasZone-86699219-34411818, IP 146.41.165.5, Port 22 2026-01-26 03:47:30,482 - DEBUG - Error on ssh to ubuntu@169.254.0.4:22, result: /bin/bash: connect: Connection refused /bin/bash: line 1: /dev/tcp/169.254.0.4/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.4/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.4/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''} 2026-01-26 03:47:30,577 - DEBUG - VM ctest-TestBGPaasZone-86699219-34411818 is NOT ready for SSH connections, VM status: ACTIVE 2026-01-26 03:47:35,577 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:47:35,577 - DEBUG - Waiting to SSH to VM ctest-TestBGPaasZone-86699219-34411818, IP 146.41.165.5, Port 22 2026-01-26 03:47:35,744 - DEBUG - VM ctest-TestBGPaasZone-86699219-34411818 is ready for SSH connections 2026-01-26 03:47:35,880 - INFO - Created control node zone ctest-test-zone-86419409(39c4a8ed-6dc7-433c-9e3d-d94a74c02940) 2026-01-26 03:47:36,236 - INFO - Created control node zone ctest-test-zone-29515895(6e0e4a41-98f3-4048-a898-8985e04101c3) 2026-01-26 03:47:36,592 - INFO - Created control node zone ctest-test-zone-23761063(ffbad0a0-3793-4ff8-a8d5-fcac3178ecd1) 2026-01-26 03:47:36,880 - INFO - Creating BGPaaS ctest-TestBGPaasZone-86699219-41916923 2026-01-26 03:47:36,956 - INFO - BGPaaS: ctest-TestBGPaasZone-86699219-41916923(8a463c47-a275-4085-a559-4278480cb1c2) 2026-01-26 03:47:36,956 - DEBUG - Requesting: http://10.0.0.141:8082/bgp-as-a-service/8a463c47-a275-4085-a559-4278480cb1c2 2026-01-26 03:47:36,967 - INFO - verify_in_api_server passed for BGPaaS obj 8a463c47-a275-4085-a559-4278480cb1c2 2026-01-26 03:47:36,967 - INFO - BGPaaS(8a463c47-a275-4085-a559-4278480cb1c2): verify_on_setup passed 2026-01-26 03:47:36,968 - INFO - We will configure BGP on the VM 2026-01-26 03:47:37,388 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:47:37,388 - INFO - Configuring BGP on ctest-TestBGPaasZone-86699219-32619934 2026-01-26 03:47:37,388 - 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 146.41.165.3; protocol bgp bgp_1{ local as 65000; neighbor 146.41.165.1 as 64512; export where source = RTS_STATIC; export all; multihop; #export all; hold time 90; bfd on; source address 146.41.165.3; } protocol bfd { neighbor 146.41.165.1 local 146.41.165.3 multihop on; } EOS , host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.130, gateway password: c0ntrail123 2026-01-26 03:47:37,389 - 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 146.41.165.3; protocol bgp bgp_1{ local as 65000; neighbor 146.41.165.1 as 64512; export where source = RTS_STATIC; export all; multihop; #export all; hold time 90; bfd on; source address 146.41.165.3; } protocol bfd { neighbor 146.41.165.1 local 146.41.165.3 multihop on; } EOS 2026-01-26 03:47:43,606 - DEBUG - None 2026-01-26 03:47:43,606 - DEBUG - Running remote_cmd, Cmd : cat >> /etc/bird/bird.conf << EOS protocol bgp bgp_2{ local as 65000; neighbor 146.41.165.2 as 64512; export where source = RTS_STATIC; export all; multihop; #export all; hold time 90; bfd on; source address 146.41.165.3; } EOS , host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.130, gateway password: c0ntrail123 2026-01-26 03:47:43,606 - DEBUG - cat >> /etc/bird/bird.conf << EOS protocol bgp bgp_2{ local as 65000; neighbor 146.41.165.2 as 64512; export where source = RTS_STATIC; export all; multihop; #export all; hold time 90; bfd on; source address 146.41.165.3; } EOS 2026-01-26 03:47:44,184 - DEBUG - None 2026-01-26 03:47:44,184 - DEBUG - Running remote_cmd, Cmd : service bird restart, host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.130, gateway password: c0ntrail123 2026-01-26 03:47:44,184 - DEBUG - service bird restart 2026-01-26 03:47:46,159 - DEBUG - bird stop/waiting bird start/running, process 1440 2026-01-26 03:47:46,159 - INFO - Attaching VMI b885a212-837b-4f15-b720-84e49f33165b to BGPaaS 8a463c47-a275-4085-a559-4278480cb1c2 2026-01-26 03:47:46,236 - INFO - Attaching the VMI 2176cab0-a621-4a70-bf71-729138832805 to the BGPaaS 8a463c47-a275-4085-a559-4278480cb1c2 object 2026-01-26 03:47:46,236 - DEBUG - Running remote_cmd, Cmd : sudo ip addr add 146.41.165.20 dev eth0, host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.130, gateway password: c0ntrail123 2026-01-26 03:47:46,236 - DEBUG - sudo ip addr add 146.41.165.20 dev eth0 2026-01-26 03:47:47,013 - DEBUG - None 2026-01-26 03:47:47,080 - INFO - Creating BGPaaS ctest-TestBGPaasZone-86699219-00371394 2026-01-26 03:47:47,153 - INFO - BGPaaS: ctest-TestBGPaasZone-86699219-00371394(f8bf2fbe-645b-44d1-84f1-233d9abd0a79) 2026-01-26 03:47:47,153 - DEBUG - Requesting: http://10.0.0.141:8082/bgp-as-a-service/f8bf2fbe-645b-44d1-84f1-233d9abd0a79 2026-01-26 03:47:47,163 - INFO - verify_in_api_server passed for BGPaaS obj f8bf2fbe-645b-44d1-84f1-233d9abd0a79 2026-01-26 03:47:47,163 - INFO - BGPaaS(f8bf2fbe-645b-44d1-84f1-233d9abd0a79): verify_on_setup passed 2026-01-26 03:47:47,164 - INFO - We will configure BGP on the VM 2026-01-26 03:47:47,580 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:47:47,580 - INFO - Configuring BGP on ctest-TestBGPaasZone-86699219-16037342 2026-01-26 03:47:47,580 - 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 146.41.165.4; protocol bgp bgp_1{ local as 65000; neighbor 146.41.165.1 as 64512; export where source = RTS_STATIC; export all; multihop; #export all; hold time 90; bfd on; source address 146.41.165.4; } protocol bfd { neighbor 146.41.165.1 local 146.41.165.4 multihop on; } EOS , host_string: ubuntu@169.254.0.7, password: ubuntugateway: ubuntu@10.0.0.65, gateway password: c0ntrail123 2026-01-26 03:47:47,580 - 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 146.41.165.4; protocol bgp bgp_1{ local as 65000; neighbor 146.41.165.1 as 64512; export where source = RTS_STATIC; export all; multihop; #export all; hold time 90; bfd on; source address 146.41.165.4; } protocol bfd { neighbor 146.41.165.1 local 146.41.165.4 multihop on; } EOS 2026-01-26 03:47:53,092 - DEBUG - None 2026-01-26 03:47:53,093 - DEBUG - Running remote_cmd, Cmd : cat >> /etc/bird/bird.conf << EOS protocol bgp bgp_2{ local as 65000; neighbor 146.41.165.2 as 64512; export where source = RTS_STATIC; export all; multihop; #export all; hold time 90; bfd on; source address 146.41.165.4; } EOS , host_string: ubuntu@169.254.0.7, password: ubuntugateway: ubuntu@10.0.0.65, gateway password: c0ntrail123 2026-01-26 03:47:53,093 - DEBUG - cat >> /etc/bird/bird.conf << EOS protocol bgp bgp_2{ local as 65000; neighbor 146.41.165.2 as 64512; export where source = RTS_STATIC; export all; multihop; #export all; hold time 90; bfd on; source address 146.41.165.4; } EOS 2026-01-26 03:47:53,594 - DEBUG - None 2026-01-26 03:47:53,594 - DEBUG - Running remote_cmd, Cmd : service bird restart, host_string: ubuntu@169.254.0.7, password: ubuntugateway: ubuntu@10.0.0.65, gateway password: c0ntrail123 2026-01-26 03:47:53,595 - DEBUG - service bird restart 2026-01-26 03:47:55,445 - DEBUG - bird stop/waiting bird start/running, process 1433 2026-01-26 03:47:55,445 - INFO - Attaching VMI f0b5a538-6484-44ac-a97c-f72157c0a050 to BGPaaS f8bf2fbe-645b-44d1-84f1-233d9abd0a79 2026-01-26 03:47:55,524 - INFO - Attaching the VMI 316071f0-f54e-472e-9865-7aee021a9678 to the BGPaaS f8bf2fbe-645b-44d1-84f1-233d9abd0a79 object 2026-01-26 03:47:55,525 - DEBUG - Running remote_cmd, Cmd : sudo ip addr add 146.41.165.20 dev eth0, host_string: ubuntu@169.254.0.7, password: ubuntugateway: ubuntu@10.0.0.65, gateway password: c0ntrail123 2026-01-26 03:47:55,525 - DEBUG - sudo ip addr add 146.41.165.20 dev eth0 2026-01-26 03:47:56,178 - DEBUG - None 2026-01-26 03:47:56,178 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:47:56,193 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:48:02,210 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:48:08,228 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:48:14,243 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:48:20,258 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:48:26,273 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:48:32,287 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:48:38,300 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:48:44,315 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:48:50,328 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:48:56,341 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:48:56,342 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:48:56,342 - INFO - primary peer not 146.41.165.3 established to the bgp_router ['10.20.0.25'] 2026-01-26 03:49:01,342 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:49:01,357 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:49:07,372 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:49:13,386 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:49:19,402 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:49:25,415 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:49:31,430 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:49:37,447 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:49:43,462 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:49:49,475 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:49:55,489 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:50:01,504 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:50:01,504 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:50:01,504 - INFO - primary peer not 146.41.165.3 established to the bgp_router ['10.20.0.25'] 2026-01-26 03:50:06,505 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:50:06,523 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:50:12,541 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:50:18,554 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:50:24,569 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:50:30,585 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:50:36,601 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:50:42,615 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:50:48,629 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:50:54,643 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:51:00,660 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:51:06,675 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:51:06,675 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:51:06,675 - INFO - primary peer not 146.41.165.3 established to the bgp_router ['10.20.0.25'] 2026-01-26 03:51:11,676 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:51:11,690 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:51:17,705 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:51:23,718 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:51:29,734 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:51:35,749 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:51:41,762 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:51:47,779 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:51:53,793 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:51:59,809 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:52:05,823 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:52:11,840 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:52:11,840 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:52:11,840 - INFO - primary peer not 146.41.165.3 established to the bgp_router ['10.20.0.25'] 2026-01-26 03:52:16,841 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:52:16,860 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:52:22,880 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:52:28,899 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:52:34,912 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:52:40,926 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:52:46,939 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:52:52,952 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:52:58,970 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:53:04,985 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:53:11,004 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:53:17,019 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:53:17,020 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:53:17,020 - INFO - primary peer not 146.41.165.3 established to the bgp_router ['10.20.0.25'] 2026-01-26 03:53:22,020 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:53:22,033 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:53:28,048 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:53:34,062 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:53:40,078 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:53:46,094 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:53:52,110 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:53:58,125 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:54:04,143 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:54:10,158 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:54:16,179 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:54:22,196 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:54:22,196 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:54:22,196 - INFO - primary peer not 146.41.165.3 established to the bgp_router ['10.20.0.25'] 2026-01-26 03:54:27,198 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:54:27,211 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:54:33,224 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:54:39,238 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:54:45,252 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:54:51,267 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:54:57,282 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:55:03,303 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:55:09,318 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:55:15,331 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:55:21,349 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:55:27,364 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:55:27,364 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:55:27,364 - INFO - primary peer not 146.41.165.3 established to the bgp_router ['10.20.0.25'] 2026-01-26 03:55:32,365 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:55:32,385 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:55:38,403 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:55:44,422 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:55:50,441 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:55:56,458 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:56:02,478 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:56:08,493 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:56:14,509 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:56:20,526 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:56:26,541 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:56:32,557 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:56:32,558 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:56:32,558 - INFO - primary peer not 146.41.165.3 established to the bgp_router ['10.20.0.25'] 2026-01-26 03:56:37,558 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:56:37,571 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:56:43,585 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:56:49,601 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:56:55,617 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:57:01,632 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:57:07,647 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:57:13,663 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:57:19,679 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:57:25,695 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:57:31,710 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:57:37,725 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:57:37,725 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:57:37,725 - INFO - primary peer not 146.41.165.3 established to the bgp_router ['10.20.0.25'] 2026-01-26 03:57:42,727 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:57:42,741 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:57:48,757 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:57:54,774 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:58:00,795 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:58:06,817 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:58:12,833 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:58:18,851 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:58:24,865 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:58:30,881 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:58:36,894 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:58:42,908 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:58:42,909 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:58:42,909 - INFO - primary peer not 146.41.165.3 established to the bgp_router ['10.20.0.25'] 2026-01-26 03:58:47,910 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:58:47,925 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:58:53,938 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:58:59,952 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:59:05,969 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:59:11,985 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:59:17,998 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:59:24,013 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:59:30,029 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:59:36,044 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:59:42,057 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:59:48,074 - ERROR - Not enough BGPaaS sessions seen in control-nodes ['10.20.0.25'] 2026-01-26 03:59:48,075 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-26 03:59:48,075 - INFO - primary peer not 146.41.165.3 established to the bgp_router ['10.20.0.25'] 2026-01-26 03:59:48,076 - INFO - Detaching VMI f0b5a538-6484-44ac-a97c-f72157c0a050 from BGPaaS f8bf2fbe-645b-44d1-84f1-233d9abd0a79 2026-01-26 03:59:48,240 - INFO - Deleting BGPaaS ctest-TestBGPaasZone-86699219-00371394(f8bf2fbe-645b-44d1-84f1-233d9abd0a79) 2026-01-26 03:59:48,281 - DEBUG - Requesting: http://10.0.0.141:8082/bgp-as-a-service/f8bf2fbe-645b-44d1-84f1-233d9abd0a79 2026-01-26 03:59:48,317 - DEBUG - Response Code: 404 2026-01-26 03:59:48,317 - DEBUG - BGPaaS: f8bf2fbe-645b-44d1-84f1-233d9abd0a79 deleted from api server 2026-01-26 03:59:48,317 - INFO - BGPaaS(f8bf2fbe-645b-44d1-84f1-233d9abd0a79): verify_on_cleanup passed 2026-01-26 03:59:48,317 - INFO - Detaching VMI b885a212-837b-4f15-b720-84e49f33165b from BGPaaS 8a463c47-a275-4085-a559-4278480cb1c2 2026-01-26 03:59:48,396 - INFO - Deleting BGPaaS ctest-TestBGPaasZone-86699219-41916923(8a463c47-a275-4085-a559-4278480cb1c2) 2026-01-26 03:59:48,441 - DEBUG - Requesting: http://10.0.0.141:8082/bgp-as-a-service/8a463c47-a275-4085-a559-4278480cb1c2 2026-01-26 03:59:48,448 - DEBUG - Response Code: 404 2026-01-26 03:59:48,448 - DEBUG - BGPaaS: 8a463c47-a275-4085-a559-4278480cb1c2 deleted from api server 2026-01-26 03:59:48,448 - INFO - BGPaaS(8a463c47-a275-4085-a559-4278480cb1c2): verify_on_cleanup passed 2026-01-26 03:59:48,448 - INFO - Deleting Control node zone ctest-test-zone-23761063(ffbad0a0-3793-4ff8-a8d5-fcac3178ecd1) 2026-01-26 03:59:48,600 - INFO - Deleting Control node zone ctest-test-zone-29515895(6e0e4a41-98f3-4048-a898-8985e04101c3) 2026-01-26 03:59:48,752 - INFO - Deleting Control node zone ctest-test-zone-86419409(39c4a8ed-6dc7-433c-9e3d-d94a74c02940) 2026-01-26 03:59:48,907 - INFO - Deleting VM ctest-TestBGPaasZone-86699219-34411818 2026-01-26 03:59:49,017 - INFO - Deleting VM ctest-TestBGPaasZone-86699219-16037342 2026-01-26 03:59:49,092 - INFO - Deleting VM ctest-TestBGPaasZone-86699219-32619934 2026-01-26 03:59:49,161 - INFO - Deleting VN ctest-cnz_vn-19149423 2026-01-26 03:59:49,252 - DEBUG - VN 3d1cef5f-0053-4f94-b786-9b742288d54e still in use: Unable to complete operation on network 3d1cef5f-0053-4f94-b786-9b742288d54e. There are one or more ports still in use on the network. Neutron server returns request_ids: ['req-61b977c2-7ae9-4959-bbcf-0b7ed4a10ff6'] 2026-01-26 03:59:49,253 - WARNING - Deleting VN ctest-cnz_vn-19149423 failed..Will retry 2026-01-26 03:59:51,414 - DEBUG - Response for deleting network () 2026-01-26 03:59:52,682 - ERROR - AssertionError Python 3.9.21: /usr/bin/python3 Mon Jan 26 03:59:48 2026 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/bgpaas/test_bgpaas_zone.py in test_bgp_control_node_zones_from_single_vnf(self=) 145 self.logger.info('executing bgp_control_zone agent restart test') 146 host_ips = [] 147 assert self.basic_control_node_zone_setup('both-zones') 148 for vm in self.vms: 149 assert self.verify_bgpaas_in_control_nodes_and_agent(self.bgpaas_fixtures[cnt],vm) self = self.basic_control_node_zone_setup = > /contrail-test/serial_scripts/bgpaas/test_bgpaas_zone.py in basic_control_node_zone_setup(self=, ctrl_zone='both-zones') 46 self.vn,self.vms[1],self.local_as,self.vip,ctrl_zone)) 47 for vm in self.vms: 48 assert self.verify_bgpaas_in_control_nodes_and_agent(self.bgpaas_fixtures[cnt],vm) 49 cnt += 1 50 msg = 'ping from %s to %s failed'%(self.client_vm.name, self.vip) self = self.verify_bgpaas_in_control_nodes_and_agent = .deco_retry....zones_from_single_vnf[sanity] id=0x7fa9f6d0d820>> self.bgpaas_fixtures = [, ] cnt = 0 vm = 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/bgpaas/test_bgpaas_zone.py", line 147, in test_bgp_control_node_zones_from_single_vnf assert self.basic_control_node_zone_setup('both-zones') File "/contrail-test/serial_scripts/bgpaas/test_bgpaas_zone.py", line 48, in basic_control_node_zone_setup assert self.verify_bgpaas_in_control_nodes_and_agent(self.bgpaas_fixtures[cnt],vm) AssertionError 2026-01-26 03:59:52,682 - DEBUG - Skipping xmpp flap check 2026-01-26 03:59:52,682 - INFO -

2026-01-26 03:59:52,682 - INFO - END TEST : test_bgp_control_node_zones_from_single_vnf : FAILED[0:14:52]

2026-01-26 03:59:52,683 - INFO - -------------------------------------------------------------------------------- 2026-01-26 03:59:53,541 - INFO - Deleted project: ctest-TestBGPaasZone-86699219, ID : dc0ec732-8a67-4a89-811e-fed8a6793120