QueryRecorder는 테스트에서 N+1 쿼리 문제를 탐지하는 도구입니다.

9c623e3e를 통해 spec/support/query_recorder.rb에 구현되었습니다

원칙적으로 머지 리퀘스트는 쿼리 수를 늘리지 않아야 합니다. N+1 쿼리를 피하기 위해 .includes(:author, :assignee)와 같은 코드를 추가하고 있다면, QueryRecorder로 이를 테스트에서 강제하는 방안을 고려합니다. 이렇게 하지 않으면 모델을 추가로 조회하는 새 기능이 문제를 조용히 되살릴 수 있습니다.

QueryRecorder의 동작 방식#

이 방식의 테스트는 ActiveRecord가 실행한 SQL 쿼리 수를 세는 방식으로 동작합니다. 먼저 기준값을 측정하고, 데이터베이스에 새 레코드를 추가한 뒤 다시 측정합니다. 쿼리 수가 크게 늘어났다면 N+1 쿼리 문제가 있는 것입니다.

예를 들어 두 번의 측정 사이에 이슈 5개를 생성하면, N+1 문제가 있을 때 쿼리 수가 5만큼 늘어납니다.

it "avoids N+1 database queries", :request_store, :use_sql_query_cache do
  visit_some_page # warm-up

  control = ActiveRecord::QueryRecorder.new(skip_cached: false) { visit_some_page }
  create_list(:issue, 5)
  expect { visit_some_page }.to issue_same_number_of_queries_as(control)
end

기댓값과 기준값을 모두 QueryRecorder 인스턴스로 둘 수도 있습니다.

it "avoids N+1 database queries", :request_store, :use_sql_query_cache do
  visit_some_page # warm-up

  control = ActiveRecord::QueryRecorder.new(skip_cached: false) { visit_some_page }
  create_list(:issue, 5)
  action = ActiveRecord::QueryRecorder.new(skip_cached: false) { visit_some_page }

  expect(action).to issue_same_number_of_queries_as(control)
end

경우에 따라서는 관계없는 이유로 실행마다 쿼리 수가 조금씩 달라질 수 있습니다. 이럴 때는 issue_same_number_of_queries_as(control).with_threshold(acceptable_change)로 테스트해야 할 수도 있지만, 가능하면 피합니다.

이 테스트가 실패하고 기준값을 QueryRecorder로 전달한 경우, 실패 메시지는 가장 긴 공통 접두사를 기준으로 쿼리를 대조하고 비슷한 쿼리를 묶어서 추가 쿼리가 어디에서 발생했는지 알려 줍니다.

권장 패턴#

N+1 쿼리 테스트의 권장 패턴에는 테스트가 운영 환경 동작을 정확히 반영하도록 하는 중요한 구성 요소가 포함됩니다.

it "avoids N+1 database queries", :request_store, :use_sql_query_cache do
  visit_some_page # warm-up

  control = ActiveRecord::QueryRecorder.new(skip_cached: false) { visit_some_page }
  create_list(:issue, 5)
  expect { visit_some_page }.to issue_same_number_of_queries_as(control)
end

각 구성 요소의 목적은 다음과 같습니다.

• :request_store: 요청이 지속되는 동안 데이터를 메모리에 캐시하는 Gitlab::SafeRequestStore를 활성화합니다. 운영 환경에서는 활성화되어 있지만 테스트에서는 기본적으로 비활성화되어 있습니다. 이를 켜지 않으면 잘못된 결과가 나올 수 있습니다.
• :use_sql_query_cache: 운영 환경에서 이미 동작 중인 SQL 쿼리 캐시를 활성화합니다.
• skip_cached: false: 캐시된 쿼리를 포함해 모든 쿼리를 셉니다. 캐싱에 가려질 수 있는 N+1 쿼리를 잡아냅니다.
• issue_same_number_of_queries_as: 쿼리 수가 예상과 달리 늘어나거나 줄어들면 실패합니다(양방향).
• warm-up: 스키마 로딩처럼 이후 요청에서 반복되지 않는 일회성 초기화 쿼리를 처리합니다.

