build: Makefile dependency regression

[refack]

• Version: master
• Platform: non-Windows
• Subsystem: build

Several recent build jobs are failing apparently because make is miss-calculating target dependencies and tries to build the test/addons too soon (before the node binary is linked) and thus fails.
Looking for help in tracking down a possible cause.

Example failing output: https://www.irccloud.com/pastebin/raw/FWBUXcqM
https://ci.nodejs.org/job/node-test-commit-linux/nodes=fedora24/14120/consoleFull

https://github.com/nodejs/node/commits/master/Makefile:
@refack - tools,build: allow build without remark-cli - e624503
@joyeecheung - tools: don't lint files that have not changed - eebcb48
@gibfahn - build: suppress lint-md output - 60d055e
@joyeecheung - build: make test-doc and lint addon docs - 390eda1
@danbev - build: make doc target quiet - 6f684d9
@addaleax @tniessen - build: ignore empty folders in test-addons-napi - 65d2067
@joyeecheung - build: run linter before running tests - 2875459
@refack - build: improve make clean - 9ab6481
@watilde - tools: add make lint-md-clean - a399881
@watilde - build: add lint-md-build - 212f4b9
@watilde - tools: add lint-md command in Makefile - f132954
@Trott - build: use doc-only instead of doc - d6ba14e
@Trott - test: fix flaky test-make-doc - c9d5be4
@gibfahn - test: update test-npm to use test-npm-package.js - 532d8b2
@evanlucas - build: add c++ coverage support on macOS - a078584
@joyeecheung - test: test make doc and verify toc - df5dc2d
@maclover7 @refack - test: move inspector tests to parallel/sequential - 978629c
@bnoordhuis @joyeecheung - build: lint benchmark addon - 411695e
@bnoordhuis @joyeecheung - build: use local node-gyp for benchmark addon - 4157342
@refack - build: restore mistakenly dropped suites - 88d05aa
@gr2m @mhdawson - build: ignore empty folders in test-addons - 7da45f8

[joyeecheung]

Hmm..maybe we should put | in the rules of build-addons and build-addons-napi?

[joyeecheung]

Also, I think I have seen this on my mac(or my linux box) very occasionally, long before all the commits listed in the OP (if my memory serve me right, at least before 8.x came out), it's probably not a recent regression, but a low-probability race or something

[bnoordhuis]

@joyeecheung I fixed just such a dependency issue in 0ea4855. That was in May last year though, maybe too long ago?

[joyeecheung]

@bnoordhuis Yes, that could be it. From the commit message:

As an order-only prerequisite, it's sometimes skipped when it shouldn't be.

I think this probably does not happen in CI where most things start fresh...so my guess in #17043 (comment) could be wrong, this is a new regression.

[joyeecheung]

Uh, wait, no, I thought that commit landed this May, but it actually landed last May, and I am pretty sure I've seen this error this year, so back to my original guess..

[joyeecheung]

I looked into the logs again and I think this is not caused by Makefile miscalculating the dependencies and tries to build addons before linking node, because it usually errors out in the middle of the for-loop of build-addons-napi. If node is not linked properly then it should error out in the first iteration instead. I think something is removing the symlink or removing out/Release/node during the execution, this should be caused by a dependency miscalculation as well though, e.g. make tries to recompile when build-addons-napi is executing

[joyeecheung]

Maybe somewhat related: somehow the napi addons are not built but still proceeded to the JS testing phase on smart os

https://ci.nodejs.org/job/node-test-commit-smartos/nodes=smartos16-64/13133/console

See test output

not ok 1868 addons-napi/test_make_callback/test
  ---
  duration_ms: 0.430
  severity: fail
  stack: |-
    module.js:544
        throw err;
        ^
    
    Error: Cannot find module './build/Release/binding'
        at Function.Module._resolveFilename (module.js:542:15)
        at Function.Module._load (module.js:472:25)
        at Module.require (module.js:585:17)
        at require (internal/module.js:11:18)
        at Object.<anonymous> (/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos16-64/test/addons-napi/test_make_callback/test.js:7:17)
        at Module._compile (module.js:641:30)
        at Object.Module._extensions..js (module.js:652:10)
        at Module.load (module.js:560:32)
        at tryModuleLoad (module.js:503:12)
        at Function.Module._load (module.js:495:3)
  ...
