Kubernetes 日志错误的严重性

huangapple go评论104阅读模式
英文:

Kubernetes Logging Wrong Severity

问题

我在k8的pod中部署了一个Python进程。这个进程使用一个简单的记录器:

  1. import sys
  2. import logging
  3. import logging.handlers
  4. from pathlib import Path
  5. import coloredlogs
  6. from app.core.config import settings
  7. CONFIG_PATH = Path.joinpath(BASE_PATH, '.configrc')
  8. LOG_FORMAT = f'%(asctime)s.[{settings.APP_NAME}] %(levelname)s %(message)s'
  9. LOG_LEVEL = settings.dict().get('LOG_LEVEL', logging.INFO)
  10. LOGGER = logging.getLogger(__name__)
  11. coloredlogs.install(
  12. level=LOG_LEVEL,
  13. fmt=LOG_FORMAT,
  14. logger=LOGGER)
  15. LOGGER.info("INFO Creating main objects...")

然而,当我检查k8的日志时,它总是抱怨这些日志是错误的:

  1. ERROR 2023-06-01T13:54:37.742688222Z [resource.labels.containerName: myapp] 2023-06-01 15:54:37.[myapp] INFO Creating main objects...
  2. {
  3. insertId: "8xj2l2hwts2f45gt"
  4. labels: {4}
  5. logName: "projects/proj-iot-poc/logs/stderr"
  6. receiveTimestamp: "2023-06-01T13:54:38.596712564Z"
  7. resource: {2}
  8. severity: "ERROR"
  9. textPayload: "2023-06-01 15:54:37.[myapp] INFO Creating main objects..."
  10. timestamp: "2023-06-01T13:54:37.742688222Z"
  11. }

不值一提的是,我只使用了 LOGGER.info("Creating main objects...") 并且我期望日志只是一个信息而不是错误。