exceed_query_limit 대신 issue_same_number_of_queries_as를 사용하는 이유#

issue_same_number_of_queries_as는 양방향으로 동작하므로 exceed_query_limit보다 우선합니다. 쿼리 수가 예상과 달리 늘어나거나 줄어들면 실패합니다. 덕분에 리팩터링 과정에서 필요한 쿼리가 실수로 제거되거나 죽은 코드가 실행되는 경우처럼 양쪽 방향의 의도치 않은 변화를 모두 잡아낼 수 있습니다.

반면 exceed_query_limit은 쿼리가 예상 개수를 초과할 때만 실패하므로, 쿼리가 예상과 달리 줄어드는 경우에는 알려 주지 않습니다.

컨트롤러 스펙 대신 request 스펙 사용#

컨트롤러 수준에서 N+1 테스트를 작성할 때는 request 스펙을 사용합니다.

컨트롤러는 예제마다 한 번만 초기화되므로 N+1 테스트를 컨트롤러 스펙으로 작성하지 않아야 합니다. 이렇게 하면 이후 "요청" 에서 쿼리가 줄어들어(예를 들어 메모이제이션 때문에) 잘못 성공하는 결과가 나올 수 있습니다.

실패를 확인하지 않은 테스트 신뢰 금지#

N+1 쿼리 테스트를 추가하기 전에, 변경 사항 없이도 그 테스트가 실패하는지 먼저 확인합니다. 테스트 자체가 잘못되었거나, 엉뚱한 이유로 통과하고 있을 수 있기 때문입니다.

테스트를 검증하는 방법은 다음과 같습니다.

1. 권장 패턴으로 테스트를 작성합니다.
2. N+1 수정 사항을 일시적으로 제거하거나 주석 처리합니다.
3. 테스트를 실행해 예상한 만큼 쿼리 수가 늘어나면서 실패하는지 확인합니다.
4. 수정 사항을 복원하고 테스트가 통과하는지 확인합니다.

쿼리 소스 찾기#

쿼리의 출처를 찾는 방법은 여러 가지가 있습니다.

• QueryRecorder의 data 속성을 확인합니다. 이 속성은 쿼리를 file_name:line_number:method_name 단위로 저장합니다. 각 항목은 다음 필드를 가진 hash 입니다.

  • count: 해당 file_name:line_number:method_name의 쿼리가 호출된 횟수
  • occurrences: 각 호출의 실제 SQL
  • backtrace: 각 호출의 스택 트레이스(아래 두 옵션 중 하나가 활성화된 경우)

  QueryRecorder#find_query를 사용하면 쿼리를 file_name:line_number:method_name과 count 속성으로 필터링할 수 있습니다. 예시는 다음과 같습니다.

  control = ActiveRecord::QueryRecorder.new(skip_cached: false) { visit_some_page }
  control.find_query(/.*note.rb.*/, 0, first_only: true)
  

  QueryRecorder#occurrences_by_line_method는 data를 기반으로 count 순으로 정렬한 배열을 반환합니다.

• ActiveRecord::QueryRecorder.new(query_recorder_debug: true)를 사용해 원하는 QueryRecorder 인스턴스의 호출 백트레이스를 확인합니다. 출력은 test.log 파일에 저장됩니다.

