Merge pull request #146 from aristanetworks/features/logging

Implement consistent logging in all modules

ansible_collections/arista/cvp/plugins/module_utils/cv_api2019.py

@@ -895,7 +895,7 @@ def get_container_by_name(self, name):
                 container (dict): Container info in dictionary format or None
         '''
         self.log.debug('Get info for container %s' % name)
-        logging.debug(
+        self.log.debug(
             '* cv_api2019 - get_container_by_name - container name is: %s', str(name))
         containers = self.clnt.get('/provisioning/searchTopology.do?queryParam=%s'
                                    '&startIndex=0&endIndex=0' % qplus(name))

ansible_collections/arista/cvp/plugins/module_utils/cv_client.py

@@ -89,6 +89,7 @@
 import inspect
 import traceback
 from logging.handlers import SysLogHandler
+import ansible_collections.arista.cvp.plugins.module_utils.logger
 from itertools import cycle
 from ansible_collections.arista.cvp.plugins.module_utils.cv_client_errors import CvpApiError, CvpLoginError, CvpRequestError, CvpSessionLogOutError
 REQUESTS_IMP_ERR = None
@@ -144,8 +145,8 @@ def __init__(self, logger='cv_apiClient', syslog=False, filename=None,
         self.headers = {'Accept': 'application/json',
                         'Content-Type': 'application/json'}
 
-        self.log = logging.getLogger(logger)
-        self.set_log_level(log_level)
+        self.log = logging.getLogger('arista.cvp.cv_client')
+        self.log.info('Start cv_client API execution')
         if syslog:
             # Enables sending logging messages to the local syslog server.
             self.log.addHandler(SysLogHandler())
@@ -278,6 +279,7 @@ def connect(self, nodes, username, password, connect_timeout=10,
         self._create_session(all_nodes=True)
         # Verify that we can connect to at least one node
         if not self.session:
+            self.log.error(' error connecting cvp: %s', str(self.error_msg))
             raise CvpLoginError(self.error_msg)
         else:
             # Instantiate the CvpApi class

ansible_collections/arista/cvp/plugins/module_utils/logger.py

@@ -0,0 +1,64 @@
+#!/usr/bin/env python
+# coding: utf-8 -*-
+#
+# FIXME: required to pass ansible-test
+# GNU General Public License v3.0+
+#
+# Copyright 2019 Arista Networks AS-EMEA
+#
+# 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.
+#
+
+from __future__ import (absolute_import, division, print_function)
+__metaclass__ = type
+
+import logging
+from logging.handlers import RotatingFileHandler
+import os
+
+# Get Logging level from Environment variable / Default INFO
+
+# Define standard logging verbosity
+LEVELS = {'debug': logging.DEBUG,
+          'info': logging.INFO,
+          'warning': logging.WARNING,
+          'error': logging.ERROR,
+          'critical': logging.CRITICAL}
+
+# Set loglevel for arista.cvp modules
+LOGGING_LEVEL = os.getenv('ANSIBLE_CVP_LOG_LEVEL', 'info')
+LOGLEVEL = LEVELS.get(LOGGING_LEVEL, logging.NOTSET)
+
+# Set loglevel for urllib3
+LOGGING_LEVEL_URLLIB3 = os.getenv('ANSIBLE_CVP_LOG_APICALL', 'warning')
+LOGLEVEL_URLLIB3 = LEVELS.get(LOGGING_LEVEL_URLLIB3, logging.WARNING)
+
+# Get filename to write logs / default /temp/arista.cvp.debug.log
+LOGGING_FILENAME = os.getenv(
+    'ANSIBLE_CVP_LOG_FILE', '/tmp/arista.cvp.debug.log')
+
+# set a format which is simpler for console use
+formatter = logging.Formatter(
+    '%(name)-12s: %(levelname)-s - func: %(funcName)-12s (L:%(lineno)-3d) - %(message)s')
+
+# set up ROOT handler to use logging with file rotation.
+handler = logging.handlers.RotatingFileHandler(
+    LOGGING_FILENAME, maxBytes=1000000, backupCount=5)
+handler.setFormatter(formatter)
+handler.setLevel(LOGLEVEL)
+# Unset default logging level for root handler
+logging.getLogger('').setLevel(logging.NOTSET)
+logging.getLogger('').addHandler(handler)
+
+# Configure URLLIB3 logging (default Warning to avoid too much verbosity)
+logging.getLogger("urllib3").setLevel(LOGLEVEL_URLLIB3)

ansible_collections/arista/cvp/plugins/modules/cv_configlet.py

@@ -31,6 +31,8 @@
 # Required by Ansible and CVP
 import re
 import traceback
+import logging
+import ansible_collections.arista.cvp.plugins.module_utils.logger
 from ansible.module_utils.basic import AnsibleModule
 from ansible_collections.arista.cvp.plugins.module_utils.cv_client import CvpClient
 from ansible_collections.arista.cvp.plugins.module_utils.cv_client_errors import CvpLoginError, CvpApiError
@@ -123,6 +125,9 @@
       register: cvp_configlet
 '''
 