清单如下:

  1. apiVersion: apps/v1
  2. kind: Deployment
  3. metadata:
  4. annotations:
  5. deployment.kubernetes.io/revision: "11"
  6. kubectl.kubernetes.io/last-applied-configuration: |
  7. {"apiVersion":"apps/v1","kind":"Deployment","metadata":{"annotations":{},"labels":{"name":"myapp"},"name":"myapp","namespace":"default"},"spec":{"replicas":1,"selector":{"matchLabels":{"app":"myapp"}},"strategy":{"type":"Recreate"},"template":{"metadata":{"labels":{"app":"myapp","version":"1.6.1rc253"}},"spec":{"containers":[{"env":[{"name":"COMMON_CONFIG_COMMIT_ID","value":"1b2e6669140391d680ff0ca34811ddc2553f15f7"},{"name":"OWN_CONFIG_COMMIT_ID","value":"52a142ca003ade39a0fd96faffbe5334facc3463"}],"envFrom":[{"configMapRef":{"name":"myapp-config"}}],"image":"europe-west1-docker.pkg.dev/mycluster/docker-main/myapp:1.6.1rc253","lifecycle":{"preStop":{"exec":{"command":["/bin/bash","-c","sleep 5"]}}},"name":"myapp","resources":null}],"restartPolicy":"Always"}}}}}
  8. creationTimestamp: "2023-05-26T07:49:37Z"
  9. generation: 13
  10. labels:
  11. name: myapp
  12. managedFields:
  13. - apiVersion: apps/v1
  14. fieldsType: FieldsV1
  15. fieldsV1:
  16. f:metadata:
  17. f:annotations:
  18. .: {}
  19. f:kubectl.kubernetes.io/last-applied-configuration: {}
  20. f:labels:
  21. .: {}
  22. f:name: {}
  23. f:spec:
  24. f:progressDeadlineSeconds: {}
  25. f:revisionHistoryLimit: {}
  26. f:selector: {}
  27. f:strategy:
  28. f:type: {}
  29. f:template:
  30. f:metadata:
  31. f:labels:
  32. .: {}
  33. f:app: {}
  34. f:version: {}
  35. f:spec:
  36. f:containers:
  37. k:{"name":"myapp"}:
  38. .: {}
  39. f:env:
  40. .: {}
  41. k:{"name":"COMMON_CONFIG_COMMIT_ID"}:
  42. .: {}
  43. f:name: {}
  44. f:value: {}
  45. k:{"name":"OWN_CONFIG_COMMIT_ID"}:
  46. .: {}
  47. f:name: {}
  48. f:value: {}
  49. f:envFrom: {}
  50. f:image: {}
  51. f:imagePullPolicy: {}
  52. f:lifecycle:
  53. .: {}
  54. f:preStop:
  55. .: {}
  56. f:exec:
  57. .: {}
  58. f:command: {}
  59. f:name: {}
  60. f:resources: {}
  61. f:terminationMessagePath: {}
  62. f:terminationMessagePolicy: {}
  63. f:dnsPolicy: {}
  64. f:restartPolicy: {}
  65. f:schedulerName: {}
  66. f:securityContext: {}
  67. f:terminationGracePeriodSeconds: {}
  68. manager: kubectl-client-side-apply
  69. operation: Update
  70. time: "2023-05-26T07:49:37Z"
  71. - apiVersion: apps/v1
  72. fieldsType: FieldsV1
  73. fieldsV1:
  74. f:metadata:
  75. f:annotations:
  76. f:deployment.kubernetes.io/revision: {}
  77. f:status:
  78. f:availableReplicas: {}
  79. f:conditions:
  80. .: {}
  81. k:{"type":"Available"}:
  82. .: {}
  83. f:lastTransitionTime: {}
  84. f:lastUpdateTime: {}
  85. f:message: {}
  86. f:reason: {}
  87. f:status: {}
  88. f:type: {}
  89. k:{"type":"Progressing"}:
  90. .: {}
  91. f:lastTransitionTime: {}
  92. f:lastUpdateTime: {}
  93. f:message: {}
  94. f:reason: {}
  95. f:status: {}
  96. f:type: {}
  97. f:observedGeneration: {}
  98. f:readyReplicas: {}
  99. f:replicas: {}
  100. f:updatedReplicas: {}
  101. manager: kube-controller-manager
  102. operation: Update
  103. subresource: status
  104. time: "2023-06-03T06:41:24Z"
  105. name: myapp
  106. namespace: default
  107. resourceVersion: "537412667"
  108. uid: 375a536e-e39c-4001-a234-e47e812f0bee
  109. spec:
  110. progressDeadlineSeconds: 600
  111. replicas: 1
  112. revisionHistoryLimit: 10
  113. selector:
  114. matchLabels:
  115. app: myapp
  116. strategy:
  117. type: Recreate
  118. template:
  119. metadata:
  120. creationTimestamp: null
  121. labels:
  122. app: myapp
  123. version: 1.6.1rc253
  124. spec:
  125. containers:
  126. - env:
  127. - name: COMMON_CONFIG_COMMIT_ID
  128. value: 1b2e6669140391d680ff0ca34811ddc2553f15f7
  129. - name: OWN_CONFIG_COMMIT_ID
  130. value: 52a142ca003ade39a0fd96faffbe5334facc3463
  131. envFrom:
  132. <details>
  133. <summary>英文:</summary>
  134. I deployed a python process into a pod of k8. The process makes of a simple logger:
  135. import sys
  136. import logging
  137. import logging.handlers
  138. from pathlib import Path
  139. import coloredlogs
  140. from app.core.config import settings
  141. CONFIG_PATH = Path.joinpath(BASE_PATH, &#39;.configrc&#39;)
  142. LOG_FORMAT = f&#39;%(asctime)s.[{settings.APP_NAME}] %(levelname)s %(message)s&#39;
  143. LOG_LEVEL = settings.dict().get(&#39;LOG_LEVEL&#39;, logging.INFO)
  144. LOGGER = logging.getLogger(__name__)
  145. coloredlogs.install(
  146. level=LOG_LEVEL,
  147. fmt=LOG_FORMAT,
  148. logger=LOGGER)
  149. LOGGER.info(&quot;INFO Creating main objects...&quot;)
  150. However, when I inspect the logs in k8, it always complains that those logs are errors:
  151. ERROR 2023-06-01T13:54:37.742688222Z [resource.labels.containerName: myapp] 2023-06-01 15:54:37.[myapp] INFO Creating main objects...
  152. {
  153. insertId: &quot;8xj2l2hwts2f45gt&quot;
  154. labels: {4}
  155. logName: &quot;projects/proj-iot-poc/logs/stderr&quot;
  156. receiveTimestamp: &quot;2023-06-01T13:54:38.596712564Z&quot;
  157. resource: {2}
  158. severity: &quot;ERROR&quot;
  159. textPayload: &quot;2023-06-01 15:54:37.[myapp] INFO Creating main objects...&quot;
  160. timestamp: &quot;2023-06-01T13:54:37.742688222Z&quot;
  161. }
  162. Not worth to say that I just usedd out `LOGGER.info(&quot;Creating main objects...&quot;)` and I expect the log to be just an INFO not and ERROR...
  163. The manifest is as follows:

apiVersion: apps/v1
kind: Deployment
metadata:
annotations:
deployment.kubernetes.io/revision: "11"
kubectl.kubernetes.io/last-applied-configuration: |
{"apiVersion":"apps/v1","kind":"Deployment","metadata":{"annotations":{},"labels":{"name":"myapp"},"name":"myapp","namespace":"default"},"spec":{"replicas":1,"selector":{"matchLabels":{"app":"myapp"}},"strategy":{"type":"Recreate"},"template":{"metadata":{"labels":{"app":"myapp","version":"1.6.1rc253"}},"spec":{"containers":[{"env":[{"name":"COMMON_CONFIG_COMMIT_ID","value":"1b2e6669140391d680ff0ca34811ddc2553f15f7"},{"name":"OWN_CONFIG_COMMIT_ID","value":"52a142ca003ade39a0fd96faffbe5334facc3463"}],"envFrom":[{"configMapRef":{"name":"myapp-config"}}],"image":"europe-west1-docker.pkg.dev/mycluster/docker-main/myapp:1.6.1rc253","lifecycle":{"preStop":{"exec":{"command":["/bin/bash","-c","sleep 5"]}}},"name":"myapp","resources":null}],"restartPolicy":"Always"}}}}
creationTimestamp: "2023-05-26T07:49:37Z"
generation: 13
labels:
name: myapp
managedFields:

  • apiVersion: apps/v1
    fieldsType: FieldsV1
    fieldsV1:
    f:metadata:
    f:annotations:
    .: {}
    f:kubectl.kubernetes.io/last-applied-configuration: {}
    f:labels:
    .: {}
    f:name: {}
    f:spec:
    f:progressDeadlineSeconds: {}
    f:revisionHistoryLimit: {}
    f:selector: {}
    f:strategy:
    f:type: {}
    f:template:
    f:metadata:
    f:labels:
    .: {}
    f:app: {}
    f:version: {}
    f:spec:
    f:containers:
    k:{"name":"myapp"}:
    .: {}
    f:env:
    .: {}
    k:{"name":"COMMON_CONFIG_COMMIT_ID"}:
    .: {}
    f:name: {}
    f:value: {}
    k:{"name":"OWN_CONFIG_COMMIT_ID"}:
    .: {}
    f:name: {}
    f:value: {}
    f:envFrom: {}
    f:image: {}
    f:imagePullPolicy: {}
    f:lifecycle:
    .: {}
    f:preStop:
    .: {}
    f:exec:
    .: {}
    f:command: {}
    f:name: {}
    f:resources: {}
    f:terminationMessagePath: {}
    f:terminationMessagePolicy: {}
    f:dnsPolicy: {}
    f:restartPolicy: {}
    f:schedulerName: {}
    f:securityContext: {}
    f:terminationGracePeriodSeconds: {}
    manager: kubectl-client-side-apply
    operation: Update
    time: "2023-05-26T07:49:37Z"
  • apiVersion: apps/v1
    fieldsType: FieldsV1
    fieldsV1:
    f:metadata:
    f:annotations:
    f:deployment.kubernetes.io/revision: {}
    f:status:
    f:availableReplicas: {}
    f:conditions:
    .: {}
    k:{"type":"Available"}:
    .: {}
    f:lastTransitionTime: {}
    f:lastUpdateTime: {}
    f:message: {}
    f:reason: {}
    f:status: {}
    f:type: {}
    k:{"type":"Progressing"}:
    .: {}
    f:lastTransitionTime: {}
    f:lastUpdateTime: {}
    f:message: {}
    f:reason: {}
    f:status: {}
    f:type: {}
    f:observedGeneration: {}
    f:readyReplicas: {}
    f:replicas: {}
    f:updatedReplicas: {}
    manager: kube-controller-manager
    operation: Update
    subresource: status
    time: "2023-06-03T06:41:24Z"
    name: myapp
    namespace: default
    resourceVersion: "537412667"
    uid: 375a536e-e39c-4001-a234-e47e812f0bee
    spec:
    progressDeadlineSeconds: 600
    replicas: 1
    revisionHistoryLimit: 10
    selector:
    matchLabels:
    app: myapp
    strategy:
    type: Recreate
    template:
    metadata:
    creationTimestamp: null
    labels:
    app: myapp
    version: 1.6.1rc253
    spec:
    containers:

    • env:
      • name: COMMON_CONFIG_COMMIT_ID
        value: 1b2e6669140391d680ff0ca34811ddc2553f15f7
      • name: OWN_CONFIG_COMMIT_ID
        value: 52a142ca003ade39a0fd96faffbe5334facc3463
        envFrom:
      • configMapRef:
        name: myapp-config
        image: europe-west1-docker.pkg.dev/mycluster/docker-main/myapp:1.6.1rc253
        imagePullPolicy: IfNotPresent
        lifecycle:
        preStop:
        exec:
        command:
        - /bin/bash
        - -c
        - sleep 5
        name: myapp
        resources: {}
        terminationMessagePath: /dev/termination-log
        terminationMessagePolicy: File
        dnsPolicy: ClusterFirst
        restartPolicy: Always
        schedulerName: default-scheduler
        securityContext: {}
        terminationGracePeriodSeconds: 30
        status:
        availableReplicas: 1
        conditions:
  • lastTransitionTime: "2023-05-26T07:49:37Z"
    lastUpdateTime: "2023-06-01T14:33:00Z"
    message: ReplicaSet "myapp-f9bbb5f6d" has successfully progressed.
    reason: NewReplicaSetAvailable
    status: "True"
    type: Progressing
  • lastTransitionTime: "2023-06-03T06:41:24Z"
    lastUpdateTime: "2023-06-03T06:41:24Z"
    message: Deployment has minimum availability.
    reason: MinimumReplicasAvailable
    status: "True"
    type: Available
    observedGeneration: 13
    readyReplicas: 1
    replicas: 1
    updatedReplicas: 1
  1. **EDIT**
  2. Maybe this is realted to:
  3. [GCP and Python Logging][1]
  4. [1]: https://stackoverflow.com/questions/54147483/google-cloud-functions-python-logging-issue
  5. </details>
  6. # 答案1
  7. **得分**: 0
  8. 在网上爬取信息后,我了解到GCP不太方便地支持Python日志记录。最终我编写了自定义的日志记录器:
  9. ```python
  10. """
  11. 通用的具有GCP兼容性的带有颜色的日志记录器
  12. """
  13. import os
  14. import sys
  15. import datetime
  16. import pprint
  17. from typing import TextIO
  18. class CustomLogger:
  19. BLACK = '\033[0;30m'
  20. RED = '\033[0;31m'
  21. GREEN = '\033[0;32m'
  22. BROWN = '\033[0;33m'
  23. BLUE = '\033[0;34m'
  24. PURPLE = '\033[0;35m'
  25. CYAN = '\033[0;36m'
  26. GREY = '\033[0;37m'
  27. DARK_GREY = '\033[1;30m'
  28. LIGHT_RED = '\033[1;31m'
  29. BOLD_RED = "\x1b[31;1m"
  30. LIGHT_GREEN = '\033[1;32m'
  31. YELLOW = '\033[1;33m'
  32. LIGHT_BLUE = '\033[1;34m'
  33. LIGHT_PURPLE = '\033[1;35m'
  34. LIGHT_CYAN = '\033[1;36m'
  35. WHITE = '\033[1;37m'
  36. RESET = "\033[0m"
  37. def __init__(self, fmt: str = ""):
  38. self.fmt = f"%(asctime).[{os.getenv('APP_NAME')}] %(levelname) %(message)"
  39. self.terminal_type = os.getenv('TERM') or ""
  40. def debug(self, message: str = ""):
  41. out = self.__format(message)
  42. self.sprint(self.DARK_GREY, message=out)
  43. def warning(self, message: str = ""):
  44. out = self.__format(message)
  45. self.sprint(self.CYAN, message=out)
  46. def info(self, message: str = ""):
  47. out = self.__format(message, 'INFO')
  48. self.sprint(self.GREEN, message=out)
  49. def critical(self, message: str = ""):
  50. out = self.__format(message, 'CRITICAL')
  51. self.sprint(self.BOLD_RED, message=out, file=sys.stderr)
  52. def exception(self, message: str = ""):
  53. out = self.__format(message, 'CRITICAL')
  54. self.sprint(self.LIGHT_RED, message=out, file=sys.stderr)
  55. def error(self, message: str = ""):
  56. out = self.__format(message, 'ERROR')
  57. self.sprint(self.RED, message=out, file=sys.stderr)
  58. def __format(self, message, level: str = ""):
  59. now = datetime.datetime.now().strftime('%Y-%m-%dT%H:%M')
  60. message = pprint.pformat(message)
  61. return self.fmt.replace("%(message)", message).\
  62. replace("%(asctime)", now).\
  63. replace("%(levelname)", level)
  64. def sprint(self, color, message, file: TextIO = sys.stdout):
  65. if 'xterm' in self.terminal_type:
  66. print(color + message + self.RESET)
  67. else:
  68. print(message)
  69. LOGGER = CustomLogger()

省略了一些代码优化部分。

英文:

After scraping the web, I understood that GCP does not support the logging python painlessy.
I ended up writing my custom logger:

  1. &quot;&quot;&quot;
  2. General colorized Logger compatible with GCP
  3. &quot;&quot;&quot;
  4. import os
  5. import sys
  6. import datetime
  7. import pprint
  8. from typing import TextIO
  9. class CustomLogger:
  10. BLACK = &#39;\033[0;30m&#39;
  11. RED = &#39;\033[0;31m&#39;
  12. GREEN = &#39;\033[0;32m&#39;
  13. BROWN = &#39;\033[0;33m&#39;
  14. BLUE = &#39;\033[0;34m&#39;
  15. PURPLE = &#39;\033[0;35m&#39;
  16. CYAN = &#39;\033[0;36m&#39;
  17. GREY = &#39;\033[0;37m&#39;
  18. DARK_GREY = &#39;\033[1;30m&#39;
  19. LIGHT_RED = &#39;\033[1;31m&#39;
  20. BOLD_RED = &quot;\x1b[31;1m&quot;
  21. LIGHT_GREEN = &#39;\033[1;32m&#39;
  22. YELLOW = &#39;\033[1;33m&#39;
  23. LIGHT_BLUE = &#39;\033[1;34m&#39;
  24. LIGHT_PURPLE = &#39;\033[1;35m&#39;
  25. LIGHT_CYAN = &#39;\033[1;36m&#39;
  26. WHITE = &#39;\033[1;37m&#39;
  27. RESET = &quot;\033[0m&quot;
  28. pippo = &quot;1&quot;
  29. def __init__(self, fmt: str = &quot;&quot;):
  30. self.fmt = f&quot;%(asctime).[{os.getenv(&#39;APP_NAME&#39;)] %(levelname) %(message)&quot;
  31. self.terminal_type = os.getenv(&#39;TERM&#39;) or &quot;&quot;
  32. def debug(self, message: str = &quot;&quot;):
  33. out = self.__format(message)
  34. self.sprint(self.DARK_GREY, message=out)
  35. def warning(self, message: str = &quot;&quot;):
  36. out = self.__format(message)
  37. self.sprint(self.CYAN, message=out)
  38. def info(self, message: str = &quot;&quot;):
  39. out = self.__format(message, &#39;INFO&#39;)
  40. self.sprint(self.GREEN, message=out)
  41. def critical(self, message: str = &quot;&quot;):
  42. out = self.__format(message, &#39;CRITICAL&#39;)
  43. self.sprint(self.BOLD_RED, message=out, file=sys.stderr)
  44. def exception(self, message: str = &quot;&quot;):
  45. out = self.__format(message, &#39;CRITICAL&#39;)
  46. self.sprint(self.LIGHT_RED, message=out, file=sys.stderr)
  47. def error(self, message: str = &quot;&quot;):
  48. out = self.__format(message, &#39;ERROR&#39;)
  49. self.sprint(self.RED, message=out, file=sys.stderr)
  50. def __format(self, message, level: str = &quot;&quot;):
  51. now = datetime.datetime.now().strftime(&#39;%Y-%m-%dT%H:%M&#39;)
  52. message = pprint.pformat(message)
  53. return self.fmt.replace(&quot;%(message)&quot;, message).\
  54. replace(&quot;%(asctime)&quot;, now).\
  55. replace(&quot;%(levelname)&quot;, level)
  56. def sprint(self, color, message, file: TextIO = sys.stdout):
  57. if &#39;xterm&#39; in self.terminal_type:
  58. print(color + message + self.RESET)
  59. else:
  60. print(message)
  61. LOGGER = CustomLogger()

Some code optimization omitted.

huangapple
  • 本文由 发表于 2023年6月1日 22:18:45
  • 转载请务必保留本文链接:https://go.coder-hub.com/76382889.html
匿名

发表评论

匿名网友

:?: :razz: :sad: :evil: :!: :smile: :oops: :grin: :eek: :shock: :???: :cool: :lol: :mad: :twisted: :roll: :wink: :idea: :arrow: :neutral: :cry: :mrgreen:

确定