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