Merge pull request #4630 from StackStorm/fix_non_fatal_error_log_level

Log non-fatal errors during service bootstrap phase under DEBUG instead of ERROR

Author: Kami

CHANGELOG.rst

@@ -110,6 +110,8 @@ Fixed
   #4615
 * Fix an issue with new line characters (``\n``) being converted to ``\r\n`` in remote shell
   command and script actions which use sudo. (bug fix) #4623
+* Update service bootstrap and ``st2-register-content`` script code so non-fatal errors are
+  suppressed by default and only logged under ``DEBUG`` log level. (bug fix) #3933 #4626 #4630
 
 2.10.4 - March 15, 2019
 -----------------------

st2common/st2common/services/triggers.py

@@ -245,7 +245,7 @@ def create_trigger_db(trigger_api):
     return trigger_db
 
 
-def create_or_update_trigger_db(trigger):
+def create_or_update_trigger_db(trigger, log_not_unique_error_as_debug=False):
     """
     Create a new TriggerDB model if one doesn't exist yet or update existing
     one.
@@ -269,7 +269,8 @@ def create_or_update_trigger_db(trigger):
     if is_update:
         trigger_db.id = existing_trigger_db.id
 
-    trigger_db = Trigger.add_or_update(trigger_db)
+    trigger_db = Trigger.add_or_update(trigger_db,
+        log_not_unique_error_as_debug=log_not_unique_error_as_debug)
 
     extra = {'trigger_db': trigger_db}
 
@@ -331,13 +332,20 @@ def cleanup_trigger_db_for_rule(rule_db):
     Trigger.delete_if_unreferenced(existing_trigger_db)
 
 
-def create_trigger_type_db(trigger_type):
+def create_trigger_type_db(trigger_type, log_not_unique_error_as_debug=False):
     """
     Creates a trigger type db object in the db given trigger_type definition as dict.
 
     :param trigger_type: Trigger type model.
     :type trigger_type: ``dict``
 
+    :param log_not_unique_error_as_debug: True to lot NotUnique errors under debug instead of
+                                          error log level. This is to be used in scenarios where
+                                          failure is non-fatal (e.g. when services register
+                                          internal trigger types which is an idempotent
+                                          operation).
+    :type log_not_unique_error_as_debug: ``bool``
+
     :rtype: ``object``
     """
     trigger_type_api = TriggerTypeAPI(**trigger_type)
@@ -349,13 +357,23 @@ def create_trigger_type_db(trigger_type):
     if not trigger_type_db:
         trigger_type_db = TriggerTypeAPI.to_model(trigger_type_api)
         LOG.debug('verified trigger and formulated TriggerDB=%s', trigger_type_db)
-        trigger_type_db = TriggerType.add_or_update(trigger_type_db)
+        trigger_type_db = TriggerType.add_or_update(trigger_type_db,
+            log_not_unique_error_as_debug=log_not_unique_error_as_debug)
+
     return trigger_type_db
 
 
-def create_shadow_trigger(trigger_type_db):
+def create_shadow_trigger(trigger_type_db, log_not_unique_error_as_debug=False):
     """
     Create a shadow trigger for TriggerType with no parameters.
+
+    :param log_not_unique_error_as_debug: True to lot NotUnique errors under debug instead of
+                                          error log level. This is to be used in scenarios where
+                                          failure is non-fatal (e.g. when services register
+                                          internal trigger types which is an idempotent
+                                          operation).
+    :type log_not_unique_error_as_debug: ``bool``
+
     """
     trigger_type_ref = trigger_type_db.get_reference().ref
 
@@ -368,16 +386,24 @@ def create_shadow_trigger(trigger_type_db):
                'type': trigger_type_ref,
                'parameters': {}}
 
-    return create_or_update_trigger_db(trigger)
+    return create_or_update_trigger_db(trigger,
+                                       log_not_unique_error_as_debug=log_not_unique_error_as_debug)
 
 
-def create_or_update_trigger_type_db(trigger_type):
+def create_or_update_trigger_type_db(trigger_type, log_not_unique_error_as_debug=False):
     """
     Create or update a trigger type db object in the db given trigger_type definition as dict.
 
     :param trigger_type: Trigger type model.
     :type trigger_type: ``dict``
 
