MySQL 쿼리 속도 측정 npm 패키지 제작기

개인 프로젝트를 진행하던 도중 데이터베이스의 쿼리 실행 시간을 비교할 필요가 생겼습니다. 쿼리 실행 시간 측정 기능을 제공하는 패키지가 당연히 있을 줄 알았지만 찾지 못했고 저와 같은 기능을 찾는 사람들이 많다는 것을 알게 되어 패키지로 제작하게 되었습니다. 패키지 제작 이유부터 중간에 했던 시행착오들을 포함한 패키지 제작과정을 기록해 볼까 합니다.

❗️이 글은 2022년 2월에 작성된 글을 블로그를 리뉴얼하며 다시 작성한 글입니다.

 

노드에서 MySQL 쿼리 실행 속도 측정

MySQL의 쿼리 실행속도를 노드에서 측정하는 법을 검색해 보면 아래와 같은 방법이 나옵니다.

// 시작시간
var start = new Date().getTime();
// 쿼리 실행
connection.query(query, function (err, rows, fields) {
  // 쿼리 종료 후 콜백 실행

  // 종료시간
  var end = new Date().getTime();
  // 쿼리 실행시간 = 종료시간 - 시작시간
  var duration = (end - start) / 1000;
});

굉장히 간단하고 직관적으로 시간을 구할 수 있습니다. 하지만 위에서 구한 시간은 데이터베이스에서 쿼리가 실행되는 데 걸리는 시간이 아닌 노드에서 데이터베이스에 쿼리 실행을 요청하고 응답을 받기까지의 시간입니다. 그렇게 큰 차이가 없을 수도 있지만 저는 다른 요인에 영향을 최대한 줄이고 쿼리가 실행되는 순수한 시간을 비교하고 싶었습니다.

connection.queryInspect(query, function (err, rows, fields, info) {
  console.log(info.duration);
});

위와 같은 기능이 있지 않을까? 라는 생각으로 검색을 해봤지만 찾지 못했고 저와 같은 기능을 찾는 사람들이 많다는 것을 알게되어 패키지로 제작했습니다.

 

MySQL query profiling

가장 먼저 든 생각은 MySQL에서 쿼리 실행속도를 측정하는 방법을 제공할 것이고 노드에서 그 방법을 실행해 쿼리 실행속도 데이터를 받아오면 되겠다는 생각이었습니다. 그 방법을 MySQL 버전을 확인하고 공식문서를 찾아봅시다. 저는 현재 MySQL 8.0.28을 사용하고 있습니다.

MySQL 버전

- Enable profiling

구글링을 해보면 다음과 같은 쿼리가 검색됩니다.

set session profiling = on;
show profiles;
show profile

결과가 잘 나오지만 아까 확인했던 mysql 패키지의 풀 리퀘스트를 보면 위 방법은 MySQL 5.6 버전 즈음 deprecated 되었고 공식문서에서는 Performance Schema 사용을 권장합니다.
쿼리를 실행시키면 Performance Schema에 쿼리의 성능 관련 정보가 저장되고 저장된 정보를 읽어 쿼리의 실행속도를 확인할 수 있습니다. 먼저 현재 유저의 행위에 대한 실행 정보를 Performance Schema에 저장하도록 설정해야 합니다.

-- master(root) 계정에서 특정 계정(cloer)에 performance_schema 권한 부여
GRANT SELECT ON performance_schema.* TO 'cloer'@'localhost';

-- setup_actors 확인
SELECT * FROM performance_schema.setup_actors;
-- 기본 행을 수정해 포그라운드 스레드의 모든 이벤트를 기록하지 않도록 수정
UPDATE performance_schema.setup_actors
SET ENABLED = 'NO', HISTORY = 'NO'
WHERE HOST = '%' AND USER = '%';
-- 특정 계정(cloer)이 실행하는 쿼리를 모니터링 하고 기록하는 행 추가
INSERT INTO performance_schema.setup_actors
(HOST,USER,ROLE,ENABLED,HISTORY)
VALUES('localhost','cloer','%','YES','YES');

