Enhance logging and error handling

Author: PhillSimonds

development/base_configuration.py

@@ -114,7 +114,20 @@
 
 # Enable custom logging. Please see the Django documentation for detailed guidance on configuring custom logs:
 #   https://docs.djangoproject.com/en/1.11/topics/logging/
-LOGGING = {}
+LOGGING = {
+    "version": 1,
+    "disable_existing_loggers": False,
+    "formatters": {"rq_console": {"format": "%(asctime)s %(message)s", "datefmt": "%H:%M:%S",},},
+    "handlers": {
+        "rq_console": {
+            "level": "DEBUG",
+            "class": "rq.utils.ColorizingStreamHandler",
+            "formatter": "rq_console",
+            "exclude": ["%(asctime)s"],
+        },
+    },
+    "loggers": {"rq.worker": {"handlers": ["rq_console"], "level": "DEBUG"},},
+}
 
 # Setting this to True will permit only authenticated users to access any part of NetBox. By default, anonymous users
 # are permitted to access most data in NetBox (excluding secrets) but not make any changes.

netbox_onboarding/netbox_keeper.py

@@ -25,6 +25,8 @@
 from .constants import NETMIKO_TO_NAPALM_STATIC
 from .exceptions import OnboardException
 
+logger = logging.getLogger("rq.worker")
+
 PLUGIN_SETTINGS = settings.PLUGINS_CONFIG["netbox_onboarding"]
 
 
