Mock Server Startup API fails

[fernanfs]

Software versions

This has been tested on Windows as well as on macOS

General Library Versions

• @pact-foundation/pact-node: 10.13.1
• @pact-foundation/pact-core: 11.1.0
• deasync: 0.1.22

Windows

• OS: Windows 10
• Node Version: v14.17.4

macOS

• OS: macOS 11.4
• Node Version: v16.6.1

Issue Checklist

Please confirm the following:

• I have upgraded to the latest
• I have the read the FAQs in the Readme
• I have triple checked, that there are no unhandled promises in my code
• I have set my log level to debug and attached a log file showing the complete request/response cycle
• For bonus points and virtual high fives, I have created a reproduceable git repository (see below) to illustrate the problem

Description

During the evaluation of karma-pact (keep reading, it is not a karma or karma-pact issue), we stumbled across a problem: the mock server didn't become available and karma did shutdown immediately.

The reason was an exception, that we tried to reproduce in an isolated way. To do this, we've extracted the core logic and executed it without karma (or anything other besides pact).
The following code has been used:

import wrapper from "@pact-foundation/pact-core"
import deasync from "deasync"
import needle from "needle"


var pacts = [{port: 8992}];

// If pact options is object, wrap in array
if (!Array.isArray(pacts)) {
    pacts = [pacts];
}

var startingServers = [];

pacts.map(function (pact) {
    var server = wrapper.createServer(pact);
    server.start().then(function () {
        console.log('Pact Mock Server running on port: ' + server.options.port);
        // Remove current server from starting servers array
        startingServers = startingServers.filter(x => x !== server.options.port);
    }, function (err) {
        console.error('Error while trying to run karma-pact: ' + err);
    });
    // Add current server to starting servers array
    startingServers.push(server.options.port);
});

deasync.loopWhile(function () {
    return !isMockServerReady();
});

function isMockServerReady() {
    return startingServers.length === 0;
}

console.log("mock server ready: " + isMockServerReady())

needle.get("http://localhost:8992", {}, function (error, value) {
    console.log("value")
    console.log(value)
    console.log("error")
    console.log(error)
});

The application crashes and the mock server never becomes available. The reason seems to be an unhandled error somewhere in the codebase:

internal/process/esm_loader.js:74
    internalBinding('errors').triggerUncaughtException(
                              ^

Error: connect ECONNREFUSED 127.0.0.1:8992
    at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1148:16)

(full log further down).

This unhandled exception becomes handled through deasync and thus terminates the process. I suspect that the exception is being caused by __waitForServiceUp() or __call() in service.ts, but was unable to track the exception down.
The code has been tested with @pact-foundation/[email protected] and @pact-foundation/[email protected]

Expected behaviour

index.js should be executed without any problems. A request to the mock server should be possible at the end.

Steps to reproduce

The project demonstrating the issue can be found here:
https://github.com/fernanfs/pact-playground

Running the example is simple:

• checkout the codebase
• execute npm install
• run node index.js

Relevant log files

This is the output generated on Windows when running index.js:

C:\Workspace\Tools\node-v14.17.4-win-x64\node.exe C:\Workspace\ws\pact-playground\index.js
Debugger listening on ws://127.0.0.1:51885/d1abdb52-1fa6-4819-b57a-9709e94932d1
Debugger attached.
[2021-08-10 13:18:28.098 +0000] INFO (25028 on WPU8L0082869): [email protected]: Creating Pact Server with options:
{"port":8992,"dir":"C:\\Workspace\\ws\\pact-playground","pactFileWriteMode":"overwrite","ssl":false,"cors":false,"host":"localhost"}
[2021-08-10 13:18:28.237 +0000] INFO (25028 on WPU8L0082869): [email protected]: Removing all Pact servers.
Waiting for the debugger to disconnect...
internal/process/esm_loader.js:74
    internalBinding('errors').triggerUncaughtException(
                              ^

Error: connect ECONNREFUSED 127.0.0.1:8992
    at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1148:16)
    at TCPConnectWrap.callbackTrampoline (internal/async_hooks.js:131:17)
    at Function.module.exports.loopWhile (C:\Workspace\ws\pact-playground\node_modules\deasync\index.js:71:23)
    at file:///C:/Workspace/ws/pact-playground/index.js:28:9
    at ModuleJob.run (internal/modules/esm/module_job.js:170:25)
    at async Loader.import (internal/modules/esm/loader.js:178:24)
    at async Object.loadESM (internal/process/esm_loader.js:68:5)
