Lumigo tracer enhanced programmatic logger (#189)

* added info, warn, and error to tracer API

Author: OrrLumigo

.circleci/config.yml

@@ -115,7 +115,7 @@ jobs:
     <<: *defaults
     steps:
       - checkout_code
-      - checkout_credentials
+      - checkout_utils
       # run tests!
       - run: echo "export AWS_DEFAULT_REGION=us-west-2" >> $BASH_ENV
       - run: mkdir -p ~/.aws

src/lumigo_tracer/__init__.py

@@ -1,3 +1,3 @@
 from .tracer import lumigo_tracer, LumigoChalice  # noqa
-from .user_utils import report_error, add_execution_tag  # noqa
+from .user_utils import report_error, add_execution_tag, info, warn, error  # noqa
 from .auto_instrument_handler import _handler  # noqa

src/lumigo_tracer/user_utils.py

@@ -1,12 +1,82 @@
+import json
+import logging
+from typing import Dict, Optional
+
 from lumigo_tracer.spans_container import SpansContainer
 from lumigo_tracer.lumigo_utils import Configuration, warn_client
 
 LUMIGO_REPORT_ERROR_STRING = "[LUMIGO_LOG]"
 MAX_TAGS = 50
+MAX_ELEMENTS_IN_EXTRA = 10
 MAX_TAG_KEY_LEN = MAX_TAG_VALUE_LEN = 50
 ADD_TAG_ERROR_MSG_PREFIX = "Skipping add_execution_tag: Unable to add tag"
 
 
+def info(msg: str, alert_type: str = "ProgrammaticInfo", extra: Dict[str, str] = None):
+    """
+    Use this function to create a log entry in your lumigo platform.
+    You can use it to dynamically generate alerts programmatically with searchable fields.
+    Then use the lumigo explore to search and filters logs in free text.
+
+    :param msg: a free text to log
+    :param alert_type: Should be considered as a grouping parameter. This indicates the type of this message. Default: ProgrammaticInfo
+    :param extra: a key-value dict. Limited to 10 keys and 50 characters per value.
+    """
+    log(logging.INFO, msg, alert_type, extra)
+
+
+def warn(msg: str, alert_type: str = "ProgrammaticWarn", extra: Dict[str, str] = None):
+    """
+    Use this function to create a log entry in your lumigo platform.
+    You can use it to dynamically generate alerts programmatically with searchable fields.
+    Then use the lumigo explore to search and filters logs in free text.
+
+    :param msg: a free text to log
+    :param alert_type: Should be considered as a grouping parameter. This indicates the type of this message. Default: ProgrammaticWarn
+    :param extra: a key-value dict. Limited to 10 keys and 50 characters per value.
+    """
+    log(logging.WARN, msg, alert_type, extra)
+
+
+def error(
+    msg: str,
+    alert_type: Optional[str] = None,
+    extra: Optional[Dict[str, str]] = None,
+    err: Optional[Exception] = None,
+):
+    """
+    Use this function to create a log entry in your lumigo platform.
+    You can use it to dynamically generate alerts programmatically with searchable fields.
+    Then use the lumigo explore to search and filters logs in free text.
+
+    :param msg: a free text to log
+    :param alert_type: Should be considered as a grouping parameter. This indicates the type of this message. Default: take the given exception type or ProgrammaticError if its None
+    :param extra: a key-value dict. Limited to 10 keys and 50 characters per value. By default we're taking the excpetion raw message
+    :param err: the actual error object.
+    """
+
+    extra = extra or {}
+    if err:
+        extra["raw_exception"] = str(err)
+        alert_type = alert_type or err.__class__.__name__
+    alert_type = alert_type or "ProgrammaticError"
+    log(logging.ERROR, msg, alert_type, extra)
+
+
+def log(level: int, msg: str, error_type: str, extra: Optional[Dict[str, str]]):
+    filtered_extra = list(
+        filter(
+            lambda element: validate_tag(element[0], element[1], 0, True),
+            (extra or {}).items(),
+        )
+    )
+    extra = {key: str(value) for key, value in filtered_extra[:MAX_ELEMENTS_IN_EXTRA]}
+    actual = {"message": msg, "type": error_type, "level": level}
+    if extra:
+        actual["extra"] = extra
+    print(LUMIGO_REPORT_ERROR_STRING, json.dumps(actual))
+
+
 def report_error(msg: str):
     message_with_initials = f"{LUMIGO_REPORT_ERROR_STRING} {msg}"
     if Configuration.enhanced_print:
@@ -16,6 +86,30 @@ def report_error(msg: str):
         print(message_with_request_id)
 
 
+def validate_tag(key, value, tags_len, should_log_errors):
+    value = str(value)
+    if not key or len(key) >= MAX_TAG_KEY_LEN:
+        if should_log_errors:
+            warn_client(
+                f"{ADD_TAG_ERROR_MSG_PREFIX}: key length should be between 1 and {MAX_TAG_KEY_LEN}: {key} - {value}"
+            )
+        return False
+    if not value or len(value) >= MAX_TAG_VALUE_LEN:
+        if should_log_errors:
+            warn_client(
+                f"{ADD_TAG_ERROR_MSG_PREFIX}: value length should be between 1 and {MAX_TAG_VALUE_LEN}: {key} - {value}"
+            )
+        return False
+    if tags_len >= MAX_TAGS:
+        if should_log_errors:
+            warn_client(
+                f"{ADD_TAG_ERROR_MSG_PREFIX}: maximum number of tags is {MAX_TAGS}: {key} - {value}"
+            )
+        return False
+
+    return True
+
+
 def add_execution_tag(key: str, value: str, should_log_errors: bool = True) -> bool:
     """
     Use this function to add an execution_tag to your function with a dynamic value.
@@ -27,28 +121,13 @@ def add_execution_tag(key: str, value: str, should_log_errors: bool = True) -> b
     :param should_log_errors: Should a log message be printed in case the tag can't be added.
     """
     try:
-        tags_len = SpansContainer.get_span().get_tags_len()
         key = str(key)
         value = str(value)
-        if not key or len(key) >= MAX_TAG_KEY_LEN:
-            if should_log_errors:
-                warn_client(
-                    f"{ADD_TAG_ERROR_MSG_PREFIX}: key length should be between 1 and {MAX_TAG_KEY_LEN}: {key} - {value}"
-                )
-            return False
-        if not value or len(value) >= MAX_TAG_VALUE_LEN:
-            if should_log_errors:
-                warn_client(
-                    f"{ADD_TAG_ERROR_MSG_PREFIX}: value length should be between 1 and {MAX_TAG_VALUE_LEN}: {key} - {value}"
-                )
-            return False
-        if tags_len >= MAX_TAGS:
-            if should_log_errors:
-                warn_client(
-                    f"{ADD_TAG_ERROR_MSG_PREFIX}: maximum number of tags is {MAX_TAGS}: {key} - {value}"
-                )
+        tags_len = SpansContainer.get_span().get_tags_len()
+        if validate_tag(key, value, tags_len, should_log_errors):
+            SpansContainer.get_span().add_tag(key, value)
+        else:
             return False
-        SpansContainer.get_span().add_tag(key, value)
     except Exception:
         if should_log_errors:
             warn_client(ADD_TAG_ERROR_MSG_PREFIX)

src/test/unit/test_user_utils.py

@@ -1,11 +1,15 @@
 from lumigo_tracer.spans_container import SpansContainer
 from lumigo_tracer.user_utils import (
     report_error,
+    warn,
+    info,
+    error,
     LUMIGO_REPORT_ERROR_STRING,
     add_execution_tag,
     MAX_TAG_KEY_LEN,
     MAX_TAG_VALUE_LEN,
     MAX_TAGS,
+    MAX_ELEMENTS_IN_EXTRA,
 )
 from lumigo_tracer.lumigo_utils import Configuration, EXECUTION_TAGS_KEY
 
@@ -18,6 +22,65 @@ def test_report_error_with_enhance_print(capsys):
     assert captured.out == f"{LUMIGO_REPORT_ERROR_STRING} {msg}\n"
 
 
+def test_err_without_alert_type_with_exception(capsys):
+    msg = '{"message": "This is error message", "type": "RuntimeError", "level": 40, "extra": {"a": "3", "b": "True", "c": "aaa", "d": "{}", "aa": "a", "a0": "0", "a1": "1", "a2": "2", "a3": "3", "a4": "4"}}'
+    error(
+        err=RuntimeError("Failed to open database"),
+        msg="This is error message",
+        extra={
+            "a": 3,
+            "b": True,
+            "c": "aaa",
+            "d": {},
+            "aa": "a",
+            "A" * 100: "A" * 100,
+            **{f"a{i}": i for i in range(MAX_ELEMENTS_IN_EXTRA)},
+        },
+    )
+    captured = capsys.readouterr().out.split("\n")
+    assert captured[1] == f"{LUMIGO_REPORT_ERROR_STRING} {msg}"
+
+
+def test_err_with_type_and_exception(capsys):
+    msg = (
+        '{"message": "This is error message", "type": "DBError",'
+        ' "level": 40, "extra": {"raw_exception": "Failed to open database"}}'
+    )
+    error(
+        err=RuntimeError("Failed to open database"),
+        msg="This is error message",
+        alert_type="DBError",
+    )
+    captured = capsys.readouterr().out.split("\n")
+    assert captured[0] == f"{LUMIGO_REPORT_ERROR_STRING} {msg}"
+
+
+def test_err_with_no_type_and_no_exception(capsys):
+    msg = '{"message": "This is error message", "type": "ProgrammaticError", "level": 40}'
+    error(
+        msg="This is error message",
+    )
+    captured = capsys.readouterr().out.split("\n")
+    assert captured[0] == f"{LUMIGO_REPORT_ERROR_STRING} {msg}"
+
+
+def test_basic_info_warn_error(capsys):
+    info("This is error message")
+    warn("This is error message")
+    error("This is error message")
+    info_msg = (
+        '[LUMIGO_LOG] {"message": "This is error message", "type": "ProgrammaticInfo", "level": 20}'
+    )
+    warn_msg = (
+        '[LUMIGO_LOG] {"message": "This is error message", "type": "ProgrammaticWarn", "level": 30}'
+    )
+    error_msg = '[LUMIGO_LOG] {"message": "This is error message", "type": "ProgrammaticError", "level": 40}'
+    captured = capsys.readouterr().out.split("\n")
+    assert captured[0] == info_msg
+    assert captured[1] == warn_msg
+    assert captured[2] == error_msg
+
+
 def test_report_error_without_enhance_print(capsys):
     Configuration.enhanced_print = False
     SpansContainer.get_span().function_span["id"] = "123"