[Mysql] RDS slow 쿼리 slack 알람 전송

전형빈·2022년 12월 23일
1

DB

목록 보기
3/6
post-thumbnail

사내에는 그룹사 클라우드 비용을 정산하고 관리하는 시스템이 존재한다. DB로 Mysql RDS를 사용하고 있는데 그룹사 계정, 계정 별 서비스 데이터를 입력하기 때문에 정말 많은 데이터 입출력이 발생한다.

시스템도 오래되었고 쿼리 속도도 느려 slow query를 모니터링하고 개선해보고자 slow query 모니터링 시스템을 구축해보았다.

현재 쿼리 관련 로그는 cloudwatch의 로그 그룹에 저장되고 있는데 지정한 시간을 초과하여 수행된 쿼리에 대해 람다를 통해 slack으로 전송하려고 한다. 물론 aws console에서 slow query를 확인하고 필터링할 수 있지만 매번 그러기엔 상당히 번거로운 일이 아닐수가 없다.


RDS에서 slow query 설정

우선 slow query의 log를 남기기 위해 RDS 인스턴스에 할당할 파라미터 그룹에서 파라미터를 설정해야한다.

  • long_query_time = 4 (4초 넘게 실행되는 쿼리들에 대한 로그)
  • slow_query_log = 1 (로그를 남기지 않으려면 0 남기려면 1)
  • slow_query_log_file = slow query log가 저장되는 경로
  • 추가로 log_output을 FiLE로 지정해야 파일형식으로 로그가 저장된다.

설정 후 저장하면 자동으로 DB가 재부팅된다. 만약 단일 DB를 사용중이라면 재부팅되는 동안 서비스가 정지될 수 있으니 주의하자!!!!!!!!!!!!!!!!!!!


slow query 테스트

RDS 인스턴스 재부팅이 끝나고 4초가 넘는 쿼리를 실행해 보자
CloudWatch 실행된 쿼리에 대한 로그는 Cloudwatch 로그 그룹 /aws/rds/instance/billdb/slowquery에서 확인할 수 있다.


Lambda 함수 생성

Cloudwatch에서 실시간으로 보내주는 로그를 파싱해서 slack으로 보내주는 lambda 함수를 생성해야 한다. Cloudwatch와 연동해야 기능이 작동되지만 미리 lambda를 생성해두고 연동해주기로 하자

slack으로 알람을 보내려면 slack webhook을 생성해야 하는데 호돌맨님의 Slack Webhook API 생성하기를 보면 아주 상세히 설명되어 있으니 참고하도록 하자


Lambda 함수 코드 작성

아래는 호돌맨님의 PostgreSQL 코드이다. 이 코드를 Mysql 정규식으로 바꾸고 약간 커스텀해서 사용했다.

const https = require('https');
const zlib = require('zlib');
const SLOW_TIME_LIMIT = 3; // 3초이상일 경우 슬랙 발송
const SLACK_URL = '슬랙 Webhook URL';

exports.handler = (input, context) => {
    var payload = Buffer.from(input.awslogs.data, 'base64');
    zlib.gunzip(payload, async(e, result) => {
        
        if (e) { 
            context.fail(e);
        } 
        
        const resultAscii = result.toString('ascii');
        
        let resultJson;

        try {
            resultJson = JSON.parse(resultAscii);
        } catch (e) {
            console.log(`[알람발송실패] JSON.parse(result.toString('ascii')) Fail, resultAscii= ${resultAscii}`);
            context.fail(e);
            return;
        }
        
        console.log(`result json = ${resultAscii}`);
        
        for(let i=0; i<resultJson.logEvents.length; i++) {
            const logJson = toJson(resultJson.logEvents[i], resultJson.logStream);
            console.log(`logJson=${JSON.stringify(logJson)}`);
        
            try {
                const message = slackMessage(logJson);
                
                if(logJson.queryTime > SLOW_TIME_LIMIT) {
                    await exports.postSlack(message, SLACK_URL);
                }    
            } catch (e) {
                console.log(`slack message fail= ${JSON.stringify(logJson)}`);
                return;
            }

        }
    });
};