Emitted 'error' event on ClientRequest instance at:
    at Socket.socketErrorListener (_http_client.js:475:9)
    at Socket.emit (events.js:400:28)
    at emitErrorNT (internal/streams/destroy.js:106:8)
    at emitErrorCloseNT (internal/streams/destroy.js:74:3)
    at processTicksAndRejections (internal/process/task_queues.js:82:21)
    at process.runNextTicks [as _tickCallback] (internal/process/task_queues.js:64:3)
    at Function.module.exports.loopWhile (C:\Workspace\ws\pact-playground\node_modules\deasync\index.js:70:11)
    at file:///C:/Workspace/ws/pact-playground/index.js:28:9
    [... lines matching original stack trace ...]
    at async Object.loadESM (internal/process/esm_loader.js:68:5) {
  errno: -4078,
  code: 'ECONNREFUSED',
  syscall: 'connect',
  address: '127.0.0.1',
  port: 8992
}

[TimothyJones]

This is an absolutely awesome report! Super detailed, logs included, tested in OSX and Windows and a reproducible example!? You're amazing!

I think this might be related to the very last version where needle was introduced. My guess is that needle.get is throwing this error, which isn't caught, because it's thrown from inside the promise constructor. If that's the case, it should be an easy fix.

[mefellows]

Definite virtual hi fives @fernanfs !

[fernanfs]

Which was the last Version of pact-node which did not include needle? I'll downgrade to that version and see if that changes anything. If so, we would have a workaround in the meantime.
Thanks for your help!

[TimothyJones]

Sorry, I wasn't very clear:

related to the very last version where needle was introduced.

This should have said "related to the latest release, in which needle was introduced". So, any version before 11.1.0.

Specifically, try 11.0.1 of pact-core, or 10.12.2 of pact-node.

I may have a fix for you - I'm about to release 11.1.1 of pact-core now, and if that works, I'll back-port it to pact-node.

---

A related aside: We have a number of challenges bringing karma-pact forward to the next version of pact-js (which will use the rust core, bringing substantial speed improvements, and also the long-overdue support for pact spec v3, which has a number of improvements around provider states, matchers etc). We're considering sunsetting both karma-pact and pact-web - I'd like to write up my thoughts on this in more detail, but to summarise quickly:

