Error 500 due to statement timeout when logging in to as user gitlab-qa (#198440) · Issues · GitLab.org / GitLab · GitLab (original) (raw)

Skip to content

• • Why GitLab
  • Pricing
  • Contact Sales
  • Explore
• Why GitLab
• Pricing
• Contact Sales
• Explore
• Sign in
• Get free trial

Error 500 due to statement timeout when logging in to as user gitlab-qa

Summary

When we try to log in to as user gitlab-qa (password in 1Password) we see error 500.

More info

The canary and production smoke tests are failing, all showing error 500. It looks like this is the error:

• Canary: https://sentry.gitlab.net/gitlab/gitlabcom/issues/1191269/
• Prod: https://sentry.gitlab.net/gitlab/gitlabcom/issues/1190608/

Example failing smoke test pipelines:

• Canary: https://ops.gitlab.net/gitlab-org/quality/canary/-/jobs/859848
• Prod: https://ops.gitlab.net/gitlab-org/quality/production/-/jobs/859815

This might be related to deleting 2k+ subgroups not long before the problem started: #35361 (comment 273945517)

Steps to reproduce

1. Log into Canary as gitlab-qa using the password in 1Password.

I could only reproduce it manually on Canary, but it's causing the smoke tests to fail on Prod too.

It's happening now on Prod too. Guess I was lucky the first time I tried.

Relevant logs and/or screenshots

ActiveRecord::QueryCanceled: PG::QueryCanceled: ERROR:  canceling statement due to statement timeout
: SELECT  "projects".* FROM "projects" INNER JOIN "project_authorizations" ON "projects"."id" = "project_authorizations"."project_id" WHERE "project_authorizations"."user_id" = 1614863 AND "projects"."archived" = FALSE ORDER BY "projects"."created_at" DESC LIMIT 20 OFFSET 0

Expand for stack trace

PG::QueryCanceled: ERROR:  canceling statement due to statement timeout

  from active_record/connection_adapters/postgresql_adapter.rb:611:in `async_exec_params'
  from active_record/connection_adapters/postgresql_adapter.rb:611:in `block (2 levels) in exec_no_cache'
  from active_support/dependencies/interlock.rb:48:in `block in permit_concurrent_loads'
  from active_support/concurrency/share_lock.rb:187:in `yield_shares'
  from active_support/dependencies/interlock.rb:47:in `permit_concurrent_loads'
  from active_record/connection_adapters/postgresql_adapter.rb:610:in `block in exec_no_cache'
  from active_record/connection_adapters/abstract_adapter.rb:581:in `block (2 levels) in log'
  from monitor.rb:235:in `mon_synchronize'
  from active_record/connection_adapters/abstract_adapter.rb:580:in `block in log'
  from active_support/notifications/instrumenter.rb:23:in `instrument'
  from active_record/connection_adapters/abstract_adapter.rb:571:in `log'
  from active_record/connection_adapters/postgresql_adapter.rb:609:in `exec_no_cache'
  from active_record/connection_adapters/postgresql_adapter.rb:596:in `execute_and_clear'
  from marginalia.rb:94:in `execute_and_clear_with_marginalia'
  from active_record/connection_adapters/postgresql/database_statements.rb:81:in `exec_query'
  from active_record/connection_adapters/abstract/database_statements.rb:478:in `select'
  from active_record/connection_adapters/abstract/database_statements.rb:70:in `select_all'
  from active_record/connection_adapters/abstract/query_cache.rb:106:in `select_all'
  from gitlab/database/load_balancing/connection_proxy.rb:63:in `block in read_using_load_balancer'
  from gitlab/database/load_balancing/load_balancer.rb:32:in `read'
  from gitlab/database/load_balancing/connection_proxy.rb:62:in `read_using_load_balancer'
  from gitlab/database/load_balancing/connection_proxy.rb:41:in `select_all'
  from active_record/querying.rb:41:in `find_by_sql'
  from active_record/relation.rb:560:in `block in exec_queries'
  from active_record/relation.rb:584:in `skip_query_cache_if_necessary'
  from active_record/relation.rb:547:in `exec_queries'
  from active_record/association_relation.rb:34:in `exec_queries'
  from active_record/relation.rb:422:in `load'
  from active_record/relation.rb:200:in `records'
  from active_record/relation.rb:504:in `blank?'
  from renders_member_access.rb:20:in `preload_max_member_access_for_collection'
  from renders_member_access.rb:11:in `prepare_projects_for_rendering'
  from dashboard/projects_controller.rb:76:in `load_projects'
  from dashboard/projects_controller.rb:54:in `projects'
  from active_support/callbacks.rb:426:in `block in make_lambda'
  from active_support/callbacks.rb:179:in `block (2 levels) in halting_and_conditional'
  from abstract_controller/callbacks.rb:34:in `block (2 levels) in <module:Callbacks>'
  from active_support/callbacks.rb:180:in `block in halting_and_conditional'
  from active_support/callbacks.rb:513:in `block in invoke_before'
  from active_support/callbacks.rb:513:in `each'
  from active_support/callbacks.rb:513:in `invoke_before'
  from active_support/callbacks.rb:107:in `block in run_callbacks'
  from gitlab/ip_address_state.rb:10:in `with'
  from ee/application_controller.rb:43:in `set_current_ip_address'
  from active_support/callbacks.rb:118:in `block in run_callbacks'
  from gitlab/session.rb:11:in `with_session'
  from application_controller.rb:467:in `set_session_storage'
  from active_support/callbacks.rb:118:in `block in run_callbacks'
  from gitlab/i18n.rb:55:in `with_locale'
  from gitlab/i18n.rb:61:in `with_user_locale'
  from application_controller.rb:461:in `set_locale'
  from active_support/callbacks.rb:118:in `block in run_callbacks'
  from labkit/context.rb:31:in `with_context'
  from gitlab/application_context.rb🔞in `with_context'
  from application_controller.rb:453:in `set_current_context'
  from active_support/callbacks.rb:118:in `block in run_callbacks'
  from gitlab/error_tracking.rb:34:in `with_context'
  from application_controller.rb:545:in `sentry_context'
  from active_support/callbacks.rb:118:in `block in run_callbacks'
  from raven/integrations/rails/controller_transaction.rb:7:in `block in included'
  from active_support/callbacks.rb:118:in `instance_exec'
  from active_support/callbacks.rb:118:in `block in run_callbacks'
  from marginalia.rb:111:in `record_query_comment'
  from active_support/callbacks.rb:118:in `block in run_callbacks'
  from active_support/callbacks.rb:136:in `run_callbacks'
  from abstract_controller/callbacks.rb:41:in `process_action'
  from action_controller/metal/rescue.rb:22:in `process_action'
  from action_controller/metal/instrumentation.rb:34:in `block in process_action'
  from active_support/notifications.rb:168:in `block in instrument'
  from active_support/notifications/instrumenter.rb:23:in `instrument'
  from active_support/notifications.rb:168:in `instrument'
  from action_controller/metal/instrumentation.rb:32:in `process_action'
  from action_controller/metal/params_wrapper.rb:256:in `process_action'
  from active_record/railties/controller_runtime.rb:24:in `process_action'
  from abstract_controller/base.rb:134:in `process'
  from action_view/rendering.rb:32:in `process'
  from action_controller/metal.rb:191:in `dispatch'
  from action_controller/metal.rb:252:in `dispatch'
  from action_dispatch/routing/route_set.rb:52:in `dispatch'
  from action_dispatch/routing/route_set.rb:34:in `serve'
  from action_dispatch/journey/router.rb:52:in `block in serve'
  from action_dispatch/journey/router.rb:35:in `each'
  from action_dispatch/journey/router.rb:35:in `serve'
  from action_dispatch/routing/route_set.rb:840:in `call'
  from omniauth/strategy.rb:192:in `call!'
  from omniauth/strategy.rb:169:in `call'
  from omniauth/strategy.rb:420:in `call_app!'
  from omni_auth/strategies/group_saml.rb:41:in `other_phase'
  from omniauth/strategy.rb:190:in `call!'
  from omniauth/strategy.rb:169:in `call'
  from omniauth/strategy.rb:192:in `call!'
  from omniauth/strategy.rb:169:in `call'
  from omniauth/strategy.rb:192:in `call!'
  from omniauth/strategy.rb:169:in `call'
  from omniauth/strategy.rb:192:in `call!'
  from omniauth/strategy.rb:169:in `call'
  from omniauth/strategy.rb:192:in `call!'
  from omniauth/strategy.rb:169:in `call'
  from gitlab/middleware/rails_queue_duration.rb:27:in `call'
  from gitlab/metrics/rack_middleware.rb:17:in `block in call'
  from gitlab/metrics/transaction.rb:62:in `run'
  from gitlab/metrics/rack_middleware.rb:17:in `call'
  from gitlab/request_profiler/middleware.rb:17:in `call'
  from gitlab/database/load_balancing/rack_middleware.rb:39:in `call'
  from labkit/middleware/rack.rb:19:in `block in call'
  from labkit/context.rb:31:in `with_context'
  from labkit/middleware/rack.rb🔞in `call'
  from gitlab/jira/middleware.rb:19:in `call'
  from gitlab/middleware/go.rb:20:in `call'
  from gitlab/etag_caching/middleware.rb:13:in `call'
  from batch_loader/middleware.rb:11:in `call'
  from apollo_upload_server/middleware.rb:20:in `call'
  from gitlab/middleware/multipart.rb:117:in `call'
  from rack/attack.rb:169:in `call'
  from warden/manager.rb:36:in `block in call'
  from warden/manager.rb:34:in `catch'
  from warden/manager.rb:34:in `call'
  from rack/cors.rb:98:in `call'
  from rack/tempfile_reaper.rb:15:in `call'
  from rack/etag.rb:25:in `call'
  from rack/conditional_get.rb:25:in `call'
  from rack/head.rb:12:in `call'
  from action_dispatch/http/content_security_policy.rb🔞in `call'
  from gitlab/middleware/read_only/controller.rb:48:in `call'
  from gitlab/middleware/read_only.rb🔞in `call'
  from rack/session/abstract/id.rb:232:in `context'
  from rack/session/abstract/id.rb:226:in `call'
  from action_dispatch/middleware/cookies.rb:670:in `call'
  from action_dispatch/middleware/callbacks.rb:28:in `block in call'
  from active_support/callbacks.rb:98:in `run_callbacks'
  from action_dispatch/middleware/callbacks.rb:26:in `call'
  from action_dispatch/middleware/debug_exceptions.rb:61:in `call'
  from action_dispatch/middleware/show_exceptions.rb:33:in `call'
  from gitlab/middleware/basic_health_check.rb:25:in `call'
  from rails/rack/logger.rb:38:in `call_app'
  from rails/rack/logger.rb:26:in `block in call'
  from active_support/tagged_logging.rb:71:in `block in tagged'
  from active_support/tagged_logging.rb:28:in `tagged'
  from active_support/tagged_logging.rb:71:in `tagged'
  from rails/rack/logger.rb:26:in `call'
  from action_dispatch/middleware/remote_ip.rb:81:in `call'
  from gitlab/middleware/request_context.rb:23:in `call'
  from request_store/middleware.rb:9:in `call'
  from action_dispatch/middleware/request_id.rb:27:in `call'
  from rack/method_override.rb:22:in `call'
  from rack/runtime.rb:22:in `call'
  from rack/timeout/core.rb:123:in `block in call'
  from rack/timeout/support/timeout.rb:19:in `timeout'
  from rack/timeout/core.rb:122:in `call'
  from /opt/gitlab/embedded/service/gitlab-rails/config/initializers/fix_local_cache_middleware.rb:9:in `call'
  from action_dispatch/middleware/executor.rb:14:in `call'
  from gitlab/metrics/requests_rack_middleware.rb:49:in `call'
  from rack/sendfile.rb:111:in `call'
  from raven/integrations/rack.rb:51:in `call'
  from rails/engine.rb:524:in `call'
  from rails/railtie.rb:190:in `public_send'
  from rails/railtie.rb:190:in `method_missing'
  from gitlab/middleware/release_env.rb:12:in `call'
  from rack/urlmap.rb:68:in `block in call'
  from rack/urlmap.rb:53:in `each'
  from rack/urlmap.rb:53:in `call'
  from puma/configuration.rb:228:in `call'
  from puma/server.rb:690:in `handle_request'
  from puma/server.rb:481:in `process_client'
  from puma/server.rb:335:in `block in run'
  from puma/thread_pool.rb:138:in `block in spawn_thread'

Output of checks

This bug happens on GitLab.com

Edited Jan 22, 2020 by Mark Lapierre