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