Pickling error when enqueing is enabled

[PythonTryHard]

Python version: 3.10.8, manually compiled with --enable-optimizations --with-lto using GCC 11.3.0 against glibc 2.25. Loguru version: 0.6.0, installed from PyPI OS information: KDE Neon 5.27 (based on Ubuntu 22.04.1 LTS), fully up-to-date Development environment: Python 3.10.8 under poetry

Minimal reproduction

1. Dependency:

   hikari-lightbulb==2.3.2

2. Minimal reproduction (2 files)

log.py

import sys
import logging

from loguru import logger

logger.remove()
logger.add(sys.stderr, level="INFO", enqueue=True)

# Copy-pasted as-is from 
class InterceptHandler(logging.Handler):
    def emit(self, record):
        # Get corresponding Loguru level if it exists
        try:
            level = logger.level(record.levelname).name
        except ValueError:
            level = record.levelno
        # Find caller from where originated the logged message
        frame, depth = logging.currentframe(), 2
        while frame.f_code.co_filename == logging.__file__:
            frame = frame.f_back
            depth += 1

        logger.opt(depth=depth, exception=record.exc_info).log(level, record.getMessage())

main.py

import logging

import lightbulb

from log import InterceptHandler

logging.basicConfig(handlers=[InterceptHandler()], level="INFO")
bot = lightbulb.BotApp(token="Garbage token to cause 401", logs="INFO")

@logger.catch
def main():
    bot.run()

main()

Instruction to run

$ python main.py

4. Expectation & Reality
   • Expected: main.py throws exception, loguru writes exception to stderr
   • Reality: main.py throws exception, loguru throws exceptions (redacted the record for brevity and potentially sensitive information):

     
     --- Logging error in Loguru Handler #1 ---
     Record was: ...
     Traceback (most recent call last):
     File "/home/f4ll3n53r4ph/.env/opereta-ds2j3CUa-py3.10/lib/python3.10/site-packages/loguru/_logger.py", line 1226, in catch_wrapper
     return function(*args, **kwargs)
     File "/home/f4ll3n53r4ph/Development/Bot/minimal_repro.py", line 32, in main
     bot.run()
     File "/home/f4ll3n53r4ph/.env/opereta-ds2j3CUa-py3.10/lib/python3.10/site-packages/hikari/impl/bot.py", line 819, in run
     loop.run_until_complete(
     File "/opt/python-3.10.8/lib/python3.10/asyncio/base_events.py", line 649, in run_until_complete
     return future.result()
     File "/home/f4ll3n53r4ph/.env/opereta-ds2j3CUa-py3.10/lib/python3.10/site-packages/hikari/impl/bot.py", line 935, in start
     requirements = await self._rest.fetch_gateway_bot_info()
     File "/home/f4ll3n53r4ph/.env/opereta-ds2j3CUa-py3.10/lib/python3.10/site-packages/hikari/impl/rest.py", line 2004, in fetch_gateway_bot_info
     response = await self._request(route)
     File "/home/f4ll3n53r4ph/.env/opereta-ds2j3CUa-py3.10/lib/python3.10/site-packages/hikari/impl/rest.py", line 734, in _request
     await aio.first_completed(request_task, self._close_event.wait())
     File "/home/f4ll3n53r4ph/.env/opereta-ds2j3CUa-py3.10/lib/python3.10/site-packages/hikari/internal/aio.py", line 138, in first_completed
     await next(iterator)
     File "/opt/python-3.10.8/lib/python3.10/asyncio/tasks.py", line 571, in _wait_for_one
     return f.result()  # May raise f.exception().
     File "/home/f4ll3n53r4ph/.env/opereta-ds2j3CUa-py3.10/lib/python3.10/site-packages/hikari/impl/rest.py", line 882, in _perform_request
     raise await net.generate_error_response(response)
     hikari.errors.UnauthorizedError: Unauthorized 401: '401: Unauthorized' for https://discord.com/api/v10/gateway/bot

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "/home/f4ll3n53r4ph/.env/opereta-ds2j3CUa-py3.10/lib/python3.10/site-packages/loguru/_handler.py", line 175, in emit self._queue.put(str_record) File "/opt/python-3.10.8/lib/python3.10/multiprocessing/queues.py", line 371, in put obj = _ForkingPickler.dumps(obj) File "/opt/python-3.10.8/lib/python3.10/multiprocessing/reduction.py", line 51, in dumps cls(buf, protocol).dump(obj) File "/home/f4ll3n53r4ph/.env/opereta-ds2j3CUa-py3.10/lib/python3.10/site-packages/loguru/_recattrs.py", line 73, in reduce pickle.dumps(self.value) TypeError: can't pickle multidict._multidict.CIMultiDictProxy objects --- End of logging error ---

**Additional information directly related to reproduction**
- This can be reliably triggered by setting `enqueue=True`. I did it for the heck of it.
- Application doesn't use `multiprocessing` at any point.
- Any normal sink will do, i.e. `stderr`, `log.log`, etc.; level should be low enough to get `loguru` to handle the exception. From experimentation, lower than `CRITICAL` will do.

**Additional information about the dependencies**
- `hikari-lightbulb`'s dependency `hikari` has an additional logging level `TRACE_HIKARI` at `5`.

[Delgan]

Hi. Thanks for the report. I think it's a duplicate of #342. I will fix it in the next few days.

[PythonTryHard]

Ah, I did see the issue you linked while searching. I saw that it was about ctypes so I ignored it from a glance. I'm commuting so I'll try the workarounds later. Thank you for the pointer!

[PythonTryHard]

@Delgan Life got in the way, my apologies for not responding.

I had a glance at #342 and while the cause is similar (something went wrong in the pickling because my code is pickling a ), I couldn't wrap my head fully around the workaround proposed there. But, I saw the idea of manually filtering out the exceptions and deal with it manually. With that, I stuck a debugger to my reproduction code to see the flow of the record that's causing the exception chain: And it missed the InterceptHandler completely. So now I'm clueless and how to proceed.

[Delgan]

You can do something like that, the idea is just to remove the Exception which can't be pickled when enqueue=True:

import hikari.errors

def fixup_pickle_error(record):
    if record["exception"] is not None and isinstance(record["exception"].value, hikari.errors.UnauthorizedError):
        record["exception"] = record["exception"]._replace(value=None)
    return True

logger.remove()
logger.add(sys.stderr, level="INFO", enqueue=True, filter=fixup_pickle_error)

[Delgan]

This should be fixed by #905 and will be available in the next release. I'm closing this ticket consequently.