logger.py 10.5 KB
Newer Older
louiz’'s avatar
louiz’ committed
1
# Copyright 2010-2011 Florent Le Coz <louiz@louiz.org>
2 3 4 5
#
# This file is part of Poezio.
#
# Poezio is free software: you can redistribute it and/or modify
6
# it under the terms of the zlib license. See the COPYING file.
7

8 9 10 11 12
"""
The logger module that handles logging of the poezio
conversations and roster changes
"""

13
import mmap
14
import os
15
import re
mathieui's avatar
mathieui committed
16
from os import makedirs
17
from datetime import datetime
18

mathieui's avatar
mathieui committed
19 20 21 22
from poezio import common
from poezio.config import config
from poezio.xhtml import clean_text
from poezio.theming import dump_tuple, get_theme
23

24 25 26 27
import logging

log = logging.getLogger(__name__)

mathieui's avatar
mathieui committed
28
from poezio.config import LOG_DIR as log_dir
29

30
MESSAGE_LOG_RE = re.compile(r'^MR (\d{4})(\d{2})(\d{2})T'
31
                            r'(\d{2}):(\d{2}):(\d{2})Z '
32 33
                            r'(\d+) <([^ ]+)>  (.*)$')
INFO_LOG_RE = re.compile(r'^MI (\d{4})(\d{2})(\d{2})T'
34
                         r'(\d{2}):(\d{2}):(\d{2})Z '
35
                         r'(\d+) (.*)$')
36

mathieui's avatar
mathieui committed
37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53
class LogItem:
    def __init__(self, year, month, day, hour, minute, second, nb_lines, message):
        self.time = datetime(int(year), int(month), int(day), int(hour),
                             int(minute), int(second))
        self.nb_lines = int(nb_lines)
        self.text = message

class LogInfo(LogItem):
    def __init__(self, *args):
        LogItem.__init__(self, *args)

class LogMessage(LogItem):
    def __init__(self, year, month, day, hour, minute, seconds, nb_lines, nick, message):
        LogItem.__init__(self, year, month, day, hour, minute, seconds,
                         nb_lines, message)
        self.nick = nick

54
def parse_log_line(msg):
55 56 57 58 59 60 61
    match = re.match(MESSAGE_LOG_RE, msg)
    if match:
        return LogMessage(*match.groups())
    match = re.match(INFO_LOG_RE, msg)
    if match:
        return LogInfo(*match.groups())
    log.debug('Error while parsing "%s"', msg)
62
    return None
63

64 65 66 67 68
class Logger(object):
    """
    Appends things to files. Error/information/warning logs
    and also log the conversations to logfiles
    """
69
    def __init__(self):
70
        self._roster_logfile = None
71
        # a dict of 'groupchatname': file-object (opened)
72
        self._fds = {}
73

74
    def __del__(self):
75
        for opened_file in self._fds.values():
76
            if opened_file:
mathieui's avatar
mathieui committed
77 78 79 80
                try:
                    opened_file.close()
                except: # Can't close? too bad
                    pass
81

82
    def close(self, jid):
83
        jid = str(jid).replace('/', '\\')
84 85 86 87 88
        if jid in self._fds:
            self._fds[jid].close()
            log.debug('Log file for %s closed.', jid)
            del self._fds[jid]

89 90
    def reload_all(self):
        """Close and reload all the file handles (on SIGHUP)"""
91
        for opened_file in self._fds.values():
92 93 94
            if opened_file:
                opened_file.close()
        log.debug('All log file handles closed')
95 96
        for room in self._fds:
            self._fds[room] = self._check_and_create_log_dir(room)
97
            log.debug('Log handle for %s re-created', room)
98

99
    def _check_and_create_log_dir(self, room, open_fd=True):
100
        """
101 102
        Check that the directory where we want to log the messages
        exists. if not, create it
103
        """
104
        if not config.get_by_tabname('use_log', room):
mathieui's avatar
mathieui committed
105
            return
106
        try:
107
            makedirs(log_dir)
mathieui's avatar
mathieui committed
108 109 110
        except OSError as e:
            if e.errno != 17: # file exists
                log.error('Unable to create the log dir', exc_info=True)
111 112
        except:
            log.error('Unable to create the log dir', exc_info=True)
113 114 115
            return
        if not open_fd:
            return
116
        try:
117
            fd = open(os.path.join(log_dir, room), 'a')
118
            self._fds[room] = fd
119
            return fd
120
        except IOError:
121 122 123
            log.error('Unable to open the log file (%s)',
                    os.path.join(log_dir, room),
                    exc_info=True)
124

125
    def get_logs(self, jid, nb=10):
126
        """
127 128 129 130
        Get the nb last messages from the log history for the given jid.
        Note that a message may be more than one line in these files, so
        this function is a little bit more complicated than “read the last
        nb lines”.
131
        """
132
        if config.get_by_tabname('load_log', jid) <= 0:
133 134
            return

135
        if not config.get_by_tabname('use_log', jid):
136 137
            return

138
        if nb <= 0:
139
            return
140

141
        self._check_and_create_log_dir(jid, open_fd=False)
142

143
        try:
144
            fd = open(os.path.join(log_dir, jid), 'rb')
145 146 147 148 149 150
        except FileNotFoundError:
            log.info('Non-existing log file (%s)',
                     os.path.join(log_dir, jid),
                     exc_info=True)
            return
        except OSError:
151
            log.error('Unable to open the log file (%s)',
152 153
                      os.path.join(log_dir, jid),
                      exc_info=True)
