test: intermittent failure running add-on tests on AIX

[mhdawson]

• Version: master
• Platform: AIX
• Subsystem: addons

Looks like the AIX jobs are failing intermittently due to a problem compiling add-ons.

It looks to me like the problem is that the step of creating the exp file has not completed before the add-on tests start to run.

For example in a failing run: https://ci.nodejs.org/job/node-test-commit-aix/nodes=aix61-ppc64/429/consoleFull

I see

 SOLINK_MODULE(target) Release/obj.target/addon.node
  LD_LIBRARY_PATH=/home/iojs/build/workspace/node-test-commit-aix/nodes/aix61-ppc64/out/Release/lib.host:/home/iojs/build/workspace/node-test-commit-aix/nodes/aix61-ppc64/out/Release/lib.target:$LD_LIBRARY_PATH; export LD_LIBRARY_PATH; cd ../.; mkdir -p /home/iojs/build/workspace/node-test-commit-aix/nodes/aix61-ppc64/out/Release; sh tools/create_expfile.sh "/home/iojs/build/workspace/node-test-commit-aix/nodes/aix61-ppc64/out/Release/obj.target" "/home/iojs/build/workspace/node-test-commit-aix/nodes/aix61-ppc64/out/Release/node.exp"
Searching /home/iojs/build/workspace/node-test-commit-aix/nodes/aix61-ppc64/out/Release/obj.target to write out expfile to /home/iojs/build/workspace/node-test-commit-aix/nodes/aix61-ppc64/out/Release/node.exp
ld: 0711-317 ERROR: Undefined symbol: .v8::String::NewFromUtf8(v8::Isolate*, char const*, v8::String::NewStringType, int)
ld: 0711-317 ERROR: Undefined symbol: .v8::Function::Call(v8::Local<v8::Value>, int, v8::Local<v8::Value>*)
ld: 0711-317 ERROR: Undefined symbol: .v8::Isolate::GetCurrent()
ld: 0711-317 ERROR: Undefined symbol: .v8::HandleScope::HandleScope(v8::Isolate*)
ld: 0711-317 ERROR: Undefined symbol: .v8::FunctionTemplate::New(v8::Isolate*, void (*)(v8::FunctionCallbackInfo<v8::Value> const&), v8::Local<v8::Value>, v8::Local<v8::Signature>, int)
ld: 0711-317 ERROR: Undefined symbol: .v8::FunctionTemplate::GetFunction()
ld: 0711-317 ERROR: Undefined symbol: .v8::Function::SetName(v8::Local<v8::String>)
ld: 0711-317 ERROR: Undefined symbol: .v8::Object::Set(v8::Local<v8::Value>, v8::Local<v8::Value>)
ld: 0711-317 ERROR: Undefined symbol: .v8::HandleScope::~HandleScope()
ld: 0711-317 ERROR: Undefined symbol: .node_module_register
ld: 0711-345 Use the -bloadmap or -bnoquiet option to obtain more information.
collect2: error: ld returned 8 exit status
gmake[2]: *** [Release/obj.target/addon.node] Error 1

Were as in a successful run I see the line:

Searching /home/iojs/build/workspace/node-test-commit-aix/nodes/aix61-ppc64/out/Release/obj.target to write out expfile to /home/iojs/build/workspace/node-test-commit-aix/nodes/aix61-ppc64/out/Release/node.exp

before the add-on tests start to run. For example:

https://ci.nodejs.org/job/node-test-commit-aix/nodes=aix61-ppc64/431/consoleFull

[mhdawson]

The target for AIX is what triggers the building of the exp file but don't see why tests would start before it was complete

'targets': [
        {
          'target_name': 'node',
          'type': 'executable',
          'dependencies': ['<(node_core_target_name)', 'node_exp'],

          'include_dirs': [
            'src',
            'deps/v8/include',
          ],

          'sources': [
            'src/node_main.cc',
            '<@(library_files)',
            # node.gyp is added to the project by default.
            'common.gypi',
          ],

          'ldflags': ['-Wl,-bbigtoc,-bE:<(PRODUCT_DIR)/node.exp'],
        },
        {
          'target_name': 'node_exp',
          'type': 'none',
          'dependencies': [
            '<(node_core_target_name)',
          ],
          'actions': [
            {
              'action_name': 'expfile',
              'inputs': [
                '<(OBJ_DIR)'
              ],
              'outputs': [
                '<(PRODUCT_DIR)/node.exp'
              ],
              'action': [
                'sh', 'tools/create_expfile.sh',
                      '<@(_inputs)', '<@(_outputs)'
              ],
            }
          ]
        }

[richardlau]

https://ci.nodejs.org/job/node-test-commit-aix/nodes=aix61-ppc64/429/consoleFull has two occurrences of

Searching /home/iojs/build/workspace/node-test-commit-aix/nodes/aix61-ppc64/out/Release/obj.target to write out expfile to /home/iojs/build/workspace/node-test-commit-aix/nodes/aix61-ppc64/out/Release/node.exp

which suggests the node_exp target is being run twice.

[mhdawson]

@bnoordhuis any chance you are familiar enough with gyp to see if my thought that its a dependency problem makes sense and what it might be ?

[bnoordhuis]

Does adding 'process_outputs_as_sources': 1 to the node_exp target help? I suspect the problem is that gyp can't divine it should wait for the target to finish before moving on to the link phase.

[mhdawson]

Thanks @bnoordhuis I'll give that a try.

[mhdawson]

Did 6 runs with that change and the add-on tests all ran ok in those cases.

PR with the fix: #8272

[mhdawson]

Reopening to investigate as I think I'm still seeing failures in the builds despite having gotten 6 successes in a row when testing it out.

[mhdawson]

Since it still seems to be occurring, I've temporarily pulled it out of node-test-commit. Guess I was just really unlucky that those 6 runs passed earlier.

[mhdawson]

Looks like there is something special going on with respect to dependencies for the addon tests.

# .buildstamp and .docbuildstamp need $(NODE_EXE) but cannot depend on it
# directly because it calls make recursively.  The parent make cannot know
# if the subprocess touched anything so it pessimistically assumes that
# .buildstamp and .docbuildstamp are out of date and need a rebuild.
# Just goes to show that recursive make really is harmful...
# TODO(bnoordhuis) Force rebuild after gyp update.
build-addons: $(NODE_EXE) test/addons/.buildstamp

Now need to see if this is the root cause of the problem.

[mhdawson]

Testing out change in this branch https://github.com/mhdawson/io.js/tree/aixaddon2

[mhdawson]

Ok so far promising, launching 10 runs on that branch to see how it goes

Also broader run to validate on other platforms: https://ci.nodejs.org/job/node-test-commit/4784/

[mhdawson]

Ok another PR which I believe fixes it #8285

[mhdawson]

Believe this is fixed now. AIX is back in since yesterday and I don't see any failures. I'll keep an eye on it for the next few days but closing this issue.