diff --git a/token_log_plan.md b/token_log_plan.md deleted file mode 100644 index b5f0fec..0000000 --- a/token_log_plan.md +++ /dev/null @@ -1,422 +0,0 @@ -# 서버 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 -```