Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[generic_config_updater] Logging #1864

Merged
merged 3 commits into from
Oct 14, 2021
Merged
Show file tree
Hide file tree
Changes from 1 commit
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
27 changes: 21 additions & 6 deletions generic_config_updater/generic_updater.py
Original file line number Diff line number Diff line change
Expand Up @@ -2,7 +2,7 @@
import os
from enum import Enum
from .gu_common import GenericConfigUpdaterError, ConfigWrapper, \
DryRunConfigWrapper, PatchWrapper
DryRunConfigWrapper, PatchWrapper, logger
from .patch_sorter import PatchSorter

CHECKPOINTS_DIR = "/etc/sonic/checkpoints"
Expand Down Expand Up @@ -32,38 +32,57 @@ def __init__(self,
changeapplier=None,
config_wrapper=None,
patch_wrapper=None):
self.LOGTITLE="Patch Applier"
self.config_wrapper = config_wrapper if config_wrapper is not None else ConfigWrapper()
self.patch_wrapper = patch_wrapper if patch_wrapper is not None else PatchWrapper()
self.patchsorter = patchsorter if patchsorter is not None else PatchSorter(self.config_wrapper, self.patch_wrapper)
self.changeapplier = changeapplier if changeapplier is not None else ChangeApplier()

def apply(self, patch):
logger.log_info(self.LOGTITLE, "Patch application starting.")
Copy link
Contributor

@qiluo-msft qiluo-msft Oct 12, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

self.LOGTITLE

You add the same title everywhere. Is it better to define an instance in this class, and init with the title. #Closed

Copy link
Contributor Author

@ghooo ghooo Oct 12, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This way makes it easier to add new log msgs, I don't have to create a new instance of logger for each class.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

nvm, created a logger instance for the PatchApplier class

logger.log_info(self.LOGTITLE, f"Patch: {patch}")

# validate patch is only updating tables with yang models
logger.log_info(self.LOGTITLE, "Validating patch is not making changes to tables without YANG models.")
if not(self.patch_wrapper.validate_config_db_patch_has_yang_models(patch)):
raise ValueError(f"Given patch is not valid because it has changes to tables without YANG models")

# Get old config
logger.log_info(self.LOGTITLE, "Getting current config db.")
old_config = self.config_wrapper.get_config_db_as_json()

# Generate target config
logger.log_info(self.LOGTITLE, "Simulating the target full config after applying the patch.")
target_config = self.patch_wrapper.simulate_patch(patch, old_config)

# Validate target config
logger.log_info(self.LOGTITLE, "Validating target config according to YANG models.")
if not(self.config_wrapper.validate_config_db_config(target_config)):
raise ValueError(f"Given patch is not valid because it will result in an invalid config")

# Generate list of changes to apply
logger.log_info(self.LOGTITLE, "Sorting patch updates.")
changes = self.patchsorter.sort(patch)
changes_len = len(changes)
logger.log_info(self.LOGTITLE,
f"The patch was sorted into {changes_len} " \
f"change{'s' if changes_len != 1 else ''}{':' if changes_len > 0 else '.'}")
for change in changes:
logger.log_info(self.LOGTITLE, f" * {change}")

# Apply changes in order
logger.log_info(self.LOGTITLE, "Applying changes in order.")
for change in changes:
self.changeapplier.apply(change)

# Validate config updated successfully
logger.log_info(self.LOGTITLE, "Verifying patch updates are reflected on ConfigDB.")
new_config = self.config_wrapper.get_config_db_as_json()
if not(self.patch_wrapper.verify_same_json(target_config, new_config)):
raise GenericConfigUpdaterError(f"After applying patch to config, there are still some parts not updated")

logger.log_info(self.LOGTITLE, "Patch application completed.")

class ConfigReplacer:
def __init__(self, patch_applier=None, config_wrapper=None, patch_wrapper=None):
self.patch_applier = patch_applier if patch_applier is not None else PatchApplier()
Expand Down Expand Up @@ -293,11 +312,7 @@ def create_config_rollbacker(self, verbose, dry_run=False):
return config_rollbacker

def init_verbose_logging(self, verbose):
# TODO: implement verbose logging
# Usually logs have levels such as: error, warning, info, debug.
# By default all log levels should show up to the user, except debug.
# By allowing verbose logging, debug msgs will also be shown to the user.
pass
logger.init_verbose_logging(verbose)

