mysql2 wait_timeout 이슈 트래킹하기
본 글은 typeorm과 mysql2를 사용하며 겪었던 MySQL wait_timeout 관련 문제의 원인을 분석하고 해결 방안을 제시합니다.
Contents
MySQL 시스템 변수
이 글에서는 MySQL 시스템 변수 설정에 관련된 내용이 등장한다. 아래의 timeout 관련 시스템 변수를 이해하고 있으면, 이 글을 더 이해하기 쉽다.
| name | description | document |
| --- | --- | --- |
| wait_timeout | The number of seconds the server waits for activity on a noninteractive connection before closing it. | MySQL Document |
| interactive_timeout | The number of seconds the server waits for activity on an interactive connection before closing it. An interactive client is defined as a client that uses the CLIENT_INTERACTIVE option to mysql_real_connect(). | MySQL Document |
배경
회사에서 typeorm + mysql2 라이브러리로 여러 프로젝트에서 개발을 진행하고 있었는데, DB 로그에서 다음과 같은 에러들이 종종하는 발생하였다.
2024-04-16T03:15:48.671083Z 22 [Note] [MY-013730] [Server] 'wait_timeout' period of 10 seconds was exceeded for `root`@`localhost`. The idle time since last command was too long.
2024-04-16T03:15:48.673402Z 22 [Note] [MY-010914] [Server] Aborted connection 22 to db: 'testdb' user: 'root' host: 'localhost' (The client was disconnected by the server because of inactivity.).
MySQL 서버에서는 wait_timeout 이 180초로 설정되어 있었는데, 어플리케이션 단의 timeout 이 이보다 길어서 나타나는 현상으로 추측하였다.
예를 들어, 다음과 같은 상황을 가정해 보자. Connection Pool Size 가 2인 상황에서, 기본적으로 Connection Pool 은 Database Connection 2개를 소유하고 있다. Connection Pool 의 idle timeout 은 360초이고, MySQL 의 wait_timeout 은 180초이다.

이 때에, 서버에 트래픽이 없어 Database Connection 에도 요청이 없는 경우, Connection 들은 Sleep 상태가 된다. 만약 Sleep 상태가 된 후 wait_timeout(180초) 만큼의 시간이 지날 경우, Database 는 해당 Connection 자원을 자동으로 해제시킨다.

즉, MySQL 서버에서는 Connection 자원을 해제시켰지만, 실제 Connection Pool 에서는 해제하지 않는 상황이 올 수 있는 것이다. 이와 다르게, Connection Pool 의 idle timeout 값이 wait_timeout 변수보다 작은 값일 때를 생각해 보자.

아까와 동일한 상황이지만, Connection Pool 의 idle timeout 만 170초로 변동된 상황이다. 동일하게 서버 트래픽이 없어 Database Connection 에도 요청이 없는 경우, Connection 들은 Sleep 상태가 된다. 만약 Sleep 상태가 된 후 idle timeout(170초) 만큼의 시간이 지날 경우, Connection Pool 은 Database Connection 자원을 반납한다.

첫 번째 예시와 다른 점은, 전자에서는 MySQL 이 직접 Connection 자원을 회수한 데에 비해, 후자의 경우에는 Connection Pool 이 MySQL 에 자원을 반납한 상황이다. 결과적으로, MySQL 입장에서는 wait_timeout 이 발생하지 않게 된다.
따라서, 어플리케이션 단의 timeout 기간이 MySQL 서버의 wait_timeout 보다 길게 설정하면 해결될 문제라고 단순히 생각하고, 소스코드를 살펴보았다. 하지만 소스코드를 살펴보았더니, MySQL Connection Pool 설정에서, idleTimeout 등과 같은 설정값은 없었다. 팀에서 사용하고 있는 ORM, DB Driver 의 기본 설정값으로 해당 설정값이 세팅되었을 것이라 생각하였다.
typeorm, 그리고 mysql2
팀에서 운영중인 서버에서는 DB 관련 라이브러리로 typeorm (ORM), mysql2 (DB Driver) 를 사용하고 있다. typeorm 을 통해 DataSource 를 생성하는 예시 코드를 살펴보자.
import { DataSource } from "typeorm"
const AppDataSource = new DataSource({
    type: "mysql",
    host: "localhost",
    port: 3306,
    username: "test",
    password: "test",
    database: "testdb",
})
AppDataSource.initialize()
    .then(() => {
        console.log("Data Source has been initialized!")
    })
    .catch((err) => {
        console.error("Error during Data Source initialization", err)
    })
