Increased "fatal: expected flush after ref listing" errors & push_from_secondary redirects
On git clones from git.drupalcode.org we've been seeing increased intermittent errors like
error: RPC failed; HTTP 302 curl 22 The requested URL returned error: 302
fatal: expected flush after ref listingI was able to capture this error with GIT_CURL_VERBOSE=1 git clone ``https://git.drupalcode.org/project/drupal.git
We've been seeing lots of warning: redirecting to ``https://git.drupalcode.org/-/push_from_secondary/9/project/drupal.git/ on git clone, potentially correlated to after upgrading to 16.3.1, which we are still running. It seems like we get this on 100% of requests now.
Our setup is 2 omnibus installations, a geo primary & secondary. /admin/geo/sites reports everything is synced and good. 99% of the HTTP traffic is routed to the secondary, I confirmed the last correlation ID in bad.txt is in the secondary's logs:
$ sudo grep -R 01HAJNSF37MBKJZF6DVT0WC7PA /var/log/gitlab/
/var/log/gitlab/gitlab-rails/production_json.log:{"method":"POST","path":"/project/drupal.git/git-upload-pack","format":null,"controller":"Repositories::GitHttpController","action":"git_upload_pack","status":302,"location":"https://git.drupalcode.org/-/push_from_secondary/9/project/drupal.git/git-upload-pack","time":"2023-09-17T22:57:12.850Z","params":[{"key":"repository_path","value":"project/drupal.git"}],"remote_ip":"216.59.172.224","ua":"git/2.39.1","request_urgency":"default","target_duration_s":1,"redis_calls":7,"redis_duration_s":0.001389,"redis_read_bytes":1245,"redis_write_bytes":466,"redis_cache_calls":2,"redis_cache_duration_s":0.000524,"redis_cache_read_bytes":250,"redis_cache_write_bytes":148,"redis_feature_flag_calls":5,"redis_feature_flag_duration_s":0.000865,"redis_feature_flag_read_bytes":995,"redis_feature_flag_write_bytes":318,"db_count":8,"db_write_count":0,"db_cached_count":1,"db_replica_count":0,"db_primary_count":8,"db_main_count":7,"db_geo_count":1,"db_ci_count":0,"db_main_replica_count":0,"db_ci_replica_count":0,"db_replica_cached_count":0,"db_primary_cached_count":1,"db_main_cached_count":1,"db_geo_cached_count":0,"db_ci_cached_count":0,"db_main_replica_cached_count":0,"db_ci_replica_cached_count":0,"db_replica_wal_count":0,"db_primary_wal_count":0,"db_main_wal_count":0,"db_geo_wal_count":0,"db_ci_wal_count":0,"db_main_replica_wal_count":0,"db_ci_replica_wal_count":0,"db_replica_wal_cached_count":0,"db_primary_wal_cached_count":0,"db_main_wal_cached_count":0,"db_geo_wal_cached_count":0,"db_ci_wal_cached_count":0,"db_main_replica_wal_cached_count":0,"db_ci_replica_wal_cached_count":0,"db_replica_duration_s":0.0,"db_primary_duration_s":0.006,"db_main_duration_s":0.006,"db_geo_duration_s":0.0,"db_ci_duration_s":0.0,"db_main_replica_duration_s":0.0,"db_ci_replica_duration_s":0.0,"cpu_s":0.036872,"mem_objects":14039,"mem_bytes":1761818,"mem_mallocs":4176,"mem_total_bytes":2323378,"pid":3754239,"worker_id":"puma_11","rate_limiting_gates":[],"correlation_id":"01HAJNSF37MBKJZF6DVT0WC7PA","db_duration_s":0.00266,"view_duration_s":0.0,"duration_s":0.01718}
/var/log/gitlab/gitlab-workhorse/current:gitlab-aws gitlab-workhorse: {"content_type":"text/html; charset=utf-8","correlation_id":"01HAJNSF37MBKJZF6DVT0WC7PA","duration_ms":46,"host":"git.drupalcode.org","level":"info","method":"POST","msg":"access","proto":"HTTP/1.1","referrer":"","remote_addr":"216.59.172.224:0","remote_ip":"216.59.172.224","route":"^/[^-].+\\.git/git-upload-pack\\z","status":302,"system":"http","time":"2023-09-17T22:57:12Z","ttfb_ms":46,"uri":"/project/drupal.git/git-upload-pack","user_agent":"git/2.39.1","written_bytes":151}