Files
keycloak-pattern/docs/evidence/d4a-deploy-hook/01-hook-verified.txt
T
DongHyeonkaandClaude Opus 5 e9baac21d5 docs(d4a): the deploy hook works — issuance to serving drops from 38m25s to 1-2s
D-4 named the fix and never ran it. Running it:

  /etc/letsencrypt/renewal-hooks/deploy/reload-nginx.sh
    #!/bin/sh
    nginx -t && nginx -s reload

certbot reports "Hook 'deploy-hook' ran", the master stays at PID 585 and
the worker is replaced 28829 -> 37252, and the served certificate changes.

One trap worth naming: certbot prefixes the hook output with "ran with error
output" whenever the hook writes anything to stderr, and nginx's routine
types_hash warning goes to stderr. Everything inside is success — "test is
successful", "signal process started". A monitor that greps for "error"
would read a working hook as a failure. The worker PID is what to check.

Timing needed a clock correction. test-server has NTP off and runs 106
seconds fast; the dev machine matches Google and the Let's Encrypt ACME
endpoint exactly. Corrected, the hook's nginx -t lands at 12:27:50 UTC
against the new certificate's SCT at 12:27:49.054 — one second. The
correction validates itself: uncorrected, the hook would have run 104
seconds before the certificate existed.

That same skew is why D-4's gap was reported 106 seconds short; corrected to
2305s in the previous commit.

Remaining and left alone: whether certbot-renew.timer performs a real
renewal, which cannot be tested for about 89 days.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
2026-09-04 21:35:00 +09:00

126 lines
6.2 KiB
Plaintext
Raw Blame History

