#1108810 nodejs: FTBFS randomly: autobuilder hangs

Package:
src:nodejs
Source:
src:nodejs
Submitter:
Santiago Vila
Date:
2025-12-07 20:23:04 UTC
Severity:
normal
Tags:
#1108810#5
Date:
2025-07-05 10:59:10 UTC
From:
To:
Dear maintainer:

During a rebuild of all packages in unstable, your package failed to build:
--------------------------------------------------------------------------------
[...]
 debian/rules clean
dh clean
   dh_auto_clean
	make -j2 distclean
make[1]: Entering directory '/<<PKGBUILDDIR>>'
rm -f -r out
rm -f config.gypi icu_config.gypi
rm -f config.mk
rm -f -r node node_g
rm -f -r node_modules
rm -f -r deps/icu
rm -f -r deps/icu4c*.tgz deps/icu4c*.zip deps/icu-tmp
rm -f node-v20.19.2-linux-x64.tar.* node-v20.19.2.tar.*
make[1]: Leaving directory '/<<PKGBUILDDIR>>'

[... snipped ...]

  duration_ms: 134.88000
  ...
ok 3462 sequential/test-child-process-emfile
  ---
  duration_ms: 261.53000
  ...
ok 3463 sequential/test-child-process-execsync
  ---
  duration_ms: 1007.65400
  ...
ok 3464 sequential/test-child-process-exit
  ---
  duration_ms: 807.32500
  ...
ok 3465 sequential/test-child-process-pass-fd
  ---
  duration_ms: 5071.90400
  ...
ok 3466 sequential/test-cli-syntax-bad
  ---
  duration_ms: 610.40800
  ...
ok 3467 sequential/test-cli-syntax-file-not-found
  ---
  duration_ms: 411.66700
  ...
ok 3468 sequential/test-cli-syntax-good
  ---
  duration_ms: 717.43300
  ...
ok 3469 sequential/test-cli-syntax-require
  ---
  duration_ms: 610.42100
  ...
ok 3470 sequential/test-cluster-inspect-brk
  ---
  duration_ms: 209.63100
  ...
ok 3471 sequential/test-cluster-net-listen-ipv6only-none
  ---
  duration_ms: 412.92300
  ...
ok 3472 sequential/test-cluster-net-listen-ipv6only-rr
  ---
  duration_ms: 408.84100
  ...
ok 3473 sequential/test-cluster-send-handle-large-payload
  ---
  duration_ms: 326.08100
  ...
ok 3474 sequential/test-cpu-prof-default
  ---
  duration_ms: 1308.33900
  ...
ok 3475 sequential/test-cpu-prof-dir-and-name
  ---
  duration_ms: 1307.36300
  ...
ok 3476 sequential/test-cpu-prof-dir-relative
  ---
  duration_ms: 1309.98700
  ...
ok 3477 sequential/test-cpu-prof-dir-worker # TODO : Fix flaky test
  ---
  duration_ms: 1507.77000
  ...
ok 3478 sequential/test-cpu-prof-drained
  ---
  duration_ms: 1307.76800
  ...
ok 3479 sequential/test-cpu-prof-exit
  ---
  duration_ms: 406.98900
  ...
ok 3480 sequential/test-cpu-prof-invalid-options
  ---
  duration_ms: 261.33200
  ...
ok 3481 sequential/test-cpu-prof-kill
  ---
  duration_ms: 406.97100
  ...
ok 3482 sequential/test-cpu-prof-name
  ---
  duration_ms: 1307.27800
  ...
ok 3483 sequential/test-cpu-prof-worker-argv
  ---
  duration_ms: 1407.64600
  ...
ok 3484 sequential/test-crypto-timing-safe-equal
  ---
  duration_ms: 134.94100
  ...
ok 3485 sequential/test-debug-prompt
  ---
  duration_ms: 609.57200
  ...
