Python testfixtures.LogCapture() Examples

def test_check_output_good_output_fractional_score_zero_point_oh(sys):
    with LogCapture() as logs:
        docker_mock = MagicMock()
        container = {
            "Id": "myimageId"
        }
        args = argparse.Namespace()
        args.timeout = 300
        args.no_rm = False

        docker_mock.wait.return_value = 0
        docker_mock.logs.side_effect = [
            '',
            '{"fractionalScore":0.0, "feedback": "Helpful comment!"}'
        ]
        # Run the function under test
        grade.run_container(docker_mock, container, args)
    logs.check(
        ('root', 'INFO', 'Debug log:'),
        ('root', 'DEBUG', "About to remove container: {'Id': 'myimageId'}")
    )
    assert not sys.exit.called, "sys.exit should not be called!" 

def test_check_output_bad_isCorrect(sys):
    with LogCapture() as logs:
        docker_mock = MagicMock()
        container = {
            "Id": "myimageId"
        }
        args = argparse.Namespace()
        args.timeout = 300
        args.no_rm = False

        docker_mock.wait.return_value = 0
        docker_mock.logs.side_effect = [
            '',
            '{"isCorrect":"true-string-is-not-true","feedback":"You win!"}'
        ]
        # Run the function under test
        grade.run_container(docker_mock, container, args)
    logs.check(
        ('root', 'INFO', 'Debug log:'),
        ('root', 'ERROR', "Field 'isCorrect' is not a boolean value."),
        ('root', 'DEBUG', "About to remove container: {'Id': 'myimageId'}")
    )
    sys.exit.assert_called_with(1) 

def test_check_output_fractional_score_boolean(sys):
    with LogCapture() as logs:
        docker_mock = MagicMock()
        container = {
            "Id": "myimageId"
        }
        args = argparse.Namespace()
        args.timeout = 300
        args.no_rm = False

        docker_mock.wait.return_value = 0
        docker_mock.logs.side_effect = [
            '',
            '{"fractionalScore": false, "feedback": "wheeeee"}'
        ]
        # Run the function under test
        grade.run_container(docker_mock, container, args)
    logs.check(
        ('root', 'INFO', 'Debug log:'),
        ('root', 'ERROR', "Field 'fractionalScore' must be a decimal."),
        ('root', 'DEBUG', "About to remove container: {'Id': 'myimageId'}")
    )
    sys.exit.assert_called_with(1) 

def test_check_output_fractional_score_too_low(sys):
    with LogCapture() as logs:
        docker_mock = MagicMock()
        container = {
            "Id": "myimageId"
        }
        args = argparse.Namespace()
        args.timeout = 300
        args.no_rm = False

        docker_mock.wait.return_value = 0
        docker_mock.logs.side_effect = [
            '',
            '{"fractionalScore":-1.1, "feedback": "wheeeee"}'
        ]
        # Run the function under test
        grade.run_container(docker_mock, container, args)
    logs.check(
        ('root', 'INFO', 'Debug log:'),
        ('root', 'ERROR', "Field 'fractionalScore' must be >= 0."),
        ('root', 'DEBUG', "About to remove container: {'Id': 'myimageId'}")
    )
    sys.exit.assert_called_with(1) 

def test_no_feature_branch(self):
        self._mock_repo()
        self._mock_branch(self.branch)
        other_branch = self._get_expected_branch("not-a-feature-branch")
        self.mock_pulls()
        branches = [other_branch]
        branches = self._mock_branches(branches)
        with LogCapture() as log:
            task = self._create_task()
            task()
            log_lines = self._get_log_lines(log)

            expected = [
                ("INFO", "Beginning task: MergeBranch"),
                ("INFO", ""),
                ("DEBUG", "Skipping branch master: is source branch"),
                (
                    "DEBUG",
                    "Skipping branch not-a-feature-branch: does not match prefix feature/",
                ),
            ]
            self.assertEqual(expected, log_lines)
        self.assertEqual(4, len(responses.calls)) 

