Python oslo_log.log.INFO Examples

def setup_logging(self):
        # Assign default logs to self.LOG so we can still
        # assert on senlin logs.
        default_level = logging.INFO
        if os.environ.get('OS_DEBUG') in _TRUE_VALUES:
            default_level = logging.DEBUG

        self.LOG = self.useFixture(
            fixtures.FakeLogger(level=default_level, format=_LOG_FORMAT))
        base_list = set([nlog.split('.')[0] for nlog in
                         logging.getLogger().logger.manager.loggerDict])
        for base in base_list:
            if base in TEST_DEFAULT_LOGLEVELS:
                self.useFixture(fixtures.FakeLogger(
                    level=TEST_DEFAULT_LOGLEVELS[base],
                    name=base, format=_LOG_FORMAT))
            elif base != 'senlin':
                self.useFixture(fixtures.FakeLogger(
                    name=base, format=_LOG_FORMAT)) 

def _validate_keys(self, ctxt, keyed_log_string):
        infocolor = handlers.ColorHandler.LEVEL_COLORS[logging.INFO]
        warncolor = handlers.ColorHandler.LEVEL_COLORS[logging.WARN]
        info_msg = 'info'
        warn_msg = 'warn'
        infoexpected = "%s %s %s" % (infocolor, keyed_log_string, info_msg)
        warnexpected = "%s %s %s" % (warncolor, keyed_log_string, warn_msg)

        self.colorlog.info(info_msg, context=ctxt)
        self.assertIn(infoexpected, self.stream.getvalue())
        self.assertEqual('\033[00;36m', infocolor)

        self.colorlog.warn(warn_msg, context=ctxt)
        self.assertIn(infoexpected, self.stream.getvalue())
        self.assertIn(warnexpected, self.stream.getvalue())
        self.assertEqual('\033[01;33m', warncolor) 

def _dump(level, action, phase, reason, timestamp):
    global dispatchers

    if timestamp is None:
        timestamp = timeutils.utcnow(True)

    # We check the logging level threshold only when debug is False
    if cfg.CONF.debug is False:
        watermark = cfg.CONF.dispatchers.priority.upper()
        bound = consts.EVENT_LEVELS.get(watermark, logging.INFO)
        if level < bound:
            return

    if cfg.CONF.dispatchers.exclude_derived_actions:
        if action.cause == consts.CAUSE_DERIVED:
            return

    try:
        dispatchers.map_method("dump", level, action,
                               phase=phase, reason=reason, timestamp=timestamp)
    except Exception as ex:
        LOG.exception("Dispatcher failed to handle the event: %s",
                      str(ex)) 

def build_simple_server():
    app = load_app()
    # Create the WSGI server and start it
    host, port = CONF.api.host, CONF.api.port

    LOG.info('Starting server in PID %s', os.getpid())
    LOG.info('Configuration:')
    CONF.log_opt_values(LOG, log.INFO)

    if host == '0.0.0.0':
        LOG.info(
            'serving on 0.0.0.0:%(port)s, view at http://127.0.0.1:%(port)s',
            {'port': port})
    else:
        LOG.info('serving on http://%(host)s:%(port)s',
                 {'host': host, 'port': port})

    LOG.info('"DANGER! For testing only, do not use in production"')

    serving.run_simple(host, port,
                       app, processes=CONF.api.workers) 

def test_debug(self):
        paths = self.setup_confs(
            "[DEFAULT]\ndebug = false\n",
            "[DEFAULT]\ndebug = true\n")
        log_root = log.getLogger(None).logger
        log._setup_logging_from_conf(self.CONF, 'test', 'test')
        self.assertEqual(False, self.CONF.debug)
        self.assertEqual(log.INFO, log_root.getEffectiveLevel())

        shutil.copy(paths[1], paths[0])
        self.CONF.mutate_config_files()

        self.assertEqual(True, self.CONF.debug)
        self.assertEqual(log.DEBUG, log_root.getEffectiveLevel()) 

def setup_logging(name, level):

    logging.setup(CONF, name)
    LOG = logging.getLogger(None)

    if level == 'INFO':
        LOG.logger.setLevel(logging.INFO)
    if level == 'DEBUG':
        LOG.logger.setLevel(logging.DEBUG)
    if level == 'WARNING':
        LOG.logger.setLevel(logging.WARNING)
    if level == 'ERROR':
        LOG.logger.setLevel(logging.ERROR) 

