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
- 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:18: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:18: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:18:in `call'
from gitlab/middleware/read_only/controller.rb:48:in `call'
from gitlab/middleware/read_only.rb:18: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 by Mark Lapierre