From 2874352c7658c4277bb67fe093c3c7d458abfe1f Mon Sep 17 00:00:00 2001 From: Phillip Simonds Date: Wed, 16 Sep 2020 15:42:44 -0700 Subject: [PATCH 1/4] Improve Logging for netdev_keeper.py --- netbox_onboarding/netdev_keeper.py | 27 +++++++++++++++------------ 1 file changed, 15 insertions(+), 12 deletions(-) diff --git a/netbox_onboarding/netdev_keeper.py b/netbox_onboarding/netdev_keeper.py index cf4657c..e2ff08b 100644 --- a/netbox_onboarding/netdev_keeper.py +++ b/netbox_onboarding/netdev_keeper.py @@ -32,6 +32,9 @@ from .constants import NETMIKO_TO_NAPALM_STATIC from .exceptions import OnboardException +logger = logging.getLogger("rq.worker") +logger.setLevel(logging.DEBUG) + PLUGIN_SETTINGS = settings.PLUGINS_CONFIG["netbox_onboarding"] @@ -144,7 +147,7 @@ def check_reachability(self): OnboardException('fail-connect'): When device unreachable """ - logging.info("CHECK: IP %s:%s", self.hostname, self.port) + logger.info("CHECK: IP %s:%s", self.hostname, self.port) try: sock = socket.socket(socket.AF_INET, socket.SOCK_STREAM) @@ -169,24 +172,24 @@ def guess_netmiko_device_type(self): } try: - logging.info("INFO guessing device type: %s", self.hostname) + logger.info("INFO guessing device type: %s", self.hostname) guesser = SSHDetect(**remote_device) guessed_device_type = guesser.autodetect() - logging.info("INFO guessed device type: %s", guessed_device_type) + logger.info("INFO guessed device type: %s", guessed_device_type) except NetMikoAuthenticationException as err: - logging.error("ERROR %s", err) + logger.error("ERROR %s", err) raise OnboardException(reason="fail-login", message=f"ERROR: {str(err)}") except (NetMikoTimeoutException, SSHException) as err: - logging.error("ERROR: %s", str(err)) + logger.error("ERROR: %s", str(err)) raise OnboardException(reason="fail-connect", message=f"ERROR: {str(err)}") except Exception as err: - logging.error("ERROR: %s", str(err)) + logger.error("ERROR: %s", str(err)) raise OnboardException(reason="fail-general", message=f"ERROR: {str(err)}") - logging.info("INFO device type is: %s", guessed_device_type) + logger.info("INFO device type is: %s", guessed_device_type) return guessed_device_type @@ -194,7 +197,7 @@ def set_napalm_driver_name(self): """Sets napalm driver name.""" if not self.napalm_driver: netmiko_device_type = self.guess_netmiko_device_type() - logging.info("Guessed Netmiko Device Type: %s", netmiko_device_type) + logger.info("Guessed Netmiko Device Type: %s", netmiko_device_type) self.netmiko_device_type = netmiko_device_type @@ -234,7 +237,7 @@ def get_onboarding_facts(self): self.check_reachability() - logging.info("COLLECT: device information %s", self.hostname) + logger.info("COLLECT: device information %s", self.hostname) try: # Get Napalm Driver with Netmiko if needed @@ -257,10 +260,10 @@ def get_onboarding_facts(self): napalm_device.open() - logging.info("COLLECT: device facts") + logger.info("COLLECT: device facts") self.facts = napalm_device.get_facts() - logging.info("COLLECT: device interface IPs") + logger.info("COLLECT: device interface IPs") self.ip_ifs = napalm_device.get_interfaces_ip() try: @@ -270,7 +273,7 @@ def get_onboarding_facts(self): self.onboarding_class = driver_addon_class.onboarding_class self.driver_addon_result = driver_addon_class.ext_result except ImportError as exc: - logging.info("No onboarding extension found for driver %s", self.napalm_driver) + logger.info("No onboarding extension found for driver %s", self.napalm_driver) except ConnectionException as exc: raise OnboardException(reason="fail-login", message=exc.args[0]) From 58657345d321bfbaf8b8ca9480cd83b39bd7ddcd Mon Sep 17 00:00:00 2001 From: Phillip Simonds Date: Wed, 16 Sep 2020 15:43:23 -0700 Subject: [PATCH 2/4] Fixes onboarding_extensions_map issue The onboarding_extensions_map setting (specified in netbox_onboarding/__init__.py or overridden in configuration.py) is used to map napalm driver names to a custom class which extends the driver, allowing extensibility. Currently, when a mapping doesn't exist for a napalm driver, the NetdevKeepr class's get_onboarding_facts() method fails. This causes the rq-worker to be unable to run the onbaord_device() function to onboard a device. The changes in this commit fix the issue. --- netbox_onboarding/netdev_keeper.py | 9 +++++---- 1 file changed, 5 insertions(+), 4 deletions(-) diff --git a/netbox_onboarding/netdev_keeper.py b/netbox_onboarding/netdev_keeper.py index e2ff08b..0d7e312 100644 --- a/netbox_onboarding/netdev_keeper.py +++ b/netbox_onboarding/netdev_keeper.py @@ -268,10 +268,11 @@ def get_onboarding_facts(self): try: module_name = PLUGIN_SETTINGS["onboarding_extensions_map"].get(self.napalm_driver) - 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 + if module_name: + 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) From 34d37db1f5e39d6ec6d581b237feb97dc477803a Mon Sep 17 00:00:00 2001 From: Phillip Simonds Date: Thu, 17 Sep 2020 11:33:34 -0700 Subject: [PATCH 3/4] Render right_page onboarding template correctly Currently, the template_content.py DeviceContent class returns `None` if onboarding is not enabled for an OnboardingDevice object. Likewise, if no OnboardingDevice object exists, the template continues trying to access attributes for an OnboardingDevice object. In the first case, template rendering will fail as an empty string is needed in order to insert nothing into the rendered HTML template presented to the user. In the second case, an AttributeError is raised as you can not access attributes of a NoneType object. --- netbox_onboarding/template_content.py | 5 ++++- 1 file changed, 4 insertions(+), 1 deletion(-) diff --git a/netbox_onboarding/template_content.py b/netbox_onboarding/template_content.py index b9aa7b9..38ee645 100644 --- a/netbox_onboarding/template_content.py +++ b/netbox_onboarding/template_content.py @@ -25,8 +25,11 @@ 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: - return None + return "" status = onboarding.status last_check_attempt_date = onboarding.last_check_attempt_date From e9921863ecf269f9344eb94e75a9930d5c43992a Mon Sep 17 00:00:00 2001 From: Phillip Simonds Date: Thu, 17 Sep 2020 11:47:04 -0700 Subject: [PATCH 4/4] Enhance logging and error handling --- development/base_configuration.py | 15 ++++++++++++++- netbox_onboarding/netbox_keeper.py | 20 +++++++++++--------- netbox_onboarding/netdev_keeper.py | 22 ++++++++++++++++------ netbox_onboarding/template_content.py | 5 +---- netbox_onboarding/views.py | 3 +-- netbox_onboarding/worker.py | 3 +-- 6 files changed, 44 insertions(+), 24 deletions(-) diff --git a/development/base_configuration.py b/development/base_configuration.py index 5bbe5a6..12aa5a1 100644 --- a/development/base_configuration.py +++ b/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. diff --git a/netbox_onboarding/netbox_keeper.py b/netbox_onboarding/netbox_keeper.py index fe36d95..dab6945 100644 --- a/netbox_onboarding/netbox_keeper.py +++ b/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() diff --git a/netbox_onboarding/netdev_keeper.py b/netbox_onboarding/netdev_keeper.py index 0d7e312..07fb1b8 100644 --- a/netbox_onboarding/netdev_keeper.py +++ b/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]) diff --git a/netbox_onboarding/template_content.py b/netbox_onboarding/template_content.py index 38ee645..4b3189a 100644 --- a/netbox_onboarding/template_content.py +++ b/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 diff --git a/netbox_onboarding/views.py b/netbox_onboarding/views.py index 7367be7..79ab623 100644 --- a/netbox_onboarding/views.py +++ b/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: diff --git a/netbox_onboarding/worker.py b/netbox_onboarding/worker.py index 494d73d..e44e422 100644 --- a/netbox_onboarding/worker.py +++ b/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