[이브 온라인] 잠자는 숲속의 공주 - 이브의 가장 오래된 버그를 어떻게 추적하여 해결하였는가

SLEEPING BEAUTY - HOW ONE OF THE OLDEST BUGS IN EVE GOT HUNTED DOWN AND RESOLVED

https://community.eveonline.com/news/dev-blogs/sleeping-beauty

때로는 버그에 대한 이야기가 무척 흥미로워, EVE Online에서 공돌이적 마인드를 갖거나 개발의 현실에 대해 궁금한 사람을 위해 쓰지 않을 수 없도록 합니다. 여기 게임에서 가장 오래된 결함 중 하나가 추적되고 해결된 방법에 대해 자세히 설명해 드릴테니, EVE Online 코드의 기술적 깊이에 대해 심도 깊은 시간을 함께 보내봅시다.

우리는 항상 EVE Online과 코드 베이스를 개선하기 위해 노력하고 있으며, 여러분에게 이 작품이 어떻게 보이는지의 여정을 함께 즐기기를 바랍니다.

이 모든 것이 어떻게 시작되었는가

얼마전 CCP karkur는 나에게, 드론들을 리콜했을 때 드론 윈도우가 가끔 갱신을 멈추는 문제를 해결할 수 있도록 도울 수 있는지 물었습니다. 그녀의 조사는 드론이나 UI와 관련한 코드의 문제를 발견하지 못했습니다. 몇시간 동안 그녀는 드론 버그를 3번이나 재현하여 문제가 있는 곳의 로깅을 추가했습니다. 마지막 재현 이후, 코드의 어딘가에 문제가 있다는 것이 명백해졌습니다. 드론창은 단순히 갱신을 시작하고 잠깐 자러가는 것처럼 보이지만, 다시는 깨어나지 않았습니다. Tasklet이 깨어나야 함에도 불구하고 그들의 잠에서 돌아오지 않는 것이었습니다.

최초의 버그는 재현하기가 매우 어려웠지만, CCP karkur는 영원히 끝나지 않는 Tasklet을 추적하기 위한 추적과 함께 특정 시간 동안 잠자기 상태로 유지되는 500,000개의 Tasklet을 생성하는 스크립트를 작성했습니다(역주: Tasklet이 끝나지 않아 문제가 발생하므로, 어디서 끝나지 않는 문제가 발생하는지 파악하기 위해 Tasklet 50만개를 만들어 돌려버림). 이 스크립트를 통해 우리는 이 수면 장애를 다소 신뢰성 있게 재현할 수 있었습니다. 이 스크립트는 깨어나지 않는 Tasklet을 확인했으며, 검사를 통해 Tasklet이 예정되거나 차단되지 않았음을 분명히 했습니다. 이는 일종의 림보(limbo)였습니다(역주: 림보란 서양쪽의 지옥의 일종).

CCP karkur의 스크립트로 버그를 재현하려는 나의 첫번째 시도는 성공하지 못했습니다. 저는 클라이언트 없이 Jessica (제작 / 디버깅 도구)에서 실행 중이었고 아무런 행운이 없었습니다. 나중에 나는 더 나은 행운으로 클라이언트에서 시도했습니다. 그래서 단순히 많은 Tasklet을 돌리는 것보다 뭔가가 더 있다고 생각되었습니다. 나는 이론을 생각해 내기 위해 관련 C ++ 코드를 읽기 시작했습니다.

배경에 관한 지식

Tasklet (자세한 정보는 Stackless Python 참고)은 PyStackless_RunWatchdogEx를 호출하여 PyScheduler :: Run에서 실행됩니다. 이 메서드는 지정된 시간이 경과할 때까지 시간 제한 값을 가져 와서 예약된 작업 표시를 실행합니다. Tasklet이 생성되면 스케줄링되고 PyScheduler :: Run이 호출될 때 실행됩니다. Tasklet이 대기 상태가되면 Synchro :: SleepWallclock이 호출되며, 이는 채널을 생성하고 채널에서 receive를 호출하여 구현됩니다. 이후 어떤 사람이 그 채널에서 뭔가를 보낼 때까지 채널을 차단합니다. Synchro는 슬리퍼의 힙을 유지합니다. 슬리퍼는 셧다운이 일어나야하는 정해진 시간과 채널을 보유하는 간단한 개체입니다. Synchro :: Tick은 힙 상단에서 슬리퍼를 당겨 채널에 값을 보냅니다. 이것은 차례대로 Tasklet을 차단 해제하고 스케줄을 계획합니다.

