Add std::source_location support when logging error information

[dmachaj]

Closes #1184

Why is this change being made?

This change is being made to (greatly!) improve the error logging for exceptions that originate in cppwinrt. This is especially directed at the cases where cppwinrt and WIL are interoperating. The extension point between them has the ability to forward the file name, line number, and function name across to be logged. They always pass null.

With C++20 and std::source_location specifically that can change. It is possible to capture that information in a standards-compliant way and forward it along to be logged. The result is vastly improved WIL logging output.

Briefly summarize what changed

Unfortunately this change is a bit ugly and requires macros. The reason for that is because std::source_location is new in C++20 and because it must be constructed by the code that is calling into cppwinrt headers. The support floor for cppwinrt is C++17 so this type needs to be behind an #ifdef. That is what leads to the macros (which evaluate to nothing for C++17).

The second bit of ugliness is that the calling code must be what constructs the std::source_location. Otherwise it will get the source information for cppwinrt itself which is not helpful. This is achieved with a default parameter for every method that can originate an error. The caller silently constructs it before the call so it has accurate source information. For cases where errors hop a few times this must be forwarded so it is not lost.

Other miscellaneous changes include:

• The test_cpp20 project was updated to the VS2022 toolset. The VS2019 toolset has an Internal Compiler Error (ICE) when building C++20 code. The crash is gone in newer versions.
• The test_cpp20 project now requests C++20 (not C++/latest).
• hresult_error::originate will now call winrt_throw_hesult_handler if it is provided. Previously throw winrt::hresult_error(E_WHATEVER) would not log to WIL. Now it does.
• #pragma detect mismatch for whether std::source_location is being used, or not.

How was this change tested?

A new test file was added to the C++20 test binary. This test ensures that the source information is accurate (and in fact caught a subtle bug when the test was being written!).

[dmachaj]

I have a sample program that combines cppwinrt and WIL to validate the logging output with and without these changes.

Lines 22-45 are as follows:

void ThrowWinrtHresult()
{
    throw winrt::hresult_error(E_INVALIDARG);
}

void CheckWinrtHresult()
{
    winrt::check_hresult(E_INVALIDARG);
}

void CheckWinrtWin32Error()
{
    winrt::check_win32(ERROR_ACCESS_AUDIT_BY_POLICY);
}

void ThrowWILException()
{
    THROW_HR(E_INVALIDARG);
}

void CheckWILException()
{
    THROW_IF_FAILED(E_INVALIDARG);
}

Lines 86-124 are as follows:

    try
    {
        OutputDebugString(L"----throw winrt::hresult_error()----\r\n");
        ThrowWinrtHresult();
    }
    CATCH_LOG();
    OutputDebugString(L"----\r\n\r\n");

    try
    {
        OutputDebugString(L"----winrt::check_hresult()----\r\n");
        CheckWinrtHresult();
    }
    CATCH_LOG();
    OutputDebugString(L"----\r\n\r\n");

    try
    {
        OutputDebugString(L"----winrt::check_win32()----\r\n");
        CheckWinrtWin32Error();
    }
    CATCH_LOG();
    OutputDebugString(L"----\r\n\r\n");

    try
    {
        OutputDebugString(L"----THROW_HR----\r\n");
        ThrowWILException();
    }
    CATCH_LOG();
    OutputDebugString(L"----\r\n\r\n");

    try
    {
        OutputDebugString(L"----THROW_IF_FAILED----\r\n");
        CheckWILException();
    }
    CATCH_LOG();
    OutputDebugString(L"----\r\n\r\n");

C++17 output

----throw winrt::hresult_error()----
(null)!00007FF6A684415E: LogHr(1) tid(a1bc) 80070057 The parameter is incorrect.
V:\T\dmachaj.randomprojects\C++WinRTAndWILInteropTesting\C++WinRTAndWILInteropTesting\App.cpp(91)\(null)!00007FF6A68E9E05: (caller: 00007FF6A68CDD4F) LogHr(2) tid(a1bc) 80070057 The parameter is incorrect.
    Msg:[winrt::hresult_error: The parameter is incorrect.] [winrt::C__WinRTAndWILInteropTesting::implementation::App::App]
----

----winrt::check_hresult()----
(null)!00007FF6A68539DE: LogHr(3) tid(a1bc) 80070057 The parameter is incorrect.
V:\T\dmachaj.randomprojects\C++WinRTAndWILInteropTesting\C++WinRTAndWILInteropTesting\App.cpp(99)\(null)!00007FF6A68E9E75: (caller: 00007FF6A68CDD4F) LogHr(4) tid(a1bc) 80070057 The parameter is incorrect.
    Msg:[winrt::hresult_error: The parameter is incorrect.] [winrt::C__WinRTAndWILInteropTesting::implementation::App::App]
----

