Skip to content

Commit

Permalink
Fix AppInitialized latency metric (#15206)
Browse files Browse the repository at this point in the history
The AppInitialized latency metric logs how long the application needs
to initialize the UI. 5b434dc broke this metric, because it was now
executing the code outside of the `Initialized` callback.
It's the difference between a "latency" of ~50ms and ~350ms.

As an added bonus it moves the `_ApplyStartupTaskStateChange` task
into the `Initialized` callback as well, because why not.

## Validation Steps Performed
* Breakpoint into "AppInitialized" - latency is now correct ✅

Co-authored-by: Dustin L. Howett <duhowett@microsoft.com>
  • Loading branch information
lhecker and DHowett authored Apr 25, 2023
1 parent e413a41 commit 405fb51
Show file tree
Hide file tree
Showing 3 changed files with 51 additions and 67 deletions.
102 changes: 42 additions & 60 deletions src/cascadia/TerminalApp/AppLogic.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -182,45 +182,7 @@ namespace winrt::TerminalApp::implementation
// this as a MTA, before the app is Create()'d
WINRT_ASSERT(_loadedInitialSettings);

// These used to be in `TerminalPage::Initialized`, so that they started
// _after_ the Terminal window was started and displayed. These could
// theoretically move there again too. TODO:GH#14957 - evaluate moving
// this after the Page is initialized
{
// Both LoadSettings and ReloadSettings are supposed to call this function,
// but LoadSettings skips it, so that the UI starts up faster.
// Now that the UI is present we can do them with a less significant UX impact.
_ProcessLazySettingsChanges();

FILETIME creationTime, exitTime, kernelTime, userTime, now;
if (GetThreadTimes(GetCurrentThread(), &creationTime, &exitTime, &kernelTime, &userTime))
{
static constexpr auto asInteger = [](const FILETIME& f) {
ULARGE_INTEGER i;
i.LowPart = f.dwLowDateTime;
i.HighPart = f.dwHighDateTime;
return i.QuadPart;
};
static constexpr auto asSeconds = [](uint64_t v) {
return v * 1e-7f;
};

GetSystemTimeAsFileTime(&now);

const auto latency = asSeconds(asInteger(now) - asInteger(creationTime));

TraceLoggingWrite(
g_hTerminalAppProvider,
"AppInitialized",
TraceLoggingDescription("Event emitted once the app is initialized"),
TraceLoggingFloat32(latency, "latency"),
TraceLoggingKeyword(MICROSOFT_KEYWORD_MEASURES),
TelemetryPrivacyDataTag(PDT_ProductAndServiceUsage));
}
}

_ApplyLanguageSettingChange();
_ApplyStartupTaskStateChange();

TraceLoggingWrite(
g_hTerminalAppProvider,
Expand Down Expand Up @@ -393,33 +355,12 @@ namespace winrt::TerminalApp::implementation
}
CATCH_LOG()

// Function Description:
// Returns the current app package or nullptr.
// TRANSITIONAL
// Exists to work around a compiler bug. This function encapsulates the
// exception handling that we used to keep around calls to Package::Current,
// so that when it's called inside a coroutine and fails it doesn't explode
// terribly.
static winrt::Windows::ApplicationModel::Package GetCurrentPackageNoThrow() noexcept
{
try
{
return winrt::Windows::ApplicationModel::Package::Current();
}
catch (...)
{
// discard any exception -- literally pretend we're not in a package
}
return nullptr;
}

fire_and_forget AppLogic::_ApplyStartupTaskStateChange()
try
{
// First, make sure we're running in a packaged context. This method
// won't work, and will crash mysteriously if we're running unpackaged.
const auto package{ GetCurrentPackageNoThrow() };
if (package == nullptr)
if (!IsPackaged())
{
co_return;
}
Expand Down Expand Up @@ -519,6 +460,47 @@ namespace winrt::TerminalApp::implementation
_SettingsChangedHandlers(*this, *ev);
}

// This is a continuation of AppLogic::Create() and includes the more expensive parts.
void AppLogic::NotifyRootInitialized()
{
if (_notifyRootInitializedCalled.exchange(true, std::memory_order_relaxed))
{
return;
}

// Both LoadSettings and ReloadSettings are supposed to call this function,
// but LoadSettings skips it, so that the UI starts up faster.
// Now that the UI is present we can do them with a less significant UX impact.
_ApplyStartupTaskStateChange();
_ProcessLazySettingsChanges();

FILETIME creationTime, exitTime, kernelTime, userTime, now;
if (GetThreadTimes(GetCurrentThread(), &creationTime, &exitTime, &kernelTime, &userTime))
{
static constexpr auto asInteger = [](const FILETIME& f) {
ULARGE_INTEGER i;
i.LowPart = f.dwLowDateTime;
i.HighPart = f.dwHighDateTime;
return i.QuadPart;
};
static constexpr auto asSeconds = [](uint64_t v) {
return v * 1e-7f;
};

GetSystemTimeAsFileTime(&now);

const auto latency = asSeconds(asInteger(now) - asInteger(creationTime));

TraceLoggingWrite(
g_hTerminalAppProvider,
"AppInitialized",
TraceLoggingDescription("Event emitted once the app is initialized"),
TraceLoggingFloat32(latency, "latency"),
TraceLoggingKeyword(MICROSOFT_KEYWORD_MEASURES),
TelemetryPrivacyDataTag(PDT_ProductAndServiceUsage));
}
}

// Method Description:
// - Returns a pointer to the global shared settings.
[[nodiscard]] CascadiaSettings AppLogic::GetSettings() const noexcept
Expand Down
3 changes: 2 additions & 1 deletion src/cascadia/TerminalApp/AppLogic.h
Original file line number Diff line number Diff line change
Expand Up @@ -45,12 +45,12 @@ namespace winrt::TerminalApp::implementation
static const Microsoft::Terminal::Settings::Model::CascadiaSettings CurrentAppSettings();

AppLogic();
~AppLogic() = default;

void Create();
bool IsRunningElevated() const noexcept;
bool CanDragDrop() const noexcept;
void ReloadSettings();
void NotifyRootInitialized();

bool HasSettingsStartupActions() const noexcept;

Expand Down Expand Up @@ -79,6 +79,7 @@ namespace winrt::TerminalApp::implementation
private:
bool _isElevated{ false };
bool _canDragDrop{ false };
std::atomic<bool> _notifyRootInitializedCalled{ false };

Microsoft::Terminal::Settings::Model::CascadiaSettings _settings{ nullptr };

Expand Down
13 changes: 7 additions & 6 deletions src/cascadia/TerminalApp/TerminalWindow.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -3,16 +3,15 @@

#include "pch.h"
#include "TerminalWindow.h"

#include "AppLogic.h"
#include "../inc/WindowingBehavior.h"
#include "TerminalWindow.g.cpp"
#include "SettingsLoadEventArgs.g.cpp"
#include "WindowProperties.g.cpp"

#include <LibraryResources.h>
#include <WtExeUtils.h>
#include <wil/token_helpers.h>

#include "../../types/inc/utils.hpp"
#include "TerminalWindow.g.cpp"
#include "SettingsLoadEventArgs.g.cpp"
#include "WindowProperties.g.cpp"

using namespace winrt::Windows::ApplicationModel;
using namespace winrt::Windows::ApplicationModel::DataTransfer;
Expand Down Expand Up @@ -235,6 +234,8 @@ namespace winrt::TerminalApp::implementation
{
_root->SetFullscreen(true);
}

AppLogic::Current()->NotifyRootInitialized();
});
_root->Create();

Expand Down

0 comments on commit 405fb51

Please sign in to comment.