slow queries: Use internal_send_stream_message().

Note that while the test mocks the actual message
send, we now have a `get_stream` call in the queue
worker, so we have to set up a real stream for
testing (or we could have mocked that as well, but
it didn't seem necessary).  The setup queries add
to the amount of queries reported by the test,
plus the `get_stream` call.  I just made the
query count a digits regex, which is a little bit
lame, but I don't think it's worth risking test
flakes for this.
This commit is contained in:
Steve Howell
2020-02-11 15:06:29 +00:00
committed by Tim Abbott
parent e37d660d19
commit 2e8dec233e
3 changed files with 33 additions and 15 deletions

View File

@@ -2,12 +2,14 @@ import time
from typing import List
from bs4 import BeautifulSoup
from django.conf import settings
from django.test import override_settings
from unittest.mock import Mock, patch
from zerver.lib.actions import create_stream_if_needed
from zerver.lib.realm_icon import get_realm_icon_url
from zerver.lib.test_classes import ZulipTestCase
from zerver.middleware import is_slow_query, write_log_line
from zerver.models import get_realm
from zerver.models import get_realm, get_system_bot
class SlowQueryTest(ZulipTestCase):
SLOW_QUERY_TIME = 10
@@ -33,6 +35,9 @@ class SlowQueryTest(ZulipTestCase):
@override_settings(SLOW_QUERY_LOGS_STREAM="logs")
@patch('logging.info')
def test_slow_query_log(self, mock_logging_info: Mock) -> None:
error_bot = get_system_bot(settings.ERROR_BOT)
create_stream_if_needed(error_bot.realm, settings.SLOW_QUERY_LOGS_STREAM)
self.log_data['time_started'] = time.time() - self.SLOW_QUERY_TIME
write_log_line(self.log_data, path='/socket/open', method='SOCKET',
remote_ip='123.456.789.012', email='unknown', client_name='?')
@@ -45,13 +50,14 @@ class SlowQueryTest(ZulipTestCase):
@override_settings(ERROR_BOT=None)
@patch('logging.info')
@patch('zerver.lib.actions.internal_send_message')
def test_slow_query_log_without_error_bot(self, mock_internal_send_message: Mock,
@patch('zerver.lib.actions.internal_send_stream_message')
def test_slow_query_log_without_error_bot(self,
mock_internal_send_stream_message: Mock,
mock_logging_info: Mock) -> None:
self.log_data['time_started'] = time.time() - self.SLOW_QUERY_TIME
write_log_line(self.log_data, path='/socket/open', method='SOCKET',
remote_ip='123.456.789.012', email='unknown', client_name='?')
mock_internal_send_message.assert_not_called()
mock_internal_send_stream_message.assert_not_called()
class OpenGraphTest(ZulipTestCase):
def check_title_and_description(self, path: str, title: str,

View File

@@ -9,6 +9,7 @@ from django.test import override_settings
from mock import patch, MagicMock
from typing import Any, Callable, Dict, List, Mapping, Tuple
from zerver.lib.actions import create_stream_if_needed
from zerver.lib.email_mirror import RateLimitedRealmMirror
from zerver.lib.email_mirror_helpers import encode_email_address
from zerver.lib.queue import MAX_REQUEST_RETRIES
@@ -83,8 +84,10 @@ class WorkerTest(ZulipTestCase):
fake_client = self.FakeClient()
worker = SlowQueryWorker()
create_stream_if_needed(error_bot.realm, 'errors')
send_mock = patch(
'zerver.worker.queue_processors.internal_send_message'
'zerver.worker.queue_processors.internal_send_stream_message'
)
with send_mock as sm, loopworker_sleep_mock as tm:
@@ -105,12 +108,11 @@ class WorkerTest(ZulipTestCase):
sm.assert_called_once()
args = [c[0] for c in sm.call_args_list][0]
self.assertEqual(args[0], error_bot.realm)
self.assertEqual(args[1], error_bot.email)
self.assertEqual(args[2], "stream")
self.assertEqual(args[3], "errors")
self.assertEqual(args[4], "testserver: slow queries")
self.assertEqual(args[1].email, error_bot.email)
self.assertEqual(args[2].name, "errors")
self.assertEqual(args[3], "testserver: slow queries")
# Testing for specific query times can lead to test discrepancies.
logging_info = re.sub(r'\(db: [0-9]+ms/13q\)', '', args[5])
logging_info = re.sub(r'\(db: [0-9]+ms/\d+q\)', '', args[4])
self.assertEqual(logging_info, ' 127.0.0.1 GET 200 -1000ms '
' /test/ (test@zulip.com via website) (test@zulip.com)\n')

View File

@@ -26,7 +26,7 @@ from zerver.lib.push_notifications import handle_push_notification, handle_remov
initialize_push_notifications, clear_push_device_tokens
from zerver.lib.actions import do_send_confirmation_email, \
do_update_user_activity, do_update_user_activity_interval, do_update_user_presence, \
internal_send_message, internal_send_private_message, notify_realm_export, \
internal_send_stream_message, internal_send_private_message, notify_realm_export, \
render_incoming_message, do_update_embedded_data, do_mark_stream_messages_as_read
from zerver.lib.url_preview import preview as url_preview
from zerver.lib.digest import handle_digest_email
@@ -38,7 +38,7 @@ from zerver.lib.streams import access_stream_by_id
from zerver.lib.db import reset_queries
from zerver.context_processors import common_context
from zerver.lib.outgoing_webhook import do_rest_call, get_outgoing_webhook_service_handler
from zerver.models import get_bot_services, RealmAuditLog
from zerver.models import get_bot_services, get_stream, RealmAuditLog
from zulip_bots.lib import ExternalBotHandler, extract_query_without_mention
from zerver.lib.bot_lib import EmbeddedBotHandler, get_bot_handler, EmbeddedBotQuitException
from zerver.lib.exceptions import RateLimited
@@ -453,9 +453,19 @@ class SlowQueryWorker(LoopQueueProcessingWorker):
for event in slow_query_events:
content += " %s\n" % (event["query"],)
error_bot_realm = get_system_bot(settings.ERROR_BOT).realm
internal_send_message(error_bot_realm, settings.ERROR_BOT,
"stream", settings.SLOW_QUERY_LOGS_STREAM, topic, content)
error_bot = get_system_bot(settings.ERROR_BOT)
realm = error_bot.realm
errors_stream = get_stream(
settings.SLOW_QUERY_LOGS_STREAM,
realm
)
internal_send_stream_message(
realm,
error_bot,
errors_stream,
topic,
content
)
@assign_queue('digest_emails')
class DigestWorker(QueueProcessingWorker): # nocoverage