Reduce thread locking on performance statistics collection.

This commit is contained in:
Bill Hollings 2020-04-10 12:18:25 -04:00
parent 0904c49014
commit 7d779a1636
2 changed files with 61 additions and 64 deletions

View File

@ -24,6 +24,7 @@
#include "MVKObjectPool.h"
#include "MVKVector.h"
#include "MVKPixelFormats.h"
#include "MVKOSExtensions.h"
#include "mvk_datatypes.hpp"
#include "vk_mvk_moltenvk.h"
#include <string>
@ -566,9 +567,7 @@ public:
* number of nanoseconds between the two calls. The convenience function mvkGetElapsedMilliseconds()
* can be used to perform this calculation.
*/
inline uint64_t getPerformanceTimestamp() {
return _pMVKConfig->performanceTracking ? getPerformanceTimestampImpl() : 0;
}
inline uint64_t getPerformanceTimestamp() { return _pMVKConfig->performanceTracking ? mvkGetTimestamp() : 0; }
/**
* If performance is being tracked, adds the performance for an activity with a duration
@ -579,7 +578,11 @@ public:
inline void addActivityPerformance(MVKPerformanceTracker& activityTracker,
uint64_t startTime, uint64_t endTime = 0) {
if (_pMVKConfig->performanceTracking) {
addActivityPerformanceImpl(activityTracker, startTime, endTime);
updateActivityPerformance(activityTracker, startTime, endTime);
// Log call not locked. Very minor chance that the tracker data will be updated during log call,
// resulting in an inconsistent report. Not worth taking lock perf hit for rare inline reporting.
if (_logActivityPerformanceInline) { logActivityPerformance(activityTracker, _performanceStatistics, true); }
}
};
@ -693,11 +696,9 @@ protected:
void enableFeatures(const VkDeviceCreateInfo* pCreateInfo);
void enableFeatures(const VkBool32* pEnable, const VkBool32* pRequested, const VkBool32* pAvailable, uint32_t count);
void enableExtensions(const VkDeviceCreateInfo* pCreateInfo);
const char* getActivityPerformanceDescription(MVKPerformanceTracker& activityTracker);
void logActivityPerformance(MVKPerformanceTracker& activityTracker, bool isInline);
uint64_t getPerformanceTimestampImpl();
void addActivityPerformanceImpl(MVKPerformanceTracker& activityTracker,
uint64_t startTime, uint64_t endTime);
const char* getActivityPerformanceDescription(MVKPerformanceTracker& activity, MVKPerformanceStatistics& perfStats);
void logActivityPerformance(MVKPerformanceTracker& activity, MVKPerformanceStatistics& perfStats, bool isInline = false);
void updateActivityPerformance(MVKPerformanceTracker& activity, uint64_t startTime, uint64_t endTime);
MVKPhysicalDevice* _physicalDevice;
MVKCommandResourceFactory* _commandResourceFactory;

View File

@ -33,7 +33,6 @@
#include "MVKCodec.h"
#include "MVKEnvironment.h"
#include "MVKLogging.h"
#include "MVKOSExtensions.h"
#include <MoltenVKSPIRVToMSLConverter/SPIRVToMSLConverter.h>
#include "vk_mvk_moltenvk.h"
@ -2442,77 +2441,74 @@ void MVKDevice::applyMemoryBarrier(VkPipelineStageFlags srcStageMask,
}
}
uint64_t MVKDevice::getPerformanceTimestampImpl() { return mvkGetTimestamp(); }
void MVKDevice::addActivityPerformanceImpl(MVKPerformanceTracker& activityTracker,
uint64_t startTime, uint64_t endTime) {
void MVKDevice::updateActivityPerformance(MVKPerformanceTracker& activity,
uint64_t startTime, uint64_t endTime) {
double currInterval = mvkGetElapsedMilliseconds(startTime, endTime);
lock_guard<mutex> lock(_perfLock);
activityTracker.latestDuration = currInterval;
activityTracker.minimumDuration = ((activityTracker.minimumDuration == 0.0)
? currInterval :
min(currInterval, activityTracker.minimumDuration));
activityTracker.maximumDuration = max(currInterval, activityTracker.maximumDuration);
double totalInterval = (activityTracker.averageDuration * activityTracker.count++) + currInterval;
activityTracker.averageDuration = totalInterval / activityTracker.count;
if (_logActivityPerformanceInline) { logActivityPerformance(activityTracker, true); }
activity.latestDuration = currInterval;
activity.minimumDuration = ((activity.minimumDuration == 0.0)
? currInterval :
min(currInterval, activity.minimumDuration));
activity.maximumDuration = max(currInterval, activity.maximumDuration);
double totalInterval = (activity.averageDuration * activity.count++) + currInterval;
activity.averageDuration = totalInterval / activity.count;
}
void MVKDevice::logActivityPerformance(MVKPerformanceTracker& activityTracker, bool isInline) {
void MVKDevice::logActivityPerformance(MVKPerformanceTracker& activity, MVKPerformanceStatistics& perfStats, bool isInline) {
MVKLogInfo("%s%s%s avg: %.3f ms, latest: %.3f ms, min: %.3f ms, max: %.3f ms, count: %d",
(isInline ? "" : " "),
getActivityPerformanceDescription(activityTracker),
getActivityPerformanceDescription(activity, perfStats),
(isInline ? " performance" : ""),
activityTracker.averageDuration,
activityTracker.latestDuration,
activityTracker.minimumDuration,
activityTracker.maximumDuration,
activityTracker.count);
activity.averageDuration,
activity.latestDuration,
activity.minimumDuration,
activity.maximumDuration,
activity.count);
}
void MVKDevice::logPerformanceSummary() {
if (_logActivityPerformanceInline) { return; }
lock_guard<mutex> lock(_perfLock);
// Get a copy to minimize time under lock
MVKPerformanceStatistics perfStats;
getPerformanceStatistics(&perfStats);
bool isInline = false;
logActivityPerformance(_performanceStatistics.queue.frameInterval, isInline);
logActivityPerformance(_performanceStatistics.queue.nextCAMetalDrawable, isInline);
logActivityPerformance(_performanceStatistics.queue.mtlCommandBufferCompletion, isInline);
logActivityPerformance(_performanceStatistics.queue.mtlQueueAccess, isInline);
logActivityPerformance(_performanceStatistics.shaderCompilation.hashShaderCode, isInline);
logActivityPerformance(_performanceStatistics.shaderCompilation.spirvToMSL, isInline);
logActivityPerformance(_performanceStatistics.shaderCompilation.mslCompile, isInline);
logActivityPerformance(_performanceStatistics.shaderCompilation.mslLoad, isInline);
logActivityPerformance(_performanceStatistics.shaderCompilation.shaderLibraryFromCache, isInline);
logActivityPerformance(_performanceStatistics.shaderCompilation.functionRetrieval, isInline);
logActivityPerformance(_performanceStatistics.shaderCompilation.functionSpecialization, isInline);
logActivityPerformance(_performanceStatistics.shaderCompilation.pipelineCompile, isInline);
logActivityPerformance(_performanceStatistics.pipelineCache.sizePipelineCache, isInline);
logActivityPerformance(_performanceStatistics.pipelineCache.readPipelineCache, isInline);
logActivityPerformance(_performanceStatistics.pipelineCache.writePipelineCache, isInline);
logActivityPerformance(perfStats.queue.frameInterval, perfStats);
logActivityPerformance(perfStats.queue.nextCAMetalDrawable, perfStats);
logActivityPerformance(perfStats.queue.mtlCommandBufferCompletion, perfStats);
logActivityPerformance(perfStats.queue.mtlQueueAccess, perfStats);
logActivityPerformance(perfStats.shaderCompilation.hashShaderCode, perfStats);
logActivityPerformance(perfStats.shaderCompilation.spirvToMSL, perfStats);
logActivityPerformance(perfStats.shaderCompilation.mslCompile, perfStats);
logActivityPerformance(perfStats.shaderCompilation.mslLoad, perfStats);
logActivityPerformance(perfStats.shaderCompilation.shaderLibraryFromCache, perfStats);
logActivityPerformance(perfStats.shaderCompilation.functionRetrieval, perfStats);
logActivityPerformance(perfStats.shaderCompilation.functionSpecialization, perfStats);
logActivityPerformance(perfStats.shaderCompilation.pipelineCompile, perfStats);
logActivityPerformance(perfStats.pipelineCache.sizePipelineCache, perfStats);
logActivityPerformance(perfStats.pipelineCache.readPipelineCache, perfStats);
logActivityPerformance(perfStats.pipelineCache.writePipelineCache, perfStats);
}
const char* MVKDevice::getActivityPerformanceDescription(MVKPerformanceTracker& activityTracker) {
if (&activityTracker == &_performanceStatistics.shaderCompilation.hashShaderCode) { return "Hash shader SPIR-V code"; }
if (&activityTracker == &_performanceStatistics.shaderCompilation.spirvToMSL) { return "Convert SPIR-V to MSL source code"; }
if (&activityTracker == &_performanceStatistics.shaderCompilation.mslCompile) { return "Compile MSL source code into a MTLLibrary"; }
if (&activityTracker == &_performanceStatistics.shaderCompilation.mslLoad) { return "Load pre-compiled MSL code into a MTLLibrary"; }
if (&activityTracker == &_performanceStatistics.shaderCompilation.shaderLibraryFromCache) { return "Retrieve shader library from the cache"; }
if (&activityTracker == &_performanceStatistics.shaderCompilation.functionRetrieval) { return "Retrieve a MTLFunction from a MTLLibrary"; }
if (&activityTracker == &_performanceStatistics.shaderCompilation.functionSpecialization) { return "Specialize a retrieved MTLFunction"; }
if (&activityTracker == &_performanceStatistics.shaderCompilation.pipelineCompile) { return "Compile MTLFunctions into a pipeline"; }
if (&activityTracker == &_performanceStatistics.pipelineCache.sizePipelineCache) { return "Calculate cache size required to write MSL to pipeline cache"; }
if (&activityTracker == &_performanceStatistics.pipelineCache.readPipelineCache) { return "Read MSL from pipeline cache"; }
if (&activityTracker == &_performanceStatistics.pipelineCache.writePipelineCache) { return "Write MSL to pipeline cache"; }
if (&activityTracker == &_performanceStatistics.queue.mtlQueueAccess) { return "Access MTLCommandQueue"; }
if (&activityTracker == &_performanceStatistics.queue.mtlCommandBufferCompletion) { return "Complete MTLCommandBuffer"; }
if (&activityTracker == &_performanceStatistics.queue.nextCAMetalDrawable) { return "Retrieve a CAMetalDrawable from CAMetalLayer"; }
if (&activityTracker == &_performanceStatistics.queue.frameInterval) { return "Frame interval"; }
return "Unknown performance activity";
const char* MVKDevice::getActivityPerformanceDescription(MVKPerformanceTracker& activity, MVKPerformanceStatistics& perfStats) {
if (&activity == &perfStats.shaderCompilation.hashShaderCode) { return "Hash shader SPIR-V code"; }
if (&activity == &perfStats.shaderCompilation.spirvToMSL) { return "Convert SPIR-V to MSL source code"; }
if (&activity == &perfStats.shaderCompilation.mslCompile) { return "Compile MSL source code into a MTLLibrary"; }
if (&activity == &perfStats.shaderCompilation.mslLoad) { return "Load pre-compiled MSL code into a MTLLibrary"; }
if (&activity == &perfStats.shaderCompilation.shaderLibraryFromCache) { return "Retrieve shader library from the cache"; }
if (&activity == &perfStats.shaderCompilation.functionRetrieval) { return "Retrieve a MTLFunction from a MTLLibrary"; }
if (&activity == &perfStats.shaderCompilation.functionSpecialization) { return "Specialize a retrieved MTLFunction"; }
if (&activity == &perfStats.shaderCompilation.pipelineCompile) { return "Compile MTLFunctions into a pipeline"; }
if (&activity == &perfStats.pipelineCache.sizePipelineCache) { return "Calculate cache size required to write MSL to pipeline cache"; }
if (&activity == &perfStats.pipelineCache.readPipelineCache) { return "Read MSL from pipeline cache"; }
if (&activity == &perfStats.pipelineCache.writePipelineCache) { return "Write MSL to pipeline cache"; }
if (&activity == &perfStats.queue.mtlQueueAccess) { return "Access MTLCommandQueue"; }
if (&activity == &perfStats.queue.mtlCommandBufferCompletion) { return "Complete MTLCommandBuffer"; }
if (&activity == &perfStats.queue.nextCAMetalDrawable) { return "Retrieve a CAMetalDrawable from CAMetalLayer"; }
if (&activity == &perfStats.queue.frameInterval) { return "Frame interval"; }
return "Unknown performance activity";
}
void MVKDevice::getPerformanceStatistics(MVKPerformanceStatistics* pPerf) {