Merge pull request #2752 from vkarak/feat/httpjson-custom-formatter

[feat] Allow custom JSON formatting for log records in the `httpjson` handler

docs/config_reference.rst

@@ -1362,6 +1362,43 @@ An example configuration of this handler for performance logging is shown here:
 
 This handler transmits the whole log record, meaning that all the information will be available and indexable at the remote end.
 
+.. py:attribute:: logging.handlers..httpjson..debug
+
+.. py:attribute:: logging.handlers_perflog..httpjson..debug
+
+   :required: No
+   :default: ``false``
+
+   If set, the ``httpjson`` handler will not attempt to send the data to the server, but it will instead dump the JSON record in the current directory.
+   The filename has the following form: ``httpjson_record_<timestamp>.json``.
+
+   .. versionadded:: 4.1
+
+
+.. py:attribute:: logging.handlers..httpjson..json_formatter
+
+.. py:attribute:: logging.handlers_perflog..httpjson..json_formatter
+
+   A callable for converting the log record into JSON.
+
+   The formatter's signature is the following:
+
+   .. py:function:: json_formatter(record: object, extras: Dict[str, str], ignore_keys: Set[str]) -> str
+
+      :arg record: The prepared log record.
+         The log record is a simple Python object with all the attributes listed in :attr:`~config.logging.handlers.format`, as well as all the default Python `log record <https://docs.python.org/3.8/library/logging.html#logrecord-attributes>`__ attributes.
+         In addition to those, there is also the special :attr:`__rfm_check__` attribute that contains a reference to the actual test for which the performance is being logged.
+      :arg extras: Any extra attributes specified in :attr:`~config.logging.handlers..httpjson..extras`.
+      :arg ignore_keys: The set of keys specified in :attr:`~config.logging.handlers..httpjson..ignore_keys`.
+         ReFrame always adds the default Python log record attributes in this set.
+      :returns: A string representation of the JSON record to be sent to the server or :obj:`None` if the record should not be sent to the server.
+
+   .. note::
+      This configuration parameter can only be used in a Python configuration file.
+
+   .. versionadded:: 4.1
+
+
 
 Execution Mode Configuration
 ----------------------------

reframe/core/logging.py

@@ -21,6 +21,7 @@
 import reframe.utility.osext as osext
 from reframe.core.exceptions import ConfigError, LoggingError
 from reframe.core.warnings import suppress_deprecations
+from reframe.utility import is_trivially_callable
 from reframe.utility.profile import TimeProfiler
 
 
@@ -469,6 +470,11 @@ def _create_graylog_handler(site_config, config_prefix):
 
 def _create_httpjson_handler(site_config, config_prefix):
     url = site_config.get(f'{config_prefix}/url')
+    extras = site_config.get(f'{config_prefix}/extras')
+    ignore_keys = site_config.get(f'{config_prefix}/ignore_keys')
+    json_formatter = site_config.get(f'{config_prefix}/json_formatter')
+    debug = site_config.get(f'{config_prefix}/debug')
+
     parsed_url = urllib.parse.urlparse(url)
     if parsed_url.scheme not in {'http', 'https'}:
         raise ConfigError(
@@ -479,27 +485,69 @@ def _create_httpjson_handler(site_config, config_prefix):
         raise ConfigError('http json handler: invalid hostname')
 
     try:
-        if not parsed_url.port:
-            raise ConfigError('http json handler: no port given')
+        port = parsed_url.port
+        if port is None:
+            if parsed_url.scheme == 'http':
+                port = 80
+            elif parsed_url.scheme == 'https':
+                port = 443
+            else:
+                # This should not happen
+                assert 0, 'invalid url scheme found'
     except ValueError as e:
-        raise ConfigError('http json handler: invalid port') from e
+        raise ConfigError('httpjson handler: invalid port') from e
 
     # Check if the remote server is up and accepts connections; if not we will
     # skip the handler
     try:
-        with socket.create_connection((parsed_url.hostname, parsed_url.port),
-                                      timeout=1):
+        with socket.create_connection((parsed_url.hostname, port), timeout=1):
             pass
     except OSError as e:
         getlogger().warning(
             f'httpjson: could not connect to server '
-            f'{parsed_url.hostname}:{parsed_url.port}: {e}'
+            f'{parsed_url.hostname}:{port}: {e}'
         )
-        return None
+        if not debug:
+            return None
+
+    if debug:
+        getlogger().warning('httpjson: running in debug mode; '
+                            'no data will be sent to the server')
+
+    return HTTPJSONHandler(url, extras, ignore_keys, json_formatter, debug)
 
-    extras = site_config.get(f'{config_prefix}/extras')
-    ignore_keys = site_config.get(f'{config_prefix}/ignore_keys')
-    return HTTPJSONHandler(url, extras, ignore_keys)
+
+def _record_to_json(record, extras, ignore_keys):
+    def _can_send(key):
+        return not key.startswith('_') and not key in ignore_keys
+
+    def _sanitize(s):
+        return re.sub(r'\W', '_', s)
+
+    json_record = {}
+    for k, v in record.__dict__.items():
+        if not _can_send(k):
+            continue
+
+        if k == 'check_perfvalues':
+            # Flatten the performance values
+            for var, info in v.items():
+                val, ref, lower, upper, unit = info
+                name = _sanitize(var.split(':')[-1])
+                json_record[f'check_perf_{name}_value'] = val
+                json_record[f'check_perf_{name}_ref'] = ref
+                json_record[f'check_perf_{name}_lower_thres'] = lower
+                json_record[f'check_perf_{name}_upper_thres'] = upper
+                json_record[f'check_perf_{name}_unit'] = unit
+        else:
+            json_record[k] = v
+
+    if extras:
+        json_record.update({
+            k: v for k, v in extras.items() if _can_send(k)
+        })
+
+    return _xfmt(json_record)
 
 
 class HTTPJSONHandler(logging.Handler):
@@ -514,35 +562,50 @@ class HTTPJSONHandler(logging.Handler):
         'stack_info', 'thread', 'threadName', 'exc_text'
     }
 
