100% загрузка ЦП с использованием кластеров и mariaSQL, когда кластер закрывается и перезапускается

В моем приложении Node.JS я использую кластеры для использования своего многоядерного процессора. Я использую библиотеку mariasql узла для связи с моей базой данных. Поскольку библиотека node-mariasql не поддерживает объединение в пул, я использую сторонний - generic-pool для поддержки пул связей.

Я заметил, что использование нашего ЦП достигает 100% всякий раз, когда соединение в главном потоке закрывается после того, как неперехваченное исключение приводит к перезапуску одного из дочерних кластеров.

Всякий раз, когда перезапускается дочерний кластер, я уничтожаю все соединения MySQL.

Версия Node – v4.2.2
Версия MariaDB – v10.0.15
Версия node-mariasql – v0.2.5

Воспроизводимый код — https://github.com/bsurendrakumar/node-simplex/

Фрагменты кода

Создание пула соединений...

var pool = poolModule.Pool({
  name: 'mariadb',
  create: function(callback) {
    var client = new mSQLClient();
    client.connect(dbConfig);
    client.on('error', function(err) {
      callback(err, null);
    });
    client.on('ready', function() {
      callback(null, client);
    });
  },
  destroy: function(client) {
    if(cluster.isMaster) {
      console.log('Destroying / ending master thread ID -', client.threadId);
    }
    if(isDraining) {
      client.destroy();
    } else {
      client.end();
    }
  },
  max: dbConfig.maxConn,
  min: dbConfig.minConn,
  idleTimeoutMillis: dbConfig.idleTimeout
});

На главной ветке...

console.log('------------------------------------');
console.log('Master Process ID:', process.pid);
console.log('------------------------------------\n\n');

console.log('Creating an extra DB connection on the master thread.\n\n');
getCountries();

// Create a worker for each CPU
for (var i = 0; i < cpuCount; i += 1) {
  cluster.fork();
}

// Restarting the thread if something exits...
cluster.on('exit', function () {
  cluster.fork();
});

Как только происходит неперехваченное исключение...

// Handle uncaught exceptions...
process.on('uncaughtException', function (err) {
  try {
    console.log('\n--------------');
    console.log(err);
    // Stop the HTTP Server
    console.log('\n--------------');
    console.log('Encountered uncaught exception!');
    console.log('Stopping HTTP server ...');
    if(httpServer) {
      httpServer.close();
    }
    console.log('Stopped HTTP server, performing cleanup ...');
    // Call the cleanup function
    cleanUp(function() {
      // Exit!!
      console.log('Cleanup done!');
      restartProcess();
    });
  } catch (e) {
    console.log(e);
    restartProcess();
  }

  function restartProcess() {
    console.log('Restarting process ...');
    process.exit(1);
  }
});

Функция очистки...

function cleanUp(cbMain) {
  isDraining = true;
  if(pool.hasOwnProperty('_inUseObjects')
    && Array.isArray(pool._inUseObjects)
    && pool._inUseObjects.length > 0) {
      let inUseObjs = pool._inUseObjects;
      let inUseObjsLen = pool._inUseObjects.length;
    for(let i = 0; i !== inUseObjsLen; ++i) {
      inUseObjs[0].destroy();
      pool.release(inUseObjs[0]);
    }
  }
  pool.drain(function() {
    pool.destroyAllNow(function() {
      return cbMain();
    });
  });
}

Минимальное количество подключений в пуле установлено на 5. Всю его конфигурацию можно найти по адресу здесь. Таким образом, когда сервер запускается, универсальный пул отключит 5 подключений к MySQL и сохранит их в своем пуле.

idleTimeout для объекта в пуле установлено значение 120 секунд. Это означает, что если в пуле более 5 (поскольку 5 — минимум) объектов и один из них не использовался в течение последних 120 секунд, он будет уничтожен.

При запуске сервера я делаю простой вызов модели нашей страны, чтобы получить список стран. Этот код находится здесь. Это устанавливает новое соединение с базой данных, поэтому теперь в пуле будет 6 SQL-соединений, одно из которых будет очищено через 120 секунд.

Ниже приведен пошаговый процесс, с помощью которого я считаю, что проблема связана с нашим использованием библиотеки mariasql.

• Когда сервер запускается, я записываю идентификатор процесса в консоль. Получите идентификатор основного процесса, например 20584.

