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