쿼리 분석 플러그인 (Query Analyzer / Query Trace)

어떤 애플리케이션이든 배포를 위해서는 필연적으로 '최적화'라는 단계를 거쳐야하며, 레일스 애플리케이션도 예외는 아니다. 최적화를 위해서 맨 먼저 해야할 일은 테스트나 벤치마크를 통해 병목 지점을 찾는 것이다. 그런데 필자의 경험이나, 지금까지 읽은 여러 글들을 통해 추측컨데 십중팔구 데이터베이스가 우리가 최초로 정복해야할 병목이다.

레일스는 액티브레코드라는 걸출한 ORM(객체-관계 매핑)을 사용한다. 액티브레코드는 개발 단계에서 데이터베이스의 존재를 몰라도 될 정도로 우아하게 상위 수준에서 지낼 수 있게 도와준다. 그렇게 '웹 개발 많이 편해졌어~'라며 룰루랄라 지내다가, 어느 날  애플리케이션 로그 파일, 또는 데이터베이스 쿼리 로그를 열어보면 모두들 깜짝 놀라게 된다. 별 생각없이 짠 코드들이 수많은 (때로는 비 효율적인) 쿼리들을 막 쏟아내고 있는 모습을 보면 정신이 아찔해지기까지 하다.

1. Schedule Load (0.023687) SELECT * FROM schedules WHERE (schedules.id = 3) LIMIT 1

   Resource Load (0.001076) SELECT * FROM resources WHERE (resources.id = 328) LIMIT 1

   Schedule Load (0.011488) SELECT * FROM schedules WHERE (schedules.id = 3) LIMIT 1

   Resource Load (0.022471) SELECT * FROM resources WHERE (resources.id = 328) LIMIT 1

사실 액티브레코드 ORM을 사용하면서 효율적으로 데이터베이스를 사용하려면, 즉 두 마리 토끼를 모두 잡기 위해서는 액티브레코드가 어떻게 동작하는지에 대한 깊은 이해가 필요하다. 공교롭게도 이 깊은 이해라는 것은 '경험'이 수반되지 않으면 생기지 않는 것이다. 그렇다면 어디서부터 시작하면 좋을까? 필자가 추천하는 방법은 '로그 파일을 뚫어져라 쳐다보는 것'이다. 어떤 코드가 어떤 결과(쿼리)를 만들어내는지 하나 하나 분석하다보면, 어떻게 코드를 짜야하는지, 어떤 코드를 피해야 하는지 자연스레 알 수 있을 것이다. 여기서는 레일스 로그에 정보를 더해 우리의 분석 작업을 도와주는 플러그인을 두 가지 소개하겠다.

이 쿼리 누가 만든거지? - Query Trace

로그 파일을 보면 한 액션을 처리하는 동안 어떤 데이터베이스 쿼리가 만들어지는지를 알 수 있다. 단순한 코드라면 그 쿼리만으로 어느 지점에서 어떤 메서드가 만든 것인지 알아낼 수 있을 것이다. 하지만 조금 복잡한 애플리케이션이라면, 쿼리를 만든 코드를 찾아내는 일도 만만치 않다. 어떻게 해야할까? 여기 답이 있다. 바로 Query Trace 플러그인이다. 이 플러그인을 설치하면 SQL 쿼리와 함께 소스 코드의 어느 지점(호출 스택과 함께)에서 만들어졌는지도 함께 출력해준다. 다음 예를 보자.

1. Schedule Load (0.023687)   SELECT * FROM schedules WHERE (schedules.id = 3) LIMIT 1

     app/models/available_work.rb:50:in `study_method'

     app/helpers/plan_helper.rb:4:in `work_description'

     app/views/plan/_resource_schedule.rhtml:27:in `_run_rhtml_plan__resource_schedule'

     app/views/plan/_resource_schedule.rhtml:24:in `_run_rhtml_plan__resource_schedule'

     app/views/plan/_schedule_listing.rhtml:5:in `_run_rhtml_plan__schedule_listing'

     app/views/plan/_schedule_listing.rhtml:3:in `_run_rhtml_plan__schedule_listing'

     app/views/plan/_schedule_listing.rhtml:1:in `_run_rhtml_plan__schedule_listing'

     app/views/plan/index.rhtml:6:in `_run_rhtml_plan_index'

     vendor/plugins/textmate_footnotes/lib/textmate_footnotes.rb:60:in `render'

   Resource Load (0.001076)   SELECT * FROM resources WHERE (resources.id = 328) LIMIT 1

     app/models/available_work.rb:54:in `div_type'

     app/helpers/plan_helper.rb:6:in `work_description'

     app/views/plan/_resource_schedule.rhtml:27:in `_run_rhtml_plan__resource_schedule'

     app/views/plan/_resource_schedule.rhtml:24:in `_run_rhtml_plan__resource_schedule'

     app/views/plan/_schedule_listing.rhtml:5:in `_run_rhtml_plan__schedule_listing'

     app/views/plan/_schedule_listing.rhtml:3:in `_run_rhtml_plan__schedule_listing'

     app/views/plan/_schedule_listing.rhtml:1:in `_run_rhtml_plan__schedule_listing'

     app/views/plan/index.rhtml:6:in `_run_rhtml_plan_index'

     vendor/plugins/textmate_footnotes/lib/textmate_footnotes.rb:60:in `render'

