relying on connection.end() callback is causing process to exit early

[gajus]

Here is the code:

const mysql = require('mysql2');
const Promise = require('bluebird');

const config = {
  "database": "showtime",
  "host": "127.0.0.1",
  "password": "your-database",
  "port": "3306",
  "user": "root"
};

+ const makeItWork = true;

const createConnection = (options = {}) => {
  options.namedPlaceholders = true;
  options.decimalNumbers = false;

  return new Promise((resolve, reject) => {
    const connection = mysql.createConnection(options);

    connection.once('connect', () => {
      resolve(connection);
    });

    connection.once('error', (error) => {
      reject(error);
    });
  });
};

const createDisposableConnection = (connectionOptions) => {
  return createConnection(connectionOptions)
    .then((connection) => {
      return connection;
    })
    .disposer((connection) => {
      console.log('Disposing of connection...');
      return Promise
        .fromCallback((callback) => {
+          if (makeItWork) {
+            connection.end();
+
+            callback();
+          } else {
+            connection.end(callback);
+          }
        })
        .then(() => {
          console.log('This is never reached. (createDisposableConnection)');
        });
    });
};

Promise
  .using(createDisposableConnection(config), (connection) => {
    return new Promise((resolve, reject) => {
      connection
        .query('SELECT `id`, `nid`, ST_X(`coordinates`) `longitude`, ST_Y(`coordinates`) `latitude` FROM `location` WHERE `coordinates` != POINT(0, 0) ORDER BY `google_places_lookup_at` ASC')
        .on('result', (row) => {
          console.log('Hello');

          connection.pause();

          reject(new Error('Continue... 0'));
        })
    })
    .catch(() => {
      console.log('I am caught!');

      throw new Error('Continue... 1');
    });
  })
  .then(() => {
    console.log('This is never called. (this)');
  })
  .catch(() => {
    console.log('This is never called. (catch)');
  });

Here is the program output when makeItWork = true:

Hello
I am caught!
Disposing of connection...
This is never reached. (createDisposableConnection)
This is never called. (catch)

Here is the program output when makeItWork = false:

Hello
I am caught!
Disposing of connection...

[gajus]

I have tried debugging this using --inspect. However, for whatever reason the debugger is crashing.

I am wondering if this is related to the use of domains.

[gajus]

@sidorares I am not marking this as a bug since I cannot confirm that whatever exits the process originates in the mysql2 code base. Can you have a look into this?

I am also interested how'd someone debug this.

[sidorares]

I'll have a look ( reading about bluebird disposers right now )

[gajus]

I thought this will have something to do with https://github.com/sidorares/node-mysql2/issues/449, but it doesn't. Just tested on a local branch that removes use of domains.

[sidorares]

@gajus works for me is connection is resumed before end(). Note that connection.pause() pauses network stream as well, and end() is never finished

 const createConnection = (options = {}) => {
  options.namedPlaceholders = true;
  options.decimalNumbers = false;

  return new Promise((resolve, reject) => {
    const connection = mysql.createConnection(options);

    connection.once('connect', () => {
      resolve(connection);
    });

    connection.once('error', (error) => {
      reject(error);
    });
  });
};

const createDisposableConnection = (connectionOptions) => {
  return createConnection(connectionOptions)
    .then((connection) => {
      return connection;
    })
    .disposer((connection) => {
      console.log('Disposing of connection...');
      return Promise
        .fromCallback((callback) => {
          connection.resume();
          connection.end(callback);
        })
        .then(() => {
          console.log('This is never reached. (createDisposableConnection)');
        });
    });
};

var config = {
  user: 'root',
  database: 'test'
};

Promise
  .using(createDisposableConnection(config), (connection) => {
    return new Promise((resolve, reject) => {
      connection
        .query('SELECT 1+1 as qqq')
        .on('result', (row) => {
          console.log('result row:', row);
          connection.pause();
          reject(new Error('...'));
        })
        .on('end', () => {
          resolve("result")
        })
    })
    .catch(() => {
      console.log('I am caught!');
      throw new Error('Continue... 0');
    });
  })
  .then(() => {
    console.log('This is never called. (this)');
  })
  .catch(() => {
    console.log('This is never called. (catch)');
  });

[gajus]

