PUBHandler prepends loglevel, module and line to log message

[Blindfreddy]

I have successfully implemented a PUBHandler, however, for all loglevels except info the subscriber seems to receive a message bytestring which has prepended the loglevel as a string, the originating module name and the line in the module.

Examples:
INFO - seems fine
2019-01-14 23:38:49,764 INFO TS_T1: starting cycle...

DEBUG - loglevel, module name and line prepended to the log message
2019-01-14 23:38:49,765 DEBUG **DEBUG sensor.py:191** - TS_T1: take_reading...

ERROR- same as debug plus appends "- None"
2019-01-14 23:42:48,936 ERROR **ERROR foundation.py:489** - TS_T1: starting cycle...done. **- None**
CRITICAL - same as debug
2019-01-14 23:38:49,770 CRITICAL **CRITICAL foundation.py:489** - TS_T1: starting cycle...done.

It can be filtered with message.split(b" - ")[-1:][0].decode('utf-8') but that seems awkward. Is there a way to suppress this at the source, or am I perhaps not understanding the way PUBHandler emits logrecords fully ?

Many thanks.

[Blindfreddy]

Further to my above post, I either don't understand how to use PUBHandler, or it is not really useful in its current form. I'd suggest to change it so that it receives a logrecord object via recv_pyobj() which can then be handled by passing it to the existing logger(s):

record = recv_pyobj()
logger.handle(record)

[guidog]

Wrong project?

[guidog]

Issue can be removed, I think.

[minrk]

PUBHandler was written a very long time ago, and should probably be updated quite a bit. I don't think I properly understood what this should do. If you'd like to take a stab at updating it, that would be cool. I wouldn't use pyobj methods (those should generally not be used in production), but I would structure the messages differently to preserve the logrecord format.

[Blindfreddy]

Ok, that explains why it doesn't really work nowadays. Just to be clear, all I wanted to use for was to handle logging to a single stream in a multiprocess python program. Since I already use zmq for inter-process communication, it wasn't a big leap to add PUBHandler. In the end I managed to achieve the same thing by way of a Queue object as described in the python mp documentation.

Apart from all the surrounding 'stuff', there are really only two lines of code in the mp logger class:

    def logger_thread_run(self, logger_q):
        msg = ("{}: logger_thread started, threads: {}."
               .format(self.name, enumerate()))
        self.logger.debug(msg)
        try:
            while True:
                try:
                    **record = logger_q.get()**                    
                    **self.logger.handle(record)**
                except Exception:
                    import sys, traceback
                    print('{}: unexpected exception.'.format(self.name), file=sys.stderr)
                    traceback.print_exc(file=sys.stderr)
        finally:
            print(msg + " has ended.") 

logger_q is the shared Queue, when a record arrives it just passes it to the local logger.
In my opinion, the PUBHandler should do exactly the same - listen for a logrecord to arrive and then pass it to the local logger(s).

Assuming that's what is desired (?) then I could have a stab at updating it accordingly.

[minrk]

Yeah, that sounds great. The one thing I would do is make sure to serialize the fields as e.g. JSON not the record object as pickle, since pickle raises unnecessary security issues on the receiving end.

[klovanone]

Hi, I recently needed similar functionality (passing logrecords over zmq and serializing/deserializing) and ended up writing my own version for a project that I am working on.

It is here if it is of any use to anyone:
https://github.com/klover1/pyzmq/tree/logrecordpubhandler

I have been using it for quite a while with no problems but please let me know if there are any issues with it.

Thanks!