"getport" sometimes throwing an error #827

tarasromil · 2023-11-03T10:59:27Z

Versions

NodeJS: 16.20.2
mongodb-memory-server-*: 9.0.1
mongodb(the binary version): 6.0.10
mongodb(the js package): 5.9.0
system: MacOS 14.1

package: mongo-memory-server

What is the Problem?

When I'm trun to run test using "vitest@0.34.6" in concurrency mode I have an error that port already in use. No always, but pretty often

Starting the MongoMemoryServer Instance failed, enable debug log for more information. Error:
 StdoutInstanceError: Port "15490" already in use

Want to notice that there is no error on v8.16.0

Code Example

globalThis.__MONGO_DB__ = await MongoMemoryServer.create();

Debug Output

stderr | unknown test
Starting the MongoMemoryServer Instance failed, enable debug log for more information. Error:
 StdoutInstanceError: Port "52929" already in use
    at MongoInstance.checkErrorInLine (/.../node_modules/.pnpm/mongodb-memory-server-core@9.0.1/node_modules/mongodb-memory-server-core/src/util/MongoInstance.ts:641:9)
    at MongoInstance.stdoutHandler (/.../node_modules/.pnpm/mongodb-memory-server-core@9.0.1/node_modules/mongodb-memory-server-core/src/util/MongoInstance.ts:615:10)
    at Socket.emit (node:events:513:28)
    at addChunk (node:internal/streams/readable:315:12)
    at readableAddChunk (node:internal/streams/readable:289:9)
    at Socket.Readable.push (node:internal/streams/readable:228:10)
    at Pipe.onStreamRead (node:internal/stream_base_commons:190:23)

Do you know why it happenes?

Looks like there is a race condition after replacing "get-port" to own implementation

The text was updated successfully, but these errors were encountered:

hasezoey · 2023-11-03T14:53:27Z

i dont know how vitest's concurrency works or how / where you create your server.
i also dont know why the new implementation would fail when the old one would not in the same scenario.

port acquisition and keeping is a fickle process, because you cant just "give me a free port and keep it on-hold until used" and also cannot be marked as "used for later", like it is tested that it is free with a small http server, which is closed to free the port so that it can be used by mongod, but in that small time another process may just get that port

AndreasGalster2 · 2023-11-07T12:49:22Z

I just got here because I have the same issue. Since there's currently no solution, I'm thinking maybe https://www.npmjs.com/package/promise-retry will do the trick to create a server in case the port fails. I haven't tried this yet but that might work at least as a temporary fix.

/edit:

    import promiseRetry from 'promise-retry';

    const promiseRetryOptions = {
      retries: 3,
      factor: 2,
      minTimeout: 50,
      maxTimeout: 10000,
    };

    return promiseRetry((retry, number) => {
      console.log(`Creating MongoClient - Retrying if port is unavailable - Try Number: ${number}`);

      return mongoose.connect(url, { useNewUrlParser: true });
    }, promiseRetryOptions);

I've done a few runs now and it seems I no longer have port issues. No guarantees here but out of 5 runs, they all passed... Before every 2nd run or so failed.

JacksonUtsch · 2023-11-09T15:18:09Z

I seem to getting the same port issue sometimes. Oddly enough also on macOS 14.1. but mongodb-memory-server v8.13.0. Will try newer version.

trevorah · 2023-11-09T15:38:01Z

We've had the same issue with v9.0.1 on macos and on GHA linux build machines, where v8.13.0 was fine.

We ended up with this workaround:

import getPort from 'get-port';
import retry from 'async-retry';

const port = await getPort();
const mongo = await retry(
  () =>
    MongoMemoryReplSet.create({
      ...this.testEnvironmentOptions,
      instanceOpts: [{ port }],
      replSet: { count: 2 },
    }),
  {
    retries: 3,
  },
);

JacksonUtsch · 2023-11-09T15:54:32Z

Well, it seems I have interesting results. Updating to v9.0.1 seems to made this issue much less frequent.

hasezoey · 2023-11-09T16:03:53Z

@JacksonUtsch @trevorah, what exact errors are you seeing, are you seeing a Port is already in use(by the mongod log) error or a Max port tries exceeded error?

i also dont know what is so much different from the get-port implementation, does someone maybe have some suggestions? code here

JacksonUtsch · 2023-11-09T16:29:31Z

