# 서버 JWT 토큰 라이프사이클 로깅 강화 계획

## 1. 토큰 라이프사이클 개요

서버가 직접 발급/관리하는 JWT 토큰의 전체 흐름:

```
[발급] kakao_login() / generate_test_token()
  ├── Access Token  생성 (sub=user_uuid, type=access, exp=60분)
  ├── Refresh Token 생성 (sub=user_uuid, type=refresh, exp=7일)
  └── Refresh Token DB 저장 (token_hash, user_id, expires_at)
         │
         ▼
[검증] get_current_user() — 매 요청마다 Access Token 검증
  ├── Bearer 헤더에서 토큰 추출
  ├── decode_token() → payload (sub, type, exp)
  ├── type == "access" 확인
  └── user_uuid로 사용자 조회/활성 확인
         │
         ▼
[갱신] refresh_tokens() — Access Token 만료 시 Refresh Token으로 갱신
  ├── 기존 Refresh Token 디코딩 → payload
  ├── token_hash로 DB 조회 → is_revoked / expires_at 확인
  ├── 기존 Refresh Token 폐기 (is_revoked=True)
  ├── 새 Access Token + 새 Refresh Token 발급
  └── 새 Refresh Token DB 저장
         │
         ▼
[폐기] logout() / logout_all()
  ├── 단일: token_hash로 해당 Refresh Token 폐기
  └── 전체: user_id로 모든 Refresh Token 폐기
```

---

## 2. 현황 분석 — 로깅 공백 지점

### 발급 단계
| 위치 | 함수 | 현재 로깅 | 부족한 정보 |
|------|------|----------|------------|
| `jwt.py` | `create_access_token()` | 없음 | 발급 대상(user_uuid), 만료시간 |
| `jwt.py` | `create_refresh_token()` | 없음 | 발급 대상(user_uuid), 만료시간 |
| `auth.py` (service) | `_save_refresh_token()` | 없음 | DB 저장 결과(token_hash, expires_at) |
| `auth.py` (service) | `kakao_login()` | `debug`로 토큰 앞 30자 출력 | 충분 (변경 불필요) |

### 검증 단계
| 위치 | 함수 | 현재 로깅 | 부족한 정보 |
|------|------|----------|------------|
| `jwt.py` | `decode_token()` | 없음 | 디코딩 성공 시 payload 내용, 실패 시 원인 |
| `auth.py` (dependency) | `get_current_user()` | 없음 | 검증 각 단계 통과/실패 사유, 토큰 내 정보 |
| `auth.py` (dependency) | `get_current_user_optional()` | 없음 | 위와 동일 |

### 갱신 단계
| 위치 | 함수 | 현재 로깅 | 부족한 정보 |
|------|------|----------|------------|
| `auth.py` (router) | `refresh_token()` | 없음 | 수신 토큰 정보, 갱신 결과 |
| `auth.py` (service) | `refresh_tokens()` | 진입/완료 `info` 1줄씩 | 각 단계 실패 사유, DB 토큰 상태, 신규 토큰 정보 |

### 폐기 단계
| 위치 | 함수 | 현재 로깅 | 부족한 정보 |
|------|------|----------|------------|
| `auth.py` (router) | `logout()`, `logout_all()` | 없음 | 요청 수신, 대상 사용자 |
| `auth.py` (service) | `logout()`, `logout_all()` | 없음 | 폐기 대상, 폐기 결과 |

---

## 3. 수정 대상 파일

| # | 파일 | 수정 내용 |
|---|------|----------|
| 1 | `app/user/services/jwt.py` | 토큰 발급 로그 + `decode_token()` 실패 원인 분류 |
| 2 | `app/user/dependencies/auth.py` | Access Token 검증 과정 로깅 |
| 3 | `app/user/services/auth.py` | `refresh_tokens()`, `_save_refresh_token()`, `logout()`, `logout_all()` 로깅 |
| 4 | `app/user/api/routers/v1/auth.py` | `refresh_token()`, `logout()`, `logout_all()` 라우터 로깅 |

---

## 4. 상세 구현 계획

### 4-1. `jwt.py` — 토큰 발급 로그 + 디코딩 실패 원인 분류

**import 추가:**
```python
import logging
from jose import JWTError, ExpiredSignatureError, JWTClaimsError, jwt

logger = logging.getLogger(__name__)
```