-- statement와 stage 측정을 활성화
UPDATE performance_schema.setup_instruments
SET ENABLED = 'YES', TIMED = 'YES'
WHERE NAME LIKE '%statement/%';
UPDATE performance_schema.setup_instruments
SET ENABLED = 'YES', TIMED = 'YES'
WHERE NAME LIKE '%stage/%';
UPDATE performance_schema.setup_consumers
SET ENABLED = 'YES'
WHERE NAME LIKE '%events_statements_%';
UPDATE performance_schema.setup_consumers
SET ENABLED = 'YES'
WHERE NAME LIKE '%events_stages_%';

이제 cloer계정으로 접속해 쿼리를 실행해 보면 performance_schema에 쿼리 실행정보가 저장되는 것을 확인할 수 있습니다.

-- 쿼리 실행
SELECT * FROM User2 WHERE userId=3;

-- 쿼리 실행시간 확인
SELECT EVENT_ID, TRUNCATE(TIMER_WAIT/1000000000000,6) as Duration, SQL_TEXT
FROM performance_schema.events_statements_history_long
WHERE SQL_TEXT like '%userId=3%';

실행 결과

이제 위 쿼리를 노드에서 데이터베이스로 요청하고 응답을 받으면 노드에서 데이터베이스의 쿼리 실행시간을 확인할 수 있을 것입니다.

 

구현

- 시행착오 1

별거 없네 싶었을 때 문제가 생겼습니다. 노드에서 위 쿼리를 데이터베이스에 요청하고 받은 응답이 파싱이 안 됐습니다.(이 이유와 해결 방법은 시행착오 2에서 다룹니다.) 원인을 찾지 못해 생각해 낸 방법이 응답을 노드에서 직접 받는 것이 아니라 MySQL이 결과를 csv파일로 저장하고 노드에서 csv파일을 읽어오는 방법이었습니다.

# MySQL에서 csv파일로 쿼리 결과 저장하기

MySQL은 기본적으로 --secure-file-priv옵션으로 실행됩니다. 이 옵션은 MySQL이 파일을 읽고 쓸 수 있는 디렉터리를 제한하는 옵션으로 secure_file_priv 시스템 변수로 설정된 디렉터리에만 파일만 읽고 쓸 수 있습니다.

-- 현재 설정된 경로(secure_file_priv) 확인
SHOW VARIABLES LIKE "secure_file_priv";

저의 경우 null로 설정되어 있었습니다. secure_file_priv를 수정하기 위해서는 my.cnf파일을 수정해야 합니다. my.cnf파일을 수정한 뒤 mysql을 재시작해줍니다.

mysql --help | grep my.cnf
vim /opt/homebrew/etc/my.cnf
mysql.server restart

테스트로 csv파일을 저장해 보겠습니다.

-- csv파일 저장
SELECT * FROM User2 WHERE userId=3
INTO OUTFILE '{설정한 경로}/user.csv'
FIELDS TERMINATED BY ','
ENCLOSED BY '"'
LINES TERMINATED BY '\n';

csv파일이 잘 저장되었습니다. 이제 실행시간을 저장해 보겠습니다.

-- 쿼리 실행시간 저장
SELECT EVENT_ID, TRUNCATE(TIMER_WAIT/1000000000000,6) as Duration, SQL_TEXT
FROM performance_schema.events_statements_history_long
WHERE SQL_TEXT like '%userId=3%'
INTO OUTFILE '{설정한 경로}/test.csv'
FIELDS TERMINATED BY ','
ENCLOSED BY '"'
LINES TERMINATED BY '\n';

이제 노드에서 MySQL에 쿼리 실행정보를 검색하고 결과를 csv파일로 저장하는 쿼리를 날려보겠습니다.

require('dotenv').config();
const path = require('path');
const db = require('mysql2/promise');

const testNo = 10;