Port "50113" already in use
  at MongoInstance.checkErrorInLine (node_modules/mongodb-memory-server-core/src/util/MongoInstance.ts:611:9)
  at MongoInstance.stdoutHandler (node_modules/mongodb-memory-server-core/src/util/MongoInstance.ts:585:10)

In the code referenced I think we need a lock of sorts for PORTS_CACHE. If we could await read and writing of that value. Does that sound about right?

hasezoey · 2023-11-09T16:31:19Z

In the code referenced I think we need a lock of sorts for PORTS_CACHE. If we could await read and writing of that value. Does that sound about right?

do you mean some kind of mutex or do you mean a cache file with lock?

also what is your use-case, replset or just many severs?

JacksonUtsch · 2023-11-09T16:36:05Z

A mutex yes. Running many e2e tests from separate files.

hasezoey · 2023-11-09T16:41:37Z

Running many e2e tests from separate files.

what is your testing environment?

(example jest) the problem with many concurrent tests and each having their own server is that those modules are isolated and cannot speak to each-other without some kind of cache file (so a normal mutex would not work), but i didnt want to increase complexity compared to the old get-port (that is why it is recommended to start a server in globalSetup)

JacksonUtsch · 2023-11-09T16:45:54Z

Yes, using jest for testing here.

Hmm, I thought there was only a single instance of PORTS_CACHE defined at the file level and they would all use the same? Ex: A singleton or global variable with locking.

hasezoey · 2023-11-09T16:50:40Z

Hmm, I thought there was only a single instance of PORTS_CACHE defined at the file level and they would all use the same? Ex: A singleton or global variable with locking.

yes it is a singleton, but the problem is that they are isolated instances, each jest worker can be seen as its own nodejs process, so a singleton is not shared across those processes (at least to my knowledge).
basically meaning that each test file is executed as a "new nodejs process"

JacksonUtsch · 2023-11-09T16:53:32Z

Ahh, good to know. Then a temp file might be the way to go.

this changes the behavior to use "net.listen(0)" to create a random port re #827

hasezoey · 2023-11-09T17:58:26Z

there might be 1 thing that is definitely different from get-port and that is that it relies on net.listen(0) returning a random port, whereas this new implementation is basically predictable. though that should theoretically not have a effect because it is tested to be free (net.listen), but another process may just snatch it in the time between generation and usage.
(i had designed it to be predictable, so that it could be tested and get to know what port might be chosen for a test)

for the next version i have done some slight refactors regarding the port implementation, and i also have cobbled something together to use net.listen(0) (earliest version 9.1.0-beta.3), under the flag EXP_NET0LISTEN (link should be valid in a few minutes)
please try this new option if you run into this often and report your results.

if that does not work, i will try to make a more complex solution similar to locking a binary download place (via our LockFile implementation) to only allow one server to generate a port, use it and then unlock it - which might make tests longer, so it will likely be a non-default option - it will also not prevent other unrelated applications using those ports in the meantime and they will have to have the same lockfile path (download dir?)

JacksonUtsch · 2023-11-09T19:59:08Z

@hasezoey This seems to work for me. I've not seen the error show up when using the tag and flag. 😃

hasezoey · 2023-11-13T15:21:01Z

because port problems are somewhat sporadic, i have not been able to actually test much about it, but today just run into a case where i consistently got failed tests because of "port already in use" (even after multiple tries), adding EXP_NET0LISTEN actually fixed it, at least for now.

i am thinking about making it the default in some future version (but not 9.1.0 yet) to get some more testing, and push the old behavior behind a flag.

just keep in mind that this will just lessen the port conflicts, but not entirely avoid them.

JacksonUtsch · 2023-11-13T15:45:23Z

Great. Agreed it should be default behavior. Good to have a reproducible test with the issue here.

hasezoey · 2023-11-13T15:48:27Z

Good to have a reproducible test with the issue here.

I dont quite know what you mean, there still is not reproduce-able case i know of, i just ran into it - if i would reboot it would likely be gone again (or after many retries), port testing is a very fickle process. The best would be if mongod would implement something to generate their own port.

JacksonUtsch · 2023-11-13T16:21:56Z

but today just run into a case where i consistently got failed tests because of "port already in use" (even after multiple tries), adding EXP_NET0LISTEN actually fixed it, at least for now.

It only sounded like this was reproducible is all.

