QGIS API Documentation  3.21.0-Master (5b68dc587e)
qgsruntimeprofiler.cpp
Go to the documentation of this file.
1 /***************************************************************************
2  qgsruntimeprofiler.cpp
3  ---------------------
4  begin : June 2016
5  copyright : (C) 2016 by Nathan Woodrow
6  email : woodrow dot nathan at gmail dot com
7  ***************************************************************************
8  * *
9  * This program is free software; you can redistribute it and/or modify *
10  * it under the terms of the GNU General Public License as published by *
11  * the Free Software Foundation; either version 2 of the License, or *
12  * (at your option) any later version. *
13  * *
14  ***************************************************************************/
15 #include "qgsruntimeprofiler.h"
16 #include "qgslogger.h"
17 #include "qgis.h"
18 #include "qgsapplication.h"
19 #include <QSet>
20 #include <QThreadStorage>
21 
22 QgsRuntimeProfiler *QgsRuntimeProfiler::sMainProfiler = nullptr;
23 
24 
25 //
26 // QgsRuntimeProfilerNode
27 //
28 
29 QgsRuntimeProfilerNode::QgsRuntimeProfilerNode( const QString &group, const QString &name )
30  : mName( name )
31  , mGroup( group )
32 {
33 
34 }
35 
37 
39 {
40  QStringList res;
41  if ( mParent )
42  {
43  res = mParent->fullParentPath();
44  const QString parentName = mParent->data( Name ).toString();
45  if ( !parentName.isEmpty() )
46  res << parentName;
47  }
48  return res;
49 }
50 
51 QVariant QgsRuntimeProfilerNode::data( int role ) const
52 {
53  switch ( role )
54  {
55  case Qt::DisplayRole:
56  case Qt::ToolTipRole:
57  case Name:
58  return mName;
59 
60  case Group:
61  return mGroup;
62 
63  case Elapsed:
64  return mElapsed;
65 
66  case ParentElapsed:
67  return mParent ? ( mParent->elapsed() > 0 ? mParent->elapsed() : mParent->totalElapsedTimeForChildren( mGroup ) ) : 0;
68  }
69  return QVariant();
70 }
71 
72 void QgsRuntimeProfilerNode::addChild( std::unique_ptr<QgsRuntimeProfilerNode> child )
73 {
74  if ( !child )
75  return;
76 
77  Q_ASSERT( !child->mParent );
78  child->mParent = this;
79 
80  mChildren.emplace_back( std::move( child ) );
81 }
82 
84 {
85  Q_ASSERT( child->mParent == this );
86  const auto it = std::find_if( mChildren.begin(), mChildren.end(), [&]( const std::unique_ptr<QgsRuntimeProfilerNode> &p )
87  {
88  return p.get() == child;
89  } );
90  if ( it != mChildren.end() )
91  return std::distance( mChildren.begin(), it );
92  return -1;
93 }
94 
95 QgsRuntimeProfilerNode *QgsRuntimeProfilerNode::child( const QString &group, const QString &name )
96 {
97  for ( auto &it : mChildren )
98  {
99  if ( it->data( Group ).toString() == group && it->data( Name ).toString() == name )
100  return it.get();
101  }
102  return nullptr;
103 }
104 
106 {
107  Q_ASSERT( static_cast< std::size_t >( index ) < mChildren.size() );
108  return mChildren[ index ].get();
109 }
110 
112 {
113  mChildren.clear();
114 }
115 
117 {
118  Q_ASSERT( static_cast< std::size_t >( index ) < mChildren.size() );
119  mChildren.erase( mChildren.begin() + index );
120 }
121 
123 {
124  mProfileTime.restart();
125 }
126 
128 {
129  mElapsed = mProfileTime.elapsed() / 1000.0;
130 }
131 
133 {
134  mElapsed = time;
135 }
136 
138 {
139  return mElapsed;
140 }
141 
142 double QgsRuntimeProfilerNode::totalElapsedTimeForChildren( const QString &group ) const
143 {
144  double total = 0;
145  for ( auto &it : mChildren )
146  {
147  if ( it->data( Group ).toString() == group )
148  total += it->elapsed();
149  }
150  return total;
151 }
152 
153 //
154 // QgsRuntimeProfiler
155 //
156 
158  : mRootNode( std::make_unique< QgsRuntimeProfilerNode >( QString(), QString() ) )
159 {
160 
161 }
162 
164 
165 QgsRuntimeProfiler *QgsRuntimeProfiler::threadLocalInstance()
166 {
167  static QThreadStorage<QgsRuntimeProfiler> sInstances;
168  QgsRuntimeProfiler *profiler = &sInstances.localData();
169 
170  if ( !qApp || profiler->thread() == qApp->thread() )
171  sMainProfiler = profiler;
172 
173  if ( !profiler->mInitialized )
174  profiler->setupConnections();
175 
176  return profiler;
177 }
178 
179 void QgsRuntimeProfiler::beginGroup( const QString &name )
180 {
181  start( name );
182 }
183 
185 {
186  end();
187 }
188 
189 QStringList QgsRuntimeProfiler::childGroups( const QString &parent, const QString &group ) const
190 {
191  QgsRuntimeProfilerNode *parentNode = pathToNode( group, parent );
192  if ( !parentNode )
193  return QStringList();
194 
195  QStringList res;
196  res.reserve( parentNode->childCount() );
197  for ( int i = 0; i < parentNode->childCount(); ++i )
198  {
199  QgsRuntimeProfilerNode *child = parentNode->childAt( i );
200  if ( child->data( QgsRuntimeProfilerNode::Group ).toString() == group )
201  res << child->data( QgsRuntimeProfilerNode::Name ).toString();
202  }
203  return res;
204 }
205 
206 void QgsRuntimeProfiler::start( const QString &name, const QString &group )
207 {
208  std::unique_ptr< QgsRuntimeProfilerNode > node = std::make_unique< QgsRuntimeProfilerNode >( group, name );
209  node->start();
210 
211  QgsRuntimeProfilerNode *child = node.get();
212  if ( !mCurrentStack[ group ].empty() )
213  {
214  QgsRuntimeProfilerNode *parent = mCurrentStack[group ].top();
215 
216  const QModelIndex parentIndex = node2index( parent );
217  beginInsertRows( parentIndex, parent->childCount(), parent->childCount() );
218  parent->addChild( std::move( node ) );
219  endInsertRows();
220  }
221  else
222  {
223  beginInsertRows( QModelIndex(), mRootNode->childCount(), mRootNode->childCount() );
224  mRootNode->addChild( std::move( node ) );
225  endInsertRows();
226  }
227 
228  mCurrentStack[group].push( child );
229  emit started( group, child->fullParentPath(), name );
230 
231  if ( !mGroups.contains( group ) )
232  {
233  mGroups.insert( group );
234  emit groupAdded( group );
235  }
236 }
237 
238 void QgsRuntimeProfiler::end( const QString &group )
239 {
240  if ( mCurrentStack[group].empty() )
241  return;
242 
243  QgsRuntimeProfilerNode *node = mCurrentStack[group].top();
244  mCurrentStack[group].pop();
245  node->stop();
246 
247  const QModelIndex nodeIndex = node2index( node );
248  const QModelIndex col2Index = index( nodeIndex.row(), 1, nodeIndex.parent() );
249  emit dataChanged( nodeIndex, nodeIndex );
250  emit dataChanged( col2Index, col2Index );
251  // parent item has data changed too, cos the overall time elapsed will have changed!
252  QModelIndex parentIndex = nodeIndex.parent();
253  while ( parentIndex.isValid() )
254  {
255  const QModelIndex parentCol2Index = index( parentIndex.row(), 1, parentIndex.parent() );
256  emit dataChanged( parentIndex, parentIndex );
257  emit dataChanged( parentCol2Index, parentCol2Index );
258  parentIndex = parentIndex.parent();
259  }
260 
261  emit ended( group, node->fullParentPath(), node->data( QgsRuntimeProfilerNode::Name ).toString(), node->data( QgsRuntimeProfilerNode::Elapsed ).toDouble() );
262 }
263 
264 double QgsRuntimeProfiler::profileTime( const QString &name, const QString &group ) const
265 {
266  QgsRuntimeProfilerNode *node = pathToNode( group, name );
267  if ( !node )
268  return 0;
269 
270  return node->data( QgsRuntimeProfilerNode::Elapsed ).toDouble();
271 }
272 
273 void QgsRuntimeProfiler::clear( const QString &group )
274 {
275  for ( int row = mRootNode->childCount() - 1; row >= 0; row-- )
276  {
277  if ( mRootNode->childAt( row )->data( QgsRuntimeProfilerNode::Group ).toString() == group )
278  {
279  beginRemoveRows( QModelIndex(), row, row );
280  mRootNode->removeChildAt( row );
281  endRemoveRows();
282  }
283  }
284 }
285 
286 double QgsRuntimeProfiler::totalTime( const QString &group )
287 {
288  if ( QgsRuntimeProfilerNode *node = pathToNode( group, QString() ) )
289  return node->elapsed();
290 
291  return 0;
292 }
293 
294 bool QgsRuntimeProfiler::groupIsActive( const QString &group ) const
295 {
296  return !mCurrentStack.value( group ).empty();
297 }
298 
299 QString QgsRuntimeProfiler::translateGroupName( const QString &group )
300 {
301  if ( group == QLatin1String( "startup" ) )
302  return tr( "Startup" );
303  else if ( group == QLatin1String( "projectload" ) )
304  return tr( "Project Load" );
305  else if ( group == QLatin1String( "render" ) )
306  return tr( "Map Render" );
307  return QString();
308 }
309 
310 int QgsRuntimeProfiler::rowCount( const QModelIndex &parent ) const
311 {
312  QgsRuntimeProfilerNode *n = index2node( parent );
313  if ( !n )
314  return 0;
315 
316  return n->childCount();
317 }
318 
319 int QgsRuntimeProfiler::columnCount( const QModelIndex &parent ) const
320 {
321  Q_UNUSED( parent )
322  return 2;
323 }
324 
325 QModelIndex QgsRuntimeProfiler::index( int row, int column, const QModelIndex &parent ) const
326 {
327  if ( column < 0 || column >= columnCount( parent ) ||
328  row < 0 || row >= rowCount( parent ) )
329  return QModelIndex();
330 
331  QgsRuntimeProfilerNode *n = index2node( parent );
332  if ( !n )
333  return QModelIndex(); // have no children
334 
335  return createIndex( row, column, n->childAt( row ) );
336 }
337 
338 QModelIndex QgsRuntimeProfiler::parent( const QModelIndex &child ) const
339 {
340  if ( !child.isValid() )
341  return QModelIndex();
342 
343  if ( QgsRuntimeProfilerNode *n = index2node( child ) )
344  {
345  return indexOfParentNode( n->parent() ); // must not be null
346  }
347  else
348  {
349  Q_ASSERT( false );
350  return QModelIndex();
351  }
352 }
353 
354 QVariant QgsRuntimeProfiler::data( const QModelIndex &index, int role ) const
355 {
356  if ( !index.isValid() || index.column() > 2 )
357  return QVariant();
358 
359  QgsRuntimeProfilerNode *node = index2node( index );
360  if ( !node )
361  return QVariant();
362 
363  switch ( index.column() )
364  {
365  case 0:
366  return node->data( role );
367 
368  case 1:
369  {
370  switch ( role )
371  {
372  case Qt::DisplayRole:
373  case Qt::InitialSortOrderRole:
374  return node->data( QgsRuntimeProfilerNode::Elapsed );
375 
376  default:
377  break;
378  }
379  return node->data( role );
380  }
381  }
382  return QVariant();
383 }
384 
385 QVariant QgsRuntimeProfiler::headerData( int section, Qt::Orientation orientation, int role ) const
386 {
387  switch ( role )
388  {
389  case Qt::DisplayRole:
390  {
391  if ( orientation == Qt::Horizontal )
392  {
393  switch ( section )
394  {
395  case 0:
396  return tr( "Task" );
397  case 1:
398  return tr( "Time (seconds)" );
399  default:
400  return QVariant();
401  }
402  }
403  else
404  {
405  return QVariant();
406  }
407  }
408 
409  default:
410  return QAbstractItemModel::headerData( section, orientation, role );
411  }
412 }
413 
414 void QgsRuntimeProfiler::otherProfilerStarted( const QString &group, const QStringList &path, const QString &name )
415 {
416  QgsRuntimeProfilerNode *parentNode = mRootNode.get();
417  for ( const QString &part : path )
418  {
419  QgsRuntimeProfilerNode *child = parentNode->child( group, part );
420  if ( !child )
421  {
422  std::unique_ptr< QgsRuntimeProfilerNode > newChild = std::make_unique< QgsRuntimeProfilerNode >( group, part );
423 
424  const QModelIndex parentIndex = node2index( parentNode );
425  beginInsertRows( parentIndex, parentNode->childCount(), parentNode->childCount() );
426  QgsRuntimeProfilerNode *next = newChild.get();
427  parentNode->addChild( std::move( newChild ) );
428  endInsertRows();
429  parentNode = next;
430  }
431  else
432  {
433  parentNode = child;
434  }
435  }
436 
437  if ( parentNode->child( group, name ) )
438  return;
439 
440  const QModelIndex parentIndex = node2index( parentNode );
441  beginInsertRows( parentIndex, parentNode->childCount(), parentNode->childCount() );
442  parentNode->addChild( std::make_unique< QgsRuntimeProfilerNode >( group, name ) );
443  endInsertRows();
444 
445  if ( !mGroups.contains( group ) )
446  {
447  mGroups.insert( group );
448  emit groupAdded( group );
449  }
450 }
451 
452 void QgsRuntimeProfiler::otherProfilerEnded( const QString &group, const QStringList &path, const QString &name, double elapsed )
453 {
454  QgsRuntimeProfilerNode *parentNode = mRootNode.get();
455  for ( const QString &part : path )
456  {
457  QgsRuntimeProfilerNode *child = parentNode->child( group, part );
458  if ( !child )
459  {
460  std::unique_ptr< QgsRuntimeProfilerNode > newChild = std::make_unique< QgsRuntimeProfilerNode >( group, part );
461 
462  const QModelIndex parentIndex = node2index( parentNode );
463  beginInsertRows( parentIndex, parentNode->childCount(), parentNode->childCount() );
464  QgsRuntimeProfilerNode *next = newChild.get();
465  parentNode->addChild( std::move( newChild ) );
466  endInsertRows();
467  parentNode = next;
468  }
469  else
470  {
471  parentNode = child;
472  }
473  }
474 
475  QgsRuntimeProfilerNode *destNode = parentNode->child( group, name );
476  if ( !destNode )
477  {
478  std::unique_ptr< QgsRuntimeProfilerNode > node = std::make_unique< QgsRuntimeProfilerNode >( group, name );
479  destNode = node.get();
480  const QModelIndex parentIndex = node2index( parentNode );
481  beginInsertRows( parentIndex, parentNode->childCount(), parentNode->childCount() );
482  parentNode->addChild( std::move( node ) );
483  endInsertRows();
484  }
485 
486  destNode->setElapsed( elapsed );
487 
488  const QModelIndex nodeIndex = node2index( destNode );
489  const QModelIndex col2Index = index( nodeIndex.row(), 1, nodeIndex.parent() );
490  emit dataChanged( nodeIndex, nodeIndex );
491  emit dataChanged( col2Index, col2Index );
492  // parent item has data changed too, cos the overall time elapsed will have changed!
493  QModelIndex parentIndex = nodeIndex.parent();
494  while ( parentIndex.isValid() )
495  {
496  const QModelIndex parentCol2Index = index( parentIndex.row(), 1, parentIndex.parent() );
497  emit dataChanged( parentIndex, parentIndex );
498  emit dataChanged( parentCol2Index, parentCol2Index );
499  parentIndex = parentIndex.parent();
500  }
501 }
502 
503 void QgsRuntimeProfiler::setupConnections()
504 {
505  mInitialized = true;
506 
507  Q_ASSERT( sMainProfiler );
508 
509  if ( sMainProfiler != this )
510  {
511  connect( this, &QgsRuntimeProfiler::started, sMainProfiler, &QgsRuntimeProfiler::otherProfilerStarted );
512  connect( this, &QgsRuntimeProfiler::ended, sMainProfiler, &QgsRuntimeProfiler::otherProfilerEnded );
513  }
514 }
515 
516 QgsRuntimeProfilerNode *QgsRuntimeProfiler::pathToNode( const QString &group, const QString &path ) const
517 {
518  const QStringList parts = path.split( '/' );
519  QgsRuntimeProfilerNode *res = mRootNode.get();
520  for ( const QString &part : parts )
521  {
522  if ( part.isEmpty() )
523  continue;
524 
525  res = res->child( group, part );
526  if ( !res )
527  break;
528  }
529  return res;
530 }
531 
532 QgsRuntimeProfilerNode *QgsRuntimeProfiler::pathToNode( const QString &group, const QStringList &path ) const
533 {
534  QgsRuntimeProfilerNode *res = mRootNode.get();
535  for ( const QString &part : path )
536  {
537  res = res->child( group, part );
538  if ( !res )
539  break;
540  }
541  return res;
542 }
543 
544 QModelIndex QgsRuntimeProfiler::node2index( QgsRuntimeProfilerNode *node ) const
545 {
546  if ( !node || !node->parent() )
547  return QModelIndex(); // this is the only root item -> invalid index
548 
549  const QModelIndex parentIndex = node2index( node->parent() );
550 
551  const int row = node->parent()->indexOf( node );
552  Q_ASSERT( row >= 0 );
553  return index( row, 0, parentIndex );
554 }
555 
556 QModelIndex QgsRuntimeProfiler::indexOfParentNode( QgsRuntimeProfilerNode *parentNode ) const
557 {
558  Q_ASSERT( parentNode );
559 
560  QgsRuntimeProfilerNode *grandParentNode = parentNode->parent();
561  if ( !grandParentNode )
562  return QModelIndex(); // root node -> invalid index
563 
564  const int row = grandParentNode->indexOf( parentNode );
565  Q_ASSERT( row >= 0 );
566 
567  return createIndex( row, 0, parentNode );
568 }
569 
570 QgsRuntimeProfilerNode *QgsRuntimeProfiler::index2node( const QModelIndex &index ) const
571 {
572  if ( !index.isValid() )
573  return mRootNode.get();
574 
575  return reinterpret_cast<QgsRuntimeProfilerNode *>( index.internalPointer() );
576 }
577 
578 
579 //
580 // QgsScopedRuntimeProfile
581 //
582 
583 QgsScopedRuntimeProfile::QgsScopedRuntimeProfile( const QString &name, const QString &group )
584  : mGroup( group )
585 {
586  QgsApplication::profiler()->start( name, mGroup );
587 }
588 
590 {
591  QgsApplication::profiler()->end( mGroup );
592 }
593 
594 void QgsScopedRuntimeProfile::switchTask( const QString &name )
595 {
596  QgsApplication::profiler()->end( mGroup );
597  QgsApplication::profiler()->start( name, mGroup );
598 }
static QgsRuntimeProfiler * profiler()
Returns the application runtime profiler.
A node representing an entry in a QgsRuntimeProfiler.
QgsRuntimeProfilerNode * parent()
Returns the node's parent node.
void stop()
Stops the node's timer, recording the elapsed time automatically.
QgsRuntimeProfilerNode * child(const QString &group, const QString &name)
Finds the child with matching group and name.
int indexOf(QgsRuntimeProfilerNode *child) const
Returns the index of the specified child node.
void clear()
Clears the node, removing all its children.
QgsRuntimeProfilerNode * childAt(int index)
Returns the child at the specified index.
double elapsed() const
Returns the node's elapsed time, in seconds.
void addChild(std::unique_ptr< QgsRuntimeProfilerNode > child)
Adds a child node to this node.
void removeChildAt(int index)
Removes and deletes the child at the specified index.
double totalElapsedTimeForChildren(const QString &group) const
Returns the total elapsed time in seconds for all children of this node with matching group.
QgsRuntimeProfilerNode(const QString &group, const QString &name)
Constructor for QgsRuntimeProfilerNode, with the specified group and name.
@ Name
Profile item name.
@ Elapsed
Node elapsed time.
@ ParentElapsed
Total elapsed time for node's parent.
int childCount() const
Returns the number of child nodes owned by this node.
QStringList fullParentPath() const
Returns the full path to the node's parent.
void setElapsed(double time)
Manually sets the node's elapsed time, in seconds.
void start()
Starts the node timer.
QVariant data(int role=Qt::DisplayRole) const
Returns the node's data for the specified model role.
Provides a method of recording run time profiles of operations, allowing easy recording of their over...
void groupAdded(const QString &group)
Emitted when a new group has started being profiled.
QModelIndex parent(const QModelIndex &child) const override
QVariant headerData(int section, Qt::Orientation orientation, int role=Qt::DisplayRole) const override
double profileTime(const QString &name, const QString &group="startup") const
Returns the profile time for the specified name.
QgsRuntimeProfiler()
Constructor to create a new runtime profiler.
QStringList childGroups(const QString &parent=QString(), const QString &group="startup") const
Returns a list of all child groups with the specified parent.
QModelIndex index(int row, int column, const QModelIndex &parent=QModelIndex()) const override
void end(const QString &group="startup")
End the current profile event.
int rowCount(const QModelIndex &parent=QModelIndex()) const override
void start(const QString &name, const QString &group="startup")
Start a profile event with the given name.
double totalTime(const QString &group="startup")
The current total time collected in the profiler.
bool groupIsActive(const QString &group) const
Returns true if the specified group is currently being logged, i.e.
void clear(const QString &group="startup")
clear Clear all profile data.
Q_DECL_DEPRECATED void beginGroup(const QString &name)
Begin the group for the profiler.
~QgsRuntimeProfiler() override
Q_DECL_DEPRECATED void endGroup()
End the current active group.
static QString translateGroupName(const QString &group)
Returns the translated name of a standard profile group.
QVariant data(const QModelIndex &index, int role=Qt::DisplayRole) const override
int columnCount(const QModelIndex &parent=QModelIndex()) const override
void switchTask(const QString &name)
Switches the current task managed by the scoped profile to a new task with the given name.
QgsScopedRuntimeProfile(const QString &name, const QString &group="startup")
Constructor for QgsScopedRuntimeProfile.
~QgsScopedRuntimeProfile()
Records the final runtime of the operation in the profiler instance.