Skip to content

Batch records when preloading for indexing

What does this MR do and why?

Resolving an alerts we saw in Slack (internal only)

The alert was multiple ActiveRecord::QueryCanceledSidekiq/ElasticIndexInitialBulkCronWorker errors in the ElasticIndexInitialBulkCronWorker

Specifically for the NOTES table.

Kibana logs: https://log.gprd.gitlab.net/goto/fc719dd0-507a-11ed-b0ec-930003e0679c

Click to expand backtrace
lib/gitlab/database/load_balancing/connection_proxy.rb:104:in `block in read_using_load_balancer', lib/gitlab/database/load_balancing/load_balancer.rb:55:in `read', lib/gitlab/database/load_balancing/connection_proxy.rb:103:in `read_using_load_balancer', lib/gitlab/database/load_balancing/connection_proxy.rb:48:in `select_all', ee/lib/gitlab/elastic/document_reference.rb:35:in `block in preload_database_records', ee/lib/gitlab/elastic/document_reference.rb:31:in `each', ee/lib/gitlab/elastic/document_reference.rb:31:in `preload_database_records', ee/app/services/elastic/process_bookkeeping_service.rb:162:in `execute_with_redis', ee/app/services/elastic/process_bookkeeping_service.rb:126:in `block in execute', lib/gitlab/redis/wrapper.rb:23:in `block in with', lib/gitlab/redis/wrapper.rb:23:in `with', ee/app/services/elastic/process_bookkeeping_service.rb:97:in `with_redis', ee/app/services/elastic/process_bookkeeping_service.rb:126:in `execute', ee/app/workers/concerns/elastic/bulk_cron_worker.rb:22:in `block in perform', lib/gitlab/exclusive_lease_helpers.rb:38:in `in_lock', ee/app/workers/concerns/elastic/bulk_cron_worker.rb:21:in `perform', lib/gitlab/database/load_balancing/sidekiq_server_middleware.rb:26:in `call', lib/gitlab/sidekiq_middleware/duplicate_jobs/strategies/until_executing.rb:16:in `perform', lib/gitlab/sidekiq_middleware/duplicate_jobs/duplicate_job.rb:58:in `perform', lib/gitlab/sidekiq_middleware/duplicate_jobs/server.rb:8:in `call', lib/gitlab/application_context.rb:113:in `block in use', lib/gitlab/application_context.rb:113:in `use', lib/gitlab/sidekiq_middleware/worker_context.rb:11:in `wrap_in_optional_context', lib/gitlab/sidekiq_middleware/worker_context/server.rb:19:in `block in call', lib/gitlab/application_context.rb:113:in `block in use', lib/gitlab/application_context.rb:113:in `use', lib/gitlab/application_context.rb:54:in `with_context', lib/gitlab/sidekiq_middleware/worker_context/server.rb:17:in `call', lib/gitlab/sidekiq_status/server_middleware.rb:7:in `call', lib/gitlab/sidekiq_versioning/middleware.rb:9:in `call', lib/gitlab/sidekiq_middleware/query_analyzer.rb:7:in `block in call', lib/gitlab/database/query_analyzer.rb:37:in `within', lib/gitlab/sidekiq_middleware/query_analyzer.rb:7:in `call', lib/gitlab/sidekiq_middleware/admin_mode/server.rb:14:in `call', lib/gitlab/sidekiq_middleware/instrumentation_logger.rb:9:in `call', lib/gitlab/sidekiq_middleware/batch_loader.rb:7:in `call', lib/gitlab/sidekiq_middleware/extra_done_log_metadata.rb:7:in `call', lib/gitlab/sidekiq_middleware/request_store_middleware.rb:10:in `block in call', lib/gitlab/with_request_store.rb:17:in `enabling_request_store', lib/gitlab/with_request_store.rb:10:in `with_request_store', lib/gitlab/sidekiq_middleware/request_store_middleware.rb:9:in `call', lib/gitlab/sidekiq_middleware/server_metrics.rb:76:in `block in call', lib/gitlab/sidekiq_middleware/server_metrics.rb:103:in `block in instrument', lib/gitlab/metrics/background_transaction.rb:33:in `run', lib/gitlab/sidekiq_middleware/server_metrics.rb:103:in `instrument', lib/gitlab/sidekiq_middleware/server_metrics.rb:75:in `call', lib/gitlab/sidekiq_middleware/monitor.rb:10:in `block in call', lib/gitlab/sidekiq_daemon/monitor.rb:49:in `within_job', lib/gitlab/sidekiq_middleware/monitor.rb:9:in `call', lib/gitlab/sidekiq_middleware/size_limiter/server.rb:13:in `call', lib/gitlab/sidekiq_logging/structured_logger.rb:21:in `call'