hasezoey · 2023-11-13T16:24:09Z

It only sounded like this was reproducible is all.

it sounded like it, but it was just sporadic as said in the earlier comment, i dont have a reproduce-able case for this, i dont even know if there is one - the best i have to test "port already in use" falky-ness is just re-running the MMS tests over and over

andr9528 · 2023-11-16T10:54:57Z

At Tv2 Danmark one of our repositories uses version 9.0.0 for tests. We have found the same bug as desribed here - but only on unix environments. Two of the developers are using Mac, which has the error along with during GitHub action, however the two other developers (me included) using windowns have not been able to reproduce the error. It appears to happen quite often on GitHub actions and for the Mac users, so it would appear to be reproducable in the right environment.

Going to test now if the v9.1.0-beta.5 fixes it for us.

At the very least i hope it helps to know that it is very likely a unix related issue.

andr9528 · 2023-11-16T11:28:10Z

At the 4th run of our GitHub check action that runs our test using this, the usual tests failed again with the same error.

 Port "27245" already in use
      at MongoInstance.checkErrorInLine (node_modules/mongodb-memory-server-core/src/util/MongoInstance.ts:643:9)
      at MongoInstance.stdoutHandler (node_modules/mongodb-memory-server-core/src/util/MongoInstance.ts:617:10)

Unsure if perhabs we are missing an option for the create method, for changes introduced to have an effect.

export class MongoTestDatabase {
  private mongoServer: MongoMemoryServer
  private client: MongoClient

  ...

  public async setupDatabase(): Promise<void> {
    this.mongoServer = await MongoMemoryServer.create()
    this.client = await MongoClient.connect(this.mongoServer.getUri())
  }

  public async teardownDatabase(): Promise<void> {
    if (this.client) {
      await this.client.close()
    }
    if (this.mongoServer) {
      await this.mongoServer.stop()
    }
  }
  ...
}

setupDatabase is called from beforeEach, and teardownDatabase is called from afterEach in each of our test files that use this class.

hasezoey · 2023-11-16T13:49:52Z

@andr9528 i dont see a problem with the code provided

Going to test now if the v9.1.0-beta.5 fixes it for us.
At the 4th run of our GitHub check action that runs our test using this, the usual tests failed again with the same error.

are those runs using the experimental option?

andr9528 · 2023-11-16T13:56:52Z

@hasezoey The 4 runs i did, where the last threw the error again, was with version 9.1.0-beta.5.

Is there anything special that needs to be configued to use the experimental option?

{ // package.json
  ...
  "devDependencies": { 
    ...
    "mongodb-memory-server": "9.1.0-beta.5",
  },
  "dependencies": { 
    ...
    "mongodb": "^6.1.0",
  }
}

hasezoey · 2023-11-16T14:12:16Z

Is there anything special that needs to be configued to use the experimental option?

yes config option EXP_NET0LISTEN aside from that option, the current beta only had some small changes regarding port generation; either set via environment variables or via the package.json

andr9528 · 2023-11-16T14:32:58Z

I am sorry that i overlooked that section. As mentioned in the section linked to, it

will not eliminate them

Immediatly after adding the missing config section to the package.json, it threw the same error twice, followed by 4 good runs, then failing again. Thus it doesn't seem to have made much of a change, if any.

The cutout of our package.json looks like this now.

{ // package.json
  ...
  "config": {
    "mongodbMemoryServer": {
      "expNet0Listen": true
    }
  },
  "devDependencies": { 
    ...
    "mongodb-memory-server": "9.1.0-beta.5",
  },
  "dependencies": { 
    ...
    "mongodb": "^6.1.0",
  }
}

As i mentioned earlier it might be related to something unix based. We are yet to see it on any of our Windows PC, while seeing it commonly on unix based enviroment. Has been seen on both MacOS and Linux, in the form of Github Actions.

hasezoey · 2023-11-16T15:07:31Z

As i mentioned earlier it might be related to something unix based

it should theoretically happen on all systems, because at the time the port is generated, another process could come in and use it before actually being used by the mongod server (in the downtime in-between), net.listen(0) should reduce the frequency, because it is actually generating a random port, instead of a predictable port like the non-experimental implementation.

to confirm, is that the only package.json or are there more? could you maybe try via a environment variable too? (i did not add a log to indicate whether the experiment is active or not, but maybe i should)

