• [email protected] [2025-10-20 05:56]:
On Oct 18, 2025, at 2:11 AM, Kirill Miazine <[email protected]> wrote:
Greetings!
Yesterday I hit a case where some logging would throw RecursionError. After
spending quite a bit of time hunting down the cause of the error, I doubled the
recursion limit and went on.
Is logging RecursionError a normal behaviour to experience? Should I take it
more seriously that just double the recursion limit?
In a word, "no, that's not normal". Without seeing the traceback I can't even
say if this is Twisted's fault or your application's, so I can't say much more. But you
should not be recursing so much that you get a RecursionError.
If it's a Twisted issue, please do let us know and file a bug.
it could certainly be an issue with my code, it wouldn't be the first
time. exception look like this, although it's a bit challenging to
reproduce them. this one was obtained when I hit Ctrl-C.
[Failure instance: Traceback: <class 'RecursionError'>: maximum
recursion depth exceeded
/home/monger/pyng/lib/pyng/master.py:428:_run_check
/home/monger/pyng/lib/pyng/master.py:379:_get_check
/usr/local/lib/python3.11/site-packages/twisted/internet/defer.py:656:addErrback
/usr/local/lib/python3.11/site-packages/twisted/internet/defer.py:533:addCallbacks
--- <exception caught here> ---
/usr/local/lib/python3.11/site-packages/twisted/internet/defer.py:1074:_runCallbacks
/home/monger/pyng/lib/pyng/master.py:379:<lambda>
/usr/local/lib/python3.11/site-packages/twisted/logger/_logger.py:341:error
/usr/local/lib/python3.11/site-packages/twisted/logger/_logger.py:226:emit
/usr/local/lib/python3.11/site-packages/twisted/logger/_observer.py:87:__call__
/usr/local/lib/python3.11/site-packages/twisted/logger/_logger.py:281:failure
/usr/local/lib/python3.11/site-packages/twisted/logger/_logger.py:226:emit
/usr/local/lib/python3.11/site-packages/twisted/logger/_observer.py:86:__call__
/usr/local/lib/python3.11/site-packages/twisted/logger/_observer.py:102:_errorLoggerForObserver
/usr/local/lib/python3.11/site-packages/twisted/logger/_observer.py:33:__init__
/usr/local/lib/python3.11/site-packages/twisted/logger/_logger.py:142:__init__
/usr/local/lib/python3.11/site-packages/twisted/logger/_logger.py:121:_namespaceFromCallingContext
]
[Failure instance: Traceback: <class 'RecursionError'>: maximum
recursion depth exceeded
/home/monger/pyng/lib/pyng/master.py:428:_run_check
/home/monger/pyng/lib/pyng/master.py:379:_get_check
/usr/local/lib/python3.11/site-packages/twisted/internet/defer.py:656:addErrback
/usr/local/lib/python3.11/site-packages/twisted/internet/defer.py:533:addCallbacks
--- <exception caught here> ---
/usr/local/lib/python3.11/site-packages/twisted/internet/defer.py:1074:_runCallbacks
/home/monger/pyng/lib/pyng/master.py:379:<lambda>
/usr/local/lib/python3.11/site-packages/twisted/logger/_logger.py:341:error
/usr/local/lib/python3.11/site-packages/twisted/logger/_logger.py:226:emit
/usr/local/lib/python3.11/site-packages/twisted/logger/_observer.py:87:__call__
/usr/local/lib/python3.11/site-packages/twisted/logger/_logger.py:281:failure
/usr/local/lib/python3.11/site-packages/twisted/logger/_logger.py:226:emit
/usr/local/lib/python3.11/site-packages/twisted/logger/_observer.py:86:__call__
/usr/local/lib/python3.11/site-packages/twisted/logger/_observer.py:102:_errorLoggerForObserver
/usr/local/lib/python3.11/site-packages/twisted/logger/_observer.py:33:__init__
/usr/local/lib/python3.11/site-packages/twisted/logger/_logger.py:142:__init__
/usr/local/lib/python3.11/site-packages/twisted/logger/_logger.py:121:_namespaceFromCallingContext
]
line 379 referenced there looks like this
<code>
376 def _get_check(self):
377 d = self.checks_queue.get()
378 d.addCallback(self._run_check)
379 d.addErrback(lambda err: self.log.error('{failure}',
failure=err))
380 d.addErrback(print)
</code>
my theory thus far is that in _run_check there were errors, which
triggered errback at line 379, and which again triggered error and I had
lines above printed by errback on line 380.
I have identified three consecutive lines in my log, the first two are
in _run_check.
<log>
2025-10-20T21:45:53+0200 [pyng.master.PyngMaster#info] Unable to format
event {'check': <pyng.PING o
bject at 0x294df13f3510>, 'log_logger': <Logger
'pyng.master.PyngMaster'>, 'log_level': <LogLevel=in
fo>, 'log_namespace': 'pyng.master.PyngMaster', 'log_source':
<pyng.master.PyngMaster object at 0x29
4df34c8090>, 'log_format': 'Ready to run {check.type} check
"{check.desc}" [{check.id}]', 'log_time'
: 1760989553.4371765}: maximum recursion depth exceeded
2025-10-20T21:45:53+0200 [pyng.master.PyngMaster#info] Unable to format
event {'check': <pyng.PING o
bject at 0x294df13f3510>, 'log_logger': <Logger
'pyng.master.PyngMaster'>, 'log_level': <LogLevel=in
fo>, 'log_namespace': 'pyng.master.PyngMaster', 'log_source':
<pyng.master.PyngMaster object at 0x29
4df34c8090>, 'log_format': 'No remote runners for {check.type} check
"{check.desc}" [{check.id}]', '
log_time': 1760989553.437236}: maximum recursion depth exceeded
2025-10-20T21:45:53+0200 [pyng.master.PyngMaster#info] Unable to format
event {'check': <pyng.PING o
bject at 0x294df13f3510>, 'delay': 60, 'log_logger': <Logger
'pyng.master.PyngMaster'>, 'log_level':
<LogLevel=info>, 'log_namespace': 'pyng.master.PyngMaster',
'log_source': <pyng.master.PyngMaster o
bject at 0x294df34c8090>, 'log_format': 'Schedule {check.type} check
"{check.desc}" [{check.id}] to
run in {delay} seconds', 'log_time': 1760989553.437282}: maximum
recursion depth exceeded while call
ing a Python object
</log>
now for the code. the first log message is printed out immediately after
the start of running of the function
<code>
def _run_check(self, check):
self.log.info(
'Ready to run {check.type} check "{check.desc}" [{check.id}]',
check=check,
)
</code>
the next one is also failry simple, still in _run_check, it just
notifies that there are no AMP runners available to run the task and
re-schedules it
<code>
if self.force_remote and runner is None:
self.log.info(
'No remote runners for {check.type} check
"{check.desc}" [{check.id}]',
check=check,
)
del self.running[check]
self._reschedule_check(check, check.interval)
return self._get_check()
</code>
and the last log line is related to when re-scheduling takes place
<code>
def _reschedule_check(self, check, delay=60):
if check in self.scheduled:
self.log.error(
'{check.type} check "{check.desc}" [{check.id}] already
scheduled',
check=check,
)
return
def _enqueue():
del self.scheduled[check]
self.checks_queue.put(check)
self.scheduled[check] = reactor.callLater(delay, _enqueue)
self.log.info(
'Schedule {check.type} check "{check.desc}" [{check.id}] to
run in {delay} seconds',
check=check, delay=delay,
)
</code>
this looks failry simple.
I have only seen this kind of error when AMP remotes disappear and I
have some connecting and re-connecting logic, where there could be some
recursion snafu.
-g
_______________________________________________
Twisted mailing list -- [email protected]
To unsubscribe send an email to [email protected]
https://mail.python.org/mailman3/lists/twisted.python.org/
Message archived at
https://mail.python.org/archives/list/[email protected]/message/PQVMO2WSHVR3A6VR4CG3JRSDDIDNIW44/
Code of Conduct: https://twisted.org/conduct
_______________________________________________
Twisted mailing list -- [email protected]
To unsubscribe send an email to [email protected]
https://mail.python.org/mailman3/lists/twisted.python.org/
Message archived at
https://mail.python.org/archives/list/[email protected]/message/TUDZYEVHBLRBPSKMYBWPJ6QNZOS2X43G/
Code of Conduct: https://twisted.org/conduct
