KLDP DB서버가 일시적으로 느려지는 현상이 종종 있습니다.
아래는 제가 staff 메일링 리스트에 제출한 내용입니다.
권순선님께서 KLDP 회원여러분들과 함께 고민하는게 좋을것 같다고 제안하셔서 공지사항으로 올리게 되었습니다.
유사한 경험이나 정보를 가지고 계시다면 함께 공유해 주시면 좋겠습니다.
우선 리포트는 아래와 같습니다.
staff 메일링 리스트 제출 내용
실제로 운영중인 서버에 영향을 끼치는 문제인지는 정확히 모르겠지만 우선 디비서버의 특정시간대의 지나친(1분에 가까운) 슬로우 쿼리에 의문이 드는 상황이라 우선 리포트 해 놓습니다.
대부분은 우선 메모리 릭이 발생해서 스왑을 지나치게 사용해 로드가 올라가는 것으로 보이지만 다른 가능성도 있을 수 있습니다. 우선 여러 게시물들에서 vm.swapness = 0 으로 세팅하는걸 제안해 놔서 저도 설정을 바꿔 놨습니다.
참고한 URL은 아래와 같습니다.
http://www.vbulletin.com/forum/archive/index.php/t-171071.html
http://www.vbulletin.com/forum/showthread.php?p=1233538#post1233538
우선은 2.6.9-42.0.3 에서 2.6.9-42.0.2로 다운그레이드를 추천하긴 하는데 저도 어떻게 해야 할지는 잘 모르겠습니다.
실제 db.kldp.org에 해당하는 문제가 아닐 가능성도 상당히 높다고 보고 있어서요.
혹시나 다른 분들께서 정보가 있으시다면 공유해 주셨으면 합니다.
다시한번 말씀 드리지만 이건 혹시나 해서 찾아본 내용에 대한 리포트 입니다.
제출 내용 끝
우선 현재 일반적인 kldp.org의 응답속도는 많이 좋아졌습니다.
하지만 db서버가 하루에 두세번 정도 1분에 가까운 슬로우 쿼리를 내고 있습니다.
아마 접속한 상태에서 가끔씩 제대로 된 페이지가 보이지 않고 'db connection timeout' 과 유사한 메시지를 보게되는 경우가 있을텐데 이런 경우가 슬로우 쿼리들로 인해 현재 DBMS에 할당된 최대 컨넥션을 넘어서 새로운 컨넥션을 얻지 못해 발생하는 상황입니다.
이외에도 불규칙적으로 평소에는 아주 빠른 응답 속도를 보이고 테이블 내의 데이터도 적고 테이블 락에 대기할리도 없는 쿼리들도 슬로우 쿼리로 10초에 가깝게 나오는 경우가 종종 있습니다.
문제는 이때가 실제로 헤비로드라면 시스템의 로드 에버리지도 상당히 높고 실제로 슬로우 쿼리들 근처에 로드를 높일만한 쿼리가 있어야 하는데 제가 살펴본 바에 의하면 로드도 20-30프로이고 대부분 평소에는 아주 낮은 실행시간을 보이는 쿼리들이고 일관성도 없어 보입니다.
그래서 고민하던 중에 CentOS(현재 db서버 배포본) x86_64 버전의 2.6.9-42.0.3.ELsmp 커널에 대한 이슈를 찾아보다가 위와 같은 내용을 찾아 리포트 하게 되었습니다.
-- 20070209
현재 커널은 이틀전쯤(0207?)에 2.6.9-42.0.8.ELsmp x86_64로 업데이트 되어 있습니다.
아직 더 지켜봐야 하겠지만 현재 1분정도 혹은 그 이상의 슬로우 쿼리는 발생하지 않고 있습니다.
하루에 한번 있는 덤프쿼리는 제외했을때 입니다.
하지만 가끔식 drupal의 accesslog를 지켜본 결과 페이지 응답의 경우는 1분 가까이(40초) 걸리는 경우도 있습니다.
물론 이렇게 걸릴때는 요청의 갯수도 많고 다소 부담스러운(조인,정렬) 쿼리가 돌만한 페이지들이 많습니다.
아래에 오늘 11시 42분경에 발생한 슬로우 쿼리 로그를 첨부합니다.
쿼리를 보면 조회 쿼리의 경우 시간이 오래 걸릴수도 있는 것들이지만 업데이트 쿼리는 그렇지 않습니다.
시스템 사용현황을 sar로 본 결과는 아래와 같습니다. 11시 40분대나 50분대에 그렇게 높지 않습니다.
10시 00분 01초 CPU %user %nice %system %iowait %idle 10시 10분 01초 all 3.25 0.00 0.64 2.94 93.17 10시 20분 01초 all 5.38 0.00 0.74 2.98 90.90 10시 30분 01초 all 7.44 0.00 0.95 3.17 88.44 10시 40분 01초 all 4.31 0.00 0.77 2.99 91.93 10시 50분 01초 all 6.12 0.00 0.84 3.12 89.91 11시 00분 01초 all 4.51 0.00 0.88 3.31 91.30 11시 10분 01초 all 3.80 0.00 0.71 2.95 92.54 11시 20분 01초 all 3.82 0.00 0.74 3.23 92.21 11시 30분 01초 all 4.40 0.00 0.74 3.22 91.64 11시 40분 01초 all 7.10 0.00 1.00 3.05 88.84 11시 50분 01초 all 8.06 0.00 0.86 3.06 88.02 12시 00분 01초 all 3.91 0.00 0.66 3.13 92.31
생각보다 IOWAIT이 적어서 UPDATE가 오래 걸리는 이유에 문제가 있는게 아닌가 하고 생각이 됩니다.
아래는 mysqlbug 파일에 있는 컴파일 옵션입니다.
실제 컴파일을 한건 아니고 mysql.com에서 community edition의 바이너리를 받아서 설치했습니다.
VERSION="5.0.27-max" COMPILATION_COMMENT="MySQL Community Edition - Experimental (GPL)" BUGmysql="mysql@lists.mysql.com" # This is set by configure COMP_ENV_INFO="CC='ccache gcc' CFLAGS='' CXX='ccache gcc' CXXFLAGS='' LDFLAGS='' ASFLAGS=''" CONFIGURE_LINE="./configure '--prefix=/usr/local/mysql' '--localstatedir=/usr/local/mysql/data' '--libexecdir=/usr/local/mysql/bin' '--with-comment=MySQL Community Edition - Experimental (GPL)' '--with-server-suffix=-max' '--enable-thread-safe-client' '--enable-local-infile' '--with-pic' '--with-fast-mutexes' '--disable-shared' '--with-zlib-dir=bundled' '--with-big-tables' '--with-yassl' '--with-readline' '--with-archive-storage-engine' '--with-blackhole-storage-engine' '--with-ndbcluster' '--with-csv-storage-engine' '--with-example-storage-engine' '--with-federated-storage-engine' '--with-innodb' '--with-extra-charsets=all' 'CC=ccache gcc' 'CXX=ccache gcc'"
물론 아직도 조인후 임시테이블에서의 정렬 쿼리가 다소 있는 forum, taxonomy 모듈 등은 최적화 대상입니다.
요청이 몰리더라도 거의 선형적으로 로드가 걸리게 해야 할테니까요.
첨부 | 파일 크기 |
---|---|
070209.update.slow_.log_.txt | 1.22 KB |
070209.select.slow_.log_.txt | 26.14 KB |
댓글
시간대가 정해져
시간대가 정해져 있나요? 아니면 불규칙적인가요?
불규칙적으로 보입니다.
제가 봤을때는 규칙성을 찾을 수 없었습니다.
물론 눈으로 그냥 본거라 정확한거는 아닙니다.
우선 몇일간 슬로우쿼리를 더 쌓은후에 다시 확인해 봐야 할 것 같습니다.
현재 슬로우쿼리들은 10초이내, 60초이내 수준의 두가지로 나뉘고 있습니다.
10초 이내는 하루에 10회 이내로 발생하고 60초 이내는 1회에서 3회 정도까지 발생하는 것으로 보입니다.
-- Signature --
青い空大好き。
蒼井ソラもっと好き。
파란 하늘 너무 좋아.
아오이 소라 더좋아.
slow 쿼리를 로깅 해보는게 좋은듯 합니다
my.cnf 에 아래와 같이 추가하시고 mysql restart 하시면 됩니다.
set-variable = long_query_time=2
log-long-format
log-slow-queries = /var/log/mysqld.slow.log
long_query_time=2 의 단위는 초입니다.
네, 현재 슬로우 쿼리로그를 남기고 있습니다.
말씀해 주신것과 똑같은 설정이네요.
그 결과 이상할 정도로 긴 슬로우 쿼리들이 발견되서 이렇게 공론화 하게 되었습니다.
아무래도 몇일간 더 로그를 남긴후에 그 내용을 올려서 다시한번 확인 과정을 거쳐야 할 것 같습니다.
저 혼자 보는것 보다는 여러분들이 함께 보신다면 제가 간과했거나 보지 못했던 부분을 보실수 있을것 같습니다.
-- Signature --
青い空大好き。
蒼井ソラもっと好き。
파란 하늘 너무 좋아.
아오이 소라 더좋아.
네
저는 방금전에 봤습니다.
==
아 씨끄러 씨끄러~ 조용해!!
레드햇 9 이하 사용금지!
하루한번 mysqloptimize
하루한번 mysqloptimize -Aos
한시간에 한번 -Aas
이런거 하면 오히려 느려질까요?
emerge money
https://xenosi.de/
innodb 테이블도 지원할까요?
현재 kldp.org의 테이블들은 거의 innodb 테이블로 되어 있습니다.
알려주신 mysqloptimize 명령어가 innodb 테이블도 지원할까요?
그리고 optimize table 쿼리와 다른점이 있는건가요?
좀 큰 테이블들의 경우 optimize table은 table에 write lock이 걸려서 웹서비스를 중지하고 하는게 좋은걸로 알고 있습니다.
언제 시간이 나면 중지시킨 후에 강제로 optimize는 해보려고 하는데 서비스 중에는 힘들것으로 생각됩니다.
혹시 mysqloptimize가 innodb도 지원하고 optimize table과 다르게 작동한다면 정기작업에서 쓸 수 있을것 같습니다.
-- Signature --
青い空大好き。
蒼井ソラもっと好き。
파란 하늘 너무 좋아.
아오이 소라 더좋아.
한시간에 한번
한시간에 한번 권해드린 a 는 analyze 로 optimize 와 달리 최적의 쿼리를 실행할 수 있도록 분석만 하는걸로 알고 있습니다.
실제 해 보면 a 는 부하가 거의 없습니다.
그리고 예전에 어떤분이 phpMyAdmin 의 내용을 보여주시면서 InnoDB 도 최적화하면 나타나는게 다르다는걸 보여주셨었습니다.
delete, update 를 하면 테이블에 표기되는게 달라지고 optimize 를 하면 다시 정상화 되더군요.
emerge money
https://xenosi.de/
그렇다면 현재 서버 상태가 좀 이상한듯 합니다.
우선 명령어는 mysqlcheck를 이용했습니다.
말씀해 주신 명령어가 없어서 mysql.com에서 찾아봤더니 동일한 역할을 하는것 같습니다.
지난주 정도에 테스트 했었습니다.
처음에 analyze만 사용했었는데 실행직후 많은 쿼리들이 슬로우쿼리로 적체되기 시작했습니다.
그래서 우선 analyze를 중지하고 어차피 하려고 했던 optimze를 서비스를 잠시 중지시킨 후에 실행했습니다.
서버의 IO가 충분한 퍼포먼스를 못내고 있는 상황이 아닌가 예상됩니다.
하지만 sar를 이용해 로드에버리지나 USER, IO WAIT, SYSTEM과 관련된 항목들을 보아도 대부분 문제가 없을듯 한 수치로 보여집니다.
특히 IO WAIT은 대부분 2-3프로 내외입니다. 세가지 항목 모두 합해서 20-30프로가 제일 로드가 심할때의 상황입니다.
물론 10분 단위로 정보가 집계되는 것이라서 순간적으로 몰리는 상황이 정확하게 기록되지는 않을거라고 생각은 됩니다.
확실한 이유는 아직도 모르겠네요.
우선 mysql의 배포 파일중에 my.huge.innodb.cnf를 참고해서 일부 innodb와 io thread 관련 설정 및 버퍼들과 관련된 설정들을 바꿔 놓고 재시작해 놓은 상태입니다. 그래도 아직 슬로우 쿼리들이 꽤 발생하고는 있습니다.
이번주 정도까지 슬로우쿼리를 모은후에 파일로 첨부해서 여러 분들이 볼 수 있도록 하겠습니다.
-- Signature --
青い空大好き。
蒼井ソラもっと好き。
파란 하늘 너무 좋아.
아오이 소라 더좋아.
pconnect 로
pconnect 로 바꿔보고,
/etc/security/limits.conf 에서 mysql 계정의 파일 한도를 늘려보고
my.cnf 의 각종 캐시 팍팍 늘려보고...
---------
2007-1-30 19:47 에 약 30초간 응답이 없었습니다.
---------
emerge money
https://xenosi.de/
현재 설정이
현재는 파일 리미트가 4096으로 되어 있습니다.
혹시나 해서 2-3주 전쯤에 설정 해 놓았습니다.
우선 말씀해 주신 8192로 수정을 해 놓은 상태이고 상황이 되면 다시한번 재 시작하려고 합니다.
현재 pconnect는 쓰고 있지는 않지만 connect시에 제일 오버헤드가 클 것이라 생각되는 쓰레드와 관련된 부분은 아래와 같은 상황입니다.
물론 pconnect로 하는게 제일 좋긴 하겠지만 역시나 소스에 손을 안대는게 관리 포인트가 가장 적을것 같아서 조금은 망설여 집니다.
그 외에 현재 캐시의 경우 innodb buffer pool은 2GB, query cache는 512MB로 설정되어 있습니다.
query cache min res unit은 기본값인 4096에서 2048로 오히려 줄여놓은 상황이구요.
현재 사용률이 약 50% 정도 되고 있습니다.
쿼리 캐시와 관련된 설정과 상황은 아래와 같습니다.
-- Signature --
青い空大好き。
蒼井ソラもっと好き。
파란 하늘 너무 좋아.
아오이 소라 더좋아.
linux 계통의 메모리
linux 계통의 메모리 하드드라이브 스왑이 어떻게 일어나는 기전은 모르지만
window에서 스왑파일을 정리하는 시점, 쿼리가 몰리는 시점, 스레드 청소시점,
connection 정리 시점이 몰릴경우
하드드라이브의 한계로인하여 정체현상이 발생한 경험이 있었습니다.
해결은 최대 스레드 갯수를 줄이고, 메모리를 증설하여 스왑 발생 빈도를 줄였습니다.
참고가 되길 바랍니다.
===============================================================
'고생은 사람을 고상하게도, 비열하게도 만든다'
방금
방금 목격했습니다.
mysql 메세지를 english 로 하는것을 추천합니다.
emerge money
https://xenosi.de/
커널 문제에
커널 문제에 대해서는 현재 RHEL4 의 updates 에 2.6.9-42.0.8.ELsmp 이 올라와 있는 것을 확인했습니다. CentOS 커널에 곧 올라올테니 update 해 보면 알 수 있겠죠. :-)
changelog 는 다음과 같습니다. changelog 상으로는 .2 에서 .3 으로 올라갔다고 slow query 가 발생할 만한 요소는 없는 것 같군요.
* 화 1월 23 2007 Jason Baron [2.6.0-42.0.8]
-fix ext2 readdir f_pos revalidation logic (David Milburn) [193877]
* 목 1월 18 2007 Jason Baron [2.6.9-42.0.7]
-re-spin
* 화 1월 16 2007 Jason Baron [2.6.9-42.0.6]
-x86_64: increase nmi watchdog timeout from 5 to 30 seconds (Larry Woodman) [205722]
* 금 1월 12 2007 Jason Baron [2.6.9-42.0.5]
-fix race condition in sys_mincore() (Doug Chapman) [180663] {CVE-2006-4814}
-ext3: READA failures cause "directory hole" (Chip Coldwell, Stephen Tweedie) [213921]
-aio: fix kernel panic in aio_free_ring (Jeff Moyer) [220971] {CVE-2006-5754}
-fix ext2_check_page denial of service (Eric Sandeen) [217021] {CVE-2006-6054}
-fix listxattr syscall can corrupt user space programs (Eric Sandeen) [220677] {CVE-2006-5753}
* 토 12월 16 2006 Jason Baron [2.6.9-42.0.4]
-ia64: fix local DoS with corrupted ELF (Dave Anderson) [205335] {CVE-2006-4538}
-fix information leak in __block_prepare_write() (Eric Sandeen) [207463] {CVE-2006-4813}
-tg3: fix init failure - unable to obtain MAC address (Andy Gospodarek) [208922]
-s390: fix information leak (Jan Glauber) [209435] {CVE-2006-5174}
-catch blocks beyond pagecache limit in __getblk_slow() (Eric Sandeen) [214288 206328] {CVE-2006-5757}
-net: fix dev_queue_xmit to not call local_bh_enable in out_kfree_skb error path (Neil Horman) [212144] {CVE-2006-6535}
-audit: close memory leak (Sachin Prabhu) [216667]
-fix ext3fs_dirhash denial of service (Eric Sandeen) [217030] {CVE-2006-6053}
-fix zlib_inflate oops due to corrupted cramfs image (Eric Sandeen) [216958] {CVE-2006-5823}
-fix get_fdb_entries() integer overflow (Thomas Graf) [216452] {CVE-2006-5751}
-fix lockup via /proc/net/ip6_flowlabel (Thomas Graf) [213214] {CVE-2006-5619}
-hfs: return error code in case of error (Eric Paris) [217011] {CVE-2006-6056}
-Add packet size checks for CAPI messages (Marcel Holtmann) [218602] {CVE-2006-6106}
* 화 9월 26 2006 Jason Baron [2.6.9-42.0.3]
-fix mprotect to not allow permission subversion (Jason Baron) [190073] {CVE-2006-2071}
-fix sys_perfmonctl() file descriptor reference count issue (Anil Keshavamurthy) [204360] {CVE-2006-3741}
-Fix hugepage crash on failing mmap (Larry Woodman) [165345] {CVE-2005-4811}
-sctp: create abort messages properly (Neil Horman) [204460] {CVE-2006-4535}
-fix oops occuring from malformed ULE packet (Neil Horman) [204912] {CVE-2006-4623}
-ipw2[12]00: restore get_wireless_stats pointer (John Linville) [198820]
-ipw2200: accept broadcast MAC traffic (John Linville) [203421]
-fix netfilter do_add_counters race (Thomas Graf) [191698] {CVE-2006-0039}
-fix ip over atm clip_mkip may dereference freed pointer (Thomas Graf) [206265]
-ppc64: Clear EN_ATTN bit in PPC970 HID0 (David Woodhouse) [201684] {CVE-2006-4093}
centos repository에
centos repository에 등록된 거 확인 했습니다. 정말 여기저기 포럼에도 그렇고, slow query에 대한 글은 안 보이네요..
저도 얼마전에
저도 얼마전에 관리하던 디비서버가 매우많이 느려졌던때가 있어서..
동시접속자랑 오랜시간동안 연결된 쿼리들 많아서 타임아웃값을 줄여줬더니.. 좋아졌었습니다.
대중이런식으루요..
my.cnf에도 옵션이 있겠죠아마?
/mysql/bin/mysqld_safe -O max_connections=1000 &
echo 10 > /proc/sys/net/ipv4/tcp_fin_timeout
이건 좀 다른
이건 좀 다른 현상인지도 모르겠습니다만.
재현경로:
답글을 작성 > "댓글 쓰기" 버튼 클릭 > 화면 바뀜 > KLDP 홈페이지의 일부만 표시되고 계속 Loading 중으로 나옴
> 오래기다려도(수 분) 안나옴
재현빈도:
답글쓰면 100%
특이사항:
- 파이어폭스 하단에 Waiting for www.google.com... 이 표시되는 상태임
- 사내방화벽 탓인지 구글 홈피접속시 그림문자(?) 입력하라는 403 Forbidden 페이지 자주 나타남
quid pro quo
내용을 업데이트 했습니다.
일부 정보를 추가하고 오늘 11시 40분쯤 발생한 슬로우 쿼리와 시스템 현황을 추가했습니다.
-- Signature --
青い空大好き。
蒼井ソラもっと好き。
파란 하늘 너무 좋아.
아오이 소라 더좋아.
또 2분넘는 슬로우 쿼리가 발생했습니다.
ㅡ,.,ㅡ
-- Signature --
青い空大好き。
蒼井ソラもっと好き。
파란 하늘 너무 좋아.
아오이 소라 더좋아.
헙
우선 아래의 행부터 이해가 가질 않네요.
node의 데이터 양이 어느정도 되길래 이렇게 단순한 쿼리의 쿼리타임이...?
nid 필드에 인덱스를 걸어보시는것도...
# Query_time: 153 Lock_time: 0 Rows_sent: 0 Rows_examined: 0
SELECT comment FROM node WHERE nid = 67595;
이런곳이 있어서 넘 좋습니다.
^___________^;
세션에서
세션에서 문제군요.
제 경험상 MySQL 의 WHERE 절은 INDEX 가 걸려있어도 rows 가 엄청 많으면 = 로 가져와도 느렸습니다.
InnoDB 로 실험 했었고요.
가비지 컬렉트를 자주 하는것을 권장합니다.
드루팔이 소스 수정없이 PostgreSQL 로 옮길 수 있는 것 같던데,
이 문제가 맞다면 장담하건데 PostgreSQL 에서는 절대 문제 없습니다.
PostgreSQL 8.1.5 에서 전체 7,704,910 rows 에서
2개 필드를 = 조건을 줘서 한줄 가져오는데
24.820 ms 걸립니다.
emerge money
https://xenosi.de/
http://kldp.org/node/78385
http://kldp.org/node/78385
저도 서버가 느려져서 원인을 찾고 있는데, 이 글타래가 도움이 될 것 같군요.
KLDP 처럼 사용자가 많지도 않은데, 이 문제는 사용자와는 상관없을까요?
F/OSS 가 함께하길.. (F/OSS서포터즈 : [[FOSS/Supporters]], [[FOSS/Supporters/Group]]) - 답글 프로젝트 : 왜! 이글에는 답글이 없나요? 덤으로 포인트도!! -
F/OSS 가 함께하길..
댓글 달기