+    :param log_not_unique_error_as_debug: True to lot NotUnique errors under debug instead of
+                                          error log level. This is to be used in scenarios where
+                                          failure is non-fatal (e.g. when services register
+                                          internal trigger types which is an idempotent
+                                          operation).
+    :type log_not_unique_error_as_debug: ``bool``
+
     :rtype: ``object``
     """
     assert isinstance(trigger_type, dict)
@@ -399,7 +425,8 @@ def create_or_update_trigger_type_db(trigger_type):
         trigger_type_api.id = existing_trigger_type_db.id
 
     try:
-        trigger_type_db = TriggerType.add_or_update(trigger_type_api)
+        trigger_type_db = TriggerType.add_or_update(trigger_type_api,
+            log_not_unique_error_as_debug=log_not_unique_error_as_debug)
     except StackStormDBObjectConflictError:
         # Operation is idempotent and trigger could have already been created by
         # another process. Ignore object already exists because it simply means

st2common/st2common/triggers.py

@@ -14,6 +14,7 @@
 # limitations under the License.
 
 from __future__ import absolute_import
+
 import six
 
 from mongoengine import ValidationError
@@ -23,7 +24,8 @@
 from st2common import log as logging
 from st2common.constants.triggers import (INTERNAL_TRIGGER_TYPES, ACTION_SENSOR_TRIGGER)
 from st2common.exceptions.db import StackStormDBObjectConflictError
-from st2common.services.triggers import create_trigger_type_db, create_shadow_trigger
+from st2common.services.triggers import create_trigger_type_db
+from st2common.services.triggers import create_shadow_trigger
 from st2common.services.triggers import get_trigger_type_db
 from st2common.models.system.common import ResourceReference
 
@@ -36,11 +38,12 @@
 
 def _register_internal_trigger_type(trigger_definition):
     try:
-        trigger_type_db = create_trigger_type_db(trigger_type=trigger_definition)
+        trigger_type_db = create_trigger_type_db(trigger_type=trigger_definition,
+                                                 log_not_unique_error_as_debug=True)
     except (NotUniqueError, StackStormDBObjectConflictError):
         # We ignore conflict error since this operation is idempotent and race is not an issue
-        LOG.debug('Internal trigger type "%s" already exists, ignoring...' %
-                  (trigger_definition['name']), exc_info=True)
+        LOG.debug('Internal trigger type "%s" already exists, ignoring error...' %
+                  (trigger_definition['name']))
 
         ref = ResourceReference.to_string_reference(name=trigger_definition['name'],
                                                     pack=trigger_definition['pack'])
@@ -52,12 +55,13 @@ def _register_internal_trigger_type(trigger_definition):
     # trigger types with parameters do no require a shadow trigger.
     if trigger_type_db and not trigger_type_db.parameters_schema:
         try:
-            trigger_db = create_shadow_trigger(trigger_type_db)
+            trigger_db = create_shadow_trigger(trigger_type_db,
+                log_not_unique_error_as_debug=True)
 
             extra = {'trigger_db': trigger_db}
             LOG.audit('Trigger created for parameter-less internal TriggerType. Trigger.id=%s' %
                       (trigger_db.id), extra=extra)
-        except StackStormDBObjectConflictError:
+        except (NotUniqueError, StackStormDBObjectConflictError):
             LOG.debug('Shadow trigger "%s" already exists. Ignoring.',
                       trigger_type_db.get_reference().ref, exc_info=True)
 
@@ -73,7 +77,11 @@ def register_internal_trigger_types():
     """
     Register internal trigger types.
 
-    Note: This method blocks until all the trigger types have been registered.
+    NOTE 1: This method blocks until all the trigger types have been registered.
+
+    NOTE 2: We log "NotUniqueError" errors under debug and not error. Those errors are not fatal
+    because this operation is idempotent and NotUniqueError simply means internal trigger type
+    has already been registered by some other service.
     """
     action_sensor_enabled = cfg.CONF.action_sensor.enable