Skip to content

rhel8-x64 executors in the CI frequently to have an unexpected 25 minute "pause" around the doc gen execution pase #1174

Closed

Description

@sxa

Spotted today while looking at the jobs which were taking longest and determining that the rhel8-x64 ones are regularly taking over an hour in total. it doesn't seem to affect RHEL8 on ppc64le or other x64 platforms from an initial look which take no more than around 2 minutes for the same section. The rhel8-x64 builds seem to pause and produce no build output on those machines. It's unclear why but it may be while running npm. Possible resource starvation, I/O on disk or network or something else but perhaps @nodejs/doc-kit might be able to provide some insight as to whether this is likely to be in the doc generation and if so be able to provider some insight on how we might be able to resolve it. These log snippets are from three machines across two providers:

Job 73039 on test-ibm-rhel8-x64-2:

14:09:09 Building addon in /home/iojs/build/workspace/node/test/sqlite/test_sqlite_extensions
14:09:09 mkdir -p out/doc
14:09:09 cp doc/node-config-schema.json out/doc
14:09:09 mkdir -p out/doc/api
14:34:58 cp -r doc/api out/doc
14:34:58 npm warn cli npm v12.1.0 does not support Node.js v27.0.0-pre. This version of npm supports the following node versions: `^22.22.2 || ^24.15.0 || >=26.0.0`. You can find the latest version at https://nodejs.org/.
14:34:58
14:34:58 added 297 packages, and audited 298 packages in 9s
14:34:58
14:34:58 148 packages are looking for funding
14:34:58   run `npm fund` for details
14:34:58
14:34:58 found 0 vulnerabilities

Job 74040 on test-ibm-rhel8-x64-1:

14:08:39 Building addon in /home/iojs/build/workspace/node/test/sqlite/test_sqlite_extensions
14:08:48 mkdir -p out/doc
14:08:48 cp doc/node-config-schema.json out/doc
14:08:48 mkdir -p out/doc/api
14:08:48 cp -r doc/api out/doc
14:08:48 npm warn cli npm v12.1.0 does not support Node.js v27.0.0-pre. This version of npm supports the following node versions: `^22.22.2 || ^24.15.0 || >=26.0.0`. You can find the latest version at https://nodejs.org/.
14:08:48
14:08:48 added 297 packages, and audited 298 packages in 9s
14:34:31
14:34:31 148 packages are looking for funding
14:34:31   run `npm fund` for details
14:34:31
14:34:31 found 0 vulnerabilities
14:34:31 Clean up any leftover processes, error if found.

Job 74037 on test-digitialocean-rhel8-x64-1:

13:20:23 Building addon in /home/iojs/build/workspace/node/test/sqlite/test_sqlite_extensions
13:20:23 mkdir -p out/doc
13:20:23 cp doc/node-config-schema.json out/doc
13:20:23 mkdir -p out/doc/api
13:20:23 cp -r doc/api out/doc
13:20:23 npm warn cli npm v12.1.0 does not support Node.js v27.0.0-pre. This version of npm supports the following node versions: `^22.22.2 || ^24.15.0 || >=26.0.0`. You can find the latest version at https://nodejs.org/.
13:49:43 
13:49:43 added 297 packages, and audited 298 packages in 10s
13:49:43 
13:49:43 148 packages are looking for funding
13:49:43   run `npm fund` for details
13:49:43 
13:49:43 found 0 vulnerabilities

