Merge pull request #357 from wklken/fix_logging_issues

feat(api/logging): enhance the logging while api 500

deploy/helm/bk-user/Chart.yaml

@@ -2,8 +2,8 @@ apiVersion: v2
 name: bk-user
 description: A Helm chart for bk-user
 type: application
-version: 1.2.3
-appVersion: "v2.3.4-beta.10"
+version: 1.2.4
+appVersion: "v2.3.4-beta.11"
 
 dependencies:
 

deploy/helm/bk-user/charts/api/Chart.yaml

@@ -3,4 +3,4 @@ name: api
 description: Api module for bk-user
 type: application
 version: 1.0.0
-appVersion: "v2.3.4-beta.10"
+appVersion: "v2.3.4-beta.11"

deploy/helm/bk-user/charts/api/values.yaml

@@ -89,7 +89,7 @@ image:
   registry: hub.bktencent.com
   repository: blueking/bk-user-api
   pullPolicy: IfNotPresent
-  tag: "v2.3.4-beta.10"
+  tag: "v2.3.4-beta.11"
 
 nameOverride: ""
 fullnameOverride: ""

deploy/helm/bk-user/charts/login/Chart.yaml

@@ -3,4 +3,4 @@ name: login
 description: login module for blueking
 type: application
 version: 1.0.0
-appVersion: "v2.3.4-beta.10"
+appVersion: "v2.3.4-beta.11"

deploy/helm/bk-user/charts/login/values.yaml

@@ -83,7 +83,7 @@ image:
   registry: hub.bktencent.com
   repository: blueking/bk-login
   pullPolicy: IfNotPresent
-  tag: "v2.3.4-beta.10"
+  tag: "v2.3.4-beta.11"
 
 nameOverride: ""
 fullnameOverride: ""

deploy/helm/bk-user/charts/saas/Chart.yaml

@@ -3,4 +3,4 @@ name: saas
 description: SaaS module for bk-user
 type: application
 version: 1.0.0
-appVersion: "v2.3.4-beta.10"
+appVersion: "v2.3.4-beta.11"

deploy/helm/bk-user/charts/saas/values.yaml

@@ -81,7 +81,7 @@ image:
   registry: hub.bktencent.com
   repository: blueking/bk-user-saas
   pullPolicy: IfNotPresent
-  tag: "v2.3.4-beta.10"
+  tag: "v2.3.4-beta.11"
 
 command: []
 args: []

src/api/bkuser_core/audit/utils.py

@@ -69,6 +69,9 @@ def create_general_log(
     }
     if request:
         extra_value["client_ip"] = get_client_ip(request)
+        # from esb/apigateway, will got a valid bk_app_code
+        if hasattr(request, "bk_app_code"):
+            extra_value["bk_app_code"] = request.bk_app_code
 
     extra_value.update(audit_info.to_dict())
     extra_value.update(extra_info or {})

src/api/bkuser_core/common/exception_handler.py