ok 3486 sequential/test-debugger-custom-port
  ---
  duration_ms: 707.24200
  ...
ok 3487 sequential/test-debugger-debug-brk
  ---
  duration_ms: 209.56400
  ...
ok 3488 sequential/test-debugger-invalid-args
  ---
  duration_ms: 5415.17500
  ...
ok 3489 sequential/test-debugger-launch
  ---
  duration_ms: 707.14700
  ...
ok 3490 sequential/test-debugger-pid
  ---
  duration_ms: 507.02900
  ...
ok 3491 sequential/test-deprecation-flags
  ---
  duration_ms: 514.89100
  ...
ok 3492 sequential/test-dgram-bind-shared-ports
  ---
  duration_ms: 409.66400
  ...
ok 3493 sequential/test-dgram-implicit-bind-failure
  ---
  duration_ms: 134.92500
  ...
ok 3494 sequential/test-dgram-pingpong
  ---
  duration_ms: 167.96300
  ...
ok 3495 sequential/test-diagnostic-dir-cpu-prof
  ---
  duration_ms: 2408.13700
  ...
ok 3496 sequential/test-diagnostic-dir-heap-prof
  ---
  duration_ms: 1808.32800
  ...
ok 3497 sequential/test-fs-opendir-recursive
  ---
  duration_ms: 209.86200
  ...
ok 3498 sequential/test-fs-readdir-recursive
  ---
  duration_ms: 209.55700
  ...
ok 3499 sequential/test-fs-stat-sync-overflow
  ---
  duration_ms: 326.01600
  ...
ok 3500 sequential/test-fs-watch # TODO : Fix flaky test
  ---
  duration_ms: 134.91800
  ...
ok 3501 sequential/test-gc-http-client
  ---
  duration_ms: 209.89300
  ...
ok 3502 sequential/test-gc-http-client-onerror
  ---
  duration_ms: 209.59300
  ...
ok 3503 sequential/test-gc-http-client-timeout
  ---
  duration_ms: 609.66200
  ...
ok 3504 sequential/test-get-heapsnapshot-options
  ---
  duration_ms: 1723.16600
  ...
ok 3505 sequential/test-heapdump
  ---
  duration_ms: 908.88200
  ...
ok 3506 sequential/test-heapdump-flag
  ---
  duration_ms: 807.53600
  ...
ok 3507 sequential/test-heapdump-flag-custom-dir
  ---
  duration_ms: 808.58200
  ...
ok 3508 sequential/test-http-econnrefused
  ---
  duration_ms: 168.01400
  ...
ok 3509 sequential/test-http-keep-alive-large-write
  ---
  duration_ms: 168.05500
  ...
ok 3510 sequential/test-http-keepalive-maxsockets
  ---
  duration_ms: 507.15900
  ...
ok 3511 sequential/test-http-regr-gh-2928
  ---
  duration_ms: 168.05500
  ...
ok 3512 sequential/test-http-server-keep-alive-timeout-slow-client-headers
  ---
  duration_ms: 3409.58200
  ...
ok 3513 sequential/test-http-server-keep-alive-timeout-slow-server
  ---
  duration_ms: 1807.97200
  ...
ok 3514 sequential/test-http-server-request-timeouts-mixed # TODO : Fix flaky test
  ---
  duration_ms: 19021.97500
  ...
ok 3515 sequential/test-http2-large-file # TODO : Fix flaky test
  ---
  duration_ms: 326.49000
  ...
ok 3516 sequential/test-http2-max-session-memory
  ---
  duration_ms: 168.14000
  ...
ok 3517 sequential/test-http2-ping-flood
  ---
  duration_ms: 213.34200
  ...
ok 3518 sequential/test-http2-settings-flood
  ---
  duration_ms: 212.19200
  ...
ok 3519 sequential/test-http2-timeout-large-write
  ---
  duration_ms: 8113.28300
  ...
