Fix the build - we added GetServerHandle to IDeviceComm

(completion with/without data are different things)

disconnect handles from the mapping list when messages indicate we
should destroy them

src/host/LogIO.cpp

@@ -0,0 +1,275 @@
+// Copyright (c) Microsoft Corporation.
+// Licensed under the MIT license.
+
+#include "precomp.h"
+#include "LogIO.h"
+
+using namespace Microsoft::Console::Host::BinaryLogging;
+
+LoggingDeviceComm::LoggingDeviceComm(IDeviceComm* loggee, const std::wstring_view file) :
+    _loggee(loggee),
+    _lastEvent(std::chrono::high_resolution_clock::now())
+{
+    _dataArena.resize(1024);
+    _file.reset(CreateFileW(file.data(), GENERIC_WRITE | DELETE, FILE_SHARE_READ, nullptr, CREATE_ALWAYS, FILE_ATTRIBUTE_NORMAL, nullptr));
+
+    USHORT processMachine{};
+    USHORT nativeMachine{};
+    THROW_IF_WIN32_BOOL_FALSE(IsWow64Process2(GetCurrentProcess(), &processMachine, &nativeMachine));
+
+    LogHeader header{};
+    header.Version = 1;
+    header.HostArchitecture = nativeMachine;
+    _writeInFull(&header, sizeof(LogHeader));
+
+    //_startLogThread();
+}
+
+[[nodiscard]] HRESULT LoggingDeviceComm::SetServerInformation(CD_IO_SERVER_INFORMATION* const pServerInfo) const
+{
+    return _loggee->SetServerInformation(pServerInfo);
+}
+
+[[nodiscard]] HRESULT LoggingDeviceComm::ReadIo(PCONSOLE_API_MSG const pReplyMsg, CONSOLE_API_MSG* const pMessage) const
+{
+    RETURN_IF_FAILED(_loggee->ReadIo(pReplyMsg, pMessage));
+    static constexpr uint32_t apiMsgLen{ sizeof(CONSOLE_API_MSG) - offsetof(CONSOLE_API_MSG, Descriptor) };
+    _writeDataWithHeader(LogPacketType::Read, _timeDelta(), apiMsgLen, &pMessage->Descriptor);
+    return S_OK;
+}
+
+[[nodiscard]] HRESULT LoggingDeviceComm::CompleteIo(CD_IO_COMPLETE* const pCompletion) const
+{
+    return _loggee->CompleteIo(pCompletion);
+}
+
+[[nodiscard]] HRESULT LoggingDeviceComm::ReadInput(CD_IO_OPERATION* const pIoOperation) const
+{
+    RETURN_IF_FAILED(_loggee->ReadInput(pIoOperation));
+    _writeDataWithHeader(LogPacketType::InputBuffer, _timeDelta(), pIoOperation->Buffer.Size, pIoOperation->Buffer.Data);
+    return S_OK;
+}
+
+[[nodiscard]] HRESULT LoggingDeviceComm::WriteOutput(CD_IO_OPERATION* const pIoOperation) const
+{
+    return _loggee->WriteOutput(pIoOperation);
+}
+
+[[nodiscard]] HRESULT LoggingDeviceComm::AllowUIAccess() const
+{
+    return _loggee->AllowUIAccess();
+}
+
+[[nodiscard]] ULONG_PTR LoggingDeviceComm::PutHandle(const void* handle)
+{
+    auto upstreamMapping{ _loggee->PutHandle(handle) };
+    auto found{ std::find(_handleTable.begin(), _handleTable.end(), upstreamMapping) };
+    if (found == _handleTable.end())
+    {
+        // append, get pos
+        found = _handleTable.emplace(found, upstreamMapping);
+    }
+    return found - _handleTable.begin();
+}
+
+[[nodiscard]] void* LoggingDeviceComm::GetHandle(ULONG_PTR handleId) const
+{
+    return _loggee->GetHandle(_handleTable.at(handleId));
+}
+
+void LoggingDeviceComm::DestroyHandle(ULONG_PTR handleId)
+{
+    auto& pos{ _handleTable.at(handleId) };
+    _loggee->DestroyHandle(pos);
+    pos = 0;
+}
+
+uint64_t LoggingDeviceComm::_timeDelta() const
+{
+    auto thisEventTime{ std::chrono::high_resolution_clock::now() };
+    int64_t delta{ (thisEventTime - _lastEvent).count() };
+    _lastEvent = thisEventTime;
+    return delta;
+}
+
+void LoggingDeviceComm::_writeInFull(void* buffer, const size_t length) const
+{
+    auto remaining{ length };
+    DWORD written{};
+    while (WriteFile(_file.get(), reinterpret_cast<std::byte*>(buffer) + (length - remaining), gsl::narrow_cast<DWORD>(remaining), &written, nullptr) != 0)
+    {
+        if ((remaining -= written) == 0)
+        {
+            break;
+        }
+    }
+
+    if (remaining)
+    {
+        THROW_HR(E_BOUNDS);
+    }
+}
+
+void LoggingDeviceComm::_writeDataWithHeader(LogPacketType packetType, uint64_t timeDelta, size_t length, const void* buffer) const
+{
+    auto fullPacketLen{ length + offsetof(LogPacketDescriptor, _PositionInFile) };
+    if (_dataArena.size() < fullPacketLen)
+    {
+        _dataArena.resize(fullPacketLen);
+    }
+    *(reinterpret_cast<LogPacketDescriptor*>(_dataArena.data())) = LogPacketDescriptor{ packetType, timeDelta, gsl::narrow_cast<uint32_t>(length) };
+    const auto bufferAsByte{ reinterpret_cast<const std::byte*>(buffer) };
+    std::copy(bufferAsByte, bufferAsByte + length, _dataArena.data() + (offsetof(LogPacketDescriptor, _PositionInFile)));
+
+    _writeInFull(_dataArena.data(), fullPacketLen);
+}
+
+void LoggingDeviceComm::_logThreadBody()
+{
+}
+
+void LoggingDeviceComm::_startLogThread()
+{
+    _logThread = std::thread{
+        [this]() {
+            _logThreadBody();
+        }
+    };
+}
+
+/******************************************************REPLAY********************************/
+
+void LogReplayDeviceComm::_readInFull(void* buffer, const size_t length) const
+{
+    /*
+        auto remaining{ length };
+        DWORD read{};
+        while (!!ReadFile(_file.get(), reinterpret_cast<std::byte*>(buffer) + (length - remaining), gsl::narrow_cast<DWORD>(remaining), &read, nullptr))
+        {
+            if ((remaining -= read) == 0)
+            {
+                break;
+            }
+        }
+
+        if (remaining)
+        {
+            THROW_HR(E_BOUNDS);
+        }
+        */
+    if (length > _max - _off)
+    {
+        THROW_HR(E_BOUNDS);
+    }
+    memcpy(buffer, _fileMapView.get() + _off, length);
+    _off += length;
+}
+
+const LogPacketDescriptor& LogReplayDeviceComm::_readDescriptor() const
+{
+    //LogPacketDescriptor descriptor{};
+    //auto filepos{ SetFilePointer(_file.get(), 0, nullptr, FILE_CURRENT) };
+    //_readInFull(&descriptor, offsetof(LogPacketDescriptor, _PositionInFile));
+    //descriptor._PositionInFile = filepos;
+    auto oldOff{ _off };
+    _off += offsetof(LogPacketDescriptor, _PositionInFile);
+    return *reinterpret_cast<LogPacketDescriptor*>(_fileMapView.get() + oldOff);
+    //return descriptor;
+}
+
+LogReplayDeviceComm::LogReplayDeviceComm(const std::wstring_view file, double timeDilation) :
+    _timeDilation(timeDilation)
+{
+    _file.reset(CreateFileW(file.data(), GENERIC_READ, FILE_SHARE_READ, nullptr, OPEN_EXISTING, FILE_ATTRIBUTE_NORMAL, nullptr));
+    _fileMapping.reset(CreateFileMappingW(_file.get(), nullptr, PAGE_READONLY, 0, 0, nullptr));
+    THROW_HR_IF_NULL(E_FAIL, _fileMapping);
+    _fileMapView.reset(static_cast<std::byte*>(MapViewOfFile(_fileMapping.get(), FILE_MAP_READ, 0, 0, 0)));
+    THROW_HR_IF_NULL(E_FAIL, _fileMapView);
+
+    MEMORY_BASIC_INFORMATION mbi{};
+    VirtualQuery(_fileMapView.get(), &mbi, sizeof(mbi));
+    _max = mbi.RegionSize;
+
+    USHORT processMachine{};
+    USHORT nativeMachine{};
+    THROW_IF_WIN32_BOOL_FALSE(IsWow64Process2(GetCurrentProcess(), &processMachine, &nativeMachine));
+
+    LogHeader header{};
+    _readInFull(&header, sizeof(header));
+    if (nativeMachine != header.HostArchitecture)
+    {
+        MessageBoxW(nullptr, wil::str_printf<std::wstring>(L"This dump was created on a conhost of a different architecture (expected %2.02x, got %2.02x).", header.HostArchitecture, nativeMachine).c_str(), L"Error", MB_OK | MB_ICONERROR);
+        ExitProcess(1);
+    }
+}
+
+[[nodiscard]] HRESULT LogReplayDeviceComm::SetServerInformation(CD_IO_SERVER_INFORMATION* const) const
+{
+    return S_OK;
+}
+
+[[nodiscard]] HRESULT LogReplayDeviceComm::ReadIo(PCONSOLE_API_MSG const, CONSOLE_API_MSG* const pMessage) const
+{
+    auto requestStartTime{ std::chrono::high_resolution_clock::now() };
+
+    static constexpr uint32_t maxLen{ sizeof(CONSOLE_API_MSG) - offsetof(CONSOLE_API_MSG, Descriptor) };
+    auto& descriptor{ _readDescriptor() };
+    THROW_HR_IF(E_UNEXPECTED, descriptor.PacketType != LogPacketType::Read || descriptor.Length < maxLen);
+
+    _readInFull(&pMessage->Descriptor, descriptor.Length);
+
+    auto finishTime{ requestStartTime + std::chrono::nanoseconds(static_cast<long long>(descriptor.TimeDeltaInNs * _timeDilation)) };
+    if (finishTime > std::chrono::high_resolution_clock::now())
+        std::this_thread::sleep_until(finishTime);
+    return S_OK;
+}
+
+[[nodiscard]] HRESULT LogReplayDeviceComm::CompleteIo(CD_IO_COMPLETE* const) const
+{
+    return S_OK;
+}
+
+[[nodiscard]] HRESULT LogReplayDeviceComm::ReadInput(CD_IO_OPERATION* const pIoOperation) const
+{
+    auto requestStartTime{ std::chrono::high_resolution_clock::now() };
+    auto& descriptor{ _readDescriptor() };
+    THROW_HR_IF(E_UNEXPECTED, descriptor.PacketType != LogPacketType::InputBuffer);
+
+    _readInFull(static_cast<uint8_t*>(pIoOperation->Buffer.Data), descriptor.Length);
+    auto finishTime{ requestStartTime + std::chrono::nanoseconds(static_cast<long long>(descriptor.TimeDeltaInNs * _timeDilation)) };
+    if (finishTime > std::chrono::high_resolution_clock::now())
+        std::this_thread::sleep_until(finishTime);
+    return S_OK;
+}
+
+[[nodiscard]] HRESULT LogReplayDeviceComm::WriteOutput(CD_IO_OPERATION* const) const
+{
+    return S_OK;
+}
+
+[[nodiscard]] HRESULT LogReplayDeviceComm::AllowUIAccess() const
+{
+    return S_OK;
+}
+
+[[nodiscard]] ULONG_PTR LogReplayDeviceComm::PutHandle(const void* handle)
+{
+    auto found{ std::find(_handleTable.begin(), _handleTable.end(), handle) };
+    if (found == _handleTable.end())
+    {
+        // append, get pos
+        found = _handleTable.emplace(found, const_cast<void*>(handle));
+    }
+    return found - _handleTable.begin();
+}
+
+[[nodiscard]] void* LogReplayDeviceComm::GetHandle(ULONG_PTR handleId) const
+{
+    return _handleTable.at(handleId);
+}
+
+void LogReplayDeviceComm::DestroyHandle(ULONG_PTR handleId)
+{
+    auto& pos{ _handleTable.at(handleId) };
+    pos = nullptr;
+}

