MongoDB Cursor Not Found - 1

Hoseok Ryu·2021년 6월 10일
0

Story

개발 주언어가 python이다 보니 pymongo를 이용하여 개발하고 있습니다. 모든 문서를 하나씩 보면서 개별적으로 massive한 작업을 진행하라와 같은 업무를 구현하였는데, 그렇게 어려운 일이 아니어서 쉽게 구현한 뒤에 편한 마음으로 퇴근했습니다. 컴퓨터가 일하면 저도 일하는 것이니까요. 😊 수행한 코드는 아래와 같습니다.

cursor = client.database.collection.find(Query)
for doc in cursor:
    massive_process_document(doc)

하지만 세상에 쉬운 게 어딨냐고 비웃는 듯 3%의 문서만 작업이 끝나고 프로그램이 죽어있었습니다.

Trouble Happening

프로그램이 남긴 다잉 메시지는 아래와 같았습니다.

pymongo.errors.CursorNotFound: cursor id '...' not valid at server.

막간을 이용해 용어를 정리해보면, 공식 문서에서 cursor란 A pointer to the result set of a query. 으로 표현됩니다. 즉, query의 결과가 batch로 존재하고, 이 위에서 이동하는 iterator인 것이죠. 그렇다면 CursorNotFound 에러는 cursor가 죽어서 더 이상 찾지 못한다는 것을 의미합니다.

이런 에러가 나면 저는 아직 뉴비 개발자이기 때문에 원인 파악보다는 일단 해결하려고 듭니다. 진정한 개발자는 원인부터 파악하겠죠..?🤣

Stopgap

임시 방편으로 떠올린 방법 2가지는 다음과 같습니다.

  • CursorNotFound 에러가 나기 전까지 처리된 문서의 개수 processedCount를 누적해놓은 다음에, cursor의 skip 기능(문서 링크)을 이용해서 이미 처리된 것들을 무시하며 모든 문서가 처리될 때까지 while문으로 반복해주기
  • NoSQL의 장점을 이용해서 처리된 document에 processedTimestamp를 추가해서 Query{processedTimestamp: {$lt: startTime}}을 추가하여 모든 문서가 처리될 때까지 while문으로 반복해주기

두 가지 방법 모두 가능한 방법인데 첫 번째의 경우는 문서의 순서가 보장되어야 하기 때문에 항상 sort가 전제되어 있어야 함을 주의해주세요. 저 같은 경우는 문서가 바뀌지 않는 한 같은 작업을 반복할 필요는 없기 때문에 바뀐 시점인 updateAt 과의 비교를 염두에 두어 2번째 방법을 사용해서 문제를 아래와 같이 해결했습니다.

done = False
while not done:
    cursor = client.database.collection.find(Query + {processedTimestamp: {$lt: startTime}})
    try:
        for doc in cursor:
            massive_process_document(doc)
        done = True
    except pymongo.errors.CursorNotFound:
        pass

Identifying the cause - Stage 1

문제점은 바로 pymongo 내부 구현 방식에 있었습니다.

If a session is idle for longer than 30 minutes, the MongoDB server marks that session as expired and may close it at any time.
When the MongoDB server closes the session, it also kills any in-progress operations and open cursors associated with the session.
This includes cursors configured with noCursorTimeout() or a maxTimeMS() greater than 30 minutes.

[출처: MongoDB 공식 문서]

cursor에는 유효 시간이 있었다는 것입니다. 가져다 쓸 거면 잘 알고 써라 라는 명언을 다시금 새기게 되었죠. cursor의 timeout을 제거해주거나 maxTimeMS 를 증가시켜주지 않으면 cursor가 아무런 일을 하지 않고 30분이 지난 뒤에 cursor는 자동 파기가 됩니다. 종종 작업이 오래 걸리게 되면서 이 유효 시간이 넘어가버리는 것입니다.

실제로 이걸로 해소가 되는 지 간단한 테스트 코드를 작성해보았습니다.

def run_one_hour(cursor):
    timestamp = datetime.now()
    cnt = 0
    try:
        for data in cursor:
            if cnt == 100:
                break
            while (datetime.now() - timestamp).seconds < 60 * 60:
                pass
            print("refreshing, cnt = ", cnt, " id = ", data['_id'])
            cnt += 1
            timestamp = datetime.now()
    except pymongo.errors.CursorNotFound:
        print("CursorNotFound Occur!!!")


cursor = client_readonly.database.collection.find({})
run_one_hour(cursor)
cursor = client_readonly.database.collection.find({}, no_cursor_timeout=True)
run_one_hour(cursor)

실험 결과는 예상과는 다소 달랐습니다. 제가 기대했던 결과는 첫번째 run_one_hour함수 호출은 cnt값이 1인 상태로 끝났어야 하는데, 무슨 이유에서인지 계속 진행되더군요. 5시간이 넘도록 잘 돌아가고 있었습니다. 분명 Idle 상태가 30분 지속되면 몽고디비 서버에서 cursor를 없앤다고 했는데..? 하지만 이제 와서 다시 읽어보니 "언제든지 없앨 수 있다" 라고 적혀있더군요. 이 때 깨달았습니다. 문제는 다른 곳에 있었다는 것을... 뉴비 개발자가 쉽게 하는 두 번째 실수까지 해버렸습니다. 너무 얕은 검색 수준이란 것을...

To be continue...

profile
Research Engineer

0개의 댓글