ok 3520 sequential/test-http2-timeout-large-write-file
  ---
  duration_ms: 8113.78900
  ...
ok 3521 sequential/test-https-connect-localport
  ---
  duration_ms: 6312.04500
  ...
ok 3522 sequential/test-https-server-keep-alive-timeout
  ---
  duration_ms: 2909.29100
  ...
ok 3523 sequential/test-init
  ---
  duration_ms: 414.96300
  ...
ok 3524 sequential/test-inspector-open-dispose
  ---
  duration_ms: 326.82200
  ...
ok 3525 sequential/test-inspector-port-cluster
  ---
  duration_ms: 2858.72600
  ...
ok 3526 sequential/test-module-loading
  ---
  duration_ms: 209.51600
  ...
ok 3527 sequential/test-net-GH-5504
  ---
  duration_ms: 407.08600
  ...
ok 3528 sequential/test-net-better-error-messages-port
  ---
  duration_ms: 134.81200
  ...
ok 3529 sequential/test-net-connect-econnrefused
  ---
  duration_ms: 261.35500
  ...
ok 3530 sequential/test-net-connect-handle-econnrefused
  ---
  duration_ms: 168.45600
  ...
ok 3531 sequential/test-net-connect-local-error
  ---
  duration_ms: 168.00900
  ...
ok 3532 sequential/test-net-listen-shared-ports
  ---
  duration_ms: 407.41000
  ...
ok 3533 sequential/test-net-localport
  ---
  duration_ms: 134.94100
  ...
ok 3534 sequential/test-net-reconnect-error
  ---
  duration_ms: 168.13800
  ...
ok 3535 sequential/test-net-response-size
  ---
  duration_ms: 1407.71600
  ...
ok 3536 sequential/test-net-server-address
  ---
  duration_ms: 134.93400
  ...
ok 3537 sequential/test-net-server-bind
  ---
  duration_ms: 261.20300
  ...
ok 3538 sequential/test-next-tick-error-spin
  ---
  duration_ms: 261.34400
  ...
ok 3539 sequential/test-perf-hooks
  ---
  duration_ms: 1207.61200
  ...
ok 3540 sequential/test-pipe
  ---
  duration_ms: 4411.11600
  ...
ok 3541 sequential/test-process-title
  ---
  duration_ms: 262.18200
  ...
ok 3542 sequential/test-process-warnings
  ---
  duration_ms: 328.35200
  ...
ok 3543 sequential/test-repl-timeout-throw
  ---
  duration_ms: 407.34900
  ...
ok 3544 sequential/test-require-cache-without-stat
  ---
  duration_ms: 169.19100
  ...
ok 3545 sequential/test-resolution-inspect-brk
  ---
  duration_ms: 209.58900
  ...
ok 3546 sequential/test-runner-run-inspect
  ---
  duration_ms: 3511.56400
  ...
ok 3547 sequential/test-single-executable-application # skip Running the resultant binary fails with `/home/iojs/node-tmp/.tmp.2366/sea: error while loading shared libraries: libnode.so.112: cannot open shared object file: No such file or directory`.
  ---
  duration_ms: 134.94500
  ...
ok 3548 sequential/test-single-executable-application-assets # skip Running the resultant binary fails with `/home/iojs/node-tmp/.tmp.2366/sea: error while loading shared libraries: libnode.so.112: cannot open shared object file: No such file or directory`.
  ---
  duration_ms: 134.91000
  ...
ok 3549 sequential/test-single-executable-application-assets-raw # skip Running the resultant binary fails with `/home/iojs/node-tmp/.tmp.2366/sea: error while loading shared libraries: libnode.so.112: cannot open shared object file: No such file or directory`.
  ---
  duration_ms: 134.99800
  ...
ok 3550 sequential/test-single-executable-application-disable-experimental-sea-warning # skip Running the resultant binary fails with `/home/iojs/node-tmp/.tmp.2366/sea: error while loading shared libraries: libnode.so.112: cannot open shared object file: No such file or directory`.
  ---
  duration_ms: 134.83900
  ...