Screenshots or screen recordings

Screenshots are required for UI changes, and strongly recommended for all other merge requests.

How to set up and validate locally

This one is hard to reproduce locally but you may be able to see the warning in the background jobs logs in gdk.

example

2022-04-05_19:44:57.94495 rails-background-jobs : {"severity":"WARN","time":"2022-04-05T19:44:57.944Z","message":"Query fetched 7887 Issue records: SELECT \"namespaces\".\"id\", \"namespaces\".\"name\", \"namespaces\".\"path\", \"namespaces\".\"owner_id\", \"namespaces\".\"created_at\", \"namespaces\".\"updated_at\", \"namespaces\".\"type\", \"namespaces\".\"description\", \"namespaces\".\"avatar\", \"namespaces\".\"membership_lock\", \"namespaces\".\"share_with_group_lock\", \"namespaces\".\"visibility_level\", \"namespaces\".\"request_access_enabled\", \"namespaces\".\"ldap_sync_status\", \"namespaces\".\"ldap_sync_error\", \"namespaces\".\"ldap_sync_last_update_at\", \"namespaces\".\"ldap_sync_last_successful_update_at\", \"namespaces\".\"ldap_sync_last_sync_at\", \"namespaces\".\"description_html\", \"namespaces\".\"lfs_enabled\", \"namespaces\".\"parent_id\", \"namespaces\".\"shared_runners_minutes_limit\", \"namespaces\".\"repository_size_limit\", \"namespaces\".\"require_two_factor_authentication\", \"namespaces\".\"two_factor_grace_period\", \"namespaces\".\"cached_markdown_version\", \"namespaces\".\"project_creation_level\", \"namespaces\".\"runners_token\", \"namespaces\".\"file_template_project_id\", \"namespaces\".\"saml_discovery_token\", \"namespaces\".\"runners_token_encrypted\", \"namespaces\".\"custom_project_templates_group_id\", \"namespaces\".\"auto_devops_enabled\", \"namespaces\".\"extra_shared_runners_minutes_limit\", \"namespaces\".\"last_ci_minutes_notification_at\", \"namespaces\".\"last_ci_minutes_usage_notification_level\", \"namespaces\".\"subgroup_creation_level\", \"namespaces\".\"emails_disabled\", \"namespaces\".\"max_pages_size\", \"namespaces\".\"max_artifacts_size\", \"namespaces\".\"mentions_disabled\", \"namespaces\".\"default_branch_protection\", \"namespaces\".\"unlock_membership_to_ldap\", \"namespaces\".\"max_personal_access_token_lifetime\", \"namespaces\".\"push_rule_id\", \"namespaces\".\"shared_runners_enabled\", \"namespaces\".\"allow_descendants_override_disabled_shared_runners\", \"namespaces\".\"traversal_ids\" FROM \"namespaces\" WHERE \"namespaces\".\"id\" IN (110, 22, 28, 1, 17, 25, 52, 27, 23, 5, 19, 26, 16, 24, 7, 2, 4, 15, 107, 20) /*application:sidekiq,correlation_id:17f8f1aae7bf73255fc2500fb6de6266,jid:a3da2b002b7ea6ef3565d8fd,endpoint_id:ElasticIndexInitialBulkCronWorker,db_config_name:main,line:/ee/lib/gitlab/elastic/document_reference.rb:35:in `block in preload_database_records'*/"}
2022-04-05_19:45:00.00834 rails-background-jobs : {"severity":"WARN","time":"2022-04-05T19:45:00.008Z","message":"Query fetched 3681 Note records: SELECT \"routes\".* FROM \"routes\" WHERE \"routes\".\"source_type\" = 'Project' AND \"routes\".\"source_id\" IN (2, 1, 43, 8, 5, 7, 3, 6, 4, 32) /*application:sidekiq,correlation_id:17f8f1aae7bf73255fc2500fb6de6266,jid:a3da2b002b7ea6ef3565d8fd,endpoint_id:ElasticIndexInitialBulkCronWorker,db_config_name:main,line:/ee/lib/gitlab/elastic/document_reference.rb:35:in `block in preload_database_records'*/"}
2022-04-05_19:45:00.47723 rails-background-jobs : {"severity":"INFO","time":"2022-04-05T19:45:00.476Z","retry":0,"queue":"default","backtrace":true,"version":0,"queue_namespace":"cronjob","args":[],"class":"ScheduleMergeRequestCleanupRefsWorker","jid":"98ec1afd27e77146e24c25ee","created_at":"2022-04-05T19:44:33.229Z","meta.caller_id":"Cronjob","correlation_id":"c43956edc25a02168f74d46380dde47c","meta.feature_category":"code_review","uber-trace-id":"35ce2a03d50f46fe:35ce2a03d50f46fe:0:1","worker_data_consistency":"always","idempotency_key":"resque:gitlab:duplicate:default:33e8a9dcd4c9780ad0ea123ad7ccbabde1aa1e90ffcbb928434ba4b5800a5811","size_limiter":"validated","enqueued_at":"2022-04-05T19:44:33.230Z","job_size_bytes":2,"pid":39562,"message":"ScheduleMergeRequestCleanupRefsWorker JID-98ec1afd27e77146e24c25ee: done: 12.211456 sec","job_status":"done","scheduling_latency_s":15.034695,"redis_calls":2,"redis_duration_s":0.000527,"redis_read_bytes":213,"redis_write_bytes":373,"redis_cache_calls":1,"redis_cache_duration_s":0.000337,"redis_cache_read_bytes":203,"redis_cache_write_bytes":61,"redis_queues_calls":1,"redis_queues_duration_s":0.00019,"redis_queues_read_bytes":10,"redis_queues_write_bytes":312,"db_count":1,"db_write_count":0,"db_cached_count":0,"db_replica_count":0,"db_primary_count":1,"db_main_count":1,"db_main_replica_count":0,"db_replica_cached_count":0,"db_primary_cached_count":0,"db_main_cached_count":0,"db_main_replica_cached_count":0,"db_replica_wal_count":0,"db_primary_wal_count":0,"db_main_wal_count":0,"db_main_replica_wal_count":0,"db_replica_wal_cached_count":0,"db_primary_wal_cached_count":0,"db_main_wal_cached_count":0,"db_main_replica_wal_cached_count":0,"db_replica_duration_s":0.0,"db_primary_duration_s":0.384,"db_main_duration_s":0.384,"db_main_replica_duration_s":0.0,"cpu_s":0.390895,"duration_s":12.211456,"completed_at":"2022-04-05T19:45:00.476Z","load_balancing_strategy":"primary","db_duration_s":0.00474}
2022-04-05_19:45:02.14660 rails-background-jobs : {"severity":"WARN","time":"2022-04-05T19:45:02.146Z","message":"Query fetched 4329 MergeRequest records: SELECT \"project_features\".* FROM \"project_features\" WHERE \"project_features\".\"project_id\" IN (2, 1, 43, 13, 11, 8, 5, 7, 3, 17, 18, 6, 12, 4, 10, 16, 9, 15, 26, 14) /*application:sidekiq,correlation_id:17f8f1aae7bf73255fc2500fb6de6266,jid:a3da2b002b7ea6ef3565d8fd,endpoint_id:ElasticIndexInitialBulkCronWorker,db_config_name:main,line:/ee/lib/gitlab/elastic/document_reference.rb:35:in `block in preload_database_records'*/"}
  1. make sure elasticsearch is enabled for gdk and advanced search is enabled in the admin
  2. index a large project (gitlabhq is a good one)
  3. check the sidekiq logs for the warnings, these should not occur when the issue is fixed

MR acceptance checklist

This checklist encourages us to confirm any changes have been analyzed to reduce risks in quality, performance, reliability, security, and maintainability.

Related to #358019 (closed)

Edited by Terri Chu

Merge request reports