Skip to content

Commit

Permalink
Improve API for QgsRuntimeProfiler
Browse files Browse the repository at this point in the history
Make it easier to nest profiled calls by removing the concept of groups,
and instead allow any profiled operation to have log child operation
runtimes as well as its overall runtime.
  • Loading branch information
nyalldawson committed May 18, 2020
1 parent 6e71130 commit 1b4dd48
Show file tree
Hide file tree
Showing 3 changed files with 94 additions and 33 deletions.
23 changes: 21 additions & 2 deletions python/core/auto_generated/qgsruntimeprofiler.sip.in
Expand Up @@ -21,17 +21,30 @@ class QgsRuntimeProfiler
Constructor to create a new runtime profiler.
%End

void beginGroup( const QString &name );
void beginGroup( const QString &name ) /Deprecated/;
%Docstring
Begin the group for the profiler. Groups will append {GroupName}/ to the
front of the profile tag set using start.

:param name: The name of the group.

.. deprecated::
use start() instead
%End

void endGroup();
void endGroup() /Deprecated/;
%Docstring
End the current active group.

.. deprecated::
use end() instead
%End

QStringList childGroups( const QString &parent = QString() ) const;
%Docstring
Returns a list of all child groups with the specified ``parent``.

.. versionadded:: 3.14
%End

void start( const QString &name );
Expand All @@ -47,6 +60,12 @@ Start a profile event with the given name.
End the current profile event.
%End

double profileTime( const QString &name ) const;
%Docstring
Returns the profile time for the specified ``name``.

.. versionadded:: 3.14
%End

void clear();
%Docstring
Expand Down
74 changes: 54 additions & 20 deletions src/core/qgsruntimeprofiler.cpp
Expand Up @@ -14,46 +14,80 @@
***************************************************************************/
#include "qgsruntimeprofiler.h"
#include "qgslogger.h"
#include "qgis.h"
#include "qgsapplication.h"
#include <QSet>

void QgsRuntimeProfiler::beginGroup( const QString &name )
{
mGroupStack.push( name );
if ( !name.isEmpty() )
{
mGroupPrefix += name;
mGroupPrefix += QLatin1Char( '/' );
}
start( name );
}

void QgsRuntimeProfiler::endGroup()
{
if ( mGroupStack.isEmpty() )
end();
}

QStringList QgsRuntimeProfiler::childGroups( const QString &parent ) const
{
QStringList res;
const int parentDepth = parent.split( '/' ).length();
for ( auto it = mProfileTimes.constBegin(); it != mProfileTimes.constEnd(); ++it )
{
qWarning( "QgsSettings::endGroup: No matching beginGroup()" );
return;
}
if ( !parent.isEmpty() && !it->first.startsWith( parent + '/' ) )
continue;

if ( it->first.isEmpty() )
continue;

QString group = mGroupStack.pop();
int len = group.size();
if ( len > 0 )
mGroupPrefix.truncate( mGroupPrefix.size() - ( len + 1 ) );
const QStringList groups = it->first.split( '/' );
if ( parent.isEmpty() )
{
if ( !res.contains( groups.at( 0 ) ) )
res << groups.at( 0 );
}
else
{
if ( !res.contains( groups.at( parentDepth ) ) )
res << groups.at( parentDepth );
}
}
return res;
}

void QgsRuntimeProfiler::start( const QString &name )
{
mProfileTime.restart();
mCurrentName = name;
mProfileTime.push( QElapsedTimer() );
mProfileTime.top().restart();
mCurrentName.push( name );
}

void QgsRuntimeProfiler::end()
{
QString name = mCurrentName;
name.prepend( mGroupPrefix );
double timing = mProfileTime.elapsed() / 1000.0;
mProfileTimes.append( QPair<QString, double>( name, timing ) );
QString name;
for ( const QString &group : qgis::as_const( mCurrentName ) )
{
name += name.isEmpty() || name.right( 1 ) == '/' ? group : '/' + group;
}
mCurrentName.pop();

double timing = mProfileTime.top().elapsed() / 1000.0;
mProfileTime.pop();

mProfileTimes << qMakePair( name, timing );
QgsDebugMsgLevel( QStringLiteral( "PROFILE: %1 - %2" ).arg( name ).arg( timing ), 2 );
}

double QgsRuntimeProfiler::profileTime( const QString &name ) const
{
for ( auto it = mProfileTimes.constBegin(); it != mProfileTimes.constEnd(); ++it )
{
if ( it->first == name )
return it->second;
}
return -1;
}

void QgsRuntimeProfiler::clear()
{
mProfileTimes.clear();
Expand Down
30 changes: 19 additions & 11 deletions src/core/qgsruntimeprofiler.h
Expand Up @@ -41,13 +41,23 @@ class CORE_EXPORT QgsRuntimeProfiler
* \brief Begin the group for the profiler. Groups will append {GroupName}/ to the
* front of the profile tag set using start.
* \param name The name of the group.
*
* \deprecated use start() instead
*/
void beginGroup( const QString &name );
Q_DECL_DEPRECATED void beginGroup( const QString &name ) SIP_DEPRECATED;

/**
* \brief End the current active group.
*
* \deprecated use end() instead
*/
void endGroup();
Q_DECL_DEPRECATED void endGroup() SIP_DEPRECATED;

/**
* Returns a list of all child groups with the specified \a parent.
* \since QGIS 3.14
*/
QStringList childGroups( const QString &parent = QString() ) const;

/**
* \brief Start a profile event with the given name.
Expand All @@ -62,11 +72,10 @@ class CORE_EXPORT QgsRuntimeProfiler
void end();

/**
* Returns all the current profile times.
* \returns A list of profile event names and times.
* \note not available in Python bindings
* Returns the profile time for the specified \a name.
* \since QGIS 3.14
*/
const QList<QPair<QString, double > > profileTimes() const { return mProfileTimes; } SIP_SKIP
double profileTime( const QString &name ) const;

/**
* \brief clear Clear all profile data.
Expand All @@ -80,11 +89,10 @@ class CORE_EXPORT QgsRuntimeProfiler
double totalTime();

private:
QString mGroupPrefix;
QStack<QString> mGroupStack;
QElapsedTimer mProfileTime;
QString mCurrentName;
QList<QPair<QString, double > > mProfileTimes;

QStack< QElapsedTimer > mProfileTime;
QStack< QString > mCurrentName;
QList< QPair< QString, double > > mProfileTimes;
};

#endif // QGSRUNTIMEPROFILER_H

0 comments on commit 1b4dd48

Please sign in to comment.