src/host/LogIO.h

@@ -0,0 +1,111 @@
+/*++
+Copyright (c) Microsoft Corporation
+Licensed under the MIT license.
+
+Module Name:
+- LogIO.h
+
+Abstract:
+- TODO DH: Explain logging
+
+Author:
+- Dustin Howett (DuHowett) 2020-11-14
+
+Revision History:
+--*/
+
+#pragma once
+
+namespace Microsoft::Console::Host::BinaryLogging
+{
+    enum class LogPacketType : uint16_t
+    {
+        Read = 1,
+        InputBuffer = 2,
+    };
+
+#pragma pack(push, 1)
+    struct LogHeader
+    {
+        uint8_t Version;
+        uint16_t HostArchitecture;
+    };
+
+    struct LogPacketDescriptor
+    {
+        LogPacketType PacketType;
+        uint64_t TimeDeltaInNs;
+        uint32_t Length;
+        uint32_t _PositionInFile;
+    };
+#pragma pack(pop)
+
+    class LoggingDeviceComm : public IDeviceComm
+    {
+    public:
+        LoggingDeviceComm(IDeviceComm* loggee, const std::wstring_view file);
+        ~LoggingDeviceComm() = default;
+
+        [[nodiscard]] HRESULT SetServerInformation(_In_ CD_IO_SERVER_INFORMATION* const pServerInfo) const override;
+        [[nodiscard]] HRESULT ReadIo(_In_opt_ PCONSOLE_API_MSG const pReplyMsg,
+                                     _Out_ CONSOLE_API_MSG* const pMessage) const override;
+        [[nodiscard]] HRESULT CompleteIo(_In_ CD_IO_COMPLETE* const pCompletion) const override;
+        [[nodiscard]] HRESULT ReadInput(_In_ CD_IO_OPERATION* const pIoOperation) const override;
+        [[nodiscard]] HRESULT WriteOutput(_In_ CD_IO_OPERATION* const pIoOperation) const override;
+        [[nodiscard]] HRESULT AllowUIAccess() const override;
+        [[nodiscard]] ULONG_PTR PutHandle(const void* handle) override;
+        [[nodiscard]] void* GetHandle(ULONG_PTR handleId) const override;
+        void DestroyHandle(ULONG_PTR handleId) override;
+        [[nodiscard]] virtual HRESULT GetServerHandle(_Out_ HANDLE* pHandle) const { *pHandle = nullptr; return E_FAIL; }
+
+    private:
+        wil::unique_hfile _file;
+        IDeviceComm* _loggee;
+
+        mutable std::chrono::high_resolution_clock::time_point _lastEvent;
+        std::vector<ULONG_PTR> _handleTable;
+
+        uint64_t _timeDelta() const;
+
+        mutable std::vector<std::byte> _dataArena;
+        void _writeInFull(void* buffer, const size_t length) const;
+        void _writeDataWithHeader(LogPacketType packetType, uint64_t timeDelta, size_t length, const void* buffer) const;
+
+        std::thread _logThread;
+        void _logThreadBody();
+        void _startLogThread();
+    };
+
+    class LogReplayDeviceComm : public IDeviceComm
+    {
+    public:
+        LogReplayDeviceComm(const std::wstring_view file, double timeDilation = 1.0);
+        ~LogReplayDeviceComm() = default;
+
+        [[nodiscard]] HRESULT SetServerInformation(_In_ CD_IO_SERVER_INFORMATION* const /*pServerInfo*/) const override;
+        [[nodiscard]] HRESULT ReadIo(_In_opt_ PCONSOLE_API_MSG const /*pReplyMsg*/,
+                                     _Out_ CONSOLE_API_MSG* const pMessage) const override;
+        [[nodiscard]] HRESULT CompleteIo(_In_ CD_IO_COMPLETE* const /*pCompletion*/) const override;
+        [[nodiscard]] HRESULT ReadInput(_In_ CD_IO_OPERATION* const pIoOperation) const override;
+        [[nodiscard]] HRESULT WriteOutput(_In_ CD_IO_OPERATION* const /*pIoOperation*/) const override;
+        [[nodiscard]] HRESULT AllowUIAccess() const override;
+        [[nodiscard]] ULONG_PTR PutHandle(const void* handle) override;
+        [[nodiscard]] void* GetHandle(ULONG_PTR handleId) const override;
+        void DestroyHandle(ULONG_PTR handleId) override;
+        [[nodiscard]] virtual HRESULT GetServerHandle(_Out_ HANDLE* pHandle) const { *pHandle = nullptr; return E_FAIL; }
+
+    private:
+        wil::unique_hfile _file;
+        double _timeDilation;
+        std::vector<void*> _handleTable;
+
+        wil::unique_handle _fileMapping;
+        wil::unique_mapview_ptr<std::byte> _fileMapView;
+        mutable ptrdiff_t _off{ 0 };
+        size_t _max{};
+
+        void _readInFull(void* buffer, const size_t length) const;
+
+        const LogPacketDescriptor& _readDescriptor() const;
+    };
+}

