Задача багтреккера структурировать информацию о наличествующих на сейчас проблемах, чтобы мне как разработчику было удобнее выбирать самые мешающие/самые воспроизводимые и конечно самые распространенные. Тем кто готов помогать в сортировке информации, следует научиться отделять одни баги от других. В самых простых случаях, баг бывает очевидным и не требует глубоко копать, например вылет при диалоге/торговле с каким-то конкретным неписем. Аналогично, можно группировать баги по любому общему признаку, если у нескольких тестеров совпадают условия его воспроизведения. Таким общим признаком может быть выполнение одинакового квеста, нахождение примерно в одинаковой точке на одной локации и т.п.
Для тех случаев, когда нужно копать глубже, придется научиться худо-бедно читать логи. А в случае моей версии движка, это означает что необходимо будет ориентироваться в системе тегов, и стеках вызова (как непосредственно движка, так и скриптов).
По поводу системы тегов, думаю ничего сложного - все похоже на твиттер, и львиная доля сообщений в логах начинается с тегов. Искать следует такие теги:
#EXCEPTION: исключение, или попросту аварийная ситуация в коде, при которой был вызван обработчик аварии.
#ERROR: ошибка - предполагает проблему, которая может быть разной степени серьёзности, и как правило сопровождается писком (звоном).
#LUA_ERROR: ошибка в скриптах, соответственно может встречаться как из-за обычных опечаток, так и в случае неявно сбойного кода.
Остальные теги:
#DBG: отладочная информация, чаще всего вывод каких-либо переменных или событий
#PERF_WARN: относится к предупреждению о низкой производительности
#PERF: просто выводиться какая-то статистика производительности
#WARN: предупреждение о чем-то не очень желательном, но вероятном и для здорового сценария работы игры.
Сложность разбора современных логов в том, что в отличии от оригинала (1.0006) игра не делает попыток моментально крэшнуться, и некоторое время работает после сбоя, выводя сообщения об вторичных и прочих сбоях. По аналогии с самолетом, первым сигналом является нечто вроде "крылья отвалились", а потом идут уже сбои в зависимом коде, вплоть до того момента когда не встретиться не возобновляемое исключение, или счетчик сбоев не получит переполнения. Так что конечно, очень важно находить в логе момент когда началась авария, т.к. самые последние сбои чаще всего вообще ни к чему конкретному не относятся. Это делать гораздо проще, если тестер при начале неадекватного поведения игры засек точное время (до секунд), поскольку как правило эксепшены вместе с дампом стеков вызовов заметно фризят игру.
Чем отличается нативный стек вызовов, от скриптового? Он касается проблем случившихся в недрах движка, т.е. в двоичном коде как правило или xrGame.dll или xr_3da.exe. К таким сбоям почти всегда относятся фаталы, ошибки доступа к памяти. Вот характерный пример:
[15:14:38.028/+01:15.520/ 28.0]. #XRAY: #EXCEPTION_INFO: 'Ошибка доступа записи памяти по адресу 0x0000000c ' at '0x1B66F320', flags = 0x0000 [15:14:38.028/+01:15.520/0.047]. #XRAY: ExceptionInformation[0] = 0x00000000 [15:14:38.028/+01:15.520/0.033]. #XRAY: ExceptionInformation[1] = 0x0000000C [15:14:38.028/+01:15.520/0.031]. #XRAY: #DEBUG_STACK/CONTEXT: [15:14:38.028/+01:15.520/0.029]. #XRAY: for thread 5424: [15:14:38.028/+01:15.520/0.029]. #XRAY: for thread 13348: [15:14:38.028/+01:15.520/0.037]. #XRAY: 1. unknown @ 0x287A15E8 [15:14:38.028/+01:15.520/0.122]. #XRAY: 0. ILT+17420(?rp_FrameYIXPAXZ) [15:14:38.072/+01:15.564/ 44.2]. #XRAY: ** break by StackWalk *** [15:14:38.073/+01:15.565/0.088]. #XRAY: Exception stack trace 27 lines, EIP = 0x1b66f320, ESP = 0x001824b8: [15:14:38.073/+01:15.565/0.045]. #XRAY: 0 0023:1B66F320 (0x001837F4 0x5F726162 0x676C6F64 0x6E75625F) xr_3da.EXE [15:14:38.073/+01:15.565/0.043]. #XRAY: 1 0023:1B67A8D2 (0x00000000 0x676C6F00 0x6E75625F 0x5F72656B) xr_3da.EXE [15:14:38.073/+01:15.565/0.048]. #XRAY: 2 0023:00A2DA24 (0x676C6F00 0x6E75625F 0x5F72656B 0x74736572) xrCore.dll, std::_Tree_buy<str_value *,xalloc<str_value *> >::_Buynode<str_value * const &>(), c:\msvs12\vc\include\xtree, 933 [15:14:38.073/+01:15.565/0.054]. #XRAY: 3 0023:00A2DAE5 (0x12312FC2 0x00000023 0x00A2E144 0x30730550) xrCore.dll, std::_Tree<std::_Tset_traits<str_value *,str_value_cmp,xalloc<str_value *>,1> >::_Insert_at<str_value * const &,std::_Nil>(), c:\msvs12\vc\include\xtree, 1844 [15:14:38.073/+01:15.565/0.050]. #XRAY: 4 0023:00A3718B (0x00182898 0x00182EEC 0x00000000 0x009D6727) xrCore.dll, xrCriticalSection::Leave(), x:\trunk\xray\xrcore\xrsyncronize.cpp, 80 [15:14:38.073/+01:15.565/0.046]. #XRAY: 5 0023:009E173D (0x0000000A 0x4B70445A 0x2EC459EA 0x00182914) xrCore.dll, CPU::QPC(), x:\trunk\xray\xrcore\_math.cpp, 147 [15:14:38.073/+01:15.565/0.048]. #XRAY: 6 0023:0051CE19 (0x00183040 0x7D86C861 0x00000000 0x27F3F7E0) xr_3da.EXE, FHierrarhyVisual::Load(), x:\trunk\xray\xr_3da\fhierrarhyvisual.cpp, 90 [15:14:38.073/+01:15.565/0.045]. #XRAY: 7 0023:7D86C807 (0x000006AC 0x00183094 0x49FC4C38 0x7DE8FAC2) KERNELBASE.dll, CreateFileW() [15:14:38.073/+01:15.565/0.041]. #XRAY: 8 0023:7DE9E193 (0x000006AC 0x00183090 0x7DE8FD02 0x7D85ECC3) ntdll.dll, RtlFreeHeap() [15:14:38.073/+01:15.565/0.042]. #XRAY: 9 0023:7D85CF72 (0x000006B0 0xFFFFFFFF 0x001830B8 0x00000000) KERNELBASE.dll, GetFileSizeEx() [15:14:38.073/+01:15.565/0.041]. #XRAY: 10 0023:7D85ECC3 (0x000006B0 0x00000004 0x00013000 0x07B40000) KERNELBASE.dll, MapViewOfFile() [15:14:38.073/+01:15.565/0.045]. #XRAY: 11 0023:009EC978 (0x000007EA 0x27F3F7E0 0x12312FE2 0x0000004B) xrCore.dll, CVirtualFileReader::CVirtualFileReader(), x:\trunk\xray\xrcore\fs.cpp, 727 [15:14:38.073/+01:15.565/0.043]. #XRAY: 12 0023:12EC02D4 (0x00000088 0x4B6A2C2A 0x00000000 0x3A07EA10) xr_3da.EXE [15:14:38.073/+01:15.565/0.043]. #XRAY: 13 0023:00A2E144 (0x27EC0000 0x00000004 0x3D68B1E0 0x00183258) xrCore.dll, str_container::dock(), x:\trunk\xray\xrcore\xrstring.cpp, 68 [15:14:38.073/+01:15.565/0.045]. #XRAY: 14 0023:7DD714BD (0x3E567C58 0x34D40798 0x00183310 0x000000F2) kernel32.dll, HeapFree() [15:14:38.073/+01:15.565/0.043]. #XRAY: 15 0023:7DEA349D (0x3E803288 0x3E7FE850 0x0018342C 0x7DEA34E7) ntdll.dll, RtlQueryPerformanceCounter() [15:14:38.073/+01:15.565/0.043]. #XRAY: 16 0023:7DEA349D (0x7DEA3516 0x63D25363 0x00000002 0x00000000) ntdll.dll, RtlQueryPerformanceCounter() [15:14:38.073/+01:15.565/0.043]. #XRAY: 17 0023:7DEA34E7 (0x49FC4D88 0x00000000 0x00000000 0x4B652E5C) ntdll.dll, RtlQueryPerformanceCounter() [15:14:38.073/+01:15.565/0.042]. #XRAY: 18 0023:02DFFE2B (0x0018348C 0x02DFFDD8 0x0000002E 0x03C2A0DE) luaicp.dll, DllCanUnloadNow() [15:14:38.073/+01:15.565/0.043]. #XRAY: 19 0023:02DFFDCB (0x00000001 0x02B412BC 0x4B4EF020 0x02DFF42C) luaicp.dll, DllCanUnloadNow() [15:14:38.073/+01:15.565/0.043]. #XRAY: 20 0023:02DFFE2B (0x49FC4D88 0x27F3F7E0 0x4B4EEFC4 0x02DFF424) luaicp.dll, DllCanUnloadNow() [15:14:38.074/+01:15.566/0.044]. #XRAY: 21 0023:02DFFE2B (0x00000000 0x000000D0 0x4B4EEFB0 0x03C2A0DE) luaicp.dll, DllCanUnloadNow() [15:14:38.074/+01:15.566/0.044]. #XRAY: 22 0023:02DFF424 (0x00183504 0x00183548 0x00183548 0x02DFF402) luaicp.dll, DllCanUnloadNow() [15:14:38.074/+01:15.566/0.042]. #XRAY: 23 0023:02DFF385 (0x0018357C 0x001835C0 0x001835C0 0x02DFF402) luaicp.dll, DllCanUnloadNow() [15:14:38.074/+01:15.566/0.044]. #XRAY: 24 0023:02DFF385 (0x007A6404 0x00000001 0x00183624 0x02DFF424) luaicp.dll, DllCanUnloadNow() [15:14:38.074/+01:15.566/0.045]. #XRAY: 25 0023:02DFF402 (0x39B8B730 0x00000000 0x00000028 0x27F3F858) luaicp.dll, DllCanUnloadNow()
Как можно убедиться, стек вызовов имеет явную нумерацию, и нулевая строка приходиться непосредственно на место ошибки. В данном случае отладочное API даже не смогло привязать к этому коду исходные файлы. Первое описание об исходном коде движка встречается на строке 4, что видно по укаанию пути к файлам x:\trunk\xray\xrcore\xrsyncronize.cpp, строка 80. К сожалению многие стеки вызовов не содержат конкретной информации, так-же как это было во времена оригиналки ТЧ.