edx-platform/common/djangoapps/performance/tests/test_logs.py

"""Tests that performance data is successfully logged."""
import datetime
import dateutil
import json
import mock
import unittest

import logging
from StringIO import StringIO

from django.test import TestCase
from django.test.client import RequestFactory
from performance.views import performance_log


class PerformanceTrackingTest(TestCase):
    """
    Tests that performance logs correctly handle events
    """

    def setUp(self):
        super(PerformanceTrackingTest, self).setUp()
        self.request_factory = RequestFactory()
        self.stream = StringIO()
        self.handler = logging.StreamHandler(self.stream)
        self.log = logging.getLogger()
        self.log.setLevel(logging.INFO)
        for handler in self.log.handlers:
            self.log.removeHandler(handler)
        self.log.addHandler(self.handler)
        self.addCleanup(self.log.removeHandler, self.handler)
        self.addCleanup(self.handler.close)

    def test_empty_get(self):
        request = self.request_factory.get('/performance')
        pre_time = datetime.datetime.utcnow()
        performance_log(request)
        post_time = datetime.datetime.utcnow()
        self.handler.flush()
        logged_value = json.loads(self.stream.getvalue().strip())
        self.assertEqual(logged_value['accept_language'], '')
        self.assertEqual(logged_value['agent'], '')
        self.assertEqual(logged_value['event'], '')
        self.assertEqual(logged_value['event_source'], 'browser')
        self.assertEqual(logged_value['expgroup'], '')
        self.assertEqual(logged_value['id'], '')
        self.assertEqual(logged_value['page'], '')
        self.assertEqual(logged_value['referer'], '')
        self.assertEqual(logged_value['value'], '')
        logged_time = dateutil.parser.parse(logged_value['time']).replace(tzinfo=None)
        self.assertTrue(pre_time <= logged_time)
        self.assertTrue(post_time >= logged_time)

    def test_empty_post(self):
        request = self.request_factory.post('/performance')
        pre_time = datetime.datetime.utcnow()
        performance_log(request)
        post_time = datetime.datetime.utcnow()
        self.handler.flush()
        logged_value = json.loads(self.stream.getvalue().strip())
        self.assertEqual(logged_value['accept_language'], '')
        self.assertEqual(logged_value['agent'], '')
        self.assertEqual(logged_value['event'], '')
        self.assertEqual(logged_value['event_source'], 'browser')
        self.assertEqual(logged_value['expgroup'], '')
        self.assertEqual(logged_value['id'], '')
        self.assertEqual(logged_value['page'], '')
        self.assertEqual(logged_value['referer'], '')
        self.assertEqual(logged_value['value'], '')
        logged_time = dateutil.parser.parse(logged_value['time']).replace(tzinfo=None)
        self.assertTrue(pre_time <= logged_time)
        self.assertTrue(post_time >= logged_time)

    def test_populated_get(self):
        request = self.request_factory.get('/performance',
                                           {'event': "a_great_event",
                                            'id': "12345012345",
                                            'expgroup': "17", 'page': "atestpage",
                                            'value': "100234"})
        request.META['HTTP_ACCEPT_LANGUAGE'] = "en"
        request.META['HTTP_REFERER'] = "https://www.edx.org/evilpage"
        request.META['HTTP_USER_AGENT'] = "Mozilla/5.0"
        request.META['REMOTE_ADDR'] = "18.19.20.21"
        request.META['SERVER_NAME'] = "some-aws-server"
        pre_time = datetime.datetime.utcnow()
        performance_log(request)
        post_time = datetime.datetime.utcnow()
        self.handler.flush()
        logged_value = json.loads(self.stream.getvalue().strip())
        self.assertEqual(logged_value['accept_language'], 'en')
        self.assertEqual(logged_value['agent'], 'Mozilla/5.0')
        self.assertEqual(logged_value['event'], 'a_great_event')
        self.assertEqual(logged_value['event_source'], 'browser')
        self.assertEqual(logged_value['expgroup'], '17')
        self.assertEqual(logged_value['host'], 'some-aws-server')
        self.assertEqual(logged_value['id'], '12345012345')
        self.assertEqual(logged_value['ip'], '18.19.20.21')
        self.assertEqual(logged_value['page'], 'atestpage')
        self.assertEqual(logged_value['referer'], 'https://www.edx.org/evilpage')
        self.assertEqual(logged_value['value'], '100234')
        logged_time = dateutil.parser.parse(logged_value['time']).replace(tzinfo=None)
        self.assertTrue(pre_time <= logged_time)
        self.assertTrue(post_time >= logged_time)

    def test_populated_post(self):
        request = self.request_factory.post('/performance',
                                            {'event': "a_great_event",
                                             'id': "12345012345",
                                             'expgroup': "17", 'page': "atestpage",
                                             'value': "100234"})
        request.META['HTTP_ACCEPT_LANGUAGE'] = "en"
        request.META['HTTP_REFERER'] = "https://www.edx.org/evilpage"
        request.META['HTTP_USER_AGENT'] = "Mozilla/5.0"
        request.META['REMOTE_ADDR'] = "18.19.20.21"
        request.META['SERVER_NAME'] = "some-aws-server"
        pre_time = datetime.datetime.utcnow()
        performance_log(request)
        post_time = datetime.datetime.utcnow()
        self.handler.flush()
        logged_value = json.loads(self.stream.getvalue().strip())
        self.assertEqual(logged_value['accept_language'], 'en')
        self.assertEqual(logged_value['agent'], 'Mozilla/5.0')
        self.assertEqual(logged_value['event'], 'a_great_event')
        self.assertEqual(logged_value['event_source'], 'browser')
        self.assertEqual(logged_value['expgroup'], '17')
        self.assertEqual(logged_value['host'], 'some-aws-server')
        self.assertEqual(logged_value['id'], '12345012345')
        self.assertEqual(logged_value['ip'], '18.19.20.21')
        self.assertEqual(logged_value['page'], 'atestpage')
        self.assertEqual(logged_value['referer'], 'https://www.edx.org/evilpage')
        self.assertEqual(logged_value['value'], '100234')
        logged_time = dateutil.parser.parse(logged_value['time']).replace(tzinfo=None)
        self.assertTrue(pre_time <= logged_time)
        self.assertTrue(post_time >= logged_time)