KafkaTimeoutError: Timeout during ApiVersions check (HPE NonStop Python)

[berrfred]

First of all thanks for your incredible work since kafka-python allows me to use KAFKA on a very particular system (HPE NonStop) and also for your support, I still remember one year ago when you pointed out that rebalancing on my consumer was due to the heartbeat not running properly and a consequence of the GIL on CPython ... solved with a small time sleep after each poll.

Now I have another issue again on the consumer while trying to upgrade my environment from version 2.2.10 to the latest 3.0.8 .
It is not reading anything and the attached debug log shows some errors, any idea what's going wrong ?

gwkmt_kafka_gmtk2.log

[dpkp]

It looks like a similar issue. In 3.0.8 all network IO is processed on a background thread (in 2.2 it was only the consumer heartbeat). There is a ~10sec default timeout on connections and it seems like you may be hitting that due to similar GIL problems. It looks like we haven't actually exposed that 10sec timeout configuration to clients, but you should be able to monkeypatch it like so:

consumer._manager.config['socket_connection_setup_timeout_ms'] = 30000  # 30sec connection timeout

(also the intent of that timeout is that it increases w/ exponential backoff, but in this case that is not working -- i'll work on a fix for that as well).

[berrfred]

I tried your suggestion setting the timeout to 30s and I do not see the previous ERROR on ApiVersions check but I think we are still facing the same issue ...

2026-07-14 10:35:03,284 - WARNING - $GMTK2 - Task <kafka.net.selector.Task object at 0x8dbce10> ran for 5.004s (>0.100s threshold). It is blocking the event loop -- likely a tight sync loop inside a coroutine. Other pollers will time out.

gwkmt_kafka_gmtk2_20260714.log

[dpkp]

Yes, I saw that warning in the first set of logs. In your case I suspect it is not actually the coroutine that is blocking but more likely it is the GIL lock problem that you raised in the prior issue. If your app code holds the GIL for 5secs then it will prevent the event loop from processing any coroutines, and then when the GIL is unlocked and the event loop starts processing again it will log this warning.

Are you seeing any other errors or issues besides this warning?

[berrfred]

No, I do not see any other error, it is only logging Timeout during ApiVersions check without increasing the connection timeout
or SASL Authentication timed out when increasing the timeout to 30 seconds. I also tried adding a time.sleep(0.001) right after the consumer creation but that does not change anything.

gwkmt_kafka_gmtk1_timeout_10s.log
gwkmt_kafka_gmtk1_timeout_30s.log

[dpkp]

This seems like the same GIL issue we investigated in #2610 . Under HPE NonStop python + your application the GIL is held continuously for 5secs at a time, and that starves kafka-python's background threads. in 2.x it was possible to ignore because we only did heartbeats on a background thread. But in 3.x it is much worse because we've moved all IO onto the background thread. The logs show that we make incremental progress on IO tasks every 5secs, but not enough to avoid the eventual timeouts.

So I think there are a handful of options here:

(1) Stay on 2.x . You know that it works, but you're stuck w/o upgrades, improvements, new features, or security fixes. Not great option.
(2) Try to identify and fix the root cause of your 5sec GIL issue. If holding the GIL for 5secs is not required by your application and is instead an accidental side-effect of customization you've done in your code, then you could potentially find the cause, fix it, and free up the background thread to run w/o the lock problems.
(3) Add a network backend to kafka-python that runs everything on the foreground thread during consumer.poll(). This might restore behavior back to the 2.x baseline that worked for you (but we'd do heartbeats in the foreground thread).

For (2), I asked claude to write up a helper script to identify if HPE Nonstop python might actually be holding the GIL where CPython does not. Would you be able/willing to run this w/ HPE Nonstop python and paste back the output? If you're able maybe also run from inside your app context (with additional cpython lib wiring you have)?

gil_probe.py

This is the output I get running locally w/ CPython:

====================================================================
GIL-release probe
--------------------------------------------------------------------
python      : 3.14.2 (main, Dec  5 2025, 16:49:16) [GCC 14.3.0]
platform    : Linux-6.12.92-x86_64-with-glibc2.40
machine     : x86_64
thread_info : sys.thread_info(name='pthread', lock='semaphore', version='NPTL 2.40')
switchint   : 0.005 s
phase dur   : 2.0 s
====================================================================

blocking call                                      bg iters/s   verdict
--------------------------------------------------------------------
time.sleep()            [GOOD baseline]              20194175   RELEASES GIL   (bg ran freely)
CPU spin loop           [STARVED baseline]            3030957   >>> HOLDS GIL  (bg STARVED) <<<
threading.Event.wait()  [used by manager.run]        19459713   RELEASES GIL   (bg ran freely)
Lock.acquire(timeout=)  [used by manager.run]        20132346   RELEASES GIL   (bg ran freely)
Condition.wait(timeout)                              20216646   RELEASES GIL   (bg ran freely)
select.select(timeout)  [used by the IO loop]        20049339   RELEASES GIL   (bg ran freely)
--------------------------------------------------------------------
Reading it:
  * 'time.sleep' should say RELEASES and 'CPU spin' should say HOLDS.
    Those two are the known-good / known-bad reference points.
  * On normal CPython, EVERYTHING except the CPU spin says RELEASES.
  * On HPE NonStop: if Event.wait / Lock.acquire / select say
    'HOLDS GIL', that is the bug starving kafka-python's IO thread.
    Please paste this whole table into the github issue.
====================================================================

[berrfred]

I've been running the script on two different NonStop systems, the first one is a classical one (NSX) still using HPE hardware and running Python 3.11 while the second one is a virtual one (NSV) running Python 3.12 . In both cases the script does not end !? I had to stop it with Ctrl^Z and then kill the process ... following is the initial output given by the script.

====================================================================
GIL-release probe
--------------------------------------------------------------------
python      : 3.11.3 (main, Jul  6 2023, 17:33:13) [C]
platform    : NONSTOP_KERNEL-L23-NSX-P-32bit
machine     : NSX-P
thread_info : sys.thread_info(name='pthread', lock='mutex+cond', version=None)
switchint   : 0.005 s
phase dur   : 2.0 s
====================================================================

====================================================================
GIL-release probe
--------------------------------------------------------------------
python      : 3.12.6 (main, May 16 2025, 11:30:19) [C]
platform    : NONSTOP_KERNEL-L25-NSV-AE-32bit
machine     : NSV-AE
thread_info : sys.thread_info(name='pthread', lock='mutex+cond', version=None)
switchint   : 0.005 s
phase dur   : 2.0 s
====================================================================

[berrfred]

As I suspected the Counter to enter an infinite loop I modified the Counter run() method with a small time.sleep()

	def run(self):
		while not self.stop:
			self.n += 1
			# Release CPU every 1000 iterations to avoid main program starvation on NonStop
			if self.n % 1000 == 0:
				time.sleep(0.0001)

and here is the output.

====================================================================
GIL-release probe
--------------------------------------------------------------------
python      : 3.11.3 (main, Jul  6 2023, 17:33:13) [C]
platform    : NONSTOP_KERNEL-L23-NSX-P-32bit
machine     : NSX-P
thread_info : sys.thread_info(name='pthread', lock='mutex+cond', version=None)
switchint   : 0.005 s
phase dur   : 2.0 s
====================================================================

blocking call                                      bg iters/s   verdict
--------------------------------------------------------------------
time.sleep()            [GOOD baseline]                481299   RELEASES GIL   (bg ran freely)
CPU spin loop           [STARVED baseline]                  0   >>> HOLDS GIL  (bg STARVED) <<<
threading.Event.wait()  [used by manager.run]          468581   RELEASES GIL   (bg ran freely)
Lock.acquire(timeout=)  [used by manager.run]          486805   RELEASES GIL   (bg ran freely)
Condition.wait(timeout)                                476285   RELEASES GIL   (bg ran freely)
select.select(timeout)  [used by the IO loop]          447300   RELEASES GIL   (bg ran freely)
--------------------------------------------------------------------
Reading it:
  * 'time.sleep' should say RELEASES and 'CPU spin' should say HOLDS.
    Those two are the known-good / known-bad reference points.
  * On normal CPython, EVERYTHING except the CPU spin says RELEASES.
  * On HPE NonStop: if Event.wait / Lock.acquire / select say
    'HOLDS GIL', that is the bug starving kafka-python's IO thread.
    Please paste this whole table into the github issue.
====================================================================

[dpkp]

Thanks, and thanks for debugging the script hang w/ time.sleep. I also found the HPE NonStop python guide online and noticed in the considerations section:

Threading module is implemented with POSIX User Thread (PUT) on NonStop. Threads are scheduled for executing
by PUT Model library. All threads created within a process share the same process address space. With the PUT Model
library, one thread can never be preempted by another thread. The program must ensure that threads relinquish
control either by explicitly calling the os.sched_yield() or time.sleep(0) function, by waiting on locks,
conditions, semaphores, events, timers and barriers, or by calling a thread-aware library function. For more
information, see Using the POSIX User Thread (PUT) Model Library in Open System Services Programmer's Guide.

NonStop Python Programmer's Guide (L-series)

The script results, and especially the hang that required your time.sleep fix, confirm the same. It's good to know that apart from that there are no differences in GIL release between CPython and NonStop python. So I think that means we're back to looking for other places in your application that may either be holding the GIL or blocking for 5secs w/o relinquishing thread control.

I saw this in the code you posted in #2610:

cext.signaltimeout(kafka_poll_interval*100, 0, TAG_POLL_REQ, None, ac_error_message)

With a little claude help I think this means that signaltimeout only arms a "Guardian" timer and then returns immediately; no blocking in this call. The actual waiting happens in your outer dispatcher? That would be whatever call produces the signal that you test for signal.l_par == TAG_POLL_REQ in the code snipped. My/our new suspicion is that the 5 seconds are spent inside a Guardian wait (AWAITIO or similar). If the PUT thread library doesn't treat that wait as a thread yield point, that could starve running threads and look similar to a GIL lock.

Three things that could help test / confirm this idea:

1. Would you be willing to paste the code that produces signal? I.e., the call your dispatcher blocks in just before the signal.l_par == TAG_POLL_REQ branch? Seeing which Guardian procedure is used and what timeout is given would be super helpful.

2. How is the cext loaded? Are you using ctypes.CDLL(...) or ctypes.PyDLL(...)? I believe CDLL releases the GIL around each foreign call, while PyDLL does not. If you are using PyDLL, switching to CDLL might be the issue and could fix.

3. Try this quick test: with kafka-python 3.0.8 unmodified (no monkeypatching), set your kafka_poll_interval to 0.25 so the idle branch arms a timeout at 25 centiseconds instead of 500. If the ApiVersions / SASL timeouts disappear and the consumer starts reading, that I think should confirm the outer dispatch theory (though wouldn't identify whether it's caused by GIL or PUT). And it could be a working configuration. If it still stalls in exact 5-second steps with the 250ms timer armed, then the 5s is coming from somewhere else.

[berrfred]

That is exactly what I wanted to point out in my next post but you already got most of it ... as we are mostly developing in C language and have built over the last 25 years some proprietary libraries (e.g. events, logs, statistics) including calls to NonStop procedures (e.g. AWAITIOX, READUPDATEX, SIGNALTIMEOUT, SERVERCLASS_SEND_), almost all our recent developments in Python do call a few shared libraries through ctypes.cdll.LoadLibrary() and the main logic of the program is based on AWAITIOX() combined with calls to SIGNALTIMEOUT() to schedule actions, mainly INI file check / STAT bumping and calls to the consumer poll() method with a default of timeout_ms=0 .

I am currently on holidays for the next 3 weeks and our main test NonStop system is under maintenance in the next days ... but I will try asap to run a new 3.0.8 test with the suggested 25 centiseconds interval. I am also wondering if setting a very small SIGNALTIMEOUT value (i.e. your suggestion) and passing the interval as timeout_ms to the poll() could be a better approach.

Hope we can manage to solve that stupid issue with 3.x but anyway thank you so much for you support.

Attached our consumer source code.
kafkc2pwy_nowait.py

[dpkp]

Thanks, yes I think this confirms. Enjoy your time off! I will try to work on a foreground-only net backend that you could use to get the 2.x IO behavior with 3.x. In the meantime I think you're correct that the two knobs you could tune now are (1) passing a non-zero timeout_ms to consumer.poll(); this will implicitly sleep if there are no messages + allow the background io thread an opportunity to progress. and (2) reduce your 5s wait interval between runs when there are no messages available; this should give more opportunities to progress IO per unit time generally.

[berrfred]

I managed to realize a very quick test with 3.0.8 by simply setting my kafka_poll_interval (the one used to schedule the next poll through NonStop SIGNALTIMEOUT) to 1 second and kafka_poll_timeout_ms (the one provided as timeout_ms in poll) to 4000 milliseconds ... in the end it achieves a scheduling very similar the current 5 second interval (I may just get my statistics bump a few seconds late which is not a big issue) and the consumer does work ! The debug log was not enabled so I cannot tell if there are still some errors but at least it seems to work.

Now that was the good news ... the bad one is that it is consuming a lot of cpu even with no message to read and I remember that was the main reason also with 2.x releases to always use timeout_ms=0 ... for some reason delegating the poll timeout management to kafka-python on the NonStop has this drawback.

See attached cpu usage, between 13:00 and 14:30 some colleagues were running some stress test with 2.x, between 15:35 and 15:50 I've been running my consumer with 3.x on cpu 02 with very few or no message to read.

[berrfred]

I also made a try with kafka_poll_interval = 1 second and timeout_ms = 0 in the poll() call ... that solves the cpu issue, I do not see any error being generated in the debug log but the consumer again does not read anything.