위의 예시 코드에서, Connection Pool 에 대한 설정은 찾을 수 없다. typeorm 에서 MySQL 을 연결하여 사용하려면, mysql2 라이브러리를 사용하는데, mysql2 공식 문서 에서는 다음과 같이 Connection Pool 을 생성할 수 있었다.
import mysql from 'mysql2/promise';
// Create the connection pool. The pool-specific settings are the defaults
const pool = mysql.createPool({
  host: 'localhost',
  user: 'root',
  database: 'testdb',
  waitForConnections: true,
  connectionLimit: 10,
  maxIdle: 10, // max idle connections, the default value is the same as `connectionLimit`
  idleTimeout: 60000, // idle connections timeout, in milliseconds, the default value 60000
  queueLimit: 0,
  enableKeepAlive: true,
  keepAliveInitialDelay: 0,
});
typeorm 에 위의 설정대로 mysql2 연결을 시도하려면, extras 파라미터를 이용하여 설정할 수 있다.
import { DataSource } from "typeorm"
const AppDataSource = new DataSource({
    type: "mysql",
    host: "localhost",
    port: 3306,
    username: "test",
    password: "test",
    database: "testdb",
    extras: {
      idleTimeout: 170 * 1000,
      maxIdle: 0,
    }
})
하지만 눈여겨 볼 점은, mysql2 라이브러리의 default idle timeout 값은 60000 (60초) 였다. MySQL 서버의 wait_timeout 이 180초로 설정되어 있었기 때문에, MySQL 서버에서는 timeout 이슈가 발생하지 않았어야 한다. 그렇다면 왜 MySQL 서버에서는 wait timeout 이 발생하게 되었을까 ?
mysql2 의 함정
발생하고 있는 현상이 이해가 되지 않아, 어플리케이션 레이어에서 가장 DB 와 가까운 mysql2 라이브러리를 살펴보기로 했다. 다음의 두 코드를 살펴보면, mysql2 의 Connection Pool 이 언제 자원을 회수시키는지 알 수 있다.
  constructor(options) {
    super();
    this.config = options.config;
    this.config.connectionConfig.pool = this;
    this._allConnections = new Queue();
    this._freeConnections = new Queue();
    this._connectionQueue = new Queue();
    this._closed = false;
    // maxIdle 이 connectionLimit 보다 작을 때에만 removeIdleTimeoutConnections 함수가 호출된다.
    if (this.config.maxIdle < this.config.connectionLimit) {
      // create idle connection timeout automatically release job
      this._removeIdleTimeoutConnections();
    }
  }
  _removeIdleTimeoutConnections() {
    if (this._removeIdleTimeoutConnectionsTimer) {
      clearTimeout(this._removeIdleTimeoutConnectionsTimer);
    }
    this._removeIdleTimeoutConnectionsTimer = setTimeout(() => {
      try {
        while (
          // 사용 가능한 Connection 의 갯수가 maxIdle 값보다 크고
          this._freeConnections.length > this.config.maxIdle &&
          // Connection 이 Sleep 상태에 빠진 시간이 idleTimeout 보다 클 때
          Date.now() - this._freeConnections.get(0).lastActiveTime >
            this.config.idleTimeout
        ) {
          // Connection 자원을 회수한다.
          this._freeConnections.get(0).destroy();
        }
      } finally {
        // 재귀적으로 자기 자신을 호출시킨다. 
        this._removeIdleTimeoutConnections();
      }
    }, 1000);
  }