첫번째 아이디어는 힙 코드에 버그가 있을 수 있다는 것입니다. 그것은 우리 자신의 코드입니다. 오래된 것이고 단위 테스트를 거친 적이 없습니다. 나는 그것에 대한 몇가지 테스트를 작성하거나 적절한 교체를 찾는 것을 고려했지만, 그 증상이 그 힙에서 결코 끌어올려지지 않는 태스크 릿과 일치하지 않는다는 것을 깨달았습니다. 그 케이스라면 Tasklet은 단순히 영원히 차단될 것입니다. 하지만 이 코드에 대한 테스트를 추가하는 것은 여전히 해야 할 일이긴 합니다.

내 다음 아이디어는 PyStackless_RunWatchdogEx의 문서를 살펴 본 것입니다. 이것은 죽거나 재스케줄되어야 하는 Tasklet을 반환 할 수 있습니다. 이는 막 다른 길로 드러났습니다 - 이것은 선제 공격 모드에서 실행될 때만 적용되며 이 경우 Tasklet은 인터럽트될 수 있습니다(역주: Tasklet이 잠에서 깨어나야 하는데 이건 잠에서 깨우는게 아니라 죽여버림).

코드 내놔

나는 Tasklet을 죽이는 것이 이것의 한 요인일지도 모르는 직감을 가지고 있었지만, 그 주위의 코드에는 아무런 문제가 보이지 않았다. 그럼에도 불구하고 채널의 참조 횟수가 정확하다는 것을 확신 할 수 없으므로 코드를 약간 정리하기로 결정했습니다. 그것이 어땠는지는 어색해 보였습니다.

PyObject* Synchro::SleepWallclock(int ms, const int64_t &due)

{

    Sleeper sl;

    sl.channel = PyChannel_New(NULL);

    if (!sl.channel)

        return 0;

    PyChannel_SetPreference(sl.channel, 0); //just make runnable on wakeup

    sl.due = due;

 

    mWallclockSleepers.Insert(sl);

     

    // Go to sleep and wake up! *(the sender releases the channel)

    PyObject *ret = PyChannel_Receive(sl.channel);

 

    if (!ret) {

        //we were killed, so lets try and find us in the queue, to release resources.

        RemoveSleeper( mWallclockSleepers, sl );

    }

    return ret;

}

SleepWallclock 함수는 채널을 만들어 Sleeper 객체에 저장하고 Sleeper 객체를 힙에 넣은 다음 채널에서 수신을 호출합니다. Synchro :: Tick이 채널에서 보내기를 호출한 후 수신 호출이 반환됩니다. 그러면 스케줄이 잡히지 않습니다. Tasklet은 또한 kill 될 수 있으며,이 경우 receive는 nullptr을 반환합니다. Synchro :: Tick의 자투리 코드를 살펴 보겠습니다.

//gather sleepers for wakeup

std::vector sleepers;

while (mWallclockSleepers.size()) {

    if (mWallclockSleepers.front().due > now)

        break;

    sleepers.push_back(mWallclockSleepers.Shift());

}

if (sleepers.size()) {

    Be::Time nnow = BeOS->GetActualTime();

    for(unsigned int i = 0; i < sleepers.size(); i++) {

        Sleeper &s = sleepers[i];

        if (PyChannel_GetBalance(s.channel)) {

            int res = PyChannel_Send(s.channel, Py_None);

            if (res)

                PyOS->PyError();

        }

        Py_DECREF(s.channel);

    }

}

이것은 모두 올바른 것처럼 보입니다 - 채널은 보내기 호출 이후까지 Tasklet에서 빼낼 수 없었습니다. tasklet이 죽으면 어떻게 될까요?

void Synchro::RemoveSleeper( Heap &sleepers, Sleeper &sl )

