Add chrome tracing support

This commit is contained in:
Ryan Huffman 2016-11-22 16:45:53 -08:00 committed by Brad Davis
parent ba8b585368
commit 7bb2755913
76 changed files with 987 additions and 176 deletions

View file

@ -37,6 +37,7 @@
#include "AssignmentClient.h"
#include "AssignmentClientLogging.h"
#include "avatars/ScriptableAvatar.h"
#include <Trace.h>
const QString ASSIGNMENT_CLIENT_TARGET_NAME = "assignment-client";
const long long ASSIGNMENT_REQUEST_INTERVAL_MSECS = 1 * 1000;
@ -48,6 +49,7 @@ AssignmentClient::AssignmentClient(Assignment::Type requestAssignmentType, QStri
{
LogUtils::init();
DependencyManager::set<tracing::Tracer>();
DependencyManager::set<AccountManager>();
auto scriptableAvatar = DependencyManager::set<ScriptableAvatar>();

View file

@ -43,6 +43,7 @@
#include "DomainServerNodeData.h"
#include "NodeConnectionData.h"
#include <Trace.h>
int const DomainServer::EXIT_CODE_REBOOT = 234923;
@ -73,6 +74,8 @@ DomainServer::DomainServer(int argc, char* argv[]) :
{
parseCommandLine();
DependencyManager::set<tracing::Tracer>();
LogUtils::init();
Setting::init();

View file

@ -46,6 +46,8 @@
#include <gl/QOpenGLContextWrapper.h>
#include <shared/GlobalAppProperties.h>
#include <StatTracker.h>
#include <Trace.h>
#include <ResourceScriptingInterface.h>
#include <AccountManager.h>
#include <AddressManager.h>
@ -423,6 +425,8 @@ bool setupEssentials(int& argc, char** argv) {
steamClient->init();
}
DependencyManager::set<tracing::Tracer>();
#if defined(Q_OS_WIN)
// Select appropriate audio DLL
QString audioDLLPath = QCoreApplication::applicationDirPath();
@ -445,6 +449,7 @@ bool setupEssentials(int& argc, char** argv) {
// Set dependencies
DependencyManager::set<AccountManager>(std::bind(&Application::getUserAgent, qApp));
DependencyManager::set<StatTracker>();
DependencyManager::set<ScriptEngines>();
DependencyManager::set<Preferences>();
DependencyManager::set<recording::Deck>();
@ -557,6 +562,7 @@ Application::Application(int& argc, char** argv, QElapsedTimer& startupTimer, bo
{
const QString TEST_SCRIPT = "--testScript";
const QString TRACE_FILE = "--traceFile";
const QStringList args = arguments();
for (int i = 0; i < args.size() - 1; ++i) {
if (args.at(i) == TEST_SCRIPT) {
@ -564,6 +570,10 @@ Application::Application(int& argc, char** argv, QElapsedTimer& startupTimer, bo
if (QFileInfo(testScriptPath).exists()) {
setProperty(hifi::properties::TEST, QUrl::fromLocalFile(testScriptPath));
}
} else if (args.at(i) == TRACE_FILE) {
QString traceFilePath = args.at(i + 1);
setProperty(hifi::properties::TRACING, traceFilePath);
DependencyManager::get<tracing::Tracer>()->startTracing();
}
}
}
@ -1572,6 +1582,13 @@ void Application::cleanupBeforeQuit() {
QString webengineRemoteDebugging = QProcessEnvironment::systemEnvironment().value("QTWEBENGINE_REMOTE_DEBUGGING", "false");
qCDebug(interfaceapp) << "QTWEBENGINE_REMOTE_DEBUGGING =" << webengineRemoteDebugging;
if (tracing::enabled()) {
auto tracer = DependencyManager::get<tracing::Tracer>();
tracer->stopTracing();
auto outputFile = property(hifi::properties::TRACING).toString();
tracer->serialize(outputFile);
}
// Stop third party processes so that they're not left running in the event of a subsequent shutdown crash.
#ifdef HAVE_DDE
DependencyManager::get<DdeFaceTracker>()->setEnabled(false);
@ -1928,6 +1945,16 @@ void Application::initializeUi() {
}
void Application::paintGL() {
PROFILE_COUNTER(interfaceapp, "fps", { { "fps", _frameCounter.rate() } });
PROFILE_COUNTER(interfaceapp, "downloads", {
{ "current", ResourceCache::getLoadingRequests().length() },
{ "pending", ResourceCache::getPendingRequestCount() }
});
PROFILE_COUNTER(interfaceapp, "processing", {
{ "current", DependencyManager::get<StatTracker>()->getStat("Processing") },
{ "pending", DependencyManager::get<StatTracker>()->getStat("PendingProcessing") }
});
// Some plugins process message events, allowing paintGL to be called reentrantly.
if (_inPaint || _aboutToQuit) {
return;
@ -1939,7 +1966,7 @@ void Application::paintGL() {
_frameCount++;
auto lastPaintBegin = usecTimestampNow();
PROFILE_RANGE_EX(__FUNCTION__, 0xff0000ff, (uint64_t)_frameCount);
PROFILE_RANGE_EX(interfaceapp, __FUNCTION__, 0xff0000ff, (uint64_t)_frameCount);
PerformanceTimer perfTimer("paintGL");
if (nullptr == _displayPlugin) {
@ -2116,7 +2143,7 @@ void Application::paintGL() {
auto finalFramebuffer = framebufferCache->getFramebuffer();
{
PROFILE_RANGE(__FUNCTION__ "/mainRender");
PROFILE_RANGE(interfaceapp, "/mainRender");
PerformanceTimer perfTimer("mainRender");
renderArgs._boomOffset = boomOffset;
// Viewport is assigned to the size of the framebuffer
@ -2171,7 +2198,7 @@ void Application::paintGL() {
frame->overlay = _applicationOverlay.getOverlayTexture();
// deliver final scene rendering commands to the display plugin
{
PROFILE_RANGE(__FUNCTION__ "/pluginOutput");
PROFILE_RANGE(interfaceapp, "/pluginOutput");
PerformanceTimer perfTimer("pluginOutput");
_frameCounter.increment();
displayPlugin->submitFrame(frame);
@ -2259,7 +2286,7 @@ void Application::resizeEvent(QResizeEvent* event) {
}
void Application::resizeGL() {
PROFILE_RANGE(__FUNCTION__);
PROFILE_RANGE(interfaceapp, __FUNCTION__);
if (nullptr == _displayPlugin) {
return;
}
@ -2314,7 +2341,6 @@ bool Application::importSVOFromURL(const QString& urlString) {
}
bool Application::event(QEvent* event) {
if (!Menu::getInstance()) {
return false;
}
@ -2905,7 +2931,7 @@ void Application::maybeToggleMenuVisible(QMouseEvent* event) const {
}
void Application::mouseMoveEvent(QMouseEvent* event) {
PROFILE_RANGE(__FUNCTION__);
PROFILE_RANGE(interfaceapp, __FUNCTION__);
if (_aboutToQuit) {
return;
@ -3213,7 +3239,7 @@ void Application::idle(float nsecsElapsed) {
connect(offscreenUi.data(), &OffscreenUi::showDesktop, this, &Application::showDesktop);
}
PROFILE_RANGE(__FUNCTION__);
PROFILE_RANGE(interfaceapp, __FUNCTION__);
if (auto steamClient = PluginManager::getInstance()->getSteamClientPlugin()) {
steamClient->runCallbacks();
@ -3930,9 +3956,11 @@ void Application::updateDialogs(float deltaTime) const {
}
}
static bool domainLoadingInProgress = false;
void Application::update(float deltaTime) {
PROFILE_RANGE_EX(__FUNCTION__, 0xffff0000, (uint64_t)_frameCount + 1);
PROFILE_RANGE_EX(interfaceapp, __FUNCTION__, 0xffff0000, (uint64_t)_frameCount + 1);
bool showWarnings = Menu::getInstance()->isOptionChecked(MenuOption::PipelineWarnings);
PerformanceWarning warn(showWarnings, "Application::update()");
@ -3940,6 +3968,11 @@ void Application::update(float deltaTime) {
updateLOD();
if (!_physicsEnabled) {
if (!domainLoadingInProgress) {
PROFILE_ASYNC_BEGIN(interfaceapp, "Scene Loading", "");
domainLoadingInProgress = true;
}
// we haven't yet enabled physics. we wait until we think we have all the collision information
// for nearby entities before starting bullet up.
quint64 now = usecTimestampNow();
@ -3969,6 +4002,9 @@ void Application::update(float deltaTime) {
}
}
}
} else if (domainLoadingInProgress) {
domainLoadingInProgress = false;
PROFILE_ASYNC_END(interfaceapp, "Scene Loading", "");
}
{
@ -4062,12 +4098,12 @@ void Application::update(float deltaTime) {
QSharedPointer<AvatarManager> avatarManager = DependencyManager::get<AvatarManager>();
if (_physicsEnabled) {
PROFILE_RANGE_EX("Physics", 0xffff0000, (uint64_t)getActiveDisplayPlugin()->presentCount());
PROFILE_RANGE_EX(interfaceapp, "Physics", 0xffff0000, (uint64_t)getActiveDisplayPlugin()->presentCount());
PerformanceTimer perfTimer("physics");
{
PROFILE_RANGE_EX("UpdateStats", 0xffffff00, (uint64_t)getActiveDisplayPlugin()->presentCount());
PROFILE_RANGE_EX(interfaceapp, "UpdateStats", 0xffffff00, (uint64_t)getActiveDisplayPlugin()->presentCount());
PerformanceTimer perfTimer("updateStates)");
static VectorOfMotionStates motionStates;
@ -4101,14 +4137,14 @@ void Application::update(float deltaTime) {
});
}
{
PROFILE_RANGE_EX("StepSimulation", 0xffff8000, (uint64_t)getActiveDisplayPlugin()->presentCount());
PROFILE_RANGE_EX(interfaceapp, "StepSimulation", 0xffff8000, (uint64_t)getActiveDisplayPlugin()->presentCount());
PerformanceTimer perfTimer("stepSimulation");
getEntities()->getTree()->withWriteLock([&] {
_physicsEngine->stepSimulation();
});
}
{
PROFILE_RANGE_EX("HarvestChanges", 0xffffff00, (uint64_t)getActiveDisplayPlugin()->presentCount());
PROFILE_RANGE_EX(interfaceapp, "HarvestChanges", 0xffffff00, (uint64_t)getActiveDisplayPlugin()->presentCount());
PerformanceTimer perfTimer("harvestChanges");
if (_physicsEngine->hasOutgoingChanges()) {
getEntities()->getTree()->withWriteLock([&] {
@ -4150,20 +4186,20 @@ void Application::update(float deltaTime) {
_avatarSimCounter.increment();
{
PROFILE_RANGE_EX("OtherAvatars", 0xffff00ff, (uint64_t)getActiveDisplayPlugin()->presentCount());
PROFILE_RANGE_EX(interfaceapp, "OtherAvatars", 0xffff00ff, (uint64_t)getActiveDisplayPlugin()->presentCount());
avatarManager->updateOtherAvatars(deltaTime);
}
qApp->updateMyAvatarLookAtPosition();
{
PROFILE_RANGE_EX("MyAvatar", 0xffff00ff, (uint64_t)getActiveDisplayPlugin()->presentCount());
PROFILE_RANGE_EX(interfaceapp, "MyAvatar", 0xffff00ff, (uint64_t)getActiveDisplayPlugin()->presentCount());
avatarManager->updateMyAvatar(deltaTime);
}
}
{
PROFILE_RANGE_EX("Overlays", 0xffff0000, (uint64_t)getActiveDisplayPlugin()->presentCount());
PROFILE_RANGE_EX(interfaceapp, "Overlays", 0xffff0000, (uint64_t)getActiveDisplayPlugin()->presentCount());
PerformanceTimer perfTimer("overlays");
_overlays.update(deltaTime);
}
@ -4183,7 +4219,7 @@ void Application::update(float deltaTime) {
// Update my voxel servers with my current voxel query...
{
PROFILE_RANGE_EX("QueryOctree", 0xffff0000, (uint64_t)getActiveDisplayPlugin()->presentCount());
PROFILE_RANGE_EX(interfaceapp, "QueryOctree", 0xffff0000, (uint64_t)getActiveDisplayPlugin()->presentCount());
QMutexLocker viewLocker(&_viewMutex);
PerformanceTimer perfTimer("queryOctree");
quint64 sinceLastQuery = now - _lastQueriedTime;
@ -4223,7 +4259,7 @@ void Application::update(float deltaTime) {
avatarManager->postUpdate(deltaTime);
{
PROFILE_RANGE_EX("PreRenderLambdas", 0xffff0000, (uint64_t)0);
PROFILE_RANGE_EX(interfaceapp, "PreRenderLambdas", 0xffff0000, (uint64_t)0);
std::unique_lock<std::mutex> guard(_postUpdateLambdasLock);
for (auto& iter : _postUpdateLambdas) {
@ -4501,7 +4537,7 @@ QRect Application::getDesirableApplicationGeometry() const {
//
void Application::loadViewFrustum(Camera& camera, ViewFrustum& viewFrustum) {
PerformanceTimer perfTimer("loadViewFrustum");
PROFILE_RANGE(__FUNCTION__);
PROFILE_RANGE(interfaceapp, __FUNCTION__);
// We will use these below, from either the camera or head vectors calculated above
viewFrustum.setProjection(camera.getProjection());
@ -4677,7 +4713,7 @@ void Application::displaySide(RenderArgs* renderArgs, Camera& theCamera, bool se
myAvatar->preDisplaySide(renderArgs);
activeRenderingThread = QThread::currentThread();
PROFILE_RANGE(__FUNCTION__);
PROFILE_RANGE(interfaceapp, __FUNCTION__);
PerformanceTimer perfTimer("display");
PerformanceWarning warn(Menu::getInstance()->isOptionChecked(MenuOption::PipelineWarnings), "Application::displaySide()");

View file

@ -10,6 +10,10 @@
#include "TestScriptingInterface.h"
#include <QtCore/QCoreApplication>
#include <QtCore/QLoggingCategory>
#include <DependencyManager.h>
#include <Trace.h>
TestScriptingInterface* TestScriptingInterface::getInstance() {
static TestScriptingInterface sharedInstance;
@ -28,3 +32,27 @@ void TestScriptingInterface::waitForDownloadIdle() {
void TestScriptingInterface::waitIdle() {
}
bool TestScriptingInterface::startTracing(QString logrules) {
if (!logrules.isEmpty()) {
QLoggingCategory::setFilterRules(logrules);
}
if (!DependencyManager::isSet<tracing::Tracer>()) {
return false;
}
DependencyManager::get<tracing::Tracer>()->startTracing();
return true;
}
bool TestScriptingInterface::stopTracing(QString filename) {
if (!DependencyManager::isSet<tracing::Tracer>()) {
return false;
}
auto tracer = DependencyManager::get<tracing::Tracer>();
tracer->stopTracing();
tracer->serialize(filename);
return true;
}

View file

@ -38,6 +38,17 @@ public slots:
*/
void waitIdle();
/**jsdoc
* Start recording Chrome compatible tracing events
* logRules can be used to specify a set of logging category rules to limit what gets captured
*/
bool startTracing(QString logrules = "");
/**jsdoc
* Stop recording Chrome compatible tracing events and serialize recorded events to a file
* Using a filename with a .gz extension will automatically compress the output file
*/
bool stopTracing(QString filename);
};
#endif // hifi_TestScriptingInterface_h

View file

@ -29,6 +29,7 @@
#include "ui/Stats.h"
#include "ui/AvatarInputs.h"
#include "OffscreenUi.h"
#include "InterfaceLogging.h"
#include <QQmlContext>
const vec4 CONNECTION_STATUS_BORDER_COLOR{ 1.0f, 0.0f, 0.0f, 0.8f };
@ -56,7 +57,7 @@ ApplicationOverlay::~ApplicationOverlay() {
// Renders the overlays either to a texture or to the screen
void ApplicationOverlay::renderOverlay(RenderArgs* renderArgs) {
PROFILE_RANGE(__FUNCTION__);
PROFILE_RANGE(interfaceapp, __FUNCTION__);
PerformanceWarning warn(Menu::getInstance()->isOptionChecked(MenuOption::PipelineWarnings), "ApplicationOverlay::displayOverlay()");
buildFramebufferObject();
@ -95,7 +96,7 @@ void ApplicationOverlay::renderOverlay(RenderArgs* renderArgs) {
}
void ApplicationOverlay::renderQmlUi(RenderArgs* renderArgs) {
PROFILE_RANGE(__FUNCTION__);
PROFILE_RANGE(interfaceapp, __FUNCTION__);
if (!_uiTexture) {
_uiTexture = gpu::TexturePointer(gpu::Texture::createExternal2D(OffscreenQmlSurface::getDiscardLambda()));
@ -123,7 +124,7 @@ void ApplicationOverlay::renderQmlUi(RenderArgs* renderArgs) {
}
void ApplicationOverlay::renderAudioScope(RenderArgs* renderArgs) {
PROFILE_RANGE(__FUNCTION__);
PROFILE_RANGE(interfaceapp, __FUNCTION__);
gpu::Batch& batch = *renderArgs->_batch;
auto geometryCache = DependencyManager::get<GeometryCache>();
@ -142,7 +143,7 @@ void ApplicationOverlay::renderAudioScope(RenderArgs* renderArgs) {
}
void ApplicationOverlay::renderOverlays(RenderArgs* renderArgs) {
PROFILE_RANGE(__FUNCTION__);
PROFILE_RANGE(interfaceapp, __FUNCTION__);
gpu::Batch& batch = *renderArgs->_batch;
auto geometryCache = DependencyManager::get<GeometryCache>();
@ -261,7 +262,7 @@ static const auto DEFAULT_SAMPLER = gpu::Sampler(gpu::Sampler::FILTER_MIN_MAG_LI
static const auto DEPTH_FORMAT = gpu::Element(gpu::SCALAR, gpu::FLOAT, gpu::DEPTH);
void ApplicationOverlay::buildFramebufferObject() {
PROFILE_RANGE(__FUNCTION__);
PROFILE_RANGE(interfaceapp, __FUNCTION__);
auto uiSize = qApp->getUiSize();
if (!_overlayFramebuffer || uiSize != _overlayFramebuffer->getSize()) {
@ -287,4 +288,4 @@ gpu::TexturePointer ApplicationOverlay::getOverlayTexture() {
return gpu::TexturePointer();
}
return _overlayFramebuffer->getRenderBuffer(0);
}
}

View file

@ -19,6 +19,7 @@
#include <RegisteredMetaTypes.h>
#include "Application.h"
#include "InterfaceLogging.h"
#include "Image3DOverlay.h"
#include "Circle3DOverlay.h"
#include "Cube3DOverlay.h"
@ -101,7 +102,7 @@ void Overlays::cleanupOverlaysToDelete() {
}
void Overlays::renderHUD(RenderArgs* renderArgs) {
PROFILE_RANGE(__FUNCTION__);
PROFILE_RANGE(interfaceapp, __FUNCTION__);
QReadLocker lock(&_lock);
gpu::Batch& batch = *renderArgs->_batch;

View file

@ -394,7 +394,7 @@ const AnimPoseVec& AnimInverseKinematics::overlay(const AnimVariantMap& animVars
loadPoses(underPoses);
} else {
PROFILE_RANGE_EX("ik/relax", 0xffff00ff, 0);
PROFILE_RANGE_EX(animation, "ik/relax", 0xffff00ff, 0);
// relax toward underPoses
// HACK: this relaxation needs to be constant per-frame rather than per-realtime
@ -433,7 +433,7 @@ const AnimPoseVec& AnimInverseKinematics::overlay(const AnimVariantMap& animVars
// build a list of targets from _targetVarVec
std::vector<IKTarget> targets;
{
PROFILE_RANGE_EX("ik/computeTargets", 0xffff00ff, 0);
PROFILE_RANGE_EX(animation, "ik/computeTargets", 0xffff00ff, 0);
computeTargets(animVars, targets, underPoses);
}
@ -450,7 +450,7 @@ const AnimPoseVec& AnimInverseKinematics::overlay(const AnimVariantMap& animVars
} else {
{
PROFILE_RANGE_EX("ik/shiftHips", 0xffff00ff, 0);
PROFILE_RANGE_EX(animation, "ik/shiftHips", 0xffff00ff, 0);
// shift hips according to the _hipsOffset from the previous frame
float offsetLength = glm::length(_hipsOffset);
@ -476,12 +476,12 @@ const AnimPoseVec& AnimInverseKinematics::overlay(const AnimVariantMap& animVars
}
{
PROFILE_RANGE_EX("ik/ccd", 0xffff00ff, 0);
PROFILE_RANGE_EX(animation, "ik/ccd", 0xffff00ff, 0);
solveWithCyclicCoordinateDescent(targets);
}
{
PROFILE_RANGE_EX("ik/measureHipsOffset", 0xffff00ff, 0);
PROFILE_RANGE_EX(animation, "ik/measureHipsOffset", 0xffff00ff, 0);
// measure new _hipsOffset for next frame
// by looking for discrepancies between where a targeted endEffector is

View file

@ -14,6 +14,9 @@
#include "AnimationCache.h"
#include "AnimationLogging.h"
#include <Trace.h>
#include <StatTracker.h>
#include <Profile.h>
int animationPointerMetaTypeId = qRegisterMetaType<AnimationPointer>();
@ -45,9 +48,14 @@ Animation::Animation(const QUrl& url) : Resource(url) {}
AnimationReader::AnimationReader(const QUrl& url, const QByteArray& data) :
_url(url),
_data(data) {
DependencyManager::get<StatTracker>()->incrementStat("PendingProcessing");
}
void AnimationReader::run() {
DependencyManager::get<StatTracker>()->decrementStat("PendingProcessing");
CounterStat counter("Processing");
PROFILE_RANGE_EX(animation, __FUNCTION__, 0xFF00FF00, 0, { { "url", _url.toString() } });
auto originalPriority = QThread::currentThread()->priority();
if (originalPriority == QThread::InheritPriority) {
originalPriority = QThread::NormalPriority;

View file

@ -65,6 +65,8 @@ public:
explicit Animation(const QUrl& url);
QString getType() const override { return "Animation"; }
const FBXGeometry& getGeometry() const { return *_geometry; }
virtual bool isLoaded() const override;

View file

@ -882,7 +882,7 @@ void Rig::updateAnimationStateHandlers() { // called on avatar update thread (wh
void Rig::updateAnimations(float deltaTime, glm::mat4 rootTransform) {
PROFILE_RANGE_EX(__FUNCTION__, 0xffff00ff, 0);
PROFILE_RANGE_EX(animation, __FUNCTION__, 0xffff00ff, 0);
setModelOffset(rootTransform);

View file

@ -16,7 +16,6 @@
#include <QtOpenGL/QGLWidget>
#include <QtGui/QImage>
#if defined(Q_OS_MAC)
#include <OpenGL/CGLCurrent.h>
#endif
@ -44,6 +43,7 @@
#include <CursorManager.h>
#include "CompositorHelper.h"
#include "Logging.h"
const char* SRGB_TO_LINEAR_FRAG = R"SCRIBE(
@ -129,7 +129,7 @@ public:
_context->makeCurrent();
while (!_shutdown) {
if (_pendingMainThreadOperation) {
PROFILE_RANGE("MainThreadOp")
PROFILE_RANGE(displayPlugins, "MainThreadOp")
{
Lock lock(_mutex);
_context->doneCurrent();
@ -203,7 +203,7 @@ public:
// Execute the frame and present it to the display device.
_context->makeCurrent();
{
PROFILE_RANGE("PluginPresent")
PROFILE_RANGE(displayPlugins, "PluginPresent")
currentPlugin->present();
CHECK_GL_ERROR();
}
@ -560,22 +560,22 @@ void OpenGLDisplayPlugin::compositeLayers() {
updateCompositeFramebuffer();
{
PROFILE_RANGE_EX("compositeScene", 0xff0077ff, (uint64_t)presentCount())
PROFILE_RANGE_EX(displayPlugins, "compositeScene", 0xff0077ff, (uint64_t)presentCount())
compositeScene();
}
{
PROFILE_RANGE_EX("compositeOverlay", 0xff0077ff, (uint64_t)presentCount())
PROFILE_RANGE_EX(displayPlugins, "compositeOverlay", 0xff0077ff, (uint64_t)presentCount())
compositeOverlay();
}
auto compositorHelper = DependencyManager::get<CompositorHelper>();
if (compositorHelper->getReticleVisible()) {
PROFILE_RANGE_EX("compositePointer", 0xff0077ff, (uint64_t)presentCount())
PROFILE_RANGE_EX(displayPlugins, "compositePointer", 0xff0077ff, (uint64_t)presentCount())
compositePointer();
}
{
PROFILE_RANGE_EX("compositeExtra", 0xff0077ff, (uint64_t)presentCount())
PROFILE_RANGE_EX(displayPlugins, "compositeExtra", 0xff0077ff, (uint64_t)presentCount())
compositeExtra();
}
}
@ -595,12 +595,12 @@ void OpenGLDisplayPlugin::internalPresent() {
}
void OpenGLDisplayPlugin::present() {
PROFILE_RANGE_EX(__FUNCTION__, 0xffffff00, (uint64_t)presentCount())
PROFILE_RANGE_EX(displayPlugins, __FUNCTION__, 0xffffff00, (uint64_t)presentCount())
updateFrameData();
incrementPresentCount();
{
PROFILE_RANGE_EX("recycle", 0xff00ff00, (uint64_t)presentCount())
PROFILE_RANGE_EX(displayPlugins, "recycle", 0xff00ff00, (uint64_t)presentCount())
_gpuContext->recycle();
}
@ -614,19 +614,19 @@ void OpenGLDisplayPlugin::present() {
_lastFrame = _currentFrame.get();
});
// Execute the frame rendering commands
PROFILE_RANGE_EX("execute", 0xff00ff00, (uint64_t)presentCount())
PROFILE_RANGE_EX(displayPlugins, "execute", 0xff00ff00, (uint64_t)presentCount())
_gpuContext->executeFrame(_currentFrame);
}
// Write all layers to a local framebuffer
{
PROFILE_RANGE_EX("composite", 0xff00ffff, (uint64_t)presentCount())
PROFILE_RANGE_EX(displayPlugins, "composite", 0xff00ffff, (uint64_t)presentCount())
compositeLayers();
}
// Take the composite framebuffer and send it to the output device
{
PROFILE_RANGE_EX("internalPresent", 0xff00ffff, (uint64_t)presentCount())
PROFILE_RANGE_EX(displayPlugins, "internalPresent", 0xff00ffff, (uint64_t)presentCount())
internalPresent();
}

View file

@ -206,7 +206,7 @@ float HmdDisplayPlugin::getLeftCenterPixel() const {
}
void HmdDisplayPlugin::internalPresent() {
PROFILE_RANGE_EX(__FUNCTION__, 0xff00ff00, (uint64_t)presentCount())
PROFILE_RANGE_EX(displayPlugins, __FUNCTION__, 0xff00ff00, (uint64_t)presentCount())
// Composite together the scene, overlay and mouse cursor
hmdPresent();

View file

@ -211,7 +211,7 @@ namespace render {
template <> void payloadRender(const RenderableModelEntityItemMeta::Pointer& payload, RenderArgs* args) {
if (args) {
if (payload && payload->entity) {
PROFILE_RANGE("MetaModelRender");
PROFILE_RANGE(renderlogging, "MetaModelRender");
payload->entity->render(args);
}
}

View file

@ -24,6 +24,7 @@
#include "EntitiesLogging.h"
#include "RecurseOctreeToMapOperator.h"
#include "LogHandler.h"
#include <Trace.h>
static const quint64 DELETED_ENTITIES_EXTRA_USECS_TO_CONSIDER = USECS_PER_MSEC * 50;
const float EntityTree::DEFAULT_MAX_TMP_ENTITY_LIFETIME = 60 * 60; // 1 hour

View file

@ -321,7 +321,7 @@ FBXNode parseTextFBXNode(Tokenizer& tokenizer) {
}
FBXNode FBXReader::parseFBX(QIODevice* device) {
PROFILE_RANGE_EX(__FUNCTION__, 0xff0000ff, device);
PROFILE_RANGE_EX(modelformat, __FUNCTION__, 0xff0000ff, device);
// verify the prolog
const QByteArray BINARY_PROLOG = "Kaydara FBX Binary ";
if (device->peek(BINARY_PROLOG.size()) != BINARY_PROLOG) {

View file

@ -420,7 +420,7 @@ done:
FBXGeometry* OBJReader::readOBJ(QByteArray& model, const QVariantHash& mapping, const QUrl& url) {
PROFILE_RANGE_EX(__FUNCTION__, 0xffff0000, nullptr);
PROFILE_RANGE_EX(modelformat, __FUNCTION__, 0xffff0000, nullptr);
QBuffer buffer { &model };
buffer.open(QIODevice::ReadOnly);

View file

@ -11,4 +11,4 @@
#include "GLLogging.h"
Q_LOGGING_CATEGORY(glLogging, "hifi.glLogging")
Q_LOGGING_CATEGORY(glLogging, "hifi.gl")

View file

@ -284,7 +284,7 @@ void OffscreenQmlSurface::render() {
GLuint texture = offscreenTextures.getNextTexture(_size);
glBindFramebuffer(GL_DRAW_FRAMEBUFFER, _fbo);
glFramebufferTexture(GL_DRAW_FRAMEBUFFER, GL_COLOR_ATTACHMENT0, texture, 0);
PROFILE_RANGE("qml_render->rendercontrol")
PROFILE_RANGE(glLogging, "qml_render->rendercontrol")
_renderControl->render();
glBindFramebuffer(GL_DRAW_FRAMEBUFFER, 0);
glBindTexture(GL_TEXTURE_2D, texture);
@ -622,7 +622,7 @@ void OffscreenQmlSurface::updateQuick() {
}
if (_render) {
PROFILE_RANGE(__FUNCTION__);
PROFILE_RANGE(glLogging, __FUNCTION__);
render();
_render = false;
}

View file

@ -30,6 +30,7 @@
#include "GLTexture.h"
#include "GLShader.h"
using namespace gpu;
using namespace gpu::gl;
@ -199,7 +200,7 @@ void GLBackend::renderPassTransfer(const Batch& batch) {
_inRenderTransferPass = true;
{ // Sync all the buffers
PROFILE_RANGE("syncGPUBuffer");
PROFILE_RANGE(gpugllogging, "syncGPUBuffer");
for (auto& cached : batch._buffers._items) {
if (cached._data) {
@ -209,7 +210,7 @@ void GLBackend::renderPassTransfer(const Batch& batch) {
}
{ // Sync all the buffers
PROFILE_RANGE("syncCPUTransform");
PROFILE_RANGE(gpugllogging, "syncCPUTransform");
_transform._cameras.clear();
_transform._cameraOffsets.clear();
@ -241,7 +242,7 @@ void GLBackend::renderPassTransfer(const Batch& batch) {
}
{ // Sync the transform buffers
PROFILE_RANGE("syncGPUTransform");
PROFILE_RANGE(gpugllogging, "syncGPUTransform");
transferTransformState(batch);
}
@ -303,7 +304,7 @@ void GLBackend::render(const Batch& batch) {
}
{
PROFILE_RANGE("Transfer");
PROFILE_RANGE(gpugllogging, "Transfer");
renderPassTransfer(batch);
}
@ -313,7 +314,7 @@ void GLBackend::render(const Batch& batch) {
}
#endif
{
PROFILE_RANGE(_stereo._enable ? "Render Stereo" : "Render");
PROFILE_RANGE(gpugllogging, _stereo._enable ? "Render Stereo" : "Render");
renderPassDraw(batch);
}
#ifdef GPU_STEREO_DRAWCALL_INSTANCED

View file

@ -10,6 +10,7 @@
//
#include "GLBackend.h"
#include "GLQuery.h"
#include "GLShared.h"
using namespace gpu;
using namespace gpu::gl;
@ -27,7 +28,7 @@ void GLBackend::do_beginQuery(const Batch& batch, size_t paramOffset) {
auto query = batch._queries.get(batch._params[paramOffset]._uint);
GLQuery* glquery = syncGPUObject(*query);
if (glquery) {
PROFILE_RANGE_BEGIN(glquery->_profileRangeId, query->getName().c_str(), 0xFFFF7F00);
PROFILE_RANGE_BEGIN(gpugllogging, glquery->_profileRangeId, query->getName().c_str(), 0xFFFF7F00);
++_queryStage._rangeQueryDepth;
glGetInteger64v(GL_TIMESTAMP, (GLint64*)&glquery->_batchElapsedTime);
@ -61,7 +62,7 @@ void GLBackend::do_endQuery(const Batch& batch, size_t paramOffset) {
glGetInteger64v(GL_TIMESTAMP, &now);
glquery->_batchElapsedTime = now - glquery->_batchElapsedTime;
PROFILE_RANGE_END(glquery->_profileRangeId);
PROFILE_RANGE_END(gpugllogging, glquery->_profileRangeId);
(void)CHECK_GL_ERROR();
}

View file

@ -12,7 +12,6 @@
#include <unordered_set>
#include <unordered_map>
#include <QtCore/QThread>
#include "../gl/GLTexelFormat.h"
@ -123,7 +122,7 @@ void GL41Texture::transferMip(uint16_t mipLevel, uint8_t face) const {
}
void GL41Texture::startTransfer() {
PROFILE_RANGE(__FUNCTION__);
PROFILE_RANGE(gpugllogging, __FUNCTION__);
Parent::startTransfer();
glBindTexture(_target, _id);

View file

@ -17,6 +17,7 @@
#include <QtCore/QDebug>
#include <QtCore/QThread>
#include <Trace.h>
#include <NumericalConstants.h>
@ -757,6 +758,9 @@ bool sphericalHarmonicsFromTexture(const gpu::Texture& cubeTexture, std::vector<
if(width != cubeTexture.getHeight()) {
return false;
}
PROFILE_RANGE(gpulogging, "sphericalHarmonicsFromTexture");
const uint sqOrder = order*order;
// allocate memory for calculations
@ -788,6 +792,7 @@ bool sphericalHarmonicsFromTexture(const gpu::Texture& cubeTexture, std::vector<
// for each face of cube texture
for(int face=0; face < gpu::Texture::NUM_CUBE_FACES; face++) {
PROFILE_RANGE(gpulogging, "ProcessFace");
auto numComponents = cubeTexture.accessStoredMipFace(0,face)->getFormat().getScalarCount();
auto data = cubeTexture.accessStoredMipFace(0,face)->readData();
@ -995,4 +1000,4 @@ Texture::ExternalUpdates Texture::getUpdates() const {
_externalUpdates.swap(result);
}
return result;
}
}

View file

@ -21,6 +21,8 @@
#include <QThreadPool>
#include "ModelNetworkingLogging.h"
#include <Trace.h>
#include <StatTracker.h>
class GeometryReader;
@ -39,6 +41,8 @@ class GeometryMappingResource : public GeometryResource {
public:
GeometryMappingResource(const QUrl& url) : GeometryResource(url) {};
QString getType() const override { return "GeometryMapping"; }
virtual void downloadFinished(const QByteArray& data) override;
private slots:
@ -50,6 +54,9 @@ private:
};
void GeometryMappingResource::downloadFinished(const QByteArray& data) {
PROFILE_ASYNC_BEGIN(modelnetworking, "GeometryMappingResource::downloadFinished", _url.toString(),
{ { "url", _url.toString() } });
auto mapping = FSTReader::readMapping(data);
QString filename = mapping.value("filename").toString();
@ -113,6 +120,7 @@ void GeometryMappingResource::onGeometryMappingLoaded(bool success) {
disconnect(_connection); // FIXME Should not have to do this
}
PROFILE_ASYNC_END(modelnetworking, "GeometryMappingResource::downloadFinished", _url.toString());
finishedLoading(success);
}
@ -120,8 +128,15 @@ class GeometryReader : public QRunnable {
public:
GeometryReader(QWeakPointer<Resource>& resource, const QUrl& url, const QVariantHash& mapping,
const QByteArray& data) :
_resource(resource), _url(url), _mapping(mapping), _data(data) {}
virtual ~GeometryReader() = default;
_resource(resource), _url(url), _mapping(mapping), _data(data) {
DependencyManager::get<StatTracker>()->incrementStat("PendingProcessing");
//trace::FLOW_BEGIN("GeometryReader", trace::cResource, _url.toString(), { { "url", _url.toString() } });
}
virtual ~GeometryReader() {
//trace::FLOW_END("GeometryReader", trace::cResource, _url.toString(), { { "url", _url.toString() } });
}
virtual void run() override;
@ -133,6 +148,10 @@ private:
};
void GeometryReader::run() {
DependencyManager::get<StatTracker>()->decrementStat("PendingProcessing");
//trace::ASYNC_BEGIN("GeometryReader::run", trace::cResource, _url.toString(), { { "url", _url.toString() } });
CounterStat counter("Processing");
PROFILE_RANGE_EX(modelnetworking, "GeometryReader::run", 0xFF00FF00, 0, { { "url", _url.toString() } });
auto originalPriority = QThread::currentThread()->priority();
if (originalPriority == QThread::InheritPriority) {
originalPriority = QThread::NormalPriority;
@ -189,6 +208,7 @@ void GeometryReader::run() {
Q_ARG(bool, false));
}
}
//trace::ASYNC_END("GeometryReader::run", trace::cResource, _url.toString());
}
class GeometryDefinitionResource : public GeometryResource {
@ -197,6 +217,8 @@ public:
GeometryDefinitionResource(const QUrl& url, const QVariantHash& mapping, const QUrl& textureBaseUrl) :
GeometryResource(url, resolveTextureBaseUrl(url, textureBaseUrl)), _mapping(mapping) {}
QString getType() const override { return "GeometryDefinition"; }
virtual void downloadFinished(const QByteArray& data) override;
protected:

View file

@ -14,6 +14,9 @@
class NetworkShader : public Resource {
public:
NetworkShader(const QUrl& url);
QString getType() const override { return "NetworkShader"; }
virtual void downloadFinished(const QByteArray& data) override;
QString _source;

View file

@ -33,6 +33,8 @@
#include <PathUtils.h>
#include "ModelNetworkingLogging.h"
#include <Trace.h>
#include <StatTracker.h>
TextureCache::TextureCache() {
setUnusedResourceCacheSize(0);
@ -331,6 +333,7 @@ ImageReader::ImageReader(const QWeakPointer<Resource>& resource, const QByteArra
outFile.close();
}
#endif
DependencyManager::get<StatTracker>()->incrementStat("PendingProcessing");
}
void ImageReader::listSupportedImageFormats() {
@ -342,7 +345,12 @@ void ImageReader::listSupportedImageFormats() {
}
void ImageReader::run() {
PROFILE_RANGE_EX(__FUNCTION__, 0xffff0000, nullptr);
DependencyManager::get<StatTracker>()->decrementStat("PendingProcessing");
CounterStat counter("Processing");
//trace::DURATION_BEGIN("ImageReader::threadSetup", trace::cResource, { { "url", _url.toString() } });
PROFILE_RANGE_EX(modelnetworking, __FUNCTION__, 0xffff0000, 0, { { "url", _url.toString() } });
auto originalPriority = QThread::currentThread()->priority();
if (originalPriority == QThread::InheritPriority) {
originalPriority = QThread::NormalPriority;
@ -356,7 +364,6 @@ void ImageReader::run() {
qCWarning(modelnetworking) << "Abandoning load of" << _url << "; could not get strong ref";
return;
}
listSupportedImageFormats();
// Help the QImage loader by extracting the image file format from the url filename ext.
@ -378,7 +385,6 @@ void ImageReader::run() {
}
return;
}
gpu::TexturePointer texture = nullptr;
{
// Double-check the resource still exists between long operations.
@ -390,7 +396,7 @@ void ImageReader::run() {
auto url = _url.toString().toStdString();
PROFILE_RANGE_EX(__FUNCTION__"::textureLoader", 0xffffff00, nullptr);
PROFILE_RANGE_EX(modelnetworking, __FUNCTION__, 0xffffff00, 0);
texture.reset(resource.dynamicCast<NetworkTexture>()->getTextureLoader()(image, url));
}

View file

@ -63,10 +63,13 @@ public:
NetworkTexture(const QUrl& url, Type type, const QByteArray& content);
NetworkTexture(const QUrl& url, const TextureLoaderFunc& textureLoader, const QByteArray& content);
QString getType() const override { return "NetworkTexture"; }
int getOriginalWidth() const { return _originalWidth; }
int getOriginalHeight() const { return _originalHeight; }
int getWidth() const { return _width; }
int getHeight() const { return _height; }
Type getTextureType() const { return _type; }
TextureLoaderFunc getTextureLoader() const;

View file

@ -14,6 +14,8 @@
#include <QPainter>
#include <QDebug>
#include <Profile.h>
#include "ModelLogging.h"
using namespace model;
@ -744,6 +746,8 @@ const CubeLayout CubeLayout::CUBEMAP_LAYOUTS[] = {
const int CubeLayout::NUM_CUBEMAP_LAYOUTS = sizeof(CubeLayout::CUBEMAP_LAYOUTS) / sizeof(CubeLayout);
gpu::Texture* TextureUsage::processCubeTextureColorFromImage(const QImage& srcImage, const std::string& srcImageName, bool isLinear, bool doCompress, bool generateMips, bool generateIrradiance) {
PROFILE_RANGE(modelLog, "processCubeTextureColorFromImage");
gpu::Texture* theTexture = nullptr;
if ((srcImage.width() > 0) && (srcImage.height() > 0)) {
QImage image = processSourceImage(srcImage, true);
@ -801,11 +805,13 @@ gpu::Texture* TextureUsage::processCubeTextureColorFromImage(const QImage& srcIm
}
if (generateMips) {
PROFILE_RANGE(modelLog, "generateMips");
theTexture->autoGenerateMips(-1);
}
// Generate irradiance while we are at it
if (generateIrradiance) {
PROFILE_RANGE(modelLog, "generateIrradiance");
theTexture->generateIrradiance();
}
}

View file

@ -604,7 +604,7 @@ bool AssetClient::cancelGetAssetRequest(MessageID id) {
for (auto& kv : _pendingRequests) {
auto& messageCallbackMap = kv.second;
auto requestIt = messageCallbackMap.find(id);
if (requestIt != kv.second.end()) {
if (requestIt != messageCallbackMap.end()) {
auto& message = requestIt->second.message;
if (message) {

View file

@ -19,8 +19,12 @@
#include "NetworkLogging.h"
#include "NodeList.h"
#include "ResourceCache.h"
#include <Trace.h>
static int requestID = 0;
AssetRequest::AssetRequest(const QString& hash) :
_requestID(++requestID),
_hash(hash)
{
}
@ -28,11 +32,17 @@ AssetRequest::AssetRequest(const QString& hash) :
AssetRequest::~AssetRequest() {
auto assetClient = DependencyManager::get<AssetClient>();
if (_assetRequestID) {
//trace::ASYNC_END("assetRequest", trace::nameAssetData, _requestID);
assetClient->cancelGetAssetRequest(_assetRequestID);
}
if (_assetInfoRequestID) {
//trace::ASYNC_END("assetRequest", trace::nameAssetInfo, _requestID);
assetClient->cancelGetAssetInfoRequest(_assetInfoRequestID);
}
if (_assetRequestID || _assetInfoRequestID) {
//trace::ASYNC_END(trace::nameAssetEndedEarly, "assetRequest", _requestID);
//trace::ASYNC_END(trace::nameAssetRequest, "assetRequest", _requestID);
}
}
void AssetRequest::start() {
@ -46,11 +56,14 @@ void AssetRequest::start() {
return;
}
//trace::ASYNC_BEGIN(trace::nameAssetRequest, "assetRequest", _requestID);
// in case we haven't parsed a valid hash, return an error now
if (!isValidHash(_hash)) {
_error = InvalidHash;
_state = Finished;
//trace::ASYNC_END(trace::nameAssetRequest, "assetRequest", _requestID);
emit finished(this);
return;
}
@ -63,16 +76,21 @@ void AssetRequest::start() {
_error = NoError;
_state = Finished;
//trace::ASYNC_END(trace::nameAssetRequest, "assetRequest", _requestID);
emit finished(this);
return;
}
_state = WaitingForInfo;
//trace::ASYNC_BEGIN(trace::nameAssetInfo, "assetRequest", _requestID);
auto assetClient = DependencyManager::get<AssetClient>();
_assetInfoRequestID = assetClient->getAssetInfo(_hash,
[this](bool responseReceived, AssetServerError serverError, AssetInfo info) {
//trace::ASYNC_END(trace::nameAssetInfo, "assetRequest", _requestID);
_assetInfoRequestID = AssetClient::INVALID_MESSAGE_ID;
_info = info;
@ -93,6 +111,7 @@ void AssetRequest::start() {
if (_error != NoError) {
qCWarning(asset_client) << "Got error retrieving asset info for" << _hash;
_state = Finished;
//trace::ASYNC_END(trace::nameAssetRequest, "assetRequest", _requestID);
emit finished(this);
return;
@ -153,6 +172,7 @@ void AssetRequest::start() {
}
_state = Finished;
//trace::ASYNC_END(trace::nameAssetRequest, "assetRequest", _requestID);
emit finished(this);
}, [this, that](qint64 totalReceived, qint64 total) {
if (!that) {

View file

@ -56,6 +56,7 @@ signals:
void progress(qint64 totalReceived, qint64 total);
private:
int _requestID;
State _state = NotStarted;
Error _error = NoError;
AssetInfo _info;

View file

@ -17,6 +17,8 @@
#include "AssetUtils.h"
#include "MappingRequest.h"
#include "NetworkLogging.h"
#include <Trace.h>
#include <Profile.h>
static const int DOWNLOAD_PROGRESS_LOG_INTERVAL_SECONDS = 5;
@ -27,12 +29,18 @@ AssetResourceRequest::AssetResourceRequest(const QUrl& url) :
}
AssetResourceRequest::~AssetResourceRequest() {
if (_assetMappingRequest) {
_assetMappingRequest->deleteLater();
}
if (_assetRequest) {
_assetRequest->deleteLater();
if (_assetRequest || _assetMappingRequest) {
if (_assetMappingRequest) {
_assetMappingRequest->deleteLater();
// PROFILE_ASYNC_END("resource", "AssetResourceRequestMapping", _url.toString());
}
if (_assetRequest) {
_assetRequest->deleteLater();
//PROFILE_ASYNC_END("resource", "AssetResourceRequestData", _url.toString());
}
//trace::ASYNC_END("AssetResourceRequest", trace::cResource, _url.toString());
}
}
@ -44,6 +52,8 @@ bool AssetResourceRequest::urlIsAssetHash() const {
}
void AssetResourceRequest::doSend() {
//trace::ASYNC_BEGIN("AssetResourceRequest", trace::cResource, _url.toString(), { { "url", _url.toString() } });
// We'll either have a hash or an ATP path to a file (that maps to a hash)
if (urlIsAssetHash()) {
// We've detected that this is a hash - simply use AssetClient to request that asset
@ -61,6 +71,8 @@ void AssetResourceRequest::doSend() {
}
void AssetResourceRequest::requestMappingForPath(const AssetPath& path) {
//trace::ASYNC_BEGIN("AssetResourceRequestMapping", trace::cResource, _url.toString());
auto assetClient = DependencyManager::get<AssetClient>();
_assetMappingRequest = assetClient->createGetMappingRequest(path);
@ -69,6 +81,8 @@ void AssetResourceRequest::requestMappingForPath(const AssetPath& path) {
Q_ASSERT(_state == InProgress);
Q_ASSERT(request == _assetMappingRequest);
//trace::ASYNC_END("AssetResourceRequestMapping", trace::cResource, _url.toString());
switch (request->getError()) {
case MappingRequest::NoError:
// we have no error, we should have a resulting hash - use that to send of a request for that asset
@ -96,6 +110,8 @@ void AssetResourceRequest::requestMappingForPath(const AssetPath& path) {
_state = Finished;
emit finished();
//trace::ASYNC_END("AssetResourceRequest", trace::cResource, _url.toString());
break;
}
}
@ -108,6 +124,7 @@ void AssetResourceRequest::requestMappingForPath(const AssetPath& path) {
}
void AssetResourceRequest::requestHash(const AssetHash& hash) {
//trace::ASYNC_BEGIN("AssetResourceRequestData", trace::cResource, _url.toString());
// Make request to atp
auto assetClient = DependencyManager::get<AssetClient>();
@ -118,6 +135,8 @@ void AssetResourceRequest::requestHash(const AssetHash& hash) {
Q_ASSERT(_state == InProgress);
Q_ASSERT(req == _assetRequest);
Q_ASSERT(req->getState() == AssetRequest::Finished);
//trace::ASYNC_END("AssetResourceRequestData", trace::cResource, _url.toString());
switch (req->getError()) {
case AssetRequest::Error::NoError:
@ -143,6 +162,8 @@ void AssetResourceRequest::requestHash(const AssetHash& hash) {
_assetRequest->deleteLater();
_assetRequest = nullptr;
//trace::ASYNC_END("AssetResourceRequest", trace::cResource, _url.toString());
});
_assetRequest->start();

View file

@ -19,6 +19,7 @@
#include <BuildInfo.h>
#include "Assignment.h"
#include <QtCore/QStandardPaths>
#include <QtCore/QDir>
Assignment::Type Assignment::typeForNodeType(NodeType_t nodeType) {
switch (nodeType) {
@ -51,7 +52,7 @@ Assignment::Assignment() :
}
Assignment::Assignment(Assignment::Command command, Assignment::Type type, const QString& pool, Assignment::Location location) :
Assignment::Assignment(Assignment::Command command, Assignment::Type type, const QString& pool, Assignment::Location location, QString dataDirectory) :
_uuid(),
_command(command),
_type(type),
@ -60,7 +61,8 @@ Assignment::Assignment(Assignment::Command command, Assignment::Type type, const
_payload(),
_isStatic(false),
_walletUUID(),
_nodeVersion()
_nodeVersion(),
_dataDirectory(dataDirectory)
{
if (_command == Assignment::CreateCommand) {
// this is a newly created assignment, generate a random UUID

View file

@ -55,7 +55,8 @@ public:
Assignment(Assignment::Command command,
Assignment::Type type,
const QString& pool = emptyPool,
Assignment::Location location = Assignment::LocalLocation);
Assignment::Location location = Assignment::LocalLocation,
QString dataDirectory = QString());
Assignment(const Assignment& otherAssignment);
Assignment& operator=(const Assignment &rhsAssignment);
@ -103,6 +104,7 @@ protected:
bool _isStatic; /// defines if this assignment needs to be re-queued in the domain-server if it stops being fulfilled
QUuid _walletUUID; /// the UUID for the wallet that should be paid for this assignment
QString _nodeVersion;
QString _dataDirectory;
};
uint qHash(const Assignment::Type& key, uint seed);

View file

@ -109,6 +109,10 @@ void HifiSockAddr::handleLookupResult(const QHostInfo& hostInfo) {
}
}
QString HifiSockAddr::toString() const {
return _address.toString() + ":" + QString::number(_port);
}
QDebug operator<<(QDebug debug, const HifiSockAddr& sockAddr) {
debug.nospace() << sockAddr._address.toString().toLocal8Bit().constData() << ":" << sockAddr._port;
return debug.space();

View file

@ -53,6 +53,8 @@ public:
static int packSockAddr(unsigned char* packetData, const HifiSockAddr& packSockAddr);
static int unpackSockAddr(const unsigned char* packetData, HifiSockAddr& unpackDestSockAddr);
QString toString() const;
friend QDebug operator<<(QDebug debug, const HifiSockAddr& sockAddr);
friend QDataStream& operator<<(QDataStream& dataStream, const HifiSockAddr& sockAddr);
friend QDataStream& operator>>(QDataStream& dataStream, HifiSockAddr& sockAddr);

View file

@ -37,6 +37,7 @@
#include "HifiSockAddr.h"
#include "NetworkLogging.h"
#include "udt/Packet.h"
#include <Trace.h>
static Setting::Handle<quint16> LIMITED_NODELIST_LOCAL_PORT("LimitedNodeList.LocalPort", 0);
@ -584,6 +585,7 @@ SharedNodePointer LimitedNodeList::addOrUpdateNode(const QUuid& uuid, NodeType_t
return matchingNode;
} else {
//trace::ASYNC_BEGIN("Node:" + NodeType::getNodeTypeName(nodeType), "NodeConnection", NodeType::getNodeTypeName(nodeType), { { "type", NodeType::getNodeTypeName(nodeType) } });
// we didn't have this node, so add them
Node* newNode = new Node(uuid, nodeType, publicSocket, localSocket, permissions, connectionSecret, this);
@ -628,6 +630,7 @@ SharedNodePointer LimitedNodeList::addOrUpdateNode(const QUuid& uuid, NodeType_t
emit nodeActivated(newNodePointer);
} else {
connect(newNodePointer.data(), &NetworkPeer::socketActivated, this, [=] {
//trace::ASYNC_END("Add" + NodeType::getNodeTypeName(nodeType), "NodeConnection", NodeType::getNodeTypeName(nodeType), { { "type", NodeType::getNodeTypeName(nodeType) } });
emit nodeActivated(newNodePointer);
disconnect(newNodePointer.data(), &NetworkPeer::socketActivated, this, 0);
});
@ -1116,7 +1119,6 @@ void LimitedNodeList::flagTimeForConnectionStep(ConnectionStep connectionStep) {
}
void LimitedNodeList::flagTimeForConnectionStep(ConnectionStep connectionStep, quint64 timestamp) {
if (connectionStep == ConnectionStep::LookupAddress) {
QWriteLocker writeLock(&_connectionTimeLock);

View file

@ -103,8 +103,7 @@ public:
ReceiveFirstAudioPacket
};
Q_ENUMS(ConnectionStep);
Q_ENUM(ConnectionStep);
const QUuid& getSessionUUID() const { return _sessionUUID; }
void setSessionUUID(const QUuid& sessionUUID);

View file

@ -12,5 +12,6 @@
#include "NetworkLogging.h"
Q_LOGGING_CATEGORY(networking, "hifi.networking")
Q_LOGGING_CATEGORY(resourceLog, "hifi.networking.resource")
Q_LOGGING_CATEGORY(asset_client, "hifi.networking.asset_client")
Q_LOGGING_CATEGORY(messages_client, "hifi.networking.messages_client")

View file

@ -14,6 +14,7 @@
#include <QLoggingCategory>
Q_DECLARE_LOGGING_CATEGORY(resourceLog)
Q_DECLARE_LOGGING_CATEGORY(networking)
Q_DECLARE_LOGGING_CATEGORY(asset_client)
Q_DECLARE_LOGGING_CATEGORY(messages_client)

View file

@ -20,6 +20,8 @@
#include "BandwidthRecorder.h"
#include "NetworkLogging.h"
#include <Trace.h>
#include "NodeType.h"
NetworkPeer::NetworkPeer(QObject* parent) :
@ -156,6 +158,7 @@ void NetworkPeer::activateMatchingOrNewSymmetricSocket(const HifiSockAddr& match
}
void NetworkPeer::softReset() {
qDebug() << "Soft reset ";
// a soft reset should clear the sockets and reset the number of connection attempts
_localSocket.clear();
_publicSocket.clear();

View file

@ -31,6 +31,7 @@
#include "NetworkLogging.h"
#include "udt/PacketHeaders.h"
#include "SharedUtil.h"
#include <Trace.h>
const int KEEPALIVE_PING_INTERVAL_MS = 1000;

View file

@ -23,6 +23,8 @@
#include "NodeList.h"
#include "ResourceCache.h"
#include <Trace.h>
#include <Profile.h>
#define clamp(x, min, max) (((x) < (min)) ? (min) :\
(((x) > (max)) ? (max) :\
@ -495,11 +497,12 @@ const int DEFAULT_REQUEST_LIMIT = 10;
int ResourceCache::_requestLimit = DEFAULT_REQUEST_LIMIT;
int ResourceCache::_requestsActive = 0;
static int requestID = 0;
Resource::Resource(const QUrl& url) :
_url(url),
_activeUrl(url),
_request(nullptr) {
_requestID(++requestID) {
init();
}
@ -647,20 +650,24 @@ void Resource::reinsert() {
void Resource::makeRequest() {
if (_request) {
PROFILE_ASYNC_END(resourceLog, "Resource:" + getType(), QString::number(_requestID));
_request->disconnect();
_request->deleteLater();
}
PROFILE_ASYNC_BEGIN(resourceLog, "Resource:" + getType(), QString::number(_requestID), { { "url", _url.toString() }, { "activeURL", _activeUrl.toString() } });
_request = ResourceManager::createResourceRequest(this, _activeUrl);
if (!_request) {
qCDebug(networking).noquote() << "Failed to get request for" << _url.toDisplayString();
ResourceCache::requestCompleted(_self);
finishedLoading(false);
PROFILE_ASYNC_END(resourceLog, "Resource:" + getType(), QString::number(_requestID));
return;
}
qCDebug(networking).noquote() << "Starting request for:" << _url.toDisplayString();
qCDebug(resourceLog).noquote() << "Starting request for:" << _url.toDisplayString();
emit loading();
connect(_request, &ResourceRequest::progress, this, &Resource::onProgress);
@ -681,6 +688,11 @@ void Resource::handleDownloadProgress(uint64_t bytesReceived, uint64_t bytesTota
void Resource::handleReplyFinished() {
Q_ASSERT_X(_request, "Resource::handleReplyFinished", "Request should not be null while in handleReplyFinished");
PROFILE_ASYNC_END(resourceLog, "Resource:" + getType(), QString::number(_requestID), {
{ "from_cache", _request->loadedFromCache() },
{ "size_mb", _bytesTotal / 1000000.0 }
});
setSize(_bytesTotal);
if (!_request || _request != sender()) {

View file

@ -342,6 +342,8 @@ public:
Resource(const QUrl& url);
~Resource();
virtual QString getType() const { return "Resource"; }
/// Returns the key last used to identify this resource in the unused map.
int getLRUKey() const { return _lruKey; }
@ -461,6 +463,7 @@ private:
bool isInScript() const { return _isInScript; }
void setInScript(bool isInScript) { _isInScript = isInScript; }
int _requestID;
ResourceRequest* _request{ nullptr };
int _lruKey{ 0 };
QTimer* _replyTimer{ nullptr };

View file

@ -23,6 +23,7 @@
#include "Packet.h"
#include "PacketList.h"
#include "Socket.h"
#include <Trace.h>
using namespace udt;
using namespace std::chrono;
@ -32,6 +33,9 @@ Connection::Connection(Socket* parentSocket, HifiSockAddr destination, std::uniq
_destination(destination),
_congestionControl(move(congestionControl))
{
//trace::ASYNC_BEGIN("Connection", "Connection", _destination.toString());
//trace::ASYNC_BEGIN("DownHandshake", "Connection", _destination.toString());
Q_ASSERT_X(parentSocket, "Connection::Connection", "Must be called with a valid Socket*");
Q_ASSERT_X(_congestionControl, "Connection::Connection", "Must be called with a valid CongestionControl object");
@ -68,6 +72,7 @@ Connection::~Connection() {
for (auto& pendingMessage : _pendingReceivedMessages) {
_parentSocket->messageFailed(this, pendingMessage.first);
}
//trace::ASYNC_END("Connection", "Connection", _destination.toString());
}
void Connection::stopSendQueue() {
@ -812,6 +817,7 @@ void Connection::processHandshake(ControlPacketPointer controlPacket) {
_parentSocket->writeBasePacket(*_handshakeACK, _destination);
// indicate that handshake has been received
//trace::ASYNC_END("DownHandshake", "Connection", _destination.toString());
_hasReceivedHandshake = true;
if (_didRequestHandshake) {

View file

@ -58,7 +58,7 @@ public:
using ControlPacketPointer = std::unique_ptr<ControlPacket>;
Connection(Socket* parentSocket, HifiSockAddr destination, std::unique_ptr<CongestionControl> congestionControl);
~Connection();
virtual ~Connection();
void sendReliablePacket(std::unique_ptr<Packet> packet);
void sendReliablePacketList(std::unique_ptr<PacketList> packet);

View file

@ -30,6 +30,8 @@
#include "PacketList.h"
#include "../UserActivityLogger.h"
#include "Socket.h"
#include <Trace.h>
#include <Profile.h>
using namespace udt;
using namespace std::chrono;
@ -84,6 +86,7 @@ SendQueue::SendQueue(Socket* socket, HifiSockAddr dest) :
_socket(socket),
_destination(dest)
{
PROFILE_ASYNC_BEGIN(networking, "SendQueue", _destination.toString());
// setup psuedo-random number generation for all instances of SendQueue
static std::random_device rd;
@ -102,6 +105,10 @@ SendQueue::SendQueue(Socket* socket, HifiSockAddr dest) :
_lastReceiverResponse = QDateTime::currentMSecsSinceEpoch();
}
SendQueue::~SendQueue() {
PROFILE_ASYNC_END(networking, "SendQueue", _destination.toString());
}
void SendQueue::queuePacket(std::unique_ptr<Packet> packet) {
_packets.queuePacket(std::move(packet));
@ -220,6 +227,7 @@ void SendQueue::sendHandshake() {
if (!_hasReceivedHandshakeACK) {
// we haven't received a handshake ACK from the client, send another now
auto handshakePacket = ControlPacket::create(ControlPacket::Handshake, sizeof(SequenceNumber));
PROFILE_ASYNC_BEGIN(networking, "SendQueue:Handshake", _destination.toString());
handshakePacket->writePrimitive(_initialSequenceNumber);
_socket->writeBasePacket(*handshakePacket, _destination);
@ -236,6 +244,7 @@ void SendQueue::handshakeACK(SequenceNumber initialSequenceNumber) {
std::lock_guard<std::mutex> locker { _handshakeMutex };
_hasReceivedHandshakeACK = true;
}
PROFILE_ASYNC_END(networking, "SendQueue:Handshake", _destination.toString());
// Notify on the handshake ACK condition
_handshakeACKCondition.notify_one();

View file

@ -51,6 +51,8 @@ public:
};
static std::unique_ptr<SendQueue> create(Socket* socket, HifiSockAddr destination);
virtual ~SendQueue();
void queuePacket(std::unique_ptr<Packet> packet);
void queuePacketList(std::unique_ptr<PacketList> packetList);

View file

@ -26,6 +26,7 @@
#include "../NLPacket.h"
#include "../NLPacketList.h"
#include "PacketList.h"
#include <Trace.h>
using namespace udt;

View file

@ -16,6 +16,8 @@
#include <QtCore/QDebug>
#include <Profile.h>
#include <LogHandler.h>
#include <NodeList.h>
#include <PerfStat.h>
@ -28,6 +30,7 @@
#include "OctreeLogging.h"
#include "OctreeUtils.h"
#include "SharedUtil.h"
#include <Trace.h>
AtomicUIntStat OctreeElement::_octreeMemoryUsage { 0 };
AtomicUIntStat OctreeElement::_octcodeMemoryUsage { 0 };
@ -389,6 +392,7 @@ OctreeElementPointer OctreeElement::addChildAtIndex(int childIndex) {
_isDirty = true;
markWithChangedTime();
PROFILE_INSTANT(octree, "EntityAdd", "g");
}
return childAt;
}

View file

@ -793,7 +793,7 @@ void RenderDeferred::configure(const Config& config) {
}
void RenderDeferred::run(const SceneContextPointer& sceneContext, const RenderContextPointer& renderContext, const Inputs& inputs) {
PROFILE_RANGE("DeferredLighting");
PROFILE_RANGE(renderlogging, "DeferredLighting");
auto deferredTransform = inputs.get0();
auto deferredFramebuffer = inputs.get1();

View file

@ -27,6 +27,7 @@
#include "Model.h"
#include "RenderUtilsLogging.h"
#include <Trace.h>
using namespace std;
@ -280,7 +281,7 @@ void Model::reset() {
}
bool Model::updateGeometry() {
PROFILE_RANGE(__FUNCTION__);
PROFILE_RANGE(renderutils, __FUNCTION__);
bool needFullUpdate = false;
if (!isLoaded()) {
@ -474,7 +475,7 @@ bool Model::convexHullContains(glm::vec3 point) {
// entity-scripts to call. I think it would be best to do the picking once-per-frame (in cpu, or gpu if possible)
// and then the calls use the most recent such result.
void Model::recalculateMeshBoxes(bool pickAgainstTriangles) {
PROFILE_RANGE(__FUNCTION__);
PROFILE_RANGE(renderutils, __FUNCTION__);
bool calculatedMeshTrianglesNeeded = pickAgainstTriangles && !_calculatedMeshTrianglesValid;
if (!_calculatedMeshBoxesValid || calculatedMeshTrianglesNeeded || (!_calculatedMeshPartBoxesValid && pickAgainstTriangles) ) {
@ -967,7 +968,7 @@ Blender::Blender(ModelPointer model, int blendNumber, const Geometry::WeakPointe
}
void Blender::run() {
PROFILE_RANGE(__FUNCTION__);
PROFILE_RANGE_EX(renderutils, __FUNCTION__, 0xFFFF0000, 0, { { "url", _model->getURL().toString() } });
QVector<glm::vec3> vertices, normals;
if (_model) {
int offset = 0;
@ -1088,7 +1089,7 @@ void Model::snapToRegistrationPoint() {
}
void Model::simulate(float deltaTime, bool fullUpdate) {
PROFILE_RANGE(__FUNCTION__);
PROFILE_RANGE(renderutils, __FUNCTION__);
fullUpdate = updateGeometry() || fullUpdate || (_scaleToFit && !_scaledToFit)
|| (_snapModelToRegistrationPoint && !_snappedToRegistrationPoint);

View file

@ -0,0 +1,11 @@
//
// Created by Bradley Austin Davis on 2016-12-14
// Copyright 2013-2016 High Fidelity, Inc.
//
// Distributed under the Apache License, Version 2.0.
// See the accompanying file LICENSE or http://www.apache.org/licenses/LICENSE-2.0.html
//
#include "Logging.h"
Q_LOGGING_CATEGORY(renderlogging, "hifi.render")

View file

@ -0,0 +1,16 @@
//
// Created by Bradley Austin Davis on 2016-12-14
// Copyright 2013-2016 High Fidelity, Inc.
//
// Distributed under the Apache License, Version 2.0.
// See the accompanying file LICENSE or http://www.apache.org/licenses/LICENSE-2.0.html
//
#ifndef hifi_render_Logging_h
#define hifi_render_Logging_h
#include <QLoggingCategory>
Q_DECLARE_LOGGING_CATEGORY(renderlogging)
#endif // hifi_render_Engine_h

View file

@ -11,7 +11,8 @@
#include "Scene.h"
#include <numeric>
#include "gpu/Batch.h"
#include <gpu/Batch.h>
#include "Logging.h"
using namespace render;
@ -77,7 +78,7 @@ void consolidateChangeQueue(PendingChangesQueue& queue, PendingChanges& singleBa
}
void Scene::processPendingChangesQueue() {
PROFILE_RANGE(__FUNCTION__);
PROFILE_RANGE(renderlogging, __FUNCTION__);
_changeQueueMutex.lock();
PendingChanges consolidatedPendingChanges;
consolidateChangeQueue(_changeQueue, consolidatedPendingChanges);

View file

@ -23,6 +23,7 @@
#include "SettingHandle.h"
#include "Context.h"
#include "Logging.h"
#include "gpu/Batch.h"
#include <PerfStat.h>
@ -571,7 +572,7 @@ public:
void run(const SceneContextPointer& sceneContext, const RenderContextPointer& renderContext) {
PerformanceTimer perfTimer(_name.c_str());
PROFILE_RANGE(_name.c_str());
PROFILE_RANGE(renderlogging, _name.c_str());
auto start = usecTimestampNow();
_concept->run(sceneContext, renderContext);

View file

@ -3,6 +3,8 @@ set(TARGET_NAME shared)
# TODO: there isn't really a good reason to have Script linked here - let's get what is requiring it out (RegisteredMetaTypes.cpp)
setup_hifi_library(Gui Network Script Widgets)
target_include_directories(${TARGET_NAME} PRIVATE "${CMAKE_BINARY_DIR}/includes")
if (WIN32)
target_link_libraries(${TARGET_NAME} Wbemuuid.lib)
endif()

View file

@ -0,0 +1,72 @@
//
// Created by Ryan Huffman on 2016-12-14
// Copyright 2013-2016 High Fidelity, Inc.
//
// Distributed under the Apache License, Version 2.0.
// See the accompanying file LICENSE or http://www.apache.org/licenses/LICENSE-2.0.html
//
#include "Profile.h"
#if defined(NSIGHT_FOUND)
#include "nvToolsExt.h"
#define NSIGHT_TRACING
#endif
Duration::Duration(const QLoggingCategory& category, const QString& name, uint32_t argbColor, uint64_t payload, QVariantMap args) : _name(name), _category(category) {
if (_category.isDebugEnabled()) {
args["nv_payload"] = QVariant::fromValue(payload);
tracing::traceEvent(_category, _name, tracing::DurationBegin, "", args);
#if defined(NSIGHT_TRACING)
nvtxEventAttributes_t eventAttrib { 0 };
eventAttrib.version = NVTX_VERSION;
eventAttrib.size = NVTX_EVENT_ATTRIB_STRUCT_SIZE;
eventAttrib.colorType = NVTX_COLOR_ARGB;
eventAttrib.color = argbColor;
eventAttrib.messageType = NVTX_MESSAGE_TYPE_ASCII;
eventAttrib.message.ascii = name.toUtf8().data();
eventAttrib.payload.llValue = payload;
eventAttrib.payloadType = NVTX_PAYLOAD_TYPE_UNSIGNED_INT64;
nvtxRangePushEx(&eventAttrib);
#endif
}
}
Duration::~Duration() {
if (_category.isDebugEnabled()) {
tracing::traceEvent(_category, _name, tracing::DurationEnd);
#ifdef NSIGHT_TRACING
nvtxRangePop();
#endif
}
}
// FIXME
uint64_t Duration::beginRange(const QLoggingCategory& category, const char* name, uint32_t argbColor) {
#ifdef NSIGHT_TRACING
if (category.isDebugEnabled()) {
nvtxEventAttributes_t eventAttrib = { 0 };
eventAttrib.version = NVTX_VERSION;
eventAttrib.size = NVTX_EVENT_ATTRIB_STRUCT_SIZE;
eventAttrib.colorType = NVTX_COLOR_ARGB;
eventAttrib.color = argbColor;
eventAttrib.messageType = NVTX_MESSAGE_TYPE_ASCII;
eventAttrib.message.ascii = name;
return nvtxRangeStartEx(&eventAttrib);
}
#endif
return 0;
}
// FIXME
void Duration::endRange(const QLoggingCategory& category, uint64_t rangeId) {
#ifdef NSIGHT_TRACING
if (category.isDebugEnabled()) {
nvtxRangeEnd(rangeId);
}
#endif
}

View file

@ -0,0 +1,63 @@
//
// Created by Ryan Huffman on 2016-12-14
// Copyright 2013-2016 High Fidelity, Inc.
//
// Distributed under the Apache License, Version 2.0.
// See the accompanying file LICENSE or http://www.apache.org/licenses/LICENSE-2.0.html
//
#pragma once
#ifndef HIFI_PROFILE_
#define HIFI_PROFILE_
#include "Trace.h"
class Duration {
public:
Duration(const QLoggingCategory& category, const QString& name, uint32_t argbColor = 0xff0000ff, uint64_t payload = 0, QVariantMap args = QVariantMap());
~Duration();
static uint64_t beginRange(const QLoggingCategory& category, const char* name, uint32_t argbColor);
static void endRange(const QLoggingCategory& category, uint64_t rangeId);
private:
QString _name;
const QLoggingCategory& _category;
};
inline void asyncBegin(const QLoggingCategory& category, const QString& name, const QString& id, const QVariantMap& args = QVariantMap(), const QVariantMap& extra = QVariantMap()) {
if (category.isDebugEnabled()) {
tracing::traceEvent(category, name, tracing::AsyncNestableStart, id, args, extra);
}
}
inline void asyncEnd(const QLoggingCategory& category, const QString& name, const QString& id, const QVariantMap& args = QVariantMap(), const QVariantMap& extra = QVariantMap()) {
if (category.isDebugEnabled()) {
tracing::traceEvent(category, name, tracing::AsyncNestableEnd, id, args, extra);
}
}
inline void instant(const QLoggingCategory& category, const QString& name, const QString& scope = "t", const QVariantMap& args = QVariantMap(), QVariantMap extra = QVariantMap()) {
if (category.isDebugEnabled()) {
extra["s"] = scope;
tracing::traceEvent(category, name, tracing::Instant, "", args, extra);
}
}
inline void counter(const QLoggingCategory& category, const QString& name, const QVariantMap& args, const QVariantMap& extra = QVariantMap()) {
if (category.isDebugEnabled()) {
tracing::traceEvent(category, name, tracing::Counter, "", args, extra);
}
}
#define PROFILE_RANGE(category, name) Duration profileRangeThis(category(), name);
#define PROFILE_RANGE_EX(category, name, argbColor, payload, ...) Duration profileRangeThis(category(), name, argbColor, (uint64_t)payload, ##__VA_ARGS__);
#define PROFILE_RANGE_BEGIN(category, rangeId, name, argbColor) rangeId = Duration::beginRange(category(), name, argbColor)
#define PROFILE_RANGE_END(category, rangeId) Duration::endRange(category(), rangeId)
#define PROFILE_ASYNC_BEGIN(category, name, id, ...) asyncBegin(category(), name, id, ##__VA_ARGS__);
#define PROFILE_ASYNC_END(category, name, id, ...) asyncEnd(category(), name, id, ##__VA_ARGS__);
#define PROFILE_COUNTER(category, name, ...) counter(category(), name, ##__VA_ARGS__);
#define PROFILE_INSTANT(category, name, ...) instant(category(), name, ##__VA_ARGS__);
#endif

View file

@ -0,0 +1,34 @@
//
// Created by Ryan Huffman on 2016-12-14
// Copyright 2013-2016 High Fidelity, Inc.
//
// Distributed under the Apache License, Version 2.0.
// See the accompanying file LICENSE or http://www.apache.org/licenses/LICENSE-2.0.html
//
#include "StatTracker.h"
StatTracker::StatTracker() {
}
QVariant StatTracker::getStat(QString name) {
std::lock_guard<std::mutex> lock(_statsLock);
return _stats[name];
}
void StatTracker::editStat(QString name, EditStatFunction fn) {
std::lock_guard<std::mutex> lock(_statsLock);
_stats[name] = fn(_stats[name]);
}
void StatTracker::incrementStat(QString name) {
std::lock_guard<std::mutex> lock(_statsLock);
QVariant stat = _stats[name];
_stats[name] = _stats[name].toInt() + 1;
}
void StatTracker::decrementStat(QString name) {
std::lock_guard<std::mutex> lock(_statsLock);
_stats[name] = _stats[name].toInt() - 1;
}

View file

@ -0,0 +1,45 @@
//
// Created by Ryan Huffman on 2016-12-14
// Copyright 2013-2016 High Fidelity, Inc.
//
// Distributed under the Apache License, Version 2.0.
// See the accompanying file LICENSE or http://www.apache.org/licenses/LICENSE-2.0.html
//
#pragma once
#include <QString>
#include <QVariant>
#include <QVariantMap>
#include <mutex>
#include "DependencyManager.h"
#include "Trace.h"
using EditStatFunction = std::function<QVariant(QVariant currentValue)>;
class StatTracker : public Dependency {
public:
StatTracker();
QVariant getStat(QString name);
void editStat(QString name, EditStatFunction fn);
void incrementStat(QString name);
void decrementStat(QString name);
private:
std::mutex _statsLock;
QVariantMap _stats;
};
class CounterStat {
public:
CounterStat(QString name) : _name(name) {
DependencyManager::get<StatTracker>()->incrementStat(_name);
//trace::COUNTER("processing", "stats", {
//{ "active", DependencyManager::get<StatTracker>()->getStat("ResourceProcessing").toInt() }
//});
}
~CounterStat() {
DependencyManager::get<StatTracker>()->decrementStat(_name);
}
private:
QString _name;
};

View file

@ -0,0 +1,205 @@
//
// Created by Ryan Huffman on 2016-12-14
// Copyright 2013-2016 High Fidelity, Inc.
//
// Distributed under the Apache License, Version 2.0.
// See the accompanying file LICENSE or http://www.apache.org/licenses/LICENSE-2.0.html
//
#include "Trace.h"
#include <chrono>
#include <QtCore/QDebug>
#include <QtCore/QCoreApplication>
#include <QtCore/QThread>
#include <QtCore/QFile>
#include <QtCore/QFileInfo>
#include <QtCore/QTemporaryFile>
#include <QtCore/QDataStream>
#include <QtCore/QTextStream>
#include <QtCore/QJsonObject>
#include <QtCore/QJsonDocument>
#include <BuildInfo.h>
#include "Gzip.h"
#include "PortableHighResolutionClock.h"
#include "shared/GlobalAppProperties.h"
using namespace tracing;
bool tracing::enabled() {
return DependencyManager::get<Tracer>()->isEnabled();
}
void Tracer::startTracing() {
std::lock_guard<std::mutex> guard(_eventsMutex);
if (_enabled) {
qWarning() << "Tried to enable tracer, but already enabled";
return;
}
_events.clear();
_enabled = true;
}
void Tracer::stopTracing() {
std::lock_guard<std::mutex> guard(_eventsMutex);
if (!_enabled) {
qWarning() << "Cannot stop tracing, already disabled";
return;
}
_enabled = false;
}
void TraceEvent::writeJson(QTextStream& out) const {
#if 0
// FIXME QJsonObject serialization is very slow, so we should be using manual JSON serialization
out << "{";
out << "\"name\":\"" << name << "\",";
out << "\"cat\":\"" << category.categoryName() << "\",";
out << "\"ph\":\"" << QString(type) << "\",";
out << "\"ts\":\"" << timestamp << "\",";
out << "\"pid\":\"" << processID << "\",";
out << "\"tid\":\"" << threadID << "\"";
//if (!extra.empty()) {
// auto it = extra.begin();
// for (; it != extra.end(); it++) {
// ev[it.key()] = QJsonValue::fromVariant(it.value());
// }
//}
//if (!args.empty()) {
// out << ",\"args\":'
//}
out << '}';
#else
QJsonObject ev {
{ "name", QJsonValue(name) },
{ "cat", category.categoryName() },
{ "ph", QString(type) },
{ "ts", timestamp },
{ "pid", processID },
{ "tid", threadID }
};
if (!id.isEmpty()) {
ev["id"] = id;
}
if (!args.empty()) {
ev["args"] = QJsonObject::fromVariantMap(args);
}
if (!extra.empty()) {
auto it = extra.begin();
for (; it != extra.end(); it++) {
ev[it.key()] = QJsonValue::fromVariant(it.value());
}
}
out << QJsonDocument(ev).toJson(QJsonDocument::Compact);
#endif
}
void Tracer::serialize(const QString& path) {
std::list<TraceEvent> currentEvents;
{
std::lock_guard<std::mutex> guard(_eventsMutex);
currentEvents.swap(_events);
}
// If the file exists and we can't remove it, fail early
if (QFileInfo(path).exists() && !QFile::remove(path)) {
return;
}
// If we can't open a temp file for writing, fail early
QByteArray data;
{
QTextStream out(&data);
out << "[\n";
bool first = true;
for (const auto& event : currentEvents) {
if (first) {
first = false;
} else {
out << ",\n";
}
event.writeJson(out);
}
out << "\n]";
}
if (path.endsWith(".gz")) {
QByteArray compressed;
gzip(data, compressed);
data = compressed;
}
{
QFile file(path);
if (!file.open(QIODevice::WriteOnly)) {
return;
}
file.write(data);
file.close();
}
#if 0
QByteArray data;
{
// "traceEvents":[
// {"args":{"nv_payload":0},"cat":"hifi.render","name":"render::Scene::processPendingChangesQueue","ph":"B","pid":14796,"tid":21636,"ts":68795933487}
QJsonArray traceEvents;
QJsonDocument document {
QJsonObject {
{ "traceEvents", traceEvents },
{ "otherData", QJsonObject {
{ "version", QString { "High Fidelity Interface v1.0" } +BuildInfo::VERSION }
} }
}
};
data = document.toJson(QJsonDocument::Compact);
}
#endif
}
void Tracer::traceEvent(const QLoggingCategory& category,
const QString& name, EventType type,
qint64 timestamp, qint64 processID, qint64 threadID,
const QString& id,
const QVariantMap& args, const QVariantMap& extra) {
std::lock_guard<std::mutex> guard(_eventsMutex);
if (!_enabled) {
return;
}
_events.push_back({
id,
name,
type,
timestamp,
processID,
threadID,
category,
args,
extra
});
}
void Tracer::traceEvent(const QLoggingCategory& category,
const QString& name, EventType type, const QString& id,
const QVariantMap& args, const QVariantMap& extra) {
if (!_enabled) {
return;
}
auto timestamp = std::chrono::duration_cast<std::chrono::microseconds>(p_high_resolution_clock::now().time_since_epoch()).count();
auto processID = QCoreApplication::applicationPid();
auto threadID = int64_t(QThread::currentThreadId());
traceEvent(category, name, type, timestamp, processID, threadID, id, args, extra);
}

View file

@ -0,0 +1,115 @@
//
// Created by Ryan Huffman on 2016-12-14
// Copyright 2013-2016 High Fidelity, Inc.
//
// Distributed under the Apache License, Version 2.0.
// See the accompanying file LICENSE or http://www.apache.org/licenses/LICENSE-2.0.html
//
#pragma once
#ifndef hifi_Trace_h
#define hifi_Trace_h
#include <cstdint>
#include <mutex>
#include <QtCore/QString>
#include <QtCore/QVariantMap>
#include <QtCore/QHash>
#include <QtCore/QSet>
#include <QtCore/QLoggingCategory>
#include "DependencyManager.h"
#define TRACE_ENABLED
namespace tracing {
bool enabled();
using TraceTimestamp = uint64_t;
enum EventType : char {
DurationBegin = 'B',
DurationEnd = 'E',
Complete = 'X',
Instant = 'i',
Counter = 'C',
AsyncNestableStart = 'b',
AsyncNestableInstant = 'n',
AsyncNestableEnd = 'e',
FlowStart = 's',
FlowStep = 't',
FlowEnd = 'f',
Sample = 'P',
ObjectCreated = 'N',
ObjectSnapshot = 'O',
ObjectDestroyed = 'D',
Metadata = 'M',
MemoryDumpGlobal = 'V',
MemoryDumpProcess = 'v',
Mark = 'R',
ClockSync = 'c',
ContextEnter = '(',
ContextLeave = ')'
};
struct TraceEvent {
QString id;
QString name;
EventType type;
qint64 timestamp;
qint64 processID;
qint64 threadID;
const QLoggingCategory& category;
QVariantMap args;
QVariantMap extra;
void writeJson(QTextStream& out) const;
};
class Tracer : public Dependency {
public:
void traceEvent(const QLoggingCategory& category,
const QString& name, EventType type,
const QString& id = "",
const QVariantMap& args = QVariantMap(), const QVariantMap& extra = QVariantMap());
void startTracing();
void stopTracing();
void serialize(const QString& file);
bool isEnabled() const { return _enabled; }
private:
void traceEvent(const QLoggingCategory& category,
const QString& name, EventType type,
qint64 timestamp, qint64 processID, qint64 threadID,
const QString& id = "",
const QVariantMap& args = QVariantMap(), const QVariantMap& extra = QVariantMap());
bool _enabled { false };
std::list<TraceEvent> _events;
std::mutex _eventsMutex;
};
inline void traceEvent(const QLoggingCategory& category, const QString& name, EventType type, const QString& id = "", const QVariantMap& args = {}, const QVariantMap& extra = {}) {
DependencyManager::get<Tracer>()->traceEvent(category, name, type, id, args, extra);
}
inline void traceEvent(const QLoggingCategory& category, const QString& name, EventType type, int id, const QVariantMap& args = {}, const QVariantMap& extra = {}) {
traceEvent(category, name, type, QString::number(id), args, extra);
}
}
#endif // hifi_Trace_h

View file

@ -14,6 +14,7 @@ namespace hifi { namespace properties {
const char* STEAM = "com.highfidelity.launchedFromSteam";
const char* LOGGER = "com.highfidelity.logger";
const char* TEST = "com.highfidelity.test";
const char* TRACING = "com.highfidelity.tracing";
namespace gl {
const char* BACKEND = "com.highfidelity.gl.backend";

View file

@ -16,6 +16,7 @@ namespace hifi { namespace properties {
extern const char* STEAM;
extern const char* LOGGER;
extern const char* TEST;
extern const char* TRACING;
namespace gl {
extern const char* BACKEND;

View file

@ -21,49 +21,6 @@ bool nsightActive() {
return nsightLaunched;
}
uint64_t ProfileRange::beginRange(const char* name, uint32_t argbColor) {
nvtxEventAttributes_t eventAttrib = { 0 };
eventAttrib.version = NVTX_VERSION;
eventAttrib.size = NVTX_EVENT_ATTRIB_STRUCT_SIZE;
eventAttrib.colorType = NVTX_COLOR_ARGB;
eventAttrib.color = argbColor;
eventAttrib.messageType = NVTX_MESSAGE_TYPE_ASCII;
eventAttrib.message.ascii = name;
return nvtxRangeStartEx(&eventAttrib);
// return nvtxRangePushEx(&eventAttrib);
}
void ProfileRange::endRange(uint64_t rangeId) {
nvtxRangeEnd(rangeId);
// nvtxRangePop();
}
ProfileRange::ProfileRange(const char *name) {
// _rangeId = nvtxRangeStart(name);
_rangeId = nvtxRangePush(name);
}
ProfileRange::ProfileRange(const char *name, uint32_t argbColor, uint64_t payload) {
nvtxEventAttributes_t eventAttrib = {0};
eventAttrib.version = NVTX_VERSION;
eventAttrib.size = NVTX_EVENT_ATTRIB_STRUCT_SIZE;
eventAttrib.colorType = NVTX_COLOR_ARGB;
eventAttrib.color = argbColor;
eventAttrib.messageType = NVTX_MESSAGE_TYPE_ASCII;
eventAttrib.message.ascii = name;
eventAttrib.payload.llValue = payload;
eventAttrib.payloadType = NVTX_PAYLOAD_TYPE_UNSIGNED_INT64;
//_rangeId = nvtxRangeStartEx(&eventAttrib);
_rangeId = nvtxRangePushEx(&eventAttrib);
}
ProfileRange::~ProfileRange() {
// nvtxRangeEnd(_rangeId);
nvtxRangePop();
}
#else
bool nsightActive() {

View file

@ -11,35 +11,6 @@
bool nsightActive();
#if defined(_WIN32) && defined(NSIGHT_FOUND)
#include <stdint.h>
class ProfileRange {
public:
ProfileRange(const char *name);
ProfileRange(const char *name, uint32_t argbColor, uint64_t payload);
~ProfileRange();
static uint64_t beginRange(const char* name, uint32_t argbColor);
static void endRange(uint64_t rangeId);
private:
uint64_t _rangeId{ 0 };
};
#define PROFILE_RANGE(name) ProfileRange profileRangeThis(name);
#define PROFILE_RANGE_EX(name, argbColor, payload) ProfileRange profileRangeThis(name, argbColor, (uint64_t)payload);
#define PROFILE_RANGE_BEGIN(rangeId, name, argbColor) rangeId = ProfileRange::beginRange(name, argbColor)
#define PROFILE_RANGE_END(rangeId) ProfileRange::endRange(rangeId)
#else
#define PROFILE_RANGE(name)
#define PROFILE_RANGE_EX(name, argbColor, payload)
#define PROFILE_RANGE_BEGIN(rangeId, name, argbColor)
#define PROFILE_RANGE_END(rangeId)
#endif
#include "../Profile.h"
#endif

View file

@ -110,7 +110,7 @@ void OculusDisplayPlugin::hmdPresent() {
return;
}
PROFILE_RANGE_EX(__FUNCTION__, 0xff00ff00, (uint64_t)_currentFrame->frameIndex)
PROFILE_RANGE_EX(displayplugins, __FUNCTION__, 0xff00ff00, (uint64_t)_currentFrame->frameIndex)
int curIndex;
ovr_GetTextureSwapChainCurrentIndex(_session, _textureSwapChain, &curIndex);

View file

@ -11,7 +11,6 @@
#include <atomic>
#include <Windows.h>
#include <QtCore/QLoggingCategory>
#include <QtCore/QFile>
#include <QtCore/QDir>
#include <QtCore/QProcessEnvironment>
@ -20,8 +19,8 @@
#include <controllers/Pose.h>
#include <NumericalConstants.h>
Q_DECLARE_LOGGING_CATEGORY(oculus)
Q_LOGGING_CATEGORY(oculus, "hifi.plugins.oculus")
Q_LOGGING_CATEGORY(displayplugins, "hifi.plugins.display")
Q_LOGGING_CATEGORY(oculus, "hifi.plugins.display.oculus")
static std::atomic<uint32_t> refCount { 0 };
static ovrSession session { nullptr };

View file

@ -7,6 +7,9 @@
//
#pragma once
#include <QtCore/QLoggingCategory>
#include <OVR_CAPI_GL.h>
#include <GLMHelpers.h>
#include <glm/gtc/type_ptr.hpp>
@ -14,6 +17,9 @@
#include <controllers/Forward.h>
Q_DECLARE_LOGGING_CATEGORY(displayplugins)
Q_DECLARE_LOGGING_CATEGORY(oculus)
void logWarning(const char* what);
void logCritical(const char* what);
bool oculusAvailable();

View file

@ -529,7 +529,7 @@ static bool isBadPose(vr::HmdMatrix34_t* mat) {
}
bool OpenVrDisplayPlugin::beginFrameRender(uint32_t frameIndex) {
PROFILE_RANGE_EX(__FUNCTION__, 0xff7fff00, frameIndex)
PROFILE_RANGE_EX(displayplugins, __FUNCTION__, 0xff7fff00, frameIndex)
handleOpenVrEvents();
if (openVrQuitRequested()) {
QMetaObject::invokeMethod(qApp, "quit");
@ -633,7 +633,7 @@ void OpenVrDisplayPlugin::compositeLayers() {
}
void OpenVrDisplayPlugin::hmdPresent() {
PROFILE_RANGE_EX(__FUNCTION__, 0xff00ff00, (uint64_t)_currentFrame->frameIndex)
PROFILE_RANGE_EX(displayplugins, __FUNCTION__, 0xff00ff00, (uint64_t)_currentFrame->frameIndex)
if (_threadedSubmit) {
_submitThread->waitForPresent();
@ -654,7 +654,7 @@ void OpenVrDisplayPlugin::hmdPresent() {
}
void OpenVrDisplayPlugin::postPreview() {
PROFILE_RANGE_EX(__FUNCTION__, 0xff00ff00, (uint64_t)_currentFrame->frameIndex)
PROFILE_RANGE_EX(displayplugins, __FUNCTION__, 0xff00ff00, (uint64_t)_currentFrame->frameIndex)
PoseData nextRender, nextSim;
nextRender.frameIndex = presentCount();

View file

@ -6,9 +6,19 @@
// See the accompanying file LICENSE or http://www.apache.org/licenses/LICENSE-2.0.html
//
print("Fooooo");
Script.setTimeout(function() {
var loggingRules = "" +
"*.debug=false\n" +
"hifi.render.debug=true\n" +
"hifi.interface.debug=true\n" +
"";
Test.startTracing(loggingRules);
}, 1 * 1000);
Script.setTimeout(function() {
Test.stopTracing("h:/testScriptTrace.json.gz");
Test.quit();
}, 10 * 1000);

View file

@ -70,6 +70,8 @@
#include "Camera.hpp"
Q_DECLARE_LOGGING_CATEGORY(renderperflogging)
Q_LOGGING_CATEGORY(renderperflogging, "hifi.render_perf")
static const QString LAST_SCENE_KEY = "lastSceneFile";
static const QString LAST_LOCATION_KEY = "lastLocation";
@ -856,7 +858,6 @@ private:
EntityUpdateOperator updateOperator(now);
//getEntities()->getTree()->recurseTreeWithOperator(&updateOperator);
{
PROFILE_RANGE_EX("PreRenderLambdas", 0xffff0000, (uint64_t)0);
for (auto& iter : _postUpdateLambdas) {
iter.second();
}
@ -899,7 +900,7 @@ private:
gpu::doInBatch(gpuContext, [&](gpu::Batch& batch) {
batch.resetStages();
});
PROFILE_RANGE(__FUNCTION__);
PROFILE_RANGE(renderperflogging, __FUNCTION__);
PerformanceTimer perfTimer("draw");
// The pending changes collecting the changes here
render::PendingChanges pendingChanges;

View file

@ -563,7 +563,6 @@ private:
gpu::doInBatch(gpuContext, [&](gpu::Batch& batch) {
batch.resetStages();
});
PROFILE_RANGE(__FUNCTION__);
auto framebuffer = DependencyManager::get<FramebufferCache>()->getFramebuffer();
gpu::doInBatch(gpuContext, [&](gpu::Batch& batch) {

View file

@ -0,0 +1,45 @@
//
// Created by Bradley Austin Davis on 2016/12/15
// Copyright 2013-2016 High Fidelity, Inc.
//
// Distributed under the Apache License, Version 2.0.
// See the accompanying file LICENSE or http://www.apache.org/licenses/LICENSE-2.0.html
//
#include "TraceTests.h"
#include <QtTest/QtTest>
#include <Trace.h>
#include <SharedUtil.h>
#include <NumericalConstants.h>
#include <../QTestExtensions.h>
QTEST_MAIN(TraceTests)
Q_LOGGING_CATEGORY(tracertestlogging, "hifi.tracer.test")
void TraceTests::testTraceSerialization() {
auto tracer = DependencyManager::set<tracing::Tracer>();
tracer->startTracing();
tracer->traceEvent(tracertestlogging(), "TestEvent", tracing::DurationBegin);
{
auto start = usecTimestampNow();
for (size_t i = 0; i < 10000; ++i) {
tracer->traceEvent(tracertestlogging(), "TestCounter", tracing::Counter, "", { { "i", i } });
}
auto duration = usecTimestampNow() - start;
duration /= USECS_PER_MSEC;
qDebug() << "Recording took " << duration << "ms";
}
tracer->traceEvent(tracertestlogging(), "TestEvent", tracing::DurationEnd);
tracer->stopTracing();
{
auto start = usecTimestampNow();
tracer->serialize("testTrace.json.gz");
auto duration = usecTimestampNow() - start;
duration /= USECS_PER_MSEC;
qDebug() << "Serialization took " << duration << "ms";
}
qDebug() << "Done";
}

View file

@ -0,0 +1,20 @@
//
// Created by Bradley Austin Davis on 2016/12/15
// Copyright 2013-2016 High Fidelity, Inc.
//
// Distributed under the Apache License, Version 2.0.
// See the accompanying file LICENSE or http://www.apache.org/licenses/LICENSE-2.0.html
//
#ifndef hifi_TraceTests_h
#define hifi_TraceTests_h
#include <QtCore/QObject>
class TraceTests : public QObject {
Q_OBJECT
private slots:
void testTraceSerialization();
};
#endif // hifi_TraceTests_h