SQLite database is locked — WAL만 켜면 더 샌다

1. 언제 나나 — 5.43초 뒤에 터지는 이유

자동매매 프로그램을 몇 달 운영하면 프로세스가 하나가 아니게 됩니다. 장중에 키움 kt10000이나 KIS TTTC0012U로 주문을 내고 체결을 fills 테이블에 쌓는 매매 봇, 그 테이블을 읽어 잔고를 알려 주는 텔레그램 봇, 장 마감 뒤 손익을 정산하는 스크립트가 같은 trade.db를 엽니다. 별도 서버가 필요 없는 SQLite가 편해서 이렇게 시작하는데, 어느 날 로그에 아래 한 줄이 찍히고 그날의 체결 기록이 비어 있습니다.

Traceback (most recent call last):
  File "bot.py", line 88, in record_fill
    conn.execute("INSERT INTO fills(code,qty,price,ts) VALUES(?,?,?,?)", row)
sqlite3.OperationalError: database is locked

SQLite는 파일 하나에 동시에 한 연결만 쓸 수 있습니다. 다른 연결이 쓰기 잠금을 쥐고 있으면 기다리다가, 정해진 시간이 지나면 SQLITE_BUSY를 돌려주고 파이썬은 이것을 OperationalError: database is locked로 올립니다. 그 대기 시간이 sqlite3.connect()의 timeout이고 기본값은 5.0초입니다(PRAGMA busy_timeout으로 읽으면 5000). 한 프로세스가 쓰기 트랜잭션을 연 채 8초 동안 커밋하지 않게 해 두고, 다른 프로세스에서 INSERT를 해 본 결과입니다.

표에서 두 가지를 읽을 수 있습니다. 첫째, 쓰기와 쓰기의 충돌은 WAL이어도 똑같이 막힙니다. WAL이 바꾸는 것은 읽기가 쓰기를 기다리지 않게 하는 부분입니다. 둘째, 8초를 쥐고 있던 이유가 문제입니다. 실제 봇에서 이런 시간은 대개 트랜잭션을 연 채 주문 API 응답을 기다릴 때 생깁니다. INSERT로 주문 기록을 먼저 넣고, requests.post()로 주문을 보내고, 응답의 주문번호(ord_no·ODNO)를 UPDATE한 다음에야 commit()하는 구조입니다. 이 사이에 ReadTimeout이 걸리면 그 시간 전체가 잠금 시간이 됩니다.

2. 실측: 설정 5가지로 2,000건을 써 보니

체결 1건이 들어올 때 봇이 하는 일을 흉내 냈습니다 — 현재 포지션을 읽고(SELECT qty FROM pos), 체결을 기록하고(INSERT INTO fills), 포지션을 1 늘립니다(UPDATE pos). 4개 프로세스(multiprocessing)가 각각 500번, 합계 2,000번 동시에 실행하고, 끝난 뒤 fills 행 수와 포지션 증가분을 셌습니다. 전부 timeout=5입니다. 표의 숫자는 3회 실행(1회 + 반복 2회) 값입니다.

더 무서운 것은 따로 돌린 다섯 번째 설정입니다. 트랜잭션을 직접 열지 않고 파이썬 sqlite3 기본값(isolation_level='')으로, 많은 봇 코드가 실제로 쓰는 모양 그대로 "읽고 → 파이썬에서 +1 → 쓰기"를 했습니다.

qty = conn.execute("SELECT qty FROM pos WHERE code='005930'").fetchone()[0]
conn.execute("UPDATE pos SET qty=? WHERE code='005930'", (qty + 1,))
conn.commit()

python-default DELETE: 25.50s fails=2 expected+=1998 actual+=703
python-default WAL:     5.22s fails=0 expected+=2000 actual+=500

WAL에서는 에러가 0건인데 포지션은 2,000이 아니라 500만 늘었습니다. 파이썬 기본 모드는 SELECT 전에는 트랜잭션을 열지 않고 UPDATE 직전에야 엽니다. 그래서 네 프로세스가 같은 qty를 읽고 각자 +1을 써서 서로의 결과를 덮어씁니다(lost update). 잠금 에러는 적어도 로그에 남지만 이것은 아무 흔적이 없습니다. 실제 봇이라면 보유 수량이 틀어진 채로 다음 매도 수량을 계산합니다. 같은 일을 UPDATE pos SET qty = qty + 1처럼 계산을 SQL 안에 넣어 돌리면 WAL에서 2,000건 전부(5.65초), DELETE에서 1,997건이 반영됐습니다.

3. WAL이 더 나빠지는 이유 — 승격 충돌

BEGIN은 기본이 DEFERRED입니다. 트랜잭션을 "읽기"로 시작했다가 첫 쓰기 문장에서 "쓰기"로 승격합니다. 그런데 읽은 뒤 승격하기 전에 다른 연결이 커밋해 버리면, WAL 모드의 이 트랜잭션은 이미 낡은 스냅숏을 보고 있으므로 쓰기를 허락받을 수 없습니다. SQLite는 이때 SQLITE_BUSY_SNAPSHOT을 돌려주는데, 기다려도 풀리지 않는 충돌이라 busy handler(timeout)를 타지 않고 즉시 실패합니다. 두 연결로 재현한 결과입니다.

== upgrade WAL
  other writer commit while A holds read txn: 0.01s -> OK
  deferred upgrade (timeout=10): 0.000s -> OperationalError: database is locked
== upgrade DELETE
  other writer commit while A holds read txn: 10.78s -> OperationalError: database is locked

