loguru icon indicating copy to clipboard operation
loguru copied to clipboard

call stack is not deep enough (Cython)

Open djsakisd opened this issue 5 years ago • 14 comments

Hi @Delgan

When using loguru 0.2.5 inside python script it works as expected, but when i compile this file to an executable using Cython i get this error and program terminates : call stack is not deep enough

More info of the error :

Traceback (most recent call last):
  File "test_layer.py", line 66, in init test_layer
    logger.warning('just test')
  File "/usr/local/lib/python3.5/dist-packages/loguru/_logger.py", line 1406, in log_function
    frame = get_frame(_self._depth + 1)
ValueError: call stack is not deep enough

Do you have any idea why ?

I tried increasing the execution depth limit inside the script that i import loguru by using sys.setrecursionlimit(3000) but still issue remains..

OS: raspbian stretch lite Cython-0.29.7

djsakisd avatar Apr 16 '19 21:04 djsakisd

Hi @djsakisd.

This is not related to the recursion limit, but to sys._getframe() which tries to access frame of the call site to extract logging information. Typically, this error indicates that loguru tried to access a frame which does not exist.

You may play with the depth option to see if some negative values fixes the problem:

logger.opt(depth=-1).info("Working?")

On my side, I will try to reproduce the error, I actually never tested Cython, so I'm not too surprised there is some incompatibilities dealing with stack frames.

Delgan avatar Apr 16 '19 21:04 Delgan

Hi @Delgan it works that way !

Is there any way to make this permanent in the script for all the logger.info or i need to set this each time ?

Because i tried this : logger.opt(depth=-1) logger.error("test")

Gives error, but : logger.opt(depth=-1).info("Working?") works fine !

Thanks again for helping me...

djsakisd avatar Apr 17 '19 09:04 djsakisd

@djsakisd As .opt() actually returns a logger object, you can add logger = logger.opt(depth=-1) at the start of your file, and then use this new logger without needing to call opt() every time.

I will investigate this issue, hopefully you will not even need this workaround in the next version. 👍

Delgan avatar Apr 17 '19 19:04 Delgan

After playing a little with Cython, I realize this is not as easy to fix as I would thought.

Cython does not insert any kind of strack frame in its compiled code. As Loguru (and logging more generally) heavily relies on frames objects, this produces weird and inherently wrong results.

While compiling with --embed a module which uses loguru, the stack depth is limited to loguru/_logger.py itself without any other frame.f_back object. If the module is compiled as a .so library and then imported in another Python file, the loguru/_logger.py frame is linked back to the Python file without any reference to the compiled extension. So, when Loguru calls sys._getframe(1), either it raises a ValueError or it returns an incorrect frame.

Unfortunately, there is not much I can do about this. I don't like wrapping _getframe() with try / except as it would silently catch others "legitimate" stack-depth errors. It seems there is no way to know whether or not Loguru has been imported by a Cython compiled code. Whatever workaround is implemented, the frame retrieved would still be wrong, so this remains a problem anyway.

For now, the proposed solution is for Cython users to add logger = logger.opt(depth=-1) at the start of their files. Be aware that this is just a workaround to avoid ValueError, but the contextual record generated will be erroneous (concerning function, file, line, etc.).

I will label this issue as "wontfix" but I leave it open in case Cython implements some kind of workaround in the future.

Delgan avatar May 08 '19 17:05 Delgan

I met this issue recently. I'm trying to migrate our logging code to use loguru, and then notice some wierd issues. After spending some time figuring out what's happening, I notice the source code version works fine (yes, we have Cython compiled version). Base on this fact, I tried to find the root cause, and then notice get_frame has some exceptions.

It was not very clear at first place, we have some other C library cowork together, and the issue was happening when C library calling back our Python callback. I thought it was something wrong with the C library we are using so it didn't call at all. Extracting out a small piece of code and running through whole build flow made the error obvious.

I'm not quite sure what's the best way to solve this issue. But I think we can at least adding some info to readme for now, like a FAQ or known issue section.

wdv4758h avatar Oct 08 '19 03:10 wdv4758h

Hey @wdv4758h.

It maybe lacks visibility, but there is a link at the end of the Readme leading to a Resources page. There, one can find a paragraph concerning interoperability with Cython.

