Skip to content

Commit

Permalink
logging: remove object-specific loggers
Browse files Browse the repository at this point in the history 
Remove all object-specific loggers, with the exception of `Plugin.log`,
which is now deprecated. Replace affected logger calls with module-level
logger calls.

Deprecate object-specific loggers in `ipa_log_manager.get_logger`.

Reviewed-By: Martin Basti <[email protected]>
  • Loading branch information
@MartinBasti
Jan Cholasta authored and MartinBasti committed Jul 14, 2017
1 parent 9d19654 commit ffadcb0
Show file tree
Hide file tree
Showing 72 changed files with 1,095 additions and 783 deletions.
20 changes: 11 additions & 9 deletions ipaclient/install/ipa_certupdate.py
View file
Original file line number Diff line number Diff line change
Expand Up @@ -17,6 +17,7 @@
# along with this program. If not, see <http://www.gnu.org/licenses/>.
#

import logging
import os
import tempfile
import shutil
Expand All @@ -34,6 +35,8 @@
from ipalib import api, errors, x509
from ipalib.constants import IPA_CA_NICKNAME, RENEWAL_CA_NAME

logger = logging.getLogger(__name__)


class CertUpdate(admintool.AdminTool):
command_name = 'ipa-certupdate'
Expand Down Expand Up @@ -103,10 +106,9 @@ def run(self):
# pylint: disable=import-error,ipa-forbidden-import
from ipaserver.install import cainstance
# pylint: enable=import-error,ipa-forbidden-import
cainstance.add_lightweight_ca_tracking_requests(
self.log, lwcas)
cainstance.add_lightweight_ca_tracking_requests(lwcas)
except Exception:
self.log.exception(
logger.exception(
"Failed to add lightweight CA tracking requests")

self.update_client(certs)
Expand All @@ -124,8 +126,8 @@ def update_client(self, certs):
try:
ipa_db.delete_cert(nickname)
except ipautil.CalledProcessError as e:
self.log.error("Failed to remove %s from %s: %s",
nickname, ipa_db.secdir, e)
logger.error("Failed to remove %s from %s: %s",
nickname, ipa_db.secdir, e)
break

self.update_db(ipa_db.secdir, certs)
Expand Down Expand Up @@ -153,7 +155,7 @@ def update_server(self, certs):
if request_id is not None:
timeout = api.env.startup_timeout + 60

self.log.debug("resubmitting certmonger request '%s'", request_id)
logger.debug("resubmitting certmonger request '%s'", request_id)
certmonger.resubmit_request(
request_id, ca='dogtag-ipa-ca-renew-agent-reuse', profile='')
try:
Expand All @@ -168,7 +170,7 @@ def update_server(self, certs):
"Error resubmitting certmonger request '%s', "
"please check the request manually" % request_id)

self.log.debug("modifying certmonger request '%s'", request_id)
logger.debug("modifying certmonger request '%s'", request_id)
certmonger.modify(request_id, ca='dogtag-ipa-ca-renew-agent')

self.update_file(paths.CA_CRT, certs)
Expand All @@ -179,7 +181,7 @@ def update_file(self, filename, certs, mode=0o444):
try:
x509.write_certificate_list(certs, filename)
except Exception as e:
self.log.error("failed to update %s: %s", filename, e)
logger.error("failed to update %s: %s", filename, e)

