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/vrouter/test_vif_stats.py", line 91, in test_vif_statistics
output = "Vif stats cleared successfully"
File "/contrail-test/scripts/vrouter/test_vif_stats.py", line 30, in get_vif_stats
vif_ids = []
AssertionError: RX packets is not available
2025-10-29 13:06:38,386 - DEBUG - No XMPP flaps were noticed during the test
2025-10-29 13:06:38,386 - INFO -
2025-10-29 13:06:38,386 - INFO - END TEST : test_vif_statistics : FAILED[0:01:50]
2025-10-29 13:06:38,387 - INFO - --------------------------------------------------------------------------------
2025-10-29 13:06:39,195 - INFO - Deleted project: ctest-TestvifStats-90697936, ID : 2843e466-50db-4827-9db6-246c56941222
2025-10-29 13:31:16,086 - DEBUG - [10.0.0.38]: Running cmd : hostname
2025-10-29 13:31:16,295 - DEBUG - Output : cn-jenkins-deploy-platform-ansible-os-4521-1
2025-10-29 13:31:16,295 - DEBUG - [10.0.0.38]: Running cmd : hostname -f
2025-10-29 13:31:16,362 - DEBUG - Output : cn-jenkins-deploy-platform-ansible-os-4521-1.
2025-10-29 13:31:16,362 - DEBUG - [10.0.0.38]: Running cmd : docker ps 2>/dev/null | grep -v "/pause\|/usr/bin/pod\|nova_api_\|contrail.*init\|init.*contrail\|provisioner\|placement" | awk '{print $NF}'
2025-10-29 13:31:16,486 - DEBUG - Output : NAMES
contrail_test_XaS2cHdub
analytics_snmp_nodemgr_1
analytics_snmp_topology_1
analytics_snmp_snmp-collector_1
analytics_alarm_nodemgr_1
analytics_alarm_alarm-gen_1
analytics_alarm_kafka_1
analytics_nodemgr_1
analytics_api_1
analytics_collector_1
analytics_database_nodemgr_1
analytics_database_query-engine_1
analytics_database_cassandra_1
control_named_1
control_control_1
control_nodemgr_1
control_dns_1
webui_web_1
webui_job_1
config_devicemgr_1
config_dnsmasq_1
config_api_1
config_schema_1
config_nodemgr_1
config_svcmonitor_1
config_database_nodemgr_1
config_database_rabbitmq_1
config_database_cassandra_1
config_database_zookeeper_1
redis_redis_1
barbican_worker
barbican_keystone_listener
barbican_api
horizon
heat_engine
heat_api_cfn
heat_api
neutron_server
nova_novncproxy
nova_conductor
nova_api
nova_scheduler
glance_api
keystone
keystone_fernet
keystone_ssh
rabbitmq
memcached
mariadb
cron
kolla_toolbox
fluentd
2025-10-29 13:31:16,487 - DEBUG - [10.0.0.38]: Running cmd : getent hosts 10.0.0.38 | head -n 1 | awk '{print $2}'
2025-10-29 13:31:16,559 - DEBUG - Output : cn-jenkins-deploy-platform-ansible-os-4521-1.
2025-10-29 13:31:16,559 - DEBUG - [10.0.0.38]: Running cmd : ip -4 -o addr show | awk '{print $4}'
2025-10-29 13:31:16,629 - DEBUG - Output : 127.0.0.1/8
10.0.0.38/24
10.20.0.17/24
172.17.0.1/16
2025-10-29 13:31:16,629 - DEBUG - [10.0.0.38]: Running cmd : getent hosts 10.20.0.17 | head -n 1 | awk '{print $2}'
2025-10-29 13:31:16,707 - DEBUG - Output :
2025-10-29 13:31:16,707 - DEBUG - [10.0.0.254]: Running cmd : hostname
2025-10-29 13:31:17,415 - DEBUG - Output : cn-jenkins-deploy-platform-ansible-os-4521-2
2025-10-29 13:31:17,415 - DEBUG - [10.0.0.254]: Running cmd : hostname -f
2025-10-29 13:31:17,473 - DEBUG - Output : cn-jenkins-deploy-platform-ansible-os-4521-2.
2025-10-29 13:31:17,473 - DEBUG - [10.0.0.254]: Running cmd : docker ps 2>/dev/null | grep -v "/pause\|/usr/bin/pod\|nova_api_\|contrail.*init\|init.*contrail\|provisioner\|placement" | awk '{print $NF}'
2025-10-29 13:31:17,569 - DEBUG - Output : NAMES
analytics_snmp_topology_1
analytics_snmp_nodemgr_1
analytics_snmp_snmp-collector_1
analytics_alarm_nodemgr_1
analytics_alarm_alarm-gen_1
analytics_alarm_kafka_1
analytics_collector_1
analytics_api_1
analytics_nodemgr_1
analytics_database_nodemgr_1
analytics_database_query-engine_1
analytics_database_cassandra_1
control_named_1
control_dns_1
control_control_1
control_nodemgr_1
webui_web_1
webui_job_1
config_devicemgr_1
config_nodemgr_1
config_svcmonitor_1
config_schema_1
config_dnsmasq_1
config_api_1
config_database_nodemgr_1
config_database_rabbitmq_1
config_database_cassandra_1
config_database_zookeeper_1
redis_redis_1
2025-10-29 13:31:17,569 - DEBUG - [10.0.0.254]: Running cmd : ip -4 -o addr show | awk '{print $4}'
2025-10-29 13:31:17,643 - DEBUG - Output : 127.0.0.1/8
10.0.0.254/24
10.20.0.254/24
172.17.0.1/16
2025-10-29 13:31:17,644 - DEBUG - [10.0.0.254]: Running cmd : getent hosts 10.0.0.254 | head -n 1 | awk '{print $2}'
2025-10-29 13:31:17,713 - DEBUG - Output : cn-jenkins-deploy-platform-ansible-os-4521-2.
2025-10-29 13:31:17,713 - DEBUG - [10.0.0.254]: Running cmd : getent hosts 10.20.0.254 | head -n 1 | awk '{print $2}'
2025-10-29 13:31:17,784 - DEBUG - Output : cn-jenkins-deploy-platform-ansible-os-4521-2
2025-10-29 13:31:17,784 - DEBUG - [10.0.0.48]: Running cmd : hostname
2025-10-29 13:31:18,504 - DEBUG - Output : cn-jenkins-deploy-platform-ansible-os-4521-3
2025-10-29 13:31:18,504 - DEBUG - [10.0.0.48]: Running cmd : hostname -f
2025-10-29 13:31:18,570 - DEBUG - Output : cn-jenkins-deploy-platform-ansible-os-4521-3.
2025-10-29 13:31:18,570 - DEBUG - [10.0.0.48]: Running cmd : docker ps 2>/dev/null | grep -v "/pause\|/usr/bin/pod\|nova_api_\|contrail.*init\|init.*contrail\|provisioner\|placement" | awk '{print $NF}'
2025-10-29 13:31:18,679 - DEBUG - Output : NAMES
analytics_snmp_nodemgr_1
analytics_snmp_topology_1
analytics_snmp_snmp-collector_1
analytics_alarm_alarm-gen_1
analytics_alarm_nodemgr_1
analytics_alarm_kafka_1
analytics_collector_1
analytics_api_1
analytics_nodemgr_1
analytics_database_nodemgr_1
analytics_database_query-engine_1
analytics_database_cassandra_1
control_named_1
control_dns_1
control_nodemgr_1
control_control_1
webui_web_1
webui_job_1
config_devicemgr_1
config_nodemgr_1
config_schema_1
config_svcmonitor_1
config_dnsmasq_1
config_api_1
config_database_rabbitmq_1
config_database_nodemgr_1
config_database_zookeeper_1
config_database_cassandra_1
redis_redis_1
2025-10-29 13:31:18,679 - DEBUG - [10.0.0.48]: Running cmd : ip -4 -o addr show | awk '{print $4}'
2025-10-29 13:31:18,737 - DEBUG - Output : 127.0.0.1/8
10.0.0.48/24
10.20.0.14/24
172.17.0.1/16
2025-10-29 13:31:18,738 - DEBUG - [10.0.0.48]: Running cmd : getent hosts 10.0.0.48 | head -n 1 | awk '{print $2}'
2025-10-29 13:31:18,803 - DEBUG - Output : cn-jenkins-deploy-platform-ansible-os-4521-3.
2025-10-29 13:31:18,803 - DEBUG - [10.0.0.48]: Running cmd : getent hosts 10.20.0.14 | head -n 1 | awk '{print $2}'
2025-10-29 13:31:18,880 - DEBUG - Output : cn-jenkins-deploy-platform-ansible-os-4521-3
2025-10-29 13:31:18,880 - DEBUG - [10.0.0.49]: Running cmd : hostname
2025-10-29 13:31:19,368 - DEBUG - Output : an-jenkins-deploy-platform-ansible-os-4521-1
2025-10-29 13:31:19,369 - DEBUG - [10.0.0.49]: Running cmd : hostname -f
2025-10-29 13:31:19,430 - DEBUG - Output : an-jenkins-deploy-platform-ansible-os-4521-1.
2025-10-29 13:31:19,430 - DEBUG - [10.0.0.49]: Running cmd : docker ps 2>/dev/null | grep -v "/pause\|/usr/bin/pod\|nova_api_\|contrail.*init\|init.*contrail\|provisioner\|placement" | awk '{print $NF}'
2025-10-29 13:31:19,529 - DEBUG - Output : NAMES
vrouter_vrouter-agent_1
vrouter_nodemgr_1
rsyslogd_rsyslogd_1
nova_compute
nova_libvirt
nova_ssh
cron
kolla_toolbox
fluentd
2025-10-29 13:31:19,530 - DEBUG - [10.0.0.49]: Running cmd : ip -4 -o addr show dev vhost0 | awk '{print $4}'
2025-10-29 13:31:19,586 - DEBUG - Output : 10.20.0.25/24
2025-10-29 13:31:19,587 - DEBUG - [10.0.0.49]: Running cmd : getent hosts 10.20.0.25 | head -n 1 | awk '{print $2}'
2025-10-29 13:31:19,661 - DEBUG - Output : an-jenkins-deploy-platform-ansible-os-4521-1
2025-10-29 13:31:19,662 - DEBUG - [10.0.0.50]: Running cmd : hostname
2025-10-29 13:31:20,148 - DEBUG - Output : an-jenkins-deploy-platform-ansible-os-4521-2
2025-10-29 13:31:20,148 - DEBUG - [10.0.0.50]: Running cmd : hostname -f
2025-10-29 13:31:20,211 - DEBUG - Output : an-jenkins-deploy-platform-ansible-os-4521-2.
2025-10-29 13:31:20,211 - DEBUG - [10.0.0.50]: Running cmd : docker ps 2>/dev/null | grep -v "/pause\|/usr/bin/pod\|nova_api_\|contrail.*init\|init.*contrail\|provisioner\|placement" | awk '{print $NF}'
2025-10-29 13:31:20,292 - DEBUG - Output : NAMES
vrouter_vrouter-agent_1
vrouter_nodemgr_1
rsyslogd_rsyslogd_1
nova_compute
nova_libvirt
nova_ssh
cron
kolla_toolbox
fluentd
2025-10-29 13:31:20,293 - DEBUG - [10.0.0.50]: Running cmd : ip -4 -o addr show dev vhost0 | awk '{print $4}'
2025-10-29 13:31:20,356 - DEBUG - Output : 10.20.0.193/24
2025-10-29 13:31:20,357 - DEBUG - [10.0.0.50]: Running cmd : getent hosts 10.20.0.193 | head -n 1 | awk '{print $2}'
2025-10-29 13:31:20,431 - DEBUG - Output : an-jenkins-deploy-platform-ansible-os-4521-2
2025-10-29 13:31:21,283 - DEBUG - Not creating keypair since it exists
2025-10-29 13:31:21,344 - INFO - Domain Default found not creating
2025-10-29 13:31:21,865 - INFO - Project ctest-TestvifStats-00326462 not found, creating it
2025-10-29 13:31:22,581 - INFO - Created Project:ctest-TestvifStats-00326462, ID : e0f392b0-60bb-4c44-aa13-e7b801f99732
2025-10-29 13:31:24,217 - INFO - Using existing project ['default-domain', 'admin'](941e9aef-7b03-4547-a8ff-19c13661cb0c)
2025-10-29 13:31:24,625 - INFO - admin user already present
2025-10-29 13:31:24,981 - INFO - Adding rules to the default security group in Project admin
2025-10-29 13:31:25,421 - INFO - ================================================================================
2025-10-29 13:31:25,421 - INFO - STARTING TEST : test_vif_statistics
2025-10-29 13:31:25,422 - INFO - TEST DESCRIPTION :
Description:
Verify vif statistics
Vm's across compute node
steps:
1. create 1 VN and launch 2 VMs in compute node
2. client and server VMs on same node
3. send icmp traffic assert if ping is not working
4. get_vif_stats to check vif interface
5. clear_vif_stats to clear vif interface stats
6. Repeat step4
Pass criteria:
1. If output of vif stats/clear execute successfully from compute
2025-10-29 13:31:26,047 - DEBUG - Skipping xmpp flap check
2025-10-29 13:31:26,047 - INFO - Initial checks done. Running the testcase now
2025-10-29 13:31:26,047 - INFO -
2025-10-29 13:31:26,774 - DEBUG - Response for create_network : {'network': {'id': '19744a99-1335-45bc-a0b7-340955b08276', 'name': 'ctest-vn-54622387', 'tenant_id': 'e0f392b060bb4c44aa13e7b801f99732', 'project_id': 'e0f392b060bb4c44aa13e7b801f99732', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestvifStats-00326462', 'ctest-vn-54622387'], 'port_security_enabled': True, 'description': ''}}
2025-10-29 13:31:27,114 - DEBUG - Response for create_subnet : {'subnet': {'id': 'e365e83a-1fc0-48b8-9c5a-d76393e3b119', 'name': '', 'tenant_id': 'e0f392b060bb4c44aa13e7b801f99732', 'network_id': '19744a99-1335-45bc-a0b7-340955b08276', 'ip_version': 4, 'cidr': '203.174.195.192/26', 'allocation_pools': [{'start': '203.174.195.194', 'end': '203.174.195.254'}], 'gateway_ip': '203.174.195.193', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '203.174.195.194', 'tags': [], 'project_id': 'e0f392b060bb4c44aa13e7b801f99732'}}
2025-10-29 13:31:27,142 - INFO - Created VN ctest-vn-54622387
2025-10-29 13:31:27,158 - DEBUG - VN ctest-vn-54622387 UUID is 19744a99-1335-45bc-a0b7-340955b08276
2025-10-29 13:31:27,242 - DEBUG - Requesting: http://10.0.0.38:8082/domains
2025-10-29 13:31:27,556 - DEBUG - Requesting: http://10.0.0.38:8082/domains
2025-10-29 13:31:27,584 - DEBUG - Requesting: http://10.0.0.38:8082/domain/fd9d3a52-0780-4060-8425-e3c883ec81fc
2025-10-29 13:31:27,600 - DEBUG - Requesting: http://10.0.0.38:8082/project/e0f392b0-60bb-4c44-aa13-e7b801f99732
2025-10-29 13:31:27,708 - DEBUG - Requesting: http://10.0.0.38:8082/virtual-network/19744a99-1335-45bc-a0b7-340955b08276
2025-10-29 13:31:27,725 - DEBUG - Requesting: http://10.0.0.38:8082/virtual-network/19744a99-1335-45bc-a0b7-340955b08276
2025-10-29 13:31:27,736 - DEBUG - Requesting: http://10.0.0.38:8082/routing-instance/bea3d70e-fd7a-4cc2-a9a4-fb8ea9e5b1b1
2025-10-29 13:31:27,744 - DEBUG - Requesting: http://10.0.0.38:8082/routing-instance/bea3d70e-fd7a-4cc2-a9a4-fb8ea9e5b1b1
2025-10-29 13:31:27,753 - DEBUG - Requesting: http://10.0.0.38:8082/route-target/1b5ca178-ea63-40d6-bb21-88f3f46f97ef
2025-10-29 13:31:27,766 - DEBUG - Route Targets: ['target:64512:8000006']
2025-10-29 13:31:27,766 - DEBUG - Requesting: http://10.0.0.38:8082/virtual-network/19744a99-1335-45bc-a0b7-340955b08276
2025-10-29 13:31:27,776 - DEBUG - Requesting: http://10.0.0.38:8082/routing-instance/bea3d70e-fd7a-4cc2-a9a4-fb8ea9e5b1b1
2025-10-29 13:31:27,797 - INFO - Verified VN network id 16 for VN 19744a99-1335-45bc-a0b7-340955b08276
2025-10-29 13:31:27,797 - INFO - Verifications in API Server for VN ctest-vn-54622387 passed
2025-10-29 13:31:27,797 - DEBUG - Requesting: http://10.0.0.38:8082/virtual-network/19744a99-1335-45bc-a0b7-340955b08276
2025-10-29 13:31:27,812 - DEBUG - Requesting: http://10.0.0.38:8082/routing-instance/bea3d70e-fd7a-4cc2-a9a4-fb8ea9e5b1b1
2025-10-29 13:31:27,820 - DEBUG - Requesting: http://10.0.0.38:8082/routing-instance/bea3d70e-fd7a-4cc2-a9a4-fb8ea9e5b1b1
2025-10-29 13:31:27,828 - DEBUG - Requesting: http://10.0.0.38:8082/route-target/1b5ca178-ea63-40d6-bb21-88f3f46f97ef
2025-10-29 13:31:27,836 - DEBUG - Requesting: http://10.0.0.38:8083/Snh_IFMapTableShowReq?table_name=virtual-network&search_string=virtual-network:default-domain:ctest-TestvifStats-00326462:ctest-vn-54622387
2025-10-29 13:31:27,843 - DEBUG - Control-node 10.0.0.38 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestvifStats-00326462:ctest-vn-54622387', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestvifStats-00326462', 'owner-access': '7', 'group': 'admin', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '1834172969559344572', 'uuid-lslong': '11580782181503500918'}, 'enable': 'true', 'created': '2025-10-29T13:31:26', 'last-modified': '2025-10-29T13:31:26', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.846752'}
2025-10-29 13:31:27,843 - DEBUG - Requesting: http://10.0.0.38:8083/Snh_ShowRoutingInstanceReq?name=default-domain:ctest-TestvifStats-00326462:ctest-vn-54622387:ctest-vn-54622387
2025-10-29 13:31:27,851 - DEBUG - Route Targets: ['target:64512:8000006']
2025-10-29 13:31:27,851 - DEBUG - Requesting: http://10.0.0.254:8083/Snh_IFMapTableShowReq?table_name=virtual-network&search_string=virtual-network:default-domain:ctest-TestvifStats-00326462:ctest-vn-54622387
2025-10-29 13:31:27,856 - DEBUG - Control-node 10.0.0.254 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestvifStats-00326462:ctest-vn-54622387', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestvifStats-00326462', 'owner-access': '7', 'group': 'admin', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '1834172969559344572', 'uuid-lslong': '11580782181503500918'}, 'enable': 'true', 'created': '2025-10-29T13:31:26', 'last-modified': '2025-10-29T13:31:26', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.868075'}
2025-10-29 13:31:27,857 - DEBUG - Requesting: http://10.0.0.254:8083/Snh_ShowRoutingInstanceReq?name=default-domain:ctest-TestvifStats-00326462:ctest-vn-54622387:ctest-vn-54622387
2025-10-29 13:31:27,864 - DEBUG - Route Targets: ['target:64512:8000006']
2025-10-29 13:31:27,865 - DEBUG - Requesting: http://10.0.0.48:8083/Snh_IFMapTableShowReq?table_name=virtual-network&search_string=virtual-network:default-domain:ctest-TestvifStats-00326462:ctest-vn-54622387
2025-10-29 13:31:27,870 - DEBUG - Control-node 10.0.0.48 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestvifStats-00326462:ctest-vn-54622387', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestvifStats-00326462', 'owner-access': '7', 'group': 'admin', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '1834172969559344572', 'uuid-lslong': '11580782181503500918'}, 'enable': 'true', 'created': '2025-10-29T13:31:26', 'last-modified': '2025-10-29T13:31:26', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.879978'}
2025-10-29 13:31:27,870 - DEBUG - Requesting: http://10.0.0.48:8083/Snh_ShowRoutingInstanceReq?name=default-domain:ctest-TestvifStats-00326462:ctest-vn-54622387:ctest-vn-54622387
2025-10-29 13:31:27,878 - DEBUG - Route Targets: ['target:64512:8000006']
2025-10-29 13:31:27,878 - INFO - On all control nodes, Config, RI and RT verification for VN ctest-vn-54622387 passed
2025-10-29 13:31:27,881 - DEBUG - ====Verifying policy data for ctest-vn-54622387 in API_Server ======
2025-10-29 13:31:27,881 - DEBUG - Requesting: http://10.0.0.38:8082/domains
2025-10-29 13:31:27,887 - DEBUG - Requesting: http://10.0.0.38:8082/domain/fd9d3a52-0780-4060-8425-e3c883ec81fc
2025-10-29 13:31:27,899 - DEBUG - Requesting: http://10.0.0.38:8082/project/e0f392b0-60bb-4c44-aa13-e7b801f99732
2025-10-29 13:31:27,993 - DEBUG - Requesting: http://10.0.0.38:8082/virtual-network/19744a99-1335-45bc-a0b7-340955b08276
2025-10-29 13:31:28,004 - DEBUG - =>VN ctest-vn-54622387 has no policy to be verified
2025-10-29 13:31:28,004 - DEBUG - Verifying the vn in opserver
2025-10-29 13:31:28,004 - DEBUG - Verifying the default-domain:ctest-TestvifStats-00326462:ctest-vn-54622387 virtual network link through opserver 10.0.0.38
2025-10-29 13:31:28,004 - DEBUG - Requesting: http://10.0.0.38:8081/analytics/uves/virtual-networks
2025-10-29 13:31:28,309 - DEBUG - Requesting: http://10.0.0.38:8081/analytics/uves/virtual-networks
2025-10-29 13:31:28,380 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestvifStats-00326462:ctest-vn-54622387', 'href': 'http://10.0.0.38:8081/analytics/uves/virtual-network/default-domain:ctest-TestvifStats-00326462:ctest-vn-54622387?flat'}
2025-10-29 13:31:28,380 - DEBUG - Verifying the default-domain:ctest-TestvifStats-00326462:ctest-vn-54622387 virtual network link through opserver 10.0.0.254
2025-10-29 13:31:28,381 - DEBUG - Requesting: http://10.0.0.254:8081/analytics/uves/virtual-networks
2025-10-29 13:31:28,690 - DEBUG - Requesting: http://10.0.0.254:8081/analytics/uves/virtual-networks
2025-10-29 13:31:28,754 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestvifStats-00326462:ctest-vn-54622387', 'href': 'http://10.0.0.254:8081/analytics/uves/virtual-network/default-domain:ctest-TestvifStats-00326462:ctest-vn-54622387?flat'}
2025-10-29 13:31:28,754 - DEBUG - Verifying the default-domain:ctest-TestvifStats-00326462:ctest-vn-54622387 virtual network link through opserver 10.0.0.48
2025-10-29 13:31:28,754 - DEBUG - Requesting: http://10.0.0.48:8081/analytics/uves/virtual-networks
2025-10-29 13:31:29,058 - DEBUG - Requesting: http://10.0.0.48:8081/analytics/uves/virtual-networks
2025-10-29 13:31:29,119 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestvifStats-00326462:ctest-vn-54622387', 'href': 'http://10.0.0.48:8081/analytics/uves/virtual-network/default-domain:ctest-TestvifStats-00326462:ctest-vn-54622387?flat'}
2025-10-29 13:31:29,119 - INFO - Validated that VN default-domain:ctest-TestvifStats-00326462:ctest-vn-54622387 is found in opserver
2025-10-29 13:31:29,120 - DEBUG - Requesting: http://10.0.0.49:8085/Snh_VrfListReq?name=default-domain:ctest-TestvifStats-00326462:ctest-vn-54622387:ctest-vn-54622387
2025-10-29 13:31:29,125 - DEBUG - Requesting: http://10.0.0.50:8085/Snh_VrfListReq?name=default-domain:ctest-TestvifStats-00326462:ctest-vn-54622387:ctest-vn-54622387
2025-10-29 13:31:29,131 - DEBUG - Requesting: http://10.0.0.49:8085/Snh_VrfListReq?name=default-domain:ctest-TestvifStats-00326462:ctest-vn-54622387:ctest-vn-54622387
2025-10-29 13:31:29,136 - DEBUG - Requesting: http://10.0.0.50:8085/Snh_VrfListReq?name=default-domain:ctest-TestvifStats-00326462:ctest-vn-54622387:ctest-vn-54622387
2025-10-29 13:31:29,141 - DEBUG - Do not have enough data to verify VN in agent
2025-10-29 13:31:29,142 - DEBUG - Requesting: http://10.0.0.49:8085/Snh_VrfListReq?name=default-domain:ctest-TestvifStats-00326462:ctest-vn-54622387:ctest-vn-54622387
2025-10-29 13:31:29,147 - DEBUG - Requesting: http://10.0.0.50:8085/Snh_VrfListReq?name=default-domain:ctest-TestvifStats-00326462:ctest-vn-54622387:ctest-vn-54622387
2025-10-29 13:31:29,152 - DEBUG - VRF ids for VN ctest-vn-54622387: {}
2025-10-29 13:31:29,183 - DEBUG - Services list from nova: [, , , ]
2025-10-29 13:31:29,183 - DEBUG - Hosts: {'nova': ['an-jenkins-deploy-platform-ansible-os-4521-2', 'an-jenkins-deploy-platform-ansible-os-4521-1']}
2025-10-29 13:31:29,183 - DEBUG - Hosts: {'nova': ['an-jenkins-deploy-platform-ansible-os-4521-2', 'an-jenkins-deploy-platform-ansible-os-4521-1']}
2025-10-29 13:31:30,561 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-4521-2), Zone: (nova:an-jenkins-deploy-platform-ansible-os-4521-2)
2025-10-29 13:31:30,562 - DEBUG - Hosts: {'nova': ['an-jenkins-deploy-platform-ansible-os-4521-2', 'an-jenkins-deploy-platform-ansible-os-4521-1']}
2025-10-29 13:31:32,068 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-4521-2), Zone: (nova:an-jenkins-deploy-platform-ansible-os-4521-2)
2025-10-29 13:31:32,068 - INFO - Waiting for VM ctest-TestvifStats-00326462-95335800 to be up..
2025-10-29 13:31:32,182 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2025-10-29 13:31:37,277 - DEBUG - VM is in ACTIVE state now
2025-10-29 13:31:37,277 - INFO - VM name : ctest-TestvifStats-00326462-95335800
2025-10-29 13:31:37,371 - DEBUG - VM ctest-TestvifStats-00326462-95335800 ID is 899f46fe-8595-496d-a242-890f80fc124a
2025-10-29 13:31:37,413 - DEBUG - VM ctest-TestvifStats-00326462-95335800 launched on Node an-jenkins-deploy-platform-ansible-os-4521-2
2025-10-29 13:31:37,505 - DEBUG - Requesting: http://10.0.0.48:8082/virtual-machine/899f46fe-8595-496d-a242-890f80fc124a
2025-10-29 13:31:37,908 - DEBUG - Requesting: http://10.0.0.48:8082/virtual-machine/899f46fe-8595-496d-a242-890f80fc124a
2025-10-29 13:31:37,963 - DEBUG - Requesting: http://10.0.0.48:8082/virtual-machine-interface/2a01c07a-f9e9-4d5d-bb74-393bf960b6d7
2025-10-29 13:31:37,976 - DEBUG - Requesting: http://10.0.0.50:8085/Snh_PageReq?x=begin:-1,end:-1,table:db.interface.0,uuid:2a01c07a-f9e9-4d5d-bb74-393bf960b6d7
2025-10-29 13:31:37,981 - DEBUG - Requesting: http://10.0.0.50:8085/Snh_VrfListReq?name=default-domain:ctest-TestvifStats-00326462:ctest-vn-54622387:ctest-vn-54622387
2025-10-29 13:31:37,986 - DEBUG - Requesting: http://10.0.0.50:8085/Snh_PageReq?x=begin:-1,end:-1,table:db.interface.0,uuid:2a01c07a-f9e9-4d5d-bb74-393bf960b6d7
2025-10-29 13:31:41,111 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1017ms')
2025-10-29 13:31:41,111 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestvifStats-00326462-95335800 failed!
2025-10-29 13:31:41,128 - DEBUG - Gateway for vn default-domain:ctest-TestvifStats-00326462:ctest-vn-54622387 is 203.174.195.193 and allocation pool is NOT set
2025-10-29 13:31:45,173 - 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')
2025-10-29 13:31:45,173 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestvifStats-00326462-95335800 failed!
2025-10-29 13:31:45,188 - DEBUG - Gateway for vn default-domain:ctest-TestvifStats-00326462:ctest-vn-54622387 is 203.174.195.193 and allocation pool is NOT set
2025-10-29 13:31:49,234 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1026ms')
2025-10-29 13:31:49,235 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestvifStats-00326462-95335800 failed!
2025-10-29 13:31:49,252 - DEBUG - Gateway for vn default-domain:ctest-TestvifStats-00326462:ctest-vn-54622387 is 203.174.195.193 and allocation pool is NOT set
2025-10-29 13:31:53,298 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1026ms')
2025-10-29 13:31:53,299 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestvifStats-00326462-95335800 failed!
2025-10-29 13:31:53,317 - DEBUG - Gateway for vn default-domain:ctest-TestvifStats-00326462:ctest-vn-54622387 is 203.174.195.193 and allocation pool is NOT set
2025-10-29 13:31:57,361 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1024ms')
2025-10-29 13:31:57,361 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestvifStats-00326462-95335800 failed!
2025-10-29 13:31:57,381 - DEBUG - Gateway for vn default-domain:ctest-TestvifStats-00326462:ctest-vn-54622387 is 203.174.195.193 and allocation pool is NOT set
2025-10-29 13:32:01,429 - 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')
2025-10-29 13:32:01,429 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestvifStats-00326462-95335800 failed!
2025-10-29 13:32:01,447 - DEBUG - Gateway for vn default-domain:ctest-TestvifStats-00326462:ctest-vn-54622387 is 203.174.195.193 and allocation pool is NOT set
2025-10-29 13:32:05,494 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1018ms')
2025-10-29 13:32:05,495 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestvifStats-00326462-95335800 failed!
2025-10-29 13:32:05,510 - DEBUG - Gateway for vn default-domain:ctest-TestvifStats-00326462:ctest-vn-54622387 is 203.174.195.193 and allocation pool is NOT set
2025-10-29 13:32:09,551 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1022ms')
2025-10-29 13:32:09,551 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestvifStats-00326462-95335800 failed!
2025-10-29 13:32:09,568 - DEBUG - Gateway for vn default-domain:ctest-TestvifStats-00326462:ctest-vn-54622387 is 203.174.195.193 and allocation pool is NOT set
2025-10-29 13:32:13,621 - 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 1029ms')
2025-10-29 13:32:13,621 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestvifStats-00326462-95335800 failed!
2025-10-29 13:32:13,638 - DEBUG - Gateway for vn default-domain:ctest-TestvifStats-00326462:ctest-vn-54622387 is 203.174.195.193 and allocation pool is NOT set
2025-10-29 13:32:17,683 - 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')
2025-10-29 13:32:17,683 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestvifStats-00326462-95335800 failed!
2025-10-29 13:32:17,700 - DEBUG - Gateway for vn default-domain:ctest-TestvifStats-00326462:ctest-vn-54622387 is 203.174.195.193 and allocation pool is NOT set
2025-10-29 13:32:21,743 - 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 1028ms')
2025-10-29 13:32:21,743 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestvifStats-00326462-95335800 failed!
2025-10-29 13:32:21,763 - DEBUG - Gateway for vn default-domain:ctest-TestvifStats-00326462:ctest-vn-54622387 is 203.174.195.193 and allocation pool is NOT set
2025-10-29 13:32:25,815 - 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 1029ms')
2025-10-29 13:32:25,815 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestvifStats-00326462-95335800 failed!
2025-10-29 13:32:25,830 - DEBUG - Gateway for vn default-domain:ctest-TestvifStats-00326462:ctest-vn-54622387 is 203.174.195.193 and allocation pool is NOT set
2025-10-29 13:32:27,860 - 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=15.4 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=1.56 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.556/8.471/15.387/6.915 ms')
2025-10-29 13:32:27,860 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-TestvifStats-00326462-95335800 passed
2025-10-29 13:32:27,954 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-29 13:32:27,955 - DEBUG - Waiting to SSH to VM ctest-TestvifStats-00326462-95335800, IP 203.174.195.195, Port 22
2025-10-29 13:32:27,991 - DEBUG - Error on ssh to ubuntu@169.254.0.3:22, result: /bin/bash: connect: Connection refused
/bin/bash: line 1: /dev/tcp/169.254.0.3/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.3/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.3/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''}
2025-10-29 13:32:28,093 - DEBUG - VM ctest-TestvifStats-00326462-95335800 is NOT ready for SSH connections, VM status: ACTIVE
2025-10-29 13:32:33,094 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-29 13:32:33,094 - DEBUG - Waiting to SSH to VM ctest-TestvifStats-00326462-95335800, IP 203.174.195.195, Port 22
2025-10-29 13:32:33,128 - DEBUG - Error on ssh to ubuntu@169.254.0.3:22, result: /bin/bash: connect: Connection refused
/bin/bash: line 1: /dev/tcp/169.254.0.3/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.3/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.3/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''}
2025-10-29 13:32:33,217 - DEBUG - VM ctest-TestvifStats-00326462-95335800 is NOT ready for SSH connections, VM status: ACTIVE
2025-10-29 13:32:38,218 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-29 13:32:38,218 - DEBUG - Waiting to SSH to VM ctest-TestvifStats-00326462-95335800, IP 203.174.195.195, Port 22
2025-10-29 13:32:38,242 - DEBUG - Error on ssh to ubuntu@169.254.0.3:22, result: /bin/bash: connect: Connection refused
/bin/bash: line 1: /dev/tcp/169.254.0.3/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.3/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.3/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''}
2025-10-29 13:32:38,334 - DEBUG - VM ctest-TestvifStats-00326462-95335800 is NOT ready for SSH connections, VM status: ACTIVE
2025-10-29 13:32:43,337 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-29 13:32:43,337 - DEBUG - Waiting to SSH to VM ctest-TestvifStats-00326462-95335800, IP 203.174.195.195, Port 22
2025-10-29 13:32:43,363 - DEBUG - Error on ssh to ubuntu@169.254.0.3:22, result: /bin/bash: connect: Connection refused
/bin/bash: line 1: /dev/tcp/169.254.0.3/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.3/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.3/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''}
2025-10-29 13:32:43,476 - DEBUG - VM ctest-TestvifStats-00326462-95335800 is NOT ready for SSH connections, VM status: ACTIVE
2025-10-29 13:32:48,477 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-29 13:32:48,477 - DEBUG - Waiting to SSH to VM ctest-TestvifStats-00326462-95335800, IP 203.174.195.195, Port 22
2025-10-29 13:32:48,502 - DEBUG - Error on ssh to ubuntu@169.254.0.3:22, result: /bin/bash: connect: Connection refused
/bin/bash: line 1: /dev/tcp/169.254.0.3/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.3/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.3/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''}
2025-10-29 13:32:48,624 - DEBUG - VM ctest-TestvifStats-00326462-95335800 is NOT ready for SSH connections, VM status: ACTIVE
2025-10-29 13:32:53,625 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-29 13:32:53,625 - DEBUG - Waiting to SSH to VM ctest-TestvifStats-00326462-95335800, IP 203.174.195.195, Port 22
2025-10-29 13:32:53,651 - DEBUG - Error on ssh to ubuntu@169.254.0.3:22, result: /bin/bash: connect: Connection refused
/bin/bash: line 1: /dev/tcp/169.254.0.3/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.3/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.3/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''}
2025-10-29 13:32:54,238 - DEBUG - VM ctest-TestvifStats-00326462-95335800 is NOT ready for SSH connections, VM status: ACTIVE
2025-10-29 13:32:59,238 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-29 13:32:59,239 - DEBUG - Waiting to SSH to VM ctest-TestvifStats-00326462-95335800, IP 203.174.195.195, Port 22
2025-10-29 13:32:59,334 - DEBUG - VM ctest-TestvifStats-00326462-95335800 is ready for SSH connections
2025-10-29 13:32:59,335 - INFO - Waiting for VM ctest-TestvifStats-00326462-26346449 to be up..
2025-10-29 13:32:59,430 - DEBUG - VM is in ACTIVE state now
2025-10-29 13:32:59,430 - INFO - VM name : ctest-TestvifStats-00326462-26346449
2025-10-29 13:32:59,517 - DEBUG - VM ctest-TestvifStats-00326462-26346449 ID is c1b0ce39-0567-46aa-92d8-078a3c7a3323
2025-10-29 13:32:59,517 - DEBUG - VM ctest-TestvifStats-00326462-26346449 launched on Node an-jenkins-deploy-platform-ansible-os-4521-2
2025-10-29 13:32:59,601 - DEBUG - Requesting: http://10.0.0.48:8082/virtual-machine/c1b0ce39-0567-46aa-92d8-078a3c7a3323
2025-10-29 13:32:59,611 - DEBUG - Requesting: http://10.0.0.48:8082/virtual-machine-interface/56f29aea-84ad-4bc8-a70e-3e39612f47e6
2025-10-29 13:32:59,621 - DEBUG - Requesting: http://10.0.0.50:8085/Snh_PageReq?x=begin:-1,end:-1,table:db.interface.0,uuid:56f29aea-84ad-4bc8-a70e-3e39612f47e6
2025-10-29 13:32:59,629 - DEBUG - Requesting: http://10.0.0.50:8085/Snh_VrfListReq?name=default-domain:ctest-TestvifStats-00326462:ctest-vn-54622387:ctest-vn-54622387
2025-10-29 13:32:59,635 - DEBUG - Requesting: http://10.0.0.50:8085/Snh_PageReq?x=begin:-1,end:-1,table:db.interface.0,uuid:56f29aea-84ad-4bc8-a70e-3e39612f47e6
2025-10-29 13:33:00,745 - 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=5.82 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=6.10 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 = 5.822/5.963/6.104/0.141 ms')
2025-10-29 13:33:00,745 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-TestvifStats-00326462-26346449 passed
2025-10-29 13:33:00,816 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-29 13:33:00,817 - DEBUG - Waiting to SSH to VM ctest-TestvifStats-00326462-26346449, IP 203.174.195.196, Port 22
2025-10-29 13:33:00,841 - 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': ''}
2025-10-29 13:33:00,940 - DEBUG - VM ctest-TestvifStats-00326462-26346449 is NOT ready for SSH connections, VM status: ACTIVE
2025-10-29 13:33:05,941 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-29 13:33:05,941 - DEBUG - Waiting to SSH to VM ctest-TestvifStats-00326462-26346449, IP 203.174.195.196, Port 22
2025-10-29 13:33:06,032 - DEBUG - VM ctest-TestvifStats-00326462-26346449 is ready for SSH connections
2025-10-29 13:33:06,032 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-29 13:33:06,032 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 203.174.195.196, host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.50, gateway password: c0ntrail123
2025-10-29 13:33:06,033 - DEBUG - ping -s 56 -c 3 -W 1 203.174.195.196
2025-10-29 13:33:36,137 - DEBUG - PING 203.174.195.196 (203.174.195.196) 56(84) bytes of data.
64 bytes from 203.174.195.196: icmp_req=1 ttl=64 time=12.6 ms
64 bytes from 203.174.195.196: icmp_req=2 ttl=64 time=4.12 ms
64 bytes from 203.174.195.196: icmp_req=3 ttl=64 time=5.05 ms
--- 203.174.195.196 ping statistics ---
3 packets transmitted, 3 received, 0% packet loss, time 2006ms
rtt min/avg/max/mdev = 4.128/7.285/12.675/3.830 ms
2025-10-29 13:33:36,137 - INFO - Ping to IP 203.174.195.196 from VM ctest-TestvifStats-00326462-95335800 passed
2025-10-29 13:33:36,137 - INFO - 10.0.0.50
2025-10-29 13:33:36,138 - DEBUG - [10.0.0.50]: Running cmd : vif --list | grep '^vif'
2025-10-29 13:33:36,206 - DEBUG - Output : /bin/bash: line 1: vif: command not found
2025-10-29 13:33:36,211 - INFO - Deleting VM ctest-TestvifStats-00326462-26346449
2025-10-29 13:33:36,301 - INFO - Deleting VM ctest-TestvifStats-00326462-95335800
2025-10-29 13:33:36,404 - INFO - Deleting VN ctest-vn-54622387
2025-10-29 13:33:36,456 - DEBUG - VN 19744a99-1335-45bc-a0b7-340955b08276 still in use: Unable to complete operation on network 19744a99-1335-45bc-a0b7-340955b08276. There are one or more ports still in use on the network.
Neutron server returns request_ids: ['req-afd263ac-0fb3-4e55-a2b1-59e28e11d072']
2025-10-29 13:33:36,456 - WARNING - Deleting VN ctest-vn-54622387 failed..Will retry
2025-10-29 13:33:38,609 - DEBUG - Response for deleting network ()
2025-10-29 13:33:38,609 - DEBUG - Requesting: http://10.0.0.38:8082/routing-instance/bea3d70e-fd7a-4cc2-a9a4-fb8ea9e5b1b1
2025-10-29 13:33:38,615 - DEBUG - Response Code: 404
2025-10-29 13:33:38,615 - DEBUG - Requesting: http://10.0.0.38:8082/domains
2025-10-29 13:33:38,621 - DEBUG - Requesting: http://10.0.0.38:8082/domain/fd9d3a52-0780-4060-8425-e3c883ec81fc
2025-10-29 13:33:38,650 - DEBUG - Requesting: http://10.0.0.38:8082/project/e0f392b0-60bb-4c44-aa13-e7b801f99732
2025-10-29 13:33:38,743 - INFO - Validated that VN ctest-vn-54622387 is not found in API Server
2025-10-29 13:33:38,743 - DEBUG - Requesting: http://10.0.0.49:8085/Snh_VnListReq?name=default-domain:ctest-TestvifStats-00326462:ctest-vn-54622387
2025-10-29 13:33:38,750 - DEBUG - Requesting: http://10.0.0.49:8085/Snh_VrfListReq?name=default-domain:ctest-TestvifStats-00326462:ctest-vn-54622387:ctest-vn-54622387
2025-10-29 13:33:38,755 - DEBUG - VN ctest-vn-54622387 is not present in Agent 10.0.0.49
2025-10-29 13:33:38,755 - DEBUG - Requesting: http://10.0.0.50:8085/Snh_VnListReq?name=default-domain:ctest-TestvifStats-00326462:ctest-vn-54622387
2025-10-29 13:33:38,761 - DEBUG - Requesting: http://10.0.0.50:8085/Snh_VrfListReq?name=default-domain:ctest-TestvifStats-00326462:ctest-vn-54622387:ctest-vn-54622387
2025-10-29 13:33:38,767 - DEBUG - VN ctest-vn-54622387 is not present in Agent 10.0.0.50
2025-10-29 13:33:38,767 - INFO - Validated that VN ctest-vn-54622387 is not in any agent
2025-10-29 13:33:38,767 - DEBUG - Requesting: http://10.0.0.49:8085/Snh_VrfListReq?name=default-domain:ctest-TestvifStats-00326462:ctest-vn-54622387:ctest-vn-54622387
2025-10-29 13:33:38,772 - DEBUG - Requesting: http://10.0.0.50:8085/Snh_VrfListReq?name=default-domain:ctest-TestvifStats-00326462:ctest-vn-54622387:ctest-vn-54622387
2025-10-29 13:33:38,776 - DEBUG - Requesting: http://10.0.0.38:8083/Snh_ShowRoutingInstanceReq?name=default-domain:ctest-TestvifStats-00326462:ctest-vn-54622387:ctest-vn-54622387
2025-10-29 13:33:38,781 - DEBUG - Requesting: http://10.0.0.254:8083/Snh_ShowRoutingInstanceReq?name=default-domain:ctest-TestvifStats-00326462:ctest-vn-54622387:ctest-vn-54622387
2025-10-29 13:33:38,787 - DEBUG - Requesting: http://10.0.0.48:8083/Snh_ShowRoutingInstanceReq?name=default-domain:ctest-TestvifStats-00326462:ctest-vn-54622387:ctest-vn-54622387
2025-10-29 13:33:38,793 - DEBUG - Requesting: http://10.0.0.48:8083/Snh_IFMapTableShowReq?table_name=virtual-network&search_string=virtual-network:default-domain:ctest-TestvifStats-00326462:ctest-vn-54622387
2025-10-29 13:33:38,800 - INFO - Validated that Routing instances and Config db in Control-nodes does not have VN ctest-vn-54622387 info
2025-10-29 13:33:40,072 - ERROR - AssertionError
Python 3.9.21: /usr/bin/python3
Wed Oct 29 13:33:36 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/vrouter/test_vif_stats.py in test_vif_statistics(self=)
124 assert client_fixtures[0].ping_with_certainty(server_fixtures[0].vm_ip, expectation=True), "ping failed"
125 compute_ip = server_fixtures[0].vm_node_ip
126 stats_pre_clr = self.get_vif_stats(compute_ip)
127 assert stats_pre_clr > 0, "vif stats should be greater than 0 before clearing"
128 self.clear_vif_stats(compute_ip)
stats_pre_clr undefined
self =
self.get_vif_stats = >
compute_ip = '10.0.0.50'
/contrail-test/scripts/vrouter/test_vif_stats.py in get_vif_stats(self=, compute_ip='10.0.0.50')
40 continue
41
42 assert vif_ids, "No valid vif interfaces found"
43 self.logger.info("Found vif interfaces: %s" % vif_ids)
44
vif_ids = []
AssertionError: No valid vif interfaces found
__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 = ('No valid vif interfaces found',)
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/vrouter/test_vif_stats.py", line 126, in test_vif_statistics
stats_pre_clr = self.get_vif_stats(compute_ip)
File "/contrail-test/scripts/vrouter/test_vif_stats.py", line 42, in get_vif_stats
assert vif_ids, "No valid vif interfaces found"
AssertionError: No valid vif interfaces found
2025-10-29 13:33:40,072 - DEBUG - Skipping xmpp flap check
2025-10-29 13:33:40,073 - INFO -
2025-10-29 13:33:40,073 - INFO - END TEST : test_vif_statistics : FAILED[0:02:15]
2025-10-29 13:33:40,073 - INFO - --------------------------------------------------------------------------------
2025-10-29 13:33:41,065 - INFO - Deleted project: ctest-TestvifStats-00326462, ID : e0f392b0-60bb-4c44-aa13-e7b801f99732
2025-10-29 13:38:34,398 - DEBUG - [10.0.0.38]: Running cmd : hostname
2025-10-29 13:38:34,924 - DEBUG - Output : cn-jenkins-deploy-platform-ansible-os-4521-1
2025-10-29 13:38:34,924 - DEBUG - [10.0.0.38]: Running cmd : hostname -f
2025-10-29 13:38:34,986 - DEBUG - Output : cn-jenkins-deploy-platform-ansible-os-4521-1.
2025-10-29 13:38:34,986 - DEBUG - [10.0.0.38]: Running cmd : docker ps 2>/dev/null | grep -v "/pause\|/usr/bin/pod\|nova_api_\|contrail.*init\|init.*contrail\|provisioner\|placement" | awk '{print $NF}'
2025-10-29 13:38:35,091 - DEBUG - Output : NAMES
contrail_test_XaS2cHdub
analytics_snmp_nodemgr_1
analytics_snmp_topology_1
analytics_snmp_snmp-collector_1
analytics_alarm_nodemgr_1
analytics_alarm_alarm-gen_1
analytics_alarm_kafka_1
analytics_nodemgr_1
analytics_api_1
analytics_collector_1
analytics_database_nodemgr_1
analytics_database_query-engine_1
analytics_database_cassandra_1
control_named_1
control_control_1
control_nodemgr_1
control_dns_1
webui_web_1
webui_job_1
config_devicemgr_1
config_dnsmasq_1
config_api_1
config_schema_1
config_nodemgr_1
config_svcmonitor_1
config_database_nodemgr_1
config_database_rabbitmq_1
config_database_cassandra_1
config_database_zookeeper_1
redis_redis_1
barbican_worker
barbican_keystone_listener
barbican_api
horizon
heat_engine
heat_api_cfn
heat_api
neutron_server
nova_novncproxy
nova_conductor
nova_api
nova_scheduler
glance_api
keystone
keystone_fernet
keystone_ssh
rabbitmq
memcached
mariadb
cron
kolla_toolbox
fluentd
2025-10-29 13:38:35,091 - DEBUG - [10.0.0.38]: Running cmd : getent hosts 10.0.0.38 | head -n 1 | awk '{print $2}'
2025-10-29 13:38:35,154 - DEBUG - Output : cn-jenkins-deploy-platform-ansible-os-4521-1.
2025-10-29 13:38:35,155 - DEBUG - [10.0.0.38]: Running cmd : ip -4 -o addr show | awk '{print $4}'
2025-10-29 13:38:35,220 - DEBUG - Output : 127.0.0.1/8
10.0.0.38/24
10.20.0.17/24
172.17.0.1/16
2025-10-29 13:38:35,220 - DEBUG - [10.0.0.38]: Running cmd : getent hosts 10.20.0.17 | head -n 1 | awk '{print $2}'
2025-10-29 13:38:35,294 - DEBUG - Output :
2025-10-29 13:38:35,294 - DEBUG - [10.0.0.254]: Running cmd : hostname
2025-10-29 13:38:35,776 - DEBUG - Output : cn-jenkins-deploy-platform-ansible-os-4521-2
2025-10-29 13:38:35,776 - DEBUG - [10.0.0.254]: Running cmd : hostname -f
2025-10-29 13:38:35,837 - DEBUG - Output : cn-jenkins-deploy-platform-ansible-os-4521-2.
2025-10-29 13:38:35,838 - DEBUG - [10.0.0.254]: Running cmd : docker ps 2>/dev/null | grep -v "/pause\|/usr/bin/pod\|nova_api_\|contrail.*init\|init.*contrail\|provisioner\|placement" | awk '{print $NF}'
2025-10-29 13:38:35,919 - DEBUG - Output : NAMES
analytics_snmp_topology_1
analytics_snmp_nodemgr_1
analytics_snmp_snmp-collector_1
analytics_alarm_nodemgr_1
analytics_alarm_alarm-gen_1
analytics_alarm_kafka_1
analytics_collector_1
analytics_api_1
analytics_nodemgr_1
analytics_database_nodemgr_1
analytics_database_query-engine_1
analytics_database_cassandra_1
control_named_1
control_dns_1
control_control_1
control_nodemgr_1
webui_web_1
webui_job_1
config_devicemgr_1
config_nodemgr_1
config_svcmonitor_1
config_schema_1
config_dnsmasq_1
config_api_1
config_database_nodemgr_1
config_database_rabbitmq_1
config_database_cassandra_1
config_database_zookeeper_1
redis_redis_1
2025-10-29 13:38:35,920 - DEBUG - [10.0.0.254]: Running cmd : ip -4 -o addr show | awk '{print $4}'
2025-10-29 13:38:35,986 - DEBUG - Output : 127.0.0.1/8
10.0.0.254/24
10.20.0.254/24
172.17.0.1/16
2025-10-29 13:38:35,986 - DEBUG - [10.0.0.254]: Running cmd : getent hosts 10.0.0.254 | head -n 1 | awk '{print $2}'
2025-10-29 13:38:36,054 - DEBUG - Output : cn-jenkins-deploy-platform-ansible-os-4521-2.
2025-10-29 13:38:36,054 - DEBUG - [10.0.0.254]: Running cmd : getent hosts 10.20.0.254 | head -n 1 | awk '{print $2}'
2025-10-29 13:38:36,128 - DEBUG - Output : cn-jenkins-deploy-platform-ansible-os-4521-2
2025-10-29 13:38:36,128 - DEBUG - [10.0.0.48]: Running cmd : hostname
2025-10-29 13:38:36,689 - DEBUG - Output : cn-jenkins-deploy-platform-ansible-os-4521-3
2025-10-29 13:38:36,689 - DEBUG - [10.0.0.48]: Running cmd : hostname -f
2025-10-29 13:38:36,752 - DEBUG - Output : cn-jenkins-deploy-platform-ansible-os-4521-3.
2025-10-29 13:38:36,752 - DEBUG - [10.0.0.48]: Running cmd : docker ps 2>/dev/null | grep -v "/pause\|/usr/bin/pod\|nova_api_\|contrail.*init\|init.*contrail\|provisioner\|placement" | awk '{print $NF}'
2025-10-29 13:38:36,848 - DEBUG - Output : NAMES
analytics_snmp_nodemgr_1
analytics_snmp_topology_1
analytics_snmp_snmp-collector_1
analytics_alarm_alarm-gen_1
analytics_alarm_nodemgr_1
analytics_alarm_kafka_1
analytics_collector_1
analytics_api_1
analytics_nodemgr_1
analytics_database_nodemgr_1
analytics_database_query-engine_1
analytics_database_cassandra_1
control_named_1
control_dns_1
control_nodemgr_1
control_control_1
webui_web_1
webui_job_1
config_devicemgr_1
config_nodemgr_1
config_schema_1
config_svcmonitor_1
config_dnsmasq_1
config_api_1
config_database_rabbitmq_1
config_database_nodemgr_1
config_database_zookeeper_1
config_database_cassandra_1
redis_redis_1
2025-10-29 13:38:36,849 - DEBUG - [10.0.0.48]: Running cmd : ip -4 -o addr show | awk '{print $4}'
2025-10-29 13:38:36,913 - DEBUG - Output : 127.0.0.1/8
10.0.0.48/24
10.20.0.14/24
172.17.0.1/16
2025-10-29 13:38:36,913 - DEBUG - [10.0.0.48]: Running cmd : getent hosts 10.0.0.48 | head -n 1 | awk '{print $2}'
2025-10-29 13:38:36,981 - DEBUG - Output : cn-jenkins-deploy-platform-ansible-os-4521-3.
2025-10-29 13:38:36,981 - DEBUG - [10.0.0.48]: Running cmd : getent hosts 10.20.0.14 | head -n 1 | awk '{print $2}'
2025-10-29 13:38:37,060 - DEBUG - Output : cn-jenkins-deploy-platform-ansible-os-4521-3
2025-10-29 13:38:37,060 - DEBUG - [10.0.0.49]: Running cmd : hostname
2025-10-29 13:38:37,252 - DEBUG - Output : an-jenkins-deploy-platform-ansible-os-4521-1
2025-10-29 13:38:37,253 - DEBUG - [10.0.0.49]: Running cmd : hostname -f
2025-10-29 13:38:37,318 - DEBUG - Output : an-jenkins-deploy-platform-ansible-os-4521-1.
2025-10-29 13:38:37,319 - DEBUG - [10.0.0.49]: Running cmd : docker ps 2>/dev/null | grep -v "/pause\|/usr/bin/pod\|nova_api_\|contrail.*init\|init.*contrail\|provisioner\|placement" | awk '{print $NF}'
2025-10-29 13:38:37,417 - DEBUG - Output : NAMES
vrouter_vrouter-agent_1
vrouter_nodemgr_1
rsyslogd_rsyslogd_1
nova_compute
nova_libvirt
nova_ssh
cron
kolla_toolbox
fluentd
2025-10-29 13:38:37,418 - DEBUG - [10.0.0.49]: Running cmd : ip -4 -o addr show dev vhost0 | awk '{print $4}'
2025-10-29 13:38:37,479 - DEBUG - Output : 10.20.0.25/24
2025-10-29 13:38:37,479 - DEBUG - [10.0.0.49]: Running cmd : getent hosts 10.20.0.25 | head -n 1 | awk '{print $2}'
2025-10-29 13:38:37,557 - DEBUG - Output : an-jenkins-deploy-platform-ansible-os-4521-1
2025-10-29 13:38:37,557 - DEBUG - [10.0.0.50]: Running cmd : hostname
2025-10-29 13:38:37,739 - DEBUG - Output : an-jenkins-deploy-platform-ansible-os-4521-2
2025-10-29 13:38:37,740 - DEBUG - [10.0.0.50]: Running cmd : hostname -f
2025-10-29 13:38:37,800 - DEBUG - Output : an-jenkins-deploy-platform-ansible-os-4521-2.
2025-10-29 13:38:37,800 - DEBUG - [10.0.0.50]: Running cmd : docker ps 2>/dev/null | grep -v "/pause\|/usr/bin/pod\|nova_api_\|contrail.*init\|init.*contrail\|provisioner\|placement" | awk '{print $NF}'
2025-10-29 13:38:37,885 - DEBUG - Output : NAMES
vrouter_vrouter-agent_1
vrouter_nodemgr_1
rsyslogd_rsyslogd_1
nova_compute
nova_libvirt
nova_ssh
cron
kolla_toolbox
fluentd
2025-10-29 13:38:37,885 - DEBUG - [10.0.0.50]: Running cmd : ip -4 -o addr show dev vhost0 | awk '{print $4}'
2025-10-29 13:38:37,944 - DEBUG - Output : 10.20.0.193/24
2025-10-29 13:38:37,944 - DEBUG - [10.0.0.50]: Running cmd : getent hosts 10.20.0.193 | head -n 1 | awk '{print $2}'
2025-10-29 13:38:38,018 - DEBUG - Output : an-jenkins-deploy-platform-ansible-os-4521-2
2025-10-29 13:38:38,763 - DEBUG - Not creating keypair since it exists
2025-10-29 13:38:38,828 - INFO - Domain Default found not creating
2025-10-29 13:38:39,335 - INFO - Project ctest-TestvifStats-59952535 not found, creating it
2025-10-29 13:38:39,895 - INFO - Created Project:ctest-TestvifStats-59952535, ID : b9c510cb-0005-45f3-8fd6-c606276fb5d5
2025-10-29 13:38:41,482 - INFO - Using existing project ['default-domain', 'admin'](941e9aef-7b03-4547-a8ff-19c13661cb0c)
2025-10-29 13:38:41,865 - INFO - admin user already present
2025-10-29 13:38:42,231 - INFO - Adding rules to the default security group in Project admin
2025-10-29 13:38:42,684 - INFO - ================================================================================
2025-10-29 13:38:42,684 - INFO - STARTING TEST : test_vif_statistics
2025-10-29 13:38:42,685 - INFO - TEST DESCRIPTION :
Description:
Verify vif statistics
Vm's across compute node
steps:
1. create 1 VN and launch 2 VMs in compute node
2. client and server VMs on same node
3. send icmp traffic assert if ping is not working
4. get_vif_stats to check vif interface
5. clear_vif_stats to clear vif interface stats
6. Repeat step4
Pass criteria:
1. If output of vif stats/clear execute successfully from compute
2025-10-29 13:38:43,317 - DEBUG - Skipping xmpp flap check
2025-10-29 13:38:43,317 - INFO - Initial checks done. Running the testcase now
2025-10-29 13:38:43,317 - INFO -
2025-10-29 13:38:43,999 - DEBUG - Response for create_network : {'network': {'id': 'a5b2dfa1-d2c1-4e8f-b320-30f57a1a8242', 'name': 'ctest-vn-48609290', 'tenant_id': 'b9c510cb000545f38fd6c606276fb5d5', 'project_id': 'b9c510cb000545f38fd6c606276fb5d5', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestvifStats-59952535', 'ctest-vn-48609290'], 'port_security_enabled': True, 'description': ''}}
2025-10-29 13:38:44,374 - DEBUG - Response for create_subnet : {'subnet': {'id': '052372a3-6c45-490a-ad5e-73b6895c61e5', 'name': '', 'tenant_id': 'b9c510cb000545f38fd6c606276fb5d5', 'network_id': 'a5b2dfa1-d2c1-4e8f-b320-30f57a1a8242', 'ip_version': 4, 'cidr': '195.43.130.0/26', 'allocation_pools': [{'start': '195.43.130.2', 'end': '195.43.130.62'}], 'gateway_ip': '195.43.130.1', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '195.43.130.2', 'tags': [], 'project_id': 'b9c510cb000545f38fd6c606276fb5d5'}}
2025-10-29 13:38:44,397 - INFO - Created VN ctest-vn-48609290
2025-10-29 13:38:44,408 - DEBUG - VN ctest-vn-48609290 UUID is a5b2dfa1-d2c1-4e8f-b320-30f57a1a8242
2025-10-29 13:38:44,485 - DEBUG - Requesting: http://10.0.0.38:8082/domains
2025-10-29 13:38:44,787 - DEBUG - Requesting: http://10.0.0.38:8082/domains
2025-10-29 13:38:44,818 - DEBUG - Requesting: http://10.0.0.38:8082/domain/fd9d3a52-0780-4060-8425-e3c883ec81fc
2025-10-29 13:38:44,834 - DEBUG - Requesting: http://10.0.0.38:8082/project/b9c510cb-0005-45f3-8fd6-c606276fb5d5
2025-10-29 13:38:44,937 - DEBUG - Requesting: http://10.0.0.38:8082/virtual-network/a5b2dfa1-d2c1-4e8f-b320-30f57a1a8242
2025-10-29 13:38:44,954 - DEBUG - Requesting: http://10.0.0.38:8082/virtual-network/a5b2dfa1-d2c1-4e8f-b320-30f57a1a8242
2025-10-29 13:38:44,967 - DEBUG - Requesting: http://10.0.0.38:8082/routing-instance/2f195bfa-971c-40dc-b5c2-8efda3f45125
2025-10-29 13:38:44,980 - DEBUG - Requesting: http://10.0.0.38:8082/routing-instance/2f195bfa-971c-40dc-b5c2-8efda3f45125
2025-10-29 13:38:44,989 - DEBUG - Requesting: http://10.0.0.38:8082/route-target/e96763a6-241e-4810-aa84-f9e277338bd6
2025-10-29 13:38:44,996 - DEBUG - Route Targets: ['target:64512:8000006']
2025-10-29 13:38:44,996 - DEBUG - Requesting: http://10.0.0.38:8082/virtual-network/a5b2dfa1-d2c1-4e8f-b320-30f57a1a8242
2025-10-29 13:38:45,007 - DEBUG - Requesting: http://10.0.0.38:8082/routing-instance/2f195bfa-971c-40dc-b5c2-8efda3f45125
2025-10-29 13:38:45,024 - INFO - Verified VN network id 16 for VN a5b2dfa1-d2c1-4e8f-b320-30f57a1a8242
2025-10-29 13:38:45,026 - INFO - Verifications in API Server for VN ctest-vn-48609290 passed
2025-10-29 13:38:45,026 - DEBUG - Requesting: http://10.0.0.38:8082/virtual-network/a5b2dfa1-d2c1-4e8f-b320-30f57a1a8242
2025-10-29 13:38:45,036 - DEBUG - Requesting: http://10.0.0.38:8082/routing-instance/2f195bfa-971c-40dc-b5c2-8efda3f45125
2025-10-29 13:38:45,044 - DEBUG - Requesting: http://10.0.0.38:8082/routing-instance/2f195bfa-971c-40dc-b5c2-8efda3f45125
2025-10-29 13:38:45,055 - DEBUG - Requesting: http://10.0.0.38:8082/route-target/e96763a6-241e-4810-aa84-f9e277338bd6
2025-10-29 13:38:45,064 - DEBUG - Requesting: http://10.0.0.38:8083/Snh_IFMapTableShowReq?table_name=virtual-network&search_string=virtual-network:default-domain:ctest-TestvifStats-59952535:ctest-vn-48609290
2025-10-29 13:38:45,073 - DEBUG - Control-node 10.0.0.38 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestvifStats-59952535:ctest-vn-48609290', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestvifStats-59952535', 'owner-access': '7', 'group': 'admin', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '11939851448231218831', 'uuid-lslong': '12907370362917519938'}, 'enable': 'true', 'created': '2025-10-29T13:38:43', 'last-modified': '2025-10-29T13:38:44', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.806097'}
2025-10-29 13:38:45,073 - DEBUG - Requesting: http://10.0.0.38:8083/Snh_ShowRoutingInstanceReq?name=default-domain:ctest-TestvifStats-59952535:ctest-vn-48609290:ctest-vn-48609290
2025-10-29 13:38:45,082 - DEBUG - Route Targets: ['target:64512:8000006']
2025-10-29 13:38:45,082 - DEBUG - Requesting: http://10.0.0.254:8083/Snh_IFMapTableShowReq?table_name=virtual-network&search_string=virtual-network:default-domain:ctest-TestvifStats-59952535:ctest-vn-48609290
2025-10-29 13:38:45,088 - DEBUG - Control-node 10.0.0.254 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestvifStats-59952535:ctest-vn-48609290', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestvifStats-59952535', 'owner-access': '7', 'group': 'admin', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '11939851448231218831', 'uuid-lslong': '12907370362917519938'}, 'enable': 'true', 'created': '2025-10-29T13:38:43', 'last-modified': '2025-10-29T13:38:44', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.816089'}
2025-10-29 13:38:45,088 - DEBUG - Requesting: http://10.0.0.254:8083/Snh_ShowRoutingInstanceReq?name=default-domain:ctest-TestvifStats-59952535:ctest-vn-48609290:ctest-vn-48609290
2025-10-29 13:38:45,103 - DEBUG - Route Targets: ['target:64512:8000006']
2025-10-29 13:38:45,103 - DEBUG - Requesting: http://10.0.0.48:8083/Snh_IFMapTableShowReq?table_name=virtual-network&search_string=virtual-network:default-domain:ctest-TestvifStats-59952535:ctest-vn-48609290
2025-10-29 13:38:45,111 - DEBUG - Control-node 10.0.0.48 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestvifStats-59952535:ctest-vn-48609290', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestvifStats-59952535', 'owner-access': '7', 'group': 'admin', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '11939851448231218831', 'uuid-lslong': '12907370362917519938'}, 'enable': 'true', 'created': '2025-10-29T13:38:43', 'last-modified': '2025-10-29T13:38:44', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.847329'}
2025-10-29 13:38:45,111 - DEBUG - Requesting: http://10.0.0.48:8083/Snh_ShowRoutingInstanceReq?name=default-domain:ctest-TestvifStats-59952535:ctest-vn-48609290:ctest-vn-48609290
2025-10-29 13:38:45,123 - DEBUG - Route Targets: ['target:64512:8000006']
2025-10-29 13:38:45,123 - INFO - On all control nodes, Config, RI and RT verification for VN ctest-vn-48609290 passed
2025-10-29 13:38:45,124 - DEBUG - ====Verifying policy data for ctest-vn-48609290 in API_Server ======
2025-10-29 13:38:45,124 - DEBUG - Requesting: http://10.0.0.38:8082/domains
2025-10-29 13:38:45,131 - DEBUG - Requesting: http://10.0.0.38:8082/domain/fd9d3a52-0780-4060-8425-e3c883ec81fc
2025-10-29 13:38:45,143 - DEBUG - Requesting: http://10.0.0.38:8082/project/b9c510cb-0005-45f3-8fd6-c606276fb5d5
2025-10-29 13:38:45,237 - DEBUG - Requesting: http://10.0.0.38:8082/virtual-network/a5b2dfa1-d2c1-4e8f-b320-30f57a1a8242
2025-10-29 13:38:45,247 - DEBUG - =>VN ctest-vn-48609290 has no policy to be verified
2025-10-29 13:38:45,248 - DEBUG - Verifying the vn in opserver
2025-10-29 13:38:45,248 - DEBUG - Verifying the default-domain:ctest-TestvifStats-59952535:ctest-vn-48609290 virtual network link through opserver 10.0.0.38
2025-10-29 13:38:45,248 - DEBUG - Requesting: http://10.0.0.38:8081/analytics/uves/virtual-networks
2025-10-29 13:38:45,559 - DEBUG - Requesting: http://10.0.0.38:8081/analytics/uves/virtual-networks
2025-10-29 13:38:45,620 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestvifStats-59952535:ctest-vn-48609290', 'href': 'http://10.0.0.38:8081/analytics/uves/virtual-network/default-domain:ctest-TestvifStats-59952535:ctest-vn-48609290?flat'}
2025-10-29 13:38:45,620 - DEBUG - Verifying the default-domain:ctest-TestvifStats-59952535:ctest-vn-48609290 virtual network link through opserver 10.0.0.254
2025-10-29 13:38:45,620 - DEBUG - Requesting: http://10.0.0.254:8081/analytics/uves/virtual-networks
2025-10-29 13:38:45,942 - DEBUG - Requesting: http://10.0.0.254:8081/analytics/uves/virtual-networks
2025-10-29 13:38:46,014 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestvifStats-59952535:ctest-vn-48609290', 'href': 'http://10.0.0.254:8081/analytics/uves/virtual-network/default-domain:ctest-TestvifStats-59952535:ctest-vn-48609290?flat'}
2025-10-29 13:38:46,014 - DEBUG - Verifying the default-domain:ctest-TestvifStats-59952535:ctest-vn-48609290 virtual network link through opserver 10.0.0.48
2025-10-29 13:38:46,015 - DEBUG - Requesting: http://10.0.0.48:8081/analytics/uves/virtual-networks
2025-10-29 13:38:46,315 - DEBUG - Requesting: http://10.0.0.48:8081/analytics/uves/virtual-networks
2025-10-29 13:38:46,377 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestvifStats-59952535:ctest-vn-48609290', 'href': 'http://10.0.0.48:8081/analytics/uves/virtual-network/default-domain:ctest-TestvifStats-59952535:ctest-vn-48609290?flat'}
2025-10-29 13:38:46,377 - INFO - Validated that VN default-domain:ctest-TestvifStats-59952535:ctest-vn-48609290 is found in opserver
2025-10-29 13:38:46,377 - DEBUG - Requesting: http://10.0.0.49:8085/Snh_VrfListReq?name=default-domain:ctest-TestvifStats-59952535:ctest-vn-48609290:ctest-vn-48609290
2025-10-29 13:38:46,384 - DEBUG - Requesting: http://10.0.0.50:8085/Snh_VrfListReq?name=default-domain:ctest-TestvifStats-59952535:ctest-vn-48609290:ctest-vn-48609290
2025-10-29 13:38:46,390 - DEBUG - Requesting: http://10.0.0.49:8085/Snh_VrfListReq?name=default-domain:ctest-TestvifStats-59952535:ctest-vn-48609290:ctest-vn-48609290
2025-10-29 13:38:46,395 - DEBUG - Requesting: http://10.0.0.50:8085/Snh_VrfListReq?name=default-domain:ctest-TestvifStats-59952535:ctest-vn-48609290:ctest-vn-48609290
2025-10-29 13:38:46,400 - DEBUG - Do not have enough data to verify VN in agent
2025-10-29 13:38:46,400 - DEBUG - Requesting: http://10.0.0.49:8085/Snh_VrfListReq?name=default-domain:ctest-TestvifStats-59952535:ctest-vn-48609290:ctest-vn-48609290
2025-10-29 13:38:46,405 - DEBUG - Requesting: http://10.0.0.50:8085/Snh_VrfListReq?name=default-domain:ctest-TestvifStats-59952535:ctest-vn-48609290:ctest-vn-48609290
2025-10-29 13:38:46,409 - DEBUG - VRF ids for VN ctest-vn-48609290: {}
2025-10-29 13:38:46,438 - DEBUG - Services list from nova: [, , , ]
2025-10-29 13:38:46,439 - DEBUG - Hosts: {'nova': ['an-jenkins-deploy-platform-ansible-os-4521-2', 'an-jenkins-deploy-platform-ansible-os-4521-1']}
2025-10-29 13:38:46,439 - DEBUG - Hosts: {'nova': ['an-jenkins-deploy-platform-ansible-os-4521-2', 'an-jenkins-deploy-platform-ansible-os-4521-1']}
2025-10-29 13:38:47,763 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-4521-2), Zone: (nova:an-jenkins-deploy-platform-ansible-os-4521-2)
2025-10-29 13:38:47,763 - DEBUG - Hosts: {'nova': ['an-jenkins-deploy-platform-ansible-os-4521-2', 'an-jenkins-deploy-platform-ansible-os-4521-1']}
2025-10-29 13:38:49,365 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-4521-2), Zone: (nova:an-jenkins-deploy-platform-ansible-os-4521-2)
2025-10-29 13:38:49,366 - INFO - Waiting for VM ctest-TestvifStats-59952535-83546733 to be up..
2025-10-29 13:38:49,464 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2025-10-29 13:38:54,557 - DEBUG - VM is in ACTIVE state now
2025-10-29 13:38:54,558 - INFO - VM name : ctest-TestvifStats-59952535-83546733
2025-10-29 13:38:54,675 - DEBUG - VM ctest-TestvifStats-59952535-83546733 ID is d540f6c8-d3db-4017-9520-c56722a18cb2
2025-10-29 13:38:54,708 - DEBUG - VM ctest-TestvifStats-59952535-83546733 launched on Node an-jenkins-deploy-platform-ansible-os-4521-2
2025-10-29 13:38:54,805 - DEBUG - Requesting: http://10.0.0.48:8082/virtual-machine/d540f6c8-d3db-4017-9520-c56722a18cb2
2025-10-29 13:38:55,129 - DEBUG - Requesting: http://10.0.0.48:8082/virtual-machine/d540f6c8-d3db-4017-9520-c56722a18cb2
2025-10-29 13:38:55,170 - DEBUG - Requesting: http://10.0.0.48:8082/virtual-machine-interface/ad05eafa-d58e-4cc0-b784-0f464188daef
2025-10-29 13:38:55,181 - DEBUG - Requesting: http://10.0.0.50:8085/Snh_PageReq?x=begin:-1,end:-1,table:db.interface.0,uuid:ad05eafa-d58e-4cc0-b784-0f464188daef
2025-10-29 13:38:55,187 - DEBUG - Requesting: http://10.0.0.50:8085/Snh_VrfListReq?name=default-domain:ctest-TestvifStats-59952535:ctest-vn-48609290:ctest-vn-48609290
2025-10-29 13:38:55,192 - DEBUG - Requesting: http://10.0.0.50:8085/Snh_PageReq?x=begin:-1,end:-1,table:db.interface.0,uuid:ad05eafa-d58e-4cc0-b784-0f464188daef
2025-10-29 13:38:58,295 - DEBUG - (True, 'PING 169.254.0.4 (169.254.0.4) 56(84) bytes of data.\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1001ms')
2025-10-29 13:38:58,295 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-TestvifStats-59952535-83546733 failed!
2025-10-29 13:38:58,312 - DEBUG - Gateway for vn default-domain:ctest-TestvifStats-59952535:ctest-vn-48609290 is 195.43.130.1 and allocation pool is NOT set
2025-10-29 13:39:02,359 - DEBUG - (True, 'PING 169.254.0.4 (169.254.0.4) 56(84) bytes of data.\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1021ms')
2025-10-29 13:39:02,359 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-TestvifStats-59952535-83546733 failed!
2025-10-29 13:39:02,376 - DEBUG - Gateway for vn default-domain:ctest-TestvifStats-59952535:ctest-vn-48609290 is 195.43.130.1 and allocation pool is NOT set
2025-10-29 13:39:06,421 - DEBUG - (True, 'PING 169.254.0.4 (169.254.0.4) 56(84) bytes of data.\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1022ms')
2025-10-29 13:39:06,422 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-TestvifStats-59952535-83546733 failed!
2025-10-29 13:39:06,440 - DEBUG - Gateway for vn default-domain:ctest-TestvifStats-59952535:ctest-vn-48609290 is 195.43.130.1 and allocation pool is NOT set
2025-10-29 13:39:10,479 - DEBUG - (True, 'PING 169.254.0.4 (169.254.0.4) 56(84) bytes of data.\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1021ms')
2025-10-29 13:39:10,479 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-TestvifStats-59952535-83546733 failed!
2025-10-29 13:39:10,495 - DEBUG - Gateway for vn default-domain:ctest-TestvifStats-59952535:ctest-vn-48609290 is 195.43.130.1 and allocation pool is NOT set
2025-10-29 13:39:14,550 - DEBUG - (True, 'PING 169.254.0.4 (169.254.0.4) 56(84) bytes of data.\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1034ms')
2025-10-29 13:39:14,550 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-TestvifStats-59952535-83546733 failed!
2025-10-29 13:39:14,564 - DEBUG - Gateway for vn default-domain:ctest-TestvifStats-59952535:ctest-vn-48609290 is 195.43.130.1 and allocation pool is NOT set
2025-10-29 13:39:18,611 - DEBUG - (True, 'PING 169.254.0.4 (169.254.0.4) 56(84) bytes of data.\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1027ms')
2025-10-29 13:39:18,611 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-TestvifStats-59952535-83546733 failed!
2025-10-29 13:39:18,628 - DEBUG - Gateway for vn default-domain:ctest-TestvifStats-59952535:ctest-vn-48609290 is 195.43.130.1 and allocation pool is NOT set
2025-10-29 13:39:22,675 - DEBUG - (True, 'PING 169.254.0.4 (169.254.0.4) 56(84) bytes of data.\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1028ms')
2025-10-29 13:39:22,675 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-TestvifStats-59952535-83546733 failed!
2025-10-29 13:39:22,690 - DEBUG - Gateway for vn default-domain:ctest-TestvifStats-59952535:ctest-vn-48609290 is 195.43.130.1 and allocation pool is NOT set
2025-10-29 13:39:26,738 - DEBUG - (True, 'PING 169.254.0.4 (169.254.0.4) 56(84) bytes of data.\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1028ms')
2025-10-29 13:39:26,738 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-TestvifStats-59952535-83546733 failed!
2025-10-29 13:39:26,754 - DEBUG - Gateway for vn default-domain:ctest-TestvifStats-59952535:ctest-vn-48609290 is 195.43.130.1 and allocation pool is NOT set
2025-10-29 13:39:30,806 - DEBUG - (True, 'PING 169.254.0.4 (169.254.0.4) 56(84) bytes of data.\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1030ms')
2025-10-29 13:39:30,806 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-TestvifStats-59952535-83546733 failed!
2025-10-29 13:39:30,824 - DEBUG - Gateway for vn default-domain:ctest-TestvifStats-59952535:ctest-vn-48609290 is 195.43.130.1 and allocation pool is NOT set
2025-10-29 13:39:34,871 - DEBUG - (True, 'PING 169.254.0.4 (169.254.0.4) 56(84) bytes of data.\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1027ms')
2025-10-29 13:39:34,871 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-TestvifStats-59952535-83546733 failed!
2025-10-29 13:39:34,888 - DEBUG - Gateway for vn default-domain:ctest-TestvifStats-59952535:ctest-vn-48609290 is 195.43.130.1 and allocation pool is NOT set
2025-10-29 13:39:36,907 - 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=5.97 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=2.72 ms\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1001ms\r\nrtt min/avg/max/mdev = 2.719/4.342/5.966/1.623 ms')
2025-10-29 13:39:36,907 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-TestvifStats-59952535-83546733 passed
2025-10-29 13:39:36,984 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-29 13:39:36,984 - DEBUG - Waiting to SSH to VM ctest-TestvifStats-59952535-83546733, IP 195.43.130.3, Port 22
2025-10-29 13:39:37,008 - 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': ''}
2025-10-29 13:39:37,103 - DEBUG - VM ctest-TestvifStats-59952535-83546733 is NOT ready for SSH connections, VM status: ACTIVE
2025-10-29 13:39:42,104 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-29 13:39:42,104 - DEBUG - Waiting to SSH to VM ctest-TestvifStats-59952535-83546733, IP 195.43.130.3, Port 22
2025-10-29 13:39:42,140 - 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': ''}
2025-10-29 13:39:42,233 - DEBUG - VM ctest-TestvifStats-59952535-83546733 is NOT ready for SSH connections, VM status: ACTIVE
2025-10-29 13:39:47,234 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-29 13:39:47,234 - DEBUG - Waiting to SSH to VM ctest-TestvifStats-59952535-83546733, IP 195.43.130.3, Port 22
2025-10-29 13:39:47,258 - 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': ''}
2025-10-29 13:39:47,360 - DEBUG - VM ctest-TestvifStats-59952535-83546733 is NOT ready for SSH connections, VM status: ACTIVE
2025-10-29 13:39:52,360 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-29 13:39:52,361 - DEBUG - Waiting to SSH to VM ctest-TestvifStats-59952535-83546733, IP 195.43.130.3, Port 22
2025-10-29 13:39:52,385 - 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': ''}
2025-10-29 13:39:52,490 - DEBUG - VM ctest-TestvifStats-59952535-83546733 is NOT ready for SSH connections, VM status: ACTIVE
2025-10-29 13:39:57,490 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-29 13:39:57,491 - DEBUG - Waiting to SSH to VM ctest-TestvifStats-59952535-83546733, IP 195.43.130.3, Port 22
2025-10-29 13:39:57,572 - DEBUG - VM ctest-TestvifStats-59952535-83546733 is ready for SSH connections
2025-10-29 13:39:57,572 - INFO - Waiting for VM ctest-TestvifStats-59952535-30794691 to be up..
2025-10-29 13:39:57,668 - DEBUG - VM is in ACTIVE state now
2025-10-29 13:39:57,668 - INFO - VM name : ctest-TestvifStats-59952535-30794691
2025-10-29 13:39:57,760 - DEBUG - VM ctest-TestvifStats-59952535-30794691 ID is 6b4618db-1763-4181-a822-93826a252393
2025-10-29 13:39:57,760 - DEBUG - VM ctest-TestvifStats-59952535-30794691 launched on Node an-jenkins-deploy-platform-ansible-os-4521-2
2025-10-29 13:39:57,853 - DEBUG - Requesting: http://10.0.0.48:8082/virtual-machine/6b4618db-1763-4181-a822-93826a252393
2025-10-29 13:39:57,865 - DEBUG - Requesting: http://10.0.0.48:8082/virtual-machine-interface/2bb6a52f-0fd5-4fab-b68c-fe620d8b7954
2025-10-29 13:39:57,876 - DEBUG - Requesting: http://10.0.0.50:8085/Snh_PageReq?x=begin:-1,end:-1,table:db.interface.0,uuid:2bb6a52f-0fd5-4fab-b68c-fe620d8b7954
2025-10-29 13:39:57,882 - DEBUG - Requesting: http://10.0.0.50:8085/Snh_VrfListReq?name=default-domain:ctest-TestvifStats-59952535:ctest-vn-48609290:ctest-vn-48609290
2025-10-29 13:39:57,887 - DEBUG - Requesting: http://10.0.0.50:8085/Snh_PageReq?x=begin:-1,end:-1,table:db.interface.0,uuid:2bb6a52f-0fd5-4fab-b68c-fe620d8b7954
2025-10-29 13:39:58,991 - DEBUG - (True, 'PING 169.254.0.5 (169.254.0.5) 56(84) bytes of data.\r\n64 bytes from 169.254.0.5: icmp_seq=1 ttl=63 time=17.0 ms\r\n64 bytes from 169.254.0.5: icmp_seq=2 ttl=63 time=3.01 ms\r\n\r\n--- 169.254.0.5 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1001ms\r\nrtt min/avg/max/mdev = 3.008/9.995/16.983/6.987 ms')
2025-10-29 13:39:58,991 - INFO - Ping to Metadata IP 169.254.0.5 of VM ctest-TestvifStats-59952535-30794691 passed
2025-10-29 13:39:59,060 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-29 13:39:59,061 - DEBUG - Waiting to SSH to VM ctest-TestvifStats-59952535-30794691, IP 195.43.130.4, Port 22
2025-10-29 13:39:59,148 - DEBUG - VM ctest-TestvifStats-59952535-30794691 is ready for SSH connections
2025-10-29 13:39:59,148 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-29 13:39:59,148 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 195.43.130.4, host_string: ubuntu@169.254.0.4, password: ubuntugateway: ubuntu@10.0.0.50, gateway password: c0ntrail123
2025-10-29 13:39:59,149 - DEBUG - ping -s 56 -c 3 -W 1 195.43.130.4
2025-10-29 13:40:28,847 - DEBUG - PING 195.43.130.4 (195.43.130.4) 56(84) bytes of data.
64 bytes from 195.43.130.4: icmp_req=1 ttl=64 time=18.5 ms
64 bytes from 195.43.130.4: icmp_req=2 ttl=64 time=4.08 ms
64 bytes from 195.43.130.4: icmp_req=3 ttl=64 time=2.81 ms
--- 195.43.130.4 ping statistics ---
3 packets transmitted, 3 received, 0% packet loss, time 2004ms
rtt min/avg/max/mdev = 2.815/8.474/18.521/7.123 ms
2025-10-29 13:40:28,847 - INFO - Ping to IP 195.43.130.4 from VM ctest-TestvifStats-59952535-83546733 passed
2025-10-29 13:40:28,847 - INFO - 10.0.0.50
2025-10-29 13:40:28,848 - DEBUG - [10.0.0.50]: Running cmd : vif --list | grep '^vif'
2025-10-29 13:40:28,975 - DEBUG - Output : /bin/bash: line 1: vif: command not found
2025-10-29 13:40:28,980 - INFO - Deleting VM ctest-TestvifStats-59952535-30794691
2025-10-29 13:40:29,064 - INFO - Deleting VM ctest-TestvifStats-59952535-83546733
2025-10-29 13:40:29,283 - INFO - Deleting VN ctest-vn-48609290
2025-10-29 13:40:29,331 - DEBUG - VN a5b2dfa1-d2c1-4e8f-b320-30f57a1a8242 still in use: Unable to complete operation on network a5b2dfa1-d2c1-4e8f-b320-30f57a1a8242. There are one or more ports still in use on the network.
Neutron server returns request_ids: ['req-dc7122e4-6aba-44f9-8360-3dbdb5d7eed6']
2025-10-29 13:40:29,331 - WARNING - Deleting VN ctest-vn-48609290 failed..Will retry
2025-10-29 13:40:31,480 - DEBUG - Response for deleting network ()
2025-10-29 13:40:31,480 - DEBUG - Requesting: http://10.0.0.38:8082/routing-instance/2f195bfa-971c-40dc-b5c2-8efda3f45125
2025-10-29 13:40:31,487 - DEBUG - Response Code: 404
2025-10-29 13:40:31,487 - DEBUG - Requesting: http://10.0.0.38:8082/domains
2025-10-29 13:40:31,493 - DEBUG - Requesting: http://10.0.0.38:8082/domain/fd9d3a52-0780-4060-8425-e3c883ec81fc
2025-10-29 13:40:31,512 - DEBUG - Requesting: http://10.0.0.38:8082/project/b9c510cb-0005-45f3-8fd6-c606276fb5d5
2025-10-29 13:40:31,605 - INFO - Validated that VN ctest-vn-48609290 is not found in API Server
2025-10-29 13:40:31,605 - DEBUG - Requesting: http://10.0.0.49:8085/Snh_VnListReq?name=default-domain:ctest-TestvifStats-59952535:ctest-vn-48609290
2025-10-29 13:40:31,614 - DEBUG - Requesting: http://10.0.0.49:8085/Snh_VrfListReq?name=default-domain:ctest-TestvifStats-59952535:ctest-vn-48609290:ctest-vn-48609290
2025-10-29 13:40:31,620 - DEBUG - VN ctest-vn-48609290 is not present in Agent 10.0.0.49
2025-10-29 13:40:31,620 - DEBUG - Requesting: http://10.0.0.50:8085/Snh_VnListReq?name=default-domain:ctest-TestvifStats-59952535:ctest-vn-48609290
2025-10-29 13:40:31,626 - DEBUG - Requesting: http://10.0.0.50:8085/Snh_VrfListReq?name=default-domain:ctest-TestvifStats-59952535:ctest-vn-48609290:ctest-vn-48609290
2025-10-29 13:40:31,631 - DEBUG - VN ctest-vn-48609290 is not present in Agent 10.0.0.50
2025-10-29 13:40:31,631 - INFO - Validated that VN ctest-vn-48609290 is not in any agent
2025-10-29 13:40:31,631 - DEBUG - Requesting: http://10.0.0.49:8085/Snh_VrfListReq?name=default-domain:ctest-TestvifStats-59952535:ctest-vn-48609290:ctest-vn-48609290
2025-10-29 13:40:31,641 - DEBUG - Requesting: http://10.0.0.50:8085/Snh_VrfListReq?name=default-domain:ctest-TestvifStats-59952535:ctest-vn-48609290:ctest-vn-48609290
2025-10-29 13:40:31,646 - DEBUG - Requesting: http://10.0.0.38:8083/Snh_ShowRoutingInstanceReq?name=default-domain:ctest-TestvifStats-59952535:ctest-vn-48609290:ctest-vn-48609290
2025-10-29 13:40:31,651 - DEBUG - Requesting: http://10.0.0.254:8083/Snh_ShowRoutingInstanceReq?name=default-domain:ctest-TestvifStats-59952535:ctest-vn-48609290:ctest-vn-48609290
2025-10-29 13:40:31,657 - DEBUG - Requesting: http://10.0.0.48:8083/Snh_ShowRoutingInstanceReq?name=default-domain:ctest-TestvifStats-59952535:ctest-vn-48609290:ctest-vn-48609290
2025-10-29 13:40:31,663 - DEBUG - Requesting: http://10.0.0.48:8083/Snh_IFMapTableShowReq?table_name=virtual-network&search_string=virtual-network:default-domain:ctest-TestvifStats-59952535:ctest-vn-48609290
2025-10-29 13:40:31,669 - INFO - Validated that Routing instances and Config db in Control-nodes does not have VN ctest-vn-48609290 info
2025-10-29 13:40:32,962 - ERROR - AssertionError
Python 3.9.21: /usr/bin/python3
Wed Oct 29 13:40:28 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/vrouter/test_vif_stats.py in test_vif_statistics(self=)
125 assert client_fixtures[0].ping_with_certainty(server_fixtures[0].vm_ip, expectation=True), "ping failed"
126 compute_ip = server_fixtures[0].vm_node_ip
127 stats_pre_clr = self.get_vif_stats(compute_ip)
128 assert stats_pre_clr > 0, "vif stats should be greater than 0 before clearing"
129 self.clear_vif_stats(compute_ip)
stats_pre_clr undefined
self =
self.get_vif_stats = >
compute_ip = '10.0.0.50'
/contrail-test/scripts/vrouter/test_vif_stats.py in get_vif_stats(self=, compute_ip='10.0.0.50')
41 continue
42
43 assert vif_ids, "No valid vif interfaces found"
44 self.logger.info("Found vif interfaces: %s" % vif_ids)
45
vif_ids = []
AssertionError: No valid vif interfaces found
__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 = ('No valid vif interfaces found',)
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/vrouter/test_vif_stats.py", line 127, in test_vif_statistics
stats_pre_clr = self.get_vif_stats(compute_ip)
File "/contrail-test/scripts/vrouter/test_vif_stats.py", line 43, in get_vif_stats
assert vif_ids, "No valid vif interfaces found"
AssertionError: No valid vif interfaces found
2025-10-29 13:40:32,963 - DEBUG - Skipping xmpp flap check
2025-10-29 13:40:32,963 - INFO -
2025-10-29 13:40:32,963 - INFO - END TEST : test_vif_statistics : FAILED[0:01:50]
2025-10-29 13:40:32,963 - INFO - --------------------------------------------------------------------------------
2025-10-29 13:40:33,798 - INFO - Deleted project: ctest-TestvifStats-59952535, ID : b9c510cb-0005-45f3-8fd6-c606276fb5d5
2025-10-29 13:44:02,978 - DEBUG - [10.0.0.38]: Running cmd : hostname
2025-10-29 13:44:03,528 - DEBUG - Output : cn-jenkins-deploy-platform-ansible-os-4521-1
2025-10-29 13:44:03,528 - DEBUG - [10.0.0.38]: Running cmd : hostname -f
2025-10-29 13:44:03,602 - DEBUG - Output : cn-jenkins-deploy-platform-ansible-os-4521-1.
2025-10-29 13:44:03,602 - DEBUG - [10.0.0.38]: Running cmd : docker ps 2>/dev/null | grep -v "/pause\|/usr/bin/pod\|nova_api_\|contrail.*init\|init.*contrail\|provisioner\|placement" | awk '{print $NF}'
2025-10-29 13:44:03,716 - DEBUG - Output : NAMES
contrail_test_XaS2cHdub
analytics_snmp_nodemgr_1
analytics_snmp_topology_1
analytics_snmp_snmp-collector_1
analytics_alarm_nodemgr_1
analytics_alarm_alarm-gen_1
analytics_alarm_kafka_1
analytics_nodemgr_1
analytics_api_1
analytics_collector_1
analytics_database_nodemgr_1
analytics_database_query-engine_1
analytics_database_cassandra_1
control_named_1
control_control_1
control_nodemgr_1
control_dns_1
webui_web_1
webui_job_1
config_devicemgr_1
config_dnsmasq_1
config_api_1
config_schema_1
config_nodemgr_1
config_svcmonitor_1
config_database_nodemgr_1
config_database_rabbitmq_1
config_database_cassandra_1
config_database_zookeeper_1
redis_redis_1
barbican_worker
barbican_keystone_listener
barbican_api
horizon
heat_engine
heat_api_cfn
heat_api
neutron_server
nova_novncproxy
nova_conductor
nova_api
nova_scheduler
glance_api
keystone
keystone_fernet
keystone_ssh
rabbitmq
memcached
mariadb
cron
kolla_toolbox
fluentd
2025-10-29 13:44:03,716 - DEBUG - [10.0.0.38]: Running cmd : getent hosts 10.0.0.38 | head -n 1 | awk '{print $2}'
2025-10-29 13:44:03,789 - DEBUG - Output : cn-jenkins-deploy-platform-ansible-os-4521-1.
2025-10-29 13:44:03,789 - DEBUG - [10.0.0.38]: Running cmd : ip -4 -o addr show | awk '{print $4}'
2025-10-29 13:44:03,846 - DEBUG - Output : 127.0.0.1/8
10.0.0.38/24
10.20.0.17/24
172.17.0.1/16
2025-10-29 13:44:03,846 - DEBUG - [10.0.0.38]: Running cmd : getent hosts 10.20.0.17 | head -n 1 | awk '{print $2}'
2025-10-29 13:44:03,923 - DEBUG - Output :
2025-10-29 13:44:03,923 - DEBUG - [10.0.0.254]: Running cmd : hostname
2025-10-29 13:44:04,423 - DEBUG - Output : cn-jenkins-deploy-platform-ansible-os-4521-2
2025-10-29 13:44:04,423 - DEBUG - [10.0.0.254]: Running cmd : hostname -f
2025-10-29 13:44:04,487 - DEBUG - Output : cn-jenkins-deploy-platform-ansible-os-4521-2.
2025-10-29 13:44:04,487 - DEBUG - [10.0.0.254]: Running cmd : docker ps 2>/dev/null | grep -v "/pause\|/usr/bin/pod\|nova_api_\|contrail.*init\|init.*contrail\|provisioner\|placement" | awk '{print $NF}'
2025-10-29 13:44:04,591 - DEBUG - Output : NAMES
analytics_snmp_topology_1
analytics_snmp_nodemgr_1
analytics_snmp_snmp-collector_1
analytics_alarm_nodemgr_1
analytics_alarm_alarm-gen_1
analytics_alarm_kafka_1
analytics_collector_1
analytics_api_1
analytics_nodemgr_1
analytics_database_nodemgr_1
analytics_database_query-engine_1
analytics_database_cassandra_1
control_named_1
control_dns_1
control_control_1
control_nodemgr_1
webui_web_1
webui_job_1
config_devicemgr_1
config_nodemgr_1
config_svcmonitor_1
config_schema_1
config_dnsmasq_1
config_api_1
config_database_nodemgr_1
config_database_rabbitmq_1
config_database_cassandra_1
config_database_zookeeper_1
redis_redis_1
2025-10-29 13:44:04,592 - DEBUG - [10.0.0.254]: Running cmd : ip -4 -o addr show | awk '{print $4}'
2025-10-29 13:44:04,659 - DEBUG - Output : 127.0.0.1/8
10.0.0.254/24
10.20.0.254/24
172.17.0.1/16
2025-10-29 13:44:04,659 - DEBUG - [10.0.0.254]: Running cmd : getent hosts 10.0.0.254 | head -n 1 | awk '{print $2}'
2025-10-29 13:44:04,722 - DEBUG - Output : cn-jenkins-deploy-platform-ansible-os-4521-2.
2025-10-29 13:44:04,722 - DEBUG - [10.0.0.254]: Running cmd : getent hosts 10.20.0.254 | head -n 1 | awk '{print $2}'
2025-10-29 13:44:04,797 - DEBUG - Output : cn-jenkins-deploy-platform-ansible-os-4521-2
2025-10-29 13:44:04,797 - DEBUG - [10.0.0.48]: Running cmd : hostname
2025-10-29 13:44:05,384 - DEBUG - Output : cn-jenkins-deploy-platform-ansible-os-4521-3
2025-10-29 13:44:05,385 - DEBUG - [10.0.0.48]: Running cmd : hostname -f
2025-10-29 13:44:05,449 - DEBUG - Output : cn-jenkins-deploy-platform-ansible-os-4521-3.
2025-10-29 13:44:05,450 - DEBUG - [10.0.0.48]: Running cmd : docker ps 2>/dev/null | grep -v "/pause\|/usr/bin/pod\|nova_api_\|contrail.*init\|init.*contrail\|provisioner\|placement" | awk '{print $NF}'
2025-10-29 13:44:05,553 - DEBUG - Output : NAMES
analytics_snmp_nodemgr_1
analytics_snmp_topology_1
analytics_snmp_snmp-collector_1
analytics_alarm_alarm-gen_1
analytics_alarm_nodemgr_1
analytics_alarm_kafka_1
analytics_collector_1
analytics_api_1
analytics_nodemgr_1
analytics_database_nodemgr_1
analytics_database_query-engine_1
analytics_database_cassandra_1
control_named_1
control_dns_1
control_nodemgr_1
control_control_1
webui_web_1
webui_job_1
config_devicemgr_1
config_nodemgr_1
config_schema_1
config_svcmonitor_1
config_dnsmasq_1
config_api_1
config_database_rabbitmq_1
config_database_nodemgr_1
config_database_zookeeper_1
config_database_cassandra_1
redis_redis_1
2025-10-29 13:44:05,554 - DEBUG - [10.0.0.48]: Running cmd : ip -4 -o addr show | awk '{print $4}'
2025-10-29 13:44:05,629 - DEBUG - Output : 127.0.0.1/8
10.0.0.48/24
10.20.0.14/24
172.17.0.1/16
2025-10-29 13:44:05,629 - DEBUG - [10.0.0.48]: Running cmd : getent hosts 10.0.0.48 | head -n 1 | awk '{print $2}'
2025-10-29 13:44:05,685 - DEBUG - Output : cn-jenkins-deploy-platform-ansible-os-4521-3.
2025-10-29 13:44:05,685 - DEBUG - [10.0.0.48]: Running cmd : getent hosts 10.20.0.14 | head -n 1 | awk '{print $2}'
2025-10-29 13:44:05,763 - DEBUG - Output : cn-jenkins-deploy-platform-ansible-os-4521-3
2025-10-29 13:44:05,763 - DEBUG - [10.0.0.49]: Running cmd : hostname
2025-10-29 13:44:06,256 - DEBUG - Output : an-jenkins-deploy-platform-ansible-os-4521-1
2025-10-29 13:44:06,256 - DEBUG - [10.0.0.49]: Running cmd : hostname -f
2025-10-29 13:44:06,323 - DEBUG - Output : an-jenkins-deploy-platform-ansible-os-4521-1.
2025-10-29 13:44:06,323 - DEBUG - [10.0.0.49]: Running cmd : docker ps 2>/dev/null | grep -v "/pause\|/usr/bin/pod\|nova_api_\|contrail.*init\|init.*contrail\|provisioner\|placement" | awk '{print $NF}'
2025-10-29 13:44:06,406 - DEBUG - Output : NAMES
vrouter_vrouter-agent_1
vrouter_nodemgr_1
rsyslogd_rsyslogd_1
nova_compute
nova_libvirt
nova_ssh
cron
kolla_toolbox
fluentd
2025-10-29 13:44:06,406 - DEBUG - [10.0.0.49]: Running cmd : ip -4 -o addr show dev vhost0 | awk '{print $4}'
2025-10-29 13:44:06,474 - DEBUG - Output : 10.20.0.25/24
2025-10-29 13:44:06,474 - DEBUG - [10.0.0.49]: Running cmd : getent hosts 10.20.0.25 | head -n 1 | awk '{print $2}'
2025-10-29 13:44:06,553 - DEBUG - Output : an-jenkins-deploy-platform-ansible-os-4521-1
2025-10-29 13:44:06,553 - DEBUG - [10.0.0.50]: Running cmd : hostname
2025-10-29 13:44:07,047 - DEBUG - Output : an-jenkins-deploy-platform-ansible-os-4521-2
2025-10-29 13:44:07,047 - DEBUG - [10.0.0.50]: Running cmd : hostname -f
2025-10-29 13:44:07,111 - DEBUG - Output : an-jenkins-deploy-platform-ansible-os-4521-2.
2025-10-29 13:44:07,111 - DEBUG - [10.0.0.50]: Running cmd : docker ps 2>/dev/null | grep -v "/pause\|/usr/bin/pod\|nova_api_\|contrail.*init\|init.*contrail\|provisioner\|placement" | awk '{print $NF}'
2025-10-29 13:44:07,196 - DEBUG - Output : NAMES
vrouter_vrouter-agent_1
vrouter_nodemgr_1
rsyslogd_rsyslogd_1
nova_compute
nova_libvirt
nova_ssh
cron
kolla_toolbox
fluentd
2025-10-29 13:44:07,196 - DEBUG - [10.0.0.50]: Running cmd : ip -4 -o addr show dev vhost0 | awk '{print $4}'
2025-10-29 13:44:07,274 - DEBUG - Output : 10.20.0.193/24
2025-10-29 13:44:07,275 - DEBUG - [10.0.0.50]: Running cmd : getent hosts 10.20.0.193 | head -n 1 | awk '{print $2}'
2025-10-29 13:44:07,354 - DEBUG - Output : an-jenkins-deploy-platform-ansible-os-4521-2
2025-10-29 13:44:08,150 - DEBUG - Not creating keypair since it exists
2025-10-29 13:44:08,208 - INFO - Domain Default found not creating
2025-10-29 13:44:08,736 - INFO - Project ctest-TestvifStats-40295410 not found, creating it
2025-10-29 13:44:09,357 - INFO - Created Project:ctest-TestvifStats-40295410, ID : 9ed5bcf8-9eb7-4d84-a66d-856ec9c230d1
2025-10-29 13:44:11,010 - INFO - Using existing project ['default-domain', 'admin'](941e9aef-7b03-4547-a8ff-19c13661cb0c)
2025-10-29 13:44:11,424 - INFO - admin user already present
2025-10-29 13:44:11,806 - INFO - Adding rules to the default security group in Project admin
2025-10-29 13:44:12,283 - INFO - ================================================================================
2025-10-29 13:44:12,283 - INFO - STARTING TEST : test_vif_statistics
2025-10-29 13:44:12,284 - INFO - TEST DESCRIPTION :
Description:
Verify vif statistics
Vm's across compute node
steps:
1. create 1 VN and launch 2 VMs in compute node
2. client and server VMs on same node
3. send icmp traffic assert if ping is not working
4. get_vif_stats to check vif interface
5. clear_vif_stats to clear vif interface stats
6. Repeat step4
Pass criteria:
1. If output of vif stats/clear execute successfully from compute
2025-10-29 13:44:12,930 - DEBUG - Skipping xmpp flap check
2025-10-29 13:44:12,930 - INFO - Initial checks done. Running the testcase now
2025-10-29 13:44:12,930 - INFO -
2025-10-29 13:44:13,647 - DEBUG - Response for create_network : {'network': {'id': '5357ca51-5d69-41d7-a53f-eaf8bc9e375f', 'name': 'ctest-vn-59721512', 'tenant_id': '9ed5bcf89eb74d84a66d856ec9c230d1', 'project_id': '9ed5bcf89eb74d84a66d856ec9c230d1', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestvifStats-40295410', 'ctest-vn-59721512'], 'port_security_enabled': True, 'description': ''}}
2025-10-29 13:44:13,895 - DEBUG - Response for create_subnet : {'subnet': {'id': 'fe6d5856-16c6-4ffe-8780-3c23e3c493fc', 'name': '', 'tenant_id': '9ed5bcf89eb74d84a66d856ec9c230d1', 'network_id': '5357ca51-5d69-41d7-a53f-eaf8bc9e375f', 'ip_version': 4, 'cidr': '17.174.219.0/26', 'allocation_pools': [{'start': '17.174.219.2', 'end': '17.174.219.62'}], 'gateway_ip': '17.174.219.1', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '17.174.219.2', 'tags': [], 'project_id': '9ed5bcf89eb74d84a66d856ec9c230d1'}}
2025-10-29 13:44:13,931 - INFO - Created VN ctest-vn-59721512
2025-10-29 13:44:13,946 - DEBUG - VN ctest-vn-59721512 UUID is 5357ca51-5d69-41d7-a53f-eaf8bc9e375f
2025-10-29 13:44:14,078 - DEBUG - Requesting: http://10.0.0.38:8082/domains
2025-10-29 13:44:14,407 - DEBUG - Requesting: http://10.0.0.38:8082/domains
2025-10-29 13:44:14,437 - DEBUG - Requesting: http://10.0.0.38:8082/domain/fd9d3a52-0780-4060-8425-e3c883ec81fc
2025-10-29 13:44:14,453 - DEBUG - Requesting: http://10.0.0.38:8082/project/9ed5bcf8-9eb7-4d84-a66d-856ec9c230d1
2025-10-29 13:44:14,551 - DEBUG - Requesting: http://10.0.0.38:8082/virtual-network/5357ca51-5d69-41d7-a53f-eaf8bc9e375f
2025-10-29 13:44:14,566 - DEBUG - Requesting: http://10.0.0.38:8082/virtual-network/5357ca51-5d69-41d7-a53f-eaf8bc9e375f
2025-10-29 13:44:14,577 - DEBUG - Requesting: http://10.0.0.38:8082/routing-instance/4dbb6844-b345-44cf-b1f9-a425fb7e91e3
2025-10-29 13:44:14,586 - DEBUG - Requesting: http://10.0.0.38:8082/routing-instance/4dbb6844-b345-44cf-b1f9-a425fb7e91e3
2025-10-29 13:44:14,594 - DEBUG - Requesting: http://10.0.0.38:8082/route-target/f689ca19-31d6-4d28-9e42-9d06fbf73bef
2025-10-29 13:44:14,600 - DEBUG - Route Targets: ['target:64512:8000008']
2025-10-29 13:44:14,600 - DEBUG - Requesting: http://10.0.0.38:8082/virtual-network/5357ca51-5d69-41d7-a53f-eaf8bc9e375f
2025-10-29 13:44:14,611 - DEBUG - Requesting: http://10.0.0.38:8082/routing-instance/4dbb6844-b345-44cf-b1f9-a425fb7e91e3
2025-10-29 13:44:14,630 - INFO - Verified VN network id 6 for VN 5357ca51-5d69-41d7-a53f-eaf8bc9e375f
2025-10-29 13:44:14,630 - INFO - Verifications in API Server for VN ctest-vn-59721512 passed
2025-10-29 13:44:14,630 - DEBUG - Requesting: http://10.0.0.38:8082/virtual-network/5357ca51-5d69-41d7-a53f-eaf8bc9e375f
2025-10-29 13:44:14,641 - DEBUG - Requesting: http://10.0.0.38:8082/routing-instance/4dbb6844-b345-44cf-b1f9-a425fb7e91e3
2025-10-29 13:44:14,649 - DEBUG - Requesting: http://10.0.0.38:8082/routing-instance/4dbb6844-b345-44cf-b1f9-a425fb7e91e3
2025-10-29 13:44:14,657 - DEBUG - Requesting: http://10.0.0.38:8082/route-target/f689ca19-31d6-4d28-9e42-9d06fbf73bef
2025-10-29 13:44:14,667 - DEBUG - Requesting: http://10.0.0.38:8083/Snh_IFMapTableShowReq?table_name=virtual-network&search_string=virtual-network:default-domain:ctest-TestvifStats-40295410:ctest-vn-59721512
2025-10-29 13:44:14,676 - DEBUG - Control-node 10.0.0.38 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestvifStats-40295410:ctest-vn-59721512', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestvifStats-40295410', 'owner-access': '7', 'group': 'admin', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '6005491078930186711', 'uuid-lslong': '11907494293828155231'}, 'enable': 'true', 'created': '2025-10-29T13:44:13', 'last-modified': '2025-10-29T13:44:13', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.834120'}
2025-10-29 13:44:14,676 - DEBUG - Requesting: http://10.0.0.38:8083/Snh_ShowRoutingInstanceReq?name=default-domain:ctest-TestvifStats-40295410:ctest-vn-59721512:ctest-vn-59721512
2025-10-29 13:44:14,686 - DEBUG - Route Targets: ['target:64512:8000008']
2025-10-29 13:44:14,686 - DEBUG - Requesting: http://10.0.0.254:8083/Snh_IFMapTableShowReq?table_name=virtual-network&search_string=virtual-network:default-domain:ctest-TestvifStats-40295410:ctest-vn-59721512
2025-10-29 13:44:14,693 - DEBUG - Control-node 10.0.0.254 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestvifStats-40295410:ctest-vn-59721512', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestvifStats-40295410', 'owner-access': '7', 'group': 'admin', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '6005491078930186711', 'uuid-lslong': '11907494293828155231'}, 'enable': 'true', 'created': '2025-10-29T13:44:13', 'last-modified': '2025-10-29T13:44:13', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.856036'}
2025-10-29 13:44:14,693 - DEBUG - Requesting: http://10.0.0.254:8083/Snh_ShowRoutingInstanceReq?name=default-domain:ctest-TestvifStats-40295410:ctest-vn-59721512:ctest-vn-59721512
2025-10-29 13:44:14,700 - DEBUG - Route Targets: ['target:64512:8000008']
2025-10-29 13:44:14,700 - DEBUG - Requesting: http://10.0.0.48:8083/Snh_IFMapTableShowReq?table_name=virtual-network&search_string=virtual-network:default-domain:ctest-TestvifStats-40295410:ctest-vn-59721512
2025-10-29 13:44:14,707 - DEBUG - Control-node 10.0.0.48 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestvifStats-40295410:ctest-vn-59721512', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestvifStats-40295410', 'owner-access': '7', 'group': 'admin', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '6005491078930186711', 'uuid-lslong': '11907494293828155231'}, 'enable': 'true', 'created': '2025-10-29T13:44:13', 'last-modified': '2025-10-29T13:44:13', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.867168'}
2025-10-29 13:44:14,708 - DEBUG - Requesting: http://10.0.0.48:8083/Snh_ShowRoutingInstanceReq?name=default-domain:ctest-TestvifStats-40295410:ctest-vn-59721512:ctest-vn-59721512
2025-10-29 13:44:14,715 - DEBUG - Route Targets: ['target:64512:8000008']
2025-10-29 13:44:14,716 - INFO - On all control nodes, Config, RI and RT verification for VN ctest-vn-59721512 passed
2025-10-29 13:44:14,716 - DEBUG - ====Verifying policy data for ctest-vn-59721512 in API_Server ======
2025-10-29 13:44:14,716 - DEBUG - Requesting: http://10.0.0.38:8082/domains
2025-10-29 13:44:14,724 - DEBUG - Requesting: http://10.0.0.38:8082/domain/fd9d3a52-0780-4060-8425-e3c883ec81fc
2025-10-29 13:44:14,738 - DEBUG - Requesting: http://10.0.0.38:8082/project/9ed5bcf8-9eb7-4d84-a66d-856ec9c230d1
2025-10-29 13:44:14,837 - DEBUG - Requesting: http://10.0.0.38:8082/virtual-network/5357ca51-5d69-41d7-a53f-eaf8bc9e375f
2025-10-29 13:44:14,848 - DEBUG - =>VN ctest-vn-59721512 has no policy to be verified
2025-10-29 13:44:14,848 - DEBUG - Verifying the vn in opserver
2025-10-29 13:44:14,848 - DEBUG - Verifying the default-domain:ctest-TestvifStats-40295410:ctest-vn-59721512 virtual network link through opserver 10.0.0.38
2025-10-29 13:44:14,849 - DEBUG - Requesting: http://10.0.0.38:8081/analytics/uves/virtual-networks
2025-10-29 13:44:15,184 - DEBUG - Requesting: http://10.0.0.38:8081/analytics/uves/virtual-networks
2025-10-29 13:44:15,251 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestvifStats-40295410:ctest-vn-59721512', 'href': 'http://10.0.0.38:8081/analytics/uves/virtual-network/default-domain:ctest-TestvifStats-40295410:ctest-vn-59721512?flat'}
2025-10-29 13:44:15,251 - DEBUG - Verifying the default-domain:ctest-TestvifStats-40295410:ctest-vn-59721512 virtual network link through opserver 10.0.0.254
2025-10-29 13:44:15,251 - DEBUG - Requesting: http://10.0.0.254:8081/analytics/uves/virtual-networks
2025-10-29 13:44:15,578 - DEBUG - Requesting: http://10.0.0.254:8081/analytics/uves/virtual-networks
2025-10-29 13:44:15,636 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestvifStats-40295410:ctest-vn-59721512', 'href': 'http://10.0.0.254:8081/analytics/uves/virtual-network/default-domain:ctest-TestvifStats-40295410:ctest-vn-59721512?flat'}
2025-10-29 13:44:15,636 - DEBUG - Verifying the default-domain:ctest-TestvifStats-40295410:ctest-vn-59721512 virtual network link through opserver 10.0.0.48
2025-10-29 13:44:15,636 - DEBUG - Requesting: http://10.0.0.48:8081/analytics/uves/virtual-networks
2025-10-29 13:44:15,945 - DEBUG - Requesting: http://10.0.0.48:8081/analytics/uves/virtual-networks
2025-10-29 13:44:16,015 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestvifStats-40295410:ctest-vn-59721512', 'href': 'http://10.0.0.48:8081/analytics/uves/virtual-network/default-domain:ctest-TestvifStats-40295410:ctest-vn-59721512?flat'}
2025-10-29 13:44:16,015 - INFO - Validated that VN default-domain:ctest-TestvifStats-40295410:ctest-vn-59721512 is found in opserver
2025-10-29 13:44:16,016 - DEBUG - Requesting: http://10.0.0.49:8085/Snh_VrfListReq?name=default-domain:ctest-TestvifStats-40295410:ctest-vn-59721512:ctest-vn-59721512
2025-10-29 13:44:16,022 - DEBUG - Requesting: http://10.0.0.50:8085/Snh_VrfListReq?name=default-domain:ctest-TestvifStats-40295410:ctest-vn-59721512:ctest-vn-59721512
2025-10-29 13:44:16,028 - DEBUG - Requesting: http://10.0.0.49:8085/Snh_VrfListReq?name=default-domain:ctest-TestvifStats-40295410:ctest-vn-59721512:ctest-vn-59721512
2025-10-29 13:44:16,033 - DEBUG - Requesting: http://10.0.0.50:8085/Snh_VrfListReq?name=default-domain:ctest-TestvifStats-40295410:ctest-vn-59721512:ctest-vn-59721512
2025-10-29 13:44:16,039 - DEBUG - Do not have enough data to verify VN in agent
2025-10-29 13:44:16,039 - DEBUG - Requesting: http://10.0.0.49:8085/Snh_VrfListReq?name=default-domain:ctest-TestvifStats-40295410:ctest-vn-59721512:ctest-vn-59721512
2025-10-29 13:44:16,045 - DEBUG - Requesting: http://10.0.0.50:8085/Snh_VrfListReq?name=default-domain:ctest-TestvifStats-40295410:ctest-vn-59721512:ctest-vn-59721512
2025-10-29 13:44:16,051 - DEBUG - VRF ids for VN ctest-vn-59721512: {}
2025-10-29 13:44:16,080 - DEBUG - Services list from nova: [, , , ]
2025-10-29 13:44:16,080 - DEBUG - Hosts: {'nova': ['an-jenkins-deploy-platform-ansible-os-4521-2', 'an-jenkins-deploy-platform-ansible-os-4521-1']}
2025-10-29 13:44:16,080 - DEBUG - Hosts: {'nova': ['an-jenkins-deploy-platform-ansible-os-4521-2', 'an-jenkins-deploy-platform-ansible-os-4521-1']}
2025-10-29 13:44:17,478 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-4521-2), Zone: (nova:an-jenkins-deploy-platform-ansible-os-4521-2)
2025-10-29 13:44:17,478 - DEBUG - Hosts: {'nova': ['an-jenkins-deploy-platform-ansible-os-4521-2', 'an-jenkins-deploy-platform-ansible-os-4521-1']}
2025-10-29 13:44:19,102 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-4521-2), Zone: (nova:an-jenkins-deploy-platform-ansible-os-4521-2)
2025-10-29 13:44:19,102 - INFO - Waiting for VM ctest-TestvifStats-40295410-29523998 to be up..
2025-10-29 13:44:19,207 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2025-10-29 13:44:24,296 - DEBUG - VM is in ACTIVE state now
2025-10-29 13:44:24,296 - INFO - VM name : ctest-TestvifStats-40295410-29523998
2025-10-29 13:44:24,396 - DEBUG - VM ctest-TestvifStats-40295410-29523998 ID is 901e3f9a-2995-42d7-a036-5e125dce5b5d
2025-10-29 13:44:24,430 - DEBUG - VM ctest-TestvifStats-40295410-29523998 launched on Node an-jenkins-deploy-platform-ansible-os-4521-2
2025-10-29 13:44:24,525 - DEBUG - Requesting: http://10.0.0.48:8082/virtual-machine/901e3f9a-2995-42d7-a036-5e125dce5b5d
2025-10-29 13:44:24,859 - DEBUG - Requesting: http://10.0.0.48:8082/virtual-machine/901e3f9a-2995-42d7-a036-5e125dce5b5d
2025-10-29 13:44:24,896 - DEBUG - Requesting: http://10.0.0.48:8082/virtual-machine-interface/1fb463aa-bf2d-404a-baac-68fb4b90749a
2025-10-29 13:44:24,907 - DEBUG - Requesting: http://10.0.0.50:8085/Snh_PageReq?x=begin:-1,end:-1,table:db.interface.0,uuid:1fb463aa-bf2d-404a-baac-68fb4b90749a
2025-10-29 13:44:24,913 - DEBUG - Requesting: http://10.0.0.50:8085/Snh_VrfListReq?name=default-domain:ctest-TestvifStats-40295410:ctest-vn-59721512:ctest-vn-59721512
2025-10-29 13:44:24,919 - DEBUG - Requesting: http://10.0.0.50:8085/Snh_PageReq?x=begin:-1,end:-1,table:db.interface.0,uuid:1fb463aa-bf2d-404a-baac-68fb4b90749a
2025-10-29 13:44:28,052 - DEBUG - (True, 'PING 169.254.0.5 (169.254.0.5) 56(84) bytes of data.\r\n\r\n--- 169.254.0.5 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1033ms')
2025-10-29 13:44:28,052 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestvifStats-40295410-29523998 failed!
2025-10-29 13:44:28,067 - DEBUG - Gateway for vn default-domain:ctest-TestvifStats-40295410:ctest-vn-59721512 is 17.174.219.1 and allocation pool is NOT set
2025-10-29 13:44:32,119 - DEBUG - (True, 'PING 169.254.0.5 (169.254.0.5) 56(84) bytes of data.\r\n\r\n--- 169.254.0.5 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1033ms')
2025-10-29 13:44:32,119 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestvifStats-40295410-29523998 failed!
2025-10-29 13:44:32,136 - DEBUG - Gateway for vn default-domain:ctest-TestvifStats-40295410:ctest-vn-59721512 is 17.174.219.1 and allocation pool is NOT set
2025-10-29 13:44:36,180 - DEBUG - (True, 'PING 169.254.0.5 (169.254.0.5) 56(84) bytes of data.\r\n\r\n--- 169.254.0.5 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1025ms')
2025-10-29 13:44:36,180 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestvifStats-40295410-29523998 failed!
2025-10-29 13:44:36,198 - DEBUG - Gateway for vn default-domain:ctest-TestvifStats-40295410:ctest-vn-59721512 is 17.174.219.1 and allocation pool is NOT set
2025-10-29 13:44:40,246 - DEBUG - (True, 'PING 169.254.0.5 (169.254.0.5) 56(84) bytes of data.\r\n\r\n--- 169.254.0.5 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1024ms')
2025-10-29 13:44:40,246 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestvifStats-40295410-29523998 failed!
2025-10-29 13:44:40,262 - DEBUG - Gateway for vn default-domain:ctest-TestvifStats-40295410:ctest-vn-59721512 is 17.174.219.1 and allocation pool is NOT set
2025-10-29 13:44:44,307 - DEBUG - (True, 'PING 169.254.0.5 (169.254.0.5) 56(84) bytes of data.\r\n\r\n--- 169.254.0.5 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1026ms')
2025-10-29 13:44:44,308 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestvifStats-40295410-29523998 failed!
2025-10-29 13:44:44,323 - DEBUG - Gateway for vn default-domain:ctest-TestvifStats-40295410:ctest-vn-59721512 is 17.174.219.1 and allocation pool is NOT set
2025-10-29 13:44:48,370 - DEBUG - (True, 'PING 169.254.0.5 (169.254.0.5) 56(84) bytes of data.\r\n\r\n--- 169.254.0.5 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1029ms')
2025-10-29 13:44:48,370 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestvifStats-40295410-29523998 failed!
2025-10-29 13:44:48,387 - DEBUG - Gateway for vn default-domain:ctest-TestvifStats-40295410:ctest-vn-59721512 is 17.174.219.1 and allocation pool is NOT set
2025-10-29 13:44:52,448 - DEBUG - (True, 'PING 169.254.0.5 (169.254.0.5) 56(84) bytes of data.\r\n\r\n--- 169.254.0.5 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1032ms')
2025-10-29 13:44:52,449 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestvifStats-40295410-29523998 failed!
2025-10-29 13:44:52,465 - DEBUG - Gateway for vn default-domain:ctest-TestvifStats-40295410:ctest-vn-59721512 is 17.174.219.1 and allocation pool is NOT set
2025-10-29 13:44:56,494 - DEBUG - (True, 'PING 169.254.0.5 (169.254.0.5) 56(84) bytes of data.\r\n\r\n--- 169.254.0.5 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1001ms')
2025-10-29 13:44:56,494 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestvifStats-40295410-29523998 failed!
2025-10-29 13:44:56,509 - DEBUG - Gateway for vn default-domain:ctest-TestvifStats-40295410:ctest-vn-59721512 is 17.174.219.1 and allocation pool is NOT set
2025-10-29 13:45:00,559 - DEBUG - (True, 'PING 169.254.0.5 (169.254.0.5) 56(84) bytes of data.\r\n\r\n--- 169.254.0.5 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1029ms')
2025-10-29 13:45:00,559 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestvifStats-40295410-29523998 failed!
2025-10-29 13:45:00,575 - DEBUG - Gateway for vn default-domain:ctest-TestvifStats-40295410:ctest-vn-59721512 is 17.174.219.1 and allocation pool is NOT set
2025-10-29 13:45:04,626 - DEBUG - (True, 'PING 169.254.0.5 (169.254.0.5) 56(84) bytes of data.\r\n\r\n--- 169.254.0.5 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1018ms')
2025-10-29 13:45:04,627 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestvifStats-40295410-29523998 failed!
2025-10-29 13:45:04,644 - DEBUG - Gateway for vn default-domain:ctest-TestvifStats-40295410:ctest-vn-59721512 is 17.174.219.1 and allocation pool is NOT set
2025-10-29 13:45:08,698 - DEBUG - (True, 'PING 169.254.0.5 (169.254.0.5) 56(84) bytes of data.\r\n\r\n--- 169.254.0.5 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1027ms')
2025-10-29 13:45:08,698 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestvifStats-40295410-29523998 failed!
2025-10-29 13:45:08,713 - DEBUG - Gateway for vn default-domain:ctest-TestvifStats-40295410:ctest-vn-59721512 is 17.174.219.1 and allocation pool is NOT set
2025-10-29 13:45:12,751 - DEBUG - (True, 'PING 169.254.0.5 (169.254.0.5) 56(84) bytes of data.\r\n\r\n--- 169.254.0.5 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1020ms')
2025-10-29 13:45:12,752 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestvifStats-40295410-29523998 failed!
2025-10-29 13:45:12,767 - DEBUG - Gateway for vn default-domain:ctest-TestvifStats-40295410:ctest-vn-59721512 is 17.174.219.1 and allocation pool is NOT set
2025-10-29 13:45:14,798 - DEBUG - (True, 'PING 169.254.0.5 (169.254.0.5) 56(84) bytes of data.\r\n64 bytes from 169.254.0.5: icmp_seq=1 ttl=63 time=11.8 ms\r\n64 bytes from 169.254.0.5: icmp_seq=2 ttl=63 time=0.905 ms\r\n\r\n--- 169.254.0.5 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1002ms\r\nrtt min/avg/max/mdev = 0.905/6.331/11.757/5.426 ms')
2025-10-29 13:45:14,799 - INFO - Ping to Metadata IP 169.254.0.5 of VM ctest-TestvifStats-40295410-29523998 passed
2025-10-29 13:45:14,879 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-29 13:45:14,879 - DEBUG - Waiting to SSH to VM ctest-TestvifStats-40295410-29523998, IP 17.174.219.3, Port 22
2025-10-29 13:45:14,903 - DEBUG - Error on ssh to ubuntu@169.254.0.5:22, result: /bin/bash: connect: Connection refused
/bin/bash: line 1: /dev/tcp/169.254.0.5/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.5/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.5/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''}
2025-10-29 13:45:15,025 - DEBUG - VM ctest-TestvifStats-40295410-29523998 is NOT ready for SSH connections, VM status: ACTIVE
2025-10-29 13:45:20,025 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-29 13:45:20,026 - DEBUG - Waiting to SSH to VM ctest-TestvifStats-40295410-29523998, IP 17.174.219.3, Port 22
2025-10-29 13:45:20,062 - DEBUG - Error on ssh to ubuntu@169.254.0.5:22, result: /bin/bash: connect: Connection refused
/bin/bash: line 1: /dev/tcp/169.254.0.5/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.5/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.5/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''}
2025-10-29 13:45:20,154 - DEBUG - VM ctest-TestvifStats-40295410-29523998 is NOT ready for SSH connections, VM status: ACTIVE
2025-10-29 13:45:25,155 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-29 13:45:25,155 - DEBUG - Waiting to SSH to VM ctest-TestvifStats-40295410-29523998, IP 17.174.219.3, Port 22
2025-10-29 13:45:25,201 - DEBUG - Error on ssh to ubuntu@169.254.0.5:22, result: /bin/bash: connect: Connection refused
/bin/bash: line 1: /dev/tcp/169.254.0.5/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.5/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.5/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''}
2025-10-29 13:45:25,289 - DEBUG - VM ctest-TestvifStats-40295410-29523998 is NOT ready for SSH connections, VM status: ACTIVE
2025-10-29 13:45:30,289 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-29 13:45:30,289 - DEBUG - Waiting to SSH to VM ctest-TestvifStats-40295410-29523998, IP 17.174.219.3, Port 22
2025-10-29 13:45:30,331 - DEBUG - Error on ssh to ubuntu@169.254.0.5:22, result: /bin/bash: connect: Connection refused
/bin/bash: line 1: /dev/tcp/169.254.0.5/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.5/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.5/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''}
2025-10-29 13:45:30,423 - DEBUG - VM ctest-TestvifStats-40295410-29523998 is NOT ready for SSH connections, VM status: ACTIVE
2025-10-29 13:45:35,423 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-29 13:45:35,424 - DEBUG - Waiting to SSH to VM ctest-TestvifStats-40295410-29523998, IP 17.174.219.3, Port 22
2025-10-29 13:45:35,458 - DEBUG - Error on ssh to ubuntu@169.254.0.5:22, result: /bin/bash: connect: Connection refused
/bin/bash: line 1: /dev/tcp/169.254.0.5/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.5/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.5/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''}
2025-10-29 13:45:35,551 - DEBUG - VM ctest-TestvifStats-40295410-29523998 is NOT ready for SSH connections, VM status: ACTIVE
2025-10-29 13:45:40,552 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-29 13:45:40,552 - DEBUG - Waiting to SSH to VM ctest-TestvifStats-40295410-29523998, IP 17.174.219.3, Port 22
2025-10-29 13:45:40,577 - DEBUG - Error on ssh to ubuntu@169.254.0.5:22, result: /bin/bash: connect: Connection refused
/bin/bash: line 1: /dev/tcp/169.254.0.5/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.5/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.5/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''}
2025-10-29 13:45:40,661 - DEBUG - VM ctest-TestvifStats-40295410-29523998 is NOT ready for SSH connections, VM status: ACTIVE
2025-10-29 13:45:45,663 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-29 13:45:45,663 - DEBUG - Waiting to SSH to VM ctest-TestvifStats-40295410-29523998, IP 17.174.219.3, Port 22
2025-10-29 13:45:45,698 - DEBUG - Error on ssh to ubuntu@169.254.0.5:22, result: /bin/bash: connect: Connection refused
/bin/bash: line 1: /dev/tcp/169.254.0.5/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.5/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.5/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''}
2025-10-29 13:45:45,793 - DEBUG - VM ctest-TestvifStats-40295410-29523998 is NOT ready for SSH connections, VM status: ACTIVE
2025-10-29 13:45:50,793 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-29 13:45:50,793 - DEBUG - Waiting to SSH to VM ctest-TestvifStats-40295410-29523998, IP 17.174.219.3, Port 22
2025-10-29 13:45:50,877 - DEBUG - VM ctest-TestvifStats-40295410-29523998 is ready for SSH connections
2025-10-29 13:45:50,877 - INFO - Waiting for VM ctest-TestvifStats-40295410-06955851 to be up..
2025-10-29 13:45:50,966 - DEBUG - VM is in ACTIVE state now
2025-10-29 13:45:50,966 - INFO - VM name : ctest-TestvifStats-40295410-06955851
2025-10-29 13:45:51,054 - DEBUG - VM ctest-TestvifStats-40295410-06955851 ID is 33d8a550-4c52-4461-9ab3-0f858eb20246
2025-10-29 13:45:51,054 - DEBUG - VM ctest-TestvifStats-40295410-06955851 launched on Node an-jenkins-deploy-platform-ansible-os-4521-2
2025-10-29 13:45:51,138 - DEBUG - Requesting: http://10.0.0.48:8082/virtual-machine/33d8a550-4c52-4461-9ab3-0f858eb20246
2025-10-29 13:45:51,149 - DEBUG - Requesting: http://10.0.0.48:8082/virtual-machine-interface/2ef8e670-f1bc-47a3-91d9-fb24fa7a76ac
2025-10-29 13:45:51,160 - DEBUG - Requesting: http://10.0.0.50:8085/Snh_PageReq?x=begin:-1,end:-1,table:db.interface.0,uuid:2ef8e670-f1bc-47a3-91d9-fb24fa7a76ac
2025-10-29 13:45:51,167 - DEBUG - Requesting: http://10.0.0.50:8085/Snh_VrfListReq?name=default-domain:ctest-TestvifStats-40295410:ctest-vn-59721512:ctest-vn-59721512
2025-10-29 13:45:51,172 - DEBUG - Requesting: http://10.0.0.50:8085/Snh_PageReq?x=begin:-1,end:-1,table:db.interface.0,uuid:2ef8e670-f1bc-47a3-91d9-fb24fa7a76ac
2025-10-29 13:45:52,272 - DEBUG - (True, 'PING 169.254.0.6 (169.254.0.6) 56(84) bytes of data.\r\n64 bytes from 169.254.0.6: icmp_seq=1 ttl=63 time=13.4 ms\r\n64 bytes from 169.254.0.6: icmp_seq=2 ttl=63 time=1.75 ms\r\n\r\n--- 169.254.0.6 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1002ms\r\nrtt min/avg/max/mdev = 1.751/7.594/13.438/5.843 ms')
2025-10-29 13:45:52,272 - INFO - Ping to Metadata IP 169.254.0.6 of VM ctest-TestvifStats-40295410-06955851 passed
2025-10-29 13:45:52,345 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-29 13:45:52,345 - DEBUG - Waiting to SSH to VM ctest-TestvifStats-40295410-06955851, IP 17.174.219.4, Port 22
2025-10-29 13:45:52,432 - DEBUG - VM ctest-TestvifStats-40295410-06955851 is ready for SSH connections
2025-10-29 13:45:52,432 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-29 13:45:52,432 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 17.174.219.4, host_string: ubuntu@169.254.0.5, password: ubuntugateway: ubuntu@10.0.0.50, gateway password: c0ntrail123
2025-10-29 13:45:52,433 - DEBUG - ping -s 56 -c 3 -W 1 17.174.219.4
2025-10-29 13:46:18,314 - DEBUG - PING 17.174.219.4 (17.174.219.4) 56(84) bytes of data.
64 bytes from 17.174.219.4: icmp_req=1 ttl=64 time=11.5 ms
64 bytes from 17.174.219.4: icmp_req=2 ttl=64 time=0.881 ms
64 bytes from 17.174.219.4: icmp_req=3 ttl=64 time=1.14 ms
--- 17.174.219.4 ping statistics ---
3 packets transmitted, 3 received, 0% packet loss, time 2003ms
rtt min/avg/max/mdev = 0.881/4.529/11.560/4.972 ms
2025-10-29 13:46:18,314 - INFO - Ping to IP 17.174.219.4 from VM ctest-TestvifStats-40295410-29523998 passed
2025-10-29 13:46:18,314 - INFO - 10.0.0.50
2025-10-29 13:46:18,314 - DEBUG - [10.0.0.50]: Running cmd : vif --list | grep '^vif'
2025-10-29 13:46:18,450 - DEBUG - Output : /bin/bash: line 1: vif: command not found
2025-10-29 13:46:18,455 - INFO - Deleting VM ctest-TestvifStats-40295410-06955851
2025-10-29 13:46:18,547 - INFO - Deleting VM ctest-TestvifStats-40295410-29523998
2025-10-29 13:46:18,627 - INFO - Deleting VN ctest-vn-59721512
2025-10-29 13:46:18,678 - DEBUG - VN 5357ca51-5d69-41d7-a53f-eaf8bc9e375f still in use: Unable to complete operation on network 5357ca51-5d69-41d7-a53f-eaf8bc9e375f. There are one or more ports still in use on the network.
Neutron server returns request_ids: ['req-d5ab8771-c79e-4e59-bf86-4da3389ba587']
2025-10-29 13:46:18,679 - WARNING - Deleting VN ctest-vn-59721512 failed..Will retry
2025-10-29 13:46:20,835 - DEBUG - Response for deleting network ()
2025-10-29 13:46:20,835 - DEBUG - Requesting: http://10.0.0.38:8082/routing-instance/4dbb6844-b345-44cf-b1f9-a425fb7e91e3
2025-10-29 13:46:20,844 - DEBUG - Response Code: 404
2025-10-29 13:46:20,844 - DEBUG - Requesting: http://10.0.0.38:8082/domains
2025-10-29 13:46:20,852 - DEBUG - Requesting: http://10.0.0.38:8082/domain/fd9d3a52-0780-4060-8425-e3c883ec81fc
2025-10-29 13:46:20,879 - DEBUG - Requesting: http://10.0.0.38:8082/project/9ed5bcf8-9eb7-4d84-a66d-856ec9c230d1
2025-10-29 13:46:20,978 - INFO - Validated that VN ctest-vn-59721512 is not found in API Server
2025-10-29 13:46:20,979 - DEBUG - Requesting: http://10.0.0.49:8085/Snh_VnListReq?name=default-domain:ctest-TestvifStats-40295410:ctest-vn-59721512
2025-10-29 13:46:20,986 - DEBUG - Requesting: http://10.0.0.49:8085/Snh_VrfListReq?name=default-domain:ctest-TestvifStats-40295410:ctest-vn-59721512:ctest-vn-59721512
2025-10-29 13:46:20,993 - DEBUG - VN ctest-vn-59721512 is not present in Agent 10.0.0.49
2025-10-29 13:46:20,993 - DEBUG - Requesting: http://10.0.0.50:8085/Snh_VnListReq?name=default-domain:ctest-TestvifStats-40295410:ctest-vn-59721512
2025-10-29 13:46:21,003 - DEBUG - Requesting: http://10.0.0.50:8085/Snh_VrfListReq?name=default-domain:ctest-TestvifStats-40295410:ctest-vn-59721512:ctest-vn-59721512
2025-10-29 13:46:21,010 - DEBUG - VN ctest-vn-59721512 is not present in Agent 10.0.0.50
2025-10-29 13:46:21,010 - INFO - Validated that VN ctest-vn-59721512 is not in any agent
2025-10-29 13:46:21,010 - DEBUG - Requesting: http://10.0.0.49:8085/Snh_VrfListReq?name=default-domain:ctest-TestvifStats-40295410:ctest-vn-59721512:ctest-vn-59721512
2025-10-29 13:46:21,015 - DEBUG - Requesting: http://10.0.0.50:8085/Snh_VrfListReq?name=default-domain:ctest-TestvifStats-40295410:ctest-vn-59721512:ctest-vn-59721512
2025-10-29 13:46:21,036 - DEBUG - Requesting: http://10.0.0.38:8083/Snh_ShowRoutingInstanceReq?name=default-domain:ctest-TestvifStats-40295410:ctest-vn-59721512:ctest-vn-59721512
2025-10-29 13:46:21,043 - DEBUG - Requesting: http://10.0.0.254:8083/Snh_ShowRoutingInstanceReq?name=default-domain:ctest-TestvifStats-40295410:ctest-vn-59721512:ctest-vn-59721512
2025-10-29 13:46:21,051 - DEBUG - Requesting: http://10.0.0.48:8083/Snh_ShowRoutingInstanceReq?name=default-domain:ctest-TestvifStats-40295410:ctest-vn-59721512:ctest-vn-59721512
2025-10-29 13:46:21,057 - DEBUG - Requesting: http://10.0.0.48:8083/Snh_IFMapTableShowReq?table_name=virtual-network&search_string=virtual-network:default-domain:ctest-TestvifStats-40295410:ctest-vn-59721512
2025-10-29 13:46:21,063 - INFO - Validated that Routing instances and Config db in Control-nodes does not have VN ctest-vn-59721512 info
2025-10-29 13:46:22,336 - ERROR - AssertionError
Python 3.9.21: /usr/bin/python3
Wed Oct 29 13:46:18 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/vrouter/test_vif_stats.py in test_vif_statistics(self=)
126 assert client_fixtures[0].ping_with_certainty(server_fixtures[0].vm_ip, expectation=True), "ping failed"
127 compute_ip = server_fixtures[0].vm_node_ip
128 stats_pre_clr = self.get_vif_stats(compute_ip)
129 assert stats_pre_clr > 0, "vif stats should be greater than 0 before clearing"
130 self.clear_vif_stats(compute_ip)
stats_pre_clr undefined
self =
self.get_vif_stats = >
compute_ip = '10.0.0.50'
/contrail-test/scripts/vrouter/test_vif_stats.py in get_vif_stats(self=, compute_ip='10.0.0.50')
42 continue
43
44 assert vif_ids, "No valid vif interfaces found"
45 self.logger.info("Found vif interfaces: %s" % vif_ids)
46
vif_ids = []
AssertionError: No valid vif interfaces found
__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 = ('No valid vif interfaces found',)
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/vrouter/test_vif_stats.py", line 128, in test_vif_statistics
stats_pre_clr = self.get_vif_stats(compute_ip)
File "/contrail-test/scripts/vrouter/test_vif_stats.py", line 44, in get_vif_stats
assert vif_ids, "No valid vif interfaces found"
AssertionError: No valid vif interfaces found
2025-10-29 13:46:22,336 - DEBUG - Skipping xmpp flap check
2025-10-29 13:46:22,336 - INFO -
2025-10-29 13:46:22,337 - INFO - END TEST : test_vif_statistics : FAILED[0:02:10]
2025-10-29 13:46:22,337 - INFO - --------------------------------------------------------------------------------
2025-10-29 13:46:23,094 - INFO - Deleted project: ctest-TestvifStats-40295410, ID : 9ed5bcf8-9eb7-4d84-a66d-856ec9c230d1