← ~/notes · 4 min read

허니팟 운영 2주차 — 들여쓰기 한 칸 때문에 6.5만 건을 놓칠 뻔했다

쌓이는데 안 쌓이는, 가장 무서운 종류의 버그. 그리고 그동안 미뤄둔 격리 강화 작업.

securityhoneypotdebugginginfra
목차
  1. 그래프가 평평해졌다
  2. 진짜 원인 — while 루프 밖에 떨어진 한 칸
  3. 어떻게 찾았는가
  4. 수정
  5. 5/12-13 백필
  6. 백필 후 일자별
  7. 함정은 또 있었다 — 노출 점검
  8. 함정 또 — 허니팟에서 LAN으로 ping이 갔다
  9. 트래픽 더 끌어모으기 — 표준 포트로 redirect
  10. 14만 건 누적 시점 통계
  11. 이번에 알게 된 것들
  12. 다음

허니팟 SOC 구축기를 올린 지 6일 됐다. 그 사이 누적 이벤트가 5만에서 14만으로 늘었다.

다만 후반 며칠은 거의 잃을 뻔했다.

그래프가 평평해졌다

대시보드를 보다가 이상한 걸 발견했다.

날짜이벤트 수
5/1013,233
5/114,774
5/1260
5/1362
5/145

5/12부터 갑자기 하루 60건이다. 어제까지 1만 건씩 들어오던 게 1/200로 떨어졌다. 봇이 단체 휴가라도 갔나.

그런데 Cowrie 로그 파일 크기는:

-rw-r--r-- 1 ... 28059720 May 12 23:59 cowrie.json.2026-05-12   ← 28MB
-rw-r--r-- 1 ... 35727071 May 13 23:59 cowrie.json.2026-05-13   ← 35MB

역대 최대다. 트래픽은 미친 듯이 들어오고 있는데, DB에는 nginx 60건만 들어가고 있었다.

진짜 원인 — while 루프 밖에 떨어진 한 칸

aggregator.py의 cowrie 처리 부분이다. 일주일 전쯤 log rotation 따라가게 수정했었다:

def tail_cowrie(con):
    ...
    while True:  # rotation 재시작 루프
        with open(path, errors="replace") as f:
            opened_ino = path.stat().st_ino
            f.seek(0, 2)
            while True:
                line = f.readline()
                if not line:
                    time.sleep(0.3)
                    if path.stat().st_ino != opened_ino:
                        break  # rotation 감지
                    continue
            try:                           # ← 여기 들여쓰기 잘못됨
                ev = json.loads(line.strip())
            except:
                continue
            ...  # 이 아래 전부가 inner while 바깥

try: json.loads(line) 라인이 inner while 안이 아니라 같은 레벨로 들여쓰기 됐다.

흐름을 따라가 보면:

  1. inner while 안에서 f.readline() 호출 → 라인 있음
  2. if not line: 분기에 안 걸리므로 continue도 break도 안 함
  3. 다음 라인 읽으러 다시 inner while 위로 감
  4. try: ev = json.loads(...) 코드는 영원히 실행 안 됨
  5. inner while이 break하는 유일한 경로: rotation 감지 (break)
  6. rotation 시점에 line은 빈 문자열 → json.loads("") 예외 → continue → outer while
  7. 처음으로 돌아가서 새 파일 열고 다시 반복

JSON 파싱부터 DB 인서트까지 통째로 죽은 코드가 됐다.

nginx watcher는 별도 함수라 영향을 안 받았다. 그래서 nginx 이벤트만 60건씩 들어오고 있었다.

어떻게 찾았는가

증상이 모호해서 한참 헤맸다. 프로세스는 살아 있고(active (running)), 파일 핸들도 잡혀 있고, 파일 사이즈가 증가하면 read offset도 따라 증가한다.

결정타는 가짜 라인 주입이었다:

echo '{"eventid":"cowrie.login.failed","src_ip":"203.0.113.99",
      "username":"root","password":"test123",...}' \
  | sudo tee -a /opt/honeypot/cowrie/var/log/cowrie/cowrie.json

4초 후:

May 14 05:38:07 [cowrie] 203.0.113.99 () cowrie.login.failed
DB: 2026-05-14T05:38:06Z | cowrie.login.failed | 203.0.113.99 | root | test123

들어왔다. aggregator는 살아 있고 라인도 처리한다.

그러면 왜 자연 트래픽은 안 들어오나? 자연 트래픽이 진짜로 안 들어왔던 게 아니라, 들어왔는데 json.loads를 한 번도 호출하지 않았던 거다.

