jisangs/chocomae

Fork 0

Files

T

jisangs b18612277c 현재 서비스중인 t3a.medium 실행 지표 상태 확인

2026-09-18 12:30:12 +09:00

15 KiB

Raw Permalink Blame History

07단계: 사후 분석 및 최적화

운영 서버 적용 후 실제 성능을 분석하고 추가 최적화를 검토합니다.

📊 실제 성능 측정 결과

운영 DB에서 측정한 개선율

comparison.txt(04단계)의 값을 옮겨 적었습니다 (2026-09-15). 6개 쿼리 전체 값은 result/comparison.txt를 참고하세요.

항목	베이스라인 (02)	개선 후 (04)	개선율	상태
EXPLAIN rows (q2 시간별·범위)	10,103	22	459배 ⬇️	[x] 확인
EXPLAIN rows (q4 일간·범위)	10,103	99	102배 ⬇️	[x] 확인
EXPLAIN rows (q3 일간·함수)	10,103	5,851	1.7배 ⬇️	[x] 확인
서버 처리 시간 (q4, ANALYZE)	75.2ms	0.47ms	161배 ⬇️	[x] 확인
서버 처리 시간 (q3 일간·함수, ANALYZE)	75.3ms	2.44ms	31배 ⬇️	[x] 확인
애플리케이션 느린 쿼리 (3초 이상)	0건 (slow log 전체 기간)	0건 (9/16 하루)	-	[x] 확인 (04:00 백업 1건 외 기록 없음)

slow log에 기록된 것은 모두 백업·작업 SQL이고, 애플리케이션 쿼리는 한 건도 없었습니다.

매일 04:00 약 5초: best_record 전체 SELECT (mysqldump 백업)

9/7 17:44~18:07: 같은 백업 SELECT 반복 (백업 스크립트 작업일)

9/15 23:04~23:09: 이번 작업의 전체 백업 덤프, 중복 DELETE, ALTER

앱 쿼리는 작업 전에도 3초를 넘지 않았으므로(측정 쿼리 서버 처리 시간 약 75ms), 이번 개선 효과는 이 지표가 아니라 04단계의 서버 처리 시간·검사 행 수로 판단합니다. 9/16 이후에도 04:00 백업 SELECT(약 5초, 전체 행을 읽으므로 인덱스와 무관)는 계속 기록되니 성능 저하로 오해하지 마세요.

원본: result/slow_log_daily_before.txt, result/slow_log_entries_before.txt

참고: 01단계 사전 측정의 일간 랭킹(함수형)은 index_merge, rows 10,100이었습니다.

MariaDB 10.11의 EXPLAIN FORMAT=JSON에는 cost 필드가 없어 스테이징의 cost 수치와 직접 비교할 수 없습니다. rows와 실행 시간으로 비교하고, 실제 실행 통계가 필요하면 ANALYZE FORMAT=JSON <쿼리>의 r_rows, r_total_time_ms를 사용하세요 (쿼리를 실제로 실행함).

저장된 파일