My personal view is that running API client tests through the browser encourages including UI in your pact tests, and I don't think that's something we should encourage. I see the argument for "well, this is the environment we're deploying too, so we should be testing in it", but as I understand it, modern transpilation practices largely make that argument moot (I may be wrong here - I haven't done a lot of digging on the topic). Additionally, both pact-web and karma-pact are challenging to maintain, so it's a lot of work to keep the ability to run tests in an environment that (personally) I don't really believe it.

However, on the other hand, I don't want pact to have opinions on how you write your tests. Just because it's not my personal preferred style, doesn't mean that we shouldn't support it. My personal style is not "correct" or "best practice" (even if I might enjoy claiming it is if we were arguing about testing over a beer). Also, I like the idea that pact supports doing something a little unusual - I don't know if many tools implement the ability to test actual http request/responses from karma. So it's a cool differentiator.

Anyway, if you're using karma-pact extensively and have thoughts on this, we'd love your thoughts on this issue: pact-foundation/pact-js#626

[TimothyJones]

Also github interpreted "may fix #XX" as "did fix #XX". Reopening, hopefully only for a short time.

[TimothyJones]

Update: 11.1.1 does not fix this issue. Hmm.

[fernanfs]

I'm really amazed about your extremely fast feedback. Thank you!

I tested v11.1.1, unfortunately with no success:

[2021-08-11 06:29:11.358 +0000] INFO (27809 on Francoiss-MBP.fritz.box): [email protected]: Creating Pact Server with options:
{"port":8992,"dir":"/Users/francois/ws-ing/pact-playground","pactFileWriteMode":"overwrite","ssl":false,"cors":false,"host":"localhost"}
[2021-08-11 06:29:11.380 +0000] INFO (27809 on Francoiss-MBP.fritz.box): [email protected]: Removing all Pact servers.
node:internal/process/esm_loader:74
    internalBinding('errors').triggerUncaughtException(
                              ^

Error: connect ECONNREFUSED 127.0.0.1:8992
    at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1142:16)
    at Function.module.exports.loopWhile (/Users/francois/ws-ing/pact-playground/node_modules/deasync/index.js:71:23)
    at file:///Users/francois/ws-ing/pact-playground/index.js:28:9
    at ModuleJob.run (node:internal/modules/esm/module_job:183:25)
    at async Loader.import (node:internal/modules/esm/loader:178:24)
    at async Object.loadESM (node:internal/process/esm_loader:68:5)
    at async handleMainPromise (node:internal/modules/run_main:63:12)
Emitted 'error' event on ClientRequest instance at:
    at Socket.socketErrorListener (node:_http_client:447:9)
    at Socket.emit (node:events:394:28)
    at emitErrorNT (node:internal/streams/destroy:157:8)
    at emitErrorCloseNT (node:internal/streams/destroy:122:3)
    at processTicksAndRejections (node:internal/process/task_queues:83:21)
    at process.runNextTicks [as _tickCallback] (node:internal/process/task_queues:65:3)
    at Function.module.exports.loopWhile (/Users/francois/ws-ing/pact-playground/node_modules/deasync/index.js:70:11)
    at file:///Users/francois/ws-ing/pact-playground/index.js:28:9
    [... lines matching original stack trace ...]
    at async handleMainPromise (node:internal/modules/run_main:63:12) {
  errno: -61,
  code: 'ECONNREFUSED',
  syscall: 'connect',
  address: '127.0.0.1',
  port: 8992
}

I then went on to give v11.0.1 of pact-core a shot. There is a difference in the execution, but unfortunately doesn't bring me much further. I don't see the exception, but the application hangs once the mock server is started.
The only output that I see is the following:

[2021-08-11 06:33:58.562 +0000] INFO (28168 on Francoiss-MBP.fritz.box): [email protected]: Creating Pact Server with options:
{"port":8992,"dir":"/Users/francois/ws-ing/pact-playground","pactFileWriteMode":"overwrite","ssl":false,"cors":false,"host":"localhost"}

But the mock server is actually running, which I can verify with curl:

➜  ~  curl localhost:8992
{"message":"No interaction found for GET /","interaction_diffs":[]}

---

regarding your side note: I get your point on using karma for pact contract tests. I tend to disagree with you on that but am happy to discuss in pact-foundation/pact-js#626

[TimothyJones]

I've just been bashing my head against this crash for the past hour. Debugging it seems to lead to a function that never returns :/ I started to suspect the M1 mac isn't playing nicely with deasync, so I'm switching to an intel one to eliminate that.

I'm really amazed about your extremely fast feedback. Thank you!

You're so welcome! It's a combination of I happened to be having an open source day, and this issue was so well written and complete that I wanted to prioritise it.

---

I tend to disagree with you on that but am happy to discuss in pact-foundation/pact-js#626

Awesome! Yes please!

[TimothyJones]

So, I think it's hanging because of a bug in deasync: abbr/deasync#140

I'm not sure if the uncaught exception is happening because of that, too, but if I wrap the whole __call function in service.ts in try/catch then the uncaught exception still happens. If I replace the function with return Promise.reject(new Error("OH NO")), then the promise never resolves because we're hitting that bug. Hmm.

[TimothyJones]

Ok, after some further digging, I found this gem in the original project that deasync was forked from:

This repository is not maintened. deasync npm package is maintained here: https://github.com/abbr/deasync, though it's just a hack and I'd strongly recommend not to use it for anything.

😂

The issue of deasync not working in node 12 / 14 has a minimal repro already in the issue I linked, but no activity yet on a fix.

In the meantime, I think your use case is for karma-pact, which only used deasync because Karma didn't support async plugins. It looks like Karma supports async plugins since 4.3.0, so maybe we can rework karma-pact to work around this.

[fernanfs]

Thanks a lot for the time you've put into this. My use case is indeed primarily using karma-pact and porting it to the async plugins api seems very sensible to do so. I'll dig into that, if you didn't do so already. Maybe I can thank you by creating at least a PR for that. ;-)

[TimothyJones]

Yes please! I definitely don't have the capacity to look at anything karma-pact related until after the next major pact-js release. It probably needs a number of other quality of life updates, too - I would guess it has at least some outdated dependencies.

[TimothyJones]

If you start looking at it and have any questions (or just want a general overview of anything), you're very welcome to pm me on slack (or ask in #pact-js-development). If you're not already in the pact-foundation slack, you should be able to generate yourself an invite here: https://slack.pact.io/

[TimothyJones]

Closing this, because thanks to @fernanfs (pact-foundation/karma-pact#27) karma-pact v3.0.0 no longer uses deasync, and it looks like this is a deasync issue rather than a pact issue.