Merge "Allow finer grained log levels"

oslo_privsep/daemon.py

@@ -193,7 +193,8 @@ class PrivsepLogHandler(pylogging.Handler):
 class _ClientChannel(comm.ClientChannel):
     """Our protocol, layered on the basic primitives in comm.ClientChannel"""
 
-    def __init__(self, sock):
+    def __init__(self, sock, context):
+        self.log = logging.getLogger(context.conf.logger_name)
         super(_ClientChannel, self).__init__(sock)
         self.exchange_ping()
 
@@ -203,11 +204,12 @@ class _ClientChannel(comm.ClientChannel):
             reply = self.send_recv((Message.PING.value,))
             success = reply[0] == Message.PONG
         except Exception as e:
-            LOG.exception('Error while sending initial PING to privsep: %s', e)
+            self.log.exception('Error while sending initial PING to privsep: '
+                               '%s', e)
             success = False
         if not success:
             msg = _('Privsep daemon failed to start')
-            LOG.critical(msg)
+            self.log.critical(msg)
             raise FailedToDropPrivileges(msg)
 
     def remote_call(self, name, args, kwargs):
@@ -231,11 +233,11 @@ class _ClientChannel(comm.ClientChannel):
             message = {encodeutils.safe_decode(k): v
                        for k, v in msg[1].items()}
             record = pylogging.makeLogRecord(message)
-            if LOG.isEnabledFor(record.levelno):
+            if self.log.isEnabledFor(record.levelno):
-                LOG.logger.handle(record)
+                self.log.logger.handle(record)
         else:
-            LOG.warning('Ignoring unexpected OOB message from privileged '
+            self.log.warning('Ignoring unexpected OOB message from privileged '
-                        'process: %r', msg)
+                             'process: %r', msg)
 
 
 def fdopen(fd, *args, **kwargs):
@@ -330,7 +332,7 @@ class ForkingClientChannel(_ClientChannel):
         # parent
 
         sock_b.close()
-        super(ForkingClientChannel, self).__init__(sock_a)
+        super(ForkingClientChannel, self).__init__(sock_a, context)
 
 
 class RootwrapClientChannel(_ClientChannel):
@@ -380,7 +382,7 @@ class RootwrapClientChannel(_ClientChannel):
                     raise
             os.rmdir(tmpdir)
 
-        super(RootwrapClientChannel, self).__init__(sock)
+        super(RootwrapClientChannel, self).__init__(sock, context)
 
 
 class Daemon(object):

oslo_privsep/priv_context.py

@@ -65,6 +65,10 @@ OPTS = [
                       'recreate the current configuration. '
                       'This command must accept suitable --privsep_context '
                       'and --privsep_sock_path arguments.')),
+    cfg.StrOpt('logger_name',
+               help=_('Logger name to use for this privsep context.  By '
+                      'default all contexts log with oslo_privsep.daemon.'),
+               default='oslo_privsep.daemon'),
 ]
 
 _ENTRYPOINT_ATTR = 'privsep_entrypoint'
@@ -124,7 +128,7 @@ def init(root_helper=None):
 
 class PrivContext(object):
     def __init__(self, prefix, cfg_section='privsep', pypath=None,
-                 capabilities=None):
+                 capabilities=None, logger_name='oslo_privsep.daemon'):
 
         # Note that capabilities=[] means retaining no capabilities
         # and leaves even uid=0 with no powers except being able to
@@ -150,6 +154,8 @@ class PrivContext(object):
         cfg.CONF.register_opts(OPTS, group=cfg_section)
         cfg.CONF.set_default('capabilities', group=cfg_section,
                              default=capabilities)
+        cfg.CONF.set_default('logger_name', group=cfg_section,
+                             default=logger_name)
 
     @property
     def conf(self):

oslo_privsep/tests/test_daemon.py

@@ -45,6 +45,20 @@ class TestException(Exception):
     pass
 
 
+def get_fake_context(conf_attrs=None, **context_attrs):
+    conf_attrs = conf_attrs or {}
+    context = mock.NonCallableMock()
+    context.conf.user = 42
+    context.conf.group = 84
+    context.conf.thread_pool_size = 10
+    context.conf.capabilities = [
+        capabilities.CAP_SYS_ADMIN, capabilities.CAP_NET_ADMIN]
+    context.conf.logger_name = 'oslo_privsep.daemon'
+    vars(context).update(context_attrs)
+    vars(context.conf).update(conf_attrs)
+    return context
+
+
 @testctx.context.entrypoint
 def logme(level, msg, exc_info=False):
     # We want to make sure we log everything from the priv side for