위의 코드를 살펴봤듯이, mysql2 의 maxIdle 변수와 connectionLimit 값이 로직에 중요한 역할을 미친다. 어플리케이션 코드에서는 별도의 maxIdle, connectionLimit 변수값이 세팅되어 있지 않았다. 그렇다면 maxIdle 과 connectionLimit 의 default 값이 무엇인지 살펴보아야 한다. mysql2 공식 문서 를 살펴보면, maxIdle=10 , connectionLimit=10 으로 세팅되어 있었다.
// Create the connection pool. The pool-specific settings are the defaults
const pool = mysql.createPool({
  host: 'localhost',
  user: 'root',
  database: 'test',
  waitForConnections: true,
  connectionLimit: 10,
  maxIdle: 10, // max idle connections, the default value is the same as `connectionLimit`
  idleTimeout: 60000, // idle connections timeout, in milliseconds, the default value 60000
  queueLimit: 0,
  enableKeepAlive: true,
  keepAliveInitialDelay: 0,
});
소스코드를 바탕으로 보았을 때, mysql2 의 디폴트 세팅으로는 Connection Pool 이 Connection Pool 자원을 회수시키지 않는다는 사실을 알 수 있다. 이 코드를 확인한 후, 믿기지 않아서 실제로 동작이 그러한지 간단한 코드로 검증해 보기로 하였다.
먼저, 테스트의 용이성을 위해 로컬 MySQL 서버의 idle_timeout 값을 10초로 조정하였다. 로컬 mysql 설정 파일을 찾아들어가, [mysqld] 섹션에 다음과 같은 코드를 추가하였다.
[mysqld]
idle_timeout=10
interactive_timeout=10
log_error_verbosity=4
이후에 로컬 MySQL 서버를 재기동 한 후, 다음과 같이 설정값을 확인해 볼 수 있다.
-- 결과값으로 10이 나오면, 정상적으로 세팅된 것이다.
select @@global.wait_timeout, @@session.wait_timeout, @@global.interactive_timeout, @@session.interactive_timeout;
이후에, 다음과 같은 샘플 코드를 작성한 후 시도해본다.
import { DataSource } from "typeorm";
import { dbLog } from "./log";
import { sleep, toMilleSeconds } from "./util";
/**
 * Mysql Database 는 다음과 같은 세팅이 필요하다.
 *
 * set wait_timeout=10;
 * show variables like 'wait_timeout';
 */
const MYSQL_WAIT_TIMEOUT = 10;
async function main() {
  await withConnection(async (dataSource: DataSource) => {
    // MYSQL DB 에 설정된 wait_timeout 보다 긴 값을 sleep한다.
    // 정상적인 경우, wait_timeout 보다 긴 시간을 대기하면, 
    // Connection Pool 에서는 idle timeout 보다 오래된 Connection 들의 자원을 해제한 후, 다시 Connection 을 수립해야 한다
    await sleep(toMilleSeconds(MYSQL_WAIT_TIMEOUT + 2));
    await ping(dataSource);
  });
}
/**
 * MySQL Connection 이 유효한지 검사한다.
 *
 * @param dataSource - typeorm DataSource
 */
async function ping(dataSource: DataSource): Promise<boolean> {
  await dataSource.query("SELECT 1");
}
/**
 * MySQL 과 연결을 맺고, 원하는 로직을 수행한 후 연결을 해제시킨다
 *
 * @param fn - callback
 */
async function withConnection<T>(fn: (dataSource: DataSource) => Promise<T>) {
  const dataSource = createDataSource();
  await dataSource.initialize();
  dbLog("MySQL Connected");
  try {
    return await fn(dataSource);
  } finally {
    dbLog("MySQL Connection Closed");
    await dataSource.destroy();
  }
}
/**
 * TypeORM MySQL DataSource 를 생성한다
 *
 * @returns DataSource
 */