hasezoey · 2023-11-16T17:01:45Z

version 9.1.0 has now been released with the EXP_NET0LISTEN option, and also added a long to know whether it is enabled or not (requires Debug Logs to be active), search for EXP_NET0LISTEN and it should either log true or false after it

hasezoey · 2023-11-24T11:48:05Z

In our case, the problem comes from mocked dates in Jest.

for now maybe try using the EXP_NET0LISTEN option

dimaip · 2023-11-24T15:15:52Z

for now maybe try using the EXP_NET0LISTEN option

Thanks for the suggestion, but that's what we were already using. Since it always starts with the same port, on the first try it would try to use that port and fail (see https://github.com/nodkz/mongodb-memory-server/blob/master/packages/mongodb-memory-server-core/src/util/getport/index.ts#L73C7-L73C46)

hasezoey · 2023-11-24T15:21:30Z

Since it always starts with the same port, on the first try it would try to use that port and fail

what exactly do you mean with "fail", as in "failed with error" or "failed and tried another port"?

PS: forgot Date.now was used to get a initial port

as a workaround you could likely use port: 0 explicitly in the server config and EXP_NET0LISTEN. i will try to think of a way to maybe improve getting a starting port if not not provided (like with EXP_NET0LISTEN to directly use 0?)

The current implementation of `getPort()` relies on using `Date.now()` to get the first port to try to launch mongo on, even when the `EXP_NET0LISTEN` flag is set. This causes a couple issues: - If the `Date` module is mocked, it can result in `getFreePort()` returning the same first port every time. - If multiple mongos are being started at once in parallel, it's possible for the same first port to be picked leading to port conflicts In order to better randomize the initial port selection so that port conflicts can be avoided, instead of using `Date.now()` for an initial seed, use `crypto.randomInt()` which should provide more randomness and hopefully avoid some of these race conditions. Fixes typegoose#827

* fix(getport): Randomize first port using crypto The current implementation of `getPort()` relies on using `Date.now()` to get the first port to try to launch mongo on, even when the `EXP_NET0LISTEN` flag is set. This causes a couple issues: - If the `Date` module is mocked, it can result in `getFreePort()` returning the same first port every time. - If multiple mongos are being started at once in parallel, it's possible for the same first port to be picked leading to port conflicts In order to better randomize the initial port selection so that port conflicts can be avoided, instead of using `Date.now()` for an initial seed, use `crypto.randomInt()` which should provide more randomness and hopefully avoid some of these race conditions. re #827 * fix(getport): change crypto.randomInt "max" to be inclusive --------- Co-authored-by: hasezoey <hasezoey@gmail.com>

hasezoey · 2024-01-13T14:25:18Z

version 9.1.5 has been released with #844, which at least fixes the use of Date.now() as a starting port (and instead uses crypto.randomInt)

zvickery · 2024-02-27T22:39:02Z

Setting "expNet0Listen": true seemed to help significantly with "Port already in use" errors I observed in my environment!

JacksonUtsch · 2024-04-05T19:44:38Z

Max port tries exceeded occurring sometimes in GitHub workflow now. 🤔

hasezoey · 2024-04-06T12:23:05Z

@JacksonUtsch if it is in the CI, this likely means a lot of MMS instances have been created and not on the same node process instance, is this the case in your tests?
also did you already try the option EXP_NET0LISTEN and use a higher or equal MMS version as 9.1.5?

JacksonUtsch · 2024-04-08T13:47:14Z

EXP_NET0LISTEN option enabled on 9.1.0-beta.3, will update version and see if that resolves

github-actions · 2024-06-24T14:54:07Z

🎉 This issue has been resolved in version 10.0.0-beta.1 🎉

The release is available on:

Your semantic-release bot 📦🚀

hasezoey · 2024-06-24T14:57:08Z

with version 10.0.0(-beta.1) the default (and only) way is now to use what was previously EXP_NET0LISTEN, i would appreciate some testing in the environments where it previously was not running great without the option.

github-actions · 2024-07-18T11:04:05Z

🎉 This issue has been resolved in version 10.0.0 🎉

The release is available on:

Your semantic-release bot 📦🚀

B4nan · 2024-08-03T08:24:38Z

I just got the same issue after upgrading to v10.0.0, only once for now (out of 10+ builds I guess).

https://github.com/mikro-orm/mikro-orm/actions/runs/10226440366/job/28296683190