{

    SleeperIt it;

    for( it = sleepers.begin(); it != sleepers.end(); ++it )

    {

        if( it->channel == sl.channel )

        {

            break;

        }

    }

 

    if( it != sleepers.end() )

    {

        //Ok found us.  Let's delete us.

        sleepers.Remove( it );

        Py_DECREF( sl.channel );

    }

}

다시 말하지만, 모든 것은 괜찮아 보입니다. Tasklet이 힙에서 제거되고 채널이 해제됩니다. 힙에서 Tasklet을 찾을 수 없다면 오류가 아니며, 깨어나고 죽을 때와 동일한 틱에서 스케줄 될 수 있지만 이 경우 채널은 틱으로 해제됩니다.

그래도 좀 더 자세히 살펴보겠습니다. 참조 카운트가 0이 되면 Py_DECREF가 메모리를 해제한다는 것을 명심하십시오. SleepWallclock의 PyChannel_New 호출은 참조 카운트가 1인 PyChannelObject를 반환합니다. 추가된 참조가 없으므로 Py_DECREF를 호출할 때 채널 객체는 Tick에서 삭제됩니다. 수신 호출 후 SleepWallclock의 채널에 대한 참조가 없으므로 이 값은 정상입니다. 다만...

Tasklet이 종료된 후에 호출되는 RemoveSleeper에서 채널 객체를 비교합니다. Tasklet과 채널과는 일대일 대응이 있어야 하므로 여기서 효과적으로 Tasklet을 찾고 있지만 채널을 추적하여 채널을 깨워야 하기 때문에 채널을 사용하기만 하면 됩니다. Sleeper 오브젝트의 Tasklet에 대한 참조를 추가하여 여기에서 확인할 수 있었고, CCP karkur에서 스크립트를 실행할 때 불일치가 생겼습니다. Tasklet은 채널을 기반으로 힙에 있다고 결정되었으므로, Tasklet이 일치하지 않습니다.

유레카의 순간

채널 객체를 삭제하면 메모리가 비어 있어 재사용할 수 있습니다. 이것은 Tasklet이 죽는 순간과 잠에서 깨어나려는 Tasklet이 정확히 같은 Tick에 작업을 수행할 경우, 깨어나는 Tasklet이 죽는 Tasklet과 동일한 채널 포인터를 얻을 수 있다는 것을 의미합니다. 그 경우 RemoveSleeper는 힙에서 잘못된 Tasklet (SleepWallclock을 방금 호출한 Tasklet)을 제거하고 채널을 종료하여 예약되지 않은 비차단 상태로 둡니다.

고치는 건 간단합니다. Py_DECREF 호출을 SleepWallclock으로 옮깁니다. 이렇게 하면 채널 객체가 조기에 재활용되지 않으며 실제로는 참조 계산이 하나의 함수로 지역화된 상태로 유지된다는 것이 제 의견으로는 분명합니다.

당연한 건 없다

EVE Online은 현재 거의 14년이 되었으며, 평생 동안 많은 전투를 겪었고, 코드 베이스가 철저히 전투 테스트를 통과했다고 말할 수 있습니다. 그렇다고 해서 그것이 비열한 버그가 숨어있지 않다는 것은 아니며 근본적인 기능에서 버그를 발견하는 것은 놀라운 일이 아닙니다. 나는 우리 코드베이스의 어떤 부분도 절대적으로 100% 정확하다고 절대 추측할 수 없다고 생각합니다. CCP karkur 및 다른 사람들은 이 문제를 추적하는 데 상당한 시간을 투자하여 높은 수준의 코드에 대한 높은 확신을 얻었습니다. 이것은 내가 이 드문 사례를 발견할 때까지 이 조사에 들어갈 수있게 해주었습니다.

우리는 몇가지 다른 버그가 동일한 근본적인 문제의 증상이라고 믿을 만한 이유가 있습니다. 예를 들어 오버뷰가 업데이트되지 않거나 실드, 아머 및 스트럭처 바가 업데이트 되지 않는 일 등입니다. 이러한 버그는 항상 재현하는 것이 거의 불가능하지만 가끔씩 보고됩니다. 특히 대규모 테스트 또는 트랭퀼리티에서 큰 싸움이 일어난 경우에 그렇습니다.