Merge pull request #2666 from lonvia/admin-command-for-forced-indexing

[nominatim.git] / nominatim / indexer / progress.py

diff --git a/nominatim/indexer/progress.py b/nominatim/indexer/progress.py
index 8324b6bb23ae22e3ac077bfe1dc0272b843e87c4..b758e10d52abce50da267df4953803dbf67e36eb 100644 (file)
--- a/nominatim/indexer/progress.py
+++ b/nominatim/indexer/progress.py
@@ -1,14 +1,20 @@
 # SPDX-License-Identifier: GPL-2.0-only
 #
-# This file is part of Nominatim.
-# Copyright (C) 2020 Sarah Hoffmann
-
+# This file is part of Nominatim. (https://nominatim.org)
+#
+# Copyright (C) 2022 by the Nominatim developer community.
+# For a full list of authors see the git log.
+"""
+Helpers for progress logging.
+"""
 import logging
 from datetime import datetime
 
-log = logging.getLogger()
+LOG = logging.getLogger()
 
-class ProgressLogger(object):
+INITIAL_PROGRESS = 10
+
+class ProgressLogger:
     """ Tracks and prints progress for the indexing process.
         `name` is the name of the indexing step being tracked.
         `total` sets up the total number of items that need processing.
@@ -21,32 +27,46 @@ class ProgressLogger(object):
         self.total_places = total
         self.done_places = 0
         self.rank_start_time = datetime.now()
-        self.next_info = 50 if log.isEnabledFor(logging.INFO) else total + 1
+        self.log_interval = log_interval
+        self.next_info = INITIAL_PROGRESS if LOG.isEnabledFor(logging.WARNING) else total + 1
 
     def add(self, num=1):
         """ Mark `num` places as processed. Print a log message if the
-            logging is at least info and the log interval has past.
+            logging is at least info and the log interval has passed.
         """
         self.done_places += num
 
-        if self.done_places >= self.next_info:
-            now = datetime.now()
-            done_time = (now - self.rank_start_time).total_seconds()
-            places_per_sec = self.done_places / done_time
-            eta = (self.total_places - self.done_places)/places_per_sec
+        if self.done_places < self.next_info:
+            return
+
+        now = datetime.now()
+        done_time = (now - self.rank_start_time).total_seconds()
 
-            log.info("Done {} in {} @ {:.3f} per second - {} ETA (seconds): {:.2f}"
-                     .format(self.done_places, int(done_time),
-                             places_per_sec, self.name, eta))
+        if done_time < 2:
+            self.next_info = self.done_places + INITIAL_PROGRESS
+            return
 
-            self.next_info += int(places_per_sec)
+        places_per_sec = self.done_places / done_time
+        eta = (self.total_places - self.done_places) / places_per_sec
+
+        LOG.warning("Done %d in %d @ %.3f per second - %s ETA (seconds): %.2f",
+                    self.done_places, int(done_time),
+                    places_per_sec, self.name, eta)
+
+        self.next_info += int(places_per_sec) * self.log_interval
 
     def done(self):
-        """ Print final staticstics about the progress.
+        """ Print final statistics about the progress.
         """
         rank_end_time = datetime.now()
-        diff_seconds = (rank_end_time-self.rank_start_time).total_seconds()
 
-        log.warning("Done {}/{} in {} @ {:.3f} per second - FINISHED {}\n".format(
+        if rank_end_time == self.rank_start_time:
+            diff_seconds = 0
+            places_per_sec = self.done_places
+        else:
+            diff_seconds = (rank_end_time - self.rank_start_time).total_seconds()
+            places_per_sec = self.done_places / diff_seconds
+
+        LOG.warning("Done %d/%d in %d @ %.3f per second - FINISHED %s\n",
                     self.done_places, self.total_places, int(diff_seconds),
-                    self.done_places/diff_seconds, self.name))
+                    places_per_sec, self.name)