코드를 다시 읽었다. 그제서야 보였다. try:가 12칸 들여쓰기, 위의 while True:도 12칸. 같은 레벨이었다.

수정

라인 430~518에 일괄로 4 spaces 추가:

sed -i '430,518 { /[^[:space:]]/ s/^/    / }' aggregator.py
python3 -m py_compile aggregator.py   # syntax 검증
systemctl restart honeypot-aggregator

수정 후 1분 만에 자연 cowrie 이벤트가 들어오기 시작했다.

5/12-13 백필

로그 파일은 멀쩡하니까 다시 밀어 넣었다. 50,724 + 62,099 = 112,823 라인, 그중 65,097건이 새로 들어갔다.

INSERT_TYPES = {
    'cowrie.login.success', 'cowrie.login.failed',
    'cowrie.command.input',
    'cowrie.session.file_upload', 'cowrie.session.file_download',
    'cowrie.session.connect', 'cowrie.client.version',
}

# 중복 방지: 기존 (ts, src_ip, event_type, session_id) 미리 로드
existing = set()
for r in con.execute("""
    SELECT ts, src_ip, event_type, COALESCE(session_id,'')
    FROM events WHERE ts >= '2026-05-12' AND source='cowrie'
"""):
    existing.add(r)

전체 통계:

{'total': 112823, 'inserted': 65097, 'skip_priv': 0, 'skip_type': 47726, 'parse_err': 0}

skip_type이 절반(47k)인 건 cowrie.direct-tcpip.*, cowrie.session.params 같이 분석에 필요 없는 이벤트들을 제외했기 때문이다.

백필 후 일자별

날짜이벤트
5/1013,233
5/114,774
5/1228,827 ← 백필
5/1336,392 ← 백필, 역대 최대

5/13 하루에 36,392건. 5/8 글 쓸 때 자랑했던 “24h 2,869건”의 12배다.

함정은 또 있었다 — 노출 점검

들여쓰기 버그 찾던 김에 외부 노출 상태를 다시 봤다. 깜짝 놀랐다.

0.0.0.0:8000   → splunkd       (Splunk Web)         ← 외부 열림
0.0.0.0:8089   → splunkd       (Splunk Management)  ← 외부 열림
0.0.0.0:8191   → mongod-8.0    (MongoDB)            ← 외부 열림

진짜 서비스 3개가 공인 IP로 노출돼 있었다. UFW에 명시적으로 허용한 적은 없는데 Docker 또는 시스템 기본 설정으로 새어 나왔다.

sudo ufw deny 8000/tcp comment 'Splunk Web'
sudo ufw deny 8089/tcp comment 'Splunk Management'
sudo ufw deny 8191/tcp comment 'MongoDB'

허니팟이 뚫리는 건 의도된 일이다. 진짜 서비스가 같이 노출되는 건 사고다.

함정 또 — 허니팟에서 LAN으로 ping이 갔다

격리 점검도 했다. cap_drop: ALL, no-new-privileges: true, docker socket 미공유 — 컨테이너 escape는 잘 막혀 있다.

문제는 네트워크였다.

docker exec hp-canary ping -c1 8.8.8.8         # ✅ 외부 (의도)
docker exec hp-canary ping -c1 172.30.1.130    # ✅ vm3 호스트  ← 위험
docker exec hp-canary ping -c1 172.30.1.254    # ✅ LAN 게이트웨이  ← 위험
docker exec hp-canary ping -c1 172.17.0.2      # ✅ cowork 컨테이너  ← 위험

컨테이너 자체는 잘 갇혀 있지만, 컨테이너 안에서 평범한 네트워크 호출로 같은 LAN의 다른 vm들에 패킷이 갔다. 누군가 Cowrie에 RCE를 따면 컨테이너 안에서도 nmap 172.30.1.0/24가 된다는 뜻이다.

해결: DOCKER-USER 체인에 룰 추가. Docker가 항상 FORWARD보다 먼저 처리하기 때문에 docker 재시작에도 살아남는다.

# 같은 honeypot-net 내부는 OK
iptables -I DOCKER-USER -s 172.28.0.0/16 -d 172.28.0.0/16 -j RETURN

# 다른 사설망(RFC1918) 전부 차단
iptables -I DOCKER-USER -s 172.28.0.0/16 -d 10.0.0.0/8 -j DROP
iptables -I DOCKER-USER -s 172.28.0.0/16 -d 192.168.0.0/16 -j DROP
iptables -I DOCKER-USER -s 172.28.0.0/16 -d 172.16.0.0/12 -j DROP

