TypeError: Object of type ... is not JSON serializable

[matthieumarrast]

When mflog is not able to json serialize a provided log message (for example if we pass it an object), we face a "fat" stack trace in our plugin log:

919353 --- Logging error ---
919354 Traceback (most recent call last):
...
919362 During handling of the above exception, another exception occurred:
919363
919364 Traceback (most recent call last):
919365   File "/opt/metwork-mfext-2.1/opt/python3_core/lib/python3.10/logging/handlers.py", line 971, in emit
919366     msg = self.format(record)
919367   File "/opt/metwork-mfext-2.1/opt/python3_core/lib/python3.10/logging/__init__.py", line 943, in format
919368     return fmt.format(record)
919369   File "/opt/metwork-mfext-2.1/opt/python3/lib/python3.10/site-packages/mflog/syslog.py", line 15, in format
919370     return json.dumps(record.msg)
919371   File "/opt/metwork-mfext-2.1/opt/python3_core/lib/python3.10/json/__init__.py", line 231, in dumps
919372     return _default_encoder.encode(obj)
919373   File "/opt/metwork-mfext-2.1/opt/python3_core/lib/python3.10/json/encoder.py", line 199, in encode
919374     chunks = self.iterencode(o, _one_shot=True)
919375   File "/opt/metwork-mfext-2.1/opt/python3_core/lib/python3.10/json/encoder.py", line 257, in iterencode
919376     return _iterencode(o, 0)
919377   File "/opt/metwork-mfext-2.1/opt/python3_core/lib/python3.10/json/encoder.py", line 179, in default
919378     raise TypeError(f'Object of type {o.__class__.__name__} '
919379 TypeError: Object of type UndefinedTable is not JSON serializable
919380 Call stack:
919381   File "/home/mfdata/var/plugins/my_plugin/image_importer.py", line 304, in <module>
919382     x.run()
919383   File "/opt/metwork-mfext-2.1/opt/python3/lib/python3.10/site-packages/acquisition/step.py", line 544, in run
919384     self.__run_in_daemon_mode(
919385   File "/opt/metwork-mfext-2.1/opt/python3/lib/python3.10/site-packages/acquisition/step.py", line 329, in __run_in_daemon_mode
919386     self._process(xaf)
919387   File "/opt/metwork-mfext-2.1/opt/python3/lib/python3.10/site-packages/acquisition/step.py", line 153, in _process
919388     process_status = self._exception_safe_call(
919389   File "/opt/metwork-mfext-2.1/opt/python3/lib/python3.10/site-packages/acquisition/step.py", line 129, in _exception_safe_call
919390     return func(*args, **kwargs)
919391   File "/home/mfdata/var/plugins/my_plugin/image_importer.py", line 295, in process
919392     self.save_image_ref(self.layer_id, self.new_filename)
919393   File "/home/mfdata/var/plugins/my_plugin/image_importer.py", line 229, in save_image_ref
919394     self.error(error)
919395   File "/opt/metwork-mfext-2.1/opt/python3/lib/python3.10/site-packages/acquisition/base.py", line 164, in error
919396     logger.error(msg, *args, **kwargs)
919397   File "/opt/metwork-mfext-2.1/opt/python3/lib/python3.10/site-packages/structlog/stdlib.py", line 200, in error
919398     return self._proxy_to_logger("error", event, *args, **kw)
919399   File "/opt/metwork-mfext-2.1/opt/python3/lib/python3.10/site-packages/structlog/stdlib.py", line 247, in _proxy_to_logger
919400     return super()._proxy_to_logger(method_name, event=event, **event_kw)
919401   File "/opt/metwork-mfext-2.1/opt/python3/lib/python3.10/site-packages/structlog/_base.py", line 206, in _proxy_to_logger
919402     return getattr(self._logger, method_name)(*args, **kw)
919403   File "/opt/metwork-mfext-2.1/opt/python3/lib/python3.10/site-packages/mflog/__init__.py", line 216, in _msg_stderr
919404     self._msg(self._stderr_print_logger, **event_dict)
919405   File "/opt/metwork-mfext-2.1/opt/python3/lib/python3.10/site-packages/mflog/__init__.py", line 139, in _msg
919406     self._syslog(**event_dict)
919407   File "/opt/metwork-mfext-2.1/opt/python3/lib/python3.10/site-packages/mflog/__init__.py", line 233, in _syslog
919408     self._syslog_logger.msg(event_dict)
919409   File "/opt/metwork-mfext-2.1/opt/python3/lib/python3.10/site-packages/mflog/syslog.py", line 39, in msg
919410     self.__syslog_handler.emit(record)
919411 Message: {'name': 'mfdata......main', 'event': UndefinedTable('relation "..." does not exist\nLINE 2:                 INSERT INTO ....(....), 'level': 'error', 'pid': 2622228, 'plugin': '....', 'timestamp': '2023-02-01T11:21:24.256635Z'}

This stack trace is produced with below code:

except (Exception) as error:
        LOGGER.error(error)

[matthieumarrast]

I think in syslog.py we must catch the TypeError:

class SyslogLoggerJSONFormatter(object):

    def format(self, record):
        try:
            return json.dumps(record.msg)
        except TypeError as te:
            # WHAT TO RETURN HERE

and also the "fat" stack trace is not logged anymore but what to return in order to have an mflog sent to mfadmin anyway... !?

[matthieumarrast]

note: we cannot return anything otherwise we'll face an error in vector.log related to lua function fix_mflog_json:

Feb 01 14:21:54.275 ERROR transform{component_kind="transform" component_name=fix_mflog_json component_type=lua}: vector::internal_events::lua: Error in lua script; discarding event. error=RuntimeErrorHooksProcess { source: RuntimeError("[string \"?\"]:5: attempt to perform arithmetic on a nil value (local \'k\')\nstack traceback:\n\t[C]: in metamethod \'__sub\'\n\t[string \"?\"]:5: in function <[string \"?\"]:1>") } internal_log_rate_secs=30

function definition:

[transforms.fix_mflog_json]
type = "lua" 
inputs = ["syslog_mflog"]
version = "2" 
hooks.process = '''
  function (event, emit)
    local i, j = event.log.message:find("{")
    local k, l = event.log.message:reverse():find("}")
    local length = event.log.message:len()
    event.log.message = event.log.message:sub(i, length - k + 1)
    emit(event)
  end
'''