def update_db(self, path, certs):
db = certdb.NSSDatabase(path)
Expand All @@ -189,5 +191,5 @@ def update_db(self, path, certs):
try:
db.add_cert(cert, nickname, trust_flags)
except ipautil.CalledProcessError as e:
self.log.error(
logger.error(
"failed to update %s in %s: %s", nickname, path, e)
13 changes: 7 additions & 6 deletions ipalib/__init__.py
View file
Original file line number Diff line number Diff line change
Expand Up @@ -527,7 +527,7 @@ class my_command(Command):
Also note that your ``execute()`` method should not contain any ``print``
statements or otherwise cause any output on ``sys.stdout``. Your command can
(and should) produce log messages by using ``self.log`` (see below).
(and should) produce log messages by using a module-level logger (see below).
To learn more about XML-RPC (XML Remote Procedure Call), see:
Expand Down Expand Up @@ -670,18 +670,19 @@ class my_command(Command):
Logging from your plugin
------------------------
After `plugable.Plugin.__init__()` is called, your plugin will have a
``self.log`` attribute. Plugins should only log through this attribute.
Plugins should log through a module-level logger.
For example:
>>> import logging
>>> logger = logging.getLogger(__name__)
>>> class paint_house(Command):
...
... takes_args = 'color'
...
... def execute(self, color, **options):
... """Uses self.log.error()"""
... """Uses logger.error()"""
... if color not in ('red', 'blue', 'green'):
... self.log.error("I don't have %s paint!", color) # Log error
... logger.error("I don't have %s paint!", color) # Log error
... return
... return 'I painted the house %s.' % color
...
Expand All @@ -691,7 +692,7 @@ class my_command(Command):
http://docs.python.org/library/logging.html
The important thing to remember is that your plugin should not configure
logging itself, but should instead simply use the ``self.log`` logger.
logging itself, but should instead simply use the module-level logger.
Also see the `plugable.API.bootstrap()` method for details on how the logging
is configured.
Expand Down
9 changes: 6 additions & 3 deletions ipalib/backend.py
View file
Original file line number Diff line number Diff line change
Expand Up @@ -21,13 +21,16 @@
Base classes for all backed-end plugins.
"""

import logging
import threading
import os

from ipalib import plugable
from ipalib.errors import PublicError, InternalError, CommandError
from ipalib.request import context, Connection, destroy_context

logger = logging.getLogger(__name__)


class Backend(plugable.Plugin):
"""
Expand Down Expand Up @@ -66,7 +69,7 @@ def connect(self, *args, **kw):
conn = self.create_connection(*args, **kw)
setattr(context, self.id, Connection(conn, self.disconnect))
assert self.conn is conn
self.debug('Created connection context.%s' % self.id)
logger.debug('Created connection context.%s', self.id)

def create_connection(self, *args, **kw):
raise NotImplementedError('%s.create_connection()' % self.id)
Expand All @@ -82,7 +85,7 @@ def disconnect(self):
)
self.destroy_connection()
delattr(context, self.id)
self.debug('Destroyed connection context.%s' % self.id)
logger.debug('Destroyed connection context.%s', self.id)