WAL에서는 A가 읽는 동안 B의 커밋이 0.01초 만에 통과했고, 그 뒤 A의 UPDATE는 timeout=10을 줬는데도 0.000초에 거절됐습니다. 2장 표에서 WAL + DEFERRED가 1.3초 만에 끝난 이유가 이것입니다 — 기다리지 않고 바로 실패했기 때문에 빠른 것입니다. 기본 DELETE 저널에서는 반대로 A가 읽기 트랜잭션을 열어 둔 것만으로 B의 커밋이 10.78초 동안 막혔습니다. 대시보드나 텔레그램 봇이 SELECT 후 커밋을 안 하고 연결을 붙잡고 있으면 매매 봇의 체결 기록이 막히는 구조입니다.

BEGIN IMMEDIATE는 시작할 때 바로 쓰기 잠금을 잡습니다. 못 잡으면 그 자리에서 timeout만큼 기다리고, 잡은 뒤에는 아무도 끼어들 수 없으므로 승격 충돌이 생기지 않습니다. 그래서 읽기→쓰기 트랜잭션에는 IMMEDIATE가 정답이고, WAL은 그 위에서 읽기 쪽을 풀어 주는 보조 장치입니다. DELETE + IMMEDIATE에서 3~5건이 남은 것은 Windows 로컬 디스크의 동기화가 느려 일부 대기가 5초를 넘었기 때문으로 보이며, timeout을 늘리면 줄어듭니다.

4. 고치는 코드

체결 기록·포지션 갱신을 이 함수 하나로만 하게 만드는 것이 핵심입니다. 키·계좌번호 같은 비밀값은 DB가 아니라 환경변수에 둡니다(API 키 보관).

import sqlite3, time, contextlib

def connect(path="trade.db"):
    # isolation_level=None: 파이썬이 몰래 BEGIN을 끼우지 않게 하고 직접 연다
    conn = sqlite3.connect(path, timeout=15, isolation_level=None)
    conn.execute("PRAGMA journal_mode=WAL")      # 읽기가 쓰기를 막지 않게
    conn.execute("PRAGMA busy_timeout=15000")    # 연결마다 따로 걸린다
    conn.execute("PRAGMA synchronous=NORMAL")    # WAL에서 흔히 쓰는 조합
    return conn

@contextlib.contextmanager
def write_tx(conn, retries=3):
    for i in range(retries):
        try:
            conn.execute("BEGIN IMMEDIATE")      # 시작부터 쓰기 잠금
            break
        except sqlite3.OperationalError as e:
            if "locked" not in str(e) or i == retries - 1:
                raise
            time.sleep(0.2 * (i + 1))
    try:
        yield conn
        conn.execute("COMMIT")
    except Exception:
        conn.execute("ROLLBACK")
        raise

def record_fill(conn, code, qty, price):
    with write_tx(conn):
        conn.execute("INSERT INTO fills(code,qty,price,ts) VALUES(?,?,?,?)",
                     (code, qty, price, time.time()))
        conn.execute("UPDATE pos SET qty = qty + ? WHERE code = ?", (qty, code))  # 계산은 SQL 안에서

fix: 0.37s rows=2000 qty+=2000 exitcodes=[0, 0, 0, 0]

위 코드를 그대로 2장과 같은 조건(4프로세스 × 500건)으로 돌린 출력입니다. 에러 0건, 체결 2,000행, 포지션 +2,000이 0.37초에 끝났습니다. 2장의 WAL + IMMEDIATE(5~7초)보다 빠른 것은 synchronous=NORMAL 덕분인데, 이 설정은 전원이 갑자기 꺼지면 마지막 커밋 몇 건을 잃을 수 있는 대신 DB 파일 자체는 깨지지 않는 조합입니다. 정전 대비가 더 중요하면 이 줄을 빼면 됩니다.

주문과 기록의 순서도 바꿔야 합니다. 트랜잭션 안에서 네트워크를 기다리지 않는 것이 규칙입니다.

1. 주문 전 — 짧은 트랜잭션으로 orders에 "보냄" 상태 1행을 넣고 커밋합니다(재시작 때 미확인 주문을 찾는 근거).
2. 주문 — 트랜잭션 밖에서 kt10000·TTTC0012U를 호출합니다. 몇 초가 걸려도 DB는 잠기지 않습니다.
3. 주문 후 — 다시 짧은 트랜잭션으로 주문번호와 상태를 UPDATE합니다. 체결은 실시간 체결 통보가 올 때 record_fill로 넣습니다.

읽기만 하는 텔레그램 봇·대시보드는 with 블록 안에서 SELECT만 하고 곧바로 연결을 닫거나, sqlite3.connect("file:trade.db?mode=ro", uri=True)로 읽기 전용으로 엽니다. 여러 스레드가 한 연결을 나눠 쓰려고 check_same_thread=False를 켜는 경우가 많은데, 그러면 한 스레드의 열린 트랜잭션에 다른 스레드의 문장이 섞입니다. 스레드마다 연결을 따로 만드는 편이 안전합니다.

5. 그래도 안 되면 — SQLite를 그만 쓸 때

위 설정이면 개인 봇 규모에서는 충분합니다. 2장 실측에서 WAL + IMMEDIATE는 쓰기 2,000건을 5~7초에 처리했고, 하루 체결이 수백 건인 봇은 이 부하의 근처에도 가지 않습니다. 그래도 아래에 해당하면 구조를 바꿀 때입니다.

운영 중에 잠금 에러가 처음 보였다면, 고치기 전에 그날 fills 행 수와 증권사 체결 내역(kt00009·TTTC0081R)을 맞대어 빠진 건부터 확인하세요. 기록이 빠진 상태로 다음 날 봇을 다시 켜면 보유 수량을 잘못 알고 시작합니다. 장애 대응 순서는 봇 장애 복구 플레이북에 정리해 두었습니다.

6. 자주 묻는 질문