This file contains ambiguous Unicode characters
This file contains Unicode characters that might be confused with other characters. If you think that this is intentional, you can safely ignore this warning. Use the Escape button to reveal them.
D-4a — deploy 훅이 실제로 nginx 를 reload 하는가
==================================================
수집: 2026-09-04 12:27 UTC (실제) · test-server
D-4 가 남긴 것
--------------
| 항목 | 상태 |
|---|---|
| deploy 훅을 넣으면 자동 반영되는가 | **미측정. 훅은 아직 넣지 않았다** |
D-4 는 처방을 적어두고 **검증하지 않았다.** 처방이 듣는지 모르는 채로
"이렇게 고치면 된다"고 쓰는 것은 이 실험대가 계속 경계해 온 바로 그 실수다.
[주입] 훅 하나를 넣고 강제 갱신
--------------------------------
/etc/letsencrypt/renewal-hooks/deploy/reload-nginx.sh
#!/bin/sh
# D-4a: certbot deploy hook. 갱신이 실제로 일어났을 때만 실행된다.
nginx -t && nginx -s reload
install -m755 /tmp/reload-nginx.sh /etc/letsencrypt/renewal-hooks/deploy/
certbot renew --force-renewal
[결과] certbot 출력 — 훅이 실행됐다
------------------------------------
Processing /etc/letsencrypt/renewal/auth.hyeonworks.com.conf
Renewing an existing certificate for auth.hyeonworks.com and 2 more
Hook 'deploy-hook' ran with error output:
2026/09/04 21:29:36 [warn] 37250#37250: could not build optimal types_hash, …
nginx: the configuration file /etc/nginx/nginx.conf syntax is ok
nginx: configuration file /etc/nginx/nginx.conf test is successful
2026/09/04 21:29:37 [warn] 37251#37251: could not build optimal types_hash, …
2026/09/04 21:29:37 [notice] 37251#37251: signal process started
Congratulations, all renewals succeeded:
/etc/letsencrypt/live/auth.hyeonworks.com/fullchain.pem (success)
★ 함정 — "Hook 'deploy-hook' ran with error output" 이라고 적혀 있지만
실패가 아니다. nginx 가 types_hash 경고를 stderr 로 내보내서 certbot 이
그것을 "error output" 으로 표시한 것뿐이다. 내용은 전부 성공이다:
· nginx -t → "test is successful"
· nginx -s reload → "signal process started"
로그에서 'error' 를 grep 하면 성공한 훅을 실패로 오독하게 된다.
[검증 1] nginx 워커가 교체됐다
-------------------------------
전 (D-4a 기준선)
585 1 ... Thu Sep 3 19:00:39 nginx: master process
28829 585 ... Fri Sep 4 18:00:35 nginx: worker process ← D-4 에서 사람이 reload 한 것
585 1 95412 Thu Sep 3 19:00:39 nginx: master process ← 마스터는 그대로
37252 585 74 Fri Sep 4 21:29:36 nginx: worker process ← ★ 자동 교체됨
마스터 PID 는 유지되고 워커만 바뀌었다 = reload 의 서명. D-4 에서 세운
진단 방법이 그대로 작동한다.
[검증 2] 서빙 인증서가 바뀌었다
--------------------------------
serial=06F3E0EF4D1BB03DE58130EAAD1176101373
notBefore=Sep 4 11:29:18 2026 GMT
notAfter=Dec 3 11:29:17 2026 GMT
SAN: app1 / app2 / auth .hyeonworks.com
D-4 의 인증서(06C7CB…EA1D)에서 바뀌었다.
[검증 3] ★ 얼마나 빨랐나 — 시계 보정이 필요하다
--------------------------------------------------
훅 로그와 워커 lstart 는 **test-server 시계**다. 그런데 test-server 는
NTP 동기가 꺼져 있다(NTPSynchronized=no).
외부 기준으로 두 시계를 검증했다.
dev → Google 차이 +0초
dev → Let's Encrypt ACME 차이 +0초
test-server → Google 차이 -105초 (즉 test-server 가 105초 빠르다)
ssh 왕복 왜곡 3회 측정: +106.1 / +106.1 / +106.1초 (안정적)
→ **dev 가 정확하고 test-server 가 106초 빠르다.**
독립 검증 — 새 인증서의 SCT (CT 로그가 서명한 시각, 자체 정확 시계):
Signed Certificate Timestamp: Sep 4 12:27:49.054 2026 GMT
Signed Certificate Timestamp: Sep 4 12:27:49.048 2026 GMT
보정한 타임라인 (전부 실제 UTC):
12:27:49.05 인증서 발급 ← SCT. 외부 권위 기준
12:27:50 훅 nginx -t ← 로그 21:29:36 KST 106초
12:27:50 새 워커 37252 기동 ← lstart 21:29:36 KST 106초
12:27:51 훅 nginx -s reload ← 로그 21:29:37 KST 106초
★ 발급 → 서빙까지 **1~2초.**
★ 그리고 보정이 자기 검증된다 — 독립 시계인 SCT 가 보정한 훅 시각의
1초 앞에 정확히 놓인다. 보정하지 않으면 훅이 발급보다 104초 먼저
실행된 것이 되어 물리적으로 불가능해진다.
════ D-4 와의 대조 ════
훅 없음 (D-4) 훅 있음 (D-4a)
갱신 → 서빙 2305초 = 38분 25초 1~2초
무엇이 reload 했나 사람 (`nginx -s reload`) certbot deploy 훅
안 했다면 다음 nginx 재시작까지 해당 없음
= 사실상 무기한
차이 약 1150배
════ 부수 정정 — D-4 의 2199초는 틀렸다 ════
D-4 에서 적은 **2199초(36분 39초)** 는 `archive/cert2.pem` 의 mtime
(test-server 시계)과 일련번호 관측 시각(dev 시계)을 **그대로 뺀** 값이었다.
106초 보정을 적용하면:
새 인증서 디스크 기록 08:20:27 UTC (실제) ← mtime 17:22:13 KST 106초
실제 서빙 시작 08:58:52 UTC (실제) ← dev 관측, 보정 불필요
공백 2305초 = 38분 25초
관련 문서를 전부 정정했다. **두 시계에서 온 값을 빼면서 그 사실을 적지
않으면, 자릿수가 아니라 방향까지 틀릴 수 있다** — 여기서는 그 오차가
100초 단위였고, 1~2초를 재는 D-4a 에서는 결과를 완전히 뒤집었다.
════ 결론 ════
1. **D-4 의 처방은 듣는다.** 훅 파일 하나로 발급 → 서빙이 38분에서 1~2초가 됐다.
2. **certbot 출력의 "ran with error output" 을 실패로 읽으면 안 된다.**
nginx 의 경고가 stderr 로 나갔을 뿐이며, 내용은 전부 성공이다.
3. **진단 방법이 재확인됐다** — 마스터 PID 유지 + 워커 PID 교체 = reload.
4. **시계를 섞어 빼면 안 된다.** test-server 는 NTP 가 꺼져 106초 빠르고,
그 사실을 적지 않은 채 계산한 D-4 의 공백은 106초 짧았다.