summaryrefslogtreecommitdiff
diff options
context:
space:
mode:
authormathieui <mathieui@mathieui.net>2017-11-21 21:24:10 +0100
committermathieui <mathieui@mathieui.net>2017-11-21 22:40:43 +0100
commit057f7ac9f5073b87b42da3509d03914a9e79a08b (patch)
tree63cc7777eeee6bf14ef8d15cd9e70ce01395677b
parent094c62750f9b54cba43b8ff7b7c6581861b180a9 (diff)
downloadpoezio-057f7ac9f5073b87b42da3509d03914a9e79a08b.tar.gz
poezio-057f7ac9f5073b87b42da3509d03914a9e79a08b.tar.bz2
poezio-057f7ac9f5073b87b42da3509d03914a9e79a08b.tar.xz
poezio-057f7ac9f5073b87b42da3509d03914a9e79a08b.zip
Refactor logger.py to make it more testable
Also fixes: - release the message log mmap when we are done with it - Write the right character in log lines
-rw-r--r--Makefile2
-rw-r--r--poezio/logger.py174
-rw-r--r--test/test_logger.py24
3 files changed, 120 insertions, 80 deletions
diff --git a/Makefile b/Makefile
index 5745b57e..1f3d1d93 100644
--- a/Makefile
+++ b/Makefile
@@ -24,7 +24,7 @@ doc:
make -C doc/ html
test:
- py.test -v test/
+ py.test test/
release:
rm -fr $(TMPDIR)/poezio-$(version)
diff --git a/poezio/logger.py b/poezio/logger.py
index 7302df2a..d2e2214f 100644
--- a/poezio/logger.py
+++ b/poezio/logger.py
@@ -171,60 +171,14 @@ class Logger(object):
# do that efficiently, instead of seek()s and read()s which are costly.
with fd:
try:
- m = mmap.mmap(fd.fileno(), 0, prot=mmap.PROT_READ)
+ lines = get_lines_from_fd(fd, nb=nb)
except Exception: # file probably empty
log.error(
'Unable to mmap the log file for (%s)',
os.path.join(log_dir, jid),
exc_info=True)
return
- pos = m.rfind(b"\nM") # start of messages begin with MI or MR,
- # after a \n
- # number of message found so far
- count = 0
- while pos != -1 and count < nb - 1:
- count += 1
- pos = m.rfind(b"\nM", 0, pos)
- if pos == -1: # If we don't have enough lines in the file
- pos = 1 # 1, because we do -1 just on the next line
- # to get 0 (start of the file)
- lines = m[pos - 1:].decode(errors='replace').splitlines()
-
- messages = []
- color = '\x19%s}' % dump_tuple(get_theme().COLOR_LOG_MSG)
-
- # now convert that data into actual Message objects
- idx = 0
- while idx < len(lines):
- if lines[idx].startswith(' '): # should not happen ; skip
- idx += 1
- log.debug('fail?')
- continue
- log_item = parse_log_line(lines[idx])
- idx += 1
- if not isinstance(log_item, LogItem):
- log.debug('wrong log format? %s', log_item)
- continue
- message = {
- 'lines': [],
- 'history': True,
- 'time': common.get_local_time(log_item.time)
- }
- size = log_item.nb_lines
- if isinstance(log_item, LogInfo):
- message['lines'].append(color + log_item.text)
- elif isinstance(log_item, LogMessage):
- message['nickname'] = log_item.nick
- message['lines'].append(color + log_item.text)
- while size != 0 and idx < len(lines):
- message['lines'].append(lines[idx][1:])
- size -= 1
- idx += 1
- message['txt'] = '\n'.join(message['lines'])
- del message['lines']
- messages.append(message)
-
- return messages
+ return parse_log_lines(lines)
def log_message(self, jid, nick, msg, date=None, typ=1):
"""
@@ -234,12 +188,11 @@ class Logger(object):
1 = Message
2 = Status/whatever
"""
- if not typ:
- return True
-
- jid = str(jid).replace('/', '\\')
if not config.get_by_tabname('use_log', jid):
return True
+ logged_msg = build_log_message(nick, msg, date=date, typ=typ)
+ if not logged_msg:
+ return True
if jid in self._fds.keys():
fd = self._fds[jid]
else:
@@ -247,30 +200,8 @@ class Logger(object):
if not fd:
return True
try:
- msg = clean_text(msg)
- if date is None:
- str_time = common.get_utc_time().strftime('%Y%m%dT%H:%M:%SZ')
- else:
- str_time = common.get_utc_time(date).strftime(
- '%Y%m%dT%H:%M:%SZ')
- if typ == 1:
- prefix = 'MR'
- else:
- prefix = 'MI'
- lines = msg.split('\n')
- first_line = lines.pop(0)
- nb_lines = str(len(lines)).zfill(3)
-
- if nick:
- nick = '<' + nick + '>'
- fd.write('%s %s %s %s %s\n' % (prefix, str_time, nb_lines,
- nick, first_line))
- else:
- fd.write('%s %s %s %s\n' % (prefix, str_time, nb_lines,
- first_line))
- for line in lines:
- fd.write(' %s\n' % line)
- except:
+ fd.write(logged_msg)
+ except OSError:
log.error(
'Unable to write in the log file (%s)',
os.path.join(log_dir, jid),
@@ -324,6 +255,97 @@ class Logger(object):
return True
+def build_log_message(nick, msg, date=None, typ=1):
+ """
+ Create a log message from a nick, a message, optionally a date and type
+ message types:
+ 0 = Don’t log
+ 1 = Message
+ 2 = Status/whatever
+ """
+ if not typ:
+ return ''
+
+ msg = clean_text(msg)
+ if date is None:
+ str_time = common.get_utc_time().strftime('%Y%m%dT%H:%M:%SZ')
+ else:
+ str_time = common.get_utc_time(date).strftime('%Y%m%dT%H:%M:%SZ')
+ if typ == 1:
+ prefix = 'MR'
+ else:
+ prefix = 'MI'
+ lines = msg.split('\n')
+ first_line = lines.pop(0)
+ nb_lines = str(len(lines)).zfill(3)
+ if nick:
+ nick = '<' + nick + '>'
+ logged_msg = '%s %s %s %s  %s\n' % (prefix, str_time, nb_lines, nick,
+ first_line)
+ else:
+ logged_msg = '%s %s %s %s\n' % (prefix, str_time, nb_lines, first_line)
+ return logged_msg + ''.join(' %s\n' % line for line in lines)
+
+
+def get_lines_from_fd(fd, nb=10):
+ """
+ Get the last log lines from a fileno
+ """
+ with mmap.mmap(fd.fileno(), 0, prot=mmap.PROT_READ) as m:
+ pos = m.rfind(b"\nM") # start of messages begin with MI or MR,
+ # after a \n
+ # number of message found so far
+ count = 0
+ while pos != -1 and count < nb - 1:
+ count += 1
+ pos = m.rfind(b"\nM", 0, pos)
+ if pos == -1: # If we don't have enough lines in the file
+ pos = 1 # 1, because we do -1 just on the next line
+ # to get 0 (start of the file)
+ lines = m[pos - 1:].decode(errors='replace').splitlines()
+ return lines
+
+
+def parse_log_lines(lines):
+ """
+ Parse raw log lines into poezio log objects
+ """
+ messages = []
+ color = '\x19%s}' % dump_tuple(get_theme().COLOR_LOG_MSG)
+
+ # now convert that data into actual Message objects
+ idx = 0
+ while idx < len(lines):
+ if lines[idx].startswith(' '): # should not happen ; skip
+ idx += 1
+ log.debug('fail?')
+ continue
+ log_item = parse_log_line(lines[idx])
+ idx += 1
+ if not isinstance(log_item, LogItem):
+ log.debug('wrong log format? %s', log_item)
+ continue
+ message = {
+ 'lines': [],
+ 'history': True,
+ 'time': common.get_local_time(log_item.time)
+ }
+ size = log_item.nb_lines
+ if isinstance(log_item, LogInfo):
+ message['lines'].append(color + log_item.text)
+ elif isinstance(log_item, LogMessage):
+ message['nickname'] = log_item.nick
+ message['lines'].append(color + log_item.text)
+ while size != 0 and idx < len(lines):
+ message['lines'].append(lines[idx][1:])
+ size -= 1
+ idx += 1
+ message['txt'] = '\n'.join(message['lines'])
+ del message['lines']
+ messages.append(message)
+ return messages
+
+
def create_logger():
"Create the global logger object"
global logger
diff --git a/test/test_logger.py b/test/test_logger.py
index b2f7c335..f1851d60 100644
--- a/test/test_logger.py
+++ b/test/test_logger.py
@@ -1,15 +1,33 @@
"""
Test the functions in the `logger` module
"""
-
-from poezio.logger import LogMessage, parse_log_line
+import datetime
+from poezio.logger import LogMessage, parse_log_line, parse_log_lines, build_log_message
+from poezio.common import get_utc_time, get_local_time
def test_parse_message():
line = 'MR 20170909T09:09:09Z 000 <nick>  body'
assert vars(parse_log_line(line)) == vars(LogMessage('2017', '09', '09', '09', '09', '09', '0', 'nick', 'body'))
line = '<>'
- assert parse_log_line(line) == None
+ assert parse_log_line(line) is None
line = 'MR 20170908T07:05:04Z 003 <nick>  '
assert vars(parse_log_line(line)) == vars(LogMessage('2017', '09', '08', '07', '05', '04', '003', 'nick', ''))
+
+
+def test_log_and_parse_messages():
+ msg1 = {'nick': 'toto', 'msg': 'coucou', 'date': datetime.datetime.now().replace(microsecond=0)}
+ msg1_utc = get_utc_time(msg1['date'])
+ built_msg1 = build_log_message(**msg1)
+ assert built_msg1 == 'MR %s 000 <toto>  coucou\n' % (msg1_utc.strftime('%Y%m%dT%H:%M:%SZ'))
+
+ msg2 = {'nick': 'toto', 'msg': 'coucou\ncoucou', 'date': datetime.datetime.now().replace(microsecond=0)}
+ built_msg2 = build_log_message(**msg2)
+ msg2_utc = get_utc_time(msg2['date'])
+ assert built_msg2 == 'MR %s 001 <toto>  coucou\n coucou\n' % (msg2_utc.strftime('%Y%m%dT%H:%M:%SZ'))
+
+ assert parse_log_lines((built_msg1 + built_msg2).split('\n')) == [
+ {'time': msg1['date'], 'history': True, 'txt': '\x195,-1}coucou', 'nickname': 'toto'},
+ {'time': msg2['date'], 'history': True, 'txt': '\x195,-1}coucou\ncoucou', 'nickname': 'toto'},
+ ]