def test_dump_cluster_action_event(self, mock_check, mock_notify):
        mock_check.return_value = 'CLUSTER'
        entity = mock.Mock()
        action = mock.Mock(context=self.ctx, entity=entity)

        res = MSG.MessageEvent.dump(logging.INFO, action)

        self.assertIsNone(res)
        mock_check.assert_called_once_with(entity)
        mock_notify.assert_called_once_with(self.ctx, logging.INFO, entity,
                                            action) 

def create_event(self, ctx, timestamp=None, level=logging.INFO,
                     entity=None, action=None, status=None,
                     status_reason=None):

        fake_timestamp = tu.parse_strtime(
            '2014-12-19 11:51:54.670244', '%Y-%m-%d %H:%M:%S.%f')

        if entity:
            e_name = reflection.get_class_name(entity, fully_qualified=False)
            type_name = e_name.upper()
            if type_name == 'CLUSTER':
                cluster_id = entity.id
            elif type_name == 'NODE':
                cluster_id = entity.cluster_id
            else:
                cluster_id = ''
        else:
            type_name = ''
            cluster_id = ''

        values = {
            'timestamp': timestamp or fake_timestamp,
            'level': level,
            'oid': entity.id if entity else '',
            'oname': entity.name if entity else '',
            'otype': type_name,
            'cluster_id': cluster_id,
            'action': action or '',
            'status': status or '',
            'status_reason': status_reason or '',
            'user': ctx.user_id,
            'project': ctx.project_id,
        }

        # Make sure all fields can be customized
        return db_api.event_create(ctx, values) 

def test_info(self, mock_dump):
        entity = mock.Mock(id='1234567890')
        entity.name = 'fake_obj'
        action = mock.Mock(id='FAKE_ID', entity=entity, action='ACTION_NAME')

        res = event.info(action, 'P1', 'R1', 'TS1')

        self.assertIsNone(res)
        mock_dump.assert_called_once_with(logging.INFO, action,
                                          'P1', 'R1', 'TS1') 

def test_dump_with_exception(self):
        cfg.CONF.set_override('debug', True)
        saved_dispathers = event.dispatchers
        event.dispatchers = mock.Mock()
        event.dispatchers.map_method.side_effect = Exception('fab')
        action = mock.Mock(cause=consts.CAUSE_RPC)
        try:
            res = event._dump(logging.INFO, action, 'Phase1', 'Reason1', 'TS1')

            self.assertIsNone(res)  # exception logged only
            event.dispatchers.map_method.assert_called_once_with(
                'dump', logging.INFO, action,
                phase='Phase1', reason='Reason1', timestamp='TS1')
        finally:
            event.dispatchers = saved_dispathers 

def test_dump_exclude_derived_actions_negative(self):
        cfg.CONF.set_override('exclude_derived_actions', False,
                              group='dispatchers')
        saved_dispathers = event.dispatchers
        event.dispatchers = mock.Mock()
        action = mock.Mock(cause=consts.CAUSE_DERIVED)
        try:
            event._dump(logging.INFO, action, 'Phase1', 'Reason1', 'TS1')

            event.dispatchers.map_method.assert_called_once_with(
                'dump', logging.INFO, action,
                phase='Phase1', reason='Reason1', timestamp='TS1')
        finally:
            event.dispatchers = saved_dispathers 

def test_dump_guarded(self):
        cfg.CONF.set_override('debug', False)
        cfg.CONF.set_override('priority', 'warning', group='dispatchers')
        saved_dispathers = event.dispatchers
        event.dispatchers = mock.Mock()
        action = mock.Mock(cause=consts.CAUSE_RPC)
        try:
            event._dump(logging.INFO, action, 'Phase1', 'Reason1', 'TS1')
            # (temporary)Remove map_method.call_count for coverage test
            # self.assertEqual(0, event.dispatchers.map_method.call_count)
        finally:
            event.dispatchers = saved_dispathers 

