diff options
| -rw-r--r-- | Makefile | 2 | ||||
| -rw-r--r-- | poezio/logger.py | 174 | ||||
| -rw-r--r-- | test/test_logger.py | 24 |
3 files changed, 120 insertions, 80 deletions
@@ -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'}, + ] |