From 3b07e31eab766253a22a83e917dc2a911612e4d7 Mon Sep 17 00:00:00 2001 From: Brad Davis Date: Tue, 29 Nov 2016 13:15:56 -0800 Subject: [PATCH] Working on OpenGL debuggability --- interface/src/Application.cpp | 6 +- libraries/gl/src/gl/Context.cpp | 26 ++- libraries/gpu-gl/src/gpu/gl/GLBackend.cpp | 6 +- libraries/gpu/src/gpu/Context.cpp | 10 + .../src/shared/AbstractLoggerInterface.cpp | 30 +++ .../src/shared/AbstractLoggerInterface.h | 5 +- libraries/shared/src/shared/FileLogger.cpp | 24 ++- libraries/shared/src/shared/FileLogger.h | 20 +- .../shared/src/shared/GlobalAppProperties.h | 28 +++ tests/render-perf/src/main.cpp | 194 ++++++++++-------- 10 files changed, 235 insertions(+), 114 deletions(-) create mode 100644 libraries/shared/src/shared/AbstractLoggerInterface.cpp create mode 100644 libraries/shared/src/shared/GlobalAppProperties.h diff --git a/interface/src/Application.cpp b/interface/src/Application.cpp index a072615c03..cff4d6a614 100644 --- a/interface/src/Application.cpp +++ b/interface/src/Application.cpp @@ -45,6 +45,7 @@ #include +#include #include #include #include @@ -536,7 +537,8 @@ Application::Application(int& argc, char** argv, QElapsedTimer& startupTimer, bo _maxOctreePPS(maxOctreePacketsPerSecond.get()), _lastFaceTrackerUpdate(0) { - setProperty("com.highfidelity.launchedFromSteam", SteamClient::isRunning()); + setProperty(hifi::properties::STEAM, SteamClient::isRunning()); + setProperty(hifi::properties::CRASHED, _previousSessionCrashed); _runningMarker.startRunningMarker(); @@ -1686,6 +1688,8 @@ void Application::initializeGL() { _glWidget->makeCurrent(); gpu::Context::init(); + qApp->setProperty(hifi::properties::gl::MAKE_PROGRAM_CALLBACK, + QVariant::fromValue((void*)(&gpu::gl::GLBackend::makeProgram))); _gpuContext = std::make_shared(); // The gpu context can make child contexts for transfers, so // we need to restore primary rendering context diff --git a/libraries/gl/src/gl/Context.cpp b/libraries/gl/src/gl/Context.cpp index ec1c284e99..f7e08e607b 100644 --- a/libraries/gl/src/gl/Context.cpp +++ b/libraries/gl/src/gl/Context.cpp @@ -19,10 +19,11 @@ #include #include +#include +#include #include #include "GLLogging.h" - #ifdef Q_OS_WIN #ifdef DEBUG @@ -37,7 +38,6 @@ static bool enableDebugLogger = QProcessEnvironment::systemEnvironment().contain #include "Config.h" #include "GLHelpers.h" - using namespace gl; @@ -131,7 +131,6 @@ void Context::setWindow(QWindow* window) { } #ifdef Q_OS_WIN -static const char* PRIMARY_CONTEXT_PROPERTY_NAME = "com.highfidelity.gl.primaryContext"; bool Context::makeCurrent() { BOOL result = wglMakeCurrent(_hdc, _hglrc); @@ -153,7 +152,17 @@ void GLAPIENTRY debugMessageCallback(GLenum source, GLenum type, GLuint id, GLen if (GL_DEBUG_SEVERITY_NOTIFICATION == severity) { return; } - qCDebug(glLogging) << "QQQ " << message; + qCDebug(glLogging) << "OpenGL: " << message; + + // For high severity errors, force a sync to the log, since we might crash + // before the log file was flushed otherwise. Performance hit here + if (GL_DEBUG_SEVERITY_HIGH == severity) { + AbstractLoggerInterface* logger = AbstractLoggerInterface::get(); + if (logger) { + // FIXME find a way to force the log file to sync that doesn't lead to a deadlock + // logger->sync(); + } + } } // FIXME build the PFD based on the @@ -192,7 +201,7 @@ void setupPixelFormatSimple(HDC hdc) { void Context::create() { if (!PRIMARY) { - PRIMARY = static_cast(qApp->property(PRIMARY_CONTEXT_PROPERTY_NAME).value()); + PRIMARY = static_cast(qApp->property(hifi::properties::gl::PRIMARY_CONTEXT).value()); } if (PRIMARY) { @@ -205,6 +214,11 @@ void Context::create() { // Create a temporary context to initialize glew static std::once_flag once; std::call_once(once, [&] { + // If the previous run crashed, force GL debug logging on + if (qApp->property(hifi::properties::CRASHED).toBool()) { + enableDebugLogger = true; + } + auto hdc = GetDC(hwnd); setupPixelFormatSimple(hdc); auto glrc = wglCreateContext(hdc); @@ -290,7 +304,7 @@ void Context::create() { if (!PRIMARY) { PRIMARY = this; - qApp->setProperty(PRIMARY_CONTEXT_PROPERTY_NAME, QVariant::fromValue((void*)PRIMARY)); + qApp->setProperty(hifi::properties::gl::PRIMARY_CONTEXT, QVariant::fromValue((void*)PRIMARY)); } if (enableDebugLogger) { diff --git a/libraries/gpu-gl/src/gpu/gl/GLBackend.cpp b/libraries/gpu-gl/src/gpu/gl/GLBackend.cpp index 719989a07a..c8a5854354 100644 --- a/libraries/gpu-gl/src/gpu/gl/GLBackend.cpp +++ b/libraries/gpu-gl/src/gpu/gl/GLBackend.cpp @@ -23,6 +23,7 @@ #include "nvToolsExt.h" #endif +#include #include #include #include @@ -36,7 +37,6 @@ static const QString DEBUG_FLAG("HIFI_DISABLE_OPENGL_45"); static bool disableOpenGL45 = QProcessEnvironment::systemEnvironment().contains(DEBUG_FLAG); static GLBackend* INSTANCE{ nullptr }; -static const char* GL_BACKEND_PROPERTY_NAME = "com.highfidelity.gl.backend"; BackendPointer GLBackend::createBackend() { // The ATI memory info extension only exposes 'free memory' so we want to force it to @@ -60,7 +60,7 @@ BackendPointer GLBackend::createBackend() { INSTANCE = result.get(); void* voidInstance = &(*result); - qApp->setProperty(GL_BACKEND_PROPERTY_NAME, QVariant::fromValue(voidInstance)); + qApp->setProperty(hifi::properties::gl::BACKEND, QVariant::fromValue(voidInstance)); gl::GLTexture::initTextureTransferHelper(); return result; @@ -68,7 +68,7 @@ BackendPointer GLBackend::createBackend() { GLBackend& getBackend() { if (!INSTANCE) { - INSTANCE = static_cast(qApp->property(GL_BACKEND_PROPERTY_NAME).value()); + INSTANCE = static_cast(qApp->property(hifi::properties::gl::BACKEND).value()); } return *INSTANCE; } diff --git a/libraries/gpu/src/gpu/Context.cpp b/libraries/gpu/src/gpu/Context.cpp index c96ae2cd19..cc94fe7752 100644 --- a/libraries/gpu/src/gpu/Context.cpp +++ b/libraries/gpu/src/gpu/Context.cpp @@ -9,8 +9,12 @@ // See the accompanying file LICENSE or http://www.apache.org/licenses/LICENSE-2.0.html // #include "Context.h" + +#include + #include "Frame.h" #include "GPULogging.h" + using namespace gpu; @@ -118,6 +122,12 @@ void Context::executeFrame(const FramePointer& frame) const { } bool Context::makeProgram(Shader& shader, const Shader::BindingSet& bindings) { + // If we're running in another DLL context, we need to fetch the program callback out of the application + // FIXME find a way to do this without reliance on Qt app properties + if (!_makeProgramCallback) { + void* rawCallback = qApp->property(hifi::properties::gl::MAKE_PROGRAM_CALLBACK).value(); + _makeProgramCallback = static_cast(rawCallback); + } if (shader.isProgram() && _makeProgramCallback) { return _makeProgramCallback(shader, bindings); } diff --git a/libraries/shared/src/shared/AbstractLoggerInterface.cpp b/libraries/shared/src/shared/AbstractLoggerInterface.cpp new file mode 100644 index 0000000000..ea722d03d2 --- /dev/null +++ b/libraries/shared/src/shared/AbstractLoggerInterface.cpp @@ -0,0 +1,30 @@ +// +// Created by Bradley Austin Davis on 2016/11/29 +// 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 "AbstractLoggerInterface.h" +#include "GlobalAppProperties.h" + +#include +#include + +AbstractLoggerInterface* AbstractLoggerInterface::get() { + QVariant loggerVar = qApp->property(hifi::properties::LOGGER); + QObject* loggerObject = qvariant_cast(loggerVar); + return qobject_cast(loggerObject); +} + +AbstractLoggerInterface::AbstractLoggerInterface(QObject* parent) : QObject(parent) { + qApp->setProperty(hifi::properties::LOGGER, QVariant::fromValue(this)); +} + +AbstractLoggerInterface::~AbstractLoggerInterface() { + if (qApp) { + qApp->setProperty(hifi::properties::LOGGER, QVariant()); + } +} + diff --git a/libraries/shared/src/shared/AbstractLoggerInterface.h b/libraries/shared/src/shared/AbstractLoggerInterface.h index 3823060b13..6a3c47a324 100644 --- a/libraries/shared/src/shared/AbstractLoggerInterface.h +++ b/libraries/shared/src/shared/AbstractLoggerInterface.h @@ -20,13 +20,16 @@ class AbstractLoggerInterface : public QObject { Q_OBJECT public: - AbstractLoggerInterface(QObject* parent = NULL) : QObject(parent) {} + static AbstractLoggerInterface* get(); + AbstractLoggerInterface(QObject* parent = NULL); + ~AbstractLoggerInterface(); inline bool extraDebugging() { return _extraDebugging; } inline void setExtraDebugging(bool debugging) { _extraDebugging = debugging; } virtual void addMessage(const QString&) = 0; virtual QString getLogData() = 0; virtual void locateLog() = 0; + virtual void sync() {} signals: void logReceived(QString message); diff --git a/libraries/shared/src/shared/FileLogger.cpp b/libraries/shared/src/shared/FileLogger.cpp index 143438ba68..3f181b36d5 100644 --- a/libraries/shared/src/shared/FileLogger.cpp +++ b/libraries/shared/src/shared/FileLogger.cpp @@ -21,6 +21,25 @@ #include "../NumericalConstants.h" #include "../SharedUtil.h" +class FilePersistThread : public GenericQueueThread < QString > { + Q_OBJECT +public: + FilePersistThread(const FileLogger& logger); + +signals: + void rollingLogFile(QString newFilename); + +protected: + void rollFileIfNecessary(QFile& file, bool notifyListenersIfRolled = true); + virtual bool processQueueItems(const Queue& messages) override; + +private: + const FileLogger& _logger; + QMutex _fileMutex; + uint64_t _lastRollTime; +}; + + static const QString FILENAME_FORMAT = "hifi-log_%1_%2.txt"; static const QString DATETIME_FORMAT = "yyyy-MM-dd_hh.mm.ss"; @@ -97,6 +116,7 @@ void FilePersistThread::rollFileIfNecessary(QFile& file, bool notifyListenersIfR } bool FilePersistThread::processQueueItems(const Queue& messages) { + QMutexLocker lock(&_fileMutex); QFile file(_logger._fileName); rollFileIfNecessary(file); if (file.open(QIODevice::WriteOnly | QIODevice::Append | QIODevice::Text)) { @@ -140,5 +160,7 @@ QString FileLogger::getLogData() { } void FileLogger::sync() { - _persistThreadInstance->waitIdle(); + _persistThreadInstance->process(); } + +#include "FileLogger.moc" \ No newline at end of file diff --git a/libraries/shared/src/shared/FileLogger.h b/libraries/shared/src/shared/FileLogger.h index f0f6dd5c09..15d211afe8 100644 --- a/libraries/shared/src/shared/FileLogger.h +++ b/libraries/shared/src/shared/FileLogger.h @@ -28,7 +28,7 @@ public: virtual void addMessage(const QString&) override; virtual QString getLogData() override; virtual void locateLog() override; - void sync(); + virtual void sync() override; signals: void rollingLogFile(QString newFilename); @@ -38,24 +38,6 @@ private: friend class FilePersistThread; }; -class FilePersistThread : public GenericQueueThread < QString > { - Q_OBJECT -public: - FilePersistThread(const FileLogger& logger); - -signals: - void rollingLogFile(QString newFilename); - -protected: - void rollFileIfNecessary(QFile& file, bool notifyListenersIfRolled = true); - virtual bool processQueueItems(const Queue& messages) override; - -private: - const FileLogger& _logger; - uint64_t _lastRollTime; -}; - - #endif // hifi_FileLogger_h diff --git a/libraries/shared/src/shared/GlobalAppProperties.h b/libraries/shared/src/shared/GlobalAppProperties.h new file mode 100644 index 0000000000..51a196e30b --- /dev/null +++ b/libraries/shared/src/shared/GlobalAppProperties.h @@ -0,0 +1,28 @@ +// +// Created by Bradley Austin Davis on 2016/11/29 +// 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_GlobalAppProperties_h +#define hifi_GlobalAppProperties_h + +namespace hifi { namespace properties { + + static const char* CRASHED = "com.highfidelity.crashed"; + static const char* STEAM = "com.highfidelity.launchedFromSteam"; + static const char* LOGGER = "com.highfidelity.logger"; + + namespace gl { + static const char* BACKEND = "com.highfidelity.gl.backend"; + static const char* MAKE_PROGRAM_CALLBACK = "com.highfidelity.gl.makeProgram"; + static const char* PRIMARY_CONTEXT = "com.highfidelity.gl.primaryContext"; + } + +} } + + +#endif // hifi_GlobalAppProperties_h diff --git a/tests/render-perf/src/main.cpp b/tests/render-perf/src/main.cpp index aaf8607f58..e798969268 100644 --- a/tests/render-perf/src/main.cpp +++ b/tests/render-perf/src/main.cpp @@ -46,6 +46,9 @@ #include #include +#include +#include +#include #include #include #include @@ -104,13 +107,13 @@ public: class QWindowCamera : public Camera { Key forKey(int key) { switch (key) { - case Qt::Key_W: return FORWARD; - case Qt::Key_S: return BACK; - case Qt::Key_A: return LEFT; - case Qt::Key_D: return RIGHT; - case Qt::Key_E: return UP; - case Qt::Key_C: return DOWN; - default: break; + case Qt::Key_W: return FORWARD; + case Qt::Key_S: return BACK; + case Qt::Key_A: return LEFT; + case Qt::Key_D: return RIGHT; + case Qt::Key_E: return UP; + case Qt::Key_C: return DOWN; + default: break; } return INVALID; } @@ -152,7 +155,7 @@ public: }; static QString toHumanSize(size_t size, size_t maxUnit = std::numeric_limits::max()) { - static const std::vector SUFFIXES{ { "B", "KB", "MB", "GB", "TB", "PB" } }; + static const std::vector SUFFIXES { { "B", "KB", "MB", "GB", "TB", "PB" } }; const size_t maxIndex = std::min(maxUnit, SUFFIXES.size() - 1); size_t suffixIndex = 0; @@ -187,7 +190,7 @@ public: gpu::ContextPointer _gpuContext; // initialized during window creation std::atomic _presentCount; QElapsedTimer _elapsed; - std::atomic _fps{ 1 }; + std::atomic _fps { 1 }; RateCounter<200> _fpsCounter; std::mutex _mutex; std::shared_ptr _backend; @@ -197,7 +200,7 @@ public: std::queue _pendingFrames; gpu::FramePointer _activeFrame; QSize _size; - static const size_t FRAME_TIME_BUFFER_SIZE{ 8192 }; + static const size_t FRAME_TIME_BUFFER_SIZE { 8192 }; void submitFrame(const gpu::FramePointer& frame) { std::unique_lock lock(_frameLock); @@ -273,7 +276,7 @@ public: _gpuContext->executeFrame(frame); { - + auto geometryCache = DependencyManager::get(); gpu::Batch presentBatch; presentBatch.setViewportTransform({ 0, 0, _size.width(), _size.height() }); @@ -290,7 +293,7 @@ public: _context.makeCurrent(); _context.swapBuffers(); _fpsCounter.increment(); - static size_t _frameCount{ 0 }; + static size_t _frameCount { 0 }; ++_frameCount; if (_elapsed.elapsed() >= 500) { _fps = _fpsCounter.rate(); @@ -357,6 +360,21 @@ public: } }; +class TestActionFactory : public EntityActionFactoryInterface { +public: + virtual EntityActionPointer factory(EntityActionType type, + const QUuid& id, + EntityItemPointer ownerEntity, + QVariantMap arguments) override { + return EntityActionPointer(); + } + + + virtual EntityActionPointer factoryBA(EntityItemPointer ownerEntity, QByteArray data) override { + return nullptr; + } +}; + // Background Render Data & rendering functions class BackgroundRenderData { public: @@ -386,17 +404,17 @@ namespace render { auto backgroundMode = skyStage->getBackgroundMode(); switch (backgroundMode) { - case model::SunSkyStage::SKY_BOX: { - auto skybox = skyStage->getSkybox(); - if (skybox) { - PerformanceTimer perfTimer("skybox"); - skybox->render(batch, args->getViewFrustum()); - break; + case model::SunSkyStage::SKY_BOX: { + auto skybox = skyStage->getSkybox(); + if (skybox) { + PerformanceTimer perfTimer("skybox"); + skybox->render(batch, args->getViewFrustum()); + break; + } } - } - default: - // this line intentionally left blank - break; + default: + // this line intentionally left blank + break; } } } @@ -452,6 +470,7 @@ protected: public: //"/-17.2049,-8.08629,-19.4153/0,0.881994,0,-0.47126" static void setup() { + DependencyManager::registerInheritance(); DependencyManager::registerInheritance(); DependencyManager::registerInheritance(); DependencyManager::set(); @@ -466,6 +485,7 @@ public: DependencyManager::set(); DependencyManager::set(); DependencyManager::set(); + DependencyManager::set(); } QTestWindow() { @@ -486,6 +506,13 @@ public: permissions.setAll(true); nodeList->setPermissions(permissions); + { + SimpleEntitySimulationPointer simpleSimulation { new SimpleEntitySimulation() }; + simpleSimulation->setEntityTree(_octree->getTree()); + _octree->getTree()->setSimulation(simpleSimulation); + _entitySimulation = simpleSimulation; + } + ResourceManager::init(); setFlags(Qt::MSWindowsOwnDC | Qt::Window | Qt::Dialog | Qt::WindowMinMaxButtonsHint | Qt::WindowTitleHint); @@ -561,49 +588,49 @@ protected: void keyPressEvent(QKeyEvent* event) override { switch (event->key()) { - case Qt::Key_F1: - importScene(); - return; + case Qt::Key_F1: + importScene(); + return; - case Qt::Key_F2: - reloadScene(); - return; + case Qt::Key_F2: + reloadScene(); + return; - case Qt::Key_F4: - cycleMode(); - return; + case Qt::Key_F4: + cycleMode(); + return; - case Qt::Key_F5: - goTo(); - return; + case Qt::Key_F5: + goTo(); + return; - case Qt::Key_F6: - savePosition(); - return; + case Qt::Key_F6: + savePosition(); + return; - case Qt::Key_F7: - restorePosition(); - return; + case Qt::Key_F7: + restorePosition(); + return; - case Qt::Key_F8: - resetPosition(); - return; + case Qt::Key_F8: + resetPosition(); + return; - case Qt::Key_F9: - toggleCulling(); - return; + case Qt::Key_F9: + toggleCulling(); + return; - case Qt::Key_Home: - gpu::Texture::setAllowedGPUMemoryUsage(0); - return; + case Qt::Key_Home: + gpu::Texture::setAllowedGPUMemoryUsage(0); + return; - case Qt::Key_End: - gpu::Texture::setAllowedGPUMemoryUsage(MB_TO_BYTES(64)); - return; + case Qt::Key_End: + gpu::Texture::setAllowedGPUMemoryUsage(MB_TO_BYTES(64)); + return; - default: - break; + default: + break; } _camera.onKeyPress(event); } @@ -676,7 +703,7 @@ private: auto framebufferCache = DependencyManager::get(); framebufferCache->setFrameBufferSize(windowSize); - + renderArgs._blitFramebuffer = framebufferCache->getFramebuffer(); // Viewport is assigned to the size of the framebuffer renderArgs._viewport = ivec4(0, 0, windowSize.width(), windowSize.height()); @@ -756,34 +783,34 @@ private: if (commandParams.length() < 2) { qDebug() << "No wait time specified"; return; - } + } int seconds = commandParams[1].toInt(); _nextCommandTime = usecTimestampNow() + seconds * USECS_PER_SECOND; - } else if (verb == "load") { - if (commandParams.length() < 2) { - qDebug() << "No load file specified"; - return; - } - QString file = commandParams[1]; - if (QFileInfo(file).isRelative()) { - file = _commandPath + "/" + file; - } - if (!QFileInfo(file).exists()) { - qDebug() << "Cannot find scene file " + file; - return; - } - - importScene(file); - } else if (verb == "go") { - if (commandParams.length() < 2) { - qDebug() << "No destination specified for go command"; - return; - } - parsePath(commandParams[1]); - } else { - qDebug() << "Unknown command " << command; + } else if (verb == "load") { + if (commandParams.length() < 2) { + qDebug() << "No load file specified"; + return; } + QString file = commandParams[1]; + if (QFileInfo(file).isRelative()) { + file = _commandPath + "/" + file; + } + if (!QFileInfo(file).exists()) { + qDebug() << "Cannot find scene file " + file; + return; + } + + importScene(file); + } else if (verb == "go") { + if (commandParams.length() < 2) { + qDebug() << "No destination specified for go command"; + return; + } + parsePath(commandParams[1]); + } else { + qDebug() << "Unknown command " << command; } +} void runNextCommand(quint64 now) { if (_commands.empty()) { @@ -893,14 +920,14 @@ private: } auto frame = gpuContext->endFrame(); frame->framebuffer = renderArgs->_blitFramebuffer; - frame->framebufferRecycler = [](const gpu::FramebufferPointer& framebuffer){ + frame->framebufferRecycler = [](const gpu::FramebufferPointer& framebuffer) { DependencyManager::get()->releaseFramebuffer(framebuffer); }; _renderThread.submitFrame(frame); if (!_renderThread.isThreaded()) { _renderThread.process(); } - + } @@ -1046,7 +1073,7 @@ private: } private: - render::CullFunctor _cullFunctor { [&](const RenderArgs* args, const AABox& bounds)->bool{ + render::CullFunctor _cullFunctor { [&](const RenderArgs* args, const AABox& bounds)->bool { if (_cullingEnabled) { return cull(args, bounds); } else { @@ -1068,6 +1095,7 @@ private: model::SunSkyStage _sunSkyStage; model::LightPointer _globalLight { std::make_shared() }; bool _ready { false }; + EntitySimulationPointer _entitySimulation; QStringList _commands; QString _commandPath; @@ -1118,7 +1146,7 @@ int main(int argc, char** argv) { QLoggingCategory::setFilterRules(LOG_FILTER_RULES); QTestWindow::setup(); QTestWindow window; - //window.loadCommands("C:/Users/bdavis/Git/dreaming/exports/commands.txt"); + //window.loadCommands("C:/Users/bdavis/Git/dreaming/exports2/commands.txt"); app.exec(); return 0; }