Make the update service use the regular logging settings (#19043)

* Make the update service use the regular logging settings

Also configure logging at startup instead of import time to minimize
impact on other bits of code, notably tests from the rest of
addons-server

* Remove services/utils.py entirely
This commit is contained in:
Mathieu Pillard 2022-04-04 11:15:49 +02:00 коммит произвёл GitHub
Родитель 70c4850455
Коммит 82532acec1
Не найден ключ, соответствующий данной подписи
Идентификатор ключа GPG: 4AEE18F83AFDEB23
3 изменённых файлов: 43 добавлений и 72 удалений

Просмотреть файл

@ -1,15 +1,14 @@
import json
import logging.config
from django.utils.encoding import force_bytes
from email.utils import formatdate
import MySQLdb as mysql
from urllib.parse import parse_qsl
import sqlalchemy.pool as pool
from time import time
from services.utils import (
log_configure,
mypool,
settings,
)
from services.settings import settings
# This has to be imported after the settings so statsd knows where to log to.
from django_statsd.clients import statsd
@ -19,15 +18,23 @@ from olympia.versions.compare import version_int
import olympia.core.logger
# Go configure the log.
log_configure()
def get_connection():
db = settings.SERVICES_DATABASE
return mysql.connect(
host=db['HOST'],
user=db['USER'],
passwd=db['PASSWORD'],
db=db['NAME'],
charset=db['OPTIONS']['charset'],
)
log = olympia.core.logger.getLogger('z.services')
pool = pool.QueuePool(get_connection, max_overflow=10, pool_size=5, recycle=300)
class Update:
def __init__(self, data, compat_mode='strict'):
self.conn, self.cursor = None, None
self.connection, self.cursor = None, None
self.data = data.copy()
self.data['row'] = {}
self.version_int = 0
@ -38,8 +45,8 @@ class Update:
# If you accessing this from unit tests, then before calling
# is valid, you can assign your own cursor.
if not self.cursor:
self.conn = mypool.connect()
self.cursor = self.conn.cursor()
self.connection = pool.connect()
self.cursor = self.connection.cursor()
data = self.data
# Version can be blank.
@ -175,8 +182,8 @@ class Update:
else:
contents = self.get_error_output()
self.cursor.close()
if self.conn:
self.conn.close()
if self.connection:
self.connection.close()
return json.dumps(contents)
def get_error_output(self):
@ -227,6 +234,14 @@ class Update:
def application(environ, start_response):
# Logging has to be configured before it can be used. In the django app
# this is done through settings.LOGGING but the update service is its own
# separate wsgi app.
logging.config.dictConfig(settings.LOGGING)
# Now we can get our logger instance.
log = olympia.core.logger.getLogger('z.services')
status = '200 OK'
with statsd.timer('services.update'):
data = dict(parse_qsl(environ['QUERY_STRING']))

Просмотреть файл

@ -1,45 +0,0 @@
import logging
import logging.config
import MySQLdb as mysql
import sqlalchemy.pool as pool
from services.settings import settings
import olympia.core.logger
def getconn():
db = settings.SERVICES_DATABASE
return mysql.connect(
host=db['HOST'],
user=db['USER'],
passwd=db['PASSWORD'],
db=db['NAME'],
charset=db['OPTIONS']['charset'],
)
mypool = pool.QueuePool(getconn, max_overflow=10, pool_size=5, recycle=300)
def log_configure():
"""You have to call this to explicitly configure logging."""
cfg = {
'version': 1,
'filters': {},
'handlers': {
'mozlog': {
'level': 'DEBUG',
'class': 'logging.StreamHandler',
'formatter': 'json',
},
},
'formatters': {
'json': {
'()': olympia.core.logger.JsonFormatter,
'logger_name': 'http_app_addons',
},
},
}
logging.config.dictConfig(cfg)

Просмотреть файл

@ -548,9 +548,9 @@ class TestResponse(VersionCheckMixin, TestCase):
# response.
assert output == [expected_output]
@mock.patch('services.update.log')
@mock.patch('services.update.logging.config.dictConfig')
@mock.patch('services.update.Update')
def test_exception_handling(self, UpdateMock, log_mock):
def test_exception_handling(self, UpdateMock, dictConfigMock):
"""Test ensuring exceptions are raised and logged properly."""
class CustomException(Exception):
@ -564,12 +564,17 @@ class TestResponse(VersionCheckMixin, TestCase):
self.inspector_call_count += 1
with self.assertRaises(CustomException):
update.application({'QUERY_STRING': ''}, inspector)
with self.assertLogs(level='ERROR') as logs:
update.application({'QUERY_STRING': ''}, inspector)
assert self.inspector_call_count == 0
assert len(logs.records) == 1
assert logs.records[0].message == 'Boom!'
assert logs.records[0].exc_info[1] == update_instance.get_output.side_effect
# The log should be present.
assert log_mock.exception.call_count == 1
log_mock.exception.assert_called_with(update_instance.get_output.side_effect)
# Ensure we had set up logging correctly. We can't let the actual call
# go through, it would override the loggers assertLogs() set up.
assert dictConfigMock.call_count == 1
assert dictConfigMock.call_args[0] == (settings.LOGGING,)
# This test needs to be a TransactionTestCase because we want to test the
@ -583,22 +588,18 @@ class TestUpdateConnectionEncoding(TransactionTestCase):
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()
connection = update.pool.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()
def test_connection_pool_encoding(self):
connection = update.pool.connect()
assert connection.connection.encoding == 'utf8'
connection.close()
@ -610,7 +611,7 @@ class TestUpdateConnectionEncoding(TransactionTestCase):
# - 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().
# connecting in get_connection().
data = {
'id': self.addon.guid,
'reqVersion': '2鎈',