Trap formatting errors

Trap errors when trying to use translated messages as format strings so
translations don't break applications. Log the error, with the format
string (without interpolated values) and the original message so a bug
report can include it to make fixing the translation easier.

Co-Authored-By: Doug Hellmann <doug@doughellmann.com>

Change-Id: I5c711b4654b5b2e591bcf365401ff35f7224fe82
Closes-bug: #1339337

2 files changed, 114 insertions, 14 deletions

diff --git a/oslo_i18n/_message.py b/oslo_i18n/_message.py
index 44a48b2..6dc02d1 100644
--- a/oslo_i18n/_message.py
+++ b/oslo_i18n/_message.py
@@ -19,6 +19,7 @@
 import copy
 import gettext
 import locale
+import logging
 import os
 
 import six
@@ -30,6 +31,9 @@ from oslo_i18n import _translate
 CONTEXT_SEPARATOR = "\x04"
 
 
+LOG = logging.getLogger(__name__)
+
+
 class Message(six.text_type):
     """A Message object is a unicode object that can be translated.
 
@@ -90,9 +94,7 @@ class Message(six.text_type):
         translated_params = _translate.translate_args(self.params,
                                                       desired_locale)
 
-        translated_message = translated_message % translated_params
-
-        return translated_message
+        return self._safe_translate(translated_message, translated_params)
 
     @staticmethod
     def _translate_msgid(msgid, domain, desired_locale=None,
@@ -138,12 +140,32 @@ class Message(six.text_type):
 
         return translated_message
 
+    def _safe_translate(self, translated_message, translated_params):
+        try:
+            translated_message = translated_message % translated_params
+        except (KeyError, TypeError) as err:
+            # KeyError for parameters named in the translated_message
+            # but not found in translated_params and TypeError for
+            # type strings that do not match the type of the
+            # parameter.
+            #
+            # Log the error translating the message and use the
+            # original message string so the translator's bad message
+            # catalog doesn't break the caller.
+            LOG.debug(
+                (u'Failed to insert replacement values into translated '
+                 u'message %s (Original: %r): %s'),
+                translated_message, self.msgid, err)
+            translated_message = self.msgid % translated_params
+
+        return translated_message
+
     def __mod__(self, other):
         # When we mod a Message we want the actual operation to be performed
         # by the parent class (i.e. unicode()), the only thing  we do here is
         # save the original msgid and the parameters in case of a translation
         params = self._sanitize_mod_params(other)
-        unicode_mod = super(Message, self).__mod__(params)
+        unicode_mod = self._safe_translate(six.text_type(self), params)
         modded = Message(self.msgid,
                          msgtext=unicode_mod,
                          params=params,
diff --git a/oslo_i18n/tests/test_message.py b/oslo_i18n/tests/test_message.py
index 5fb6705..036ef5e 100644
--- a/oslo_i18n/tests/test_message.py
+++ b/oslo_i18n/tests/test_message.py
@@ -157,6 +157,41 @@ class MessageTestCase(test_base.BaseTestCase):
         self.assertEqual(expected, result)
         self.assertEqual(expected, result.translate())
 
+    def test_mod_with_wrong_field_type_in_trans(self):
+        msgid = "Correct type %(arg1)s"
+        params = {'arg1': 'test1'}
+        with mock.patch('gettext.translation') as trans:
+            # Set up ugettext to return the original message with the
+            # correct format string.
+            trans.return_value.ugettext.return_value = msgid
+            # Build a message and give it some parameters.
+            result = _message.Message(msgid) % params
+            # Now set up ugettext to return the translated version of
+            # the original message, with a bad format string.
+            wrong_type = u'Wrong type %(arg1)d'
+            if six.PY3:
+                trans.return_value.gettext.return_value = wrong_type
+            else:
+                trans.return_value.ugettext.return_value = wrong_type
+            trans_result = result.translate()
+            expected = msgid % params
+            self.assertEqual(expected, trans_result)
+
+    def test_mod_with_wrong_field_type(self):
+        msgid = "Test that we handle unused args %(arg1)d"
+        params = {'arg1': 'test1'}
+
+        self.assertRaises(TypeError, lambda: _message.Message(msgid) % params)
+
+    def test_mod_with_missing_arg(self):
+        msgid = "Test that we handle missing args %(arg1)s %(arg2)s"
+        params = {'arg1': 'test1'}
+
+        e = self.assertRaises(KeyError,
+                              lambda: _message.Message(msgid) % params)
+        self.assertIn('arg2', six.text_type(e),
+                      'Missing key \'arg2\' was not flagged')
+
     def test_mod_with_integer_parameters(self):
         msgid = "Some string with params: %d"
         params = [0, 1, 10, 24124]
@@ -258,16 +293,6 @@ class MessageTestCase(test_base.BaseTestCase):
         # Make sure unused params still there
         self.assertEqual(result.params.keys(), params.keys())
 
-    def test_mod_with_missing_named_parameters(self):
-        msgid = ("Some string with params: %(param1)s %(param2)s"
-                 " and a missing one %(missing)s")
-        params = {'param1': 'test',
-                  'param2': 'test2'}
-
-        test_me = lambda: _message.Message(msgid) % params
-        # Just like with strings missing named parameters raise KeyError
-        self.assertRaises(KeyError, test_me)
-
     def test_add_disabled(self):
         msgid = "A message"
         test_me = lambda: _message.Message(msgid) + ' some string'
@@ -353,6 +378,59 @@ class MessageTestCase(test_base.BaseTestCase):
         self.assertEqual(default_translation, msg.translate('XX'))
 
     @mock.patch('gettext.translation')
+    @mock.patch('oslo_i18n._message.LOG')
+    def test_translate_message_bad_translation(self, mock_log,
+                                               mock_translation):
+        message_with_params = 'A message: %s'
+        es_translation = 'A message in Spanish: %s %s'
+        param = 'A Message param'
+
+        translations = {message_with_params: es_translation}
+        translator = fakes.FakeTranslations.translator({'es': translations})
+        mock_translation.side_effect = translator
+
+        msg = _message.Message(message_with_params)
+        msg = msg % param
+        self.assertFalse(mock_log.debug.called)
+
+        default_translation = message_with_params % param
+        self.assertEqual(default_translation, msg.translate('es'))
+        mock_log.debug.assert_called_with(('Failed to insert replacement '
+                                           'values into translated message %s '
+                                           '(Original: %r): %s'),
+                                          es_translation,
+                                          message_with_params,
+                                          mock.ANY)
+
+    @mock.patch('gettext.translation')
+    @mock.patch('locale.getdefaultlocale', return_value=('es', ''))
+    @mock.patch('oslo_i18n._message.LOG')
+    def test_translate_message_bad_default_translation(self, mock_log,
+                                                       mock_local,
+                                                       mock_translation):
+        message_with_params = 'A message: %s'
+        es_translation = 'A message in Spanish: %s %s'
+        param = 'A Message param'
+
+        translations = {message_with_params: es_translation}
+        translator = fakes.FakeTranslations.translator({'es': translations})
+        mock_translation.side_effect = translator
+
+        msg = _message.Message(message_with_params)
+        msg = msg % param
+        mock_log.debug.assert_called_with(('Failed to insert replacement '
+                                           'values into translated message %s '
+                                           '(Original: %r): %s'),
+                                          es_translation,
+                                          message_with_params,
+                                          mock.ANY)
+        mock_log.reset_mock()
+
+        default_translation = message_with_params % param
+        self.assertEqual(default_translation, msg)
+        self.assertFalse(mock_log.debug.called)
+
+    @mock.patch('gettext.translation')
     def test_translate_message_with_object_param(self, mock_translation):
         message_with_params = 'A message: %s'
         es_translation = 'A message in Spanish: %s'