단순히 호출 스택을 출력해서, 필요없는 정보도 있기는 하지만, 단순히 쿼리만 찍히던 때와 비교하면, 정말 친절한 로그라고 할 수 있다. 쿼리를 줄일 수 있을것 같은 '용기'를 만들어주는 플러그인이 아닐까 싶다. 위 로그를 보고 필요없는 쿼리를 찾아서 없앤다던가, 중복되는 쿼리는 한번만 불릴 수 있도록 적절한 캐싱 방법을 적용한다든가 하는 방법을 강구할 수 있다.  스프링노트팀도 오픈 전후로 한동안 Query Trace가 포함된 로그 파일을 뚫어져라 쳐다보고 있었다. 무거운 액션 하나를 처리하는데 1400라인도 넘게 찍혔으니, 이 로그를 보는 일이 쉽지만은 않았으리라 짐작이 될 것이다. 그래도 이 플러그인 덕분에 쿼리 수를 1/4 수준으로 줄일 수 있었다 :)

 

이 쿼리의 성능은? - Query Analyzer

Query Trace를 이용해 불필요한 쿼리를 제거했다면, 이제 꼭 필요한 쿼리들의 성능을 개선할 차례이다. 그리고 가장 손쉽고 당연히 해야하는 일이 바로 적절한 '인덱스'를 만드는 것이다. 모든 개발자가 당연히 인덱스를 잘 잡았을거라고 생각하지만, 실제로 그렇지 않은 경우도 매우 많다. 그래서 간단한 인덱스만 잡아줘도 애플리케이션의 성능이 많게는 10배까지 빨라지기도 한다. 특정 쿼리가 데이터베이스에서 어떻게 해석되는지 알기 위해서는 플랜을 봐야하는데, mysql의 경우 EXPLAIN 명령으로 알 수 있다. 로그를 보고, 특정 쿼리를 사냥해서 데이터베이스 콘솔에서 EXPLAIN을 앞에 붙여 돌려보기를 반복하며 성능이 나쁜 쿼리를 찾을 수 있다. 가만보니, 너무 큰 중복이다! 이를 제거할 방법은? Query Analyzer 플러그인을 사용하면 된다.

 

Query Analyzer 플러그인을 설치해두는 것만으로 레일스가 만드는 모든 쿼리의 플랜을 함께 보여준다. 이제 우리는 우리의 전략, 즉 '뚫어져라 로그 쳐다보기'에만 집중할 수 있게 된 것이다. 로그를 보고 인덱스를 타지 않는 쿼리를 찾아서, 인덱스를 타게 만들어주면 된다.

You Aren't Gonna Need It

최적화라는 것은 꼭 필요해질 시점에 하는 것이 정답이다. 미리 최적화랍시고 코드만 복잡하게 만든다면, 그것은 명백한 퇴보 행위다. 어떤 애플리케이션은 이런 쿼리 튜닝이 전혀 필요없을 수도 있다. 오래걸리는 작업을 단순히 캐싱해버리는 것만으로 인생을 쉽게 살 수 있다면 그렇게 하는 것이 좋다. 정말 필요하다고 느낄 때(데이터베이스 서버가 힘들어할 때, 또는 DB 처리 시간이 너무 길어 응답 시간이 늦어질 때) 그 때 시작해도 늦지 않다. 필요를 느낀다면, 위에서 소개한 플러그인을 이용해 보다 쉽게 상황을 개선할 수 있기를 바란다.