+MODULE_LOGGER = logging.getLogger('arista.cvp.cv_configlet')
+MODULE_LOGGER.info('Start cv_configlet module execution')
+
 
 def compare(fromText, toText, fromName='', toName='', lines=10):
     """ Compare text string in 'fromText' with 'toText' and produce

ansible_collections/arista/cvp/plugins/modules/cv_container.py

@@ -33,6 +33,7 @@
 import json
 import traceback
 import logging
+import ansible_collections.arista.cvp.plugins.module_utils.logger
 from ansible.module_utils.basic import AnsibleModule
 from ansible.module_utils.connection import Connection, ConnectionError
 from ansible_collections.arista.cvp.plugins.module_utils.cv_client import CvpClient
@@ -110,6 +111,10 @@
 '''
 
 
+MODULE_LOGGER = logging.getLogger('arista.cvp.cv_container')
+MODULE_LOGGER.info('Start cv_container module execution')
+
+
 def create_builtin_containers(facts, debug=False):
     """
     Update builtin containers with root container name
@@ -142,10 +147,10 @@ def get_root_container(containers_fact, debug=True):
         Name of the root container, if not found, return Tenant as default value
     """
     for container in containers_fact:
-        logging.debug('  -> CloudVision container %s', str(container))
+        MODULE_LOGGER.debug('working on container %s', str(container))
         if container['Key'] == 'root':
             # if debug:
-            logging.debug('  -> CloudVision ROOT container has name %s', container['Name'])
+            MODULE_LOGGER.info('! ROOT container has name %s', container['Name'])
             return container['Name']
     return 'Tenant'
 
@@ -249,8 +254,7 @@ def tree_build_from_dict(containers=None, root='Tenant', debug=False):
     tree = Tree()  # Create the base node
     previously_created = list()
     # Create root node to mimic CVP behavior
-    if debug:
-        logging.debug('  -> tree_build_from_dict - containers list is %s', str(containers))
+    MODULE_LOGGER.debug('containers list is %s', str(containers))
     tree.create_node(root, root)
     # Iterate for first level of containers directly attached under root.
     for container_name, container_info in containers.items():
@@ -319,8 +323,7 @@ def tree_build_from_list(containers, root='Tenant', debug=False):
     tree = Tree()  # Create the base node
     previously_created = list()
     # Create root node to mimic CVP behavior
-    if debug:
-        logging.debug('  -> tree_build_from_list - containers list is %s', str(containers))
+    MODULE_LOGGER.debug('containers list is %s', str(containers))
     tree.create_node(root, root)
     # Iterate for first level of containers directly attached under root.
     for cvp_container in containers:
@@ -544,18 +547,19 @@ def is_empty(module, container_name, facts, debug=False):
 
 
 def is_container_empty(module, container_name, debug=False):
-    logging.debug('* is_container_empty - get_devices_in_container %s', container_name)
+    MODULE_LOGGER.debug('get_devices_in_container %s', container_name)
     container_status = module.client.api.get_devices_in_container(container_name)
+    MODULE_LOGGER.debug('* is_container_empty - get_devices_in_container %s', str(container_status))
     if container_status is not None:
         if isIterable(container_status) and len(container_status) > 0:
-            logging.debug(
-                '* is_container_empty - Found devices in container %s', str(container_name))
+            MODULE_LOGGER.info(
+                'Found devices in container %s', str(container_name))
             return False
-        logging.debug(
-            '* is_container_empty - No devices found in container %s', str(container_name))
+        MODULE_LOGGER.info(
+            'No devices found in container %s', str(container_name))
         return True
-    logging.debug(
-        '* is_container_empty - No devices found in container %s (default behavior)', str(container_name))
+    MODULE_LOGGER.debug(
+        'No devices found in container %s (default behavior)', str(container_name))
     return False
 
 
@@ -618,7 +622,7 @@ def delete_unused_containers(module, intended, facts, debug=False):
             if cvp_container not in container_intended_ordered_list:
                 container_to_delete.append(cvp_container)
 
-    logging.debug('* delete_unused_containers - List of containers to delete: %s', str(container_to_delete))
+    MODULE_LOGGER.info('List of containers to delete: %s', str(container_to_delete))
 
     # Read cvp_container from end. If containers are part of container_to_delete, then delete container
     for cvp_container in reversed(container_to_delete):
@@ -628,15 +632,16 @@ def delete_unused_containers(module, intended, facts, debug=False):
             container_fact = get_container_facts(container_name=cvp_container, facts=facts)
             # Check we have a result. Even if we should always have a match here.
             if container_fact is not None:
-                logging.debug('* delete_unused_containers - %s', container_fact['name'])
+                MODULE_LOGGER.info('container: %s', container_fact['name'])
                 response = None
                 try:
                     response = process_container(module=module,
                                                  container=container_fact['name'],
                                                  parent=container_fact['parentName'],
                                                  action='delete')
                 except:  # noqa E722
-                    logging.error("Unexpected error: %s", str(sys.exc_info()[0]))
+                    MODULE_LOGGER.error(
+                        "Unexpected error: %s", str(sys.exc_info()[0]))
                     continue
                 if response[0]:
                     count_container_deletion += 1
@@ -917,7 +922,7 @@ def delete_topology(module, intended, facts, debug=False):
     container_intended_tree = tree_build_from_dict(containers=intended, root=topology_root, debug=debug)
     container_intended_ordered_list = tree_to_list(json_data=container_intended_tree, myList=list())
 
-    logging.debug('* delete_topology - container_intended_ordered_list %s', container_intended_ordered_list)
+    MODULE_LOGGER.info('container_intended_ordered_list %s', container_intended_ordered_list)
 
     container_to_delete = list()
     # Check if containers can be deleted (i.e. no attached devices)
@@ -931,18 +936,18 @@ def delete_topology(module, intended, facts, debug=False):
                 if cvp_container in container_intended_ordered_list:
                     container_to_delete.append(cvp_container)
 
-    logging.debug('* delete_topology - container_to_delete %s', str(container_to_delete))
+    MODULE_LOGGER.debug('containers_to_delete %s', str(container_to_delete))
 
     for cvp_container in reversed(container_to_delete):
-        logging.debug('* delete_topology - deletion of cvp_container %s', str(cvp_container))
+        MODULE_LOGGER.debug('deletion of cvp_container %s', str(cvp_container))
         # Check if container is not in intended topology and not a default container.
         if cvp_container in container_to_delete and cvp_container not in builtin_containers:
             # Get container fact for parentName
-            logging.debug('* delete_topology - get_container_facts %s', cvp_container)
+            MODULE_LOGGER.debug('get_container_facts %s', cvp_container)
             container_fact = get_container_facts(container_name=cvp_container, facts=facts)
             # Check we have a result. Even if we should always have a match here.
             if container_fact is not None:
-                logging.debug('* delete_topology - %s', container_fact['name'])
+                MODULE_LOGGER.debug('container name: %s', container_fact['name'])
                 response = process_container(module=module,
                                              container=container_fact['name'],
                                              parent=container_fact['parentName'],
@@ -994,10 +999,6 @@ def main():
                   choices=['merge', 'override', 'delete'])
     )
 
-    if DEBUG_MODULE:
-        logging.basicConfig(format='%(asctime)s %(message)s',
-                            filename='cv_container.log', level=logging.DEBUG)
-
     module = AnsibleModule(argument_spec=argument_spec,
                            supports_check_mode=False)
     result = dict(changed=False, data={})

ansible_collections/arista/cvp/plugins/modules/cv_device.py

@@ -29,6 +29,8 @@
 }
 
 import re
+import logging
+import ansible_collections.arista.cvp.plugins.module_utils.logger
 from ansible.module_utils.basic import AnsibleModule
 from ansible.module_utils.connection import Connection, ConnectionError
 from ansible_collections.arista.cvp.plugins.module_utils.cv_client import CvpClient
@@ -115,6 +117,9 @@
       register: cvp_device
 '''
 
+MODULE_LOGGER = logging.getLogger('arista.cvp.cv_device')
+MODULE_LOGGER.info('Start cv_device module execution')
+
 
 def connect(module):
     ''' Connects to CVP device using user provided credentials from playbook.