[4/17] 자동매매 개발일지 – KIS API 에러 3가지와 진단 순서

미장봇을 KIS API에 붙이면서 만난 에러 메시지는 원인을 엉뚱하게 가리킬 때가 많았다. “유효하지 않은 AppKey”라는데 키는 멀쩡했고, HTTP 500이 뜨는데 서버는 정상이었다.

아래 세 가지는 모두 운영하면서 실제로 만났고, 봇의 트러블슈팅 로그에 날짜와 함께 남아 있다. 세 번 다 메시지만 믿고 다른 곳을 의심하다 시간을 썼다. 표의 넷째 줄은 에러가 아니라, 똑같이 생긴 500을 원인별로 가르는 진단 순서다.

키를 새로 받아도 EGW00103이 그대로였다

첫 번째는 KIS API 호출이 EGW00103 “유효하지 않은 AppKey”로 거부된 일이다. 메시지만 보면 답이 뻔해 보여서 처음에는 KIS 개발자 콘솔에서 키를 재발급하고 .env를 갱신했다. 증상은 그대로였다.

방향이 바뀐 건 토큰을 손으로 직접 받아 본 뒤였다. 터미널에서 curl로 토큰 발급 엔드포인트를 불렀더니 200 OK와 함께 정상 토큰이 나왔다.

# 키가 진짜 죽었는지 확인하는 한 줄. 200이면 키는 정상이다
curl -s -X POST https://openapi.koreainvestment.com:9443/oauth2/tokenP \
  -H "Content-Type: application/json" \
  -d '{"grant_type":"client_credentials","appkey":"'$KEY'","appsecret":"'$SEC'"}'

키가 정상이면 남는 건 봇의 토큰 재시도 코드다. 1편에서도 잠깐 적은 일인데, 로그를 되짚어 보니 이렇게 흘러갔다. 2026년 4월 11일 KIS 서버에 일시 장애가 있었고 봇의 토큰 발급이 실패했다. 봇은 30초 간격으로 재시도를 반복했는데 KIS의 토큰 발급은 분당 1회로 제한된다. 30초 루프는 이 제한을 계속 어겼고, 위반이 쌓이면서 4월 12일부터 403이 반복되더니 13일에는 앱/IP 단위로 하루치 차단(lockout)이 걸렸다.

고정 간격으로 재시도한 게 문제였으니, 실패할수록 더 오래 기다리는 지수 백오프(exponential backoff)로 바꿨다. 토큰 발급이 실패하면 대기 시간을 1분, 5분, 15분, 30분, 1시간으로 늘려 가고, 한 번 성공하면 카운트를 리셋한다.

# kis_auth.py: 토큰 발급 백오프 스케줄
# KIS는 tokenP를 rate-limit 하므로, 실패 시 물러섰다가 재시도한다
_BACKOFF_SCHEDULE = (60, 300, 900, 1800, 3600)  # 1m, 5m, 15m, 30m, 1h

# 실패 횟수에 맞춰 대기 시간 선택 (스케줄 끝에서 clamp)
idx = min(self._failure_count - 1, len(self._BACKOFF_SCHEDULE) - 1)
delay = self._BACKOFF_SCHEDULE[idx]

셸이 시크릿의 마지막 1바이트를 먹었다

두 번째는 모든 KIS 호출이 HTTP 500에 빈 body(rt_cd:”1″, msg_cd:””, msg1:””)로 실패한 일이다. 헤더, 파라미터, 토큰 모두 정상으로 보였다. 누가 봐도 서버 문제처럼 생긴 증상이었는데 결정적인 단서가 하나 있었다. bash로 띄운 경로에서만 500이 나고, 파이썬 python-dotenv로 .env를 직접 읽어 같은 요청을 보내면 200이 나왔다. 그렇다면 문제는 KIS가 아니라 환경변수를 읽어 들이는 셸 쪽에 있었다.

원인은 .env를 읽던 bash 한 줄이었다.

# 문제의 코드: value가 '='로 끝나면 마지막 '='를 잘라먹는다
while IFS='=' read -r key value; do
    export "$key=$value"
done < .env

bash의 read는 필드 끝에 붙은 IFS 문자, 여기서는 =를 잘라낸다. 그런데 KIS_APP_SECRET은 base64로 인코딩돼 있어서 = 패딩으로 끝나는 경우가 있다. 그렇게 시크릿의 끝 1바이트가 조용히 잘려 나갔고, 1바이트 잘린 시크릿은 KIS 인증 검증을 통과하지 못해 빈 body의 500이 돌아왔다. 헤더도 토큰 발급도 파라미터도 다 정상이라 티가 나지 않았다.

고친 방법은 IFS를 비워서 read가 아무 바이트도 자르지 않게 하고, 키와 값은 substring expansion으로 직접 나누는 것이다.

# IFS를 비우면 read가 아무 바이트도 자르지 않는다.
# key/value는 substring expansion으로 직접 분리한다.
while IFS= read -r line || [ -n "$line" ]; do
    key="${line%%=*}"    # 첫 '=' 앞 = 키
    value="${line#*=}"   # 첫 '=' 뒤 전부 = 값 (뒤쪽 '='도 보존)
    # ... 따옴표/공백 정리 후 export ...
done < .env

여기에 파이썬 쪽 방어를 한 겹 더 넣었다. config.py에서 load_dotenv(env_path, override=True)로 .env 파일을 다시 읽어 덮어쓴다. 셸이 잘못 export해도 파이썬이 파일 원본으로 바로잡으니, .env 파일 하나가 기준이 된다.

