X-Git-Url: https://git.openstreetmap.org./nominatim.git/blobdiff_plain/96e1ef3ff846324bbfef1f209bfe30d88125b5bd..201b4689afaee3acfddd1fc7fe829fafc70667d6:/nominatim/api/logging.py?ds=sidebyside diff --git a/nominatim/api/logging.py b/nominatim/api/logging.py index e9c88470..30999a3f 100644 --- a/nominatim/api/logging.py +++ b/nominatim/api/logging.py @@ -7,10 +7,13 @@ """ Functions for specialised logging with HTML output. """ -from typing import Any, cast +from typing import Any, Iterator, Optional, List, Tuple, cast, Union, Mapping, Sequence from contextvars import ContextVar +import datetime as dt import textwrap import io +import re +import html import sqlalchemy as sa from sqlalchemy.ext.asyncio import AsyncConnection @@ -24,6 +27,13 @@ except ModuleNotFoundError: CODE_HIGHLIGHT = False +def _debug_name(res: Any) -> str: + if res.names: + return cast(str, res.names.get('name', next(iter(res.names.values())))) + + return f"Hnr {res.housenumber}" if res.housenumber is not None else '[NONE]' + + class BaseLogger: """ Interface for logging function. @@ -56,10 +66,67 @@ class BaseLogger: """ - def sql(self, conn: AsyncConnection, statement: 'sa.Executable') -> None: + def table_dump(self, heading: str, rows: Iterator[Optional[List[Any]]]) -> None: + """ Print the table generated by the generator function. + """ + + + def result_dump(self, heading: str, results: Iterator[Tuple[Any, Any]]) -> None: + """ Print a list of search results generated by the generator function. + """ + + + def sql(self, conn: AsyncConnection, statement: 'sa.Executable', + params: Union[Mapping[str, Any], Sequence[Mapping[str, Any]], None]) -> None: """ Print the SQL for the given statement. """ + def format_sql(self, conn: AsyncConnection, statement: 'sa.Executable', + extra_params: Union[Mapping[str, Any], + Sequence[Mapping[str, Any]], None]) -> str: + """ Return the compiled version of the statement. + """ + compiled = cast('sa.ClauseElement', statement).compile(conn.sync_engine) + + params = dict(compiled.params) + if isinstance(extra_params, Mapping): + for k, v in extra_params.items(): + if hasattr(v, 'to_wkt'): + params[k] = v.to_wkt() + elif isinstance(v, (int, float)): + params[k] = v + else: + params[k] = str(v) + elif isinstance(extra_params, Sequence) and extra_params: + for k in extra_params[0]: + params[k] = f':{k}' + + sqlstr = str(compiled) + + if conn.dialect.name == 'postgresql': + if sa.__version__.startswith('1'): + try: + sqlstr = re.sub(r'__\[POSTCOMPILE_[^]]*\]', '%s', sqlstr) + return sqlstr % tuple((repr(params.get(name, None)) + for name in compiled.positiontup)) # type: ignore + except TypeError: + return sqlstr + + # Fixes an odd issue with Python 3.7 where percentages are not + # quoted correctly. + sqlstr = re.sub(r'%(?!\()', '%%', sqlstr) + sqlstr = re.sub(r'__\[POSTCOMPILE_([^]]*)\]', r'%(\1)s', sqlstr) + return sqlstr % params + + assert conn.dialect.name == 'sqlite' + + # params in positional order + pparams = (repr(params.get(name, None)) for name in compiled.positiontup) # type: ignore + + sqlstr = re.sub(r'__\[POSTCOMPILE_([^]]*)\]', '?', sqlstr) + sqlstr = re.sub(r"\?", lambda m: next(pparams), sqlstr) + + return sqlstr class HTMLLogger(BaseLogger): """ Logger that formats messages in HTML. @@ -68,11 +135,16 @@ class HTMLLogger(BaseLogger): self.buffer = io.StringIO() + def _timestamp(self) -> None: + self._write(f'

[{dt.datetime.now()}]

') + + def get_buffer(self) -> str: return HTML_HEADER + self.buffer.getvalue() + HTML_FOOTER def function(self, func: str, **kwargs: Any) -> None: + self._timestamp() self._write(f"

Debug output for {func}()

\n

Parameters:

") for name, value in kwargs.items(): self._write(f'
{name}
{self._python_var(value)}
') @@ -80,34 +152,91 @@ class HTMLLogger(BaseLogger): def section(self, heading: str) -> None: + self._timestamp() self._write(f"

{heading}

") def comment(self, text: str) -> None: + self._timestamp() self._write(f"

{text}

") def var_dump(self, heading: str, var: Any) -> None: + self._timestamp() + if callable(var): + var = var() + self._write(f'
{heading}
{self._python_var(var)}') - def sql(self, conn: AsyncConnection, statement: 'sa.Executable') -> None: - sqlstr = str(cast('sa.ClauseElement', statement) - .compile(conn.sync_engine, compile_kwargs={"literal_binds": True})) + def table_dump(self, heading: str, rows: Iterator[Optional[List[Any]]]) -> None: + self._timestamp() + head = next(rows) + assert head + self._write(f'') + for cell in head: + self._write(f'') + self._write('') + for row in rows: + if row is not None: + self._write('') + for cell in row: + self._write(f'') + self._write('') + self._write('
{heading}
{cell}
{cell}
') + + + def result_dump(self, heading: str, results: Iterator[Tuple[Any, Any]]) -> None: + """ Print a list of search results generated by the generator function. + """ + self._timestamp() + def format_osm(osm_object: Optional[Tuple[str, int]]) -> str: + if not osm_object: + return '-' + + t, i = osm_object + if t == 'N': + fullt = 'node' + elif t == 'W': + fullt = 'way' + elif t == 'R': + fullt = 'relation' + else: + return f'{t}{i}' + + return f'{t}{i}' + + self._write(f'
{heading}

') + total = 0 + for rank, res in results: + self._write(f'
[{rank:.3f}]
{res.source_table.name}(') + self._write(f"{_debug_name(res)}, type=({','.join(res.category)}), ") + self._write(f"rank={res.rank_address}, ") + self._write(f"osm={format_osm(res.osm_object)}, ") + self._write(f'cc={res.country_code}, ') + self._write(f'importance={res.importance or float("nan"):.5f})
') + total += 1 + self._write(f'
TOTAL: {total}

') + + + def sql(self, conn: AsyncConnection, statement: 'sa.Executable', + params: Union[Mapping[str, Any], Sequence[Mapping[str, Any]], None]) -> None: + self._timestamp() + sqlstr = self.format_sql(conn, statement, params) if CODE_HIGHLIGHT: sqlstr = highlight(sqlstr, PostgresLexer(), - HtmlFormatter(nowrap=True, lineseparator='
')) + HtmlFormatter(nowrap=True, lineseparator='
')) self._write(f'
{sqlstr}
') else: - self._write(f'{sqlstr}') + self._write(f'{html.escape(sqlstr)}') def _python_var(self, var: Any) -> str: if CODE_HIGHLIGHT: - fmt = highlight(repr(var), PythonLexer(), HtmlFormatter(nowrap=True)) + fmt = highlight(str(var), PythonLexer(), HtmlFormatter(nowrap=True)) return f'
{fmt}
' - return f'{str(var)}' + return f'{html.escape(str(var))}' def _write(self, text: str) -> None: @@ -123,6 +252,10 @@ class TextLogger(BaseLogger): self.buffer = io.StringIO() + def _timestamp(self) -> None: + self._write(f'[{dt.datetime.now()}]\n') + + def get_buffer(self) -> str: return self.buffer.getvalue() @@ -135,6 +268,7 @@ class TextLogger(BaseLogger): def section(self, heading: str) -> None: + self._timestamp() self._write(f"\n# {heading}\n\n") @@ -143,13 +277,52 @@ class TextLogger(BaseLogger): def var_dump(self, heading: str, var: Any) -> None: + if callable(var): + var = var() + self._write(f'{heading}:\n {self._python_var(var)}\n\n') - def sql(self, conn: AsyncConnection, statement: 'sa.Executable') -> None: - sqlstr = str(cast('sa.ClauseElement', statement) - .compile(conn.sync_engine, compile_kwargs={"literal_binds": True})) - sqlstr = '\n| '.join(textwrap.wrap(sqlstr, width=78)) + def table_dump(self, heading: str, rows: Iterator[Optional[List[Any]]]) -> None: + self._write(f'{heading}:\n') + data = [list(map(self._python_var, row)) if row else None for row in rows] + assert data[0] is not None + num_cols = len(data[0]) + + maxlens = [max(len(d[i]) for d in data if d) for i in range(num_cols)] + tablewidth = sum(maxlens) + 3 * num_cols + 1 + row_format = '| ' +' | '.join(f'{{:<{l}}}' for l in maxlens) + ' |\n' + self._write('-'*tablewidth + '\n') + self._write(row_format.format(*data[0])) + self._write('-'*tablewidth + '\n') + for row in data[1:]: + if row: + self._write(row_format.format(*row)) + else: + self._write('-'*tablewidth + '\n') + if data[-1]: + self._write('-'*tablewidth + '\n') + + + def result_dump(self, heading: str, results: Iterator[Tuple[Any, Any]]) -> None: + self._timestamp() + self._write(f'{heading}:\n') + total = 0 + for rank, res in results: + self._write(f'[{rank:.3f}] {res.source_table.name}(') + self._write(f"{_debug_name(res)}, type=({','.join(res.category)}), ") + self._write(f"rank={res.rank_address}, ") + self._write(f"osm={''.join(map(str, res.osm_object or []))}, ") + self._write(f'cc={res.country_code}, ') + self._write(f'importance={res.importance or -1:.5f})\n') + total += 1 + self._write(f'TOTAL: {total}\n\n') + + + def sql(self, conn: AsyncConnection, statement: 'sa.Executable', + params: Union[Mapping[str, Any], Sequence[Mapping[str, Any]], None]) -> None: + self._timestamp() + sqlstr = '\n| '.join(textwrap.wrap(self.format_sql(conn, statement, params), width=78)) self._write(f"| {sqlstr}\n\n") @@ -232,6 +405,26 @@ HTML_HEADER: str = """ padding: 3pt; border: solid lightgrey 0.1pt } + + table, th, tbody { + border: thin solid; + border-collapse: collapse; + } + td { + border-right: thin solid; + padding-left: 3pt; + padding-right: 3pt; + } + + .timestamp { + font-size: 0.8em; + color: darkblue; + width: calc(100% - 5pt); + text-align: right; + position: absolute; + left: 0; + margin-top: -5px; + }