src/host/exe/exemain.cpp

@@ -328,7 +328,12 @@ int CALLBACK wWinMain(
             if (useV2)
 #endif // TIL_FEATURE_LEGACYCONHOST_ENABLED
             {
-                if (args.ShouldCreateServerHandle())
+                auto clientCommandLine{ args.GetClientCommandline() };
+                if (clientCommandLine.rfind(L".bin") != std::wstring::npos)
+                {
+                    hr = Entrypoints::StartConsoleForAPIDump(&args);
+                }
+                else if (args.ShouldCreateServerHandle())
                 {
                     hr = Entrypoints::StartConsoleForCmdLine(args.GetClientCommandline().c_str(), &args);
                 }

src/host/host-common.vcxitems

@@ -48,6 +48,7 @@
     <ClCompile Include="..\VtApiRoutines.cpp" />
     <ClCompile Include="..\VtInputThread.cpp" />
     <ClCompile Include="..\VtIo.cpp" />
+    <ClCompile Include="..\LogIO.cpp" />
     <ClCompile Include="..\writeData.cpp" />
     <ClCompile Include="..\_output.cpp" />
     <ClCompile Include="..\_stream.cpp" />
@@ -100,6 +101,7 @@
     <ClInclude Include="..\VtApiRoutines.h" />
     <ClInclude Include="..\VtInputThread.hpp" />
     <ClInclude Include="..\VtIo.hpp" />
+    <ClInclude Include="..\LogIO.hpp" />
     <ClInclude Include="..\writeData.hpp" />
     <ClInclude Include="..\_output.h" />
     <ClInclude Include="..\_stream.h" />

src/host/srvinit.cpp

@@ -26,6 +26,7 @@
 #include "renderData.hpp"
 #include "../renderer/base/renderer.hpp"
 
+#include "LogIO.h"
 #include "../inc/conint.h"
 
 #include "tracing.hpp"
@@ -38,6 +39,7 @@
 
 using namespace Microsoft::Console::Interactivity;
 using namespace Microsoft::Console::Render;
+using namespace Microsoft::Console::Host::BinaryLogging;
 
 const UINT CONSOLE_EVENT_FAILURE_ID = 21790;
 const UINT CONSOLE_LPC_PORT_FAILURE_ID = 21791;
@@ -50,11 +52,20 @@ try
     if (!Globals.pDeviceComm)
     {
         // in rare circumstances (such as in the fuzzing harness), there will already be a device comm
-        Globals.pDeviceComm = new ConDrvDeviceComm(Server);
+        if (!Server)
+        {
+            Globals.pDeviceComm = new LogReplayDeviceComm(args->GetClientCommandline(), 1.0);
+        }
+        else
+        {
+            auto underlyingComm{ new ConDrvDeviceComm(Server) };
+            Globals.pDeviceComm = new LoggingDeviceComm(underlyingComm, L"conhost_log.bin");
+        }
     }
 
     Globals.launchArgs = *args;
 
+    // TODO(DH) These should be part of the dump/trace
     Globals.uiOEMCP = GetOEMCP();
     Globals.uiWindowsCP = GetACP();
 

src/server/ConDrvDeviceComm.cpp

@@ -172,6 +172,11 @@ ConDrvDeviceComm::~ConDrvDeviceComm() = default;
     return reinterpret_cast<void*>(handleId);
 }
 
+void ConDrvDeviceComm::DestroyHandle(ULONG_PTR /*handleId*/)
+{
+    // nothing
+}
+
 // Routine Description:
 // - Provides access to the raw server handle so it can be used to hand off
 //   the session to another console host server.

src/server/ConDrvDeviceComm.h

@@ -39,6 +39,7 @@ public:
 
     [[nodiscard]] ULONG_PTR PutHandle(const void*) override;
     [[nodiscard]] void* GetHandle(ULONG_PTR) const override;
+    void DestroyHandle(ULONG_PTR) override;
 
     [[nodiscard]] HRESULT GetServerHandle(_Out_ HANDLE* pHandle) const override;
 

src/server/DeviceComm.h

@@ -35,6 +35,7 @@ public:
 
     [[nodiscard]] virtual ULONG_PTR PutHandle(const void*) = 0;
     [[nodiscard]] virtual void* GetHandle(ULONG_PTR) const = 0;
+    virtual void DestroyHandle(ULONG_PTR) = 0;
 
     [[nodiscard]] virtual HRESULT GetServerHandle(_Out_ HANDLE* pHandle) const = 0;
 };