@@ -149,9 +151,9 @@ def ensure_device_type(
 
         slug = self.netdev_model
         if self.netdev_model and re.search(r"[^a-zA-Z0-9\-_]+", slug):
-            logging.warning("device model is not sluggable: %s", slug)
+            logger.warning("device model is not sluggable: %s", slug)
             self.netdev_model = slug.replace(" ", "-")
-            logging.warning("device model is now: %s", self.netdev_model)
+            logger.warning("device model is now: %s", self.netdev_model)
 
         # Use declared device type or auto-discovered model
         nb_device_type_text = self.netdev_nb_device_type_slug or self.netdev_model
@@ -172,7 +174,7 @@ def ensure_device_type(
 
         except DeviceType.DoesNotExist:
             if create_device_type:
-                logging.info("CREATE: device-type: %s", self.netdev_model)
+                logger.info("CREATE: device-type: %s", self.netdev_model)
                 self.nb_device_type = DeviceType.objects.create(
                     slug=nb_device_type_slug, model=nb_device_type_slug.upper(), manufacturer=self.nb_manufacturer,
                 )
@@ -237,7 +239,7 @@ def ensure_device_platform(self, create_platform_if_missing=PLUGIN_SETTINGS["cre
 
             self.nb_platform = Platform.objects.get(slug=self.netdev_nb_platform_slug)
 
-            logging.info("PLATFORM: found in NetBox %s", self.netdev_nb_platform_slug)
+            logger.info("PLATFORM: found in NetBox %s", self.netdev_nb_platform_slug)
 
         except Platform.DoesNotExist:
             if create_platform_if_missing:
@@ -278,7 +280,7 @@ def ensure_device_instance(self, default_status=PLUGIN_SETTINGS["default_device_
             if self.netdev_mgmt_ip_address:
                 onboarded_device = Device.objects.get(primary_ip4__address__net_host=self.netdev_mgmt_ip_address)
         except Device.DoesNotExist:
-            logging.info(
+            logger.info(
                 "Could not find existing NetBox device for requested primary IP address (%s)",
                 self.netdev_mgmt_ip_address,
             )
@@ -291,7 +293,7 @@ def ensure_device_instance(self, default_status=PLUGIN_SETTINGS["default_device_
         if onboarded_device:
             # Construct lookup arguments if onboarded device already exists in NetBox
 
-            logging.info(
+            logger.info(
                 "Found existing NetBox device (%s) for requested primary IP address (%s)",
                 onboarded_device.name,
                 self.netdev_mgmt_ip_address,
@@ -328,9 +330,9 @@ def ensure_device_instance(self, default_status=PLUGIN_SETTINGS["default_device_
             self.device, created = Device.objects.update_or_create(**lookup_args)
 
             if created:
-                logging.info("CREATED device: %s", self.netdev_hostname)
+                logger.info("CREATED device: %s", self.netdev_hostname)
             else:
-                logging.info("GOT/UPDATED device: %s", self.netdev_hostname)
+                logger.info("GOT/UPDATED device: %s", self.netdev_hostname)
 
         except Device.MultipleObjectsReturned:
             raise OnboardException(
@@ -350,7 +352,7 @@ def ensure_primary_ip(self):
         )
 
         if created or not self.nb_primary_ip in self.nb_mgmt_ifname.ip_addresses.all():
-            logging.info("ASSIGN: IP address %s to %s", self.nb_primary_ip.address, self.nb_mgmt_ifname.name)
+            logger.info("ASSIGN: IP address %s to %s", self.nb_primary_ip.address, self.nb_mgmt_ifname.name)
             self.nb_mgmt_ifname.ip_addresses.add(self.nb_primary_ip)
             self.nb_mgmt_ifname.save()
 

netbox_onboarding/netdev_keeper.py

@@ -33,7 +33,6 @@
 from .exceptions import OnboardException
 
 logger = logging.getLogger("rq.worker")
-logger.setLevel(logging.DEBUG)
 
 PLUGIN_SETTINGS = settings.PLUGINS_CONFIG["netbox_onboarding"]
 
@@ -266,15 +265,26 @@ def get_onboarding_facts(self):
             logger.info("COLLECT: device interface IPs")
             self.ip_ifs = napalm_device.get_interfaces_ip()
 
-            try:
-                module_name = PLUGIN_SETTINGS["onboarding_extensions_map"].get(self.napalm_driver)
-                if module_name:
+            module_name = PLUGIN_SETTINGS["onboarding_extensions_map"].get(self.napalm_driver)
+
+            if module_name:
+                try:
                     module = importlib.import_module(module_name)
                     driver_addon_class = module.OnboardingDriverExtensions(napalm_device=napalm_device)
                     self.onboarding_class = driver_addon_class.onboarding_class
                     self.driver_addon_result = driver_addon_class.ext_result
-            except ImportError as exc:
-                logger.info("No onboarding extension found for driver %s", self.napalm_driver)
+                except ModuleNotFoundError as exc:
+                    raise OnboardException(
+                        reason="fail-general",
+                        message=f"ERROR: ModuleNotFoundError: Onboarding extension for napalm driver {self.napalm_driver} configured but can not be imported per configuration",
+                    )
+                except ImportError as exc:
+                    raise OnboardException(reason="fail-general", message="ERROR: ImportError: %s" % exc.args[0])
+            else:
+                logger.info(
+                    "INFO: No onboarding extension defined for napalm driver %s, using default napalm driver",
+                    self.napalm_driver,
+                )
 
         except ConnectionException as exc:
             raise OnboardException(reason="fail-login", message=exc.args[0])

netbox_onboarding/template_content.py

@@ -25,10 +25,7 @@ def right_page(self):
         """Show table on right side of view."""
         onboarding = OnboardingDevice.objects.filter(device=self.context["object"]).first()
 
-        if not onboarding:
-            return ""
-
-        if not onboarding.enabled:
+        if not onboarding or not onboarding.enabled:
             return ""
 
         status = onboarding.status

netbox_onboarding/views.py

@@ -25,8 +25,7 @@
 from .models import OnboardingTask
 from .tables import OnboardingTaskTable, OnboardingTaskFeedBulkTable
 
-log = logging.getLogger("rq.worker")
-log.setLevel(logging.DEBUG)
+logger = logging.getLogger("rq.worker")
 
 
 if NETBOX_RELEASE_CURRENT < NETBOX_RELEASE_29:

netbox_onboarding/worker.py

@@ -26,7 +26,6 @@
 from .onboard import OnboardingManager
 
 logger = logging.getLogger("rq.worker")
-logger.setLevel(logging.DEBUG)
 
 
 @job("default")
@@ -80,7 +79,7 @@ def onboard_device(task_id, credentials):  # pylint: disable=too-many-statements
         if onboarded_device:
             ot.created_device = onboarded_device
 
-        logger.error("Onboarding Error - OnboardException")
+        logger.error("%s", exc)
         ot.status = OnboardingStatusChoices.STATUS_FAILED
         ot.failed_reason = exc.reason
         ot.message = exc.message