fix(ci): ожидание докер-лока оставляет след в логе (#2950)

Изъян в собственном критерии приёмки #2950. Я записал: «в логе второго деплоя
видна строка ожидания лока — то есть он реально ждал первого». Но flock при
успешном захвате молчит, и такой строки не бывает. Критерий был неизмеримым:
отличить «второй дождался первого» от «они просто разошлись по времени» нечем.

Теперь сначала неблокирующая попытка:

  флаг свободен  → «докер-лок свободен, взят сразу»
  флаг занят     → «докер-лок занят соседним деплоем, жду (до 900с)…»
                   потом «докер-лок получен через Nс ожидания»
  не дождались   → прежнее сообщение с подсказкой про fuser, выход 1

Длительность печатается не для красоты: без неё непонятно, ждал деплой две
секунды или четверть часа, а это разные диагнозы — разминулись случайно или
взаимное исключение несёт реальную нагрузку.

Гейт дополнен тремя проверками (flock -n, факт ожидания, длительность).
Мутация «вернуть слепой блокирующий вызов» краснит его: 1 failed, контроль
9 passed rc=0.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>

.forgejo/workflows/deploy-tradein.yml

@@ -655,10 +655,21 @@ jobs:
             # прикрывать, что и требуется. Ожидание ограничено: не дождались за
             # 900с — падаем с внятным сообщением, а не молча ждём вечно.
             exec 9>/var/lock/gendesign-docker-deploy.lock
-            if ! flock -w 900 9; then
-              echo "ERROR: не дождался лока докер-деплоя за 900с."
-              echo "       Кто держит: ssh на хост, затем fuser -v /var/lock/gendesign-docker-deploy.lock"
-              exit 1
+            # Сначала неблокирующая попытка — чтобы ОЖИДАНИЕ оставляло след в логе.
+            # Без этого работающий лок ненаблюдаем: flock при успехе молчит, и отличить
+            # «второй деплой дождался первого» от «они просто разошлись по времени»
+            # нельзя — а именно это и есть критерий приёмки #2950.
+            if flock -n 9; then
+              echo "→ докер-лок свободен, взят сразу"
+            else
+              echo "→ докер-лок занят соседним деплоем, жду (до 900с)…"
+              lock_wait_started=$(date +%s)
+              if ! flock -w 900 9; then
+                echo "ERROR: не дождался лока докер-деплоя за 900с."
+                echo "       Кто держит: ssh на хост, затем fuser -v /var/lock/gendesign-docker-deploy.lock"
+                exit 1
+              fi
+              echo "→ докер-лок получен через $(( $(date +%s) - lock_wait_started ))с ожидания"
             fi
             cd /opt/gendesign
 

.forgejo/workflows/deploy.yml

@@ -501,10 +501,21 @@ jobs:
             # прикрывать, что и требуется. Ожидание ограничено: не дождались за
             # 900с — падаем с внятным сообщением, а не молча ждём вечно.
             exec 9>/var/lock/gendesign-docker-deploy.lock
-            if ! flock -w 900 9; then
-              echo "ERROR: не дождался лока докер-деплоя за 900с."
-              echo "       Кто держит: ssh на хост, затем fuser -v /var/lock/gendesign-docker-deploy.lock"
-              exit 1
+            # Сначала неблокирующая попытка — чтобы ОЖИДАНИЕ оставляло след в логе.
+            # Без этого работающий лок ненаблюдаем: flock при успехе молчит, и отличить
+            # «второй деплой дождался первого» от «они просто разошлись по времени»
+            # нельзя — а именно это и есть критерий приёмки #2950.
+            if flock -n 9; then
+              echo "→ докер-лок свободен, взят сразу"
+            else
+              echo "→ докер-лок занят соседним деплоем, жду (до 900с)…"
+              lock_wait_started=$(date +%s)
+              if ! flock -w 900 9; then
+                echo "ERROR: не дождался лока докер-деплоя за 900с."
+                echo "       Кто держит: ssh на хост, затем fuser -v /var/lock/gendesign-docker-deploy.lock"
+                exit 1
+              fi
+              echo "→ докер-лок получен через $(( $(date +%s) - lock_wait_started ))с ожидания"
             fi
             cd /opt/gendesign
 

backend/tests/ops/test_2950_deploy_concurrency_group.py

@@ -69,6 +69,27 @@ def test_prod_deploy_takes_the_host_lock(name: str) -> None:
     )
 
 
+@pytest.mark.parametrize("name", PROD_DEPLOYS)
+def test_lock_wait_leaves_a_trace(name: str) -> None:
+    """Ожидание лока видно в логе — иначе работающий лок ненаблюдаем.
+
+    `flock` при успехе молчит. Если брать лок сразу блокирующим вызовом, отличить
+    «второй деплой дождался первого» от «они просто разошлись по времени» нельзя —
+    а это и есть критерий приёмки #2950. Поэтому сначала неблокирующая попытка, и
+    при занятом локе в лог уходит и факт ожидания, и его длительность.
+    """
+    script = _deploy_script(name)
+    assert "flock -n" in script, (
+        f"{name}: лок берётся сразу блокирующим вызовом — ожидание не попадёт в лог, "
+        "и проверить, что взаимное исключение сработало, будет нечем"
+    )
+    assert "жду" in script, f"{name}: нет строки об ожидании лока"
+    assert "с ожидания" in script, (
+        f"{name}: не печатается длительность ожидания — без неё непонятно, "
+        "ждал деплой две секунды или четверть часа"
+    )
+
+
 @pytest.mark.parametrize("name", PROD_DEPLOYS)
 def test_lock_wait_is_bounded_and_loud(name: str) -> None:
     """Ожидание ограничено и провал слышен: молча ждать вечно — не вариант."""