measure(failover): DB 페일오버 때 앱 전환 — DNS 5~30초 · 앱 재시작 약 106초, 잃은 0 (EC2)

docs/decisions/failover-app-reconnect.md

@@ -0,0 +1,98 @@
+# DB 페일오버 때 앱이 새 DB 로 넘어가는 방법 — 측정 전 후보 정리
+
+작성일: 2026-11-08
+상태: 🟢 **측정 끝(11-08, 결정 로그 마지막 줄).** 잴 것·rig 세부 확정. 2026-11-08 사용자 confirm — 후보 A + B, 흉내 K1 + K2. 운영 채택 문서가 아니다.
+연관: [`./rpo-rto-targets.md`](./rpo-rto-targets.md) §5 구성 3 · §7 · §8 R1 ·
+[`../../loadtest/results/replica-promotion-2026-11-08/README.md`](../../loadtest/results/replica-promotion-2026-11-08/README.md) (DB 쪽 승격 0.25~8초) ·
+[`./replication-lag-and-semisync.md`](./replication-lag-and-semisync.md)
+
+---
+
+## 0. 왜 이 문서인가
+
+11-08 승격 실험은 **DB 가 다시 쓰기를 받기까지**만 쟀다(밀림 없으면 약 0.25초, 약 21초 밀리면 약 7.8초).
+사용자가 겪는 시간은 그보다 길다:
+
+```
+원본 DB 죽음 ─▶ ① 알아챔 ─▶ ② 승격 결정 ─▶ ③ 승격 (잼: 0.25~8초) ─▶ ④ 앱 연결을 새 DB 로 ─▶ ⑤ 앱이 실제로 다시 씀
+```
+
+④·⑤ 가 비어 있다. 그리고 승격 실험은 원본·리플리카가 **한 박스**라 «못 받은 데이터» 가 0 이었다 — 두 박스에서 얼마를 잃는지도 비어 있다.
+
+🔴 **범위 메모**: `rpo-rto-targets.md` §7 은 «자동 페일오버 — 리플리카(3) 채택 전엔 의미 없다» 로 안 하기로 했고,
+리플리카는 보류 상태다. 이 문서는 **재는 것**이지 페일오버를 운영에 넣자는 게 아니다. 측정 결과는 Q5(리플리카를 둘지)의 근거로만 쓴다.
+
+## 1. 지금 앱이 DB 에 붙는 방식 (바꿀 대상)
+
+- `application.yml:43` — `jdbc:mysql://${DB_HOST:shadowfit-mysql}:3306/...` — 호스트 이름 하나. 운영 compose 는 `DB_HOST: shadowfit-mysql`(`docker-compose.prod.yml:95`)
+- HikariCP `maximum-pool-size: 15` · `connection-timeout: 30000`(30초). `max-lifetime` 은 기본값
+- Connector/J `connectTimeout`·`socketTimeout` 은 **지정 안 함**(기본값)
+
+→ 지금은 DB 주소가 바뀌면 **설정을 고쳐 앱을 다시 띄우는 것 말고는 방법이 없다.**
+
+## 2. 후보 — 앱 연결을 새 DB 로 바꾸는 방법 (④)
+
+| # | 방법 | 앱 쪽 변경 | 전환 때 하는 일 | 예상되는 함정 (재서 확인할 것) | 운영 부담 |
+|---|---|---|---|---|---|
+| **A** | **주소 바꾸고 앱 재시작** | 없음 | `DB_HOST` 를 새 DB 로 바꾸고 백엔드 컨테이너 재시작 | 재시작 동안 API 전체가 멈춘다. 그 시간 = Spring 기동 시간(안 쟀다) | 없음. 사람이 해야 함 |
+| **B** | **DNS 이름 바꾸기** (예: Route 53 사설 영역 `db.internal`) | `DB_HOST` 를 DNS 이름으로 | 레코드를 새 DB IP 로 | **JVM 이 DNS 결과를 캐시한다** — 레코드 TTL 과 JVM 캐시가 겹쳐 «바꿨는데 옛 주소로 붙는» 시간이 생긴다. 이 길이가 측정 대상 | Route 53 사설 영역 1개 |
+| **C** | **사설 IP 옮기기** (EC2 보조 사설 IP 를 새 DB 로 재할당) | `DB_HOST` 를 그 IP 로 | `assign-private-ip-addresses --allow-reassignment` | DNS 캐시는 없다. 대신 **AWS 전용**이고 같은 서브넷(같은 AZ)이어야 한다 — 다른 AZ 로 못 넘긴다 | IAM 권한 · 같은 AZ 제약 |
+| **D** | **프록시** (ProxySQL · MySQL Router) | `DB_HOST` 를 프록시로 | 프록시가 백엔드를 바꿈 (자동 가능) | 프록시 자체가 새 단일 장애점. 홉 하나 추가 | 프록시 서버·설정 상시. 🔴 `db-portfolio-roadmap.md:200` 이 «read replica/CQRS 풀구현» 을 오버엔지니어링으로 닫았다(읽기 라우팅 ProxySQL 도 같은 이유로 안 함 — `replication-lag-and-semisync.md:548`) |
+| **E** | **JDBC 다중 호스트 URL** (`jdbc:mysql://원본,리플리카/...`) | URL 한 줄 | 없음 — 드라이버가 첫 호스트 실패 시 다음으로 | Connector/J 는 넘어간 연결을 **기본적으로 읽기 전용**으로 연다고 알고 있다(`failOverReadOnly`, 확인 필요). 원본이 살아나면 그쪽으로 되돌아가는 문제(갈라진 두 DB 에 쓰기) | 없음. 대신 위험이 앱 설정 안에 숨는다 |
+| F | 매니지드 (RDS Multi-AZ) | — | — | — | 🚫 범위 밖 — `rpo-rto-targets.md` §7 «매니지드는 다른 판단» |
+
+## 3. 장애를 어떻게 흉내 내나 — 이게 결과를 가장 크게 바꾼다
+
+| 흉내 | 앱이 보는 것 | 비고 |
+|---|---|---|
+| **K1. 프로세스 죽이기** (`docker kill`) | OS 가 살아 있어 연결이 **바로 끊겼다는 응답(RST)** 을 받는다 → 빨리 실패 | 11-08 승격 실험이 쓴 방식. 실제 호스트 상실보다 낙관적 |
+| **K2. 네트워크 끊기** (보안 그룹·iptables 로 원본으로 가는 패킷 버리기) | **아무 응답도 없다** → 열린 연결의 쿼리가 타임아웃까지 매달린다. `socketTimeout` 이 기본값(무제한)이면 TCP 재전송 한도까지 갈 수 있다(추정, 확인 필요). 새 연결은 Hikari `connection-timeout` 30초에 걸린다 | 호스트 상실·AZ 장애에 더 가깝다 |
+
+→ **같은 후보라도 K1 에선 몇 초, K2 에선 수십 초~분일 수 있다**(추정). 그래서 K2 를 빼면 «앱 전환 N초» 를 인용할 수 없다고 본다.
+K2 에서 시간이 길게 나오면, 그 다음 질문은 «`socketTimeout`·`connectTimeout` 을 얼마로 둘까» 인데 — 그 값은 이 측정이 근거가 된다(지금 정하지 않는다).
+
+## 4. 무엇을 재나 (후보와 무관하게 공통)
+
+- **무대**: EC2 3대 — 원본 DB · 리플리카 DB · 백엔드 + 부하 발생기. 원본·리플리카를 **다른 박스**로 나눠 «못 받아서 잃은 양» 을 같이 잰다
+- **부하**: 운동 기록 저장 같은 쓰기 API 를 일정 속도로 계속 부른다(문서 §8-1 가정 피크 — 초당 45행). 요청마다 «보낸 시각 · 응답 시각 · 성공 여부» 를 남긴다
+- **결과 칸**: 죽인 시각 → 첫 실패 · 마지막 실패 · **첫 성공까지 걸린 시간**, 그 사이 실패 요청 수, 매달린 요청의 최대 응답 시간,
+  성공 응답을 받았는데 새 DB 에 없는 쓰기 수(= 잃은 양)
+- **①② (알아채기·결정)는 고정값으로 뺀다** — 사람이 하면 사람 시간이고, 자동으로 하면 감시 주기다. 이 실험은 «승격 명령을 내린 뒤» 부터를 잰다.
+  안 하면 결과가 «사람이 몇 초 만에 봤나» 에 묻힌다
+- 반복: 후보 × 흉내마다 버림판 1 + 본판 3 이상, 순서는 섞는다
+
+## 5. 추천 (Claude) — 결정은 사용자
+
+- **A + B, 흉내는 K1·K2 둘 다.**
+  - A 는 이 규모에서 **실제로 하게 될 방법**이라 기준선으로 필요하다. 남은 빈칸이 «Spring 재기동 시간» 하나라 싸다
+  - B 는 업계에서 가장 흔한 방식(매니지드 DB 도 DNS 를 바꾼다)이고, **JVM DNS 캐시라는 앱 쪽 함정**이 결과에 드러난다 — 면접에서 «페일오버 어떻게 하나요» 에 «DNS 를 바꾸면 끝» 이 아니라 그 뒤 몇 초가 어디서 나오는지 말할 수 있다
+  - K2 는 §3 이유로 빼면 안 된다
+- C 는 같은 AZ 제약 때문에 AZ 장애엔 못 쓴다 — 추천 안 함. D 는 로드맵이 닫은 방향과 부딪힌다. E 는 읽기 전용·되돌아감 위험을 앱 설정 안에 숨겨서, 재더라도 «이래서 안 쓴다» 를 보이는 용도다
+- 규모: 2 후보 × 2 흉내 × 4판 = 16판. EC2 3대로 한 라운드(시간은 rig 를 만든 뒤 로컬 스모크로 추정)
+
+## 6. 결정할 것
+
+- [x] **Q1. 잴 후보** → 🟢 **A + B** (2026-11-08 사용자 confirm)
+- [x] **Q2. 장애 흉내** → 🟢 **K1 + K2** (2026-11-08 사용자 confirm)
+- [ ] **Q3. 범위** — §0 메모대로 «측정만, 운영 채택 아님» 으로 둘지. 명시 답은 아직 없다 — 그동안 `rpo-rto-targets.md` §7 «자동 페일오버 안 함» 은 그대로 둔다
+
+### 6-1. rig 세부 — ✅ 2026-11-08 사용자 confirm (R-a 앱 박스 DNS · R-b·R-c 추천대로)
+
+| | 후보 | 추천 | 걸리는 것 |
+|---|---|---|---|
+| R-a | B 의 DNS 를 무엇으로 | Route 53 사설 영역 → 🟢 **채택은 앱 박스 DNS(dnsmasq)** | 측정용 IAM 사용자에 Route 53 권한이 **없다**(11-08 `AccessDenied` 확인) — 사용자가 콘솔에서 붙여야 한다. 대안은 앱 박스에 작은 DNS 를 띄우는 것(권한 불필요, 레코드 전파 시간은 빠져 낙관적) |
+| R-b | 앱의 DB 타임아웃 | 🟢 지금 설정 그대로(기본값) | 시간 제한 넣은 팔을 더하면 판이 2배이고, 넣을 값의 근거가 아직 없다 |
+| R-c | 요청 간격 | 🟢 초당 10번 | 가정 피크(세션 시작 초당 0.075번)면 13초에 한 번이라 초 단위 변화를 못 잡는다. 10번은 부하가 아니라 **시간 해상도 0.1초**에서 나온 값이다 |
+
+## 결정 로그
+
+- 2026-11-08: 후보 초안. 11-08 승격 실험이 DB 쪽(0.25~8초)만 쟀고, 앱 전환·두 박스 유실이 비어 있어서 정리했다. 후보 A~F · 흉내 K1/K2 · 공통 측정 칸 · 추천(A + B, K1 + K2). 결정은 미결.
+- 2026-11-08: 🟢 **Q1 A + B · Q2 K1 + K2 채택** (사용자 confirm «추천대로»). Q3 는 명시 답 없음. rig 세부 셋(§6-1 R-a~R-c)은 미정 — 특히 R-a 는 IAM 권한이 필요하다.
+- 2026-11-08: 🟢 **rig 세부 확정** (사용자 confirm) — R-a 는 **앱 박스에 DNS 를 직접 띄운다**(Route 53 아님 → 레코드 전파 시간이 빠져
+  실제보다 낙관적이라는 것을 결과에 적는다), R-b 기본 타임아웃 그대로, R-c 초당 10번.
+- 2026-11-08: **측정 끝** (EC2 m6i.xlarge 3대 · 커밋 `f61c3d25` · 본판 12, [결과](../../loadtest/results/failover-app-reconnect-2026-11-08/README.md)).
+  회복 시각: **A 약 106초**(K1·K2 같음) · **B·K1 약 30초 · B·K2 약 5.3초**, 잃은 쓰기 16판 모두 0.
+  예상과 다른 것 셋 — ① A 의 106초 중 약 90초는 기동이 아니라 **종료 대기**(systemd 기본 90초에 걸린 것과 맞음, 무엇이 붙잡았는지 미확인 —
+  운영은 Docker 라 이 숫자가 아니다) ② B·K2 에서 끊긴 연결 위 요청 약 14개가 **약 16분 매달림**(`socketTimeout` 미지정, §3 예상대로)
+  ③ DB 장애가 클라이언트에 **401** 로 보임 — `JwtAuthFilter` 가 DB 예외를 토큰 불량과 같이 처리(#848).
+  `socketTimeout` 값과 운영에서 쓸 후보는 **정하지 않았다**. 목표 RTO 는 `rpo-rto-targets.md` §6-3 (리플리카 보류 유지라 이 측정은 Q5 근거로만 쓰였다).

loadtest/results/failover-app-reconnect-2026-11-08/README.md

@@ -0,0 +1,87 @@
+# DB 페일오버 때 앱이 새 DB 로 넘어가기까지 (2026-11-08, EC2)
+
+설계 문서: [`../../../docs/decisions/failover-app-reconnect.md`](../../../docs/decisions/failover-app-reconnect.md) (후보 A + B · 흉내 K1 + K2 · rig 세부 §6-1) ·
+[`rpo-rto-targets.md`](../../../docs/decisions/rpo-rto-targets.md) §5 구성 3 · §6-3
+짝 실험: [리플리카 승격](../replica-promotion-2026-11-08/README.md) — DB 쪽 승격만 잰 것(0.25~8초)
+무대: **EC2 `m6i.xlarge` 3대** (원본 DB · 리플리카 DB · 앱 + 탐침) · MySQL `mysql:8.0` GTID 비동기 복제 · 백엔드 jar(prod 프로파일, Java 21) ·
+RUN_ID `failover-ec2-20261108-054629` · 커밋 `f61c3d25` · 16판(버림 4 + 본판 12)
+
+질문: 원본 DB 가 죽고 리플리카를 승격했을 때, **사용자가 다시 저장되는 걸 보기까지** 얼마나 걸리나? 승격 실험은 DB 쪽만 쟀다.
+
+## 0. 한 줄
+
+**DNS 바꾸기(B)는 5~30초, 앱 재시작(A)은 약 106초 — 잃은 쓰기는 16판 모두 0.**
+단 B 는 네트워크가 끊기는 장애(K2)에서 **요청 약 14개가 약 16분 매달렸고**, A 의 106초 중 약 90초는 **앱이 안 꺼져서** 생긴 시간이다.
+그리고 DB 장애가 클라이언트에겐 **401(인증 실패)** 로 보였다(§3).
+
+## 1. 결과 (본판, 칸마다 3판)
+
+모든 시각은 장애를 넣은 순간 기준. 승격 + 전환은 판마다 약 1.2~1.6초에 끝났다(①알아챔·②결정 = 0, 설계 §4).
+
+| 후보 | 흉내 | 판 | **회복** | 실패 요청 | 가장 오래 걸린 요청 | 5초 넘은 요청 | 잃은 쓰기 |
+|---|---|---|---:|---:|---:|---:|---:|
+| A 재시작 | K1 프로세스 | 8 · 12 · 14 | **105.3~106.1초** | 1,047~1,057 | 30.0초 | 15~17 | 0 |
+| A 재시작 | K2 네트워크 | 6 · 9 · 15 | **105.5~105.8초** | 1,050~1,052 | 31.4~31.5초 | 15~16 | 0 |
+| B DNS | K1 프로세스 | 7 · 10 · 13 | **30.4~30.5초** | 0~1 | 30.3초 | 253~255 | 0 |
+| B DNS | K2 네트워크 | 5 · 11 · 16 | **5.3~5.4초** | 1~2 | **961~965초** | 13~14 | 0 |
+
+«회복» = 이 시각 뒤에 보낸 요청은 끝까지 전부 성공한, 그 첫 요청이 돌아온 시각(사용자가 «다시 저장된다» 를 처음 보는 때).
+요청은 초당 10번(시간 해상도 0.1초용, 부하 아님 — 설계 §6-1 R-c). 버림판 4개도 같은 범위다(`ec2/summary.tsv`).
+
+## 2. 읽기
+
+### 2-1. A 의 106초 중 약 90초는 «앱이 안 꺼지는» 시간
+
+A 판(6·9·12·14·15)의 앱 로그 시각이 모두 같은 모양이다:
+
+```
+장애 +1.4초   systemctl restart → 종료 시작 (Commencing graceful shutdown)
+     +31초    Tomcat graceful 끝 — 붙잡혀 있던 요청이 Hikari 30초에 걸려 끝남
+     +91.5초  새 프로세스 Starting  ← 종료 시작 후 약 90초
+     +104초   Started (기동 자체는 12.3~18.1초)
+```
+
+종료 시작부터 새 프로세스까지가 매번 약 90초 — **systemd 기본 정지 한도(`TimeoutStopSec` 90초) 에 걸려 강제 종료된 것과 맞는다.**
+Tomcat 은 31초에 끝났는데 JVM 이 그 뒤로 안 내려갔다. 무엇이 붙잡았는지는 **확인하지 않았다**(스레드 덤프 없음).
+→ «A = Spring 기동 시간» 이라는 설계의 예상과 달리, **죽은 DB 앞에선 종료가 기동보다 오래 걸린다.**
+운영은 systemd 가 아니라 Docker 라서 정지 한도가 다르다(`docker stop` 기본 10초 뒤 강제 종료) — 운영 A 의 시간은 이 숫자가 아니다.
+
+### 2-2. B·K2 — 새 요청은 5초에 돌아오지만, 끊긴 연결 위의 요청은 약 16분 매달림
+
+- 네트워크를 끊으면 원본은 «끊겼다» 는 응답(RST)조차 안 보낸다. 이미 원본과 이야기하던 요청은 리눅스가 TCP 재전송을 포기할 때까지 기다린다
+  (`tcp_retries2=15`, 약 924초 + Hikari 30초 ≈ 961초 관측)
+- Connector/J `socketTimeout` 을 지정하지 않아서다(설계 §6-1 R-b, 일부러 기본값). 그 값을 정할 근거로 이 숫자를 쓴다 — 값은 정하지 않았다
+- 매달린 13~14개는 결국 실패로 돌아왔다(401 — §3)
+
+### 2-3. B·K1 의 30초 — 추정 둘, 이 데이터로는 못 가른다
+
+프로세스를 죽이면 앱은 즉시 끊김을 알고 다시 연결하려 한다. 그 순간(전환 1.4초 **전**) DNS 는 아직 옛 주소를 준다.
+- 추정 ① JVM 이 DNS 결과를 30초 기억한다(보안 관리자 없을 때 기본) — 옛 주소가 30초 남는다
+- 추정 ② Hikari `connection-timeout` 30초 — 연결을 못 얻은 요청이 30초에 끝난다
+
+둘 다 30초라 구분이 안 된다. K2 가 5초인 건 끊김을 몰라 바로 다시 묻지 않았고, 나중에 새 연결을 만들 때는 DNS 기억이 이미 지나 있었기 때문으로 보인다(확인 안 함).
+
+## 3. 🔴 찾은 결함 — DB 장애가 401 로 보인다
+
+실패 응답이 500 이 아니라 **401** 이었다(A 판마다 13~17건, B 판 1~2건 + 매달렸다 돌아온 요청).
+`JwtAuthFilter.java:90` 이 요청마다 DB 에서 회원을 읽는데, DB 예외를 `:105` 의 `catch (Exception e)` 가 «토큰 불량» 과 같이 처리한다 —
+앱 로그 `JWT 인증 실패: DataAccessResourceFailureException` 137줄. 클라이언트가 401 에 로그아웃하면 **DB 가 잠깐 흔들려도 사용자가 로그아웃된다**(프론트 동작은 확인 안 함). [#848](https://github.com/Shadowfit/init/issues/848).
+
+## 4. 조건 — 인용할 때 떼면 안 되는 것
+
+1. **알아채기·결정 시간 0.** 장애 직후 바로 승격·전환했다. 사람이 하면 사람 시간이 더해진다(§6-3 은 저녁 30분으로 잡았다)
+2. **DNS 는 앱 박스의 dnsmasq**(TTL 0) — Route 53 이 아니다(설계 §6-1 R-a). 레코드가 퍼지는 시간이 빠져 **실제보다 낙관적**이다
+3. **앱은 systemd 로 돌았다** — A 의 약 90초 정지 대기는 systemd 기본값에서 나왔다. 운영(Docker)과 다르다
+4. 앱 DB 타임아웃은 지금 설정 그대로(Hikari 30초 · `socketTimeout`·`connectTimeout` 미지정)
+5. 비동기 복제인데 잃은 게 0 인 건 쓰기가 초당 10번으로 가벼워 리플리카가 따라가 있었기 때문으로 본다 — 무거운 쓰기에서 두 박스 손실은 안 쟀다
+6. K2 는 원본 박스에서 3306 을 드나드는 패킷을 버린 것 — 호스트 상실의 대리다
+
+## 5. 재현
+
+```bash
+bash launch.sh <커밋 SHA>      # EC2 3대. 결과는 S3 의 RUN_ID 아래
+python3 analyze.py <out 폴더>  # events.tsv + t*/probe.tsv → summary.tsv
+```
+
+산출물: `ec2/summary.tsv`(판 1줄) · `ec2/events.tsv` · `ec2/CONDITIONS.txt` · `ec2/run.log` · `ec2/*.round.log` · `ec2/*box.txt`.
+판별 원본(`t*/probe.tsv`·`app.log`, 전체 앱 로그 `app.full.log`)은 저장소에 안 넣었다 — S3 `shadowfit/failover-ec2-20261108-054629/out/`.

loadtest/results/failover-app-reconnect-2026-11-08/analyze.py

@@ -0,0 +1,53 @@
+#!/usr/bin/env python3
+"""판별 요약 — events.tsv + t*/probe.tsv → 한 판 한 줄 (모든 시각은 장애를 넣은 시각 t_kill 기준, ms)
+
+  first_fail      장애 뒤 처음 실패가 «돌아온» 시각 (실패한 요청의 응답 시각 중 가장 이른 것)
+  recovered       이 시각 뒤에 «보낸» 요청은 끝까지 전부 성공했다 — 그 첫 요청이 성공으로 돌아온 시각.
+                  사용자가 «다시 저장된다» 를 처음 보는 시각이다
+  n_fail          실패 수 (HTTP 204 가 아닌 것 전부)
+  fail_kinds      실패 종류별 수
+  max_hang        장애 전후로 나간 요청 중 가장 오래 걸린 응답 시간
+  n_over_5s       5초 넘게 걸린 요청 수
+  unreturned      클라이언트 상한(CLIENT_TIMEOUT_S)까지 안 돌아온 요청 수 (probe.tsv 에 줄이 없다)
+  lost_acked      성공(204)을 받았는데 새 원본에 없는 쓰기
+"""
+import collections
+import csv
+import os
+import sys
+
+out = sys.argv[1]
+ev = list(csv.DictReader(open(os.path.join(out, "events.tsv")), delimiter="\t"))
+cols = ["trial", "kind", "arm", "kill", "promoted", "switch_at", "first_fail", "recovered", "n_fail",
+        "fail_kinds", "max_hang", "n_over_5s", "unreturned", "lost_acked", "rows_on_old", "status"]
+print("\t".join(cols))
+for e in ev:
+    tk = int(e["t_kill_ms"])
+    rows = list(csv.DictReader(open(os.path.join(out, "t" + e["trial"], "probe.tsv")), delimiter="\t"))
+    sent = set()
+    for r in rows:
+        sent.add(int(r["seq"]))
+    max_seq = max(sent) if sent else -1
+    unreturned = (max_seq + 1) - len(sent)
+    rows.sort(key=lambda r: int(r["t_send_ms"]))
+    fails = [r for r in rows if r["result"] != "204" and int(r["t_done_ms"]) >= tk]
+    first_fail = min((int(r["t_done_ms"]) for r in fails), default=None)
+    # recovered: 뒤에서부터 훑어 «마지막 실패보다 뒤에 보낸» 첫 성공
+    last_bad_send = max((int(r["t_send_ms"]) for r in rows if r["result"] != "204"), default=None)
+    rec = None
+    if last_bad_send is None:
+        rec = 0
+    else:
+        after = [r for r in rows if int(r["t_send_ms"]) > last_bad_send]
+        if after:
+            rec = int(after[0]["t_done_ms"]) - tk
+    kinds = collections.Counter(r["result"] for r in fails)
+    lat = [int(r["t_done_ms"]) - int(r["t_send_ms"]) for r in rows if int(r["t_done_ms"]) >= tk]
+    print("\t".join(str(x) for x in [
+        e["trial"], e["kind"], e["arm"], e["kill"], e["promoted_after_kill_ms"],
+        int(e["t_switch_ms"]) - tk,
+        "" if first_fail is None else first_fail - tk,
+        "" if rec is None else rec,
+        len(fails), ",".join(f"{k}:{v}" for k, v in kinds.most_common()),
+        max(lat, default=""), sum(1 for x in lat if x > 5000), unreturned,
+        e["lost_acked"], e["rows_on_old"], e["status"]]))