# vm3 호스트 자체 차단 (응답 트래픽은 살림)
iptables -I INPUT -s 172.28.0.0/16 -m state --state ESTABLISHED,RELATED -j ACCEPT
iptables -I INPUT -s 172.28.0.0/16 -d 172.30.1.130 -j DROP

netfilter-persistent로 저장. 재부팅해도 살아남는다.

검증:

docker exec hp-canary ping 8.8.8.8        # ✅ 외부 OK (페이로드 분석용)
docker exec hp-canary ping 172.30.1.130   # ❌ vm3 호스트
docker exec hp-canary ping 172.30.1.254   # ❌ LAN gw (다른 vm 보호)
docker exec hp-canary ping 172.17.0.2     # ❌ 진짜 서비스 컨테이너

원하는 그림이 됐다. 허니팟 안에서 공격자가 뭘 하든 외부 인터넷으로만 나갈 수 있다.

트래픽 더 끌어모으기 — 표준 포트로 redirect

봇은 보통 22(SSH), 23(Telnet), 80(HTTP)을 먼저 스캔한다. 우리 허니팟은 2222, 2323, 8080에 있었다.

22번에는 진짜 sshd가 있어서 잘못 건드리면 잠긴다. 23과 80은 비어 있었다.

# 23 → Cowrie Telnet(2323)
iptables -t nat -A PREROUTING -p tcp --dport 23 -j REDIRECT --to-port 2323

# 80 → HellPot(8080)
iptables -t nat -A PREROUTING -p tcp --dport 80 -j REDIRECT --to-port 8080

ufw allow 23/tcp comment 'Cowrie Telnet redirect'
ufw allow 80/tcp comment 'HellPot HTTP redirect'

영구화는 /etc/ufw/before.rules의 *nat 섹션에 같은 룰을 넣었다. 재부팅해도 살아남는다.

22 → 2222 redirect는 진짜 sshd를 다른 포트로 옮긴 다음에 해야 한다. 락아웃 위험이 있어서 별도 작업으로 분리했다.

14만 건 누적 시점 통계

항목수치
누적 전체143,771건
5/13 단일일36,392건 (역대 최대)
5/13 고유 공격자 IP455개
자동 차단 IP18개

차단 사유 분포:

사유건수
컨테이너 탈출 시도7
DDoS 봇넷 설치6
악성파일 UPLOAD2
컨테이너 탈출 시도 (반복)1
SSH 백도어 설치 (3회 반복)1
/tmp 바이너리 직접 실행1

5/10에는 단일 IP 176.125.224.179 하나가 하루에 5,773건을 때렸다. 정상적인 봇 스캔이 아니라 거의 DoS 수준이다.

이번에 알게 된 것들

조용히 실패하는 코드가 가장 무섭다. 세그폴트나 예외처럼 비명을 지르면 차라리 낫다. aggregator는 살아 있고, 프로세스도 active이고, fd offset도 증가하는데, DB만 안 채워졌다. 모니터링이 “프로세스 살아있나”에만 의존하면 못 잡는다.

들여쓰기는 의미가 아니라 구조다. Python에서 들여쓰기 한 칸은 } 하나와 같다. 4 spaces 하나가 빠지면 코드 블록 전체가 다른 컨텍스트로 가버린다. linter도 syntax check도 통과한다.

격리는 컨테이너 안만 보면 안 된다. cap_drop: ALL이 들어가 있다고 안심하면 안 된다. 컨테이너 안에서 평범한 connect()로 호스트 LAN의 다른 시스템에 닿을 수 있다. 별도로 막아야 한다.

진짜 노출은 의도하지 않은 곳에서 새어 나온다. UFW에 명시적으로 허용한 적 없는데도 Splunk, MongoDB가 외부에서 보이고 있었다. 정기적으로 ss -tlnp | grep 0.0.0.0을 봐야 한다.

다음

22번을 Cowrie로 옮기는 건 다음 작업이다. 실 sshd를 22222로 이전하고, ufw allow 22222를 확인하고, 새 터미널로 22222 접속 검증한 다음에야 22를 닫는다. 순서 잘못하면 잠긴다.

22 redirect까지 적용하면 일자 평균 5만 건 정도까지 늘 것 같다. SSH 브루트포스가 가장 많은 비중을 차지하니까.

오늘은 여기까지. 들여쓰기 한 칸 때문에 글이 한 편 더 생겼다.