From 0d3f915da01d09985f39faf098898d27806f13a2 Mon Sep 17 00:00:00 2001
From: Wolfgang Schnerring <wolfgang.schnerring@zeit.de>
Date: Mon, 19 Feb 2024 08:53:35 +0100
Subject: [PATCH] ZO-4683: Add logging for more cases, unify log messages

---
 core/src/zeit/speech/connection.py            | 20 ++++++++++---------
 core/src/zeit/speech/tests/test_connection.py |  4 ++--
 2 files changed, 13 insertions(+), 11 deletions(-)

diff --git a/core/src/zeit/speech/connection.py b/core/src/zeit/speech/connection.py
index 15d150e72c..9e94d16f73 100644
--- a/core/src/zeit/speech/connection.py
+++ b/core/src/zeit/speech/connection.py
@@ -57,7 +57,7 @@ def _create(self, data: dict) -> IAudio:
         speech.audio_type = 'tts'
         folder = self._get_target_folder(data['uuid'])
         folder[data['uuid']] = speech
-        log.info('Text-to-speech was created for article uuid %s', data['uuid'])
+        log.info('Created %s for article uuid %s', speech, data['uuid'])
         self._update(data, folder[data['uuid']])
         return folder[data['uuid']]
 
@@ -73,7 +73,7 @@ def _update(self, data: dict, speech: IAudio):
                 elif audio['type'] == 'PREVIEW_TTS':
                     ISpeechInfo(co).preview_url = audio_entry['url']
             ISemanticChange(co).last_semantic_change = datetime.now(pytz.UTC)
-        log.info('Text-to-speech %s was updated for article uuid %s', speech.uniqueId, data['uuid'])
+        log.info('Updated %s for article uuid %s', speech, data['uuid'])
 
     def _find(self, article_uuid: str) -> Optional[IAudio]:
         connector = zope.component.getUtility(zeit.connector.interfaces.IConnector)
@@ -81,7 +81,7 @@ def _find(self, article_uuid: str) -> Optional[IAudio]:
         if not result:
             return None
         content = zeit.cms.interfaces.ICMSContent(result[0][0])
-        log.debug('Text-to-speech %s found for %s.', content.uniqueId, article_uuid)
+        log.debug('%s found for article uuid %s.', content, article_uuid)
         return content
 
     def update(self, data: dict):
@@ -98,10 +98,12 @@ def _add_audio_reference(self, speech: IAudio):
 
         IPublish(speech).publish(background=False)
         if speech in IAudioReferences(article).items:
+            log.debug('%s already references %s', article, speech)
             return
         with checked_out(article, raise_if_error=True) as co:
             references = IAudioReferences(co)
             references.add(speech)
+        log.info('Added reference from %s to %s', article, speech)
         IPublish(article).publish(background=False)
 
     def _article(self, speech: IAudio) -> IArticle:
@@ -115,9 +117,9 @@ def _assert_article_unchanged(self, speech: IAudio) -> IArticle:
         last_published = zeit.cms.workflow.interfaces.IPublishInfo(article).date_last_published
         if last_modified > last_published:
             raise AudioReferenceError(
-                'Article %s was modified after publish. Speech %s is not referenced.',
-                article.uniqueId,
-                speech.uniqueId,
+                '%s was modified after publish. Skipped adding reference to %s.',
+                article,
+                speech,
             )
         return article
 
@@ -125,7 +127,7 @@ def _remove_reference_from_article(self, speech: IAudio):
         article = self._article(speech)
         if not article:
             log.warning(
-                'No article found for Text-to-speech %s. ' 'Maybe it was already deleted?',
+                'No article found for %s. Maybe it was already deleted?',
                 speech,
             )
             return
@@ -137,7 +139,7 @@ def delete(self, data: dict):
         speech = self._find(data['article_uuid'])
         if not speech:
             log.warning(
-                'No Text-to-speech found for article uuid %s. '
+                'No audio object found for article uuid %s. '
                 'Maybe it was already deleted?' % data['article_uuid'],
             )
             return
@@ -145,4 +147,4 @@ def delete(self, data: dict):
         IPublish(speech).retract(background=False)
         unique_id = speech.uniqueId
         del speech.__parent__[speech.__name__]
-        log.info('Text-to-speech %s successfully deleted.', unique_id)
+        log.info('Deleted %s', unique_id)
diff --git a/core/src/zeit/speech/tests/test_connection.py b/core/src/zeit/speech/tests/test_connection.py
index dd551b77c6..fb48240b56 100644
--- a/core/src/zeit/speech/tests/test_connection.py
+++ b/core/src/zeit/speech/tests/test_connection.py
@@ -143,5 +143,5 @@ def test_unable_to_remove_anything_because_article_is_missing(self):
         self.repository.connector.search_result = []
         with mock.patch('zeit.speech.connection.Speech._find', return_value=audio):
             Speech().delete(TTS_DELETED)
-        assert f'No article found for Text-to-speech {audio}' in self.caplog.text
-        assert not self.repository.has_key('audio')
+        assert f'No article found for {audio}' in self.caplog.text
+        assert 'audio' not in self.repository