2025-08-15 10:16:16,021 - INFO - Domain Default found not creating 2025-08-15 10:16:16,138 - INFO - Project ctest-TestRP-20757291 not found, creating it 2025-08-15 10:16:16,643 - INFO - Created Project:ctest-TestRP-20757291, ID : 255f7da2-d533-4c2e-a2b5-3180054bb83d 2025-08-15 10:16:18,033 - DEBUG - Services list from nova: [, , , ] 2025-08-15 10:16:18,033 - DEBUG - Hosts: {'nova': ['an-jenkins-deploy-platform-ansible-os-3861-2', 'an-jenkins-deploy-platform-ansible-os-3861-1']} 2025-08-15 10:16:18,035 - INFO - ================================================================================ 2025-08-15 10:16:18,035 - INFO - STARTING TEST : test_rp_interface 2025-08-15 10:16:18,036 - INFO - TEST DESCRIPTION : 1. Create a routing policy with interface match. 2. Launch VMs. 3. Attach policy to VN and confirm if policy takes hold. 2025-08-15 10:16:19,311 - DEBUG - Nothing to compare xmpp stats {'10.0.0.241': {'10.20.0.14': '0', '10.20.0.254': '0'}, '10.0.0.242': {'10.20.0.254': '0', '10.20.0.25': '1'}} with 2025-08-15 10:16:19,311 - INFO - Initial checks done. Running the testcase now 2025-08-15 10:16:19,311 - INFO - 2025-08-15 10:16:19,966 - DEBUG - Response for create_network : {'network': {'id': '688ab3dd-56c8-477d-8dd5-b7690fb6f0fb', 'name': 'ctest-bgpaas_vn-68845975', 'tenant_id': '255f7da2d5334c2ea2b53180054bb83d', 'project_id': '255f7da2d5334c2ea2b53180054bb83d', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRP-20757291', 'ctest-bgpaas_vn-68845975'], 'port_security_enabled': True, 'description': ''}} 2025-08-15 10:16:20,203 - DEBUG - Response for create_subnet : {'subnet': {'id': '1cd5af53-fcf6-44df-9812-e7f7d56fb5b9', 'name': '', 'tenant_id': '255f7da2d5334c2ea2b53180054bb83d', 'network_id': '688ab3dd-56c8-477d-8dd5-b7690fb6f0fb', 'ip_version': 4, 'cidr': '77.245.42.192/26', 'allocation_pools': [{'start': '77.245.42.194', 'end': '77.245.42.254'}], 'gateway_ip': '77.245.42.193', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '77.245.42.194', 'tags': [], 'project_id': '255f7da2d5334c2ea2b53180054bb83d'}} 2025-08-15 10:16:20,223 - INFO - Created VN ctest-bgpaas_vn-68845975 2025-08-15 10:16:20,234 - DEBUG - VN ctest-bgpaas_vn-68845975 UUID is 688ab3dd-56c8-477d-8dd5-b7690fb6f0fb 2025-08-15 10:16:20,776 - DEBUG - Response for create_network : {'network': {'id': '7225d1de-41d7-4107-8025-0eb04f2612a2', 'name': 'ctest-bgpaas_vn-98924803', 'tenant_id': '255f7da2d5334c2ea2b53180054bb83d', 'project_id': '255f7da2d5334c2ea2b53180054bb83d', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRP-20757291', 'ctest-bgpaas_vn-98924803'], 'port_security_enabled': True, 'description': ''}} 2025-08-15 10:16:20,994 - DEBUG - Response for create_subnet : {'subnet': {'id': '52bab9b7-e59e-4083-8dfa-7a1ae2efc976', 'name': '', 'tenant_id': '255f7da2d5334c2ea2b53180054bb83d', 'network_id': '7225d1de-41d7-4107-8025-0eb04f2612a2', 'ip_version': 4, 'cidr': '78.79.37.0/26', 'allocation_pools': [{'start': '78.79.37.2', 'end': '78.79.37.62'}], 'gateway_ip': '78.79.37.1', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '78.79.37.2', 'tags': [], 'project_id': '255f7da2d5334c2ea2b53180054bb83d'}} 2025-08-15 10:16:21,017 - INFO - Created VN ctest-bgpaas_vn-98924803 2025-08-15 10:16:21,030 - DEBUG - VN ctest-bgpaas_vn-98924803 UUID is 7225d1de-41d7-4107-8025-0eb04f2612a2 2025-08-15 10:16:22,332 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-3861-2), Zone: (nova:an-jenkins-deploy-platform-ansible-os-3861-2) 2025-08-15 10:16:23,551 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-3861-1), Zone: (nova:an-jenkins-deploy-platform-ansible-os-3861-1) 2025-08-15 10:16:23,551 - INFO - Waiting for VM test_vm to be up.. 2025-08-15 10:16:23,626 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2025-08-15 10:16:28,698 - DEBUG - VM is in ACTIVE state now 2025-08-15 10:16:28,698 - INFO - VM name : test_vm 2025-08-15 10:16:28,774 - DEBUG - VM test_vm ID is 7ecdd56c-e61f-4ea7-a69e-789c17495df5 2025-08-15 10:16:28,795 - DEBUG - VM test_vm launched on Node an-jenkins-deploy-platform-ansible-os-3861-2 2025-08-15 10:16:28,869 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine/7ecdd56c-e61f-4ea7-a69e-789c17495df5 2025-08-15 10:16:29,169 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine/7ecdd56c-e61f-4ea7-a69e-789c17495df5 2025-08-15 10:16:29,201 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine-interface/a688d0ff-b6c2-448a-a5bf-9b606bee27b0 2025-08-15 10:16:32,368 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1020ms') 2025-08-15 10:16:32,368 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM test_vm failed! 2025-08-15 10:16:32,384 - DEBUG - Gateway for vn default-domain:ctest-TestRP-20757291:ctest-bgpaas_vn-68845975 is 77.245.42.193 and allocation pool is NOT set 2025-08-15 10:16:34,452 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n64 bytes from 169.254.0.3: icmp_seq=1 ttl=63 time=3.99 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=1.05 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.049/2.519/3.990/1.470 ms') 2025-08-15 10:16:34,453 - INFO - Ping to Metadata IP 169.254.0.3 of VM test_vm passed 2025-08-15 10:16:34,519 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-15 10:16:34,519 - DEBUG - Waiting to SSH to VM test_vm, IP 77.245.42.195, Port 22 2025-08-15 10:16:34,585 - DEBUG - Error on ssh to cirros@169.254.0.3:22, result: /bin/bash: connect: Connection refused /bin/bash: line 1: /dev/tcp/169.254.0.3/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.3/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.3/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''} 2025-08-15 10:16:34,656 - DEBUG - VM test_vm is NOT ready for SSH connections, VM status: ACTIVE 2025-08-15 10:16:39,657 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-15 10:16:39,658 - DEBUG - Waiting to SSH to VM test_vm, IP 77.245.42.195, Port 22 2025-08-15 10:16:39,829 - DEBUG - VM test_vm is ready for SSH connections 2025-08-15 10:16:39,829 - INFO - Waiting for VM test2_vm to be up.. 2025-08-15 10:16:39,901 - DEBUG - VM is in ACTIVE state now 2025-08-15 10:16:39,901 - INFO - VM name : test2_vm 2025-08-15 10:16:39,981 - DEBUG - VM test2_vm ID is c2b0e7bd-97ff-4dc4-9100-c8efe18d7d4d 2025-08-15 10:16:39,981 - DEBUG - VM test2_vm launched on Node an-jenkins-deploy-platform-ansible-os-3861-1 2025-08-15 10:16:40,060 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine/c2b0e7bd-97ff-4dc4-9100-c8efe18d7d4d 2025-08-15 10:16:40,068 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine-interface/b4bbb4e3-b837-4ace-a3b8-505f3cef9adc 2025-08-15 10:16:40,082 - WARNING - VMI tapb4bbb4e3-b8 status is not active, it is Inactive < vn-null vrf-null ipv4_inactive ipv6_inactive l2_inactive > 2025-08-15 10:16:40,150 - DEBUG - VM test2_vm does not seem to be fully up 2025-08-15 10:16:40,498 - DEBUG - Console output: [ 0.000000] Initializing cgroup subsys cpuset [ 0.000000] Initializing cgroup subsys cpu [ 0.000000] Linux version 3.0.0-12-virtual (buildd@crested) (gcc version 4.6.1 (Ubuntu/Linaro 4.6.1-9ubuntu3) ) #20-Ubuntu SMP Fri Oct 7 18:19:02 UTC 2011 (Ubuntu 3.0.0-12.20-virtual 3.0.4) [ 0.000000] Command line: LABEL=cirros-rootfs ro console=tty0 console=ttyS0 console=hvc0 [ 0.000000] KERNEL supported cpus: [ 0.000000] Intel GenuineIntel [ 0.000000] AMD AuthenticAMD [ 0.000000] Centaur CentaurHauls [ 0.000000] BIOS-provided physical RAM map: [ 0.000000] BIOS-e820: 0000000000000000 - 000000000009fc00 (usable) [ 0.000000] BIOS-e820: 000000000009fc00 - 00000000000a0000 (reserved) [ 0.000000] BIOS-e820: 00000000000f0000 - 0000000000100000 (reserved) [ 0.000000] BIOS-e820: 0000000000100000 - 000000003ffdb000 (usable) [ 0.000000] BIOS-e820: 000000003ffdb000 - 0000000040000000 (reserved) [ 0.000000] BIOS-e820: 00000000fffc0000 - 0000000100000000 (reserved) [ 0.000000] NX (Execute Disable) protection: active [ 0.000000] DMI 2.8 present. [ 0.000000] No AGP bridge found [ 0.000000] last_pfn = 0x3ffdb max_arch_pfn = 0x400000000 [ 0.000000] x86 PAT enabled: cpu 0, old 0x7040600070406, new 0x7010600070106 [ 0.000000] found SMP MP-table at [ffff8800000f5b30] f5b30 [ 0.000000] Using GB pages for direct mapping [ 0.000000] init_memory_mapping: 0000000000000000-000000003ffdb000 [ 0.000000] RAMDISK: 37dfc000 - 37ff0000 [ 0.000000] ACPI: RSDP 00000000000f5900 00014 (v00 BOCHS ) [ 0.000000] ACPI: RSDT 000000003ffe17da 00030 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACP 000000003ffe16c6 00074 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: DSDT 000000003ffe0040 01686 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACS 000000003ffe0000 00040 [ 0.000000] ACPI: APIC 000000003ffe173a 00078 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: WAET 000000003ffe17b2 00028 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] No NUMA configuration found [ 0.000000] Faking a node at 0000000000000000-000000003ffdb000 [ 0.000000] Initmem setup node 0 0000000000000000-000000003ffdb000 [ 0.000000] NODE_DATA [000000003ffd3000 - 000000003ffd7fff] [ 0.000000] Zone PFN ranges: [ 0.000000] DMA 0x00000010 -> 0x00001000 [ 0.000000] DMA32 0x00001000 -> 0x00100000 [ 0.000000] Normal empty [ 0.000000] Movable zone start PFN for each node [ 0.000000] early_node_map[2] active PFN ranges [ 0.000000] 0: 0x00000010 -> 0x0000009f [ 0.000000] 0: 0x00000100 -> 0x0003ffdb [ 0.000000] ACPI: PM-Timer IO Port: 0x608 [ 0.000000] ACPI: LAPIC (acpi_id[0x00] lapic_id[0x00] enabled) [ 0.000000] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1]) [ 0.000000] ACPI: IOAPIC (id[0x00] address[0xfec00000] gsi_base[0]) [ 0.000000] IOAPIC[0]: apic_id 0, version 32, address 0xfec00000, GSI 0-23 [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level) [ 0.000000] Using ACPI (MADT) for SMP configuration information [ 0.000000] SMP: Allowing 1 CPUs, 0 hotplug CPUs [ 0.000000] PM: Registered nosave memory: 000000000009f000 - 00000000000a0000 [ 0.000000] PM: Registered nosave memory: 00000000000a0000 - 00000000000f0000 [ 0.000000] PM: Registered nosave memory: 00000000000f0000 - 0000000000100000 [ 0.000000] Allocating PCI resources starting at 40000000 (gap: 40000000:bffc0000) [ 0.000000] Booting paravirtualized kernel on bare hardware [ 0.000000] setup_percpu: NR_CPUS:64 nr_cpumask_bits:64 nr_cpu_ids:1 nr_node_ids:1 [ 0.000000] PERCPU: Embedded 27 pages/cpu @ffff88003fc00000 s79296 r8192 d23104 u2097152 [ 0.000000] Built 1 zonelists in Node order, mobility grouping on. Total pages: 258405 [ 0.000000] Policy zone: DMA32 [ 0.000000] Kernel command line: LABEL=cirros-rootfs ro console=tty0 console=ttyS0 console=hvc0 [ 0.000000] PID hash table entries: 4096 (order: 3, 32768 bytes) [ 0.000000] xsave/xrstor: enabled xstate_bv 0x3, cntxt size 0x240 [ 0.000000] Checking aperture... [ 0.000000] No AGP bridge found [ 0.000000] Memory: 1015852k/1048428k available (6206k kernel code, 452k absent, 32124k reserved, 6907k data, 900k init) [ 0.000000] SLUB: Genslabs=15, HWalign=64, Order=0-3, MinObjects=0, CPUs=1, Nodes=1 [ 0.000000] Hierarchical RCU implementation. [ 0.000000] RCU dyntick-idle grace-period acceleration is enabled. [ 0.000000] NR_IRQS:4352 nr_irqs:256 16 [ 0.000000] Console: colour VGA+ 80x25 [ 0.000000] console [tty0] enabled [ 0.000000] console [ttyS0] enabled [ 0.000000] allocated 8388608 bytes of page_cgroup [ 0.000000] please try 'cgroup_disable=memory' option if you don't want memory cgroups [ 0.000000] Fast TSC calibration failed [ 0.000000] TSC: Unable to calibrate against PIT [ 0.000000] TSC: using PMTIMER reference calibration [ 0.000000] Detected 2294.466 MHz processor. [ 0.028806] Calibrating delay loop (skipped), value calculated using timer frequency.. 4588.93 BogoMIPS (lpj=9177864) [ 0.029723] pid_max: default: 32768 minimum: 301 [ 0.034510] Security Framework initialized [ 0.038958] AppArmor: AppArmor initialized [ 0.039222] Yama: becoming mindful. [ 0.045963] Dentry cache hash table entries: 131072 (order: 8, 1048576 bytes) [ 0.048444] Inode-cache hash table entries: 65536 (order: 7, 524288 bytes) [ 0.049688] Mount-cache hash table entries: 256 [ 0.059837] Initializing cgroup subsys cpuacct [ 0.060270] Initializing cgroup subsys memory [ 0.061229] Initializing cgroup subsys devices [ 0.061528] Initializing cgroup subsys freezer [ 0.061770] Initializing cgroup subsys net_cls [ 0.062017] Initializing cgroup subsys blkio [ 0.062275] Initializing cgroup subsys perf_event [ 0.067202] mce: CPU supports 10 MCE banks [ 0.068855] using AMD E400 aware idle routine [ 0.071713] SMP alternatives: switching to UP code [ 0.288547] Freeing SMP alternatives: 24k freed [ 0.289322] ACPI: Core revision 20110413 [ 0.316331] ftrace: allocating 26075 entries in 103 pages [ 0.343837] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1 [ 0.385195] CPU0: AMD Opteron 23xx (Gen 3 Class Opteron) stepping 03 [ 0.388023] Performance Events: Broken PMU hardware detected, using software events only. [ 0.395545] Brought up 1 CPUs [ 0.395883] Total of 1 processors activated (4588.93 BogoMIPS). [ 0.405713] devtmpfs: initialized [ 0.427860] print_constraints: dummy: [ 0.428679] Time: 10:16:26 Date: 08/15/25 [ 0.430398] NET: Registered protocol family 16 [ 0.435764] Extended Config Space enabled on 0 nodes [ 0.436668] ACPI: bus type pci registered [ 0.439181] PCI: Using configuration type 1 for base access [ 0.439439] PCI: Using configuration type 1 for extended access [ 0.455077] bio: create slab at 0 [ 0.482032] ACPI: Interpreter enabled [ 0.482288] ACPI: (supports S0 S5) [ 0.483111] ACPI: Using IOAPIC for interrupt routing [ 0.515301] ACPI: No dock devices found. [ 0.515621] HEST: Table not found. [ 0.515919] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug [ 0.518333] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) [ 0.520930] pci_root PNP0A03:00: host bridge window [io 0x0000-0x0cf7] [ 0.521217] pci_root PNP0A03:00: host bridge window [io 0x0d00-0xffff] [ 0.521496] pci_root PNP0A03:00: host bridge window [mem 0x000a0000-0x000bffff] [ 0.521774] pci_root PNP0A03:00: host bridge window [mem 0x40000000-0xfebfffff] [ 0.522040] pci_root PNP0A03:00: host bridge window [mem 0x100000000-0x17fffffff] [ 0.533658] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI [ 0.534027] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB [ 1.074247] pci0000:00: Requesting ACPI _OSC control (0x1d) [ 1.074704] pci0000:00: ACPI _OSC request failed (AE_NOT_FOUND), returned control mask: 0x1d [ 1.075033] ACPI _OSC control for PCIe not granted, disabling ASPM [ 1.104649] ACPI: PCI Interrupt Link [LNKA] (IRQs 5 *10 11) [ 1.105716] ACPI: PCI Interrupt Link [LNKB] (IRQs 5 *10 11) [ 1.106413] ACPI: PCI Interrupt Link [LNKC] (IRQs 5 10 *11) [ 1.107095] ACPI: PCI Interrupt Link [LNKD] (IRQs 5 10 *11) [ 1.107565] ACPI: PCI Interrupt Link [LNKS] (IRQs *9) [ 1.113069] vgaarb: device added: PCI:0000:00:02.0,decodes=io+mem,owns=io+mem,locks=none [ 1.113467] vgaarb: loaded [ 1.113616] vgaarb: bridge control possible 0000:00:02.0 [ 1.117291] SCSI subsystem initialized [ 1.119417] usbcore: registered new interface driver usbfs [ 1.120143] usbcore: registered new interface driver hub [ 1.120795] usbcore: registered new device driver usb [ 1.123201] PCI: Using ACPI for IRQ routing [ 1.131373] NetLabel: Initializing [ 1.131585] NetLabel: domain hash size = 128 [ 1.131755] NetLabel: protocols = UNLABELED CIPSOv4 [ 1.133198] NetLabel: unlabeled traffic allowed by default [ 1.194241] AppArmor: AppArmor Filesystem Enabled [ 1.195553] pnp: PnP ACPI init [ 1.196005] ACPI: bus type pnp registered [ 1.203466] pnp: PnP ACPI: found 9 devices [ 1.203736] ACPI: ACPI bus type pnp unregistered [ 1.225661] Switching to clocksource acpi_pm [ 1.227581] Switched to NOHz mode on CPU #0 [ 1.227581] NET: Registered protocol family 2 [ 1.231401] IP route cache hash table entries: 32768 (order: 6, 262144 bytes) [ 1.240663] TCP established hash table entries: 131072 (order: 9, 2097152 bytes) [ 1.245332] TCP bind hash table entries: 65536 (order: 8, 1048576 bytes) [ 1.247418] TCP: Hash tables configured (established 131072 bind 65536) [ 1.247807] TCP reno registered [ 1.248224] UDP hash table entries: 512 (order: 2, 16384 bytes) [ 1.248713] UDP-Lite hash table entries: 512 (order: 2, 16384 bytes) [ 1.250824] NET: Registered protocol family 1 [ 1.251324] pci 0000:00:00.0: Limiting direct PCI/PCI transfers [ 1.251643] pci 0000:00:01.0: PIIX3: Enabling Passive Release [ 1.252239] pci 0000:00:01.0: Activating ISA DMA hang workarounds [ 1.264390] Trying to unpack rootfs image as initramfs... [ 1.285436] audit: initializing netlink socket (disabled) [ 1.286520] type=2000 audit(1755252987.280:1): initialized [ 1.399723] HugeTLB registered 2 MB page size, pre-allocated 0 pages [ 1.441660] VFS: Disk quotas dquot_6.5.2 [ 1.442385] Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 1.457127] fuse init (API version 7.16) [ 1.458641] msgmni has been set to 1984 [ 1.478842] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 253) [ 1.484479] io scheduler noop registered [ 1.484774] io scheduler deadline registered (default) [ 1.485403] io scheduler cfq registered [ 1.487258] pci_hotplug: PCI Hot Plug PCI Core version: 0.5 [ 1.488834] pciehp: PCI Express Hot Plug Controller Driver version: 0.4 [ 1.492178] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 [ 1.493166] ACPI: Power Button [PWRF] [ 1.512418] ERST: Table is not found! [ 1.516268] ACPI: PCI Interrupt Link [LNKC] enabled at IRQ 11 [ 1.516735] virtio-pci 0000:00:03.0: PCI INT A -> Link[LNKC] -> GSI 11 (level, high) -> IRQ 11 [ 1.519427] ACPI: PCI Interrupt Link [LNKD] enabled at IRQ 10 [ 1.519736] virtio-pci 0000:00:04.0: PCI INT A -> Link[LNKD] -> GSI 10 (level, high) -> IRQ 10 [ 1.529159] ACPI: PCI Interrupt Link [LNKA] enabled at IRQ 10 [ 1.529501] virtio-pci 0000:00:05.0: PCI INT A -> Link[LNKA] -> GSI 10 (level, high) -> IRQ 10 [ 1.530889] ACPI: PCI Interrupt Link [LNKB] enabled at IRQ 11 [ 1.531136] virtio-pci 0000:00:06.0: PCI INT A -> Link[LNKB] -> GSI 11 (level, high) -> IRQ 11 [ 1.532512] virtio-pci 0000:00:07.0: PCI INT A -> Link[LNKC] -> GSI 11 (level, high) -> IRQ 11 [ 1.534794] Serial: 8250/16550 driver, 32 ports, IRQ sharing enabled [ 1.558136] serial8250: ttyS0 at I/O 0x3f8 (irq = 4) is a 16550A [ 1.591016] 00:01: ttyS0 at I/O 0x3f8 (irq = 4) is a 16550A [ 1.593697] Linux agpgart interface v0.103 [ 1.606870] brd: module loaded [ 1.611735] loop: module loaded [ 1.714950] Freeing initrd memory: 2000k freed [ 1.723337] vda: vda1 [ 1.739371] scsi0 : ata_piix [ 1.741034] scsi1 : ata_piix [ 1.741749] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc100 irq 14 [ 1.742040] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc108 irq 15 [ 1.747036] Fixed MDIO Bus: probed [ 1.747766] PPP generic driver version 2.4.2 [ 1.748784] tun: Universal TUN/TAP device driver, 1.6 [ 1.749011] tun: (C) 1999-2004 Max Krasnyansky [ 1.756159] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver [ 1.757071] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver [ 1.757488] uhci_hcd: USB Universal Host Controller Interface driver [ 1.758003] uhci_hcd 0000:00:01.2: PCI INT D -> Link[LNKD] -> GSI 10 (level, high) -> IRQ 10 [ 1.758652] uhci_hcd 0000:00:01.2: UHCI Host Controller [ 1.759757] uhci_hcd 0000:00:01.2: new USB bus registered, assigned bus number 1 [ 1.761158] uhci_hcd 0000:00:01.2: irq 10, io base 0x0000c080 [ 1.769039] hub 1-0:1.0: USB hub found [ 1.769675] hub 1-0:1.0: 2 ports detected [ 1.773029] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 [ 1.776038] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 1.776038] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 1.778094] mousedev: PS/2 mouse device common for all mice [ 1.779314] rtc_cmos 00:05: RTC can wake from S4 [ 1.781628] rtc_cmos 00:05: rtc core: registered rtc_cmos as rtc0 [ 1.782258] rtc0: alarms up to one day, y3k, 242 bytes nvram [ 1.783339] device-mapper: uevent: version 1.0.3 [ 1.784408] device-mapper: ioctl: 4.20.0-ioctl (2011-02-02) initialised: dm-devel@redhat.com [ 1.785547] cpuidle: using governor ladder [ 1.785817] cpuidle: using governor menu [ 1.785988] EFI Variables Facility v0.08 2004-May-17 [ 1.788371] TCP cubic registered [ 1.789568] NET: Registered protocol family 10 [ 1.799156] NET: Registered protocol family 17 [ 1.799766] Registering the dns_resolver key type [ 1.802403] registered taskstats version 1 [ 1.810483] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1 [ 1.963431] Magic number: 5:917:274 [ 1.963922] tty tty11: hash matches [ 1.964914] rtc_cmos 00:05: setting system clock to 2025-08-15 10:16:28 UTC (1755252988) [ 1.966645] BIOS EDD facility v0.16 2004-Jun-25, 0 devices found [ 1.966910] EDD information not available. [ 1.985107] Freeing unused kernel memory: 900k freed [ 2.021151] Write protecting the kernel read-only data: 12288k [ 2.056643] Freeing unused kernel memory: 1968k freed [ 2.082994] Freeing unused kernel memory: 1368k freed [ 2.147106] usb 1-1: new full speed USB device number 2 using uhci_hcd info: initramfs: up at 2.19 GROWROOT: CHANGED: partition=1 start=16065 old: size=64260 end=80325 new: size=2072385,end=2088450 info: initramfs loading root from /dev/vda1 info: /etc/init.d/rc.sysinit: up at 3.87 [ 3.900458] EXT3-fs (vda1): warning: checktime reached, running e2fsck is recommended Starting logging: OK Initializing random number generator... done. Starting network... udhcpc (v1.18.5) started Sending discover... Sending select for 78.79.37.3... Lease of 78.79.37.3 obtained, lease time 10 cloud-setup: checking http://169.254.169.254/2009-04-04/meta-data/instance-id wget: can't connect to remote host (169.254.169.254): Network is unreachable cloud-setup: failed 1/30: up 5.93. request failed wget: can't connect to remote host (169.254.169.254): Network is unreachable cloud-setup: failed 2/30: up 6.97. request failed wget: can't connect to remote host (169.254.169.254): Network is unreachable cloud-setup: failed 3/30: up 8.03. request failed wget: can't connect to remote host (169.254.169.254): Network is unreachable cloud-setup: failed 4/30: up 9.07. request failed wget: can't connect to remote host (169.254.169.254): Network is unreachable cloud-setup: failed 5/30: up 10.12. request failed wget: can't connect to remote host (169.254.169.254): Network is unreachable cloud-setup: failed 6/30: up 11.16. request failed wget: can't connect to remote host (169.254.169.254): Network is unreachable cloud-setup: failed 7/30: up 12.21. request failed wget: can't connect to remote host (169.254.169.254): Network is unreachable cloud-setup: failed 8/30: up 13.25. request failed 2025-08-15 10:16:40,498 - ERROR - VM test2_vm does not seem to be fully up. Check logs 2025-08-15 10:16:40,605 - DEBUG - [ 0.000000] Initializing cgroup subsys cpuset [ 0.000000] Initializing cgroup subsys cpu [ 0.000000] Linux version 3.0.0-12-virtual (buildd@crested) (gcc version 4.6.1 (Ubuntu/Linaro 4.6.1-9ubuntu3) ) #20-Ubuntu SMP Fri Oct 7 18:19:02 UTC 2011 (Ubuntu 3.0.0-12.20-virtual 3.0.4) [ 0.000000] Command line: LABEL=cirros-rootfs ro console=tty0 console=ttyS0 console=hvc0 [ 0.000000] KERNEL supported cpus: [ 0.000000] Intel GenuineIntel [ 0.000000] AMD AuthenticAMD [ 0.000000] Centaur CentaurHauls [ 0.000000] BIOS-provided physical RAM map: [ 0.000000] BIOS-e820: 0000000000000000 - 000000000009fc00 (usable) [ 0.000000] BIOS-e820: 000000000009fc00 - 00000000000a0000 (reserved) [ 0.000000] BIOS-e820: 00000000000f0000 - 0000000000100000 (reserved) [ 0.000000] BIOS-e820: 0000000000100000 - 000000003ffdb000 (usable) [ 0.000000] BIOS-e820: 000000003ffdb000 - 0000000040000000 (reserved) [ 0.000000] BIOS-e820: 00000000fffc0000 - 0000000100000000 (reserved) [ 0.000000] NX (Execute Disable) protection: active [ 0.000000] DMI 2.8 present. [ 0.000000] No AGP bridge found [ 0.000000] last_pfn = 0x3ffdb max_arch_pfn = 0x400000000 [ 0.000000] x86 PAT enabled: cpu 0, old 0x7040600070406, new 0x7010600070106 [ 0.000000] found SMP MP-table at [ffff8800000f5b30] f5b30 [ 0.000000] Using GB pages for direct mapping [ 0.000000] init_memory_mapping: 0000000000000000-000000003ffdb000 [ 0.000000] RAMDISK: 37dfc000 - 37ff0000 [ 0.000000] ACPI: RSDP 00000000000f5900 00014 (v00 BOCHS ) [ 0.000000] ACPI: RSDT 000000003ffe17da 00030 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACP 000000003ffe16c6 00074 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: DSDT 000000003ffe0040 01686 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: FACS 000000003ffe0000 00040 [ 0.000000] ACPI: APIC 000000003ffe173a 00078 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] ACPI: WAET 000000003ffe17b2 00028 (v01 BOCHS BXPC 00000001 BXPC 00000001) [ 0.000000] No NUMA configuration found [ 0.000000] Faking a node at 0000000000000000-000000003ffdb000 [ 0.000000] Initmem setup node 0 0000000000000000-000000003ffdb000 [ 0.000000] NODE_DATA [000000003ffd3000 - 000000003ffd7fff] [ 0.000000] Zone PFN ranges: [ 0.000000] DMA 0x00000010 -> 0x00001000 [ 0.000000] DMA32 0x00001000 -> 0x00100000 [ 0.000000] Normal empty [ 0.000000] Movable zone start PFN for each node [ 0.000000] early_node_map[2] active PFN ranges [ 0.000000] 0: 0x00000010 -> 0x0000009f [ 0.000000] 0: 0x00000100 -> 0x0003ffdb [ 0.000000] ACPI: PM-Timer IO Port: 0x608 [ 0.000000] ACPI: LAPIC (acpi_id[0x00] lapic_id[0x00] enabled) [ 0.000000] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1]) [ 0.000000] ACPI: IOAPIC (id[0x00] address[0xfec00000] gsi_base[0]) [ 0.000000] IOAPIC[0]: apic_id 0, version 32, address 0xfec00000, GSI 0-23 [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level) [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level) [ 0.000000] Using ACPI (MADT) for SMP configuration information [ 0.000000] SMP: Allowing 1 CPUs, 0 hotplug CPUs [ 0.000000] PM: Registered nosave memory: 000000000009f000 - 00000000000a0000 [ 0.000000] PM: Registered nosave memory: 00000000000a0000 - 00000000000f0000 [ 0.000000] PM: Registered nosave memory: 00000000000f0000 - 0000000000100000 [ 0.000000] Allocating PCI resources starting at 40000000 (gap: 40000000:bffc0000) [ 0.000000] Booting paravirtualized kernel on bare hardware [ 0.000000] setup_percpu: NR_CPUS:64 nr_cpumask_bits:64 nr_cpu_ids:1 nr_node_ids:1 [ 0.000000] PERCPU: Embedded 27 pages/cpu @ffff88003fc00000 s79296 r8192 d23104 u2097152 [ 0.000000] Built 1 zonelists in Node order, mobility grouping on. Total pages: 258405 [ 0.000000] Policy zone: DMA32 [ 0.000000] Kernel command line: LABEL=cirros-rootfs ro console=tty0 console=ttyS0 console=hvc0 [ 0.000000] PID hash table entries: 4096 (order: 3, 32768 bytes) [ 0.000000] xsave/xrstor: enabled xstate_bv 0x3, cntxt size 0x240 [ 0.000000] Checking aperture... [ 0.000000] No AGP bridge found [ 0.000000] Memory: 1015852k/1048428k available (6206k kernel code, 452k absent, 32124k reserved, 6907k data, 900k init) [ 0.000000] SLUB: Genslabs=15, HWalign=64, Order=0-3, MinObjects=0, CPUs=1, Nodes=1 [ 0.000000] Hierarchical RCU implementation. [ 0.000000] RCU dyntick-idle grace-period acceleration is enabled. [ 0.000000] NR_IRQS:4352 nr_irqs:256 16 [ 0.000000] Console: colour VGA+ 80x25 [ 0.000000] console [tty0] enabled [ 0.000000] console [ttyS0] enabled [ 0.000000] allocated 8388608 bytes of page_cgroup [ 0.000000] please try 'cgroup_disable=memory' option if you don't want memory cgroups [ 0.000000] Fast TSC calibration failed [ 0.000000] TSC: Unable to calibrate against PIT [ 0.000000] TSC: using PMTIMER reference calibration [ 0.000000] Detected 2294.466 MHz processor. [ 0.028806] Calibrating delay loop (skipped), value calculated using timer frequency.. 4588.93 BogoMIPS (lpj=9177864) [ 0.029723] pid_max: default: 32768 minimum: 301 [ 0.034510] Security Framework initialized [ 0.038958] AppArmor: AppArmor initialized [ 0.039222] Yama: becoming mindful. [ 0.045963] Dentry cache hash table entries: 131072 (order: 8, 1048576 bytes) [ 0.048444] Inode-cache hash table entries: 65536 (order: 7, 524288 bytes) [ 0.049688] Mount-cache hash table entries: 256 [ 0.059837] Initializing cgroup subsys cpuacct [ 0.060270] Initializing cgroup subsys memory [ 0.061229] Initializing cgroup subsys devices [ 0.061528] Initializing cgroup subsys freezer [ 0.061770] Initializing cgroup subsys net_cls [ 0.062017] Initializing cgroup subsys blkio [ 0.062275] Initializing cgroup subsys perf_event [ 0.067202] mce: CPU supports 10 MCE banks [ 0.068855] using AMD E400 aware idle routine [ 0.071713] SMP alternatives: switching to UP code [ 0.288547] Freeing SMP alternatives: 24k freed [ 0.289322] ACPI: Core revision 20110413 [ 0.316331] ftrace: allocating 26075 entries in 103 pages [ 0.343837] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1 [ 0.385195] CPU0: AMD Opteron 23xx (Gen 3 Class Opteron) stepping 03 [ 0.388023] Performance Events: Broken PMU hardware detected, using software events only. [ 0.395545] Brought up 1 CPUs [ 0.395883] Total of 1 processors activated (4588.93 BogoMIPS). [ 0.405713] devtmpfs: initialized [ 0.427860] print_constraints: dummy: [ 0.428679] Time: 10:16:26 Date: 08/15/25 [ 0.430398] NET: Registered protocol family 16 [ 0.435764] Extended Config Space enabled on 0 nodes [ 0.436668] ACPI: bus type pci registered [ 0.439181] PCI: Using configuration type 1 for base access [ 0.439439] PCI: Using configuration type 1 for extended access [ 0.455077] bio: create slab at 0 [ 0.482032] ACPI: Interpreter enabled [ 0.482288] ACPI: (supports S0 S5) [ 0.483111] ACPI: Using IOAPIC for interrupt routing [ 0.515301] ACPI: No dock devices found. [ 0.515621] HEST: Table not found. [ 0.515919] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug [ 0.518333] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) [ 0.520930] pci_root PNP0A03:00: host bridge window [io 0x0000-0x0cf7] [ 0.521217] pci_root PNP0A03:00: host bridge window [io 0x0d00-0xffff] [ 0.521496] pci_root PNP0A03:00: host bridge window [mem 0x000a0000-0x000bffff] [ 0.521774] pci_root PNP0A03:00: host bridge window [mem 0x40000000-0xfebfffff] [ 0.522040] pci_root PNP0A03:00: host bridge window [mem 0x100000000-0x17fffffff] [ 0.533658] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI [ 0.534027] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB [ 1.074247] pci0000:00: Requesting ACPI _OSC control (0x1d) [ 1.074704] pci0000:00: ACPI _OSC request failed (AE_NOT_FOUND), returned control mask: 0x1d [ 1.075033] ACPI _OSC control for PCIe not granted, disabling ASPM [ 1.104649] ACPI: PCI Interrupt Link [LNKA] (IRQs 5 *10 11) [ 1.105716] ACPI: PCI Interrupt Link [LNKB] (IRQs 5 *10 11) [ 1.106413] ACPI: PCI Interrupt Link [LNKC] (IRQs 5 10 *11) [ 1.107095] ACPI: PCI Interrupt Link [LNKD] (IRQs 5 10 *11) [ 1.107565] ACPI: PCI Interrupt Link [LNKS] (IRQs *9) [ 1.113069] vgaarb: device added: PCI:0000:00:02.0,decodes=io+mem,owns=io+mem,locks=none [ 1.113467] vgaarb: loaded [ 1.113616] vgaarb: bridge control possible 0000:00:02.0 [ 1.117291] SCSI subsystem initialized [ 1.119417] usbcore: registered new interface driver usbfs [ 1.120143] usbcore: registered new interface driver hub [ 1.120795] usbcore: registered new device driver usb [ 1.123201] PCI: Using ACPI for IRQ routing [ 1.131373] NetLabel: Initializing [ 1.131585] NetLabel: domain hash size = 128 [ 1.131755] NetLabel: protocols = UNLABELED CIPSOv4 [ 1.133198] NetLabel: unlabeled traffic allowed by default [ 1.194241] AppArmor: AppArmor Filesystem Enabled [ 1.195553] pnp: PnP ACPI init [ 1.196005] ACPI: bus type pnp registered [ 1.203466] pnp: PnP ACPI: found 9 devices [ 1.203736] ACPI: ACPI bus type pnp unregistered [ 1.225661] Switching to clocksource acpi_pm [ 1.227581] Switched to NOHz mode on CPU #0 [ 1.227581] NET: Registered protocol family 2 [ 1.231401] IP route cache hash table entries: 32768 (order: 6, 262144 bytes) [ 1.240663] TCP established hash table entries: 131072 (order: 9, 2097152 bytes) [ 1.245332] TCP bind hash table entries: 65536 (order: 8, 1048576 bytes) [ 1.247418] TCP: Hash tables configured (established 131072 bind 65536) [ 1.247807] TCP reno registered [ 1.248224] UDP hash table entries: 512 (order: 2, 16384 bytes) [ 1.248713] UDP-Lite hash table entries: 512 (order: 2, 16384 bytes) [ 1.250824] NET: Registered protocol family 1 [ 1.251324] pci 0000:00:00.0: Limiting direct PCI/PCI transfers [ 1.251643] pci 0000:00:01.0: PIIX3: Enabling Passive Release [ 1.252239] pci 0000:00:01.0: Activating ISA DMA hang workarounds [ 1.264390] Trying to unpack rootfs image as initramfs... [ 1.285436] audit: initializing netlink socket (disabled) [ 1.286520] type=2000 audit(1755252987.280:1): initialized [ 1.399723] HugeTLB registered 2 MB page size, pre-allocated 0 pages [ 1.441660] VFS: Disk quotas dquot_6.5.2 [ 1.442385] Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 1.457127] fuse init (API version 7.16) [ 1.458641] msgmni has been set to 1984 [ 1.478842] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 253) [ 1.484479] io scheduler noop registered [ 1.484774] io scheduler deadline registered (default) [ 1.485403] io scheduler cfq registered [ 1.487258] pci_hotplug: PCI Hot Plug PCI Core version: 0.5 [ 1.488834] pciehp: PCI Express Hot Plug Controller Driver version: 0.4 [ 1.492178] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 [ 1.493166] ACPI: Power Button [PWRF] [ 1.512418] ERST: Table is not found! [ 1.516268] ACPI: PCI Interrupt Link [LNKC] enabled at IRQ 11 [ 1.516735] virtio-pci 0000:00:03.0: PCI INT A -> Link[LNKC] -> GSI 11 (level, high) -> IRQ 11 [ 1.519427] ACPI: PCI Interrupt Link [LNKD] enabled at IRQ 10 [ 1.519736] virtio-pci 0000:00:04.0: PCI INT A -> Link[LNKD] -> GSI 10 (level, high) -> IRQ 10 [ 1.529159] ACPI: PCI Interrupt Link [LNKA] enabled at IRQ 10 [ 1.529501] virtio-pci 0000:00:05.0: PCI INT A -> Link[LNKA] -> GSI 10 (level, high) -> IRQ 10 [ 1.530889] ACPI: PCI Interrupt Link [LNKB] enabled at IRQ 11 [ 1.531136] virtio-pci 0000:00:06.0: PCI INT A -> Link[LNKB] -> GSI 11 (level, high) -> IRQ 11 [ 1.532512] virtio-pci 0000:00:07.0: PCI INT A -> Link[LNKC] -> GSI 11 (level, high) -> IRQ 11 [ 1.534794] Serial: 8250/16550 driver, 32 ports, IRQ sharing enabled [ 1.558136] serial8250: ttyS0 at I/O 0x3f8 (irq = 4) is a 16550A [ 1.591016] 00:01: ttyS0 at I/O 0x3f8 (irq = 4) is a 16550A [ 1.593697] Linux agpgart interface v0.103 [ 1.606870] brd: module loaded [ 1.611735] loop: module loaded [ 1.714950] Freeing initrd memory: 2000k freed [ 1.723337] vda: vda1 [ 1.739371] scsi0 : ata_piix [ 1.741034] scsi1 : ata_piix [ 1.741749] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc100 irq 14 [ 1.742040] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc108 irq 15 [ 1.747036] Fixed MDIO Bus: probed [ 1.747766] PPP generic driver version 2.4.2 [ 1.748784] tun: Universal TUN/TAP device driver, 1.6 [ 1.749011] tun: (C) 1999-2004 Max Krasnyansky [ 1.756159] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver [ 1.757071] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver [ 1.757488] uhci_hcd: USB Universal Host Controller Interface driver [ 1.758003] uhci_hcd 0000:00:01.2: PCI INT D -> Link[LNKD] -> GSI 10 (level, high) -> IRQ 10 [ 1.758652] uhci_hcd 0000:00:01.2: UHCI Host Controller [ 1.759757] uhci_hcd 0000:00:01.2: new USB bus registered, assigned bus number 1 [ 1.761158] uhci_hcd 0000:00:01.2: irq 10, io base 0x0000c080 [ 1.769039] hub 1-0:1.0: USB hub found [ 1.769675] hub 1-0:1.0: 2 ports detected [ 1.773029] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12 [ 1.776038] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 1.776038] serio: i8042 AUX port at 0x60,0x64 irq 12 [ 1.778094] mousedev: PS/2 mouse device common for all mice [ 1.779314] rtc_cmos 00:05: RTC can wake from S4 [ 1.781628] rtc_cmos 00:05: rtc core: registered rtc_cmos as rtc0 [ 1.782258] rtc0: alarms up to one day, y3k, 242 bytes nvram [ 1.783339] device-mapper: uevent: version 1.0.3 [ 1.784408] device-mapper: ioctl: 4.20.0-ioctl (2011-02-02) initialised: dm-devel@redhat.com [ 1.785547] cpuidle: using governor ladder [ 1.785817] cpuidle: using governor menu [ 1.785988] EFI Variables Facility v0.08 2004-May-17 [ 1.788371] TCP cubic registered [ 1.789568] NET: Registered protocol family 10 [ 1.799156] NET: Registered protocol family 17 [ 1.799766] Registering the dns_resolver key type [ 1.802403] registered taskstats version 1 [ 1.810483] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1 [ 1.963431] Magic number: 5:917:274 [ 1.963922] tty tty11: hash matches [ 1.964914] rtc_cmos 00:05: setting system clock to 2025-08-15 10:16:28 UTC (1755252988) [ 1.966645] BIOS EDD facility v0.16 2004-Jun-25, 0 devices found [ 1.966910] EDD information not available. [ 1.985107] Freeing unused kernel memory: 900k freed [ 2.021151] Write protecting the kernel read-only data: 12288k [ 2.056643] Freeing unused kernel memory: 1968k freed [ 2.082994] Freeing unused kernel memory: 1368k freed [ 2.147106] usb 1-1: new full speed USB device number 2 using uhci_hcd info: initramfs: up at 2.19 GROWROOT: CHANGED: partition=1 start=16065 old: size=64260 end=80325 new: size=2072385,end=2088450 info: initramfs loading root from /dev/vda1 info: /etc/init.d/rc.sysinit: up at 3.87 [ 3.900458] EXT3-fs (vda1): warning: checktime reached, running e2fsck is recommended Starting logging: OK Initializing random number generator... done. Starting network... udhcpc (v1.18.5) started Sending discover... Sending select for 78.79.37.3... Lease of 78.79.37.3 obtained, lease time 10 cloud-setup: checking http://169.254.169.254/2009-04-04/meta-data/instance-id wget: can't connect to remote host (169.254.169.254): Network is unreachable cloud-setup: failed 1/30: up 5.93. request failed wget: can't connect to remote host (169.254.169.254): Network is unreachable cloud-setup: failed 2/30: up 6.97. request failed wget: can't connect to remote host (169.254.169.254): Network is unreachable cloud-setup: failed 3/30: up 8.03. request failed wget: can't connect to remote host (169.254.169.254): Network is unreachable cloud-setup: failed 4/30: up 9.07. request failed wget: can't connect to remote host (169.254.169.254): Network is unreachable cloud-setup: failed 5/30: up 10.12. request failed wget: can't connect to remote host (169.254.169.254): Network is unreachable cloud-setup: failed 6/30: up 11.16. request failed wget: can't connect to remote host (169.254.169.254): Network is unreachable cloud-setup: failed 7/30: up 12.21. request failed wget: can't connect to remote host (169.254.169.254): Network is unreachable cloud-setup: failed 8/30: up 13.25. request failed 2025-08-15 10:16:40,606 - INFO - Deleting VM test2_vm 2025-08-15 10:16:40,662 - INFO - Deleting VM test_vm 2025-08-15 10:16:40,722 - INFO - Deleting VN ctest-bgpaas_vn-98924803 2025-08-15 10:16:40,764 - DEBUG - VN 7225d1de-41d7-4107-8025-0eb04f2612a2 still in use: Unable to complete operation on network 7225d1de-41d7-4107-8025-0eb04f2612a2. There are one or more ports still in use on the network. Neutron server returns request_ids: ['req-9842eaaa-7473-4bf6-b09f-53ee4501dfcd'] 2025-08-15 10:16:40,764 - WARNING - Deleting VN ctest-bgpaas_vn-98924803 failed..Will retry 2025-08-15 10:16:42,932 - DEBUG - Response for deleting network () 2025-08-15 10:16:42,933 - INFO - Deleting VN ctest-bgpaas_vn-68845975 2025-08-15 10:16:43,122 - DEBUG - Response for deleting network () 2025-08-15 10:16:44,383 - ERROR - AssertionError Python 3.9.21: /usr/bin/python3 Fri Aug 15 10:16:40 2025 A problem occurred in a Python script. Here is the sequence of function calls leading up to the error, in the order they occurred. /contrail-test/tcutils/wrappers.py in wrapper(self=, *args=(), **kwargs={}) 78 log.info('Initial checks done. Running the testcase now') 79 log.info('') 80 result = function(self, *args, **kwargs) 81 if self.inputs.upgrade: 82 pid = os.getpid() result = None function = self = args = () kwargs = {} /contrail-test/scripts/routing_policy/test_routing_policy.py in test_rp_interface(self=) 38 3. Attach policy to VN and confirm if policy takes hold. 39 ''' 40 ret_dict = self.config_basic() 41 vn_fixture = ret_dict['vn_fixture'] 42 test_vm = ret_dict['test_vm'] ret_dict undefined self = self.config_basic = > /contrail-test/scripts/routing_policy/base.py in config_basic(self=) 44 test2_vm = self.create_vm(vn2_fixture, 'test2_vm', image_name='cirros') 45 assert test_vm.wait_till_vm_is_up() 46 assert test2_vm.wait_till_vm_is_up() 47 48 ret_dict = { test2_vm = test2_vm.wait_till_vm_is_up = > 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/scripts/routing_policy/test_routing_policy.py", line 40, in test_rp_interface ret_dict = self.config_basic() File "/contrail-test/scripts/routing_policy/base.py", line 46, in config_basic assert test2_vm.wait_till_vm_is_up() AssertionError 2025-08-15 10:16:44,396 - DEBUG - No XMPP flaps were noticed during the test 2025-08-15 10:16:44,396 - INFO -
2025-08-15 10:16:44,396 - INFO - END TEST : test_rp_interface : FAILED[0:00:26]
2025-08-15 10:16:44,396 - INFO - -------------------------------------------------------------------------------- 2025-08-15 10:16:44,399 - INFO - ================================================================================ 2025-08-15 10:16:44,399 - INFO - STARTING TEST : test_rp_interface_ext_community 2025-08-15 10:16:44,399 - INFO - TEST DESCRIPTION : 1. Create a routing policy with interface match. 2. Launch VMs. 3. Attach policy to VN and confirm if policy takes hold. 2025-08-15 10:16:45,654 - DEBUG - Nothing to compare xmpp stats {'10.0.0.241': {'10.20.0.14': '0', '10.20.0.254': '0'}, '10.0.0.242': {'10.20.0.254': '0', '10.20.0.25': '1'}} with 2025-08-15 10:16:45,654 - INFO - Initial checks done. Running the testcase now 2025-08-15 10:16:45,654 - INFO - 2025-08-15 10:16:45,913 - DEBUG - Response for create_network : {'network': {'id': 'b80afd5a-1413-4a2c-97c2-50a8b30caca1', 'name': 'ctest-bgpaas_vn-11053439', 'tenant_id': '255f7da2d5334c2ea2b53180054bb83d', 'project_id': '255f7da2d5334c2ea2b53180054bb83d', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRP-20757291', 'ctest-bgpaas_vn-11053439'], 'port_security_enabled': True, 'description': ''}} 2025-08-15 10:16:46,185 - DEBUG - Response for create_subnet : {'subnet': {'id': '95376406-e28e-4e90-a520-bfec56df2711', 'name': '', 'tenant_id': '255f7da2d5334c2ea2b53180054bb83d', 'network_id': 'b80afd5a-1413-4a2c-97c2-50a8b30caca1', 'ip_version': 4, 'cidr': '66.27.41.128/26', 'allocation_pools': [{'start': '66.27.41.130', 'end': '66.27.41.190'}], 'gateway_ip': '66.27.41.129', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '66.27.41.130', 'tags': [], 'project_id': '255f7da2d5334c2ea2b53180054bb83d'}} 2025-08-15 10:16:46,213 - INFO - Created VN ctest-bgpaas_vn-11053439 2025-08-15 10:16:46,227 - DEBUG - VN ctest-bgpaas_vn-11053439 UUID is b80afd5a-1413-4a2c-97c2-50a8b30caca1 2025-08-15 10:16:46,795 - DEBUG - Response for create_network : {'network': {'id': 'd3df55d9-0488-481c-872a-11eef6ae68c2', 'name': 'ctest-bgpaas_vn-81984011', 'tenant_id': '255f7da2d5334c2ea2b53180054bb83d', 'project_id': '255f7da2d5334c2ea2b53180054bb83d', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRP-20757291', 'ctest-bgpaas_vn-81984011'], 'port_security_enabled': True, 'description': ''}} 2025-08-15 10:16:47,054 - DEBUG - Response for create_subnet : {'subnet': {'id': '33fba0fc-4026-4397-9ead-97be37df6b1e', 'name': '', 'tenant_id': '255f7da2d5334c2ea2b53180054bb83d', 'network_id': 'd3df55d9-0488-481c-872a-11eef6ae68c2', 'ip_version': 4, 'cidr': '118.31.218.64/26', 'allocation_pools': [{'start': '118.31.218.66', 'end': '118.31.218.126'}], 'gateway_ip': '118.31.218.65', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '118.31.218.66', 'tags': [], 'project_id': '255f7da2d5334c2ea2b53180054bb83d'}} 2025-08-15 10:16:47,072 - INFO - Created VN ctest-bgpaas_vn-81984011 2025-08-15 10:16:47,082 - DEBUG - VN ctest-bgpaas_vn-81984011 UUID is d3df55d9-0488-481c-872a-11eef6ae68c2 2025-08-15 10:16:48,389 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-3861-2), Zone: (nova:an-jenkins-deploy-platform-ansible-os-3861-2) 2025-08-15 10:16:49,922 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-3861-1), Zone: (nova:an-jenkins-deploy-platform-ansible-os-3861-1) 2025-08-15 10:16:49,922 - INFO - Waiting for VM test_vm to be up.. 2025-08-15 10:16:50,016 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2025-08-15 10:16:55,094 - DEBUG - VM is in ACTIVE state now 2025-08-15 10:16:55,094 - INFO - VM name : test_vm 2025-08-15 10:16:55,166 - DEBUG - VM test_vm ID is 651cffb2-28b3-4dfa-b6ec-f692e12c02ca 2025-08-15 10:16:55,167 - DEBUG - VM test_vm launched on Node an-jenkins-deploy-platform-ansible-os-3861-2 2025-08-15 10:16:55,245 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine/651cffb2-28b3-4dfa-b6ec-f692e12c02ca 2025-08-15 10:16:55,255 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine-interface/fc041165-f1bd-40f6-b3cd-dafcb9ef79c6 2025-08-15 10:16:58,422 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1012ms') 2025-08-15 10:16:58,422 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM test_vm failed! 2025-08-15 10:16:58,435 - DEBUG - Gateway for vn default-domain:ctest-TestRP-20757291:ctest-bgpaas_vn-11053439 is 66.27.41.129 and allocation pool is NOT set 2025-08-15 10:17:00,495 - 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.67 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=0.492 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.492/1.583/2.674/1.091 ms') 2025-08-15 10:17:00,495 - INFO - Ping to Metadata IP 169.254.0.3 of VM test_vm passed 2025-08-15 10:17:00,566 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-15 10:17:00,566 - DEBUG - Waiting to SSH to VM test_vm, IP 66.27.41.131, Port 22 2025-08-15 10:17:00,722 - DEBUG - VM test_vm is ready for SSH connections 2025-08-15 10:17:00,722 - INFO - Waiting for VM test2_vm to be up.. 2025-08-15 10:17:00,813 - DEBUG - VM is in ACTIVE state now 2025-08-15 10:17:00,813 - INFO - VM name : test2_vm 2025-08-15 10:17:00,895 - DEBUG - VM test2_vm ID is cef2ee15-0bd1-42d4-a271-af7a94a2989f 2025-08-15 10:17:00,895 - DEBUG - VM test2_vm launched on Node an-jenkins-deploy-platform-ansible-os-3861-1 2025-08-15 10:17:00,974 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine/cef2ee15-0bd1-42d4-a271-af7a94a2989f 2025-08-15 10:17:00,983 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine-interface/0055590b-2ddc-4470-85b4-88e6108351b8 2025-08-15 10:17:02,150 - 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.43 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=0.599 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 = 0.599/2.516/4.433/1.917 ms') 2025-08-15 10:17:02,150 - INFO - Ping to Metadata IP 169.254.0.3 of VM test2_vm passed 2025-08-15 10:17:02,215 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-15 10:17:02,215 - DEBUG - Waiting to SSH to VM test2_vm, IP 118.31.218.67, Port 22 2025-08-15 10:17:02,380 - DEBUG - VM test2_vm is ready for SSH connections 2025-08-15 10:17:02,547 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-15 10:17:02,560 - DEBUG - Requesting: http://10.20.0.254:8083/Snh_ShowRouteReq?x=default-domain:ctest-TestRP-20757291:ctest-bgpaas_vn-11053439:ctest-bgpaas_vn-11053439.inet.0 2025-08-15 10:17:02,570 - DEBUG - Requesting: http://10.20.0.25:8083/Snh_ShowRouteReq?x=default-domain:ctest-TestRP-20757291:ctest-bgpaas_vn-11053439:ctest-bgpaas_vn-11053439.inet.0 2025-08-15 10:17:02,586 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-15 10:17:02,586 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 118.31.218.67, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.242, gateway password: c0ntrail123 2025-08-15 10:17:02,586 - DEBUG - ping -s 56 -c 3 -W 1 118.31.218.67 2025-08-15 10:17:06,511 - DEBUG - PING 118.31.218.67 (118.31.218.67): 56 data bytes 64 bytes from 118.31.218.67: seq=0 ttl=63 time=6.783 ms 64 bytes from 118.31.218.67: seq=1 ttl=63 time=1.130 ms 64 bytes from 118.31.218.67: seq=2 ttl=63 time=1.203 ms --- 118.31.218.67 ping statistics --- 3 packets transmitted, 3 packets received, 0% packet loss round-trip min/avg/max = 1.130/3.038/6.783 ms 2025-08-15 10:17:06,512 - INFO - Ping to IP 118.31.218.67 from VM test_vm passed 2025-08-15 10:17:06,708 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-15 10:17:06,720 - DEBUG - Requesting: http://10.20.0.254:8083/Snh_ShowRouteReq?x=default-domain:ctest-TestRP-20757291:ctest-bgpaas_vn-11053439:ctest-bgpaas_vn-11053439.inet.0 2025-08-15 10:17:06,728 - DEBUG - Requesting: http://10.20.0.25:8083/Snh_ShowRouteReq?x=default-domain:ctest-TestRP-20757291:ctest-bgpaas_vn-11053439:ctest-bgpaas_vn-11053439.inet.0 2025-08-15 10:17:07,004 - INFO - Deleting VM test2_vm 2025-08-15 10:17:07,073 - INFO - Deleting VM test_vm 2025-08-15 10:17:07,133 - INFO - Deleting VN ctest-bgpaas_vn-81984011 2025-08-15 10:17:07,174 - DEBUG - VN d3df55d9-0488-481c-872a-11eef6ae68c2 still in use: Unable to complete operation on network d3df55d9-0488-481c-872a-11eef6ae68c2. There are one or more ports still in use on the network. Neutron server returns request_ids: ['req-4a571fc3-fd72-4ffa-b8c3-67877cfd5906'] 2025-08-15 10:17:07,174 - WARNING - Deleting VN ctest-bgpaas_vn-81984011 failed..Will retry 2025-08-15 10:17:09,315 - DEBUG - Response for deleting network () 2025-08-15 10:17:09,315 - INFO - Deleting VN ctest-bgpaas_vn-11053439 2025-08-15 10:17:09,480 - DEBUG - Response for deleting network () 2025-08-15 10:17:10,750 - ERROR - XMPP status is {'10.0.0.241': {'10.20.0.14': '1', '10.20.0.254': '1'}, '10.0.0.242': {'10.20.0.254': '0', '10.20.0.25': '1'}}, Expected: {'10.0.0.241': {'10.20.0.14': '0', '10.20.0.254': '0'}, '10.0.0.242': {'10.20.0.254': '0', '10.20.0.25': '1'}} 2025-08-15 10:17:10,750 - INFO -
2025-08-15 10:17:10,751 - INFO - END TEST : test_rp_interface_ext_community : FAILED[0:00:26]
2025-08-15 10:17:10,751 - INFO - -------------------------------------------------------------------------------- 2025-08-15 10:17:10,753 - INFO - ================================================================================ 2025-08-15 10:17:10,753 - INFO - STARTING TEST : test_rp_interface_static 2025-08-15 10:17:10,753 - INFO - TEST DESCRIPTION : 1. Create a routing policy with interface-static match. 2. Launch VMs. 3. Attach policy to VN and confirm if policy takes hold. 2025-08-15 10:17:12,006 - DEBUG - Nothing to compare xmpp stats {'10.0.0.241': {'10.20.0.14': '1', '10.20.0.254': '1'}, '10.0.0.242': {'10.20.0.254': '0', '10.20.0.25': '1'}} with 2025-08-15 10:17:12,006 - INFO - Initial checks done. Running the testcase now 2025-08-15 10:17:12,006 - INFO - 2025-08-15 10:17:12,251 - DEBUG - Response for create_network : {'network': {'id': '6553a2fa-be20-4cf6-bcf8-20512e585714', 'name': 'ctest-bgpaas_vn-12057219', 'tenant_id': '255f7da2d5334c2ea2b53180054bb83d', 'project_id': '255f7da2d5334c2ea2b53180054bb83d', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRP-20757291', 'ctest-bgpaas_vn-12057219'], 'port_security_enabled': True, 'description': ''}} 2025-08-15 10:17:12,447 - DEBUG - Response for create_subnet : {'subnet': {'id': '135b80ee-72eb-4265-ba57-321852e86aef', 'name': '', 'tenant_id': '255f7da2d5334c2ea2b53180054bb83d', 'network_id': '6553a2fa-be20-4cf6-bcf8-20512e585714', 'ip_version': 4, 'cidr': '132.141.56.192/26', 'allocation_pools': [{'start': '132.141.56.194', 'end': '132.141.56.254'}], 'gateway_ip': '132.141.56.193', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '132.141.56.194', 'tags': [], 'project_id': '255f7da2d5334c2ea2b53180054bb83d'}} 2025-08-15 10:17:12,472 - INFO - Created VN ctest-bgpaas_vn-12057219 2025-08-15 10:17:12,483 - DEBUG - VN ctest-bgpaas_vn-12057219 UUID is 6553a2fa-be20-4cf6-bcf8-20512e585714 2025-08-15 10:17:12,975 - DEBUG - Response for create_network : {'network': {'id': '323cdd6e-15dd-4e54-8d8b-1ced1d5900c2', 'name': 'ctest-bgpaas_vn-55006989', 'tenant_id': '255f7da2d5334c2ea2b53180054bb83d', 'project_id': '255f7da2d5334c2ea2b53180054bb83d', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRP-20757291', 'ctest-bgpaas_vn-55006989'], 'port_security_enabled': True, 'description': ''}} 2025-08-15 10:17:13,215 - DEBUG - Response for create_subnet : {'subnet': {'id': 'a81e42a4-794a-461f-b5f7-2cd4668c8d85', 'name': '', 'tenant_id': '255f7da2d5334c2ea2b53180054bb83d', 'network_id': '323cdd6e-15dd-4e54-8d8b-1ced1d5900c2', 'ip_version': 4, 'cidr': '87.158.140.0/26', 'allocation_pools': [{'start': '87.158.140.2', 'end': '87.158.140.62'}], 'gateway_ip': '87.158.140.1', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '87.158.140.2', 'tags': [], 'project_id': '255f7da2d5334c2ea2b53180054bb83d'}} 2025-08-15 10:17:13,236 - INFO - Created VN ctest-bgpaas_vn-55006989 2025-08-15 10:17:13,248 - DEBUG - VN ctest-bgpaas_vn-55006989 UUID is 323cdd6e-15dd-4e54-8d8b-1ced1d5900c2 2025-08-15 10:17:14,472 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-3861-2), Zone: (nova:an-jenkins-deploy-platform-ansible-os-3861-2) 2025-08-15 10:17:15,720 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-3861-1), Zone: (nova:an-jenkins-deploy-platform-ansible-os-3861-1) 2025-08-15 10:17:15,721 - INFO - Waiting for VM test_vm to be up.. 2025-08-15 10:17:15,804 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2025-08-15 10:17:20,881 - DEBUG - VM is in ACTIVE state now 2025-08-15 10:17:20,881 - INFO - VM name : test_vm 2025-08-15 10:17:20,957 - DEBUG - VM test_vm ID is 5af9c77a-55b1-48de-b038-250ef7ff83ea 2025-08-15 10:17:20,957 - DEBUG - VM test_vm launched on Node an-jenkins-deploy-platform-ansible-os-3861-2 2025-08-15 10:17:21,052 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine/5af9c77a-55b1-48de-b038-250ef7ff83ea 2025-08-15 10:17:21,063 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine-interface/4c09ad4d-fce1-4a42-a8d4-a04172c1a418 2025-08-15 10:17:24,240 - 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 1007ms') 2025-08-15 10:17:24,240 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM test_vm failed! 2025-08-15 10:17:24,253 - DEBUG - Gateway for vn default-domain:ctest-TestRP-20757291:ctest-bgpaas_vn-12057219 is 132.141.56.193 and allocation pool is NOT set 2025-08-15 10:17:26,311 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n64 bytes from 169.254.0.3: icmp_seq=1 ttl=63 time=2.78 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=0.406 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.406/1.591/2.777/1.185 ms') 2025-08-15 10:17:26,311 - INFO - Ping to Metadata IP 169.254.0.3 of VM test_vm passed 2025-08-15 10:17:26,385 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-15 10:17:26,385 - DEBUG - Waiting to SSH to VM test_vm, IP 132.141.56.195, Port 22 2025-08-15 10:17:26,553 - DEBUG - VM test_vm is ready for SSH connections 2025-08-15 10:17:26,553 - INFO - Waiting for VM test2_vm to be up.. 2025-08-15 10:17:26,639 - DEBUG - VM is in ACTIVE state now 2025-08-15 10:17:26,639 - INFO - VM name : test2_vm 2025-08-15 10:17:26,724 - DEBUG - VM test2_vm ID is c868063c-5836-43fa-bb12-e2bc82ea23ca 2025-08-15 10:17:26,724 - DEBUG - VM test2_vm launched on Node an-jenkins-deploy-platform-ansible-os-3861-1 2025-08-15 10:17:26,800 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine/c868063c-5836-43fa-bb12-e2bc82ea23ca 2025-08-15 10:17:26,811 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine-interface/f54c2418-fbc0-495d-ac62-0cdf98a12f3d 2025-08-15 10:17:27,990 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n64 bytes from 169.254.0.3: icmp_seq=1 ttl=63 time=3.19 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=0.524 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 = 0.524/1.858/3.192/1.334 ms') 2025-08-15 10:17:27,990 - INFO - Ping to Metadata IP 169.254.0.3 of VM test2_vm passed 2025-08-15 10:17:28,055 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-15 10:17:28,055 - DEBUG - Waiting to SSH to VM test2_vm, IP 87.158.140.3, Port 22 2025-08-15 10:17:28,212 - DEBUG - VM test2_vm is ready for SSH connections 2025-08-15 10:17:28,315 - INFO - Created InterfaceRouteTable ['default-domain', 'ctest-TestRP-20757291', 'ctest-int_table_right-31654061'](UUID 273739b9-2329-4ab4-82ba-ca3311a4c2d9), prefixes : ['141.43.27.0/26'] 2025-08-15 10:17:28,379 - INFO - Added intf route table 273739b9-2329-4ab4-82ba-ca3311a4c2d9 to port 4c09ad4d-fce1-4a42-a8d4-a04172c1a418 2025-08-15 10:17:28,572 - DEBUG - Requesting: http://10.20.0.254:8083/Snh_ShowRouteReq?x=default-domain:ctest-TestRP-20757291:ctest-bgpaas_vn-12057219:ctest-bgpaas_vn-12057219.inet.0 2025-08-15 10:17:28,583 - DEBUG - Requesting: http://10.20.0.25:8083/Snh_ShowRouteReq?x=default-domain:ctest-TestRP-20757291:ctest-bgpaas_vn-12057219:ctest-bgpaas_vn-12057219.inet.0 2025-08-15 10:17:28,597 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-15 10:17:28,597 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 87.158.140.3, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.242, gateway password: c0ntrail123 2025-08-15 10:17:28,597 - DEBUG - ping -s 56 -c 3 -W 1 87.158.140.3 2025-08-15 10:17:32,245 - DEBUG - PING 87.158.140.3 (87.158.140.3): 56 data bytes 64 bytes from 87.158.140.3: seq=0 ttl=63 time=7.818 ms 64 bytes from 87.158.140.3: seq=1 ttl=63 time=1.099 ms 64 bytes from 87.158.140.3: seq=2 ttl=63 time=1.153 ms --- 87.158.140.3 ping statistics --- 3 packets transmitted, 3 packets received, 0% packet loss round-trip min/avg/max = 1.099/3.356/7.818 ms 2025-08-15 10:17:32,246 - INFO - Ping to IP 87.158.140.3 from VM test_vm passed 2025-08-15 10:17:32,354 - INFO - Deleting VM test2_vm 2025-08-15 10:17:32,437 - INFO - Deleting VM test_vm 2025-08-15 10:17:32,494 - INFO - Deleting VN ctest-bgpaas_vn-55006989 2025-08-15 10:17:32,531 - DEBUG - VN 323cdd6e-15dd-4e54-8d8b-1ced1d5900c2 still in use: Unable to complete operation on network 323cdd6e-15dd-4e54-8d8b-1ced1d5900c2. There are one or more ports still in use on the network. Neutron server returns request_ids: ['req-e3f47712-3c19-42ee-9a6a-40e0d3a2d7f5'] 2025-08-15 10:17:32,531 - WARNING - Deleting VN ctest-bgpaas_vn-55006989 failed..Will retry 2025-08-15 10:17:34,658 - DEBUG - Response for deleting network () 2025-08-15 10:17:34,659 - INFO - Deleting VN ctest-bgpaas_vn-12057219 2025-08-15 10:17:34,815 - DEBUG - Response for deleting network () 2025-08-15 10:17:36,090 - DEBUG - No XMPP flaps were noticed during the test
2025-08-15 10:17:36,090 - INFO - END TEST : test_rp_interface_static : PASSED[0:00:26]
2025-08-15 10:17:36,091 - INFO - -------------------------------------------------------------------------------- 2025-08-15 10:17:36,757 - INFO - Deleted project: ctest-TestRP-20757291, ID : 255f7da2-d533-4c2e-a2b5-3180054bb83d