From a913a6aa5aed2121dee7ca39574366b814358c7c Mon Sep 17 00:00:00 2001 From: Nyall Dawson Date: Mon, 18 May 2020 14:22:16 +1000 Subject: [PATCH] Create RAII QgsScopedRuntimeProfile class and Python context manager to ease logging of runtime profiles. Now it's possible to do: with QgsRuntimeProfiler.profile('My operation'): # do something to automatically handle everything required to log the operation runtime --- python/core/__init__.py.in | 2 + .../auto_generated/qgsruntimeprofiler.sip.in | 37 +++++++++++++++++++ src/app/qgisapp.cpp | 3 +- src/app/qgspluginregistry.cpp | 1 + src/core/qgsruntimeprofiler.cpp | 20 ++++++++-- src/core/qgsruntimeprofiler.h | 37 +++++++++++++++++++ 6 files changed, 95 insertions(+), 5 deletions(-) diff --git a/python/core/__init__.py.in b/python/core/__init__.py.in index 7c91ee733ff..59b16954078 100644 --- a/python/core/__init__.py.in +++ b/python/core/__init__.py.in @@ -36,6 +36,7 @@ from .additions.qgsgeometry import _geometryNonZero, mapping_geometry from .additions.qgssettings import _qgssettings_enum_value, _qgssettings_set_enum_value, _qgssettings_flag_value from .additions.qgstaskwrapper import QgsTaskWrapper from .additions.readwritecontextentercategory import ReadWriteContextEnterCategory +from .additions.runtimeprofiler import ScopedRuntimeProfileContextManager from .additions.validitycheck import check # Injections into classes @@ -47,6 +48,7 @@ QgsProcessingFeatureSourceDefinition.__repr__ = processing_source_repr QgsProcessingOutputLayerDefinition.__repr__ = processing_output_layer_repr QgsProject.blockDirtying = ProjectDirtyBlocker QgsReadWriteContext.enterCategory = ReadWriteContextEnterCategory +QgsRuntimeProfiler.profile = ScopedRuntimeProfileContextManager QgsSettings.enumValue = _qgssettings_enum_value QgsSettings.setEnumValue = _qgssettings_set_enum_value QgsSettings.flagValue = _qgssettings_flag_value diff --git a/python/core/auto_generated/qgsruntimeprofiler.sip.in b/python/core/auto_generated/qgsruntimeprofiler.sip.in index 5dd7e2a608e..db7cc43a575 100644 --- a/python/core/auto_generated/qgsruntimeprofiler.sip.in +++ b/python/core/auto_generated/qgsruntimeprofiler.sip.in @@ -81,6 +81,43 @@ The current total time collected in the profiler. }; + +class QgsScopedRuntimeProfile +{ +%Docstring + +Scoped object for logging of the runtime for a single operation or group of operations. + +This class automatically takes care of registering an operation in the :py:func:`QgsApplication.profiler()` +registry upon construction, and recording of the elapsed runtime upon destruction. + +Python scripts should not use QgsScopedRuntimeProfile directly. Instead, use :py:func:`QgsRuntimeProfiler.profile()` +.. code-block:: python + + with QgsRuntimeProfiler.profile('My operation'): + # do something + +.. versionadded:: 3.14 +%End + +%TypeHeaderCode +#include "qgsruntimeprofiler.h" +%End + public: + + QgsScopedRuntimeProfile( const QString &name ); +%Docstring +Constructor for QgsScopedRuntimeProfile. + +Automatically registers the operation in the QgsApplication.profiler() instance +and starts recording the run time of the operation. +%End + + ~QgsScopedRuntimeProfile(); + +}; + + /************************************************************************ * This file has been generated automatically from * * * diff --git a/src/app/qgisapp.cpp b/src/app/qgisapp.cpp index 946ce13f46f..5925eeaed52 100644 --- a/src/app/qgisapp.cpp +++ b/src/app/qgisapp.cpp @@ -14979,9 +14979,8 @@ void QgisApp::endProfile() void QgisApp::functionProfile( void ( QgisApp::*fnc )(), QgisApp *instance, const QString &name ) { - startProfile( name ); + QgsScopedRuntimeProfile profile( name ); ( instance->*fnc )(); - endProfile(); } void QgisApp::mapCanvas_keyPressed( QKeyEvent *e ) diff --git a/src/app/qgspluginregistry.cpp b/src/app/qgspluginregistry.cpp index f700d353120..069cf666dda 100644 --- a/src/app/qgspluginregistry.cpp +++ b/src/app/qgspluginregistry.cpp @@ -32,6 +32,7 @@ #include "qgslogger.h" #include "qgsmessagelog.h" #include "qgsmessagebar.h" +#include "qgsruntimeprofiler.h" #ifdef WITH_BINDINGS #include "qgspythonutils.h" diff --git a/src/core/qgsruntimeprofiler.cpp b/src/core/qgsruntimeprofiler.cpp index b87dc6e6a8e..ad727da1def 100644 --- a/src/core/qgsruntimeprofiler.cpp +++ b/src/core/qgsruntimeprofiler.cpp @@ -96,10 +96,24 @@ void QgsRuntimeProfiler::clear() double QgsRuntimeProfiler::totalTime() { double total = 0; - QList >::const_iterator it = mProfileTimes.constBegin(); - for ( ; it != mProfileTimes.constEnd(); ++it ) + for ( auto it = mProfileTimes.constBegin(); it != mProfileTimes.constEnd(); ++it ) { - total += ( *it ).second; + total += it->second; } return total; } + + +// +// QgsScopedRuntimeProfile +// + +QgsScopedRuntimeProfile::QgsScopedRuntimeProfile( const QString &name ) +{ + QgsApplication::profiler()->start( name ); +} + +QgsScopedRuntimeProfile::~QgsScopedRuntimeProfile() +{ + QgsApplication::profiler()->end(); +} diff --git a/src/core/qgsruntimeprofiler.h b/src/core/qgsruntimeprofiler.h index 1bb77acae22..5c22b93015c 100644 --- a/src/core/qgsruntimeprofiler.h +++ b/src/core/qgsruntimeprofiler.h @@ -95,4 +95,41 @@ class CORE_EXPORT QgsRuntimeProfiler QList< QPair< QString, double > > mProfileTimes; }; + +/** + * \ingroup core + * + * Scoped object for logging of the runtime for a single operation or group of operations. + * + * This class automatically takes care of registering an operation in the QgsApplication::profiler() + * registry upon construction, and recording of the elapsed runtime upon destruction. + * + * Python scripts should not use QgsScopedRuntimeProfile directly. Instead, use QgsRuntimeProfiler.profile() + * \code{.py} + * with QgsRuntimeProfiler.profile('My operation'): + * # do something + * \endcode + * + * \since QGIS 3.14 + */ +class CORE_EXPORT QgsScopedRuntimeProfile +{ + public: + + /** + * Constructor for QgsScopedRuntimeProfile. + * + * Automatically registers the operation in the QgsApplication::profiler() instance + * and starts recording the run time of the operation. + */ + QgsScopedRuntimeProfile( const QString &name ); + + /** + * Records the final runtime of the operation in the profiler instance. + */ + ~QgsScopedRuntimeProfile(); + +}; + + #endif // QGSRUNTIMEPROFILER_H