**`create_access_token()` — 발급 로그 추가:**
```python
def create_access_token(user_uuid: str) -> str:
    expire = now() + timedelta(minutes=jwt_settings.JWT_ACCESS_TOKEN_EXPIRE_MINUTES)
    to_encode = {"sub": user_uuid, "exp": expire, "type": "access"}
    token = jwt.encode(to_encode, jwt_settings.JWT_SECRET, algorithm=jwt_settings.JWT_ALGORITHM)
    logger.debug(f"[JWT] Access Token 발급 - user_uuid: {user_uuid}, expires: {expire}, token: ...{token[-20:]}")
    return token
```

**`create_refresh_token()` — 발급 로그 추가:**
```python
def create_refresh_token(user_uuid: str) -> str:
    expire = now() + timedelta(days=jwt_settings.JWT_REFRESH_TOKEN_EXPIRE_DAYS)
    to_encode = {"sub": user_uuid, "exp": expire, "type": "refresh"}
    token = jwt.encode(to_encode, jwt_settings.JWT_SECRET, algorithm=jwt_settings.JWT_ALGORITHM)
    logger.debug(f"[JWT] Refresh Token 발급 - user_uuid: {user_uuid}, expires: {expire}, token: ...{token[-20:]}")
    return token
```

**`decode_token()` — 성공/실패 분류 로그:**
```python
def decode_token(token: str) -> Optional[dict]:
    try:
        payload = jwt.decode(token, jwt_settings.JWT_SECRET, algorithms=[jwt_settings.JWT_ALGORITHM])
        logger.debug(
            f"[JWT] 토큰 디코딩 성공 - type: {payload.get('type')}, "
            f"sub: {payload.get('sub')}, exp: {payload.get('exp')}, "
            f"token: ...{token[-20:]}"
        )
        return payload
    except ExpiredSignatureError:
        logger.info(f"[JWT] 토큰 만료 - token: ...{token[-20:]}")
        return None
    except JWTClaimsError as e:
        logger.warning(f"[JWT] 클레임 검증 실패 - error: {e}, token: ...{token[-20:]}")
        return None
    except JWTError as e:
        logger.warning(f"[JWT] 토큰 디코딩 실패 - error: {type(e).__name__}: {e}, token: ...{token[-20:]}")
        return None
```

### 4-2. `dependencies/auth.py` — Access Token 검증 로깅

**import 추가:**
```python
import logging
logger = logging.getLogger(__name__)
```

**`get_current_user()` — 검증 과정 로그:**
```python
async def get_current_user(...) -> User:
    if credentials is None:
        logger.info("[AUTH-DEP] 토큰 없음 - MissingTokenError")
        raise MissingTokenError()

    token = credentials.credentials
    logger.debug(f"[AUTH-DEP] Access Token 검증 시작 - token: ...{token[-20:]}")

    payload = decode_token(token)
    if payload is None:
        logger.warning(f"[AUTH-DEP] Access Token 디코딩 실패 - token: ...{token[-20:]}")
        raise InvalidTokenError()

    if payload.get("type") != "access":
        logger.warning(f"[AUTH-DEP] 토큰 타입 불일치 - expected: access, got: {payload.get('type')}, sub: {payload.get('sub')}")
        raise InvalidTokenError("액세스 토큰이 아닙니다.")

    user_uuid = payload.get("sub")
    if user_uuid is None:
        logger.warning(f"[AUTH-DEP] 토큰에 sub 클레임 없음 - token: ...{token[-20:]}")
        raise InvalidTokenError()

    # 사용자 조회
    result = await session.execute(...)
    user = result.scalar_one_or_none()

    if user is None:
        logger.warning(f"[AUTH-DEP] 사용자 미존재 - user_uuid: {user_uuid}")
        raise UserNotFoundError()

    if not user.is_active:
        logger.warning(f"[AUTH-DEP] 비활성 사용자 접근 - user_uuid: {user_uuid}, user_id: {user.id}")
        raise UserInactiveError()

    logger.debug(f"[AUTH-DEP] Access Token 검증 성공 - user_uuid: {user_uuid}, user_id: {user.id}")
    return user
```

**`get_current_user_optional()` — 동일 패턴, `debug` 레벨:**
```python
async def get_current_user_optional(...) -> Optional[User]:
    if credentials is None:
        logger.debug("[AUTH-DEP] 선택적 인증 - 토큰 없음")
        return None

    token = credentials.credentials
    payload = decode_token(token)
    if payload is None:
        logger.debug(f"[AUTH-DEP] 선택적 인증 - 디코딩 실패, token: ...{token[-20:]}")
        return None

    if payload.get("type") != "access":
        logger.debug(f"[AUTH-DEP] 선택적 인증 - 타입 불일치 (type={payload.get('type')})")
        return None

    user_uuid = payload.get("sub")
    if user_uuid is None:
        logger.debug("[AUTH-DEP] 선택적 인증 - sub 없음")
        return None

    result = await session.execute(...)
    user = result.scalar_one_or_none()

    if user is None or not user.is_active:
        logger.debug(f"[AUTH-DEP] 선택적 인증 - 사용자 미존재 또는 비활성, user_uuid: {user_uuid}")
        return None

    logger.debug(f"[AUTH-DEP] 선택적 인증 성공 - user_uuid: {user_uuid}, user_id: {user.id}")
    return user
```