ok 3551 sequential/test-single-executable-application-empty # skip Running the resultant binary fails with `/home/iojs/node-tmp/.tmp.2366/sea: error while loading shared libraries: libnode.so.112: cannot open shared object file: No such file or directory`.
  ---
  duration_ms: 134.86100
  ...
ok 3552 sequential/test-single-executable-application-snapshot # skip Running the resultant binary fails with `/home/iojs/node-tmp/.tmp.2366/sea: error while loading shared libraries: libnode.so.112: cannot open shared object file: No such file or directory`.
  ---
  duration_ms: 134.84100
  ...
ok 3553 sequential/test-single-executable-application-snapshot-and-code-cache # skip Running the resultant binary fails with `/home/iojs/node-tmp/.tmp.2366/sea: error while loading shared libraries: libnode.so.112: cannot open shared object file: No such file or directory`.
  ---
  duration_ms: 134.88300
  ...
ok 3554 sequential/test-single-executable-application-snapshot-worker # skip Running the resultant binary fails with `/home/iojs/node-tmp/.tmp.2366/sea: error while loading shared libraries: libnode.so.112: cannot open shared object file: No such file or directory`.
  ---
  duration_ms: 134.86300
  ...
ok 3555 sequential/test-single-executable-application-use-code-cache # skip Running the resultant binary fails with `/home/iojs/node-tmp/.tmp.2366/sea: error while loading shared libraries: libnode.so.112: cannot open shared object file: No such file or directory`.
  ---
  duration_ms: 134.90300
  ...
ok 3556 sequential/test-stream2-fs
  ---
  duration_ms: 168.06200
  ...
ok 3557 sequential/test-stream2-stderr-sync
  ---
  duration_ms: 515.13100
  ...
ok 3558 sequential/test-timers-block-eventloop
  ---
  duration_ms: 168.04100
  ...
ok 3559 sequential/test-timers-set-interval-excludes-callback-duration
  ---
  duration_ms: 506.98900
  ...
ok 3560 sequential/test-tls-connect
  ---
  duration_ms: 168.51200
  ...
ok 3561 sequential/test-tls-lookup
  ---
  duration_ms: 168.07200
  ...
ok 3562 sequential/test-tls-psk-client # TODO : Fix flaky test
  ---
  duration_ms: 209.57200
  ...
ok 3563 sequential/test-tls-securepair-client # TODO : Fix flaky test
  ---
  duration_ms: 1307.64300
  ...
not ok 3564 sequential/test-tls-session-timeout # TODO : Fix flaky test
  ---
  duration_ms: 209.63500
  severity: flaky
  exitcode: 1
  stack: |-
    node:assert:90
      throw new AssertionError(obj);
      ^

    AssertionError [ERR_ASSERTION]: Expected values to be strictly equal:
    + actual - expected

    + 'New'
    - 'Reused'
        at /<<PKGBUILDDIR>>/test/sequential/test-tls-session-timeout.js:146:16
        at ChildProcess.<anonymous> (/<<PKGBUILDDIR>>/test/sequential/test-tls-session-timeout.js:130:7)
        at ChildProcess.emit (node:events:524:28)
        at ChildProcess._handle.onexit (node:internal/child_process:293:12) {
      generatedMessage: true,
      code: 'ERR_ASSERTION',
      actual: 'New',
      expected: 'Reused',
      operator: 'strictEqual'
    }

    Node.js v20.19.2
  ...
ok 3565 sequential/test-util-debug
  ---
  duration_ms: 2435.10800
  ...
ok 3566 sequential/test-vm-break-on-sigint
  ---
  duration_ms: 519.39100
  ...
ok 3567 sequential/test-vm-timeout-escape-promise-module-2
  ---
  duration_ms: 167.92900
  ...