function createDataSource(): DataSource {
  return new DataSource({
    type: "mysql",
    host: "localhost",
    port: 3306,
    username: "root",
    password: "password",
    database: "testdb",
    entities: [],
    poolSize: 10,
    logging: true,
    extra: {
      /**
       * typeorm default 는 60000ms 이다
       */
      idleTimeout: toMilleSeconds(MYSQL_WAIT_TIMEOUT / 2),
      /**
       * mysql2 기본 설정에서, maxIdle 과 connectionLimit 은 모두 10으로 세팅된다.
       * 그런데, maxIdle 과 connectionLimit 이 같은 경우, Connection Pool 에서 세션을 반환하지 않는 이슈가 있다.
       *
       * 실제 Production 환경에서는 maxIdle 값이 0으로 설정되어야, 올바르게 자원이 회수된다.
       * 단, 오랜 기간동안 DB 와의 통신이 없는 경우, Connection Pool 에 Connection 이 0개로 설정되어, DB 와의 연결을 맺는 시간이 소요될 수 있다.
       *
       * @see - https://github.com/sidorares/node-mysql2/blob/6dccf5503fb3e564ba87749dc8b1ea38907caf90/lib/pool.js#L30-L32
       * @see - https://github.com/sidorares/node-mysql2/blob/6dccf5503fb3e564ba87749dc8b1ea38907caf90/lib/pool.js#L202-L208
       *
       * @remarks
       * typeorm 이 아닌 MikroORM 을 사용할 때에는 해당 이슈가 발생하지 않음. MikroORM 에서는 tarn.js 라는 자원 관리 라이브러리를 사용하는데 (JVM 의 HikariCP 와 유사), 해당 라이브러리의 자원 회수 로직은 위의 경우에도 올바르게 자원이 회수되게 로직이 작성되어 있음
       *
       * @see - https://github.com/Vincit/tarn.js/blob/e33d223831367a264db33e35d4c9381a089e539c/src/Pool.ts#L252-L260
       */
      // maxIdle: 0,
    },
  });
}
main();
위의 코드는 고의적으로 MySQL 서버의 wait_timeout 보다 오랜 시간을 sleep 한 후, MySQL 서버에 PING 쿼리를 날리는 샘플 코드이다. 위의 코드를 실행시키면, LIVE 환경에서 발생했던 로그가 로컬 MySQL 서버의 로그 파일에서 발견할 수 있었다.
2024-04-16T03:15:48.671083Z 22 [Note] [MY-013730] [Server] 'wait_timeout' period of 10 seconds was exceeded for `root`@`localhost`. The idle time since last command was too long.
2024-04-16T03:15:48.673402Z 22 [Note] [MY-010914] [Server] Aborted connection 22 to db: 'testdb' user: 'root' host: 'localhost' (The client was disconnected by the server because of inactivity.).
그렇다면, 위의 현상은 어떻게 하면 해결할 수 있을까 ? 
위의 테스트코드에서 maxIdle 옵션 값을 0 으로 세팅하면 된다. 즉, maxIdleTimeout 시간이 초과하면, 항상 MySQL 서버에 Connection 을 회수시키면 되는 것이다. 
MikroORM 은 어떨까 ?
최근에 typeorm 을 대체할 Node.js ORM 라이브러리를 찾고 있었는데, 그 중 괜찮다고 생각했던 라이브러리가 MikroORM 이었다. JVM 계열의 Hibernate 라이브러리와 유사한 동작을 하고, 최근까지 활발하게 코드 개선 작업이 이루어지고 있는 라이브러리이기 때문이다. 이번 이슈를 겪으면서, MikroORM 에서는 어떻게 Connection Pool 관리를 하고 있는지 궁금해졌다.
MikroORM 은 내부적으로 tarn.js 를 사용하고 있다. JVM 으로 치자면, HikariCP 와 비슷한 역할을 하는 라이브러리이다. 물론 라이브러리의 완성도는 HikariCP 가 훨씬 높을 것 같다. tarn.js 에서 Connection Pool 에 자원을 회수시키는 코드를 살펴보았다.
    const timestamp = now();
    const newFree: Resource<T>[] = [];
    const minKeep = this.min - this.used.length;
    // 최대로 회수할 수 있는 Connection 의 갯수
    const maxDestroy = this.free.length - minKeep;
    let numDestroyed = 0;
    this.free.forEach(free => {
      if (
        // Sleep 상태에 빠진 Connection 이 idleTimeoutMillis 이상으로 쉬고 있고
        duration(timestamp, free.timestamp) >= this.idleTimeoutMillis &&
        // 회수한 Connection 갯수가 최대로 회수할 수 있는 Connection 의 갯수보다 작은 경우
        numDestroyed < maxDestroy
      ) {
        numDestroyed++;
        this._destroy(free.resource);
      } else {
        newFree.push(free);
      }
    });
웃기긴 하지만, 이번 일을 겪으면서 MikroORM + tarn.js 에 대한 신뢰가 더 상승하였다.
참고문서
MySQL의 timeout 설정 mysql2 Github Repository tarn.js Github Repository MySQL 8.0 공식문서 MikroORM 공식문서
이것도 읽어보세요