### 4-3. `services/auth.py` — Refresh Token 갱신/폐기 로깅

**`refresh_tokens()` — 전체 흐름 로그:**
```python
async def refresh_tokens(self, refresh_token: str, session: AsyncSession) -> TokenResponse:
    logger.info(f"[AUTH] 토큰 갱신 시작 (Rotation) - token: ...{refresh_token[-20:]}")

    # 1. 디코딩
    payload = decode_token(refresh_token)
    if payload is None:
        logger.warning(f"[AUTH] 토큰 갱신 실패 [1/8 디코딩] - token: ...{refresh_token[-20:]}")
        raise InvalidTokenError()

    if payload.get("type") != "refresh":
        logger.warning(f"[AUTH] 토큰 갱신 실패 [1/8 타입] - type={payload.get('type')}, sub: {payload.get('sub')}")
        raise InvalidTokenError("리프레시 토큰이 아닙니다.")

    logger.debug(f"[AUTH] 토큰 갱신 [1/8] 디코딩 성공 - sub: {payload.get('sub')}, exp: {payload.get('exp')}")

    # 2. DB 조회
    token_hash = get_token_hash(refresh_token)
    db_token = await self._get_refresh_token_by_hash(token_hash, session)

    if db_token is None:
        logger.warning(f"[AUTH] 토큰 갱신 실패 [2/8 DB조회] - DB에 없음, token_hash: {token_hash[:16]}...")
        raise InvalidTokenError()

    logger.debug(f"[AUTH] 토큰 갱신 [2/8] DB 조회 성공 - token_hash: {token_hash[:16]}..., user_uuid: {db_token.user_uuid}, is_revoked: {db_token.is_revoked}, expires_at: {db_token.expires_at}")

    # 3. 폐기 여부
    if db_token.is_revoked:
        logger.warning(f"[AUTH] 토큰 갱신 실패 [3/8 폐기됨] - 이미 폐기된 토큰 (replay attack 의심), token_hash: {token_hash[:16]}..., user_uuid: {db_token.user_uuid}, revoked_at: {db_token.revoked_at}")
        raise TokenRevokedError()

    # 4. 만료 확인
    if db_token.expires_at < now().replace(tzinfo=None):
        logger.info(f"[AUTH] 토큰 갱신 실패 [4/8 만료] - expires_at: {db_token.expires_at}, user_uuid: {db_token.user_uuid}")
        raise TokenExpiredError()

    # 5. 사용자 확인
    user_uuid = payload.get("sub")
    user = await self._get_user_by_uuid(user_uuid, session)

    if user is None:
        logger.warning(f"[AUTH] 토큰 갱신 실패 [5/8 사용자] - 사용자 미존재, user_uuid: {user_uuid}")
        raise UserNotFoundError()

    if not user.is_active:
        logger.warning(f"[AUTH] 토큰 갱신 실패 [5/8 비활성] - user_uuid: {user_uuid}, user_id: {user.id}")
        raise UserInactiveError()

    # 6. 기존 토큰 폐기
    db_token.is_revoked = True
    db_token.revoked_at = now().replace(tzinfo=None)
    logger.debug(f"[AUTH] 토큰 갱신 [6/8] 기존 토큰 폐기 - token_hash: {token_hash[:16]}...")

    # 7. 새 토큰 발급
    new_access_token = create_access_token(user.user_uuid)
    new_refresh_token = create_refresh_token(user.user_uuid)
    logger.debug(f"[AUTH] 토큰 갱신 [7/8] 새 토큰 발급 - new_access: ...{new_access_token[-20:]}, new_refresh: ...{new_refresh_token[-20:]}")

    # 8. 새 Refresh Token DB 저장 + 커밋
    await self._save_refresh_token(user_id=user.id, user_uuid=user.user_uuid, token=new_refresh_token, session=session)
    await session.commit()

    logger.info(f"[AUTH] 토큰 갱신 완료 [8/8] - user_uuid: {user.user_uuid}, user_id: {user.id}, old_hash: {token_hash[:16]}..., new_refresh: ...{new_refresh_token[-20:]}")
    return TokenResponse(...)
```