154 155 156
            return
        if not fd:
            return
157

158 159 160 161
        # read the needed data from the file, we just search nb messages by
        # searching "\nM" nb times from the end of the file.  We use mmap to
        # do that efficiently, instead of seek()s and read()s which are costly.
        with fd:
162 163 164 165 166 167 168
            try:
                m = mmap.mmap(fd.fileno(), 0, prot=mmap.PROT_READ)
            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
169 170 171 172 173 174 175 176 177 178
            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)
louiz’'s avatar
louiz’ committed
179
            lines = m[pos-1:].decode(errors='replace').splitlines()
180 181

        messages = []
182
        color = '\x19%s}' % dump_tuple(get_theme().COLOR_LOG_MSG)
183

184
        # now convert that data into actual Message objects
185 186 187 188 189 190
        idx = 0
        while idx < len(lines):
            if lines[idx].startswith(' '): # should not happen ; skip
                idx += 1
                log.debug('fail?')
                continue
191
            log_item = parse_log_line(lines[idx])
192
            idx += 1
mathieui's avatar
mathieui committed
193
            if not isinstance(log_item, LogItem):
mathieui's avatar
mathieui committed
194
                log.debug('wrong log format? %s', log_item)
195
                continue
196 197
            message = {'lines': [],
                       'history': True,
mathieui's avatar
mathieui committed
198 199 200 201 202 203 204
                       '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)
205 206 207 208 209 210 211 212 213
            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
214

215
    def log_message(self, jid, nick, msg, date=None, typ=1):
216
        """
217
        log the message in the appropriate jid's file
218 219 220
        type:
              0 = Don’t log
              1 = Message
221
              2 = Status/whatever
222
        """
223 224 225
        if not typ:
            return True

226
        jid = str(jid).replace('/', '\\')
227
        if not config.get_by_tabname('use_log', jid):
228
            return True
229 230
        if jid in self._fds.keys():
            fd = self._fds[jid]
231
        else:
232
            fd = self._check_and_create_log_dir(jid)
233
        if not fd:
mathieui's avatar
mathieui committed
234
            return True
235
        try:
mathieui's avatar
mathieui committed
236
            msg = clean_text(msg)
mathieui's avatar
mathieui committed
237
            if date is None:
238
                str_time = common.get_utc_time().strftime('%Y%m%dT%H:%M:%SZ')
mathieui's avatar
mathieui committed
239
            else:
240
                str_time = common.get_utc_time(date).strftime('%Y%m%dT%H:%M:%SZ')
241 242 243 244
            if typ == 1:
                prefix = 'MR'
            else:
                prefix = 'MI'
245 246 247 248
            lines = msg.split('\n')
            first_line = lines.pop(0)
            nb_lines = str(len(lines)).zfill(3)

249
            if nick:
250
                nick = '<' + nick + '>'
251
                fd.write('%s %s %s %s  %s\n' % (prefix, str_time, nb_lines, nick, first_line))
252
            else:
mathieui's avatar
mathieui committed
253
                fd.write('%s %s %s %s\n' % (prefix, str_time, nb_lines, first_line))
254 255
            for line in lines:
                fd.write(' %s\n' % line)
mathieui's avatar
mathieui committed
256
        except:
257 258 259
            log.error('Unable to write in the log file (%s)',
                    os.path.join(log_dir, jid),
                    exc_info=True)
mathieui's avatar
mathieui committed
260
            return False
261
        else:
mathieui's avatar
mathieui committed
262 263
            try:
                fd.flush()          # TODO do something better here?
264
            except OSError:
265 266 267
                log.error('Unable to flush the log file (%s)',
                        os.path.join(log_dir, jid),
                        exc_info=True)
mathieui's avatar
mathieui committed
268 269
                return False
        return True
270

mathieui's avatar
mathieui committed
271
    def log_roster_change(self, jid, message):
272 273 274
        """
        Log a roster change
        """
275
        if not config.get_by_tabname('use_log', jid):
276
            return True
277 278
        self._check_and_create_log_dir('', open_fd=False)
        if not self._roster_logfile:
mathieui's avatar
mathieui committed
279
            try:
280
                self._roster_logfile = open(os.path.join(log_dir, 'roster.log'), 'a')
mathieui's avatar
mathieui committed
281
            except IOError:
282 283 284
                log.error('Unable to create the log file (%s)',
                        os.path.join(log_dir, 'roster.log'),
                        exc_info=True)
mathieui's avatar
mathieui committed
285 286
                return False
        try:
287
            str_time = common.get_utc_time().strftime('%Y%m%dT%H:%M:%SZ')
288
            message = clean_text(message)
289 290 291
            lines = message.split('\n')
            first_line = lines.pop(0)
            nb_lines = str(len(lines)).zfill(3)
292
            self._roster_logfile.write('MI %s %s %s %s\n' % (str_time, nb_lines, jid, first_line))
293
            for line in lines:
294 295
                self._roster_logfile.write(' %s\n' % line)
            self._roster_logfile.flush()
mathieui's avatar
mathieui committed
296
        except:
297 298 299
            log.error('Unable to write in the log file (%s)',
                    os.path.join(log_dir, 'roster.log'),
                    exc_info=True)
mathieui's avatar
mathieui committed
300 301
            return False
        return True
mathieui's avatar
mathieui committed
302

303 304 305 306 307 308
def create_logger():
    "Create the global logger object"
    global logger
    logger = Logger()

logger = None