metarhia/jstp

test: investigate intermittent resendable-call-from-client failures

aqrln opened this issue · 3 comments

aqrln commented

Possibly bug or just a flaky test:

not ok 30 - test/node/resendable-call-from-client.js # time=241094.551ms
  ---
  timeout: 240000
  file: test/node/resendable-call-from-client.js
  command: /home/travis/.nvm/versions/node/v6.14.3/bin/node
  args:
    - test/node/resendable-call-from-client.js
  stdio:
    - 0
    - pipe
    - 2
  cwd: /home/travis/build/metarhia/jstp
  ...
{
    ok 1 - must connect without errors
    not ok 2 - timeout!
      ---
      signal: SIGTERM
      handles:
        - type: ChildProcess
          events:
            - internalMessage
            - message
        - type: Pipe
        - type: Socket
          events:
            - end
            - finish
            - _socketEnd
            - data
            - error
            - close
      expired: TAP
      stack: |
        emit (node_modules/nyc/node_modules/signal-exit/index.js:77:11)
        process.listener (node_modules/nyc/node_modules/signal-exit/index.js:91:7)
        processEmit (node_modules/nyc/node_modules/signal-exit/index.js:155:32)
        processEmit (node_modules/signal-exit/index.js:155:32)
      test: TAP
      ...
    
    1..2
    # failed 1 of 2 tests
    # time=185627.749ms
    
    not ok 3 - timeout!
      ---
      expired: test/node/resendable-call-from-client.js
      ...
}

Evidence: https://travis-ci.org/metarhia/jstp/jobs/413136428

Upon further investigation it look like actual error is:

test/node/resendable-call-from-client.js ....events.js:160
      throw er; // Unhandled 'error' event
      ^

Error: channel closed
    at process.target.send (internal/child_process.js:554:16)
    at Object.set (/Users/metarhia/Project/jstp/test/utils/resendable-call/server.js:23:13)
    at Connection.connection.once (/Users/metarhia/Project/jstp/lib/server.js:217:34)
    at Connection.g (events.js:292:16)
    at emitOne (events.js:96:13)
    at Connection.emit (events.js:188:7)
    at Connection._onSocketClose (/Users/metarhia/Project/jstp/lib/connection.js:473:10)
    at emitOne (events.js:96:13)
    at Transport.emit (events.js:188:7)
    at Socket.from.on (/Users/metarhia/Project/jstp/lib/common.js:13:8)

It appears that #363 didn't fix the problem.

Current problem is that the test doesn't always finish before timeout.