(async () => {
  try {
    const conn = await db.createConnection({
      host: 'localhost',
      user: process.env.DB_USER,
      password: process.env.DB_PASSWORD,
      database: process.env.DB_NAME,
      multipleStatements: true,
    });

    for (let i = 0; i < testNo; i++) {
      const testUserId = Math.ceil(Math.random() * 10000);

      const [[{ local: testLocal, domain: testDomain }]] = await conn.query(
        `SELECT local, domain FROM User2 WHERE userId=?;`,
        testUserId
      );
      console.log(`${testUserId}: ${testLocal}${testDomain}`);
    }
    const result = await conn.query(
      `SELECT * FROM (
      SELECT 'EVENT_ID','Duration','SQL_TEXT'
      UNION ALL
      ( 
        SELECT EVENT_ID, TRUNCATE(TIMER_WAIT/1000000000000,6) as Duration, SQL_TEXT
        FROM performance_schema.events_statements_history_long 
        WHERE SQL_TEXT like '%where userId=%')
      ) a
      INTO OUTFILE '${path.join(process.env.SECURE_FILE_PRIV, 'test.csv')}'
      FIELDS TERMINATED BY ','
      ENCLOSED BY '"'
      LINES TERMINATED BY '
      ';`
    );
    conn.end();
    console.log('Test done.');
  } catch (err) {
    console.error(new Error('DB ERROR--------------------'));
    console.error(err);
  }
})();

# 노드로 csv파일 읽기

이제 저장한 csv파일을 노드에서 읽어오면 됩니다.

require('dotenv').config();
const { open } = require('fs').promises;
const path = require('path');
const parser = require('csv-parser');

(async () => {
  const results = [];
  const file = await open(path.join(process.env.SECURE_FILE_PRIV, 'test.csv'));
  file
    .createReadStream()
    .pipe(parser())
    .on('data', (data) => results.push(data))
    .on('end', () => console.log(results));
})();

- 시행착오 2

쿼리 실행 정보를 얻는 쿼리를 보면, 설정된 사용자의 액션을 performance_schema의 events_stages_history_long에 저장하고 쿼리를 이용해 액션을 검색하여 원하는 쿼리의 실행정보를 가져옵니다. 하지만 노드에서 MySQL과 생성한 커넥션은 프로젝트를 진행하며 만든 스키마이다. 프로젝트 스키마에 커넥션을 만들고 performance_schema에 쿼리를 날렸으니 오류가 발생했던 것이다. 실험을 위해 createConnection객체에 속성을 database: 'performance_schema'로 수정하고 실행해 보면 csv파일을 거치지 않고 결과를 얻어올 수 있었습니다.

require('dotenv').config();
const path = require('path');
const db = require('mysql2/promise');

const testNo = 10;

(async () => {
  try {
    const conn = await db.createConnection({
      host: 'localhost',
      user: process.env.DB_USER,
      password: process.env.DB_PASSWORD,
      database: 'performance_schema', // 수정
      multipleStatements: true,
    });
    const [result] = await conn.query(
      `SELECT EVENT_ID, TRUNCATE(TIMER_WAIT/1000000000000,6) as Duration, SQL_TEXT
      FROM performance_schema.events_statements_history_long WHERE SQL_TEXT like '%userId=%';`
    );
    conn.end();
    console.log(result);
    console.log('Test done.');
  } catch (err) {
    console.error(new Error('DB ERROR--------------------'));
    console.error(err);
  }
})();

 

NPM 패키지 제작

쉽게 node에서 MySQL의 performance_schema에서 쿼리 실행 시간을 읽어올 수 있도록 npm 패키지로 제작했습니다. typescript를 위해 타입을 추가하고 권한 설정을 해주는 giveGrants함수는 만들었지만 마스터 계정을 이용해야 하고 권한을 해제도 해야 해서 삭게 했습니다.
npm: mysql-query-time
github: mysql-query-time

+ Update(2022-02-20)

이틀 만에 생각보다 많은 사람들이 다운을 받았고 편리성을 위해 삭제했던 권한 설정을 해주는 giveGrants함수를 setMysql이라는 함수로 추가했습니다.