• QUERY_RECORDER_DEBUG 환경 변수를 사용해 모든 테스트에서 호출 백트레이스를 활성화합니다.

  활성화하려면 QUERY_RECORDER_DEBUG 환경 변수를 설정한 상태로 스펙을 실행합니다. 예시는 다음과 같습니다.

  QUERY_RECORDER_DEBUG=1 bundle exec rspec spec/requests/api/projects_spec.rb
  

  이렇게 하면 QueryRecorder 호출이 test.log 파일에 기록됩니다. 예시는 다음과 같습니다.

   QueryRecorder SQL: SELECT COUNT(*) FROM "issues" WHERE "issues"."deleted_at" IS NULL AND "issues"."project_id" = $1 AND ("issues"."state" IN ('opened')) AND "issues"."confidential" = $2
      --> /home/user/gitlab/gdk/gitlab/spec/support/query_recorder.rb:19:in `callback'
      --> /home/user/.rbenv/versions/2.3.5/lib/ruby/gems/2.3.0/gems/activesupport-4.2.8/lib/active_support/notifications/fanout.rb:127:in `finish'
      --> /home/user/.rbenv/versions/2.3.5/lib/ruby/gems/2.3.0/gems/activesupport-4.2.8/lib/active_support/notifications/fanout.rb:46:in `block in finish'
      --> /home/user/.rbenv/versions/2.3.5/lib/ruby/gems/2.3.0/gems/activesupport-4.2.8/lib/active_support/notifications/fanout.rb:46:in `each'
      --> /home/user/.rbenv/versions/2.3.5/lib/ruby/gems/2.3.0/gems/activesupport-4.2.8/lib/active_support/notifications/fanout.rb:46:in `finish'
      --> /home/user/.rbenv/versions/2.3.5/lib/ruby/gems/2.3.0/gems/activesupport-4.2.8/lib/active_support/notifications/instrumenter.rb:36:in `finish'
      --> /home/user/.rbenv/versions/2.3.5/lib/ruby/gems/2.3.0/gems/activesupport-4.2.8/lib/active_support/notifications/instrumenter.rb:25:in `instrument'
      --> /home/user/.rbenv/versions/2.3.5/lib/ruby/gems/2.3.0/gems/activerecord-4.2.8/lib/active_record/connection_adapters/abstract_adapter.rb:478:in `log'
      --> /home/user/.rbenv/versions/2.3.5/lib/ruby/gems/2.3.0/gems/activerecord-4.2.8/lib/active_record/connection_adapters/postgresql_adapter.rb:601:in `exec_cache'
      --> /home/user/.rbenv/versions/2.3.5/lib/ruby/gems/2.3.0/gems/activerecord-4.2.8/lib/active_record/connection_adapters/postgresql_adapter.rb:585:in `execute_and_clear'
      --> /home/user/.rbenv/versions/2.3.5/lib/ruby/gems/2.3.0/gems/activerecord-4.2.8/lib/active_record/connection_adapters/postgresql/database_statements.rb:160:in `exec_query'
      --> /home/user/.rbenv/versions/2.3.5/lib/ruby/gems/2.3.0/gems/activerecord-4.2.8/lib/active_record/connection_adapters/abstract/database_statements.rb:356:in `select'
      --> /home/user/.rbenv/versions/2.3.5/lib/ruby/gems/2.3.0/gems/activerecord-4.2.8/lib/active_record/connection_adapters/abstract/database_statements.rb:32:in `select_all'
      --> /home/user/.rbenv/versions/2.3.5/lib/ruby/gems/2.3.0/gems/activerecord-4.2.8/lib/active_record/connection_adapters/abstract/query_cache.rb:68:in `block in select_all'
      --> /home/user/.rbenv/versions/2.3.5/lib/ruby/gems/2.3.0/gems/activerecord-4.2.8/lib/active_record/connection_adapters/abstract/query_cache.rb:83:in `cache_sql'
      --> /home/user/.rbenv/versions/2.3.5/lib/ruby/gems/2.3.0/gems/activerecord-4.2.8/lib/active_record/connection_adapters/abstract/query_cache.rb:68:in `select_all'
      --> /home/user/.rbenv/versions/2.3.5/lib/ruby/gems/2.3.0/gems/activerecord-4.2.8/lib/active_record/relation/calculations.rb:270:in `execute_simple_calculation'
      --> /home/user/.rbenv/versions/2.3.5/lib/ruby/gems/2.3.0/gems/activerecord-4.2.8/lib/active_record/relation/calculations.rb:227:in `perform_calculation'
      --> /home/user/.rbenv/versions/2.3.5/lib/ruby/gems/2.3.0/gems/activerecord-4.2.8/lib/active_record/relation/calculations.rb:133:in `calculate'
      --> /home/user/.rbenv/versions/2.3.5/lib/ruby/gems/2.3.0/gems/activerecord-4.2.8/lib/active_record/relation/calculations.rb:48:in `count'
      --> /home/user/gitlab/gdk/gitlab/app/services/base_count_service.rb:20:in `uncached_count'
      --> /home/user/gitlab/gdk/gitlab/app/services/base_count_service.rb:12:in `block in count'
      --> /home/user/.rbenv/versions/2.3.5/lib/ruby/gems/2.3.0/gems/activesupport-4.2.8/lib/active_support/cache.rb:299:in `block in fetch'
      --> /home/user/.rbenv/versions/2.3.5/lib/ruby/gems/2.3.0/gems/activesupport-4.2.8/lib/active_support/cache.rb:585:in `block in save_block_result_to_cache'
      --> /home/user/.rbenv/versions/2.3.5/lib/ruby/gems/2.3.0/gems/activesupport-4.2.8/lib/active_support/cache.rb:547:in `block in instrument'
      --> /home/user/.rbenv/versions/2.3.5/lib/ruby/gems/2.3.0/gems/activesupport-4.2.8/lib/active_support/notifications.rb:166:in `instrument'
      --> /home/user/.rbenv/versions/2.3.5/lib/ruby/gems/2.3.0/gems/activesupport-4.2.8/lib/active_support/cache.rb:547:in `instrument'
      --> /home/user/.rbenv/versions/2.3.5/lib/ruby/gems/2.3.0/gems/activesupport-4.2.8/lib/active_support/cache.rb:584:in `save_block_result_to_cache'
      --> /home/user/.rbenv/versions/2.3.5/lib/ruby/gems/2.3.0/gems/activesupport-4.2.8/lib/active_support/cache.rb:299:in `fetch'
      --> /home/user/gitlab/gdk/gitlab/app/services/base_count_service.rb:12:in `count'
      --> /home/user/gitlab/gdk/gitlab/app/models/project.rb:1296:in `open_issues_count'
  

Rails 콘솔에서 쿼리 수 테스트#

개발 중에는 Rails 콘솔 출력만으로 데이터베이스 쿼리를 식별하고 세기가 쉽지 않습니다. QueryRecorder를 대화형으로 사용하면 테스트를 작성하기 전에 쿼리 성능을 분석하고 최적화하는 데 도움이 됩니다.

다음과 같은 경우에 특히 유용합니다.

• 기능 개발 중 N+1 쿼리를 디버깅하는 경우
• 여러 프리로딩 전략을 비교하는 경우
• 코드를 커밋하기 전에 쿼리 최적화를 검증하는 경우

QueryRecorder 헬퍼는 Rails 콘솔에 자동으로 로드되지 않으므로 먼저 require 해야 합니다.

# Important: Require the QueryRecorder helper (not loaded by default)
require './spec/support/helpers/query_recorder.rb'

# Example: Analyzing query counts for different preloading strategies
result = {}
package_files = Packages::PackageFile.limit(5)

# Create a helper to count queries
query_counter = proc do |&query_block|
  ActiveRecord::QueryRecorder.new(&query_block).data.map { |_, v| v[:count] }.reduce(&:+)
end

# Test different approaches
result['without preloading'] = query_counter.call { package_files.map(&:package) }
result['with preload(:package)'] = query_counter.call { package_files.preload(:package).map(&:package) }
result['with includes(package: :project)'] = query_counter.call { package_files.includes(package: :project).map(&:package) }

# View results
result
# => {"without preloading"=>5, "with preload(:package)"=>2, "with includes(package: :project)"=>2}

# Find the most efficient approach
result.min { |a, b| a.second <=> b.second }
# => ["with preload(:package)", 2]

이 방법을 사용하면 개발 중에 여러 쿼리 전략을 빠르게 시험하고 비교할 수 있습니다. 테스트와 코드를 작성하기 전에 가장 효율적인 구현을 고르는 데 도움이 됩니다.

참고 자료#

• Bullet N+1 쿼리 문제를 찾을 때 사용합니다
• 성능 가이드라인
• 머지 리퀘스트 성능 가이드라인 - 쿼리 수
• 머지 리퀘스트 성능 가이드라인 - 캐시된 쿼리
• RedisCommands::Recorder Redis에서 N+1 호출을 테스트할 때 사용합니다