def test_dump_without_timestamp(self):
        cfg.CONF.set_override('debug', True)
        saved_dispathers = event.dispatchers
        event.dispatchers = mock.Mock()
        action = mock.Mock(cause=consts.CAUSE_RPC)
        try:
            event._dump(logging.INFO, action, 'Phase1', 'Reason1', None)

            event.dispatchers.map_method.assert_called_once_with(
                'dump', logging.INFO, action,
                phase='Phase1', reason='Reason1', timestamp=mock.ANY)
        finally:
            event.dispatchers = saved_dispathers 

def test_dump(self):
        cfg.CONF.set_override('debug', True)
        saved_dispathers = event.dispatchers
        event.dispatchers = mock.Mock()
        action = mock.Mock(cause=consts.CAUSE_RPC)
        try:
            event._dump(logging.INFO, action, 'Phase1', 'Reason1', 'TS1')
            event.dispatchers.map_method.assert_called_once_with(
                'dump', logging.INFO, action,
                phase='Phase1', reason='Reason1', timestamp='TS1')
        finally:
            event.dispatchers = saved_dispathers 

def info(action, phase=None, reason=None, timestamp=None):
    _dump(logging.INFO, action, phase, reason, timestamp)
    LOG.info(FMT, _event_data(action, phase, reason)) 

def _log_entry(log_type, entry, log_level=logging.INFO, **kwargs):
    delta = datetime.now() - datetime.min
    timestamp = delta.total_seconds()
    log_dict = {'log_type': log_type, 'op': entry.operation,
                'obj_type': entry.object_type, 'obj_id': entry.object_uuid,
                'entry_id': entry.seqnum, 'timestamp': timestamp}
    LOG.log(log_level, LOG_ENTRY_TEMPLATE, log_dict, **kwargs) 

def test_resource_key_dict_in_log_msg(self):
        color = handlers.ColorHandler.LEVEL_COLORS[logging.INFO]
        ctxt = _fake_context()
        type = 'fake_resource'
        resource_id = '202260f9-1224-490d-afaf-6a744c13141f'
        fake_resource = {'type': type,
                         'id': resource_id}
        message = 'info'
        self.colorlog.info(message, context=ctxt, resource=fake_resource)
        expected = ('%s [%s]: [%s-%s] %s\033[00m\n' %
                    (color, ctxt.request_id, type, resource_id, message))
        self.assertEqual(expected, self.stream.getvalue()) 

def test_resource_key_in_log_msg(self):
        color = handlers.ColorHandler.LEVEL_COLORS[logging.INFO]
        ctxt = _fake_context()
        resource = 'resource-202260f9-1224-490d-afaf-6a744c13141f'
        fake_resource = {'name': resource}
        message = 'info'
        self.colorlog.info(message, context=ctxt, resource=fake_resource)
        expected = ('%s [%s]: [%s] %s\033[00m\n' %
                    (color, ctxt.request_id, resource, message))
        self.assertEqual(expected, self.stream.getvalue()) 

def test_message_logging_3rd_party_log_records(self):
        ctxt = _fake_context()
        ctxt.request_id = str('99')
        sa_log = logging.getLogger('sqlalchemy.engine')
        sa_log.setLevel(logging.INFO)
        message = self.trans_fixture.lazy('test ' + chr(128))
        sa_log.info(message)

        expected = ('HAS CONTEXT [%s]: %s\n' % (ctxt.request_id,
                                                str(message)))
        self.assertEqual(expected, self.stream.getvalue()) 

def test_contextual_information_is_imparted_to_3rd_party_log_records(self):
        ctxt = _fake_context()
        sa_log = logging.getLogger('sqlalchemy.engine')
        sa_log.setLevel(logging.INFO)
        message = 'emulate logging within sqlalchemy'
        sa_log.info(message)

        expected = ('HAS CONTEXT [%s]: %s\n' % (ctxt.request_id, message))
        self.assertEqual(expected, self.stream.getvalue()) 

def test_child_log_has_level_of_parent_flag(self):
        logger = log.getLogger('nova-test.foo')
        self.assertEqual(logging.INFO, logger.logger.getEffectiveLevel()) 

def test_has_level_from_flags(self):
        self.assertEqual(logging.INFO, self.log.logger.getEffectiveLevel()) 

