Coverage for an_website/utils/logging.py: 35.849%

1# This program is free software: you can redistribute it and/or modify 

2# it under the terms of the GNU Affero General Public License as 

3# published by the Free Software Foundation, either version 3 of the 

4# License, or (at your option) any later version. 

5# 

6# This program is distributed in the hope that it will be useful, 

7# but WITHOUT ANY WARRANTY; without even the implied warranty of 

8# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the 

9# GNU Affero General Public License for more details. 

10# 

11# You should have received a copy of the GNU Affero General Public License 

12# along with this program. If not, see <https://www.gnu.org/licenses/>. 

13 

14"""Logging stuff used by the website.""" 

15 

16from __future__ import annotations 

17 

18import asyncio 

19import logging 

20import traceback 

21from asyncio import AbstractEventLoop 

22from collections.abc import Callable, Coroutine, Iterable 

23from concurrent.futures import Future 

24from datetime import datetime, tzinfo 

25from logging import LogRecord 

26from pathlib import Path 

27from typing import Never 

28 

29import orjson as json 

30from tornado.httpclient import AsyncHTTPClient 

31 

32from an_website import DIR as AN_WEBSITE_DIR 

33 

34from .. import CA_BUNDLE_PATH 

35 

36HOME: str = Path("~/").expanduser().as_posix().rstrip("/") 

37 

38 

39def minify_filepath(path: str) -> str: 

40 """Make a filepath smaller.""" 

41 if path.startswith(f"{HOME}/"): 

42 return "~" + path.removeprefix(HOME) 

43 return path 

44 

45 

46def get_minimal_traceback( 

47 record: LogRecord, prefix: str = "\n\n" 

48) -> Iterable[str]: 

49 """Get a minimal traceback from the log record.""" 

50 if not record.exc_info: 

51 return 

52 (_, value, tb) = record.exc_info 

53 if not (value and tb): 

54 return 

55 

56 yield prefix 

57 yield from traceback.format_exception(value, limit=0) 

58 

59 summary = traceback.extract_tb(tb) 

60 if isinstance(AN_WEBSITE_DIR, Path): 

61 start_path = f"{str(AN_WEBSITE_DIR).rstrip('/')}/" 

62 

63 for i in reversed(range(len(summary))): 

64 if summary[i].filename.startswith(start_path): 

65 summary = traceback.StackSummary(summary[i:]) 

66 break 

67 

68 for frame in summary: 

69 frame.filename = minify_filepath(frame.filename) 

70 

71 yield from summary.format() 

72 

73 

74class AsyncHandler(logging.Handler): 

75 """A logging handler that can handle log records asynchronously.""" 

76 

77 futures: set[Future[object]] 

78 loop: AbstractEventLoop 

79 

80 def __init__( 

81 self, 

82 level: int | str = logging.NOTSET, 

83 *, 

84 loop: AbstractEventLoop, 

85 ): 

86 """Initialize the handler.""" 

87 super().__init__(level=level) 

88 self.futures = set() 

89 self.loop = loop 

90 

91 def callback(self, future: Future[object]) -> None: 

92 """Remove the reference to the future from the handler.""" 

93 self.acquire() 

94 try: 

95 self.futures.discard(future) 

96 finally: 

97 self.release() 

98 

99 def emit( # type: ignore[override] 

100 self, record: LogRecord 

101 ) -> None | Coroutine[None, Never, object]: 

102 """ 

103 Do whatever it takes to actually log the specified logging record. 

104 

105 This version is intended to be implemented by subclasses and so 

106 raises a NotImplementedError. 

107 """ 

108 raise NotImplementedError( 

109 "emit must be implemented by AsyncHandler subclasses" 

110 ) 

111 

112 def handle( # type: ignore[override] 

113 self, record: LogRecord 

114 ) -> bool | LogRecord: 

115 """Handle incoming log records.""" 

116 rv = self.filter(record) 

117 if isinstance(rv, LogRecord): 

118 record = rv 

119 if rv and not self.loop.is_closed(): 

120 self.acquire() 

121 try: 

122 if awaitable := self.emit(record): 

123 future: Future[object] = asyncio.run_coroutine_threadsafe( 

124 awaitable, self.loop 

125 ) 

126 self.futures.add(future) 

127 future.add_done_callback(self.callback) 

128 finally: 

129 self.release() 

130 return rv 

131 

132 

133class DatetimeFormatter(logging.Formatter): 

134 """A logging formatter that formats the time using datetime.""" 

135 

136 timezone: None | tzinfo = None 

137 

138 def formatTime( # noqa: N802 

139 self, record: LogRecord, datefmt: None | str = None 

140 ) -> str: 

141 """Return the creation time of the LogRecord as formatted text.""" 

142 spam = datetime.fromtimestamp(record.created).astimezone(self.timezone) 

143 if datefmt: 

144 return spam.strftime(datefmt) 

145 return spam.isoformat() 

146 

147 

148class WebhookFormatter(DatetimeFormatter): 

149 """A logging formatter optimized for logging to a webhook.""" 

150 

151 escape_message = False 

152 max_message_length: int | None = None 

153 get_context_line: Callable[[LogRecord], str | None] | None = None 

154 

155 def format(self, record: LogRecord) -> str: 

156 """Format the specified record as text.""" 

157 record.message = record.getMessage() 

158 if self.usesTime(): 

159 record.asctime = self.formatTime(record, self.datefmt) 

160 if ( 

161 self.max_message_length is not None 

162 and len(record.message) > self.max_message_length 

163 ): 

164 record.message = record.message[: self.max_message_length] 

165 for line in get_minimal_traceback(record): 

166 if ( 

167 self.max_message_length is not None 

168 and len(line) + len(record.message) > self.max_message_length 

169 ): 

170 ellipsis = "…" 

171 if ( 

172 len(ellipsis) + len(record.message) 

173 <= self.max_message_length 

174 ): 

175 record.message += ellipsis 

176 break 

177 record.message += line 

178 if ( 

179 self.get_context_line 

180 and (context_line := self.get_context_line(record)) 

181 and ( 

182 (len(record.message) + 2 + len(context_line)) 

183 <= self.max_message_length 

184 if self.max_message_length 

185 else True 

186 ) 

187 ): 

188 record.message += f"\n\n{context_line}" 

189 if self.escape_message: 

190 record.message = json.dumps(record.message).decode("UTF-8")[1:-1] 

191 return self.formatMessage(record) 

192 

193 

194class WebhookHandler(AsyncHandler): 

195 """A logging handler that sends logs to a webhook.""" 

196 

197 url: str 

198 content_type: str 

199 

200 def __init__( 

201 self, 

202 level: int | str = logging.NOTSET, 

203 *, 

204 loop: AbstractEventLoop, 

205 url: str, 

206 content_type: str, 

207 ): 

208 """Initialize the handler.""" 

209 super().__init__(level=level, loop=loop) 

210 self.url = url 

211 self.content_type = content_type 

212 

213 async def emit(self, record: LogRecord) -> None: # type: ignore[override] 

214 """Send the request to the webhook.""" 

215 # pylint: disable=invalid-overridden-method 

216 try: 

217 message = self.format(record) 

218 await AsyncHTTPClient().fetch( 

219 self.url, 

220 method="POST", 

221 headers={"Content-Type": self.content_type}, 

222 body=message.strip(), 

223 ca_certs=CA_BUNDLE_PATH, 

224 ) 

225 except Exception: # pylint: disable=broad-except 

226 self.handleError(record)