----winrt::check_win32()----
(null)!00007FF6A6839A25: LogHr(5) tid(a1bc) 80070311 Access to %1 is monitored by policy rule %2.
V:\T\dmachaj.randomprojects\C++WinRTAndWILInteropTesting\C++WinRTAndWILInteropTesting\App.cpp(107)\(null)!00007FF6A68E9EE5: (caller: 00007FF6A68CDD4F) LogHr(6) tid(a1bc) 80070311 Access to %1 is monitored by policy rule %2.
    Msg:[winrt::hresult_error: Access to %1 is monitored by policy rule %2.] [winrt::C__WinRTAndWILInteropTesting::implementation::App::App]
----

----THROW_HR----
V:\T\dmachaj.randomprojects\C++WinRTAndWILInteropTesting\C++WinRTAndWILInteropTesting\App.cpp(39)\(null)!00007FF6A6851665: (caller: 00007FF6A684215D) Exception(1) tid(a1bc) 80070057 The parameter is incorrect.
    [ThrowWILException(E_INVALIDARG)]
V:\T\dmachaj.randomprojects\C++WinRTAndWILInteropTesting\C++WinRTAndWILInteropTesting\App.cpp(115)\(null)!00007FF6A68E9F55: (caller: 00007FF6A68CDD4F) LogHr(7) tid(a1bc) 80070057 The parameter is incorrect.
    Msg:[V:\T\dmachaj.randomprojects\C++WinRTAndWILInteropTesting\C++WinRTAndWILInteropTesting\App.cpp(39)\(null)!00007FF6A6851665: (caller: 00007FF6A684215D) Exception(1) tid(a1bc) 80070057 The parameter is incorrect.
    [ThrowWILException(E_INVALIDARG)]
] [winrt::C__WinRTAndWILInteropTesting::implementation::App::App]
----

----THROW_IF_FAILED----
V:\T\dmachaj.randomprojects\C++WinRTAndWILInteropTesting\C++WinRTAndWILInteropTesting\App.cpp(44)\(null)!00007FF6A685181C: (caller: 00007FF6A6842180) Exception(2) tid(a1bc) 80070057 The parameter is incorrect.
    [CheckWILException(E_INVALIDARG)]
V:\T\dmachaj.randomprojects\C++WinRTAndWILInteropTesting\C++WinRTAndWILInteropTesting\App.cpp(123)\(null)!00007FF6A68E9FC5: (caller: 00007FF6A68CDD4F) LogHr(8) tid(a1bc) 80070057 The parameter is incorrect.
    Msg:[V:\T\dmachaj.randomprojects\C++WinRTAndWILInteropTesting\C++WinRTAndWILInteropTesting\App.cpp(44)\(null)!00007FF6A685181C: (caller: 00007FF6A6842180) Exception(2) tid(a1bc) 80070057 The parameter is incorrect.
    [CheckWILException(E_INVALIDARG)]
] [winrt::C__WinRTAndWILInteropTesting::implementation::App::App]
----

C++20 output

----throw winrt::hresult_error()----
V:\T\dmachaj.randomprojects\C++WinRTAndWILInteropTesting\C++WinRTAndWILInteropTesting\App.cpp(24)\(null)!00007FF6063DAAA3: LogHr(1) tid(ab54) 80070057 The parameter is incorrect.
    [ThrowWinrtHresult]
V:\T\dmachaj.randomprojects\C++WinRTAndWILInteropTesting\C++WinRTAndWILInteropTesting\App.cpp(91)\(null)!00007FF606488975: (caller: 00007FF60646BC2F) LogHr(2) tid(ab54) 80070057 The parameter is incorrect.
    Msg:[winrt::hresult_error: The parameter is incorrect.] [winrt::C__WinRTAndWILInteropTesting::implementation::App::App]
----

----winrt::check_hresult()----
V:\T\dmachaj.randomprojects\C++WinRTAndWILInteropTesting\C++WinRTAndWILInteropTesting\App.cpp(29)\(null)!00007FF6063EBA33: LogHr(3) tid(ab54) 80070057 The parameter is incorrect.
    [CheckWinrtHresult]
V:\T\dmachaj.randomprojects\C++WinRTAndWILInteropTesting\C++WinRTAndWILInteropTesting\App.cpp(99)\(null)!00007FF6064889E5: (caller: 00007FF60646BC2F) LogHr(4) tid(ab54) 80070057 The parameter is incorrect.
    Msg:[winrt::hresult_error: The parameter is incorrect.] [winrt::C__WinRTAndWILInteropTesting::implementation::App::App]
----

----winrt::check_win32()----
V:\T\dmachaj.randomprojects\C++WinRTAndWILInteropTesting\C++WinRTAndWILInteropTesting\App.cpp(34)\(null)!00007FF6063CFB91: LogHr(5) tid(ab54) 80070311 Access to %1 is monitored by policy rule %2.
    [CheckWinrtWin32Error]