result/
├── premeasure_*.txt, premeasure_*.json            ← 01 사전 측정
├── params.sql, queries/*.sql                      ← 02·04 공통 측정 쿼리
├── run_measure.sh, summarize_*.py                 ← 02·04 공통 측정 도구
├── baseline_explain_q*.json, baseline_perf.txt    ← 02 EXPLAIN, 실행 시간
├── baseline_analyze.txt, baseline_*_summary.txt   ← 02 서버 처리 시간
├── dedupe_before_count.txt, dedupe_result.txt     ← 03 중복 정리
├── add_indexes.sql, add_indexes_*.txt             ← 03 인덱스 추가
├── after_explain_q*.json, after_perf.txt          ← 04 EXPLAIN, 실행 시간
├── after_analyze.txt, after_slow_log.txt          ← 04 서버 처리 시간, slow log
├── explain_summary.txt, analyze_summary.txt       ← 04 비교 요약
├── comparison.txt                                 ← 04 비교표·결론
├── slow_log_daily_before.txt, slow_log_entries_*.txt  ← 07 slow log 분석
├── peaktime/                                      ← 07 vmstat 원본 로그·스크립트
└── peaktime_vmstat_summary.txt                    ← 07 피크 시간대 비교

커밋 제외 (로컬에만 보관, 개인정보·비밀번호 해시 포함):
backup_chocomae_full_20260915.sql.gz, backup_app_highest_dup_rows.sql, *grants*.txt

🔍 성능 분석

피크 시간대 서버 상태 (vmstat, 12:50~15:00)

운영 서버 cron이 매일 12:50부터 vmstat 10 780을 기록합니다 (chocomae-peaktime-monitoring.sh). 9/14·9/15는 개선 전, 9/16은 개선 후입니다.

지표 (779샘플 평균)	9/14	9/15	9/16 (개선 후)
CPU 사용 us+sy	13.51%	9.49%	2.80%
CPU 사용 p95	29%	23%	6%
누적 CPU 시간 (130분)	1,052.8초	739.5초	217.9초
us > 5 인 샘플 수	701	468	5
실행 대기 r ≥ 2 샘플 수	86	62	16
디스크 읽기 bi 평균	71.8	60.5	17.4
문맥 전환 cs 평균 (부하 지표)	879	658	645
여유 메모리 free 평균	564MB	433MB	471MB
피크 기록 수 (best_record)	2,705건	1,947건	2,173건
기록 1,000건당 CPU	389.2초	379.8초	100.3초

부하는 비슷한데 CPU 사용량이 3.4배 줄었습니다. 문맥 전환 수(cs)는 9/15 658 → 9/16 645로 거의 같은데, CPU 사용률은 9.49% → 2.80%입니다.
디스크 읽기(bi)도 3.5배 줄어, 인덱스로 읽는 페이지가 줄어든 것과 일치합니다.
메모리는 큰 변화가 없습니다.

원본과 계산 결과: result/peaktime/, result/peaktime_vmstat_summary.txt

사용자 수로 보정한 결과 (2026-09-16 확인): 9/16은 9/15보다 기록이 약 12% 많았는데도 CPU는 3.4배 적게 썼습니다. 기록 1,000건당 CPU로 환산하면 380초 → 100초로 약 3.8배 감소했습니다. 개선 전 두 날(389.2초, 379.8초)의 값이 서로 비슷해 기준값으로 믿을 만합니다.

디스크 사용량 변화 (인덱스 추가 비용)

2026-09-16에 운영 DB에서 다시 측정했습니다. 01단계 측정값과 비교한 결과입니다.

테이블	data_mb (전 → 후)	index_mb (전 → 후)	인덱스 증가
best_record	72.5 → 73.5	72.1 → 143.2	+71.1MB
app_highest_record	16.5 → 16.5	15.8 → 21.3	+5.5MB
typing_exam_record	10.3 → 10.3	10.9 → 17.9	+7.0MB
typing_exam_highest_record	1.4 → 1.4	1.2 → 1.7	+0.5MB

best_record 인덱스별 크기 (mysql.innodb_index_stats)

인덱스	크기	비고
PRIMARY	73.5MB	데이터 본체
`idx_maestro_player_app_dt`	35.6MB	이번에 추가
`idx_maestro_app_dt`	30.6MB	이번에 추가
PlayerID	29.3MB	기존, 외래키용
AppID	25.4MB	기존, 외래키용
MaestroID	22.3MB	기존, 외래키용 (새 인덱스로 대체 가능)

인덱스로 늘어난 디스크는 약 79MB입니다. best_record의 증가분 71.1MB 중 약 4.9MB는 같은 기간 기록이 7% 늘어난 몫이고, 나머지 66.2MB가 새 복합 인덱스 2개입니다.
DB 전체 크기는 약 207MB → 292MB로 약 41% 늘었습니다. 성능과 맞바꾼 디스크 비용입니다.
app_highest_record는 8,795행을 지웠는데도 data_mb가 그대로입니다. InnoDB가 삭제한 공간을 파일에서 반환하지 않고 새 행에 재사용하기 때문이며 정상입니다.
메모리 사용량은 줄지 않았습니다. InnoDB 버퍼 풀은 시작할 때 정해진 크기를 확보하므로 쿼리가 빨라져도 사용량이 달라지지 않습니다. 대신 같은 캐시로 더 적은 데이터만 다루게 되어 디스크 읽기가 줄었습니다(위 vmstat bi 참고).

원본: result/index_size_after.txt

📈 비즈니스 영향

지표	개선 전	개선 후	변화
피크 시간 기록 수 (부하)	1,947건 (9/15)	2,173건 (9/16)	12% 증가
평균 응답 시간	측정 안 함 (웹 서버 응답 시간 미기록)	-	-
실패율	측정 안 함	-	-
CPU 사용률 (피크 12:50~15:00)	9.49% (9/15)	2.80% (9/16)	3.4배 ⬇️
기록 1,000건당 CPU (부하 보정)	379.8초 (9/15)	100.3초 (9/16)	3.8배 ⬇️
여유 메모리 (피크 평균)	433MB (9/15)	471MB (9/16)	큰 변화 없음

✅ 성공 여부 판단

성공 기준

범위형 쿼리(q2·q4·q6)의 rows가 베이스라인 대비 대폭 감소 (목표: 조회 기간의 실제 기록 수 수준) — 10,103 → 22 / 99 / 709
애플리케이션 느린 쿼리(3초 이상) 없음 — 9/16 하루 동안 0건 (기록된 것은 04:00 백업 SELECT 1건뿐, result/slow_log_entries_after.txt)
결과 행 수 변화 없음, 최고기록 화면 정상 — 04-3 diff 통과, 2026-09-15 운영 화면 확인
서비스 가용성 100% 유지 — 온라인 DDL로 중단 없음, 9/15 작업 직후 운영 화면 확인, 9/16 피크 시간에 기록 2,173건 정상 저장
사용자 불만 없음 — 2026-09-16까지 접수된 문의 없음 (기간을 더 두고 확인)

결론

[x] 성공: 모든 기준 달성, 운영 정상화 (2026-09-16 판단)
[ ] 부분 성공: 대부분 달성, 모니터링 계속
[ ] 실패: 목표 미달, 추가 최적화 필요

근거 요약

서버 처리 시간: 범위형 쿼리 75~~80ms → 0.26~~2.50ms (32~~292배), 함수형도 18~~36배 단축
검사 행 수: 10,103 → 22 / 99 / 709
피크 시간 CPU: 기록 1,000건당 379.8초 → 100.3초 (3.8배 감소, 부하 12% 증가 상태에서)
조회 결과 행 수는 개선 전과 동일, 운영 화면 정상, 앱 느린 쿼리 0건
남은 확인: 사용자 문의 여부는 기간을 더 두고 관찰

🔧 추가 최적화 제안

단계별 추가 개선

1단계: 쿼리 최적화 (안 1)

함수 제거 쿼리 적용 (03단계 3-4, Stage에서 수정 완료한 코드를 2026-09-15 운영 배포)
효과: 같은 조건에서 함수형 대비 서버 처리 시간 q1→q2 8배, q3→q4 5배, q5→q6 1.7배 추가 단축 (04단계)

2단계: 집계 테이블 도입 (안 2)

daily_best_record, daily_typing_exam_record 생성
예상 효과: 히스토리/랭킹 조회 극적 개선

3단계: 아카이빙 (안 3)

13개월 이전 기록 아카이빙
예상 효과: 테이블 크기 감소, 백업 시간 단축
참고: 월 적재량이 전년 대비 약 2.1배로 늘고 있음 (01 사전 측정)

4단계: 애플리케이션 최적화 (안 5)

N+1 쿼리 제거
SQL Injection 보안 강화
최고기록 저장을 INSERT ... ON DUPLICATE KEY UPDATE로 변경 (UNIQUE 키 활용, 동시 저장 시 더 좋은 기록 유지)
예상 효과: 동시 사용자 처리량 2~3배 향상

5단계: 중복 인덱스 정리 (선택)

best_record의 MaestroID 단일 인덱스 삭제 검토 (22.3MB 회수)
- 새로 만든 idx_maestro_app_dt가 MaestroID로 시작하므로 외래키 제약도 충족하고 조회도 대체됩니다.
- ALTER TABLE best_record DROP INDEX MaestroID, ALGORITHM=INPLACE, LOCK=NONE;
- AppID, PlayerID 단일 인덱스는 각각 그 컬럼으로 시작하는 외래키가 있어 삭제하면 안 됩니다.
typing_exam_record 등 다른 테이블에도 같은 정리 여지가 있는지 인덱스 목록 확인
스테이징에서 외래키 제약과 쿼리 계획을 먼저 확인한 뒤 운영 적용

📋 모니터링 계획

지속적 모니터링 (24시간 이후)

작업 후 slow query log는 원래 설정(slow_query_log=ON, long_query_time=3, log_output=FILE)으로 돌아갔고, 작업용 jisangs 계정은 삭제했습니다. 그래서 mysql.slow_log 테이블이 아니라 MariaDB가 실행되는 서버(또는 컨테이너)의 slow log 파일로 확인합니다.

작업 전후 모두 같은 기준(3초 이상)으로 기록되므로, 날짜별 건수를 그대로 비교할 수 있습니다.

2026-09-15 23:05~23:20에는 기준이 0.5초였고 작업 SQL(ALTER·DELETE)이 기록됐습니다. 9/15 건수에서 이 시간대는 제외하고 보세요.

1. 날짜별 느린 쿼리 건수 (서버에서 root/sudo로 실행)

sudo awk '/^# Time:/ {d = substr($3, 1, 10)} /^# Query_time:/ {c[d]++} END {for (k in c) print k, c[k]}' \
  /var/log/mysql/mariadb-slow.log | sort | tail -14

첫 열은 # Time: 줄의 날짜입니다 (형식에 따라 260916 또는 2026-09-16). 9/15 이전 며칠과 9/16 이후를 비교해 위 표의 "느린 쿼리 수"에 적습니다.

2. 느린 쿼리 종류 상위 10개 (mariadb-dumpslow가 설치된 경우)

sudo mariadb-dumpslow -s c -t 10 /var/log/mysql/mariadb-slow.log

best_record, typing_exam_record의 날짜 조건 쿼리가 9/16 이후에도 나오는지 확인합니다. 나오면 03-4에서 수정하지 못한 쿼리가 남아 있는 것입니다. 백업 덤프의 SELECT /*!40001 SQL_NO_CACHE */ ... FROM best_record는 정상입니다.