@gajus works for me is connection is resumed before end(). Note that connection.pause() pauses network stream as well, and end() is never finished

The reason this works for you is because SELECT 1+1 as qqq returns 1 row. Try running a query that would return multiple rows.

[sidorares]

looks like side effect of pasue/resume. Need investigate more. Try this one (resume moved earlier in disposer):

const createDisposableConnection = (connectionOptions) => {
  return createConnection(connectionOptions)
    .then((connection) => {
      return connection;
    })
    .disposer((connection) => {
      console.log('Disposing of connection...');
      connection.resume();
      return Promise
        .fromCallback((callback) => {
          connection.end(callback);
        })
        .then(() => {
          console.log('This is never reached. (createDisposableConnection)');
        });
    });
};

[gajus]

Just in case... this behaviour depends on the amount of rows. I was trying to build a test case using a table with 100 records and couldn't make it. I was only able to replicate the issue when I tried against a dataset with 4000 records.

[gajus]

Here is a bare minimum I have got to to replicate the issue:

const mysql = require('mysql2');

const config = {
  database: 'test',
  host: '127.0.0.1',
  password: 'test',
  port: '3306',
  user: 'root'
};

const createConnection = (options = {}) => {
  options.namedPlaceholders = true;
  options.decimalNumbers = false;

  return new Promise((resolve, reject) => {
    const connection = mysql.createConnection(options);

    connection.once('connect', () => {
      resolve(connection);
    });

    connection.once('error', (error) => {
      reject(error);
    });

    connection.connect();
  });
};

const promiseRoutine = (connection) => {
  return new Promise((resolve, reject) => {
    connection
      .query('SELECT `id` FROM `location`')
      .on('result', (row) => {
        console.log('Hello', row.id);

        connection.pause();

        reject(new Error('Force error 0'));
      });
  });
};

const disposePromise = (connection) => {
  console.log('Disposing of connection... 0');
  return new Promise((resolve, reject) => {
    console.log('Disposing of connection... 1');
    connection.end((error) => {
      console.log('Disposing of connection... 2', error);

      if (error) {
        reject(error);
      } else {
        resolve();
      }
    });
  });
};

createConnection(config)
  .then((connection) => {
    return promiseRoutine(connection)
      .catch((error) => {
        return disposePromise(connection)
          .then(() => {
            throw new error;
          });
      });
  });

Notice the output is:

Disposing of connection... 0
Disposing of connection... 1

It is missing "Disposing of connection... 2". Ensure that the locations table has at least 4000 records.

[gajus]

I have read the relevant source code of mysql2 and the issue now makes more sense.

Here the "quit" command gets queued.

https://github.com/sidorares/node-mysql2/blob/0efa5f3fcfa726fc3f7424b604fd364fa781c562/lib/connection.js#L816-L819

The first problem is that at this point the command stream is in "paused" state, therefore the "quit" command is never going to get executed. This should be a simple fix, https://github.com/sidorares/node-mysql2/pull/456.

However, using the previous example,

const promiseRoutine = (connection) => {
  return new Promise((resolve, reject) => {
    connection
      .query('SELECT `id` FROM `location`')
      .on('result', (row) => {
        console.log('Hello', row.id);

        connection.pause();

        reject(new Error('Force error 0'));
      });
  });
};

on first result, connection.pause will pause the command stream and reject the promise. This will trigger connection.end, which will queue a command to call the supplied callback. However, because now the command queue is active again, on('result', (row) => { will continue to get results. Therefore, connection.pause will be executed again. However, this time "pausing" the command queue will take out the "end" command out of the event cycle. As a result, the process will think that the connection.end callback will never be called and exit.

I cannot think how to solve this at the mysql2 level – connection.end by definition is a promise that pending tasks will continue. Therefore, it would be invalid to abort the existing stream. (Maybe another control in addition to connection.pause?)

In user land, user can choose to ignore further stream data, e.g.

const promiseRoutine = (connection) => {
  return new Promise((resolve, reject) => {
    let isRejected;

    connection
      .query('SELECT `id` FROM `location`')
      .on('result', (row) => {
        if (isRejected) {
          return;
        }

        isRejected = true;

        connection.pause();

        reject(new Error('Force error 0'));
      });
  });
};