V:\T\dmachaj.randomprojects\C++WinRTAndWILInteropTesting\C++WinRTAndWILInteropTesting\App.cpp(107)\(null)!00007FF606488A55: (caller: 00007FF60646BC2F) LogHr(6) tid(ab54) 80070311 Access to %1 is monitored by policy rule %2.
    Msg:[winrt::hresult_error: Access to %1 is monitored by policy rule %2.] [winrt::C__WinRTAndWILInteropTesting::implementation::App::App]
----

----THROW_HR----
V:\T\dmachaj.randomprojects\C++WinRTAndWILInteropTesting\C++WinRTAndWILInteropTesting\App.cpp(39)\(null)!00007FF6063E9315: (caller: 00007FF6063D884D) Exception(1) tid(ab54) 80070057 The parameter is incorrect.
    [ThrowWILException(E_INVALIDARG)]
V:\T\dmachaj.randomprojects\C++WinRTAndWILInteropTesting\C++WinRTAndWILInteropTesting\App.cpp(115)\(null)!00007FF606488AC5: (caller: 00007FF60646BC2F) LogHr(7) tid(ab54) 80070057 The parameter is incorrect.
    Msg:[V:\T\dmachaj.randomprojects\C++WinRTAndWILInteropTesting\C++WinRTAndWILInteropTesting\App.cpp(39)\(null)!00007FF6063E9315: (caller: 00007FF6063D884D) Exception(1) tid(ab54) 80070057 The parameter is incorrect.
    [ThrowWILException(E_INVALIDARG)]
] [winrt::C__WinRTAndWILInteropTesting::implementation::App::App]
----

----THROW_IF_FAILED----
V:\T\dmachaj.randomprojects\C++WinRTAndWILInteropTesting\C++WinRTAndWILInteropTesting\App.cpp(44)\(null)!00007FF6063E956C: (caller: 00007FF6063D8870) Exception(2) tid(ab54) 80070057 The parameter is incorrect.
    [CheckWILException(E_INVALIDARG)]
V:\T\dmachaj.randomprojects\C++WinRTAndWILInteropTesting\C++WinRTAndWILInteropTesting\App.cpp(123)\(null)!00007FF606488B35: (caller: 00007FF60646BC2F) LogHr(8) tid(ab54) 80070057 The parameter is incorrect.
    Msg:[V:\T\dmachaj.randomprojects\C++WinRTAndWILInteropTesting\C++WinRTAndWILInteropTesting\App.cpp(44)\(null)!00007FF6063E956C: (caller: 00007FF6063D8870) Exception(2) tid(ab54) 80070057 The parameter is incorrect.
    [CheckWILException(E_INVALIDARG)]
] [winrt::C__WinRTAndWILInteropTesting::implementation::App::App]
----

The code was the same in both cases. The only difference was changing the C++ language standard and recompiling. The notable difference is that previously there was no logging where the exception was thrown (e.g. line 29). Now there is logging both when it is thrown and when it is caught/logged. This will greatly improve the debugging experience.

[kennykerr]

/azp run

[azure-pipelines]

Azure Pipelines successfully started running 1 pipeline(s).

[dmachaj]

@kennykerr unfortunately the build is failing because the agents do not have the v143 toolset installed

C:\Program Files (x86)\Microsoft Visual Studio\2019\Enterprise\MSBuild\Microsoft\VC\v160\Microsoft.CppBuild.targets(439,5): error MSB8020: The build tools for v143 (Platform Toolset = 'v143') cannot be found. To build using the v143 build tools, please install v143 build tools.  Alternatively, you may upgrade to the current Visual Studio tools by selecting the Project menu or right-click the solution, and then selecting "Retarget solution". [D:\a\1\s\test\test_cpp20\test_cpp20.vcxproj]

The C++20 support in v142 is incomplete and the compiler crashes when std::source_information is included (let alone used).

[kennykerr]

unfortunately the build is failing because the agents do not have the v143 toolset installed

Is it just a matter of upgrading the solution to target 143 instead?

[dmachaj]

unfortunately the build is failing because the agents do not have the v143 toolset installed

Is it just a matter of upgrading the solution to target 143 instead?

The error makes it sound like the build agent does not have it installed. I suspect that no code changes to this PR are needed to fix the toolset. Some sort of ADO "build agent configuration" change is needed instead. Once that happens it would probably be a good thing to update everything to VS2022, but that is scope creep beyond the minimum needed for this PR.

[kennykerr]

Agreed - just trying to figure out what's needed - I'll poke around and see if I can get this upgraded separately.

[kennykerr]

Other than the check_hresult declaration needing the default (rather than the definition), this looks great. Ideally, we can eventually apply this to the projection itself and not just to explicit calls to check_hresult and exceptions, but I think this is a good start to get some experience with this new C++20 feature before applying it more broadly. Applying it more broadly is also really ugly as this parameter needs to be added to every single API call, which is gross.