운영 서버의 mariadb-dumpslow는 이 로그 중간에서 Died at /usr/bin/mariadb-dumpslow line 182 에러로 멈췄습니다 (2026-09-15). 멈추기 전까지의 요약은 출력되므로 참고용으로 쓰고, 건수는 1번 awk 명령으로 확인하세요.

3. 느린 쿼리 항목별 목록 (시각, 실행 시간, 검사 행 수 — SQL 본문은 출력하지 않음)

sudo awk '/^# Time:/ {t = $3 " " $4} /^# Query_time:/ {print t, "query_time=" $3, "rows_examined=" $NF}' \
  /var/log/mysql/mariadb-slow.log | tail -30

9/16 이후 항목이 04:00 백업 1건(검사 행 약 121만)뿐이면 정상입니다.

4. 피크 시간대 기록 저장 건수 (vmstat 비교를 사용자 수로 보정할 때, 서버에서 관리자 계정으로 실행)

SELECT DATE(RecordDateTime) AS day, COUNT(*) AS best_record_cnt
FROM best_record
WHERE RecordDateTime >= '2026-09-14' AND RecordDateTime < '2026-09-17'
  AND TIME(RecordDateTime) >= '12:50:00' AND TIME(RecordDateTime) < '15:00:00'
GROUP BY day ORDER BY day;

날짜별 건수가 비슷하면 vmstat의 CPU 감소는 개선 효과로 볼 수 있고, 9/16 건수가 크게 적으면 사용자가 적었던 영향도 섞인 것입니다.

결과 (2026-09-16): 9/14 2,705건 / 9/15 1,947건 / 9/16 2,173건 → 9/16이 9/15보다 많으므로, CPU 감소는 사용자가 줄어서가 아닙니다.

📝 최종 보고서 항목

실행 요약
- 작업 목표 및 결과
- 성과 지표
기술 분석
- EXPLAIN 개선 결과
- 실행 시간 비교
- 중복 정리 결과 (삭제 행 수, 백업 파일)
비즈니스 임팩트
- 사용자 경험 개선
- 서버 비용 절감 효과
추가 제안
- 다음 단계 최적화 계획
- 예상 추가 효과

🎯 다음 단계

스테이징에서 안 2 (집계 테이블) 테스트
운영 DB 추가 최적화 검토
팀 회의에서 결과 공유
성능 모니터링 대시보드 구축

운영 서버 성능 개선 프로젝트 완료! 🎉

15 KiB Raw Permalink Blame History