🔊(backend) add logs to bootstrap_elasticsearch command

Too few logs were displayed when running bootstrap_elasticsearch command.

Author: kernicPanel

src/richie/apps/search/index_manager.py

@@ -2,6 +2,7 @@
 ElasticSearch indices utilities.
 """
 
+import logging
 import re
 from functools import reduce
 
@@ -16,6 +17,8 @@
 from .indexers import ES_INDICES
 from .text_indexing import ANALYSIS_SETTINGS
 
+logger = logging.getLogger(__name__)
+
 
 def richie_bulk(actions):
     """Wrap bulk helper to set default parameters."""
@@ -37,16 +40,16 @@ def get_indices_by_alias(existing_indices, alias):
             yield index, alias
 
 
-def perform_create_index(indexable, logger=None):
+def perform_create_index(indexable):
     """
     Create a new index in ElasticSearch from an indexable instance
     """
+    logger.info("Creating the index %s...", indexable.index_name)
     # Create a new index name, suffixing its name with a timestamp
     new_index = f"{indexable.index_name:s}_{timezone.now():%Y-%m-%d-%Hh%Mm%S.%fs}"
 
     # Create the new index
-    if logger:
-        logger.info(f'Creating a new Elasticsearch index "{new_index:s}"...')
+    logger.info("Creating a new Elasticsearch index %s...", new_index)
     ES_INDICES_CLIENT.create(index=new_index)
 
     # The index needs to be closed before we set an analyzer
@@ -63,23 +66,23 @@ def perform_create_index(indexable, logger=None):
     return new_index
 
 
-def regenerate_indices(logger):
+def regenerate_indices():
     """
     Create new indices for our indexables and replace possible existing indices with
     a new one only once it has successfully built it.
     """
+    logger.info("Regenerating ES indices...")
     # Get all existing indices once; we'll look up into this list many times
     try:
         existing_indices = ES_INDICES_CLIENT.get_alias("*")
     except NotFoundError:
         # Provide a fallback empty list so we don't have to check for its existence later on
         existing_indices = []
 
+    logger.info("Creating new ES indices...")
     # Create a new index for each of those modules
     # NB: we're mapping perform_create_index which produces side-effects
-    indices_to_create = zip(
-        list(map(lambda ix: perform_create_index(ix, logger), ES_INDICES)), ES_INDICES
-    )
+    indices_to_create = [(perform_create_index(ix), ix) for ix in ES_INDICES]
 
     # Prepare to alias them so they can be swapped-in for the previous versions
     actions_to_create_aliases = [
@@ -152,13 +155,16 @@ def perform_aliases_update():
         ES_INDICES_CLIENT.delete(index=useless_index, ignore=[400, 404])
 
 
-def store_es_scripts(logger=None):
+def store_es_scripts():
     """
     Iterate over the indexers listed in the settings, import them, and store the scripts
     they define on their "scripts" key in ElasticSearch
     """
     for indexer in ES_INDICES:
         for script_id, script_body in indexer.scripts.items():
-            if logger:
-                logger.info(f'Storing script "{script_id:s}"...')
+            logger.info(
+                "Storing script %s for indexer %s...",
+                script_id,
+                indexer.__name__,
+            )
             ES_CLIENT.put_script(id=script_id, body=script_body)

src/richie/apps/search/indexers/persons.py

@@ -2,6 +2,7 @@
 ElasticSearch person document management utilities
 """
 
+import logging
 from collections import defaultdict
 
 from django.conf import settings
@@ -20,6 +21,8 @@
 from ..utils.i18n import get_best_field_language
 from ..utils.indexers import slice_string_for_completion
 