def setUp(self):

        self.my_dir, self.panoptes_test_conf_file = get_test_conf_file()
        self._panoptes_resource = PanoptesResource(resource_site="test", resource_class="test",
                                                   resource_subclass="test", resource_type="test", resource_id="test",
                                                   resource_endpoint="test", resource_creation_timestamp=_TIMESTAMP,
                                                   resource_plugin="test")

        self._panoptes_context = PanoptesContext(self.panoptes_test_conf_file,
                                                 key_value_store_class_list=[PanoptesTestKeyValueStore,
                                                                             PanoptesResourcesKeyValueStore,
                                                                             PanoptesPollingPluginKeyValueStore,
                                                                             PanoptesSecretsStore,
                                                                             PanoptesPollingPluginAgentKeyValueStore,
                                                                             PanoptesDiscoveryPluginAgentKeyValueStore,
                                                                             PanoptesDiscoveryPluginKeyValueStore],
                                                 create_message_producer=False, async_message_producer=False,
                                                 create_zookeeper_client=True)
        self._runner_class = PanoptesPluginWithEnrichmentRunner

        self._log_capture = LogCapture(attributes=TestPanoptesPluginRunner.extract) 

def setUp(self):

        self.my_dir, self.panoptes_test_conf_file = get_test_conf_file()
        self._panoptes_resource = PanoptesResource(resource_site="test", resource_class="test",
                                                   resource_subclass="test", resource_type="test", resource_id="test",
                                                   resource_endpoint="test", resource_creation_timestamp=_TIMESTAMP,
                                                   resource_plugin="test")

        self._panoptes_context = PanoptesContext(self.panoptes_test_conf_file,
                                                 key_value_store_class_list=[PanoptesTestKeyValueStore,
                                                                             PanoptesResourcesKeyValueStore,
                                                                             PanoptesPollingPluginKeyValueStore,
                                                                             PanoptesSecretsStore,
                                                                             PanoptesPollingPluginAgentKeyValueStore,
                                                                             PanoptesDiscoveryPluginAgentKeyValueStore,
                                                                             PanoptesDiscoveryPluginKeyValueStore],
                                                 create_message_producer=False, async_message_producer=False,
                                                 create_zookeeper_client=True)
        self._runner_class = PanoptesPluginWithEnrichmentRunner

        self._log_capture = LogCapture(attributes=TestPanoptesPluginRunner.extract) 

def test_feature_branch_no_diff(self):
        self._mock_repo()
        self._mock_branch(self.branch)
        self.mock_pulls()
        branch_name = "feature/a-test"
        branches = []
        branches.append(self._get_expected_branch(branch_name))
        branches = self._mock_branches(branches)
        self._mock_compare(
            base=branches[1]["name"], head=self.project_config.repo_commit
        )
        with LogCapture() as log:
            task = self._create_task()
            task()
            log_lines = self._get_log_lines(log)

            expected = [
                ("INFO", "Beginning task: MergeBranch"),
                ("INFO", ""),
                ("DEBUG", "Skipping branch master: is source branch"),
                ("INFO", "Skipping branch feature/a-test: no file diffs found"),
            ]
            self.assertEqual(expected, log_lines)
        self.assertEqual(5, len(responses.calls)) 

def test_check_output_fractional_score_string(sys):
    with LogCapture() as logs:
        docker_mock = MagicMock()
        container = {
            "Id": "myimageId"
        }
        args = argparse.Namespace()
        args.timeout = 300
        args.no_rm = False

        docker_mock.wait.return_value = 0
        docker_mock.logs.side_effect = [
            '',
            '{"fractionalScore": "0.3", "feedback": "wheeeee"}'
        ]
        # Run the function under test
        grade.run_container(docker_mock, container, args)
    logs.check(
        ('root', 'INFO', 'Debug log:'),
        ('root', 'ERROR', "Field 'fractionalScore' must be a decimal."),
        ('root', 'DEBUG', "About to remove container: {'Id': 'myimageId'}")
    )
    sys.exit.assert_called_with(1) 