ok 3568 sequential/test-vm-timeout-rethrow
  ---
  duration_ms: 261.18800
  ...
ok 3569 sequential/test-worker-eventlooputil
  ---
  duration_ms: 325.96000
  ...
ok 3570 sequential/test-worker-fshandles-error-on-termination
  ---
  duration_ms: 1115.90500
  ...
ok 3571 sequential/test-worker-fshandles-open-close-on-termination
  ---
  duration_ms: 1019.83800
  ...
ok 3572 sequential/test-worker-heapsnapshot-options # TODO : Fix flaky test
  ---
  duration_ms: 910.17200
  ...
ok 3573 sequential/test-worker-prof
  ---
  duration_ms: 1511.67200
  ...
ok 3574 sequential/test-write-heapsnapshot-options
  ---
  duration_ms: 1713.34700
  ...
E: Build killed with signal TERM after 60 minutes of inactivity
--------------------------------------------------------------------------------

The above is just how the build ends and not necessarily the most relevant part.
I've put several full build logs here:

https://people.debian.org/~sanvila/build-logs/202507/

About the archive rebuild: The build was made on virtual machines from AWS,
using sbuild and a reduced chroot with only build-essential packages.

Note: The build might not always fail (hence the "randomly" in the title),
but I'm getting a high failure rate (around 36% here). However, I have not
built the current version (20.19.2+dfsg-1) enough times to get a significant
failure rate statistics but it might easily be above the usual thresholds
used by the RT. If you could not reproduce these random failures please
contact me privately, as I am willing to provide ssh access to a virtual
machine where they happen.

If this is really a bug in one of the build-depends, please use
reassign and add an affects on src:nodejs, so that this is still
visible in the BTS web page for this package.

Thanks.

#1108810#10
Date:
2025-07-21 17:25:33 UTC
From:
To:
Le sam. 5 juil. 2025 à 13:01, Santiago Vila <sanvila@debian.org> a écrit :


Oddly, I can't reproduce (tried six times today).

In any case, there is a mistake in debian/rules,
--timeout=6000
should be
--timeout=1000
to make sure tests have enough time on riscv64 but don't go above 60
minutes which triggers a failure.

#1108810#17
Date:
2025-12-05 21:35:19 UTC
From:
To:
Is this still happening with forky/sid ?
#1108810#22
Date:
2025-12-06 11:36:35 UTC
From:
To:
No, the random failures are not happening with version
22.21.1+dfsg+~cs22.19.0-5 (tried a lot of times in my setup this night
to be sure).

But they still happen in stable. What can we do about it?

Thanks.

#1108810#27
Date:
2025-12-07 18:49:11 UTC
From:
To:
Hi,
a regression for glibc) that has this:
1232s not ok 3789
sequential/test-http-server-keep-alive-timeout-slow-client-headers #
TODO : Fix flaky test

Maybe it would be best to mark all flaky tests as flaky, such that they
don't cause the whole autopkgtest to fail. If that's not possible in the
framework in use, maybe better don't run those tests in the autopkgtest.

Paul

[1] https://ci.debian.net/packages/n/nodejs/testing/ppc64el/66892056/

#1108810#32
Date:
2025-12-07 20:07:30 UTC
From:
To:
Le dim. 7 déc. 2025 à 19:51, Paul Gevers <elbrus@debian.org> a écrit :
the tests with
"not ok"  TODO: Fix flaky test
won't be accounted for.

#1108810#37
Date:
2025-12-07 20:13:20 UTC
From:
To:
Hi,


Hmm, ok. So it only failed on the following?
443s not ok 1372 parallel/test-http-keep-alive-empty-line

Paul

#1108810#42
Date:
2025-12-07 20:20:31 UTC
From:
To:
Le dim. 7 déc. 2025 à 21:15, Paul Gevers <elbrus@debian.org> a écrit :

Yes

That test should be marked as flaky, the parameters don't take into account
the possibility of the environment being slow.