+logger = logging.getLogger(__name__)
+
 
 class PersonsIndexer:
     """
@@ -78,6 +81,11 @@ def get_es_document_for_person(cls, person, index=None, action="index"):
         ):
             language = portrait.cmsplugin_ptr.language
             with translation.override(language):
+                logger.debug(
+                    "Indexing %s portrait for language %s",
+                    person.extended_object.get_absolute_url(language),
+                    language,
+                )
                 portrait_images[language] = get_picture_info(portrait, "portrait")
 
         # Get bio texts

src/richie/apps/search/management/commands/bootstrap_elasticsearch.py

@@ -27,14 +27,14 @@ def handle(self, *args, **options):
 
         # Creates new indices each time, populates them, and atomically replaces
         # the old indices once the new ones are ready.
-        regenerate_indices(logger)
+        regenerate_indices()
 
         # Confirm operation success through a console log
         logger.info("ES indices regenerated.")
 
         logger.info("Starting to store ES scripts...")
 
         # Iterates over indexables to find all the necessary scripts and store them
-        store_es_scripts(logger)
+        store_es_scripts()
 
         logger.info("ES scripts stored.")

tests/apps/search/test_index_manager.py

@@ -130,10 +130,10 @@ def get_es_documents(self, index, action="index"):
         # Make sure our index is empty before we call the function
         self.assertEqual(ES_INDICES_CLIENT.get_alias("*"), {})
 
-        mock_logger = mock.Mock(spec=["info"])
-
-        with mock.patch.object(django_timezone, "now", return_value=now):
-            new_index = perform_create_index(indexable, mock_logger)
+        with mock.patch.object(
+            django_timezone, "now", return_value=now
+        ), self.assertLogs() as mock_logger:
+            new_index = perform_create_index(indexable)
         ES_INDICES_CLIENT.refresh()
 
         self.assertEqual(new_index, "richie_courses_2016-05-04-03h12m33.123456s")
@@ -151,7 +151,7 @@ def get_es_documents(self, index, action="index"):
                 }
             },
         )
-        mock_logger.info.assert_called()
+        self.assertNotEqual(mock_logger.records, [])
 
     @mock.patch.object(
         ES_INDICES.categories,
@@ -201,7 +201,7 @@ def test_index_manager_regenerate_indices(self, *args):
         creation1_datetime = datetime(2010, 1, 1, tzinfo=timezone.utc)
         creation1_string = creation1_datetime.strftime("%Y-%m-%d-%Hh%Mm%S.%fs")
         with mock.patch.object(django_timezone, "now", return_value=creation1_datetime):
-            regenerate_indices(None)
+            regenerate_indices()
 
         expected_indices = [
             "richie_test_categories",
@@ -223,7 +223,7 @@ def test_index_manager_regenerate_indices(self, *args):
         creation2_datetime = datetime(2011, 2, 2, tzinfo=timezone.utc)
         creation2_string = creation2_datetime.strftime("%Y-%m-%d-%Hh%Mm%S.%fs")
         with mock.patch.object(django_timezone, "now", return_value=creation2_datetime):
-            regenerate_indices(None)
+            regenerate_indices()
 
         # All indices were replaced and aliases updated
         for alias_name in expected_indices:
@@ -252,7 +252,7 @@ def test_index_manager_regenerate_indices(self, *args):
         creation3_datetime = datetime(2012, 3, 3, tzinfo=timezone.utc)
         creation3_string = creation3_datetime.strftime("%Y-%m-%d-%Hh%Mm%S.%fs")
         with mock.patch.object(django_timezone, "now", return_value=creation3_datetime):
-            regenerate_indices(None)
+            regenerate_indices()
 
         # All indices were replaced and had their aliases changed
         for index_name in expected_indices:
@@ -314,7 +314,7 @@ def test_index_manager_regenerate_indices_from_broken_state(self, *args):
         creation_datetime = datetime(2010, 1, 1, tzinfo=timezone.utc)
         creation_string = creation_datetime.strftime("%Y-%m-%d-%Hh%Mm%S.%fs")
         with mock.patch.object(django_timezone, "now", return_value=creation_datetime):
-            regenerate_indices(None)
+            regenerate_indices()
 
         # No error was thrown, the courses index (like all others) was bootstrapped
         self.assertIsNotNone(
@@ -345,7 +345,7 @@ def test_index_manager_store_es_scripts(self, mock_put_script, *args):
         Make sure store_es_scripts iterates over all indexers to store their scripts and
         does not choke when there are (0 | 1 | 2+) scripts on an indexer.
         """
-        store_es_scripts(None)
+        store_es_scripts()
         mock_put_script.assert_any_call(body="script body A", id="script_id_A")
         mock_put_script.assert_any_call(body="script body B", id="script_id_B")
         mock_put_script.assert_any_call(body="script body C", id="script_id_C")