Merge remote-tracking branch 'upstream/master'

[nominatim.git] / nominatim / api / logging.py

diff --git a/nominatim/api/logging.py b/nominatim/api/logging.py
index 351da9a1d6ebe81272df4b45a09e569a9dce65da..5b6d0e4dbbc03573b643e88cba43a871d7bd038a 100644 (file)
--- a/nominatim/api/logging.py
+++ b/nominatim/api/logging.py
@@ -7,10 +7,12 @@
 """
 Functions for specialised logging with HTML output.
 """
 """
 Functions for specialised logging with HTML output.
 """

-from typing import Any, Iterator, Optional, List, Tuple, cast
+from typing import Any, Iterator, Optional, List, Tuple, cast, Union, Mapping, Sequence

 from contextvars import ContextVar
 from contextvars import ContextVar

+import datetime as dt

 import textwrap
 import io
 import textwrap
 import io

+import re

 
 import sqlalchemy as sa
 from sqlalchemy.ext.asyncio import AsyncConnection
 
 import sqlalchemy as sa
 from sqlalchemy.ext.asyncio import AsyncConnection


@@ -73,23 +75,41 @@ class BaseLogger:
         """
 
 
         """
 
 

-    def sql(self, conn: AsyncConnection, statement: 'sa.Executable') -> None:
+    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.
         """
 
         """ Print the SQL for the given statement.
         """
 

-    def format_sql(self, conn: AsyncConnection, statement: 'sa.Executable') -> str:
+    def format_sql(self, conn: AsyncConnection, statement: 'sa.Executable',
+                   extra_params: Union[Mapping[str, Any],
+                                 Sequence[Mapping[str, Any]], None]) -> str:

         """ Return the comiled version of the statement.
         """
         """ Return the comiled version of the statement.
         """

-        try:
-            return str(cast('sa.ClauseElement', statement)
-                         .compile(conn.sync_engine, compile_kwargs={"literal_binds": True}))
-        except sa.exc.CompileError:
-            pass
-        except NotImplementedError:
-            pass
-
-        return str(cast('sa.ClauseElement', statement).compile(conn.sync_engine))
-
+        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():
+                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 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

 
 class HTMLLogger(BaseLogger):
     """ Logger that formats messages in HTML.
 
 class HTMLLogger(BaseLogger):
     """ Logger that formats messages in HTML.


@@ -98,11 +118,16 @@ class HTMLLogger(BaseLogger):
         self.buffer = io.StringIO()
 
 
         self.buffer = io.StringIO()
 
 

+    def _timestamp(self) -> None:
+        self._write(f'<p class="timestamp">[{dt.datetime.now()}]</p>')
+
+

     def get_buffer(self) -> str:
         return HTML_HEADER + self.buffer.getvalue() + HTML_FOOTER
 
 
     def function(self, func: str, **kwargs: Any) -> None:
     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"<h1>Debug output for {func}()</h1>\n<p>Parameters:<dl>")
         for name, value in kwargs.items():
             self._write(f'<dt>{name}</dt><dd>{self._python_var(value)}</dd>')
         self._write(f"<h1>Debug output for {func}()</h1>\n<p>Parameters:<dl>")
         for name, value in kwargs.items():
             self._write(f'<dt>{name}</dt><dd>{self._python_var(value)}</dd>')


@@ -110,14 +135,17 @@ class HTMLLogger(BaseLogger):
 
 
     def section(self, heading: str) -> None:
 
 
     def section(self, heading: str) -> None:

+        self._timestamp()

         self._write(f"<h2>{heading}</h2>")
 
 
     def comment(self, text: str) -> None:
         self._write(f"<h2>{heading}</h2>")
 
 
     def comment(self, text: str) -> None:

+        self._timestamp()

         self._write(f"<p>{text}</p>")
 
 
     def var_dump(self, heading: str, var: Any) -> None:
         self._write(f"<p>{text}</p>")
 
 
     def var_dump(self, heading: str, var: Any) -> None:

+        self._timestamp()

         if callable(var):
             var = var()
 
         if callable(var):
             var = var()
 


@@ -125,6 +153,7 @@ class HTMLLogger(BaseLogger):
 
 
     def table_dump(self, heading: str, rows: Iterator[Optional[List[Any]]]) -> None:
 
 
     def table_dump(self, heading: str, rows: Iterator[Optional[List[Any]]]) -> None:

+        self._timestamp()

         head = next(rows)
         assert head
         self._write(f'<table><thead><tr><th colspan="{len(head)}">{heading}</th></tr><tr>')
         head = next(rows)
         assert head
         self._write(f'<table><thead><tr><th colspan="{len(head)}">{heading}</th></tr><tr>')


@@ -143,6 +172,7 @@ class HTMLLogger(BaseLogger):
     def result_dump(self, heading: str, results: Iterator[Tuple[Any, Any]]) -> None:
         """ Print a list of search results 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.
         """

+        self._timestamp()

         def format_osm(osm_object: Optional[Tuple[str, int]]) -> str:
             if not osm_object:
                 return '-'
         def format_osm(osm_object: Optional[Tuple[str, int]]) -> str:
             if not osm_object:
                 return '-'


@@ -167,13 +197,15 @@ class HTMLLogger(BaseLogger):
             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"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 -1:.5f})</dd>')
+            self._write(f'importance={res.importance or float("nan"):.5f})</dd>')

             total += 1
         self._write(f'</dl><b>TOTAL:</b> {total}</p>')
 
 
             total += 1
         self._write(f'</dl><b>TOTAL:</b> {total}</p>')
 
 

-    def sql(self, conn: AsyncConnection, statement: 'sa.Executable') -> None:
-        sqlstr = self.format_sql(conn, statement)
+    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='<br />'))
         if CODE_HIGHLIGHT:
             sqlstr = highlight(sqlstr, PostgresLexer(),
                                HtmlFormatter(nowrap=True, lineseparator='<br />'))


@@ -184,7 +216,7 @@ class HTMLLogger(BaseLogger):
 
     def _python_var(self, var: Any) -> str:
         if CODE_HIGHLIGHT:
 
     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'<div class="highlight"><code class="lang-python">{fmt}</code></div>'
 
         return f'<code class="lang-python">{str(var)}</code>'
             return f'<div class="highlight"><code class="lang-python">{fmt}</code></div>'
 
         return f'<code class="lang-python">{str(var)}</code>'


@@ -264,8 +296,9 @@ class TextLogger(BaseLogger):
         self._write(f'TOTAL: {total}\n\n')
 
 
         self._write(f'TOTAL: {total}\n\n')
 
 

-    def sql(self, conn: AsyncConnection, statement: 'sa.Executable') -> None:
-        sqlstr = '\n| '.join(textwrap.wrap(self.format_sql(conn, statement), width=78))
+    def sql(self, conn: AsyncConnection, statement: 'sa.Executable',
+            params: Union[Mapping[str, Any], Sequence[Mapping[str, Any]], None]) -> None:
+        sqlstr = '\n| '.join(textwrap.wrap(self.format_sql(conn, statement, params), width=78))

         self._write(f"| {sqlstr}\n\n")
 
 
         self._write(f"| {sqlstr}\n\n")
 
 


@@ -348,6 +381,26 @@ HTML_HEADER: str = """<!DOCTYPE html>
         padding: 3pt;
         border: solid lightgrey 0.1pt
     }
         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;
+    }

   </style>
 </head>
 <body>
   </style>
 </head>
 <body>