merging latest dev

Signed-off-by: Gene Walters <genewalt@amazon.com>
This commit is contained in:
Gene Walters
2021-11-23 19:11:02 -08:00
1574 changed files with 24181 additions and 13745 deletions
@@ -103,6 +103,8 @@ set(FILES
native/utilities/PlatformConfiguration.cpp
native/utilities/PlatformConfiguration.h
native/utilities/PotentialDependencies.h
native/utilities/StatsCapture.cpp
native/utilities/StatsCapture.h
native/utilities/SpecializedDependencyScanner.h
native/utilities/ThreadHelper.cpp
native/utilities/ThreadHelper.h
@@ -36,6 +36,7 @@ set(FILES
native/tests/platformconfiguration/platformconfigurationtests.h
native/tests/utilities/JobModelTest.cpp
native/tests/utilities/JobModelTest.h
native/tests/utilities/StatsCaptureTest.cpp
native/tests/AssetCatalog/AssetCatalogUnitTests.cpp
native/tests/assetscanner/AssetScannerTests.h
native/tests/assetscanner/AssetScannerTests.cpp
@@ -25,6 +25,7 @@
#include <native/AssetManager/PathDependencyManager.h>
#include <native/utilities/BuilderConfigurationBus.h>
#include <native/utilities/StatsCapture.h>
#include "AssetRequestHandler.h"
@@ -123,6 +124,9 @@ namespace AssetProcessor
{
if (status == AssetProcessor::AssetScanningStatus::Started)
{
// capture scanning stats:
AssetProcessor::StatsCapture::BeginCaptureStat("AssetScanning");
// Ensure that the source file list is populated before a scan begins
m_sourceFilesInDatabase.clear();
m_fileModTimes.clear();
@@ -176,6 +180,8 @@ namespace AssetProcessor
(status == AssetProcessor::AssetScanningStatus::Stopped))
{
m_isCurrentlyScanning = false;
AssetProcessor::StatsCapture::EndCaptureStat("AssetScanning");
// we cannot invoke this immediately - the scanner might be done, but we aren't actually ready until we've processed all remaining messages:
QMetaObject::invokeMethod(this, "CheckMissingFiles", Qt::QueuedConnection);
}
@@ -209,13 +215,24 @@ namespace AssetProcessor
}
else
{
QString statKey = QString("ProcessJob,%1,%2,%3").arg(jobEntry.m_databaseSourceName).arg(jobEntry.m_jobKey).arg(jobEntry.m_platformInfo.m_identifier.c_str());
if (status == JobStatus::InProgress)
{
//update to in progress status
m_jobRunKeyToJobInfoMap[jobEntry.m_jobRunKey].m_status = JobStatus::InProgress;
// stats tracking. Start accumulating time.
AssetProcessor::StatsCapture::BeginCaptureStat(statKey.toUtf8().constData());
}
else //if failed or succeeded remove from the map
{
// note that sometimes this gets called twice, once by the RCJobs thread and once by the AP itself,
// because sometimes jobs take a short cut from "started" -> "failed" or "started" -> "complete
// without going thru the RC.
// as such, all the code in this block should be crafted to work regardless of whether its double called.
AssetProcessor::StatsCapture::EndCaptureStat(statKey.toUtf8().constData());
m_jobRunKeyToJobInfoMap.erase(jobEntry.m_jobRunKey);
Q_EMIT SourceFinished(sourceUUID, legacySourceUUID);
Q_EMIT JobComplete(jobEntry, status);
@@ -3355,8 +3372,13 @@ namespace AssetProcessor
AZStd::string logFileName = AssetUtilities::ComputeJobLogFileName(createJobsRequest);
{
AssetUtilities::JobLogTraceListener jobLogTraceListener(logFileName, runKey, true);
// track the time it takes to createJobs. We can perform analysis later to present it by extension and other stats.
QString statKey = QString("CreateJobs,%1,%2").arg(actualRelativePath).arg(builderInfo.m_name.c_str());
AssetProcessor::StatsCapture::BeginCaptureStat(statKey.toUtf8().constData());
builderInfo.m_createJobFunction(createJobsRequest, createJobsResponse);
AssetProcessor::StatsCapture::EndCaptureStat(statKey.toUtf8().constData());
}
AssetProcessor::SetThreadLocalJobId(0);
bool isBuilderMissingFingerprint = (createJobsResponse.m_result == AssetBuilderSDK::CreateJobsResultCode::Success
@@ -4839,5 +4861,7 @@ namespace AssetProcessor
}
return filesFound;
}
} // namespace AssetProcessor
@@ -0,0 +1,200 @@
/*
* Copyright (c) Contributors to the Open 3D Engine Project.
* For complete copyright and license terms please see the LICENSE at the root of this distribution.
*
* SPDX-License-Identifier: Apache-2.0 OR MIT
*
*/
#include <native/tests/AssetProcessorTest.h>
#include <native/utilities/StatsCapture.h>
#include <AzCore/std/containers/vector.h>
#include <AzCore/std/string/string.h>
#include <AzCore/Settings/SettingsRegistry.h>
#include <AzCore/Debug/TraceMessageBus.h>
#include <AzCore/StringFunc/StringFunc.h>
// the simple stats capture system has a trivial interface and only writes to printf.
// So the simplest tests we can do is make sure it only asserts when it should
// and doesn't assert in cases when it shouldn't, and that the stats are reasonable
// in printf format.
namespace AssetProcessor
{
// Its okay to talk to this system when unintialized, you can gain some perf
// by not intializing it at all
TEST_F(AssetProcessorTest, StatsCaptureTest_UninitializedSystemDoesNotAssert)
{
AssetProcessor::StatsCapture::BeginCaptureStat("Test");
AssetProcessor::StatsCapture::EndCaptureStat("Test");
AssetProcessor::StatsCapture::Dump();
AssetProcessor::StatsCapture::Shutdown();
}
// Double-intiailize is an error
TEST_F(AssetProcessorTest, StatsCaptureTest_DoubleInitializeIsAnAssert)
{
m_errorAbsorber->Clear();
AssetProcessor::StatsCapture::Initialize();
AssetProcessor::StatsCapture::Initialize();
EXPECT_EQ(m_errorAbsorber->m_numErrorsAbsorbed, 0);
EXPECT_EQ(m_errorAbsorber->m_numAssertsAbsorbed, 1); // not allowed to assert on this
AssetProcessor::StatsCapture::BeginCaptureStat("Test");
AssetProcessor::StatsCapture::Shutdown();
}
class StatsCaptureOutputTest : public AssetProcessorTest, public AZ::Debug::TraceMessageBus::Handler
{
public:
void SetUp() override
{
AssetProcessorTest::SetUp();
AssetProcessor::StatsCapture::Initialize();
}
// dump but also capture the dump as a vector of lines:
void Dump()
{
AZ::Debug::TraceMessageBus::Handler::BusConnect();
AssetProcessor::StatsCapture::Dump();
AZ::Debug::TraceMessageBus::Handler::BusDisconnect();
}
virtual bool OnPrintf(const char* /*window*/, const char* message)
{
m_gatheredMessages.emplace_back(message);
AZ::StringFunc::TrimWhiteSpace(m_gatheredMessages.back(), true, true);
return false;
}
void TearDown() override
{
m_gatheredMessages = {};
AssetProcessor::StatsCapture::Shutdown();
AssetProcessorTest::TearDown();
}
AZStd::vector<AZStd::string> m_gatheredMessages;
};
// turning off machine and human readable mode, should not dump anything.
TEST_F(StatsCaptureOutputTest, StatsCaptureTest_DisabledByRegset_DumpsNothing)
{
auto registry = AZ::SettingsRegistry::Get();
ASSERT_NE(registry, nullptr);
registry->Set("/Amazon/AssetProcessor/Settings/Stats/HumanReadable", false);
registry->Set("/Amazon/AssetProcessor/Settings/Stats/MachineReadable", false);
AssetProcessor::StatsCapture::BeginCaptureStat("Test");
AssetProcessor::StatsCapture::EndCaptureStat("Test");
Dump();
EXPECT_EQ(m_gatheredMessages.size(), 0);
}
// turning on Human Readable, turn off Machine Readable, should not output any machine readable stats.
TEST_F(StatsCaptureOutputTest, StatsCaptureTest_HumanReadableOnly_DumpsNoMachineReadable)
{
auto registry = AZ::SettingsRegistry::Get();
ASSERT_NE(registry, nullptr);
registry->Set("/Amazon/AssetProcessor/Settings/Stats/HumanReadable", true);
registry->Set("/Amazon/AssetProcessor/Settings/Stats/MachineReadable", false);
AssetProcessor::StatsCapture::BeginCaptureStat("Test");
AssetProcessor::StatsCapture::EndCaptureStat("Test");
Dump();
EXPECT_GT(m_gatheredMessages.size(), 0);
for (const auto& message : m_gatheredMessages)
{
// we expect to see ZERO "Machine Readable" lines
EXPECT_FALSE(message.contains("MachineReadableStat:")) << "Found unexpected line in output: " << message.c_str();
}
}
// Turn on Machine Readable, Turn off Human Readable, ensure only Machine Readable stats emitted.
TEST_F(StatsCaptureOutputTest, StatsCaptureTest_MachineReadableOnly_DumpsNoHumanReadable)
{
auto registry = AZ::SettingsRegistry::Get();
ASSERT_NE(registry, nullptr);
registry->Set("/Amazon/AssetProcessor/Settings/Stats/HumanReadable", false);
registry->Set("/Amazon/AssetProcessor/Settings/Stats/MachineReadable", true);
AssetProcessor::StatsCapture::BeginCaptureStat("Test");
AssetProcessor::StatsCapture::EndCaptureStat("Test");
Dump();
for (const auto& message : m_gatheredMessages)
{
// we expect to see ONLY "Machine Readable" lines
EXPECT_TRUE(message.contains("MachineReadableStat:")) << "Found unexpected line in output: " << message.c_str();
}
EXPECT_GT(m_gatheredMessages.size(), 0);
}
// The interface for StatsCapture just captures and then dumps.
// For us to test this, we thus have to capture and parse the dump output.
TEST_F(StatsCaptureOutputTest, StatsCaptureTest_Sanity)
{
auto registry = AZ::SettingsRegistry::Get();
ASSERT_NE(registry, nullptr);
// Make it output in "machine raadable" format so that it is simpler to parse.
registry->Set("/Amazon/AssetProcessor/Settings/Stats/HumanReadable", false);
registry->Set("/Amazon/AssetProcessor/Settings/Stats/MachineReadable", true);
AssetProcessor::StatsCapture::BeginCaptureStat("CreateJobs,foo,mybuilder");
AssetProcessor::StatsCapture::EndCaptureStat("CreateJobs,foo,mybuilder");
// Intentionally not using sleeps in this test. It means that the
// captured duration will be likely 0 but its not worth it to slow down tests.
// If the durations end up 0 its going to be extremely noticable in day-to-day use.
AssetProcessor::StatsCapture::BeginCaptureStat("CreateJobs,foo,mybuilder");
AssetProcessor::StatsCapture::EndCaptureStat("CreateJobs,foo,mybuilder");
// for the second stat, we'll double capture and double end, in order to test debounce
AssetProcessor::StatsCapture::BeginCaptureStat("CreateJobs,foo2,mybuilder");
AssetProcessor::StatsCapture::BeginCaptureStat("CreateJobs,foo2,mybuilder");
AssetProcessor::StatsCapture::EndCaptureStat("CreateJobs,foo2,mybuilder2");
AssetProcessor::StatsCapture::EndCaptureStat("CreateJobs,foo2,mybuilder2");
m_gatheredMessages.clear();
Dump();
EXPECT_GT(m_gatheredMessages.size(), 0);
// We'll parse the machine readable stat lines here and make sure that the following is true
// mybuilder appears
// mybuilder appears only once but count is 2
bool foundFoo = false;
bool foundFoo2 = false;
for (const auto& stat : m_gatheredMessages)
{
if (stat.contains("MachineReadableStat:"))
{
AZStd::vector<AZStd::string> tokens;
AZ::StringFunc::Tokenize(stat, tokens, ":", false, false);
ASSERT_EQ(tokens.size(), 5); // should be "MachineReadableStat:time:count:average:name)
const auto& countData = tokens[2];
const auto& nameData = tokens[4];
if (AZ::StringFunc::Equal(nameData, "CreateJobs,foo,mybuilder"))
{
EXPECT_FALSE(foundFoo); // should only find one of these
foundFoo = true;
EXPECT_STREQ(countData.c_str(), "2");
}
if (AZ::StringFunc::Equal(nameData, "CreateJobs,foo2,mybuilder2"))
{
EXPECT_FALSE(foundFoo2); // should only find one of these
foundFoo2 = true;
EXPECT_STREQ(countData.c_str(), "1");
}
}
}
EXPECT_TRUE(foundFoo) << "The expected token CreateJobs,foo,mybuilder did not appear in the output.";
EXPECT_TRUE(foundFoo2) << "The expected CreateJobs.foo2.mybuilder2 did not appear in the output";
}
}
@@ -16,7 +16,8 @@
#include <AzFramework/Logging/LoggingComponent.h>
#include <AzFramework/Asset/AssetSystemComponent.h>
#include "native/resourcecompiler/RCBuilder.h"
#include <native/resourcecompiler/RCBuilder.h>
#include <native/utilities/StatsCapture.h>
#include <QLocale>
#include <QTranslator>
@@ -200,6 +201,10 @@ ApplicationManager::~ApplicationManager()
delete m_appDependencies[idx];
}
// end stats capture (dump and shutdown)
AssetProcessor::StatsCapture::Dump();
AssetProcessor::StatsCapture::Shutdown();
qInstallMessageHandler(nullptr);
//deleting QCoreApplication/QApplication
@@ -571,6 +576,8 @@ bool ApplicationManager::StartAZFramework()
bool ApplicationManager::ActivateModules()
{
AssetProcessor::StatsCapture::BeginCaptureStat("LoadingModules");
// we load the editor xml for our modules since it contains the list of gems we need for tools to function (not just runtime)
connect(&m_frameworkApp, &AssetProcessorAZApplication::AssetProcessorStatus, this,
[this](AssetProcessor::AssetProcessorStatusEntry entry)
@@ -587,6 +594,8 @@ bool ApplicationManager::ActivateModules()
}
m_frameworkApp.LoadDynamicModules();
AssetProcessor::StatsCapture::EndCaptureStat("LoadingModules");
return true;
}
@@ -618,6 +627,9 @@ ApplicationManager::BeforeRunStatus ApplicationManager::BeforeRun()
return ApplicationManager::BeforeRunStatus::Status_Failure;
}
// enable stats capture from this point on
AssetProcessor::StatsCapture::Initialize();
return ApplicationManager::BeforeRunStatus::Status_Success;
}
@@ -1173,6 +1173,7 @@ void ApplicationManagerBase::InitBuilderManager()
{
m_builderManager->ConnectionLost(connId);
});
}
void ApplicationManagerBase::ShutdownBuilderManager()
@@ -0,0 +1,394 @@
/*
* Copyright (c) Contributors to the Open 3D Engine Project.
* For complete copyright and license terms please see the LICENSE at the root of this distribution.
*
* SPDX-License-Identifier: Apache-2.0 OR MIT
*
*/
#include <native/utilities/StatsCapture.h>
#include <native/assetprocessor.h>
#include <AzCore/Memory/SystemAllocator.h>
#include <AzCore/Settings/SettingsRegistry.h>
#include <AzCore/std/chrono/chrono.h>
#include <AzCore/std/chrono/clocks.h>
#include <AzCore/std/string/string.h>
#include <AzCore/std/sort.h>
#include <AzCore/std/containers/unordered_map.h>
#include <AzCore/std/containers/unordered_set.h>
#include <AzCore/std/containers/vector.h>
#include <AzCore/StringFunc/StringFunc.h>
#include <inttypes.h>
namespace AssetProcessor
{
namespace StatsCapture
{
// This class captures stats by storing them in a map of type
// [name of stat] -> Stat struct
// It can then analyze these stats and produce more stats from the original
// Captures, before dumping.
class StatsCaptureImpl final
{
public:
AZ_CLASS_ALLOCATOR(StatsCaptureImpl, AZ::SystemAllocator, 0);
void BeginCaptureStat(AZStd::string_view statName);
void EndCaptureStat(AZStd::string_view statName);
void Dump();
private:
using timepoint = AZStd::chrono::high_resolution_clock::time_point;
using duration = AZStd::chrono::milliseconds;
struct StatsEntry
{
duration m_cumulativeTime = {}; // The total amount of time spent on this.
timepoint m_operationStartTime = {}; // Async tracking - the last time stamp an operation started.
int64_t m_operationCount = 0; // In case there's more than one sample. Used to calc average.
};
AZStd::unordered_map<AZStd::string, StatsEntry> m_stats;
bool m_dumpMachineReadableStats = false;
bool m_dumpHumanReadableStats = true;
// Make a friendly time string of the format nnHnnMhhS.xxxms
AZStd::string FormatDuration(const duration& duration)
{
int64_t milliseconds = duration.count();
constexpr int64_t millisecondsInASecond = 1000;
constexpr int64_t millisecondsInAMinute = millisecondsInASecond * 60;
constexpr int64_t millisecondsInAnHour = millisecondsInAMinute * 60;
int64_t hours = milliseconds / millisecondsInAnHour;
milliseconds -= hours * millisecondsInAnHour;
int64_t minutes = milliseconds / millisecondsInAMinute;
milliseconds -= minutes * millisecondsInAMinute;
int64_t seconds = milliseconds / millisecondsInASecond;
milliseconds -= seconds * millisecondsInASecond;
// omit the sections which dont make sense for readability
if (hours)
{
return AZStd::string::format("%02" PRId64 "h%02" PRId64 "m%02" PRId64 "s%03" PRId64 "ms" , hours, minutes, seconds, milliseconds);
}
else if (minutes)
{
return AZStd::string::format(" %02" PRId64 "m%02" PRId64 "s%03" PRId64 "ms", minutes, seconds, milliseconds);
}
else if (seconds)
{
return AZStd::string::format(" %02" PRId64 "s%03" PRId64 "ms", seconds, milliseconds);
}
return AZStd::string::format(" %03" PRId64 "ms", milliseconds);
}
// Prints out a single stat.
void PrintStat([[maybe_unused]] const char* name, duration milliseconds, int64_t count)
{
// note that name may be unused as it only appears in Trace macros, which are
// stripped out in release builds.
if (count <= 1)
{
count = 1;
}
duration average(static_cast<int64_t>(static_cast<double>(milliseconds.count()) / static_cast<double>(count)));
if (m_dumpHumanReadableStats)
{
if (count > 1)
{
AZ_TracePrintf(AssetProcessor::ConsoleChannel, " Time: %s, Count: %4" PRId64 ", Average: %s, EventName: %s\n",
FormatDuration(milliseconds).c_str(),
count,
FormatDuration(average).c_str(),
name);
}
else
{
AZ_TracePrintf(AssetProcessor::ConsoleChannel, " Time: %s, EventName: %s\n",
FormatDuration(milliseconds).c_str(),
name);
}
}
if (m_dumpMachineReadableStats)
{
// machine Readable mode prints raw milliseconds and uses a CSV-like format
// note that the stat itself may contain commas, so we dont acutally separate with comma
// instead we separate with :
// and each "interesting line" is 'MachineReadableStat:milliseconds:count:average:name'
AZ_TracePrintf(AssetProcessor::ConsoleChannel, "MachineReadableStat:%" PRId64 ":%" PRId64 ":%" PRId64 ":%s\n",
milliseconds.count(),
count,
count > 1 ? average.count() : milliseconds.count(),
name);
}
}
// calls PrintStat on each element in the vector.
void PrintStatsArray(AZStd::vector<AZStd::string>& keys, int maxToPrint, const char* header)
{
if ((m_dumpHumanReadableStats)&&(header))
{
AZ_TracePrintf(AssetProcessor::ConsoleChannel,"Top %i %s\n", maxToPrint, header);
}
auto sortByTimeDescending = [&](const AZStd::string& s1, const AZStd::string& s2)
{
return this->m_stats[s1].m_cumulativeTime > this->m_stats[s2].m_cumulativeTime;
};
AZStd::sort(keys.begin(), keys.end(), sortByTimeDescending);
for (int idx = 0; idx < maxToPrint; ++idx)
{
if (idx < keys.size())
{
PrintStat(keys[idx].c_str(), m_stats[keys[idx]].m_cumulativeTime, m_stats[keys[idx]].m_operationCount);
}
}
}
};
void StatsCaptureImpl::BeginCaptureStat(AZStd::string_view statName)
{
StatsEntry& existingStat = m_stats[statName];
if (existingStat.m_operationStartTime != timepoint())
{
// prevent double 'Begins'
return;
}
existingStat.m_operationStartTime = AZStd::chrono::high_resolution_clock::now();
}
void StatsCaptureImpl::EndCaptureStat(AZStd::string_view statName)
{
StatsEntry& existingStat = m_stats[statName];
if (existingStat.m_operationStartTime != timepoint())
{
existingStat.m_cumulativeTime = AZStd::chrono::high_resolution_clock::now() - existingStat.m_operationStartTime;
existingStat.m_operationCount = existingStat.m_operationCount + 1;
existingStat.m_operationStartTime = timepoint(); // reset the start time so that double 'Ends' are ignored.
}
}
void StatsCaptureImpl::Dump()
{
timepoint startTimeStamp = AZStd::chrono::high_resolution_clock::now();
auto settingsRegistry = AZ::SettingsRegistry::Get();
int maxCumulativeStats = 5; // default max cumulative stats to show
int maxIndividualStats = 5; // default max individual files to show
if (settingsRegistry)
{
AZ::u64 cumulativeStats = static_cast<AZ::u64>(maxCumulativeStats);
AZ::u64 individualStats = static_cast<AZ::u64>(maxIndividualStats);
settingsRegistry->Get(m_dumpHumanReadableStats, "/Amazon/AssetProcessor/Settings/Stats/HumanReadable");
settingsRegistry->Get(m_dumpMachineReadableStats, "/Amazon/AssetProcessor/Settings/Stats/MachineReadable");
settingsRegistry->Get(cumulativeStats, "/Amazon/AssetProcessor/Settings/Stats/MaxCumulativeStats");
settingsRegistry->Get(individualStats, "/Amazon/AssetProcessor/Settings/Stats/MaxIndividualStats");
maxCumulativeStats = static_cast<int>(cumulativeStats);
maxIndividualStats = static_cast<int>(individualStats);
}
if ((!m_dumpHumanReadableStats)&&(!m_dumpMachineReadableStats))
{
return;
}
AZStd::vector<AZStd::string> allCreateJobs; // individual
AZStd::vector<AZStd::string> allCreateJobsByBuilder; // bucketed by builder
AZStd::vector<AZStd::string> allProcessJobs; // individual
AZStd::vector<AZStd::string> allProcessJobsByPlatform; // bucketed by platform
AZStd::vector<AZStd::string> allProcessJobsByJobKey; // bucketed by type of job (job key)
AZStd::vector<AZStd::string> allHashFiles;
// capture only existing keys as we will be expanding the stats
// this approach avoids mutating an iterator.
AZStd::vector<AZStd::string> statKeys;
for (const auto& element : m_stats)
{
statKeys.push_back(element.first);
}
for (const AZStd::string& statKey : statKeys)
{
const StatsEntry& statistic = m_stats[statKey];
// Createjobs stats encode like (CreateJobs,sourcefilepath,builderid)
if (AZ::StringFunc::StartsWith(statKey, "CreateJobs,", true))
{
allCreateJobs.push_back(statKey);
AZStd::vector<AZStd::string> tokens;
AZ::StringFunc::Tokenize(statKey, tokens, ",", false, false);
// look up the builder so you can get its name:
AZStd::string_view builderName = tokens[2];
// synthesize a stat to track per-builder createjobs times:
{
AZStd::string newStatKey = AZStd::string::format("CreateJobsByBuilder,%.*s", AZ_STRING_ARG(builderName));
auto insertion = m_stats.insert(newStatKey);
StatsEntry& statToSynth = insertion.first->second;
statToSynth.m_cumulativeTime += statistic.m_cumulativeTime;
statToSynth.m_operationCount += statistic.m_operationCount;
if (insertion.second)
{
allCreateJobsByBuilder.push_back(newStatKey);
}
}
// synthesize a stat to track total createjobs times:
{
StatsEntry& statToSynth = m_stats["CreateJobsTotal"];
statToSynth.m_cumulativeTime += statistic.m_cumulativeTime;
statToSynth.m_operationCount += statistic.m_operationCount;
}
}
else if (AZ::StringFunc::StartsWith(statKey, "ProcessJob,", true))
{
allProcessJobs.push_back(statKey);
// processjob has the format ProcessJob,sourcename,jobkey,platformname
AZStd::vector<AZStd::string> tokens;
AZ::StringFunc::Tokenize(statKey, tokens, ",", false, false);
AZStd::string_view jobKey = tokens[2];
AZStd::string_view platformName = tokens[3];
// synthesize a stat to record process time accumulated by job key platform
{
AZStd::string newStatKey = AZStd::string::format("ProcessJobsByPlatform,%.*s", AZ_STRING_ARG(platformName));
auto insertion = m_stats.insert(newStatKey);
StatsEntry& statToSynth = insertion.first->second;
statToSynth.m_cumulativeTime += statistic.m_cumulativeTime;
statToSynth.m_operationCount += statistic.m_operationCount;
if (insertion.second)
{
allProcessJobsByPlatform.push_back(newStatKey);
}
}
// synthesize a stat to record process time accumulated job key total across all platforms
{
AZStd::string newStatKey = AZStd::string::format("ProcessJobsByJobKey,%.*s", AZ_STRING_ARG(jobKey));
auto insertion = m_stats.insert(newStatKey);
StatsEntry& statToSynth = insertion.first->second;
statToSynth.m_cumulativeTime += statistic.m_cumulativeTime;
statToSynth.m_operationCount += statistic.m_operationCount;
if (insertion.second)
{
allProcessJobsByJobKey.push_back(newStatKey);
}
}
// synthesize a stat to track total processjob times:
{
StatsEntry& statToSynth = m_stats["ProcessJobsTotal"];
statToSynth.m_cumulativeTime += statistic.m_cumulativeTime;
statToSynth.m_operationCount += statistic.m_operationCount;
}
}
else if (AZ::StringFunc::StartsWith(statKey, "HashFile,", true))
{
allHashFiles.push_back(statKey);
// processjob has the format ProcessJob,sourcename,jobkey,platformname
// synthesize a stat to track total hash times:
StatsEntry& statToSynth = m_stats["HashFileTotal"];
statToSynth.m_cumulativeTime += statistic.m_cumulativeTime;
statToSynth.m_operationCount += statistic.m_operationCount;
}
}
StatsEntry& gemLoadStat = m_stats["LoadingModules"];
PrintStat("LoadingGems", gemLoadStat.m_cumulativeTime, 1);
// analysis-related stats
StatsEntry& totalScanTime = m_stats["AssetScanning"];
PrintStat("AssetScanning", totalScanTime.m_cumulativeTime, totalScanTime.m_operationCount);
StatsEntry& totalHashTime = m_stats["HashFileTotal"];
PrintStat("HashFileTotal", totalHashTime.m_cumulativeTime, totalHashTime.m_operationCount);
PrintStatsArray(allHashFiles, maxIndividualStats, "longest individual file hashes:");
// CreateJobs stats
StatsEntry& totalCreateJobs = m_stats["CreateJobsTotal"];
if (totalCreateJobs.m_operationCount)
{
PrintStat("CreateJobsTotal", totalCreateJobs.m_cumulativeTime, totalCreateJobs.m_operationCount);
PrintStatsArray(allCreateJobs, maxIndividualStats, "longest individual CreateJobs");
PrintStatsArray(allCreateJobsByBuilder, maxCumulativeStats, "longest CreateJobs By builder");
}
// ProcessJobs stats
StatsEntry& totalProcessJobs = m_stats["ProcessJobsTotal"];
if (totalProcessJobs.m_operationCount)
{
PrintStat("ProcessJobsTotal", totalProcessJobs.m_cumulativeTime, totalProcessJobs.m_operationCount);
PrintStatsArray(allProcessJobs, maxIndividualStats, "longest individual ProcessJob");
PrintStatsArray(allProcessJobsByJobKey, maxCumulativeStats, "cumulative time spent in ProcessJob by JobKey");
PrintStatsArray(allProcessJobsByPlatform, maxCumulativeStats, "cumulative time spent in ProcessJob by Platform");
}
duration costToGenerateStats = AZStd::chrono::high_resolution_clock::now() - startTimeStamp;
PrintStat("ComputeStatsTime", costToGenerateStats, 1);
}
// Public interface:
static StatsCaptureImpl* g_instance = nullptr;
//! call this one time before capturing stats.
void Initialize()
{
if (g_instance)
{
AZ_Assert(false, "An instance of StatsCaptureImpl already exists.");
return;
}
g_instance = aznew StatsCaptureImpl();
}
//! Call this one time as part of shutting down.
//! note that while it is an error to double-initialize, it is intentionally
//! not an error to call any other function when uninitialized, allowing this system
//! to essentially be "turned off" just by not initializing it in the first place.
void Shutdown()
{
if (g_instance)
{
delete g_instance;
g_instance = nullptr;
}
}
//! Start the clock running for a particular stat name.
void BeginCaptureStat(AZStd::string_view statName)
{
if (g_instance)
{
g_instance->BeginCaptureStat(statName);
}
}
//! Stop the clock running for a particular stat name.
void EndCaptureStat(AZStd::string_view statName)
{
if (g_instance)
{
g_instance->EndCaptureStat(statName);
}
}
//! Do additional processing and then write the cumulative stats to log.
//! Note that since this is an AP-specific system, the analysis done in the dump function
//! is going to make a lot of assumptions about the way the data is encoded.
void Dump()
{
if (g_instance)
{
g_instance->Dump();
}
}
}
}
@@ -0,0 +1,40 @@
/*
* Copyright (c) Contributors to the Open 3D Engine Project.
* For complete copyright and license terms please see the LICENSE at the root of this distribution.
*
* SPDX-License-Identifier: Apache-2.0 OR MIT
*
*/
// This is an AssetProcessor-only stats capture system. Its kept out-of-band
// from the rest of the Asset Processor systems so that it can avoid interfering
// with the rest of the processing decision making and other parts of AssetProcessor.
// This is not meant to be used anywhere except in AssetProcessor.
#pragma once
#include <AzCore/std/string/string_view.h>
namespace AssetProcessor
{
namespace StatsCapture
{
//! call this one time before capturing stats.
void Initialize();
//! Call this one time as part of shutting down.
void Shutdown();
//! Start the clock running for a particular stat name.
void BeginCaptureStat(AZStd::string_view statName);
//! Stop the clock running for a particular stat name.
void EndCaptureStat(AZStd::string_view statName);
//! Do additional processing and then write the cumulative stats to log.
//! Note that since this is an AP-specific system, the analysis done in the dump function
//! is going to make a lot of assumptions about the way the data is encoded.
void Dump();
}
}
@@ -10,9 +10,10 @@
#include <AzCore/Component/ComponentApplication.h>
#include <AzCore/Math/Sha1.h>
#include "native/utilities/PlatformConfiguration.h"
#include "native/AssetManager/FileStateCache.h"
#include "native/AssetDatabase/AssetDatabase.h"
#include <native/utilities/PlatformConfiguration.h>
#include <native/utilities/StatsCapture.h>
#include <native/AssetManager/FileStateCache.h>
#include <native/AssetDatabase/AssetDatabase.h>
#include <utilities/ThreadHelper.h>
#include <QCoreApplication>
#include <QElapsedTimer>
@@ -19,7 +19,7 @@ namespace O3DE::ProjectManager
{
// Attempt to use the Ninja build system if it is installed (described in the o3de documentation) if possible,
// otherwise default to the the default for Linux (Unix Makefiles)
auto whichNinjaResult = ProjectUtils::ExecuteCommandResult("which", QStringList{"ninja"}, QProcessEnvironment::systemEnvironment());
auto whichNinjaResult = ProjectUtils::ExecuteCommandResult("which", QStringList{"ninja"});
QString cmakeGenerator = (whichNinjaResult.IsSuccess()) ? "Ninja Multi-Config" : "Unix Makefiles";
bool compileProfileOnBuild = (whichNinjaResult.IsSuccess());
@@ -38,7 +38,7 @@ namespace O3DE::ProjectManager
AZ::Outcome<QStringList, QString> ProjectBuilderWorker::ConstructCmakeBuildCommandArguments() const
{
auto whichNinjaResult = ProjectUtils::ExecuteCommandResult("which", QStringList{"ninja"}, QProcessEnvironment::systemEnvironment());
auto whichNinjaResult = ProjectUtils::ExecuteCommandResult("which", QStringList{"ninja"});
bool compileProfileOnBuild = (whichNinjaResult.IsSuccess());
QString targetBuildPath = QDir(m_projectInfo.m_path).filePath(ProjectBuildPathPostfix);
QString launcherTargetName = m_projectInfo.m_projectName + ".GameLauncher";
@@ -19,16 +19,15 @@ namespace O3DE::ProjectManager
// The list of clang C/C++ compiler command lines to validate on the host Linux system
const QStringList SupportedClangVersions = {"13", "12", "11", "10", "9", "8", "7", "6.0"};
AZ::Outcome<QProcessEnvironment, QString> GetCommandLineProcessEnvironment()
AZ::Outcome<void, QString> SetupCommandLineProcessEnvironment()
{
QProcessEnvironment currentEnvironment(QProcessEnvironment::systemEnvironment());
return AZ::Success(currentEnvironment);
return AZ::Success();
}
AZ::Outcome<QString, QString> FindSupportedCompilerForPlatform()
{
// Validate that cmake is installed and is in the command line
auto whichCMakeResult = ProjectUtils::ExecuteCommandResult("which", QStringList{ProjectCMakeCommand}, QProcessEnvironment::systemEnvironment());
auto whichCMakeResult = ProjectUtils::ExecuteCommandResult("which", QStringList{ProjectCMakeCommand});
if (!whichCMakeResult.IsSuccess())
{
return AZ::Failure(QObject::tr("CMake not found. <br><br>"
@@ -39,8 +38,8 @@ namespace O3DE::ProjectManager
// Look for the first compatible version of clang. The list below will contain the known clang compilers that have been tested for O3DE.
for (const QString& supportClangVersion : SupportedClangVersions)
{
auto whichClangResult = ProjectUtils::ExecuteCommandResult("which", QStringList{QString("clang-%1").arg(supportClangVersion)}, QProcessEnvironment::systemEnvironment());
auto whichClangPPResult = ProjectUtils::ExecuteCommandResult("which", QStringList{QString("clang++-%1").arg(supportClangVersion)}, QProcessEnvironment::systemEnvironment());
auto whichClangResult = ProjectUtils::ExecuteCommandResult("which", QStringList{QString("clang-%1").arg(supportClangVersion)});
auto whichClangPPResult = ProjectUtils::ExecuteCommandResult("which", QStringList{QString("clang++-%1").arg(supportClangVersion)});
if (whichClangResult.IsSuccess() && whichClangPPResult.IsSuccess())
{
return AZ::Success(QString("clang-%1").arg(supportClangVersion));
@@ -54,7 +53,7 @@ namespace O3DE::ProjectManager
AZ::Outcome<void, QString> OpenCMakeGUI(const QString& projectPath)
{
AZ::Outcome processEnvResult = GetCommandLineProcessEnvironment();
AZ::Outcome processEnvResult = SetupCommandLineProcessEnvironment();
if (!processEnvResult.IsSuccess())
{
return AZ::Failure(processEnvResult.GetError());
@@ -68,7 +67,6 @@ namespace O3DE::ProjectManager
}
QProcess process;
process.setProcessEnvironment(processEnvResult.GetValue());
// if the project build path is relative, it should be relative to the project path
process.setWorkingDirectory(projectPath);
@@ -88,7 +86,6 @@ namespace O3DE::ProjectManager
return ExecuteCommandResultModalDialog(
QString("%1/python/get_python.sh").arg(engineRoot),
{},
QProcessEnvironment::systemEnvironment(),
QObject::tr("Running get_python script..."));
}
@@ -19,16 +19,14 @@ namespace O3DE::ProjectManager
{
AZ::Outcome<QString, QString> QueryInstalledCmakeFullPath()
{
auto environmentRequest = ProjectUtils::GetCommandLineProcessEnvironment();
auto environmentRequest = ProjectUtils::SetupCommandLineProcessEnvironment();
if (!environmentRequest.IsSuccess())
{
return AZ::Failure(environmentRequest.GetError());
}
auto currentEnvironment = environmentRequest.GetValue();
auto queryCmakeInstalled = ProjectUtils::ExecuteCommandResult("which",
QStringList{ProjectCMakeCommand},
currentEnvironment);
QStringList{ProjectCMakeCommand});
if (!queryCmakeInstalled.IsSuccess())
{
return AZ::Failure(QObject::tr("Unable to detect CMake on this host."));
@@ -18,28 +18,36 @@ namespace O3DE::ProjectManager
{
namespace ProjectUtils
{
AZ::Outcome<QProcessEnvironment, QString> GetCommandLineProcessEnvironment()
AZ::Outcome<void, QString> SetupCommandLineProcessEnvironment()
{
// For CMake on Mac, if its installed through home-brew, then it will be installed
// under /usr/local/bin, which may not be in the system PATH environment.
// Add that path for the command line process so that it will be able to locate
// a home-brew installed version of CMake
QProcessEnvironment currentEnvironment(QProcessEnvironment::systemEnvironment());
QString pathValue = currentEnvironment.value("PATH");
pathValue += ":/usr/local/bin";
currentEnvironment.insert("PATH", pathValue);
return AZ::Success(currentEnvironment);
QString pathEnv = qEnvironmentVariable("PATH");
QStringList pathEnvList = pathEnv.split(":");
if (!pathEnvList.contains("/usr/local/bin"))
{
pathEnv += ":/usr/local/bin";
if (!qputenv("PATH", pathEnv.toStdString().c_str()))
{
return AZ::Failure(QObject::tr("Failed to set PATH environment variable"));
}
}
return AZ::Success();
}
AZ::Outcome<QString, QString> FindSupportedCompilerForPlatform()
{
QProcessEnvironment currentEnvironment(QProcessEnvironment::systemEnvironment());
QString pathValue = currentEnvironment.value("PATH");
pathValue += ":/usr/local/bin";
currentEnvironment.insert("PATH", pathValue);
AZ::Outcome processEnvResult = SetupCommandLineProcessEnvironment();
if (!processEnvResult.IsSuccess())
{
return AZ::Failure(processEnvResult.GetError());
}
// Validate that we have cmake installed first
auto queryCmakeInstalled = ExecuteCommandResult("which", QStringList{ProjectCMakeCommand}, currentEnvironment);
auto queryCmakeInstalled = ExecuteCommandResult("which", QStringList{ProjectCMakeCommand});
if (!queryCmakeInstalled.IsSuccess())
{
return AZ::Failure(QObject::tr("Unable to detect CMake on this host."));
@@ -47,7 +55,7 @@ namespace O3DE::ProjectManager
QString cmakeInstalledPath = queryCmakeInstalled.GetValue().split("\n")[0];
// Query the version of the installed cmake
auto queryCmakeVersionQuery = ExecuteCommandResult(cmakeInstalledPath, QStringList{"-version"}, currentEnvironment);
auto queryCmakeVersionQuery = ExecuteCommandResult(cmakeInstalledPath, QStringList{"-version"});
if (!queryCmakeVersionQuery.IsSuccess())
{
return AZ::Failure(QObject::tr("Unable to determine the version of CMake on this host."));
@@ -55,7 +63,7 @@ namespace O3DE::ProjectManager
AZ_TracePrintf("Project Manager", "Cmake version %s detected.", queryCmakeVersionQuery.GetValue().split("\n")[0].toUtf8().constData());
// Query for the version of xcodebuild (if installed)
auto queryXcodeBuildVersion = ExecuteCommandResult("xcodebuild", QStringList{"-version"}, currentEnvironment);
auto queryXcodeBuildVersion = ExecuteCommandResult("xcodebuild", QStringList{"-version"});
if (!queryCmakeInstalled.IsSuccess())
{
return AZ::Failure(QObject::tr("Unable to detect XCodeBuilder on this host."));
@@ -104,7 +112,6 @@ namespace O3DE::ProjectManager
return ExecuteCommandResultModalDialog(
QString("%1/python/get_python.sh").arg(engineRoot),
{},
QProcessEnvironment::systemEnvironment(),
QObject::tr("Running get_python script..."));
}
@@ -21,7 +21,7 @@ namespace O3DE::ProjectManager
{
namespace ProjectUtils
{
AZ::Outcome<QProcessEnvironment, QString> GetCommandLineProcessEnvironment()
AZ::Outcome<void, QString> SetupCommandLineProcessEnvironment()
{
// Use the engine path to insert a path for cmake
auto engineInfoResult = PythonBindingsInterface::Get()->GetEngineInfo();
@@ -31,26 +31,34 @@ namespace O3DE::ProjectManager
}
auto engineInfo = engineInfoResult.GetValue();
QProcessEnvironment currentEnvironment(QProcessEnvironment::systemEnvironment());
// Append cmake path to PATH incase it is missing
// Append cmake path to the current environment PATH incase it is missing, since if
// we are starting CMake itself the current application needs to find it using Path
// This also takes affect for all child processes.
QDir cmakePath(engineInfo.m_path);
cmakePath.cd("cmake/runtime/bin");
QString pathValue = currentEnvironment.value("PATH");
pathValue += ";" + cmakePath.path();
currentEnvironment.insert("PATH", pathValue);
return AZ::Success(currentEnvironment);
QString pathEnv = qEnvironmentVariable("Path");
QStringList pathEnvList = pathEnv.split(";");
if (!pathEnvList.contains(cmakePath.path()))
{
pathEnv += ";" + cmakePath.path();
if (!qputenv("Path", pathEnv.toStdString().c_str()))
{
return AZ::Failure(QObject::tr("Failed to set Path environment variable"));
}
}
return AZ::Success();
}
AZ::Outcome<QString, QString> FindSupportedCompilerForPlatform()
{
// Validate that cmake is installed
auto cmakeProcessEnvResult = GetCommandLineProcessEnvironment();
auto cmakeProcessEnvResult = SetupCommandLineProcessEnvironment();
if (!cmakeProcessEnvResult.IsSuccess())
{
return AZ::Failure(cmakeProcessEnvResult.GetError());
}
auto cmakeVersionQueryResult = ExecuteCommandResult("cmake", QStringList{"--version"}, cmakeProcessEnvResult.GetValue());
auto cmakeVersionQueryResult = ExecuteCommandResult("cmake", QStringList{"--version"});
if (!cmakeVersionQueryResult.IsSuccess())
{
return AZ::Failure(QObject::tr("CMake not found. \n\n"
@@ -104,7 +112,7 @@ namespace O3DE::ProjectManager
AZ::Outcome<void, QString> OpenCMakeGUI(const QString& projectPath)
{
AZ::Outcome processEnvResult = GetCommandLineProcessEnvironment();
AZ::Outcome processEnvResult = SetupCommandLineProcessEnvironment();
if (!processEnvResult.IsSuccess())
{
return AZ::Failure(processEnvResult.GetError());
@@ -118,7 +126,6 @@ namespace O3DE::ProjectManager
}
QProcess process;
process.setProcessEnvironment(processEnvResult.GetValue());
// if the project build path is relative, it should be relative to the project path
process.setWorkingDirectory(projectPath);
@@ -139,7 +146,6 @@ namespace O3DE::ProjectManager
return ExecuteCommandResultModalDialog(
"cmd.exe",
QStringList{"/c", batPath},
QProcessEnvironment::systemEnvironment(),
QObject::tr("Running get_python script..."));
}
@@ -157,7 +163,7 @@ namespace O3DE::ProjectManager
.arg(shortcutPath)
.arg(targetPath)
.arg(arguments.join(' '));
auto createShortcutResult = ExecuteCommandResult(cmd, QStringList{"-Command", arg}, QProcessEnvironment::systemEnvironment());
auto createShortcutResult = ExecuteCommandResult(cmd, QStringList{"-Command", arg});
if (!createShortcutResult.IsSuccess())
{
return AZ::Failure(QObject::tr("Failed to create desktop shortcut %1 <br><br>"
@@ -117,18 +117,16 @@ namespace O3DE::ProjectManager
// Show some kind of progress with very approximate estimates
UpdateProgress(++m_progressEstimate);
auto currentEnvironmentRequest = ProjectUtils::GetCommandLineProcessEnvironment();
auto currentEnvironmentRequest = ProjectUtils::SetupCommandLineProcessEnvironment();
if (!currentEnvironmentRequest.IsSuccess())
{
QStringToAZTracePrint(currentEnvironmentRequest.GetError());
return AZ::Failure(currentEnvironmentRequest.GetError());
}
QProcessEnvironment currentEnvironment = currentEnvironmentRequest.GetValue();
m_configProjectProcess = new QProcess(this);
m_configProjectProcess->setProcessChannelMode(QProcess::MergedChannels);
m_configProjectProcess->setWorkingDirectory(m_projectInfo.m_path);
m_configProjectProcess->setProcessEnvironment(currentEnvironment);
auto cmakeGenerateArgumentsResult = ConstructCmakeGenerateProjectArguments(engineInfo.m_thirdPartyPath);
if (!cmakeGenerateArgumentsResult.IsSuccess())
@@ -181,7 +179,6 @@ namespace O3DE::ProjectManager
m_buildProjectProcess = new QProcess(this);
m_buildProjectProcess->setProcessChannelMode(QProcess::MergedChannels);
m_buildProjectProcess->setWorkingDirectory(m_projectInfo.m_path);
m_buildProjectProcess->setProcessEnvironment(currentEnvironment);
auto cmakeBuildArgumentsResult = ConstructCmakeBuildCommandArguments();
if (!cmakeBuildArgumentsResult.IsSuccess())
@@ -520,12 +520,10 @@ namespace O3DE::ProjectManager
AZ::Outcome<QString, QString> ExecuteCommandResultModalDialog(
const QString& cmd,
const QStringList& arguments,
const QProcessEnvironment& processEnv,
const QString& title)
{
QString resultOutput;
QProcess execProcess;
execProcess.setProcessEnvironment(processEnv);
execProcess.setProcessChannelMode(QProcess::MergedChannels);
QProgressDialog dialog(title, QObject::tr("Cancel"), /*minimum=*/0, /*maximum=*/0);
@@ -611,11 +609,9 @@ namespace O3DE::ProjectManager
AZ::Outcome<QString, QString> ExecuteCommandResult(
const QString& cmd,
const QStringList& arguments,
const QProcessEnvironment& processEnv,
int commandTimeoutSeconds /*= ProjectCommandLineTimeoutSeconds*/)
{
QProcess execProcess;
execProcess.setProcessEnvironment(processEnv);
execProcess.setProcessChannelMode(QProcess::MergedChannels);
execProcess.start(cmd, arguments);
if (!execProcess.waitForStarted())
@@ -47,7 +47,6 @@ namespace O3DE::ProjectManager
AZ::Outcome<QString, QString> ExecuteCommandResult(
const QString& cmd,
const QStringList& arguments,
const QProcessEnvironment& processEnv,
int commandTimeoutSeconds = ProjectCommandLineTimeoutSeconds);
/**
@@ -61,10 +60,9 @@ namespace O3DE::ProjectManager
AZ::Outcome<QString, QString> ExecuteCommandResultModalDialog(
const QString& cmd,
const QStringList& arguments,
const QProcessEnvironment& processEnv,
const QString& title);
AZ::Outcome<QProcessEnvironment, QString> GetCommandLineProcessEnvironment();
AZ::Outcome<void, QString> SetupCommandLineProcessEnvironment();
AZ::Outcome<QString, QString> GetProjectBuildPath(const QString& projectPath);
AZ::Outcome<void, QString> OpenCMakeGUI(const QString& projectPath);
AZ::Outcome<QString, QString> RunGetPythonScript(const QString& enginePath);