common.lib.logger

  1"""
  2Log handler
  3"""
  4import traceback
  5import platform
  6import logging
  7import time
  8import json
  9
 10from pathlib import Path
 11
 12from logging.handlers import RotatingFileHandler, HTTPHandler
 13
 14from common.config_manager import config
 15
 16
 17class WebHookLogHandler(HTTPHandler):
 18    """
 19    Basic HTTPHandler for webhooks via standard log handling
 20
 21    In essence, an HTTPHandler that formats its payload as JSON.
 22    """
 23    server_name = ""
 24
 25    def __init__(self, url):
 26        """
 27        Initialise WebHook handler
 28
 29        :param str url:  URL to send log messages to
 30        """
 31        host = url.split("/")[2]
 32        secure = url.lower().startswith("https")
 33
 34        super().__init__(host, url, method="POST", secure=secure)
 35
 36    def emit(self, record):
 37        """
 38        Emit a record
 39
 40        Send the record to the Web server as a percent-encoded dictionary
 41        This is the `emit()` method of the original HTTPHandler; the only
 42        change is that content is sent as JSON (which the webhooks expect)
 43        instead of urlencoded data.
 44
 45        :param logging.LogRecord record:  Log record to send
 46        """
 47        try:
 48            import http.client, urllib.parse
 49            host = self.host
 50            if self.secure:
 51                h = http.client.HTTPSConnection(host, context=self.context)
 52            else:
 53                h = http.client.HTTPConnection(host)
 54            url = self.url
 55            ############### CHANGED FROM ORIGINAL ###############
 56            data = json.dumps(self.mapLogRecord(record))
 57            #####################################################
 58            if self.method == "GET":
 59                if (url.find('?') >= 0):
 60                    sep = '&'
 61                else:
 62                    sep = '?'
 63                url = url + "%c%s" % (sep, data)
 64            h.putrequest(self.method, url)
 65            # support multiple hosts on one IP address...
 66            # need to strip optional :port from host, if present
 67            i = host.find(":")
 68            if i >= 0:
 69                host = host[:i]
 70            # See issue #30904: putrequest call above already adds this header
 71            # on Python 3.x.
 72            # h.putheader("Host", host)
 73            if self.method == "POST":
 74                ############### CHANGED FROM ORIGINAL ###############
 75                h.putheader("Content-type", "application/json")
 76                #####################################################
 77                h.putheader("Content-length", str(len(data)))
 78            if self.credentials:
 79                import base64
 80                s = ('%s:%s' % self.credentials).encode('utf-8')
 81                s = 'Basic ' + base64.b64encode(s).strip().decode('ascii')
 82                h.putheader('Authorization', s)
 83            h.endheaders()
 84            if self.method == "POST":
 85                h.send(data.encode('utf-8'))
 86            h.getresponse()  # can't do anything with the result
 87        except Exception:
 88            self.handleError(record)
 89
 90
 91class SlackLogHandler(WebHookLogHandler):
 92    """
 93    Slack webhook log handler
 94    """
 95
 96    def mapLogRecord(self, record):
 97        """
 98        Format log message so it is compatible with Slack webhooks
 99
100        :param logging.LogRecord record: Log record
101        """
102        if record.levelno in (logging.ERROR, logging.CRITICAL):
103            color = "#FF0000"  # red
104        elif record.levelno == logging.WARNING:
105            color = "#DD7711"  # orange
106        else:
107            color = "#3CC619"  # green
108
109        # simple stack trace
110        # the last 9 frames are not specific to the exception (general logging code etc)
111        # the frame before that is where the exception was raised
112        frames = traceback.extract_stack()[:-9]
113        location = "`%s`" % "` → `".join([frame.filename.split("/")[-1] + ":" + str(frame.lineno) for frame in frames])
114
115        # prepare slack webhook payload
116        fields = [{
117            "title": "Stack trace:",
118            "value": location,
119            "short": False
120        }]
121
122        # try to read some metadata from the offending file
123        try:
124            with Path(record.frame.filename).open() as infile:
125                fields.append({
126                    "title": "Code (`" + record.frame.filename.split("/")[-1] + ":" + str(record.frame.lineno) + "`):",
127                    "value": "```" + infile.readlines()[record.frame.lineno - 1].strip() + "```",
128                    "short": False
129                })
130        except (IndexError, AttributeError):
131            # the file is not readable, or the line number is out of bounds
132            pass
133
134        return {
135            "text": ":bell: 4CAT %s logged on `%s`:" % (record.levelname.lower(), platform.uname().node),
136            "mrkdwn_in": ["text"],
137            "attachments": [{
138                "color": color,
139                "text": record.message,
140                "fields": fields
141            }]
142        }
143
144
145class Logger:
146    """
147    Logger
148
149    Sets up a rotating logger that writes to a log file
150    """
151    logger = None
152    log_path = None
153    print_logs = True
154    db = None
155    previous_report = 0
156    levels = {
157        "DEBUG": logging.DEBUG,
158        "INFO": logging.INFO,
159        "WARNING": logging.WARNING,
160        "ERROR": logging.ERROR,
161        "CRITICAL": logging.CRITICAL,
162        "FATAL": logging.FATAL
163    }
164    alert_level = "FATAL"
165
166    def __init__(self, logger_name='4cat-backend', output=False, filename='4cat.log', log_level="INFO"):
167        """
168        Set up log handler
169
170        :param bool output:  Whether to print logs to output
171        """
172        if self.logger:
173            return
174        log_level = self.levels.get(log_level, logging.INFO)
175
176        self.print_logs = output
177        log_folder = config.get('PATH_ROOT').joinpath(config.get('PATH_LOGS'))
178        if not log_folder.exists():
179            log_folder.mkdir(parents=True)
180
181        self.log_path = log_folder.joinpath(filename)
182        self.previous_report = time.time()
183
184        self.logger = logging.getLogger(logger_name)
185        self.logger.setLevel(log_level)
186
187        # this handler manages the text log files
188        if not self.logger.handlers:
189            handler = RotatingFileHandler(self.log_path, maxBytes=(50 * 1024 * 1024), backupCount=1)
190            handler.setLevel(log_level)
191            handler.setFormatter(logging.Formatter("%(asctime)-15s | %(levelname)s at %(location)s: %(message)s",
192                                                   "%d-%m-%Y %H:%M:%S"))
193            self.logger.addHandler(handler)
194
195            # the slack webhook has its own handler, and is only active if the
196            # webhook URL is set
197            try:
198                if config.get("logging.slack.webhook"):
199                    slack_handler = SlackLogHandler(config.get("logging.slack.webhook"))
200                    slack_handler.setLevel(self.levels.get(config.get("logging.slack.level"), self.alert_level))
201                    self.logger.addHandler(slack_handler)
202            except Exception:
203                # we *may* need the logger before the database is in working order
204                if config.db is not None:
205                    config.db.rollback()
206
207    def log(self, message, level=logging.INFO, frame=None):
208        """
209        Log message
210
211        :param message:  Message to log
212        :param level:  Severity level, should be a logger.* constant
213        :param frame:  Traceback frame. If no frame is given, it is
214        extrapolated
215        """
216        # logging can include the full stack trace in the log, but that's a
217        # bit excessive - instead, only include the location the log was called
218        if not frame:
219            frame = traceback.extract_stack()[-3]
220        location = frame.filename.split("/")[-1] + ":" + str(frame.lineno)
221        self.logger.log(level, message, extra={"location": location, "frame": frame})
222
223    def debug(self, message, frame=None):
224        """
225        Log DEBUG level message
226
227        :param message: Message to log
228        :param frame:  Traceback frame relating to the error
229        """
230        self.log(message, logging.DEBUG, frame)
231
232    def info(self, message, frame=None):
233        """
234        Log INFO level message
235
236        :param message: Message to log
237        :param frame:  Traceback frame relating to the error
238        """
239        self.log(message, logging.INFO)
240
241    def warning(self, message, frame=None):
242        """
243        Log WARNING level message
244
245        :param message: Message to log
246        :param frame:  Traceback frame relating to the error
247        """
248        self.log(message, logging.WARN, frame)
249
250    def error(self, message, frame=None):
251        """
252        Log ERROR level message
253
254        :param message: Message to log
255        :param frame:  Traceback frame relating to the error
256        """
257        self.log(message, logging.ERROR, frame)
258
259    def critical(self, message, frame=None):
260        """
261        Log CRITICAL level message
262
263        :param message: Message to log
264        :param frame:  Traceback frame relating to the error
265        """
266        self.log(message, logging.CRITICAL, frame)
267
268    def fatal(self, message, frame=None):
269        """
270        Log FATAL level message
271
272        :param message: Message to log
273        :param frame:  Traceback frame relating to the error
274        """
275        self.log(message, logging.FATAL, frame)