I prefer not to add such section directly to the Readme to keep it short and readable. Maybe could I rename the "Resources" link to something like "FAQ & Troubleshooting", to make it more explicit?

Delgan avatar Oct 08 '19 20:10 Delgan

@Delgan oh, my bad, thanks for pointing out

Yes, renaming it sounds good. I probably thought that's related talk videos or blog posts. I should have looked those pages, my bad.

wdv4758h avatar Oct 09 '19 06:10 wdv4758h

@wdv4758h Yeah, no problem, it's just a proof that I need to improve the visibility of these pages. ;)

Delgan avatar Oct 09 '19 18:10 Delgan

This one caught me with the following pattern:

import atexit
from loguru import logger


logger.info('Hi!')
atexit.register(logger.info, 'Bye!')

logger.info('Doing stuff...')
2022-07-06 11:50:55.989 | INFO     | __main__:<module>:6 - Hi!
2022-07-06 11:50:55.989 | INFO     | __main__:<module>:8 - Doing stuff...
Error in atexit._run_exitfuncs:
Traceback (most recent call last):
  File "/home/hannes/work/repos/loguru/loguru/_logger.py", line 1974, in info
    __self._log("INFO", None, False, __self._options, __message, args, kwargs)
  File "/home/hannes/work/repos/loguru/loguru/_logger.py", line 1852, in _log
    frame = get_frame(depth + 2)
ValueError: call stack is not deep enough

astromancer avatar Jul 06 '22 09:07 astromancer

@astromancer Thanks for the report, I moved this to a new ticker: #680

Delgan avatar Jul 07 '22 19:07 Delgan

Is there any progress? I had this problem

More info of the error :

>>> import gevent
>>> from apps.utils.qsl_job_rpc_methods import get_qsl_job_result
>>> s= gevent.spawn(get_qsl_job_result, 1, "133ab04b67cc487bad9a71345683712a", 0)
>>> gevent.joinall([s])
Traceback (most recent call last):
  File "src/gevent/greenlet.py", line 908, in gevent._gevent_cgreenlet.Greenlet.run
  File "qsl_job_rpc_methods.py", line 84, in apps.utils.qsl_job_rpc_methods.get_qsl_job_result
  File "engine_proxy.py", line 374, in apps.service.engine_proxy.EngineProxy.get_qsl_job_result
  File "engine_proxy.py", line 184, in apps.service.engine_proxy.EngineProxy.request_grpc_response
  File "/usr/local/qingteng/python3.8/lib/python3.8/site-packages/loguru/_logger.py", line 1973, in debug
    __self._log("DEBUG", None, False, __self._options, __message, args, kwargs)
  File "/usr/local/qingteng/python3.8/lib/python3.8/site-packages/loguru/_logger.py", line 1855, in _log
    frame = get_frame(depth + 2)
ValueError: call stack is not deep enough
2023-03-17T07:06:37Z <Greenlet at 0x7f44416182c0: get_qsl_job_result(1, '133ab04b67cc487bad9a71345683712a', 0)> failed with ValueError
[<Greenlet at 0x7f44416182c0: get_qsl_job_result(1, '133ab04b67cc487bad9a71345683712a', 0)>]

logger.opt(depth=-1) is not work Do you have any idea why ?

kouyalong avatar Mar 17 '23 08:03 kouyalong

@kouyalong Are you using Cython?

If yes, there is unfortunately no possible solution that I know of. If no, please open a new issue with a minimal reproducible example so we can investigate further.

Delgan avatar Mar 17 '23 09:03 Delgan

Hi,

I'm using Cython and loguru works but I can't manage (disable) logging:

from loguru import logger

logger.disable(<module_name>)

the above code works for source distribution and doesn't work with the binary (Cythonized) distribution.

Compiled with extra_link_args=['-Wl, --strip-all'].

Has anyone experienced this behavior?

senysenyseny16 avatar May 16 '23 11:05 senysenyseny16

@senysenyseny16 Sorry for the late reply. I answered you on the ticket you opened: https://github.com/Delgan/loguru/issues/875#issuecomment-1557811948

Delgan avatar May 22 '23 19:05 Delgan