Remove all logers as utils method args.
[functest-xtesting.git] / testcases / OpenStack / vPing / vping_util.py
1 import os
2 import re
3 import pprint
4 import sys
5 import time
6
7 import functest.utils.functest_utils as ft_utils
8 import functest.utils.openstack_utils as os_utils
9 import paramiko
10 from scp import SCPClient
11 import yaml
12
13 REPO_PATH = os.environ['repos_dir'] + '/functest/'
14
15 with open(os.environ["CONFIG_FUNCTEST_YAML"]) as f:
16     functest_yaml = yaml.safe_load(f)
17 f.close()
18
19 NAME_VM_1 = functest_yaml.get("vping").get("vm_name_1")
20 NAME_VM_2 = functest_yaml.get("vping").get("vm_name_2")
21
22 VM_BOOT_TIMEOUT = 180
23 VM_DELETE_TIMEOUT = 100
24 PING_TIMEOUT = functest_yaml.get("vping").get("ping_timeout")
25
26 GLANCE_IMAGE_NAME = functest_yaml.get("vping").get("image_name")
27 GLANCE_IMAGE_FILENAME = functest_yaml.get("general").get(
28     "openstack").get("image_file_name")
29 GLANCE_IMAGE_FORMAT = functest_yaml.get("general").get(
30     "openstack").get("image_disk_format")
31 GLANCE_IMAGE_PATH = functest_yaml.get("general").get("directories").get(
32     "dir_functest_data") + "/" + GLANCE_IMAGE_FILENAME
33
34 FLAVOR = functest_yaml.get("vping").get("vm_flavor")
35
36 # NEUTRON Private Network parameters
37 PRIVATE_NET_NAME = functest_yaml.get("vping").get(
38     "vping_private_net_name")
39 PRIVATE_SUBNET_NAME = functest_yaml.get("vping").get(
40     "vping_private_subnet_name")
41 PRIVATE_SUBNET_CIDR = functest_yaml.get("vping").get(
42     "vping_private_subnet_cidr")
43 ROUTER_NAME = functest_yaml.get("vping").get(
44     "vping_router_name")
45
46 SECGROUP_NAME = functest_yaml.get("vping").get("vping_sg_name")
47 SECGROUP_DESCR = functest_yaml.get("vping").get("vping_sg_descr")
48
49
50 neutron_client = None
51 glance_client = None
52 nova_client = None
53 logger = None
54
55 pp = pprint.PrettyPrinter(indent=4)
56
57
58 def pMsg(value):
59     """pretty printing"""
60     pp.pprint(value)
61
62
63 def check_repo_exist():
64     if not os.path.exists(REPO_PATH):
65         logger.error("Functest repository not found '%s'" % REPO_PATH)
66         exit(-1)
67
68
69 def get_vmname_1():
70     return NAME_VM_1
71
72
73 def get_vmname_2():
74     return NAME_VM_2
75
76
77 def init(vping_logger):
78     global nova_client
79     nova_client = os_utils.get_nova_client()
80     global neutron_client
81     neutron_client = os_utils.get_neutron_client()
82     global glance_client
83     glance_client = os_utils.get_glance_client()
84     global logger
85     logger = vping_logger
86
87
88 def waitVmActive(nova, vm):
89
90     # sleep and wait for VM status change
91     sleep_time = 3
92     count = VM_BOOT_TIMEOUT / sleep_time
93     while True:
94         status = os_utils.get_instance_status(nova, vm)
95         logger.debug("Status: %s" % status)
96         if status == "ACTIVE":
97             return True
98         if status == "ERROR" or status == "error":
99             return False
100         if count == 0:
101             logger.debug("Booting a VM timed out...")
102             return False
103         count -= 1
104         time.sleep(sleep_time)
105     return False
106
107
108 def create_security_group():
109     sg_id = os_utils.get_security_group_id(neutron_client,
110                                            SECGROUP_NAME)
111     if sg_id != '':
112         logger.info("Using existing security group '%s'..." % SECGROUP_NAME)
113     else:
114         logger.info("Creating security group  '%s'..." % SECGROUP_NAME)
115         SECGROUP = os_utils.create_security_group(neutron_client,
116                                                   SECGROUP_NAME,
117                                                   SECGROUP_DESCR)
118         if not SECGROUP:
119             logger.error("Failed to create the security group...")
120             return False
121
122         sg_id = SECGROUP['id']
123
124         logger.debug("Security group '%s' with ID=%s created successfully."
125                      % (SECGROUP['name'], sg_id))
126
127         logger.debug("Adding ICMP rules in security group '%s'..."
128                      % SECGROUP_NAME)
129         if not os_utils.create_secgroup_rule(neutron_client, sg_id,
130                                              'ingress', 'icmp'):
131             logger.error("Failed to create the security group rule...")
132             return False
133
134         logger.debug("Adding SSH rules in security group '%s'..."
135                      % SECGROUP_NAME)
136         if not os_utils.create_secgroup_rule(neutron_client, sg_id,
137                                              'ingress', 'tcp',
138                                              '22', '22'):
139             logger.error("Failed to create the security group rule...")
140             return False
141
142         if not os_utils.create_secgroup_rule(
143                 neutron_client, sg_id, 'egress', 'tcp', '22', '22'):
144             logger.error("Failed to create the security group rule...")
145             return False
146     return sg_id
147
148
149 def create_image():
150     _, image_id = os_utils.get_or_create_image(GLANCE_IMAGE_NAME,
151                                                GLANCE_IMAGE_PATH,
152                                                GLANCE_IMAGE_FORMAT)
153     if not image_id:
154         exit(-1)
155
156     return image_id
157
158
159 def get_flavor():
160     EXIT_CODE = -1
161
162     # Check if the given flavor exists
163     try:
164         flavor = nova_client.flavors.find(name=FLAVOR)
165         logger.info("Using existing Flavor '%s'..." % FLAVOR)
166         return flavor
167     except:
168         logger.error("Flavor '%s' not found." % FLAVOR)
169         logger.info("Available flavors are: ")
170         pMsg(nova_client.flavor.list())
171         exit(EXIT_CODE)
172
173
174 def create_network_full():
175     EXIT_CODE = -1
176
177     network_dic = os_utils.create_network_full(neutron_client,
178                                                PRIVATE_NET_NAME,
179                                                PRIVATE_SUBNET_NAME,
180                                                ROUTER_NAME,
181                                                PRIVATE_SUBNET_CIDR)
182
183     if not network_dic:
184         logger.error(
185             "There has been a problem when creating the neutron network")
186         exit(EXIT_CODE)
187     network_id = network_dic["net_id"]
188     return network_id
189
190
191 def delete_exist_vms():
192     servers = nova_client.servers.list()
193     for server in servers:
194         if server.name == NAME_VM_1 or server.name == NAME_VM_2:
195             logger.info("Instance %s found. Deleting..." % server.name)
196             server.delete()
197
198
199 def is_userdata(case):
200     return case == 'vping_userdata'
201
202
203 def is_ssh(case):
204     return case == 'vping_ssh'
205
206
207 def boot_vm(case, name, image_id, flavor, network_id, test_ip, sg_id):
208     EXIT_CODE = -1
209
210     config = dict()
211     config['name'] = name
212     config['flavor'] = flavor
213     config['image'] = image_id
214     config['nics'] = [{"net-id": network_id}]
215     if is_userdata(case):
216         config['config_drive'] = True
217         if name == NAME_VM_2:
218             u = ("#!/bin/sh\n\n"
219                  "while true; do\n"
220                  " ping -c 1 %s 2>&1 >/dev/null\n"
221                  " RES=$?\n"
222                  " if [ \"Z$RES\" = \"Z0\" ] ; then\n"
223                  "  echo 'vPing OK'\n"
224                  "  break\n"
225                  " else\n"
226                  "  echo 'vPing KO'\n"
227                  " fi\n"
228                  " sleep 1\n"
229                  "done\n" % test_ip)
230             config['userdata'] = u
231
232     logger.info("Creating instance '%s'..." % name)
233     logger.debug("Configuration: %s" % config)
234     vm = nova_client.servers.create(**config)
235
236     # wait until VM status is active
237     if not waitVmActive(nova_client, vm):
238
239         logger.error("Instance '%s' cannot be booted. Status is '%s'" % (
240             name, os_utils.get_instance_status(nova_client, vm)))
241         exit(EXIT_CODE)
242     else:
243         logger.info("Instance '%s' is ACTIVE." % name)
244
245     add_secgroup(name, vm.id, sg_id)
246
247     return vm
248
249
250 def get_test_ip(vm):
251     test_ip = vm.networks.get(PRIVATE_NET_NAME)[0]
252     logger.debug("Instance '%s' got %s" % (vm.name, test_ip))
253     return test_ip
254
255
256 def add_secgroup(vmname, vm_id, sg_id):
257     logger.info("Adding '%s' to security group '%s'..." %
258                 (vmname, SECGROUP_NAME))
259     os_utils.add_secgroup_to_instance(nova_client, vm_id, sg_id)
260
261
262 def add_float_ip(vm):
263     EXIT_CODE = -1
264
265     logger.info("Creating floating IP for VM '%s'..." % NAME_VM_2)
266     floatip_dic = os_utils.create_floating_ip(neutron_client)
267     floatip = floatip_dic['fip_addr']
268
269     if floatip is None:
270         logger.error("Cannot create floating IP.")
271         exit(EXIT_CODE)
272     logger.info("Floating IP created: '%s'" % floatip)
273
274     logger.info("Associating floating ip: '%s' to VM '%s' "
275                 % (floatip, NAME_VM_2))
276     if not os_utils.add_floating_ip(nova_client, vm.id, floatip):
277         logger.error("Cannot associate floating IP to VM.")
278         exit(EXIT_CODE)
279
280     return floatip
281
282
283 def establish_ssh(vm, floatip):
284     EXIT_CODE = -1
285
286     logger.info("Trying to establish SSH connection to %s..." % floatip)
287     username = 'cirros'
288     password = 'cubswin:)'
289     ssh = paramiko.SSHClient()
290     ssh.set_missing_host_key_policy(paramiko.AutoAddPolicy())
291
292     timeout = 50
293     nolease = False
294     got_ip = False
295     discover_count = 0
296     cidr_first_octet = PRIVATE_SUBNET_CIDR.split('.')[0]
297     while timeout > 0:
298         try:
299             ssh.connect(floatip, username=username,
300                         password=password, timeout=2)
301             logger.debug("SSH connection established to %s." % floatip)
302             break
303         except:
304             logger.debug("Waiting for %s..." % floatip)
305             time.sleep(6)
306             timeout -= 1
307
308         console_log = vm.get_console_output()
309
310         # print each "Sending discover" captured on the console log
311         if (len(re.findall("Sending discover", console_log)) >
312                 discover_count and not got_ip):
313             discover_count += 1
314             logger.debug("Console-log '%s': Sending discover..."
315                          % NAME_VM_2)
316
317         # check if eth0 got an ip,the line looks like this:
318         # "inet addr:192.168."....
319         # if the dhcp agent fails to assing ip, this line will not appear
320         if "inet addr:" + cidr_first_octet in console_log and not got_ip:
321             got_ip = True
322             logger.debug("The instance '%s' succeeded to get the IP "
323                          "from the dhcp agent." % NAME_VM_2)
324
325         # if dhcp doesnt work,it shows "No lease, failing".The test will fail
326         if "No lease, failing" in console_log and not nolease and not got_ip:
327             nolease = True
328             logger.debug("Console-log '%s': No lease, failing..."
329                          % NAME_VM_2)
330             logger.info("The instance failed to get an IP from the "
331                         "DHCP agent. The test will probably timeout...")
332
333     if timeout == 0:  # 300 sec timeout (5 min)
334         logger.error("Cannot establish connection to IP '%s'. Aborting"
335                      % floatip)
336         exit(EXIT_CODE)
337     return ssh
338
339
340 def transfer_ping_script(ssh, floatip):
341     EXIT_CODE = -1
342
343     logger.info("Trying to transfer ping.sh to %s..." % floatip)
344     scp = SCPClient(ssh.get_transport())
345
346     ping_script = REPO_PATH + "testcases/OpenStack/vPing/ping.sh"
347     try:
348         scp.put(ping_script, "~/")
349     except:
350         logger.error("Cannot SCP the file '%s' to VM '%s'"
351                      % (ping_script, floatip))
352         exit(EXIT_CODE)
353
354     cmd = 'chmod 755 ~/ping.sh'
355     (stdin, stdout, stderr) = ssh.exec_command(cmd)
356     for line in stdout.readlines():
357         print line
358
359
360 def do_vping_ssh(ssh, test_ip):
361     logger.info("Waiting for ping...")
362
363     sec = 0
364     cmd = '~/ping.sh ' + test_ip
365     flag = False
366
367     while True:
368         time.sleep(1)
369         (stdin, stdout, stderr) = ssh.exec_command(cmd)
370         output = stdout.readlines()
371
372         for line in output:
373             if "vPing OK" in line:
374                 logger.info("vPing detected!")
375                 EXIT_CODE = 0
376                 flag = True
377                 break
378
379             elif sec == PING_TIMEOUT:
380                 logger.info("Timeout reached.")
381                 flag = True
382                 break
383         if flag:
384             break
385         logger.debug("Pinging %s. Waiting for response..." % test_ip)
386         sec += 1
387     return EXIT_CODE, time.time()
388
389
390 def do_vping_userdata(vm, test_ip):
391     logger.info("Waiting for ping...")
392     EXIT_CODE = -1
393     sec = 0
394     metadata_tries = 0
395
396     while True:
397         time.sleep(1)
398         console_log = vm.get_console_output()
399         if "vPing OK" in console_log:
400             logger.info("vPing detected!")
401             EXIT_CODE = 0
402             break
403         elif ("failed to read iid from metadata" in console_log or
404               metadata_tries > 5):
405             EXIT_CODE = -2
406             break
407         elif sec == PING_TIMEOUT:
408             logger.info("Timeout reached.")
409             break
410         elif sec % 10 == 0:
411             if "request failed" in console_log:
412                 logger.debug("It seems userdata is not supported in "
413                              "nova boot. Waiting a bit...")
414                 metadata_tries += 1
415             else:
416                 logger.debug("Pinging %s. Waiting for response..." % test_ip)
417         sec += 1
418
419     return EXIT_CODE, time.time()
420
421
422 def do_vping(case, vm, test_ip):
423     if is_userdata(case):
424         return do_vping_userdata(vm, test_ip)
425     else:
426         floatip = add_float_ip(vm)
427         ssh = establish_ssh(vm, floatip)
428         transfer_ping_script(ssh, floatip)
429         return do_vping_ssh(ssh, test_ip)
430
431
432 def check_result(code, start_time, stop_time):
433     test_status = "FAIL"
434     if code == 0:
435         logger.info("vPing OK")
436         duration = round(stop_time - start_time, 1)
437         logger.info("vPing duration:'%s'" % duration)
438         test_status = "PASS"
439     elif code == -2:
440         duration = 0
441         logger.info("Userdata is not supported in nova boot. Aborting test...")
442     else:
443         duration = 0
444         logger.error("vPing FAILED")
445
446     details = {'timestart': start_time,
447                'duration': duration,
448                'status': test_status}
449
450     return details
451
452
453 def push_result(report, case, start_time, stop_time, details):
454     if report:
455         try:
456             logger.debug("Pushing vPing %s results into DB..." % case)
457             ft_utils.push_results_to_db('functest',
458                                         case,
459                                         start_time,
460                                         stop_time,
461                                         details['status'],
462                                         details=details)
463         except:
464             logger.error("Error pushing results into Database '%s'"
465                          % sys.exc_info()[0])