Knex를 이용해서 MySQL에 접속해 쿼리를 실행시킬 수 있고 스키마나 데이터를 변경할 수 있다. 아주 편리한 이 라이브러리는 커넥션풀 또한 지원하고 있으며 직접적이진 않지만 응답시간을 체크할 수도 있다. 바로 쿼리 실행 시, 종료 시 호출될 콜백함수를 등록할 수 있기 때문이다. 이런 식으로 사용하는 것이 최선인지는 잘 모르겠지만 개발과정과 프로덕션 운영 중 발생한 문제를 해결하는데 큰 도움이 됐기에 정리해봤다.
구현
우선 HTTP 서버를 생성했다.
1 2 3 4 5 6 7 8 9 | const server = http.createServer(async (req, res) => { res.writeHead(200, {'Content-Type': 'text/html'}) const q = url.parse(req.url, true).query const userId = q.user_id const { id, title, firstName, surname, dateOfBirth } = await getUser({ userId }) res.write(`Found user: ID: ${title} ${surname} ${firstName} ${dateOfBirth}`) res.end() }) server.listen(serverPortNo) | cs |
db-conn.js 파일을 생성하고 knex 객체를 생성한다.
1 2 3 4 5 6 7 8 9 10 11 12 13 14 | const db = knex({ client: 'mysql', connection: { timezone: 'UTC', host: process.env.SERVICE_MYSQL_ADDRESS, user: process.env.SERVICE_MYSQL_USER, password: process.env.SERVICE_MYSQL_PASSWORD, database: process.env.SERVICE_MYSQL_DATABASE }, pool: { min: parseInt(process.env.KNEX_POOL_MIN, 10) || 2, max: parseInt(process.env.KNEX_POOL_MAX, 10) || 10 } }) | cs |
knex 객체에 쿼리 실행 시 호출될 함수를 정의하고 등록한다.
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 | const queries = {} let count = 0 const onQuery = query => { if (count > knexTrackingConnMaxCnt) count = 0 const uid = query.__knexQueryUid queries[uid] = { position: count, method: query.method, sql: query.sql, queriedAt: new Date().getTime() } count += 1 } db.on('query', onQuery) | cs |
쿼리가 실행되면 쿼리의 ID를 queries 객체에 키로 저장하며 값으로는 로그로 사용할 수 있는 값들을 넣었다. queriedAt 프로퍼티는 종료 시 시간과의 차이를 구할 때 사용한다. 얼마나 많은 쿼리가 누적이 될지 알 수 없기 때문에 tracking connection의 최대값을 설정했다.
knex 객체에 쿼리 종료 시 호출될 함수를 정의하고 등록한다.
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 | const onQueryResponse = (response, query) => { const uid = query.__knexQueryUid if (queries[uid]) { const diff = new Date().getTime() - queries[uid].queriedAt if (diff > knexResponseTimeThresholdMsec) { const perfLog = { position: queries[uid].position, method: queries[uid].method, sql: queries[uid].sql, diff } console.log(`RESPONSE_TIME: ${diff} ms > ${knexResponseTimeThresholdMsec}`, perfLog) } delete queries[uid] } } db.on('query-response', onQueryResponse) | cs |
쿼리가 종료될 때 query의 ID를 키로하여 queries 객체에서 값을 찾아 종료 시간과 queriedAt 차이를 구해 설정된 threshold와 비교한다. 시간이 초과된 경우 데이터를 화면에 출력한다.
테스트
다음의 명령을 실행해서 필요한 패키지를 설치하고 서버를 실행한다.
npm i
npm start
메시지를 서버로 전송하기 위해 cURL을 이용한다.
curl -i "http://localhost:8080/?user_id=3"
결과 확인
유저 정보를 읽는 단순한 쿼리는 수 ms 내에 처리되기 때문에 로그를 볼 수 없다. 그래서 KNEX_RESPONSE_TIME_THRESHOLD_MSEC=1로 설정한 뒤 cURL 명령을 실행하여 로그가 출력되는 것을 확인했다.
RESPONSE_TIME: 3 ms > 1 { position: 0,
method: 'select',
sql: 'select `id`, `title`, `first_name`, `surname`, `date_of_birth` from `users` where `id` = ?',
diff: 3 }
예제이기 때문에 화면에 출력하도록 했지만 실제로는 로그파일에 쓰거나 또는 ElasticSearch에 로그를 전송해서 데이터 분석이나 성능 튜닝에 사용할 수 있다. Busy hour인 경우에는 Slack에 바로 메시지를 전송해 백앤드 엔지니어들을 괴롭힐 수도 있다.
이 예제에서는 dotenv 라이브러리를 이용해서 .env 파일에 저장된 변수들을 사용했다. 그리고 예로 든 db_user 데이터베이스에 users 테이블이 존재한다고 가정했다. 테이블을 생성하는 방법은 간단하니 여기에서는 패스하기로.
전체 소스 코드는 이 곳에서 확인할 수 있다.
https://github.com/ksleeq21/knex-response-time
