smartOS builds are taking more than 6 hours

[anonrig]

Hi,

smartOS builds are taking more than 3.5 hours at the moment, and blocking landing URLPattern PR (nodejs/node#56452)

3.5 hours: https://ci.nodejs.org/job/node-test-commit-smartos/58956/nodes=smartos22-x64/console
6 hours: https://ci.nodejs.org/job/node-test-commit-smartos/58762/
7 hours and 41 minutes: https://ci.nodejs.org/job/node-test-commit-smartos/58760/

cc @jasnell @mcollina @nodejs/platform-smartos @nodejs/tsc @nodejs/build

[bahamat]

When @ryanaslett and I were setting up these new instances, we noticed that total build time was significantly affected by caching. When the cache empty or invalidated the builds would take significantly longer (around 3+h). Builds with valid cache will take about 30-40m (IIRC).

I don’t really understand what the caching situation is, Ryan may be able to share more details. But to my knowledge this isn’t an OS controlled behavior.

If someone who is more familiar with the build system and the caching model is available and up to it, we can try to help debug this live to figure out what’s going on.

[targos]

Merging nodejs/node#55014 completely invalidated the cache.

[anonrig]

There are even cases where it takes 6 hours: https://ci.nodejs.org/job/node-test-commit-smartos/58762/

[anonrig]

When the cache empty or invalidated the builds would take significantly longer (around 3+h). Builds with valid cache will take about 30-40m (IIRC).

There are examples where the builds take 6 hours. Even with or without ccache, I think there is something wrong.

[bahamat]

Do you have a specific build log where it took 6h with a known valid cache that I could look at? I would definitely want to start by looking at that log before attempting to replicate it.

[targos]

@anonrig The number on the top-right of these pages includes the time that the job was waiting for available machines. The jobs themselves (https://ci.nodejs.org/job/node-test-commit-smartos/58762/nodes=smartos22-x64/ and https://ci.nodejs.org/job/node-test-commit-smartos/58762/nodes=smartos23-x64/) didn't take that long.

[bahamat]

Merging nodejs/node#55014 completely invalidated the cache.

This is useful information, and is definitely a significant contributor to what’s going on.

How does this cache affect other builds?

[anonrig]

Do you have a specific build log where it took 6h with a known valid cache that I could look at? I would definitely want to start by looking at that log before attempting to replicate it.

The closest I can find right now is URLPattern PR. It is still building for almost 4 hours and didn't start running the tests...

[targos]

But I agree that more than 4 hours to build without cache doesn't seem reasonable. Are those executors on particularly old or undersized hardware?

[anonrig]

@anonrig The number on the top-right of these pages includes the time that the job was waiting for available machines. The jobs themselves (https://ci.nodejs.org/job/node-test-commit-smartos/58762/nodes=smartos22-x64/ and https://ci.nodejs.org/job/node-test-commit-smartos/58762/nodes=smartos23-x64/) didn't take that long.

Yes but that shows that our smartOS machine count is not sufficient enough to handle our CI run which impacts the PR time to land. URLPattern PR shares an example where it takes more than 4 hours...

[bahamat]

But I agree that more than 4 hours to build without cache doesn't seem reasonable. Are those executors on particularly old or undersized hardware?

They have 8GB of RAM and 4 CPUs. If it needs to be increased, I can do that.

[bahamat]

Yes but that shows that our smartOS machine count is not sufficient enough to handle our CI run which impacts the PR time to land. URLPattern PR shares an example where it takes more than 4 hours...

How many runners do you suggest? We can create more.

[targos]

https://ci.nodejs.org/view/All/job/node-test-commit-smartos/nodes=smartos22-x64/58957/consoleFull

14:53:31 + ./configure
14:53:32 Node.js configure: Found Python 3.11.1...
14:53:34 INFO: configure completed successfully
14:53:34 + make run-ci -j 1
14:53:34 + JOBS=4
14:53:34 + NODE_TEST_DIR=/home/iojs/node-tmp
14:53:34 + NODE_COMMON_PORT=15000
14:53:34 + FLAKY_TESTS=dontcare
14:53:34 + TEST_CI_ARGS='-t 300'
14:53:34 /opt/local/bin/python3.11 ./configure --verbose 
14:53:34 Node.js configure: Found Python 3.11.1...
14:53:34 Detected C++ compiler (CXX=ccache g++) version: 12.2.0
14:53:34 Detected C compiler (CC=ccache gcc) version: 12.2.0

It looks like only one CPU is used??? I don't know which will take precedence between -j 1 and JOBS=4

Also, it seems that ./configure is called once for nothing before make run-ci (which calls it again)

[targos]

https://ci.nodejs.org/view/All/job/node-test-commit-smartos/configure contains:

#/bin/bash -xe

curl https://raw.githubusercontent.com/nodejs/build/main/jenkins/scripts/node-test-commit-pre.sh | bash -ex -s before

export CCACHE_BASEDIR=$(pwd)
export CC="ccache gcc"
export CXX="ccache g++"
# Need to add this to ENV var to make behaviors match between smart os platforms: See: https://github.com/nodejs/build/issues/3731#issuecomment-2546193074
export CXXFLAGS="${CXXFLAGS} -fno-zero-initialized-in-bss"
curl -sLO https://raw.githubusercontent.com/nodejs/build/main/jenkins/scripts/select-compiler.sh
. ./select-compiler.sh
# configure will pick the correct version of Python to use on all currently supported Node.js versions. 
# Starting from SmartOS 20 the unversioned `python` is Python 3 which doesn't work with Node.js 12.
./configure
JOBS=4 NODE_TEST_DIR=${HOME}/node-tmp NODE_COMMON_PORT=15000 FLAKY_TESTS=dontcare TEST_CI_ARGS="-t 300" make run-ci -j $JOBS

curl https://raw.githubusercontent.com/nodejs/build/main/jenkins/scripts/node-test-commit-diagnostics.sh | bash -ex -s after