testcases/vPing/CI/libraries/vPing_ssh.py

   1 #!/usr/bin/python
   2 #
   3 # Copyright (c) 2015 All rights reserved
   4 # This program and the accompanying materials
   5 # are made available under the terms of the Apache License, Version 2.0
   6 # which accompanies this distribution, and is available at
   7 #
   8 # http://www.apache.org/licenses/LICENSE-2.0
   9 #
  10 # 0.1: This script boots the VM1 and allocates IP address from Nova
  11 # Later, the VM2 boots then execute cloud-init to ping VM1.
  12 # After successful ping, both the VMs are deleted.
  13 # 0.2: measure test duration and publish results under json format
  14 #
  15 #
  16 import argparse
  17 import datetime
  18 import logging
  19 import os
  20 import paramiko
  21 import pprint
  22 import re
  23 import subprocess
  24 import sys
  25 import time
  26 import yaml
  27 from scp import SCPClient
  28 from novaclient import client as novaclient
  29 from neutronclient.v2_0 import client as neutronclient
  30 from keystoneclient.v2_0 import client as keystoneclient
  31 from glanceclient import client as glanceclient
  32
  33 pp = pprint.PrettyPrinter(indent=4)
  34
  35 parser = argparse.ArgumentParser()
  36
  37 parser.add_argument("-d", "--debug", help="Debug mode", action="store_true")
  38 parser.add_argument("-r", "--report",
  39                     help="Create json result file",
  40                     action="store_true")
  41 parser.add_argument("-n", "--noclean",
  42                     help="Don't clean the created resources for this test.",
  43                     action="store_true")
  44
  45 args = parser.parse_args()
  46
  47 """ logging configuration """
  48
  49 logger = logging.getLogger('vPing_ssh')
  50 logger.setLevel(logging.DEBUG)
  51
  52 ch = logging.StreamHandler()
  53
  54 if args.debug:
  55     ch.setLevel(logging.DEBUG)
  56 else:
  57     ch.setLevel(logging.INFO)
  58
  59 formatter = logging.Formatter('%(asctime)s - %(name)s'
  60                               '- %(levelname)s - %(message)s')
  61
  62 ch.setFormatter(formatter)
  63 logger.addHandler(ch)
  64 paramiko.util.log_to_file("/var/log/paramiko.log")
  65
  66 REPO_PATH = os.environ['repos_dir']+'/functest/'
  67 if not os.path.exists(REPO_PATH):
  68     logger.error("Functest repository directory not found '%s'" % REPO_PATH)
  69     exit(-1)
  70 sys.path.append(REPO_PATH + "testcases/")
  71 import functest_utils
  72
  73 with open("/home/opnfv/functest/conf/config_functest.yaml") as f:
  74     functest_yaml = yaml.safe_load(f)
  75 f.close()
  76
  77 HOME = os.environ['HOME'] + "/"
  78 # vPing parameters
  79 VM_BOOT_TIMEOUT = 180
  80 VM_DELETE_TIMEOUT = 100
  81 PING_TIMEOUT = functest_yaml.get("vping").get("ping_timeout")
  82 TEST_DB = functest_yaml.get("results").get("test_db_url")
  83 NAME_VM_1 = functest_yaml.get("vping").get("vm_name_1")
  84 NAME_VM_2 = functest_yaml.get("vping").get("vm_name_2")
  85 # GLANCE_IMAGE_NAME = functest_yaml.get("general"). \
  86 #    get("openstack").get("image_name")
  87 GLANCE_IMAGE_NAME = "functest-vping"
  88 GLANCE_IMAGE_FILENAME = functest_yaml.get("general"). \
  89     get("openstack").get("image_file_name")
  90 GLANCE_IMAGE_FORMAT = functest_yaml.get("general"). \
  91     get("openstack").get("image_disk_format")
  92 GLANCE_IMAGE_PATH = functest_yaml.get("general"). \
  93     get("directories").get("dir_functest_data") + "/" + GLANCE_IMAGE_FILENAME
  94
  95
  96 FLAVOR = functest_yaml.get("vping").get("vm_flavor")
  97
  98 # NEUTRON Private Network parameters
  99
 100 NEUTRON_PRIVATE_NET_NAME = functest_yaml.get("vping"). \
 101     get("vping_private_net_name")
 102 NEUTRON_PRIVATE_SUBNET_NAME = functest_yaml.get("vping"). \
 103     get("vping_private_subnet_name")
 104 NEUTRON_PRIVATE_SUBNET_CIDR = functest_yaml.get("vping"). \
 105     get("vping_private_subnet_cidr")
 106 NEUTRON_ROUTER_NAME = functest_yaml.get("vping"). \
 107     get("vping_router_name")
 108
 109 SECGROUP_NAME = functest_yaml.get("vping"). \
 110     get("vping_sg_name")
 111 SECGROUP_DESCR = functest_yaml.get("vping"). \
 112     get("vping_sg_descr")
 113
 114
 115 def pMsg(value):
 116
 117     """pretty printing"""
 118     pp.pprint(value)
 119
 120
 121 def waitVmActive(nova, vm):
 122
 123     # sleep and wait for VM status change
 124     sleep_time = 3
 125     count = VM_BOOT_TIMEOUT / sleep_time
 126     while True:
 127         status = functest_utils.get_instance_status(nova, vm)
 128         logger.debug("Status: %s" % status)
 129         if status == "ACTIVE":
 130             return True
 131         if status == "ERROR" or status == "error":
 132             return False
 133         if count == 0:
 134             logger.debug("Booting a VM timed out...")
 135             return False
 136         count -= 1
 137         time.sleep(sleep_time)
 138     return False
 139
 140
 141 def waitVmDeleted(nova, vm):
 142
 143     # sleep and wait for VM status change
 144     sleep_time = 3
 145     count = VM_DELETE_TIMEOUT / sleep_time
 146     while True:
 147         status = functest_utils.get_instance_status(nova, vm)
 148         if not status:
 149             return True
 150         elif count == 0:
 151             logger.debug("Timeout")
 152             return False
 153         else:
 154             # return False
 155             count -= 1
 156         time.sleep(sleep_time)
 157     return False
 158
 159
 160 def create_private_neutron_net(neutron):
 161
 162     # Check if the network already exists
 163     network_id = functest_utils.get_network_id(neutron,NEUTRON_PRIVATE_NET_NAME)
 164     subnet_id = functest_utils.get_subnet_id(neutron,NEUTRON_PRIVATE_SUBNET_NAME)
 165     router_id = functest_utils.get_router_id(neutron,NEUTRON_ROUTER_NAME)
 166
 167     if network_id != '' and subnet_id != ''  and router_id != '' :
 168         logger.info("Using existing network '%s'..." % NEUTRON_PRIVATE_NET_NAME)
 169     else:
 170         neutron.format = 'json'
 171         logger.info('Creating neutron network %s...' % NEUTRON_PRIVATE_NET_NAME)
 172         network_id = functest_utils. \
 173             create_neutron_net(neutron, NEUTRON_PRIVATE_NET_NAME)
 174
 175         if not network_id:
 176             return False
 177         logger.debug("Network '%s' created successfully" % network_id)
 178         logger.debug('Creating Subnet....')
 179         subnet_id = functest_utils. \
 180             create_neutron_subnet(neutron,
 181                                   NEUTRON_PRIVATE_SUBNET_NAME,
 182                                   NEUTRON_PRIVATE_SUBNET_CIDR,
 183                                   network_id)
 184         if not subnet_id:
 185             return False
 186         logger.debug("Subnet '%s' created successfully" % subnet_id)
 187         logger.debug('Creating Router...')
 188         router_id = functest_utils. \
 189             create_neutron_router(neutron, NEUTRON_ROUTER_NAME)
 190
 191         if not router_id:
 192             return False
 193
 194         logger.debug("Router '%s' created successfully" % router_id)
 195         logger.debug('Adding router to subnet...')
 196
 197         if not functest_utils.add_interface_router(neutron, router_id, subnet_id):
 198             return False
 199         logger.debug("Interface added successfully.")
 200
 201         logger.debug('Adding gateway to router...')
 202         if not functest_utils.add_gateway_router(neutron, router_id):
 203             return False
 204         logger.debug("Gateway added successfully.")
 205
 206     network_dic = {'net_id': network_id,
 207                    'subnet_id': subnet_id,
 208                    'router_id': router_id}
 209     return network_dic
 210
 211 def create_security_group(neutron_client):
 212     sg_id = functest_utils.get_security_group_id(neutron_client, SECGROUP_NAME)
 213     if sg_id != '':
 214         logger.info("Using existing security group '%s'..." % SECGROUP_NAME)
 215     else:
 216         logger.info("Creating security group  '%s'..." % SECGROUP_NAME)
 217         SECGROUP = functest_utils.create_security_group(neutron_client,
 218                                               SECGROUP_NAME,
 219                                               SECGROUP_DESCR)
 220         if not SECGROUP:
 221             logger.error("Failed to create the security group...")
 222             return False
 223
 224         sg_id = SECGROUP['id']
 225
 226         logger.debug("Security group '%s' with ID=%s created successfully." %\
 227                       (SECGROUP['name'], sg_id))
 228
 229         logger.debug("Adding ICMP rules in security group '%s'..." % SECGROUP_NAME)
 230         if not functest_utils.create_secgroup_rule(neutron_client, sg_id, \
 231                         'ingress', 'icmp'):
 232             logger.error("Failed to create the security group rule...")
 233             return False
 234
 235         logger.debug("Adding SSH rules in security group '%s'..." % SECGROUP_NAME)
 236         if not functest_utils.create_secgroup_rule(neutron_client, sg_id, \
 237                         'ingress', 'tcp', '22', '22'):
 238             logger.error("Failed to create the security group rule...")
 239             return False
 240
 241         if not functest_utils.create_secgroup_rule(neutron_client, sg_id, \
 242                         'egress', 'tcp', '22', '22'):
 243             logger.error("Failed to create the security group rule...")
 244             return False
 245     return sg_id
 246
 247 def cleanup(nova, neutron, image_id, network_dic, sg_id, floatingip):
 248     if args.noclean:
 249         logger.debug("The OpenStack resources are not deleted.")
 250         return True
 251
 252     # delete both VMs
 253     logger.info("Cleaning up...")
 254     logger.debug("Deleting image...")
 255     if not functest_utils.delete_glance_image(nova, image_id):
 256         logger.error("Error deleting the glance image")
 257
 258     vm1 = functest_utils.get_instance_by_name(nova, NAME_VM_1)
 259     if vm1:
 260         logger.debug("Deleting '%s'..." % NAME_VM_1)
 261         nova.servers.delete(vm1)
 262         # wait until VMs are deleted
 263         if not waitVmDeleted(nova, vm1):
 264             logger.error(
 265                 "Instance '%s' with cannot be deleted. Status is '%s'" % (
 266                     NAME_VM_1, functest_utils.get_instance_status(nova, vm1)))
 267         else:
 268             logger.debug("Instance %s terminated." % NAME_VM_1)
 269
 270     vm2 = functest_utils.get_instance_by_name(nova, NAME_VM_2)
 271
 272     if vm2:
 273         logger.debug("Deleting '%s'..." % NAME_VM_2)
 274         vm2 = nova.servers.find(name=NAME_VM_2)
 275         nova.servers.delete(vm2)
 276
 277         if not waitVmDeleted(nova, vm2):
 278             logger.error(
 279                 "Instance '%s' with cannot be deleted. Status is '%s'" % (
 280                     NAME_VM_2, functest_utils.get_instance_status(nova, vm2)))
 281         else:
 282             logger.debug("Instance %s terminated." % NAME_VM_2)
 283
 284     # delete created network
 285     logger.debug("Deleting network '%s'..." % NEUTRON_PRIVATE_NET_NAME)
 286     net_id = network_dic["net_id"]
 287     subnet_id = network_dic["subnet_id"]
 288     router_id = network_dic["router_id"]
 289
 290     if not functest_utils.remove_interface_router(neutron, router_id,
 291                                                   subnet_id):
 292         logger.error("Unable to remove subnet '%s' from router '%s'" % (
 293             subnet_id, router_id))
 294         return False
 295
 296     logger.debug("Interface removed successfully")
 297     if not functest_utils.delete_neutron_router(neutron, router_id):
 298         logger.error("Unable to delete router '%s'" % router_id)
 299         return False
 300
 301     logger.debug("Router deleted successfully")
 302
 303     if not functest_utils.delete_neutron_subnet(neutron, subnet_id):
 304         logger.error("Unable to delete subnet '%s'" % subnet_id)
 305         return False
 306
 307     logger.debug(
 308         "Subnet '%s' deleted successfully" % NEUTRON_PRIVATE_SUBNET_NAME)
 309
 310     if not functest_utils.delete_neutron_net(neutron, net_id):
 311         logger.error("Unable to delete network '%s'" % net_id)
 312         return False
 313
 314     logger.debug(
 315         "Network '%s' deleted successfully" % NEUTRON_PRIVATE_NET_NAME)
 316
 317     if not functest_utils.delete_security_group(neutron, sg_id):
 318         logger.error("Unable to delete security group '%s'" % sg_id)
 319         return False
 320     logger.debug(
 321         "Security group '%s' deleted successfully" % sg_id)
 322
 323     logger.debug("Releasing floating ip '%s'..." % floatingip['fip_addr'])
 324     if not functest_utils.delete_floating_ip(nova, floatingip['fip_id']):
 325         logger.error("Unable to delete floatingip '%s'" % floatingip['fip_addr'])
 326         return False
 327     logger.debug(
 328         "Floating IP '%s' deleted successfully" % floatingip['fip_addr'])
 329     return True
 330
 331
 332 def push_results(start_time_ts, duration, test_status):
 333     try:
 334         logger.debug("Pushing result into DB...")
 335         scenario = functest_utils.get_scenario(logger)
 336         pod_name = functest_utils.get_pod_name(logger)
 337         functest_utils.push_results_to_db(TEST_DB,
 338                                           "functest",
 339                                           "vPing",
 340                                           logger, pod_name, scenario,
 341                                           payload={'timestart': start_time_ts,
 342                                                    'duration': duration,
 343                                                    'status': test_status})
 344     except:
 345         logger.error("Error pushing results into Database '%s'" % sys.exc_info()[0])
 346
 347
 348 def main():
 349
 350     creds_nova = functest_utils.get_credentials("nova")
 351     nova_client = novaclient.Client('2', **creds_nova)
 352     creds_neutron = functest_utils.get_credentials("neutron")
 353     neutron_client = neutronclient.Client(**creds_neutron)
 354     creds_keystone = functest_utils.get_credentials("keystone")
 355     keystone_client = keystoneclient.Client(**creds_keystone)
 356     glance_endpoint = keystone_client.service_catalog.url_for(service_type='image',
 357                                                               endpoint_type='publicURL')
 358     glance_client = glanceclient.Client(1, glance_endpoint,
 359                                         token=keystone_client.auth_token)
 360     EXIT_CODE = -1
 361
 362     image_id = None
 363     flavor = None
 364
 365     # Check if the given image exists
 366     image_id = functest_utils.get_image_id(glance_client, GLANCE_IMAGE_NAME)
 367     if image_id != '':
 368         logger.info("Using existing image '%s'..." % GLANCE_IMAGE_NAME)
 369     else:
 370         logger.info("Creating image '%s' from '%s'..." % (GLANCE_IMAGE_NAME,
 371                                                        GLANCE_IMAGE_PATH))
 372         image_id = functest_utils.create_glance_image(glance_client,
 373                                                       GLANCE_IMAGE_NAME,
 374                                                       GLANCE_IMAGE_PATH)
 375         if not image_id:
 376             logger.error("Failed to create a Glance image...")
 377             return(EXIT_CODE)
 378         logger.debug("Image '%s' with ID=%s created successfully." %\
 379                   (GLANCE_IMAGE_NAME, image_id))
 380
 381
 382     network_dic = create_private_neutron_net(neutron_client)
 383     if not network_dic:
 384         logger.error(
 385             "There has been a problem when creating the neutron network")
 386         return(EXIT_CODE)
 387
 388     network_id = network_dic["net_id"]
 389
 390     sg_id = create_security_group(neutron_client)
 391
 392     # Check if the given flavor exists
 393     try:
 394         flavor = nova_client.flavors.find(name=FLAVOR)
 395         logger.info("Using existing Flavor '%s'..." % FLAVOR)
 396     except:
 397         logger.error("Flavor '%s' not found." % FLAVOR)
 398         logger.info("Available flavors are: ")
 399         pMsg(nova_client.flavor.list())
 400         return(EXIT_CODE)
 401
 402     # Deleting instances if they exist
 403     servers = nova_client.servers.list()
 404     for server in servers:
 405         if server.name == NAME_VM_1 or server.name == NAME_VM_2:
 406             logger.info("Instance %s found. Deleting..." % server.name)
 407             server.delete()
 408
 409
 410     # boot VM 1
 411     start_time_ts = time.time()
 412     end_time_ts = start_time_ts
 413     logger.info("vPing Start Time:'%s'" % (
 414         datetime.datetime.fromtimestamp(start_time_ts).strftime(
 415             '%Y-%m-%d %H:%M:%S')))
 416
 417     logger.info("Creating instance '%s'..." % NAME_VM_1)
 418     logger.debug(
 419         "Configuration:\n name=%s \n flavor=%s \n image=%s \n "
 420         "network=%s \n" % (NAME_VM_1, flavor, image_id, network_id))
 421     vm1 = nova_client.servers.create(
 422         name=NAME_VM_1,
 423         flavor=flavor,
 424         image=image_id,
 425         nics=[{"net-id": network_id}]
 426     )
 427
 428     # wait until VM status is active
 429     if not waitVmActive(nova_client, vm1):
 430         logger.error("Instance '%s' cannot be booted. Status is '%s'" % (
 431             NAME_VM_1, functest_utils.get_instance_status(nova_client, vm1)))
 432         cleanup(nova_client, neutron_client, image_id, network_dic, sg_id, floatingip)
 433         return (EXIT_CODE)
 434     else:
 435         logger.info("Instance '%s' is ACTIVE." % NAME_VM_1)
 436
 437     # Retrieve IP of first VM
 438     test_ip = vm1.networks.get(NEUTRON_PRIVATE_NET_NAME)[0]
 439     logger.debug("Instance '%s' got private ip '%s'." % (NAME_VM_1, test_ip))
 440
 441     logger.info("Adding '%s' to security group '%s'..." % (NAME_VM_1, SECGROUP_NAME))
 442     functest_utils.add_secgroup_to_instance(nova_client, vm1.id, sg_id)
 443
 444     # boot VM 2
 445     logger.info("Creating instance '%s'..." % NAME_VM_2)
 446     logger.debug(
 447         "Configuration:\n name=%s \n flavor=%s \n image=%s \n "
 448         "network=%s \n" % (NAME_VM_2, flavor, image_id, network_id))
 449     vm2 = nova_client.servers.create(
 450         name=NAME_VM_2,
 451         flavor=flavor,
 452         image=image_id,
 453         nics=[{"net-id": network_id}]
 454     )
 455
 456     if not waitVmActive(nova_client, vm2):
 457         logger.error("Instance '%s' cannot be booted. Status is '%s'" % (
 458             NAME_VM_2, functest_utils.get_instance_status(nova_client, vm2)))
 459         cleanup(nova_client, neutron_client, image_id, network_dic, sg_id, floatip_dic)
 460         return (EXIT_CODE)
 461     else:
 462         logger.info("Instance '%s' is ACTIVE." % NAME_VM_2)
 463
 464     logger.info("Adding '%s' to security group '%s'..." % (NAME_VM_2, SECGROUP_NAME))
 465     functest_utils.add_secgroup_to_instance(nova_client, vm2.id, sg_id)
 466
 467     logger.info("Creating floating IP for VM '%s'..." % NAME_VM_2)
 468     floatip_dic = functest_utils.create_floating_ip(neutron_client)
 469     floatip = floatip_dic['fip_addr']
 470     floatip_id = floatip_dic['fip_id']
 471
 472     if floatip == None:
 473         logger.error("Cannot create floating IP.")
 474         cleanup(nova_client, neutron_client, image_id, network_dic, sg_id, floatip_dic)
 475         return (EXIT_CODE)
 476     logger.info("Floating IP created: '%s'" % floatip)
 477
 478     logger.info("Associating floating ip: '%s' to VM '%s' " % (floatip, NAME_VM_2))
 479     if not functest_utils.add_floating_ip(nova_client, vm2.id, floatip):
 480         logger.error("Cannot associate floating IP to VM.")
 481         cleanup(nova_client, neutron_client, image_id, network_dic, sg_id, floatip_dic)
 482         return (EXIT_CODE)
 483
 484     logger.info("Trying to establish SSH connection to %s..." % floatip)
 485     username='cirros'
 486     password='cubswin:)'
 487     ssh = paramiko.SSHClient()
 488     ssh.set_missing_host_key_policy(paramiko.AutoAddPolicy())
 489
 490     timeout = 50
 491     nolease = False
 492     got_ip = False
 493     discover_count = 0
 494     cidr_first_octet = NEUTRON_PRIVATE_SUBNET_CIDR.split('.')[0]
 495     while timeout > 0:
 496         try:
 497             ssh.connect(floatip, username=username, password=password, timeout=2)
 498             logger.debug("SSH connection established to %s." % floatip)
 499             break
 500         except Exception, e:
 501             logger.debug("Waiting for %s..." % floatip)
 502             time.sleep(6)
 503             timeout -= 1
 504
 505         console_log = vm2.get_console_output()
 506
 507         # print each "Sending discover" captured on the console log
 508         if len(re.findall("Sending discover",console_log)) > discover_count and not got_ip:
 509             discover_count += 1
 510             logger.debug("Console-log '%s': Sending discover..." % NAME_VM_2)
 511
 512         # check if eth0 got an ip, the line looks like this: "inet addr:192.168."....
 513         # if the dhcp agent fails to assing ip, this line will not appear
 514         if "inet addr:"+cidr_first_octet in console_log and not got_ip:
 515             got_ip = True
 516             logger.debug("The instance '%s' succeeded to get the IP from the dhcp agent.")
 517
 518         # if dhcp doesn't work, it shows "No lease, failing". The test will fail...
 519         if "No lease, failing" in console_log and not nolease and not got_ip:
 520                 nolease = True
 521                 logger.debug("Console-log '%s': No lease, failing..." % NAME_VM_2)
 522                 logger.info("The instance failed to get an IP from "\
 523                             "the DHCP agent. The test will probably timeout...")
 524
 525
 526     if timeout == 0: # 300 sec timeout (5 min)
 527         logger.error("Cannot establish connection to IP '%s'. Aborting" % floatip)
 528         cleanup(nova_client, neutron_client, image_id, network_dic, sg_id, floatip_dic)
 529         return (EXIT_CODE)
 530
 531     scp = SCPClient(ssh.get_transport())
 532
 533     ping_script = REPO_PATH + "testcases/vPing/CI/libraries/ping.sh"
 534     try:
 535         scp.put(ping_script,"~/")
 536     except Exception, e:
 537         logger.error("Cannot SCP the file '%s' to VM '%s'" % (ping_script,floatip))
 538
 539
 540     cmd = 'chmod 755 ~/ping.sh'
 541     (stdin, stdout, stderr) = ssh.exec_command(cmd)
 542     for line in stdout.readlines():
 543         print line
 544
 545     logger.info("Waiting for ping...")
 546     sec = 0
 547     duration = 0
 548
 549     cmd = '~/ping.sh ' + test_ip
 550     flag = False
 551     while True:
 552         time.sleep(1)
 553         (stdin, stdout, stderr) = ssh.exec_command(cmd)
 554         output = stdout.readlines()
 555
 556
 557         for line in output:
 558             if "vPing OK" in line:
 559                 logger.info("vPing detected!")
 560
 561                 # we consider start time at VM1 booting
 562                 end_time_ts = time.time()
 563                 duration = round(end_time_ts - start_time_ts, 1)
 564                 logger.info("vPing duration:'%s' s." % duration)
 565                 EXIT_CODE = 0
 566                 flag = True
 567                 break
 568             elif sec == PING_TIMEOUT:
 569                 logger.info("Timeout reached.")
 570                 flag = True
 571                 break
 572         if flag :
 573             break
 574         logger.debug("Pinging %s. Waiting for response..." % test_ip)
 575         sec += 1
 576
 577     cleanup(nova_client, neutron_client, image_id, network_dic, sg_id, floatip_dic)
 578
 579     test_status = "NOK"
 580     if EXIT_CODE == 0:
 581         logger.info("vPing OK")
 582         test_status = "OK"
 583     else:
 584         duration = 0
 585         logger.error("vPing FAILED")
 586
 587     if args.report:
 588         push_results(start_time_ts, duration, test_status)
 589
 590     exit(EXIT_CODE)
 591
 592 if __name__ == '__main__':
 593     main()