zeromq / pyzmq

PyZMQ: Python bindings for zeromq
http://zguide.zeromq.org/py:all
BSD 3-Clause "New" or "Revised" License
3.72k stars 636 forks source link

zmq logger does not support custom Message types #1834

Closed umesh-timalsina closed 1 year ago

umesh-timalsina commented 1 year ago

What pyzmq version?

25.0.0

What libzmq version?

4.3.4

Python version (and how it was installed)

Python 3.10.8 | packaged by conda-forge | (main, Nov 22 2022, 08:26:04) [GCC 10.4.0] on linux

OS

Ubuntu 22.04

What happened?

Apparently, the emit function in pyzmq's PubHandler doesn't take into account the possibility of typecasting when applying the split function for a LogRecord's msg attribute in python. This causes a lot of issues when the log handler is used in conjunction with the logger already in existence. A possible resolution might be to use getMessage instead which does the type casting.

https://github.com/zeromq/pyzmq/blob/9b767422dd8b32c29496d5fe1858b4e325fb42d2/zmq/log/handlers.py#L132-L157

Code to reproduce bug

import random
import time

import zmq.log.handlers
import logging

class DummyClass:
    def __init__(self, prop1: int) -> None:
        self.prop1 = prop1

    def __str__(self):
        return f"DummyClass(prop1={self.prop1})"

class DummyLogServer:
    def __init__(self, port=10000):
        self.port = port
        self.context = zmq.Context()
        self.socket = self.context.socket(zmq.PUB)
        self.socket.bind("ws://*:%s" % self.port)

        self.logger = logging.getLogger("DummyLogServer")
        self.logger.setLevel(logging.DEBUG)
        formatter = logging.Formatter(
            "%(asctime)s - %(name)s - %(levelname)s - %(message)s"
        )

        self.pub_handler = zmq.log.handlers.PUBHandler(self.socket)
        self.pub_handler.setFormatter(formatter)
        self.console_handler = logging.StreamHandler()

        self.pub_handler.root_topic = "mock_logs"
        self.logger.addHandler(self.pub_handler)
        self.logger.addHandler(self.console_handler)

    def run(self):
        while True:
            callable = random.choice(
                [
                    self.logger.debug,
                    self.logger.info,
                    self.logger.warning,
                    self.logger.error,
                    self.logger.critical,
                ]
            )
            callable(
              DummyClass(random.randint(0, 2000))
            )
            time.sleep(random.random())

if __name__ == "__main__":
    server = DummyLogServer()
    server.run()

Traceback, if applicable

file "/path/to/python_lib/python3.10/site-packages/zmq/log/handlers.py", line 136, in emit
    topic, record.msg = record.msg.split(TOPIC_DELIM, 1)
AttributeError: 'DummyClass' object has no attribute 'split'

More info

No response

minrk commented 1 year ago

LogRecord.msg is defined to be:

msg (str) – The event description message, which can be a %-format string with placeholders for variable data.

So I think passing an int here would be a bug. But it does say it should support custom Message types, as long as they have a __str__ method that returns an appropriate format string, so we should do the same and getMessage seems like the right call, thanks!

davetapley commented 1 year ago

Did I just happen to also run in to this the same week, or is it a regression?

minrk commented 1 year ago

I don't think this file has been touched in a pretty long time, so coincidence seems likely.