function toJson(logEvent, logLocation) {
    const message = logEvent.message;
    
    const currentTime = toYyyymmddhhmmss(logEvent.timestamp);
    const dateTimeRegex = new RegExp('(\\d{4})-(\\d{2})-(\\d{2}) (\\d{2}):(\\d{2}):(\\d{2}) UTC:');
    const matchArray = message.match(dateTimeRegex);
    const removedUtcMessage = message.replace(matchArray[0], '');
    const messages = removedUtcMessage.split(':');
    const timeSplit = messages.length>6? messages[5].trim().split(' '): [];
    const queryTime = timeSplit.length>1? (Number(timeSplit[0]) / 1000).toFixed(3): 0;
    const querySplit = message.split('\<unnamed\>\:');

    return {
        "currentTime": currentTime,
        "logLocation": logLocation,
        "userIp": messages[0].trim(),
        "user": messages[1].trim(),
        "pid": messages[2].trim().replace('[', '').replace(']', ''),
        "queryTime": queryTime,
        "query": querySplit[querySplit.length-1].trim()
    }
}

// 타임존 UTC -> KST
function toYyyymmddhhmmss(timestamp) {

    if(!timestamp){
        return '';
    }

    function pad2(n) { return n < 10 ? '0' + n : n }

    var kstDate = new Date(timestamp + 32400000);
    return kstDate.getFullYear().toString()
        + '-'+ pad2(kstDate.getMonth() + 1)
        + '-'+ pad2(kstDate.getDate())
        + ' '+ pad2(kstDate.getHours())
        + ':'+ pad2(kstDate.getMinutes())
        + ':'+ pad2(kstDate.getSeconds());
}

function slackMessage(messageJson) {
    const title = `[${SLOW_TIME_LIMIT}초이상 실행된 쿼리]`;
    const message = `언제: ${messageJson.currentTime}\n로그위치:${messageJson.logLocation}\n계정: ${messageJson.user}\n계정IP: ${messageJson.userIp}\npid: ${messageJson.pid}\nQueryTime: ${messageJson.queryTime}초\n쿼리: ${messageJson.query}`;
    
    return {
        attachments: [
            {
                color: '#2eb886',
                title: `${title}`,
                fields: [
                    {
                        value: message,
                        short: false
                    }
                ]
            }
        ]
    };
}

exports.postSlack = async (message, slackUrl) => {
    return await request(exports.options(slackUrl), message);
}

exports.options = (slackUrl) => {
    const {host, pathname} = new URL(slackUrl);
    return {
        hostname: host,
        path: pathname,
        method: 'POST',
        headers: {
            'Content-Type': 'application/json'
        },
    };
}

function request(options, data) {

    return new Promise((resolve, reject) => {
        const req = https.request(options, (res) => {
            res.setEncoding('utf8');
            let responseBody = '';

            res.on('data', (chunk) => {
                responseBody += chunk;
            });

            res.on('end', () => {
                resolve(responseBody);
            });
        });

        req.on('error', (err) => {
            console.error(err);
            reject(err);
        });

        req.write(JSON.stringify(data));
        req.end();
    });
}

이제 Cloudwatch와 연동만 하면 된다.

RDS mysql의 로그 그룹에서 위에서 생성한 람다를 등록해준다. 위에서 생성한 람다 함수를 지정해준다. 구독 필터 이름이 없으면 생성이 불가능하니 식별 가능한 이름으로 생성해준다. 추가로 구독 필터 패턴을 사용하여 필터링하면 더 효율적으로 사용 가능하니 필요하다면 추가해주도록 한다.
구독을 활성화 시키면 아래와 같이 로그 그룹 그룹 필터에 1개의 구독이 추가된 것을 볼 수 있다.
이제 마지막으로 slack에 알람이 가는지 확인해보면 된다.
이렇게 슬랙으로 정식 알람이 오면 끝


이렇게 slow query에 대한 모니터링 시스템을 구축하는건 생각보다 간단한 일이다. 이제 이렇게 발생한 쿼리를 개선하는게 꽤나 어려운 일이다. 이제 어떻게 쿼리를 개선하면 좋을지 고민해봐야겠다.




REFERENCE

0개의 댓글