Strange counting of queries

[akostadinov]

What did you do?

class Admin::Api::ApplicationPlanLimitsControllerTest < ActionDispatch::IntegrationTest
  include NPlusOneControl::MinitestHelper

  attr_reader :service, :app_plan

  def setup
    @provider = FactoryBot.create(:provider_account)
    @token = FactoryBot.create(:access_token, owner: @provider.admin_users.first!, scopes: %w[account_management]).value
    host! @provider.admin_domain
    @service = FactoryBot.create(:simple_service, account: @provider)
    @app_plan = FactoryBot.create(:simple_application_plan, issuer: service)
  end

  test "something" do
    populate = ->(n) do
      metrics = FactoryBot.create_list(:metric, n, service: service)
      methods = FactoryBot.create_list(:method, n, owner: service)
      metrics.zip(methods).each do |metric, method|
        metric.usage_limits.create(period: :week, value: 1, plan: app_plan)
        method.usage_limits.create(period: :week, value: 1, plan: app_plan)
        method.usage_limits.create(period: :month, value: 1, plan: app_plan)
        metric.usage_limits.create(period: :month, value: 1, plan: app_plan)
      end
    end

    assert_perform_constant_number_of_queries(populate: populate, scale_factors: [2, 10, 2]) do
      get admin_api_application_plan_limits_path(app_plan, format: :json, access_token: @token)
      assert_response :success
    end
  end
end

What did you expect to happen?

PASS

What actually happened?

Minitest::Assertion: Expected to make the same number of queries, but got:
  17 for N=2
  107 for N=10
  35 for N=2
Unmatched query numbers by tables:
  services (SELECT): 2 != 12

Additional context

In the log when running without n_plus_one_control, I don't see such number of queries logged. I suspect it might be an issue with counting the setup queries or something. It makes no sense to me. I will appreciate any advice how to debug.

Environment

Ruby Version: 2.6

Framework Version (Rails, whatever): Rails 5.1.7

N Plus One Control Version: n_plus_one_control (0.6.2)

[akostadinov]

Definitely it's counting something else, because running with [2, 10, 2, 2] results in:

Minitest::Assertion: Expected to make the same number of queries, but got:
  17 for N=2
  107 for N=10
  35 for N=2
  35 for N=2
Unmatched query numbers by tables:
  services (SELECT): 2 != 12

[palkan]

because running with [2, 10, 2, 2] results in:

The difference between the first run (N=2 -> 17) and the subsequent runs with the same factor (35) could be explained by some caching/memoization at the controller level — that's why we see the difference totals for the same N. Try adding a warmup block.

To see the recorded queries, run the test with NPLUSONE_VERBOSE=1.

[akostadinov]

I'm not sure I know what exactly happened. But refactoring the test locally it works fine without strangeness.

Issue is though that when #populate method is private, it is not run. Maybe there came the ofiginal confusion from. I think this is an issue because one can have a #populate method but it not being run and thus test being a false positive.

I think private method should be called.

And thank you for the ultra-useful gem!

[palkan]

I think private method should be called.

Yeah, makes sense. Would you like to propose a PR? (Another one 🙂)