[bug]: Aborted connection warning in DB

[vaasuu]

Bug Report

Describe the bug:

When running Jest tests with mysql2@3.2.0 library connecting to MariaDB 10.11.2-MariaDB-1:10.11.2+maria~ubu2204 container, the following warning messages are logged in the Mariadb container logs:

db-db-1       | 2023-04-11 10:07:05 0 [Note] mariadbd: ready for connections.
db-db-1       | Version: '10.11.2-MariaDB-1:10.11.2+maria~ubu2204'  socket: '/run/mysqld/mysqld.sock'  port: 3306  mariadb.org binary distribution
db-db-1       | 2023-04-11 10:07:05 0 [Note] InnoDB: Buffer pool(s) load completed at 230411 10:07:05
db-db-1       | 2023-04-11 10:07:31 3 [Warning] Aborted connection 3 to db: 'test' user: 'root' host: '172.27.0.1' (Got an error reading communication packets)
db-db-1       | 2023-04-11 10:07:31 5 [Warning] Aborted connection 5 to db: 'test' user: 'root' host: '172.27.0.1' (Got an error reading communication packets)
db-db-1       | 2023-04-11 10:07:31 4 [Warning] Aborted connection 4 to db: 'test' user: 'root' host: '172.27.0.1' (Got an error reading communication packets)

To Reproduce:

1. Pull latest code: 54203bf (also happens earlier)
2. Start the DB docker container using docker compose up)
3. Wait for the DB to start
4. Run Jest tests against the node.js application: npx jest, they mostly pass fine.
5. Observe the warning messages in the Mariadb container logs.

Expected behavior:

There should be no warning messages in the Mariadb container logs.

Environment:

Node.js version: v18.15.0
node-mysql2 package version: 3.2.0
Jest version: 29.5.0
DB: MariaDB version 10.11.2-MariaDB-1:10.11.2+maria~ubu2204 in docker / mysql:8 in docker (version 8.0.32-1.el8)
Operating system: macOS 11.6.8

Additional context:

The warning messages suggest that there might be an issue with the network communication between the node.js application and the MariaDB container, or there might be some issues with the MariaDB server configuration. Same aborted connections happen when using mysql docker image, but that doesn't log them; still shows via mysql> SHOW GLOBAL STATUS;. I checked Wireshark and mysql packets seem ok. The SQL queries run fine.

Full log

mariadb-docker.log

[vaasuu]

Looks to be related:

$ npx jest --detectLeaks
 PASS  __tests__/misc.test.js
 FAIL  __tests__/roles.test.js
  ● Test suite failed to run

    EXPERIMENTAL FEATURE!
    Your test suite is leaking memory. Please ensure all references are cleaned.

    There is a number of things that can leak memory:
      - Async operations that have not finished (e.g. fs.readFile).
      - Timers not properly mocked (e.g. setInterval, setTimeout).
      - Keeping references to the global scope.

      at onResult (node_modules/@jest/core/build/TestScheduler.js:150:18)
      at node_modules/@jest/core/build/TestScheduler.js:254:19
      at node_modules/emittery/index.js:363:13
          at Array.map (<anonymous>)
      at Emittery.emit (node_modules/emittery/index.js:361:23)

 FAIL  __tests__/users.test.js
  ● Test suite failed to run

    EXPERIMENTAL FEATURE!
    Your test suite is leaking memory. Please ensure all references are cleaned.

    There is a number of things that can leak memory:
      - Async operations that have not finished (e.g. fs.readFile).
      - Timers not properly mocked (e.g. setInterval, setTimeout).
      - Keeping references to the global scope.

      at onResult (node_modules/@jest/core/build/TestScheduler.js:150:18)
      at node_modules/@jest/core/build/TestScheduler.js:254:19
      at node_modules/emittery/index.js:363:13
          at Array.map (<anonymous>)
      at Emittery.emit (node_modules/emittery/index.js:361:23)

A worker process has failed to exit gracefully and has been force exited. This is likely caused by tests leaking due to improper teardown. Try running with --detectOpenHandles to find leaks. Active timers can also cause this, ensure that .unref() was called on them.
Test Suites: 2 failed, 1 passed, 3 total
Tests:       1 passed, 1 total
Snapshots:   0 total
Time:        6.255 s, estimated 7 s
Ran all test suites.
valtteri@Hackintosh:backend$

$ npx jest --detectOpenHandles --no-cache
 PASS  __tests__/users.test.js (6.538 s)
 PASS  __tests__/roles.test.js
 PASS  __tests__/misc.test.js

Test Suites: 3 passed, 3 total
Tests:       50 passed, 50 total
Snapshots:   0 total
Time:        8.045 s
Ran all test suites.

Jest has detected the following 3 open handles potentially keeping Jest from exiting:

  ●  TCPWRAP

      14 | beforeAll(async () => {
      15 |   // Remove all test users from db
    > 16 |   db.query("DELETE FROM users WHERE email LIKE '%@test.example.com'");
         |      ^
      17 | });
      18 |
      19 | afterAll(async () => {

      at new Connection (node_modules/mysql2/lib/connection.js:50:27)
      at new PoolConnection (node_modules/mysql2/lib/pool_connection.js:7:5)
      at Pool.getConnection (node_modules/mysql2/lib/pool.js:55:20)
      at Pool.query (node_modules/mysql2/lib/pool.js:143:10)
      at Object.query (__tests__/users.test.js:16:6)


  ●  TCPWRAP

      24 | describe("POST signup", () => {
      25 |   it("should create a new user", async () => {
    > 26 |     const res = await request(app).post("/api/v1/users/signup").send({
         |                                    ^
      27 |       name: "Success User",
      28 |       email: "success.user@test.example.com",
      29 |       password: "success.user",

      at Test.serverAddress (node_modules/supertest/lib/test.js:48:35)
      at new Test (node_modules/supertest/lib/test.js:34:14)
      at Object.obj.<computed> [as post] (node_modules/supertest/index.js:43:18)
      at Object.post (__tests__/users.test.js:26:36)


  ●  TCPWRAP

      10 |
      11 |   it("should return roles", async () => {
    > 12 |     const res = await request(app).post("/api/v1/users/login").send({
         |                                    ^
      13 |       email: "john.smith@example.com",
      14 |       password: "john.smith",
      15 |     });

      at Test.serverAddress (node_modules/supertest/lib/test.js:48:35)
      at new Test (node_modules/supertest/lib/test.js:34:14)
      at Object.obj.<computed> [as post] (node_modules/supertest/index.js:43:18)
      at Object.post (__tests__/roles.test.js:12:36)

[vaasuu]

Was caused by async code problems in tests and leaving DB connections open.

Something similar to ladjs/supertest#520 & https://www.dariacaraway.com/blog/jest-async-flakes

Fixed in #3