User indexing cause additional SQL queries
Summary
For every indexed user we execute multiple additional queries:
D, [2023-02-02T12:58:52.115321 #2504285] DEBUG -- : WebauthnRegistration Exists? (34.9ms) /*application:console,correlation_id:8f940c1a27ae19a5dbe14d0200f55909,db_config_name:main,console_hostname:console-01-sv-gprd,console_username:dgruzd-rails*/ SELECT 1 AS one FROM "webauthn_registrations" WHERE "webauthn_registrations"."user_id" = 9279456 LIMIT 1
D, [2023-02-02T12:58:52.150220 #2504285] DEBUG -- : Project Exists? (32.5ms) /*application:console,correlation_id:8f940c1a27ae19a5dbe14d0200f55909,db_config_name:main,console_hostname:console-01-sv-gprd,console_username:dgruzd-rails*/ SELECT 1 AS one FROM "projects" INNER JOIN "members" ON "projects"."id" = "members"."source_id" WHERE "members"."type" IN ('ProjectMember', 'ProjectNamespaceMember') AND "members"."source_type" = 'Project' AND "members"."user_id" = 9279456 AND "members"."requested_at" IS NULL LIMIT 1
D, [2023-02-02T12:58:52.182956 #2504285] DEBUG -- : Member Load (31.5ms) /*application:console,correlation_id:8f940c1a27ae19a5dbe14d0200f55909,db_config_name:main,console_hostname:console-01-sv-gprd,console_username:dgruzd-rails*/ SELECT "members".* FROM "members" WHERE "members"."user_id" = 9279456
D, [2023-02-02T12:58:52.216669 #2504285] DEBUG -- : Namespace Load (31.6ms) /*application:console,correlation_id:8f940c1a27ae19a5dbe14d0200f55909,db_config_name:main,console_hostname:console-01-sv-gprd,console_username:dgruzd-rails*/ SELECT "namespaces".* FROM "namespaces" WHERE "namespaces"."id" IN (12664165, 14093380, 14093392, 63308624)
D, [2023-02-02T12:58:52.250838 #2504285] DEBUG -- : Project Load (32.1ms) /*application:console,correlation_id:8f940c1a27ae19a5dbe14d0200f55909,db_config_name:main,console_hostname:console-01-sv-gprd,console_username:dgruzd-rails*/ SELECT "projects".* FROM "projects" WHERE "projects"."id" IN (27984546, 41046676, 41046828)
D, [2023-02-02T12:58:52.294282 #2504285] DEBUG -- : Namespace Load (31.6ms) /*application:console,correlation_id:8f940c1a27ae19a5dbe14d0200f55909,db_config_name:main,console_hostname:console-01-sv-gprd,console_username:dgruzd-rails*/ SELECT "namespaces".* FROM "namespaces" WHERE "namespaces"."id" = 14093380 LIMIT 1
D, [2023-02-02T12:58:52.328627 #2504285] DEBUG -- : Namespace Load (31.9ms) /*application:console,correlation_id:8f940c1a27ae19a5dbe14d0200f55909,db_config_name:main,console_hostname:console-01-sv-gprd,console_username:dgruzd-rails*/ SELECT "namespaces".* FROM "namespaces" WHERE "namespaces"."id" = 12664165 LIMIT 1
D, [2023-02-02T12:58:52.365966 #2504285] DEBUG -- : Namespace Load (31.6ms) /*application:console,correlation_id:8f940c1a27ae19a5dbe14d0200f55909,db_config_name:main,console_hostname:console-01-sv-gprd,console_username:dgruzd-rails*/ SELECT "namespaces".* FROM "namespaces" WHERE "namespaces"."id" = 12664147 LIMIT 1
D, [2023-02-02T12:58:52.403775 #2504285] DEBUG -- : Namespace Load (32.0ms) /*application:console,correlation_id:8f940c1a27ae19a5dbe14d0200f55909,db_config_name:main,console_hostname:console-01-sv-gprd,console_username:dgruzd-rails*/ SELECT "namespaces".* FROM "namespaces" WHERE "namespaces"."id" = 12664147 LIMIT 1
D, [2023-02-02T12:58:52.445106 #2504285] DEBUG -- : Namespace Load (31.6ms) /*application:console,correlation_id:8f940c1a27ae19a5dbe14d0200f55909,db_config_name:main,console_hostname:console-01-sv-gprd,console_username:dgruzd-rails*/ SELECT "namespaces".* FROM "namespaces" WHERE "namespaces"."id" = 14093380 LIMIT 1
Steps to reproduce
service = Elastic::ProcessBookkeepingService.new
Elastic::ProcessBookkeepingService.track!(*User.all)
ActiveRecord::Base.logger = Logger.new $stdout
items = Elastic::ProcessBookkeepingService.queued_items
refs = service.send(:deserialize_all, items.values.flatten(1))
refs.preload_database_records.each do |ref|
puts ">>>>>>>>>>> #{ref.klass.to_s}"
service.send(:submit_document, ref)
end;nil
What is the current bug behavior?
It adds 4 + additional SQL queries. It happens on https://gitlab.com/gitlab-org/gitlab/-/blob/ba886e5b84a65decb64a4a018678fe53cb94c76e/ee/app/services/elastic/process_bookkeeping_service.rb#L165
What is the expected correct behavior?
Relevant logs and/or screenshots
Possible fixes
Edited by Dmitry Gruzd