Fix database encoding and exception handling in update service (#14851)

* Fix database encoding and exception handling in update service

* Remove leftover ipdb

* Cleaner way to override SERVICES_DATABASE in tests through pytest fixture

* Remove now unused imports

conftest.py

@@ -81,6 +81,11 @@ def mock_basket(settings):
         json={'status': 'ok', 'token': USER_TOKEN})
 
 
+@pytest.fixture(autouse=True)
+def update_services_db_name_to_follow_test_db_name(db, settings, request):
+    settings.SERVICES_DATABASE['NAME'] = settings.DATABASES['default']['NAME']
+
+
 def pytest_configure(config):
     import django
     # Forcefully call `django.setup`, pytest-django tries to be very lazy

services/update.py

@@ -1,5 +1,4 @@
 import json
-import sys
 
 from django.utils.encoding import force_bytes
 from email.utils import formatdate
@@ -24,7 +23,7 @@ import olympia.core.logger
 # Go configure the log.
 log_configure()
 
-error_log = olympia.core.logger.getLogger('z.services')
+log = olympia.core.logger.getLogger('z.services')
 
 
 class Update(object):
@@ -155,7 +154,6 @@ class Update(object):
             sql.append('AND appmax.version_int >= %(version_int)s ')
 
         sql.append('ORDER BY versions.id DESC LIMIT 1;')
-
         self.cursor.execute(''.join(sql), data)
         result = self.cursor.fetchone()
 
@@ -237,11 +235,6 @@ class Update(object):
                 ('Content-Length', str(length))]
 
 
-def log_exception(data):
-    (typ, value, traceback) = sys.exc_info()
-    error_log.error(u'Type: %s, %s. Query: %s' % (typ, value, data))
-
-
 def application(environ, start_response):
     status = '200 OK'
     with statsd.timer('services.update'):
@@ -251,7 +244,7 @@ def application(environ, start_response):
             update = Update(data, compat_mode)
             output = force_bytes(update.get_output())
             start_response(status, update.get_headers(len(output)))
-        except Exception:
-            log_exception(data)
+        except Exception as e:
+            log.exception(e)
             raise
     return [output]

services/utils.py

@@ -76,7 +76,8 @@ def get_cdn_url(id, row):
 def getconn():
     db = settings.SERVICES_DATABASE
     return mysql.connect(host=db['HOST'], user=db['USER'],
-                         passwd=db['PASSWORD'], db=db['NAME'])
+                         passwd=db['PASSWORD'], db=db['NAME'],
+                         charset=db['OPTIONS']['charset'])
 
 
 mypool = pool.QueuePool(getconn, max_overflow=10, pool_size=5, recycle=300)

src/olympia/addons/tests/test_update.py

@@ -5,13 +5,15 @@ from unittest import mock
 from datetime import datetime, timedelta
 from email import utils
 
+from django.conf import settings
 from django.db import connection
+from django.test.testcases import TransactionTestCase
 
 from services import update
 
 from olympia import amo
 from olympia.addons.models import Addon
-from olympia.amo.tests import TestCase
+from olympia.amo.tests import addon_factory, TestCase
 from olympia.applications.models import AppVersion
 from olympia.files.models import File
 from olympia.versions.models import ApplicationsVersions, Version
@@ -406,37 +408,6 @@ class TestDefaultToCompat(VersionCheckMixin, TestCase):
                     expected['-'.join([version, mode])]
                 )
 
-    def test_application(self):
-        # Basic test making sure application() is returning the output of
-        # Update.get_output(). Have to mock Update(): otherwise, the real
-        # database would be hit, not the test one, because of how services
-        # use a different setting and database connection APIs.
-        environ = {
-            'QUERY_STRING': ''
-        }
-        self.start_response_call_count = 0
-
-        expected_headers = [
-            ('FakeHeader', 'FakeHeaderValue')
-        ]
-
-        expected_output = b'{"fake": "output"}'
-
-        def start_response_inspector(status, headers):
-            self.start_response_call_count += 1
-            assert status == '200 OK'
-            assert headers == expected_headers
-
-        with mock.patch('services.update.Update') as UpdateMock:
-            update_instance = UpdateMock.return_value
-            update_instance.get_headers.return_value = expected_headers
-            update_instance.get_output.return_value = expected_output
-            output = update.application(environ, start_response_inspector)
-        assert self.start_response_call_count == 1
-        # Output is an array with a single string containing the body of the
-        # response.
-        assert output == [expected_output]
-
     def test_baseline(self):
         # Tests simple add-on (non-binary-components, non-strict).
         self.check(self.expected)