-    def __init__(self, url, extras=None, ignore_keys=None):
+    def __init__(self, url, extras=None, ignore_keys=None,
+                 json_formatter=None, debug=False):
         super().__init__()
         self._url = url
         self._extras = extras
-        self._ignore_keys = ignore_keys
+        self._ignore_keys = self.LOG_ATTRS
+        if ignore_keys:
+            self._ignore_keys |= set(ignore_keys)
 
-    def _record_to_json(self, record):
-        def _can_send(key):
-            return not (
-                key.startswith('_') or key in HTTPJSONHandler.LOG_ATTRS or
-                (self._ignore_keys and key in self._ignore_keys)
-            )
+        self._json_format = json_formatter or _record_to_json
+        if not callable(self._json_format):
+            raise ConfigError("httpjson: 'json_formatter' is not a callable")
 
-        json_record = {
-            k: v for k, v in record.__dict__.items() if _can_send(k)
-        }
-        if self._extras:
-            json_record.update({
-                k: v for k, v in self._extras.items() if _can_send(k)
-            })
+        if not is_trivially_callable(self._json_format, non_def_args=3):
+            raise ConfigError(
+                "httpjson: 'json_formatter' has not the right signature: "
+                "it must be 'json_formatter(record, extras, ignore_keys)'"
+            )
 
-        return _xfmt(json_record).encode('utf-8')
+        self._debug = debug
 
     def emit(self, record):
-        json_record = self._record_to_json(record)
+        # Convert tags to a list to make them JSON friendly
+        record.check_tags = list(record.check_tags)
+        json_record = self._json_format(record,
+                                        self._extras,
+                                        self._ignore_keys)
+        if json_record is None:
+            return
+
+        if self._debug:
+            import time
+            ts = int(time.time() * 1_000)
+            dump_file = f'httpjson_record_{ts}.json'
+            with open(dump_file, 'w') as fp:
+                fp.write(json_record)
+
+            return
+
         try:
             requests.post(
                 self._url, data=json_record,
-                headers={'Content-type': 'application/json'}
+                headers={'Content-type': 'application/json',
+                         'Accept-Charset': 'UTF-8'}
             )
         except requests.exceptions.RequestException as e:
             raise LoggingError('logging failed') from e
@@ -899,3 +962,27 @@ def _fn(*args, **kwargs):
         return fn(*args, **kwargs)
 
     return _fn
+
+
+# The following is meant to be used only by the unit tests
+
+class logging_sandbox:
+    '''Define a region that you can safely change the logging config.
+
+    At entering the region, this context manager saves the logging
+    configuration and restores it at exit.
+
+    :meta private:
+    '''
+
+    def __enter__(self):
+        self._logger = _logger
+        self._perf_logger = _perf_logger
+        self._context_logger = _context_logger
+
+    def __exit__(self, exc_type, exc_value, traceback):
+        global _logger, _perf_logger, _context_logger
+
+        _logger = self._logger
+        _perf_logger = self._perf_logger
+        _context_logger = self._context_logger

reframe/schemas/config.json

@@ -163,7 +163,9 @@
                         "ignore_keys": {
                             "type": "array",
                             "items": {"type": "string"}
-                        }
+                        },
+                        "json_formatter": {},
+                        "debug": {"type": "boolean"}
                     },
                     "required": ["url"]
                 }
@@ -565,6 +567,8 @@
         "logging/handlers*/graylog_extras": {},
         "logging/handlers*/httpjson_extras": {},
         "logging/handlers*/httpjson_ignore_keys": [],
+        "logging/handlers*/httpjson_json_formatter": null,
+        "logging/handlers*/httpjson_debug": false,
         "logging/handlers*/stream_name": "stdout",
         "logging/handlers*/syslog_socktype": "udp",
         "logging/handlers*/syslog_facility": "user",