Bug 16429

Summary: server/process: make the runCommand reply timeout configurable (hardcoded 30s+30s too short for large images)
Product: [Build System, Metadata & Runtime] BitBake Reporter: Bogdan Prădatu <bogdan.pradatu>
Component: bitbakeAssignee: Bogdan Prădatu <bogdan.pradatu>
Status: NEEDINFO --- QA Contact:
Severity: minor    
Priority: Medium CC: paul, poky.bs.watcher, poky.watcher, randy.macleod, richard.purdie, ross.burton, yoann.congal
Version: unspecified   
Target Milestone: 6.2   
Hardware: x86   
OS: Multiple   
Whiteboard:
OS type for building Yocto: --- Type of Regression: ---
Verified: Documentation change: Yes (doc changes required)
Attachments:
Description Flags
Instrumented bitbake server patch for timeout diagnosis none

Description Bogdan Prădatu 2026-09-17 18:17:37 UTC 
ServerCommunicator.runCommand() in lib/bb/server/process.py (https://github.com/openembedded/bitbake/blob/62be9113d98fccb347c6aa0a10d5c4ee2857f8b6/lib/bb/server/process.py#L476) enforces a hardcoded 30s + 30s reply timeout. On large image builds the server can legitimately be busy longer than 60s inside a single GIL-holding operation, so an otherwise-healthy build is sporadically aborted with:
```
    NOTE: No reply from server in 30s (for command ping at ...)
    Timeout while waiting for a reply from the bitbake server (60s at ...)
```

There is currently no way to raise this threshold, not via a variable and not via a command-line option. I would like to propose making it configurable via an environment variable (e.g. `BB_COMMAND_TIMEOUT`), keeping the current 30s/60s as the default.

Note that `BB_SERVER_TIMEOUT` does not help here: it only controls how long the resident server stays alive when idle, which is unrelated to the command reply poll.

Affected code (still present on master, bitbake 2.19.1):
```python
    # lib/bb/server/process.py
    class ServerCommunicator():
        def runCommand(self, command):
            ...
            if not self.recv.poll(30):
                logger.info("No reply from server in 30s (for command %s at %s)"
                            % (command[0], currenttime()))
                if not self.recv.poll(30):
                    raise ProcessTimeout(
                        "Timeout while waiting for a reply from the bitbake "
                        "server (60s at %s)" % currenttime())
```

Why the server exceeds 60s
==========================
I traced this to the runqueue's per-task dispatch. Live py-spy stack of the server process at the moment the UI reported "No reply", captured on bitbake 2.8.0 / Python 3.12.10. The idle thread was in state "active+gil" and was still in the same frame 10 seconds later:

```
    Thread (active+gil): "Thread-1 (idle_thread)"
        __getnewargs__ (collections/__init__.py:476)
        send_pickled_data (bb/runqueue.py:1359)   # pickle.dumps(data)
        execute (bb/runqueue.py:2403)             # send_pickled_data(w, runtask, "runtask")
        _execute_runqueue (bb/runqueue.py:1620)
        execute_runqueue (bb/runqueue.py:1654)
        buildTargetsIdle (bb/cooker.py:1488)
        idle_thread_internal (bb/server/process.py:435)

    Thread (idle): "MainThread"
        idle_commands (bb/server/process.py:505)  # cannot reply: GIL is held
```

Probable mechanism:
 - `execute()` builds a per-task runtask dict containing 'taskdepdata': `self.build_taskdepdata(task)`.

 - `build_taskdepdata()` walks the task's entire transitive dependency closure and returns `{tid: bb.TaskData(...)}`. `bb.TaskData` is a namedtuple, so pickling each entry calls `__getnewargs__`, matching the captured frame.

 - For late image tasks (`do_image_complete`, `do_rootfs`, `do_flush_pseudodb`, `do_image_ext4/cpio`) that closure is effectively the whole build (thousands of tasks). `pickle.dumps()` of that structure runs for tens of seconds on the server's idle thread while holding the GIL, starving the MainThread that answers the ping.

The `build_taskdepdata_cache` optimisation (commit c4519b542) helps building the dict, but the full taskdepdata is still pickled per task on the GIL thread, unchanged on master (runqueue.py:2405 / 2422).

Observed impact
===============
Intermittent CI failures on a large Yocto image build (~7900 tasks), roughly 30-45% of builds, always in the final image-assembly phase, and reproducible across different build machines.

The machine is otherwise idle at the stall: no I/O pressure, no memory pressure, no OOM, and no process in D state. That is consistent with a pure CPU/GIL stall in userspace Python rather than any resource exhaustion.

Precedent
=========
This class of failure has been addressed twice before by raising the hardcoded literal:

 - 131d4b8a5 (2017) "server/process: Increase runCommand timeout", 5s -> 30s:
   "We were seeing cases where we could hit the 5s timeout on large/fast machines running many different tasks at once."  [YOCTO #12116]

 - e567743e7 (2020) "server/process: Increase timeout for commands", added the second 30s poll: "We're running into this timeout on loaded autobuilders in situations where things should otherwise succeed."

This is the third occurrence of the same pattern as builds continue to grow.
Rather than bumping the constant a third time, I suggest making it tunable.

Proposed change
===============
Make the poll interval configurable, defaulting to the current 30s so existing behaviour is unchanged:

```python
    class ServerCommunicator():
        def __init__(self, connection, recv):
            self.connection = connection
            self.recv = recv
            try:
                self.timeout = float(os.environ.get("BB_COMMAND_TIMEOUT", 30))
            except ValueError:
                logger.warning("Ignoring invalid BB_COMMAND_TIMEOUT, using 30s")
                self.timeout = 30

        def runCommand(self, command):
            ...
            if not self.recv.poll(self.timeout):
                logger.info("No reply from server in %ss (for command %s at %s)"
                            % (self.timeout, command[0], currenttime()))
                if not self.recv.poll(self.timeout):
                    raise ProcessTimeout(
                        "Timeout while waiting for a reply from the bitbake "
                        "server (%ss at %s)"
                        % (2 * self.timeout, currenttime()))
```

Let me know what you think. I could, probably, submit a patch as well.
Comment 1 Richard Purdie 2026-09-24 14:37:23 UTC 
Please don't send such a patch. The issue is likely to be too much over the IPC rather than the timeout and that should be fixed instead.

8000 tasks is normal and shouldn't be an issue and our systems run this regularly. Is this machine heavily resource constrained.
Comment 2 Bogdan Prădatu 2026-09-25 07:42:47 UTC 
Hi,

I have to be honest, I have no idea what IPC is. The machines are not resource constrained, they are virtual machines with 16 CPU (1 thread per core) / 32 GB RAM (32GB swap), otherwise idle during the failures.

We are also running the yocto build on k9s pods where disk swap isn't available, so I am applying these settings in CI for all builds:
```
# Deriving Yocto parallelism: available_cpus=16, available_memory_gib=31.30, gib_per_thread=3.00, memory_threads=10 -> BB_NUMBER_THREADS=10, PARALLEL_MAKE=-j 10
# Use conservative no-swap Kubernetes parallelism capped by both the cgroup-aware CPU count
# and the available memory (roughly 3.0 GiB per BitBake thread).
BB_NUMBER_THREADS:forcevariable = "10"
PARALLEL_MAKE:forcevariable = "-j 10"

# Dynamically throttle BitBake task scheduling when Linux memory PSI pressure is high.
BB_PRESSURE_MAX_MEMORY = "50000"
```

At the moment of "No reply from server":
 - PSI cpu/io/memory "full" ~0% (no stall or queueing)
 - No processes in D state (no I/O block)
 - No OOM (cgroup memory.events oom=0), GBs of RAM free
 - Reproduces on multiple different hosts, with cache on and off, and at two different BB_NUMBER_THREADS/PARALLEL_MAKE settings
 - The stall lands on different tasks between runs (do_flush_pseudodb, do_image_complete, do_rootfs, do_packagedata, ...), i.e. not always one slow task

So, as much as I can tell, it isn't disk, memory pressure or host contention since the machine is pretty much idle while the server goes quiet.

attaching py-spy to the live bitbake-server at the exact "No reply" moment (and again 10s later) shows the idle_thread in the same frame both times, holding the GIL:

```python
    __getnewargs__ (collections/__init__.py:476)
    send_pickled_data (bb/runqueue.py:1359)   # pickle.dumps(data)
    execute (bb/runqueue.py:2403)             # send_pickled_data(worker, runtask, "runtask")
    buildTargetsIdle (bb/cooker.py:1488)
```

That's what led me to point at the per-task taskdepdata pickle. I don't have visibility into how large that taskdepdata payload is for our image, so we may well be hitting a scaling edge on that side.

If there's a specific thing you'd like me to measure or instrument to better diagnose this issue, let me know.

A colleague applied a patch to the bitbake code, increasing the timeout to 120s and we're not seeing issues so far, but we may as well just be covering up the symptoms instead of actually fixing the root cause.
Comment 3 Richard Purdie 2026-09-25 16:20:34 UTC 
The 120s is almost certainly masking some other issue. I'd have a look at the size of the data being transferred by send_pickled_data(), maybe log that somewhere.

IPC is "Inter Process Communication", i.e. how bitbake communicates between it's workers, the server (cooker) and the UI (knotty) which are all separate processes.

My suspicion is there is a large chunk of data unintentionally being transferred between them and this is what is taking up the time, if you profile shows it in this function.
Comment 4 Bogdan Prădatu 2026-10-01 15:11:49 UTC 
Created attachment 5250 [details]
Instrumented bitbake server patch for timeout diagnosis

I (and when I say "I", I mean my AI companion) instrumented send_pickled_data() to time the pickle and the pipe write separately, and also profiled the taskdepdata entries individually when the payload is large.

I am building this image: https://github.com/nxp-auto/meta-grayvip/blob/release/GrayVIP-1.0.6.4/recipes-fsl/images/fsl-image-grayvip.bb

Well, an internal unreleased version, not the exact one from the url. We're on poky scarthgap (BB 2.8.0, Python 3.12). There are ~7900 tasks, 10 consecutive builds on the same code/image.

The data size is normal, but pickle.dumps() non-deterministically degenerates on it.

The runtask payload for late image tasks (do_rootfs, do_image_*, do_flush_pseudodb) is ~6.6 MiB with ~7800-7900 taskdepdata entries. The pipe write is consistently fast (0.01-0.02s). The pickle is where all the time goes:

Build  Result  Stalling task        entries  pickle_time
-----  ------  -------------------  -------  -------------------
37     FAIL    do_image_cpio        7840     146.37s
38     PASS    (none)               7826     max 0.98s
39     FAIL    do_flush_pseudodb    7827     136.04s
40     PASS    (none)               7826     max 2.28s
44     FAIL    do_image_tar         7830     154.08s
45     PASS    (none)               7826     max 0.27s
46     PASS    (none)               7826     max 0.33s
47     FAIL    do_image_qa          7828     >120s (killed)
48     PASS    (none)               7826     max 1.21s
49     PASS    (none)               7826     max 0.80s

Builds 47 shows '>120s (killed)' because the 60s heartbeat timeout terminated the server before pickle.dumps() returned. The build_taskdepdata log (emitted before the pickle call) appeared ~2 minutes before the kill.

Also seems like different tasks hit the pickle stall each time, it's not consistently halting in one place.

When pickling each taskdepdata entry separately, the sum is ~0.6-0.9s for all ~7800 entries, with the slowest single entry at 0.015s. But pickling the same entries as a single dict takes 2-146s (or hangs).

From build 48 (passing):
- Pickle 7826 entries one by one: 0.46s total
- Pickle the same entries as one dict: 1.21s

From build 39 (failing):
- Pickle 7826 entries one by one: 0.93s total  
- Pickle the same entries as one dict: 136.04s
Comment 5 Paul Barker 2026-10-15 15:26:11 UTC 
Hi,

What's the full list of layers you have included in the build? For public layers could you share the specific commits used?

I wonder if this is reproducible without third party BSP layers. If you take just poky and try `bitbake core-image-full-cmdline core-image-sato core-image-weston`, that should exercise the same do_image* tasks a few times. You could collect the pickle time for that and see if it significantly different.

There are a couple of possible causes for the stall - either something on your build infrastructure or something in the layers you're using. Trying to reproduce with just the core layers would help to determine which is the likely culprit.
Comment 6 Randy MacLeod 2026-10-15 17:46:40 UTC 
Set to NEEDINFO state so we don't loose track of this issue.
Comment 7 Bogdan Prădatu 2026-10-19 07:20:24 UTC 
You're not gonna make this easy on me are you :))?

The layer list:
BBLAYERS ?= " \
  {yocto_workspace_dir}/sources/poky/meta \
  {yocto_workspace_dir}/sources/poky/meta-poky \
  {yocto_workspace_dir}/sources/poky/meta-yocto-bsp \
  {yocto_workspace_dir}/sources/meta-openembedded/meta-oe \
  {yocto_workspace_dir}/sources/meta-openembedded/meta-multimedia \
  {yocto_workspace_dir}/sources/meta-openembedded/meta-python \
  {yocto_workspace_dir}/sources/meta-openembedded/meta-networking \
  {yocto_workspace_dir}/sources/meta-openembedded/meta-gnome \
  {yocto_workspace_dir}/sources/meta-openembedded/meta-filesystems \
  {yocto_workspace_dir}/sources/meta-openembedded/meta-webserver \
  {yocto_workspace_dir}/sources/meta-openembedded/meta-perl \
  {yocto_workspace_dir}/sources/meta-openembedded/meta-xfce \
  {yocto_workspace_dir}/sources/meta-virtualization \
  {yocto_workspace_dir}/sources/meta-security \
  {yocto_workspace_dir}/sources/meta-freescale \
  {yocto_workspace_dir}/sources/meta-rust-bin \
  {yocto_workspace_dir}/sources/meta-alb/meta-alb-bsp \
  {yocto_workspace_dir}/sources/meta-alb/meta-alb-sdk \
  {yocto_workspace_dir}/sources/meta-alb-dev \
  {yocto_workspace_dir}/sources/meta-alb-url-proxy \
  {yocto_workspace_dir}/sources/meta-aws \
  {yocto_workspace_dir}/sources/meta-vip \
  {yocto_workspace_dir}/sources/meta-grayvip \
  {yocto_workspace_dir}/sources/meta-grayvip-dev \
  {yocto_workspace_dir}/sources/meta-eiqa \
  {yocto_workspace_dir}/sources/meta-carv \
  {yocto_workspace_dir}/sources/meta-alb/hw-partitions/hw-partition-1.2/meta-alb-hw-partition-1.2.1 \
  "

The public layers:
Layer                               Remote                           Revision
-----                                -----                           --------
poky (scarthgap)                     git.yoctoproject.org            077627338ac18aeca34bfe0c52777fab38e2e0c0
meta-openembedded                    git.openembedded.org            e621da947048842109db1b4fd3917a02e0501aa2
meta-freescale                       git.yoctoproject.org            62423c69631d7f7cffe2bd20997412d76caa94ef
meta-security                        git.yoctoproject.org            bc865c5276c2ab4031229916e8d7c20148dfbac3
meta-virtualization                  git.yoctoproject.org            af1db2042caf8021d767dce1b26c08b59b96f3d1
meta-rust-bin                        github.com/rust-embedded        63d677de912551b8f5606ce459748532c6ae529d
meta-qoriq                           github.com/nxp-qoriq            533e78f92774326d48f15adb5982a516fe114ee7
meta-aws (upstream: scarthgap)       git.yoctoproject.org            d82f0cdbda398d3fbab92318ced32c37b6c1d0d4


Reran 10 builds with a minimal config, as you suggested (`bitbake core-image-full-cmdline core-image-sato core-image-weston`):
BBLAYERS ?= " \
  {yocto_workspace_dir}/sources/poky/meta \
  {yocto_workspace_dir}/sources/poky/meta-poky \
  {yocto_workspace_dir}/sources/poky/meta-yocto-bsp \
  "

This is how it looks like:
Build  Host         Max pickle_time  Task                    Entries  Size
-----  -----------  ---------------  ----------------------  -------  -------
1      Host 1       55.978s          do_create_runtime_spdx  2848     2.11 MiB
2      Host 2        8.288s          do_package              2763     1.67 MiB
3      Host 3       47.200s          do_write_qemuboot_conf  5141     4.28 MiB
4      Host 2       25.588s          do_packagedata          2764     1.67 MiB
5      Host 1       50.977s          do_package_write_rpm    3030     1.97 MiB
6      Host 4        9.121s          do_rootfs               7935     6.82 MiB
7      Host 3       54.986s          do_image                5144     4.28 MiB
8      Host 1       49.595s          do_image                5144     4.28 MiB
9      Host 4        9.568s          do_package_write_rpm    3129     2.09 MiB
10     Host 2       23.789s          do_package              2715     1.65 MiB

Some of them are pretty close to the 60s timeout threshold.

Should I try anything else, send some of my collected data or what's the next step?
Comment 8 Paul Barker 2026-10-19 07:50:10 UTC 
That is good data!

Being that close to the 60s timeout with only the core layers is unexpected. With more layers and more to pickle it's no surprise that it is pushed over the timeout. So I don't think there is likely to be a specific issue in the other layers you're using.

What's interesting is that the max pickle duration doesn't correlate with the size of the data being pickled.

The remaining possibilities:
- Poor/inconsistent pickle performance in oe-core/bitbake
- Issue in your infrastructure causing stalls

Could you share the instrumentation code you used to create that table?
Comment 9 Bogdan Prădatu 2026-10-19 13:33:47 UTC 
Check the attachment of this bug, there is a patch called "Instrumented bitbake server patch for timeout diagnosis"

Or check comment No. 4 https://bugzilla.yoctoproject.org/show_bug.cgi?id=16429#c4
Comment 10 Paul Barker 2026-10-20 09:09:42 UTC 
Hi,

I applied the instrumentation patch to poky (scarthgap commit 104772c5fd0653290cbb5e4b77813343957939cc) and ran `bitbake core-image-base core-image-full-cmdline core-image-weston core-image-sato` to generate lots of samples. Looking at the resulting bitbake-send-pickled-data.csv file, and sorting by pickle time (4th column), the maximum value I see is around 185 ms to pickle 168 kB for zstd:do_populate_sysroot. Only the top 4 entries took longer than 100 ms. The largest amount of data (6.76 MB for core-image-sato:do_populate_lic_deploy) took around 18ms.

I suspect the issue here is your build environment. Do you have a non-kubernetes environment you can test in?
Comment 11 Bogdan Prădatu 2026-10-20 10:38:04 UTC 
OK, thanks for testing. I was actually hitting this issue on static virtual machines, not in kubernetes. I will try to test in a different environment and see how it goes.