@@ -9,14 +9,15 @@
 specific language governing permissions and limitations under the License.
 """
 import logging
+import traceback
 
 from bkuser_core.bkiam.exceptions import IAMPermissionDenied
 from django.core.exceptions import PermissionDenied
 from django.db import ProgrammingError
 from django.http import Http404
 from rest_framework.exceptions import AuthenticationFailed, ValidationError
 from rest_framework.response import Response
-from rest_framework.status import HTTP_400_BAD_REQUEST
+from rest_framework.status import HTTP_400_BAD_REQUEST, HTTP_500_INTERNAL_SERVER_ERROR
 from rest_framework.views import exception_handler
 from sentry_sdk import capture_exception
 
@@ -43,13 +44,30 @@ def custom_exception_handler(exc, context):
     #     # Only presents in ValidationError
     #     "fields_detail": {"field1": ["error message"]}
     # }
+    # extra details
+    detail = {
+        "error": "unknown",
+    }
+    if context:
+        try:
+            req = context.get("request")
+            detail["path"] = req.path
+            detail["method"] = req.method
+            detail["query_params"] = req.query_params
+            detail["request_id"] = req.headers.get("X-Request-Id")
+            if hasattr(req, "bk_app_code"):
+                detail["bk_app_code"] = req.bk_app_code
+        except Exception:  # pylint: disable=broad-except
+            # do nothing if get extra details fail
+            pass
+
     if exist_force_raw_header(context["request"]):
-        return get_raw_exception_response(exc, context)
+        return get_raw_exception_response(exc, context, detail)
     else:
-        return get_ee_exception_response(exc, context)
+        return get_ee_exception_response(exc, context, detail)
 
 
-def get_ee_exception_response(exc, context):
+def get_ee_exception_response(exc, context, detail):
     """针对企业版异常返回封装"""
     data = {"result": False, "data": None, "code": -1}
 
@@ -70,7 +88,7 @@ def get_ee_exception_response(exc, context):
         data["message"] = "403, authentication failed"
     else:
         # log
-        logger.exception("unknown exception while handling the request")
+        logger.exception("unknown exception while handling the request, detail=%s", detail)
         # report to sentry
         capture_exception(exc)
         # build response
@@ -104,7 +122,7 @@ def one_line_error(detail):
         return "参数格式错误"
 
 
-def get_raw_exception_response(exc, context):
+def get_raw_exception_response(exc, context, detail):
     if isinstance(exc, ValidationError):
         data = {
             "code": "VALIDATION_ERROR",
@@ -126,11 +144,25 @@ def get_raw_exception_response(exc, context):
         data = {"code": "PROGRAMMING_ERROR", "detail": UNKNOWN_ERROR_HINT}
         return Response(data, status=HTTP_400_BAD_REQUEST, headers={})
 
+    # log
+    logger.exception("unknown exception while handling the request, detail=%s", detail)
+    # report to sentry
+    capture_exception(exc)
+
     # Call REST framework's default exception handler to get the standard error response.
     response = exception_handler(exc, context)
     # Use a default error code
     if response is not None:
         response.data.update(code="ERROR")
         setattr(response, "from_exception", True)
+        return response
 
+    # NOTE: 不暴露给前端, 只打日志, 所以不放入data.detail
+    # error detail
+    if exc is not None:
+        detail["error"] = traceback.format_exc()
+
+    data = {"result": False, "data": detail, "code": -1, "message": UNKNOWN_ERROR_HINT}
+    response = Response(data=data, status=HTTP_500_INTERNAL_SERVER_ERROR)
+    setattr(response, "from_exception", True)
     return response

src/api/bkuser_core/config/overlays/unittest.py

@@ -16,6 +16,60 @@
 LOG_LEVEL = "DEBUG"
 LOGGING = get_logging(logging_type=LoggingType.STDOUT, log_level=LOG_LEVEL, package_name="bkuser_core")
 
+
+def get_loggers(package_name: str, log_level: str) -> dict:
+    return {
+        "django": {
+            "handlers": ["null"],
+            "level": "INFO",
+            "propagate": True,
+        },
+        "django.request": {
+            "handlers": ["root"],
+            "level": "ERROR",
+            "propagate": True,
+        },
+        "django.db.backends": {
+            "handlers": ["root"],
+            "level": "INFO",
+            "propagate": True,
+        },
+        "django.security": {
+            "handlers": ["root"],
+            "level": "INFO",
+            "propagate": True,
+        },
+        package_name: {
+            "handlers": ["root"],
+            "level": log_level,
+            "propagate": True,
+        },
+        "": {
+            "handlers": ["root"],
+            "level": log_level,
+        },
+        "requests": {
+            "handlers": ["root"],
+            "level": log_level,
+            "propagate": True,
+        },
+        # 组件调用日志
+        "component": {
+            "handlers": ["root"],
+            "level": "WARN",
+            "propagate": True,
+        },
+        "iam": {
+            "handlers": ["root"],
+            "level": log_level,
+            "propagate": True,
+        },
+    }
+
+
+# patch the unittest logging loggers
+LOGGING["loggers"] = get_loggers("bkuser_core", LOG_LEVEL)
+
 # ==============================================================================
 # Test Ldap
 # ==============================================================================

src/api/bkuser_core/profiles/password.py

@@ -165,5 +165,10 @@ def validate(self, value: str):
         for e_name in self.include_elements:
             get_element_cls_by_name(e_name).match(value)
 
+        # FIXME: currently the user_settings value type json is not checked before save into database
+        # so, we do a protect here, but should fix it in the future, and remove these codes
+        if isinstance(self.exclude_elements_config, list) and not self.exclude_elements_config:
+            self.exclude_elements_config = {}
+
         for e_name, max_length in self.exclude_elements_config.items():
             get_element_cls_by_name(e_name).match(value, max_seq_len=max_length)

src/bkuser_global/logging.py

@@ -58,22 +58,22 @@ def get_loggers(package_name: str, log_level: str) -> dict:
         "django.request": {
             "handlers": ["root"],
             "level": "ERROR",
-            "propagate": True,
+            "propagate": False,
         },
         "django.db.backends": {
             "handlers": ["root"],
             "level": "INFO",
-            "propagate": True,
+            "propagate": False,
         },
         "django.security": {
             "handlers": ["root"],
             "level": "INFO",
-            "propagate": True,
+            "propagate": False,
         },
         package_name: {
             "handlers": ["root"],
             "level": log_level,
-            "propagate": True,
+            "propagate": False,
         },
         "": {
             "handlers": ["root"],
@@ -82,17 +82,18 @@ def get_loggers(package_name: str, log_level: str) -> dict:
         "requests": {
             "handlers": ["root"],
             "level": log_level,
+            "propagate": False,
         },
         # 组件调用日志
         "component": {
             "handlers": ["root"],
             "level": "WARN",
-            "propagate": True,
+            "propagate": False,
         },
         "iam": {
             "handlers": ["root"],
             "level": log_level,
-            "propagate": True,
+            "propagate": False,
         },
     }
 

src/saas/bkuser_shell/apis/viewset.py

@@ -11,6 +11,7 @@
 import json
 import logging
 import math
+import uuid
 from collections import OrderedDict
 from typing import Callable, Optional
 
@@ -176,4 +177,5 @@ def make_default_headers(operator: str) -> dict:
         settings.API_APP_CODE_HEADER_NAME: settings.APP_ID,
         settings.API_APP_SECRET_HEADER_NAME: settings.APP_TOKEN,
         "Accept-Language": get_language(),
+        "X-Request-ID": uuid.uuid4().hex,
     }