• Посмотрите на файловые дескрипторы, используемые процессом, используя - ls -l /proc/20584/fd. Запишите соединения сокетов. Вывод этого будет выглядеть примерно так - lrwx------ 1 abijeet abijeet 64 Jun 9 19:24 12 -> socket:[2469914] lrwx------ 1 abijeet abijeet 64 Jun 9 19:24 13 -> socket:[2469917] lrwx------ 1 abijeet abijeet 64 Jun 9 19:24 14 -> socket:[2468106] lrwx------ 1 abijeet abijeet 64 Jun 9 19:24 15 -> socket:[2468109] lrwx------ 1 abijeet abijeet 64 Jun 9 19:24 17 -> socket:[2467206] lrwx------ 1 abijeet abijeet 64 Jun 9 19:24 18 -> socket:[2467208] lrwx------ 1 abijeet abijeet 64 Jun 9 19:24 19 -> socket:[2467210] lrwx------ 1 abijeet abijeet 64 Jun 9 19:24 2 -> /dev/tty lrwx------ 1 abijeet abijeet 64 Jun 9 19:24 20 -> socket:[2467212] lrwx------ 1 abijeet abijeet 64 Jun 9 19:24 21 -> socket:[2467214] lrwx------ 1 abijeet abijeet 64 Jun 9 19:24 22 -> socket:[2467306]

• Скопируйте несколько номеров сокетов, например 2467212, и запустите lsof | grep 2467212. Вы заметите, что это соединения с сервером MySQL. Вывод должен быть примерно таким - node 20584 abijeet 20u IPv4 2467212 0t0 TCP localhost:57092->localhost:mysql (ESTABLISHED) V8 20584 20585 abijeet 20u IPv4 2467212 0t0 TCP localhost:57092->localhost:mysql (ESTABLISHED) V8 20584 20586 abijeet 20u IPv4 2467212 0t0 TCP localhost:57092->localhost:mysql (ESTABLISHED) V8 20584 20587 abijeet 20u IPv4 2467212 0t0 TCP localhost:57092->localhost:mysql (ESTABLISHED) V8 20584 20588 abijeet 20u IPv4 2467212 0t0 TCP localhost:57092->localhost:mysql (ESTABLISHED)

• Сбой сервера, перейдя по адресу http://127.0.0.1:3000/api/v1/country/list. Это приведет к сбою одного из дочерних процессов. Всякий раз, когда возникает неперехваченное исключение, я делаю некоторую очистку и выхожу. Затем я разветвляю другой процесс, чтобы заменить только что убитый. Очистка включает в себя -

  • Closing http server
  • Закрытие соединений MySQL в общем пуле
  • Закрытие потоков winston logger.
• Подождите, пока соединение MySQL в главном потоке будет закрыто. Когда это происходит, я пишу лог в консоль - Destroying / ending master thread ID - 4984
• Проверьте использование ЦП, вы заметите, что один из ЦП увеличился до 100%.
• Следующий запуск, strace -o log.txt -eepoll_ctl,epoll_wait -p 20584. Обратите внимание, что вам может потребоваться установить strace. Эта команда регистрирует все epoll_ctl, epoll_wait системных вызовов, сделанных процессом Node.JS, и помещает их в файл с именем log.txt в текущем рабочем каталоге.

• Откройте файл log.txt, и вы увидите журналы, похожие на эти — epoll_wait(5, {{EPOLLIN|EPOLLHUP, {u32=16, u64=16}}}, 1024, 847) = 1 epoll_ctl(5, EPOLL_CTL_DEL, 16, 7ffe441aa850) = -1 EBADF (Bad file descriptor) epoll_wait(5, {{EPOLLIN|EPOLLHUP, {u32=16, u64=16}}}, 1024, 845) = 1 epoll_ctl(5, EPOLL_CTL_DEL, 16, 7ffe441aa850) = -1 EBADF (Bad file descriptor) epoll_wait(5, {{EPOLLIN|EPOLLHUP, {u32=16, u64=16}}}, 1024, 843) = 1 epoll_ctl(5, EPOLL_CTL_DEL, 16, 7ffe441aa850) = -1 EBADF (Bad file descriptor)

• Файловый дескриптор здесь 16, и если вы сопоставите его с более ранними ls -l /proc/20584/fd и lsof | grep 2467212, вы поймете, что он относится к только что закрытому соединению MySQL.

Это наводит меня на мысль, что где-то, даже когда соединение с MySQL освобождается, там висит файловый дескриптор, который все еще используется. Я нашел различные темы на форумах с похожими проблемами -

• https://github.com/joyent/libuv/issues/1099
• https://github.com/nodejs/node-v0.x-archive/issues/6271
• https://github.com/joyent/libuv/issues/826