‘폰 서버 안정화 일지’ 세 번째 글이다. 재부팅 뒤 카카오톡 봇이 명령에 응답하지 않는데, 워치독은 “정상"이라고 했다. 프로세스 존재와 서비스 동작은 다른 것이라는 걸 비싼 수업료를 내고 배웠다.

증상: 봇이 조용하다

재부팅 뒤 방에서 !내정보를 쳤는데 답이 없었다. tmux 세션 iris의 두 창을 보니 창 0의 Iris 데몬도, 창 1의 python3 irispy.py도 살아 있었다. 워치독 로그도 “정상 — 조치 없음"만 찍혀 있었다. 그런데 봇 창 쪽 로그엔 Connection refused와 Connection reset by peer가 반복되고 있었다.

원인 1: NotificationListener 바인더 NPE 루프

Iris 데몬 창의 로그를 끝까지 보니 같은 예외가 무한히 반복되고 있었다.

NotificationPoller.getActiveNotifications
NullPointerException: null cannot be cast to non-null type android.os.IBinder

Iris는 카카오톡 메시지를 안드로이드 NotificationListenerService로 받는다. 재부팅 직후 그 바인더 연결이 깨진 상태로 데몬이 올라오면, 알림을 폴링하는 루프가 NPE를 던지고 다시 돌고 다시 던진다. 프로세스는 살아 있지만 HTTP API 포트는 절대 열리지 않는다. 봇은 그 포트에 붙으려다 거절당하는 것이다.

해법은 데몬을 완전히 죽이고 다시 띄우는 것이었다. 그런데 여기서 두 번째 버그를 만났다.

원인 2: iris_stop이 PID 두 개를 한 문자열로 넘긴다

제어 스크립트 iris_control_termux의 stop이 실패했다. get_iris_pid()가 app_process 프로세스를 찾는데 결과가 두 줄이면 $pid에 줄바꿈이 들어간 문자열이 담기고, 그걸 그대로 su -c "kill -s SIGKILL $pid"에 넘긴다. su는 두 번째 PID를 명령 이름으로 해석해 <second_pid>: inaccessible or not found를 내고, 프로세스는 살아남는다. 그 뒤 start를 치면 “Iris is already running"으로 거절된다. 두 번 재현해서 구조적인 버그임을 확정했다.

우회는 제어 스크립트를 거치지 않는 것이다. 이 작업은 proot 컨테이너의 셸이 아니라 실제 Termux 창에서 해야 한다. 컨테이너 안의 ps와 kill은 폰의 실제 프로세스 상태와 자주 어긋났기 때문이다.

# tmux 창 iris:0 안에서
su -c 'ps -ef | grep app_process | grep -v grep'   # 진짜 PID 확인
su -c 'kill -9 <pid1> <pid2>'
su -c 'ps -ef | grep app_process | grep -v grep'   # 비었는지 재확인
./iris_control_termux start -v

첫 번째 재기동 뒤에도 “여전히 안 된다"는 피드백을 받았다. 이번엔 데몬이 알림을 처리하면서(Detected N new log(s). Processing...) 답장 전송에서 InvocationTargetException을 간헐적으로 냈다. 같은 절차를 한 번 더 돌린 뒤 15초 동안 로그를 지켜봐 오류가 없는 걸 확인하고 끝냈다.

원인 3: 빈 DB를 서빙하는 좀비

다른 날에는 또 다른 모양으로 죽어 있었다. 데몬 API는 응답하는데 /query로 테이블을 조회하면 android_metadata 하나만 나오고 chat_logs가 없었다. 카카오톡 DB 핸들이 낡은 상태로 굳은 것이다. iris_control_termux status는 “already running"이라고 했지만 ps aux에는 app_process도 qwer도 없었다. 상태 파일만 남은 좀비였다. stop 뒤 start -v로 해결했다.

수정: 워치독에 기능 체크 추가

워치독의 봇 점검(항목 10)은 pgrep -f "python3 irispy\.py"만 봤다. 스크립트 주석에 “런처 프로세스는 종료하므로 직접 확인하지 않는다"고 적혀 있을 만큼 의도적인 선택이었지만, 그래서 “파이썬은 살았는데 코어가 죽은” 상태가 보이지 않았다.

항목 11을 새로 넣었다. 기존 check_http 헬퍼로 Iris 데몬의 로컬 API에 실제 HTTP 요청을 보내 응답(502, 503, 504, 530, 000은 비정상)을 확인한다. 실패하면 제어 스크립트의 버그를 우회해 su -c "pkill -9 -f party.qwer.iris.Main"으로 데몬을 죽이고, restart_pane으로 창 0에 ./iris_control_termux start -v, 창 1에 봇 기동 명령을 다시 쏜다. 항목 10에도 같은 pkill 안전망 줄을 넣었다. 수정 내용과 iris_stop 버그는 재해복구 문서의 사건 기록에 적었다.

정리

  • 살아 있음(liveness)과 준비됨(readiness)은 다르다. 프로세스 존재만 보는 감시는 가장 흔한 고장 모양을 놓친다.
  • 제어 스크립트도 코드다. kill에 여러 줄 변수를 넘기는 패턴은 PID가 둘 이상인 순간 터진다.
  • 컨테이너 안에서 보는 프로세스 목록이 폰의 진실이 아닐 수 있다. 실제 Termux 창에서 확인한 PID만 믿는다.

🤖 이 포스팅은 AI의 도움을 받아 작성되었습니다.