def get_config_wrapper(self, dry_run):
if dry_run:
Expand Down
43 changes: 43 additions & 0 deletions generic_config_updater/gu_common.py
Original file line number Diff line number Diff line change
Expand Up @@ -2,13 +2,15 @@
import jsonpatch
from jsonpointer import JsonPointer
import sonic_yang
import syslog
import subprocess
import yang as ly
import copy
import re
from enum import Enum

YANG_DIR = "/usr/local/yang-models"
SYSLOG_IDENTIFIER = "GenericConfigUpdater"
Copy link
Contributor

@qiluo-msft qiluo-msft Oct 12, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

GenericConfigUpdater

Is this ident too long? The default will be process name such as config, is it good enough since you have add title to diffentiate. #Closed

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Here is how it look like:

Oct 11 18:15:50.604939 vlab-01 INFO GenericConfigUpdater: Patch Applier: Getting current config db.
Oct 11 18:15:51.494117 vlab-01 INFO GenericConfigUpdater: Patch Applier: Simulating the target full config after applying the patch.
Oct 11 18:15:51.502449 vlab-01 INFO GenericConfigUpdater: Patch Applier: Validating target config according to YANG models.

I think it is OK, this way I can grep all syslogs associated with GenericConfigUpdater i.e. cat /var/log/syslog | grep GenericConfigUpdater

I think we will add more logs to other parts such config replace, rollback checkpoint and the applier.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Also I don't think we should use config since this library might be used with REST APIs like was requested in some of the earlier meetings with SONiC Community


class GenericConfigUpdaterError(Exception):
pass
Expand Down Expand Up @@ -691,3 +693,44 @@ def _get_model(self, model, name):
return submodel

return None

class GenericUpdaterLogger:
Copy link
Contributor

@qiluo-msft qiluo-msft Oct 12, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

GenericUpdaterLogger

This class seems have general value, like https://github.com/Azure/sonic-buildimage/blob/master/src/sonic-py-common/sonic_py_common/logger.py.

Is it better to enhance existing Logger class? If something is impossible, we can inherit the class. #Closed

Copy link
Contributor Author

@ghooo ghooo Oct 13, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

used sonic-py-common logger

"""
Logs are printed to console and added to syslog.
Console settings: log levels [error, warning, info] always printed, [debug] only printed if verbose logging
Syslog settings: log all levels [error, warning, info, debug]
"""
def init_verbose_logging(self, verbose):
Copy link
Contributor

@qiluo-msft qiluo-msft Oct 12, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

init_verbose_logging

Better use __init__() #Closed

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

if I use __init__ it means when creating the logger I initialize verbose, but this is not the case as we modify verbosity later.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

used loggingSettings instead and the logger is created from loggingSettings.getlogger

# Usually logs have levels such as: error, warning, info, debug.
# By default all log levels should show up to the user, except debug.
# By allowing verbose logging, debug msgs will also be shown to the user.
self.enable_verbose_logging = verbose

def log_error(self, title, msg):
self.log(title, msg, syslog.LOG_ERR)

def log_warning(self, title, msg):
self.log(title, msg, syslog.LOG_WARNING)

def log_info(self, title, msg):
self.log(title, msg, syslog.LOG_INFO)

def log_debug(self, title, msg):
self.log(title, msg, syslog.LOG_DEBUG)

def log(self, title, msg, logLevel):
combined_msg = f"{title}: {msg}"
self._log_to_console(combined_msg, logLevel)
self._log_to_syslog(combined_msg, logLevel)

def _log_to_console(self, msg, logLevel):
# Always log [warning, error, info] i.e. not debug, but if verbose logging print debug as well
if logLevel < syslog.LOG_DEBUG or self.enable_verbose_logging:
print(msg)
Copy link
Contributor

@qiluo-msft qiluo-msft Oct 12, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

print

It is an error, should we print to stderr? How about warning? #Closed

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

used common logger logic


def _log_to_syslog(self, msg, logLevel):
syslog.openlog(SYSLOG_IDENTIFIER)
syslog.syslog(logLevel, msg)
syslog.closelog()

logger = GenericUpdaterLogger()
Copy link
Contributor

@qiluo-msft qiluo-msft Oct 12, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

logger

If global object is used by multiple places, and init verbose multiple time, user will be confused about the interference #Closed

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The idea is to have a single global logger in gu_common for which verbosity can be modified.

Another idea is to create an init_env(...) method in gu_common and this function takes care of creating the logger.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

global loggingSettings and then each logger instance is created per class, there is no global logger

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

init_env(...) will solve the user confusing issue I mentioned.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@qiluo-msft I have used loggingSettings instead, there the verbose flag can change, but then once a logger is created its verbosity can not change. Do you think this is confusing?