]> git.openstreetmap.org Git - nominatim.git/blob - nominatim/api/logging.py
Merge pull request #3383 from lonvia/window-searches
[nominatim.git] / nominatim / api / logging.py
1 # SPDX-License-Identifier: GPL-3.0-or-later
2 #
3 # This file is part of Nominatim. (https://nominatim.org)
4 #
5 # Copyright (C) 2023 by the Nominatim developer community.
6 # For a full list of authors see the git log.
7 """
8 Functions for specialised logging with HTML output.
9 """
10 from typing import Any, Iterator, Optional, List, Tuple, cast, Union, Mapping, Sequence
11 from contextvars import ContextVar
12 import datetime as dt
13 import textwrap
14 import io
15 import re
16 import html
17
18 import sqlalchemy as sa
19 from sqlalchemy.ext.asyncio import AsyncConnection
20
21 try:
22     from pygments import highlight
23     from pygments.lexers import PythonLexer, PostgresLexer
24     from pygments.formatters import HtmlFormatter
25     CODE_HIGHLIGHT = True
26 except ModuleNotFoundError:
27     CODE_HIGHLIGHT = False
28
29
30 def _debug_name(res: Any) -> str:
31     if res.names:
32         return cast(str, res.names.get('name', next(iter(res.names.values()))))
33
34     return f"Hnr {res.housenumber}" if res.housenumber is not None else '[NONE]'
35
36
37 class BaseLogger:
38     """ Interface for logging function.
39
40         The base implementation does nothing. Overwrite the functions
41         in derived classes which implement logging functionality.
42     """
43     def get_buffer(self) -> str:
44         """ Return the current content of the log buffer.
45         """
46         return ''
47
48     def function(self, func: str, **kwargs: Any) -> None:
49         """ Start a new debug chapter for the given function and its parameters.
50         """
51
52
53     def section(self, heading: str) -> None:
54         """ Start a new section with the given title.
55         """
56
57
58     def comment(self, text: str) -> None:
59         """ Add a simple comment to the debug output.
60         """
61
62
63     def var_dump(self, heading: str, var: Any) -> None:
64         """ Print the content of the variable to the debug output prefixed by
65             the given heading.
66         """
67
68
69     def table_dump(self, heading: str, rows: Iterator[Optional[List[Any]]]) -> None:
70         """ Print the table generated by the generator function.
71         """
72
73
74     def result_dump(self, heading: str, results: Iterator[Tuple[Any, Any]]) -> None:
75         """ Print a list of search results generated by the generator function.
76         """
77
78
79     def sql(self, conn: AsyncConnection, statement: 'sa.Executable',
80             params: Union[Mapping[str, Any], Sequence[Mapping[str, Any]], None]) -> None:
81         """ Print the SQL for the given statement.
82         """
83
84     def format_sql(self, conn: AsyncConnection, statement: 'sa.Executable',
85                    extra_params: Union[Mapping[str, Any],
86                                  Sequence[Mapping[str, Any]], None]) -> str:
87         """ Return the compiled version of the statement.
88         """
89         compiled = cast('sa.ClauseElement', statement).compile(conn.sync_engine)
90
91         params = dict(compiled.params)
92         if isinstance(extra_params, Mapping):
93             for k, v in extra_params.items():
94                 if hasattr(v, 'to_wkt'):
95                     params[k] = v.to_wkt()
96                 elif isinstance(v, (int, float)):
97                     params[k] = v
98                 else:
99                     params[k] = str(v)
100         elif isinstance(extra_params, Sequence) and extra_params:
101             for k in extra_params[0]:
102                 params[k] = f':{k}'
103
104         sqlstr = str(compiled)
105
106         if conn.dialect.name == 'postgresql':
107             if sa.__version__.startswith('1'):
108                 try:
109                     sqlstr = re.sub(r'__\[POSTCOMPILE_[^]]*\]', '%s', sqlstr)
110                     return sqlstr % tuple((repr(params.get(name, None))
111                                           for name in compiled.positiontup)) # type: ignore
112                 except TypeError:
113                     return sqlstr
114
115             # Fixes an odd issue with Python 3.7 where percentages are not
116             # quoted correctly.
117             sqlstr = re.sub(r'%(?!\()', '%%', sqlstr)
118             sqlstr = re.sub(r'__\[POSTCOMPILE_([^]]*)\]', r'%(\1)s', sqlstr)
119             return sqlstr % params
120
121         assert conn.dialect.name == 'sqlite'
122
123         # params in positional order
124         pparams = (repr(params.get(name, None)) for name in compiled.positiontup) # type: ignore
125
126         sqlstr = re.sub(r'__\[POSTCOMPILE_([^]]*)\]', '?', sqlstr)
127         sqlstr = re.sub(r"\?", lambda m: next(pparams), sqlstr)
128
129         return sqlstr
130
131 class HTMLLogger(BaseLogger):
132     """ Logger that formats messages in HTML.
133     """
134     def __init__(self) -> None:
135         self.buffer = io.StringIO()
136
137
138     def _timestamp(self) -> None:
139         self._write(f'<p class="timestamp">[{dt.datetime.now()}]</p>')
140
141
142     def get_buffer(self) -> str:
143         return HTML_HEADER + self.buffer.getvalue() + HTML_FOOTER
144
145
146     def function(self, func: str, **kwargs: Any) -> None:
147         self._timestamp()
148         self._write(f"<h1>Debug output for {func}()</h1>\n<p>Parameters:<dl>")
149         for name, value in kwargs.items():
150             self._write(f'<dt>{name}</dt><dd>{self._python_var(value)}</dd>')
151         self._write('</dl></p>')
152
153
154     def section(self, heading: str) -> None:
155         self._timestamp()
156         self._write(f"<h2>{heading}</h2>")
157
158
159     def comment(self, text: str) -> None:
160         self._timestamp()
161         self._write(f"<p>{text}</p>")
162
163
164     def var_dump(self, heading: str, var: Any) -> None:
165         self._timestamp()
166         if callable(var):
167             var = var()
168
169         self._write(f'<h5>{heading}</h5>{self._python_var(var)}')
170
171
172     def table_dump(self, heading: str, rows: Iterator[Optional[List[Any]]]) -> None:
173         self._timestamp()
174         head = next(rows)
175         assert head
176         self._write(f'<table><thead><tr><th colspan="{len(head)}">{heading}</th></tr><tr>')
177         for cell in head:
178             self._write(f'<th>{cell}</th>')
179         self._write('</tr></thead><tbody>')
180         for row in rows:
181             if row is not None:
182                 self._write('<tr>')
183                 for cell in row:
184                     self._write(f'<td>{cell}</td>')
185                 self._write('</tr>')
186         self._write('</tbody></table>')
187
188
189     def result_dump(self, heading: str, results: Iterator[Tuple[Any, Any]]) -> None:
190         """ Print a list of search results generated by the generator function.
191         """
192         self._timestamp()
193         def format_osm(osm_object: Optional[Tuple[str, int]]) -> str:
194             if not osm_object:
195                 return '-'
196
197             t, i = osm_object
198             if t == 'N':
199                 fullt = 'node'
200             elif t == 'W':
201                 fullt = 'way'
202             elif t == 'R':
203                 fullt = 'relation'
204             else:
205                 return f'{t}{i}'
206
207             return f'<a href="https://www.openstreetmap.org/{fullt}/{i}">{t}{i}</a>'
208
209         self._write(f'<h5>{heading}</h5><p><dl>')
210         total = 0
211         for rank, res in results:
212             self._write(f'<dt>[{rank:.3f}]</dt>  <dd>{res.source_table.name}(')
213             self._write(f"{_debug_name(res)}, type=({','.join(res.category)}), ")
214             self._write(f"rank={res.rank_address}, ")
215             self._write(f"osm={format_osm(res.osm_object)}, ")
216             self._write(f'cc={res.country_code}, ')
217             self._write(f'importance={res.importance or float("nan"):.5f})</dd>')
218             total += 1
219         self._write(f'</dl><b>TOTAL:</b> {total}</p>')
220
221
222     def sql(self, conn: AsyncConnection, statement: 'sa.Executable',
223             params: Union[Mapping[str, Any], Sequence[Mapping[str, Any]], None]) -> None:
224         self._timestamp()
225         sqlstr = self.format_sql(conn, statement, params)
226         if CODE_HIGHLIGHT:
227             sqlstr = highlight(sqlstr, PostgresLexer(),
228                                HtmlFormatter(nowrap=True, lineseparator='<br />'))
229             self._write(f'<div class="highlight"><code class="lang-sql">{sqlstr}</code></div>')
230         else:
231             self._write(f'<code class="lang-sql">{html.escape(sqlstr)}</code>')
232
233
234     def _python_var(self, var: Any) -> str:
235         if CODE_HIGHLIGHT:
236             fmt = highlight(str(var), PythonLexer(), HtmlFormatter(nowrap=True))
237             return f'<div class="highlight"><code class="lang-python">{fmt}</code></div>'
238
239         return f'<code class="lang-python">{html.escape(str(var))}</code>'
240
241
242     def _write(self, text: str) -> None:
243         """ Add the raw text to the debug output.
244         """
245         self.buffer.write(text)
246
247
248 class TextLogger(BaseLogger):
249     """ Logger creating output suitable for the console.
250     """
251     def __init__(self) -> None:
252         self.buffer = io.StringIO()
253
254
255     def _timestamp(self) -> None:
256         self._write(f'[{dt.datetime.now()}]\n')
257
258
259     def get_buffer(self) -> str:
260         return self.buffer.getvalue()
261
262
263     def function(self, func: str, **kwargs: Any) -> None:
264         self._write(f"#### Debug output for {func}()\n\nParameters:\n")
265         for name, value in kwargs.items():
266             self._write(f'  {name}: {self._python_var(value)}\n')
267         self._write('\n')
268
269
270     def section(self, heading: str) -> None:
271         self._timestamp()
272         self._write(f"\n# {heading}\n\n")
273
274
275     def comment(self, text: str) -> None:
276         self._write(f"{text}\n")
277
278
279     def var_dump(self, heading: str, var: Any) -> None:
280         if callable(var):
281             var = var()
282
283         self._write(f'{heading}:\n  {self._python_var(var)}\n\n')
284
285
286     def table_dump(self, heading: str, rows: Iterator[Optional[List[Any]]]) -> None:
287         self._write(f'{heading}:\n')
288         data = [list(map(self._python_var, row)) if row else None for row in rows]
289         assert data[0] is not None
290         num_cols = len(data[0])
291
292         maxlens = [max(len(d[i]) for d in data if d) for i in range(num_cols)]
293         tablewidth = sum(maxlens) + 3 * num_cols + 1
294         row_format = '| ' +' | '.join(f'{{:<{l}}}' for l in maxlens) + ' |\n'
295         self._write('-'*tablewidth + '\n')
296         self._write(row_format.format(*data[0]))
297         self._write('-'*tablewidth + '\n')
298         for row in data[1:]:
299             if row:
300                 self._write(row_format.format(*row))
301             else:
302                 self._write('-'*tablewidth + '\n')
303         if data[-1]:
304             self._write('-'*tablewidth + '\n')
305
306
307     def result_dump(self, heading: str, results: Iterator[Tuple[Any, Any]]) -> None:
308         self._timestamp()
309         self._write(f'{heading}:\n')
310         total = 0
311         for rank, res in results:
312             self._write(f'[{rank:.3f}]  {res.source_table.name}(')
313             self._write(f"{_debug_name(res)}, type=({','.join(res.category)}), ")
314             self._write(f"rank={res.rank_address}, ")
315             self._write(f"osm={''.join(map(str, res.osm_object or []))}, ")
316             self._write(f'cc={res.country_code}, ')
317             self._write(f'importance={res.importance or -1:.5f})\n')
318             total += 1
319         self._write(f'TOTAL: {total}\n\n')
320
321
322     def sql(self, conn: AsyncConnection, statement: 'sa.Executable',
323             params: Union[Mapping[str, Any], Sequence[Mapping[str, Any]], None]) -> None:
324         self._timestamp()
325         sqlstr = '\n| '.join(textwrap.wrap(self.format_sql(conn, statement, params), width=78))
326         self._write(f"| {sqlstr}\n\n")
327
328
329     def _python_var(self, var: Any) -> str:
330         return str(var)
331
332
333     def _write(self, text: str) -> None:
334         self.buffer.write(text)
335
336
337 logger: ContextVar[BaseLogger] = ContextVar('logger', default=BaseLogger())
338
339
340 def set_log_output(fmt: str) -> None:
341     """ Enable collecting debug information.
342     """
343     if fmt == 'html':
344         logger.set(HTMLLogger())
345     elif fmt == 'text':
346         logger.set(TextLogger())
347     else:
348         logger.set(BaseLogger())
349
350
351 def log() -> BaseLogger:
352     """ Return the logger for the current context.
353     """
354     return logger.get()
355
356
357 def get_and_disable() -> str:
358     """ Return the current content of the debug buffer and disable logging.
359     """
360     buf = logger.get().get_buffer()
361     logger.set(BaseLogger())
362     return buf
363
364
365 HTML_HEADER: str = """<!DOCTYPE html>
366 <html>
367 <head>
368   <title>Nominatim - Debug</title>
369   <style>
370 """ + \
371 (HtmlFormatter(nobackground=True).get_style_defs('.highlight') if CODE_HIGHLIGHT else '') +\
372 """
373     h2 { font-size: x-large }
374
375     dl {
376       padding-left: 10pt;
377       font-family: monospace
378     }
379
380     dt {
381       float: left;
382       font-weight: bold;
383       margin-right: 0.5em
384     }
385
386     dt::after { content: ": "; }
387
388     dd::after {
389       clear: left;
390       display: block
391     }
392
393     .lang-sql {
394       color: #555;
395       font-size: small
396     }
397
398     h5 {
399         border: solid lightgrey 0.1pt;
400         margin-bottom: 0;
401         background-color: #f7f7f7
402     }
403
404     h5 + .highlight {
405         padding: 3pt;
406         border: solid lightgrey 0.1pt
407     }
408
409     table, th, tbody {
410         border: thin solid;
411         border-collapse: collapse;
412     }
413     td {
414         border-right: thin solid;
415         padding-left: 3pt;
416         padding-right: 3pt;
417     }
418
419     .timestamp {
420         font-size: 0.8em;
421         color: darkblue;
422         width: calc(100% - 5pt);
423         text-align: right;
424         position: absolute;
425         left: 0;
426         margin-top: -5px;
427     }
428   </style>
429 </head>
430 <body>
431 """
432
433 HTML_FOOTER: str = "</body></html>"