Gitaly times out counting tags when core Git works fine
We have a repository that had 30k+ tags pushed, and our self-hosted Gitlab instance is timing out when running Gitaly operations, even after trimming the number of tags down to around 1500.
Running the same operation with core Git commands on the server works fine:
# time git tag -l | wc -l
1448
real 0m0.030s
user 0m0.020s
sys 0m0.010sGoing to the project in the browser returns a 500 error, and looking at the error using the correlation ID returns:
# grep -h 01G11BXXD24BY8F131N97CMMBQ /mnt/gitlab-app/log/gitlab/*/*log | /user/gitdet/bin/jq
{
"method": "GET",
"path": "<REDACTED>",
"format": "html",
"controller": "ProjectsController",
"action": "show",
"status": 500,
"time": "2022-04-19T16:54:32.004Z",
"params": [
{
"key": "namespace_id",
"value": "<REDACTED>"
},
{
"key": "id",
"value": "<REDACTED>"
}
],
"correlation_id": "01G11BXXD24BY8F131N97CMMBQ",
"meta.user": "<REDACTED>",
"meta.project": "<REDACTED>",
"meta.root_namespace": "<REDACTED>",
"meta.caller_id": "ProjectsController#show",
"meta.remote_ip": "<REDACTED>",
"meta.feature_category": "projects",
"meta.client_id": "user/2",
"remote_ip": "<REDACTED>",
"user_id": 2,
"username": "<REDACTED>",
"ua": "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/100.0.4896.75 Safari/537.36 Edg/100.0.1185.39",
"queue_duration_s": 0.011018,
"request_urgency": "default",
"target_duration_s": 1,
"gitaly_calls": 1,
"gitaly_duration_s": 19.027241,
"redis_calls": 32,
"redis_duration_s": 0.00661,
"redis_read_bytes": 2266,
"redis_write_bytes": 4281,
"redis_cache_calls": 30,
"redis_cache_duration_s": 0.00619,
"redis_cache_read_bytes": 2021,
"redis_cache_write_bytes": 3074,
"redis_shared_state_calls": 1,
"redis_shared_state_duration_s": 0.000169,
"redis_shared_state_write_bytes": 53,
"redis_sessions_calls": 1,
"redis_sessions_duration_s": 0.000251,
"redis_sessions_read_bytes": 245,
"redis_sessions_write_bytes": 1154,
"db_count": 41,
"db_write_count": 0,
"db_cached_count": 8,
"db_replica_count": 0,
"db_primary_count": 41,
"db_replica_cached_count": 0,
"db_primary_cached_count": 8,
"db_replica_wal_count": 0,
"db_primary_wal_count": 0,
"db_replica_wal_cached_count": 0,
"db_primary_wal_cached_count": 0,
"db_replica_duration_s": 0,
"db_primary_duration_s": 0.021,
"cpu_s": 0.30232,
"mem_objects": 165536,
"mem_bytes": 15522744,
"mem_mallocs": 52078,
"mem_total_bytes": 22144184,
"pid": 5319,
"exception.class": "ActionView::Template::Error",
"exception.message": "4:Deadline Exceeded.",
"exception.backtrace": [
"lib/gitlab/git/wraps_gitaly_errors.rb:13:in `rescue in wrapped_gitaly_errors'",
"lib/gitlab/git/wraps_gitaly_errors.rb:6:in `wrapped_gitaly_errors'",
"lib/gitlab/git/repository.rb:192:in `tag_count'",
"app/models/repository.rb:571:in `tag_count'",
"lib/gitlab/repository_cache_adapter.rb:21:in `block (2 levels) in cache_method'",
"lib/gitlab/repository_cache.rb:25:in `fetch'",
"lib/gitlab/repository_cache_adapter.rb:163:in `block in cache_method_output'",
"lib/gitlab/utils/strong_memoize.rb:28:in `strong_memoize'",
"lib/gitlab/repository_cache_adapter.rb:203:in `block in memoize_method_output'",
"lib/gitlab/repository_cache_adapter.rb:212:in `no_repository_fallback'",
"lib/gitlab/repository_cache_adapter.rb:202:in `memoize_method_output'",
"lib/gitlab/repository_cache_adapter.rb:162:in `cache_method_output'",
"lib/gitlab/repository_cache_adapter.rb:20:in `block in cache_method'",
"app/presenters/project_presenter.rb:240:in `tags_anchor_data'",
"app/presenters/project_presenter.rb:31:in `statistics_anchors'",
"app/views/projects/_home_panel.html.haml:52",
"app/views/projects/_home_panel.html.haml:47",
"app/views/projects/show.html.haml:13",
"app/controllers/application_controller.rb:133:in `render'",
"app/controllers/application_controller.rb:541:in `block in allow_gitaly_ref_name_caching'",
"lib/gitlab/gitaly_client.rb:321:in `allow_ref_name_caching'",
"app/controllers/application_controller.rb:540:in `allow_gitaly_ref_name_caching'",
"ee/lib/gitlab/ip_address_state.rb:10:in `with'",
"ee/app/controllers/ee/application_controller.rb:46:in `set_current_ip_address'",
"app/controllers/application_controller.rb:490:in `set_current_admin'",
"lib/gitlab/session.rb:11:in `with_session'",
"app/controllers/application_controller.rb:481:in `set_session_storage'",
"lib/gitlab/i18n.rb:105:in `with_locale'",
"lib/gitlab/i18n.rb:111:in `with_user_locale'",
"app/controllers/application_controller.rb:475:in `set_locale'",
"app/controllers/application_controller.rb:469:in `set_current_context'",
"lib/gitlab/metrics/elasticsearch_rack_middleware.rb:16:in `call'",
"lib/gitlab/middleware/rails_queue_duration.rb:33:in `call'",
"lib/gitlab/middleware/speedscope.rb:13:in `call'",
"lib/gitlab/request_profiler/middleware.rb:17:in `call'",
"lib/gitlab/database/load_balancing/rack_middleware.rb:23:in `call'",
"lib/gitlab/metrics/rack_middleware.rb:16:in `block in call'",
"lib/gitlab/metrics/web_transaction.rb:46:in `run'",
"lib/gitlab/metrics/rack_middleware.rb:16:in `call'",
"lib/gitlab/jira/middleware.rb:19:in `call'",
"lib/gitlab/middleware/go.rb:20:in `call'",
"lib/gitlab/etag_caching/middleware.rb:21:in `call'",
"lib/gitlab/middleware/multipart.rb:173:in `call'",
"lib/gitlab/middleware/read_only/controller.rb:50:in `call'",
"lib/gitlab/middleware/read_only.rb:18:in `call'",
"lib/gitlab/middleware/same_site_cookies.rb:27:in `call'",
"lib/gitlab/middleware/handle_malformed_strings.rb:21:in `call'",
"lib/gitlab/middleware/basic_health_check.rb:25:in `call'",
"lib/gitlab/middleware/handle_ip_spoof_attack_error.rb:25:in `call'",
"lib/gitlab/middleware/request_context.rb:21:in `call'",
"lib/gitlab/middleware/webhook_recursion_detection.rb:15:in `call'",
"config/initializers/fix_local_cache_middleware.rb:11:in `call'",
"lib/gitlab/middleware/compressed_json.rb:26:in `call'",
"lib/gitlab/middleware/rack_multipart_tempfile_factory.rb:19:in `call'",
"lib/gitlab/middleware/sidekiq_web_static.rb:20:in `call'",
"lib/gitlab/metrics/requests_rack_middleware.rb:75:in `call'",
"lib/gitlab/middleware/release_env.rb:13:in `call'"
],
"db_duration_s": 0.03496,
"view_duration_s": 0,
"duration_s": 19.32756
}
While I could increase the Gitaly timeouts, this would only make the Web UI slower. Also, the native Git command is fast, so there's no reason for Gitaly to be so slow.
What can I do to help debug this further?