make log output configurable

docs/customize/Settings.md

@@ -648,21 +648,39 @@ See also [NOMINATIM_DEFAULT_LANGUAGE](#nominatim_default_language).
 | **Description:**   | Log requests into a file |
 | **Format:**        | path |
 | **Default:**       | _empty_ (logging disabled) |
-| **After Changes:** | run `nominatim refresh --website` |
 
 Enable logging of requests into a file with this setting by setting the log
 file where to log to. A relative file name is assumed to be relative to
-the project directory.
+the project directory. The format of the log output can be set
+with NOMINATIM_LOG_FORMAT.
 
+#### NOMINATIM_LOG_FORMAT
 
-The entries in the log file have the following format:
+| Summary            |                                                     |
+| --------------     | --------------------------------------------------- |
+| **Description:**   | Log requests into a file |
+| **Format:**        | [Python String Format](https://docs.python.org/3/library/string.html#formatstrings) string |
+| **Default:**       | `[{start}] {total_time:.4f} {results_total} {endpoint} "{query_string}"` |
 
-    <request time> <execution time in s> <number of results> <type> "<query string>"
+Describes the content of a log line for a single request. The format
+must be readable by Python's format function. Nominatim provides a number
+of metrics than can be logged. The default set of metrics is the following:
 
-Request time is the time when the request was started. The execution time is
-given in seconds and includes the entire time the query was queued and executed
-in the frontend.
-type contains the name of the endpoint used.
+/// html | div.simple-table
+| name            | type   | Description |
+| --------------- | ------ | ------------|
+| start           | time   | Point in time when the request arrived. |
+| end             | time   | Point in time when the request was done. |
+| query_start     | time   | Point in time when processing started. |
+| total_time      | float  | Total time in seconds to handle the request. |
+| wait_time       | float  | Time in seconds the request waited for a database connection to be available. |
+| query_time      | float  | Total time in seconds to process the request once a connection was available. |
+| results_total   | int    | Number of results found. |
+| endpoint        | string | API endpoint used. |
+| query_string    | string | Raw query string received. |
+///
+
+Variables of type 'time' contain a UTC timestamp string in ISO format.
 
 #### NOMINATIM_DEBUG_SQL
 

docs/extra.css

@@ -39,3 +39,9 @@ th {
   filter: grayscale(100%);
   font-size: 80%;
 }
+
+.simple-table table:not([class]) th,
+.simple-table table:not([class]) td {
+    padding: 2px 4px;
+    background: white;
+}

mkdocs.yml

@@ -67,6 +67,7 @@ markdown_extensions:
     - codehilite
     - admonition
     - pymdownx.superfences
+    - pymdownx.blocks.html
     - pymdownx.tabbed:
         alternate_style: true
     - def_list

settings/env.defaults

@@ -208,6 +208,13 @@ NOMINATIM_OUTPUT_NAMES=name:XX,name,brand,official_name:XX,short_name:XX,officia
 # To enable logging set this setting to the file to log to.
 NOMINATIM_LOG_FILE=
 
+# Set the output format of the query log.
+# This is a string following the Python String Format syntax,
+# see https://docs.python.org/3/library/string.html#formatstrings.
+# For possible replacement values, see the full documentation at
+# https://nominatim.org/release-docs/latest/customize/Settings/
+NOMINATIM_LOG_FORMAT='[{start}] {total_time:.4f} {results_total} {endpoint} "{query_string}"'
+
 # Echo raw SQL from SQLAlchemy statements.
 # EXPERT: Works only in command line/library use.
 NOMINATIM_DEBUG_SQL=no

src/nominatim_api/server/falcon/server.py

@@ -122,7 +122,8 @@ class FileLoggingMiddleware:
     """ Middleware to log selected requests into a file.
     """
 
-    def __init__(self, file_name: str):
+    def __init__(self, file_name: str, logstr: str):
+        self.logstr = logstr + '\n'
         self.fd = open(file_name, 'a', buffering=1, encoding='utf8')
 
     async def process_request(self, req: Request, _: Response) -> None:
@@ -151,8 +152,7 @@ class FileLoggingMiddleware:
                 qs[param] = qs[param].replace(tzinfo=None)\
                                      .isoformat(sep=' ', timespec='milliseconds')
 
-        self.fd.write(("[{start}] {total_time:.4f} {results_total} "
-                       '{endpoint} "{query_string}"\n').format_map(qs))
+        self.fd.write(self.logstr.format_map(qs))
 
 
 class APIMiddleware:
@@ -201,7 +201,7 @@ def get_application(project_dir: Path,
     middleware: List[Any] = [apimw]
     log_file = apimw.config.LOG_FILE
     if log_file:
-        middleware.append(FileLoggingMiddleware(log_file))
+        middleware.append(FileLoggingMiddleware(log_file, apimw.config.LOG_FORMAT))
 
     app = App(cors_enable=apimw.config.get_bool('CORS_NOACCESSCONTROL'),
               middleware=middleware)

src/nominatim_api/server/starlette/server.py

@@ -87,9 +87,10 @@ class FileLoggingMiddleware(BaseHTTPMiddleware):
     """ Middleware to log selected requests into a file.
     """
 
-    def __init__(self, app: Starlette, file_name: str = ''):
+    def __init__(self, app: Starlette, file_name: str = '', logstr: str = ''):
         super().__init__(app)
         self.fd = open(file_name, 'a', buffering=1, encoding='utf8')
+        self.logstr = logstr + '\n'
 
     async def dispatch(self, request: Request,
                        call_next: RequestResponseEndpoint) -> Response:
@@ -114,8 +115,7 @@ class FileLoggingMiddleware(BaseHTTPMiddleware):
                 qs[param] = qs[param].replace(tzinfo=None)\
                                      .isoformat(sep=' ', timespec='milliseconds')
 
-        self.fd.write(("[{start}] {total_time:.4f} {results_total} "
-                       '{endpoint} "{query_string}"\n').format_map(qs))
+        self.fd.write(self.logstr.format_map(qs))
 
         return response
 
@@ -149,7 +149,8 @@ def get_application(project_dir: Path,
 
     log_file = config.LOG_FILE
     if log_file:
-        middleware.append(Middleware(FileLoggingMiddleware, file_name=log_file))  # type: ignore
+        middleware.append(Middleware(FileLoggingMiddleware, file_name=log_file,  # type: ignore
+                                     logstr=config.LOG_FORMAT))
 
     exceptions: Dict[Any, Callable[[Request, Exception], Awaitable[Response]]] = {
         TimeoutError: timeout_error,