B4nan · 2024-08-03T10:15:09Z

wdym, the error is exactly the same as in the OP

hasezoey · 2024-08-03T10:21:10Z

@B4nan sorry, forgotten that this was part of this issue (was only thinking about max port tries exceeded), anyway could you still open a new issue outlining your setup?

tarasromil added the bug label Nov 3, 2023

hasezoey added a commit that referenced this issue Nov 9, 2023

feat(getport): add experimental "EXP_NET0LISTEN" option

631ec28

this changes the behavior to use "net.listen(0)" to create a random port re #827

This comment was marked as outdated.

Sign in to view

github-actions bot added the stale This Issue is outdated and will likely be closed if no further comments are given label Dec 25, 2023

hasezoey added keep Keep this issue open (no Stale) and removed stale This Issue is outdated and will likely be closed if no further comments are given labels Dec 25, 2023

noseworthy mentioned this issue Jan 11, 2024

fix(getport): Randomize first port using crypto #844

Merged

hasezoey added this to the 10.0 milestone Jun 8, 2024

github-actions bot added the released on @beta label Jun 24, 2024

hasezoey closed this as completed in 887f1a1 Jul 18, 2024

github-actions bot added the released Pull Request released | Issue is fixed label Jul 18, 2024

This comment was marked as outdated.

Sign in to view

B4nan mentioned this issue Aug 3, 2024

Occasional StdoutInstanceError: Port "39697" already in use with v10.0.0 #883

Closed

lholmquist mentioned this issue Aug 10, 2024

[Snyk] Upgrade mongodb-memory-server from 9.4.1 to 10.0.0 nodeshift/mern-workshop#229

Merged

"getport" sometimes throwing an error #827

"getport" sometimes throwing an error #827

Comments

tarasromil commented Nov 3, 2023

Versions

What is the Problem?

Code Example

Debug Output

Do you know why it happenes?

hasezoey commented Nov 3, 2023

AndreasGalster2 commented Nov 7, 2023 • edited Loading

JacksonUtsch commented Nov 9, 2023

trevorah commented Nov 9, 2023

JacksonUtsch commented Nov 9, 2023

hasezoey commented Nov 9, 2023

JacksonUtsch commented Nov 9, 2023

hasezoey commented Nov 9, 2023 • edited Loading

JacksonUtsch commented Nov 9, 2023

hasezoey commented Nov 9, 2023

JacksonUtsch commented Nov 9, 2023

hasezoey commented Nov 9, 2023

JacksonUtsch commented Nov 9, 2023

hasezoey commented Nov 9, 2023

JacksonUtsch commented Nov 9, 2023

hasezoey commented Nov 13, 2023

JacksonUtsch commented Nov 13, 2023

hasezoey commented Nov 13, 2023

JacksonUtsch commented Nov 13, 2023

hasezoey commented Nov 13, 2023

andr9528 commented Nov 16, 2023 • edited Loading

andr9528 commented Nov 16, 2023 • edited Loading

hasezoey commented Nov 16, 2023

andr9528 commented Nov 16, 2023

hasezoey commented Nov 16, 2023

andr9528 commented Nov 16, 2023

hasezoey commented Nov 16, 2023

hasezoey commented Nov 16, 2023

hasezoey commented Nov 24, 2023

dimaip commented Nov 24, 2023

hasezoey commented Nov 24, 2023 • edited Loading

This comment was marked as outdated.

hasezoey commented Jan 13, 2024

zvickery commented Feb 27, 2024

JacksonUtsch commented Apr 5, 2024

hasezoey commented Apr 6, 2024

JacksonUtsch commented Apr 8, 2024 • edited Loading

github-actions bot commented Jun 24, 2024

hasezoey commented Jun 24, 2024

github-actions bot commented Jul 18, 2024

B4nan commented Aug 3, 2024

This comment was marked as outdated.

B4nan commented Aug 3, 2024

hasezoey commented Aug 3, 2024

AndreasGalster2 commented Nov 7, 2023 •

edited

Loading

hasezoey commented Nov 9, 2023 •

edited

Loading

andr9528 commented Nov 16, 2023 •

edited

Loading

andr9528 commented Nov 16, 2023 •

edited

Loading

hasezoey commented Nov 24, 2023 •

edited

Loading

JacksonUtsch commented Apr 8, 2024 •

edited

Loading