Skip to content
Permalink
Browse files

Fix rendering crash in debug mode (fixes #14369)

Introduced in b6de197 due to the use of static variables in a function that is called from multiple threads.

Further changes to logging:
- also works when sequential rendering is used
- also works in release mode (to allow checking of rendering speed in normal QGIS release)
  • Loading branch information
wonder-sk committed Feb 25, 2016
1 parent a934b01 commit 31c788d7f7cdbacb06c06b93cd3ba599e2fa29b8
@@ -200,6 +200,8 @@ void QgsMapRendererCustomPainterJob::futureFinished()
mRenderingTime = mRenderingStart.elapsed();
QgsDebugMsg( "QPAINTER futureFinished" );

logRenderingTime( mLayerJobs );

// final cleanup
cleanupJobs( mLayerJobs );

@@ -248,8 +250,15 @@ void QgsMapRendererCustomPainterJob::doRender()
}

if ( !job.cached )
{
QTime layerTime;
layerTime.start();

job.renderer->render();

job.renderingTime = layerTime.elapsed();
}

if ( job.img )
{
// If we flattened this layer for alternate blend modes, composite it now
@@ -29,6 +29,7 @@
#include "qgsmaplayerrenderer.h"
#include "qgsmaplayerstylemanager.h"
#include "qgsmaprenderercache.h"
#include "qgsmessagelog.h"
#include "qgspallabeling.h"
#include "qgsvectorlayerrenderer.h"
#include "qgsvectorlayer.h"
@@ -245,6 +246,7 @@ LayerRenderJobs QgsMapRendererJob::prepareJobs( QPainter* painter, QgsPalLabelin
job.img = nullptr;
job.blendMode = ml->blendMode();
job.layerId = ml->id();
job.renderingTime = -1;

job.context = QgsRenderContext::fromMapSettings( mSettings );
job.context.setPainter( painter );
@@ -367,3 +369,22 @@ QImage QgsMapRendererJob::composeImage( const QgsMapSettings& settings, const La
painter.end();
return image;
}

void QgsMapRendererJob::logRenderingTime( const LayerRenderJobs& jobs )
{
QSettings settings;
if ( !settings.value( "/Map/logCanvasRefreshEvent", false ).toBool() )
return;

QMultiMap<int, QString> elapsed;
Q_FOREACH ( const LayerRenderJob& job, jobs )
elapsed.insert( job.renderingTime, job.layerId );

QList<int> tt( elapsed.uniqueKeys() );
qSort( tt.begin(), tt.end(), qGreater<int>() );
Q_FOREACH ( int t, tt )
{
QgsMessageLog::logMessage( tr( "%1 ms: %2" ).arg( t ).arg( QStringList( elapsed.values( t ) ).join( ", " ) ), tr( "Rendering" ) );
}
QgsMessageLog::logMessage( "---", tr( "Rendering" ) );
}
@@ -47,6 +47,7 @@ struct LayerRenderJob
QPainter::CompositionMode blendMode;
bool cached; // if true, img already contains cached image from previous rendering
QString layerId;
int renderingTime; //!< time it took to render the layer in ms (it is -1 if not rendered or still rendering)
};

typedef QList<LayerRenderJob> LayerRenderJobs;
@@ -155,6 +156,9 @@ class CORE_EXPORT QgsMapRendererJob : public QObject
//! @note not available in python bindings
void cleanupJobs( LayerRenderJobs& jobs );

//! @note not available in python bindings
void logRenderingTime( const LayerRenderJobs& jobs );

static QImage composeImage( const QgsMapSettings& settings, const LayerRenderJobs& jobs );

bool needTemporaryImage( QgsMapLayer* ml );
@@ -19,10 +19,8 @@
#include "qgslogger.h"
#include "qgsmaplayerrenderer.h"
#include "qgspallabeling.h"
#include "qgsmessagelog.h"

#include <QtConcurrentMap>
#include <QSettings>

#define LABELING_V2

@@ -188,6 +186,8 @@ void QgsMapRendererParallelJob::renderLayersFinished()
// compose final image
mFinalImage = composeImage( mSettings, mLayerJobs );

logRenderingTime( mLayerJobs );

cleanupJobs( mLayerJobs );

QgsDebugMsg( "PARALLEL layers finished" );
@@ -227,22 +227,9 @@ void QgsMapRendererParallelJob::renderLayerStatic( LayerRenderJob& job )
if ( job.cached )
return;

#ifdef QGISDEBUG
static QSet<QString> running;
static QMultiMap<int, QString> elapsed;

QSettings settings;
bool log = settings.value( "/Map/logCanvasRefreshEvent", false ).toBool();

QTime t;
t.start();
QgsDebugMsg( QString( "job %1 start" ).arg( reinterpret_cast< ulong >( &job ), 0, 16 ) );
if ( log )
{
QgsMessageLog::logMessage( tr( "Layer %1 job started" ).arg( job.layerId ), tr( "Rendering" ) );
running << job.layerId;
}
#endif
QgsDebugMsg( QString( "job %1 start (layer %2)" ).arg( reinterpret_cast< ulong >( &job ), 0, 16 ).arg( job.layerId ) );

try
{
@@ -261,30 +248,8 @@ void QgsMapRendererParallelJob::renderLayerStatic( LayerRenderJob& job )
QgsDebugMsg( "Caught unhandled unknown exception" );
}

#ifdef QGISDEBUG
int tt = t.elapsed();

QgsDebugMsg( QString( "job %1 end [%2 ms]" ).arg( reinterpret_cast< ulong >( &job ), 0, 16 ).arg( tt ) );

if ( log )
{
running.remove( job.layerId );
elapsed.insert( tt, job.layerId );

QgsMessageLog::logMessage( tr( "Layer %1 job ended (%2 ms; still running:%3)" ).arg( job.layerId ).arg( tt ).arg( QStringList( running.values() ).join( ", " ) ), tr( "Rendering" ) );
if ( running.isEmpty() )
{
QList<int> tt( elapsed.keys() );
qSort( tt.begin(), tt.end(), qGreater<int>() );
Q_FOREACH ( int t, tt )
{
QgsMessageLog::logMessage( tr( "%1 ms: %2" ).arg( t ).arg( QStringList( elapsed.values( t ) ).join( ", " ) ), tr( "Rendering" ) );
}
QgsMessageLog::logMessage( "---", tr( "Rendering" ) );
elapsed.clear();
}
}
#endif
job.renderingTime = t.elapsed();
QgsDebugMsg( QString( "job %1 end [%2 ms] (layer %3)" ).arg( reinterpret_cast< ulong >( &job ), 0, 16 ).arg( job.renderingTime ).arg( job.layerId ) );
}


1 comment on commit 31c788d

@jef-n

This comment has been minimized.

Copy link
Member

@jef-n jef-n commented on 31c788d Feb 25, 2016

sorry.

Please sign in to comment.
You can’t perform that action at this time.