def test_check_output_missing_grade(sys):
    with LogCapture() as logs:
        docker_mock = MagicMock()
        container = {
            "Id": "myimageId"
        }
        args = argparse.Namespace()
        args.timeout = 300
        args.no_rm = False

        docker_mock.wait.return_value = 0
        docker_mock.logs.side_effect = [
            '',
            '{"feedback": "wheeeee"}'
        ]
        # Run the function under test
        grade.run_container(docker_mock, container, args)
    logs.check(
        ('root', 'INFO', 'Debug log:'),
        ('root', 'ERROR', "Required field 'fractionalScore' is missing."),
        ('root', 'DEBUG', "About to remove container: {'Id': 'myimageId'}")
    )
    sys.exit.assert_called_with(1) 

def test_check_output_malformed_output(sys):
    with LogCapture() as logs:
        docker_mock = MagicMock()
        container = {
            "Id": "myimageId"
        }
        args = argparse.Namespace()
        args.timeout = 300
        args.no_rm = False

        docker_mock.wait.return_value = 0
        docker_mock.logs.side_effect = [
            '',
            '{"isCorrect":false, "not-feedback": "garbageeeeeeee'
        ]
        # Run the function under test
        grade.run_container(docker_mock, container, args)
    logs.check(
        ('root', 'INFO', 'Debug log:'),
        ('root', 'ERROR', "The output was not a valid JSON document."),
        ('root', 'DEBUG', "About to remove container: {'Id': 'myimageId'}")
    )
    sys.exit.assert_called_with(1) 

def test_check_output_good_output_is_correct(sys):
    with LogCapture() as logs:
        docker_mock = MagicMock()
        container = {
            "Id": "myimageId"
        }
        args = argparse.Namespace()
        args.timeout = 300
        args.no_rm = False

        docker_mock.wait.return_value = 0
        docker_mock.logs.side_effect = [
            '',
            '{"isCorrect":false, "feedback": "Helpful comment!"}'
        ]
        # Run the function under test
        grade.run_container(docker_mock, container, args)
    logs.check(
        ('root', 'INFO', 'Debug log:'),
        ('root', 'DEBUG', "About to remove container: {'Id': 'myimageId'}")
    )
    assert not sys.exit.called, "sys.exit should not be called!" 

def test_check_output_good_output_fractional_score_one(sys):
    with LogCapture() as logs:
        docker_mock = MagicMock()
        container = {
            "Id": "myimageId"
        }
        args = argparse.Namespace()
        args.timeout = 300
        args.no_rm = False

        docker_mock.wait.return_value = 0
        docker_mock.logs.side_effect = [
            '',
            '{"fractionalScore":1, "feedback": "Helpful comment!"}'
        ]
        # Run the function under test
        grade.run_container(docker_mock, container, args)
    logs.check(
        ('root', 'INFO', 'Debug log:'),
        ('root', 'DEBUG', "About to remove container: {'Id': 'myimageId'}")
    )
    assert not sys.exit.called, "sys.exit should not be called!" 

def test_check_output_good_output_fractional_score_one_point_oh(sys):
    with LogCapture() as logs:
        docker_mock = MagicMock()
        container = {
            "Id": "myimageId"
        }
        args = argparse.Namespace()
        args.timeout = 300
        args.no_rm = False

        docker_mock.wait.return_value = 0
        docker_mock.logs.side_effect = [
            '',
            '{"fractionalScore":1.0, "feedback": "Helpful comment!"}'
        ]
        # Run the function under test
        grade.run_container(docker_mock, container, args)
    logs.check(
        ('root', 'INFO', 'Debug log:'),
        ('root', 'DEBUG', "About to remove container: {'Id': 'myimageId'}")
    )
    assert not sys.exit.called, "sys.exit should not be called!" 

def test_check_output_good_output_fractional_score_zero(sys):
    with LogCapture() as logs:
        docker_mock = MagicMock()
        container = {
            "Id": "myimageId"
        }
        args = argparse.Namespace()
        args.timeout = 300
        args.no_rm = False

        docker_mock.wait.return_value = 0
        docker_mock.logs.side_effect = [
            '',
            '{"fractionalScore":0, "feedback": "Helpful comment!"}'
        ]
        # Run the function under test
        grade.run_container(docker_mock, container, args)
    logs.check(
        ('root', 'INFO', 'Debug log:'),
        ('root', 'DEBUG', "About to remove container: {'Id': 'myimageId'}")
    )
    assert not sys.exit.called, "sys.exit should not be called!" 