src/server/Entrypoints.cpp

@@ -176,4 +176,16 @@
     FAIL_FAST_HR(E_UNEXPECTED);
     return S_OK;
 }
+
+[[nodiscard]] HRESULT Entrypoints::StartConsoleForAPIDump(const ConsoleArguments* const args)
+{
+    // Create a scope because we're going to exit thread if everything goes well.
+    // This scope will ensure all C++ objects and smart pointers get a chance to destruct before ExitThread is called.
+    RETURN_IF_FAILED(ConsoleCreateIoThreadLegacy(nullptr, args));
+    ExitThread(S_OK);
+
+    // We won't hit this. The ExitThread above will kill the caller at this point.
+    FAIL_FAST_HR(E_UNEXPECTED);
+    return S_OK;
+}
 #pragma warning(pop)

src/server/Entrypoints.h

@@ -22,4 +22,5 @@ namespace Entrypoints
 {
     [[nodiscard]] HRESULT StartConsoleForServerHandle(const HANDLE ServerHandle, const ConsoleArguments* const args);
     [[nodiscard]] HRESULT StartConsoleForCmdLine(_In_ PCWSTR pwszCmdLine, const ConsoleArguments* const args);
+    [[nodiscard]] HRESULT StartConsoleForAPIDump(const ConsoleArguments* const args);
 };

src/server/lib/server.vcxproj.filters

@@ -147,4 +147,4 @@
   <ItemGroup>
     <Natvis Include="$(SolutionDir)tools\ConsoleTypes.natvis" />
   </ItemGroup>
-</Project>
+</Project>