Failures in Geo::RepositoryDestroyWorker: Deadline Exceeded
After turning on the GRPD nodes, I started seeing a lot of messages due to Gitaly saying 4:Deadline Exceeded such as:
2018-03-16_05:26:59.60988 sidekiq-besteffort-01-sv-gprd sidekiq-cluster: 2018-03-16T05:26:59.609Z 51815 TID-or9plmolc WARN: {"context":"Job raised exception","job":{"class":"GeoRepositoryDestroyWorker","args":[5747540,"pet_clinic","fardin.2018/pet_clinic","nfs-file16"],"retry":3,"queue":"geo:geo_repository_destroy","queue_namespace":"geo","jid":"8cadf1c662c72a920772c880","created_at":1521177897.065036,"enqueued_at":1521178007.291986,"error_message":"4:Deadline Exceeded","error_class":"GRPC::DeadlineExceeded","failed_at":1521177910.0470793,"retry_count":1,"retried_at":1521177957.7555532},"jobstr":"{\"class\":\"GeoRepositoryDestroyWorker\",\"args\":[5747540,\"pet_clinic\",\"fardin.2018/pet_clinic\",\"nfs-file16\"],\"retry\":3,\"queue\":\"geo:geo_repository_destroy\",\"queue_namespace\":\"geo\",\"jid\":\"8cadf1c662c72a920772c880\",\"created_at\":1521177897.065036,\"enqueued_at\":1521178007.291986,\"error_message\":\"4:Deadline Exceeded\",\"error_class\":\"GRPC::DeadlineExceeded\",\"failed_at\":1521177910.0470793,\"retry_count\":1,\"retried_at\":1521177957.7555532}"}
2018-03-16_05:26:59.60995 sidekiq-besteffort-01-sv-gprd sidekiq-cluster: 2018-03-16T05:26:59.609Z 51815 TID-or9plmolc WARN: GRPC::DeadlineExceeded: 4:Deadline Exceeded
2018-03-16_05:26:59.61001 sidekiq-besteffort-01-sv-gprd sidekiq-cluster: 2018-03-16T05:26:59.609Z 51815 TID-or9plmolc WARN: /opt/gitlab/embedded/lib/ruby/gems/2.3.0/gems/grpc-1.8.3-x86_64-linux/src/ruby/lib/grpc/generic/active_call.rb:31:in `check_status'
2018-03-16_05:26:59.61003 sidekiq-besteffort-01-sv-gprd sidekiq-cluster: /opt/gitlab/embedded/lib/ruby/gems/2.3.0/gems/grpc-1.8.3-x86_64-linux/src/ruby/lib/grpc/generic/active_call.rb:180:in `attach_status_results_and_complete_call'
2018-03-16_05:26:59.61005 sidekiq-besteffort-01-sv-gprd sidekiq-cluster: /opt/gitlab/embedded/lib/ruby/gems/2.3.0/gems/grpc-1.8.3-x86_64-linux/src/ruby/lib/grpc/generic/active_call.rb:372:in `request_response'
2018-03-16_05:26:59.61007 sidekiq-besteffort-01-sv-gprd sidekiq-cluster: /opt/gitlab/embedded/lib/ruby/gems/2.3.0/gems/grpc-1.8.3-x86_64-linux/src/ruby/lib/grpc/generic/client_stub.rb:178:in `block in request_response'
2018-03-16_05:26:59.61009 sidekiq-besteffort-01-sv-gprd sidekiq-cluster: /opt/gitlab/embedded/lib/ruby/gems/2.3.0/gems/grpc-1.8.3-x86_64-linux/src/ruby/lib/grpc/generic/interceptors.rb:170:in `intercept!'
2018-03-16_05:26:59.61011 sidekiq-besteffort-01-sv-gprd sidekiq-cluster: /opt/gitlab/embedded/lib/ruby/gems/2.3.0/gems/grpc-1.8.3-x86_64-linux/src/ruby/lib/grpc/generic/client_stub.rb:177:in `request_response'
2018-03-16_05:26:59.61013 sidekiq-besteffort-01-sv-gprd sidekiq-cluster: /opt/gitlab/embedded/lib/ruby/gems/2.3.0/gems/grpc-1.8.3-x86_64-linux/src/ruby/lib/grpc/generic/service.rb:170:in `block (3 levels) in rpc_stub_class'
2018-03-16_05:26:59.61016 sidekiq-besteffort-01-sv-gprd sidekiq-cluster: /opt/gitlab/embedded/service/gitlab-rails/lib/gitlab/gitaly_client.rb:127:in `call'
2018-03-16_05:26:59.61018 sidekiq-besteffort-01-sv-gprd sidekiq-cluster: /opt/gitlab/embedded/service/gitlab-rails/lib/gitlab/gitaly_client/repository_service.rb:17:in `exists?'
2018-03-16_05:26:59.61020 sidekiq-besteffort-01-sv-gprd sidekiq-cluster: /opt/gitlab/embedded/service/gitlab-rails/lib/gitlab/git/repository.rb:142:in `block in exists?'
2018-03-16_05:26:59.61021 sidekiq-besteffort-01-sv-gprd sidekiq-cluster: /opt/gitlab/embedded/service/gitlab-rails/lib/gitlab/gitaly_client.rb:255:in `block (2 levels) in migrate'
2018-03-16_05:26:59.61024 sidekiq-besteffort-01-sv-gprd sidekiq-cluster: /opt/gitlab/embedded/service/gitlab-rails/lib/gitlab/gitaly_client.rb:297:in `allow_n_plus_1_calls'
2018-03-16_05:26:59.61025 sidekiq-besteffort-01-sv-gprd sidekiq-cluster: /opt/gitlab/embedded/service/gitlab-rails/lib/gitlab/gitaly_client.rb:250:in `block in migrate'
2018-03-16_05:26:59.61027 sidekiq-besteffort-01-sv-gprd sidekiq-cluster: /opt/gitlab/embedded/service/gitlab-rails/lib/gitlab/metrics/influx_db.rb:103:in `measure'
2018-03-16_05:26:59.61030 sidekiq-besteffort-01-sv-gprd sidekiq-cluster: /opt/gitlab/embedded/service/gitlab-rails/lib/gitlab/gitaly_client.rb:248:in `migrate'
2018-03-16_05:26:59.61032 sidekiq-besteffort-01-sv-gprd sidekiq-cluster: /opt/gitlab/embedded/service/gitlab-rails/lib/gitlab/git/repository.rb:140:in `exists?'
2018-03-16_05:26:59.61033 sidekiq-besteffort-01-sv-gprd sidekiq-cluster: /opt/gitlab/embedded/service/gitlab-rails/app/models/repository.rb:512:in `exists?'
2018-03-16_05:26:59.61036 sidekiq-besteffort-01-sv-gprd sidekiq-cluster: /opt/gitlab/embedded/service/gitlab-rails/lib/gitlab/metrics/instrumentation.rb:159:in `block in _uncached_exists?'
2018-03-16_05:26:59.61039 sidekiq-besteffort-01-sv-gprd sidekiq-cluster: /opt/gitlab/embedded/service/gitlab-rails/lib/gitlab/metrics/method_call.rb:36:in `measure'
2018-03-16_05:26:59.61041 sidekiq-besteffort-01-sv-gprd sidekiq-cluster: /opt/gitlab/embedded/service/gitlab-rails/lib/gitlab/metrics/instrumentation.rb:159:in `_uncached_exists?'
2018-03-16_05:26:59.61043 sidekiq-besteffort-01-sv-gprd sidekiq-cluster: /opt/gitlab/embedded/service/gitlab-rails/app/models/repository.rb:78:in `block (2 levels) in cache_method'
2018-03-16_05:26:59.61045 sidekiq-besteffort-01-sv-gprd sidekiq-cluster: /opt/gitlab/embedded/lib/ruby/gems/2.3.0/gems/activesupport-4.2.10/lib/active_support/cache.rb:299:in `block in fetch'
2018-03-16_05:26:59.61048 sidekiq-besteffort-01-sv-gprd sidekiq-cluster: /opt/gitlab/embedded/lib/ruby/gems/2.3.0/gems/activesupport-4.2.10/lib/active_support/cache.rb:585:in `block in save_block_result_to_cache'
2018-03-16_05:26:59.61049 sidekiq-besteffort-01-sv-gprd sidekiq-cluster: /opt/gitlab/embedded/lib/ruby/gems/2.3.0/gems/activesupport-4.2.10/lib/active_support/cache.rb:547:in `block in instrument'
2018-03-16_05:26:59.61051 sidekiq-besteffort-01-sv-gprd sidekiq-cluster: /opt/gitlab/embedded/lib/ruby/gems/2.3.0/gems/activesupport-4.2.10/lib/active_support/notifications.rb:164:in `block in instrument'
2018-03-16_05:26:59.61053 sidekiq-besteffort-01-sv-gprd sidekiq-cluster: /opt/gitlab/embedded/lib/ruby/gems/2.3.0/gems/activesupport-4.2.10/lib/active_support/notifications/instrumenter.rb:20:in `instrument'
2018-03-16_05:26:59.61055 sidekiq-besteffort-01-sv-gprd sidekiq-cluster: /opt/gitlab/embedded/lib/ruby/gems/2.3.0/gems/activesupport-4.2.10/lib/active_support/notifications.rb:164:in `instrument'
2018-03-16_05:26:59.61058 sidekiq-besteffort-01-sv-gprd sidekiq-cluster: /opt/gitlab/embedded/lib/ruby/gems/2.3.0/gems/activesupport-4.2.10/lib/active_support/cache.rb:547:in `instrument'
2018-03-16_05:26:59.61060 sidekiq-besteffort-01-sv-gprd sidekiq-cluster: /opt/gitlab/embedded/lib/ruby/gems/2.3.0/gems/activesupport-4.2.10/lib/active_support/cache.rb:584:in `save_block_result_to_cache'
2018-03-16_05:26:59.61062 sidekiq-besteffort-01-sv-gprd sidekiq-cluster: /opt/gitlab/embedded/lib/ruby/gems/2.3.0/gems/activesupport-4.2.10/lib/active_support/cache.rb:299:in `fetch'
2018-03-16_05:26:59.61064 sidekiq-besteffort-01-sv-gprd sidekiq-cluster: /opt/gitlab/embedded/service/gitlab-rails/lib/repository_cache.rb:20:in `fetch'
2018-03-16_05:26:59.61066 sidekiq-besteffort-01-sv-gprd sidekiq-cluster: /opt/gitlab/embedded/service/gitlab-rails/app/models/repository.rb:1013:in `cache_method_output'
2018-03-16_05:26:59.61068 sidekiq-besteffort-01-sv-gprd sidekiq-cluster: /opt/gitlab/embedded/service/gitlab-rails/lib/gitlab/metrics/instrumentation.rb:159:in `block in cache_method_output'
2018-03-16_05:26:59.61070 sidekiq-besteffort-01-sv-gprd sidekiq-cluster: /opt/gitlab/embedded/service/gitlab-rails/lib/gitlab/metrics/method_call.rb:36:in `measure'
2018-03-16_05:26:59.61071 sidekiq-besteffort-01-sv-gprd sidekiq-cluster: /opt/gitlab/embedded/service/gitlab-rails/lib/gitlab/metrics/instrumentation.rb:159:in `cache_method_output'
2018-03-16_05:26:59.61073 sidekiq-besteffort-01-sv-gprd sidekiq-cluster: /opt/gitlab/embedded/service/gitlab-rails/app/models/repository.rb:77:in `block in cache_method'
2018-03-16_05:26:59.61076 sidekiq-besteffort-01-sv-gprd sidekiq-cluster: /opt/gitlab/embedded/service/gitlab-rails/lib/gitlab/metrics/instrumentation.rb:159:in `block in exists?'
2018-03-16_05:26:59.61078 sidekiq-besteffort-01-sv-gprd sidekiq-cluster: /opt/gitlab/embedded/service/gitlab-rails/lib/gitlab/metrics/method_call.rb:36:in `measure'
2018-03-16_05:26:59.61080 sidekiq-besteffort-01-sv-gprd sidekiq-cluster: /opt/gitlab/embedded/service/gitlab-rails/lib/gitlab/metrics/instrumentation.rb:159:in `exists?'
2018-03-16_05:26:59.61082 sidekiq-besteffort-01-sv-gprd sidekiq-cluster: /opt/gitlab/embedded/service/gitlab-rails/app/models/repository.rb:404:in `before_delete'
2018-03-16_05:26:59.61084 sidekiq-besteffort-01-sv-gprd sidekiq-cluster: /opt/gitlab/embedded/service/gitlab-rails/lib/gitlab/metrics/instrumentation.rb:159:in `block in before_delete'
2018-03-16_05:26:59.61087 sidekiq-besteffort-01-sv-gprd sidekiq-cluster: /opt/gitlab/embedded/service/gitlab-rails/lib/gitlab/metrics/method_call.rb:36:in `measure'
2018-03-16_05:26:59.61089 sidekiq-besteffort-01-sv-gprd sidekiq-cluster: /opt/gitlab/embedded/service/gitlab-rails/lib/gitlab/metrics/instrumentation.rb:159:in `before_delete'
2018-03-16_05:26:59.61091 sidekiq-besteffort-01-sv-gprd sidekiq-cluster: /opt/gitlab/embedded/service/gitlab-rails/app/services/projects/destroy_service.rb:136:in `flush_caches'
2018-03-16_05:26:59.61094 sidekiq-besteffort-01-sv-gprd sidekiq-cluster: /opt/gitlab/embedded/service/gitlab-rails/lib/gitlab/metrics/instrumentation.rb:159:in `block in flush_caches'
2018-03-16_05:26:59.61096 sidekiq-besteffort-01-sv-gprd sidekiq-cluster: /opt/gitlab/embedded/service/gitlab-rails/lib/gitlab/metrics/method_call.rb:36:in `measure'
2018-03-16_05:26:59.61099 sidekiq-besteffort-01-sv-gprd sidekiq-cluster: /opt/gitlab/embedded/service/gitlab-rails/lib/gitlab/metrics/instrumentation.rb:159:in `flush_caches'
2018-03-16_05:26:59.61101 sidekiq-besteffort-01-sv-gprd sidekiq-cluster: /opt/gitlab/embedded/service/gitlab-rails/ee/app/services/ee/projects/destroy_service.rb:42:in `geo_replicate'
2018-03-16_05:26:59.61103 sidekiq-besteffort-01-sv-gprd sidekiq-cluster: /opt/gitlab/embedded/service/gitlab-rails/ee/app/services/geo/repository_destroy_service.rb:17:in `execute'
2018-03-16_05:26:59.61105 sidekiq-besteffort-01-sv-gprd sidekiq-cluster: /opt/gitlab/embedded/service/gitlab-rails/ee/app/workers/geo_repository_destroy_worker.rb:7:in `perform'
2018-03-16_05:26:59.61107 sidekiq-besteffort-01-sv-gprd sidekiq-cluster: /opt/gitlab/embedded/lib/ruby/gems/2.3.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:188:in `execute_job'
2018-03-16_05:26:59.61109 sidekiq-besteffort-01-sv-gprd sidekiq-cluster: /opt/gitlab/embedded/lib/ruby/gems/2.3.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:170:in `block (2 levels) in process'
2018-03-16_05:26:59.61111 sidekiq-besteffort-01-sv-gprd sidekiq-cluster: /opt/gitlab/embedded/lib/ruby/gems/2.3.0/gems/sidekiq-5.0.5/lib/sidekiq/middleware/chain.rb:128:in `block in invoke'
2018-03-16_05:26:59.61113 sidekiq-besteffort-01-sv-gprd sidekiq-cluster: /opt/gitlab/embedded/service/gitlab-rails/lib/gitlab/sidekiq_status/server_middleware.rb:5:in `call'
2018-03-16_05:26:59.61115 sidekiq-besteffort-01-sv-gprd sidekiq-cluster: /opt/gitlab/embedded/lib/ruby/gems/2.3.0/gems/sidekiq-5.0.5/lib/sidekiq/middleware/chain.rb:130:in `block in invoke'