Visual Studio 2015 Standard Library and Telemetry

Preamble

C and C ++ programs typically spend most of their life inside the main() function and functions that are directly or indirectly called from main() . However, in fact, the program starts not with main() , but with some code from the standard library that comes with the compiler. This code, in theory, should prepare the environment for other functions of the standard library, which may be called main() , as well as the main() parameters (under Windows; Unix systems tend to send argc/argv/envp in a prepared form directly when you start the process, but it's not about them). Symmetrically, the final return in main() is not the last instruction of the program, after it follows some more code from the standard library.
In Visual Studio, the “real” entry point to the program is called mainCRTStartup . Included with VS are the sources of the standard library, in VS2015 the definition of mainCRTStartup is in %PROGRAMFILES(X86)%\VC\crt\src\vcruntime\exe_main.cpp , but, by the way, all the work is done by exe_common.inl . Let's see there.

 ... // 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; ... 

Go deeper

Experienced paranoids, no doubt, have already paid attention to the challenges of __telemetry_main_invoke_trigger and __telemetry_main_return_trigger . Let's try to find their source ... and figs. When you try to go inside these functions, the VS debugger reports “telemetry.cpp is not found” (which means that the source file that MS “forgot” to include in the delivery is called telemetry.cpp. Logical) and offers to either specify the path manually or go to disassembled code.
A careful search for other functions from telemetry.cpp finds a couple more functions __vcrt_initialize_telemetry_provider and __vcrt_uninitialize_telemetry_provider , called during, respectively, initialization and completion.

Of course, the failure to provide the source does not mean that it is impossible to look inside. Looking at disassembly leads to variable _Microsoft_CRTProvider type const __vcrt_trace_logging_provider::_TlgProvider_t* const , and type _TlgProvider_t is no longer a secret, and can easily be found in the SDK: %PROGRAMFILES(X86)%\Windows Kits\10\Include\10.0.10586.0\shared\TraceLoggingProvider.h . %PROGRAMFILES(X86)%\Windows Kits\10\Include\10.0.10586.0\shared\TraceLoggingProvider.h ... and here is the documentation . (The documentation says "Windows 10", which, however, does not prevent the code from working under Windows 7.) So, well, where does it write all these logs?

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

That is, this is another incarnation of the Event Tracing for Windows subsystem. Yeah.
Brief information for those who first hear the abbreviation ETW: this is the infrastructure for the unified processing of various logs and counters, which appeared in Windows 2000 and received a serious increase in Vista. Those interested can type in the command line logman query providers to assess the scale.
')

Look logs

Take some simple program, for example:

 #include <stdio.h> int main() { printf("Hello, World!\n"); return 0; } 

Result of compiling with cl /Os hello.c : yadi.sk/d/pa0S5qVoqw9Q4
So, in the compiled exe file there should be a record of some kind of logs before and after the main() call. The ETW subsystem simply discards everything for which there was no command for logging. Let's turn on the logs: admin name,

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

( logman and the tracerpt needed later are standard utilities from the Windows tracerpt ). Where did I get the {5EEC90AB-C022-44B2-A5DD-FD716A222A15}? The VS debugger showed when viewing the _Microsoft_CRTProvider variable already mentioned.
Run hello.exe, see the classic greeting. We dump logs in the file,

 logman stop test_crt_telemetry 

and see what is written there:

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

 <Events> <Event xmlns="http://schemas.microsoft.com/win/2004/08/events/event"> <System> <Provider Name="Microsoft.CRTProvider" Guid="{5eec90ab-c022-44b2-a5dd-fd716a222a15}" /> <EventID>17</EventID> <Version>0</Version> <Level>5</Level> <Task>0</Task> <Opcode>0</Opcode> <Keywords>0x200000000000</Keywords> <TimeCreated SystemTime="2016-04-11T00:57:29.437589800Z" /> <Correlation ActivityID="{00000000-0000-0000-0000-000000000000}" /> <Execution ProcessID="7656" ThreadID="5796" ProcessorID="0" KernelTime="0" UserTime="0" /> <Channel /> <Computer /> </System> <EventData> <Data Name="&quot;Main Invoked.&quot;">Main Invoked.</Data> <Data Name="FileName">C:\temp\hello.exe</Data> </EventData> <RenderingInfo Culture="ru-RU"> <Task>InvokeMainViaCRT</Task> </RenderingInfo> </Event> <Event xmlns="http://schemas.microsoft.com/win/2004/08/events/event"> <System> <Provider Name="Microsoft.CRTProvider" Guid="{5eec90ab-c022-44b2-a5dd-fd716a222a15}" /> <EventID>77</EventID> <Version>0</Version> <Level>5</Level> <Task>0</Task> <Opcode>0</Opcode> <Keywords>0x200000000000</Keywords> <TimeCreated SystemTime="2016-04-11T00:57:29.437734300Z" /> <Correlation ActivityID="{00000000-0000-0000-0000-000000000000}" /> <Execution ProcessID="7656" ThreadID="5796" ProcessorID="0" KernelTime="0" UserTime="0" /> <Channel /> <Computer /> </System> <EventData> <Data Name="&quot;Main Returned.&quot;">Main Returned.</Data> <Data Name="FileName">C:\temp\hello.exe</Data> </EventData> <RenderingInfo Culture="ru-RU"> <Task>ExitMainViaCRT</Task> </RenderingInfo> </Event> 

Yes, there are logs. There is, however, not much data: in addition to the main() call / return message itself and the standard ETW headers, only the name of the executable is written.

By the way, and if you leave a log of logging included and work? Can catch for example

 <EventData> <Data Name="&quot;Main Invoked.&quot;">Main Invoked.</Data> <Data Name="FileName">C:\Program Files\Python 3.5\python35.dll</Data> </EventData> <EventData> <Data Name="&quot;Main Invoked.&quot;">Main Invoked.</Data> <Data Name="FileName">C:\Program Files\Python 3.5\python.exe</Data> </EventData> <EventData> <Data Name="&quot;Main Returned.&quot;">Main Returned.</Data> <Data Name="FileName">C:\Program Files\Python 3.5\python.exe</Data> </EventData> <EventData> <Data Name="&quot;Main Returned.&quot;">Main Returned.</Data> <Data Name="FileName">C:\Program Files\Python 3.5\python35.dll</Data> </EventData> 

Python keeps up with progress! Sorry, Python 3 keeps up with progress!

Don't panic

What do we have in the end?

• In any binaries compiled by VS2015 from a C or C ++ program, there is code that can write logs. (bore-mode: if you do not make special efforts to disable the standard library. However, if you can still write in C without it, then in C ++ you can only write to the first exception)
• Logs are scanty, there is nothing particularly interesting there that the system would not know without it. It is possible to distinguish cases of " main() normally returned control" and "someone caused an exit or abort " but it is rather interesting for the developer to debug. Paranoids can relax.
• But the precedent itself is interesting.
• By default, the logs are not written anywhere. They need to be included specifically. However, the inclusion command may not know anything at all about the program or the subject area (neither logman nor tracerpt is aware of a specific Microsoft.CRTProvider - the entire structure of the logs is written above together with the logs).
• You can check if the logs are enabled with the following code:
  

   #include <Windows.h> #include <evntprov.h> static void NTAPI EnableCallback(LPCGUID, ULONG isEnabled, UCHAR, ULONGLONG, ULONGLONG, PEVENT_FILTER_DESCRIPTOR, PVOID context) { *(bool*)context = (bool)isEnabled; } typedef ULONG (WINAPI *EventSetInformation_t)(REGHANDLE, EVENT_INFO_CLASS, PVOID, ULONG); #pragma pack(push, 1) static struct { unsigned short TotalSize; char ProviderName[22]; unsigned short Chunk1Size; unsigned char Chunk1Type; GUID GroupGuid; } _Microsoft_CRTProvider_traits = { 0x2B, "Microsoft.CRTProvider", 0x13, 1, { 0x4F50731A, 0x89CF, 0x4782, 0xB3, 0xE0, 0xDC, 0xE8, 0xC9, 0x04, 0x76, 0xBA }, }; static_assert(sizeof(_Microsoft_CRTProvider_traits) == 0x2B, "invalid size"); #pragma pack(pop) int main() { static const GUID providerId = { 0x5eec90ab, 0xc022, 0x44b2, 0xa5, 0xdd, 0xfd, 0x71, 0x6a, 0x22, 0x2a, 0x15 }; REGHANDLE hProvider; bool enabled = false; ULONG status = EventRegister(&providerId, &EnableCallback, &enabled, &hProvider); if (status == ERROR_SUCCESS) { EventSetInformation_t EventSetInformation = (EventSetInformation_t)GetProcAddress(GetModuleHandleA("advapi32.dll"), "EventSetInformation"); if (EventSetInformation) EventSetInformation(hProvider, EventProviderSetTraits, &_Microsoft_CRTProvider_traits, sizeof(_Microsoft_CRTProvider_traits)); EventUnregister(hProvider); } printf("Microsoft.CRTProvider logging is %s\n", enabled ? "on" : "off"); return 0; } 

  (it will not work under XP due to the lack of necessary APIs. However, for exactly the same reason, logging under XP is always disabled. exe-shnik for the lazy: yadi.sk/d/pvQkFUqKqwJSV )
• Such logs would be most logical to use as an aid to debugging. But by itself, running under the debugger does not include logs. Of course, it is possible that some checkbox in the settings includes functionality that needs logs ... or logs are needed for some clever debugging utility ... but then it is not clear why the code remains when compiled with the release library.
  
  
  UPD from 12:00 04/13/2016: updated the detection code of the presence of an active user of logs, now it corresponds exactly to what is happening inside __vcrt_initialize_telemetry_provider.