def test_is_enabled_for(self):
        self.assertTrue(self.log.isEnabledFor(logging.INFO))
        self.assertFalse(self.log_no_debug.isEnabledFor(logging.DEBUG))
        self.assertTrue(self.log_below_debug.isEnabledFor(logging.DEBUG))
        self.assertTrue(self.log_below_debug.isEnabledFor(7))
        self.assertTrue(self.log_trace.isEnabledFor(log.TRACE)) 

def test_emit(self):
        logger = log.getLogger('nova-test.foo')
        local_context = _fake_new_context()
        logger.info("Foo", context=local_context)
        self.assertEqual(
            mock.call(mock.ANY, CODE_FILE=mock.ANY, CODE_FUNC='test_emit',
                      CODE_LINE=mock.ANY, LOGGER_LEVEL='INFO',
                      LOGGER_NAME='nova-test.foo', PRIORITY=6,
                      SYSLOG_FACILITY=syslog.LOG_USER,
                      SYSLOG_IDENTIFIER=mock.ANY,
                      REQUEST_ID=mock.ANY,
                      PROJECT_NAME='mytenant',
                      PROCESS_NAME='MainProcess',
                      THREAD_NAME='MainThread',
                      USER_NAME='myuser'),
            self.journal.send.call_args)
        args, kwargs = self.journal.send.call_args
        self.assertEqual(len(args), 1)
        self.assertIsInstance(args[0], str)
        self.assertIsInstance(kwargs['CODE_LINE'], int)
        self.assertIsInstance(kwargs['PRIORITY'], int)
        self.assertIsInstance(kwargs['SYSLOG_FACILITY'], int)
        del kwargs['CODE_LINE'], kwargs['PRIORITY'], kwargs['SYSLOG_FACILITY']
        for key, arg in kwargs.items():
            self.assertIsInstance(key, str)
            self.assertIsInstance(arg, (bytes, str)) 

def test_handler(self):
        handler = handlers.OSJournalHandler()
        handler.emit(
            logging.LogRecord("foo", logging.INFO,
                              "path", 123, "hey!",
                              None, None))
        self.assertTrue(self.journal.send.called) 

def test_syslog(self):
        msg_unicode = u"Benoît Knecht & François Deppierraz login failure"
        handler = handlers.OSSysLogHandler()
        syslog.syslog = mock.Mock()
        handler.emit(
            logging.LogRecord("name", logging.INFO, "path", 123,
                              msg_unicode, None, None))
        syslog.syslog.assert_called_once_with(syslog.LOG_INFO, msg_unicode) 

def test_handler(self):
        handler = handlers.OSSysLogHandler()
        syslog.syslog = mock.Mock()
        handler.emit(
            logging.LogRecord("foo", logging.INFO,
                              "path", 123, "hey!",
                              None, None))
        self.assertTrue(syslog.syslog.called) 

def test_will_be_info_if_debug_flag_not_set(self):
        self.config(debug=False)
        logger_name = 'test_is_not_debug'
        log.setup(self.CONF, logger_name)
        logger = logging.getLogger(logger_name)
        self.assertEqual(logging.INFO, logger.getEffectiveLevel()) 

def test_mk_log_config_full(self):
        data = {'loggers': {'aaa': {'level': 'INFO'},
                            'bbb': {'level': 'WARN',
                                    'propagate': False}},
                'handlers': {'aaa': {'level': 'INFO'},
                             'bbb': {'level': 'WARN',
                                     'propagate': False,
                                     'args': (1, 2)}},
                'formatters': {'aaa': {'level': 'INFO'},
                               'bbb': {'level': 'WARN',
                                       'propagate': False}},
                'root': {'level': 'INFO',
                         'handlers': 'aaa'},
                }
        full = """[formatters]
keys=aaa,bbb

[formatter_aaa]
level=INFO

[formatter_bbb]
level=WARN
propagate=False

[handlers]
keys=aaa,bbb

[handler_aaa]
level=INFO
args=()

[handler_bbb]
args=(1, 2)
level=WARN
propagate=False

[loggers]
keys=root,aaa,bbb

[logger_aaa]
level=INFO
qualname=aaa
handlers=

[logger_bbb]
level=WARN
propagate=False
qualname=bbb
handlers=

[logger_root]
handlers=aaa
level=INFO"""
        self.assertEqual(full, self.mk_log_config(data))