def destroy_connection(self):
raise NotImplementedError('%s.destroy_connection()' % self.id)
Expand Down Expand Up @@ -140,7 +143,7 @@ def execute(self, _name, *args, **options):
except PublicError as e:
error = e
except Exception as e:
self.exception(
logger.exception(
'non-public: %s: %s', e.__class__.__name__, str(e)
)
error = InternalError()
Expand Down
10 changes: 7 additions & 3 deletions ipalib/frontend.py
View file
Original file line number Diff line number Diff line change
Expand Up @@ -20,6 +20,8 @@
"""
Base classes for all front-end plugins.
"""
import logging

import six

from ipapython.version import API_VERSION
Expand All @@ -41,6 +43,8 @@
if six.PY3:
unicode = str

logger = logging.getLogger(__name__)

RULE_FLAG = 'validation_rule'

def rule(obj):
Expand Down Expand Up @@ -459,14 +463,14 @@ def __do_call(self, *args, **options):
self.add_message(
messages.VersionMissing(server_version=self.api_version))
params = self.args_options_2_params(*args, **options)
self.debug(
logger.debug(
'raw: %s(%s)', self.name, ', '.join(self._repr_iter(**params))
)
if self.api.env.in_server:
params.update(self.get_default(**params))
params = self.normalize(**params)
params = self.convert(**params)
self.debug(
logger.debug(
'%s(%s)', self.name, ', '.join(self._repr_iter(**params))
)
if self.api.env.in_server:
Expand Down Expand Up @@ -1463,7 +1467,7 @@ def execute(self, **options):
raise NotImplementedError('%s.execute()' % self.name)

def __call__(self, **options):
self.debug(
logger.debug(
'raw: %s', self.name
)

Expand Down
50 changes: 28 additions & 22 deletions ipalib/rpc.py
View file
Original file line number Diff line number Diff line change
Expand Up @@ -34,6 +34,7 @@

from decimal import Decimal
import datetime
import logging
import os
import locale
import base64
Expand Down Expand Up @@ -91,6 +92,8 @@
if six.PY3:
unicode = str

logger = logging.getLogger(__name__)

COOKIE_NAME = 'ipa_session'
CCACHE_COOKIE_KEY = 'X-IPA-Session-Cookie'

Expand Down Expand Up @@ -889,8 +892,7 @@ def get_session_cookie_from_persistent_storage(self, principal):
cookie_string = read_persistent_client_session_data(principal)
cookie_string = cookie_string.decode('utf-8')
except Exception as e:
self.log.debug('Error reading client session data: {err}'
.format(err=e))
logger.debug('Error reading client session data: %s', e)
return None

# Search for the session cookie within the cookie string
Expand All @@ -899,9 +901,9 @@ def get_session_cookie_from_persistent_storage(self, principal):
cookie_string, COOKIE_NAME,
timestamp=datetime.datetime.utcnow())
except Exception as e:
self.log.debug(
'Error retrieving cookie from the persistent storage: {err}'
.format(err=e))
logger.debug(
'Error retrieving cookie from the persistent storage: %s',
e)
return None

return session_cookie
Expand Down Expand Up @@ -934,33 +936,37 @@ def apply_session_cookie(self, url):

session_cookie = self.get_session_cookie_from_persistent_storage(principal)
if session_cookie is None:
self.log.debug("failed to find session_cookie in persistent storage for principal '%s'",
principal)
logger.debug("failed to find session_cookie in persistent storage "
"for principal '%s'",
principal)
return original_url
else:
self.debug("found session_cookie in persistent storage for principal '%s', cookie: '%s'",
principal, session_cookie)
logger.debug("found session_cookie in persistent storage for "
"principal '%s', cookie: '%s'",
principal, session_cookie)

# Decide if we should send the cookie to the server
try:
session_cookie.http_return_ok(original_url)
except Cookie.Expired as e:
self.debug("deleting session data for principal '%s': %s", principal, e)
logger.debug("deleting session data for principal '%s': %s",
principal, e)
try:
delete_persistent_client_session_data(principal)
except Exception as e:
pass
return original_url
except Cookie.URLMismatch as e:
self.debug("not sending session cookie, URL mismatch: %s", e)
logger.debug("not sending session cookie, URL mismatch: %s", e)
return original_url
except Exception as e:
self.error("not sending session cookie, unknown error: %s", e)
logger.error("not sending session cookie, unknown error: %s", e)
return original_url

# O.K. session_cookie is valid to be returned, stash it away where it will will
# get included in a HTTP Cookie headed sent to the server.
self.log.debug("setting session_cookie into context '%s'", session_cookie.http_cookie())
logger.debug("setting session_cookie into context '%s'",
session_cookie.http_cookie())
setattr(context, 'session_cookie', session_cookie.http_cookie())

# Form the session URL by substituting the session path into the original URL
Expand Down Expand Up @@ -1023,7 +1029,7 @@ def create_connection(self, ccache=None, verbose=None, fallback=None,
transport_class = LanguageAwareTransport
proxy_kw['transport'] = transport_class(
protocol=self.protocol, service='HTTP', ccache=ccache)
self.log.info('trying %s' % url)
logger.info('trying %s', url)
setattr(context, 'request_url', url)
serverproxy = self.server_proxy_class(url, **proxy_kw)
if len(urls) == 1:
Expand Down Expand Up @@ -1066,15 +1072,15 @@ def create_connection(self, ccache=None, verbose=None, fallback=None,
if not fallback:
raise
else:
self.log.info(
logger.info(
'Connection to %s failed with %s', url, e)
# try the next url
break
except Exception as e:
if not fallback:
raise
else:
self.log.info(
logger.info(
'Connection to %s failed with %s', url, e)
# try the next url
break
Expand Down Expand Up @@ -1113,14 +1119,14 @@ def forward(self, name, *args, **kw):
# each time should we be getting UNAUTHORIZED error from the server
max_tries = 5
for try_num in range(0, max_tries):
self.log.info("[try %d]: Forwarding '%s' to %s server '%s'",
try_num+1, name, self.protocol, server)
logger.info("[try %d]: Forwarding '%s' to %s server '%s'",
try_num+1, name, self.protocol, server)
try:
return self._call_command(command, params)
except Fault as e:
e = decode_fault(e)
self.debug('Caught fault %d from server %s: %s', e.faultCode,
server, e.faultString)
logger.debug('Caught fault %d from server %s: %s', e.faultCode,
server, e.faultString)
if e.faultCode in errors_by_code:
error = errors_by_code[e.faultCode]
raise error(message=e.faultString)
Expand All @@ -1143,8 +1149,8 @@ def forward(self, name, *args, **kw):
except Exception as e:
# This shouldn't happen if we have a session
# but it isn't fatal.
self.debug("Error trying to remove persisent session "
"data: {err}".format(err=e))
logger.debug("Error trying to remove persisent "
"session data: %s", e)

# Create a new serverproxy with the non-session URI
serverproxy = self.create_connection(
Expand Down
Loading

0 comments on commit ffadcb0

Please sign in to comment.