**`_save_refresh_token()` — DB 저장 로그:**
```python
async def _save_refresh_token(self, ...) -> RefreshToken:
    token_hash = get_token_hash(token)
    expires_at = get_refresh_token_expires_at()

    refresh_token = RefreshToken(...)
    session.add(refresh_token)
    await session.flush()

    logger.debug(f"[AUTH] Refresh Token DB 저장 - user_uuid: {user_uuid}, token_hash: {token_hash[:16]}..., expires_at: {expires_at}")
    return refresh_token
```

**`logout()` — 단일 로그아웃 로그:**
```python
async def logout(self, user_id: int, refresh_token: str, session: AsyncSession) -> None:
    token_hash = get_token_hash(refresh_token)
    logger.info(f"[AUTH] 로그아웃 - user_id: {user_id}, token_hash: {token_hash[:16]}..., token: ...{refresh_token[-20:]}")
    await self._revoke_refresh_token_by_hash(token_hash, session)
    logger.info(f"[AUTH] 로그아웃 완료 - user_id: {user_id}")
```

**`logout_all()` — 전체 로그아웃 로그:**
```python
async def logout_all(self, user_id: int, session: AsyncSession) -> None:
    logger.info(f"[AUTH] 전체 로그아웃 - user_id: {user_id}")
    await self._revoke_all_user_tokens(user_id, session)
    logger.info(f"[AUTH] 전체 로그아웃 완료 - user_id: {user_id}")
```

### 4-4. `routers/v1/auth.py` — 라우터 진입/완료 로깅

```python
# POST /auth/refresh
async def refresh_token(body, session) -> TokenResponse:
    logger.info(f"[ROUTER] POST /auth/refresh - token: ...{body.refresh_token[-20:]}")
    result = await auth_service.refresh_tokens(refresh_token=body.refresh_token, session=session)
    logger.info(f"[ROUTER] POST /auth/refresh 완료 - new_access: ...{result.access_token[-20:]}, new_refresh: ...{result.refresh_token[-20:]}")
    return result

# POST /auth/logout
async def logout(body, current_user, session) -> Response:
    logger.info(f"[ROUTER] POST /auth/logout - user_id: {current_user.id}, user_uuid: {current_user.user_uuid}, token: ...{body.refresh_token[-20:]}")
    await auth_service.logout(user_id=current_user.id, refresh_token=body.refresh_token, session=session)
    logger.info(f"[ROUTER] POST /auth/logout 완료 - user_id: {current_user.id}")
    return Response(status_code=status.HTTP_204_NO_CONTENT)

# POST /auth/logout/all
async def logout_all(current_user, session) -> Response:
    logger.info(f"[ROUTER] POST /auth/logout/all - user_id: {current_user.id}, user_uuid: {current_user.user_uuid}")
    await auth_service.logout_all(user_id=current_user.id, session=session)
    logger.info(f"[ROUTER] POST /auth/logout/all 완료 - user_id: {current_user.id}")
    return Response(status_code=status.HTTP_204_NO_CONTENT)
```

---

## 5. 보안 원칙

| 원칙 | 적용 방법 | 이유 |
|------|----------|------|
| 토큰 전체 노출 금지 | 뒷 20자만: `...{token[-20:]}` | 토큰 탈취 시 세션 하이재킹 가능 |
| 해시값 부분 노출 | 앞 16자만: `{hash[:16]}...` | DB 레코드 식별에 충분 |
| user_uuid 전체 허용 | 전체 출력 | 내부 식별자, 토큰이 아님 |
| 페이로드 내용 출력 | `sub`, `type`, `exp` 출력 | 디버깅에 필수, 민감정보 아님 |
| DB 토큰 상태 출력 | `is_revoked`, `expires_at`, `revoked_at` | 토큰 라이프사이클 추적 |
| 로그 레벨 구분 | 하단 표 참조 | 운영 환경에서 불필요한 로그 억제 |

### 로그 레벨 기준

| 레벨 | 사용 기준 | 예시 |
|------|----------|------|
| `debug` | 정상 처리 과정 상세 (운영환경에서 비활성) | 토큰 발급, 디코딩 성공, 검증 통과 |
| `info` | 주요 이벤트 (운영환경에서 활성) | 갱신 시작/완료, 로그아웃, 만료로 인한 실패 |
| `warning` | 비정상/의심 상황 | 디코딩 실패, 폐기된 토큰 사용, 사용자 미존재 |

