Skip to content

Commit

Permalink
added verbosity levels to log
Browse files Browse the repository at this point in the history
  • Loading branch information
cannatag committed May 4, 2015
1 parent 34cf659 commit 22d29f1
Show file tree
Hide file tree
Showing 3 changed files with 51 additions and 38 deletions.
52 changes: 26 additions & 26 deletions ldap3/core/connection.py
Original file line number Diff line number Diff line change
Expand Up @@ -367,7 +367,7 @@ def bind(self,
"""
if log_enabled():
log(VERBOSITY_LOW, 'start BIND operation via %s', self)
log(VERBOSITY_LOW, 'start BIND operation via <%s>', self)

with self.lock:
if self.lazy and not self._executing_deferred:
Expand Down Expand Up @@ -426,7 +426,7 @@ def bind(self,
self._entries = None

if log_enabled():
log(VERBOSITY_LOW, 'done BIND operation, result %s', self.bound)
log(VERBOSITY_LOW, 'done BIND operation, result <%s>', self.bound)

return self.bound

Expand All @@ -438,7 +438,7 @@ def unbind(self,
"""
if log_enabled():
log(VERBOSITY_LOW, 'start UNBIND operation via %s', self)
log(VERBOSITY_LOW, 'start UNBIND operation via <%s>', self)

with self.lock:
if self.lazy and not self._executing_deferred and (self._deferred_bind or self._deferred_open): # clear deferred status
Expand All @@ -452,7 +452,7 @@ def unbind(self,
self.strategy.close()

if log_enabled():
log(VERBOSITY_LOW, 'done UNBIND operation, result %s', self.bound)
log(VERBOSITY_LOW, 'done UNBIND operation, result <%s>', True)

return True

Expand Down Expand Up @@ -485,7 +485,7 @@ def search(self,
LDAP operation is performed
"""
if log_enabled():
log(VERBOSITY_LOW, 'start SEARCH operation via %s', self)
log(VERBOSITY_LOW, 'start SEARCH operation via <%s>', self)

with self.lock:
self._fire_deferred()
Expand Down Expand Up @@ -517,7 +517,7 @@ def search(self,
return_value = True if self.result['type'] == 'searchResDone' and len(response) > 0 else False

if log_enabled():
log(VERBOSITY_LOW, 'done SEARCH operation, result %s', return_value)
log(VERBOSITY_LOW, 'done SEARCH operation, result <%s>', return_value)

return return_value

Expand All @@ -530,7 +530,7 @@ def compare(self,
Perform a compare operation
"""
if log_enabled():
log(VERBOSITY_LOW, 'start COMPARE operation via %s', self)
log(VERBOSITY_LOW, 'start COMPARE operation via <%s>', self)

with self.lock:
self._fire_deferred()
Expand All @@ -543,7 +543,7 @@ def compare(self,
return_value = True if self.result['type'] == 'compareResponse' and self.result['result'] == RESULT_COMPARE_TRUE else False

if log_enabled():
log(VERBOSITY_LOW, 'done COMPARE operation, result %s', return_value)
log(VERBOSITY_LOW, 'done COMPARE operation, result <%s>', return_value)

return return_value

Expand All @@ -560,7 +560,7 @@ def add(self,
['val1', 'val2', ...] for multivalued attributes
"""
if log_enabled():
log(VERBOSITY_LOW, 'start ADD operation via %s', self)
log(VERBOSITY_LOW, 'start ADD operation via <%s>', self)

with self.lock:
self._fire_deferred()
Expand Down Expand Up @@ -597,7 +597,7 @@ def add(self,
return_value = True if self.result['type'] == 'addResponse' and self.result['result'] == RESULT_SUCCESS else False

if log_enabled():
log(VERBOSITY_LOW, 'done ADD operation, result %s', return_value)
log(VERBOSITY_LOW, 'done ADD operation, result <%s>', return_value)

return return_value

Expand All @@ -608,7 +608,7 @@ def delete(self,
Delete the entry identified by the DN from the DIB.
"""
if log_enabled():
log(VERBOSITY_LOW, 'start DELETE operation via %s', self)
log(VERBOSITY_LOW, 'start DELETE operation via <%s>', self)

with self.lock:
self._fire_deferred()
Expand All @@ -626,7 +626,7 @@ def delete(self,
return_value = True if self.result['type'] == 'delResponse' and self.result['result'] == RESULT_SUCCESS else False

if log_enabled():
log(VERBOSITY_LOW, 'done DELETE operation, result %s', return_value)
log(VERBOSITY_LOW, 'done DELETE operation, result <%s>', return_value)

return return_value

Expand All @@ -642,7 +642,7 @@ def modify(self,
- Operation is 0 (MODIFY_ADD), 1 (MODIFY_DELETE), 2 (MODIFY_REPLACE), 3 (MODIFY_INCREMENT)
"""
if log_enabled():
log(VERBOSITY_LOW, 'start MODIFY operation via %s', self)
log(VERBOSITY_LOW, 'start MODIFY operation via <%s>', self)

with self.lock:
self._fire_deferred()
Expand Down Expand Up @@ -676,7 +676,7 @@ def modify(self,
return_value = True if self.result['type'] == 'modifyResponse' and self.result['result'] == RESULT_SUCCESS else False

if log_enabled():
log(VERBOSITY_LOW, 'done MODIFY operation, result %s', return_value)
log(VERBOSITY_LOW, 'done MODIFY operation, result <%s>', return_value)

return return_value

Expand All @@ -691,7 +691,7 @@ def modify_dn(self,
DIT.
"""
if log_enabled():
log(VERBOSITY_LOW, 'start MODIFY DN operation via %s', self)
log(VERBOSITY_LOW, 'start MODIFY DN operation via <%s>', self)

with self.lock:
self._fire_deferred()
Expand All @@ -713,7 +713,7 @@ def modify_dn(self,
return_value = True if self.result['type'] == 'modDNResponse' and self.result['result'] == RESULT_SUCCESS else False

if log_enabled():
log(VERBOSITY_LOW, 'done MODIFY DN operation, result %s', return_value)
log(VERBOSITY_LOW, 'done MODIFY DN operation, result <%s>', return_value)

return return_value

Expand All @@ -724,7 +724,7 @@ def abandon(self,
Abandon the operation indicated by message_id
"""
if log_enabled():
log(VERBOSITY_LOW, 'start ABANDON operation via %s', self)
log(VERBOSITY_LOW, 'start ABANDON operation via <%s>', self)

with self.lock:
self._fire_deferred()
Expand All @@ -739,7 +739,7 @@ def abandon(self,
return_value = True

if log_enabled():
log(VERBOSITY_LOW, 'done ABANDON operation, result %s', return_value)
log(VERBOSITY_LOW, 'done ABANDON operation, result <%s>', return_value)

return return_value

Expand All @@ -751,7 +751,7 @@ def extended(self,
Performs an extended operation
"""
if log_enabled():
log(VERBOSITY_LOW, 'start EXTENDED operation via %s', self)
log(VERBOSITY_LOW, 'start EXTENDED operation <via> %s', self)

with self.lock:
self._fire_deferred()
Expand All @@ -764,14 +764,14 @@ def extended(self,
return_value = True if self.result['type'] == 'extendedResp' and self.result['result'] == RESULT_SUCCESS else False

if log_enabled():
log(VERBOSITY_LOW, 'done EXTENDED operation, result %s', return_value)
log(VERBOSITY_LOW, 'done EXTENDED operation, result <%s>', return_value)

return return_value

def start_tls(self, read_server_info=True): # as per RFC4511. Removal of TLS is defined as MAY in RFC4511 so the client can't implement a generic stop_tls method0

if log_enabled():
log(VERBOSITY_LOW, 'start START TLS operation via %s', self)
log(VERBOSITY_LOW, 'start START TLS operation via <%s>', self)

with self.lock:
return_value = False
Expand All @@ -792,14 +792,14 @@ def start_tls(self, read_server_info=True): # as per RFC4511. Removal of TLS is
return_value = True

if log_enabled():
log(VERBOSITY_LOW, 'done START TLS operation, result %s', return_value)
log(VERBOSITY_LOW, 'done START TLS operation, result <%s>', return_value)

return return_value

def do_sasl_bind(self,
controls):
if log_enabled():
log(VERBOSITY_LOW, 'start SASL BIND operation via %s', self)
log(VERBOSITY_LOW, 'start SASL BIND operation via <%s>', self)

with self.lock:
result = None
Expand All @@ -816,14 +816,14 @@ def do_sasl_bind(self,
self.sasl_in_progress = False

if log_enabled():
log(VERBOSITY_LOW, 'done SASL BIND operation, result %s', result)
log(VERBOSITY_LOW, 'done SASL BIND operation, result <%s>', result)

return result

def do_ntlm_bind(self,
controls):
if log_enabled():
log(VERBOSITY_LOW, 'start NTLM BIND operation via %s', self)
log(VERBOSITY_LOW, 'start NTLM BIND operation via <%s>', self)

with self.lock:
result = None
Expand Down Expand Up @@ -867,7 +867,7 @@ def do_ntlm_bind(self,
self.sasl_in_progress = False

if log_enabled():
log(VERBOSITY_LOW, 'done SASL NTLM operation, result %s', result)
log(VERBOSITY_LOW, 'done SASL NTLM operation, result <%s>', result)

return result

Expand Down
12 changes: 6 additions & 6 deletions ldap3/core/server.py
Original file line number Diff line number Diff line change
Expand Up @@ -199,7 +199,7 @@ def address_info(self):

if log_enabled():
for address in self._address_info:
log(VERBOSITY_MEDIUM, 'address for %s resolved at %r', self, address[:-2])
log(VERBOSITY_MEDIUM, 'address for <%s> resolved at <%r>', self, address[:-2])
return self._address_info

def update_availability(self, address, available):
Expand Down Expand Up @@ -240,12 +240,12 @@ def check_availability(self):

if available:
if log_enabled():
log(VERBOSITY_MEDIUM, 'server %s available at %r', self, address)
log(VERBOSITY_MEDIUM, 'server <%s> available at <%r>', self, address)
self.update_availability(address, True)
break # if an available address is found exits immediately
else:
self.update_availability(address, False)
log(VERBOSITY_LOW, 'server %s not available at %r', self, address)
log(VERBOSITY_LOW, 'server <%s> not available at <%r>', self, address)

return available

Expand Down Expand Up @@ -291,7 +291,7 @@ def _get_dsa_info(self, connection):
self._dsa_info = DsaInfo(results[0]['attributes'], results[0]['raw_attributes'])

if log_enabled():
log(VERBOSITY_MEDIUM, 'DSA info read for %s via %s', self, connection)
log(VERBOSITY_MEDIUM, 'DSA info read for <%s> via <%s>', self, connection)

def _get_schema_info(self, connection, entry=''):
"""
Expand Down Expand Up @@ -347,7 +347,7 @@ def _get_schema_info(self, connection, entry=''):
for attribute in self._dsa_info.other:
self._dsa_info.other[attribute] = format_attribute_values(self._schema_info, attribute, self._dsa_info.raw[attribute], self.custom_formatter)
if log_enabled():
log(VERBOSITY_MEDIUM, 'schema read for %s via %s', self, connection)
log(VERBOSITY_MEDIUM, 'schema read for <%s> via <%s>', self, connection)

def get_info_from_server(self, connection):
"""
Expand Down Expand Up @@ -442,5 +442,5 @@ def candidate_addresses(self):

if log_enabled():
for candidate in candidates:
log(VERBOSITY_LOW, 'candidate address for %s: %r', self, candidate[:-2])
log(VERBOSITY_LOW, 'candidate address for <%s>: <%r>', self, candidate[:-2])
return candidates
25 changes: 19 additions & 6 deletions ldap3/utils/log.py
Original file line number Diff line number Diff line change
Expand Up @@ -26,9 +26,9 @@
from logging import getLogger, getLevelName, DEBUG

# logging
VERBOSITY_HIGH = 10
VERBOSITY_LOW = 10
VERBOSITY_MEDIUM = 20
VERBOSITY_LOW = 30
VERBOSITY_HIGH = 30
VERBOSITY_LEVELS = [VERBOSITY_LOW, VERBOSITY_MEDIUM, VERBOSITY_HIGH]
LIBRARY_VERBOSITY_LEVEL = VERBOSITY_MEDIUM
LIBRARY_LOGGING_LEVEL = DEBUG
Expand All @@ -43,18 +43,31 @@

class NullHandler(Handler):
def handle(self, record):
"""Stub."""
pass

def emit(self, record):
"""Stub."""
pass

def createLock(self):
self.lock = None


def get_verbosity_level_name(level):

if level == VERBOSITY_LOW:
return 'VERBOSITY_LOW'
elif level == VERBOSITY_MEDIUM:
return 'VERBOSITY_MEDIUM'
elif level == VERBOSITY_HIGH:
return 'VERBOSITY_HIGH'

raise ValueError('unknown verbosity level')


def log(verbosity, message, *args):
if verbosity <= verbosity_level:
logger.log(logging_level, message, *args)
logger.log(logging_level, '[' + get_verbosity_level_name(verbosity) + '] ' + message, *args)


def log_enabled():
return True if logger.isEnabledFor(logging_level) else False
Expand All @@ -78,4 +91,4 @@ def set_library_verbosity_level(verbosity):
set_library_verbosity_level(LIBRARY_VERBOSITY_LEVEL)

# emits a info message to let the application know that ldap3 logging is available when the log level is set to logging_level
logger.info('ldap3 library intialized - logging emitted when loglevel is' + getLevelName(logging_level))
logger.info('ldap3 library intialized - logging emitted when loglevel is ' + getLevelName(logging_level))

0 comments on commit 22d29f1

Please sign in to comment.