프로덕션에서 Ruby 성능 문제를 디버깅하는 방법: rbtrace 활용 가이드

성능은 곧 기능입니다. 그리고 많은 성능 문제는 개발 단계에서 발견하고 해결할 수 있습니다.

하지만 프로덕션 환경에서만 나타나는 성능 저하라면 어떨까요? 모든 코드 줄마다 로그 메시지를 추가해야 할까요? 그건 오히려 애플리케이션을 더 느리게 만들 뿐입니다. 아니면 "이러면 고쳐지려나?" 하는 식의 자잘한 커밋을 수없이 쏟아붓으며 무엇이 효과가 있는지 지켜봐야 할까요?

사실 코드를 망가뜨리지 않고도 충분히 분석할 수 있습니다. 바로 rbtrace를 사용하는 것입니다.

실행 중인 Ruby 애플리케이션 추적하기

rbtrace를 사용하면 성능 문제를 감지하고, 다른 Ruby 프로세스 내부에서 코드를 실행하며, 코드를 단 한 줄도 추가하지 않은 채 메서드 호출을 기록할 수 있습니다. Gemfile에 gem "rbtrace" 한 줄만 추가하면 끝입니다.

저는 Sam Saffron이 Ruby의 메모리 누수를 디버깅하는 방법을 다룬 훌륭한 글(아직 읽어보지 않으셨다면 꼭 읽어보시길 권합니다)을 통해 rbtrace를 알게 되었습니다.

Sam은 이 글에서 rbtrace를 활용해 프로세스가 사용 중인 모든 객체를 덤프했습니다:

bundle exec rbtrace -p $SIDEKIQ_PID -e 'Thread.new{GC.start;require "objspace";io=File.open("/tmp/ruby-heap.dump", "w"); ObjectSpace.dump_all(output: io); io.close}'

정말 인상적인 기능입니다. 하지만 이것 외에도 훨씬 더 많은 작업이 가능합니다.

rbtrace로 무엇을 할 수 있을까?

프로덕션에서 실행되는 SQL 문과 각 쿼리가 걸리는 시간을 확인하고 싶었던 적이 있으신가요?

~/Source/testapps/rbtrace jweiss$ rbtrace -p $RAILS_PID --methods "ActiveRecord::ConnectionAdapters::PostgreSQLAdapter#execute_and_clear(sql)"             
*** attached to process 7897
ActiveRecord::ConnectionAdapters::PostgreSQLAdapter#execute_and_clear(sql="SELECT  \"articles\".* FROM \"articles\" WHERE \"articles\".\"id\" = $1 LIMIT 1") <0.002631>

2초 이상 걸리는 모든 메서드 호출을 찾아낼 수도 있습니다:

~/Source/testapps/rbtrace jweiss$ rbtrace -p $RAILS_PID --slow 2000
*** attached to process 8154
    Integer#times <2.463761>
        ArticlesController#create <2.558673>

특정 메서드가 호출될 때마다 그 순간을 포착하고 싶다면:

~/Source/testapps/rbtrace jweiss$ rbtrace -p $RAILS_PID --methods "ActiveRecord::Persistence#save" 
*** attached to process 8154
ActiveRecord::Persistence#save <0.010964>

애플리케이션이 현재 실행 중인 스레드 목록도 확인할 수 있습니다:

~/Source/testapps/rbtrace jweiss$ rbtrace -p $RAILS_PID -e "Thread.list"
*** attached to process 8154
>> Thread.list
=> [#<Thread:0x007ff4fcc9a8a8@/usr/local/lib/ruby/gems/2.2.0/gems/puma-2.6.0/lib/puma/server.rb:269 sleep>, #<Thread:0x007ff4fcc9aa10@/usr/local/lib/ruby/gems/2.2.0/gems/puma-2.6.0/lib/puma/thread_pool.rb:148 sleep>, #<Thread:0x007ff4fcc9ab50@/usr/local/lib/ruby/gems/2.2.0/gems/puma/reactor.rb:104 sleep>, #<Thread:0x007ff4f98c0410 sleep>]

그렇습니다. -e 옵션을 사용하면 실행 중인 서버 내부에서 Ruby 코드를 직접 실행할 수 있습니다:

~/Source/testapps/rbtrace jweiss$ rbtrace -p $RAILS_PID -e "ActiveRecord::Base.connection_config"
*** attached to process 8154
>> ActiveRecord::Base.connection_config
=> {:adapter=>"postgresql", :pool=>5, :timeout=>5000, :database=>"rbtrace_test"}

네, 이제 조금 소름 돋기까지 합니다. 하지만 그래도 정말 강력한 기능임은 분명합니다. (다행히 프로세스에 접근 권한이 있는 사용자만 rbtrace를 사용할 수 있으므로 크게 걱정할 일은 아닙니다.)

rbtrace는 스테이징과 프로덕션 환경에서 Ruby 프로세스를 검사할 수 있는 다양한 도구를 제공합니다. 프로세스가 메모리를 어떻게 사용하고 있는지(혹은 남용하고 있는지) 파악하고, 느린 함수 호출을 추적하며, 심지어 Ruby 코드를 원격으로 실행할 수도 있습니다.

문제를 해결하기 위해 수많은 테스트 커밋과 로그 메시지를 만들어낼 필요가 없습니다. 서버에 접속해 필요한 데이터를 수집한 뒤, 그대로 빠져나오면 됩니다. 아직 프로덕션에서 사용하는 것이 완전히 편안하지는 않지만, 적어도 테스트 환경에서는 분명 큰 도움이 될 것이라 확신합니다.

여러분은 어떠신가요? rbtrace를 어떤 용도로 활용해 보고 싶으신가요?