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
  11 from contextvars import ContextVar
  12 import textwrap
  13 import io
  14
  15 import sqlalchemy as sa
  16 from sqlalchemy.ext.asyncio import AsyncConnection
  17
  18 try:
  19     from pygments import highlight
  20     from pygments.lexers import PythonLexer, PostgresLexer
  21     from pygments.formatters import HtmlFormatter
  22     CODE_HIGHLIGHT = True
  23 except ModuleNotFoundError:
  24     CODE_HIGHLIGHT = False
  25
  26
  27 def _debug_name(res: Any) -> str:
  28     if res.names:
  29         return cast(str, res.names.get('name', next(iter(res.names.values()))))
  30
  31     return f"Hnr {res.housenumber}" if res.housenumber is not None else '[NONE]'
  32
  33
  34 class BaseLogger:
  35     """ Interface for logging function.
  36
  37         The base implementation does nothing. Overwrite the functions
  38         in derived classes which implement logging functionality.
  39     """
  40     def get_buffer(self) -> str:
  41         """ Return the current content of the log buffer.
  42         """
  43         return ''
  44
  45     def function(self, func: str, **kwargs: Any) -> None:
  46         """ Start a new debug chapter for the given function and its parameters.
  47         """
  48
  49
  50     def section(self, heading: str) -> None:
  51         """ Start a new section with the given title.
  52         """
  53
  54
  55     def comment(self, text: str) -> None:
  56         """ Add a simple comment to the debug output.
  57         """
  58
  59
  60     def var_dump(self, heading: str, var: Any) -> None:
  61         """ Print the content of the variable to the debug output prefixed by
  62             the given heading.
  63         """
  64
  65
  66     def table_dump(self, heading: str, rows: Iterator[Optional[List[Any]]]) -> None:
  67         """ Print the table generated by the generator function.
  68         """
  69
  70
  71     def result_dump(self, heading: str, results: Iterator[Tuple[Any, Any]]) -> None:
  72         """ Print a list of search results generated by the generator function.
  73         """
  74
  75
  76     def sql(self, conn: AsyncConnection, statement: 'sa.Executable') -> None:
  77         """ Print the SQL for the given statement.
  78         """
  79
  80     def format_sql(self, conn: AsyncConnection, statement: 'sa.Executable') -> str:
  81         """ Return the comiled version of the statement.
  82         """
  83         try:
  84             return str(cast('sa.ClauseElement', statement)
  85                          .compile(conn.sync_engine, compile_kwargs={"literal_binds": True}))
  86         except sa.exc.CompileError:
  87             pass
  88         except NotImplementedError:
  89             pass
  90
  91         return str(cast('sa.ClauseElement', statement).compile(conn.sync_engine))
  92
  93
  94 class HTMLLogger(BaseLogger):
  95     """ Logger that formats messages in HTML.
  96     """
  97     def __init__(self) -> None:
  98         self.buffer = io.StringIO()
  99
 100
 101     def get_buffer(self) -> str:
 102         return HTML_HEADER + self.buffer.getvalue() + HTML_FOOTER
 103
 104
 105     def function(self, func: str, **kwargs: Any) -> None:
 106         self._write(f"<h1>Debug output for {func}()</h1>\n<p>Parameters:<dl>")
 107         for name, value in kwargs.items():
 108             self._write(f'<dt>{name}</dt><dd>{self._python_var(value)}</dd>')
 109         self._write('</dl></p>')
 110
 111
 112     def section(self, heading: str) -> None:
 113         self._write(f"<h2>{heading}</h2>")
 114
 115
 116     def comment(self, text: str) -> None:
 117         self._write(f"<p>{text}</p>")
 118
 119
 120     def var_dump(self, heading: str, var: Any) -> None:
 121         if callable(var):
 122             var = var()
 123
 124         self._write(f'<h5>{heading}</h5>{self._python_var(var)}')
 125
 126
 127     def table_dump(self, heading: str, rows: Iterator[Optional[List[Any]]]) -> None:
 128         head = next(rows)
 129         assert head
 130         self._write(f'<table><thead><tr><th colspan="{len(head)}">{heading}</th></tr><tr>')
 131         for cell in head:
 132             self._write(f'<th>{cell}</th>')
 133         self._write('</tr></thead><tbody>')
 134         for row in rows:
 135             if row is not None:
 136                 self._write('<tr>')
 137                 for cell in row:
 138                     self._write(f'<td>{cell}</td>')
 139                 self._write('</tr>')
 140         self._write('</tbody></table>')
 141
 142
 143     def result_dump(self, heading: str, results: Iterator[Tuple[Any, Any]]) -> None:
 144         """ Print a list of search results generated by the generator function.
 145         """
 146         def format_osm(osm_object: Optional[Tuple[str, int]]) -> str:
 147             if not osm_object:
 148                 return '-'
 149
 150             t, i = osm_object
 151             if t == 'N':
 152                 fullt = 'node'
 153             elif t == 'W':
 154                 fullt = 'way'
 155             elif t == 'R':
 156                 fullt = 'relation'
 157             else:
 158                 return f'{t}{i}'
 159
 160             return f'<a href="https://www.openstreetmap.org/{fullt}/{i}">{t}{i}</a>'
 161
 162         self._write(f'<h5>{heading}</h5><p><dl>')
 163         total = 0
 164         for rank, res in results:
 165             self._write(f'<dt>[{rank:.3f}]</dt>  <dd>{res.source_table.name}(')
 166             self._write(f"{_debug_name(res)}, type=({','.join(res.category)}), ")
 167             self._write(f"rank={res.rank_address}, ")
 168             self._write(f"osm={format_osm(res.osm_object)}, ")
 169             self._write(f'cc={res.country_code}, ')
 170             self._write(f'importance={res.importance or -1:.5f})</dd>')
 171             total += 1
 172         self._write(f'</dl><b>TOTAL:</b> {total}</p>')
 173
 174
 175     def sql(self, conn: AsyncConnection, statement: 'sa.Executable') -> None:
 176         sqlstr = self.format_sql(conn, statement)
 177         if CODE_HIGHLIGHT:
 178             sqlstr = highlight(sqlstr, PostgresLexer(),
 179                                HtmlFormatter(nowrap=True, lineseparator='<br />'))
 180             self._write(f'<div class="highlight"><code class="lang-sql">{sqlstr}</code></div>')
 181         else:
 182             self._write(f'<code class="lang-sql">{sqlstr}</code>')
 183
 184
 185     def _python_var(self, var: Any) -> str:
 186         if CODE_HIGHLIGHT:
 187             fmt = highlight(repr(var), PythonLexer(), HtmlFormatter(nowrap=True))
 188             return f'<div class="highlight"><code class="lang-python">{fmt}</code></div>'
 189
 190         return f'<code class="lang-python">{str(var)}</code>'
 191
 192
 193     def _write(self, text: str) -> None:
 194         """ Add the raw text to the debug output.
 195         """
 196         self.buffer.write(text)
 197
 198
 199 class TextLogger(BaseLogger):
 200     """ Logger creating output suitable for the console.
 201     """
 202     def __init__(self) -> None:
 203         self.buffer = io.StringIO()
 204
 205
 206     def get_buffer(self) -> str:
 207         return self.buffer.getvalue()
 208
 209
 210     def function(self, func: str, **kwargs: Any) -> None:
 211         self._write(f"#### Debug output for {func}()\n\nParameters:\n")
 212         for name, value in kwargs.items():
 213             self._write(f'  {name}: {self._python_var(value)}\n')
 214         self._write('\n')
 215
 216
 217     def section(self, heading: str) -> None:
 218         self._write(f"\n# {heading}\n\n")
 219
 220
 221     def comment(self, text: str) -> None:
 222         self._write(f"{text}\n")
 223
 224
 225     def var_dump(self, heading: str, var: Any) -> None:
 226         if callable(var):
 227             var = var()
 228
 229         self._write(f'{heading}:\n  {self._python_var(var)}\n\n')
 230
 231
 232     def table_dump(self, heading: str, rows: Iterator[Optional[List[Any]]]) -> None:
 233         self._write(f'{heading}:\n')
 234         data = [list(map(self._python_var, row)) if row else None for row in rows]
 235         assert data[0] is not None
 236         num_cols = len(data[0])
 237
 238         maxlens = [max(len(d[i]) for d in data if d) for i in range(num_cols)]
 239         tablewidth = sum(maxlens) + 3 * num_cols + 1
 240         row_format = '| ' +' | '.join(f'{{:<{l}}}' for l in maxlens) + ' |\n'
 241         self._write('-'*tablewidth + '\n')
 242         self._write(row_format.format(*data[0]))
 243         self._write('-'*tablewidth + '\n')
 244         for row in data[1:]:
 245             if row:
 246                 self._write(row_format.format(*row))
 247             else:
 248                 self._write('-'*tablewidth + '\n')
 249         if data[-1]:
 250             self._write('-'*tablewidth + '\n')
 251
 252
 253     def result_dump(self, heading: str, results: Iterator[Tuple[Any, Any]]) -> None:
 254         self._write(f'{heading}:\n')
 255         total = 0
 256         for rank, res in results:
 257             self._write(f'[{rank:.3f}]  {res.source_table.name}(')
 258             self._write(f"{_debug_name(res)}, type=({','.join(res.category)}), ")
 259             self._write(f"rank={res.rank_address}, ")
 260             self._write(f"osm={''.join(map(str, res.osm_object or []))}, ")
 261             self._write(f'cc={res.country_code}, ')
 262             self._write(f'importance={res.importance or -1:.5f})\n')
 263             total += 1
 264         self._write(f'TOTAL: {total}\n\n')
 265
 266
 267     def sql(self, conn: AsyncConnection, statement: 'sa.Executable') -> None:
 268         sqlstr = '\n| '.join(textwrap.wrap(self.format_sql(conn, statement), width=78))
 269         self._write(f"| {sqlstr}\n\n")
 270
 271
 272     def _python_var(self, var: Any) -> str:
 273         return str(var)
 274
 275
 276     def _write(self, text: str) -> None:
 277         self.buffer.write(text)
 278
 279
 280 logger: ContextVar[BaseLogger] = ContextVar('logger', default=BaseLogger())
 281
 282
 283 def set_log_output(fmt: str) -> None:
 284     """ Enable collecting debug information.
 285     """
 286     if fmt == 'html':
 287         logger.set(HTMLLogger())
 288     elif fmt == 'text':
 289         logger.set(TextLogger())
 290     else:
 291         logger.set(BaseLogger())
 292
 293
 294 def log() -> BaseLogger:
 295     """ Return the logger for the current context.
 296     """
 297     return logger.get()
 298
 299
 300 def get_and_disable() -> str:
 301     """ Return the current content of the debug buffer and disable logging.
 302     """
 303     buf = logger.get().get_buffer()
 304     logger.set(BaseLogger())
 305     return buf
 306
 307
 308 HTML_HEADER: str = """<!DOCTYPE html>
 309 <html>
 310 <head>
 311   <title>Nominatim - Debug</title>
 312   <style>
 313 """ + \
 314 (HtmlFormatter(nobackground=True).get_style_defs('.highlight') if CODE_HIGHLIGHT else '') +\
 315 """
 316     h2 { font-size: x-large }
 317
 318     dl {
 319       padding-left: 10pt;
 320       font-family: monospace
 321     }
 322
 323     dt {
 324       float: left;
 325       font-weight: bold;
 326       margin-right: 0.5em
 327     }
 328
 329     dt::after { content: ": "; }
 330
 331     dd::after {
 332       clear: left;
 333       display: block
 334     }
 335
 336     .lang-sql {
 337       color: #555;
 338       font-size: small
 339     }
 340
 341     h5 {
 342         border: solid lightgrey 0.1pt;
 343         margin-bottom: 0;
 344         background-color: #f7f7f7
 345     }
 346
 347     h5 + .highlight {
 348         padding: 3pt;
 349         border: solid lightgrey 0.1pt
 350     }
 351   </style>
 352 </head>
 353 <body>
 354 """
 355
 356 HTML_FOOTER: str = "</body></html>"