def test_check_output_bad_return_code(sys):
    with LogCapture():
        docker_mock = MagicMock()
        container = {
            "Id": "myimageId"
        }
        args = argparse.Namespace()
        args.timeout = 300
        args.no_rm = False

        docker_mock.wait.return_value = 1
        docker_mock.logs.side_effect = [
            'debug output',
            '{"isCorrect":true,"feedback":"You win!"}'
        ]
        # Run the function under test
        grade.run_container(docker_mock, container, args)
    sys.exit.assert_called_with(1) 

def test_bad_message_is_logged(self, config, trivial_message):
        responses.add(responses.POST, "https://api.github.com/repos/tdsmith/test_repo/hooks")
        repo_listener = snooze.RepositoryListener(
            events=snooze.LISTEN_EVENTS,
            **config["tdsmith/test_repo"])

        sqs = boto3.resource("sqs", region_name="us-west-2")
        sqs_queue = list(sqs.queues.all())[0]
        sqs_queue.send_message(MessageBody="this isn't a json message at all")

        with LogCapture() as l:
            repo_listener.poll()
            assert 'ERROR' in str(l)

        def my_callback(event, message):
            raise ValueError("I object!")
        sqs_queue.send_message(MessageBody=trivial_message)
        repo_listener.register_callback(my_callback)
        with LogCapture() as l:
            repo_listener.poll()
            assert 'I object!' in str(l) 

def test_no_instances(self):
        """
        Verify that the command correctly notifies the user that there are no instances for migration.
        """
        try:
            with LogCapture() as captured_logs:
                call_command(
                    'migrate_ephemeral',
                    stdout=StringIO(),
                )
                # Verify the logs
                self.assertIn(
                    'Found "0" instances using ephemeral databases',
                    [l[2] for l in captured_logs.actual()])
        except FieldDoesNotExist:
            # Field already removed from database
            pass 

def test_migrate(self, mock_spawn_appserver):
        """
        Verify that the command correctly migrate an instance to use external databases.
        """
        try:
            OpenEdXInstance.objects.create(
                sub_domain='test_migrate', use_ephemeral_databases=True, name='test_migrate instance')
            with LogCapture() as captured_logs:
                call_command(
                    'migrate_ephemeral',
                    stdout=StringIO(),
                )
                # Verify the logs
                actual = set(l[2] for l in captured_logs.actual())
                expected = {
                    'Found "1" instances using ephemeral databases',
                    'Migrated and started provisioning a new app server for test_migrate instance',
                }
                self.assertTrue(expected <= actual)

            self.assertTrue(mock_spawn_appserver.called)
        except TypeError:
            # Field already removed from database
            pass 

def test_default_arguments(self, mock_consul):
        """
        Verify status is logged as expected with default arguments
        """
        with LogCapture() as captured_logs:
            call_command('instance_redeploy', '--tag=test-tag', '--force')
            expected_logs = ((self.cmd_module, self.log_level, msg) for msg in (
                '******* Status *******',
                'Instances pending redeployment: 0',
                'Redeployments in progress: 0',
                'Failed to redeploy: 0',
                'Successfully redeployed (done): 0',
                'Batch size: 2',
                'Batch frequency: 0:10:00',
                'Number of upgrade attempts per instance: 1',
                '** Starting redeployment **',
                '******* Status *******',
                'Instances pending redeployment: 0',
                'Redeployments in progress: 0',
                'Failed to redeploy: 0',
                'Successfully redeployed (done): 0',
                '** Redeployment done **',
            ))
            captured_logs.check(*expected_logs) 