---

## 6. 구현 순서

| 순서 | 파일 | 이유 |
|------|------|------|
| 1 | `app/user/services/jwt.py` | 최하위 유틸리티. 토큰 발급/디코딩의 기본 로그 |
| 2 | `app/user/dependencies/auth.py` | 모든 인증 API의 공통 진입점 |
| 3 | `app/user/services/auth.py` | 갱신/폐기 비즈니스 로직 |
| 4 | `app/user/api/routers/v1/auth.py` | 라우터 진입/완료 + 응답 토큰 정보 |

---

## 7. 기대 효과 — 시나리오별 로그 출력 예시

### 시나리오 1: 정상 토큰 갱신
```
[ROUTER] POST /auth/refresh - token: ...7d90-aac8-ecf1385c
[AUTH] 토큰 갱신 시작 (Rotation) - token: ...7d90-aac8-ecf1385c
[JWT] 토큰 디코딩 성공 - type: refresh, sub: 019c5452-b1cf-7d90-aac8-ecf1385c9dc4, exp: 1739450400
[AUTH] 토큰 갱신 [1/8] 디코딩 성공 - sub: 019c5452-..., exp: 1739450400
[AUTH] 토큰 갱신 [2/8] DB 조회 성공 - token_hash: a1b2c3d4e5f6g7h8..., is_revoked: False, expires_at: 2026-02-20 11:46:36
[AUTH] 토큰 갱신 [6/8] 기존 토큰 폐기 - token_hash: a1b2c3d4e5f6g7h8...
[JWT] Access Token 발급 - user_uuid: 019c5452-..., expires: 2026-02-13 12:46:36
[JWT] Refresh Token 발급 - user_uuid: 019c5452-..., expires: 2026-02-20 11:46:36
[AUTH] 토큰 갱신 [7/8] 새 토큰 발급 - new_access: ...xNewAccess12345, new_refresh: ...xNewRefresh6789
[AUTH] Refresh Token DB 저장 - user_uuid: 019c5452-..., token_hash: f8e9d0c1b2a3..., expires_at: 2026-02-20 11:46:36
[AUTH] 토큰 갱신 완료 [8/8] - user_uuid: 019c5452-..., user_id: 42, old_hash: a1b2c3d4e5f6g7h8..., new_refresh: ...xNewRefresh6789
[ROUTER] POST /auth/refresh 완료 - new_access: ...xNewAccess12345, new_refresh: ...xNewRefresh6789
```

### 시나리오 2: 만료된 Refresh Token으로 갱신 시도
```
[ROUTER] POST /auth/refresh - token: ...expiredToken12345
[AUTH] 토큰 갱신 시작 (Rotation) - token: ...expiredToken12345
[JWT] 토큰 만료 - token: ...expiredToken12345
[AUTH] 토큰 갱신 실패 [1/8 디코딩] - token: ...expiredToken12345
→ 401 InvalidTokenError 응답
```

### 시나리오 3: 이미 폐기된 Refresh Token 재사용 (Replay Attack)
```
[ROUTER] POST /auth/refresh - token: ...revokedToken98765
[AUTH] 토큰 갱신 시작 (Rotation) - token: ...revokedToken98765
[JWT] 토큰 디코딩 성공 - type: refresh, sub: 019c5452-..., exp: 1739450400
[AUTH] 토큰 갱신 [2/8] DB 조회 성공 - token_hash: c3d4e5f6..., is_revoked: True, expires_at: 2026-02-20
[AUTH] 토큰 갱신 실패 [3/8 폐기됨] - replay attack 의심, token_hash: c3d4e5f6..., user_uuid: 019c5452-..., revoked_at: 2026-02-13 10:30:00
→ 401 TokenRevokedError 응답
```

### 시나리오 4: Access Token 검증 (매 API 요청)
```
[AUTH-DEP] Access Token 검증 시작 - token: ...validAccess12345
[JWT] 토큰 디코딩 성공 - type: access, sub: 019c5452-..., exp: 1739450400
[AUTH-DEP] Access Token 검증 성공 - user_uuid: 019c5452-..., user_id: 42
```

### 시나리오 5: 로그아웃
```
[ROUTER] POST /auth/logout - user_id: 42, user_uuid: 019c5452-..., token: ...refreshToRevoke99
[AUTH] 로그아웃 - user_id: 42, token_hash: d5e6f7g8..., token: ...refreshToRevoke99
[AUTH] 로그아웃 완료 - user_id: 42
[ROUTER] POST /auth/logout 완료 - user_id: 42
```