test-osuosl-aix72-ppc64_be-3 build failures

[Trott]

test-osuosl-aix72-ppc64_be-3 is failing repeatedly so I marked it offline.

Refs: nodejs/node#39604 (comment)

@nodejs/platform-aix

[richardlau]

I had to clean up a bunch of leftover gmake/gcc processes on that machine on Thursday while preparing the releases. Given that https://ci.nodejs.org/job/node-test-commit-aix/37790/nodes=aix72-ppc64/ is encountering EAGAIN errors spawning processes, the likely situation is that again there are lots of leftover processes running on the system. We'd previously seen that situation on the same machine in #2621 (comment).

I won't be able to log into the machine until late Sunday night/Monday -- supposedly we have a playbook runnable from our AWX server that is able to clean up processes (https://github.com/nodejs/build/blob/master/ansible/playbooks/jenkins/worker/restart-agent.yml) but I don't actually see any templates under resources as I did before as documented in #2714 (cc @AshCripps).

[richardlau]

Looks like test-osuosl-aix72-ppc64_be-2 may be exhibiting the same problem now 😞,
e.g. https://ci.nodejs.org/job/node-test-commit-aix/nodes=aix72-ppc64/37812/console

[richardlau]

hmm. I just logged into test-osuosl-aix72-ppc64_be-3 and there are no leftover gcc/gmake processes running -- but it also looks like the Jenkins agent crashed last night and restarted (which may have caused any leftover processes to have been cleaned up):