@@ -152,12 +166,7 @@ class DaemonTest(base.BaseTestCase):
     def test_drop_privs(self, mock_dropcaps, mock_keepcaps,
                         mock_setgroups, mock_setgid, mock_setuid):
         channel = mock.NonCallableMock()
-        context = mock.NonCallableMock()
+        context = get_fake_context()
-        context.conf.user = 42
-        context.conf.group = 84
-        context.conf.thread_pool_size = 10
-        context.conf.capabilities = [
-            capabilities.CAP_SYS_ADMIN, capabilities.CAP_NET_ADMIN]
 
         d = daemon.Daemon(channel, context)
         d._drop_privs()
@@ -200,23 +209,51 @@ class ClientChannelTestCase(base.BaseTestCase):
 
     def setUp(self):
         super(ClientChannelTestCase, self).setUp()
+        context = get_fake_context()
         with mock.patch.object(comm.ClientChannel, '__init__'), \
                 mock.patch.object(daemon._ClientChannel, 'exchange_ping'):
-            self.client_channel = daemon._ClientChannel(mock.ANY)
+            self.client_channel = daemon._ClientChannel(mock.ANY, context)
 
-    def test_out_of_band_log_message(self):
+    @mock.patch.object(daemon.LOG.logger, 'handle')
+    def test_out_of_band_log_message(self, handle_mock):
         message = [daemon.Message.LOG, self.DICT]
+        self.assertEqual(self.client_channel.log, daemon.LOG)
         with mock.patch.object(pylogging, 'makeLogRecord') as mock_make_log, \
                 mock.patch.object(daemon.LOG, 'isEnabledFor',
-                                  return_value=False):
+                                  return_value=True) as mock_enabled:
             self.client_channel.out_of_band(message)
             mock_make_log.assert_called_once_with(self.EXPECTED)
+            handle_mock.assert_called_once_with(mock_make_log.return_value)
+            mock_enabled.assert_called_once_with(
+                mock_make_log.return_value.levelno)
 
     def test_out_of_band_not_log_message(self):
         with mock.patch.object(daemon.LOG, 'warning') as mock_warning:
             self.client_channel.out_of_band([daemon.Message.PING])
             mock_warning.assert_called_once()
 
+    @mock.patch.object(daemon.logging, 'getLogger')
+    @mock.patch.object(pylogging, 'makeLogRecord')
+    def test_out_of_band_log_message_context_logger(self, make_log_mock,
+                                                    get_logger_mock):
+        logger_name = 'os_brick.privileged'
+        context = get_fake_context(conf_attrs={'logger_name': logger_name})
+        with mock.patch.object(comm.ClientChannel, '__init__'), \
+                mock.patch.object(daemon._ClientChannel, 'exchange_ping'):
+            channel = daemon._ClientChannel(mock.ANY, context)
+
+        get_logger_mock.assert_called_once_with(logger_name)
+        self.assertEqual(get_logger_mock.return_value, channel.log)
+
+        message = [daemon.Message.LOG, self.DICT]
+        channel.out_of_band(message)
+
+        make_log_mock.assert_called_once_with(self.EXPECTED)
+        channel.log.isEnabledFor.assert_called_once_with(
+            make_log_mock.return_value.levelno)
+        channel.log.logger.handle.assert_called_once_with(
+            make_log_mock.return_value)
+
 
 class UnMonkeyPatch(base.BaseTestCase):
 

releasenotes/notes/context-logger-06b475357bebadc7.yaml

@@ -0,0 +1,15 @@
+---
+features:
+  - |
+    ``PrivContext`` accepts a new string parameter called ``logger_name`` to
+    define the logger we want to use for the daemon logs of this context.
+
+    By default all contexts use ``oslo_privsep.daemon``, but in some cases we
+    may need finer grained log levels, for example nova running in debug mode
+    could log its own privsep calls on INFO level regardless, but leave all
+    libraries' privsep calls, such as os-brick's, to be logged in the normal
+    DEBUG level.
+
+    See `bug 1922052`_.
+
+    .. _`bug 1922052`: https://bugs.launchpad.net/nova/+bug/1922052