Written by Greed.thread
on March 09, 2021

[Node.js] Mysql2 모듈 사용하여 장시간 켜놓을시 커넥션 예외가 발생하는 이슈

최근 기존 시스템의 DB Connection pool 관련 서버코드를 변경하였는데
이후 몇일 뒤 로컬 환경에서 서버를 켜두고 퇴근을 하고 난 다음날 중지하지 않았던 서버에 request를 요청시 이따금 이상한 오류가 발생하였다.

발생오류

Error: Can't add new command when connection is in closed state

Error: This socket has been ended by the other party

이상하게도 이번에 변경한 코드내에서는 처리한 부분이 connection을 release(반납) 위치만 바꾸었을뿐인데 특별히 발생할 오류는 아닌것 같았다.

에러 내용을 보면

커넥션이 닫힌상테에서는 새로운 명령을 추가 할 수 없다.
이 소켓은 상대측에 의해 종료되었다.

인데 도통 감이 오지 않았다.

괜스레 적용한 코드가 잘 못 되었나 하고 되짚어 보았지만 마땅히 짚히는 구석이 보이진 않았다.

mysql2

우선적으로 생각해보니 이전에 내가 개발하고 운영했던 서비스 서버를 생각해보니 당시에는 nodejs에 mysqljs 모듈을 사용하였고 현재는 mysql2를 사용하고 있다.

mysql2가 가진 기존 mysqljs와의 차이점으로는 크게

더 빠르고 더 나은 성능
promise 지원

가 있고 mysql2의 소개페이지에도 나와 있는데 대부분의 mysqljs 기능을 지원하고 있다고 한다.
(이외에 기능은 사실 mysqljs 기반으로 추가하여 가능한 부분이라서 잘 와닿지가 ㅎ promise도 마찬가지지만. )

특별히 이점이 문제가 될 것처럼 보이지는 않았다.

구글링

일단 오류내용을 google, git issue 페이지에서 찾았다.

node-mysql2: Issues#939

이슈 내용을 보면 굉장히 많은 다른 사용자들이 동일 현상을 겪고 있었고 해결이 되지 않은것 처럼 확인된것으로 보였다.

몇몇은 connection 방식에서 connection pool 방식으로 변경하여 해결이 되었다고 하지만 현재 시스템에서는 이미 connection pool을 사용하고 있었기에 해결방안이 되지 않았다.

또한 두번째 Error: This socket has been ended by the other party 의 경우는 특이하게 mysql2 에서 많이 발생하였고 mysql2 를 기반으로 사용하는 orm 모듈에서도 발생사례가 제보된것이 확인되었다.

~~하지만 이렇다할 해결 방안이나 fix된 내용도 확인되지 않았다.~~

(03-11 추가 여기서부터 삽질시작)

재현

대부분의 경우가 (내 상황과 마찬가지로) 장기간 실행시 idle 상태로 방치하고 연결이 없을때 주로 발생 되는 것으로 확인되었는데 몇가지 재현 스택에 가닥이 잡혀 시도 해보았다.

MYSQL 서버 wait_timeout 값 변경하여 connection 테스트
- mysql 서버내에 wait_timeout 설정을 10~20초로 변경.
- 서버에 request를 요청하여 pool 내에 connection 을 생성/유지
- connection이 wait_timeout 설정을 넘겼을때 오류가 발생하는지?
mysql 서버에서 nodejs 서버에서 맺고있는 thread를 kill
nodejs 서버 또는 mysql 서버측간에 네트워크 강제로 끊기

1,2,3의 모든 경우에도 request 요청시 connection 관련 오류가 발생하지 않았다.

코드 확인

도통 재현이 되지 않으니 찜찜함이 너무 남아서 기존 mysql2 모듈 파일을 확인하고 대략적인 흐름으로 확인해보았다.

  _addCommandClosedState(cmd) {
    // 오류 발생지점
    const err = new Error(
      "Can't add new command when connection is in closed state"
    );
    err.fatal = true;
    if (cmd.onResult) {
      cmd.onResult(err);
    } else {
      this.emit('error', err);
    }
  }
  
  // handleFatal 오류 
  _handleFatalError(err) {
    err.fatal = true;
    // stop receiving packets
    this.stream.removeAllListeners('data');
    this.addCommand = this._addCommandClosedState;
    this.write = () => {
      this.emit('error', new Error("Can't write in closed state"));
    };
    this._notifyError(err);
    this._fatalError = err;
  }

  // handle Network error로 부터 던져졌을것 같음.
  _handleNetworkError(err) {
    if (this.connectTimeout) {
      Timers.clearTimeout(this.connectTimeout);
      this.connectTimeout = null;
    }
    // Do not throw an error when a connection ends with a RST,ACK packet
    if (err.errno === 'ECONNRESET' && this._closing) {
      return;
    }
    this._handleFatalError(err);
  }