iojs@p8-aix2-nodejs02:[/home/iojs]cat jenkins_console.log
JVMDUMP039I Processing dump event "corruptcache", detail "" at 2021/08/01 22:49:31 - please wait.
JVMDUMP032I JVM requested System dump using '/home/iojs/core.20210801.224931.6160858.0001.dmp' in response to an event
Note: "Enable full CORE dump" in smit is set to FALSE and as a result there will be limited threading information in core file.
JVMDUMP012E Error in System dump: cannot find core file: "No such file or directory". check "ulimit -Hc" is set high enough
JVMDUMP032I JVM requested Java dump using '/home/iojs/javacore.20210801.224931.6160858.0002.txt' in response to an event
JVMDUMP010I Java dump written to /home/iojs/javacore.20210801.224931.6160858.0002.txt
JVMDUMP032I JVM requested Snap dump using '/home/iojs/Snap.20210801.224931.6160858.0003.trc' in response to an event
JVMDUMP010I Snap dump written to /home/iojs/Snap.20210801.224931.6160858.0003.trc
JVMDUMP013I Processed dump event "corruptcache", detail "".
Aug 01, 2021 10:49:36 PM hudson.remoting.jnlp.Main createEngine
INFO: Setting up agent: test-osuosl-aix72-ppc64_be-3
Aug 01, 2021 10:49:36 PM hudson.remoting.jnlp.Main$CuiListener <init>
INFO: Jenkins agent is running in headless mode.
Aug 01, 2021 10:49:36 PM hudson.remoting.Engine startEngine
INFO: Using Remoting version: 4.5
Aug 01, 2021 10:49:36 PM hudson.remoting.Engine startEngine
WARNING: No Working Directory. Using the legacy JAR Cache location: /home/iojs/.jenkins/cache/jars
Aug 01, 2021 10:49:36 PM hudson.remoting.jnlp.Main$CuiListener status
INFO: Locating server among [https://ci.nodejs.org/]
Aug 01, 2021 10:49:37 PM org.jenkinsci.remoting.engine.JnlpAgentEndpointResolver resolve
INFO: Remoting server accepts the following protocols: [JNLP4-connect, Ping]
Aug 01, 2021 10:49:37 PM hudson.remoting.jnlp.Main$CuiListener status
INFO: Agent discovery successful
  Agent address: ci.nodejs.org
  Agent port:    41913
  Identity:      4f:22:06:c2:64:29:f3:3f:6d:7c:d7:01:f2:18:bb:93
Aug 01, 2021 10:49:37 PM hudson.remoting.jnlp.Main$CuiListener status
INFO: Handshaking
Aug 01, 2021 10:49:37 PM hudson.remoting.jnlp.Main$CuiListener status
INFO: Connecting to ci.nodejs.org:41913
Aug 01, 2021 10:49:37 PM hudson.remoting.jnlp.Main$CuiListener status
INFO: Trying protocol: JNLP4-connect
Aug 01, 2021 10:49:37 PM hudson.remoting.jnlp.Main$CuiListener status
INFO: Remote identity confirmed: 4f:22:06:c2:64:29:f3:3f:6d:7c:d7:01:f2:18:bb:93
Aug 01, 2021 10:49:40 PM hudson.remoting.jnlp.Main$CuiListener status
INFO: Connected
iojs@p8-aix2-nodejs02:[/home/iojs]

[richardlau]

I attempted to run the Jenkins worker playbook against test-osuosl-aix72-ppc64_be-3 to update Java -- currently we're on:

iojs@p8-aix2-nodejs02:[/home/iojs]java -version
openjdk version "1.8.0_282"
OpenJDK Runtime Environment (build 1.8.0_282-b08)
Eclipse OpenJ9 VM (build openj9-0.24.0, JRE 1.8.0 AIX ppc64-64-Bit Compressed References 20210120_953 (JIT enabled, AOT enabled)
OpenJ9   - 345e1b09e
OMR      - 741e94ea8
JCL      - ab07c6a8fd based on jdk8u282-b08)
iojs@p8-aix2-nodejs02:[/home/iojs]

while https://github.com/AdoptOpenJDK/openjdk8-binaries/releases/tag/jdk8u292-b10_openj9-0.26.0 is the latest.

Unfortunately I got an error running the playbook:

TASK [java-base : unpack adoptopenjdk binary] **************************************************************************************************************
fatal: [test-osuosl-aix72-ppc64_be-3]: FAILED! => {"changed": false, "msg": "Failed to find handler for \"/var/cache/adoptopenjdk-binaries/OpenJDK8U-jre_ppc64_aix_openj9_8u292b10_openj9-0.26.0.tar.gz\". Make sure the required command to extract the file is installed. Command \"/usr/bin/unzip\" could not handle archive. Command \"/usr/bin/tar\" detected as tar type None. GNU tar required."}

which is because Ansible has failed to find gtar and fallen back to tar. Looking at the tar package on AIX it looks like that latest version has dropped the symlinks that used to be created in /usr/bin.

Details

root@p8-aix2-nodejs03:[/root]repoquery --list tar-1.32-1 repoquery -l
/opt/freeware/bin/tar
/opt/freeware/bin/tar_32
/opt/freeware/bin/tar_64
/opt/freeware/doc/tar-1.32
/opt/freeware/doc/tar-1.32/AUTHORS
/opt/freeware/doc/tar-1.32/NEWS
/opt/freeware/doc/tar-1.32/README
/opt/freeware/doc/tar-1.32/THANKS
/opt/freeware/doc/tar-1.32/TODO
/opt/freeware/info/tar.info-1.gz
/opt/freeware/info/tar.info-2.gz
/opt/freeware/info/tar.info.gz
/opt/freeware/share/locale/bg/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/ca/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/cs/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/da/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/de/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/el/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/eo/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/es/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/et/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/eu/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/fi/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/fr/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/ga/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/gl/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/hr/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/hu/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/id/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/it/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/ja/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/ko/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/ky/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/ms/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/nb/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/nl/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/pl/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/pt/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/pt_BR/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/ro/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/ru/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/sk/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/sl/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/sr/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/sv/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/tr/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/uk/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/vi/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/zh_CN/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/zh_TW/LC_MESSAGES/tar.mo
/usr/bin/gtar
/usr/bin/gtar_32
/usr/bin/gtar_64
/usr/linux/bin/gtar
/usr/linux/bin/gtar_32
/usr/linux/bin/gtar_64
/usr/linux/bin/tar
/usr/linux/bin/tar_32
/usr/linux/bin/tar_64
root@p8-aix2-nodejs03:[/root]repoquery --list tar-1.33-1 repoquery -l
/opt/freeware/bin/tar
/opt/freeware/bin/tar_32
/opt/freeware/bin/tar_64
/opt/freeware/doc/tar-1.33
/opt/freeware/doc/tar-1.33/AUTHORS
/opt/freeware/doc/tar-1.33/NEWS
/opt/freeware/doc/tar-1.33/README
/opt/freeware/doc/tar-1.33/THANKS
/opt/freeware/doc/tar-1.33/TODO
/opt/freeware/info/tar.info-1.gz
/opt/freeware/info/tar.info-2.gz
/opt/freeware/info/tar.info.gz
/opt/freeware/share/locale/bg/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/ca/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/cs/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/da/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/de/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/el/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/eo/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/es/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/et/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/eu/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/fi/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/fr/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/ga/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/gl/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/hr/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/hu/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/id/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/it/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/ja/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/ko/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/ky/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/ms/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/nb/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/nl/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/pl/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/pt/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/pt_BR/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/ro/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/ru/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/sk/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/sl/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/sr/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/sv/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/tr/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/uk/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/vi/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/zh_CN/LC_MESSAGES/tar.mo
/opt/freeware/share/locale/zh_TW/LC_MESSAGES/tar.mo
root@p8-aix2-nodejs03:[/root]

We saw a similar issue before for curl (#2536) -- I'll open a PR to recreate the gtar symlinks on AIX so we can run the playbook (and update to the most recent Java 8).

[richardlau]

#2720 to fix the gtar issue. I've reansibled test-osuosl-aix72-ppc64_be-3, which has updated Java to

iojs@test-osuosl-aix72-ppc64_be-3:[/home/iojs]java -version
openjdk version "1.8.0_292"
OpenJDK Runtime Environment (build 1.8.0_292-b10)
Eclipse OpenJ9 VM (build openj9-0.26.0, JRE 1.8.0 AIX ppc64-64-Bit Compressed References 20210421_1023 (JIT enabled, AOT enabled)
OpenJ9   - b4cc246d9
OMR      - 162e6f729
JCL      - 2a5e268814 based on jdk8u292-b10)
iojs@test-osuosl-aix72-ppc64_be-3:[/home/iojs]

[richardlau]

Current theory is that the instability is coming from /var being full on all three hosts.
e.g. test-osuosl-aix72-ppc64_be-2:

root@test-osuosl-aix72-ppc64_be-2:[/root]df
Filesystem    512-blocks      Free %Used    Iused %Iused Mounted on
/dev/hd4         4194304   3595656   15%    11929     3% /
/dev/hd2        12582912   7984184   37%    34671     4% /usr
/dev/hd9var      2097152         0  100%     1658    66% /var
/dev/hd3         2097152   2076184    1%      241     1% /tmp
/dev/hd1       104857600  78039584   26%   308424     4% /home
/dev/hd11admin    2097152   2096144    1%        5     1% /admin
/proc                  -         -    -        -      - /proc
/dev/hd10opt    10485760   2818680   74%    40169    12% /opt
/dev/livedump    2097152   2096176    1%        4     1% /var/adm/ras/livedump
/aha                   -         -    -     1584     5% /aha
/dev/lvBESC      4194304   3460240   18%      726     1% /var/opt/BESClient
root@test-osuosl-aix72-ppc64_be-2:[/root]

root@test-osuosl-aix72-ppc64_be-2:[/var]du -s *
0       aacct
33936   adm
1920512 cache
16      cache_mgt
58792   ct
1712    ecc
0       empty
0       ha
2376    lib
8       locks
5952    log
0       lost+found
0       msgs
0       news
731232  opt
69936   perf
0       preserve
0       probevue
8       run
0       security
120     spool
168     ssl
0       state
8       statmon
8       suma
40      tmp
0       tss
8       websm
root@test-osuosl-aix72-ppc64_be-2:[/var]

Where /var/cache is some adoptopenjdk downloaded tarballs (via our Ansible scripts) and the yum cache. I've cleaned out the yum cache via yum clean all.

[richardlau]

We've had a reasonable number of green builds on -3 but also some failures. For example on test-osuosl-aix72-ppc64_be-3

https://ci.nodejs.org/job/node-test-commit-aix/nodes=aix72-ppc64/37855/ and
https://ci.nodejs.org/job/node-test-commit-aix/nodes=aix72-ppc64/37856/
both got java.io.IOException: Backing channel 'JNLP4-connect connection from p8-aix2-nodejs02.osuosl.org/140.211.9.131:56336' is disconnected. exceptions -- when this happens it looks like the gcc/gmake processes are still left running on the machine.

[richardlau]

There was a suggestion to wipe out the agent jar and reinstall it -- I've done so (delete, rerun the Jenkins worker create playbook and the restart agent playbook) but we've already got the Java exceptions 😞.

[richardlau]

There was a suggestion to wipe out the agent jar and reinstall it -- I've done so (delete, rerun the Jenkins worker create playbook and the restart agent playbook) but we've already got the Java exceptions 😞.

And since those exceptions we've had ten straight green builds (with 3 green test 16.5.0 builds immediately before that) across all three AIX 7.2 CI hosts without me changing anything on them 🤷 .

[richardlau]

nio disconnection in https://ci.nodejs.org/job/node-test-commit-aix/nodes=aix72-ppc64/37887/console on -2 😞 .

[richardlau]

We appear to have had nio disconnects as far back as over a month ago, e.g. https://ci.nodejs.org/job/node-test-commit-aix/nodes=aix72-ppc64/37311/ (1 month 7 days ago on -3). Not sure about earlier than that as we don't have the Jenkins logs for the earlier failed builds.

It does feel like the disconnects have become more frequent recently.