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