not ok 1869 addons-napi/test_string/test
  ---
  duration_ms: 0.429
  severity: fail
  stack: |-
    module.js:544
        throw err;
        ^
    
    Error: Cannot find module './build/Release/test_string'
        at Function.Module._resolveFilename (module.js:542:15)
        at Function.Module._load (module.js:472:25)
        at Module.require (module.js:585:17)
        at require (internal/module.js:11:18)
        at Object.<anonymous> (/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos16-64/test/addons-napi/test_string/test.js:6:21)
        at Module._compile (module.js:641:30)
        at Object.Module._extensions..js (module.js:652:10)
        at Module.load (module.js:560:32)
        at tryModuleLoad (module.js:503:12)
        at Function.Module._load (module.js:495:3)
  ...
not ok 1870 addons-napi/test_make_callback_recurse/test
  ---
  duration_ms: 0.347
  severity: fail
  stack: |-
    module.js:544
        throw err;
        ^
    
    Error: Cannot find module './build/Release/binding'
        at Function.Module._resolveFilename (module.js:542:15)
        at Function.Module._load (module.js:472:25)
        at Module.require (module.js:585:17)
        at require (internal/module.js:11:18)
        at Object.<anonymous> (/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos16-64/test/addons-napi/test_make_callback_recurse/test.js:6:17)
        at Module._compile (module.js:641:30)
        at Object.Module._extensions..js (module.js:652:10)
        at Module.load (module.js:560:32)
        at tryModuleLoad (module.js:503:12)
        at Function.Module._load (module.js:495:3)
...

The building phase:

See build trace

Building addon /home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos16-64/test/addons-napi/6_object_wrap/

Building addon /home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos16-64/test/addons-napi/7_factory_wrap/

Building addon /home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos16-64/test/addons-napi/8_passing_wrapped/

Building addon /home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos16-64/test/addons-napi/test_array/

Building addon /home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos16-64/test/addons-napi/test_async/

Building addon /home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos16-64/test/addons-napi/test_buffer/

Building addon /home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos16-64/test/addons-napi/test_constructor/

Building addon /home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos16-64/test/addons-napi/test_conversions/

Building addon /home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos16-64/test/addons-napi/test_dataview/

Building addon /home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos16-64/test/addons-napi/test_env_sharing/

Building addon /home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos16-64/test/addons-napi/test_error/

Building addon /home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos16-64/test/addons-napi/test_exception/

Building addon /home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos16-64/test/addons-napi/test_fatal/

Building addon /home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos16-64/test/addons-napi/test_function/

Building addon /home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos16-64/test/addons-napi/test_general/

Building addon /home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos16-64/test/addons-napi/test_handle_scope/

Building addon /home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos16-64/test/addons-napi/test_make_callback/

Building addon /home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos16-64/test/addons-napi/test_make_callback_recurse/

Building addon /home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos16-64/test/addons-napi/test_number/

Building addon /home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos16-64/test/addons-napi/test_object/

Building addon /home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos16-64/test/addons-napi/test_promise/

Building addon /home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos16-64/test/addons-napi/test_properties/

Building addon /home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos16-64/test/addons-napi/test_reference/

Building addon /home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos16-64/test/addons-napi/test_string/

Building addon /home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos16-64/test/addons-napi/test_symbol/

Building addon /home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos16-64/test/addons-napi/test_typedarray/

Building addon /home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos16-64/test/addons-napi/test_warning/
touch test/addons-napi/.buildstamp
/bin/sh[1]: ./node: ./node: cannot execute [Invalid argument]
/bin/sh[1]: ./node: ./node: cannot execute [Invalid argument]
/bin/sh[1]: ./node: ./node: cannot execute [Invalid argument]

[joyeecheung]

Another one on smart OS, this time the test/addons were missing builds, but judging from the log they were built before the tests started, I think those builds were somehow deleted before the test executor went to the addon tests.

https://ci.nodejs.org/job/node-test-commit-smartos/13181/nodes=smartos15-64/console

[joyeecheung]

Looks like the race condition documented in the $(NODE_EXE) target

# The -r/-L check stops it recreating the link if it is already in place,
# otherwise $(NODE_EXE) being a .PHONY target means it is always re-run.
# Without the check there is a race condition between the link being deleted
# and recreated which can break the addons build when running test-ci

is back