def format(self, record): """Format message with structured tags and any exception/trailer""" import talisker.sentry # lazy to break import cycle try: record.message = self.clean_message(record.getMessage()) # we never want sentry to capture DEBUG logs in its breadcrumbs, as # they may be sensitive if record.levelno > logging.DEBUG: talisker.sentry.record_log_breadcrumb(record) if len(record.message) > self.MAX_MSG_SIZE: record.message = ( record.message[:self.MAX_MSG_SIZE] + self.TRUNCATED ) # this is verbatim from the parent class in stdlib if self.usesTime(): record.asctime = self.formatTime(record, self.datefmt) s = self._fmt % record.__dict__ # add our structured tags *before* exception info is added structured = getattr(record, 'extra', {}) if record.exc_info and 'errno' not in structured: structured.update(get_errno_fields(record.exc_info[1])) if structured: s += " " + self.logfmt(structured) # add talisker trailers trailer = getattr(record, '_trailer', None) if trailer is not None: s += '\n' + str(trailer) # this is verbatim from the parent class in stdlib if record.exc_info: # Cache the traceback text to avoid converting it multiple # times (it's constant anyway) if not record.exc_text: record.exc_text = self.formatException(record.exc_info) if record.exc_text: if s[-1:] != "\n": s = s + "\n" try: s = s + record.exc_text except UnicodeError: # pragma: no cover # Sometimes filenames have non-ASCII chars, which can lead # to errors when s is Unicode and record.exc_text is str # See issue 8924. # We also use replace for when there are multiple # encodings, e.g. UTF-8 for the filesystem and latin-1 # for a script. See issue 13232. s = s + record.exc_text.decode( sys.getfilesystemencoding(), 'replace') return s except Exception: # ensure unexpected error doesn't break logging return super().format(record)
def test_get_errno_fields_permissions(): exc = None try: open('/blah', 'w') except Exception as e: exc = e assert util.get_errno_fields(exc) == { 'errno': 'EACCES', 'strerror': 'Permission denied', 'filename': '/blah', }
def test_get_errno_fields_dns(): exc = None try: import socket s = socket.socket() s.connect(('some-host-name-that-will-not-resolve.com', 54321)) except Exception as e: exc = e assert util.get_errno_fields(exc) == { 'errno': 'EAI_NONAME', 'strerror': 'Name or service not known', }
def test_get_errno_fields_connection(): exc = None try: import socket s = socket.socket() s.connect(('localhost', 54321)) except Exception as e: exc = e assert util.get_errno_fields(exc) == { 'errno': 'ECONNREFUSED', 'strerror': 'Connection refused', }
def record_request(request, response=None, exc=None): metadata = collect_metadata(request, response) if response: Context.track('http', metadata['duration_ms']) if exc: metadata.update(get_errno_fields(exc)) talisker.sentry.record_breadcrumb( type='http', category='requests', data=metadata, ) labels = { 'host': metadata['host'], 'view': metadata.get('view', 'unknown'), } ctx = Context.current metric_api_name = getattr(ctx, 'metric_api_name', None) metric_host_name = getattr(ctx, 'metric_host_name', None) if metric_api_name is not None: labels['view'] = metric_api_name if metric_host_name is not None: labels['host'] = metric_host_name labels['host'] = labels['host'].replace('.', '-') RequestsMetric.count.inc(**labels) if response is None: # likely connection errors logger.exception('http request failure', extra=metadata) labels['type'] = 'connection' labels['status'] = metadata.get('errno', 'unknown') RequestsMetric.errors.inc(**labels) else: logger.info('http request', extra=metadata) labels['status'] = metadata['status_code'] RequestsMetric.latency.observe(metadata['duration_ms'], **labels) if metadata['status_code'] >= 500: labels['type'] = 'http' RequestsMetric.errors.inc(**labels)
def test_get_errno_fields_dns(): exc = None try: import socket import platform s = socket.socket() s.connect(('some-host-name-that-will-not-resolve.com', 54321)) except Exception as e: exc = e processed_exc = util.get_errno_fields(exc) if platform.system() == 'Darwin': assert processed_exc == { 'errno': 'ENOEXEC', 'strerror': 'nodename nor servname provided, or not known' } else: assert processed_exc == { 'errno': 'EAI_NONAME', 'strerror': 'Name or service not known' }