Coverage for /builds/BuildGrid/buildgrid/buildgrid/server/logging.py: 100.00%

1# Copyright (C) 2024 Bloomberg LP 

2# 

3# Licensed under the Apache License, Version 2.0 (the "License"); 

4# you may not use this file except in compliance with the License. 

5# You may obtain a copy of the License at 

6# 

7# <http://www.apache.org/licenses/LICENSE-2.0> 

8# 

9# Unless required by applicable law or agreed to in writing, software 

10# distributed under the License is distributed on an "AS IS" BASIS, 

11# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. 

12# See the License for the specific language governing permissions and 

13# limitations under the License. 

14 

15import json 

16import logging 

17from enum import Enum 

18from types import TracebackType 

19from typing import Any, Union 

20 

21from google.protobuf import text_format 

22from google.protobuf.message import Message 

23 

24from buildgrid._protos.build.bazel.remote.execution.v2.remote_execution_pb2 import Digest 

25from buildgrid.server.settings import LOG_RECORD_FORMAT 

26from buildgrid.server.version import __version__ 

27 

28Exc = Union[ 

29 bool, 

30 tuple[type[BaseException], BaseException, TracebackType | None], 

31 tuple[None, None, None], 

32 BaseException, 

33] 

34 

35Tags = dict[str, Any] 

36 

37 

38def _str_escape(s: str) -> str: 

39 return str(s).replace('"', r"\"") 

40 

41 

42def _format_log_tag_value(value: Any) -> Any: 

43 if value is None: 

44 return '""' 

45 elif isinstance(value, int): 

46 return value 

47 elif isinstance(value, float): 

48 return f"{value:.2f}" 

49 elif isinstance(value, Digest): 

50 return f'"{value.hash}/{value.size_bytes}"' 

51 elif isinstance(value, Message): 

52 return f'"{_str_escape(text_format.MessageToString(value, as_one_line=True))}"' 

53 elif isinstance(value, Enum): 

54 return value.name 

55 else: 

56 return f'"{_str_escape(value)}"' 

57 

58 

59def _json_format_log_tag_value(value: Any) -> Any: 

60 if value is None: 

61 return "" 

62 elif isinstance(value, int): 

63 return value 

64 elif isinstance(value, float): 

65 return f"{value:.2f}" 

66 elif isinstance(value, Digest): 

67 return f"{value.hash}/{value.size_bytes}" 

68 elif isinstance(value, Message): 

69 return f"{text_format.MessageToString(value, as_one_line=True)}" 

70 elif isinstance(value, Enum): 

71 return value.name 

72 else: 

73 return f"{value}" 

74 

75 

76def _format_log_tags(tags: Tags | None) -> str: 

77 if not tags: 

78 return "" 

79 return "".join([f" {key}={_format_log_tag_value(value)}" for key, value in sorted(tags.items())]) 

80 

81 

82def _format_message(record: logging.LogRecord) -> str: 

83 # LOG_RECORD_FORMAT should still be used for the message field 

84 msg_formatter = logging.Formatter(LOG_RECORD_FORMAT) 

85 return msg_formatter.format(record) 

86 

87 

88class JSONFormatter(logging.Formatter): 

89 def format(self, record: logging.LogRecord) -> str: 

90 log_record = { 

91 "date": self.formatTime(record), 

92 "message": _format_message(record), 

93 "log_level": record.levelname, 

94 "logger_name": record.name, 

95 "request_id": getattr(record, "request_id", ""), 

96 "bgd_version": __version__, 

97 } 

98 

99 if record_tags := getattr(record, "tags", {}): 

100 tags = {} 

101 for tag, tag_value in record_tags.items(): 

102 if tag in log_record.keys(): 

103 tag = "tag_" + tag 

104 tags[tag] = _json_format_log_tag_value(tag_value) 

105 log_record.update(tags) 

106 

107 return json.dumps(log_record) 

108 

109 

110class BuildgridLogger: 

111 def __init__(self, logger: logging.Logger) -> None: 

112 """ 

113 The buildgrid logger is a helper utility wrapped around a standard logger instance. 

114 It allows placing key=value strings at the end of log lines, reducing boilerplate in 

115 displaying values and adding standardization to our log lines. Within each logging method, 

116 tags may be added by setting the "tags" argument. 

117 

118 Each logger is set to log at stacklevel=2 such that function names and source line numbers 

119 show the line at which this utility is invoked. 

120 

121 Special encoding rules for tag values: 

122 - int: reported as is. `value=1` 

123 - float: rounded to the nearest two decimals. `value=1.23` 

124 - Digest: unpacked as hash/size. `value=deadbeef/123` 

125 - proto.Message: text_format, escaped, and quoted. `value="blob_digests { hash: \"deadbeef\" }"` 

126 - Enum: attribute name is used. `value=OK` 

127 - others: converted to str, escaped, and quoted. `value="foo: \"bar\""` 

128 

129 Encoding is only performed if logging is enabled for that level. 

130 """ 

131 self._logger = logger 

132 

133 def is_enabled_for(self, level: int) -> bool: 

134 return self._logger.isEnabledFor(level) 

135 

136 def debug(self, msg: Any, *, exc_info: Exc | None = None, tags: Tags | None = None) -> None: 

137 if self._logger.isEnabledFor(logging.DEBUG): 

138 self._logger.debug( 

139 str(msg) + _format_log_tags(tags), extra={"tags": tags or {}}, exc_info=exc_info, stacklevel=2 

140 ) 

141 

142 def info(self, msg: Any, *, exc_info: Exc | None = None, tags: Tags | None = None) -> None: 

143 if self._logger.isEnabledFor(logging.INFO): 

144 self._logger.info( 

145 str(msg) + _format_log_tags(tags), extra={"tags": tags or {}}, exc_info=exc_info, stacklevel=2 

146 ) 

147 

148 def warning(self, msg: Any, *, exc_info: Exc | None = None, tags: Tags | None = None) -> None: 

149 if self._logger.isEnabledFor(logging.WARNING): 

150 self._logger.warning( 

151 str(msg) + _format_log_tags(tags), extra={"tags": tags or {}}, exc_info=exc_info, stacklevel=2 

152 ) 

153 

154 def error(self, msg: Any, *, exc_info: Exc | None = None, tags: Tags | None = None) -> None: 

155 if self._logger.isEnabledFor(logging.ERROR): 

156 self._logger.error( 

157 str(msg) + _format_log_tags(tags), extra={"tags": tags or {}}, exc_info=exc_info, stacklevel=2 

158 ) 

159 

160 def exception(self, msg: Any, *, exc_info: Exc | None = True, tags: Tags | None = None) -> None: 

161 if self._logger.isEnabledFor(logging.ERROR): 

162 # Note we call error here instead of exception. 

163 # logger.exception is a helper around calling error with exc_info defaulting to True. 

164 # On python<3.11 that helper causes the stacklevel to report incorrectly. 

165 self._logger.error( 

166 str(msg) + _format_log_tags(tags), extra={"tags": tags or {}}, exc_info=exc_info, stacklevel=2 

167 ) 

168 

169 

170def buildgrid_logger(name: str) -> BuildgridLogger: 

171 return BuildgridLogger(logging.getLogger(name))