@@ -651,3 +622,110 @@ class TestResponse(VersionCheckMixin, TestCase):
         assert (
             json.loads(instance.get_output()) ==
             instance.get_no_updates_output())
+
+    def test_application(self):
+        # Basic test making sure application() is returning the output of
+        # Update.get_output(). Have to mock Update(): otherwise, even though
+        # we're setting SERVICES_DATABASE to point to the test database in
+        # settings_test.py, we wouldn't see results because the data wouldn't
+        # exist with the cursor the update service is using, which is different
+        # from the one used by django tests.
+        environ = {
+            'QUERY_STRING': ''
+        }
+        self.start_response_call_count = 0
+
+        expected_headers = [
+            ('FakeHeader', 'FakeHeaderValue')
+        ]
+
+        expected_output = b'{"fake": "output"}'
+
+        def start_response_inspector(status, headers):
+            self.start_response_call_count += 1
+            assert status == '200 OK'
+            assert headers == expected_headers
+
+        with mock.patch('services.update.Update') as UpdateMock:
+            update_instance = UpdateMock.return_value
+            update_instance.get_headers.return_value = expected_headers
+            update_instance.get_output.return_value = expected_output
+            output = update.application(environ, start_response_inspector)
+        assert self.start_response_call_count == 1
+        # Output is an array with a single string containing the body of the
+        # response.
+        assert output == [expected_output]
+
+    @mock.patch('services.update.log')
+    @mock.patch('services.update.Update')
+    def test_exception_handling(self, UpdateMock, log_mock):
+        """Test ensuring exceptions are raised and logged properly."""
+        class CustomException(Exception):
+            pass
+
+        self.inspector_call_count = 0
+        update_instance = UpdateMock.return_value
+        update_instance.get_output.side_effect = CustomException('Boom!')
+
+        def inspector(status, headers):
+            self.inspector_call_count += 1
+
+        with self.assertRaises(CustomException):
+            update.application({'QUERY_STRING': ''}, inspector)
+        assert self.inspector_call_count == 0
+
+        # The log should be present.
+        assert log_mock.exception.call_count == 1
+        log_mock.exception.assert_called_with(
+            update_instance.get_output.side_effect)
+
+
+# This test needs to be a TransactionTestCase because we want to test the
+# behavior of database cursor created by the update service. Since the data is
+# written by a different cursor, it needs to be committed for the update
+# service to see it (Other tests above that aren't explicitly mocking the
+# service and care about the output cheat and override the cursor to use
+# django's).
+class TestUpdateConnectionEncoding(TransactionTestCase):
+    def setUp(self):
+        self.addon = addon_factory()
+
+    def test_service_database_setting(self):
+        from services.utils import mypool
+
+        expected_name = settings.DATABASES['default']['NAME']
+        assert 'test' in expected_name
+        assert settings.SERVICES_DATABASE['NAME'] == expected_name
+
+        connection = mypool.connect()
+        cursor = connection.cursor()
+        cursor.execute('SELECT DATABASE();')
+        assert cursor.fetchone()[0] == expected_name
+        connection.close()
+
+    def test_mypool_encoding(self):
+        from services.utils import mypool
+
+        connection = mypool.connect()
+        assert connection.connection.encoding == 'utf8'
+        connection.close()
+
+    def test_unicode_data(self):
+        # To trigger the error this test is trying to cover, we need 2 things:
+        # - An update request that would be considered 'valid', i.e. the
+        #   necessary parameters are presentTestUpdateConnectionEncoding and
+        #   the add-on exists.
+        # - A database cursor instantiated from the update service, not by
+        #   django tests.
+        # Note that this test would hang before the fix to pass charset when
+        # connecting in services.utils.getconn().
+        data = {
+            'id': self.addon.guid,
+            'reqVersion': '2鎈',
+            'appID': amo.FIREFOX.guid,
+            'appVersion': '78.0',
+        }
+        instance = update.Update(data)
+        output = instance.get_output()
+        update_data = json.loads(output)
+        assert update_data