o2o-castad-backend/token_log_plan.md

서버 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 추가:

import logging
from jose import JWTError, ExpiredSignatureError, JWTClaimsError, jwt

logger = logging.getLogger(__name__)

create_access_token() — 발급 로그 추가:

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() — 발급 로그 추가:

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() — 성공/실패 분류 로그:

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 추가:

import logging
logger = logging.getLogger(__name__)

get_current_user() — 검증 과정 로그:

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 레벨:

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() — 전체 흐름 로그:

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 저장 로그:

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() — 단일 로그아웃 로그:

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() — 전체 로그아웃 로그:

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 — 라우터 진입/완료 로깅

# 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