인증 실패가 의심되면 값을 눈으로 비교하지 말고 길이를 비교한다. 끝의 = 하나 차이는 눈으로는 잘 보이지 않는다.

# bash가 export한 시크릿 길이 vs .env 원본 길이
echo "SEC_LEN=${#KIS_APP_SECRET}"
grep KIS_APP_SECRET .env | wc -c
# 두 길이가 1 byte라도 다르면 IFS 파싱 의심 확정

막 띄운 프로세스만 500을 받았다

세 번째는 봇 프로세스를 새로 띄운 직후 첫 15~60초 동안만 대부분의 KIS GET API가 HTTP 500을 돌려준 일이다. 시세 조회(HHDFS00000300)도 예수금 조회(CTRP6504R)도 그랬다. 이미 떠 있던 warm 프로세스에서는 같은 토큰, 같은 파라미터로 200이 나왔다.

앞의 두 건과 똑같이 생긴 HTTP 500이라 처음에는 또 토큰을 의심했다. 하지만 같은 토큰으로 warm 프로세스에서는 200이 나왔으니 토큰은 정상이었다. cold 프로세스에서만 500이 난다면 원인은 KIS 서버 쪽의 세션 priming 지연이다. 새 연결이 서버에서 데워지는 데 시간이 걸리는 것이다.

자동매매에서는 이 몇십 초가 하루치 매매를 날린다. 봇의 self.capital 초기값은 0.0인데, 시작 직후 자본을 맞추는 _sync_capital이 하필 이 구간에 걸려 실패하면 그날 매수 수량이 이렇게 계산된다.

shares = int(self.capital / price)   # capital=0.0 이면
#      = int(0.0 / price)
#      = 0   그날 매매 전면 차단

자본이 0으로 읽히니 주문 수량이 0이 되고, 봇은 아무것도 사지 못한 채 하루를 보낸다. 안에 있던 1초, 2초, 4초, 다 합쳐 7초짜리 재시도로는 이 15~60초 구간을 넘지 못했다.

그래서 KIS 초기화 직후에 warm_up()을 부르게 했다. 가벼운 시세 엔드포인트를 10초 간격으로 최대 90초까지 찔러 보다가 200이 오면 바로 빠져나온다.

# KISClient.warm_up: 서버가 200을 줄 때까지 기다렸다가 매매 시작
def warm_up(self, max_secs: int = 90, poll_interval: int = 10) -> bool:
    deadline = time.time() + max_secs
    while time.time() < deadline:
        # 핵심: retry=False. 내부 재시도가 polling 예산을 먹으면 안 된다
        if self._probe_quote(retry=False):   # 200 받으면
            return True                       # 즉시 종료
        time.sleep(poll_interval)
    return False   # 실패해도 봇은 계속 진행 (다음 동기화에서 자동 교정)

여기서 챙겨야 할 건 retry=False다. 워밍업 호출에 재시도를 붙이면 재시도가 90초를 다 써 버려서 서버를 찔러 보는 횟수가 줄어든다. 워밍업은 한 번 찔러 보고 아니면 다음 주기로 넘어가는 식으로 단순해야 한다. 워밍업이 실패해도 봇은 멈추지 않고 진행하고, 다음 자본 동기화(새 날이나 장 마감) 때 저절로 바로잡힌다.

똑같은 500, 원인은 어떻게 가를까

두 번째와 세 번째 사건은 겉으로 보이는 증상이 똑같았다. 둘 다 HTTP 500에 빈 body였지만 하나는 셸 파싱 버그였고 하나는 서버 세션 지연이었다. 원인이 다르니 처방도 달라서, 같은 증상에서 원인을 갈라내는 순서가 필요했다.

HTTP 500에 빈 body는 서버 신호처럼 생겼지만 실제로는 클라이언트 인증 실패인 경우가 더 많았다. 그래서 서버를 탓하기 전에 이 순서로 내려간다.

가장 싸고 결과가 분명한 검사부터 한다. 시크릿 길이 비교는 명령 두 줄이면 끝나고 결과가 딱 갈린다. 길이가 같으면 프로세스가 방금 떴는지 본다. 방금 시작했다면 cold-start일 가능성이 높다. 이 둘을 다 배제한 다음에야 토큰과 서버를 의심한다. 서버 탓은 맨 마지막이다.

KIS 제한은 두 가지라 헷갈리기 쉽다. 일반 API 호출은 초당 20건까지이고, 넘으면 EGW00201이 온다. 토큰 발급은 첫 번째 사건에서 본 분당 1회다. 그래서 미장봇은 토큰을 config/token.json에 캐시해 두고 호출할 때마다 새로 받지 않는다.

로그에는 2편에 적은 대로, KIS가 500을 돌려주면 엔드포인트와 tr_id, 응답 body의 msg_cd와 msg1을 한 줄에 같이 남긴다. KIS가 왜 거절했는지는 메시지를 읽는 것보다 내가 보낸 값을 직접 확인하는 쪽이 빨랐다.

다음 편부터는 이 API 위에 첫 매매 전략인 ORB+FVG를 얹는 이야기로 넘어간다.

이 글은 미국주식 자동매매 봇을 만들며 겪은 API 연동 문제를 적은 개발 기록이고, 특정 종목이나 전략의 매매를 권하지 않는다. 코드와 수치, 로그는 모두 실제 프로젝트 문서에 근거한다.

참고한 자료: KIS Developers, 한국투자증권 오픈API 개발자센터, 한국투자증권 API 호출 유량 제한(초당 20건) 대응 사례 (hky035)