From 5fbc516b2ccda19b9dc1bbce034e3f03aba66927 Mon Sep 17 00:00:00 2001 From: Yichen Wang Date: Wed, 25 May 2016 09:38:17 -0700 Subject: [PATCH] Adding logging framework to VMTP 1. Adding logging framework to VMTP; 2. Fix the dependency issue while building VMTP container; Change-Id: Idb532aaec758d0a062e0ccee16f1fb9dfd466a6f --- Dockerfile | 6 +- requirements.txt | 1 + vmtp/compute.py | 70 +++++++++++------------ vmtp/config.py | 5 ++ vmtp/credentials.py | 8 ++- vmtp/instance.py | 19 ++++--- vmtp/iperf_tool.py | 7 ++- vmtp/log.py | 51 +++++++++++++++++ vmtp/network.py | 39 +++++++------ vmtp/nuttcp_tool.py | 5 ++ vmtp/perf_instance.py | 5 ++ vmtp/perf_tool.py | 9 ++- vmtp/sshutils.py | 17 ++++-- vmtp/vmtp.py | 127 ++++++++++++++++++++++-------------------- 14 files changed, 230 insertions(+), 139 deletions(-) create mode 100644 vmtp/log.py diff --git a/Dockerfile b/Dockerfile index 71825d4..e7a7dbe 100644 --- a/Dockerfile +++ b/Dockerfile @@ -4,16 +4,14 @@ MAINTAINER vmtp-core # Install VMTP script and dependencies RUN apt-get update && apt-get install -y \ - lib32z1-dev \ + libz-dev \ libffi-dev \ libssl-dev \ libxml2-dev \ - libxslt1-dev \ + libxslt-dev \ libyaml-dev \ - openssh-client \ python \ python-dev \ - python-lxml \ python-pip \ && rm -rf /var/lib/apt/lists/* diff --git a/requirements.txt b/requirements.txt index 09441fd..30e4bd4 100644 --- a/requirements.txt +++ b/requirements.txt @@ -15,6 +15,7 @@ python-neutronclient<3,>=2.3.6 python-novaclient>=2.18.1 python-openstackclient>=0.4.1 python-keystoneclient>=1.0.0 +pytz>=2016.4 scp>=0.8.0 tabulate>=0.7.3 diff --git a/vmtp/compute.py b/vmtp/compute.py index 6a4c199..bbade9b 100644 --- a/vmtp/compute.py +++ b/vmtp/compute.py @@ -15,6 +15,7 @@ '''Module for Openstack compute operations''' +import log import os import time @@ -22,6 +23,10 @@ import glanceclient.exc as glance_exception import novaclient import novaclient.exceptions as exceptions +CONLOG = log.getLogger('vmtp', 'console') +LSLOG = log.getLogger('vmtp', 'logstash') +LOG = log.getLogger('vmtp', 'all') + class Compute(object): def __init__(self, nova_client, config): @@ -61,34 +66,32 @@ class Compute(object): while img.status in ['queued', 'saving'] and retry < retry_count: img = glance_client.images.find(name=img.name) retry = retry + 1 - if self.config.debug: - print "Image not yet active, retrying %s of %s..." \ - % (retry, retry_count) + CONLOG.debug("Image not yet active, retrying %s of %s..." % (retry, retry_count)) time.sleep(2) if img.status != 'active': raise Exception except glance_exception.HTTPForbidden: - print "Cannot upload image without admin access. Please make sure the "\ - "image is uploaded and is either public or owned by you." + CONLOG.error("Cannot upload image without admin access. Please make " + "sure the image is uploaded and is either public or owned by you.") return False except IOError: # catch the exception for file based errors. - print "Failed while uploading the image. Please make sure the " \ - "image at the specified location %s is correct." % image_url + CONLOG.error("Failed while uploading the image. Please make sure the " + "image at the specified location %s is correct." % image_url) return False except Exception: - print "Failed while uploading the image, please make sure the cloud "\ - "under test has the access to URL: %s." % image_url + CONLOG.error("Failed while uploading the image, please make sure the " + "cloud under test has the access to URL: %s." % image_url) return False return True def delete_image(self, glance_client, img_name): try: - print "Deleting image %s..." % img_name + CONLOG.log("Deleting image %s..." % img_name) img = glance_client.images.find(name=img_name) glance_client.images.delete(img.id) except Exception: - print "Failed to delete the image %s." % img_name + CONLOG.error("Failed to delete the image %s." % img_name) return False return True @@ -99,7 +102,7 @@ class Compute(object): for key in keypair_list: if key.name == name: self.novaclient.keypairs.delete(name) - print 'Removed public key %s' % (name) + CONLOG.info('Removed public key %s' % (name)) break # Test if keypair file is present if not create it @@ -123,8 +126,7 @@ class Compute(object): with open(os.path.expanduser(public_key_file)) as pkf: public_key = pkf.read() except IOError as exc: - print 'ERROR: Cannot open public key file %s: %s' % \ - (public_key_file, exc) + CONLOG.error('Cannot open public key file %s: %s' % (public_key_file, exc)) return None keypair = self.novaclient.keypairs.create(name, public_key) return keypair @@ -174,15 +176,14 @@ class Compute(object): if instance.status == 'ACTIVE': return instance if instance.status == 'ERROR': - print 'Instance creation error:' + instance.fault['message'] + CONLOG.error('Instance creation error:' + instance.fault['message']) break - if self.config.debug: - print "[%s] VM status=%s, retrying %s of %s..." \ - % (vmname, instance.status, (retry_attempt + 1), retry_count) + CONLOG.debug("[%s] VM status=%s, retrying %s of %s..." % + (vmname, instance.status, (retry_attempt + 1), retry_count)) time.sleep(2) # instance not in ACTIVE state - print('Instance failed status=' + instance.status) + CONLOG.error('Instance failed status=' + instance.status) self.delete_server(instance) return None @@ -212,11 +213,10 @@ class Compute(object): if server.name == vmname and server.status == "ACTIVE": return True # Sleep between retries - if self.config.debug: - print "[%s] VM not yet found, retrying %s of %s..." \ - % (vmname, (retry_attempt + 1), retry_count) + CONLOG.debug("[%s] VM not yet found, retrying %s of %s..." % + (vmname, (retry_attempt + 1), retry_count)) time.sleep(2) - print "[%s] VM not found, after %s attempts" % (vmname, retry_count) + CONLOG.error("[%s] VM not found, after %s attempts" % (vmname, retry_count)) return False # Returns True if server is found and deleted/False if not, @@ -225,7 +225,7 @@ class Compute(object): servers_list = self.get_server_list() for server in servers_list: if server.name == vmname: - print 'deleting server %s' % (server) + CONLOG.info('Deleting server %s' % (server)) self.novaclient.servers.delete(server) return True return False @@ -253,11 +253,11 @@ class Compute(object): if hyp.host == host: return self.normalize_az_host(hyp.zone, host) # no match on host - print('Error: passed host name does not exist: ' + host) + CONLOG.error('Passed host name does not exist: ' + host) return None if self.config.availability_zone: return self.normalize_az_host(None, host) - print('Error: --hypervisor passed without an az and no az configured') + CONLOG.error('--hypervisor passed without an az and no az configured') return None def sanitize_az_host(self, host_list, az_host): @@ -285,7 +285,7 @@ class Compute(object): return az_host # else continue - another zone with same host name? # no match - print('Error: no match for availability zone and host ' + az_host) + CONLOG.error('No match for availability zone and host ' + az_host) return None else: return self.auto_fill_az(host_list, az_host) @@ -318,8 +318,8 @@ class Compute(object): try: host_list = self.novaclient.services.list() except novaclient.exceptions.Forbidden: - print ('Warning: Operation Forbidden: could not retrieve list of hosts' - ' (likely no permission)') + CONLOG.warning('Operation Forbidden: could not retrieve list of hosts' + ' (likely no permission)') # the user has specified a list of 1 or 2 hypervisors to use if self.config.hypervisors: @@ -338,7 +338,7 @@ class Compute(object): # pick first 2 matches at most if len(avail_list) == 2: break - print 'Using hypervisors ' + ', '.join(avail_list) + CONLOG.info('Using hypervisors ' + ', '.join(avail_list)) else: for host in host_list: # this host must be a compute node @@ -360,10 +360,10 @@ class Compute(object): if not avail_list: if not self.config.availability_zone: - print('Error: availability_zone must be configured') + CONLOG.error('Availability_zone must be configured') elif host_list: - print('Error: no host matching the selection for availability zone: ' + - self.config.availability_zone) + CONLOG.error('No host matching the selection for availability zone: ' + + self.config.availability_zone) avail_list = [] else: avail_list = [self.config.availability_zone] @@ -379,7 +379,7 @@ class Compute(object): else: return False except novaclient.exceptions: - print "Exception in retrieving the hostId of servers" + CONLOG.warning("Exception in retrieving the hostId of servers") # Create a new security group with appropriate rules def security_group_create(self): @@ -407,7 +407,7 @@ class Compute(object): # Delete a security group def security_group_delete(self, group): if group: - print "Deleting security group" + CONLOG.info("Deleting security group") self.novaclient.security_groups.delete(group) # Add rules to the security group diff --git a/vmtp/config.py b/vmtp/config.py index ee49e61..a63c81c 100644 --- a/vmtp/config.py +++ b/vmtp/config.py @@ -14,8 +14,13 @@ # from attrdict import AttrDict +import log import yaml +CONLOG = log.getLogger('vmtp', 'console') +LSLOG = log.getLogger('vmtp', 'logstash') +LOG = log.getLogger('vmtp', 'all') + def config_load(file_name, from_cfg=None): '''Load a yaml file into a config dict, merge with from_cfg if not None The config file content taking precedence in case of duplicate diff --git a/vmtp/credentials.py b/vmtp/credentials.py index 2249856..f034cad 100644 --- a/vmtp/credentials.py +++ b/vmtp/credentials.py @@ -15,9 +15,13 @@ # Module for credentials in Openstack import getpass +import log import os import re +CONLOG = log.getLogger('vmtp', 'console') +LSLOG = log.getLogger('vmtp', 'logstash') +LOG = log.getLogger('vmtp', 'all') class Credentials(object): @@ -86,7 +90,7 @@ class Credentials(object): elif name == "CACERT": self.rc_cacert = value else: - print 'Error: rc file does not exist %s' % (openrc_file) + CONLOG.error('Error: rc file does not exist %s' % (openrc_file)) success = False elif not no_env: # no openrc file passed - we assume the variables have been @@ -94,7 +98,7 @@ class Credentials(object): # just check that they are present for varname in ['OS_USERNAME', 'OS_AUTH_URL', 'OS_TENANT_NAME']: if varname not in os.environ: - # print 'Warning: %s is missing' % (varname) + CONLOG.warning('%s is missing' % (varname)) success = False if success: self.rc_username = os.environ['OS_USERNAME'] diff --git a/vmtp/instance.py b/vmtp/instance.py index 9949177..e4a8ba8 100644 --- a/vmtp/instance.py +++ b/vmtp/instance.py @@ -15,10 +15,15 @@ import re +import log import monitor from netaddr import IPAddress import sshutils +CONLOG = log.getLogger('vmtp', 'console') +LSLOG = log.getLogger('vmtp', 'logstash') +LOG = log.getLogger('vmtp', 'all') + # a dictionary of sequence number indexed by a name prefix prefix_seq = {} @@ -63,7 +68,7 @@ class Instance(object): if not self.internal_ip: self.internal_ip = host_access.host self.ssh_access = host_access - self.buginf('Setup SSH for %s@%s' % (host_access.username, host_access.host)) + self.display('Setup SSH for %s@%s' % (host_access.username, host_access.host)) self.ssh = sshutils.SSH(self.ssh_access, connect_retry_count=self.config.ssh_retry_count) return True @@ -144,13 +149,12 @@ class Instance(object): return False self.ssh_access.host = fip['floatingip']['floating_ip_address'] self.ssh_ip_id = fip['floatingip']['id'] - self.buginf('Floating IP %s created', self.ssh_access.host) - self.buginf('Started - associating floating IP %s', self.ssh_access.host) + self.display('Associating floating IP %s', self.ssh_access.host) self.instance.add_floating_ip(self.ssh_access.host, ipv4_fixed_address) # extract the IP for the data network - self.buginf('Internal network IP: %s', self.internal_ip) - self.buginf('SSH IP: %s', self.ssh_access.host) + self.display('Internal network IP: %s', self.internal_ip) + self.display('SSH IP: %s', self.ssh_access.host) # create ssh session if not self.setup_ssh(self.ssh_access): @@ -174,12 +178,11 @@ class Instance(object): # Display a status message with the standard header that has the instance # name (e.g. [foo] some text) def display(self, fmt, *args): - print ('[%s] ' + fmt) % ((self.name,) + args) + CONLOG.info(('[%s] ' + fmt) % ((self.name,) + args)) # Debugging message, to be printed only in debug mode def buginf(self, fmt, *args): - if self.config.debug: - self.display(fmt, *args) + CONLOG.debug(('[%s] ' + fmt) % ((self.name,) + args)) # Ping an IP from this instance def ping_check(self, target_ip, ping_count, pass_threshold): diff --git a/vmtp/iperf_tool.py b/vmtp/iperf_tool.py index 610af1b..c56b366 100644 --- a/vmtp/iperf_tool.py +++ b/vmtp/iperf_tool.py @@ -15,8 +15,13 @@ import re +import log from perf_tool import PerfTool +CONLOG = log.getLogger('vmtp', 'console') +LSLOG = log.getLogger('vmtp', 'logstash') +LOG = log.getLogger('vmtp', 'all') + # The resulting unit should be in K MULTIPLIERS = {'K': 1, 'M': 1.0e3, @@ -28,7 +33,7 @@ def get_bdw_kbps(bdw, bdw_unit): return bdw / 1000 if bdw_unit in MULTIPLIERS: return int(bdw * MULTIPLIERS[bdw_unit]) - print('Error: unknown multiplier: ' + bdw_unit) + CONLOG.error('Error: unknown multiplier: ' + bdw_unit) return bdw class IperfTool(PerfTool): diff --git a/vmtp/log.py b/vmtp/log.py new file mode 100644 index 0000000..c6a4821 --- /dev/null +++ b/vmtp/log.py @@ -0,0 +1,51 @@ +# Copyright 2016 Cisco Systems, Inc. All rights reserved. +# +# Licensed under the Apache License, Version 2.0 (the "License"); you may +# not use this file except in compliance with the License. You may obtain +# a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, WITHOUT +# WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the +# License for the specific language governing permissions and limitations +# under the License. + +import logging + +def setup(product_name, debug=False, logfile=None): + log_level = logging.DEBUG if debug else logging.INFO + console_handler = file_handler = None + + # logging.basicConfig() + console_formatter_str = '%(asctime)s %(levelname)s %(message)s' + console_handler = logging.StreamHandler() + console_handler.setFormatter(logging.Formatter(console_formatter_str)) + + # Add a FileHandler if logfile is supplied + if logfile: + file_formatter_str = '%(asctime)s %(levelname)s %(message)s' + file_handler = logging.FileHandler(logfile, mode='w') + file_handler.setFormatter(logging.Formatter(file_formatter_str)) + + # Add appropriate handlers to loggers + console_logger = logging.getLogger(product_name + '_' + 'console') + console_logger.addHandler(console_handler) + console_logger.setLevel(log_level) + + logstash_logger = logging.getLogger(product_name + '_' + 'logstash') + logstash_logger.setLevel(log_level) + + all_logger = logging.getLogger(product_name + '_' + 'all') + all_logger.addHandler(console_handler) + all_logger.setLevel(log_level) + + if file_handler: + logstash_logger.addHandler(file_handler) + all_logger.addHandler(file_handler) + +def getLogger(product, target): + logger = logging.getLogger(product + "_" + target) + + return logger diff --git a/vmtp/network.py b/vmtp/network.py index 51bfe5d..9918633 100644 --- a/vmtp/network.py +++ b/vmtp/network.py @@ -15,11 +15,16 @@ import time +import log # Module containing a helper class for operating on OpenStack networks from neutronclient.common.exceptions import NetworkInUseClient from neutronclient.common.exceptions import NeutronException import vmtp +CONLOG = log.getLogger('vmtp', 'console') +LSLOG = log.getLogger('vmtp', 'logstash') +LOG = log.getLogger('vmtp', 'all') + class Network(object): # @@ -75,10 +80,10 @@ class Network(object): break if not self.ext_net: - print "No external network found." + CONLOG.error("No external network found.") return - print "Using external network: " + self.ext_net['name'] + CONLOG.info("Using external network: " + self.ext_net['name']) # Find or create the router to the external network ext_net_id = self.ext_net['id'] @@ -88,8 +93,7 @@ class Network(object): if external_gw_info: if external_gw_info['network_id'] == ext_net_id: self.ext_router = router - print 'Found external router: %s' % \ - (self.ext_router['name']) + CONLOG.info('Found external router: %s' % (self.ext_router['name'])) break # create a new external router if none found and a name was given @@ -97,7 +101,7 @@ class Network(object): if (not self.ext_router) and self.ext_router_name: self.ext_router = self.create_router(self.ext_router_name, self.ext_net['id']) - print '[%s] Created ext router' % (self.ext_router_name) + CONLOG.info('Created ext router %s.' % (self.ext_router_name)) self.ext_router_created = True if config.ipv6_mode: @@ -142,8 +146,7 @@ class Network(object): for network in self.networks: if network['name'] == network_name: - print ('Found existing internal network: %s' - % (network_name)) + CONLOG.info('Found existing internal network: %s' % (network_name)) return network body = { @@ -182,7 +185,7 @@ class Network(object): subnet = self.neutron_client.create_subnet(body)['subnet'] # add the subnet id to the network dict network['subnets'].append(subnet['id']) - print 'Created internal network: %s' % (network_name) + CONLOG.info('Created internal network: %s.' % (network_name)) return network # Delete a network and associated subnet @@ -193,7 +196,7 @@ class Network(object): for _ in range(1, 5): try: self.neutron_client.delete_network(network['id']) - print 'Network %s deleted' % (name) + CONLOG.info('Network %s deleted.' % (name)) break except NetworkInUseClient: time.sleep(1) @@ -217,7 +220,7 @@ class Network(object): port_ip = port['fixed_ips'][0] if (port['device_id'] == self.ext_router['id']) and \ (port_ip['subnet_id'] == self.vm_int_net[0]['subnets'][0]): - print 'Ext router already associated to the internal network' + CONLOG.info('Ext router already associated to the internal network.') return for int_net in self.vm_int_net: @@ -225,8 +228,7 @@ class Network(object): 'subnet_id': int_net['subnets'][0] } self.neutron_client.add_interface_router(self.ext_router['id'], body) - if self.config.debug: - print 'Ext router associated to ' + int_net['name'] + CONLOG.debug('Ext router associated to ' + int_net['name']) # If ipv6 is enabled than add second subnet if self.ipv6_enabled: body = { @@ -254,7 +256,7 @@ class Network(object): except NeutronException: # May fail with neutronclient.common.exceptions.Conflict # if there are floating IP in use - just ignore - print('Router interface may have floating IP in use: not deleted') + CONLOG.warning('Router interface may have floating IP in use: not deleted') # Lookup network given network name def lookup_network(self, network_name): @@ -283,7 +285,6 @@ class Network(object): # Update a router given router and network id def update_router(self, router_id, net_id): - print net_id body = { "router": { "name": "pns-router", @@ -307,12 +308,11 @@ class Network(object): body['port']['binding:vnic_type'] = vnic_type port = self.neutron_client.create_port(body) if self.config.debug: - print 'Created port ' + port['port']['id'] + CONLOG.info('Created port ' + port['port']['id']) return port['port'] def delete_port(self, port): - if self.config.debug: - print 'Deleting port ' + port['id'] + CONLOG.debug('Deleting port ' + port['id']) self.neutron_client.delete_port(port['id']) # Create a floating ip on the external network and return it @@ -344,10 +344,9 @@ class Network(object): self.neutron_client.remove_gateway_router( self.ext_router['id']) self.neutron_client.delete_router(self.ext_router['id']) - print 'External router %s deleted' % \ - (self.ext_router['name']) + CONLOG.info('External router %s deleted' % (self.ext_router['name'])) except TypeError: - print "No external router set" + CONLOG.info("No external router set") def _get_l2agent_type(self): ''' diff --git a/vmtp/nuttcp_tool.py b/vmtp/nuttcp_tool.py index d71d748..fa69091 100644 --- a/vmtp/nuttcp_tool.py +++ b/vmtp/nuttcp_tool.py @@ -15,9 +15,14 @@ import re +import log from perf_tool import PerfTool import sshutils +CONLOG = log.getLogger('vmtp', 'console') +LSLOG = log.getLogger('vmtp', 'logstash') +LOG = log.getLogger('vmtp', 'all') + class NuttcpTool(PerfTool): def __init__(self, instance): diff --git a/vmtp/perf_instance.py b/vmtp/perf_instance.py index 81c7573..33872e5 100644 --- a/vmtp/perf_instance.py +++ b/vmtp/perf_instance.py @@ -14,8 +14,13 @@ # from instance import Instance as Instance +import log from perf_tool import PingTool +CONLOG = log.getLogger('vmtp', 'console') +LSLOG = log.getLogger('vmtp', 'logstash') +LOG = log.getLogger('vmtp', 'all') + class PerfInstance(Instance): '''An openstack instance to run performance tools ''' diff --git a/vmtp/perf_tool.py b/vmtp/perf_tool.py index 59f2c9c..c5444d6 100644 --- a/vmtp/perf_tool.py +++ b/vmtp/perf_tool.py @@ -16,11 +16,16 @@ import abc import re +import log from pkg_resources import resource_filename # where to copy the tool on the target, must end with slash SCP_DEST_DIR = '/tmp/' +CONLOG = log.getLogger('vmtp', 'console') +LSLOG = log.getLogger('vmtp', 'logstash') +LOG = log.getLogger('vmtp', 'all') + # # A base class for all tools that can be associated to an instance # @@ -188,7 +193,7 @@ class PerfTool(object): min_kbps = int((max_kbps + min_kbps) / 2) kbps = int((max_kbps + min_kbps) / 2) - # print ' undershot, min=%d kbps=%d max=%d' % (min_kbps, kbps, max_kbps) + # CONLOG.debug(' undershot, min=%d kbps=%d max=%d' % (min_kbps, kbps, max_kbps)) elif loss_rate > max_loss_rate: # overshot max_kbps = kbps @@ -196,7 +201,7 @@ class PerfTool(object): kbps = measured_kbps else: kbps = int((max_kbps + min_kbps) / 2) - # print ' overshot, min=%d kbps=%d max=%d' % (min_kbps, kbps, max_kbps) + # CONLOG.debug(' overshot, min=%d kbps=%d max=%d' % (min_kbps, kbps, max_kbps)) else: # converged within loss rate bracket break diff --git a/vmtp/sshutils.py b/vmtp/sshutils.py index 719dcd0..3274e3f 100644 --- a/vmtp/sshutils.py +++ b/vmtp/sshutils.py @@ -64,9 +64,14 @@ import StringIO import sys import time +import log import paramiko import scp +CONLOG = log.getLogger('vmtp', 'console') +LSLOG = log.getLogger('vmtp', 'logstash') +LOG = log.getLogger('vmtp', 'all') + # from rally.openstack.common.gettextutils import _ @@ -407,7 +412,7 @@ class SSH(object): if int(pkt_loss) < int(pass_threshold): return 1 else: - print 'Ping to %s failed: %s' % (target_ip, cmd_output) + CONLOG.error('Ping to %s failed: %s' % (target_ip, cmd_output)) return 0 def get_file_from_host(self, from_path, to_path): @@ -420,7 +425,7 @@ class SSH(object): try: scpcon.get(from_path, to_path) except scp.SCPException as exp: - print "Receive failed: [%s]" % exp + CONLOG.error("Receive failed: [%s]" % exp) return 0 return 1 @@ -434,7 +439,7 @@ class SSH(object): try: scpcon.put(from_path, remote_path=to_path) except scp.SCPException as exp: - print "Send failed: [%s]" % exp + CONLOG.error("Send failed: [%s]" % exp) return 0 return 1 @@ -460,7 +465,7 @@ class SSH(object): if self.stat(os_release_file): data = self.read_remote_file(os_release_file) if data is None: - print "ERROR:Failed to read file %s" % os_release_file + CONLOG.error("Failed to read file %s" % os_release_file) return None for line in data.splitlines(): @@ -478,7 +483,7 @@ class SSH(object): if self.stat(sys_release_file): data = self.read_remote_file(sys_release_file) if data is None: - print "ERROR:Failed to read file %s" % sys_release_file + CONLOG.error("Failed to read file %s" % sys_release_file) return None for line in data.splitlines(): @@ -507,7 +512,7 @@ class SSH(object): if mobj: return mobj.group(0) - print "%s pkg installed " % rpm_pkg + CONLOG.info("%s pkg installed " % rpm_pkg) return None diff --git a/vmtp/vmtp.py b/vmtp/vmtp.py index de0bfd6..dcd9587 100755 --- a/vmtp/vmtp.py +++ b/vmtp/vmtp.py @@ -18,7 +18,7 @@ import argparse import datetime import hashlib import json -import logging +import log import os import pprint import re @@ -44,14 +44,18 @@ import pns_mongo from prettytable import PrettyTable import sshutils +CONLOG = log.getLogger('vmtp', 'console') +LSLOG = log.getLogger('vmtp', 'logstash') +LOG = log.getLogger('vmtp', 'all') + flow_num = 0 class FlowPrinter(object): @staticmethod def print_desc(desc): global flow_num flow_num = flow_num + 1 - print "=" * 60 - print('Flow %d: %s' % (flow_num, desc)) + CONLOG.info("=" * 60) + CONLOG.info('Flow %d: %s' % (flow_num, desc)) class ResultsCollector(object): @@ -70,13 +74,6 @@ class ResultsCollector(object): def add_flow_result(self, flow_res): self.results['flows'].append(flow_res) - self.ppr.pprint(flow_res) - - def display(self): - self.ppr.pprint(self.results) - - def pprint(self, res): - self.ppr.pprint(res) def get_result(self, key): if keystoneclient in self.results: @@ -102,13 +99,13 @@ class ResultsCollector(object): def save(self, cfg): '''Save results in json format file.''' - print('Saving results in json file: ' + cfg.json_file + "...") + CONLOG.info('Saving results in json file: ' + cfg.json_file + "...") with open(cfg.json_file, 'w') as jfp: json.dump(self.results, jfp, indent=4, sort_keys=True) def save_to_db(self, cfg): '''Save results to MongoDB database.''' - print "Saving results to MongoDB database..." + CONLOG.info("Saving results to MongoDB database...") post_id = pns_mongo.\ pns_add_test_result_to_mongod(cfg.vmtp_mongod_ip, cfg.vmtp_mongod_port, @@ -116,7 +113,7 @@ class ResultsCollector(object): cfg.vmtp_collection, self.results) if post_id is None: - print "ERROR: Failed to add result to DB" + CONLOG.error("Failed to add result to DB") class VmtpException(Exception): pass @@ -187,14 +184,14 @@ class VmtpTest(object): self.instance_access.public_key_file = pub_key self.instance_access.private_key_file = priv_key else: - print('Error: Default keypair ~/.ssh/id_rsa[.pub] does not exist. Please ' - 'either create one in your home directory, or specify your keypair ' - 'information in the config file before running VMTP.') + CONLOG.error('Default keypair ~/.ssh/id_rsa[.pub] does not exist. Please ' + 'either create one in your home directory, or specify your ' + 'keypair information in the config file before running VMTP.') sys.exit(1) if self.config.debug and self.instance_access.public_key_file: - print('VM public key: ' + self.instance_access.public_key_file) - print('VM private key: ' + self.instance_access.private_key_file) + CONLOG.info('VM public key: ' + self.instance_access.public_key_file) + CONLOG.info('VM private key: ' + self.instance_access.private_key_file) # If we need to reuse existing vms just return without setup if not self.config.reuse_existing_vm: @@ -212,8 +209,8 @@ class VmtpTest(object): self.image_instance = self.comp.find_image(self.config.image_name) if self.image_instance is None: if self.config.vm_image_url != "": - print '%s: image for VM not found, trying to upload it ...' \ - % (self.config.image_name) + CONLOG.info('%s: image for VM not found, trying to upload it ...' % + (self.config.image_name)) keystone = keystoneclient.Client(**creds) glance_endpoint = keystone.service_catalog.url_for( service_type='image', endpoint_type='publicURL') @@ -228,24 +225,24 @@ class VmtpTest(object): self.image_uploaded = True else: # Exit the pogram - print '%s: image to launch VM not found. ABORTING.' \ - % (self.config.image_name) + CONLOG.error('%s: image to launch VM not found. ABORTING.' % + (self.config.image_name)) sys.exit(1) self.assert_true(self.image_instance) - print 'Found image %s to launch VM, will continue' % (self.config.image_name) + CONLOG.info('Found image %s to launch VM, will continue' % (self.config.image_name)) self.flavor_type = self.comp.find_flavor(self.config.flavor_type) self.net = network.Network(neutron, self.config) self.rescol.add_property('l2agent_type', self.net.l2agent_type) - print "OpenStack agent: " + self.net.l2agent_type + CONLOG.info("OpenStack agent: " + self.net.l2agent_type) try: network_type = self.net.vm_int_net[0]['provider:network_type'] - print "OpenStack network type: " + network_type + CONLOG.info("OpenStack network type: " + network_type) self.rescol.add_property('encapsulation', network_type) except KeyError as exp: network_type = 'Unknown' - print "Provider network type not found: ", str(exp) + CONLOG.info("Provider network type not found: ", str(exp)) # Create a new security group for the test self.sec_group = self.comp.security_group_create() @@ -323,6 +320,7 @@ class VmtpTest(object): bidirectional=True) if res: self.rescol.add_flow_result(res) + CONLOG.info(self.rescol.ppr.pformat(res)) client.dispose() def add_location(self, label): @@ -358,11 +356,12 @@ class VmtpTest(object): results_list = perf_output['results'] for res_dict in results_list: if 'error' in res_dict: - print('Stopping execution on error, cleanup all VMs/networks manually') - self.rescol.pprint(perf_output) + CONLOG.error('Stopping execution on error, cleanup all VMs/networks manually') + CONLOG.info(self.rescol.ppr.pformat(perf_output)) sys.exit(2) self.rescol.add_flow_result(perf_output) + CONLOG.info(self.rescol.ppr.pformat(perf_output)) def measure_vm_flows(self): # scenarios need to be tested for both inter and intra node @@ -398,7 +397,7 @@ class VmtpTest(object): ''' Clean up the floating ip and VMs ''' - print '---- Cleanup ----' + CONLOG.info('Cleaning up...') if self.server: self.server.dispose() if self.client: @@ -414,7 +413,7 @@ class VmtpTest(object): self.comp.security_group_delete(self.sec_group) except ClientException: # May throw novaclient.exceptions.BadRequest if in use - print('Security group in use: not deleted') + CONLOG.warning('Security group in use: not deleted') if self.image_uploaded and self.config.delete_image_after_run: self.comp.delete_image(self.glance_client, self.config.image_name) @@ -427,12 +426,11 @@ class VmtpTest(object): except KeyboardInterrupt: traceback.format_exc() except (VmtpException, sshutils.SSHError, ClientException, Exception): - print 'print_exc:' - traceback.print_exc() + CONLOG.error(traceback.print_exc()) error_flag = True if self.config.stop_on_error and error_flag: - print('Stopping execution on error, cleanup all VMs/networks manually') + CONLOG.error('Stopping execution on error, cleanup all VMs/networks manually') sys.exit(2) else: self.teardown() @@ -460,7 +458,7 @@ def test_native_tp(nhosts, ifname, config): # use the IP address configured on given interface server_ip = server.get_interface_ip(ifname) if not server_ip: - print('Error: cannot get IP address for interface ' + ifname) + CONLOG.error('Cannot get IP address for interface ' + ifname) else: server.display('Clients will use server IP address %s (%s)' % (server_ip, ifname)) @@ -494,10 +492,10 @@ def test_native_tp(nhosts, ifname, config): def get_controller_info(ssh_access, net, res_col, retry_count): if not ssh_access: return - print 'Fetching OpenStack deployment details...' + CONLOG.info('Fetching OpenStack deployment details...') sshcon = sshutils.SSH(ssh_access, connect_retry_count=retry_count) if sshcon is None: - print 'ERROR: Cannot connect to the controller node' + CONLOG.error('Cannot connect to the controller node') return res = {} res['distro'] = sshcon.get_host_os_version() @@ -512,7 +510,7 @@ def get_controller_info(ssh_access, net, res_col, retry_count): net.internal_iface_dict) res['l2agent_version'] = sshcon.get_l2agent_version(l2type) # print results - res_col.pprint(res) + CONLOG.info(res_col.ppr.pformat(res)) res_col.add_properties(res) def gen_report_data(proto, result): @@ -632,13 +630,15 @@ def print_report(results): for row in table: ptable.add_row(row) - print "\nSummary of results" - print "==================" - print "Total Scenarios: %d" % (len(table) - 1) - print "Passed Scenarios: %d [%.2f%%]" % (cnt_passed, passed_rate) - print "Failed Scenarios: %d [%.2f%%]" % (cnt_failed, failed_rate) - print "Skipped Scenarios: %d" % (cnt_skipped) - print ptable + summary = "Summary of results\n" + summary += "==================\n" + summary += "Total Scenarios: %d\n" % (len(table) - 1) + summary += "Passed Scenarios: %d [%.2f%%]\n" % (cnt_passed, passed_rate) + summary += "Failed Scenarios: %d [%.2f%%]\n" % (cnt_failed, failed_rate) + summary += "Skipped Scenarios: %d\n" % (cnt_skipped) + summary += str(ptable) + + CONLOG.info(summary) def normalize_paths(cfg): ''' @@ -666,7 +666,7 @@ def get_ssh_access(opt_name, opt_value, config): host_access.private_key_file = config.private_key_file host_access.public_key_file = config.public_key_file if host_access.error: - print'Error for --' + (opt_name + ':' + host_access.error) + CONLOG.error('Error for --' + (opt_name + ':' + host_access.error)) sys.exit(2) return host_access @@ -768,7 +768,6 @@ def parse_opts_from_cli(): '(implies --protocols M[...], --tp-tool nuttcp )', metavar='') - parser.add_argument('--bandwidth', dest='vm_bandwidth', action='store', default=0, @@ -844,6 +843,11 @@ def parse_opts_from_cli(): help='The test description to be stored in JSON or MongoDB', metavar='') + parser.add_argument('--log-file', '--logfile', dest='logfile', + action='store', + help='Filename for saving VMTP logs', + metavar='') + return parser.parse_known_args()[0] def merge_opts_to_configs(opts): @@ -876,15 +880,15 @@ def merge_opts_to_configs(opts): config.same_network_only = opts.same_network_only if config.public_key_file and not os.path.isfile(config.public_key_file): - print('Warning: invalid public_key_file:' + config.public_key_file) + CONLOG.warning('Invalid public_key_file:' + config.public_key_file) config.public_key_file = None if config.private_key_file and not os.path.isfile(config.private_key_file): - print('Warning: invalid private_key_file:' + config.private_key_file) + CONLOG.warning('Invalid private_key_file:' + config.private_key_file) config.private_key_file = None # direct: use SR-IOV ports for all the test VMs if opts.vnic_type not in [None, 'direct', 'macvtap', 'normal']: - print('Invalid vnic-type: ' + opts.vnic_type) + CONLOG.error('Invalid vnic-type: ' + opts.vnic_type) sys.exit(1) config.vnic_type = opts.vnic_type config.hypervisors = opts.hypervisors @@ -933,8 +937,8 @@ def merge_opts_to_configs(opts): raise ValueError val = int(opts.vm_bandwidth[0:-1]) except ValueError: - print 'Invalid --bandwidth parameter. A valid input must '\ - 'specify only one unit (K|M|G).' + CONLOG.error('Invalid --bandwidth parameter. A valid input must ' + 'specify only one unit (K|M|G).') sys.exit(1) config.vm_bandwidth = int(val * (10 ** (ex_unit * 3))) @@ -946,8 +950,8 @@ def merge_opts_to_configs(opts): for i in xrange(len(config.tcp_pkt_sizes)): config.tcp_pkt_sizes[i] = int(config.tcp_pkt_sizes[i]) except ValueError: - print 'Invalid --tcpbuf parameter. A valid input must be '\ - 'integers seperated by comma.' + CONLOG.error('Invalid --tcpbuf parameter. A valid input must be ' + 'integers seperated by comma.') sys.exit(1) if opts.udp_pkt_sizes: @@ -956,8 +960,8 @@ def merge_opts_to_configs(opts): for i in xrange(len(config.udp_pkt_sizes)): config.udp_pkt_sizes[i] = int(config.udp_pkt_sizes[i]) except ValueError: - print 'Invalid --udpbuf parameter. A valid input must be '\ - 'integers seperated by comma.' + CONLOG.error('Invalid --udpbuf parameter. A valid input must be ' + 'integers seperated by comma.') sys.exit(1) if opts.reuse_network_name: @@ -983,12 +987,12 @@ def merge_opts_to_configs(opts): if mobj: config.gmond_svr_ip = mobj.group(1) config.gmond_svr_port = mobj.group(2) - print "Ganglia monitoring enabled (%s:%s)" % \ - (config.gmond_svr_ip, config.gmond_svr_port) + CONLOG.info("Ganglia monitoring enabled (%s:%s)" % + (config.gmond_svr_ip, config.gmond_svr_port)) config.time = 30 else: - print 'Invalid --monitor syntax: ' + opts.monitor + CONLOG.warning('Invalid --monitor syntax: ' + opts.monitor) ################################################### # Once we parse the config files, normalize @@ -1013,7 +1017,7 @@ def merge_opts_to_configs(opts): elif opts.tp_tool.lower() == 'iperf': config.tp_tool = iperf_tool.IperfTool else: - print 'Invalid transport tool: ' + opts.tp_tool + CONLOG.warning('Invalid transport tool: ' + opts.tp_tool) sys.exit(1) else: config.tp_tool = None @@ -1063,12 +1067,13 @@ def run_vmtp(opts): for item in native_tp_results: rescol.add_flow_result(item) + CONLOG.info(rescol.ppr.pformat(item)) # Parse the credentials of the OpenStack cloud, and run the benchmarking cred = credentials.Credentials(opts.rc, opts.passwd, opts.no_env) if cred.rc_auth_url: if config.debug: - print 'Using ' + cred.rc_auth_url + CONLOG.info('Using ' + cred.rc_auth_url) vmtp_instance = VmtpTest(config, cred, rescol) vmtp_instance.run() vmtp_net = vmtp_instance.net @@ -1103,8 +1108,8 @@ def run_vmtp(opts): return rescol.results def main(): - logging.basicConfig() opts = parse_opts_from_cli() + log.setup('vmtp', debug=opts.debug, logfile=opts.logfile) run_vmtp(opts) if __name__ == '__main__':