Timeout on deleting a user account
Summary
Our cron script delete users from gitlab. The script worked without problems for a long time but on last run a user couldn't deleted. GitLab terminates deleting of the user account with ERROR: canceling statement due to statement timeout
.
Execution of Delete user
on administrator gui produce same errors.
What is the current bug behavior?
API-Call: https://host/api/v4/users/1470?private_token=xxxxxxxx&hard_delete=true
API-Response (HTTP-Status): 204
Sidekiq: Job raised exception
PostgreSql: canceling statement due to statement timeout
What is the expected correct behavior?
User deleted
Relevant logs and/or screenshots
Production system - Log
Sidekiq
2019-06-03_08:24:14.10509 2019-06-03T08:24:14.105Z 19083 TID-osfkymk33 WARN: {"context":"Job raised exception","job":{"class":"DeleteUserWorker","args":[1,1470,{"private_token":"xxxxxxx","hard_delete":false,"id":1470}],"retry":3,"queue":"delete_user","jid":"c32fb728d0c6ff789fb708e7","created_at":1559549221.102758,"correlation_id":"JqieJneyHU1","enqueued_at":1559549456.366244,"error_message":"PG::QueryCanceled: ERROR: canceling statement due to statement timeout\nCONTEXT: while updating tuple (56,5) in relation \"notes\"\n: UPDATE \"notes\" SET \"author_id\" = 1064 WHERE \"notes\".\"author_id\" = 1470","error_class":"ActiveRecord::StatementInvalid","failed_at":1559549282.732489,"retry_count":1,"retried_at":1559549383.5560215},"jobstr":"{\"class\":\"DeleteUserWorker\",\"args\":[1,1470,{\"private_token\":\"xxxxxxx\",\"hard_delete\":false,\"id\":1470}],\"retry\":3,\"queue\":\"delete_user\",\"jid\":\"c32fb728d0c6ff789fb708e7\",\"created_at\":1559549221.102758,\"correlation_id\":\"JqieJneyHU1\",\"enqueued_at\":1559549456.366244,\"error_message\":\"PG::QueryCanceled: ERROR: canceling statement due to statement timeout\\nCONTEXT: whileupdating tuple (56,5) in relation \\\"notes\\\"\\n: UPDATE \\\"notes\\\" SET \\\"author_id\\\" = 1064 WHERE \\\"notes\\\".\\\"author_id\\\" = 1470\",\"error_class\":\"ActiveRecord::StatementInvalid\",\"failed_at\":1559549282.732489,\"retry_count\":1,\"retried_at\":1559549383.5560215}"}
Postgresql
2019-06-03_08:24:05.84130 FATAL: terminating connection due to idle-in-transaction timeout
2019-06-03_08:24:05.84157 LOG: process 105654 acquired ShareLock on transaction 18359698 after 41953.369 ms
2019-06-03_08:24:05.84158 CONTEXT: while deleting tuple (3,137) in relation "project_authorizations"
2019-06-03_08:24:05.84158 STATEMENT: DELETE FROM "project_authorizations" WHERE "project_authorizations"."user_id" = 1470 AND "project_authorizations"."project_id" IN (122, 123, 145, 157, 169, 204, 332, 362, 364, 365, 369, 370, 373, 376, 377, 378, 380, 695, 701, 737, 759, 897, 1051, 1168, 1463, 1466, 1478, 1505, 1507, 1522, 1533, 1534, 1561, 1565, 1566, 1649, 1749, 1821, 1872, 1947, 2068, 2119, 2324, 2366, 2381, 2395, 2406, 2409, 2412, 2557, 2569, 2629, 2630, 2690, 2869, 2928, 2931, 3058, 3078, 3098, 3185, 3309, 3355, 3412, 3418, 3465, 3650, 3694, 3696, 3708, 3709, 3757, 3763, 3791, 4000, 4003, 4032, 4146, 4202, 4211, 4239, 4248, 4281, 4286, 4342, 4381, 4526, 4530, 5103, 5118, 5312, 5410, 5636, 5649, 5650, 5853, 5988, 6015, 6041, 6092, 6143, 6263, 6285, 6371, 6412, 6418, 6482, 6503, 6504, 6506, 6511, 6530, 6548, 6555, 6588, 6686, 6693, 6706, 6847, 6954, 6984, 7104, 7293, 7319, 7358, 7366, 7367, 7374, 7379, 7387, 7392, 7409, 7410, 7411, 7416, 7427, 7432, 7433, 7439, 7448, 7482, 7518, 7576, 7587, 7597, 7733, 7773, 7829, 7862, 7867, 7905, 8176, 8279, 8285, 8336, 8358, 8462, 8499, 8534, 8679, 8686, 8762, 8783, 8804, 8835, 8852, 8862, 8932, 8960, 9106, 9117, 9167, 9228, 9233, 9319, 9504, 9531, 9666, 9744, 9960, 10115, 10181, 10290, 10293, 10654, 10866, 10869, 11070, 11497, 11574, 11760, 12026, 12163, 12166, 12170, 12196, 12369, 12483, 12505, 12592, 12860, 12912, 12943, 13050, 13157, 13171, 13221, 13372, 13614, 13656, 13834, 13918, 13938)
Additional test on another system which same data set (Cold standby system) - Log
Sidekiq
2019-06-03_10:50:04.76058 2019-06-03T10:50:04.758Z 42017 TID-os28y94x1 ExpireBuildArtifactsWorker JID-0fa316182fbe737928ab0e86 INFO: done: 2.727 sec
2019-06-03_10:59:56.90902 FATAL: terminating connection due to idle-in-transaction timeout
2019-06-03_10:59:56.91586 2019-06-03T10:59:56.915Z 42017 TID-os28y951d DeleteUserWorker JID-d7af03f4b866c387f449f443 INFO: Adding dead DeleteUserWorker job d7af03f4b866c387f449f443
2019-06-03_10:59:56.92286 2019-06-03T10:59:56.920Z 42017 TID-os28y951d DeleteUserWorker JID-d7af03f4b866c387f449f443 INFO: fail: 1067.233 sec
2019-06-03_10:59:56.92288 2019-06-03T10:59:56.920Z 42017 TID-os28y951d WARN: {"context":"Job raised exception","job":{"class":"DeleteUserWorker","args":[1,1470,{"private_token":"xxxxxx","hard_delete":true,"id":1470}],"retry":3,"queue":"delete_user","jid":"d7af03f4b866c387f449f443","created_at":1559554974.848926,"correlation_id":"NSmUNdS9VC4","enqueued_at":1559558529.6831517,"error_message":"PG::UnableToSend: no connection to the server\n: SELECT \"feature_gates\".* FROM \"feature_gates\" WHERE \"feature_gates\".\"feature_key\" = 'prometheus_transaction_event_sidekiq_exception_total'","error_class":"ActiveRecord::StatementInvalid","failed_at":1559556080.6999009,"retry_count":2,"retried_at":1559558475.4082093},"jobstr":"{\"class\":\"DeleteUserWorker\",\"args\":[1,1470,{\"private_token\":\"xxxxxxxx\",\"hard_delete\":true,\"id\":1470}],\"retry\":3,\"queue\":\"delete_user\",\"jid\":\"d7af03f4b866c387f449f443\",\"created_at\":1559554974.848926,\"correlation_id\":\"NSmUNdS9VC4\",\"enqueued_at\":1559558529.6831517,\"error_message\":\"PG::UnableToSend: no connection to the server\\n: SELECT \\\"feature_gates\\\".* FROM \\\"feature_gates\\\" WHERE \\\"feature_gates\\\".\\\"feature_key\\\" = 'prometheus_transaction_event_sidekiq_exception_total'\",\"error_class\":\"ActiveRecord::StatementInvalid\",\"failed_at\":1559556080.6999009,\"retry_count\":2,\"retried_at\":1559558475.4082093}"}
Output of checks
Results of GitLab environment info
Expand for output related to GitLab environment info
System information System: RedHatEnterpriseServer 7.6 Current User: git Using RVM: no Ruby Version: 2.5.3p105 Gem Version: 2.7.6 Bundler Version:1.17.3 Rake Version: 12.3.2 Redis Version: 3.2.12 Git Version: 2.18.1 Sidekiq Version:5.2.5 Go Version: unknown
GitLab information Version: 11.10.4 Revision: 62c464651d2 Directory: /data/opt/gitlab/embedded/service/gitlab-rails DB Adapter: PostgreSQL DB Version: 9.6.11 URL: https://host HTTP Clone URL: https://host/some-group/some-project.git SSH Clone URL: git@localhost:some-group/some-project.git Using LDAP: yes Using Omniauth: yes Omniauth Providers:
GitLab Shell Version: 9.0.0 Repository storage paths: default: /data/var/opt/gitlab/git-data/repositories GitLab Shell path: /opt/gitlab/embedded/service/gitlab-shell Git: /opt/gitlab/embedded/bin/git
Results of GitLab application Check
Expand for output related to the GitLab application check
Checking GitLab subtasks ... Checking GitLab Shell ... GitLab Shell: ... GitLab Shell version >= 9.0.0 ? ... OK (9.0.0) Running /opt/gitlab/embedded/service/gitlab-shell/bin/check Check GitLab API access: OK Redis available via internal API: OK Access to /data/var/opt/gitlab/.ssh/authorized_keys: OK gitlab-shell self-check successful Checking GitLab Shell ... Finished Checking Gitaly ... Gitaly: ... default ... OK Checking Gitaly ... Finished Checking Sidekiq ... Sidekiq: ... Running? ... yes Number of Sidekiq processes ... 1 Checking Sidekiq ... Finished Checking Incoming Email ... Incoming Email: ... Reply by email is disabled in config/gitlab.yml Checking Incoming Email ... Finished Checking LDAP ... LDAP: ... Server: ldapmain LDAP authentication... Success Checking LDAP ... Finished Checking GitLab App ... Git configured correctly? ... yes Database config exists? ... yes All migrations up? ... yes Database contains orphaned GroupMembers? ... no GitLab config exists? ... yes GitLab config up to date? ... yes Log directory writable? ... yes Tmp directory writable? ... yes Uploads directory exists? ... yes Uploads directory has correct permissions? ... yes Uploads directory tmp has correct permissions? ... yes Init script exists? ... no Try fixing it: Install the init script For more information see: doc/install/installation.md in section "Install Init Script" Please fix the error above and rerun the checks. Init script up-to-date? ... can't check because of previous errors Redis version >= 2.8.0? ... yes Ruby version >= 2.5.3 ? ... yes (2.5.3) Git version >= 2.18.0 ? ... yes (2.18.1) Git user has default SSH configuration? ... yes Active users: ... 3297 Checking GitLab App ... Finished Checking GitLab subtasks ... Finished
Possible fixes
(If you can, link to the line of code that might be responsible for the problem)