조치 (해결이라 쓰면 좋겠으나)

이전 시스템에서 release(반납) 로직이 잘못되어 pool에서 connection을 여러개를 사용하지 못하고 대기하는 현상을 수정한것인데 이번에 release 관련 로직을 수정함으로 유휴 connection이 발생하여 해당 connection 사용시 오류가 발생한것으로 예상되었다.

또 결정적으로 mysql과 mysql2는 다시 가져온 connection 자체가 유효한지 체크 로직 유무가 다르다고 한다.(validate관련 한 로직이 mysql2에는 없다고 함, 정확하지 않음.)

확실하지는 않지만 pool에서 가져온 connection 자체가 문제가 있다면 pool에 반환하지 않고 destroy 시키고 다시 connection을 가져오는 방향으로 로직을 수정하였다.

// <구현 예>
// * 이전 시스템은 async await을 특별히 사용하지 않은 callback방식
// 변경전 
function getConnection(pool, callback) {
    pool.getConnection(function(err, connection) {
        if(err) {
            console.log("getRetryConnection err : " + err);
            // connection 종료처리
            connection.destroy();
            callback(err);
        }
        else {
            callback(null, connection);
        }
    })
}

// 변경후
function getConnection(pool, callback) {
    pool.getConnection(function(err, connection) {
        if(err) {
            console.log("getRetryConnection err : " + err);
            // connection 종료처리
            connection.destroy();

            // 재연결 처리를 1회 다시한번 진행.
            pool.getConnection(function(reConnErr, reConnection) {
                // 재연결시에도 오류가 발생하면 커넥션 파괴 후 error 콜백 반환
                if(reConnErr) {
                    console.log("getRetryConnection retry fail err : " + err);
                    reConnection.destroy();
                    return callback(reConnErr);
                }
                callback(reConnErr, reConnection);
            });
        }
        else {
            callback(null, connection);
        }
    })
}

조금 더 나은 방식이라면 재귀나 참조를 통해 적당한 선에서 n회차 반복처리를 하였으나 장기간 비활성시 종료되었을때라서 1회만 다시 시도해도 문제 없을것 같아 위 같이 처리하였다.

일단은 앞서 발생한 오류가 발생해도 재연결 처리를 하니 문제는 없겠지만… 재현도 안되는데 수정부터 하니 굉장히 마음이 찜찜하다. (내 로컬 PC에서 발생한 것도 아니어서)

추후 더 나은 방향이 있거나 해결방안이 있으면 수정해야지.

해결방안 (03-11 추가 여기서부터 삽질 끝!)

위 처리로 전혀 해결이 되지않았다. 이유는 즉슨

connection 장시간 유휴 상태 이후 connection.getConnection 실행시 오류가 발생하지 않는다.
- getConnection을 재시도하는 의미가 없음
실제 오류 발생하는 위치는 connection.query 를 할때 발생함.
connection.query 이후 오류 2.Error: This socket has been ended by the other party가 발생했을때 transaction 종료 처리를 위해 connection.rollback() 을 시도할 경우 1.Error: Can't add new command when connection is in closed state 가 발생됨.

해결 방안은 pool 설정에 enableKeepAlive: true를 추가

   const pool = mysql.createPool({
         host: 'db',
         user: process.env.MYSQL_USER,
         password: process.env.MYSQL_PASSWORD,
         database: process.env.MYSQL_DATABASE,
         connectionLimit: 2,
         waitForConnections: true,
         queueLimit: 0,
         keepAliveInitialDelay: 10000, // 0 by default.
         enableKeepAlive: true, // false by default.
   });

친절하게도 mysql2 sidorares 개발자가 직접 답변을 달아주셨음. node-mysql2: Issues#1302

we should probably make it default option. Currently when remote side closes the socket the client might not see it, see net.setKeepAlive

기본 옵션으로 설정해야합니다. 현재 원격 측이 소켓을 닫을 때 클라이언트가 소켓을 보지 못할 수 있습니다. net.setKeepAlive를 참조하십시오.

20-03-12 해결됨

Discussion and feedback

← → Top