def test_create_with_api_exception(self):
        with mock.patch(
            # We are using get_course_key because it is called prior to trying to contact the
            # e-commerce service and still gives the effect of an api exception.
            'course_discovery.apps.api.v1.views.courses.CourseViewSet.get_course_key',
            side_effect=IntegrityError('Error')
        ):
            with LogCapture(course_logger.name) as log_capture:
                response = self.create_course()
                self.assertEqual(response.status_code, 400)
                log_capture.check(
                    (
                        course_logger.name,
                        'ERROR',
                        'Failed to set data: Error',
                    )
                ) 

def test_update_with_api_exception(self):
        """ Verify that if the serializer fails, error message is logged and update fails"""
        url = reverse('api:v1:person-detail', kwargs={'uuid': self.person.uuid})
        data = self._update_person_data()
        with mock.patch.object(MarketingSitePeople, 'update_or_publish_person', return_value={}):
            with mock.patch(
                'course_discovery.apps.api.v1.views.people.PersonViewSet.perform_update',
                side_effect=IntegrityError
            ):
                with LogCapture(people_logger.name) as log_capture:
                    response = self.client.patch(url, self._update_person_data(), format='json')
                    self.assertEqual(response.status_code, 400)
                    log_capture.check(
                        (
                            people_logger.name,
                            'ERROR',
                            'An error occurred while updating the person [{}]-[{}] in discovery.'.format(
                                data['given_name'], data['family_name']
                            )
                        )
                    ) 

def test_update_without_drupal_client_settings(self):
        """ Verify that if credentials are missing api will return the error. """
        url = reverse('api:v1:person-detail', kwargs={'uuid': self.person.uuid})
        self.partner.marketing_site_api_username = None
        self.partner.save()
        data = self._update_person_data()

        with LogCapture(people_logger.name) as log_capture:
            response = self.client.patch(url, data, format='json')
            self.assertEqual(response.status_code, 400)
            log_capture.check(
                (
                    people_logger.name,
                    'ERROR',
                    'An error occurred while updating the person [{}]-[{}] on the marketing site.'.format(
                        data['given_name'], data['family_name']
                    )
                )
            ) 

def test_create_with_api_exception(self):
        """ Verify that after creating drupal page if serializer fail due to any error, message
        will be logged and drupal page will be deleted. """

        data = self._person_data()
        with mock.patch.object(MarketingSitePeople, 'update_or_publish_person', return_value=self.expected_node):
            with mock.patch(
                'course_discovery.apps.api.v1.views.people.PersonViewSet.perform_create',
                side_effect=IntegrityError
            ):
                with mock.patch.object(MarketingSitePeople, 'delete_person', return_value=None):
                    with LogCapture(people_logger.name) as log_capture:
                        response = self.client.post(self.people_list_url, self._person_data(), format='json')
                        self.assertEqual(response.status_code, 400)
                        log_capture.check(
                            (
                                people_logger.name,
                                'ERROR',
                                'An error occurred while adding the person [{}]-[{}] in discovery.'.format(
                                    data['given_name'], data['family_name'],
                                )
                            )
                        )

        self.assertFalse(self.person_exists(data)) 

def test_create_without_drupal_client_settings(self):
        """ Verify that if credentials are missing api will return the error. """
        self.partner.marketing_site_api_username = None
        self.partner.save()
        data = self._person_data()

        with LogCapture(people_logger.name) as log_capture:
            response = self.client.post(self.people_list_url, self._person_data(), format='json')
            self.assertEqual(response.status_code, 400)
            log_capture.check(
                (
                    people_logger.name,
                    'ERROR',
                    'An error occurred while adding the person [{}]-[{}] to the marketing site.'.format(
                        data['given_name'], data['family_name']
                    )
                )
            )

        self.assertFalse(self.person_exists(data)) 

def test_start_stop():
    with LogCapture() as l:
        if os.path.exists("tests/tmp.db"):
            os.remove("tests/tmp.db")  # Remove existing db

        b = bumper
        b.db = "tests/tmp.db"  # Set db location for testing
        b.conf1_listen_address = "127.0.0.1"
        b.conf1_listen_port = 444
        asyncio.create_task(b.start())
        await asyncio.sleep(0.1)
        l.check_present(("bumper", "INFO", "Starting Bumper"))
        l.clear()

        asyncio.create_task(b.shutdown())
        await asyncio.sleep(0.1)
        l.check_present(
            ("bumper", "INFO", "Shutting down"), ("bumper", "INFO", "Shutdown complete")
        )
        assert b.shutting_down == True 