Activity

  1. sxa commented on Oct 22, 2026

    @sxa
    MemberAuthor

    Looking at the non-main runs:

  2. ovflowd commented on Oct 22, 2026

    @ovflowd
    Member

    Hi @sxa thanks for reporting this, I guess we can move this to nodejs/doc-kit for now, I'd be good if there were more logs from NPM (verbose) to see where and what is causing it to hang.

    cc @nodejs/doc-kit

  3. transferred this issue fromnodejs/nodeon Oct 22, 2026
  4. self-assigned this
    on Oct 25, 2026
  5. ovflowd commented on Oct 25, 2026

    @ovflowd
    Member

    Took a deeper look at this one 👀

    tl;dr: it's not npm (that finishes in 9s), it's the three doc-kit generate calls in make doc-only, and it's specific to the rhel8-x64 agents themselves. I couldn't reproduce it anywhere else. I wrote the whole investigation up here, with the chart and raw numbers: https://claude.ai/artifact/FbB9rHEYudQzmH7ZTx9csv

    The stall is pretty stable per agent, which makes me think it's slow work rather than some timeout (a timeout would be the same everywhere):

    Agent doc step
    test-ibm-rhel8-x64-1 1528–1543s
    test-ibm-rhel8-x64-2 1549–1559s
    test-ibm-rhel8-x64-3 1738–1793s
    test-digitalocean-rhel8-x64-1 1561–1879s
    rhel9 / debian12 / ubuntu2404 27–28s
    alpine 112–129s

    What I ran locally

    All of these run Node's exact doc step (the three generate calls from make doc-only, with tools/doc installed the same way the Makefile does it) on main's doc/api, pinned to 2 CPUs like the agents' make -j 2:

    Setup What it rules out doc step
    My machine, 2 CPUs CPU count ~24s
    + 1.5GB memory cap / 768MB heap memory pressure, heap sizing ~18–20s (web step)
    + ulimit -v address space limits crashes right away instead of slowing down
    UBI 8.10 userland + Node 24 glibc 2.28, RHEL 8 libraries, native bindings ~24s
    UBI 8.10 + main built like CI (clang, glibc 2.28) the CI binary itself ~23s
    UBI 8.10 from Dec 2024 (glibc 2.28-251.el8_10.5) the condition variable missed wakeup bug, fixed in RHBA-2025:1573 ~23s (twice)
    AlmaLinux 8.10 VM, kernel 4.18.0-553, 2 vCPU / 8GB the RHEL 8 kernel: cgroup v1, THP always, kvm-clock ~25s
    Same VM as Broadwell / Sandy Bridge / Westmere missing AVX-512 / AVX2 / AVX ~27s
    strace -e connect on the build network timeouts 0 connect calls
    How these were set up
    • The UBI 8 runs used the official ubi8/ubi root filesystem in a bubblewrap sandbox. The Dec 2024 one is the 8.10-1132.1733300785 tag, whose glibc doesn't have the "Fix missed wakeup in POSIX thread condition variables" changelog entry yet.
    • main was compiled inside a ubi8/ubi container with clang and gcc-toolset headers, following select-compiler.sh for rhel on Node ≥ 25 (UBI only ships clang 21, CI pins 20.1.8).
    • The VM is the AlmaLinux 8.10 GenericCloud image under KVM. The CPU models come from QEMU's -cpu.
    • The doc-kit side is the exact tools/doc from main (@doc-kit/cli 1.0.5, @doc-kit/generator-react 0.5.0, @node-core/doc-kit 2.0.6), and every run produced all 71 HTML pages.

    What's still open

    • The comparison itself: web.doc-kit.config.mjs only builds the HTML pages when the machine has more than 5GB of RAM. If rhel9/debian/ubuntu are below that, their ~27s is the JSON-only build, and rhel8 might just be the slowest of the agents doing HTML.
    • The hypervisor or neighbours: the rest of the rhel8 job is only ~1.4x slower than rhel9, but this is the only long, CPU-heavy, multithreaded JS step in the pipeline.
    • Swap: the step peaks around 2GB, fine unless the agent has little free memory left.
    • The agents' patch level: the VM ran today's RHEL 8.10 kernel, an older 4.18 build could carry a fixed regression.
    • Something else running on the agents (a security/monitoring agent, an LD_PRELOAD, leftover processes).

    @sxa would you be able to run this on one of the rhel8 agents? It runs make doc-only V=1 (doc-kit's debug logs timestamp every phase) with vmstat next to it, so we can see if it's steal time, swap, or one specific phase. VARIANTS=1 also tries a few V8/doc-kit flags (-p 1, --single-threaded-gc, --liftoff-only, a bigger semi-space) to narrow it down. And do you know how much RAM these agents have?

    diagnose-doc-build.sh
    #!/bin/bash
    # Diagnose slow `make doc-only` runs on a Node.js CI agent (nodejs/doc-kit#1174).
    # Run from a built nodejs/node checkout (out/Release/node must exist).
    #
    #   bash diagnose-doc-build.sh                # environment + one debug run
    #   VARIANTS=1 bash diagnose-doc-build.sh     # also try V8/doc-kit flag variants
    #
    # Everything lands in $OUT (default /tmp/doc-kit-diagnostics).
    
    set -u
    OUT=${OUT:-/tmp/doc-kit-diagnostics}
    NODE=${NODE:-./out/Release/node}
    mkdir -p "$OUT"
    
    {
      echo "== os";      cat /etc/redhat-release /etc/os-release 2>/dev/null | head -3; uname -r
      echo "== cpu";     nproc; lscpu | grep -E 'Model name|Hypervisor|Thread|MHz' | head -6
      echo "== memory";  free -m; swapon --show
      echo "== cgroup";  stat -fc %T /sys/fs/cgroup; cat /proc/self/cgroup | head -5
      echo "== thp";     cat /sys/kernel/mm/transparent_hugepage/enabled /sys/kernel/mm/transparent_hugepage/defrag
      echo "== clock";   cat /sys/devices/system/clocksource/clocksource0/current_clocksource
      echo "== libs";    rpm -q glibc kernel 2>/dev/null | tail -3
      echo "== limits";  ulimit -a
      echo "== env";     env | grep -E '^(NODE_|UV_|JOBS|MAKEFLAGS|TMPDIR|LD_)' || true
      echo "== node"
      "$NODE" -p 'JSON.stringify({ version: process.version, totalmem: os.totalmem(), constrained: process.constrainedMemory(), heapLimit: v8.getHeapStatistics().heap_size_limit, parallelism: os.availableParallelism(), cpus: os.cpus().length }, null, 2)'
      echo "== load";    uptime; ps -eo pid,pcpu,pmem,etime,comm --sort=-pcpu | head -8
    } > "$OUT/env.txt" 2>&1
    
    run() {
      local name=$1; shift
      rm -rf out/doc
      vmstat -t 5 > "$OUT/vmstat-$name.txt" 2>&1 &
      local vm=$!
      local start=$(date +%s)
      env "$@" make doc-only V=1 > "$OUT/doc-only-$name.log" 2>&1
      local status=$?
      kill "$vm" 2>/dev/null
      echo "$name: $(( $(date +%s) - start ))s (exit $status)" | tee -a "$OUT/summary.txt"
    }
    
    : > "$OUT/summary.txt"
    run baseline
    
    if [ "${VARIANTS:-0}" = 1 ]; then
      run one-thread         JOBS=1
      run single-threaded-gc NODE_OPTIONS=--single-threaded-gc
      run liftoff-only       NODE_OPTIONS=--liftoff-only
      run bigger-semi-space  NODE_OPTIONS=--max-semi-space-size=64
    fi
    
    echo "Done. Please share $OUT (env.txt, summary.txt, vmstat-*.txt and doc-only-*.log)."
  6. ovflowd commented on Oct 25, 2026

    @ovflowd
    Member

    cc @nodejs/build

  7. sxa commented on Oct 26, 2026

    @sxa
    MemberAuthor

    Those machines have 4G of RAM

    [iojs@test-ibm-rhel8-x64-1 node]$ VARIANTS=1 bash ~/sxa/cabbage.sh
    baseline: 87s (exit 0)
    /home/iojs/sxa/cabbage.sh: line 30: 3348676 Terminated              vmstat -t 5 > "$OUT/vmstat-$name.txt" 2>&1
    one-thread: 87s (exit 0)
    /home/iojs/sxa/cabbage.sh: line 30: 3350334 Terminated              vmstat -t 5 > "$OUT/vmstat-$name.txt" 2>&1
    single-threaded-gc: 0s (exit 0)
    /home/iojs/sxa/cabbage.sh: line 30: 3351989 Terminated              vmstat -t 5 > "$OUT/vmstat-$name.txt" 2>&1
    liftoff-only: 1s (exit 0)
    /home/iojs/sxa/cabbage.sh: line 30: 3352066 Terminated              vmstat -t 5 > "$OUT/vmstat-$name.txt" 2>&1
    bigger-semi-space: 87s (exit 0)
    /home/iojs/sxa/cabbage.sh: line 30: 3352142 Terminated              vmstat -t 5 > "$OUT/vmstat-$name.txt" 2>&1
    Done. Please share /tmp/doc-kit-diagnostics (env.txt, summary.txt, vmstat-*.txt and doc-only-*.log).
    

    Noting that the command and script above was presumably AI generated and has done things that don't appear to work and are perhaps untested e.g. --liftoff-only is not allowed in NODE_OPTIONS. Here is the tarball of the output directory: doc-kit-diagnostics.1174.tar.gz

    Hopefully those results are useful for the diagnosis :-)

  8. ovflowd commented on Oct 26, 2026

    @ovflowd
    Member

    Noting that the command and script above was presumably AI generated and has done things that don't appear to work and are perhaps untested e.g. --liftoff-only is not allowed in NODE_OPTIONS

    Yeah absolutely. I had no way to really verify if it would be useful OR not in this environment.

    Here is the tarball of the output directory: doc-kit-diagnostics.1174.tar.gz

    Thank you so much, @sxa will attempt to use this! Note that I have opened two PRs #1178 and #1179 already as an attempt to reduce even further memory usage/performance costs.

    That said if these VMs have 4GB RAM... that's plenty.

  9. ovflowd commented on Oct 26, 2026

    @ovflowd
    Member

    So here's the weird thing, based on the code on main, since the VMs had only 4GB of RAM, doc-kit was supposed to have skipped HTML generation completely... I cannot understand how it generating only the JSON pieces caused it to get stuck for 25 minutes. I never seen doc-kit, even on worst simulated environments from my previous comments (1GB RAM, 1 thread) take more than 120 seconds.

    So I'm truly unsure what could have caused the VM to hang for 25 minutes... Still analyzing what you gave me... but, just no idea lol

  10. sxa commented on Oct 26, 2026

    @sxa
    MemberAuthor

    That said if these VMs have 4GB RAM... that's plenty.

    That's good to hear. We need a reasonable amount of RAM for some of the parts of the V8 build so I was hoping doc-kit wouldn't need more than that :-)

  11. ovflowd commented on Oct 26, 2026

    @ovflowd
    Member

    That said if these VMs have 4GB RAM... that's plenty.

    That's good to hear. We need a reasonable amount of RAM for some of the parts of the V8 build so I was hoping doc-kit wouldn't need more than that :-)

    BTW @sxa (also sent a Slack message) I have the feeling the branch/tag/commit you checked out to run this doesn't seem to have been using doc-kit yet 🤔 seems an outdated v24 tag before we itnroduced doc-kit.

    Let me give you an updated script, with corrections that would help!

  12. ovflowd commented on Oct 26, 2026

    @ovflowd
    Member

    Updated Diagnosis Script (cc @sxa)

    #!/bin/bash
    # Diagnose slow `make doc-only` runs on a Node.js CI agent (nodejs/doc-kit#1174).
    #
    # Run it from a nodejs/node checkout (main, v26.x or v24.x). It runs that
    # checkout's own `make doc-only V=1`, times every command make runs, and records
    # memory, swap and CPU next to it. Each run deletes and rebuilds out/doc.
    #
    #   bash diagnose-doc-build.sh               # one run, as on CI
    #   VARIANTS=1 bash diagnose-doc-build.sh    # plus one thread and two V8 flags
    #
    # NODE  the binary that builds the docs (default: out/Release/node, else `node`)
    # JOBS  threads for doc-kit, where the Makefile passes them (default: 2, as on CI)
    # OUT   where the results go (default: /tmp/doc-kit-diagnostics)
    #
    # Tested on nodejs/node main (ba3c34a), v26.x (6466cb1) and v24.x (59e46ca), with
    # Node.js 24.18 and 26.12.
    
    set -u
    
    OUT=${OUT:-/tmp/doc-kit-diagnostics}
    JOBS=${JOBS:-2}
    NODE=${NODE:-$PWD/out/Release/node}
    [ -x "$NODE" ] || NODE=$(command -v node)
    
    if [ ! -f Makefile ] || [ ! -d doc/api ]; then
      echo "Run this from a nodejs/node checkout." >&2
      exit 1
    fi
    
    rm -rf "$OUT"
    mkdir -p "$OUT"
    
    # Make runs every command through $SHELL, so this one logs how long each took
    cat > "$OUT/timed-shell" <<'EOF'
    #!/bin/sh
    start=$(date +%s%N)
    /bin/sh "$@"
    rc=$?
    end=$(date +%s%N)
    for last; do :; done
    printf '%8.1fs rc=%s %s\n' "$(( (end - start) / 1000000 ))e-3" "$rc" \
      "$(printf '%s' "$last" | tr '\n\t' '  ' | cut -c1-400)" >> "$STEPS"
    exit $rc
    EOF
    chmod +x "$OUT/timed-shell"
    
    # A node binary that always gets the given V8 flags. They can't go through
    # NODE_OPTIONS: Node.js only allows a few V8 flags there.
    node_with() {
      local wrapper="$OUT/node-$1"
      shift
      printf '#!/bin/sh\nexec "%s" %s "$@"\n' "$NODE" "$*" > "$wrapper"
      chmod +x "$wrapper"
      echo "$wrapper"
    }
    
    {
      echo "== checkout"; git log -1 --format='%H %s' 2>/dev/null; git branch --show-current 2>/dev/null
      echo "== os"; cat /etc/redhat-release /etc/os-release 2>/dev/null | head -3; uname -r
      echo "== cpu"; nproc; lscpu | grep -E 'Model name|Hypervisor|Thread|MHz|Flags' | cut -c1-200
      echo "== memory"; free -m; swapon --show
      echo "== cgroup"; stat -fc %T /sys/fs/cgroup
      cat /sys/fs/cgroup/memory.max /sys/fs/cgroup/memory/memory.limit_in_bytes 2>/dev/null
      echo "== thp"; cat /sys/kernel/mm/transparent_hugepage/enabled /sys/kernel/mm/transparent_hugepage/defrag
      echo "== clock"; cat /sys/devices/system/clocksource/clocksource0/current_clocksource
      echo "== node ($NODE)"
      "$NODE" -p 'JSON.stringify({
        version: process.version,
        totalmem: os.totalmem(),
        availableMemory: process.availableMemory?.(),
        constrainedMemory: process.constrainedMemory?.(),
        heapLimit: v8.getHeapStatistics().heap_size_limit,
        parallelism: os.availableParallelism(),
        buildsHTML: os.totalmem() > 5 * 1024 ** 3,
      }, null, 2)'
      echo "== doc dependencies (tools/doc/package-lock.json)"
      "$NODE" -e '
        const { packages = {} } = require("./tools/doc/package-lock.json");
        for (const [path, { version }] of Object.entries(packages)) {
          if (/node_modules\/(@doc-kit\/[^/]+|@node-core\/[^/]+|@swc\/[^/]+|shiki|lightningcss|rolldown|vite)$/.test(path)) {
            console.log(path.replace(/^node_modules\//, ""), version);
          }
        }'
      echo "== limits"; ulimit -a
      echo "== env"; env | grep -E '^(NODE_|UV_|JOBS|MAKEFLAGS|TMPDIR|LD_|MALLOC|ROLLDOWN|RAYON)' || true
      echo "== load"; uptime; ps -eo pid,pcpu,pmem,etime,comm --sort=-pcpu | head -8
    } > "$OUT/env.txt" 2>&1
    
    # run <name> <node binary> [make variables...]
    run() {
      local name=$1 node=$2
      shift 2
    
      rm -rf out/doc
    
      export STEPS="$OUT/steps-$name.txt"
      : > "$STEPS"
    
      vmstat -t 5 > "$OUT/vmstat-$name.txt" 2>&1 &
      local vmstat=$!
      local start
      start=$(date +%s)
    
      make doc-only V=1 JOBS="$JOBS" NODE="$node" SHELL="$OUT/timed-shell" "$@" \
        > "$OUT/make-$name.log" 2>&1
      local rc=$?
    
      { kill "$vmstat" && wait "$vmstat"; } 2>/dev/null
    
      echo "$name: $(( $(date +%s) - start ))s (exit $rc), slowest commands:" >> "$OUT/summary.txt"
      # The Makefile's rules start with a "Skipping <target>" guard, which names them
      sort -rn "$STEPS" | head -3 \
        | sed -E 's/^( *[0-9.]+s rc=[0-9]+) .*Skipping ([^ ]+) .*/\1 \2/' | cut -c1-200 \
        >> "$OUT/summary.txt"
      echo "$name: $(( $(date +%s) - start ))s (exit $rc)"
    }
    
    # The doc dependencies are installed once, outside the timed runs
    STEPS="$OUT/steps-install.txt" make tools/doc/node_modules NODE="$NODE" \
      SHELL="$OUT/timed-shell" > "$OUT/make-install.log" 2>&1
    
    run baseline "$NODE"
    
    if [ "${VARIANTS:-0}" = 1 ]; then
      run one-thread "$NODE" JOBS=1
      run single-threaded-gc "$(node_with stgc --single-threaded-gc)"
      run semi-space-64 "$(node_with semi64 --max-semi-space-size=64)"
    fi
    
    tar czf "$OUT.tar.gz" -C "$(dirname "$OUT")" "$(basename "$OUT")"
    echo "Done. Please share $OUT.tar.gz"
  13. sxa commented on Oct 26, 2026

    @sxa
    MemberAuthor

    With the above updated script:

    baseline: 1525s (exit 0)
    one-thread: 1089s (exit 0)
    single-threaded-gc: 1600s (exit 0)
    semi-space-64: 1503s (exit 0)
    Done. Please share /tmp/doc-kit-diagnostics.tar.gz
    

    Here's the tarball: doc-kit-diagnostics.tar.gz

  14. ovflowd commented on Oct 26, 2026

    @ovflowd
    Member

    Thank you so much @sxa, that tarball nailed it!

    Turns out doc-kit isn't slow there, it runs 69 times. steps-baseline.txt shows the doc recipe running once per out/doc/api/*.html target, ~22s each (1497s of the 1525s), and the make log has legacy-json-all starting 69 times while html never runs. So that answers my "how can JSON only take 25 minutes" question 😅

    What's going on:

    • With 4GB, web.doc-kit.config.mjs skips the HTML (the > 5GB gate), so only the JSON gets written.
    • But the Makefile still lists every .html as an output of that rule, and as a prerequisite of doc-only, so they're always missing.
    • That rule is a grouped target (&:), which needs GNU make 4.3+. RHEL 8 ships make 4.2.1, which reads it as a regular rule where each file is its own target, so it reruns the whole build for every missing .html.

    That's also why it's only rhel8 (4GB and an old make), why each agent's time is so stable (69 × one JSON build on that CPU), and why I never could reproduce it locally (make 4.4 here). I reproduced the mechanism with a tiny Makefile too: with missing outputs, &: runs the recipe once, a plain : once per missing file.

    Could you double-check make --version on one of them? I'd expect 4.2.1.

    The fix is on the Makefile side: a stamp file instead of the grouped target, which runs once on any make version. I'll push that to nodejs/node#66713, which also drops the memory gate.

  15. sxa commented on Oct 27, 2026

    @sxa
    MemberAuthor

    Confirmed that RHEL8 has make 4.2.1. If the PR which has that commit doesn't get merged in the next week I would suggest we look at splitting it out into a separately landable PR.

  16. ovflowd commented on Oct 27, 2026

    @ovflowd
    Member

    Confirmed that RHEL8 has make 4.2.1. If the PR which has that commit doesn't get merged in the next week I would suggest we look at splitting it out into a separately landable PR.

    @sxa that won't be needed, as @aduh95 landed the revert commit on nodejs/node that disables the doc-kit tooling that attempts to build the redesigned docs. The issue was that since doc-kit was selectively building the redesigned docs (HTML files) based on RAM >= 5GB and other rules, the Makefile rule didn't see the change and entered in a loop. Given that with Make >= 4.3 that wouldn't happen at all, but with the current state of main this won't happen either for now

    The PR that re-introduces doc-kit to generate the new redesigned docs is open with the fix as a commit there. So now we only need to wait to bring doc-kit back to main.

  17. sxa commented on Oct 27, 2026

    @sxa
    MemberAuthor

    Ah yes thanks I see nodejs/node#67015 went in last night to revert nodejs/node#62045 which would have introduced the problem on September 16th. Happy to close this since the builds are no longer affected and we have a fix for when it is reinstated. Thanks for your work in tracking it down!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

Labels

No labels
No labels

Type

No type

Projects

No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions