Стандартная библиотека Visual Studio 2015 и телеметрия12.04.2016 21:48

5b0c45508fb648f6b44f421b6647b5b2.png

Преамбула


Программы на C и C++, как правило, проводят бо́льшую часть своей жизни внутри функции main() и функций, прямо или косвенно вызываемых из main(). Тем не менее, на самом деле выполнение программы начинается вовсе не с main(), а с некоторого кода из стандартной библиотеки, поставляемой вместе с компилятором. Таковой код, по идее, должен подготавливать окружение для других функций стандартной библиотеки, которые, возможно, позовёт main(), а также параметры самой main() (под Windows; Unix-системы имеют тенденцию передавать argc/argv/envp в подготовленном виде прямо при запуске процесса, но речь не о них). Симметрично, завершающий return в функции main() — вовсе не последняя инструкция программы, после него следует ещё немного кода из стандартной библиотеки.
В Visual Studio «настоящая» точка входа в программу называется mainCRTStartup. В комплекте с VS идут исходники стандартной библиотеки, в VS2015 определение mainCRTStartup находится в %PROGRAMFILES(X86)%\VC\crt\src\vcruntime\exe_main.cpp, но, впрочем, всю работу выполняет exe_common.inl рядом. Давайте туда посмотрим.

...
        // If this module has any thread-local destructors, register the
        // callback function with the Unified CRT to run on exit.
        _tls_callback_type const * const tls_dtor_callback = __scrt_get_dyn_tls_dtor_callback();
        if (*tls_dtor_callback != nullptr && __scrt_is_nonwritable_in_current_image(tls_dtor_callback))
        {
            _register_thread_local_exe_atexit_callback(*tls_dtor_callback);
        }

        __telemetry_main_invoke_trigger(nullptr);

        //
        // Initialization is complete; invoke main...
        //

        int const main_result = invoke_main();

        //
        // main has returned; exit somehow...
        //

        __telemetry_main_return_trigger(nullptr);

        if (!__scrt_is_managed_app())
            exit(main_result);

        if (!has_cctor)
            _cexit();

        // Finally, we terminate the CRT:
        __scrt_uninitialize_crt(true, false);
        return main_result;
...


Идём глубже


Опытные параноики, несомненно, уже обратили внимание на вызовы __telemetry_main_invoke_trigger и __telemetry_main_return_trigger. Попробуем найти их исходники…, а фигушки. При попытке зайти внутрь этих функций отладчик VS сообщает «telemetry.cpp не найден» (значит, файл с исходниками, который MS «забыла» включить в поставку, называется telemetry.cpp. Логично) и предлагает либо указать путь вручную, либо перейти к дизассемблированному коду.
Внимательный поиск других функций из telemetry.cpp находит ещё пару функций __vcrt_initialize_telemetry_provider и __vcrt_uninitialize_telemetry_provider, вызываемых в ходе, соответственно, инициализации и завершения.

Конечно, непредоставление исходников ещё не означает невозможности заглянуть внутрь. Разглядывание дизассемблированного кода приводит к переменной _Microsoft_CRTProvider типа const __vcrt_trace_logging_provider::_TlgProvider_t* const, а тип _TlgProvider_t уже не секретный и легко находится в SDK: %PROGRAMFILES(X86)%\Windows Kits\10\Include\10.0.10586.0\shared\TraceLoggingProvider.h…, а вот и документация. (В документации написано «Windows 10», что, впрочем, совершенно не мешает коду работать под Windows 7.) Так, хорошо, а куда оно пишет все эти логи?

TraceLogging events are sent to ETW as described in this section.

То есть это очередная инкарнация подсистемы Event Tracing for Windows. Ага.
Краткая справка для тех, кто впервые слышит аббревиатуру ETW: это инфраструктура для унифицированной обработки всевозможных логов и счётчиков, появившаяся ещё в Windows 2000 и получившая серьёзную прибавку в Vista. Желающие могут набрать в командной строке logman query providers для оценки масштаба.

Смотрим логи


Возьмём какую-нибудь простенькую программу, например: 

#include 
int main()
{
        printf("Hello, World!\n");
        return 0;
}


Результат компиляции командой cl /Os hello.c: yadi.sk/d/pa0S5qVoqw9Q4
Итак, в скомпилированном exe-шнике должна быть запись каких-то логов перед и после вызова main(). Подсистема ETW просто отбрасывает всё, для чего не было команды на ведение логов. Давайте включим логи: именем администратора, 

logman create trace test_crt_telemetry -p {5EEC90AB-C022-44B2-A5DD-FD716A222A15} -o C:\temp\test_telemetry
logman start test_crt_telemetry


(logman и нужная далее tracerpt — стандартные утилиты из поставки Windows). Откуда я взял {5EEC90AB-C022–44B2-A5DD-FD716A222A15}? Отладчик VS показал при просмотре уже упоминавшейся переменной _Microsoft_CRTProvider.
Запускаем hello.exe, видим классическое приветствие. Сбрасываем логи в файл, 

logman stop test_crt_telemetry


и смотрим, что туда записалось: 

tracerpt -summary summary.txt -o dumpfile.xml C:\temp\test_telemetry_000001.etl



        
                
                17
                0
                5
                0
                0
                0x200000000000
                
                
                
                
                
        
        
                Main Invoked.
                C:\temp\hello.exe
        
        
                InvokeMainViaCRT
        


        
                
                77
                0
                5
                0
                0
                0x200000000000
                
                
                
                
                
        
        
                Main Returned.
                C:\temp\hello.exe
        
        
                ExitMainViaCRT


Да, логи есть. Данных, впрочем, не особенно много: помимо собственно сообщения о вызове/возврате main() и стандартных заголовков ETW, пишется только имя exe-шника.

Кстати, а если оставить запись логов включённой и поработать? Можно поймать, например, 


        
                Main Invoked.
                C:\Program Files\Python 3.5\python35.dll
        
        
                Main Invoked.
                C:\Program Files\Python 3.5\python.exe
        
        
                Main Returned.
                C:\Program Files\Python 3.5\python.exe
        
        
                Main Returned.
                C:\Program Files\Python 3.5\python35.dll


Python идёт в ногу с прогрессом! Пардон, Python 3 идёт в ногу с прогрессом!

Don’t panic


Что мы имеем в итоге?

  • В любом бинарнике, скомпилированном VS2015 из программы на C или C++, есть код, который может писать логи. (зануда-mode: если не предпринимать специальных усилий по отключению стандартной библиотеки. Впрочем, если на Си ещё можно писать без неё, то на C++ — только до первого исключения)
  • Логи куцые, там нет ничего особенно интересного, что система и без того бы не знала. Можно различить случаи »main() штатно вернула управление» и «кто-то вызвал exit или abort», но это скорее интересно разработчику для отладки. Параноики могут расслабиться.
  • Но сам прецедент интересный.
  • По умолчанию логи никуда не пишутся. Их нужно включать специально. Однако, команда включения может вообще ничего не знать ни о программе, ни о предметной области (ни logman, ни tracerpt не в курсе о конкретном Microsoft.CRTProvider — вся структура логов выше пишется вместе с логами).
  • Проверить, включены ли логи, можно следующим кодом: 
    #include 
#include 

static void NTAPI EnableCallback(LPCGUID, ULONG isEnabled, UCHAR, ULONGLONG, ULONGLONG, PEVENT_FILTER_DESCRIPTOR, PVOID context)
{
        *(bool*)context = (bool)isEnabled;
}

int main()
{
        static const GUID providerId = { 0x5eec90ab, 0xc022, 0x44b2, 0xa5, 0xdd, 0xfd, 0x71, 0x6a, 0x22, 0x2a, 0x15 };
        REGHANDLE hProvider;
        bool enabled = false;
        EventRegister(&providerId, &EnableCallback, &enabled, &hProvider);
        EventUnregister(hProvider);
        printf("Microsoft.CRTProvider logging is %s\n", enabled ? "on" : "off");
        return 0;
}
    (под XP работать не будет в силу отсутствия необходимых API. Впрочем, по ровно той же причине логгинг под XP всегда отключён. exe-шник для ленивых: yadi.sk/d/pvQkFUqKqwJSV)
  • Такие логи логичнее всего было бы использовать как вспомогательное средство отладки. Но сам по себе запуск под отладчиком не включает логи. Конечно, не исключено, что какой-нибудь флажок в настройках включает функциональность, которой нужны логи… или логи нужны для какой-нибудь хитрой отладочной утилиты…, но тогда непонятно, почему код остаётся при компиляции с релизной библиотекой.

© Habrahabr.ru