def test_start_stop_debug():
    with LogCapture() as l:
        if os.path.exists("tests/tmp.db"):
            os.remove("tests/tmp.db")  # Remove existing db

        b = bumper
        b.db = "tests/tmp.db"  # Set db location for testing
        b.bumper_listen = "0.0.0.0"
        b.bumper_debug = True
        asyncio.create_task(b.start())

        await asyncio.sleep(0.1)
        asyncio.create_task(b.shutdown())
        l.check_present(("bumper", "INFO", "Starting Bumper"))
        l.clear()
        await asyncio.sleep(0.1)
        l.check_present(
            ("bumper", "INFO", "Shutting down"), ("bumper", "INFO", "Shutdown complete")
        )
        assert b.shutting_down == True 

def test_confserver_exceptions():
    with LogCapture() as l:

            conf_server = bumper.ConfServer(("127.0.0.1", 8007), usessl=True)
            conf_server.confserver_app()        
            conf_server.site = web.TCPSite

            #bind permission       
            conf_server.site.start = mock.Mock(side_effect=OSError(1, "error while attempting to bind on address ('127.0.0.1', 8007): permission denied"))
            await conf_server.start_server()

            #asyncio Cancel
            conf_server.site = web.TCPSite
            conf_server.site.start = mock.Mock(side_effect=asyncio.CancelledError)
            await conf_server.start_server()

            #general exception
            conf_server.site = web.TCPSite
            conf_server.site.start = mock.Mock(side_effect=Exception(1, "general"))
            await conf_server.start_server()
    
    l.check_present(
        ("confserver", "ERROR", "error while attempting to bind on address ('127.0.0.1', 8007): permission denied")
    ) 

def do_publish_create_republish(config):
    """Test if creating republishes works."""
    with testfixtures.LogCapture() as l:
        do_publish_create(config)
        found = False
        for rec in l.records:
            if rec.levelname == "CRITICAL":
                if "has been deferred" in rec.msg:
                    found = True
        assert found
    args = [
        '-c',
        config,
        'publish',
        'create',
    ]
    main(args)
    state = SystemStateReader()
    state.read()
    assert 'fakerepo01-stable main' in state.publishes 

def test_fetch_production_no_solar(self):
        response_text = resource_string("parsers.test.mocks", "hops.json")
        self.adapter.register_uri("GET", "https://www.hops.hr/Home/PowerExchange", content=response_text)
        response_text = resource_string("parsers.test.mocks", "hrote_dates.json")
        self.adapter.register_uri("GET", "https://files.hrote.hr/files/EKO_BG/FORECAST/SOLAR/FTP/TEST_DRIVE/dates.json",
                                  content=response_text)
        response_text = resource_string("parsers.test.mocks", "hrote_no_solar_on_that_hour.json")
        self.adapter.register_uri("GET", "https://files.hrote.hr/files/EKO_BG/FORECAST/SOLAR/FTP/TEST_DRIVE/"
                                         "21.5.2020.json", content=response_text)

        with LogCapture() as log:
            data = HOPS.fetch_production('HR', self.session)
        self.assertTrue(('parsers.HOPS', 'WARNING', 'No value for Solar power production on '
                                                 '2020-05-21 18:00:00+02:00') in log.actual())
        self.assertIsNotNone(data)
        data = data[0]
        self.assertEqual(data['zoneKey'], 'HR')
        self.assertEqual(data['source'], 'hops.hr')
        self.assertIsNotNone(data['datetime'])
        self.assertIsNotNone(data['production'])
        self.assertEqual(data['production']['wind'], 504.0)
        self.assertEqual(data['production']['solar'], None)
        self.assertEqual(data['production']['unknown'], 1494.0)