diff --git a/stateengine/StateEngineAction.py b/stateengine/StateEngineAction.py index 8037b1c24..958b6905e 100755 --- a/stateengine/StateEngineAction.py +++ b/stateengine/StateEngineAction.py @@ -145,25 +145,22 @@ def update_webif_actionstatus(self, state, name, success, issue=None): pass # Write action to logger - def write_to_logger(self, log_level=StateEngineDefaults.log_level): - if log_level == -1: - self._log_info("name: {}", self._name) - else: - self._log_debug("name: {}", self._name) - self.__delay.write_to_logger(log_level) + def write_to_logger(self): + self._log_debug("name: {}", self._name) + self.__delay.write_to_logger() if self.__repeat is not None: - self.__repeat.write_to_logger(log_level) + self.__repeat.write_to_logger() if self.__instanteval is not None: - self.__instanteval.write_to_logger(log_level) + self.__instanteval.write_to_logger() if self.conditionset is not None: - self.conditionset.write_to_logger(log_level) + self.conditionset.write_to_logger() if self.previousconditionset is not None: - self.previousconditionset.write_to_logger(log_level) + self.previousconditionset.write_to_logger() if self.previousstate_conditionset is not None: - self.previousstate_conditionset.write_to_logger(log_level) + self.previousstate_conditionset.write_to_logger() if self.__mode is not None: - self.__mode.write_to_logger(log_level) - self.__order.write_to_logger(log_level) + self.__mode.write_to_logger() + self.__order.write_to_logger() def set_source(self, current_condition, previous_condition, previousstate_condition): source = [] @@ -485,25 +482,16 @@ def complete(self, item_state, evals_items=None): self._caller += '_self' # Write action to logger - def write_to_logger(self, log_level=StateEngineDefaults.log_level): - SeActionBase.write_to_logger(self, log_level) + def write_to_logger(self): + SeActionBase.write_to_logger(self) if isinstance(self.__item, str): - if log_level == -1: - self._log_info("item from eval: {0}", self.__item) - else: - self._log_debug("item from eval: {0}", self.__item) + self._log_debug("item from eval: {0}", self.__item) elif self.__item is not None: - if log_level == -1: - self._log_info("item: {0}", self.__item.property.path) - else: - self._log_debug("item: {0}", self.__item.property.path) + self._log_debug("item: {0}", self.__item.property.path) if self.__status is not None: - if log_level == -1: - self._log_info("status: {0}", self.__status.property.path) - else: - self._log_debug("status: {0}", self.__status.property.path) - self.__mindelta.write_to_logger(log_level) - self.__value.write_to_logger(log_level) + self._log_debug("status: {0}", self.__status.property.path) + self.__mindelta.write_to_logger() + self.__value.write_to_logger() # Check if execution is possible def _can_execute(self, state): @@ -612,17 +600,11 @@ def complete(self, item_state, evals_items=None): self._scheduler_name = "{}-SeByAttrDelayTimer".format(self.__byattr) # Write action to logger - def write_to_logger(self, log_level=StateEngineDefaults.log_level): - if log_level == -1: - self._log_info("function: {}", self.__function) - else: - self._log_debug("function: {}", self.__function) - SeActionBase.write_to_logger(self, log_level) + def write_to_logger(self): + self._log_debug("function: {}", self.__function) + SeActionBase.write_to_logger(self) if self.__byattr is not None: - if log_level == -1: - self._log_info("set by attribute: {0}", self.__byattr) - else: - self._log_debug("set by attribute: {0}", self.__byattr) + self._log_debug("set by attribute: {0}", self.__byattr) # Really execute the action def real_execute(self, state, actionname: str, namevar: str = "", repeat_text: str = "", value=None, returnvalue=False, current_condition=None, previous_condition=None, previousstate_condition=None): @@ -670,22 +652,13 @@ def complete(self, item_state, evals_items=None): self._scheduler_name = "{}-SeLogicDelayTimer".format(self.__logic) # Write action to logger - def write_to_logger(self, log_level=StateEngineDefaults.log_level): - if log_level == -1: - self._log_info("function: {}", self.__function) - else: - self._log_debug("function: {}", self.__function) - SeActionBase.write_to_logger(self, log_level) + def write_to_logger(self): + self._log_debug("function: {}", self.__function) + SeActionBase.write_to_logger(self) if self.__logic is not None: - if log_level == -1: - self._log_info("trigger logic: {0}", self.__logic) - else: - self._log_debug("trigger logic: {0}", self.__logic) + self._log_debug("trigger logic: {0}", self.__logic) if self.__value is not None: - if log_level == -1: - self._log_info("value: {0}", self.__value) - else: - self._log_debug("value: {0}", self.__value) + self._log_debug("value: {0}", self.__value) # Really execute the action def real_execute(self, state, actionname: str, namevar: str = "", repeat_text: str = "", value=None, returnvalue=False, current_condition=None, previous_condition=None, previousstate_condition=None): @@ -739,17 +712,11 @@ def complete(self, item_state, evals_items=None): self._scheduler_name = "{}-SeRunDelayTimer".format(StateEngineTools.get_eval_name(self.__eval)) # Write action to logger - def write_to_logger(self, log_level=StateEngineDefaults.log_level): - if log_level == -1: - self._log_info("function: {}", self.__function) - else: - self._log_debug("function: {}", self.__function) - SeActionBase.write_to_logger(self, log_level) + def write_to_logger(self): + self._log_debug("function: {}", self.__function) + SeActionBase.write_to_logger(self) if self.__eval is not None: - if log_level == -1: - self._log_info("eval: {0}", StateEngineTools.get_eval_name(self.__eval)) - else: - self._log_debug("eval: {0}", StateEngineTools.get_eval_name(self.__eval)) + self._log_debug("eval: {0}", StateEngineTools.get_eval_name(self.__eval)) # Really execute the action def real_execute(self, state, actionname: str, namevar: str = "", repeat_text: str = "", value=None, returnvalue=False, current_condition=None, previous_condition=None, previousstate_condition=None): @@ -848,35 +815,19 @@ def complete(self, item_state, evals_items=None): self._scheduler_name = "{}-SeItemDelayTimer".format(self.__item.property.path) # Write action to logger - def write_to_logger(self, log_level=StateEngineDefaults.log_level): - if log_level == -1: - self._log_info("function: {}", self.__function) - self._log_info("value: {}", self.__value) - else: - self._log_debug("function: {}", self.__function) - self._log_debug("value: {}", self.__value) - SeActionBase.write_to_logger(self, log_level) + def write_to_logger(self): + self._log_debug("function: {}", self.__function) + self._log_debug("value: {}", self.__value) + SeActionBase.write_to_logger(self) if isinstance(self.__item, str): - if log_level == -1: - self._log_info("item from eval: {0}", self.__item) - else: - self._log_debug("item from eval: {0}", self.__item) + self._log_debug("item from eval: {0}", self.__item) elif self.__item is not None: - if log_level == -1: - self._log_info("item: {0}", self.__item.property.path) - else: - self._log_debug("item: {0}", self.__item.property.path) + self._log_debug("item: {0}", self.__item.property.path) if self.__status is not None: - if log_level == -1: - self._log_info("status: {0}", self.__status.property.path) - else: - self._log_debug("status: {0}", self.__status.property.path) - self.__mindelta.write_to_logger(log_level) - self.__value.write_to_logger(log_level) - if log_level == -1: - self._log_info("force update: yes") - else: - self._log_debug("force update: yes") + self._log_debug("status: {0}", self.__status.property.path) + self.__mindelta.write_to_logger() + self.__value.write_to_logger() + self._log_debug("force update: yes") # Check if execution is possible def _can_execute(self, state): @@ -1019,26 +970,14 @@ def complete(self, item_state, evals_items=None): self._scheduler_name = "{}_{}-SeSpecialDelayTimer".format(self.__special, item) # Write action to logger - def write_to_logger(self, log_level=StateEngineDefaults.log_level): - if log_level == -1: - self._log_info("function: {}", self.__function) - else: - self._log_debug("function: {}", self.__function) - SeActionBase.write_to_logger(self, log_level) - if log_level == -1: - self._log_info("Special Action: {0}", self.__special) - else: - self._log_debug("Special Action: {0}", self.__special) + def write_to_logger(self): + self._log_debug("function: {}", self.__function) + SeActionBase.write_to_logger(self) + self._log_debug("Special Action: {0}", self.__special) if isinstance(self.__value, list): - if log_level == -1: - self._log_info("value: {0}", self.__value) - else: - self._log_debug("value: {0}", self.__value) + self._log_debug("value: {0}", self.__value) else: - if log_level == -1: - self._log_info("Retrigger item: {0}", self.__value.property.path) - else: - self._log_debug("Retrigger item: {0}", self.__value.property.path) + self._log_debug("Retrigger item: {0}", self.__value.property.path) # Really execute the action def real_execute(self, state, actionname: str, namevar: str = "", repeat_text: str = "", value=None, returnvalue=False, current_condition=None, previous_condition=None, previousstate_condition=None): @@ -1144,13 +1083,10 @@ def __init__(self, abitem, name: str): def __repr__(self): return "SeAction Add {}".format(self._name) - def write_to_logger(self, log_level=StateEngineDefaults.log_level): - if log_level == 1: - self._log_info("function: {}", self.__function) - else: - self._log_debug("function: {}", self.__function) - SeActionSetItem.write_to_logger(self, log_level) - SeActionBase.write_to_logger(self, log_level) + def write_to_logger(self): + self._log_debug("function: {}", self.__function) + SeActionSetItem.write_to_logger(self) + SeActionBase.write_to_logger(self) def _execute_set_add_remove(self, state, actionname, namevar, repeat_text, item, value, current_condition=None, previous_condition=None, previousstate_condition=None): value = value if isinstance(value, list) else [value] @@ -1185,13 +1121,10 @@ def __init__(self, abitem, name: str): def __repr__(self): return "SeAction RemoveFirst {}".format(self._name) - def write_to_logger(self, log_level=StateEngineDefaults.log_level): - if log_level == -1: - self._log_info("function: {}", self.__function) - else: - self._log_debug("function: {}", self.__function) - SeActionSetItem.write_to_logger(self, log_level) - SeActionBase.write_to_logger(self, log_level) + def write_to_logger(self): + self._log_debug("function: {}", self.__function) + SeActionSetItem.write_to_logger(self) + SeActionBase.write_to_logger(self) def _execute_set_add_remove(self, state, actionname, namevar, repeat_text, item, value, current_condition=None, previous_condition=None, previousstate_condition=None): currentvalue = item.property.value @@ -1232,13 +1165,10 @@ def __init__(self, abitem, name: str): def __repr__(self): return "SeAction RemoveLast {}".format(self._name) - def write_to_logger(self, log_level=StateEngineDefaults.log_level): - if log_level == -1: - self._log_info("function: {}", self.__function) - else: - self._log_debug("function: {}", self.__function) - SeActionSetItem.write_to_logger(self, log_level) - SeActionBase.write_to_logger(self, log_level) + def write_to_logger(self): + self._log_debug("function: {}", self.__function) + SeActionSetItem.write_to_logger(self) + SeActionBase.write_to_logger(self) def _execute_set_add_remove(self, state, actionname, namevar, repeat_text, item, value, current_condition=None, previous_condition=None, previousstate_condition=None): currentvalue = item.property.value @@ -1281,13 +1211,10 @@ def __init__(self, abitem, name: str): def __repr__(self): return "SeAction RemoveAll {}".format(self._name) - def write_to_logger(self, log_level=StateEngineDefaults.log_level): - if log_level == -1: - self._log_info("function: {}", self.__function) - else: - self._log_debug("function: {}", self.__function) - SeActionSetItem.write_to_logger(self, log_level) - SeActionBase.write_to_logger(self, log_level) + def write_to_logger(self): + self._log_debug("function: {}", self.__function) + SeActionSetItem.write_to_logger(self) + SeActionBase.write_to_logger(self) def _execute_set_add_remove(self, state, actionname, namevar, repeat_text, item, value, current_condition=None, previous_condition=None, previousstate_condition=None): currentvalue = item.property.value diff --git a/stateengine/StateEngineActions.py b/stateengine/StateEngineActions.py index 32adb5754..db6f261af 100755 --- a/stateengine/StateEngineActions.py +++ b/stateengine/StateEngineActions.py @@ -432,7 +432,7 @@ def get(self): return finalactions # log all actions - def write_to_logger(self, log_level=StateEngineDefaults.log_level): + def write_to_logger(self): actions = [] for name in self.__actions: actions.append((self.__actions[name].get_order(), self.__actions[name])) @@ -441,6 +441,6 @@ def write_to_logger(self, log_level=StateEngineDefaults.log_level): self._log_info("Action '{0}':", action.name) self._log_increase_indent() self._abitem._initactionname = action.name - action.write_to_logger(log_level) + action.write_to_logger() self._abitem._initactionname = None self._log_decrease_indent() diff --git a/stateengine/StateEngineCondition.py b/stateengine/StateEngineCondition.py index 87bb13abb..637ab2c88 100755 --- a/stateengine/StateEngineCondition.py +++ b/stateengine/StateEngineCondition.py @@ -299,7 +299,7 @@ def check(self, state): return True # Write condition to logger - def write_to_logger(self, log_level=StateEngineDefaults.log_level): + def write_to_logger(self): if self.__error is not None: self._log_warning("error: {0}", self.__error) if self.__item is not None: @@ -320,22 +320,22 @@ def write_to_logger(self, log_level=StateEngineDefaults.log_level): self._log_info("eval: {0}", StateEngineTools.get_eval_name(e)) else: self._log_info("eval: {0}", StateEngineTools.get_eval_name(self.__eval)) - self.__value.write_to_logger(log_level) - self.__min.write_to_logger(log_level) - self.__max.write_to_logger(log_level) + self.__value.write_to_logger() + self.__min.write_to_logger() + self.__max.write_to_logger() if self.__negate is not None: self._log_info("negate: {0}", self.__negate) - self.__agemin.write_to_logger(log_level) - self.__agemax.write_to_logger(log_level) + self.__agemin.write_to_logger() + self.__agemax.write_to_logger() if self.__agenegate is not None: self._log_info("age negate: {0}", self.__agenegate) - self.__changedby.write_to_logger(log_level) + self.__changedby.write_to_logger() if self.__changedbynegate is not None and not self.__changedby.is_empty(): self._log_info("changedby negate: {0}", self.__changedbynegate) - self.__updatedby.write_to_logger(log_level) + self.__updatedby.write_to_logger() if self.__updatedbynegate is not None and not self.__updatedby.is_empty(): self._log_info("updatedby negate: {0}", self.__updatedbynegate) - self.__triggeredby.write_to_logger(log_level) + self.__triggeredby.write_to_logger() if self.__updatedbynegate is not None and not self.__triggeredby.is_empty(): self._log_info("triggeredby negate: {0}", self.__triggeredbynegate) diff --git a/stateengine/StateEngineConditionSet.py b/stateengine/StateEngineConditionSet.py index e12f80ca9..881f815e3 100755 --- a/stateengine/StateEngineConditionSet.py +++ b/stateengine/StateEngineConditionSet.py @@ -127,11 +127,11 @@ def complete(self, item_state): del self.conditions[name] # Write the whole condition set to the logger - def write_to_logger(self, log_level=StateEngineDefaults.log_level): + def write_to_logger(self): for name in self.__conditions: self._log_info("Condition '{0}':", name) self._log_increase_indent() - self.__conditions[name].write_to_logger(log_level) + self.__conditions[name].write_to_logger() self._log_decrease_indent() def __currentconditionset_set(self, conditionsetid, name): diff --git a/stateengine/StateEngineConditionSets.py b/stateengine/StateEngineConditionSets.py index d4065e072..ff87f582a 100755 --- a/stateengine/StateEngineConditionSets.py +++ b/stateengine/StateEngineConditionSets.py @@ -74,11 +74,11 @@ def complete(self, item_state): self.__condition_sets[name].complete(item_state) # Write all condition sets to logger - def write_to_logger(self, log_level=StateEngineDefaults.log_level): + def write_to_logger(self): for name in self.__condition_sets: self._log_info("Condition Set '{0}':", name) self._log_increase_indent() - self.__condition_sets[name].write_to_logger(log_level) + self.__condition_sets[name].write_to_logger() self._log_decrease_indent() # check if one of the conditions sets in the list is matching. diff --git a/stateengine/StateEngineDefaults.py b/stateengine/StateEngineDefaults.py index 5dc52c8f0..59fa53efb 100755 --- a/stateengine/StateEngineDefaults.py +++ b/stateengine/StateEngineDefaults.py @@ -26,8 +26,6 @@ suspend_time = 3600 -log_level = 0 - suntracking_offset = 0 lamella_open_value = 0 @@ -40,8 +38,6 @@ logger = None -se_logger = logging.getLogger('stateengine') - log_maxage = 0 diff --git a/stateengine/StateEngineFunctions.py b/stateengine/StateEngineFunctions.py index 8d015288c..6b90c0822 100755 --- a/stateengine/StateEngineFunctions.py +++ b/stateengine/StateEngineFunctions.py @@ -37,7 +37,7 @@ def ab_alive(self): def ab_alive(self, value): self.__ab_alive = value - def __init__(self, smarthome, logger): + def __init__(self, smarthome=None, logger=None): self.logger = logger self.__sh = smarthome self.__locks = {} @@ -66,7 +66,7 @@ def __get_lock(self, lock_id): def manual_item_update_eval(self, item_id, caller=None, source=None): item = self.itemsApi.return_item(item_id) if item is None: - self.logger.error("manual_item_update_eval: item {0} not found!", item_id) + self.logger.error("manual_item_update_eval: item {0} not found!".format(item_id)) # Leave immediately in case StateEngine Plugin is not yet fully running if not self.__ab_alive: @@ -80,7 +80,7 @@ def manual_item_update_eval(self, item_id, caller=None, source=None): elog_item_id = item.conf["se_manual_logitem"] elog_item = self.itemsApi.return_item(elog_item_id) if elog_item is None: - self.logger.error("manual_item_update_item: se_manual_logitem {0} not found!", elog_item_id) + self.logger.error("manual_item_update_item: se_manual_logitem {0} not found!".format(elog_item_id)) elog = StateEngineLogger.SeLoggerDummy() else: elog = StateEngineLogger.SeLogger.create(elog_item) diff --git a/stateengine/StateEngineItem.py b/stateengine/StateEngineItem.py index 196e1f088..080983f0d 100755 --- a/stateengine/StateEngineItem.py +++ b/stateengine/StateEngineItem.py @@ -44,10 +44,6 @@ class SeItem: def id(self): return self.__id - @property - def log_level(self): - return self.__log_level - @property def variables(self): return self.__variables @@ -176,13 +172,37 @@ def __init__(self, smarthome, item, se_plugin): self.__name = str(self.__item) self.__itemClass = Item # initialize logging - - self.__log_level = StateEngineValue.SeValue(self, "Log Level", False, "num") - self.__log_level.set_from_attr(self.__item, "se_log_level", StateEngineDefaults.log_level) self.__logger.header("") - self.__logger.header("Initialize Item {0} (Log Level set" - " to {1})".format(self.id, self.__log_level)) - self.__logger.override_loglevel(self.__log_level, self.__item) + _log_level = StateEngineValue.SeValue(self, "Log Level", False, "num") + _default_log_level = SeLogger.default_log_level.get() + _returnvalue, _returntype, _using_default = _log_level.set_from_attr(self.__item, "se_log_level", + _default_log_level) + + if len(_returnvalue) > 1: + self.__logger.warning("se_log_level for item {} can not be defined as a list" + " ({}). Using default value {}.", self.id, _returnvalue, _default_log_level) + _log_level.set(_default_log_level) + elif len(_returnvalue) == 1 and _returnvalue[0] is None: + _log_level.set(_default_log_level) + self.__logger.header("Initialize Item {0} (Log {1}, Level set" + " to {2} based on default log level {3}" + " because se_log_level has issues)".format(self.id, self.__logger.name, _log_level, + _default_log_level)) + elif _using_default: + self.__logger.header("Initialize Item {0} (Log {1}, Level set" + " to {2} based on default log level {3})".format(self.id, self.__logger.name, + _log_level, + _default_log_level)) + else: + self.__logger.header("Initialize Item {0} (Log {1}, Level set" + " to {2}, default log level is {3})".format(self.id, self.__logger.name, _log_level, + _default_log_level)) + _startup_log_level = SeLogger.startup_log_level.get() + self.__logger.log_level.set(_startup_log_level) + self.__logger.info("Set log level to startup log level {}", _startup_log_level) + if _startup_log_level > 0: + base = self.__sh.get_basedir() + SeLogger.manage_logdirectory(base, SeLogger.log_directory, True) # get startup delay self.__startup_delay = StateEngineValue.SeValue(self, "Startup Delay", False, "num") self.__startup_delay.set_from_attr(self.__item, "se_startup_delay", StateEngineDefaults.startup_delay) @@ -309,6 +329,8 @@ def __init__(self, smarthome, item, se_plugin): self.__add_triggers() else: self.__startup_delay_callback(self.__item, "Init", None, None) + self.__logger.info("Reset log level to {}", _log_level) + self.__logger.log_level = _log_level def __repr__(self): return self.__id @@ -334,8 +356,16 @@ def remove_all_schedulers(self): # run queue def run_queue(self): if not self.__ab_alive: - self.__logger.debug("{} not running (anymore). Queue not activated.", StateEngineDefaults.plugin_identification) + self.__logger.debug("{} not running (anymore). Queue not activated.", + StateEngineDefaults.plugin_identification) return + _current_log_level = self.__logger.get_loglevel() + _default_log_level = SeLogger.default_log_level.get() + if _current_log_level > 0: + base = self.__sh.get_basedir() + SeLogger.manage_logdirectory(base, SeLogger.log_directory, True) + self.__logger.debug("Current log level {}, default {}, currently using default {}", + self.__logger.log_level, _default_log_level, self.__logger.using_default) self.update_lock.acquire(True, 10) while not self.__queue.empty() and self.__ab_alive: job = self.__queue.get() @@ -712,7 +742,7 @@ def __check_releasedby(self, state, _checked_states, _releasedby, _wouldenter, _ elif result is False: self.__logger.develop("State {} FALSE, has_released {}, _releasedby list {}, _wouldenter {}", - state.id, self.__has_released, _releasedby, _wouldenter) + state.id, self.__has_released, _releasedby, _wouldenter) if _wouldenter is None: for entry in self.__has_released.keys(): if state.id in self.__has_released.get(entry): @@ -1095,7 +1125,7 @@ def __write_to_log(self): for state in self.__states: # Update Releasedby Dict self.update_releasedby(state) - state.write_to_log(log_level=-1) + state.write_to_log() self._initstate = None # endregion diff --git a/stateengine/StateEngineLogger.py b/stateengine/StateEngineLogger.py index 8ce03712d..61e6e8bbe 100755 --- a/stateengine/StateEngineLogger.py +++ b/stateengine/StateEngineLogger.py @@ -27,32 +27,70 @@ class SeLogger: + @property + def default_log_level(self): + return SeLogger.__default_log_level.get() + + @default_log_level.setter + def default_log_level(self, value): + SeLogger.__default_log_level = value + + @property + def startup_log_level(self): + return SeLogger.__startup_log_level.get() + + @startup_log_level.setter + def default_log_level(self, value): + SeLogger.__startup_log_level = value + + @property + def using_default(self): + return self.__using_default + + @using_default.setter + def using_default(self, value): + self.__using_default = value + + @property + def name(self): + return self.__name + # Set global log level # loglevel: current loglevel - @staticmethod - def set_loglevel(loglevel): + @property + def log_level(self): + return self.__log_level.get() + + @log_level.setter + def log_level(self, value): try: - SeLogger.__loglevel = int(loglevel) + self.__log_level = int(value) except ValueError: - SeLogger.__loglevel = 0 + self.__log_level = 0 logger = StateEngineDefaults.logger logger.error("Loglevel has to be an int number!") - # Set log directory - # logdirectory: Target directory for StateEngine log files + @property + def log_directory(self): + return SeLogger.__log_directory + + @log_directory.setter + def log_directory(self, value): + SeLogger.__log_directory = value + @staticmethod - def set_logdirectory(logdirectory): - SeLogger.__logdirectory = logdirectory + def init(sh): + SeLogger.__sh = sh # Create log directory # logdirectory: Target directory for StateEngine log files @staticmethod - def create_logdirectory(base, log_directory): + def manage_logdirectory(base, log_directory, create=True): if log_directory[0] != "/": if base[-1] != "/": base += "/" log_directory = base + log_directory - if not os.path.exists(log_directory): + if create is True and not os.path.isdir(log_directory): os.makedirs(log_directory) return log_directory @@ -70,17 +108,17 @@ def set_logmaxage(logmaxage): # Remove old log files (by scheduler) @staticmethod def remove_old_logfiles(): - if SeLogger.__logmaxage == 0: + if SeLogger.__logmaxage == 0 or not os.path.isdir(SeLogger.log_directory): return logger = StateEngineDefaults.logger logger.info("Removing logfiles older than {0} days".format(SeLogger.__logmaxage)) count_success = 0 count_error = 0 now = datetime.datetime.now() - for file in os.listdir(SeLogger.__logdirectory): + for file in os.listdir(SeLogger.log_directory): if file.endswith(".log"): try: - abs_file = os.path.join(SeLogger.__logdirectory, file) + abs_file = os.path.join(SeLogger.log_directory, file) stat = os.stat(abs_file) mtime = datetime.datetime.fromtimestamp(stat.st_mtime) age_in_days = (now - mtime).total_seconds() / 86400.0 @@ -102,33 +140,30 @@ def create(item): # Constructor # item: item for which the detailed log is (used as part of file name) def __init__(self, item): - #self.logger = StateEngineDefaults.se_logger self.logger = logging.getLogger('stateengine.{}'.format(item.property.path)) + self.__name = 'stateengine.{}'.format(item.property.path) self.__section = item.property.path.replace(".", "_").replace("/", "") self.__indentlevel = 0 - self.__loglevel = StateEngineDefaults.log_level + self.__default_log_level = None + self.__startup_log_level = None + self.__log_level = None + self.__using_default = False self.__logmaxage = StateEngineDefaults.log_maxage self.__date = None self.__logerror = False self.__filename = "" self.update_logfile() - # override log level for specific items by using se_log_level attribute - def override_loglevel(self, loglevel, item=None): - self.__loglevel = loglevel.get() - if self.__loglevel != StateEngineDefaults.log_level: - self.logger.info("Loglevel for item {0} got individually set to {1}.".format(item.property.path, self.__loglevel)) - # get current log level of abitem def get_loglevel(self): - return self.__loglevel + return self.log_level.get() # Update name logfile if required def update_logfile(self): if self.__date == datetime.datetime.today() and self.__filename is not None: return self.__date = str(datetime.date.today()) - self.__filename = str(SeLogger.__logdirectory + self.__date + '-' + self.__section + ".log") + self.__filename = str(SeLogger.log_directory + self.__date + '-' + self.__section + ".log") # Increase indentation level # by: number of levels to increase @@ -148,7 +183,13 @@ def decrease_indent(self, by=1): # text: text to log def log(self, level, text, *args): # Section given: Check level - if level <= self.__loglevel: + _log_level = self.get_loglevel() + if _log_level == -1: + self.using_default = True + _log_level = SeLogger.default_log_level.get() + else: + self.using_default = False + if level <= _log_level: indent = "\t" * self.__indentlevel text = text.format(*args) logtext = "{0}{1} {2}\r\n".format(datetime.datetime.now(), indent, text) diff --git a/stateengine/StateEngineState.py b/stateengine/StateEngineState.py index d62c2a294..945af8d77 100755 --- a/stateengine/StateEngineState.py +++ b/stateengine/StateEngineState.py @@ -114,7 +114,7 @@ def can_enter(self): return result # log state data - def write_to_log(self, log_level=StateEngineDefaults.log_level): + def write_to_log(self): self._abitem._initstate = self self._log_info("State {0}:", self.id) self._log_increase_indent() @@ -140,34 +140,34 @@ def write_to_log(self, log_level=StateEngineDefaults.log_level): if self.__conditions.count() > 0: self._log_info("Condition sets to enter state:") self._log_increase_indent() - self.__conditions.write_to_logger(log_level) + self.__conditions.write_to_logger() self._log_decrease_indent() if self.__actions_enter.count() > 0: self._log_info("Actions to perform on enter:") self._log_increase_indent() - self.__actions_enter.write_to_logger(log_level) + self.__actions_enter.write_to_logger() self._log_decrease_indent() self._abitem.update_webif([self.id, 'actions_enter'], self.__actions_enter.dict_actions('actions_enter', self.id)) if self.__actions_stay.count() > 0: self._log_info("Actions to perform on stay:") self._log_increase_indent() - self.__actions_stay.write_to_logger(log_level) + self.__actions_stay.write_to_logger() self._log_decrease_indent() self._abitem.update_webif([self.id, 'actions_stay'], self.__actions_stay.dict_actions('actions_stay', self.id)) if self.__actions_enter_or_stay.count() > 0: self._log_info("Actions to perform on enter or stay:") self._log_increase_indent() - self.__actions_enter_or_stay.write_to_logger(log_level) + self.__actions_enter_or_stay.write_to_logger() self._log_decrease_indent() self._abitem.update_webif([self.id, 'actions_enter_or_stay'], self.__actions_enter_or_stay.dict_actions('actions_enter_or_stay', self.id)) if self.__actions_leave.count() > 0: self._log_info("Actions to perform on leave (instant leave: {})", self._abitem.instant_leaveaction) self._log_increase_indent() - self.__actions_leave.write_to_logger(log_level) + self.__actions_leave.write_to_logger() self._log_decrease_indent() self._abitem.update_webif([self.id, 'actions_leave'], self.__actions_leave.dict_actions('actions_leave', self.id)) self._abitem.set_variable("current.state_name", "") diff --git a/stateengine/StateEngineTools.py b/stateengine/StateEngineTools.py index ab9e2e480..3e8464c7e 100755 --- a/stateengine/StateEngineTools.py +++ b/stateengine/StateEngineTools.py @@ -19,6 +19,7 @@ # You should have received a copy of the GNU General Public License # along with this plugin. If not, see . ######################################################################### +from . import StateEngineLogger import datetime from ast import literal_eval from lib.item import Items @@ -37,41 +38,45 @@ class SeItemChild: # abitem: parent SeItem instance def __init__(self, abitem): self._abitem = abitem + if self._abitem is None: + self.__logger = StateEngineLogger.SeLoggerDummy() + else: + self.__logger = self._abitem.logger self.se_plugin = abitem.se_plugin self._sh = abitem.sh self._shtime = abitem.shtime # wrapper method for logger.info def _log_info(self, text, *args): - self._abitem.logger.info(text, *args) + self.__logger.info(text, *args) # wrapper method for logger.debug def _log_develop(self, text, *args): - self._abitem.logger.develop(text, *args) + self.__logger.develop(text, *args) # wrapper method for logger.debug def _log_debug(self, text, *args): - self._abitem.logger.debug(text, *args) + self.__logger.debug(text, *args) # wrapper method for logger.warning def _log_warning(self, text, *args): - self._abitem.logger.warning(text, *args) + self.__logger.warning(text, *args) # wrapper method for logger.error def _log_error(self, text, *args): - self._abitem.logger.error(text, *args) + self.__logger.error(text, *args) # wrapper method for logger.exception def _log_exception(self, msg, *args, **kwargs): - self._abitem.logger.exception(msg, *args, **kwargs) + self.__logger.exception(msg, *args, **kwargs) # wrapper method for logger.increase_indent def _log_increase_indent(self, by=1): - self._abitem.logger.increase_indent(by) + self.__logger.increase_indent(by) # wrapper method for logger.decrease_indent def _log_decrease_indent(self, by=1): - self._abitem.logger.decrease_indent(by) + self.__logger.decrease_indent(by) # Find a certain item below a given item. diff --git a/stateengine/StateEngineValue.py b/stateengine/StateEngineValue.py index 7a9906682..9dd18dfe2 100755 --- a/stateengine/StateEngineValue.py +++ b/stateengine/StateEngineValue.py @@ -41,7 +41,10 @@ class SeValue(StateEngineTools.SeItemChild): # allow_value_list: Flag: list of values allowed # value_type: Type of value to preset the cast function (allowed: str, num, bool, time) def __init__(self, abitem, name, allow_value_list=False, value_type=None): - super().__init__(abitem) + try: + super().__init__(abitem) + except Exception: + pass self.__name = name self.__allow_value_list = allow_value_list self.__value = None @@ -85,9 +88,14 @@ def is_empty(self): # attribute_name: name of attribute to use # default_value: default value to be used if item contains no such attribute def set_from_attr(self, item, attribute_name, default_value=None, reset=True, attr_type=None): - value = copy.deepcopy(item.conf.get(attribute_name)) or default_value + value = copy.deepcopy(item.conf.get(attribute_name)) if value is not None: + _using_default = False self._log_develop("Processing value {0} from attribute name {1}, reset {2}", value, attribute_name, reset) + else: + value = default_value + _using_default = True + self._log_develop("Processing value from attribute name {0}, reset {1}: using default value {2}", attribute_name, reset, value) value_list = [] if value is not None and isinstance(value, list) and attr_type is not None: for i, entry in enumerate(value): @@ -115,7 +123,7 @@ def set_from_attr(self, item, attribute_name, default_value=None, reset=True, at if value is not None: self._log_develop("Setting value {0}, attribute name {1}, reset {2}", value, attribute_name, reset) _returnvalue, _returntype = self.set(value, attribute_name, reset, item) - return _returnvalue, _returntype + return _returnvalue, _returntype, _using_default def _set_additional(self, _additional_sources): for _use in _additional_sources: @@ -389,89 +397,50 @@ def get_type(self): return self.__type_listorder # Write condition to logger - def write_to_logger(self, log_level=StateEngineDefaults.log_level): + def write_to_logger(self): if self.__template is not None: - if log_level == -1: - self._log_debug("{0}: Using template(s) {1}", self.__name, self.__template) - else: - self._log_info("{0}: Using template(s) {1}", self.__name, self.__template) + self._log_info("{0}: Using template(s) {1}", self.__name, self.__template) if self.__value is not None: if isinstance(self.__value, list): for i in self.__value: if i is not None: - if log_level == -1: - self._log_info("{0}: {1} ({2})", self.__name, i, type(i)) - else: - self._log_debug("{0}: {1} ({2})", self.__name, i, type(i)) + self._log_debug("{0}: {1} ({2})", self.__name, i, type(i)) else: - if log_level == -1: - self._log_info("{0}: {1} ({2})", self.__name, self.__value, type(self.__value)) - else: - self._log_debug("{0}: {1} ({2})", self.__name, self.__value, type(self.__value)) + self._log_debug("{0}: {1} ({2})", self.__name, self.__value, type(self.__value)) if self.__regex is not None: if isinstance(self.__regex, list): for i in self.__regex: if i is not None: - if log_level == -1: - self._log_info("{0} from regex: {1}", self.__name, i) - else: - self._log_debug("{0} from regex: {1}", self.__name, i) + self._log_debug("{0} from regex: {1}", self.__name, i) else: - if log_level == -1: - self._log_info("{0} from regex: {1}", self.__name, self.__regex) - else: - self._log_debug("{0} from regex: {1}", self.__name, self.__regex) + self._log_debug("{0} from regex: {1}", self.__name, self.__regex) if self.__struct is not None: if isinstance(self.__struct, list): for i in self.__struct: if i is not None: - if log_level == -1: - self._log_info("{0} from struct: {1}", self.__name, i.property.path) - else: - self._log_debug("{0} from struct: {1}", self.__name, i.property.path) + self._log_debug("{0} from struct: {1}", self.__name, i.property.path) else: - if log_level == - 1: - self._log_info("{0} from struct: {1}", self.__name, self.__struct.property.path) - else: - self._log_debug("{0} from struct: {1}", self.__name, self.__struct.property.path) + self._log_debug("{0} from struct: {1}", self.__name, self.__struct.property.path) if self.__item is not None: if isinstance(self.__item, list): for i in self.__item: if i is not None: - if log_level == - 1: - self._log_info("{0} from item: {1}", self.__name, i.property.path) - else: - self._log_debug("{0} from item: {1}", self.__name, i.property.path) + self._log_debug("{0} from item: {1}", self.__name, i.property.path) else: - if log_level == - 1: - self._log_info("{0} from item: {1}", self.__name, self.__item.property.path) - else: - self._log_debug("{0} from item: {1}", self.__name, self.__item.property.path) + self._log_debug("{0} from item: {1}", self.__name, self.__item.property.path) if self.__eval is not None: - if log_level == - 1: - self._log_info("{0} from eval: {1}", self.__name, self.__eval) - else: - self._log_debug("{0} from eval: {1}", self.__name, self.__eval) + self._log_debug("{0} from eval: {1}", self.__name, self.__eval) _original_listorder = copy.copy(self.__listorder) - if log_level == - 1: - self._log_info("Currently eval results in {}", self.__get_eval()) - else: - self._log_debug("Currently eval results in {}", self.__get_eval()) + self._log_debug("Currently eval results in {}", self.__get_eval()) self.__listorder = _original_listorder if self.__varname is not None: if isinstance(self.__varname, list): for i in self.__varname: if i is not None: - if log_level == - 1: - self._log_info("{0} from variable: {1}", self.__name, i) - else: - self._log_debug("{0} from variable: {1}", self.__name, i) + self._log_debug("{0} from variable: {1}", self.__name, i) else: - if log_level == - 1: - self._log_info("{0} from variable: {1}", self.__name, self.__varname) - else: - self._log_debug("{0} from variable: {1}", self.__name, self.__varname) + self._log_debug("{0} from variable: {1}", self.__name, self.__varname) # Get Text (similar to logger text) # prefix: Prefix for text diff --git a/stateengine/__init__.py b/stateengine/__init__.py index e21fa1206..dacde6e3f 100755 --- a/stateengine/__init__.py +++ b/stateengine/__init__.py @@ -26,6 +26,7 @@ from . import StateEngineTools from . import StateEngineCliCommands from . import StateEngineFunctions +from . import StateEngineValue from . import StateEngineWebif from . import StateEngineStructs import logging @@ -63,11 +64,22 @@ def __init__(self, sh): if not self.vis_enabled: self.logger.warning(f'StateEngine is missing the PyDotPlus package, WebIf visualization is disabled') self.init_webinterface(WebInterface) - self.__log_directory = self.get_parameter_value("log_directory") + self.get_sh().stateengine_plugin_functions = StateEngineFunctions.SeFunctions(self.get_sh(), self.logger) try: + log_level = self.get_parameter_value("log_level") - StateEngineDefaults.log_level = log_level - log_directory = self.__log_directory + startup_log_level = self.get_parameter_value("startup_log_level") + log_directory = self.get_parameter_value("log_directory") + default_log_level_value = StateEngineValue.SeValue(self, "Default Log Level", False, "num") + default_log_level_value.set(log_level) + SeLogger.default_log_level = default_log_level_value + startup_log_level_value = StateEngineValue.SeValue(self, "Startup Log Level", False, "num") + startup_log_level_value.set(startup_log_level) + SeLogger.startup_log_level = startup_log_level_value + log_level_value = StateEngineValue.SeValue(self, "Log Level", False, "num") + log_level_value.set(log_level) + SeLogger.log_level = log_level_value + self.logger.info("Set default log level to {}, Startup log level to {}.".format(SeLogger.log_level, SeLogger.startup_log_level)) self.logger.info("Init StateEngine (log_level={0}, log_directory={1})".format(log_level, log_directory)) StateEngineDefaults.startup_delay = self.get_parameter_value("startup_delay_default") StateEngineDefaults.suspend_time = self.get_parameter_value("suspend_time_default") @@ -75,23 +87,22 @@ def __init__(self, sh): StateEngineDefaults.suntracking_offset = self.get_parameter_value("lamella_offset") StateEngineDefaults.lamella_open_value = self.get_parameter_value("lamella_open_value") StateEngineDefaults.write_to_log(self.logger) - self.get_sh().stateengine_plugin_functions = StateEngineFunctions.SeFunctions(self.get_sh(), self.logger) - StateEngineCurrent.init(self.get_sh()) + StateEngineCurrent.init(self.get_sh()) base = self.get_sh().get_basedir() - log_directory = SeLogger.create_logdirectory(base, log_directory) + log_directory = SeLogger.manage_logdirectory(base, log_directory, False) + SeLogger.log_directory = log_directory if log_level > 0: text = "StateEngine extended logging is active. Logging to '{0}' with log level {1}." self.logger.info(text.format(log_directory, log_level)) + log_maxage = self.get_parameter_value("log_maxage") if log_maxage > 0: self.logger.info("StateEngine extended log files will be deleted after {0} days.".format(log_maxage)) SeLogger.set_logmaxage(log_maxage) cron = ['init', '30 0 * *'] self.scheduler_add('StateEngine: Remove old logfiles', SeLogger.remove_old_logfiles, cron=cron, offset=0) - SeLogger.set_loglevel(log_level) - SeLogger.set_logdirectory(log_directory) except Exception as ex: self._init_complete = False @@ -114,9 +125,6 @@ def parse_item(self, item): item._eval = "sh.stateengine_plugin_functions.manual_item_update_eval('" + item.id() + "', caller, source)" elif self.has_iattr(item.conf, "se_manual_invert"): item._eval = "not sh." + item.id() + "()" - if self.has_iattr(item.conf, "se_log_level"): - base = self.get_sh().get_basedir() - SeLogger.create_logdirectory(base, self.__log_directory) return None # Initialization of plugin diff --git a/stateengine/plugin.yaml b/stateengine/plugin.yaml index 9423d1993..4d33daa0e 100755 --- a/stateengine/plugin.yaml +++ b/stateengine/plugin.yaml @@ -117,29 +117,59 @@ parameters: type: int default: 0 valid_list: + - -1 - 0 - 1 - 2 - 3 valid_list_description: - de: ['deaktiviert', 'Info', 'Debug', 'Develop'] - en: ['deactivated', 'Info', 'Debug', 'Develop'] + de: ['Standardlevel aus plugin.yaml', 'deaktiviert', 'Info', 'Debug', 'Develop'] + en: ['default level from plugin.yaml', 'deactivated', 'Info', 'Debug', 'Develop'] description: - de: 'Erweiterte Protokollierung: Loglevel (0: aus, 1: Info, 2: Debug, 3: Develop/Verbose)' - en: 'Extended Logging: Loglevel (0: off, 1: Info, 2: Debug, 3: Develop/Verbose)' + de: 'Erweiterte Protokollierung: Loglevel (-1: Wert aus plugin.yaml, 0: aus, 1: Info, 2: Debug, 3: Develop/Verbose)' + en: 'Extended Logging: Loglevel (-1: value from plugin.yaml, 0: off, 1: Info, 2: Debug, 3: Develop/Verbose)' description_long: de: '**Erweiterte Protokollierung:**\n - Bei einem Wert von 1 oder 2 wird pro Item eine eigene Logdatei im unter log_directory + Bei einem Wert von 1, 2 oder 3 wird pro Item eine eigene Logdatei im unter log_directory angegebenen Verzeichnis angelegt. Wenn der Parameter nicht angegeben oder auf 0 gestellt ist, ist die erweiterte Protokollierung deaktiviert. ' en: '**Extended Logging**:\n - If 1 or 2 is given there will be a seperate log file for each item in the folder + If 1, 2 or 3 is given there will be a seperate log file for each item in the folder defined as log_directory. If the parameter is absent or set to 0 no extended logging is active ' + startup_log_level: + type: int + default: 2 + valid_list: + - -1 + - 0 + - 1 + - 2 + - 3 + valid_list_description: + de: ['Standardlevel aus plugin.yaml', 'deaktiviert', 'Info', 'Debug', 'Develop'] + en: ['default level from plugin.yaml', 'deactivated', 'Info', 'Debug', 'Develop'] + description: + de: 'Erweiterte Protokollierung beim Starten des Plugins: Loglevel (-1: Wert aus plugin.yaml, 0: aus, 1: Info, 2: Debug, 3: Develop/Verbose)' + en: 'Extended Logging at plugin startup: Loglevel (-1: value from plugin.yaml, 0: off, 1: Info, 2: Debug, 3: Develop/Verbose)' + description_long: + de: '**Erweiterte Protokollierung:**\n + Bei einem Wert von 1, 2 oder 3 wird pro Item eine eigene Logdatei im unter log_directory + angegebenen Verzeichnis angelegt. + Ist die Initialisierung eines Stateengine Items abgeschlossen, wird der über se_log_level oder + den Standard Loglevel im plugin.yaml eingestellt. + ' + en: '**Extended Logging**:\n + If 1, 2 or 3 is given there will be a seperate log file for each item in the folder + defined as log_directory. + After initialization of the stateengine items the log level will be set to the one + defined in se_log_level or as a standard log level in plugin.yaml. + ' + log_directory: type: str default: 'var/log/stateengine/' @@ -564,24 +594,20 @@ item_attributes: ' se_log_level: - type: int - valid_list: - - 0 - - 1 - - 2 - - 3 - valid_list_description: - de: ['deaktiviert', 'Info', 'Debug', 'Develop'] - en: ['deactivated', 'Info', 'Debug', 'Develop'] + type: foo description: de: 'Loglevel für ein konkretes Stateengine Item' en: 'Log level for a distinct stateengine item' description_long: de: 'Das global angegebene Loglevel kann für jedes SE item individuell überschrieben werden. Somit ist es einfacher möglich, bestimme State Engines zu debuggen. + Das Loglevel kann durch das Settings Item log_level im laufenden Betrieb angepasst werden. + Ist der Wert auf -1 gesetzt, wird der Standardwert aus dem plugin.yaml übernommen. ' en: 'The globally defined log level can be overwritten for each SE item individually. Therefore it is easier to debug specific state engines. + The log level can be adjusted by changing the setting item log_level while the plugin is running. + If the value is set to -1 the standard value from plugin.yaml is used. ' se_use: @@ -700,6 +726,10 @@ item_structs: on_update: ..rules = True settings: + log_level: + type: num + initial_value: -1 + settings_edited: type: bool name: settings editiert @@ -712,6 +742,7 @@ item_structs: remark: configure your se_item_* and eval_triggers here type: bool se_plugin: active + se_log_level: item:..settings.log_level eval: True se_laststate_item_id: ..state_id se_laststate_item_name: ..state_name